[==========] Running 2 tests from 1 test suite.
[----------] Global test environment set-up.
[----------] 2 tests from EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy
[ RUN      ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/0
WARNING: Logging before InitGoogleLogging() is written to STDERR
I20260812 06:18:23.130873 16044 internal_mini_cluster.cc:156] Creating distributed mini masters. Addrs: 127.15.171.62:40781
I20260812 06:18:23.132179 16044 env_posix.cc:2285] Not raising this process' open files per process limit of 1048576; it is already as high as it can go
I20260812 06:18:23.132861 16044 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:18:23.139622 16050 instance_detector.cc:116] could not retrieve Azure instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:18:23.139634 16052 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:18:23.139981 16049 instance_detector.cc:116] could not retrieve AWS instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:18:23.140125 16044 server_base.cc:1061] running on GCE node
I20260812 06:18:23.140626 16044 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:18:23.140723 16044 system_unsync_time.cc:38] NTP support is disabled. Clock error bounds will not be accurate. This configuration is not suitable for distributed clusters.
I20260812 06:18:23.140769 16044 hybrid_clock.cc:648] HybridClock initialized: now 1786515503140765 us; error 0 us; skew 500 ppm
I20260812 06:18:23.142707 16044 webserver.cc:533] Webserver started at http://127.15.171.62:35395/ using document root <none> and password file <none>
I20260812 06:18:23.143278 16044 fs_manager.cc:362] Metadata directory not provided
I20260812 06:18:23.143337 16044 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:18:23.143534 16044 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:18:23.146148 16044 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskSk6K39/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515503120097-16044-0/minicluster-data/master-0-root/instance:
uuid: "0337355cc73748dc94052af289c968ae"
format_stamp: "Formatted at 2026-08-12 06:18:23 on dist-test-slave-f7th"
I20260812 06:18:23.150012 16044 fs_manager.cc:696] Time spent creating directory manager: real 0.003s	user 0.004s	sys 0.000s
I20260812 06:18:23.152262 16057 log_block_manager.cc:4127] Time spent loading block containers with low live blocks: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:18:23.153340 16044 fs_manager.cc:730] Time spent opening block manager: real 0.002s	user 0.000s	sys 0.003s
I20260812 06:18:23.153450 16044 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskSk6K39/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515503120097-16044-0/minicluster-data/master-0-root
uuid: "0337355cc73748dc94052af289c968ae"
format_stamp: "Formatted at 2026-08-12 06:18:23 on dist-test-slave-f7th"
I20260812 06:18:23.153543 16044 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskSk6K39/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515503120097-16044-0/minicluster-data/master-0-root
metadata directory: /tmp/dist-test-taskSk6K39/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515503120097-16044-0/minicluster-data/master-0-root
1 data directories: /tmp/dist-test-taskSk6K39/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515503120097-16044-0/minicluster-data/master-0-root/data
Total live blocks: 0
Total live bytes: 0
Total live bytes (after alignment): 0
Total number of LBM containers: 0 (0 full)
Did not check for missing blocks
Did not check for orphaned blocks
Total full LBM containers with extra space: 0 (0 repaired)
Total full LBM container extra space in bytes: 0 (0 repaired)
Total incomplete LBM containers: 0 (0 repaired)
Total LBM partial records: 0 (0 repaired)
Total corrupted LBM metadata records in RocksDB: 0 (0 repaired)
I20260812 06:18:23.176487 16044 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:18:23.177841 16044 env_posix.cc:2285] Not raising this process' running threads per effective uid limit of 18446744073709551615; it is already as high as it can go
I20260812 06:18:23.178038 16044 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:18:23.188412 16110 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.15.171.62:40781 every 8 connection(s)
I20260812 06:18:23.188452 16044 rpc_server.cc:307] RPC server started. Bound to: 127.15.171.62:40781
I20260812 06:18:23.191088 16111 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet 00000000000000000000000000000000. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:18:23.196557 16111 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P 0337355cc73748dc94052af289c968ae: Bootstrap starting.
I20260812 06:18:23.198906 16111 tablet_bootstrap.cc:654] T 00000000000000000000000000000000 P 0337355cc73748dc94052af289c968ae: Neither blocks nor log segments found. Creating new log.
I20260812 06:18:23.199851 16111 log.cc:826] T 00000000000000000000000000000000 P 0337355cc73748dc94052af289c968ae: Log is configured to *not* fsync() on all Append() calls
I20260812 06:18:23.201711 16111 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P 0337355cc73748dc94052af289c968ae: No bootstrap required, opened a new log
I20260812 06:18:23.204748 16111 raft_consensus.cc:359] T 00000000000000000000000000000000 P 0337355cc73748dc94052af289c968ae [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "0337355cc73748dc94052af289c968ae" member_type: VOTER }
I20260812 06:18:23.204927 16111 raft_consensus.cc:385] T 00000000000000000000000000000000 P 0337355cc73748dc94052af289c968ae [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:18:23.204995 16111 raft_consensus.cc:740] T 00000000000000000000000000000000 P 0337355cc73748dc94052af289c968ae [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: 0337355cc73748dc94052af289c968ae, State: Initialized, Role: FOLLOWER
I20260812 06:18:23.205595 16111 consensus_queue.cc:260] T 00000000000000000000000000000000 P 0337355cc73748dc94052af289c968ae [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: "0337355cc73748dc94052af289c968ae" member_type: VOTER }
I20260812 06:18:23.205760 16111 raft_consensus.cc:399] T 00000000000000000000000000000000 P 0337355cc73748dc94052af289c968ae [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:18:23.205828 16111 raft_consensus.cc:493] T 00000000000000000000000000000000 P 0337355cc73748dc94052af289c968ae [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:18:23.205951 16111 raft_consensus.cc:3060] T 00000000000000000000000000000000 P 0337355cc73748dc94052af289c968ae [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:18:23.206744 16111 raft_consensus.cc:515] T 00000000000000000000000000000000 P 0337355cc73748dc94052af289c968ae [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "0337355cc73748dc94052af289c968ae" member_type: VOTER }
I20260812 06:18:23.207178 16111 leader_election.cc:304] T 00000000000000000000000000000000 P 0337355cc73748dc94052af289c968ae [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: 0337355cc73748dc94052af289c968ae; no voters: 
I20260812 06:18:23.207523 16111 leader_election.cc:290] T 00000000000000000000000000000000 P 0337355cc73748dc94052af289c968ae [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:18:23.207674 16114 raft_consensus.cc:2804] T 00000000000000000000000000000000 P 0337355cc73748dc94052af289c968ae [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:18:23.207921 16114 raft_consensus.cc:697] T 00000000000000000000000000000000 P 0337355cc73748dc94052af289c968ae [term 1 LEADER]: Becoming Leader. State: Replica: 0337355cc73748dc94052af289c968ae, State: Running, Role: LEADER
I20260812 06:18:23.208377 16114 consensus_queue.cc:237] T 00000000000000000000000000000000 P 0337355cc73748dc94052af289c968ae [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: "0337355cc73748dc94052af289c968ae" member_type: VOTER }
I20260812 06:18:23.208566 16111 sys_catalog.cc:565] T 00000000000000000000000000000000 P 0337355cc73748dc94052af289c968ae [sys.catalog]: configured and running, proceeding with master startup.
I20260812 06:18:23.210333 16116 sys_catalog.cc:455] T 00000000000000000000000000000000 P 0337355cc73748dc94052af289c968ae [sys.catalog]: SysCatalogTable state changed. Reason: New leader 0337355cc73748dc94052af289c968ae. Latest consensus state: current_term: 1 leader_uuid: "0337355cc73748dc94052af289c968ae" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "0337355cc73748dc94052af289c968ae" member_type: VOTER } }
I20260812 06:18:23.210439 16116 sys_catalog.cc:458] T 00000000000000000000000000000000 P 0337355cc73748dc94052af289c968ae [sys.catalog]: This master's current role is: LEADER
I20260812 06:18:23.210387 16115 sys_catalog.cc:455] T 00000000000000000000000000000000 P 0337355cc73748dc94052af289c968ae [sys.catalog]: SysCatalogTable state changed. Reason: RaftConsensus started. Latest consensus state: current_term: 1 leader_uuid: "0337355cc73748dc94052af289c968ae" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "0337355cc73748dc94052af289c968ae" member_type: VOTER } }
I20260812 06:18:23.210490 16115 sys_catalog.cc:458] T 00000000000000000000000000000000 P 0337355cc73748dc94052af289c968ae [sys.catalog]: This master's current role is: LEADER
I20260812 06:18:23.210767 16126 catalog_manager.cc:1511] Loading table and tablet metadata into memory...
I20260812 06:18:23.210918 16044 internal_mini_cluster.cc:184] Waiting to initialize catalog manager on master 0
I20260812 06:18:23.213137 16126 catalog_manager.cc:1520] Initializing Kudu cluster ID...
I20260812 06:18:23.217628 16126 catalog_manager.cc:1383] Generated new cluster ID: 868bcbdb01d3479a8b9032b3a37fb565
I20260812 06:18:23.217701 16126 catalog_manager.cc:1531] Initializing Kudu internal certificate authority...
I20260812 06:18:23.226435 16126 catalog_manager.cc:1406] Generated new certificate authority record
I20260812 06:18:23.227278 16126 catalog_manager.cc:1540] Loading token signing keys...
I20260812 06:18:23.242712 16126 catalog_manager.cc:6092] T 00000000000000000000000000000000 P 0337355cc73748dc94052af289c968ae: Generated new TSK 0
I20260812 06:18:23.243498 16126 catalog_manager.cc:1550] Initializing in-progress tserver states...
I20260812 06:18:23.275635 16044 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:18:23.278340 16136 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:18:23.278532 16133 instance_detector.cc:116] could not retrieve AWS instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:18:23.278594 16044 server_base.cc:1061] running on GCE node
W20260812 06:18:23.278689 16134 instance_detector.cc:116] could not retrieve Azure instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:18:23.278888 16044 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:18:23.278932 16044 system_unsync_time.cc:38] NTP support is disabled. Clock error bounds will not be accurate. This configuration is not suitable for distributed clusters.
I20260812 06:18:23.278952 16044 hybrid_clock.cc:648] HybridClock initialized: now 1786515503278952 us; error 0 us; skew 500 ppm
I20260812 06:18:23.279826 16044 webserver.cc:533] Webserver started at http://127.15.171.1:32773/ using document root <none> and password file <none>
I20260812 06:18:23.279984 16044 fs_manager.cc:362] Metadata directory not provided
I20260812 06:18:23.280046 16044 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:18:23.280122 16044 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:18:23.280493 16044 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskSk6K39/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515503120097-16044-0/minicluster-data/ts-0-root/instance:
uuid: "35c65960fa7f47628551d5a0aa637595"
format_stamp: "Formatted at 2026-08-12 06:18:23 on dist-test-slave-f7th"
I20260812 06:18:23.281839 16044 fs_manager.cc:696] Time spent creating directory manager: real 0.001s	user 0.002s	sys 0.000s
I20260812 06:18:23.282725 16141 log_block_manager.cc:4127] Time spent loading block containers with low live blocks: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:18:23.282928 16044 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.001s	sys 0.000s
I20260812 06:18:23.282992 16044 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskSk6K39/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515503120097-16044-0/minicluster-data/ts-0-root
uuid: "35c65960fa7f47628551d5a0aa637595"
format_stamp: "Formatted at 2026-08-12 06:18:23 on dist-test-slave-f7th"
I20260812 06:18:23.283068 16044 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskSk6K39/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515503120097-16044-0/minicluster-data/ts-0-root
metadata directory: /tmp/dist-test-taskSk6K39/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515503120097-16044-0/minicluster-data/ts-0-root
1 data directories: /tmp/dist-test-taskSk6K39/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515503120097-16044-0/minicluster-data/ts-0-root/data
Total live blocks: 0
Total live bytes: 0
Total live bytes (after alignment): 0
Total number of LBM containers: 0 (0 full)
Did not check for missing blocks
Did not check for orphaned blocks
Total full LBM containers with extra space: 0 (0 repaired)
Total full LBM container extra space in bytes: 0 (0 repaired)
Total incomplete LBM containers: 0 (0 repaired)
Total LBM partial records: 0 (0 repaired)
Total corrupted LBM metadata records in RocksDB: 0 (0 repaired)
I20260812 06:18:23.295444 16044 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:18:23.296007 16044 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:18:23.296903 16044 txn_system_client.cc:432] TxnSystemClient initialization is disabled...
I20260812 06:18:23.297971 16044 ts_tablet_manager.cc:585] Loaded tablet metadata (0 total tablets, 0 live tablets)
I20260812 06:18:23.298063 16044 ts_tablet_manager.cc:531] Time spent load tablet metadata: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:18:23.298136 16044 ts_tablet_manager.cc:616] Registered 0 tablets
I20260812 06:18:23.298190 16044 ts_tablet_manager.cc:595] Time spent register tablets: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:18:23.305105 16044 rpc_server.cc:307] RPC server started. Bound to: 127.15.171.1:38203
I20260812 06:18:23.305133 16204 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.15.171.1:38203 every 8 connection(s)
I20260812 06:18:23.323407 16205 heartbeater.cc:344] Connected to a master server at 127.15.171.62:40781
I20260812 06:18:23.323764 16205 heartbeater.cc:461] Registering TS with master...
I20260812 06:18:23.324314 16205 heartbeater.cc:507] Master 127.15.171.62:40781 requested a full tablet report, sending...
I20260812 06:18:23.325919 16075 ts_manager.cc:194] Registered new tserver with Master: 35c65960fa7f47628551d5a0aa637595 (127.15.171.1:38203)
I20260812 06:18:23.326759 16044 internal_mini_cluster.cc:371] 1 TS(s) registered with all masters after 0.020896968s
I20260812 06:18:23.327428 16075 master_service.cc:502] Signed X509 certificate for tserver {username='slave'} at 127.0.0.1:52228
I20260812 06:18:23.338225 16075 catalog_manager.cc:2283] Servicing CreateTable request from {username='slave'} at 127.0.0.1:52242:
name: "heavy-update-compaction-test"
schema {
  columns {
    name: "key"
    type: INT64
    is_key: true
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_a"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_b"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_c"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_d"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_e"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
}
num_replicas: 1
split_rows_range_bounds {
}
partition_schema {
  range_schema {
  }
}
I20260812 06:18:23.352360 16169 tablet_service.cc:1511] Processing CreateTablet for tablet c82eb4d1b7da4939893e809d46274ee2 (DEFAULT_TABLE table=heavy-update-compaction-test [id=8df06637c45e4dccb382ccd9fe2b9287]), partition=
I20260812 06:18:23.352842 16169 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet c82eb4d1b7da4939893e809d46274ee2. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:18:23.355433 16217 tablet_bootstrap.cc:492] T c82eb4d1b7da4939893e809d46274ee2 P 35c65960fa7f47628551d5a0aa637595: Bootstrap starting.
I20260812 06:18:23.356412 16217 tablet_bootstrap.cc:654] T c82eb4d1b7da4939893e809d46274ee2 P 35c65960fa7f47628551d5a0aa637595: Neither blocks nor log segments found. Creating new log.
I20260812 06:18:23.357430 16217 tablet_bootstrap.cc:492] T c82eb4d1b7da4939893e809d46274ee2 P 35c65960fa7f47628551d5a0aa637595: No bootstrap required, opened a new log
I20260812 06:18:23.357527 16217 ts_tablet_manager.cc:1403] T c82eb4d1b7da4939893e809d46274ee2 P 35c65960fa7f47628551d5a0aa637595: Time spent bootstrapping tablet: real 0.002s	user 0.002s	sys 0.000s
I20260812 06:18:23.357993 16217 raft_consensus.cc:359] T c82eb4d1b7da4939893e809d46274ee2 P 35c65960fa7f47628551d5a0aa637595 [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "35c65960fa7f47628551d5a0aa637595" member_type: VOTER last_known_addr { host: "127.15.171.1" port: 38203 } }
I20260812 06:18:23.358095 16217 raft_consensus.cc:385] T c82eb4d1b7da4939893e809d46274ee2 P 35c65960fa7f47628551d5a0aa637595 [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:18:23.358127 16217 raft_consensus.cc:740] T c82eb4d1b7da4939893e809d46274ee2 P 35c65960fa7f47628551d5a0aa637595 [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: 35c65960fa7f47628551d5a0aa637595, State: Initialized, Role: FOLLOWER
I20260812 06:18:23.358279 16217 consensus_queue.cc:260] T c82eb4d1b7da4939893e809d46274ee2 P 35c65960fa7f47628551d5a0aa637595 [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: "35c65960fa7f47628551d5a0aa637595" member_type: VOTER last_known_addr { host: "127.15.171.1" port: 38203 } }
I20260812 06:18:23.358358 16217 raft_consensus.cc:399] T c82eb4d1b7da4939893e809d46274ee2 P 35c65960fa7f47628551d5a0aa637595 [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:18:23.358441 16217 raft_consensus.cc:493] T c82eb4d1b7da4939893e809d46274ee2 P 35c65960fa7f47628551d5a0aa637595 [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:18:23.358494 16217 raft_consensus.cc:3060] T c82eb4d1b7da4939893e809d46274ee2 P 35c65960fa7f47628551d5a0aa637595 [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:18:23.359534 16217 raft_consensus.cc:515] T c82eb4d1b7da4939893e809d46274ee2 P 35c65960fa7f47628551d5a0aa637595 [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "35c65960fa7f47628551d5a0aa637595" member_type: VOTER last_known_addr { host: "127.15.171.1" port: 38203 } }
I20260812 06:18:23.359781 16217 leader_election.cc:304] T c82eb4d1b7da4939893e809d46274ee2 P 35c65960fa7f47628551d5a0aa637595 [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: 35c65960fa7f47628551d5a0aa637595; no voters: 
I20260812 06:18:23.359985 16217 leader_election.cc:290] T c82eb4d1b7da4939893e809d46274ee2 P 35c65960fa7f47628551d5a0aa637595 [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:18:23.360126 16219 raft_consensus.cc:2804] T c82eb4d1b7da4939893e809d46274ee2 P 35c65960fa7f47628551d5a0aa637595 [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:18:23.360350 16219 raft_consensus.cc:697] T c82eb4d1b7da4939893e809d46274ee2 P 35c65960fa7f47628551d5a0aa637595 [term 1 LEADER]: Becoming Leader. State: Replica: 35c65960fa7f47628551d5a0aa637595, State: Running, Role: LEADER
I20260812 06:18:23.360348 16217 ts_tablet_manager.cc:1434] T c82eb4d1b7da4939893e809d46274ee2 P 35c65960fa7f47628551d5a0aa637595: Time spent starting tablet: real 0.003s	user 0.003s	sys 0.000s
I20260812 06:18:23.360538 16219 consensus_queue.cc:237] T c82eb4d1b7da4939893e809d46274ee2 P 35c65960fa7f47628551d5a0aa637595 [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: "35c65960fa7f47628551d5a0aa637595" member_type: VOTER last_known_addr { host: "127.15.171.1" port: 38203 } }
I20260812 06:18:23.360683 16205 heartbeater.cc:499] Master 127.15.171.62:40781 was elected leader, sending a full tablet report...
I20260812 06:18:23.363163 16075 catalog_manager.cc:5719] T c82eb4d1b7da4939893e809d46274ee2 P 35c65960fa7f47628551d5a0aa637595 reported cstate change: term changed from 0 to 1, leader changed from <none> to 35c65960fa7f47628551d5a0aa637595 (127.15.171.1). New cstate: current_term: 1 leader_uuid: "35c65960fa7f47628551d5a0aa637595" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "35c65960fa7f47628551d5a0aa637595" member_type: VOTER last_known_addr { host: "127.15.171.1" port: 38203 } health_report { overall_health: HEALTHY } } }
I20260812 06:18:23.439057 16044 heavy-update-compaction-itest.cc:215] Time spent inserting: real 0.066s	user 0.017s	sys 0.012s
I20260812 06:18:23.556538 16206 maintenance_manager.cc:419] P 35c65960fa7f47628551d5a0aa637595: Scheduling FlushMRSOp(c82eb4d1b7da4939893e809d46274ee2): perf score=15.086190
I20260812 06:18:23.761052 16146 maintenance_manager.cc:643] P 35c65960fa7f47628551d5a0aa637595: FlushMRSOp(c82eb4d1b7da4939893e809d46274ee2) complete. Timing: real 0.204s	user 0.128s	sys 0.036s Metrics: {"bytes_written":12307490,"cfile_init":1,"compiler_manager_pool.queue_time_us":238,"delete_count":0,"dirs.queue_time_us":42,"dirs.run_cpu_time_us":170,"dirs.run_wall_time_us":853,"drs_written":1,"lbm_read_time_us":74,"lbm_reads_lt_1ms":4,"lbm_write_time_us":54000,"lbm_writes_1-10_ms":2,"lbm_writes_lt_1ms":655,"peak_mem_usage":0,"reinsert_count":0,"rows_written":103,"thread_start_us":123,"threads_started":1,"update_count":1500}
I20260812 06:18:23.762295 16206 maintenance_manager.cc:419] P 35c65960fa7f47628551d5a0aa637595: Scheduling LogGCOp(c82eb4d1b7da4939893e809d46274ee2): free 8725963 bytes of WAL
I20260812 06:18:23.762657 16146 log_reader.cc:385] T c82eb4d1b7da4939893e809d46274ee2: removed 1 log segments from log reader
I20260812 06:18:23.762780 16146 log.cc:1079] T c82eb4d1b7da4939893e809d46274ee2 P 35c65960fa7f47628551d5a0aa637595: Deleting log segment in path: /tmp/dist-test-taskSk6K39/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515503120097-16044-0/minicluster-data/ts-0-root/wals/c82eb4d1b7da4939893e809d46274ee2/wal-000000001 (ops 1-6)
I20260812 06:18:23.765085 16146 maintenance_manager.cc:643] P 35c65960fa7f47628551d5a0aa637595: LogGCOp(c82eb4d1b7da4939893e809d46274ee2) complete. Timing: real 0.003s	user 0.000s	sys 0.001s Metrics: {}
I20260812 06:18:23.765450 16206 maintenance_manager.cc:419] P 35c65960fa7f47628551d5a0aa637595: Scheduling UndoDeltaBlockGCOp(c82eb4d1b7da4939893e809d46274ee2): 12308958 bytes on disk
I20260812 06:18:23.766067 16146 maintenance_manager.cc:643] P 35c65960fa7f47628551d5a0aa637595: UndoDeltaBlockGCOp(c82eb4d1b7da4939893e809d46274ee2) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":65,"lbm_reads_lt_1ms":4}
I20260812 06:18:23.766544 16206 maintenance_manager.cc:419] P 35c65960fa7f47628551d5a0aa637595: Scheduling FlushDeltaMemStoresOp(c82eb4d1b7da4939893e809d46274ee2): perf score=3.181125
I20260812 06:18:23.795120 16146 maintenance_manager.cc:643] P 35c65960fa7f47628551d5a0aa637595: FlushDeltaMemStoresOp(c82eb4d1b7da4939893e809d46274ee2) complete. Timing: real 0.028s	user 0.010s	sys 0.004s Metrics: {"bytes_written":4512903,"delete_count":0,"lbm_write_time_us":8518,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":112,"reinsert_count":0,"update_count":550}
I20260812 06:18:23.795689 16206 maintenance_manager.cc:419] P 35c65960fa7f47628551d5a0aa637595: Scheduling FlushDeltaMemStoresOp(c82eb4d1b7da4939893e809d46274ee2): perf score=2.188937
I20260812 06:18:23.807489 16146 maintenance_manager.cc:643] P 35c65960fa7f47628551d5a0aa637595: FlushDeltaMemStoresOp(c82eb4d1b7da4939893e809d46274ee2) complete. Timing: real 0.012s	user 0.002s	sys 0.008s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":4481,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:18:23.808094 16206 maintenance_manager.cc:419] P 35c65960fa7f47628551d5a0aa637595: Scheduling MajorDeltaCompactionOp(c82eb4d1b7da4939893e809d46274ee2): perf score=1.000000
I20260812 06:18:23.977355 16146 maintenance_manager.cc:643] P 35c65960fa7f47628551d5a0aa637595: MajorDeltaCompactionOp(c82eb4d1b7da4939893e809d46274ee2) complete. Timing: real 0.169s	user 0.133s	sys 0.029s Metrics: {"cfile_cache_miss":533,"cfile_cache_miss_bytes":24733833,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":530,"lbm_read_time_us":10562,"lbm_reads_lt_1ms":569,"lbm_write_time_us":29815,"lbm_writes_lt_1ms":543,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":896,"thread_start_us":262,"threads_started":5,"update_count":2500}
I20260812 06:18:23.977880 16206 maintenance_manager.cc:419] P 35c65960fa7f47628551d5a0aa637595: Scheduling FlushDeltaMemStoresOp(c82eb4d1b7da4939893e809d46274ee2): perf score=10.126437
I20260812 06:18:24.025153 16146 maintenance_manager.cc:643] P 35c65960fa7f47628551d5a0aa637595: FlushDeltaMemStoresOp(c82eb4d1b7da4939893e809d46274ee2) complete. Timing: real 0.047s	user 0.029s	sys 0.008s Metrics: {"bytes_written":12307492,"delete_count":0,"lbm_write_time_us":16797,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:18:24.025702 16206 maintenance_manager.cc:419] P 35c65960fa7f47628551d5a0aa637595: Scheduling FlushDeltaMemStoresOp(c82eb4d1b7da4939893e809d46274ee2): perf score=2.188937
I20260812 06:18:24.039170 16146 maintenance_manager.cc:643] P 35c65960fa7f47628551d5a0aa637595: FlushDeltaMemStoresOp(c82eb4d1b7da4939893e809d46274ee2) complete. Timing: real 0.012s	user 0.010s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4376,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:24.039724 16206 maintenance_manager.cc:419] P 35c65960fa7f47628551d5a0aa637595: Scheduling MajorDeltaCompactionOp(c82eb4d1b7da4939893e809d46274ee2): perf score=1.000000
I20260812 06:18:24.165556 16146 maintenance_manager.cc:643] P 35c65960fa7f47628551d5a0aa637595: MajorDeltaCompactionOp(c82eb4d1b7da4939893e809d46274ee2) complete. Timing: real 0.126s	user 0.104s	sys 0.021s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20631314,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":134,"lbm_read_time_us":8844,"lbm_reads_lt_1ms":472,"lbm_write_time_us":25124,"lbm_writes_lt_1ms":443,"mutex_wait_us":46,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":896,"update_count":2000}
I20260812 06:18:24.166075 16206 maintenance_manager.cc:419] P 35c65960fa7f47628551d5a0aa637595: Scheduling FlushDeltaMemStoresOp(c82eb4d1b7da4939893e809d46274ee2): perf score=6.157687
I20260812 06:18:24.191231 16146 maintenance_manager.cc:643] P 35c65960fa7f47628551d5a0aa637595: FlushDeltaMemStoresOp(c82eb4d1b7da4939893e809d46274ee2) complete. Timing: real 0.025s	user 0.019s	sys 0.003s Metrics: {"bytes_written":8205078,"delete_count":0,"lbm_write_time_us":10234,"lbm_writes_lt_1ms":203,"reinsert_count":0,"update_count":1000}
I20260812 06:18:24.191792 16206 maintenance_manager.cc:419] P 35c65960fa7f47628551d5a0aa637595: Scheduling MajorDeltaCompactionOp(c82eb4d1b7da4939893e809d46274ee2): perf score=1.000000
I20260812 06:18:24.282675 16146 maintenance_manager.cc:643] P 35c65960fa7f47628551d5a0aa637595: MajorDeltaCompactionOp(c82eb4d1b7da4939893e809d46274ee2) complete. Timing: real 0.091s	user 0.074s	sys 0.016s Metrics: {"cfile_cache_miss":231,"cfile_cache_miss_bytes":12426369,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":1,"delta_iterators_relevant":1,"dirs.queue_time_us":160,"lbm_read_time_us":5594,"lbm_reads_lt_1ms":267,"lbm_write_time_us":15596,"lbm_writes_lt_1ms":243,"mutex_wait_us":16,"peak_mem_usage":25836184,"reinsert_count":0,"spinlock_wait_cycles":1920,"update_count":1000}
I20260812 06:18:24.283195 16206 maintenance_manager.cc:419] P 35c65960fa7f47628551d5a0aa637595: Scheduling FlushDeltaMemStoresOp(c82eb4d1b7da4939893e809d46274ee2): perf score=6.157687
I20260812 06:18:24.314582 16146 maintenance_manager.cc:643] P 35c65960fa7f47628551d5a0aa637595: FlushDeltaMemStoresOp(c82eb4d1b7da4939893e809d46274ee2) complete. Timing: real 0.031s	user 0.014s	sys 0.007s Metrics: {"bytes_written":8205078,"delete_count":0,"lbm_write_time_us":10079,"lbm_writes_lt_1ms":203,"reinsert_count":0,"update_count":1000}
I20260812 06:18:24.315068 16206 maintenance_manager.cc:419] P 35c65960fa7f47628551d5a0aa637595: Scheduling FlushDeltaMemStoresOp(c82eb4d1b7da4939893e809d46274ee2): perf score=2.188937
I20260812 06:18:24.331149 16146 maintenance_manager.cc:643] P 35c65960fa7f47628551d5a0aa637595: FlushDeltaMemStoresOp(c82eb4d1b7da4939893e809d46274ee2) complete. Timing: real 0.016s	user 0.010s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4708,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:24.331801 16206 maintenance_manager.cc:419] P 35c65960fa7f47628551d5a0aa637595: Scheduling MajorDeltaCompactionOp(c82eb4d1b7da4939893e809d46274ee2): perf score=1.000000
I20260812 06:18:24.451186 16146 maintenance_manager.cc:643] P 35c65960fa7f47628551d5a0aa637595: MajorDeltaCompactionOp(c82eb4d1b7da4939893e809d46274ee2) complete. Timing: real 0.119s	user 0.093s	sys 0.019s Metrics: {"cfile_cache_miss":332,"cfile_cache_miss_bytes":16528900,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":520,"lbm_read_time_us":7460,"lbm_reads_lt_1ms":372,"lbm_write_time_us":19625,"lbm_writes_lt_1ms":343,"mutex_wait_us":247,"peak_mem_usage":38262756,"reinsert_count":0,"spinlock_wait_cycles":2048,"update_count":1500}
I20260812 06:18:24.451717 16206 maintenance_manager.cc:419] P 35c65960fa7f47628551d5a0aa637595: Scheduling FlushDeltaMemStoresOp(c82eb4d1b7da4939893e809d46274ee2): perf score=7.149875
I20260812 06:18:24.474247 16146 maintenance_manager.cc:643] P 35c65960fa7f47628551d5a0aa637595: FlushDeltaMemStoresOp(c82eb4d1b7da4939893e809d46274ee2) complete. Timing: real 0.022s	user 0.011s	sys 0.008s Metrics: {"bytes_written":8615323,"delete_count":0,"lbm_write_time_us":9486,"lbm_writes_lt_1ms":213,"reinsert_count":0,"update_count":1050}
I20260812 06:18:24.474648 16206 maintenance_manager.cc:419] P 35c65960fa7f47628551d5a0aa637595: Scheduling FlushDeltaMemStoresOp(c82eb4d1b7da4939893e809d46274ee2): perf score=2.188937
I20260812 06:18:24.489228 16146 maintenance_manager.cc:643] P 35c65960fa7f47628551d5a0aa637595: FlushDeltaMemStoresOp(c82eb4d1b7da4939893e809d46274ee2) complete. Timing: real 0.014s	user 0.002s	sys 0.007s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":4303,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:18:24.489733 16206 maintenance_manager.cc:419] P 35c65960fa7f47628551d5a0aa637595: Scheduling MajorDeltaCompactionOp(c82eb4d1b7da4939893e809d46274ee2): perf score=1.000000
I20260812 06:18:24.608508 16146 maintenance_manager.cc:643] P 35c65960fa7f47628551d5a0aa637595: MajorDeltaCompactionOp(c82eb4d1b7da4939893e809d46274ee2) complete. Timing: real 0.119s	user 0.093s	sys 0.024s Metrics: {"cfile_cache_miss":332,"cfile_cache_miss_bytes":16528891,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":636,"lbm_read_time_us":8562,"lbm_reads_lt_1ms":372,"lbm_write_time_us":20947,"lbm_writes_lt_1ms":343,"mutex_wait_us":286,"peak_mem_usage":38262756,"reinsert_count":0,"spinlock_wait_cycles":2304,"update_count":1500}
I20260812 06:18:24.608970 16206 maintenance_manager.cc:419] P 35c65960fa7f47628551d5a0aa637595: Scheduling FlushDeltaMemStoresOp(c82eb4d1b7da4939893e809d46274ee2): perf score=7.149875
I20260812 06:18:24.636487 16146 maintenance_manager.cc:643] P 35c65960fa7f47628551d5a0aa637595: FlushDeltaMemStoresOp(c82eb4d1b7da4939893e809d46274ee2) complete. Timing: real 0.027s	user 0.019s	sys 0.008s Metrics: {"bytes_written":8615323,"delete_count":0,"lbm_write_time_us":11482,"lbm_writes_lt_1ms":213,"reinsert_count":0,"update_count":1050}
I20260812 06:18:24.636958 16206 maintenance_manager.cc:419] P 35c65960fa7f47628551d5a0aa637595: Scheduling FlushDeltaMemStoresOp(c82eb4d1b7da4939893e809d46274ee2): perf score=2.188937
I20260812 06:18:24.646581 16146 maintenance_manager.cc:643] P 35c65960fa7f47628551d5a0aa637595: FlushDeltaMemStoresOp(c82eb4d1b7da4939893e809d46274ee2) complete. Timing: real 0.009s	user 0.004s	sys 0.004s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3641,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:18:24.647167 16206 maintenance_manager.cc:419] P 35c65960fa7f47628551d5a0aa637595: Scheduling MajorDeltaCompactionOp(c82eb4d1b7da4939893e809d46274ee2): perf score=1.000000
I20260812 06:18:24.763113 16146 maintenance_manager.cc:643] P 35c65960fa7f47628551d5a0aa637595: MajorDeltaCompactionOp(c82eb4d1b7da4939893e809d46274ee2) complete. Timing: real 0.115s	user 0.104s	sys 0.009s Metrics: {"cfile_cache_miss":332,"cfile_cache_miss_bytes":16528891,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":760,"lbm_read_time_us":6930,"lbm_reads_lt_1ms":372,"lbm_write_time_us":20388,"lbm_writes_lt_1ms":343,"mutex_wait_us":213,"peak_mem_usage":38262756,"reinsert_count":0,"update_count":1500}
I20260812 06:18:24.763669 16206 maintenance_manager.cc:419] P 35c65960fa7f47628551d5a0aa637595: Scheduling FlushDeltaMemStoresOp(c82eb4d1b7da4939893e809d46274ee2): perf score=6.157687
I20260812 06:18:24.806607 16146 maintenance_manager.cc:643] P 35c65960fa7f47628551d5a0aa637595: FlushDeltaMemStoresOp(c82eb4d1b7da4939893e809d46274ee2) complete. Timing: real 0.043s	user 0.007s	sys 0.016s Metrics: {"bytes_written":8205078,"delete_count":0,"lbm_write_time_us":12399,"lbm_writes_lt_1ms":203,"reinsert_count":0,"update_count":1000}
I20260812 06:18:24.807152 16206 maintenance_manager.cc:419] P 35c65960fa7f47628551d5a0aa637595: Scheduling FlushDeltaMemStoresOp(c82eb4d1b7da4939893e809d46274ee2): perf score=2.188937
I20260812 06:18:24.824306 16146 maintenance_manager.cc:643] P 35c65960fa7f47628551d5a0aa637595: FlushDeltaMemStoresOp(c82eb4d1b7da4939893e809d46274ee2) complete. Timing: real 0.017s	user 0.003s	sys 0.013s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6755,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:24.824899 16206 maintenance_manager.cc:419] P 35c65960fa7f47628551d5a0aa637595: Scheduling MajorDeltaCompactionOp(c82eb4d1b7da4939893e809d46274ee2): perf score=1.000000
I20260812 06:18:24.943331 16146 maintenance_manager.cc:643] P 35c65960fa7f47628551d5a0aa637595: MajorDeltaCompactionOp(c82eb4d1b7da4939893e809d46274ee2) complete. Timing: real 0.118s	user 0.076s	sys 0.037s Metrics: {"cfile_cache_miss":332,"cfile_cache_miss_bytes":16528900,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":775,"lbm_read_time_us":7232,"lbm_reads_lt_1ms":372,"lbm_write_time_us":21023,"lbm_writes_lt_1ms":343,"peak_mem_usage":38262756,"reinsert_count":0,"spinlock_wait_cycles":896,"update_count":1500}
I20260812 06:18:24.943853 16206 maintenance_manager.cc:419] P 35c65960fa7f47628551d5a0aa637595: Scheduling FlushDeltaMemStoresOp(c82eb4d1b7da4939893e809d46274ee2): perf score=7.149875
I20260812 06:18:24.974385 16146 maintenance_manager.cc:643] P 35c65960fa7f47628551d5a0aa637595: FlushDeltaMemStoresOp(c82eb4d1b7da4939893e809d46274ee2) complete. Timing: real 0.030s	user 0.014s	sys 0.013s Metrics: {"bytes_written":8615323,"delete_count":0,"lbm_write_time_us":12219,"lbm_writes_lt_1ms":213,"reinsert_count":0,"update_count":1050}
I20260812 06:18:24.974905 16206 maintenance_manager.cc:419] P 35c65960fa7f47628551d5a0aa637595: Scheduling FlushDeltaMemStoresOp(c82eb4d1b7da4939893e809d46274ee2): perf score=2.188937
I20260812 06:18:24.992393 16146 maintenance_manager.cc:643] P 35c65960fa7f47628551d5a0aa637595: FlushDeltaMemStoresOp(c82eb4d1b7da4939893e809d46274ee2) complete. Timing: real 0.017s	user 0.009s	sys 0.004s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":5436,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:18:24.992834 16206 maintenance_manager.cc:419] P 35c65960fa7f47628551d5a0aa637595: Scheduling MajorDeltaCompactionOp(c82eb4d1b7da4939893e809d46274ee2): perf score=1.000000
I20260812 06:18:25.110808 16146 maintenance_manager.cc:643] P 35c65960fa7f47628551d5a0aa637595: MajorDeltaCompactionOp(c82eb4d1b7da4939893e809d46274ee2) complete. Timing: real 0.118s	user 0.083s	sys 0.024s Metrics: {"cfile_cache_miss":332,"cfile_cache_miss_bytes":16528891,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":747,"lbm_read_time_us":5880,"lbm_reads_lt_1ms":364,"lbm_write_time_us":19044,"lbm_writes_lt_1ms":343,"mutex_wait_us":471,"peak_mem_usage":38262756,"reinsert_count":0,"update_count":1500}
I20260812 06:18:25.111409 16206 maintenance_manager.cc:419] P 35c65960fa7f47628551d5a0aa637595: Scheduling FlushDeltaMemStoresOp(c82eb4d1b7da4939893e809d46274ee2): perf score=10.126437
I20260812 06:18:25.164817 16146 maintenance_manager.cc:643] P 35c65960fa7f47628551d5a0aa637595: FlushDeltaMemStoresOp(c82eb4d1b7da4939893e809d46274ee2) complete. Timing: real 0.053s	user 0.034s	sys 0.008s Metrics: {"bytes_written":12307493,"delete_count":0,"lbm_write_time_us":19938,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":302,"reinsert_count":0,"update_count":1500}
I20260812 06:18:25.165375 16206 maintenance_manager.cc:419] P 35c65960fa7f47628551d5a0aa637595: Scheduling FlushDeltaMemStoresOp(c82eb4d1b7da4939893e809d46274ee2): perf score=2.188937
I20260812 06:18:25.177656 16146 maintenance_manager.cc:643] P 35c65960fa7f47628551d5a0aa637595: FlushDeltaMemStoresOp(c82eb4d1b7da4939893e809d46274ee2) complete. Timing: real 0.012s	user 0.010s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4306,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:25.178567 16206 maintenance_manager.cc:419] P 35c65960fa7f47628551d5a0aa637595: Scheduling FlushMRSOp(c82eb4d1b7da4939893e809d46274ee2): perf score=1.000000
I20260812 06:18:25.215754 16146 maintenance_manager.cc:643] P 35c65960fa7f47628551d5a0aa637595: FlushMRSOp(c82eb4d1b7da4939893e809d46274ee2) complete. Timing: real 0.037s	user 0.030s	sys 0.004s Metrics: {"bytes_written":1234474,"cfile_init":1,"dirs.queue_time_us":56,"dirs.run_cpu_time_us":228,"dirs.run_wall_time_us":1280,"drs_written":1,"lbm_read_time_us":41,"lbm_reads_lt_1ms":4,"lbm_write_time_us":2319,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":30}
I20260812 06:18:25.216611 16206 maintenance_manager.cc:419] P 35c65960fa7f47628551d5a0aa637595: Scheduling LogGCOp(c82eb4d1b7da4939893e809d46274ee2): free 124257230 bytes of WAL
I20260812 06:18:25.216814 16146 log_reader.cc:385] T c82eb4d1b7da4939893e809d46274ee2: removed 12 log segments from log reader
I20260812 06:18:25.216854 16146 log.cc:1079] T c82eb4d1b7da4939893e809d46274ee2 P 35c65960fa7f47628551d5a0aa637595: Deleting log segment in path: /tmp/dist-test-taskSk6K39/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515503120097-16044-0/minicluster-data/ts-0-root/wals/c82eb4d1b7da4939893e809d46274ee2/wal-000000002 (ops 7-11)
I20260812 06:18:25.216892 16146 log.cc:1079] T c82eb4d1b7da4939893e809d46274ee2 P 35c65960fa7f47628551d5a0aa637595: Deleting log segment in path: /tmp/dist-test-taskSk6K39/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515503120097-16044-0/minicluster-data/ts-0-root/wals/c82eb4d1b7da4939893e809d46274ee2/wal-000000003 (ops 12-16)
I20260812 06:18:25.216917 16146 log.cc:1079] T c82eb4d1b7da4939893e809d46274ee2 P 35c65960fa7f47628551d5a0aa637595: Deleting log segment in path: /tmp/dist-test-taskSk6K39/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515503120097-16044-0/minicluster-data/ts-0-root/wals/c82eb4d1b7da4939893e809d46274ee2/wal-000000004 (ops 17-21)
I20260812 06:18:25.216936 16146 log.cc:1079] T c82eb4d1b7da4939893e809d46274ee2 P 35c65960fa7f47628551d5a0aa637595: Deleting log segment in path: /tmp/dist-test-taskSk6K39/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515503120097-16044-0/minicluster-data/ts-0-root/wals/c82eb4d1b7da4939893e809d46274ee2/wal-000000005 (ops 22-26)
I20260812 06:18:25.216958 16146 log.cc:1079] T c82eb4d1b7da4939893e809d46274ee2 P 35c65960fa7f47628551d5a0aa637595: Deleting log segment in path: /tmp/dist-test-taskSk6K39/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515503120097-16044-0/minicluster-data/ts-0-root/wals/c82eb4d1b7da4939893e809d46274ee2/wal-000000006 (ops 27-30)
I20260812 06:18:25.216980 16146 log.cc:1079] T c82eb4d1b7da4939893e809d46274ee2 P 35c65960fa7f47628551d5a0aa637595: Deleting log segment in path: /tmp/dist-test-taskSk6K39/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515503120097-16044-0/minicluster-data/ts-0-root/wals/c82eb4d1b7da4939893e809d46274ee2/wal-000000007 (ops 31-35)
I20260812 06:18:25.217005 16146 log.cc:1079] T c82eb4d1b7da4939893e809d46274ee2 P 35c65960fa7f47628551d5a0aa637595: Deleting log segment in path: /tmp/dist-test-taskSk6K39/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515503120097-16044-0/minicluster-data/ts-0-root/wals/c82eb4d1b7da4939893e809d46274ee2/wal-000000008 (ops 36-40)
I20260812 06:18:25.217025 16146 log.cc:1079] T c82eb4d1b7da4939893e809d46274ee2 P 35c65960fa7f47628551d5a0aa637595: Deleting log segment in path: /tmp/dist-test-taskSk6K39/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515503120097-16044-0/minicluster-data/ts-0-root/wals/c82eb4d1b7da4939893e809d46274ee2/wal-000000009 (ops 41-45)
I20260812 06:18:25.217046 16146 log.cc:1079] T c82eb4d1b7da4939893e809d46274ee2 P 35c65960fa7f47628551d5a0aa637595: Deleting log segment in path: /tmp/dist-test-taskSk6K39/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515503120097-16044-0/minicluster-data/ts-0-root/wals/c82eb4d1b7da4939893e809d46274ee2/wal-000000010 (ops 46-50)
I20260812 06:18:25.217068 16146 log.cc:1079] T c82eb4d1b7da4939893e809d46274ee2 P 35c65960fa7f47628551d5a0aa637595: Deleting log segment in path: /tmp/dist-test-taskSk6K39/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515503120097-16044-0/minicluster-data/ts-0-root/wals/c82eb4d1b7da4939893e809d46274ee2/wal-000000011 (ops 51-55)
I20260812 06:18:25.217099 16146 log.cc:1079] T c82eb4d1b7da4939893e809d46274ee2 P 35c65960fa7f47628551d5a0aa637595: Deleting log segment in path: /tmp/dist-test-taskSk6K39/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515503120097-16044-0/minicluster-data/ts-0-root/wals/c82eb4d1b7da4939893e809d46274ee2/wal-000000012 (ops 56-60)
I20260812 06:18:25.217123 16146 log.cc:1079] T c82eb4d1b7da4939893e809d46274ee2 P 35c65960fa7f47628551d5a0aa637595: Deleting log segment in path: /tmp/dist-test-taskSk6K39/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515503120097-16044-0/minicluster-data/ts-0-root/wals/c82eb4d1b7da4939893e809d46274ee2/wal-000000013 (ops 61-65)
I20260812 06:18:25.242865 16146 maintenance_manager.cc:643] P 35c65960fa7f47628551d5a0aa637595: LogGCOp(c82eb4d1b7da4939893e809d46274ee2) complete. Timing: real 0.026s	user 0.000s	sys 0.023s Metrics: {}
I20260812 06:18:25.243407 16206 maintenance_manager.cc:419] P 35c65960fa7f47628551d5a0aa637595: Scheduling UndoDeltaBlockGCOp(c82eb4d1b7da4939893e809d46274ee2): 473 bytes on disk
I20260812 06:18:25.243983 16146 maintenance_manager.cc:643] P 35c65960fa7f47628551d5a0aa637595: UndoDeltaBlockGCOp(c82eb4d1b7da4939893e809d46274ee2) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":49,"lbm_reads_lt_1ms":4}
I20260812 06:18:25.244415 16206 maintenance_manager.cc:419] P 35c65960fa7f47628551d5a0aa637595: Scheduling FlushDeltaMemStoresOp(c82eb4d1b7da4939893e809d46274ee2): perf score=3.181125
I20260812 06:18:25.257746 16146 maintenance_manager.cc:643] P 35c65960fa7f47628551d5a0aa637595: FlushDeltaMemStoresOp(c82eb4d1b7da4939893e809d46274ee2) complete. Timing: real 0.013s	user 0.010s	sys 0.001s Metrics: {"bytes_written":4512903,"delete_count":0,"lbm_write_time_us":4949,"lbm_writes_lt_1ms":113,"reinsert_count":0,"update_count":550}
I20260812 06:18:25.258140 16206 maintenance_manager.cc:419] P 35c65960fa7f47628551d5a0aa637595: Scheduling LogGCOp(c82eb4d1b7da4939893e809d46274ee2): free 12017932 bytes of WAL
I20260812 06:18:25.258299 16146 log_reader.cc:385] T c82eb4d1b7da4939893e809d46274ee2: removed 1 log segments from log reader
I20260812 06:18:25.258337 16146 log.cc:1079] T c82eb4d1b7da4939893e809d46274ee2 P 35c65960fa7f47628551d5a0aa637595: Deleting log segment in path: /tmp/dist-test-taskSk6K39/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515503120097-16044-0/minicluster-data/ts-0-root/wals/c82eb4d1b7da4939893e809d46274ee2/wal-000000014 (ops 66-70)
I20260812 06:18:25.260339 16146 maintenance_manager.cc:643] P 35c65960fa7f47628551d5a0aa637595: LogGCOp(c82eb4d1b7da4939893e809d46274ee2) complete. Timing: real 0.002s	user 0.000s	sys 0.001s Metrics: {}
I20260812 06:18:25.260582 16206 maintenance_manager.cc:419] P 35c65960fa7f47628551d5a0aa637595: Scheduling FlushDeltaMemStoresOp(c82eb4d1b7da4939893e809d46274ee2): perf score=2.188937
I20260812 06:18:25.270345 16146 maintenance_manager.cc:643] P 35c65960fa7f47628551d5a0aa637595: FlushDeltaMemStoresOp(c82eb4d1b7da4939893e809d46274ee2) complete. Timing: real 0.010s	user 0.002s	sys 0.005s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3307,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:18:25.270926 16206 maintenance_manager.cc:419] P 35c65960fa7f47628551d5a0aa637595: Scheduling MajorDeltaCompactionOp(c82eb4d1b7da4939893e809d46274ee2): perf score=1.000000
I20260812 06:18:25.445940 16146 maintenance_manager.cc:643] P 35c65960fa7f47628551d5a0aa637595: MajorDeltaCompactionOp(c82eb4d1b7da4939893e809d46274ee2) complete. Timing: real 0.175s	user 0.120s	sys 0.044s Metrics: {"cfile_cache_miss":634,"cfile_cache_miss_bytes":28836367,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":474,"lbm_read_time_us":11380,"lbm_reads_lt_1ms":674,"lbm_write_time_us":33074,"lbm_writes_lt_1ms":643,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":896,"thread_start_us":79,"threads_started":1,"update_count":3000}
I20260812 06:18:25.446703 16206 maintenance_manager.cc:419] P 35c65960fa7f47628551d5a0aa637595: Scheduling FlushDeltaMemStoresOp(c82eb4d1b7da4939893e809d46274ee2): perf score=11.118625
I20260812 06:18:25.487421 16146 maintenance_manager.cc:643] P 35c65960fa7f47628551d5a0aa637595: FlushDeltaMemStoresOp(c82eb4d1b7da4939893e809d46274ee2) complete. Timing: real 0.041s	user 0.026s	sys 0.011s Metrics: {"bytes_written":12717735,"delete_count":0,"lbm_write_time_us":17283,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:18:25.489231 16206 maintenance_manager.cc:419] P 35c65960fa7f47628551d5a0aa637595: Scheduling FlushDeltaMemStoresOp(c82eb4d1b7da4939893e809d46274ee2): perf score=2.188937
I20260812 06:18:25.513571 16146 maintenance_manager.cc:643] P 35c65960fa7f47628551d5a0aa637595: FlushDeltaMemStoresOp(c82eb4d1b7da4939893e809d46274ee2) complete. Timing: real 0.024s	user 0.009s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5612,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:25.514029 16206 maintenance_manager.cc:419] P 35c65960fa7f47628551d5a0aa637595: Scheduling FlushDeltaMemStoresOp(c82eb4d1b7da4939893e809d46274ee2): perf score=2.188937
I20260812 06:18:25.523545 16146 maintenance_manager.cc:643] P 35c65960fa7f47628551d5a0aa637595: FlushDeltaMemStoresOp(c82eb4d1b7da4939893e809d46274ee2) complete. Timing: real 0.009s	user 0.004s	sys 0.004s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3425,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:18:25.524048 16206 maintenance_manager.cc:419] P 35c65960fa7f47628551d5a0aa637595: Scheduling MajorDeltaCompactionOp(c82eb4d1b7da4939893e809d46274ee2): perf score=1.000000
I20260812 06:18:25.681121 16146 maintenance_manager.cc:643] P 35c65960fa7f47628551d5a0aa637595: MajorDeltaCompactionOp(c82eb4d1b7da4939893e809d46274ee2) complete. Timing: real 0.157s	user 0.132s	sys 0.020s Metrics: {"cfile_cache_miss":533,"cfile_cache_miss_bytes":24733834,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":209,"lbm_read_time_us":10721,"lbm_reads_lt_1ms":573,"lbm_write_time_us":31666,"lbm_writes_lt_1ms":543,"mutex_wait_us":50,"peak_mem_usage":63115900,"reinsert_count":0,"update_count":2500}
I20260812 06:18:25.681669 16206 maintenance_manager.cc:419] P 35c65960fa7f47628551d5a0aa637595: Scheduling FlushDeltaMemStoresOp(c82eb4d1b7da4939893e809d46274ee2): perf score=11.118625
I20260812 06:18:25.715729 16146 maintenance_manager.cc:643] P 35c65960fa7f47628551d5a0aa637595: FlushDeltaMemStoresOp(c82eb4d1b7da4939893e809d46274ee2) complete. Timing: real 0.032s	user 0.022s	sys 0.008s Metrics: {"bytes_written":12717735,"delete_count":0,"lbm_write_time_us":12846,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:18:25.716252 16206 maintenance_manager.cc:419] P 35c65960fa7f47628551d5a0aa637595: Scheduling FlushDeltaMemStoresOp(c82eb4d1b7da4939893e809d46274ee2): perf score=2.188937
I20260812 06:18:25.726809 16146 maintenance_manager.cc:643] P 35c65960fa7f47628551d5a0aa637595: FlushDeltaMemStoresOp(c82eb4d1b7da4939893e809d46274ee2) complete. Timing: real 0.010s	user 0.001s	sys 0.008s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3882,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:18:25.727214 16206 maintenance_manager.cc:419] P 35c65960fa7f47628551d5a0aa637595: Scheduling MajorDeltaCompactionOp(c82eb4d1b7da4939893e809d46274ee2): perf score=1.000000
I20260812 06:18:25.872541 16146 maintenance_manager.cc:643] P 35c65960fa7f47628551d5a0aa637595: MajorDeltaCompactionOp(c82eb4d1b7da4939893e809d46274ee2) complete. Timing: real 0.145s	user 0.101s	sys 0.036s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20631303,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":459,"lbm_read_time_us":9609,"lbm_reads_lt_1ms":472,"lbm_write_time_us":22032,"lbm_writes_lt_1ms":443,"mutex_wait_us":246,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":10368,"update_count":2000}
I20260812 06:18:25.873131 16206 maintenance_manager.cc:419] P 35c65960fa7f47628551d5a0aa637595: Scheduling FlushDeltaMemStoresOp(c82eb4d1b7da4939893e809d46274ee2): perf score=10.126437
I20260812 06:18:25.913640 16146 maintenance_manager.cc:643] P 35c65960fa7f47628551d5a0aa637595: FlushDeltaMemStoresOp(c82eb4d1b7da4939893e809d46274ee2) complete. Timing: real 0.040s	user 0.019s	sys 0.015s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":12925,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:18:25.914242 16206 maintenance_manager.cc:419] P 35c65960fa7f47628551d5a0aa637595: Scheduling MajorDeltaCompactionOp(c82eb4d1b7da4939893e809d46274ee2): perf score=1.000000
I20260812 06:18:26.050761 16146 maintenance_manager.cc:643] P 35c65960fa7f47628551d5a0aa637595: MajorDeltaCompactionOp(c82eb4d1b7da4939893e809d46274ee2) complete. Timing: real 0.136s	user 0.100s	sys 0.036s Metrics: {"cfile_cache_miss":331,"cfile_cache_miss_bytes":16528781,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":1,"delta_iterators_relevant":1,"dirs.queue_time_us":143,"lbm_read_time_us":9022,"lbm_reads_lt_1ms":363,"lbm_write_time_us":21182,"lbm_writes_lt_1ms":343,"mutex_wait_us":55,"peak_mem_usage":38262756,"reinsert_count":0,"update_count":1500}
I20260812 06:18:26.051239 16206 maintenance_manager.cc:419] P 35c65960fa7f47628551d5a0aa637595: Scheduling FlushDeltaMemStoresOp(c82eb4d1b7da4939893e809d46274ee2): perf score=10.126437
I20260812 06:18:26.095808 16146 maintenance_manager.cc:643] P 35c65960fa7f47628551d5a0aa637595: FlushDeltaMemStoresOp(c82eb4d1b7da4939893e809d46274ee2) complete. Timing: real 0.044s	user 0.023s	sys 0.008s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":13308,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:18:26.096385 16206 maintenance_manager.cc:419] P 35c65960fa7f47628551d5a0aa637595: Scheduling FlushDeltaMemStoresOp(c82eb4d1b7da4939893e809d46274ee2): perf score=2.188937
I20260812 06:18:26.108879 16146 maintenance_manager.cc:643] P 35c65960fa7f47628551d5a0aa637595: FlushDeltaMemStoresOp(c82eb4d1b7da4939893e809d46274ee2) complete. Timing: real 0.012s	user 0.006s	sys 0.005s Metrics: {"bytes_written":4102660,"delete_count":0,"lbm_write_time_us":4417,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:26.109364 16206 maintenance_manager.cc:419] P 35c65960fa7f47628551d5a0aa637595: Scheduling MajorDeltaCompactionOp(c82eb4d1b7da4939893e809d46274ee2): perf score=1.000000
I20260812 06:18:26.250499 16146 maintenance_manager.cc:643] P 35c65960fa7f47628551d5a0aa637595: MajorDeltaCompactionOp(c82eb4d1b7da4939893e809d46274ee2) complete. Timing: real 0.141s	user 0.113s	sys 0.025s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20631313,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":816,"lbm_read_time_us":9269,"lbm_reads_lt_1ms":472,"lbm_write_time_us":26004,"lbm_writes_lt_1ms":443,"mutex_wait_us":257,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":13056,"update_count":2000}
I20260812 06:18:26.251111 16206 maintenance_manager.cc:419] P 35c65960fa7f47628551d5a0aa637595: Scheduling FlushDeltaMemStoresOp(c82eb4d1b7da4939893e809d46274ee2): perf score=10.126437
I20260812 06:18:26.301929 16146 maintenance_manager.cc:643] P 35c65960fa7f47628551d5a0aa637595: FlushDeltaMemStoresOp(c82eb4d1b7da4939893e809d46274ee2) complete. Timing: real 0.051s	user 0.026s	sys 0.012s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":17260,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:18:26.302546 16206 maintenance_manager.cc:419] P 35c65960fa7f47628551d5a0aa637595: Scheduling FlushDeltaMemStoresOp(c82eb4d1b7da4939893e809d46274ee2): perf score=2.188937
I20260812 06:18:26.319186 16146 maintenance_manager.cc:643] P 35c65960fa7f47628551d5a0aa637595: FlushDeltaMemStoresOp(c82eb4d1b7da4939893e809d46274ee2) complete. Timing: real 0.016s	user 0.010s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6580,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:26.319924 16206 maintenance_manager.cc:419] P 35c65960fa7f47628551d5a0aa637595: Scheduling MajorDeltaCompactionOp(c82eb4d1b7da4939893e809d46274ee2): perf score=1.000000
I20260812 06:18:26.452597 16146 maintenance_manager.cc:643] P 35c65960fa7f47628551d5a0aa637595: MajorDeltaCompactionOp(c82eb4d1b7da4939893e809d46274ee2) complete. Timing: real 0.132s	user 0.110s	sys 0.020s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20631312,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":443,"lbm_read_time_us":8258,"lbm_reads_lt_1ms":472,"lbm_write_time_us":24741,"lbm_writes_lt_1ms":443,"mutex_wait_us":275,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":2176,"update_count":2000}
I20260812 06:18:26.453085 16206 maintenance_manager.cc:419] P 35c65960fa7f47628551d5a0aa637595: Scheduling FlushDeltaMemStoresOp(c82eb4d1b7da4939893e809d46274ee2): perf score=10.126437
I20260812 06:18:26.501611 16146 maintenance_manager.cc:643] P 35c65960fa7f47628551d5a0aa637595: FlushDeltaMemStoresOp(c82eb4d1b7da4939893e809d46274ee2) complete. Timing: real 0.048s	user 0.021s	sys 0.019s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":14516,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:18:26.502084 16206 maintenance_manager.cc:419] P 35c65960fa7f47628551d5a0aa637595: Scheduling FlushDeltaMemStoresOp(c82eb4d1b7da4939893e809d46274ee2): perf score=2.188937
I20260812 06:18:26.514811 16146 maintenance_manager.cc:643] P 35c65960fa7f47628551d5a0aa637595: FlushDeltaMemStoresOp(c82eb4d1b7da4939893e809d46274ee2) complete. Timing: real 0.013s	user 0.007s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4596,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:26.515424 16206 maintenance_manager.cc:419] P 35c65960fa7f47628551d5a0aa637595: Scheduling MajorDeltaCompactionOp(c82eb4d1b7da4939893e809d46274ee2): perf score=1.000000
I20260812 06:18:26.668812 16146 maintenance_manager.cc:643] P 35c65960fa7f47628551d5a0aa637595: MajorDeltaCompactionOp(c82eb4d1b7da4939893e809d46274ee2) complete. Timing: real 0.153s	user 0.107s	sys 0.042s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20631312,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":545,"lbm_read_time_us":10995,"lbm_reads_lt_1ms":472,"lbm_write_time_us":23402,"lbm_writes_lt_1ms":443,"mutex_wait_us":41,"peak_mem_usage":50689328,"reinsert_count":0,"update_count":2000}
I20260812 06:18:26.669373 16206 maintenance_manager.cc:419] P 35c65960fa7f47628551d5a0aa637595: Scheduling FlushDeltaMemStoresOp(c82eb4d1b7da4939893e809d46274ee2): perf score=10.126437
I20260812 06:18:26.704013 16146 maintenance_manager.cc:643] P 35c65960fa7f47628551d5a0aa637595: FlushDeltaMemStoresOp(c82eb4d1b7da4939893e809d46274ee2) complete. Timing: real 0.034s	user 0.014s	sys 0.017s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":13280,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:18:26.704566 16206 maintenance_manager.cc:419] P 35c65960fa7f47628551d5a0aa637595: Scheduling FlushMRSOp(c82eb4d1b7da4939893e809d46274ee2): perf score=1.000000
I20260812 06:18:26.745751 16146 maintenance_manager.cc:643] P 35c65960fa7f47628551d5a0aa637595: FlushMRSOp(c82eb4d1b7da4939893e809d46274ee2) complete. Timing: real 0.041s	user 0.026s	sys 0.003s Metrics: {"bytes_written":1234479,"cfile_init":1,"dirs.queue_time_us":65,"dirs.run_cpu_time_us":220,"dirs.run_wall_time_us":1231,"drs_written":1,"lbm_read_time_us":70,"lbm_reads_lt_1ms":4,"lbm_write_time_us":2096,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":30}
I20260812 06:18:26.746569 16206 maintenance_manager.cc:419] P 35c65960fa7f47628551d5a0aa637595: Scheduling FlushDeltaMemStoresOp(c82eb4d1b7da4939893e809d46274ee2): perf score=3.181125
I20260812 06:18:26.760241 16146 maintenance_manager.cc:643] P 35c65960fa7f47628551d5a0aa637595: FlushDeltaMemStoresOp(c82eb4d1b7da4939893e809d46274ee2) complete. Timing: real 0.013s	user 0.009s	sys 0.004s Metrics: {"bytes_written":4512903,"delete_count":0,"lbm_write_time_us":5002,"lbm_writes_lt_1ms":113,"reinsert_count":0,"update_count":550}
I20260812 06:18:26.760679 16206 maintenance_manager.cc:419] P 35c65960fa7f47628551d5a0aa637595: Scheduling LogGCOp(c82eb4d1b7da4939893e809d46274ee2): free 121006436 bytes of WAL
I20260812 06:18:26.760928 16146 log_reader.cc:385] T c82eb4d1b7da4939893e809d46274ee2: removed 12 log segments from log reader
I20260812 06:18:26.760989 16146 log.cc:1079] T c82eb4d1b7da4939893e809d46274ee2 P 35c65960fa7f47628551d5a0aa637595: Deleting log segment in path: /tmp/dist-test-taskSk6K39/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515503120097-16044-0/minicluster-data/ts-0-root/wals/c82eb4d1b7da4939893e809d46274ee2/wal-000000015 (ops 71-75)
I20260812 06:18:26.761027 16146 log.cc:1079] T c82eb4d1b7da4939893e809d46274ee2 P 35c65960fa7f47628551d5a0aa637595: Deleting log segment in path: /tmp/dist-test-taskSk6K39/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515503120097-16044-0/minicluster-data/ts-0-root/wals/c82eb4d1b7da4939893e809d46274ee2/wal-000000016 (ops 76-80)
I20260812 06:18:26.761101 16146 log.cc:1079] T c82eb4d1b7da4939893e809d46274ee2 P 35c65960fa7f47628551d5a0aa637595: Deleting log segment in path: /tmp/dist-test-taskSk6K39/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515503120097-16044-0/minicluster-data/ts-0-root/wals/c82eb4d1b7da4939893e809d46274ee2/wal-000000017 (ops 81-85)
I20260812 06:18:26.761171 16146 log.cc:1079] T c82eb4d1b7da4939893e809d46274ee2 P 35c65960fa7f47628551d5a0aa637595: Deleting log segment in path: /tmp/dist-test-taskSk6K39/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515503120097-16044-0/minicluster-data/ts-0-root/wals/c82eb4d1b7da4939893e809d46274ee2/wal-000000018 (ops 86-90)
I20260812 06:18:26.761257 16146 log.cc:1079] T c82eb4d1b7da4939893e809d46274ee2 P 35c65960fa7f47628551d5a0aa637595: Deleting log segment in path: /tmp/dist-test-taskSk6K39/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515503120097-16044-0/minicluster-data/ts-0-root/wals/c82eb4d1b7da4939893e809d46274ee2/wal-000000019 (ops 91-95)
I20260812 06:18:26.761323 16146 log.cc:1079] T c82eb4d1b7da4939893e809d46274ee2 P 35c65960fa7f47628551d5a0aa637595: Deleting log segment in path: /tmp/dist-test-taskSk6K39/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515503120097-16044-0/minicluster-data/ts-0-root/wals/c82eb4d1b7da4939893e809d46274ee2/wal-000000020 (ops 96-100)
I20260812 06:18:26.761379 16146 log.cc:1079] T c82eb4d1b7da4939893e809d46274ee2 P 35c65960fa7f47628551d5a0aa637595: Deleting log segment in path: /tmp/dist-test-taskSk6K39/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515503120097-16044-0/minicluster-data/ts-0-root/wals/c82eb4d1b7da4939893e809d46274ee2/wal-000000021 (ops 101-104)
I20260812 06:18:26.761433 16146 log.cc:1079] T c82eb4d1b7da4939893e809d46274ee2 P 35c65960fa7f47628551d5a0aa637595: Deleting log segment in path: /tmp/dist-test-taskSk6K39/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515503120097-16044-0/minicluster-data/ts-0-root/wals/c82eb4d1b7da4939893e809d46274ee2/wal-000000022 (ops 105-109)
I20260812 06:18:26.761488 16146 log.cc:1079] T c82eb4d1b7da4939893e809d46274ee2 P 35c65960fa7f47628551d5a0aa637595: Deleting log segment in path: /tmp/dist-test-taskSk6K39/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515503120097-16044-0/minicluster-data/ts-0-root/wals/c82eb4d1b7da4939893e809d46274ee2/wal-000000023 (ops 110-114)
I20260812 06:18:26.761545 16146 log.cc:1079] T c82eb4d1b7da4939893e809d46274ee2 P 35c65960fa7f47628551d5a0aa637595: Deleting log segment in path: /tmp/dist-test-taskSk6K39/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515503120097-16044-0/minicluster-data/ts-0-root/wals/c82eb4d1b7da4939893e809d46274ee2/wal-000000024 (ops 115-119)
I20260812 06:18:26.761600 16146 log.cc:1079] T c82eb4d1b7da4939893e809d46274ee2 P 35c65960fa7f47628551d5a0aa637595: Deleting log segment in path: /tmp/dist-test-taskSk6K39/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515503120097-16044-0/minicluster-data/ts-0-root/wals/c82eb4d1b7da4939893e809d46274ee2/wal-000000025 (ops 120-124)
I20260812 06:18:26.761656 16146 log.cc:1079] T c82eb4d1b7da4939893e809d46274ee2 P 35c65960fa7f47628551d5a0aa637595: Deleting log segment in path: /tmp/dist-test-taskSk6K39/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515503120097-16044-0/minicluster-data/ts-0-root/wals/c82eb4d1b7da4939893e809d46274ee2/wal-000000026 (ops 125-129)
I20260812 06:18:26.785678 16146 maintenance_manager.cc:643] P 35c65960fa7f47628551d5a0aa637595: LogGCOp(c82eb4d1b7da4939893e809d46274ee2) complete. Timing: real 0.025s	user 0.000s	sys 0.023s Metrics: {}
I20260812 06:18:26.786118 16206 maintenance_manager.cc:419] P 35c65960fa7f47628551d5a0aa637595: Scheduling FlushDeltaMemStoresOp(c82eb4d1b7da4939893e809d46274ee2): perf score=2.188937
I20260812 06:18:26.813970 16146 maintenance_manager.cc:643] P 35c65960fa7f47628551d5a0aa637595: FlushDeltaMemStoresOp(c82eb4d1b7da4939893e809d46274ee2) complete. Timing: real 0.028s	user 0.005s	sys 0.012s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4117,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:26.814406 16206 maintenance_manager.cc:419] P 35c65960fa7f47628551d5a0aa637595: Scheduling FlushDeltaMemStoresOp(c82eb4d1b7da4939893e809d46274ee2): perf score=2.188937
I20260812 06:18:26.827626 16146 maintenance_manager.cc:643] P 35c65960fa7f47628551d5a0aa637595: FlushDeltaMemStoresOp(c82eb4d1b7da4939893e809d46274ee2) complete. Timing: real 0.013s	user 0.003s	sys 0.008s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":4787,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:18:26.828073 16206 maintenance_manager.cc:419] P 35c65960fa7f47628551d5a0aa637595: Scheduling MajorDeltaCompactionOp(c82eb4d1b7da4939893e809d46274ee2): perf score=1.000000
I20260812 06:18:27.016096 16146 maintenance_manager.cc:643] P 35c65960fa7f47628551d5a0aa637595: MajorDeltaCompactionOp(c82eb4d1b7da4939893e809d46274ee2) complete. Timing: real 0.188s	user 0.126s	sys 0.060s Metrics: {"cfile_cache_miss":634,"cfile_cache_miss_bytes":28836364,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":1085,"lbm_read_time_us":13336,"lbm_reads_lt_1ms":674,"lbm_write_time_us":31256,"lbm_writes_lt_1ms":643,"mutex_wait_us":448,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":1664,"thread_start_us":78,"threads_started":1,"update_count":3000}
I20260812 06:18:27.016582 16206 maintenance_manager.cc:419] P 35c65960fa7f47628551d5a0aa637595: Scheduling UndoDeltaBlockGCOp(c82eb4d1b7da4939893e809d46274ee2): 472 bytes on disk
I20260812 06:18:27.016974 16146 maintenance_manager.cc:643] P 35c65960fa7f47628551d5a0aa637595: UndoDeltaBlockGCOp(c82eb4d1b7da4939893e809d46274ee2) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":56,"lbm_reads_lt_1ms":4}
I20260812 06:18:27.017764 16206 maintenance_manager.cc:419] P 35c65960fa7f47628551d5a0aa637595: Scheduling FlushDeltaMemStoresOp(c82eb4d1b7da4939893e809d46274ee2): perf score=11.118625
I20260812 06:18:27.055878 16146 maintenance_manager.cc:643] P 35c65960fa7f47628551d5a0aa637595: FlushDeltaMemStoresOp(c82eb4d1b7da4939893e809d46274ee2) complete. Timing: real 0.038s	user 0.026s	sys 0.012s Metrics: {"bytes_written":12717735,"delete_count":0,"lbm_write_time_us":15784,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:18:27.056437 16206 maintenance_manager.cc:419] P 35c65960fa7f47628551d5a0aa637595: Scheduling FlushDeltaMemStoresOp(c82eb4d1b7da4939893e809d46274ee2): perf score=2.188937
I20260812 06:18:27.075865 16146 maintenance_manager.cc:643] P 35c65960fa7f47628551d5a0aa637595: FlushDeltaMemStoresOp(c82eb4d1b7da4939893e809d46274ee2) complete. Timing: real 0.019s	user 0.009s	sys 0.004s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":4410,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:18:27.076570 16206 maintenance_manager.cc:419] P 35c65960fa7f47628551d5a0aa637595: Scheduling MajorDeltaCompactionOp(c82eb4d1b7da4939893e809d46274ee2): perf score=1.000000
I20260812 06:18:27.228418 16146 maintenance_manager.cc:643] P 35c65960fa7f47628551d5a0aa637595: MajorDeltaCompactionOp(c82eb4d1b7da4939893e809d46274ee2) complete. Timing: real 0.151s	user 0.083s	sys 0.068s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20631303,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":372,"lbm_read_time_us":10653,"lbm_reads_lt_1ms":464,"lbm_write_time_us":23517,"lbm_writes_lt_1ms":443,"mutex_wait_us":65,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":19200,"update_count":2000}
I20260812 06:18:27.229147 16206 maintenance_manager.cc:419] P 35c65960fa7f47628551d5a0aa637595: Scheduling FlushDeltaMemStoresOp(c82eb4d1b7da4939893e809d46274ee2): perf score=10.126437
I20260812 06:18:27.273252 16146 maintenance_manager.cc:643] P 35c65960fa7f47628551d5a0aa637595: FlushDeltaMemStoresOp(c82eb4d1b7da4939893e809d46274ee2) complete. Timing: real 0.044s	user 0.027s	sys 0.008s Metrics: {"bytes_written":12307492,"delete_count":0,"lbm_write_time_us":15818,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:18:27.273803 16206 maintenance_manager.cc:419] P 35c65960fa7f47628551d5a0aa637595: Scheduling FlushDeltaMemStoresOp(c82eb4d1b7da4939893e809d46274ee2): perf score=2.188937
I20260812 06:18:27.283974 16146 maintenance_manager.cc:643] P 35c65960fa7f47628551d5a0aa637595: FlushDeltaMemStoresOp(c82eb4d1b7da4939893e809d46274ee2) complete. Timing: real 0.010s	user 0.010s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3688,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:27.284435 16206 maintenance_manager.cc:419] P 35c65960fa7f47628551d5a0aa637595: Scheduling MajorDeltaCompactionOp(c82eb4d1b7da4939893e809d46274ee2): perf score=1.000000
I20260812 06:18:27.416908 16146 maintenance_manager.cc:643] P 35c65960fa7f47628551d5a0aa637595: MajorDeltaCompactionOp(c82eb4d1b7da4939893e809d46274ee2) complete. Timing: real 0.132s	user 0.089s	sys 0.042s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20631314,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":179,"lbm_read_time_us":8945,"lbm_reads_lt_1ms":472,"lbm_write_time_us":23439,"lbm_writes_lt_1ms":443,"mutex_wait_us":39,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":4864,"update_count":2000}
I20260812 06:18:27.420192 16206 maintenance_manager.cc:419] P 35c65960fa7f47628551d5a0aa637595: Scheduling FlushDeltaMemStoresOp(c82eb4d1b7da4939893e809d46274ee2): perf score=10.126437
I20260812 06:18:27.463686 16146 maintenance_manager.cc:643] P 35c65960fa7f47628551d5a0aa637595: FlushDeltaMemStoresOp(c82eb4d1b7da4939893e809d46274ee2) complete. Timing: real 0.043s	user 0.010s	sys 0.025s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":15333,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:18:27.464237 16206 maintenance_manager.cc:419] P 35c65960fa7f47628551d5a0aa637595: Scheduling FlushDeltaMemStoresOp(c82eb4d1b7da4939893e809d46274ee2): perf score=2.188937
I20260812 06:18:27.474560 16146 maintenance_manager.cc:643] P 35c65960fa7f47628551d5a0aa637595: FlushDeltaMemStoresOp(c82eb4d1b7da4939893e809d46274ee2) complete. Timing: real 0.010s	user 0.009s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3807,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:27.475018 16206 maintenance_manager.cc:419] P 35c65960fa7f47628551d5a0aa637595: Scheduling MajorDeltaCompactionOp(c82eb4d1b7da4939893e809d46274ee2): perf score=1.000000
I20260812 06:18:27.617344 16146 maintenance_manager.cc:643] P 35c65960fa7f47628551d5a0aa637595: MajorDeltaCompactionOp(c82eb4d1b7da4939893e809d46274ee2) complete. Timing: real 0.142s	user 0.112s	sys 0.020s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20631312,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":1636,"lbm_read_time_us":9608,"lbm_reads_lt_1ms":472,"lbm_write_time_us":23633,"lbm_writes_lt_1ms":443,"mutex_wait_us":582,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":5632,"update_count":2000}
I20260812 06:18:27.617873 16206 maintenance_manager.cc:419] P 35c65960fa7f47628551d5a0aa637595: Scheduling FlushDeltaMemStoresOp(c82eb4d1b7da4939893e809d46274ee2): perf score=10.126437
I20260812 06:18:27.679196 16146 maintenance_manager.cc:643] P 35c65960fa7f47628551d5a0aa637595: FlushDeltaMemStoresOp(c82eb4d1b7da4939893e809d46274ee2) complete. Timing: real 0.061s	user 0.022s	sys 0.035s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":20017,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:18:27.679836 16206 maintenance_manager.cc:419] P 35c65960fa7f47628551d5a0aa637595: Scheduling FlushDeltaMemStoresOp(c82eb4d1b7da4939893e809d46274ee2): perf score=2.188937
I20260812 06:18:27.690809 16146 maintenance_manager.cc:643] P 35c65960fa7f47628551d5a0aa637595: FlushDeltaMemStoresOp(c82eb4d1b7da4939893e809d46274ee2) complete. Timing: real 0.011s	user 0.009s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4100,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:27.691282 16206 maintenance_manager.cc:419] P 35c65960fa7f47628551d5a0aa637595: Scheduling MajorDeltaCompactionOp(c82eb4d1b7da4939893e809d46274ee2): perf score=1.000000
I20260812 06:18:27.851792 16146 maintenance_manager.cc:643] P 35c65960fa7f47628551d5a0aa637595: MajorDeltaCompactionOp(c82eb4d1b7da4939893e809d46274ee2) complete. Timing: real 0.160s	user 0.120s	sys 0.039s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20631312,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":96,"lbm_read_time_us":11849,"lbm_reads_lt_1ms":472,"lbm_write_time_us":27283,"lbm_writes_lt_1ms":443,"mutex_wait_us":22,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":10240,"update_count":2000}
I20260812 06:18:27.852411 16206 maintenance_manager.cc:419] P 35c65960fa7f47628551d5a0aa637595: Scheduling FlushDeltaMemStoresOp(c82eb4d1b7da4939893e809d46274ee2): perf score=10.126437
I20260812 06:18:27.898903 16146 maintenance_manager.cc:643] P 35c65960fa7f47628551d5a0aa637595: FlushDeltaMemStoresOp(c82eb4d1b7da4939893e809d46274ee2) complete. Timing: real 0.046s	user 0.018s	sys 0.016s Metrics: {"bytes_written":12307491,"delete_count":0,"lbm_write_time_us":16445,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:18:27.899376 16206 maintenance_manager.cc:419] P 35c65960fa7f47628551d5a0aa637595: Scheduling FlushDeltaMemStoresOp(c82eb4d1b7da4939893e809d46274ee2): perf score=2.188937
I20260812 06:18:27.909164 16146 maintenance_manager.cc:643] P 35c65960fa7f47628551d5a0aa637595: FlushDeltaMemStoresOp(c82eb4d1b7da4939893e809d46274ee2) complete. Timing: real 0.010s	user 0.008s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3619,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:27.909570 16206 maintenance_manager.cc:419] P 35c65960fa7f47628551d5a0aa637595: Scheduling MajorDeltaCompactionOp(c82eb4d1b7da4939893e809d46274ee2): perf score=1.000000
I20260812 06:18:28.036378 16146 maintenance_manager.cc:643] P 35c65960fa7f47628551d5a0aa637595: MajorDeltaCompactionOp(c82eb4d1b7da4939893e809d46274ee2) complete. Timing: real 0.127s	user 0.106s	sys 0.016s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20631313,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":547,"lbm_read_time_us":9076,"lbm_reads_lt_1ms":472,"lbm_write_time_us":21385,"lbm_writes_lt_1ms":443,"mutex_wait_us":260,"peak_mem_usage":50689328,"reinsert_count":0,"update_count":2000}
I20260812 06:18:28.036937 16206 maintenance_manager.cc:419] P 35c65960fa7f47628551d5a0aa637595: Scheduling FlushDeltaMemStoresOp(c82eb4d1b7da4939893e809d46274ee2): perf score=10.126437
I20260812 06:18:28.086256 16146 maintenance_manager.cc:643] P 35c65960fa7f47628551d5a0aa637595: FlushDeltaMemStoresOp(c82eb4d1b7da4939893e809d46274ee2) complete. Timing: real 0.049s	user 0.034s	sys 0.005s Metrics: {"bytes_written":12307489,"delete_count":0,"lbm_write_time_us":18951,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":302,"reinsert_count":0,"update_count":1500}
I20260812 06:18:28.086799 16206 maintenance_manager.cc:419] P 35c65960fa7f47628551d5a0aa637595: Scheduling FlushDeltaMemStoresOp(c82eb4d1b7da4939893e809d46274ee2): perf score=2.188937
I20260812 06:18:28.101927 16146 maintenance_manager.cc:643] P 35c65960fa7f47628551d5a0aa637595: FlushDeltaMemStoresOp(c82eb4d1b7da4939893e809d46274ee2) complete. Timing: real 0.015s	user 0.004s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5435,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:28.102571 16206 maintenance_manager.cc:419] P 35c65960fa7f47628551d5a0aa637595: Scheduling MajorDeltaCompactionOp(c82eb4d1b7da4939893e809d46274ee2): perf score=1.000000
I20260812 06:18:28.228381 16146 maintenance_manager.cc:643] P 35c65960fa7f47628551d5a0aa637595: MajorDeltaCompactionOp(c82eb4d1b7da4939893e809d46274ee2) complete. Timing: real 0.125s	user 0.095s	sys 0.028s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20631311,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":1121,"lbm_read_time_us":8507,"lbm_reads_lt_1ms":472,"lbm_write_time_us":22136,"lbm_writes_lt_1ms":443,"mutex_wait_us":253,"peak_mem_usage":50689328,"reinsert_count":0,"update_count":2000}
I20260812 06:18:28.229746 16206 maintenance_manager.cc:419] P 35c65960fa7f47628551d5a0aa637595: Scheduling FlushDeltaMemStoresOp(c82eb4d1b7da4939893e809d46274ee2): perf score=10.126437
I20260812 06:18:28.272962 16146 maintenance_manager.cc:643] P 35c65960fa7f47628551d5a0aa637595: FlushDeltaMemStoresOp(c82eb4d1b7da4939893e809d46274ee2) complete. Timing: real 0.043s	user 0.030s	sys 0.004s Metrics: {"bytes_written":12307492,"delete_count":0,"lbm_write_time_us":14718,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:18:28.273542 16206 maintenance_manager.cc:419] P 35c65960fa7f47628551d5a0aa637595: Scheduling FlushDeltaMemStoresOp(c82eb4d1b7da4939893e809d46274ee2): perf score=2.188937
I20260812 06:18:28.286087 16146 maintenance_manager.cc:643] P 35c65960fa7f47628551d5a0aa637595: FlushDeltaMemStoresOp(c82eb4d1b7da4939893e809d46274ee2) complete. Timing: real 0.012s	user 0.007s	sys 0.003s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4622,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:28.286755 16206 maintenance_manager.cc:419] P 35c65960fa7f47628551d5a0aa637595: Scheduling FlushMRSOp(c82eb4d1b7da4939893e809d46274ee2): perf score=1.000000
I20260812 06:18:28.322763 16146 maintenance_manager.cc:643] P 35c65960fa7f47628551d5a0aa637595: FlushMRSOp(c82eb4d1b7da4939893e809d46274ee2) complete. Timing: real 0.036s	user 0.029s	sys 0.000s Metrics: {"bytes_written":1234477,"cfile_init":1,"dirs.queue_time_us":57,"dirs.run_cpu_time_us":156,"dirs.run_wall_time_us":1348,"drs_written":1,"lbm_read_time_us":48,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1614,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":30}
I20260812 06:18:28.323704 16206 maintenance_manager.cc:419] P 35c65960fa7f47628551d5a0aa637595: Scheduling LogGCOp(c82eb4d1b7da4939893e809d46274ee2): free 120553638 bytes of WAL
I20260812 06:18:28.323964 16146 log_reader.cc:385] T c82eb4d1b7da4939893e809d46274ee2: removed 12 log segments from log reader
I20260812 06:18:28.324021 16146 log.cc:1079] T c82eb4d1b7da4939893e809d46274ee2 P 35c65960fa7f47628551d5a0aa637595: Deleting log segment in path: /tmp/dist-test-taskSk6K39/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515503120097-16044-0/minicluster-data/ts-0-root/wals/c82eb4d1b7da4939893e809d46274ee2/wal-000000027 (ops 130-134)
I20260812 06:18:28.324060 16146 log.cc:1079] T c82eb4d1b7da4939893e809d46274ee2 P 35c65960fa7f47628551d5a0aa637595: Deleting log segment in path: /tmp/dist-test-taskSk6K39/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515503120097-16044-0/minicluster-data/ts-0-root/wals/c82eb4d1b7da4939893e809d46274ee2/wal-000000028 (ops 135-139)
I20260812 06:18:28.324092 16146 log.cc:1079] T c82eb4d1b7da4939893e809d46274ee2 P 35c65960fa7f47628551d5a0aa637595: Deleting log segment in path: /tmp/dist-test-taskSk6K39/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515503120097-16044-0/minicluster-data/ts-0-root/wals/c82eb4d1b7da4939893e809d46274ee2/wal-000000029 (ops 140-144)
I20260812 06:18:28.324123 16146 log.cc:1079] T c82eb4d1b7da4939893e809d46274ee2 P 35c65960fa7f47628551d5a0aa637595: Deleting log segment in path: /tmp/dist-test-taskSk6K39/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515503120097-16044-0/minicluster-data/ts-0-root/wals/c82eb4d1b7da4939893e809d46274ee2/wal-000000030 (ops 145-148)
I20260812 06:18:28.324153 16146 log.cc:1079] T c82eb4d1b7da4939893e809d46274ee2 P 35c65960fa7f47628551d5a0aa637595: Deleting log segment in path: /tmp/dist-test-taskSk6K39/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515503120097-16044-0/minicluster-data/ts-0-root/wals/c82eb4d1b7da4939893e809d46274ee2/wal-000000031 (ops 149-153)
I20260812 06:18:28.324184 16146 log.cc:1079] T c82eb4d1b7da4939893e809d46274ee2 P 35c65960fa7f47628551d5a0aa637595: Deleting log segment in path: /tmp/dist-test-taskSk6K39/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515503120097-16044-0/minicluster-data/ts-0-root/wals/c82eb4d1b7da4939893e809d46274ee2/wal-000000032 (ops 154-158)
I20260812 06:18:28.324214 16146 log.cc:1079] T c82eb4d1b7da4939893e809d46274ee2 P 35c65960fa7f47628551d5a0aa637595: Deleting log segment in path: /tmp/dist-test-taskSk6K39/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515503120097-16044-0/minicluster-data/ts-0-root/wals/c82eb4d1b7da4939893e809d46274ee2/wal-000000033 (ops 159-163)
I20260812 06:18:28.324244 16146 log.cc:1079] T c82eb4d1b7da4939893e809d46274ee2 P 35c65960fa7f47628551d5a0aa637595: Deleting log segment in path: /tmp/dist-test-taskSk6K39/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515503120097-16044-0/minicluster-data/ts-0-root/wals/c82eb4d1b7da4939893e809d46274ee2/wal-000000034 (ops 164-168)
I20260812 06:18:28.324275 16146 log.cc:1079] T c82eb4d1b7da4939893e809d46274ee2 P 35c65960fa7f47628551d5a0aa637595: Deleting log segment in path: /tmp/dist-test-taskSk6K39/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515503120097-16044-0/minicluster-data/ts-0-root/wals/c82eb4d1b7da4939893e809d46274ee2/wal-000000035 (ops 169-172)
I20260812 06:18:28.324304 16146 log.cc:1079] T c82eb4d1b7da4939893e809d46274ee2 P 35c65960fa7f47628551d5a0aa637595: Deleting log segment in path: /tmp/dist-test-taskSk6K39/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515503120097-16044-0/minicluster-data/ts-0-root/wals/c82eb4d1b7da4939893e809d46274ee2/wal-000000036 (ops 173-177)
I20260812 06:18:28.324333 16146 log.cc:1079] T c82eb4d1b7da4939893e809d46274ee2 P 35c65960fa7f47628551d5a0aa637595: Deleting log segment in path: /tmp/dist-test-taskSk6K39/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515503120097-16044-0/minicluster-data/ts-0-root/wals/c82eb4d1b7da4939893e809d46274ee2/wal-000000037 (ops 178-182)
I20260812 06:18:28.324363 16146 log.cc:1079] T c82eb4d1b7da4939893e809d46274ee2 P 35c65960fa7f47628551d5a0aa637595: Deleting log segment in path: /tmp/dist-test-taskSk6K39/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515503120097-16044-0/minicluster-data/ts-0-root/wals/c82eb4d1b7da4939893e809d46274ee2/wal-000000038 (ops 183-187)
I20260812 06:18:28.344398 16146 maintenance_manager.cc:643] P 35c65960fa7f47628551d5a0aa637595: LogGCOp(c82eb4d1b7da4939893e809d46274ee2) complete. Timing: real 0.021s	user 0.000s	sys 0.020s Metrics: {}
I20260812 06:18:28.344959 16206 maintenance_manager.cc:419] P 35c65960fa7f47628551d5a0aa637595: Scheduling FlushDeltaMemStoresOp(c82eb4d1b7da4939893e809d46274ee2): perf score=2.188937
I20260812 06:18:28.371372 16146 maintenance_manager.cc:643] P 35c65960fa7f47628551d5a0aa637595: FlushDeltaMemStoresOp(c82eb4d1b7da4939893e809d46274ee2) complete. Timing: real 0.026s	user 0.004s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5267,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:28.371855 16206 maintenance_manager.cc:419] P 35c65960fa7f47628551d5a0aa637595: Scheduling UndoDeltaBlockGCOp(c82eb4d1b7da4939893e809d46274ee2): 473 bytes on disk
I20260812 06:18:28.372264 16146 maintenance_manager.cc:643] P 35c65960fa7f47628551d5a0aa637595: UndoDeltaBlockGCOp(c82eb4d1b7da4939893e809d46274ee2) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":61,"lbm_reads_lt_1ms":4}
I20260812 06:18:28.372843 16206 maintenance_manager.cc:419] P 35c65960fa7f47628551d5a0aa637595: Scheduling FlushDeltaMemStoresOp(c82eb4d1b7da4939893e809d46274ee2): perf score=2.188937
I20260812 06:18:28.387400 16146 maintenance_manager.cc:643] P 35c65960fa7f47628551d5a0aa637595: FlushDeltaMemStoresOp(c82eb4d1b7da4939893e809d46274ee2) complete. Timing: real 0.014s	user 0.008s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5244,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:28.388111 16206 maintenance_manager.cc:419] P 35c65960fa7f47628551d5a0aa637595: Scheduling MajorDeltaCompactionOp(c82eb4d1b7da4939893e809d46274ee2): perf score=1.000000
I20260812 06:18:28.574771 16146 maintenance_manager.cc:643] P 35c65960fa7f47628551d5a0aa637595: MajorDeltaCompactionOp(c82eb4d1b7da4939893e809d46274ee2) complete. Timing: real 0.186s	user 0.151s	sys 0.029s Metrics: {"cfile_cache_miss":634,"cfile_cache_miss_bytes":28836376,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":1734,"lbm_read_time_us":12857,"lbm_reads_1-10_ms":1,"lbm_reads_lt_1ms":673,"lbm_write_time_us":37581,"lbm_writes_lt_1ms":643,"mutex_wait_us":248,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":12288,"thread_start_us":54,"threads_started":1,"update_count":3000}
I20260812 06:18:28.575197 16206 maintenance_manager.cc:419] P 35c65960fa7f47628551d5a0aa637595: Scheduling FlushDeltaMemStoresOp(c82eb4d1b7da4939893e809d46274ee2): perf score=14.095187
I20260812 06:18:28.625232 16044 heavy-update-compaction-itest.cc:229] Time spent updating: real 5.186s	user 1.834s	sys 0.119s
I20260812 06:18:28.628814 16146 maintenance_manager.cc:643] P 35c65960fa7f47628551d5a0aa637595: FlushDeltaMemStoresOp(c82eb4d1b7da4939893e809d46274ee2) complete. Timing: real 0.053s	user 0.049s	sys 0.003s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":23062,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:18:28.629374 16206 maintenance_manager.cc:419] P 35c65960fa7f47628551d5a0aa637595: Scheduling FlushDeltaMemStoresOp(c82eb4d1b7da4939893e809d46274ee2): perf score=2.188937
I20260812 06:18:28.645750 16146 maintenance_manager.cc:643] P 35c65960fa7f47628551d5a0aa637595: FlushDeltaMemStoresOp(c82eb4d1b7da4939893e809d46274ee2) complete. Timing: real 0.016s	user 0.015s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6678,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:28.646422 16206 maintenance_manager.cc:419] P 35c65960fa7f47628551d5a0aa637595: Scheduling MajorDeltaCompactionOp(c82eb4d1b7da4939893e809d46274ee2): perf score=1.000000
I20260812 06:18:28.693094 16044 heavy-update-compaction-itest.cc:265] Time spent scanning: real 0.067s	user 0.004s	sys 0.000s
I20260812 06:18:28.693773 16044 tablet_server.cc:179] TabletServer@127.15.171.1:0 shutting down...
I20260812 06:18:28.781625 16146 maintenance_manager.cc:643] P 35c65960fa7f47628551d5a0aa637595: MajorDeltaCompactionOp(c82eb4d1b7da4939893e809d46274ee2) complete. Timing: real 0.135s	user 0.111s	sys 0.024s Metrics: {"cfile_cache_hit":379,"cfile_cache_hit_bytes":15507525,"cfile_cache_miss":153,"cfile_cache_miss_bytes":9226198,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":340,"lbm_read_time_us":5033,"lbm_reads_lt_1ms":185,"lbm_write_time_us":28281,"lbm_writes_lt_1ms":543,"mutex_wait_us":48,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":10496,"update_count":2500}
I20260812 06:18:28.782305 16044 ts_tablet_manager.cc:1507] Shutting down tablet manager...
I20260812 06:18:28.782848 16044 tablet_replica.cc:333] T c82eb4d1b7da4939893e809d46274ee2 P 35c65960fa7f47628551d5a0aa637595: stopping tablet replica
I20260812 06:18:28.783070 16044 raft_consensus.cc:2243] T c82eb4d1b7da4939893e809d46274ee2 P 35c65960fa7f47628551d5a0aa637595 [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:18:28.783295 16044 raft_consensus.cc:2272] T c82eb4d1b7da4939893e809d46274ee2 P 35c65960fa7f47628551d5a0aa637595 [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:18:28.800601 16044 tablet_server.cc:196] TabletServer@127.15.171.1:0 shutdown complete.
I20260812 06:18:28.827368 16044 master.cc:562] Master@127.15.171.62:40781 shutting down...
I20260812 06:18:28.830770 16044 raft_consensus.cc:2243] T 00000000000000000000000000000000 P 0337355cc73748dc94052af289c968ae [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:18:28.830936 16044 raft_consensus.cc:2272] T 00000000000000000000000000000000 P 0337355cc73748dc94052af289c968ae [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:18:28.830986 16044 tablet_replica.cc:333] T 00000000000000000000000000000000 P 0337355cc73748dc94052af289c968ae: stopping tablet replica
I20260812 06:18:28.843423 16044 master.cc:584] Master@127.15.171.62:40781 shutdown complete.
[       OK ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/0 (5791 ms)
[ RUN      ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/1
I20260812 06:18:28.931659 16044 internal_mini_cluster.cc:156] Creating distributed mini masters. Addrs: 127.15.171.62:35923
I20260812 06:18:28.932083 16044 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:18:28.934074 16243 instance_detector.cc:116] could not retrieve OpenStack instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:18:28.934170 16044 server_base.cc:1061] running on GCE node
W20260812 06:18:28.934062 16241 instance_detector.cc:116] could not retrieve Azure instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:18:28.934042 16240 instance_detector.cc:116] could not retrieve AWS instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:18:28.934492 16044 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:18:28.934535 16044 system_unsync_time.cc:38] NTP support is disabled. Clock error bounds will not be accurate. This configuration is not suitable for distributed clusters.
I20260812 06:18:28.934553 16044 hybrid_clock.cc:648] HybridClock initialized: now 1786515508934553 us; error 0 us; skew 500 ppm
I20260812 06:18:28.935375 16044 webserver.cc:533] Webserver started at http://127.15.171.62:42703/ using document root <none> and password file <none>
I20260812 06:18:28.935534 16044 fs_manager.cc:362] Metadata directory not provided
I20260812 06:18:28.935578 16044 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:18:28.935671 16044 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:18:28.936028 16044 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskSk6K39/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515503120097-16044-0/minicluster-data/master-0-root/instance:
uuid: "c4378bd186a74d11ae635155ab5514dd"
format_stamp: "Formatted at 2026-08-12 06:18:28 on dist-test-slave-f7th"
I20260812 06:18:28.937502 16044 fs_manager.cc:696] Time spent creating directory manager: real 0.001s	user 0.000s	sys 0.002s
I20260812 06:18:28.938391 16248 log_block_manager.cc:4127] Time spent loading block containers with low live blocks: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:18:28.938668 16044 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.000s	sys 0.001s
I20260812 06:18:28.938736 16044 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskSk6K39/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515503120097-16044-0/minicluster-data/master-0-root
uuid: "c4378bd186a74d11ae635155ab5514dd"
format_stamp: "Formatted at 2026-08-12 06:18:28 on dist-test-slave-f7th"
I20260812 06:18:28.938812 16044 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskSk6K39/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515503120097-16044-0/minicluster-data/master-0-root
metadata directory: /tmp/dist-test-taskSk6K39/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515503120097-16044-0/minicluster-data/master-0-root
1 data directories: /tmp/dist-test-taskSk6K39/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515503120097-16044-0/minicluster-data/master-0-root/data
Total live blocks: 0
Total live bytes: 0
Total live bytes (after alignment): 0
Total number of LBM containers: 0 (0 full)
Did not check for missing blocks
Did not check for orphaned blocks
Total full LBM containers with extra space: 0 (0 repaired)
Total full LBM container extra space in bytes: 0 (0 repaired)
Total incomplete LBM containers: 0 (0 repaired)
Total LBM partial records: 0 (0 repaired)
Total corrupted LBM metadata records in RocksDB: 0 (0 repaired)
I20260812 06:18:28.969864 16044 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:18:28.970266 16044 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:18:28.974888 16044 rpc_server.cc:307] RPC server started. Bound to: 127.15.171.62:35923
I20260812 06:18:28.975687 16300 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.15.171.62:35923 every 8 connection(s)
I20260812 06:18:28.977720 16301 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet 00000000000000000000000000000000. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:18:28.980370 16301 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P c4378bd186a74d11ae635155ab5514dd: Bootstrap starting.
I20260812 06:18:28.981235 16301 tablet_bootstrap.cc:654] T 00000000000000000000000000000000 P c4378bd186a74d11ae635155ab5514dd: Neither blocks nor log segments found. Creating new log.
I20260812 06:18:28.982380 16301 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P c4378bd186a74d11ae635155ab5514dd: No bootstrap required, opened a new log
I20260812 06:18:28.982795 16301 raft_consensus.cc:359] T 00000000000000000000000000000000 P c4378bd186a74d11ae635155ab5514dd [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "c4378bd186a74d11ae635155ab5514dd" member_type: VOTER }
I20260812 06:18:28.982913 16301 raft_consensus.cc:385] T 00000000000000000000000000000000 P c4378bd186a74d11ae635155ab5514dd [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:18:28.982952 16301 raft_consensus.cc:740] T 00000000000000000000000000000000 P c4378bd186a74d11ae635155ab5514dd [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: c4378bd186a74d11ae635155ab5514dd, State: Initialized, Role: FOLLOWER
I20260812 06:18:28.983098 16301 consensus_queue.cc:260] T 00000000000000000000000000000000 P c4378bd186a74d11ae635155ab5514dd [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: "c4378bd186a74d11ae635155ab5514dd" member_type: VOTER }
I20260812 06:18:28.983175 16301 raft_consensus.cc:399] T 00000000000000000000000000000000 P c4378bd186a74d11ae635155ab5514dd [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:18:28.983218 16301 raft_consensus.cc:493] T 00000000000000000000000000000000 P c4378bd186a74d11ae635155ab5514dd [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:18:28.983271 16301 raft_consensus.cc:3060] T 00000000000000000000000000000000 P c4378bd186a74d11ae635155ab5514dd [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:18:28.984001 16301 raft_consensus.cc:515] T 00000000000000000000000000000000 P c4378bd186a74d11ae635155ab5514dd [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "c4378bd186a74d11ae635155ab5514dd" member_type: VOTER }
I20260812 06:18:28.984145 16301 leader_election.cc:304] T 00000000000000000000000000000000 P c4378bd186a74d11ae635155ab5514dd [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: c4378bd186a74d11ae635155ab5514dd; no voters: 
I20260812 06:18:28.984323 16301 leader_election.cc:290] T 00000000000000000000000000000000 P c4378bd186a74d11ae635155ab5514dd [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:18:28.984419 16304 raft_consensus.cc:2804] T 00000000000000000000000000000000 P c4378bd186a74d11ae635155ab5514dd [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:18:28.984687 16304 raft_consensus.cc:697] T 00000000000000000000000000000000 P c4378bd186a74d11ae635155ab5514dd [term 1 LEADER]: Becoming Leader. State: Replica: c4378bd186a74d11ae635155ab5514dd, State: Running, Role: LEADER
I20260812 06:18:28.984802 16301 sys_catalog.cc:565] T 00000000000000000000000000000000 P c4378bd186a74d11ae635155ab5514dd [sys.catalog]: configured and running, proceeding with master startup.
I20260812 06:18:28.984882 16304 consensus_queue.cc:237] T 00000000000000000000000000000000 P c4378bd186a74d11ae635155ab5514dd [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: "c4378bd186a74d11ae635155ab5514dd" member_type: VOTER }
I20260812 06:18:28.985339 16305 sys_catalog.cc:455] T 00000000000000000000000000000000 P c4378bd186a74d11ae635155ab5514dd [sys.catalog]: SysCatalogTable state changed. Reason: RaftConsensus started. Latest consensus state: current_term: 1 leader_uuid: "c4378bd186a74d11ae635155ab5514dd" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "c4378bd186a74d11ae635155ab5514dd" member_type: VOTER } }
I20260812 06:18:28.985360 16306 sys_catalog.cc:455] T 00000000000000000000000000000000 P c4378bd186a74d11ae635155ab5514dd [sys.catalog]: SysCatalogTable state changed. Reason: New leader c4378bd186a74d11ae635155ab5514dd. Latest consensus state: current_term: 1 leader_uuid: "c4378bd186a74d11ae635155ab5514dd" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "c4378bd186a74d11ae635155ab5514dd" member_type: VOTER } }
I20260812 06:18:28.985483 16306 sys_catalog.cc:458] T 00000000000000000000000000000000 P c4378bd186a74d11ae635155ab5514dd [sys.catalog]: This master's current role is: LEADER
I20260812 06:18:28.985471 16305 sys_catalog.cc:458] T 00000000000000000000000000000000 P c4378bd186a74d11ae635155ab5514dd [sys.catalog]: This master's current role is: LEADER
I20260812 06:18:28.986070 16311 catalog_manager.cc:1511] Loading table and tablet metadata into memory...
I20260812 06:18:28.986960 16311 catalog_manager.cc:1520] Initializing Kudu cluster ID...
I20260812 06:18:28.987157 16044 internal_mini_cluster.cc:184] Waiting to initialize catalog manager on master 0
I20260812 06:18:28.989006 16311 catalog_manager.cc:1383] Generated new cluster ID: 225616ae16e54ec1bb396b54750f2179
I20260812 06:18:28.989063 16311 catalog_manager.cc:1531] Initializing Kudu internal certificate authority...
I20260812 06:18:29.018956 16311 catalog_manager.cc:1406] Generated new certificate authority record
I20260812 06:18:29.019515 16311 catalog_manager.cc:1540] Loading token signing keys...
I20260812 06:18:29.029095 16311 catalog_manager.cc:6092] T 00000000000000000000000000000000 P c4378bd186a74d11ae635155ab5514dd: Generated new TSK 0
I20260812 06:18:29.029285 16311 catalog_manager.cc:1550] Initializing in-progress tserver states...
I20260812 06:18:29.051730 16044 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:18:29.053654 16322 instance_detector.cc:116] could not retrieve AWS instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:18:29.053771 16325 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:18:29.053829 16323 instance_detector.cc:116] could not retrieve Azure instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:18:29.054072 16044 server_base.cc:1061] running on GCE node
I20260812 06:18:29.054229 16044 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:18:29.054281 16044 system_unsync_time.cc:38] NTP support is disabled. Clock error bounds will not be accurate. This configuration is not suitable for distributed clusters.
I20260812 06:18:29.054301 16044 hybrid_clock.cc:648] HybridClock initialized: now 1786515509054300 us; error 0 us; skew 500 ppm
I20260812 06:18:29.055114 16044 webserver.cc:533] Webserver started at http://127.15.171.1:34807/ using document root <none> and password file <none>
I20260812 06:18:29.055260 16044 fs_manager.cc:362] Metadata directory not provided
I20260812 06:18:29.055302 16044 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:18:29.055372 16044 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:18:29.055787 16044 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskSk6K39/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515503120097-16044-0/minicluster-data/ts-0-root/instance:
uuid: "596aa374dc5f431681fdb26bd3b9b130"
format_stamp: "Formatted at 2026-08-12 06:18:29 on dist-test-slave-f7th"
I20260812 06:18:29.057263 16044 fs_manager.cc:696] Time spent creating directory manager: real 0.001s	user 0.001s	sys 0.000s
I20260812 06:18:29.058359 16330 log_block_manager.cc:4127] Time spent loading block containers with low live blocks: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:18:29.058640 16044 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.001s	sys 0.000s
I20260812 06:18:29.058701 16044 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskSk6K39/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515503120097-16044-0/minicluster-data/ts-0-root
uuid: "596aa374dc5f431681fdb26bd3b9b130"
format_stamp: "Formatted at 2026-08-12 06:18:29 on dist-test-slave-f7th"
I20260812 06:18:29.058760 16044 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskSk6K39/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515503120097-16044-0/minicluster-data/ts-0-root
metadata directory: /tmp/dist-test-taskSk6K39/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515503120097-16044-0/minicluster-data/ts-0-root
1 data directories: /tmp/dist-test-taskSk6K39/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515503120097-16044-0/minicluster-data/ts-0-root/data
Total live blocks: 0
Total live bytes: 0
Total live bytes (after alignment): 0
Total number of LBM containers: 0 (0 full)
Did not check for missing blocks
Did not check for orphaned blocks
Total full LBM containers with extra space: 0 (0 repaired)
Total full LBM container extra space in bytes: 0 (0 repaired)
Total incomplete LBM containers: 0 (0 repaired)
Total LBM partial records: 0 (0 repaired)
Total corrupted LBM metadata records in RocksDB: 0 (0 repaired)
I20260812 06:18:29.075472 16044 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:18:29.075858 16044 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:18:29.076143 16044 txn_system_client.cc:432] TxnSystemClient initialization is disabled...
I20260812 06:18:29.076575 16044 ts_tablet_manager.cc:585] Loaded tablet metadata (0 total tablets, 0 live tablets)
I20260812 06:18:29.076612 16044 ts_tablet_manager.cc:531] Time spent load tablet metadata: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:18:29.076656 16044 ts_tablet_manager.cc:616] Registered 0 tablets
I20260812 06:18:29.076683 16044 ts_tablet_manager.cc:595] Time spent register tablets: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:18:29.081259 16044 rpc_server.cc:307] RPC server started. Bound to: 127.15.171.1:43193
I20260812 06:18:29.082971 16393 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.15.171.1:43193 every 8 connection(s)
I20260812 06:18:29.090087 16394 heartbeater.cc:344] Connected to a master server at 127.15.171.62:35923
I20260812 06:18:29.090198 16394 heartbeater.cc:461] Registering TS with master...
I20260812 06:18:29.090447 16394 heartbeater.cc:507] Master 127.15.171.62:35923 requested a full tablet report, sending...
I20260812 06:18:29.091208 16265 ts_manager.cc:194] Registered new tserver with Master: 596aa374dc5f431681fdb26bd3b9b130 (127.15.171.1:43193)
I20260812 06:18:29.091748 16044 internal_mini_cluster.cc:371] 1 TS(s) registered with all masters after 0.009913092s
I20260812 06:18:29.092185 16265 master_service.cc:502] Signed X509 certificate for tserver {username='slave'} at 127.0.0.1:57266
I20260812 06:18:29.099012 16265 catalog_manager.cc:2283] Servicing CreateTable request from {username='slave'} at 127.0.0.1:57274:
name: "heavy-update-compaction-test"
schema {
  columns {
    name: "key"
    type: INT64
    is_key: true
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_a"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_b"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_c"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_d"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_e"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
}
num_replicas: 1
split_rows_range_bounds {
}
partition_schema {
  range_schema {
  }
}
I20260812 06:18:29.108587 16358 tablet_service.cc:1511] Processing CreateTablet for tablet 9a91ddcc618b47c9b8199450cb0b4523 (DEFAULT_TABLE table=heavy-update-compaction-test [id=1042c893517240bc9c52279813ddcd25]), partition=
I20260812 06:18:29.108811 16358 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet 9a91ddcc618b47c9b8199450cb0b4523. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:18:29.110800 16406 tablet_bootstrap.cc:492] T 9a91ddcc618b47c9b8199450cb0b4523 P 596aa374dc5f431681fdb26bd3b9b130: Bootstrap starting.
I20260812 06:18:29.111702 16406 tablet_bootstrap.cc:654] T 9a91ddcc618b47c9b8199450cb0b4523 P 596aa374dc5f431681fdb26bd3b9b130: Neither blocks nor log segments found. Creating new log.
I20260812 06:18:29.112706 16406 tablet_bootstrap.cc:492] T 9a91ddcc618b47c9b8199450cb0b4523 P 596aa374dc5f431681fdb26bd3b9b130: No bootstrap required, opened a new log
I20260812 06:18:29.112795 16406 ts_tablet_manager.cc:1403] T 9a91ddcc618b47c9b8199450cb0b4523 P 596aa374dc5f431681fdb26bd3b9b130: Time spent bootstrapping tablet: real 0.002s	user 0.000s	sys 0.001s
I20260812 06:18:29.113231 16406 raft_consensus.cc:359] T 9a91ddcc618b47c9b8199450cb0b4523 P 596aa374dc5f431681fdb26bd3b9b130 [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "596aa374dc5f431681fdb26bd3b9b130" member_type: VOTER last_known_addr { host: "127.15.171.1" port: 43193 } }
I20260812 06:18:29.113327 16406 raft_consensus.cc:385] T 9a91ddcc618b47c9b8199450cb0b4523 P 596aa374dc5f431681fdb26bd3b9b130 [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:18:29.113363 16406 raft_consensus.cc:740] T 9a91ddcc618b47c9b8199450cb0b4523 P 596aa374dc5f431681fdb26bd3b9b130 [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: 596aa374dc5f431681fdb26bd3b9b130, State: Initialized, Role: FOLLOWER
I20260812 06:18:29.113500 16406 consensus_queue.cc:260] T 9a91ddcc618b47c9b8199450cb0b4523 P 596aa374dc5f431681fdb26bd3b9b130 [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: "596aa374dc5f431681fdb26bd3b9b130" member_type: VOTER last_known_addr { host: "127.15.171.1" port: 43193 } }
I20260812 06:18:29.113606 16406 raft_consensus.cc:399] T 9a91ddcc618b47c9b8199450cb0b4523 P 596aa374dc5f431681fdb26bd3b9b130 [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:18:29.113655 16406 raft_consensus.cc:493] T 9a91ddcc618b47c9b8199450cb0b4523 P 596aa374dc5f431681fdb26bd3b9b130 [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:18:29.113703 16406 raft_consensus.cc:3060] T 9a91ddcc618b47c9b8199450cb0b4523 P 596aa374dc5f431681fdb26bd3b9b130 [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:18:29.114455 16406 raft_consensus.cc:515] T 9a91ddcc618b47c9b8199450cb0b4523 P 596aa374dc5f431681fdb26bd3b9b130 [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "596aa374dc5f431681fdb26bd3b9b130" member_type: VOTER last_known_addr { host: "127.15.171.1" port: 43193 } }
I20260812 06:18:29.114581 16406 leader_election.cc:304] T 9a91ddcc618b47c9b8199450cb0b4523 P 596aa374dc5f431681fdb26bd3b9b130 [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: 596aa374dc5f431681fdb26bd3b9b130; no voters: 
I20260812 06:18:29.114727 16406 leader_election.cc:290] T 9a91ddcc618b47c9b8199450cb0b4523 P 596aa374dc5f431681fdb26bd3b9b130 [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:18:29.114841 16408 raft_consensus.cc:2804] T 9a91ddcc618b47c9b8199450cb0b4523 P 596aa374dc5f431681fdb26bd3b9b130 [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:18:29.115043 16408 raft_consensus.cc:697] T 9a91ddcc618b47c9b8199450cb0b4523 P 596aa374dc5f431681fdb26bd3b9b130 [term 1 LEADER]: Becoming Leader. State: Replica: 596aa374dc5f431681fdb26bd3b9b130, State: Running, Role: LEADER
I20260812 06:18:29.115059 16406 ts_tablet_manager.cc:1434] T 9a91ddcc618b47c9b8199450cb0b4523 P 596aa374dc5f431681fdb26bd3b9b130: Time spent starting tablet: real 0.002s	user 0.000s	sys 0.002s
I20260812 06:18:29.115109 16394 heartbeater.cc:499] Master 127.15.171.62:35923 was elected leader, sending a full tablet report...
I20260812 06:18:29.115255 16408 consensus_queue.cc:237] T 9a91ddcc618b47c9b8199450cb0b4523 P 596aa374dc5f431681fdb26bd3b9b130 [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: "596aa374dc5f431681fdb26bd3b9b130" member_type: VOTER last_known_addr { host: "127.15.171.1" port: 43193 } }
I20260812 06:18:29.116398 16265 catalog_manager.cc:5719] T 9a91ddcc618b47c9b8199450cb0b4523 P 596aa374dc5f431681fdb26bd3b9b130 reported cstate change: term changed from 0 to 1, leader changed from <none> to 596aa374dc5f431681fdb26bd3b9b130 (127.15.171.1). New cstate: current_term: 1 leader_uuid: "596aa374dc5f431681fdb26bd3b9b130" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "596aa374dc5f431681fdb26bd3b9b130" member_type: VOTER last_known_addr { host: "127.15.171.1" port: 43193 } health_report { overall_health: HEALTHY } } }
I20260812 06:18:29.176479 16044 heavy-update-compaction-itest.cc:215] Time spent inserting: real 0.052s	user 0.023s	sys 0.000s
I20260812 06:18:29.333381 16395 maintenance_manager.cc:419] P 596aa374dc5f431681fdb26bd3b9b130: Scheduling FlushMRSOp(9a91ddcc618b47c9b8199450cb0b4523): perf score=19.054940
I20260812 06:18:29.497521 16335 maintenance_manager.cc:643] P 596aa374dc5f431681fdb26bd3b9b130: FlushMRSOp(9a91ddcc618b47c9b8199450cb0b4523) complete. Timing: real 0.164s	user 0.118s	sys 0.043s Metrics: {"bytes_written":12307490,"cfile_init":1,"delete_count":0,"dirs.queue_time_us":121,"dirs.run_cpu_time_us":159,"dirs.run_wall_time_us":842,"drs_written":1,"lbm_read_time_us":82,"lbm_reads_lt_1ms":4,"lbm_write_time_us":41631,"lbm_writes_lt_1ms":757,"peak_mem_usage":0,"reinsert_count":0,"rows_written":104,"update_count":1500}
I20260812 06:18:29.498265 16395 maintenance_manager.cc:419] P 596aa374dc5f431681fdb26bd3b9b130: Scheduling LogGCOp(9a91ddcc618b47c9b8199450cb0b4523): free 20743880 bytes of WAL
I20260812 06:18:29.498481 16335 log_reader.cc:385] T 9a91ddcc618b47c9b8199450cb0b4523: removed 2 log segments from log reader
I20260812 06:18:29.498523 16335 log.cc:1079] T 9a91ddcc618b47c9b8199450cb0b4523 P 596aa374dc5f431681fdb26bd3b9b130: Deleting log segment in path: /tmp/dist-test-taskSk6K39/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515503120097-16044-0/minicluster-data/ts-0-root/wals/9a91ddcc618b47c9b8199450cb0b4523/wal-000000001 (ops 1-6)
I20260812 06:18:29.498564 16335 log.cc:1079] T 9a91ddcc618b47c9b8199450cb0b4523 P 596aa374dc5f431681fdb26bd3b9b130: Deleting log segment in path: /tmp/dist-test-taskSk6K39/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515503120097-16044-0/minicluster-data/ts-0-root/wals/9a91ddcc618b47c9b8199450cb0b4523/wal-000000002 (ops 7-11)
I20260812 06:18:29.502033 16335 maintenance_manager.cc:643] P 596aa374dc5f431681fdb26bd3b9b130: LogGCOp(9a91ddcc618b47c9b8199450cb0b4523) complete. Timing: real 0.004s	user 0.000s	sys 0.001s Metrics: {}
I20260812 06:18:29.502446 16395 maintenance_manager.cc:419] P 596aa374dc5f431681fdb26bd3b9b130: Scheduling UndoDeltaBlockGCOp(9a91ddcc618b47c9b8199450cb0b4523): 16411395 bytes on disk
I20260812 06:18:29.502951 16335 maintenance_manager.cc:643] P 596aa374dc5f431681fdb26bd3b9b130: UndoDeltaBlockGCOp(9a91ddcc618b47c9b8199450cb0b4523) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":63,"lbm_reads_lt_1ms":4}
I20260812 06:18:29.503443 16395 maintenance_manager.cc:419] P 596aa374dc5f431681fdb26bd3b9b130: Scheduling FlushDeltaMemStoresOp(9a91ddcc618b47c9b8199450cb0b4523): perf score=2.188937
I20260812 06:18:29.519789 16335 maintenance_manager.cc:643] P 596aa374dc5f431681fdb26bd3b9b130: FlushDeltaMemStoresOp(9a91ddcc618b47c9b8199450cb0b4523) complete. Timing: real 0.016s	user 0.009s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5117,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:29.520226 16395 maintenance_manager.cc:419] P 596aa374dc5f431681fdb26bd3b9b130: Scheduling MajorDeltaCompactionOp(9a91ddcc618b47c9b8199450cb0b4523): perf score=1.000000
I20260812 06:18:29.671347 16335 maintenance_manager.cc:643] P 596aa374dc5f431681fdb26bd3b9b130: MajorDeltaCompactionOp(9a91ddcc618b47c9b8199450cb0b4523) complete. Timing: real 0.151s	user 0.100s	sys 0.045s 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":765,"lbm_read_time_us":9986,"lbm_reads_lt_1ms":464,"lbm_write_time_us":23661,"lbm_writes_lt_1ms":443,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":768,"thread_start_us":303,"threads_started":5,"update_count":2000}
I20260812 06:18:29.672102 16395 maintenance_manager.cc:419] P 596aa374dc5f431681fdb26bd3b9b130: Scheduling FlushDeltaMemStoresOp(9a91ddcc618b47c9b8199450cb0b4523): perf score=11.118625
I20260812 06:18:29.718279 16335 maintenance_manager.cc:643] P 596aa374dc5f431681fdb26bd3b9b130: FlushDeltaMemStoresOp(9a91ddcc618b47c9b8199450cb0b4523) complete. Timing: real 0.046s	user 0.024s	sys 0.019s Metrics: {"bytes_written":12717735,"delete_count":0,"lbm_write_time_us":15913,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:18:29.719017 16395 maintenance_manager.cc:419] P 596aa374dc5f431681fdb26bd3b9b130: Scheduling FlushDeltaMemStoresOp(9a91ddcc618b47c9b8199450cb0b4523): perf score=2.188937
I20260812 06:18:29.733191 16335 maintenance_manager.cc:643] P 596aa374dc5f431681fdb26bd3b9b130: FlushDeltaMemStoresOp(9a91ddcc618b47c9b8199450cb0b4523) complete. Timing: real 0.014s	user 0.004s	sys 0.008s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":5101,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:18:29.733752 16395 maintenance_manager.cc:419] P 596aa374dc5f431681fdb26bd3b9b130: Scheduling MajorDeltaCompactionOp(9a91ddcc618b47c9b8199450cb0b4523): perf score=1.000000
I20260812 06:18:29.890715 16335 maintenance_manager.cc:643] P 596aa374dc5f431681fdb26bd3b9b130: MajorDeltaCompactionOp(9a91ddcc618b47c9b8199450cb0b4523) complete. Timing: real 0.157s	user 0.109s	sys 0.048s 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":107,"lbm_read_time_us":11082,"lbm_reads_lt_1ms":464,"lbm_write_time_us":24975,"lbm_writes_lt_1ms":443,"mutex_wait_us":28,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":12032,"update_count":2000}
I20260812 06:18:29.891223 16395 maintenance_manager.cc:419] P 596aa374dc5f431681fdb26bd3b9b130: Scheduling FlushDeltaMemStoresOp(9a91ddcc618b47c9b8199450cb0b4523): perf score=10.126437
I20260812 06:18:29.930917 16335 maintenance_manager.cc:643] P 596aa374dc5f431681fdb26bd3b9b130: FlushDeltaMemStoresOp(9a91ddcc618b47c9b8199450cb0b4523) complete. Timing: real 0.040s	user 0.022s	sys 0.011s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":15106,"lbm_writes_lt_1ms":303,"reinsert_count":0,"spinlock_wait_cycles":2944,"update_count":1500}
I20260812 06:18:29.931427 16395 maintenance_manager.cc:419] P 596aa374dc5f431681fdb26bd3b9b130: Scheduling FlushDeltaMemStoresOp(9a91ddcc618b47c9b8199450cb0b4523): perf score=2.188937
I20260812 06:18:29.942076 16335 maintenance_manager.cc:643] P 596aa374dc5f431681fdb26bd3b9b130: FlushDeltaMemStoresOp(9a91ddcc618b47c9b8199450cb0b4523) complete. Timing: real 0.010s	user 0.002s	sys 0.007s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3997,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:29.942452 16395 maintenance_manager.cc:419] P 596aa374dc5f431681fdb26bd3b9b130: Scheduling MajorDeltaCompactionOp(9a91ddcc618b47c9b8199450cb0b4523): perf score=1.000000
I20260812 06:18:30.082966 16335 maintenance_manager.cc:643] P 596aa374dc5f431681fdb26bd3b9b130: MajorDeltaCompactionOp(9a91ddcc618b47c9b8199450cb0b4523) complete. Timing: real 0.140s	user 0.105s	sys 0.033s 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":179,"lbm_read_time_us":10254,"lbm_reads_lt_1ms":472,"lbm_write_time_us":27550,"lbm_writes_lt_1ms":443,"mutex_wait_us":20,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":12160,"update_count":2000}
I20260812 06:18:30.086373 16395 maintenance_manager.cc:419] P 596aa374dc5f431681fdb26bd3b9b130: Scheduling FlushDeltaMemStoresOp(9a91ddcc618b47c9b8199450cb0b4523): perf score=10.126437
I20260812 06:18:30.139418 16335 maintenance_manager.cc:643] P 596aa374dc5f431681fdb26bd3b9b130: FlushDeltaMemStoresOp(9a91ddcc618b47c9b8199450cb0b4523) complete. Timing: real 0.053s	user 0.023s	sys 0.016s Metrics: {"bytes_written":12307489,"delete_count":0,"lbm_write_time_us":18693,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:18:30.140012 16395 maintenance_manager.cc:419] P 596aa374dc5f431681fdb26bd3b9b130: Scheduling FlushDeltaMemStoresOp(9a91ddcc618b47c9b8199450cb0b4523): perf score=2.188937
I20260812 06:18:30.153106 16335 maintenance_manager.cc:643] P 596aa374dc5f431681fdb26bd3b9b130: FlushDeltaMemStoresOp(9a91ddcc618b47c9b8199450cb0b4523) complete. Timing: real 0.013s	user 0.007s	sys 0.005s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4643,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:30.153649 16395 maintenance_manager.cc:419] P 596aa374dc5f431681fdb26bd3b9b130: Scheduling MajorDeltaCompactionOp(9a91ddcc618b47c9b8199450cb0b4523): perf score=1.000000
I20260812 06:18:30.293737 16335 maintenance_manager.cc:643] P 596aa374dc5f431681fdb26bd3b9b130: MajorDeltaCompactionOp(9a91ddcc618b47c9b8199450cb0b4523) complete. Timing: real 0.140s	user 0.102s	sys 0.036s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672276,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":160,"lbm_read_time_us":9385,"lbm_reads_lt_1ms":472,"lbm_write_time_us":27663,"lbm_writes_lt_1ms":443,"mutex_wait_us":3,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":85888,"update_count":2000}
I20260812 06:18:30.294450 16395 maintenance_manager.cc:419] P 596aa374dc5f431681fdb26bd3b9b130: Scheduling FlushDeltaMemStoresOp(9a91ddcc618b47c9b8199450cb0b4523): perf score=10.126437
I20260812 06:18:30.344564 16335 maintenance_manager.cc:643] P 596aa374dc5f431681fdb26bd3b9b130: FlushDeltaMemStoresOp(9a91ddcc618b47c9b8199450cb0b4523) complete. Timing: real 0.050s	user 0.022s	sys 0.023s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":16708,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:18:30.345042 16395 maintenance_manager.cc:419] P 596aa374dc5f431681fdb26bd3b9b130: Scheduling FlushDeltaMemStoresOp(9a91ddcc618b47c9b8199450cb0b4523): perf score=2.188937
I20260812 06:18:30.355670 16335 maintenance_manager.cc:643] P 596aa374dc5f431681fdb26bd3b9b130: FlushDeltaMemStoresOp(9a91ddcc618b47c9b8199450cb0b4523) complete. Timing: real 0.010s	user 0.006s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4011,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:30.356037 16395 maintenance_manager.cc:419] P 596aa374dc5f431681fdb26bd3b9b130: Scheduling MajorDeltaCompactionOp(9a91ddcc618b47c9b8199450cb0b4523): perf score=1.000000
I20260812 06:18:30.506268 16335 maintenance_manager.cc:643] P 596aa374dc5f431681fdb26bd3b9b130: MajorDeltaCompactionOp(9a91ddcc618b47c9b8199450cb0b4523) complete. Timing: real 0.150s	user 0.116s	sys 0.033s 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":185,"lbm_read_time_us":10253,"lbm_reads_lt_1ms":472,"lbm_write_time_us":22064,"lbm_writes_lt_1ms":443,"mutex_wait_us":36,"peak_mem_usage":50689328,"reinsert_count":0,"update_count":2000}
I20260812 06:18:30.506843 16395 maintenance_manager.cc:419] P 596aa374dc5f431681fdb26bd3b9b130: Scheduling FlushDeltaMemStoresOp(9a91ddcc618b47c9b8199450cb0b4523): perf score=7.149875
I20260812 06:18:30.538499 16335 maintenance_manager.cc:643] P 596aa374dc5f431681fdb26bd3b9b130: FlushDeltaMemStoresOp(9a91ddcc618b47c9b8199450cb0b4523) complete. Timing: real 0.031s	user 0.020s	sys 0.008s Metrics: {"bytes_written":8615323,"delete_count":0,"lbm_write_time_us":13268,"lbm_writes_lt_1ms":213,"reinsert_count":0,"update_count":1050}
I20260812 06:18:30.538990 16395 maintenance_manager.cc:419] P 596aa374dc5f431681fdb26bd3b9b130: Scheduling FlushDeltaMemStoresOp(9a91ddcc618b47c9b8199450cb0b4523): perf score=2.188937
I20260812 06:18:30.552722 16335 maintenance_manager.cc:643] P 596aa374dc5f431681fdb26bd3b9b130: FlushDeltaMemStoresOp(9a91ddcc618b47c9b8199450cb0b4523) complete. Timing: real 0.014s	user 0.012s	sys 0.000s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":4980,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:18:30.553242 16395 maintenance_manager.cc:419] P 596aa374dc5f431681fdb26bd3b9b130: Scheduling MajorDeltaCompactionOp(9a91ddcc618b47c9b8199450cb0b4523): perf score=1.000000
I20260812 06:18:30.679380 16335 maintenance_manager.cc:643] P 596aa374dc5f431681fdb26bd3b9b130: MajorDeltaCompactionOp(9a91ddcc618b47c9b8199450cb0b4523) complete. Timing: real 0.126s	user 0.098s	sys 0.016s Metrics: {"cfile_cache_miss":332,"cfile_cache_miss_bytes":16569856,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":471,"lbm_read_time_us":7300,"lbm_reads_lt_1ms":372,"lbm_write_time_us":21074,"lbm_writes_lt_1ms":343,"mutex_wait_us":274,"peak_mem_usage":38262756,"reinsert_count":0,"spinlock_wait_cycles":2176,"update_count":1500}
I20260812 06:18:30.679982 16395 maintenance_manager.cc:419] P 596aa374dc5f431681fdb26bd3b9b130: Scheduling FlushDeltaMemStoresOp(9a91ddcc618b47c9b8199450cb0b4523): perf score=10.126437
I20260812 06:18:30.716802 16335 maintenance_manager.cc:643] P 596aa374dc5f431681fdb26bd3b9b130: FlushDeltaMemStoresOp(9a91ddcc618b47c9b8199450cb0b4523) complete. Timing: real 0.037s	user 0.014s	sys 0.016s Metrics: {"bytes_written":12307491,"delete_count":0,"lbm_write_time_us":13050,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:18:30.717367 16395 maintenance_manager.cc:419] P 596aa374dc5f431681fdb26bd3b9b130: Scheduling MajorDeltaCompactionOp(9a91ddcc618b47c9b8199450cb0b4523): perf score=1.000000
I20260812 06:18:30.844588 16335 maintenance_manager.cc:643] P 596aa374dc5f431681fdb26bd3b9b130: MajorDeltaCompactionOp(9a91ddcc618b47c9b8199450cb0b4523) complete. Timing: real 0.127s	user 0.111s	sys 0.016s Metrics: {"cfile_cache_miss":331,"cfile_cache_miss_bytes":16569747,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":1,"delta_iterators_relevant":1,"dirs.queue_time_us":314,"lbm_read_time_us":8467,"lbm_reads_lt_1ms":363,"lbm_write_time_us":23322,"lbm_writes_lt_1ms":343,"mutex_wait_us":39,"peak_mem_usage":38262756,"reinsert_count":0,"spinlock_wait_cycles":20480,"update_count":1500}
I20260812 06:18:30.845165 16395 maintenance_manager.cc:419] P 596aa374dc5f431681fdb26bd3b9b130: Scheduling FlushDeltaMemStoresOp(9a91ddcc618b47c9b8199450cb0b4523): perf score=10.126437
I20260812 06:18:30.887709 16335 maintenance_manager.cc:643] P 596aa374dc5f431681fdb26bd3b9b130: FlushDeltaMemStoresOp(9a91ddcc618b47c9b8199450cb0b4523) complete. Timing: real 0.042s	user 0.034s	sys 0.003s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":16166,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:18:30.888309 16395 maintenance_manager.cc:419] P 596aa374dc5f431681fdb26bd3b9b130: Scheduling FlushDeltaMemStoresOp(9a91ddcc618b47c9b8199450cb0b4523): perf score=2.188937
I20260812 06:18:30.903338 16335 maintenance_manager.cc:643] P 596aa374dc5f431681fdb26bd3b9b130: FlushDeltaMemStoresOp(9a91ddcc618b47c9b8199450cb0b4523) complete. Timing: real 0.015s	user 0.008s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5311,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:30.903882 16395 maintenance_manager.cc:419] P 596aa374dc5f431681fdb26bd3b9b130: Scheduling FlushMRSOp(9a91ddcc618b47c9b8199450cb0b4523): perf score=1.000000
I20260812 06:18:30.933123 16335 maintenance_manager.cc:643] P 596aa374dc5f431681fdb26bd3b9b130: FlushMRSOp(9a91ddcc618b47c9b8199450cb0b4523) complete. Timing: real 0.029s	user 0.023s	sys 0.005s Metrics: {"bytes_written":1234473,"cfile_init":1,"dirs.queue_time_us":63,"dirs.run_cpu_time_us":213,"dirs.run_wall_time_us":1212,"drs_written":1,"lbm_read_time_us":54,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1764,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":30}
I20260812 06:18:30.933804 16395 maintenance_manager.cc:419] P 596aa374dc5f431681fdb26bd3b9b130: Scheduling LogGCOp(9a91ddcc618b47c9b8199450cb0b4523): free 124710294 bytes of WAL
I20260812 06:18:30.934059 16335 log_reader.cc:385] T 9a91ddcc618b47c9b8199450cb0b4523: removed 12 log segments from log reader
I20260812 06:18:30.934108 16335 log.cc:1079] T 9a91ddcc618b47c9b8199450cb0b4523 P 596aa374dc5f431681fdb26bd3b9b130: Deleting log segment in path: /tmp/dist-test-taskSk6K39/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515503120097-16044-0/minicluster-data/ts-0-root/wals/9a91ddcc618b47c9b8199450cb0b4523/wal-000000003 (ops 12-16)
I20260812 06:18:30.934145 16335 log.cc:1079] T 9a91ddcc618b47c9b8199450cb0b4523 P 596aa374dc5f431681fdb26bd3b9b130: Deleting log segment in path: /tmp/dist-test-taskSk6K39/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515503120097-16044-0/minicluster-data/ts-0-root/wals/9a91ddcc618b47c9b8199450cb0b4523/wal-000000004 (ops 17-21)
I20260812 06:18:30.934212 16335 log.cc:1079] T 9a91ddcc618b47c9b8199450cb0b4523 P 596aa374dc5f431681fdb26bd3b9b130: Deleting log segment in path: /tmp/dist-test-taskSk6K39/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515503120097-16044-0/minicluster-data/ts-0-root/wals/9a91ddcc618b47c9b8199450cb0b4523/wal-000000005 (ops 22-26)
I20260812 06:18:30.934244 16335 log.cc:1079] T 9a91ddcc618b47c9b8199450cb0b4523 P 596aa374dc5f431681fdb26bd3b9b130: Deleting log segment in path: /tmp/dist-test-taskSk6K39/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515503120097-16044-0/minicluster-data/ts-0-root/wals/9a91ddcc618b47c9b8199450cb0b4523/wal-000000006 (ops 27-31)
I20260812 06:18:30.934299 16335 log.cc:1079] T 9a91ddcc618b47c9b8199450cb0b4523 P 596aa374dc5f431681fdb26bd3b9b130: Deleting log segment in path: /tmp/dist-test-taskSk6K39/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515503120097-16044-0/minicluster-data/ts-0-root/wals/9a91ddcc618b47c9b8199450cb0b4523/wal-000000007 (ops 32-36)
I20260812 06:18:30.934336 16335 log.cc:1079] T 9a91ddcc618b47c9b8199450cb0b4523 P 596aa374dc5f431681fdb26bd3b9b130: Deleting log segment in path: /tmp/dist-test-taskSk6K39/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515503120097-16044-0/minicluster-data/ts-0-root/wals/9a91ddcc618b47c9b8199450cb0b4523/wal-000000008 (ops 37-41)
I20260812 06:18:30.934358 16335 log.cc:1079] T 9a91ddcc618b47c9b8199450cb0b4523 P 596aa374dc5f431681fdb26bd3b9b130: Deleting log segment in path: /tmp/dist-test-taskSk6K39/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515503120097-16044-0/minicluster-data/ts-0-root/wals/9a91ddcc618b47c9b8199450cb0b4523/wal-000000009 (ops 42-46)
I20260812 06:18:30.934410 16335 log.cc:1079] T 9a91ddcc618b47c9b8199450cb0b4523 P 596aa374dc5f431681fdb26bd3b9b130: Deleting log segment in path: /tmp/dist-test-taskSk6K39/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515503120097-16044-0/minicluster-data/ts-0-root/wals/9a91ddcc618b47c9b8199450cb0b4523/wal-000000010 (ops 47-51)
I20260812 06:18:30.934445 16335 log.cc:1079] T 9a91ddcc618b47c9b8199450cb0b4523 P 596aa374dc5f431681fdb26bd3b9b130: Deleting log segment in path: /tmp/dist-test-taskSk6K39/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515503120097-16044-0/minicluster-data/ts-0-root/wals/9a91ddcc618b47c9b8199450cb0b4523/wal-000000011 (ops 52-56)
I20260812 06:18:30.934501 16335 log.cc:1079] T 9a91ddcc618b47c9b8199450cb0b4523 P 596aa374dc5f431681fdb26bd3b9b130: Deleting log segment in path: /tmp/dist-test-taskSk6K39/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515503120097-16044-0/minicluster-data/ts-0-root/wals/9a91ddcc618b47c9b8199450cb0b4523/wal-000000012 (ops 57-61)
I20260812 06:18:30.934535 16335 log.cc:1079] T 9a91ddcc618b47c9b8199450cb0b4523 P 596aa374dc5f431681fdb26bd3b9b130: Deleting log segment in path: /tmp/dist-test-taskSk6K39/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515503120097-16044-0/minicluster-data/ts-0-root/wals/9a91ddcc618b47c9b8199450cb0b4523/wal-000000013 (ops 62-66)
I20260812 06:18:30.934585 16335 log.cc:1079] T 9a91ddcc618b47c9b8199450cb0b4523 P 596aa374dc5f431681fdb26bd3b9b130: Deleting log segment in path: /tmp/dist-test-taskSk6K39/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515503120097-16044-0/minicluster-data/ts-0-root/wals/9a91ddcc618b47c9b8199450cb0b4523/wal-000000014 (ops 67-71)
I20260812 06:18:30.960843 16335 maintenance_manager.cc:643] P 596aa374dc5f431681fdb26bd3b9b130: LogGCOp(9a91ddcc618b47c9b8199450cb0b4523) complete. Timing: real 0.027s	user 0.000s	sys 0.026s Metrics: {}
I20260812 06:18:30.961251 16395 maintenance_manager.cc:419] P 596aa374dc5f431681fdb26bd3b9b130: Scheduling UndoDeltaBlockGCOp(9a91ddcc618b47c9b8199450cb0b4523): 472 bytes on disk
I20260812 06:18:30.961668 16335 maintenance_manager.cc:643] P 596aa374dc5f431681fdb26bd3b9b130: UndoDeltaBlockGCOp(9a91ddcc618b47c9b8199450cb0b4523) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":58,"lbm_reads_lt_1ms":4}
I20260812 06:18:30.962086 16395 maintenance_manager.cc:419] P 596aa374dc5f431681fdb26bd3b9b130: Scheduling FlushDeltaMemStoresOp(9a91ddcc618b47c9b8199450cb0b4523): perf score=3.181125
I20260812 06:18:30.984714 16335 maintenance_manager.cc:643] P 596aa374dc5f431681fdb26bd3b9b130: FlushDeltaMemStoresOp(9a91ddcc618b47c9b8199450cb0b4523) complete. Timing: real 0.022s	user 0.006s	sys 0.005s Metrics: {"bytes_written":4512903,"delete_count":0,"lbm_write_time_us":4139,"lbm_writes_lt_1ms":113,"reinsert_count":0,"update_count":550}
I20260812 06:18:30.985128 16395 maintenance_manager.cc:419] P 596aa374dc5f431681fdb26bd3b9b130: Scheduling FlushDeltaMemStoresOp(9a91ddcc618b47c9b8199450cb0b4523): perf score=2.188937
I20260812 06:18:30.998229 16335 maintenance_manager.cc:643] P 596aa374dc5f431681fdb26bd3b9b130: FlushDeltaMemStoresOp(9a91ddcc618b47c9b8199450cb0b4523) complete. Timing: real 0.013s	user 0.003s	sys 0.008s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":4803,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:18:30.998682 16395 maintenance_manager.cc:419] P 596aa374dc5f431681fdb26bd3b9b130: Scheduling MajorDeltaCompactionOp(9a91ddcc618b47c9b8199450cb0b4523): perf score=1.000000
I20260812 06:18:31.213163 16335 maintenance_manager.cc:643] P 596aa374dc5f431681fdb26bd3b9b130: MajorDeltaCompactionOp(9a91ddcc618b47c9b8199450cb0b4523) complete. Timing: real 0.214s	user 0.152s	sys 0.059s Metrics: {"cfile_cache_miss":634,"cfile_cache_miss_bytes":28877329,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":4580,"lbm_read_time_us":16468,"lbm_reads_lt_1ms":674,"lbm_write_time_us":33602,"lbm_writes_lt_1ms":643,"mutex_wait_us":3289,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":13568,"thread_start_us":111,"threads_started":1,"update_count":3000}
I20260812 06:18:31.214247 16395 maintenance_manager.cc:419] P 596aa374dc5f431681fdb26bd3b9b130: Scheduling FlushDeltaMemStoresOp(9a91ddcc618b47c9b8199450cb0b4523): perf score=14.095187
I20260812 06:18:31.268803 16335 maintenance_manager.cc:643] P 596aa374dc5f431681fdb26bd3b9b130: FlushDeltaMemStoresOp(9a91ddcc618b47c9b8199450cb0b4523) complete. Timing: real 0.054s	user 0.026s	sys 0.027s Metrics: {"bytes_written":16409904,"delete_count":0,"lbm_write_time_us":20092,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:18:31.269431 16395 maintenance_manager.cc:419] P 596aa374dc5f431681fdb26bd3b9b130: Scheduling FlushDeltaMemStoresOp(9a91ddcc618b47c9b8199450cb0b4523): perf score=2.188937
I20260812 06:18:31.283396 16335 maintenance_manager.cc:643] P 596aa374dc5f431681fdb26bd3b9b130: FlushDeltaMemStoresOp(9a91ddcc618b47c9b8199450cb0b4523) complete. Timing: real 0.014s	user 0.008s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5438,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:31.283852 16395 maintenance_manager.cc:419] P 596aa374dc5f431681fdb26bd3b9b130: Scheduling MajorDeltaCompactionOp(9a91ddcc618b47c9b8199450cb0b4523): perf score=1.000000
I20260812 06:18:31.500555 16335 maintenance_manager.cc:643] P 596aa374dc5f431681fdb26bd3b9b130: MajorDeltaCompactionOp(9a91ddcc618b47c9b8199450cb0b4523) complete. Timing: real 0.217s	user 0.142s	sys 0.062s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774691,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":148,"lbm_read_time_us":13718,"lbm_reads_lt_1ms":572,"lbm_write_time_us":37185,"lbm_writes_lt_1ms":543,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":2688,"update_count":2500}
I20260812 06:18:31.502315 16395 maintenance_manager.cc:419] P 596aa374dc5f431681fdb26bd3b9b130: Scheduling FlushDeltaMemStoresOp(9a91ddcc618b47c9b8199450cb0b4523): perf score=14.095187
I20260812 06:18:31.560037 16335 maintenance_manager.cc:643] P 596aa374dc5f431681fdb26bd3b9b130: FlushDeltaMemStoresOp(9a91ddcc618b47c9b8199450cb0b4523) complete. Timing: real 0.058s	user 0.032s	sys 0.019s Metrics: {"bytes_written":16409906,"delete_count":0,"lbm_write_time_us":19235,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:18:31.560631 16395 maintenance_manager.cc:419] P 596aa374dc5f431681fdb26bd3b9b130: Scheduling FlushDeltaMemStoresOp(9a91ddcc618b47c9b8199450cb0b4523): perf score=2.188937
I20260812 06:18:31.571844 16335 maintenance_manager.cc:643] P 596aa374dc5f431681fdb26bd3b9b130: FlushDeltaMemStoresOp(9a91ddcc618b47c9b8199450cb0b4523) complete. Timing: real 0.011s	user 0.002s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4225,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:31.572292 16395 maintenance_manager.cc:419] P 596aa374dc5f431681fdb26bd3b9b130: Scheduling MajorDeltaCompactionOp(9a91ddcc618b47c9b8199450cb0b4523): perf score=1.000000
I20260812 06:18:31.745173 16335 maintenance_manager.cc:643] P 596aa374dc5f431681fdb26bd3b9b130: MajorDeltaCompactionOp(9a91ddcc618b47c9b8199450cb0b4523) complete. Timing: real 0.173s	user 0.112s	sys 0.060s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774693,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":637,"lbm_read_time_us":11870,"lbm_reads_lt_1ms":572,"lbm_write_time_us":26280,"lbm_writes_lt_1ms":543,"mutex_wait_us":280,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":1792,"update_count":2500}
I20260812 06:18:31.745762 16395 maintenance_manager.cc:419] P 596aa374dc5f431681fdb26bd3b9b130: Scheduling FlushDeltaMemStoresOp(9a91ddcc618b47c9b8199450cb0b4523): perf score=11.118625
I20260812 06:18:31.783424 16335 maintenance_manager.cc:643] P 596aa374dc5f431681fdb26bd3b9b130: FlushDeltaMemStoresOp(9a91ddcc618b47c9b8199450cb0b4523) complete. Timing: real 0.038s	user 0.023s	sys 0.011s Metrics: {"bytes_written":12717736,"delete_count":0,"lbm_write_time_us":16095,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:18:31.783903 16395 maintenance_manager.cc:419] P 596aa374dc5f431681fdb26bd3b9b130: Scheduling FlushDeltaMemStoresOp(9a91ddcc618b47c9b8199450cb0b4523): perf score=2.188937
I20260812 06:18:31.794893 16335 maintenance_manager.cc:643] P 596aa374dc5f431681fdb26bd3b9b130: FlushDeltaMemStoresOp(9a91ddcc618b47c9b8199450cb0b4523) complete. Timing: real 0.011s	user 0.009s	sys 0.000s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3885,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:18:31.795290 16395 maintenance_manager.cc:419] P 596aa374dc5f431681fdb26bd3b9b130: Scheduling MajorDeltaCompactionOp(9a91ddcc618b47c9b8199450cb0b4523): perf score=1.000000
I20260812 06:18:31.927039 16335 maintenance_manager.cc:643] P 596aa374dc5f431681fdb26bd3b9b130: MajorDeltaCompactionOp(9a91ddcc618b47c9b8199450cb0b4523) complete. Timing: real 0.132s	user 0.105s	sys 0.024s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672269,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":847,"lbm_read_time_us":8242,"lbm_reads_lt_1ms":472,"lbm_write_time_us":24234,"lbm_writes_lt_1ms":443,"mutex_wait_us":420,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":16384,"update_count":2000}
I20260812 06:18:31.927698 16395 maintenance_manager.cc:419] P 596aa374dc5f431681fdb26bd3b9b130: Scheduling FlushDeltaMemStoresOp(9a91ddcc618b47c9b8199450cb0b4523): perf score=10.126437
I20260812 06:18:31.973486 16335 maintenance_manager.cc:643] P 596aa374dc5f431681fdb26bd3b9b130: FlushDeltaMemStoresOp(9a91ddcc618b47c9b8199450cb0b4523) complete. Timing: real 0.046s	user 0.015s	sys 0.021s Metrics: {"bytes_written":12307489,"delete_count":0,"lbm_write_time_us":16573,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:18:31.973976 16395 maintenance_manager.cc:419] P 596aa374dc5f431681fdb26bd3b9b130: Scheduling FlushDeltaMemStoresOp(9a91ddcc618b47c9b8199450cb0b4523): perf score=2.188937
I20260812 06:18:31.989271 16335 maintenance_manager.cc:643] P 596aa374dc5f431681fdb26bd3b9b130: FlushDeltaMemStoresOp(9a91ddcc618b47c9b8199450cb0b4523) complete. Timing: real 0.014s	user 0.004s	sys 0.007s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4756,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:31.989872 16395 maintenance_manager.cc:419] P 596aa374dc5f431681fdb26bd3b9b130: Scheduling MajorDeltaCompactionOp(9a91ddcc618b47c9b8199450cb0b4523): perf score=1.000000
I20260812 06:18:32.117281 16335 maintenance_manager.cc:643] P 596aa374dc5f431681fdb26bd3b9b130: MajorDeltaCompactionOp(9a91ddcc618b47c9b8199450cb0b4523) complete. Timing: real 0.127s	user 0.096s	sys 0.030s 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":117,"lbm_read_time_us":8782,"lbm_reads_lt_1ms":464,"lbm_write_time_us":23070,"lbm_writes_lt_1ms":443,"mutex_wait_us":30,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":4096,"update_count":2000}
I20260812 06:18:32.118352 16395 maintenance_manager.cc:419] P 596aa374dc5f431681fdb26bd3b9b130: Scheduling FlushDeltaMemStoresOp(9a91ddcc618b47c9b8199450cb0b4523): perf score=10.126437
I20260812 06:18:32.166368 16335 maintenance_manager.cc:643] P 596aa374dc5f431681fdb26bd3b9b130: FlushDeltaMemStoresOp(9a91ddcc618b47c9b8199450cb0b4523) complete. Timing: real 0.048s	user 0.029s	sys 0.005s Metrics: {"bytes_written":12307491,"delete_count":0,"lbm_write_time_us":15963,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:18:32.166848 16395 maintenance_manager.cc:419] P 596aa374dc5f431681fdb26bd3b9b130: Scheduling FlushDeltaMemStoresOp(9a91ddcc618b47c9b8199450cb0b4523): perf score=2.188937
I20260812 06:18:32.177595 16335 maintenance_manager.cc:643] P 596aa374dc5f431681fdb26bd3b9b130: FlushDeltaMemStoresOp(9a91ddcc618b47c9b8199450cb0b4523) complete. Timing: real 0.011s	user 0.006s	sys 0.003s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4166,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:32.178115 16395 maintenance_manager.cc:419] P 596aa374dc5f431681fdb26bd3b9b130: Scheduling MajorDeltaCompactionOp(9a91ddcc618b47c9b8199450cb0b4523): perf score=1.000000
I20260812 06:18:32.321552 16335 maintenance_manager.cc:643] P 596aa374dc5f431681fdb26bd3b9b130: MajorDeltaCompactionOp(9a91ddcc618b47c9b8199450cb0b4523) complete. Timing: real 0.143s	user 0.120s	sys 0.019s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672278,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":169,"lbm_read_time_us":9934,"lbm_reads_lt_1ms":472,"lbm_write_time_us":24963,"lbm_writes_lt_1ms":443,"mutex_wait_us":110,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":2560,"update_count":2000}
I20260812 06:18:32.322034 16395 maintenance_manager.cc:419] P 596aa374dc5f431681fdb26bd3b9b130: Scheduling FlushDeltaMemStoresOp(9a91ddcc618b47c9b8199450cb0b4523): perf score=10.126437
I20260812 06:18:32.367683 16335 maintenance_manager.cc:643] P 596aa374dc5f431681fdb26bd3b9b130: FlushDeltaMemStoresOp(9a91ddcc618b47c9b8199450cb0b4523) complete. Timing: real 0.046s	user 0.037s	sys 0.008s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":15341,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:18:32.368217 16395 maintenance_manager.cc:419] P 596aa374dc5f431681fdb26bd3b9b130: Scheduling FlushMRSOp(9a91ddcc618b47c9b8199450cb0b4523): perf score=1.000000
I20260812 06:18:32.399521 16335 maintenance_manager.cc:643] P 596aa374dc5f431681fdb26bd3b9b130: FlushMRSOp(9a91ddcc618b47c9b8199450cb0b4523) complete. Timing: real 0.031s	user 0.023s	sys 0.000s Metrics: {"bytes_written":1152514,"cfile_init":1,"dirs.queue_time_us":59,"dirs.run_cpu_time_us":175,"dirs.run_wall_time_us":1408,"drs_written":1,"lbm_read_time_us":44,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1344,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":28}
I20260812 06:18:32.400563 16395 maintenance_manager.cc:419] P 596aa374dc5f431681fdb26bd3b9b130: Scheduling LogGCOp(9a91ddcc618b47c9b8199450cb0b4523): free 112239314 bytes of WAL
I20260812 06:18:32.400888 16335 log_reader.cc:385] T 9a91ddcc618b47c9b8199450cb0b4523: removed 11 log segments from log reader
I20260812 06:18:32.401014 16335 log.cc:1079] T 9a91ddcc618b47c9b8199450cb0b4523 P 596aa374dc5f431681fdb26bd3b9b130: Deleting log segment in path: /tmp/dist-test-taskSk6K39/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515503120097-16044-0/minicluster-data/ts-0-root/wals/9a91ddcc618b47c9b8199450cb0b4523/wal-000000015 (ops 72-76)
I20260812 06:18:32.401110 16335 log.cc:1079] T 9a91ddcc618b47c9b8199450cb0b4523 P 596aa374dc5f431681fdb26bd3b9b130: Deleting log segment in path: /tmp/dist-test-taskSk6K39/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515503120097-16044-0/minicluster-data/ts-0-root/wals/9a91ddcc618b47c9b8199450cb0b4523/wal-000000016 (ops 77-81)
I20260812 06:18:32.401188 16335 log.cc:1079] T 9a91ddcc618b47c9b8199450cb0b4523 P 596aa374dc5f431681fdb26bd3b9b130: Deleting log segment in path: /tmp/dist-test-taskSk6K39/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515503120097-16044-0/minicluster-data/ts-0-root/wals/9a91ddcc618b47c9b8199450cb0b4523/wal-000000017 (ops 82-86)
I20260812 06:18:32.401244 16335 log.cc:1079] T 9a91ddcc618b47c9b8199450cb0b4523 P 596aa374dc5f431681fdb26bd3b9b130: Deleting log segment in path: /tmp/dist-test-taskSk6K39/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515503120097-16044-0/minicluster-data/ts-0-root/wals/9a91ddcc618b47c9b8199450cb0b4523/wal-000000018 (ops 87-91)
I20260812 06:18:32.401299 16335 log.cc:1079] T 9a91ddcc618b47c9b8199450cb0b4523 P 596aa374dc5f431681fdb26bd3b9b130: Deleting log segment in path: /tmp/dist-test-taskSk6K39/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515503120097-16044-0/minicluster-data/ts-0-root/wals/9a91ddcc618b47c9b8199450cb0b4523/wal-000000019 (ops 92-96)
I20260812 06:18:32.401362 16335 log.cc:1079] T 9a91ddcc618b47c9b8199450cb0b4523 P 596aa374dc5f431681fdb26bd3b9b130: Deleting log segment in path: /tmp/dist-test-taskSk6K39/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515503120097-16044-0/minicluster-data/ts-0-root/wals/9a91ddcc618b47c9b8199450cb0b4523/wal-000000020 (ops 97-100)
I20260812 06:18:32.401432 16335 log.cc:1079] T 9a91ddcc618b47c9b8199450cb0b4523 P 596aa374dc5f431681fdb26bd3b9b130: Deleting log segment in path: /tmp/dist-test-taskSk6K39/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515503120097-16044-0/minicluster-data/ts-0-root/wals/9a91ddcc618b47c9b8199450cb0b4523/wal-000000021 (ops 101-105)
I20260812 06:18:32.401504 16335 log.cc:1079] T 9a91ddcc618b47c9b8199450cb0b4523 P 596aa374dc5f431681fdb26bd3b9b130: Deleting log segment in path: /tmp/dist-test-taskSk6K39/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515503120097-16044-0/minicluster-data/ts-0-root/wals/9a91ddcc618b47c9b8199450cb0b4523/wal-000000022 (ops 106-110)
I20260812 06:18:32.401580 16335 log.cc:1079] T 9a91ddcc618b47c9b8199450cb0b4523 P 596aa374dc5f431681fdb26bd3b9b130: Deleting log segment in path: /tmp/dist-test-taskSk6K39/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515503120097-16044-0/minicluster-data/ts-0-root/wals/9a91ddcc618b47c9b8199450cb0b4523/wal-000000023 (ops 111-115)
I20260812 06:18:32.401657 16335 log.cc:1079] T 9a91ddcc618b47c9b8199450cb0b4523 P 596aa374dc5f431681fdb26bd3b9b130: Deleting log segment in path: /tmp/dist-test-taskSk6K39/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515503120097-16044-0/minicluster-data/ts-0-root/wals/9a91ddcc618b47c9b8199450cb0b4523/wal-000000024 (ops 116-120)
I20260812 06:18:32.401731 16335 log.cc:1079] T 9a91ddcc618b47c9b8199450cb0b4523 P 596aa374dc5f431681fdb26bd3b9b130: Deleting log segment in path: /tmp/dist-test-taskSk6K39/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515503120097-16044-0/minicluster-data/ts-0-root/wals/9a91ddcc618b47c9b8199450cb0b4523/wal-000000025 (ops 121-125)
I20260812 06:18:32.423538 16335 maintenance_manager.cc:643] P 596aa374dc5f431681fdb26bd3b9b130: LogGCOp(9a91ddcc618b47c9b8199450cb0b4523) complete. Timing: real 0.023s	user 0.000s	sys 0.019s Metrics: {}
I20260812 06:18:32.423931 16395 maintenance_manager.cc:419] P 596aa374dc5f431681fdb26bd3b9b130: Scheduling UndoDeltaBlockGCOp(9a91ddcc618b47c9b8199450cb0b4523): 447 bytes on disk
I20260812 06:18:32.424309 16335 maintenance_manager.cc:643] P 596aa374dc5f431681fdb26bd3b9b130: UndoDeltaBlockGCOp(9a91ddcc618b47c9b8199450cb0b4523) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":47,"lbm_reads_lt_1ms":4}
I20260812 06:18:32.424907 16395 maintenance_manager.cc:419] P 596aa374dc5f431681fdb26bd3b9b130: Scheduling FlushDeltaMemStoresOp(9a91ddcc618b47c9b8199450cb0b4523): perf score=3.181125
I20260812 06:18:32.439976 16335 maintenance_manager.cc:643] P 596aa374dc5f431681fdb26bd3b9b130: FlushDeltaMemStoresOp(9a91ddcc618b47c9b8199450cb0b4523) complete. Timing: real 0.015s	user 0.008s	sys 0.005s Metrics: {"bytes_written":4512901,"delete_count":0,"lbm_write_time_us":4674,"lbm_writes_lt_1ms":113,"reinsert_count":0,"update_count":550}
I20260812 06:18:32.440495 16395 maintenance_manager.cc:419] P 596aa374dc5f431681fdb26bd3b9b130: Scheduling FlushDeltaMemStoresOp(9a91ddcc618b47c9b8199450cb0b4523): perf score=2.188937
I20260812 06:18:32.456022 16335 maintenance_manager.cc:643] P 596aa374dc5f431681fdb26bd3b9b130: FlushDeltaMemStoresOp(9a91ddcc618b47c9b8199450cb0b4523) complete. Timing: real 0.015s	user 0.007s	sys 0.008s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":5644,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:18:32.456694 16395 maintenance_manager.cc:419] P 596aa374dc5f431681fdb26bd3b9b130: Scheduling MajorDeltaCompactionOp(9a91ddcc618b47c9b8199450cb0b4523): perf score=1.000000
I20260812 06:18:32.644902 16335 maintenance_manager.cc:643] P 596aa374dc5f431681fdb26bd3b9b130: MajorDeltaCompactionOp(9a91ddcc618b47c9b8199450cb0b4523) complete. Timing: real 0.188s	user 0.135s	sys 0.052s Metrics: {"cfile_cache_miss":533,"cfile_cache_miss_bytes":24774796,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":533,"lbm_read_time_us":12012,"lbm_reads_lt_1ms":573,"lbm_write_time_us":32721,"lbm_writes_lt_1ms":543,"mutex_wait_us":258,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":2304,"thread_start_us":60,"threads_started":1,"update_count":2500}
I20260812 06:18:32.645462 16395 maintenance_manager.cc:419] P 596aa374dc5f431681fdb26bd3b9b130: Scheduling FlushDeltaMemStoresOp(9a91ddcc618b47c9b8199450cb0b4523): perf score=14.095187
I20260812 06:18:32.708724 16335 maintenance_manager.cc:643] P 596aa374dc5f431681fdb26bd3b9b130: FlushDeltaMemStoresOp(9a91ddcc618b47c9b8199450cb0b4523) complete. Timing: real 0.063s	user 0.027s	sys 0.035s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":22845,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:18:32.709367 16395 maintenance_manager.cc:419] P 596aa374dc5f431681fdb26bd3b9b130: Scheduling FlushDeltaMemStoresOp(9a91ddcc618b47c9b8199450cb0b4523): perf score=2.188937
I20260812 06:18:32.721637 16335 maintenance_manager.cc:643] P 596aa374dc5f431681fdb26bd3b9b130: FlushDeltaMemStoresOp(9a91ddcc618b47c9b8199450cb0b4523) complete. Timing: real 0.012s	user 0.006s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4274,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:32.722177 16395 maintenance_manager.cc:419] P 596aa374dc5f431681fdb26bd3b9b130: Scheduling MajorDeltaCompactionOp(9a91ddcc618b47c9b8199450cb0b4523): perf score=1.000000
I20260812 06:18:32.902068 16335 maintenance_manager.cc:643] P 596aa374dc5f431681fdb26bd3b9b130: MajorDeltaCompactionOp(9a91ddcc618b47c9b8199450cb0b4523) complete. Timing: real 0.180s	user 0.137s	sys 0.039s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774689,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":1619,"lbm_read_time_us":14642,"lbm_reads_1-10_ms":1,"lbm_reads_lt_1ms":571,"lbm_write_time_us":27396,"lbm_writes_lt_1ms":543,"mutex_wait_us":319,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":6400,"update_count":2500}
I20260812 06:18:32.902513 16395 maintenance_manager.cc:419] P 596aa374dc5f431681fdb26bd3b9b130: Scheduling FlushDeltaMemStoresOp(9a91ddcc618b47c9b8199450cb0b4523): perf score=11.118625
I20260812 06:18:32.937115 16335 maintenance_manager.cc:643] P 596aa374dc5f431681fdb26bd3b9b130: FlushDeltaMemStoresOp(9a91ddcc618b47c9b8199450cb0b4523) complete. Timing: real 0.034s	user 0.023s	sys 0.010s Metrics: {"bytes_written":12717735,"delete_count":0,"lbm_write_time_us":14187,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:18:32.938058 16395 maintenance_manager.cc:419] P 596aa374dc5f431681fdb26bd3b9b130: Scheduling FlushDeltaMemStoresOp(9a91ddcc618b47c9b8199450cb0b4523): perf score=2.188937
I20260812 06:18:32.971895 16335 maintenance_manager.cc:643] P 596aa374dc5f431681fdb26bd3b9b130: FlushDeltaMemStoresOp(9a91ddcc618b47c9b8199450cb0b4523) complete. Timing: real 0.034s	user 0.008s	sys 0.003s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4437,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:32.972421 16395 maintenance_manager.cc:419] P 596aa374dc5f431681fdb26bd3b9b130: Scheduling FlushDeltaMemStoresOp(9a91ddcc618b47c9b8199450cb0b4523): perf score=2.188937
I20260812 06:18:32.982370 16335 maintenance_manager.cc:643] P 596aa374dc5f431681fdb26bd3b9b130: FlushDeltaMemStoresOp(9a91ddcc618b47c9b8199450cb0b4523) complete. Timing: real 0.010s	user 0.001s	sys 0.008s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3697,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:18:32.982758 16395 maintenance_manager.cc:419] P 596aa374dc5f431681fdb26bd3b9b130: Scheduling MajorDeltaCompactionOp(9a91ddcc618b47c9b8199450cb0b4523): perf score=1.000000
I20260812 06:18:33.185393 16335 maintenance_manager.cc:643] P 596aa374dc5f431681fdb26bd3b9b130: MajorDeltaCompactionOp(9a91ddcc618b47c9b8199450cb0b4523) complete. Timing: real 0.202s	user 0.136s	sys 0.052s 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":588,"lbm_read_time_us":12235,"lbm_reads_lt_1ms":573,"lbm_write_time_us":33562,"lbm_writes_lt_1ms":543,"mutex_wait_us":303,"peak_mem_usage":63115900,"reinsert_count":0,"update_count":2500}
I20260812 06:18:33.185918 16395 maintenance_manager.cc:419] P 596aa374dc5f431681fdb26bd3b9b130: Scheduling FlushDeltaMemStoresOp(9a91ddcc618b47c9b8199450cb0b4523): perf score=14.095187
I20260812 06:18:33.238472 16335 maintenance_manager.cc:643] P 596aa374dc5f431681fdb26bd3b9b130: FlushDeltaMemStoresOp(9a91ddcc618b47c9b8199450cb0b4523) complete. Timing: real 0.052s	user 0.021s	sys 0.020s Metrics: {"bytes_written":16409903,"delete_count":0,"lbm_write_time_us":19278,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:18:33.238876 16395 maintenance_manager.cc:419] P 596aa374dc5f431681fdb26bd3b9b130: Scheduling FlushDeltaMemStoresOp(9a91ddcc618b47c9b8199450cb0b4523): perf score=2.188937
I20260812 06:18:33.259781 16335 maintenance_manager.cc:643] P 596aa374dc5f431681fdb26bd3b9b130: FlushDeltaMemStoresOp(9a91ddcc618b47c9b8199450cb0b4523) complete. Timing: real 0.021s	user 0.010s	sys 0.010s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4445,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:33.260425 16395 maintenance_manager.cc:419] P 596aa374dc5f431681fdb26bd3b9b130: Scheduling MajorDeltaCompactionOp(9a91ddcc618b47c9b8199450cb0b4523): perf score=1.000000
I20260812 06:18:33.442525 16335 maintenance_manager.cc:643] P 596aa374dc5f431681fdb26bd3b9b130: MajorDeltaCompactionOp(9a91ddcc618b47c9b8199450cb0b4523) complete. Timing: real 0.182s	user 0.113s	sys 0.069s 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":244,"lbm_read_time_us":12471,"lbm_reads_lt_1ms":572,"lbm_write_time_us":30649,"lbm_writes_lt_1ms":543,"mutex_wait_us":44,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":17024,"update_count":2500}
I20260812 06:18:33.444020 16395 maintenance_manager.cc:419] P 596aa374dc5f431681fdb26bd3b9b130: Scheduling FlushDeltaMemStoresOp(9a91ddcc618b47c9b8199450cb0b4523): perf score=10.126437
I20260812 06:18:33.482017 16335 maintenance_manager.cc:643] P 596aa374dc5f431681fdb26bd3b9b130: FlushDeltaMemStoresOp(9a91ddcc618b47c9b8199450cb0b4523) complete. Timing: real 0.037s	user 0.013s	sys 0.016s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":13065,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:18:33.482468 16395 maintenance_manager.cc:419] P 596aa374dc5f431681fdb26bd3b9b130: Scheduling FlushDeltaMemStoresOp(9a91ddcc618b47c9b8199450cb0b4523): perf score=2.188937
I20260812 06:18:33.495184 16335 maintenance_manager.cc:643] P 596aa374dc5f431681fdb26bd3b9b130: FlushDeltaMemStoresOp(9a91ddcc618b47c9b8199450cb0b4523) complete. Timing: real 0.013s	user 0.000s	sys 0.011s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4440,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:33.495867 16395 maintenance_manager.cc:419] P 596aa374dc5f431681fdb26bd3b9b130: Scheduling MajorDeltaCompactionOp(9a91ddcc618b47c9b8199450cb0b4523): perf score=1.000000
I20260812 06:18:33.632282 16335 maintenance_manager.cc:643] P 596aa374dc5f431681fdb26bd3b9b130: MajorDeltaCompactionOp(9a91ddcc618b47c9b8199450cb0b4523) complete. Timing: real 0.136s	user 0.102s	sys 0.032s 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":507,"lbm_read_time_us":8049,"lbm_reads_lt_1ms":472,"lbm_write_time_us":25743,"lbm_writes_lt_1ms":443,"mutex_wait_us":36,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":4096,"update_count":2000}
I20260812 06:18:33.632946 16395 maintenance_manager.cc:419] P 596aa374dc5f431681fdb26bd3b9b130: Scheduling FlushDeltaMemStoresOp(9a91ddcc618b47c9b8199450cb0b4523): perf score=10.126437
I20260812 06:18:33.676848 16335 maintenance_manager.cc:643] P 596aa374dc5f431681fdb26bd3b9b130: FlushDeltaMemStoresOp(9a91ddcc618b47c9b8199450cb0b4523) complete. Timing: real 0.044s	user 0.030s	sys 0.003s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":14584,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:18:33.677341 16395 maintenance_manager.cc:419] P 596aa374dc5f431681fdb26bd3b9b130: Scheduling FlushDeltaMemStoresOp(9a91ddcc618b47c9b8199450cb0b4523): perf score=2.188937
I20260812 06:18:33.692664 16335 maintenance_manager.cc:643] P 596aa374dc5f431681fdb26bd3b9b130: FlushDeltaMemStoresOp(9a91ddcc618b47c9b8199450cb0b4523) complete. Timing: real 0.015s	user 0.010s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5535,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:33.693383 16395 maintenance_manager.cc:419] P 596aa374dc5f431681fdb26bd3b9b130: Scheduling MajorDeltaCompactionOp(9a91ddcc618b47c9b8199450cb0b4523): perf score=1.000000
I20260812 06:18:33.828320 16335 maintenance_manager.cc:643] P 596aa374dc5f431681fdb26bd3b9b130: MajorDeltaCompactionOp(9a91ddcc618b47c9b8199450cb0b4523) complete. Timing: real 0.135s	user 0.109s	sys 0.023s 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":159,"lbm_read_time_us":8601,"lbm_reads_lt_1ms":472,"lbm_write_time_us":26591,"lbm_writes_lt_1ms":443,"mutex_wait_us":41,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":4352,"update_count":2000}
I20260812 06:18:33.829018 16395 maintenance_manager.cc:419] P 596aa374dc5f431681fdb26bd3b9b130: Scheduling FlushDeltaMemStoresOp(9a91ddcc618b47c9b8199450cb0b4523): perf score=10.126437
I20260812 06:18:33.870509 16335 maintenance_manager.cc:643] P 596aa374dc5f431681fdb26bd3b9b130: FlushDeltaMemStoresOp(9a91ddcc618b47c9b8199450cb0b4523) complete. Timing: real 0.041s	user 0.033s	sys 0.004s Metrics: {"bytes_written":12307491,"delete_count":0,"lbm_write_time_us":17959,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:18:33.871176 16395 maintenance_manager.cc:419] P 596aa374dc5f431681fdb26bd3b9b130: Scheduling FlushMRSOp(9a91ddcc618b47c9b8199450cb0b4523): perf score=1.000000
I20260812 06:18:33.928027 16335 maintenance_manager.cc:643] P 596aa374dc5f431681fdb26bd3b9b130: FlushMRSOp(9a91ddcc618b47c9b8199450cb0b4523) complete. Timing: real 0.057s	user 0.033s	sys 0.000s Metrics: {"bytes_written":1152510,"cfile_init":1,"dirs.queue_time_us":68,"dirs.run_cpu_time_us":178,"dirs.run_wall_time_us":2074,"drs_written":1,"lbm_read_time_us":56,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1499,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":28}
I20260812 06:18:33.928839 16395 maintenance_manager.cc:419] P 596aa374dc5f431681fdb26bd3b9b130: Scheduling LogGCOp(9a91ddcc618b47c9b8199450cb0b4523): free 112239488 bytes of WAL
I20260812 06:18:33.929065 16335 log_reader.cc:385] T 9a91ddcc618b47c9b8199450cb0b4523: removed 11 log segments from log reader
I20260812 06:18:33.929157 16335 log.cc:1079] T 9a91ddcc618b47c9b8199450cb0b4523 P 596aa374dc5f431681fdb26bd3b9b130: Deleting log segment in path: /tmp/dist-test-taskSk6K39/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515503120097-16044-0/minicluster-data/ts-0-root/wals/9a91ddcc618b47c9b8199450cb0b4523/wal-000000026 (ops 126-130)
I20260812 06:18:33.929207 16335 log.cc:1079] T 9a91ddcc618b47c9b8199450cb0b4523 P 596aa374dc5f431681fdb26bd3b9b130: Deleting log segment in path: /tmp/dist-test-taskSk6K39/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515503120097-16044-0/minicluster-data/ts-0-root/wals/9a91ddcc618b47c9b8199450cb0b4523/wal-000000027 (ops 131-135)
I20260812 06:18:33.929263 16335 log.cc:1079] T 9a91ddcc618b47c9b8199450cb0b4523 P 596aa374dc5f431681fdb26bd3b9b130: Deleting log segment in path: /tmp/dist-test-taskSk6K39/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515503120097-16044-0/minicluster-data/ts-0-root/wals/9a91ddcc618b47c9b8199450cb0b4523/wal-000000028 (ops 136-140)
I20260812 06:18:33.929296 16335 log.cc:1079] T 9a91ddcc618b47c9b8199450cb0b4523 P 596aa374dc5f431681fdb26bd3b9b130: Deleting log segment in path: /tmp/dist-test-taskSk6K39/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515503120097-16044-0/minicluster-data/ts-0-root/wals/9a91ddcc618b47c9b8199450cb0b4523/wal-000000029 (ops 141-144)
I20260812 06:18:33.929322 16335 log.cc:1079] T 9a91ddcc618b47c9b8199450cb0b4523 P 596aa374dc5f431681fdb26bd3b9b130: Deleting log segment in path: /tmp/dist-test-taskSk6K39/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515503120097-16044-0/minicluster-data/ts-0-root/wals/9a91ddcc618b47c9b8199450cb0b4523/wal-000000030 (ops 145-149)
I20260812 06:18:33.929351 16335 log.cc:1079] T 9a91ddcc618b47c9b8199450cb0b4523 P 596aa374dc5f431681fdb26bd3b9b130: Deleting log segment in path: /tmp/dist-test-taskSk6K39/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515503120097-16044-0/minicluster-data/ts-0-root/wals/9a91ddcc618b47c9b8199450cb0b4523/wal-000000031 (ops 150-154)
I20260812 06:18:33.929381 16335 log.cc:1079] T 9a91ddcc618b47c9b8199450cb0b4523 P 596aa374dc5f431681fdb26bd3b9b130: Deleting log segment in path: /tmp/dist-test-taskSk6K39/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515503120097-16044-0/minicluster-data/ts-0-root/wals/9a91ddcc618b47c9b8199450cb0b4523/wal-000000032 (ops 155-159)
I20260812 06:18:33.929410 16335 log.cc:1079] T 9a91ddcc618b47c9b8199450cb0b4523 P 596aa374dc5f431681fdb26bd3b9b130: Deleting log segment in path: /tmp/dist-test-taskSk6K39/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515503120097-16044-0/minicluster-data/ts-0-root/wals/9a91ddcc618b47c9b8199450cb0b4523/wal-000000033 (ops 160-164)
I20260812 06:18:33.929440 16335 log.cc:1079] T 9a91ddcc618b47c9b8199450cb0b4523 P 596aa374dc5f431681fdb26bd3b9b130: Deleting log segment in path: /tmp/dist-test-taskSk6K39/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515503120097-16044-0/minicluster-data/ts-0-root/wals/9a91ddcc618b47c9b8199450cb0b4523/wal-000000034 (ops 165-169)
I20260812 06:18:33.929469 16335 log.cc:1079] T 9a91ddcc618b47c9b8199450cb0b4523 P 596aa374dc5f431681fdb26bd3b9b130: Deleting log segment in path: /tmp/dist-test-taskSk6K39/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515503120097-16044-0/minicluster-data/ts-0-root/wals/9a91ddcc618b47c9b8199450cb0b4523/wal-000000035 (ops 170-174)
I20260812 06:18:33.929514 16335 log.cc:1079] T 9a91ddcc618b47c9b8199450cb0b4523 P 596aa374dc5f431681fdb26bd3b9b130: Deleting log segment in path: /tmp/dist-test-taskSk6K39/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515503120097-16044-0/minicluster-data/ts-0-root/wals/9a91ddcc618b47c9b8199450cb0b4523/wal-000000036 (ops 175-179)
I20260812 06:18:33.950853 16335 maintenance_manager.cc:643] P 596aa374dc5f431681fdb26bd3b9b130: LogGCOp(9a91ddcc618b47c9b8199450cb0b4523) complete. Timing: real 0.022s	user 0.001s	sys 0.018s Metrics: {}
I20260812 06:18:33.951277 16395 maintenance_manager.cc:419] P 596aa374dc5f431681fdb26bd3b9b130: Scheduling FlushDeltaMemStoresOp(9a91ddcc618b47c9b8199450cb0b4523): perf score=6.157687
I20260812 06:18:33.978480 16335 maintenance_manager.cc:643] P 596aa374dc5f431681fdb26bd3b9b130: FlushDeltaMemStoresOp(9a91ddcc618b47c9b8199450cb0b4523) complete. Timing: real 0.027s	user 0.019s	sys 0.000s Metrics: {"bytes_written":8205078,"delete_count":0,"lbm_write_time_us":8843,"lbm_writes_lt_1ms":203,"reinsert_count":0,"update_count":1000}
I20260812 06:18:33.979066 16395 maintenance_manager.cc:419] P 596aa374dc5f431681fdb26bd3b9b130: Scheduling UndoDeltaBlockGCOp(9a91ddcc618b47c9b8199450cb0b4523): 447 bytes on disk
I20260812 06:18:33.979661 16335 maintenance_manager.cc:643] P 596aa374dc5f431681fdb26bd3b9b130: UndoDeltaBlockGCOp(9a91ddcc618b47c9b8199450cb0b4523) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":80,"lbm_reads_lt_1ms":4}
I20260812 06:18:33.980374 16395 maintenance_manager.cc:419] P 596aa374dc5f431681fdb26bd3b9b130: Scheduling FlushDeltaMemStoresOp(9a91ddcc618b47c9b8199450cb0b4523): perf score=2.188937
I20260812 06:18:33.994937 16335 maintenance_manager.cc:643] P 596aa374dc5f431681fdb26bd3b9b130: FlushDeltaMemStoresOp(9a91ddcc618b47c9b8199450cb0b4523) complete. Timing: real 0.014s	user 0.012s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5237,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:33.995647 16395 maintenance_manager.cc:419] P 596aa374dc5f431681fdb26bd3b9b130: Scheduling MajorDeltaCompactionOp(9a91ddcc618b47c9b8199450cb0b4523): perf score=1.000000
I20260812 06:18:34.187294 16335 maintenance_manager.cc:643] P 596aa374dc5f431681fdb26bd3b9b130: MajorDeltaCompactionOp(9a91ddcc618b47c9b8199450cb0b4523) complete. Timing: real 0.191s	user 0.152s	sys 0.029s Metrics: {"cfile_cache_miss":633,"cfile_cache_miss_bytes":28877222,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":735,"lbm_read_time_us":13425,"lbm_reads_lt_1ms":673,"lbm_write_time_us":35294,"lbm_writes_lt_1ms":643,"mutex_wait_us":241,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":3968,"thread_start_us":67,"threads_started":1,"update_count":3000}
I20260812 06:18:34.188108 16395 maintenance_manager.cc:419] P 596aa374dc5f431681fdb26bd3b9b130: Scheduling FlushDeltaMemStoresOp(9a91ddcc618b47c9b8199450cb0b4523): perf score=14.095187
I20260812 06:18:34.240393 16335 maintenance_manager.cc:643] P 596aa374dc5f431681fdb26bd3b9b130: FlushDeltaMemStoresOp(9a91ddcc618b47c9b8199450cb0b4523) complete. Timing: real 0.052s	user 0.033s	sys 0.007s Metrics: {"bytes_written":16409903,"delete_count":0,"lbm_write_time_us":17237,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:18:34.240813 16395 maintenance_manager.cc:419] P 596aa374dc5f431681fdb26bd3b9b130: Scheduling FlushDeltaMemStoresOp(9a91ddcc618b47c9b8199450cb0b4523): perf score=2.188937
I20260812 06:18:34.251194 16335 maintenance_manager.cc:643] P 596aa374dc5f431681fdb26bd3b9b130: FlushDeltaMemStoresOp(9a91ddcc618b47c9b8199450cb0b4523) complete. Timing: real 0.010s	user 0.004s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3872,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:34.251646 16395 maintenance_manager.cc:419] P 596aa374dc5f431681fdb26bd3b9b130: Scheduling MajorDeltaCompactionOp(9a91ddcc618b47c9b8199450cb0b4523): perf score=1.000000
I20260812 06:18:34.391724 16044 heavy-update-compaction-itest.cc:229] Time spent updating: real 5.215s	user 1.813s	sys 0.219s
I20260812 06:18:34.417951 16335 maintenance_manager.cc:643] P 596aa374dc5f431681fdb26bd3b9b130: MajorDeltaCompactionOp(9a91ddcc618b47c9b8199450cb0b4523) complete. Timing: real 0.166s	user 0.118s	sys 0.043s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774690,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"lbm_read_time_us":12851,"lbm_reads_1-10_ms":1,"lbm_reads_lt_1ms":567,"lbm_write_time_us":32708,"lbm_writes_lt_1ms":543,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":896,"update_count":2500}
I20260812 06:18:34.418486 16395 maintenance_manager.cc:419] P 596aa374dc5f431681fdb26bd3b9b130: Scheduling FlushDeltaMemStoresOp(9a91ddcc618b47c9b8199450cb0b4523): perf score=10.126437
I20260812 06:18:34.460703 16335 maintenance_manager.cc:643] P 596aa374dc5f431681fdb26bd3b9b130: FlushDeltaMemStoresOp(9a91ddcc618b47c9b8199450cb0b4523) complete. Timing: real 0.042s	user 0.027s	sys 0.014s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":19264,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:18:34.461326 16395 maintenance_manager.cc:419] P 596aa374dc5f431681fdb26bd3b9b130: Scheduling MajorDeltaCompactionOp(9a91ddcc618b47c9b8199450cb0b4523): perf score=1.000000
I20260812 06:18:34.504588 16044 heavy-update-compaction-itest.cc:265] Time spent scanning: real 0.113s	user 0.003s	sys 0.000s
I20260812 06:18:34.505206 16044 tablet_server.cc:179] TabletServer@127.15.171.1:0 shutting down...
I20260812 06:18:34.581732 16335 maintenance_manager.cc:643] P 596aa374dc5f431681fdb26bd3b9b130: MajorDeltaCompactionOp(9a91ddcc618b47c9b8199450cb0b4523) complete. Timing: real 0.120s	user 0.086s	sys 0.034s Metrics: {"cfile_cache_miss":331,"cfile_cache_miss_bytes":16569746,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":1,"delta_iterators_relevant":1,"dirs.queue_time_us":309,"lbm_read_time_us":11098,"lbm_reads_lt_1ms":367,"lbm_write_time_us":22692,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":342,"mutex_wait_us":66,"peak_mem_usage":38262756,"reinsert_count":0,"spinlock_wait_cycles":16640,"update_count":1500}
I20260812 06:18:34.582566 16044 ts_tablet_manager.cc:1507] Shutting down tablet manager...
I20260812 06:18:34.582947 16044 tablet_replica.cc:333] T 9a91ddcc618b47c9b8199450cb0b4523 P 596aa374dc5f431681fdb26bd3b9b130: stopping tablet replica
I20260812 06:18:34.583083 16044 raft_consensus.cc:2243] T 9a91ddcc618b47c9b8199450cb0b4523 P 596aa374dc5f431681fdb26bd3b9b130 [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:18:34.583252 16044 raft_consensus.cc:2272] T 9a91ddcc618b47c9b8199450cb0b4523 P 596aa374dc5f431681fdb26bd3b9b130 [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:18:34.598209 16044 tablet_server.cc:196] TabletServer@127.15.171.1:0 shutdown complete.
I20260812 06:18:34.613845 16044 master.cc:562] Master@127.15.171.62:35923 shutting down...
I20260812 06:18:34.616966 16044 raft_consensus.cc:2243] T 00000000000000000000000000000000 P c4378bd186a74d11ae635155ab5514dd [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:18:34.617139 16044 raft_consensus.cc:2272] T 00000000000000000000000000000000 P c4378bd186a74d11ae635155ab5514dd [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:18:34.617202 16044 tablet_replica.cc:333] T 00000000000000000000000000000000 P c4378bd186a74d11ae635155ab5514dd: stopping tablet replica
I20260812 06:18:34.629498 16044 master.cc:584] Master@127.15.171.62:35923 shutdown complete.
[       OK ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/1 (5785 ms)
[----------] 2 tests from EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy (11578 ms total)

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