[==========] Running 2 tests from 1 test suite.
[----------] Global test environment set-up.
[----------] 2 tests from EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy
[ RUN      ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/0
WARNING: Logging before InitGoogleLogging() is written to STDERR
I20260812 06:19:03.850153 14326 internal_mini_cluster.cc:156] Creating distributed mini masters. Addrs: 127.13.253.190:44007
I20260812 06:19:03.851143 14326 env_posix.cc:2285] Not raising this process' open files per process limit of 1048576; it is already as high as it can go
I20260812 06:19:03.851737 14326 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:19:03.857793 14339 instance_detector.cc:116] could not retrieve Azure instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:19:03.857882 14326 server_base.cc:1061] running on GCE node
W20260812 06:19:03.857769 14337 instance_detector.cc:116] could not retrieve AWS instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:19:03.858067 14345 instance_detector.cc:116] could not retrieve OpenStack instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:19:03.858533 14326 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:19:03.858629 14326 system_unsync_time.cc:38] NTP support is disabled. Clock error bounds will not be accurate. This configuration is not suitable for distributed clusters.
I20260812 06:19:03.858660 14326 hybrid_clock.cc:648] HybridClock initialized: now 1786515543858659 us; error 0 us; skew 500 ppm
I20260812 06:19:03.860399 14326 webserver.cc:533] Webserver started at http://127.13.253.190:33323/ using document root <none> and password file <none>
I20260812 06:19:03.860883 14326 fs_manager.cc:362] Metadata directory not provided
I20260812 06:19:03.860939 14326 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:19:03.861119 14326 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:19:03.862681 14326 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskbgpkED/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515543839567-14326-0/minicluster-data/master-0-root/instance:
uuid: "4ad04750e5ba40a4b87b0231a559bcd0"
format_stamp: "Formatted at 2026-08-12 06:19:03 on dist-test-slave-39l8"
I20260812 06:19:03.865965 14326 fs_manager.cc:696] Time spent creating directory manager: real 0.003s	user 0.002s	sys 0.000s
I20260812 06:19:03.867928 14351 log_block_manager.cc:4127] Time spent loading block containers with low live blocks: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:19:03.869105 14326 fs_manager.cc:730] Time spent opening block manager: real 0.002s	user 0.001s	sys 0.000s
I20260812 06:19:03.869252 14326 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskbgpkED/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515543839567-14326-0/minicluster-data/master-0-root
uuid: "4ad04750e5ba40a4b87b0231a559bcd0"
format_stamp: "Formatted at 2026-08-12 06:19:03 on dist-test-slave-39l8"
I20260812 06:19:03.869343 14326 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskbgpkED/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515543839567-14326-0/minicluster-data/master-0-root
metadata directory: /tmp/dist-test-taskbgpkED/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515543839567-14326-0/minicluster-data/master-0-root
1 data directories: /tmp/dist-test-taskbgpkED/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515543839567-14326-0/minicluster-data/master-0-root/data
Total live blocks: 0
Total live bytes: 0
Total live bytes (after alignment): 0
Total number of LBM containers: 0 (0 full)
Did not check for missing blocks
Did not check for orphaned blocks
Total full LBM containers with extra space: 0 (0 repaired)
Total full LBM container extra space in bytes: 0 (0 repaired)
Total incomplete LBM containers: 0 (0 repaired)
Total LBM partial records: 0 (0 repaired)
Total corrupted LBM metadata records in RocksDB: 0 (0 repaired)
I20260812 06:19:03.885643 14326 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:19:03.886243 14326 env_posix.cc:2285] Not raising this process' running threads per effective uid limit of 18446744073709551615; it is already as high as it can go
I20260812 06:19:03.886417 14326 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:19:03.893555 14326 rpc_server.cc:307] RPC server started. Bound to: 127.13.253.190:44007
I20260812 06:19:03.893620 14449 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.13.253.190:44007 every 8 connection(s)
I20260812 06:19:03.895725 14450 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet 00000000000000000000000000000000. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:19:03.900890 14450 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P 4ad04750e5ba40a4b87b0231a559bcd0: Bootstrap starting.
I20260812 06:19:03.903146 14450 tablet_bootstrap.cc:654] T 00000000000000000000000000000000 P 4ad04750e5ba40a4b87b0231a559bcd0: Neither blocks nor log segments found. Creating new log.
I20260812 06:19:03.904016 14450 log.cc:826] T 00000000000000000000000000000000 P 4ad04750e5ba40a4b87b0231a559bcd0: Log is configured to *not* fsync() on all Append() calls
I20260812 06:19:03.905644 14450 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P 4ad04750e5ba40a4b87b0231a559bcd0: No bootstrap required, opened a new log
I20260812 06:19:03.908655 14450 raft_consensus.cc:359] T 00000000000000000000000000000000 P 4ad04750e5ba40a4b87b0231a559bcd0 [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "4ad04750e5ba40a4b87b0231a559bcd0" member_type: VOTER }
I20260812 06:19:03.908810 14450 raft_consensus.cc:385] T 00000000000000000000000000000000 P 4ad04750e5ba40a4b87b0231a559bcd0 [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:19:03.908849 14450 raft_consensus.cc:740] T 00000000000000000000000000000000 P 4ad04750e5ba40a4b87b0231a559bcd0 [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: 4ad04750e5ba40a4b87b0231a559bcd0, State: Initialized, Role: FOLLOWER
I20260812 06:19:03.909442 14450 consensus_queue.cc:260] T 00000000000000000000000000000000 P 4ad04750e5ba40a4b87b0231a559bcd0 [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: "4ad04750e5ba40a4b87b0231a559bcd0" member_type: VOTER }
I20260812 06:19:03.909580 14450 raft_consensus.cc:399] T 00000000000000000000000000000000 P 4ad04750e5ba40a4b87b0231a559bcd0 [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:19:03.909629 14450 raft_consensus.cc:493] T 00000000000000000000000000000000 P 4ad04750e5ba40a4b87b0231a559bcd0 [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:19:03.909711 14450 raft_consensus.cc:3060] T 00000000000000000000000000000000 P 4ad04750e5ba40a4b87b0231a559bcd0 [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:19:03.910409 14450 raft_consensus.cc:515] T 00000000000000000000000000000000 P 4ad04750e5ba40a4b87b0231a559bcd0 [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "4ad04750e5ba40a4b87b0231a559bcd0" member_type: VOTER }
I20260812 06:19:03.910828 14450 leader_election.cc:304] T 00000000000000000000000000000000 P 4ad04750e5ba40a4b87b0231a559bcd0 [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: 4ad04750e5ba40a4b87b0231a559bcd0; no voters: 
I20260812 06:19:03.911155 14450 leader_election.cc:290] T 00000000000000000000000000000000 P 4ad04750e5ba40a4b87b0231a559bcd0 [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:19:03.911262 14454 raft_consensus.cc:2804] T 00000000000000000000000000000000 P 4ad04750e5ba40a4b87b0231a559bcd0 [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:19:03.911504 14454 raft_consensus.cc:697] T 00000000000000000000000000000000 P 4ad04750e5ba40a4b87b0231a559bcd0 [term 1 LEADER]: Becoming Leader. State: Replica: 4ad04750e5ba40a4b87b0231a559bcd0, State: Running, Role: LEADER
I20260812 06:19:03.911912 14454 consensus_queue.cc:237] T 00000000000000000000000000000000 P 4ad04750e5ba40a4b87b0231a559bcd0 [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: "4ad04750e5ba40a4b87b0231a559bcd0" member_type: VOTER }
I20260812 06:19:03.912161 14450 sys_catalog.cc:565] T 00000000000000000000000000000000 P 4ad04750e5ba40a4b87b0231a559bcd0 [sys.catalog]: configured and running, proceeding with master startup.
I20260812 06:19:03.913718 14456 sys_catalog.cc:455] T 00000000000000000000000000000000 P 4ad04750e5ba40a4b87b0231a559bcd0 [sys.catalog]: SysCatalogTable state changed. Reason: New leader 4ad04750e5ba40a4b87b0231a559bcd0. Latest consensus state: current_term: 1 leader_uuid: "4ad04750e5ba40a4b87b0231a559bcd0" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "4ad04750e5ba40a4b87b0231a559bcd0" member_type: VOTER } }
I20260812 06:19:03.913729 14455 sys_catalog.cc:455] T 00000000000000000000000000000000 P 4ad04750e5ba40a4b87b0231a559bcd0 [sys.catalog]: SysCatalogTable state changed. Reason: RaftConsensus started. Latest consensus state: current_term: 1 leader_uuid: "4ad04750e5ba40a4b87b0231a559bcd0" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "4ad04750e5ba40a4b87b0231a559bcd0" member_type: VOTER } }
I20260812 06:19:03.913899 14455 sys_catalog.cc:458] T 00000000000000000000000000000000 P 4ad04750e5ba40a4b87b0231a559bcd0 [sys.catalog]: This master's current role is: LEADER
I20260812 06:19:03.913893 14456 sys_catalog.cc:458] T 00000000000000000000000000000000 P 4ad04750e5ba40a4b87b0231a559bcd0 [sys.catalog]: This master's current role is: LEADER
I20260812 06:19:03.914356 14477 catalog_manager.cc:1511] Loading table and tablet metadata into memory...
I20260812 06:19:03.914577 14326 internal_mini_cluster.cc:184] Waiting to initialize catalog manager on master 0
I20260812 06:19:03.916566 14477 catalog_manager.cc:1520] Initializing Kudu cluster ID...
I20260812 06:19:03.920909 14477 catalog_manager.cc:1383] Generated new cluster ID: 4f2d27602ff84b02b5bb4d56ece91b01
I20260812 06:19:03.920984 14477 catalog_manager.cc:1531] Initializing Kudu internal certificate authority...
I20260812 06:19:03.943439 14477 catalog_manager.cc:1406] Generated new certificate authority record
I20260812 06:19:03.944293 14477 catalog_manager.cc:1540] Loading token signing keys...
I20260812 06:19:03.949584 14477 catalog_manager.cc:6092] T 00000000000000000000000000000000 P 4ad04750e5ba40a4b87b0231a559bcd0: Generated new TSK 0
I20260812 06:19:03.950152 14477 catalog_manager.cc:1550] Initializing in-progress tserver states...
I20260812 06:19:03.979875 14326 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:19:03.983057 14490 instance_detector.cc:116] could not retrieve Azure instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:19:03.983152 14492 instance_detector.cc:116] could not retrieve OpenStack instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:19:03.983170 14489 instance_detector.cc:116] could not retrieve AWS instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:19:03.983501 14326 server_base.cc:1061] running on GCE node
I20260812 06:19:03.983685 14326 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:19:03.983731 14326 system_unsync_time.cc:38] NTP support is disabled. Clock error bounds will not be accurate. This configuration is not suitable for distributed clusters.
I20260812 06:19:03.983747 14326 hybrid_clock.cc:648] HybridClock initialized: now 1786515543983746 us; error 0 us; skew 500 ppm
I20260812 06:19:03.984649 14326 webserver.cc:533] Webserver started at http://127.13.253.129:46165/ using document root <none> and password file <none>
I20260812 06:19:03.984822 14326 fs_manager.cc:362] Metadata directory not provided
I20260812 06:19:03.984877 14326 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:19:03.984977 14326 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:19:03.985383 14326 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskbgpkED/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515543839567-14326-0/minicluster-data/ts-0-root/instance:
uuid: "4fca7a3611af474e8fa35a3f8d88c1ab"
format_stamp: "Formatted at 2026-08-12 06:19:03 on dist-test-slave-39l8"
I20260812 06:19:03.986974 14326 fs_manager.cc:696] Time spent creating directory manager: real 0.001s	user 0.001s	sys 0.001s
I20260812 06:19:03.987998 14500 log_block_manager.cc:4127] Time spent loading block containers with low live blocks: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:19:03.988240 14326 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.001s	sys 0.000s
I20260812 06:19:03.988309 14326 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskbgpkED/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515543839567-14326-0/minicluster-data/ts-0-root
uuid: "4fca7a3611af474e8fa35a3f8d88c1ab"
format_stamp: "Formatted at 2026-08-12 06:19:03 on dist-test-slave-39l8"
I20260812 06:19:03.988394 14326 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskbgpkED/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515543839567-14326-0/minicluster-data/ts-0-root
metadata directory: /tmp/dist-test-taskbgpkED/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515543839567-14326-0/minicluster-data/ts-0-root
1 data directories: /tmp/dist-test-taskbgpkED/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515543839567-14326-0/minicluster-data/ts-0-root/data
Total live blocks: 0
Total live bytes: 0
Total live bytes (after alignment): 0
Total number of LBM containers: 0 (0 full)
Did not check for missing blocks
Did not check for orphaned blocks
Total full LBM containers with extra space: 0 (0 repaired)
Total full LBM container extra space in bytes: 0 (0 repaired)
Total incomplete LBM containers: 0 (0 repaired)
Total LBM partial records: 0 (0 repaired)
Total corrupted LBM metadata records in RocksDB: 0 (0 repaired)
I20260812 06:19:04.002679 14326 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:19:04.003538 14326 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:19:04.004037 14326 txn_system_client.cc:432] TxnSystemClient initialization is disabled...
I20260812 06:19:04.004889 14326 ts_tablet_manager.cc:585] Loaded tablet metadata (0 total tablets, 0 live tablets)
I20260812 06:19:04.004942 14326 ts_tablet_manager.cc:531] Time spent load tablet metadata: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:19:04.005010 14326 ts_tablet_manager.cc:616] Registered 0 tablets
I20260812 06:19:04.005049 14326 ts_tablet_manager.cc:595] Time spent register tablets: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:19:04.012017 14326 rpc_server.cc:307] RPC server started. Bound to: 127.13.253.129:46203
I20260812 06:19:04.012272 14595 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.13.253.129:46203 every 8 connection(s)
I20260812 06:19:04.028828 14596 heartbeater.cc:344] Connected to a master server at 127.13.253.190:44007
I20260812 06:19:04.029109 14596 heartbeater.cc:461] Registering TS with master...
I20260812 06:19:04.029548 14596 heartbeater.cc:507] Master 127.13.253.190:44007 requested a full tablet report, sending...
I20260812 06:19:04.031116 14375 ts_manager.cc:194] Registered new tserver with Master: 4fca7a3611af474e8fa35a3f8d88c1ab (127.13.253.129:46203)
I20260812 06:19:04.031234 14326 internal_mini_cluster.cc:371] 1 TS(s) registered with all masters after 0.018231736s
I20260812 06:19:04.032752 14375 master_service.cc:502] Signed X509 certificate for tserver {username='slave'} at 127.0.0.1:46576
I20260812 06:19:04.041311 14375 catalog_manager.cc:2283] Servicing CreateTable request from {username='slave'} at 127.0.0.1:46580:
name: "heavy-update-compaction-test"
schema {
  columns {
    name: "key"
    type: INT64
    is_key: true
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_a"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_b"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_c"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_d"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_e"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
}
num_replicas: 1
split_rows_range_bounds {
}
partition_schema {
  range_schema {
  }
}
I20260812 06:19:04.056195 14542 tablet_service.cc:1511] Processing CreateTablet for tablet e931487044eb49f3813d57b50b449524 (DEFAULT_TABLE table=heavy-update-compaction-test [id=cc1bad50d167418d8cafd46885d3d3c1]), partition=
I20260812 06:19:04.056674 14542 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet e931487044eb49f3813d57b50b449524. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:19:04.058856 14612 tablet_bootstrap.cc:492] T e931487044eb49f3813d57b50b449524 P 4fca7a3611af474e8fa35a3f8d88c1ab: Bootstrap starting.
I20260812 06:19:04.060277 14612 tablet_bootstrap.cc:654] T e931487044eb49f3813d57b50b449524 P 4fca7a3611af474e8fa35a3f8d88c1ab: Neither blocks nor log segments found. Creating new log.
I20260812 06:19:04.061429 14612 tablet_bootstrap.cc:492] T e931487044eb49f3813d57b50b449524 P 4fca7a3611af474e8fa35a3f8d88c1ab: No bootstrap required, opened a new log
I20260812 06:19:04.061553 14612 ts_tablet_manager.cc:1403] T e931487044eb49f3813d57b50b449524 P 4fca7a3611af474e8fa35a3f8d88c1ab: Time spent bootstrapping tablet: real 0.003s	user 0.000s	sys 0.002s
I20260812 06:19:04.061962 14612 raft_consensus.cc:359] T e931487044eb49f3813d57b50b449524 P 4fca7a3611af474e8fa35a3f8d88c1ab [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "4fca7a3611af474e8fa35a3f8d88c1ab" member_type: VOTER last_known_addr { host: "127.13.253.129" port: 46203 } }
I20260812 06:19:04.062085 14612 raft_consensus.cc:385] T e931487044eb49f3813d57b50b449524 P 4fca7a3611af474e8fa35a3f8d88c1ab [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:19:04.062162 14612 raft_consensus.cc:740] T e931487044eb49f3813d57b50b449524 P 4fca7a3611af474e8fa35a3f8d88c1ab [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: 4fca7a3611af474e8fa35a3f8d88c1ab, State: Initialized, Role: FOLLOWER
I20260812 06:19:04.062321 14612 consensus_queue.cc:260] T e931487044eb49f3813d57b50b449524 P 4fca7a3611af474e8fa35a3f8d88c1ab [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: "4fca7a3611af474e8fa35a3f8d88c1ab" member_type: VOTER last_known_addr { host: "127.13.253.129" port: 46203 } }
I20260812 06:19:04.062431 14612 raft_consensus.cc:399] T e931487044eb49f3813d57b50b449524 P 4fca7a3611af474e8fa35a3f8d88c1ab [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:19:04.062481 14612 raft_consensus.cc:493] T e931487044eb49f3813d57b50b449524 P 4fca7a3611af474e8fa35a3f8d88c1ab [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:19:04.062533 14612 raft_consensus.cc:3060] T e931487044eb49f3813d57b50b449524 P 4fca7a3611af474e8fa35a3f8d88c1ab [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:19:04.063385 14612 raft_consensus.cc:515] T e931487044eb49f3813d57b50b449524 P 4fca7a3611af474e8fa35a3f8d88c1ab [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "4fca7a3611af474e8fa35a3f8d88c1ab" member_type: VOTER last_known_addr { host: "127.13.253.129" port: 46203 } }
I20260812 06:19:04.063551 14612 leader_election.cc:304] T e931487044eb49f3813d57b50b449524 P 4fca7a3611af474e8fa35a3f8d88c1ab [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: 4fca7a3611af474e8fa35a3f8d88c1ab; no voters: 
I20260812 06:19:04.063822 14612 leader_election.cc:290] T e931487044eb49f3813d57b50b449524 P 4fca7a3611af474e8fa35a3f8d88c1ab [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:19:04.064047 14615 raft_consensus.cc:2804] T e931487044eb49f3813d57b50b449524 P 4fca7a3611af474e8fa35a3f8d88c1ab [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:19:04.064224 14615 raft_consensus.cc:697] T e931487044eb49f3813d57b50b449524 P 4fca7a3611af474e8fa35a3f8d88c1ab [term 1 LEADER]: Becoming Leader. State: Replica: 4fca7a3611af474e8fa35a3f8d88c1ab, State: Running, Role: LEADER
I20260812 06:19:04.064232 14612 ts_tablet_manager.cc:1434] T e931487044eb49f3813d57b50b449524 P 4fca7a3611af474e8fa35a3f8d88c1ab: Time spent starting tablet: real 0.003s	user 0.000s	sys 0.003s
I20260812 06:19:04.064379 14615 consensus_queue.cc:237] T e931487044eb49f3813d57b50b449524 P 4fca7a3611af474e8fa35a3f8d88c1ab [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: "4fca7a3611af474e8fa35a3f8d88c1ab" member_type: VOTER last_known_addr { host: "127.13.253.129" port: 46203 } }
I20260812 06:19:04.064574 14596 heartbeater.cc:499] Master 127.13.253.190:44007 was elected leader, sending a full tablet report...
I20260812 06:19:04.066869 14375 catalog_manager.cc:5719] T e931487044eb49f3813d57b50b449524 P 4fca7a3611af474e8fa35a3f8d88c1ab reported cstate change: term changed from 0 to 1, leader changed from <none> to 4fca7a3611af474e8fa35a3f8d88c1ab (127.13.253.129). New cstate: current_term: 1 leader_uuid: "4fca7a3611af474e8fa35a3f8d88c1ab" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "4fca7a3611af474e8fa35a3f8d88c1ab" member_type: VOTER last_known_addr { host: "127.13.253.129" port: 46203 } health_report { overall_health: HEALTHY } } }
I20260812 06:19:04.133805 14326 heavy-update-compaction-itest.cc:215] Time spent inserting: real 0.057s	user 0.021s	sys 0.009s
I20260812 06:19:04.263401 14597 maintenance_manager.cc:419] P 4fca7a3611af474e8fa35a3f8d88c1ab: Scheduling FlushMRSOp(e931487044eb49f3813d57b50b449524): perf score=19.054940
I20260812 06:19:04.443758 14506 maintenance_manager.cc:643] P 4fca7a3611af474e8fa35a3f8d88c1ab: FlushMRSOp(e931487044eb49f3813d57b50b449524) complete. Timing: real 0.180s	user 0.113s	sys 0.065s Metrics: {"bytes_written":12799789,"cfile_init":1,"compiler_manager_pool.queue_time_us":184,"delete_count":0,"dirs.queue_time_us":45,"dirs.run_cpu_time_us":240,"dirs.run_wall_time_us":846,"drs_written":1,"lbm_read_time_us":74,"lbm_reads_lt_1ms":4,"lbm_write_time_us":44057,"lbm_writes_lt_1ms":769,"peak_mem_usage":0,"reinsert_count":0,"rows_written":104,"spinlock_wait_cycles":167808,"thread_start_us":120,"threads_started":1,"update_count":1560}
I20260812 06:19:04.445050 14597 maintenance_manager.cc:419] P 4fca7a3611af474e8fa35a3f8d88c1ab: Scheduling LogGCOp(e931487044eb49f3813d57b50b449524): free 20743880 bytes of WAL
I20260812 06:19:04.445346 14506 log_reader.cc:385] T e931487044eb49f3813d57b50b449524: removed 2 log segments from log reader
I20260812 06:19:04.445423 14506 log.cc:1079] T e931487044eb49f3813d57b50b449524 P 4fca7a3611af474e8fa35a3f8d88c1ab: Deleting log segment in path: /tmp/dist-test-taskbgpkED/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515543839567-14326-0/minicluster-data/ts-0-root/wals/e931487044eb49f3813d57b50b449524/wal-000000001 (ops 1-6)
I20260812 06:19:04.445494 14506 log.cc:1079] T e931487044eb49f3813d57b50b449524 P 4fca7a3611af474e8fa35a3f8d88c1ab: Deleting log segment in path: /tmp/dist-test-taskbgpkED/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515543839567-14326-0/minicluster-data/ts-0-root/wals/e931487044eb49f3813d57b50b449524/wal-000000002 (ops 7-11)
I20260812 06:19:04.449633 14506 maintenance_manager.cc:643] P 4fca7a3611af474e8fa35a3f8d88c1ab: LogGCOp(e931487044eb49f3813d57b50b449524) complete. Timing: real 0.004s	user 0.000s	sys 0.002s Metrics: {}
I20260812 06:19:04.449980 14597 maintenance_manager.cc:419] P 4fca7a3611af474e8fa35a3f8d88c1ab: Scheduling UndoDeltaBlockGCOp(e931487044eb49f3813d57b50b449524): 16411392 bytes on disk
I20260812 06:19:04.450500 14506 maintenance_manager.cc:643] P 4fca7a3611af474e8fa35a3f8d88c1ab: UndoDeltaBlockGCOp(e931487044eb49f3813d57b50b449524) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":51,"lbm_reads_lt_1ms":4}
I20260812 06:19:04.451135 14597 maintenance_manager.cc:419] P 4fca7a3611af474e8fa35a3f8d88c1ab: Scheduling FlushDeltaMemStoresOp(e931487044eb49f3813d57b50b449524): perf score=2.188937
I20260812 06:19:04.468899 14506 maintenance_manager.cc:643] P 4fca7a3611af474e8fa35a3f8d88c1ab: FlushDeltaMemStoresOp(e931487044eb49f3813d57b50b449524) complete. Timing: real 0.018s	user 0.005s	sys 0.010s Metrics: {"bytes_written":4307790,"delete_count":0,"lbm_write_time_us":4125,"lbm_writes_lt_1ms":108,"reinsert_count":0,"update_count":525}
I20260812 06:19:04.469331 14597 maintenance_manager.cc:419] P 4fca7a3611af474e8fa35a3f8d88c1ab: Scheduling FlushDeltaMemStoresOp(e931487044eb49f3813d57b50b449524): perf score=2.188937
I20260812 06:19:04.478526 14506 maintenance_manager.cc:643] P 4fca7a3611af474e8fa35a3f8d88c1ab: FlushDeltaMemStoresOp(e931487044eb49f3813d57b50b449524) complete. Timing: real 0.009s	user 0.000s	sys 0.008s Metrics: {"bytes_written":3405230,"delete_count":0,"lbm_write_time_us":3533,"lbm_writes_lt_1ms":86,"reinsert_count":0,"update_count":415}
I20260812 06:19:04.478947 14597 maintenance_manager.cc:419] P 4fca7a3611af474e8fa35a3f8d88c1ab: Scheduling MajorDeltaCompactionOp(e931487044eb49f3813d57b50b449524): perf score=1.000000
I20260812 06:19:04.650755 14506 maintenance_manager.cc:643] P 4fca7a3611af474e8fa35a3f8d88c1ab: MajorDeltaCompactionOp(e931487044eb49f3813d57b50b449524) complete. Timing: real 0.172s	user 0.119s	sys 0.052s Metrics: {"cfile_cache_miss":533,"cfile_cache_miss_bytes":24774809,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":876,"lbm_read_time_us":12613,"lbm_reads_lt_1ms":569,"lbm_write_time_us":28443,"lbm_writes_lt_1ms":543,"mutex_wait_us":78,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":9856,"thread_start_us":334,"threads_started":5,"update_count":2500}
I20260812 06:19:04.651427 14597 maintenance_manager.cc:419] P 4fca7a3611af474e8fa35a3f8d88c1ab: Scheduling FlushDeltaMemStoresOp(e931487044eb49f3813d57b50b449524): perf score=10.126437
I20260812 06:19:04.689220 14506 maintenance_manager.cc:643] P 4fca7a3611af474e8fa35a3f8d88c1ab: FlushDeltaMemStoresOp(e931487044eb49f3813d57b50b449524) complete. Timing: real 0.038s	user 0.014s	sys 0.020s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":15187,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:19:04.689661 14597 maintenance_manager.cc:419] P 4fca7a3611af474e8fa35a3f8d88c1ab: Scheduling FlushDeltaMemStoresOp(e931487044eb49f3813d57b50b449524): perf score=2.188937
I20260812 06:19:04.703959 14506 maintenance_manager.cc:643] P 4fca7a3611af474e8fa35a3f8d88c1ab: FlushDeltaMemStoresOp(e931487044eb49f3813d57b50b449524) complete. Timing: real 0.014s	user 0.009s	sys 0.004s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":5648,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:04.704489 14597 maintenance_manager.cc:419] P 4fca7a3611af474e8fa35a3f8d88c1ab: Scheduling MajorDeltaCompactionOp(e931487044eb49f3813d57b50b449524): perf score=1.000000
I20260812 06:19:04.833505 14506 maintenance_manager.cc:643] P 4fca7a3611af474e8fa35a3f8d88c1ab: MajorDeltaCompactionOp(e931487044eb49f3813d57b50b449524) complete. Timing: real 0.129s	user 0.094s	sys 0.034s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672276,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":631,"lbm_read_time_us":7762,"lbm_reads_lt_1ms":472,"lbm_write_time_us":26321,"lbm_writes_lt_1ms":443,"mutex_wait_us":310,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":768,"update_count":2000}
I20260812 06:19:04.833964 14597 maintenance_manager.cc:419] P 4fca7a3611af474e8fa35a3f8d88c1ab: Scheduling FlushDeltaMemStoresOp(e931487044eb49f3813d57b50b449524): perf score=10.126437
I20260812 06:19:04.880858 14506 maintenance_manager.cc:643] P 4fca7a3611af474e8fa35a3f8d88c1ab: FlushDeltaMemStoresOp(e931487044eb49f3813d57b50b449524) complete. Timing: real 0.047s	user 0.019s	sys 0.025s Metrics: {"bytes_written":12307489,"delete_count":0,"lbm_write_time_us":19592,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":302,"reinsert_count":0,"update_count":1500}
I20260812 06:19:04.881352 14597 maintenance_manager.cc:419] P 4fca7a3611af474e8fa35a3f8d88c1ab: Scheduling FlushDeltaMemStoresOp(e931487044eb49f3813d57b50b449524): perf score=2.188937
I20260812 06:19:04.892386 14506 maintenance_manager.cc:643] P 4fca7a3611af474e8fa35a3f8d88c1ab: FlushDeltaMemStoresOp(e931487044eb49f3813d57b50b449524) complete. Timing: real 0.011s	user 0.004s	sys 0.005s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3989,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:04.892874 14597 maintenance_manager.cc:419] P 4fca7a3611af474e8fa35a3f8d88c1ab: Scheduling MajorDeltaCompactionOp(e931487044eb49f3813d57b50b449524): perf score=1.000000
I20260812 06:19:05.017262 14506 maintenance_manager.cc:643] P 4fca7a3611af474e8fa35a3f8d88c1ab: MajorDeltaCompactionOp(e931487044eb49f3813d57b50b449524) complete. Timing: real 0.124s	user 0.087s	sys 0.035s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672276,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":305,"lbm_read_time_us":9232,"lbm_reads_lt_1ms":472,"lbm_write_time_us":24913,"lbm_writes_lt_1ms":443,"mutex_wait_us":2,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":896,"update_count":2000}
I20260812 06:19:05.020268 14597 maintenance_manager.cc:419] P 4fca7a3611af474e8fa35a3f8d88c1ab: Scheduling FlushDeltaMemStoresOp(e931487044eb49f3813d57b50b449524): perf score=10.126437
I20260812 06:19:05.061645 14506 maintenance_manager.cc:643] P 4fca7a3611af474e8fa35a3f8d88c1ab: FlushDeltaMemStoresOp(e931487044eb49f3813d57b50b449524) complete. Timing: real 0.041s	user 0.008s	sys 0.028s Metrics: {"bytes_written":12307489,"delete_count":0,"lbm_write_time_us":17403,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:19:05.062215 14597 maintenance_manager.cc:419] P 4fca7a3611af474e8fa35a3f8d88c1ab: Scheduling FlushDeltaMemStoresOp(e931487044eb49f3813d57b50b449524): perf score=2.188937
I20260812 06:19:05.072863 14506 maintenance_manager.cc:643] P 4fca7a3611af474e8fa35a3f8d88c1ab: FlushDeltaMemStoresOp(e931487044eb49f3813d57b50b449524) complete. Timing: real 0.010s	user 0.006s	sys 0.003s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4005,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:05.073513 14597 maintenance_manager.cc:419] P 4fca7a3611af474e8fa35a3f8d88c1ab: Scheduling MajorDeltaCompactionOp(e931487044eb49f3813d57b50b449524): perf score=1.000000
I20260812 06:19:05.193513 14506 maintenance_manager.cc:643] P 4fca7a3611af474e8fa35a3f8d88c1ab: MajorDeltaCompactionOp(e931487044eb49f3813d57b50b449524) complete. Timing: real 0.120s	user 0.100s	sys 0.020s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672276,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":1036,"lbm_read_time_us":8556,"lbm_reads_lt_1ms":472,"lbm_write_time_us":23061,"lbm_writes_lt_1ms":443,"mutex_wait_us":271,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":4352,"update_count":2000}
I20260812 06:19:05.194142 14597 maintenance_manager.cc:419] P 4fca7a3611af474e8fa35a3f8d88c1ab: Scheduling FlushDeltaMemStoresOp(e931487044eb49f3813d57b50b449524): perf score=10.126437
I20260812 06:19:05.244009 14506 maintenance_manager.cc:643] P 4fca7a3611af474e8fa35a3f8d88c1ab: FlushDeltaMemStoresOp(e931487044eb49f3813d57b50b449524) complete. Timing: real 0.050s	user 0.029s	sys 0.014s Metrics: {"bytes_written":12307489,"delete_count":0,"lbm_write_time_us":16661,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:19:05.244534 14597 maintenance_manager.cc:419] P 4fca7a3611af474e8fa35a3f8d88c1ab: Scheduling FlushDeltaMemStoresOp(e931487044eb49f3813d57b50b449524): perf score=2.188937
I20260812 06:19:05.254976 14506 maintenance_manager.cc:643] P 4fca7a3611af474e8fa35a3f8d88c1ab: FlushDeltaMemStoresOp(e931487044eb49f3813d57b50b449524) complete. Timing: real 0.010s	user 0.006s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4155,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:05.255376 14597 maintenance_manager.cc:419] P 4fca7a3611af474e8fa35a3f8d88c1ab: Scheduling MajorDeltaCompactionOp(e931487044eb49f3813d57b50b449524): perf score=1.000000
I20260812 06:19:05.408360 14506 maintenance_manager.cc:643] P 4fca7a3611af474e8fa35a3f8d88c1ab: MajorDeltaCompactionOp(e931487044eb49f3813d57b50b449524) complete. Timing: real 0.153s	user 0.105s	sys 0.048s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672276,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":317,"lbm_read_time_us":10543,"lbm_reads_lt_1ms":472,"lbm_write_time_us":24999,"lbm_writes_lt_1ms":443,"mutex_wait_us":108,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":14336,"update_count":2000}
I20260812 06:19:05.408987 14597 maintenance_manager.cc:419] P 4fca7a3611af474e8fa35a3f8d88c1ab: Scheduling FlushDeltaMemStoresOp(e931487044eb49f3813d57b50b449524): perf score=10.126437
I20260812 06:19:05.446902 14506 maintenance_manager.cc:643] P 4fca7a3611af474e8fa35a3f8d88c1ab: FlushDeltaMemStoresOp(e931487044eb49f3813d57b50b449524) complete. Timing: real 0.038s	user 0.030s	sys 0.007s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":16158,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:19:05.447379 14597 maintenance_manager.cc:419] P 4fca7a3611af474e8fa35a3f8d88c1ab: Scheduling MajorDeltaCompactionOp(e931487044eb49f3813d57b50b449524): perf score=1.000000
I20260812 06:19:05.554857 14506 maintenance_manager.cc:643] P 4fca7a3611af474e8fa35a3f8d88c1ab: MajorDeltaCompactionOp(e931487044eb49f3813d57b50b449524) complete. Timing: real 0.107s	user 0.076s	sys 0.030s Metrics: {"cfile_cache_miss":331,"cfile_cache_miss_bytes":16569746,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":1,"delta_iterators_relevant":1,"dirs.queue_time_us":991,"lbm_read_time_us":7169,"lbm_reads_lt_1ms":363,"lbm_write_time_us":20650,"lbm_writes_lt_1ms":343,"mutex_wait_us":304,"peak_mem_usage":38262756,"reinsert_count":0,"spinlock_wait_cycles":3712,"update_count":1500}
I20260812 06:19:05.555544 14597 maintenance_manager.cc:419] P 4fca7a3611af474e8fa35a3f8d88c1ab: Scheduling FlushDeltaMemStoresOp(e931487044eb49f3813d57b50b449524): perf score=10.126437
I20260812 06:19:05.588423 14506 maintenance_manager.cc:643] P 4fca7a3611af474e8fa35a3f8d88c1ab: FlushDeltaMemStoresOp(e931487044eb49f3813d57b50b449524) complete. Timing: real 0.033s	user 0.018s	sys 0.013s Metrics: {"bytes_written":12307489,"delete_count":0,"lbm_write_time_us":14223,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:19:05.588966 14597 maintenance_manager.cc:419] P 4fca7a3611af474e8fa35a3f8d88c1ab: Scheduling FlushMRSOp(e931487044eb49f3813d57b50b449524): perf score=1.000000
I20260812 06:19:05.616405 14506 maintenance_manager.cc:643] P 4fca7a3611af474e8fa35a3f8d88c1ab: FlushMRSOp(e931487044eb49f3813d57b50b449524) complete. Timing: real 0.027s	user 0.025s	sys 0.000s Metrics: {"bytes_written":1152508,"cfile_init":1,"dirs.queue_time_us":76,"dirs.run_cpu_time_us":284,"dirs.run_wall_time_us":1384,"drs_written":1,"lbm_read_time_us":56,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1831,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":28}
I20260812 06:19:05.617234 14597 maintenance_manager.cc:419] P 4fca7a3611af474e8fa35a3f8d88c1ab: Scheduling LogGCOp(e931487044eb49f3813d57b50b449524): free 111786285 bytes of WAL
I20260812 06:19:05.617506 14506 log_reader.cc:385] T e931487044eb49f3813d57b50b449524: removed 11 log segments from log reader
I20260812 06:19:05.617573 14506 log.cc:1079] T e931487044eb49f3813d57b50b449524 P 4fca7a3611af474e8fa35a3f8d88c1ab: Deleting log segment in path: /tmp/dist-test-taskbgpkED/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515543839567-14326-0/minicluster-data/ts-0-root/wals/e931487044eb49f3813d57b50b449524/wal-000000003 (ops 12-16)
I20260812 06:19:05.617609 14506 log.cc:1079] T e931487044eb49f3813d57b50b449524 P 4fca7a3611af474e8fa35a3f8d88c1ab: Deleting log segment in path: /tmp/dist-test-taskbgpkED/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515543839567-14326-0/minicluster-data/ts-0-root/wals/e931487044eb49f3813d57b50b449524/wal-000000004 (ops 17-21)
I20260812 06:19:05.617633 14506 log.cc:1079] T e931487044eb49f3813d57b50b449524 P 4fca7a3611af474e8fa35a3f8d88c1ab: Deleting log segment in path: /tmp/dist-test-taskbgpkED/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515543839567-14326-0/minicluster-data/ts-0-root/wals/e931487044eb49f3813d57b50b449524/wal-000000005 (ops 22-26)
I20260812 06:19:05.617668 14506 log.cc:1079] T e931487044eb49f3813d57b50b449524 P 4fca7a3611af474e8fa35a3f8d88c1ab: Deleting log segment in path: /tmp/dist-test-taskbgpkED/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515543839567-14326-0/minicluster-data/ts-0-root/wals/e931487044eb49f3813d57b50b449524/wal-000000006 (ops 27-30)
I20260812 06:19:05.617691 14506 log.cc:1079] T e931487044eb49f3813d57b50b449524 P 4fca7a3611af474e8fa35a3f8d88c1ab: Deleting log segment in path: /tmp/dist-test-taskbgpkED/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515543839567-14326-0/minicluster-data/ts-0-root/wals/e931487044eb49f3813d57b50b449524/wal-000000007 (ops 31-35)
I20260812 06:19:05.617713 14506 log.cc:1079] T e931487044eb49f3813d57b50b449524 P 4fca7a3611af474e8fa35a3f8d88c1ab: Deleting log segment in path: /tmp/dist-test-taskbgpkED/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515543839567-14326-0/minicluster-data/ts-0-root/wals/e931487044eb49f3813d57b50b449524/wal-000000008 (ops 36-40)
I20260812 06:19:05.617744 14506 log.cc:1079] T e931487044eb49f3813d57b50b449524 P 4fca7a3611af474e8fa35a3f8d88c1ab: Deleting log segment in path: /tmp/dist-test-taskbgpkED/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515543839567-14326-0/minicluster-data/ts-0-root/wals/e931487044eb49f3813d57b50b449524/wal-000000009 (ops 41-44)
I20260812 06:19:05.617782 14506 log.cc:1079] T e931487044eb49f3813d57b50b449524 P 4fca7a3611af474e8fa35a3f8d88c1ab: Deleting log segment in path: /tmp/dist-test-taskbgpkED/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515543839567-14326-0/minicluster-data/ts-0-root/wals/e931487044eb49f3813d57b50b449524/wal-000000010 (ops 45-49)
I20260812 06:19:05.617820 14506 log.cc:1079] T e931487044eb49f3813d57b50b449524 P 4fca7a3611af474e8fa35a3f8d88c1ab: Deleting log segment in path: /tmp/dist-test-taskbgpkED/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515543839567-14326-0/minicluster-data/ts-0-root/wals/e931487044eb49f3813d57b50b449524/wal-000000011 (ops 50-54)
I20260812 06:19:05.617861 14506 log.cc:1079] T e931487044eb49f3813d57b50b449524 P 4fca7a3611af474e8fa35a3f8d88c1ab: Deleting log segment in path: /tmp/dist-test-taskbgpkED/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515543839567-14326-0/minicluster-data/ts-0-root/wals/e931487044eb49f3813d57b50b449524/wal-000000012 (ops 55-59)
I20260812 06:19:05.617894 14506 log.cc:1079] T e931487044eb49f3813d57b50b449524 P 4fca7a3611af474e8fa35a3f8d88c1ab: Deleting log segment in path: /tmp/dist-test-taskbgpkED/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515543839567-14326-0/minicluster-data/ts-0-root/wals/e931487044eb49f3813d57b50b449524/wal-000000013 (ops 60-64)
I20260812 06:19:05.644284 14506 maintenance_manager.cc:643] P 4fca7a3611af474e8fa35a3f8d88c1ab: LogGCOp(e931487044eb49f3813d57b50b449524) complete. Timing: real 0.027s	user 0.000s	sys 0.025s Metrics: {}
I20260812 06:19:05.644645 14597 maintenance_manager.cc:419] P 4fca7a3611af474e8fa35a3f8d88c1ab: Scheduling FlushDeltaMemStoresOp(e931487044eb49f3813d57b50b449524): perf score=4.173312
I20260812 06:19:05.660905 14506 maintenance_manager.cc:643] P 4fca7a3611af474e8fa35a3f8d88c1ab: FlushDeltaMemStoresOp(e931487044eb49f3813d57b50b449524) complete. Timing: real 0.016s	user 0.005s	sys 0.009s Metrics: {"bytes_written":5415441,"delete_count":0,"lbm_write_time_us":6349,"lbm_writes_lt_1ms":135,"reinsert_count":0,"update_count":660}
I20260812 06:19:05.661396 14597 maintenance_manager.cc:419] P 4fca7a3611af474e8fa35a3f8d88c1ab: Scheduling FlushDeltaMemStoresOp(e931487044eb49f3813d57b50b449524): perf score=1.196750
I20260812 06:19:05.672950 14506 maintenance_manager.cc:643] P 4fca7a3611af474e8fa35a3f8d88c1ab: FlushDeltaMemStoresOp(e931487044eb49f3813d57b50b449524) complete. Timing: real 0.011s	user 0.009s	sys 0.000s Metrics: {"bytes_written":2789855,"delete_count":0,"lbm_write_time_us":3973,"lbm_writes_lt_1ms":71,"reinsert_count":0,"update_count":340}
I20260812 06:19:05.673486 14597 maintenance_manager.cc:419] P 4fca7a3611af474e8fa35a3f8d88c1ab: Scheduling MajorDeltaCompactionOp(e931487044eb49f3813d57b50b449524): perf score=1.000000
I20260812 06:19:05.822199 14506 maintenance_manager.cc:643] P 4fca7a3611af474e8fa35a3f8d88c1ab: MajorDeltaCompactionOp(e931487044eb49f3813d57b50b449524) complete. Timing: real 0.149s	user 0.108s	sys 0.040s Metrics: {"cfile_cache_miss":533,"cfile_cache_miss_bytes":24774779,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":620,"lbm_read_time_us":9643,"lbm_reads_lt_1ms":573,"lbm_write_time_us":28715,"lbm_writes_lt_1ms":543,"mutex_wait_us":44,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":14208,"thread_start_us":88,"threads_started":1,"update_count":2500}
I20260812 06:19:05.822667 14597 maintenance_manager.cc:419] P 4fca7a3611af474e8fa35a3f8d88c1ab: Scheduling FlushDeltaMemStoresOp(e931487044eb49f3813d57b50b449524): perf score=11.118625
I20260812 06:19:05.855245 14506 maintenance_manager.cc:643] P 4fca7a3611af474e8fa35a3f8d88c1ab: FlushDeltaMemStoresOp(e931487044eb49f3813d57b50b449524) complete. Timing: real 0.032s	user 0.020s	sys 0.012s Metrics: {"bytes_written":12717735,"delete_count":0,"lbm_write_time_us":14340,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:19:05.855827 14597 maintenance_manager.cc:419] P 4fca7a3611af474e8fa35a3f8d88c1ab: Scheduling UndoDeltaBlockGCOp(e931487044eb49f3813d57b50b449524): 447 bytes on disk
I20260812 06:19:05.856405 14506 maintenance_manager.cc:643] P 4fca7a3611af474e8fa35a3f8d88c1ab: UndoDeltaBlockGCOp(e931487044eb49f3813d57b50b449524) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":74,"lbm_reads_lt_1ms":4}
I20260812 06:19:05.856941 14597 maintenance_manager.cc:419] P 4fca7a3611af474e8fa35a3f8d88c1ab: Scheduling FlushDeltaMemStoresOp(e931487044eb49f3813d57b50b449524): perf score=2.188937
I20260812 06:19:05.870806 14506 maintenance_manager.cc:643] P 4fca7a3611af474e8fa35a3f8d88c1ab: FlushDeltaMemStoresOp(e931487044eb49f3813d57b50b449524) complete. Timing: real 0.014s	user 0.002s	sys 0.011s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":5307,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:19:05.871361 14597 maintenance_manager.cc:419] P 4fca7a3611af474e8fa35a3f8d88c1ab: Scheduling MajorDeltaCompactionOp(e931487044eb49f3813d57b50b449524): perf score=1.000000
I20260812 06:19:06.019752 14506 maintenance_manager.cc:643] P 4fca7a3611af474e8fa35a3f8d88c1ab: MajorDeltaCompactionOp(e931487044eb49f3813d57b50b449524) complete. Timing: real 0.148s	user 0.108s	sys 0.040s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672268,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":183,"lbm_read_time_us":12345,"lbm_reads_lt_1ms":472,"lbm_write_time_us":24680,"lbm_writes_lt_1ms":443,"mutex_wait_us":21,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":19968,"update_count":2000}
I20260812 06:19:06.025024 14597 maintenance_manager.cc:419] P 4fca7a3611af474e8fa35a3f8d88c1ab: Scheduling FlushDeltaMemStoresOp(e931487044eb49f3813d57b50b449524): perf score=10.126437
I20260812 06:19:06.057821 14506 maintenance_manager.cc:643] P 4fca7a3611af474e8fa35a3f8d88c1ab: FlushDeltaMemStoresOp(e931487044eb49f3813d57b50b449524) complete. Timing: real 0.032s	user 0.009s	sys 0.020s Metrics: {"bytes_written":12307491,"delete_count":0,"lbm_write_time_us":13361,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:19:06.058362 14597 maintenance_manager.cc:419] P 4fca7a3611af474e8fa35a3f8d88c1ab: Scheduling FlushDeltaMemStoresOp(e931487044eb49f3813d57b50b449524): perf score=2.188937
I20260812 06:19:06.071187 14506 maintenance_manager.cc:643] P 4fca7a3611af474e8fa35a3f8d88c1ab: FlushDeltaMemStoresOp(e931487044eb49f3813d57b50b449524) complete. Timing: real 0.013s	user 0.011s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4152,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:06.071620 14597 maintenance_manager.cc:419] P 4fca7a3611af474e8fa35a3f8d88c1ab: Scheduling MajorDeltaCompactionOp(e931487044eb49f3813d57b50b449524): perf score=1.000000
I20260812 06:19:06.217286 14506 maintenance_manager.cc:643] P 4fca7a3611af474e8fa35a3f8d88c1ab: MajorDeltaCompactionOp(e931487044eb49f3813d57b50b449524) complete. Timing: real 0.145s	user 0.126s	sys 0.019s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672278,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":851,"lbm_read_time_us":9929,"lbm_reads_lt_1ms":472,"lbm_write_time_us":28632,"lbm_writes_lt_1ms":443,"mutex_wait_us":57,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":2944,"update_count":2000}
I20260812 06:19:06.217844 14597 maintenance_manager.cc:419] P 4fca7a3611af474e8fa35a3f8d88c1ab: Scheduling FlushDeltaMemStoresOp(e931487044eb49f3813d57b50b449524): perf score=10.126437
I20260812 06:19:06.256560 14506 maintenance_manager.cc:643] P 4fca7a3611af474e8fa35a3f8d88c1ab: FlushDeltaMemStoresOp(e931487044eb49f3813d57b50b449524) complete. Timing: real 0.039s	user 0.017s	sys 0.019s Metrics: {"bytes_written":12307491,"delete_count":0,"lbm_write_time_us":16342,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:19:06.257139 14597 maintenance_manager.cc:419] P 4fca7a3611af474e8fa35a3f8d88c1ab: Scheduling FlushDeltaMemStoresOp(e931487044eb49f3813d57b50b449524): perf score=2.188937
I20260812 06:19:06.268914 14506 maintenance_manager.cc:643] P 4fca7a3611af474e8fa35a3f8d88c1ab: FlushDeltaMemStoresOp(e931487044eb49f3813d57b50b449524) complete. Timing: real 0.012s	user 0.005s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4257,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:06.269405 14597 maintenance_manager.cc:419] P 4fca7a3611af474e8fa35a3f8d88c1ab: Scheduling MajorDeltaCompactionOp(e931487044eb49f3813d57b50b449524): perf score=1.000000
I20260812 06:19:06.387557 14506 maintenance_manager.cc:643] P 4fca7a3611af474e8fa35a3f8d88c1ab: MajorDeltaCompactionOp(e931487044eb49f3813d57b50b449524) complete. Timing: real 0.118s	user 0.092s	sys 0.026s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672278,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":455,"lbm_read_time_us":8703,"lbm_reads_lt_1ms":472,"lbm_write_time_us":22186,"lbm_writes_lt_1ms":443,"mutex_wait_us":115,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":10624,"update_count":2000}
I20260812 06:19:06.388119 14597 maintenance_manager.cc:419] P 4fca7a3611af474e8fa35a3f8d88c1ab: Scheduling FlushDeltaMemStoresOp(e931487044eb49f3813d57b50b449524): perf score=10.126437
I20260812 06:19:06.429327 14506 maintenance_manager.cc:643] P 4fca7a3611af474e8fa35a3f8d88c1ab: FlushDeltaMemStoresOp(e931487044eb49f3813d57b50b449524) complete. Timing: real 0.041s	user 0.021s	sys 0.018s Metrics: {"bytes_written":12307492,"delete_count":0,"lbm_write_time_us":18133,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:19:06.429788 14597 maintenance_manager.cc:419] P 4fca7a3611af474e8fa35a3f8d88c1ab: Scheduling FlushDeltaMemStoresOp(e931487044eb49f3813d57b50b449524): perf score=2.188937
I20260812 06:19:06.441304 14506 maintenance_manager.cc:643] P 4fca7a3611af474e8fa35a3f8d88c1ab: FlushDeltaMemStoresOp(e931487044eb49f3813d57b50b449524) complete. Timing: real 0.011s	user 0.002s	sys 0.007s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4086,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:06.441746 14597 maintenance_manager.cc:419] P 4fca7a3611af474e8fa35a3f8d88c1ab: Scheduling MajorDeltaCompactionOp(e931487044eb49f3813d57b50b449524): perf score=1.000000
I20260812 06:19:06.568446 14506 maintenance_manager.cc:643] P 4fca7a3611af474e8fa35a3f8d88c1ab: MajorDeltaCompactionOp(e931487044eb49f3813d57b50b449524) complete. Timing: real 0.127s	user 0.102s	sys 0.024s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672279,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":258,"lbm_read_time_us":9008,"lbm_reads_lt_1ms":472,"lbm_write_time_us":24074,"lbm_writes_lt_1ms":443,"mutex_wait_us":64,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":15104,"update_count":2000}
I20260812 06:19:06.569233 14597 maintenance_manager.cc:419] P 4fca7a3611af474e8fa35a3f8d88c1ab: Scheduling FlushDeltaMemStoresOp(e931487044eb49f3813d57b50b449524): perf score=10.126437
I20260812 06:19:06.615478 14506 maintenance_manager.cc:643] P 4fca7a3611af474e8fa35a3f8d88c1ab: FlushDeltaMemStoresOp(e931487044eb49f3813d57b50b449524) complete. Timing: real 0.046s	user 0.018s	sys 0.027s Metrics: {"bytes_written":12307489,"delete_count":0,"lbm_write_time_us":16296,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:19:06.616036 14597 maintenance_manager.cc:419] P 4fca7a3611af474e8fa35a3f8d88c1ab: Scheduling FlushDeltaMemStoresOp(e931487044eb49f3813d57b50b449524): perf score=2.188937
I20260812 06:19:06.626683 14506 maintenance_manager.cc:643] P 4fca7a3611af474e8fa35a3f8d88c1ab: FlushDeltaMemStoresOp(e931487044eb49f3813d57b50b449524) complete. Timing: real 0.010s	user 0.008s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4045,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:06.627173 14597 maintenance_manager.cc:419] P 4fca7a3611af474e8fa35a3f8d88c1ab: Scheduling MajorDeltaCompactionOp(e931487044eb49f3813d57b50b449524): perf score=1.000000
I20260812 06:19:06.771572 14506 maintenance_manager.cc:643] P 4fca7a3611af474e8fa35a3f8d88c1ab: MajorDeltaCompactionOp(e931487044eb49f3813d57b50b449524) complete. Timing: real 0.144s	user 0.116s	sys 0.028s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672276,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":203,"lbm_read_time_us":12196,"lbm_reads_lt_1ms":472,"lbm_write_time_us":21109,"lbm_writes_lt_1ms":443,"mutex_wait_us":46,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":4352,"update_count":2000}
I20260812 06:19:06.772203 14597 maintenance_manager.cc:419] P 4fca7a3611af474e8fa35a3f8d88c1ab: Scheduling FlushDeltaMemStoresOp(e931487044eb49f3813d57b50b449524): perf score=10.126437
I20260812 06:19:06.815588 14506 maintenance_manager.cc:643] P 4fca7a3611af474e8fa35a3f8d88c1ab: FlushDeltaMemStoresOp(e931487044eb49f3813d57b50b449524) complete. Timing: real 0.043s	user 0.026s	sys 0.011s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":16160,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:19:06.816133 14597 maintenance_manager.cc:419] P 4fca7a3611af474e8fa35a3f8d88c1ab: Scheduling FlushDeltaMemStoresOp(e931487044eb49f3813d57b50b449524): perf score=2.188937
I20260812 06:19:06.826927 14506 maintenance_manager.cc:643] P 4fca7a3611af474e8fa35a3f8d88c1ab: FlushDeltaMemStoresOp(e931487044eb49f3813d57b50b449524) complete. Timing: real 0.011s	user 0.002s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4037,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:06.827713 14597 maintenance_manager.cc:419] P 4fca7a3611af474e8fa35a3f8d88c1ab: Scheduling MajorDeltaCompactionOp(e931487044eb49f3813d57b50b449524): perf score=1.000000
I20260812 06:19:06.946491 14506 maintenance_manager.cc:643] P 4fca7a3611af474e8fa35a3f8d88c1ab: MajorDeltaCompactionOp(e931487044eb49f3813d57b50b449524) complete. Timing: real 0.119s	user 0.086s	sys 0.032s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672277,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":199,"lbm_read_time_us":9663,"lbm_reads_lt_1ms":472,"lbm_write_time_us":21569,"lbm_writes_lt_1ms":443,"mutex_wait_us":44,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":10880,"update_count":2000}
I20260812 06:19:06.947214 14597 maintenance_manager.cc:419] P 4fca7a3611af474e8fa35a3f8d88c1ab: Scheduling FlushDeltaMemStoresOp(e931487044eb49f3813d57b50b449524): perf score=10.126437
I20260812 06:19:06.987980 14506 maintenance_manager.cc:643] P 4fca7a3611af474e8fa35a3f8d88c1ab: FlushDeltaMemStoresOp(e931487044eb49f3813d57b50b449524) complete. Timing: real 0.041s	user 0.025s	sys 0.012s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":16350,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:19:06.988507 14597 maintenance_manager.cc:419] P 4fca7a3611af474e8fa35a3f8d88c1ab: Scheduling FlushDeltaMemStoresOp(e931487044eb49f3813d57b50b449524): perf score=2.188937
I20260812 06:19:07.004135 14506 maintenance_manager.cc:643] P 4fca7a3611af474e8fa35a3f8d88c1ab: FlushDeltaMemStoresOp(e931487044eb49f3813d57b50b449524) complete. Timing: real 0.015s	user 0.008s	sys 0.006s Metrics: {"bytes_written":4102660,"delete_count":0,"lbm_write_time_us":5654,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:07.004678 14597 maintenance_manager.cc:419] P 4fca7a3611af474e8fa35a3f8d88c1ab: Scheduling FlushMRSOp(e931487044eb49f3813d57b50b449524): perf score=1.000000
I20260812 06:19:07.033272 14506 maintenance_manager.cc:643] P 4fca7a3611af474e8fa35a3f8d88c1ab: FlushMRSOp(e931487044eb49f3813d57b50b449524) complete. Timing: real 0.028s	user 0.027s	sys 0.000s Metrics: {"bytes_written":1193509,"cfile_init":1,"dirs.queue_time_us":64,"dirs.run_cpu_time_us":202,"dirs.run_wall_time_us":1267,"drs_written":1,"lbm_read_time_us":95,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1743,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":29}
I20260812 06:19:07.034003 14597 maintenance_manager.cc:419] P 4fca7a3611af474e8fa35a3f8d88c1ab: Scheduling LogGCOp(e931487044eb49f3813d57b50b449524): free 121006441 bytes of WAL
I20260812 06:19:07.034238 14506 log_reader.cc:385] T e931487044eb49f3813d57b50b449524: removed 12 log segments from log reader
I20260812 06:19:07.034286 14506 log.cc:1079] T e931487044eb49f3813d57b50b449524 P 4fca7a3611af474e8fa35a3f8d88c1ab: Deleting log segment in path: /tmp/dist-test-taskbgpkED/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515543839567-14326-0/minicluster-data/ts-0-root/wals/e931487044eb49f3813d57b50b449524/wal-000000014 (ops 65-69)
I20260812 06:19:07.034312 14506 log.cc:1079] T e931487044eb49f3813d57b50b449524 P 4fca7a3611af474e8fa35a3f8d88c1ab: Deleting log segment in path: /tmp/dist-test-taskbgpkED/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515543839567-14326-0/minicluster-data/ts-0-root/wals/e931487044eb49f3813d57b50b449524/wal-000000015 (ops 70-74)
I20260812 06:19:07.034356 14506 log.cc:1079] T e931487044eb49f3813d57b50b449524 P 4fca7a3611af474e8fa35a3f8d88c1ab: Deleting log segment in path: /tmp/dist-test-taskbgpkED/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515543839567-14326-0/minicluster-data/ts-0-root/wals/e931487044eb49f3813d57b50b449524/wal-000000016 (ops 75-78)
I20260812 06:19:07.034399 14506 log.cc:1079] T e931487044eb49f3813d57b50b449524 P 4fca7a3611af474e8fa35a3f8d88c1ab: Deleting log segment in path: /tmp/dist-test-taskbgpkED/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515543839567-14326-0/minicluster-data/ts-0-root/wals/e931487044eb49f3813d57b50b449524/wal-000000017 (ops 79-83)
I20260812 06:19:07.034447 14506 log.cc:1079] T e931487044eb49f3813d57b50b449524 P 4fca7a3611af474e8fa35a3f8d88c1ab: Deleting log segment in path: /tmp/dist-test-taskbgpkED/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515543839567-14326-0/minicluster-data/ts-0-root/wals/e931487044eb49f3813d57b50b449524/wal-000000018 (ops 84-88)
I20260812 06:19:07.034492 14506 log.cc:1079] T e931487044eb49f3813d57b50b449524 P 4fca7a3611af474e8fa35a3f8d88c1ab: Deleting log segment in path: /tmp/dist-test-taskbgpkED/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515543839567-14326-0/minicluster-data/ts-0-root/wals/e931487044eb49f3813d57b50b449524/wal-000000019 (ops 89-93)
I20260812 06:19:07.034519 14506 log.cc:1079] T e931487044eb49f3813d57b50b449524 P 4fca7a3611af474e8fa35a3f8d88c1ab: Deleting log segment in path: /tmp/dist-test-taskbgpkED/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515543839567-14326-0/minicluster-data/ts-0-root/wals/e931487044eb49f3813d57b50b449524/wal-000000020 (ops 94-98)
I20260812 06:19:07.034562 14506 log.cc:1079] T e931487044eb49f3813d57b50b449524 P 4fca7a3611af474e8fa35a3f8d88c1ab: Deleting log segment in path: /tmp/dist-test-taskbgpkED/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515543839567-14326-0/minicluster-data/ts-0-root/wals/e931487044eb49f3813d57b50b449524/wal-000000021 (ops 99-103)
I20260812 06:19:07.034603 14506 log.cc:1079] T e931487044eb49f3813d57b50b449524 P 4fca7a3611af474e8fa35a3f8d88c1ab: Deleting log segment in path: /tmp/dist-test-taskbgpkED/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515543839567-14326-0/minicluster-data/ts-0-root/wals/e931487044eb49f3813d57b50b449524/wal-000000022 (ops 104-108)
I20260812 06:19:07.034641 14506 log.cc:1079] T e931487044eb49f3813d57b50b449524 P 4fca7a3611af474e8fa35a3f8d88c1ab: Deleting log segment in path: /tmp/dist-test-taskbgpkED/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515543839567-14326-0/minicluster-data/ts-0-root/wals/e931487044eb49f3813d57b50b449524/wal-000000023 (ops 109-113)
I20260812 06:19:07.034682 14506 log.cc:1079] T e931487044eb49f3813d57b50b449524 P 4fca7a3611af474e8fa35a3f8d88c1ab: Deleting log segment in path: /tmp/dist-test-taskbgpkED/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515543839567-14326-0/minicluster-data/ts-0-root/wals/e931487044eb49f3813d57b50b449524/wal-000000024 (ops 114-118)
I20260812 06:19:07.034747 14506 log.cc:1079] T e931487044eb49f3813d57b50b449524 P 4fca7a3611af474e8fa35a3f8d88c1ab: Deleting log segment in path: /tmp/dist-test-taskbgpkED/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515543839567-14326-0/minicluster-data/ts-0-root/wals/e931487044eb49f3813d57b50b449524/wal-000000025 (ops 119-123)
I20260812 06:19:07.062335 14506 maintenance_manager.cc:643] P 4fca7a3611af474e8fa35a3f8d88c1ab: LogGCOp(e931487044eb49f3813d57b50b449524) complete. Timing: real 0.028s	user 0.002s	sys 0.023s Metrics: {}
I20260812 06:19:07.062865 14597 maintenance_manager.cc:419] P 4fca7a3611af474e8fa35a3f8d88c1ab: Scheduling UndoDeltaBlockGCOp(e931487044eb49f3813d57b50b449524): 462 bytes on disk
I20260812 06:19:07.063464 14506 maintenance_manager.cc:643] P 4fca7a3611af474e8fa35a3f8d88c1ab: UndoDeltaBlockGCOp(e931487044eb49f3813d57b50b449524) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":73,"lbm_reads_lt_1ms":4}
I20260812 06:19:07.064005 14597 maintenance_manager.cc:419] P 4fca7a3611af474e8fa35a3f8d88c1ab: Scheduling FlushDeltaMemStoresOp(e931487044eb49f3813d57b50b449524): perf score=3.181125
I20260812 06:19:07.081658 14506 maintenance_manager.cc:643] P 4fca7a3611af474e8fa35a3f8d88c1ab: FlushDeltaMemStoresOp(e931487044eb49f3813d57b50b449524) complete. Timing: real 0.017s	user 0.008s	sys 0.008s Metrics: {"bytes_written":4512900,"delete_count":0,"lbm_write_time_us":7409,"lbm_writes_lt_1ms":113,"reinsert_count":0,"update_count":550}
I20260812 06:19:07.082095 14597 maintenance_manager.cc:419] P 4fca7a3611af474e8fa35a3f8d88c1ab: Scheduling FlushDeltaMemStoresOp(e931487044eb49f3813d57b50b449524): perf score=2.188937
I20260812 06:19:07.092031 14506 maintenance_manager.cc:643] P 4fca7a3611af474e8fa35a3f8d88c1ab: FlushDeltaMemStoresOp(e931487044eb49f3813d57b50b449524) complete. Timing: real 0.010s	user 0.004s	sys 0.004s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3792,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:19:07.092756 14597 maintenance_manager.cc:419] P 4fca7a3611af474e8fa35a3f8d88c1ab: Scheduling MajorDeltaCompactionOp(e931487044eb49f3813d57b50b449524): perf score=1.000000
I20260812 06:19:07.269886 14506 maintenance_manager.cc:643] P 4fca7a3611af474e8fa35a3f8d88c1ab: MajorDeltaCompactionOp(e931487044eb49f3813d57b50b449524) complete. Timing: real 0.177s	user 0.119s	sys 0.055s Metrics: {"cfile_cache_miss":634,"cfile_cache_miss_bytes":28877327,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":4805,"lbm_read_time_us":13361,"lbm_reads_lt_1ms":674,"lbm_write_time_us":33686,"lbm_writes_lt_1ms":643,"mutex_wait_us":2057,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":384,"thread_start_us":84,"threads_started":1,"update_count":3000}
I20260812 06:19:07.270602 14597 maintenance_manager.cc:419] P 4fca7a3611af474e8fa35a3f8d88c1ab: Scheduling FlushDeltaMemStoresOp(e931487044eb49f3813d57b50b449524): perf score=14.095187
I20260812 06:19:07.318830 14506 maintenance_manager.cc:643] P 4fca7a3611af474e8fa35a3f8d88c1ab: FlushDeltaMemStoresOp(e931487044eb49f3813d57b50b449524) complete. Timing: real 0.048s	user 0.032s	sys 0.016s Metrics: {"bytes_written":16409905,"delete_count":0,"lbm_write_time_us":22030,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":402,"reinsert_count":0,"update_count":2000}
I20260812 06:19:07.319326 14597 maintenance_manager.cc:419] P 4fca7a3611af474e8fa35a3f8d88c1ab: Scheduling FlushDeltaMemStoresOp(e931487044eb49f3813d57b50b449524): perf score=2.188937
I20260812 06:19:07.333263 14506 maintenance_manager.cc:643] P 4fca7a3611af474e8fa35a3f8d88c1ab: FlushDeltaMemStoresOp(e931487044eb49f3813d57b50b449524) complete. Timing: real 0.014s	user 0.004s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5147,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:07.333830 14597 maintenance_manager.cc:419] P 4fca7a3611af474e8fa35a3f8d88c1ab: Scheduling MajorDeltaCompactionOp(e931487044eb49f3813d57b50b449524): perf score=1.000000
I20260812 06:19:07.493760 14506 maintenance_manager.cc:643] P 4fca7a3611af474e8fa35a3f8d88c1ab: MajorDeltaCompactionOp(e931487044eb49f3813d57b50b449524) complete. Timing: real 0.160s	user 0.102s	sys 0.045s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774692,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":197,"lbm_read_time_us":11015,"lbm_reads_lt_1ms":564,"lbm_write_time_us":28809,"lbm_writes_lt_1ms":543,"mutex_wait_us":52,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":1664,"update_count":2500}
I20260812 06:19:07.494446 14597 maintenance_manager.cc:419] P 4fca7a3611af474e8fa35a3f8d88c1ab: Scheduling FlushDeltaMemStoresOp(e931487044eb49f3813d57b50b449524): perf score=14.095187
I20260812 06:19:07.544421 14506 maintenance_manager.cc:643] P 4fca7a3611af474e8fa35a3f8d88c1ab: FlushDeltaMemStoresOp(e931487044eb49f3813d57b50b449524) complete. Timing: real 0.050s	user 0.021s	sys 0.024s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":20610,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:07.544988 14597 maintenance_manager.cc:419] P 4fca7a3611af474e8fa35a3f8d88c1ab: Scheduling FlushDeltaMemStoresOp(e931487044eb49f3813d57b50b449524): perf score=2.188937
I20260812 06:19:07.555753 14506 maintenance_manager.cc:643] P 4fca7a3611af474e8fa35a3f8d88c1ab: FlushDeltaMemStoresOp(e931487044eb49f3813d57b50b449524) complete. Timing: real 0.011s	user 0.005s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4148,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:07.556501 14597 maintenance_manager.cc:419] P 4fca7a3611af474e8fa35a3f8d88c1ab: Scheduling MajorDeltaCompactionOp(e931487044eb49f3813d57b50b449524): perf score=1.000000
I20260812 06:19:07.738103 14506 maintenance_manager.cc:643] P 4fca7a3611af474e8fa35a3f8d88c1ab: MajorDeltaCompactionOp(e931487044eb49f3813d57b50b449524) complete. Timing: real 0.181s	user 0.118s	sys 0.060s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774689,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":1168,"lbm_read_time_us":10788,"lbm_reads_lt_1ms":572,"lbm_write_time_us":31955,"lbm_writes_lt_1ms":543,"mutex_wait_us":373,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":4608,"update_count":2500}
I20260812 06:19:07.738646 14597 maintenance_manager.cc:419] P 4fca7a3611af474e8fa35a3f8d88c1ab: Scheduling FlushDeltaMemStoresOp(e931487044eb49f3813d57b50b449524): perf score=14.095187
I20260812 06:19:07.792367 14506 maintenance_manager.cc:643] P 4fca7a3611af474e8fa35a3f8d88c1ab: FlushDeltaMemStoresOp(e931487044eb49f3813d57b50b449524) complete. Timing: real 0.054s	user 0.031s	sys 0.020s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":24643,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:07.792912 14597 maintenance_manager.cc:419] P 4fca7a3611af474e8fa35a3f8d88c1ab: Scheduling MajorDeltaCompactionOp(e931487044eb49f3813d57b50b449524): perf score=1.000000
I20260812 06:19:07.939649 14506 maintenance_manager.cc:643] P 4fca7a3611af474e8fa35a3f8d88c1ab: MajorDeltaCompactionOp(e931487044eb49f3813d57b50b449524) complete. Timing: real 0.147s	user 0.102s	sys 0.044s Metrics: {"cfile_cache_miss":431,"cfile_cache_miss_bytes":20672158,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":1,"delta_iterators_relevant":1,"dirs.queue_time_us":228,"lbm_read_time_us":11494,"lbm_reads_lt_1ms":467,"lbm_write_time_us":24049,"lbm_writes_lt_1ms":443,"mutex_wait_us":2,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":1664,"update_count":2000}
I20260812 06:19:07.940338 14597 maintenance_manager.cc:419] P 4fca7a3611af474e8fa35a3f8d88c1ab: Scheduling FlushDeltaMemStoresOp(e931487044eb49f3813d57b50b449524): perf score=11.118625
I20260812 06:19:07.975018 14506 maintenance_manager.cc:643] P 4fca7a3611af474e8fa35a3f8d88c1ab: FlushDeltaMemStoresOp(e931487044eb49f3813d57b50b449524) complete. Timing: real 0.034s	user 0.018s	sys 0.015s Metrics: {"bytes_written":12717735,"delete_count":0,"lbm_write_time_us":14616,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:19:07.975751 14597 maintenance_manager.cc:419] P 4fca7a3611af474e8fa35a3f8d88c1ab: Scheduling FlushDeltaMemStoresOp(e931487044eb49f3813d57b50b449524): perf score=2.188937
I20260812 06:19:07.993379 14506 maintenance_manager.cc:643] P 4fca7a3611af474e8fa35a3f8d88c1ab: FlushDeltaMemStoresOp(e931487044eb49f3813d57b50b449524) complete. Timing: real 0.017s	user 0.006s	sys 0.005s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":4718,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:19:07.993844 14597 maintenance_manager.cc:419] P 4fca7a3611af474e8fa35a3f8d88c1ab: Scheduling MajorDeltaCompactionOp(e931487044eb49f3813d57b50b449524): perf score=1.000000
I20260812 06:19:08.129927 14506 maintenance_manager.cc:643] P 4fca7a3611af474e8fa35a3f8d88c1ab: MajorDeltaCompactionOp(e931487044eb49f3813d57b50b449524) complete. Timing: real 0.136s	user 0.087s	sys 0.048s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672268,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":539,"lbm_read_time_us":8448,"lbm_reads_lt_1ms":464,"lbm_write_time_us":26634,"lbm_writes_lt_1ms":443,"mutex_wait_us":271,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":5632,"update_count":2000}
I20260812 06:19:08.130671 14597 maintenance_manager.cc:419] P 4fca7a3611af474e8fa35a3f8d88c1ab: Scheduling FlushDeltaMemStoresOp(e931487044eb49f3813d57b50b449524): perf score=10.126437
I20260812 06:19:08.168306 14506 maintenance_manager.cc:643] P 4fca7a3611af474e8fa35a3f8d88c1ab: FlushDeltaMemStoresOp(e931487044eb49f3813d57b50b449524) complete. Timing: real 0.037s	user 0.015s	sys 0.016s Metrics: {"bytes_written":12307491,"delete_count":0,"lbm_write_time_us":14055,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:19:08.168830 14597 maintenance_manager.cc:419] P 4fca7a3611af474e8fa35a3f8d88c1ab: Scheduling FlushDeltaMemStoresOp(e931487044eb49f3813d57b50b449524): perf score=2.188937
I20260812 06:19:08.183198 14506 maintenance_manager.cc:643] P 4fca7a3611af474e8fa35a3f8d88c1ab: FlushDeltaMemStoresOp(e931487044eb49f3813d57b50b449524) complete. Timing: real 0.014s	user 0.006s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5692,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:08.183640 14597 maintenance_manager.cc:419] P 4fca7a3611af474e8fa35a3f8d88c1ab: Scheduling MajorDeltaCompactionOp(e931487044eb49f3813d57b50b449524): perf score=1.000000
I20260812 06:19:08.306254 14506 maintenance_manager.cc:643] P 4fca7a3611af474e8fa35a3f8d88c1ab: MajorDeltaCompactionOp(e931487044eb49f3813d57b50b449524) complete. Timing: real 0.122s	user 0.084s	sys 0.037s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672278,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":895,"lbm_read_time_us":9316,"lbm_reads_lt_1ms":472,"lbm_write_time_us":23499,"lbm_writes_lt_1ms":443,"mutex_wait_us":302,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":2688,"update_count":2000}
I20260812 06:19:08.306857 14597 maintenance_manager.cc:419] P 4fca7a3611af474e8fa35a3f8d88c1ab: Scheduling FlushDeltaMemStoresOp(e931487044eb49f3813d57b50b449524): perf score=10.126437
I20260812 06:19:08.357400 14506 maintenance_manager.cc:643] P 4fca7a3611af474e8fa35a3f8d88c1ab: FlushDeltaMemStoresOp(e931487044eb49f3813d57b50b449524) complete. Timing: real 0.050s	user 0.025s	sys 0.012s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":17390,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:19:08.358004 14597 maintenance_manager.cc:419] P 4fca7a3611af474e8fa35a3f8d88c1ab: Scheduling FlushDeltaMemStoresOp(e931487044eb49f3813d57b50b449524): perf score=2.188937
I20260812 06:19:08.369724 14506 maintenance_manager.cc:643] P 4fca7a3611af474e8fa35a3f8d88c1ab: FlushDeltaMemStoresOp(e931487044eb49f3813d57b50b449524) complete. Timing: real 0.012s	user 0.009s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4133,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:08.370455 14597 maintenance_manager.cc:419] P 4fca7a3611af474e8fa35a3f8d88c1ab: Scheduling FlushMRSOp(e931487044eb49f3813d57b50b449524): perf score=1.000000
I20260812 06:19:08.396391 14506 maintenance_manager.cc:643] P 4fca7a3611af474e8fa35a3f8d88c1ab: FlushMRSOp(e931487044eb49f3813d57b50b449524) complete. Timing: real 0.026s	user 0.022s	sys 0.002s Metrics: {"bytes_written":1152510,"cfile_init":1,"dirs.queue_time_us":38,"dirs.run_cpu_time_us":189,"dirs.run_wall_time_us":1178,"drs_written":1,"lbm_read_time_us":37,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1481,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":28}
I20260812 06:19:08.397035 14597 maintenance_manager.cc:419] P 4fca7a3611af474e8fa35a3f8d88c1ab: Scheduling LogGCOp(e931487044eb49f3813d57b50b449524): free 120553614 bytes of WAL
I20260812 06:19:08.397253 14506 log_reader.cc:385] T e931487044eb49f3813d57b50b449524: removed 12 log segments from log reader
I20260812 06:19:08.397297 14506 log.cc:1079] T e931487044eb49f3813d57b50b449524 P 4fca7a3611af474e8fa35a3f8d88c1ab: Deleting log segment in path: /tmp/dist-test-taskbgpkED/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515543839567-14326-0/minicluster-data/ts-0-root/wals/e931487044eb49f3813d57b50b449524/wal-000000026 (ops 124-128)
I20260812 06:19:08.397325 14506 log.cc:1079] T e931487044eb49f3813d57b50b449524 P 4fca7a3611af474e8fa35a3f8d88c1ab: Deleting log segment in path: /tmp/dist-test-taskbgpkED/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515543839567-14326-0/minicluster-data/ts-0-root/wals/e931487044eb49f3813d57b50b449524/wal-000000027 (ops 129-132)
I20260812 06:19:08.397384 14506 log.cc:1079] T e931487044eb49f3813d57b50b449524 P 4fca7a3611af474e8fa35a3f8d88c1ab: Deleting log segment in path: /tmp/dist-test-taskbgpkED/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515543839567-14326-0/minicluster-data/ts-0-root/wals/e931487044eb49f3813d57b50b449524/wal-000000028 (ops 133-137)
I20260812 06:19:08.397430 14506 log.cc:1079] T e931487044eb49f3813d57b50b449524 P 4fca7a3611af474e8fa35a3f8d88c1ab: Deleting log segment in path: /tmp/dist-test-taskbgpkED/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515543839567-14326-0/minicluster-data/ts-0-root/wals/e931487044eb49f3813d57b50b449524/wal-000000029 (ops 138-142)
I20260812 06:19:08.397471 14506 log.cc:1079] T e931487044eb49f3813d57b50b449524 P 4fca7a3611af474e8fa35a3f8d88c1ab: Deleting log segment in path: /tmp/dist-test-taskbgpkED/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515543839567-14326-0/minicluster-data/ts-0-root/wals/e931487044eb49f3813d57b50b449524/wal-000000030 (ops 143-147)
I20260812 06:19:08.397514 14506 log.cc:1079] T e931487044eb49f3813d57b50b449524 P 4fca7a3611af474e8fa35a3f8d88c1ab: Deleting log segment in path: /tmp/dist-test-taskbgpkED/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515543839567-14326-0/minicluster-data/ts-0-root/wals/e931487044eb49f3813d57b50b449524/wal-000000031 (ops 148-152)
I20260812 06:19:08.397552 14506 log.cc:1079] T e931487044eb49f3813d57b50b449524 P 4fca7a3611af474e8fa35a3f8d88c1ab: Deleting log segment in path: /tmp/dist-test-taskbgpkED/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515543839567-14326-0/minicluster-data/ts-0-root/wals/e931487044eb49f3813d57b50b449524/wal-000000032 (ops 153-156)
I20260812 06:19:08.397593 14506 log.cc:1079] T e931487044eb49f3813d57b50b449524 P 4fca7a3611af474e8fa35a3f8d88c1ab: Deleting log segment in path: /tmp/dist-test-taskbgpkED/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515543839567-14326-0/minicluster-data/ts-0-root/wals/e931487044eb49f3813d57b50b449524/wal-000000033 (ops 157-161)
I20260812 06:19:08.397627 14506 log.cc:1079] T e931487044eb49f3813d57b50b449524 P 4fca7a3611af474e8fa35a3f8d88c1ab: Deleting log segment in path: /tmp/dist-test-taskbgpkED/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515543839567-14326-0/minicluster-data/ts-0-root/wals/e931487044eb49f3813d57b50b449524/wal-000000034 (ops 162-166)
I20260812 06:19:08.397668 14506 log.cc:1079] T e931487044eb49f3813d57b50b449524 P 4fca7a3611af474e8fa35a3f8d88c1ab: Deleting log segment in path: /tmp/dist-test-taskbgpkED/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515543839567-14326-0/minicluster-data/ts-0-root/wals/e931487044eb49f3813d57b50b449524/wal-000000035 (ops 167-171)
I20260812 06:19:08.397716 14506 log.cc:1079] T e931487044eb49f3813d57b50b449524 P 4fca7a3611af474e8fa35a3f8d88c1ab: Deleting log segment in path: /tmp/dist-test-taskbgpkED/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515543839567-14326-0/minicluster-data/ts-0-root/wals/e931487044eb49f3813d57b50b449524/wal-000000036 (ops 172-176)
I20260812 06:19:08.397756 14506 log.cc:1079] T e931487044eb49f3813d57b50b449524 P 4fca7a3611af474e8fa35a3f8d88c1ab: Deleting log segment in path: /tmp/dist-test-taskbgpkED/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515543839567-14326-0/minicluster-data/ts-0-root/wals/e931487044eb49f3813d57b50b449524/wal-000000037 (ops 177-181)
I20260812 06:19:08.424477 14506 maintenance_manager.cc:643] P 4fca7a3611af474e8fa35a3f8d88c1ab: LogGCOp(e931487044eb49f3813d57b50b449524) complete. Timing: real 0.027s	user 0.000s	sys 0.026s Metrics: {}
I20260812 06:19:08.424907 14597 maintenance_manager.cc:419] P 4fca7a3611af474e8fa35a3f8d88c1ab: Scheduling UndoDeltaBlockGCOp(e931487044eb49f3813d57b50b449524): 447 bytes on disk
I20260812 06:19:08.425504 14506 maintenance_manager.cc:643] P 4fca7a3611af474e8fa35a3f8d88c1ab: UndoDeltaBlockGCOp(e931487044eb49f3813d57b50b449524) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":91,"lbm_reads_lt_1ms":4}
I20260812 06:19:08.426081 14597 maintenance_manager.cc:419] P 4fca7a3611af474e8fa35a3f8d88c1ab: Scheduling FlushDeltaMemStoresOp(e931487044eb49f3813d57b50b449524): perf score=3.181125
I20260812 06:19:08.443533 14506 maintenance_manager.cc:643] P 4fca7a3611af474e8fa35a3f8d88c1ab: FlushDeltaMemStoresOp(e931487044eb49f3813d57b50b449524) complete. Timing: real 0.017s	user 0.009s	sys 0.008s Metrics: {"bytes_written":4512900,"delete_count":0,"lbm_write_time_us":7266,"lbm_writes_lt_1ms":113,"reinsert_count":0,"update_count":550}
I20260812 06:19:08.443944 14597 maintenance_manager.cc:419] P 4fca7a3611af474e8fa35a3f8d88c1ab: Scheduling FlushDeltaMemStoresOp(e931487044eb49f3813d57b50b449524): perf score=2.188937
I20260812 06:19:08.453830 14506 maintenance_manager.cc:643] P 4fca7a3611af474e8fa35a3f8d88c1ab: FlushDeltaMemStoresOp(e931487044eb49f3813d57b50b449524) complete. Timing: real 0.010s	user 0.005s	sys 0.003s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3782,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:19:08.454231 14597 maintenance_manager.cc:419] P 4fca7a3611af474e8fa35a3f8d88c1ab: Scheduling MajorDeltaCompactionOp(e931487044eb49f3813d57b50b449524): perf score=1.000000
I20260812 06:19:08.622483 14506 maintenance_manager.cc:643] P 4fca7a3611af474e8fa35a3f8d88c1ab: MajorDeltaCompactionOp(e931487044eb49f3813d57b50b449524) complete. Timing: real 0.168s	user 0.148s	sys 0.016s Metrics: {"cfile_cache_miss":634,"cfile_cache_miss_bytes":28877326,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":438,"lbm_read_time_us":13314,"lbm_reads_lt_1ms":674,"lbm_write_time_us":32916,"lbm_writes_lt_1ms":643,"mutex_wait_us":295,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":2688,"thread_start_us":108,"threads_started":1,"update_count":3000}
I20260812 06:19:08.623600 14597 maintenance_manager.cc:419] P 4fca7a3611af474e8fa35a3f8d88c1ab: Scheduling FlushDeltaMemStoresOp(e931487044eb49f3813d57b50b449524): perf score=14.095187
I20260812 06:19:08.674451 14506 maintenance_manager.cc:643] P 4fca7a3611af474e8fa35a3f8d88c1ab: FlushDeltaMemStoresOp(e931487044eb49f3813d57b50b449524) complete. Timing: real 0.051s	user 0.019s	sys 0.028s Metrics: {"bytes_written":16409900,"delete_count":0,"lbm_write_time_us":22180,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":402,"reinsert_count":0,"update_count":2000}
I20260812 06:19:08.675096 14597 maintenance_manager.cc:419] P 4fca7a3611af474e8fa35a3f8d88c1ab: Scheduling FlushDeltaMemStoresOp(e931487044eb49f3813d57b50b449524): perf score=2.188937
I20260812 06:19:08.692626 14506 maintenance_manager.cc:643] P 4fca7a3611af474e8fa35a3f8d88c1ab: FlushDeltaMemStoresOp(e931487044eb49f3813d57b50b449524) complete. Timing: real 0.017s	user 0.012s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6654,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:08.693130 14597 maintenance_manager.cc:419] P 4fca7a3611af474e8fa35a3f8d88c1ab: Scheduling MajorDeltaCompactionOp(e931487044eb49f3813d57b50b449524): perf score=1.000000
I20260812 06:19:08.829487 14326 heavy-update-compaction-itest.cc:229] Time spent updating: real 4.696s	user 1.786s	sys 0.113s
I20260812 06:19:08.839586 14506 maintenance_manager.cc:643] P 4fca7a3611af474e8fa35a3f8d88c1ab: MajorDeltaCompactionOp(e931487044eb49f3813d57b50b449524) complete. Timing: real 0.146s	user 0.121s	sys 0.022s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774687,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":156,"lbm_read_time_us":9328,"lbm_reads_lt_1ms":572,"lbm_write_time_us":28201,"lbm_writes_lt_1ms":543,"mutex_wait_us":32,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":6272,"update_count":2500}
I20260812 06:19:08.840289 14597 maintenance_manager.cc:419] P 4fca7a3611af474e8fa35a3f8d88c1ab: Scheduling FlushDeltaMemStoresOp(e931487044eb49f3813d57b50b449524): perf score=14.095187
I20260812 06:19:08.881778 14326 heavy-update-compaction-itest.cc:265] Time spent scanning: real 0.052s	user 0.001s	sys 0.000s
I20260812 06:19:08.882407 14326 tablet_server.cc:179] TabletServer@127.13.253.129:0 shutting down...
I20260812 06:19:08.885408 14506 maintenance_manager.cc:643] P 4fca7a3611af474e8fa35a3f8d88c1ab: FlushDeltaMemStoresOp(e931487044eb49f3813d57b50b449524) complete. Timing: real 0.045s	user 0.022s	sys 0.021s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":21825,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":402,"reinsert_count":0,"spinlock_wait_cycles":1408,"update_count":2000}
I20260812 06:19:08.886070 14597 maintenance_manager.cc:419] P 4fca7a3611af474e8fa35a3f8d88c1ab: Scheduling MajorDeltaCompactionOp(e931487044eb49f3813d57b50b449524): perf score=1.000000
I20260812 06:19:09.000856 14506 maintenance_manager.cc:643] P 4fca7a3611af474e8fa35a3f8d88c1ab: MajorDeltaCompactionOp(e931487044eb49f3813d57b50b449524) complete. Timing: real 0.115s	user 0.090s	sys 0.025s Metrics: {"cfile_cache_hit":30,"cfile_cache_hit_bytes":4262390,"cfile_cache_miss":401,"cfile_cache_miss_bytes":16409768,"cfile_init":3,"delete_count":0,"delta_blocks_compacted":1,"delta_iterators_relevant":1,"dirs.queue_time_us":368,"lbm_read_time_us":5848,"lbm_reads_lt_1ms":413,"lbm_write_time_us":19499,"lbm_writes_lt_1ms":443,"mutex_wait_us":36,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":30336,"update_count":2000}
I20260812 06:19:09.001626 14326 ts_tablet_manager.cc:1507] Shutting down tablet manager...
I20260812 06:19:09.002005 14326 tablet_replica.cc:333] T e931487044eb49f3813d57b50b449524 P 4fca7a3611af474e8fa35a3f8d88c1ab: stopping tablet replica
I20260812 06:19:09.002239 14326 raft_consensus.cc:2243] T e931487044eb49f3813d57b50b449524 P 4fca7a3611af474e8fa35a3f8d88c1ab [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:19:09.002477 14326 raft_consensus.cc:2272] T e931487044eb49f3813d57b50b449524 P 4fca7a3611af474e8fa35a3f8d88c1ab [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:19:09.019162 14326 tablet_server.cc:196] TabletServer@127.13.253.129:0 shutdown complete.
I20260812 06:19:09.040652 14326 master.cc:562] Master@127.13.253.190:44007 shutting down...
I20260812 06:19:09.044005 14326 raft_consensus.cc:2243] T 00000000000000000000000000000000 P 4ad04750e5ba40a4b87b0231a559bcd0 [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:19:09.044201 14326 raft_consensus.cc:2272] T 00000000000000000000000000000000 P 4ad04750e5ba40a4b87b0231a559bcd0 [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:19:09.044284 14326 tablet_replica.cc:333] T 00000000000000000000000000000000 P 4ad04750e5ba40a4b87b0231a559bcd0: stopping tablet replica
I20260812 06:19:09.056445 14326 master.cc:584] Master@127.13.253.190:44007 shutdown complete.
[       OK ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/0 (5297 ms)
[ RUN      ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/1
I20260812 06:19:09.147429 14326 internal_mini_cluster.cc:156] Creating distributed mini masters. Addrs: 127.13.253.190:42851
I20260812 06:19:09.147851 14326 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:19:09.150183 14639 instance_detector.cc:116] could not retrieve AWS instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:19:09.150276 14640 instance_detector.cc:116] could not retrieve Azure instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:19:09.150341 14326 server_base.cc:1061] running on GCE node
W20260812 06:19:09.150157 14646 instance_detector.cc:116] could not retrieve OpenStack instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:19:09.150565 14326 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:19:09.150609 14326 system_unsync_time.cc:38] NTP support is disabled. Clock error bounds will not be accurate. This configuration is not suitable for distributed clusters.
I20260812 06:19:09.150624 14326 hybrid_clock.cc:648] HybridClock initialized: now 1786515549150624 us; error 0 us; skew 500 ppm
I20260812 06:19:09.151510 14326 webserver.cc:533] Webserver started at http://127.13.253.190:36967/ using document root <none> and password file <none>
I20260812 06:19:09.151640 14326 fs_manager.cc:362] Metadata directory not provided
I20260812 06:19:09.151679 14326 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:19:09.151738 14326 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:19:09.152087 14326 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskbgpkED/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515543839567-14326-0/minicluster-data/master-0-root/instance:
uuid: "ce1fc8511df24bd1bc492d9706d27988"
format_stamp: "Formatted at 2026-08-12 06:19:09 on dist-test-slave-39l8"
I20260812 06:19:09.153534 14326 fs_manager.cc:696] Time spent creating directory manager: real 0.001s	user 0.002s	sys 0.000s
I20260812 06:19:09.154394 14655 log_block_manager.cc:4127] Time spent loading block containers with low live blocks: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:19:09.154675 14326 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.001s	sys 0.000s
I20260812 06:19:09.154816 14326 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskbgpkED/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515543839567-14326-0/minicluster-data/master-0-root
uuid: "ce1fc8511df24bd1bc492d9706d27988"
format_stamp: "Formatted at 2026-08-12 06:19:09 on dist-test-slave-39l8"
I20260812 06:19:09.154897 14326 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskbgpkED/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515543839567-14326-0/minicluster-data/master-0-root
metadata directory: /tmp/dist-test-taskbgpkED/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515543839567-14326-0/minicluster-data/master-0-root
1 data directories: /tmp/dist-test-taskbgpkED/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515543839567-14326-0/minicluster-data/master-0-root/data
Total live blocks: 0
Total live bytes: 0
Total live bytes (after alignment): 0
Total number of LBM containers: 0 (0 full)
Did not check for missing blocks
Did not check for orphaned blocks
Total full LBM containers with extra space: 0 (0 repaired)
Total full LBM container extra space in bytes: 0 (0 repaired)
Total incomplete LBM containers: 0 (0 repaired)
Total LBM partial records: 0 (0 repaired)
Total corrupted LBM metadata records in RocksDB: 0 (0 repaired)
I20260812 06:19:09.166369 14326 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:19:09.166850 14326 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:19:09.171013 14326 rpc_server.cc:307] RPC server started. Bound to: 127.13.253.190:42851
I20260812 06:19:09.174167 14738 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.13.253.190:42851 every 8 connection(s)
I20260812 06:19:09.175891 14740 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet 00000000000000000000000000000000. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:19:09.185490 14740 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P ce1fc8511df24bd1bc492d9706d27988: Bootstrap starting.
I20260812 06:19:09.186348 14740 tablet_bootstrap.cc:654] T 00000000000000000000000000000000 P ce1fc8511df24bd1bc492d9706d27988: Neither blocks nor log segments found. Creating new log.
I20260812 06:19:09.187590 14740 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P ce1fc8511df24bd1bc492d9706d27988: No bootstrap required, opened a new log
I20260812 06:19:09.188004 14740 raft_consensus.cc:359] T 00000000000000000000000000000000 P ce1fc8511df24bd1bc492d9706d27988 [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "ce1fc8511df24bd1bc492d9706d27988" member_type: VOTER }
I20260812 06:19:09.188092 14740 raft_consensus.cc:385] T 00000000000000000000000000000000 P ce1fc8511df24bd1bc492d9706d27988 [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:19:09.188138 14740 raft_consensus.cc:740] T 00000000000000000000000000000000 P ce1fc8511df24bd1bc492d9706d27988 [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: ce1fc8511df24bd1bc492d9706d27988, State: Initialized, Role: FOLLOWER
I20260812 06:19:09.188328 14740 consensus_queue.cc:260] T 00000000000000000000000000000000 P ce1fc8511df24bd1bc492d9706d27988 [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: "ce1fc8511df24bd1bc492d9706d27988" member_type: VOTER }
I20260812 06:19:09.188403 14740 raft_consensus.cc:399] T 00000000000000000000000000000000 P ce1fc8511df24bd1bc492d9706d27988 [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:19:09.188465 14740 raft_consensus.cc:493] T 00000000000000000000000000000000 P ce1fc8511df24bd1bc492d9706d27988 [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:19:09.188531 14740 raft_consensus.cc:3060] T 00000000000000000000000000000000 P ce1fc8511df24bd1bc492d9706d27988 [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:19:09.189252 14740 raft_consensus.cc:515] T 00000000000000000000000000000000 P ce1fc8511df24bd1bc492d9706d27988 [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "ce1fc8511df24bd1bc492d9706d27988" member_type: VOTER }
I20260812 06:19:09.189396 14740 leader_election.cc:304] T 00000000000000000000000000000000 P ce1fc8511df24bd1bc492d9706d27988 [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: ce1fc8511df24bd1bc492d9706d27988; no voters: 
I20260812 06:19:09.189620 14740 leader_election.cc:290] T 00000000000000000000000000000000 P ce1fc8511df24bd1bc492d9706d27988 [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:19:09.189800 14745 raft_consensus.cc:2804] T 00000000000000000000000000000000 P ce1fc8511df24bd1bc492d9706d27988 [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:19:09.190048 14745 raft_consensus.cc:697] T 00000000000000000000000000000000 P ce1fc8511df24bd1bc492d9706d27988 [term 1 LEADER]: Becoming Leader. State: Replica: ce1fc8511df24bd1bc492d9706d27988, State: Running, Role: LEADER
I20260812 06:19:09.190074 14740 sys_catalog.cc:565] T 00000000000000000000000000000000 P ce1fc8511df24bd1bc492d9706d27988 [sys.catalog]: configured and running, proceeding with master startup.
I20260812 06:19:09.190241 14745 consensus_queue.cc:237] T 00000000000000000000000000000000 P ce1fc8511df24bd1bc492d9706d27988 [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: "ce1fc8511df24bd1bc492d9706d27988" member_type: VOTER }
I20260812 06:19:09.190744 14749 sys_catalog.cc:455] T 00000000000000000000000000000000 P ce1fc8511df24bd1bc492d9706d27988 [sys.catalog]: SysCatalogTable state changed. Reason: New leader ce1fc8511df24bd1bc492d9706d27988. Latest consensus state: current_term: 1 leader_uuid: "ce1fc8511df24bd1bc492d9706d27988" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "ce1fc8511df24bd1bc492d9706d27988" member_type: VOTER } }
I20260812 06:19:09.190843 14749 sys_catalog.cc:458] T 00000000000000000000000000000000 P ce1fc8511df24bd1bc492d9706d27988 [sys.catalog]: This master's current role is: LEADER
I20260812 06:19:09.190730 14746 sys_catalog.cc:455] T 00000000000000000000000000000000 P ce1fc8511df24bd1bc492d9706d27988 [sys.catalog]: SysCatalogTable state changed. Reason: RaftConsensus started. Latest consensus state: current_term: 1 leader_uuid: "ce1fc8511df24bd1bc492d9706d27988" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "ce1fc8511df24bd1bc492d9706d27988" member_type: VOTER } }
I20260812 06:19:09.190948 14746 sys_catalog.cc:458] T 00000000000000000000000000000000 P ce1fc8511df24bd1bc492d9706d27988 [sys.catalog]: This master's current role is: LEADER
I20260812 06:19:09.191414 14756 catalog_manager.cc:1511] Loading table and tablet metadata into memory...
I20260812 06:19:09.192386 14756 catalog_manager.cc:1520] Initializing Kudu cluster ID...
I20260812 06:19:09.192648 14326 internal_mini_cluster.cc:184] Waiting to initialize catalog manager on master 0
I20260812 06:19:09.194171 14756 catalog_manager.cc:1383] Generated new cluster ID: e45aba69d088406fb3a6852d65a10260
I20260812 06:19:09.194226 14756 catalog_manager.cc:1531] Initializing Kudu internal certificate authority...
I20260812 06:19:09.203743 14756 catalog_manager.cc:1406] Generated new certificate authority record
I20260812 06:19:09.204236 14756 catalog_manager.cc:1540] Loading token signing keys...
I20260812 06:19:09.211087 14756 catalog_manager.cc:6092] T 00000000000000000000000000000000 P ce1fc8511df24bd1bc492d9706d27988: Generated new TSK 0
I20260812 06:19:09.211237 14756 catalog_manager.cc:1550] Initializing in-progress tserver states...
I20260812 06:19:09.225018 14326 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:19:09.226964 14774 instance_detector.cc:116] could not retrieve Azure instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:19:09.227006 14773 instance_detector.cc:116] could not retrieve AWS instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:19:09.227109 14326 server_base.cc:1061] running on GCE node
W20260812 06:19:09.226965 14777 instance_detector.cc:116] could not retrieve OpenStack instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:19:09.227391 14326 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:19:09.227454 14326 system_unsync_time.cc:38] NTP support is disabled. Clock error bounds will not be accurate. This configuration is not suitable for distributed clusters.
I20260812 06:19:09.227479 14326 hybrid_clock.cc:648] HybridClock initialized: now 1786515549227478 us; error 0 us; skew 500 ppm
I20260812 06:19:09.228317 14326 webserver.cc:533] Webserver started at http://127.13.253.129:41693/ using document root <none> and password file <none>
I20260812 06:19:09.228494 14326 fs_manager.cc:362] Metadata directory not provided
I20260812 06:19:09.228566 14326 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:19:09.228644 14326 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:19:09.229066 14326 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskbgpkED/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515543839567-14326-0/minicluster-data/ts-0-root/instance:
uuid: "6a0ebdeefd144b309086c92cd1642ab9"
format_stamp: "Formatted at 2026-08-12 06:19:09 on dist-test-slave-39l8"
I20260812 06:19:09.230517 14326 fs_manager.cc:696] Time spent creating directory manager: real 0.001s	user 0.002s	sys 0.000s
I20260812 06:19:09.231487 14786 log_block_manager.cc:4127] Time spent loading block containers with low live blocks: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:19:09.231750 14326 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.001s	sys 0.000s
I20260812 06:19:09.231837 14326 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskbgpkED/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515543839567-14326-0/minicluster-data/ts-0-root
uuid: "6a0ebdeefd144b309086c92cd1642ab9"
format_stamp: "Formatted at 2026-08-12 06:19:09 on dist-test-slave-39l8"
I20260812 06:19:09.231930 14326 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskbgpkED/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515543839567-14326-0/minicluster-data/ts-0-root
metadata directory: /tmp/dist-test-taskbgpkED/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515543839567-14326-0/minicluster-data/ts-0-root
1 data directories: /tmp/dist-test-taskbgpkED/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515543839567-14326-0/minicluster-data/ts-0-root/data
Total live blocks: 0
Total live bytes: 0
Total live bytes (after alignment): 0
Total number of LBM containers: 0 (0 full)
Did not check for missing blocks
Did not check for orphaned blocks
Total full LBM containers with extra space: 0 (0 repaired)
Total full LBM container extra space in bytes: 0 (0 repaired)
Total incomplete LBM containers: 0 (0 repaired)
Total LBM partial records: 0 (0 repaired)
Total corrupted LBM metadata records in RocksDB: 0 (0 repaired)
I20260812 06:19:09.252405 14326 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:19:09.252823 14326 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:19:09.253156 14326 txn_system_client.cc:432] TxnSystemClient initialization is disabled...
I20260812 06:19:09.253649 14326 ts_tablet_manager.cc:585] Loaded tablet metadata (0 total tablets, 0 live tablets)
I20260812 06:19:09.253711 14326 ts_tablet_manager.cc:531] Time spent load tablet metadata: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:19:09.253762 14326 ts_tablet_manager.cc:616] Registered 0 tablets
I20260812 06:19:09.253813 14326 ts_tablet_manager.cc:595] Time spent register tablets: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:19:09.258421 14326 rpc_server.cc:307] RPC server started. Bound to: 127.13.253.129:40199
I20260812 06:19:09.258546 14885 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.13.253.129:40199 every 8 connection(s)
I20260812 06:19:09.267189 14886 heartbeater.cc:344] Connected to a master server at 127.13.253.190:42851
I20260812 06:19:09.267304 14886 heartbeater.cc:461] Registering TS with master...
I20260812 06:19:09.267580 14886 heartbeater.cc:507] Master 127.13.253.190:42851 requested a full tablet report, sending...
I20260812 06:19:09.268249 14686 ts_manager.cc:194] Registered new tserver with Master: 6a0ebdeefd144b309086c92cd1642ab9 (127.13.253.129:40199)
I20260812 06:19:09.268872 14326 internal_mini_cluster.cc:371] 1 TS(s) registered with all masters after 0.009941881s
I20260812 06:19:09.269034 14686 master_service.cc:502] Signed X509 certificate for tserver {username='slave'} at 127.0.0.1:46800
I20260812 06:19:09.276468 14686 catalog_manager.cc:2283] Servicing CreateTable request from {username='slave'} at 127.0.0.1:46814:
name: "heavy-update-compaction-test"
schema {
  columns {
    name: "key"
    type: INT64
    is_key: true
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_a"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_b"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_c"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_d"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_e"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
}
num_replicas: 1
split_rows_range_bounds {
}
partition_schema {
  range_schema {
  }
}
I20260812 06:19:09.285085 14832 tablet_service.cc:1511] Processing CreateTablet for tablet 94839290fa604b5ca2b76d3e2431a44f (DEFAULT_TABLE table=heavy-update-compaction-test [id=689e293e55594bd992dda59470bbf096]), partition=
I20260812 06:19:09.285365 14832 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet 94839290fa604b5ca2b76d3e2431a44f. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:19:09.287504 14904 tablet_bootstrap.cc:492] T 94839290fa604b5ca2b76d3e2431a44f P 6a0ebdeefd144b309086c92cd1642ab9: Bootstrap starting.
I20260812 06:19:09.288360 14904 tablet_bootstrap.cc:654] T 94839290fa604b5ca2b76d3e2431a44f P 6a0ebdeefd144b309086c92cd1642ab9: Neither blocks nor log segments found. Creating new log.
I20260812 06:19:09.289287 14904 tablet_bootstrap.cc:492] T 94839290fa604b5ca2b76d3e2431a44f P 6a0ebdeefd144b309086c92cd1642ab9: No bootstrap required, opened a new log
I20260812 06:19:09.289358 14904 ts_tablet_manager.cc:1403] T 94839290fa604b5ca2b76d3e2431a44f P 6a0ebdeefd144b309086c92cd1642ab9: Time spent bootstrapping tablet: real 0.002s	user 0.001s	sys 0.000s
I20260812 06:19:09.289655 14904 raft_consensus.cc:359] T 94839290fa604b5ca2b76d3e2431a44f P 6a0ebdeefd144b309086c92cd1642ab9 [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "6a0ebdeefd144b309086c92cd1642ab9" member_type: VOTER last_known_addr { host: "127.13.253.129" port: 40199 } }
I20260812 06:19:09.289738 14904 raft_consensus.cc:385] T 94839290fa604b5ca2b76d3e2431a44f P 6a0ebdeefd144b309086c92cd1642ab9 [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:19:09.289760 14904 raft_consensus.cc:740] T 94839290fa604b5ca2b76d3e2431a44f P 6a0ebdeefd144b309086c92cd1642ab9 [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: 6a0ebdeefd144b309086c92cd1642ab9, State: Initialized, Role: FOLLOWER
I20260812 06:19:09.289893 14904 consensus_queue.cc:260] T 94839290fa604b5ca2b76d3e2431a44f P 6a0ebdeefd144b309086c92cd1642ab9 [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: "6a0ebdeefd144b309086c92cd1642ab9" member_type: VOTER last_known_addr { host: "127.13.253.129" port: 40199 } }
I20260812 06:19:09.289986 14904 raft_consensus.cc:399] T 94839290fa604b5ca2b76d3e2431a44f P 6a0ebdeefd144b309086c92cd1642ab9 [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:19:09.290010 14904 raft_consensus.cc:493] T 94839290fa604b5ca2b76d3e2431a44f P 6a0ebdeefd144b309086c92cd1642ab9 [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:19:09.290045 14904 raft_consensus.cc:3060] T 94839290fa604b5ca2b76d3e2431a44f P 6a0ebdeefd144b309086c92cd1642ab9 [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:19:09.291021 14904 raft_consensus.cc:515] T 94839290fa604b5ca2b76d3e2431a44f P 6a0ebdeefd144b309086c92cd1642ab9 [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "6a0ebdeefd144b309086c92cd1642ab9" member_type: VOTER last_known_addr { host: "127.13.253.129" port: 40199 } }
I20260812 06:19:09.291144 14904 leader_election.cc:304] T 94839290fa604b5ca2b76d3e2431a44f P 6a0ebdeefd144b309086c92cd1642ab9 [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: 6a0ebdeefd144b309086c92cd1642ab9; no voters: 
I20260812 06:19:09.291291 14904 leader_election.cc:290] T 94839290fa604b5ca2b76d3e2431a44f P 6a0ebdeefd144b309086c92cd1642ab9 [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:19:09.291421 14907 raft_consensus.cc:2804] T 94839290fa604b5ca2b76d3e2431a44f P 6a0ebdeefd144b309086c92cd1642ab9 [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:19:09.291605 14907 raft_consensus.cc:697] T 94839290fa604b5ca2b76d3e2431a44f P 6a0ebdeefd144b309086c92cd1642ab9 [term 1 LEADER]: Becoming Leader. State: Replica: 6a0ebdeefd144b309086c92cd1642ab9, State: Running, Role: LEADER
I20260812 06:19:09.291723 14904 ts_tablet_manager.cc:1434] T 94839290fa604b5ca2b76d3e2431a44f P 6a0ebdeefd144b309086c92cd1642ab9: Time spent starting tablet: real 0.002s	user 0.003s	sys 0.000s
I20260812 06:19:09.291761 14886 heartbeater.cc:499] Master 127.13.253.190:42851 was elected leader, sending a full tablet report...
I20260812 06:19:09.291765 14907 consensus_queue.cc:237] T 94839290fa604b5ca2b76d3e2431a44f P 6a0ebdeefd144b309086c92cd1642ab9 [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: "6a0ebdeefd144b309086c92cd1642ab9" member_type: VOTER last_known_addr { host: "127.13.253.129" port: 40199 } }
I20260812 06:19:09.293102 14686 catalog_manager.cc:5719] T 94839290fa604b5ca2b76d3e2431a44f P 6a0ebdeefd144b309086c92cd1642ab9 reported cstate change: term changed from 0 to 1, leader changed from <none> to 6a0ebdeefd144b309086c92cd1642ab9 (127.13.253.129). New cstate: current_term: 1 leader_uuid: "6a0ebdeefd144b309086c92cd1642ab9" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "6a0ebdeefd144b309086c92cd1642ab9" member_type: VOTER last_known_addr { host: "127.13.253.129" port: 40199 } health_report { overall_health: HEALTHY } } }
I20260812 06:19:09.348425 14326 heavy-update-compaction-itest.cc:215] Time spent inserting: real 0.052s	user 0.014s	sys 0.008s
I20260812 06:19:09.509500 14888 maintenance_manager.cc:419] P 6a0ebdeefd144b309086c92cd1642ab9: Scheduling FlushMRSOp(94839290fa604b5ca2b76d3e2431a44f): perf score=19.054940
I20260812 06:19:09.659485 14794 maintenance_manager.cc:643] P 6a0ebdeefd144b309086c92cd1642ab9: FlushMRSOp(94839290fa604b5ca2b76d3e2431a44f) complete. Timing: real 0.150s	user 0.097s	sys 0.052s Metrics: {"bytes_written":13702313,"cfile_init":1,"delete_count":0,"dirs.queue_time_us":59,"dirs.run_cpu_time_us":203,"dirs.run_wall_time_us":880,"drs_written":1,"lbm_read_time_us":113,"lbm_reads_lt_1ms":4,"lbm_write_time_us":39131,"lbm_writes_lt_1ms":791,"peak_mem_usage":0,"reinsert_count":0,"rows_written":104,"update_count":1670}
I20260812 06:19:09.660140 14888 maintenance_manager.cc:419] P 6a0ebdeefd144b309086c92cd1642ab9: Scheduling LogGCOp(94839290fa604b5ca2b76d3e2431a44f): free 20743880 bytes of WAL
I20260812 06:19:09.660437 14794 log_reader.cc:385] T 94839290fa604b5ca2b76d3e2431a44f: removed 2 log segments from log reader
I20260812 06:19:09.660512 14794 log.cc:1079] T 94839290fa604b5ca2b76d3e2431a44f P 6a0ebdeefd144b309086c92cd1642ab9: Deleting log segment in path: /tmp/dist-test-taskbgpkED/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515543839567-14326-0/minicluster-data/ts-0-root/wals/94839290fa604b5ca2b76d3e2431a44f/wal-000000001 (ops 1-6)
I20260812 06:19:09.660558 14794 log.cc:1079] T 94839290fa604b5ca2b76d3e2431a44f P 6a0ebdeefd144b309086c92cd1642ab9: Deleting log segment in path: /tmp/dist-test-taskbgpkED/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515543839567-14326-0/minicluster-data/ts-0-root/wals/94839290fa604b5ca2b76d3e2431a44f/wal-000000002 (ops 7-11)
I20260812 06:19:09.665948 14794 maintenance_manager.cc:643] P 6a0ebdeefd144b309086c92cd1642ab9: LogGCOp(94839290fa604b5ca2b76d3e2431a44f) complete. Timing: real 0.006s	user 0.000s	sys 0.002s Metrics: {}
I20260812 06:19:09.666400 14888 maintenance_manager.cc:419] P 6a0ebdeefd144b309086c92cd1642ab9: Scheduling UndoDeltaBlockGCOp(94839290fa604b5ca2b76d3e2431a44f): 16411396 bytes on disk
I20260812 06:19:09.666834 14794 maintenance_manager.cc:643] P 6a0ebdeefd144b309086c92cd1642ab9: UndoDeltaBlockGCOp(94839290fa604b5ca2b76d3e2431a44f) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":51,"lbm_reads_lt_1ms":4}
I20260812 06:19:09.667207 14888 maintenance_manager.cc:419] P 6a0ebdeefd144b309086c92cd1642ab9: Scheduling FlushDeltaMemStoresOp(94839290fa604b5ca2b76d3e2431a44f): perf score=2.188937
I20260812 06:19:09.677047 14794 maintenance_manager.cc:643] P 6a0ebdeefd144b309086c92cd1642ab9: FlushDeltaMemStoresOp(94839290fa604b5ca2b76d3e2431a44f) complete. Timing: real 0.010s	user 0.003s	sys 0.004s Metrics: {"bytes_written":3323188,"delete_count":0,"lbm_write_time_us":3384,"lbm_writes_lt_1ms":84,"reinsert_count":0,"update_count":405}
I20260812 06:19:09.677457 14888 maintenance_manager.cc:419] P 6a0ebdeefd144b309086c92cd1642ab9: Scheduling FlushDeltaMemStoresOp(94839290fa604b5ca2b76d3e2431a44f): perf score=2.188937
I20260812 06:19:09.689616 14794 maintenance_manager.cc:643] P 6a0ebdeefd144b309086c92cd1642ab9: FlushDeltaMemStoresOp(94839290fa604b5ca2b76d3e2431a44f) complete. Timing: real 0.012s	user 0.003s	sys 0.007s Metrics: {"bytes_written":3487280,"delete_count":0,"lbm_write_time_us":4706,"lbm_writes_lt_1ms":88,"reinsert_count":0,"update_count":425}
I20260812 06:19:09.690003 14888 maintenance_manager.cc:419] P 6a0ebdeefd144b309086c92cd1642ab9: Scheduling MajorDeltaCompactionOp(94839290fa604b5ca2b76d3e2431a44f): perf score=1.000000
I20260812 06:19:09.858851 14794 maintenance_manager.cc:643] P 6a0ebdeefd144b309086c92cd1642ab9: MajorDeltaCompactionOp(94839290fa604b5ca2b76d3e2431a44f) complete. Timing: real 0.169s	user 0.128s	sys 0.032s Metrics: {"cfile_cache_miss":533,"cfile_cache_miss_bytes":24774781,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":576,"lbm_read_time_us":10949,"lbm_reads_lt_1ms":569,"lbm_write_time_us":30982,"lbm_writes_lt_1ms":543,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":5248,"thread_start_us":369,"threads_started":5,"update_count":2500}
I20260812 06:19:09.859352 14888 maintenance_manager.cc:419] P 6a0ebdeefd144b309086c92cd1642ab9: Scheduling FlushDeltaMemStoresOp(94839290fa604b5ca2b76d3e2431a44f): perf score=14.095187
I20260812 06:19:09.908353 14794 maintenance_manager.cc:643] P 6a0ebdeefd144b309086c92cd1642ab9: FlushDeltaMemStoresOp(94839290fa604b5ca2b76d3e2431a44f) complete. Timing: real 0.049s	user 0.030s	sys 0.007s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":17214,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:09.908759 14888 maintenance_manager.cc:419] P 6a0ebdeefd144b309086c92cd1642ab9: Scheduling FlushDeltaMemStoresOp(94839290fa604b5ca2b76d3e2431a44f): perf score=2.188937
I20260812 06:19:09.919605 14794 maintenance_manager.cc:643] P 6a0ebdeefd144b309086c92cd1642ab9: FlushDeltaMemStoresOp(94839290fa604b5ca2b76d3e2431a44f) complete. Timing: real 0.011s	user 0.010s	sys 0.000s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4031,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:09.920061 14888 maintenance_manager.cc:419] P 6a0ebdeefd144b309086c92cd1642ab9: Scheduling MajorDeltaCompactionOp(94839290fa604b5ca2b76d3e2431a44f): perf score=1.000000
I20260812 06:19:10.089282 14794 maintenance_manager.cc:643] P 6a0ebdeefd144b309086c92cd1642ab9: MajorDeltaCompactionOp(94839290fa604b5ca2b76d3e2431a44f) complete. Timing: real 0.169s	user 0.103s	sys 0.053s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774687,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":137,"lbm_read_time_us":10073,"lbm_reads_lt_1ms":572,"lbm_write_time_us":31844,"lbm_writes_lt_1ms":543,"mutex_wait_us":21,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":13440,"update_count":2500}
I20260812 06:19:10.089912 14888 maintenance_manager.cc:419] P 6a0ebdeefd144b309086c92cd1642ab9: Scheduling FlushDeltaMemStoresOp(94839290fa604b5ca2b76d3e2431a44f): perf score=14.095187
I20260812 06:19:10.145681 14794 maintenance_manager.cc:643] P 6a0ebdeefd144b309086c92cd1642ab9: FlushDeltaMemStoresOp(94839290fa604b5ca2b76d3e2431a44f) complete. Timing: real 0.056s	user 0.016s	sys 0.024s Metrics: {"bytes_written":16409905,"delete_count":0,"lbm_write_time_us":19484,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:10.146224 14888 maintenance_manager.cc:419] P 6a0ebdeefd144b309086c92cd1642ab9: Scheduling FlushDeltaMemStoresOp(94839290fa604b5ca2b76d3e2431a44f): perf score=2.188937
I20260812 06:19:10.157222 14794 maintenance_manager.cc:643] P 6a0ebdeefd144b309086c92cd1642ab9: FlushDeltaMemStoresOp(94839290fa604b5ca2b76d3e2431a44f) complete. Timing: real 0.011s	user 0.006s	sys 0.003s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3862,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:10.157721 14888 maintenance_manager.cc:419] P 6a0ebdeefd144b309086c92cd1642ab9: Scheduling MajorDeltaCompactionOp(94839290fa604b5ca2b76d3e2431a44f): perf score=1.000000
I20260812 06:19:10.338783 14794 maintenance_manager.cc:643] P 6a0ebdeefd144b309086c92cd1642ab9: MajorDeltaCompactionOp(94839290fa604b5ca2b76d3e2431a44f) complete. Timing: real 0.181s	user 0.117s	sys 0.063s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774692,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":830,"lbm_read_time_us":13506,"lbm_reads_lt_1ms":572,"lbm_write_time_us":26970,"lbm_writes_lt_1ms":543,"mutex_wait_us":331,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":896,"update_count":2500}
I20260812 06:19:10.339329 14888 maintenance_manager.cc:419] P 6a0ebdeefd144b309086c92cd1642ab9: Scheduling FlushDeltaMemStoresOp(94839290fa604b5ca2b76d3e2431a44f): perf score=14.095187
I20260812 06:19:10.409772 14794 maintenance_manager.cc:643] P 6a0ebdeefd144b309086c92cd1642ab9: FlushDeltaMemStoresOp(94839290fa604b5ca2b76d3e2431a44f) complete. Timing: real 0.070s	user 0.033s	sys 0.024s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":28040,"lbm_writes_1-10_ms":3,"lbm_writes_lt_1ms":400,"reinsert_count":0,"update_count":2000}
I20260812 06:19:10.410233 14888 maintenance_manager.cc:419] P 6a0ebdeefd144b309086c92cd1642ab9: Scheduling FlushDeltaMemStoresOp(94839290fa604b5ca2b76d3e2431a44f): perf score=2.188937
I20260812 06:19:10.420774 14794 maintenance_manager.cc:643] P 6a0ebdeefd144b309086c92cd1642ab9: FlushDeltaMemStoresOp(94839290fa604b5ca2b76d3e2431a44f) complete. Timing: real 0.010s	user 0.008s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3790,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:10.421711 14888 maintenance_manager.cc:419] P 6a0ebdeefd144b309086c92cd1642ab9: Scheduling MajorDeltaCompactionOp(94839290fa604b5ca2b76d3e2431a44f): perf score=1.000000
I20260812 06:19:10.582764 14794 maintenance_manager.cc:643] P 6a0ebdeefd144b309086c92cd1642ab9: MajorDeltaCompactionOp(94839290fa604b5ca2b76d3e2431a44f) complete. Timing: real 0.161s	user 0.097s	sys 0.064s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774688,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":321,"lbm_read_time_us":11463,"lbm_reads_lt_1ms":572,"lbm_write_time_us":26970,"lbm_writes_lt_1ms":543,"mutex_wait_us":21,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":8704,"update_count":2500}
I20260812 06:19:10.583408 14888 maintenance_manager.cc:419] P 6a0ebdeefd144b309086c92cd1642ab9: Scheduling FlushDeltaMemStoresOp(94839290fa604b5ca2b76d3e2431a44f): perf score=14.095187
I20260812 06:19:10.640460 14794 maintenance_manager.cc:643] P 6a0ebdeefd144b309086c92cd1642ab9: FlushDeltaMemStoresOp(94839290fa604b5ca2b76d3e2431a44f) complete. Timing: real 0.057s	user 0.036s	sys 0.019s Metrics: {"bytes_written":16409903,"delete_count":0,"lbm_write_time_us":21256,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:10.641067 14888 maintenance_manager.cc:419] P 6a0ebdeefd144b309086c92cd1642ab9: Scheduling FlushDeltaMemStoresOp(94839290fa604b5ca2b76d3e2431a44f): perf score=2.188937
I20260812 06:19:10.652731 14794 maintenance_manager.cc:643] P 6a0ebdeefd144b309086c92cd1642ab9: FlushDeltaMemStoresOp(94839290fa604b5ca2b76d3e2431a44f) complete. Timing: real 0.011s	user 0.009s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4131,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:10.653160 14888 maintenance_manager.cc:419] P 6a0ebdeefd144b309086c92cd1642ab9: Scheduling MajorDeltaCompactionOp(94839290fa604b5ca2b76d3e2431a44f): perf score=1.000000
I20260812 06:19:10.834589 14794 maintenance_manager.cc:643] P 6a0ebdeefd144b309086c92cd1642ab9: MajorDeltaCompactionOp(94839290fa604b5ca2b76d3e2431a44f) complete. Timing: real 0.181s	user 0.117s	sys 0.064s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774690,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":208,"lbm_read_time_us":11979,"lbm_reads_lt_1ms":572,"lbm_write_time_us":29790,"lbm_writes_lt_1ms":543,"mutex_wait_us":42,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":3968,"update_count":2500}
I20260812 06:19:10.835328 14888 maintenance_manager.cc:419] P 6a0ebdeefd144b309086c92cd1642ab9: Scheduling FlushDeltaMemStoresOp(94839290fa604b5ca2b76d3e2431a44f): perf score=14.095187
I20260812 06:19:10.890475 14794 maintenance_manager.cc:643] P 6a0ebdeefd144b309086c92cd1642ab9: FlushDeltaMemStoresOp(94839290fa604b5ca2b76d3e2431a44f) complete. Timing: real 0.055s	user 0.041s	sys 0.011s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":20540,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:10.891044 14888 maintenance_manager.cc:419] P 6a0ebdeefd144b309086c92cd1642ab9: Scheduling FlushDeltaMemStoresOp(94839290fa604b5ca2b76d3e2431a44f): perf score=2.188937
I20260812 06:19:10.901630 14794 maintenance_manager.cc:643] P 6a0ebdeefd144b309086c92cd1642ab9: FlushDeltaMemStoresOp(94839290fa604b5ca2b76d3e2431a44f) complete. Timing: real 0.010s	user 0.009s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4143,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:10.902082 14888 maintenance_manager.cc:419] P 6a0ebdeefd144b309086c92cd1642ab9: Scheduling FlushMRSOp(94839290fa604b5ca2b76d3e2431a44f): perf score=1.000000
I20260812 06:19:10.944054 14794 maintenance_manager.cc:643] P 6a0ebdeefd144b309086c92cd1642ab9: FlushMRSOp(94839290fa604b5ca2b76d3e2431a44f) complete. Timing: real 0.042s	user 0.025s	sys 0.008s Metrics: {"bytes_written":1234473,"cfile_init":1,"dirs.queue_time_us":55,"dirs.run_cpu_time_us":239,"dirs.run_wall_time_us":1210,"drs_written":1,"lbm_read_time_us":41,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1421,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":30}
I20260812 06:19:10.944829 14888 maintenance_manager.cc:419] P 6a0ebdeefd144b309086c92cd1642ab9: Scheduling LogGCOp(94839290fa604b5ca2b76d3e2431a44f): free 120553343 bytes of WAL
I20260812 06:19:10.945081 14794 log_reader.cc:385] T 94839290fa604b5ca2b76d3e2431a44f: removed 12 log segments from log reader
I20260812 06:19:10.945150 14794 log.cc:1079] T 94839290fa604b5ca2b76d3e2431a44f P 6a0ebdeefd144b309086c92cd1642ab9: Deleting log segment in path: /tmp/dist-test-taskbgpkED/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515543839567-14326-0/minicluster-data/ts-0-root/wals/94839290fa604b5ca2b76d3e2431a44f/wal-000000003 (ops 12-16)
I20260812 06:19:10.945201 14794 log.cc:1079] T 94839290fa604b5ca2b76d3e2431a44f P 6a0ebdeefd144b309086c92cd1642ab9: Deleting log segment in path: /tmp/dist-test-taskbgpkED/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515543839567-14326-0/minicluster-data/ts-0-root/wals/94839290fa604b5ca2b76d3e2431a44f/wal-000000004 (ops 17-21)
I20260812 06:19:10.945255 14794 log.cc:1079] T 94839290fa604b5ca2b76d3e2431a44f P 6a0ebdeefd144b309086c92cd1642ab9: Deleting log segment in path: /tmp/dist-test-taskbgpkED/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515543839567-14326-0/minicluster-data/ts-0-root/wals/94839290fa604b5ca2b76d3e2431a44f/wal-000000005 (ops 22-26)
I20260812 06:19:10.945298 14794 log.cc:1079] T 94839290fa604b5ca2b76d3e2431a44f P 6a0ebdeefd144b309086c92cd1642ab9: Deleting log segment in path: /tmp/dist-test-taskbgpkED/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515543839567-14326-0/minicluster-data/ts-0-root/wals/94839290fa604b5ca2b76d3e2431a44f/wal-000000006 (ops 27-30)
I20260812 06:19:10.945338 14794 log.cc:1079] T 94839290fa604b5ca2b76d3e2431a44f P 6a0ebdeefd144b309086c92cd1642ab9: Deleting log segment in path: /tmp/dist-test-taskbgpkED/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515543839567-14326-0/minicluster-data/ts-0-root/wals/94839290fa604b5ca2b76d3e2431a44f/wal-000000007 (ops 31-35)
I20260812 06:19:10.945377 14794 log.cc:1079] T 94839290fa604b5ca2b76d3e2431a44f P 6a0ebdeefd144b309086c92cd1642ab9: Deleting log segment in path: /tmp/dist-test-taskbgpkED/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515543839567-14326-0/minicluster-data/ts-0-root/wals/94839290fa604b5ca2b76d3e2431a44f/wal-000000008 (ops 36-40)
I20260812 06:19:10.945415 14794 log.cc:1079] T 94839290fa604b5ca2b76d3e2431a44f P 6a0ebdeefd144b309086c92cd1642ab9: Deleting log segment in path: /tmp/dist-test-taskbgpkED/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515543839567-14326-0/minicluster-data/ts-0-root/wals/94839290fa604b5ca2b76d3e2431a44f/wal-000000009 (ops 41-44)
I20260812 06:19:10.945454 14794 log.cc:1079] T 94839290fa604b5ca2b76d3e2431a44f P 6a0ebdeefd144b309086c92cd1642ab9: Deleting log segment in path: /tmp/dist-test-taskbgpkED/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515543839567-14326-0/minicluster-data/ts-0-root/wals/94839290fa604b5ca2b76d3e2431a44f/wal-000000010 (ops 45-49)
I20260812 06:19:10.945489 14794 log.cc:1079] T 94839290fa604b5ca2b76d3e2431a44f P 6a0ebdeefd144b309086c92cd1642ab9: Deleting log segment in path: /tmp/dist-test-taskbgpkED/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515543839567-14326-0/minicluster-data/ts-0-root/wals/94839290fa604b5ca2b76d3e2431a44f/wal-000000011 (ops 50-54)
I20260812 06:19:10.945525 14794 log.cc:1079] T 94839290fa604b5ca2b76d3e2431a44f P 6a0ebdeefd144b309086c92cd1642ab9: Deleting log segment in path: /tmp/dist-test-taskbgpkED/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515543839567-14326-0/minicluster-data/ts-0-root/wals/94839290fa604b5ca2b76d3e2431a44f/wal-000000012 (ops 55-59)
I20260812 06:19:10.945561 14794 log.cc:1079] T 94839290fa604b5ca2b76d3e2431a44f P 6a0ebdeefd144b309086c92cd1642ab9: Deleting log segment in path: /tmp/dist-test-taskbgpkED/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515543839567-14326-0/minicluster-data/ts-0-root/wals/94839290fa604b5ca2b76d3e2431a44f/wal-000000013 (ops 60-64)
I20260812 06:19:10.945597 14794 log.cc:1079] T 94839290fa604b5ca2b76d3e2431a44f P 6a0ebdeefd144b309086c92cd1642ab9: Deleting log segment in path: /tmp/dist-test-taskbgpkED/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515543839567-14326-0/minicluster-data/ts-0-root/wals/94839290fa604b5ca2b76d3e2431a44f/wal-000000014 (ops 65-69)
I20260812 06:19:10.971927 14794 maintenance_manager.cc:643] P 6a0ebdeefd144b309086c92cd1642ab9: LogGCOp(94839290fa604b5ca2b76d3e2431a44f) complete. Timing: real 0.027s	user 0.000s	sys 0.026s Metrics: {}
I20260812 06:19:10.972466 14888 maintenance_manager.cc:419] P 6a0ebdeefd144b309086c92cd1642ab9: Scheduling FlushDeltaMemStoresOp(94839290fa604b5ca2b76d3e2431a44f): perf score=3.181125
I20260812 06:19:10.993754 14794 maintenance_manager.cc:643] P 6a0ebdeefd144b309086c92cd1642ab9: FlushDeltaMemStoresOp(94839290fa604b5ca2b76d3e2431a44f) complete. Timing: real 0.021s	user 0.012s	sys 0.004s Metrics: {"bytes_written":4512900,"delete_count":0,"lbm_write_time_us":6864,"lbm_writes_lt_1ms":113,"reinsert_count":0,"update_count":550}
I20260812 06:19:10.994266 14888 maintenance_manager.cc:419] P 6a0ebdeefd144b309086c92cd1642ab9: Scheduling FlushDeltaMemStoresOp(94839290fa604b5ca2b76d3e2431a44f): perf score=2.188937
I20260812 06:19:11.007377 14794 maintenance_manager.cc:643] P 6a0ebdeefd144b309086c92cd1642ab9: FlushDeltaMemStoresOp(94839290fa604b5ca2b76d3e2431a44f) complete. Timing: real 0.013s	user 0.012s	sys 0.000s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":4931,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:19:11.007890 14888 maintenance_manager.cc:419] P 6a0ebdeefd144b309086c92cd1642ab9: Scheduling UndoDeltaBlockGCOp(94839290fa604b5ca2b76d3e2431a44f): 472 bytes on disk
I20260812 06:19:11.008383 14794 maintenance_manager.cc:643] P 6a0ebdeefd144b309086c92cd1642ab9: UndoDeltaBlockGCOp(94839290fa604b5ca2b76d3e2431a44f) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":66,"lbm_reads_lt_1ms":4}
I20260812 06:19:11.008865 14888 maintenance_manager.cc:419] P 6a0ebdeefd144b309086c92cd1642ab9: Scheduling MajorDeltaCompactionOp(94839290fa604b5ca2b76d3e2431a44f): perf score=1.000000
I20260812 06:19:11.227643 14794 maintenance_manager.cc:643] P 6a0ebdeefd144b309086c92cd1642ab9: MajorDeltaCompactionOp(94839290fa604b5ca2b76d3e2431a44f) complete. Timing: real 0.219s	user 0.156s	sys 0.060s Metrics: {"cfile_cache_miss":734,"cfile_cache_miss_bytes":32979738,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":478,"lbm_read_time_us":16585,"lbm_reads_lt_1ms":774,"lbm_write_time_us":34674,"lbm_writes_lt_1ms":743,"mutex_wait_us":34,"peak_mem_usage":87969044,"reinsert_count":0,"spinlock_wait_cycles":9088,"thread_start_us":82,"threads_started":1,"update_count":3500}
I20260812 06:19:11.228430 14888 maintenance_manager.cc:419] P 6a0ebdeefd144b309086c92cd1642ab9: Scheduling FlushDeltaMemStoresOp(94839290fa604b5ca2b76d3e2431a44f): perf score=15.087375
I20260812 06:19:11.291679 14794 maintenance_manager.cc:643] P 6a0ebdeefd144b309086c92cd1642ab9: FlushDeltaMemStoresOp(94839290fa604b5ca2b76d3e2431a44f) complete. Timing: real 0.063s	user 0.028s	sys 0.020s Metrics: {"bytes_written":16820145,"delete_count":0,"lbm_write_time_us":21569,"lbm_writes_lt_1ms":413,"reinsert_count":0,"update_count":2050}
I20260812 06:19:11.292310 14888 maintenance_manager.cc:419] P 6a0ebdeefd144b309086c92cd1642ab9: Scheduling FlushDeltaMemStoresOp(94839290fa604b5ca2b76d3e2431a44f): perf score=6.157687
I20260812 06:19:11.319427 14794 maintenance_manager.cc:643] P 6a0ebdeefd144b309086c92cd1642ab9: FlushDeltaMemStoresOp(94839290fa604b5ca2b76d3e2431a44f) complete. Timing: real 0.027s	user 0.018s	sys 0.008s Metrics: {"bytes_written":7794836,"delete_count":0,"lbm_write_time_us":11031,"lbm_writes_lt_1ms":193,"reinsert_count":0,"update_count":950}
I20260812 06:19:11.319852 14888 maintenance_manager.cc:419] P 6a0ebdeefd144b309086c92cd1642ab9: Scheduling MajorDeltaCompactionOp(94839290fa604b5ca2b76d3e2431a44f): perf score=1.000000
I20260812 06:19:11.493835 14794 maintenance_manager.cc:643] P 6a0ebdeefd144b309086c92cd1642ab9: MajorDeltaCompactionOp(94839290fa604b5ca2b76d3e2431a44f) complete. Timing: real 0.174s	user 0.097s	sys 0.076s Metrics: {"cfile_cache_miss":632,"cfile_cache_miss_bytes":28877103,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":93,"lbm_read_time_us":10121,"lbm_reads_lt_1ms":672,"lbm_write_time_us":34566,"lbm_writes_lt_1ms":643,"mutex_wait_us":47,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":18944,"update_count":3000}
I20260812 06:19:11.495827 14888 maintenance_manager.cc:419] P 6a0ebdeefd144b309086c92cd1642ab9: Scheduling FlushDeltaMemStoresOp(94839290fa604b5ca2b76d3e2431a44f): perf score=14.095187
I20260812 06:19:11.533742 14794 maintenance_manager.cc:643] P 6a0ebdeefd144b309086c92cd1642ab9: FlushDeltaMemStoresOp(94839290fa604b5ca2b76d3e2431a44f) complete. Timing: real 0.038s	user 0.014s	sys 0.021s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":16969,"lbm_writes_lt_1ms":403,"reinsert_count":0,"spinlock_wait_cycles":2432,"update_count":2000}
I20260812 06:19:11.534264 14888 maintenance_manager.cc:419] P 6a0ebdeefd144b309086c92cd1642ab9: Scheduling FlushDeltaMemStoresOp(94839290fa604b5ca2b76d3e2431a44f): perf score=2.188937
I20260812 06:19:11.552476 14794 maintenance_manager.cc:643] P 6a0ebdeefd144b309086c92cd1642ab9: FlushDeltaMemStoresOp(94839290fa604b5ca2b76d3e2431a44f) complete. Timing: real 0.018s	user 0.015s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6249,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:11.552958 14888 maintenance_manager.cc:419] P 6a0ebdeefd144b309086c92cd1642ab9: Scheduling MajorDeltaCompactionOp(94839290fa604b5ca2b76d3e2431a44f): perf score=1.000000
I20260812 06:19:11.722509 14794 maintenance_manager.cc:643] P 6a0ebdeefd144b309086c92cd1642ab9: MajorDeltaCompactionOp(94839290fa604b5ca2b76d3e2431a44f) complete. Timing: real 0.169s	user 0.121s	sys 0.039s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774688,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":338,"lbm_read_time_us":10078,"lbm_reads_lt_1ms":564,"lbm_write_time_us":33001,"lbm_writes_lt_1ms":543,"mutex_wait_us":41,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":19584,"update_count":2500}
I20260812 06:19:11.723222 14888 maintenance_manager.cc:419] P 6a0ebdeefd144b309086c92cd1642ab9: Scheduling FlushDeltaMemStoresOp(94839290fa604b5ca2b76d3e2431a44f): perf score=14.095187
I20260812 06:19:11.778658 14794 maintenance_manager.cc:643] P 6a0ebdeefd144b309086c92cd1642ab9: FlushDeltaMemStoresOp(94839290fa604b5ca2b76d3e2431a44f) complete. Timing: real 0.055s	user 0.031s	sys 0.020s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":24176,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:11.779400 14888 maintenance_manager.cc:419] P 6a0ebdeefd144b309086c92cd1642ab9: Scheduling MajorDeltaCompactionOp(94839290fa604b5ca2b76d3e2431a44f): perf score=1.000000
I20260812 06:19:11.925961 14794 maintenance_manager.cc:643] P 6a0ebdeefd144b309086c92cd1642ab9: MajorDeltaCompactionOp(94839290fa604b5ca2b76d3e2431a44f) complete. Timing: real 0.146s	user 0.098s	sys 0.049s Metrics: {"cfile_cache_miss":431,"cfile_cache_miss_bytes":20672157,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":1,"delta_iterators_relevant":1,"dirs.queue_time_us":173,"lbm_read_time_us":9311,"lbm_reads_lt_1ms":463,"lbm_write_time_us":22950,"lbm_writes_lt_1ms":443,"mutex_wait_us":38,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":6656,"update_count":2000}
I20260812 06:19:11.926530 14888 maintenance_manager.cc:419] P 6a0ebdeefd144b309086c92cd1642ab9: Scheduling FlushDeltaMemStoresOp(94839290fa604b5ca2b76d3e2431a44f): perf score=14.095187
I20260812 06:19:11.981827 14794 maintenance_manager.cc:643] P 6a0ebdeefd144b309086c92cd1642ab9: FlushDeltaMemStoresOp(94839290fa604b5ca2b76d3e2431a44f) complete. Timing: real 0.055s	user 0.038s	sys 0.011s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":23832,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:11.982403 14888 maintenance_manager.cc:419] P 6a0ebdeefd144b309086c92cd1642ab9: Scheduling FlushDeltaMemStoresOp(94839290fa604b5ca2b76d3e2431a44f): perf score=2.188937
I20260812 06:19:11.993912 14794 maintenance_manager.cc:643] P 6a0ebdeefd144b309086c92cd1642ab9: FlushDeltaMemStoresOp(94839290fa604b5ca2b76d3e2431a44f) complete. Timing: real 0.011s	user 0.010s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4137,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:11.994391 14888 maintenance_manager.cc:419] P 6a0ebdeefd144b309086c92cd1642ab9: Scheduling MajorDeltaCompactionOp(94839290fa604b5ca2b76d3e2431a44f): perf score=1.000000
I20260812 06:19:12.183936 14794 maintenance_manager.cc:643] P 6a0ebdeefd144b309086c92cd1642ab9: MajorDeltaCompactionOp(94839290fa604b5ca2b76d3e2431a44f) complete. Timing: real 0.189s	user 0.108s	sys 0.071s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774688,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":249,"lbm_read_time_us":11766,"lbm_reads_lt_1ms":572,"lbm_write_time_us":28842,"lbm_writes_lt_1ms":543,"mutex_wait_us":56,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":1408,"update_count":2500}
I20260812 06:19:12.184577 14888 maintenance_manager.cc:419] P 6a0ebdeefd144b309086c92cd1642ab9: Scheduling FlushDeltaMemStoresOp(94839290fa604b5ca2b76d3e2431a44f): perf score=14.095187
I20260812 06:19:12.243674 14794 maintenance_manager.cc:643] P 6a0ebdeefd144b309086c92cd1642ab9: FlushDeltaMemStoresOp(94839290fa604b5ca2b76d3e2431a44f) complete. Timing: real 0.059s	user 0.035s	sys 0.016s Metrics: {"bytes_written":16409904,"delete_count":0,"lbm_write_time_us":22978,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:12.244143 14888 maintenance_manager.cc:419] P 6a0ebdeefd144b309086c92cd1642ab9: Scheduling FlushDeltaMemStoresOp(94839290fa604b5ca2b76d3e2431a44f): perf score=2.188937
I20260812 06:19:12.256296 14794 maintenance_manager.cc:643] P 6a0ebdeefd144b309086c92cd1642ab9: FlushDeltaMemStoresOp(94839290fa604b5ca2b76d3e2431a44f) complete. Timing: real 0.012s	user 0.007s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4318,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:12.256844 14888 maintenance_manager.cc:419] P 6a0ebdeefd144b309086c92cd1642ab9: Scheduling MajorDeltaCompactionOp(94839290fa604b5ca2b76d3e2431a44f): perf score=1.000000
I20260812 06:19:12.425415 14794 maintenance_manager.cc:643] P 6a0ebdeefd144b309086c92cd1642ab9: MajorDeltaCompactionOp(94839290fa604b5ca2b76d3e2431a44f) complete. Timing: real 0.168s	user 0.119s	sys 0.044s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774691,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":455,"lbm_read_time_us":9835,"lbm_reads_lt_1ms":572,"lbm_write_time_us":32447,"lbm_writes_lt_1ms":543,"mutex_wait_us":104,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":5888,"update_count":2500}
I20260812 06:19:12.426105 14888 maintenance_manager.cc:419] P 6a0ebdeefd144b309086c92cd1642ab9: Scheduling FlushDeltaMemStoresOp(94839290fa604b5ca2b76d3e2431a44f): perf score=11.118625
I20260812 06:19:12.459872 14794 maintenance_manager.cc:643] P 6a0ebdeefd144b309086c92cd1642ab9: FlushDeltaMemStoresOp(94839290fa604b5ca2b76d3e2431a44f) complete. Timing: real 0.034s	user 0.013s	sys 0.019s Metrics: {"bytes_written":12717737,"delete_count":0,"lbm_write_time_us":14516,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:19:12.460348 14888 maintenance_manager.cc:419] P 6a0ebdeefd144b309086c92cd1642ab9: Scheduling FlushDeltaMemStoresOp(94839290fa604b5ca2b76d3e2431a44f): perf score=2.188937
I20260812 06:19:12.483385 14794 maintenance_manager.cc:643] P 6a0ebdeefd144b309086c92cd1642ab9: FlushDeltaMemStoresOp(94839290fa604b5ca2b76d3e2431a44f) complete. Timing: real 0.023s	user 0.009s	sys 0.004s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":4686,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:19:12.483839 14888 maintenance_manager.cc:419] P 6a0ebdeefd144b309086c92cd1642ab9: Scheduling FlushDeltaMemStoresOp(94839290fa604b5ca2b76d3e2431a44f): perf score=2.188937
I20260812 06:19:12.494796 14794 maintenance_manager.cc:643] P 6a0ebdeefd144b309086c92cd1642ab9: FlushDeltaMemStoresOp(94839290fa604b5ca2b76d3e2431a44f) complete. Timing: real 0.011s	user 0.007s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4539,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:12.495258 14888 maintenance_manager.cc:419] P 6a0ebdeefd144b309086c92cd1642ab9: Scheduling FlushMRSOp(94839290fa604b5ca2b76d3e2431a44f): perf score=1.000000
I20260812 06:19:12.525151 14794 maintenance_manager.cc:643] P 6a0ebdeefd144b309086c92cd1642ab9: FlushMRSOp(94839290fa604b5ca2b76d3e2431a44f) complete. Timing: real 0.030s	user 0.028s	sys 0.000s Metrics: {"bytes_written":1316419,"cfile_init":1,"dirs.queue_time_us":74,"dirs.run_cpu_time_us":182,"dirs.run_wall_time_us":1121,"drs_written":1,"lbm_read_time_us":43,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1829,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":32}
I20260812 06:19:12.525846 14888 maintenance_manager.cc:419] P 6a0ebdeefd144b309086c92cd1642ab9: Scheduling LogGCOp(94839290fa604b5ca2b76d3e2431a44f): free 132571380 bytes of WAL
I20260812 06:19:12.526063 14794 log_reader.cc:385] T 94839290fa604b5ca2b76d3e2431a44f: removed 13 log segments from log reader
I20260812 06:19:12.526129 14794 log.cc:1079] T 94839290fa604b5ca2b76d3e2431a44f P 6a0ebdeefd144b309086c92cd1642ab9: Deleting log segment in path: /tmp/dist-test-taskbgpkED/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515543839567-14326-0/minicluster-data/ts-0-root/wals/94839290fa604b5ca2b76d3e2431a44f/wal-000000015 (ops 70-74)
I20260812 06:19:12.526182 14794 log.cc:1079] T 94839290fa604b5ca2b76d3e2431a44f P 6a0ebdeefd144b309086c92cd1642ab9: Deleting log segment in path: /tmp/dist-test-taskbgpkED/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515543839567-14326-0/minicluster-data/ts-0-root/wals/94839290fa604b5ca2b76d3e2431a44f/wal-000000016 (ops 75-78)
I20260812 06:19:12.526223 14794 log.cc:1079] T 94839290fa604b5ca2b76d3e2431a44f P 6a0ebdeefd144b309086c92cd1642ab9: Deleting log segment in path: /tmp/dist-test-taskbgpkED/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515543839567-14326-0/minicluster-data/ts-0-root/wals/94839290fa604b5ca2b76d3e2431a44f/wal-000000017 (ops 79-83)
I20260812 06:19:12.526260 14794 log.cc:1079] T 94839290fa604b5ca2b76d3e2431a44f P 6a0ebdeefd144b309086c92cd1642ab9: Deleting log segment in path: /tmp/dist-test-taskbgpkED/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515543839567-14326-0/minicluster-data/ts-0-root/wals/94839290fa604b5ca2b76d3e2431a44f/wal-000000018 (ops 84-88)
I20260812 06:19:12.526297 14794 log.cc:1079] T 94839290fa604b5ca2b76d3e2431a44f P 6a0ebdeefd144b309086c92cd1642ab9: Deleting log segment in path: /tmp/dist-test-taskbgpkED/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515543839567-14326-0/minicluster-data/ts-0-root/wals/94839290fa604b5ca2b76d3e2431a44f/wal-000000019 (ops 89-93)
I20260812 06:19:12.526335 14794 log.cc:1079] T 94839290fa604b5ca2b76d3e2431a44f P 6a0ebdeefd144b309086c92cd1642ab9: Deleting log segment in path: /tmp/dist-test-taskbgpkED/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515543839567-14326-0/minicluster-data/ts-0-root/wals/94839290fa604b5ca2b76d3e2431a44f/wal-000000020 (ops 94-98)
I20260812 06:19:12.526371 14794 log.cc:1079] T 94839290fa604b5ca2b76d3e2431a44f P 6a0ebdeefd144b309086c92cd1642ab9: Deleting log segment in path: /tmp/dist-test-taskbgpkED/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515543839567-14326-0/minicluster-data/ts-0-root/wals/94839290fa604b5ca2b76d3e2431a44f/wal-000000021 (ops 99-102)
I20260812 06:19:12.526407 14794 log.cc:1079] T 94839290fa604b5ca2b76d3e2431a44f P 6a0ebdeefd144b309086c92cd1642ab9: Deleting log segment in path: /tmp/dist-test-taskbgpkED/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515543839567-14326-0/minicluster-data/ts-0-root/wals/94839290fa604b5ca2b76d3e2431a44f/wal-000000022 (ops 103-107)
I20260812 06:19:12.526443 14794 log.cc:1079] T 94839290fa604b5ca2b76d3e2431a44f P 6a0ebdeefd144b309086c92cd1642ab9: Deleting log segment in path: /tmp/dist-test-taskbgpkED/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515543839567-14326-0/minicluster-data/ts-0-root/wals/94839290fa604b5ca2b76d3e2431a44f/wal-000000023 (ops 108-112)
I20260812 06:19:12.526481 14794 log.cc:1079] T 94839290fa604b5ca2b76d3e2431a44f P 6a0ebdeefd144b309086c92cd1642ab9: Deleting log segment in path: /tmp/dist-test-taskbgpkED/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515543839567-14326-0/minicluster-data/ts-0-root/wals/94839290fa604b5ca2b76d3e2431a44f/wal-000000024 (ops 113-117)
I20260812 06:19:12.526517 14794 log.cc:1079] T 94839290fa604b5ca2b76d3e2431a44f P 6a0ebdeefd144b309086c92cd1642ab9: Deleting log segment in path: /tmp/dist-test-taskbgpkED/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515543839567-14326-0/minicluster-data/ts-0-root/wals/94839290fa604b5ca2b76d3e2431a44f/wal-000000025 (ops 118-122)
I20260812 06:19:12.526553 14794 log.cc:1079] T 94839290fa604b5ca2b76d3e2431a44f P 6a0ebdeefd144b309086c92cd1642ab9: Deleting log segment in path: /tmp/dist-test-taskbgpkED/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515543839567-14326-0/minicluster-data/ts-0-root/wals/94839290fa604b5ca2b76d3e2431a44f/wal-000000026 (ops 123-127)
I20260812 06:19:12.526592 14794 log.cc:1079] T 94839290fa604b5ca2b76d3e2431a44f P 6a0ebdeefd144b309086c92cd1642ab9: Deleting log segment in path: /tmp/dist-test-taskbgpkED/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515543839567-14326-0/minicluster-data/ts-0-root/wals/94839290fa604b5ca2b76d3e2431a44f/wal-000000027 (ops 128-132)
I20260812 06:19:12.554467 14794 maintenance_manager.cc:643] P 6a0ebdeefd144b309086c92cd1642ab9: LogGCOp(94839290fa604b5ca2b76d3e2431a44f) complete. Timing: real 0.028s	user 0.000s	sys 0.025s Metrics: {}
I20260812 06:19:12.555156 14888 maintenance_manager.cc:419] P 6a0ebdeefd144b309086c92cd1642ab9: Scheduling FlushDeltaMemStoresOp(94839290fa604b5ca2b76d3e2431a44f): perf score=4.173312
I20260812 06:19:12.580111 14794 maintenance_manager.cc:643] P 6a0ebdeefd144b309086c92cd1642ab9: FlushDeltaMemStoresOp(94839290fa604b5ca2b76d3e2431a44f) complete. Timing: real 0.025s	user 0.004s	sys 0.019s Metrics: {"bytes_written":6071824,"delete_count":0,"lbm_write_time_us":6144,"lbm_writes_lt_1ms":151,"reinsert_count":0,"update_count":740}
I20260812 06:19:12.580732 14888 maintenance_manager.cc:419] P 6a0ebdeefd144b309086c92cd1642ab9: Scheduling UndoDeltaBlockGCOp(94839290fa604b5ca2b76d3e2431a44f): 492 bytes on disk
I20260812 06:19:12.581207 14794 maintenance_manager.cc:643] P 6a0ebdeefd144b309086c92cd1642ab9: UndoDeltaBlockGCOp(94839290fa604b5ca2b76d3e2431a44f) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":62,"lbm_reads_lt_1ms":4}
I20260812 06:19:12.581717 14888 maintenance_manager.cc:419] P 6a0ebdeefd144b309086c92cd1642ab9: Scheduling FlushDeltaMemStoresOp(94839290fa604b5ca2b76d3e2431a44f): perf score=1.000000
I20260812 06:19:12.588270 14794 maintenance_manager.cc:643] P 6a0ebdeefd144b309086c92cd1642ab9: FlushDeltaMemStoresOp(94839290fa604b5ca2b76d3e2431a44f) complete. Timing: real 0.006s	user 0.005s	sys 0.000s Metrics: {"bytes_written":2133453,"delete_count":0,"lbm_write_time_us":2193,"lbm_writes_lt_1ms":55,"reinsert_count":0,"update_count":260}
I20260812 06:19:12.588647 14888 maintenance_manager.cc:419] P 6a0ebdeefd144b309086c92cd1642ab9: Scheduling MajorDeltaCompactionOp(94839290fa604b5ca2b76d3e2431a44f): perf score=1.000000
I20260812 06:19:12.809870 14794 maintenance_manager.cc:643] P 6a0ebdeefd144b309086c92cd1642ab9: MajorDeltaCompactionOp(94839290fa604b5ca2b76d3e2431a44f) complete. Timing: real 0.221s	user 0.162s	sys 0.057s Metrics: {"cfile_cache_miss":735,"cfile_cache_miss_bytes":32979816,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":5,"delta_iterators_relevant":5,"dirs.queue_time_us":520,"lbm_read_time_us":15628,"lbm_reads_lt_1ms":775,"lbm_write_time_us":36961,"lbm_writes_lt_1ms":743,"mutex_wait_us":39,"peak_mem_usage":87969044,"reinsert_count":0,"spinlock_wait_cycles":10240,"thread_start_us":81,"threads_started":1,"update_count":3500}
I20260812 06:19:12.810381 14888 maintenance_manager.cc:419] P 6a0ebdeefd144b309086c92cd1642ab9: Scheduling FlushDeltaMemStoresOp(94839290fa604b5ca2b76d3e2431a44f): perf score=15.087375
I20260812 06:19:12.865939 14794 maintenance_manager.cc:643] P 6a0ebdeefd144b309086c92cd1642ab9: FlushDeltaMemStoresOp(94839290fa604b5ca2b76d3e2431a44f) complete. Timing: real 0.055s	user 0.025s	sys 0.027s Metrics: {"bytes_written":16820144,"delete_count":0,"lbm_write_time_us":24487,"lbm_writes_lt_1ms":413,"reinsert_count":0,"update_count":2050}
I20260812 06:19:12.866722 14888 maintenance_manager.cc:419] P 6a0ebdeefd144b309086c92cd1642ab9: Scheduling FlushDeltaMemStoresOp(94839290fa604b5ca2b76d3e2431a44f): perf score=2.188937
I20260812 06:19:12.887108 14794 maintenance_manager.cc:643] P 6a0ebdeefd144b309086c92cd1642ab9: FlushDeltaMemStoresOp(94839290fa604b5ca2b76d3e2431a44f) complete. Timing: real 0.020s	user 0.011s	sys 0.001s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4592,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:12.887550 14888 maintenance_manager.cc:419] P 6a0ebdeefd144b309086c92cd1642ab9: Scheduling FlushDeltaMemStoresOp(94839290fa604b5ca2b76d3e2431a44f): perf score=2.188937
I20260812 06:19:12.897389 14794 maintenance_manager.cc:643] P 6a0ebdeefd144b309086c92cd1642ab9: FlushDeltaMemStoresOp(94839290fa604b5ca2b76d3e2431a44f) complete. Timing: real 0.010s	user 0.001s	sys 0.007s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3727,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:19:12.897811 14888 maintenance_manager.cc:419] P 6a0ebdeefd144b309086c92cd1642ab9: Scheduling MajorDeltaCompactionOp(94839290fa604b5ca2b76d3e2431a44f): perf score=1.000000
I20260812 06:19:13.099447 14794 maintenance_manager.cc:643] P 6a0ebdeefd144b309086c92cd1642ab9: MajorDeltaCompactionOp(94839290fa604b5ca2b76d3e2431a44f) complete. Timing: real 0.201s	user 0.142s	sys 0.059s Metrics: {"cfile_cache_miss":633,"cfile_cache_miss_bytes":28877208,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":667,"lbm_read_time_us":13501,"lbm_reads_lt_1ms":673,"lbm_write_time_us":32894,"lbm_writes_lt_1ms":643,"mutex_wait_us":41,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":16000,"update_count":3000}
I20260812 06:19:13.100215 14888 maintenance_manager.cc:419] P 6a0ebdeefd144b309086c92cd1642ab9: Scheduling FlushDeltaMemStoresOp(94839290fa604b5ca2b76d3e2431a44f): perf score=14.095187
I20260812 06:19:13.154052 14794 maintenance_manager.cc:643] P 6a0ebdeefd144b309086c92cd1642ab9: FlushDeltaMemStoresOp(94839290fa604b5ca2b76d3e2431a44f) complete. Timing: real 0.054s	user 0.026s	sys 0.023s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":25157,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":402,"reinsert_count":0,"update_count":2000}
I20260812 06:19:13.154605 14888 maintenance_manager.cc:419] P 6a0ebdeefd144b309086c92cd1642ab9: Scheduling FlushDeltaMemStoresOp(94839290fa604b5ca2b76d3e2431a44f): perf score=2.188937
I20260812 06:19:13.171033 14794 maintenance_manager.cc:643] P 6a0ebdeefd144b309086c92cd1642ab9: FlushDeltaMemStoresOp(94839290fa604b5ca2b76d3e2431a44f) complete. Timing: real 0.016s	user 0.010s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5802,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:13.171582 14888 maintenance_manager.cc:419] P 6a0ebdeefd144b309086c92cd1642ab9: Scheduling MajorDeltaCompactionOp(94839290fa604b5ca2b76d3e2431a44f): perf score=1.000000
I20260812 06:19:13.345723 14794 maintenance_manager.cc:643] P 6a0ebdeefd144b309086c92cd1642ab9: MajorDeltaCompactionOp(94839290fa604b5ca2b76d3e2431a44f) complete. Timing: real 0.174s	user 0.116s	sys 0.057s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774688,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":1017,"lbm_read_time_us":12219,"lbm_reads_lt_1ms":564,"lbm_write_time_us":31209,"lbm_writes_lt_1ms":543,"mutex_wait_us":319,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":2432,"update_count":2500}
I20260812 06:19:13.346217 14888 maintenance_manager.cc:419] P 6a0ebdeefd144b309086c92cd1642ab9: Scheduling FlushDeltaMemStoresOp(94839290fa604b5ca2b76d3e2431a44f): perf score=14.095187
I20260812 06:19:13.411787 14794 maintenance_manager.cc:643] P 6a0ebdeefd144b309086c92cd1642ab9: FlushDeltaMemStoresOp(94839290fa604b5ca2b76d3e2431a44f) complete. Timing: real 0.065s	user 0.024s	sys 0.026s Metrics: {"bytes_written":16409903,"delete_count":0,"lbm_write_time_us":23230,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":402,"reinsert_count":0,"update_count":2000}
I20260812 06:19:13.412307 14888 maintenance_manager.cc:419] P 6a0ebdeefd144b309086c92cd1642ab9: Scheduling FlushDeltaMemStoresOp(94839290fa604b5ca2b76d3e2431a44f): perf score=2.188937
I20260812 06:19:13.423183 14794 maintenance_manager.cc:643] P 6a0ebdeefd144b309086c92cd1642ab9: FlushDeltaMemStoresOp(94839290fa604b5ca2b76d3e2431a44f) complete. Timing: real 0.011s	user 0.010s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4259,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:13.423795 14888 maintenance_manager.cc:419] P 6a0ebdeefd144b309086c92cd1642ab9: Scheduling MajorDeltaCompactionOp(94839290fa604b5ca2b76d3e2431a44f): perf score=1.000000
I20260812 06:19:13.604601 14794 maintenance_manager.cc:643] P 6a0ebdeefd144b309086c92cd1642ab9: MajorDeltaCompactionOp(94839290fa604b5ca2b76d3e2431a44f) complete. Timing: real 0.181s	user 0.113s	sys 0.060s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774690,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":303,"lbm_read_time_us":13252,"lbm_reads_lt_1ms":572,"lbm_write_time_us":29372,"lbm_writes_lt_1ms":543,"mutex_wait_us":45,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":10240,"update_count":2500}
I20260812 06:19:13.605151 14888 maintenance_manager.cc:419] P 6a0ebdeefd144b309086c92cd1642ab9: Scheduling FlushDeltaMemStoresOp(94839290fa604b5ca2b76d3e2431a44f): perf score=14.095187
I20260812 06:19:13.666368 14794 maintenance_manager.cc:643] P 6a0ebdeefd144b309086c92cd1642ab9: FlushDeltaMemStoresOp(94839290fa604b5ca2b76d3e2431a44f) complete. Timing: real 0.061s	user 0.023s	sys 0.035s Metrics: {"bytes_written":16409904,"delete_count":0,"lbm_write_time_us":21528,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":402,"reinsert_count":0,"update_count":2000}
I20260812 06:19:13.667016 14888 maintenance_manager.cc:419] P 6a0ebdeefd144b309086c92cd1642ab9: Scheduling FlushDeltaMemStoresOp(94839290fa604b5ca2b76d3e2431a44f): perf score=2.188937
I20260812 06:19:13.678422 14794 maintenance_manager.cc:643] P 6a0ebdeefd144b309086c92cd1642ab9: FlushDeltaMemStoresOp(94839290fa604b5ca2b76d3e2431a44f) complete. Timing: real 0.011s	user 0.001s	sys 0.009s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4528,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:13.678911 14888 maintenance_manager.cc:419] P 6a0ebdeefd144b309086c92cd1642ab9: Scheduling MajorDeltaCompactionOp(94839290fa604b5ca2b76d3e2431a44f): perf score=1.000000
I20260812 06:19:13.869005 14794 maintenance_manager.cc:643] P 6a0ebdeefd144b309086c92cd1642ab9: MajorDeltaCompactionOp(94839290fa604b5ca2b76d3e2431a44f) complete. Timing: real 0.190s	user 0.125s	sys 0.053s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774691,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":142,"lbm_read_time_us":13109,"lbm_reads_lt_1ms":572,"lbm_write_time_us":29164,"lbm_writes_lt_1ms":543,"mutex_wait_us":23,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":50432,"update_count":2500}
I20260812 06:19:13.869704 14888 maintenance_manager.cc:419] P 6a0ebdeefd144b309086c92cd1642ab9: Scheduling FlushDeltaMemStoresOp(94839290fa604b5ca2b76d3e2431a44f): perf score=14.095187
I20260812 06:19:13.915707 14794 maintenance_manager.cc:643] P 6a0ebdeefd144b309086c92cd1642ab9: FlushDeltaMemStoresOp(94839290fa604b5ca2b76d3e2431a44f) complete. Timing: real 0.046s	user 0.028s	sys 0.016s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":21744,"lbm_writes_1-10_ms":2,"lbm_writes_lt_1ms":401,"reinsert_count":0,"update_count":2000}
I20260812 06:19:13.916244 14888 maintenance_manager.cc:419] P 6a0ebdeefd144b309086c92cd1642ab9: Scheduling FlushDeltaMemStoresOp(94839290fa604b5ca2b76d3e2431a44f): perf score=2.188937
I20260812 06:19:13.941725 14794 maintenance_manager.cc:643] P 6a0ebdeefd144b309086c92cd1642ab9: FlushDeltaMemStoresOp(94839290fa604b5ca2b76d3e2431a44f) complete. Timing: real 0.025s	user 0.007s	sys 0.015s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5809,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:13.942596 14888 maintenance_manager.cc:419] P 6a0ebdeefd144b309086c92cd1642ab9: Scheduling FlushMRSOp(94839290fa604b5ca2b76d3e2431a44f): perf score=1.000000
I20260812 06:19:13.979633 14794 maintenance_manager.cc:643] P 6a0ebdeefd144b309086c92cd1642ab9: FlushMRSOp(94839290fa604b5ca2b76d3e2431a44f) complete. Timing: real 0.037s	user 0.027s	sys 0.001s Metrics: {"bytes_written":1152512,"cfile_init":1,"dirs.queue_time_us":66,"dirs.run_cpu_time_us":240,"dirs.run_wall_time_us":1209,"drs_written":1,"lbm_read_time_us":46,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1472,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":28}
I20260812 06:19:13.980371 14888 maintenance_manager.cc:419] P 6a0ebdeefd144b309086c92cd1642ab9: Scheduling LogGCOp(94839290fa604b5ca2b76d3e2431a44f): free 117302835 bytes of WAL
I20260812 06:19:13.980647 14794 log_reader.cc:385] T 94839290fa604b5ca2b76d3e2431a44f: removed 12 log segments from log reader
I20260812 06:19:13.980720 14794 log.cc:1079] T 94839290fa604b5ca2b76d3e2431a44f P 6a0ebdeefd144b309086c92cd1642ab9: Deleting log segment in path: /tmp/dist-test-taskbgpkED/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515543839567-14326-0/minicluster-data/ts-0-root/wals/94839290fa604b5ca2b76d3e2431a44f/wal-000000028 (ops 133-137)
I20260812 06:19:13.980759 14794 log.cc:1079] T 94839290fa604b5ca2b76d3e2431a44f P 6a0ebdeefd144b309086c92cd1642ab9: Deleting log segment in path: /tmp/dist-test-taskbgpkED/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515543839567-14326-0/minicluster-data/ts-0-root/wals/94839290fa604b5ca2b76d3e2431a44f/wal-000000029 (ops 138-142)
I20260812 06:19:13.980789 14794 log.cc:1079] T 94839290fa604b5ca2b76d3e2431a44f P 6a0ebdeefd144b309086c92cd1642ab9: Deleting log segment in path: /tmp/dist-test-taskbgpkED/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515543839567-14326-0/minicluster-data/ts-0-root/wals/94839290fa604b5ca2b76d3e2431a44f/wal-000000030 (ops 143-147)
I20260812 06:19:13.980813 14794 log.cc:1079] T 94839290fa604b5ca2b76d3e2431a44f P 6a0ebdeefd144b309086c92cd1642ab9: Deleting log segment in path: /tmp/dist-test-taskbgpkED/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515543839567-14326-0/minicluster-data/ts-0-root/wals/94839290fa604b5ca2b76d3e2431a44f/wal-000000031 (ops 148-152)
I20260812 06:19:13.980846 14794 log.cc:1079] T 94839290fa604b5ca2b76d3e2431a44f P 6a0ebdeefd144b309086c92cd1642ab9: Deleting log segment in path: /tmp/dist-test-taskbgpkED/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515543839567-14326-0/minicluster-data/ts-0-root/wals/94839290fa604b5ca2b76d3e2431a44f/wal-000000032 (ops 153-157)
I20260812 06:19:13.980880 14794 log.cc:1079] T 94839290fa604b5ca2b76d3e2431a44f P 6a0ebdeefd144b309086c92cd1642ab9: Deleting log segment in path: /tmp/dist-test-taskbgpkED/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515543839567-14326-0/minicluster-data/ts-0-root/wals/94839290fa604b5ca2b76d3e2431a44f/wal-000000033 (ops 158-162)
I20260812 06:19:13.980909 14794 log.cc:1079] T 94839290fa604b5ca2b76d3e2431a44f P 6a0ebdeefd144b309086c92cd1642ab9: Deleting log segment in path: /tmp/dist-test-taskbgpkED/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515543839567-14326-0/minicluster-data/ts-0-root/wals/94839290fa604b5ca2b76d3e2431a44f/wal-000000034 (ops 163-166)
I20260812 06:19:13.980954 14794 log.cc:1079] T 94839290fa604b5ca2b76d3e2431a44f P 6a0ebdeefd144b309086c92cd1642ab9: Deleting log segment in path: /tmp/dist-test-taskbgpkED/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515543839567-14326-0/minicluster-data/ts-0-root/wals/94839290fa604b5ca2b76d3e2431a44f/wal-000000035 (ops 167-171)
I20260812 06:19:13.980978 14794 log.cc:1079] T 94839290fa604b5ca2b76d3e2431a44f P 6a0ebdeefd144b309086c92cd1642ab9: Deleting log segment in path: /tmp/dist-test-taskbgpkED/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515543839567-14326-0/minicluster-data/ts-0-root/wals/94839290fa604b5ca2b76d3e2431a44f/wal-000000036 (ops 172-176)
I20260812 06:19:13.981010 14794 log.cc:1079] T 94839290fa604b5ca2b76d3e2431a44f P 6a0ebdeefd144b309086c92cd1642ab9: Deleting log segment in path: /tmp/dist-test-taskbgpkED/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515543839567-14326-0/minicluster-data/ts-0-root/wals/94839290fa604b5ca2b76d3e2431a44f/wal-000000037 (ops 177-180)
I20260812 06:19:13.981043 14794 log.cc:1079] T 94839290fa604b5ca2b76d3e2431a44f P 6a0ebdeefd144b309086c92cd1642ab9: Deleting log segment in path: /tmp/dist-test-taskbgpkED/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515543839567-14326-0/minicluster-data/ts-0-root/wals/94839290fa604b5ca2b76d3e2431a44f/wal-000000038 (ops 181-185)
I20260812 06:19:13.981073 14794 log.cc:1079] T 94839290fa604b5ca2b76d3e2431a44f P 6a0ebdeefd144b309086c92cd1642ab9: Deleting log segment in path: /tmp/dist-test-taskbgpkED/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515543839567-14326-0/minicluster-data/ts-0-root/wals/94839290fa604b5ca2b76d3e2431a44f/wal-000000039 (ops 186-190)
I20260812 06:19:14.006657 14794 maintenance_manager.cc:643] P 6a0ebdeefd144b309086c92cd1642ab9: LogGCOp(94839290fa604b5ca2b76d3e2431a44f) complete. Timing: real 0.026s	user 0.003s	sys 0.019s Metrics: {}
I20260812 06:19:14.007124 14888 maintenance_manager.cc:419] P 6a0ebdeefd144b309086c92cd1642ab9: Scheduling FlushDeltaMemStoresOp(94839290fa604b5ca2b76d3e2431a44f): perf score=2.188937
I20260812 06:19:14.034910 14794 maintenance_manager.cc:643] P 6a0ebdeefd144b309086c92cd1642ab9: FlushDeltaMemStoresOp(94839290fa604b5ca2b76d3e2431a44f) complete. Timing: real 0.028s	user 0.006s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5559,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:14.035363 14888 maintenance_manager.cc:419] P 6a0ebdeefd144b309086c92cd1642ab9: Scheduling FlushDeltaMemStoresOp(94839290fa604b5ca2b76d3e2431a44f): perf score=2.188937
I20260812 06:19:14.045655 14794 maintenance_manager.cc:643] P 6a0ebdeefd144b309086c92cd1642ab9: FlushDeltaMemStoresOp(94839290fa604b5ca2b76d3e2431a44f) complete. Timing: real 0.010s	user 0.001s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3931,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:14.046113 14888 maintenance_manager.cc:419] P 6a0ebdeefd144b309086c92cd1642ab9: Scheduling MajorDeltaCompactionOp(94839290fa604b5ca2b76d3e2431a44f): perf score=1.000000
I20260812 06:19:14.234926 14326 heavy-update-compaction-itest.cc:229] Time spent updating: real 4.886s	user 1.859s	sys 0.166s
I20260812 06:19:14.270522 14794 maintenance_manager.cc:643] P 6a0ebdeefd144b309086c92cd1642ab9: MajorDeltaCompactionOp(94839290fa604b5ca2b76d3e2431a44f) complete. Timing: real 0.224s	user 0.142s	sys 0.079s Metrics: {"cfile_cache_miss":734,"cfile_cache_miss_bytes":32979750,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"lbm_read_time_us":15434,"lbm_reads_lt_1ms":770,"lbm_write_time_us":37687,"lbm_writes_lt_1ms":743,"peak_mem_usage":87969044,"reinsert_count":0,"spinlock_wait_cycles":3584,"update_count":3500}
I20260812 06:19:14.271116 14888 maintenance_manager.cc:419] P 6a0ebdeefd144b309086c92cd1642ab9: Scheduling FlushDeltaMemStoresOp(94839290fa604b5ca2b76d3e2431a44f): perf score=14.095187
I20260812 06:19:14.304041 14794 maintenance_manager.cc:643] P 6a0ebdeefd144b309086c92cd1642ab9: FlushDeltaMemStoresOp(94839290fa604b5ca2b76d3e2431a44f) complete. Timing: real 0.033s	user 0.022s	sys 0.009s Metrics: {"bytes_written":16409900,"delete_count":0,"lbm_write_time_us":15816,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:14.304607 14888 maintenance_manager.cc:419] P 6a0ebdeefd144b309086c92cd1642ab9: Scheduling MajorDeltaCompactionOp(94839290fa604b5ca2b76d3e2431a44f): perf score=1.000000
I20260812 06:19:14.333578 14326 heavy-update-compaction-itest.cc:265] Time spent scanning: real 0.098s	user 0.001s	sys 0.000s
I20260812 06:19:14.334100 14326 tablet_server.cc:179] TabletServer@127.13.253.129:0 shutting down...
I20260812 06:19:14.422884 14794 maintenance_manager.cc:643] P 6a0ebdeefd144b309086c92cd1642ab9: MajorDeltaCompactionOp(94839290fa604b5ca2b76d3e2431a44f) complete. Timing: real 0.118s	user 0.101s	sys 0.016s Metrics: {"cfile_cache_miss":431,"cfile_cache_miss_bytes":20672156,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":1,"delta_iterators_relevant":1,"dirs.queue_time_us":1501,"lbm_read_time_us":9430,"lbm_reads_lt_1ms":467,"lbm_write_time_us":22754,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":442,"mutex_wait_us":956,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":9600,"update_count":2000}
I20260812 06:19:14.423523 14326 ts_tablet_manager.cc:1507] Shutting down tablet manager...
I20260812 06:19:14.423767 14326 tablet_replica.cc:333] T 94839290fa604b5ca2b76d3e2431a44f P 6a0ebdeefd144b309086c92cd1642ab9: stopping tablet replica
I20260812 06:19:14.423909 14326 raft_consensus.cc:2243] T 94839290fa604b5ca2b76d3e2431a44f P 6a0ebdeefd144b309086c92cd1642ab9 [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:19:14.424073 14326 raft_consensus.cc:2272] T 94839290fa604b5ca2b76d3e2431a44f P 6a0ebdeefd144b309086c92cd1642ab9 [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:19:14.438345 14326 tablet_server.cc:196] TabletServer@127.13.253.129:0 shutdown complete.
I20260812 06:19:14.460753 14326 master.cc:562] Master@127.13.253.190:42851 shutting down...
I20260812 06:19:14.464738 14326 raft_consensus.cc:2243] T 00000000000000000000000000000000 P ce1fc8511df24bd1bc492d9706d27988 [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:19:14.464932 14326 raft_consensus.cc:2272] T 00000000000000000000000000000000 P ce1fc8511df24bd1bc492d9706d27988 [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:19:14.465022 14326 tablet_replica.cc:333] T 00000000000000000000000000000000 P ce1fc8511df24bd1bc492d9706d27988: stopping tablet replica
I20260812 06:19:14.477099 14326 master.cc:584] Master@127.13.253.190:42851 shutdown complete.
[       OK ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/1 (5415 ms)
[----------] 2 tests from EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy (10714 ms total)

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