[==========] 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:50.059203 21414 internal_mini_cluster.cc:156] Creating distributed mini masters. Addrs: 127.20.233.190:40095
I20260812 06:19:50.060166 21414 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:50.060738 21414 file_cache.cc:504] Constructed file cache file cache with capacity 419430
I20260812 06:19:50.066677 21414 server_base.cc:1061] running on GCE node
W20260812 06:19:50.066773 21421 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:50.067024 21420 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:50.067134 21423 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:50.067559 21414 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:19:50.067659 21414 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:50.067701 21414 hybrid_clock.cc:648] HybridClock initialized: now 1786515590067699 us; error 0 us; skew 500 ppm
I20260812 06:19:50.069326 21414 webserver.cc:533] Webserver started at http://127.20.233.190:38609/ using document root <none> and password file <none>
I20260812 06:19:50.069823 21414 fs_manager.cc:362] Metadata directory not provided
I20260812 06:19:50.069887 21414 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:19:50.070113 21414 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:19:50.071668 21414 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-tasktjZuXx/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515590048853-21414-0/minicluster-data/master-0-root/instance:
uuid: "57c4284664e240e089ee5a1a3ec02d75"
format_stamp: "Formatted at 2026-08-12 06:19:50 on dist-test-slave-k5rr"
I20260812 06:19:50.074926 21414 fs_manager.cc:696] Time spent creating directory manager: real 0.003s	user 0.005s	sys 0.000s
I20260812 06:19:50.076808 21431 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:50.077754 21414 fs_manager.cc:730] Time spent opening block manager: real 0.002s	user 0.002s	sys 0.000s
I20260812 06:19:50.077858 21414 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-tasktjZuXx/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515590048853-21414-0/minicluster-data/master-0-root
uuid: "57c4284664e240e089ee5a1a3ec02d75"
format_stamp: "Formatted at 2026-08-12 06:19:50 on dist-test-slave-k5rr"
I20260812 06:19:50.077947 21414 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-tasktjZuXx/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515590048853-21414-0/minicluster-data/master-0-root
metadata directory: /tmp/dist-test-tasktjZuXx/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515590048853-21414-0/minicluster-data/master-0-root
1 data directories: /tmp/dist-test-tasktjZuXx/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515590048853-21414-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:50.098546 21414 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:19:50.099148 21414 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:50.099298 21414 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:19:50.106869 21517 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.20.233.190:40095 every 8 connection(s)
I20260812 06:19:50.106874 21414 rpc_server.cc:307] RPC server started. Bound to: 127.20.233.190:40095
I20260812 06:19:50.109064 21519 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:50.114312 21519 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P 57c4284664e240e089ee5a1a3ec02d75: Bootstrap starting.
I20260812 06:19:50.116526 21519 tablet_bootstrap.cc:654] T 00000000000000000000000000000000 P 57c4284664e240e089ee5a1a3ec02d75: Neither blocks nor log segments found. Creating new log.
I20260812 06:19:50.117424 21519 log.cc:826] T 00000000000000000000000000000000 P 57c4284664e240e089ee5a1a3ec02d75: Log is configured to *not* fsync() on all Append() calls
I20260812 06:19:50.118993 21519 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P 57c4284664e240e089ee5a1a3ec02d75: No bootstrap required, opened a new log
I20260812 06:19:50.121618 21519 raft_consensus.cc:359] T 00000000000000000000000000000000 P 57c4284664e240e089ee5a1a3ec02d75 [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "57c4284664e240e089ee5a1a3ec02d75" member_type: VOTER }
I20260812 06:19:50.121773 21519 raft_consensus.cc:385] T 00000000000000000000000000000000 P 57c4284664e240e089ee5a1a3ec02d75 [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:19:50.121819 21519 raft_consensus.cc:740] T 00000000000000000000000000000000 P 57c4284664e240e089ee5a1a3ec02d75 [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: 57c4284664e240e089ee5a1a3ec02d75, State: Initialized, Role: FOLLOWER
I20260812 06:19:50.122326 21519 consensus_queue.cc:260] T 00000000000000000000000000000000 P 57c4284664e240e089ee5a1a3ec02d75 [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: "57c4284664e240e089ee5a1a3ec02d75" member_type: VOTER }
I20260812 06:19:50.122462 21519 raft_consensus.cc:399] T 00000000000000000000000000000000 P 57c4284664e240e089ee5a1a3ec02d75 [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:19:50.122506 21519 raft_consensus.cc:493] T 00000000000000000000000000000000 P 57c4284664e240e089ee5a1a3ec02d75 [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:19:50.122589 21519 raft_consensus.cc:3060] T 00000000000000000000000000000000 P 57c4284664e240e089ee5a1a3ec02d75 [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:19:50.123253 21519 raft_consensus.cc:515] T 00000000000000000000000000000000 P 57c4284664e240e089ee5a1a3ec02d75 [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "57c4284664e240e089ee5a1a3ec02d75" member_type: VOTER }
I20260812 06:19:50.123621 21519 leader_election.cc:304] T 00000000000000000000000000000000 P 57c4284664e240e089ee5a1a3ec02d75 [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: 57c4284664e240e089ee5a1a3ec02d75; no voters: 
I20260812 06:19:50.123889 21519 leader_election.cc:290] T 00000000000000000000000000000000 P 57c4284664e240e089ee5a1a3ec02d75 [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:19:50.123993 21524 raft_consensus.cc:2804] T 00000000000000000000000000000000 P 57c4284664e240e089ee5a1a3ec02d75 [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:19:50.124213 21524 raft_consensus.cc:697] T 00000000000000000000000000000000 P 57c4284664e240e089ee5a1a3ec02d75 [term 1 LEADER]: Becoming Leader. State: Replica: 57c4284664e240e089ee5a1a3ec02d75, State: Running, Role: LEADER
I20260812 06:19:50.124579 21524 consensus_queue.cc:237] T 00000000000000000000000000000000 P 57c4284664e240e089ee5a1a3ec02d75 [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: "57c4284664e240e089ee5a1a3ec02d75" member_type: VOTER }
I20260812 06:19:50.124764 21519 sys_catalog.cc:565] T 00000000000000000000000000000000 P 57c4284664e240e089ee5a1a3ec02d75 [sys.catalog]: configured and running, proceeding with master startup.
I20260812 06:19:50.126329 21527 sys_catalog.cc:455] T 00000000000000000000000000000000 P 57c4284664e240e089ee5a1a3ec02d75 [sys.catalog]: SysCatalogTable state changed. Reason: New leader 57c4284664e240e089ee5a1a3ec02d75. Latest consensus state: current_term: 1 leader_uuid: "57c4284664e240e089ee5a1a3ec02d75" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "57c4284664e240e089ee5a1a3ec02d75" member_type: VOTER } }
I20260812 06:19:50.126359 21526 sys_catalog.cc:455] T 00000000000000000000000000000000 P 57c4284664e240e089ee5a1a3ec02d75 [sys.catalog]: SysCatalogTable state changed. Reason: RaftConsensus started. Latest consensus state: current_term: 1 leader_uuid: "57c4284664e240e089ee5a1a3ec02d75" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "57c4284664e240e089ee5a1a3ec02d75" member_type: VOTER } }
I20260812 06:19:50.126466 21527 sys_catalog.cc:458] T 00000000000000000000000000000000 P 57c4284664e240e089ee5a1a3ec02d75 [sys.catalog]: This master's current role is: LEADER
I20260812 06:19:50.126466 21526 sys_catalog.cc:458] T 00000000000000000000000000000000 P 57c4284664e240e089ee5a1a3ec02d75 [sys.catalog]: This master's current role is: LEADER
I20260812 06:19:50.126814 21541 catalog_manager.cc:1511] Loading table and tablet metadata into memory...
I20260812 06:19:50.126896 21414 internal_mini_cluster.cc:184] Waiting to initialize catalog manager on master 0
I20260812 06:19:50.128939 21541 catalog_manager.cc:1520] Initializing Kudu cluster ID...
I20260812 06:19:50.133373 21541 catalog_manager.cc:1383] Generated new cluster ID: 2c4de245738440cbaef5c7b4425fd1f7
I20260812 06:19:50.133447 21541 catalog_manager.cc:1531] Initializing Kudu internal certificate authority...
I20260812 06:19:50.151916 21541 catalog_manager.cc:1406] Generated new certificate authority record
I20260812 06:19:50.152999 21541 catalog_manager.cc:1540] Loading token signing keys...
I20260812 06:19:50.163059 21541 catalog_manager.cc:6092] T 00000000000000000000000000000000 P 57c4284664e240e089ee5a1a3ec02d75: Generated new TSK 0
I20260812 06:19:50.163657 21541 catalog_manager.cc:1550] Initializing in-progress tserver states...
I20260812 06:19:50.191486 21414 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:19:50.193981 21551 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:50.194144 21552 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:50.194213 21554 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:50.194523 21414 server_base.cc:1061] running on GCE node
I20260812 06:19:50.194685 21414 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:19:50.194722 21414 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:50.194742 21414 hybrid_clock.cc:648] HybridClock initialized: now 1786515590194742 us; error 0 us; skew 500 ppm
I20260812 06:19:50.195608 21414 webserver.cc:533] Webserver started at http://127.20.233.129:35641/ using document root <none> and password file <none>
I20260812 06:19:50.195772 21414 fs_manager.cc:362] Metadata directory not provided
I20260812 06:19:50.195827 21414 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:19:50.195904 21414 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:19:50.196269 21414 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-tasktjZuXx/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515590048853-21414-0/minicluster-data/ts-0-root/instance:
uuid: "9eb42ed7820e4c6f9101a96004d4caba"
format_stamp: "Formatted at 2026-08-12 06:19:50 on dist-test-slave-k5rr"
I20260812 06:19:50.197799 21414 fs_manager.cc:696] Time spent creating directory manager: real 0.001s	user 0.002s	sys 0.000s
I20260812 06:19:50.198729 21565 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:50.198997 21414 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.001s	sys 0.000s
I20260812 06:19:50.199066 21414 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-tasktjZuXx/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515590048853-21414-0/minicluster-data/ts-0-root
uuid: "9eb42ed7820e4c6f9101a96004d4caba"
format_stamp: "Formatted at 2026-08-12 06:19:50 on dist-test-slave-k5rr"
I20260812 06:19:50.199137 21414 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-tasktjZuXx/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515590048853-21414-0/minicluster-data/ts-0-root
metadata directory: /tmp/dist-test-tasktjZuXx/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515590048853-21414-0/minicluster-data/ts-0-root
1 data directories: /tmp/dist-test-tasktjZuXx/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515590048853-21414-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:50.219091 21414 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:19:50.219533 21414 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:19:50.219998 21414 txn_system_client.cc:432] TxnSystemClient initialization is disabled...
I20260812 06:19:50.220817 21414 ts_tablet_manager.cc:585] Loaded tablet metadata (0 total tablets, 0 live tablets)
I20260812 06:19:50.220870 21414 ts_tablet_manager.cc:531] Time spent load tablet metadata: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:19:50.220918 21414 ts_tablet_manager.cc:616] Registered 0 tablets
I20260812 06:19:50.220948 21414 ts_tablet_manager.cc:595] Time spent register tablets: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:19:50.227506 21414 rpc_server.cc:307] RPC server started. Bound to: 127.20.233.129:40003
I20260812 06:19:50.227569 21681 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.20.233.129:40003 every 8 connection(s)
I20260812 06:19:50.237824 21682 heartbeater.cc:344] Connected to a master server at 127.20.233.190:40095
I20260812 06:19:50.238090 21682 heartbeater.cc:461] Registering TS with master...
I20260812 06:19:50.238555 21682 heartbeater.cc:507] Master 127.20.233.190:40095 requested a full tablet report, sending...
I20260812 06:19:50.239982 21455 ts_manager.cc:194] Registered new tserver with Master: 9eb42ed7820e4c6f9101a96004d4caba (127.20.233.129:40003)
I20260812 06:19:50.240381 21414 internal_mini_cluster.cc:371] 1 TS(s) registered with all masters after 0.012265715s
I20260812 06:19:50.241454 21455 master_service.cc:502] Signed X509 certificate for tserver {username='slave'} at 127.0.0.1:41838
I20260812 06:19:50.249750 21455 catalog_manager.cc:2283] Servicing CreateTable request from {username='slave'} at 127.0.0.1:41850:
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:50.263242 21614 tablet_service.cc:1511] Processing CreateTablet for tablet f3c3f004ad2d4f1bab826390386de2e2 (DEFAULT_TABLE table=heavy-update-compaction-test [id=329ba049777e4edc906a59e0bb3cce43]), partition=
I20260812 06:19:50.263664 21614 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet f3c3f004ad2d4f1bab826390386de2e2. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:19:50.266032 21705 tablet_bootstrap.cc:492] T f3c3f004ad2d4f1bab826390386de2e2 P 9eb42ed7820e4c6f9101a96004d4caba: Bootstrap starting.
I20260812 06:19:50.267284 21705 tablet_bootstrap.cc:654] T f3c3f004ad2d4f1bab826390386de2e2 P 9eb42ed7820e4c6f9101a96004d4caba: Neither blocks nor log segments found. Creating new log.
I20260812 06:19:50.268420 21705 tablet_bootstrap.cc:492] T f3c3f004ad2d4f1bab826390386de2e2 P 9eb42ed7820e4c6f9101a96004d4caba: No bootstrap required, opened a new log
I20260812 06:19:50.268518 21705 ts_tablet_manager.cc:1403] T f3c3f004ad2d4f1bab826390386de2e2 P 9eb42ed7820e4c6f9101a96004d4caba: Time spent bootstrapping tablet: real 0.003s	user 0.002s	sys 0.000s
I20260812 06:19:50.268932 21705 raft_consensus.cc:359] T f3c3f004ad2d4f1bab826390386de2e2 P 9eb42ed7820e4c6f9101a96004d4caba [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "9eb42ed7820e4c6f9101a96004d4caba" member_type: VOTER last_known_addr { host: "127.20.233.129" port: 40003 } }
I20260812 06:19:50.269075 21705 raft_consensus.cc:385] T f3c3f004ad2d4f1bab826390386de2e2 P 9eb42ed7820e4c6f9101a96004d4caba [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:19:50.269121 21705 raft_consensus.cc:740] T f3c3f004ad2d4f1bab826390386de2e2 P 9eb42ed7820e4c6f9101a96004d4caba [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: 9eb42ed7820e4c6f9101a96004d4caba, State: Initialized, Role: FOLLOWER
I20260812 06:19:50.269256 21705 consensus_queue.cc:260] T f3c3f004ad2d4f1bab826390386de2e2 P 9eb42ed7820e4c6f9101a96004d4caba [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: "9eb42ed7820e4c6f9101a96004d4caba" member_type: VOTER last_known_addr { host: "127.20.233.129" port: 40003 } }
I20260812 06:19:50.269351 21705 raft_consensus.cc:399] T f3c3f004ad2d4f1bab826390386de2e2 P 9eb42ed7820e4c6f9101a96004d4caba [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:19:50.269393 21705 raft_consensus.cc:493] T f3c3f004ad2d4f1bab826390386de2e2 P 9eb42ed7820e4c6f9101a96004d4caba [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:19:50.269441 21705 raft_consensus.cc:3060] T f3c3f004ad2d4f1bab826390386de2e2 P 9eb42ed7820e4c6f9101a96004d4caba [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:19:50.270120 21705 raft_consensus.cc:515] T f3c3f004ad2d4f1bab826390386de2e2 P 9eb42ed7820e4c6f9101a96004d4caba [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "9eb42ed7820e4c6f9101a96004d4caba" member_type: VOTER last_known_addr { host: "127.20.233.129" port: 40003 } }
I20260812 06:19:50.270251 21705 leader_election.cc:304] T f3c3f004ad2d4f1bab826390386de2e2 P 9eb42ed7820e4c6f9101a96004d4caba [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: 9eb42ed7820e4c6f9101a96004d4caba; no voters: 
I20260812 06:19:50.270429 21705 leader_election.cc:290] T f3c3f004ad2d4f1bab826390386de2e2 P 9eb42ed7820e4c6f9101a96004d4caba [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:19:50.270537 21711 raft_consensus.cc:2804] T f3c3f004ad2d4f1bab826390386de2e2 P 9eb42ed7820e4c6f9101a96004d4caba [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:19:50.270751 21705 ts_tablet_manager.cc:1434] T f3c3f004ad2d4f1bab826390386de2e2 P 9eb42ed7820e4c6f9101a96004d4caba: Time spent starting tablet: real 0.002s	user 0.002s	sys 0.000s
I20260812 06:19:50.270803 21711 raft_consensus.cc:697] T f3c3f004ad2d4f1bab826390386de2e2 P 9eb42ed7820e4c6f9101a96004d4caba [term 1 LEADER]: Becoming Leader. State: Replica: 9eb42ed7820e4c6f9101a96004d4caba, State: Running, Role: LEADER
I20260812 06:19:50.270974 21711 consensus_queue.cc:237] T f3c3f004ad2d4f1bab826390386de2e2 P 9eb42ed7820e4c6f9101a96004d4caba [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: "9eb42ed7820e4c6f9101a96004d4caba" member_type: VOTER last_known_addr { host: "127.20.233.129" port: 40003 } }
I20260812 06:19:50.271040 21682 heartbeater.cc:499] Master 127.20.233.190:40095 was elected leader, sending a full tablet report...
I20260812 06:19:50.273811 21455 catalog_manager.cc:5719] T f3c3f004ad2d4f1bab826390386de2e2 P 9eb42ed7820e4c6f9101a96004d4caba reported cstate change: term changed from 0 to 1, leader changed from <none> to 9eb42ed7820e4c6f9101a96004d4caba (127.20.233.129). New cstate: current_term: 1 leader_uuid: "9eb42ed7820e4c6f9101a96004d4caba" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "9eb42ed7820e4c6f9101a96004d4caba" member_type: VOTER last_known_addr { host: "127.20.233.129" port: 40003 } health_report { overall_health: HEALTHY } } }
I20260812 06:19:50.326894 21414 heavy-update-compaction-itest.cc:215] Time spent inserting: real 0.048s	user 0.013s	sys 0.008s
I20260812 06:19:50.478735 21683 maintenance_manager.cc:419] P 9eb42ed7820e4c6f9101a96004d4caba: Scheduling FlushMRSOp(f3c3f004ad2d4f1bab826390386de2e2): perf score=19.054940
I20260812 06:19:50.644805 21574 maintenance_manager.cc:643] P 9eb42ed7820e4c6f9101a96004d4caba: FlushMRSOp(f3c3f004ad2d4f1bab826390386de2e2) complete. Timing: real 0.166s	user 0.124s	sys 0.035s Metrics: {"bytes_written":12307490,"cfile_init":1,"compiler_manager_pool.queue_time_us":647,"delete_count":0,"dirs.queue_time_us":63,"dirs.run_cpu_time_us":199,"dirs.run_wall_time_us":685,"drs_written":1,"lbm_read_time_us":60,"lbm_reads_lt_1ms":4,"lbm_write_time_us":44384,"lbm_writes_lt_1ms":857,"peak_mem_usage":0,"reinsert_count":0,"rows_written":104,"thread_start_us":149,"threads_started":1,"update_count":1500}
I20260812 06:19:50.645983 21683 maintenance_manager.cc:419] P 9eb42ed7820e4c6f9101a96004d4caba: Scheduling UndoDeltaBlockGCOp(f3c3f004ad2d4f1bab826390386de2e2): 20513803 bytes on disk
I20260812 06:19:50.646505 21574 maintenance_manager.cc:643] P 9eb42ed7820e4c6f9101a96004d4caba: UndoDeltaBlockGCOp(f3c3f004ad2d4f1bab826390386de2e2) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":60,"lbm_reads_lt_1ms":4}
I20260812 06:19:50.646867 21683 maintenance_manager.cc:419] P 9eb42ed7820e4c6f9101a96004d4caba: Scheduling FlushDeltaMemStoresOp(f3c3f004ad2d4f1bab826390386de2e2): perf score=1.000000
I20260812 06:19:50.655736 21574 maintenance_manager.cc:643] P 9eb42ed7820e4c6f9101a96004d4caba: FlushDeltaMemStoresOp(f3c3f004ad2d4f1bab826390386de2e2) complete. Timing: real 0.009s	user 0.005s	sys 0.000s Metrics: {"bytes_written":1682181,"delete_count":0,"lbm_write_time_us":1969,"lbm_writes_lt_1ms":44,"reinsert_count":0,"update_count":205}
I20260812 06:19:50.656155 21683 maintenance_manager.cc:419] P 9eb42ed7820e4c6f9101a96004d4caba: Scheduling LogGCOp(f3c3f004ad2d4f1bab826390386de2e2): free 20743880 bytes of WAL
I20260812 06:19:50.656538 21574 log_reader.cc:385] T f3c3f004ad2d4f1bab826390386de2e2: removed 2 log segments from log reader
I20260812 06:19:50.656669 21574 log.cc:1079] T f3c3f004ad2d4f1bab826390386de2e2 P 9eb42ed7820e4c6f9101a96004d4caba: Deleting log segment in path: /tmp/dist-test-tasktjZuXx/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515590048853-21414-0/minicluster-data/ts-0-root/wals/f3c3f004ad2d4f1bab826390386de2e2/wal-000000001 (ops 1-6)
I20260812 06:19:50.656795 21574 log.cc:1079] T f3c3f004ad2d4f1bab826390386de2e2 P 9eb42ed7820e4c6f9101a96004d4caba: Deleting log segment in path: /tmp/dist-test-tasktjZuXx/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515590048853-21414-0/minicluster-data/ts-0-root/wals/f3c3f004ad2d4f1bab826390386de2e2/wal-000000002 (ops 7-11)
I20260812 06:19:50.661734 21574 maintenance_manager.cc:643] P 9eb42ed7820e4c6f9101a96004d4caba: LogGCOp(f3c3f004ad2d4f1bab826390386de2e2) complete. Timing: real 0.005s	user 0.000s	sys 0.005s Metrics: {}
I20260812 06:19:50.662065 21683 maintenance_manager.cc:419] P 9eb42ed7820e4c6f9101a96004d4caba: Scheduling FlushDeltaMemStoresOp(f3c3f004ad2d4f1bab826390386de2e2): perf score=1.196750
I20260812 06:19:50.670640 21574 maintenance_manager.cc:643] P 9eb42ed7820e4c6f9101a96004d4caba: FlushDeltaMemStoresOp(f3c3f004ad2d4f1bab826390386de2e2) complete. Timing: real 0.008s	user 0.004s	sys 0.003s Metrics: {"bytes_written":2420629,"delete_count":0,"lbm_write_time_us":2907,"lbm_writes_lt_1ms":62,"reinsert_count":0,"update_count":295}
I20260812 06:19:50.670979 21683 maintenance_manager.cc:419] P 9eb42ed7820e4c6f9101a96004d4caba: Scheduling MajorDeltaCompactionOp(f3c3f004ad2d4f1bab826390386de2e2): perf score=1.000000
I20260812 06:19:50.817900 21574 maintenance_manager.cc:643] P 9eb42ed7820e4c6f9101a96004d4caba: MajorDeltaCompactionOp(f3c3f004ad2d4f1bab826390386de2e2) complete. Timing: real 0.147s	user 0.113s	sys 0.028s Metrics: {"cfile_cache_miss":433,"cfile_cache_miss_bytes":20672301,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":825,"lbm_read_time_us":9582,"lbm_reads_lt_1ms":469,"lbm_write_time_us":20880,"lbm_writes_lt_1ms":443,"peak_mem_usage":50689328,"reinsert_count":0,"thread_start_us":283,"threads_started":5,"update_count":2000}
I20260812 06:19:50.818369 21683 maintenance_manager.cc:419] P 9eb42ed7820e4c6f9101a96004d4caba: Scheduling FlushDeltaMemStoresOp(f3c3f004ad2d4f1bab826390386de2e2): perf score=10.126437
I20260812 06:19:50.862283 21574 maintenance_manager.cc:643] P 9eb42ed7820e4c6f9101a96004d4caba: FlushDeltaMemStoresOp(f3c3f004ad2d4f1bab826390386de2e2) complete. Timing: real 0.044s	user 0.012s	sys 0.024s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":17358,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":302,"reinsert_count":0,"update_count":1500}
I20260812 06:19:50.862788 21683 maintenance_manager.cc:419] P 9eb42ed7820e4c6f9101a96004d4caba: Scheduling FlushDeltaMemStoresOp(f3c3f004ad2d4f1bab826390386de2e2): perf score=2.188937
I20260812 06:19:50.878123 21574 maintenance_manager.cc:643] P 9eb42ed7820e4c6f9101a96004d4caba: FlushDeltaMemStoresOp(f3c3f004ad2d4f1bab826390386de2e2) complete. Timing: real 0.015s	user 0.005s	sys 0.010s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5620,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:50.878553 21683 maintenance_manager.cc:419] P 9eb42ed7820e4c6f9101a96004d4caba: Scheduling MajorDeltaCompactionOp(f3c3f004ad2d4f1bab826390386de2e2): perf score=1.000000
I20260812 06:19:51.007438 21574 maintenance_manager.cc:643] P 9eb42ed7820e4c6f9101a96004d4caba: MajorDeltaCompactionOp(f3c3f004ad2d4f1bab826390386de2e2) complete. Timing: real 0.129s	user 0.100s	sys 0.028s 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":1838,"lbm_read_time_us":8023,"lbm_reads_lt_1ms":472,"lbm_write_time_us":25815,"lbm_writes_lt_1ms":443,"mutex_wait_us":593,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":2432,"update_count":2000}
I20260812 06:19:51.008028 21683 maintenance_manager.cc:419] P 9eb42ed7820e4c6f9101a96004d4caba: Scheduling FlushDeltaMemStoresOp(f3c3f004ad2d4f1bab826390386de2e2): perf score=10.126437
I20260812 06:19:51.054185 21574 maintenance_manager.cc:643] P 9eb42ed7820e4c6f9101a96004d4caba: FlushDeltaMemStoresOp(f3c3f004ad2d4f1bab826390386de2e2) complete. Timing: real 0.046s	user 0.028s	sys 0.012s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":17853,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:19:51.054673 21683 maintenance_manager.cc:419] P 9eb42ed7820e4c6f9101a96004d4caba: Scheduling FlushDeltaMemStoresOp(f3c3f004ad2d4f1bab826390386de2e2): perf score=2.188937
I20260812 06:19:51.066334 21574 maintenance_manager.cc:643] P 9eb42ed7820e4c6f9101a96004d4caba: FlushDeltaMemStoresOp(f3c3f004ad2d4f1bab826390386de2e2) complete. Timing: real 0.011s	user 0.009s	sys 0.001s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3918,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:51.066943 21683 maintenance_manager.cc:419] P 9eb42ed7820e4c6f9101a96004d4caba: Scheduling MajorDeltaCompactionOp(f3c3f004ad2d4f1bab826390386de2e2): perf score=1.000000
I20260812 06:19:51.182176 21574 maintenance_manager.cc:643] P 9eb42ed7820e4c6f9101a96004d4caba: MajorDeltaCompactionOp(f3c3f004ad2d4f1bab826390386de2e2) complete. Timing: real 0.115s	user 0.098s	sys 0.017s 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":240,"lbm_read_time_us":7154,"lbm_reads_lt_1ms":472,"lbm_write_time_us":23393,"lbm_writes_lt_1ms":443,"mutex_wait_us":51,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":8320,"update_count":2000}
I20260812 06:19:51.182624 21683 maintenance_manager.cc:419] P 9eb42ed7820e4c6f9101a96004d4caba: Scheduling FlushDeltaMemStoresOp(f3c3f004ad2d4f1bab826390386de2e2): perf score=10.126437
I20260812 06:19:51.232266 21574 maintenance_manager.cc:643] P 9eb42ed7820e4c6f9101a96004d4caba: FlushDeltaMemStoresOp(f3c3f004ad2d4f1bab826390386de2e2) complete. Timing: real 0.049s	user 0.023s	sys 0.015s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":15299,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:19:51.232836 21683 maintenance_manager.cc:419] P 9eb42ed7820e4c6f9101a96004d4caba: Scheduling FlushDeltaMemStoresOp(f3c3f004ad2d4f1bab826390386de2e2): perf score=2.188937
I20260812 06:19:51.242799 21574 maintenance_manager.cc:643] P 9eb42ed7820e4c6f9101a96004d4caba: FlushDeltaMemStoresOp(f3c3f004ad2d4f1bab826390386de2e2) complete. Timing: real 0.010s	user 0.004s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3616,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:51.243216 21683 maintenance_manager.cc:419] P 9eb42ed7820e4c6f9101a96004d4caba: Scheduling MajorDeltaCompactionOp(f3c3f004ad2d4f1bab826390386de2e2): perf score=1.000000
I20260812 06:19:51.392416 21574 maintenance_manager.cc:643] P 9eb42ed7820e4c6f9101a96004d4caba: MajorDeltaCompactionOp(f3c3f004ad2d4f1bab826390386de2e2) complete. Timing: real 0.149s	user 0.097s	sys 0.052s 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":196,"lbm_read_time_us":11201,"lbm_reads_lt_1ms":472,"lbm_write_time_us":26780,"lbm_writes_lt_1ms":443,"mutex_wait_us":73,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":768,"update_count":2000}
I20260812 06:19:51.393049 21683 maintenance_manager.cc:419] P 9eb42ed7820e4c6f9101a96004d4caba: Scheduling FlushDeltaMemStoresOp(f3c3f004ad2d4f1bab826390386de2e2): perf score=10.126437
I20260812 06:19:51.431764 21574 maintenance_manager.cc:643] P 9eb42ed7820e4c6f9101a96004d4caba: FlushDeltaMemStoresOp(f3c3f004ad2d4f1bab826390386de2e2) complete. Timing: real 0.039s	user 0.021s	sys 0.012s Metrics: {"bytes_written":12307494,"delete_count":0,"lbm_write_time_us":15280,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:19:51.432256 21683 maintenance_manager.cc:419] P 9eb42ed7820e4c6f9101a96004d4caba: Scheduling FlushDeltaMemStoresOp(f3c3f004ad2d4f1bab826390386de2e2): perf score=2.188937
I20260812 06:19:51.448385 21574 maintenance_manager.cc:643] P 9eb42ed7820e4c6f9101a96004d4caba: FlushDeltaMemStoresOp(f3c3f004ad2d4f1bab826390386de2e2) complete. Timing: real 0.016s	user 0.006s	sys 0.007s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6069,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:51.449057 21683 maintenance_manager.cc:419] P 9eb42ed7820e4c6f9101a96004d4caba: Scheduling MajorDeltaCompactionOp(f3c3f004ad2d4f1bab826390386de2e2): perf score=1.000000
I20260812 06:19:51.575940 21574 maintenance_manager.cc:643] P 9eb42ed7820e4c6f9101a96004d4caba: MajorDeltaCompactionOp(f3c3f004ad2d4f1bab826390386de2e2) complete. Timing: real 0.127s	user 0.113s	sys 0.013s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672281,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":871,"lbm_read_time_us":9718,"lbm_reads_lt_1ms":472,"lbm_write_time_us":22380,"lbm_writes_lt_1ms":443,"mutex_wait_us":80,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":10240,"update_count":2000}
I20260812 06:19:51.576453 21683 maintenance_manager.cc:419] P 9eb42ed7820e4c6f9101a96004d4caba: Scheduling FlushDeltaMemStoresOp(f3c3f004ad2d4f1bab826390386de2e2): perf score=10.126437
I20260812 06:19:51.614688 21574 maintenance_manager.cc:643] P 9eb42ed7820e4c6f9101a96004d4caba: FlushDeltaMemStoresOp(f3c3f004ad2d4f1bab826390386de2e2) complete. Timing: real 0.038s	user 0.029s	sys 0.004s Metrics: {"bytes_written":12307489,"delete_count":0,"lbm_write_time_us":14369,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:19:51.615257 21683 maintenance_manager.cc:419] P 9eb42ed7820e4c6f9101a96004d4caba: Scheduling FlushDeltaMemStoresOp(f3c3f004ad2d4f1bab826390386de2e2): perf score=2.188937
I20260812 06:19:51.632867 21574 maintenance_manager.cc:643] P 9eb42ed7820e4c6f9101a96004d4caba: FlushDeltaMemStoresOp(f3c3f004ad2d4f1bab826390386de2e2) complete. Timing: real 0.017s	user 0.008s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6969,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:51.633406 21683 maintenance_manager.cc:419] P 9eb42ed7820e4c6f9101a96004d4caba: Scheduling MajorDeltaCompactionOp(f3c3f004ad2d4f1bab826390386de2e2): perf score=1.000000
I20260812 06:19:51.757130 21574 maintenance_manager.cc:643] P 9eb42ed7820e4c6f9101a96004d4caba: MajorDeltaCompactionOp(f3c3f004ad2d4f1bab826390386de2e2) complete. Timing: real 0.124s	user 0.100s	sys 0.022s 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":846,"lbm_read_time_us":9724,"lbm_reads_lt_1ms":472,"lbm_write_time_us":23313,"lbm_writes_lt_1ms":443,"mutex_wait_us":65,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":3072,"update_count":2000}
I20260812 06:19:51.757723 21683 maintenance_manager.cc:419] P 9eb42ed7820e4c6f9101a96004d4caba: Scheduling FlushDeltaMemStoresOp(f3c3f004ad2d4f1bab826390386de2e2): perf score=10.126437
I20260812 06:19:51.809643 21574 maintenance_manager.cc:643] P 9eb42ed7820e4c6f9101a96004d4caba: FlushDeltaMemStoresOp(f3c3f004ad2d4f1bab826390386de2e2) complete. Timing: real 0.052s	user 0.029s	sys 0.019s Metrics: {"bytes_written":12307493,"delete_count":0,"lbm_write_time_us":19347,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:19:51.810114 21683 maintenance_manager.cc:419] P 9eb42ed7820e4c6f9101a96004d4caba: Scheduling FlushDeltaMemStoresOp(f3c3f004ad2d4f1bab826390386de2e2): perf score=2.188937
I20260812 06:19:51.819965 21574 maintenance_manager.cc:643] P 9eb42ed7820e4c6f9101a96004d4caba: FlushDeltaMemStoresOp(f3c3f004ad2d4f1bab826390386de2e2) complete. Timing: real 0.010s	user 0.004s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3693,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:51.820425 21683 maintenance_manager.cc:419] P 9eb42ed7820e4c6f9101a96004d4caba: Scheduling FlushMRSOp(f3c3f004ad2d4f1bab826390386de2e2): perf score=1.000000
I20260812 06:19:51.862787 21574 maintenance_manager.cc:643] P 9eb42ed7820e4c6f9101a96004d4caba: FlushMRSOp(f3c3f004ad2d4f1bab826390386de2e2) complete. Timing: real 0.042s	user 0.029s	sys 0.000s Metrics: {"bytes_written":1193503,"cfile_init":1,"dirs.queue_time_us":74,"dirs.run_cpu_time_us":171,"dirs.run_wall_time_us":1170,"drs_written":1,"lbm_read_time_us":43,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1343,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":29}
I20260812 06:19:51.863606 21683 maintenance_manager.cc:419] P 9eb42ed7820e4c6f9101a96004d4caba: Scheduling LogGCOp(f3c3f004ad2d4f1bab826390386de2e2): free 112692368 bytes of WAL
I20260812 06:19:51.863848 21574 log_reader.cc:385] T f3c3f004ad2d4f1bab826390386de2e2: removed 11 log segments from log reader
I20260812 06:19:51.863912 21574 log.cc:1079] T f3c3f004ad2d4f1bab826390386de2e2 P 9eb42ed7820e4c6f9101a96004d4caba: Deleting log segment in path: /tmp/dist-test-tasktjZuXx/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515590048853-21414-0/minicluster-data/ts-0-root/wals/f3c3f004ad2d4f1bab826390386de2e2/wal-000000003 (ops 12-16)
I20260812 06:19:51.863953 21574 log.cc:1079] T f3c3f004ad2d4f1bab826390386de2e2 P 9eb42ed7820e4c6f9101a96004d4caba: Deleting log segment in path: /tmp/dist-test-tasktjZuXx/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515590048853-21414-0/minicluster-data/ts-0-root/wals/f3c3f004ad2d4f1bab826390386de2e2/wal-000000004 (ops 17-21)
I20260812 06:19:51.863986 21574 log.cc:1079] T f3c3f004ad2d4f1bab826390386de2e2 P 9eb42ed7820e4c6f9101a96004d4caba: Deleting log segment in path: /tmp/dist-test-tasktjZuXx/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515590048853-21414-0/minicluster-data/ts-0-root/wals/f3c3f004ad2d4f1bab826390386de2e2/wal-000000005 (ops 22-26)
I20260812 06:19:51.864012 21574 log.cc:1079] T f3c3f004ad2d4f1bab826390386de2e2 P 9eb42ed7820e4c6f9101a96004d4caba: Deleting log segment in path: /tmp/dist-test-tasktjZuXx/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515590048853-21414-0/minicluster-data/ts-0-root/wals/f3c3f004ad2d4f1bab826390386de2e2/wal-000000006 (ops 27-31)
I20260812 06:19:51.864040 21574 log.cc:1079] T f3c3f004ad2d4f1bab826390386de2e2 P 9eb42ed7820e4c6f9101a96004d4caba: Deleting log segment in path: /tmp/dist-test-tasktjZuXx/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515590048853-21414-0/minicluster-data/ts-0-root/wals/f3c3f004ad2d4f1bab826390386de2e2/wal-000000007 (ops 32-36)
I20260812 06:19:51.864068 21574 log.cc:1079] T f3c3f004ad2d4f1bab826390386de2e2 P 9eb42ed7820e4c6f9101a96004d4caba: Deleting log segment in path: /tmp/dist-test-tasktjZuXx/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515590048853-21414-0/minicluster-data/ts-0-root/wals/f3c3f004ad2d4f1bab826390386de2e2/wal-000000008 (ops 37-41)
I20260812 06:19:51.864095 21574 log.cc:1079] T f3c3f004ad2d4f1bab826390386de2e2 P 9eb42ed7820e4c6f9101a96004d4caba: Deleting log segment in path: /tmp/dist-test-tasktjZuXx/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515590048853-21414-0/minicluster-data/ts-0-root/wals/f3c3f004ad2d4f1bab826390386de2e2/wal-000000009 (ops 42-46)
I20260812 06:19:51.864125 21574 log.cc:1079] T f3c3f004ad2d4f1bab826390386de2e2 P 9eb42ed7820e4c6f9101a96004d4caba: Deleting log segment in path: /tmp/dist-test-tasktjZuXx/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515590048853-21414-0/minicluster-data/ts-0-root/wals/f3c3f004ad2d4f1bab826390386de2e2/wal-000000010 (ops 47-51)
I20260812 06:19:51.864157 21574 log.cc:1079] T f3c3f004ad2d4f1bab826390386de2e2 P 9eb42ed7820e4c6f9101a96004d4caba: Deleting log segment in path: /tmp/dist-test-tasktjZuXx/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515590048853-21414-0/minicluster-data/ts-0-root/wals/f3c3f004ad2d4f1bab826390386de2e2/wal-000000011 (ops 52-56)
I20260812 06:19:51.864187 21574 log.cc:1079] T f3c3f004ad2d4f1bab826390386de2e2 P 9eb42ed7820e4c6f9101a96004d4caba: Deleting log segment in path: /tmp/dist-test-tasktjZuXx/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515590048853-21414-0/minicluster-data/ts-0-root/wals/f3c3f004ad2d4f1bab826390386de2e2/wal-000000012 (ops 57-61)
I20260812 06:19:51.864214 21574 log.cc:1079] T f3c3f004ad2d4f1bab826390386de2e2 P 9eb42ed7820e4c6f9101a96004d4caba: Deleting log segment in path: /tmp/dist-test-tasktjZuXx/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515590048853-21414-0/minicluster-data/ts-0-root/wals/f3c3f004ad2d4f1bab826390386de2e2/wal-000000013 (ops 62-66)
I20260812 06:19:51.889142 21574 maintenance_manager.cc:643] P 9eb42ed7820e4c6f9101a96004d4caba: LogGCOp(f3c3f004ad2d4f1bab826390386de2e2) complete. Timing: real 0.025s	user 0.000s	sys 0.025s Metrics: {}
I20260812 06:19:51.889536 21683 maintenance_manager.cc:419] P 9eb42ed7820e4c6f9101a96004d4caba: Scheduling FlushDeltaMemStoresOp(f3c3f004ad2d4f1bab826390386de2e2): perf score=3.181125
I20260812 06:19:51.905858 21574 maintenance_manager.cc:643] P 9eb42ed7820e4c6f9101a96004d4caba: FlushDeltaMemStoresOp(f3c3f004ad2d4f1bab826390386de2e2) complete. Timing: real 0.016s	user 0.003s	sys 0.007s Metrics: {"bytes_written":4512900,"delete_count":0,"lbm_write_time_us":3802,"lbm_writes_lt_1ms":113,"reinsert_count":0,"update_count":550}
I20260812 06:19:51.906304 21683 maintenance_manager.cc:419] P 9eb42ed7820e4c6f9101a96004d4caba: Scheduling UndoDeltaBlockGCOp(f3c3f004ad2d4f1bab826390386de2e2): 462 bytes on disk
I20260812 06:19:51.906723 21574 maintenance_manager.cc:643] P 9eb42ed7820e4c6f9101a96004d4caba: UndoDeltaBlockGCOp(f3c3f004ad2d4f1bab826390386de2e2) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":52,"lbm_reads_lt_1ms":4}
I20260812 06:19:51.907167 21683 maintenance_manager.cc:419] P 9eb42ed7820e4c6f9101a96004d4caba: Scheduling FlushDeltaMemStoresOp(f3c3f004ad2d4f1bab826390386de2e2): perf score=2.188937
I20260812 06:19:51.915982 21574 maintenance_manager.cc:643] P 9eb42ed7820e4c6f9101a96004d4caba: FlushDeltaMemStoresOp(f3c3f004ad2d4f1bab826390386de2e2) complete. Timing: real 0.009s	user 0.004s	sys 0.003s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3161,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:19:51.916370 21683 maintenance_manager.cc:419] P 9eb42ed7820e4c6f9101a96004d4caba: Scheduling MajorDeltaCompactionOp(f3c3f004ad2d4f1bab826390386de2e2): perf score=1.000000
I20260812 06:19:52.094081 21574 maintenance_manager.cc:643] P 9eb42ed7820e4c6f9101a96004d4caba: MajorDeltaCompactionOp(f3c3f004ad2d4f1bab826390386de2e2) complete. Timing: real 0.178s	user 0.118s	sys 0.055s Metrics: {"cfile_cache_miss":634,"cfile_cache_miss_bytes":28877329,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":1142,"lbm_read_time_us":12087,"lbm_reads_lt_1ms":674,"lbm_write_time_us":27860,"lbm_writes_lt_1ms":643,"mutex_wait_us":328,"peak_mem_usage":75542472,"reinsert_count":0,"thread_start_us":70,"threads_started":1,"update_count":3000}
I20260812 06:19:52.094555 21683 maintenance_manager.cc:419] P 9eb42ed7820e4c6f9101a96004d4caba: Scheduling FlushDeltaMemStoresOp(f3c3f004ad2d4f1bab826390386de2e2): perf score=14.095187
I20260812 06:19:52.141163 21574 maintenance_manager.cc:643] P 9eb42ed7820e4c6f9101a96004d4caba: FlushDeltaMemStoresOp(f3c3f004ad2d4f1bab826390386de2e2) complete. Timing: real 0.046s	user 0.035s	sys 0.012s Metrics: {"bytes_written":16409904,"delete_count":0,"lbm_write_time_us":20820,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:52.141685 21683 maintenance_manager.cc:419] P 9eb42ed7820e4c6f9101a96004d4caba: Scheduling MajorDeltaCompactionOp(f3c3f004ad2d4f1bab826390386de2e2): perf score=1.000000
I20260812 06:19:52.278040 21574 maintenance_manager.cc:643] P 9eb42ed7820e4c6f9101a96004d4caba: MajorDeltaCompactionOp(f3c3f004ad2d4f1bab826390386de2e2) complete. Timing: real 0.136s	user 0.087s	sys 0.048s Metrics: {"cfile_cache_miss":431,"cfile_cache_miss_bytes":20672160,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":1,"delta_iterators_relevant":1,"dirs.queue_time_us":562,"lbm_read_time_us":8305,"lbm_reads_lt_1ms":467,"lbm_write_time_us":23098,"lbm_writes_lt_1ms":443,"mutex_wait_us":274,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":896,"update_count":2000}
I20260812 06:19:52.278694 21683 maintenance_manager.cc:419] P 9eb42ed7820e4c6f9101a96004d4caba: Scheduling FlushDeltaMemStoresOp(f3c3f004ad2d4f1bab826390386de2e2): perf score=10.126437
I20260812 06:19:52.310047 21574 maintenance_manager.cc:643] P 9eb42ed7820e4c6f9101a96004d4caba: FlushDeltaMemStoresOp(f3c3f004ad2d4f1bab826390386de2e2) complete. Timing: real 0.031s	user 0.010s	sys 0.020s Metrics: {"bytes_written":12430563,"delete_count":0,"lbm_write_time_us":13093,"lbm_writes_lt_1ms":306,"mutex_wait_us":75,"reinsert_count":0,"update_count":1515}
I20260812 06:19:52.310536 21683 maintenance_manager.cc:419] P 9eb42ed7820e4c6f9101a96004d4caba: Scheduling FlushDeltaMemStoresOp(f3c3f004ad2d4f1bab826390386de2e2): perf score=2.188937
I20260812 06:19:52.324604 21574 maintenance_manager.cc:643] P 9eb42ed7820e4c6f9101a96004d4caba: FlushDeltaMemStoresOp(f3c3f004ad2d4f1bab826390386de2e2) complete. Timing: real 0.014s	user 0.008s	sys 0.004s Metrics: {"bytes_written":3979584,"delete_count":0,"lbm_write_time_us":5557,"lbm_writes_lt_1ms":100,"reinsert_count":0,"update_count":485}
I20260812 06:19:52.325093 21683 maintenance_manager.cc:419] P 9eb42ed7820e4c6f9101a96004d4caba: Scheduling MajorDeltaCompactionOp(f3c3f004ad2d4f1bab826390386de2e2): perf score=1.000000
I20260812 06:19:52.457139 21574 maintenance_manager.cc:643] P 9eb42ed7820e4c6f9101a96004d4caba: MajorDeltaCompactionOp(f3c3f004ad2d4f1bab826390386de2e2) complete. Timing: real 0.132s	user 0.089s	sys 0.041s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672275,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":694,"lbm_read_time_us":8880,"lbm_reads_lt_1ms":472,"lbm_write_time_us":23827,"lbm_writes_lt_1ms":443,"mutex_wait_us":298,"peak_mem_usage":50689328,"reinsert_count":0,"update_count":2000}
I20260812 06:19:52.457736 21683 maintenance_manager.cc:419] P 9eb42ed7820e4c6f9101a96004d4caba: Scheduling FlushDeltaMemStoresOp(f3c3f004ad2d4f1bab826390386de2e2): perf score=10.126437
I20260812 06:19:52.495069 21574 maintenance_manager.cc:643] P 9eb42ed7820e4c6f9101a96004d4caba: FlushDeltaMemStoresOp(f3c3f004ad2d4f1bab826390386de2e2) complete. Timing: real 0.037s	user 0.017s	sys 0.012s Metrics: {"bytes_written":12307489,"delete_count":0,"lbm_write_time_us":13175,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:19:52.495576 21683 maintenance_manager.cc:419] P 9eb42ed7820e4c6f9101a96004d4caba: Scheduling FlushDeltaMemStoresOp(f3c3f004ad2d4f1bab826390386de2e2): perf score=2.188937
I20260812 06:19:52.510586 21574 maintenance_manager.cc:643] P 9eb42ed7820e4c6f9101a96004d4caba: FlushDeltaMemStoresOp(f3c3f004ad2d4f1bab826390386de2e2) complete. Timing: real 0.015s	user 0.009s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5408,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:52.511276 21683 maintenance_manager.cc:419] P 9eb42ed7820e4c6f9101a96004d4caba: Scheduling MajorDeltaCompactionOp(f3c3f004ad2d4f1bab826390386de2e2): perf score=1.000000
I20260812 06:19:52.626294 21574 maintenance_manager.cc:643] P 9eb42ed7820e4c6f9101a96004d4caba: MajorDeltaCompactionOp(f3c3f004ad2d4f1bab826390386de2e2) complete. Timing: real 0.115s	user 0.095s	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":324,"lbm_read_time_us":7881,"lbm_reads_lt_1ms":472,"lbm_write_time_us":21058,"lbm_writes_lt_1ms":443,"mutex_wait_us":32,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":5760,"update_count":2000}
I20260812 06:19:52.626832 21683 maintenance_manager.cc:419] P 9eb42ed7820e4c6f9101a96004d4caba: Scheduling FlushDeltaMemStoresOp(f3c3f004ad2d4f1bab826390386de2e2): perf score=10.126437
I20260812 06:19:52.664067 21574 maintenance_manager.cc:643] P 9eb42ed7820e4c6f9101a96004d4caba: FlushDeltaMemStoresOp(f3c3f004ad2d4f1bab826390386de2e2) complete. Timing: real 0.037s	user 0.016s	sys 0.012s Metrics: {"bytes_written":12307493,"delete_count":0,"lbm_write_time_us":13352,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:19:52.664582 21683 maintenance_manager.cc:419] P 9eb42ed7820e4c6f9101a96004d4caba: Scheduling FlushDeltaMemStoresOp(f3c3f004ad2d4f1bab826390386de2e2): perf score=2.188937
I20260812 06:19:52.674665 21574 maintenance_manager.cc:643] P 9eb42ed7820e4c6f9101a96004d4caba: FlushDeltaMemStoresOp(f3c3f004ad2d4f1bab826390386de2e2) complete. Timing: real 0.010s	user 0.004s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3735,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:52.675293 21683 maintenance_manager.cc:419] P 9eb42ed7820e4c6f9101a96004d4caba: Scheduling MajorDeltaCompactionOp(f3c3f004ad2d4f1bab826390386de2e2): perf score=1.000000
I20260812 06:19:52.787150 21574 maintenance_manager.cc:643] P 9eb42ed7820e4c6f9101a96004d4caba: MajorDeltaCompactionOp(f3c3f004ad2d4f1bab826390386de2e2) complete. Timing: real 0.112s	user 0.094s	sys 0.015s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672280,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":204,"lbm_read_time_us":9474,"lbm_reads_1-10_ms":1,"lbm_reads_lt_1ms":471,"lbm_write_time_us":20133,"lbm_writes_lt_1ms":443,"mutex_wait_us":44,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":38784,"update_count":2000}
I20260812 06:19:52.787719 21683 maintenance_manager.cc:419] P 9eb42ed7820e4c6f9101a96004d4caba: Scheduling FlushDeltaMemStoresOp(f3c3f004ad2d4f1bab826390386de2e2): perf score=10.126437
I20260812 06:19:52.830837 21574 maintenance_manager.cc:643] P 9eb42ed7820e4c6f9101a96004d4caba: FlushDeltaMemStoresOp(f3c3f004ad2d4f1bab826390386de2e2) complete. Timing: real 0.043s	user 0.020s	sys 0.015s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":13600,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:19:52.831429 21683 maintenance_manager.cc:419] P 9eb42ed7820e4c6f9101a96004d4caba: Scheduling FlushDeltaMemStoresOp(f3c3f004ad2d4f1bab826390386de2e2): perf score=2.188937
I20260812 06:19:52.841389 21574 maintenance_manager.cc:643] P 9eb42ed7820e4c6f9101a96004d4caba: FlushDeltaMemStoresOp(f3c3f004ad2d4f1bab826390386de2e2) complete. Timing: real 0.010s	user 0.005s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3679,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:52.841814 21683 maintenance_manager.cc:419] P 9eb42ed7820e4c6f9101a96004d4caba: Scheduling MajorDeltaCompactionOp(f3c3f004ad2d4f1bab826390386de2e2): perf score=1.000000
I20260812 06:19:52.988569 21574 maintenance_manager.cc:643] P 9eb42ed7820e4c6f9101a96004d4caba: MajorDeltaCompactionOp(f3c3f004ad2d4f1bab826390386de2e2) complete. Timing: real 0.147s	user 0.087s	sys 0.053s 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":868,"lbm_read_time_us":10712,"lbm_reads_lt_1ms":472,"lbm_write_time_us":22267,"lbm_writes_lt_1ms":443,"mutex_wait_us":40,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":1664,"update_count":2000}
I20260812 06:19:52.989276 21683 maintenance_manager.cc:419] P 9eb42ed7820e4c6f9101a96004d4caba: Scheduling FlushDeltaMemStoresOp(f3c3f004ad2d4f1bab826390386de2e2): perf score=11.118625
I20260812 06:19:53.026880 21574 maintenance_manager.cc:643] P 9eb42ed7820e4c6f9101a96004d4caba: FlushDeltaMemStoresOp(f3c3f004ad2d4f1bab826390386de2e2) complete. Timing: real 0.037s	user 0.020s	sys 0.016s Metrics: {"bytes_written":12717735,"delete_count":0,"lbm_write_time_us":15453,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:19:53.027602 21683 maintenance_manager.cc:419] P 9eb42ed7820e4c6f9101a96004d4caba: Scheduling FlushDeltaMemStoresOp(f3c3f004ad2d4f1bab826390386de2e2): perf score=2.188937
I20260812 06:19:53.039664 21574 maintenance_manager.cc:643] P 9eb42ed7820e4c6f9101a96004d4caba: FlushDeltaMemStoresOp(f3c3f004ad2d4f1bab826390386de2e2) complete. Timing: real 0.012s	user 0.007s	sys 0.003s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":4394,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:19:53.040194 21683 maintenance_manager.cc:419] P 9eb42ed7820e4c6f9101a96004d4caba: Scheduling MajorDeltaCompactionOp(f3c3f004ad2d4f1bab826390386de2e2): perf score=1.000000
I20260812 06:19:53.166579 21574 maintenance_manager.cc:643] P 9eb42ed7820e4c6f9101a96004d4caba: MajorDeltaCompactionOp(f3c3f004ad2d4f1bab826390386de2e2) complete. Timing: real 0.126s	user 0.109s	sys 0.016s 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":330,"lbm_read_time_us":8797,"lbm_reads_lt_1ms":464,"lbm_write_time_us":24456,"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:53.167408 21683 maintenance_manager.cc:419] P 9eb42ed7820e4c6f9101a96004d4caba: Scheduling FlushDeltaMemStoresOp(f3c3f004ad2d4f1bab826390386de2e2): perf score=10.126437
I20260812 06:19:53.197418 21574 maintenance_manager.cc:643] P 9eb42ed7820e4c6f9101a96004d4caba: FlushDeltaMemStoresOp(f3c3f004ad2d4f1bab826390386de2e2) complete. Timing: real 0.030s	user 0.022s	sys 0.007s Metrics: {"bytes_written":12307492,"delete_count":0,"lbm_write_time_us":12481,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:19:53.197922 21683 maintenance_manager.cc:419] P 9eb42ed7820e4c6f9101a96004d4caba: Scheduling FlushDeltaMemStoresOp(f3c3f004ad2d4f1bab826390386de2e2): perf score=2.188937
I20260812 06:19:53.212806 21574 maintenance_manager.cc:643] P 9eb42ed7820e4c6f9101a96004d4caba: FlushDeltaMemStoresOp(f3c3f004ad2d4f1bab826390386de2e2) complete. Timing: real 0.015s	user 0.008s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5330,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:53.213446 21683 maintenance_manager.cc:419] P 9eb42ed7820e4c6f9101a96004d4caba: Scheduling FlushMRSOp(f3c3f004ad2d4f1bab826390386de2e2): perf score=1.000000
I20260812 06:19:53.242031 21574 maintenance_manager.cc:643] P 9eb42ed7820e4c6f9101a96004d4caba: FlushMRSOp(f3c3f004ad2d4f1bab826390386de2e2) complete. Timing: real 0.028s	user 0.023s	sys 0.005s Metrics: {"bytes_written":1234479,"cfile_init":1,"dirs.queue_time_us":56,"dirs.run_cpu_time_us":189,"dirs.run_wall_time_us":1407,"drs_written":1,"lbm_read_time_us":52,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1615,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":30}
I20260812 06:19:53.242784 21683 maintenance_manager.cc:419] P 9eb42ed7820e4c6f9101a96004d4caba: Scheduling LogGCOp(f3c3f004ad2d4f1bab826390386de2e2): free 124257249 bytes of WAL
I20260812 06:19:53.243038 21574 log_reader.cc:385] T f3c3f004ad2d4f1bab826390386de2e2: removed 12 log segments from log reader
I20260812 06:19:53.243100 21574 log.cc:1079] T f3c3f004ad2d4f1bab826390386de2e2 P 9eb42ed7820e4c6f9101a96004d4caba: Deleting log segment in path: /tmp/dist-test-tasktjZuXx/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515590048853-21414-0/minicluster-data/ts-0-root/wals/f3c3f004ad2d4f1bab826390386de2e2/wal-000000014 (ops 67-71)
I20260812 06:19:53.243147 21574 log.cc:1079] T f3c3f004ad2d4f1bab826390386de2e2 P 9eb42ed7820e4c6f9101a96004d4caba: Deleting log segment in path: /tmp/dist-test-tasktjZuXx/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515590048853-21414-0/minicluster-data/ts-0-root/wals/f3c3f004ad2d4f1bab826390386de2e2/wal-000000015 (ops 72-76)
I20260812 06:19:53.243181 21574 log.cc:1079] T f3c3f004ad2d4f1bab826390386de2e2 P 9eb42ed7820e4c6f9101a96004d4caba: Deleting log segment in path: /tmp/dist-test-tasktjZuXx/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515590048853-21414-0/minicluster-data/ts-0-root/wals/f3c3f004ad2d4f1bab826390386de2e2/wal-000000016 (ops 77-81)
I20260812 06:19:53.243203 21574 log.cc:1079] T f3c3f004ad2d4f1bab826390386de2e2 P 9eb42ed7820e4c6f9101a96004d4caba: Deleting log segment in path: /tmp/dist-test-tasktjZuXx/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515590048853-21414-0/minicluster-data/ts-0-root/wals/f3c3f004ad2d4f1bab826390386de2e2/wal-000000017 (ops 82-86)
I20260812 06:19:53.243232 21574 log.cc:1079] T f3c3f004ad2d4f1bab826390386de2e2 P 9eb42ed7820e4c6f9101a96004d4caba: Deleting log segment in path: /tmp/dist-test-tasktjZuXx/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515590048853-21414-0/minicluster-data/ts-0-root/wals/f3c3f004ad2d4f1bab826390386de2e2/wal-000000018 (ops 87-91)
I20260812 06:19:53.243260 21574 log.cc:1079] T f3c3f004ad2d4f1bab826390386de2e2 P 9eb42ed7820e4c6f9101a96004d4caba: Deleting log segment in path: /tmp/dist-test-tasktjZuXx/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515590048853-21414-0/minicluster-data/ts-0-root/wals/f3c3f004ad2d4f1bab826390386de2e2/wal-000000019 (ops 92-96)
I20260812 06:19:53.243292 21574 log.cc:1079] T f3c3f004ad2d4f1bab826390386de2e2 P 9eb42ed7820e4c6f9101a96004d4caba: Deleting log segment in path: /tmp/dist-test-tasktjZuXx/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515590048853-21414-0/minicluster-data/ts-0-root/wals/f3c3f004ad2d4f1bab826390386de2e2/wal-000000020 (ops 97-101)
I20260812 06:19:53.243322 21574 log.cc:1079] T f3c3f004ad2d4f1bab826390386de2e2 P 9eb42ed7820e4c6f9101a96004d4caba: Deleting log segment in path: /tmp/dist-test-tasktjZuXx/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515590048853-21414-0/minicluster-data/ts-0-root/wals/f3c3f004ad2d4f1bab826390386de2e2/wal-000000021 (ops 102-106)
I20260812 06:19:53.243350 21574 log.cc:1079] T f3c3f004ad2d4f1bab826390386de2e2 P 9eb42ed7820e4c6f9101a96004d4caba: Deleting log segment in path: /tmp/dist-test-tasktjZuXx/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515590048853-21414-0/minicluster-data/ts-0-root/wals/f3c3f004ad2d4f1bab826390386de2e2/wal-000000022 (ops 107-110)
I20260812 06:19:53.243377 21574 log.cc:1079] T f3c3f004ad2d4f1bab826390386de2e2 P 9eb42ed7820e4c6f9101a96004d4caba: Deleting log segment in path: /tmp/dist-test-tasktjZuXx/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515590048853-21414-0/minicluster-data/ts-0-root/wals/f3c3f004ad2d4f1bab826390386de2e2/wal-000000023 (ops 111-115)
I20260812 06:19:53.243414 21574 log.cc:1079] T f3c3f004ad2d4f1bab826390386de2e2 P 9eb42ed7820e4c6f9101a96004d4caba: Deleting log segment in path: /tmp/dist-test-tasktjZuXx/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515590048853-21414-0/minicluster-data/ts-0-root/wals/f3c3f004ad2d4f1bab826390386de2e2/wal-000000024 (ops 116-120)
I20260812 06:19:53.243450 21574 log.cc:1079] T f3c3f004ad2d4f1bab826390386de2e2 P 9eb42ed7820e4c6f9101a96004d4caba: Deleting log segment in path: /tmp/dist-test-tasktjZuXx/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515590048853-21414-0/minicluster-data/ts-0-root/wals/f3c3f004ad2d4f1bab826390386de2e2/wal-000000025 (ops 121-125)
I20260812 06:19:53.268778 21574 maintenance_manager.cc:643] P 9eb42ed7820e4c6f9101a96004d4caba: LogGCOp(f3c3f004ad2d4f1bab826390386de2e2) complete. Timing: real 0.026s	user 0.000s	sys 0.022s Metrics: {}
I20260812 06:19:53.269263 21683 maintenance_manager.cc:419] P 9eb42ed7820e4c6f9101a96004d4caba: Scheduling UndoDeltaBlockGCOp(f3c3f004ad2d4f1bab826390386de2e2): 473 bytes on disk
I20260812 06:19:53.269696 21574 maintenance_manager.cc:643] P 9eb42ed7820e4c6f9101a96004d4caba: UndoDeltaBlockGCOp(f3c3f004ad2d4f1bab826390386de2e2) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":50,"lbm_reads_lt_1ms":4}
I20260812 06:19:53.270264 21683 maintenance_manager.cc:419] P 9eb42ed7820e4c6f9101a96004d4caba: Scheduling FlushDeltaMemStoresOp(f3c3f004ad2d4f1bab826390386de2e2): perf score=3.181125
I20260812 06:19:53.281504 21574 maintenance_manager.cc:643] P 9eb42ed7820e4c6f9101a96004d4caba: FlushDeltaMemStoresOp(f3c3f004ad2d4f1bab826390386de2e2) complete. Timing: real 0.011s	user 0.002s	sys 0.008s Metrics: {"bytes_written":4512901,"delete_count":0,"lbm_write_time_us":4021,"lbm_writes_lt_1ms":113,"reinsert_count":0,"update_count":550}
I20260812 06:19:53.281929 21683 maintenance_manager.cc:419] P 9eb42ed7820e4c6f9101a96004d4caba: Scheduling FlushDeltaMemStoresOp(f3c3f004ad2d4f1bab826390386de2e2): perf score=2.188937
I20260812 06:19:53.295812 21574 maintenance_manager.cc:643] P 9eb42ed7820e4c6f9101a96004d4caba: FlushDeltaMemStoresOp(f3c3f004ad2d4f1bab826390386de2e2) complete. Timing: real 0.014s	user 0.007s	sys 0.004s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":4804,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:19:53.296413 21683 maintenance_manager.cc:419] P 9eb42ed7820e4c6f9101a96004d4caba: Scheduling MajorDeltaCompactionOp(f3c3f004ad2d4f1bab826390386de2e2): perf score=1.000000
I20260812 06:19:53.457181 21574 maintenance_manager.cc:643] P 9eb42ed7820e4c6f9101a96004d4caba: MajorDeltaCompactionOp(f3c3f004ad2d4f1bab826390386de2e2) complete. Timing: real 0.161s	user 0.117s	sys 0.036s Metrics: {"cfile_cache_miss":634,"cfile_cache_miss_bytes":28877329,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":205,"lbm_read_time_us":11580,"lbm_reads_lt_1ms":674,"lbm_write_time_us":29771,"lbm_writes_lt_1ms":643,"mutex_wait_us":76,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":10752,"thread_start_us":71,"threads_started":1,"update_count":3000}
I20260812 06:19:53.457698 21683 maintenance_manager.cc:419] P 9eb42ed7820e4c6f9101a96004d4caba: Scheduling FlushDeltaMemStoresOp(f3c3f004ad2d4f1bab826390386de2e2): perf score=14.095187
I20260812 06:19:53.503978 21574 maintenance_manager.cc:643] P 9eb42ed7820e4c6f9101a96004d4caba: FlushDeltaMemStoresOp(f3c3f004ad2d4f1bab826390386de2e2) complete. Timing: real 0.046s	user 0.038s	sys 0.002s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":18272,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:53.504519 21683 maintenance_manager.cc:419] P 9eb42ed7820e4c6f9101a96004d4caba: Scheduling FlushDeltaMemStoresOp(f3c3f004ad2d4f1bab826390386de2e2): perf score=2.188937
I20260812 06:19:53.519333 21574 maintenance_manager.cc:643] P 9eb42ed7820e4c6f9101a96004d4caba: FlushDeltaMemStoresOp(f3c3f004ad2d4f1bab826390386de2e2) complete. Timing: real 0.015s	user 0.008s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5334,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:53.519878 21683 maintenance_manager.cc:419] P 9eb42ed7820e4c6f9101a96004d4caba: Scheduling MajorDeltaCompactionOp(f3c3f004ad2d4f1bab826390386de2e2): perf score=1.000000
I20260812 06:19:53.665203 21574 maintenance_manager.cc:643] P 9eb42ed7820e4c6f9101a96004d4caba: MajorDeltaCompactionOp(f3c3f004ad2d4f1bab826390386de2e2) complete. Timing: real 0.145s	user 0.098s	sys 0.044s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774689,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":4044,"lbm_read_time_us":10244,"lbm_reads_lt_1ms":572,"lbm_write_time_us":29260,"lbm_writes_lt_1ms":543,"mutex_wait_us":3350,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":896,"update_count":2500}
I20260812 06:19:53.665840 21683 maintenance_manager.cc:419] P 9eb42ed7820e4c6f9101a96004d4caba: Scheduling FlushDeltaMemStoresOp(f3c3f004ad2d4f1bab826390386de2e2): perf score=11.118625
I20260812 06:19:53.699594 21574 maintenance_manager.cc:643] P 9eb42ed7820e4c6f9101a96004d4caba: FlushDeltaMemStoresOp(f3c3f004ad2d4f1bab826390386de2e2) complete. Timing: real 0.034s	user 0.025s	sys 0.004s Metrics: {"bytes_written":13210025,"delete_count":0,"lbm_write_time_us":13450,"lbm_writes_lt_1ms":325,"reinsert_count":0,"update_count":1610}
I20260812 06:19:53.700162 21683 maintenance_manager.cc:419] P 9eb42ed7820e4c6f9101a96004d4caba: Scheduling FlushDeltaMemStoresOp(f3c3f004ad2d4f1bab826390386de2e2): perf score=2.188937
I20260812 06:19:53.719031 21574 maintenance_manager.cc:643] P 9eb42ed7820e4c6f9101a96004d4caba: FlushDeltaMemStoresOp(f3c3f004ad2d4f1bab826390386de2e2) complete. Timing: real 0.019s	user 0.009s	sys 0.000s Metrics: {"bytes_written":3610359,"delete_count":0,"lbm_write_time_us":3915,"lbm_writes_lt_1ms":91,"reinsert_count":0,"spinlock_wait_cycles":1408,"update_count":440}
I20260812 06:19:53.719624 21683 maintenance_manager.cc:419] P 9eb42ed7820e4c6f9101a96004d4caba: Scheduling FlushDeltaMemStoresOp(f3c3f004ad2d4f1bab826390386de2e2): perf score=2.188937
I20260812 06:19:53.729584 21574 maintenance_manager.cc:643] P 9eb42ed7820e4c6f9101a96004d4caba: FlushDeltaMemStoresOp(f3c3f004ad2d4f1bab826390386de2e2) complete. Timing: real 0.010s	user 0.005s	sys 0.004s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3522,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:19:53.730201 21683 maintenance_manager.cc:419] P 9eb42ed7820e4c6f9101a96004d4caba: Scheduling MajorDeltaCompactionOp(f3c3f004ad2d4f1bab826390386de2e2): perf score=1.000000
I20260812 06:19:53.888228 21574 maintenance_manager.cc:643] P 9eb42ed7820e4c6f9101a96004d4caba: MajorDeltaCompactionOp(f3c3f004ad2d4f1bab826390386de2e2) complete. Timing: real 0.158s	user 0.088s	sys 0.051s Metrics: {"cfile_cache_miss":533,"cfile_cache_miss_bytes":24774789,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":976,"lbm_read_time_us":9028,"lbm_reads_lt_1ms":573,"lbm_write_time_us":28138,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":542,"mutex_wait_us":597,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":41344,"update_count":2500}
I20260812 06:19:53.888816 21683 maintenance_manager.cc:419] P 9eb42ed7820e4c6f9101a96004d4caba: Scheduling FlushDeltaMemStoresOp(f3c3f004ad2d4f1bab826390386de2e2): perf score=14.095187
I20260812 06:19:53.937680 21574 maintenance_manager.cc:643] P 9eb42ed7820e4c6f9101a96004d4caba: FlushDeltaMemStoresOp(f3c3f004ad2d4f1bab826390386de2e2) complete. Timing: real 0.049s	user 0.029s	sys 0.011s Metrics: {"bytes_written":16409910,"delete_count":0,"lbm_write_time_us":18087,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:53.938211 21683 maintenance_manager.cc:419] P 9eb42ed7820e4c6f9101a96004d4caba: Scheduling FlushDeltaMemStoresOp(f3c3f004ad2d4f1bab826390386de2e2): perf score=2.188937
I20260812 06:19:53.953697 21574 maintenance_manager.cc:643] P 9eb42ed7820e4c6f9101a96004d4caba: FlushDeltaMemStoresOp(f3c3f004ad2d4f1bab826390386de2e2) complete. Timing: real 0.015s	user 0.010s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5783,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:53.954342 21683 maintenance_manager.cc:419] P 9eb42ed7820e4c6f9101a96004d4caba: Scheduling MajorDeltaCompactionOp(f3c3f004ad2d4f1bab826390386de2e2): perf score=1.000000
I20260812 06:19:54.133355 21574 maintenance_manager.cc:643] P 9eb42ed7820e4c6f9101a96004d4caba: MajorDeltaCompactionOp(f3c3f004ad2d4f1bab826390386de2e2) complete. Timing: real 0.178s	user 0.129s	sys 0.040s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774697,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":338,"lbm_read_time_us":12249,"lbm_reads_lt_1ms":572,"lbm_write_time_us":28535,"lbm_writes_lt_1ms":543,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":2560,"update_count":2500}
I20260812 06:19:54.133886 21683 maintenance_manager.cc:419] P 9eb42ed7820e4c6f9101a96004d4caba: Scheduling FlushDeltaMemStoresOp(f3c3f004ad2d4f1bab826390386de2e2): perf score=14.095187
I20260812 06:19:54.179723 21574 maintenance_manager.cc:643] P 9eb42ed7820e4c6f9101a96004d4caba: FlushDeltaMemStoresOp(f3c3f004ad2d4f1bab826390386de2e2) complete. Timing: real 0.046s	user 0.030s	sys 0.013s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":20367,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:54.180286 21683 maintenance_manager.cc:419] P 9eb42ed7820e4c6f9101a96004d4caba: Scheduling MajorDeltaCompactionOp(f3c3f004ad2d4f1bab826390386de2e2): perf score=1.000000
I20260812 06:19:54.336884 21574 maintenance_manager.cc:643] P 9eb42ed7820e4c6f9101a96004d4caba: MajorDeltaCompactionOp(f3c3f004ad2d4f1bab826390386de2e2) complete. Timing: real 0.156s	user 0.086s	sys 0.055s Metrics: {"cfile_cache_miss":431,"cfile_cache_miss_bytes":20672158,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":1,"delta_iterators_relevant":1,"dirs.queue_time_us":7666,"lbm_read_time_us":9165,"lbm_reads_lt_1ms":463,"lbm_write_time_us":23026,"lbm_writes_lt_1ms":443,"mutex_wait_us":3566,"peak_mem_usage":50689328,"reinsert_count":0,"update_count":2000}
I20260812 06:19:54.337777 21683 maintenance_manager.cc:419] P 9eb42ed7820e4c6f9101a96004d4caba: Scheduling FlushDeltaMemStoresOp(f3c3f004ad2d4f1bab826390386de2e2): perf score=14.095187
I20260812 06:19:54.382951 21574 maintenance_manager.cc:643] P 9eb42ed7820e4c6f9101a96004d4caba: FlushDeltaMemStoresOp(f3c3f004ad2d4f1bab826390386de2e2) complete. Timing: real 0.045s	user 0.028s	sys 0.011s Metrics: {"bytes_written":16409904,"delete_count":0,"lbm_write_time_us":17601,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:54.383432 21683 maintenance_manager.cc:419] P 9eb42ed7820e4c6f9101a96004d4caba: Scheduling FlushDeltaMemStoresOp(f3c3f004ad2d4f1bab826390386de2e2): perf score=2.188937
I20260812 06:19:54.394456 21574 maintenance_manager.cc:643] P 9eb42ed7820e4c6f9101a96004d4caba: FlushDeltaMemStoresOp(f3c3f004ad2d4f1bab826390386de2e2) complete. Timing: real 0.011s	user 0.005s	sys 0.004s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":3825,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:54.394982 21683 maintenance_manager.cc:419] P 9eb42ed7820e4c6f9101a96004d4caba: Scheduling MajorDeltaCompactionOp(f3c3f004ad2d4f1bab826390386de2e2): perf score=1.000000
I20260812 06:19:54.579214 21574 maintenance_manager.cc:643] P 9eb42ed7820e4c6f9101a96004d4caba: MajorDeltaCompactionOp(f3c3f004ad2d4f1bab826390386de2e2) complete. Timing: real 0.184s	user 0.113s	sys 0.057s 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":601,"lbm_read_time_us":9811,"lbm_reads_lt_1ms":572,"lbm_write_time_us":27103,"lbm_writes_lt_1ms":543,"mutex_wait_us":296,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":1280,"update_count":2500}
I20260812 06:19:54.579772 21683 maintenance_manager.cc:419] P 9eb42ed7820e4c6f9101a96004d4caba: Scheduling FlushDeltaMemStoresOp(f3c3f004ad2d4f1bab826390386de2e2): perf score=14.095187
I20260812 06:19:54.626206 21574 maintenance_manager.cc:643] P 9eb42ed7820e4c6f9101a96004d4caba: FlushDeltaMemStoresOp(f3c3f004ad2d4f1bab826390386de2e2) complete. Timing: real 0.046s	user 0.019s	sys 0.023s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":19137,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:54.626766 21683 maintenance_manager.cc:419] P 9eb42ed7820e4c6f9101a96004d4caba: Scheduling FlushDeltaMemStoresOp(f3c3f004ad2d4f1bab826390386de2e2): perf score=2.188937
I20260812 06:19:54.641959 21574 maintenance_manager.cc:643] P 9eb42ed7820e4c6f9101a96004d4caba: FlushDeltaMemStoresOp(f3c3f004ad2d4f1bab826390386de2e2) complete. Timing: real 0.015s	user 0.004s	sys 0.010s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5525,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:54.642495 21683 maintenance_manager.cc:419] P 9eb42ed7820e4c6f9101a96004d4caba: Scheduling FlushMRSOp(f3c3f004ad2d4f1bab826390386de2e2): perf score=1.000000
I20260812 06:19:54.670972 21574 maintenance_manager.cc:643] P 9eb42ed7820e4c6f9101a96004d4caba: FlushMRSOp(f3c3f004ad2d4f1bab826390386de2e2) complete. Timing: real 0.028s	user 0.021s	sys 0.006s Metrics: {"bytes_written":1275447,"cfile_init":1,"dirs.queue_time_us":57,"dirs.run_cpu_time_us":168,"dirs.run_wall_time_us":1240,"drs_written":1,"lbm_read_time_us":54,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1666,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":31}
I20260812 06:19:54.671756 21683 maintenance_manager.cc:419] P 9eb42ed7820e4c6f9101a96004d4caba: Scheduling LogGCOp(f3c3f004ad2d4f1bab826390386de2e2): free 129320775 bytes of WAL
I20260812 06:19:54.672006 21574 log_reader.cc:385] T f3c3f004ad2d4f1bab826390386de2e2: removed 13 log segments from log reader
I20260812 06:19:54.672071 21574 log.cc:1079] T f3c3f004ad2d4f1bab826390386de2e2 P 9eb42ed7820e4c6f9101a96004d4caba: Deleting log segment in path: /tmp/dist-test-tasktjZuXx/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515590048853-21414-0/minicluster-data/ts-0-root/wals/f3c3f004ad2d4f1bab826390386de2e2/wal-000000026 (ops 126-130)
I20260812 06:19:54.672115 21574 log.cc:1079] T f3c3f004ad2d4f1bab826390386de2e2 P 9eb42ed7820e4c6f9101a96004d4caba: Deleting log segment in path: /tmp/dist-test-tasktjZuXx/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515590048853-21414-0/minicluster-data/ts-0-root/wals/f3c3f004ad2d4f1bab826390386de2e2/wal-000000027 (ops 131-135)
I20260812 06:19:54.672151 21574 log.cc:1079] T f3c3f004ad2d4f1bab826390386de2e2 P 9eb42ed7820e4c6f9101a96004d4caba: Deleting log segment in path: /tmp/dist-test-tasktjZuXx/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515590048853-21414-0/minicluster-data/ts-0-root/wals/f3c3f004ad2d4f1bab826390386de2e2/wal-000000028 (ops 136-140)
I20260812 06:19:54.672173 21574 log.cc:1079] T f3c3f004ad2d4f1bab826390386de2e2 P 9eb42ed7820e4c6f9101a96004d4caba: Deleting log segment in path: /tmp/dist-test-tasktjZuXx/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515590048853-21414-0/minicluster-data/ts-0-root/wals/f3c3f004ad2d4f1bab826390386de2e2/wal-000000029 (ops 141-144)
I20260812 06:19:54.672200 21574 log.cc:1079] T f3c3f004ad2d4f1bab826390386de2e2 P 9eb42ed7820e4c6f9101a96004d4caba: Deleting log segment in path: /tmp/dist-test-tasktjZuXx/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515590048853-21414-0/minicluster-data/ts-0-root/wals/f3c3f004ad2d4f1bab826390386de2e2/wal-000000030 (ops 145-149)
I20260812 06:19:54.672230 21574 log.cc:1079] T f3c3f004ad2d4f1bab826390386de2e2 P 9eb42ed7820e4c6f9101a96004d4caba: Deleting log segment in path: /tmp/dist-test-tasktjZuXx/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515590048853-21414-0/minicluster-data/ts-0-root/wals/f3c3f004ad2d4f1bab826390386de2e2/wal-000000031 (ops 150-154)
I20260812 06:19:54.672262 21574 log.cc:1079] T f3c3f004ad2d4f1bab826390386de2e2 P 9eb42ed7820e4c6f9101a96004d4caba: Deleting log segment in path: /tmp/dist-test-tasktjZuXx/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515590048853-21414-0/minicluster-data/ts-0-root/wals/f3c3f004ad2d4f1bab826390386de2e2/wal-000000032 (ops 155-159)
I20260812 06:19:54.672294 21574 log.cc:1079] T f3c3f004ad2d4f1bab826390386de2e2 P 9eb42ed7820e4c6f9101a96004d4caba: Deleting log segment in path: /tmp/dist-test-tasktjZuXx/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515590048853-21414-0/minicluster-data/ts-0-root/wals/f3c3f004ad2d4f1bab826390386de2e2/wal-000000033 (ops 160-164)
I20260812 06:19:54.672323 21574 log.cc:1079] T f3c3f004ad2d4f1bab826390386de2e2 P 9eb42ed7820e4c6f9101a96004d4caba: Deleting log segment in path: /tmp/dist-test-tasktjZuXx/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515590048853-21414-0/minicluster-data/ts-0-root/wals/f3c3f004ad2d4f1bab826390386de2e2/wal-000000034 (ops 165-168)
I20260812 06:19:54.672351 21574 log.cc:1079] T f3c3f004ad2d4f1bab826390386de2e2 P 9eb42ed7820e4c6f9101a96004d4caba: Deleting log segment in path: /tmp/dist-test-tasktjZuXx/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515590048853-21414-0/minicluster-data/ts-0-root/wals/f3c3f004ad2d4f1bab826390386de2e2/wal-000000035 (ops 169-173)
I20260812 06:19:54.672379 21574 log.cc:1079] T f3c3f004ad2d4f1bab826390386de2e2 P 9eb42ed7820e4c6f9101a96004d4caba: Deleting log segment in path: /tmp/dist-test-tasktjZuXx/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515590048853-21414-0/minicluster-data/ts-0-root/wals/f3c3f004ad2d4f1bab826390386de2e2/wal-000000036 (ops 174-178)
I20260812 06:19:54.672400 21574 log.cc:1079] T f3c3f004ad2d4f1bab826390386de2e2 P 9eb42ed7820e4c6f9101a96004d4caba: Deleting log segment in path: /tmp/dist-test-tasktjZuXx/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515590048853-21414-0/minicluster-data/ts-0-root/wals/f3c3f004ad2d4f1bab826390386de2e2/wal-000000037 (ops 179-183)
I20260812 06:19:54.672431 21574 log.cc:1079] T f3c3f004ad2d4f1bab826390386de2e2 P 9eb42ed7820e4c6f9101a96004d4caba: Deleting log segment in path: /tmp/dist-test-tasktjZuXx/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515590048853-21414-0/minicluster-data/ts-0-root/wals/f3c3f004ad2d4f1bab826390386de2e2/wal-000000038 (ops 184-188)
I20260812 06:19:54.702266 21574 maintenance_manager.cc:643] P 9eb42ed7820e4c6f9101a96004d4caba: LogGCOp(f3c3f004ad2d4f1bab826390386de2e2) complete. Timing: real 0.030s	user 0.000s	sys 0.029s Metrics: {}
I20260812 06:19:54.702672 21683 maintenance_manager.cc:419] P 9eb42ed7820e4c6f9101a96004d4caba: Scheduling UndoDeltaBlockGCOp(f3c3f004ad2d4f1bab826390386de2e2): 482 bytes on disk
I20260812 06:19:54.703127 21574 maintenance_manager.cc:643] P 9eb42ed7820e4c6f9101a96004d4caba: UndoDeltaBlockGCOp(f3c3f004ad2d4f1bab826390386de2e2) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":49,"lbm_reads_lt_1ms":4}
I20260812 06:19:54.703687 21683 maintenance_manager.cc:419] P 9eb42ed7820e4c6f9101a96004d4caba: Scheduling FlushDeltaMemStoresOp(f3c3f004ad2d4f1bab826390386de2e2): perf score=3.181125
I20260812 06:19:54.725787 21574 maintenance_manager.cc:643] P 9eb42ed7820e4c6f9101a96004d4caba: FlushDeltaMemStoresOp(f3c3f004ad2d4f1bab826390386de2e2) complete. Timing: real 0.022s	user 0.011s	sys 0.004s Metrics: {"bytes_written":4512900,"delete_count":0,"lbm_write_time_us":6133,"lbm_writes_lt_1ms":113,"reinsert_count":0,"update_count":550}
I20260812 06:19:54.726260 21683 maintenance_manager.cc:419] P 9eb42ed7820e4c6f9101a96004d4caba: Scheduling FlushDeltaMemStoresOp(f3c3f004ad2d4f1bab826390386de2e2): perf score=2.188937
I20260812 06:19:54.735399 21574 maintenance_manager.cc:643] P 9eb42ed7820e4c6f9101a96004d4caba: FlushDeltaMemStoresOp(f3c3f004ad2d4f1bab826390386de2e2) complete. Timing: real 0.009s	user 0.004s	sys 0.003s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3418,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:19:54.735805 21683 maintenance_manager.cc:419] P 9eb42ed7820e4c6f9101a96004d4caba: Scheduling MajorDeltaCompactionOp(f3c3f004ad2d4f1bab826390386de2e2): perf score=1.000000
I20260812 06:19:54.924584 21414 heavy-update-compaction-itest.cc:229] Time spent updating: real 4.598s	user 1.734s	sys 0.128s
I20260812 06:19:54.955312 21574 maintenance_manager.cc:643] P 9eb42ed7820e4c6f9101a96004d4caba: MajorDeltaCompactionOp(f3c3f004ad2d4f1bab826390386de2e2) complete. Timing: real 0.219s	user 0.159s	sys 0.057s Metrics: {"cfile_cache_miss":734,"cfile_cache_miss_bytes":32979737,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"lbm_read_time_us":15080,"lbm_reads_lt_1ms":770,"lbm_write_time_us":38552,"lbm_writes_lt_1ms":743,"peak_mem_usage":87969044,"reinsert_count":0,"spinlock_wait_cycles":768,"update_count":3500}
I20260812 06:19:54.955888 21683 maintenance_manager.cc:419] P 9eb42ed7820e4c6f9101a96004d4caba: Scheduling FlushDeltaMemStoresOp(f3c3f004ad2d4f1bab826390386de2e2): perf score=14.095187
I20260812 06:19:54.986267 21574 maintenance_manager.cc:643] P 9eb42ed7820e4c6f9101a96004d4caba: FlushDeltaMemStoresOp(f3c3f004ad2d4f1bab826390386de2e2) complete. Timing: real 0.030s	user 0.010s	sys 0.019s Metrics: {"bytes_written":16409905,"delete_count":0,"lbm_write_time_us":14220,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:54.986824 21683 maintenance_manager.cc:419] P 9eb42ed7820e4c6f9101a96004d4caba: Scheduling MajorDeltaCompactionOp(f3c3f004ad2d4f1bab826390386de2e2): perf score=1.000000
I20260812 06:19:55.026573 21414 heavy-update-compaction-itest.cc:265] Time spent scanning: real 0.101s	user 0.002s	sys 0.000s
I20260812 06:19:55.027267 21414 tablet_server.cc:179] TabletServer@127.20.233.129:0 shutting down...
I20260812 06:19:55.100725 21574 maintenance_manager.cc:643] P 9eb42ed7820e4c6f9101a96004d4caba: MajorDeltaCompactionOp(f3c3f004ad2d4f1bab826390386de2e2) complete. Timing: real 0.114s	user 0.077s	sys 0.036s Metrics: {"cfile_cache_miss":431,"cfile_cache_miss_bytes":20672161,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":1,"delta_iterators_relevant":1,"dirs.queue_time_us":242,"lbm_read_time_us":9067,"lbm_reads_lt_1ms":467,"lbm_write_time_us":21146,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":442,"mutex_wait_us":33,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":57344,"update_count":2000}
I20260812 06:19:55.101511 21414 ts_tablet_manager.cc:1507] Shutting down tablet manager...
I20260812 06:19:55.102020 21414 tablet_replica.cc:333] T f3c3f004ad2d4f1bab826390386de2e2 P 9eb42ed7820e4c6f9101a96004d4caba: stopping tablet replica
I20260812 06:19:55.102284 21414 raft_consensus.cc:2243] T f3c3f004ad2d4f1bab826390386de2e2 P 9eb42ed7820e4c6f9101a96004d4caba [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:19:55.102516 21414 raft_consensus.cc:2272] T f3c3f004ad2d4f1bab826390386de2e2 P 9eb42ed7820e4c6f9101a96004d4caba [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:19:55.117911 21414 tablet_server.cc:196] TabletServer@127.20.233.129:0 shutdown complete.
I20260812 06:19:55.147812 21414 master.cc:562] Master@127.20.233.190:40095 shutting down...
I20260812 06:19:55.151011 21414 raft_consensus.cc:2243] T 00000000000000000000000000000000 P 57c4284664e240e089ee5a1a3ec02d75 [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:19:55.151185 21414 raft_consensus.cc:2272] T 00000000000000000000000000000000 P 57c4284664e240e089ee5a1a3ec02d75 [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:19:55.151260 21414 tablet_replica.cc:333] T 00000000000000000000000000000000 P 57c4284664e240e089ee5a1a3ec02d75: stopping tablet replica
I20260812 06:19:55.163357 21414 master.cc:584] Master@127.20.233.190:40095 shutdown complete.
[       OK ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/0 (5180 ms)
[ RUN      ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/1
I20260812 06:19:55.250265 21414 internal_mini_cluster.cc:156] Creating distributed mini masters. Addrs: 127.20.233.190:35783
I20260812 06:19:55.250705 21414 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:19:55.253047 21746 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:55.253130 21742 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:55.253175 21741 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:55.253232 21414 server_base.cc:1061] running on GCE node
I20260812 06:19:55.253397 21414 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:19:55.253443 21414 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:55.253463 21414 hybrid_clock.cc:648] HybridClock initialized: now 1786515595253462 us; error 0 us; skew 500 ppm
I20260812 06:19:55.254371 21414 webserver.cc:533] Webserver started at http://127.20.233.190:45927/ using document root <none> and password file <none>
I20260812 06:19:55.254539 21414 fs_manager.cc:362] Metadata directory not provided
I20260812 06:19:55.254593 21414 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:19:55.254673 21414 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:19:55.255074 21414 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-tasktjZuXx/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515590048853-21414-0/minicluster-data/master-0-root/instance:
uuid: "becbf340aab64d38be9b437c570cc824"
format_stamp: "Formatted at 2026-08-12 06:19:55 on dist-test-slave-k5rr"
I20260812 06:19:55.256536 21414 fs_manager.cc:696] Time spent creating directory manager: real 0.001s	user 0.002s	sys 0.000s
I20260812 06:19:55.257507 21753 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:55.257733 21414 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.000s	sys 0.000s
I20260812 06:19:55.257802 21414 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-tasktjZuXx/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515590048853-21414-0/minicluster-data/master-0-root
uuid: "becbf340aab64d38be9b437c570cc824"
format_stamp: "Formatted at 2026-08-12 06:19:55 on dist-test-slave-k5rr"
I20260812 06:19:55.257875 21414 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-tasktjZuXx/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515590048853-21414-0/minicluster-data/master-0-root
metadata directory: /tmp/dist-test-tasktjZuXx/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515590048853-21414-0/minicluster-data/master-0-root
1 data directories: /tmp/dist-test-tasktjZuXx/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515590048853-21414-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:55.266912 21414 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:19:55.267252 21414 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:19:55.271198 21414 rpc_server.cc:307] RPC server started. Bound to: 127.20.233.190:35783
I20260812 06:19:55.271220 21840 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.20.233.190:35783 every 8 connection(s)
I20260812 06:19:55.272037 21842 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:55.273872 21842 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P becbf340aab64d38be9b437c570cc824: Bootstrap starting.
I20260812 06:19:55.274629 21842 tablet_bootstrap.cc:654] T 00000000000000000000000000000000 P becbf340aab64d38be9b437c570cc824: Neither blocks nor log segments found. Creating new log.
I20260812 06:19:55.275530 21842 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P becbf340aab64d38be9b437c570cc824: No bootstrap required, opened a new log
I20260812 06:19:55.275923 21842 raft_consensus.cc:359] T 00000000000000000000000000000000 P becbf340aab64d38be9b437c570cc824 [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "becbf340aab64d38be9b437c570cc824" member_type: VOTER }
I20260812 06:19:55.276005 21842 raft_consensus.cc:385] T 00000000000000000000000000000000 P becbf340aab64d38be9b437c570cc824 [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:19:55.276036 21842 raft_consensus.cc:740] T 00000000000000000000000000000000 P becbf340aab64d38be9b437c570cc824 [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: becbf340aab64d38be9b437c570cc824, State: Initialized, Role: FOLLOWER
I20260812 06:19:55.276175 21842 consensus_queue.cc:260] T 00000000000000000000000000000000 P becbf340aab64d38be9b437c570cc824 [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: "becbf340aab64d38be9b437c570cc824" member_type: VOTER }
I20260812 06:19:55.276259 21842 raft_consensus.cc:399] T 00000000000000000000000000000000 P becbf340aab64d38be9b437c570cc824 [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:19:55.276298 21842 raft_consensus.cc:493] T 00000000000000000000000000000000 P becbf340aab64d38be9b437c570cc824 [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:19:55.276347 21842 raft_consensus.cc:3060] T 00000000000000000000000000000000 P becbf340aab64d38be9b437c570cc824 [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:19:55.276975 21842 raft_consensus.cc:515] T 00000000000000000000000000000000 P becbf340aab64d38be9b437c570cc824 [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "becbf340aab64d38be9b437c570cc824" member_type: VOTER }
I20260812 06:19:55.277136 21842 leader_election.cc:304] T 00000000000000000000000000000000 P becbf340aab64d38be9b437c570cc824 [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: becbf340aab64d38be9b437c570cc824; no voters: 
I20260812 06:19:55.277311 21842 leader_election.cc:290] T 00000000000000000000000000000000 P becbf340aab64d38be9b437c570cc824 [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:19:55.277420 21848 raft_consensus.cc:2804] T 00000000000000000000000000000000 P becbf340aab64d38be9b437c570cc824 [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:19:55.277599 21848 raft_consensus.cc:697] T 00000000000000000000000000000000 P becbf340aab64d38be9b437c570cc824 [term 1 LEADER]: Becoming Leader. State: Replica: becbf340aab64d38be9b437c570cc824, State: Running, Role: LEADER
I20260812 06:19:55.277740 21842 sys_catalog.cc:565] T 00000000000000000000000000000000 P becbf340aab64d38be9b437c570cc824 [sys.catalog]: configured and running, proceeding with master startup.
I20260812 06:19:55.277732 21848 consensus_queue.cc:237] T 00000000000000000000000000000000 P becbf340aab64d38be9b437c570cc824 [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: "becbf340aab64d38be9b437c570cc824" member_type: VOTER }
I20260812 06:19:55.278184 21851 sys_catalog.cc:455] T 00000000000000000000000000000000 P becbf340aab64d38be9b437c570cc824 [sys.catalog]: SysCatalogTable state changed. Reason: New leader becbf340aab64d38be9b437c570cc824. Latest consensus state: current_term: 1 leader_uuid: "becbf340aab64d38be9b437c570cc824" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "becbf340aab64d38be9b437c570cc824" member_type: VOTER } }
I20260812 06:19:55.278270 21851 sys_catalog.cc:458] T 00000000000000000000000000000000 P becbf340aab64d38be9b437c570cc824 [sys.catalog]: This master's current role is: LEADER
I20260812 06:19:55.278168 21849 sys_catalog.cc:455] T 00000000000000000000000000000000 P becbf340aab64d38be9b437c570cc824 [sys.catalog]: SysCatalogTable state changed. Reason: RaftConsensus started. Latest consensus state: current_term: 1 leader_uuid: "becbf340aab64d38be9b437c570cc824" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "becbf340aab64d38be9b437c570cc824" member_type: VOTER } }
I20260812 06:19:55.278323 21849 sys_catalog.cc:458] T 00000000000000000000000000000000 P becbf340aab64d38be9b437c570cc824 [sys.catalog]: This master's current role is: LEADER
I20260812 06:19:55.278553 21860 catalog_manager.cc:1511] Loading table and tablet metadata into memory...
I20260812 06:19:55.279368 21860 catalog_manager.cc:1520] Initializing Kudu cluster ID...
I20260812 06:19:55.279523 21414 internal_mini_cluster.cc:184] Waiting to initialize catalog manager on master 0
I20260812 06:19:55.281078 21860 catalog_manager.cc:1383] Generated new cluster ID: 0b58b7a302d54a73a1087ad02ce0dcb9
I20260812 06:19:55.281132 21860 catalog_manager.cc:1531] Initializing Kudu internal certificate authority...
I20260812 06:19:55.292783 21860 catalog_manager.cc:1406] Generated new certificate authority record
I20260812 06:19:55.293365 21860 catalog_manager.cc:1540] Loading token signing keys...
I20260812 06:19:55.303182 21860 catalog_manager.cc:6092] T 00000000000000000000000000000000 P becbf340aab64d38be9b437c570cc824: Generated new TSK 0
I20260812 06:19:55.303334 21860 catalog_manager.cc:1550] Initializing in-progress tserver states...
I20260812 06:19:55.311766 21414 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:19:55.313637 21881 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:55.313746 21882 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:55.313838 21884 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:55.313920 21414 server_base.cc:1061] running on GCE node
I20260812 06:19:55.314152 21414 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:19:55.314194 21414 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:55.314209 21414 hybrid_clock.cc:648] HybridClock initialized: now 1786515595314210 us; error 0 us; skew 500 ppm
I20260812 06:19:55.314983 21414 webserver.cc:533] Webserver started at http://127.20.233.129:39529/ using document root <none> and password file <none>
I20260812 06:19:55.315119 21414 fs_manager.cc:362] Metadata directory not provided
I20260812 06:19:55.315160 21414 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:19:55.315214 21414 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:19:55.315552 21414 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-tasktjZuXx/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515590048853-21414-0/minicluster-data/ts-0-root/instance:
uuid: "adc4af581caa449aabf038e2b55c35de"
format_stamp: "Formatted at 2026-08-12 06:19:55 on dist-test-slave-k5rr"
I20260812 06:19:55.316926 21414 fs_manager.cc:696] Time spent creating directory manager: real 0.001s	user 0.002s	sys 0.000s
I20260812 06:19:55.317817 21893 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:55.318050 21414 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.001s	sys 0.000s
I20260812 06:19:55.318115 21414 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-tasktjZuXx/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515590048853-21414-0/minicluster-data/ts-0-root
uuid: "adc4af581caa449aabf038e2b55c35de"
format_stamp: "Formatted at 2026-08-12 06:19:55 on dist-test-slave-k5rr"
I20260812 06:19:55.318181 21414 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-tasktjZuXx/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515590048853-21414-0/minicluster-data/ts-0-root
metadata directory: /tmp/dist-test-tasktjZuXx/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515590048853-21414-0/minicluster-data/ts-0-root
1 data directories: /tmp/dist-test-tasktjZuXx/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515590048853-21414-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:55.329074 21414 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:19:55.329406 21414 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:19:55.329672 21414 txn_system_client.cc:432] TxnSystemClient initialization is disabled...
I20260812 06:19:55.330117 21414 ts_tablet_manager.cc:585] Loaded tablet metadata (0 total tablets, 0 live tablets)
I20260812 06:19:55.330155 21414 ts_tablet_manager.cc:531] Time spent load tablet metadata: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:19:55.330188 21414 ts_tablet_manager.cc:616] Registered 0 tablets
I20260812 06:19:55.330217 21414 ts_tablet_manager.cc:595] Time spent register tablets: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:19:55.334398 21414 rpc_server.cc:307] RPC server started. Bound to: 127.20.233.129:33035
I20260812 06:19:55.334456 21994 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.20.233.129:33035 every 8 connection(s)
I20260812 06:19:55.341775 21995 heartbeater.cc:344] Connected to a master server at 127.20.233.190:35783
I20260812 06:19:55.341904 21995 heartbeater.cc:461] Registering TS with master...
I20260812 06:19:55.342149 21995 heartbeater.cc:507] Master 127.20.233.190:35783 requested a full tablet report, sending...
I20260812 06:19:55.342792 21780 ts_manager.cc:194] Registered new tserver with Master: adc4af581caa449aabf038e2b55c35de (127.20.233.129:33035)
I20260812 06:19:55.343489 21780 master_service.cc:502] Signed X509 certificate for tserver {username='slave'} at 127.0.0.1:60134
I20260812 06:19:55.343684 21414 internal_mini_cluster.cc:371] 1 TS(s) registered with all masters after 0.008896021s
I20260812 06:19:55.350229 21780 catalog_manager.cc:2283] Servicing CreateTable request from {username='slave'} at 127.0.0.1:60146:
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:55.358317 21935 tablet_service.cc:1511] Processing CreateTablet for tablet 2ba6ce16708e4e529040d74b2aefa66d (DEFAULT_TABLE table=heavy-update-compaction-test [id=8cca2a58f85a4e8b9066807d8b07dd6a]), partition=
I20260812 06:19:55.358578 21935 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet 2ba6ce16708e4e529040d74b2aefa66d. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:19:55.360445 22013 tablet_bootstrap.cc:492] T 2ba6ce16708e4e529040d74b2aefa66d P adc4af581caa449aabf038e2b55c35de: Bootstrap starting.
I20260812 06:19:55.361371 22013 tablet_bootstrap.cc:654] T 2ba6ce16708e4e529040d74b2aefa66d P adc4af581caa449aabf038e2b55c35de: Neither blocks nor log segments found. Creating new log.
I20260812 06:19:55.362353 22013 tablet_bootstrap.cc:492] T 2ba6ce16708e4e529040d74b2aefa66d P adc4af581caa449aabf038e2b55c35de: No bootstrap required, opened a new log
I20260812 06:19:55.362440 22013 ts_tablet_manager.cc:1403] T 2ba6ce16708e4e529040d74b2aefa66d P adc4af581caa449aabf038e2b55c35de: Time spent bootstrapping tablet: real 0.002s	user 0.001s	sys 0.000s
I20260812 06:19:55.362838 22013 raft_consensus.cc:359] T 2ba6ce16708e4e529040d74b2aefa66d P adc4af581caa449aabf038e2b55c35de [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "adc4af581caa449aabf038e2b55c35de" member_type: VOTER last_known_addr { host: "127.20.233.129" port: 33035 } }
I20260812 06:19:55.362926 22013 raft_consensus.cc:385] T 2ba6ce16708e4e529040d74b2aefa66d P adc4af581caa449aabf038e2b55c35de [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:19:55.362958 22013 raft_consensus.cc:740] T 2ba6ce16708e4e529040d74b2aefa66d P adc4af581caa449aabf038e2b55c35de [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: adc4af581caa449aabf038e2b55c35de, State: Initialized, Role: FOLLOWER
I20260812 06:19:55.363088 22013 consensus_queue.cc:260] T 2ba6ce16708e4e529040d74b2aefa66d P adc4af581caa449aabf038e2b55c35de [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: "adc4af581caa449aabf038e2b55c35de" member_type: VOTER last_known_addr { host: "127.20.233.129" port: 33035 } }
I20260812 06:19:55.363161 22013 raft_consensus.cc:399] T 2ba6ce16708e4e529040d74b2aefa66d P adc4af581caa449aabf038e2b55c35de [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:19:55.363194 22013 raft_consensus.cc:493] T 2ba6ce16708e4e529040d74b2aefa66d P adc4af581caa449aabf038e2b55c35de [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:19:55.363243 22013 raft_consensus.cc:3060] T 2ba6ce16708e4e529040d74b2aefa66d P adc4af581caa449aabf038e2b55c35de [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:19:55.364049 22013 raft_consensus.cc:515] T 2ba6ce16708e4e529040d74b2aefa66d P adc4af581caa449aabf038e2b55c35de [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "adc4af581caa449aabf038e2b55c35de" member_type: VOTER last_known_addr { host: "127.20.233.129" port: 33035 } }
I20260812 06:19:55.364185 22013 leader_election.cc:304] T 2ba6ce16708e4e529040d74b2aefa66d P adc4af581caa449aabf038e2b55c35de [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: adc4af581caa449aabf038e2b55c35de; no voters: 
I20260812 06:19:55.364373 22013 leader_election.cc:290] T 2ba6ce16708e4e529040d74b2aefa66d P adc4af581caa449aabf038e2b55c35de [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:19:55.364494 22015 raft_consensus.cc:2804] T 2ba6ce16708e4e529040d74b2aefa66d P adc4af581caa449aabf038e2b55c35de [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:19:55.364691 22013 ts_tablet_manager.cc:1434] T 2ba6ce16708e4e529040d74b2aefa66d P adc4af581caa449aabf038e2b55c35de: Time spent starting tablet: real 0.002s	user 0.002s	sys 0.000s
I20260812 06:19:55.364725 21995 heartbeater.cc:499] Master 127.20.233.190:35783 was elected leader, sending a full tablet report...
I20260812 06:19:55.364691 22015 raft_consensus.cc:697] T 2ba6ce16708e4e529040d74b2aefa66d P adc4af581caa449aabf038e2b55c35de [term 1 LEADER]: Becoming Leader. State: Replica: adc4af581caa449aabf038e2b55c35de, State: Running, Role: LEADER
I20260812 06:19:55.364900 22015 consensus_queue.cc:237] T 2ba6ce16708e4e529040d74b2aefa66d P adc4af581caa449aabf038e2b55c35de [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: "adc4af581caa449aabf038e2b55c35de" member_type: VOTER last_known_addr { host: "127.20.233.129" port: 33035 } }
I20260812 06:19:55.366189 21780 catalog_manager.cc:5719] T 2ba6ce16708e4e529040d74b2aefa66d P adc4af581caa449aabf038e2b55c35de reported cstate change: term changed from 0 to 1, leader changed from <none> to adc4af581caa449aabf038e2b55c35de (127.20.233.129). New cstate: current_term: 1 leader_uuid: "adc4af581caa449aabf038e2b55c35de" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "adc4af581caa449aabf038e2b55c35de" member_type: VOTER last_known_addr { host: "127.20.233.129" port: 33035 } health_report { overall_health: HEALTHY } } }
I20260812 06:19:55.420218 21414 heavy-update-compaction-itest.cc:215] Time spent inserting: real 0.051s	user 0.019s	sys 0.003s
I20260812 06:19:55.585333 21996 maintenance_manager.cc:419] P adc4af581caa449aabf038e2b55c35de: Scheduling FlushMRSOp(2ba6ce16708e4e529040d74b2aefa66d): perf score=23.023690
I20260812 06:19:55.750895 21901 maintenance_manager.cc:643] P adc4af581caa449aabf038e2b55c35de: FlushMRSOp(2ba6ce16708e4e529040d74b2aefa66d) complete. Timing: real 0.165s	user 0.108s	sys 0.056s Metrics: {"bytes_written":12307490,"cfile_init":1,"delete_count":0,"dirs.queue_time_us":58,"dirs.run_cpu_time_us":157,"dirs.run_wall_time_us":753,"drs_written":1,"lbm_read_time_us":53,"lbm_reads_lt_1ms":4,"lbm_write_time_us":41701,"lbm_writes_lt_1ms":857,"peak_mem_usage":0,"reinsert_count":0,"rows_written":105,"update_count":1500}
I20260812 06:19:55.751722 21996 maintenance_manager.cc:419] P adc4af581caa449aabf038e2b55c35de: Scheduling LogGCOp(2ba6ce16708e4e529040d74b2aefa66d): free 20743880 bytes of WAL
I20260812 06:19:55.751998 21901 log_reader.cc:385] T 2ba6ce16708e4e529040d74b2aefa66d: removed 2 log segments from log reader
I20260812 06:19:55.752058 21901 log.cc:1079] T 2ba6ce16708e4e529040d74b2aefa66d P adc4af581caa449aabf038e2b55c35de: Deleting log segment in path: /tmp/dist-test-tasktjZuXx/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515590048853-21414-0/minicluster-data/ts-0-root/wals/2ba6ce16708e4e529040d74b2aefa66d/wal-000000001 (ops 1-6)
I20260812 06:19:55.752100 21901 log.cc:1079] T 2ba6ce16708e4e529040d74b2aefa66d P adc4af581caa449aabf038e2b55c35de: Deleting log segment in path: /tmp/dist-test-tasktjZuXx/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515590048853-21414-0/minicluster-data/ts-0-root/wals/2ba6ce16708e4e529040d74b2aefa66d/wal-000000002 (ops 7-11)
I20260812 06:19:55.756474 21901 maintenance_manager.cc:643] P adc4af581caa449aabf038e2b55c35de: LogGCOp(2ba6ce16708e4e529040d74b2aefa66d) complete. Timing: real 0.005s	user 0.000s	sys 0.001s Metrics: {}
I20260812 06:19:55.756839 21996 maintenance_manager.cc:419] P adc4af581caa449aabf038e2b55c35de: Scheduling UndoDeltaBlockGCOp(2ba6ce16708e4e529040d74b2aefa66d): 20513814 bytes on disk
I20260812 06:19:55.757304 21901 maintenance_manager.cc:643] P adc4af581caa449aabf038e2b55c35de: UndoDeltaBlockGCOp(2ba6ce16708e4e529040d74b2aefa66d) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":58,"lbm_reads_lt_1ms":4}
I20260812 06:19:55.757736 21996 maintenance_manager.cc:419] P adc4af581caa449aabf038e2b55c35de: Scheduling FlushDeltaMemStoresOp(2ba6ce16708e4e529040d74b2aefa66d): perf score=2.188937
I20260812 06:19:55.772637 21901 maintenance_manager.cc:643] P adc4af581caa449aabf038e2b55c35de: FlushDeltaMemStoresOp(2ba6ce16708e4e529040d74b2aefa66d) complete. Timing: real 0.015s	user 0.007s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4517,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:55.773247 21996 maintenance_manager.cc:419] P adc4af581caa449aabf038e2b55c35de: Scheduling MajorDeltaCompactionOp(2ba6ce16708e4e529040d74b2aefa66d): perf score=1.000000
I20260812 06:19:55.931660 21901 maintenance_manager.cc:643] P adc4af581caa449aabf038e2b55c35de: MajorDeltaCompactionOp(2ba6ce16708e4e529040d74b2aefa66d) complete. Timing: real 0.158s	user 0.116s	sys 0.040s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20713272,"cfile_init":7,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":636,"lbm_read_time_us":10741,"lbm_reads_lt_1ms":460,"lbm_write_time_us":23803,"lbm_writes_lt_1ms":443,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":768,"thread_start_us":302,"threads_started":5,"update_count":2000}
I20260812 06:19:55.932183 21996 maintenance_manager.cc:419] P adc4af581caa449aabf038e2b55c35de: Scheduling FlushDeltaMemStoresOp(2ba6ce16708e4e529040d74b2aefa66d): perf score=14.095187
I20260812 06:19:55.979912 21901 maintenance_manager.cc:643] P adc4af581caa449aabf038e2b55c35de: FlushDeltaMemStoresOp(2ba6ce16708e4e529040d74b2aefa66d) complete. Timing: real 0.048s	user 0.020s	sys 0.019s Metrics: {"bytes_written":16409897,"delete_count":0,"lbm_write_time_us":18042,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:55.980455 21996 maintenance_manager.cc:419] P adc4af581caa449aabf038e2b55c35de: Scheduling FlushDeltaMemStoresOp(2ba6ce16708e4e529040d74b2aefa66d): perf score=2.188937
I20260812 06:19:55.992669 21901 maintenance_manager.cc:643] P adc4af581caa449aabf038e2b55c35de: FlushDeltaMemStoresOp(2ba6ce16708e4e529040d74b2aefa66d) complete. Timing: real 0.012s	user 0.000s	sys 0.010s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4210,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:55.993621 21996 maintenance_manager.cc:419] P adc4af581caa449aabf038e2b55c35de: Scheduling MajorDeltaCompactionOp(2ba6ce16708e4e529040d74b2aefa66d): perf score=1.000000
I20260812 06:19:56.141757 21901 maintenance_manager.cc:643] P adc4af581caa449aabf038e2b55c35de: MajorDeltaCompactionOp(2ba6ce16708e4e529040d74b2aefa66d) complete. Timing: real 0.148s	user 0.094s	sys 0.052s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24815679,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":260,"lbm_read_time_us":10796,"lbm_reads_lt_1ms":572,"lbm_write_time_us":28529,"lbm_writes_lt_1ms":543,"mutex_wait_us":99,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":55808,"update_count":2500}
I20260812 06:19:56.142275 21996 maintenance_manager.cc:419] P adc4af581caa449aabf038e2b55c35de: Scheduling FlushDeltaMemStoresOp(2ba6ce16708e4e529040d74b2aefa66d): perf score=11.118625
I20260812 06:19:56.175454 21901 maintenance_manager.cc:643] P adc4af581caa449aabf038e2b55c35de: FlushDeltaMemStoresOp(2ba6ce16708e4e529040d74b2aefa66d) complete. Timing: real 0.033s	user 0.023s	sys 0.007s Metrics: {"bytes_written":12717735,"delete_count":0,"lbm_write_time_us":13356,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:19:56.176039 21996 maintenance_manager.cc:419] P adc4af581caa449aabf038e2b55c35de: Scheduling FlushDeltaMemStoresOp(2ba6ce16708e4e529040d74b2aefa66d): perf score=2.188937
I20260812 06:19:56.191176 21901 maintenance_manager.cc:643] P adc4af581caa449aabf038e2b55c35de: FlushDeltaMemStoresOp(2ba6ce16708e4e529040d74b2aefa66d) complete. Timing: real 0.015s	user 0.004s	sys 0.008s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":5103,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:19:56.191769 21996 maintenance_manager.cc:419] P adc4af581caa449aabf038e2b55c35de: Scheduling MajorDeltaCompactionOp(2ba6ce16708e4e529040d74b2aefa66d): perf score=1.000000
I20260812 06:19:56.322642 21901 maintenance_manager.cc:643] P adc4af581caa449aabf038e2b55c35de: MajorDeltaCompactionOp(2ba6ce16708e4e529040d74b2aefa66d) complete. Timing: real 0.131s	user 0.112s	sys 0.017s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20713263,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":80,"lbm_read_time_us":8514,"lbm_reads_lt_1ms":464,"lbm_write_time_us":24377,"lbm_writes_lt_1ms":443,"mutex_wait_us":2,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":9344,"update_count":2000}
I20260812 06:19:56.323206 21996 maintenance_manager.cc:419] P adc4af581caa449aabf038e2b55c35de: Scheduling FlushDeltaMemStoresOp(2ba6ce16708e4e529040d74b2aefa66d): perf score=10.126437
I20260812 06:19:56.364058 21901 maintenance_manager.cc:643] P adc4af581caa449aabf038e2b55c35de: FlushDeltaMemStoresOp(2ba6ce16708e4e529040d74b2aefa66d) complete. Timing: real 0.040s	user 0.019s	sys 0.008s Metrics: {"bytes_written":12307492,"delete_count":0,"lbm_write_time_us":13088,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:19:56.364599 21996 maintenance_manager.cc:419] P adc4af581caa449aabf038e2b55c35de: Scheduling FlushDeltaMemStoresOp(2ba6ce16708e4e529040d74b2aefa66d): perf score=2.188937
I20260812 06:19:56.379429 21901 maintenance_manager.cc:643] P adc4af581caa449aabf038e2b55c35de: FlushDeltaMemStoresOp(2ba6ce16708e4e529040d74b2aefa66d) complete. Timing: real 0.015s	user 0.012s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5185,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:56.379870 21996 maintenance_manager.cc:419] P adc4af581caa449aabf038e2b55c35de: Scheduling MajorDeltaCompactionOp(2ba6ce16708e4e529040d74b2aefa66d): perf score=1.000000
I20260812 06:19:56.502502 21901 maintenance_manager.cc:643] P adc4af581caa449aabf038e2b55c35de: MajorDeltaCompactionOp(2ba6ce16708e4e529040d74b2aefa66d) complete. Timing: real 0.122s	user 0.083s	sys 0.039s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20713274,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":952,"lbm_read_time_us":8947,"lbm_reads_lt_1ms":472,"lbm_write_time_us":23997,"lbm_writes_lt_1ms":443,"mutex_wait_us":297,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":28672,"update_count":2000}
I20260812 06:19:56.503065 21996 maintenance_manager.cc:419] P adc4af581caa449aabf038e2b55c35de: Scheduling FlushDeltaMemStoresOp(2ba6ce16708e4e529040d74b2aefa66d): perf score=10.126437
I20260812 06:19:56.553952 21901 maintenance_manager.cc:643] P adc4af581caa449aabf038e2b55c35de: FlushDeltaMemStoresOp(2ba6ce16708e4e529040d74b2aefa66d) complete. Timing: real 0.051s	user 0.011s	sys 0.039s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":18448,"lbm_writes_1-10_ms":2,"lbm_writes_lt_1ms":301,"reinsert_count":0,"update_count":1500}
I20260812 06:19:56.554427 21996 maintenance_manager.cc:419] P adc4af581caa449aabf038e2b55c35de: Scheduling FlushDeltaMemStoresOp(2ba6ce16708e4e529040d74b2aefa66d): perf score=2.188937
I20260812 06:19:56.564862 21901 maintenance_manager.cc:643] P adc4af581caa449aabf038e2b55c35de: FlushDeltaMemStoresOp(2ba6ce16708e4e529040d74b2aefa66d) complete. Timing: real 0.010s	user 0.004s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3869,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:56.565305 21996 maintenance_manager.cc:419] P adc4af581caa449aabf038e2b55c35de: Scheduling MajorDeltaCompactionOp(2ba6ce16708e4e529040d74b2aefa66d): perf score=1.000000
I20260812 06:19:56.711436 21901 maintenance_manager.cc:643] P adc4af581caa449aabf038e2b55c35de: MajorDeltaCompactionOp(2ba6ce16708e4e529040d74b2aefa66d) complete. Timing: real 0.146s	user 0.096s	sys 0.050s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20713272,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":146,"lbm_read_time_us":10189,"lbm_reads_lt_1ms":472,"lbm_write_time_us":23839,"lbm_writes_lt_1ms":443,"mutex_wait_us":18,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":14464,"update_count":2000}
I20260812 06:19:56.712023 21996 maintenance_manager.cc:419] P adc4af581caa449aabf038e2b55c35de: Scheduling FlushDeltaMemStoresOp(2ba6ce16708e4e529040d74b2aefa66d): perf score=10.126437
I20260812 06:19:56.751225 21901 maintenance_manager.cc:643] P adc4af581caa449aabf038e2b55c35de: FlushDeltaMemStoresOp(2ba6ce16708e4e529040d74b2aefa66d) complete. Timing: real 0.039s	user 0.012s	sys 0.017s Metrics: {"bytes_written":12307491,"delete_count":0,"lbm_write_time_us":13127,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:19:56.751757 21996 maintenance_manager.cc:419] P adc4af581caa449aabf038e2b55c35de: Scheduling FlushDeltaMemStoresOp(2ba6ce16708e4e529040d74b2aefa66d): perf score=2.188937
I20260812 06:19:56.764705 21901 maintenance_manager.cc:643] P adc4af581caa449aabf038e2b55c35de: FlushDeltaMemStoresOp(2ba6ce16708e4e529040d74b2aefa66d) complete. Timing: real 0.013s	user 0.003s	sys 0.008s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":5138,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:56.765308 21996 maintenance_manager.cc:419] P adc4af581caa449aabf038e2b55c35de: Scheduling MajorDeltaCompactionOp(2ba6ce16708e4e529040d74b2aefa66d): perf score=1.000000
I20260812 06:19:56.888175 21901 maintenance_manager.cc:643] P adc4af581caa449aabf038e2b55c35de: MajorDeltaCompactionOp(2ba6ce16708e4e529040d74b2aefa66d) complete. Timing: real 0.123s	user 0.089s	sys 0.033s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20713272,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":977,"lbm_read_time_us":8622,"lbm_reads_lt_1ms":472,"lbm_write_time_us":23826,"lbm_writes_lt_1ms":443,"mutex_wait_us":281,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":10752,"update_count":2000}
I20260812 06:19:56.888762 21996 maintenance_manager.cc:419] P adc4af581caa449aabf038e2b55c35de: Scheduling FlushDeltaMemStoresOp(2ba6ce16708e4e529040d74b2aefa66d): perf score=10.126437
I20260812 06:19:56.931679 21901 maintenance_manager.cc:643] P adc4af581caa449aabf038e2b55c35de: FlushDeltaMemStoresOp(2ba6ce16708e4e529040d74b2aefa66d) complete. Timing: real 0.043s	user 0.024s	sys 0.016s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":16024,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:19:56.932226 21996 maintenance_manager.cc:419] P adc4af581caa449aabf038e2b55c35de: Scheduling FlushDeltaMemStoresOp(2ba6ce16708e4e529040d74b2aefa66d): perf score=2.188937
I20260812 06:19:56.947649 21901 maintenance_manager.cc:643] P adc4af581caa449aabf038e2b55c35de: FlushDeltaMemStoresOp(2ba6ce16708e4e529040d74b2aefa66d) complete. Timing: real 0.015s	user 0.010s	sys 0.003s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5989,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:56.948172 21996 maintenance_manager.cc:419] P adc4af581caa449aabf038e2b55c35de: Scheduling FlushMRSOp(2ba6ce16708e4e529040d74b2aefa66d): perf score=1.000000
I20260812 06:19:56.973939 21901 maintenance_manager.cc:643] P adc4af581caa449aabf038e2b55c35de: FlushMRSOp(2ba6ce16708e4e529040d74b2aefa66d) complete. Timing: real 0.026s	user 0.020s	sys 0.005s Metrics: {"bytes_written":1193503,"cfile_init":1,"dirs.queue_time_us":62,"dirs.run_cpu_time_us":244,"dirs.run_wall_time_us":1266,"drs_written":1,"lbm_read_time_us":53,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1439,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":29}
I20260812 06:19:56.974601 21996 maintenance_manager.cc:419] P adc4af581caa449aabf038e2b55c35de: Scheduling LogGCOp(2ba6ce16708e4e529040d74b2aefa66d): free 124257238 bytes of WAL
I20260812 06:19:56.974841 21901 log_reader.cc:385] T 2ba6ce16708e4e529040d74b2aefa66d: removed 12 log segments from log reader
I20260812 06:19:56.974901 21901 log.cc:1079] T 2ba6ce16708e4e529040d74b2aefa66d P adc4af581caa449aabf038e2b55c35de: Deleting log segment in path: /tmp/dist-test-tasktjZuXx/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515590048853-21414-0/minicluster-data/ts-0-root/wals/2ba6ce16708e4e529040d74b2aefa66d/wal-000000003 (ops 12-16)
I20260812 06:19:56.974941 21901 log.cc:1079] T 2ba6ce16708e4e529040d74b2aefa66d P adc4af581caa449aabf038e2b55c35de: Deleting log segment in path: /tmp/dist-test-tasktjZuXx/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515590048853-21414-0/minicluster-data/ts-0-root/wals/2ba6ce16708e4e529040d74b2aefa66d/wal-000000004 (ops 17-21)
I20260812 06:19:56.974973 21901 log.cc:1079] T 2ba6ce16708e4e529040d74b2aefa66d P adc4af581caa449aabf038e2b55c35de: Deleting log segment in path: /tmp/dist-test-tasktjZuXx/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515590048853-21414-0/minicluster-data/ts-0-root/wals/2ba6ce16708e4e529040d74b2aefa66d/wal-000000005 (ops 22-26)
I20260812 06:19:56.975004 21901 log.cc:1079] T 2ba6ce16708e4e529040d74b2aefa66d P adc4af581caa449aabf038e2b55c35de: Deleting log segment in path: /tmp/dist-test-tasktjZuXx/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515590048853-21414-0/minicluster-data/ts-0-root/wals/2ba6ce16708e4e529040d74b2aefa66d/wal-000000006 (ops 27-31)
I20260812 06:19:56.975035 21901 log.cc:1079] T 2ba6ce16708e4e529040d74b2aefa66d P adc4af581caa449aabf038e2b55c35de: Deleting log segment in path: /tmp/dist-test-tasktjZuXx/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515590048853-21414-0/minicluster-data/ts-0-root/wals/2ba6ce16708e4e529040d74b2aefa66d/wal-000000007 (ops 32-36)
I20260812 06:19:56.975065 21901 log.cc:1079] T 2ba6ce16708e4e529040d74b2aefa66d P adc4af581caa449aabf038e2b55c35de: Deleting log segment in path: /tmp/dist-test-tasktjZuXx/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515590048853-21414-0/minicluster-data/ts-0-root/wals/2ba6ce16708e4e529040d74b2aefa66d/wal-000000008 (ops 37-41)
I20260812 06:19:56.975095 21901 log.cc:1079] T 2ba6ce16708e4e529040d74b2aefa66d P adc4af581caa449aabf038e2b55c35de: Deleting log segment in path: /tmp/dist-test-tasktjZuXx/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515590048853-21414-0/minicluster-data/ts-0-root/wals/2ba6ce16708e4e529040d74b2aefa66d/wal-000000009 (ops 42-46)
I20260812 06:19:56.975124 21901 log.cc:1079] T 2ba6ce16708e4e529040d74b2aefa66d P adc4af581caa449aabf038e2b55c35de: Deleting log segment in path: /tmp/dist-test-tasktjZuXx/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515590048853-21414-0/minicluster-data/ts-0-root/wals/2ba6ce16708e4e529040d74b2aefa66d/wal-000000010 (ops 47-51)
I20260812 06:19:56.975157 21901 log.cc:1079] T 2ba6ce16708e4e529040d74b2aefa66d P adc4af581caa449aabf038e2b55c35de: Deleting log segment in path: /tmp/dist-test-tasktjZuXx/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515590048853-21414-0/minicluster-data/ts-0-root/wals/2ba6ce16708e4e529040d74b2aefa66d/wal-000000011 (ops 52-56)
I20260812 06:19:56.975185 21901 log.cc:1079] T 2ba6ce16708e4e529040d74b2aefa66d P adc4af581caa449aabf038e2b55c35de: Deleting log segment in path: /tmp/dist-test-tasktjZuXx/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515590048853-21414-0/minicluster-data/ts-0-root/wals/2ba6ce16708e4e529040d74b2aefa66d/wal-000000012 (ops 57-60)
I20260812 06:19:56.975216 21901 log.cc:1079] T 2ba6ce16708e4e529040d74b2aefa66d P adc4af581caa449aabf038e2b55c35de: Deleting log segment in path: /tmp/dist-test-tasktjZuXx/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515590048853-21414-0/minicluster-data/ts-0-root/wals/2ba6ce16708e4e529040d74b2aefa66d/wal-000000013 (ops 61-65)
I20260812 06:19:56.975246 21901 log.cc:1079] T 2ba6ce16708e4e529040d74b2aefa66d P adc4af581caa449aabf038e2b55c35de: Deleting log segment in path: /tmp/dist-test-tasktjZuXx/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515590048853-21414-0/minicluster-data/ts-0-root/wals/2ba6ce16708e4e529040d74b2aefa66d/wal-000000014 (ops 66-70)
I20260812 06:19:56.997960 21901 maintenance_manager.cc:643] P adc4af581caa449aabf038e2b55c35de: LogGCOp(2ba6ce16708e4e529040d74b2aefa66d) complete. Timing: real 0.023s	user 0.000s	sys 0.022s Metrics: {}
I20260812 06:19:56.998399 21996 maintenance_manager.cc:419] P adc4af581caa449aabf038e2b55c35de: Scheduling FlushDeltaMemStoresOp(2ba6ce16708e4e529040d74b2aefa66d): perf score=3.181125
I20260812 06:19:57.010459 21901 maintenance_manager.cc:643] P adc4af581caa449aabf038e2b55c35de: FlushDeltaMemStoresOp(2ba6ce16708e4e529040d74b2aefa66d) complete. Timing: real 0.012s	user 0.004s	sys 0.007s Metrics: {"bytes_written":4512900,"delete_count":0,"lbm_write_time_us":4472,"lbm_writes_lt_1ms":113,"reinsert_count":0,"update_count":550}
I20260812 06:19:57.010896 21996 maintenance_manager.cc:419] P adc4af581caa449aabf038e2b55c35de: Scheduling FlushDeltaMemStoresOp(2ba6ce16708e4e529040d74b2aefa66d): perf score=2.188937
I20260812 06:19:57.019701 21901 maintenance_manager.cc:643] P adc4af581caa449aabf038e2b55c35de: FlushDeltaMemStoresOp(2ba6ce16708e4e529040d74b2aefa66d) complete. Timing: real 0.009s	user 0.004s	sys 0.003s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3143,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:19:57.020080 21996 maintenance_manager.cc:419] P adc4af581caa449aabf038e2b55c35de: Scheduling UndoDeltaBlockGCOp(2ba6ce16708e4e529040d74b2aefa66d): 462 bytes on disk
I20260812 06:19:57.020474 21901 maintenance_manager.cc:643] P adc4af581caa449aabf038e2b55c35de: UndoDeltaBlockGCOp(2ba6ce16708e4e529040d74b2aefa66d) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":50,"lbm_reads_lt_1ms":4}
I20260812 06:19:57.020917 21996 maintenance_manager.cc:419] P adc4af581caa449aabf038e2b55c35de: Scheduling MajorDeltaCompactionOp(2ba6ce16708e4e529040d74b2aefa66d): perf score=1.000000
I20260812 06:19:57.186022 21901 maintenance_manager.cc:643] P adc4af581caa449aabf038e2b55c35de: MajorDeltaCompactionOp(2ba6ce16708e4e529040d74b2aefa66d) complete. Timing: real 0.165s	user 0.125s	sys 0.033s Metrics: {"cfile_cache_miss":634,"cfile_cache_miss_bytes":28918321,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":1378,"lbm_read_time_us":11105,"lbm_reads_lt_1ms":674,"lbm_write_time_us":29887,"lbm_writes_lt_1ms":643,"mutex_wait_us":482,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":2688,"thread_start_us":74,"threads_started":1,"update_count":3000}
I20260812 06:19:57.186595 21996 maintenance_manager.cc:419] P adc4af581caa449aabf038e2b55c35de: Scheduling FlushDeltaMemStoresOp(2ba6ce16708e4e529040d74b2aefa66d): perf score=14.095187
I20260812 06:19:57.234369 21901 maintenance_manager.cc:643] P adc4af581caa449aabf038e2b55c35de: FlushDeltaMemStoresOp(2ba6ce16708e4e529040d74b2aefa66d) complete. Timing: real 0.048s	user 0.018s	sys 0.027s Metrics: {"bytes_written":16409903,"delete_count":0,"lbm_write_time_us":20788,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:57.234954 21996 maintenance_manager.cc:419] P adc4af581caa449aabf038e2b55c35de: Scheduling FlushDeltaMemStoresOp(2ba6ce16708e4e529040d74b2aefa66d): perf score=2.188937
I20260812 06:19:57.251210 21901 maintenance_manager.cc:643] P adc4af581caa449aabf038e2b55c35de: FlushDeltaMemStoresOp(2ba6ce16708e4e529040d74b2aefa66d) complete. Timing: real 0.016s	user 0.003s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5034,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:57.251677 21996 maintenance_manager.cc:419] P adc4af581caa449aabf038e2b55c35de: Scheduling MajorDeltaCompactionOp(2ba6ce16708e4e529040d74b2aefa66d): perf score=1.000000
I20260812 06:19:57.395085 21901 maintenance_manager.cc:643] P adc4af581caa449aabf038e2b55c35de: MajorDeltaCompactionOp(2ba6ce16708e4e529040d74b2aefa66d) complete. Timing: real 0.143s	user 0.106s	sys 0.031s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24815685,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":289,"lbm_read_time_us":10642,"lbm_reads_lt_1ms":564,"lbm_write_time_us":25201,"lbm_writes_lt_1ms":543,"mutex_wait_us":80,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":896,"update_count":2500}
I20260812 06:19:57.395744 21996 maintenance_manager.cc:419] P adc4af581caa449aabf038e2b55c35de: Scheduling FlushDeltaMemStoresOp(2ba6ce16708e4e529040d74b2aefa66d): perf score=14.095187
I20260812 06:19:57.447247 21901 maintenance_manager.cc:643] P adc4af581caa449aabf038e2b55c35de: FlushDeltaMemStoresOp(2ba6ce16708e4e529040d74b2aefa66d) complete. Timing: real 0.051s	user 0.022s	sys 0.016s Metrics: {"bytes_written":16409904,"delete_count":0,"lbm_write_time_us":17516,"lbm_writes_lt_1ms":403,"reinsert_count":0,"spinlock_wait_cycles":2304,"update_count":2000}
I20260812 06:19:57.447751 21996 maintenance_manager.cc:419] P adc4af581caa449aabf038e2b55c35de: Scheduling FlushDeltaMemStoresOp(2ba6ce16708e4e529040d74b2aefa66d): perf score=2.188937
I20260812 06:19:57.460565 21901 maintenance_manager.cc:643] P adc4af581caa449aabf038e2b55c35de: FlushDeltaMemStoresOp(2ba6ce16708e4e529040d74b2aefa66d) complete. Timing: real 0.013s	user 0.011s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4542,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:57.461256 21996 maintenance_manager.cc:419] P adc4af581caa449aabf038e2b55c35de: Scheduling MajorDeltaCompactionOp(2ba6ce16708e4e529040d74b2aefa66d): perf score=1.000000
I20260812 06:19:57.627143 21901 maintenance_manager.cc:643] P adc4af581caa449aabf038e2b55c35de: MajorDeltaCompactionOp(2ba6ce16708e4e529040d74b2aefa66d) complete. Timing: real 0.166s	user 0.105s	sys 0.060s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24815686,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":503,"lbm_read_time_us":11604,"lbm_reads_lt_1ms":572,"lbm_write_time_us":25603,"lbm_writes_lt_1ms":543,"mutex_wait_us":50,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":5632,"update_count":2500}
I20260812 06:19:57.627691 21996 maintenance_manager.cc:419] P adc4af581caa449aabf038e2b55c35de: Scheduling FlushDeltaMemStoresOp(2ba6ce16708e4e529040d74b2aefa66d): perf score=14.095187
I20260812 06:19:57.670686 21901 maintenance_manager.cc:643] P adc4af581caa449aabf038e2b55c35de: FlushDeltaMemStoresOp(2ba6ce16708e4e529040d74b2aefa66d) complete. Timing: real 0.043s	user 0.029s	sys 0.011s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":18411,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:57.671317 21996 maintenance_manager.cc:419] P adc4af581caa449aabf038e2b55c35de: Scheduling MajorDeltaCompactionOp(2ba6ce16708e4e529040d74b2aefa66d): perf score=1.000000
I20260812 06:19:57.818873 21901 maintenance_manager.cc:643] P adc4af581caa449aabf038e2b55c35de: MajorDeltaCompactionOp(2ba6ce16708e4e529040d74b2aefa66d) complete. Timing: real 0.147s	user 0.084s	sys 0.062s Metrics: {"cfile_cache_miss":431,"cfile_cache_miss_bytes":20713153,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":1,"delta_iterators_relevant":1,"dirs.queue_time_us":332,"lbm_read_time_us":11200,"lbm_reads_lt_1ms":463,"lbm_write_time_us":23868,"lbm_writes_lt_1ms":443,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":10880,"update_count":2000}
I20260812 06:19:57.819444 21996 maintenance_manager.cc:419] P adc4af581caa449aabf038e2b55c35de: Scheduling FlushDeltaMemStoresOp(2ba6ce16708e4e529040d74b2aefa66d): perf score=14.095187
I20260812 06:19:57.867282 21901 maintenance_manager.cc:643] P adc4af581caa449aabf038e2b55c35de: FlushDeltaMemStoresOp(2ba6ce16708e4e529040d74b2aefa66d) complete. Timing: real 0.048s	user 0.020s	sys 0.025s Metrics: {"bytes_written":16409903,"delete_count":0,"lbm_write_time_us":20242,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:57.867736 21996 maintenance_manager.cc:419] P adc4af581caa449aabf038e2b55c35de: Scheduling FlushDeltaMemStoresOp(2ba6ce16708e4e529040d74b2aefa66d): perf score=2.188937
I20260812 06:19:57.879602 21901 maintenance_manager.cc:643] P adc4af581caa449aabf038e2b55c35de: FlushDeltaMemStoresOp(2ba6ce16708e4e529040d74b2aefa66d) complete. Timing: real 0.012s	user 0.008s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4294,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:57.880353 21996 maintenance_manager.cc:419] P adc4af581caa449aabf038e2b55c35de: Scheduling MajorDeltaCompactionOp(2ba6ce16708e4e529040d74b2aefa66d): perf score=1.000000
I20260812 06:19:58.059146 21901 maintenance_manager.cc:643] P adc4af581caa449aabf038e2b55c35de: MajorDeltaCompactionOp(2ba6ce16708e4e529040d74b2aefa66d) complete. Timing: real 0.179s	user 0.104s	sys 0.060s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24815685,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":205,"lbm_read_time_us":10396,"lbm_reads_lt_1ms":564,"lbm_write_time_us":25820,"lbm_writes_lt_1ms":543,"peak_mem_usage":63115900,"reinsert_count":0,"update_count":2500}
I20260812 06:19:58.059680 21996 maintenance_manager.cc:419] P adc4af581caa449aabf038e2b55c35de: Scheduling FlushDeltaMemStoresOp(2ba6ce16708e4e529040d74b2aefa66d): perf score=14.095187
I20260812 06:19:58.111575 21901 maintenance_manager.cc:643] P adc4af581caa449aabf038e2b55c35de: FlushDeltaMemStoresOp(2ba6ce16708e4e529040d74b2aefa66d) complete. Timing: real 0.052s	user 0.024s	sys 0.020s Metrics: {"bytes_written":16409907,"delete_count":0,"lbm_write_time_us":20415,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:58.112164 21996 maintenance_manager.cc:419] P adc4af581caa449aabf038e2b55c35de: Scheduling FlushDeltaMemStoresOp(2ba6ce16708e4e529040d74b2aefa66d): perf score=2.188937
I20260812 06:19:58.123174 21901 maintenance_manager.cc:643] P adc4af581caa449aabf038e2b55c35de: FlushDeltaMemStoresOp(2ba6ce16708e4e529040d74b2aefa66d) complete. Timing: real 0.011s	user 0.000s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3858,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:58.123658 21996 maintenance_manager.cc:419] P adc4af581caa449aabf038e2b55c35de: Scheduling MajorDeltaCompactionOp(2ba6ce16708e4e529040d74b2aefa66d): perf score=1.000000
I20260812 06:19:58.271652 21901 maintenance_manager.cc:643] P adc4af581caa449aabf038e2b55c35de: MajorDeltaCompactionOp(2ba6ce16708e4e529040d74b2aefa66d) complete. Timing: real 0.148s	user 0.125s	sys 0.016s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24815689,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":1055,"lbm_read_time_us":11251,"lbm_reads_lt_1ms":572,"lbm_write_time_us":26735,"lbm_writes_lt_1ms":543,"mutex_wait_us":539,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":14336,"update_count":2500}
I20260812 06:19:58.272168 21996 maintenance_manager.cc:419] P adc4af581caa449aabf038e2b55c35de: Scheduling FlushDeltaMemStoresOp(2ba6ce16708e4e529040d74b2aefa66d): perf score=11.118625
I20260812 06:19:58.310412 21901 maintenance_manager.cc:643] P adc4af581caa449aabf038e2b55c35de: FlushDeltaMemStoresOp(2ba6ce16708e4e529040d74b2aefa66d) complete. Timing: real 0.038s	user 0.026s	sys 0.011s Metrics: {"bytes_written":12717734,"delete_count":0,"lbm_write_time_us":15937,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:19:58.311097 21996 maintenance_manager.cc:419] P adc4af581caa449aabf038e2b55c35de: Scheduling FlushDeltaMemStoresOp(2ba6ce16708e4e529040d74b2aefa66d): perf score=2.188937
I20260812 06:19:58.328336 21901 maintenance_manager.cc:643] P adc4af581caa449aabf038e2b55c35de: FlushDeltaMemStoresOp(2ba6ce16708e4e529040d74b2aefa66d) complete. Timing: real 0.017s	user 0.006s	sys 0.005s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":7064,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":92,"reinsert_count":0,"update_count":450}
I20260812 06:19:58.328953 21996 maintenance_manager.cc:419] P adc4af581caa449aabf038e2b55c35de: Scheduling FlushMRSOp(2ba6ce16708e4e529040d74b2aefa66d): perf score=1.000000
I20260812 06:19:58.366348 21901 maintenance_manager.cc:643] P adc4af581caa449aabf038e2b55c35de: FlushMRSOp(2ba6ce16708e4e529040d74b2aefa66d) complete. Timing: real 0.037s	user 0.025s	sys 0.001s Metrics: {"bytes_written":1275449,"cfile_init":1,"dirs.queue_time_us":54,"dirs.run_cpu_time_us":176,"dirs.run_wall_time_us":1143,"drs_written":1,"lbm_read_time_us":58,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1530,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":31}
I20260812 06:19:58.367110 21996 maintenance_manager.cc:419] P adc4af581caa449aabf038e2b55c35de: Scheduling UndoDeltaBlockGCOp(2ba6ce16708e4e529040d74b2aefa66d): 482 bytes on disk
I20260812 06:19:58.367516 21901 maintenance_manager.cc:643] P adc4af581caa449aabf038e2b55c35de: UndoDeltaBlockGCOp(2ba6ce16708e4e529040d74b2aefa66d) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":45,"lbm_reads_lt_1ms":4}
I20260812 06:19:58.368201 21996 maintenance_manager.cc:419] P adc4af581caa449aabf038e2b55c35de: Scheduling FlushDeltaMemStoresOp(2ba6ce16708e4e529040d74b2aefa66d): perf score=3.181125
I20260812 06:19:58.380851 21901 maintenance_manager.cc:643] P adc4af581caa449aabf038e2b55c35de: FlushDeltaMemStoresOp(2ba6ce16708e4e529040d74b2aefa66d) complete. Timing: real 0.012s	user 0.006s	sys 0.003s Metrics: {"bytes_written":4512901,"delete_count":0,"lbm_write_time_us":4047,"lbm_writes_lt_1ms":113,"reinsert_count":0,"update_count":550}
I20260812 06:19:58.381389 21996 maintenance_manager.cc:419] P adc4af581caa449aabf038e2b55c35de: Scheduling LogGCOp(2ba6ce16708e4e529040d74b2aefa66d): free 129320520 bytes of WAL
I20260812 06:19:58.381623 21901 log_reader.cc:385] T 2ba6ce16708e4e529040d74b2aefa66d: removed 13 log segments from log reader
I20260812 06:19:58.381686 21901 log.cc:1079] T 2ba6ce16708e4e529040d74b2aefa66d P adc4af581caa449aabf038e2b55c35de: Deleting log segment in path: /tmp/dist-test-tasktjZuXx/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515590048853-21414-0/minicluster-data/ts-0-root/wals/2ba6ce16708e4e529040d74b2aefa66d/wal-000000015 (ops 71-75)
I20260812 06:19:58.381731 21901 log.cc:1079] T 2ba6ce16708e4e529040d74b2aefa66d P adc4af581caa449aabf038e2b55c35de: Deleting log segment in path: /tmp/dist-test-tasktjZuXx/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515590048853-21414-0/minicluster-data/ts-0-root/wals/2ba6ce16708e4e529040d74b2aefa66d/wal-000000016 (ops 76-80)
I20260812 06:19:58.381767 21901 log.cc:1079] T 2ba6ce16708e4e529040d74b2aefa66d P adc4af581caa449aabf038e2b55c35de: Deleting log segment in path: /tmp/dist-test-tasktjZuXx/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515590048853-21414-0/minicluster-data/ts-0-root/wals/2ba6ce16708e4e529040d74b2aefa66d/wal-000000017 (ops 81-84)
I20260812 06:19:58.381795 21901 log.cc:1079] T 2ba6ce16708e4e529040d74b2aefa66d P adc4af581caa449aabf038e2b55c35de: Deleting log segment in path: /tmp/dist-test-tasktjZuXx/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515590048853-21414-0/minicluster-data/ts-0-root/wals/2ba6ce16708e4e529040d74b2aefa66d/wal-000000018 (ops 85-89)
I20260812 06:19:58.381824 21901 log.cc:1079] T 2ba6ce16708e4e529040d74b2aefa66d P adc4af581caa449aabf038e2b55c35de: Deleting log segment in path: /tmp/dist-test-tasktjZuXx/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515590048853-21414-0/minicluster-data/ts-0-root/wals/2ba6ce16708e4e529040d74b2aefa66d/wal-000000019 (ops 90-94)
I20260812 06:19:58.381850 21901 log.cc:1079] T 2ba6ce16708e4e529040d74b2aefa66d P adc4af581caa449aabf038e2b55c35de: Deleting log segment in path: /tmp/dist-test-tasktjZuXx/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515590048853-21414-0/minicluster-data/ts-0-root/wals/2ba6ce16708e4e529040d74b2aefa66d/wal-000000020 (ops 95-98)
I20260812 06:19:58.381878 21901 log.cc:1079] T 2ba6ce16708e4e529040d74b2aefa66d P adc4af581caa449aabf038e2b55c35de: Deleting log segment in path: /tmp/dist-test-tasktjZuXx/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515590048853-21414-0/minicluster-data/ts-0-root/wals/2ba6ce16708e4e529040d74b2aefa66d/wal-000000021 (ops 99-103)
I20260812 06:19:58.381922 21901 log.cc:1079] T 2ba6ce16708e4e529040d74b2aefa66d P adc4af581caa449aabf038e2b55c35de: Deleting log segment in path: /tmp/dist-test-tasktjZuXx/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515590048853-21414-0/minicluster-data/ts-0-root/wals/2ba6ce16708e4e529040d74b2aefa66d/wal-000000022 (ops 104-108)
I20260812 06:19:58.381951 21901 log.cc:1079] T 2ba6ce16708e4e529040d74b2aefa66d P adc4af581caa449aabf038e2b55c35de: Deleting log segment in path: /tmp/dist-test-tasktjZuXx/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515590048853-21414-0/minicluster-data/ts-0-root/wals/2ba6ce16708e4e529040d74b2aefa66d/wal-000000023 (ops 109-113)
I20260812 06:19:58.381980 21901 log.cc:1079] T 2ba6ce16708e4e529040d74b2aefa66d P adc4af581caa449aabf038e2b55c35de: Deleting log segment in path: /tmp/dist-test-tasktjZuXx/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515590048853-21414-0/minicluster-data/ts-0-root/wals/2ba6ce16708e4e529040d74b2aefa66d/wal-000000024 (ops 114-118)
I20260812 06:19:58.382007 21901 log.cc:1079] T 2ba6ce16708e4e529040d74b2aefa66d P adc4af581caa449aabf038e2b55c35de: Deleting log segment in path: /tmp/dist-test-tasktjZuXx/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515590048853-21414-0/minicluster-data/ts-0-root/wals/2ba6ce16708e4e529040d74b2aefa66d/wal-000000025 (ops 119-123)
I20260812 06:19:58.382035 21901 log.cc:1079] T 2ba6ce16708e4e529040d74b2aefa66d P adc4af581caa449aabf038e2b55c35de: Deleting log segment in path: /tmp/dist-test-tasktjZuXx/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515590048853-21414-0/minicluster-data/ts-0-root/wals/2ba6ce16708e4e529040d74b2aefa66d/wal-000000026 (ops 124-128)
I20260812 06:19:58.382068 21901 log.cc:1079] T 2ba6ce16708e4e529040d74b2aefa66d P adc4af581caa449aabf038e2b55c35de: Deleting log segment in path: /tmp/dist-test-tasktjZuXx/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515590048853-21414-0/minicluster-data/ts-0-root/wals/2ba6ce16708e4e529040d74b2aefa66d/wal-000000027 (ops 129-133)
I20260812 06:19:58.410630 21901 maintenance_manager.cc:643] P adc4af581caa449aabf038e2b55c35de: LogGCOp(2ba6ce16708e4e529040d74b2aefa66d) complete. Timing: real 0.029s	user 0.000s	sys 0.027s Metrics: {}
I20260812 06:19:58.411085 21996 maintenance_manager.cc:419] P adc4af581caa449aabf038e2b55c35de: Scheduling FlushDeltaMemStoresOp(2ba6ce16708e4e529040d74b2aefa66d): perf score=2.188937
I20260812 06:19:58.439996 21901 maintenance_manager.cc:643] P adc4af581caa449aabf038e2b55c35de: FlushDeltaMemStoresOp(2ba6ce16708e4e529040d74b2aefa66d) complete. Timing: real 0.029s	user 0.014s	sys 0.011s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6844,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:58.440536 21996 maintenance_manager.cc:419] P adc4af581caa449aabf038e2b55c35de: Scheduling FlushDeltaMemStoresOp(2ba6ce16708e4e529040d74b2aefa66d): perf score=2.188937
I20260812 06:19:58.450842 21901 maintenance_manager.cc:643] P adc4af581caa449aabf038e2b55c35de: FlushDeltaMemStoresOp(2ba6ce16708e4e529040d74b2aefa66d) complete. Timing: real 0.010s	user 0.008s	sys 0.000s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3833,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:19:58.451292 21996 maintenance_manager.cc:419] P adc4af581caa449aabf038e2b55c35de: Scheduling MajorDeltaCompactionOp(2ba6ce16708e4e529040d74b2aefa66d): perf score=1.000000
I20260812 06:19:58.681078 21901 maintenance_manager.cc:643] P adc4af581caa449aabf038e2b55c35de: MajorDeltaCompactionOp(2ba6ce16708e4e529040d74b2aefa66d) complete. Timing: real 0.230s	user 0.134s	sys 0.096s Metrics: {"cfile_cache_miss":735,"cfile_cache_miss_bytes":33020843,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":5,"delta_iterators_relevant":5,"dirs.queue_time_us":535,"lbm_read_time_us":16959,"lbm_reads_lt_1ms":775,"lbm_write_time_us":41153,"lbm_writes_lt_1ms":743,"mutex_wait_us":75,"peak_mem_usage":87969044,"reinsert_count":0,"thread_start_us":94,"threads_started":1,"update_count":3500}
I20260812 06:19:58.684262 21996 maintenance_manager.cc:419] P adc4af581caa449aabf038e2b55c35de: Scheduling FlushDeltaMemStoresOp(2ba6ce16708e4e529040d74b2aefa66d): perf score=15.087375
I20260812 06:19:58.759886 21901 maintenance_manager.cc:643] P adc4af581caa449aabf038e2b55c35de: FlushDeltaMemStoresOp(2ba6ce16708e4e529040d74b2aefa66d) complete. Timing: real 0.075s	user 0.045s	sys 0.014s Metrics: {"bytes_written":16943219,"delete_count":0,"lbm_write_time_us":31720,"lbm_writes_1-10_ms":3,"lbm_writes_lt_1ms":413,"reinsert_count":0,"update_count":2065}
I20260812 06:19:58.760419 21996 maintenance_manager.cc:419] P adc4af581caa449aabf038e2b55c35de: Scheduling FlushDeltaMemStoresOp(2ba6ce16708e4e529040d74b2aefa66d): perf score=6.157687
I20260812 06:19:58.783625 21901 maintenance_manager.cc:643] P adc4af581caa449aabf038e2b55c35de: FlushDeltaMemStoresOp(2ba6ce16708e4e529040d74b2aefa66d) complete. Timing: real 0.023s	user 0.011s	sys 0.007s Metrics: {"bytes_written":7671765,"delete_count":0,"lbm_write_time_us":8451,"lbm_writes_lt_1ms":190,"reinsert_count":0,"update_count":935}
I20260812 06:19:58.784192 21996 maintenance_manager.cc:419] P adc4af581caa449aabf038e2b55c35de: Scheduling MajorDeltaCompactionOp(2ba6ce16708e4e529040d74b2aefa66d): perf score=1.000000
I20260812 06:19:58.995407 21901 maintenance_manager.cc:643] P adc4af581caa449aabf038e2b55c35de: MajorDeltaCompactionOp(2ba6ce16708e4e529040d74b2aefa66d) complete. Timing: real 0.211s	user 0.133s	sys 0.071s Metrics: {"cfile_cache_miss":632,"cfile_cache_miss_bytes":28918101,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":327,"lbm_read_time_us":12676,"lbm_reads_lt_1ms":664,"lbm_write_time_us":38304,"lbm_writes_lt_1ms":643,"mutex_wait_us":66,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":1920,"update_count":3000}
I20260812 06:19:58.996047 21996 maintenance_manager.cc:419] P adc4af581caa449aabf038e2b55c35de: Scheduling FlushDeltaMemStoresOp(2ba6ce16708e4e529040d74b2aefa66d): perf score=18.063937
I20260812 06:19:59.058969 21901 maintenance_manager.cc:643] P adc4af581caa449aabf038e2b55c35de: FlushDeltaMemStoresOp(2ba6ce16708e4e529040d74b2aefa66d) complete. Timing: real 0.063s	user 0.021s	sys 0.027s Metrics: {"bytes_written":20512316,"delete_count":0,"lbm_write_time_us":22430,"lbm_writes_lt_1ms":503,"reinsert_count":0,"update_count":2500}
I20260812 06:19:59.059553 21996 maintenance_manager.cc:419] P adc4af581caa449aabf038e2b55c35de: Scheduling FlushDeltaMemStoresOp(2ba6ce16708e4e529040d74b2aefa66d): perf score=2.188937
I20260812 06:19:59.075103 21901 maintenance_manager.cc:643] P adc4af581caa449aabf038e2b55c35de: FlushDeltaMemStoresOp(2ba6ce16708e4e529040d74b2aefa66d) complete. Timing: real 0.015s	user 0.009s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5550,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:59.075670 21996 maintenance_manager.cc:419] P adc4af581caa449aabf038e2b55c35de: Scheduling MajorDeltaCompactionOp(2ba6ce16708e4e529040d74b2aefa66d): perf score=1.000000
I20260812 06:19:59.256264 21901 maintenance_manager.cc:643] P adc4af581caa449aabf038e2b55c35de: MajorDeltaCompactionOp(2ba6ce16708e4e529040d74b2aefa66d) complete. Timing: real 0.180s	user 0.128s	sys 0.052s Metrics: {"cfile_cache_miss":632,"cfile_cache_miss_bytes":28918098,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":407,"lbm_read_time_us":13040,"lbm_reads_lt_1ms":672,"lbm_write_time_us":28205,"lbm_writes_lt_1ms":643,"mutex_wait_us":2,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":3072,"update_count":3000}
I20260812 06:19:59.256832 21996 maintenance_manager.cc:419] P adc4af581caa449aabf038e2b55c35de: Scheduling FlushDeltaMemStoresOp(2ba6ce16708e4e529040d74b2aefa66d): perf score=14.095187
I20260812 06:19:59.310431 21901 maintenance_manager.cc:643] P adc4af581caa449aabf038e2b55c35de: FlushDeltaMemStoresOp(2ba6ce16708e4e529040d74b2aefa66d) complete. Timing: real 0.053s	user 0.040s	sys 0.011s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":25809,"lbm_writes_1-10_ms":2,"lbm_writes_lt_1ms":401,"reinsert_count":0,"update_count":2000}
I20260812 06:19:59.311000 21996 maintenance_manager.cc:419] P adc4af581caa449aabf038e2b55c35de: Scheduling FlushDeltaMemStoresOp(2ba6ce16708e4e529040d74b2aefa66d): perf score=3.181125
I20260812 06:19:59.326294 21901 maintenance_manager.cc:643] P adc4af581caa449aabf038e2b55c35de: FlushDeltaMemStoresOp(2ba6ce16708e4e529040d74b2aefa66d) complete. Timing: real 0.015s	user 0.002s	sys 0.008s Metrics: {"bytes_written":4512900,"delete_count":0,"lbm_write_time_us":4057,"lbm_writes_lt_1ms":113,"reinsert_count":0,"update_count":550}
I20260812 06:19:59.326788 21996 maintenance_manager.cc:419] P adc4af581caa449aabf038e2b55c35de: Scheduling FlushDeltaMemStoresOp(2ba6ce16708e4e529040d74b2aefa66d): perf score=2.188937
I20260812 06:19:59.340083 21901 maintenance_manager.cc:643] P adc4af581caa449aabf038e2b55c35de: FlushDeltaMemStoresOp(2ba6ce16708e4e529040d74b2aefa66d) complete. Timing: real 0.013s	user 0.011s	sys 0.000s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":4733,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:19:59.340656 21996 maintenance_manager.cc:419] P adc4af581caa449aabf038e2b55c35de: Scheduling MajorDeltaCompactionOp(2ba6ce16708e4e529040d74b2aefa66d): perf score=1.000000
I20260812 06:19:59.529222 21901 maintenance_manager.cc:643] P adc4af581caa449aabf038e2b55c35de: MajorDeltaCompactionOp(2ba6ce16708e4e529040d74b2aefa66d) complete. Timing: real 0.188s	user 0.124s	sys 0.064s Metrics: {"cfile_cache_miss":633,"cfile_cache_miss_bytes":28918202,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":714,"lbm_read_time_us":12850,"lbm_reads_lt_1ms":673,"lbm_write_time_us":31035,"lbm_writes_lt_1ms":643,"mutex_wait_us":334,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":1536,"update_count":3000}
I20260812 06:19:59.529829 21996 maintenance_manager.cc:419] P adc4af581caa449aabf038e2b55c35de: Scheduling FlushDeltaMemStoresOp(2ba6ce16708e4e529040d74b2aefa66d): perf score=14.095187
I20260812 06:19:59.582490 21901 maintenance_manager.cc:643] P adc4af581caa449aabf038e2b55c35de: FlushDeltaMemStoresOp(2ba6ce16708e4e529040d74b2aefa66d) complete. Timing: real 0.052s	user 0.030s	sys 0.020s Metrics: {"bytes_written":16409904,"delete_count":0,"lbm_write_time_us":24029,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":402,"reinsert_count":0,"update_count":2000}
I20260812 06:19:59.583087 21996 maintenance_manager.cc:419] P adc4af581caa449aabf038e2b55c35de: Scheduling FlushDeltaMemStoresOp(2ba6ce16708e4e529040d74b2aefa66d): perf score=2.188937
I20260812 06:19:59.594996 21901 maintenance_manager.cc:643] P adc4af581caa449aabf038e2b55c35de: FlushDeltaMemStoresOp(2ba6ce16708e4e529040d74b2aefa66d) complete. Timing: real 0.012s	user 0.003s	sys 0.007s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4448,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:59.595608 21996 maintenance_manager.cc:419] P adc4af581caa449aabf038e2b55c35de: Scheduling MajorDeltaCompactionOp(2ba6ce16708e4e529040d74b2aefa66d): perf score=1.000000
I20260812 06:19:59.775375 21901 maintenance_manager.cc:643] P adc4af581caa449aabf038e2b55c35de: MajorDeltaCompactionOp(2ba6ce16708e4e529040d74b2aefa66d) complete. Timing: real 0.180s	user 0.131s	sys 0.048s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24815686,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":899,"lbm_read_time_us":12342,"lbm_reads_lt_1ms":572,"lbm_write_time_us":32550,"lbm_writes_lt_1ms":543,"mutex_wait_us":44,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":27648,"update_count":2500}
I20260812 06:19:59.775985 21996 maintenance_manager.cc:419] P adc4af581caa449aabf038e2b55c35de: Scheduling FlushDeltaMemStoresOp(2ba6ce16708e4e529040d74b2aefa66d): perf score=14.095187
I20260812 06:19:59.828953 21901 maintenance_manager.cc:643] P adc4af581caa449aabf038e2b55c35de: FlushDeltaMemStoresOp(2ba6ce16708e4e529040d74b2aefa66d) complete. Timing: real 0.053s	user 0.031s	sys 0.016s Metrics: {"bytes_written":16409900,"delete_count":0,"lbm_write_time_us":22759,"lbm_writes_1-10_ms":2,"lbm_writes_lt_1ms":401,"reinsert_count":0,"update_count":2000}
I20260812 06:19:59.829735 21996 maintenance_manager.cc:419] P adc4af581caa449aabf038e2b55c35de: Scheduling FlushDeltaMemStoresOp(2ba6ce16708e4e529040d74b2aefa66d): perf score=2.188937
I20260812 06:19:59.845970 21901 maintenance_manager.cc:643] P adc4af581caa449aabf038e2b55c35de: FlushDeltaMemStoresOp(2ba6ce16708e4e529040d74b2aefa66d) complete. Timing: real 0.016s	user 0.012s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4794,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:59.846457 21996 maintenance_manager.cc:419] P adc4af581caa449aabf038e2b55c35de: Scheduling FlushMRSOp(2ba6ce16708e4e529040d74b2aefa66d): perf score=1.000000
I20260812 06:19:59.896142 21901 maintenance_manager.cc:643] P adc4af581caa449aabf038e2b55c35de: FlushMRSOp(2ba6ce16708e4e529040d74b2aefa66d) complete. Timing: real 0.050s	user 0.024s	sys 0.003s Metrics: {"bytes_written":1275447,"cfile_init":1,"dirs.queue_time_us":34,"dirs.run_cpu_time_us":209,"dirs.run_wall_time_us":1239,"drs_written":1,"lbm_read_time_us":63,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1736,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":31}
I20260812 06:19:59.896970 21996 maintenance_manager.cc:419] P adc4af581caa449aabf038e2b55c35de: Scheduling LogGCOp(2ba6ce16708e4e529040d74b2aefa66d): free 120100588 bytes of WAL
I20260812 06:19:59.897269 21901 log_reader.cc:385] T 2ba6ce16708e4e529040d74b2aefa66d: removed 12 log segments from log reader
I20260812 06:19:59.897341 21901 log.cc:1079] T 2ba6ce16708e4e529040d74b2aefa66d P adc4af581caa449aabf038e2b55c35de: Deleting log segment in path: /tmp/dist-test-tasktjZuXx/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515590048853-21414-0/minicluster-data/ts-0-root/wals/2ba6ce16708e4e529040d74b2aefa66d/wal-000000028 (ops 134-138)
I20260812 06:19:59.897396 21901 log.cc:1079] T 2ba6ce16708e4e529040d74b2aefa66d P adc4af581caa449aabf038e2b55c35de: Deleting log segment in path: /tmp/dist-test-tasktjZuXx/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515590048853-21414-0/minicluster-data/ts-0-root/wals/2ba6ce16708e4e529040d74b2aefa66d/wal-000000029 (ops 139-143)
I20260812 06:19:59.897464 21901 log.cc:1079] T 2ba6ce16708e4e529040d74b2aefa66d P adc4af581caa449aabf038e2b55c35de: Deleting log segment in path: /tmp/dist-test-tasktjZuXx/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515590048853-21414-0/minicluster-data/ts-0-root/wals/2ba6ce16708e4e529040d74b2aefa66d/wal-000000030 (ops 144-148)
I20260812 06:19:59.897511 21901 log.cc:1079] T 2ba6ce16708e4e529040d74b2aefa66d P adc4af581caa449aabf038e2b55c35de: Deleting log segment in path: /tmp/dist-test-tasktjZuXx/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515590048853-21414-0/minicluster-data/ts-0-root/wals/2ba6ce16708e4e529040d74b2aefa66d/wal-000000031 (ops 149-152)
I20260812 06:19:59.897579 21901 log.cc:1079] T 2ba6ce16708e4e529040d74b2aefa66d P adc4af581caa449aabf038e2b55c35de: Deleting log segment in path: /tmp/dist-test-tasktjZuXx/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515590048853-21414-0/minicluster-data/ts-0-root/wals/2ba6ce16708e4e529040d74b2aefa66d/wal-000000032 (ops 153-157)
I20260812 06:19:59.897635 21901 log.cc:1079] T 2ba6ce16708e4e529040d74b2aefa66d P adc4af581caa449aabf038e2b55c35de: Deleting log segment in path: /tmp/dist-test-tasktjZuXx/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515590048853-21414-0/minicluster-data/ts-0-root/wals/2ba6ce16708e4e529040d74b2aefa66d/wal-000000033 (ops 158-162)
I20260812 06:19:59.897679 21901 log.cc:1079] T 2ba6ce16708e4e529040d74b2aefa66d P adc4af581caa449aabf038e2b55c35de: Deleting log segment in path: /tmp/dist-test-tasktjZuXx/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515590048853-21414-0/minicluster-data/ts-0-root/wals/2ba6ce16708e4e529040d74b2aefa66d/wal-000000034 (ops 163-167)
I20260812 06:19:59.897720 21901 log.cc:1079] T 2ba6ce16708e4e529040d74b2aefa66d P adc4af581caa449aabf038e2b55c35de: Deleting log segment in path: /tmp/dist-test-tasktjZuXx/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515590048853-21414-0/minicluster-data/ts-0-root/wals/2ba6ce16708e4e529040d74b2aefa66d/wal-000000035 (ops 168-172)
I20260812 06:19:59.897754 21901 log.cc:1079] T 2ba6ce16708e4e529040d74b2aefa66d P adc4af581caa449aabf038e2b55c35de: Deleting log segment in path: /tmp/dist-test-tasktjZuXx/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515590048853-21414-0/minicluster-data/ts-0-root/wals/2ba6ce16708e4e529040d74b2aefa66d/wal-000000036 (ops 173-176)
I20260812 06:19:59.897776 21901 log.cc:1079] T 2ba6ce16708e4e529040d74b2aefa66d P adc4af581caa449aabf038e2b55c35de: Deleting log segment in path: /tmp/dist-test-tasktjZuXx/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515590048853-21414-0/minicluster-data/ts-0-root/wals/2ba6ce16708e4e529040d74b2aefa66d/wal-000000037 (ops 177-181)
I20260812 06:19:59.897841 21901 log.cc:1079] T 2ba6ce16708e4e529040d74b2aefa66d P adc4af581caa449aabf038e2b55c35de: Deleting log segment in path: /tmp/dist-test-tasktjZuXx/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515590048853-21414-0/minicluster-data/ts-0-root/wals/2ba6ce16708e4e529040d74b2aefa66d/wal-000000038 (ops 182-186)
I20260812 06:19:59.897881 21901 log.cc:1079] T 2ba6ce16708e4e529040d74b2aefa66d P adc4af581caa449aabf038e2b55c35de: Deleting log segment in path: /tmp/dist-test-tasktjZuXx/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515590048853-21414-0/minicluster-data/ts-0-root/wals/2ba6ce16708e4e529040d74b2aefa66d/wal-000000039 (ops 187-190)
I20260812 06:19:59.919246 21901 maintenance_manager.cc:643] P adc4af581caa449aabf038e2b55c35de: LogGCOp(2ba6ce16708e4e529040d74b2aefa66d) complete. Timing: real 0.022s	user 0.000s	sys 0.019s Metrics: {}
I20260812 06:19:59.919688 21996 maintenance_manager.cc:419] P adc4af581caa449aabf038e2b55c35de: Scheduling UndoDeltaBlockGCOp(2ba6ce16708e4e529040d74b2aefa66d): 482 bytes on disk
I20260812 06:19:59.920190 21901 maintenance_manager.cc:643] P adc4af581caa449aabf038e2b55c35de: UndoDeltaBlockGCOp(2ba6ce16708e4e529040d74b2aefa66d) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":58,"lbm_reads_lt_1ms":4}
I20260812 06:19:59.920886 21996 maintenance_manager.cc:419] P adc4af581caa449aabf038e2b55c35de: Scheduling FlushDeltaMemStoresOp(2ba6ce16708e4e529040d74b2aefa66d): perf score=6.157687
I20260812 06:19:59.941534 21901 maintenance_manager.cc:643] P adc4af581caa449aabf038e2b55c35de: FlushDeltaMemStoresOp(2ba6ce16708e4e529040d74b2aefa66d) complete. Timing: real 0.020s	user 0.013s	sys 0.005s Metrics: {"bytes_written":8205078,"delete_count":0,"lbm_write_time_us":7415,"lbm_writes_lt_1ms":203,"reinsert_count":0,"update_count":1000}
I20260812 06:19:59.942023 21996 maintenance_manager.cc:419] P adc4af581caa449aabf038e2b55c35de: Scheduling LogGCOp(2ba6ce16708e4e529040d74b2aefa66d): free 8767140 bytes of WAL
I20260812 06:19:59.942241 21901 log_reader.cc:385] T 2ba6ce16708e4e529040d74b2aefa66d: removed 1 log segments from log reader
I20260812 06:19:59.942291 21901 log.cc:1079] T 2ba6ce16708e4e529040d74b2aefa66d P adc4af581caa449aabf038e2b55c35de: Deleting log segment in path: /tmp/dist-test-tasktjZuXx/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515590048853-21414-0/minicluster-data/ts-0-root/wals/2ba6ce16708e4e529040d74b2aefa66d/wal-000000040 (ops 191-195)
I20260812 06:19:59.943758 21901 maintenance_manager.cc:643] P adc4af581caa449aabf038e2b55c35de: LogGCOp(2ba6ce16708e4e529040d74b2aefa66d) complete. Timing: real 0.002s	user 0.000s	sys 0.000s Metrics: {}
I20260812 06:19:59.944074 21996 maintenance_manager.cc:419] P adc4af581caa449aabf038e2b55c35de: Scheduling FlushDeltaMemStoresOp(2ba6ce16708e4e529040d74b2aefa66d): perf score=2.188937
I20260812 06:19:59.954206 21901 maintenance_manager.cc:643] P adc4af581caa449aabf038e2b55c35de: FlushDeltaMemStoresOp(2ba6ce16708e4e529040d74b2aefa66d) complete. Timing: real 0.010s	user 0.009s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3611,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:59.954785 21996 maintenance_manager.cc:419] P adc4af581caa449aabf038e2b55c35de: Scheduling MajorDeltaCompactionOp(2ba6ce16708e4e529040d74b2aefa66d): perf score=1.000000
I20260812 06:20:00.029366 21414 heavy-update-compaction-itest.cc:229] Time spent updating: real 4.609s	user 1.724s	sys 0.135s
I20260812 06:20:00.127110 21414 heavy-update-compaction-itest.cc:265] Time spent scanning: real 0.097s	user 0.001s	sys 0.000s
I20260812 06:20:00.127676 21414 tablet_server.cc:179] TabletServer@127.20.233.129:0 shutting down...
I20260812 06:20:00.163110 21901 maintenance_manager.cc:643] P adc4af581caa449aabf038e2b55c35de: MajorDeltaCompactionOp(2ba6ce16708e4e529040d74b2aefa66d) complete. Timing: real 0.208s	user 0.131s	sys 0.075s Metrics: {"cfile_cache_miss":834,"cfile_cache_miss_bytes":37123157,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":423,"lbm_read_time_us":15892,"lbm_reads_lt_1ms":870,"lbm_write_time_us":33253,"lbm_writes_lt_1ms":843,"mutex_wait_us":55,"peak_mem_usage":100395616,"reinsert_count":0,"spinlock_wait_cycles":573312,"thread_start_us":72,"threads_started":1,"update_count":4000}
I20260812 06:20:00.164119 21414 ts_tablet_manager.cc:1507] Shutting down tablet manager...
I20260812 06:20:00.164357 21414 tablet_replica.cc:333] T 2ba6ce16708e4e529040d74b2aefa66d P adc4af581caa449aabf038e2b55c35de: stopping tablet replica
I20260812 06:20:00.164490 21414 raft_consensus.cc:2243] T 2ba6ce16708e4e529040d74b2aefa66d P adc4af581caa449aabf038e2b55c35de [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:20:00.164657 21414 raft_consensus.cc:2272] T 2ba6ce16708e4e529040d74b2aefa66d P adc4af581caa449aabf038e2b55c35de [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:20:00.169059 21414 tablet_server.cc:196] TabletServer@127.20.233.129:0 shutdown complete.
I20260812 06:20:00.231819 21414 master.cc:562] Master@127.20.233.190:35783 shutting down...
I20260812 06:20:00.235157 21414 raft_consensus.cc:2243] T 00000000000000000000000000000000 P becbf340aab64d38be9b437c570cc824 [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:20:00.235342 21414 raft_consensus.cc:2272] T 00000000000000000000000000000000 P becbf340aab64d38be9b437c570cc824 [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:20:00.235411 21414 tablet_replica.cc:333] T 00000000000000000000000000000000 P becbf340aab64d38be9b437c570cc824: stopping tablet replica
I20260812 06:20:00.247598 21414 master.cc:584] Master@127.20.233.190:35783 shutdown complete.
[       OK ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/1 (5079 ms)
[----------] 2 tests from EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy (10261 ms total)

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