[==========] Running 2 tests from 1 test suite.
[----------] Global test environment set-up.
[----------] 2 tests from EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy
[ RUN      ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/0
WARNING: Logging before InitGoogleLogging() is written to STDERR
I20260812 06:18:20.558653 22822 internal_mini_cluster.cc:156] Creating distributed mini masters. Addrs: 127.22.73.190:41271
I20260812 06:18:20.559692 22822 env_posix.cc:2285] Not raising this process' open files per process limit of 1048576; it is already as high as it can go
I20260812 06:18:20.560297 22822 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:18:20.567309 22837 instance_detector.cc:116] could not retrieve OpenStack instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:18:20.567309 22834 instance_detector.cc:116] could not retrieve Azure instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:18:20.567394 22822 server_base.cc:1061] running on GCE node
W20260812 06:18:20.567584 22831 instance_detector.cc:116] could not retrieve AWS instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:18:20.568032 22822 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:18:20.568156 22822 system_unsync_time.cc:38] NTP support is disabled. Clock error bounds will not be accurate. This configuration is not suitable for distributed clusters.
I20260812 06:18:20.568208 22822 hybrid_clock.cc:648] HybridClock initialized: now 1786515500568206 us; error 0 us; skew 500 ppm
I20260812 06:18:20.569934 22822 webserver.cc:533] Webserver started at http://127.22.73.190:45939/ using document root <none> and password file <none>
I20260812 06:18:20.570570 22822 fs_manager.cc:362] Metadata directory not provided
I20260812 06:18:20.570659 22822 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:18:20.570891 22822 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:18:20.572496 22822 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskVApfHZ/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515500541946-22822-0/minicluster-data/master-0-root/instance:
uuid: "b17b81fcd2474997a07ecf6b5975e47c"
format_stamp: "Formatted at 2026-08-12 06:18:20 on dist-test-slave-jztv"
I20260812 06:18:20.575963 22822 fs_manager.cc:696] Time spent creating directory manager: real 0.003s	user 0.005s	sys 0.000s
I20260812 06:18:20.577940 22845 log_block_manager.cc:4127] Time spent loading block containers with low live blocks: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:18:20.578929 22822 fs_manager.cc:730] Time spent opening block manager: real 0.002s	user 0.002s	sys 0.000s
I20260812 06:18:20.579063 22822 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskVApfHZ/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515500541946-22822-0/minicluster-data/master-0-root
uuid: "b17b81fcd2474997a07ecf6b5975e47c"
format_stamp: "Formatted at 2026-08-12 06:18:20 on dist-test-slave-jztv"
I20260812 06:18:20.579165 22822 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskVApfHZ/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515500541946-22822-0/minicluster-data/master-0-root
metadata directory: /tmp/dist-test-taskVApfHZ/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515500541946-22822-0/minicluster-data/master-0-root
1 data directories: /tmp/dist-test-taskVApfHZ/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515500541946-22822-0/minicluster-data/master-0-root/data
Total live blocks: 0
Total live bytes: 0
Total live bytes (after alignment): 0
Total number of LBM containers: 0 (0 full)
Did not check for missing blocks
Did not check for orphaned blocks
Total full LBM containers with extra space: 0 (0 repaired)
Total full LBM container extra space in bytes: 0 (0 repaired)
Total incomplete LBM containers: 0 (0 repaired)
Total LBM partial records: 0 (0 repaired)
Total corrupted LBM metadata records in RocksDB: 0 (0 repaired)
I20260812 06:18:20.607826 22822 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:18:20.608539 22822 env_posix.cc:2285] Not raising this process' running threads per effective uid limit of 18446744073709551615; it is already as high as it can go
I20260812 06:18:20.608736 22822 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:18:20.616372 22822 rpc_server.cc:307] RPC server started. Bound to: 127.22.73.190:41271
I20260812 06:18:20.616396 22942 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.22.73.190:41271 every 8 connection(s)
I20260812 06:18:20.618906 22943 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet 00000000000000000000000000000000. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:18:20.624346 22943 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P b17b81fcd2474997a07ecf6b5975e47c: Bootstrap starting.
I20260812 06:18:20.626662 22943 tablet_bootstrap.cc:654] T 00000000000000000000000000000000 P b17b81fcd2474997a07ecf6b5975e47c: Neither blocks nor log segments found. Creating new log.
I20260812 06:18:20.627513 22943 log.cc:826] T 00000000000000000000000000000000 P b17b81fcd2474997a07ecf6b5975e47c: Log is configured to *not* fsync() on all Append() calls
I20260812 06:18:20.629127 22943 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P b17b81fcd2474997a07ecf6b5975e47c: No bootstrap required, opened a new log
I20260812 06:18:20.631870 22943 raft_consensus.cc:359] T 00000000000000000000000000000000 P b17b81fcd2474997a07ecf6b5975e47c [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "b17b81fcd2474997a07ecf6b5975e47c" member_type: VOTER }
I20260812 06:18:20.632097 22943 raft_consensus.cc:385] T 00000000000000000000000000000000 P b17b81fcd2474997a07ecf6b5975e47c [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:18:20.632197 22943 raft_consensus.cc:740] T 00000000000000000000000000000000 P b17b81fcd2474997a07ecf6b5975e47c [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: b17b81fcd2474997a07ecf6b5975e47c, State: Initialized, Role: FOLLOWER
I20260812 06:18:20.632781 22943 consensus_queue.cc:260] T 00000000000000000000000000000000 P b17b81fcd2474997a07ecf6b5975e47c [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: "b17b81fcd2474997a07ecf6b5975e47c" member_type: VOTER }
I20260812 06:18:20.632922 22943 raft_consensus.cc:399] T 00000000000000000000000000000000 P b17b81fcd2474997a07ecf6b5975e47c [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:18:20.632970 22943 raft_consensus.cc:493] T 00000000000000000000000000000000 P b17b81fcd2474997a07ecf6b5975e47c [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:18:20.633064 22943 raft_consensus.cc:3060] T 00000000000000000000000000000000 P b17b81fcd2474997a07ecf6b5975e47c [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:18:20.633762 22943 raft_consensus.cc:515] T 00000000000000000000000000000000 P b17b81fcd2474997a07ecf6b5975e47c [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "b17b81fcd2474997a07ecf6b5975e47c" member_type: VOTER }
I20260812 06:18:20.634127 22943 leader_election.cc:304] T 00000000000000000000000000000000 P b17b81fcd2474997a07ecf6b5975e47c [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: b17b81fcd2474997a07ecf6b5975e47c; no voters: 
I20260812 06:18:20.634444 22943 leader_election.cc:290] T 00000000000000000000000000000000 P b17b81fcd2474997a07ecf6b5975e47c [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:18:20.634634 22947 raft_consensus.cc:2804] T 00000000000000000000000000000000 P b17b81fcd2474997a07ecf6b5975e47c [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:18:20.634908 22947 raft_consensus.cc:697] T 00000000000000000000000000000000 P b17b81fcd2474997a07ecf6b5975e47c [term 1 LEADER]: Becoming Leader. State: Replica: b17b81fcd2474997a07ecf6b5975e47c, State: Running, Role: LEADER
I20260812 06:18:20.635306 22947 consensus_queue.cc:237] T 00000000000000000000000000000000 P b17b81fcd2474997a07ecf6b5975e47c [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: "b17b81fcd2474997a07ecf6b5975e47c" member_type: VOTER }
I20260812 06:18:20.635402 22943 sys_catalog.cc:565] T 00000000000000000000000000000000 P b17b81fcd2474997a07ecf6b5975e47c [sys.catalog]: configured and running, proceeding with master startup.
I20260812 06:18:20.637214 22948 sys_catalog.cc:455] T 00000000000000000000000000000000 P b17b81fcd2474997a07ecf6b5975e47c [sys.catalog]: SysCatalogTable state changed. Reason: RaftConsensus started. Latest consensus state: current_term: 1 leader_uuid: "b17b81fcd2474997a07ecf6b5975e47c" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "b17b81fcd2474997a07ecf6b5975e47c" member_type: VOTER } }
I20260812 06:18:20.637301 22948 sys_catalog.cc:458] T 00000000000000000000000000000000 P b17b81fcd2474997a07ecf6b5975e47c [sys.catalog]: This master's current role is: LEADER
I20260812 06:18:20.637171 22949 sys_catalog.cc:455] T 00000000000000000000000000000000 P b17b81fcd2474997a07ecf6b5975e47c [sys.catalog]: SysCatalogTable state changed. Reason: New leader b17b81fcd2474997a07ecf6b5975e47c. Latest consensus state: current_term: 1 leader_uuid: "b17b81fcd2474997a07ecf6b5975e47c" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "b17b81fcd2474997a07ecf6b5975e47c" member_type: VOTER } }
I20260812 06:18:20.637614 22949 sys_catalog.cc:458] T 00000000000000000000000000000000 P b17b81fcd2474997a07ecf6b5975e47c [sys.catalog]: This master's current role is: LEADER
I20260812 06:18:20.637698 22822 internal_mini_cluster.cc:184] Waiting to initialize catalog manager on master 0
I20260812 06:18:20.637686 22962 catalog_manager.cc:1511] Loading table and tablet metadata into memory...
I20260812 06:18:20.639878 22962 catalog_manager.cc:1520] Initializing Kudu cluster ID...
I20260812 06:18:20.644040 22962 catalog_manager.cc:1383] Generated new cluster ID: 0a2aeee6d69743f6aa47c014b40e3747
I20260812 06:18:20.644104 22962 catalog_manager.cc:1531] Initializing Kudu internal certificate authority...
I20260812 06:18:20.658854 22962 catalog_manager.cc:1406] Generated new certificate authority record
I20260812 06:18:20.659704 22962 catalog_manager.cc:1540] Loading token signing keys...
I20260812 06:18:20.666983 22962 catalog_manager.cc:6092] T 00000000000000000000000000000000 P b17b81fcd2474997a07ecf6b5975e47c: Generated new TSK 0
I20260812 06:18:20.667618 22962 catalog_manager.cc:1550] Initializing in-progress tserver states...
I20260812 06:18:20.670260 22822 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:18:20.673146 22981 instance_detector.cc:116] could not retrieve OpenStack instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:18:20.673153 22977 instance_detector.cc:116] could not retrieve Azure instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:18:20.673149 22969 instance_detector.cc:116] could not retrieve AWS instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:18:20.673419 22822 server_base.cc:1061] running on GCE node
I20260812 06:18:20.673779 22822 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:18:20.673846 22822 system_unsync_time.cc:38] NTP support is disabled. Clock error bounds will not be accurate. This configuration is not suitable for distributed clusters.
I20260812 06:18:20.673870 22822 hybrid_clock.cc:648] HybridClock initialized: now 1786515500673870 us; error 0 us; skew 500 ppm
I20260812 06:18:20.674903 22822 webserver.cc:533] Webserver started at http://127.22.73.129:45863/ using document root <none> and password file <none>
I20260812 06:18:20.675098 22822 fs_manager.cc:362] Metadata directory not provided
I20260812 06:18:20.675172 22822 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:18:20.675252 22822 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:18:20.675648 22822 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskVApfHZ/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515500541946-22822-0/minicluster-data/ts-0-root/instance:
uuid: "891bcb87f7644e7aa45312337f99d3cc"
format_stamp: "Formatted at 2026-08-12 06:18:20 on dist-test-slave-jztv"
I20260812 06:18:20.677191 22822 fs_manager.cc:696] Time spent creating directory manager: real 0.001s	user 0.002s	sys 0.000s
I20260812 06:18:20.678201 22987 log_block_manager.cc:4127] Time spent loading block containers with low live blocks: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:18:20.678465 22822 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.001s	sys 0.000s
I20260812 06:18:20.678566 22822 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskVApfHZ/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515500541946-22822-0/minicluster-data/ts-0-root
uuid: "891bcb87f7644e7aa45312337f99d3cc"
format_stamp: "Formatted at 2026-08-12 06:18:20 on dist-test-slave-jztv"
I20260812 06:18:20.678660 22822 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskVApfHZ/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515500541946-22822-0/minicluster-data/ts-0-root
metadata directory: /tmp/dist-test-taskVApfHZ/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515500541946-22822-0/minicluster-data/ts-0-root
1 data directories: /tmp/dist-test-taskVApfHZ/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515500541946-22822-0/minicluster-data/ts-0-root/data
Total live blocks: 0
Total live bytes: 0
Total live bytes (after alignment): 0
Total number of LBM containers: 0 (0 full)
Did not check for missing blocks
Did not check for orphaned blocks
Total full LBM containers with extra space: 0 (0 repaired)
Total full LBM container extra space in bytes: 0 (0 repaired)
Total incomplete LBM containers: 0 (0 repaired)
Total LBM partial records: 0 (0 repaired)
Total corrupted LBM metadata records in RocksDB: 0 (0 repaired)
I20260812 06:18:20.707190 22822 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:18:20.707684 22822 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:18:20.708169 22822 txn_system_client.cc:432] TxnSystemClient initialization is disabled...
I20260812 06:18:20.709077 22822 ts_tablet_manager.cc:585] Loaded tablet metadata (0 total tablets, 0 live tablets)
I20260812 06:18:20.709153 22822 ts_tablet_manager.cc:531] Time spent load tablet metadata: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:18:20.709229 22822 ts_tablet_manager.cc:616] Registered 0 tablets
I20260812 06:18:20.709276 22822 ts_tablet_manager.cc:595] Time spent register tablets: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:18:20.716174 22822 rpc_server.cc:307] RPC server started. Bound to: 127.22.73.129:44267
I20260812 06:18:20.716213 23084 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.22.73.129:44267 every 8 connection(s)
I20260812 06:18:20.729560 23086 heartbeater.cc:344] Connected to a master server at 127.22.73.190:41271
I20260812 06:18:20.729787 23086 heartbeater.cc:461] Registering TS with master...
I20260812 06:18:20.730280 23086 heartbeater.cc:507] Master 127.22.73.190:41271 requested a full tablet report, sending...
I20260812 06:18:20.731738 22888 ts_manager.cc:194] Registered new tserver with Master: 891bcb87f7644e7aa45312337f99d3cc (127.22.73.129:44267)
I20260812 06:18:20.732363 22822 internal_mini_cluster.cc:371] 1 TS(s) registered with all masters after 0.015568331s
I20260812 06:18:20.733260 22888 master_service.cc:502] Signed X509 certificate for tserver {username='slave'} at 127.0.0.1:35828
I20260812 06:18:20.741796 22888 catalog_manager.cc:2283] Servicing CreateTable request from {username='slave'} at 127.0.0.1:35840:
name: "heavy-update-compaction-test"
schema {
  columns {
    name: "key"
    type: INT64
    is_key: true
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_a"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_b"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_c"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_d"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_e"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
}
num_replicas: 1
split_rows_range_bounds {
}
partition_schema {
  range_schema {
  }
}
I20260812 06:18:20.755863 23037 tablet_service.cc:1511] Processing CreateTablet for tablet 1222fe41ac9d4328aa2dab76f1b378b4 (DEFAULT_TABLE table=heavy-update-compaction-test [id=d31e9a87012a4bf3baef91e6b86e8360]), partition=
I20260812 06:18:20.756383 23037 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet 1222fe41ac9d4328aa2dab76f1b378b4. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:18:20.758420 23110 tablet_bootstrap.cc:492] T 1222fe41ac9d4328aa2dab76f1b378b4 P 891bcb87f7644e7aa45312337f99d3cc: Bootstrap starting.
I20260812 06:18:20.759397 23110 tablet_bootstrap.cc:654] T 1222fe41ac9d4328aa2dab76f1b378b4 P 891bcb87f7644e7aa45312337f99d3cc: Neither blocks nor log segments found. Creating new log.
I20260812 06:18:20.760617 23110 tablet_bootstrap.cc:492] T 1222fe41ac9d4328aa2dab76f1b378b4 P 891bcb87f7644e7aa45312337f99d3cc: No bootstrap required, opened a new log
I20260812 06:18:20.760720 23110 ts_tablet_manager.cc:1403] T 1222fe41ac9d4328aa2dab76f1b378b4 P 891bcb87f7644e7aa45312337f99d3cc: Time spent bootstrapping tablet: real 0.002s	user 0.002s	sys 0.000s
I20260812 06:18:20.761211 23110 raft_consensus.cc:359] T 1222fe41ac9d4328aa2dab76f1b378b4 P 891bcb87f7644e7aa45312337f99d3cc [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "891bcb87f7644e7aa45312337f99d3cc" member_type: VOTER last_known_addr { host: "127.22.73.129" port: 44267 } }
I20260812 06:18:20.761328 23110 raft_consensus.cc:385] T 1222fe41ac9d4328aa2dab76f1b378b4 P 891bcb87f7644e7aa45312337f99d3cc [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:18:20.761379 23110 raft_consensus.cc:740] T 1222fe41ac9d4328aa2dab76f1b378b4 P 891bcb87f7644e7aa45312337f99d3cc [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: 891bcb87f7644e7aa45312337f99d3cc, State: Initialized, Role: FOLLOWER
I20260812 06:18:20.761505 23110 consensus_queue.cc:260] T 1222fe41ac9d4328aa2dab76f1b378b4 P 891bcb87f7644e7aa45312337f99d3cc [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: "891bcb87f7644e7aa45312337f99d3cc" member_type: VOTER last_known_addr { host: "127.22.73.129" port: 44267 } }
I20260812 06:18:20.761592 23110 raft_consensus.cc:399] T 1222fe41ac9d4328aa2dab76f1b378b4 P 891bcb87f7644e7aa45312337f99d3cc [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:18:20.761626 23110 raft_consensus.cc:493] T 1222fe41ac9d4328aa2dab76f1b378b4 P 891bcb87f7644e7aa45312337f99d3cc [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:18:20.761673 23110 raft_consensus.cc:3060] T 1222fe41ac9d4328aa2dab76f1b378b4 P 891bcb87f7644e7aa45312337f99d3cc [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:18:20.762593 23110 raft_consensus.cc:515] T 1222fe41ac9d4328aa2dab76f1b378b4 P 891bcb87f7644e7aa45312337f99d3cc [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "891bcb87f7644e7aa45312337f99d3cc" member_type: VOTER last_known_addr { host: "127.22.73.129" port: 44267 } }
I20260812 06:18:20.762768 23110 leader_election.cc:304] T 1222fe41ac9d4328aa2dab76f1b378b4 P 891bcb87f7644e7aa45312337f99d3cc [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: 891bcb87f7644e7aa45312337f99d3cc; no voters: 
I20260812 06:18:20.762972 23110 leader_election.cc:290] T 1222fe41ac9d4328aa2dab76f1b378b4 P 891bcb87f7644e7aa45312337f99d3cc [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:18:20.763095 23114 raft_consensus.cc:2804] T 1222fe41ac9d4328aa2dab76f1b378b4 P 891bcb87f7644e7aa45312337f99d3cc [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:18:20.763382 23114 raft_consensus.cc:697] T 1222fe41ac9d4328aa2dab76f1b378b4 P 891bcb87f7644e7aa45312337f99d3cc [term 1 LEADER]: Becoming Leader. State: Replica: 891bcb87f7644e7aa45312337f99d3cc, State: Running, Role: LEADER
I20260812 06:18:20.763424 23110 ts_tablet_manager.cc:1434] T 1222fe41ac9d4328aa2dab76f1b378b4 P 891bcb87f7644e7aa45312337f99d3cc: Time spent starting tablet: real 0.003s	user 0.003s	sys 0.000s
I20260812 06:18:20.763901 23086 heartbeater.cc:499] Master 127.22.73.190:41271 was elected leader, sending a full tablet report...
I20260812 06:18:20.763998 23114 consensus_queue.cc:237] T 1222fe41ac9d4328aa2dab76f1b378b4 P 891bcb87f7644e7aa45312337f99d3cc [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: "891bcb87f7644e7aa45312337f99d3cc" member_type: VOTER last_known_addr { host: "127.22.73.129" port: 44267 } }
I20260812 06:18:20.766532 22888 catalog_manager.cc:5719] T 1222fe41ac9d4328aa2dab76f1b378b4 P 891bcb87f7644e7aa45312337f99d3cc reported cstate change: term changed from 0 to 1, leader changed from <none> to 891bcb87f7644e7aa45312337f99d3cc (127.22.73.129). New cstate: current_term: 1 leader_uuid: "891bcb87f7644e7aa45312337f99d3cc" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "891bcb87f7644e7aa45312337f99d3cc" member_type: VOTER last_known_addr { host: "127.22.73.129" port: 44267 } health_report { overall_health: HEALTHY } } }
I20260812 06:18:20.837330 22822 heavy-update-compaction-itest.cc:215] Time spent inserting: real 0.061s	user 0.026s	sys 0.008s
I20260812 06:18:20.967191 23088 maintenance_manager.cc:419] P 891bcb87f7644e7aa45312337f99d3cc: Scheduling FlushMRSOp(1222fe41ac9d4328aa2dab76f1b378b4): perf score=19.054940
I20260812 06:18:21.146112 22995 maintenance_manager.cc:643] P 891bcb87f7644e7aa45312337f99d3cc: FlushMRSOp(1222fe41ac9d4328aa2dab76f1b378b4) complete. Timing: real 0.179s	user 0.120s	sys 0.052s Metrics: {"bytes_written":13374125,"cfile_init":1,"compiler_manager_pool.queue_time_us":171,"delete_count":0,"dirs.queue_time_us":90,"dirs.run_cpu_time_us":257,"dirs.run_wall_time_us":1019,"drs_written":1,"lbm_read_time_us":75,"lbm_reads_lt_1ms":4,"lbm_write_time_us":45055,"lbm_writes_lt_1ms":783,"peak_mem_usage":0,"reinsert_count":0,"rows_written":104,"spinlock_wait_cycles":263040,"thread_start_us":107,"threads_started":1,"update_count":1630}
I20260812 06:18:21.147336 23088 maintenance_manager.cc:419] P 891bcb87f7644e7aa45312337f99d3cc: Scheduling UndoDeltaBlockGCOp(1222fe41ac9d4328aa2dab76f1b378b4): 16411394 bytes on disk
I20260812 06:18:21.147892 22995 maintenance_manager.cc:643] P 891bcb87f7644e7aa45312337f99d3cc: UndoDeltaBlockGCOp(1222fe41ac9d4328aa2dab76f1b378b4) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":63,"lbm_reads_lt_1ms":4}
I20260812 06:18:21.148397 23088 maintenance_manager.cc:419] P 891bcb87f7644e7aa45312337f99d3cc: Scheduling FlushDeltaMemStoresOp(1222fe41ac9d4328aa2dab76f1b378b4): perf score=3.181125
I20260812 06:18:21.169348 22995 maintenance_manager.cc:643] P 891bcb87f7644e7aa45312337f99d3cc: FlushDeltaMemStoresOp(1222fe41ac9d4328aa2dab76f1b378b4) complete. Timing: real 0.021s	user 0.012s	sys 0.004s Metrics: {"bytes_written":4882122,"delete_count":0,"lbm_write_time_us":6234,"lbm_writes_lt_1ms":122,"reinsert_count":0,"update_count":595}
I20260812 06:18:21.169870 23088 maintenance_manager.cc:419] P 891bcb87f7644e7aa45312337f99d3cc: Scheduling LogGCOp(1222fe41ac9d4328aa2dab76f1b378b4): free 20743831 bytes of WAL
I20260812 06:18:21.170245 22995 log_reader.cc:385] T 1222fe41ac9d4328aa2dab76f1b378b4: removed 2 log segments from log reader
I20260812 06:18:21.170315 22995 log.cc:1079] T 1222fe41ac9d4328aa2dab76f1b378b4 P 891bcb87f7644e7aa45312337f99d3cc: Deleting log segment in path: /tmp/dist-test-taskVApfHZ/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515500541946-22822-0/minicluster-data/ts-0-root/wals/1222fe41ac9d4328aa2dab76f1b378b4/wal-000000001 (ops 1-6)
I20260812 06:18:21.170419 22995 log.cc:1079] T 1222fe41ac9d4328aa2dab76f1b378b4 P 891bcb87f7644e7aa45312337f99d3cc: Deleting log segment in path: /tmp/dist-test-taskVApfHZ/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515500541946-22822-0/minicluster-data/ts-0-root/wals/1222fe41ac9d4328aa2dab76f1b378b4/wal-000000002 (ops 7-11)
I20260812 06:18:21.175834 22995 maintenance_manager.cc:643] P 891bcb87f7644e7aa45312337f99d3cc: LogGCOp(1222fe41ac9d4328aa2dab76f1b378b4) complete. Timing: real 0.006s	user 0.001s	sys 0.003s Metrics: {}
I20260812 06:18:21.176199 23088 maintenance_manager.cc:419] P 891bcb87f7644e7aa45312337f99d3cc: Scheduling FlushDeltaMemStoresOp(1222fe41ac9d4328aa2dab76f1b378b4): perf score=1.196750
I20260812 06:18:21.186369 22995 maintenance_manager.cc:643] P 891bcb87f7644e7aa45312337f99d3cc: FlushDeltaMemStoresOp(1222fe41ac9d4328aa2dab76f1b378b4) complete. Timing: real 0.010s	user 0.010s	sys 0.000s Metrics: {"bytes_written":2256529,"delete_count":0,"lbm_write_time_us":3403,"lbm_writes_lt_1ms":58,"reinsert_count":0,"update_count":275}
I20260812 06:18:21.186838 23088 maintenance_manager.cc:419] P 891bcb87f7644e7aa45312337f99d3cc: Scheduling MajorDeltaCompactionOp(1222fe41ac9d4328aa2dab76f1b378b4): perf score=1.000000
I20260812 06:18:21.355279 22995 maintenance_manager.cc:643] P 891bcb87f7644e7aa45312337f99d3cc: MajorDeltaCompactionOp(1222fe41ac9d4328aa2dab76f1b378b4) complete. Timing: real 0.168s	user 0.112s	sys 0.056s Metrics: {"cfile_cache_miss":533,"cfile_cache_miss_bytes":24774776,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":422,"lbm_read_time_us":11642,"lbm_reads_lt_1ms":569,"lbm_write_time_us":28298,"lbm_writes_lt_1ms":543,"mutex_wait_us":23,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":11392,"thread_start_us":318,"threads_started":5,"update_count":2500}
I20260812 06:18:21.356006 23088 maintenance_manager.cc:419] P 891bcb87f7644e7aa45312337f99d3cc: Scheduling FlushDeltaMemStoresOp(1222fe41ac9d4328aa2dab76f1b378b4): perf score=11.118625
I20260812 06:18:21.389958 22995 maintenance_manager.cc:643] P 891bcb87f7644e7aa45312337f99d3cc: FlushDeltaMemStoresOp(1222fe41ac9d4328aa2dab76f1b378b4) complete. Timing: real 0.034s	user 0.014s	sys 0.015s Metrics: {"bytes_written":12635684,"delete_count":0,"lbm_write_time_us":15221,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":310,"reinsert_count":0,"update_count":1540}
I20260812 06:18:21.390467 23088 maintenance_manager.cc:419] P 891bcb87f7644e7aa45312337f99d3cc: Scheduling FlushDeltaMemStoresOp(1222fe41ac9d4328aa2dab76f1b378b4): perf score=2.188937
I20260812 06:18:21.408169 22995 maintenance_manager.cc:643] P 891bcb87f7644e7aa45312337f99d3cc: FlushDeltaMemStoresOp(1222fe41ac9d4328aa2dab76f1b378b4) complete. Timing: real 0.017s	user 0.010s	sys 0.005s Metrics: {"bytes_written":3774459,"delete_count":0,"lbm_write_time_us":6152,"lbm_writes_lt_1ms":95,"reinsert_count":0,"update_count":460}
I20260812 06:18:21.408625 23088 maintenance_manager.cc:419] P 891bcb87f7644e7aa45312337f99d3cc: Scheduling MajorDeltaCompactionOp(1222fe41ac9d4328aa2dab76f1b378b4): perf score=1.000000
I20260812 06:18:21.542157 22995 maintenance_manager.cc:643] P 891bcb87f7644e7aa45312337f99d3cc: MajorDeltaCompactionOp(1222fe41ac9d4328aa2dab76f1b378b4) complete. Timing: real 0.133s	user 0.108s	sys 0.024s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672271,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":393,"lbm_read_time_us":9164,"lbm_reads_lt_1ms":468,"lbm_write_time_us":26552,"lbm_writes_lt_1ms":443,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":3072,"update_count":2000}
I20260812 06:18:21.543160 23088 maintenance_manager.cc:419] P 891bcb87f7644e7aa45312337f99d3cc: Scheduling FlushDeltaMemStoresOp(1222fe41ac9d4328aa2dab76f1b378b4): perf score=10.126437
I20260812 06:18:21.591213 22995 maintenance_manager.cc:643] P 891bcb87f7644e7aa45312337f99d3cc: FlushDeltaMemStoresOp(1222fe41ac9d4328aa2dab76f1b378b4) complete. Timing: real 0.048s	user 0.024s	sys 0.011s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":16246,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:18:21.591696 23088 maintenance_manager.cc:419] P 891bcb87f7644e7aa45312337f99d3cc: Scheduling FlushDeltaMemStoresOp(1222fe41ac9d4328aa2dab76f1b378b4): perf score=2.188937
I20260812 06:18:21.601925 22995 maintenance_manager.cc:643] P 891bcb87f7644e7aa45312337f99d3cc: FlushDeltaMemStoresOp(1222fe41ac9d4328aa2dab76f1b378b4) complete. Timing: real 0.010s	user 0.004s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3926,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:21.602562 23088 maintenance_manager.cc:419] P 891bcb87f7644e7aa45312337f99d3cc: Scheduling MajorDeltaCompactionOp(1222fe41ac9d4328aa2dab76f1b378b4): perf score=1.000000
I20260812 06:18:21.717868 22995 maintenance_manager.cc:643] P 891bcb87f7644e7aa45312337f99d3cc: MajorDeltaCompactionOp(1222fe41ac9d4328aa2dab76f1b378b4) complete. Timing: real 0.115s	user 0.067s	sys 0.048s 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":464,"lbm_read_time_us":8134,"lbm_reads_lt_1ms":472,"lbm_write_time_us":21595,"lbm_writes_lt_1ms":443,"mutex_wait_us":23,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":11904,"update_count":2000}
I20260812 06:18:21.718636 23088 maintenance_manager.cc:419] P 891bcb87f7644e7aa45312337f99d3cc: Scheduling FlushDeltaMemStoresOp(1222fe41ac9d4328aa2dab76f1b378b4): perf score=10.126437
I20260812 06:18:21.755776 22995 maintenance_manager.cc:643] P 891bcb87f7644e7aa45312337f99d3cc: FlushDeltaMemStoresOp(1222fe41ac9d4328aa2dab76f1b378b4) complete. Timing: real 0.037s	user 0.028s	sys 0.007s Metrics: {"bytes_written":12307489,"delete_count":0,"lbm_write_time_us":15269,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":302,"reinsert_count":0,"update_count":1500}
I20260812 06:18:21.756335 23088 maintenance_manager.cc:419] P 891bcb87f7644e7aa45312337f99d3cc: Scheduling FlushDeltaMemStoresOp(1222fe41ac9d4328aa2dab76f1b378b4): perf score=2.188937
I20260812 06:18:21.772506 22995 maintenance_manager.cc:643] P 891bcb87f7644e7aa45312337f99d3cc: FlushDeltaMemStoresOp(1222fe41ac9d4328aa2dab76f1b378b4) complete. Timing: real 0.016s	user 0.013s	sys 0.001s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6035,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:21.773003 23088 maintenance_manager.cc:419] P 891bcb87f7644e7aa45312337f99d3cc: Scheduling MajorDeltaCompactionOp(1222fe41ac9d4328aa2dab76f1b378b4): perf score=1.000000
I20260812 06:18:21.899056 22995 maintenance_manager.cc:643] P 891bcb87f7644e7aa45312337f99d3cc: MajorDeltaCompactionOp(1222fe41ac9d4328aa2dab76f1b378b4) complete. Timing: real 0.126s	user 0.109s	sys 0.017s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672276,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":537,"lbm_read_time_us":7099,"lbm_reads_lt_1ms":464,"lbm_write_time_us":25984,"lbm_writes_lt_1ms":443,"mutex_wait_us":38,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":15616,"update_count":2000}
I20260812 06:18:21.899725 23088 maintenance_manager.cc:419] P 891bcb87f7644e7aa45312337f99d3cc: Scheduling FlushDeltaMemStoresOp(1222fe41ac9d4328aa2dab76f1b378b4): perf score=10.126437
I20260812 06:18:21.941708 22995 maintenance_manager.cc:643] P 891bcb87f7644e7aa45312337f99d3cc: FlushDeltaMemStoresOp(1222fe41ac9d4328aa2dab76f1b378b4) complete. Timing: real 0.042s	user 0.015s	sys 0.023s Metrics: {"bytes_written":12307491,"delete_count":0,"lbm_write_time_us":14359,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:18:21.942340 23088 maintenance_manager.cc:419] P 891bcb87f7644e7aa45312337f99d3cc: Scheduling FlushDeltaMemStoresOp(1222fe41ac9d4328aa2dab76f1b378b4): perf score=2.188937
I20260812 06:18:21.952701 22995 maintenance_manager.cc:643] P 891bcb87f7644e7aa45312337f99d3cc: FlushDeltaMemStoresOp(1222fe41ac9d4328aa2dab76f1b378b4) complete. Timing: real 0.010s	user 0.004s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3981,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:21.953287 23088 maintenance_manager.cc:419] P 891bcb87f7644e7aa45312337f99d3cc: Scheduling MajorDeltaCompactionOp(1222fe41ac9d4328aa2dab76f1b378b4): perf score=1.000000
I20260812 06:18:22.095863 22995 maintenance_manager.cc:643] P 891bcb87f7644e7aa45312337f99d3cc: MajorDeltaCompactionOp(1222fe41ac9d4328aa2dab76f1b378b4) complete. Timing: real 0.142s	user 0.094s	sys 0.047s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672278,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":1257,"lbm_read_time_us":10566,"lbm_reads_lt_1ms":472,"lbm_write_time_us":22659,"lbm_writes_lt_1ms":443,"mutex_wait_us":623,"peak_mem_usage":50689328,"reinsert_count":0,"update_count":2000}
I20260812 06:18:22.096370 23088 maintenance_manager.cc:419] P 891bcb87f7644e7aa45312337f99d3cc: Scheduling FlushDeltaMemStoresOp(1222fe41ac9d4328aa2dab76f1b378b4): perf score=10.126437
I20260812 06:18:22.133507 22995 maintenance_manager.cc:643] P 891bcb87f7644e7aa45312337f99d3cc: FlushDeltaMemStoresOp(1222fe41ac9d4328aa2dab76f1b378b4) complete. Timing: real 0.037s	user 0.025s	sys 0.008s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":15941,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:18:22.133999 23088 maintenance_manager.cc:419] P 891bcb87f7644e7aa45312337f99d3cc: Scheduling FlushDeltaMemStoresOp(1222fe41ac9d4328aa2dab76f1b378b4): perf score=2.188937
I20260812 06:18:22.150835 22995 maintenance_manager.cc:643] P 891bcb87f7644e7aa45312337f99d3cc: FlushDeltaMemStoresOp(1222fe41ac9d4328aa2dab76f1b378b4) complete. Timing: real 0.017s	user 0.009s	sys 0.007s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6119,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:22.151397 23088 maintenance_manager.cc:419] P 891bcb87f7644e7aa45312337f99d3cc: Scheduling MajorDeltaCompactionOp(1222fe41ac9d4328aa2dab76f1b378b4): perf score=1.000000
I20260812 06:18:22.276526 22995 maintenance_manager.cc:643] P 891bcb87f7644e7aa45312337f99d3cc: MajorDeltaCompactionOp(1222fe41ac9d4328aa2dab76f1b378b4) complete. Timing: real 0.124s	user 0.098s	sys 0.027s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672277,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":40,"lbm_read_time_us":8238,"lbm_reads_lt_1ms":464,"lbm_write_time_us":24354,"lbm_writes_lt_1ms":443,"mutex_wait_us":26,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":14976,"update_count":2000}
I20260812 06:18:22.277868 23088 maintenance_manager.cc:419] P 891bcb87f7644e7aa45312337f99d3cc: Scheduling FlushDeltaMemStoresOp(1222fe41ac9d4328aa2dab76f1b378b4): perf score=10.126437
I20260812 06:18:22.317570 22995 maintenance_manager.cc:643] P 891bcb87f7644e7aa45312337f99d3cc: FlushDeltaMemStoresOp(1222fe41ac9d4328aa2dab76f1b378b4) complete. Timing: real 0.039s	user 0.023s	sys 0.013s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":16815,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:18:22.318125 23088 maintenance_manager.cc:419] P 891bcb87f7644e7aa45312337f99d3cc: Scheduling FlushDeltaMemStoresOp(1222fe41ac9d4328aa2dab76f1b378b4): perf score=2.188937
I20260812 06:18:22.334170 22995 maintenance_manager.cc:643] P 891bcb87f7644e7aa45312337f99d3cc: FlushDeltaMemStoresOp(1222fe41ac9d4328aa2dab76f1b378b4) complete. Timing: real 0.016s	user 0.009s	sys 0.005s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6231,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:22.334687 23088 maintenance_manager.cc:419] P 891bcb87f7644e7aa45312337f99d3cc: Scheduling FlushMRSOp(1222fe41ac9d4328aa2dab76f1b378b4): perf score=1.000000
I20260812 06:18:22.362032 22995 maintenance_manager.cc:643] P 891bcb87f7644e7aa45312337f99d3cc: FlushMRSOp(1222fe41ac9d4328aa2dab76f1b378b4) complete. Timing: real 0.027s	user 0.024s	sys 0.002s Metrics: {"bytes_written":1193503,"cfile_init":1,"dirs.queue_time_us":71,"dirs.run_cpu_time_us":276,"dirs.run_wall_time_us":1441,"drs_written":1,"lbm_read_time_us":40,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1646,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":29}
I20260812 06:18:22.362861 23088 maintenance_manager.cc:419] P 891bcb87f7644e7aa45312337f99d3cc: Scheduling LogGCOp(1222fe41ac9d4328aa2dab76f1b378b4): free 120553455 bytes of WAL
I20260812 06:18:22.363101 22995 log_reader.cc:385] T 1222fe41ac9d4328aa2dab76f1b378b4: removed 12 log segments from log reader
I20260812 06:18:22.363144 22995 log.cc:1079] T 1222fe41ac9d4328aa2dab76f1b378b4 P 891bcb87f7644e7aa45312337f99d3cc: Deleting log segment in path: /tmp/dist-test-taskVApfHZ/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515500541946-22822-0/minicluster-data/ts-0-root/wals/1222fe41ac9d4328aa2dab76f1b378b4/wal-000000003 (ops 12-16)
I20260812 06:18:22.363173 22995 log.cc:1079] T 1222fe41ac9d4328aa2dab76f1b378b4 P 891bcb87f7644e7aa45312337f99d3cc: Deleting log segment in path: /tmp/dist-test-taskVApfHZ/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515500541946-22822-0/minicluster-data/ts-0-root/wals/1222fe41ac9d4328aa2dab76f1b378b4/wal-000000004 (ops 17-21)
I20260812 06:18:22.363232 22995 log.cc:1079] T 1222fe41ac9d4328aa2dab76f1b378b4 P 891bcb87f7644e7aa45312337f99d3cc: Deleting log segment in path: /tmp/dist-test-taskVApfHZ/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515500541946-22822-0/minicluster-data/ts-0-root/wals/1222fe41ac9d4328aa2dab76f1b378b4/wal-000000005 (ops 22-26)
I20260812 06:18:22.363276 22995 log.cc:1079] T 1222fe41ac9d4328aa2dab76f1b378b4 P 891bcb87f7644e7aa45312337f99d3cc: Deleting log segment in path: /tmp/dist-test-taskVApfHZ/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515500541946-22822-0/minicluster-data/ts-0-root/wals/1222fe41ac9d4328aa2dab76f1b378b4/wal-000000006 (ops 27-31)
I20260812 06:18:22.363315 22995 log.cc:1079] T 1222fe41ac9d4328aa2dab76f1b378b4 P 891bcb87f7644e7aa45312337f99d3cc: Deleting log segment in path: /tmp/dist-test-taskVApfHZ/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515500541946-22822-0/minicluster-data/ts-0-root/wals/1222fe41ac9d4328aa2dab76f1b378b4/wal-000000007 (ops 32-36)
I20260812 06:18:22.363355 22995 log.cc:1079] T 1222fe41ac9d4328aa2dab76f1b378b4 P 891bcb87f7644e7aa45312337f99d3cc: Deleting log segment in path: /tmp/dist-test-taskVApfHZ/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515500541946-22822-0/minicluster-data/ts-0-root/wals/1222fe41ac9d4328aa2dab76f1b378b4/wal-000000008 (ops 37-41)
I20260812 06:18:22.363389 22995 log.cc:1079] T 1222fe41ac9d4328aa2dab76f1b378b4 P 891bcb87f7644e7aa45312337f99d3cc: Deleting log segment in path: /tmp/dist-test-taskVApfHZ/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515500541946-22822-0/minicluster-data/ts-0-root/wals/1222fe41ac9d4328aa2dab76f1b378b4/wal-000000009 (ops 42-46)
I20260812 06:18:22.363433 22995 log.cc:1079] T 1222fe41ac9d4328aa2dab76f1b378b4 P 891bcb87f7644e7aa45312337f99d3cc: Deleting log segment in path: /tmp/dist-test-taskVApfHZ/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515500541946-22822-0/minicluster-data/ts-0-root/wals/1222fe41ac9d4328aa2dab76f1b378b4/wal-000000010 (ops 47-50)
I20260812 06:18:22.363466 22995 log.cc:1079] T 1222fe41ac9d4328aa2dab76f1b378b4 P 891bcb87f7644e7aa45312337f99d3cc: Deleting log segment in path: /tmp/dist-test-taskVApfHZ/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515500541946-22822-0/minicluster-data/ts-0-root/wals/1222fe41ac9d4328aa2dab76f1b378b4/wal-000000011 (ops 51-55)
I20260812 06:18:22.363503 22995 log.cc:1079] T 1222fe41ac9d4328aa2dab76f1b378b4 P 891bcb87f7644e7aa45312337f99d3cc: Deleting log segment in path: /tmp/dist-test-taskVApfHZ/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515500541946-22822-0/minicluster-data/ts-0-root/wals/1222fe41ac9d4328aa2dab76f1b378b4/wal-000000012 (ops 56-60)
I20260812 06:18:22.363543 22995 log.cc:1079] T 1222fe41ac9d4328aa2dab76f1b378b4 P 891bcb87f7644e7aa45312337f99d3cc: Deleting log segment in path: /tmp/dist-test-taskVApfHZ/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515500541946-22822-0/minicluster-data/ts-0-root/wals/1222fe41ac9d4328aa2dab76f1b378b4/wal-000000013 (ops 61-64)
I20260812 06:18:22.363583 22995 log.cc:1079] T 1222fe41ac9d4328aa2dab76f1b378b4 P 891bcb87f7644e7aa45312337f99d3cc: Deleting log segment in path: /tmp/dist-test-taskVApfHZ/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515500541946-22822-0/minicluster-data/ts-0-root/wals/1222fe41ac9d4328aa2dab76f1b378b4/wal-000000014 (ops 65-69)
I20260812 06:18:22.390784 22995 maintenance_manager.cc:643] P 891bcb87f7644e7aa45312337f99d3cc: LogGCOp(1222fe41ac9d4328aa2dab76f1b378b4) complete. Timing: real 0.028s	user 0.000s	sys 0.027s Metrics: {}
I20260812 06:18:22.391273 23088 maintenance_manager.cc:419] P 891bcb87f7644e7aa45312337f99d3cc: Scheduling FlushDeltaMemStoresOp(1222fe41ac9d4328aa2dab76f1b378b4): perf score=3.181125
I20260812 06:18:22.408818 22995 maintenance_manager.cc:643] P 891bcb87f7644e7aa45312337f99d3cc: FlushDeltaMemStoresOp(1222fe41ac9d4328aa2dab76f1b378b4) complete. Timing: real 0.017s	user 0.015s	sys 0.000s Metrics: {"bytes_written":4512900,"delete_count":0,"lbm_write_time_us":6876,"lbm_writes_lt_1ms":113,"reinsert_count":0,"update_count":550}
I20260812 06:18:22.409261 23088 maintenance_manager.cc:419] P 891bcb87f7644e7aa45312337f99d3cc: Scheduling FlushDeltaMemStoresOp(1222fe41ac9d4328aa2dab76f1b378b4): perf score=2.188937
I20260812 06:18:22.419694 22995 maintenance_manager.cc:643] P 891bcb87f7644e7aa45312337f99d3cc: FlushDeltaMemStoresOp(1222fe41ac9d4328aa2dab76f1b378b4) complete. Timing: real 0.010s	user 0.005s	sys 0.004s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3812,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:18:22.420385 23088 maintenance_manager.cc:419] P 891bcb87f7644e7aa45312337f99d3cc: Scheduling MajorDeltaCompactionOp(1222fe41ac9d4328aa2dab76f1b378b4): perf score=1.000000
I20260812 06:18:22.590831 22995 maintenance_manager.cc:643] P 891bcb87f7644e7aa45312337f99d3cc: MajorDeltaCompactionOp(1222fe41ac9d4328aa2dab76f1b378b4) complete. Timing: real 0.170s	user 0.146s	sys 0.020s Metrics: {"cfile_cache_miss":634,"cfile_cache_miss_bytes":28877326,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":1037,"lbm_read_time_us":10544,"lbm_reads_lt_1ms":674,"lbm_write_time_us":32639,"lbm_writes_lt_1ms":643,"mutex_wait_us":352,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":1664,"thread_start_us":81,"threads_started":1,"update_count":3000}
I20260812 06:18:22.591482 23088 maintenance_manager.cc:419] P 891bcb87f7644e7aa45312337f99d3cc: Scheduling FlushDeltaMemStoresOp(1222fe41ac9d4328aa2dab76f1b378b4): perf score=14.095187
I20260812 06:18:22.646014 22995 maintenance_manager.cc:643] P 891bcb87f7644e7aa45312337f99d3cc: FlushDeltaMemStoresOp(1222fe41ac9d4328aa2dab76f1b378b4) complete. Timing: real 0.054s	user 0.027s	sys 0.024s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":25042,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":402,"reinsert_count":0,"update_count":2000}
I20260812 06:18:22.646498 23088 maintenance_manager.cc:419] P 891bcb87f7644e7aa45312337f99d3cc: Scheduling UndoDeltaBlockGCOp(1222fe41ac9d4328aa2dab76f1b378b4): 462 bytes on disk
I20260812 06:18:22.646915 22995 maintenance_manager.cc:643] P 891bcb87f7644e7aa45312337f99d3cc: UndoDeltaBlockGCOp(1222fe41ac9d4328aa2dab76f1b378b4) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":49,"lbm_reads_lt_1ms":4}
I20260812 06:18:22.647346 23088 maintenance_manager.cc:419] P 891bcb87f7644e7aa45312337f99d3cc: Scheduling FlushDeltaMemStoresOp(1222fe41ac9d4328aa2dab76f1b378b4): perf score=2.188937
I20260812 06:18:22.659212 22995 maintenance_manager.cc:643] P 891bcb87f7644e7aa45312337f99d3cc: FlushDeltaMemStoresOp(1222fe41ac9d4328aa2dab76f1b378b4) complete. Timing: real 0.012s	user 0.006s	sys 0.004s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4275,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:22.659703 23088 maintenance_manager.cc:419] P 891bcb87f7644e7aa45312337f99d3cc: Scheduling MajorDeltaCompactionOp(1222fe41ac9d4328aa2dab76f1b378b4): perf score=1.000000
I20260812 06:18:22.802918 22995 maintenance_manager.cc:643] P 891bcb87f7644e7aa45312337f99d3cc: MajorDeltaCompactionOp(1222fe41ac9d4328aa2dab76f1b378b4) complete. Timing: real 0.143s	user 0.120s	sys 0.022s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774687,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":235,"lbm_read_time_us":8817,"lbm_reads_lt_1ms":572,"lbm_write_time_us":28752,"lbm_writes_lt_1ms":543,"mutex_wait_us":56,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":1920,"update_count":2500}
I20260812 06:18:22.803578 23088 maintenance_manager.cc:419] P 891bcb87f7644e7aa45312337f99d3cc: Scheduling FlushDeltaMemStoresOp(1222fe41ac9d4328aa2dab76f1b378b4): perf score=11.118625
I20260812 06:18:22.837380 22995 maintenance_manager.cc:643] P 891bcb87f7644e7aa45312337f99d3cc: FlushDeltaMemStoresOp(1222fe41ac9d4328aa2dab76f1b378b4) complete. Timing: real 0.034s	user 0.017s	sys 0.013s Metrics: {"bytes_written":12717735,"delete_count":0,"lbm_write_time_us":13651,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:18:22.838033 23088 maintenance_manager.cc:419] P 891bcb87f7644e7aa45312337f99d3cc: Scheduling FlushDeltaMemStoresOp(1222fe41ac9d4328aa2dab76f1b378b4): perf score=2.188937
I20260812 06:18:22.863245 22995 maintenance_manager.cc:643] P 891bcb87f7644e7aa45312337f99d3cc: FlushDeltaMemStoresOp(1222fe41ac9d4328aa2dab76f1b378b4) complete. Timing: real 0.025s	user 0.011s	sys 0.003s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":6819,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":92,"reinsert_count":0,"update_count":450}
I20260812 06:18:22.863699 23088 maintenance_manager.cc:419] P 891bcb87f7644e7aa45312337f99d3cc: Scheduling FlushDeltaMemStoresOp(1222fe41ac9d4328aa2dab76f1b378b4): perf score=2.188937
I20260812 06:18:22.874239 22995 maintenance_manager.cc:643] P 891bcb87f7644e7aa45312337f99d3cc: FlushDeltaMemStoresOp(1222fe41ac9d4328aa2dab76f1b378b4) complete. Timing: real 0.010s	user 0.009s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4085,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:22.874784 23088 maintenance_manager.cc:419] P 891bcb87f7644e7aa45312337f99d3cc: Scheduling MajorDeltaCompactionOp(1222fe41ac9d4328aa2dab76f1b378b4): perf score=1.000000
I20260812 06:18:23.023082 22995 maintenance_manager.cc:643] P 891bcb87f7644e7aa45312337f99d3cc: MajorDeltaCompactionOp(1222fe41ac9d4328aa2dab76f1b378b4) complete. Timing: real 0.148s	user 0.114s	sys 0.027s Metrics: {"cfile_cache_miss":533,"cfile_cache_miss_bytes":24774799,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":186,"lbm_read_time_us":9764,"lbm_reads_lt_1ms":573,"lbm_write_time_us":28923,"lbm_writes_lt_1ms":543,"mutex_wait_us":3,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":3968,"update_count":2500}
I20260812 06:18:23.024083 23088 maintenance_manager.cc:419] P 891bcb87f7644e7aa45312337f99d3cc: Scheduling FlushDeltaMemStoresOp(1222fe41ac9d4328aa2dab76f1b378b4): perf score=11.118625
I20260812 06:18:23.067898 22995 maintenance_manager.cc:643] P 891bcb87f7644e7aa45312337f99d3cc: FlushDeltaMemStoresOp(1222fe41ac9d4328aa2dab76f1b378b4) complete. Timing: real 0.043s	user 0.023s	sys 0.015s Metrics: {"bytes_written":12717737,"delete_count":0,"lbm_write_time_us":14703,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:18:23.068583 23088 maintenance_manager.cc:419] P 891bcb87f7644e7aa45312337f99d3cc: Scheduling FlushDeltaMemStoresOp(1222fe41ac9d4328aa2dab76f1b378b4): perf score=3.181125
I20260812 06:18:23.084860 22995 maintenance_manager.cc:643] P 891bcb87f7644e7aa45312337f99d3cc: FlushDeltaMemStoresOp(1222fe41ac9d4328aa2dab76f1b378b4) complete. Timing: real 0.016s	user 0.011s	sys 0.003s Metrics: {"bytes_written":4800070,"delete_count":0,"lbm_write_time_us":6801,"lbm_writes_lt_1ms":120,"reinsert_count":0,"update_count":585}
I20260812 06:18:23.085274 23088 maintenance_manager.cc:419] P 891bcb87f7644e7aa45312337f99d3cc: Scheduling FlushDeltaMemStoresOp(1222fe41ac9d4328aa2dab76f1b378b4): perf score=1.196750
I20260812 06:18:23.093102 22995 maintenance_manager.cc:643] P 891bcb87f7644e7aa45312337f99d3cc: FlushDeltaMemStoresOp(1222fe41ac9d4328aa2dab76f1b378b4) complete. Timing: real 0.008s	user 0.006s	sys 0.000s Metrics: {"bytes_written":2994980,"delete_count":0,"lbm_write_time_us":2831,"lbm_writes_lt_1ms":76,"reinsert_count":0,"update_count":365}
I20260812 06:18:23.093900 23088 maintenance_manager.cc:419] P 891bcb87f7644e7aa45312337f99d3cc: Scheduling MajorDeltaCompactionOp(1222fe41ac9d4328aa2dab76f1b378b4): perf score=1.000000
I20260812 06:18:23.257934 22995 maintenance_manager.cc:643] P 891bcb87f7644e7aa45312337f99d3cc: MajorDeltaCompactionOp(1222fe41ac9d4328aa2dab76f1b378b4) complete. Timing: real 0.164s	user 0.138s	sys 0.023s Metrics: {"cfile_cache_miss":533,"cfile_cache_miss_bytes":24774787,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":1503,"lbm_read_time_us":11753,"lbm_reads_lt_1ms":573,"lbm_write_time_us":29917,"lbm_writes_lt_1ms":543,"mutex_wait_us":66,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":384,"update_count":2500}
I20260812 06:18:23.259557 23088 maintenance_manager.cc:419] P 891bcb87f7644e7aa45312337f99d3cc: Scheduling FlushDeltaMemStoresOp(1222fe41ac9d4328aa2dab76f1b378b4): perf score=12.110812
I20260812 06:18:23.301815 22995 maintenance_manager.cc:643] P 891bcb87f7644e7aa45312337f99d3cc: FlushDeltaMemStoresOp(1222fe41ac9d4328aa2dab76f1b378b4) complete. Timing: real 0.042s	user 0.026s	sys 0.012s Metrics: {"bytes_written":13784349,"delete_count":0,"lbm_write_time_us":17700,"lbm_writes_lt_1ms":339,"reinsert_count":0,"update_count":1680}
I20260812 06:18:23.302520 23088 maintenance_manager.cc:419] P 891bcb87f7644e7aa45312337f99d3cc: Scheduling FlushDeltaMemStoresOp(1222fe41ac9d4328aa2dab76f1b378b4): perf score=1.196750
I20260812 06:18:23.313391 22995 maintenance_manager.cc:643] P 891bcb87f7644e7aa45312337f99d3cc: FlushDeltaMemStoresOp(1222fe41ac9d4328aa2dab76f1b378b4) complete. Timing: real 0.010s	user 0.004s	sys 0.004s Metrics: {"bytes_written":2625754,"delete_count":0,"lbm_write_time_us":3231,"lbm_writes_lt_1ms":67,"reinsert_count":0,"spinlock_wait_cycles":1280,"update_count":320}
I20260812 06:18:23.314023 23088 maintenance_manager.cc:419] P 891bcb87f7644e7aa45312337f99d3cc: Scheduling MajorDeltaCompactionOp(1222fe41ac9d4328aa2dab76f1b378b4): perf score=1.000000
I20260812 06:18:23.456135 22995 maintenance_manager.cc:643] P 891bcb87f7644e7aa45312337f99d3cc: MajorDeltaCompactionOp(1222fe41ac9d4328aa2dab76f1b378b4) complete. Timing: real 0.142s	user 0.104s	sys 0.032s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672231,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":207,"lbm_read_time_us":8547,"lbm_reads_lt_1ms":468,"lbm_write_time_us":23440,"lbm_writes_lt_1ms":443,"mutex_wait_us":48,"peak_mem_usage":50689328,"reinsert_count":0,"update_count":2000}
I20260812 06:18:23.456761 23088 maintenance_manager.cc:419] P 891bcb87f7644e7aa45312337f99d3cc: Scheduling FlushDeltaMemStoresOp(1222fe41ac9d4328aa2dab76f1b378b4): perf score=11.118625
I20260812 06:18:23.498504 22995 maintenance_manager.cc:643] P 891bcb87f7644e7aa45312337f99d3cc: FlushDeltaMemStoresOp(1222fe41ac9d4328aa2dab76f1b378b4) complete. Timing: real 0.042s	user 0.026s	sys 0.015s Metrics: {"bytes_written":12717735,"delete_count":0,"lbm_write_time_us":18682,"lbm_writes_1-10_ms":2,"lbm_writes_lt_1ms":311,"reinsert_count":0,"update_count":1550}
I20260812 06:18:23.498986 23088 maintenance_manager.cc:419] P 891bcb87f7644e7aa45312337f99d3cc: Scheduling FlushDeltaMemStoresOp(1222fe41ac9d4328aa2dab76f1b378b4): perf score=2.188937
I20260812 06:18:23.516404 22995 maintenance_manager.cc:643] P 891bcb87f7644e7aa45312337f99d3cc: FlushDeltaMemStoresOp(1222fe41ac9d4328aa2dab76f1b378b4) complete. Timing: real 0.017s	user 0.013s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6191,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:23.516947 23088 maintenance_manager.cc:419] P 891bcb87f7644e7aa45312337f99d3cc: Scheduling FlushDeltaMemStoresOp(1222fe41ac9d4328aa2dab76f1b378b4): perf score=2.188937
I20260812 06:18:23.540815 22995 maintenance_manager.cc:643] P 891bcb87f7644e7aa45312337f99d3cc: FlushDeltaMemStoresOp(1222fe41ac9d4328aa2dab76f1b378b4) complete. Timing: real 0.024s	user 0.003s	sys 0.018s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":5095,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:18:23.541391 23088 maintenance_manager.cc:419] P 891bcb87f7644e7aa45312337f99d3cc: Scheduling MajorDeltaCompactionOp(1222fe41ac9d4328aa2dab76f1b378b4): perf score=1.000000
I20260812 06:18:23.716751 22995 maintenance_manager.cc:643] P 891bcb87f7644e7aa45312337f99d3cc: MajorDeltaCompactionOp(1222fe41ac9d4328aa2dab76f1b378b4) complete. Timing: real 0.175s	user 0.110s	sys 0.065s Metrics: {"cfile_cache_miss":533,"cfile_cache_miss_bytes":24774799,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":939,"lbm_read_time_us":14803,"lbm_reads_lt_1ms":573,"lbm_write_time_us":28688,"lbm_writes_lt_1ms":543,"mutex_wait_us":258,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":8704,"update_count":2500}
I20260812 06:18:23.717602 23088 maintenance_manager.cc:419] P 891bcb87f7644e7aa45312337f99d3cc: Scheduling FlushDeltaMemStoresOp(1222fe41ac9d4328aa2dab76f1b378b4): perf score=10.126437
I20260812 06:18:23.756086 22995 maintenance_manager.cc:643] P 891bcb87f7644e7aa45312337f99d3cc: FlushDeltaMemStoresOp(1222fe41ac9d4328aa2dab76f1b378b4) complete. Timing: real 0.038s	user 0.027s	sys 0.009s Metrics: {"bytes_written":12307491,"delete_count":0,"lbm_write_time_us":16979,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:18:23.756704 23088 maintenance_manager.cc:419] P 891bcb87f7644e7aa45312337f99d3cc: Scheduling FlushDeltaMemStoresOp(1222fe41ac9d4328aa2dab76f1b378b4): perf score=2.188937
I20260812 06:18:23.770815 22995 maintenance_manager.cc:643] P 891bcb87f7644e7aa45312337f99d3cc: FlushDeltaMemStoresOp(1222fe41ac9d4328aa2dab76f1b378b4) complete. Timing: real 0.014s	user 0.009s	sys 0.005s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5486,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:23.771421 23088 maintenance_manager.cc:419] P 891bcb87f7644e7aa45312337f99d3cc: Scheduling FlushMRSOp(1222fe41ac9d4328aa2dab76f1b378b4): perf score=1.000000
I20260812 06:18:23.800745 22995 maintenance_manager.cc:643] P 891bcb87f7644e7aa45312337f99d3cc: FlushMRSOp(1222fe41ac9d4328aa2dab76f1b378b4) complete. Timing: real 0.029s	user 0.027s	sys 0.000s Metrics: {"bytes_written":1275449,"cfile_init":1,"dirs.queue_time_us":73,"dirs.run_cpu_time_us":236,"dirs.run_wall_time_us":1466,"drs_written":1,"lbm_read_time_us":40,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1638,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":31}
I20260812 06:18:23.801465 23088 maintenance_manager.cc:419] P 891bcb87f7644e7aa45312337f99d3cc: Scheduling LogGCOp(1222fe41ac9d4328aa2dab76f1b378b4): free 124257263 bytes of WAL
I20260812 06:18:23.801720 22995 log_reader.cc:385] T 1222fe41ac9d4328aa2dab76f1b378b4: removed 12 log segments from log reader
I20260812 06:18:23.801787 22995 log.cc:1079] T 1222fe41ac9d4328aa2dab76f1b378b4 P 891bcb87f7644e7aa45312337f99d3cc: Deleting log segment in path: /tmp/dist-test-taskVApfHZ/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515500541946-22822-0/minicluster-data/ts-0-root/wals/1222fe41ac9d4328aa2dab76f1b378b4/wal-000000015 (ops 70-74)
I20260812 06:18:23.801839 22995 log.cc:1079] T 1222fe41ac9d4328aa2dab76f1b378b4 P 891bcb87f7644e7aa45312337f99d3cc: Deleting log segment in path: /tmp/dist-test-taskVApfHZ/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515500541946-22822-0/minicluster-data/ts-0-root/wals/1222fe41ac9d4328aa2dab76f1b378b4/wal-000000016 (ops 75-79)
I20260812 06:18:23.801898 22995 log.cc:1079] T 1222fe41ac9d4328aa2dab76f1b378b4 P 891bcb87f7644e7aa45312337f99d3cc: Deleting log segment in path: /tmp/dist-test-taskVApfHZ/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515500541946-22822-0/minicluster-data/ts-0-root/wals/1222fe41ac9d4328aa2dab76f1b378b4/wal-000000017 (ops 80-84)
I20260812 06:18:23.801939 22995 log.cc:1079] T 1222fe41ac9d4328aa2dab76f1b378b4 P 891bcb87f7644e7aa45312337f99d3cc: Deleting log segment in path: /tmp/dist-test-taskVApfHZ/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515500541946-22822-0/minicluster-data/ts-0-root/wals/1222fe41ac9d4328aa2dab76f1b378b4/wal-000000018 (ops 85-89)
I20260812 06:18:23.801975 22995 log.cc:1079] T 1222fe41ac9d4328aa2dab76f1b378b4 P 891bcb87f7644e7aa45312337f99d3cc: Deleting log segment in path: /tmp/dist-test-taskVApfHZ/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515500541946-22822-0/minicluster-data/ts-0-root/wals/1222fe41ac9d4328aa2dab76f1b378b4/wal-000000019 (ops 90-94)
I20260812 06:18:23.802011 22995 log.cc:1079] T 1222fe41ac9d4328aa2dab76f1b378b4 P 891bcb87f7644e7aa45312337f99d3cc: Deleting log segment in path: /tmp/dist-test-taskVApfHZ/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515500541946-22822-0/minicluster-data/ts-0-root/wals/1222fe41ac9d4328aa2dab76f1b378b4/wal-000000020 (ops 95-99)
I20260812 06:18:23.802047 22995 log.cc:1079] T 1222fe41ac9d4328aa2dab76f1b378b4 P 891bcb87f7644e7aa45312337f99d3cc: Deleting log segment in path: /tmp/dist-test-taskVApfHZ/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515500541946-22822-0/minicluster-data/ts-0-root/wals/1222fe41ac9d4328aa2dab76f1b378b4/wal-000000021 (ops 100-104)
I20260812 06:18:23.802083 22995 log.cc:1079] T 1222fe41ac9d4328aa2dab76f1b378b4 P 891bcb87f7644e7aa45312337f99d3cc: Deleting log segment in path: /tmp/dist-test-taskVApfHZ/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515500541946-22822-0/minicluster-data/ts-0-root/wals/1222fe41ac9d4328aa2dab76f1b378b4/wal-000000022 (ops 105-109)
I20260812 06:18:23.802119 22995 log.cc:1079] T 1222fe41ac9d4328aa2dab76f1b378b4 P 891bcb87f7644e7aa45312337f99d3cc: Deleting log segment in path: /tmp/dist-test-taskVApfHZ/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515500541946-22822-0/minicluster-data/ts-0-root/wals/1222fe41ac9d4328aa2dab76f1b378b4/wal-000000023 (ops 110-114)
I20260812 06:18:23.802155 22995 log.cc:1079] T 1222fe41ac9d4328aa2dab76f1b378b4 P 891bcb87f7644e7aa45312337f99d3cc: Deleting log segment in path: /tmp/dist-test-taskVApfHZ/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515500541946-22822-0/minicluster-data/ts-0-root/wals/1222fe41ac9d4328aa2dab76f1b378b4/wal-000000024 (ops 115-118)
I20260812 06:18:23.802191 22995 log.cc:1079] T 1222fe41ac9d4328aa2dab76f1b378b4 P 891bcb87f7644e7aa45312337f99d3cc: Deleting log segment in path: /tmp/dist-test-taskVApfHZ/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515500541946-22822-0/minicluster-data/ts-0-root/wals/1222fe41ac9d4328aa2dab76f1b378b4/wal-000000025 (ops 119-123)
I20260812 06:18:23.802258 22995 log.cc:1079] T 1222fe41ac9d4328aa2dab76f1b378b4 P 891bcb87f7644e7aa45312337f99d3cc: Deleting log segment in path: /tmp/dist-test-taskVApfHZ/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515500541946-22822-0/minicluster-data/ts-0-root/wals/1222fe41ac9d4328aa2dab76f1b378b4/wal-000000026 (ops 124-128)
I20260812 06:18:23.831977 22995 maintenance_manager.cc:643] P 891bcb87f7644e7aa45312337f99d3cc: LogGCOp(1222fe41ac9d4328aa2dab76f1b378b4) complete. Timing: real 0.030s	user 0.002s	sys 0.027s Metrics: {}
I20260812 06:18:23.832686 23088 maintenance_manager.cc:419] P 891bcb87f7644e7aa45312337f99d3cc: Scheduling FlushDeltaMemStoresOp(1222fe41ac9d4328aa2dab76f1b378b4): perf score=5.165500
I20260812 06:18:23.852416 22995 maintenance_manager.cc:643] P 891bcb87f7644e7aa45312337f99d3cc: FlushDeltaMemStoresOp(1222fe41ac9d4328aa2dab76f1b378b4) complete. Timing: real 0.020s	user 0.014s	sys 0.003s Metrics: {"bytes_written":6605135,"delete_count":0,"lbm_write_time_us":8536,"lbm_writes_lt_1ms":164,"reinsert_count":0,"update_count":805}
I20260812 06:18:23.852874 23088 maintenance_manager.cc:419] P 891bcb87f7644e7aa45312337f99d3cc: Scheduling FlushDeltaMemStoresOp(1222fe41ac9d4328aa2dab76f1b378b4): perf score=1.000000
I20260812 06:18:23.858444 22995 maintenance_manager.cc:643] P 891bcb87f7644e7aa45312337f99d3cc: FlushDeltaMemStoresOp(1222fe41ac9d4328aa2dab76f1b378b4) complete. Timing: real 0.005s	user 0.005s	sys 0.000s Metrics: {"bytes_written":1600127,"delete_count":0,"lbm_write_time_us":1601,"lbm_writes_lt_1ms":42,"reinsert_count":0,"update_count":195}
I20260812 06:18:23.858881 23088 maintenance_manager.cc:419] P 891bcb87f7644e7aa45312337f99d3cc: Scheduling MajorDeltaCompactionOp(1222fe41ac9d4328aa2dab76f1b378b4): perf score=1.000000
I20260812 06:18:24.046003 22995 maintenance_manager.cc:643] P 891bcb87f7644e7aa45312337f99d3cc: MajorDeltaCompactionOp(1222fe41ac9d4328aa2dab76f1b378b4) complete. Timing: real 0.187s	user 0.146s	sys 0.040s Metrics: {"cfile_cache_miss":634,"cfile_cache_miss_bytes":28877279,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":304,"lbm_read_time_us":13800,"lbm_reads_lt_1ms":674,"lbm_write_time_us":31559,"lbm_writes_lt_1ms":643,"mutex_wait_us":46,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":643584,"thread_start_us":77,"threads_started":1,"update_count":3000}
I20260812 06:18:24.046761 23088 maintenance_manager.cc:419] P 891bcb87f7644e7aa45312337f99d3cc: Scheduling UndoDeltaBlockGCOp(1222fe41ac9d4328aa2dab76f1b378b4): 482 bytes on disk
I20260812 06:18:24.047303 22995 maintenance_manager.cc:643] P 891bcb87f7644e7aa45312337f99d3cc: UndoDeltaBlockGCOp(1222fe41ac9d4328aa2dab76f1b378b4) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":91,"lbm_reads_lt_1ms":4}
I20260812 06:18:24.048079 23088 maintenance_manager.cc:419] P 891bcb87f7644e7aa45312337f99d3cc: Scheduling FlushDeltaMemStoresOp(1222fe41ac9d4328aa2dab76f1b378b4): perf score=14.095187
I20260812 06:18:24.109809 22995 maintenance_manager.cc:643] P 891bcb87f7644e7aa45312337f99d3cc: FlushDeltaMemStoresOp(1222fe41ac9d4328aa2dab76f1b378b4) complete. Timing: real 0.062s	user 0.035s	sys 0.023s Metrics: {"bytes_written":16409903,"delete_count":0,"lbm_write_time_us":23443,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":402,"reinsert_count":0,"update_count":2000}
I20260812 06:18:24.110517 23088 maintenance_manager.cc:419] P 891bcb87f7644e7aa45312337f99d3cc: Scheduling FlushDeltaMemStoresOp(1222fe41ac9d4328aa2dab76f1b378b4): perf score=2.188937
I20260812 06:18:24.126304 22995 maintenance_manager.cc:643] P 891bcb87f7644e7aa45312337f99d3cc: FlushDeltaMemStoresOp(1222fe41ac9d4328aa2dab76f1b378b4) complete. Timing: real 0.016s	user 0.006s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5719,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:24.126819 23088 maintenance_manager.cc:419] P 891bcb87f7644e7aa45312337f99d3cc: Scheduling MajorDeltaCompactionOp(1222fe41ac9d4328aa2dab76f1b378b4): perf score=1.000000
I20260812 06:18:24.285523 22995 maintenance_manager.cc:643] P 891bcb87f7644e7aa45312337f99d3cc: MajorDeltaCompactionOp(1222fe41ac9d4328aa2dab76f1b378b4) complete. Timing: real 0.159s	user 0.118s	sys 0.040s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774690,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":755,"lbm_read_time_us":11878,"lbm_reads_lt_1ms":564,"lbm_write_time_us":25908,"lbm_writes_lt_1ms":543,"mutex_wait_us":295,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":16512,"update_count":2500}
I20260812 06:18:24.286279 23088 maintenance_manager.cc:419] P 891bcb87f7644e7aa45312337f99d3cc: Scheduling FlushDeltaMemStoresOp(1222fe41ac9d4328aa2dab76f1b378b4): perf score=14.095187
I20260812 06:18:24.352986 22995 maintenance_manager.cc:643] P 891bcb87f7644e7aa45312337f99d3cc: FlushDeltaMemStoresOp(1222fe41ac9d4328aa2dab76f1b378b4) complete. Timing: real 0.066s	user 0.027s	sys 0.035s Metrics: {"bytes_written":16409903,"delete_count":0,"lbm_write_time_us":25095,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":402,"reinsert_count":0,"update_count":2000}
I20260812 06:18:24.353663 23088 maintenance_manager.cc:419] P 891bcb87f7644e7aa45312337f99d3cc: Scheduling FlushDeltaMemStoresOp(1222fe41ac9d4328aa2dab76f1b378b4): perf score=2.188937
I20260812 06:18:24.373382 22995 maintenance_manager.cc:643] P 891bcb87f7644e7aa45312337f99d3cc: FlushDeltaMemStoresOp(1222fe41ac9d4328aa2dab76f1b378b4) complete. Timing: real 0.020s	user 0.007s	sys 0.007s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":6212,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:24.373937 23088 maintenance_manager.cc:419] P 891bcb87f7644e7aa45312337f99d3cc: Scheduling MajorDeltaCompactionOp(1222fe41ac9d4328aa2dab76f1b378b4): perf score=1.000000
I20260812 06:18:24.551357 22995 maintenance_manager.cc:643] P 891bcb87f7644e7aa45312337f99d3cc: MajorDeltaCompactionOp(1222fe41ac9d4328aa2dab76f1b378b4) complete. Timing: real 0.177s	user 0.133s	sys 0.044s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774689,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":756,"lbm_read_time_us":10613,"lbm_reads_lt_1ms":564,"lbm_write_time_us":30599,"lbm_writes_lt_1ms":543,"mutex_wait_us":8,"peak_mem_usage":63115900,"reinsert_count":0,"update_count":2500}
I20260812 06:18:24.554937 23088 maintenance_manager.cc:419] P 891bcb87f7644e7aa45312337f99d3cc: Scheduling FlushDeltaMemStoresOp(1222fe41ac9d4328aa2dab76f1b378b4): perf score=14.095187
I20260812 06:18:24.608879 22995 maintenance_manager.cc:643] P 891bcb87f7644e7aa45312337f99d3cc: FlushDeltaMemStoresOp(1222fe41ac9d4328aa2dab76f1b378b4) complete. Timing: real 0.054s	user 0.038s	sys 0.013s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":23921,"lbm_writes_lt_1ms":403,"mutex_wait_us":3,"reinsert_count":0,"update_count":2000}
I20260812 06:18:24.609448 23088 maintenance_manager.cc:419] P 891bcb87f7644e7aa45312337f99d3cc: Scheduling FlushDeltaMemStoresOp(1222fe41ac9d4328aa2dab76f1b378b4): perf score=2.188937
I20260812 06:18:24.624812 22995 maintenance_manager.cc:643] P 891bcb87f7644e7aa45312337f99d3cc: FlushDeltaMemStoresOp(1222fe41ac9d4328aa2dab76f1b378b4) complete. Timing: real 0.015s	user 0.008s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5767,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:24.625474 23088 maintenance_manager.cc:419] P 891bcb87f7644e7aa45312337f99d3cc: Scheduling MajorDeltaCompactionOp(1222fe41ac9d4328aa2dab76f1b378b4): perf score=1.000000
I20260812 06:18:24.817585 22995 maintenance_manager.cc:643] P 891bcb87f7644e7aa45312337f99d3cc: MajorDeltaCompactionOp(1222fe41ac9d4328aa2dab76f1b378b4) complete. Timing: real 0.192s	user 0.146s	sys 0.033s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774688,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":811,"lbm_read_time_us":10599,"lbm_reads_lt_1ms":572,"lbm_write_time_us":30938,"lbm_writes_lt_1ms":543,"mutex_wait_us":311,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":2304,"update_count":2500}
I20260812 06:18:24.818300 23088 maintenance_manager.cc:419] P 891bcb87f7644e7aa45312337f99d3cc: Scheduling FlushDeltaMemStoresOp(1222fe41ac9d4328aa2dab76f1b378b4): perf score=14.095187
I20260812 06:18:24.874380 22995 maintenance_manager.cc:643] P 891bcb87f7644e7aa45312337f99d3cc: FlushDeltaMemStoresOp(1222fe41ac9d4328aa2dab76f1b378b4) complete. Timing: real 0.056s	user 0.036s	sys 0.020s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":24381,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:18:24.875002 23088 maintenance_manager.cc:419] P 891bcb87f7644e7aa45312337f99d3cc: Scheduling FlushDeltaMemStoresOp(1222fe41ac9d4328aa2dab76f1b378b4): perf score=2.188937
I20260812 06:18:24.895730 22995 maintenance_manager.cc:643] P 891bcb87f7644e7aa45312337f99d3cc: FlushDeltaMemStoresOp(1222fe41ac9d4328aa2dab76f1b378b4) complete. Timing: real 0.020s	user 0.010s	sys 0.004s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":6183,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:24.896345 23088 maintenance_manager.cc:419] P 891bcb87f7644e7aa45312337f99d3cc: Scheduling MajorDeltaCompactionOp(1222fe41ac9d4328aa2dab76f1b378b4): perf score=1.000000
I20260812 06:18:25.050356 22995 maintenance_manager.cc:643] P 891bcb87f7644e7aa45312337f99d3cc: MajorDeltaCompactionOp(1222fe41ac9d4328aa2dab76f1b378b4) complete. Timing: real 0.154s	user 0.106s	sys 0.036s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774687,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":638,"lbm_read_time_us":10484,"lbm_reads_lt_1ms":564,"lbm_write_time_us":27972,"lbm_writes_lt_1ms":543,"mutex_wait_us":71,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":15616,"update_count":2500}
I20260812 06:18:25.051028 23088 maintenance_manager.cc:419] P 891bcb87f7644e7aa45312337f99d3cc: Scheduling FlushDeltaMemStoresOp(1222fe41ac9d4328aa2dab76f1b378b4): perf score=14.095187
I20260812 06:18:25.101867 22995 maintenance_manager.cc:643] P 891bcb87f7644e7aa45312337f99d3cc: FlushDeltaMemStoresOp(1222fe41ac9d4328aa2dab76f1b378b4) complete. Timing: real 0.051s	user 0.033s	sys 0.012s Metrics: {"bytes_written":16409904,"delete_count":0,"lbm_write_time_us":21899,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:18:25.102497 23088 maintenance_manager.cc:419] P 891bcb87f7644e7aa45312337f99d3cc: Scheduling FlushDeltaMemStoresOp(1222fe41ac9d4328aa2dab76f1b378b4): perf score=2.188937
I20260812 06:18:25.113863 22995 maintenance_manager.cc:643] P 891bcb87f7644e7aa45312337f99d3cc: FlushDeltaMemStoresOp(1222fe41ac9d4328aa2dab76f1b378b4) complete. Timing: real 0.011s	user 0.001s	sys 0.008s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4309,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:25.114406 23088 maintenance_manager.cc:419] P 891bcb87f7644e7aa45312337f99d3cc: Scheduling MajorDeltaCompactionOp(1222fe41ac9d4328aa2dab76f1b378b4): perf score=1.000000
I20260812 06:18:25.271763 22995 maintenance_manager.cc:643] P 891bcb87f7644e7aa45312337f99d3cc: MajorDeltaCompactionOp(1222fe41ac9d4328aa2dab76f1b378b4) complete. Timing: real 0.157s	user 0.112s	sys 0.037s 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":1049,"lbm_read_time_us":10660,"lbm_reads_lt_1ms":572,"lbm_write_time_us":30278,"lbm_writes_lt_1ms":543,"mutex_wait_us":76,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":16000,"update_count":2500}
I20260812 06:18:25.272650 23088 maintenance_manager.cc:419] P 891bcb87f7644e7aa45312337f99d3cc: Scheduling FlushDeltaMemStoresOp(1222fe41ac9d4328aa2dab76f1b378b4): perf score=14.095187
I20260812 06:18:25.320345 22995 maintenance_manager.cc:643] P 891bcb87f7644e7aa45312337f99d3cc: FlushDeltaMemStoresOp(1222fe41ac9d4328aa2dab76f1b378b4) complete. Timing: real 0.048s	user 0.021s	sys 0.023s Metrics: {"bytes_written":16409903,"delete_count":0,"lbm_write_time_us":21636,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":402,"reinsert_count":0,"update_count":2000}
I20260812 06:18:25.321012 23088 maintenance_manager.cc:419] P 891bcb87f7644e7aa45312337f99d3cc: Scheduling FlushDeltaMemStoresOp(1222fe41ac9d4328aa2dab76f1b378b4): perf score=2.188937
I20260812 06:18:25.331812 22995 maintenance_manager.cc:643] P 891bcb87f7644e7aa45312337f99d3cc: FlushDeltaMemStoresOp(1222fe41ac9d4328aa2dab76f1b378b4) complete. Timing: real 0.011s	user 0.005s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4122,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:25.332566 23088 maintenance_manager.cc:419] P 891bcb87f7644e7aa45312337f99d3cc: Scheduling FlushMRSOp(1222fe41ac9d4328aa2dab76f1b378b4): perf score=1.000000
I20260812 06:18:25.365460 22995 maintenance_manager.cc:643] P 891bcb87f7644e7aa45312337f99d3cc: FlushMRSOp(1222fe41ac9d4328aa2dab76f1b378b4) complete. Timing: real 0.033s	user 0.030s	sys 0.001s Metrics: {"bytes_written":1275447,"cfile_init":1,"dirs.queue_time_us":59,"dirs.run_cpu_time_us":230,"dirs.run_wall_time_us":1655,"drs_written":1,"lbm_read_time_us":38,"lbm_reads_lt_1ms":4,"lbm_write_time_us":2328,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":31}
I20260812 06:18:25.366118 23088 maintenance_manager.cc:419] P 891bcb87f7644e7aa45312337f99d3cc: Scheduling LogGCOp(1222fe41ac9d4328aa2dab76f1b378b4): free 129320782 bytes of WAL
I20260812 06:18:25.366361 22995 log_reader.cc:385] T 1222fe41ac9d4328aa2dab76f1b378b4: removed 13 log segments from log reader
I20260812 06:18:25.366425 22995 log.cc:1079] T 1222fe41ac9d4328aa2dab76f1b378b4 P 891bcb87f7644e7aa45312337f99d3cc: Deleting log segment in path: /tmp/dist-test-taskVApfHZ/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515500541946-22822-0/minicluster-data/ts-0-root/wals/1222fe41ac9d4328aa2dab76f1b378b4/wal-000000027 (ops 129-133)
I20260812 06:18:25.366478 22995 log.cc:1079] T 1222fe41ac9d4328aa2dab76f1b378b4 P 891bcb87f7644e7aa45312337f99d3cc: Deleting log segment in path: /tmp/dist-test-taskVApfHZ/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515500541946-22822-0/minicluster-data/ts-0-root/wals/1222fe41ac9d4328aa2dab76f1b378b4/wal-000000028 (ops 134-138)
I20260812 06:18:25.366536 22995 log.cc:1079] T 1222fe41ac9d4328aa2dab76f1b378b4 P 891bcb87f7644e7aa45312337f99d3cc: Deleting log segment in path: /tmp/dist-test-taskVApfHZ/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515500541946-22822-0/minicluster-data/ts-0-root/wals/1222fe41ac9d4328aa2dab76f1b378b4/wal-000000029 (ops 139-143)
I20260812 06:18:25.366582 22995 log.cc:1079] T 1222fe41ac9d4328aa2dab76f1b378b4 P 891bcb87f7644e7aa45312337f99d3cc: Deleting log segment in path: /tmp/dist-test-taskVApfHZ/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515500541946-22822-0/minicluster-data/ts-0-root/wals/1222fe41ac9d4328aa2dab76f1b378b4/wal-000000030 (ops 144-148)
I20260812 06:18:25.366631 22995 log.cc:1079] T 1222fe41ac9d4328aa2dab76f1b378b4 P 891bcb87f7644e7aa45312337f99d3cc: Deleting log segment in path: /tmp/dist-test-taskVApfHZ/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515500541946-22822-0/minicluster-data/ts-0-root/wals/1222fe41ac9d4328aa2dab76f1b378b4/wal-000000031 (ops 149-152)
I20260812 06:18:25.366670 22995 log.cc:1079] T 1222fe41ac9d4328aa2dab76f1b378b4 P 891bcb87f7644e7aa45312337f99d3cc: Deleting log segment in path: /tmp/dist-test-taskVApfHZ/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515500541946-22822-0/minicluster-data/ts-0-root/wals/1222fe41ac9d4328aa2dab76f1b378b4/wal-000000032 (ops 153-157)
I20260812 06:18:25.366706 22995 log.cc:1079] T 1222fe41ac9d4328aa2dab76f1b378b4 P 891bcb87f7644e7aa45312337f99d3cc: Deleting log segment in path: /tmp/dist-test-taskVApfHZ/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515500541946-22822-0/minicluster-data/ts-0-root/wals/1222fe41ac9d4328aa2dab76f1b378b4/wal-000000033 (ops 158-162)
I20260812 06:18:25.366742 22995 log.cc:1079] T 1222fe41ac9d4328aa2dab76f1b378b4 P 891bcb87f7644e7aa45312337f99d3cc: Deleting log segment in path: /tmp/dist-test-taskVApfHZ/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515500541946-22822-0/minicluster-data/ts-0-root/wals/1222fe41ac9d4328aa2dab76f1b378b4/wal-000000034 (ops 163-166)
I20260812 06:18:25.366778 22995 log.cc:1079] T 1222fe41ac9d4328aa2dab76f1b378b4 P 891bcb87f7644e7aa45312337f99d3cc: Deleting log segment in path: /tmp/dist-test-taskVApfHZ/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515500541946-22822-0/minicluster-data/ts-0-root/wals/1222fe41ac9d4328aa2dab76f1b378b4/wal-000000035 (ops 167-171)
I20260812 06:18:25.366816 22995 log.cc:1079] T 1222fe41ac9d4328aa2dab76f1b378b4 P 891bcb87f7644e7aa45312337f99d3cc: Deleting log segment in path: /tmp/dist-test-taskVApfHZ/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515500541946-22822-0/minicluster-data/ts-0-root/wals/1222fe41ac9d4328aa2dab76f1b378b4/wal-000000036 (ops 172-176)
I20260812 06:18:25.366853 22995 log.cc:1079] T 1222fe41ac9d4328aa2dab76f1b378b4 P 891bcb87f7644e7aa45312337f99d3cc: Deleting log segment in path: /tmp/dist-test-taskVApfHZ/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515500541946-22822-0/minicluster-data/ts-0-root/wals/1222fe41ac9d4328aa2dab76f1b378b4/wal-000000037 (ops 177-181)
I20260812 06:18:25.366889 22995 log.cc:1079] T 1222fe41ac9d4328aa2dab76f1b378b4 P 891bcb87f7644e7aa45312337f99d3cc: Deleting log segment in path: /tmp/dist-test-taskVApfHZ/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515500541946-22822-0/minicluster-data/ts-0-root/wals/1222fe41ac9d4328aa2dab76f1b378b4/wal-000000038 (ops 182-186)
I20260812 06:18:25.366925 22995 log.cc:1079] T 1222fe41ac9d4328aa2dab76f1b378b4 P 891bcb87f7644e7aa45312337f99d3cc: Deleting log segment in path: /tmp/dist-test-taskVApfHZ/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515500541946-22822-0/minicluster-data/ts-0-root/wals/1222fe41ac9d4328aa2dab76f1b378b4/wal-000000039 (ops 187-191)
I20260812 06:18:25.395881 22995 maintenance_manager.cc:643] P 891bcb87f7644e7aa45312337f99d3cc: LogGCOp(1222fe41ac9d4328aa2dab76f1b378b4) complete. Timing: real 0.030s	user 0.000s	sys 0.027s Metrics: {}
I20260812 06:18:25.396271 23088 maintenance_manager.cc:419] P 891bcb87f7644e7aa45312337f99d3cc: Scheduling FlushDeltaMemStoresOp(1222fe41ac9d4328aa2dab76f1b378b4): perf score=4.173312
I20260812 06:18:25.409897 22995 maintenance_manager.cc:643] P 891bcb87f7644e7aa45312337f99d3cc: FlushDeltaMemStoresOp(1222fe41ac9d4328aa2dab76f1b378b4) complete. Timing: real 0.013s	user 0.012s	sys 0.000s Metrics: {"bytes_written":5497489,"delete_count":0,"lbm_write_time_us":5477,"lbm_writes_lt_1ms":137,"reinsert_count":0,"update_count":670}
I20260812 06:18:25.410449 23088 maintenance_manager.cc:419] P 891bcb87f7644e7aa45312337f99d3cc: Scheduling FlushDeltaMemStoresOp(1222fe41ac9d4328aa2dab76f1b378b4): perf score=1.196750
I20260812 06:18:25.420217 22995 maintenance_manager.cc:643] P 891bcb87f7644e7aa45312337f99d3cc: FlushDeltaMemStoresOp(1222fe41ac9d4328aa2dab76f1b378b4) complete. Timing: real 0.010s	user 0.007s	sys 0.001s Metrics: {"bytes_written":2707805,"delete_count":0,"lbm_write_time_us":2948,"lbm_writes_lt_1ms":69,"reinsert_count":0,"update_count":330}
I20260812 06:18:25.420790 23088 maintenance_manager.cc:419] P 891bcb87f7644e7aa45312337f99d3cc: Scheduling UndoDeltaBlockGCOp(1222fe41ac9d4328aa2dab76f1b378b4): 483 bytes on disk
I20260812 06:18:25.421346 22995 maintenance_manager.cc:643] P 891bcb87f7644e7aa45312337f99d3cc: UndoDeltaBlockGCOp(1222fe41ac9d4328aa2dab76f1b378b4) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":94,"lbm_reads_lt_1ms":4}
I20260812 06:18:25.422271 23088 maintenance_manager.cc:419] P 891bcb87f7644e7aa45312337f99d3cc: Scheduling MajorDeltaCompactionOp(1222fe41ac9d4328aa2dab76f1b378b4): perf score=1.000000
I20260812 06:18:25.569047 22822 heavy-update-compaction-itest.cc:229] Time spent updating: real 4.732s	user 1.802s	sys 0.128s
I20260812 06:18:25.642552 22995 maintenance_manager.cc:643] P 891bcb87f7644e7aa45312337f99d3cc: MajorDeltaCompactionOp(1222fe41ac9d4328aa2dab76f1b378b4) complete. Timing: real 0.218s	user 0.142s	sys 0.071s Metrics: {"cfile_cache_miss":734,"cfile_cache_miss_bytes":32979722,"cfile_init":7,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":448,"lbm_read_time_us":15606,"lbm_reads_lt_1ms":762,"lbm_write_time_us":37322,"lbm_writes_lt_1ms":743,"mutex_wait_us":846,"peak_mem_usage":87969044,"reinsert_count":0,"spinlock_wait_cycles":11904,"thread_start_us":100,"threads_started":1,"update_count":3500}
I20260812 06:18:25.643421 23088 maintenance_manager.cc:419] P 891bcb87f7644e7aa45312337f99d3cc: Scheduling FlushDeltaMemStoresOp(1222fe41ac9d4328aa2dab76f1b378b4): perf score=10.126437
I20260812 06:18:25.658049 22822 heavy-update-compaction-itest.cc:265] Time spent scanning: real 0.088s	user 0.001s	sys 0.000s
I20260812 06:18:25.658738 22822 tablet_server.cc:179] TabletServer@127.22.73.129:0 shutting down...
I20260812 06:18:25.682472 22995 maintenance_manager.cc:643] P 891bcb87f7644e7aa45312337f99d3cc: FlushDeltaMemStoresOp(1222fe41ac9d4328aa2dab76f1b378b4) complete. Timing: real 0.039s	user 0.025s	sys 0.011s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":18589,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":302,"reinsert_count":0,"update_count":1500}
I20260812 06:18:25.683154 22822 ts_tablet_manager.cc:1507] Shutting down tablet manager...
I20260812 06:18:25.683594 22822 tablet_replica.cc:333] T 1222fe41ac9d4328aa2dab76f1b378b4 P 891bcb87f7644e7aa45312337f99d3cc: stopping tablet replica
I20260812 06:18:25.683832 22822 raft_consensus.cc:2243] T 1222fe41ac9d4328aa2dab76f1b378b4 P 891bcb87f7644e7aa45312337f99d3cc [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:18:25.684074 22822 raft_consensus.cc:2272] T 1222fe41ac9d4328aa2dab76f1b378b4 P 891bcb87f7644e7aa45312337f99d3cc [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:18:25.688853 22822 tablet_server.cc:196] TabletServer@127.22.73.129:0 shutdown complete.
I20260812 06:18:25.700937 22822 master.cc:562] Master@127.22.73.190:41271 shutting down...
I20260812 06:18:25.704852 22822 raft_consensus.cc:2243] T 00000000000000000000000000000000 P b17b81fcd2474997a07ecf6b5975e47c [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:18:25.705070 22822 raft_consensus.cc:2272] T 00000000000000000000000000000000 P b17b81fcd2474997a07ecf6b5975e47c [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:18:25.705170 22822 tablet_replica.cc:333] T 00000000000000000000000000000000 P b17b81fcd2474997a07ecf6b5975e47c: stopping tablet replica
I20260812 06:18:25.717844 22822 master.cc:584] Master@127.22.73.190:41271 shutdown complete.
[       OK ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/0 (5254 ms)
[ RUN      ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/1
I20260812 06:18:25.819814 22822 internal_mini_cluster.cc:156] Creating distributed mini masters. Addrs: 127.22.73.190:44755
I20260812 06:18:25.820286 22822 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:18:25.822576 23147 instance_detector.cc:116] could not retrieve OpenStack instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:18:25.822587 23144 instance_detector.cc:116] could not retrieve Azure instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:18:25.822588 23143 instance_detector.cc:116] could not retrieve AWS instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:18:25.822763 22822 server_base.cc:1061] running on GCE node
I20260812 06:18:25.823019 22822 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:18:25.823066 22822 system_unsync_time.cc:38] NTP support is disabled. Clock error bounds will not be accurate. This configuration is not suitable for distributed clusters.
I20260812 06:18:25.823082 22822 hybrid_clock.cc:648] HybridClock initialized: now 1786515505823083 us; error 0 us; skew 500 ppm
I20260812 06:18:25.823967 22822 webserver.cc:533] Webserver started at http://127.22.73.190:39939/ using document root <none> and password file <none>
I20260812 06:18:25.824149 22822 fs_manager.cc:362] Metadata directory not provided
I20260812 06:18:25.824214 22822 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:18:25.824273 22822 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:18:25.824651 22822 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskVApfHZ/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515500541946-22822-0/minicluster-data/master-0-root/instance:
uuid: "26c615fb01ae4ae4b7659f8790afc3e0"
format_stamp: "Formatted at 2026-08-12 06:18:25 on dist-test-slave-jztv"
I20260812 06:18:25.826195 22822 fs_manager.cc:696] Time spent creating directory manager: real 0.001s	user 0.002s	sys 0.000s
I20260812 06:18:25.827405 23153 log_block_manager.cc:4127] Time spent loading block containers with low live blocks: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:18:25.827752 22822 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.001s	sys 0.000s
I20260812 06:18:25.827864 22822 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskVApfHZ/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515500541946-22822-0/minicluster-data/master-0-root
uuid: "26c615fb01ae4ae4b7659f8790afc3e0"
format_stamp: "Formatted at 2026-08-12 06:18:25 on dist-test-slave-jztv"
I20260812 06:18:25.827972 22822 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskVApfHZ/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515500541946-22822-0/minicluster-data/master-0-root
metadata directory: /tmp/dist-test-taskVApfHZ/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515500541946-22822-0/minicluster-data/master-0-root
1 data directories: /tmp/dist-test-taskVApfHZ/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515500541946-22822-0/minicluster-data/master-0-root/data
Total live blocks: 0
Total live bytes: 0
Total live bytes (after alignment): 0
Total number of LBM containers: 0 (0 full)
Did not check for missing blocks
Did not check for orphaned blocks
Total full LBM containers with extra space: 0 (0 repaired)
Total full LBM container extra space in bytes: 0 (0 repaired)
Total incomplete LBM containers: 0 (0 repaired)
Total LBM partial records: 0 (0 repaired)
Total corrupted LBM metadata records in RocksDB: 0 (0 repaired)
I20260812 06:18:25.838919 22822 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:18:25.839394 22822 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:18:25.844031 22822 rpc_server.cc:307] RPC server started. Bound to: 127.22.73.190:44755
I20260812 06:18:25.846338 23243 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.22.73.190:44755 every 8 connection(s)
I20260812 06:18:25.848486 23245 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet 00000000000000000000000000000000. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:18:25.850562 23245 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P 26c615fb01ae4ae4b7659f8790afc3e0: Bootstrap starting.
I20260812 06:18:25.851328 23245 tablet_bootstrap.cc:654] T 00000000000000000000000000000000 P 26c615fb01ae4ae4b7659f8790afc3e0: Neither blocks nor log segments found. Creating new log.
I20260812 06:18:25.852339 23245 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P 26c615fb01ae4ae4b7659f8790afc3e0: No bootstrap required, opened a new log
I20260812 06:18:25.852735 23245 raft_consensus.cc:359] T 00000000000000000000000000000000 P 26c615fb01ae4ae4b7659f8790afc3e0 [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "26c615fb01ae4ae4b7659f8790afc3e0" member_type: VOTER }
I20260812 06:18:25.852828 23245 raft_consensus.cc:385] T 00000000000000000000000000000000 P 26c615fb01ae4ae4b7659f8790afc3e0 [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:18:25.852852 23245 raft_consensus.cc:740] T 00000000000000000000000000000000 P 26c615fb01ae4ae4b7659f8790afc3e0 [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: 26c615fb01ae4ae4b7659f8790afc3e0, State: Initialized, Role: FOLLOWER
I20260812 06:18:25.853006 23245 consensus_queue.cc:260] T 00000000000000000000000000000000 P 26c615fb01ae4ae4b7659f8790afc3e0 [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: "26c615fb01ae4ae4b7659f8790afc3e0" member_type: VOTER }
I20260812 06:18:25.853107 23245 raft_consensus.cc:399] T 00000000000000000000000000000000 P 26c615fb01ae4ae4b7659f8790afc3e0 [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:18:25.853140 23245 raft_consensus.cc:493] T 00000000000000000000000000000000 P 26c615fb01ae4ae4b7659f8790afc3e0 [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:18:25.853173 23245 raft_consensus.cc:3060] T 00000000000000000000000000000000 P 26c615fb01ae4ae4b7659f8790afc3e0 [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:18:25.853850 23245 raft_consensus.cc:515] T 00000000000000000000000000000000 P 26c615fb01ae4ae4b7659f8790afc3e0 [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "26c615fb01ae4ae4b7659f8790afc3e0" member_type: VOTER }
I20260812 06:18:25.853967 23245 leader_election.cc:304] T 00000000000000000000000000000000 P 26c615fb01ae4ae4b7659f8790afc3e0 [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: 26c615fb01ae4ae4b7659f8790afc3e0; no voters: 
I20260812 06:18:25.854122 23245 leader_election.cc:290] T 00000000000000000000000000000000 P 26c615fb01ae4ae4b7659f8790afc3e0 [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:18:25.854280 23250 raft_consensus.cc:2804] T 00000000000000000000000000000000 P 26c615fb01ae4ae4b7659f8790afc3e0 [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:18:25.854526 23250 raft_consensus.cc:697] T 00000000000000000000000000000000 P 26c615fb01ae4ae4b7659f8790afc3e0 [term 1 LEADER]: Becoming Leader. State: Replica: 26c615fb01ae4ae4b7659f8790afc3e0, State: Running, Role: LEADER
I20260812 06:18:25.854679 23245 sys_catalog.cc:565] T 00000000000000000000000000000000 P 26c615fb01ae4ae4b7659f8790afc3e0 [sys.catalog]: configured and running, proceeding with master startup.
I20260812 06:18:25.854719 23250 consensus_queue.cc:237] T 00000000000000000000000000000000 P 26c615fb01ae4ae4b7659f8790afc3e0 [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: "26c615fb01ae4ae4b7659f8790afc3e0" member_type: VOTER }
I20260812 06:18:25.855201 23253 sys_catalog.cc:455] T 00000000000000000000000000000000 P 26c615fb01ae4ae4b7659f8790afc3e0 [sys.catalog]: SysCatalogTable state changed. Reason: New leader 26c615fb01ae4ae4b7659f8790afc3e0. Latest consensus state: current_term: 1 leader_uuid: "26c615fb01ae4ae4b7659f8790afc3e0" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "26c615fb01ae4ae4b7659f8790afc3e0" member_type: VOTER } }
I20260812 06:18:25.855187 23251 sys_catalog.cc:455] T 00000000000000000000000000000000 P 26c615fb01ae4ae4b7659f8790afc3e0 [sys.catalog]: SysCatalogTable state changed. Reason: RaftConsensus started. Latest consensus state: current_term: 1 leader_uuid: "26c615fb01ae4ae4b7659f8790afc3e0" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "26c615fb01ae4ae4b7659f8790afc3e0" member_type: VOTER } }
I20260812 06:18:25.855298 23253 sys_catalog.cc:458] T 00000000000000000000000000000000 P 26c615fb01ae4ae4b7659f8790afc3e0 [sys.catalog]: This master's current role is: LEADER
I20260812 06:18:25.855309 23251 sys_catalog.cc:458] T 00000000000000000000000000000000 P 26c615fb01ae4ae4b7659f8790afc3e0 [sys.catalog]: This master's current role is: LEADER
I20260812 06:18:25.855638 23257 catalog_manager.cc:1511] Loading table and tablet metadata into memory...
I20260812 06:18:25.856393 23257 catalog_manager.cc:1520] Initializing Kudu cluster ID...
I20260812 06:18:25.856714 22822 internal_mini_cluster.cc:184] Waiting to initialize catalog manager on master 0
I20260812 06:18:25.858294 23257 catalog_manager.cc:1383] Generated new cluster ID: 29fc60ebf92349c2b427874d0cebcf1c
I20260812 06:18:25.858351 23257 catalog_manager.cc:1531] Initializing Kudu internal certificate authority...
I20260812 06:18:25.882961 23257 catalog_manager.cc:1406] Generated new certificate authority record
I20260812 06:18:25.883808 23257 catalog_manager.cc:1540] Loading token signing keys...
I20260812 06:18:25.897536 23257 catalog_manager.cc:6092] T 00000000000000000000000000000000 P 26c615fb01ae4ae4b7659f8790afc3e0: Generated new TSK 0
I20260812 06:18:25.897774 23257 catalog_manager.cc:1550] Initializing in-progress tserver states...
I20260812 06:18:25.921757 22822 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:18:25.924278 23277 instance_detector.cc:116] could not retrieve AWS instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:18:25.924280 23279 instance_detector.cc:116] could not retrieve Azure instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:18:25.924516 23284 instance_detector.cc:116] could not retrieve OpenStack instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:18:25.924413 22822 server_base.cc:1061] running on GCE node
I20260812 06:18:25.924832 22822 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:18:25.924896 22822 system_unsync_time.cc:38] NTP support is disabled. Clock error bounds will not be accurate. This configuration is not suitable for distributed clusters.
I20260812 06:18:25.924924 22822 hybrid_clock.cc:648] HybridClock initialized: now 1786515505924924 us; error 0 us; skew 500 ppm
I20260812 06:18:25.926074 22822 webserver.cc:533] Webserver started at http://127.22.73.129:34439/ using document root <none> and password file <none>
I20260812 06:18:25.926303 22822 fs_manager.cc:362] Metadata directory not provided
I20260812 06:18:25.926373 22822 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:18:25.926465 22822 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:18:25.927016 22822 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskVApfHZ/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515500541946-22822-0/minicluster-data/ts-0-root/instance:
uuid: "10d98943476543d79e3d022c51e2019f"
format_stamp: "Formatted at 2026-08-12 06:18:25 on dist-test-slave-jztv"
I20260812 06:18:25.929302 22822 fs_manager.cc:696] Time spent creating directory manager: real 0.002s	user 0.000s	sys 0.003s
I20260812 06:18:25.930634 23292 log_block_manager.cc:4127] Time spent loading block containers with low live blocks: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:18:25.930917 22822 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.001s	sys 0.001s
I20260812 06:18:25.931016 22822 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskVApfHZ/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515500541946-22822-0/minicluster-data/ts-0-root
uuid: "10d98943476543d79e3d022c51e2019f"
format_stamp: "Formatted at 2026-08-12 06:18:25 on dist-test-slave-jztv"
I20260812 06:18:25.931103 22822 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskVApfHZ/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515500541946-22822-0/minicluster-data/ts-0-root
metadata directory: /tmp/dist-test-taskVApfHZ/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515500541946-22822-0/minicluster-data/ts-0-root
1 data directories: /tmp/dist-test-taskVApfHZ/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515500541946-22822-0/minicluster-data/ts-0-root/data
Total live blocks: 0
Total live bytes: 0
Total live bytes (after alignment): 0
Total number of LBM containers: 0 (0 full)
Did not check for missing blocks
Did not check for orphaned blocks
Total full LBM containers with extra space: 0 (0 repaired)
Total full LBM container extra space in bytes: 0 (0 repaired)
Total incomplete LBM containers: 0 (0 repaired)
Total LBM partial records: 0 (0 repaired)
Total corrupted LBM metadata records in RocksDB: 0 (0 repaired)
I20260812 06:18:25.951081 22822 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:18:25.951424 22822 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:18:25.951694 22822 txn_system_client.cc:432] TxnSystemClient initialization is disabled...
I20260812 06:18:25.952188 22822 ts_tablet_manager.cc:585] Loaded tablet metadata (0 total tablets, 0 live tablets)
I20260812 06:18:25.952226 22822 ts_tablet_manager.cc:531] Time spent load tablet metadata: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:18:25.952288 22822 ts_tablet_manager.cc:616] Registered 0 tablets
I20260812 06:18:25.952329 22822 ts_tablet_manager.cc:595] Time spent register tablets: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:18:25.956772 22822 rpc_server.cc:307] RPC server started. Bound to: 127.22.73.129:38947
I20260812 06:18:25.958941 23390 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.22.73.129:38947 every 8 connection(s)
I20260812 06:18:25.963629 23392 heartbeater.cc:344] Connected to a master server at 127.22.73.190:44755
I20260812 06:18:25.963750 23392 heartbeater.cc:461] Registering TS with master...
I20260812 06:18:25.963990 23392 heartbeater.cc:507] Master 127.22.73.190:44755 requested a full tablet report, sending...
I20260812 06:18:25.964619 23176 ts_manager.cc:194] Registered new tserver with Master: 10d98943476543d79e3d022c51e2019f (127.22.73.129:38947)
I20260812 06:18:25.965166 22822 internal_mini_cluster.cc:371] 1 TS(s) registered with all masters after 0.00771518s
I20260812 06:18:25.965431 23176 master_service.cc:502] Signed X509 certificate for tserver {username='slave'} at 127.0.0.1:33660
I20260812 06:18:25.972105 23176 catalog_manager.cc:2283] Servicing CreateTable request from {username='slave'} at 127.0.0.1:33666:
name: "heavy-update-compaction-test"
schema {
  columns {
    name: "key"
    type: INT64
    is_key: true
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_a"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_b"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_c"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_d"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_e"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
}
num_replicas: 1
split_rows_range_bounds {
}
partition_schema {
  range_schema {
  }
}
I20260812 06:18:25.981076 23329 tablet_service.cc:1511] Processing CreateTablet for tablet c8bc0cb2dc2047fdaa3e09bf341b9abd (DEFAULT_TABLE table=heavy-update-compaction-test [id=d3f494664ff74fde98ec14f8d696e995]), partition=
I20260812 06:18:25.981314 23329 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet c8bc0cb2dc2047fdaa3e09bf341b9abd. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:18:25.983359 23410 tablet_bootstrap.cc:492] T c8bc0cb2dc2047fdaa3e09bf341b9abd P 10d98943476543d79e3d022c51e2019f: Bootstrap starting.
I20260812 06:18:25.984356 23410 tablet_bootstrap.cc:654] T c8bc0cb2dc2047fdaa3e09bf341b9abd P 10d98943476543d79e3d022c51e2019f: Neither blocks nor log segments found. Creating new log.
I20260812 06:18:25.985461 23410 tablet_bootstrap.cc:492] T c8bc0cb2dc2047fdaa3e09bf341b9abd P 10d98943476543d79e3d022c51e2019f: No bootstrap required, opened a new log
I20260812 06:18:25.985574 23410 ts_tablet_manager.cc:1403] T c8bc0cb2dc2047fdaa3e09bf341b9abd P 10d98943476543d79e3d022c51e2019f: Time spent bootstrapping tablet: real 0.002s	user 0.002s	sys 0.000s
I20260812 06:18:25.986021 23410 raft_consensus.cc:359] T c8bc0cb2dc2047fdaa3e09bf341b9abd P 10d98943476543d79e3d022c51e2019f [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "10d98943476543d79e3d022c51e2019f" member_type: VOTER last_known_addr { host: "127.22.73.129" port: 38947 } }
I20260812 06:18:25.986112 23410 raft_consensus.cc:385] T c8bc0cb2dc2047fdaa3e09bf341b9abd P 10d98943476543d79e3d022c51e2019f [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:18:25.986176 23410 raft_consensus.cc:740] T c8bc0cb2dc2047fdaa3e09bf341b9abd P 10d98943476543d79e3d022c51e2019f [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: 10d98943476543d79e3d022c51e2019f, State: Initialized, Role: FOLLOWER
I20260812 06:18:25.986366 23410 consensus_queue.cc:260] T c8bc0cb2dc2047fdaa3e09bf341b9abd P 10d98943476543d79e3d022c51e2019f [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: "10d98943476543d79e3d022c51e2019f" member_type: VOTER last_known_addr { host: "127.22.73.129" port: 38947 } }
I20260812 06:18:25.986465 23410 raft_consensus.cc:399] T c8bc0cb2dc2047fdaa3e09bf341b9abd P 10d98943476543d79e3d022c51e2019f [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:18:25.986522 23410 raft_consensus.cc:493] T c8bc0cb2dc2047fdaa3e09bf341b9abd P 10d98943476543d79e3d022c51e2019f [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:18:25.986572 23410 raft_consensus.cc:3060] T c8bc0cb2dc2047fdaa3e09bf341b9abd P 10d98943476543d79e3d022c51e2019f [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:18:25.987432 23410 raft_consensus.cc:515] T c8bc0cb2dc2047fdaa3e09bf341b9abd P 10d98943476543d79e3d022c51e2019f [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "10d98943476543d79e3d022c51e2019f" member_type: VOTER last_known_addr { host: "127.22.73.129" port: 38947 } }
I20260812 06:18:25.987551 23410 leader_election.cc:304] T c8bc0cb2dc2047fdaa3e09bf341b9abd P 10d98943476543d79e3d022c51e2019f [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: 10d98943476543d79e3d022c51e2019f; no voters: 
I20260812 06:18:25.987709 23410 leader_election.cc:290] T c8bc0cb2dc2047fdaa3e09bf341b9abd P 10d98943476543d79e3d022c51e2019f [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:18:25.987834 23413 raft_consensus.cc:2804] T c8bc0cb2dc2047fdaa3e09bf341b9abd P 10d98943476543d79e3d022c51e2019f [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:18:25.988073 23413 raft_consensus.cc:697] T c8bc0cb2dc2047fdaa3e09bf341b9abd P 10d98943476543d79e3d022c51e2019f [term 1 LEADER]: Becoming Leader. State: Replica: 10d98943476543d79e3d022c51e2019f, State: Running, Role: LEADER
I20260812 06:18:25.988080 23410 ts_tablet_manager.cc:1434] T c8bc0cb2dc2047fdaa3e09bf341b9abd P 10d98943476543d79e3d022c51e2019f: Time spent starting tablet: real 0.002s	user 0.000s	sys 0.003s
I20260812 06:18:25.988116 23392 heartbeater.cc:499] Master 127.22.73.190:44755 was elected leader, sending a full tablet report...
I20260812 06:18:25.988231 23413 consensus_queue.cc:237] T c8bc0cb2dc2047fdaa3e09bf341b9abd P 10d98943476543d79e3d022c51e2019f [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: "10d98943476543d79e3d022c51e2019f" member_type: VOTER last_known_addr { host: "127.22.73.129" port: 38947 } }
I20260812 06:18:25.989589 23176 catalog_manager.cc:5719] T c8bc0cb2dc2047fdaa3e09bf341b9abd P 10d98943476543d79e3d022c51e2019f reported cstate change: term changed from 0 to 1, leader changed from <none> to 10d98943476543d79e3d022c51e2019f (127.22.73.129). New cstate: current_term: 1 leader_uuid: "10d98943476543d79e3d022c51e2019f" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "10d98943476543d79e3d022c51e2019f" member_type: VOTER last_known_addr { host: "127.22.73.129" port: 38947 } health_report { overall_health: HEALTHY } } }
I20260812 06:18:26.048784 22822 heavy-update-compaction-itest.cc:215] Time spent inserting: real 0.052s	user 0.018s	sys 0.004s
I20260812 06:18:26.209352 23393 maintenance_manager.cc:419] P 10d98943476543d79e3d022c51e2019f: Scheduling FlushMRSOp(c8bc0cb2dc2047fdaa3e09bf341b9abd): perf score=19.054940
I20260812 06:18:26.372432 23299 maintenance_manager.cc:643] P 10d98943476543d79e3d022c51e2019f: FlushMRSOp(c8bc0cb2dc2047fdaa3e09bf341b9abd) complete. Timing: real 0.163s	user 0.101s	sys 0.055s Metrics: {"bytes_written":12307489,"cfile_init":1,"delete_count":0,"dirs.queue_time_us":76,"dirs.run_cpu_time_us":219,"dirs.run_wall_time_us":956,"drs_written":1,"lbm_read_time_us":38,"lbm_reads_lt_1ms":4,"lbm_write_time_us":42144,"lbm_writes_lt_1ms":857,"peak_mem_usage":0,"reinsert_count":0,"rows_written":104,"update_count":1500}
I20260812 06:18:26.373183 23393 maintenance_manager.cc:419] P 10d98943476543d79e3d022c51e2019f: Scheduling LogGCOp(c8bc0cb2dc2047fdaa3e09bf341b9abd): free 20743880 bytes of WAL
I20260812 06:18:26.373401 23299 log_reader.cc:385] T c8bc0cb2dc2047fdaa3e09bf341b9abd: removed 2 log segments from log reader
I20260812 06:18:26.373440 23299 log.cc:1079] T c8bc0cb2dc2047fdaa3e09bf341b9abd P 10d98943476543d79e3d022c51e2019f: Deleting log segment in path: /tmp/dist-test-taskVApfHZ/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515500541946-22822-0/minicluster-data/ts-0-root/wals/c8bc0cb2dc2047fdaa3e09bf341b9abd/wal-000000001 (ops 1-6)
I20260812 06:18:26.373467 23299 log.cc:1079] T c8bc0cb2dc2047fdaa3e09bf341b9abd P 10d98943476543d79e3d022c51e2019f: Deleting log segment in path: /tmp/dist-test-taskVApfHZ/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515500541946-22822-0/minicluster-data/ts-0-root/wals/c8bc0cb2dc2047fdaa3e09bf341b9abd/wal-000000002 (ops 7-11)
I20260812 06:18:26.377648 23299 maintenance_manager.cc:643] P 10d98943476543d79e3d022c51e2019f: LogGCOp(c8bc0cb2dc2047fdaa3e09bf341b9abd) complete. Timing: real 0.004s	user 0.000s	sys 0.001s Metrics: {}
I20260812 06:18:26.378010 23393 maintenance_manager.cc:419] P 10d98943476543d79e3d022c51e2019f: Scheduling UndoDeltaBlockGCOp(c8bc0cb2dc2047fdaa3e09bf341b9abd): 20513807 bytes on disk
I20260812 06:18:26.378517 23299 maintenance_manager.cc:643] P 10d98943476543d79e3d022c51e2019f: UndoDeltaBlockGCOp(c8bc0cb2dc2047fdaa3e09bf341b9abd) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":60,"lbm_reads_lt_1ms":4}
I20260812 06:18:26.378912 23393 maintenance_manager.cc:419] P 10d98943476543d79e3d022c51e2019f: Scheduling FlushDeltaMemStoresOp(c8bc0cb2dc2047fdaa3e09bf341b9abd): perf score=2.188937
I20260812 06:18:26.392043 23299 maintenance_manager.cc:643] P 10d98943476543d79e3d022c51e2019f: FlushDeltaMemStoresOp(c8bc0cb2dc2047fdaa3e09bf341b9abd) complete. Timing: real 0.013s	user 0.005s	sys 0.006s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4977,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:26.392462 23393 maintenance_manager.cc:419] P 10d98943476543d79e3d022c51e2019f: Scheduling MajorDeltaCompactionOp(c8bc0cb2dc2047fdaa3e09bf341b9abd): perf score=1.000000
I20260812 06:18:26.545310 23299 maintenance_manager.cc:643] P 10d98943476543d79e3d022c51e2019f: MajorDeltaCompactionOp(c8bc0cb2dc2047fdaa3e09bf341b9abd) complete. Timing: real 0.153s	user 0.096s	sys 0.052s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672276,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":90,"lbm_read_time_us":10056,"lbm_reads_lt_1ms":464,"lbm_write_time_us":28573,"lbm_writes_lt_1ms":443,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":3200,"thread_start_us":249,"threads_started":5,"update_count":2000}
I20260812 06:18:26.545863 23393 maintenance_manager.cc:419] P 10d98943476543d79e3d022c51e2019f: Scheduling FlushDeltaMemStoresOp(c8bc0cb2dc2047fdaa3e09bf341b9abd): perf score=12.110812
I20260812 06:18:26.592367 23299 maintenance_manager.cc:643] P 10d98943476543d79e3d022c51e2019f: FlushDeltaMemStoresOp(c8bc0cb2dc2047fdaa3e09bf341b9abd) complete. Timing: real 0.046s	user 0.013s	sys 0.030s Metrics: {"bytes_written":13907424,"delete_count":0,"lbm_write_time_us":20210,"lbm_writes_lt_1ms":342,"reinsert_count":0,"update_count":1695}
I20260812 06:18:26.592839 23393 maintenance_manager.cc:419] P 10d98943476543d79e3d022c51e2019f: Scheduling FlushDeltaMemStoresOp(c8bc0cb2dc2047fdaa3e09bf341b9abd): perf score=1.196750
I20260812 06:18:26.615253 23299 maintenance_manager.cc:643] P 10d98943476543d79e3d022c51e2019f: FlushDeltaMemStoresOp(c8bc0cb2dc2047fdaa3e09bf341b9abd) complete. Timing: real 0.022s	user 0.010s	sys 0.000s Metrics: {"bytes_written":2912934,"delete_count":0,"lbm_write_time_us":4002,"lbm_writes_lt_1ms":74,"reinsert_count":0,"update_count":355}
I20260812 06:18:26.615669 23393 maintenance_manager.cc:419] P 10d98943476543d79e3d022c51e2019f: Scheduling FlushDeltaMemStoresOp(c8bc0cb2dc2047fdaa3e09bf341b9abd): perf score=2.188937
I20260812 06:18:26.624893 23299 maintenance_manager.cc:643] P 10d98943476543d79e3d022c51e2019f: FlushDeltaMemStoresOp(c8bc0cb2dc2047fdaa3e09bf341b9abd) complete. Timing: real 0.009s	user 0.005s	sys 0.002s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3490,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:18:26.625317 23393 maintenance_manager.cc:419] P 10d98943476543d79e3d022c51e2019f: Scheduling MajorDeltaCompactionOp(c8bc0cb2dc2047fdaa3e09bf341b9abd): perf score=1.000000
I20260812 06:18:26.796017 23299 maintenance_manager.cc:643] P 10d98943476543d79e3d022c51e2019f: MajorDeltaCompactionOp(c8bc0cb2dc2047fdaa3e09bf341b9abd) complete. Timing: real 0.171s	user 0.109s	sys 0.059s Metrics: {"cfile_cache_miss":533,"cfile_cache_miss_bytes":24774763,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":657,"lbm_read_time_us":12708,"lbm_reads_lt_1ms":573,"lbm_write_time_us":29244,"lbm_writes_lt_1ms":543,"mutex_wait_us":50,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":38016,"update_count":2500}
I20260812 06:18:26.796594 23393 maintenance_manager.cc:419] P 10d98943476543d79e3d022c51e2019f: Scheduling FlushDeltaMemStoresOp(c8bc0cb2dc2047fdaa3e09bf341b9abd): perf score=14.095187
I20260812 06:18:26.853883 23299 maintenance_manager.cc:643] P 10d98943476543d79e3d022c51e2019f: FlushDeltaMemStoresOp(c8bc0cb2dc2047fdaa3e09bf341b9abd) complete. Timing: real 0.057s	user 0.023s	sys 0.015s Metrics: {"bytes_written":16409899,"delete_count":0,"lbm_write_time_us":18752,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:18:26.854405 23393 maintenance_manager.cc:419] P 10d98943476543d79e3d022c51e2019f: Scheduling FlushDeltaMemStoresOp(c8bc0cb2dc2047fdaa3e09bf341b9abd): perf score=2.188937
I20260812 06:18:26.865315 23299 maintenance_manager.cc:643] P 10d98943476543d79e3d022c51e2019f: FlushDeltaMemStoresOp(c8bc0cb2dc2047fdaa3e09bf341b9abd) complete. Timing: real 0.011s	user 0.001s	sys 0.008s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4186,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:26.865797 23393 maintenance_manager.cc:419] P 10d98943476543d79e3d022c51e2019f: Scheduling MajorDeltaCompactionOp(c8bc0cb2dc2047fdaa3e09bf341b9abd): perf score=1.000000
I20260812 06:18:27.035063 23299 maintenance_manager.cc:643] P 10d98943476543d79e3d022c51e2019f: MajorDeltaCompactionOp(c8bc0cb2dc2047fdaa3e09bf341b9abd) complete. Timing: real 0.169s	user 0.129s	sys 0.040s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774685,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":488,"lbm_read_time_us":12466,"lbm_reads_lt_1ms":572,"lbm_write_time_us":26445,"lbm_writes_lt_1ms":543,"mutex_wait_us":24,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":10496,"update_count":2500}
I20260812 06:18:27.035665 23393 maintenance_manager.cc:419] P 10d98943476543d79e3d022c51e2019f: Scheduling FlushDeltaMemStoresOp(c8bc0cb2dc2047fdaa3e09bf341b9abd): perf score=14.095187
I20260812 06:18:27.099161 23299 maintenance_manager.cc:643] P 10d98943476543d79e3d022c51e2019f: FlushDeltaMemStoresOp(c8bc0cb2dc2047fdaa3e09bf341b9abd) complete. Timing: real 0.063s	user 0.031s	sys 0.031s Metrics: {"bytes_written":16409900,"delete_count":0,"lbm_write_time_us":25284,"lbm_writes_1-10_ms":2,"lbm_writes_lt_1ms":401,"reinsert_count":0,"update_count":2000}
I20260812 06:18:27.099718 23393 maintenance_manager.cc:419] P 10d98943476543d79e3d022c51e2019f: Scheduling FlushDeltaMemStoresOp(c8bc0cb2dc2047fdaa3e09bf341b9abd): perf score=2.188937
I20260812 06:18:27.111594 23299 maintenance_manager.cc:643] P 10d98943476543d79e3d022c51e2019f: FlushDeltaMemStoresOp(c8bc0cb2dc2047fdaa3e09bf341b9abd) complete. Timing: real 0.012s	user 0.009s	sys 0.001s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4282,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:27.112311 23393 maintenance_manager.cc:419] P 10d98943476543d79e3d022c51e2019f: Scheduling MajorDeltaCompactionOp(c8bc0cb2dc2047fdaa3e09bf341b9abd): perf score=1.000000
I20260812 06:18:27.309708 23299 maintenance_manager.cc:643] P 10d98943476543d79e3d022c51e2019f: MajorDeltaCompactionOp(c8bc0cb2dc2047fdaa3e09bf341b9abd) complete. Timing: real 0.197s	user 0.128s	sys 0.062s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774686,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":366,"lbm_read_time_us":13209,"lbm_reads_lt_1ms":572,"lbm_write_time_us":32114,"lbm_writes_lt_1ms":543,"mutex_wait_us":42,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":4736,"update_count":2500}
I20260812 06:18:27.310423 23393 maintenance_manager.cc:419] P 10d98943476543d79e3d022c51e2019f: Scheduling FlushDeltaMemStoresOp(c8bc0cb2dc2047fdaa3e09bf341b9abd): perf score=14.095187
I20260812 06:18:27.371301 23299 maintenance_manager.cc:643] P 10d98943476543d79e3d022c51e2019f: FlushDeltaMemStoresOp(c8bc0cb2dc2047fdaa3e09bf341b9abd) complete. Timing: real 0.061s	user 0.036s	sys 0.024s Metrics: {"bytes_written":16409903,"delete_count":0,"lbm_write_time_us":24028,"lbm_writes_1-10_ms":2,"lbm_writes_lt_1ms":401,"reinsert_count":0,"update_count":2000}
I20260812 06:18:27.371829 23393 maintenance_manager.cc:419] P 10d98943476543d79e3d022c51e2019f: Scheduling FlushDeltaMemStoresOp(c8bc0cb2dc2047fdaa3e09bf341b9abd): perf score=2.188937
I20260812 06:18:27.382578 23299 maintenance_manager.cc:643] P 10d98943476543d79e3d022c51e2019f: FlushDeltaMemStoresOp(c8bc0cb2dc2047fdaa3e09bf341b9abd) complete. Timing: real 0.011s	user 0.010s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4144,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:27.383175 23393 maintenance_manager.cc:419] P 10d98943476543d79e3d022c51e2019f: Scheduling MajorDeltaCompactionOp(c8bc0cb2dc2047fdaa3e09bf341b9abd): perf score=1.000000
I20260812 06:18:27.573776 23299 maintenance_manager.cc:643] P 10d98943476543d79e3d022c51e2019f: MajorDeltaCompactionOp(c8bc0cb2dc2047fdaa3e09bf341b9abd) complete. Timing: real 0.190s	user 0.126s	sys 0.064s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774690,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":1301,"lbm_read_time_us":12893,"lbm_reads_lt_1ms":572,"lbm_write_time_us":30891,"lbm_writes_lt_1ms":543,"mutex_wait_us":343,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":3712,"update_count":2500}
I20260812 06:18:27.574416 23393 maintenance_manager.cc:419] P 10d98943476543d79e3d022c51e2019f: Scheduling FlushDeltaMemStoresOp(c8bc0cb2dc2047fdaa3e09bf341b9abd): perf score=14.095187
I20260812 06:18:27.625202 23299 maintenance_manager.cc:643] P 10d98943476543d79e3d022c51e2019f: FlushDeltaMemStoresOp(c8bc0cb2dc2047fdaa3e09bf341b9abd) complete. Timing: real 0.051s	user 0.030s	sys 0.013s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":20046,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:18:27.625808 23393 maintenance_manager.cc:419] P 10d98943476543d79e3d022c51e2019f: Scheduling FlushDeltaMemStoresOp(c8bc0cb2dc2047fdaa3e09bf341b9abd): perf score=2.188937
I20260812 06:18:27.646534 23299 maintenance_manager.cc:643] P 10d98943476543d79e3d022c51e2019f: FlushDeltaMemStoresOp(c8bc0cb2dc2047fdaa3e09bf341b9abd) complete. Timing: real 0.021s	user 0.006s	sys 0.014s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4372,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:27.647219 23393 maintenance_manager.cc:419] P 10d98943476543d79e3d022c51e2019f: Scheduling FlushMRSOp(c8bc0cb2dc2047fdaa3e09bf341b9abd): perf score=1.000000
I20260812 06:18:27.681166 23299 maintenance_manager.cc:643] P 10d98943476543d79e3d022c51e2019f: FlushMRSOp(c8bc0cb2dc2047fdaa3e09bf341b9abd) complete. Timing: real 0.034s	user 0.028s	sys 0.004s Metrics: {"bytes_written":1234473,"cfile_init":1,"dirs.queue_time_us":76,"dirs.run_cpu_time_us":281,"dirs.run_wall_time_us":1388,"drs_written":1,"lbm_read_time_us":70,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1641,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":30}
I20260812 06:18:27.681838 23393 maintenance_manager.cc:419] P 10d98943476543d79e3d022c51e2019f: Scheduling LogGCOp(c8bc0cb2dc2047fdaa3e09bf341b9abd): free 121006433 bytes of WAL
I20260812 06:18:27.682068 23299 log_reader.cc:385] T c8bc0cb2dc2047fdaa3e09bf341b9abd: removed 12 log segments from log reader
I20260812 06:18:27.682113 23299 log.cc:1079] T c8bc0cb2dc2047fdaa3e09bf341b9abd P 10d98943476543d79e3d022c51e2019f: Deleting log segment in path: /tmp/dist-test-taskVApfHZ/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515500541946-22822-0/minicluster-data/ts-0-root/wals/c8bc0cb2dc2047fdaa3e09bf341b9abd/wal-000000003 (ops 12-16)
I20260812 06:18:27.682142 23299 log.cc:1079] T c8bc0cb2dc2047fdaa3e09bf341b9abd P 10d98943476543d79e3d022c51e2019f: Deleting log segment in path: /tmp/dist-test-taskVApfHZ/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515500541946-22822-0/minicluster-data/ts-0-root/wals/c8bc0cb2dc2047fdaa3e09bf341b9abd/wal-000000004 (ops 17-21)
I20260812 06:18:27.682235 23299 log.cc:1079] T c8bc0cb2dc2047fdaa3e09bf341b9abd P 10d98943476543d79e3d022c51e2019f: Deleting log segment in path: /tmp/dist-test-taskVApfHZ/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515500541946-22822-0/minicluster-data/ts-0-root/wals/c8bc0cb2dc2047fdaa3e09bf341b9abd/wal-000000005 (ops 22-26)
I20260812 06:18:27.682278 23299 log.cc:1079] T c8bc0cb2dc2047fdaa3e09bf341b9abd P 10d98943476543d79e3d022c51e2019f: Deleting log segment in path: /tmp/dist-test-taskVApfHZ/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515500541946-22822-0/minicluster-data/ts-0-root/wals/c8bc0cb2dc2047fdaa3e09bf341b9abd/wal-000000006 (ops 27-31)
I20260812 06:18:27.682309 23299 log.cc:1079] T c8bc0cb2dc2047fdaa3e09bf341b9abd P 10d98943476543d79e3d022c51e2019f: Deleting log segment in path: /tmp/dist-test-taskVApfHZ/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515500541946-22822-0/minicluster-data/ts-0-root/wals/c8bc0cb2dc2047fdaa3e09bf341b9abd/wal-000000007 (ops 32-36)
I20260812 06:18:27.682348 23299 log.cc:1079] T c8bc0cb2dc2047fdaa3e09bf341b9abd P 10d98943476543d79e3d022c51e2019f: Deleting log segment in path: /tmp/dist-test-taskVApfHZ/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515500541946-22822-0/minicluster-data/ts-0-root/wals/c8bc0cb2dc2047fdaa3e09bf341b9abd/wal-000000008 (ops 37-40)
I20260812 06:18:27.682384 23299 log.cc:1079] T c8bc0cb2dc2047fdaa3e09bf341b9abd P 10d98943476543d79e3d022c51e2019f: Deleting log segment in path: /tmp/dist-test-taskVApfHZ/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515500541946-22822-0/minicluster-data/ts-0-root/wals/c8bc0cb2dc2047fdaa3e09bf341b9abd/wal-000000009 (ops 41-45)
I20260812 06:18:27.682416 23299 log.cc:1079] T c8bc0cb2dc2047fdaa3e09bf341b9abd P 10d98943476543d79e3d022c51e2019f: Deleting log segment in path: /tmp/dist-test-taskVApfHZ/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515500541946-22822-0/minicluster-data/ts-0-root/wals/c8bc0cb2dc2047fdaa3e09bf341b9abd/wal-000000010 (ops 46-50)
I20260812 06:18:27.682453 23299 log.cc:1079] T c8bc0cb2dc2047fdaa3e09bf341b9abd P 10d98943476543d79e3d022c51e2019f: Deleting log segment in path: /tmp/dist-test-taskVApfHZ/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515500541946-22822-0/minicluster-data/ts-0-root/wals/c8bc0cb2dc2047fdaa3e09bf341b9abd/wal-000000011 (ops 51-55)
I20260812 06:18:27.682493 23299 log.cc:1079] T c8bc0cb2dc2047fdaa3e09bf341b9abd P 10d98943476543d79e3d022c51e2019f: Deleting log segment in path: /tmp/dist-test-taskVApfHZ/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515500541946-22822-0/minicluster-data/ts-0-root/wals/c8bc0cb2dc2047fdaa3e09bf341b9abd/wal-000000012 (ops 56-60)
I20260812 06:18:27.682533 23299 log.cc:1079] T c8bc0cb2dc2047fdaa3e09bf341b9abd P 10d98943476543d79e3d022c51e2019f: Deleting log segment in path: /tmp/dist-test-taskVApfHZ/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515500541946-22822-0/minicluster-data/ts-0-root/wals/c8bc0cb2dc2047fdaa3e09bf341b9abd/wal-000000013 (ops 61-65)
I20260812 06:18:27.682574 23299 log.cc:1079] T c8bc0cb2dc2047fdaa3e09bf341b9abd P 10d98943476543d79e3d022c51e2019f: Deleting log segment in path: /tmp/dist-test-taskVApfHZ/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515500541946-22822-0/minicluster-data/ts-0-root/wals/c8bc0cb2dc2047fdaa3e09bf341b9abd/wal-000000014 (ops 66-70)
I20260812 06:18:27.709564 23299 maintenance_manager.cc:643] P 10d98943476543d79e3d022c51e2019f: LogGCOp(c8bc0cb2dc2047fdaa3e09bf341b9abd) complete. Timing: real 0.028s	user 0.002s	sys 0.023s Metrics: {}
I20260812 06:18:27.709991 23393 maintenance_manager.cc:419] P 10d98943476543d79e3d022c51e2019f: Scheduling FlushDeltaMemStoresOp(c8bc0cb2dc2047fdaa3e09bf341b9abd): perf score=3.181125
I20260812 06:18:27.725015 23299 maintenance_manager.cc:643] P 10d98943476543d79e3d022c51e2019f: FlushDeltaMemStoresOp(c8bc0cb2dc2047fdaa3e09bf341b9abd) complete. Timing: real 0.015s	user 0.001s	sys 0.009s Metrics: {"bytes_written":4430855,"delete_count":0,"lbm_write_time_us":4352,"lbm_writes_lt_1ms":111,"reinsert_count":0,"update_count":540}
I20260812 06:18:27.725466 23393 maintenance_manager.cc:419] P 10d98943476543d79e3d022c51e2019f: Scheduling UndoDeltaBlockGCOp(c8bc0cb2dc2047fdaa3e09bf341b9abd): 472 bytes on disk
I20260812 06:18:27.725863 23299 maintenance_manager.cc:643] P 10d98943476543d79e3d022c51e2019f: UndoDeltaBlockGCOp(c8bc0cb2dc2047fdaa3e09bf341b9abd) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":53,"lbm_reads_lt_1ms":4}
I20260812 06:18:27.726588 23393 maintenance_manager.cc:419] P 10d98943476543d79e3d022c51e2019f: Scheduling FlushDeltaMemStoresOp(c8bc0cb2dc2047fdaa3e09bf341b9abd): perf score=2.188937
I20260812 06:18:27.736359 23299 maintenance_manager.cc:643] P 10d98943476543d79e3d022c51e2019f: FlushDeltaMemStoresOp(c8bc0cb2dc2047fdaa3e09bf341b9abd) complete. Timing: real 0.010s	user 0.004s	sys 0.004s Metrics: {"bytes_written":3774459,"delete_count":0,"lbm_write_time_us":3685,"lbm_writes_lt_1ms":95,"reinsert_count":0,"update_count":460}
I20260812 06:18:27.736922 23393 maintenance_manager.cc:419] P 10d98943476543d79e3d022c51e2019f: Scheduling MajorDeltaCompactionOp(c8bc0cb2dc2047fdaa3e09bf341b9abd): perf score=1.000000
I20260812 06:18:27.973166 23299 maintenance_manager.cc:643] P 10d98943476543d79e3d022c51e2019f: MajorDeltaCompactionOp(c8bc0cb2dc2047fdaa3e09bf341b9abd) complete. Timing: real 0.236s	user 0.159s	sys 0.076s Metrics: {"cfile_cache_miss":734,"cfile_cache_miss_bytes":32979747,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":552,"lbm_read_time_us":15574,"lbm_reads_lt_1ms":774,"lbm_write_time_us":38699,"lbm_writes_lt_1ms":743,"mutex_wait_us":3,"peak_mem_usage":87969044,"reinsert_count":0,"spinlock_wait_cycles":6784,"thread_start_us":89,"threads_started":1,"update_count":3500}
I20260812 06:18:27.973870 23393 maintenance_manager.cc:419] P 10d98943476543d79e3d022c51e2019f: Scheduling FlushDeltaMemStoresOp(c8bc0cb2dc2047fdaa3e09bf341b9abd): perf score=16.079562
I20260812 06:18:28.044081 23299 maintenance_manager.cc:643] P 10d98943476543d79e3d022c51e2019f: FlushDeltaMemStoresOp(c8bc0cb2dc2047fdaa3e09bf341b9abd) complete. Timing: real 0.070s	user 0.029s	sys 0.024s Metrics: {"bytes_written":17845753,"delete_count":0,"lbm_write_time_us":22712,"lbm_writes_lt_1ms":438,"reinsert_count":0,"update_count":2175}
I20260812 06:18:28.044549 23393 maintenance_manager.cc:419] P 10d98943476543d79e3d022c51e2019f: Scheduling FlushDeltaMemStoresOp(c8bc0cb2dc2047fdaa3e09bf341b9abd): perf score=5.165500
I20260812 06:18:28.064066 23299 maintenance_manager.cc:643] P 10d98943476543d79e3d022c51e2019f: FlushDeltaMemStoresOp(c8bc0cb2dc2047fdaa3e09bf341b9abd) complete. Timing: real 0.019s	user 0.017s	sys 0.000s Metrics: {"bytes_written":6769240,"delete_count":0,"lbm_write_time_us":7384,"lbm_writes_lt_1ms":168,"reinsert_count":0,"update_count":825}
I20260812 06:18:28.064627 23393 maintenance_manager.cc:419] P 10d98943476543d79e3d022c51e2019f: Scheduling MajorDeltaCompactionOp(c8bc0cb2dc2047fdaa3e09bf341b9abd): perf score=1.000000
I20260812 06:18:28.267056 23299 maintenance_manager.cc:643] P 10d98943476543d79e3d022c51e2019f: MajorDeltaCompactionOp(c8bc0cb2dc2047fdaa3e09bf341b9abd) complete. Timing: real 0.202s	user 0.100s	sys 0.099s Metrics: {"cfile_cache_miss":632,"cfile_cache_miss_bytes":28877115,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":686,"lbm_read_time_us":12893,"lbm_reads_lt_1ms":672,"lbm_write_time_us":33408,"lbm_writes_lt_1ms":643,"mutex_wait_us":154,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":16512,"update_count":3000}
I20260812 06:18:28.267680 23393 maintenance_manager.cc:419] P 10d98943476543d79e3d022c51e2019f: Scheduling FlushDeltaMemStoresOp(c8bc0cb2dc2047fdaa3e09bf341b9abd): perf score=18.063937
I20260812 06:18:28.340188 23299 maintenance_manager.cc:643] P 10d98943476543d79e3d022c51e2019f: FlushDeltaMemStoresOp(c8bc0cb2dc2047fdaa3e09bf341b9abd) complete. Timing: real 0.072s	user 0.039s	sys 0.020s Metrics: {"bytes_written":20512317,"delete_count":0,"lbm_write_time_us":28171,"lbm_writes_lt_1ms":503,"reinsert_count":0,"update_count":2500}
I20260812 06:18:28.340663 23393 maintenance_manager.cc:419] P 10d98943476543d79e3d022c51e2019f: Scheduling FlushDeltaMemStoresOp(c8bc0cb2dc2047fdaa3e09bf341b9abd): perf score=2.188937
I20260812 06:18:28.352016 23299 maintenance_manager.cc:643] P 10d98943476543d79e3d022c51e2019f: FlushDeltaMemStoresOp(c8bc0cb2dc2047fdaa3e09bf341b9abd) complete. Timing: real 0.011s	user 0.005s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4094,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:28.352746 23393 maintenance_manager.cc:419] P 10d98943476543d79e3d022c51e2019f: Scheduling MajorDeltaCompactionOp(c8bc0cb2dc2047fdaa3e09bf341b9abd): perf score=1.000000
I20260812 06:18:28.553356 23299 maintenance_manager.cc:643] P 10d98943476543d79e3d022c51e2019f: MajorDeltaCompactionOp(c8bc0cb2dc2047fdaa3e09bf341b9abd) complete. Timing: real 0.200s	user 0.128s	sys 0.072s Metrics: {"cfile_cache_miss":632,"cfile_cache_miss_bytes":28877104,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":734,"lbm_read_time_us":15580,"lbm_reads_lt_1ms":672,"lbm_write_time_us":33876,"lbm_writes_lt_1ms":643,"mutex_wait_us":43,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":3072,"update_count":3000}
I20260812 06:18:28.554105 23393 maintenance_manager.cc:419] P 10d98943476543d79e3d022c51e2019f: Scheduling FlushDeltaMemStoresOp(c8bc0cb2dc2047fdaa3e09bf341b9abd): perf score=14.095187
I20260812 06:18:28.605643 23299 maintenance_manager.cc:643] P 10d98943476543d79e3d022c51e2019f: FlushDeltaMemStoresOp(c8bc0cb2dc2047fdaa3e09bf341b9abd) complete. Timing: real 0.051s	user 0.027s	sys 0.021s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":21999,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:18:28.606127 23393 maintenance_manager.cc:419] P 10d98943476543d79e3d022c51e2019f: Scheduling FlushDeltaMemStoresOp(c8bc0cb2dc2047fdaa3e09bf341b9abd): perf score=2.188937
I20260812 06:18:28.624194 23299 maintenance_manager.cc:643] P 10d98943476543d79e3d022c51e2019f: FlushDeltaMemStoresOp(c8bc0cb2dc2047fdaa3e09bf341b9abd) complete. Timing: real 0.018s	user 0.005s	sys 0.009s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6137,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:28.624747 23393 maintenance_manager.cc:419] P 10d98943476543d79e3d022c51e2019f: Scheduling MajorDeltaCompactionOp(c8bc0cb2dc2047fdaa3e09bf341b9abd): perf score=1.000000
I20260812 06:18:28.801407 23299 maintenance_manager.cc:643] P 10d98943476543d79e3d022c51e2019f: MajorDeltaCompactionOp(c8bc0cb2dc2047fdaa3e09bf341b9abd) complete. Timing: real 0.176s	user 0.118s	sys 0.059s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774688,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":89,"lbm_read_time_us":12843,"lbm_reads_lt_1ms":564,"lbm_write_time_us":29059,"lbm_writes_lt_1ms":543,"mutex_wait_us":34,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":2688,"update_count":2500}
I20260812 06:18:28.802140 23393 maintenance_manager.cc:419] P 10d98943476543d79e3d022c51e2019f: Scheduling FlushDeltaMemStoresOp(c8bc0cb2dc2047fdaa3e09bf341b9abd): perf score=14.095187
I20260812 06:18:28.859817 23299 maintenance_manager.cc:643] P 10d98943476543d79e3d022c51e2019f: FlushDeltaMemStoresOp(c8bc0cb2dc2047fdaa3e09bf341b9abd) complete. Timing: real 0.057s	user 0.024s	sys 0.032s Metrics: {"bytes_written":16409900,"delete_count":0,"lbm_write_time_us":19940,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:18:28.860565 23393 maintenance_manager.cc:419] P 10d98943476543d79e3d022c51e2019f: Scheduling FlushDeltaMemStoresOp(c8bc0cb2dc2047fdaa3e09bf341b9abd): perf score=2.188937
I20260812 06:18:28.879163 23299 maintenance_manager.cc:643] P 10d98943476543d79e3d022c51e2019f: FlushDeltaMemStoresOp(c8bc0cb2dc2047fdaa3e09bf341b9abd) complete. Timing: real 0.018s	user 0.016s	sys 0.001s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":7172,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:28.879627 23393 maintenance_manager.cc:419] P 10d98943476543d79e3d022c51e2019f: Scheduling MajorDeltaCompactionOp(c8bc0cb2dc2047fdaa3e09bf341b9abd): perf score=1.000000
I20260812 06:18:29.054293 23299 maintenance_manager.cc:643] P 10d98943476543d79e3d022c51e2019f: MajorDeltaCompactionOp(c8bc0cb2dc2047fdaa3e09bf341b9abd) complete. Timing: real 0.174s	user 0.120s	sys 0.052s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774687,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":554,"lbm_read_time_us":12958,"lbm_reads_lt_1ms":572,"lbm_write_time_us":28724,"lbm_writes_lt_1ms":543,"mutex_wait_us":249,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":10368,"update_count":2500}
I20260812 06:18:29.054993 23393 maintenance_manager.cc:419] P 10d98943476543d79e3d022c51e2019f: Scheduling FlushDeltaMemStoresOp(c8bc0cb2dc2047fdaa3e09bf341b9abd): perf score=11.118625
I20260812 06:18:29.087193 23299 maintenance_manager.cc:643] P 10d98943476543d79e3d022c51e2019f: FlushDeltaMemStoresOp(c8bc0cb2dc2047fdaa3e09bf341b9abd) complete. Timing: real 0.032s	user 0.023s	sys 0.008s Metrics: {"bytes_written":12717735,"delete_count":0,"lbm_write_time_us":13198,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:18:29.087689 23393 maintenance_manager.cc:419] P 10d98943476543d79e3d022c51e2019f: Scheduling FlushDeltaMemStoresOp(c8bc0cb2dc2047fdaa3e09bf341b9abd): perf score=2.188937
I20260812 06:18:29.102412 23299 maintenance_manager.cc:643] P 10d98943476543d79e3d022c51e2019f: FlushDeltaMemStoresOp(c8bc0cb2dc2047fdaa3e09bf341b9abd) complete. Timing: real 0.015s	user 0.010s	sys 0.004s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":5809,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:18:29.102860 23393 maintenance_manager.cc:419] P 10d98943476543d79e3d022c51e2019f: Scheduling FlushMRSOp(c8bc0cb2dc2047fdaa3e09bf341b9abd): perf score=1.000000
I20260812 06:18:29.128175 23299 maintenance_manager.cc:643] P 10d98943476543d79e3d022c51e2019f: FlushMRSOp(c8bc0cb2dc2047fdaa3e09bf341b9abd) complete. Timing: real 0.025s	user 0.024s	sys 0.000s Metrics: {"bytes_written":1152514,"cfile_init":1,"dirs.queue_time_us":67,"dirs.run_cpu_time_us":230,"dirs.run_wall_time_us":1502,"drs_written":1,"lbm_read_time_us":38,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1637,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":28}
I20260812 06:18:29.128793 23393 maintenance_manager.cc:419] P 10d98943476543d79e3d022c51e2019f: Scheduling LogGCOp(c8bc0cb2dc2047fdaa3e09bf341b9abd): free 115490138 bytes of WAL
I20260812 06:18:29.129014 23299 log_reader.cc:385] T c8bc0cb2dc2047fdaa3e09bf341b9abd: removed 11 log segments from log reader
I20260812 06:18:29.129076 23299 log.cc:1079] T c8bc0cb2dc2047fdaa3e09bf341b9abd P 10d98943476543d79e3d022c51e2019f: Deleting log segment in path: /tmp/dist-test-taskVApfHZ/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515500541946-22822-0/minicluster-data/ts-0-root/wals/c8bc0cb2dc2047fdaa3e09bf341b9abd/wal-000000015 (ops 71-74)
I20260812 06:18:29.129127 23299 log.cc:1079] T c8bc0cb2dc2047fdaa3e09bf341b9abd P 10d98943476543d79e3d022c51e2019f: Deleting log segment in path: /tmp/dist-test-taskVApfHZ/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515500541946-22822-0/minicluster-data/ts-0-root/wals/c8bc0cb2dc2047fdaa3e09bf341b9abd/wal-000000016 (ops 75-79)
I20260812 06:18:29.129185 23299 log.cc:1079] T c8bc0cb2dc2047fdaa3e09bf341b9abd P 10d98943476543d79e3d022c51e2019f: Deleting log segment in path: /tmp/dist-test-taskVApfHZ/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515500541946-22822-0/minicluster-data/ts-0-root/wals/c8bc0cb2dc2047fdaa3e09bf341b9abd/wal-000000017 (ops 80-84)
I20260812 06:18:29.129225 23299 log.cc:1079] T c8bc0cb2dc2047fdaa3e09bf341b9abd P 10d98943476543d79e3d022c51e2019f: Deleting log segment in path: /tmp/dist-test-taskVApfHZ/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515500541946-22822-0/minicluster-data/ts-0-root/wals/c8bc0cb2dc2047fdaa3e09bf341b9abd/wal-000000018 (ops 85-89)
I20260812 06:18:29.129259 23299 log.cc:1079] T c8bc0cb2dc2047fdaa3e09bf341b9abd P 10d98943476543d79e3d022c51e2019f: Deleting log segment in path: /tmp/dist-test-taskVApfHZ/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515500541946-22822-0/minicluster-data/ts-0-root/wals/c8bc0cb2dc2047fdaa3e09bf341b9abd/wal-000000019 (ops 90-94)
I20260812 06:18:29.129297 23299 log.cc:1079] T c8bc0cb2dc2047fdaa3e09bf341b9abd P 10d98943476543d79e3d022c51e2019f: Deleting log segment in path: /tmp/dist-test-taskVApfHZ/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515500541946-22822-0/minicluster-data/ts-0-root/wals/c8bc0cb2dc2047fdaa3e09bf341b9abd/wal-000000020 (ops 95-99)
I20260812 06:18:29.129333 23299 log.cc:1079] T c8bc0cb2dc2047fdaa3e09bf341b9abd P 10d98943476543d79e3d022c51e2019f: Deleting log segment in path: /tmp/dist-test-taskVApfHZ/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515500541946-22822-0/minicluster-data/ts-0-root/wals/c8bc0cb2dc2047fdaa3e09bf341b9abd/wal-000000021 (ops 100-104)
I20260812 06:18:29.129369 23299 log.cc:1079] T c8bc0cb2dc2047fdaa3e09bf341b9abd P 10d98943476543d79e3d022c51e2019f: Deleting log segment in path: /tmp/dist-test-taskVApfHZ/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515500541946-22822-0/minicluster-data/ts-0-root/wals/c8bc0cb2dc2047fdaa3e09bf341b9abd/wal-000000022 (ops 105-109)
I20260812 06:18:29.129393 23299 log.cc:1079] T c8bc0cb2dc2047fdaa3e09bf341b9abd P 10d98943476543d79e3d022c51e2019f: Deleting log segment in path: /tmp/dist-test-taskVApfHZ/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515500541946-22822-0/minicluster-data/ts-0-root/wals/c8bc0cb2dc2047fdaa3e09bf341b9abd/wal-000000023 (ops 110-114)
I20260812 06:18:29.129423 23299 log.cc:1079] T c8bc0cb2dc2047fdaa3e09bf341b9abd P 10d98943476543d79e3d022c51e2019f: Deleting log segment in path: /tmp/dist-test-taskVApfHZ/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515500541946-22822-0/minicluster-data/ts-0-root/wals/c8bc0cb2dc2047fdaa3e09bf341b9abd/wal-000000024 (ops 115-119)
I20260812 06:18:29.129460 23299 log.cc:1079] T c8bc0cb2dc2047fdaa3e09bf341b9abd P 10d98943476543d79e3d022c51e2019f: Deleting log segment in path: /tmp/dist-test-taskVApfHZ/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515500541946-22822-0/minicluster-data/ts-0-root/wals/c8bc0cb2dc2047fdaa3e09bf341b9abd/wal-000000025 (ops 120-124)
I20260812 06:18:29.154848 23299 maintenance_manager.cc:643] P 10d98943476543d79e3d022c51e2019f: LogGCOp(c8bc0cb2dc2047fdaa3e09bf341b9abd) complete. Timing: real 0.026s	user 0.000s	sys 0.025s Metrics: {}
I20260812 06:18:29.155279 23393 maintenance_manager.cc:419] P 10d98943476543d79e3d022c51e2019f: Scheduling UndoDeltaBlockGCOp(c8bc0cb2dc2047fdaa3e09bf341b9abd): 447 bytes on disk
I20260812 06:18:29.155789 23299 maintenance_manager.cc:643] P 10d98943476543d79e3d022c51e2019f: UndoDeltaBlockGCOp(c8bc0cb2dc2047fdaa3e09bf341b9abd) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":67,"lbm_reads_lt_1ms":4}
I20260812 06:18:29.156399 23393 maintenance_manager.cc:419] P 10d98943476543d79e3d022c51e2019f: Scheduling FlushDeltaMemStoresOp(c8bc0cb2dc2047fdaa3e09bf341b9abd): perf score=3.181125
I20260812 06:18:29.175565 23299 maintenance_manager.cc:643] P 10d98943476543d79e3d022c51e2019f: FlushDeltaMemStoresOp(c8bc0cb2dc2047fdaa3e09bf341b9abd) complete. Timing: real 0.019s	user 0.012s	sys 0.005s Metrics: {"bytes_written":4512903,"delete_count":0,"lbm_write_time_us":7237,"lbm_writes_lt_1ms":113,"reinsert_count":0,"update_count":550}
I20260812 06:18:29.175994 23393 maintenance_manager.cc:419] P 10d98943476543d79e3d022c51e2019f: Scheduling FlushDeltaMemStoresOp(c8bc0cb2dc2047fdaa3e09bf341b9abd): perf score=2.188937
I20260812 06:18:29.185431 23299 maintenance_manager.cc:643] P 10d98943476543d79e3d022c51e2019f: FlushDeltaMemStoresOp(c8bc0cb2dc2047fdaa3e09bf341b9abd) complete. Timing: real 0.009s	user 0.008s	sys 0.000s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3513,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:18:29.185854 23393 maintenance_manager.cc:419] P 10d98943476543d79e3d022c51e2019f: Scheduling MajorDeltaCompactionOp(c8bc0cb2dc2047fdaa3e09bf341b9abd): perf score=1.000000
I20260812 06:18:29.394606 23299 maintenance_manager.cc:643] P 10d98943476543d79e3d022c51e2019f: MajorDeltaCompactionOp(c8bc0cb2dc2047fdaa3e09bf341b9abd) complete. Timing: real 0.209s	user 0.140s	sys 0.068s Metrics: {"cfile_cache_miss":634,"cfile_cache_miss_bytes":28877320,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":236,"lbm_read_time_us":15183,"lbm_reads_lt_1ms":674,"lbm_write_time_us":33442,"lbm_writes_lt_1ms":643,"mutex_wait_us":99,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":12288,"thread_start_us":93,"threads_started":1,"update_count":3000}
I20260812 06:18:29.395439 23393 maintenance_manager.cc:419] P 10d98943476543d79e3d022c51e2019f: Scheduling FlushDeltaMemStoresOp(c8bc0cb2dc2047fdaa3e09bf341b9abd): perf score=14.095187
I20260812 06:18:29.445497 23299 maintenance_manager.cc:643] P 10d98943476543d79e3d022c51e2019f: FlushDeltaMemStoresOp(c8bc0cb2dc2047fdaa3e09bf341b9abd) complete. Timing: real 0.050s	user 0.025s	sys 0.016s Metrics: {"bytes_written":16409907,"delete_count":0,"lbm_write_time_us":19854,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:18:29.446004 23393 maintenance_manager.cc:419] P 10d98943476543d79e3d022c51e2019f: Scheduling FlushDeltaMemStoresOp(c8bc0cb2dc2047fdaa3e09bf341b9abd): perf score=2.188937
I20260812 06:18:29.457089 23299 maintenance_manager.cc:643] P 10d98943476543d79e3d022c51e2019f: FlushDeltaMemStoresOp(c8bc0cb2dc2047fdaa3e09bf341b9abd) complete. Timing: real 0.011s	user 0.002s	sys 0.007s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4264,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:29.457810 23393 maintenance_manager.cc:419] P 10d98943476543d79e3d022c51e2019f: Scheduling MajorDeltaCompactionOp(c8bc0cb2dc2047fdaa3e09bf341b9abd): perf score=1.000000
I20260812 06:18:29.620131 23299 maintenance_manager.cc:643] P 10d98943476543d79e3d022c51e2019f: MajorDeltaCompactionOp(c8bc0cb2dc2047fdaa3e09bf341b9abd) complete. Timing: real 0.162s	user 0.118s	sys 0.044s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774694,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":218,"lbm_read_time_us":10983,"lbm_reads_lt_1ms":572,"lbm_write_time_us":26050,"lbm_writes_lt_1ms":543,"mutex_wait_us":24,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":6528,"update_count":2500}
I20260812 06:18:29.620834 23393 maintenance_manager.cc:419] P 10d98943476543d79e3d022c51e2019f: Scheduling FlushDeltaMemStoresOp(c8bc0cb2dc2047fdaa3e09bf341b9abd): perf score=14.095187
I20260812 06:18:29.668414 23299 maintenance_manager.cc:643] P 10d98943476543d79e3d022c51e2019f: FlushDeltaMemStoresOp(c8bc0cb2dc2047fdaa3e09bf341b9abd) complete. Timing: real 0.047s	user 0.034s	sys 0.011s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":20639,"lbm_writes_lt_1ms":403,"reinsert_count":0,"spinlock_wait_cycles":52992,"update_count":2000}
I20260812 06:18:29.668957 23393 maintenance_manager.cc:419] P 10d98943476543d79e3d022c51e2019f: Scheduling FlushDeltaMemStoresOp(c8bc0cb2dc2047fdaa3e09bf341b9abd): perf score=2.188937
I20260812 06:18:29.683684 23299 maintenance_manager.cc:643] P 10d98943476543d79e3d022c51e2019f: FlushDeltaMemStoresOp(c8bc0cb2dc2047fdaa3e09bf341b9abd) complete. Timing: real 0.015s	user 0.013s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5628,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:29.684273 23393 maintenance_manager.cc:419] P 10d98943476543d79e3d022c51e2019f: Scheduling MajorDeltaCompactionOp(c8bc0cb2dc2047fdaa3e09bf341b9abd): perf score=1.000000
I20260812 06:18:29.864760 23299 maintenance_manager.cc:643] P 10d98943476543d79e3d022c51e2019f: MajorDeltaCompactionOp(c8bc0cb2dc2047fdaa3e09bf341b9abd) complete. Timing: real 0.180s	user 0.148s	sys 0.029s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774689,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":669,"lbm_read_time_us":13271,"lbm_reads_lt_1ms":564,"lbm_write_time_us":30641,"lbm_writes_lt_1ms":543,"mutex_wait_us":47,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":7808,"update_count":2500}
I20260812 06:18:29.865465 23393 maintenance_manager.cc:419] P 10d98943476543d79e3d022c51e2019f: Scheduling FlushDeltaMemStoresOp(c8bc0cb2dc2047fdaa3e09bf341b9abd): perf score=14.095187
I20260812 06:18:29.932539 23299 maintenance_manager.cc:643] P 10d98943476543d79e3d022c51e2019f: FlushDeltaMemStoresOp(c8bc0cb2dc2047fdaa3e09bf341b9abd) complete. Timing: real 0.067s	user 0.033s	sys 0.032s Metrics: {"bytes_written":16409904,"delete_count":0,"lbm_write_time_us":23227,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:18:29.933169 23393 maintenance_manager.cc:419] P 10d98943476543d79e3d022c51e2019f: Scheduling FlushDeltaMemStoresOp(c8bc0cb2dc2047fdaa3e09bf341b9abd): perf score=2.188937
I20260812 06:18:29.949816 23299 maintenance_manager.cc:643] P 10d98943476543d79e3d022c51e2019f: FlushDeltaMemStoresOp(c8bc0cb2dc2047fdaa3e09bf341b9abd) complete. Timing: real 0.016s	user 0.011s	sys 0.003s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6242,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:29.950459 23393 maintenance_manager.cc:419] P 10d98943476543d79e3d022c51e2019f: Scheduling MajorDeltaCompactionOp(c8bc0cb2dc2047fdaa3e09bf341b9abd): perf score=1.000000
I20260812 06:18:30.137457 23299 maintenance_manager.cc:643] P 10d98943476543d79e3d022c51e2019f: MajorDeltaCompactionOp(c8bc0cb2dc2047fdaa3e09bf341b9abd) complete. Timing: real 0.187s	user 0.126s	sys 0.049s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774691,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":143,"lbm_read_time_us":13350,"lbm_reads_lt_1ms":572,"lbm_write_time_us":31497,"lbm_writes_lt_1ms":543,"mutex_wait_us":21,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":77312,"update_count":2500}
I20260812 06:18:30.138284 23393 maintenance_manager.cc:419] P 10d98943476543d79e3d022c51e2019f: Scheduling FlushDeltaMemStoresOp(c8bc0cb2dc2047fdaa3e09bf341b9abd): perf score=14.095187
I20260812 06:18:30.189687 23299 maintenance_manager.cc:643] P 10d98943476543d79e3d022c51e2019f: FlushDeltaMemStoresOp(c8bc0cb2dc2047fdaa3e09bf341b9abd) complete. Timing: real 0.051s	user 0.032s	sys 0.010s Metrics: {"bytes_written":16409903,"delete_count":0,"lbm_write_time_us":19954,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:18:30.190277 23393 maintenance_manager.cc:419] P 10d98943476543d79e3d022c51e2019f: Scheduling FlushDeltaMemStoresOp(c8bc0cb2dc2047fdaa3e09bf341b9abd): perf score=2.188937
I20260812 06:18:30.211582 23299 maintenance_manager.cc:643] P 10d98943476543d79e3d022c51e2019f: FlushDeltaMemStoresOp(c8bc0cb2dc2047fdaa3e09bf341b9abd) complete. Timing: real 0.021s	user 0.005s	sys 0.015s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4446,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:30.212255 23393 maintenance_manager.cc:419] P 10d98943476543d79e3d022c51e2019f: Scheduling MajorDeltaCompactionOp(c8bc0cb2dc2047fdaa3e09bf341b9abd): perf score=1.000000
I20260812 06:18:30.390364 23299 maintenance_manager.cc:643] P 10d98943476543d79e3d022c51e2019f: MajorDeltaCompactionOp(c8bc0cb2dc2047fdaa3e09bf341b9abd) complete. Timing: real 0.178s	user 0.115s	sys 0.062s 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":470,"lbm_read_time_us":12523,"lbm_reads_lt_1ms":572,"lbm_write_time_us":27642,"lbm_writes_lt_1ms":543,"mutex_wait_us":29,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":4224,"update_count":2500}
I20260812 06:18:30.390981 23393 maintenance_manager.cc:419] P 10d98943476543d79e3d022c51e2019f: Scheduling FlushDeltaMemStoresOp(c8bc0cb2dc2047fdaa3e09bf341b9abd): perf score=14.095187
I20260812 06:18:30.445166 23299 maintenance_manager.cc:643] P 10d98943476543d79e3d022c51e2019f: FlushDeltaMemStoresOp(c8bc0cb2dc2047fdaa3e09bf341b9abd) complete. Timing: real 0.054s	user 0.030s	sys 0.017s Metrics: {"bytes_written":16409903,"delete_count":0,"lbm_write_time_us":22385,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:18:30.445703 23393 maintenance_manager.cc:419] P 10d98943476543d79e3d022c51e2019f: Scheduling FlushDeltaMemStoresOp(c8bc0cb2dc2047fdaa3e09bf341b9abd): perf score=2.188937
I20260812 06:18:30.457281 23299 maintenance_manager.cc:643] P 10d98943476543d79e3d022c51e2019f: FlushDeltaMemStoresOp(c8bc0cb2dc2047fdaa3e09bf341b9abd) complete. Timing: real 0.011s	user 0.006s	sys 0.003s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4077,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:30.457787 23393 maintenance_manager.cc:419] P 10d98943476543d79e3d022c51e2019f: Scheduling MajorDeltaCompactionOp(c8bc0cb2dc2047fdaa3e09bf341b9abd): perf score=1.000000
I20260812 06:18:30.632983 23299 maintenance_manager.cc:643] P 10d98943476543d79e3d022c51e2019f: MajorDeltaCompactionOp(c8bc0cb2dc2047fdaa3e09bf341b9abd) complete. Timing: real 0.175s	user 0.135s	sys 0.028s 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":528,"lbm_read_time_us":10758,"lbm_reads_lt_1ms":572,"lbm_write_time_us":28097,"lbm_writes_lt_1ms":543,"mutex_wait_us":37,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":4864,"update_count":2500}
I20260812 06:18:30.633535 23393 maintenance_manager.cc:419] P 10d98943476543d79e3d022c51e2019f: Scheduling FlushDeltaMemStoresOp(c8bc0cb2dc2047fdaa3e09bf341b9abd): perf score=14.095187
I20260812 06:18:30.681514 23299 maintenance_manager.cc:643] P 10d98943476543d79e3d022c51e2019f: FlushDeltaMemStoresOp(c8bc0cb2dc2047fdaa3e09bf341b9abd) complete. Timing: real 0.048s	user 0.014s	sys 0.022s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":17958,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:18:30.682044 23393 maintenance_manager.cc:419] P 10d98943476543d79e3d022c51e2019f: Scheduling FlushDeltaMemStoresOp(c8bc0cb2dc2047fdaa3e09bf341b9abd): perf score=2.188937
I20260812 06:18:30.694088 23299 maintenance_manager.cc:643] P 10d98943476543d79e3d022c51e2019f: FlushDeltaMemStoresOp(c8bc0cb2dc2047fdaa3e09bf341b9abd) complete. Timing: real 0.012s	user 0.006s	sys 0.003s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4287,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:30.694685 23393 maintenance_manager.cc:419] P 10d98943476543d79e3d022c51e2019f: Scheduling FlushMRSOp(c8bc0cb2dc2047fdaa3e09bf341b9abd): perf score=1.000000
I20260812 06:18:30.727116 23299 maintenance_manager.cc:643] P 10d98943476543d79e3d022c51e2019f: FlushMRSOp(c8bc0cb2dc2047fdaa3e09bf341b9abd) complete. Timing: real 0.032s	user 0.031s	sys 0.001s Metrics: {"bytes_written":1316417,"cfile_init":1,"dirs.queue_time_us":34,"dirs.run_cpu_time_us":245,"dirs.run_wall_time_us":1502,"drs_written":1,"lbm_read_time_us":37,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1522,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":32}
I20260812 06:18:30.727768 23393 maintenance_manager.cc:419] P 10d98943476543d79e3d022c51e2019f: Scheduling LogGCOp(c8bc0cb2dc2047fdaa3e09bf341b9abd): free 129320758 bytes of WAL
I20260812 06:18:30.728003 23299 log_reader.cc:385] T c8bc0cb2dc2047fdaa3e09bf341b9abd: removed 13 log segments from log reader
I20260812 06:18:30.728047 23299 log.cc:1079] T c8bc0cb2dc2047fdaa3e09bf341b9abd P 10d98943476543d79e3d022c51e2019f: Deleting log segment in path: /tmp/dist-test-taskVApfHZ/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515500541946-22822-0/minicluster-data/ts-0-root/wals/c8bc0cb2dc2047fdaa3e09bf341b9abd/wal-000000026 (ops 125-129)
I20260812 06:18:30.728075 23299 log.cc:1079] T c8bc0cb2dc2047fdaa3e09bf341b9abd P 10d98943476543d79e3d022c51e2019f: Deleting log segment in path: /tmp/dist-test-taskVApfHZ/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515500541946-22822-0/minicluster-data/ts-0-root/wals/c8bc0cb2dc2047fdaa3e09bf341b9abd/wal-000000027 (ops 130-134)
I20260812 06:18:30.728092 23299 log.cc:1079] T c8bc0cb2dc2047fdaa3e09bf341b9abd P 10d98943476543d79e3d022c51e2019f: Deleting log segment in path: /tmp/dist-test-taskVApfHZ/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515500541946-22822-0/minicluster-data/ts-0-root/wals/c8bc0cb2dc2047fdaa3e09bf341b9abd/wal-000000028 (ops 135-139)
I20260812 06:18:30.728153 23299 log.cc:1079] T c8bc0cb2dc2047fdaa3e09bf341b9abd P 10d98943476543d79e3d022c51e2019f: Deleting log segment in path: /tmp/dist-test-taskVApfHZ/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515500541946-22822-0/minicluster-data/ts-0-root/wals/c8bc0cb2dc2047fdaa3e09bf341b9abd/wal-000000029 (ops 140-144)
I20260812 06:18:30.728215 23299 log.cc:1079] T c8bc0cb2dc2047fdaa3e09bf341b9abd P 10d98943476543d79e3d022c51e2019f: Deleting log segment in path: /tmp/dist-test-taskVApfHZ/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515500541946-22822-0/minicluster-data/ts-0-root/wals/c8bc0cb2dc2047fdaa3e09bf341b9abd/wal-000000030 (ops 145-148)
I20260812 06:18:30.728261 23299 log.cc:1079] T c8bc0cb2dc2047fdaa3e09bf341b9abd P 10d98943476543d79e3d022c51e2019f: Deleting log segment in path: /tmp/dist-test-taskVApfHZ/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515500541946-22822-0/minicluster-data/ts-0-root/wals/c8bc0cb2dc2047fdaa3e09bf341b9abd/wal-000000031 (ops 149-153)
I20260812 06:18:30.728299 23299 log.cc:1079] T c8bc0cb2dc2047fdaa3e09bf341b9abd P 10d98943476543d79e3d022c51e2019f: Deleting log segment in path: /tmp/dist-test-taskVApfHZ/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515500541946-22822-0/minicluster-data/ts-0-root/wals/c8bc0cb2dc2047fdaa3e09bf341b9abd/wal-000000032 (ops 154-158)
I20260812 06:18:30.728340 23299 log.cc:1079] T c8bc0cb2dc2047fdaa3e09bf341b9abd P 10d98943476543d79e3d022c51e2019f: Deleting log segment in path: /tmp/dist-test-taskVApfHZ/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515500541946-22822-0/minicluster-data/ts-0-root/wals/c8bc0cb2dc2047fdaa3e09bf341b9abd/wal-000000033 (ops 159-163)
I20260812 06:18:30.728382 23299 log.cc:1079] T c8bc0cb2dc2047fdaa3e09bf341b9abd P 10d98943476543d79e3d022c51e2019f: Deleting log segment in path: /tmp/dist-test-taskVApfHZ/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515500541946-22822-0/minicluster-data/ts-0-root/wals/c8bc0cb2dc2047fdaa3e09bf341b9abd/wal-000000034 (ops 164-168)
I20260812 06:18:30.728422 23299 log.cc:1079] T c8bc0cb2dc2047fdaa3e09bf341b9abd P 10d98943476543d79e3d022c51e2019f: Deleting log segment in path: /tmp/dist-test-taskVApfHZ/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515500541946-22822-0/minicluster-data/ts-0-root/wals/c8bc0cb2dc2047fdaa3e09bf341b9abd/wal-000000035 (ops 169-173)
I20260812 06:18:30.728461 23299 log.cc:1079] T c8bc0cb2dc2047fdaa3e09bf341b9abd P 10d98943476543d79e3d022c51e2019f: Deleting log segment in path: /tmp/dist-test-taskVApfHZ/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515500541946-22822-0/minicluster-data/ts-0-root/wals/c8bc0cb2dc2047fdaa3e09bf341b9abd/wal-000000036 (ops 174-178)
I20260812 06:18:30.728503 23299 log.cc:1079] T c8bc0cb2dc2047fdaa3e09bf341b9abd P 10d98943476543d79e3d022c51e2019f: Deleting log segment in path: /tmp/dist-test-taskVApfHZ/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515500541946-22822-0/minicluster-data/ts-0-root/wals/c8bc0cb2dc2047fdaa3e09bf341b9abd/wal-000000037 (ops 179-182)
I20260812 06:18:30.728542 23299 log.cc:1079] T c8bc0cb2dc2047fdaa3e09bf341b9abd P 10d98943476543d79e3d022c51e2019f: Deleting log segment in path: /tmp/dist-test-taskVApfHZ/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515500541946-22822-0/minicluster-data/ts-0-root/wals/c8bc0cb2dc2047fdaa3e09bf341b9abd/wal-000000038 (ops 183-187)
I20260812 06:18:30.756448 23299 maintenance_manager.cc:643] P 10d98943476543d79e3d022c51e2019f: LogGCOp(c8bc0cb2dc2047fdaa3e09bf341b9abd) complete. Timing: real 0.028s	user 0.000s	sys 0.026s Metrics: {}
I20260812 06:18:30.756974 23393 maintenance_manager.cc:419] P 10d98943476543d79e3d022c51e2019f: Scheduling UndoDeltaBlockGCOp(c8bc0cb2dc2047fdaa3e09bf341b9abd): 493 bytes on disk
I20260812 06:18:30.757521 23299 maintenance_manager.cc:643] P 10d98943476543d79e3d022c51e2019f: UndoDeltaBlockGCOp(c8bc0cb2dc2047fdaa3e09bf341b9abd) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":76,"lbm_reads_lt_1ms":4}
I20260812 06:18:30.758185 23393 maintenance_manager.cc:419] P 10d98943476543d79e3d022c51e2019f: Scheduling FlushDeltaMemStoresOp(c8bc0cb2dc2047fdaa3e09bf341b9abd): perf score=6.157687
I20260812 06:18:30.783224 23299 maintenance_manager.cc:643] P 10d98943476543d79e3d022c51e2019f: FlushDeltaMemStoresOp(c8bc0cb2dc2047fdaa3e09bf341b9abd) complete. Timing: real 0.025s	user 0.015s	sys 0.009s Metrics: {"bytes_written":8205079,"delete_count":0,"lbm_write_time_us":9868,"lbm_writes_lt_1ms":203,"reinsert_count":0,"update_count":1000}
I20260812 06:18:30.783880 23393 maintenance_manager.cc:419] P 10d98943476543d79e3d022c51e2019f: Scheduling LogGCOp(c8bc0cb2dc2047fdaa3e09bf341b9abd): free 12017952 bytes of WAL
I20260812 06:18:30.784188 23299 log_reader.cc:385] T c8bc0cb2dc2047fdaa3e09bf341b9abd: removed 1 log segments from log reader
I20260812 06:18:30.784263 23299 log.cc:1079] T c8bc0cb2dc2047fdaa3e09bf341b9abd P 10d98943476543d79e3d022c51e2019f: Deleting log segment in path: /tmp/dist-test-taskVApfHZ/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515500541946-22822-0/minicluster-data/ts-0-root/wals/c8bc0cb2dc2047fdaa3e09bf341b9abd/wal-000000039 (ops 188-192)
I20260812 06:18:30.787544 23299 maintenance_manager.cc:643] P 10d98943476543d79e3d022c51e2019f: LogGCOp(c8bc0cb2dc2047fdaa3e09bf341b9abd) complete. Timing: real 0.003s	user 0.000s	sys 0.002s Metrics: {}
I20260812 06:18:30.788339 23393 maintenance_manager.cc:419] P 10d98943476543d79e3d022c51e2019f: Scheduling MajorDeltaCompactionOp(c8bc0cb2dc2047fdaa3e09bf341b9abd): perf score=1.000000
I20260812 06:18:30.965214 22822 heavy-update-compaction-itest.cc:229] Time spent updating: real 4.916s	user 1.850s	sys 0.150s
I20260812 06:18:31.016975 23299 maintenance_manager.cc:643] P 10d98943476543d79e3d022c51e2019f: MajorDeltaCompactionOp(c8bc0cb2dc2047fdaa3e09bf341b9abd) complete. Timing: real 0.228s	user 0.155s	sys 0.071s Metrics: {"cfile_cache_miss":733,"cfile_cache_miss_bytes":32979633,"cfile_init":7,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"lbm_read_time_us":16079,"lbm_reads_lt_1ms":761,"lbm_write_time_us":39757,"lbm_writes_lt_1ms":743,"peak_mem_usage":87969044,"reinsert_count":0,"spinlock_wait_cycles":1792,"update_count":3500}
I20260812 06:18:31.017547 23393 maintenance_manager.cc:419] P 10d98943476543d79e3d022c51e2019f: Scheduling FlushDeltaMemStoresOp(c8bc0cb2dc2047fdaa3e09bf341b9abd): perf score=14.095187
I20260812 06:18:31.049116 22822 heavy-update-compaction-itest.cc:265] Time spent scanning: real 0.083s	user 0.001s	sys 0.000s
I20260812 06:18:31.049646 22822 tablet_server.cc:179] TabletServer@127.22.73.129:0 shutting down...
I20260812 06:18:31.066841 23299 maintenance_manager.cc:643] P 10d98943476543d79e3d022c51e2019f: FlushDeltaMemStoresOp(c8bc0cb2dc2047fdaa3e09bf341b9abd) complete. Timing: real 0.049s	user 0.030s	sys 0.019s Metrics: {"bytes_written":16409941,"delete_count":0,"lbm_write_time_us":18003,"lbm_writes_lt_1ms":403,"reinsert_count":0,"spinlock_wait_cycles":1408,"update_count":2000}
I20260812 06:18:31.067525 22822 ts_tablet_manager.cc:1507] Shutting down tablet manager...
I20260812 06:18:31.067755 22822 tablet_replica.cc:333] T c8bc0cb2dc2047fdaa3e09bf341b9abd P 10d98943476543d79e3d022c51e2019f: stopping tablet replica
I20260812 06:18:31.067898 22822 raft_consensus.cc:2243] T c8bc0cb2dc2047fdaa3e09bf341b9abd P 10d98943476543d79e3d022c51e2019f [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:18:31.068091 22822 raft_consensus.cc:2272] T c8bc0cb2dc2047fdaa3e09bf341b9abd P 10d98943476543d79e3d022c51e2019f [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:18:31.071683 22822 tablet_server.cc:196] TabletServer@127.22.73.129:0 shutdown complete.
I20260812 06:18:31.091717 22822 master.cc:562] Master@127.22.73.190:44755 shutting down...
I20260812 06:18:31.095299 22822 raft_consensus.cc:2243] T 00000000000000000000000000000000 P 26c615fb01ae4ae4b7659f8790afc3e0 [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:18:31.095525 22822 raft_consensus.cc:2272] T 00000000000000000000000000000000 P 26c615fb01ae4ae4b7659f8790afc3e0 [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:18:31.095614 22822 tablet_replica.cc:333] T 00000000000000000000000000000000 P 26c615fb01ae4ae4b7659f8790afc3e0: stopping tablet replica
I20260812 06:18:31.107859 22822 master.cc:584] Master@127.22.73.190:44755 shutdown complete.
[       OK ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/1 (5386 ms)
[----------] 2 tests from EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy (10642 ms total)

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