[==========] 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:18:13.536267 10296 internal_mini_cluster.cc:156] Creating distributed mini masters. Addrs: 127.10.14.62:42327
I20260812 06:18:13.537222 10296 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:18:13.537823 10296 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:18:13.543766 10307 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:18:13.543900 10296 server_base.cc:1061] running on GCE node
W20260812 06:18:13.543789 10303 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:18:13.544070 10305 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:18:13.544557 10296 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:18:13.544677 10296 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:18:13.544730 10296 hybrid_clock.cc:648] HybridClock initialized: now 1786515493544728 us; error 0 us; skew 500 ppm
I20260812 06:18:13.546420 10296 webserver.cc:533] Webserver started at http://127.10.14.62:33097/ using document root <none> and password file <none>
I20260812 06:18:13.546936 10296 fs_manager.cc:362] Metadata directory not provided
I20260812 06:18:13.546994 10296 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:18:13.547278 10296 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:18:13.548892 10296 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskLBU3bg/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515493525939-10296-0/minicluster-data/master-0-root/instance:
uuid: "1ffa208a10b9446da67287ba16cba281"
format_stamp: "Formatted at 2026-08-12 06:18:13 on dist-test-slave-w4v5"
I20260812 06:18:13.552382 10296 fs_manager.cc:696] Time spent creating directory manager: real 0.003s	user 0.004s	sys 0.000s
I20260812 06:18:13.554414 10313 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:18:13.555454 10296 fs_manager.cc:730] Time spent opening block manager: real 0.002s	user 0.003s	sys 0.000s
I20260812 06:18:13.555573 10296 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskLBU3bg/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515493525939-10296-0/minicluster-data/master-0-root
uuid: "1ffa208a10b9446da67287ba16cba281"
format_stamp: "Formatted at 2026-08-12 06:18:13 on dist-test-slave-w4v5"
I20260812 06:18:13.555671 10296 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskLBU3bg/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515493525939-10296-0/minicluster-data/master-0-root
metadata directory: /tmp/dist-test-taskLBU3bg/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515493525939-10296-0/minicluster-data/master-0-root
1 data directories: /tmp/dist-test-taskLBU3bg/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515493525939-10296-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:18:13.569798 10296 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:18:13.570365 10296 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:18:13.570551 10296 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:18:13.578275 10296 rpc_server.cc:307] RPC server started. Bound to: 127.10.14.62:42327
I20260812 06:18:13.578367 10405 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.10.14.62:42327 every 8 connection(s)
I20260812 06:18:13.580415 10408 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:18:13.585664 10408 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P 1ffa208a10b9446da67287ba16cba281: Bootstrap starting.
I20260812 06:18:13.587986 10408 tablet_bootstrap.cc:654] T 00000000000000000000000000000000 P 1ffa208a10b9446da67287ba16cba281: Neither blocks nor log segments found. Creating new log.
I20260812 06:18:13.588856 10408 log.cc:826] T 00000000000000000000000000000000 P 1ffa208a10b9446da67287ba16cba281: Log is configured to *not* fsync() on all Append() calls
I20260812 06:18:13.590618 10408 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P 1ffa208a10b9446da67287ba16cba281: No bootstrap required, opened a new log
I20260812 06:18:13.593430 10408 raft_consensus.cc:359] T 00000000000000000000000000000000 P 1ffa208a10b9446da67287ba16cba281 [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "1ffa208a10b9446da67287ba16cba281" member_type: VOTER }
I20260812 06:18:13.593604 10408 raft_consensus.cc:385] T 00000000000000000000000000000000 P 1ffa208a10b9446da67287ba16cba281 [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:18:13.593647 10408 raft_consensus.cc:740] T 00000000000000000000000000000000 P 1ffa208a10b9446da67287ba16cba281 [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: 1ffa208a10b9446da67287ba16cba281, State: Initialized, Role: FOLLOWER
I20260812 06:18:13.594254 10408 consensus_queue.cc:260] T 00000000000000000000000000000000 P 1ffa208a10b9446da67287ba16cba281 [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: "1ffa208a10b9446da67287ba16cba281" member_type: VOTER }
I20260812 06:18:13.594424 10408 raft_consensus.cc:399] T 00000000000000000000000000000000 P 1ffa208a10b9446da67287ba16cba281 [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:18:13.594496 10408 raft_consensus.cc:493] T 00000000000000000000000000000000 P 1ffa208a10b9446da67287ba16cba281 [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:18:13.594661 10408 raft_consensus.cc:3060] T 00000000000000000000000000000000 P 1ffa208a10b9446da67287ba16cba281 [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:18:13.595475 10408 raft_consensus.cc:515] T 00000000000000000000000000000000 P 1ffa208a10b9446da67287ba16cba281 [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "1ffa208a10b9446da67287ba16cba281" member_type: VOTER }
I20260812 06:18:13.595921 10408 leader_election.cc:304] T 00000000000000000000000000000000 P 1ffa208a10b9446da67287ba16cba281 [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: 1ffa208a10b9446da67287ba16cba281; no voters: 
I20260812 06:18:13.596257 10408 leader_election.cc:290] T 00000000000000000000000000000000 P 1ffa208a10b9446da67287ba16cba281 [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:18:13.596379 10412 raft_consensus.cc:2804] T 00000000000000000000000000000000 P 1ffa208a10b9446da67287ba16cba281 [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:18:13.596629 10412 raft_consensus.cc:697] T 00000000000000000000000000000000 P 1ffa208a10b9446da67287ba16cba281 [term 1 LEADER]: Becoming Leader. State: Replica: 1ffa208a10b9446da67287ba16cba281, State: Running, Role: LEADER
I20260812 06:18:13.597084 10412 consensus_queue.cc:237] T 00000000000000000000000000000000 P 1ffa208a10b9446da67287ba16cba281 [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: "1ffa208a10b9446da67287ba16cba281" member_type: VOTER }
I20260812 06:18:13.597266 10408 sys_catalog.cc:565] T 00000000000000000000000000000000 P 1ffa208a10b9446da67287ba16cba281 [sys.catalog]: configured and running, proceeding with master startup.
I20260812 06:18:13.598839 10417 sys_catalog.cc:455] T 00000000000000000000000000000000 P 1ffa208a10b9446da67287ba16cba281 [sys.catalog]: SysCatalogTable state changed. Reason: New leader 1ffa208a10b9446da67287ba16cba281. Latest consensus state: current_term: 1 leader_uuid: "1ffa208a10b9446da67287ba16cba281" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "1ffa208a10b9446da67287ba16cba281" member_type: VOTER } }
I20260812 06:18:13.598881 10413 sys_catalog.cc:455] T 00000000000000000000000000000000 P 1ffa208a10b9446da67287ba16cba281 [sys.catalog]: SysCatalogTable state changed. Reason: RaftConsensus started. Latest consensus state: current_term: 1 leader_uuid: "1ffa208a10b9446da67287ba16cba281" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "1ffa208a10b9446da67287ba16cba281" member_type: VOTER } }
I20260812 06:18:13.598956 10417 sys_catalog.cc:458] T 00000000000000000000000000000000 P 1ffa208a10b9446da67287ba16cba281 [sys.catalog]: This master's current role is: LEADER
I20260812 06:18:13.598984 10413 sys_catalog.cc:458] T 00000000000000000000000000000000 P 1ffa208a10b9446da67287ba16cba281 [sys.catalog]: This master's current role is: LEADER
I20260812 06:18:13.599414 10429 catalog_manager.cc:1511] Loading table and tablet metadata into memory...
I20260812 06:18:13.599731 10296 internal_mini_cluster.cc:184] Waiting to initialize catalog manager on master 0
I20260812 06:18:13.601962 10429 catalog_manager.cc:1520] Initializing Kudu cluster ID...
I20260812 06:18:13.606693 10429 catalog_manager.cc:1383] Generated new cluster ID: 400b975ce35144b6b9c68754f25b32f1
I20260812 06:18:13.606765 10429 catalog_manager.cc:1531] Initializing Kudu internal certificate authority...
I20260812 06:18:13.617901 10429 catalog_manager.cc:1406] Generated new certificate authority record
I20260812 06:18:13.618717 10429 catalog_manager.cc:1540] Loading token signing keys...
I20260812 06:18:13.623827 10429 catalog_manager.cc:6092] T 00000000000000000000000000000000 P 1ffa208a10b9446da67287ba16cba281: Generated new TSK 0
I20260812 06:18:13.624435 10429 catalog_manager.cc:1550] Initializing in-progress tserver states...
I20260812 06:18:13.632257 10296 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:18:13.635140 10442 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:18:13.635210 10445 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:18:13.635332 10449 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:18:13.635581 10296 server_base.cc:1061] running on GCE node
I20260812 06:18:13.635795 10296 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:18:13.635836 10296 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:18:13.635852 10296 hybrid_clock.cc:648] HybridClock initialized: now 1786515493635852 us; error 0 us; skew 500 ppm
I20260812 06:18:13.636799 10296 webserver.cc:533] Webserver started at http://127.10.14.1:38341/ using document root <none> and password file <none>
I20260812 06:18:13.636981 10296 fs_manager.cc:362] Metadata directory not provided
I20260812 06:18:13.637030 10296 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:18:13.637142 10296 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:18:13.637552 10296 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskLBU3bg/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515493525939-10296-0/minicluster-data/ts-0-root/instance:
uuid: "ac381f53065b4cbe98e69ae84ee46847"
format_stamp: "Formatted at 2026-08-12 06:18:13 on dist-test-slave-w4v5"
I20260812 06:18:13.639070 10296 fs_manager.cc:696] Time spent creating directory manager: real 0.001s	user 0.002s	sys 0.000s
I20260812 06:18:13.640194 10455 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:18:13.640452 10296 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.001s	sys 0.000s
I20260812 06:18:13.640542 10296 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskLBU3bg/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515493525939-10296-0/minicluster-data/ts-0-root
uuid: "ac381f53065b4cbe98e69ae84ee46847"
format_stamp: "Formatted at 2026-08-12 06:18:13 on dist-test-slave-w4v5"
I20260812 06:18:13.640616 10296 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskLBU3bg/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515493525939-10296-0/minicluster-data/ts-0-root
metadata directory: /tmp/dist-test-taskLBU3bg/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515493525939-10296-0/minicluster-data/ts-0-root
1 data directories: /tmp/dist-test-taskLBU3bg/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515493525939-10296-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:18:13.670454 10296 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:18:13.670955 10296 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:18:13.671551 10296 txn_system_client.cc:432] TxnSystemClient initialization is disabled...
I20260812 06:18:13.672412 10296 ts_tablet_manager.cc:585] Loaded tablet metadata (0 total tablets, 0 live tablets)
I20260812 06:18:13.672492 10296 ts_tablet_manager.cc:531] Time spent load tablet metadata: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:18:13.672570 10296 ts_tablet_manager.cc:616] Registered 0 tablets
I20260812 06:18:13.672616 10296 ts_tablet_manager.cc:595] Time spent register tablets: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:18:13.679500 10296 rpc_server.cc:307] RPC server started. Bound to: 127.10.14.1:46795
I20260812 06:18:13.679543 10577 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.10.14.1:46795 every 8 connection(s)
I20260812 06:18:13.689975 10578 heartbeater.cc:344] Connected to a master server at 127.10.14.62:42327
I20260812 06:18:13.690213 10578 heartbeater.cc:461] Registering TS with master...
I20260812 06:18:13.690723 10578 heartbeater.cc:507] Master 127.10.14.62:42327 requested a full tablet report, sending...
I20260812 06:18:13.692286 10342 ts_manager.cc:194] Registered new tserver with Master: ac381f53065b4cbe98e69ae84ee46847 (127.10.14.1:46795)
I20260812 06:18:13.692543 10296 internal_mini_cluster.cc:371] 1 TS(s) registered with all masters after 0.012422346s
I20260812 06:18:13.693789 10342 master_service.cc:502] Signed X509 certificate for tserver {username='slave'} at 127.0.0.1:43100
I20260812 06:18:13.702199 10342 catalog_manager.cc:2283] Servicing CreateTable request from {username='slave'} at 127.0.0.1:43108:
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:18:13.716470 10514 tablet_service.cc:1511] Processing CreateTablet for tablet ffcd899db4b34bb0ae2ed1d1ffe997aa (DEFAULT_TABLE table=heavy-update-compaction-test [id=fc9a377ae3d9491498b103927700a482]), partition=
I20260812 06:18:13.716984 10514 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet ffcd899db4b34bb0ae2ed1d1ffe997aa. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:18:13.719219 10597 tablet_bootstrap.cc:492] T ffcd899db4b34bb0ae2ed1d1ffe997aa P ac381f53065b4cbe98e69ae84ee46847: Bootstrap starting.
I20260812 06:18:13.720086 10597 tablet_bootstrap.cc:654] T ffcd899db4b34bb0ae2ed1d1ffe997aa P ac381f53065b4cbe98e69ae84ee46847: Neither blocks nor log segments found. Creating new log.
I20260812 06:18:13.721230 10597 tablet_bootstrap.cc:492] T ffcd899db4b34bb0ae2ed1d1ffe997aa P ac381f53065b4cbe98e69ae84ee46847: No bootstrap required, opened a new log
I20260812 06:18:13.721313 10597 ts_tablet_manager.cc:1403] T ffcd899db4b34bb0ae2ed1d1ffe997aa P ac381f53065b4cbe98e69ae84ee46847: Time spent bootstrapping tablet: real 0.002s	user 0.002s	sys 0.000s
I20260812 06:18:13.721751 10597 raft_consensus.cc:359] T ffcd899db4b34bb0ae2ed1d1ffe997aa P ac381f53065b4cbe98e69ae84ee46847 [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "ac381f53065b4cbe98e69ae84ee46847" member_type: VOTER last_known_addr { host: "127.10.14.1" port: 46795 } }
I20260812 06:18:13.721848 10597 raft_consensus.cc:385] T ffcd899db4b34bb0ae2ed1d1ffe997aa P ac381f53065b4cbe98e69ae84ee46847 [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:18:13.721870 10597 raft_consensus.cc:740] T ffcd899db4b34bb0ae2ed1d1ffe997aa P ac381f53065b4cbe98e69ae84ee46847 [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: ac381f53065b4cbe98e69ae84ee46847, State: Initialized, Role: FOLLOWER
I20260812 06:18:13.722028 10597 consensus_queue.cc:260] T ffcd899db4b34bb0ae2ed1d1ffe997aa P ac381f53065b4cbe98e69ae84ee46847 [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: "ac381f53065b4cbe98e69ae84ee46847" member_type: VOTER last_known_addr { host: "127.10.14.1" port: 46795 } }
I20260812 06:18:13.722122 10597 raft_consensus.cc:399] T ffcd899db4b34bb0ae2ed1d1ffe997aa P ac381f53065b4cbe98e69ae84ee46847 [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:18:13.722172 10597 raft_consensus.cc:493] T ffcd899db4b34bb0ae2ed1d1ffe997aa P ac381f53065b4cbe98e69ae84ee46847 [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:18:13.722229 10597 raft_consensus.cc:3060] T ffcd899db4b34bb0ae2ed1d1ffe997aa P ac381f53065b4cbe98e69ae84ee46847 [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:18:13.722934 10597 raft_consensus.cc:515] T ffcd899db4b34bb0ae2ed1d1ffe997aa P ac381f53065b4cbe98e69ae84ee46847 [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "ac381f53065b4cbe98e69ae84ee46847" member_type: VOTER last_known_addr { host: "127.10.14.1" port: 46795 } }
I20260812 06:18:13.723083 10597 leader_election.cc:304] T ffcd899db4b34bb0ae2ed1d1ffe997aa P ac381f53065b4cbe98e69ae84ee46847 [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: ac381f53065b4cbe98e69ae84ee46847; no voters: 
I20260812 06:18:13.723343 10597 leader_election.cc:290] T ffcd899db4b34bb0ae2ed1d1ffe997aa P ac381f53065b4cbe98e69ae84ee46847 [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:18:13.723464 10600 raft_consensus.cc:2804] T ffcd899db4b34bb0ae2ed1d1ffe997aa P ac381f53065b4cbe98e69ae84ee46847 [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:18:13.723676 10597 ts_tablet_manager.cc:1434] T ffcd899db4b34bb0ae2ed1d1ffe997aa P ac381f53065b4cbe98e69ae84ee46847: Time spent starting tablet: real 0.002s	user 0.000s	sys 0.002s
I20260812 06:18:13.723775 10600 raft_consensus.cc:697] T ffcd899db4b34bb0ae2ed1d1ffe997aa P ac381f53065b4cbe98e69ae84ee46847 [term 1 LEADER]: Becoming Leader. State: Replica: ac381f53065b4cbe98e69ae84ee46847, State: Running, Role: LEADER
I20260812 06:18:13.723867 10578 heartbeater.cc:499] Master 127.10.14.62:42327 was elected leader, sending a full tablet report...
I20260812 06:18:13.723913 10600 consensus_queue.cc:237] T ffcd899db4b34bb0ae2ed1d1ffe997aa P ac381f53065b4cbe98e69ae84ee46847 [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: "ac381f53065b4cbe98e69ae84ee46847" member_type: VOTER last_known_addr { host: "127.10.14.1" port: 46795 } }
I20260812 06:18:13.726619 10342 catalog_manager.cc:5719] T ffcd899db4b34bb0ae2ed1d1ffe997aa P ac381f53065b4cbe98e69ae84ee46847 reported cstate change: term changed from 0 to 1, leader changed from <none> to ac381f53065b4cbe98e69ae84ee46847 (127.10.14.1). New cstate: current_term: 1 leader_uuid: "ac381f53065b4cbe98e69ae84ee46847" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "ac381f53065b4cbe98e69ae84ee46847" member_type: VOTER last_known_addr { host: "127.10.14.1" port: 46795 } health_report { overall_health: HEALTHY } } }
I20260812 06:18:13.795399 10296 heavy-update-compaction-itest.cc:215] Time spent inserting: real 0.064s	user 0.027s	sys 0.008s
I20260812 06:18:13.930601 10580 maintenance_manager.cc:419] P ac381f53065b4cbe98e69ae84ee46847: Scheduling FlushMRSOp(ffcd899db4b34bb0ae2ed1d1ffe997aa): perf score=19.054940
I20260812 06:18:14.113336 10463 maintenance_manager.cc:643] P ac381f53065b4cbe98e69ae84ee46847: FlushMRSOp(ffcd899db4b34bb0ae2ed1d1ffe997aa) complete. Timing: real 0.182s	user 0.125s	sys 0.051s Metrics: {"bytes_written":13415136,"cfile_init":1,"compiler_manager_pool.queue_time_us":221,"delete_count":0,"dirs.queue_time_us":75,"dirs.run_cpu_time_us":235,"dirs.run_wall_time_us":796,"drs_written":1,"lbm_read_time_us":73,"lbm_reads_lt_1ms":4,"lbm_write_time_us":47645,"lbm_writes_lt_1ms":784,"peak_mem_usage":0,"reinsert_count":0,"rows_written":104,"spinlock_wait_cycles":60288,"thread_start_us":146,"threads_started":1,"update_count":1635}
I20260812 06:18:14.114586 10580 maintenance_manager.cc:419] P ac381f53065b4cbe98e69ae84ee46847: Scheduling UndoDeltaBlockGCOp(ffcd899db4b34bb0ae2ed1d1ffe997aa): 16411483 bytes on disk
I20260812 06:18:14.115335 10463 maintenance_manager.cc:643] P ac381f53065b4cbe98e69ae84ee46847: UndoDeltaBlockGCOp(ffcd899db4b34bb0ae2ed1d1ffe997aa) complete. Timing: real 0.001s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":87,"lbm_reads_lt_1ms":4}
I20260812 06:18:14.115746 10580 maintenance_manager.cc:419] P ac381f53065b4cbe98e69ae84ee46847: Scheduling FlushDeltaMemStoresOp(ffcd899db4b34bb0ae2ed1d1ffe997aa): perf score=3.181125
I20260812 06:18:14.137576 10463 maintenance_manager.cc:643] P ac381f53065b4cbe98e69ae84ee46847: FlushDeltaMemStoresOp(ffcd899db4b34bb0ae2ed1d1ffe997aa) complete. Timing: real 0.022s	user 0.006s	sys 0.011s Metrics: {"bytes_written":4759050,"delete_count":0,"lbm_write_time_us":6301,"lbm_writes_lt_1ms":119,"reinsert_count":0,"update_count":580}
I20260812 06:18:14.138113 10580 maintenance_manager.cc:419] P ac381f53065b4cbe98e69ae84ee46847: Scheduling LogGCOp(ffcd899db4b34bb0ae2ed1d1ffe997aa): free 20743880 bytes of WAL
I20260812 06:18:14.138411 10463 log_reader.cc:385] T ffcd899db4b34bb0ae2ed1d1ffe997aa: removed 2 log segments from log reader
I20260812 06:18:14.138478 10463 log.cc:1079] T ffcd899db4b34bb0ae2ed1d1ffe997aa P ac381f53065b4cbe98e69ae84ee46847: Deleting log segment in path: /tmp/dist-test-taskLBU3bg/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515493525939-10296-0/minicluster-data/ts-0-root/wals/ffcd899db4b34bb0ae2ed1d1ffe997aa/wal-000000001 (ops 1-6)
I20260812 06:18:14.138530 10463 log.cc:1079] T ffcd899db4b34bb0ae2ed1d1ffe997aa P ac381f53065b4cbe98e69ae84ee46847: Deleting log segment in path: /tmp/dist-test-taskLBU3bg/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515493525939-10296-0/minicluster-data/ts-0-root/wals/ffcd899db4b34bb0ae2ed1d1ffe997aa/wal-000000002 (ops 7-11)
I20260812 06:18:14.144162 10463 maintenance_manager.cc:643] P ac381f53065b4cbe98e69ae84ee46847: LogGCOp(ffcd899db4b34bb0ae2ed1d1ffe997aa) complete. Timing: real 0.006s	user 0.000s	sys 0.005s Metrics: {}
I20260812 06:18:14.144511 10580 maintenance_manager.cc:419] P ac381f53065b4cbe98e69ae84ee46847: Scheduling FlushDeltaMemStoresOp(ffcd899db4b34bb0ae2ed1d1ffe997aa): perf score=1.196750
I20260812 06:18:14.154834 10463 maintenance_manager.cc:643] P ac381f53065b4cbe98e69ae84ee46847: FlushDeltaMemStoresOp(ffcd899db4b34bb0ae2ed1d1ffe997aa) complete. Timing: real 0.010s	user 0.007s	sys 0.001s Metrics: {"bytes_written":2338579,"delete_count":0,"lbm_write_time_us":3601,"lbm_writes_lt_1ms":60,"reinsert_count":0,"update_count":285}
I20260812 06:18:14.155354 10580 maintenance_manager.cc:419] P ac381f53065b4cbe98e69ae84ee46847: Scheduling MajorDeltaCompactionOp(ffcd899db4b34bb0ae2ed1d1ffe997aa): perf score=1.000000
I20260812 06:18:14.331739 10463 maintenance_manager.cc:643] P ac381f53065b4cbe98e69ae84ee46847: MajorDeltaCompactionOp(ffcd899db4b34bb0ae2ed1d1ffe997aa) complete. Timing: real 0.176s	user 0.119s	sys 0.056s Metrics: {"cfile_cache_miss":533,"cfile_cache_miss_bytes":24774765,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":482,"lbm_read_time_us":11820,"lbm_reads_lt_1ms":569,"lbm_write_time_us":31083,"lbm_writes_lt_1ms":543,"mutex_wait_us":20,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":7040,"thread_start_us":301,"threads_started":5,"update_count":2500}
I20260812 06:18:14.332259 10580 maintenance_manager.cc:419] P ac381f53065b4cbe98e69ae84ee46847: Scheduling FlushDeltaMemStoresOp(ffcd899db4b34bb0ae2ed1d1ffe997aa): perf score=10.126437
I20260812 06:18:14.370157 10463 maintenance_manager.cc:643] P ac381f53065b4cbe98e69ae84ee46847: FlushDeltaMemStoresOp(ffcd899db4b34bb0ae2ed1d1ffe997aa) complete. Timing: real 0.038s	user 0.016s	sys 0.016s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":15007,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:18:14.370733 10580 maintenance_manager.cc:419] P ac381f53065b4cbe98e69ae84ee46847: Scheduling FlushDeltaMemStoresOp(ffcd899db4b34bb0ae2ed1d1ffe997aa): perf score=2.188937
I20260812 06:18:14.385716 10463 maintenance_manager.cc:643] P ac381f53065b4cbe98e69ae84ee46847: FlushDeltaMemStoresOp(ffcd899db4b34bb0ae2ed1d1ffe997aa) complete. Timing: real 0.015s	user 0.008s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5598,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:14.386248 10580 maintenance_manager.cc:419] P ac381f53065b4cbe98e69ae84ee46847: Scheduling MajorDeltaCompactionOp(ffcd899db4b34bb0ae2ed1d1ffe997aa): perf score=1.000000
I20260812 06:18:14.514473 10463 maintenance_manager.cc:643] P ac381f53065b4cbe98e69ae84ee46847: MajorDeltaCompactionOp(ffcd899db4b34bb0ae2ed1d1ffe997aa) complete. Timing: real 0.128s	user 0.108s	sys 0.020s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672277,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":444,"lbm_read_time_us":8846,"lbm_reads_lt_1ms":472,"lbm_write_time_us":24960,"lbm_writes_lt_1ms":443,"mutex_wait_us":102,"peak_mem_usage":50689328,"reinsert_count":0,"update_count":2000}
I20260812 06:18:14.515161 10580 maintenance_manager.cc:419] P ac381f53065b4cbe98e69ae84ee46847: Scheduling FlushDeltaMemStoresOp(ffcd899db4b34bb0ae2ed1d1ffe997aa): perf score=10.126437
I20260812 06:18:14.565038 10463 maintenance_manager.cc:643] P ac381f53065b4cbe98e69ae84ee46847: FlushDeltaMemStoresOp(ffcd899db4b34bb0ae2ed1d1ffe997aa) complete. Timing: real 0.050s	user 0.026s	sys 0.010s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":17315,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":302,"reinsert_count":0,"update_count":1500}
I20260812 06:18:14.565541 10580 maintenance_manager.cc:419] P ac381f53065b4cbe98e69ae84ee46847: Scheduling FlushDeltaMemStoresOp(ffcd899db4b34bb0ae2ed1d1ffe997aa): perf score=2.188937
I20260812 06:18:14.576763 10463 maintenance_manager.cc:643] P ac381f53065b4cbe98e69ae84ee46847: FlushDeltaMemStoresOp(ffcd899db4b34bb0ae2ed1d1ffe997aa) complete. Timing: real 0.011s	user 0.001s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4169,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:14.577462 10580 maintenance_manager.cc:419] P ac381f53065b4cbe98e69ae84ee46847: Scheduling MajorDeltaCompactionOp(ffcd899db4b34bb0ae2ed1d1ffe997aa): perf score=1.000000
I20260812 06:18:14.702023 10463 maintenance_manager.cc:643] P ac381f53065b4cbe98e69ae84ee46847: MajorDeltaCompactionOp(ffcd899db4b34bb0ae2ed1d1ffe997aa) complete. Timing: real 0.124s	user 0.106s	sys 0.015s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672277,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":414,"lbm_read_time_us":7915,"lbm_reads_lt_1ms":472,"lbm_write_time_us":24916,"lbm_writes_lt_1ms":443,"mutex_wait_us":67,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":7936,"update_count":2000}
I20260812 06:18:14.702646 10580 maintenance_manager.cc:419] P ac381f53065b4cbe98e69ae84ee46847: Scheduling FlushDeltaMemStoresOp(ffcd899db4b34bb0ae2ed1d1ffe997aa): perf score=10.126437
I20260812 06:18:14.739916 10463 maintenance_manager.cc:643] P ac381f53065b4cbe98e69ae84ee46847: FlushDeltaMemStoresOp(ffcd899db4b34bb0ae2ed1d1ffe997aa) complete. Timing: real 0.037s	user 0.017s	sys 0.015s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":14188,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:18:14.740387 10580 maintenance_manager.cc:419] P ac381f53065b4cbe98e69ae84ee46847: Scheduling FlushDeltaMemStoresOp(ffcd899db4b34bb0ae2ed1d1ffe997aa): perf score=2.188937
I20260812 06:18:14.751638 10463 maintenance_manager.cc:643] P ac381f53065b4cbe98e69ae84ee46847: FlushDeltaMemStoresOp(ffcd899db4b34bb0ae2ed1d1ffe997aa) complete. Timing: real 0.011s	user 0.006s	sys 0.004s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4018,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:14.752200 10580 maintenance_manager.cc:419] P ac381f53065b4cbe98e69ae84ee46847: Scheduling MajorDeltaCompactionOp(ffcd899db4b34bb0ae2ed1d1ffe997aa): perf score=1.000000
I20260812 06:18:14.890525 10463 maintenance_manager.cc:643] P ac381f53065b4cbe98e69ae84ee46847: MajorDeltaCompactionOp(ffcd899db4b34bb0ae2ed1d1ffe997aa) complete. Timing: real 0.138s	user 0.101s	sys 0.036s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672276,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":1290,"lbm_read_time_us":11233,"lbm_reads_lt_1ms":472,"lbm_write_time_us":27618,"lbm_writes_lt_1ms":443,"mutex_wait_us":330,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":7808,"update_count":2000}
I20260812 06:18:14.891256 10580 maintenance_manager.cc:419] P ac381f53065b4cbe98e69ae84ee46847: Scheduling FlushDeltaMemStoresOp(ffcd899db4b34bb0ae2ed1d1ffe997aa): perf score=10.126437
I20260812 06:18:14.937379 10463 maintenance_manager.cc:643] P ac381f53065b4cbe98e69ae84ee46847: FlushDeltaMemStoresOp(ffcd899db4b34bb0ae2ed1d1ffe997aa) complete. Timing: real 0.046s	user 0.023s	sys 0.016s Metrics: {"bytes_written":12307491,"delete_count":0,"lbm_write_time_us":14713,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:18:14.937983 10580 maintenance_manager.cc:419] P ac381f53065b4cbe98e69ae84ee46847: Scheduling FlushDeltaMemStoresOp(ffcd899db4b34bb0ae2ed1d1ffe997aa): perf score=2.188937
I20260812 06:18:14.948618 10463 maintenance_manager.cc:643] P ac381f53065b4cbe98e69ae84ee46847: FlushDeltaMemStoresOp(ffcd899db4b34bb0ae2ed1d1ffe997aa) complete. Timing: real 0.010s	user 0.009s	sys 0.000s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4176,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:14.949029 10580 maintenance_manager.cc:419] P ac381f53065b4cbe98e69ae84ee46847: Scheduling MajorDeltaCompactionOp(ffcd899db4b34bb0ae2ed1d1ffe997aa): perf score=1.000000
I20260812 06:18:15.092768 10463 maintenance_manager.cc:643] P ac381f53065b4cbe98e69ae84ee46847: MajorDeltaCompactionOp(ffcd899db4b34bb0ae2ed1d1ffe997aa) complete. Timing: real 0.144s	user 0.101s	sys 0.042s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672277,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":475,"lbm_read_time_us":10595,"lbm_reads_lt_1ms":472,"lbm_write_time_us":23505,"lbm_writes_lt_1ms":443,"mutex_wait_us":32,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":19968,"update_count":2000}
I20260812 06:18:15.093304 10580 maintenance_manager.cc:419] P ac381f53065b4cbe98e69ae84ee46847: Scheduling FlushDeltaMemStoresOp(ffcd899db4b34bb0ae2ed1d1ffe997aa): perf score=10.126437
I20260812 06:18:15.132651 10463 maintenance_manager.cc:643] P ac381f53065b4cbe98e69ae84ee46847: FlushDeltaMemStoresOp(ffcd899db4b34bb0ae2ed1d1ffe997aa) complete. Timing: real 0.039s	user 0.028s	sys 0.008s Metrics: {"bytes_written":12307491,"delete_count":0,"lbm_write_time_us":16852,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:18:15.133090 10580 maintenance_manager.cc:419] P ac381f53065b4cbe98e69ae84ee46847: Scheduling FlushDeltaMemStoresOp(ffcd899db4b34bb0ae2ed1d1ffe997aa): perf score=2.188937
I20260812 06:18:15.144322 10463 maintenance_manager.cc:643] P ac381f53065b4cbe98e69ae84ee46847: FlushDeltaMemStoresOp(ffcd899db4b34bb0ae2ed1d1ffe997aa) complete. Timing: real 0.011s	user 0.002s	sys 0.008s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4072,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:15.144765 10580 maintenance_manager.cc:419] P ac381f53065b4cbe98e69ae84ee46847: Scheduling MajorDeltaCompactionOp(ffcd899db4b34bb0ae2ed1d1ffe997aa): perf score=1.000000
I20260812 06:18:15.272677 10463 maintenance_manager.cc:643] P ac381f53065b4cbe98e69ae84ee46847: MajorDeltaCompactionOp(ffcd899db4b34bb0ae2ed1d1ffe997aa) complete. Timing: real 0.128s	user 0.097s	sys 0.030s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672277,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":942,"lbm_read_time_us":7417,"lbm_reads_lt_1ms":472,"lbm_write_time_us":27265,"lbm_writes_lt_1ms":443,"mutex_wait_us":273,"peak_mem_usage":50689328,"reinsert_count":0,"update_count":2000}
I20260812 06:18:15.273253 10580 maintenance_manager.cc:419] P ac381f53065b4cbe98e69ae84ee46847: Scheduling FlushDeltaMemStoresOp(ffcd899db4b34bb0ae2ed1d1ffe997aa): perf score=10.126437
I20260812 06:18:15.315044 10463 maintenance_manager.cc:643] P ac381f53065b4cbe98e69ae84ee46847: FlushDeltaMemStoresOp(ffcd899db4b34bb0ae2ed1d1ffe997aa) complete. Timing: real 0.042s	user 0.027s	sys 0.001s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":13679,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:18:15.315551 10580 maintenance_manager.cc:419] P ac381f53065b4cbe98e69ae84ee46847: Scheduling FlushDeltaMemStoresOp(ffcd899db4b34bb0ae2ed1d1ffe997aa): perf score=2.188937
I20260812 06:18:15.325820 10463 maintenance_manager.cc:643] P ac381f53065b4cbe98e69ae84ee46847: FlushDeltaMemStoresOp(ffcd899db4b34bb0ae2ed1d1ffe997aa) complete. Timing: real 0.010s	user 0.008s	sys 0.001s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3967,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:15.326221 10580 maintenance_manager.cc:419] P ac381f53065b4cbe98e69ae84ee46847: Scheduling FlushMRSOp(ffcd899db4b34bb0ae2ed1d1ffe997aa): perf score=1.000000
I20260812 06:18:15.358419 10463 maintenance_manager.cc:643] P ac381f53065b4cbe98e69ae84ee46847: FlushMRSOp(ffcd899db4b34bb0ae2ed1d1ffe997aa) complete. Timing: real 0.032s	user 0.028s	sys 0.000s Metrics: {"bytes_written":1193503,"cfile_init":1,"dirs.queue_time_us":77,"dirs.run_cpu_time_us":236,"dirs.run_wall_time_us":1141,"drs_written":1,"lbm_read_time_us":60,"lbm_reads_lt_1ms":4,"lbm_write_time_us":2137,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":29}
I20260812 06:18:15.359380 10580 maintenance_manager.cc:419] P ac381f53065b4cbe98e69ae84ee46847: Scheduling LogGCOp(ffcd899db4b34bb0ae2ed1d1ffe997aa): free 115943200 bytes of WAL
I20260812 06:18:15.359635 10463 log_reader.cc:385] T ffcd899db4b34bb0ae2ed1d1ffe997aa: removed 11 log segments from log reader
I20260812 06:18:15.359685 10463 log.cc:1079] T ffcd899db4b34bb0ae2ed1d1ffe997aa P ac381f53065b4cbe98e69ae84ee46847: Deleting log segment in path: /tmp/dist-test-taskLBU3bg/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515493525939-10296-0/minicluster-data/ts-0-root/wals/ffcd899db4b34bb0ae2ed1d1ffe997aa/wal-000000003 (ops 12-16)
I20260812 06:18:15.359724 10463 log.cc:1079] T ffcd899db4b34bb0ae2ed1d1ffe997aa P ac381f53065b4cbe98e69ae84ee46847: Deleting log segment in path: /tmp/dist-test-taskLBU3bg/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515493525939-10296-0/minicluster-data/ts-0-root/wals/ffcd899db4b34bb0ae2ed1d1ffe997aa/wal-000000004 (ops 17-21)
I20260812 06:18:15.359759 10463 log.cc:1079] T ffcd899db4b34bb0ae2ed1d1ffe997aa P ac381f53065b4cbe98e69ae84ee46847: Deleting log segment in path: /tmp/dist-test-taskLBU3bg/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515493525939-10296-0/minicluster-data/ts-0-root/wals/ffcd899db4b34bb0ae2ed1d1ffe997aa/wal-000000005 (ops 22-26)
I20260812 06:18:15.359787 10463 log.cc:1079] T ffcd899db4b34bb0ae2ed1d1ffe997aa P ac381f53065b4cbe98e69ae84ee46847: Deleting log segment in path: /tmp/dist-test-taskLBU3bg/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515493525939-10296-0/minicluster-data/ts-0-root/wals/ffcd899db4b34bb0ae2ed1d1ffe997aa/wal-000000006 (ops 27-31)
I20260812 06:18:15.359815 10463 log.cc:1079] T ffcd899db4b34bb0ae2ed1d1ffe997aa P ac381f53065b4cbe98e69ae84ee46847: Deleting log segment in path: /tmp/dist-test-taskLBU3bg/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515493525939-10296-0/minicluster-data/ts-0-root/wals/ffcd899db4b34bb0ae2ed1d1ffe997aa/wal-000000007 (ops 32-36)
I20260812 06:18:15.359838 10463 log.cc:1079] T ffcd899db4b34bb0ae2ed1d1ffe997aa P ac381f53065b4cbe98e69ae84ee46847: Deleting log segment in path: /tmp/dist-test-taskLBU3bg/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515493525939-10296-0/minicluster-data/ts-0-root/wals/ffcd899db4b34bb0ae2ed1d1ffe997aa/wal-000000008 (ops 37-41)
I20260812 06:18:15.359870 10463 log.cc:1079] T ffcd899db4b34bb0ae2ed1d1ffe997aa P ac381f53065b4cbe98e69ae84ee46847: Deleting log segment in path: /tmp/dist-test-taskLBU3bg/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515493525939-10296-0/minicluster-data/ts-0-root/wals/ffcd899db4b34bb0ae2ed1d1ffe997aa/wal-000000009 (ops 42-46)
I20260812 06:18:15.359901 10463 log.cc:1079] T ffcd899db4b34bb0ae2ed1d1ffe997aa P ac381f53065b4cbe98e69ae84ee46847: Deleting log segment in path: /tmp/dist-test-taskLBU3bg/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515493525939-10296-0/minicluster-data/ts-0-root/wals/ffcd899db4b34bb0ae2ed1d1ffe997aa/wal-000000010 (ops 47-51)
I20260812 06:18:15.359931 10463 log.cc:1079] T ffcd899db4b34bb0ae2ed1d1ffe997aa P ac381f53065b4cbe98e69ae84ee46847: Deleting log segment in path: /tmp/dist-test-taskLBU3bg/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515493525939-10296-0/minicluster-data/ts-0-root/wals/ffcd899db4b34bb0ae2ed1d1ffe997aa/wal-000000011 (ops 52-56)
I20260812 06:18:15.359958 10463 log.cc:1079] T ffcd899db4b34bb0ae2ed1d1ffe997aa P ac381f53065b4cbe98e69ae84ee46847: Deleting log segment in path: /tmp/dist-test-taskLBU3bg/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515493525939-10296-0/minicluster-data/ts-0-root/wals/ffcd899db4b34bb0ae2ed1d1ffe997aa/wal-000000012 (ops 57-61)
I20260812 06:18:15.359987 10463 log.cc:1079] T ffcd899db4b34bb0ae2ed1d1ffe997aa P ac381f53065b4cbe98e69ae84ee46847: Deleting log segment in path: /tmp/dist-test-taskLBU3bg/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515493525939-10296-0/minicluster-data/ts-0-root/wals/ffcd899db4b34bb0ae2ed1d1ffe997aa/wal-000000013 (ops 62-66)
I20260812 06:18:15.389093 10463 maintenance_manager.cc:643] P ac381f53065b4cbe98e69ae84ee46847: LogGCOp(ffcd899db4b34bb0ae2ed1d1ffe997aa) complete. Timing: real 0.030s	user 0.000s	sys 0.028s Metrics: {}
I20260812 06:18:15.389564 10580 maintenance_manager.cc:419] P ac381f53065b4cbe98e69ae84ee46847: Scheduling UndoDeltaBlockGCOp(ffcd899db4b34bb0ae2ed1d1ffe997aa): 461 bytes on disk
I20260812 06:18:15.390161 10463 maintenance_manager.cc:643] P ac381f53065b4cbe98e69ae84ee46847: UndoDeltaBlockGCOp(ffcd899db4b34bb0ae2ed1d1ffe997aa) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":77,"lbm_reads_lt_1ms":4}
I20260812 06:18:15.390759 10580 maintenance_manager.cc:419] P ac381f53065b4cbe98e69ae84ee46847: Scheduling FlushDeltaMemStoresOp(ffcd899db4b34bb0ae2ed1d1ffe997aa): perf score=2.188937
I20260812 06:18:15.412828 10463 maintenance_manager.cc:643] P ac381f53065b4cbe98e69ae84ee46847: FlushDeltaMemStoresOp(ffcd899db4b34bb0ae2ed1d1ffe997aa) complete. Timing: real 0.022s	user 0.010s	sys 0.003s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":5975,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:15.413246 10580 maintenance_manager.cc:419] P ac381f53065b4cbe98e69ae84ee46847: Scheduling FlushDeltaMemStoresOp(ffcd899db4b34bb0ae2ed1d1ffe997aa): perf score=2.188937
I20260812 06:18:15.423280 10463 maintenance_manager.cc:643] P ac381f53065b4cbe98e69ae84ee46847: FlushDeltaMemStoresOp(ffcd899db4b34bb0ae2ed1d1ffe997aa) complete. Timing: real 0.010s	user 0.010s	sys 0.000s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":3851,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:15.423695 10580 maintenance_manager.cc:419] P ac381f53065b4cbe98e69ae84ee46847: Scheduling MajorDeltaCompactionOp(ffcd899db4b34bb0ae2ed1d1ffe997aa): perf score=1.000000
I20260812 06:18:15.604842 10463 maintenance_manager.cc:643] P ac381f53065b4cbe98e69ae84ee46847: MajorDeltaCompactionOp(ffcd899db4b34bb0ae2ed1d1ffe997aa) complete. Timing: real 0.181s	user 0.110s	sys 0.068s Metrics: {"cfile_cache_miss":634,"cfile_cache_miss_bytes":28877337,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":675,"lbm_read_time_us":13052,"lbm_reads_lt_1ms":674,"lbm_write_time_us":36243,"lbm_writes_lt_1ms":643,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":896,"thread_start_us":76,"threads_started":1,"update_count":3000}
I20260812 06:18:15.605810 10580 maintenance_manager.cc:419] P ac381f53065b4cbe98e69ae84ee46847: Scheduling FlushDeltaMemStoresOp(ffcd899db4b34bb0ae2ed1d1ffe997aa): perf score=14.095187
I20260812 06:18:15.652701 10463 maintenance_manager.cc:643] P ac381f53065b4cbe98e69ae84ee46847: FlushDeltaMemStoresOp(ffcd899db4b34bb0ae2ed1d1ffe997aa) complete. Timing: real 0.047s	user 0.021s	sys 0.019s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":18905,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:18:15.653164 10580 maintenance_manager.cc:419] P ac381f53065b4cbe98e69ae84ee46847: Scheduling FlushDeltaMemStoresOp(ffcd899db4b34bb0ae2ed1d1ffe997aa): perf score=2.188937
I20260812 06:18:15.663796 10463 maintenance_manager.cc:643] P ac381f53065b4cbe98e69ae84ee46847: FlushDeltaMemStoresOp(ffcd899db4b34bb0ae2ed1d1ffe997aa) complete. Timing: real 0.010s	user 0.006s	sys 0.004s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4178,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:15.664207 10580 maintenance_manager.cc:419] P ac381f53065b4cbe98e69ae84ee46847: Scheduling MajorDeltaCompactionOp(ffcd899db4b34bb0ae2ed1d1ffe997aa): perf score=1.000000
I20260812 06:18:15.828953 10463 maintenance_manager.cc:643] P ac381f53065b4cbe98e69ae84ee46847: MajorDeltaCompactionOp(ffcd899db4b34bb0ae2ed1d1ffe997aa) complete. Timing: real 0.165s	user 0.120s	sys 0.034s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774688,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":222,"lbm_read_time_us":10109,"lbm_reads_lt_1ms":572,"lbm_write_time_us":31595,"lbm_writes_lt_1ms":543,"mutex_wait_us":35,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":10368,"update_count":2500}
I20260812 06:18:15.829715 10580 maintenance_manager.cc:419] P ac381f53065b4cbe98e69ae84ee46847: Scheduling FlushDeltaMemStoresOp(ffcd899db4b34bb0ae2ed1d1ffe997aa): perf score=14.095187
I20260812 06:18:15.880345 10463 maintenance_manager.cc:643] P ac381f53065b4cbe98e69ae84ee46847: FlushDeltaMemStoresOp(ffcd899db4b34bb0ae2ed1d1ffe997aa) complete. Timing: real 0.050s	user 0.045s	sys 0.004s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":22835,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:18:15.880844 10580 maintenance_manager.cc:419] P ac381f53065b4cbe98e69ae84ee46847: Scheduling MajorDeltaCompactionOp(ffcd899db4b34bb0ae2ed1d1ffe997aa): perf score=1.000000
I20260812 06:18:16.027869 10463 maintenance_manager.cc:643] P ac381f53065b4cbe98e69ae84ee46847: MajorDeltaCompactionOp(ffcd899db4b34bb0ae2ed1d1ffe997aa) complete. Timing: real 0.147s	user 0.115s	sys 0.032s Metrics: {"cfile_cache_miss":431,"cfile_cache_miss_bytes":20672158,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":1,"delta_iterators_relevant":1,"dirs.queue_time_us":854,"lbm_read_time_us":10921,"lbm_reads_lt_1ms":467,"lbm_write_time_us":26004,"lbm_writes_lt_1ms":443,"mutex_wait_us":100,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":16256,"update_count":2000}
I20260812 06:18:16.028528 10580 maintenance_manager.cc:419] P ac381f53065b4cbe98e69ae84ee46847: Scheduling FlushDeltaMemStoresOp(ffcd899db4b34bb0ae2ed1d1ffe997aa): perf score=10.126437
I20260812 06:18:16.074970 10463 maintenance_manager.cc:643] P ac381f53065b4cbe98e69ae84ee46847: FlushDeltaMemStoresOp(ffcd899db4b34bb0ae2ed1d1ffe997aa) complete. Timing: real 0.046s	user 0.021s	sys 0.020s Metrics: {"bytes_written":12307491,"delete_count":0,"lbm_write_time_us":18830,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:18:16.075486 10580 maintenance_manager.cc:419] P ac381f53065b4cbe98e69ae84ee46847: Scheduling FlushDeltaMemStoresOp(ffcd899db4b34bb0ae2ed1d1ffe997aa): perf score=2.188937
I20260812 06:18:16.099035 10463 maintenance_manager.cc:643] P ac381f53065b4cbe98e69ae84ee46847: FlushDeltaMemStoresOp(ffcd899db4b34bb0ae2ed1d1ffe997aa) complete. Timing: real 0.023s	user 0.014s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6661,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:16.099601 10580 maintenance_manager.cc:419] P ac381f53065b4cbe98e69ae84ee46847: Scheduling FlushDeltaMemStoresOp(ffcd899db4b34bb0ae2ed1d1ffe997aa): perf score=2.188937
I20260812 06:18:16.109988 10463 maintenance_manager.cc:643] P ac381f53065b4cbe98e69ae84ee46847: FlushDeltaMemStoresOp(ffcd899db4b34bb0ae2ed1d1ffe997aa) complete. Timing: real 0.010s	user 0.005s	sys 0.004s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4030,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:16.110503 10580 maintenance_manager.cc:419] P ac381f53065b4cbe98e69ae84ee46847: Scheduling MajorDeltaCompactionOp(ffcd899db4b34bb0ae2ed1d1ffe997aa): perf score=1.000000
I20260812 06:18:16.305788 10463 maintenance_manager.cc:643] P ac381f53065b4cbe98e69ae84ee46847: MajorDeltaCompactionOp(ffcd899db4b34bb0ae2ed1d1ffe997aa) complete. Timing: real 0.195s	user 0.118s	sys 0.064s Metrics: {"cfile_cache_miss":533,"cfile_cache_miss_bytes":24774808,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":561,"lbm_read_time_us":11574,"lbm_reads_lt_1ms":573,"lbm_write_time_us":31714,"lbm_writes_lt_1ms":543,"mutex_wait_us":320,"peak_mem_usage":63115900,"reinsert_count":0,"update_count":2500}
I20260812 06:18:16.306823 10580 maintenance_manager.cc:419] P ac381f53065b4cbe98e69ae84ee46847: Scheduling FlushDeltaMemStoresOp(ffcd899db4b34bb0ae2ed1d1ffe997aa): perf score=14.095187
I20260812 06:18:16.355577 10463 maintenance_manager.cc:643] P ac381f53065b4cbe98e69ae84ee46847: FlushDeltaMemStoresOp(ffcd899db4b34bb0ae2ed1d1ffe997aa) complete. Timing: real 0.048s	user 0.026s	sys 0.015s Metrics: {"bytes_written":16409898,"delete_count":0,"lbm_write_time_us":18768,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:18:16.356186 10580 maintenance_manager.cc:419] P ac381f53065b4cbe98e69ae84ee46847: Scheduling FlushDeltaMemStoresOp(ffcd899db4b34bb0ae2ed1d1ffe997aa): perf score=2.188937
I20260812 06:18:16.368630 10463 maintenance_manager.cc:643] P ac381f53065b4cbe98e69ae84ee46847: FlushDeltaMemStoresOp(ffcd899db4b34bb0ae2ed1d1ffe997aa) complete. Timing: real 0.012s	user 0.001s	sys 0.010s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4478,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:16.369184 10580 maintenance_manager.cc:419] P ac381f53065b4cbe98e69ae84ee46847: Scheduling MajorDeltaCompactionOp(ffcd899db4b34bb0ae2ed1d1ffe997aa): perf score=1.000000
I20260812 06:18:16.525506 10463 maintenance_manager.cc:643] P ac381f53065b4cbe98e69ae84ee46847: MajorDeltaCompactionOp(ffcd899db4b34bb0ae2ed1d1ffe997aa) complete. Timing: real 0.156s	user 0.114s	sys 0.040s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774685,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":1112,"lbm_read_time_us":11115,"lbm_reads_lt_1ms":572,"lbm_write_time_us":32111,"lbm_writes_lt_1ms":543,"mutex_wait_us":321,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":16640,"update_count":2500}
I20260812 06:18:16.526196 10580 maintenance_manager.cc:419] P ac381f53065b4cbe98e69ae84ee46847: Scheduling FlushDeltaMemStoresOp(ffcd899db4b34bb0ae2ed1d1ffe997aa): perf score=10.126437
I20260812 06:18:16.562534 10463 maintenance_manager.cc:643] P ac381f53065b4cbe98e69ae84ee46847: FlushDeltaMemStoresOp(ffcd899db4b34bb0ae2ed1d1ffe997aa) complete. Timing: real 0.036s	user 0.019s	sys 0.011s Metrics: {"bytes_written":12307489,"delete_count":0,"lbm_write_time_us":14710,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:18:16.563112 10580 maintenance_manager.cc:419] P ac381f53065b4cbe98e69ae84ee46847: Scheduling FlushDeltaMemStoresOp(ffcd899db4b34bb0ae2ed1d1ffe997aa): perf score=2.188937
I20260812 06:18:16.578128 10463 maintenance_manager.cc:643] P ac381f53065b4cbe98e69ae84ee46847: FlushDeltaMemStoresOp(ffcd899db4b34bb0ae2ed1d1ffe997aa) complete. Timing: real 0.015s	user 0.007s	sys 0.005s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4950,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:16.578878 10580 maintenance_manager.cc:419] P ac381f53065b4cbe98e69ae84ee46847: Scheduling MajorDeltaCompactionOp(ffcd899db4b34bb0ae2ed1d1ffe997aa): perf score=1.000000
I20260812 06:18:16.715243 10463 maintenance_manager.cc:643] P ac381f53065b4cbe98e69ae84ee46847: MajorDeltaCompactionOp(ffcd899db4b34bb0ae2ed1d1ffe997aa) complete. Timing: real 0.136s	user 0.102s	sys 0.032s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672276,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":1433,"lbm_read_time_us":10468,"lbm_reads_lt_1ms":472,"lbm_write_time_us":25485,"lbm_writes_lt_1ms":443,"mutex_wait_us":317,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":3456,"update_count":2000}
I20260812 06:18:16.715893 10580 maintenance_manager.cc:419] P ac381f53065b4cbe98e69ae84ee46847: Scheduling FlushDeltaMemStoresOp(ffcd899db4b34bb0ae2ed1d1ffe997aa): perf score=10.126437
I20260812 06:18:16.762133 10463 maintenance_manager.cc:643] P ac381f53065b4cbe98e69ae84ee46847: FlushDeltaMemStoresOp(ffcd899db4b34bb0ae2ed1d1ffe997aa) complete. Timing: real 0.046s	user 0.018s	sys 0.020s Metrics: {"bytes_written":12307492,"delete_count":0,"lbm_write_time_us":18485,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":302,"reinsert_count":0,"update_count":1500}
I20260812 06:18:16.762866 10580 maintenance_manager.cc:419] P ac381f53065b4cbe98e69ae84ee46847: Scheduling FlushDeltaMemStoresOp(ffcd899db4b34bb0ae2ed1d1ffe997aa): perf score=2.188937
I20260812 06:18:16.778100 10463 maintenance_manager.cc:643] P ac381f53065b4cbe98e69ae84ee46847: FlushDeltaMemStoresOp(ffcd899db4b34bb0ae2ed1d1ffe997aa) complete. Timing: real 0.015s	user 0.009s	sys 0.003s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5550,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:16.778712 10580 maintenance_manager.cc:419] P ac381f53065b4cbe98e69ae84ee46847: Scheduling FlushMRSOp(ffcd899db4b34bb0ae2ed1d1ffe997aa): perf score=1.000000
I20260812 06:18:16.812909 10463 maintenance_manager.cc:643] P ac381f53065b4cbe98e69ae84ee46847: FlushMRSOp(ffcd899db4b34bb0ae2ed1d1ffe997aa) complete. Timing: real 0.034s	user 0.031s	sys 0.000s Metrics: {"bytes_written":1193509,"cfile_init":1,"dirs.queue_time_us":70,"dirs.run_cpu_time_us":305,"dirs.run_wall_time_us":1336,"drs_written":1,"lbm_read_time_us":103,"lbm_reads_lt_1ms":4,"lbm_write_time_us":2096,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":29}
I20260812 06:18:16.813812 10580 maintenance_manager.cc:419] P ac381f53065b4cbe98e69ae84ee46847: Scheduling LogGCOp(ffcd899db4b34bb0ae2ed1d1ffe997aa): free 120553382 bytes of WAL
I20260812 06:18:16.814086 10463 log_reader.cc:385] T ffcd899db4b34bb0ae2ed1d1ffe997aa: removed 12 log segments from log reader
I20260812 06:18:16.814162 10463 log.cc:1079] T ffcd899db4b34bb0ae2ed1d1ffe997aa P ac381f53065b4cbe98e69ae84ee46847: Deleting log segment in path: /tmp/dist-test-taskLBU3bg/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515493525939-10296-0/minicluster-data/ts-0-root/wals/ffcd899db4b34bb0ae2ed1d1ffe997aa/wal-000000014 (ops 67-71)
I20260812 06:18:16.814213 10463 log.cc:1079] T ffcd899db4b34bb0ae2ed1d1ffe997aa P ac381f53065b4cbe98e69ae84ee46847: Deleting log segment in path: /tmp/dist-test-taskLBU3bg/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515493525939-10296-0/minicluster-data/ts-0-root/wals/ffcd899db4b34bb0ae2ed1d1ffe997aa/wal-000000015 (ops 72-76)
I20260812 06:18:16.814280 10463 log.cc:1079] T ffcd899db4b34bb0ae2ed1d1ffe997aa P ac381f53065b4cbe98e69ae84ee46847: Deleting log segment in path: /tmp/dist-test-taskLBU3bg/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515493525939-10296-0/minicluster-data/ts-0-root/wals/ffcd899db4b34bb0ae2ed1d1ffe997aa/wal-000000016 (ops 77-81)
I20260812 06:18:16.814325 10463 log.cc:1079] T ffcd899db4b34bb0ae2ed1d1ffe997aa P ac381f53065b4cbe98e69ae84ee46847: Deleting log segment in path: /tmp/dist-test-taskLBU3bg/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515493525939-10296-0/minicluster-data/ts-0-root/wals/ffcd899db4b34bb0ae2ed1d1ffe997aa/wal-000000017 (ops 82-86)
I20260812 06:18:16.814366 10463 log.cc:1079] T ffcd899db4b34bb0ae2ed1d1ffe997aa P ac381f53065b4cbe98e69ae84ee46847: Deleting log segment in path: /tmp/dist-test-taskLBU3bg/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515493525939-10296-0/minicluster-data/ts-0-root/wals/ffcd899db4b34bb0ae2ed1d1ffe997aa/wal-000000018 (ops 87-90)
I20260812 06:18:16.814402 10463 log.cc:1079] T ffcd899db4b34bb0ae2ed1d1ffe997aa P ac381f53065b4cbe98e69ae84ee46847: Deleting log segment in path: /tmp/dist-test-taskLBU3bg/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515493525939-10296-0/minicluster-data/ts-0-root/wals/ffcd899db4b34bb0ae2ed1d1ffe997aa/wal-000000019 (ops 91-95)
I20260812 06:18:16.814435 10463 log.cc:1079] T ffcd899db4b34bb0ae2ed1d1ffe997aa P ac381f53065b4cbe98e69ae84ee46847: Deleting log segment in path: /tmp/dist-test-taskLBU3bg/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515493525939-10296-0/minicluster-data/ts-0-root/wals/ffcd899db4b34bb0ae2ed1d1ffe997aa/wal-000000020 (ops 96-100)
I20260812 06:18:16.814474 10463 log.cc:1079] T ffcd899db4b34bb0ae2ed1d1ffe997aa P ac381f53065b4cbe98e69ae84ee46847: Deleting log segment in path: /tmp/dist-test-taskLBU3bg/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515493525939-10296-0/minicluster-data/ts-0-root/wals/ffcd899db4b34bb0ae2ed1d1ffe997aa/wal-000000021 (ops 101-105)
I20260812 06:18:16.814514 10463 log.cc:1079] T ffcd899db4b34bb0ae2ed1d1ffe997aa P ac381f53065b4cbe98e69ae84ee46847: Deleting log segment in path: /tmp/dist-test-taskLBU3bg/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515493525939-10296-0/minicluster-data/ts-0-root/wals/ffcd899db4b34bb0ae2ed1d1ffe997aa/wal-000000022 (ops 106-110)
I20260812 06:18:16.814554 10463 log.cc:1079] T ffcd899db4b34bb0ae2ed1d1ffe997aa P ac381f53065b4cbe98e69ae84ee46847: Deleting log segment in path: /tmp/dist-test-taskLBU3bg/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515493525939-10296-0/minicluster-data/ts-0-root/wals/ffcd899db4b34bb0ae2ed1d1ffe997aa/wal-000000023 (ops 111-115)
I20260812 06:18:16.814599 10463 log.cc:1079] T ffcd899db4b34bb0ae2ed1d1ffe997aa P ac381f53065b4cbe98e69ae84ee46847: Deleting log segment in path: /tmp/dist-test-taskLBU3bg/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515493525939-10296-0/minicluster-data/ts-0-root/wals/ffcd899db4b34bb0ae2ed1d1ffe997aa/wal-000000024 (ops 116-120)
I20260812 06:18:16.814637 10463 log.cc:1079] T ffcd899db4b34bb0ae2ed1d1ffe997aa P ac381f53065b4cbe98e69ae84ee46847: Deleting log segment in path: /tmp/dist-test-taskLBU3bg/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515493525939-10296-0/minicluster-data/ts-0-root/wals/ffcd899db4b34bb0ae2ed1d1ffe997aa/wal-000000025 (ops 121-124)
I20260812 06:18:16.840696 10463 maintenance_manager.cc:643] P ac381f53065b4cbe98e69ae84ee46847: LogGCOp(ffcd899db4b34bb0ae2ed1d1ffe997aa) complete. Timing: real 0.027s	user 0.000s	sys 0.025s Metrics: {}
I20260812 06:18:16.841326 10580 maintenance_manager.cc:419] P ac381f53065b4cbe98e69ae84ee46847: Scheduling FlushDeltaMemStoresOp(ffcd899db4b34bb0ae2ed1d1ffe997aa): perf score=2.188937
I20260812 06:18:16.856537 10463 maintenance_manager.cc:643] P ac381f53065b4cbe98e69ae84ee46847: FlushDeltaMemStoresOp(ffcd899db4b34bb0ae2ed1d1ffe997aa) complete. Timing: real 0.015s	user 0.001s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4423,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:16.857038 10580 maintenance_manager.cc:419] P ac381f53065b4cbe98e69ae84ee46847: Scheduling UndoDeltaBlockGCOp(ffcd899db4b34bb0ae2ed1d1ffe997aa): 463 bytes on disk
I20260812 06:18:16.857434 10463 maintenance_manager.cc:643] P ac381f53065b4cbe98e69ae84ee46847: UndoDeltaBlockGCOp(ffcd899db4b34bb0ae2ed1d1ffe997aa) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":52,"lbm_reads_lt_1ms":4}
I20260812 06:18:16.857909 10580 maintenance_manager.cc:419] P ac381f53065b4cbe98e69ae84ee46847: Scheduling FlushDeltaMemStoresOp(ffcd899db4b34bb0ae2ed1d1ffe997aa): perf score=2.188937
I20260812 06:18:16.868562 10463 maintenance_manager.cc:643] P ac381f53065b4cbe98e69ae84ee46847: FlushDeltaMemStoresOp(ffcd899db4b34bb0ae2ed1d1ffe997aa) complete. Timing: real 0.010s	user 0.005s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4059,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:16.869387 10580 maintenance_manager.cc:419] P ac381f53065b4cbe98e69ae84ee46847: Scheduling MajorDeltaCompactionOp(ffcd899db4b34bb0ae2ed1d1ffe997aa): perf score=1.000000
I20260812 06:18:17.039309 10463 maintenance_manager.cc:643] P ac381f53065b4cbe98e69ae84ee46847: MajorDeltaCompactionOp(ffcd899db4b34bb0ae2ed1d1ffe997aa) complete. Timing: real 0.170s	user 0.112s	sys 0.058s Metrics: {"cfile_cache_miss":634,"cfile_cache_miss_bytes":28877341,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":656,"lbm_read_time_us":13328,"lbm_reads_lt_1ms":674,"lbm_write_time_us":33726,"lbm_writes_lt_1ms":643,"mutex_wait_us":2,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":3712,"thread_start_us":80,"threads_started":1,"update_count":3000}
I20260812 06:18:17.040060 10580 maintenance_manager.cc:419] P ac381f53065b4cbe98e69ae84ee46847: Scheduling FlushDeltaMemStoresOp(ffcd899db4b34bb0ae2ed1d1ffe997aa): perf score=14.095187
I20260812 06:18:17.084445 10463 maintenance_manager.cc:643] P ac381f53065b4cbe98e69ae84ee46847: FlushDeltaMemStoresOp(ffcd899db4b34bb0ae2ed1d1ffe997aa) complete. Timing: real 0.044s	user 0.022s	sys 0.021s Metrics: {"bytes_written":16409900,"delete_count":0,"lbm_write_time_us":19617,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:18:17.084932 10580 maintenance_manager.cc:419] P ac381f53065b4cbe98e69ae84ee46847: Scheduling FlushDeltaMemStoresOp(ffcd899db4b34bb0ae2ed1d1ffe997aa): perf score=2.188937
I20260812 06:18:17.096525 10463 maintenance_manager.cc:643] P ac381f53065b4cbe98e69ae84ee46847: FlushDeltaMemStoresOp(ffcd899db4b34bb0ae2ed1d1ffe997aa) complete. Timing: real 0.011s	user 0.001s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4262,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:17.097189 10580 maintenance_manager.cc:419] P ac381f53065b4cbe98e69ae84ee46847: Scheduling MajorDeltaCompactionOp(ffcd899db4b34bb0ae2ed1d1ffe997aa): perf score=1.000000
I20260812 06:18:17.254910 10463 maintenance_manager.cc:643] P ac381f53065b4cbe98e69ae84ee46847: MajorDeltaCompactionOp(ffcd899db4b34bb0ae2ed1d1ffe997aa) complete. Timing: real 0.157s	user 0.109s	sys 0.044s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774687,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":593,"lbm_read_time_us":9788,"lbm_reads_lt_1ms":572,"lbm_write_time_us":29783,"lbm_writes_lt_1ms":543,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":1152,"update_count":2500}
I20260812 06:18:17.255527 10580 maintenance_manager.cc:419] P ac381f53065b4cbe98e69ae84ee46847: Scheduling FlushDeltaMemStoresOp(ffcd899db4b34bb0ae2ed1d1ffe997aa): perf score=12.110812
I20260812 06:18:17.299973 10463 maintenance_manager.cc:643] P ac381f53065b4cbe98e69ae84ee46847: FlushDeltaMemStoresOp(ffcd899db4b34bb0ae2ed1d1ffe997aa) complete. Timing: real 0.044s	user 0.037s	sys 0.007s Metrics: {"bytes_written":13702314,"delete_count":0,"lbm_write_time_us":19378,"lbm_writes_lt_1ms":337,"reinsert_count":0,"update_count":1670}
I20260812 06:18:17.300726 10580 maintenance_manager.cc:419] P ac381f53065b4cbe98e69ae84ee46847: Scheduling FlushDeltaMemStoresOp(ffcd899db4b34bb0ae2ed1d1ffe997aa): perf score=1.196750
I20260812 06:18:17.314548 10463 maintenance_manager.cc:643] P ac381f53065b4cbe98e69ae84ee46847: FlushDeltaMemStoresOp(ffcd899db4b34bb0ae2ed1d1ffe997aa) complete. Timing: real 0.014s	user 0.010s	sys 0.001s Metrics: {"bytes_written":3118059,"delete_count":0,"lbm_write_time_us":4123,"lbm_writes_lt_1ms":79,"reinsert_count":0,"update_count":380}
I20260812 06:18:17.314985 10580 maintenance_manager.cc:419] P ac381f53065b4cbe98e69ae84ee46847: Scheduling MajorDeltaCompactionOp(ffcd899db4b34bb0ae2ed1d1ffe997aa): perf score=1.000000
I20260812 06:18:17.469516 10463 maintenance_manager.cc:643] P ac381f53065b4cbe98e69ae84ee46847: MajorDeltaCompactionOp(ffcd899db4b34bb0ae2ed1d1ffe997aa) complete. Timing: real 0.154s	user 0.109s	sys 0.037s Metrics: {"cfile_cache_miss":442,"cfile_cache_miss_bytes":21082501,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":891,"lbm_read_time_us":9585,"lbm_reads_lt_1ms":474,"lbm_write_time_us":26244,"lbm_writes_lt_1ms":453,"mutex_wait_us":303,"peak_mem_usage":51099678,"reinsert_count":0,"spinlock_wait_cycles":5888,"update_count":2050}
I20260812 06:18:17.470082 10580 maintenance_manager.cc:419] P ac381f53065b4cbe98e69ae84ee46847: Scheduling FlushDeltaMemStoresOp(ffcd899db4b34bb0ae2ed1d1ffe997aa): perf score=14.095187
I20260812 06:18:17.522596 10463 maintenance_manager.cc:643] P ac381f53065b4cbe98e69ae84ee46847: FlushDeltaMemStoresOp(ffcd899db4b34bb0ae2ed1d1ffe997aa) complete. Timing: real 0.052s	user 0.023s	sys 0.019s Metrics: {"bytes_written":15999661,"delete_count":0,"lbm_write_time_us":20986,"lbm_writes_lt_1ms":393,"reinsert_count":0,"update_count":1950}
I20260812 06:18:17.523145 10580 maintenance_manager.cc:419] P ac381f53065b4cbe98e69ae84ee46847: Scheduling FlushDeltaMemStoresOp(ffcd899db4b34bb0ae2ed1d1ffe997aa): perf score=2.188937
I20260812 06:18:17.542299 10463 maintenance_manager.cc:643] P ac381f53065b4cbe98e69ae84ee46847: FlushDeltaMemStoresOp(ffcd899db4b34bb0ae2ed1d1ffe997aa) complete. Timing: real 0.019s	user 0.008s	sys 0.007s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4080,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:17.542894 10580 maintenance_manager.cc:419] P ac381f53065b4cbe98e69ae84ee46847: Scheduling MajorDeltaCompactionOp(ffcd899db4b34bb0ae2ed1d1ffe997aa): perf score=1.000000
I20260812 06:18:17.721916 10463 maintenance_manager.cc:643] P ac381f53065b4cbe98e69ae84ee46847: MajorDeltaCompactionOp(ffcd899db4b34bb0ae2ed1d1ffe997aa) complete. Timing: real 0.179s	user 0.115s	sys 0.056s Metrics: {"cfile_cache_miss":522,"cfile_cache_miss_bytes":24364447,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":986,"lbm_read_time_us":12074,"lbm_reads_lt_1ms":562,"lbm_write_time_us":30422,"lbm_writes_lt_1ms":533,"mutex_wait_us":281,"peak_mem_usage":61665166,"reinsert_count":0,"spinlock_wait_cycles":9216,"update_count":2450}
I20260812 06:18:17.722877 10580 maintenance_manager.cc:419] P ac381f53065b4cbe98e69ae84ee46847: Scheduling FlushDeltaMemStoresOp(ffcd899db4b34bb0ae2ed1d1ffe997aa): perf score=14.095187
I20260812 06:18:17.767681 10463 maintenance_manager.cc:643] P ac381f53065b4cbe98e69ae84ee46847: FlushDeltaMemStoresOp(ffcd899db4b34bb0ae2ed1d1ffe997aa) complete. Timing: real 0.045s	user 0.031s	sys 0.012s Metrics: {"bytes_written":16409903,"delete_count":0,"lbm_write_time_us":18437,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:18:17.768282 10580 maintenance_manager.cc:419] P ac381f53065b4cbe98e69ae84ee46847: Scheduling FlushDeltaMemStoresOp(ffcd899db4b34bb0ae2ed1d1ffe997aa): perf score=2.188937
I20260812 06:18:17.783923 10463 maintenance_manager.cc:643] P ac381f53065b4cbe98e69ae84ee46847: FlushDeltaMemStoresOp(ffcd899db4b34bb0ae2ed1d1ffe997aa) complete. Timing: real 0.015s	user 0.014s	sys 0.000s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":5909,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:17.784516 10580 maintenance_manager.cc:419] P ac381f53065b4cbe98e69ae84ee46847: Scheduling MajorDeltaCompactionOp(ffcd899db4b34bb0ae2ed1d1ffe997aa): perf score=1.000000
I20260812 06:18:17.975309 10463 maintenance_manager.cc:643] P ac381f53065b4cbe98e69ae84ee46847: MajorDeltaCompactionOp(ffcd899db4b34bb0ae2ed1d1ffe997aa) complete. Timing: real 0.191s	user 0.136s	sys 0.041s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774689,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":901,"lbm_read_time_us":9627,"lbm_reads_lt_1ms":572,"lbm_write_time_us":32968,"lbm_writes_lt_1ms":543,"mutex_wait_us":313,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":3200,"update_count":2500}
I20260812 06:18:17.975875 10580 maintenance_manager.cc:419] P ac381f53065b4cbe98e69ae84ee46847: Scheduling FlushDeltaMemStoresOp(ffcd899db4b34bb0ae2ed1d1ffe997aa): perf score=14.095187
I20260812 06:18:18.027659 10463 maintenance_manager.cc:643] P ac381f53065b4cbe98e69ae84ee46847: FlushDeltaMemStoresOp(ffcd899db4b34bb0ae2ed1d1ffe997aa) complete. Timing: real 0.052s	user 0.027s	sys 0.012s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":17466,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:18:18.028208 10580 maintenance_manager.cc:419] P ac381f53065b4cbe98e69ae84ee46847: Scheduling FlushDeltaMemStoresOp(ffcd899db4b34bb0ae2ed1d1ffe997aa): perf score=2.188937
I20260812 06:18:18.040241 10463 maintenance_manager.cc:643] P ac381f53065b4cbe98e69ae84ee46847: FlushDeltaMemStoresOp(ffcd899db4b34bb0ae2ed1d1ffe997aa) complete. Timing: real 0.012s	user 0.006s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4319,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:18.040745 10580 maintenance_manager.cc:419] P ac381f53065b4cbe98e69ae84ee46847: Scheduling MajorDeltaCompactionOp(ffcd899db4b34bb0ae2ed1d1ffe997aa): perf score=1.000000
I20260812 06:18:18.190735 10463 maintenance_manager.cc:643] P ac381f53065b4cbe98e69ae84ee46847: MajorDeltaCompactionOp(ffcd899db4b34bb0ae2ed1d1ffe997aa) complete. Timing: real 0.150s	user 0.121s	sys 0.028s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774688,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":93,"lbm_read_time_us":10278,"lbm_reads_lt_1ms":572,"lbm_write_time_us":30598,"lbm_writes_lt_1ms":543,"mutex_wait_us":24,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":10496,"update_count":2500}
I20260812 06:18:18.191742 10580 maintenance_manager.cc:419] P ac381f53065b4cbe98e69ae84ee46847: Scheduling FlushDeltaMemStoresOp(ffcd899db4b34bb0ae2ed1d1ffe997aa): perf score=10.126437
I20260812 06:18:18.222440 10463 maintenance_manager.cc:643] P ac381f53065b4cbe98e69ae84ee46847: FlushDeltaMemStoresOp(ffcd899db4b34bb0ae2ed1d1ffe997aa) complete. Timing: real 0.030s	user 0.013s	sys 0.015s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":13450,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:18:18.222954 10580 maintenance_manager.cc:419] P ac381f53065b4cbe98e69ae84ee46847: Scheduling FlushDeltaMemStoresOp(ffcd899db4b34bb0ae2ed1d1ffe997aa): perf score=2.188937
I20260812 06:18:18.237876 10463 maintenance_manager.cc:643] P ac381f53065b4cbe98e69ae84ee46847: FlushDeltaMemStoresOp(ffcd899db4b34bb0ae2ed1d1ffe997aa) complete. Timing: real 0.015s	user 0.013s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5762,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:18.238377 10580 maintenance_manager.cc:419] P ac381f53065b4cbe98e69ae84ee46847: Scheduling FlushMRSOp(ffcd899db4b34bb0ae2ed1d1ffe997aa): perf score=1.000000
I20260812 06:18:18.266567 10463 maintenance_manager.cc:643] P ac381f53065b4cbe98e69ae84ee46847: FlushMRSOp(ffcd899db4b34bb0ae2ed1d1ffe997aa) complete. Timing: real 0.028s	user 0.023s	sys 0.003s Metrics: {"bytes_written":1275447,"cfile_init":1,"dirs.queue_time_us":79,"dirs.run_cpu_time_us":153,"dirs.run_wall_time_us":1390,"drs_written":1,"lbm_read_time_us":58,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1981,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":31}
I20260812 06:18:18.267380 10580 maintenance_manager.cc:419] P ac381f53065b4cbe98e69ae84ee46847: Scheduling LogGCOp(ffcd899db4b34bb0ae2ed1d1ffe997aa): free 121006629 bytes of WAL
I20260812 06:18:18.267659 10463 log_reader.cc:385] T ffcd899db4b34bb0ae2ed1d1ffe997aa: removed 12 log segments from log reader
I20260812 06:18:18.267727 10463 log.cc:1079] T ffcd899db4b34bb0ae2ed1d1ffe997aa P ac381f53065b4cbe98e69ae84ee46847: Deleting log segment in path: /tmp/dist-test-taskLBU3bg/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515493525939-10296-0/minicluster-data/ts-0-root/wals/ffcd899db4b34bb0ae2ed1d1ffe997aa/wal-000000026 (ops 125-129)
I20260812 06:18:18.267767 10463 log.cc:1079] T ffcd899db4b34bb0ae2ed1d1ffe997aa P ac381f53065b4cbe98e69ae84ee46847: Deleting log segment in path: /tmp/dist-test-taskLBU3bg/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515493525939-10296-0/minicluster-data/ts-0-root/wals/ffcd899db4b34bb0ae2ed1d1ffe997aa/wal-000000027 (ops 130-134)
I20260812 06:18:18.267791 10463 log.cc:1079] T ffcd899db4b34bb0ae2ed1d1ffe997aa P ac381f53065b4cbe98e69ae84ee46847: Deleting log segment in path: /tmp/dist-test-taskLBU3bg/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515493525939-10296-0/minicluster-data/ts-0-root/wals/ffcd899db4b34bb0ae2ed1d1ffe997aa/wal-000000028 (ops 135-139)
I20260812 06:18:18.267813 10463 log.cc:1079] T ffcd899db4b34bb0ae2ed1d1ffe997aa P ac381f53065b4cbe98e69ae84ee46847: Deleting log segment in path: /tmp/dist-test-taskLBU3bg/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515493525939-10296-0/minicluster-data/ts-0-root/wals/ffcd899db4b34bb0ae2ed1d1ffe997aa/wal-000000029 (ops 140-144)
I20260812 06:18:18.267839 10463 log.cc:1079] T ffcd899db4b34bb0ae2ed1d1ffe997aa P ac381f53065b4cbe98e69ae84ee46847: Deleting log segment in path: /tmp/dist-test-taskLBU3bg/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515493525939-10296-0/minicluster-data/ts-0-root/wals/ffcd899db4b34bb0ae2ed1d1ffe997aa/wal-000000030 (ops 145-148)
I20260812 06:18:18.267874 10463 log.cc:1079] T ffcd899db4b34bb0ae2ed1d1ffe997aa P ac381f53065b4cbe98e69ae84ee46847: Deleting log segment in path: /tmp/dist-test-taskLBU3bg/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515493525939-10296-0/minicluster-data/ts-0-root/wals/ffcd899db4b34bb0ae2ed1d1ffe997aa/wal-000000031 (ops 149-153)
I20260812 06:18:18.267906 10463 log.cc:1079] T ffcd899db4b34bb0ae2ed1d1ffe997aa P ac381f53065b4cbe98e69ae84ee46847: Deleting log segment in path: /tmp/dist-test-taskLBU3bg/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515493525939-10296-0/minicluster-data/ts-0-root/wals/ffcd899db4b34bb0ae2ed1d1ffe997aa/wal-000000032 (ops 154-158)
I20260812 06:18:18.267935 10463 log.cc:1079] T ffcd899db4b34bb0ae2ed1d1ffe997aa P ac381f53065b4cbe98e69ae84ee46847: Deleting log segment in path: /tmp/dist-test-taskLBU3bg/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515493525939-10296-0/minicluster-data/ts-0-root/wals/ffcd899db4b34bb0ae2ed1d1ffe997aa/wal-000000033 (ops 159-163)
I20260812 06:18:18.267963 10463 log.cc:1079] T ffcd899db4b34bb0ae2ed1d1ffe997aa P ac381f53065b4cbe98e69ae84ee46847: Deleting log segment in path: /tmp/dist-test-taskLBU3bg/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515493525939-10296-0/minicluster-data/ts-0-root/wals/ffcd899db4b34bb0ae2ed1d1ffe997aa/wal-000000034 (ops 164-168)
I20260812 06:18:18.267995 10463 log.cc:1079] T ffcd899db4b34bb0ae2ed1d1ffe997aa P ac381f53065b4cbe98e69ae84ee46847: Deleting log segment in path: /tmp/dist-test-taskLBU3bg/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515493525939-10296-0/minicluster-data/ts-0-root/wals/ffcd899db4b34bb0ae2ed1d1ffe997aa/wal-000000035 (ops 169-173)
I20260812 06:18:18.268030 10463 log.cc:1079] T ffcd899db4b34bb0ae2ed1d1ffe997aa P ac381f53065b4cbe98e69ae84ee46847: Deleting log segment in path: /tmp/dist-test-taskLBU3bg/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515493525939-10296-0/minicluster-data/ts-0-root/wals/ffcd899db4b34bb0ae2ed1d1ffe997aa/wal-000000036 (ops 174-178)
I20260812 06:18:18.268069 10463 log.cc:1079] T ffcd899db4b34bb0ae2ed1d1ffe997aa P ac381f53065b4cbe98e69ae84ee46847: Deleting log segment in path: /tmp/dist-test-taskLBU3bg/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515493525939-10296-0/minicluster-data/ts-0-root/wals/ffcd899db4b34bb0ae2ed1d1ffe997aa/wal-000000037 (ops 179-183)
I20260812 06:18:18.296689 10463 maintenance_manager.cc:643] P ac381f53065b4cbe98e69ae84ee46847: LogGCOp(ffcd899db4b34bb0ae2ed1d1ffe997aa) complete. Timing: real 0.029s	user 0.000s	sys 0.028s Metrics: {}
I20260812 06:18:18.297256 10580 maintenance_manager.cc:419] P ac381f53065b4cbe98e69ae84ee46847: Scheduling FlushDeltaMemStoresOp(ffcd899db4b34bb0ae2ed1d1ffe997aa): perf score=3.181125
I20260812 06:18:18.310001 10463 maintenance_manager.cc:643] P ac381f53065b4cbe98e69ae84ee46847: FlushDeltaMemStoresOp(ffcd899db4b34bb0ae2ed1d1ffe997aa) complete. Timing: real 0.013s	user 0.007s	sys 0.004s Metrics: {"bytes_written":4841095,"delete_count":0,"lbm_write_time_us":5125,"lbm_writes_lt_1ms":121,"reinsert_count":0,"update_count":590}
I20260812 06:18:18.310452 10580 maintenance_manager.cc:419] P ac381f53065b4cbe98e69ae84ee46847: Scheduling LogGCOp(ffcd899db4b34bb0ae2ed1d1ffe997aa): free 8767195 bytes of WAL
I20260812 06:18:18.310668 10463 log_reader.cc:385] T ffcd899db4b34bb0ae2ed1d1ffe997aa: removed 1 log segments from log reader
I20260812 06:18:18.310712 10463 log.cc:1079] T ffcd899db4b34bb0ae2ed1d1ffe997aa P ac381f53065b4cbe98e69ae84ee46847: Deleting log segment in path: /tmp/dist-test-taskLBU3bg/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515493525939-10296-0/minicluster-data/ts-0-root/wals/ffcd899db4b34bb0ae2ed1d1ffe997aa/wal-000000038 (ops 184-188)
I20260812 06:18:18.312368 10463 maintenance_manager.cc:643] P ac381f53065b4cbe98e69ae84ee46847: LogGCOp(ffcd899db4b34bb0ae2ed1d1ffe997aa) complete. Timing: real 0.002s	user 0.000s	sys 0.000s Metrics: {}
I20260812 06:18:18.312722 10580 maintenance_manager.cc:419] P ac381f53065b4cbe98e69ae84ee46847: Scheduling FlushDeltaMemStoresOp(ffcd899db4b34bb0ae2ed1d1ffe997aa): perf score=2.188937
I20260812 06:18:18.325111 10463 maintenance_manager.cc:643] P ac381f53065b4cbe98e69ae84ee46847: FlushDeltaMemStoresOp(ffcd899db4b34bb0ae2ed1d1ffe997aa) complete. Timing: real 0.012s	user 0.004s	sys 0.006s Metrics: {"bytes_written":3364205,"delete_count":0,"lbm_write_time_us":4501,"lbm_writes_lt_1ms":85,"reinsert_count":0,"update_count":410}
I20260812 06:18:18.325613 10580 maintenance_manager.cc:419] P ac381f53065b4cbe98e69ae84ee46847: Scheduling UndoDeltaBlockGCOp(ffcd899db4b34bb0ae2ed1d1ffe997aa): 482 bytes on disk
I20260812 06:18:18.326097 10463 maintenance_manager.cc:643] P ac381f53065b4cbe98e69ae84ee46847: UndoDeltaBlockGCOp(ffcd899db4b34bb0ae2ed1d1ffe997aa) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":55,"lbm_reads_lt_1ms":4}
I20260812 06:18:18.326637 10580 maintenance_manager.cc:419] P ac381f53065b4cbe98e69ae84ee46847: Scheduling MajorDeltaCompactionOp(ffcd899db4b34bb0ae2ed1d1ffe997aa): perf score=1.000000
I20260812 06:18:18.499441 10463 maintenance_manager.cc:643] P ac381f53065b4cbe98e69ae84ee46847: MajorDeltaCompactionOp(ffcd899db4b34bb0ae2ed1d1ffe997aa) complete. Timing: real 0.173s	user 0.128s	sys 0.043s Metrics: {"cfile_cache_miss":634,"cfile_cache_miss_bytes":28877321,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":1143,"lbm_read_time_us":11738,"lbm_reads_lt_1ms":674,"lbm_write_time_us":33717,"lbm_writes_lt_1ms":643,"mutex_wait_us":663,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":13824,"thread_start_us":80,"threads_started":1,"update_count":3000}
I20260812 06:18:18.500101 10580 maintenance_manager.cc:419] P ac381f53065b4cbe98e69ae84ee46847: Scheduling FlushDeltaMemStoresOp(ffcd899db4b34bb0ae2ed1d1ffe997aa): perf score=14.095187
I20260812 06:18:18.551142 10463 maintenance_manager.cc:643] P ac381f53065b4cbe98e69ae84ee46847: FlushDeltaMemStoresOp(ffcd899db4b34bb0ae2ed1d1ffe997aa) complete. Timing: real 0.051s	user 0.030s	sys 0.021s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":22561,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:18:18.551720 10580 maintenance_manager.cc:419] P ac381f53065b4cbe98e69ae84ee46847: Scheduling FlushDeltaMemStoresOp(ffcd899db4b34bb0ae2ed1d1ffe997aa): perf score=2.188937
I20260812 06:18:18.569211 10463 maintenance_manager.cc:643] P ac381f53065b4cbe98e69ae84ee46847: FlushDeltaMemStoresOp(ffcd899db4b34bb0ae2ed1d1ffe997aa) complete. Timing: real 0.017s	user 0.011s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6848,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:18.569747 10580 maintenance_manager.cc:419] P ac381f53065b4cbe98e69ae84ee46847: Scheduling MajorDeltaCompactionOp(ffcd899db4b34bb0ae2ed1d1ffe997aa): perf score=1.000000
I20260812 06:18:18.591779 10296 heavy-update-compaction-itest.cc:229] Time spent updating: real 4.796s	user 1.848s	sys 0.105s
I20260812 06:18:18.686120 10296 heavy-update-compaction-itest.cc:265] Time spent scanning: real 0.094s	user 0.002s	sys 0.000s
I20260812 06:18:18.686833 10296 tablet_server.cc:179] TabletServer@127.10.14.1:0 shutting down...
I20260812 06:18:18.735466 10463 maintenance_manager.cc:643] P ac381f53065b4cbe98e69ae84ee46847: MajorDeltaCompactionOp(ffcd899db4b34bb0ae2ed1d1ffe997aa) complete. Timing: real 0.166s	user 0.103s	sys 0.055s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774688,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":2876,"lbm_read_time_us":11140,"lbm_reads_lt_1ms":568,"lbm_write_time_us":25795,"lbm_writes_lt_1ms":543,"mutex_wait_us":44,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":8576,"update_count":2500}
I20260812 06:18:18.736320 10296 ts_tablet_manager.cc:1507] Shutting down tablet manager...
I20260812 06:18:18.736754 10296 tablet_replica.cc:333] T ffcd899db4b34bb0ae2ed1d1ffe997aa P ac381f53065b4cbe98e69ae84ee46847: stopping tablet replica
I20260812 06:18:18.737023 10296 raft_consensus.cc:2243] T ffcd899db4b34bb0ae2ed1d1ffe997aa P ac381f53065b4cbe98e69ae84ee46847 [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:18:18.737273 10296 raft_consensus.cc:2272] T ffcd899db4b34bb0ae2ed1d1ffe997aa P ac381f53065b4cbe98e69ae84ee46847 [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:18:18.752640 10296 tablet_server.cc:196] TabletServer@127.10.14.1:0 shutdown complete.
I20260812 06:18:18.778673 10296 master.cc:562] Master@127.10.14.62:42327 shutting down...
I20260812 06:18:18.782119 10296 raft_consensus.cc:2243] T 00000000000000000000000000000000 P 1ffa208a10b9446da67287ba16cba281 [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:18:18.782317 10296 raft_consensus.cc:2272] T 00000000000000000000000000000000 P 1ffa208a10b9446da67287ba16cba281 [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:18:18.782419 10296 tablet_replica.cc:333] T 00000000000000000000000000000000 P 1ffa208a10b9446da67287ba16cba281: stopping tablet replica
I20260812 06:18:18.795007 10296 master.cc:584] Master@127.10.14.62:42327 shutdown complete.
[       OK ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/0 (5347 ms)
[ RUN      ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/1
I20260812 06:18:18.882958 10296 internal_mini_cluster.cc:156] Creating distributed mini masters. Addrs: 127.10.14.62:37849
I20260812 06:18:18.883419 10296 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:18:18.885491 10624 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:18:18.885718 10296 server_base.cc:1061] running on GCE node
W20260812 06:18:18.885736 10626 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:18:18.885777 10629 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:18:18.886101 10296 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:18:18.886166 10296 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:18:18.886193 10296 hybrid_clock.cc:648] HybridClock initialized: now 1786515498886191 us; error 0 us; skew 500 ppm
I20260812 06:18:18.887346 10296 webserver.cc:533] Webserver started at http://127.10.14.62:40233/ using document root <none> and password file <none>
I20260812 06:18:18.887521 10296 fs_manager.cc:362] Metadata directory not provided
I20260812 06:18:18.887588 10296 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:18:18.887737 10296 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:18:18.888199 10296 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskLBU3bg/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515493525939-10296-0/minicluster-data/master-0-root/instance:
uuid: "d8c1161ff053496a9da39375c9a6067c"
format_stamp: "Formatted at 2026-08-12 06:18:18 on dist-test-slave-w4v5"
I20260812 06:18:18.889739 10296 fs_manager.cc:696] Time spent creating directory manager: real 0.001s	user 0.000s	sys 0.002s
I20260812 06:18:18.890692 10642 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:18:18.890941 10296 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.000s	sys 0.001s
I20260812 06:18:18.891037 10296 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskLBU3bg/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515493525939-10296-0/minicluster-data/master-0-root
uuid: "d8c1161ff053496a9da39375c9a6067c"
format_stamp: "Formatted at 2026-08-12 06:18:18 on dist-test-slave-w4v5"
I20260812 06:18:18.891155 10296 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskLBU3bg/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515493525939-10296-0/minicluster-data/master-0-root
metadata directory: /tmp/dist-test-taskLBU3bg/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515493525939-10296-0/minicluster-data/master-0-root
1 data directories: /tmp/dist-test-taskLBU3bg/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515493525939-10296-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:18:18.897400 10296 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:18:18.897763 10296 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:18:18.901975 10296 rpc_server.cc:307] RPC server started. Bound to: 127.10.14.62:37849
I20260812 06:18:18.904354 10729 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.10.14.62:37849 every 8 connection(s)
I20260812 06:18:18.906978 10731 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:18:18.918349 10731 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P d8c1161ff053496a9da39375c9a6067c: Bootstrap starting.
I20260812 06:18:18.919234 10731 tablet_bootstrap.cc:654] T 00000000000000000000000000000000 P d8c1161ff053496a9da39375c9a6067c: Neither blocks nor log segments found. Creating new log.
I20260812 06:18:18.920275 10731 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P d8c1161ff053496a9da39375c9a6067c: No bootstrap required, opened a new log
I20260812 06:18:18.920707 10731 raft_consensus.cc:359] T 00000000000000000000000000000000 P d8c1161ff053496a9da39375c9a6067c [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "d8c1161ff053496a9da39375c9a6067c" member_type: VOTER }
I20260812 06:18:18.920818 10731 raft_consensus.cc:385] T 00000000000000000000000000000000 P d8c1161ff053496a9da39375c9a6067c [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:18:18.920871 10731 raft_consensus.cc:740] T 00000000000000000000000000000000 P d8c1161ff053496a9da39375c9a6067c [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: d8c1161ff053496a9da39375c9a6067c, State: Initialized, Role: FOLLOWER
I20260812 06:18:18.921032 10731 consensus_queue.cc:260] T 00000000000000000000000000000000 P d8c1161ff053496a9da39375c9a6067c [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: "d8c1161ff053496a9da39375c9a6067c" member_type: VOTER }
I20260812 06:18:18.921126 10731 raft_consensus.cc:399] T 00000000000000000000000000000000 P d8c1161ff053496a9da39375c9a6067c [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:18:18.921167 10731 raft_consensus.cc:493] T 00000000000000000000000000000000 P d8c1161ff053496a9da39375c9a6067c [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:18:18.921221 10731 raft_consensus.cc:3060] T 00000000000000000000000000000000 P d8c1161ff053496a9da39375c9a6067c [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:18:18.921893 10731 raft_consensus.cc:515] T 00000000000000000000000000000000 P d8c1161ff053496a9da39375c9a6067c [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "d8c1161ff053496a9da39375c9a6067c" member_type: VOTER }
I20260812 06:18:18.922045 10731 leader_election.cc:304] T 00000000000000000000000000000000 P d8c1161ff053496a9da39375c9a6067c [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: d8c1161ff053496a9da39375c9a6067c; no voters: 
I20260812 06:18:18.922266 10731 leader_election.cc:290] T 00000000000000000000000000000000 P d8c1161ff053496a9da39375c9a6067c [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:18:18.922399 10735 raft_consensus.cc:2804] T 00000000000000000000000000000000 P d8c1161ff053496a9da39375c9a6067c [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:18:18.922688 10735 raft_consensus.cc:697] T 00000000000000000000000000000000 P d8c1161ff053496a9da39375c9a6067c [term 1 LEADER]: Becoming Leader. State: Replica: d8c1161ff053496a9da39375c9a6067c, State: Running, Role: LEADER
I20260812 06:18:18.922722 10731 sys_catalog.cc:565] T 00000000000000000000000000000000 P d8c1161ff053496a9da39375c9a6067c [sys.catalog]: configured and running, proceeding with master startup.
I20260812 06:18:18.922873 10735 consensus_queue.cc:237] T 00000000000000000000000000000000 P d8c1161ff053496a9da39375c9a6067c [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: "d8c1161ff053496a9da39375c9a6067c" member_type: VOTER }
I20260812 06:18:18.923367 10736 sys_catalog.cc:455] T 00000000000000000000000000000000 P d8c1161ff053496a9da39375c9a6067c [sys.catalog]: SysCatalogTable state changed. Reason: RaftConsensus started. Latest consensus state: current_term: 1 leader_uuid: "d8c1161ff053496a9da39375c9a6067c" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "d8c1161ff053496a9da39375c9a6067c" member_type: VOTER } }
I20260812 06:18:18.923480 10736 sys_catalog.cc:458] T 00000000000000000000000000000000 P d8c1161ff053496a9da39375c9a6067c [sys.catalog]: This master's current role is: LEADER
I20260812 06:18:18.923382 10737 sys_catalog.cc:455] T 00000000000000000000000000000000 P d8c1161ff053496a9da39375c9a6067c [sys.catalog]: SysCatalogTable state changed. Reason: New leader d8c1161ff053496a9da39375c9a6067c. Latest consensus state: current_term: 1 leader_uuid: "d8c1161ff053496a9da39375c9a6067c" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "d8c1161ff053496a9da39375c9a6067c" member_type: VOTER } }
I20260812 06:18:18.923534 10737 sys_catalog.cc:458] T 00000000000000000000000000000000 P d8c1161ff053496a9da39375c9a6067c [sys.catalog]: This master's current role is: LEADER
I20260812 06:18:18.923779 10747 catalog_manager.cc:1511] Loading table and tablet metadata into memory...
I20260812 06:18:18.924576 10747 catalog_manager.cc:1520] Initializing Kudu cluster ID...
I20260812 06:18:18.924746 10296 internal_mini_cluster.cc:184] Waiting to initialize catalog manager on master 0
I20260812 06:18:18.926357 10747 catalog_manager.cc:1383] Generated new cluster ID: 2053ca74327c4122bfc0cd8a7222157b
I20260812 06:18:18.926415 10747 catalog_manager.cc:1531] Initializing Kudu internal certificate authority...
I20260812 06:18:18.936290 10747 catalog_manager.cc:1406] Generated new certificate authority record
I20260812 06:18:18.936825 10747 catalog_manager.cc:1540] Loading token signing keys...
I20260812 06:18:18.954223 10747 catalog_manager.cc:6092] T 00000000000000000000000000000000 P d8c1161ff053496a9da39375c9a6067c: Generated new TSK 0
I20260812 06:18:18.954401 10747 catalog_manager.cc:1550] Initializing in-progress tserver states...
I20260812 06:18:18.957073 10296 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:18:18.959200 10769 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:18:18.959322 10296 server_base.cc:1061] running on GCE node
W20260812 06:18:18.959266 10768 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:18:18.959308 10771 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:18:18.959733 10296 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:18:18.959777 10296 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:18:18.959793 10296 hybrid_clock.cc:648] HybridClock initialized: now 1786515498959794 us; error 0 us; skew 500 ppm
I20260812 06:18:18.960680 10296 webserver.cc:533] Webserver started at http://127.10.14.1:45035/ using document root <none> and password file <none>
I20260812 06:18:18.960860 10296 fs_manager.cc:362] Metadata directory not provided
I20260812 06:18:18.960937 10296 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:18:18.961023 10296 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:18:18.961431 10296 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskLBU3bg/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515493525939-10296-0/minicluster-data/ts-0-root/instance:
uuid: "946b209f82f84450b3c66224d4dffd4c"
format_stamp: "Formatted at 2026-08-12 06:18:18 on dist-test-slave-w4v5"
I20260812 06:18:18.962898 10296 fs_manager.cc:696] Time spent creating directory manager: real 0.001s	user 0.002s	sys 0.000s
I20260812 06:18:18.963910 10779 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:18:18.964178 10296 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.001s	sys 0.000s
I20260812 06:18:18.964241 10296 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskLBU3bg/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515493525939-10296-0/minicluster-data/ts-0-root
uuid: "946b209f82f84450b3c66224d4dffd4c"
format_stamp: "Formatted at 2026-08-12 06:18:18 on dist-test-slave-w4v5"
I20260812 06:18:18.964323 10296 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskLBU3bg/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515493525939-10296-0/minicluster-data/ts-0-root
metadata directory: /tmp/dist-test-taskLBU3bg/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515493525939-10296-0/minicluster-data/ts-0-root
1 data directories: /tmp/dist-test-taskLBU3bg/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515493525939-10296-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:18:18.977752 10296 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:18:18.978144 10296 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:18:18.978457 10296 txn_system_client.cc:432] TxnSystemClient initialization is disabled...
I20260812 06:18:18.978935 10296 ts_tablet_manager.cc:585] Loaded tablet metadata (0 total tablets, 0 live tablets)
I20260812 06:18:18.978972 10296 ts_tablet_manager.cc:531] Time spent load tablet metadata: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:18:18.979027 10296 ts_tablet_manager.cc:616] Registered 0 tablets
I20260812 06:18:18.979113 10296 ts_tablet_manager.cc:595] Time spent register tablets: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:18:18.983494 10296 rpc_server.cc:307] RPC server started. Bound to: 127.10.14.1:43583
I20260812 06:18:18.983577 10896 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.10.14.1:43583 every 8 connection(s)
I20260812 06:18:18.992565 10897 heartbeater.cc:344] Connected to a master server at 127.10.14.62:37849
I20260812 06:18:18.992723 10897 heartbeater.cc:461] Registering TS with master...
I20260812 06:18:18.993009 10897 heartbeater.cc:507] Master 127.10.14.62:37849 requested a full tablet report, sending...
I20260812 06:18:18.993808 10671 ts_manager.cc:194] Registered new tserver with Master: 946b209f82f84450b3c66224d4dffd4c (127.10.14.1:43583)
I20260812 06:18:18.994066 10296 internal_mini_cluster.cc:371] 1 TS(s) registered with all masters after 0.010158494s
I20260812 06:18:18.994814 10671 master_service.cc:502] Signed X509 certificate for tserver {username='slave'} at 127.0.0.1:36596
I20260812 06:18:19.002242 10671 catalog_manager.cc:2283] Servicing CreateTable request from {username='slave'} at 127.0.0.1:36600:
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:18:19.011178 10822 tablet_service.cc:1511] Processing CreateTablet for tablet aef78abd84f4476f8176fe51291037c3 (DEFAULT_TABLE table=heavy-update-compaction-test [id=a438bb0cf14f46fc989dd123e859b477]), partition=
I20260812 06:18:19.011426 10822 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet aef78abd84f4476f8176fe51291037c3. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:18:19.013446 10912 tablet_bootstrap.cc:492] T aef78abd84f4476f8176fe51291037c3 P 946b209f82f84450b3c66224d4dffd4c: Bootstrap starting.
I20260812 06:18:19.014406 10912 tablet_bootstrap.cc:654] T aef78abd84f4476f8176fe51291037c3 P 946b209f82f84450b3c66224d4dffd4c: Neither blocks nor log segments found. Creating new log.
I20260812 06:18:19.015537 10912 tablet_bootstrap.cc:492] T aef78abd84f4476f8176fe51291037c3 P 946b209f82f84450b3c66224d4dffd4c: No bootstrap required, opened a new log
I20260812 06:18:19.015632 10912 ts_tablet_manager.cc:1403] T aef78abd84f4476f8176fe51291037c3 P 946b209f82f84450b3c66224d4dffd4c: Time spent bootstrapping tablet: real 0.002s	user 0.002s	sys 0.000s
I20260812 06:18:19.016088 10912 raft_consensus.cc:359] T aef78abd84f4476f8176fe51291037c3 P 946b209f82f84450b3c66224d4dffd4c [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "946b209f82f84450b3c66224d4dffd4c" member_type: VOTER last_known_addr { host: "127.10.14.1" port: 43583 } }
I20260812 06:18:19.016178 10912 raft_consensus.cc:385] T aef78abd84f4476f8176fe51291037c3 P 946b209f82f84450b3c66224d4dffd4c [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:18:19.016244 10912 raft_consensus.cc:740] T aef78abd84f4476f8176fe51291037c3 P 946b209f82f84450b3c66224d4dffd4c [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: 946b209f82f84450b3c66224d4dffd4c, State: Initialized, Role: FOLLOWER
I20260812 06:18:19.016423 10912 consensus_queue.cc:260] T aef78abd84f4476f8176fe51291037c3 P 946b209f82f84450b3c66224d4dffd4c [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: "946b209f82f84450b3c66224d4dffd4c" member_type: VOTER last_known_addr { host: "127.10.14.1" port: 43583 } }
I20260812 06:18:19.016521 10912 raft_consensus.cc:399] T aef78abd84f4476f8176fe51291037c3 P 946b209f82f84450b3c66224d4dffd4c [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:18:19.016571 10912 raft_consensus.cc:493] T aef78abd84f4476f8176fe51291037c3 P 946b209f82f84450b3c66224d4dffd4c [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:18:19.016635 10912 raft_consensus.cc:3060] T aef78abd84f4476f8176fe51291037c3 P 946b209f82f84450b3c66224d4dffd4c [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:18:19.017584 10912 raft_consensus.cc:515] T aef78abd84f4476f8176fe51291037c3 P 946b209f82f84450b3c66224d4dffd4c [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "946b209f82f84450b3c66224d4dffd4c" member_type: VOTER last_known_addr { host: "127.10.14.1" port: 43583 } }
I20260812 06:18:19.017735 10912 leader_election.cc:304] T aef78abd84f4476f8176fe51291037c3 P 946b209f82f84450b3c66224d4dffd4c [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: 946b209f82f84450b3c66224d4dffd4c; no voters: 
I20260812 06:18:19.017957 10912 leader_election.cc:290] T aef78abd84f4476f8176fe51291037c3 P 946b209f82f84450b3c66224d4dffd4c [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:18:19.018121 10915 raft_consensus.cc:2804] T aef78abd84f4476f8176fe51291037c3 P 946b209f82f84450b3c66224d4dffd4c [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:18:19.018337 10912 ts_tablet_manager.cc:1434] T aef78abd84f4476f8176fe51291037c3 P 946b209f82f84450b3c66224d4dffd4c: Time spent starting tablet: real 0.003s	user 0.003s	sys 0.000s
I20260812 06:18:19.018393 10915 raft_consensus.cc:697] T aef78abd84f4476f8176fe51291037c3 P 946b209f82f84450b3c66224d4dffd4c [term 1 LEADER]: Becoming Leader. State: Replica: 946b209f82f84450b3c66224d4dffd4c, State: Running, Role: LEADER
I20260812 06:18:19.018352 10897 heartbeater.cc:499] Master 127.10.14.62:37849 was elected leader, sending a full tablet report...
I20260812 06:18:19.018554 10915 consensus_queue.cc:237] T aef78abd84f4476f8176fe51291037c3 P 946b209f82f84450b3c66224d4dffd4c [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: "946b209f82f84450b3c66224d4dffd4c" member_type: VOTER last_known_addr { host: "127.10.14.1" port: 43583 } }
I20260812 06:18:19.019886 10671 catalog_manager.cc:5719] T aef78abd84f4476f8176fe51291037c3 P 946b209f82f84450b3c66224d4dffd4c reported cstate change: term changed from 0 to 1, leader changed from <none> to 946b209f82f84450b3c66224d4dffd4c (127.10.14.1). New cstate: current_term: 1 leader_uuid: "946b209f82f84450b3c66224d4dffd4c" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "946b209f82f84450b3c66224d4dffd4c" member_type: VOTER last_known_addr { host: "127.10.14.1" port: 43583 } health_report { overall_health: HEALTHY } } }
I20260812 06:18:19.081039 10296 heavy-update-compaction-itest.cc:215] Time spent inserting: real 0.054s	user 0.015s	sys 0.008s
I20260812 06:18:19.234422 10898 maintenance_manager.cc:419] P 946b209f82f84450b3c66224d4dffd4c: Scheduling FlushMRSOp(aef78abd84f4476f8176fe51291037c3): perf score=19.054940
I20260812 06:18:19.395248 10790 maintenance_manager.cc:643] P 946b209f82f84450b3c66224d4dffd4c: FlushMRSOp(aef78abd84f4476f8176fe51291037c3) complete. Timing: real 0.161s	user 0.104s	sys 0.055s Metrics: {"bytes_written":12594663,"cfile_init":1,"delete_count":0,"dirs.queue_time_us":81,"dirs.run_cpu_time_us":219,"dirs.run_wall_time_us":840,"drs_written":1,"lbm_read_time_us":50,"lbm_reads_lt_1ms":4,"lbm_write_time_us":42218,"lbm_writes_lt_1ms":764,"peak_mem_usage":0,"reinsert_count":0,"rows_written":104,"spinlock_wait_cycles":15744,"update_count":1535}
I20260812 06:18:19.395915 10898 maintenance_manager.cc:419] P 946b209f82f84450b3c66224d4dffd4c: Scheduling LogGCOp(aef78abd84f4476f8176fe51291037c3): free 20290830 bytes of WAL
I20260812 06:18:19.396162 10790 log_reader.cc:385] T aef78abd84f4476f8176fe51291037c3: removed 2 log segments from log reader
I20260812 06:18:19.396207 10790 log.cc:1079] T aef78abd84f4476f8176fe51291037c3 P 946b209f82f84450b3c66224d4dffd4c: Deleting log segment in path: /tmp/dist-test-taskLBU3bg/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515493525939-10296-0/minicluster-data/ts-0-root/wals/aef78abd84f4476f8176fe51291037c3/wal-000000001 (ops 1-6)
I20260812 06:18:19.396238 10790 log.cc:1079] T aef78abd84f4476f8176fe51291037c3 P 946b209f82f84450b3c66224d4dffd4c: Deleting log segment in path: /tmp/dist-test-taskLBU3bg/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515493525939-10296-0/minicluster-data/ts-0-root/wals/aef78abd84f4476f8176fe51291037c3/wal-000000002 (ops 7-10)
I20260812 06:18:19.402261 10790 maintenance_manager.cc:643] P 946b209f82f84450b3c66224d4dffd4c: LogGCOp(aef78abd84f4476f8176fe51291037c3) complete. Timing: real 0.006s	user 0.000s	sys 0.003s Metrics: {}
I20260812 06:18:19.402819 10898 maintenance_manager.cc:419] P 946b209f82f84450b3c66224d4dffd4c: Scheduling FlushDeltaMemStoresOp(aef78abd84f4476f8176fe51291037c3): perf score=2.188937
I20260812 06:18:19.423738 10790 maintenance_manager.cc:643] P 946b209f82f84450b3c66224d4dffd4c: FlushDeltaMemStoresOp(aef78abd84f4476f8176fe51291037c3) complete. Timing: real 0.021s	user 0.014s	sys 0.000s Metrics: {"bytes_written":3815483,"delete_count":0,"lbm_write_time_us":5837,"lbm_writes_lt_1ms":96,"reinsert_count":0,"spinlock_wait_cycles":896,"update_count":465}
I20260812 06:18:19.424250 10898 maintenance_manager.cc:419] P 946b209f82f84450b3c66224d4dffd4c: Scheduling UndoDeltaBlockGCOp(aef78abd84f4476f8176fe51291037c3): 16411394 bytes on disk
I20260812 06:18:19.424639 10790 maintenance_manager.cc:643] P 946b209f82f84450b3c66224d4dffd4c: UndoDeltaBlockGCOp(aef78abd84f4476f8176fe51291037c3) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":51,"lbm_reads_lt_1ms":4}
I20260812 06:18:19.425034 10898 maintenance_manager.cc:419] P 946b209f82f84450b3c66224d4dffd4c: Scheduling FlushDeltaMemStoresOp(aef78abd84f4476f8176fe51291037c3): perf score=2.188937
I20260812 06:18:19.435284 10790 maintenance_manager.cc:643] P 946b209f82f84450b3c66224d4dffd4c: FlushDeltaMemStoresOp(aef78abd84f4476f8176fe51291037c3) complete. Timing: real 0.010s	user 0.010s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3876,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:19.435704 10898 maintenance_manager.cc:419] P 946b209f82f84450b3c66224d4dffd4c: Scheduling MajorDeltaCompactionOp(aef78abd84f4476f8176fe51291037c3): perf score=1.000000
I20260812 06:18:19.628275 10790 maintenance_manager.cc:643] P 946b209f82f84450b3c66224d4dffd4c: MajorDeltaCompactionOp(aef78abd84f4476f8176fe51291037c3) complete. Timing: real 0.192s	user 0.112s	sys 0.064s Metrics: {"cfile_cache_miss":533,"cfile_cache_miss_bytes":24774805,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":539,"lbm_read_time_us":11056,"lbm_reads_lt_1ms":569,"lbm_write_time_us":30648,"lbm_writes_lt_1ms":543,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":11008,"thread_start_us":345,"threads_started":5,"update_count":2500}
I20260812 06:18:19.629011 10898 maintenance_manager.cc:419] P 946b209f82f84450b3c66224d4dffd4c: Scheduling FlushDeltaMemStoresOp(aef78abd84f4476f8176fe51291037c3): perf score=14.095187
I20260812 06:18:19.681178 10790 maintenance_manager.cc:643] P 946b209f82f84450b3c66224d4dffd4c: FlushDeltaMemStoresOp(aef78abd84f4476f8176fe51291037c3) complete. Timing: real 0.052s	user 0.033s	sys 0.011s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":20427,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:18:19.681752 10898 maintenance_manager.cc:419] P 946b209f82f84450b3c66224d4dffd4c: Scheduling FlushDeltaMemStoresOp(aef78abd84f4476f8176fe51291037c3): perf score=2.188937
I20260812 06:18:19.693193 10790 maintenance_manager.cc:643] P 946b209f82f84450b3c66224d4dffd4c: FlushDeltaMemStoresOp(aef78abd84f4476f8176fe51291037c3) complete. Timing: real 0.011s	user 0.005s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4214,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:19.693810 10898 maintenance_manager.cc:419] P 946b209f82f84450b3c66224d4dffd4c: Scheduling MajorDeltaCompactionOp(aef78abd84f4476f8176fe51291037c3): perf score=1.000000
I20260812 06:18:19.851863 10790 maintenance_manager.cc:643] P 946b209f82f84450b3c66224d4dffd4c: MajorDeltaCompactionOp(aef78abd84f4476f8176fe51291037c3) complete. Timing: real 0.158s	user 0.136s	sys 0.021s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774689,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":1003,"lbm_read_time_us":11617,"lbm_reads_lt_1ms":572,"lbm_write_time_us":31078,"lbm_writes_lt_1ms":543,"mutex_wait_us":367,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":11904,"update_count":2500}
I20260812 06:18:19.852624 10898 maintenance_manager.cc:419] P 946b209f82f84450b3c66224d4dffd4c: Scheduling FlushDeltaMemStoresOp(aef78abd84f4476f8176fe51291037c3): perf score=10.126437
I20260812 06:18:19.883356 10790 maintenance_manager.cc:643] P 946b209f82f84450b3c66224d4dffd4c: FlushDeltaMemStoresOp(aef78abd84f4476f8176fe51291037c3) complete. Timing: real 0.030s	user 0.019s	sys 0.011s Metrics: {"bytes_written":12307491,"delete_count":0,"lbm_write_time_us":13235,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:18:19.883934 10898 maintenance_manager.cc:419] P 946b209f82f84450b3c66224d4dffd4c: Scheduling FlushDeltaMemStoresOp(aef78abd84f4476f8176fe51291037c3): perf score=2.188937
I20260812 06:18:19.899544 10790 maintenance_manager.cc:643] P 946b209f82f84450b3c66224d4dffd4c: FlushDeltaMemStoresOp(aef78abd84f4476f8176fe51291037c3) complete. Timing: real 0.015s	user 0.007s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5777,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:19.900770 10898 maintenance_manager.cc:419] P 946b209f82f84450b3c66224d4dffd4c: Scheduling MajorDeltaCompactionOp(aef78abd84f4476f8176fe51291037c3): perf score=1.000000
I20260812 06:18:20.025499 10790 maintenance_manager.cc:643] P 946b209f82f84450b3c66224d4dffd4c: MajorDeltaCompactionOp(aef78abd84f4476f8176fe51291037c3) complete. Timing: real 0.125s	user 0.100s	sys 0.024s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672278,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":274,"lbm_read_time_us":8304,"lbm_reads_lt_1ms":472,"lbm_write_time_us":22800,"lbm_writes_lt_1ms":443,"mutex_wait_us":28,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":7296,"update_count":2000}
I20260812 06:18:20.026165 10898 maintenance_manager.cc:419] P 946b209f82f84450b3c66224d4dffd4c: Scheduling FlushDeltaMemStoresOp(aef78abd84f4476f8176fe51291037c3): perf score=10.126437
I20260812 06:18:20.069702 10790 maintenance_manager.cc:643] P 946b209f82f84450b3c66224d4dffd4c: FlushDeltaMemStoresOp(aef78abd84f4476f8176fe51291037c3) complete. Timing: real 0.043s	user 0.016s	sys 0.023s Metrics: {"bytes_written":12307489,"delete_count":0,"lbm_write_time_us":18474,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":302,"reinsert_count":0,"update_count":1500}
I20260812 06:18:20.070226 10898 maintenance_manager.cc:419] P 946b209f82f84450b3c66224d4dffd4c: Scheduling FlushDeltaMemStoresOp(aef78abd84f4476f8176fe51291037c3): perf score=2.188937
I20260812 06:18:20.081883 10790 maintenance_manager.cc:643] P 946b209f82f84450b3c66224d4dffd4c: FlushDeltaMemStoresOp(aef78abd84f4476f8176fe51291037c3) complete. Timing: real 0.011s	user 0.006s	sys 0.003s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4146,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:20.082707 10898 maintenance_manager.cc:419] P 946b209f82f84450b3c66224d4dffd4c: Scheduling MajorDeltaCompactionOp(aef78abd84f4476f8176fe51291037c3): perf score=1.000000
I20260812 06:18:20.234091 10790 maintenance_manager.cc:643] P 946b209f82f84450b3c66224d4dffd4c: MajorDeltaCompactionOp(aef78abd84f4476f8176fe51291037c3) complete. Timing: real 0.151s	user 0.111s	sys 0.040s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672276,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":327,"lbm_read_time_us":9457,"lbm_reads_lt_1ms":472,"lbm_write_time_us":27723,"lbm_writes_lt_1ms":443,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":3200,"update_count":2000}
I20260812 06:18:20.234647 10898 maintenance_manager.cc:419] P 946b209f82f84450b3c66224d4dffd4c: Scheduling FlushDeltaMemStoresOp(aef78abd84f4476f8176fe51291037c3): perf score=10.126437
I20260812 06:18:20.282306 10790 maintenance_manager.cc:643] P 946b209f82f84450b3c66224d4dffd4c: FlushDeltaMemStoresOp(aef78abd84f4476f8176fe51291037c3) complete. Timing: real 0.047s	user 0.022s	sys 0.023s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":16767,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:18:20.282907 10898 maintenance_manager.cc:419] P 946b209f82f84450b3c66224d4dffd4c: Scheduling FlushDeltaMemStoresOp(aef78abd84f4476f8176fe51291037c3): perf score=2.188937
I20260812 06:18:20.293895 10790 maintenance_manager.cc:643] P 946b209f82f84450b3c66224d4dffd4c: FlushDeltaMemStoresOp(aef78abd84f4476f8176fe51291037c3) complete. Timing: real 0.011s	user 0.001s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4332,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:20.294355 10898 maintenance_manager.cc:419] P 946b209f82f84450b3c66224d4dffd4c: Scheduling MajorDeltaCompactionOp(aef78abd84f4476f8176fe51291037c3): perf score=1.000000
I20260812 06:18:20.454559 10790 maintenance_manager.cc:643] P 946b209f82f84450b3c66224d4dffd4c: MajorDeltaCompactionOp(aef78abd84f4476f8176fe51291037c3) complete. Timing: real 0.160s	user 0.116s	sys 0.044s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672277,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":940,"lbm_read_time_us":10903,"lbm_reads_lt_1ms":472,"lbm_write_time_us":26786,"lbm_writes_lt_1ms":443,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":2816,"update_count":2000}
I20260812 06:18:20.455185 10898 maintenance_manager.cc:419] P 946b209f82f84450b3c66224d4dffd4c: Scheduling FlushDeltaMemStoresOp(aef78abd84f4476f8176fe51291037c3): perf score=10.126437
I20260812 06:18:20.496215 10790 maintenance_manager.cc:643] P 946b209f82f84450b3c66224d4dffd4c: FlushDeltaMemStoresOp(aef78abd84f4476f8176fe51291037c3) complete. Timing: real 0.041s	user 0.021s	sys 0.013s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":14745,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:18:20.496742 10898 maintenance_manager.cc:419] P 946b209f82f84450b3c66224d4dffd4c: Scheduling FlushDeltaMemStoresOp(aef78abd84f4476f8176fe51291037c3): perf score=2.188937
I20260812 06:18:20.507766 10790 maintenance_manager.cc:643] P 946b209f82f84450b3c66224d4dffd4c: FlushDeltaMemStoresOp(aef78abd84f4476f8176fe51291037c3) complete. Timing: real 0.011s	user 0.006s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4303,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:20.508348 10898 maintenance_manager.cc:419] P 946b209f82f84450b3c66224d4dffd4c: Scheduling MajorDeltaCompactionOp(aef78abd84f4476f8176fe51291037c3): perf score=1.000000
I20260812 06:18:20.622581 10790 maintenance_manager.cc:643] P 946b209f82f84450b3c66224d4dffd4c: MajorDeltaCompactionOp(aef78abd84f4476f8176fe51291037c3) complete. Timing: real 0.114s	user 0.090s	sys 0.024s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672277,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":471,"lbm_read_time_us":7660,"lbm_reads_lt_1ms":472,"lbm_write_time_us":22024,"lbm_writes_lt_1ms":443,"mutex_wait_us":2,"peak_mem_usage":50689328,"reinsert_count":0,"update_count":2000}
I20260812 06:18:20.623260 10898 maintenance_manager.cc:419] P 946b209f82f84450b3c66224d4dffd4c: Scheduling FlushDeltaMemStoresOp(aef78abd84f4476f8176fe51291037c3): perf score=10.126437
I20260812 06:18:20.661814 10790 maintenance_manager.cc:643] P 946b209f82f84450b3c66224d4dffd4c: FlushDeltaMemStoresOp(aef78abd84f4476f8176fe51291037c3) complete. Timing: real 0.038s	user 0.015s	sys 0.021s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":17776,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":302,"reinsert_count":0,"spinlock_wait_cycles":3840,"update_count":1500}
I20260812 06:18:20.662412 10898 maintenance_manager.cc:419] P 946b209f82f84450b3c66224d4dffd4c: Scheduling FlushDeltaMemStoresOp(aef78abd84f4476f8176fe51291037c3): perf score=2.188937
I20260812 06:18:20.677989 10790 maintenance_manager.cc:643] P 946b209f82f84450b3c66224d4dffd4c: FlushDeltaMemStoresOp(aef78abd84f4476f8176fe51291037c3) complete. Timing: real 0.015s	user 0.010s	sys 0.003s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6174,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:20.678586 10898 maintenance_manager.cc:419] P 946b209f82f84450b3c66224d4dffd4c: Scheduling FlushMRSOp(aef78abd84f4476f8176fe51291037c3): perf score=1.000000
I20260812 06:18:20.712110 10790 maintenance_manager.cc:643] P 946b209f82f84450b3c66224d4dffd4c: FlushMRSOp(aef78abd84f4476f8176fe51291037c3) complete. Timing: real 0.033s	user 0.032s	sys 0.000s Metrics: {"bytes_written":1234473,"cfile_init":1,"dirs.queue_time_us":68,"dirs.run_cpu_time_us":269,"dirs.run_wall_time_us":1407,"drs_written":1,"lbm_read_time_us":38,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1610,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":30}
I20260812 06:18:20.712759 10898 maintenance_manager.cc:419] P 946b209f82f84450b3c66224d4dffd4c: Scheduling LogGCOp(aef78abd84f4476f8176fe51291037c3): free 121006439 bytes of WAL
I20260812 06:18:20.713030 10790 log_reader.cc:385] T aef78abd84f4476f8176fe51291037c3: removed 12 log segments from log reader
I20260812 06:18:20.713099 10790 log.cc:1079] T aef78abd84f4476f8176fe51291037c3 P 946b209f82f84450b3c66224d4dffd4c: Deleting log segment in path: /tmp/dist-test-taskLBU3bg/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515493525939-10296-0/minicluster-data/ts-0-root/wals/aef78abd84f4476f8176fe51291037c3/wal-000000003 (ops 11-15)
I20260812 06:18:20.713140 10790 log.cc:1079] T aef78abd84f4476f8176fe51291037c3 P 946b209f82f84450b3c66224d4dffd4c: Deleting log segment in path: /tmp/dist-test-taskLBU3bg/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515493525939-10296-0/minicluster-data/ts-0-root/wals/aef78abd84f4476f8176fe51291037c3/wal-000000004 (ops 16-20)
I20260812 06:18:20.713176 10790 log.cc:1079] T aef78abd84f4476f8176fe51291037c3 P 946b209f82f84450b3c66224d4dffd4c: Deleting log segment in path: /tmp/dist-test-taskLBU3bg/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515493525939-10296-0/minicluster-data/ts-0-root/wals/aef78abd84f4476f8176fe51291037c3/wal-000000005 (ops 21-25)
I20260812 06:18:20.713210 10790 log.cc:1079] T aef78abd84f4476f8176fe51291037c3 P 946b209f82f84450b3c66224d4dffd4c: Deleting log segment in path: /tmp/dist-test-taskLBU3bg/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515493525939-10296-0/minicluster-data/ts-0-root/wals/aef78abd84f4476f8176fe51291037c3/wal-000000006 (ops 26-30)
I20260812 06:18:20.713232 10790 log.cc:1079] T aef78abd84f4476f8176fe51291037c3 P 946b209f82f84450b3c66224d4dffd4c: Deleting log segment in path: /tmp/dist-test-taskLBU3bg/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515493525939-10296-0/minicluster-data/ts-0-root/wals/aef78abd84f4476f8176fe51291037c3/wal-000000007 (ops 31-34)
I20260812 06:18:20.713261 10790 log.cc:1079] T aef78abd84f4476f8176fe51291037c3 P 946b209f82f84450b3c66224d4dffd4c: Deleting log segment in path: /tmp/dist-test-taskLBU3bg/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515493525939-10296-0/minicluster-data/ts-0-root/wals/aef78abd84f4476f8176fe51291037c3/wal-000000008 (ops 35-39)
I20260812 06:18:20.713290 10790 log.cc:1079] T aef78abd84f4476f8176fe51291037c3 P 946b209f82f84450b3c66224d4dffd4c: Deleting log segment in path: /tmp/dist-test-taskLBU3bg/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515493525939-10296-0/minicluster-data/ts-0-root/wals/aef78abd84f4476f8176fe51291037c3/wal-000000009 (ops 40-44)
I20260812 06:18:20.713322 10790 log.cc:1079] T aef78abd84f4476f8176fe51291037c3 P 946b209f82f84450b3c66224d4dffd4c: Deleting log segment in path: /tmp/dist-test-taskLBU3bg/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515493525939-10296-0/minicluster-data/ts-0-root/wals/aef78abd84f4476f8176fe51291037c3/wal-000000010 (ops 45-49)
I20260812 06:18:20.713356 10790 log.cc:1079] T aef78abd84f4476f8176fe51291037c3 P 946b209f82f84450b3c66224d4dffd4c: Deleting log segment in path: /tmp/dist-test-taskLBU3bg/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515493525939-10296-0/minicluster-data/ts-0-root/wals/aef78abd84f4476f8176fe51291037c3/wal-000000011 (ops 50-54)
I20260812 06:18:20.713387 10790 log.cc:1079] T aef78abd84f4476f8176fe51291037c3 P 946b209f82f84450b3c66224d4dffd4c: Deleting log segment in path: /tmp/dist-test-taskLBU3bg/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515493525939-10296-0/minicluster-data/ts-0-root/wals/aef78abd84f4476f8176fe51291037c3/wal-000000012 (ops 55-59)
I20260812 06:18:20.713415 10790 log.cc:1079] T aef78abd84f4476f8176fe51291037c3 P 946b209f82f84450b3c66224d4dffd4c: Deleting log segment in path: /tmp/dist-test-taskLBU3bg/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515493525939-10296-0/minicluster-data/ts-0-root/wals/aef78abd84f4476f8176fe51291037c3/wal-000000013 (ops 60-64)
I20260812 06:18:20.713443 10790 log.cc:1079] T aef78abd84f4476f8176fe51291037c3 P 946b209f82f84450b3c66224d4dffd4c: Deleting log segment in path: /tmp/dist-test-taskLBU3bg/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515493525939-10296-0/minicluster-data/ts-0-root/wals/aef78abd84f4476f8176fe51291037c3/wal-000000014 (ops 65-69)
I20260812 06:18:20.742904 10790 maintenance_manager.cc:643] P 946b209f82f84450b3c66224d4dffd4c: LogGCOp(aef78abd84f4476f8176fe51291037c3) complete. Timing: real 0.030s	user 0.000s	sys 0.026s Metrics: {}
I20260812 06:18:20.743319 10898 maintenance_manager.cc:419] P 946b209f82f84450b3c66224d4dffd4c: Scheduling FlushDeltaMemStoresOp(aef78abd84f4476f8176fe51291037c3): perf score=4.173312
I20260812 06:18:20.757038 10790 maintenance_manager.cc:643] P 946b209f82f84450b3c66224d4dffd4c: FlushDeltaMemStoresOp(aef78abd84f4476f8176fe51291037c3) complete. Timing: real 0.014s	user 0.003s	sys 0.009s Metrics: {"bytes_written":5784657,"delete_count":0,"lbm_write_time_us":5594,"lbm_writes_lt_1ms":144,"reinsert_count":0,"update_count":705}
I20260812 06:18:20.757563 10898 maintenance_manager.cc:419] P 946b209f82f84450b3c66224d4dffd4c: Scheduling UndoDeltaBlockGCOp(aef78abd84f4476f8176fe51291037c3): 472 bytes on disk
I20260812 06:18:20.758111 10790 maintenance_manager.cc:643] P 946b209f82f84450b3c66224d4dffd4c: UndoDeltaBlockGCOp(aef78abd84f4476f8176fe51291037c3) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":65,"lbm_reads_lt_1ms":4}
I20260812 06:18:20.758687 10898 maintenance_manager.cc:419] P 946b209f82f84450b3c66224d4dffd4c: Scheduling FlushDeltaMemStoresOp(aef78abd84f4476f8176fe51291037c3): perf score=1.196750
I20260812 06:18:20.770411 10790 maintenance_manager.cc:643] P 946b209f82f84450b3c66224d4dffd4c: FlushDeltaMemStoresOp(aef78abd84f4476f8176fe51291037c3) complete. Timing: real 0.012s	user 0.006s	sys 0.003s Metrics: {"bytes_written":2420629,"delete_count":0,"lbm_write_time_us":4368,"lbm_writes_lt_1ms":62,"reinsert_count":0,"update_count":295}
I20260812 06:18:20.770987 10898 maintenance_manager.cc:419] P 946b209f82f84450b3c66224d4dffd4c: Scheduling MajorDeltaCompactionOp(aef78abd84f4476f8176fe51291037c3): perf score=1.000000
I20260812 06:18:20.942637 10790 maintenance_manager.cc:643] P 946b209f82f84450b3c66224d4dffd4c: MajorDeltaCompactionOp(aef78abd84f4476f8176fe51291037c3) complete. Timing: real 0.171s	user 0.146s	sys 0.025s Metrics: {"cfile_cache_miss":634,"cfile_cache_miss_bytes":28877301,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":976,"lbm_read_time_us":10570,"lbm_reads_lt_1ms":666,"lbm_write_time_us":36512,"lbm_writes_lt_1ms":643,"mutex_wait_us":271,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":9600,"thread_start_us":73,"threads_started":1,"update_count":3000}
I20260812 06:18:20.943142 10898 maintenance_manager.cc:419] P 946b209f82f84450b3c66224d4dffd4c: Scheduling FlushDeltaMemStoresOp(aef78abd84f4476f8176fe51291037c3): perf score=14.095187
I20260812 06:18:20.993911 10790 maintenance_manager.cc:643] P 946b209f82f84450b3c66224d4dffd4c: FlushDeltaMemStoresOp(aef78abd84f4476f8176fe51291037c3) complete. Timing: real 0.051s	user 0.023s	sys 0.020s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":20235,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:18:20.994438 10898 maintenance_manager.cc:419] P 946b209f82f84450b3c66224d4dffd4c: Scheduling FlushDeltaMemStoresOp(aef78abd84f4476f8176fe51291037c3): perf score=2.188937
I20260812 06:18:21.005864 10790 maintenance_manager.cc:643] P 946b209f82f84450b3c66224d4dffd4c: FlushDeltaMemStoresOp(aef78abd84f4476f8176fe51291037c3) complete. Timing: real 0.011s	user 0.006s	sys 0.003s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4131,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:21.006300 10898 maintenance_manager.cc:419] P 946b209f82f84450b3c66224d4dffd4c: Scheduling MajorDeltaCompactionOp(aef78abd84f4476f8176fe51291037c3): perf score=1.000000
I20260812 06:18:21.164237 10790 maintenance_manager.cc:643] P 946b209f82f84450b3c66224d4dffd4c: MajorDeltaCompactionOp(aef78abd84f4476f8176fe51291037c3) complete. Timing: real 0.158s	user 0.099s	sys 0.051s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774689,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":172,"lbm_read_time_us":10523,"lbm_reads_lt_1ms":572,"lbm_write_time_us":29771,"lbm_writes_lt_1ms":543,"mutex_wait_us":87,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":768,"update_count":2500}
I20260812 06:18:21.164881 10898 maintenance_manager.cc:419] P 946b209f82f84450b3c66224d4dffd4c: Scheduling FlushDeltaMemStoresOp(aef78abd84f4476f8176fe51291037c3): perf score=14.095187
I20260812 06:18:21.225485 10790 maintenance_manager.cc:643] P 946b209f82f84450b3c66224d4dffd4c: FlushDeltaMemStoresOp(aef78abd84f4476f8176fe51291037c3) complete. Timing: real 0.060s	user 0.036s	sys 0.011s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":22126,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:18:21.225976 10898 maintenance_manager.cc:419] P 946b209f82f84450b3c66224d4dffd4c: Scheduling FlushDeltaMemStoresOp(aef78abd84f4476f8176fe51291037c3): perf score=2.188937
I20260812 06:18:21.237143 10790 maintenance_manager.cc:643] P 946b209f82f84450b3c66224d4dffd4c: FlushDeltaMemStoresOp(aef78abd84f4476f8176fe51291037c3) complete. Timing: real 0.011s	user 0.005s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3961,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:21.237740 10898 maintenance_manager.cc:419] P 946b209f82f84450b3c66224d4dffd4c: Scheduling MajorDeltaCompactionOp(aef78abd84f4476f8176fe51291037c3): perf score=1.000000
I20260812 06:18:21.401618 10790 maintenance_manager.cc:643] P 946b209f82f84450b3c66224d4dffd4c: MajorDeltaCompactionOp(aef78abd84f4476f8176fe51291037c3) complete. Timing: real 0.164s	user 0.103s	sys 0.060s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774688,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":1196,"lbm_read_time_us":10610,"lbm_reads_lt_1ms":572,"lbm_write_time_us":28081,"lbm_writes_lt_1ms":543,"mutex_wait_us":344,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":8192,"update_count":2500}
I20260812 06:18:21.402271 10898 maintenance_manager.cc:419] P 946b209f82f84450b3c66224d4dffd4c: Scheduling FlushDeltaMemStoresOp(aef78abd84f4476f8176fe51291037c3): perf score=14.095187
I20260812 06:18:21.458238 10790 maintenance_manager.cc:643] P 946b209f82f84450b3c66224d4dffd4c: FlushDeltaMemStoresOp(aef78abd84f4476f8176fe51291037c3) complete. Timing: real 0.056s	user 0.032s	sys 0.019s Metrics: {"bytes_written":16409903,"delete_count":0,"lbm_write_time_us":24576,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":402,"reinsert_count":0,"update_count":2000}
I20260812 06:18:21.458817 10898 maintenance_manager.cc:419] P 946b209f82f84450b3c66224d4dffd4c: Scheduling FlushDeltaMemStoresOp(aef78abd84f4476f8176fe51291037c3): perf score=2.188937
I20260812 06:18:21.476023 10790 maintenance_manager.cc:643] P 946b209f82f84450b3c66224d4dffd4c: FlushDeltaMemStoresOp(aef78abd84f4476f8176fe51291037c3) complete. Timing: real 0.017s	user 0.016s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6771,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:21.476486 10898 maintenance_manager.cc:419] P 946b209f82f84450b3c66224d4dffd4c: Scheduling MajorDeltaCompactionOp(aef78abd84f4476f8176fe51291037c3): perf score=1.000000
I20260812 06:18:21.650753 10790 maintenance_manager.cc:643] P 946b209f82f84450b3c66224d4dffd4c: MajorDeltaCompactionOp(aef78abd84f4476f8176fe51291037c3) complete. Timing: real 0.171s	user 0.108s	sys 0.061s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774690,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":725,"lbm_read_time_us":12859,"lbm_reads_lt_1ms":572,"lbm_write_time_us":29544,"lbm_writes_lt_1ms":543,"mutex_wait_us":292,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":9728,"update_count":2500}
I20260812 06:18:21.651480 10898 maintenance_manager.cc:419] P 946b209f82f84450b3c66224d4dffd4c: Scheduling FlushDeltaMemStoresOp(aef78abd84f4476f8176fe51291037c3): perf score=14.095187
I20260812 06:18:21.708632 10790 maintenance_manager.cc:643] P 946b209f82f84450b3c66224d4dffd4c: FlushDeltaMemStoresOp(aef78abd84f4476f8176fe51291037c3) complete. Timing: real 0.057s	user 0.021s	sys 0.034s Metrics: {"bytes_written":16409900,"delete_count":0,"lbm_write_time_us":20642,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:18:21.709210 10898 maintenance_manager.cc:419] P 946b209f82f84450b3c66224d4dffd4c: Scheduling FlushDeltaMemStoresOp(aef78abd84f4476f8176fe51291037c3): perf score=2.188937
I20260812 06:18:21.719928 10790 maintenance_manager.cc:643] P 946b209f82f84450b3c66224d4dffd4c: FlushDeltaMemStoresOp(aef78abd84f4476f8176fe51291037c3) complete. Timing: real 0.011s	user 0.005s	sys 0.005s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4228,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:21.720351 10898 maintenance_manager.cc:419] P 946b209f82f84450b3c66224d4dffd4c: Scheduling MajorDeltaCompactionOp(aef78abd84f4476f8176fe51291037c3): perf score=1.000000
I20260812 06:18:21.885567 10790 maintenance_manager.cc:643] P 946b209f82f84450b3c66224d4dffd4c: MajorDeltaCompactionOp(aef78abd84f4476f8176fe51291037c3) complete. Timing: real 0.165s	user 0.099s	sys 0.061s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774687,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":196,"lbm_read_time_us":12049,"lbm_reads_lt_1ms":572,"lbm_write_time_us":26100,"lbm_writes_lt_1ms":543,"peak_mem_usage":63115900,"reinsert_count":0,"update_count":2500}
I20260812 06:18:21.886152 10898 maintenance_manager.cc:419] P 946b209f82f84450b3c66224d4dffd4c: Scheduling FlushDeltaMemStoresOp(aef78abd84f4476f8176fe51291037c3): perf score=11.118625
I20260812 06:18:21.923305 10790 maintenance_manager.cc:643] P 946b209f82f84450b3c66224d4dffd4c: FlushDeltaMemStoresOp(aef78abd84f4476f8176fe51291037c3) complete. Timing: real 0.037s	user 0.021s	sys 0.016s Metrics: {"bytes_written":12717736,"delete_count":0,"lbm_write_time_us":14687,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:18:21.923871 10898 maintenance_manager.cc:419] P 946b209f82f84450b3c66224d4dffd4c: Scheduling FlushDeltaMemStoresOp(aef78abd84f4476f8176fe51291037c3): perf score=2.188937
I20260812 06:18:21.953605 10790 maintenance_manager.cc:643] P 946b209f82f84450b3c66224d4dffd4c: FlushDeltaMemStoresOp(aef78abd84f4476f8176fe51291037c3) complete. Timing: real 0.030s	user 0.002s	sys 0.016s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4395,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:21.954150 10898 maintenance_manager.cc:419] P 946b209f82f84450b3c66224d4dffd4c: Scheduling FlushDeltaMemStoresOp(aef78abd84f4476f8176fe51291037c3): perf score=2.188937
I20260812 06:18:21.965003 10790 maintenance_manager.cc:643] P 946b209f82f84450b3c66224d4dffd4c: FlushDeltaMemStoresOp(aef78abd84f4476f8176fe51291037c3) complete. Timing: real 0.011s	user 0.009s	sys 0.000s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":4035,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:18:21.965453 10898 maintenance_manager.cc:419] P 946b209f82f84450b3c66224d4dffd4c: Scheduling MajorDeltaCompactionOp(aef78abd84f4476f8176fe51291037c3): perf score=1.000000
I20260812 06:18:22.151738 10790 maintenance_manager.cc:643] P 946b209f82f84450b3c66224d4dffd4c: MajorDeltaCompactionOp(aef78abd84f4476f8176fe51291037c3) complete. Timing: real 0.186s	user 0.118s	sys 0.067s Metrics: {"cfile_cache_miss":533,"cfile_cache_miss_bytes":24774800,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":164,"lbm_read_time_us":12169,"lbm_reads_lt_1ms":573,"lbm_write_time_us":32126,"lbm_writes_lt_1ms":543,"mutex_wait_us":47,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":20352,"update_count":2500}
I20260812 06:18:22.152537 10898 maintenance_manager.cc:419] P 946b209f82f84450b3c66224d4dffd4c: Scheduling FlushDeltaMemStoresOp(aef78abd84f4476f8176fe51291037c3): perf score=10.126437
I20260812 06:18:22.196599 10790 maintenance_manager.cc:643] P 946b209f82f84450b3c66224d4dffd4c: FlushDeltaMemStoresOp(aef78abd84f4476f8176fe51291037c3) complete. Timing: real 0.044s	user 0.034s	sys 0.003s Metrics: {"bytes_written":12307492,"delete_count":0,"lbm_write_time_us":16340,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:18:22.197166 10898 maintenance_manager.cc:419] P 946b209f82f84450b3c66224d4dffd4c: Scheduling FlushDeltaMemStoresOp(aef78abd84f4476f8176fe51291037c3): perf score=2.188937
I20260812 06:18:22.211772 10790 maintenance_manager.cc:643] P 946b209f82f84450b3c66224d4dffd4c: FlushDeltaMemStoresOp(aef78abd84f4476f8176fe51291037c3) complete. Timing: real 0.014s	user 0.010s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5846,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:22.212371 10898 maintenance_manager.cc:419] P 946b209f82f84450b3c66224d4dffd4c: Scheduling FlushMRSOp(aef78abd84f4476f8176fe51291037c3): perf score=1.000000
I20260812 06:18:22.242861 10790 maintenance_manager.cc:643] P 946b209f82f84450b3c66224d4dffd4c: FlushMRSOp(aef78abd84f4476f8176fe51291037c3) complete. Timing: real 0.030s	user 0.025s	sys 0.004s Metrics: {"bytes_written":1275449,"cfile_init":1,"dirs.queue_time_us":72,"dirs.run_cpu_time_us":260,"dirs.run_wall_time_us":1202,"drs_written":1,"lbm_read_time_us":39,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1651,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":31}
I20260812 06:18:22.243516 10898 maintenance_manager.cc:419] P 946b209f82f84450b3c66224d4dffd4c: Scheduling LogGCOp(aef78abd84f4476f8176fe51291037c3): free 133024341 bytes of WAL
I20260812 06:18:22.243750 10790 log_reader.cc:385] T aef78abd84f4476f8176fe51291037c3: removed 13 log segments from log reader
I20260812 06:18:22.243798 10790 log.cc:1079] T aef78abd84f4476f8176fe51291037c3 P 946b209f82f84450b3c66224d4dffd4c: Deleting log segment in path: /tmp/dist-test-taskLBU3bg/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515493525939-10296-0/minicluster-data/ts-0-root/wals/aef78abd84f4476f8176fe51291037c3/wal-000000015 (ops 70-74)
I20260812 06:18:22.243826 10790 log.cc:1079] T aef78abd84f4476f8176fe51291037c3 P 946b209f82f84450b3c66224d4dffd4c: Deleting log segment in path: /tmp/dist-test-taskLBU3bg/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515493525939-10296-0/minicluster-data/ts-0-root/wals/aef78abd84f4476f8176fe51291037c3/wal-000000016 (ops 75-79)
I20260812 06:18:22.243888 10790 log.cc:1079] T aef78abd84f4476f8176fe51291037c3 P 946b209f82f84450b3c66224d4dffd4c: Deleting log segment in path: /tmp/dist-test-taskLBU3bg/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515493525939-10296-0/minicluster-data/ts-0-root/wals/aef78abd84f4476f8176fe51291037c3/wal-000000017 (ops 80-84)
I20260812 06:18:22.243934 10790 log.cc:1079] T aef78abd84f4476f8176fe51291037c3 P 946b209f82f84450b3c66224d4dffd4c: Deleting log segment in path: /tmp/dist-test-taskLBU3bg/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515493525939-10296-0/minicluster-data/ts-0-root/wals/aef78abd84f4476f8176fe51291037c3/wal-000000018 (ops 85-89)
I20260812 06:18:22.243980 10790 log.cc:1079] T aef78abd84f4476f8176fe51291037c3 P 946b209f82f84450b3c66224d4dffd4c: Deleting log segment in path: /tmp/dist-test-taskLBU3bg/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515493525939-10296-0/minicluster-data/ts-0-root/wals/aef78abd84f4476f8176fe51291037c3/wal-000000019 (ops 90-94)
I20260812 06:18:22.244024 10790 log.cc:1079] T aef78abd84f4476f8176fe51291037c3 P 946b209f82f84450b3c66224d4dffd4c: Deleting log segment in path: /tmp/dist-test-taskLBU3bg/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515493525939-10296-0/minicluster-data/ts-0-root/wals/aef78abd84f4476f8176fe51291037c3/wal-000000020 (ops 95-99)
I20260812 06:18:22.244065 10790 log.cc:1079] T aef78abd84f4476f8176fe51291037c3 P 946b209f82f84450b3c66224d4dffd4c: Deleting log segment in path: /tmp/dist-test-taskLBU3bg/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515493525939-10296-0/minicluster-data/ts-0-root/wals/aef78abd84f4476f8176fe51291037c3/wal-000000021 (ops 100-104)
I20260812 06:18:22.244117 10790 log.cc:1079] T aef78abd84f4476f8176fe51291037c3 P 946b209f82f84450b3c66224d4dffd4c: Deleting log segment in path: /tmp/dist-test-taskLBU3bg/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515493525939-10296-0/minicluster-data/ts-0-root/wals/aef78abd84f4476f8176fe51291037c3/wal-000000022 (ops 105-108)
I20260812 06:18:22.244141 10790 log.cc:1079] T aef78abd84f4476f8176fe51291037c3 P 946b209f82f84450b3c66224d4dffd4c: Deleting log segment in path: /tmp/dist-test-taskLBU3bg/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515493525939-10296-0/minicluster-data/ts-0-root/wals/aef78abd84f4476f8176fe51291037c3/wal-000000023 (ops 109-113)
I20260812 06:18:22.244200 10790 log.cc:1079] T aef78abd84f4476f8176fe51291037c3 P 946b209f82f84450b3c66224d4dffd4c: Deleting log segment in path: /tmp/dist-test-taskLBU3bg/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515493525939-10296-0/minicluster-data/ts-0-root/wals/aef78abd84f4476f8176fe51291037c3/wal-000000024 (ops 114-118)
I20260812 06:18:22.244240 10790 log.cc:1079] T aef78abd84f4476f8176fe51291037c3 P 946b209f82f84450b3c66224d4dffd4c: Deleting log segment in path: /tmp/dist-test-taskLBU3bg/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515493525939-10296-0/minicluster-data/ts-0-root/wals/aef78abd84f4476f8176fe51291037c3/wal-000000025 (ops 119-123)
I20260812 06:18:22.244279 10790 log.cc:1079] T aef78abd84f4476f8176fe51291037c3 P 946b209f82f84450b3c66224d4dffd4c: Deleting log segment in path: /tmp/dist-test-taskLBU3bg/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515493525939-10296-0/minicluster-data/ts-0-root/wals/aef78abd84f4476f8176fe51291037c3/wal-000000026 (ops 124-128)
I20260812 06:18:22.244321 10790 log.cc:1079] T aef78abd84f4476f8176fe51291037c3 P 946b209f82f84450b3c66224d4dffd4c: Deleting log segment in path: /tmp/dist-test-taskLBU3bg/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515493525939-10296-0/minicluster-data/ts-0-root/wals/aef78abd84f4476f8176fe51291037c3/wal-000000027 (ops 129-133)
I20260812 06:18:22.272336 10790 maintenance_manager.cc:643] P 946b209f82f84450b3c66224d4dffd4c: LogGCOp(aef78abd84f4476f8176fe51291037c3) complete. Timing: real 0.029s	user 0.000s	sys 0.027s Metrics: {}
I20260812 06:18:22.272773 10898 maintenance_manager.cc:419] P 946b209f82f84450b3c66224d4dffd4c: Scheduling UndoDeltaBlockGCOp(aef78abd84f4476f8176fe51291037c3): 483 bytes on disk
I20260812 06:18:22.273222 10790 maintenance_manager.cc:643] P 946b209f82f84450b3c66224d4dffd4c: UndoDeltaBlockGCOp(aef78abd84f4476f8176fe51291037c3) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":53,"lbm_reads_lt_1ms":4}
I20260812 06:18:22.273734 10898 maintenance_manager.cc:419] P 946b209f82f84450b3c66224d4dffd4c: Scheduling FlushDeltaMemStoresOp(aef78abd84f4476f8176fe51291037c3): perf score=3.181125
I20260812 06:18:22.292061 10790 maintenance_manager.cc:643] P 946b209f82f84450b3c66224d4dffd4c: FlushDeltaMemStoresOp(aef78abd84f4476f8176fe51291037c3) complete. Timing: real 0.018s	user 0.014s	sys 0.000s Metrics: {"bytes_written":4512900,"delete_count":0,"lbm_write_time_us":5548,"lbm_writes_lt_1ms":113,"reinsert_count":0,"update_count":550}
I20260812 06:18:22.292655 10898 maintenance_manager.cc:419] P 946b209f82f84450b3c66224d4dffd4c: Scheduling FlushDeltaMemStoresOp(aef78abd84f4476f8176fe51291037c3): perf score=2.188937
I20260812 06:18:22.304136 10790 maintenance_manager.cc:643] P 946b209f82f84450b3c66224d4dffd4c: FlushDeltaMemStoresOp(aef78abd84f4476f8176fe51291037c3) complete. Timing: real 0.011s	user 0.009s	sys 0.001s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":4421,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:18:22.304615 10898 maintenance_manager.cc:419] P 946b209f82f84450b3c66224d4dffd4c: Scheduling MajorDeltaCompactionOp(aef78abd84f4476f8176fe51291037c3): perf score=1.000000
I20260812 06:18:22.522958 10790 maintenance_manager.cc:643] P 946b209f82f84450b3c66224d4dffd4c: MajorDeltaCompactionOp(aef78abd84f4476f8176fe51291037c3) complete. Timing: real 0.218s	user 0.146s	sys 0.067s Metrics: {"cfile_cache_miss":634,"cfile_cache_miss_bytes":28877328,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":698,"lbm_read_time_us":15960,"lbm_reads_lt_1ms":674,"lbm_write_time_us":38090,"lbm_writes_lt_1ms":643,"mutex_wait_us":45,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":6656,"thread_start_us":82,"threads_started":1,"update_count":3000}
I20260812 06:18:22.523712 10898 maintenance_manager.cc:419] P 946b209f82f84450b3c66224d4dffd4c: Scheduling FlushDeltaMemStoresOp(aef78abd84f4476f8176fe51291037c3): perf score=18.063937
I20260812 06:18:22.590791 10790 maintenance_manager.cc:643] P 946b209f82f84450b3c66224d4dffd4c: FlushDeltaMemStoresOp(aef78abd84f4476f8176fe51291037c3) complete. Timing: real 0.067s	user 0.039s	sys 0.024s Metrics: {"bytes_written":20512316,"delete_count":0,"lbm_write_time_us":30800,"lbm_writes_lt_1ms":503,"reinsert_count":0,"update_count":2500}
I20260812 06:18:22.591460 10898 maintenance_manager.cc:419] P 946b209f82f84450b3c66224d4dffd4c: Scheduling FlushDeltaMemStoresOp(aef78abd84f4476f8176fe51291037c3): perf score=2.188937
I20260812 06:18:22.604542 10790 maintenance_manager.cc:643] P 946b209f82f84450b3c66224d4dffd4c: FlushDeltaMemStoresOp(aef78abd84f4476f8176fe51291037c3) complete. Timing: real 0.013s	user 0.006s	sys 0.006s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4981,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:22.605029 10898 maintenance_manager.cc:419] P 946b209f82f84450b3c66224d4dffd4c: Scheduling MajorDeltaCompactionOp(aef78abd84f4476f8176fe51291037c3): perf score=1.000000
I20260812 06:18:22.819263 10790 maintenance_manager.cc:643] P 946b209f82f84450b3c66224d4dffd4c: MajorDeltaCompactionOp(aef78abd84f4476f8176fe51291037c3) complete. Timing: real 0.214s	user 0.131s	sys 0.069s Metrics: {"cfile_cache_miss":632,"cfile_cache_miss_bytes":28877103,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":887,"lbm_read_time_us":13085,"lbm_reads_lt_1ms":672,"lbm_write_time_us":34219,"lbm_writes_lt_1ms":643,"mutex_wait_us":350,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":1280,"update_count":3000}
I20260812 06:18:22.820039 10898 maintenance_manager.cc:419] P 946b209f82f84450b3c66224d4dffd4c: Scheduling FlushDeltaMemStoresOp(aef78abd84f4476f8176fe51291037c3): perf score=18.063937
I20260812 06:18:22.887888 10790 maintenance_manager.cc:643] P 946b209f82f84450b3c66224d4dffd4c: FlushDeltaMemStoresOp(aef78abd84f4476f8176fe51291037c3) complete. Timing: real 0.068s	user 0.054s	sys 0.007s Metrics: {"bytes_written":20512318,"delete_count":0,"lbm_write_time_us":27442,"lbm_writes_lt_1ms":503,"reinsert_count":0,"update_count":2500}
I20260812 06:18:22.888399 10898 maintenance_manager.cc:419] P 946b209f82f84450b3c66224d4dffd4c: Scheduling FlushDeltaMemStoresOp(aef78abd84f4476f8176fe51291037c3): perf score=2.188937
I20260812 06:18:22.898980 10790 maintenance_manager.cc:643] P 946b209f82f84450b3c66224d4dffd4c: FlushDeltaMemStoresOp(aef78abd84f4476f8176fe51291037c3) complete. Timing: real 0.010s	user 0.005s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4100,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:22.899549 10898 maintenance_manager.cc:419] P 946b209f82f84450b3c66224d4dffd4c: Scheduling MajorDeltaCompactionOp(aef78abd84f4476f8176fe51291037c3): perf score=1.000000
I20260812 06:18:23.101547 10790 maintenance_manager.cc:643] P 946b209f82f84450b3c66224d4dffd4c: MajorDeltaCompactionOp(aef78abd84f4476f8176fe51291037c3) complete. Timing: real 0.202s	user 0.118s	sys 0.079s Metrics: {"cfile_cache_miss":632,"cfile_cache_miss_bytes":28877105,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":887,"lbm_read_time_us":14520,"lbm_reads_lt_1ms":672,"lbm_write_time_us":34882,"lbm_writes_lt_1ms":643,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":11648,"update_count":3000}
I20260812 06:18:23.102269 10898 maintenance_manager.cc:419] P 946b209f82f84450b3c66224d4dffd4c: Scheduling FlushDeltaMemStoresOp(aef78abd84f4476f8176fe51291037c3): perf score=14.095187
I20260812 06:18:23.163259 10790 maintenance_manager.cc:643] P 946b209f82f84450b3c66224d4dffd4c: FlushDeltaMemStoresOp(aef78abd84f4476f8176fe51291037c3) complete. Timing: real 0.061s	user 0.034s	sys 0.011s Metrics: {"bytes_written":16409903,"delete_count":0,"lbm_write_time_us":20273,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:18:23.163719 10898 maintenance_manager.cc:419] P 946b209f82f84450b3c66224d4dffd4c: Scheduling FlushDeltaMemStoresOp(aef78abd84f4476f8176fe51291037c3): perf score=2.188937
I20260812 06:18:23.176033 10790 maintenance_manager.cc:643] P 946b209f82f84450b3c66224d4dffd4c: FlushDeltaMemStoresOp(aef78abd84f4476f8176fe51291037c3) complete. Timing: real 0.012s	user 0.007s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4341,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:23.176865 10898 maintenance_manager.cc:419] P 946b209f82f84450b3c66224d4dffd4c: Scheduling MajorDeltaCompactionOp(aef78abd84f4476f8176fe51291037c3): perf score=1.000000
I20260812 06:18:23.366717 10790 maintenance_manager.cc:643] P 946b209f82f84450b3c66224d4dffd4c: MajorDeltaCompactionOp(aef78abd84f4476f8176fe51291037c3) complete. Timing: real 0.190s	user 0.137s	sys 0.044s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774690,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":328,"lbm_read_time_us":12698,"lbm_reads_lt_1ms":572,"lbm_write_time_us":31540,"lbm_writes_lt_1ms":543,"mutex_wait_us":25,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":9472,"update_count":2500}
I20260812 06:18:23.367352 10898 maintenance_manager.cc:419] P 946b209f82f84450b3c66224d4dffd4c: Scheduling FlushDeltaMemStoresOp(aef78abd84f4476f8176fe51291037c3): perf score=14.095187
I20260812 06:18:23.428637 10790 maintenance_manager.cc:643] P 946b209f82f84450b3c66224d4dffd4c: FlushDeltaMemStoresOp(aef78abd84f4476f8176fe51291037c3) complete. Timing: real 0.059s	user 0.037s	sys 0.019s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":20101,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:18:23.429216 10898 maintenance_manager.cc:419] P 946b209f82f84450b3c66224d4dffd4c: Scheduling FlushDeltaMemStoresOp(aef78abd84f4476f8176fe51291037c3): perf score=2.188937
I20260812 06:18:23.446768 10790 maintenance_manager.cc:643] P 946b209f82f84450b3c66224d4dffd4c: FlushDeltaMemStoresOp(aef78abd84f4476f8176fe51291037c3) complete. Timing: real 0.017s	user 0.011s	sys 0.004s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":6524,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:23.447486 10898 maintenance_manager.cc:419] P 946b209f82f84450b3c66224d4dffd4c: Scheduling MajorDeltaCompactionOp(aef78abd84f4476f8176fe51291037c3): perf score=1.000000
I20260812 06:18:23.620745 10790 maintenance_manager.cc:643] P 946b209f82f84450b3c66224d4dffd4c: MajorDeltaCompactionOp(aef78abd84f4476f8176fe51291037c3) complete. Timing: real 0.173s	user 0.118s	sys 0.051s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774687,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":227,"lbm_read_time_us":12422,"lbm_reads_lt_1ms":572,"lbm_write_time_us":28098,"lbm_writes_lt_1ms":543,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":768,"update_count":2500}
I20260812 06:18:23.621358 10898 maintenance_manager.cc:419] P 946b209f82f84450b3c66224d4dffd4c: Scheduling FlushDeltaMemStoresOp(aef78abd84f4476f8176fe51291037c3): perf score=11.118625
I20260812 06:18:23.656687 10790 maintenance_manager.cc:643] P 946b209f82f84450b3c66224d4dffd4c: FlushDeltaMemStoresOp(aef78abd84f4476f8176fe51291037c3) complete. Timing: real 0.035s	user 0.021s	sys 0.012s Metrics: {"bytes_written":12717736,"delete_count":0,"lbm_write_time_us":15471,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:18:23.657269 10898 maintenance_manager.cc:419] P 946b209f82f84450b3c66224d4dffd4c: Scheduling FlushDeltaMemStoresOp(aef78abd84f4476f8176fe51291037c3): perf score=2.188937
I20260812 06:18:23.676277 10790 maintenance_manager.cc:643] P 946b209f82f84450b3c66224d4dffd4c: FlushDeltaMemStoresOp(aef78abd84f4476f8176fe51291037c3) complete. Timing: real 0.019s	user 0.007s	sys 0.011s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":4709,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:18:23.676916 10898 maintenance_manager.cc:419] P 946b209f82f84450b3c66224d4dffd4c: Scheduling FlushMRSOp(aef78abd84f4476f8176fe51291037c3): perf score=1.000000
I20260812 06:18:23.736306 10790 maintenance_manager.cc:643] P 946b209f82f84450b3c66224d4dffd4c: FlushMRSOp(aef78abd84f4476f8176fe51291037c3) complete. Timing: real 0.059s	user 0.025s	sys 0.004s Metrics: {"bytes_written":1152512,"cfile_init":1,"dirs.queue_time_us":73,"dirs.run_cpu_time_us":275,"dirs.run_wall_time_us":1290,"drs_written":1,"lbm_read_time_us":43,"lbm_reads_lt_1ms":4,"lbm_write_time_us":2256,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":28}
I20260812 06:18:23.737004 10898 maintenance_manager.cc:419] P 946b209f82f84450b3c66224d4dffd4c: Scheduling LogGCOp(aef78abd84f4476f8176fe51291037c3): free 111786550 bytes of WAL
I20260812 06:18:23.737254 10790 log_reader.cc:385] T aef78abd84f4476f8176fe51291037c3: removed 11 log segments from log reader
I20260812 06:18:23.737298 10790 log.cc:1079] T aef78abd84f4476f8176fe51291037c3 P 946b209f82f84450b3c66224d4dffd4c: Deleting log segment in path: /tmp/dist-test-taskLBU3bg/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515493525939-10296-0/minicluster-data/ts-0-root/wals/aef78abd84f4476f8176fe51291037c3/wal-000000028 (ops 134-138)
I20260812 06:18:23.737327 10790 log.cc:1079] T aef78abd84f4476f8176fe51291037c3 P 946b209f82f84450b3c66224d4dffd4c: Deleting log segment in path: /tmp/dist-test-taskLBU3bg/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515493525939-10296-0/minicluster-data/ts-0-root/wals/aef78abd84f4476f8176fe51291037c3/wal-000000029 (ops 139-143)
I20260812 06:18:23.737391 10790 log.cc:1079] T aef78abd84f4476f8176fe51291037c3 P 946b209f82f84450b3c66224d4dffd4c: Deleting log segment in path: /tmp/dist-test-taskLBU3bg/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515493525939-10296-0/minicluster-data/ts-0-root/wals/aef78abd84f4476f8176fe51291037c3/wal-000000030 (ops 144-148)
I20260812 06:18:23.737432 10790 log.cc:1079] T aef78abd84f4476f8176fe51291037c3 P 946b209f82f84450b3c66224d4dffd4c: Deleting log segment in path: /tmp/dist-test-taskLBU3bg/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515493525939-10296-0/minicluster-data/ts-0-root/wals/aef78abd84f4476f8176fe51291037c3/wal-000000031 (ops 149-152)
I20260812 06:18:23.737473 10790 log.cc:1079] T aef78abd84f4476f8176fe51291037c3 P 946b209f82f84450b3c66224d4dffd4c: Deleting log segment in path: /tmp/dist-test-taskLBU3bg/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515493525939-10296-0/minicluster-data/ts-0-root/wals/aef78abd84f4476f8176fe51291037c3/wal-000000032 (ops 153-157)
I20260812 06:18:23.737514 10790 log.cc:1079] T aef78abd84f4476f8176fe51291037c3 P 946b209f82f84450b3c66224d4dffd4c: Deleting log segment in path: /tmp/dist-test-taskLBU3bg/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515493525939-10296-0/minicluster-data/ts-0-root/wals/aef78abd84f4476f8176fe51291037c3/wal-000000033 (ops 158-162)
I20260812 06:18:23.737550 10790 log.cc:1079] T aef78abd84f4476f8176fe51291037c3 P 946b209f82f84450b3c66224d4dffd4c: Deleting log segment in path: /tmp/dist-test-taskLBU3bg/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515493525939-10296-0/minicluster-data/ts-0-root/wals/aef78abd84f4476f8176fe51291037c3/wal-000000034 (ops 163-166)
I20260812 06:18:23.737586 10790 log.cc:1079] T aef78abd84f4476f8176fe51291037c3 P 946b209f82f84450b3c66224d4dffd4c: Deleting log segment in path: /tmp/dist-test-taskLBU3bg/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515493525939-10296-0/minicluster-data/ts-0-root/wals/aef78abd84f4476f8176fe51291037c3/wal-000000035 (ops 167-171)
I20260812 06:18:23.737632 10790 log.cc:1079] T aef78abd84f4476f8176fe51291037c3 P 946b209f82f84450b3c66224d4dffd4c: Deleting log segment in path: /tmp/dist-test-taskLBU3bg/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515493525939-10296-0/minicluster-data/ts-0-root/wals/aef78abd84f4476f8176fe51291037c3/wal-000000036 (ops 172-176)
I20260812 06:18:23.737670 10790 log.cc:1079] T aef78abd84f4476f8176fe51291037c3 P 946b209f82f84450b3c66224d4dffd4c: Deleting log segment in path: /tmp/dist-test-taskLBU3bg/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515493525939-10296-0/minicluster-data/ts-0-root/wals/aef78abd84f4476f8176fe51291037c3/wal-000000037 (ops 177-181)
I20260812 06:18:23.737707 10790 log.cc:1079] T aef78abd84f4476f8176fe51291037c3 P 946b209f82f84450b3c66224d4dffd4c: Deleting log segment in path: /tmp/dist-test-taskLBU3bg/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515493525939-10296-0/minicluster-data/ts-0-root/wals/aef78abd84f4476f8176fe51291037c3/wal-000000038 (ops 182-186)
I20260812 06:18:23.762065 10790 maintenance_manager.cc:643] P 946b209f82f84450b3c66224d4dffd4c: LogGCOp(aef78abd84f4476f8176fe51291037c3) complete. Timing: real 0.025s	user 0.003s	sys 0.019s Metrics: {}
I20260812 06:18:23.762499 10898 maintenance_manager.cc:419] P 946b209f82f84450b3c66224d4dffd4c: Scheduling FlushDeltaMemStoresOp(aef78abd84f4476f8176fe51291037c3): perf score=6.157687
I20260812 06:18:23.789909 10790 maintenance_manager.cc:643] P 946b209f82f84450b3c66224d4dffd4c: FlushDeltaMemStoresOp(aef78abd84f4476f8176fe51291037c3) complete. Timing: real 0.027s	user 0.012s	sys 0.012s Metrics: {"bytes_written":8205078,"delete_count":0,"lbm_write_time_us":11621,"lbm_writes_lt_1ms":203,"reinsert_count":0,"update_count":1000}
I20260812 06:18:23.790515 10898 maintenance_manager.cc:419] P 946b209f82f84450b3c66224d4dffd4c: Scheduling UndoDeltaBlockGCOp(aef78abd84f4476f8176fe51291037c3): 447 bytes on disk
I20260812 06:18:23.791003 10790 maintenance_manager.cc:643] P 946b209f82f84450b3c66224d4dffd4c: UndoDeltaBlockGCOp(aef78abd84f4476f8176fe51291037c3) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":51,"lbm_reads_lt_1ms":4}
I20260812 06:18:23.791569 10898 maintenance_manager.cc:419] P 946b209f82f84450b3c66224d4dffd4c: Scheduling FlushDeltaMemStoresOp(aef78abd84f4476f8176fe51291037c3): perf score=2.188937
I20260812 06:18:23.802367 10790 maintenance_manager.cc:643] P 946b209f82f84450b3c66224d4dffd4c: FlushDeltaMemStoresOp(aef78abd84f4476f8176fe51291037c3) complete. Timing: real 0.011s	user 0.006s	sys 0.003s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4186,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:23.803129 10898 maintenance_manager.cc:419] P 946b209f82f84450b3c66224d4dffd4c: Scheduling MajorDeltaCompactionOp(aef78abd84f4476f8176fe51291037c3): perf score=1.000000
I20260812 06:18:23.993809 10296 heavy-update-compaction-itest.cc:229] Time spent updating: real 4.913s	user 1.863s	sys 0.170s
I20260812 06:18:24.025581 10790 maintenance_manager.cc:643] P 946b209f82f84450b3c66224d4dffd4c: MajorDeltaCompactionOp(aef78abd84f4476f8176fe51291037c3) complete. Timing: real 0.222s	user 0.157s	sys 0.063s Metrics: {"cfile_cache_miss":734,"cfile_cache_miss_bytes":32979744,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"lbm_read_time_us":16274,"lbm_reads_lt_1ms":770,"lbm_write_time_us":39853,"lbm_writes_lt_1ms":743,"peak_mem_usage":87969044,"reinsert_count":0,"spinlock_wait_cycles":6400,"update_count":3500}
I20260812 06:18:24.026144 10898 maintenance_manager.cc:419] P 946b209f82f84450b3c66224d4dffd4c: Scheduling FlushDeltaMemStoresOp(aef78abd84f4476f8176fe51291037c3): perf score=14.095187
I20260812 06:18:24.059577 10790 maintenance_manager.cc:643] P 946b209f82f84450b3c66224d4dffd4c: FlushDeltaMemStoresOp(aef78abd84f4476f8176fe51291037c3) complete. Timing: real 0.033s	user 0.020s	sys 0.013s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":16153,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:18:24.060053 10898 maintenance_manager.cc:419] P 946b209f82f84450b3c66224d4dffd4c: Scheduling MajorDeltaCompactionOp(aef78abd84f4476f8176fe51291037c3): perf score=1.000000
I20260812 06:18:24.101025 10296 heavy-update-compaction-itest.cc:265] Time spent scanning: real 0.107s	user 0.001s	sys 0.000s
I20260812 06:18:24.101562 10296 tablet_server.cc:179] TabletServer@127.10.14.1:0 shutting down...
I20260812 06:18:24.188679 10790 maintenance_manager.cc:643] P 946b209f82f84450b3c66224d4dffd4c: MajorDeltaCompactionOp(aef78abd84f4476f8176fe51291037c3) complete. Timing: real 0.128s	user 0.072s	sys 0.057s Metrics: {"cfile_cache_miss":431,"cfile_cache_miss_bytes":20672158,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":1,"delta_iterators_relevant":1,"dirs.queue_time_us":665,"lbm_read_time_us":9138,"lbm_reads_lt_1ms":467,"lbm_write_time_us":26647,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":442,"mutex_wait_us":105,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":13568,"update_count":2000}
I20260812 06:18:24.189424 10296 ts_tablet_manager.cc:1507] Shutting down tablet manager...
I20260812 06:18:24.191303 10296 tablet_replica.cc:333] T aef78abd84f4476f8176fe51291037c3 P 946b209f82f84450b3c66224d4dffd4c: stopping tablet replica
I20260812 06:18:24.191490 10296 raft_consensus.cc:2243] T aef78abd84f4476f8176fe51291037c3 P 946b209f82f84450b3c66224d4dffd4c [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:18:24.191672 10296 raft_consensus.cc:2272] T aef78abd84f4476f8176fe51291037c3 P 946b209f82f84450b3c66224d4dffd4c [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:18:24.205559 10296 tablet_server.cc:196] TabletServer@127.10.14.1:0 shutdown complete.
I20260812 06:18:24.226915 10296 master.cc:562] Master@127.10.14.62:37849 shutting down...
I20260812 06:18:24.230358 10296 raft_consensus.cc:2243] T 00000000000000000000000000000000 P d8c1161ff053496a9da39375c9a6067c [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:18:24.230576 10296 raft_consensus.cc:2272] T 00000000000000000000000000000000 P d8c1161ff053496a9da39375c9a6067c [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:18:24.230640 10296 tablet_replica.cc:333] T 00000000000000000000000000000000 P d8c1161ff053496a9da39375c9a6067c: stopping tablet replica
I20260812 06:18:24.244458 10296 master.cc:584] Master@127.10.14.62:37849 shutdown complete.
[       OK ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/1 (5449 ms)
[----------] 2 tests from EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy (10797 ms total)

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