[==========] 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:46.991469 32748 internal_mini_cluster.cc:156] Creating distributed mini masters. Addrs: 127.31.251.62:37421
I20260812 06:18:46.992635 32748 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:46.993335 32748 file_cache.cc:504] Constructed file cache file cache with capacity 419430
I20260812 06:18:47.001354 32748 server_base.cc:1061] running on GCE node
W20260812 06:18:47.001454 32756 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:47.001452 32753 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:47.001794 32754 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:47.002375 32748 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:18:47.002524 32748 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:47.002591 32748 hybrid_clock.cc:648] HybridClock initialized: now 1786515527002588 us; error 0 us; skew 500 ppm
I20260812 06:18:47.004822 32748 webserver.cc:533] Webserver started at http://127.31.251.62:33003/ using document root <none> and password file <none>
I20260812 06:18:47.005477 32748 fs_manager.cc:362] Metadata directory not provided
I20260812 06:18:47.005584 32748 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:18:47.005877 32748 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:18:47.007768 32748 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskyiE61X/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515526977841-32748-0/minicluster-data/master-0-root/instance:
uuid: "770aacc7bd7246438ab41db5eeddcb1e"
format_stamp: "Formatted at 2026-08-12 06:18:47 on dist-test-slave-csg5"
I20260812 06:18:47.011829 32748 fs_manager.cc:696] Time spent creating directory manager: real 0.004s	user 0.004s	sys 0.000s
I20260812 06:18:47.014361 32765 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:47.015771 32748 fs_manager.cc:730] Time spent opening block manager: real 0.003s	user 0.003s	sys 0.000s
I20260812 06:18:47.015946 32748 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskyiE61X/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515526977841-32748-0/minicluster-data/master-0-root
uuid: "770aacc7bd7246438ab41db5eeddcb1e"
format_stamp: "Formatted at 2026-08-12 06:18:47 on dist-test-slave-csg5"
I20260812 06:18:47.016083 32748 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskyiE61X/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515526977841-32748-0/minicluster-data/master-0-root
metadata directory: /tmp/dist-test-taskyiE61X/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515526977841-32748-0/minicluster-data/master-0-root
1 data directories: /tmp/dist-test-taskyiE61X/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515526977841-32748-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:47.036118 32748 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:18:47.036939 32748 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:47.037153 32748 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:18:47.047125 32748 rpc_server.cc:307] RPC server started. Bound to: 127.31.251.62:37421
I20260812 06:18:47.047180   354 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.31.251.62:37421 every 8 connection(s)
I20260812 06:18:47.049801   355 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:47.055955   355 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P 770aacc7bd7246438ab41db5eeddcb1e: Bootstrap starting.
I20260812 06:18:47.058576   355 tablet_bootstrap.cc:654] T 00000000000000000000000000000000 P 770aacc7bd7246438ab41db5eeddcb1e: Neither blocks nor log segments found. Creating new log.
I20260812 06:18:47.059800   355 log.cc:826] T 00000000000000000000000000000000 P 770aacc7bd7246438ab41db5eeddcb1e: Log is configured to *not* fsync() on all Append() calls
I20260812 06:18:47.061848   355 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P 770aacc7bd7246438ab41db5eeddcb1e: No bootstrap required, opened a new log
I20260812 06:18:47.065121   355 raft_consensus.cc:359] T 00000000000000000000000000000000 P 770aacc7bd7246438ab41db5eeddcb1e [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "770aacc7bd7246438ab41db5eeddcb1e" member_type: VOTER }
I20260812 06:18:47.065320   355 raft_consensus.cc:385] T 00000000000000000000000000000000 P 770aacc7bd7246438ab41db5eeddcb1e [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:18:47.065392   355 raft_consensus.cc:740] T 00000000000000000000000000000000 P 770aacc7bd7246438ab41db5eeddcb1e [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: 770aacc7bd7246438ab41db5eeddcb1e, State: Initialized, Role: FOLLOWER
I20260812 06:18:47.066083   355 consensus_queue.cc:260] T 00000000000000000000000000000000 P 770aacc7bd7246438ab41db5eeddcb1e [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: "770aacc7bd7246438ab41db5eeddcb1e" member_type: VOTER }
I20260812 06:18:47.066246   355 raft_consensus.cc:399] T 00000000000000000000000000000000 P 770aacc7bd7246438ab41db5eeddcb1e [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:18:47.066318   355 raft_consensus.cc:493] T 00000000000000000000000000000000 P 770aacc7bd7246438ab41db5eeddcb1e [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:18:47.066473   355 raft_consensus.cc:3060] T 00000000000000000000000000000000 P 770aacc7bd7246438ab41db5eeddcb1e [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:18:47.067402   355 raft_consensus.cc:515] T 00000000000000000000000000000000 P 770aacc7bd7246438ab41db5eeddcb1e [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "770aacc7bd7246438ab41db5eeddcb1e" member_type: VOTER }
I20260812 06:18:47.067903   355 leader_election.cc:304] T 00000000000000000000000000000000 P 770aacc7bd7246438ab41db5eeddcb1e [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: 770aacc7bd7246438ab41db5eeddcb1e; no voters: 
I20260812 06:18:47.068266   355 leader_election.cc:290] T 00000000000000000000000000000000 P 770aacc7bd7246438ab41db5eeddcb1e [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:18:47.068449   358 raft_consensus.cc:2804] T 00000000000000000000000000000000 P 770aacc7bd7246438ab41db5eeddcb1e [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:18:47.068720   358 raft_consensus.cc:697] T 00000000000000000000000000000000 P 770aacc7bd7246438ab41db5eeddcb1e [term 1 LEADER]: Becoming Leader. State: Replica: 770aacc7bd7246438ab41db5eeddcb1e, State: Running, Role: LEADER
I20260812 06:18:47.069172   358 consensus_queue.cc:237] T 00000000000000000000000000000000 P 770aacc7bd7246438ab41db5eeddcb1e [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: "770aacc7bd7246438ab41db5eeddcb1e" member_type: VOTER }
I20260812 06:18:47.069375   355 sys_catalog.cc:565] T 00000000000000000000000000000000 P 770aacc7bd7246438ab41db5eeddcb1e [sys.catalog]: configured and running, proceeding with master startup.
I20260812 06:18:47.071429   360 sys_catalog.cc:455] T 00000000000000000000000000000000 P 770aacc7bd7246438ab41db5eeddcb1e [sys.catalog]: SysCatalogTable state changed. Reason: New leader 770aacc7bd7246438ab41db5eeddcb1e. Latest consensus state: current_term: 1 leader_uuid: "770aacc7bd7246438ab41db5eeddcb1e" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "770aacc7bd7246438ab41db5eeddcb1e" member_type: VOTER } }
I20260812 06:18:47.071448   359 sys_catalog.cc:455] T 00000000000000000000000000000000 P 770aacc7bd7246438ab41db5eeddcb1e [sys.catalog]: SysCatalogTable state changed. Reason: RaftConsensus started. Latest consensus state: current_term: 1 leader_uuid: "770aacc7bd7246438ab41db5eeddcb1e" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "770aacc7bd7246438ab41db5eeddcb1e" member_type: VOTER } }
I20260812 06:18:47.071585   360 sys_catalog.cc:458] T 00000000000000000000000000000000 P 770aacc7bd7246438ab41db5eeddcb1e [sys.catalog]: This master's current role is: LEADER
I20260812 06:18:47.071585   359 sys_catalog.cc:458] T 00000000000000000000000000000000 P 770aacc7bd7246438ab41db5eeddcb1e [sys.catalog]: This master's current role is: LEADER
I20260812 06:18:47.071779 32748 internal_mini_cluster.cc:184] Waiting to initialize catalog manager on master 0
W20260812 06:18:47.073840   374 catalog_manager.cc:1594] T 00000000000000000000000000000000 P 770aacc7bd7246438ab41db5eeddcb1e: loading cluster ID for follower catalog manager: Not found: cluster ID entry not found
W20260812 06:18:47.073940   374 catalog_manager.cc:883] Not found: cluster ID entry not found: failed to prepare follower catalog manager, will retry
I20260812 06:18:47.074015   375 catalog_manager.cc:1511] Loading table and tablet metadata into memory...
I20260812 06:18:47.074831   375 catalog_manager.cc:1520] Initializing Kudu cluster ID...
I20260812 06:18:47.079996   375 catalog_manager.cc:1383] Generated new cluster ID: 1a3da8afa83544af9d1c3dcdea2f2230
I20260812 06:18:47.080114   375 catalog_manager.cc:1531] Initializing Kudu internal certificate authority...
I20260812 06:18:47.104575   375 catalog_manager.cc:1406] Generated new certificate authority record
I20260812 06:18:47.105612   375 catalog_manager.cc:1540] Loading token signing keys...
I20260812 06:18:47.114990   375 catalog_manager.cc:6092] T 00000000000000000000000000000000 P 770aacc7bd7246438ab41db5eeddcb1e: Generated new TSK 0
I20260812 06:18:47.115888   375 catalog_manager.cc:1550] Initializing in-progress tserver states...
I20260812 06:18:47.136873 32748 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:18:47.139861   379 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:47.139961   382 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:47.140089   380 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:47.140312 32748 server_base.cc:1061] running on GCE node
I20260812 06:18:47.140535 32748 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:18:47.140578 32748 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:47.140595 32748 hybrid_clock.cc:648] HybridClock initialized: now 1786515527140595 us; error 0 us; skew 500 ppm
I20260812 06:18:47.141670 32748 webserver.cc:533] Webserver started at http://127.31.251.1:41553/ using document root <none> and password file <none>
I20260812 06:18:47.142004 32748 fs_manager.cc:362] Metadata directory not provided
I20260812 06:18:47.142112 32748 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:18:47.142235 32748 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:18:47.142800 32748 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskyiE61X/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515526977841-32748-0/minicluster-data/ts-0-root/instance:
uuid: "57befd549e9740aebaffb34054751973"
format_stamp: "Formatted at 2026-08-12 06:18:47 on dist-test-slave-csg5"
I20260812 06:18:47.144554 32748 fs_manager.cc:696] Time spent creating directory manager: real 0.001s	user 0.001s	sys 0.001s
I20260812 06:18:47.145742   387 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:47.146026 32748 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.001s	sys 0.000s
I20260812 06:18:47.146108 32748 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskyiE61X/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515526977841-32748-0/minicluster-data/ts-0-root
uuid: "57befd549e9740aebaffb34054751973"
format_stamp: "Formatted at 2026-08-12 06:18:47 on dist-test-slave-csg5"
I20260812 06:18:47.146216 32748 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskyiE61X/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515526977841-32748-0/minicluster-data/ts-0-root
metadata directory: /tmp/dist-test-taskyiE61X/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515526977841-32748-0/minicluster-data/ts-0-root
1 data directories: /tmp/dist-test-taskyiE61X/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515526977841-32748-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:47.157965 32748 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:18:47.158552 32748 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:18:47.159282 32748 txn_system_client.cc:432] TxnSystemClient initialization is disabled...
I20260812 06:18:47.160332 32748 ts_tablet_manager.cc:585] Loaded tablet metadata (0 total tablets, 0 live tablets)
I20260812 06:18:47.160393 32748 ts_tablet_manager.cc:531] Time spent load tablet metadata: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:18:47.160491 32748 ts_tablet_manager.cc:616] Registered 0 tablets
I20260812 06:18:47.160533 32748 ts_tablet_manager.cc:595] Time spent register tablets: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:18:47.168555 32748 rpc_server.cc:307] RPC server started. Bound to: 127.31.251.1:34947
I20260812 06:18:47.168593   458 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.31.251.1:34947 every 8 connection(s)
I20260812 06:18:47.180506   459 heartbeater.cc:344] Connected to a master server at 127.31.251.62:37421
I20260812 06:18:47.180826   459 heartbeater.cc:461] Registering TS with master...
I20260812 06:18:47.181370   459 heartbeater.cc:507] Master 127.31.251.62:37421 requested a full tablet report, sending...
I20260812 06:18:47.183179   318 ts_manager.cc:194] Registered new tserver with Master: 57befd549e9740aebaffb34054751973 (127.31.251.1:34947)
I20260812 06:18:47.183274 32748 internal_mini_cluster.cc:371] 1 TS(s) registered with all masters after 0.013993229s
I20260812 06:18:47.184791   318 master_service.cc:502] Signed X509 certificate for tserver {username='slave'} at 127.0.0.1:39936
I20260812 06:18:47.195181   318 catalog_manager.cc:2283] Servicing CreateTable request from {username='slave'} at 127.0.0.1:39944:
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:47.212692   418 tablet_service.cc:1511] Processing CreateTablet for tablet e02f35ae36554678a4d8e93f65e387ad (DEFAULT_TABLE table=heavy-update-compaction-test [id=6ceea275472c47c59bc86f4324ef99c1]), partition=
I20260812 06:18:47.213328   418 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet e02f35ae36554678a4d8e93f65e387ad. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:18:47.217437   473 tablet_bootstrap.cc:492] T e02f35ae36554678a4d8e93f65e387ad P 57befd549e9740aebaffb34054751973: Bootstrap starting.
I20260812 06:18:47.218696   473 tablet_bootstrap.cc:654] T e02f35ae36554678a4d8e93f65e387ad P 57befd549e9740aebaffb34054751973: Neither blocks nor log segments found. Creating new log.
I20260812 06:18:47.220870   473 tablet_bootstrap.cc:492] T e02f35ae36554678a4d8e93f65e387ad P 57befd549e9740aebaffb34054751973: No bootstrap required, opened a new log
I20260812 06:18:47.221136   473 ts_tablet_manager.cc:1403] T e02f35ae36554678a4d8e93f65e387ad P 57befd549e9740aebaffb34054751973: Time spent bootstrapping tablet: real 0.004s	user 0.000s	sys 0.003s
I20260812 06:18:47.221794   473 raft_consensus.cc:359] T e02f35ae36554678a4d8e93f65e387ad P 57befd549e9740aebaffb34054751973 [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "57befd549e9740aebaffb34054751973" member_type: VOTER last_known_addr { host: "127.31.251.1" port: 34947 } }
I20260812 06:18:47.221912   473 raft_consensus.cc:385] T e02f35ae36554678a4d8e93f65e387ad P 57befd549e9740aebaffb34054751973 [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:18:47.221936   473 raft_consensus.cc:740] T e02f35ae36554678a4d8e93f65e387ad P 57befd549e9740aebaffb34054751973 [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: 57befd549e9740aebaffb34054751973, State: Initialized, Role: FOLLOWER
I20260812 06:18:47.222092   473 consensus_queue.cc:260] T e02f35ae36554678a4d8e93f65e387ad P 57befd549e9740aebaffb34054751973 [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: "57befd549e9740aebaffb34054751973" member_type: VOTER last_known_addr { host: "127.31.251.1" port: 34947 } }
I20260812 06:18:47.222188   473 raft_consensus.cc:399] T e02f35ae36554678a4d8e93f65e387ad P 57befd549e9740aebaffb34054751973 [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:18:47.222216   473 raft_consensus.cc:493] T e02f35ae36554678a4d8e93f65e387ad P 57befd549e9740aebaffb34054751973 [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:18:47.222291   473 raft_consensus.cc:3060] T e02f35ae36554678a4d8e93f65e387ad P 57befd549e9740aebaffb34054751973 [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:18:47.223273   473 raft_consensus.cc:515] T e02f35ae36554678a4d8e93f65e387ad P 57befd549e9740aebaffb34054751973 [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "57befd549e9740aebaffb34054751973" member_type: VOTER last_known_addr { host: "127.31.251.1" port: 34947 } }
I20260812 06:18:47.223469   473 leader_election.cc:304] T e02f35ae36554678a4d8e93f65e387ad P 57befd549e9740aebaffb34054751973 [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: 57befd549e9740aebaffb34054751973; no voters: 
I20260812 06:18:47.223758   473 leader_election.cc:290] T e02f35ae36554678a4d8e93f65e387ad P 57befd549e9740aebaffb34054751973 [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:18:47.224089   475 raft_consensus.cc:2804] T e02f35ae36554678a4d8e93f65e387ad P 57befd549e9740aebaffb34054751973 [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:18:47.224359   475 raft_consensus.cc:697] T e02f35ae36554678a4d8e93f65e387ad P 57befd549e9740aebaffb34054751973 [term 1 LEADER]: Becoming Leader. State: Replica: 57befd549e9740aebaffb34054751973, State: Running, Role: LEADER
I20260812 06:18:47.224442   473 ts_tablet_manager.cc:1434] T e02f35ae36554678a4d8e93f65e387ad P 57befd549e9740aebaffb34054751973: Time spent starting tablet: real 0.003s	user 0.003s	sys 0.000s
I20260812 06:18:47.224618   475 consensus_queue.cc:237] T e02f35ae36554678a4d8e93f65e387ad P 57befd549e9740aebaffb34054751973 [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: "57befd549e9740aebaffb34054751973" member_type: VOTER last_known_addr { host: "127.31.251.1" port: 34947 } }
I20260812 06:18:47.224689   459 heartbeater.cc:499] Master 127.31.251.62:37421 was elected leader, sending a full tablet report...
I20260812 06:18:47.228641   318 catalog_manager.cc:5719] T e02f35ae36554678a4d8e93f65e387ad P 57befd549e9740aebaffb34054751973 reported cstate change: term changed from 0 to 1, leader changed from <none> to 57befd549e9740aebaffb34054751973 (127.31.251.1). New cstate: current_term: 1 leader_uuid: "57befd549e9740aebaffb34054751973" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "57befd549e9740aebaffb34054751973" member_type: VOTER last_known_addr { host: "127.31.251.1" port: 34947 } health_report { overall_health: HEALTHY } } }
I20260812 06:18:47.299247 32748 heavy-update-compaction-itest.cc:215] Time spent inserting: real 0.059s	user 0.018s	sys 0.009s
I20260812 06:18:47.419958   460 maintenance_manager.cc:419] P 57befd549e9740aebaffb34054751973: Scheduling FlushMRSOp(e02f35ae36554678a4d8e93f65e387ad): perf score=15.086190
I20260812 06:18:47.574189   392 maintenance_manager.cc:643] P 57befd549e9740aebaffb34054751973: FlushMRSOp(e02f35ae36554678a4d8e93f65e387ad) complete. Timing: real 0.154s	user 0.111s	sys 0.040s Metrics: {"bytes_written":8205078,"cfile_init":1,"compiler_manager_pool.queue_time_us":287,"delete_count":0,"dirs.queue_time_us":11940,"dirs.run_cpu_time_us":287,"dirs.run_wall_time_us":1246,"drs_written":1,"lbm_read_time_us":95,"lbm_reads_lt_1ms":4,"lbm_write_time_us":33188,"lbm_writes_lt_1ms":557,"peak_mem_usage":0,"reinsert_count":0,"rows_written":103,"thread_start_us":191,"threads_started":1,"update_count":1000}
I20260812 06:18:47.576045   460 maintenance_manager.cc:419] P 57befd549e9740aebaffb34054751973: Scheduling LogGCOp(e02f35ae36554678a4d8e93f65e387ad): free 20290830 bytes of WAL
I20260812 06:18:47.576475   392 log_reader.cc:385] T e02f35ae36554678a4d8e93f65e387ad: removed 2 log segments from log reader
I20260812 06:18:47.576598   392 log.cc:1079] T e02f35ae36554678a4d8e93f65e387ad P 57befd549e9740aebaffb34054751973: Deleting log segment in path: /tmp/dist-test-taskyiE61X/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515526977841-32748-0/minicluster-data/ts-0-root/wals/e02f35ae36554678a4d8e93f65e387ad/wal-000000001 (ops 1-6)
I20260812 06:18:47.576705   392 log.cc:1079] T e02f35ae36554678a4d8e93f65e387ad P 57befd549e9740aebaffb34054751973: Deleting log segment in path: /tmp/dist-test-taskyiE61X/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515526977841-32748-0/minicluster-data/ts-0-root/wals/e02f35ae36554678a4d8e93f65e387ad/wal-000000002 (ops 7-10)
I20260812 06:18:47.582036   392 maintenance_manager.cc:643] P 57befd549e9740aebaffb34054751973: LogGCOp(e02f35ae36554678a4d8e93f65e387ad) complete. Timing: real 0.006s	user 0.000s	sys 0.002s Metrics: {}
I20260812 06:18:47.582551   460 maintenance_manager.cc:419] P 57befd549e9740aebaffb34054751973: Scheduling UndoDeltaBlockGCOp(e02f35ae36554678a4d8e93f65e387ad): 12308958 bytes on disk
I20260812 06:18:47.583570   392 maintenance_manager.cc:643] P 57befd549e9740aebaffb34054751973: UndoDeltaBlockGCOp(e02f35ae36554678a4d8e93f65e387ad) complete. Timing: real 0.001s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":79,"lbm_reads_lt_1ms":4}
I20260812 06:18:47.584353   460 maintenance_manager.cc:419] P 57befd549e9740aebaffb34054751973: Scheduling FlushDeltaMemStoresOp(e02f35ae36554678a4d8e93f65e387ad): perf score=2.188937
I20260812 06:18:47.608103   392 maintenance_manager.cc:643] P 57befd549e9740aebaffb34054751973: FlushDeltaMemStoresOp(e02f35ae36554678a4d8e93f65e387ad) complete. Timing: real 0.023s	user 0.009s	sys 0.005s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6227,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:47.608762   460 maintenance_manager.cc:419] P 57befd549e9740aebaffb34054751973: Scheduling FlushDeltaMemStoresOp(e02f35ae36554678a4d8e93f65e387ad): perf score=2.188937
I20260812 06:18:47.625377   392 maintenance_manager.cc:643] P 57befd549e9740aebaffb34054751973: FlushDeltaMemStoresOp(e02f35ae36554678a4d8e93f65e387ad) complete. Timing: real 0.016s	user 0.009s	sys 0.005s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6592,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:47.625926   460 maintenance_manager.cc:419] P 57befd549e9740aebaffb34054751973: Scheduling MajorDeltaCompactionOp(e02f35ae36554678a4d8e93f65e387ad): perf score=1.000000
I20260812 06:18:47.774065   392 maintenance_manager.cc:643] P 57befd549e9740aebaffb34054751973: MajorDeltaCompactionOp(e02f35ae36554678a4d8e93f65e387ad) complete. Timing: real 0.148s	user 0.122s	sys 0.025s Metrics: {"cfile_cache_miss":433,"cfile_cache_miss_bytes":20631431,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":909,"lbm_read_time_us":10235,"lbm_reads_lt_1ms":469,"lbm_write_time_us":26590,"lbm_writes_lt_1ms":443,"mutex_wait_us":24,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":17536,"thread_start_us":328,"threads_started":5,"update_count":2000}
I20260812 06:18:47.774804   460 maintenance_manager.cc:419] P 57befd549e9740aebaffb34054751973: Scheduling FlushDeltaMemStoresOp(e02f35ae36554678a4d8e93f65e387ad): perf score=10.126437
I20260812 06:18:47.821718   392 maintenance_manager.cc:643] P 57befd549e9740aebaffb34054751973: FlushDeltaMemStoresOp(e02f35ae36554678a4d8e93f65e387ad) complete. Timing: real 0.047s	user 0.022s	sys 0.013s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":16651,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":302,"reinsert_count":0,"update_count":1500}
I20260812 06:18:47.822356   460 maintenance_manager.cc:419] P 57befd549e9740aebaffb34054751973: Scheduling FlushDeltaMemStoresOp(e02f35ae36554678a4d8e93f65e387ad): perf score=2.188937
I20260812 06:18:47.839986   392 maintenance_manager.cc:643] P 57befd549e9740aebaffb34054751973: FlushDeltaMemStoresOp(e02f35ae36554678a4d8e93f65e387ad) complete. Timing: real 0.017s	user 0.008s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6378,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:47.840586   460 maintenance_manager.cc:419] P 57befd549e9740aebaffb34054751973: Scheduling MajorDeltaCompactionOp(e02f35ae36554678a4d8e93f65e387ad): perf score=1.000000
I20260812 06:18:47.983733   392 maintenance_manager.cc:643] P 57befd549e9740aebaffb34054751973: MajorDeltaCompactionOp(e02f35ae36554678a4d8e93f65e387ad) complete. Timing: real 0.143s	user 0.111s	sys 0.032s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20631312,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":241,"lbm_read_time_us":9876,"lbm_reads_lt_1ms":472,"lbm_write_time_us":28332,"lbm_writes_lt_1ms":443,"mutex_wait_us":69,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":3456,"update_count":2000}
I20260812 06:18:47.984450   460 maintenance_manager.cc:419] P 57befd549e9740aebaffb34054751973: Scheduling FlushDeltaMemStoresOp(e02f35ae36554678a4d8e93f65e387ad): perf score=10.126437
I20260812 06:18:48.038808   392 maintenance_manager.cc:643] P 57befd549e9740aebaffb34054751973: FlushDeltaMemStoresOp(e02f35ae36554678a4d8e93f65e387ad) complete. Timing: real 0.054s	user 0.034s	sys 0.019s Metrics: {"bytes_written":12307491,"delete_count":0,"lbm_write_time_us":18465,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:18:48.039410   460 maintenance_manager.cc:419] P 57befd549e9740aebaffb34054751973: Scheduling FlushDeltaMemStoresOp(e02f35ae36554678a4d8e93f65e387ad): perf score=2.188937
I20260812 06:18:48.050524   392 maintenance_manager.cc:643] P 57befd549e9740aebaffb34054751973: FlushDeltaMemStoresOp(e02f35ae36554678a4d8e93f65e387ad) complete. Timing: real 0.011s	user 0.009s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4352,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:48.051195   460 maintenance_manager.cc:419] P 57befd549e9740aebaffb34054751973: Scheduling MajorDeltaCompactionOp(e02f35ae36554678a4d8e93f65e387ad): perf score=1.000000
I20260812 06:18:48.223815   392 maintenance_manager.cc:643] P 57befd549e9740aebaffb34054751973: MajorDeltaCompactionOp(e02f35ae36554678a4d8e93f65e387ad) complete. Timing: real 0.172s	user 0.113s	sys 0.052s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20631313,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":582,"lbm_read_time_us":11568,"lbm_reads_lt_1ms":472,"lbm_write_time_us":29680,"lbm_writes_lt_1ms":443,"mutex_wait_us":235,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":4352,"update_count":2000}
I20260812 06:18:48.224572   460 maintenance_manager.cc:419] P 57befd549e9740aebaffb34054751973: Scheduling FlushDeltaMemStoresOp(e02f35ae36554678a4d8e93f65e387ad): perf score=10.126437
I20260812 06:18:48.279316   392 maintenance_manager.cc:643] P 57befd549e9740aebaffb34054751973: FlushDeltaMemStoresOp(e02f35ae36554678a4d8e93f65e387ad) complete. Timing: real 0.055s	user 0.030s	sys 0.012s Metrics: {"bytes_written":12307492,"delete_count":0,"lbm_write_time_us":18617,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:18:48.279902   460 maintenance_manager.cc:419] P 57befd549e9740aebaffb34054751973: Scheduling FlushDeltaMemStoresOp(e02f35ae36554678a4d8e93f65e387ad): perf score=2.188937
I20260812 06:18:48.291602   392 maintenance_manager.cc:643] P 57befd549e9740aebaffb34054751973: FlushDeltaMemStoresOp(e02f35ae36554678a4d8e93f65e387ad) complete. Timing: real 0.012s	user 0.006s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4209,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:48.292331   460 maintenance_manager.cc:419] P 57befd549e9740aebaffb34054751973: Scheduling MajorDeltaCompactionOp(e02f35ae36554678a4d8e93f65e387ad): perf score=1.000000
I20260812 06:18:48.430953   392 maintenance_manager.cc:643] P 57befd549e9740aebaffb34054751973: MajorDeltaCompactionOp(e02f35ae36554678a4d8e93f65e387ad) complete. Timing: real 0.138s	user 0.114s	sys 0.024s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20631314,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":655,"lbm_read_time_us":8667,"lbm_reads_lt_1ms":472,"lbm_write_time_us":28553,"lbm_writes_lt_1ms":443,"mutex_wait_us":324,"peak_mem_usage":50689328,"reinsert_count":0,"update_count":2000}
I20260812 06:18:48.431743   460 maintenance_manager.cc:419] P 57befd549e9740aebaffb34054751973: Scheduling FlushDeltaMemStoresOp(e02f35ae36554678a4d8e93f65e387ad): perf score=10.126437
I20260812 06:18:48.462298   392 maintenance_manager.cc:643] P 57befd549e9740aebaffb34054751973: FlushDeltaMemStoresOp(e02f35ae36554678a4d8e93f65e387ad) complete. Timing: real 0.030s	user 0.024s	sys 0.004s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":13315,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:18:48.462918   460 maintenance_manager.cc:419] P 57befd549e9740aebaffb34054751973: Scheduling FlushDeltaMemStoresOp(e02f35ae36554678a4d8e93f65e387ad): perf score=2.188937
I20260812 06:18:48.478830   392 maintenance_manager.cc:643] P 57befd549e9740aebaffb34054751973: FlushDeltaMemStoresOp(e02f35ae36554678a4d8e93f65e387ad) complete. Timing: real 0.016s	user 0.015s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5579,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:48.479307   460 maintenance_manager.cc:419] P 57befd549e9740aebaffb34054751973: Scheduling MajorDeltaCompactionOp(e02f35ae36554678a4d8e93f65e387ad): perf score=1.000000
I20260812 06:18:48.618482   392 maintenance_manager.cc:643] P 57befd549e9740aebaffb34054751973: MajorDeltaCompactionOp(e02f35ae36554678a4d8e93f65e387ad) complete. Timing: real 0.139s	user 0.091s	sys 0.045s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20631312,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":1127,"lbm_read_time_us":9153,"lbm_reads_lt_1ms":472,"lbm_write_time_us":26590,"lbm_writes_lt_1ms":443,"mutex_wait_us":329,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":38528,"update_count":2000}
I20260812 06:18:48.619240   460 maintenance_manager.cc:419] P 57befd549e9740aebaffb34054751973: Scheduling FlushDeltaMemStoresOp(e02f35ae36554678a4d8e93f65e387ad): perf score=10.126437
I20260812 06:18:48.671766   392 maintenance_manager.cc:643] P 57befd549e9740aebaffb34054751973: FlushDeltaMemStoresOp(e02f35ae36554678a4d8e93f65e387ad) complete. Timing: real 0.052s	user 0.037s	sys 0.012s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":22256,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:18:48.672363   460 maintenance_manager.cc:419] P 57befd549e9740aebaffb34054751973: Scheduling FlushDeltaMemStoresOp(e02f35ae36554678a4d8e93f65e387ad): perf score=2.188937
I20260812 06:18:48.683545   392 maintenance_manager.cc:643] P 57befd549e9740aebaffb34054751973: FlushDeltaMemStoresOp(e02f35ae36554678a4d8e93f65e387ad) complete. Timing: real 0.011s	user 0.005s	sys 0.005s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4074,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:48.684171   460 maintenance_manager.cc:419] P 57befd549e9740aebaffb34054751973: Scheduling MajorDeltaCompactionOp(e02f35ae36554678a4d8e93f65e387ad): perf score=1.000000
I20260812 06:18:48.820829   392 maintenance_manager.cc:643] P 57befd549e9740aebaffb34054751973: MajorDeltaCompactionOp(e02f35ae36554678a4d8e93f65e387ad) complete. Timing: real 0.136s	user 0.098s	sys 0.038s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20631312,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":1107,"lbm_read_time_us":8987,"lbm_reads_lt_1ms":472,"lbm_write_time_us":24109,"lbm_writes_lt_1ms":443,"mutex_wait_us":291,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":21120,"update_count":2000}
I20260812 06:18:48.821527   460 maintenance_manager.cc:419] P 57befd549e9740aebaffb34054751973: Scheduling FlushDeltaMemStoresOp(e02f35ae36554678a4d8e93f65e387ad): perf score=10.126437
I20260812 06:18:48.873358   392 maintenance_manager.cc:643] P 57befd549e9740aebaffb34054751973: FlushDeltaMemStoresOp(e02f35ae36554678a4d8e93f65e387ad) complete. Timing: real 0.052s	user 0.022s	sys 0.019s Metrics: {"bytes_written":12307491,"delete_count":0,"lbm_write_time_us":15462,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:18:48.873997   460 maintenance_manager.cc:419] P 57befd549e9740aebaffb34054751973: Scheduling FlushDeltaMemStoresOp(e02f35ae36554678a4d8e93f65e387ad): perf score=2.188937
I20260812 06:18:48.886344   392 maintenance_manager.cc:643] P 57befd549e9740aebaffb34054751973: FlushDeltaMemStoresOp(e02f35ae36554678a4d8e93f65e387ad) complete. Timing: real 0.012s	user 0.007s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4772,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:48.887059   460 maintenance_manager.cc:419] P 57befd549e9740aebaffb34054751973: Scheduling FlushMRSOp(e02f35ae36554678a4d8e93f65e387ad): perf score=1.000000
I20260812 06:18:48.922930   392 maintenance_manager.cc:643] P 57befd549e9740aebaffb34054751973: FlushMRSOp(e02f35ae36554678a4d8e93f65e387ad) complete. Timing: real 0.036s	user 0.033s	sys 0.000s Metrics: {"bytes_written":1152509,"cfile_init":1,"dirs.queue_time_us":97,"dirs.run_cpu_time_us":269,"dirs.run_wall_time_us":1908,"drs_written":1,"lbm_read_time_us":63,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1937,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":28}
I20260812 06:18:48.924031   460 maintenance_manager.cc:419] P 57befd549e9740aebaffb34054751973: Scheduling UndoDeltaBlockGCOp(e02f35ae36554678a4d8e93f65e387ad): 447 bytes on disk
I20260812 06:18:48.924890   392 maintenance_manager.cc:643] P 57befd549e9740aebaffb34054751973: UndoDeltaBlockGCOp(e02f35ae36554678a4d8e93f65e387ad) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":99,"lbm_reads_lt_1ms":4}
I20260812 06:18:48.925482   460 maintenance_manager.cc:419] P 57befd549e9740aebaffb34054751973: Scheduling MajorDeltaCompactionOp(e02f35ae36554678a4d8e93f65e387ad): perf score=1.000000
I20260812 06:18:49.098160   392 maintenance_manager.cc:643] P 57befd549e9740aebaffb34054751973: MajorDeltaCompactionOp(e02f35ae36554678a4d8e93f65e387ad) complete. Timing: real 0.172s	user 0.109s	sys 0.052s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20631313,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":948,"lbm_read_time_us":9899,"lbm_reads_lt_1ms":464,"lbm_write_time_us":28016,"lbm_writes_lt_1ms":443,"mutex_wait_us":58,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":18176,"update_count":2000}
I20260812 06:18:49.098902   460 maintenance_manager.cc:419] P 57befd549e9740aebaffb34054751973: Scheduling LogGCOp(e02f35ae36554678a4d8e93f65e387ad): free 112692366 bytes of WAL
I20260812 06:18:49.099150   392 log_reader.cc:385] T e02f35ae36554678a4d8e93f65e387ad: removed 11 log segments from log reader
I20260812 06:18:49.099215   392 log.cc:1079] T e02f35ae36554678a4d8e93f65e387ad P 57befd549e9740aebaffb34054751973: Deleting log segment in path: /tmp/dist-test-taskyiE61X/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515526977841-32748-0/minicluster-data/ts-0-root/wals/e02f35ae36554678a4d8e93f65e387ad/wal-000000003 (ops 11-15)
I20260812 06:18:49.099275   392 log.cc:1079] T e02f35ae36554678a4d8e93f65e387ad P 57befd549e9740aebaffb34054751973: Deleting log segment in path: /tmp/dist-test-taskyiE61X/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515526977841-32748-0/minicluster-data/ts-0-root/wals/e02f35ae36554678a4d8e93f65e387ad/wal-000000004 (ops 16-20)
I20260812 06:18:49.099316   392 log.cc:1079] T e02f35ae36554678a4d8e93f65e387ad P 57befd549e9740aebaffb34054751973: Deleting log segment in path: /tmp/dist-test-taskyiE61X/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515526977841-32748-0/minicluster-data/ts-0-root/wals/e02f35ae36554678a4d8e93f65e387ad/wal-000000005 (ops 21-25)
I20260812 06:18:49.099359   392 log.cc:1079] T e02f35ae36554678a4d8e93f65e387ad P 57befd549e9740aebaffb34054751973: Deleting log segment in path: /tmp/dist-test-taskyiE61X/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515526977841-32748-0/minicluster-data/ts-0-root/wals/e02f35ae36554678a4d8e93f65e387ad/wal-000000006 (ops 26-30)
I20260812 06:18:49.099400   392 log.cc:1079] T e02f35ae36554678a4d8e93f65e387ad P 57befd549e9740aebaffb34054751973: Deleting log segment in path: /tmp/dist-test-taskyiE61X/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515526977841-32748-0/minicluster-data/ts-0-root/wals/e02f35ae36554678a4d8e93f65e387ad/wal-000000007 (ops 31-35)
I20260812 06:18:49.099442   392 log.cc:1079] T e02f35ae36554678a4d8e93f65e387ad P 57befd549e9740aebaffb34054751973: Deleting log segment in path: /tmp/dist-test-taskyiE61X/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515526977841-32748-0/minicluster-data/ts-0-root/wals/e02f35ae36554678a4d8e93f65e387ad/wal-000000008 (ops 36-40)
I20260812 06:18:49.099481   392 log.cc:1079] T e02f35ae36554678a4d8e93f65e387ad P 57befd549e9740aebaffb34054751973: Deleting log segment in path: /tmp/dist-test-taskyiE61X/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515526977841-32748-0/minicluster-data/ts-0-root/wals/e02f35ae36554678a4d8e93f65e387ad/wal-000000009 (ops 41-45)
I20260812 06:18:49.099529   392 log.cc:1079] T e02f35ae36554678a4d8e93f65e387ad P 57befd549e9740aebaffb34054751973: Deleting log segment in path: /tmp/dist-test-taskyiE61X/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515526977841-32748-0/minicluster-data/ts-0-root/wals/e02f35ae36554678a4d8e93f65e387ad/wal-000000010 (ops 46-50)
I20260812 06:18:49.099570   392 log.cc:1079] T e02f35ae36554678a4d8e93f65e387ad P 57befd549e9740aebaffb34054751973: Deleting log segment in path: /tmp/dist-test-taskyiE61X/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515526977841-32748-0/minicluster-data/ts-0-root/wals/e02f35ae36554678a4d8e93f65e387ad/wal-000000011 (ops 51-55)
I20260812 06:18:49.099613   392 log.cc:1079] T e02f35ae36554678a4d8e93f65e387ad P 57befd549e9740aebaffb34054751973: Deleting log segment in path: /tmp/dist-test-taskyiE61X/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515526977841-32748-0/minicluster-data/ts-0-root/wals/e02f35ae36554678a4d8e93f65e387ad/wal-000000012 (ops 56-60)
I20260812 06:18:49.099654   392 log.cc:1079] T e02f35ae36554678a4d8e93f65e387ad P 57befd549e9740aebaffb34054751973: Deleting log segment in path: /tmp/dist-test-taskyiE61X/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515526977841-32748-0/minicluster-data/ts-0-root/wals/e02f35ae36554678a4d8e93f65e387ad/wal-000000013 (ops 61-65)
I20260812 06:18:49.128715   392 maintenance_manager.cc:643] P 57befd549e9740aebaffb34054751973: LogGCOp(e02f35ae36554678a4d8e93f65e387ad) complete. Timing: real 0.030s	user 0.001s	sys 0.028s Metrics: {}
I20260812 06:18:49.129316   460 maintenance_manager.cc:419] P 57befd549e9740aebaffb34054751973: Scheduling FlushDeltaMemStoresOp(e02f35ae36554678a4d8e93f65e387ad): perf score=14.095187
I20260812 06:18:49.192952   392 maintenance_manager.cc:643] P 57befd549e9740aebaffb34054751973: FlushDeltaMemStoresOp(e02f35ae36554678a4d8e93f65e387ad) complete. Timing: real 0.063s	user 0.033s	sys 0.024s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":26775,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:18:49.193482   460 maintenance_manager.cc:419] P 57befd549e9740aebaffb34054751973: Scheduling FlushDeltaMemStoresOp(e02f35ae36554678a4d8e93f65e387ad): perf score=3.181125
I20260812 06:18:49.207367   392 maintenance_manager.cc:643] P 57befd549e9740aebaffb34054751973: FlushDeltaMemStoresOp(e02f35ae36554678a4d8e93f65e387ad) complete. Timing: real 0.014s	user 0.009s	sys 0.004s Metrics: {"bytes_written":4512904,"delete_count":0,"lbm_write_time_us":4827,"lbm_writes_lt_1ms":113,"reinsert_count":0,"update_count":550}
I20260812 06:18:49.207940   460 maintenance_manager.cc:419] P 57befd549e9740aebaffb34054751973: Scheduling FlushDeltaMemStoresOp(e02f35ae36554678a4d8e93f65e387ad): perf score=2.188937
I20260812 06:18:49.227442   392 maintenance_manager.cc:643] P 57befd549e9740aebaffb34054751973: FlushDeltaMemStoresOp(e02f35ae36554678a4d8e93f65e387ad) complete. Timing: real 0.019s	user 0.011s	sys 0.007s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":4182,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:18:49.228124   460 maintenance_manager.cc:419] P 57befd549e9740aebaffb34054751973: Scheduling MajorDeltaCompactionOp(e02f35ae36554678a4d8e93f65e387ad): perf score=1.000000
I20260812 06:18:49.449105   392 maintenance_manager.cc:643] P 57befd549e9740aebaffb34054751973: MajorDeltaCompactionOp(e02f35ae36554678a4d8e93f65e387ad) complete. Timing: real 0.221s	user 0.166s	sys 0.052s Metrics: {"cfile_cache_miss":633,"cfile_cache_miss_bytes":28836246,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":635,"lbm_read_time_us":15211,"lbm_reads_lt_1ms":673,"lbm_write_time_us":36498,"lbm_writes_lt_1ms":643,"mutex_wait_us":76,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":768,"update_count":3000}
I20260812 06:18:49.449842   460 maintenance_manager.cc:419] P 57befd549e9740aebaffb34054751973: Scheduling FlushDeltaMemStoresOp(e02f35ae36554678a4d8e93f65e387ad): perf score=14.095187
I20260812 06:18:49.515923   392 maintenance_manager.cc:643] P 57befd549e9740aebaffb34054751973: FlushDeltaMemStoresOp(e02f35ae36554678a4d8e93f65e387ad) complete. Timing: real 0.066s	user 0.026s	sys 0.027s Metrics: {"bytes_written":16409898,"delete_count":0,"lbm_write_time_us":18350,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:18:49.516716   460 maintenance_manager.cc:419] P 57befd549e9740aebaffb34054751973: Scheduling FlushDeltaMemStoresOp(e02f35ae36554678a4d8e93f65e387ad): perf score=2.188937
I20260812 06:18:49.533746   392 maintenance_manager.cc:643] P 57befd549e9740aebaffb34054751973: FlushDeltaMemStoresOp(e02f35ae36554678a4d8e93f65e387ad) complete. Timing: real 0.017s	user 0.011s	sys 0.003s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6396,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:49.534562   460 maintenance_manager.cc:419] P 57befd549e9740aebaffb34054751973: Scheduling MajorDeltaCompactionOp(e02f35ae36554678a4d8e93f65e387ad): perf score=1.000000
I20260812 06:18:49.733000   392 maintenance_manager.cc:643] P 57befd549e9740aebaffb34054751973: MajorDeltaCompactionOp(e02f35ae36554678a4d8e93f65e387ad) complete. Timing: real 0.198s	user 0.111s	sys 0.084s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24733720,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":216,"lbm_read_time_us":14288,"lbm_reads_lt_1ms":572,"lbm_write_time_us":31934,"lbm_writes_lt_1ms":543,"mutex_wait_us":50,"peak_mem_usage":63115900,"reinsert_count":0,"update_count":2500}
I20260812 06:18:49.733847   460 maintenance_manager.cc:419] P 57befd549e9740aebaffb34054751973: Scheduling FlushDeltaMemStoresOp(e02f35ae36554678a4d8e93f65e387ad): perf score=11.118625
I20260812 06:18:49.772095   392 maintenance_manager.cc:643] P 57befd549e9740aebaffb34054751973: FlushDeltaMemStoresOp(e02f35ae36554678a4d8e93f65e387ad) complete. Timing: real 0.038s	user 0.025s	sys 0.011s Metrics: {"bytes_written":12717735,"delete_count":0,"lbm_write_time_us":16743,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:18:49.772907   460 maintenance_manager.cc:419] P 57befd549e9740aebaffb34054751973: Scheduling FlushDeltaMemStoresOp(e02f35ae36554678a4d8e93f65e387ad): perf score=2.188937
I20260812 06:18:49.793687   392 maintenance_manager.cc:643] P 57befd549e9740aebaffb34054751973: FlushDeltaMemStoresOp(e02f35ae36554678a4d8e93f65e387ad) complete. Timing: real 0.021s	user 0.013s	sys 0.000s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":5751,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:18:49.794163   460 maintenance_manager.cc:419] P 57befd549e9740aebaffb34054751973: Scheduling MajorDeltaCompactionOp(e02f35ae36554678a4d8e93f65e387ad): perf score=1.000000
I20260812 06:18:49.923265   392 maintenance_manager.cc:643] P 57befd549e9740aebaffb34054751973: MajorDeltaCompactionOp(e02f35ae36554678a4d8e93f65e387ad) complete. Timing: real 0.129s	user 0.108s	sys 0.020s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20631303,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":84,"lbm_read_time_us":7105,"lbm_reads_lt_1ms":464,"lbm_write_time_us":25581,"lbm_writes_lt_1ms":443,"mutex_wait_us":28,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":21888,"update_count":2000}
I20260812 06:18:49.924017   460 maintenance_manager.cc:419] P 57befd549e9740aebaffb34054751973: Scheduling FlushDeltaMemStoresOp(e02f35ae36554678a4d8e93f65e387ad): perf score=10.126437
I20260812 06:18:49.963944   392 maintenance_manager.cc:643] P 57befd549e9740aebaffb34054751973: FlushDeltaMemStoresOp(e02f35ae36554678a4d8e93f65e387ad) complete. Timing: real 0.040s	user 0.021s	sys 0.017s Metrics: {"bytes_written":12307491,"delete_count":0,"lbm_write_time_us":16116,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:18:49.964599   460 maintenance_manager.cc:419] P 57befd549e9740aebaffb34054751973: Scheduling FlushDeltaMemStoresOp(e02f35ae36554678a4d8e93f65e387ad): perf score=2.188937
I20260812 06:18:49.980858   392 maintenance_manager.cc:643] P 57befd549e9740aebaffb34054751973: FlushDeltaMemStoresOp(e02f35ae36554678a4d8e93f65e387ad) complete. Timing: real 0.016s	user 0.013s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6135,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:49.981706   460 maintenance_manager.cc:419] P 57befd549e9740aebaffb34054751973: Scheduling MajorDeltaCompactionOp(e02f35ae36554678a4d8e93f65e387ad): perf score=1.000000
I20260812 06:18:50.131736   392 maintenance_manager.cc:643] P 57befd549e9740aebaffb34054751973: MajorDeltaCompactionOp(e02f35ae36554678a4d8e93f65e387ad) complete. Timing: real 0.150s	user 0.130s	sys 0.019s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20631313,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":845,"lbm_read_time_us":10677,"lbm_reads_lt_1ms":472,"lbm_write_time_us":29418,"lbm_writes_lt_1ms":443,"mutex_wait_us":264,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":8832,"update_count":2000}
I20260812 06:18:50.132460   460 maintenance_manager.cc:419] P 57befd549e9740aebaffb34054751973: Scheduling FlushDeltaMemStoresOp(e02f35ae36554678a4d8e93f65e387ad): perf score=10.126437
I20260812 06:18:50.189543   392 maintenance_manager.cc:643] P 57befd549e9740aebaffb34054751973: FlushDeltaMemStoresOp(e02f35ae36554678a4d8e93f65e387ad) complete. Timing: real 0.057s	user 0.030s	sys 0.012s Metrics: {"bytes_written":12307489,"delete_count":0,"lbm_write_time_us":19234,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:18:50.190346   460 maintenance_manager.cc:419] P 57befd549e9740aebaffb34054751973: Scheduling FlushDeltaMemStoresOp(e02f35ae36554678a4d8e93f65e387ad): perf score=2.188937
I20260812 06:18:50.208900   392 maintenance_manager.cc:643] P 57befd549e9740aebaffb34054751973: FlushDeltaMemStoresOp(e02f35ae36554678a4d8e93f65e387ad) complete. Timing: real 0.018s	user 0.012s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6869,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:50.209595   460 maintenance_manager.cc:419] P 57befd549e9740aebaffb34054751973: Scheduling MajorDeltaCompactionOp(e02f35ae36554678a4d8e93f65e387ad): perf score=1.000000
I20260812 06:18:50.361204   392 maintenance_manager.cc:643] P 57befd549e9740aebaffb34054751973: MajorDeltaCompactionOp(e02f35ae36554678a4d8e93f65e387ad) complete. Timing: real 0.151s	user 0.123s	sys 0.024s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20631311,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":1818,"lbm_read_time_us":10286,"lbm_reads_lt_1ms":472,"lbm_write_time_us":28927,"lbm_writes_lt_1ms":443,"mutex_wait_us":726,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":92288,"update_count":2000}
I20260812 06:18:50.361850   460 maintenance_manager.cc:419] P 57befd549e9740aebaffb34054751973: Scheduling FlushDeltaMemStoresOp(e02f35ae36554678a4d8e93f65e387ad): perf score=10.126437
I20260812 06:18:50.433585   392 maintenance_manager.cc:643] P 57befd549e9740aebaffb34054751973: FlushDeltaMemStoresOp(e02f35ae36554678a4d8e93f65e387ad) complete. Timing: real 0.071s	user 0.022s	sys 0.027s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":19599,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":302,"reinsert_count":0,"update_count":1500}
I20260812 06:18:50.434417   460 maintenance_manager.cc:419] P 57befd549e9740aebaffb34054751973: Scheduling FlushDeltaMemStoresOp(e02f35ae36554678a4d8e93f65e387ad): perf score=2.188937
I20260812 06:18:50.445998   392 maintenance_manager.cc:643] P 57befd549e9740aebaffb34054751973: FlushDeltaMemStoresOp(e02f35ae36554678a4d8e93f65e387ad) complete. Timing: real 0.011s	user 0.009s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4332,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:50.446604   460 maintenance_manager.cc:419] P 57befd549e9740aebaffb34054751973: Scheduling MajorDeltaCompactionOp(e02f35ae36554678a4d8e93f65e387ad): perf score=1.000000
I20260812 06:18:50.614312   392 maintenance_manager.cc:643] P 57befd549e9740aebaffb34054751973: MajorDeltaCompactionOp(e02f35ae36554678a4d8e93f65e387ad) complete. Timing: real 0.167s	user 0.118s	sys 0.049s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20631312,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":412,"lbm_read_time_us":10851,"lbm_reads_lt_1ms":472,"lbm_write_time_us":27501,"lbm_writes_lt_1ms":443,"mutex_wait_us":33,"peak_mem_usage":50689328,"reinsert_count":0,"update_count":2000}
I20260812 06:18:50.615118   460 maintenance_manager.cc:419] P 57befd549e9740aebaffb34054751973: Scheduling FlushDeltaMemStoresOp(e02f35ae36554678a4d8e93f65e387ad): perf score=10.126437
I20260812 06:18:50.659570   392 maintenance_manager.cc:643] P 57befd549e9740aebaffb34054751973: FlushDeltaMemStoresOp(e02f35ae36554678a4d8e93f65e387ad) complete. Timing: real 0.044s	user 0.024s	sys 0.013s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":16806,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:18:50.660140   460 maintenance_manager.cc:419] P 57befd549e9740aebaffb34054751973: Scheduling FlushDeltaMemStoresOp(e02f35ae36554678a4d8e93f65e387ad): perf score=2.188937
I20260812 06:18:50.674036   392 maintenance_manager.cc:643] P 57befd549e9740aebaffb34054751973: FlushDeltaMemStoresOp(e02f35ae36554678a4d8e93f65e387ad) complete. Timing: real 0.014s	user 0.011s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4998,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:50.674939   460 maintenance_manager.cc:419] P 57befd549e9740aebaffb34054751973: Scheduling FlushMRSOp(e02f35ae36554678a4d8e93f65e387ad): perf score=1.000000
I20260812 06:18:50.712071   392 maintenance_manager.cc:643] P 57befd549e9740aebaffb34054751973: FlushMRSOp(e02f35ae36554678a4d8e93f65e387ad) complete. Timing: real 0.037s	user 0.031s	sys 0.004s Metrics: {"bytes_written":1275449,"cfile_init":1,"dirs.queue_time_us":174,"dirs.run_cpu_time_us":247,"dirs.run_wall_time_us":1740,"drs_written":1,"lbm_read_time_us":100,"lbm_reads_lt_1ms":4,"lbm_write_time_us":2473,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":31}
I20260812 06:18:50.712949   460 maintenance_manager.cc:419] P 57befd549e9740aebaffb34054751973: Scheduling LogGCOp(e02f35ae36554678a4d8e93f65e387ad): free 124257248 bytes of WAL
I20260812 06:18:50.713234   392 log_reader.cc:385] T e02f35ae36554678a4d8e93f65e387ad: removed 12 log segments from log reader
I20260812 06:18:50.713304   392 log.cc:1079] T e02f35ae36554678a4d8e93f65e387ad P 57befd549e9740aebaffb34054751973: Deleting log segment in path: /tmp/dist-test-taskyiE61X/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515526977841-32748-0/minicluster-data/ts-0-root/wals/e02f35ae36554678a4d8e93f65e387ad/wal-000000014 (ops 66-70)
I20260812 06:18:50.713364   392 log.cc:1079] T e02f35ae36554678a4d8e93f65e387ad P 57befd549e9740aebaffb34054751973: Deleting log segment in path: /tmp/dist-test-taskyiE61X/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515526977841-32748-0/minicluster-data/ts-0-root/wals/e02f35ae36554678a4d8e93f65e387ad/wal-000000015 (ops 71-74)
I20260812 06:18:50.713431   392 log.cc:1079] T e02f35ae36554678a4d8e93f65e387ad P 57befd549e9740aebaffb34054751973: Deleting log segment in path: /tmp/dist-test-taskyiE61X/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515526977841-32748-0/minicluster-data/ts-0-root/wals/e02f35ae36554678a4d8e93f65e387ad/wal-000000016 (ops 75-79)
I20260812 06:18:50.713476   392 log.cc:1079] T e02f35ae36554678a4d8e93f65e387ad P 57befd549e9740aebaffb34054751973: Deleting log segment in path: /tmp/dist-test-taskyiE61X/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515526977841-32748-0/minicluster-data/ts-0-root/wals/e02f35ae36554678a4d8e93f65e387ad/wal-000000017 (ops 80-84)
I20260812 06:18:50.713518   392 log.cc:1079] T e02f35ae36554678a4d8e93f65e387ad P 57befd549e9740aebaffb34054751973: Deleting log segment in path: /tmp/dist-test-taskyiE61X/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515526977841-32748-0/minicluster-data/ts-0-root/wals/e02f35ae36554678a4d8e93f65e387ad/wal-000000018 (ops 85-89)
I20260812 06:18:50.713562   392 log.cc:1079] T e02f35ae36554678a4d8e93f65e387ad P 57befd549e9740aebaffb34054751973: Deleting log segment in path: /tmp/dist-test-taskyiE61X/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515526977841-32748-0/minicluster-data/ts-0-root/wals/e02f35ae36554678a4d8e93f65e387ad/wal-000000019 (ops 90-94)
I20260812 06:18:50.713603   392 log.cc:1079] T e02f35ae36554678a4d8e93f65e387ad P 57befd549e9740aebaffb34054751973: Deleting log segment in path: /tmp/dist-test-taskyiE61X/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515526977841-32748-0/minicluster-data/ts-0-root/wals/e02f35ae36554678a4d8e93f65e387ad/wal-000000020 (ops 95-99)
I20260812 06:18:50.713644   392 log.cc:1079] T e02f35ae36554678a4d8e93f65e387ad P 57befd549e9740aebaffb34054751973: Deleting log segment in path: /tmp/dist-test-taskyiE61X/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515526977841-32748-0/minicluster-data/ts-0-root/wals/e02f35ae36554678a4d8e93f65e387ad/wal-000000021 (ops 100-104)
I20260812 06:18:50.713686   392 log.cc:1079] T e02f35ae36554678a4d8e93f65e387ad P 57befd549e9740aebaffb34054751973: Deleting log segment in path: /tmp/dist-test-taskyiE61X/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515526977841-32748-0/minicluster-data/ts-0-root/wals/e02f35ae36554678a4d8e93f65e387ad/wal-000000022 (ops 105-109)
I20260812 06:18:50.713729   392 log.cc:1079] T e02f35ae36554678a4d8e93f65e387ad P 57befd549e9740aebaffb34054751973: Deleting log segment in path: /tmp/dist-test-taskyiE61X/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515526977841-32748-0/minicluster-data/ts-0-root/wals/e02f35ae36554678a4d8e93f65e387ad/wal-000000023 (ops 110-114)
I20260812 06:18:50.713770   392 log.cc:1079] T e02f35ae36554678a4d8e93f65e387ad P 57befd549e9740aebaffb34054751973: Deleting log segment in path: /tmp/dist-test-taskyiE61X/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515526977841-32748-0/minicluster-data/ts-0-root/wals/e02f35ae36554678a4d8e93f65e387ad/wal-000000024 (ops 115-119)
I20260812 06:18:50.713811   392 log.cc:1079] T e02f35ae36554678a4d8e93f65e387ad P 57befd549e9740aebaffb34054751973: Deleting log segment in path: /tmp/dist-test-taskyiE61X/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515526977841-32748-0/minicluster-data/ts-0-root/wals/e02f35ae36554678a4d8e93f65e387ad/wal-000000025 (ops 120-124)
I20260812 06:18:50.744946   392 maintenance_manager.cc:643] P 57befd549e9740aebaffb34054751973: LogGCOp(e02f35ae36554678a4d8e93f65e387ad) complete. Timing: real 0.032s	user 0.000s	sys 0.030s Metrics: {}
I20260812 06:18:50.745500   460 maintenance_manager.cc:419] P 57befd549e9740aebaffb34054751973: Scheduling UndoDeltaBlockGCOp(e02f35ae36554678a4d8e93f65e387ad): 483 bytes on disk
I20260812 06:18:50.746047   392 maintenance_manager.cc:643] P 57befd549e9740aebaffb34054751973: UndoDeltaBlockGCOp(e02f35ae36554678a4d8e93f65e387ad) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":60,"lbm_reads_lt_1ms":4}
I20260812 06:18:50.746591   460 maintenance_manager.cc:419] P 57befd549e9740aebaffb34054751973: Scheduling FlushDeltaMemStoresOp(e02f35ae36554678a4d8e93f65e387ad): perf score=5.165500
I20260812 06:18:50.774241   392 maintenance_manager.cc:643] P 57befd549e9740aebaffb34054751973: FlushDeltaMemStoresOp(e02f35ae36554678a4d8e93f65e387ad) complete. Timing: real 0.027s	user 0.012s	sys 0.012s Metrics: {"bytes_written":6728210,"delete_count":0,"lbm_write_time_us":7975,"lbm_writes_lt_1ms":167,"reinsert_count":0,"update_count":820}
I20260812 06:18:50.775064   460 maintenance_manager.cc:419] P 57befd549e9740aebaffb34054751973: Scheduling FlushDeltaMemStoresOp(e02f35ae36554678a4d8e93f65e387ad): perf score=1.000000
I20260812 06:18:50.783517   392 maintenance_manager.cc:643] P 57befd549e9740aebaffb34054751973: FlushDeltaMemStoresOp(e02f35ae36554678a4d8e93f65e387ad) complete. Timing: real 0.008s	user 0.007s	sys 0.001s Metrics: {"bytes_written":1477052,"delete_count":0,"lbm_write_time_us":2655,"lbm_writes_lt_1ms":39,"reinsert_count":0,"update_count":180}
I20260812 06:18:50.784075   460 maintenance_manager.cc:419] P 57befd549e9740aebaffb34054751973: Scheduling MajorDeltaCompactionOp(e02f35ae36554678a4d8e93f65e387ad): perf score=1.000000
I20260812 06:18:51.002488   392 maintenance_manager.cc:643] P 57befd549e9740aebaffb34054751973: MajorDeltaCompactionOp(e02f35ae36554678a4d8e93f65e387ad) complete. Timing: real 0.218s	user 0.162s	sys 0.055s Metrics: {"cfile_cache_miss":634,"cfile_cache_miss_bytes":28836313,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":1551,"lbm_read_time_us":15103,"lbm_reads_lt_1ms":674,"lbm_write_time_us":39110,"lbm_writes_lt_1ms":643,"mutex_wait_us":250,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":768,"thread_start_us":92,"threads_started":1,"update_count":3000}
I20260812 06:18:51.003268   460 maintenance_manager.cc:419] P 57befd549e9740aebaffb34054751973: Scheduling FlushDeltaMemStoresOp(e02f35ae36554678a4d8e93f65e387ad): perf score=14.095187
I20260812 06:18:51.068838   392 maintenance_manager.cc:643] P 57befd549e9740aebaffb34054751973: FlushDeltaMemStoresOp(e02f35ae36554678a4d8e93f65e387ad) complete. Timing: real 0.065s	user 0.039s	sys 0.023s Metrics: {"bytes_written":16409898,"delete_count":0,"lbm_write_time_us":27110,"lbm_writes_1-10_ms":2,"lbm_writes_lt_1ms":401,"reinsert_count":0,"update_count":2000}
I20260812 06:18:51.069442   460 maintenance_manager.cc:419] P 57befd549e9740aebaffb34054751973: Scheduling FlushDeltaMemStoresOp(e02f35ae36554678a4d8e93f65e387ad): perf score=2.188937
I20260812 06:18:51.087817   392 maintenance_manager.cc:643] P 57befd549e9740aebaffb34054751973: FlushDeltaMemStoresOp(e02f35ae36554678a4d8e93f65e387ad) complete. Timing: real 0.018s	user 0.007s	sys 0.005s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5137,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:51.088480   460 maintenance_manager.cc:419] P 57befd549e9740aebaffb34054751973: Scheduling FlushDeltaMemStoresOp(e02f35ae36554678a4d8e93f65e387ad): perf score=2.188937
I20260812 06:18:51.105423   392 maintenance_manager.cc:643] P 57befd549e9740aebaffb34054751973: FlushDeltaMemStoresOp(e02f35ae36554678a4d8e93f65e387ad) complete. Timing: real 0.017s	user 0.014s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6351,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:51.106316   460 maintenance_manager.cc:419] P 57befd549e9740aebaffb34054751973: Scheduling MajorDeltaCompactionOp(e02f35ae36554678a4d8e93f65e387ad): perf score=1.000000
I20260812 06:18:51.315508   392 maintenance_manager.cc:643] P 57befd549e9740aebaffb34054751973: MajorDeltaCompactionOp(e02f35ae36554678a4d8e93f65e387ad) complete. Timing: real 0.209s	user 0.142s	sys 0.067s Metrics: {"cfile_cache_miss":633,"cfile_cache_miss_bytes":28836251,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":373,"lbm_read_time_us":17275,"lbm_reads_lt_1ms":673,"lbm_write_time_us":32975,"lbm_writes_lt_1ms":643,"mutex_wait_us":33,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":13056,"update_count":3000}
I20260812 06:18:51.316359   460 maintenance_manager.cc:419] P 57befd549e9740aebaffb34054751973: Scheduling FlushDeltaMemStoresOp(e02f35ae36554678a4d8e93f65e387ad): perf score=14.095187
I20260812 06:18:51.368536   392 maintenance_manager.cc:643] P 57befd549e9740aebaffb34054751973: FlushDeltaMemStoresOp(e02f35ae36554678a4d8e93f65e387ad) complete. Timing: real 0.052s	user 0.022s	sys 0.028s Metrics: {"bytes_written":16409904,"delete_count":0,"lbm_write_time_us":23303,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:18:51.369187   460 maintenance_manager.cc:419] P 57befd549e9740aebaffb34054751973: Scheduling FlushDeltaMemStoresOp(e02f35ae36554678a4d8e93f65e387ad): perf score=2.188937
I20260812 06:18:51.388880   392 maintenance_manager.cc:643] P 57befd549e9740aebaffb34054751973: FlushDeltaMemStoresOp(e02f35ae36554678a4d8e93f65e387ad) complete. Timing: real 0.019s	user 0.013s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":8126,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:51.389513   460 maintenance_manager.cc:419] P 57befd549e9740aebaffb34054751973: Scheduling MajorDeltaCompactionOp(e02f35ae36554678a4d8e93f65e387ad): perf score=1.000000
I20260812 06:18:51.584103   392 maintenance_manager.cc:643] P 57befd549e9740aebaffb34054751973: MajorDeltaCompactionOp(e02f35ae36554678a4d8e93f65e387ad) complete. Timing: real 0.194s	user 0.123s	sys 0.061s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24733726,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":8548,"lbm_read_time_us":13849,"lbm_reads_lt_1ms":568,"lbm_write_time_us":33097,"lbm_writes_lt_1ms":543,"mutex_wait_us":4450,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":19200,"update_count":2500}
I20260812 06:18:51.585461   460 maintenance_manager.cc:419] P 57befd549e9740aebaffb34054751973: Scheduling FlushDeltaMemStoresOp(e02f35ae36554678a4d8e93f65e387ad): perf score=14.095187
I20260812 06:18:51.651976   392 maintenance_manager.cc:643] P 57befd549e9740aebaffb34054751973: FlushDeltaMemStoresOp(e02f35ae36554678a4d8e93f65e387ad) complete. Timing: real 0.065s	user 0.042s	sys 0.021s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":24648,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:18:51.652617   460 maintenance_manager.cc:419] P 57befd549e9740aebaffb34054751973: Scheduling FlushDeltaMemStoresOp(e02f35ae36554678a4d8e93f65e387ad): perf score=2.188937
I20260812 06:18:51.663882   392 maintenance_manager.cc:643] P 57befd549e9740aebaffb34054751973: FlushDeltaMemStoresOp(e02f35ae36554678a4d8e93f65e387ad) complete. Timing: real 0.011s	user 0.005s	sys 0.005s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4257,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:51.664590   460 maintenance_manager.cc:419] P 57befd549e9740aebaffb34054751973: Scheduling MajorDeltaCompactionOp(e02f35ae36554678a4d8e93f65e387ad): perf score=1.000000
I20260812 06:18:51.861285   392 maintenance_manager.cc:643] P 57befd549e9740aebaffb34054751973: MajorDeltaCompactionOp(e02f35ae36554678a4d8e93f65e387ad) complete. Timing: real 0.196s	user 0.133s	sys 0.052s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24733723,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":810,"lbm_read_time_us":13351,"lbm_reads_lt_1ms":572,"lbm_write_time_us":31886,"lbm_writes_lt_1ms":543,"mutex_wait_us":295,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":21888,"update_count":2500}
I20260812 06:18:51.862064   460 maintenance_manager.cc:419] P 57befd549e9740aebaffb34054751973: Scheduling FlushDeltaMemStoresOp(e02f35ae36554678a4d8e93f65e387ad): perf score=14.095187
I20260812 06:18:51.926867   392 maintenance_manager.cc:643] P 57befd549e9740aebaffb34054751973: FlushDeltaMemStoresOp(e02f35ae36554678a4d8e93f65e387ad) complete. Timing: real 0.065s	user 0.048s	sys 0.016s Metrics: {"bytes_written":16409906,"delete_count":0,"lbm_write_time_us":25043,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:18:51.927568   460 maintenance_manager.cc:419] P 57befd549e9740aebaffb34054751973: Scheduling FlushDeltaMemStoresOp(e02f35ae36554678a4d8e93f65e387ad): perf score=2.188937
I20260812 06:18:51.939134   392 maintenance_manager.cc:643] P 57befd549e9740aebaffb34054751973: FlushDeltaMemStoresOp(e02f35ae36554678a4d8e93f65e387ad) complete. Timing: real 0.011s	user 0.010s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4370,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:51.939750   460 maintenance_manager.cc:419] P 57befd549e9740aebaffb34054751973: Scheduling MajorDeltaCompactionOp(e02f35ae36554678a4d8e93f65e387ad): perf score=1.000000
I20260812 06:18:52.130874   392 maintenance_manager.cc:643] P 57befd549e9740aebaffb34054751973: MajorDeltaCompactionOp(e02f35ae36554678a4d8e93f65e387ad) complete. Timing: real 0.191s	user 0.134s	sys 0.044s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24733728,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":637,"lbm_read_time_us":13519,"lbm_reads_lt_1ms":572,"lbm_write_time_us":30408,"lbm_writes_lt_1ms":543,"mutex_wait_us":24,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":13184,"update_count":2500}
I20260812 06:18:52.131559   460 maintenance_manager.cc:419] P 57befd549e9740aebaffb34054751973: Scheduling FlushDeltaMemStoresOp(e02f35ae36554678a4d8e93f65e387ad): perf score=14.095187
I20260812 06:18:52.193245   392 maintenance_manager.cc:643] P 57befd549e9740aebaffb34054751973: FlushDeltaMemStoresOp(e02f35ae36554678a4d8e93f65e387ad) complete. Timing: real 0.061s	user 0.019s	sys 0.037s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":25455,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:18:52.194063   460 maintenance_manager.cc:419] P 57befd549e9740aebaffb34054751973: Scheduling FlushDeltaMemStoresOp(e02f35ae36554678a4d8e93f65e387ad): perf score=2.188937
I20260812 06:18:52.218808   392 maintenance_manager.cc:643] P 57befd549e9740aebaffb34054751973: FlushDeltaMemStoresOp(e02f35ae36554678a4d8e93f65e387ad) complete. Timing: real 0.024s	user 0.009s	sys 0.015s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5144,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:52.219489   460 maintenance_manager.cc:419] P 57befd549e9740aebaffb34054751973: Scheduling FlushMRSOp(e02f35ae36554678a4d8e93f65e387ad): perf score=1.000000
I20260812 06:18:52.260093   392 maintenance_manager.cc:643] P 57befd549e9740aebaffb34054751973: FlushMRSOp(e02f35ae36554678a4d8e93f65e387ad) complete. Timing: real 0.040s	user 0.031s	sys 0.001s Metrics: {"bytes_written":1152510,"cfile_init":1,"dirs.queue_time_us":68,"dirs.run_cpu_time_us":349,"dirs.run_wall_time_us":1642,"drs_written":1,"lbm_read_time_us":52,"lbm_reads_lt_1ms":4,"lbm_write_time_us":2246,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":28}
I20260812 06:18:52.261499   460 maintenance_manager.cc:419] P 57befd549e9740aebaffb34054751973: Scheduling LogGCOp(e02f35ae36554678a4d8e93f65e387ad): free 112692545 bytes of WAL
I20260812 06:18:52.261838   392 log_reader.cc:385] T e02f35ae36554678a4d8e93f65e387ad: removed 11 log segments from log reader
I20260812 06:18:52.261910   392 log.cc:1079] T e02f35ae36554678a4d8e93f65e387ad P 57befd549e9740aebaffb34054751973: Deleting log segment in path: /tmp/dist-test-taskyiE61X/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515526977841-32748-0/minicluster-data/ts-0-root/wals/e02f35ae36554678a4d8e93f65e387ad/wal-000000026 (ops 125-129)
I20260812 06:18:52.261955   392 log.cc:1079] T e02f35ae36554678a4d8e93f65e387ad P 57befd549e9740aebaffb34054751973: Deleting log segment in path: /tmp/dist-test-taskyiE61X/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515526977841-32748-0/minicluster-data/ts-0-root/wals/e02f35ae36554678a4d8e93f65e387ad/wal-000000027 (ops 130-134)
I20260812 06:18:52.261983   392 log.cc:1079] T e02f35ae36554678a4d8e93f65e387ad P 57befd549e9740aebaffb34054751973: Deleting log segment in path: /tmp/dist-test-taskyiE61X/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515526977841-32748-0/minicluster-data/ts-0-root/wals/e02f35ae36554678a4d8e93f65e387ad/wal-000000028 (ops 135-139)
I20260812 06:18:52.262008   392 log.cc:1079] T e02f35ae36554678a4d8e93f65e387ad P 57befd549e9740aebaffb34054751973: Deleting log segment in path: /tmp/dist-test-taskyiE61X/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515526977841-32748-0/minicluster-data/ts-0-root/wals/e02f35ae36554678a4d8e93f65e387ad/wal-000000029 (ops 140-144)
I20260812 06:18:52.262046   392 log.cc:1079] T e02f35ae36554678a4d8e93f65e387ad P 57befd549e9740aebaffb34054751973: Deleting log segment in path: /tmp/dist-test-taskyiE61X/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515526977841-32748-0/minicluster-data/ts-0-root/wals/e02f35ae36554678a4d8e93f65e387ad/wal-000000030 (ops 145-149)
I20260812 06:18:52.262071   392 log.cc:1079] T e02f35ae36554678a4d8e93f65e387ad P 57befd549e9740aebaffb34054751973: Deleting log segment in path: /tmp/dist-test-taskyiE61X/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515526977841-32748-0/minicluster-data/ts-0-root/wals/e02f35ae36554678a4d8e93f65e387ad/wal-000000031 (ops 150-154)
I20260812 06:18:52.262096   392 log.cc:1079] T e02f35ae36554678a4d8e93f65e387ad P 57befd549e9740aebaffb34054751973: Deleting log segment in path: /tmp/dist-test-taskyiE61X/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515526977841-32748-0/minicluster-data/ts-0-root/wals/e02f35ae36554678a4d8e93f65e387ad/wal-000000032 (ops 155-159)
I20260812 06:18:52.262133   392 log.cc:1079] T e02f35ae36554678a4d8e93f65e387ad P 57befd549e9740aebaffb34054751973: Deleting log segment in path: /tmp/dist-test-taskyiE61X/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515526977841-32748-0/minicluster-data/ts-0-root/wals/e02f35ae36554678a4d8e93f65e387ad/wal-000000033 (ops 160-164)
I20260812 06:18:52.262162   392 log.cc:1079] T e02f35ae36554678a4d8e93f65e387ad P 57befd549e9740aebaffb34054751973: Deleting log segment in path: /tmp/dist-test-taskyiE61X/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515526977841-32748-0/minicluster-data/ts-0-root/wals/e02f35ae36554678a4d8e93f65e387ad/wal-000000034 (ops 165-169)
I20260812 06:18:52.262197   392 log.cc:1079] T e02f35ae36554678a4d8e93f65e387ad P 57befd549e9740aebaffb34054751973: Deleting log segment in path: /tmp/dist-test-taskyiE61X/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515526977841-32748-0/minicluster-data/ts-0-root/wals/e02f35ae36554678a4d8e93f65e387ad/wal-000000035 (ops 170-174)
I20260812 06:18:52.262220   392 log.cc:1079] T e02f35ae36554678a4d8e93f65e387ad P 57befd549e9740aebaffb34054751973: Deleting log segment in path: /tmp/dist-test-taskyiE61X/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515526977841-32748-0/minicluster-data/ts-0-root/wals/e02f35ae36554678a4d8e93f65e387ad/wal-000000036 (ops 175-179)
I20260812 06:18:52.290165   392 maintenance_manager.cc:643] P 57befd549e9740aebaffb34054751973: LogGCOp(e02f35ae36554678a4d8e93f65e387ad) complete. Timing: real 0.028s	user 0.000s	sys 0.025s Metrics: {}
I20260812 06:18:52.290794   460 maintenance_manager.cc:419] P 57befd549e9740aebaffb34054751973: Scheduling UndoDeltaBlockGCOp(e02f35ae36554678a4d8e93f65e387ad): 447 bytes on disk
I20260812 06:18:52.291527   392 maintenance_manager.cc:643] P 57befd549e9740aebaffb34054751973: UndoDeltaBlockGCOp(e02f35ae36554678a4d8e93f65e387ad) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":109,"lbm_reads_lt_1ms":4}
I20260812 06:18:52.292312   460 maintenance_manager.cc:419] P 57befd549e9740aebaffb34054751973: Scheduling FlushDeltaMemStoresOp(e02f35ae36554678a4d8e93f65e387ad): perf score=2.188937
I20260812 06:18:52.322824   392 maintenance_manager.cc:643] P 57befd549e9740aebaffb34054751973: FlushDeltaMemStoresOp(e02f35ae36554678a4d8e93f65e387ad) complete. Timing: real 0.030s	user 0.010s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":7248,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:52.323453   460 maintenance_manager.cc:419] P 57befd549e9740aebaffb34054751973: Scheduling LogGCOp(e02f35ae36554678a4d8e93f65e387ad): free 12018006 bytes of WAL
I20260812 06:18:52.323751   392 log_reader.cc:385] T e02f35ae36554678a4d8e93f65e387ad: removed 1 log segments from log reader
I20260812 06:18:52.323827   392 log.cc:1079] T e02f35ae36554678a4d8e93f65e387ad P 57befd549e9740aebaffb34054751973: Deleting log segment in path: /tmp/dist-test-taskyiE61X/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515526977841-32748-0/minicluster-data/ts-0-root/wals/e02f35ae36554678a4d8e93f65e387ad/wal-000000037 (ops 180-184)
I20260812 06:18:52.326188   392 maintenance_manager.cc:643] P 57befd549e9740aebaffb34054751973: LogGCOp(e02f35ae36554678a4d8e93f65e387ad) complete. Timing: real 0.002s	user 0.000s	sys 0.000s Metrics: {}
I20260812 06:18:52.326601   460 maintenance_manager.cc:419] P 57befd549e9740aebaffb34054751973: Scheduling FlushDeltaMemStoresOp(e02f35ae36554678a4d8e93f65e387ad): perf score=2.188937
I20260812 06:18:52.340529   392 maintenance_manager.cc:643] P 57befd549e9740aebaffb34054751973: FlushDeltaMemStoresOp(e02f35ae36554678a4d8e93f65e387ad) complete. Timing: real 0.014s	user 0.003s	sys 0.009s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4435,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:52.341096   460 maintenance_manager.cc:419] P 57befd549e9740aebaffb34054751973: Scheduling MajorDeltaCompactionOp(e02f35ae36554678a4d8e93f65e387ad): perf score=1.000000
I20260812 06:18:52.608294   392 maintenance_manager.cc:643] P 57befd549e9740aebaffb34054751973: MajorDeltaCompactionOp(e02f35ae36554678a4d8e93f65e387ad) complete. Timing: real 0.267s	user 0.177s	sys 0.080s Metrics: {"cfile_cache_miss":734,"cfile_cache_miss_bytes":32938785,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":3805,"lbm_read_time_us":17510,"lbm_reads_lt_1ms":766,"lbm_write_time_us":45348,"lbm_writes_lt_1ms":743,"mutex_wait_us":2538,"peak_mem_usage":87969044,"reinsert_count":0,"spinlock_wait_cycles":2816,"thread_start_us":109,"threads_started":1,"update_count":3500}
I20260812 06:18:52.609512   460 maintenance_manager.cc:419] P 57befd549e9740aebaffb34054751973: Scheduling FlushDeltaMemStoresOp(e02f35ae36554678a4d8e93f65e387ad): perf score=18.063937
I20260812 06:18:52.694588   392 maintenance_manager.cc:643] P 57befd549e9740aebaffb34054751973: FlushDeltaMemStoresOp(e02f35ae36554678a4d8e93f65e387ad) complete. Timing: real 0.085s	user 0.044s	sys 0.031s Metrics: {"bytes_written":20512315,"delete_count":0,"lbm_write_time_us":35558,"lbm_writes_lt_1ms":503,"reinsert_count":0,"update_count":2500}
I20260812 06:18:52.695456   460 maintenance_manager.cc:419] P 57befd549e9740aebaffb34054751973: Scheduling FlushDeltaMemStoresOp(e02f35ae36554678a4d8e93f65e387ad): perf score=2.188937
I20260812 06:18:52.707470   392 maintenance_manager.cc:643] P 57befd549e9740aebaffb34054751973: FlushDeltaMemStoresOp(e02f35ae36554678a4d8e93f65e387ad) complete. Timing: real 0.012s	user 0.011s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4367,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:52.708062   460 maintenance_manager.cc:419] P 57befd549e9740aebaffb34054751973: Scheduling MajorDeltaCompactionOp(e02f35ae36554678a4d8e93f65e387ad): perf score=1.000000
I20260812 06:18:52.796842 32748 heavy-update-compaction-itest.cc:229] Time spent updating: real 5.497s	user 2.020s	sys 0.181s
I20260812 06:18:52.877125 32748 heavy-update-compaction-itest.cc:265] Time spent scanning: real 0.080s	user 0.002s	sys 0.000s
I20260812 06:18:52.877842 32748 tablet_server.cc:179] TabletServer@127.31.251.1:0 shutting down...
I20260812 06:18:52.908078   392 maintenance_manager.cc:643] P 57befd549e9740aebaffb34054751973: MajorDeltaCompactionOp(e02f35ae36554678a4d8e93f65e387ad) complete. Timing: real 0.199s	user 0.151s	sys 0.047s Metrics: {"cfile_cache_miss":632,"cfile_cache_miss_bytes":28836137,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":1092,"lbm_read_time_us":13815,"lbm_reads_lt_1ms":668,"lbm_write_time_us":34170,"lbm_writes_lt_1ms":643,"mutex_wait_us":370,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":38528,"update_count":3000}
I20260812 06:18:52.908811 32748 ts_tablet_manager.cc:1507] Shutting down tablet manager...
I20260812 06:18:52.909291 32748 tablet_replica.cc:333] T e02f35ae36554678a4d8e93f65e387ad P 57befd549e9740aebaffb34054751973: stopping tablet replica
I20260812 06:18:52.909544 32748 raft_consensus.cc:2243] T e02f35ae36554678a4d8e93f65e387ad P 57befd549e9740aebaffb34054751973 [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:18:52.909807 32748 raft_consensus.cc:2272] T e02f35ae36554678a4d8e93f65e387ad P 57befd549e9740aebaffb34054751973 [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:18:52.928128 32748 tablet_server.cc:196] TabletServer@127.31.251.1:0 shutdown complete.
I20260812 06:18:52.962899 32748 master.cc:562] Master@127.31.251.62:37421 shutting down...
I20260812 06:18:52.968564 32748 raft_consensus.cc:2243] T 00000000000000000000000000000000 P 770aacc7bd7246438ab41db5eeddcb1e [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:18:52.968793 32748 raft_consensus.cc:2272] T 00000000000000000000000000000000 P 770aacc7bd7246438ab41db5eeddcb1e [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:18:52.968858 32748 tablet_replica.cc:333] T 00000000000000000000000000000000 P 770aacc7bd7246438ab41db5eeddcb1e: stopping tablet replica
I20260812 06:18:52.982630 32748 master.cc:584] Master@127.31.251.62:37421 shutdown complete.
[       OK ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/0 (6081 ms)
[ RUN      ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/1
I20260812 06:18:53.071911 32748 internal_mini_cluster.cc:156] Creating distributed mini masters. Addrs: 127.31.251.62:44891
I20260812 06:18:53.072295 32748 file_cache.cc:504] Constructed file cache file cache with capacity 419430
I20260812 06:18:53.075021 32748 server_base.cc:1061] running on GCE node
W20260812 06:18:53.075145   497 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:53.075281   494 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:53.075353   495 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:53.075647 32748 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:18:53.075696 32748 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:53.075718 32748 hybrid_clock.cc:648] HybridClock initialized: now 1786515533075718 us; error 0 us; skew 500 ppm
I20260812 06:18:53.076617 32748 webserver.cc:533] Webserver started at http://127.31.251.62:41101/ using document root <none> and password file <none>
I20260812 06:18:53.076779 32748 fs_manager.cc:362] Metadata directory not provided
I20260812 06:18:53.076826 32748 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:18:53.076881 32748 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:18:53.077261 32748 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskyiE61X/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515526977841-32748-0/minicluster-data/master-0-root/instance:
uuid: "24f17e846c61416b8b76d32eb4f0e50f"
format_stamp: "Formatted at 2026-08-12 06:18:53 on dist-test-slave-csg5"
I20260812 06:18:53.078878 32748 fs_manager.cc:696] Time spent creating directory manager: real 0.001s	user 0.002s	sys 0.000s
I20260812 06:18:53.079989   503 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:53.080683 32748 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.001s	sys 0.000s
I20260812 06:18:53.080835 32748 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskyiE61X/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515526977841-32748-0/minicluster-data/master-0-root
uuid: "24f17e846c61416b8b76d32eb4f0e50f"
format_stamp: "Formatted at 2026-08-12 06:18:53 on dist-test-slave-csg5"
I20260812 06:18:53.080968 32748 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskyiE61X/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515526977841-32748-0/minicluster-data/master-0-root
metadata directory: /tmp/dist-test-taskyiE61X/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515526977841-32748-0/minicluster-data/master-0-root
1 data directories: /tmp/dist-test-taskyiE61X/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515526977841-32748-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:53.091025 32748 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:18:53.091535 32748 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:18:53.097016 32748 rpc_server.cc:307] RPC server started. Bound to: 127.31.251.62:44891
I20260812 06:18:53.098968   559 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.31.251.62:44891 every 8 connection(s)
I20260812 06:18:53.099617   560 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:53.106742   560 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P 24f17e846c61416b8b76d32eb4f0e50f: Bootstrap starting.
I20260812 06:18:53.107995   560 tablet_bootstrap.cc:654] T 00000000000000000000000000000000 P 24f17e846c61416b8b76d32eb4f0e50f: Neither blocks nor log segments found. Creating new log.
I20260812 06:18:53.109891   560 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P 24f17e846c61416b8b76d32eb4f0e50f: No bootstrap required, opened a new log
I20260812 06:18:53.110370   560 raft_consensus.cc:359] T 00000000000000000000000000000000 P 24f17e846c61416b8b76d32eb4f0e50f [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "24f17e846c61416b8b76d32eb4f0e50f" member_type: VOTER }
I20260812 06:18:53.110474   560 raft_consensus.cc:385] T 00000000000000000000000000000000 P 24f17e846c61416b8b76d32eb4f0e50f [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:18:53.110500   560 raft_consensus.cc:740] T 00000000000000000000000000000000 P 24f17e846c61416b8b76d32eb4f0e50f [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: 24f17e846c61416b8b76d32eb4f0e50f, State: Initialized, Role: FOLLOWER
I20260812 06:18:53.110682   560 consensus_queue.cc:260] T 00000000000000000000000000000000 P 24f17e846c61416b8b76d32eb4f0e50f [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: "24f17e846c61416b8b76d32eb4f0e50f" member_type: VOTER }
I20260812 06:18:53.110975   560 raft_consensus.cc:399] T 00000000000000000000000000000000 P 24f17e846c61416b8b76d32eb4f0e50f [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:18:53.111011   560 raft_consensus.cc:493] T 00000000000000000000000000000000 P 24f17e846c61416b8b76d32eb4f0e50f [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:18:53.111045   560 raft_consensus.cc:3060] T 00000000000000000000000000000000 P 24f17e846c61416b8b76d32eb4f0e50f [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:18:53.111981   560 raft_consensus.cc:515] T 00000000000000000000000000000000 P 24f17e846c61416b8b76d32eb4f0e50f [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "24f17e846c61416b8b76d32eb4f0e50f" member_type: VOTER }
I20260812 06:18:53.112128   560 leader_election.cc:304] T 00000000000000000000000000000000 P 24f17e846c61416b8b76d32eb4f0e50f [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: 24f17e846c61416b8b76d32eb4f0e50f; no voters: 
I20260812 06:18:53.112316   560 leader_election.cc:290] T 00000000000000000000000000000000 P 24f17e846c61416b8b76d32eb4f0e50f [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:18:53.112583   565 raft_consensus.cc:2804] T 00000000000000000000000000000000 P 24f17e846c61416b8b76d32eb4f0e50f [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:18:53.112777   565 raft_consensus.cc:697] T 00000000000000000000000000000000 P 24f17e846c61416b8b76d32eb4f0e50f [term 1 LEADER]: Becoming Leader. State: Replica: 24f17e846c61416b8b76d32eb4f0e50f, State: Running, Role: LEADER
I20260812 06:18:53.112880   560 sys_catalog.cc:565] T 00000000000000000000000000000000 P 24f17e846c61416b8b76d32eb4f0e50f [sys.catalog]: configured and running, proceeding with master startup.
I20260812 06:18:53.112921   565 consensus_queue.cc:237] T 00000000000000000000000000000000 P 24f17e846c61416b8b76d32eb4f0e50f [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: "24f17e846c61416b8b76d32eb4f0e50f" member_type: VOTER }
I20260812 06:18:53.113682   568 sys_catalog.cc:455] T 00000000000000000000000000000000 P 24f17e846c61416b8b76d32eb4f0e50f [sys.catalog]: SysCatalogTable state changed. Reason: New leader 24f17e846c61416b8b76d32eb4f0e50f. Latest consensus state: current_term: 1 leader_uuid: "24f17e846c61416b8b76d32eb4f0e50f" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "24f17e846c61416b8b76d32eb4f0e50f" member_type: VOTER } }
I20260812 06:18:53.113853   568 sys_catalog.cc:458] T 00000000000000000000000000000000 P 24f17e846c61416b8b76d32eb4f0e50f [sys.catalog]: This master's current role is: LEADER
I20260812 06:18:53.113871   564 sys_catalog.cc:455] T 00000000000000000000000000000000 P 24f17e846c61416b8b76d32eb4f0e50f [sys.catalog]: SysCatalogTable state changed. Reason: RaftConsensus started. Latest consensus state: current_term: 1 leader_uuid: "24f17e846c61416b8b76d32eb4f0e50f" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "24f17e846c61416b8b76d32eb4f0e50f" member_type: VOTER } }
I20260812 06:18:53.114039   564 sys_catalog.cc:458] T 00000000000000000000000000000000 P 24f17e846c61416b8b76d32eb4f0e50f [sys.catalog]: This master's current role is: LEADER
I20260812 06:18:53.114379   576 catalog_manager.cc:1511] Loading table and tablet metadata into memory...
I20260812 06:18:53.115367   576 catalog_manager.cc:1520] Initializing Kudu cluster ID...
I20260812 06:18:53.115598 32748 internal_mini_cluster.cc:184] Waiting to initialize catalog manager on master 0
I20260812 06:18:53.118892   576 catalog_manager.cc:1383] Generated new cluster ID: 0467cfa2daf64588b7cd807abf4ac1f2
I20260812 06:18:53.119014   576 catalog_manager.cc:1531] Initializing Kudu internal certificate authority...
I20260812 06:18:53.146198   576 catalog_manager.cc:1406] Generated new certificate authority record
I20260812 06:18:53.146890   576 catalog_manager.cc:1540] Loading token signing keys...
I20260812 06:18:53.154053   576 catalog_manager.cc:6092] T 00000000000000000000000000000000 P 24f17e846c61416b8b76d32eb4f0e50f: Generated new TSK 0
I20260812 06:18:53.154476   576 catalog_manager.cc:1550] Initializing in-progress tserver states...
I20260812 06:18:53.180735 32748 file_cache.cc:504] Constructed file cache file cache with capacity 419430
I20260812 06:18:53.183804 32748 server_base.cc:1061] running on GCE node
W20260812 06:18:53.183835   589 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:53.184013   588 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:53.184013   591 instance_detector.cc:116] could not retrieve OpenStack instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:18:53.184430 32748 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:18:53.184485 32748 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:53.184504 32748 hybrid_clock.cc:648] HybridClock initialized: now 1786515533184504 us; error 0 us; skew 500 ppm
I20260812 06:18:53.185631 32748 webserver.cc:533] Webserver started at http://127.31.251.1:38359/ using document root <none> and password file <none>
I20260812 06:18:53.185803 32748 fs_manager.cc:362] Metadata directory not provided
I20260812 06:18:53.185859 32748 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:18:53.185918 32748 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:18:53.186375 32748 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskyiE61X/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515526977841-32748-0/minicluster-data/ts-0-root/instance:
uuid: "3a642cd9441b461fb13d5a48427e7fe6"
format_stamp: "Formatted at 2026-08-12 06:18:53 on dist-test-slave-csg5"
I20260812 06:18:53.188133 32748 fs_manager.cc:696] Time spent creating directory manager: real 0.002s	user 0.002s	sys 0.000s
I20260812 06:18:53.189697   597 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:53.190412 32748 fs_manager.cc:730] Time spent opening block manager: real 0.002s	user 0.001s	sys 0.000s
I20260812 06:18:53.190781 32748 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskyiE61X/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515526977841-32748-0/minicluster-data/ts-0-root
uuid: "3a642cd9441b461fb13d5a48427e7fe6"
format_stamp: "Formatted at 2026-08-12 06:18:53 on dist-test-slave-csg5"
I20260812 06:18:53.190917 32748 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskyiE61X/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515526977841-32748-0/minicluster-data/ts-0-root
metadata directory: /tmp/dist-test-taskyiE61X/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515526977841-32748-0/minicluster-data/ts-0-root
1 data directories: /tmp/dist-test-taskyiE61X/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515526977841-32748-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:53.196902 32748 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:18:53.197398 32748 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:18:53.197819 32748 txn_system_client.cc:432] TxnSystemClient initialization is disabled...
I20260812 06:18:53.198354 32748 ts_tablet_manager.cc:585] Loaded tablet metadata (0 total tablets, 0 live tablets)
I20260812 06:18:53.198419 32748 ts_tablet_manager.cc:531] Time spent load tablet metadata: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:18:53.198484 32748 ts_tablet_manager.cc:616] Registered 0 tablets
I20260812 06:18:53.198536 32748 ts_tablet_manager.cc:595] Time spent register tablets: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:18:53.204037 32748 rpc_server.cc:307] RPC server started. Bound to: 127.31.251.1:35401
I20260812 06:18:53.205662   665 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.31.251.1:35401 every 8 connection(s)
I20260812 06:18:53.216856   666 heartbeater.cc:344] Connected to a master server at 127.31.251.62:44891
I20260812 06:18:53.217069   666 heartbeater.cc:461] Registering TS with master...
I20260812 06:18:53.217506   666 heartbeater.cc:507] Master 127.31.251.62:44891 requested a full tablet report, sending...
I20260812 06:18:53.218483   520 ts_manager.cc:194] Registered new tserver with Master: 3a642cd9441b461fb13d5a48427e7fe6 (127.31.251.1:35401)
I20260812 06:18:53.218866 32748 internal_mini_cluster.cc:371] 1 TS(s) registered with all masters after 0.013837473s
I20260812 06:18:53.219507   520 master_service.cc:502] Signed X509 certificate for tserver {username='slave'} at 127.0.0.1:43178
I20260812 06:18:53.229229   520 catalog_manager.cc:2283] Servicing CreateTable request from {username='slave'} at 127.0.0.1:43194:
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:53.240401   627 tablet_service.cc:1511] Processing CreateTablet for tablet f2ecdb559656470780b20a25947dc543 (DEFAULT_TABLE table=heavy-update-compaction-test [id=26a149dc8821495eac5de6c7102a62ca]), partition=
I20260812 06:18:53.240727   627 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet f2ecdb559656470780b20a25947dc543. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:18:53.243432   681 tablet_bootstrap.cc:492] T f2ecdb559656470780b20a25947dc543 P 3a642cd9441b461fb13d5a48427e7fe6: Bootstrap starting.
I20260812 06:18:53.244477   681 tablet_bootstrap.cc:654] T f2ecdb559656470780b20a25947dc543 P 3a642cd9441b461fb13d5a48427e7fe6: Neither blocks nor log segments found. Creating new log.
I20260812 06:18:53.246030   681 tablet_bootstrap.cc:492] T f2ecdb559656470780b20a25947dc543 P 3a642cd9441b461fb13d5a48427e7fe6: No bootstrap required, opened a new log
I20260812 06:18:53.246182   681 ts_tablet_manager.cc:1403] T f2ecdb559656470780b20a25947dc543 P 3a642cd9441b461fb13d5a48427e7fe6: Time spent bootstrapping tablet: real 0.003s	user 0.002s	sys 0.000s
I20260812 06:18:53.246809   681 raft_consensus.cc:359] T f2ecdb559656470780b20a25947dc543 P 3a642cd9441b461fb13d5a48427e7fe6 [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "3a642cd9441b461fb13d5a48427e7fe6" member_type: VOTER last_known_addr { host: "127.31.251.1" port: 35401 } }
I20260812 06:18:53.246922   681 raft_consensus.cc:385] T f2ecdb559656470780b20a25947dc543 P 3a642cd9441b461fb13d5a48427e7fe6 [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:18:53.246948   681 raft_consensus.cc:740] T f2ecdb559656470780b20a25947dc543 P 3a642cd9441b461fb13d5a48427e7fe6 [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: 3a642cd9441b461fb13d5a48427e7fe6, State: Initialized, Role: FOLLOWER
I20260812 06:18:53.247174   681 consensus_queue.cc:260] T f2ecdb559656470780b20a25947dc543 P 3a642cd9441b461fb13d5a48427e7fe6 [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: "3a642cd9441b461fb13d5a48427e7fe6" member_type: VOTER last_known_addr { host: "127.31.251.1" port: 35401 } }
I20260812 06:18:53.247262   681 raft_consensus.cc:399] T f2ecdb559656470780b20a25947dc543 P 3a642cd9441b461fb13d5a48427e7fe6 [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:18:53.247288   681 raft_consensus.cc:493] T f2ecdb559656470780b20a25947dc543 P 3a642cd9441b461fb13d5a48427e7fe6 [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:18:53.247362   681 raft_consensus.cc:3060] T f2ecdb559656470780b20a25947dc543 P 3a642cd9441b461fb13d5a48427e7fe6 [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:18:53.248240   681 raft_consensus.cc:515] T f2ecdb559656470780b20a25947dc543 P 3a642cd9441b461fb13d5a48427e7fe6 [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "3a642cd9441b461fb13d5a48427e7fe6" member_type: VOTER last_known_addr { host: "127.31.251.1" port: 35401 } }
I20260812 06:18:53.248411   681 leader_election.cc:304] T f2ecdb559656470780b20a25947dc543 P 3a642cd9441b461fb13d5a48427e7fe6 [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: 3a642cd9441b461fb13d5a48427e7fe6; no voters: 
I20260812 06:18:53.248698   681 leader_election.cc:290] T f2ecdb559656470780b20a25947dc543 P 3a642cd9441b461fb13d5a48427e7fe6 [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:18:53.248957   684 raft_consensus.cc:2804] T f2ecdb559656470780b20a25947dc543 P 3a642cd9441b461fb13d5a48427e7fe6 [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:18:53.249063   681 ts_tablet_manager.cc:1434] T f2ecdb559656470780b20a25947dc543 P 3a642cd9441b461fb13d5a48427e7fe6: Time spent starting tablet: real 0.003s	user 0.003s	sys 0.000s
I20260812 06:18:53.249104   666 heartbeater.cc:499] Master 127.31.251.62:44891 was elected leader, sending a full tablet report...
I20260812 06:18:53.249073   684 raft_consensus.cc:697] T f2ecdb559656470780b20a25947dc543 P 3a642cd9441b461fb13d5a48427e7fe6 [term 1 LEADER]: Becoming Leader. State: Replica: 3a642cd9441b461fb13d5a48427e7fe6, State: Running, Role: LEADER
I20260812 06:18:53.249445   684 consensus_queue.cc:237] T f2ecdb559656470780b20a25947dc543 P 3a642cd9441b461fb13d5a48427e7fe6 [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: "3a642cd9441b461fb13d5a48427e7fe6" member_type: VOTER last_known_addr { host: "127.31.251.1" port: 35401 } }
I20260812 06:18:53.251036   520 catalog_manager.cc:5719] T f2ecdb559656470780b20a25947dc543 P 3a642cd9441b461fb13d5a48427e7fe6 reported cstate change: term changed from 0 to 1, leader changed from <none> to 3a642cd9441b461fb13d5a48427e7fe6 (127.31.251.1). New cstate: current_term: 1 leader_uuid: "3a642cd9441b461fb13d5a48427e7fe6" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "3a642cd9441b461fb13d5a48427e7fe6" member_type: VOTER last_known_addr { host: "127.31.251.1" port: 35401 } health_report { overall_health: HEALTHY } } }
I20260812 06:18:53.321208 32748 heavy-update-compaction-itest.cc:215] Time spent inserting: real 0.064s	user 0.025s	sys 0.005s
I20260812 06:18:53.456318   667 maintenance_manager.cc:419] P 3a642cd9441b461fb13d5a48427e7fe6: Scheduling FlushMRSOp(f2ecdb559656470780b20a25947dc543): perf score=15.086190
I20260812 06:18:53.626044   602 maintenance_manager.cc:643] P 3a642cd9441b461fb13d5a48427e7fe6: FlushMRSOp(f2ecdb559656470780b20a25947dc543) complete. Timing: real 0.169s	user 0.122s	sys 0.040s Metrics: {"bytes_written":12307490,"cfile_init":1,"delete_count":0,"dirs.queue_time_us":46,"dirs.run_cpu_time_us":207,"dirs.run_wall_time_us":1310,"drs_written":1,"lbm_read_time_us":91,"lbm_reads_lt_1ms":4,"lbm_write_time_us":42062,"lbm_writes_lt_1ms":657,"peak_mem_usage":0,"reinsert_count":0,"rows_written":103,"update_count":1500}
I20260812 06:18:53.627208   667 maintenance_manager.cc:419] P 3a642cd9441b461fb13d5a48427e7fe6: Scheduling LogGCOp(f2ecdb559656470780b20a25947dc543): free 8725963 bytes of WAL
I20260812 06:18:53.627601   602 log_reader.cc:385] T f2ecdb559656470780b20a25947dc543: removed 1 log segments from log reader
I20260812 06:18:53.627673   602 log.cc:1079] T f2ecdb559656470780b20a25947dc543 P 3a642cd9441b461fb13d5a48427e7fe6: Deleting log segment in path: /tmp/dist-test-taskyiE61X/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515526977841-32748-0/minicluster-data/ts-0-root/wals/f2ecdb559656470780b20a25947dc543/wal-000000001 (ops 1-6)
I20260812 06:18:53.630411   602 maintenance_manager.cc:643] P 3a642cd9441b461fb13d5a48427e7fe6: LogGCOp(f2ecdb559656470780b20a25947dc543) complete. Timing: real 0.003s	user 0.000s	sys 0.000s Metrics: {}
I20260812 06:18:53.631043   667 maintenance_manager.cc:419] P 3a642cd9441b461fb13d5a48427e7fe6: Scheduling FlushDeltaMemStoresOp(f2ecdb559656470780b20a25947dc543): perf score=2.188937
I20260812 06:18:53.650677   602 maintenance_manager.cc:643] P 3a642cd9441b461fb13d5a48427e7fe6: FlushDeltaMemStoresOp(f2ecdb559656470780b20a25947dc543) complete. Timing: real 0.019s	user 0.013s	sys 0.004s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":7128,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:53.651228   667 maintenance_manager.cc:419] P 3a642cd9441b461fb13d5a48427e7fe6: Scheduling UndoDeltaBlockGCOp(f2ecdb559656470780b20a25947dc543): 12308960 bytes on disk
I20260812 06:18:53.651755   602 maintenance_manager.cc:643] P 3a642cd9441b461fb13d5a48427e7fe6: UndoDeltaBlockGCOp(f2ecdb559656470780b20a25947dc543) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":97,"lbm_reads_lt_1ms":4}
I20260812 06:18:53.652410   667 maintenance_manager.cc:419] P 3a642cd9441b461fb13d5a48427e7fe6: Scheduling MajorDeltaCompactionOp(f2ecdb559656470780b20a25947dc543): perf score=1.000000
I20260812 06:18:53.816658   602 maintenance_manager.cc:643] P 3a642cd9441b461fb13d5a48427e7fe6: MajorDeltaCompactionOp(f2ecdb559656470780b20a25947dc543) complete. Timing: real 0.164s	user 0.104s	sys 0.060s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20631311,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":1172,"lbm_read_time_us":13138,"lbm_reads_lt_1ms":464,"lbm_write_time_us":25851,"lbm_writes_lt_1ms":443,"mutex_wait_us":3,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":11136,"thread_start_us":486,"threads_started":5,"update_count":2000}
I20260812 06:18:53.817358   667 maintenance_manager.cc:419] P 3a642cd9441b461fb13d5a48427e7fe6: Scheduling FlushDeltaMemStoresOp(f2ecdb559656470780b20a25947dc543): perf score=10.126437
I20260812 06:18:53.869731   602 maintenance_manager.cc:643] P 3a642cd9441b461fb13d5a48427e7fe6: FlushDeltaMemStoresOp(f2ecdb559656470780b20a25947dc543) complete. Timing: real 0.052s	user 0.022s	sys 0.027s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":18661,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:18:53.870373   667 maintenance_manager.cc:419] P 3a642cd9441b461fb13d5a48427e7fe6: Scheduling FlushDeltaMemStoresOp(f2ecdb559656470780b20a25947dc543): perf score=2.188937
I20260812 06:18:53.881634   602 maintenance_manager.cc:643] P 3a642cd9441b461fb13d5a48427e7fe6: FlushDeltaMemStoresOp(f2ecdb559656470780b20a25947dc543) complete. Timing: real 0.011s	user 0.006s	sys 0.003s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4210,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:53.882153   667 maintenance_manager.cc:419] P 3a642cd9441b461fb13d5a48427e7fe6: Scheduling MajorDeltaCompactionOp(f2ecdb559656470780b20a25947dc543): perf score=1.000000
I20260812 06:18:54.076036   602 maintenance_manager.cc:643] P 3a642cd9441b461fb13d5a48427e7fe6: MajorDeltaCompactionOp(f2ecdb559656470780b20a25947dc543) complete. Timing: real 0.194s	user 0.157s	sys 0.036s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20631311,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":237,"lbm_read_time_us":12730,"lbm_reads_lt_1ms":472,"lbm_write_time_us":32189,"lbm_writes_lt_1ms":443,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":14720,"update_count":2000}
I20260812 06:18:54.076534   667 maintenance_manager.cc:419] P 3a642cd9441b461fb13d5a48427e7fe6: Scheduling FlushDeltaMemStoresOp(f2ecdb559656470780b20a25947dc543): perf score=10.126437
I20260812 06:18:54.121449   602 maintenance_manager.cc:643] P 3a642cd9441b461fb13d5a48427e7fe6: FlushDeltaMemStoresOp(f2ecdb559656470780b20a25947dc543) complete. Timing: real 0.044s	user 0.024s	sys 0.013s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":15980,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:18:54.122115   667 maintenance_manager.cc:419] P 3a642cd9441b461fb13d5a48427e7fe6: Scheduling FlushDeltaMemStoresOp(f2ecdb559656470780b20a25947dc543): perf score=2.188937
I20260812 06:18:54.134438   602 maintenance_manager.cc:643] P 3a642cd9441b461fb13d5a48427e7fe6: FlushDeltaMemStoresOp(f2ecdb559656470780b20a25947dc543) complete. Timing: real 0.012s	user 0.003s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4960,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:54.134971   667 maintenance_manager.cc:419] P 3a642cd9441b461fb13d5a48427e7fe6: Scheduling MajorDeltaCompactionOp(f2ecdb559656470780b20a25947dc543): perf score=1.000000
I20260812 06:18:54.275604   602 maintenance_manager.cc:643] P 3a642cd9441b461fb13d5a48427e7fe6: MajorDeltaCompactionOp(f2ecdb559656470780b20a25947dc543) complete. Timing: real 0.140s	user 0.104s	sys 0.036s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20631312,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":1218,"lbm_read_time_us":10965,"lbm_reads_lt_1ms":472,"lbm_write_time_us":25998,"lbm_writes_lt_1ms":443,"mutex_wait_us":316,"peak_mem_usage":50689328,"reinsert_count":0,"update_count":2000}
I20260812 06:18:54.276187   667 maintenance_manager.cc:419] P 3a642cd9441b461fb13d5a48427e7fe6: Scheduling FlushDeltaMemStoresOp(f2ecdb559656470780b20a25947dc543): perf score=10.126437
I20260812 06:18:54.332952   602 maintenance_manager.cc:643] P 3a642cd9441b461fb13d5a48427e7fe6: FlushDeltaMemStoresOp(f2ecdb559656470780b20a25947dc543) complete. Timing: real 0.057s	user 0.033s	sys 0.011s Metrics: {"bytes_written":12307491,"delete_count":0,"lbm_write_time_us":20560,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:18:54.333542   667 maintenance_manager.cc:419] P 3a642cd9441b461fb13d5a48427e7fe6: Scheduling FlushDeltaMemStoresOp(f2ecdb559656470780b20a25947dc543): perf score=2.188937
I20260812 06:18:54.347846   602 maintenance_manager.cc:643] P 3a642cd9441b461fb13d5a48427e7fe6: FlushDeltaMemStoresOp(f2ecdb559656470780b20a25947dc543) complete. Timing: real 0.014s	user 0.013s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4729,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:54.348567   667 maintenance_manager.cc:419] P 3a642cd9441b461fb13d5a48427e7fe6: Scheduling MajorDeltaCompactionOp(f2ecdb559656470780b20a25947dc543): perf score=1.000000
I20260812 06:18:54.505359   602 maintenance_manager.cc:643] P 3a642cd9441b461fb13d5a48427e7fe6: MajorDeltaCompactionOp(f2ecdb559656470780b20a25947dc543) complete. Timing: real 0.157s	user 0.137s	sys 0.020s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20631313,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":700,"lbm_read_time_us":12066,"lbm_reads_lt_1ms":472,"lbm_write_time_us":27404,"lbm_writes_lt_1ms":443,"mutex_wait_us":97,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":25344,"update_count":2000}
I20260812 06:18:54.506289   667 maintenance_manager.cc:419] P 3a642cd9441b461fb13d5a48427e7fe6: Scheduling FlushDeltaMemStoresOp(f2ecdb559656470780b20a25947dc543): perf score=10.126437
I20260812 06:18:54.558269   602 maintenance_manager.cc:643] P 3a642cd9441b461fb13d5a48427e7fe6: FlushDeltaMemStoresOp(f2ecdb559656470780b20a25947dc543) complete. Timing: real 0.052s	user 0.024s	sys 0.024s Metrics: {"bytes_written":12307492,"delete_count":0,"lbm_write_time_us":17226,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:18:54.559011   667 maintenance_manager.cc:419] P 3a642cd9441b461fb13d5a48427e7fe6: Scheduling FlushDeltaMemStoresOp(f2ecdb559656470780b20a25947dc543): perf score=2.188937
I20260812 06:18:54.572032   602 maintenance_manager.cc:643] P 3a642cd9441b461fb13d5a48427e7fe6: FlushDeltaMemStoresOp(f2ecdb559656470780b20a25947dc543) complete. Timing: real 0.013s	user 0.010s	sys 0.002s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4694,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:54.572624   667 maintenance_manager.cc:419] P 3a642cd9441b461fb13d5a48427e7fe6: Scheduling MajorDeltaCompactionOp(f2ecdb559656470780b20a25947dc543): perf score=1.000000
I20260812 06:18:54.770248   602 maintenance_manager.cc:643] P 3a642cd9441b461fb13d5a48427e7fe6: MajorDeltaCompactionOp(f2ecdb559656470780b20a25947dc543) complete. Timing: real 0.197s	user 0.135s	sys 0.061s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20631314,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":1080,"lbm_read_time_us":13775,"lbm_reads_lt_1ms":472,"lbm_write_time_us":30719,"lbm_writes_lt_1ms":443,"mutex_wait_us":60,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":1536,"update_count":2000}
I20260812 06:18:54.771106   667 maintenance_manager.cc:419] P 3a642cd9441b461fb13d5a48427e7fe6: Scheduling FlushDeltaMemStoresOp(f2ecdb559656470780b20a25947dc543): perf score=11.118625
I20260812 06:18:54.809087   602 maintenance_manager.cc:643] P 3a642cd9441b461fb13d5a48427e7fe6: FlushDeltaMemStoresOp(f2ecdb559656470780b20a25947dc543) complete. Timing: real 0.038s	user 0.027s	sys 0.008s Metrics: {"bytes_written":12717735,"delete_count":0,"lbm_write_time_us":15790,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:18:54.809700   667 maintenance_manager.cc:419] P 3a642cd9441b461fb13d5a48427e7fe6: Scheduling FlushDeltaMemStoresOp(f2ecdb559656470780b20a25947dc543): perf score=2.188937
I20260812 06:18:54.831043   602 maintenance_manager.cc:643] P 3a642cd9441b461fb13d5a48427e7fe6: FlushDeltaMemStoresOp(f2ecdb559656470780b20a25947dc543) complete. Timing: real 0.021s	user 0.013s	sys 0.004s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":6391,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:18:54.831725   667 maintenance_manager.cc:419] P 3a642cd9441b461fb13d5a48427e7fe6: Scheduling MajorDeltaCompactionOp(f2ecdb559656470780b20a25947dc543): perf score=1.000000
I20260812 06:18:54.972417   602 maintenance_manager.cc:643] P 3a642cd9441b461fb13d5a48427e7fe6: MajorDeltaCompactionOp(f2ecdb559656470780b20a25947dc543) complete. Timing: real 0.140s	user 0.112s	sys 0.028s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20631303,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":253,"lbm_read_time_us":9929,"lbm_reads_lt_1ms":464,"lbm_write_time_us":27263,"lbm_writes_lt_1ms":443,"mutex_wait_us":64,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":21376,"update_count":2000}
I20260812 06:18:54.973383   667 maintenance_manager.cc:419] P 3a642cd9441b461fb13d5a48427e7fe6: Scheduling FlushDeltaMemStoresOp(f2ecdb559656470780b20a25947dc543): perf score=10.126437
I20260812 06:18:55.018543   602 maintenance_manager.cc:643] P 3a642cd9441b461fb13d5a48427e7fe6: FlushDeltaMemStoresOp(f2ecdb559656470780b20a25947dc543) complete. Timing: real 0.045s	user 0.034s	sys 0.007s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":19308,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:18:55.019407   667 maintenance_manager.cc:419] P 3a642cd9441b461fb13d5a48427e7fe6: Scheduling FlushDeltaMemStoresOp(f2ecdb559656470780b20a25947dc543): perf score=2.188937
I20260812 06:18:55.036252   602 maintenance_manager.cc:643] P 3a642cd9441b461fb13d5a48427e7fe6: FlushDeltaMemStoresOp(f2ecdb559656470780b20a25947dc543) complete. Timing: real 0.017s	user 0.014s	sys 0.001s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6204,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:55.036747   667 maintenance_manager.cc:419] P 3a642cd9441b461fb13d5a48427e7fe6: Scheduling FlushMRSOp(f2ecdb559656470780b20a25947dc543): perf score=1.000000
I20260812 06:18:55.070015   602 maintenance_manager.cc:643] P 3a642cd9441b461fb13d5a48427e7fe6: FlushMRSOp(f2ecdb559656470780b20a25947dc543) complete. Timing: real 0.033s	user 0.031s	sys 0.000s Metrics: {"bytes_written":1152509,"cfile_init":1,"dirs.queue_time_us":103,"dirs.run_cpu_time_us":308,"dirs.run_wall_time_us":1764,"drs_written":1,"lbm_read_time_us":92,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1569,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":28}
I20260812 06:18:55.070875   667 maintenance_manager.cc:419] P 3a642cd9441b461fb13d5a48427e7fe6: Scheduling LogGCOp(f2ecdb559656470780b20a25947dc543): free 120553370 bytes of WAL
I20260812 06:18:55.071121   602 log_reader.cc:385] T f2ecdb559656470780b20a25947dc543: removed 12 log segments from log reader
I20260812 06:18:55.071168   602 log.cc:1079] T f2ecdb559656470780b20a25947dc543 P 3a642cd9441b461fb13d5a48427e7fe6: Deleting log segment in path: /tmp/dist-test-taskyiE61X/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515526977841-32748-0/minicluster-data/ts-0-root/wals/f2ecdb559656470780b20a25947dc543/wal-000000002 (ops 7-11)
I20260812 06:18:55.071199   602 log.cc:1079] T f2ecdb559656470780b20a25947dc543 P 3a642cd9441b461fb13d5a48427e7fe6: Deleting log segment in path: /tmp/dist-test-taskyiE61X/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515526977841-32748-0/minicluster-data/ts-0-root/wals/f2ecdb559656470780b20a25947dc543/wal-000000003 (ops 12-16)
I20260812 06:18:55.071274   602 log.cc:1079] T f2ecdb559656470780b20a25947dc543 P 3a642cd9441b461fb13d5a48427e7fe6: Deleting log segment in path: /tmp/dist-test-taskyiE61X/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515526977841-32748-0/minicluster-data/ts-0-root/wals/f2ecdb559656470780b20a25947dc543/wal-000000004 (ops 17-21)
I20260812 06:18:55.071346   602 log.cc:1079] T f2ecdb559656470780b20a25947dc543 P 3a642cd9441b461fb13d5a48427e7fe6: Deleting log segment in path: /tmp/dist-test-taskyiE61X/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515526977841-32748-0/minicluster-data/ts-0-root/wals/f2ecdb559656470780b20a25947dc543/wal-000000005 (ops 22-26)
I20260812 06:18:55.071395   602 log.cc:1079] T f2ecdb559656470780b20a25947dc543 P 3a642cd9441b461fb13d5a48427e7fe6: Deleting log segment in path: /tmp/dist-test-taskyiE61X/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515526977841-32748-0/minicluster-data/ts-0-root/wals/f2ecdb559656470780b20a25947dc543/wal-000000006 (ops 27-30)
I20260812 06:18:55.071444   602 log.cc:1079] T f2ecdb559656470780b20a25947dc543 P 3a642cd9441b461fb13d5a48427e7fe6: Deleting log segment in path: /tmp/dist-test-taskyiE61X/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515526977841-32748-0/minicluster-data/ts-0-root/wals/f2ecdb559656470780b20a25947dc543/wal-000000007 (ops 31-35)
I20260812 06:18:55.071486   602 log.cc:1079] T f2ecdb559656470780b20a25947dc543 P 3a642cd9441b461fb13d5a48427e7fe6: Deleting log segment in path: /tmp/dist-test-taskyiE61X/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515526977841-32748-0/minicluster-data/ts-0-root/wals/f2ecdb559656470780b20a25947dc543/wal-000000008 (ops 36-40)
I20260812 06:18:55.071532   602 log.cc:1079] T f2ecdb559656470780b20a25947dc543 P 3a642cd9441b461fb13d5a48427e7fe6: Deleting log segment in path: /tmp/dist-test-taskyiE61X/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515526977841-32748-0/minicluster-data/ts-0-root/wals/f2ecdb559656470780b20a25947dc543/wal-000000009 (ops 41-45)
I20260812 06:18:55.071578   602 log.cc:1079] T f2ecdb559656470780b20a25947dc543 P 3a642cd9441b461fb13d5a48427e7fe6: Deleting log segment in path: /tmp/dist-test-taskyiE61X/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515526977841-32748-0/minicluster-data/ts-0-root/wals/f2ecdb559656470780b20a25947dc543/wal-000000010 (ops 46-50)
I20260812 06:18:55.071621   602 log.cc:1079] T f2ecdb559656470780b20a25947dc543 P 3a642cd9441b461fb13d5a48427e7fe6: Deleting log segment in path: /tmp/dist-test-taskyiE61X/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515526977841-32748-0/minicluster-data/ts-0-root/wals/f2ecdb559656470780b20a25947dc543/wal-000000011 (ops 51-54)
I20260812 06:18:55.071674   602 log.cc:1079] T f2ecdb559656470780b20a25947dc543 P 3a642cd9441b461fb13d5a48427e7fe6: Deleting log segment in path: /tmp/dist-test-taskyiE61X/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515526977841-32748-0/minicluster-data/ts-0-root/wals/f2ecdb559656470780b20a25947dc543/wal-000000012 (ops 55-59)
I20260812 06:18:55.071719   602 log.cc:1079] T f2ecdb559656470780b20a25947dc543 P 3a642cd9441b461fb13d5a48427e7fe6: Deleting log segment in path: /tmp/dist-test-taskyiE61X/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515526977841-32748-0/minicluster-data/ts-0-root/wals/f2ecdb559656470780b20a25947dc543/wal-000000013 (ops 60-64)
I20260812 06:18:55.099749   602 maintenance_manager.cc:643] P 3a642cd9441b461fb13d5a48427e7fe6: LogGCOp(f2ecdb559656470780b20a25947dc543) complete. Timing: real 0.029s	user 0.000s	sys 0.028s Metrics: {}
I20260812 06:18:55.100284   667 maintenance_manager.cc:419] P 3a642cd9441b461fb13d5a48427e7fe6: Scheduling UndoDeltaBlockGCOp(f2ecdb559656470780b20a25947dc543): 447 bytes on disk
I20260812 06:18:55.100831   602 maintenance_manager.cc:643] P 3a642cd9441b461fb13d5a48427e7fe6: UndoDeltaBlockGCOp(f2ecdb559656470780b20a25947dc543) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":82,"lbm_reads_lt_1ms":4}
I20260812 06:18:55.101444   667 maintenance_manager.cc:419] P 3a642cd9441b461fb13d5a48427e7fe6: Scheduling FlushDeltaMemStoresOp(f2ecdb559656470780b20a25947dc543): perf score=3.181125
I20260812 06:18:55.116104   602 maintenance_manager.cc:643] P 3a642cd9441b461fb13d5a48427e7fe6: FlushDeltaMemStoresOp(f2ecdb559656470780b20a25947dc543) complete. Timing: real 0.014s	user 0.005s	sys 0.008s Metrics: {"bytes_written":4512903,"delete_count":0,"lbm_write_time_us":5692,"lbm_writes_lt_1ms":113,"reinsert_count":0,"update_count":550}
I20260812 06:18:55.116716   667 maintenance_manager.cc:419] P 3a642cd9441b461fb13d5a48427e7fe6: Scheduling FlushDeltaMemStoresOp(f2ecdb559656470780b20a25947dc543): perf score=2.188937
I20260812 06:18:55.132805   602 maintenance_manager.cc:643] P 3a642cd9441b461fb13d5a48427e7fe6: FlushDeltaMemStoresOp(f2ecdb559656470780b20a25947dc543) complete. Timing: real 0.016s	user 0.010s	sys 0.004s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":5894,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:18:55.133590   667 maintenance_manager.cc:419] P 3a642cd9441b461fb13d5a48427e7fe6: Scheduling MajorDeltaCompactionOp(f2ecdb559656470780b20a25947dc543): perf score=1.000000
I20260812 06:18:55.350848   602 maintenance_manager.cc:643] P 3a642cd9441b461fb13d5a48427e7fe6: MajorDeltaCompactionOp(f2ecdb559656470780b20a25947dc543) complete. Timing: real 0.217s	user 0.163s	sys 0.049s Metrics: {"cfile_cache_miss":634,"cfile_cache_miss_bytes":28836364,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":1666,"lbm_read_time_us":15681,"lbm_reads_lt_1ms":674,"lbm_write_time_us":41606,"lbm_writes_lt_1ms":643,"mutex_wait_us":319,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":136064,"thread_start_us":264,"threads_started":1,"update_count":3000}
I20260812 06:18:55.351745   667 maintenance_manager.cc:419] P 3a642cd9441b461fb13d5a48427e7fe6: Scheduling FlushDeltaMemStoresOp(f2ecdb559656470780b20a25947dc543): perf score=14.095187
I20260812 06:18:55.439006   602 maintenance_manager.cc:643] P 3a642cd9441b461fb13d5a48427e7fe6: FlushDeltaMemStoresOp(f2ecdb559656470780b20a25947dc543) complete. Timing: real 0.087s	user 0.025s	sys 0.030s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":56407,"lbm_writes_10-100_ms":1,"lbm_writes_lt_1ms":402,"reinsert_count":0,"update_count":2000}
I20260812 06:18:55.439800   667 maintenance_manager.cc:419] P 3a642cd9441b461fb13d5a48427e7fe6: Scheduling FlushDeltaMemStoresOp(f2ecdb559656470780b20a25947dc543): perf score=2.188937
I20260812 06:18:55.457401   602 maintenance_manager.cc:643] P 3a642cd9441b461fb13d5a48427e7fe6: FlushDeltaMemStoresOp(f2ecdb559656470780b20a25947dc543) complete. Timing: real 0.017s	user 0.011s	sys 0.004s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":6631,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:55.457919   667 maintenance_manager.cc:419] P 3a642cd9441b461fb13d5a48427e7fe6: Scheduling MajorDeltaCompactionOp(f2ecdb559656470780b20a25947dc543): perf score=1.000000
I20260812 06:18:55.620220   602 maintenance_manager.cc:643] P 3a642cd9441b461fb13d5a48427e7fe6: MajorDeltaCompactionOp(f2ecdb559656470780b20a25947dc543) complete. Timing: real 0.162s	user 0.127s	sys 0.030s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24733722,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":463,"lbm_read_time_us":11274,"lbm_reads_lt_1ms":568,"lbm_write_time_us":30705,"lbm_writes_lt_1ms":543,"mutex_wait_us":109,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":5120,"update_count":2500}
I20260812 06:18:55.621013   667 maintenance_manager.cc:419] P 3a642cd9441b461fb13d5a48427e7fe6: Scheduling FlushDeltaMemStoresOp(f2ecdb559656470780b20a25947dc543): perf score=11.118625
I20260812 06:18:55.660358   602 maintenance_manager.cc:643] P 3a642cd9441b461fb13d5a48427e7fe6: FlushDeltaMemStoresOp(f2ecdb559656470780b20a25947dc543) complete. Timing: real 0.039s	user 0.013s	sys 0.025s Metrics: {"bytes_written":12717736,"delete_count":0,"lbm_write_time_us":19539,"lbm_writes_1-10_ms":2,"lbm_writes_lt_1ms":311,"reinsert_count":0,"update_count":1550}
I20260812 06:18:55.663460   667 maintenance_manager.cc:419] P 3a642cd9441b461fb13d5a48427e7fe6: Scheduling FlushDeltaMemStoresOp(f2ecdb559656470780b20a25947dc543): perf score=2.188937
I20260812 06:18:55.688540   602 maintenance_manager.cc:643] P 3a642cd9441b461fb13d5a48427e7fe6: FlushDeltaMemStoresOp(f2ecdb559656470780b20a25947dc543) complete. Timing: real 0.025s	user 0.015s	sys 0.001s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":6375,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:18:55.689057   667 maintenance_manager.cc:419] P 3a642cd9441b461fb13d5a48427e7fe6: Scheduling FlushDeltaMemStoresOp(f2ecdb559656470780b20a25947dc543): perf score=2.188937
I20260812 06:18:55.702355   602 maintenance_manager.cc:643] P 3a642cd9441b461fb13d5a48427e7fe6: FlushDeltaMemStoresOp(f2ecdb559656470780b20a25947dc543) complete. Timing: real 0.013s	user 0.008s	sys 0.003s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5119,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:55.702991   667 maintenance_manager.cc:419] P 3a642cd9441b461fb13d5a48427e7fe6: Scheduling MajorDeltaCompactionOp(f2ecdb559656470780b20a25947dc543): perf score=1.000000
I20260812 06:18:55.872678   602 maintenance_manager.cc:643] P 3a642cd9441b461fb13d5a48427e7fe6: MajorDeltaCompactionOp(f2ecdb559656470780b20a25947dc543) complete. Timing: real 0.169s	user 0.136s	sys 0.028s Metrics: {"cfile_cache_miss":533,"cfile_cache_miss_bytes":24733835,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":693,"lbm_read_time_us":12272,"lbm_reads_lt_1ms":573,"lbm_write_time_us":31033,"lbm_writes_lt_1ms":543,"mutex_wait_us":76,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":674816,"update_count":2500}
I20260812 06:18:55.873458   667 maintenance_manager.cc:419] P 3a642cd9441b461fb13d5a48427e7fe6: Scheduling FlushDeltaMemStoresOp(f2ecdb559656470780b20a25947dc543): perf score=11.118625
I20260812 06:18:55.911350   602 maintenance_manager.cc:643] P 3a642cd9441b461fb13d5a48427e7fe6: FlushDeltaMemStoresOp(f2ecdb559656470780b20a25947dc543) complete. Timing: real 0.038s	user 0.026s	sys 0.011s Metrics: {"bytes_written":12717735,"delete_count":0,"lbm_write_time_us":16582,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:18:55.912191   667 maintenance_manager.cc:419] P 3a642cd9441b461fb13d5a48427e7fe6: Scheduling FlushDeltaMemStoresOp(f2ecdb559656470780b20a25947dc543): perf score=2.188937
I20260812 06:18:55.933167   602 maintenance_manager.cc:643] P 3a642cd9441b461fb13d5a48427e7fe6: FlushDeltaMemStoresOp(f2ecdb559656470780b20a25947dc543) complete. Timing: real 0.021s	user 0.012s	sys 0.000s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":5453,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:18:55.933686   667 maintenance_manager.cc:419] P 3a642cd9441b461fb13d5a48427e7fe6: Scheduling MajorDeltaCompactionOp(f2ecdb559656470780b20a25947dc543): perf score=1.000000
I20260812 06:18:56.121013   602 maintenance_manager.cc:643] P 3a642cd9441b461fb13d5a48427e7fe6: MajorDeltaCompactionOp(f2ecdb559656470780b20a25947dc543) complete. Timing: real 0.187s	user 0.150s	sys 0.028s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20631303,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":3255,"lbm_read_time_us":11067,"lbm_reads_lt_1ms":464,"lbm_write_time_us":34306,"lbm_writes_lt_1ms":443,"mutex_wait_us":996,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":896,"update_count":2000}
I20260812 06:18:56.121940   667 maintenance_manager.cc:419] P 3a642cd9441b461fb13d5a48427e7fe6: Scheduling FlushDeltaMemStoresOp(f2ecdb559656470780b20a25947dc543): perf score=11.118625
I20260812 06:18:56.175819   602 maintenance_manager.cc:643] P 3a642cd9441b461fb13d5a48427e7fe6: FlushDeltaMemStoresOp(f2ecdb559656470780b20a25947dc543) complete. Timing: real 0.054s	user 0.029s	sys 0.023s Metrics: {"bytes_written":12717735,"delete_count":0,"lbm_write_time_us":18393,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:18:56.176558   667 maintenance_manager.cc:419] P 3a642cd9441b461fb13d5a48427e7fe6: Scheduling FlushDeltaMemStoresOp(f2ecdb559656470780b20a25947dc543): perf score=2.188937
I20260812 06:18:56.205307   602 maintenance_manager.cc:643] P 3a642cd9441b461fb13d5a48427e7fe6: FlushDeltaMemStoresOp(f2ecdb559656470780b20a25947dc543) complete. Timing: real 0.029s	user 0.003s	sys 0.007s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":4851,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:18:56.205850   667 maintenance_manager.cc:419] P 3a642cd9441b461fb13d5a48427e7fe6: Scheduling FlushDeltaMemStoresOp(f2ecdb559656470780b20a25947dc543): perf score=2.188937
I20260812 06:18:56.218910   602 maintenance_manager.cc:643] P 3a642cd9441b461fb13d5a48427e7fe6: FlushDeltaMemStoresOp(f2ecdb559656470780b20a25947dc543) complete. Timing: real 0.013s	user 0.013s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5052,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:56.219499   667 maintenance_manager.cc:419] P 3a642cd9441b461fb13d5a48427e7fe6: Scheduling MajorDeltaCompactionOp(f2ecdb559656470780b20a25947dc543): perf score=1.000000
I20260812 06:18:56.423910   602 maintenance_manager.cc:643] P 3a642cd9441b461fb13d5a48427e7fe6: MajorDeltaCompactionOp(f2ecdb559656470780b20a25947dc543) complete. Timing: real 0.204s	user 0.128s	sys 0.063s Metrics: {"cfile_cache_miss":533,"cfile_cache_miss_bytes":24733834,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":1295,"lbm_read_time_us":13599,"lbm_reads_lt_1ms":573,"lbm_write_time_us":33238,"lbm_writes_lt_1ms":543,"mutex_wait_us":291,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":18560,"update_count":2500}
I20260812 06:18:56.424974   667 maintenance_manager.cc:419] P 3a642cd9441b461fb13d5a48427e7fe6: Scheduling FlushDeltaMemStoresOp(f2ecdb559656470780b20a25947dc543): perf score=14.095187
I20260812 06:18:56.496052   602 maintenance_manager.cc:643] P 3a642cd9441b461fb13d5a48427e7fe6: FlushDeltaMemStoresOp(f2ecdb559656470780b20a25947dc543) complete. Timing: real 0.071s	user 0.037s	sys 0.027s Metrics: {"bytes_written":16409905,"delete_count":0,"lbm_write_time_us":24879,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:18:56.496893   667 maintenance_manager.cc:419] P 3a642cd9441b461fb13d5a48427e7fe6: Scheduling FlushDeltaMemStoresOp(f2ecdb559656470780b20a25947dc543): perf score=2.188937
I20260812 06:18:56.509613   602 maintenance_manager.cc:643] P 3a642cd9441b461fb13d5a48427e7fe6: FlushDeltaMemStoresOp(f2ecdb559656470780b20a25947dc543) complete. Timing: real 0.012s	user 0.009s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4427,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:56.510250   667 maintenance_manager.cc:419] P 3a642cd9441b461fb13d5a48427e7fe6: Scheduling MajorDeltaCompactionOp(f2ecdb559656470780b20a25947dc543): perf score=1.000000
I20260812 06:18:56.733875   602 maintenance_manager.cc:643] P 3a642cd9441b461fb13d5a48427e7fe6: MajorDeltaCompactionOp(f2ecdb559656470780b20a25947dc543) complete. Timing: real 0.223s	user 0.132s	sys 0.075s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24733727,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":4717,"dirs.run_cpu_time_us":594,"dirs.run_wall_time_us":3715,"lbm_read_time_us":15821,"lbm_reads_lt_1ms":572,"lbm_write_time_us":35396,"lbm_writes_lt_1ms":543,"mutex_wait_us":3518,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":29568,"update_count":2500}
I20260812 06:18:56.734652   667 maintenance_manager.cc:419] P 3a642cd9441b461fb13d5a48427e7fe6: Scheduling FlushDeltaMemStoresOp(f2ecdb559656470780b20a25947dc543): perf score=14.095187
I20260812 06:18:56.793776   602 maintenance_manager.cc:643] P 3a642cd9441b461fb13d5a48427e7fe6: FlushDeltaMemStoresOp(f2ecdb559656470780b20a25947dc543) complete. Timing: real 0.059s	user 0.040s	sys 0.016s Metrics: {"bytes_written":16409912,"delete_count":0,"lbm_write_time_us":22051,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:18:56.794399   667 maintenance_manager.cc:419] P 3a642cd9441b461fb13d5a48427e7fe6: Scheduling FlushDeltaMemStoresOp(f2ecdb559656470780b20a25947dc543): perf score=2.188937
I20260812 06:18:56.805601   602 maintenance_manager.cc:643] P 3a642cd9441b461fb13d5a48427e7fe6: FlushDeltaMemStoresOp(f2ecdb559656470780b20a25947dc543) complete. Timing: real 0.011s	user 0.006s	sys 0.003s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4303,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:56.806165   667 maintenance_manager.cc:419] P 3a642cd9441b461fb13d5a48427e7fe6: Scheduling FlushMRSOp(f2ecdb559656470780b20a25947dc543): perf score=1.000000
I20260812 06:18:56.845626   602 maintenance_manager.cc:643] P 3a642cd9441b461fb13d5a48427e7fe6: FlushMRSOp(f2ecdb559656470780b20a25947dc543) complete. Timing: real 0.039s	user 0.033s	sys 0.004s Metrics: {"bytes_written":1275449,"cfile_init":1,"dirs.queue_time_us":94,"dirs.run_cpu_time_us":288,"dirs.run_wall_time_us":2313,"drs_written":1,"lbm_read_time_us":45,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1928,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":31}
I20260812 06:18:56.846448   667 maintenance_manager.cc:419] P 3a642cd9441b461fb13d5a48427e7fe6: Scheduling LogGCOp(f2ecdb559656470780b20a25947dc543): free 132571256 bytes of WAL
I20260812 06:18:56.846776   602 log_reader.cc:385] T f2ecdb559656470780b20a25947dc543: removed 13 log segments from log reader
I20260812 06:18:56.846844   602 log.cc:1079] T f2ecdb559656470780b20a25947dc543 P 3a642cd9441b461fb13d5a48427e7fe6: Deleting log segment in path: /tmp/dist-test-taskyiE61X/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515526977841-32748-0/minicluster-data/ts-0-root/wals/f2ecdb559656470780b20a25947dc543/wal-000000014 (ops 65-68)
I20260812 06:18:56.846907   602 log.cc:1079] T f2ecdb559656470780b20a25947dc543 P 3a642cd9441b461fb13d5a48427e7fe6: Deleting log segment in path: /tmp/dist-test-taskyiE61X/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515526977841-32748-0/minicluster-data/ts-0-root/wals/f2ecdb559656470780b20a25947dc543/wal-000000015 (ops 69-73)
I20260812 06:18:56.846972   602 log.cc:1079] T f2ecdb559656470780b20a25947dc543 P 3a642cd9441b461fb13d5a48427e7fe6: Deleting log segment in path: /tmp/dist-test-taskyiE61X/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515526977841-32748-0/minicluster-data/ts-0-root/wals/f2ecdb559656470780b20a25947dc543/wal-000000016 (ops 74-78)
I20260812 06:18:56.847021   602 log.cc:1079] T f2ecdb559656470780b20a25947dc543 P 3a642cd9441b461fb13d5a48427e7fe6: Deleting log segment in path: /tmp/dist-test-taskyiE61X/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515526977841-32748-0/minicluster-data/ts-0-root/wals/f2ecdb559656470780b20a25947dc543/wal-000000017 (ops 79-83)
I20260812 06:18:56.847064   602 log.cc:1079] T f2ecdb559656470780b20a25947dc543 P 3a642cd9441b461fb13d5a48427e7fe6: Deleting log segment in path: /tmp/dist-test-taskyiE61X/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515526977841-32748-0/minicluster-data/ts-0-root/wals/f2ecdb559656470780b20a25947dc543/wal-000000018 (ops 84-88)
I20260812 06:18:56.847106   602 log.cc:1079] T f2ecdb559656470780b20a25947dc543 P 3a642cd9441b461fb13d5a48427e7fe6: Deleting log segment in path: /tmp/dist-test-taskyiE61X/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515526977841-32748-0/minicluster-data/ts-0-root/wals/f2ecdb559656470780b20a25947dc543/wal-000000019 (ops 89-93)
I20260812 06:18:56.847146   602 log.cc:1079] T f2ecdb559656470780b20a25947dc543 P 3a642cd9441b461fb13d5a48427e7fe6: Deleting log segment in path: /tmp/dist-test-taskyiE61X/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515526977841-32748-0/minicluster-data/ts-0-root/wals/f2ecdb559656470780b20a25947dc543/wal-000000020 (ops 94-98)
I20260812 06:18:56.847229   602 log.cc:1079] T f2ecdb559656470780b20a25947dc543 P 3a642cd9441b461fb13d5a48427e7fe6: Deleting log segment in path: /tmp/dist-test-taskyiE61X/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515526977841-32748-0/minicluster-data/ts-0-root/wals/f2ecdb559656470780b20a25947dc543/wal-000000021 (ops 99-103)
I20260812 06:18:56.847277   602 log.cc:1079] T f2ecdb559656470780b20a25947dc543 P 3a642cd9441b461fb13d5a48427e7fe6: Deleting log segment in path: /tmp/dist-test-taskyiE61X/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515526977841-32748-0/minicluster-data/ts-0-root/wals/f2ecdb559656470780b20a25947dc543/wal-000000022 (ops 104-108)
I20260812 06:18:56.847306   602 log.cc:1079] T f2ecdb559656470780b20a25947dc543 P 3a642cd9441b461fb13d5a48427e7fe6: Deleting log segment in path: /tmp/dist-test-taskyiE61X/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515526977841-32748-0/minicluster-data/ts-0-root/wals/f2ecdb559656470780b20a25947dc543/wal-000000023 (ops 109-113)
I20260812 06:18:56.847388   602 log.cc:1079] T f2ecdb559656470780b20a25947dc543 P 3a642cd9441b461fb13d5a48427e7fe6: Deleting log segment in path: /tmp/dist-test-taskyiE61X/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515526977841-32748-0/minicluster-data/ts-0-root/wals/f2ecdb559656470780b20a25947dc543/wal-000000024 (ops 114-118)
I20260812 06:18:56.847462   602 log.cc:1079] T f2ecdb559656470780b20a25947dc543 P 3a642cd9441b461fb13d5a48427e7fe6: Deleting log segment in path: /tmp/dist-test-taskyiE61X/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515526977841-32748-0/minicluster-data/ts-0-root/wals/f2ecdb559656470780b20a25947dc543/wal-000000025 (ops 119-122)
I20260812 06:18:56.847503   602 log.cc:1079] T f2ecdb559656470780b20a25947dc543 P 3a642cd9441b461fb13d5a48427e7fe6: Deleting log segment in path: /tmp/dist-test-taskyiE61X/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515526977841-32748-0/minicluster-data/ts-0-root/wals/f2ecdb559656470780b20a25947dc543/wal-000000026 (ops 123-127)
I20260812 06:18:56.878165   602 maintenance_manager.cc:643] P 3a642cd9441b461fb13d5a48427e7fe6: LogGCOp(f2ecdb559656470780b20a25947dc543) complete. Timing: real 0.032s	user 0.001s	sys 0.027s Metrics: {}
I20260812 06:18:56.878827   667 maintenance_manager.cc:419] P 3a642cd9441b461fb13d5a48427e7fe6: Scheduling FlushDeltaMemStoresOp(f2ecdb559656470780b20a25947dc543): perf score=3.181125
I20260812 06:18:56.894593   602 maintenance_manager.cc:643] P 3a642cd9441b461fb13d5a48427e7fe6: FlushDeltaMemStoresOp(f2ecdb559656470780b20a25947dc543) complete. Timing: real 0.016s	user 0.010s	sys 0.001s Metrics: {"bytes_written":4512903,"delete_count":0,"lbm_write_time_us":5128,"lbm_writes_lt_1ms":113,"reinsert_count":0,"update_count":550}
I20260812 06:18:56.895131   667 maintenance_manager.cc:419] P 3a642cd9441b461fb13d5a48427e7fe6: Scheduling UndoDeltaBlockGCOp(f2ecdb559656470780b20a25947dc543): 483 bytes on disk
I20260812 06:18:56.895608   602 maintenance_manager.cc:643] P 3a642cd9441b461fb13d5a48427e7fe6: UndoDeltaBlockGCOp(f2ecdb559656470780b20a25947dc543) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":72,"lbm_reads_lt_1ms":4}
I20260812 06:18:56.896116   667 maintenance_manager.cc:419] P 3a642cd9441b461fb13d5a48427e7fe6: Scheduling FlushDeltaMemStoresOp(f2ecdb559656470780b20a25947dc543): perf score=2.188937
I20260812 06:18:56.912379   602 maintenance_manager.cc:643] P 3a642cd9441b461fb13d5a48427e7fe6: FlushDeltaMemStoresOp(f2ecdb559656470780b20a25947dc543) complete. Timing: real 0.016s	user 0.010s	sys 0.004s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":5905,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:18:56.913051   667 maintenance_manager.cc:419] P 3a642cd9441b461fb13d5a48427e7fe6: Scheduling MajorDeltaCompactionOp(f2ecdb559656470780b20a25947dc543): perf score=1.000000
I20260812 06:18:57.157347   602 maintenance_manager.cc:643] P 3a642cd9441b461fb13d5a48427e7fe6: MajorDeltaCompactionOp(f2ecdb559656470780b20a25947dc543) complete. Timing: real 0.244s	user 0.178s	sys 0.062s Metrics: {"cfile_cache_miss":734,"cfile_cache_miss_bytes":32938786,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":1030,"lbm_read_time_us":17523,"lbm_reads_lt_1ms":774,"lbm_write_time_us":41356,"lbm_writes_lt_1ms":743,"mutex_wait_us":230,"peak_mem_usage":87969044,"reinsert_count":0,"spinlock_wait_cycles":8960,"thread_start_us":86,"threads_started":1,"update_count":3500}
I20260812 06:18:57.158249   667 maintenance_manager.cc:419] P 3a642cd9441b461fb13d5a48427e7fe6: Scheduling FlushDeltaMemStoresOp(f2ecdb559656470780b20a25947dc543): perf score=15.087375
I20260812 06:18:57.209682   602 maintenance_manager.cc:643] P 3a642cd9441b461fb13d5a48427e7fe6: FlushDeltaMemStoresOp(f2ecdb559656470780b20a25947dc543) complete. Timing: real 0.051s	user 0.036s	sys 0.012s Metrics: {"bytes_written":16820143,"delete_count":0,"lbm_write_time_us":22445,"lbm_writes_lt_1ms":413,"reinsert_count":0,"update_count":2050}
I20260812 06:18:57.210412   667 maintenance_manager.cc:419] P 3a642cd9441b461fb13d5a48427e7fe6: Scheduling FlushDeltaMemStoresOp(f2ecdb559656470780b20a25947dc543): perf score=2.188937
I20260812 06:18:57.225696   602 maintenance_manager.cc:643] P 3a642cd9441b461fb13d5a48427e7fe6: FlushDeltaMemStoresOp(f2ecdb559656470780b20a25947dc543) complete. Timing: real 0.015s	user 0.010s	sys 0.003s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":6008,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:18:57.226241   667 maintenance_manager.cc:419] P 3a642cd9441b461fb13d5a48427e7fe6: Scheduling MajorDeltaCompactionOp(f2ecdb559656470780b20a25947dc543): perf score=1.000000
I20260812 06:18:57.413314   602 maintenance_manager.cc:643] P 3a642cd9441b461fb13d5a48427e7fe6: MajorDeltaCompactionOp(f2ecdb559656470780b20a25947dc543) complete. Timing: real 0.187s	user 0.118s	sys 0.067s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24733711,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":904,"lbm_read_time_us":12001,"lbm_reads_lt_1ms":564,"lbm_write_time_us":30211,"lbm_writes_lt_1ms":543,"mutex_wait_us":365,"peak_mem_usage":63115900,"reinsert_count":0,"update_count":2500}
I20260812 06:18:57.413975   667 maintenance_manager.cc:419] P 3a642cd9441b461fb13d5a48427e7fe6: Scheduling FlushDeltaMemStoresOp(f2ecdb559656470780b20a25947dc543): perf score=14.095187
I20260812 06:18:57.473943   602 maintenance_manager.cc:643] P 3a642cd9441b461fb13d5a48427e7fe6: FlushDeltaMemStoresOp(f2ecdb559656470780b20a25947dc543) complete. Timing: real 0.060s	user 0.039s	sys 0.015s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":26255,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:18:57.474649   667 maintenance_manager.cc:419] P 3a642cd9441b461fb13d5a48427e7fe6: Scheduling MajorDeltaCompactionOp(f2ecdb559656470780b20a25947dc543): perf score=1.000000
I20260812 06:18:57.647575   602 maintenance_manager.cc:643] P 3a642cd9441b461fb13d5a48427e7fe6: MajorDeltaCompactionOp(f2ecdb559656470780b20a25947dc543) complete. Timing: real 0.173s	user 0.099s	sys 0.064s Metrics: {"cfile_cache_miss":431,"cfile_cache_miss_bytes":20631193,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":1,"delta_iterators_relevant":1,"dirs.queue_time_us":1329,"lbm_read_time_us":11444,"lbm_reads_lt_1ms":463,"lbm_write_time_us":28868,"lbm_writes_lt_1ms":443,"mutex_wait_us":339,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":11392,"update_count":2000}
I20260812 06:18:57.648479   667 maintenance_manager.cc:419] P 3a642cd9441b461fb13d5a48427e7fe6: Scheduling FlushDeltaMemStoresOp(f2ecdb559656470780b20a25947dc543): perf score=14.095187
I20260812 06:18:57.708603   602 maintenance_manager.cc:643] P 3a642cd9441b461fb13d5a48427e7fe6: FlushDeltaMemStoresOp(f2ecdb559656470780b20a25947dc543) complete. Timing: real 0.060s	user 0.030s	sys 0.028s Metrics: {"bytes_written":16409906,"delete_count":0,"lbm_write_time_us":27426,"lbm_writes_lt_1ms":403,"reinsert_count":0,"spinlock_wait_cycles":1792,"update_count":2000}
I20260812 06:18:57.709502   667 maintenance_manager.cc:419] P 3a642cd9441b461fb13d5a48427e7fe6: Scheduling FlushDeltaMemStoresOp(f2ecdb559656470780b20a25947dc543): perf score=2.188937
I20260812 06:18:57.722002   602 maintenance_manager.cc:643] P 3a642cd9441b461fb13d5a48427e7fe6: FlushDeltaMemStoresOp(f2ecdb559656470780b20a25947dc543) complete. Timing: real 0.012s	user 0.002s	sys 0.007s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4718,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:57.722950   667 maintenance_manager.cc:419] P 3a642cd9441b461fb13d5a48427e7fe6: Scheduling MajorDeltaCompactionOp(f2ecdb559656470780b20a25947dc543): perf score=1.000000
I20260812 06:18:57.945888   602 maintenance_manager.cc:643] P 3a642cd9441b461fb13d5a48427e7fe6: MajorDeltaCompactionOp(f2ecdb559656470780b20a25947dc543) complete. Timing: real 0.223s	user 0.128s	sys 0.080s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24733728,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":549,"lbm_read_time_us":12123,"lbm_reads_lt_1ms":572,"lbm_write_time_us":44467,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":542,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":3712,"update_count":2500}
I20260812 06:18:57.947093   667 maintenance_manager.cc:419] P 3a642cd9441b461fb13d5a48427e7fe6: Scheduling FlushDeltaMemStoresOp(f2ecdb559656470780b20a25947dc543): perf score=11.118625
I20260812 06:18:57.988806   602 maintenance_manager.cc:643] P 3a642cd9441b461fb13d5a48427e7fe6: FlushDeltaMemStoresOp(f2ecdb559656470780b20a25947dc543) complete. Timing: real 0.041s	user 0.019s	sys 0.020s Metrics: {"bytes_written":12717737,"delete_count":0,"lbm_write_time_us":17812,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:18:57.989750   667 maintenance_manager.cc:419] P 3a642cd9441b461fb13d5a48427e7fe6: Scheduling FlushDeltaMemStoresOp(f2ecdb559656470780b20a25947dc543): perf score=2.188937
I20260812 06:18:58.010015   602 maintenance_manager.cc:643] P 3a642cd9441b461fb13d5a48427e7fe6: FlushDeltaMemStoresOp(f2ecdb559656470780b20a25947dc543) complete. Timing: real 0.020s	user 0.018s	sys 0.000s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":7438,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:18:58.010599   667 maintenance_manager.cc:419] P 3a642cd9441b461fb13d5a48427e7fe6: Scheduling MajorDeltaCompactionOp(f2ecdb559656470780b20a25947dc543): perf score=1.000000
I20260812 06:18:58.156852   602 maintenance_manager.cc:643] P 3a642cd9441b461fb13d5a48427e7fe6: MajorDeltaCompactionOp(f2ecdb559656470780b20a25947dc543) complete. Timing: real 0.146s	user 0.101s	sys 0.041s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20631305,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":688,"lbm_read_time_us":10699,"lbm_reads_lt_1ms":464,"lbm_write_time_us":26618,"lbm_writes_lt_1ms":443,"mutex_wait_us":75,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":6912,"update_count":2000}
I20260812 06:18:58.157653   667 maintenance_manager.cc:419] P 3a642cd9441b461fb13d5a48427e7fe6: Scheduling FlushDeltaMemStoresOp(f2ecdb559656470780b20a25947dc543): perf score=10.126437
I20260812 06:18:58.204492   602 maintenance_manager.cc:643] P 3a642cd9441b461fb13d5a48427e7fe6: FlushDeltaMemStoresOp(f2ecdb559656470780b20a25947dc543) complete. Timing: real 0.047s	user 0.026s	sys 0.012s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":17054,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:18:58.205245   667 maintenance_manager.cc:419] P 3a642cd9441b461fb13d5a48427e7fe6: Scheduling MajorDeltaCompactionOp(f2ecdb559656470780b20a25947dc543): perf score=1.000000
I20260812 06:18:58.352751   602 maintenance_manager.cc:643] P 3a642cd9441b461fb13d5a48427e7fe6: MajorDeltaCompactionOp(f2ecdb559656470780b20a25947dc543) complete. Timing: real 0.147s	user 0.122s	sys 0.019s Metrics: {"cfile_cache_miss":331,"cfile_cache_miss_bytes":16528781,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":1,"delta_iterators_relevant":1,"dirs.queue_time_us":233,"lbm_read_time_us":8181,"lbm_reads_lt_1ms":363,"lbm_write_time_us":27558,"lbm_writes_lt_1ms":343,"mutex_wait_us":245,"peak_mem_usage":38262756,"reinsert_count":0,"spinlock_wait_cycles":1408,"update_count":1500}
I20260812 06:18:58.353547   667 maintenance_manager.cc:419] P 3a642cd9441b461fb13d5a48427e7fe6: Scheduling FlushDeltaMemStoresOp(f2ecdb559656470780b20a25947dc543): perf score=10.126437
I20260812 06:18:58.404579   602 maintenance_manager.cc:643] P 3a642cd9441b461fb13d5a48427e7fe6: FlushDeltaMemStoresOp(f2ecdb559656470780b20a25947dc543) complete. Timing: real 0.051s	user 0.024s	sys 0.015s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":17825,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:18:58.405160   667 maintenance_manager.cc:419] P 3a642cd9441b461fb13d5a48427e7fe6: Scheduling FlushDeltaMemStoresOp(f2ecdb559656470780b20a25947dc543): perf score=2.188937
I20260812 06:18:58.419977   602 maintenance_manager.cc:643] P 3a642cd9441b461fb13d5a48427e7fe6: FlushDeltaMemStoresOp(f2ecdb559656470780b20a25947dc543) complete. Timing: real 0.015s	user 0.010s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5091,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:58.421037   667 maintenance_manager.cc:419] P 3a642cd9441b461fb13d5a48427e7fe6: Scheduling MajorDeltaCompactionOp(f2ecdb559656470780b20a25947dc543): perf score=1.000000
I20260812 06:18:58.578192   602 maintenance_manager.cc:643] P 3a642cd9441b461fb13d5a48427e7fe6: MajorDeltaCompactionOp(f2ecdb559656470780b20a25947dc543) complete. Timing: real 0.157s	user 0.107s	sys 0.044s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20631312,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":229,"lbm_read_time_us":10866,"lbm_reads_lt_1ms":472,"lbm_write_time_us":27310,"lbm_writes_lt_1ms":443,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":2176,"update_count":2000}
I20260812 06:18:58.579103   667 maintenance_manager.cc:419] P 3a642cd9441b461fb13d5a48427e7fe6: Scheduling FlushDeltaMemStoresOp(f2ecdb559656470780b20a25947dc543): perf score=10.126437
I20260812 06:18:58.632441   602 maintenance_manager.cc:643] P 3a642cd9441b461fb13d5a48427e7fe6: FlushDeltaMemStoresOp(f2ecdb559656470780b20a25947dc543) complete. Timing: real 0.053s	user 0.031s	sys 0.017s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":21785,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":302,"reinsert_count":0,"update_count":1500}
I20260812 06:18:58.633136   667 maintenance_manager.cc:419] P 3a642cd9441b461fb13d5a48427e7fe6: Scheduling FlushDeltaMemStoresOp(f2ecdb559656470780b20a25947dc543): perf score=2.188937
I20260812 06:18:58.645153   602 maintenance_manager.cc:643] P 3a642cd9441b461fb13d5a48427e7fe6: FlushDeltaMemStoresOp(f2ecdb559656470780b20a25947dc543) complete. Timing: real 0.012s	user 0.001s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4119,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:58.645902   667 maintenance_manager.cc:419] P 3a642cd9441b461fb13d5a48427e7fe6: Scheduling FlushMRSOp(f2ecdb559656470780b20a25947dc543): perf score=1.000000
I20260812 06:18:58.681568   602 maintenance_manager.cc:643] P 3a642cd9441b461fb13d5a48427e7fe6: FlushMRSOp(f2ecdb559656470780b20a25947dc543) complete. Timing: real 0.035s	user 0.033s	sys 0.000s Metrics: {"bytes_written":1275447,"cfile_init":1,"dirs.queue_time_us":89,"dirs.run_cpu_time_us":272,"dirs.run_wall_time_us":1855,"drs_written":1,"lbm_read_time_us":46,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1702,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":31}
I20260812 06:18:58.682507   667 maintenance_manager.cc:419] P 3a642cd9441b461fb13d5a48427e7fe6: Scheduling LogGCOp(f2ecdb559656470780b20a25947dc543): free 128867766 bytes of WAL
I20260812 06:18:58.682834   602 log_reader.cc:385] T f2ecdb559656470780b20a25947dc543: removed 13 log segments from log reader
I20260812 06:18:58.682893   602 log.cc:1079] T f2ecdb559656470780b20a25947dc543 P 3a642cd9441b461fb13d5a48427e7fe6: Deleting log segment in path: /tmp/dist-test-taskyiE61X/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515526977841-32748-0/minicluster-data/ts-0-root/wals/f2ecdb559656470780b20a25947dc543/wal-000000027 (ops 128-132)
I20260812 06:18:58.682924   602 log.cc:1079] T f2ecdb559656470780b20a25947dc543 P 3a642cd9441b461fb13d5a48427e7fe6: Deleting log segment in path: /tmp/dist-test-taskyiE61X/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515526977841-32748-0/minicluster-data/ts-0-root/wals/f2ecdb559656470780b20a25947dc543/wal-000000028 (ops 133-137)
I20260812 06:18:58.682986   602 log.cc:1079] T f2ecdb559656470780b20a25947dc543 P 3a642cd9441b461fb13d5a48427e7fe6: Deleting log segment in path: /tmp/dist-test-taskyiE61X/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515526977841-32748-0/minicluster-data/ts-0-root/wals/f2ecdb559656470780b20a25947dc543/wal-000000029 (ops 138-142)
I20260812 06:18:58.683029   602 log.cc:1079] T f2ecdb559656470780b20a25947dc543 P 3a642cd9441b461fb13d5a48427e7fe6: Deleting log segment in path: /tmp/dist-test-taskyiE61X/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515526977841-32748-0/minicluster-data/ts-0-root/wals/f2ecdb559656470780b20a25947dc543/wal-000000030 (ops 143-146)
I20260812 06:18:58.683073   602 log.cc:1079] T f2ecdb559656470780b20a25947dc543 P 3a642cd9441b461fb13d5a48427e7fe6: Deleting log segment in path: /tmp/dist-test-taskyiE61X/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515526977841-32748-0/minicluster-data/ts-0-root/wals/f2ecdb559656470780b20a25947dc543/wal-000000031 (ops 147-151)
I20260812 06:18:58.683204   602 log.cc:1079] T f2ecdb559656470780b20a25947dc543 P 3a642cd9441b461fb13d5a48427e7fe6: Deleting log segment in path: /tmp/dist-test-taskyiE61X/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515526977841-32748-0/minicluster-data/ts-0-root/wals/f2ecdb559656470780b20a25947dc543/wal-000000032 (ops 152-156)
I20260812 06:18:58.683262   602 log.cc:1079] T f2ecdb559656470780b20a25947dc543 P 3a642cd9441b461fb13d5a48427e7fe6: Deleting log segment in path: /tmp/dist-test-taskyiE61X/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515526977841-32748-0/minicluster-data/ts-0-root/wals/f2ecdb559656470780b20a25947dc543/wal-000000033 (ops 157-160)
I20260812 06:18:58.683290   602 log.cc:1079] T f2ecdb559656470780b20a25947dc543 P 3a642cd9441b461fb13d5a48427e7fe6: Deleting log segment in path: /tmp/dist-test-taskyiE61X/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515526977841-32748-0/minicluster-data/ts-0-root/wals/f2ecdb559656470780b20a25947dc543/wal-000000034 (ops 161-165)
I20260812 06:18:58.683331   602 log.cc:1079] T f2ecdb559656470780b20a25947dc543 P 3a642cd9441b461fb13d5a48427e7fe6: Deleting log segment in path: /tmp/dist-test-taskyiE61X/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515526977841-32748-0/minicluster-data/ts-0-root/wals/f2ecdb559656470780b20a25947dc543/wal-000000035 (ops 166-170)
I20260812 06:18:58.683372   602 log.cc:1079] T f2ecdb559656470780b20a25947dc543 P 3a642cd9441b461fb13d5a48427e7fe6: Deleting log segment in path: /tmp/dist-test-taskyiE61X/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515526977841-32748-0/minicluster-data/ts-0-root/wals/f2ecdb559656470780b20a25947dc543/wal-000000036 (ops 171-174)
I20260812 06:18:58.683413   602 log.cc:1079] T f2ecdb559656470780b20a25947dc543 P 3a642cd9441b461fb13d5a48427e7fe6: Deleting log segment in path: /tmp/dist-test-taskyiE61X/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515526977841-32748-0/minicluster-data/ts-0-root/wals/f2ecdb559656470780b20a25947dc543/wal-000000037 (ops 175-179)
I20260812 06:18:58.683452   602 log.cc:1079] T f2ecdb559656470780b20a25947dc543 P 3a642cd9441b461fb13d5a48427e7fe6: Deleting log segment in path: /tmp/dist-test-taskyiE61X/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515526977841-32748-0/minicluster-data/ts-0-root/wals/f2ecdb559656470780b20a25947dc543/wal-000000038 (ops 180-184)
I20260812 06:18:58.683492   602 log.cc:1079] T f2ecdb559656470780b20a25947dc543 P 3a642cd9441b461fb13d5a48427e7fe6: Deleting log segment in path: /tmp/dist-test-taskyiE61X/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515526977841-32748-0/minicluster-data/ts-0-root/wals/f2ecdb559656470780b20a25947dc543/wal-000000039 (ops 185-189)
I20260812 06:18:58.712518   602 maintenance_manager.cc:643] P 3a642cd9441b461fb13d5a48427e7fe6: LogGCOp(f2ecdb559656470780b20a25947dc543) complete. Timing: real 0.030s	user 0.000s	sys 0.028s Metrics: {}
I20260812 06:18:58.713135   667 maintenance_manager.cc:419] P 3a642cd9441b461fb13d5a48427e7fe6: Scheduling FlushDeltaMemStoresOp(f2ecdb559656470780b20a25947dc543): perf score=3.181125
I20260812 06:18:58.727480   602 maintenance_manager.cc:643] P 3a642cd9441b461fb13d5a48427e7fe6: FlushDeltaMemStoresOp(f2ecdb559656470780b20a25947dc543) complete. Timing: real 0.014s	user 0.013s	sys 0.000s Metrics: {"bytes_written":4512899,"delete_count":0,"lbm_write_time_us":5419,"lbm_writes_lt_1ms":113,"reinsert_count":0,"update_count":550}
I20260812 06:18:58.728139   667 maintenance_manager.cc:419] P 3a642cd9441b461fb13d5a48427e7fe6: Scheduling FlushDeltaMemStoresOp(f2ecdb559656470780b20a25947dc543): perf score=2.188937
I20260812 06:18:58.743520   602 maintenance_manager.cc:643] P 3a642cd9441b461fb13d5a48427e7fe6: FlushDeltaMemStoresOp(f2ecdb559656470780b20a25947dc543) complete. Timing: real 0.015s	user 0.011s	sys 0.004s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":5802,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:18:58.744237   667 maintenance_manager.cc:419] P 3a642cd9441b461fb13d5a48427e7fe6: Scheduling MajorDeltaCompactionOp(f2ecdb559656470780b20a25947dc543): perf score=1.000000
I20260812 06:18:58.960253   602 maintenance_manager.cc:643] P 3a642cd9441b461fb13d5a48427e7fe6: MajorDeltaCompactionOp(f2ecdb559656470780b20a25947dc543) complete. Timing: real 0.216s	user 0.116s	sys 0.087s Metrics: {"cfile_cache_miss":634,"cfile_cache_miss_bytes":28836360,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":2418,"lbm_read_time_us":14890,"lbm_reads_lt_1ms":674,"lbm_write_time_us":40165,"lbm_writes_lt_1ms":643,"mutex_wait_us":558,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":14464,"thread_start_us":97,"threads_started":1,"update_count":3000}
I20260812 06:18:58.961009   667 maintenance_manager.cc:419] P 3a642cd9441b461fb13d5a48427e7fe6: Scheduling UndoDeltaBlockGCOp(f2ecdb559656470780b20a25947dc543): 485 bytes on disk
I20260812 06:18:58.961572   602 maintenance_manager.cc:643] P 3a642cd9441b461fb13d5a48427e7fe6: UndoDeltaBlockGCOp(f2ecdb559656470780b20a25947dc543) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":76,"lbm_reads_lt_1ms":4}
I20260812 06:18:58.962352   667 maintenance_manager.cc:419] P 3a642cd9441b461fb13d5a48427e7fe6: Scheduling FlushDeltaMemStoresOp(f2ecdb559656470780b20a25947dc543): perf score=14.095187
I20260812 06:18:59.029194 32748 heavy-update-compaction-itest.cc:229] Time spent updating: real 5.708s	user 2.132s	sys 0.177s
I20260812 06:18:59.032898   602 maintenance_manager.cc:643] P 3a642cd9441b461fb13d5a48427e7fe6: FlushDeltaMemStoresOp(f2ecdb559656470780b20a25947dc543) complete. Timing: real 0.070s	user 0.041s	sys 0.020s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":29133,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:18:59.033622   667 maintenance_manager.cc:419] P 3a642cd9441b461fb13d5a48427e7fe6: Scheduling FlushDeltaMemStoresOp(f2ecdb559656470780b20a25947dc543): perf score=2.188937
I20260812 06:18:59.044518   602 maintenance_manager.cc:643] P 3a642cd9441b461fb13d5a48427e7fe6: FlushDeltaMemStoresOp(f2ecdb559656470780b20a25947dc543) complete. Timing: real 0.011s	user 0.002s	sys 0.007s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4551,"lbm_writes_lt_1ms":103,"reinsert_count":0,"spinlock_wait_cycles":1408,"update_count":500}
I20260812 06:18:59.045009   667 maintenance_manager.cc:419] P 3a642cd9441b461fb13d5a48427e7fe6: Scheduling MajorDeltaCompactionOp(f2ecdb559656470780b20a25947dc543): perf score=1.000000
I20260812 06:18:59.080701 32748 heavy-update-compaction-itest.cc:265] Time spent scanning: real 0.051s	user 0.003s	sys 0.000s
I20260812 06:18:59.081384 32748 tablet_server.cc:179] TabletServer@127.31.251.1:0 shutting down...
I20260812 06:18:59.166538   602 maintenance_manager.cc:643] P 3a642cd9441b461fb13d5a48427e7fe6: MajorDeltaCompactionOp(f2ecdb559656470780b20a25947dc543) complete. Timing: real 0.121s	user 0.085s	sys 0.036s Metrics: {"cfile_cache_hit":393,"cfile_cache_hit_bytes":16081680,"cfile_cache_miss":139,"cfile_cache_miss_bytes":8652044,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":928,"lbm_read_time_us":3567,"lbm_reads_lt_1ms":171,"lbm_write_time_us":27928,"lbm_writes_lt_1ms":543,"mutex_wait_us":314,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":51072,"update_count":2500}
I20260812 06:18:59.167464 32748 ts_tablet_manager.cc:1507] Shutting down tablet manager...
I20260812 06:18:59.167842 32748 tablet_replica.cc:333] T f2ecdb559656470780b20a25947dc543 P 3a642cd9441b461fb13d5a48427e7fe6: stopping tablet replica
I20260812 06:18:59.168020 32748 raft_consensus.cc:2243] T f2ecdb559656470780b20a25947dc543 P 3a642cd9441b461fb13d5a48427e7fe6 [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:18:59.168215 32748 raft_consensus.cc:2272] T f2ecdb559656470780b20a25947dc543 P 3a642cd9441b461fb13d5a48427e7fe6 [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:18:59.174433 32748 tablet_server.cc:196] TabletServer@127.31.251.1:0 shutdown complete.
I20260812 06:18:59.212764 32748 master.cc:562] Master@127.31.251.62:44891 shutting down...
I20260812 06:18:59.217398 32748 raft_consensus.cc:2243] T 00000000000000000000000000000000 P 24f17e846c61416b8b76d32eb4f0e50f [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:18:59.217603 32748 raft_consensus.cc:2272] T 00000000000000000000000000000000 P 24f17e846c61416b8b76d32eb4f0e50f [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:18:59.217656 32748 tablet_replica.cc:333] T 00000000000000000000000000000000 P 24f17e846c61416b8b76d32eb4f0e50f: stopping tablet replica
I20260812 06:18:59.231166 32748 master.cc:584] Master@127.31.251.62:44891 shutdown complete.
[       OK ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/1 (6249 ms)
[----------] 2 tests from EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy (12332 ms total)

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