[==========] 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:19:20.715219  7469 internal_mini_cluster.cc:156] Creating distributed mini masters. Addrs: 127.7.75.126:41833
I20260812 06:19:20.716279  7469 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:19:20.716897  7469 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:19:20.723981  7474 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:19:20.724078  7469 server_base.cc:1061] running on GCE node
W20260812 06:19:20.724275  7475 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:19:20.723976  7479 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:19:20.724828  7469 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:19:20.724963  7469 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:19:20.725013  7469 hybrid_clock.cc:648] HybridClock initialized: now 1786515560725010 us; error 0 us; skew 500 ppm
I20260812 06:19:20.727118  7469 webserver.cc:533] Webserver started at http://127.7.75.126:38749/ using document root <none> and password file <none>
I20260812 06:19:20.727691  7469 fs_manager.cc:362] Metadata directory not provided
I20260812 06:19:20.727780  7469 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:19:20.728024  7469 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:19:20.729650  7469 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-task4BgTQF/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515560703209-7469-0/minicluster-data/master-0-root/instance:
uuid: "2553ff6c23a546b58a500d2187a652e0"
format_stamp: "Formatted at 2026-08-12 06:19:20 on dist-test-slave-drl0"
I20260812 06:19:20.733325  7469 fs_manager.cc:696] Time spent creating directory manager: real 0.003s	user 0.005s	sys 0.000s
I20260812 06:19:20.735617  7488 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:19:20.736965  7469 fs_manager.cc:730] Time spent opening block manager: real 0.002s	user 0.002s	sys 0.000s
I20260812 06:19:20.737279  7469 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-task4BgTQF/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515560703209-7469-0/minicluster-data/master-0-root
uuid: "2553ff6c23a546b58a500d2187a652e0"
format_stamp: "Formatted at 2026-08-12 06:19:20 on dist-test-slave-drl0"
I20260812 06:19:20.737408  7469 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-task4BgTQF/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515560703209-7469-0/minicluster-data/master-0-root
metadata directory: /tmp/dist-test-task4BgTQF/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515560703209-7469-0/minicluster-data/master-0-root
1 data directories: /tmp/dist-test-task4BgTQF/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515560703209-7469-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:19:20.754036  7469 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:19:20.755138  7469 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:19:20.755362  7469 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:19:20.763967  7469 rpc_server.cc:307] RPC server started. Bound to: 127.7.75.126:41833
I20260812 06:19:20.764101  7578 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.7.75.126:41833 every 8 connection(s)
I20260812 06:19:20.766458  7579 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:19:20.772210  7579 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P 2553ff6c23a546b58a500d2187a652e0: Bootstrap starting.
I20260812 06:19:20.774684  7579 tablet_bootstrap.cc:654] T 00000000000000000000000000000000 P 2553ff6c23a546b58a500d2187a652e0: Neither blocks nor log segments found. Creating new log.
I20260812 06:19:20.775628  7579 log.cc:826] T 00000000000000000000000000000000 P 2553ff6c23a546b58a500d2187a652e0: Log is configured to *not* fsync() on all Append() calls
I20260812 06:19:20.777489  7579 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P 2553ff6c23a546b58a500d2187a652e0: No bootstrap required, opened a new log
I20260812 06:19:20.780360  7579 raft_consensus.cc:359] T 00000000000000000000000000000000 P 2553ff6c23a546b58a500d2187a652e0 [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "2553ff6c23a546b58a500d2187a652e0" member_type: VOTER }
I20260812 06:19:20.780529  7579 raft_consensus.cc:385] T 00000000000000000000000000000000 P 2553ff6c23a546b58a500d2187a652e0 [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:19:20.780570  7579 raft_consensus.cc:740] T 00000000000000000000000000000000 P 2553ff6c23a546b58a500d2187a652e0 [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: 2553ff6c23a546b58a500d2187a652e0, State: Initialized, Role: FOLLOWER
I20260812 06:19:20.781289  7579 consensus_queue.cc:260] T 00000000000000000000000000000000 P 2553ff6c23a546b58a500d2187a652e0 [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: "2553ff6c23a546b58a500d2187a652e0" member_type: VOTER }
I20260812 06:19:20.781440  7579 raft_consensus.cc:399] T 00000000000000000000000000000000 P 2553ff6c23a546b58a500d2187a652e0 [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:19:20.781482  7579 raft_consensus.cc:493] T 00000000000000000000000000000000 P 2553ff6c23a546b58a500d2187a652e0 [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:19:20.781610  7579 raft_consensus.cc:3060] T 00000000000000000000000000000000 P 2553ff6c23a546b58a500d2187a652e0 [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:19:20.782394  7579 raft_consensus.cc:515] T 00000000000000000000000000000000 P 2553ff6c23a546b58a500d2187a652e0 [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "2553ff6c23a546b58a500d2187a652e0" member_type: VOTER }
I20260812 06:19:20.782851  7579 leader_election.cc:304] T 00000000000000000000000000000000 P 2553ff6c23a546b58a500d2187a652e0 [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: 2553ff6c23a546b58a500d2187a652e0; no voters: 
I20260812 06:19:20.783203  7579 leader_election.cc:290] T 00000000000000000000000000000000 P 2553ff6c23a546b58a500d2187a652e0 [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:19:20.783371  7585 raft_consensus.cc:2804] T 00000000000000000000000000000000 P 2553ff6c23a546b58a500d2187a652e0 [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:19:20.783635  7585 raft_consensus.cc:697] T 00000000000000000000000000000000 P 2553ff6c23a546b58a500d2187a652e0 [term 1 LEADER]: Becoming Leader. State: Replica: 2553ff6c23a546b58a500d2187a652e0, State: Running, Role: LEADER
I20260812 06:19:20.784039  7585 consensus_queue.cc:237] T 00000000000000000000000000000000 P 2553ff6c23a546b58a500d2187a652e0 [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: "2553ff6c23a546b58a500d2187a652e0" member_type: VOTER }
I20260812 06:19:20.784198  7579 sys_catalog.cc:565] T 00000000000000000000000000000000 P 2553ff6c23a546b58a500d2187a652e0 [sys.catalog]: configured and running, proceeding with master startup.
I20260812 06:19:20.785904  7587 sys_catalog.cc:455] T 00000000000000000000000000000000 P 2553ff6c23a546b58a500d2187a652e0 [sys.catalog]: SysCatalogTable state changed. Reason: RaftConsensus started. Latest consensus state: current_term: 1 leader_uuid: "2553ff6c23a546b58a500d2187a652e0" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "2553ff6c23a546b58a500d2187a652e0" member_type: VOTER } }
I20260812 06:19:20.785953  7589 sys_catalog.cc:455] T 00000000000000000000000000000000 P 2553ff6c23a546b58a500d2187a652e0 [sys.catalog]: SysCatalogTable state changed. Reason: New leader 2553ff6c23a546b58a500d2187a652e0. Latest consensus state: current_term: 1 leader_uuid: "2553ff6c23a546b58a500d2187a652e0" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "2553ff6c23a546b58a500d2187a652e0" member_type: VOTER } }
I20260812 06:19:20.786069  7589 sys_catalog.cc:458] T 00000000000000000000000000000000 P 2553ff6c23a546b58a500d2187a652e0 [sys.catalog]: This master's current role is: LEADER
I20260812 06:19:20.786010  7587 sys_catalog.cc:458] T 00000000000000000000000000000000 P 2553ff6c23a546b58a500d2187a652e0 [sys.catalog]: This master's current role is: LEADER
I20260812 06:19:20.786559  7602 catalog_manager.cc:1511] Loading table and tablet metadata into memory...
I20260812 06:19:20.786660  7469 internal_mini_cluster.cc:184] Waiting to initialize catalog manager on master 0
I20260812 06:19:20.789382  7602 catalog_manager.cc:1520] Initializing Kudu cluster ID...
I20260812 06:19:20.794104  7602 catalog_manager.cc:1383] Generated new cluster ID: 2e917f24dc0545e9b35edba743b8a87e
I20260812 06:19:20.794170  7602 catalog_manager.cc:1531] Initializing Kudu internal certificate authority...
I20260812 06:19:20.827834  7602 catalog_manager.cc:1406] Generated new certificate authority record
I20260812 06:19:20.829034  7602 catalog_manager.cc:1540] Loading token signing keys...
I20260812 06:19:20.834753  7602 catalog_manager.cc:6092] T 00000000000000000000000000000000 P 2553ff6c23a546b58a500d2187a652e0: Generated new TSK 0
I20260812 06:19:20.835671  7602 catalog_manager.cc:1550] Initializing in-progress tserver states...
I20260812 06:19:20.852406  7469 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:19:20.855662  7612 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:19:20.855849  7469 server_base.cc:1061] running on GCE node
W20260812 06:19:20.855984  7613 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:19:20.855736  7615 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:19:20.856343  7469 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:19:20.856412  7469 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:19:20.856439  7469 hybrid_clock.cc:648] HybridClock initialized: now 1786515560856438 us; error 0 us; skew 500 ppm
I20260812 06:19:20.857748  7469 webserver.cc:533] Webserver started at http://127.7.75.65:40337/ using document root <none> and password file <none>
I20260812 06:19:20.858047  7469 fs_manager.cc:362] Metadata directory not provided
I20260812 06:19:20.858143  7469 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:19:20.858248  7469 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:19:20.858778  7469 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-task4BgTQF/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515560703209-7469-0/minicluster-data/ts-0-root/instance:
uuid: "a4c03b44f7b54441810db27ae31a30b9"
format_stamp: "Formatted at 2026-08-12 06:19:20 on dist-test-slave-drl0"
I20260812 06:19:20.860844  7469 fs_manager.cc:696] Time spent creating directory manager: real 0.002s	user 0.000s	sys 0.002s
I20260812 06:19:20.862160  7624 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:19:20.862442  7469 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.000s	sys 0.001s
I20260812 06:19:20.862511  7469 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-task4BgTQF/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515560703209-7469-0/minicluster-data/ts-0-root
uuid: "a4c03b44f7b54441810db27ae31a30b9"
format_stamp: "Formatted at 2026-08-12 06:19:20 on dist-test-slave-drl0"
I20260812 06:19:20.862613  7469 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-task4BgTQF/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515560703209-7469-0/minicluster-data/ts-0-root
metadata directory: /tmp/dist-test-task4BgTQF/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515560703209-7469-0/minicluster-data/ts-0-root
1 data directories: /tmp/dist-test-task4BgTQF/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515560703209-7469-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:19:20.877703  7469 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:19:20.878214  7469 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:19:20.878757  7469 txn_system_client.cc:432] TxnSystemClient initialization is disabled...
I20260812 06:19:20.879875  7469 ts_tablet_manager.cc:585] Loaded tablet metadata (0 total tablets, 0 live tablets)
I20260812 06:19:20.879930  7469 ts_tablet_manager.cc:531] Time spent load tablet metadata: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:19:20.880002  7469 ts_tablet_manager.cc:616] Registered 0 tablets
I20260812 06:19:20.880044  7469 ts_tablet_manager.cc:595] Time spent register tablets: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:19:20.888648  7469 rpc_server.cc:307] RPC server started. Bound to: 127.7.75.65:35919
I20260812 06:19:20.888684  7722 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.7.75.65:35919 every 8 connection(s)
I20260812 06:19:20.899772  7725 heartbeater.cc:344] Connected to a master server at 127.7.75.126:41833
I20260812 06:19:20.900231  7725 heartbeater.cc:461] Registering TS with master...
I20260812 06:19:20.900801  7725 heartbeater.cc:507] Master 127.7.75.126:41833 requested a full tablet report, sending...
I20260812 06:19:20.902387  7518 ts_manager.cc:194] Registered new tserver with Master: a4c03b44f7b54441810db27ae31a30b9 (127.7.75.65:35919)
I20260812 06:19:20.903020  7469 internal_mini_cluster.cc:371] 1 TS(s) registered with all masters after 0.013673888s
I20260812 06:19:20.903915  7518 master_service.cc:502] Signed X509 certificate for tserver {username='slave'} at 127.0.0.1:46798
I20260812 06:19:20.915230  7518 catalog_manager.cc:2283] Servicing CreateTable request from {username='slave'} at 127.0.0.1:46814:
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:19:20.936179  7673 tablet_service.cc:1511] Processing CreateTablet for tablet 45169db616af43f186fb78ab4a20bd42 (DEFAULT_TABLE table=heavy-update-compaction-test [id=a23e541f363148078b32082d847cfdc9]), partition=
I20260812 06:19:20.936708  7673 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet 45169db616af43f186fb78ab4a20bd42. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:19:20.939689  7744 tablet_bootstrap.cc:492] T 45169db616af43f186fb78ab4a20bd42 P a4c03b44f7b54441810db27ae31a30b9: Bootstrap starting.
I20260812 06:19:20.940639  7744 tablet_bootstrap.cc:654] T 45169db616af43f186fb78ab4a20bd42 P a4c03b44f7b54441810db27ae31a30b9: Neither blocks nor log segments found. Creating new log.
I20260812 06:19:20.942286  7744 tablet_bootstrap.cc:492] T 45169db616af43f186fb78ab4a20bd42 P a4c03b44f7b54441810db27ae31a30b9: No bootstrap required, opened a new log
I20260812 06:19:20.942408  7744 ts_tablet_manager.cc:1403] T 45169db616af43f186fb78ab4a20bd42 P a4c03b44f7b54441810db27ae31a30b9: Time spent bootstrapping tablet: real 0.003s	user 0.002s	sys 0.000s
I20260812 06:19:20.943112  7744 raft_consensus.cc:359] T 45169db616af43f186fb78ab4a20bd42 P a4c03b44f7b54441810db27ae31a30b9 [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "a4c03b44f7b54441810db27ae31a30b9" member_type: VOTER last_known_addr { host: "127.7.75.65" port: 35919 } }
I20260812 06:19:20.943387  7744 raft_consensus.cc:385] T 45169db616af43f186fb78ab4a20bd42 P a4c03b44f7b54441810db27ae31a30b9 [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:19:20.943416  7744 raft_consensus.cc:740] T 45169db616af43f186fb78ab4a20bd42 P a4c03b44f7b54441810db27ae31a30b9 [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: a4c03b44f7b54441810db27ae31a30b9, State: Initialized, Role: FOLLOWER
I20260812 06:19:20.943858  7744 consensus_queue.cc:260] T 45169db616af43f186fb78ab4a20bd42 P a4c03b44f7b54441810db27ae31a30b9 [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: "a4c03b44f7b54441810db27ae31a30b9" member_type: VOTER last_known_addr { host: "127.7.75.65" port: 35919 } }
I20260812 06:19:20.943981  7744 raft_consensus.cc:399] T 45169db616af43f186fb78ab4a20bd42 P a4c03b44f7b54441810db27ae31a30b9 [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:19:20.944015  7744 raft_consensus.cc:493] T 45169db616af43f186fb78ab4a20bd42 P a4c03b44f7b54441810db27ae31a30b9 [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:19:20.944114  7744 raft_consensus.cc:3060] T 45169db616af43f186fb78ab4a20bd42 P a4c03b44f7b54441810db27ae31a30b9 [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:19:20.945180  7744 raft_consensus.cc:515] T 45169db616af43f186fb78ab4a20bd42 P a4c03b44f7b54441810db27ae31a30b9 [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "a4c03b44f7b54441810db27ae31a30b9" member_type: VOTER last_known_addr { host: "127.7.75.65" port: 35919 } }
I20260812 06:19:20.945351  7744 leader_election.cc:304] T 45169db616af43f186fb78ab4a20bd42 P a4c03b44f7b54441810db27ae31a30b9 [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: a4c03b44f7b54441810db27ae31a30b9; no voters: 
I20260812 06:19:20.945642  7744 leader_election.cc:290] T 45169db616af43f186fb78ab4a20bd42 P a4c03b44f7b54441810db27ae31a30b9 [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:19:20.945839  7748 raft_consensus.cc:2804] T 45169db616af43f186fb78ab4a20bd42 P a4c03b44f7b54441810db27ae31a30b9 [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:19:20.946163  7748 raft_consensus.cc:697] T 45169db616af43f186fb78ab4a20bd42 P a4c03b44f7b54441810db27ae31a30b9 [term 1 LEADER]: Becoming Leader. State: Replica: a4c03b44f7b54441810db27ae31a30b9, State: Running, Role: LEADER
I20260812 06:19:20.946161  7744 ts_tablet_manager.cc:1434] T 45169db616af43f186fb78ab4a20bd42 P a4c03b44f7b54441810db27ae31a30b9: Time spent starting tablet: real 0.004s	user 0.004s	sys 0.000s
I20260812 06:19:20.946388  7725 heartbeater.cc:499] Master 127.7.75.126:41833 was elected leader, sending a full tablet report...
I20260812 06:19:20.946592  7748 consensus_queue.cc:237] T 45169db616af43f186fb78ab4a20bd42 P a4c03b44f7b54441810db27ae31a30b9 [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: "a4c03b44f7b54441810db27ae31a30b9" member_type: VOTER last_known_addr { host: "127.7.75.65" port: 35919 } }
I20260812 06:19:20.949421  7518 catalog_manager.cc:5719] T 45169db616af43f186fb78ab4a20bd42 P a4c03b44f7b54441810db27ae31a30b9 reported cstate change: term changed from 0 to 1, leader changed from <none> to a4c03b44f7b54441810db27ae31a30b9 (127.7.75.65). New cstate: current_term: 1 leader_uuid: "a4c03b44f7b54441810db27ae31a30b9" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "a4c03b44f7b54441810db27ae31a30b9" member_type: VOTER last_known_addr { host: "127.7.75.65" port: 35919 } health_report { overall_health: HEALTHY } } }
I20260812 06:19:21.018080  7469 heavy-update-compaction-itest.cc:215] Time spent inserting: real 0.063s	user 0.018s	sys 0.008s
I20260812 06:19:21.139873  7726 maintenance_manager.cc:419] P a4c03b44f7b54441810db27ae31a30b9: Scheduling FlushMRSOp(45169db616af43f186fb78ab4a20bd42): perf score=15.086190
I20260812 06:19:21.287561  7632 maintenance_manager.cc:643] P a4c03b44f7b54441810db27ae31a30b9: FlushMRSOp(45169db616af43f186fb78ab4a20bd42) complete. Timing: real 0.147s	user 0.117s	sys 0.028s Metrics: {"bytes_written":8779420,"cfile_init":1,"compiler_manager_pool.queue_time_us":259,"delete_count":0,"dirs.queue_time_us":59,"dirs.run_cpu_time_us":220,"dirs.run_wall_time_us":812,"drs_written":1,"lbm_read_time_us":52,"lbm_reads_lt_1ms":4,"lbm_write_time_us":34454,"lbm_writes_lt_1ms":571,"peak_mem_usage":0,"reinsert_count":0,"rows_written":103,"spinlock_wait_cycles":121216,"thread_start_us":180,"threads_started":1,"update_count":1070}
I20260812 06:19:21.288903  7726 maintenance_manager.cc:419] P a4c03b44f7b54441810db27ae31a30b9: Scheduling LogGCOp(45169db616af43f186fb78ab4a20bd42): free 11976772 bytes of WAL
I20260812 06:19:21.289305  7632 log_reader.cc:385] T 45169db616af43f186fb78ab4a20bd42: removed 1 log segments from log reader
I20260812 06:19:21.289387  7632 log.cc:1079] T 45169db616af43f186fb78ab4a20bd42 P a4c03b44f7b54441810db27ae31a30b9: Deleting log segment in path: /tmp/dist-test-task4BgTQF/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515560703209-7469-0/minicluster-data/ts-0-root/wals/45169db616af43f186fb78ab4a20bd42/wal-000000001 (ops 1-6)
I20260812 06:19:21.292951  7632 maintenance_manager.cc:643] P a4c03b44f7b54441810db27ae31a30b9: LogGCOp(45169db616af43f186fb78ab4a20bd42) complete. Timing: real 0.004s	user 0.000s	sys 0.002s Metrics: {}
I20260812 06:19:21.293298  7726 maintenance_manager.cc:419] P a4c03b44f7b54441810db27ae31a30b9: Scheduling UndoDeltaBlockGCOp(45169db616af43f186fb78ab4a20bd42): 12308959 bytes on disk
I20260812 06:19:21.294088  7632 maintenance_manager.cc:643] P a4c03b44f7b54441810db27ae31a30b9: UndoDeltaBlockGCOp(45169db616af43f186fb78ab4a20bd42) complete. Timing: real 0.001s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":98,"lbm_reads_lt_1ms":4}
I20260812 06:19:21.294483  7726 maintenance_manager.cc:419] P a4c03b44f7b54441810db27ae31a30b9: Scheduling FlushDeltaMemStoresOp(45169db616af43f186fb78ab4a20bd42): perf score=2.188937
I20260812 06:19:21.312494  7632 maintenance_manager.cc:643] P a4c03b44f7b54441810db27ae31a30b9: FlushDeltaMemStoresOp(45169db616af43f186fb78ab4a20bd42) complete. Timing: real 0.018s	user 0.011s	sys 0.004s Metrics: {"bytes_written":3528305,"delete_count":0,"lbm_write_time_us":6554,"lbm_writes_lt_1ms":89,"reinsert_count":0,"update_count":430}
I20260812 06:19:21.313251  7726 maintenance_manager.cc:419] P a4c03b44f7b54441810db27ae31a30b9: Scheduling MajorDeltaCompactionOp(45169db616af43f186fb78ab4a20bd42): perf score=1.000000
I20260812 06:19:21.459612  7632 maintenance_manager.cc:643] P a4c03b44f7b54441810db27ae31a30b9: MajorDeltaCompactionOp(45169db616af43f186fb78ab4a20bd42) complete. Timing: real 0.146s	user 0.111s	sys 0.024s Metrics: {"cfile_cache_miss":332,"cfile_cache_miss_bytes":16528888,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":914,"lbm_read_time_us":9750,"lbm_reads_lt_1ms":364,"lbm_write_time_us":25359,"lbm_writes_lt_1ms":343,"peak_mem_usage":38262756,"reinsert_count":0,"spinlock_wait_cycles":2944,"thread_start_us":279,"threads_started":5,"update_count":1500}
I20260812 06:19:21.460527  7726 maintenance_manager.cc:419] P a4c03b44f7b54441810db27ae31a30b9: Scheduling FlushDeltaMemStoresOp(45169db616af43f186fb78ab4a20bd42): perf score=10.126437
I20260812 06:19:21.513321  7632 maintenance_manager.cc:643] P a4c03b44f7b54441810db27ae31a30b9: FlushDeltaMemStoresOp(45169db616af43f186fb78ab4a20bd42) complete. Timing: real 0.053s	user 0.030s	sys 0.012s Metrics: {"bytes_written":12307491,"delete_count":0,"lbm_write_time_us":19522,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:19:21.513795  7726 maintenance_manager.cc:419] P a4c03b44f7b54441810db27ae31a30b9: Scheduling FlushDeltaMemStoresOp(45169db616af43f186fb78ab4a20bd42): perf score=2.188937
I20260812 06:19:21.527208  7632 maintenance_manager.cc:643] P a4c03b44f7b54441810db27ae31a30b9: FlushDeltaMemStoresOp(45169db616af43f186fb78ab4a20bd42) complete. Timing: real 0.013s	user 0.001s	sys 0.011s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4481,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:21.527985  7726 maintenance_manager.cc:419] P a4c03b44f7b54441810db27ae31a30b9: Scheduling MajorDeltaCompactionOp(45169db616af43f186fb78ab4a20bd42): perf score=1.000000
I20260812 06:19:21.661382  7632 maintenance_manager.cc:643] P a4c03b44f7b54441810db27ae31a30b9: MajorDeltaCompactionOp(45169db616af43f186fb78ab4a20bd42) complete. Timing: real 0.133s	user 0.096s	sys 0.036s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20631313,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":1278,"lbm_read_time_us":10486,"lbm_reads_lt_1ms":472,"lbm_write_time_us":24749,"lbm_writes_lt_1ms":443,"mutex_wait_us":399,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":83584,"update_count":2000}
I20260812 06:19:21.662135  7726 maintenance_manager.cc:419] P a4c03b44f7b54441810db27ae31a30b9: Scheduling FlushDeltaMemStoresOp(45169db616af43f186fb78ab4a20bd42): perf score=10.126437
I20260812 06:19:21.719444  7632 maintenance_manager.cc:643] P a4c03b44f7b54441810db27ae31a30b9: FlushDeltaMemStoresOp(45169db616af43f186fb78ab4a20bd42) complete. Timing: real 0.057s	user 0.034s	sys 0.015s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":16958,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:19:21.720016  7726 maintenance_manager.cc:419] P a4c03b44f7b54441810db27ae31a30b9: Scheduling FlushDeltaMemStoresOp(45169db616af43f186fb78ab4a20bd42): perf score=2.188937
I20260812 06:19:21.736968  7632 maintenance_manager.cc:643] P a4c03b44f7b54441810db27ae31a30b9: FlushDeltaMemStoresOp(45169db616af43f186fb78ab4a20bd42) complete. Timing: real 0.017s	user 0.006s	sys 0.009s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6319,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:21.737530  7726 maintenance_manager.cc:419] P a4c03b44f7b54441810db27ae31a30b9: Scheduling MajorDeltaCompactionOp(45169db616af43f186fb78ab4a20bd42): perf score=1.000000
I20260812 06:19:21.896941  7632 maintenance_manager.cc:643] P a4c03b44f7b54441810db27ae31a30b9: MajorDeltaCompactionOp(45169db616af43f186fb78ab4a20bd42) complete. Timing: real 0.159s	user 0.092s	sys 0.066s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20631312,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":483,"lbm_read_time_us":13204,"lbm_reads_lt_1ms":472,"lbm_write_time_us":25985,"lbm_writes_lt_1ms":443,"peak_mem_usage":50689328,"reinsert_count":0,"update_count":2000}
I20260812 06:19:21.897765  7726 maintenance_manager.cc:419] P a4c03b44f7b54441810db27ae31a30b9: Scheduling FlushDeltaMemStoresOp(45169db616af43f186fb78ab4a20bd42): perf score=10.126437
I20260812 06:19:21.945760  7632 maintenance_manager.cc:643] P a4c03b44f7b54441810db27ae31a30b9: FlushDeltaMemStoresOp(45169db616af43f186fb78ab4a20bd42) complete. Timing: real 0.048s	user 0.027s	sys 0.012s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":19160,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:19:21.946467  7726 maintenance_manager.cc:419] P a4c03b44f7b54441810db27ae31a30b9: Scheduling FlushDeltaMemStoresOp(45169db616af43f186fb78ab4a20bd42): perf score=2.188937
I20260812 06:19:21.960595  7632 maintenance_manager.cc:643] P a4c03b44f7b54441810db27ae31a30b9: FlushDeltaMemStoresOp(45169db616af43f186fb78ab4a20bd42) complete. Timing: real 0.014s	user 0.003s	sys 0.009s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5054,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:21.961259  7726 maintenance_manager.cc:419] P a4c03b44f7b54441810db27ae31a30b9: Scheduling MajorDeltaCompactionOp(45169db616af43f186fb78ab4a20bd42): perf score=1.000000
I20260812 06:19:22.095865  7632 maintenance_manager.cc:643] P a4c03b44f7b54441810db27ae31a30b9: MajorDeltaCompactionOp(45169db616af43f186fb78ab4a20bd42) complete. Timing: real 0.134s	user 0.090s	sys 0.044s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20631312,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":846,"lbm_read_time_us":10274,"lbm_reads_lt_1ms":472,"lbm_write_time_us":26704,"lbm_writes_lt_1ms":443,"mutex_wait_us":392,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":3072,"update_count":2000}
I20260812 06:19:22.096441  7726 maintenance_manager.cc:419] P a4c03b44f7b54441810db27ae31a30b9: Scheduling FlushDeltaMemStoresOp(45169db616af43f186fb78ab4a20bd42): perf score=10.126437
I20260812 06:19:22.139389  7632 maintenance_manager.cc:643] P a4c03b44f7b54441810db27ae31a30b9: FlushDeltaMemStoresOp(45169db616af43f186fb78ab4a20bd42) complete. Timing: real 0.043s	user 0.024s	sys 0.016s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":16888,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:19:22.139887  7726 maintenance_manager.cc:419] P a4c03b44f7b54441810db27ae31a30b9: Scheduling FlushDeltaMemStoresOp(45169db616af43f186fb78ab4a20bd42): perf score=2.188937
I20260812 06:19:22.155884  7632 maintenance_manager.cc:643] P a4c03b44f7b54441810db27ae31a30b9: FlushDeltaMemStoresOp(45169db616af43f186fb78ab4a20bd42) complete. Timing: real 0.016s	user 0.011s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6089,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:22.156525  7726 maintenance_manager.cc:419] P a4c03b44f7b54441810db27ae31a30b9: Scheduling MajorDeltaCompactionOp(45169db616af43f186fb78ab4a20bd42): perf score=1.000000
I20260812 06:19:22.298693  7632 maintenance_manager.cc:643] P a4c03b44f7b54441810db27ae31a30b9: MajorDeltaCompactionOp(45169db616af43f186fb78ab4a20bd42) complete. Timing: real 0.142s	user 0.121s	sys 0.020s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20631312,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":1024,"lbm_read_time_us":11645,"lbm_reads_lt_1ms":472,"lbm_write_time_us":26009,"lbm_writes_lt_1ms":443,"mutex_wait_us":365,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":1536,"update_count":2000}
I20260812 06:19:22.299361  7726 maintenance_manager.cc:419] P a4c03b44f7b54441810db27ae31a30b9: Scheduling FlushDeltaMemStoresOp(45169db616af43f186fb78ab4a20bd42): perf score=10.126437
I20260812 06:19:22.352578  7632 maintenance_manager.cc:643] P a4c03b44f7b54441810db27ae31a30b9: FlushDeltaMemStoresOp(45169db616af43f186fb78ab4a20bd42) complete. Timing: real 0.053s	user 0.036s	sys 0.015s Metrics: {"bytes_written":12307493,"delete_count":0,"lbm_write_time_us":17627,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:19:22.353215  7726 maintenance_manager.cc:419] P a4c03b44f7b54441810db27ae31a30b9: Scheduling FlushDeltaMemStoresOp(45169db616af43f186fb78ab4a20bd42): perf score=2.188937
I20260812 06:19:22.364825  7632 maintenance_manager.cc:643] P a4c03b44f7b54441810db27ae31a30b9: FlushDeltaMemStoresOp(45169db616af43f186fb78ab4a20bd42) complete. Timing: real 0.011s	user 0.005s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4316,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:22.365250  7726 maintenance_manager.cc:419] P a4c03b44f7b54441810db27ae31a30b9: Scheduling MajorDeltaCompactionOp(45169db616af43f186fb78ab4a20bd42): perf score=1.000000
I20260812 06:19:22.522115  7632 maintenance_manager.cc:643] P a4c03b44f7b54441810db27ae31a30b9: MajorDeltaCompactionOp(45169db616af43f186fb78ab4a20bd42) complete. Timing: real 0.157s	user 0.107s	sys 0.044s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20631315,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":260,"lbm_read_time_us":11618,"lbm_reads_lt_1ms":472,"lbm_write_time_us":25088,"lbm_writes_lt_1ms":443,"mutex_wait_us":28,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":4992,"update_count":2000}
I20260812 06:19:22.522691  7726 maintenance_manager.cc:419] P a4c03b44f7b54441810db27ae31a30b9: Scheduling FlushDeltaMemStoresOp(45169db616af43f186fb78ab4a20bd42): perf score=10.126437
I20260812 06:19:22.574226  7632 maintenance_manager.cc:643] P a4c03b44f7b54441810db27ae31a30b9: FlushDeltaMemStoresOp(45169db616af43f186fb78ab4a20bd42) complete. Timing: real 0.051s	user 0.024s	sys 0.015s Metrics: {"bytes_written":12307541,"delete_count":0,"lbm_write_time_us":17848,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:19:22.574807  7726 maintenance_manager.cc:419] P a4c03b44f7b54441810db27ae31a30b9: Scheduling FlushDeltaMemStoresOp(45169db616af43f186fb78ab4a20bd42): perf score=2.188937
I20260812 06:19:22.590137  7632 maintenance_manager.cc:643] P a4c03b44f7b54441810db27ae31a30b9: FlushDeltaMemStoresOp(45169db616af43f186fb78ab4a20bd42) complete. Timing: real 0.015s	user 0.004s	sys 0.008s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":5847,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:22.590725  7726 maintenance_manager.cc:419] P a4c03b44f7b54441810db27ae31a30b9: Scheduling MajorDeltaCompactionOp(45169db616af43f186fb78ab4a20bd42): perf score=1.000000
I20260812 06:19:22.732669  7632 maintenance_manager.cc:643] P a4c03b44f7b54441810db27ae31a30b9: MajorDeltaCompactionOp(45169db616af43f186fb78ab4a20bd42) complete. Timing: real 0.142s	user 0.118s	sys 0.024s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20631362,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":729,"lbm_read_time_us":10393,"lbm_reads_lt_1ms":472,"lbm_write_time_us":27253,"lbm_writes_lt_1ms":443,"mutex_wait_us":290,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":6144,"update_count":2000}
I20260812 06:19:22.733359  7726 maintenance_manager.cc:419] P a4c03b44f7b54441810db27ae31a30b9: Scheduling FlushDeltaMemStoresOp(45169db616af43f186fb78ab4a20bd42): perf score=10.126437
I20260812 06:19:22.784022  7632 maintenance_manager.cc:643] P a4c03b44f7b54441810db27ae31a30b9: FlushDeltaMemStoresOp(45169db616af43f186fb78ab4a20bd42) complete. Timing: real 0.050s	user 0.020s	sys 0.016s Metrics: {"bytes_written":12307492,"delete_count":0,"lbm_write_time_us":15749,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:19:22.784715  7726 maintenance_manager.cc:419] P a4c03b44f7b54441810db27ae31a30b9: Scheduling FlushDeltaMemStoresOp(45169db616af43f186fb78ab4a20bd42): perf score=2.188937
I20260812 06:19:22.799971  7632 maintenance_manager.cc:643] P a4c03b44f7b54441810db27ae31a30b9: FlushDeltaMemStoresOp(45169db616af43f186fb78ab4a20bd42) complete. Timing: real 0.015s	user 0.010s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5554,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:22.800873  7726 maintenance_manager.cc:419] P a4c03b44f7b54441810db27ae31a30b9: Scheduling FlushMRSOp(45169db616af43f186fb78ab4a20bd42): perf score=1.000000
I20260812 06:19:22.830399  7632 maintenance_manager.cc:643] P a4c03b44f7b54441810db27ae31a30b9: FlushMRSOp(45169db616af43f186fb78ab4a20bd42) complete. Timing: real 0.029s	user 0.028s	sys 0.000s Metrics: {"bytes_written":1275444,"cfile_init":1,"dirs.queue_time_us":39,"dirs.run_cpu_time_us":285,"dirs.run_wall_time_us":1376,"drs_written":1,"lbm_read_time_us":62,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1712,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":31}
I20260812 06:19:22.831408  7726 maintenance_manager.cc:419] P a4c03b44f7b54441810db27ae31a30b9: Scheduling LogGCOp(45169db616af43f186fb78ab4a20bd42): free 129773548 bytes of WAL
I20260812 06:19:22.831848  7632 log_reader.cc:385] T 45169db616af43f186fb78ab4a20bd42: removed 13 log segments from log reader
I20260812 06:19:22.831919  7632 log.cc:1079] T 45169db616af43f186fb78ab4a20bd42 P a4c03b44f7b54441810db27ae31a30b9: Deleting log segment in path: /tmp/dist-test-task4BgTQF/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515560703209-7469-0/minicluster-data/ts-0-root/wals/45169db616af43f186fb78ab4a20bd42/wal-000000002 (ops 7-11)
I20260812 06:19:22.831974  7632 log.cc:1079] T 45169db616af43f186fb78ab4a20bd42 P a4c03b44f7b54441810db27ae31a30b9: Deleting log segment in path: /tmp/dist-test-task4BgTQF/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515560703209-7469-0/minicluster-data/ts-0-root/wals/45169db616af43f186fb78ab4a20bd42/wal-000000003 (ops 12-16)
I20260812 06:19:22.832032  7632 log.cc:1079] T 45169db616af43f186fb78ab4a20bd42 P a4c03b44f7b54441810db27ae31a30b9: Deleting log segment in path: /tmp/dist-test-task4BgTQF/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515560703209-7469-0/minicluster-data/ts-0-root/wals/45169db616af43f186fb78ab4a20bd42/wal-000000004 (ops 17-21)
I20260812 06:19:22.832073  7632 log.cc:1079] T 45169db616af43f186fb78ab4a20bd42 P a4c03b44f7b54441810db27ae31a30b9: Deleting log segment in path: /tmp/dist-test-task4BgTQF/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515560703209-7469-0/minicluster-data/ts-0-root/wals/45169db616af43f186fb78ab4a20bd42/wal-000000005 (ops 22-26)
I20260812 06:19:22.832108  7632 log.cc:1079] T 45169db616af43f186fb78ab4a20bd42 P a4c03b44f7b54441810db27ae31a30b9: Deleting log segment in path: /tmp/dist-test-task4BgTQF/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515560703209-7469-0/minicluster-data/ts-0-root/wals/45169db616af43f186fb78ab4a20bd42/wal-000000006 (ops 27-30)
I20260812 06:19:22.832145  7632 log.cc:1079] T 45169db616af43f186fb78ab4a20bd42 P a4c03b44f7b54441810db27ae31a30b9: Deleting log segment in path: /tmp/dist-test-task4BgTQF/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515560703209-7469-0/minicluster-data/ts-0-root/wals/45169db616af43f186fb78ab4a20bd42/wal-000000007 (ops 31-35)
I20260812 06:19:22.832183  7632 log.cc:1079] T 45169db616af43f186fb78ab4a20bd42 P a4c03b44f7b54441810db27ae31a30b9: Deleting log segment in path: /tmp/dist-test-task4BgTQF/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515560703209-7469-0/minicluster-data/ts-0-root/wals/45169db616af43f186fb78ab4a20bd42/wal-000000008 (ops 36-40)
I20260812 06:19:22.832219  7632 log.cc:1079] T 45169db616af43f186fb78ab4a20bd42 P a4c03b44f7b54441810db27ae31a30b9: Deleting log segment in path: /tmp/dist-test-task4BgTQF/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515560703209-7469-0/minicluster-data/ts-0-root/wals/45169db616af43f186fb78ab4a20bd42/wal-000000009 (ops 41-45)
I20260812 06:19:22.832255  7632 log.cc:1079] T 45169db616af43f186fb78ab4a20bd42 P a4c03b44f7b54441810db27ae31a30b9: Deleting log segment in path: /tmp/dist-test-task4BgTQF/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515560703209-7469-0/minicluster-data/ts-0-root/wals/45169db616af43f186fb78ab4a20bd42/wal-000000010 (ops 46-50)
I20260812 06:19:22.832293  7632 log.cc:1079] T 45169db616af43f186fb78ab4a20bd42 P a4c03b44f7b54441810db27ae31a30b9: Deleting log segment in path: /tmp/dist-test-task4BgTQF/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515560703209-7469-0/minicluster-data/ts-0-root/wals/45169db616af43f186fb78ab4a20bd42/wal-000000011 (ops 51-55)
I20260812 06:19:22.832335  7632 log.cc:1079] T 45169db616af43f186fb78ab4a20bd42 P a4c03b44f7b54441810db27ae31a30b9: Deleting log segment in path: /tmp/dist-test-task4BgTQF/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515560703209-7469-0/minicluster-data/ts-0-root/wals/45169db616af43f186fb78ab4a20bd42/wal-000000012 (ops 56-60)
I20260812 06:19:22.832373  7632 log.cc:1079] T 45169db616af43f186fb78ab4a20bd42 P a4c03b44f7b54441810db27ae31a30b9: Deleting log segment in path: /tmp/dist-test-task4BgTQF/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515560703209-7469-0/minicluster-data/ts-0-root/wals/45169db616af43f186fb78ab4a20bd42/wal-000000013 (ops 61-65)
I20260812 06:19:22.832407  7632 log.cc:1079] T 45169db616af43f186fb78ab4a20bd42 P a4c03b44f7b54441810db27ae31a30b9: Deleting log segment in path: /tmp/dist-test-task4BgTQF/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515560703209-7469-0/minicluster-data/ts-0-root/wals/45169db616af43f186fb78ab4a20bd42/wal-000000014 (ops 66-70)
I20260812 06:19:22.863893  7632 maintenance_manager.cc:643] P a4c03b44f7b54441810db27ae31a30b9: LogGCOp(45169db616af43f186fb78ab4a20bd42) complete. Timing: real 0.032s	user 0.000s	sys 0.031s Metrics: {}
I20260812 06:19:22.864696  7726 maintenance_manager.cc:419] P a4c03b44f7b54441810db27ae31a30b9: Scheduling FlushDeltaMemStoresOp(45169db616af43f186fb78ab4a20bd42): perf score=6.157687
I20260812 06:19:22.896737  7632 maintenance_manager.cc:643] P a4c03b44f7b54441810db27ae31a30b9: FlushDeltaMemStoresOp(45169db616af43f186fb78ab4a20bd42) complete. Timing: real 0.032s	user 0.020s	sys 0.009s Metrics: {"bytes_written":8205078,"delete_count":0,"lbm_write_time_us":13745,"lbm_writes_lt_1ms":203,"reinsert_count":0,"update_count":1000}
I20260812 06:19:22.897223  7726 maintenance_manager.cc:419] P a4c03b44f7b54441810db27ae31a30b9: Scheduling UndoDeltaBlockGCOp(45169db616af43f186fb78ab4a20bd42): 483 bytes on disk
I20260812 06:19:22.897601  7632 maintenance_manager.cc:643] P a4c03b44f7b54441810db27ae31a30b9: UndoDeltaBlockGCOp(45169db616af43f186fb78ab4a20bd42) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":48,"lbm_reads_lt_1ms":4}
I20260812 06:19:22.898025  7726 maintenance_manager.cc:419] P a4c03b44f7b54441810db27ae31a30b9: Scheduling MajorDeltaCompactionOp(45169db616af43f186fb78ab4a20bd42): perf score=1.000000
I20260812 06:19:23.075616  7632 maintenance_manager.cc:643] P a4c03b44f7b54441810db27ae31a30b9: MajorDeltaCompactionOp(45169db616af43f186fb78ab4a20bd42) complete. Timing: real 0.177s	user 0.126s	sys 0.048s Metrics: {"cfile_cache_miss":633,"cfile_cache_miss_bytes":28836258,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":238,"lbm_read_time_us":12136,"lbm_reads_lt_1ms":665,"lbm_write_time_us":36033,"lbm_writes_lt_1ms":643,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":11904,"thread_start_us":79,"threads_started":1,"update_count":3000}
I20260812 06:19:23.076133  7726 maintenance_manager.cc:419] P a4c03b44f7b54441810db27ae31a30b9: Scheduling FlushDeltaMemStoresOp(45169db616af43f186fb78ab4a20bd42): perf score=14.095187
I20260812 06:19:23.139935  7632 maintenance_manager.cc:643] P a4c03b44f7b54441810db27ae31a30b9: FlushDeltaMemStoresOp(45169db616af43f186fb78ab4a20bd42) complete. Timing: real 0.064s	user 0.037s	sys 0.020s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":26432,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:23.140462  7726 maintenance_manager.cc:419] P a4c03b44f7b54441810db27ae31a30b9: Scheduling FlushDeltaMemStoresOp(45169db616af43f186fb78ab4a20bd42): perf score=2.188937
I20260812 06:19:23.151885  7632 maintenance_manager.cc:643] P a4c03b44f7b54441810db27ae31a30b9: FlushDeltaMemStoresOp(45169db616af43f186fb78ab4a20bd42) complete. Timing: real 0.011s	user 0.009s	sys 0.001s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4592,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:23.152333  7726 maintenance_manager.cc:419] P a4c03b44f7b54441810db27ae31a30b9: Scheduling MajorDeltaCompactionOp(45169db616af43f186fb78ab4a20bd42): perf score=1.000000
I20260812 06:19:23.324735  7632 maintenance_manager.cc:643] P a4c03b44f7b54441810db27ae31a30b9: MajorDeltaCompactionOp(45169db616af43f186fb78ab4a20bd42) complete. Timing: real 0.172s	user 0.125s	sys 0.045s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24733724,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":720,"lbm_read_time_us":12321,"lbm_reads_lt_1ms":572,"lbm_write_time_us":33065,"lbm_writes_lt_1ms":543,"mutex_wait_us":48,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":768,"update_count":2500}
I20260812 06:19:23.325467  7726 maintenance_manager.cc:419] P a4c03b44f7b54441810db27ae31a30b9: Scheduling FlushDeltaMemStoresOp(45169db616af43f186fb78ab4a20bd42): perf score=14.095187
I20260812 06:19:23.372735  7632 maintenance_manager.cc:643] P a4c03b44f7b54441810db27ae31a30b9: FlushDeltaMemStoresOp(45169db616af43f186fb78ab4a20bd42) complete. Timing: real 0.047s	user 0.033s	sys 0.012s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":21899,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:23.373395  7726 maintenance_manager.cc:419] P a4c03b44f7b54441810db27ae31a30b9: Scheduling MajorDeltaCompactionOp(45169db616af43f186fb78ab4a20bd42): perf score=1.000000
I20260812 06:19:23.528892  7632 maintenance_manager.cc:643] P a4c03b44f7b54441810db27ae31a30b9: MajorDeltaCompactionOp(45169db616af43f186fb78ab4a20bd42) complete. Timing: real 0.155s	user 0.115s	sys 0.040s Metrics: {"cfile_cache_miss":431,"cfile_cache_miss_bytes":20631192,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":1,"delta_iterators_relevant":1,"dirs.queue_time_us":256,"lbm_read_time_us":12617,"lbm_reads_lt_1ms":467,"lbm_write_time_us":28014,"lbm_writes_lt_1ms":443,"mutex_wait_us":82,"peak_mem_usage":50689328,"reinsert_count":0,"update_count":2000}
I20260812 06:19:23.529520  7726 maintenance_manager.cc:419] P a4c03b44f7b54441810db27ae31a30b9: Scheduling FlushDeltaMemStoresOp(45169db616af43f186fb78ab4a20bd42): perf score=10.126437
I20260812 06:19:23.570109  7632 maintenance_manager.cc:643] P a4c03b44f7b54441810db27ae31a30b9: FlushDeltaMemStoresOp(45169db616af43f186fb78ab4a20bd42) complete. Timing: real 0.040s	user 0.021s	sys 0.011s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":15483,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:19:23.570786  7726 maintenance_manager.cc:419] P a4c03b44f7b54441810db27ae31a30b9: Scheduling FlushDeltaMemStoresOp(45169db616af43f186fb78ab4a20bd42): perf score=2.188937
I20260812 06:19:23.589713  7632 maintenance_manager.cc:643] P a4c03b44f7b54441810db27ae31a30b9: FlushDeltaMemStoresOp(45169db616af43f186fb78ab4a20bd42) complete. Timing: real 0.019s	user 0.008s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6981,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:23.590204  7726 maintenance_manager.cc:419] P a4c03b44f7b54441810db27ae31a30b9: Scheduling MajorDeltaCompactionOp(45169db616af43f186fb78ab4a20bd42): perf score=1.000000
I20260812 06:19:23.744167  7632 maintenance_manager.cc:643] P a4c03b44f7b54441810db27ae31a30b9: MajorDeltaCompactionOp(45169db616af43f186fb78ab4a20bd42) complete. Timing: real 0.154s	user 0.108s	sys 0.045s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20631312,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":1261,"lbm_read_time_us":11010,"lbm_reads_lt_1ms":472,"lbm_write_time_us":29181,"lbm_writes_lt_1ms":443,"mutex_wait_us":424,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":15616,"update_count":2000}
I20260812 06:19:23.744714  7726 maintenance_manager.cc:419] P a4c03b44f7b54441810db27ae31a30b9: Scheduling FlushDeltaMemStoresOp(45169db616af43f186fb78ab4a20bd42): perf score=10.126437
I20260812 06:19:23.794191  7632 maintenance_manager.cc:643] P a4c03b44f7b54441810db27ae31a30b9: FlushDeltaMemStoresOp(45169db616af43f186fb78ab4a20bd42) complete. Timing: real 0.049s	user 0.018s	sys 0.016s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":16294,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:19:23.794893  7726 maintenance_manager.cc:419] P a4c03b44f7b54441810db27ae31a30b9: Scheduling FlushDeltaMemStoresOp(45169db616af43f186fb78ab4a20bd42): perf score=2.188937
I20260812 06:19:23.806412  7632 maintenance_manager.cc:643] P a4c03b44f7b54441810db27ae31a30b9: FlushDeltaMemStoresOp(45169db616af43f186fb78ab4a20bd42) complete. Timing: real 0.011s	user 0.005s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4270,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:23.807090  7726 maintenance_manager.cc:419] P a4c03b44f7b54441810db27ae31a30b9: Scheduling MajorDeltaCompactionOp(45169db616af43f186fb78ab4a20bd42): perf score=1.000000
I20260812 06:19:23.947340  7632 maintenance_manager.cc:643] P a4c03b44f7b54441810db27ae31a30b9: MajorDeltaCompactionOp(45169db616af43f186fb78ab4a20bd42) complete. Timing: real 0.139s	user 0.106s	sys 0.033s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20631312,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":284,"lbm_read_time_us":10943,"lbm_reads_lt_1ms":472,"lbm_write_time_us":25610,"lbm_writes_lt_1ms":443,"mutex_wait_us":43,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":13312,"update_count":2000}
I20260812 06:19:23.948251  7726 maintenance_manager.cc:419] P a4c03b44f7b54441810db27ae31a30b9: Scheduling FlushDeltaMemStoresOp(45169db616af43f186fb78ab4a20bd42): perf score=10.126437
I20260812 06:19:23.983767  7632 maintenance_manager.cc:643] P a4c03b44f7b54441810db27ae31a30b9: FlushDeltaMemStoresOp(45169db616af43f186fb78ab4a20bd42) complete. Timing: real 0.035s	user 0.017s	sys 0.017s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":14410,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:19:23.984504  7726 maintenance_manager.cc:419] P a4c03b44f7b54441810db27ae31a30b9: Scheduling FlushDeltaMemStoresOp(45169db616af43f186fb78ab4a20bd42): perf score=2.188937
I20260812 06:19:23.996368  7632 maintenance_manager.cc:643] P a4c03b44f7b54441810db27ae31a30b9: FlushDeltaMemStoresOp(45169db616af43f186fb78ab4a20bd42) complete. Timing: real 0.012s	user 0.006s	sys 0.005s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4734,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:23.996850  7726 maintenance_manager.cc:419] P a4c03b44f7b54441810db27ae31a30b9: Scheduling MajorDeltaCompactionOp(45169db616af43f186fb78ab4a20bd42): perf score=1.000000
I20260812 06:19:24.138396  7632 maintenance_manager.cc:643] P a4c03b44f7b54441810db27ae31a30b9: MajorDeltaCompactionOp(45169db616af43f186fb78ab4a20bd42) complete. Timing: real 0.141s	user 0.113s	sys 0.028s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20631312,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":335,"lbm_read_time_us":9587,"lbm_reads_lt_1ms":472,"lbm_write_time_us":28939,"lbm_writes_lt_1ms":443,"mutex_wait_us":57,"peak_mem_usage":50689328,"reinsert_count":0,"update_count":2000}
I20260812 06:19:24.139026  7726 maintenance_manager.cc:419] P a4c03b44f7b54441810db27ae31a30b9: Scheduling FlushDeltaMemStoresOp(45169db616af43f186fb78ab4a20bd42): perf score=10.126437
I20260812 06:19:24.198622  7632 maintenance_manager.cc:643] P a4c03b44f7b54441810db27ae31a30b9: FlushDeltaMemStoresOp(45169db616af43f186fb78ab4a20bd42) complete. Timing: real 0.059s	user 0.013s	sys 0.035s Metrics: {"bytes_written":12307489,"delete_count":0,"lbm_write_time_us":17239,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:19:24.199194  7726 maintenance_manager.cc:419] P a4c03b44f7b54441810db27ae31a30b9: Scheduling FlushDeltaMemStoresOp(45169db616af43f186fb78ab4a20bd42): perf score=2.188937
I20260812 06:19:24.211562  7632 maintenance_manager.cc:643] P a4c03b44f7b54441810db27ae31a30b9: FlushDeltaMemStoresOp(45169db616af43f186fb78ab4a20bd42) complete. Timing: real 0.012s	user 0.007s	sys 0.004s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4698,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:24.212224  7726 maintenance_manager.cc:419] P a4c03b44f7b54441810db27ae31a30b9: Scheduling MajorDeltaCompactionOp(45169db616af43f186fb78ab4a20bd42): perf score=1.000000
I20260812 06:19:24.374104  7632 maintenance_manager.cc:643] P a4c03b44f7b54441810db27ae31a30b9: MajorDeltaCompactionOp(45169db616af43f186fb78ab4a20bd42) complete. Timing: real 0.162s	user 0.105s	sys 0.056s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20631310,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":171,"lbm_read_time_us":11887,"lbm_reads_lt_1ms":472,"lbm_write_time_us":26871,"lbm_writes_lt_1ms":443,"mutex_wait_us":39,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":11008,"update_count":2000}
I20260812 06:19:24.374881  7726 maintenance_manager.cc:419] P a4c03b44f7b54441810db27ae31a30b9: Scheduling FlushDeltaMemStoresOp(45169db616af43f186fb78ab4a20bd42): perf score=10.126437
I20260812 06:19:24.422398  7632 maintenance_manager.cc:643] P a4c03b44f7b54441810db27ae31a30b9: FlushDeltaMemStoresOp(45169db616af43f186fb78ab4a20bd42) complete. Timing: real 0.047s	user 0.025s	sys 0.012s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":17297,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:19:24.422878  7726 maintenance_manager.cc:419] P a4c03b44f7b54441810db27ae31a30b9: Scheduling FlushDeltaMemStoresOp(45169db616af43f186fb78ab4a20bd42): perf score=2.188937
I20260812 06:19:24.434612  7632 maintenance_manager.cc:643] P a4c03b44f7b54441810db27ae31a30b9: FlushDeltaMemStoresOp(45169db616af43f186fb78ab4a20bd42) complete. Timing: real 0.012s	user 0.005s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4405,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:24.435207  7726 maintenance_manager.cc:419] P a4c03b44f7b54441810db27ae31a30b9: Scheduling FlushMRSOp(45169db616af43f186fb78ab4a20bd42): perf score=1.000000
I20260812 06:19:24.469354  7632 maintenance_manager.cc:643] P a4c03b44f7b54441810db27ae31a30b9: FlushMRSOp(45169db616af43f186fb78ab4a20bd42) complete. Timing: real 0.034s	user 0.032s	sys 0.000s Metrics: {"bytes_written":1275449,"cfile_init":1,"dirs.queue_time_us":101,"dirs.run_cpu_time_us":260,"dirs.run_wall_time_us":1260,"drs_written":1,"lbm_read_time_us":55,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1737,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":31}
I20260812 06:19:24.470325  7726 maintenance_manager.cc:419] P a4c03b44f7b54441810db27ae31a30b9: Scheduling LogGCOp(45169db616af43f186fb78ab4a20bd42): free 124257193 bytes of WAL
I20260812 06:19:24.470633  7632 log_reader.cc:385] T 45169db616af43f186fb78ab4a20bd42: removed 12 log segments from log reader
I20260812 06:19:24.470695  7632 log.cc:1079] T 45169db616af43f186fb78ab4a20bd42 P a4c03b44f7b54441810db27ae31a30b9: Deleting log segment in path: /tmp/dist-test-task4BgTQF/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515560703209-7469-0/minicluster-data/ts-0-root/wals/45169db616af43f186fb78ab4a20bd42/wal-000000015 (ops 71-75)
I20260812 06:19:24.470726  7632 log.cc:1079] T 45169db616af43f186fb78ab4a20bd42 P a4c03b44f7b54441810db27ae31a30b9: Deleting log segment in path: /tmp/dist-test-task4BgTQF/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515560703209-7469-0/minicluster-data/ts-0-root/wals/45169db616af43f186fb78ab4a20bd42/wal-000000016 (ops 76-80)
I20260812 06:19:24.470806  7632 log.cc:1079] T 45169db616af43f186fb78ab4a20bd42 P a4c03b44f7b54441810db27ae31a30b9: Deleting log segment in path: /tmp/dist-test-task4BgTQF/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515560703209-7469-0/minicluster-data/ts-0-root/wals/45169db616af43f186fb78ab4a20bd42/wal-000000017 (ops 81-85)
I20260812 06:19:24.470826  7632 log.cc:1079] T 45169db616af43f186fb78ab4a20bd42 P a4c03b44f7b54441810db27ae31a30b9: Deleting log segment in path: /tmp/dist-test-task4BgTQF/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515560703209-7469-0/minicluster-data/ts-0-root/wals/45169db616af43f186fb78ab4a20bd42/wal-000000018 (ops 86-90)
I20260812 06:19:24.470885  7632 log.cc:1079] T 45169db616af43f186fb78ab4a20bd42 P a4c03b44f7b54441810db27ae31a30b9: Deleting log segment in path: /tmp/dist-test-task4BgTQF/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515560703209-7469-0/minicluster-data/ts-0-root/wals/45169db616af43f186fb78ab4a20bd42/wal-000000019 (ops 91-95)
I20260812 06:19:24.470927  7632 log.cc:1079] T 45169db616af43f186fb78ab4a20bd42 P a4c03b44f7b54441810db27ae31a30b9: Deleting log segment in path: /tmp/dist-test-task4BgTQF/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515560703209-7469-0/minicluster-data/ts-0-root/wals/45169db616af43f186fb78ab4a20bd42/wal-000000020 (ops 96-100)
I20260812 06:19:24.470993  7632 log.cc:1079] T 45169db616af43f186fb78ab4a20bd42 P a4c03b44f7b54441810db27ae31a30b9: Deleting log segment in path: /tmp/dist-test-task4BgTQF/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515560703209-7469-0/minicluster-data/ts-0-root/wals/45169db616af43f186fb78ab4a20bd42/wal-000000021 (ops 101-105)
I20260812 06:19:24.471035  7632 log.cc:1079] T 45169db616af43f186fb78ab4a20bd42 P a4c03b44f7b54441810db27ae31a30b9: Deleting log segment in path: /tmp/dist-test-task4BgTQF/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515560703209-7469-0/minicluster-data/ts-0-root/wals/45169db616af43f186fb78ab4a20bd42/wal-000000022 (ops 106-110)
I20260812 06:19:24.471076  7632 log.cc:1079] T 45169db616af43f186fb78ab4a20bd42 P a4c03b44f7b54441810db27ae31a30b9: Deleting log segment in path: /tmp/dist-test-task4BgTQF/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515560703209-7469-0/minicluster-data/ts-0-root/wals/45169db616af43f186fb78ab4a20bd42/wal-000000023 (ops 111-114)
I20260812 06:19:24.471117  7632 log.cc:1079] T 45169db616af43f186fb78ab4a20bd42 P a4c03b44f7b54441810db27ae31a30b9: Deleting log segment in path: /tmp/dist-test-task4BgTQF/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515560703209-7469-0/minicluster-data/ts-0-root/wals/45169db616af43f186fb78ab4a20bd42/wal-000000024 (ops 115-119)
I20260812 06:19:24.471161  7632 log.cc:1079] T 45169db616af43f186fb78ab4a20bd42 P a4c03b44f7b54441810db27ae31a30b9: Deleting log segment in path: /tmp/dist-test-task4BgTQF/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515560703209-7469-0/minicluster-data/ts-0-root/wals/45169db616af43f186fb78ab4a20bd42/wal-000000025 (ops 120-124)
I20260812 06:19:24.471200  7632 log.cc:1079] T 45169db616af43f186fb78ab4a20bd42 P a4c03b44f7b54441810db27ae31a30b9: Deleting log segment in path: /tmp/dist-test-task4BgTQF/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515560703209-7469-0/minicluster-data/ts-0-root/wals/45169db616af43f186fb78ab4a20bd42/wal-000000026 (ops 125-129)
I20260812 06:19:24.499604  7632 maintenance_manager.cc:643] P a4c03b44f7b54441810db27ae31a30b9: LogGCOp(45169db616af43f186fb78ab4a20bd42) complete. Timing: real 0.029s	user 0.000s	sys 0.028s Metrics: {}
I20260812 06:19:24.500097  7726 maintenance_manager.cc:419] P a4c03b44f7b54441810db27ae31a30b9: Scheduling FlushDeltaMemStoresOp(45169db616af43f186fb78ab4a20bd42): perf score=6.157687
I20260812 06:19:24.532028  7632 maintenance_manager.cc:643] P a4c03b44f7b54441810db27ae31a30b9: FlushDeltaMemStoresOp(45169db616af43f186fb78ab4a20bd42) complete. Timing: real 0.032s	user 0.017s	sys 0.014s Metrics: {"bytes_written":7466642,"delete_count":0,"lbm_write_time_us":8973,"lbm_writes_lt_1ms":185,"reinsert_count":0,"update_count":910}
I20260812 06:19:24.532670  7726 maintenance_manager.cc:419] P a4c03b44f7b54441810db27ae31a30b9: Scheduling LogGCOp(45169db616af43f186fb78ab4a20bd42): free 12018006 bytes of WAL
I20260812 06:19:24.532965  7632 log_reader.cc:385] T 45169db616af43f186fb78ab4a20bd42: removed 1 log segments from log reader
I20260812 06:19:24.533021  7632 log.cc:1079] T 45169db616af43f186fb78ab4a20bd42 P a4c03b44f7b54441810db27ae31a30b9: Deleting log segment in path: /tmp/dist-test-task4BgTQF/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515560703209-7469-0/minicluster-data/ts-0-root/wals/45169db616af43f186fb78ab4a20bd42/wal-000000027 (ops 130-134)
I20260812 06:19:24.536111  7632 maintenance_manager.cc:643] P a4c03b44f7b54441810db27ae31a30b9: LogGCOp(45169db616af43f186fb78ab4a20bd42) complete. Timing: real 0.003s	user 0.000s	sys 0.002s Metrics: {"spinlock_wait_cycles":51584}
I20260812 06:19:24.537590  7726 maintenance_manager.cc:419] P a4c03b44f7b54441810db27ae31a30b9: Scheduling FlushDeltaMemStoresOp(45169db616af43f186fb78ab4a20bd42): perf score=1.000000
I20260812 06:19:24.546635  7632 maintenance_manager.cc:643] P a4c03b44f7b54441810db27ae31a30b9: FlushDeltaMemStoresOp(45169db616af43f186fb78ab4a20bd42) complete. Timing: real 0.009s	user 0.000s	sys 0.003s Metrics: {"bytes_written":1148856,"delete_count":0,"lbm_write_time_us":1387,"lbm_writes_lt_1ms":31,"reinsert_count":0,"update_count":140}
I20260812 06:19:24.547144  7726 maintenance_manager.cc:419] P a4c03b44f7b54441810db27ae31a30b9: Scheduling UndoDeltaBlockGCOp(45169db616af43f186fb78ab4a20bd42): 482 bytes on disk
I20260812 06:19:24.547537  7632 maintenance_manager.cc:643] P a4c03b44f7b54441810db27ae31a30b9: UndoDeltaBlockGCOp(45169db616af43f186fb78ab4a20bd42) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":56,"lbm_reads_lt_1ms":4}
I20260812 06:19:24.548000  7726 maintenance_manager.cc:419] P a4c03b44f7b54441810db27ae31a30b9: Scheduling MajorDeltaCompactionOp(45169db616af43f186fb78ab4a20bd42): perf score=1.000000
I20260812 06:19:24.750520  7632 maintenance_manager.cc:643] P a4c03b44f7b54441810db27ae31a30b9: MajorDeltaCompactionOp(45169db616af43f186fb78ab4a20bd42) complete. Timing: real 0.202s	user 0.154s	sys 0.049s Metrics: {"cfile_cache_miss":644,"cfile_cache_miss_bytes":29246549,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":376,"lbm_read_time_us":13597,"lbm_reads_lt_1ms":676,"lbm_write_time_us":35705,"lbm_writes_lt_1ms":653,"mutex_wait_us":32,"peak_mem_usage":75952822,"reinsert_count":0,"spinlock_wait_cycles":29696,"thread_start_us":114,"threads_started":1,"update_count":3050}
I20260812 06:19:24.751675  7726 maintenance_manager.cc:419] P a4c03b44f7b54441810db27ae31a30b9: Scheduling FlushDeltaMemStoresOp(45169db616af43f186fb78ab4a20bd42): perf score=14.095187
I20260812 06:19:24.820199  7632 maintenance_manager.cc:643] P a4c03b44f7b54441810db27ae31a30b9: FlushDeltaMemStoresOp(45169db616af43f186fb78ab4a20bd42) complete. Timing: real 0.068s	user 0.035s	sys 0.030s Metrics: {"bytes_written":15999660,"delete_count":0,"lbm_write_time_us":27402,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":392,"reinsert_count":0,"update_count":1950}
I20260812 06:19:24.820647  7726 maintenance_manager.cc:419] P a4c03b44f7b54441810db27ae31a30b9: Scheduling FlushDeltaMemStoresOp(45169db616af43f186fb78ab4a20bd42): perf score=3.181125
I20260812 06:19:24.847325  7632 maintenance_manager.cc:643] P a4c03b44f7b54441810db27ae31a30b9: FlushDeltaMemStoresOp(45169db616af43f186fb78ab4a20bd42) complete. Timing: real 0.027s	user 0.010s	sys 0.004s Metrics: {"bytes_written":4512901,"delete_count":0,"lbm_write_time_us":4972,"lbm_writes_lt_1ms":113,"reinsert_count":0,"update_count":550}
I20260812 06:19:24.847987  7726 maintenance_manager.cc:419] P a4c03b44f7b54441810db27ae31a30b9: Scheduling FlushDeltaMemStoresOp(45169db616af43f186fb78ab4a20bd42): perf score=2.188937
I20260812 06:19:24.859130  7632 maintenance_manager.cc:643] P a4c03b44f7b54441810db27ae31a30b9: FlushDeltaMemStoresOp(45169db616af43f186fb78ab4a20bd42) complete. Timing: real 0.011s	user 0.011s	sys 0.000s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":4338,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:19:24.859655  7726 maintenance_manager.cc:419] P a4c03b44f7b54441810db27ae31a30b9: Scheduling MajorDeltaCompactionOp(45169db616af43f186fb78ab4a20bd42): perf score=1.000000
I20260812 06:19:25.069267  7632 maintenance_manager.cc:643] P a4c03b44f7b54441810db27ae31a30b9: MajorDeltaCompactionOp(45169db616af43f186fb78ab4a20bd42) complete. Timing: real 0.209s	user 0.141s	sys 0.068s Metrics: {"cfile_cache_miss":623,"cfile_cache_miss_bytes":28426001,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":399,"lbm_read_time_us":13858,"lbm_reads_lt_1ms":663,"lbm_write_time_us":39494,"lbm_writes_lt_1ms":633,"peak_mem_usage":74091738,"reinsert_count":0,"spinlock_wait_cycles":16768,"update_count":2950}
I20260812 06:19:25.069962  7726 maintenance_manager.cc:419] P a4c03b44f7b54441810db27ae31a30b9: Scheduling FlushDeltaMemStoresOp(45169db616af43f186fb78ab4a20bd42): perf score=14.095187
I20260812 06:19:25.126390  7632 maintenance_manager.cc:643] P a4c03b44f7b54441810db27ae31a30b9: FlushDeltaMemStoresOp(45169db616af43f186fb78ab4a20bd42) complete. Timing: real 0.056s	user 0.027s	sys 0.023s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":23911,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:25.127012  7726 maintenance_manager.cc:419] P a4c03b44f7b54441810db27ae31a30b9: Scheduling FlushDeltaMemStoresOp(45169db616af43f186fb78ab4a20bd42): perf score=2.188937
I20260812 06:19:25.138427  7632 maintenance_manager.cc:643] P a4c03b44f7b54441810db27ae31a30b9: FlushDeltaMemStoresOp(45169db616af43f186fb78ab4a20bd42) complete. Timing: real 0.011s	user 0.001s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4697,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:25.138902  7726 maintenance_manager.cc:419] P a4c03b44f7b54441810db27ae31a30b9: Scheduling MajorDeltaCompactionOp(45169db616af43f186fb78ab4a20bd42): perf score=1.000000
I20260812 06:19:25.326615  7632 maintenance_manager.cc:643] P a4c03b44f7b54441810db27ae31a30b9: MajorDeltaCompactionOp(45169db616af43f186fb78ab4a20bd42) complete. Timing: real 0.187s	user 0.123s	sys 0.062s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24733723,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":232,"lbm_read_time_us":14874,"lbm_reads_lt_1ms":572,"lbm_write_time_us":32290,"lbm_writes_lt_1ms":543,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":3456,"update_count":2500}
I20260812 06:19:25.327280  7726 maintenance_manager.cc:419] P a4c03b44f7b54441810db27ae31a30b9: Scheduling FlushDeltaMemStoresOp(45169db616af43f186fb78ab4a20bd42): perf score=14.095187
I20260812 06:19:25.396032  7632 maintenance_manager.cc:643] P a4c03b44f7b54441810db27ae31a30b9: FlushDeltaMemStoresOp(45169db616af43f186fb78ab4a20bd42) complete. Timing: real 0.069s	user 0.034s	sys 0.027s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":23230,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:25.396624  7726 maintenance_manager.cc:419] P a4c03b44f7b54441810db27ae31a30b9: Scheduling FlushDeltaMemStoresOp(45169db616af43f186fb78ab4a20bd42): perf score=2.188937
I20260812 06:19:25.408053  7632 maintenance_manager.cc:643] P a4c03b44f7b54441810db27ae31a30b9: FlushDeltaMemStoresOp(45169db616af43f186fb78ab4a20bd42) complete. Timing: real 0.011s	user 0.002s	sys 0.009s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4630,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:25.408722  7726 maintenance_manager.cc:419] P a4c03b44f7b54441810db27ae31a30b9: Scheduling MajorDeltaCompactionOp(45169db616af43f186fb78ab4a20bd42): perf score=1.000000
I20260812 06:19:25.571924  7632 maintenance_manager.cc:643] P a4c03b44f7b54441810db27ae31a30b9: MajorDeltaCompactionOp(45169db616af43f186fb78ab4a20bd42) complete. Timing: real 0.163s	user 0.106s	sys 0.056s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24733722,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":375,"lbm_read_time_us":13161,"lbm_reads_lt_1ms":572,"lbm_write_time_us":29613,"lbm_writes_lt_1ms":543,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":4992,"update_count":2500}
I20260812 06:19:25.572686  7726 maintenance_manager.cc:419] P a4c03b44f7b54441810db27ae31a30b9: Scheduling FlushDeltaMemStoresOp(45169db616af43f186fb78ab4a20bd42): perf score=10.126437
I20260812 06:19:25.622527  7632 maintenance_manager.cc:643] P a4c03b44f7b54441810db27ae31a30b9: FlushDeltaMemStoresOp(45169db616af43f186fb78ab4a20bd42) complete. Timing: real 0.050s	user 0.019s	sys 0.027s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":23051,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":302,"reinsert_count":0,"update_count":1500}
I20260812 06:19:25.623168  7726 maintenance_manager.cc:419] P a4c03b44f7b54441810db27ae31a30b9: Scheduling FlushDeltaMemStoresOp(45169db616af43f186fb78ab4a20bd42): perf score=2.188937
I20260812 06:19:25.636843  7632 maintenance_manager.cc:643] P a4c03b44f7b54441810db27ae31a30b9: FlushDeltaMemStoresOp(45169db616af43f186fb78ab4a20bd42) complete. Timing: real 0.013s	user 0.002s	sys 0.009s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5584,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:25.637354  7726 maintenance_manager.cc:419] P a4c03b44f7b54441810db27ae31a30b9: Scheduling MajorDeltaCompactionOp(45169db616af43f186fb78ab4a20bd42): perf score=1.000000
I20260812 06:19:25.803097  7632 maintenance_manager.cc:643] P a4c03b44f7b54441810db27ae31a30b9: MajorDeltaCompactionOp(45169db616af43f186fb78ab4a20bd42) complete. Timing: real 0.166s	user 0.113s	sys 0.045s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20631312,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":510,"lbm_read_time_us":10893,"lbm_reads_lt_1ms":472,"lbm_write_time_us":24763,"lbm_writes_lt_1ms":443,"mutex_wait_us":21,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":6400,"update_count":2000}
I20260812 06:19:25.803910  7726 maintenance_manager.cc:419] P a4c03b44f7b54441810db27ae31a30b9: Scheduling FlushDeltaMemStoresOp(45169db616af43f186fb78ab4a20bd42): perf score=10.126437
I20260812 06:19:25.853217  7632 maintenance_manager.cc:643] P a4c03b44f7b54441810db27ae31a30b9: FlushDeltaMemStoresOp(45169db616af43f186fb78ab4a20bd42) complete. Timing: real 0.049s	user 0.038s	sys 0.008s Metrics: {"bytes_written":12307489,"delete_count":0,"lbm_write_time_us":22029,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:19:25.853966  7726 maintenance_manager.cc:419] P a4c03b44f7b54441810db27ae31a30b9: Scheduling FlushDeltaMemStoresOp(45169db616af43f186fb78ab4a20bd42): perf score=2.188937
I20260812 06:19:25.869761  7632 maintenance_manager.cc:643] P a4c03b44f7b54441810db27ae31a30b9: FlushDeltaMemStoresOp(45169db616af43f186fb78ab4a20bd42) complete. Timing: real 0.016s	user 0.004s	sys 0.008s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":5098,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:25.870236  7726 maintenance_manager.cc:419] P a4c03b44f7b54441810db27ae31a30b9: Scheduling MajorDeltaCompactionOp(45169db616af43f186fb78ab4a20bd42): perf score=1.000000
I20260812 06:19:26.003067  7632 maintenance_manager.cc:643] P a4c03b44f7b54441810db27ae31a30b9: MajorDeltaCompactionOp(45169db616af43f186fb78ab4a20bd42) complete. Timing: real 0.133s	user 0.105s	sys 0.027s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20631310,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":195,"lbm_read_time_us":7971,"lbm_reads_lt_1ms":464,"lbm_write_time_us":25792,"lbm_writes_lt_1ms":443,"mutex_wait_us":2,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":86656,"update_count":2000}
I20260812 06:19:26.003780  7726 maintenance_manager.cc:419] P a4c03b44f7b54441810db27ae31a30b9: Scheduling FlushDeltaMemStoresOp(45169db616af43f186fb78ab4a20bd42): perf score=11.118625
I20260812 06:19:26.054064  7632 maintenance_manager.cc:643] P a4c03b44f7b54441810db27ae31a30b9: FlushDeltaMemStoresOp(45169db616af43f186fb78ab4a20bd42) complete. Timing: real 0.050s	user 0.024s	sys 0.021s Metrics: {"bytes_written":12717735,"delete_count":0,"lbm_write_time_us":20885,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":312,"reinsert_count":0,"update_count":1550}
I20260812 06:19:26.054885  7726 maintenance_manager.cc:419] P a4c03b44f7b54441810db27ae31a30b9: Scheduling FlushDeltaMemStoresOp(45169db616af43f186fb78ab4a20bd42): perf score=2.188937
I20260812 06:19:26.068941  7632 maintenance_manager.cc:643] P a4c03b44f7b54441810db27ae31a30b9: FlushDeltaMemStoresOp(45169db616af43f186fb78ab4a20bd42) complete. Timing: real 0.014s	user 0.010s	sys 0.001s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":4372,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:19:26.069598  7726 maintenance_manager.cc:419] P a4c03b44f7b54441810db27ae31a30b9: Scheduling FlushMRSOp(45169db616af43f186fb78ab4a20bd42): perf score=1.000000
I20260812 06:19:26.129110  7632 maintenance_manager.cc:643] P a4c03b44f7b54441810db27ae31a30b9: FlushMRSOp(45169db616af43f186fb78ab4a20bd42) complete. Timing: real 0.059s	user 0.037s	sys 0.000s Metrics: {"bytes_written":1275447,"cfile_init":1,"dirs.queue_time_us":56,"dirs.run_cpu_time_us":181,"dirs.run_wall_time_us":1220,"drs_written":1,"lbm_read_time_us":39,"lbm_reads_lt_1ms":4,"lbm_write_time_us":2295,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":31}
I20260812 06:19:26.129819  7726 maintenance_manager.cc:419] P a4c03b44f7b54441810db27ae31a30b9: Scheduling LogGCOp(45169db616af43f186fb78ab4a20bd42): free 121006700 bytes of WAL
I20260812 06:19:26.130033  7632 log_reader.cc:385] T 45169db616af43f186fb78ab4a20bd42: removed 12 log segments from log reader
I20260812 06:19:26.130093  7632 log.cc:1079] T 45169db616af43f186fb78ab4a20bd42 P a4c03b44f7b54441810db27ae31a30b9: Deleting log segment in path: /tmp/dist-test-task4BgTQF/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515560703209-7469-0/minicluster-data/ts-0-root/wals/45169db616af43f186fb78ab4a20bd42/wal-000000028 (ops 135-139)
I20260812 06:19:26.130148  7632 log.cc:1079] T 45169db616af43f186fb78ab4a20bd42 P a4c03b44f7b54441810db27ae31a30b9: Deleting log segment in path: /tmp/dist-test-task4BgTQF/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515560703209-7469-0/minicluster-data/ts-0-root/wals/45169db616af43f186fb78ab4a20bd42/wal-000000029 (ops 140-144)
I20260812 06:19:26.130182  7632 log.cc:1079] T 45169db616af43f186fb78ab4a20bd42 P a4c03b44f7b54441810db27ae31a30b9: Deleting log segment in path: /tmp/dist-test-task4BgTQF/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515560703209-7469-0/minicluster-data/ts-0-root/wals/45169db616af43f186fb78ab4a20bd42/wal-000000030 (ops 145-149)
I20260812 06:19:26.130215  7632 log.cc:1079] T 45169db616af43f186fb78ab4a20bd42 P a4c03b44f7b54441810db27ae31a30b9: Deleting log segment in path: /tmp/dist-test-task4BgTQF/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515560703209-7469-0/minicluster-data/ts-0-root/wals/45169db616af43f186fb78ab4a20bd42/wal-000000031 (ops 150-154)
I20260812 06:19:26.130249  7632 log.cc:1079] T 45169db616af43f186fb78ab4a20bd42 P a4c03b44f7b54441810db27ae31a30b9: Deleting log segment in path: /tmp/dist-test-task4BgTQF/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515560703209-7469-0/minicluster-data/ts-0-root/wals/45169db616af43f186fb78ab4a20bd42/wal-000000032 (ops 155-158)
I20260812 06:19:26.130273  7632 log.cc:1079] T 45169db616af43f186fb78ab4a20bd42 P a4c03b44f7b54441810db27ae31a30b9: Deleting log segment in path: /tmp/dist-test-task4BgTQF/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515560703209-7469-0/minicluster-data/ts-0-root/wals/45169db616af43f186fb78ab4a20bd42/wal-000000033 (ops 159-163)
I20260812 06:19:26.130296  7632 log.cc:1079] T 45169db616af43f186fb78ab4a20bd42 P a4c03b44f7b54441810db27ae31a30b9: Deleting log segment in path: /tmp/dist-test-task4BgTQF/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515560703209-7469-0/minicluster-data/ts-0-root/wals/45169db616af43f186fb78ab4a20bd42/wal-000000034 (ops 164-168)
I20260812 06:19:26.130318  7632 log.cc:1079] T 45169db616af43f186fb78ab4a20bd42 P a4c03b44f7b54441810db27ae31a30b9: Deleting log segment in path: /tmp/dist-test-task4BgTQF/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515560703209-7469-0/minicluster-data/ts-0-root/wals/45169db616af43f186fb78ab4a20bd42/wal-000000035 (ops 169-173)
I20260812 06:19:26.130347  7632 log.cc:1079] T 45169db616af43f186fb78ab4a20bd42 P a4c03b44f7b54441810db27ae31a30b9: Deleting log segment in path: /tmp/dist-test-task4BgTQF/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515560703209-7469-0/minicluster-data/ts-0-root/wals/45169db616af43f186fb78ab4a20bd42/wal-000000036 (ops 174-178)
I20260812 06:19:26.130379  7632 log.cc:1079] T 45169db616af43f186fb78ab4a20bd42 P a4c03b44f7b54441810db27ae31a30b9: Deleting log segment in path: /tmp/dist-test-task4BgTQF/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515560703209-7469-0/minicluster-data/ts-0-root/wals/45169db616af43f186fb78ab4a20bd42/wal-000000037 (ops 179-183)
I20260812 06:19:26.130426  7632 log.cc:1079] T 45169db616af43f186fb78ab4a20bd42 P a4c03b44f7b54441810db27ae31a30b9: Deleting log segment in path: /tmp/dist-test-task4BgTQF/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515560703209-7469-0/minicluster-data/ts-0-root/wals/45169db616af43f186fb78ab4a20bd42/wal-000000038 (ops 184-188)
I20260812 06:19:26.130481  7632 log.cc:1079] T 45169db616af43f186fb78ab4a20bd42 P a4c03b44f7b54441810db27ae31a30b9: Deleting log segment in path: /tmp/dist-test-task4BgTQF/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515560703209-7469-0/minicluster-data/ts-0-root/wals/45169db616af43f186fb78ab4a20bd42/wal-000000039 (ops 189-193)
I20260812 06:19:26.158299  7632 maintenance_manager.cc:643] P a4c03b44f7b54441810db27ae31a30b9: LogGCOp(45169db616af43f186fb78ab4a20bd42) complete. Timing: real 0.028s	user 0.000s	sys 0.025s Metrics: {}
I20260812 06:19:26.158696  7726 maintenance_manager.cc:419] P a4c03b44f7b54441810db27ae31a30b9: Scheduling UndoDeltaBlockGCOp(45169db616af43f186fb78ab4a20bd42): 483 bytes on disk
I20260812 06:19:26.159149  7632 maintenance_manager.cc:643] P a4c03b44f7b54441810db27ae31a30b9: UndoDeltaBlockGCOp(45169db616af43f186fb78ab4a20bd42) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":107,"lbm_reads_lt_1ms":4}
I20260812 06:19:26.159646  7726 maintenance_manager.cc:419] P a4c03b44f7b54441810db27ae31a30b9: Scheduling FlushDeltaMemStoresOp(45169db616af43f186fb78ab4a20bd42): perf score=7.149875
I20260812 06:19:26.183003  7632 maintenance_manager.cc:643] P a4c03b44f7b54441810db27ae31a30b9: FlushDeltaMemStoresOp(45169db616af43f186fb78ab4a20bd42) complete. Timing: real 0.023s	user 0.001s	sys 0.022s Metrics: {"bytes_written":8697368,"delete_count":0,"lbm_write_time_us":10322,"lbm_writes_lt_1ms":215,"reinsert_count":0,"update_count":1060}
I20260812 06:19:26.183876  7726 maintenance_manager.cc:419] P a4c03b44f7b54441810db27ae31a30b9: Scheduling FlushDeltaMemStoresOp(45169db616af43f186fb78ab4a20bd42): perf score=2.188937
I20260812 06:19:26.204053  7632 maintenance_manager.cc:643] P a4c03b44f7b54441810db27ae31a30b9: FlushDeltaMemStoresOp(45169db616af43f186fb78ab4a20bd42) complete. Timing: real 0.020s	user 0.012s	sys 0.006s Metrics: {"bytes_written":3610355,"delete_count":0,"lbm_write_time_us":7157,"lbm_writes_lt_1ms":91,"reinsert_count":0,"update_count":440}
I20260812 06:19:26.204516  7726 maintenance_manager.cc:419] P a4c03b44f7b54441810db27ae31a30b9: Scheduling MajorDeltaCompactionOp(45169db616af43f186fb78ab4a20bd42): perf score=1.000000
I20260812 06:19:26.277112  7469 heavy-update-compaction-itest.cc:229] Time spent updating: real 5.259s	user 1.980s	sys 0.120s
I20260812 06:19:26.375319  7469 heavy-update-compaction-itest.cc:265] Time spent scanning: real 0.098s	user 0.003s	sys 0.000s
I20260812 06:19:26.375975  7469 tablet_server.cc:179] TabletServer@127.7.75.65:0 shutting down...
I20260812 06:19:26.449673  7632 maintenance_manager.cc:643] P a4c03b44f7b54441810db27ae31a30b9: MajorDeltaCompactionOp(45169db616af43f186fb78ab4a20bd42) complete. Timing: real 0.245s	user 0.168s	sys 0.072s Metrics: {"cfile_cache_miss":734,"cfile_cache_miss_bytes":32938764,"cfile_init":7,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":11477,"lbm_read_time_us":15949,"lbm_reads_lt_1ms":762,"lbm_write_time_us":50456,"lbm_writes_lt_1ms":743,"mutex_wait_us":3879,"peak_mem_usage":87969044,"reinsert_count":0,"spinlock_wait_cycles":36992,"thread_start_us":118,"threads_started":1,"update_count":3500}
I20260812 06:19:26.450466  7469 ts_tablet_manager.cc:1507] Shutting down tablet manager...
I20260812 06:19:26.450981  7469 tablet_replica.cc:333] T 45169db616af43f186fb78ab4a20bd42 P a4c03b44f7b54441810db27ae31a30b9: stopping tablet replica
I20260812 06:19:26.451241  7469 raft_consensus.cc:2243] T 45169db616af43f186fb78ab4a20bd42 P a4c03b44f7b54441810db27ae31a30b9 [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:19:26.451499  7469 raft_consensus.cc:2272] T 45169db616af43f186fb78ab4a20bd42 P a4c03b44f7b54441810db27ae31a30b9 [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:19:26.645211  7469 tablet_server.cc:196] TabletServer@127.7.75.65:0 shutdown complete.
I20260812 06:19:26.651091  7469 master.cc:562] Master@127.7.75.126:41833 shutting down...
I20260812 06:19:26.655850  7469 raft_consensus.cc:2243] T 00000000000000000000000000000000 P 2553ff6c23a546b58a500d2187a652e0 [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:19:26.656033  7469 raft_consensus.cc:2272] T 00000000000000000000000000000000 P 2553ff6c23a546b58a500d2187a652e0 [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:19:26.656126  7469 tablet_replica.cc:333] T 00000000000000000000000000000000 P 2553ff6c23a546b58a500d2187a652e0: stopping tablet replica
I20260812 06:19:26.668622  7469 master.cc:584] Master@127.7.75.126:41833 shutdown complete.
[       OK ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/0 (6050 ms)
[ RUN      ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/1
I20260812 06:19:26.765501  7469 internal_mini_cluster.cc:156] Creating distributed mini masters. Addrs: 127.7.75.126:43645
I20260812 06:19:26.765870  7469 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:19:26.768414  7790 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:19:26.768442  7469 server_base.cc:1061] running on GCE node
W20260812 06:19:26.768455  7788 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:19:26.768474  7787 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:19:26.768780  7469 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:19:26.768850  7469 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:19:26.768875  7469 hybrid_clock.cc:648] HybridClock initialized: now 1786515566768875 us; error 0 us; skew 500 ppm
I20260812 06:19:26.769754  7469 webserver.cc:533] Webserver started at http://127.7.75.126:42419/ using document root <none> and password file <none>
I20260812 06:19:26.769958  7469 fs_manager.cc:362] Metadata directory not provided
I20260812 06:19:26.770035  7469 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:19:26.770124  7469 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:19:26.770541  7469 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-task4BgTQF/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515560703209-7469-0/minicluster-data/master-0-root/instance:
uuid: "4cbca2ac08434391887bb06de3138eaa"
format_stamp: "Formatted at 2026-08-12 06:19:26 on dist-test-slave-drl0"
I20260812 06:19:26.772228  7469 fs_manager.cc:696] Time spent creating directory manager: real 0.001s	user 0.000s	sys 0.002s
I20260812 06:19:26.773654  7800 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:19:26.774047  7469 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.000s	sys 0.001s
I20260812 06:19:26.774142  7469 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-task4BgTQF/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515560703209-7469-0/minicluster-data/master-0-root
uuid: "4cbca2ac08434391887bb06de3138eaa"
format_stamp: "Formatted at 2026-08-12 06:19:26 on dist-test-slave-drl0"
I20260812 06:19:26.774230  7469 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-task4BgTQF/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515560703209-7469-0/minicluster-data/master-0-root
metadata directory: /tmp/dist-test-task4BgTQF/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515560703209-7469-0/minicluster-data/master-0-root
1 data directories: /tmp/dist-test-task4BgTQF/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515560703209-7469-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:19:26.792856  7469 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:19:26.793232  7469 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:19:26.798233  7469 rpc_server.cc:307] RPC server started. Bound to: 127.7.75.126:43645
I20260812 06:19:26.801292  7875 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.7.75.126:43645 every 8 connection(s)
I20260812 06:19:26.802204  7876 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:19:26.820219  7876 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P 4cbca2ac08434391887bb06de3138eaa: Bootstrap starting.
I20260812 06:19:26.821099  7876 tablet_bootstrap.cc:654] T 00000000000000000000000000000000 P 4cbca2ac08434391887bb06de3138eaa: Neither blocks nor log segments found. Creating new log.
I20260812 06:19:26.822211  7876 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P 4cbca2ac08434391887bb06de3138eaa: No bootstrap required, opened a new log
I20260812 06:19:26.822667  7876 raft_consensus.cc:359] T 00000000000000000000000000000000 P 4cbca2ac08434391887bb06de3138eaa [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "4cbca2ac08434391887bb06de3138eaa" member_type: VOTER }
I20260812 06:19:26.822763  7876 raft_consensus.cc:385] T 00000000000000000000000000000000 P 4cbca2ac08434391887bb06de3138eaa [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:19:26.822786  7876 raft_consensus.cc:740] T 00000000000000000000000000000000 P 4cbca2ac08434391887bb06de3138eaa [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: 4cbca2ac08434391887bb06de3138eaa, State: Initialized, Role: FOLLOWER
I20260812 06:19:26.822981  7876 consensus_queue.cc:260] T 00000000000000000000000000000000 P 4cbca2ac08434391887bb06de3138eaa [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: "4cbca2ac08434391887bb06de3138eaa" member_type: VOTER }
I20260812 06:19:26.823062  7876 raft_consensus.cc:399] T 00000000000000000000000000000000 P 4cbca2ac08434391887bb06de3138eaa [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:19:26.823107  7876 raft_consensus.cc:493] T 00000000000000000000000000000000 P 4cbca2ac08434391887bb06de3138eaa [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:19:26.823170  7876 raft_consensus.cc:3060] T 00000000000000000000000000000000 P 4cbca2ac08434391887bb06de3138eaa [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:19:26.823889  7876 raft_consensus.cc:515] T 00000000000000000000000000000000 P 4cbca2ac08434391887bb06de3138eaa [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "4cbca2ac08434391887bb06de3138eaa" member_type: VOTER }
I20260812 06:19:26.824015  7876 leader_election.cc:304] T 00000000000000000000000000000000 P 4cbca2ac08434391887bb06de3138eaa [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: 4cbca2ac08434391887bb06de3138eaa; no voters: 
I20260812 06:19:26.824249  7876 leader_election.cc:290] T 00000000000000000000000000000000 P 4cbca2ac08434391887bb06de3138eaa [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:19:26.824465  7880 raft_consensus.cc:2804] T 00000000000000000000000000000000 P 4cbca2ac08434391887bb06de3138eaa [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:19:26.824685  7880 raft_consensus.cc:697] T 00000000000000000000000000000000 P 4cbca2ac08434391887bb06de3138eaa [term 1 LEADER]: Becoming Leader. State: Replica: 4cbca2ac08434391887bb06de3138eaa, State: Running, Role: LEADER
I20260812 06:19:26.824780  7876 sys_catalog.cc:565] T 00000000000000000000000000000000 P 4cbca2ac08434391887bb06de3138eaa [sys.catalog]: configured and running, proceeding with master startup.
I20260812 06:19:26.824841  7880 consensus_queue.cc:237] T 00000000000000000000000000000000 P 4cbca2ac08434391887bb06de3138eaa [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: "4cbca2ac08434391887bb06de3138eaa" member_type: VOTER }
I20260812 06:19:26.825385  7881 sys_catalog.cc:455] T 00000000000000000000000000000000 P 4cbca2ac08434391887bb06de3138eaa [sys.catalog]: SysCatalogTable state changed. Reason: RaftConsensus started. Latest consensus state: current_term: 1 leader_uuid: "4cbca2ac08434391887bb06de3138eaa" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "4cbca2ac08434391887bb06de3138eaa" member_type: VOTER } }
I20260812 06:19:26.825398  7883 sys_catalog.cc:455] T 00000000000000000000000000000000 P 4cbca2ac08434391887bb06de3138eaa [sys.catalog]: SysCatalogTable state changed. Reason: New leader 4cbca2ac08434391887bb06de3138eaa. Latest consensus state: current_term: 1 leader_uuid: "4cbca2ac08434391887bb06de3138eaa" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "4cbca2ac08434391887bb06de3138eaa" member_type: VOTER } }
I20260812 06:19:26.825506  7881 sys_catalog.cc:458] T 00000000000000000000000000000000 P 4cbca2ac08434391887bb06de3138eaa [sys.catalog]: This master's current role is: LEADER
I20260812 06:19:26.825539  7883 sys_catalog.cc:458] T 00000000000000000000000000000000 P 4cbca2ac08434391887bb06de3138eaa [sys.catalog]: This master's current role is: LEADER
I20260812 06:19:26.825779  7888 catalog_manager.cc:1511] Loading table and tablet metadata into memory...
I20260812 06:19:26.826550  7888 catalog_manager.cc:1520] Initializing Kudu cluster ID...
I20260812 06:19:26.827160  7469 internal_mini_cluster.cc:184] Waiting to initialize catalog manager on master 0
I20260812 06:19:26.828529  7888 catalog_manager.cc:1383] Generated new cluster ID: 82b377211f594c168843322eb5dd10a9
I20260812 06:19:26.828616  7888 catalog_manager.cc:1531] Initializing Kudu internal certificate authority...
I20260812 06:19:26.848963  7888 catalog_manager.cc:1406] Generated new certificate authority record
I20260812 06:19:26.849581  7888 catalog_manager.cc:1540] Loading token signing keys...
I20260812 06:19:26.859051  7888 catalog_manager.cc:6092] T 00000000000000000000000000000000 P 4cbca2ac08434391887bb06de3138eaa: Generated new TSK 0
I20260812 06:19:26.859225  7888 catalog_manager.cc:1550] Initializing in-progress tserver states...
I20260812 06:19:26.891942  7469 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:19:26.894649  7916 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:19:26.894657  7469 server_base.cc:1061] running on GCE node
W20260812 06:19:26.894912  7913 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:19:26.895006  7914 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:19:26.895349  7469 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:19:26.895395  7469 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:19:26.895416  7469 hybrid_clock.cc:648] HybridClock initialized: now 1786515566895415 us; error 0 us; skew 500 ppm
I20260812 06:19:26.896397  7469 webserver.cc:533] Webserver started at http://127.7.75.65:46105/ using document root <none> and password file <none>
I20260812 06:19:26.896552  7469 fs_manager.cc:362] Metadata directory not provided
I20260812 06:19:26.896621  7469 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:19:26.896682  7469 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:19:26.897063  7469 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-task4BgTQF/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515560703209-7469-0/minicluster-data/ts-0-root/instance:
uuid: "b28235d2539e4c1bbd0cff56bdf600a5"
format_stamp: "Formatted at 2026-08-12 06:19:26 on dist-test-slave-drl0"
I20260812 06:19:26.898715  7469 fs_manager.cc:696] Time spent creating directory manager: real 0.001s	user 0.002s	sys 0.000s
I20260812 06:19:26.900274  7922 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:19:26.900653  7469 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.001s	sys 0.000s
I20260812 06:19:26.900718  7469 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-task4BgTQF/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515560703209-7469-0/minicluster-data/ts-0-root
uuid: "b28235d2539e4c1bbd0cff56bdf600a5"
format_stamp: "Formatted at 2026-08-12 06:19:26 on dist-test-slave-drl0"
I20260812 06:19:26.900768  7469 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-task4BgTQF/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515560703209-7469-0/minicluster-data/ts-0-root
metadata directory: /tmp/dist-test-task4BgTQF/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515560703209-7469-0/minicluster-data/ts-0-root
1 data directories: /tmp/dist-test-task4BgTQF/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515560703209-7469-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:19:26.905187  7469 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:19:26.905453  7469 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:19:26.905714  7469 txn_system_client.cc:432] TxnSystemClient initialization is disabled...
I20260812 06:19:26.906137  7469 ts_tablet_manager.cc:585] Loaded tablet metadata (0 total tablets, 0 live tablets)
I20260812 06:19:26.906177  7469 ts_tablet_manager.cc:531] Time spent load tablet metadata: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:19:26.906208  7469 ts_tablet_manager.cc:616] Registered 0 tablets
I20260812 06:19:26.906221  7469 ts_tablet_manager.cc:595] Time spent register tablets: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:19:26.910677  7469 rpc_server.cc:307] RPC server started. Bound to: 127.7.75.65:37301
I20260812 06:19:26.910698  8017 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.7.75.65:37301 every 8 connection(s)
I20260812 06:19:26.919332  8018 heartbeater.cc:344] Connected to a master server at 127.7.75.126:43645
I20260812 06:19:26.919456  8018 heartbeater.cc:461] Registering TS with master...
I20260812 06:19:26.919771  8018 heartbeater.cc:507] Master 127.7.75.126:43645 requested a full tablet report, sending...
I20260812 06:19:26.920549  7826 ts_manager.cc:194] Registered new tserver with Master: b28235d2539e4c1bbd0cff56bdf600a5 (127.7.75.65:37301)
I20260812 06:19:26.921350  7826 master_service.cc:502] Signed X509 certificate for tserver {username='slave'} at 127.0.0.1:56550
I20260812 06:19:26.921443  7469 internal_mini_cluster.cc:371] 1 TS(s) registered with all masters after 0.010286676s
I20260812 06:19:26.930737  7826 catalog_manager.cc:2283] Servicing CreateTable request from {username='slave'} at 127.0.0.1:56566:
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:19:26.942090  7963 tablet_service.cc:1511] Processing CreateTablet for tablet c1ec7be1bb3b4260b9b6fc4a230f4056 (DEFAULT_TABLE table=heavy-update-compaction-test [id=6ead4d7d88304ea9aa3640070a01a627]), partition=
I20260812 06:19:26.942394  7963 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet c1ec7be1bb3b4260b9b6fc4a230f4056. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:19:26.944383  8036 tablet_bootstrap.cc:492] T c1ec7be1bb3b4260b9b6fc4a230f4056 P b28235d2539e4c1bbd0cff56bdf600a5: Bootstrap starting.
I20260812 06:19:26.945346  8036 tablet_bootstrap.cc:654] T c1ec7be1bb3b4260b9b6fc4a230f4056 P b28235d2539e4c1bbd0cff56bdf600a5: Neither blocks nor log segments found. Creating new log.
I20260812 06:19:26.946487  8036 tablet_bootstrap.cc:492] T c1ec7be1bb3b4260b9b6fc4a230f4056 P b28235d2539e4c1bbd0cff56bdf600a5: No bootstrap required, opened a new log
I20260812 06:19:26.946621  8036 ts_tablet_manager.cc:1403] T c1ec7be1bb3b4260b9b6fc4a230f4056 P b28235d2539e4c1bbd0cff56bdf600a5: Time spent bootstrapping tablet: real 0.002s	user 0.002s	sys 0.000s
I20260812 06:19:26.947151  8036 raft_consensus.cc:359] T c1ec7be1bb3b4260b9b6fc4a230f4056 P b28235d2539e4c1bbd0cff56bdf600a5 [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "b28235d2539e4c1bbd0cff56bdf600a5" member_type: VOTER last_known_addr { host: "127.7.75.65" port: 37301 } }
I20260812 06:19:26.947265  8036 raft_consensus.cc:385] T c1ec7be1bb3b4260b9b6fc4a230f4056 P b28235d2539e4c1bbd0cff56bdf600a5 [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:19:26.947312  8036 raft_consensus.cc:740] T c1ec7be1bb3b4260b9b6fc4a230f4056 P b28235d2539e4c1bbd0cff56bdf600a5 [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: b28235d2539e4c1bbd0cff56bdf600a5, State: Initialized, Role: FOLLOWER
I20260812 06:19:26.947451  8036 consensus_queue.cc:260] T c1ec7be1bb3b4260b9b6fc4a230f4056 P b28235d2539e4c1bbd0cff56bdf600a5 [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: "b28235d2539e4c1bbd0cff56bdf600a5" member_type: VOTER last_known_addr { host: "127.7.75.65" port: 37301 } }
I20260812 06:19:26.947542  8036 raft_consensus.cc:399] T c1ec7be1bb3b4260b9b6fc4a230f4056 P b28235d2539e4c1bbd0cff56bdf600a5 [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:19:26.947590  8036 raft_consensus.cc:493] T c1ec7be1bb3b4260b9b6fc4a230f4056 P b28235d2539e4c1bbd0cff56bdf600a5 [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:19:26.947642  8036 raft_consensus.cc:3060] T c1ec7be1bb3b4260b9b6fc4a230f4056 P b28235d2539e4c1bbd0cff56bdf600a5 [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:19:26.948992  8036 raft_consensus.cc:515] T c1ec7be1bb3b4260b9b6fc4a230f4056 P b28235d2539e4c1bbd0cff56bdf600a5 [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "b28235d2539e4c1bbd0cff56bdf600a5" member_type: VOTER last_known_addr { host: "127.7.75.65" port: 37301 } }
I20260812 06:19:26.949157  8036 leader_election.cc:304] T c1ec7be1bb3b4260b9b6fc4a230f4056 P b28235d2539e4c1bbd0cff56bdf600a5 [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: b28235d2539e4c1bbd0cff56bdf600a5; no voters: 
I20260812 06:19:26.949364  8036 leader_election.cc:290] T c1ec7be1bb3b4260b9b6fc4a230f4056 P b28235d2539e4c1bbd0cff56bdf600a5 [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:19:26.949522  8038 raft_consensus.cc:2804] T c1ec7be1bb3b4260b9b6fc4a230f4056 P b28235d2539e4c1bbd0cff56bdf600a5 [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:19:26.949764  8038 raft_consensus.cc:697] T c1ec7be1bb3b4260b9b6fc4a230f4056 P b28235d2539e4c1bbd0cff56bdf600a5 [term 1 LEADER]: Becoming Leader. State: Replica: b28235d2539e4c1bbd0cff56bdf600a5, State: Running, Role: LEADER
I20260812 06:19:26.949764  8036 ts_tablet_manager.cc:1434] T c1ec7be1bb3b4260b9b6fc4a230f4056 P b28235d2539e4c1bbd0cff56bdf600a5: Time spent starting tablet: real 0.003s	user 0.000s	sys 0.003s
I20260812 06:19:26.949798  8018 heartbeater.cc:499] Master 127.7.75.126:43645 was elected leader, sending a full tablet report...
I20260812 06:19:26.949977  8038 consensus_queue.cc:237] T c1ec7be1bb3b4260b9b6fc4a230f4056 P b28235d2539e4c1bbd0cff56bdf600a5 [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: "b28235d2539e4c1bbd0cff56bdf600a5" member_type: VOTER last_known_addr { host: "127.7.75.65" port: 37301 } }
I20260812 06:19:26.951443  7826 catalog_manager.cc:5719] T c1ec7be1bb3b4260b9b6fc4a230f4056 P b28235d2539e4c1bbd0cff56bdf600a5 reported cstate change: term changed from 0 to 1, leader changed from <none> to b28235d2539e4c1bbd0cff56bdf600a5 (127.7.75.65). New cstate: current_term: 1 leader_uuid: "b28235d2539e4c1bbd0cff56bdf600a5" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "b28235d2539e4c1bbd0cff56bdf600a5" member_type: VOTER last_known_addr { host: "127.7.75.65" port: 37301 } health_report { overall_health: HEALTHY } } }
I20260812 06:19:27.015671  7469 heavy-update-compaction-itest.cc:215] Time spent inserting: real 0.056s	user 0.010s	sys 0.012s
I20260812 06:19:27.161803  8020 maintenance_manager.cc:419] P b28235d2539e4c1bbd0cff56bdf600a5: Scheduling FlushMRSOp(c1ec7be1bb3b4260b9b6fc4a230f4056): perf score=15.086190
I20260812 06:19:27.303867  7927 maintenance_manager.cc:643] P b28235d2539e4c1bbd0cff56bdf600a5: FlushMRSOp(c1ec7be1bb3b4260b9b6fc4a230f4056) complete. Timing: real 0.142s	user 0.098s	sys 0.043s Metrics: {"bytes_written":11897250,"cfile_init":1,"delete_count":0,"dirs.queue_time_us":80,"dirs.run_cpu_time_us":213,"dirs.run_wall_time_us":696,"drs_written":1,"lbm_read_time_us":37,"lbm_reads_lt_1ms":4,"lbm_write_time_us":38308,"lbm_writes_lt_1ms":657,"peak_mem_usage":0,"reinsert_count":0,"rows_written":104,"update_count":1450}
I20260812 06:19:27.304455  8020 maintenance_manager.cc:419] P b28235d2539e4c1bbd0cff56bdf600a5: Scheduling LogGCOp(c1ec7be1bb3b4260b9b6fc4a230f4056): free 20743880 bytes of WAL
I20260812 06:19:27.304667  7927 log_reader.cc:385] T c1ec7be1bb3b4260b9b6fc4a230f4056: removed 2 log segments from log reader
I20260812 06:19:27.304709  7927 log.cc:1079] T c1ec7be1bb3b4260b9b6fc4a230f4056 P b28235d2539e4c1bbd0cff56bdf600a5: Deleting log segment in path: /tmp/dist-test-task4BgTQF/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515560703209-7469-0/minicluster-data/ts-0-root/wals/c1ec7be1bb3b4260b9b6fc4a230f4056/wal-000000001 (ops 1-6)
I20260812 06:19:27.304739  7927 log.cc:1079] T c1ec7be1bb3b4260b9b6fc4a230f4056 P b28235d2539e4c1bbd0cff56bdf600a5: Deleting log segment in path: /tmp/dist-test-task4BgTQF/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515560703209-7469-0/minicluster-data/ts-0-root/wals/c1ec7be1bb3b4260b9b6fc4a230f4056/wal-000000002 (ops 7-11)
I20260812 06:19:27.309303  7927 maintenance_manager.cc:643] P b28235d2539e4c1bbd0cff56bdf600a5: LogGCOp(c1ec7be1bb3b4260b9b6fc4a230f4056) complete. Timing: real 0.005s	user 0.000s	sys 0.002s Metrics: {}
I20260812 06:19:27.309906  8020 maintenance_manager.cc:419] P b28235d2539e4c1bbd0cff56bdf600a5: Scheduling FlushDeltaMemStoresOp(c1ec7be1bb3b4260b9b6fc4a230f4056): perf score=2.188937
I20260812 06:19:27.331081  7927 maintenance_manager.cc:643] P b28235d2539e4c1bbd0cff56bdf600a5: FlushDeltaMemStoresOp(c1ec7be1bb3b4260b9b6fc4a230f4056) complete. Timing: real 0.021s	user 0.018s	sys 0.000s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":7051,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:27.331563  8020 maintenance_manager.cc:419] P b28235d2539e4c1bbd0cff56bdf600a5: Scheduling UndoDeltaBlockGCOp(c1ec7be1bb3b4260b9b6fc4a230f4056): 12719216 bytes on disk
I20260812 06:19:27.332648  7927 maintenance_manager.cc:643] P b28235d2539e4c1bbd0cff56bdf600a5: UndoDeltaBlockGCOp(c1ec7be1bb3b4260b9b6fc4a230f4056) complete. Timing: real 0.001s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":76,"lbm_reads_lt_1ms":4}
I20260812 06:19:27.333102  8020 maintenance_manager.cc:419] P b28235d2539e4c1bbd0cff56bdf600a5: Scheduling MajorDeltaCompactionOp(c1ec7be1bb3b4260b9b6fc4a230f4056): perf score=1.000000
I20260812 06:19:27.484815  7927 maintenance_manager.cc:643] P b28235d2539e4c1bbd0cff56bdf600a5: MajorDeltaCompactionOp(c1ec7be1bb3b4260b9b6fc4a230f4056) complete. Timing: real 0.152s	user 0.100s	sys 0.048s Metrics: {"cfile_cache_miss":422,"cfile_cache_miss_bytes":20262036,"cfile_init":7,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":623,"lbm_read_time_us":11830,"lbm_reads_lt_1ms":450,"lbm_write_time_us":27987,"lbm_writes_lt_1ms":433,"peak_mem_usage":49238594,"reinsert_count":0,"spinlock_wait_cycles":6400,"thread_start_us":292,"threads_started":5,"update_count":1950}
I20260812 06:19:27.485495  8020 maintenance_manager.cc:419] P b28235d2539e4c1bbd0cff56bdf600a5: Scheduling FlushDeltaMemStoresOp(c1ec7be1bb3b4260b9b6fc4a230f4056): perf score=11.118625
I20260812 06:19:27.531754  7927 maintenance_manager.cc:643] P b28235d2539e4c1bbd0cff56bdf600a5: FlushDeltaMemStoresOp(c1ec7be1bb3b4260b9b6fc4a230f4056) complete. Timing: real 0.046s	user 0.037s	sys 0.007s Metrics: {"bytes_written":12717736,"delete_count":0,"lbm_write_time_us":19764,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":312,"reinsert_count":0,"update_count":1550}
I20260812 06:19:27.532256  8020 maintenance_manager.cc:419] P b28235d2539e4c1bbd0cff56bdf600a5: Scheduling FlushDeltaMemStoresOp(c1ec7be1bb3b4260b9b6fc4a230f4056): perf score=2.188937
I20260812 06:19:27.554502  7927 maintenance_manager.cc:643] P b28235d2539e4c1bbd0cff56bdf600a5: FlushDeltaMemStoresOp(c1ec7be1bb3b4260b9b6fc4a230f4056) complete. Timing: real 0.022s	user 0.000s	sys 0.012s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5466,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:27.555022  8020 maintenance_manager.cc:419] P b28235d2539e4c1bbd0cff56bdf600a5: Scheduling FlushDeltaMemStoresOp(c1ec7be1bb3b4260b9b6fc4a230f4056): perf score=2.188937
I20260812 06:19:27.564388  7927 maintenance_manager.cc:643] P b28235d2539e4c1bbd0cff56bdf600a5: FlushDeltaMemStoresOp(c1ec7be1bb3b4260b9b6fc4a230f4056) complete. Timing: real 0.009s	user 0.003s	sys 0.005s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3658,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:19:27.564747  8020 maintenance_manager.cc:419] P b28235d2539e4c1bbd0cff56bdf600a5: Scheduling MajorDeltaCompactionOp(c1ec7be1bb3b4260b9b6fc4a230f4056): perf score=1.000000
I20260812 06:19:27.760686  7927 maintenance_manager.cc:643] P b28235d2539e4c1bbd0cff56bdf600a5: MajorDeltaCompactionOp(c1ec7be1bb3b4260b9b6fc4a230f4056) complete. Timing: real 0.196s	user 0.135s	sys 0.046s 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":213,"lbm_read_time_us":12938,"lbm_reads_lt_1ms":573,"lbm_write_time_us":33440,"lbm_writes_lt_1ms":543,"mutex_wait_us":50,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":45056,"update_count":2500}
I20260812 06:19:27.761231  8020 maintenance_manager.cc:419] P b28235d2539e4c1bbd0cff56bdf600a5: Scheduling FlushDeltaMemStoresOp(c1ec7be1bb3b4260b9b6fc4a230f4056): perf score=14.095187
I20260812 06:19:27.819278  7927 maintenance_manager.cc:643] P b28235d2539e4c1bbd0cff56bdf600a5: FlushDeltaMemStoresOp(c1ec7be1bb3b4260b9b6fc4a230f4056) complete. Timing: real 0.058s	user 0.032s	sys 0.020s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":24236,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:27.819736  8020 maintenance_manager.cc:419] P b28235d2539e4c1bbd0cff56bdf600a5: Scheduling MajorDeltaCompactionOp(c1ec7be1bb3b4260b9b6fc4a230f4056): perf score=1.000000
I20260812 06:19:27.987995  7927 maintenance_manager.cc:643] P b28235d2539e4c1bbd0cff56bdf600a5: MajorDeltaCompactionOp(c1ec7be1bb3b4260b9b6fc4a230f4056) complete. Timing: real 0.168s	user 0.101s	sys 0.059s Metrics: {"cfile_cache_miss":431,"cfile_cache_miss_bytes":20672157,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":1,"delta_iterators_relevant":1,"dirs.queue_time_us":145,"lbm_read_time_us":13158,"lbm_reads_lt_1ms":463,"lbm_write_time_us":26683,"lbm_writes_lt_1ms":443,"mutex_wait_us":41,"peak_mem_usage":50689328,"reinsert_count":0,"update_count":2000}
I20260812 06:19:27.988571  8020 maintenance_manager.cc:419] P b28235d2539e4c1bbd0cff56bdf600a5: Scheduling FlushDeltaMemStoresOp(c1ec7be1bb3b4260b9b6fc4a230f4056): perf score=14.095187
I20260812 06:19:28.039908  7927 maintenance_manager.cc:643] P b28235d2539e4c1bbd0cff56bdf600a5: FlushDeltaMemStoresOp(c1ec7be1bb3b4260b9b6fc4a230f4056) complete. Timing: real 0.051s	user 0.033s	sys 0.016s Metrics: {"bytes_written":16409903,"delete_count":0,"lbm_write_time_us":23128,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:28.040411  8020 maintenance_manager.cc:419] P b28235d2539e4c1bbd0cff56bdf600a5: Scheduling FlushDeltaMemStoresOp(c1ec7be1bb3b4260b9b6fc4a230f4056): perf score=2.188937
I20260812 06:19:28.055018  7927 maintenance_manager.cc:643] P b28235d2539e4c1bbd0cff56bdf600a5: FlushDeltaMemStoresOp(c1ec7be1bb3b4260b9b6fc4a230f4056) complete. Timing: real 0.014s	user 0.014s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4848,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:28.055462  8020 maintenance_manager.cc:419] P b28235d2539e4c1bbd0cff56bdf600a5: Scheduling MajorDeltaCompactionOp(c1ec7be1bb3b4260b9b6fc4a230f4056): perf score=1.000000
I20260812 06:19:28.262369  7927 maintenance_manager.cc:643] P b28235d2539e4c1bbd0cff56bdf600a5: MajorDeltaCompactionOp(c1ec7be1bb3b4260b9b6fc4a230f4056) complete. Timing: real 0.207s	user 0.140s	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":300,"lbm_read_time_us":15520,"lbm_reads_lt_1ms":572,"lbm_write_time_us":31836,"lbm_writes_lt_1ms":543,"mutex_wait_us":48,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":8960,"update_count":2500}
I20260812 06:19:28.263049  8020 maintenance_manager.cc:419] P b28235d2539e4c1bbd0cff56bdf600a5: Scheduling FlushDeltaMemStoresOp(c1ec7be1bb3b4260b9b6fc4a230f4056): perf score=14.095187
I20260812 06:19:28.318589  7927 maintenance_manager.cc:643] P b28235d2539e4c1bbd0cff56bdf600a5: FlushDeltaMemStoresOp(c1ec7be1bb3b4260b9b6fc4a230f4056) complete. Timing: real 0.055s	user 0.028s	sys 0.017s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":21362,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:28.319193  8020 maintenance_manager.cc:419] P b28235d2539e4c1bbd0cff56bdf600a5: Scheduling FlushDeltaMemStoresOp(c1ec7be1bb3b4260b9b6fc4a230f4056): perf score=2.188937
I20260812 06:19:28.332808  7927 maintenance_manager.cc:643] P b28235d2539e4c1bbd0cff56bdf600a5: FlushDeltaMemStoresOp(c1ec7be1bb3b4260b9b6fc4a230f4056) complete. Timing: real 0.013s	user 0.003s	sys 0.009s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4923,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:28.333518  8020 maintenance_manager.cc:419] P b28235d2539e4c1bbd0cff56bdf600a5: Scheduling MajorDeltaCompactionOp(c1ec7be1bb3b4260b9b6fc4a230f4056): perf score=1.000000
I20260812 06:19:28.518187  7927 maintenance_manager.cc:643] P b28235d2539e4c1bbd0cff56bdf600a5: MajorDeltaCompactionOp(c1ec7be1bb3b4260b9b6fc4a230f4056) complete. Timing: real 0.184s	user 0.143s	sys 0.031s 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":175,"lbm_read_time_us":11264,"lbm_reads_lt_1ms":572,"lbm_write_time_us":35117,"lbm_writes_lt_1ms":543,"mutex_wait_us":40,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":3712,"update_count":2500}
I20260812 06:19:28.518877  8020 maintenance_manager.cc:419] P b28235d2539e4c1bbd0cff56bdf600a5: Scheduling FlushDeltaMemStoresOp(c1ec7be1bb3b4260b9b6fc4a230f4056): perf score=14.095187
I20260812 06:19:28.577775  7927 maintenance_manager.cc:643] P b28235d2539e4c1bbd0cff56bdf600a5: FlushDeltaMemStoresOp(c1ec7be1bb3b4260b9b6fc4a230f4056) complete. Timing: real 0.059s	user 0.015s	sys 0.037s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":24547,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:28.578260  8020 maintenance_manager.cc:419] P b28235d2539e4c1bbd0cff56bdf600a5: Scheduling FlushDeltaMemStoresOp(c1ec7be1bb3b4260b9b6fc4a230f4056): perf score=2.188937
I20260812 06:19:28.590987  7927 maintenance_manager.cc:643] P b28235d2539e4c1bbd0cff56bdf600a5: FlushDeltaMemStoresOp(c1ec7be1bb3b4260b9b6fc4a230f4056) complete. Timing: real 0.013s	user 0.009s	sys 0.003s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4546,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:28.591580  8020 maintenance_manager.cc:419] P b28235d2539e4c1bbd0cff56bdf600a5: Scheduling MajorDeltaCompactionOp(c1ec7be1bb3b4260b9b6fc4a230f4056): perf score=1.000000
I20260812 06:19:28.759775  7927 maintenance_manager.cc:643] P b28235d2539e4c1bbd0cff56bdf600a5: MajorDeltaCompactionOp(c1ec7be1bb3b4260b9b6fc4a230f4056) complete. Timing: real 0.168s	user 0.135s	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":153,"lbm_read_time_us":11581,"lbm_reads_lt_1ms":572,"lbm_write_time_us":33978,"lbm_writes_lt_1ms":543,"mutex_wait_us":72,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":12928,"update_count":2500}
I20260812 06:19:28.760537  8020 maintenance_manager.cc:419] P b28235d2539e4c1bbd0cff56bdf600a5: Scheduling FlushDeltaMemStoresOp(c1ec7be1bb3b4260b9b6fc4a230f4056): perf score=11.118625
I20260812 06:19:28.807463  7927 maintenance_manager.cc:643] P b28235d2539e4c1bbd0cff56bdf600a5: FlushDeltaMemStoresOp(c1ec7be1bb3b4260b9b6fc4a230f4056) complete. Timing: real 0.047s	user 0.018s	sys 0.028s Metrics: {"bytes_written":12717736,"delete_count":0,"lbm_write_time_us":21515,"lbm_writes_1-10_ms":2,"lbm_writes_lt_1ms":311,"reinsert_count":0,"update_count":1550}
I20260812 06:19:28.808261  8020 maintenance_manager.cc:419] P b28235d2539e4c1bbd0cff56bdf600a5: Scheduling FlushDeltaMemStoresOp(c1ec7be1bb3b4260b9b6fc4a230f4056): perf score=2.188937
I20260812 06:19:28.824934  7927 maintenance_manager.cc:643] P b28235d2539e4c1bbd0cff56bdf600a5: FlushDeltaMemStoresOp(c1ec7be1bb3b4260b9b6fc4a230f4056) complete. Timing: real 0.016s	user 0.011s	sys 0.000s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":5153,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:19:28.825438  8020 maintenance_manager.cc:419] P b28235d2539e4c1bbd0cff56bdf600a5: Scheduling FlushDeltaMemStoresOp(c1ec7be1bb3b4260b9b6fc4a230f4056): perf score=2.188937
I20260812 06:19:28.838649  7927 maintenance_manager.cc:643] P b28235d2539e4c1bbd0cff56bdf600a5: FlushDeltaMemStoresOp(c1ec7be1bb3b4260b9b6fc4a230f4056) complete. Timing: real 0.013s	user 0.003s	sys 0.007s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":5161,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:28.840516  8020 maintenance_manager.cc:419] P b28235d2539e4c1bbd0cff56bdf600a5: Scheduling FlushMRSOp(c1ec7be1bb3b4260b9b6fc4a230f4056): perf score=1.000000
I20260812 06:19:28.874639  7927 maintenance_manager.cc:643] P b28235d2539e4c1bbd0cff56bdf600a5: FlushMRSOp(c1ec7be1bb3b4260b9b6fc4a230f4056) complete. Timing: real 0.034s	user 0.024s	sys 0.008s Metrics: {"bytes_written":1316413,"cfile_init":1,"dirs.queue_time_us":115,"dirs.run_cpu_time_us":207,"dirs.run_wall_time_us":1383,"drs_written":1,"lbm_read_time_us":145,"lbm_reads_lt_1ms":4,"lbm_write_time_us":2133,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":32}
I20260812 06:19:28.875450  8020 maintenance_manager.cc:419] P b28235d2539e4c1bbd0cff56bdf600a5: Scheduling LogGCOp(c1ec7be1bb3b4260b9b6fc4a230f4056): free 132571309 bytes of WAL
I20260812 06:19:28.875658  7927 log_reader.cc:385] T c1ec7be1bb3b4260b9b6fc4a230f4056: removed 13 log segments from log reader
I20260812 06:19:28.875717  7927 log.cc:1079] T c1ec7be1bb3b4260b9b6fc4a230f4056 P b28235d2539e4c1bbd0cff56bdf600a5: Deleting log segment in path: /tmp/dist-test-task4BgTQF/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515560703209-7469-0/minicluster-data/ts-0-root/wals/c1ec7be1bb3b4260b9b6fc4a230f4056/wal-000000003 (ops 12-16)
I20260812 06:19:28.875758  7927 log.cc:1079] T c1ec7be1bb3b4260b9b6fc4a230f4056 P b28235d2539e4c1bbd0cff56bdf600a5: Deleting log segment in path: /tmp/dist-test-task4BgTQF/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515560703209-7469-0/minicluster-data/ts-0-root/wals/c1ec7be1bb3b4260b9b6fc4a230f4056/wal-000000004 (ops 17-21)
I20260812 06:19:28.875787  7927 log.cc:1079] T c1ec7be1bb3b4260b9b6fc4a230f4056 P b28235d2539e4c1bbd0cff56bdf600a5: Deleting log segment in path: /tmp/dist-test-task4BgTQF/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515560703209-7469-0/minicluster-data/ts-0-root/wals/c1ec7be1bb3b4260b9b6fc4a230f4056/wal-000000005 (ops 22-26)
I20260812 06:19:28.875811  7927 log.cc:1079] T c1ec7be1bb3b4260b9b6fc4a230f4056 P b28235d2539e4c1bbd0cff56bdf600a5: Deleting log segment in path: /tmp/dist-test-task4BgTQF/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515560703209-7469-0/minicluster-data/ts-0-root/wals/c1ec7be1bb3b4260b9b6fc4a230f4056/wal-000000006 (ops 27-30)
I20260812 06:19:28.875842  7927 log.cc:1079] T c1ec7be1bb3b4260b9b6fc4a230f4056 P b28235d2539e4c1bbd0cff56bdf600a5: Deleting log segment in path: /tmp/dist-test-task4BgTQF/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515560703209-7469-0/minicluster-data/ts-0-root/wals/c1ec7be1bb3b4260b9b6fc4a230f4056/wal-000000007 (ops 31-35)
I20260812 06:19:28.875873  7927 log.cc:1079] T c1ec7be1bb3b4260b9b6fc4a230f4056 P b28235d2539e4c1bbd0cff56bdf600a5: Deleting log segment in path: /tmp/dist-test-task4BgTQF/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515560703209-7469-0/minicluster-data/ts-0-root/wals/c1ec7be1bb3b4260b9b6fc4a230f4056/wal-000000008 (ops 36-40)
I20260812 06:19:28.875902  7927 log.cc:1079] T c1ec7be1bb3b4260b9b6fc4a230f4056 P b28235d2539e4c1bbd0cff56bdf600a5: Deleting log segment in path: /tmp/dist-test-task4BgTQF/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515560703209-7469-0/minicluster-data/ts-0-root/wals/c1ec7be1bb3b4260b9b6fc4a230f4056/wal-000000009 (ops 41-45)
I20260812 06:19:28.875934  7927 log.cc:1079] T c1ec7be1bb3b4260b9b6fc4a230f4056 P b28235d2539e4c1bbd0cff56bdf600a5: Deleting log segment in path: /tmp/dist-test-task4BgTQF/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515560703209-7469-0/minicluster-data/ts-0-root/wals/c1ec7be1bb3b4260b9b6fc4a230f4056/wal-000000010 (ops 46-50)
I20260812 06:19:28.875969  7927 log.cc:1079] T c1ec7be1bb3b4260b9b6fc4a230f4056 P b28235d2539e4c1bbd0cff56bdf600a5: Deleting log segment in path: /tmp/dist-test-task4BgTQF/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515560703209-7469-0/minicluster-data/ts-0-root/wals/c1ec7be1bb3b4260b9b6fc4a230f4056/wal-000000011 (ops 51-55)
I20260812 06:19:28.875999  7927 log.cc:1079] T c1ec7be1bb3b4260b9b6fc4a230f4056 P b28235d2539e4c1bbd0cff56bdf600a5: Deleting log segment in path: /tmp/dist-test-task4BgTQF/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515560703209-7469-0/minicluster-data/ts-0-root/wals/c1ec7be1bb3b4260b9b6fc4a230f4056/wal-000000012 (ops 56-60)
I20260812 06:19:28.876029  7927 log.cc:1079] T c1ec7be1bb3b4260b9b6fc4a230f4056 P b28235d2539e4c1bbd0cff56bdf600a5: Deleting log segment in path: /tmp/dist-test-task4BgTQF/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515560703209-7469-0/minicluster-data/ts-0-root/wals/c1ec7be1bb3b4260b9b6fc4a230f4056/wal-000000013 (ops 61-64)
I20260812 06:19:28.876056  7927 log.cc:1079] T c1ec7be1bb3b4260b9b6fc4a230f4056 P b28235d2539e4c1bbd0cff56bdf600a5: Deleting log segment in path: /tmp/dist-test-task4BgTQF/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515560703209-7469-0/minicluster-data/ts-0-root/wals/c1ec7be1bb3b4260b9b6fc4a230f4056/wal-000000014 (ops 65-69)
I20260812 06:19:28.876085  7927 log.cc:1079] T c1ec7be1bb3b4260b9b6fc4a230f4056 P b28235d2539e4c1bbd0cff56bdf600a5: Deleting log segment in path: /tmp/dist-test-task4BgTQF/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515560703209-7469-0/minicluster-data/ts-0-root/wals/c1ec7be1bb3b4260b9b6fc4a230f4056/wal-000000015 (ops 70-74)
I20260812 06:19:28.912362  7927 maintenance_manager.cc:643] P b28235d2539e4c1bbd0cff56bdf600a5: LogGCOp(c1ec7be1bb3b4260b9b6fc4a230f4056) complete. Timing: real 0.037s	user 0.000s	sys 0.035s Metrics: {}
I20260812 06:19:28.912859  8020 maintenance_manager.cc:419] P b28235d2539e4c1bbd0cff56bdf600a5: Scheduling UndoDeltaBlockGCOp(c1ec7be1bb3b4260b9b6fc4a230f4056): 492 bytes on disk
I20260812 06:19:28.913519  7927 maintenance_manager.cc:643] P b28235d2539e4c1bbd0cff56bdf600a5: UndoDeltaBlockGCOp(c1ec7be1bb3b4260b9b6fc4a230f4056) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":59,"lbm_reads_lt_1ms":4}
I20260812 06:19:28.914037  8020 maintenance_manager.cc:419] P b28235d2539e4c1bbd0cff56bdf600a5: Scheduling FlushDeltaMemStoresOp(c1ec7be1bb3b4260b9b6fc4a230f4056): perf score=4.173312
I20260812 06:19:28.930328  7927 maintenance_manager.cc:643] P b28235d2539e4c1bbd0cff56bdf600a5: FlushDeltaMemStoresOp(c1ec7be1bb3b4260b9b6fc4a230f4056) complete. Timing: real 0.016s	user 0.010s	sys 0.003s Metrics: {"bytes_written":5538513,"delete_count":0,"lbm_write_time_us":6463,"lbm_writes_lt_1ms":138,"reinsert_count":0,"update_count":675}
I20260812 06:19:28.930894  8020 maintenance_manager.cc:419] P b28235d2539e4c1bbd0cff56bdf600a5: Scheduling FlushDeltaMemStoresOp(c1ec7be1bb3b4260b9b6fc4a230f4056): perf score=1.196750
I20260812 06:19:28.954844  7927 maintenance_manager.cc:643] P b28235d2539e4c1bbd0cff56bdf600a5: FlushDeltaMemStoresOp(c1ec7be1bb3b4260b9b6fc4a230f4056) complete. Timing: real 0.024s	user 0.008s	sys 0.012s Metrics: {"bytes_written":2666779,"delete_count":0,"lbm_write_time_us":4593,"lbm_writes_lt_1ms":68,"reinsert_count":0,"update_count":325}
I20260812 06:19:28.955353  8020 maintenance_manager.cc:419] P b28235d2539e4c1bbd0cff56bdf600a5: Scheduling MajorDeltaCompactionOp(c1ec7be1bb3b4260b9b6fc4a230f4056): perf score=1.000000
I20260812 06:19:29.203413  7927 maintenance_manager.cc:643] P b28235d2539e4c1bbd0cff56bdf600a5: MajorDeltaCompactionOp(c1ec7be1bb3b4260b9b6fc4a230f4056) complete. Timing: real 0.248s	user 0.163s	sys 0.084s Metrics: {"cfile_cache_miss":735,"cfile_cache_miss_bytes":32979829,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":5,"delta_iterators_relevant":5,"dirs.queue_time_us":223,"lbm_read_time_us":19420,"lbm_reads_lt_1ms":767,"lbm_write_time_us":41233,"lbm_writes_lt_1ms":743,"mutex_wait_us":27,"peak_mem_usage":87969044,"reinsert_count":0,"spinlock_wait_cycles":21376,"thread_start_us":89,"threads_started":1,"update_count":3500}
I20260812 06:19:29.204166  8020 maintenance_manager.cc:419] P b28235d2539e4c1bbd0cff56bdf600a5: Scheduling FlushDeltaMemStoresOp(c1ec7be1bb3b4260b9b6fc4a230f4056): perf score=14.095187
I20260812 06:19:29.281168  7927 maintenance_manager.cc:643] P b28235d2539e4c1bbd0cff56bdf600a5: FlushDeltaMemStoresOp(c1ec7be1bb3b4260b9b6fc4a230f4056) complete. Timing: real 0.077s	user 0.025s	sys 0.047s Metrics: {"bytes_written":16409903,"delete_count":0,"lbm_write_time_us":27539,"lbm_writes_1-10_ms":2,"lbm_writes_lt_1ms":401,"reinsert_count":0,"update_count":2000}
I20260812 06:19:29.281672  8020 maintenance_manager.cc:419] P b28235d2539e4c1bbd0cff56bdf600a5: Scheduling FlushDeltaMemStoresOp(c1ec7be1bb3b4260b9b6fc4a230f4056): perf score=3.181125
I20260812 06:19:29.295248  7927 maintenance_manager.cc:643] P b28235d2539e4c1bbd0cff56bdf600a5: FlushDeltaMemStoresOp(c1ec7be1bb3b4260b9b6fc4a230f4056) complete. Timing: real 0.013s	user 0.009s	sys 0.003s Metrics: {"bytes_written":4512899,"delete_count":0,"lbm_write_time_us":4938,"lbm_writes_lt_1ms":113,"reinsert_count":0,"update_count":550}
I20260812 06:19:29.295698  8020 maintenance_manager.cc:419] P b28235d2539e4c1bbd0cff56bdf600a5: Scheduling FlushDeltaMemStoresOp(c1ec7be1bb3b4260b9b6fc4a230f4056): perf score=2.188937
I20260812 06:19:29.305627  7927 maintenance_manager.cc:643] P b28235d2539e4c1bbd0cff56bdf600a5: FlushDeltaMemStoresOp(c1ec7be1bb3b4260b9b6fc4a230f4056) complete. Timing: real 0.010s	user 0.005s	sys 0.004s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":4075,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:19:29.306034  8020 maintenance_manager.cc:419] P b28235d2539e4c1bbd0cff56bdf600a5: Scheduling MajorDeltaCompactionOp(c1ec7be1bb3b4260b9b6fc4a230f4056): perf score=1.000000
I20260812 06:19:29.547906  7927 maintenance_manager.cc:643] P b28235d2539e4c1bbd0cff56bdf600a5: MajorDeltaCompactionOp(c1ec7be1bb3b4260b9b6fc4a230f4056) complete. Timing: real 0.242s	user 0.126s	sys 0.115s Metrics: {"cfile_cache_miss":633,"cfile_cache_miss_bytes":28877207,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":164,"lbm_read_time_us":17539,"lbm_reads_lt_1ms":673,"lbm_write_time_us":40608,"lbm_writes_lt_1ms":643,"mutex_wait_us":38,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":52864,"update_count":3000}
I20260812 06:19:29.548715  8020 maintenance_manager.cc:419] P b28235d2539e4c1bbd0cff56bdf600a5: Scheduling FlushDeltaMemStoresOp(c1ec7be1bb3b4260b9b6fc4a230f4056): perf score=14.095187
I20260812 06:19:29.601682  7927 maintenance_manager.cc:643] P b28235d2539e4c1bbd0cff56bdf600a5: FlushDeltaMemStoresOp(c1ec7be1bb3b4260b9b6fc4a230f4056) complete. Timing: real 0.053s	user 0.033s	sys 0.017s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":24626,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:29.602216  8020 maintenance_manager.cc:419] P b28235d2539e4c1bbd0cff56bdf600a5: Scheduling MajorDeltaCompactionOp(c1ec7be1bb3b4260b9b6fc4a230f4056): perf score=1.000000
I20260812 06:19:29.760308  7927 maintenance_manager.cc:643] P b28235d2539e4c1bbd0cff56bdf600a5: MajorDeltaCompactionOp(c1ec7be1bb3b4260b9b6fc4a230f4056) complete. Timing: real 0.158s	user 0.099s	sys 0.054s Metrics: {"cfile_cache_miss":431,"cfile_cache_miss_bytes":20672157,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":1,"delta_iterators_relevant":1,"dirs.queue_time_us":1122,"lbm_read_time_us":12400,"lbm_reads_lt_1ms":467,"lbm_write_time_us":24272,"lbm_writes_lt_1ms":443,"mutex_wait_us":275,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":5888,"update_count":2000}
I20260812 06:19:29.760885  8020 maintenance_manager.cc:419] P b28235d2539e4c1bbd0cff56bdf600a5: Scheduling FlushDeltaMemStoresOp(c1ec7be1bb3b4260b9b6fc4a230f4056): perf score=11.118625
I20260812 06:19:29.803020  7927 maintenance_manager.cc:643] P b28235d2539e4c1bbd0cff56bdf600a5: FlushDeltaMemStoresOp(c1ec7be1bb3b4260b9b6fc4a230f4056) complete. Timing: real 0.042s	user 0.026s	sys 0.016s Metrics: {"bytes_written":12717736,"delete_count":0,"lbm_write_time_us":18408,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:19:29.803637  8020 maintenance_manager.cc:419] P b28235d2539e4c1bbd0cff56bdf600a5: Scheduling FlushDeltaMemStoresOp(c1ec7be1bb3b4260b9b6fc4a230f4056): perf score=2.188937
I20260812 06:19:29.830406  7927 maintenance_manager.cc:643] P b28235d2539e4c1bbd0cff56bdf600a5: FlushDeltaMemStoresOp(c1ec7be1bb3b4260b9b6fc4a230f4056) complete. Timing: real 0.027s	user 0.006s	sys 0.005s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":5223,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:19:29.831060  8020 maintenance_manager.cc:419] P b28235d2539e4c1bbd0cff56bdf600a5: Scheduling FlushDeltaMemStoresOp(c1ec7be1bb3b4260b9b6fc4a230f4056): perf score=2.188937
I20260812 06:19:29.846530  7927 maintenance_manager.cc:643] P b28235d2539e4c1bbd0cff56bdf600a5: FlushDeltaMemStoresOp(c1ec7be1bb3b4260b9b6fc4a230f4056) complete. Timing: real 0.015s	user 0.012s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6063,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:29.847128  8020 maintenance_manager.cc:419] P b28235d2539e4c1bbd0cff56bdf600a5: Scheduling MajorDeltaCompactionOp(c1ec7be1bb3b4260b9b6fc4a230f4056): perf score=1.000000
I20260812 06:19:30.026533  7927 maintenance_manager.cc:643] P b28235d2539e4c1bbd0cff56bdf600a5: MajorDeltaCompactionOp(c1ec7be1bb3b4260b9b6fc4a230f4056) complete. Timing: real 0.179s	user 0.106s	sys 0.068s 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":477,"lbm_read_time_us":10749,"lbm_reads_lt_1ms":573,"lbm_write_time_us":27903,"lbm_writes_lt_1ms":543,"peak_mem_usage":63115900,"reinsert_count":0,"update_count":2500}
I20260812 06:19:30.027174  8020 maintenance_manager.cc:419] P b28235d2539e4c1bbd0cff56bdf600a5: Scheduling FlushDeltaMemStoresOp(c1ec7be1bb3b4260b9b6fc4a230f4056): perf score=10.126437
I20260812 06:19:30.064993  7927 maintenance_manager.cc:643] P b28235d2539e4c1bbd0cff56bdf600a5: FlushDeltaMemStoresOp(c1ec7be1bb3b4260b9b6fc4a230f4056) complete. Timing: real 0.038s	user 0.015s	sys 0.021s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":17065,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:19:30.065580  8020 maintenance_manager.cc:419] P b28235d2539e4c1bbd0cff56bdf600a5: Scheduling FlushDeltaMemStoresOp(c1ec7be1bb3b4260b9b6fc4a230f4056): perf score=2.188937
I20260812 06:19:30.080011  7927 maintenance_manager.cc:643] P b28235d2539e4c1bbd0cff56bdf600a5: FlushDeltaMemStoresOp(c1ec7be1bb3b4260b9b6fc4a230f4056) complete. Timing: real 0.014s	user 0.008s	sys 0.005s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5659,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:30.081658  8020 maintenance_manager.cc:419] P b28235d2539e4c1bbd0cff56bdf600a5: Scheduling MajorDeltaCompactionOp(c1ec7be1bb3b4260b9b6fc4a230f4056): perf score=1.000000
I20260812 06:19:30.218118  7927 maintenance_manager.cc:643] P b28235d2539e4c1bbd0cff56bdf600a5: MajorDeltaCompactionOp(c1ec7be1bb3b4260b9b6fc4a230f4056) complete. Timing: real 0.136s	user 0.116s	sys 0.020s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672277,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":1273,"lbm_read_time_us":8317,"lbm_reads_lt_1ms":464,"lbm_write_time_us":28499,"lbm_writes_lt_1ms":443,"mutex_wait_us":263,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":20352,"update_count":2000}
I20260812 06:19:30.219094  8020 maintenance_manager.cc:419] P b28235d2539e4c1bbd0cff56bdf600a5: Scheduling FlushDeltaMemStoresOp(c1ec7be1bb3b4260b9b6fc4a230f4056): perf score=10.126437
I20260812 06:19:30.268977  7927 maintenance_manager.cc:643] P b28235d2539e4c1bbd0cff56bdf600a5: FlushDeltaMemStoresOp(c1ec7be1bb3b4260b9b6fc4a230f4056) complete. Timing: real 0.050s	user 0.029s	sys 0.012s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":17263,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:19:30.269639  8020 maintenance_manager.cc:419] P b28235d2539e4c1bbd0cff56bdf600a5: Scheduling FlushDeltaMemStoresOp(c1ec7be1bb3b4260b9b6fc4a230f4056): perf score=2.188937
I20260812 06:19:30.286128  7927 maintenance_manager.cc:643] P b28235d2539e4c1bbd0cff56bdf600a5: FlushDeltaMemStoresOp(c1ec7be1bb3b4260b9b6fc4a230f4056) complete. Timing: real 0.016s	user 0.006s	sys 0.007s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6160,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:30.286971  8020 maintenance_manager.cc:419] P b28235d2539e4c1bbd0cff56bdf600a5: Scheduling MajorDeltaCompactionOp(c1ec7be1bb3b4260b9b6fc4a230f4056): perf score=1.000000
I20260812 06:19:30.428215  7927 maintenance_manager.cc:643] P b28235d2539e4c1bbd0cff56bdf600a5: MajorDeltaCompactionOp(c1ec7be1bb3b4260b9b6fc4a230f4056) complete. Timing: real 0.141s	user 0.116s	sys 0.025s 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":148,"lbm_read_time_us":11219,"lbm_reads_lt_1ms":472,"lbm_write_time_us":26660,"lbm_writes_lt_1ms":443,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":3456,"update_count":2000}
I20260812 06:19:30.429008  8020 maintenance_manager.cc:419] P b28235d2539e4c1bbd0cff56bdf600a5: Scheduling FlushDeltaMemStoresOp(c1ec7be1bb3b4260b9b6fc4a230f4056): perf score=10.126437
I20260812 06:19:30.480680  7927 maintenance_manager.cc:643] P b28235d2539e4c1bbd0cff56bdf600a5: FlushDeltaMemStoresOp(c1ec7be1bb3b4260b9b6fc4a230f4056) complete. Timing: real 0.051s	user 0.012s	sys 0.037s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":17758,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":302,"reinsert_count":0,"update_count":1500}
I20260812 06:19:30.481325  8020 maintenance_manager.cc:419] P b28235d2539e4c1bbd0cff56bdf600a5: Scheduling FlushDeltaMemStoresOp(c1ec7be1bb3b4260b9b6fc4a230f4056): perf score=2.188937
I20260812 06:19:30.493803  7927 maintenance_manager.cc:643] P b28235d2539e4c1bbd0cff56bdf600a5: FlushDeltaMemStoresOp(c1ec7be1bb3b4260b9b6fc4a230f4056) complete. Timing: real 0.012s	user 0.007s	sys 0.003s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4679,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:30.494318  8020 maintenance_manager.cc:419] P b28235d2539e4c1bbd0cff56bdf600a5: Scheduling FlushMRSOp(c1ec7be1bb3b4260b9b6fc4a230f4056): perf score=1.000000
I20260812 06:19:30.533737  7927 maintenance_manager.cc:643] P b28235d2539e4c1bbd0cff56bdf600a5: FlushMRSOp(c1ec7be1bb3b4260b9b6fc4a230f4056) complete. Timing: real 0.039s	user 0.030s	sys 0.004s Metrics: {"bytes_written":1193507,"cfile_init":1,"dirs.queue_time_us":55,"dirs.run_cpu_time_us":186,"dirs.run_wall_time_us":1323,"drs_written":1,"lbm_read_time_us":43,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1703,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":29,"spinlock_wait_cycles":896}
I20260812 06:19:30.534507  8020 maintenance_manager.cc:419] P b28235d2539e4c1bbd0cff56bdf600a5: Scheduling LogGCOp(c1ec7be1bb3b4260b9b6fc4a230f4056): free 121006409 bytes of WAL
I20260812 06:19:30.534773  7927 log_reader.cc:385] T c1ec7be1bb3b4260b9b6fc4a230f4056: removed 12 log segments from log reader
I20260812 06:19:30.534834  7927 log.cc:1079] T c1ec7be1bb3b4260b9b6fc4a230f4056 P b28235d2539e4c1bbd0cff56bdf600a5: Deleting log segment in path: /tmp/dist-test-task4BgTQF/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515560703209-7469-0/minicluster-data/ts-0-root/wals/c1ec7be1bb3b4260b9b6fc4a230f4056/wal-000000016 (ops 75-79)
I20260812 06:19:30.534875  7927 log.cc:1079] T c1ec7be1bb3b4260b9b6fc4a230f4056 P b28235d2539e4c1bbd0cff56bdf600a5: Deleting log segment in path: /tmp/dist-test-task4BgTQF/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515560703209-7469-0/minicluster-data/ts-0-root/wals/c1ec7be1bb3b4260b9b6fc4a230f4056/wal-000000017 (ops 80-84)
I20260812 06:19:30.534901  7927 log.cc:1079] T c1ec7be1bb3b4260b9b6fc4a230f4056 P b28235d2539e4c1bbd0cff56bdf600a5: Deleting log segment in path: /tmp/dist-test-task4BgTQF/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515560703209-7469-0/minicluster-data/ts-0-root/wals/c1ec7be1bb3b4260b9b6fc4a230f4056/wal-000000018 (ops 85-88)
I20260812 06:19:30.534960  7927 log.cc:1079] T c1ec7be1bb3b4260b9b6fc4a230f4056 P b28235d2539e4c1bbd0cff56bdf600a5: Deleting log segment in path: /tmp/dist-test-task4BgTQF/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515560703209-7469-0/minicluster-data/ts-0-root/wals/c1ec7be1bb3b4260b9b6fc4a230f4056/wal-000000019 (ops 89-93)
I20260812 06:19:30.534989  7927 log.cc:1079] T c1ec7be1bb3b4260b9b6fc4a230f4056 P b28235d2539e4c1bbd0cff56bdf600a5: Deleting log segment in path: /tmp/dist-test-task4BgTQF/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515560703209-7469-0/minicluster-data/ts-0-root/wals/c1ec7be1bb3b4260b9b6fc4a230f4056/wal-000000020 (ops 94-98)
I20260812 06:19:30.535022  7927 log.cc:1079] T c1ec7be1bb3b4260b9b6fc4a230f4056 P b28235d2539e4c1bbd0cff56bdf600a5: Deleting log segment in path: /tmp/dist-test-task4BgTQF/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515560703209-7469-0/minicluster-data/ts-0-root/wals/c1ec7be1bb3b4260b9b6fc4a230f4056/wal-000000021 (ops 99-103)
I20260812 06:19:30.535043  7927 log.cc:1079] T c1ec7be1bb3b4260b9b6fc4a230f4056 P b28235d2539e4c1bbd0cff56bdf600a5: Deleting log segment in path: /tmp/dist-test-task4BgTQF/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515560703209-7469-0/minicluster-data/ts-0-root/wals/c1ec7be1bb3b4260b9b6fc4a230f4056/wal-000000022 (ops 104-108)
I20260812 06:19:30.535072  7927 log.cc:1079] T c1ec7be1bb3b4260b9b6fc4a230f4056 P b28235d2539e4c1bbd0cff56bdf600a5: Deleting log segment in path: /tmp/dist-test-task4BgTQF/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515560703209-7469-0/minicluster-data/ts-0-root/wals/c1ec7be1bb3b4260b9b6fc4a230f4056/wal-000000023 (ops 109-113)
I20260812 06:19:30.535102  7927 log.cc:1079] T c1ec7be1bb3b4260b9b6fc4a230f4056 P b28235d2539e4c1bbd0cff56bdf600a5: Deleting log segment in path: /tmp/dist-test-task4BgTQF/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515560703209-7469-0/minicluster-data/ts-0-root/wals/c1ec7be1bb3b4260b9b6fc4a230f4056/wal-000000024 (ops 114-119)
I20260812 06:19:30.535137  7927 log.cc:1079] T c1ec7be1bb3b4260b9b6fc4a230f4056 P b28235d2539e4c1bbd0cff56bdf600a5: Deleting log segment in path: /tmp/dist-test-task4BgTQF/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515560703209-7469-0/minicluster-data/ts-0-root/wals/c1ec7be1bb3b4260b9b6fc4a230f4056/wal-000000025 (ops 120-124)
I20260812 06:19:30.535171  7927 log.cc:1079] T c1ec7be1bb3b4260b9b6fc4a230f4056 P b28235d2539e4c1bbd0cff56bdf600a5: Deleting log segment in path: /tmp/dist-test-task4BgTQF/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515560703209-7469-0/minicluster-data/ts-0-root/wals/c1ec7be1bb3b4260b9b6fc4a230f4056/wal-000000026 (ops 125-128)
I20260812 06:19:30.535199  7927 log.cc:1079] T c1ec7be1bb3b4260b9b6fc4a230f4056 P b28235d2539e4c1bbd0cff56bdf600a5: Deleting log segment in path: /tmp/dist-test-task4BgTQF/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515560703209-7469-0/minicluster-data/ts-0-root/wals/c1ec7be1bb3b4260b9b6fc4a230f4056/wal-000000027 (ops 129-133)
I20260812 06:19:30.569561  7927 maintenance_manager.cc:643] P b28235d2539e4c1bbd0cff56bdf600a5: LogGCOp(c1ec7be1bb3b4260b9b6fc4a230f4056) complete. Timing: real 0.035s	user 0.002s	sys 0.030s Metrics: {}
I20260812 06:19:30.570258  8020 maintenance_manager.cc:419] P b28235d2539e4c1bbd0cff56bdf600a5: Scheduling FlushDeltaMemStoresOp(c1ec7be1bb3b4260b9b6fc4a230f4056): perf score=2.188937
I20260812 06:19:30.596652  7927 maintenance_manager.cc:643] P b28235d2539e4c1bbd0cff56bdf600a5: FlushDeltaMemStoresOp(c1ec7be1bb3b4260b9b6fc4a230f4056) complete. Timing: real 0.026s	user 0.003s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5130,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:30.597128  8020 maintenance_manager.cc:419] P b28235d2539e4c1bbd0cff56bdf600a5: Scheduling UndoDeltaBlockGCOp(c1ec7be1bb3b4260b9b6fc4a230f4056): 463 bytes on disk
I20260812 06:19:30.597502  7927 maintenance_manager.cc:643] P b28235d2539e4c1bbd0cff56bdf600a5: UndoDeltaBlockGCOp(c1ec7be1bb3b4260b9b6fc4a230f4056) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":49,"lbm_reads_lt_1ms":4}
I20260812 06:19:30.597929  8020 maintenance_manager.cc:419] P b28235d2539e4c1bbd0cff56bdf600a5: Scheduling FlushDeltaMemStoresOp(c1ec7be1bb3b4260b9b6fc4a230f4056): perf score=2.188937
I20260812 06:19:30.613511  7927 maintenance_manager.cc:643] P b28235d2539e4c1bbd0cff56bdf600a5: FlushDeltaMemStoresOp(c1ec7be1bb3b4260b9b6fc4a230f4056) complete. Timing: real 0.015s	user 0.009s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5927,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:30.614078  8020 maintenance_manager.cc:419] P b28235d2539e4c1bbd0cff56bdf600a5: Scheduling MajorDeltaCompactionOp(c1ec7be1bb3b4260b9b6fc4a230f4056): perf score=1.000000
I20260812 06:19:30.839107  7927 maintenance_manager.cc:643] P b28235d2539e4c1bbd0cff56bdf600a5: MajorDeltaCompactionOp(c1ec7be1bb3b4260b9b6fc4a230f4056) complete. Timing: real 0.225s	user 0.169s	sys 0.055s Metrics: {"cfile_cache_miss":634,"cfile_cache_miss_bytes":28877338,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":192,"lbm_read_time_us":16638,"lbm_reads_lt_1ms":674,"lbm_write_time_us":36406,"lbm_writes_lt_1ms":643,"mutex_wait_us":4,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":5248,"thread_start_us":115,"threads_started":1,"update_count":3000}
I20260812 06:19:30.839892  8020 maintenance_manager.cc:419] P b28235d2539e4c1bbd0cff56bdf600a5: Scheduling FlushDeltaMemStoresOp(c1ec7be1bb3b4260b9b6fc4a230f4056): perf score=14.095187
I20260812 06:19:30.889272  7927 maintenance_manager.cc:643] P b28235d2539e4c1bbd0cff56bdf600a5: FlushDeltaMemStoresOp(c1ec7be1bb3b4260b9b6fc4a230f4056) complete. Timing: real 0.049s	user 0.034s	sys 0.008s Metrics: {"bytes_written":16409900,"delete_count":0,"lbm_write_time_us":20810,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":402,"reinsert_count":0,"update_count":2000}
I20260812 06:19:30.889855  8020 maintenance_manager.cc:419] P b28235d2539e4c1bbd0cff56bdf600a5: Scheduling FlushDeltaMemStoresOp(c1ec7be1bb3b4260b9b6fc4a230f4056): perf score=2.188937
I20260812 06:19:30.906056  7927 maintenance_manager.cc:643] P b28235d2539e4c1bbd0cff56bdf600a5: FlushDeltaMemStoresOp(c1ec7be1bb3b4260b9b6fc4a230f4056) complete. Timing: real 0.016s	user 0.010s	sys 0.003s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6165,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:30.906674  8020 maintenance_manager.cc:419] P b28235d2539e4c1bbd0cff56bdf600a5: Scheduling MajorDeltaCompactionOp(c1ec7be1bb3b4260b9b6fc4a230f4056): perf score=1.000000
I20260812 06:19:31.127285  7927 maintenance_manager.cc:643] P b28235d2539e4c1bbd0cff56bdf600a5: MajorDeltaCompactionOp(c1ec7be1bb3b4260b9b6fc4a230f4056) complete. Timing: real 0.220s	user 0.130s	sys 0.077s 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":1065,"lbm_read_time_us":16342,"lbm_reads_lt_1ms":572,"lbm_write_time_us":35853,"lbm_writes_lt_1ms":543,"mutex_wait_us":338,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":22784,"update_count":2500}
I20260812 06:19:31.128469  8020 maintenance_manager.cc:419] P b28235d2539e4c1bbd0cff56bdf600a5: Scheduling FlushDeltaMemStoresOp(c1ec7be1bb3b4260b9b6fc4a230f4056): perf score=14.095187
I20260812 06:19:31.192487  7927 maintenance_manager.cc:643] P b28235d2539e4c1bbd0cff56bdf600a5: FlushDeltaMemStoresOp(c1ec7be1bb3b4260b9b6fc4a230f4056) complete. Timing: real 0.064s	user 0.047s	sys 0.008s Metrics: {"bytes_written":16409903,"delete_count":0,"lbm_write_time_us":23668,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:31.193640  8020 maintenance_manager.cc:419] P b28235d2539e4c1bbd0cff56bdf600a5: Scheduling FlushDeltaMemStoresOp(c1ec7be1bb3b4260b9b6fc4a230f4056): perf score=2.188937
I20260812 06:19:31.212767  7927 maintenance_manager.cc:643] P b28235d2539e4c1bbd0cff56bdf600a5: FlushDeltaMemStoresOp(c1ec7be1bb3b4260b9b6fc4a230f4056) complete. Timing: real 0.019s	user 0.001s	sys 0.016s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":7191,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:31.216356  8020 maintenance_manager.cc:419] P b28235d2539e4c1bbd0cff56bdf600a5: Scheduling MajorDeltaCompactionOp(c1ec7be1bb3b4260b9b6fc4a230f4056): perf score=1.000000
I20260812 06:19:31.425038  7927 maintenance_manager.cc:643] P b28235d2539e4c1bbd0cff56bdf600a5: MajorDeltaCompactionOp(c1ec7be1bb3b4260b9b6fc4a230f4056) complete. Timing: real 0.208s	user 0.144s	sys 0.057s 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":248,"lbm_read_time_us":15197,"lbm_reads_lt_1ms":572,"lbm_write_time_us":34745,"lbm_writes_lt_1ms":543,"mutex_wait_us":22,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":5632,"update_count":2500}
I20260812 06:19:31.425670  8020 maintenance_manager.cc:419] P b28235d2539e4c1bbd0cff56bdf600a5: Scheduling FlushDeltaMemStoresOp(c1ec7be1bb3b4260b9b6fc4a230f4056): perf score=14.095187
I20260812 06:19:31.497155  7927 maintenance_manager.cc:643] P b28235d2539e4c1bbd0cff56bdf600a5: FlushDeltaMemStoresOp(c1ec7be1bb3b4260b9b6fc4a230f4056) complete. Timing: real 0.071s	user 0.027s	sys 0.039s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":23595,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:31.497763  8020 maintenance_manager.cc:419] P b28235d2539e4c1bbd0cff56bdf600a5: Scheduling FlushDeltaMemStoresOp(c1ec7be1bb3b4260b9b6fc4a230f4056): perf score=2.188937
I20260812 06:19:31.514439  7927 maintenance_manager.cc:643] P b28235d2539e4c1bbd0cff56bdf600a5: FlushDeltaMemStoresOp(c1ec7be1bb3b4260b9b6fc4a230f4056) complete. Timing: real 0.016s	user 0.015s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6870,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:31.515034  8020 maintenance_manager.cc:419] P b28235d2539e4c1bbd0cff56bdf600a5: Scheduling MajorDeltaCompactionOp(c1ec7be1bb3b4260b9b6fc4a230f4056): perf score=1.000000
I20260812 06:19:31.716982  7927 maintenance_manager.cc:643] P b28235d2539e4c1bbd0cff56bdf600a5: MajorDeltaCompactionOp(c1ec7be1bb3b4260b9b6fc4a230f4056) complete. Timing: real 0.202s	user 0.152s	sys 0.045s 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":299,"lbm_read_time_us":14595,"lbm_reads_lt_1ms":572,"lbm_write_time_us":33342,"lbm_writes_lt_1ms":543,"mutex_wait_us":71,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":6784,"update_count":2500}
I20260812 06:19:31.717597  8020 maintenance_manager.cc:419] P b28235d2539e4c1bbd0cff56bdf600a5: Scheduling FlushDeltaMemStoresOp(c1ec7be1bb3b4260b9b6fc4a230f4056): perf score=14.095187
I20260812 06:19:31.771077  7927 maintenance_manager.cc:643] P b28235d2539e4c1bbd0cff56bdf600a5: FlushDeltaMemStoresOp(c1ec7be1bb3b4260b9b6fc4a230f4056) complete. Timing: real 0.053s	user 0.035s	sys 0.007s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":19844,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:31.771648  8020 maintenance_manager.cc:419] P b28235d2539e4c1bbd0cff56bdf600a5: Scheduling FlushDeltaMemStoresOp(c1ec7be1bb3b4260b9b6fc4a230f4056): perf score=2.188937
I20260812 06:19:31.797263  7927 maintenance_manager.cc:643] P b28235d2539e4c1bbd0cff56bdf600a5: FlushDeltaMemStoresOp(c1ec7be1bb3b4260b9b6fc4a230f4056) complete. Timing: real 0.025s	user 0.008s	sys 0.015s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4652,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:31.798002  8020 maintenance_manager.cc:419] P b28235d2539e4c1bbd0cff56bdf600a5: Scheduling MajorDeltaCompactionOp(c1ec7be1bb3b4260b9b6fc4a230f4056): perf score=1.000000
I20260812 06:19:31.989274  7927 maintenance_manager.cc:643] P b28235d2539e4c1bbd0cff56bdf600a5: MajorDeltaCompactionOp(c1ec7be1bb3b4260b9b6fc4a230f4056) complete. Timing: real 0.191s	user 0.123s	sys 0.068s 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":335,"lbm_read_time_us":11253,"lbm_reads_lt_1ms":572,"lbm_write_time_us":32138,"lbm_writes_lt_1ms":543,"peak_mem_usage":63115900,"reinsert_count":0,"update_count":2500}
I20260812 06:19:31.989908  8020 maintenance_manager.cc:419] P b28235d2539e4c1bbd0cff56bdf600a5: Scheduling FlushDeltaMemStoresOp(c1ec7be1bb3b4260b9b6fc4a230f4056): perf score=14.095187
I20260812 06:19:32.049553  7927 maintenance_manager.cc:643] P b28235d2539e4c1bbd0cff56bdf600a5: FlushDeltaMemStoresOp(c1ec7be1bb3b4260b9b6fc4a230f4056) complete. Timing: real 0.059s	user 0.039s	sys 0.012s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":23819,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:32.050164  8020 maintenance_manager.cc:419] P b28235d2539e4c1bbd0cff56bdf600a5: Scheduling FlushDeltaMemStoresOp(c1ec7be1bb3b4260b9b6fc4a230f4056): perf score=2.188937
I20260812 06:19:32.062209  7927 maintenance_manager.cc:643] P b28235d2539e4c1bbd0cff56bdf600a5: FlushDeltaMemStoresOp(c1ec7be1bb3b4260b9b6fc4a230f4056) complete. Timing: real 0.012s	user 0.009s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4233,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:32.062736  8020 maintenance_manager.cc:419] P b28235d2539e4c1bbd0cff56bdf600a5: Scheduling MajorDeltaCompactionOp(c1ec7be1bb3b4260b9b6fc4a230f4056): perf score=1.000000
I20260812 06:19:32.259068  7927 maintenance_manager.cc:643] P b28235d2539e4c1bbd0cff56bdf600a5: MajorDeltaCompactionOp(c1ec7be1bb3b4260b9b6fc4a230f4056) complete. Timing: real 0.196s	user 0.082s	sys 0.100s 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":491,"lbm_read_time_us":9444,"lbm_reads_lt_1ms":572,"lbm_write_time_us":33662,"lbm_writes_lt_1ms":543,"mutex_wait_us":35,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":8576,"update_count":2500}
I20260812 06:19:32.259908  8020 maintenance_manager.cc:419] P b28235d2539e4c1bbd0cff56bdf600a5: Scheduling FlushDeltaMemStoresOp(c1ec7be1bb3b4260b9b6fc4a230f4056): perf score=14.095187
I20260812 06:19:32.308514  7927 maintenance_manager.cc:643] P b28235d2539e4c1bbd0cff56bdf600a5: FlushDeltaMemStoresOp(c1ec7be1bb3b4260b9b6fc4a230f4056) complete. Timing: real 0.048s	user 0.025s	sys 0.020s Metrics: {"bytes_written":16409904,"delete_count":0,"lbm_write_time_us":20138,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:32.309041  8020 maintenance_manager.cc:419] P b28235d2539e4c1bbd0cff56bdf600a5: Scheduling FlushDeltaMemStoresOp(c1ec7be1bb3b4260b9b6fc4a230f4056): perf score=2.188937
I20260812 06:19:32.322676  7927 maintenance_manager.cc:643] P b28235d2539e4c1bbd0cff56bdf600a5: FlushDeltaMemStoresOp(c1ec7be1bb3b4260b9b6fc4a230f4056) complete. Timing: real 0.013s	user 0.008s	sys 0.004s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":5525,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:32.323343  8020 maintenance_manager.cc:419] P b28235d2539e4c1bbd0cff56bdf600a5: Scheduling FlushMRSOp(c1ec7be1bb3b4260b9b6fc4a230f4056): perf score=1.000000
I20260812 06:19:32.361287  7927 maintenance_manager.cc:643] P b28235d2539e4c1bbd0cff56bdf600a5: FlushMRSOp(c1ec7be1bb3b4260b9b6fc4a230f4056) complete. Timing: real 0.038s	user 0.030s	sys 0.005s Metrics: {"bytes_written":1316417,"cfile_init":1,"dirs.queue_time_us":94,"dirs.run_cpu_time_us":284,"dirs.run_wall_time_us":1424,"drs_written":1,"lbm_read_time_us":56,"lbm_reads_lt_1ms":4,"lbm_write_time_us":2395,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":32}
I20260812 06:19:32.362030  8020 maintenance_manager.cc:419] P b28235d2539e4c1bbd0cff56bdf600a5: Scheduling LogGCOp(c1ec7be1bb3b4260b9b6fc4a230f4056): free 132571642 bytes of WAL
I20260812 06:19:32.362290  7927 log_reader.cc:385] T c1ec7be1bb3b4260b9b6fc4a230f4056: removed 13 log segments from log reader
I20260812 06:19:32.362360  7927 log.cc:1079] T c1ec7be1bb3b4260b9b6fc4a230f4056 P b28235d2539e4c1bbd0cff56bdf600a5: Deleting log segment in path: /tmp/dist-test-task4BgTQF/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515560703209-7469-0/minicluster-data/ts-0-root/wals/c1ec7be1bb3b4260b9b6fc4a230f4056/wal-000000028 (ops 134-138)
I20260812 06:19:32.362401  7927 log.cc:1079] T c1ec7be1bb3b4260b9b6fc4a230f4056 P b28235d2539e4c1bbd0cff56bdf600a5: Deleting log segment in path: /tmp/dist-test-task4BgTQF/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515560703209-7469-0/minicluster-data/ts-0-root/wals/c1ec7be1bb3b4260b9b6fc4a230f4056/wal-000000029 (ops 139-143)
I20260812 06:19:32.362432  7927 log.cc:1079] T c1ec7be1bb3b4260b9b6fc4a230f4056 P b28235d2539e4c1bbd0cff56bdf600a5: Deleting log segment in path: /tmp/dist-test-task4BgTQF/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515560703209-7469-0/minicluster-data/ts-0-root/wals/c1ec7be1bb3b4260b9b6fc4a230f4056/wal-000000030 (ops 144-148)
I20260812 06:19:32.362457  7927 log.cc:1079] T c1ec7be1bb3b4260b9b6fc4a230f4056 P b28235d2539e4c1bbd0cff56bdf600a5: Deleting log segment in path: /tmp/dist-test-task4BgTQF/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515560703209-7469-0/minicluster-data/ts-0-root/wals/c1ec7be1bb3b4260b9b6fc4a230f4056/wal-000000031 (ops 149-152)
I20260812 06:19:32.362480  7927 log.cc:1079] T c1ec7be1bb3b4260b9b6fc4a230f4056 P b28235d2539e4c1bbd0cff56bdf600a5: Deleting log segment in path: /tmp/dist-test-task4BgTQF/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515560703209-7469-0/minicluster-data/ts-0-root/wals/c1ec7be1bb3b4260b9b6fc4a230f4056/wal-000000032 (ops 153-157)
I20260812 06:19:32.362502  7927 log.cc:1079] T c1ec7be1bb3b4260b9b6fc4a230f4056 P b28235d2539e4c1bbd0cff56bdf600a5: Deleting log segment in path: /tmp/dist-test-task4BgTQF/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515560703209-7469-0/minicluster-data/ts-0-root/wals/c1ec7be1bb3b4260b9b6fc4a230f4056/wal-000000033 (ops 158-162)
I20260812 06:19:32.362524  7927 log.cc:1079] T c1ec7be1bb3b4260b9b6fc4a230f4056 P b28235d2539e4c1bbd0cff56bdf600a5: Deleting log segment in path: /tmp/dist-test-task4BgTQF/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515560703209-7469-0/minicluster-data/ts-0-root/wals/c1ec7be1bb3b4260b9b6fc4a230f4056/wal-000000034 (ops 163-167)
I20260812 06:19:32.362546  7927 log.cc:1079] T c1ec7be1bb3b4260b9b6fc4a230f4056 P b28235d2539e4c1bbd0cff56bdf600a5: Deleting log segment in path: /tmp/dist-test-task4BgTQF/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515560703209-7469-0/minicluster-data/ts-0-root/wals/c1ec7be1bb3b4260b9b6fc4a230f4056/wal-000000035 (ops 168-172)
I20260812 06:19:32.362582  7927 log.cc:1079] T c1ec7be1bb3b4260b9b6fc4a230f4056 P b28235d2539e4c1bbd0cff56bdf600a5: Deleting log segment in path: /tmp/dist-test-task4BgTQF/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515560703209-7469-0/minicluster-data/ts-0-root/wals/c1ec7be1bb3b4260b9b6fc4a230f4056/wal-000000036 (ops 173-176)
I20260812 06:19:32.362610  7927 log.cc:1079] T c1ec7be1bb3b4260b9b6fc4a230f4056 P b28235d2539e4c1bbd0cff56bdf600a5: Deleting log segment in path: /tmp/dist-test-task4BgTQF/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515560703209-7469-0/minicluster-data/ts-0-root/wals/c1ec7be1bb3b4260b9b6fc4a230f4056/wal-000000037 (ops 177-181)
I20260812 06:19:32.362633  7927 log.cc:1079] T c1ec7be1bb3b4260b9b6fc4a230f4056 P b28235d2539e4c1bbd0cff56bdf600a5: Deleting log segment in path: /tmp/dist-test-task4BgTQF/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515560703209-7469-0/minicluster-data/ts-0-root/wals/c1ec7be1bb3b4260b9b6fc4a230f4056/wal-000000038 (ops 182-186)
I20260812 06:19:32.362655  7927 log.cc:1079] T c1ec7be1bb3b4260b9b6fc4a230f4056 P b28235d2539e4c1bbd0cff56bdf600a5: Deleting log segment in path: /tmp/dist-test-task4BgTQF/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515560703209-7469-0/minicluster-data/ts-0-root/wals/c1ec7be1bb3b4260b9b6fc4a230f4056/wal-000000039 (ops 187-191)
I20260812 06:19:32.362677  7927 log.cc:1079] T c1ec7be1bb3b4260b9b6fc4a230f4056 P b28235d2539e4c1bbd0cff56bdf600a5: Deleting log segment in path: /tmp/dist-test-task4BgTQF/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515560703209-7469-0/minicluster-data/ts-0-root/wals/c1ec7be1bb3b4260b9b6fc4a230f4056/wal-000000040 (ops 192-196)
I20260812 06:19:32.395361  7927 maintenance_manager.cc:643] P b28235d2539e4c1bbd0cff56bdf600a5: LogGCOp(c1ec7be1bb3b4260b9b6fc4a230f4056) complete. Timing: real 0.033s	user 0.000s	sys 0.033s Metrics: {}
I20260812 06:19:32.395778  8020 maintenance_manager.cc:419] P b28235d2539e4c1bbd0cff56bdf600a5: Scheduling FlushDeltaMemStoresOp(c1ec7be1bb3b4260b9b6fc4a230f4056): perf score=2.188937
I20260812 06:19:32.427695  7927 maintenance_manager.cc:643] P b28235d2539e4c1bbd0cff56bdf600a5: FlushDeltaMemStoresOp(c1ec7be1bb3b4260b9b6fc4a230f4056) complete. Timing: real 0.032s	user 0.012s	sys 0.002s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":5704,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:32.428221  8020 maintenance_manager.cc:419] P b28235d2539e4c1bbd0cff56bdf600a5: Scheduling FlushDeltaMemStoresOp(c1ec7be1bb3b4260b9b6fc4a230f4056): perf score=2.188937
I20260812 06:19:32.444020  7927 maintenance_manager.cc:643] P b28235d2539e4c1bbd0cff56bdf600a5: FlushDeltaMemStoresOp(c1ec7be1bb3b4260b9b6fc4a230f4056) complete. Timing: real 0.016s	user 0.009s	sys 0.005s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6323,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:32.444833  8020 maintenance_manager.cc:419] P b28235d2539e4c1bbd0cff56bdf600a5: Scheduling UndoDeltaBlockGCOp(c1ec7be1bb3b4260b9b6fc4a230f4056): 493 bytes on disk
I20260812 06:19:32.445452  7927 maintenance_manager.cc:643] P b28235d2539e4c1bbd0cff56bdf600a5: UndoDeltaBlockGCOp(c1ec7be1bb3b4260b9b6fc4a230f4056) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":71,"lbm_reads_lt_1ms":4}
I20260812 06:19:32.446082  8020 maintenance_manager.cc:419] P b28235d2539e4c1bbd0cff56bdf600a5: Scheduling MajorDeltaCompactionOp(c1ec7be1bb3b4260b9b6fc4a230f4056): perf score=1.000000
I20260812 06:19:32.485951  7469 heavy-update-compaction-itest.cc:229] Time spent updating: real 5.470s	user 2.056s	sys 0.181s
I20260812 06:19:32.597209  7469 heavy-update-compaction-itest.cc:265] Time spent scanning: real 0.111s	user 0.001s	sys 0.000s
I20260812 06:19:32.597826  7469 tablet_server.cc:179] TabletServer@127.7.75.65:0 shutting down...
I20260812 06:19:32.666172  7927 maintenance_manager.cc:643] P b28235d2539e4c1bbd0cff56bdf600a5: MajorDeltaCompactionOp(c1ec7be1bb3b4260b9b6fc4a230f4056) complete. Timing: real 0.220s	user 0.163s	sys 0.056s Metrics: {"cfile_cache_miss":734,"cfile_cache_miss_bytes":32979751,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":1130,"lbm_read_time_us":17611,"lbm_reads_lt_1ms":770,"lbm_write_time_us":37743,"lbm_writes_lt_1ms":743,"mutex_wait_us":310,"peak_mem_usage":87969044,"reinsert_count":0,"spinlock_wait_cycles":66560,"thread_start_us":80,"threads_started":1,"update_count":3500}
I20260812 06:19:32.668303  7469 ts_tablet_manager.cc:1507] Shutting down tablet manager...
I20260812 06:19:32.668536  7469 tablet_replica.cc:333] T c1ec7be1bb3b4260b9b6fc4a230f4056 P b28235d2539e4c1bbd0cff56bdf600a5: stopping tablet replica
I20260812 06:19:32.668705  7469 raft_consensus.cc:2243] T c1ec7be1bb3b4260b9b6fc4a230f4056 P b28235d2539e4c1bbd0cff56bdf600a5 [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:19:32.668895  7469 raft_consensus.cc:2272] T c1ec7be1bb3b4260b9b6fc4a230f4056 P b28235d2539e4c1bbd0cff56bdf600a5 [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:19:32.674674  7469 tablet_server.cc:196] TabletServer@127.7.75.65:0 shutdown complete.
I20260812 06:19:32.724242  7469 master.cc:562] Master@127.7.75.126:43645 shutting down...
I20260812 06:19:32.728690  7469 raft_consensus.cc:2243] T 00000000000000000000000000000000 P 4cbca2ac08434391887bb06de3138eaa [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:19:32.728904  7469 raft_consensus.cc:2272] T 00000000000000000000000000000000 P 4cbca2ac08434391887bb06de3138eaa [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:19:32.728983  7469 tablet_replica.cc:333] T 00000000000000000000000000000000 P 4cbca2ac08434391887bb06de3138eaa: stopping tablet replica
I20260812 06:19:32.742055  7469 master.cc:584] Master@127.7.75.126:43645 shutdown complete.
[       OK ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/1 (6069 ms)
[----------] 2 tests from EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy (12121 ms total)

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