[==========] 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:38.296129 27409 internal_mini_cluster.cc:156] Creating distributed mini masters. Addrs: 127.26.196.126:40121
I20260812 06:18:38.297210 27409 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:38.297849 27409 file_cache.cc:504] Constructed file cache file cache with capacity 419430
I20260812 06:18:38.304899 27409 server_base.cc:1061] running on GCE node
W20260812 06:18:38.304975 27415 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:38.304937 27419 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:38.305208 27416 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:38.305745 27409 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:18:38.305877 27409 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:38.305929 27409 hybrid_clock.cc:648] HybridClock initialized: now 1786515518305926 us; error 0 us; skew 500 ppm
I20260812 06:18:38.307994 27409 webserver.cc:533] Webserver started at http://127.26.196.126:37965/ using document root <none> and password file <none>
I20260812 06:18:38.308640 27409 fs_manager.cc:362] Metadata directory not provided
I20260812 06:18:38.308712 27409 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:18:38.308992 27409 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:18:38.310843 27409 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-task_caSEa/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515518284916-27409-0/minicluster-data/master-0-root/instance:
uuid: "a51cb34289ab49ceae3c6273e67f755e"
format_stamp: "Formatted at 2026-08-12 06:18:38 on dist-test-slave-mvvj"
I20260812 06:18:38.314710 27409 fs_manager.cc:696] Time spent creating directory manager: real 0.003s	user 0.003s	sys 0.003s
I20260812 06:18:38.317088 27424 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:38.318169 27409 fs_manager.cc:730] Time spent opening block manager: real 0.002s	user 0.001s	sys 0.000s
I20260812 06:18:38.318349 27409 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-task_caSEa/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515518284916-27409-0/minicluster-data/master-0-root
uuid: "a51cb34289ab49ceae3c6273e67f755e"
format_stamp: "Formatted at 2026-08-12 06:18:38 on dist-test-slave-mvvj"
I20260812 06:18:38.318513 27409 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-task_caSEa/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515518284916-27409-0/minicluster-data/master-0-root
metadata directory: /tmp/dist-test-task_caSEa/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515518284916-27409-0/minicluster-data/master-0-root
1 data directories: /tmp/dist-test-task_caSEa/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515518284916-27409-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:38.334367 27409 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:18:38.335117 27409 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:38.335317 27409 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:18:38.343353 27409 rpc_server.cc:307] RPC server started. Bound to: 127.26.196.126:40121
I20260812 06:18:38.343406 27485 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.26.196.126:40121 every 8 connection(s)
I20260812 06:18:38.345834 27486 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:38.351270 27486 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P a51cb34289ab49ceae3c6273e67f755e: Bootstrap starting.
I20260812 06:18:38.353746 27486 tablet_bootstrap.cc:654] T 00000000000000000000000000000000 P a51cb34289ab49ceae3c6273e67f755e: Neither blocks nor log segments found. Creating new log.
I20260812 06:18:38.354730 27486 log.cc:826] T 00000000000000000000000000000000 P a51cb34289ab49ceae3c6273e67f755e: Log is configured to *not* fsync() on all Append() calls
I20260812 06:18:38.356535 27486 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P a51cb34289ab49ceae3c6273e67f755e: No bootstrap required, opened a new log
I20260812 06:18:38.359421 27486 raft_consensus.cc:359] T 00000000000000000000000000000000 P a51cb34289ab49ceae3c6273e67f755e [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "a51cb34289ab49ceae3c6273e67f755e" member_type: VOTER }
I20260812 06:18:38.359601 27486 raft_consensus.cc:385] T 00000000000000000000000000000000 P a51cb34289ab49ceae3c6273e67f755e [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:18:38.359715 27486 raft_consensus.cc:740] T 00000000000000000000000000000000 P a51cb34289ab49ceae3c6273e67f755e [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: a51cb34289ab49ceae3c6273e67f755e, State: Initialized, Role: FOLLOWER
I20260812 06:18:38.360448 27486 consensus_queue.cc:260] T 00000000000000000000000000000000 P a51cb34289ab49ceae3c6273e67f755e [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: "a51cb34289ab49ceae3c6273e67f755e" member_type: VOTER }
I20260812 06:18:38.360599 27486 raft_consensus.cc:399] T 00000000000000000000000000000000 P a51cb34289ab49ceae3c6273e67f755e [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:18:38.360697 27486 raft_consensus.cc:493] T 00000000000000000000000000000000 P a51cb34289ab49ceae3c6273e67f755e [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:18:38.360853 27486 raft_consensus.cc:3060] T 00000000000000000000000000000000 P a51cb34289ab49ceae3c6273e67f755e [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:18:38.361670 27486 raft_consensus.cc:515] T 00000000000000000000000000000000 P a51cb34289ab49ceae3c6273e67f755e [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "a51cb34289ab49ceae3c6273e67f755e" member_type: VOTER }
I20260812 06:18:38.362143 27486 leader_election.cc:304] T 00000000000000000000000000000000 P a51cb34289ab49ceae3c6273e67f755e [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: a51cb34289ab49ceae3c6273e67f755e; no voters: 
I20260812 06:18:38.362480 27486 leader_election.cc:290] T 00000000000000000000000000000000 P a51cb34289ab49ceae3c6273e67f755e [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:18:38.362643 27490 raft_consensus.cc:2804] T 00000000000000000000000000000000 P a51cb34289ab49ceae3c6273e67f755e [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:18:38.362926 27490 raft_consensus.cc:697] T 00000000000000000000000000000000 P a51cb34289ab49ceae3c6273e67f755e [term 1 LEADER]: Becoming Leader. State: Replica: a51cb34289ab49ceae3c6273e67f755e, State: Running, Role: LEADER
I20260812 06:18:38.363304 27490 consensus_queue.cc:237] T 00000000000000000000000000000000 P a51cb34289ab49ceae3c6273e67f755e [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: "a51cb34289ab49ceae3c6273e67f755e" member_type: VOTER }
I20260812 06:18:38.363551 27486 sys_catalog.cc:565] T 00000000000000000000000000000000 P a51cb34289ab49ceae3c6273e67f755e [sys.catalog]: configured and running, proceeding with master startup.
I20260812 06:18:38.365281 27492 sys_catalog.cc:455] T 00000000000000000000000000000000 P a51cb34289ab49ceae3c6273e67f755e [sys.catalog]: SysCatalogTable state changed. Reason: New leader a51cb34289ab49ceae3c6273e67f755e. Latest consensus state: current_term: 1 leader_uuid: "a51cb34289ab49ceae3c6273e67f755e" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "a51cb34289ab49ceae3c6273e67f755e" member_type: VOTER } }
I20260812 06:18:38.365435 27492 sys_catalog.cc:458] T 00000000000000000000000000000000 P a51cb34289ab49ceae3c6273e67f755e [sys.catalog]: This master's current role is: LEADER
I20260812 06:18:38.365295 27491 sys_catalog.cc:455] T 00000000000000000000000000000000 P a51cb34289ab49ceae3c6273e67f755e [sys.catalog]: SysCatalogTable state changed. Reason: RaftConsensus started. Latest consensus state: current_term: 1 leader_uuid: "a51cb34289ab49ceae3c6273e67f755e" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "a51cb34289ab49ceae3c6273e67f755e" member_type: VOTER } }
I20260812 06:18:38.365494 27491 sys_catalog.cc:458] T 00000000000000000000000000000000 P a51cb34289ab49ceae3c6273e67f755e [sys.catalog]: This master's current role is: LEADER
I20260812 06:18:38.366118 27502 catalog_manager.cc:1511] Loading table and tablet metadata into memory...
I20260812 06:18:38.366238 27409 internal_mini_cluster.cc:184] Waiting to initialize catalog manager on master 0
I20260812 06:18:38.368443 27502 catalog_manager.cc:1520] Initializing Kudu cluster ID...
I20260812 06:18:38.373073 27502 catalog_manager.cc:1383] Generated new cluster ID: c95e12e1ebae42f2acf3765b52a862d7
I20260812 06:18:38.373152 27502 catalog_manager.cc:1531] Initializing Kudu internal certificate authority...
I20260812 06:18:38.381085 27502 catalog_manager.cc:1406] Generated new certificate authority record
I20260812 06:18:38.381991 27502 catalog_manager.cc:1540] Loading token signing keys...
I20260812 06:18:38.398236 27502 catalog_manager.cc:6092] T 00000000000000000000000000000000 P a51cb34289ab49ceae3c6273e67f755e: Generated new TSK 0
I20260812 06:18:38.399073 27502 catalog_manager.cc:1550] Initializing in-progress tserver states...
I20260812 06:18:38.431200 27409 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:18:38.434533 27511 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:38.434592 27409 server_base.cc:1061] running on GCE node
W20260812 06:18:38.434669 27514 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:38.434562 27512 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:38.435137 27409 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:18:38.435204 27409 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:38.435231 27409 hybrid_clock.cc:648] HybridClock initialized: now 1786515518435231 us; error 0 us; skew 500 ppm
I20260812 06:18:38.436265 27409 webserver.cc:533] Webserver started at http://127.26.196.65:42013/ using document root <none> and password file <none>
I20260812 06:18:38.436456 27409 fs_manager.cc:362] Metadata directory not provided
I20260812 06:18:38.436539 27409 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:18:38.436625 27409 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:18:38.437038 27409 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-task_caSEa/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515518284916-27409-0/minicluster-data/ts-0-root/instance:
uuid: "9dd97c82fea44b7fb5534e173cfac07a"
format_stamp: "Formatted at 2026-08-12 06:18:38 on dist-test-slave-mvvj"
I20260812 06:18:38.438652 27409 fs_manager.cc:696] Time spent creating directory manager: real 0.001s	user 0.000s	sys 0.002s
I20260812 06:18:38.439695 27520 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:38.440011 27409 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.000s	sys 0.000s
I20260812 06:18:38.440102 27409 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-task_caSEa/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515518284916-27409-0/minicluster-data/ts-0-root
uuid: "9dd97c82fea44b7fb5534e173cfac07a"
format_stamp: "Formatted at 2026-08-12 06:18:38 on dist-test-slave-mvvj"
I20260812 06:18:38.440194 27409 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-task_caSEa/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515518284916-27409-0/minicluster-data/ts-0-root
metadata directory: /tmp/dist-test-task_caSEa/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515518284916-27409-0/minicluster-data/ts-0-root
1 data directories: /tmp/dist-test-task_caSEa/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515518284916-27409-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:38.452054 27409 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:18:38.452538 27409 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:18:38.453059 27409 txn_system_client.cc:432] TxnSystemClient initialization is disabled...
I20260812 06:18:38.453912 27409 ts_tablet_manager.cc:585] Loaded tablet metadata (0 total tablets, 0 live tablets)
I20260812 06:18:38.453984 27409 ts_tablet_manager.cc:531] Time spent load tablet metadata: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:18:38.454062 27409 ts_tablet_manager.cc:616] Registered 0 tablets
I20260812 06:18:38.454105 27409 ts_tablet_manager.cc:595] Time spent register tablets: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:18:38.461179 27409 rpc_server.cc:307] RPC server started. Bound to: 127.26.196.65:43861
I20260812 06:18:38.461200 27593 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.26.196.65:43861 every 8 connection(s)
I20260812 06:18:38.473917 27594 heartbeater.cc:344] Connected to a master server at 127.26.196.126:40121
I20260812 06:18:38.474272 27594 heartbeater.cc:461] Registering TS with master...
I20260812 06:18:38.474958 27594 heartbeater.cc:507] Master 127.26.196.126:40121 requested a full tablet report, sending...
I20260812 06:18:38.476547 27446 ts_manager.cc:194] Registered new tserver with Master: 9dd97c82fea44b7fb5534e173cfac07a (127.26.196.65:43861)
I20260812 06:18:38.476639 27409 internal_mini_cluster.cc:371] 1 TS(s) registered with all masters after 0.014779023s
I20260812 06:18:38.478035 27446 master_service.cc:502] Signed X509 certificate for tserver {username='slave'} at 127.0.0.1:49644
I20260812 06:18:38.487106 27446 catalog_manager.cc:2283] Servicing CreateTable request from {username='slave'} at 127.0.0.1:49652:
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:38.502642 27551 tablet_service.cc:1511] Processing CreateTablet for tablet ef96416aef5a4681af58cde2a026d69c (DEFAULT_TABLE table=heavy-update-compaction-test [id=37900fad7edc413bb68cb4dc8d673d47]), partition=
I20260812 06:18:38.503134 27551 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet ef96416aef5a4681af58cde2a026d69c. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:18:38.506258 27612 tablet_bootstrap.cc:492] T ef96416aef5a4681af58cde2a026d69c P 9dd97c82fea44b7fb5534e173cfac07a: Bootstrap starting.
I20260812 06:18:38.507392 27612 tablet_bootstrap.cc:654] T ef96416aef5a4681af58cde2a026d69c P 9dd97c82fea44b7fb5534e173cfac07a: Neither blocks nor log segments found. Creating new log.
I20260812 06:18:38.508765 27612 tablet_bootstrap.cc:492] T ef96416aef5a4681af58cde2a026d69c P 9dd97c82fea44b7fb5534e173cfac07a: No bootstrap required, opened a new log
I20260812 06:18:38.508857 27612 ts_tablet_manager.cc:1403] T ef96416aef5a4681af58cde2a026d69c P 9dd97c82fea44b7fb5534e173cfac07a: Time spent bootstrapping tablet: real 0.003s	user 0.002s	sys 0.000s
I20260812 06:18:38.509414 27612 raft_consensus.cc:359] T ef96416aef5a4681af58cde2a026d69c P 9dd97c82fea44b7fb5534e173cfac07a [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "9dd97c82fea44b7fb5534e173cfac07a" member_type: VOTER last_known_addr { host: "127.26.196.65" port: 43861 } }
I20260812 06:18:38.509562 27612 raft_consensus.cc:385] T ef96416aef5a4681af58cde2a026d69c P 9dd97c82fea44b7fb5534e173cfac07a [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:18:38.509644 27612 raft_consensus.cc:740] T ef96416aef5a4681af58cde2a026d69c P 9dd97c82fea44b7fb5534e173cfac07a [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: 9dd97c82fea44b7fb5534e173cfac07a, State: Initialized, Role: FOLLOWER
I20260812 06:18:38.509835 27612 consensus_queue.cc:260] T ef96416aef5a4681af58cde2a026d69c P 9dd97c82fea44b7fb5534e173cfac07a [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: "9dd97c82fea44b7fb5534e173cfac07a" member_type: VOTER last_known_addr { host: "127.26.196.65" port: 43861 } }
I20260812 06:18:38.509974 27612 raft_consensus.cc:399] T ef96416aef5a4681af58cde2a026d69c P 9dd97c82fea44b7fb5534e173cfac07a [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:18:38.510077 27612 raft_consensus.cc:493] T ef96416aef5a4681af58cde2a026d69c P 9dd97c82fea44b7fb5534e173cfac07a [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:18:38.510144 27612 raft_consensus.cc:3060] T ef96416aef5a4681af58cde2a026d69c P 9dd97c82fea44b7fb5534e173cfac07a [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:18:38.510929 27612 raft_consensus.cc:515] T ef96416aef5a4681af58cde2a026d69c P 9dd97c82fea44b7fb5534e173cfac07a [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "9dd97c82fea44b7fb5534e173cfac07a" member_type: VOTER last_known_addr { host: "127.26.196.65" port: 43861 } }
I20260812 06:18:38.511049 27612 leader_election.cc:304] T ef96416aef5a4681af58cde2a026d69c P 9dd97c82fea44b7fb5534e173cfac07a [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: 9dd97c82fea44b7fb5534e173cfac07a; no voters: 
I20260812 06:18:38.511337 27612 leader_election.cc:290] T ef96416aef5a4681af58cde2a026d69c P 9dd97c82fea44b7fb5534e173cfac07a [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:18:38.511436 27614 raft_consensus.cc:2804] T ef96416aef5a4681af58cde2a026d69c P 9dd97c82fea44b7fb5534e173cfac07a [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:18:38.511636 27614 raft_consensus.cc:697] T ef96416aef5a4681af58cde2a026d69c P 9dd97c82fea44b7fb5534e173cfac07a [term 1 LEADER]: Becoming Leader. State: Replica: 9dd97c82fea44b7fb5534e173cfac07a, State: Running, Role: LEADER
I20260812 06:18:38.511727 27612 ts_tablet_manager.cc:1434] T ef96416aef5a4681af58cde2a026d69c P 9dd97c82fea44b7fb5534e173cfac07a: Time spent starting tablet: real 0.003s	user 0.003s	sys 0.000s
I20260812 06:18:38.511821 27614 consensus_queue.cc:237] T ef96416aef5a4681af58cde2a026d69c P 9dd97c82fea44b7fb5534e173cfac07a [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: "9dd97c82fea44b7fb5534e173cfac07a" member_type: VOTER last_known_addr { host: "127.26.196.65" port: 43861 } }
I20260812 06:18:38.512153 27594 heartbeater.cc:499] Master 127.26.196.126:40121 was elected leader, sending a full tablet report...
I20260812 06:18:38.515038 27446 catalog_manager.cc:5719] T ef96416aef5a4681af58cde2a026d69c P 9dd97c82fea44b7fb5534e173cfac07a reported cstate change: term changed from 0 to 1, leader changed from <none> to 9dd97c82fea44b7fb5534e173cfac07a (127.26.196.65). New cstate: current_term: 1 leader_uuid: "9dd97c82fea44b7fb5534e173cfac07a" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "9dd97c82fea44b7fb5534e173cfac07a" member_type: VOTER last_known_addr { host: "127.26.196.65" port: 43861 } health_report { overall_health: HEALTHY } } }
I20260812 06:18:38.580626 27409 heavy-update-compaction-itest.cc:215] Time spent inserting: real 0.058s	user 0.019s	sys 0.008s
I20260812 06:18:38.712608 27596 maintenance_manager.cc:419] P 9dd97c82fea44b7fb5534e173cfac07a: Scheduling FlushMRSOp(ef96416aef5a4681af58cde2a026d69c): perf score=15.086190
I20260812 06:18:38.868969 27526 maintenance_manager.cc:643] P 9dd97c82fea44b7fb5534e173cfac07a: FlushMRSOp(ef96416aef5a4681af58cde2a026d69c) complete. Timing: real 0.156s	user 0.109s	sys 0.043s Metrics: {"bytes_written":8615323,"cfile_init":1,"compiler_manager_pool.queue_time_us":560,"delete_count":0,"dirs.queue_time_us":58,"dirs.run_cpu_time_us":221,"dirs.run_wall_time_us":927,"drs_written":1,"lbm_read_time_us":84,"lbm_reads_lt_1ms":4,"lbm_write_time_us":38203,"lbm_writes_lt_1ms":667,"peak_mem_usage":0,"reinsert_count":0,"rows_written":104,"spinlock_wait_cycles":178176,"thread_start_us":161,"threads_started":1,"update_count":1050}
I20260812 06:18:38.870086 27596 maintenance_manager.cc:419] P 9dd97c82fea44b7fb5534e173cfac07a: Scheduling LogGCOp(ef96416aef5a4681af58cde2a026d69c): free 20743880 bytes of WAL
I20260812 06:18:38.870410 27526 log_reader.cc:385] T ef96416aef5a4681af58cde2a026d69c: removed 2 log segments from log reader
I20260812 06:18:38.870492 27526 log.cc:1079] T ef96416aef5a4681af58cde2a026d69c P 9dd97c82fea44b7fb5534e173cfac07a: Deleting log segment in path: /tmp/dist-test-task_caSEa/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515518284916-27409-0/minicluster-data/ts-0-root/wals/ef96416aef5a4681af58cde2a026d69c/wal-000000001 (ops 1-6)
I20260812 06:18:38.870638 27526 log.cc:1079] T ef96416aef5a4681af58cde2a026d69c P 9dd97c82fea44b7fb5534e173cfac07a: Deleting log segment in path: /tmp/dist-test-task_caSEa/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515518284916-27409-0/minicluster-data/ts-0-root/wals/ef96416aef5a4681af58cde2a026d69c/wal-000000002 (ops 7-11)
I20260812 06:18:38.874855 27526 maintenance_manager.cc:643] P 9dd97c82fea44b7fb5534e173cfac07a: LogGCOp(ef96416aef5a4681af58cde2a026d69c) complete. Timing: real 0.005s	user 0.000s	sys 0.002s Metrics: {}
I20260812 06:18:38.875453 27596 maintenance_manager.cc:419] P 9dd97c82fea44b7fb5534e173cfac07a: Scheduling FlushDeltaMemStoresOp(ef96416aef5a4681af58cde2a026d69c): perf score=2.188937
I20260812 06:18:38.893246 27526 maintenance_manager.cc:643] P 9dd97c82fea44b7fb5534e173cfac07a: FlushDeltaMemStoresOp(ef96416aef5a4681af58cde2a026d69c) complete. Timing: real 0.018s	user 0.014s	sys 0.000s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":5712,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:18:38.893810 27596 maintenance_manager.cc:419] P 9dd97c82fea44b7fb5534e173cfac07a: Scheduling MajorDeltaCompactionOp(ef96416aef5a4681af58cde2a026d69c): perf score=1.000000
I20260812 06:18:39.007012 27526 maintenance_manager.cc:643] P 9dd97c82fea44b7fb5534e173cfac07a: MajorDeltaCompactionOp(ef96416aef5a4681af58cde2a026d69c) complete. Timing: real 0.113s	user 0.084s	sys 0.022s Metrics: {"cfile_cache_miss":332,"cfile_cache_miss_bytes":16569856,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":848,"lbm_read_time_us":5862,"lbm_reads_lt_1ms":364,"lbm_write_time_us":19095,"lbm_writes_lt_1ms":343,"peak_mem_usage":38262756,"reinsert_count":0,"thread_start_us":389,"threads_started":5,"update_count":1500}
I20260812 06:18:39.007696 27596 maintenance_manager.cc:419] P 9dd97c82fea44b7fb5534e173cfac07a: Scheduling FlushDeltaMemStoresOp(ef96416aef5a4681af58cde2a026d69c): perf score=10.126437
I20260812 06:18:39.050318 27526 maintenance_manager.cc:643] P 9dd97c82fea44b7fb5534e173cfac07a: FlushDeltaMemStoresOp(ef96416aef5a4681af58cde2a026d69c) complete. Timing: real 0.042s	user 0.019s	sys 0.016s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":20353,"lbm_writes_1-10_ms":3,"lbm_writes_lt_1ms":300,"reinsert_count":0,"update_count":1500}
I20260812 06:18:39.050763 27596 maintenance_manager.cc:419] P 9dd97c82fea44b7fb5534e173cfac07a: Scheduling FlushDeltaMemStoresOp(ef96416aef5a4681af58cde2a026d69c): perf score=2.188937
I20260812 06:18:39.061810 27526 maintenance_manager.cc:643] P 9dd97c82fea44b7fb5534e173cfac07a: FlushDeltaMemStoresOp(ef96416aef5a4681af58cde2a026d69c) complete. Timing: real 0.011s	user 0.005s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4022,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:39.062441 27596 maintenance_manager.cc:419] P 9dd97c82fea44b7fb5534e173cfac07a: Scheduling UndoDeltaBlockGCOp(ef96416aef5a4681af58cde2a026d69c): 16411394 bytes on disk
I20260812 06:18:39.063153 27526 maintenance_manager.cc:643] P 9dd97c82fea44b7fb5534e173cfac07a: UndoDeltaBlockGCOp(ef96416aef5a4681af58cde2a026d69c) complete. Timing: real 0.001s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":127,"lbm_reads_lt_1ms":4}
I20260812 06:18:39.063719 27596 maintenance_manager.cc:419] P 9dd97c82fea44b7fb5534e173cfac07a: Scheduling MajorDeltaCompactionOp(ef96416aef5a4681af58cde2a026d69c): perf score=1.000000
I20260812 06:18:39.182627 27526 maintenance_manager.cc:643] P 9dd97c82fea44b7fb5534e173cfac07a: MajorDeltaCompactionOp(ef96416aef5a4681af58cde2a026d69c) complete. Timing: real 0.119s	user 0.099s	sys 0.018s 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":394,"lbm_read_time_us":8244,"lbm_reads_lt_1ms":472,"lbm_write_time_us":22583,"lbm_writes_lt_1ms":443,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":768,"update_count":2000}
I20260812 06:18:39.183226 27596 maintenance_manager.cc:419] P 9dd97c82fea44b7fb5534e173cfac07a: Scheduling FlushDeltaMemStoresOp(ef96416aef5a4681af58cde2a026d69c): perf score=10.126437
I20260812 06:18:39.240581 27526 maintenance_manager.cc:643] P 9dd97c82fea44b7fb5534e173cfac07a: FlushDeltaMemStoresOp(ef96416aef5a4681af58cde2a026d69c) complete. Timing: real 0.057s	user 0.020s	sys 0.026s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":17799,"lbm_writes_lt_1ms":303,"mutex_wait_us":2,"reinsert_count":0,"update_count":1500}
I20260812 06:18:39.241211 27596 maintenance_manager.cc:419] P 9dd97c82fea44b7fb5534e173cfac07a: Scheduling FlushDeltaMemStoresOp(ef96416aef5a4681af58cde2a026d69c): perf score=2.188937
I20260812 06:18:39.252208 27526 maintenance_manager.cc:643] P 9dd97c82fea44b7fb5534e173cfac07a: FlushDeltaMemStoresOp(ef96416aef5a4681af58cde2a026d69c) complete. Timing: real 0.011s	user 0.006s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4288,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:39.252683 27596 maintenance_manager.cc:419] P 9dd97c82fea44b7fb5534e173cfac07a: Scheduling MajorDeltaCompactionOp(ef96416aef5a4681af58cde2a026d69c): perf score=1.000000
I20260812 06:18:39.399715 27526 maintenance_manager.cc:643] P 9dd97c82fea44b7fb5534e173cfac07a: MajorDeltaCompactionOp(ef96416aef5a4681af58cde2a026d69c) complete. Timing: real 0.147s	user 0.086s	sys 0.056s 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":1425,"lbm_read_time_us":11216,"lbm_reads_lt_1ms":472,"lbm_write_time_us":23495,"lbm_writes_lt_1ms":443,"mutex_wait_us":448,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":12288,"update_count":2000}
I20260812 06:18:39.400358 27596 maintenance_manager.cc:419] P 9dd97c82fea44b7fb5534e173cfac07a: Scheduling FlushDeltaMemStoresOp(ef96416aef5a4681af58cde2a026d69c): perf score=10.126437
I20260812 06:18:39.437264 27526 maintenance_manager.cc:643] P 9dd97c82fea44b7fb5534e173cfac07a: FlushDeltaMemStoresOp(ef96416aef5a4681af58cde2a026d69c) complete. Timing: real 0.037s	user 0.025s	sys 0.007s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":13665,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:18:39.437804 27596 maintenance_manager.cc:419] P 9dd97c82fea44b7fb5534e173cfac07a: Scheduling MajorDeltaCompactionOp(ef96416aef5a4681af58cde2a026d69c): perf score=1.000000
I20260812 06:18:39.545819 27526 maintenance_manager.cc:643] P 9dd97c82fea44b7fb5534e173cfac07a: MajorDeltaCompactionOp(ef96416aef5a4681af58cde2a026d69c) complete. Timing: real 0.108s	user 0.075s	sys 0.032s Metrics: {"cfile_cache_miss":331,"cfile_cache_miss_bytes":16569746,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":1,"delta_iterators_relevant":1,"dirs.queue_time_us":277,"lbm_read_time_us":5796,"lbm_reads_lt_1ms":363,"lbm_write_time_us":21016,"lbm_writes_lt_1ms":343,"peak_mem_usage":38262756,"reinsert_count":0,"spinlock_wait_cycles":4736,"update_count":1500}
I20260812 06:18:39.546693 27596 maintenance_manager.cc:419] P 9dd97c82fea44b7fb5534e173cfac07a: Scheduling FlushDeltaMemStoresOp(ef96416aef5a4681af58cde2a026d69c): perf score=10.126437
I20260812 06:18:39.591626 27526 maintenance_manager.cc:643] P 9dd97c82fea44b7fb5534e173cfac07a: FlushDeltaMemStoresOp(ef96416aef5a4681af58cde2a026d69c) complete. Timing: real 0.045s	user 0.026s	sys 0.007s Metrics: {"bytes_written":12307491,"delete_count":0,"lbm_write_time_us":15620,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:18:39.592135 27596 maintenance_manager.cc:419] P 9dd97c82fea44b7fb5534e173cfac07a: Scheduling FlushDeltaMemStoresOp(ef96416aef5a4681af58cde2a026d69c): perf score=2.188937
I20260812 06:18:39.603324 27526 maintenance_manager.cc:643] P 9dd97c82fea44b7fb5534e173cfac07a: FlushDeltaMemStoresOp(ef96416aef5a4681af58cde2a026d69c) complete. Timing: real 0.011s	user 0.009s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3888,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:39.603955 27596 maintenance_manager.cc:419] P 9dd97c82fea44b7fb5534e173cfac07a: Scheduling MajorDeltaCompactionOp(ef96416aef5a4681af58cde2a026d69c): perf score=1.000000
I20260812 06:18:39.732260 27526 maintenance_manager.cc:643] P 9dd97c82fea44b7fb5534e173cfac07a: MajorDeltaCompactionOp(ef96416aef5a4681af58cde2a026d69c) complete. Timing: real 0.128s	user 0.105s	sys 0.023s 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":721,"lbm_read_time_us":8902,"lbm_reads_lt_1ms":472,"lbm_write_time_us":26016,"lbm_writes_lt_1ms":443,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":5376,"update_count":2000}
I20260812 06:18:39.732810 27596 maintenance_manager.cc:419] P 9dd97c82fea44b7fb5534e173cfac07a: Scheduling FlushDeltaMemStoresOp(ef96416aef5a4681af58cde2a026d69c): perf score=10.126437
I20260812 06:18:39.780474 27526 maintenance_manager.cc:643] P 9dd97c82fea44b7fb5534e173cfac07a: FlushDeltaMemStoresOp(ef96416aef5a4681af58cde2a026d69c) complete. Timing: real 0.047s	user 0.023s	sys 0.017s Metrics: {"bytes_written":12307489,"delete_count":0,"lbm_write_time_us":14517,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:18:39.781030 27596 maintenance_manager.cc:419] P 9dd97c82fea44b7fb5534e173cfac07a: Scheduling FlushDeltaMemStoresOp(ef96416aef5a4681af58cde2a026d69c): perf score=2.188937
I20260812 06:18:39.791435 27526 maintenance_manager.cc:643] P 9dd97c82fea44b7fb5534e173cfac07a: FlushDeltaMemStoresOp(ef96416aef5a4681af58cde2a026d69c) complete. Timing: real 0.010s	user 0.004s	sys 0.004s 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:39.792030 27596 maintenance_manager.cc:419] P 9dd97c82fea44b7fb5534e173cfac07a: Scheduling MajorDeltaCompactionOp(ef96416aef5a4681af58cde2a026d69c): perf score=1.000000
I20260812 06:18:39.939198 27526 maintenance_manager.cc:643] P 9dd97c82fea44b7fb5534e173cfac07a: MajorDeltaCompactionOp(ef96416aef5a4681af58cde2a026d69c) complete. Timing: real 0.147s	user 0.110s	sys 0.037s 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":280,"lbm_read_time_us":10597,"lbm_reads_lt_1ms":472,"lbm_write_time_us":24625,"lbm_writes_lt_1ms":443,"mutex_wait_us":23,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":8960,"update_count":2000}
I20260812 06:18:39.940073 27596 maintenance_manager.cc:419] P 9dd97c82fea44b7fb5534e173cfac07a: Scheduling FlushDeltaMemStoresOp(ef96416aef5a4681af58cde2a026d69c): perf score=10.126437
I20260812 06:18:39.980989 27526 maintenance_manager.cc:643] P 9dd97c82fea44b7fb5534e173cfac07a: FlushDeltaMemStoresOp(ef96416aef5a4681af58cde2a026d69c) complete. Timing: real 0.041s	user 0.027s	sys 0.005s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":14412,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:18:39.981469 27596 maintenance_manager.cc:419] P 9dd97c82fea44b7fb5534e173cfac07a: Scheduling FlushDeltaMemStoresOp(ef96416aef5a4681af58cde2a026d69c): perf score=2.188937
I20260812 06:18:39.992730 27526 maintenance_manager.cc:643] P 9dd97c82fea44b7fb5534e173cfac07a: FlushDeltaMemStoresOp(ef96416aef5a4681af58cde2a026d69c) complete. Timing: real 0.011s	user 0.010s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4081,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:39.993287 27596 maintenance_manager.cc:419] P 9dd97c82fea44b7fb5534e173cfac07a: Scheduling MajorDeltaCompactionOp(ef96416aef5a4681af58cde2a026d69c): perf score=1.000000
I20260812 06:18:40.117992 27526 maintenance_manager.cc:643] P 9dd97c82fea44b7fb5534e173cfac07a: MajorDeltaCompactionOp(ef96416aef5a4681af58cde2a026d69c) complete. Timing: real 0.125s	user 0.088s	sys 0.036s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672277,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":662,"lbm_read_time_us":8330,"lbm_reads_lt_1ms":472,"lbm_write_time_us":24536,"lbm_writes_lt_1ms":443,"mutex_wait_us":284,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":12928,"update_count":2000}
I20260812 06:18:40.120833 27596 maintenance_manager.cc:419] P 9dd97c82fea44b7fb5534e173cfac07a: Scheduling FlushDeltaMemStoresOp(ef96416aef5a4681af58cde2a026d69c): perf score=10.126437
I20260812 06:18:40.162631 27526 maintenance_manager.cc:643] P 9dd97c82fea44b7fb5534e173cfac07a: FlushDeltaMemStoresOp(ef96416aef5a4681af58cde2a026d69c) complete. Timing: real 0.042s	user 0.026s	sys 0.008s Metrics: {"bytes_written":12307489,"delete_count":0,"lbm_write_time_us":16260,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:18:40.163139 27596 maintenance_manager.cc:419] P 9dd97c82fea44b7fb5534e173cfac07a: Scheduling FlushDeltaMemStoresOp(ef96416aef5a4681af58cde2a026d69c): perf score=2.188937
I20260812 06:18:40.175257 27526 maintenance_manager.cc:643] P 9dd97c82fea44b7fb5534e173cfac07a: FlushDeltaMemStoresOp(ef96416aef5a4681af58cde2a026d69c) complete. Timing: real 0.012s	user 0.006s	sys 0.003s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4428,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:40.175993 27596 maintenance_manager.cc:419] P 9dd97c82fea44b7fb5534e173cfac07a: Scheduling FlushMRSOp(ef96416aef5a4681af58cde2a026d69c): perf score=1.000000
I20260812 06:18:40.206877 27526 maintenance_manager.cc:643] P 9dd97c82fea44b7fb5534e173cfac07a: FlushMRSOp(ef96416aef5a4681af58cde2a026d69c) complete. Timing: real 0.031s	user 0.029s	sys 0.000s Metrics: {"bytes_written":1234473,"cfile_init":1,"dirs.queue_time_us":68,"dirs.run_cpu_time_us":286,"dirs.run_wall_time_us":1506,"drs_written":1,"lbm_read_time_us":41,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1740,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":30}
I20260812 06:18:40.207676 27596 maintenance_manager.cc:419] P 9dd97c82fea44b7fb5534e173cfac07a: Scheduling LogGCOp(ef96416aef5a4681af58cde2a026d69c): free 121006437 bytes of WAL
I20260812 06:18:40.207971 27526 log_reader.cc:385] T ef96416aef5a4681af58cde2a026d69c: removed 12 log segments from log reader
I20260812 06:18:40.208019 27526 log.cc:1079] T ef96416aef5a4681af58cde2a026d69c P 9dd97c82fea44b7fb5534e173cfac07a: Deleting log segment in path: /tmp/dist-test-task_caSEa/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515518284916-27409-0/minicluster-data/ts-0-root/wals/ef96416aef5a4681af58cde2a026d69c/wal-000000003 (ops 12-16)
I20260812 06:18:40.208050 27526 log.cc:1079] T ef96416aef5a4681af58cde2a026d69c P 9dd97c82fea44b7fb5534e173cfac07a: Deleting log segment in path: /tmp/dist-test-task_caSEa/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515518284916-27409-0/minicluster-data/ts-0-root/wals/ef96416aef5a4681af58cde2a026d69c/wal-000000004 (ops 17-21)
I20260812 06:18:40.208113 27526 log.cc:1079] T ef96416aef5a4681af58cde2a026d69c P 9dd97c82fea44b7fb5534e173cfac07a: Deleting log segment in path: /tmp/dist-test-task_caSEa/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515518284916-27409-0/minicluster-data/ts-0-root/wals/ef96416aef5a4681af58cde2a026d69c/wal-000000005 (ops 22-26)
I20260812 06:18:40.208155 27526 log.cc:1079] T ef96416aef5a4681af58cde2a026d69c P 9dd97c82fea44b7fb5534e173cfac07a: Deleting log segment in path: /tmp/dist-test-task_caSEa/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515518284916-27409-0/minicluster-data/ts-0-root/wals/ef96416aef5a4681af58cde2a026d69c/wal-000000006 (ops 27-31)
I20260812 06:18:40.208194 27526 log.cc:1079] T ef96416aef5a4681af58cde2a026d69c P 9dd97c82fea44b7fb5534e173cfac07a: Deleting log segment in path: /tmp/dist-test-task_caSEa/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515518284916-27409-0/minicluster-data/ts-0-root/wals/ef96416aef5a4681af58cde2a026d69c/wal-000000007 (ops 32-36)
I20260812 06:18:40.208240 27526 log.cc:1079] T ef96416aef5a4681af58cde2a026d69c P 9dd97c82fea44b7fb5534e173cfac07a: Deleting log segment in path: /tmp/dist-test-task_caSEa/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515518284916-27409-0/minicluster-data/ts-0-root/wals/ef96416aef5a4681af58cde2a026d69c/wal-000000008 (ops 37-40)
I20260812 06:18:40.208313 27526 log.cc:1079] T ef96416aef5a4681af58cde2a026d69c P 9dd97c82fea44b7fb5534e173cfac07a: Deleting log segment in path: /tmp/dist-test-task_caSEa/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515518284916-27409-0/minicluster-data/ts-0-root/wals/ef96416aef5a4681af58cde2a026d69c/wal-000000009 (ops 41-45)
I20260812 06:18:40.208353 27526 log.cc:1079] T ef96416aef5a4681af58cde2a026d69c P 9dd97c82fea44b7fb5534e173cfac07a: Deleting log segment in path: /tmp/dist-test-task_caSEa/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515518284916-27409-0/minicluster-data/ts-0-root/wals/ef96416aef5a4681af58cde2a026d69c/wal-000000010 (ops 46-50)
I20260812 06:18:40.208400 27526 log.cc:1079] T ef96416aef5a4681af58cde2a026d69c P 9dd97c82fea44b7fb5534e173cfac07a: Deleting log segment in path: /tmp/dist-test-task_caSEa/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515518284916-27409-0/minicluster-data/ts-0-root/wals/ef96416aef5a4681af58cde2a026d69c/wal-000000011 (ops 51-55)
I20260812 06:18:40.208441 27526 log.cc:1079] T ef96416aef5a4681af58cde2a026d69c P 9dd97c82fea44b7fb5534e173cfac07a: Deleting log segment in path: /tmp/dist-test-task_caSEa/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515518284916-27409-0/minicluster-data/ts-0-root/wals/ef96416aef5a4681af58cde2a026d69c/wal-000000012 (ops 56-60)
I20260812 06:18:40.208479 27526 log.cc:1079] T ef96416aef5a4681af58cde2a026d69c P 9dd97c82fea44b7fb5534e173cfac07a: Deleting log segment in path: /tmp/dist-test-task_caSEa/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515518284916-27409-0/minicluster-data/ts-0-root/wals/ef96416aef5a4681af58cde2a026d69c/wal-000000013 (ops 61-65)
I20260812 06:18:40.208516 27526 log.cc:1079] T ef96416aef5a4681af58cde2a026d69c P 9dd97c82fea44b7fb5534e173cfac07a: Deleting log segment in path: /tmp/dist-test-task_caSEa/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515518284916-27409-0/minicluster-data/ts-0-root/wals/ef96416aef5a4681af58cde2a026d69c/wal-000000014 (ops 66-70)
I20260812 06:18:40.234732 27526 maintenance_manager.cc:643] P 9dd97c82fea44b7fb5534e173cfac07a: LogGCOp(ef96416aef5a4681af58cde2a026d69c) complete. Timing: real 0.027s	user 0.001s	sys 0.023s Metrics: {}
I20260812 06:18:40.235268 27596 maintenance_manager.cc:419] P 9dd97c82fea44b7fb5534e173cfac07a: Scheduling UndoDeltaBlockGCOp(ef96416aef5a4681af58cde2a026d69c): 472 bytes on disk
I20260812 06:18:40.235744 27526 maintenance_manager.cc:643] P 9dd97c82fea44b7fb5534e173cfac07a: UndoDeltaBlockGCOp(ef96416aef5a4681af58cde2a026d69c) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":67,"lbm_reads_lt_1ms":4}
I20260812 06:18:40.236260 27596 maintenance_manager.cc:419] P 9dd97c82fea44b7fb5534e173cfac07a: Scheduling FlushDeltaMemStoresOp(ef96416aef5a4681af58cde2a026d69c): perf score=3.181125
I20260812 06:18:40.255393 27526 maintenance_manager.cc:643] P 9dd97c82fea44b7fb5534e173cfac07a: FlushDeltaMemStoresOp(ef96416aef5a4681af58cde2a026d69c) complete. Timing: real 0.019s	user 0.009s	sys 0.007s Metrics: {"bytes_written":4512902,"delete_count":0,"lbm_write_time_us":7399,"lbm_writes_lt_1ms":113,"reinsert_count":0,"update_count":550}
I20260812 06:18:40.255918 27596 maintenance_manager.cc:419] P 9dd97c82fea44b7fb5534e173cfac07a: Scheduling FlushDeltaMemStoresOp(ef96416aef5a4681af58cde2a026d69c): perf score=2.188937
I20260812 06:18:40.265712 27526 maintenance_manager.cc:643] P 9dd97c82fea44b7fb5534e173cfac07a: FlushDeltaMemStoresOp(ef96416aef5a4681af58cde2a026d69c) complete. Timing: real 0.010s	user 0.007s	sys 0.001s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3464,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:18:40.266338 27596 maintenance_manager.cc:419] P 9dd97c82fea44b7fb5534e173cfac07a: Scheduling MajorDeltaCompactionOp(ef96416aef5a4681af58cde2a026d69c): perf score=1.000000
I20260812 06:18:40.442129 27526 maintenance_manager.cc:643] P 9dd97c82fea44b7fb5534e173cfac07a: MajorDeltaCompactionOp(ef96416aef5a4681af58cde2a026d69c) complete. Timing: real 0.176s	user 0.146s	sys 0.027s Metrics: {"cfile_cache_miss":634,"cfile_cache_miss_bytes":28877327,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":432,"lbm_read_time_us":13919,"lbm_reads_lt_1ms":674,"lbm_write_time_us":33272,"lbm_writes_lt_1ms":643,"mutex_wait_us":35,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":2560,"thread_start_us":75,"threads_started":1,"update_count":3000}
I20260812 06:18:40.442803 27596 maintenance_manager.cc:419] P 9dd97c82fea44b7fb5534e173cfac07a: Scheduling FlushDeltaMemStoresOp(ef96416aef5a4681af58cde2a026d69c): perf score=14.095187
I20260812 06:18:40.493432 27526 maintenance_manager.cc:643] P 9dd97c82fea44b7fb5534e173cfac07a: FlushDeltaMemStoresOp(ef96416aef5a4681af58cde2a026d69c) complete. Timing: real 0.050s	user 0.024s	sys 0.023s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":19825,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:18:40.493928 27596 maintenance_manager.cc:419] P 9dd97c82fea44b7fb5534e173cfac07a: Scheduling FlushDeltaMemStoresOp(ef96416aef5a4681af58cde2a026d69c): perf score=2.188937
I20260812 06:18:40.506181 27526 maintenance_manager.cc:643] P 9dd97c82fea44b7fb5534e173cfac07a: FlushDeltaMemStoresOp(ef96416aef5a4681af58cde2a026d69c) complete. Timing: real 0.012s	user 0.007s	sys 0.003s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4710,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:40.506822 27596 maintenance_manager.cc:419] P 9dd97c82fea44b7fb5534e173cfac07a: Scheduling MajorDeltaCompactionOp(ef96416aef5a4681af58cde2a026d69c): perf score=1.000000
I20260812 06:18:40.673349 27526 maintenance_manager.cc:643] P 9dd97c82fea44b7fb5534e173cfac07a: MajorDeltaCompactionOp(ef96416aef5a4681af58cde2a026d69c) complete. Timing: real 0.166s	user 0.126s	sys 0.031s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774688,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":1400,"lbm_read_time_us":10461,"lbm_reads_lt_1ms":572,"lbm_write_time_us":31650,"lbm_writes_lt_1ms":543,"mutex_wait_us":368,"peak_mem_usage":63115900,"reinsert_count":0,"update_count":2500}
I20260812 06:18:40.673964 27596 maintenance_manager.cc:419] P 9dd97c82fea44b7fb5534e173cfac07a: Scheduling FlushDeltaMemStoresOp(ef96416aef5a4681af58cde2a026d69c): perf score=14.095187
I20260812 06:18:40.739470 27526 maintenance_manager.cc:643] P 9dd97c82fea44b7fb5534e173cfac07a: FlushDeltaMemStoresOp(ef96416aef5a4681af58cde2a026d69c) complete. Timing: real 0.065s	user 0.021s	sys 0.028s Metrics: {"bytes_written":16409900,"delete_count":0,"lbm_write_time_us":25110,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":402,"reinsert_count":0,"update_count":2000}
I20260812 06:18:40.740006 27596 maintenance_manager.cc:419] P 9dd97c82fea44b7fb5534e173cfac07a: Scheduling FlushDeltaMemStoresOp(ef96416aef5a4681af58cde2a026d69c): perf score=2.188937
I20260812 06:18:40.750937 27526 maintenance_manager.cc:643] P 9dd97c82fea44b7fb5534e173cfac07a: FlushDeltaMemStoresOp(ef96416aef5a4681af58cde2a026d69c) complete. Timing: real 0.011s	user 0.004s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3973,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:40.751696 27596 maintenance_manager.cc:419] P 9dd97c82fea44b7fb5534e173cfac07a: Scheduling MajorDeltaCompactionOp(ef96416aef5a4681af58cde2a026d69c): perf score=1.000000
I20260812 06:18:40.910697 27526 maintenance_manager.cc:643] P 9dd97c82fea44b7fb5534e173cfac07a: MajorDeltaCompactionOp(ef96416aef5a4681af58cde2a026d69c) complete. Timing: real 0.159s	user 0.095s	sys 0.061s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774687,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":312,"lbm_read_time_us":10829,"lbm_reads_lt_1ms":572,"lbm_write_time_us":26415,"lbm_writes_lt_1ms":543,"mutex_wait_us":44,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":12672,"update_count":2500}
I20260812 06:18:40.911300 27596 maintenance_manager.cc:419] P 9dd97c82fea44b7fb5534e173cfac07a: Scheduling FlushDeltaMemStoresOp(ef96416aef5a4681af58cde2a026d69c): perf score=14.095187
I20260812 06:18:40.971424 27526 maintenance_manager.cc:643] P 9dd97c82fea44b7fb5534e173cfac07a: FlushDeltaMemStoresOp(ef96416aef5a4681af58cde2a026d69c) complete. Timing: real 0.060s	user 0.035s	sys 0.008s Metrics: {"bytes_written":16409908,"delete_count":0,"lbm_write_time_us":18755,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:18:40.972040 27596 maintenance_manager.cc:419] P 9dd97c82fea44b7fb5534e173cfac07a: Scheduling FlushDeltaMemStoresOp(ef96416aef5a4681af58cde2a026d69c): perf score=2.188937
I20260812 06:18:40.983886 27526 maintenance_manager.cc:643] P 9dd97c82fea44b7fb5534e173cfac07a: FlushDeltaMemStoresOp(ef96416aef5a4681af58cde2a026d69c) complete. Timing: real 0.012s	user 0.007s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4308,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:40.984541 27596 maintenance_manager.cc:419] P 9dd97c82fea44b7fb5534e173cfac07a: Scheduling MajorDeltaCompactionOp(ef96416aef5a4681af58cde2a026d69c): perf score=1.000000
I20260812 06:18:41.166834 27526 maintenance_manager.cc:643] P 9dd97c82fea44b7fb5534e173cfac07a: MajorDeltaCompactionOp(ef96416aef5a4681af58cde2a026d69c) complete. Timing: real 0.182s	user 0.126s	sys 0.048s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774695,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":149,"lbm_read_time_us":13053,"lbm_reads_lt_1ms":572,"lbm_write_time_us":31333,"lbm_writes_lt_1ms":543,"mutex_wait_us":20,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":6016,"update_count":2500}
I20260812 06:18:41.167584 27596 maintenance_manager.cc:419] P 9dd97c82fea44b7fb5534e173cfac07a: Scheduling FlushDeltaMemStoresOp(ef96416aef5a4681af58cde2a026d69c): perf score=14.095187
I20260812 06:18:41.225922 27526 maintenance_manager.cc:643] P 9dd97c82fea44b7fb5534e173cfac07a: FlushDeltaMemStoresOp(ef96416aef5a4681af58cde2a026d69c) complete. Timing: real 0.058s	user 0.023s	sys 0.023s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":17859,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:18:41.226471 27596 maintenance_manager.cc:419] P 9dd97c82fea44b7fb5534e173cfac07a: Scheduling FlushDeltaMemStoresOp(ef96416aef5a4681af58cde2a026d69c): perf score=2.188937
I20260812 06:18:41.237053 27526 maintenance_manager.cc:643] P 9dd97c82fea44b7fb5534e173cfac07a: FlushDeltaMemStoresOp(ef96416aef5a4681af58cde2a026d69c) complete. Timing: real 0.010s	user 0.005s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4087,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:41.237528 27596 maintenance_manager.cc:419] P 9dd97c82fea44b7fb5534e173cfac07a: Scheduling MajorDeltaCompactionOp(ef96416aef5a4681af58cde2a026d69c): perf score=1.000000
I20260812 06:18:41.398469 27526 maintenance_manager.cc:643] P 9dd97c82fea44b7fb5534e173cfac07a: MajorDeltaCompactionOp(ef96416aef5a4681af58cde2a026d69c) complete. Timing: real 0.161s	user 0.098s	sys 0.061s 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":97,"lbm_read_time_us":11875,"lbm_reads_lt_1ms":572,"lbm_write_time_us":28040,"lbm_writes_lt_1ms":543,"mutex_wait_us":1,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":3200,"update_count":2500}
I20260812 06:18:41.399308 27596 maintenance_manager.cc:419] P 9dd97c82fea44b7fb5534e173cfac07a: Scheduling FlushDeltaMemStoresOp(ef96416aef5a4681af58cde2a026d69c): perf score=10.126437
I20260812 06:18:41.440274 27526 maintenance_manager.cc:643] P 9dd97c82fea44b7fb5534e173cfac07a: FlushDeltaMemStoresOp(ef96416aef5a4681af58cde2a026d69c) complete. Timing: real 0.041s	user 0.029s	sys 0.012s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":18205,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:18:41.440821 27596 maintenance_manager.cc:419] P 9dd97c82fea44b7fb5534e173cfac07a: Scheduling FlushDeltaMemStoresOp(ef96416aef5a4681af58cde2a026d69c): perf score=2.188937
I20260812 06:18:41.450923 27526 maintenance_manager.cc:643] P 9dd97c82fea44b7fb5534e173cfac07a: FlushDeltaMemStoresOp(ef96416aef5a4681af58cde2a026d69c) complete. Timing: real 0.010s	user 0.004s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3914,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:41.451398 27596 maintenance_manager.cc:419] P 9dd97c82fea44b7fb5534e173cfac07a: Scheduling MajorDeltaCompactionOp(ef96416aef5a4681af58cde2a026d69c): perf score=1.000000
I20260812 06:18:41.603334 27526 maintenance_manager.cc:643] P 9dd97c82fea44b7fb5534e173cfac07a: MajorDeltaCompactionOp(ef96416aef5a4681af58cde2a026d69c) complete. Timing: real 0.152s	user 0.104s	sys 0.040s 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":703,"lbm_read_time_us":9401,"lbm_reads_lt_1ms":472,"lbm_write_time_us":26218,"lbm_writes_lt_1ms":443,"mutex_wait_us":22,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":4864,"update_count":2000}
I20260812 06:18:41.603820 27596 maintenance_manager.cc:419] P 9dd97c82fea44b7fb5534e173cfac07a: Scheduling FlushDeltaMemStoresOp(ef96416aef5a4681af58cde2a026d69c): perf score=10.126437
I20260812 06:18:41.646742 27526 maintenance_manager.cc:643] P 9dd97c82fea44b7fb5534e173cfac07a: FlushDeltaMemStoresOp(ef96416aef5a4681af58cde2a026d69c) complete. Timing: real 0.043s	user 0.018s	sys 0.013s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":14484,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:18:41.647339 27596 maintenance_manager.cc:419] P 9dd97c82fea44b7fb5534e173cfac07a: Scheduling FlushDeltaMemStoresOp(ef96416aef5a4681af58cde2a026d69c): perf score=2.188937
I20260812 06:18:41.662467 27526 maintenance_manager.cc:643] P 9dd97c82fea44b7fb5534e173cfac07a: FlushDeltaMemStoresOp(ef96416aef5a4681af58cde2a026d69c) complete. Timing: real 0.015s	user 0.004s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5625,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:41.663105 27596 maintenance_manager.cc:419] P 9dd97c82fea44b7fb5534e173cfac07a: Scheduling FlushMRSOp(ef96416aef5a4681af58cde2a026d69c): perf score=1.000000
I20260812 06:18:41.692812 27526 maintenance_manager.cc:643] P 9dd97c82fea44b7fb5534e173cfac07a: FlushMRSOp(ef96416aef5a4681af58cde2a026d69c) complete. Timing: real 0.029s	user 0.027s	sys 0.001s Metrics: {"bytes_written":1234479,"cfile_init":1,"dirs.queue_time_us":349,"dirs.run_cpu_time_us":217,"dirs.run_wall_time_us":1317,"drs_written":1,"lbm_read_time_us":55,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1485,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":30}
I20260812 06:18:41.693578 27596 maintenance_manager.cc:419] P 9dd97c82fea44b7fb5534e173cfac07a: Scheduling LogGCOp(ef96416aef5a4681af58cde2a026d69c): free 123804191 bytes of WAL
I20260812 06:18:41.693852 27526 log_reader.cc:385] T ef96416aef5a4681af58cde2a026d69c: removed 12 log segments from log reader
I20260812 06:18:41.693917 27526 log.cc:1079] T ef96416aef5a4681af58cde2a026d69c P 9dd97c82fea44b7fb5534e173cfac07a: Deleting log segment in path: /tmp/dist-test-task_caSEa/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515518284916-27409-0/minicluster-data/ts-0-root/wals/ef96416aef5a4681af58cde2a026d69c/wal-000000015 (ops 71-74)
I20260812 06:18:41.693954 27526 log.cc:1079] T ef96416aef5a4681af58cde2a026d69c P 9dd97c82fea44b7fb5534e173cfac07a: Deleting log segment in path: /tmp/dist-test-task_caSEa/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515518284916-27409-0/minicluster-data/ts-0-root/wals/ef96416aef5a4681af58cde2a026d69c/wal-000000016 (ops 75-79)
I20260812 06:18:41.693977 27526 log.cc:1079] T ef96416aef5a4681af58cde2a026d69c P 9dd97c82fea44b7fb5534e173cfac07a: Deleting log segment in path: /tmp/dist-test-task_caSEa/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515518284916-27409-0/minicluster-data/ts-0-root/wals/ef96416aef5a4681af58cde2a026d69c/wal-000000017 (ops 80-84)
I20260812 06:18:41.694018 27526 log.cc:1079] T ef96416aef5a4681af58cde2a026d69c P 9dd97c82fea44b7fb5534e173cfac07a: Deleting log segment in path: /tmp/dist-test-task_caSEa/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515518284916-27409-0/minicluster-data/ts-0-root/wals/ef96416aef5a4681af58cde2a026d69c/wal-000000018 (ops 85-89)
I20260812 06:18:41.694051 27526 log.cc:1079] T ef96416aef5a4681af58cde2a026d69c P 9dd97c82fea44b7fb5534e173cfac07a: Deleting log segment in path: /tmp/dist-test-task_caSEa/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515518284916-27409-0/minicluster-data/ts-0-root/wals/ef96416aef5a4681af58cde2a026d69c/wal-000000019 (ops 90-94)
I20260812 06:18:41.694087 27526 log.cc:1079] T ef96416aef5a4681af58cde2a026d69c P 9dd97c82fea44b7fb5534e173cfac07a: Deleting log segment in path: /tmp/dist-test-task_caSEa/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515518284916-27409-0/minicluster-data/ts-0-root/wals/ef96416aef5a4681af58cde2a026d69c/wal-000000020 (ops 95-99)
I20260812 06:18:41.694115 27526 log.cc:1079] T ef96416aef5a4681af58cde2a026d69c P 9dd97c82fea44b7fb5534e173cfac07a: Deleting log segment in path: /tmp/dist-test-task_caSEa/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515518284916-27409-0/minicluster-data/ts-0-root/wals/ef96416aef5a4681af58cde2a026d69c/wal-000000021 (ops 100-104)
I20260812 06:18:41.694144 27526 log.cc:1079] T ef96416aef5a4681af58cde2a026d69c P 9dd97c82fea44b7fb5534e173cfac07a: Deleting log segment in path: /tmp/dist-test-task_caSEa/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515518284916-27409-0/minicluster-data/ts-0-root/wals/ef96416aef5a4681af58cde2a026d69c/wal-000000022 (ops 105-108)
I20260812 06:18:41.694170 27526 log.cc:1079] T ef96416aef5a4681af58cde2a026d69c P 9dd97c82fea44b7fb5534e173cfac07a: Deleting log segment in path: /tmp/dist-test-task_caSEa/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515518284916-27409-0/minicluster-data/ts-0-root/wals/ef96416aef5a4681af58cde2a026d69c/wal-000000023 (ops 109-113)
I20260812 06:18:41.694199 27526 log.cc:1079] T ef96416aef5a4681af58cde2a026d69c P 9dd97c82fea44b7fb5534e173cfac07a: Deleting log segment in path: /tmp/dist-test-task_caSEa/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515518284916-27409-0/minicluster-data/ts-0-root/wals/ef96416aef5a4681af58cde2a026d69c/wal-000000024 (ops 114-118)
I20260812 06:18:41.694233 27526 log.cc:1079] T ef96416aef5a4681af58cde2a026d69c P 9dd97c82fea44b7fb5534e173cfac07a: Deleting log segment in path: /tmp/dist-test-task_caSEa/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515518284916-27409-0/minicluster-data/ts-0-root/wals/ef96416aef5a4681af58cde2a026d69c/wal-000000025 (ops 119-123)
I20260812 06:18:41.694262 27526 log.cc:1079] T ef96416aef5a4681af58cde2a026d69c P 9dd97c82fea44b7fb5534e173cfac07a: Deleting log segment in path: /tmp/dist-test-task_caSEa/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515518284916-27409-0/minicluster-data/ts-0-root/wals/ef96416aef5a4681af58cde2a026d69c/wal-000000026 (ops 124-128)
I20260812 06:18:41.723937 27526 maintenance_manager.cc:643] P 9dd97c82fea44b7fb5534e173cfac07a: LogGCOp(ef96416aef5a4681af58cde2a026d69c) complete. Timing: real 0.030s	user 0.002s	sys 0.028s Metrics: {}
I20260812 06:18:41.724537 27596 maintenance_manager.cc:419] P 9dd97c82fea44b7fb5534e173cfac07a: Scheduling FlushDeltaMemStoresOp(ef96416aef5a4681af58cde2a026d69c): perf score=2.188937
I20260812 06:18:41.745077 27526 maintenance_manager.cc:643] P 9dd97c82fea44b7fb5534e173cfac07a: FlushDeltaMemStoresOp(ef96416aef5a4681af58cde2a026d69c) complete. Timing: real 0.020s	user 0.009s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5744,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:41.745592 27596 maintenance_manager.cc:419] P 9dd97c82fea44b7fb5534e173cfac07a: Scheduling UndoDeltaBlockGCOp(ef96416aef5a4681af58cde2a026d69c): 472 bytes on disk
I20260812 06:18:41.746035 27526 maintenance_manager.cc:643] P 9dd97c82fea44b7fb5534e173cfac07a: UndoDeltaBlockGCOp(ef96416aef5a4681af58cde2a026d69c) 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:41.746551 27596 maintenance_manager.cc:419] P 9dd97c82fea44b7fb5534e173cfac07a: Scheduling FlushDeltaMemStoresOp(ef96416aef5a4681af58cde2a026d69c): perf score=2.188937
I20260812 06:18:41.757275 27526 maintenance_manager.cc:643] P 9dd97c82fea44b7fb5534e173cfac07a: FlushDeltaMemStoresOp(ef96416aef5a4681af58cde2a026d69c) complete. Timing: real 0.011s	user 0.005s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4023,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:41.757977 27596 maintenance_manager.cc:419] P 9dd97c82fea44b7fb5534e173cfac07a: Scheduling MajorDeltaCompactionOp(ef96416aef5a4681af58cde2a026d69c): perf score=1.000000
I20260812 06:18:41.919345 27526 maintenance_manager.cc:643] P 9dd97c82fea44b7fb5534e173cfac07a: MajorDeltaCompactionOp(ef96416aef5a4681af58cde2a026d69c) complete. Timing: real 0.161s	user 0.133s	sys 0.028s Metrics: {"cfile_cache_miss":634,"cfile_cache_miss_bytes":28877339,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":771,"lbm_read_time_us":11754,"lbm_reads_lt_1ms":674,"lbm_write_time_us":33935,"lbm_writes_lt_1ms":643,"mutex_wait_us":59,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":10880,"thread_start_us":80,"threads_started":1,"update_count":3000}
I20260812 06:18:41.920228 27596 maintenance_manager.cc:419] P 9dd97c82fea44b7fb5534e173cfac07a: Scheduling FlushDeltaMemStoresOp(ef96416aef5a4681af58cde2a026d69c): perf score=14.095187
I20260812 06:18:41.977363 27526 maintenance_manager.cc:643] P 9dd97c82fea44b7fb5534e173cfac07a: FlushDeltaMemStoresOp(ef96416aef5a4681af58cde2a026d69c) complete. Timing: real 0.057s	user 0.037s	sys 0.017s Metrics: {"bytes_written":16409903,"delete_count":0,"lbm_write_time_us":25020,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:18:41.978055 27596 maintenance_manager.cc:419] P 9dd97c82fea44b7fb5534e173cfac07a: Scheduling FlushDeltaMemStoresOp(ef96416aef5a4681af58cde2a026d69c): perf score=2.188937
I20260812 06:18:41.989665 27526 maintenance_manager.cc:643] P 9dd97c82fea44b7fb5534e173cfac07a: FlushDeltaMemStoresOp(ef96416aef5a4681af58cde2a026d69c) complete. Timing: real 0.011s	user 0.009s	sys 0.000s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":3961,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:41.990162 27596 maintenance_manager.cc:419] P 9dd97c82fea44b7fb5534e173cfac07a: Scheduling MajorDeltaCompactionOp(ef96416aef5a4681af58cde2a026d69c): perf score=1.000000
I20260812 06:18:42.143937 27526 maintenance_manager.cc:643] P 9dd97c82fea44b7fb5534e173cfac07a: MajorDeltaCompactionOp(ef96416aef5a4681af58cde2a026d69c) complete. Timing: real 0.154s	user 0.102s	sys 0.044s 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":1505,"lbm_read_time_us":10250,"lbm_reads_lt_1ms":572,"lbm_write_time_us":30601,"lbm_writes_lt_1ms":543,"mutex_wait_us":23,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":8960,"update_count":2500}
I20260812 06:18:42.144666 27596 maintenance_manager.cc:419] P 9dd97c82fea44b7fb5534e173cfac07a: Scheduling FlushDeltaMemStoresOp(ef96416aef5a4681af58cde2a026d69c): perf score=11.118625
I20260812 06:18:42.176882 27526 maintenance_manager.cc:643] P 9dd97c82fea44b7fb5534e173cfac07a: FlushDeltaMemStoresOp(ef96416aef5a4681af58cde2a026d69c) complete. Timing: real 0.032s	user 0.015s	sys 0.016s Metrics: {"bytes_written":12717736,"delete_count":0,"lbm_write_time_us":13499,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:18:42.177430 27596 maintenance_manager.cc:419] P 9dd97c82fea44b7fb5534e173cfac07a: Scheduling FlushDeltaMemStoresOp(ef96416aef5a4681af58cde2a026d69c): perf score=2.188937
I20260812 06:18:42.201102 27526 maintenance_manager.cc:643] P 9dd97c82fea44b7fb5534e173cfac07a: FlushDeltaMemStoresOp(ef96416aef5a4681af58cde2a026d69c) complete. Timing: real 0.023s	user 0.010s	sys 0.000s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3961,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:18:42.201611 27596 maintenance_manager.cc:419] P 9dd97c82fea44b7fb5534e173cfac07a: Scheduling FlushDeltaMemStoresOp(ef96416aef5a4681af58cde2a026d69c): perf score=2.188937
I20260812 06:18:42.212208 27526 maintenance_manager.cc:643] P 9dd97c82fea44b7fb5534e173cfac07a: FlushDeltaMemStoresOp(ef96416aef5a4681af58cde2a026d69c) complete. Timing: real 0.010s	user 0.010s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4036,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:42.212965 27596 maintenance_manager.cc:419] P 9dd97c82fea44b7fb5534e173cfac07a: Scheduling MajorDeltaCompactionOp(ef96416aef5a4681af58cde2a026d69c): perf score=1.000000
I20260812 06:18:42.360864 27526 maintenance_manager.cc:643] P 9dd97c82fea44b7fb5534e173cfac07a: MajorDeltaCompactionOp(ef96416aef5a4681af58cde2a026d69c) complete. Timing: real 0.148s	user 0.115s	sys 0.031s Metrics: {"cfile_cache_miss":533,"cfile_cache_miss_bytes":24774800,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":1042,"lbm_read_time_us":9358,"lbm_reads_lt_1ms":573,"lbm_write_time_us":29974,"lbm_writes_lt_1ms":543,"mutex_wait_us":365,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":768,"update_count":2500}
I20260812 06:18:42.361495 27596 maintenance_manager.cc:419] P 9dd97c82fea44b7fb5534e173cfac07a: Scheduling FlushDeltaMemStoresOp(ef96416aef5a4681af58cde2a026d69c): perf score=11.118625
I20260812 06:18:42.397260 27526 maintenance_manager.cc:643] P 9dd97c82fea44b7fb5534e173cfac07a: FlushDeltaMemStoresOp(ef96416aef5a4681af58cde2a026d69c) complete. Timing: real 0.036s	user 0.026s	sys 0.008s Metrics: {"bytes_written":12717737,"delete_count":0,"lbm_write_time_us":15504,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:18:42.398061 27596 maintenance_manager.cc:419] P 9dd97c82fea44b7fb5534e173cfac07a: Scheduling FlushDeltaMemStoresOp(ef96416aef5a4681af58cde2a026d69c): perf score=2.188937
I20260812 06:18:42.413558 27526 maintenance_manager.cc:643] P 9dd97c82fea44b7fb5534e173cfac07a: FlushDeltaMemStoresOp(ef96416aef5a4681af58cde2a026d69c) complete. Timing: real 0.015s	user 0.010s	sys 0.000s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3910,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:18:42.414182 27596 maintenance_manager.cc:419] P 9dd97c82fea44b7fb5534e173cfac07a: Scheduling MajorDeltaCompactionOp(ef96416aef5a4681af58cde2a026d69c): perf score=1.000000
I20260812 06:18:42.542307 27526 maintenance_manager.cc:643] P 9dd97c82fea44b7fb5534e173cfac07a: MajorDeltaCompactionOp(ef96416aef5a4681af58cde2a026d69c) complete. Timing: real 0.128s	user 0.111s	sys 0.016s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672270,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":390,"lbm_read_time_us":7247,"lbm_reads_lt_1ms":464,"lbm_write_time_us":25625,"lbm_writes_lt_1ms":443,"mutex_wait_us":2,"peak_mem_usage":50689328,"reinsert_count":0,"update_count":2000}
I20260812 06:18:42.543177 27596 maintenance_manager.cc:419] P 9dd97c82fea44b7fb5534e173cfac07a: Scheduling FlushDeltaMemStoresOp(ef96416aef5a4681af58cde2a026d69c): perf score=10.126437
I20260812 06:18:42.585690 27526 maintenance_manager.cc:643] P 9dd97c82fea44b7fb5534e173cfac07a: FlushDeltaMemStoresOp(ef96416aef5a4681af58cde2a026d69c) complete. Timing: real 0.042s	user 0.024s	sys 0.011s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":15778,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:18:42.586267 27596 maintenance_manager.cc:419] P 9dd97c82fea44b7fb5534e173cfac07a: Scheduling FlushDeltaMemStoresOp(ef96416aef5a4681af58cde2a026d69c): perf score=2.188937
I20260812 06:18:42.597445 27526 maintenance_manager.cc:643] P 9dd97c82fea44b7fb5534e173cfac07a: FlushDeltaMemStoresOp(ef96416aef5a4681af58cde2a026d69c) complete. Timing: real 0.011s	user 0.009s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3929,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:42.598245 27596 maintenance_manager.cc:419] P 9dd97c82fea44b7fb5534e173cfac07a: Scheduling MajorDeltaCompactionOp(ef96416aef5a4681af58cde2a026d69c): perf score=1.000000
I20260812 06:18:42.720028 27526 maintenance_manager.cc:643] P 9dd97c82fea44b7fb5534e173cfac07a: MajorDeltaCompactionOp(ef96416aef5a4681af58cde2a026d69c) complete. Timing: real 0.122s	user 0.101s	sys 0.020s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672277,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":673,"lbm_read_time_us":8701,"lbm_reads_lt_1ms":472,"lbm_write_time_us":22561,"lbm_writes_lt_1ms":443,"mutex_wait_us":313,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":9600,"update_count":2000}
I20260812 06:18:42.720814 27596 maintenance_manager.cc:419] P 9dd97c82fea44b7fb5534e173cfac07a: Scheduling FlushDeltaMemStoresOp(ef96416aef5a4681af58cde2a026d69c): perf score=10.126437
I20260812 06:18:42.773777 27526 maintenance_manager.cc:643] P 9dd97c82fea44b7fb5534e173cfac07a: FlushDeltaMemStoresOp(ef96416aef5a4681af58cde2a026d69c) complete. Timing: real 0.053s	user 0.027s	sys 0.015s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":16214,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:18:42.774354 27596 maintenance_manager.cc:419] P 9dd97c82fea44b7fb5534e173cfac07a: Scheduling FlushDeltaMemStoresOp(ef96416aef5a4681af58cde2a026d69c): perf score=2.188937
I20260812 06:18:42.787107 27526 maintenance_manager.cc:643] P 9dd97c82fea44b7fb5534e173cfac07a: FlushDeltaMemStoresOp(ef96416aef5a4681af58cde2a026d69c) complete. Timing: real 0.013s	user 0.011s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5343,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:42.787609 27596 maintenance_manager.cc:419] P 9dd97c82fea44b7fb5534e173cfac07a: Scheduling MajorDeltaCompactionOp(ef96416aef5a4681af58cde2a026d69c): perf score=1.000000
I20260812 06:18:42.933526 27526 maintenance_manager.cc:643] P 9dd97c82fea44b7fb5534e173cfac07a: MajorDeltaCompactionOp(ef96416aef5a4681af58cde2a026d69c) complete. Timing: real 0.146s	user 0.113s	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":1582,"lbm_read_time_us":11228,"lbm_reads_lt_1ms":472,"lbm_write_time_us":23638,"lbm_writes_lt_1ms":443,"mutex_wait_us":447,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":176512,"update_count":2000}
I20260812 06:18:42.934262 27596 maintenance_manager.cc:419] P 9dd97c82fea44b7fb5534e173cfac07a: Scheduling FlushDeltaMemStoresOp(ef96416aef5a4681af58cde2a026d69c): perf score=10.126437
I20260812 06:18:42.974593 27526 maintenance_manager.cc:643] P 9dd97c82fea44b7fb5534e173cfac07a: FlushDeltaMemStoresOp(ef96416aef5a4681af58cde2a026d69c) complete. Timing: real 0.040s	user 0.017s	sys 0.016s Metrics: {"bytes_written":12307492,"delete_count":0,"lbm_write_time_us":15600,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:18:42.975212 27596 maintenance_manager.cc:419] P 9dd97c82fea44b7fb5534e173cfac07a: Scheduling FlushDeltaMemStoresOp(ef96416aef5a4681af58cde2a026d69c): perf score=2.188937
I20260812 06:18:42.985802 27526 maintenance_manager.cc:643] P 9dd97c82fea44b7fb5534e173cfac07a: FlushDeltaMemStoresOp(ef96416aef5a4681af58cde2a026d69c) complete. Timing: real 0.010s	user 0.009s	sys 0.000s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":3988,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:42.986433 27596 maintenance_manager.cc:419] P 9dd97c82fea44b7fb5534e173cfac07a: Scheduling FlushMRSOp(ef96416aef5a4681af58cde2a026d69c): perf score=1.000000
I20260812 06:18:43.017225 27526 maintenance_manager.cc:643] P 9dd97c82fea44b7fb5534e173cfac07a: FlushMRSOp(ef96416aef5a4681af58cde2a026d69c) complete. Timing: real 0.031s	user 0.029s	sys 0.000s Metrics: {"bytes_written":1152510,"cfile_init":1,"dirs.queue_time_us":70,"dirs.run_cpu_time_us":191,"dirs.run_wall_time_us":1435,"drs_written":1,"lbm_read_time_us":39,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1780,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":28}
I20260812 06:18:43.017895 27596 maintenance_manager.cc:419] P 9dd97c82fea44b7fb5534e173cfac07a: Scheduling LogGCOp(ef96416aef5a4681af58cde2a026d69c): free 121006640 bytes of WAL
I20260812 06:18:43.018137 27526 log_reader.cc:385] T ef96416aef5a4681af58cde2a026d69c: removed 12 log segments from log reader
I20260812 06:18:43.018183 27526 log.cc:1079] T ef96416aef5a4681af58cde2a026d69c P 9dd97c82fea44b7fb5534e173cfac07a: Deleting log segment in path: /tmp/dist-test-task_caSEa/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515518284916-27409-0/minicluster-data/ts-0-root/wals/ef96416aef5a4681af58cde2a026d69c/wal-000000027 (ops 129-133)
I20260812 06:18:43.018213 27526 log.cc:1079] T ef96416aef5a4681af58cde2a026d69c P 9dd97c82fea44b7fb5534e173cfac07a: Deleting log segment in path: /tmp/dist-test-task_caSEa/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515518284916-27409-0/minicluster-data/ts-0-root/wals/ef96416aef5a4681af58cde2a026d69c/wal-000000028 (ops 134-138)
I20260812 06:18:43.018287 27526 log.cc:1079] T ef96416aef5a4681af58cde2a026d69c P 9dd97c82fea44b7fb5534e173cfac07a: Deleting log segment in path: /tmp/dist-test-task_caSEa/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515518284916-27409-0/minicluster-data/ts-0-root/wals/ef96416aef5a4681af58cde2a026d69c/wal-000000029 (ops 139-143)
I20260812 06:18:43.018332 27526 log.cc:1079] T ef96416aef5a4681af58cde2a026d69c P 9dd97c82fea44b7fb5534e173cfac07a: Deleting log segment in path: /tmp/dist-test-task_caSEa/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515518284916-27409-0/minicluster-data/ts-0-root/wals/ef96416aef5a4681af58cde2a026d69c/wal-000000030 (ops 144-148)
I20260812 06:18:43.018373 27526 log.cc:1079] T ef96416aef5a4681af58cde2a026d69c P 9dd97c82fea44b7fb5534e173cfac07a: Deleting log segment in path: /tmp/dist-test-task_caSEa/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515518284916-27409-0/minicluster-data/ts-0-root/wals/ef96416aef5a4681af58cde2a026d69c/wal-000000031 (ops 149-152)
I20260812 06:18:43.018435 27526 log.cc:1079] T ef96416aef5a4681af58cde2a026d69c P 9dd97c82fea44b7fb5534e173cfac07a: Deleting log segment in path: /tmp/dist-test-task_caSEa/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515518284916-27409-0/minicluster-data/ts-0-root/wals/ef96416aef5a4681af58cde2a026d69c/wal-000000032 (ops 153-157)
I20260812 06:18:43.018479 27526 log.cc:1079] T ef96416aef5a4681af58cde2a026d69c P 9dd97c82fea44b7fb5534e173cfac07a: Deleting log segment in path: /tmp/dist-test-task_caSEa/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515518284916-27409-0/minicluster-data/ts-0-root/wals/ef96416aef5a4681af58cde2a026d69c/wal-000000033 (ops 158-162)
I20260812 06:18:43.018522 27526 log.cc:1079] T ef96416aef5a4681af58cde2a026d69c P 9dd97c82fea44b7fb5534e173cfac07a: Deleting log segment in path: /tmp/dist-test-task_caSEa/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515518284916-27409-0/minicluster-data/ts-0-root/wals/ef96416aef5a4681af58cde2a026d69c/wal-000000034 (ops 163-167)
I20260812 06:18:43.018560 27526 log.cc:1079] T ef96416aef5a4681af58cde2a026d69c P 9dd97c82fea44b7fb5534e173cfac07a: Deleting log segment in path: /tmp/dist-test-task_caSEa/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515518284916-27409-0/minicluster-data/ts-0-root/wals/ef96416aef5a4681af58cde2a026d69c/wal-000000035 (ops 168-172)
I20260812 06:18:43.018601 27526 log.cc:1079] T ef96416aef5a4681af58cde2a026d69c P 9dd97c82fea44b7fb5534e173cfac07a: Deleting log segment in path: /tmp/dist-test-task_caSEa/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515518284916-27409-0/minicluster-data/ts-0-root/wals/ef96416aef5a4681af58cde2a026d69c/wal-000000036 (ops 173-177)
I20260812 06:18:43.018641 27526 log.cc:1079] T ef96416aef5a4681af58cde2a026d69c P 9dd97c82fea44b7fb5534e173cfac07a: Deleting log segment in path: /tmp/dist-test-task_caSEa/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515518284916-27409-0/minicluster-data/ts-0-root/wals/ef96416aef5a4681af58cde2a026d69c/wal-000000037 (ops 178-182)
I20260812 06:18:43.018682 27526 log.cc:1079] T ef96416aef5a4681af58cde2a026d69c P 9dd97c82fea44b7fb5534e173cfac07a: Deleting log segment in path: /tmp/dist-test-task_caSEa/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515518284916-27409-0/minicluster-data/ts-0-root/wals/ef96416aef5a4681af58cde2a026d69c/wal-000000038 (ops 183-187)
I20260812 06:18:43.047885 27526 maintenance_manager.cc:643] P 9dd97c82fea44b7fb5534e173cfac07a: LogGCOp(ef96416aef5a4681af58cde2a026d69c) complete. Timing: real 0.030s	user 0.002s	sys 0.026s Metrics: {}
I20260812 06:18:43.048425 27596 maintenance_manager.cc:419] P 9dd97c82fea44b7fb5534e173cfac07a: Scheduling FlushDeltaMemStoresOp(ef96416aef5a4681af58cde2a026d69c): perf score=3.181125
I20260812 06:18:43.071023 27526 maintenance_manager.cc:643] P 9dd97c82fea44b7fb5534e173cfac07a: FlushDeltaMemStoresOp(ef96416aef5a4681af58cde2a026d69c) complete. Timing: real 0.022s	user 0.007s	sys 0.012s Metrics: {"bytes_written":4512903,"delete_count":0,"lbm_write_time_us":4611,"lbm_writes_lt_1ms":113,"reinsert_count":0,"update_count":550}
I20260812 06:18:43.071650 27596 maintenance_manager.cc:419] P 9dd97c82fea44b7fb5534e173cfac07a: Scheduling FlushDeltaMemStoresOp(ef96416aef5a4681af58cde2a026d69c): perf score=2.188937
I20260812 06:18:43.086448 27526 maintenance_manager.cc:643] P 9dd97c82fea44b7fb5534e173cfac07a: FlushDeltaMemStoresOp(ef96416aef5a4681af58cde2a026d69c) complete. Timing: real 0.015s	user 0.011s	sys 0.001s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":5392,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:18:43.087028 27596 maintenance_manager.cc:419] P 9dd97c82fea44b7fb5534e173cfac07a: Scheduling UndoDeltaBlockGCOp(ef96416aef5a4681af58cde2a026d69c): 448 bytes on disk
I20260812 06:18:43.087664 27526 maintenance_manager.cc:643] P 9dd97c82fea44b7fb5534e173cfac07a: UndoDeltaBlockGCOp(ef96416aef5a4681af58cde2a026d69c) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":100,"lbm_reads_lt_1ms":4}
I20260812 06:18:43.088526 27596 maintenance_manager.cc:419] P 9dd97c82fea44b7fb5534e173cfac07a: Scheduling MajorDeltaCompactionOp(ef96416aef5a4681af58cde2a026d69c): perf score=1.000000
I20260812 06:18:43.306181 27526 maintenance_manager.cc:643] P 9dd97c82fea44b7fb5534e173cfac07a: MajorDeltaCompactionOp(ef96416aef5a4681af58cde2a026d69c) complete. Timing: real 0.217s	user 0.165s	sys 0.044s Metrics: {"cfile_cache_miss":634,"cfile_cache_miss_bytes":28877330,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":576,"lbm_read_time_us":15200,"lbm_reads_lt_1ms":674,"lbm_write_time_us":36716,"lbm_writes_lt_1ms":643,"mutex_wait_us":47,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":26240,"thread_start_us":81,"threads_started":1,"update_count":3000}
I20260812 06:18:43.306993 27596 maintenance_manager.cc:419] P 9dd97c82fea44b7fb5534e173cfac07a: Scheduling FlushDeltaMemStoresOp(ef96416aef5a4681af58cde2a026d69c): perf score=14.095187
I20260812 06:18:43.366757 27526 maintenance_manager.cc:643] P 9dd97c82fea44b7fb5534e173cfac07a: FlushDeltaMemStoresOp(ef96416aef5a4681af58cde2a026d69c) complete. Timing: real 0.060s	user 0.030s	sys 0.020s Metrics: {"bytes_written":16409903,"delete_count":0,"lbm_write_time_us":20021,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:18:43.367302 27596 maintenance_manager.cc:419] P 9dd97c82fea44b7fb5534e173cfac07a: Scheduling FlushDeltaMemStoresOp(ef96416aef5a4681af58cde2a026d69c): perf score=2.188937
I20260812 06:18:43.378799 27526 maintenance_manager.cc:643] P 9dd97c82fea44b7fb5534e173cfac07a: FlushDeltaMemStoresOp(ef96416aef5a4681af58cde2a026d69c) complete. Timing: real 0.011s	user 0.009s	sys 0.000s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4197,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:43.379360 27596 maintenance_manager.cc:419] P 9dd97c82fea44b7fb5534e173cfac07a: Scheduling MajorDeltaCompactionOp(ef96416aef5a4681af58cde2a026d69c): perf score=1.000000
I20260812 06:18:43.430423 27409 heavy-update-compaction-itest.cc:229] Time spent updating: real 4.850s	user 1.835s	sys 0.141s
I20260812 06:18:43.535915 27409 heavy-update-compaction-itest.cc:265] Time spent scanning: real 0.105s	user 0.005s	sys 0.000s
I20260812 06:18:43.536610 27409 tablet_server.cc:179] TabletServer@127.26.196.65:0 shutting down...
I20260812 06:18:43.569840 27526 maintenance_manager.cc:643] P 9dd97c82fea44b7fb5534e173cfac07a: MajorDeltaCompactionOp(ef96416aef5a4681af58cde2a026d69c) complete. Timing: real 0.190s	user 0.133s	sys 0.056s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774689,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":395,"lbm_read_time_us":12430,"lbm_reads_1-10_ms":1,"lbm_reads_lt_1ms":567,"lbm_write_time_us":36009,"lbm_writes_lt_1ms":543,"mutex_wait_us":35,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":16640,"update_count":2500}
I20260812 06:18:43.570565 27409 ts_tablet_manager.cc:1507] Shutting down tablet manager...
I20260812 06:18:43.571022 27409 tablet_replica.cc:333] T ef96416aef5a4681af58cde2a026d69c P 9dd97c82fea44b7fb5534e173cfac07a: stopping tablet replica
I20260812 06:18:43.571300 27409 raft_consensus.cc:2243] T ef96416aef5a4681af58cde2a026d69c P 9dd97c82fea44b7fb5534e173cfac07a [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:18:43.571557 27409 raft_consensus.cc:2272] T ef96416aef5a4681af58cde2a026d69c P 9dd97c82fea44b7fb5534e173cfac07a [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:18:43.578389 27409 tablet_server.cc:196] TabletServer@127.26.196.65:0 shutdown complete.
I20260812 06:18:43.617422 27409 master.cc:562] Master@127.26.196.126:40121 shutting down...
I20260812 06:18:43.621513 27409 raft_consensus.cc:2243] T 00000000000000000000000000000000 P a51cb34289ab49ceae3c6273e67f755e [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:18:43.621695 27409 raft_consensus.cc:2272] T 00000000000000000000000000000000 P a51cb34289ab49ceae3c6273e67f755e [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:18:43.621752 27409 tablet_replica.cc:333] T 00000000000000000000000000000000 P a51cb34289ab49ceae3c6273e67f755e: stopping tablet replica
I20260812 06:18:43.634271 27409 master.cc:584] Master@127.26.196.126:40121 shutdown complete.
[       OK ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/0 (5425 ms)
[ RUN      ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/1
I20260812 06:18:43.735972 27409 internal_mini_cluster.cc:156] Creating distributed mini masters. Addrs: 127.26.196.126:38455
I20260812 06:18:43.736392 27409 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:18:43.738579 27635 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:43.738746 27637 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:43.738749 27634 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:43.738991 27409 server_base.cc:1061] running on GCE node
I20260812 06:18:43.739219 27409 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:18:43.739262 27409 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:43.739296 27409 hybrid_clock.cc:648] HybridClock initialized: now 1786515523739296 us; error 0 us; skew 500 ppm
I20260812 06:18:43.740268 27409 webserver.cc:533] Webserver started at http://127.26.196.126:36613/ using document root <none> and password file <none>
I20260812 06:18:43.740473 27409 fs_manager.cc:362] Metadata directory not provided
I20260812 06:18:43.740563 27409 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:18:43.740656 27409 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:18:43.741104 27409 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-task_caSEa/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515518284916-27409-0/minicluster-data/master-0-root/instance:
uuid: "e655b330ad964b9b9770c5c31beaf8b7"
format_stamp: "Formatted at 2026-08-12 06:18:43 on dist-test-slave-mvvj"
I20260812 06:18:43.742736 27409 fs_manager.cc:696] Time spent creating directory manager: real 0.001s	user 0.000s	sys 0.002s
I20260812 06:18:43.743738 27642 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:43.744052 27409 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.000s	sys 0.001s
I20260812 06:18:43.744154 27409 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-task_caSEa/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515518284916-27409-0/minicluster-data/master-0-root
uuid: "e655b330ad964b9b9770c5c31beaf8b7"
format_stamp: "Formatted at 2026-08-12 06:18:43 on dist-test-slave-mvvj"
I20260812 06:18:43.744256 27409 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-task_caSEa/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515518284916-27409-0/minicluster-data/master-0-root
metadata directory: /tmp/dist-test-task_caSEa/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515518284916-27409-0/minicluster-data/master-0-root
1 data directories: /tmp/dist-test-task_caSEa/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515518284916-27409-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:43.761514 27409 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:18:43.761986 27409 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:18:43.767017 27409 rpc_server.cc:307] RPC server started. Bound to: 127.26.196.126:38455
I20260812 06:18:43.769255 27701 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.26.196.126:38455 every 8 connection(s)
I20260812 06:18:43.769742 27702 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:43.771535 27702 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P e655b330ad964b9b9770c5c31beaf8b7: Bootstrap starting.
I20260812 06:18:43.772315 27702 tablet_bootstrap.cc:654] T 00000000000000000000000000000000 P e655b330ad964b9b9770c5c31beaf8b7: Neither blocks nor log segments found. Creating new log.
I20260812 06:18:43.773325 27702 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P e655b330ad964b9b9770c5c31beaf8b7: No bootstrap required, opened a new log
I20260812 06:18:43.773721 27702 raft_consensus.cc:359] T 00000000000000000000000000000000 P e655b330ad964b9b9770c5c31beaf8b7 [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "e655b330ad964b9b9770c5c31beaf8b7" member_type: VOTER }
I20260812 06:18:43.773809 27702 raft_consensus.cc:385] T 00000000000000000000000000000000 P e655b330ad964b9b9770c5c31beaf8b7 [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:18:43.773831 27702 raft_consensus.cc:740] T 00000000000000000000000000000000 P e655b330ad964b9b9770c5c31beaf8b7 [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: e655b330ad964b9b9770c5c31beaf8b7, State: Initialized, Role: FOLLOWER
I20260812 06:18:43.773975 27702 consensus_queue.cc:260] T 00000000000000000000000000000000 P e655b330ad964b9b9770c5c31beaf8b7 [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: "e655b330ad964b9b9770c5c31beaf8b7" member_type: VOTER }
I20260812 06:18:43.774067 27702 raft_consensus.cc:399] T 00000000000000000000000000000000 P e655b330ad964b9b9770c5c31beaf8b7 [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:18:43.774093 27702 raft_consensus.cc:493] T 00000000000000000000000000000000 P e655b330ad964b9b9770c5c31beaf8b7 [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:18:43.774123 27702 raft_consensus.cc:3060] T 00000000000000000000000000000000 P e655b330ad964b9b9770c5c31beaf8b7 [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:18:43.774763 27702 raft_consensus.cc:515] T 00000000000000000000000000000000 P e655b330ad964b9b9770c5c31beaf8b7 [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "e655b330ad964b9b9770c5c31beaf8b7" member_type: VOTER }
I20260812 06:18:43.774876 27702 leader_election.cc:304] T 00000000000000000000000000000000 P e655b330ad964b9b9770c5c31beaf8b7 [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: e655b330ad964b9b9770c5c31beaf8b7; no voters: 
I20260812 06:18:43.775012 27702 leader_election.cc:290] T 00000000000000000000000000000000 P e655b330ad964b9b9770c5c31beaf8b7 [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:18:43.775184 27706 raft_consensus.cc:2804] T 00000000000000000000000000000000 P e655b330ad964b9b9770c5c31beaf8b7 [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:18:43.775372 27706 raft_consensus.cc:697] T 00000000000000000000000000000000 P e655b330ad964b9b9770c5c31beaf8b7 [term 1 LEADER]: Becoming Leader. State: Replica: e655b330ad964b9b9770c5c31beaf8b7, State: Running, Role: LEADER
I20260812 06:18:43.775524 27706 consensus_queue.cc:237] T 00000000000000000000000000000000 P e655b330ad964b9b9770c5c31beaf8b7 [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: "e655b330ad964b9b9770c5c31beaf8b7" member_type: VOTER }
I20260812 06:18:43.775533 27702 sys_catalog.cc:565] T 00000000000000000000000000000000 P e655b330ad964b9b9770c5c31beaf8b7 [sys.catalog]: configured and running, proceeding with master startup.
I20260812 06:18:43.776054 27708 sys_catalog.cc:455] T 00000000000000000000000000000000 P e655b330ad964b9b9770c5c31beaf8b7 [sys.catalog]: SysCatalogTable state changed. Reason: New leader e655b330ad964b9b9770c5c31beaf8b7. Latest consensus state: current_term: 1 leader_uuid: "e655b330ad964b9b9770c5c31beaf8b7" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "e655b330ad964b9b9770c5c31beaf8b7" member_type: VOTER } }
I20260812 06:18:43.776041 27707 sys_catalog.cc:455] T 00000000000000000000000000000000 P e655b330ad964b9b9770c5c31beaf8b7 [sys.catalog]: SysCatalogTable state changed. Reason: RaftConsensus started. Latest consensus state: current_term: 1 leader_uuid: "e655b330ad964b9b9770c5c31beaf8b7" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "e655b330ad964b9b9770c5c31beaf8b7" member_type: VOTER } }
I20260812 06:18:43.776152 27708 sys_catalog.cc:458] T 00000000000000000000000000000000 P e655b330ad964b9b9770c5c31beaf8b7 [sys.catalog]: This master's current role is: LEADER
I20260812 06:18:43.776162 27707 sys_catalog.cc:458] T 00000000000000000000000000000000 P e655b330ad964b9b9770c5c31beaf8b7 [sys.catalog]: This master's current role is: LEADER
I20260812 06:18:43.776472 27710 catalog_manager.cc:1511] Loading table and tablet metadata into memory...
I20260812 06:18:43.777325 27710 catalog_manager.cc:1520] Initializing Kudu cluster ID...
I20260812 06:18:43.777719 27409 internal_mini_cluster.cc:184] Waiting to initialize catalog manager on master 0
I20260812 06:18:43.779177 27710 catalog_manager.cc:1383] Generated new cluster ID: 10bfac05049c4ebbb71bdd037f358204
I20260812 06:18:43.779271 27710 catalog_manager.cc:1531] Initializing Kudu internal certificate authority...
I20260812 06:18:43.792743 27710 catalog_manager.cc:1406] Generated new certificate authority record
I20260812 06:18:43.793413 27710 catalog_manager.cc:1540] Loading token signing keys...
I20260812 06:18:43.803474 27710 catalog_manager.cc:6092] T 00000000000000000000000000000000 P e655b330ad964b9b9770c5c31beaf8b7: Generated new TSK 0
I20260812 06:18:43.803709 27710 catalog_manager.cc:1550] Initializing in-progress tserver states...
I20260812 06:18:43.810228 27409 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:18:43.812590 27725 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:43.812662 27728 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:43.812610 27726 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:43.812747 27409 server_base.cc:1061] running on GCE node
I20260812 06:18:43.813050 27409 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:18:43.813095 27409 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:43.813112 27409 hybrid_clock.cc:648] HybridClock initialized: now 1786515523813111 us; error 0 us; skew 500 ppm
I20260812 06:18:43.814072 27409 webserver.cc:533] Webserver started at http://127.26.196.65:36365/ using document root <none> and password file <none>
I20260812 06:18:43.814255 27409 fs_manager.cc:362] Metadata directory not provided
I20260812 06:18:43.814322 27409 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:18:43.814414 27409 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:18:43.814831 27409 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-task_caSEa/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515518284916-27409-0/minicluster-data/ts-0-root/instance:
uuid: "919859f35e944a1e878347bb5e8c845b"
format_stamp: "Formatted at 2026-08-12 06:18:43 on dist-test-slave-mvvj"
I20260812 06:18:43.816449 27409 fs_manager.cc:696] Time spent creating directory manager: real 0.001s	user 0.000s	sys 0.002s
I20260812 06:18:43.817480 27734 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:43.817793 27409 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.000s	sys 0.001s
I20260812 06:18:43.817901 27409 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-task_caSEa/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515518284916-27409-0/minicluster-data/ts-0-root
uuid: "919859f35e944a1e878347bb5e8c845b"
format_stamp: "Formatted at 2026-08-12 06:18:43 on dist-test-slave-mvvj"
I20260812 06:18:43.817994 27409 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-task_caSEa/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515518284916-27409-0/minicluster-data/ts-0-root
metadata directory: /tmp/dist-test-task_caSEa/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515518284916-27409-0/minicluster-data/ts-0-root
1 data directories: /tmp/dist-test-task_caSEa/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515518284916-27409-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:43.835711 27409 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:18:43.836213 27409 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:18:43.836578 27409 txn_system_client.cc:432] TxnSystemClient initialization is disabled...
I20260812 06:18:43.837083 27409 ts_tablet_manager.cc:585] Loaded tablet metadata (0 total tablets, 0 live tablets)
I20260812 06:18:43.837148 27409 ts_tablet_manager.cc:531] Time spent load tablet metadata: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:18:43.837209 27409 ts_tablet_manager.cc:616] Registered 0 tablets
I20260812 06:18:43.837261 27409 ts_tablet_manager.cc:595] Time spent register tablets: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:18:43.842234 27409 rpc_server.cc:307] RPC server started. Bound to: 127.26.196.65:41803
I20260812 06:18:43.842276 27805 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.26.196.65:41803 every 8 connection(s)
I20260812 06:18:43.851310 27807 heartbeater.cc:344] Connected to a master server at 127.26.196.126:38455
I20260812 06:18:43.851480 27807 heartbeater.cc:461] Registering TS with master...
I20260812 06:18:43.851766 27807 heartbeater.cc:507] Master 127.26.196.126:38455 requested a full tablet report, sending...
I20260812 06:18:43.852490 27661 ts_manager.cc:194] Registered new tserver with Master: 919859f35e944a1e878347bb5e8c845b (127.26.196.65:41803)
I20260812 06:18:43.852878 27409 internal_mini_cluster.cc:371] 1 TS(s) registered with all masters after 0.010155419s
I20260812 06:18:43.853300 27661 master_service.cc:502] Signed X509 certificate for tserver {username='slave'} at 127.0.0.1:55610
I20260812 06:18:43.860634 27661 catalog_manager.cc:2283] Servicing CreateTable request from {username='slave'} at 127.0.0.1:55616:
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:43.869837 27765 tablet_service.cc:1511] Processing CreateTablet for tablet cd8aa1eab95f453b8f9b333d81cbafb9 (DEFAULT_TABLE table=heavy-update-compaction-test [id=e46d6c9ced5a4af08308443badac0fb1]), partition=
I20260812 06:18:43.870152 27765 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet cd8aa1eab95f453b8f9b333d81cbafb9. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:18:43.872175 27819 tablet_bootstrap.cc:492] T cd8aa1eab95f453b8f9b333d81cbafb9 P 919859f35e944a1e878347bb5e8c845b: Bootstrap starting.
I20260812 06:18:43.872998 27819 tablet_bootstrap.cc:654] T cd8aa1eab95f453b8f9b333d81cbafb9 P 919859f35e944a1e878347bb5e8c845b: Neither blocks nor log segments found. Creating new log.
I20260812 06:18:43.873958 27819 tablet_bootstrap.cc:492] T cd8aa1eab95f453b8f9b333d81cbafb9 P 919859f35e944a1e878347bb5e8c845b: No bootstrap required, opened a new log
I20260812 06:18:43.874032 27819 ts_tablet_manager.cc:1403] T cd8aa1eab95f453b8f9b333d81cbafb9 P 919859f35e944a1e878347bb5e8c845b: Time spent bootstrapping tablet: real 0.002s	user 0.001s	sys 0.000s
I20260812 06:18:43.874361 27819 raft_consensus.cc:359] T cd8aa1eab95f453b8f9b333d81cbafb9 P 919859f35e944a1e878347bb5e8c845b [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "919859f35e944a1e878347bb5e8c845b" member_type: VOTER last_known_addr { host: "127.26.196.65" port: 41803 } }
I20260812 06:18:43.874465 27819 raft_consensus.cc:385] T cd8aa1eab95f453b8f9b333d81cbafb9 P 919859f35e944a1e878347bb5e8c845b [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:18:43.874492 27819 raft_consensus.cc:740] T cd8aa1eab95f453b8f9b333d81cbafb9 P 919859f35e944a1e878347bb5e8c845b [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: 919859f35e944a1e878347bb5e8c845b, State: Initialized, Role: FOLLOWER
I20260812 06:18:43.874630 27819 consensus_queue.cc:260] T cd8aa1eab95f453b8f9b333d81cbafb9 P 919859f35e944a1e878347bb5e8c845b [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: "919859f35e944a1e878347bb5e8c845b" member_type: VOTER last_known_addr { host: "127.26.196.65" port: 41803 } }
I20260812 06:18:43.874737 27819 raft_consensus.cc:399] T cd8aa1eab95f453b8f9b333d81cbafb9 P 919859f35e944a1e878347bb5e8c845b [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:18:43.874783 27819 raft_consensus.cc:493] T cd8aa1eab95f453b8f9b333d81cbafb9 P 919859f35e944a1e878347bb5e8c845b [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:18:43.874841 27819 raft_consensus.cc:3060] T cd8aa1eab95f453b8f9b333d81cbafb9 P 919859f35e944a1e878347bb5e8c845b [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:18:43.875664 27819 raft_consensus.cc:515] T cd8aa1eab95f453b8f9b333d81cbafb9 P 919859f35e944a1e878347bb5e8c845b [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "919859f35e944a1e878347bb5e8c845b" member_type: VOTER last_known_addr { host: "127.26.196.65" port: 41803 } }
I20260812 06:18:43.875780 27819 leader_election.cc:304] T cd8aa1eab95f453b8f9b333d81cbafb9 P 919859f35e944a1e878347bb5e8c845b [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: 919859f35e944a1e878347bb5e8c845b; no voters: 
I20260812 06:18:43.876001 27819 leader_election.cc:290] T cd8aa1eab95f453b8f9b333d81cbafb9 P 919859f35e944a1e878347bb5e8c845b [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:18:43.876142 27821 raft_consensus.cc:2804] T cd8aa1eab95f453b8f9b333d81cbafb9 P 919859f35e944a1e878347bb5e8c845b [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:18:43.876310 27807 heartbeater.cc:499] Master 127.26.196.126:38455 was elected leader, sending a full tablet report...
I20260812 06:18:43.876327 27819 ts_tablet_manager.cc:1434] T cd8aa1eab95f453b8f9b333d81cbafb9 P 919859f35e944a1e878347bb5e8c845b: Time spent starting tablet: real 0.002s	user 0.003s	sys 0.000s
I20260812 06:18:43.876677 27821 raft_consensus.cc:697] T cd8aa1eab95f453b8f9b333d81cbafb9 P 919859f35e944a1e878347bb5e8c845b [term 1 LEADER]: Becoming Leader. State: Replica: 919859f35e944a1e878347bb5e8c845b, State: Running, Role: LEADER
I20260812 06:18:43.876856 27821 consensus_queue.cc:237] T cd8aa1eab95f453b8f9b333d81cbafb9 P 919859f35e944a1e878347bb5e8c845b [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: "919859f35e944a1e878347bb5e8c845b" member_type: VOTER last_known_addr { host: "127.26.196.65" port: 41803 } }
I20260812 06:18:43.878139 27661 catalog_manager.cc:5719] T cd8aa1eab95f453b8f9b333d81cbafb9 P 919859f35e944a1e878347bb5e8c845b reported cstate change: term changed from 0 to 1, leader changed from <none> to 919859f35e944a1e878347bb5e8c845b (127.26.196.65). New cstate: current_term: 1 leader_uuid: "919859f35e944a1e878347bb5e8c845b" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "919859f35e944a1e878347bb5e8c845b" member_type: VOTER last_known_addr { host: "127.26.196.65" port: 41803 } health_report { overall_health: HEALTHY } } }
I20260812 06:18:43.938634 27409 heavy-update-compaction-itest.cc:215] Time spent inserting: real 0.053s	user 0.015s	sys 0.008s
I20260812 06:18:44.093554 27808 maintenance_manager.cc:419] P 919859f35e944a1e878347bb5e8c845b: Scheduling FlushMRSOp(cd8aa1eab95f453b8f9b333d81cbafb9): perf score=19.054940
I20260812 06:18:44.265507 27740 maintenance_manager.cc:643] P 919859f35e944a1e878347bb5e8c845b: FlushMRSOp(cd8aa1eab95f453b8f9b333d81cbafb9) complete. Timing: real 0.172s	user 0.130s	sys 0.039s Metrics: {"bytes_written":13168992,"cfile_init":1,"delete_count":0,"dirs.queue_time_us":77,"dirs.run_cpu_time_us":237,"dirs.run_wall_time_us":1107,"drs_written":1,"lbm_read_time_us":51,"lbm_reads_lt_1ms":4,"lbm_write_time_us":41849,"lbm_writes_lt_1ms":778,"peak_mem_usage":0,"reinsert_count":0,"rows_written":104,"spinlock_wait_cycles":768,"update_count":1605}
I20260812 06:18:44.266368 27808 maintenance_manager.cc:419] P 919859f35e944a1e878347bb5e8c845b: Scheduling LogGCOp(cd8aa1eab95f453b8f9b333d81cbafb9): free 20743880 bytes of WAL
I20260812 06:18:44.266628 27740 log_reader.cc:385] T cd8aa1eab95f453b8f9b333d81cbafb9: removed 2 log segments from log reader
I20260812 06:18:44.266698 27740 log.cc:1079] T cd8aa1eab95f453b8f9b333d81cbafb9 P 919859f35e944a1e878347bb5e8c845b: Deleting log segment in path: /tmp/dist-test-task_caSEa/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515518284916-27409-0/minicluster-data/ts-0-root/wals/cd8aa1eab95f453b8f9b333d81cbafb9/wal-000000001 (ops 1-6)
I20260812 06:18:44.266749 27740 log.cc:1079] T cd8aa1eab95f453b8f9b333d81cbafb9 P 919859f35e944a1e878347bb5e8c845b: Deleting log segment in path: /tmp/dist-test-task_caSEa/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515518284916-27409-0/minicluster-data/ts-0-root/wals/cd8aa1eab95f453b8f9b333d81cbafb9/wal-000000002 (ops 7-11)
I20260812 06:18:44.272018 27740 maintenance_manager.cc:643] P 919859f35e944a1e878347bb5e8c845b: LogGCOp(cd8aa1eab95f453b8f9b333d81cbafb9) complete. Timing: real 0.005s	user 0.000s	sys 0.005s Metrics: {}
I20260812 06:18:44.272552 27808 maintenance_manager.cc:419] P 919859f35e944a1e878347bb5e8c845b: Scheduling FlushDeltaMemStoresOp(cd8aa1eab95f453b8f9b333d81cbafb9): perf score=2.188937
I20260812 06:18:44.290333 27740 maintenance_manager.cc:643] P 919859f35e944a1e878347bb5e8c845b: FlushDeltaMemStoresOp(cd8aa1eab95f453b8f9b333d81cbafb9) complete. Timing: real 0.018s	user 0.008s	sys 0.006s Metrics: {"bytes_written":4020613,"delete_count":0,"lbm_write_time_us":6233,"lbm_writes_lt_1ms":101,"reinsert_count":0,"update_count":490}
I20260812 06:18:44.296120 27808 maintenance_manager.cc:419] P 919859f35e944a1e878347bb5e8c845b: Scheduling UndoDeltaBlockGCOp(cd8aa1eab95f453b8f9b333d81cbafb9): 16411395 bytes on disk
I20260812 06:18:44.296715 27740 maintenance_manager.cc:643] P 919859f35e944a1e878347bb5e8c845b: UndoDeltaBlockGCOp(cd8aa1eab95f453b8f9b333d81cbafb9) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":95,"lbm_reads_lt_1ms":4}
I20260812 06:18:44.297196 27808 maintenance_manager.cc:419] P 919859f35e944a1e878347bb5e8c845b: Scheduling FlushDeltaMemStoresOp(cd8aa1eab95f453b8f9b333d81cbafb9): perf score=2.188937
I20260812 06:18:44.313794 27740 maintenance_manager.cc:643] P 919859f35e944a1e878347bb5e8c845b: FlushDeltaMemStoresOp(cd8aa1eab95f453b8f9b333d81cbafb9) complete. Timing: real 0.016s	user 0.006s	sys 0.008s Metrics: {"bytes_written":3323180,"delete_count":0,"lbm_write_time_us":5801,"lbm_writes_lt_1ms":84,"reinsert_count":0,"update_count":405}
I20260812 06:18:44.314397 27808 maintenance_manager.cc:419] P 919859f35e944a1e878347bb5e8c845b: Scheduling MajorDeltaCompactionOp(cd8aa1eab95f453b8f9b333d81cbafb9): perf score=1.000000
I20260812 06:18:44.499819 27740 maintenance_manager.cc:643] P 919859f35e944a1e878347bb5e8c845b: MajorDeltaCompactionOp(cd8aa1eab95f453b8f9b333d81cbafb9) complete. Timing: real 0.185s	user 0.161s	sys 0.024s Metrics: {"cfile_cache_miss":533,"cfile_cache_miss_bytes":24774785,"cfile_init":7,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":54,"lbm_read_time_us":13828,"lbm_reads_lt_1ms":561,"lbm_write_time_us":28061,"lbm_writes_lt_1ms":543,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":2688,"thread_start_us":321,"threads_started":5,"update_count":2500}
I20260812 06:18:44.500422 27808 maintenance_manager.cc:419] P 919859f35e944a1e878347bb5e8c845b: Scheduling FlushDeltaMemStoresOp(cd8aa1eab95f453b8f9b333d81cbafb9): perf score=14.095187
I20260812 06:18:44.565522 27740 maintenance_manager.cc:643] P 919859f35e944a1e878347bb5e8c845b: FlushDeltaMemStoresOp(cd8aa1eab95f453b8f9b333d81cbafb9) complete. Timing: real 0.065s	user 0.038s	sys 0.023s Metrics: {"bytes_written":16409919,"delete_count":0,"lbm_write_time_us":30002,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":402,"reinsert_count":0,"update_count":2000}
I20260812 06:18:44.566236 27808 maintenance_manager.cc:419] P 919859f35e944a1e878347bb5e8c845b: Scheduling FlushDeltaMemStoresOp(cd8aa1eab95f453b8f9b333d81cbafb9): perf score=2.188937
I20260812 06:18:44.585359 27740 maintenance_manager.cc:643] P 919859f35e944a1e878347bb5e8c845b: FlushDeltaMemStoresOp(cd8aa1eab95f453b8f9b333d81cbafb9) complete. Timing: real 0.019s	user 0.009s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":7455,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:44.586041 27808 maintenance_manager.cc:419] P 919859f35e944a1e878347bb5e8c845b: Scheduling MajorDeltaCompactionOp(cd8aa1eab95f453b8f9b333d81cbafb9): perf score=1.000000
I20260812 06:18:44.773618 27740 maintenance_manager.cc:643] P 919859f35e944a1e878347bb5e8c845b: MajorDeltaCompactionOp(cd8aa1eab95f453b8f9b333d81cbafb9) complete. Timing: real 0.187s	user 0.112s	sys 0.070s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774706,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":857,"lbm_read_time_us":14572,"lbm_reads_lt_1ms":564,"lbm_write_time_us":28160,"lbm_writes_lt_1ms":543,"peak_mem_usage":63115900,"reinsert_count":0,"update_count":2500}
I20260812 06:18:44.774098 27808 maintenance_manager.cc:419] P 919859f35e944a1e878347bb5e8c845b: Scheduling FlushDeltaMemStoresOp(cd8aa1eab95f453b8f9b333d81cbafb9): perf score=14.095187
I20260812 06:18:44.826699 27740 maintenance_manager.cc:643] P 919859f35e944a1e878347bb5e8c845b: FlushDeltaMemStoresOp(cd8aa1eab95f453b8f9b333d81cbafb9) complete. Timing: real 0.052s	user 0.029s	sys 0.017s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":21590,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:18:44.827203 27808 maintenance_manager.cc:419] P 919859f35e944a1e878347bb5e8c845b: Scheduling FlushDeltaMemStoresOp(cd8aa1eab95f453b8f9b333d81cbafb9): perf score=2.188937
I20260812 06:18:44.839201 27740 maintenance_manager.cc:643] P 919859f35e944a1e878347bb5e8c845b: FlushDeltaMemStoresOp(cd8aa1eab95f453b8f9b333d81cbafb9) complete. Timing: real 0.012s	user 0.006s	sys 0.003s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4476,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:44.839987 27808 maintenance_manager.cc:419] P 919859f35e944a1e878347bb5e8c845b: Scheduling MajorDeltaCompactionOp(cd8aa1eab95f453b8f9b333d81cbafb9): perf score=1.000000
I20260812 06:18:45.033922 27740 maintenance_manager.cc:643] P 919859f35e944a1e878347bb5e8c845b: MajorDeltaCompactionOp(cd8aa1eab95f453b8f9b333d81cbafb9) complete. Timing: real 0.194s	user 0.107s	sys 0.070s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774688,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":496,"lbm_read_time_us":10149,"lbm_reads_lt_1ms":572,"lbm_write_time_us":30309,"lbm_writes_lt_1ms":543,"mutex_wait_us":48,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":11648,"update_count":2500}
I20260812 06:18:45.035467 27808 maintenance_manager.cc:419] P 919859f35e944a1e878347bb5e8c845b: Scheduling FlushDeltaMemStoresOp(cd8aa1eab95f453b8f9b333d81cbafb9): perf score=14.095187
I20260812 06:18:45.084738 27740 maintenance_manager.cc:643] P 919859f35e944a1e878347bb5e8c845b: FlushDeltaMemStoresOp(cd8aa1eab95f453b8f9b333d81cbafb9) complete. Timing: real 0.049s	user 0.033s	sys 0.015s Metrics: {"bytes_written":16409903,"delete_count":0,"lbm_write_time_us":21040,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:18:45.085412 27808 maintenance_manager.cc:419] P 919859f35e944a1e878347bb5e8c845b: Scheduling FlushDeltaMemStoresOp(cd8aa1eab95f453b8f9b333d81cbafb9): perf score=2.188937
I20260812 06:18:45.097893 27740 maintenance_manager.cc:643] P 919859f35e944a1e878347bb5e8c845b: FlushDeltaMemStoresOp(cd8aa1eab95f453b8f9b333d81cbafb9) complete. Timing: real 0.012s	user 0.010s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4259,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:45.098592 27808 maintenance_manager.cc:419] P 919859f35e944a1e878347bb5e8c845b: Scheduling MajorDeltaCompactionOp(cd8aa1eab95f453b8f9b333d81cbafb9): perf score=1.000000
I20260812 06:18:45.252126 27740 maintenance_manager.cc:643] P 919859f35e944a1e878347bb5e8c845b: MajorDeltaCompactionOp(cd8aa1eab95f453b8f9b333d81cbafb9) complete. Timing: real 0.153s	user 0.113s	sys 0.036s 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":463,"lbm_read_time_us":11679,"lbm_reads_lt_1ms":572,"lbm_write_time_us":29272,"lbm_writes_lt_1ms":543,"mutex_wait_us":75,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":23936,"update_count":2500}
I20260812 06:18:45.252897 27808 maintenance_manager.cc:419] P 919859f35e944a1e878347bb5e8c845b: Scheduling FlushDeltaMemStoresOp(cd8aa1eab95f453b8f9b333d81cbafb9): perf score=11.118625
I20260812 06:18:45.296239 27740 maintenance_manager.cc:643] P 919859f35e944a1e878347bb5e8c845b: FlushDeltaMemStoresOp(cd8aa1eab95f453b8f9b333d81cbafb9) complete. Timing: real 0.043s	user 0.030s	sys 0.013s Metrics: {"bytes_written":12717736,"delete_count":0,"lbm_write_time_us":19264,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":312,"reinsert_count":0,"update_count":1550}
I20260812 06:18:45.296948 27808 maintenance_manager.cc:419] P 919859f35e944a1e878347bb5e8c845b: Scheduling FlushDeltaMemStoresOp(cd8aa1eab95f453b8f9b333d81cbafb9): perf score=2.188937
I20260812 06:18:45.319802 27740 maintenance_manager.cc:643] P 919859f35e944a1e878347bb5e8c845b: FlushDeltaMemStoresOp(cd8aa1eab95f453b8f9b333d81cbafb9) complete. Timing: real 0.023s	user 0.013s	sys 0.000s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":5608,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:18:45.320504 27808 maintenance_manager.cc:419] P 919859f35e944a1e878347bb5e8c845b: Scheduling FlushDeltaMemStoresOp(cd8aa1eab95f453b8f9b333d81cbafb9): perf score=2.188937
I20260812 06:18:45.334626 27740 maintenance_manager.cc:643] P 919859f35e944a1e878347bb5e8c845b: FlushDeltaMemStoresOp(cd8aa1eab95f453b8f9b333d81cbafb9) complete. Timing: real 0.014s	user 0.012s	sys 0.000s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":5508,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:45.335114 27808 maintenance_manager.cc:419] P 919859f35e944a1e878347bb5e8c845b: Scheduling MajorDeltaCompactionOp(cd8aa1eab95f453b8f9b333d81cbafb9): perf score=1.000000
I20260812 06:18:45.487063 27740 maintenance_manager.cc:643] P 919859f35e944a1e878347bb5e8c845b: MajorDeltaCompactionOp(cd8aa1eab95f453b8f9b333d81cbafb9) complete. Timing: real 0.152s	user 0.124s	sys 0.028s 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":359,"lbm_read_time_us":11097,"lbm_reads_lt_1ms":573,"lbm_write_time_us":29427,"lbm_writes_lt_1ms":543,"mutex_wait_us":74,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":3200,"update_count":2500}
I20260812 06:18:45.487675 27808 maintenance_manager.cc:419] P 919859f35e944a1e878347bb5e8c845b: Scheduling FlushDeltaMemStoresOp(cd8aa1eab95f453b8f9b333d81cbafb9): perf score=10.126437
I20260812 06:18:45.524633 27740 maintenance_manager.cc:643] P 919859f35e944a1e878347bb5e8c845b: FlushDeltaMemStoresOp(cd8aa1eab95f453b8f9b333d81cbafb9) complete. Timing: real 0.037s	user 0.023s	sys 0.009s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":14328,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:18:45.525168 27808 maintenance_manager.cc:419] P 919859f35e944a1e878347bb5e8c845b: Scheduling FlushDeltaMemStoresOp(cd8aa1eab95f453b8f9b333d81cbafb9): perf score=2.188937
I20260812 06:18:45.536512 27740 maintenance_manager.cc:643] P 919859f35e944a1e878347bb5e8c845b: FlushDeltaMemStoresOp(cd8aa1eab95f453b8f9b333d81cbafb9) complete. Timing: real 0.011s	user 0.006s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4481,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:45.537039 27808 maintenance_manager.cc:419] P 919859f35e944a1e878347bb5e8c845b: Scheduling FlushMRSOp(cd8aa1eab95f453b8f9b333d81cbafb9): perf score=1.000000
I20260812 06:18:45.570046 27740 maintenance_manager.cc:643] P 919859f35e944a1e878347bb5e8c845b: FlushMRSOp(cd8aa1eab95f453b8f9b333d81cbafb9) complete. Timing: real 0.033s	user 0.031s	sys 0.000s Metrics: {"bytes_written":1193503,"cfile_init":1,"dirs.queue_time_us":77,"dirs.run_cpu_time_us":210,"dirs.run_wall_time_us":1622,"drs_written":1,"lbm_read_time_us":65,"lbm_reads_lt_1ms":4,"lbm_write_time_us":2058,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":29}
I20260812 06:18:45.570654 27808 maintenance_manager.cc:419] P 919859f35e944a1e878347bb5e8c845b: Scheduling LogGCOp(cd8aa1eab95f453b8f9b333d81cbafb9): free 120553388 bytes of WAL
I20260812 06:18:45.570894 27740 log_reader.cc:385] T cd8aa1eab95f453b8f9b333d81cbafb9: removed 12 log segments from log reader
I20260812 06:18:45.570940 27740 log.cc:1079] T cd8aa1eab95f453b8f9b333d81cbafb9 P 919859f35e944a1e878347bb5e8c845b: Deleting log segment in path: /tmp/dist-test-task_caSEa/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515518284916-27409-0/minicluster-data/ts-0-root/wals/cd8aa1eab95f453b8f9b333d81cbafb9/wal-000000003 (ops 12-16)
I20260812 06:18:45.570994 27740 log.cc:1079] T cd8aa1eab95f453b8f9b333d81cbafb9 P 919859f35e944a1e878347bb5e8c845b: Deleting log segment in path: /tmp/dist-test-task_caSEa/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515518284916-27409-0/minicluster-data/ts-0-root/wals/cd8aa1eab95f453b8f9b333d81cbafb9/wal-000000004 (ops 17-21)
I20260812 06:18:45.571041 27740 log.cc:1079] T cd8aa1eab95f453b8f9b333d81cbafb9 P 919859f35e944a1e878347bb5e8c845b: Deleting log segment in path: /tmp/dist-test-task_caSEa/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515518284916-27409-0/minicluster-data/ts-0-root/wals/cd8aa1eab95f453b8f9b333d81cbafb9/wal-000000005 (ops 22-26)
I20260812 06:18:45.571085 27740 log.cc:1079] T cd8aa1eab95f453b8f9b333d81cbafb9 P 919859f35e944a1e878347bb5e8c845b: Deleting log segment in path: /tmp/dist-test-task_caSEa/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515518284916-27409-0/minicluster-data/ts-0-root/wals/cd8aa1eab95f453b8f9b333d81cbafb9/wal-000000006 (ops 27-30)
I20260812 06:18:45.571128 27740 log.cc:1079] T cd8aa1eab95f453b8f9b333d81cbafb9 P 919859f35e944a1e878347bb5e8c845b: Deleting log segment in path: /tmp/dist-test-task_caSEa/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515518284916-27409-0/minicluster-data/ts-0-root/wals/cd8aa1eab95f453b8f9b333d81cbafb9/wal-000000007 (ops 31-35)
I20260812 06:18:45.571180 27740 log.cc:1079] T cd8aa1eab95f453b8f9b333d81cbafb9 P 919859f35e944a1e878347bb5e8c845b: Deleting log segment in path: /tmp/dist-test-task_caSEa/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515518284916-27409-0/minicluster-data/ts-0-root/wals/cd8aa1eab95f453b8f9b333d81cbafb9/wal-000000008 (ops 36-40)
I20260812 06:18:45.571220 27740 log.cc:1079] T cd8aa1eab95f453b8f9b333d81cbafb9 P 919859f35e944a1e878347bb5e8c845b: Deleting log segment in path: /tmp/dist-test-task_caSEa/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515518284916-27409-0/minicluster-data/ts-0-root/wals/cd8aa1eab95f453b8f9b333d81cbafb9/wal-000000009 (ops 41-45)
I20260812 06:18:45.571260 27740 log.cc:1079] T cd8aa1eab95f453b8f9b333d81cbafb9 P 919859f35e944a1e878347bb5e8c845b: Deleting log segment in path: /tmp/dist-test-task_caSEa/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515518284916-27409-0/minicluster-data/ts-0-root/wals/cd8aa1eab95f453b8f9b333d81cbafb9/wal-000000010 (ops 46-50)
I20260812 06:18:45.571308 27740 log.cc:1079] T cd8aa1eab95f453b8f9b333d81cbafb9 P 919859f35e944a1e878347bb5e8c845b: Deleting log segment in path: /tmp/dist-test-task_caSEa/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515518284916-27409-0/minicluster-data/ts-0-root/wals/cd8aa1eab95f453b8f9b333d81cbafb9/wal-000000011 (ops 51-54)
I20260812 06:18:45.571348 27740 log.cc:1079] T cd8aa1eab95f453b8f9b333d81cbafb9 P 919859f35e944a1e878347bb5e8c845b: Deleting log segment in path: /tmp/dist-test-task_caSEa/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515518284916-27409-0/minicluster-data/ts-0-root/wals/cd8aa1eab95f453b8f9b333d81cbafb9/wal-000000012 (ops 55-59)
I20260812 06:18:45.571388 27740 log.cc:1079] T cd8aa1eab95f453b8f9b333d81cbafb9 P 919859f35e944a1e878347bb5e8c845b: Deleting log segment in path: /tmp/dist-test-task_caSEa/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515518284916-27409-0/minicluster-data/ts-0-root/wals/cd8aa1eab95f453b8f9b333d81cbafb9/wal-000000013 (ops 60-64)
I20260812 06:18:45.571429 27740 log.cc:1079] T cd8aa1eab95f453b8f9b333d81cbafb9 P 919859f35e944a1e878347bb5e8c845b: Deleting log segment in path: /tmp/dist-test-task_caSEa/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515518284916-27409-0/minicluster-data/ts-0-root/wals/cd8aa1eab95f453b8f9b333d81cbafb9/wal-000000014 (ops 65-69)
I20260812 06:18:45.597398 27740 maintenance_manager.cc:643] P 919859f35e944a1e878347bb5e8c845b: LogGCOp(cd8aa1eab95f453b8f9b333d81cbafb9) complete. Timing: real 0.027s	user 0.002s	sys 0.023s Metrics: {}
I20260812 06:18:45.597815 27808 maintenance_manager.cc:419] P 919859f35e944a1e878347bb5e8c845b: Scheduling FlushDeltaMemStoresOp(cd8aa1eab95f453b8f9b333d81cbafb9): perf score=2.188937
I20260812 06:18:45.612258 27740 maintenance_manager.cc:643] P 919859f35e944a1e878347bb5e8c845b: FlushDeltaMemStoresOp(cd8aa1eab95f453b8f9b333d81cbafb9) complete. Timing: real 0.014s	user 0.006s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4035,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:45.612699 27808 maintenance_manager.cc:419] P 919859f35e944a1e878347bb5e8c845b: Scheduling UndoDeltaBlockGCOp(cd8aa1eab95f453b8f9b333d81cbafb9): 462 bytes on disk
I20260812 06:18:45.613106 27740 maintenance_manager.cc:643] P 919859f35e944a1e878347bb5e8c845b: UndoDeltaBlockGCOp(cd8aa1eab95f453b8f9b333d81cbafb9) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":55,"lbm_reads_lt_1ms":4}
I20260812 06:18:45.613518 27808 maintenance_manager.cc:419] P 919859f35e944a1e878347bb5e8c845b: Scheduling FlushDeltaMemStoresOp(cd8aa1eab95f453b8f9b333d81cbafb9): perf score=2.188937
I20260812 06:18:45.624459 27740 maintenance_manager.cc:643] P 919859f35e944a1e878347bb5e8c845b: FlushDeltaMemStoresOp(cd8aa1eab95f453b8f9b333d81cbafb9) complete. Timing: real 0.011s	user 0.006s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4082,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:45.625017 27808 maintenance_manager.cc:419] P 919859f35e944a1e878347bb5e8c845b: Scheduling MajorDeltaCompactionOp(cd8aa1eab95f453b8f9b333d81cbafb9): perf score=1.000000
I20260812 06:18:45.820997 27740 maintenance_manager.cc:643] P 919859f35e944a1e878347bb5e8c845b: MajorDeltaCompactionOp(cd8aa1eab95f453b8f9b333d81cbafb9) complete. Timing: real 0.196s	user 0.143s	sys 0.047s Metrics: {"cfile_cache_miss":634,"cfile_cache_miss_bytes":28877339,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":585,"lbm_read_time_us":13236,"lbm_reads_lt_1ms":674,"lbm_write_time_us":40236,"lbm_writes_lt_1ms":643,"mutex_wait_us":59,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":40320,"thread_start_us":87,"threads_started":1,"update_count":3000}
I20260812 06:18:45.821779 27808 maintenance_manager.cc:419] P 919859f35e944a1e878347bb5e8c845b: Scheduling FlushDeltaMemStoresOp(cd8aa1eab95f453b8f9b333d81cbafb9): perf score=14.095187
I20260812 06:18:45.873975 27740 maintenance_manager.cc:643] P 919859f35e944a1e878347bb5e8c845b: FlushDeltaMemStoresOp(cd8aa1eab95f453b8f9b333d81cbafb9) complete. Timing: real 0.052s	user 0.034s	sys 0.012s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":21211,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:18:45.874476 27808 maintenance_manager.cc:419] P 919859f35e944a1e878347bb5e8c845b: Scheduling FlushDeltaMemStoresOp(cd8aa1eab95f453b8f9b333d81cbafb9): perf score=2.188937
I20260812 06:18:45.886675 27740 maintenance_manager.cc:643] P 919859f35e944a1e878347bb5e8c845b: FlushDeltaMemStoresOp(cd8aa1eab95f453b8f9b333d81cbafb9) complete. Timing: real 0.012s	user 0.005s	sys 0.004s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4267,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:45.887276 27808 maintenance_manager.cc:419] P 919859f35e944a1e878347bb5e8c845b: Scheduling MajorDeltaCompactionOp(cd8aa1eab95f453b8f9b333d81cbafb9): perf score=1.000000
I20260812 06:18:46.043980 27740 maintenance_manager.cc:643] P 919859f35e944a1e878347bb5e8c845b: MajorDeltaCompactionOp(cd8aa1eab95f453b8f9b333d81cbafb9) complete. Timing: real 0.156s	user 0.103s	sys 0.052s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774687,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":149,"lbm_read_time_us":10715,"lbm_reads_lt_1ms":572,"lbm_write_time_us":29112,"lbm_writes_lt_1ms":543,"mutex_wait_us":24,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":97536,"update_count":2500}
I20260812 06:18:46.044714 27808 maintenance_manager.cc:419] P 919859f35e944a1e878347bb5e8c845b: Scheduling FlushDeltaMemStoresOp(cd8aa1eab95f453b8f9b333d81cbafb9): perf score=12.110812
I20260812 06:18:46.078301 27740 maintenance_manager.cc:643] P 919859f35e944a1e878347bb5e8c845b: FlushDeltaMemStoresOp(cd8aa1eab95f453b8f9b333d81cbafb9) complete. Timing: real 0.033s	user 0.019s	sys 0.012s Metrics: {"bytes_written":13620264,"delete_count":0,"lbm_write_time_us":14224,"lbm_writes_lt_1ms":335,"reinsert_count":0,"update_count":1660}
I20260812 06:18:46.078922 27808 maintenance_manager.cc:419] P 919859f35e944a1e878347bb5e8c845b: Scheduling FlushDeltaMemStoresOp(cd8aa1eab95f453b8f9b333d81cbafb9): perf score=1.196750
I20260812 06:18:46.089730 27740 maintenance_manager.cc:643] P 919859f35e944a1e878347bb5e8c845b: FlushDeltaMemStoresOp(cd8aa1eab95f453b8f9b333d81cbafb9) complete. Timing: real 0.011s	user 0.009s	sys 0.000s Metrics: {"bytes_written":2789855,"delete_count":0,"lbm_write_time_us":3857,"lbm_writes_lt_1ms":71,"reinsert_count":0,"update_count":340}
I20260812 06:18:46.090168 27808 maintenance_manager.cc:419] P 919859f35e944a1e878347bb5e8c845b: Scheduling MajorDeltaCompactionOp(cd8aa1eab95f453b8f9b333d81cbafb9): perf score=1.000000
I20260812 06:18:46.247354 27740 maintenance_manager.cc:643] P 919859f35e944a1e878347bb5e8c845b: MajorDeltaCompactionOp(cd8aa1eab95f453b8f9b333d81cbafb9) complete. Timing: real 0.157s	user 0.094s	sys 0.060s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672247,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":585,"lbm_read_time_us":12039,"lbm_reads_lt_1ms":468,"lbm_write_time_us":25145,"lbm_writes_lt_1ms":443,"mutex_wait_us":352,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":2176,"update_count":2000}
I20260812 06:18:46.248006 27808 maintenance_manager.cc:419] P 919859f35e944a1e878347bb5e8c845b: Scheduling FlushDeltaMemStoresOp(cd8aa1eab95f453b8f9b333d81cbafb9): perf score=11.118625
I20260812 06:18:46.291633 27740 maintenance_manager.cc:643] P 919859f35e944a1e878347bb5e8c845b: FlushDeltaMemStoresOp(cd8aa1eab95f453b8f9b333d81cbafb9) complete. Timing: real 0.043s	user 0.017s	sys 0.016s Metrics: {"bytes_written":12717735,"delete_count":0,"lbm_write_time_us":17746,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":312,"reinsert_count":0,"update_count":1550}
I20260812 06:18:46.292182 27808 maintenance_manager.cc:419] P 919859f35e944a1e878347bb5e8c845b: Scheduling FlushDeltaMemStoresOp(cd8aa1eab95f453b8f9b333d81cbafb9): perf score=2.188937
I20260812 06:18:46.302974 27740 maintenance_manager.cc:643] P 919859f35e944a1e878347bb5e8c845b: FlushDeltaMemStoresOp(cd8aa1eab95f453b8f9b333d81cbafb9) complete. Timing: real 0.011s	user 0.004s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4156,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:46.303440 27808 maintenance_manager.cc:419] P 919859f35e944a1e878347bb5e8c845b: Scheduling FlushDeltaMemStoresOp(cd8aa1eab95f453b8f9b333d81cbafb9): perf score=2.188937
I20260812 06:18:46.322376 27740 maintenance_manager.cc:643] P 919859f35e944a1e878347bb5e8c845b: FlushDeltaMemStoresOp(cd8aa1eab95f453b8f9b333d81cbafb9) complete. Timing: real 0.019s	user 0.009s	sys 0.007s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3674,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:18:46.322922 27808 maintenance_manager.cc:419] P 919859f35e944a1e878347bb5e8c845b: Scheduling MajorDeltaCompactionOp(cd8aa1eab95f453b8f9b333d81cbafb9): perf score=1.000000
I20260812 06:18:46.496313 27740 maintenance_manager.cc:643] P 919859f35e944a1e878347bb5e8c845b: MajorDeltaCompactionOp(cd8aa1eab95f453b8f9b333d81cbafb9) complete. Timing: real 0.173s	user 0.132s	sys 0.040s 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":487,"lbm_read_time_us":11663,"lbm_reads_lt_1ms":573,"lbm_write_time_us":29703,"lbm_writes_lt_1ms":543,"mutex_wait_us":100,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":30336,"update_count":2500}
I20260812 06:18:46.496887 27808 maintenance_manager.cc:419] P 919859f35e944a1e878347bb5e8c845b: Scheduling FlushDeltaMemStoresOp(cd8aa1eab95f453b8f9b333d81cbafb9): perf score=11.118625
I20260812 06:18:46.526454 27740 maintenance_manager.cc:643] P 919859f35e944a1e878347bb5e8c845b: FlushDeltaMemStoresOp(cd8aa1eab95f453b8f9b333d81cbafb9) complete. Timing: real 0.029s	user 0.018s	sys 0.009s Metrics: {"bytes_written":12717736,"delete_count":0,"lbm_write_time_us":12959,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:18:46.527091 27808 maintenance_manager.cc:419] P 919859f35e944a1e878347bb5e8c845b: Scheduling FlushDeltaMemStoresOp(cd8aa1eab95f453b8f9b333d81cbafb9): perf score=2.188937
I20260812 06:18:46.545132 27740 maintenance_manager.cc:643] P 919859f35e944a1e878347bb5e8c845b: FlushDeltaMemStoresOp(cd8aa1eab95f453b8f9b333d81cbafb9) complete. Timing: real 0.018s	user 0.014s	sys 0.000s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":5540,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:18:46.545750 27808 maintenance_manager.cc:419] P 919859f35e944a1e878347bb5e8c845b: Scheduling MajorDeltaCompactionOp(cd8aa1eab95f453b8f9b333d81cbafb9): perf score=1.000000
I20260812 06:18:46.675879 27740 maintenance_manager.cc:643] P 919859f35e944a1e878347bb5e8c845b: MajorDeltaCompactionOp(cd8aa1eab95f453b8f9b333d81cbafb9) complete. Timing: real 0.130s	user 0.099s	sys 0.031s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672269,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":189,"lbm_read_time_us":7295,"lbm_reads_lt_1ms":464,"lbm_write_time_us":26524,"lbm_writes_lt_1ms":443,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":3584,"update_count":2000}
I20260812 06:18:46.676646 27808 maintenance_manager.cc:419] P 919859f35e944a1e878347bb5e8c845b: Scheduling FlushDeltaMemStoresOp(cd8aa1eab95f453b8f9b333d81cbafb9): perf score=10.126437
I20260812 06:18:46.707785 27740 maintenance_manager.cc:643] P 919859f35e944a1e878347bb5e8c845b: FlushDeltaMemStoresOp(cd8aa1eab95f453b8f9b333d81cbafb9) complete. Timing: real 0.031s	user 0.016s	sys 0.012s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":13371,"lbm_writes_lt_1ms":303,"reinsert_count":0,"spinlock_wait_cycles":1280,"update_count":1500}
I20260812 06:18:46.708469 27808 maintenance_manager.cc:419] P 919859f35e944a1e878347bb5e8c845b: Scheduling FlushDeltaMemStoresOp(cd8aa1eab95f453b8f9b333d81cbafb9): perf score=2.188937
I20260812 06:18:46.724936 27740 maintenance_manager.cc:643] P 919859f35e944a1e878347bb5e8c845b: FlushDeltaMemStoresOp(cd8aa1eab95f453b8f9b333d81cbafb9) complete. Timing: real 0.016s	user 0.009s	sys 0.005s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5564,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:46.725406 27808 maintenance_manager.cc:419] P 919859f35e944a1e878347bb5e8c845b: Scheduling MajorDeltaCompactionOp(cd8aa1eab95f453b8f9b333d81cbafb9): perf score=1.000000
I20260812 06:18:46.860361 27740 maintenance_manager.cc:643] P 919859f35e944a1e878347bb5e8c845b: MajorDeltaCompactionOp(cd8aa1eab95f453b8f9b333d81cbafb9) complete. Timing: real 0.135s	user 0.102s	sys 0.029s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672277,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":1055,"lbm_read_time_us":9772,"lbm_reads_lt_1ms":468,"lbm_write_time_us":25327,"lbm_writes_lt_1ms":443,"mutex_wait_us":253,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":50304,"update_count":2000}
I20260812 06:18:46.861147 27808 maintenance_manager.cc:419] P 919859f35e944a1e878347bb5e8c845b: Scheduling FlushDeltaMemStoresOp(cd8aa1eab95f453b8f9b333d81cbafb9): perf score=10.126437
I20260812 06:18:46.901175 27740 maintenance_manager.cc:643] P 919859f35e944a1e878347bb5e8c845b: FlushDeltaMemStoresOp(cd8aa1eab95f453b8f9b333d81cbafb9) complete. Timing: real 0.039s	user 0.023s	sys 0.012s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":15527,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":302,"reinsert_count":0,"update_count":1500}
I20260812 06:18:46.901722 27808 maintenance_manager.cc:419] P 919859f35e944a1e878347bb5e8c845b: Scheduling FlushDeltaMemStoresOp(cd8aa1eab95f453b8f9b333d81cbafb9): perf score=2.188937
I20260812 06:18:46.912731 27740 maintenance_manager.cc:643] P 919859f35e944a1e878347bb5e8c845b: FlushDeltaMemStoresOp(cd8aa1eab95f453b8f9b333d81cbafb9) complete. Timing: real 0.011s	user 0.010s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4028,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:46.913705 27808 maintenance_manager.cc:419] P 919859f35e944a1e878347bb5e8c845b: Scheduling FlushMRSOp(cd8aa1eab95f453b8f9b333d81cbafb9): perf score=1.000000
I20260812 06:18:46.944408 27740 maintenance_manager.cc:643] P 919859f35e944a1e878347bb5e8c845b: FlushMRSOp(cd8aa1eab95f453b8f9b333d81cbafb9) complete. Timing: real 0.030s	user 0.025s	sys 0.003s Metrics: {"bytes_written":1152514,"cfile_init":1,"dirs.queue_time_us":75,"dirs.run_cpu_time_us":258,"dirs.run_wall_time_us":1491,"drs_written":1,"lbm_read_time_us":39,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1518,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":28}
I20260812 06:18:46.945200 27808 maintenance_manager.cc:419] P 919859f35e944a1e878347bb5e8c845b: Scheduling LogGCOp(cd8aa1eab95f453b8f9b333d81cbafb9): free 112692378 bytes of WAL
I20260812 06:18:46.945458 27740 log_reader.cc:385] T cd8aa1eab95f453b8f9b333d81cbafb9: removed 11 log segments from log reader
I20260812 06:18:46.945502 27740 log.cc:1079] T cd8aa1eab95f453b8f9b333d81cbafb9 P 919859f35e944a1e878347bb5e8c845b: Deleting log segment in path: /tmp/dist-test-task_caSEa/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515518284916-27409-0/minicluster-data/ts-0-root/wals/cd8aa1eab95f453b8f9b333d81cbafb9/wal-000000015 (ops 70-74)
I20260812 06:18:46.945531 27740 log.cc:1079] T cd8aa1eab95f453b8f9b333d81cbafb9 P 919859f35e944a1e878347bb5e8c845b: Deleting log segment in path: /tmp/dist-test-task_caSEa/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515518284916-27409-0/minicluster-data/ts-0-root/wals/cd8aa1eab95f453b8f9b333d81cbafb9/wal-000000016 (ops 75-79)
I20260812 06:18:46.945592 27740 log.cc:1079] T cd8aa1eab95f453b8f9b333d81cbafb9 P 919859f35e944a1e878347bb5e8c845b: Deleting log segment in path: /tmp/dist-test-task_caSEa/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515518284916-27409-0/minicluster-data/ts-0-root/wals/cd8aa1eab95f453b8f9b333d81cbafb9/wal-000000017 (ops 80-84)
I20260812 06:18:46.945641 27740 log.cc:1079] T cd8aa1eab95f453b8f9b333d81cbafb9 P 919859f35e944a1e878347bb5e8c845b: Deleting log segment in path: /tmp/dist-test-task_caSEa/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515518284916-27409-0/minicluster-data/ts-0-root/wals/cd8aa1eab95f453b8f9b333d81cbafb9/wal-000000018 (ops 85-89)
I20260812 06:18:46.945683 27740 log.cc:1079] T cd8aa1eab95f453b8f9b333d81cbafb9 P 919859f35e944a1e878347bb5e8c845b: Deleting log segment in path: /tmp/dist-test-task_caSEa/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515518284916-27409-0/minicluster-data/ts-0-root/wals/cd8aa1eab95f453b8f9b333d81cbafb9/wal-000000019 (ops 90-94)
I20260812 06:18:46.945724 27740 log.cc:1079] T cd8aa1eab95f453b8f9b333d81cbafb9 P 919859f35e944a1e878347bb5e8c845b: Deleting log segment in path: /tmp/dist-test-task_caSEa/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515518284916-27409-0/minicluster-data/ts-0-root/wals/cd8aa1eab95f453b8f9b333d81cbafb9/wal-000000020 (ops 95-99)
I20260812 06:18:46.945765 27740 log.cc:1079] T cd8aa1eab95f453b8f9b333d81cbafb9 P 919859f35e944a1e878347bb5e8c845b: Deleting log segment in path: /tmp/dist-test-task_caSEa/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515518284916-27409-0/minicluster-data/ts-0-root/wals/cd8aa1eab95f453b8f9b333d81cbafb9/wal-000000021 (ops 100-104)
I20260812 06:18:46.945806 27740 log.cc:1079] T cd8aa1eab95f453b8f9b333d81cbafb9 P 919859f35e944a1e878347bb5e8c845b: Deleting log segment in path: /tmp/dist-test-task_caSEa/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515518284916-27409-0/minicluster-data/ts-0-root/wals/cd8aa1eab95f453b8f9b333d81cbafb9/wal-000000022 (ops 105-109)
I20260812 06:18:46.945847 27740 log.cc:1079] T cd8aa1eab95f453b8f9b333d81cbafb9 P 919859f35e944a1e878347bb5e8c845b: Deleting log segment in path: /tmp/dist-test-task_caSEa/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515518284916-27409-0/minicluster-data/ts-0-root/wals/cd8aa1eab95f453b8f9b333d81cbafb9/wal-000000023 (ops 110-114)
I20260812 06:18:46.945887 27740 log.cc:1079] T cd8aa1eab95f453b8f9b333d81cbafb9 P 919859f35e944a1e878347bb5e8c845b: Deleting log segment in path: /tmp/dist-test-task_caSEa/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515518284916-27409-0/minicluster-data/ts-0-root/wals/cd8aa1eab95f453b8f9b333d81cbafb9/wal-000000024 (ops 115-119)
I20260812 06:18:46.945926 27740 log.cc:1079] T cd8aa1eab95f453b8f9b333d81cbafb9 P 919859f35e944a1e878347bb5e8c845b: Deleting log segment in path: /tmp/dist-test-task_caSEa/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515518284916-27409-0/minicluster-data/ts-0-root/wals/cd8aa1eab95f453b8f9b333d81cbafb9/wal-000000025 (ops 120-124)
I20260812 06:18:46.970297 27740 maintenance_manager.cc:643] P 919859f35e944a1e878347bb5e8c845b: LogGCOp(cd8aa1eab95f453b8f9b333d81cbafb9) complete. Timing: real 0.025s	user 0.003s	sys 0.019s Metrics: {}
I20260812 06:18:46.970777 27808 maintenance_manager.cc:419] P 919859f35e944a1e878347bb5e8c845b: Scheduling FlushDeltaMemStoresOp(cd8aa1eab95f453b8f9b333d81cbafb9): perf score=3.181125
I20260812 06:18:46.983085 27740 maintenance_manager.cc:643] P 919859f35e944a1e878347bb5e8c845b: FlushDeltaMemStoresOp(cd8aa1eab95f453b8f9b333d81cbafb9) complete. Timing: real 0.012s	user 0.007s	sys 0.003s Metrics: {"bytes_written":4512902,"delete_count":0,"lbm_write_time_us":4695,"lbm_writes_lt_1ms":113,"reinsert_count":0,"update_count":550}
I20260812 06:18:46.983531 27808 maintenance_manager.cc:419] P 919859f35e944a1e878347bb5e8c845b: Scheduling UndoDeltaBlockGCOp(cd8aa1eab95f453b8f9b333d81cbafb9): 447 bytes on disk
I20260812 06:18:46.984125 27740 maintenance_manager.cc:643] P 919859f35e944a1e878347bb5e8c845b: UndoDeltaBlockGCOp(cd8aa1eab95f453b8f9b333d81cbafb9) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":71,"lbm_reads_lt_1ms":4}
I20260812 06:18:46.984674 27808 maintenance_manager.cc:419] P 919859f35e944a1e878347bb5e8c845b: Scheduling FlushDeltaMemStoresOp(cd8aa1eab95f453b8f9b333d81cbafb9): perf score=2.188937
I20260812 06:18:46.994709 27740 maintenance_manager.cc:643] P 919859f35e944a1e878347bb5e8c845b: FlushDeltaMemStoresOp(cd8aa1eab95f453b8f9b333d81cbafb9) complete. Timing: real 0.010s	user 0.008s	sys 0.000s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3753,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:18:46.996389 27808 maintenance_manager.cc:419] P 919859f35e944a1e878347bb5e8c845b: Scheduling MajorDeltaCompactionOp(cd8aa1eab95f453b8f9b333d81cbafb9): perf score=1.000000
I20260812 06:18:47.183128 27740 maintenance_manager.cc:643] P 919859f35e944a1e878347bb5e8c845b: MajorDeltaCompactionOp(cd8aa1eab95f453b8f9b333d81cbafb9) complete. Timing: real 0.186s	user 0.140s	sys 0.040s Metrics: {"cfile_cache_miss":634,"cfile_cache_miss_bytes":28877328,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":319,"lbm_read_time_us":13048,"lbm_reads_lt_1ms":674,"lbm_write_time_us":34775,"lbm_writes_lt_1ms":643,"mutex_wait_us":25,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":45184,"thread_start_us":79,"threads_started":1,"update_count":3000}
I20260812 06:18:47.183914 27808 maintenance_manager.cc:419] P 919859f35e944a1e878347bb5e8c845b: Scheduling FlushDeltaMemStoresOp(cd8aa1eab95f453b8f9b333d81cbafb9): perf score=14.095187
I20260812 06:18:47.243676 27740 maintenance_manager.cc:643] P 919859f35e944a1e878347bb5e8c845b: FlushDeltaMemStoresOp(cd8aa1eab95f453b8f9b333d81cbafb9) complete. Timing: real 0.060s	user 0.042s	sys 0.008s Metrics: {"bytes_written":16409903,"delete_count":0,"lbm_write_time_us":24034,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:18:47.244316 27808 maintenance_manager.cc:419] P 919859f35e944a1e878347bb5e8c845b: Scheduling FlushDeltaMemStoresOp(cd8aa1eab95f453b8f9b333d81cbafb9): perf score=2.188937
I20260812 06:18:47.260370 27740 maintenance_manager.cc:643] P 919859f35e944a1e878347bb5e8c845b: FlushDeltaMemStoresOp(cd8aa1eab95f453b8f9b333d81cbafb9) complete. Timing: real 0.016s	user 0.012s	sys 0.003s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6039,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:47.261029 27808 maintenance_manager.cc:419] P 919859f35e944a1e878347bb5e8c845b: Scheduling MajorDeltaCompactionOp(cd8aa1eab95f453b8f9b333d81cbafb9): perf score=1.000000
I20260812 06:18:47.422406 27740 maintenance_manager.cc:643] P 919859f35e944a1e878347bb5e8c845b: MajorDeltaCompactionOp(cd8aa1eab95f453b8f9b333d81cbafb9) complete. Timing: real 0.161s	user 0.091s	sys 0.059s 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":361,"lbm_read_time_us":9803,"lbm_reads_lt_1ms":572,"lbm_write_time_us":29373,"lbm_writes_lt_1ms":543,"mutex_wait_us":46,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":52352,"update_count":2500}
I20260812 06:18:47.423101 27808 maintenance_manager.cc:419] P 919859f35e944a1e878347bb5e8c845b: Scheduling FlushDeltaMemStoresOp(cd8aa1eab95f453b8f9b333d81cbafb9): perf score=14.095187
I20260812 06:18:47.486544 27740 maintenance_manager.cc:643] P 919859f35e944a1e878347bb5e8c845b: FlushDeltaMemStoresOp(cd8aa1eab95f453b8f9b333d81cbafb9) complete. Timing: real 0.063s	user 0.028s	sys 0.023s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":23455,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:18:47.487104 27808 maintenance_manager.cc:419] P 919859f35e944a1e878347bb5e8c845b: Scheduling FlushDeltaMemStoresOp(cd8aa1eab95f453b8f9b333d81cbafb9): perf score=2.188937
I20260812 06:18:47.503165 27740 maintenance_manager.cc:643] P 919859f35e944a1e878347bb5e8c845b: FlushDeltaMemStoresOp(cd8aa1eab95f453b8f9b333d81cbafb9) complete. Timing: real 0.016s	user 0.002s	sys 0.011s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5825,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:47.503895 27808 maintenance_manager.cc:419] P 919859f35e944a1e878347bb5e8c845b: Scheduling MajorDeltaCompactionOp(cd8aa1eab95f453b8f9b333d81cbafb9): perf score=1.000000
I20260812 06:18:47.677587 27740 maintenance_manager.cc:643] P 919859f35e944a1e878347bb5e8c845b: MajorDeltaCompactionOp(cd8aa1eab95f453b8f9b333d81cbafb9) complete. Timing: real 0.174s	user 0.093s	sys 0.079s 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":842,"lbm_read_time_us":11963,"lbm_reads_lt_1ms":572,"lbm_write_time_us":29700,"lbm_writes_lt_1ms":543,"mutex_wait_us":77,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":2944,"update_count":2500}
I20260812 06:18:47.678187 27808 maintenance_manager.cc:419] P 919859f35e944a1e878347bb5e8c845b: Scheduling FlushDeltaMemStoresOp(cd8aa1eab95f453b8f9b333d81cbafb9): perf score=14.095187
I20260812 06:18:47.740523 27740 maintenance_manager.cc:643] P 919859f35e944a1e878347bb5e8c845b: FlushDeltaMemStoresOp(cd8aa1eab95f453b8f9b333d81cbafb9) complete. Timing: real 0.062s	user 0.034s	sys 0.020s Metrics: {"bytes_written":16409903,"delete_count":0,"lbm_write_time_us":21316,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:18:47.741110 27808 maintenance_manager.cc:419] P 919859f35e944a1e878347bb5e8c845b: Scheduling FlushDeltaMemStoresOp(cd8aa1eab95f453b8f9b333d81cbafb9): perf score=2.188937
I20260812 06:18:47.751722 27740 maintenance_manager.cc:643] P 919859f35e944a1e878347bb5e8c845b: FlushDeltaMemStoresOp(cd8aa1eab95f453b8f9b333d81cbafb9) complete. Timing: real 0.010s	user 0.001s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4217,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:47.752347 27808 maintenance_manager.cc:419] P 919859f35e944a1e878347bb5e8c845b: Scheduling MajorDeltaCompactionOp(cd8aa1eab95f453b8f9b333d81cbafb9): perf score=1.000000
I20260812 06:18:47.926119 27740 maintenance_manager.cc:643] P 919859f35e944a1e878347bb5e8c845b: MajorDeltaCompactionOp(cd8aa1eab95f453b8f9b333d81cbafb9) complete. Timing: real 0.174s	user 0.104s	sys 0.068s 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":1087,"lbm_read_time_us":13104,"lbm_reads_lt_1ms":572,"lbm_write_time_us":28918,"lbm_writes_lt_1ms":543,"mutex_wait_us":312,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":13568,"update_count":2500}
I20260812 06:18:47.926846 27808 maintenance_manager.cc:419] P 919859f35e944a1e878347bb5e8c845b: Scheduling FlushDeltaMemStoresOp(cd8aa1eab95f453b8f9b333d81cbafb9): perf score=11.118625
I20260812 06:18:47.966104 27740 maintenance_manager.cc:643] P 919859f35e944a1e878347bb5e8c845b: FlushDeltaMemStoresOp(cd8aa1eab95f453b8f9b333d81cbafb9) complete. Timing: real 0.039s	user 0.025s	sys 0.011s Metrics: {"bytes_written":12717735,"delete_count":0,"lbm_write_time_us":16737,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:18:47.967110 27808 maintenance_manager.cc:419] P 919859f35e944a1e878347bb5e8c845b: Scheduling FlushDeltaMemStoresOp(cd8aa1eab95f453b8f9b333d81cbafb9): perf score=2.188937
I20260812 06:18:47.985826 27740 maintenance_manager.cc:643] P 919859f35e944a1e878347bb5e8c845b: FlushDeltaMemStoresOp(cd8aa1eab95f453b8f9b333d81cbafb9) complete. Timing: real 0.018s	user 0.008s	sys 0.004s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":5094,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:18:47.986459 27808 maintenance_manager.cc:419] P 919859f35e944a1e878347bb5e8c845b: Scheduling MajorDeltaCompactionOp(cd8aa1eab95f453b8f9b333d81cbafb9): perf score=1.000000
I20260812 06:18:48.144724 27740 maintenance_manager.cc:643] P 919859f35e944a1e878347bb5e8c845b: MajorDeltaCompactionOp(cd8aa1eab95f453b8f9b333d81cbafb9) complete. Timing: real 0.158s	user 0.106s	sys 0.052s 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":837,"lbm_read_time_us":13204,"lbm_reads_lt_1ms":464,"lbm_write_time_us":24771,"lbm_writes_lt_1ms":443,"mutex_wait_us":28,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":7168,"update_count":2000}
I20260812 06:18:48.145411 27808 maintenance_manager.cc:419] P 919859f35e944a1e878347bb5e8c845b: Scheduling FlushDeltaMemStoresOp(cd8aa1eab95f453b8f9b333d81cbafb9): perf score=11.118625
I20260812 06:18:48.186792 27740 maintenance_manager.cc:643] P 919859f35e944a1e878347bb5e8c845b: FlushDeltaMemStoresOp(cd8aa1eab95f453b8f9b333d81cbafb9) complete. Timing: real 0.041s	user 0.021s	sys 0.017s Metrics: {"bytes_written":12717737,"delete_count":0,"lbm_write_time_us":17440,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:18:48.187489 27808 maintenance_manager.cc:419] P 919859f35e944a1e878347bb5e8c845b: Scheduling FlushDeltaMemStoresOp(cd8aa1eab95f453b8f9b333d81cbafb9): perf score=2.188937
I20260812 06:18:48.204522 27740 maintenance_manager.cc:643] P 919859f35e944a1e878347bb5e8c845b: FlushDeltaMemStoresOp(cd8aa1eab95f453b8f9b333d81cbafb9) complete. Timing: real 0.017s	user 0.007s	sys 0.005s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":5645,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:18:48.205217 27808 maintenance_manager.cc:419] P 919859f35e944a1e878347bb5e8c845b: Scheduling MajorDeltaCompactionOp(cd8aa1eab95f453b8f9b333d81cbafb9): perf score=1.000000
I20260812 06:18:48.328447 27740 maintenance_manager.cc:643] P 919859f35e944a1e878347bb5e8c845b: MajorDeltaCompactionOp(cd8aa1eab95f453b8f9b333d81cbafb9) complete. Timing: real 0.123s	user 0.085s	sys 0.037s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672270,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":880,"lbm_read_time_us":7878,"lbm_reads_lt_1ms":464,"lbm_write_time_us":23478,"lbm_writes_lt_1ms":443,"mutex_wait_us":287,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":32640,"update_count":2000}
I20260812 06:18:48.329245 27808 maintenance_manager.cc:419] P 919859f35e944a1e878347bb5e8c845b: Scheduling FlushDeltaMemStoresOp(cd8aa1eab95f453b8f9b333d81cbafb9): perf score=10.126437
I20260812 06:18:48.368183 27740 maintenance_manager.cc:643] P 919859f35e944a1e878347bb5e8c845b: FlushDeltaMemStoresOp(cd8aa1eab95f453b8f9b333d81cbafb9) complete. Timing: real 0.039s	user 0.019s	sys 0.016s Metrics: {"bytes_written":12307489,"delete_count":0,"lbm_write_time_us":14766,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:18:48.368728 27808 maintenance_manager.cc:419] P 919859f35e944a1e878347bb5e8c845b: Scheduling FlushDeltaMemStoresOp(cd8aa1eab95f453b8f9b333d81cbafb9): perf score=2.188937
I20260812 06:18:48.380501 27740 maintenance_manager.cc:643] P 919859f35e944a1e878347bb5e8c845b: FlushDeltaMemStoresOp(cd8aa1eab95f453b8f9b333d81cbafb9) complete. Timing: real 0.012s	user 0.007s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4158,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:48.381042 27808 maintenance_manager.cc:419] P 919859f35e944a1e878347bb5e8c845b: Scheduling FlushMRSOp(cd8aa1eab95f453b8f9b333d81cbafb9): perf score=1.000000
I20260812 06:18:48.409437 27740 maintenance_manager.cc:643] P 919859f35e944a1e878347bb5e8c845b: FlushMRSOp(cd8aa1eab95f453b8f9b333d81cbafb9) complete. Timing: real 0.028s	user 0.026s	sys 0.000s Metrics: {"bytes_written":1193505,"cfile_init":1,"dirs.queue_time_us":83,"dirs.run_cpu_time_us":183,"dirs.run_wall_time_us":1633,"drs_written":1,"lbm_read_time_us":53,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1416,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":29}
I20260812 06:18:48.410187 27808 maintenance_manager.cc:419] P 919859f35e944a1e878347bb5e8c845b: Scheduling LogGCOp(cd8aa1eab95f453b8f9b333d81cbafb9): free 115943401 bytes of WAL
I20260812 06:18:48.410454 27740 log_reader.cc:385] T cd8aa1eab95f453b8f9b333d81cbafb9: removed 11 log segments from log reader
I20260812 06:18:48.410526 27740 log.cc:1079] T cd8aa1eab95f453b8f9b333d81cbafb9 P 919859f35e944a1e878347bb5e8c845b: Deleting log segment in path: /tmp/dist-test-task_caSEa/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515518284916-27409-0/minicluster-data/ts-0-root/wals/cd8aa1eab95f453b8f9b333d81cbafb9/wal-000000026 (ops 125-129)
I20260812 06:18:48.410579 27740 log.cc:1079] T cd8aa1eab95f453b8f9b333d81cbafb9 P 919859f35e944a1e878347bb5e8c845b: Deleting log segment in path: /tmp/dist-test-task_caSEa/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515518284916-27409-0/minicluster-data/ts-0-root/wals/cd8aa1eab95f453b8f9b333d81cbafb9/wal-000000027 (ops 130-134)
I20260812 06:18:48.410638 27740 log.cc:1079] T cd8aa1eab95f453b8f9b333d81cbafb9 P 919859f35e944a1e878347bb5e8c845b: Deleting log segment in path: /tmp/dist-test-task_caSEa/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515518284916-27409-0/minicluster-data/ts-0-root/wals/cd8aa1eab95f453b8f9b333d81cbafb9/wal-000000028 (ops 135-139)
I20260812 06:18:48.410683 27740 log.cc:1079] T cd8aa1eab95f453b8f9b333d81cbafb9 P 919859f35e944a1e878347bb5e8c845b: Deleting log segment in path: /tmp/dist-test-task_caSEa/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515518284916-27409-0/minicluster-data/ts-0-root/wals/cd8aa1eab95f453b8f9b333d81cbafb9/wal-000000029 (ops 140-144)
I20260812 06:18:48.410723 27740 log.cc:1079] T cd8aa1eab95f453b8f9b333d81cbafb9 P 919859f35e944a1e878347bb5e8c845b: Deleting log segment in path: /tmp/dist-test-task_caSEa/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515518284916-27409-0/minicluster-data/ts-0-root/wals/cd8aa1eab95f453b8f9b333d81cbafb9/wal-000000030 (ops 145-149)
I20260812 06:18:48.410763 27740 log.cc:1079] T cd8aa1eab95f453b8f9b333d81cbafb9 P 919859f35e944a1e878347bb5e8c845b: Deleting log segment in path: /tmp/dist-test-task_caSEa/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515518284916-27409-0/minicluster-data/ts-0-root/wals/cd8aa1eab95f453b8f9b333d81cbafb9/wal-000000031 (ops 150-154)
I20260812 06:18:48.410802 27740 log.cc:1079] T cd8aa1eab95f453b8f9b333d81cbafb9 P 919859f35e944a1e878347bb5e8c845b: Deleting log segment in path: /tmp/dist-test-task_caSEa/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515518284916-27409-0/minicluster-data/ts-0-root/wals/cd8aa1eab95f453b8f9b333d81cbafb9/wal-000000032 (ops 155-159)
I20260812 06:18:48.410848 27740 log.cc:1079] T cd8aa1eab95f453b8f9b333d81cbafb9 P 919859f35e944a1e878347bb5e8c845b: Deleting log segment in path: /tmp/dist-test-task_caSEa/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515518284916-27409-0/minicluster-data/ts-0-root/wals/cd8aa1eab95f453b8f9b333d81cbafb9/wal-000000033 (ops 160-164)
I20260812 06:18:48.410887 27740 log.cc:1079] T cd8aa1eab95f453b8f9b333d81cbafb9 P 919859f35e944a1e878347bb5e8c845b: Deleting log segment in path: /tmp/dist-test-task_caSEa/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515518284916-27409-0/minicluster-data/ts-0-root/wals/cd8aa1eab95f453b8f9b333d81cbafb9/wal-000000034 (ops 165-169)
I20260812 06:18:48.410925 27740 log.cc:1079] T cd8aa1eab95f453b8f9b333d81cbafb9 P 919859f35e944a1e878347bb5e8c845b: Deleting log segment in path: /tmp/dist-test-task_caSEa/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515518284916-27409-0/minicluster-data/ts-0-root/wals/cd8aa1eab95f453b8f9b333d81cbafb9/wal-000000035 (ops 170-174)
I20260812 06:18:48.410964 27740 log.cc:1079] T cd8aa1eab95f453b8f9b333d81cbafb9 P 919859f35e944a1e878347bb5e8c845b: Deleting log segment in path: /tmp/dist-test-task_caSEa/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515518284916-27409-0/minicluster-data/ts-0-root/wals/cd8aa1eab95f453b8f9b333d81cbafb9/wal-000000036 (ops 175-179)
I20260812 06:18:48.436403 27740 maintenance_manager.cc:643] P 919859f35e944a1e878347bb5e8c845b: LogGCOp(cd8aa1eab95f453b8f9b333d81cbafb9) complete. Timing: real 0.026s	user 0.000s	sys 0.025s Metrics: {}
I20260812 06:18:48.438079 27808 maintenance_manager.cc:419] P 919859f35e944a1e878347bb5e8c845b: Scheduling FlushDeltaMemStoresOp(cd8aa1eab95f453b8f9b333d81cbafb9): perf score=2.188937
I20260812 06:18:48.451295 27740 maintenance_manager.cc:643] P 919859f35e944a1e878347bb5e8c845b: FlushDeltaMemStoresOp(cd8aa1eab95f453b8f9b333d81cbafb9) complete. Timing: real 0.013s	user 0.010s	sys 0.000s Metrics: {"bytes_written":4307782,"delete_count":0,"lbm_write_time_us":4656,"lbm_writes_lt_1ms":108,"reinsert_count":0,"update_count":525}
I20260812 06:18:48.451756 27808 maintenance_manager.cc:419] P 919859f35e944a1e878347bb5e8c845b: Scheduling LogGCOp(cd8aa1eab95f453b8f9b333d81cbafb9): free 12017954 bytes of WAL
I20260812 06:18:48.452066 27740 log_reader.cc:385] T cd8aa1eab95f453b8f9b333d81cbafb9: removed 1 log segments from log reader
I20260812 06:18:48.452133 27740 log.cc:1079] T cd8aa1eab95f453b8f9b333d81cbafb9 P 919859f35e944a1e878347bb5e8c845b: Deleting log segment in path: /tmp/dist-test-task_caSEa/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515518284916-27409-0/minicluster-data/ts-0-root/wals/cd8aa1eab95f453b8f9b333d81cbafb9/wal-000000037 (ops 180-184)
I20260812 06:18:48.454492 27740 maintenance_manager.cc:643] P 919859f35e944a1e878347bb5e8c845b: LogGCOp(cd8aa1eab95f453b8f9b333d81cbafb9) complete. Timing: real 0.002s	user 0.000s	sys 0.000s Metrics: {}
I20260812 06:18:48.454859 27808 maintenance_manager.cc:419] P 919859f35e944a1e878347bb5e8c845b: Scheduling UndoDeltaBlockGCOp(cd8aa1eab95f453b8f9b333d81cbafb9): 463 bytes on disk
I20260812 06:18:48.455345 27740 maintenance_manager.cc:643] P 919859f35e944a1e878347bb5e8c845b: UndoDeltaBlockGCOp(cd8aa1eab95f453b8f9b333d81cbafb9) 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:48.455988 27808 maintenance_manager.cc:419] P 919859f35e944a1e878347bb5e8c845b: Scheduling FlushDeltaMemStoresOp(cd8aa1eab95f453b8f9b333d81cbafb9): perf score=2.188937
I20260812 06:18:48.468122 27740 maintenance_manager.cc:643] P 919859f35e944a1e878347bb5e8c845b: FlushDeltaMemStoresOp(cd8aa1eab95f453b8f9b333d81cbafb9) complete. Timing: real 0.012s	user 0.008s	sys 0.004s Metrics: {"bytes_written":3897533,"delete_count":0,"lbm_write_time_us":3828,"lbm_writes_lt_1ms":98,"reinsert_count":0,"update_count":475}
I20260812 06:18:48.468606 27808 maintenance_manager.cc:419] P 919859f35e944a1e878347bb5e8c845b: Scheduling MajorDeltaCompactionOp(cd8aa1eab95f453b8f9b333d81cbafb9): perf score=1.000000
I20260812 06:18:48.647500 27740 maintenance_manager.cc:643] P 919859f35e944a1e878347bb5e8c845b: MajorDeltaCompactionOp(cd8aa1eab95f453b8f9b333d81cbafb9) complete. Timing: real 0.179s	user 0.131s	sys 0.045s Metrics: {"cfile_cache_miss":634,"cfile_cache_miss_bytes":28877335,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":1278,"lbm_read_time_us":13365,"lbm_reads_lt_1ms":670,"lbm_write_time_us":36230,"lbm_writes_lt_1ms":643,"mutex_wait_us":54,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":16896,"thread_start_us":82,"threads_started":1,"update_count":3000}
I20260812 06:18:48.648314 27808 maintenance_manager.cc:419] P 919859f35e944a1e878347bb5e8c845b: Scheduling FlushDeltaMemStoresOp(cd8aa1eab95f453b8f9b333d81cbafb9): perf score=14.095187
I20260812 06:18:48.706126 27740 maintenance_manager.cc:643] P 919859f35e944a1e878347bb5e8c845b: FlushDeltaMemStoresOp(cd8aa1eab95f453b8f9b333d81cbafb9) complete. Timing: real 0.058s	user 0.028s	sys 0.027s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":27916,"lbm_writes_1-10_ms":2,"lbm_writes_lt_1ms":401,"reinsert_count":0,"update_count":2000}
I20260812 06:18:48.706773 27808 maintenance_manager.cc:419] P 919859f35e944a1e878347bb5e8c845b: Scheduling FlushDeltaMemStoresOp(cd8aa1eab95f453b8f9b333d81cbafb9): perf score=2.188937
I20260812 06:18:48.719278 27740 maintenance_manager.cc:643] P 919859f35e944a1e878347bb5e8c845b: FlushDeltaMemStoresOp(cd8aa1eab95f453b8f9b333d81cbafb9) complete. Timing: real 0.012s	user 0.011s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4762,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:48.719955 27808 maintenance_manager.cc:419] P 919859f35e944a1e878347bb5e8c845b: Scheduling MajorDeltaCompactionOp(cd8aa1eab95f453b8f9b333d81cbafb9): perf score=1.000000
I20260812 06:18:48.821331 27409 heavy-update-compaction-itest.cc:229] Time spent updating: real 4.883s	user 1.805s	sys 0.139s
I20260812 06:18:48.860466 27740 maintenance_manager.cc:643] P 919859f35e944a1e878347bb5e8c845b: MajorDeltaCompactionOp(cd8aa1eab95f453b8f9b333d81cbafb9) complete. Timing: real 0.140s	user 0.104s	sys 0.036s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774688,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"lbm_read_time_us":9276,"lbm_reads_lt_1ms":568,"lbm_write_time_us":28102,"lbm_writes_lt_1ms":543,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":21888,"update_count":2500}
I20260812 06:18:48.861065 27808 maintenance_manager.cc:419] P 919859f35e944a1e878347bb5e8c845b: Scheduling FlushDeltaMemStoresOp(cd8aa1eab95f453b8f9b333d81cbafb9): perf score=10.126437
I20260812 06:18:48.889657 27740 maintenance_manager.cc:643] P 919859f35e944a1e878347bb5e8c845b: FlushDeltaMemStoresOp(cd8aa1eab95f453b8f9b333d81cbafb9) complete. Timing: real 0.028s	user 0.022s	sys 0.004s Metrics: {"bytes_written":12307489,"delete_count":0,"lbm_write_time_us":12486,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:18:48.890166 27808 maintenance_manager.cc:419] P 919859f35e944a1e878347bb5e8c845b: Scheduling MajorDeltaCompactionOp(cd8aa1eab95f453b8f9b333d81cbafb9): perf score=1.000000
I20260812 06:18:48.896325 27409 heavy-update-compaction-itest.cc:265] Time spent scanning: real 0.075s	user 0.004s	sys 0.000s
I20260812 06:18:48.897020 27409 tablet_server.cc:179] TabletServer@127.26.196.65:0 shutting down...
I20260812 06:18:49.000674 27740 maintenance_manager.cc:643] P 919859f35e944a1e878347bb5e8c845b: MajorDeltaCompactionOp(cd8aa1eab95f453b8f9b333d81cbafb9) complete. Timing: real 0.110s	user 0.074s	sys 0.036s Metrics: {"cfile_cache_miss":331,"cfile_cache_miss_bytes":16569745,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":1,"delta_iterators_relevant":1,"dirs.queue_time_us":102,"lbm_read_time_us":7941,"lbm_reads_lt_1ms":367,"lbm_write_time_us":22417,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":342,"peak_mem_usage":38262756,"reinsert_count":0,"update_count":1500}
I20260812 06:18:49.001529 27409 ts_tablet_manager.cc:1507] Shutting down tablet manager...
I20260812 06:18:49.001845 27409 tablet_replica.cc:333] T cd8aa1eab95f453b8f9b333d81cbafb9 P 919859f35e944a1e878347bb5e8c845b: stopping tablet replica
I20260812 06:18:49.002002 27409 raft_consensus.cc:2243] T cd8aa1eab95f453b8f9b333d81cbafb9 P 919859f35e944a1e878347bb5e8c845b [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:18:49.002204 27409 raft_consensus.cc:2272] T cd8aa1eab95f453b8f9b333d81cbafb9 P 919859f35e944a1e878347bb5e8c845b [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:18:49.017077 27409 tablet_server.cc:196] TabletServer@127.26.196.65:0 shutdown complete.
I20260812 06:18:49.036805 27409 master.cc:562] Master@127.26.196.126:38455 shutting down...
I20260812 06:18:49.040690 27409 raft_consensus.cc:2243] T 00000000000000000000000000000000 P e655b330ad964b9b9770c5c31beaf8b7 [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:18:49.040944 27409 raft_consensus.cc:2272] T 00000000000000000000000000000000 P e655b330ad964b9b9770c5c31beaf8b7 [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:18:49.041041 27409 tablet_replica.cc:333] T 00000000000000000000000000000000 P e655b330ad964b9b9770c5c31beaf8b7: stopping tablet replica
I20260812 06:18:49.053934 27409 master.cc:584] Master@127.26.196.126:38455 shutdown complete.
[       OK ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/1 (5431 ms)
[----------] 2 tests from EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy (10857 ms total)

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