[==========] 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:36.454351 23593 internal_mini_cluster.cc:156] Creating distributed mini masters. Addrs: 127.23.10.126:38959
I20260812 06:19:36.455327 23593 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:36.455919 23593 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:19:36.462656 23604 instance_detector.cc:116] could not retrieve OpenStack instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:19:36.462616 23600 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:36.462782 23593 server_base.cc:1061] running on GCE node
W20260812 06:19:36.462918 23601 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:36.463354 23593 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:19:36.463472 23593 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:36.463536 23593 hybrid_clock.cc:648] HybridClock initialized: now 1786515576463533 us; error 0 us; skew 500 ppm
I20260812 06:19:36.465281 23593 webserver.cc:533] Webserver started at http://127.23.10.126:45537/ using document root <none> and password file <none>
I20260812 06:19:36.465799 23593 fs_manager.cc:362] Metadata directory not provided
I20260812 06:19:36.465883 23593 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:19:36.466143 23593 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:19:36.467685 23593 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-task0b99mg/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515576443844-23593-0/minicluster-data/master-0-root/instance:
uuid: "5d87a422b01844bcb72d70b52397fdeb"
format_stamp: "Formatted at 2026-08-12 06:19:36 on dist-test-slave-cbbz"
I20260812 06:19:36.470964 23593 fs_manager.cc:696] Time spent creating directory manager: real 0.003s	user 0.003s	sys 0.002s
I20260812 06:19:36.472955 23609 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:36.473884 23593 fs_manager.cc:730] Time spent opening block manager: real 0.002s	user 0.002s	sys 0.000s
I20260812 06:19:36.474011 23593 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-task0b99mg/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515576443844-23593-0/minicluster-data/master-0-root
uuid: "5d87a422b01844bcb72d70b52397fdeb"
format_stamp: "Formatted at 2026-08-12 06:19:36 on dist-test-slave-cbbz"
I20260812 06:19:36.474121 23593 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-task0b99mg/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515576443844-23593-0/minicluster-data/master-0-root
metadata directory: /tmp/dist-test-task0b99mg/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515576443844-23593-0/minicluster-data/master-0-root
1 data directories: /tmp/dist-test-task0b99mg/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515576443844-23593-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:36.499303 23593 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:19:36.499940 23593 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:36.500169 23593 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:19:36.507705 23593 rpc_server.cc:307] RPC server started. Bound to: 127.23.10.126:38959
I20260812 06:19:36.507720 23669 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.23.10.126:38959 every 8 connection(s)
I20260812 06:19:36.510039 23671 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:36.515501 23671 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P 5d87a422b01844bcb72d70b52397fdeb: Bootstrap starting.
I20260812 06:19:36.517834 23671 tablet_bootstrap.cc:654] T 00000000000000000000000000000000 P 5d87a422b01844bcb72d70b52397fdeb: Neither blocks nor log segments found. Creating new log.
I20260812 06:19:36.518673 23671 log.cc:826] T 00000000000000000000000000000000 P 5d87a422b01844bcb72d70b52397fdeb: Log is configured to *not* fsync() on all Append() calls
I20260812 06:19:36.520467 23671 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P 5d87a422b01844bcb72d70b52397fdeb: No bootstrap required, opened a new log
I20260812 06:19:36.523136 23671 raft_consensus.cc:359] T 00000000000000000000000000000000 P 5d87a422b01844bcb72d70b52397fdeb [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "5d87a422b01844bcb72d70b52397fdeb" member_type: VOTER }
I20260812 06:19:36.523291 23671 raft_consensus.cc:385] T 00000000000000000000000000000000 P 5d87a422b01844bcb72d70b52397fdeb [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:19:36.523334 23671 raft_consensus.cc:740] T 00000000000000000000000000000000 P 5d87a422b01844bcb72d70b52397fdeb [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: 5d87a422b01844bcb72d70b52397fdeb, State: Initialized, Role: FOLLOWER
I20260812 06:19:36.523860 23671 consensus_queue.cc:260] T 00000000000000000000000000000000 P 5d87a422b01844bcb72d70b52397fdeb [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: "5d87a422b01844bcb72d70b52397fdeb" member_type: VOTER }
I20260812 06:19:36.523984 23671 raft_consensus.cc:399] T 00000000000000000000000000000000 P 5d87a422b01844bcb72d70b52397fdeb [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:19:36.524029 23671 raft_consensus.cc:493] T 00000000000000000000000000000000 P 5d87a422b01844bcb72d70b52397fdeb [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:19:36.524115 23671 raft_consensus.cc:3060] T 00000000000000000000000000000000 P 5d87a422b01844bcb72d70b52397fdeb [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:19:36.524936 23671 raft_consensus.cc:515] T 00000000000000000000000000000000 P 5d87a422b01844bcb72d70b52397fdeb [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "5d87a422b01844bcb72d70b52397fdeb" member_type: VOTER }
I20260812 06:19:36.525308 23671 leader_election.cc:304] T 00000000000000000000000000000000 P 5d87a422b01844bcb72d70b52397fdeb [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: 5d87a422b01844bcb72d70b52397fdeb; no voters: 
I20260812 06:19:36.525563 23671 leader_election.cc:290] T 00000000000000000000000000000000 P 5d87a422b01844bcb72d70b52397fdeb [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:19:36.525709 23674 raft_consensus.cc:2804] T 00000000000000000000000000000000 P 5d87a422b01844bcb72d70b52397fdeb [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:19:36.526002 23674 raft_consensus.cc:697] T 00000000000000000000000000000000 P 5d87a422b01844bcb72d70b52397fdeb [term 1 LEADER]: Becoming Leader. State: Replica: 5d87a422b01844bcb72d70b52397fdeb, State: Running, Role: LEADER
I20260812 06:19:36.526407 23674 consensus_queue.cc:237] T 00000000000000000000000000000000 P 5d87a422b01844bcb72d70b52397fdeb [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: "5d87a422b01844bcb72d70b52397fdeb" member_type: VOTER }
I20260812 06:19:36.526571 23671 sys_catalog.cc:565] T 00000000000000000000000000000000 P 5d87a422b01844bcb72d70b52397fdeb [sys.catalog]: configured and running, proceeding with master startup.
I20260812 06:19:36.528378 23676 sys_catalog.cc:455] T 00000000000000000000000000000000 P 5d87a422b01844bcb72d70b52397fdeb [sys.catalog]: SysCatalogTable state changed. Reason: New leader 5d87a422b01844bcb72d70b52397fdeb. Latest consensus state: current_term: 1 leader_uuid: "5d87a422b01844bcb72d70b52397fdeb" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "5d87a422b01844bcb72d70b52397fdeb" member_type: VOTER } }
I20260812 06:19:36.528409 23675 sys_catalog.cc:455] T 00000000000000000000000000000000 P 5d87a422b01844bcb72d70b52397fdeb [sys.catalog]: SysCatalogTable state changed. Reason: RaftConsensus started. Latest consensus state: current_term: 1 leader_uuid: "5d87a422b01844bcb72d70b52397fdeb" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "5d87a422b01844bcb72d70b52397fdeb" member_type: VOTER } }
I20260812 06:19:36.528508 23675 sys_catalog.cc:458] T 00000000000000000000000000000000 P 5d87a422b01844bcb72d70b52397fdeb [sys.catalog]: This master's current role is: LEADER
I20260812 06:19:36.528508 23676 sys_catalog.cc:458] T 00000000000000000000000000000000 P 5d87a422b01844bcb72d70b52397fdeb [sys.catalog]: This master's current role is: LEADER
I20260812 06:19:36.528878 23689 catalog_manager.cc:1511] Loading table and tablet metadata into memory...
I20260812 06:19:36.528976 23593 internal_mini_cluster.cc:184] Waiting to initialize catalog manager on master 0
I20260812 06:19:36.531286 23689 catalog_manager.cc:1520] Initializing Kudu cluster ID...
I20260812 06:19:36.535799 23689 catalog_manager.cc:1383] Generated new cluster ID: e12b3e81ce2740b0866aaa28d06e2a62
I20260812 06:19:36.535868 23689 catalog_manager.cc:1531] Initializing Kudu internal certificate authority...
I20260812 06:19:36.549839 23689 catalog_manager.cc:1406] Generated new certificate authority record
I20260812 06:19:36.550676 23689 catalog_manager.cc:1540] Loading token signing keys...
I20260812 06:19:36.556015 23689 catalog_manager.cc:6092] T 00000000000000000000000000000000 P 5d87a422b01844bcb72d70b52397fdeb: Generated new TSK 0
I20260812 06:19:36.556630 23689 catalog_manager.cc:1550] Initializing in-progress tserver states...
I20260812 06:19:36.561409 23593 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:19:36.564070 23700 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:36.564234 23593 server_base.cc:1061] running on GCE node
W20260812 06:19:36.564035 23696 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:36.564023 23697 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:36.564524 23593 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:19:36.564579 23593 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:36.564601 23593 hybrid_clock.cc:648] HybridClock initialized: now 1786515576564601 us; error 0 us; skew 500 ppm
I20260812 06:19:36.565523 23593 webserver.cc:533] Webserver started at http://127.23.10.65:38579/ using document root <none> and password file <none>
I20260812 06:19:36.565696 23593 fs_manager.cc:362] Metadata directory not provided
I20260812 06:19:36.565752 23593 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:19:36.565827 23593 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:19:36.566241 23593 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-task0b99mg/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515576443844-23593-0/minicluster-data/ts-0-root/instance:
uuid: "28f091be01f840278e06d55a309877b9"
format_stamp: "Formatted at 2026-08-12 06:19:36 on dist-test-slave-cbbz"
I20260812 06:19:36.568034 23593 fs_manager.cc:696] Time spent creating directory manager: real 0.002s	user 0.002s	sys 0.000s
I20260812 06:19:36.569183 23705 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:36.569465 23593 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.001s	sys 0.000s
I20260812 06:19:36.569530 23593 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-task0b99mg/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515576443844-23593-0/minicluster-data/ts-0-root
uuid: "28f091be01f840278e06d55a309877b9"
format_stamp: "Formatted at 2026-08-12 06:19:36 on dist-test-slave-cbbz"
I20260812 06:19:36.569622 23593 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-task0b99mg/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515576443844-23593-0/minicluster-data/ts-0-root
metadata directory: /tmp/dist-test-task0b99mg/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515576443844-23593-0/minicluster-data/ts-0-root
1 data directories: /tmp/dist-test-task0b99mg/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515576443844-23593-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:36.597374 23593 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:19:36.597887 23593 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:19:36.598387 23593 txn_system_client.cc:432] TxnSystemClient initialization is disabled...
I20260812 06:19:36.599334 23593 ts_tablet_manager.cc:585] Loaded tablet metadata (0 total tablets, 0 live tablets)
I20260812 06:19:36.599411 23593 ts_tablet_manager.cc:531] Time spent load tablet metadata: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:19:36.599485 23593 ts_tablet_manager.cc:616] Registered 0 tablets
I20260812 06:19:36.599534 23593 ts_tablet_manager.cc:595] Time spent register tablets: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:19:36.606472 23593 rpc_server.cc:307] RPC server started. Bound to: 127.23.10.65:35845
I20260812 06:19:36.606510 23773 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.23.10.65:35845 every 8 connection(s)
I20260812 06:19:36.621919 23774 heartbeater.cc:344] Connected to a master server at 127.23.10.126:38959
I20260812 06:19:36.622188 23774 heartbeater.cc:461] Registering TS with master...
I20260812 06:19:36.622704 23774 heartbeater.cc:507] Master 127.23.10.126:38959 requested a full tablet report, sending...
I20260812 06:19:36.624310 23628 ts_manager.cc:194] Registered new tserver with Master: 28f091be01f840278e06d55a309877b9 (127.23.10.65:35845)
I20260812 06:19:36.625062 23593 internal_mini_cluster.cc:371] 1 TS(s) registered with all masters after 0.017940086s
I20260812 06:19:36.625859 23628 master_service.cc:502] Signed X509 certificate for tserver {username='slave'} at 127.0.0.1:41412
I20260812 06:19:36.634493 23628 catalog_manager.cc:2283] Servicing CreateTable request from {username='slave'} at 127.0.0.1:41416:
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:36.651854 23735 tablet_service.cc:1511] Processing CreateTablet for tablet 3bb20398982942c09171cef44e6ce18a (DEFAULT_TABLE table=heavy-update-compaction-test [id=08e74bffc4964378a778d12a98fd4543]), partition=
I20260812 06:19:36.652382 23735 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet 3bb20398982942c09171cef44e6ce18a. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:19:36.654490 23788 tablet_bootstrap.cc:492] T 3bb20398982942c09171cef44e6ce18a P 28f091be01f840278e06d55a309877b9: Bootstrap starting.
I20260812 06:19:36.655668 23788 tablet_bootstrap.cc:654] T 3bb20398982942c09171cef44e6ce18a P 28f091be01f840278e06d55a309877b9: Neither blocks nor log segments found. Creating new log.
I20260812 06:19:36.656960 23788 tablet_bootstrap.cc:492] T 3bb20398982942c09171cef44e6ce18a P 28f091be01f840278e06d55a309877b9: No bootstrap required, opened a new log
I20260812 06:19:36.657047 23788 ts_tablet_manager.cc:1403] T 3bb20398982942c09171cef44e6ce18a P 28f091be01f840278e06d55a309877b9: Time spent bootstrapping tablet: real 0.003s	user 0.002s	sys 0.000s
I20260812 06:19:36.657565 23788 raft_consensus.cc:359] T 3bb20398982942c09171cef44e6ce18a P 28f091be01f840278e06d55a309877b9 [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "28f091be01f840278e06d55a309877b9" member_type: VOTER last_known_addr { host: "127.23.10.65" port: 35845 } }
I20260812 06:19:36.657681 23788 raft_consensus.cc:385] T 3bb20398982942c09171cef44e6ce18a P 28f091be01f840278e06d55a309877b9 [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:19:36.657704 23788 raft_consensus.cc:740] T 3bb20398982942c09171cef44e6ce18a P 28f091be01f840278e06d55a309877b9 [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: 28f091be01f840278e06d55a309877b9, State: Initialized, Role: FOLLOWER
I20260812 06:19:36.657874 23788 consensus_queue.cc:260] T 3bb20398982942c09171cef44e6ce18a P 28f091be01f840278e06d55a309877b9 [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: "28f091be01f840278e06d55a309877b9" member_type: VOTER last_known_addr { host: "127.23.10.65" port: 35845 } }
I20260812 06:19:36.657958 23788 raft_consensus.cc:399] T 3bb20398982942c09171cef44e6ce18a P 28f091be01f840278e06d55a309877b9 [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:19:36.658006 23788 raft_consensus.cc:493] T 3bb20398982942c09171cef44e6ce18a P 28f091be01f840278e06d55a309877b9 [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:19:36.658063 23788 raft_consensus.cc:3060] T 3bb20398982942c09171cef44e6ce18a P 28f091be01f840278e06d55a309877b9 [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:19:36.658944 23788 raft_consensus.cc:515] T 3bb20398982942c09171cef44e6ce18a P 28f091be01f840278e06d55a309877b9 [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "28f091be01f840278e06d55a309877b9" member_type: VOTER last_known_addr { host: "127.23.10.65" port: 35845 } }
I20260812 06:19:36.659111 23788 leader_election.cc:304] T 3bb20398982942c09171cef44e6ce18a P 28f091be01f840278e06d55a309877b9 [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: 28f091be01f840278e06d55a309877b9; no voters: 
I20260812 06:19:36.659365 23788 leader_election.cc:290] T 3bb20398982942c09171cef44e6ce18a P 28f091be01f840278e06d55a309877b9 [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:19:36.659582 23790 raft_consensus.cc:2804] T 3bb20398982942c09171cef44e6ce18a P 28f091be01f840278e06d55a309877b9 [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:19:36.659879 23788 ts_tablet_manager.cc:1434] T 3bb20398982942c09171cef44e6ce18a P 28f091be01f840278e06d55a309877b9: Time spent starting tablet: real 0.003s	user 0.003s	sys 0.000s
I20260812 06:19:36.659952 23790 raft_consensus.cc:697] T 3bb20398982942c09171cef44e6ce18a P 28f091be01f840278e06d55a309877b9 [term 1 LEADER]: Becoming Leader. State: Replica: 28f091be01f840278e06d55a309877b9, State: Running, Role: LEADER
I20260812 06:19:36.660274 23790 consensus_queue.cc:237] T 3bb20398982942c09171cef44e6ce18a P 28f091be01f840278e06d55a309877b9 [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: "28f091be01f840278e06d55a309877b9" member_type: VOTER last_known_addr { host: "127.23.10.65" port: 35845 } }
I20260812 06:19:36.660386 23774 heartbeater.cc:499] Master 127.23.10.126:38959 was elected leader, sending a full tablet report...
I20260812 06:19:36.663024 23628 catalog_manager.cc:5719] T 3bb20398982942c09171cef44e6ce18a P 28f091be01f840278e06d55a309877b9 reported cstate change: term changed from 0 to 1, leader changed from <none> to 28f091be01f840278e06d55a309877b9 (127.23.10.65). New cstate: current_term: 1 leader_uuid: "28f091be01f840278e06d55a309877b9" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "28f091be01f840278e06d55a309877b9" member_type: VOTER last_known_addr { host: "127.23.10.65" port: 35845 } health_report { overall_health: HEALTHY } } }
I20260812 06:19:36.729068 23593 heavy-update-compaction-itest.cc:215] Time spent inserting: real 0.056s	user 0.022s	sys 0.005s
I20260812 06:19:36.857568 23775 maintenance_manager.cc:419] P 28f091be01f840278e06d55a309877b9: Scheduling FlushMRSOp(3bb20398982942c09171cef44e6ce18a): perf score=19.054940
I20260812 06:19:37.043061 23710 maintenance_manager.cc:643] P 28f091be01f840278e06d55a309877b9: FlushMRSOp(3bb20398982942c09171cef44e6ce18a) complete. Timing: real 0.185s	user 0.137s	sys 0.044s Metrics: {"bytes_written":12307490,"cfile_init":1,"compiler_manager_pool.queue_time_us":210,"delete_count":0,"dirs.queue_time_us":82,"dirs.run_cpu_time_us":290,"dirs.run_wall_time_us":883,"drs_written":1,"lbm_read_time_us":75,"lbm_reads_lt_1ms":4,"lbm_write_time_us":45527,"lbm_writes_lt_1ms":757,"peak_mem_usage":0,"reinsert_count":0,"rows_written":104,"spinlock_wait_cycles":1280,"thread_start_us":133,"threads_started":1,"update_count":1500}
I20260812 06:19:37.044488 23775 maintenance_manager.cc:419] P 28f091be01f840278e06d55a309877b9: Scheduling LogGCOp(3bb20398982942c09171cef44e6ce18a): free 20743880 bytes of WAL
I20260812 06:19:37.044803 23710 log_reader.cc:385] T 3bb20398982942c09171cef44e6ce18a: removed 2 log segments from log reader
I20260812 06:19:37.044872 23710 log.cc:1079] T 3bb20398982942c09171cef44e6ce18a P 28f091be01f840278e06d55a309877b9: Deleting log segment in path: /tmp/dist-test-task0b99mg/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515576443844-23593-0/minicluster-data/ts-0-root/wals/3bb20398982942c09171cef44e6ce18a/wal-000000001 (ops 1-6)
I20260812 06:19:37.044924 23710 log.cc:1079] T 3bb20398982942c09171cef44e6ce18a P 28f091be01f840278e06d55a309877b9: Deleting log segment in path: /tmp/dist-test-task0b99mg/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515576443844-23593-0/minicluster-data/ts-0-root/wals/3bb20398982942c09171cef44e6ce18a/wal-000000002 (ops 7-11)
I20260812 06:19:37.050652 23710 maintenance_manager.cc:643] P 28f091be01f840278e06d55a309877b9: LogGCOp(3bb20398982942c09171cef44e6ce18a) complete. Timing: real 0.006s	user 0.000s	sys 0.003s Metrics: {}
I20260812 06:19:37.050974 23775 maintenance_manager.cc:419] P 28f091be01f840278e06d55a309877b9: Scheduling FlushDeltaMemStoresOp(3bb20398982942c09171cef44e6ce18a): perf score=3.181125
I20260812 06:19:37.075294 23710 maintenance_manager.cc:643] P 28f091be01f840278e06d55a309877b9: FlushDeltaMemStoresOp(3bb20398982942c09171cef44e6ce18a) complete. Timing: real 0.024s	user 0.009s	sys 0.012s Metrics: {"bytes_written":4512900,"delete_count":0,"lbm_write_time_us":5931,"lbm_writes_lt_1ms":113,"reinsert_count":0,"update_count":550}
I20260812 06:19:37.075776 23775 maintenance_manager.cc:419] P 28f091be01f840278e06d55a309877b9: Scheduling FlushDeltaMemStoresOp(3bb20398982942c09171cef44e6ce18a): perf score=2.188937
I20260812 06:19:37.090739 23710 maintenance_manager.cc:643] P 28f091be01f840278e06d55a309877b9: FlushDeltaMemStoresOp(3bb20398982942c09171cef44e6ce18a) complete. Timing: real 0.015s	user 0.013s	sys 0.000s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":5714,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:19:37.091185 23775 maintenance_manager.cc:419] P 28f091be01f840278e06d55a309877b9: Scheduling UndoDeltaBlockGCOp(3bb20398982942c09171cef44e6ce18a): 16411393 bytes on disk
I20260812 06:19:37.091827 23710 maintenance_manager.cc:643] P 28f091be01f840278e06d55a309877b9: UndoDeltaBlockGCOp(3bb20398982942c09171cef44e6ce18a) 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:37.092315 23775 maintenance_manager.cc:419] P 28f091be01f840278e06d55a309877b9: Scheduling MajorDeltaCompactionOp(3bb20398982942c09171cef44e6ce18a): perf score=1.000000
I20260812 06:19:37.266928 23710 maintenance_manager.cc:643] P 28f091be01f840278e06d55a309877b9: MajorDeltaCompactionOp(3bb20398982942c09171cef44e6ce18a) complete. Timing: real 0.174s	user 0.117s	sys 0.057s Metrics: {"cfile_cache_miss":533,"cfile_cache_miss_bytes":24774795,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":598,"lbm_read_time_us":11981,"lbm_reads_lt_1ms":569,"lbm_write_time_us":30420,"lbm_writes_lt_1ms":543,"mutex_wait_us":88,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":13312,"thread_start_us":362,"threads_started":5,"update_count":2500}
I20260812 06:19:37.267577 23775 maintenance_manager.cc:419] P 28f091be01f840278e06d55a309877b9: Scheduling FlushDeltaMemStoresOp(3bb20398982942c09171cef44e6ce18a): perf score=10.126437
I20260812 06:19:37.304347 23710 maintenance_manager.cc:643] P 28f091be01f840278e06d55a309877b9: FlushDeltaMemStoresOp(3bb20398982942c09171cef44e6ce18a) complete. Timing: real 0.037s	user 0.029s	sys 0.007s Metrics: {"bytes_written":12307491,"delete_count":0,"lbm_write_time_us":15796,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:19:37.304888 23775 maintenance_manager.cc:419] P 28f091be01f840278e06d55a309877b9: Scheduling FlushDeltaMemStoresOp(3bb20398982942c09171cef44e6ce18a): perf score=2.188937
I20260812 06:19:37.326735 23710 maintenance_manager.cc:643] P 28f091be01f840278e06d55a309877b9: FlushDeltaMemStoresOp(3bb20398982942c09171cef44e6ce18a) complete. Timing: real 0.022s	user 0.009s	sys 0.004s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":5806,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:37.327158 23775 maintenance_manager.cc:419] P 28f091be01f840278e06d55a309877b9: Scheduling MajorDeltaCompactionOp(3bb20398982942c09171cef44e6ce18a): perf score=1.000000
I20260812 06:19:37.453820 23710 maintenance_manager.cc:643] P 28f091be01f840278e06d55a309877b9: MajorDeltaCompactionOp(3bb20398982942c09171cef44e6ce18a) complete. Timing: real 0.126s	user 0.108s	sys 0.018s 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":935,"lbm_read_time_us":8338,"lbm_reads_lt_1ms":464,"lbm_write_time_us":25153,"lbm_writes_lt_1ms":443,"mutex_wait_us":263,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":5504,"update_count":2000}
I20260812 06:19:37.454353 23775 maintenance_manager.cc:419] P 28f091be01f840278e06d55a309877b9: Scheduling FlushDeltaMemStoresOp(3bb20398982942c09171cef44e6ce18a): perf score=10.126437
I20260812 06:19:37.494686 23710 maintenance_manager.cc:643] P 28f091be01f840278e06d55a309877b9: FlushDeltaMemStoresOp(3bb20398982942c09171cef44e6ce18a) complete. Timing: real 0.040s	user 0.012s	sys 0.025s Metrics: {"bytes_written":12307492,"delete_count":0,"lbm_write_time_us":18871,"lbm_writes_1-10_ms":2,"lbm_writes_lt_1ms":301,"reinsert_count":0,"update_count":1500}
I20260812 06:19:37.495132 23775 maintenance_manager.cc:419] P 28f091be01f840278e06d55a309877b9: Scheduling FlushDeltaMemStoresOp(3bb20398982942c09171cef44e6ce18a): perf score=2.188937
I20260812 06:19:37.507766 23710 maintenance_manager.cc:643] P 28f091be01f840278e06d55a309877b9: FlushDeltaMemStoresOp(3bb20398982942c09171cef44e6ce18a) complete. Timing: real 0.012s	user 0.010s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4624,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:37.508253 23775 maintenance_manager.cc:419] P 28f091be01f840278e06d55a309877b9: Scheduling MajorDeltaCompactionOp(3bb20398982942c09171cef44e6ce18a): perf score=1.000000
I20260812 06:19:37.626703 23710 maintenance_manager.cc:643] P 28f091be01f840278e06d55a309877b9: MajorDeltaCompactionOp(3bb20398982942c09171cef44e6ce18a) complete. Timing: real 0.118s	user 0.107s	sys 0.009s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672279,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":820,"lbm_read_time_us":8678,"lbm_reads_lt_1ms":464,"lbm_write_time_us":23276,"lbm_writes_lt_1ms":443,"mutex_wait_us":289,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":11776,"update_count":2000}
I20260812 06:19:37.627480 23775 maintenance_manager.cc:419] P 28f091be01f840278e06d55a309877b9: Scheduling FlushDeltaMemStoresOp(3bb20398982942c09171cef44e6ce18a): perf score=10.126437
I20260812 06:19:37.663892 23710 maintenance_manager.cc:643] P 28f091be01f840278e06d55a309877b9: FlushDeltaMemStoresOp(3bb20398982942c09171cef44e6ce18a) complete. Timing: real 0.036s	user 0.026s	sys 0.007s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":15922,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:19:37.664371 23775 maintenance_manager.cc:419] P 28f091be01f840278e06d55a309877b9: Scheduling FlushDeltaMemStoresOp(3bb20398982942c09171cef44e6ce18a): perf score=2.188937
I20260812 06:19:37.677542 23710 maintenance_manager.cc:643] P 28f091be01f840278e06d55a309877b9: FlushDeltaMemStoresOp(3bb20398982942c09171cef44e6ce18a) complete. Timing: real 0.013s	user 0.007s	sys 0.005s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4716,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:37.678043 23775 maintenance_manager.cc:419] P 28f091be01f840278e06d55a309877b9: Scheduling MajorDeltaCompactionOp(3bb20398982942c09171cef44e6ce18a): perf score=1.000000
I20260812 06:19:37.795780 23710 maintenance_manager.cc:643] P 28f091be01f840278e06d55a309877b9: MajorDeltaCompactionOp(3bb20398982942c09171cef44e6ce18a) complete. Timing: real 0.118s	user 0.088s	sys 0.028s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672276,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":348,"lbm_read_time_us":7609,"lbm_reads_lt_1ms":464,"lbm_write_time_us":23978,"lbm_writes_lt_1ms":443,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":7168,"update_count":2000}
I20260812 06:19:37.796442 23775 maintenance_manager.cc:419] P 28f091be01f840278e06d55a309877b9: Scheduling FlushDeltaMemStoresOp(3bb20398982942c09171cef44e6ce18a): perf score=10.126437
I20260812 06:19:37.843587 23710 maintenance_manager.cc:643] P 28f091be01f840278e06d55a309877b9: FlushDeltaMemStoresOp(3bb20398982942c09171cef44e6ce18a) complete. Timing: real 0.047s	user 0.028s	sys 0.016s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":16552,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:19:37.844167 23775 maintenance_manager.cc:419] P 28f091be01f840278e06d55a309877b9: Scheduling FlushDeltaMemStoresOp(3bb20398982942c09171cef44e6ce18a): perf score=2.188937
I20260812 06:19:37.854838 23710 maintenance_manager.cc:643] P 28f091be01f840278e06d55a309877b9: FlushDeltaMemStoresOp(3bb20398982942c09171cef44e6ce18a) complete. Timing: real 0.010s	user 0.001s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4226,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:37.855306 23775 maintenance_manager.cc:419] P 28f091be01f840278e06d55a309877b9: Scheduling MajorDeltaCompactionOp(3bb20398982942c09171cef44e6ce18a): perf score=1.000000
I20260812 06:19:38.008280 23710 maintenance_manager.cc:643] P 28f091be01f840278e06d55a309877b9: MajorDeltaCompactionOp(3bb20398982942c09171cef44e6ce18a) complete. Timing: real 0.153s	user 0.107s	sys 0.042s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672277,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":1014,"lbm_read_time_us":11264,"lbm_reads_lt_1ms":472,"lbm_write_time_us":26984,"lbm_writes_lt_1ms":443,"mutex_wait_us":322,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":9472,"update_count":2000}
I20260812 06:19:38.008865 23775 maintenance_manager.cc:419] P 28f091be01f840278e06d55a309877b9: Scheduling FlushDeltaMemStoresOp(3bb20398982942c09171cef44e6ce18a): perf score=10.126437
I20260812 06:19:38.057507 23710 maintenance_manager.cc:643] P 28f091be01f840278e06d55a309877b9: FlushDeltaMemStoresOp(3bb20398982942c09171cef44e6ce18a) complete. Timing: real 0.048s	user 0.021s	sys 0.013s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":15728,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:19:38.057940 23775 maintenance_manager.cc:419] P 28f091be01f840278e06d55a309877b9: Scheduling FlushDeltaMemStoresOp(3bb20398982942c09171cef44e6ce18a): perf score=2.188937
I20260812 06:19:38.068567 23710 maintenance_manager.cc:643] P 28f091be01f840278e06d55a309877b9: FlushDeltaMemStoresOp(3bb20398982942c09171cef44e6ce18a) complete. Timing: real 0.010s	user 0.010s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4124,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:38.069262 23775 maintenance_manager.cc:419] P 28f091be01f840278e06d55a309877b9: Scheduling MajorDeltaCompactionOp(3bb20398982942c09171cef44e6ce18a): perf score=1.000000
I20260812 06:19:38.192399 23710 maintenance_manager.cc:643] P 28f091be01f840278e06d55a309877b9: MajorDeltaCompactionOp(3bb20398982942c09171cef44e6ce18a) complete. Timing: real 0.123s	user 0.084s	sys 0.036s 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":3306,"dirs.run_cpu_time_us":515,"dirs.run_wall_time_us":2848,"lbm_read_time_us":10758,"lbm_reads_lt_1ms":472,"lbm_write_time_us":21411,"lbm_writes_lt_1ms":443,"mutex_wait_us":2778,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":5632,"update_count":2000}
I20260812 06:19:38.192956 23775 maintenance_manager.cc:419] P 28f091be01f840278e06d55a309877b9: Scheduling FlushDeltaMemStoresOp(3bb20398982942c09171cef44e6ce18a): perf score=10.126437
I20260812 06:19:38.230656 23710 maintenance_manager.cc:643] P 28f091be01f840278e06d55a309877b9: FlushDeltaMemStoresOp(3bb20398982942c09171cef44e6ce18a) complete. Timing: real 0.038s	user 0.022s	sys 0.008s Metrics: {"bytes_written":12307489,"delete_count":0,"lbm_write_time_us":14050,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:19:38.231164 23775 maintenance_manager.cc:419] P 28f091be01f840278e06d55a309877b9: Scheduling FlushDeltaMemStoresOp(3bb20398982942c09171cef44e6ce18a): perf score=2.188937
I20260812 06:19:38.241715 23710 maintenance_manager.cc:643] P 28f091be01f840278e06d55a309877b9: FlushDeltaMemStoresOp(3bb20398982942c09171cef44e6ce18a) complete. Timing: real 0.010s	user 0.001s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4180,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:38.242384 23775 maintenance_manager.cc:419] P 28f091be01f840278e06d55a309877b9: Scheduling FlushMRSOp(3bb20398982942c09171cef44e6ce18a): perf score=1.000000
I20260812 06:19:38.274308 23710 maintenance_manager.cc:643] P 28f091be01f840278e06d55a309877b9: FlushMRSOp(3bb20398982942c09171cef44e6ce18a) complete. Timing: real 0.032s	user 0.030s	sys 0.000s Metrics: {"bytes_written":1193503,"cfile_init":1,"dirs.queue_time_us":60,"dirs.run_cpu_time_us":261,"dirs.run_wall_time_us":1283,"drs_written":1,"lbm_read_time_us":39,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1795,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":29}
I20260812 06:19:38.275103 23775 maintenance_manager.cc:419] P 28f091be01f840278e06d55a309877b9: Scheduling LogGCOp(3bb20398982942c09171cef44e6ce18a): free 112239257 bytes of WAL
I20260812 06:19:38.275353 23710 log_reader.cc:385] T 3bb20398982942c09171cef44e6ce18a: removed 11 log segments from log reader
I20260812 06:19:38.275399 23710 log.cc:1079] T 3bb20398982942c09171cef44e6ce18a P 28f091be01f840278e06d55a309877b9: Deleting log segment in path: /tmp/dist-test-task0b99mg/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515576443844-23593-0/minicluster-data/ts-0-root/wals/3bb20398982942c09171cef44e6ce18a/wal-000000003 (ops 12-16)
I20260812 06:19:38.275429 23710 log.cc:1079] T 3bb20398982942c09171cef44e6ce18a P 28f091be01f840278e06d55a309877b9: Deleting log segment in path: /tmp/dist-test-task0b99mg/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515576443844-23593-0/minicluster-data/ts-0-root/wals/3bb20398982942c09171cef44e6ce18a/wal-000000004 (ops 17-21)
I20260812 06:19:38.275491 23710 log.cc:1079] T 3bb20398982942c09171cef44e6ce18a P 28f091be01f840278e06d55a309877b9: Deleting log segment in path: /tmp/dist-test-task0b99mg/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515576443844-23593-0/minicluster-data/ts-0-root/wals/3bb20398982942c09171cef44e6ce18a/wal-000000005 (ops 22-26)
I20260812 06:19:38.275537 23710 log.cc:1079] T 3bb20398982942c09171cef44e6ce18a P 28f091be01f840278e06d55a309877b9: Deleting log segment in path: /tmp/dist-test-task0b99mg/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515576443844-23593-0/minicluster-data/ts-0-root/wals/3bb20398982942c09171cef44e6ce18a/wal-000000006 (ops 27-31)
I20260812 06:19:38.275573 23710 log.cc:1079] T 3bb20398982942c09171cef44e6ce18a P 28f091be01f840278e06d55a309877b9: Deleting log segment in path: /tmp/dist-test-task0b99mg/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515576443844-23593-0/minicluster-data/ts-0-root/wals/3bb20398982942c09171cef44e6ce18a/wal-000000007 (ops 32-36)
I20260812 06:19:38.275627 23710 log.cc:1079] T 3bb20398982942c09171cef44e6ce18a P 28f091be01f840278e06d55a309877b9: Deleting log segment in path: /tmp/dist-test-task0b99mg/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515576443844-23593-0/minicluster-data/ts-0-root/wals/3bb20398982942c09171cef44e6ce18a/wal-000000008 (ops 37-41)
I20260812 06:19:38.275663 23710 log.cc:1079] T 3bb20398982942c09171cef44e6ce18a P 28f091be01f840278e06d55a309877b9: Deleting log segment in path: /tmp/dist-test-task0b99mg/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515576443844-23593-0/minicluster-data/ts-0-root/wals/3bb20398982942c09171cef44e6ce18a/wal-000000009 (ops 42-46)
I20260812 06:19:38.275692 23710 log.cc:1079] T 3bb20398982942c09171cef44e6ce18a P 28f091be01f840278e06d55a309877b9: Deleting log segment in path: /tmp/dist-test-task0b99mg/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515576443844-23593-0/minicluster-data/ts-0-root/wals/3bb20398982942c09171cef44e6ce18a/wal-000000010 (ops 47-51)
I20260812 06:19:38.275728 23710 log.cc:1079] T 3bb20398982942c09171cef44e6ce18a P 28f091be01f840278e06d55a309877b9: Deleting log segment in path: /tmp/dist-test-task0b99mg/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515576443844-23593-0/minicluster-data/ts-0-root/wals/3bb20398982942c09171cef44e6ce18a/wal-000000011 (ops 52-56)
I20260812 06:19:38.275765 23710 log.cc:1079] T 3bb20398982942c09171cef44e6ce18a P 28f091be01f840278e06d55a309877b9: Deleting log segment in path: /tmp/dist-test-task0b99mg/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515576443844-23593-0/minicluster-data/ts-0-root/wals/3bb20398982942c09171cef44e6ce18a/wal-000000012 (ops 57-60)
I20260812 06:19:38.275805 23710 log.cc:1079] T 3bb20398982942c09171cef44e6ce18a P 28f091be01f840278e06d55a309877b9: Deleting log segment in path: /tmp/dist-test-task0b99mg/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515576443844-23593-0/minicluster-data/ts-0-root/wals/3bb20398982942c09171cef44e6ce18a/wal-000000013 (ops 61-65)
I20260812 06:19:38.300891 23710 maintenance_manager.cc:643] P 28f091be01f840278e06d55a309877b9: LogGCOp(3bb20398982942c09171cef44e6ce18a) complete. Timing: real 0.026s	user 0.000s	sys 0.025s Metrics: {}
I20260812 06:19:38.301395 23775 maintenance_manager.cc:419] P 28f091be01f840278e06d55a309877b9: Scheduling UndoDeltaBlockGCOp(3bb20398982942c09171cef44e6ce18a): 462 bytes on disk
I20260812 06:19:38.301945 23710 maintenance_manager.cc:643] P 28f091be01f840278e06d55a309877b9: UndoDeltaBlockGCOp(3bb20398982942c09171cef44e6ce18a) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":64,"lbm_reads_lt_1ms":4}
I20260812 06:19:38.302523 23775 maintenance_manager.cc:419] P 28f091be01f840278e06d55a309877b9: Scheduling FlushDeltaMemStoresOp(3bb20398982942c09171cef44e6ce18a): perf score=4.173312
I20260812 06:19:38.316433 23710 maintenance_manager.cc:643] P 28f091be01f840278e06d55a309877b9: FlushDeltaMemStoresOp(3bb20398982942c09171cef44e6ce18a) complete. Timing: real 0.014s	user 0.005s	sys 0.009s Metrics: {"bytes_written":5743633,"delete_count":0,"lbm_write_time_us":5725,"lbm_writes_lt_1ms":143,"reinsert_count":0,"update_count":700}
I20260812 06:19:38.316877 23775 maintenance_manager.cc:419] P 28f091be01f840278e06d55a309877b9: Scheduling LogGCOp(3bb20398982942c09171cef44e6ce18a): free 12017983 bytes of WAL
I20260812 06:19:38.317091 23710 log_reader.cc:385] T 3bb20398982942c09171cef44e6ce18a: removed 1 log segments from log reader
I20260812 06:19:38.317137 23710 log.cc:1079] T 3bb20398982942c09171cef44e6ce18a P 28f091be01f840278e06d55a309877b9: Deleting log segment in path: /tmp/dist-test-task0b99mg/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515576443844-23593-0/minicluster-data/ts-0-root/wals/3bb20398982942c09171cef44e6ce18a/wal-000000014 (ops 66-70)
I20260812 06:19:38.319579 23710 maintenance_manager.cc:643] P 28f091be01f840278e06d55a309877b9: LogGCOp(3bb20398982942c09171cef44e6ce18a) complete. Timing: real 0.003s	user 0.000s	sys 0.000s Metrics: {}
I20260812 06:19:38.319890 23775 maintenance_manager.cc:419] P 28f091be01f840278e06d55a309877b9: Scheduling FlushDeltaMemStoresOp(3bb20398982942c09171cef44e6ce18a): perf score=1.196750
I20260812 06:19:38.333030 23710 maintenance_manager.cc:643] P 28f091be01f840278e06d55a309877b9: FlushDeltaMemStoresOp(3bb20398982942c09171cef44e6ce18a) complete. Timing: real 0.013s	user 0.010s	sys 0.000s Metrics: {"bytes_written":2461654,"delete_count":0,"lbm_write_time_us":3692,"lbm_writes_lt_1ms":63,"reinsert_count":0,"update_count":300}
I20260812 06:19:38.333514 23775 maintenance_manager.cc:419] P 28f091be01f840278e06d55a309877b9: Scheduling MajorDeltaCompactionOp(3bb20398982942c09171cef44e6ce18a): perf score=1.000000
I20260812 06:19:38.516500 23710 maintenance_manager.cc:643] P 28f091be01f840278e06d55a309877b9: MajorDeltaCompactionOp(3bb20398982942c09171cef44e6ce18a) complete. Timing: real 0.183s	user 0.140s	sys 0.040s Metrics: {"cfile_cache_miss":634,"cfile_cache_miss_bytes":28877301,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":3371,"lbm_read_time_us":12641,"lbm_reads_lt_1ms":670,"lbm_write_time_us":36172,"lbm_writes_lt_1ms":643,"mutex_wait_us":2726,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":16640,"thread_start_us":97,"threads_started":1,"update_count":3000}
I20260812 06:19:38.517217 23775 maintenance_manager.cc:419] P 28f091be01f840278e06d55a309877b9: Scheduling FlushDeltaMemStoresOp(3bb20398982942c09171cef44e6ce18a): perf score=14.095187
I20260812 06:19:38.561899 23710 maintenance_manager.cc:643] P 28f091be01f840278e06d55a309877b9: FlushDeltaMemStoresOp(3bb20398982942c09171cef44e6ce18a) complete. Timing: real 0.044s	user 0.031s	sys 0.012s Metrics: {"bytes_written":16409903,"delete_count":0,"lbm_write_time_us":19825,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:38.562415 23775 maintenance_manager.cc:419] P 28f091be01f840278e06d55a309877b9: Scheduling FlushDeltaMemStoresOp(3bb20398982942c09171cef44e6ce18a): perf score=2.188937
I20260812 06:19:38.573765 23710 maintenance_manager.cc:643] P 28f091be01f840278e06d55a309877b9: FlushDeltaMemStoresOp(3bb20398982942c09171cef44e6ce18a) complete. Timing: real 0.011s	user 0.005s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4310,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:38.574316 23775 maintenance_manager.cc:419] P 28f091be01f840278e06d55a309877b9: Scheduling MajorDeltaCompactionOp(3bb20398982942c09171cef44e6ce18a): perf score=1.000000
I20260812 06:19:38.731449 23710 maintenance_manager.cc:643] P 28f091be01f840278e06d55a309877b9: MajorDeltaCompactionOp(3bb20398982942c09171cef44e6ce18a) complete. Timing: real 0.157s	user 0.102s	sys 0.049s 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":203,"lbm_read_time_us":9185,"lbm_reads_lt_1ms":572,"lbm_write_time_us":30196,"lbm_writes_lt_1ms":543,"mutex_wait_us":30,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":15488,"update_count":2500}
I20260812 06:19:38.732199 23775 maintenance_manager.cc:419] P 28f091be01f840278e06d55a309877b9: Scheduling FlushDeltaMemStoresOp(3bb20398982942c09171cef44e6ce18a): perf score=14.095187
I20260812 06:19:38.788461 23710 maintenance_manager.cc:643] P 28f091be01f840278e06d55a309877b9: FlushDeltaMemStoresOp(3bb20398982942c09171cef44e6ce18a) complete. Timing: real 0.056s	user 0.037s	sys 0.013s Metrics: {"bytes_written":16409900,"delete_count":0,"lbm_write_time_us":22612,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:38.789011 23775 maintenance_manager.cc:419] P 28f091be01f840278e06d55a309877b9: Scheduling MajorDeltaCompactionOp(3bb20398982942c09171cef44e6ce18a): perf score=1.000000
I20260812 06:19:38.934782 23710 maintenance_manager.cc:643] P 28f091be01f840278e06d55a309877b9: MajorDeltaCompactionOp(3bb20398982942c09171cef44e6ce18a) complete. Timing: real 0.146s	user 0.086s	sys 0.057s Metrics: {"cfile_cache_miss":431,"cfile_cache_miss_bytes":20672156,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":1,"delta_iterators_relevant":1,"dirs.queue_time_us":511,"lbm_read_time_us":9470,"lbm_reads_lt_1ms":463,"lbm_write_time_us":26963,"lbm_writes_lt_1ms":443,"mutex_wait_us":289,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":8448,"update_count":2000}
I20260812 06:19:38.935534 23775 maintenance_manager.cc:419] P 28f091be01f840278e06d55a309877b9: Scheduling FlushDeltaMemStoresOp(3bb20398982942c09171cef44e6ce18a): perf score=11.118625
I20260812 06:19:38.974881 23710 maintenance_manager.cc:643] P 28f091be01f840278e06d55a309877b9: FlushDeltaMemStoresOp(3bb20398982942c09171cef44e6ce18a) complete. Timing: real 0.039s	user 0.018s	sys 0.017s Metrics: {"bytes_written":12717735,"delete_count":0,"lbm_write_time_us":15766,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:19:38.975370 23775 maintenance_manager.cc:419] P 28f091be01f840278e06d55a309877b9: Scheduling FlushDeltaMemStoresOp(3bb20398982942c09171cef44e6ce18a): perf score=2.188937
I20260812 06:19:38.992587 23710 maintenance_manager.cc:643] P 28f091be01f840278e06d55a309877b9: FlushDeltaMemStoresOp(3bb20398982942c09171cef44e6ce18a) complete. Timing: real 0.017s	user 0.008s	sys 0.003s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4165,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:38.993028 23775 maintenance_manager.cc:419] P 28f091be01f840278e06d55a309877b9: Scheduling FlushDeltaMemStoresOp(3bb20398982942c09171cef44e6ce18a): perf score=2.188937
I20260812 06:19:39.002560 23710 maintenance_manager.cc:643] P 28f091be01f840278e06d55a309877b9: FlushDeltaMemStoresOp(3bb20398982942c09171cef44e6ce18a) complete. Timing: real 0.009s	user 0.004s	sys 0.003s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3640,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:19:39.002982 23775 maintenance_manager.cc:419] P 28f091be01f840278e06d55a309877b9: Scheduling MajorDeltaCompactionOp(3bb20398982942c09171cef44e6ce18a): perf score=1.000000
I20260812 06:19:39.177508 23710 maintenance_manager.cc:643] P 28f091be01f840278e06d55a309877b9: MajorDeltaCompactionOp(3bb20398982942c09171cef44e6ce18a) complete. Timing: real 0.174s	user 0.125s	sys 0.039s Metrics: {"cfile_cache_miss":533,"cfile_cache_miss_bytes":24774799,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":470,"lbm_read_time_us":11311,"lbm_reads_lt_1ms":573,"lbm_write_time_us":28596,"lbm_writes_lt_1ms":543,"mutex_wait_us":171,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":768,"update_count":2500}
I20260812 06:19:39.178287 23775 maintenance_manager.cc:419] P 28f091be01f840278e06d55a309877b9: Scheduling FlushDeltaMemStoresOp(3bb20398982942c09171cef44e6ce18a): perf score=11.118625
I20260812 06:19:39.225589 23710 maintenance_manager.cc:643] P 28f091be01f840278e06d55a309877b9: FlushDeltaMemStoresOp(3bb20398982942c09171cef44e6ce18a) complete. Timing: real 0.047s	user 0.021s	sys 0.024s Metrics: {"bytes_written":12717735,"delete_count":0,"lbm_write_time_us":22124,"lbm_writes_1-10_ms":2,"lbm_writes_lt_1ms":311,"reinsert_count":0,"update_count":1550}
I20260812 06:19:39.226045 23775 maintenance_manager.cc:419] P 28f091be01f840278e06d55a309877b9: Scheduling FlushDeltaMemStoresOp(3bb20398982942c09171cef44e6ce18a): perf score=2.188937
I20260812 06:19:39.241237 23710 maintenance_manager.cc:643] P 28f091be01f840278e06d55a309877b9: FlushDeltaMemStoresOp(3bb20398982942c09171cef44e6ce18a) complete. Timing: real 0.015s	user 0.010s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4010,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:39.241694 23775 maintenance_manager.cc:419] P 28f091be01f840278e06d55a309877b9: Scheduling FlushDeltaMemStoresOp(3bb20398982942c09171cef44e6ce18a): perf score=2.188937
I20260812 06:19:39.251019 23710 maintenance_manager.cc:643] P 28f091be01f840278e06d55a309877b9: FlushDeltaMemStoresOp(3bb20398982942c09171cef44e6ce18a) complete. Timing: real 0.009s	user 0.008s	sys 0.000s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3535,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:19:39.251458 23775 maintenance_manager.cc:419] P 28f091be01f840278e06d55a309877b9: Scheduling MajorDeltaCompactionOp(3bb20398982942c09171cef44e6ce18a): perf score=1.000000
I20260812 06:19:39.410970 23710 maintenance_manager.cc:643] P 28f091be01f840278e06d55a309877b9: MajorDeltaCompactionOp(3bb20398982942c09171cef44e6ce18a) complete. Timing: real 0.159s	user 0.107s	sys 0.044s Metrics: {"cfile_cache_miss":533,"cfile_cache_miss_bytes":24774799,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":284,"lbm_read_time_us":11227,"lbm_reads_lt_1ms":573,"lbm_write_time_us":30434,"lbm_writes_lt_1ms":543,"mutex_wait_us":58,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":768,"update_count":2500}
I20260812 06:19:39.411613 23775 maintenance_manager.cc:419] P 28f091be01f840278e06d55a309877b9: Scheduling FlushDeltaMemStoresOp(3bb20398982942c09171cef44e6ce18a): perf score=11.118625
I20260812 06:19:39.444741 23710 maintenance_manager.cc:643] P 28f091be01f840278e06d55a309877b9: FlushDeltaMemStoresOp(3bb20398982942c09171cef44e6ce18a) complete. Timing: real 0.032s	user 0.023s	sys 0.009s Metrics: {"bytes_written":12717735,"delete_count":0,"lbm_write_time_us":13524,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:19:39.445421 23775 maintenance_manager.cc:419] P 28f091be01f840278e06d55a309877b9: Scheduling FlushDeltaMemStoresOp(3bb20398982942c09171cef44e6ce18a): perf score=2.188937
I20260812 06:19:39.470263 23710 maintenance_manager.cc:643] P 28f091be01f840278e06d55a309877b9: FlushDeltaMemStoresOp(3bb20398982942c09171cef44e6ce18a) complete. Timing: real 0.025s	user 0.008s	sys 0.004s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":5369,"lbm_writes_lt_1ms":93,"reinsert_count":0,"spinlock_wait_cycles":1792,"update_count":450}
I20260812 06:19:39.470714 23775 maintenance_manager.cc:419] P 28f091be01f840278e06d55a309877b9: Scheduling FlushDeltaMemStoresOp(3bb20398982942c09171cef44e6ce18a): perf score=2.188937
I20260812 06:19:39.481068 23710 maintenance_manager.cc:643] P 28f091be01f840278e06d55a309877b9: FlushDeltaMemStoresOp(3bb20398982942c09171cef44e6ce18a) complete. Timing: real 0.010s	user 0.004s	sys 0.005s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3992,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:39.481514 23775 maintenance_manager.cc:419] P 28f091be01f840278e06d55a309877b9: Scheduling MajorDeltaCompactionOp(3bb20398982942c09171cef44e6ce18a): perf score=1.000000
I20260812 06:19:39.636543 23710 maintenance_manager.cc:643] P 28f091be01f840278e06d55a309877b9: MajorDeltaCompactionOp(3bb20398982942c09171cef44e6ce18a) complete. Timing: real 0.155s	user 0.094s	sys 0.050s Metrics: {"cfile_cache_miss":533,"cfile_cache_miss_bytes":24774799,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":179,"lbm_read_time_us":11482,"lbm_reads_lt_1ms":573,"lbm_write_time_us":29674,"lbm_writes_lt_1ms":543,"mutex_wait_us":19,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":11392,"update_count":2500}
I20260812 06:19:39.637274 23775 maintenance_manager.cc:419] P 28f091be01f840278e06d55a309877b9: Scheduling FlushDeltaMemStoresOp(3bb20398982942c09171cef44e6ce18a): perf score=14.095187
I20260812 06:19:39.685186 23710 maintenance_manager.cc:643] P 28f091be01f840278e06d55a309877b9: FlushDeltaMemStoresOp(3bb20398982942c09171cef44e6ce18a) complete. Timing: real 0.048s	user 0.028s	sys 0.016s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":19700,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:39.685747 23775 maintenance_manager.cc:419] P 28f091be01f840278e06d55a309877b9: Scheduling FlushDeltaMemStoresOp(3bb20398982942c09171cef44e6ce18a): perf score=2.188937
I20260812 06:19:39.701484 23710 maintenance_manager.cc:643] P 28f091be01f840278e06d55a309877b9: FlushDeltaMemStoresOp(3bb20398982942c09171cef44e6ce18a) complete. Timing: real 0.016s	user 0.010s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5668,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:39.702033 23775 maintenance_manager.cc:419] P 28f091be01f840278e06d55a309877b9: Scheduling FlushMRSOp(3bb20398982942c09171cef44e6ce18a): perf score=1.000000
I20260812 06:19:39.734000 23710 maintenance_manager.cc:643] P 28f091be01f840278e06d55a309877b9: FlushMRSOp(3bb20398982942c09171cef44e6ce18a) complete. Timing: real 0.032s	user 0.022s	sys 0.008s Metrics: {"bytes_written":1275449,"cfile_init":1,"dirs.queue_time_us":69,"dirs.run_cpu_time_us":340,"dirs.run_wall_time_us":1449,"drs_written":1,"lbm_read_time_us":55,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1869,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":31}
I20260812 06:19:39.734820 23775 maintenance_manager.cc:419] P 28f091be01f840278e06d55a309877b9: Scheduling LogGCOp(3bb20398982942c09171cef44e6ce18a): free 120553389 bytes of WAL
I20260812 06:19:39.735105 23710 log_reader.cc:385] T 3bb20398982942c09171cef44e6ce18a: removed 12 log segments from log reader
I20260812 06:19:39.735167 23710 log.cc:1079] T 3bb20398982942c09171cef44e6ce18a P 28f091be01f840278e06d55a309877b9: Deleting log segment in path: /tmp/dist-test-task0b99mg/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515576443844-23593-0/minicluster-data/ts-0-root/wals/3bb20398982942c09171cef44e6ce18a/wal-000000015 (ops 71-75)
I20260812 06:19:39.735209 23710 log.cc:1079] T 3bb20398982942c09171cef44e6ce18a P 28f091be01f840278e06d55a309877b9: Deleting log segment in path: /tmp/dist-test-task0b99mg/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515576443844-23593-0/minicluster-data/ts-0-root/wals/3bb20398982942c09171cef44e6ce18a/wal-000000016 (ops 76-80)
I20260812 06:19:39.735244 23710 log.cc:1079] T 3bb20398982942c09171cef44e6ce18a P 28f091be01f840278e06d55a309877b9: Deleting log segment in path: /tmp/dist-test-task0b99mg/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515576443844-23593-0/minicluster-data/ts-0-root/wals/3bb20398982942c09171cef44e6ce18a/wal-000000017 (ops 81-84)
I20260812 06:19:39.735272 23710 log.cc:1079] T 3bb20398982942c09171cef44e6ce18a P 28f091be01f840278e06d55a309877b9: Deleting log segment in path: /tmp/dist-test-task0b99mg/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515576443844-23593-0/minicluster-data/ts-0-root/wals/3bb20398982942c09171cef44e6ce18a/wal-000000018 (ops 85-89)
I20260812 06:19:39.735301 23710 log.cc:1079] T 3bb20398982942c09171cef44e6ce18a P 28f091be01f840278e06d55a309877b9: Deleting log segment in path: /tmp/dist-test-task0b99mg/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515576443844-23593-0/minicluster-data/ts-0-root/wals/3bb20398982942c09171cef44e6ce18a/wal-000000019 (ops 90-94)
I20260812 06:19:39.735327 23710 log.cc:1079] T 3bb20398982942c09171cef44e6ce18a P 28f091be01f840278e06d55a309877b9: Deleting log segment in path: /tmp/dist-test-task0b99mg/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515576443844-23593-0/minicluster-data/ts-0-root/wals/3bb20398982942c09171cef44e6ce18a/wal-000000020 (ops 95-98)
I20260812 06:19:39.735361 23710 log.cc:1079] T 3bb20398982942c09171cef44e6ce18a P 28f091be01f840278e06d55a309877b9: Deleting log segment in path: /tmp/dist-test-task0b99mg/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515576443844-23593-0/minicluster-data/ts-0-root/wals/3bb20398982942c09171cef44e6ce18a/wal-000000021 (ops 99-103)
I20260812 06:19:39.735394 23710 log.cc:1079] T 3bb20398982942c09171cef44e6ce18a P 28f091be01f840278e06d55a309877b9: Deleting log segment in path: /tmp/dist-test-task0b99mg/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515576443844-23593-0/minicluster-data/ts-0-root/wals/3bb20398982942c09171cef44e6ce18a/wal-000000022 (ops 104-108)
I20260812 06:19:39.735419 23710 log.cc:1079] T 3bb20398982942c09171cef44e6ce18a P 28f091be01f840278e06d55a309877b9: Deleting log segment in path: /tmp/dist-test-task0b99mg/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515576443844-23593-0/minicluster-data/ts-0-root/wals/3bb20398982942c09171cef44e6ce18a/wal-000000023 (ops 109-113)
I20260812 06:19:39.735447 23710 log.cc:1079] T 3bb20398982942c09171cef44e6ce18a P 28f091be01f840278e06d55a309877b9: Deleting log segment in path: /tmp/dist-test-task0b99mg/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515576443844-23593-0/minicluster-data/ts-0-root/wals/3bb20398982942c09171cef44e6ce18a/wal-000000024 (ops 114-118)
I20260812 06:19:39.735472 23710 log.cc:1079] T 3bb20398982942c09171cef44e6ce18a P 28f091be01f840278e06d55a309877b9: Deleting log segment in path: /tmp/dist-test-task0b99mg/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515576443844-23593-0/minicluster-data/ts-0-root/wals/3bb20398982942c09171cef44e6ce18a/wal-000000025 (ops 119-123)
I20260812 06:19:39.735503 23710 log.cc:1079] T 3bb20398982942c09171cef44e6ce18a P 28f091be01f840278e06d55a309877b9: Deleting log segment in path: /tmp/dist-test-task0b99mg/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515576443844-23593-0/minicluster-data/ts-0-root/wals/3bb20398982942c09171cef44e6ce18a/wal-000000026 (ops 124-128)
I20260812 06:19:39.764214 23710 maintenance_manager.cc:643] P 28f091be01f840278e06d55a309877b9: LogGCOp(3bb20398982942c09171cef44e6ce18a) complete. Timing: real 0.029s	user 0.006s	sys 0.023s Metrics: {}
I20260812 06:19:39.764695 23775 maintenance_manager.cc:419] P 28f091be01f840278e06d55a309877b9: Scheduling UndoDeltaBlockGCOp(3bb20398982942c09171cef44e6ce18a): 483 bytes on disk
I20260812 06:19:39.765239 23710 maintenance_manager.cc:643] P 28f091be01f840278e06d55a309877b9: UndoDeltaBlockGCOp(3bb20398982942c09171cef44e6ce18a) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":90,"lbm_reads_lt_1ms":4}
I20260812 06:19:39.765790 23775 maintenance_manager.cc:419] P 28f091be01f840278e06d55a309877b9: Scheduling FlushDeltaMemStoresOp(3bb20398982942c09171cef44e6ce18a): perf score=2.188937
I20260812 06:19:39.789534 23710 maintenance_manager.cc:643] P 28f091be01f840278e06d55a309877b9: FlushDeltaMemStoresOp(3bb20398982942c09171cef44e6ce18a) complete. Timing: real 0.024s	user 0.010s	sys 0.005s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6577,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:39.790061 23775 maintenance_manager.cc:419] P 28f091be01f840278e06d55a309877b9: Scheduling FlushDeltaMemStoresOp(3bb20398982942c09171cef44e6ce18a): perf score=2.188937
I20260812 06:19:39.802033 23710 maintenance_manager.cc:643] P 28f091be01f840278e06d55a309877b9: FlushDeltaMemStoresOp(3bb20398982942c09171cef44e6ce18a) complete. Timing: real 0.012s	user 0.010s	sys 0.000s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4480,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:39.802695 23775 maintenance_manager.cc:419] P 28f091be01f840278e06d55a309877b9: Scheduling MajorDeltaCompactionOp(3bb20398982942c09171cef44e6ce18a): perf score=1.000000
I20260812 06:19:40.056494 23710 maintenance_manager.cc:643] P 28f091be01f840278e06d55a309877b9: MajorDeltaCompactionOp(3bb20398982942c09171cef44e6ce18a) complete. Timing: real 0.254s	user 0.173s	sys 0.067s Metrics: {"cfile_cache_miss":734,"cfile_cache_miss_bytes":32979749,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":707,"lbm_read_time_us":16619,"lbm_reads_lt_1ms":774,"lbm_write_time_us":42323,"lbm_writes_lt_1ms":743,"mutex_wait_us":42,"peak_mem_usage":87969044,"reinsert_count":0,"spinlock_wait_cycles":23936,"thread_start_us":79,"threads_started":1,"update_count":3500}
I20260812 06:19:40.057548 23775 maintenance_manager.cc:419] P 28f091be01f840278e06d55a309877b9: Scheduling FlushDeltaMemStoresOp(3bb20398982942c09171cef44e6ce18a): perf score=18.063937
I20260812 06:19:40.115171 23710 maintenance_manager.cc:643] P 28f091be01f840278e06d55a309877b9: FlushDeltaMemStoresOp(3bb20398982942c09171cef44e6ce18a) complete. Timing: real 0.057s	user 0.021s	sys 0.033s Metrics: {"bytes_written":20512316,"delete_count":0,"lbm_write_time_us":26237,"lbm_writes_lt_1ms":503,"reinsert_count":0,"update_count":2500}
I20260812 06:19:40.115636 23775 maintenance_manager.cc:419] P 28f091be01f840278e06d55a309877b9: Scheduling FlushDeltaMemStoresOp(3bb20398982942c09171cef44e6ce18a): perf score=2.188937
I20260812 06:19:40.127562 23710 maintenance_manager.cc:643] P 28f091be01f840278e06d55a309877b9: FlushDeltaMemStoresOp(3bb20398982942c09171cef44e6ce18a) complete. Timing: real 0.012s	user 0.002s	sys 0.007s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4169,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:40.128499 23775 maintenance_manager.cc:419] P 28f091be01f840278e06d55a309877b9: Scheduling MajorDeltaCompactionOp(3bb20398982942c09171cef44e6ce18a): perf score=1.000000
I20260812 06:19:40.317847 23710 maintenance_manager.cc:643] P 28f091be01f840278e06d55a309877b9: MajorDeltaCompactionOp(3bb20398982942c09171cef44e6ce18a) complete. Timing: real 0.189s	user 0.112s	sys 0.077s Metrics: {"cfile_cache_miss":632,"cfile_cache_miss_bytes":28877103,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":793,"lbm_read_time_us":15150,"lbm_reads_lt_1ms":672,"lbm_write_time_us":31582,"lbm_writes_lt_1ms":643,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":768,"update_count":3000}
I20260812 06:19:40.326292 23775 maintenance_manager.cc:419] P 28f091be01f840278e06d55a309877b9: Scheduling FlushDeltaMemStoresOp(3bb20398982942c09171cef44e6ce18a): perf score=14.095187
I20260812 06:19:40.390812 23710 maintenance_manager.cc:643] P 28f091be01f840278e06d55a309877b9: FlushDeltaMemStoresOp(3bb20398982942c09171cef44e6ce18a) complete. Timing: real 0.064s	user 0.034s	sys 0.028s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":29757,"lbm_writes_1-10_ms":3,"lbm_writes_lt_1ms":400,"reinsert_count":0,"update_count":2000}
I20260812 06:19:40.391685 23775 maintenance_manager.cc:419] P 28f091be01f840278e06d55a309877b9: Scheduling FlushDeltaMemStoresOp(3bb20398982942c09171cef44e6ce18a): perf score=2.188937
I20260812 06:19:40.407894 23710 maintenance_manager.cc:643] P 28f091be01f840278e06d55a309877b9: FlushDeltaMemStoresOp(3bb20398982942c09171cef44e6ce18a) complete. Timing: real 0.016s	user 0.014s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6041,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:40.408375 23775 maintenance_manager.cc:419] P 28f091be01f840278e06d55a309877b9: Scheduling MajorDeltaCompactionOp(3bb20398982942c09171cef44e6ce18a): perf score=1.000000
I20260812 06:19:40.573336 23710 maintenance_manager.cc:643] P 28f091be01f840278e06d55a309877b9: MajorDeltaCompactionOp(3bb20398982942c09171cef44e6ce18a) complete. Timing: real 0.165s	user 0.145s	sys 0.020s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774688,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":50,"lbm_read_time_us":12175,"lbm_reads_lt_1ms":564,"lbm_write_time_us":26740,"lbm_writes_lt_1ms":543,"mutex_wait_us":22,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":12032,"update_count":2500}
I20260812 06:19:40.574044 23775 maintenance_manager.cc:419] P 28f091be01f840278e06d55a309877b9: Scheduling FlushDeltaMemStoresOp(3bb20398982942c09171cef44e6ce18a): perf score=14.095187
I20260812 06:19:40.634781 23710 maintenance_manager.cc:643] P 28f091be01f840278e06d55a309877b9: FlushDeltaMemStoresOp(3bb20398982942c09171cef44e6ce18a) complete. Timing: real 0.061s	user 0.027s	sys 0.031s Metrics: {"bytes_written":16409906,"delete_count":0,"lbm_write_time_us":22184,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:40.635449 23775 maintenance_manager.cc:419] P 28f091be01f840278e06d55a309877b9: Scheduling FlushDeltaMemStoresOp(3bb20398982942c09171cef44e6ce18a): perf score=2.188937
I20260812 06:19:40.651147 23710 maintenance_manager.cc:643] P 28f091be01f840278e06d55a309877b9: FlushDeltaMemStoresOp(3bb20398982942c09171cef44e6ce18a) complete. Timing: real 0.016s	user 0.013s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5663,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:40.651803 23775 maintenance_manager.cc:419] P 28f091be01f840278e06d55a309877b9: Scheduling MajorDeltaCompactionOp(3bb20398982942c09171cef44e6ce18a): perf score=1.000000
I20260812 06:19:40.816543 23710 maintenance_manager.cc:643] P 28f091be01f840278e06d55a309877b9: MajorDeltaCompactionOp(3bb20398982942c09171cef44e6ce18a) complete. Timing: real 0.165s	user 0.115s	sys 0.049s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774693,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":1339,"lbm_read_time_us":10655,"lbm_reads_lt_1ms":564,"lbm_write_time_us":27871,"lbm_writes_lt_1ms":543,"mutex_wait_us":421,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":1664,"update_count":2500}
I20260812 06:19:40.817022 23775 maintenance_manager.cc:419] P 28f091be01f840278e06d55a309877b9: Scheduling FlushDeltaMemStoresOp(3bb20398982942c09171cef44e6ce18a): perf score=14.095187
I20260812 06:19:40.879860 23710 maintenance_manager.cc:643] P 28f091be01f840278e06d55a309877b9: FlushDeltaMemStoresOp(3bb20398982942c09171cef44e6ce18a) complete. Timing: real 0.063s	user 0.030s	sys 0.029s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":24240,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:40.880450 23775 maintenance_manager.cc:419] P 28f091be01f840278e06d55a309877b9: Scheduling FlushDeltaMemStoresOp(3bb20398982942c09171cef44e6ce18a): perf score=2.188937
I20260812 06:19:40.890930 23710 maintenance_manager.cc:643] P 28f091be01f840278e06d55a309877b9: FlushDeltaMemStoresOp(3bb20398982942c09171cef44e6ce18a) complete. Timing: real 0.010s	user 0.004s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4130,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:40.891440 23775 maintenance_manager.cc:419] P 28f091be01f840278e06d55a309877b9: Scheduling MajorDeltaCompactionOp(3bb20398982942c09171cef44e6ce18a): perf score=1.000000
I20260812 06:19:41.061911 23710 maintenance_manager.cc:643] P 28f091be01f840278e06d55a309877b9: MajorDeltaCompactionOp(3bb20398982942c09171cef44e6ce18a) complete. Timing: real 0.170s	user 0.096s	sys 0.072s 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":220,"lbm_read_time_us":12941,"lbm_reads_lt_1ms":572,"lbm_write_time_us":28607,"lbm_writes_lt_1ms":543,"mutex_wait_us":42,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":52736,"update_count":2500}
I20260812 06:19:41.062538 23775 maintenance_manager.cc:419] P 28f091be01f840278e06d55a309877b9: Scheduling FlushDeltaMemStoresOp(3bb20398982942c09171cef44e6ce18a): perf score=11.118625
I20260812 06:19:41.099857 23710 maintenance_manager.cc:643] P 28f091be01f840278e06d55a309877b9: FlushDeltaMemStoresOp(3bb20398982942c09171cef44e6ce18a) complete. Timing: real 0.037s	user 0.021s	sys 0.012s Metrics: {"bytes_written":12717735,"delete_count":0,"lbm_write_time_us":15534,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:19:41.100805 23775 maintenance_manager.cc:419] P 28f091be01f840278e06d55a309877b9: Scheduling FlushDeltaMemStoresOp(3bb20398982942c09171cef44e6ce18a): perf score=2.188937
I20260812 06:19:41.117897 23710 maintenance_manager.cc:643] P 28f091be01f840278e06d55a309877b9: FlushDeltaMemStoresOp(3bb20398982942c09171cef44e6ce18a) complete. Timing: real 0.017s	user 0.011s	sys 0.004s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":5913,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:19:41.118541 23775 maintenance_manager.cc:419] P 28f091be01f840278e06d55a309877b9: Scheduling MajorDeltaCompactionOp(3bb20398982942c09171cef44e6ce18a): perf score=1.000000
I20260812 06:19:41.253876 23710 maintenance_manager.cc:643] P 28f091be01f840278e06d55a309877b9: MajorDeltaCompactionOp(3bb20398982942c09171cef44e6ce18a) complete. Timing: real 0.135s	user 0.104s	sys 0.028s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672268,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":480,"dirs.run_cpu_time_us":531,"dirs.run_wall_time_us":2693,"lbm_read_time_us":7367,"lbm_reads_lt_1ms":464,"lbm_write_time_us":26359,"lbm_writes_lt_1ms":443,"mutex_wait_us":19,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":8064,"update_count":2000}
I20260812 06:19:41.256771 23775 maintenance_manager.cc:419] P 28f091be01f840278e06d55a309877b9: Scheduling FlushDeltaMemStoresOp(3bb20398982942c09171cef44e6ce18a): perf score=10.126437
I20260812 06:19:41.289619 23710 maintenance_manager.cc:643] P 28f091be01f840278e06d55a309877b9: FlushDeltaMemStoresOp(3bb20398982942c09171cef44e6ce18a) complete. Timing: real 0.033s	user 0.023s	sys 0.008s Metrics: {"bytes_written":12307491,"delete_count":0,"lbm_write_time_us":14108,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:19:41.290119 23775 maintenance_manager.cc:419] P 28f091be01f840278e06d55a309877b9: Scheduling FlushDeltaMemStoresOp(3bb20398982942c09171cef44e6ce18a): perf score=2.188937
I20260812 06:19:41.307776 23710 maintenance_manager.cc:643] P 28f091be01f840278e06d55a309877b9: FlushDeltaMemStoresOp(3bb20398982942c09171cef44e6ce18a) complete. Timing: real 0.017s	user 0.011s	sys 0.003s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":6397,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:41.308454 23775 maintenance_manager.cc:419] P 28f091be01f840278e06d55a309877b9: Scheduling FlushMRSOp(3bb20398982942c09171cef44e6ce18a): perf score=1.000000
I20260812 06:19:41.335875 23710 maintenance_manager.cc:643] P 28f091be01f840278e06d55a309877b9: FlushMRSOp(3bb20398982942c09171cef44e6ce18a) complete. Timing: real 0.027s	user 0.021s	sys 0.004s Metrics: {"bytes_written":1275447,"cfile_init":1,"dirs.queue_time_us":68,"dirs.run_cpu_time_us":304,"dirs.run_wall_time_us":1445,"drs_written":1,"lbm_read_time_us":56,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1949,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":31}
I20260812 06:19:41.336628 23775 maintenance_manager.cc:419] P 28f091be01f840278e06d55a309877b9: Scheduling LogGCOp(3bb20398982942c09171cef44e6ce18a): free 129320774 bytes of WAL
I20260812 06:19:41.336930 23710 log_reader.cc:385] T 3bb20398982942c09171cef44e6ce18a: removed 13 log segments from log reader
I20260812 06:19:41.336993 23710 log.cc:1079] T 3bb20398982942c09171cef44e6ce18a P 28f091be01f840278e06d55a309877b9: Deleting log segment in path: /tmp/dist-test-task0b99mg/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515576443844-23593-0/minicluster-data/ts-0-root/wals/3bb20398982942c09171cef44e6ce18a/wal-000000027 (ops 129-133)
I20260812 06:19:41.337037 23710 log.cc:1079] T 3bb20398982942c09171cef44e6ce18a P 28f091be01f840278e06d55a309877b9: Deleting log segment in path: /tmp/dist-test-task0b99mg/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515576443844-23593-0/minicluster-data/ts-0-root/wals/3bb20398982942c09171cef44e6ce18a/wal-000000028 (ops 134-138)
I20260812 06:19:41.337075 23710 log.cc:1079] T 3bb20398982942c09171cef44e6ce18a P 28f091be01f840278e06d55a309877b9: Deleting log segment in path: /tmp/dist-test-task0b99mg/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515576443844-23593-0/minicluster-data/ts-0-root/wals/3bb20398982942c09171cef44e6ce18a/wal-000000029 (ops 139-143)
I20260812 06:19:41.337098 23710 log.cc:1079] T 3bb20398982942c09171cef44e6ce18a P 28f091be01f840278e06d55a309877b9: Deleting log segment in path: /tmp/dist-test-task0b99mg/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515576443844-23593-0/minicluster-data/ts-0-root/wals/3bb20398982942c09171cef44e6ce18a/wal-000000030 (ops 144-148)
I20260812 06:19:41.337136 23710 log.cc:1079] T 3bb20398982942c09171cef44e6ce18a P 28f091be01f840278e06d55a309877b9: Deleting log segment in path: /tmp/dist-test-task0b99mg/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515576443844-23593-0/minicluster-data/ts-0-root/wals/3bb20398982942c09171cef44e6ce18a/wal-000000031 (ops 149-153)
I20260812 06:19:41.337158 23710 log.cc:1079] T 3bb20398982942c09171cef44e6ce18a P 28f091be01f840278e06d55a309877b9: Deleting log segment in path: /tmp/dist-test-task0b99mg/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515576443844-23593-0/minicluster-data/ts-0-root/wals/3bb20398982942c09171cef44e6ce18a/wal-000000032 (ops 154-158)
I20260812 06:19:41.337190 23710 log.cc:1079] T 3bb20398982942c09171cef44e6ce18a P 28f091be01f840278e06d55a309877b9: Deleting log segment in path: /tmp/dist-test-task0b99mg/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515576443844-23593-0/minicluster-data/ts-0-root/wals/3bb20398982942c09171cef44e6ce18a/wal-000000033 (ops 159-162)
I20260812 06:19:41.337224 23710 log.cc:1079] T 3bb20398982942c09171cef44e6ce18a P 28f091be01f840278e06d55a309877b9: Deleting log segment in path: /tmp/dist-test-task0b99mg/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515576443844-23593-0/minicluster-data/ts-0-root/wals/3bb20398982942c09171cef44e6ce18a/wal-000000034 (ops 163-167)
I20260812 06:19:41.337255 23710 log.cc:1079] T 3bb20398982942c09171cef44e6ce18a P 28f091be01f840278e06d55a309877b9: Deleting log segment in path: /tmp/dist-test-task0b99mg/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515576443844-23593-0/minicluster-data/ts-0-root/wals/3bb20398982942c09171cef44e6ce18a/wal-000000035 (ops 168-172)
I20260812 06:19:41.337281 23710 log.cc:1079] T 3bb20398982942c09171cef44e6ce18a P 28f091be01f840278e06d55a309877b9: Deleting log segment in path: /tmp/dist-test-task0b99mg/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515576443844-23593-0/minicluster-data/ts-0-root/wals/3bb20398982942c09171cef44e6ce18a/wal-000000036 (ops 173-177)
I20260812 06:19:41.337306 23710 log.cc:1079] T 3bb20398982942c09171cef44e6ce18a P 28f091be01f840278e06d55a309877b9: Deleting log segment in path: /tmp/dist-test-task0b99mg/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515576443844-23593-0/minicluster-data/ts-0-root/wals/3bb20398982942c09171cef44e6ce18a/wal-000000037 (ops 178-182)
I20260812 06:19:41.337337 23710 log.cc:1079] T 3bb20398982942c09171cef44e6ce18a P 28f091be01f840278e06d55a309877b9: Deleting log segment in path: /tmp/dist-test-task0b99mg/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515576443844-23593-0/minicluster-data/ts-0-root/wals/3bb20398982942c09171cef44e6ce18a/wal-000000038 (ops 183-186)
I20260812 06:19:41.337370 23710 log.cc:1079] T 3bb20398982942c09171cef44e6ce18a P 28f091be01f840278e06d55a309877b9: Deleting log segment in path: /tmp/dist-test-task0b99mg/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515576443844-23593-0/minicluster-data/ts-0-root/wals/3bb20398982942c09171cef44e6ce18a/wal-000000039 (ops 187-191)
I20260812 06:19:41.368376 23710 maintenance_manager.cc:643] P 28f091be01f840278e06d55a309877b9: LogGCOp(3bb20398982942c09171cef44e6ce18a) complete. Timing: real 0.032s	user 0.000s	sys 0.031s Metrics: {}
I20260812 06:19:41.368796 23775 maintenance_manager.cc:419] P 28f091be01f840278e06d55a309877b9: Scheduling UndoDeltaBlockGCOp(3bb20398982942c09171cef44e6ce18a): 481 bytes on disk
I20260812 06:19:41.369434 23710 maintenance_manager.cc:643] P 28f091be01f840278e06d55a309877b9: UndoDeltaBlockGCOp(3bb20398982942c09171cef44e6ce18a) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":53,"lbm_reads_lt_1ms":4}
I20260812 06:19:41.369992 23775 maintenance_manager.cc:419] P 28f091be01f840278e06d55a309877b9: Scheduling FlushDeltaMemStoresOp(3bb20398982942c09171cef44e6ce18a): perf score=3.181125
I20260812 06:19:41.382856 23710 maintenance_manager.cc:643] P 28f091be01f840278e06d55a309877b9: FlushDeltaMemStoresOp(3bb20398982942c09171cef44e6ce18a) complete. Timing: real 0.013s	user 0.003s	sys 0.008s Metrics: {"bytes_written":4512900,"delete_count":0,"lbm_write_time_us":4865,"lbm_writes_lt_1ms":113,"reinsert_count":0,"update_count":550}
I20260812 06:19:41.383325 23775 maintenance_manager.cc:419] P 28f091be01f840278e06d55a309877b9: Scheduling FlushDeltaMemStoresOp(3bb20398982942c09171cef44e6ce18a): perf score=2.188937
I20260812 06:19:41.393033 23710 maintenance_manager.cc:643] P 28f091be01f840278e06d55a309877b9: FlushDeltaMemStoresOp(3bb20398982942c09171cef44e6ce18a) complete. Timing: real 0.010s	user 0.000s	sys 0.009s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3726,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:19:41.393541 23775 maintenance_manager.cc:419] P 28f091be01f840278e06d55a309877b9: Scheduling MajorDeltaCompactionOp(3bb20398982942c09171cef44e6ce18a): perf score=1.000000
I20260812 06:19:41.521098 23593 heavy-update-compaction-itest.cc:229] Time spent updating: real 4.792s	user 1.818s	sys 0.120s
I20260812 06:19:41.559845 23710 maintenance_manager.cc:643] P 28f091be01f840278e06d55a309877b9: MajorDeltaCompactionOp(3bb20398982942c09171cef44e6ce18a) complete. Timing: real 0.166s	user 0.135s	sys 0.029s Metrics: {"cfile_cache_miss":634,"cfile_cache_miss_bytes":28877326,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"lbm_read_time_us":12988,"lbm_reads_lt_1ms":670,"lbm_write_time_us":31859,"lbm_writes_lt_1ms":643,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":3328,"update_count":3000}
I20260812 06:19:41.560379 23775 maintenance_manager.cc:419] P 28f091be01f840278e06d55a309877b9: Scheduling FlushDeltaMemStoresOp(3bb20398982942c09171cef44e6ce18a): perf score=10.126437
I20260812 06:19:41.590659 23710 maintenance_manager.cc:643] P 28f091be01f840278e06d55a309877b9: FlushDeltaMemStoresOp(3bb20398982942c09171cef44e6ce18a) complete. Timing: real 0.030s	user 0.022s	sys 0.006s Metrics: {"bytes_written":12307491,"delete_count":0,"lbm_write_time_us":13094,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:19:41.591218 23775 maintenance_manager.cc:419] P 28f091be01f840278e06d55a309877b9: Scheduling MajorDeltaCompactionOp(3bb20398982942c09171cef44e6ce18a): perf score=1.000000
I20260812 06:19:41.595381 23593 heavy-update-compaction-itest.cc:265] Time spent scanning: real 0.074s	user 0.001s	sys 0.000s
I20260812 06:19:41.596019 23593 tablet_server.cc:179] TabletServer@127.23.10.65:0 shutting down...
I20260812 06:19:41.697773 23710 maintenance_manager.cc:643] P 28f091be01f840278e06d55a309877b9: MajorDeltaCompactionOp(3bb20398982942c09171cef44e6ce18a) complete. Timing: real 0.106s	user 0.065s	sys 0.039s Metrics: {"cfile_cache_miss":331,"cfile_cache_miss_bytes":16569747,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":1,"delta_iterators_relevant":1,"dirs.queue_time_us":387,"lbm_read_time_us":8244,"lbm_reads_lt_1ms":367,"lbm_write_time_us":20952,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":342,"mutex_wait_us":35,"peak_mem_usage":38262756,"reinsert_count":0,"spinlock_wait_cycles":24320,"update_count":1500}
I20260812 06:19:41.698647 23593 ts_tablet_manager.cc:1507] Shutting down tablet manager...
I20260812 06:19:41.699105 23593 tablet_replica.cc:333] T 3bb20398982942c09171cef44e6ce18a P 28f091be01f840278e06d55a309877b9: stopping tablet replica
I20260812 06:19:41.699400 23593 raft_consensus.cc:2243] T 3bb20398982942c09171cef44e6ce18a P 28f091be01f840278e06d55a309877b9 [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:19:41.699680 23593 raft_consensus.cc:2272] T 3bb20398982942c09171cef44e6ce18a P 28f091be01f840278e06d55a309877b9 [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:19:41.716204 23593 tablet_server.cc:196] TabletServer@127.23.10.65:0 shutdown complete.
I20260812 06:19:41.730406 23593 master.cc:562] Master@127.23.10.126:38959 shutting down...
I20260812 06:19:41.734388 23593 raft_consensus.cc:2243] T 00000000000000000000000000000000 P 5d87a422b01844bcb72d70b52397fdeb [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:19:41.734583 23593 raft_consensus.cc:2272] T 00000000000000000000000000000000 P 5d87a422b01844bcb72d70b52397fdeb [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:19:41.734687 23593 tablet_replica.cc:333] T 00000000000000000000000000000000 P 5d87a422b01844bcb72d70b52397fdeb: stopping tablet replica
I20260812 06:19:41.746944 23593 master.cc:584] Master@127.23.10.126:38959 shutdown complete.
[       OK ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/0 (5385 ms)
[ RUN      ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/1
I20260812 06:19:41.839417 23593 internal_mini_cluster.cc:156] Creating distributed mini masters. Addrs: 127.23.10.126:43247
I20260812 06:19:41.839859 23593 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:19:41.842576 23811 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:41.842638 23813 instance_detector.cc:116] could not retrieve OpenStack instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:19:41.842702 23810 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:41.842641 23593 server_base.cc:1061] running on GCE node
I20260812 06:19:41.843011 23593 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:19:41.843053 23593 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:41.843068 23593 hybrid_clock.cc:648] HybridClock initialized: now 1786515581843068 us; error 0 us; skew 500 ppm
I20260812 06:19:41.844069 23593 webserver.cc:533] Webserver started at http://127.23.10.126:36359/ using document root <none> and password file <none>
I20260812 06:19:41.844290 23593 fs_manager.cc:362] Metadata directory not provided
I20260812 06:19:41.844342 23593 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:19:41.844444 23593 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:19:41.844854 23593 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-task0b99mg/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515576443844-23593-0/minicluster-data/master-0-root/instance:
uuid: "0779d6bce548478ea4fff8ccf07774ae"
format_stamp: "Formatted at 2026-08-12 06:19:41 on dist-test-slave-cbbz"
I20260812 06:19:41.846341 23593 fs_manager.cc:696] Time spent creating directory manager: real 0.001s	user 0.002s	sys 0.000s
I20260812 06:19:41.847285 23818 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:41.847546 23593 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.001s	sys 0.000s
I20260812 06:19:41.847611 23593 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-task0b99mg/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515576443844-23593-0/minicluster-data/master-0-root
uuid: "0779d6bce548478ea4fff8ccf07774ae"
format_stamp: "Formatted at 2026-08-12 06:19:41 on dist-test-slave-cbbz"
I20260812 06:19:41.847669 23593 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-task0b99mg/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515576443844-23593-0/minicluster-data/master-0-root
metadata directory: /tmp/dist-test-task0b99mg/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515576443844-23593-0/minicluster-data/master-0-root
1 data directories: /tmp/dist-test-task0b99mg/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515576443844-23593-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:41.861624 23593 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:19:41.861946 23593 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:19:41.865934 23593 rpc_server.cc:307] RPC server started. Bound to: 127.23.10.126:43247
I20260812 06:19:41.870901 23879 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.23.10.126:43247 every 8 connection(s)
I20260812 06:19:41.876423 23880 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:41.878301 23880 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P 0779d6bce548478ea4fff8ccf07774ae: Bootstrap starting.
I20260812 06:19:41.879084 23880 tablet_bootstrap.cc:654] T 00000000000000000000000000000000 P 0779d6bce548478ea4fff8ccf07774ae: Neither blocks nor log segments found. Creating new log.
I20260812 06:19:41.880129 23880 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P 0779d6bce548478ea4fff8ccf07774ae: No bootstrap required, opened a new log
I20260812 06:19:41.880578 23880 raft_consensus.cc:359] T 00000000000000000000000000000000 P 0779d6bce548478ea4fff8ccf07774ae [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "0779d6bce548478ea4fff8ccf07774ae" member_type: VOTER }
I20260812 06:19:41.880689 23880 raft_consensus.cc:385] T 00000000000000000000000000000000 P 0779d6bce548478ea4fff8ccf07774ae [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:19:41.880757 23880 raft_consensus.cc:740] T 00000000000000000000000000000000 P 0779d6bce548478ea4fff8ccf07774ae [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: 0779d6bce548478ea4fff8ccf07774ae, State: Initialized, Role: FOLLOWER
I20260812 06:19:41.880923 23880 consensus_queue.cc:260] T 00000000000000000000000000000000 P 0779d6bce548478ea4fff8ccf07774ae [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: "0779d6bce548478ea4fff8ccf07774ae" member_type: VOTER }
I20260812 06:19:41.881018 23880 raft_consensus.cc:399] T 00000000000000000000000000000000 P 0779d6bce548478ea4fff8ccf07774ae [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:19:41.881063 23880 raft_consensus.cc:493] T 00000000000000000000000000000000 P 0779d6bce548478ea4fff8ccf07774ae [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:19:41.881130 23880 raft_consensus.cc:3060] T 00000000000000000000000000000000 P 0779d6bce548478ea4fff8ccf07774ae [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:19:41.881819 23880 raft_consensus.cc:515] T 00000000000000000000000000000000 P 0779d6bce548478ea4fff8ccf07774ae [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "0779d6bce548478ea4fff8ccf07774ae" member_type: VOTER }
I20260812 06:19:41.881978 23880 leader_election.cc:304] T 00000000000000000000000000000000 P 0779d6bce548478ea4fff8ccf07774ae [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: 0779d6bce548478ea4fff8ccf07774ae; no voters: 
I20260812 06:19:41.882207 23880 leader_election.cc:290] T 00000000000000000000000000000000 P 0779d6bce548478ea4fff8ccf07774ae [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:19:41.882341 23883 raft_consensus.cc:2804] T 00000000000000000000000000000000 P 0779d6bce548478ea4fff8ccf07774ae [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:19:41.882573 23883 raft_consensus.cc:697] T 00000000000000000000000000000000 P 0779d6bce548478ea4fff8ccf07774ae [term 1 LEADER]: Becoming Leader. State: Replica: 0779d6bce548478ea4fff8ccf07774ae, State: Running, Role: LEADER
I20260812 06:19:41.882689 23880 sys_catalog.cc:565] T 00000000000000000000000000000000 P 0779d6bce548478ea4fff8ccf07774ae [sys.catalog]: configured and running, proceeding with master startup.
I20260812 06:19:41.882714 23883 consensus_queue.cc:237] T 00000000000000000000000000000000 P 0779d6bce548478ea4fff8ccf07774ae [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: "0779d6bce548478ea4fff8ccf07774ae" member_type: VOTER }
I20260812 06:19:41.883169 23884 sys_catalog.cc:455] T 00000000000000000000000000000000 P 0779d6bce548478ea4fff8ccf07774ae [sys.catalog]: SysCatalogTable state changed. Reason: RaftConsensus started. Latest consensus state: current_term: 1 leader_uuid: "0779d6bce548478ea4fff8ccf07774ae" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "0779d6bce548478ea4fff8ccf07774ae" member_type: VOTER } }
I20260812 06:19:41.883224 23885 sys_catalog.cc:455] T 00000000000000000000000000000000 P 0779d6bce548478ea4fff8ccf07774ae [sys.catalog]: SysCatalogTable state changed. Reason: New leader 0779d6bce548478ea4fff8ccf07774ae. Latest consensus state: current_term: 1 leader_uuid: "0779d6bce548478ea4fff8ccf07774ae" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "0779d6bce548478ea4fff8ccf07774ae" member_type: VOTER } }
I20260812 06:19:41.883353 23885 sys_catalog.cc:458] T 00000000000000000000000000000000 P 0779d6bce548478ea4fff8ccf07774ae [sys.catalog]: This master's current role is: LEADER
I20260812 06:19:41.883335 23884 sys_catalog.cc:458] T 00000000000000000000000000000000 P 0779d6bce548478ea4fff8ccf07774ae [sys.catalog]: This master's current role is: LEADER
I20260812 06:19:41.883837 23890 catalog_manager.cc:1511] Loading table and tablet metadata into memory...
I20260812 06:19:41.884827 23890 catalog_manager.cc:1520] Initializing Kudu cluster ID...
I20260812 06:19:41.885094 23593 internal_mini_cluster.cc:184] Waiting to initialize catalog manager on master 0
I20260812 06:19:41.886868 23890 catalog_manager.cc:1383] Generated new cluster ID: b6335799f543409894e6467016f5dbf9
I20260812 06:19:41.886927 23890 catalog_manager.cc:1531] Initializing Kudu internal certificate authority...
I20260812 06:19:41.914354 23890 catalog_manager.cc:1406] Generated new certificate authority record
I20260812 06:19:41.914964 23890 catalog_manager.cc:1540] Loading token signing keys...
I20260812 06:19:41.920414 23890 catalog_manager.cc:6092] T 00000000000000000000000000000000 P 0779d6bce548478ea4fff8ccf07774ae: Generated new TSK 0
I20260812 06:19:41.920625 23890 catalog_manager.cc:1550] Initializing in-progress tserver states...
I20260812 06:19:41.949721 23593 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:19:41.951853 23904 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:41.951901 23903 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:41.951911 23593 server_base.cc:1061] running on GCE node
W20260812 06:19:41.951944 23906 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:41.952327 23593 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:19:41.952375 23593 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:41.952391 23593 hybrid_clock.cc:648] HybridClock initialized: now 1786515581952391 us; error 0 us; skew 500 ppm
I20260812 06:19:41.953231 23593 webserver.cc:533] Webserver started at http://127.23.10.65:45719/ using document root <none> and password file <none>
I20260812 06:19:41.953369 23593 fs_manager.cc:362] Metadata directory not provided
I20260812 06:19:41.953415 23593 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:19:41.953469 23593 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:19:41.953815 23593 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-task0b99mg/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515576443844-23593-0/minicluster-data/ts-0-root/instance:
uuid: "b1a993cb1bce4192ab0c2f9b4f5b7840"
format_stamp: "Formatted at 2026-08-12 06:19:41 on dist-test-slave-cbbz"
I20260812 06:19:41.955390 23593 fs_manager.cc:696] Time spent creating directory manager: real 0.001s	user 0.002s	sys 0.000s
I20260812 06:19:41.956471 23912 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:41.956764 23593 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.001s	sys 0.000s
I20260812 06:19:41.956831 23593 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-task0b99mg/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515576443844-23593-0/minicluster-data/ts-0-root
uuid: "b1a993cb1bce4192ab0c2f9b4f5b7840"
format_stamp: "Formatted at 2026-08-12 06:19:41 on dist-test-slave-cbbz"
I20260812 06:19:41.956918 23593 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-task0b99mg/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515576443844-23593-0/minicluster-data/ts-0-root
metadata directory: /tmp/dist-test-task0b99mg/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515576443844-23593-0/minicluster-data/ts-0-root
1 data directories: /tmp/dist-test-task0b99mg/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515576443844-23593-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:41.965646 23593 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:19:41.965966 23593 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:19:41.966269 23593 txn_system_client.cc:432] TxnSystemClient initialization is disabled...
I20260812 06:19:41.966711 23593 ts_tablet_manager.cc:585] Loaded tablet metadata (0 total tablets, 0 live tablets)
I20260812 06:19:41.966774 23593 ts_tablet_manager.cc:531] Time spent load tablet metadata: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:19:41.966830 23593 ts_tablet_manager.cc:616] Registered 0 tablets
I20260812 06:19:41.966879 23593 ts_tablet_manager.cc:595] Time spent register tablets: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:19:41.971221 23593 rpc_server.cc:307] RPC server started. Bound to: 127.23.10.65:33857
I20260812 06:19:41.972239 23988 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.23.10.65:33857 every 8 connection(s)
I20260812 06:19:41.980721 23989 heartbeater.cc:344] Connected to a master server at 127.23.10.126:43247
I20260812 06:19:41.980875 23989 heartbeater.cc:461] Registering TS with master...
I20260812 06:19:41.981148 23989 heartbeater.cc:507] Master 127.23.10.126:43247 requested a full tablet report, sending...
I20260812 06:19:41.981864 23838 ts_manager.cc:194] Registered new tserver with Master: b1a993cb1bce4192ab0c2f9b4f5b7840 (127.23.10.65:33857)
I20260812 06:19:41.982189 23593 internal_mini_cluster.cc:371] 1 TS(s) registered with all masters after 0.009970533s
I20260812 06:19:41.982666 23838 master_service.cc:502] Signed X509 certificate for tserver {username='slave'} at 127.0.0.1:52536
I20260812 06:19:41.989646 23838 catalog_manager.cc:2283] Servicing CreateTable request from {username='slave'} at 127.0.0.1:52552:
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:41.998095 23946 tablet_service.cc:1511] Processing CreateTablet for tablet 4e8e58b6d16b44269757ac267001cc5f (DEFAULT_TABLE table=heavy-update-compaction-test [id=bf547ef806a24f10bab49dc216aa7793]), partition=
I20260812 06:19:41.998314 23946 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet 4e8e58b6d16b44269757ac267001cc5f. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:19:42.000088 24003 tablet_bootstrap.cc:492] T 4e8e58b6d16b44269757ac267001cc5f P b1a993cb1bce4192ab0c2f9b4f5b7840: Bootstrap starting.
I20260812 06:19:42.001114 24003 tablet_bootstrap.cc:654] T 4e8e58b6d16b44269757ac267001cc5f P b1a993cb1bce4192ab0c2f9b4f5b7840: Neither blocks nor log segments found. Creating new log.
I20260812 06:19:42.002079 24003 tablet_bootstrap.cc:492] T 4e8e58b6d16b44269757ac267001cc5f P b1a993cb1bce4192ab0c2f9b4f5b7840: No bootstrap required, opened a new log
I20260812 06:19:42.002169 24003 ts_tablet_manager.cc:1403] T 4e8e58b6d16b44269757ac267001cc5f P b1a993cb1bce4192ab0c2f9b4f5b7840: Time spent bootstrapping tablet: real 0.002s	user 0.001s	sys 0.000s
I20260812 06:19:42.002499 24003 raft_consensus.cc:359] T 4e8e58b6d16b44269757ac267001cc5f P b1a993cb1bce4192ab0c2f9b4f5b7840 [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "b1a993cb1bce4192ab0c2f9b4f5b7840" member_type: VOTER last_known_addr { host: "127.23.10.65" port: 33857 } }
I20260812 06:19:42.002579 24003 raft_consensus.cc:385] T 4e8e58b6d16b44269757ac267001cc5f P b1a993cb1bce4192ab0c2f9b4f5b7840 [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:19:42.002604 24003 raft_consensus.cc:740] T 4e8e58b6d16b44269757ac267001cc5f P b1a993cb1bce4192ab0c2f9b4f5b7840 [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: b1a993cb1bce4192ab0c2f9b4f5b7840, State: Initialized, Role: FOLLOWER
I20260812 06:19:42.002709 24003 consensus_queue.cc:260] T 4e8e58b6d16b44269757ac267001cc5f P b1a993cb1bce4192ab0c2f9b4f5b7840 [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: "b1a993cb1bce4192ab0c2f9b4f5b7840" member_type: VOTER last_known_addr { host: "127.23.10.65" port: 33857 } }
I20260812 06:19:42.002769 24003 raft_consensus.cc:399] T 4e8e58b6d16b44269757ac267001cc5f P b1a993cb1bce4192ab0c2f9b4f5b7840 [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:19:42.002792 24003 raft_consensus.cc:493] T 4e8e58b6d16b44269757ac267001cc5f P b1a993cb1bce4192ab0c2f9b4f5b7840 [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:19:42.002830 24003 raft_consensus.cc:3060] T 4e8e58b6d16b44269757ac267001cc5f P b1a993cb1bce4192ab0c2f9b4f5b7840 [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:19:42.003547 24003 raft_consensus.cc:515] T 4e8e58b6d16b44269757ac267001cc5f P b1a993cb1bce4192ab0c2f9b4f5b7840 [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "b1a993cb1bce4192ab0c2f9b4f5b7840" member_type: VOTER last_known_addr { host: "127.23.10.65" port: 33857 } }
I20260812 06:19:42.003695 24003 leader_election.cc:304] T 4e8e58b6d16b44269757ac267001cc5f P b1a993cb1bce4192ab0c2f9b4f5b7840 [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: b1a993cb1bce4192ab0c2f9b4f5b7840; no voters: 
I20260812 06:19:42.003932 24003 leader_election.cc:290] T 4e8e58b6d16b44269757ac267001cc5f P b1a993cb1bce4192ab0c2f9b4f5b7840 [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:19:42.004020 24005 raft_consensus.cc:2804] T 4e8e58b6d16b44269757ac267001cc5f P b1a993cb1bce4192ab0c2f9b4f5b7840 [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:19:42.004256 24005 raft_consensus.cc:697] T 4e8e58b6d16b44269757ac267001cc5f P b1a993cb1bce4192ab0c2f9b4f5b7840 [term 1 LEADER]: Becoming Leader. State: Replica: b1a993cb1bce4192ab0c2f9b4f5b7840, State: Running, Role: LEADER
I20260812 06:19:42.004297 24003 ts_tablet_manager.cc:1434] T 4e8e58b6d16b44269757ac267001cc5f P b1a993cb1bce4192ab0c2f9b4f5b7840: Time spent starting tablet: real 0.002s	user 0.002s	sys 0.000s
I20260812 06:19:42.004328 23989 heartbeater.cc:499] Master 127.23.10.126:43247 was elected leader, sending a full tablet report...
I20260812 06:19:42.004537 24005 consensus_queue.cc:237] T 4e8e58b6d16b44269757ac267001cc5f P b1a993cb1bce4192ab0c2f9b4f5b7840 [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: "b1a993cb1bce4192ab0c2f9b4f5b7840" member_type: VOTER last_known_addr { host: "127.23.10.65" port: 33857 } }
I20260812 06:19:42.005834 23838 catalog_manager.cc:5719] T 4e8e58b6d16b44269757ac267001cc5f P b1a993cb1bce4192ab0c2f9b4f5b7840 reported cstate change: term changed from 0 to 1, leader changed from <none> to b1a993cb1bce4192ab0c2f9b4f5b7840 (127.23.10.65). New cstate: current_term: 1 leader_uuid: "b1a993cb1bce4192ab0c2f9b4f5b7840" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "b1a993cb1bce4192ab0c2f9b4f5b7840" member_type: VOTER last_known_addr { host: "127.23.10.65" port: 33857 } health_report { overall_health: HEALTHY } } }
I20260812 06:19:42.061388 23593 heavy-update-compaction-itest.cc:215] Time spent inserting: real 0.052s	user 0.018s	sys 0.004s
I20260812 06:19:42.222666 23990 maintenance_manager.cc:419] P b1a993cb1bce4192ab0c2f9b4f5b7840: Scheduling FlushMRSOp(4e8e58b6d16b44269757ac267001cc5f): perf score=23.023690
I20260812 06:19:42.400645 23917 maintenance_manager.cc:643] P b1a993cb1bce4192ab0c2f9b4f5b7840: FlushMRSOp(4e8e58b6d16b44269757ac267001cc5f) complete. Timing: real 0.178s	user 0.137s	sys 0.039s Metrics: {"bytes_written":12307489,"cfile_init":1,"delete_count":0,"dirs.queue_time_us":57,"dirs.run_cpu_time_us":194,"dirs.run_wall_time_us":837,"drs_written":1,"lbm_read_time_us":57,"lbm_reads_lt_1ms":4,"lbm_write_time_us":48300,"lbm_writes_lt_1ms":857,"peak_mem_usage":0,"reinsert_count":0,"rows_written":105,"update_count":1500}
I20260812 06:19:42.401352 23990 maintenance_manager.cc:419] P b1a993cb1bce4192ab0c2f9b4f5b7840: Scheduling LogGCOp(4e8e58b6d16b44269757ac267001cc5f): free 20743880 bytes of WAL
I20260812 06:19:42.401597 23917 log_reader.cc:385] T 4e8e58b6d16b44269757ac267001cc5f: removed 2 log segments from log reader
I20260812 06:19:42.401641 23917 log.cc:1079] T 4e8e58b6d16b44269757ac267001cc5f P b1a993cb1bce4192ab0c2f9b4f5b7840: Deleting log segment in path: /tmp/dist-test-task0b99mg/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515576443844-23593-0/minicluster-data/ts-0-root/wals/4e8e58b6d16b44269757ac267001cc5f/wal-000000001 (ops 1-6)
I20260812 06:19:42.401670 23917 log.cc:1079] T 4e8e58b6d16b44269757ac267001cc5f P b1a993cb1bce4192ab0c2f9b4f5b7840: Deleting log segment in path: /tmp/dist-test-task0b99mg/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515576443844-23593-0/minicluster-data/ts-0-root/wals/4e8e58b6d16b44269757ac267001cc5f/wal-000000002 (ops 7-11)
I20260812 06:19:42.405889 23917 maintenance_manager.cc:643] P b1a993cb1bce4192ab0c2f9b4f5b7840: LogGCOp(4e8e58b6d16b44269757ac267001cc5f) complete. Timing: real 0.004s	user 0.000s	sys 0.003s Metrics: {}
I20260812 06:19:42.406353 23990 maintenance_manager.cc:419] P b1a993cb1bce4192ab0c2f9b4f5b7840: Scheduling FlushDeltaMemStoresOp(4e8e58b6d16b44269757ac267001cc5f): perf score=2.188937
I20260812 06:19:42.421937 23917 maintenance_manager.cc:643] P b1a993cb1bce4192ab0c2f9b4f5b7840: FlushDeltaMemStoresOp(4e8e58b6d16b44269757ac267001cc5f) complete. Timing: real 0.015s	user 0.012s	sys 0.000s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":5574,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:42.422386 23990 maintenance_manager.cc:419] P b1a993cb1bce4192ab0c2f9b4f5b7840: Scheduling MajorDeltaCompactionOp(4e8e58b6d16b44269757ac267001cc5f): perf score=1.000000
I20260812 06:19:42.577484 23917 maintenance_manager.cc:643] P b1a993cb1bce4192ab0c2f9b4f5b7840: MajorDeltaCompactionOp(4e8e58b6d16b44269757ac267001cc5f) complete. Timing: real 0.155s	user 0.096s	sys 0.052s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20713270,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":517,"lbm_read_time_us":9350,"lbm_reads_lt_1ms":464,"lbm_write_time_us":26104,"lbm_writes_lt_1ms":443,"mutex_wait_us":21,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":1408,"thread_start_us":355,"threads_started":5,"update_count":2000}
I20260812 06:19:42.578207 23990 maintenance_manager.cc:419] P b1a993cb1bce4192ab0c2f9b4f5b7840: Scheduling UndoDeltaBlockGCOp(4e8e58b6d16b44269757ac267001cc5f): 20513813 bytes on disk
I20260812 06:19:42.578765 23917 maintenance_manager.cc:643] P b1a993cb1bce4192ab0c2f9b4f5b7840: UndoDeltaBlockGCOp(4e8e58b6d16b44269757ac267001cc5f) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":108,"lbm_reads_lt_1ms":4}
I20260812 06:19:42.579279 23990 maintenance_manager.cc:419] P b1a993cb1bce4192ab0c2f9b4f5b7840: Scheduling FlushDeltaMemStoresOp(4e8e58b6d16b44269757ac267001cc5f): perf score=14.095187
I20260812 06:19:42.633180 23917 maintenance_manager.cc:643] P b1a993cb1bce4192ab0c2f9b4f5b7840: FlushDeltaMemStoresOp(4e8e58b6d16b44269757ac267001cc5f) complete. Timing: real 0.054s	user 0.038s	sys 0.008s Metrics: {"bytes_written":16409904,"delete_count":0,"lbm_write_time_us":21276,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:42.633729 23990 maintenance_manager.cc:419] P b1a993cb1bce4192ab0c2f9b4f5b7840: Scheduling MajorDeltaCompactionOp(4e8e58b6d16b44269757ac267001cc5f): perf score=1.000000
I20260812 06:19:42.787354 23917 maintenance_manager.cc:643] P b1a993cb1bce4192ab0c2f9b4f5b7840: MajorDeltaCompactionOp(4e8e58b6d16b44269757ac267001cc5f) complete. Timing: real 0.153s	user 0.109s	sys 0.040s Metrics: {"cfile_cache_miss":431,"cfile_cache_miss_bytes":20713155,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":1,"delta_iterators_relevant":1,"dirs.queue_time_us":151,"lbm_read_time_us":12957,"lbm_reads_lt_1ms":463,"lbm_write_time_us":22556,"lbm_writes_lt_1ms":443,"mutex_wait_us":29,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":1408,"update_count":2000}
I20260812 06:19:42.787931 23990 maintenance_manager.cc:419] P b1a993cb1bce4192ab0c2f9b4f5b7840: Scheduling FlushDeltaMemStoresOp(4e8e58b6d16b44269757ac267001cc5f): perf score=14.095187
I20260812 06:19:42.843371 23917 maintenance_manager.cc:643] P b1a993cb1bce4192ab0c2f9b4f5b7840: FlushDeltaMemStoresOp(4e8e58b6d16b44269757ac267001cc5f) complete. Timing: real 0.055s	user 0.036s	sys 0.016s Metrics: {"bytes_written":16409903,"delete_count":0,"lbm_write_time_us":23802,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:42.843914 23990 maintenance_manager.cc:419] P b1a993cb1bce4192ab0c2f9b4f5b7840: Scheduling FlushDeltaMemStoresOp(4e8e58b6d16b44269757ac267001cc5f): perf score=2.188937
I20260812 06:19:42.869947 23917 maintenance_manager.cc:643] P b1a993cb1bce4192ab0c2f9b4f5b7840: FlushDeltaMemStoresOp(4e8e58b6d16b44269757ac267001cc5f) complete. Timing: real 0.026s	user 0.005s	sys 0.013s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":5661,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:42.870575 23990 maintenance_manager.cc:419] P b1a993cb1bce4192ab0c2f9b4f5b7840: Scheduling MajorDeltaCompactionOp(4e8e58b6d16b44269757ac267001cc5f): perf score=1.000000
I20260812 06:19:43.050215 23917 maintenance_manager.cc:643] P b1a993cb1bce4192ab0c2f9b4f5b7840: MajorDeltaCompactionOp(4e8e58b6d16b44269757ac267001cc5f) complete. Timing: real 0.179s	user 0.123s	sys 0.056s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24815684,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":883,"lbm_read_time_us":12477,"lbm_reads_lt_1ms":564,"lbm_write_time_us":28986,"lbm_writes_lt_1ms":543,"mutex_wait_us":37,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":2304,"update_count":2500}
I20260812 06:19:43.050925 23990 maintenance_manager.cc:419] P b1a993cb1bce4192ab0c2f9b4f5b7840: Scheduling FlushDeltaMemStoresOp(4e8e58b6d16b44269757ac267001cc5f): perf score=14.095187
I20260812 06:19:43.116544 23917 maintenance_manager.cc:643] P b1a993cb1bce4192ab0c2f9b4f5b7840: FlushDeltaMemStoresOp(4e8e58b6d16b44269757ac267001cc5f) complete. Timing: real 0.065s	user 0.028s	sys 0.024s Metrics: {"bytes_written":16409900,"delete_count":0,"lbm_write_time_us":21935,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:43.116986 23990 maintenance_manager.cc:419] P b1a993cb1bce4192ab0c2f9b4f5b7840: Scheduling FlushDeltaMemStoresOp(4e8e58b6d16b44269757ac267001cc5f): perf score=6.157687
I20260812 06:19:43.150602 23917 maintenance_manager.cc:643] P b1a993cb1bce4192ab0c2f9b4f5b7840: FlushDeltaMemStoresOp(4e8e58b6d16b44269757ac267001cc5f) complete. Timing: real 0.033s	user 0.015s	sys 0.012s Metrics: {"bytes_written":8205078,"delete_count":0,"lbm_write_time_us":8886,"lbm_writes_lt_1ms":203,"reinsert_count":0,"update_count":1000}
I20260812 06:19:43.151185 23990 maintenance_manager.cc:419] P b1a993cb1bce4192ab0c2f9b4f5b7840: Scheduling FlushDeltaMemStoresOp(4e8e58b6d16b44269757ac267001cc5f): perf score=1.000000
I20260812 06:19:43.159765 23917 maintenance_manager.cc:643] P b1a993cb1bce4192ab0c2f9b4f5b7840: FlushDeltaMemStoresOp(4e8e58b6d16b44269757ac267001cc5f) complete. Timing: real 0.008s	user 0.000s	sys 0.003s Metrics: {"bytes_written":1230905,"delete_count":0,"lbm_write_time_us":1247,"lbm_writes_lt_1ms":33,"reinsert_count":0,"update_count":150}
I20260812 06:19:43.160287 23990 maintenance_manager.cc:419] P b1a993cb1bce4192ab0c2f9b4f5b7840: Scheduling FlushDeltaMemStoresOp(4e8e58b6d16b44269757ac267001cc5f): perf score=1.196750
I20260812 06:19:43.167972 23917 maintenance_manager.cc:643] P b1a993cb1bce4192ab0c2f9b4f5b7840: FlushDeltaMemStoresOp(4e8e58b6d16b44269757ac267001cc5f) complete. Timing: real 0.008s	user 0.001s	sys 0.005s Metrics: {"bytes_written":2871905,"delete_count":0,"lbm_write_time_us":2891,"lbm_writes_lt_1ms":73,"reinsert_count":0,"update_count":350}
I20260812 06:19:43.168521 23990 maintenance_manager.cc:419] P b1a993cb1bce4192ab0c2f9b4f5b7840: Scheduling MajorDeltaCompactionOp(4e8e58b6d16b44269757ac267001cc5f): perf score=1.000000
I20260812 06:19:43.409672 23917 maintenance_manager.cc:643] P b1a993cb1bce4192ab0c2f9b4f5b7840: MajorDeltaCompactionOp(4e8e58b6d16b44269757ac267001cc5f) complete. Timing: real 0.241s	user 0.142s	sys 0.088s Metrics: {"cfile_cache_miss":734,"cfile_cache_miss_bytes":33020650,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":684,"lbm_read_time_us":14543,"lbm_reads_lt_1ms":774,"lbm_write_time_us":39387,"lbm_writes_lt_1ms":743,"mutex_wait_us":50,"peak_mem_usage":87969044,"reinsert_count":0,"spinlock_wait_cycles":10624,"update_count":3500}
I20260812 06:19:43.410270 23990 maintenance_manager.cc:419] P b1a993cb1bce4192ab0c2f9b4f5b7840: Scheduling FlushDeltaMemStoresOp(4e8e58b6d16b44269757ac267001cc5f): perf score=18.063937
I20260812 06:19:43.476699 23917 maintenance_manager.cc:643] P b1a993cb1bce4192ab0c2f9b4f5b7840: FlushDeltaMemStoresOp(4e8e58b6d16b44269757ac267001cc5f) complete. Timing: real 0.066s	user 0.039s	sys 0.016s Metrics: {"bytes_written":20512315,"delete_count":0,"lbm_write_time_us":24767,"lbm_writes_lt_1ms":503,"reinsert_count":0,"update_count":2500}
I20260812 06:19:43.477165 23990 maintenance_manager.cc:419] P b1a993cb1bce4192ab0c2f9b4f5b7840: Scheduling FlushDeltaMemStoresOp(4e8e58b6d16b44269757ac267001cc5f): perf score=2.188937
I20260812 06:19:43.487876 23917 maintenance_manager.cc:643] P b1a993cb1bce4192ab0c2f9b4f5b7840: FlushDeltaMemStoresOp(4e8e58b6d16b44269757ac267001cc5f) complete. Timing: real 0.011s	user 0.001s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4321,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:43.488660 23990 maintenance_manager.cc:419] P b1a993cb1bce4192ab0c2f9b4f5b7840: Scheduling MajorDeltaCompactionOp(4e8e58b6d16b44269757ac267001cc5f): perf score=1.000000
I20260812 06:19:43.692778 23917 maintenance_manager.cc:643] P b1a993cb1bce4192ab0c2f9b4f5b7840: MajorDeltaCompactionOp(4e8e58b6d16b44269757ac267001cc5f) complete. Timing: real 0.204s	user 0.120s	sys 0.084s Metrics: {"cfile_cache_miss":632,"cfile_cache_miss_bytes":28918097,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":135,"lbm_read_time_us":14831,"lbm_reads_lt_1ms":672,"lbm_write_time_us":33678,"lbm_writes_lt_1ms":643,"mutex_wait_us":46,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":21376,"update_count":3000}
I20260812 06:19:43.693636 23990 maintenance_manager.cc:419] P b1a993cb1bce4192ab0c2f9b4f5b7840: Scheduling FlushDeltaMemStoresOp(4e8e58b6d16b44269757ac267001cc5f): perf score=14.095187
I20260812 06:19:43.742381 23917 maintenance_manager.cc:643] P b1a993cb1bce4192ab0c2f9b4f5b7840: FlushDeltaMemStoresOp(4e8e58b6d16b44269757ac267001cc5f) complete. Timing: real 0.049s	user 0.031s	sys 0.013s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":19729,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:43.742957 23990 maintenance_manager.cc:419] P b1a993cb1bce4192ab0c2f9b4f5b7840: Scheduling FlushDeltaMemStoresOp(4e8e58b6d16b44269757ac267001cc5f): perf score=2.188937
I20260812 06:19:43.758208 23917 maintenance_manager.cc:643] P b1a993cb1bce4192ab0c2f9b4f5b7840: FlushDeltaMemStoresOp(4e8e58b6d16b44269757ac267001cc5f) complete. Timing: real 0.015s	user 0.005s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5949,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:43.758855 23990 maintenance_manager.cc:419] P b1a993cb1bce4192ab0c2f9b4f5b7840: Scheduling FlushMRSOp(4e8e58b6d16b44269757ac267001cc5f): perf score=1.000000
I20260812 06:19:43.793325 23917 maintenance_manager.cc:643] P b1a993cb1bce4192ab0c2f9b4f5b7840: FlushMRSOp(4e8e58b6d16b44269757ac267001cc5f) complete. Timing: real 0.034s	user 0.029s	sys 0.004s Metrics: {"bytes_written":1275444,"cfile_init":1,"dirs.queue_time_us":68,"dirs.run_cpu_time_us":222,"dirs.run_wall_time_us":1367,"drs_written":1,"lbm_read_time_us":58,"lbm_reads_lt_1ms":4,"lbm_write_time_us":2157,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":31}
I20260812 06:19:43.793926 23990 maintenance_manager.cc:419] P b1a993cb1bce4192ab0c2f9b4f5b7840: Scheduling LogGCOp(4e8e58b6d16b44269757ac267001cc5f): free 128867392 bytes of WAL
I20260812 06:19:43.794157 23917 log_reader.cc:385] T 4e8e58b6d16b44269757ac267001cc5f: removed 13 log segments from log reader
I20260812 06:19:43.794221 23917 log.cc:1079] T 4e8e58b6d16b44269757ac267001cc5f P b1a993cb1bce4192ab0c2f9b4f5b7840: Deleting log segment in path: /tmp/dist-test-task0b99mg/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515576443844-23593-0/minicluster-data/ts-0-root/wals/4e8e58b6d16b44269757ac267001cc5f/wal-000000003 (ops 12-16)
I20260812 06:19:43.794275 23917 log.cc:1079] T 4e8e58b6d16b44269757ac267001cc5f P b1a993cb1bce4192ab0c2f9b4f5b7840: Deleting log segment in path: /tmp/dist-test-task0b99mg/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515576443844-23593-0/minicluster-data/ts-0-root/wals/4e8e58b6d16b44269757ac267001cc5f/wal-000000004 (ops 17-20)
I20260812 06:19:43.794333 23917 log.cc:1079] T 4e8e58b6d16b44269757ac267001cc5f P b1a993cb1bce4192ab0c2f9b4f5b7840: Deleting log segment in path: /tmp/dist-test-task0b99mg/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515576443844-23593-0/minicluster-data/ts-0-root/wals/4e8e58b6d16b44269757ac267001cc5f/wal-000000005 (ops 21-25)
I20260812 06:19:43.794373 23917 log.cc:1079] T 4e8e58b6d16b44269757ac267001cc5f P b1a993cb1bce4192ab0c2f9b4f5b7840: Deleting log segment in path: /tmp/dist-test-task0b99mg/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515576443844-23593-0/minicluster-data/ts-0-root/wals/4e8e58b6d16b44269757ac267001cc5f/wal-000000006 (ops 26-30)
I20260812 06:19:43.794409 23917 log.cc:1079] T 4e8e58b6d16b44269757ac267001cc5f P b1a993cb1bce4192ab0c2f9b4f5b7840: Deleting log segment in path: /tmp/dist-test-task0b99mg/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515576443844-23593-0/minicluster-data/ts-0-root/wals/4e8e58b6d16b44269757ac267001cc5f/wal-000000007 (ops 31-35)
I20260812 06:19:43.794445 23917 log.cc:1079] T 4e8e58b6d16b44269757ac267001cc5f P b1a993cb1bce4192ab0c2f9b4f5b7840: Deleting log segment in path: /tmp/dist-test-task0b99mg/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515576443844-23593-0/minicluster-data/ts-0-root/wals/4e8e58b6d16b44269757ac267001cc5f/wal-000000008 (ops 36-40)
I20260812 06:19:43.794482 23917 log.cc:1079] T 4e8e58b6d16b44269757ac267001cc5f P b1a993cb1bce4192ab0c2f9b4f5b7840: Deleting log segment in path: /tmp/dist-test-task0b99mg/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515576443844-23593-0/minicluster-data/ts-0-root/wals/4e8e58b6d16b44269757ac267001cc5f/wal-000000009 (ops 41-44)
I20260812 06:19:43.794518 23917 log.cc:1079] T 4e8e58b6d16b44269757ac267001cc5f P b1a993cb1bce4192ab0c2f9b4f5b7840: Deleting log segment in path: /tmp/dist-test-task0b99mg/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515576443844-23593-0/minicluster-data/ts-0-root/wals/4e8e58b6d16b44269757ac267001cc5f/wal-000000010 (ops 45-49)
I20260812 06:19:43.794556 23917 log.cc:1079] T 4e8e58b6d16b44269757ac267001cc5f P b1a993cb1bce4192ab0c2f9b4f5b7840: Deleting log segment in path: /tmp/dist-test-task0b99mg/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515576443844-23593-0/minicluster-data/ts-0-root/wals/4e8e58b6d16b44269757ac267001cc5f/wal-000000011 (ops 50-54)
I20260812 06:19:43.794600 23917 log.cc:1079] T 4e8e58b6d16b44269757ac267001cc5f P b1a993cb1bce4192ab0c2f9b4f5b7840: Deleting log segment in path: /tmp/dist-test-task0b99mg/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515576443844-23593-0/minicluster-data/ts-0-root/wals/4e8e58b6d16b44269757ac267001cc5f/wal-000000012 (ops 55-59)
I20260812 06:19:43.794636 23917 log.cc:1079] T 4e8e58b6d16b44269757ac267001cc5f P b1a993cb1bce4192ab0c2f9b4f5b7840: Deleting log segment in path: /tmp/dist-test-task0b99mg/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515576443844-23593-0/minicluster-data/ts-0-root/wals/4e8e58b6d16b44269757ac267001cc5f/wal-000000013 (ops 60-64)
I20260812 06:19:43.794673 23917 log.cc:1079] T 4e8e58b6d16b44269757ac267001cc5f P b1a993cb1bce4192ab0c2f9b4f5b7840: Deleting log segment in path: /tmp/dist-test-task0b99mg/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515576443844-23593-0/minicluster-data/ts-0-root/wals/4e8e58b6d16b44269757ac267001cc5f/wal-000000014 (ops 65-68)
I20260812 06:19:43.794709 23917 log.cc:1079] T 4e8e58b6d16b44269757ac267001cc5f P b1a993cb1bce4192ab0c2f9b4f5b7840: Deleting log segment in path: /tmp/dist-test-task0b99mg/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515576443844-23593-0/minicluster-data/ts-0-root/wals/4e8e58b6d16b44269757ac267001cc5f/wal-000000015 (ops 69-73)
I20260812 06:19:43.822052 23917 maintenance_manager.cc:643] P b1a993cb1bce4192ab0c2f9b4f5b7840: LogGCOp(4e8e58b6d16b44269757ac267001cc5f) complete. Timing: real 0.028s	user 0.000s	sys 0.026s Metrics: {}
I20260812 06:19:43.822500 23990 maintenance_manager.cc:419] P b1a993cb1bce4192ab0c2f9b4f5b7840: Scheduling FlushDeltaMemStoresOp(4e8e58b6d16b44269757ac267001cc5f): perf score=3.181125
I20260812 06:19:43.842286 23917 maintenance_manager.cc:643] P b1a993cb1bce4192ab0c2f9b4f5b7840: FlushDeltaMemStoresOp(4e8e58b6d16b44269757ac267001cc5f) complete. Timing: real 0.020s	user 0.008s	sys 0.008s Metrics: {"bytes_written":4512900,"delete_count":0,"lbm_write_time_us":7269,"lbm_writes_lt_1ms":113,"reinsert_count":0,"update_count":550}
I20260812 06:19:43.842710 23990 maintenance_manager.cc:419] P b1a993cb1bce4192ab0c2f9b4f5b7840: Scheduling FlushDeltaMemStoresOp(4e8e58b6d16b44269757ac267001cc5f): perf score=2.188937
I20260812 06:19:43.852115 23917 maintenance_manager.cc:643] P b1a993cb1bce4192ab0c2f9b4f5b7840: FlushDeltaMemStoresOp(4e8e58b6d16b44269757ac267001cc5f) complete. Timing: real 0.009s	user 0.004s	sys 0.003s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3611,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:19:43.852571 23990 maintenance_manager.cc:419] P b1a993cb1bce4192ab0c2f9b4f5b7840: Scheduling UndoDeltaBlockGCOp(4e8e58b6d16b44269757ac267001cc5f): 482 bytes on disk
I20260812 06:19:43.852957 23917 maintenance_manager.cc:643] P b1a993cb1bce4192ab0c2f9b4f5b7840: UndoDeltaBlockGCOp(4e8e58b6d16b44269757ac267001cc5f) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":50,"lbm_reads_lt_1ms":4}
I20260812 06:19:43.853376 23990 maintenance_manager.cc:419] P b1a993cb1bce4192ab0c2f9b4f5b7840: Scheduling MajorDeltaCompactionOp(4e8e58b6d16b44269757ac267001cc5f): perf score=1.000000
I20260812 06:19:44.063478 23917 maintenance_manager.cc:643] P b1a993cb1bce4192ab0c2f9b4f5b7840: MajorDeltaCompactionOp(4e8e58b6d16b44269757ac267001cc5f) complete. Timing: real 0.210s	user 0.160s	sys 0.050s Metrics: {"cfile_cache_miss":734,"cfile_cache_miss_bytes":33020732,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":267,"lbm_read_time_us":15697,"lbm_reads_lt_1ms":774,"lbm_write_time_us":36074,"lbm_writes_lt_1ms":743,"mutex_wait_us":23,"peak_mem_usage":87969044,"reinsert_count":0,"spinlock_wait_cycles":7680,"thread_start_us":82,"threads_started":1,"update_count":3500}
I20260812 06:19:44.064913 23990 maintenance_manager.cc:419] P b1a993cb1bce4192ab0c2f9b4f5b7840: Scheduling FlushDeltaMemStoresOp(4e8e58b6d16b44269757ac267001cc5f): perf score=18.063937
I20260812 06:19:44.134121 23917 maintenance_manager.cc:643] P b1a993cb1bce4192ab0c2f9b4f5b7840: FlushDeltaMemStoresOp(4e8e58b6d16b44269757ac267001cc5f) complete. Timing: real 0.069s	user 0.051s	sys 0.016s Metrics: {"bytes_written":20512314,"delete_count":0,"lbm_write_time_us":31971,"lbm_writes_lt_1ms":503,"reinsert_count":0,"update_count":2500}
I20260812 06:19:44.134662 23990 maintenance_manager.cc:419] P b1a993cb1bce4192ab0c2f9b4f5b7840: Scheduling FlushDeltaMemStoresOp(4e8e58b6d16b44269757ac267001cc5f): perf score=2.188937
I20260812 06:19:44.147526 23917 maintenance_manager.cc:643] P b1a993cb1bce4192ab0c2f9b4f5b7840: FlushDeltaMemStoresOp(4e8e58b6d16b44269757ac267001cc5f) complete. Timing: real 0.013s	user 0.011s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4859,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:44.147996 23990 maintenance_manager.cc:419] P b1a993cb1bce4192ab0c2f9b4f5b7840: Scheduling MajorDeltaCompactionOp(4e8e58b6d16b44269757ac267001cc5f): perf score=1.000000
I20260812 06:19:44.328860 23917 maintenance_manager.cc:643] P b1a993cb1bce4192ab0c2f9b4f5b7840: MajorDeltaCompactionOp(4e8e58b6d16b44269757ac267001cc5f) complete. Timing: real 0.181s	user 0.145s	sys 0.035s Metrics: {"cfile_cache_miss":632,"cfile_cache_miss_bytes":28918096,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":505,"lbm_read_time_us":12785,"lbm_reads_lt_1ms":672,"lbm_write_time_us":38778,"lbm_writes_lt_1ms":643,"mutex_wait_us":418,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":1408,"update_count":3000}
I20260812 06:19:44.329596 23990 maintenance_manager.cc:419] P b1a993cb1bce4192ab0c2f9b4f5b7840: Scheduling FlushDeltaMemStoresOp(4e8e58b6d16b44269757ac267001cc5f): perf score=14.095187
I20260812 06:19:44.382263 23917 maintenance_manager.cc:643] P b1a993cb1bce4192ab0c2f9b4f5b7840: FlushDeltaMemStoresOp(4e8e58b6d16b44269757ac267001cc5f) complete. Timing: real 0.052s	user 0.030s	sys 0.020s Metrics: {"bytes_written":16409900,"delete_count":0,"lbm_write_time_us":23535,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:44.382929 23990 maintenance_manager.cc:419] P b1a993cb1bce4192ab0c2f9b4f5b7840: Scheduling FlushDeltaMemStoresOp(4e8e58b6d16b44269757ac267001cc5f): perf score=2.188937
I20260812 06:19:44.404390 23917 maintenance_manager.cc:643] P b1a993cb1bce4192ab0c2f9b4f5b7840: FlushDeltaMemStoresOp(4e8e58b6d16b44269757ac267001cc5f) complete. Timing: real 0.021s	user 0.010s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":7516,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:44.404896 23990 maintenance_manager.cc:419] P b1a993cb1bce4192ab0c2f9b4f5b7840: Scheduling MajorDeltaCompactionOp(4e8e58b6d16b44269757ac267001cc5f): perf score=1.000000
I20260812 06:19:44.564970 23917 maintenance_manager.cc:643] P b1a993cb1bce4192ab0c2f9b4f5b7840: MajorDeltaCompactionOp(4e8e58b6d16b44269757ac267001cc5f) complete. Timing: real 0.160s	user 0.120s	sys 0.039s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24815682,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":234,"lbm_read_time_us":9480,"lbm_reads_lt_1ms":564,"lbm_write_time_us":30712,"lbm_writes_lt_1ms":543,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":1792,"update_count":2500}
I20260812 06:19:44.565613 23990 maintenance_manager.cc:419] P b1a993cb1bce4192ab0c2f9b4f5b7840: Scheduling FlushDeltaMemStoresOp(4e8e58b6d16b44269757ac267001cc5f): perf score=14.095187
I20260812 06:19:44.633131 23917 maintenance_manager.cc:643] P b1a993cb1bce4192ab0c2f9b4f5b7840: FlushDeltaMemStoresOp(4e8e58b6d16b44269757ac267001cc5f) complete. Timing: real 0.067s	user 0.040s	sys 0.013s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":23889,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:44.633605 23990 maintenance_manager.cc:419] P b1a993cb1bce4192ab0c2f9b4f5b7840: Scheduling FlushDeltaMemStoresOp(4e8e58b6d16b44269757ac267001cc5f): perf score=2.188937
I20260812 06:19:44.652283 23917 maintenance_manager.cc:643] P b1a993cb1bce4192ab0c2f9b4f5b7840: FlushDeltaMemStoresOp(4e8e58b6d16b44269757ac267001cc5f) complete. Timing: real 0.018s	user 0.013s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4929,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:44.652928 23990 maintenance_manager.cc:419] P b1a993cb1bce4192ab0c2f9b4f5b7840: Scheduling MajorDeltaCompactionOp(4e8e58b6d16b44269757ac267001cc5f): perf score=1.000000
I20260812 06:19:44.830173 23917 maintenance_manager.cc:643] P b1a993cb1bce4192ab0c2f9b4f5b7840: MajorDeltaCompactionOp(4e8e58b6d16b44269757ac267001cc5f) complete. Timing: real 0.177s	user 0.133s	sys 0.044s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24815683,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":437,"lbm_read_time_us":13363,"lbm_reads_lt_1ms":572,"lbm_write_time_us":29598,"lbm_writes_lt_1ms":543,"mutex_wait_us":25,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":13056,"update_count":2500}
I20260812 06:19:44.830742 23990 maintenance_manager.cc:419] P b1a993cb1bce4192ab0c2f9b4f5b7840: Scheduling FlushDeltaMemStoresOp(4e8e58b6d16b44269757ac267001cc5f): perf score=14.095187
I20260812 06:19:44.893801 23917 maintenance_manager.cc:643] P b1a993cb1bce4192ab0c2f9b4f5b7840: FlushDeltaMemStoresOp(4e8e58b6d16b44269757ac267001cc5f) complete. Timing: real 0.063s	user 0.049s	sys 0.004s Metrics: {"bytes_written":16409904,"delete_count":0,"lbm_write_time_us":23147,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:44.894374 23990 maintenance_manager.cc:419] P b1a993cb1bce4192ab0c2f9b4f5b7840: Scheduling FlushDeltaMemStoresOp(4e8e58b6d16b44269757ac267001cc5f): perf score=2.188937
I20260812 06:19:44.905788 23917 maintenance_manager.cc:643] P b1a993cb1bce4192ab0c2f9b4f5b7840: FlushDeltaMemStoresOp(4e8e58b6d16b44269757ac267001cc5f) complete. Timing: real 0.011s	user 0.009s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4331,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:44.906279 23990 maintenance_manager.cc:419] P b1a993cb1bce4192ab0c2f9b4f5b7840: Scheduling MajorDeltaCompactionOp(4e8e58b6d16b44269757ac267001cc5f): perf score=1.000000
I20260812 06:19:45.077747 23917 maintenance_manager.cc:643] P b1a993cb1bce4192ab0c2f9b4f5b7840: MajorDeltaCompactionOp(4e8e58b6d16b44269757ac267001cc5f) complete. Timing: real 0.171s	user 0.119s	sys 0.052s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24815686,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":895,"lbm_read_time_us":12248,"lbm_reads_lt_1ms":572,"lbm_write_time_us":29314,"lbm_writes_lt_1ms":543,"mutex_wait_us":334,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":29824,"update_count":2500}
I20260812 06:19:45.078250 23990 maintenance_manager.cc:419] P b1a993cb1bce4192ab0c2f9b4f5b7840: Scheduling FlushDeltaMemStoresOp(4e8e58b6d16b44269757ac267001cc5f): perf score=14.095187
I20260812 06:19:45.134608 23917 maintenance_manager.cc:643] P b1a993cb1bce4192ab0c2f9b4f5b7840: FlushDeltaMemStoresOp(4e8e58b6d16b44269757ac267001cc5f) complete. Timing: real 0.056s	user 0.034s	sys 0.019s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":19541,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:45.135115 23990 maintenance_manager.cc:419] P b1a993cb1bce4192ab0c2f9b4f5b7840: Scheduling FlushDeltaMemStoresOp(4e8e58b6d16b44269757ac267001cc5f): perf score=2.188937
I20260812 06:19:45.145512 23917 maintenance_manager.cc:643] P b1a993cb1bce4192ab0c2f9b4f5b7840: FlushDeltaMemStoresOp(4e8e58b6d16b44269757ac267001cc5f) complete. Timing: real 0.010s	user 0.005s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4099,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:45.145948 23990 maintenance_manager.cc:419] P b1a993cb1bce4192ab0c2f9b4f5b7840: Scheduling FlushMRSOp(4e8e58b6d16b44269757ac267001cc5f): perf score=1.000000
I20260812 06:19:45.188918 23917 maintenance_manager.cc:643] P b1a993cb1bce4192ab0c2f9b4f5b7840: FlushMRSOp(4e8e58b6d16b44269757ac267001cc5f) complete. Timing: real 0.043s	user 0.034s	sys 0.000s Metrics: {"bytes_written":1152512,"cfile_init":1,"dirs.queue_time_us":49,"dirs.run_cpu_time_us":169,"dirs.run_wall_time_us":1258,"drs_written":1,"lbm_read_time_us":38,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1350,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":28}
I20260812 06:19:45.189649 23990 maintenance_manager.cc:419] P b1a993cb1bce4192ab0c2f9b4f5b7840: Scheduling LogGCOp(4e8e58b6d16b44269757ac267001cc5f): free 112239314 bytes of WAL
I20260812 06:19:45.189924 23917 log_reader.cc:385] T 4e8e58b6d16b44269757ac267001cc5f: removed 11 log segments from log reader
I20260812 06:19:45.189985 23917 log.cc:1079] T 4e8e58b6d16b44269757ac267001cc5f P b1a993cb1bce4192ab0c2f9b4f5b7840: Deleting log segment in path: /tmp/dist-test-task0b99mg/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515576443844-23593-0/minicluster-data/ts-0-root/wals/4e8e58b6d16b44269757ac267001cc5f/wal-000000016 (ops 74-78)
I20260812 06:19:45.190025 23917 log.cc:1079] T 4e8e58b6d16b44269757ac267001cc5f P b1a993cb1bce4192ab0c2f9b4f5b7840: Deleting log segment in path: /tmp/dist-test-task0b99mg/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515576443844-23593-0/minicluster-data/ts-0-root/wals/4e8e58b6d16b44269757ac267001cc5f/wal-000000017 (ops 79-83)
I20260812 06:19:45.190061 23917 log.cc:1079] T 4e8e58b6d16b44269757ac267001cc5f P b1a993cb1bce4192ab0c2f9b4f5b7840: Deleting log segment in path: /tmp/dist-test-task0b99mg/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515576443844-23593-0/minicluster-data/ts-0-root/wals/4e8e58b6d16b44269757ac267001cc5f/wal-000000018 (ops 84-88)
I20260812 06:19:45.190084 23917 log.cc:1079] T 4e8e58b6d16b44269757ac267001cc5f P b1a993cb1bce4192ab0c2f9b4f5b7840: Deleting log segment in path: /tmp/dist-test-task0b99mg/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515576443844-23593-0/minicluster-data/ts-0-root/wals/4e8e58b6d16b44269757ac267001cc5f/wal-000000019 (ops 89-92)
I20260812 06:19:45.190106 23917 log.cc:1079] T 4e8e58b6d16b44269757ac267001cc5f P b1a993cb1bce4192ab0c2f9b4f5b7840: Deleting log segment in path: /tmp/dist-test-task0b99mg/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515576443844-23593-0/minicluster-data/ts-0-root/wals/4e8e58b6d16b44269757ac267001cc5f/wal-000000020 (ops 93-97)
I20260812 06:19:45.190129 23917 log.cc:1079] T 4e8e58b6d16b44269757ac267001cc5f P b1a993cb1bce4192ab0c2f9b4f5b7840: Deleting log segment in path: /tmp/dist-test-task0b99mg/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515576443844-23593-0/minicluster-data/ts-0-root/wals/4e8e58b6d16b44269757ac267001cc5f/wal-000000021 (ops 98-102)
I20260812 06:19:45.190158 23917 log.cc:1079] T 4e8e58b6d16b44269757ac267001cc5f P b1a993cb1bce4192ab0c2f9b4f5b7840: Deleting log segment in path: /tmp/dist-test-task0b99mg/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515576443844-23593-0/minicluster-data/ts-0-root/wals/4e8e58b6d16b44269757ac267001cc5f/wal-000000022 (ops 103-107)
I20260812 06:19:45.190181 23917 log.cc:1079] T 4e8e58b6d16b44269757ac267001cc5f P b1a993cb1bce4192ab0c2f9b4f5b7840: Deleting log segment in path: /tmp/dist-test-task0b99mg/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515576443844-23593-0/minicluster-data/ts-0-root/wals/4e8e58b6d16b44269757ac267001cc5f/wal-000000023 (ops 108-112)
I20260812 06:19:45.190217 23917 log.cc:1079] T 4e8e58b6d16b44269757ac267001cc5f P b1a993cb1bce4192ab0c2f9b4f5b7840: Deleting log segment in path: /tmp/dist-test-task0b99mg/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515576443844-23593-0/minicluster-data/ts-0-root/wals/4e8e58b6d16b44269757ac267001cc5f/wal-000000024 (ops 113-117)
I20260812 06:19:45.190241 23917 log.cc:1079] T 4e8e58b6d16b44269757ac267001cc5f P b1a993cb1bce4192ab0c2f9b4f5b7840: Deleting log segment in path: /tmp/dist-test-task0b99mg/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515576443844-23593-0/minicluster-data/ts-0-root/wals/4e8e58b6d16b44269757ac267001cc5f/wal-000000025 (ops 118-122)
I20260812 06:19:45.190263 23917 log.cc:1079] T 4e8e58b6d16b44269757ac267001cc5f P b1a993cb1bce4192ab0c2f9b4f5b7840: Deleting log segment in path: /tmp/dist-test-task0b99mg/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515576443844-23593-0/minicluster-data/ts-0-root/wals/4e8e58b6d16b44269757ac267001cc5f/wal-000000026 (ops 123-127)
I20260812 06:19:45.218245 23917 maintenance_manager.cc:643] P b1a993cb1bce4192ab0c2f9b4f5b7840: LogGCOp(4e8e58b6d16b44269757ac267001cc5f) complete. Timing: real 0.028s	user 0.000s	sys 0.026s Metrics: {}
I20260812 06:19:45.218746 23990 maintenance_manager.cc:419] P b1a993cb1bce4192ab0c2f9b4f5b7840: Scheduling FlushDeltaMemStoresOp(4e8e58b6d16b44269757ac267001cc5f): perf score=2.188937
I20260812 06:19:45.245056 23917 maintenance_manager.cc:643] P b1a993cb1bce4192ab0c2f9b4f5b7840: FlushDeltaMemStoresOp(4e8e58b6d16b44269757ac267001cc5f) complete. Timing: real 0.026s	user 0.009s	sys 0.005s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5777,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:45.245554 23990 maintenance_manager.cc:419] P b1a993cb1bce4192ab0c2f9b4f5b7840: Scheduling UndoDeltaBlockGCOp(4e8e58b6d16b44269757ac267001cc5f): 447 bytes on disk
I20260812 06:19:45.245956 23917 maintenance_manager.cc:643] P b1a993cb1bce4192ab0c2f9b4f5b7840: UndoDeltaBlockGCOp(4e8e58b6d16b44269757ac267001cc5f) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":55,"lbm_reads_lt_1ms":4}
I20260812 06:19:45.246448 23990 maintenance_manager.cc:419] P b1a993cb1bce4192ab0c2f9b4f5b7840: Scheduling FlushDeltaMemStoresOp(4e8e58b6d16b44269757ac267001cc5f): perf score=2.188937
I20260812 06:19:45.257016 23917 maintenance_manager.cc:643] P b1a993cb1bce4192ab0c2f9b4f5b7840: FlushDeltaMemStoresOp(4e8e58b6d16b44269757ac267001cc5f) complete. Timing: real 0.010s	user 0.008s	sys 0.002s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4024,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:45.257455 23990 maintenance_manager.cc:419] P b1a993cb1bce4192ab0c2f9b4f5b7840: Scheduling MajorDeltaCompactionOp(4e8e58b6d16b44269757ac267001cc5f): perf score=1.000000
I20260812 06:19:45.504556 23917 maintenance_manager.cc:643] P b1a993cb1bce4192ab0c2f9b4f5b7840: MajorDeltaCompactionOp(4e8e58b6d16b44269757ac267001cc5f) complete. Timing: real 0.247s	user 0.168s	sys 0.066s Metrics: {"cfile_cache_miss":734,"cfile_cache_miss_bytes":33020744,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":607,"lbm_read_time_us":18074,"lbm_reads_lt_1ms":774,"lbm_write_time_us":40149,"lbm_writes_lt_1ms":743,"mutex_wait_us":612,"peak_mem_usage":87969044,"reinsert_count":0,"spinlock_wait_cycles":11904,"thread_start_us":92,"threads_started":1,"update_count":3500}
I20260812 06:19:45.505149 23990 maintenance_manager.cc:419] P b1a993cb1bce4192ab0c2f9b4f5b7840: Scheduling FlushDeltaMemStoresOp(4e8e58b6d16b44269757ac267001cc5f): perf score=18.063937
I20260812 06:19:45.568048 23917 maintenance_manager.cc:643] P b1a993cb1bce4192ab0c2f9b4f5b7840: FlushDeltaMemStoresOp(4e8e58b6d16b44269757ac267001cc5f) complete. Timing: real 0.063s	user 0.042s	sys 0.013s Metrics: {"bytes_written":20512316,"delete_count":0,"lbm_write_time_us":26668,"lbm_writes_lt_1ms":503,"reinsert_count":0,"update_count":2500}
I20260812 06:19:45.568583 23990 maintenance_manager.cc:419] P b1a993cb1bce4192ab0c2f9b4f5b7840: Scheduling FlushDeltaMemStoresOp(4e8e58b6d16b44269757ac267001cc5f): perf score=2.188937
I20260812 06:19:45.582322 23917 maintenance_manager.cc:643] P b1a993cb1bce4192ab0c2f9b4f5b7840: FlushDeltaMemStoresOp(4e8e58b6d16b44269757ac267001cc5f) complete. Timing: real 0.014s	user 0.013s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5066,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:45.582989 23990 maintenance_manager.cc:419] P b1a993cb1bce4192ab0c2f9b4f5b7840: Scheduling MajorDeltaCompactionOp(4e8e58b6d16b44269757ac267001cc5f): perf score=1.000000
I20260812 06:19:45.771710 23917 maintenance_manager.cc:643] P b1a993cb1bce4192ab0c2f9b4f5b7840: MajorDeltaCompactionOp(4e8e58b6d16b44269757ac267001cc5f) complete. Timing: real 0.189s	user 0.144s	sys 0.044s Metrics: {"cfile_cache_miss":632,"cfile_cache_miss_bytes":28918098,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":908,"lbm_read_time_us":11939,"lbm_reads_lt_1ms":664,"lbm_write_time_us":36891,"lbm_writes_lt_1ms":643,"mutex_wait_us":263,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":14720,"update_count":3000}
I20260812 06:19:45.772342 23990 maintenance_manager.cc:419] P b1a993cb1bce4192ab0c2f9b4f5b7840: Scheduling FlushDeltaMemStoresOp(4e8e58b6d16b44269757ac267001cc5f): perf score=14.095187
I20260812 06:19:45.816463 23917 maintenance_manager.cc:643] P b1a993cb1bce4192ab0c2f9b4f5b7840: FlushDeltaMemStoresOp(4e8e58b6d16b44269757ac267001cc5f) complete. Timing: real 0.044s	user 0.023s	sys 0.020s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":19899,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:45.816975 23990 maintenance_manager.cc:419] P b1a993cb1bce4192ab0c2f9b4f5b7840: Scheduling FlushDeltaMemStoresOp(4e8e58b6d16b44269757ac267001cc5f): perf score=2.188937
I20260812 06:19:45.830605 23917 maintenance_manager.cc:643] P b1a993cb1bce4192ab0c2f9b4f5b7840: FlushDeltaMemStoresOp(4e8e58b6d16b44269757ac267001cc5f) complete. Timing: real 0.013s	user 0.011s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5123,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:45.831102 23990 maintenance_manager.cc:419] P b1a993cb1bce4192ab0c2f9b4f5b7840: Scheduling MajorDeltaCompactionOp(4e8e58b6d16b44269757ac267001cc5f): perf score=1.000000
I20260812 06:19:45.992102 23917 maintenance_manager.cc:643] P b1a993cb1bce4192ab0c2f9b4f5b7840: MajorDeltaCompactionOp(4e8e58b6d16b44269757ac267001cc5f) complete. Timing: real 0.161s	user 0.123s	sys 0.032s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24815683,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":1005,"lbm_read_time_us":9498,"lbm_reads_lt_1ms":564,"lbm_write_time_us":31051,"lbm_writes_lt_1ms":543,"mutex_wait_us":279,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":12544,"update_count":2500}
I20260812 06:19:45.992815 23990 maintenance_manager.cc:419] P b1a993cb1bce4192ab0c2f9b4f5b7840: Scheduling FlushDeltaMemStoresOp(4e8e58b6d16b44269757ac267001cc5f): perf score=14.095187
I20260812 06:19:46.055250 23917 maintenance_manager.cc:643] P b1a993cb1bce4192ab0c2f9b4f5b7840: FlushDeltaMemStoresOp(4e8e58b6d16b44269757ac267001cc5f) complete. Timing: real 0.062s	user 0.027s	sys 0.019s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":22097,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:46.055727 23990 maintenance_manager.cc:419] P b1a993cb1bce4192ab0c2f9b4f5b7840: Scheduling FlushDeltaMemStoresOp(4e8e58b6d16b44269757ac267001cc5f): perf score=2.188937
I20260812 06:19:46.067819 23917 maintenance_manager.cc:643] P b1a993cb1bce4192ab0c2f9b4f5b7840: FlushDeltaMemStoresOp(4e8e58b6d16b44269757ac267001cc5f) complete. Timing: real 0.012s	user 0.003s	sys 0.007s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4660,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:46.068473 23990 maintenance_manager.cc:419] P b1a993cb1bce4192ab0c2f9b4f5b7840: Scheduling MajorDeltaCompactionOp(4e8e58b6d16b44269757ac267001cc5f): perf score=1.000000
I20260812 06:19:46.252221 23917 maintenance_manager.cc:643] P b1a993cb1bce4192ab0c2f9b4f5b7840: MajorDeltaCompactionOp(4e8e58b6d16b44269757ac267001cc5f) complete. Timing: real 0.184s	user 0.101s	sys 0.072s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24815683,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":341,"lbm_read_time_us":12424,"lbm_reads_lt_1ms":572,"lbm_write_time_us":32058,"lbm_writes_lt_1ms":543,"mutex_wait_us":38,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":2688,"update_count":2500}
I20260812 06:19:46.252990 23990 maintenance_manager.cc:419] P b1a993cb1bce4192ab0c2f9b4f5b7840: Scheduling FlushDeltaMemStoresOp(4e8e58b6d16b44269757ac267001cc5f): perf score=14.095187
I20260812 06:19:46.310549 23917 maintenance_manager.cc:643] P b1a993cb1bce4192ab0c2f9b4f5b7840: FlushDeltaMemStoresOp(4e8e58b6d16b44269757ac267001cc5f) complete. Timing: real 0.057s	user 0.025s	sys 0.024s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":18833,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:46.311129 23990 maintenance_manager.cc:419] P b1a993cb1bce4192ab0c2f9b4f5b7840: Scheduling FlushDeltaMemStoresOp(4e8e58b6d16b44269757ac267001cc5f): perf score=2.188937
I20260812 06:19:46.321656 23917 maintenance_manager.cc:643] P b1a993cb1bce4192ab0c2f9b4f5b7840: FlushDeltaMemStoresOp(4e8e58b6d16b44269757ac267001cc5f) complete. Timing: real 0.010s	user 0.004s	sys 0.004s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4143,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:46.322101 23990 maintenance_manager.cc:419] P b1a993cb1bce4192ab0c2f9b4f5b7840: Scheduling MajorDeltaCompactionOp(4e8e58b6d16b44269757ac267001cc5f): perf score=1.000000
I20260812 06:19:46.497632 23917 maintenance_manager.cc:643] P b1a993cb1bce4192ab0c2f9b4f5b7840: MajorDeltaCompactionOp(4e8e58b6d16b44269757ac267001cc5f) complete. Timing: real 0.175s	user 0.132s	sys 0.041s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24815683,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":618,"lbm_read_time_us":13312,"lbm_reads_lt_1ms":572,"lbm_write_time_us":29310,"lbm_writes_lt_1ms":543,"mutex_wait_us":294,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":24576,"update_count":2500}
I20260812 06:19:46.498391 23990 maintenance_manager.cc:419] P b1a993cb1bce4192ab0c2f9b4f5b7840: Scheduling FlushDeltaMemStoresOp(4e8e58b6d16b44269757ac267001cc5f): perf score=14.095187
I20260812 06:19:46.558202 23917 maintenance_manager.cc:643] P b1a993cb1bce4192ab0c2f9b4f5b7840: FlushDeltaMemStoresOp(4e8e58b6d16b44269757ac267001cc5f) complete. Timing: real 0.059s	user 0.030s	sys 0.027s Metrics: {"bytes_written":16409903,"delete_count":0,"lbm_write_time_us":21011,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:46.558730 23990 maintenance_manager.cc:419] P b1a993cb1bce4192ab0c2f9b4f5b7840: Scheduling FlushDeltaMemStoresOp(4e8e58b6d16b44269757ac267001cc5f): perf score=2.188937
I20260812 06:19:46.569547 23917 maintenance_manager.cc:643] P b1a993cb1bce4192ab0c2f9b4f5b7840: FlushDeltaMemStoresOp(4e8e58b6d16b44269757ac267001cc5f) complete. Timing: real 0.011s	user 0.001s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4115,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:46.570329 23990 maintenance_manager.cc:419] P b1a993cb1bce4192ab0c2f9b4f5b7840: Scheduling FlushMRSOp(4e8e58b6d16b44269757ac267001cc5f): perf score=1.000000
I20260812 06:19:46.606302 23917 maintenance_manager.cc:643] P b1a993cb1bce4192ab0c2f9b4f5b7840: FlushMRSOp(4e8e58b6d16b44269757ac267001cc5f) complete. Timing: real 0.036s	user 0.027s	sys 0.000s Metrics: {"bytes_written":1152510,"cfile_init":1,"dirs.queue_time_us":89,"dirs.run_cpu_time_us":250,"dirs.run_wall_time_us":1391,"drs_written":1,"lbm_read_time_us":37,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1645,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":28}
I20260812 06:19:46.607023 23990 maintenance_manager.cc:419] P b1a993cb1bce4192ab0c2f9b4f5b7840: Scheduling LogGCOp(4e8e58b6d16b44269757ac267001cc5f): free 121006745 bytes of WAL
I20260812 06:19:46.607296 23917 log_reader.cc:385] T 4e8e58b6d16b44269757ac267001cc5f: removed 12 log segments from log reader
I20260812 06:19:46.607355 23917 log.cc:1079] T 4e8e58b6d16b44269757ac267001cc5f P b1a993cb1bce4192ab0c2f9b4f5b7840: Deleting log segment in path: /tmp/dist-test-task0b99mg/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515576443844-23593-0/minicluster-data/ts-0-root/wals/4e8e58b6d16b44269757ac267001cc5f/wal-000000027 (ops 128-132)
I20260812 06:19:46.607393 23917 log.cc:1079] T 4e8e58b6d16b44269757ac267001cc5f P b1a993cb1bce4192ab0c2f9b4f5b7840: Deleting log segment in path: /tmp/dist-test-task0b99mg/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515576443844-23593-0/minicluster-data/ts-0-root/wals/4e8e58b6d16b44269757ac267001cc5f/wal-000000028 (ops 133-137)
I20260812 06:19:46.607429 23917 log.cc:1079] T 4e8e58b6d16b44269757ac267001cc5f P b1a993cb1bce4192ab0c2f9b4f5b7840: Deleting log segment in path: /tmp/dist-test-task0b99mg/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515576443844-23593-0/minicluster-data/ts-0-root/wals/4e8e58b6d16b44269757ac267001cc5f/wal-000000029 (ops 138-142)
I20260812 06:19:46.607453 23917 log.cc:1079] T 4e8e58b6d16b44269757ac267001cc5f P b1a993cb1bce4192ab0c2f9b4f5b7840: Deleting log segment in path: /tmp/dist-test-task0b99mg/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515576443844-23593-0/minicluster-data/ts-0-root/wals/4e8e58b6d16b44269757ac267001cc5f/wal-000000030 (ops 143-146)
I20260812 06:19:46.607482 23917 log.cc:1079] T 4e8e58b6d16b44269757ac267001cc5f P b1a993cb1bce4192ab0c2f9b4f5b7840: Deleting log segment in path: /tmp/dist-test-task0b99mg/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515576443844-23593-0/minicluster-data/ts-0-root/wals/4e8e58b6d16b44269757ac267001cc5f/wal-000000031 (ops 147-151)
I20260812 06:19:46.607512 23917 log.cc:1079] T 4e8e58b6d16b44269757ac267001cc5f P b1a993cb1bce4192ab0c2f9b4f5b7840: Deleting log segment in path: /tmp/dist-test-task0b99mg/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515576443844-23593-0/minicluster-data/ts-0-root/wals/4e8e58b6d16b44269757ac267001cc5f/wal-000000032 (ops 152-156)
I20260812 06:19:46.607542 23917 log.cc:1079] T 4e8e58b6d16b44269757ac267001cc5f P b1a993cb1bce4192ab0c2f9b4f5b7840: Deleting log segment in path: /tmp/dist-test-task0b99mg/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515576443844-23593-0/minicluster-data/ts-0-root/wals/4e8e58b6d16b44269757ac267001cc5f/wal-000000033 (ops 157-161)
I20260812 06:19:46.607578 23917 log.cc:1079] T 4e8e58b6d16b44269757ac267001cc5f P b1a993cb1bce4192ab0c2f9b4f5b7840: Deleting log segment in path: /tmp/dist-test-task0b99mg/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515576443844-23593-0/minicluster-data/ts-0-root/wals/4e8e58b6d16b44269757ac267001cc5f/wal-000000034 (ops 162-166)
I20260812 06:19:46.607604 23917 log.cc:1079] T 4e8e58b6d16b44269757ac267001cc5f P b1a993cb1bce4192ab0c2f9b4f5b7840: Deleting log segment in path: /tmp/dist-test-task0b99mg/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515576443844-23593-0/minicluster-data/ts-0-root/wals/4e8e58b6d16b44269757ac267001cc5f/wal-000000035 (ops 167-171)
I20260812 06:19:46.607626 23917 log.cc:1079] T 4e8e58b6d16b44269757ac267001cc5f P b1a993cb1bce4192ab0c2f9b4f5b7840: Deleting log segment in path: /tmp/dist-test-task0b99mg/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515576443844-23593-0/minicluster-data/ts-0-root/wals/4e8e58b6d16b44269757ac267001cc5f/wal-000000036 (ops 172-176)
I20260812 06:19:46.607654 23917 log.cc:1079] T 4e8e58b6d16b44269757ac267001cc5f P b1a993cb1bce4192ab0c2f9b4f5b7840: Deleting log segment in path: /tmp/dist-test-task0b99mg/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515576443844-23593-0/minicluster-data/ts-0-root/wals/4e8e58b6d16b44269757ac267001cc5f/wal-000000037 (ops 177-181)
I20260812 06:19:46.607682 23917 log.cc:1079] T 4e8e58b6d16b44269757ac267001cc5f P b1a993cb1bce4192ab0c2f9b4f5b7840: Deleting log segment in path: /tmp/dist-test-task0b99mg/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515576443844-23593-0/minicluster-data/ts-0-root/wals/4e8e58b6d16b44269757ac267001cc5f/wal-000000038 (ops 182-186)
I20260812 06:19:46.639175 23917 maintenance_manager.cc:643] P b1a993cb1bce4192ab0c2f9b4f5b7840: LogGCOp(4e8e58b6d16b44269757ac267001cc5f) complete. Timing: real 0.032s	user 0.000s	sys 0.029s Metrics: {}
I20260812 06:19:46.639711 23990 maintenance_manager.cc:419] P b1a993cb1bce4192ab0c2f9b4f5b7840: Scheduling UndoDeltaBlockGCOp(4e8e58b6d16b44269757ac267001cc5f): 447 bytes on disk
I20260812 06:19:46.640323 23917 maintenance_manager.cc:643] P b1a993cb1bce4192ab0c2f9b4f5b7840: UndoDeltaBlockGCOp(4e8e58b6d16b44269757ac267001cc5f) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":112,"lbm_reads_lt_1ms":4}
I20260812 06:19:46.641080 23990 maintenance_manager.cc:419] P b1a993cb1bce4192ab0c2f9b4f5b7840: Scheduling FlushDeltaMemStoresOp(4e8e58b6d16b44269757ac267001cc5f): perf score=2.188937
I20260812 06:19:46.666332 23917 maintenance_manager.cc:643] P b1a993cb1bce4192ab0c2f9b4f5b7840: FlushDeltaMemStoresOp(4e8e58b6d16b44269757ac267001cc5f) complete. Timing: real 0.025s	user 0.003s	sys 0.012s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6543,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:46.666792 23990 maintenance_manager.cc:419] P b1a993cb1bce4192ab0c2f9b4f5b7840: Scheduling FlushDeltaMemStoresOp(4e8e58b6d16b44269757ac267001cc5f): perf score=2.188937
I20260812 06:19:46.677043 23917 maintenance_manager.cc:643] P b1a993cb1bce4192ab0c2f9b4f5b7840: FlushDeltaMemStoresOp(4e8e58b6d16b44269757ac267001cc5f) complete. Timing: real 0.010s	user 0.000s	sys 0.009s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4008,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:46.677520 23990 maintenance_manager.cc:419] P b1a993cb1bce4192ab0c2f9b4f5b7840: Scheduling MajorDeltaCompactionOp(4e8e58b6d16b44269757ac267001cc5f): perf score=1.000000
I20260812 06:19:46.911394 23917 maintenance_manager.cc:643] P b1a993cb1bce4192ab0c2f9b4f5b7840: MajorDeltaCompactionOp(4e8e58b6d16b44269757ac267001cc5f) complete. Timing: real 0.234s	user 0.147s	sys 0.082s Metrics: {"cfile_cache_miss":734,"cfile_cache_miss_bytes":33020746,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":61,"lbm_read_time_us":16038,"lbm_reads_lt_1ms":774,"lbm_write_time_us":40737,"lbm_writes_lt_1ms":743,"mutex_wait_us":19,"peak_mem_usage":87969044,"reinsert_count":0,"spinlock_wait_cycles":10240,"thread_start_us":74,"threads_started":1,"update_count":3500}
I20260812 06:19:46.912047 23990 maintenance_manager.cc:419] P b1a993cb1bce4192ab0c2f9b4f5b7840: Scheduling FlushDeltaMemStoresOp(4e8e58b6d16b44269757ac267001cc5f): perf score=15.087375
I20260812 06:19:46.965603 23917 maintenance_manager.cc:643] P b1a993cb1bce4192ab0c2f9b4f5b7840: FlushDeltaMemStoresOp(4e8e58b6d16b44269757ac267001cc5f) complete. Timing: real 0.053s	user 0.015s	sys 0.036s Metrics: {"bytes_written":16820145,"delete_count":0,"lbm_write_time_us":24771,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":412,"reinsert_count":0,"update_count":2050}
I20260812 06:19:46.966312 23990 maintenance_manager.cc:419] P b1a993cb1bce4192ab0c2f9b4f5b7840: Scheduling FlushDeltaMemStoresOp(4e8e58b6d16b44269757ac267001cc5f): perf score=2.188937
I20260812 06:19:46.985770 23593 heavy-update-compaction-itest.cc:229] Time spent updating: real 4.924s	user 1.863s	sys 0.188s
I20260812 06:19:46.987253 23917 maintenance_manager.cc:643] P b1a993cb1bce4192ab0c2f9b4f5b7840: FlushDeltaMemStoresOp(4e8e58b6d16b44269757ac267001cc5f) complete. Timing: real 0.021s	user 0.008s	sys 0.004s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":5017,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:19:46.987706 23990 maintenance_manager.cc:419] P b1a993cb1bce4192ab0c2f9b4f5b7840: Scheduling FlushDeltaMemStoresOp(4e8e58b6d16b44269757ac267001cc5f): perf score=2.188937
I20260812 06:19:46.997141 23917 maintenance_manager.cc:643] P b1a993cb1bce4192ab0c2f9b4f5b7840: FlushDeltaMemStoresOp(4e8e58b6d16b44269757ac267001cc5f) complete. Timing: real 0.009s	user 0.006s	sys 0.003s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3861,"lbm_writes_lt_1ms":103,"reinsert_count":0,"spinlock_wait_cycles":1280,"update_count":500}
I20260812 06:19:46.997529 23990 maintenance_manager.cc:419] P b1a993cb1bce4192ab0c2f9b4f5b7840: Scheduling MajorDeltaCompactionOp(4e8e58b6d16b44269757ac267001cc5f): perf score=1.000000
I20260812 06:19:47.056041 23593 heavy-update-compaction-itest.cc:265] Time spent scanning: real 0.070s	user 0.001s	sys 0.000s
I20260812 06:19:47.056598 23593 tablet_server.cc:179] TabletServer@127.23.10.65:0 shutting down...
I20260812 06:19:47.158744 23917 maintenance_manager.cc:643] P b1a993cb1bce4192ab0c2f9b4f5b7840: MajorDeltaCompactionOp(4e8e58b6d16b44269757ac267001cc5f) complete. Timing: real 0.161s	user 0.108s	sys 0.052s Metrics: {"cfile_cache_hit":223,"cfile_cache_hit_bytes":9070219,"cfile_cache_miss":410,"cfile_cache_miss_bytes":19847985,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":914,"lbm_read_time_us":8948,"lbm_reads_lt_1ms":442,"lbm_write_time_us":29887,"lbm_writes_lt_1ms":643,"mutex_wait_us":121,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":43264,"update_count":3000}
I20260812 06:19:47.159677 23593 ts_tablet_manager.cc:1507] Shutting down tablet manager...
I20260812 06:19:47.159927 23593 tablet_replica.cc:333] T 4e8e58b6d16b44269757ac267001cc5f P b1a993cb1bce4192ab0c2f9b4f5b7840: stopping tablet replica
I20260812 06:19:47.160084 23593 raft_consensus.cc:2243] T 4e8e58b6d16b44269757ac267001cc5f P b1a993cb1bce4192ab0c2f9b4f5b7840 [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:19:47.160320 23593 raft_consensus.cc:2272] T 4e8e58b6d16b44269757ac267001cc5f P b1a993cb1bce4192ab0c2f9b4f5b7840 [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:19:47.165074 23593 tablet_server.cc:196] TabletServer@127.23.10.65:0 shutdown complete.
I20260812 06:19:47.212970 23593 master.cc:562] Master@127.23.10.126:43247 shutting down...
I20260812 06:19:47.218222 23593 raft_consensus.cc:2243] T 00000000000000000000000000000000 P 0779d6bce548478ea4fff8ccf07774ae [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:19:47.218461 23593 raft_consensus.cc:2272] T 00000000000000000000000000000000 P 0779d6bce548478ea4fff8ccf07774ae [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:19:47.218573 23593 tablet_replica.cc:333] T 00000000000000000000000000000000 P 0779d6bce548478ea4fff8ccf07774ae: stopping tablet replica
I20260812 06:19:47.231201 23593 master.cc:584] Master@127.23.10.126:43247 shutdown complete.
[       OK ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/1 (5484 ms)
[----------] 2 tests from EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy (10870 ms total)

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