[==========] Running 2 tests from 1 test suite.
[----------] Global test environment set-up.
[----------] 2 tests from EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy
[ RUN      ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/0
WARNING: Logging before InitGoogleLogging() is written to STDERR
I20260812 06:19:05.509132 27980 internal_mini_cluster.cc:156] Creating distributed mini masters. Addrs: 127.27.83.62:45541
I20260812 06:19:05.510227 27980 env_posix.cc:2285] Not raising this process' open files per process limit of 1048576; it is already as high as it can go
I20260812 06:19:05.510936 27980 file_cache.cc:504] Constructed file cache file cache with capacity 419430
I20260812 06:19:05.519522 27980 server_base.cc:1061] running on GCE node
W20260812 06:19:05.519620 27988 instance_detector.cc:116] could not retrieve Azure instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:19:05.519821 27987 instance_detector.cc:116] could not retrieve AWS instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:19:05.519791 27990 instance_detector.cc:116] could not retrieve OpenStack instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:19:05.520488 27980 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:19:05.520587 27980 system_unsync_time.cc:38] NTP support is disabled. Clock error bounds will not be accurate. This configuration is not suitable for distributed clusters.
I20260812 06:19:05.520614 27980 hybrid_clock.cc:648] HybridClock initialized: now 1786515545520613 us; error 0 us; skew 500 ppm
I20260812 06:19:05.522652 27980 webserver.cc:533] Webserver started at http://127.27.83.62:42203/ using document root <none> and password file <none>
I20260812 06:19:05.523247 27980 fs_manager.cc:362] Metadata directory not provided
I20260812 06:19:05.523309 27980 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:19:05.523612 27980 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:19:05.525345 27980 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskt6ZbCi/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515545497762-27980-0/minicluster-data/master-0-root/instance:
uuid: "5d295e22520c413c87a3e5fca01ed39d"
format_stamp: "Formatted at 2026-08-12 06:19:05 on dist-test-slave-btw8"
I20260812 06:19:05.529716 27980 fs_manager.cc:696] Time spent creating directory manager: real 0.004s	user 0.005s	sys 0.000s
I20260812 06:19:05.532192 27996 log_block_manager.cc:4127] Time spent loading block containers with low live blocks: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:19:05.533429 27980 fs_manager.cc:730] Time spent opening block manager: real 0.002s	user 0.002s	sys 0.000s
I20260812 06:19:05.533548 27980 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskt6ZbCi/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515545497762-27980-0/minicluster-data/master-0-root
uuid: "5d295e22520c413c87a3e5fca01ed39d"
format_stamp: "Formatted at 2026-08-12 06:19:05 on dist-test-slave-btw8"
I20260812 06:19:05.533648 27980 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskt6ZbCi/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515545497762-27980-0/minicluster-data/master-0-root
metadata directory: /tmp/dist-test-taskt6ZbCi/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515545497762-27980-0/minicluster-data/master-0-root
1 data directories: /tmp/dist-test-taskt6ZbCi/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515545497762-27980-0/minicluster-data/master-0-root/data
Total live blocks: 0
Total live bytes: 0
Total live bytes (after alignment): 0
Total number of LBM containers: 0 (0 full)
Did not check for missing blocks
Did not check for orphaned blocks
Total full LBM containers with extra space: 0 (0 repaired)
Total full LBM container extra space in bytes: 0 (0 repaired)
Total incomplete LBM containers: 0 (0 repaired)
Total LBM partial records: 0 (0 repaired)
Total corrupted LBM metadata records in RocksDB: 0 (0 repaired)
I20260812 06:19:05.583992 27980 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:19:05.584663 27980 env_posix.cc:2285] Not raising this process' running threads per effective uid limit of 18446744073709551615; it is already as high as it can go
I20260812 06:19:05.584816 27980 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:19:05.593279 27980 rpc_server.cc:307] RPC server started. Bound to: 127.27.83.62:45541
I20260812 06:19:05.593369 28053 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.27.83.62:45541 every 8 connection(s)
I20260812 06:19:05.595911 28054 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet 00000000000000000000000000000000. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:19:05.602160 28054 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P 5d295e22520c413c87a3e5fca01ed39d: Bootstrap starting.
I20260812 06:19:05.605155 28054 tablet_bootstrap.cc:654] T 00000000000000000000000000000000 P 5d295e22520c413c87a3e5fca01ed39d: Neither blocks nor log segments found. Creating new log.
I20260812 06:19:05.606417 28054 log.cc:826] T 00000000000000000000000000000000 P 5d295e22520c413c87a3e5fca01ed39d: Log is configured to *not* fsync() on all Append() calls
I20260812 06:19:05.608887 28054 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P 5d295e22520c413c87a3e5fca01ed39d: No bootstrap required, opened a new log
I20260812 06:19:05.612519 28054 raft_consensus.cc:359] T 00000000000000000000000000000000 P 5d295e22520c413c87a3e5fca01ed39d [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "5d295e22520c413c87a3e5fca01ed39d" member_type: VOTER }
I20260812 06:19:05.612751 28054 raft_consensus.cc:385] T 00000000000000000000000000000000 P 5d295e22520c413c87a3e5fca01ed39d [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:19:05.612799 28054 raft_consensus.cc:740] T 00000000000000000000000000000000 P 5d295e22520c413c87a3e5fca01ed39d [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: 5d295e22520c413c87a3e5fca01ed39d, State: Initialized, Role: FOLLOWER
I20260812 06:19:05.613586 28054 consensus_queue.cc:260] T 00000000000000000000000000000000 P 5d295e22520c413c87a3e5fca01ed39d [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: "5d295e22520c413c87a3e5fca01ed39d" member_type: VOTER }
I20260812 06:19:05.613772 28054 raft_consensus.cc:399] T 00000000000000000000000000000000 P 5d295e22520c413c87a3e5fca01ed39d [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:19:05.613822 28054 raft_consensus.cc:493] T 00000000000000000000000000000000 P 5d295e22520c413c87a3e5fca01ed39d [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:19:05.614146 28054 raft_consensus.cc:3060] T 00000000000000000000000000000000 P 5d295e22520c413c87a3e5fca01ed39d [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:19:05.615404 28054 raft_consensus.cc:515] T 00000000000000000000000000000000 P 5d295e22520c413c87a3e5fca01ed39d [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "5d295e22520c413c87a3e5fca01ed39d" member_type: VOTER }
I20260812 06:19:05.616040 28054 leader_election.cc:304] T 00000000000000000000000000000000 P 5d295e22520c413c87a3e5fca01ed39d [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: 5d295e22520c413c87a3e5fca01ed39d; no voters: 
I20260812 06:19:05.616477 28054 leader_election.cc:290] T 00000000000000000000000000000000 P 5d295e22520c413c87a3e5fca01ed39d [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:19:05.616703 28059 raft_consensus.cc:2804] T 00000000000000000000000000000000 P 5d295e22520c413c87a3e5fca01ed39d [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:19:05.617005 28059 raft_consensus.cc:697] T 00000000000000000000000000000000 P 5d295e22520c413c87a3e5fca01ed39d [term 1 LEADER]: Becoming Leader. State: Replica: 5d295e22520c413c87a3e5fca01ed39d, State: Running, Role: LEADER
I20260812 06:19:05.617529 28059 consensus_queue.cc:237] T 00000000000000000000000000000000 P 5d295e22520c413c87a3e5fca01ed39d [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: "5d295e22520c413c87a3e5fca01ed39d" member_type: VOTER }
I20260812 06:19:05.617776 28054 sys_catalog.cc:565] T 00000000000000000000000000000000 P 5d295e22520c413c87a3e5fca01ed39d [sys.catalog]: configured and running, proceeding with master startup.
I20260812 06:19:05.619886 28060 sys_catalog.cc:455] T 00000000000000000000000000000000 P 5d295e22520c413c87a3e5fca01ed39d [sys.catalog]: SysCatalogTable state changed. Reason: RaftConsensus started. Latest consensus state: current_term: 1 leader_uuid: "5d295e22520c413c87a3e5fca01ed39d" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "5d295e22520c413c87a3e5fca01ed39d" member_type: VOTER } }
I20260812 06:19:05.619963 28061 sys_catalog.cc:455] T 00000000000000000000000000000000 P 5d295e22520c413c87a3e5fca01ed39d [sys.catalog]: SysCatalogTable state changed. Reason: New leader 5d295e22520c413c87a3e5fca01ed39d. Latest consensus state: current_term: 1 leader_uuid: "5d295e22520c413c87a3e5fca01ed39d" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "5d295e22520c413c87a3e5fca01ed39d" member_type: VOTER } }
I20260812 06:19:05.620095 28061 sys_catalog.cc:458] T 00000000000000000000000000000000 P 5d295e22520c413c87a3e5fca01ed39d [sys.catalog]: This master's current role is: LEADER
I20260812 06:19:05.620038 28060 sys_catalog.cc:458] T 00000000000000000000000000000000 P 5d295e22520c413c87a3e5fca01ed39d [sys.catalog]: This master's current role is: LEADER
I20260812 06:19:05.620645 28075 catalog_manager.cc:1511] Loading table and tablet metadata into memory...
I20260812 06:19:05.620651 27980 internal_mini_cluster.cc:184] Waiting to initialize catalog manager on master 0
I20260812 06:19:05.623206 28075 catalog_manager.cc:1520] Initializing Kudu cluster ID...
I20260812 06:19:05.629135 28075 catalog_manager.cc:1383] Generated new cluster ID: a81bd250aeef46e081a15e9e5c2f0e22
I20260812 06:19:05.629252 28075 catalog_manager.cc:1531] Initializing Kudu internal certificate authority...
I20260812 06:19:05.649665 28075 catalog_manager.cc:1406] Generated new certificate authority record
I20260812 06:19:05.650658 28075 catalog_manager.cc:1540] Loading token signing keys...
I20260812 06:19:05.656345 28075 catalog_manager.cc:6092] T 00000000000000000000000000000000 P 5d295e22520c413c87a3e5fca01ed39d: Generated new TSK 0
I20260812 06:19:05.657073 28075 catalog_manager.cc:1550] Initializing in-progress tserver states...
I20260812 06:19:05.685902 27980 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:19:05.689634 28083 instance_detector.cc:116] could not retrieve AWS instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:19:05.689750 27980 server_base.cc:1061] running on GCE node
W20260812 06:19:05.689576 28085 instance_detector.cc:116] could not retrieve Azure instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:19:05.689610 28087 instance_detector.cc:116] could not retrieve OpenStack instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:19:05.690197 27980 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:19:05.690326 27980 system_unsync_time.cc:38] NTP support is disabled. Clock error bounds will not be accurate. This configuration is not suitable for distributed clusters.
I20260812 06:19:05.690354 27980 hybrid_clock.cc:648] HybridClock initialized: now 1786515545690353 us; error 0 us; skew 500 ppm
I20260812 06:19:05.691516 27980 webserver.cc:533] Webserver started at http://127.27.83.1:35505/ using document root <none> and password file <none>
I20260812 06:19:05.691722 27980 fs_manager.cc:362] Metadata directory not provided
I20260812 06:19:05.691799 27980 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:19:05.691885 27980 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:19:05.692333 27980 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskt6ZbCi/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515545497762-27980-0/minicluster-data/ts-0-root/instance:
uuid: "a90d5b3f20c74b4b8e452e41c378fc23"
format_stamp: "Formatted at 2026-08-12 06:19:05 on dist-test-slave-btw8"
I20260812 06:19:05.694036 27980 fs_manager.cc:696] Time spent creating directory manager: real 0.001s	user 0.000s	sys 0.002s
I20260812 06:19:05.695197 28093 log_block_manager.cc:4127] Time spent loading block containers with low live blocks: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:19:05.695509 27980 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.000s	sys 0.001s
I20260812 06:19:05.695592 27980 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskt6ZbCi/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515545497762-27980-0/minicluster-data/ts-0-root
uuid: "a90d5b3f20c74b4b8e452e41c378fc23"
format_stamp: "Formatted at 2026-08-12 06:19:05 on dist-test-slave-btw8"
I20260812 06:19:05.695693 27980 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskt6ZbCi/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515545497762-27980-0/minicluster-data/ts-0-root
metadata directory: /tmp/dist-test-taskt6ZbCi/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515545497762-27980-0/minicluster-data/ts-0-root
1 data directories: /tmp/dist-test-taskt6ZbCi/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515545497762-27980-0/minicluster-data/ts-0-root/data
Total live blocks: 0
Total live bytes: 0
Total live bytes (after alignment): 0
Total number of LBM containers: 0 (0 full)
Did not check for missing blocks
Did not check for orphaned blocks
Total full LBM containers with extra space: 0 (0 repaired)
Total full LBM container extra space in bytes: 0 (0 repaired)
Total incomplete LBM containers: 0 (0 repaired)
Total LBM partial records: 0 (0 repaired)
Total corrupted LBM metadata records in RocksDB: 0 (0 repaired)
I20260812 06:19:05.710956 27980 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:19:05.711635 27980 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:19:05.712225 27980 txn_system_client.cc:432] TxnSystemClient initialization is disabled...
I20260812 06:19:05.713213 27980 ts_tablet_manager.cc:585] Loaded tablet metadata (0 total tablets, 0 live tablets)
I20260812 06:19:05.713267 27980 ts_tablet_manager.cc:531] Time spent load tablet metadata: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:19:05.713343 27980 ts_tablet_manager.cc:616] Registered 0 tablets
I20260812 06:19:05.713382 27980 ts_tablet_manager.cc:595] Time spent register tablets: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:19:05.721282 27980 rpc_server.cc:307] RPC server started. Bound to: 127.27.83.1:44043
I20260812 06:19:05.721336 28164 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.27.83.1:44043 every 8 connection(s)
I20260812 06:19:05.738857 28165 heartbeater.cc:344] Connected to a master server at 127.27.83.62:45541
I20260812 06:19:05.739180 28165 heartbeater.cc:461] Registering TS with master...
I20260812 06:19:05.739779 28165 heartbeater.cc:507] Master 127.27.83.62:45541 requested a full tablet report, sending...
I20260812 06:19:05.741546 28015 ts_manager.cc:194] Registered new tserver with Master: a90d5b3f20c74b4b8e452e41c378fc23 (127.27.83.1:44043)
I20260812 06:19:05.741659 27980 internal_mini_cluster.cc:371] 1 TS(s) registered with all masters after 0.01966082s
I20260812 06:19:05.742992 28015 master_service.cc:502] Signed X509 certificate for tserver {username='slave'} at 127.0.0.1:48906
I20260812 06:19:05.753008 28015 catalog_manager.cc:2283] Servicing CreateTable request from {username='slave'} at 127.0.0.1:48910:
name: "heavy-update-compaction-test"
schema {
  columns {
    name: "key"
    type: INT64
    is_key: true
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_a"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_b"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_c"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_d"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_e"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
}
num_replicas: 1
split_rows_range_bounds {
}
partition_schema {
  range_schema {
  }
}
I20260812 06:19:05.769097 28122 tablet_service.cc:1511] Processing CreateTablet for tablet 41cc8eda859d48b89eaec402e9d76753 (DEFAULT_TABLE table=heavy-update-compaction-test [id=dd68169afa1c4eab90606af2b23c0d90]), partition=
I20260812 06:19:05.769672 28122 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet 41cc8eda859d48b89eaec402e9d76753. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:19:05.773408 28179 tablet_bootstrap.cc:492] T 41cc8eda859d48b89eaec402e9d76753 P a90d5b3f20c74b4b8e452e41c378fc23: Bootstrap starting.
I20260812 06:19:05.774479 28179 tablet_bootstrap.cc:654] T 41cc8eda859d48b89eaec402e9d76753 P a90d5b3f20c74b4b8e452e41c378fc23: Neither blocks nor log segments found. Creating new log.
I20260812 06:19:05.776324 28179 tablet_bootstrap.cc:492] T 41cc8eda859d48b89eaec402e9d76753 P a90d5b3f20c74b4b8e452e41c378fc23: No bootstrap required, opened a new log
I20260812 06:19:05.776480 28179 ts_tablet_manager.cc:1403] T 41cc8eda859d48b89eaec402e9d76753 P a90d5b3f20c74b4b8e452e41c378fc23: Time spent bootstrapping tablet: real 0.003s	user 0.002s	sys 0.000s
I20260812 06:19:05.777165 28179 raft_consensus.cc:359] T 41cc8eda859d48b89eaec402e9d76753 P a90d5b3f20c74b4b8e452e41c378fc23 [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "a90d5b3f20c74b4b8e452e41c378fc23" member_type: VOTER last_known_addr { host: "127.27.83.1" port: 44043 } }
I20260812 06:19:05.777343 28179 raft_consensus.cc:385] T 41cc8eda859d48b89eaec402e9d76753 P a90d5b3f20c74b4b8e452e41c378fc23 [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:19:05.777403 28179 raft_consensus.cc:740] T 41cc8eda859d48b89eaec402e9d76753 P a90d5b3f20c74b4b8e452e41c378fc23 [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: a90d5b3f20c74b4b8e452e41c378fc23, State: Initialized, Role: FOLLOWER
I20260812 06:19:05.777551 28179 consensus_queue.cc:260] T 41cc8eda859d48b89eaec402e9d76753 P a90d5b3f20c74b4b8e452e41c378fc23 [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: "a90d5b3f20c74b4b8e452e41c378fc23" member_type: VOTER last_known_addr { host: "127.27.83.1" port: 44043 } }
I20260812 06:19:05.777657 28179 raft_consensus.cc:399] T 41cc8eda859d48b89eaec402e9d76753 P a90d5b3f20c74b4b8e452e41c378fc23 [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:19:05.777688 28179 raft_consensus.cc:493] T 41cc8eda859d48b89eaec402e9d76753 P a90d5b3f20c74b4b8e452e41c378fc23 [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:19:05.777760 28179 raft_consensus.cc:3060] T 41cc8eda859d48b89eaec402e9d76753 P a90d5b3f20c74b4b8e452e41c378fc23 [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:19:05.778620 28179 raft_consensus.cc:515] T 41cc8eda859d48b89eaec402e9d76753 P a90d5b3f20c74b4b8e452e41c378fc23 [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "a90d5b3f20c74b4b8e452e41c378fc23" member_type: VOTER last_known_addr { host: "127.27.83.1" port: 44043 } }
I20260812 06:19:05.778801 28179 leader_election.cc:304] T 41cc8eda859d48b89eaec402e9d76753 P a90d5b3f20c74b4b8e452e41c378fc23 [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: a90d5b3f20c74b4b8e452e41c378fc23; no voters: 
I20260812 06:19:05.779044 28179 leader_election.cc:290] T 41cc8eda859d48b89eaec402e9d76753 P a90d5b3f20c74b4b8e452e41c378fc23 [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:19:05.779237 28181 raft_consensus.cc:2804] T 41cc8eda859d48b89eaec402e9d76753 P a90d5b3f20c74b4b8e452e41c378fc23 [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:19:05.779500 28179 ts_tablet_manager.cc:1434] T 41cc8eda859d48b89eaec402e9d76753 P a90d5b3f20c74b4b8e452e41c378fc23: Time spent starting tablet: real 0.003s	user 0.003s	sys 0.000s
I20260812 06:19:05.779556 28181 raft_consensus.cc:697] T 41cc8eda859d48b89eaec402e9d76753 P a90d5b3f20c74b4b8e452e41c378fc23 [term 1 LEADER]: Becoming Leader. State: Replica: a90d5b3f20c74b4b8e452e41c378fc23, State: Running, Role: LEADER
I20260812 06:19:05.779721 28165 heartbeater.cc:499] Master 127.27.83.62:45541 was elected leader, sending a full tablet report...
I20260812 06:19:05.779783 28181 consensus_queue.cc:237] T 41cc8eda859d48b89eaec402e9d76753 P a90d5b3f20c74b4b8e452e41c378fc23 [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: "a90d5b3f20c74b4b8e452e41c378fc23" member_type: VOTER last_known_addr { host: "127.27.83.1" port: 44043 } }
I20260812 06:19:05.783041 28014 catalog_manager.cc:5719] T 41cc8eda859d48b89eaec402e9d76753 P a90d5b3f20c74b4b8e452e41c378fc23 reported cstate change: term changed from 0 to 1, leader changed from <none> to a90d5b3f20c74b4b8e452e41c378fc23 (127.27.83.1). New cstate: current_term: 1 leader_uuid: "a90d5b3f20c74b4b8e452e41c378fc23" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "a90d5b3f20c74b4b8e452e41c378fc23" member_type: VOTER last_known_addr { host: "127.27.83.1" port: 44043 } health_report { overall_health: HEALTHY } } }
I20260812 06:19:05.850404 27980 heavy-update-compaction-itest.cc:215] Time spent inserting: real 0.059s	user 0.024s	sys 0.004s
I20260812 06:19:05.972883 28166 maintenance_manager.cc:419] P a90d5b3f20c74b4b8e452e41c378fc23: Scheduling FlushMRSOp(41cc8eda859d48b89eaec402e9d76753): perf score=15.086190
I20260812 06:19:06.138525 28098 maintenance_manager.cc:643] P a90d5b3f20c74b4b8e452e41c378fc23: FlushMRSOp(41cc8eda859d48b89eaec402e9d76753) complete. Timing: real 0.165s	user 0.126s	sys 0.036s Metrics: {"bytes_written":12307490,"cfile_init":1,"compiler_manager_pool.queue_time_us":228,"delete_count":0,"dirs.queue_time_us":90,"dirs.run_cpu_time_us":247,"dirs.run_wall_time_us":954,"drs_written":1,"lbm_read_time_us":78,"lbm_reads_lt_1ms":4,"lbm_write_time_us":40425,"lbm_writes_lt_1ms":657,"peak_mem_usage":0,"reinsert_count":0,"rows_written":103,"thread_start_us":150,"threads_started":1,"update_count":1500}
I20260812 06:19:06.139964 28166 maintenance_manager.cc:419] P a90d5b3f20c74b4b8e452e41c378fc23: Scheduling LogGCOp(41cc8eda859d48b89eaec402e9d76753): free 8725963 bytes of WAL
I20260812 06:19:06.140316 28098 log_reader.cc:385] T 41cc8eda859d48b89eaec402e9d76753: removed 1 log segments from log reader
I20260812 06:19:06.140385 28098 log.cc:1079] T 41cc8eda859d48b89eaec402e9d76753 P a90d5b3f20c74b4b8e452e41c378fc23: Deleting log segment in path: /tmp/dist-test-taskt6ZbCi/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515545497762-27980-0/minicluster-data/ts-0-root/wals/41cc8eda859d48b89eaec402e9d76753/wal-000000001 (ops 1-6)
I20260812 06:19:06.142879 28098 maintenance_manager.cc:643] P a90d5b3f20c74b4b8e452e41c378fc23: LogGCOp(41cc8eda859d48b89eaec402e9d76753) complete. Timing: real 0.003s	user 0.000s	sys 0.000s Metrics: {}
I20260812 06:19:06.143513 28166 maintenance_manager.cc:419] P a90d5b3f20c74b4b8e452e41c378fc23: Scheduling UndoDeltaBlockGCOp(41cc8eda859d48b89eaec402e9d76753): 12308959 bytes on disk
I20260812 06:19:06.144438 28098 maintenance_manager.cc:643] P a90d5b3f20c74b4b8e452e41c378fc23: UndoDeltaBlockGCOp(41cc8eda859d48b89eaec402e9d76753) complete. Timing: real 0.001s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":95,"lbm_reads_lt_1ms":4}
I20260812 06:19:06.145115 28166 maintenance_manager.cc:419] P a90d5b3f20c74b4b8e452e41c378fc23: Scheduling FlushDeltaMemStoresOp(41cc8eda859d48b89eaec402e9d76753): perf score=2.188937
I20260812 06:19:06.163287 28098 maintenance_manager.cc:643] P a90d5b3f20c74b4b8e452e41c378fc23: FlushDeltaMemStoresOp(41cc8eda859d48b89eaec402e9d76753) complete. Timing: real 0.018s	user 0.007s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6554,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:06.164137 28166 maintenance_manager.cc:419] P a90d5b3f20c74b4b8e452e41c378fc23: Scheduling MajorDeltaCompactionOp(41cc8eda859d48b89eaec402e9d76753): perf score=1.000000
I20260812 06:19:06.318710 28098 maintenance_manager.cc:643] P a90d5b3f20c74b4b8e452e41c378fc23: MajorDeltaCompactionOp(41cc8eda859d48b89eaec402e9d76753) complete. Timing: real 0.154s	user 0.121s	sys 0.033s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20631312,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":1103,"lbm_read_time_us":11152,"lbm_reads_lt_1ms":464,"lbm_write_time_us":27776,"lbm_writes_lt_1ms":443,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":4352,"thread_start_us":349,"threads_started":5,"update_count":2000}
I20260812 06:19:06.319537 28166 maintenance_manager.cc:419] P a90d5b3f20c74b4b8e452e41c378fc23: Scheduling FlushDeltaMemStoresOp(41cc8eda859d48b89eaec402e9d76753): perf score=10.126437
I20260812 06:19:06.367281 28098 maintenance_manager.cc:643] P a90d5b3f20c74b4b8e452e41c378fc23: FlushDeltaMemStoresOp(41cc8eda859d48b89eaec402e9d76753) complete. Timing: real 0.047s	user 0.010s	sys 0.029s Metrics: {"bytes_written":12307491,"delete_count":0,"lbm_write_time_us":19761,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":302,"reinsert_count":0,"update_count":1500}
I20260812 06:19:06.367991 28166 maintenance_manager.cc:419] P a90d5b3f20c74b4b8e452e41c378fc23: Scheduling FlushDeltaMemStoresOp(41cc8eda859d48b89eaec402e9d76753): perf score=2.188937
I20260812 06:19:06.380926 28098 maintenance_manager.cc:643] P a90d5b3f20c74b4b8e452e41c378fc23: FlushDeltaMemStoresOp(41cc8eda859d48b89eaec402e9d76753) complete. Timing: real 0.013s	user 0.006s	sys 0.005s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4903,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:06.381836 28166 maintenance_manager.cc:419] P a90d5b3f20c74b4b8e452e41c378fc23: Scheduling MajorDeltaCompactionOp(41cc8eda859d48b89eaec402e9d76753): perf score=1.000000
I20260812 06:19:06.513720 28098 maintenance_manager.cc:643] P a90d5b3f20c74b4b8e452e41c378fc23: MajorDeltaCompactionOp(41cc8eda859d48b89eaec402e9d76753) complete. Timing: real 0.132s	user 0.112s	sys 0.019s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20631313,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":1064,"lbm_read_time_us":8219,"lbm_reads_lt_1ms":472,"lbm_write_time_us":26480,"lbm_writes_lt_1ms":443,"mutex_wait_us":368,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":8192,"update_count":2000}
I20260812 06:19:06.514420 28166 maintenance_manager.cc:419] P a90d5b3f20c74b4b8e452e41c378fc23: Scheduling FlushDeltaMemStoresOp(41cc8eda859d48b89eaec402e9d76753): perf score=10.126437
I20260812 06:19:06.560695 28098 maintenance_manager.cc:643] P a90d5b3f20c74b4b8e452e41c378fc23: FlushDeltaMemStoresOp(41cc8eda859d48b89eaec402e9d76753) complete. Timing: real 0.046s	user 0.022s	sys 0.016s Metrics: {"bytes_written":12307489,"delete_count":0,"lbm_write_time_us":17251,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:19:06.561206 28166 maintenance_manager.cc:419] P a90d5b3f20c74b4b8e452e41c378fc23: Scheduling FlushDeltaMemStoresOp(41cc8eda859d48b89eaec402e9d76753): perf score=2.188937
I20260812 06:19:06.572814 28098 maintenance_manager.cc:643] P a90d5b3f20c74b4b8e452e41c378fc23: FlushDeltaMemStoresOp(41cc8eda859d48b89eaec402e9d76753) complete. Timing: real 0.011s	user 0.006s	sys 0.004s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4223,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:06.573469 28166 maintenance_manager.cc:419] P a90d5b3f20c74b4b8e452e41c378fc23: Scheduling MajorDeltaCompactionOp(41cc8eda859d48b89eaec402e9d76753): perf score=1.000000
I20260812 06:19:06.709697 28098 maintenance_manager.cc:643] P a90d5b3f20c74b4b8e452e41c378fc23: MajorDeltaCompactionOp(41cc8eda859d48b89eaec402e9d76753) complete. Timing: real 0.136s	user 0.105s	sys 0.030s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20631310,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":499,"lbm_read_time_us":10162,"lbm_reads_lt_1ms":472,"lbm_write_time_us":26311,"lbm_writes_lt_1ms":443,"mutex_wait_us":51,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":19072,"update_count":2000}
I20260812 06:19:06.710352 28166 maintenance_manager.cc:419] P a90d5b3f20c74b4b8e452e41c378fc23: Scheduling FlushDeltaMemStoresOp(41cc8eda859d48b89eaec402e9d76753): perf score=10.126437
I20260812 06:19:06.766145 28098 maintenance_manager.cc:643] P a90d5b3f20c74b4b8e452e41c378fc23: FlushDeltaMemStoresOp(41cc8eda859d48b89eaec402e9d76753) complete. Timing: real 0.056s	user 0.019s	sys 0.022s Metrics: {"bytes_written":12307491,"delete_count":0,"lbm_write_time_us":15170,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:19:06.766808 28166 maintenance_manager.cc:419] P a90d5b3f20c74b4b8e452e41c378fc23: Scheduling FlushDeltaMemStoresOp(41cc8eda859d48b89eaec402e9d76753): perf score=2.188937
I20260812 06:19:06.780339 28098 maintenance_manager.cc:643] P a90d5b3f20c74b4b8e452e41c378fc23: FlushDeltaMemStoresOp(41cc8eda859d48b89eaec402e9d76753) complete. Timing: real 0.013s	user 0.012s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4751,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:06.780972 28166 maintenance_manager.cc:419] P a90d5b3f20c74b4b8e452e41c378fc23: Scheduling MajorDeltaCompactionOp(41cc8eda859d48b89eaec402e9d76753): perf score=1.000000
I20260812 06:19:06.953414 28098 maintenance_manager.cc:643] P a90d5b3f20c74b4b8e452e41c378fc23: MajorDeltaCompactionOp(41cc8eda859d48b89eaec402e9d76753) complete. Timing: real 0.172s	user 0.156s	sys 0.011s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20631313,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":359,"lbm_read_time_us":13763,"lbm_reads_lt_1ms":472,"lbm_write_time_us":27455,"lbm_writes_lt_1ms":443,"mutex_wait_us":62,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":3328,"update_count":2000}
I20260812 06:19:06.954048 28166 maintenance_manager.cc:419] P a90d5b3f20c74b4b8e452e41c378fc23: Scheduling FlushDeltaMemStoresOp(41cc8eda859d48b89eaec402e9d76753): perf score=10.126437
I20260812 06:19:06.992028 28098 maintenance_manager.cc:643] P a90d5b3f20c74b4b8e452e41c378fc23: FlushDeltaMemStoresOp(41cc8eda859d48b89eaec402e9d76753) complete. Timing: real 0.038s	user 0.010s	sys 0.024s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":14779,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:19:06.992705 28166 maintenance_manager.cc:419] P a90d5b3f20c74b4b8e452e41c378fc23: Scheduling MajorDeltaCompactionOp(41cc8eda859d48b89eaec402e9d76753): perf score=1.000000
I20260812 06:19:07.109730 28098 maintenance_manager.cc:643] P a90d5b3f20c74b4b8e452e41c378fc23: MajorDeltaCompactionOp(41cc8eda859d48b89eaec402e9d76753) complete. Timing: real 0.117s	user 0.078s	sys 0.039s Metrics: {"cfile_cache_miss":331,"cfile_cache_miss_bytes":16528781,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":1,"delta_iterators_relevant":1,"dirs.queue_time_us":542,"lbm_read_time_us":8153,"lbm_reads_lt_1ms":363,"lbm_write_time_us":20762,"lbm_writes_lt_1ms":343,"peak_mem_usage":38262756,"reinsert_count":0,"update_count":1500}
I20260812 06:19:07.110425 28166 maintenance_manager.cc:419] P a90d5b3f20c74b4b8e452e41c378fc23: Scheduling FlushDeltaMemStoresOp(41cc8eda859d48b89eaec402e9d76753): perf score=10.126437
I20260812 06:19:07.156311 28098 maintenance_manager.cc:643] P a90d5b3f20c74b4b8e452e41c378fc23: FlushDeltaMemStoresOp(41cc8eda859d48b89eaec402e9d76753) complete. Timing: real 0.046s	user 0.024s	sys 0.017s Metrics: {"bytes_written":12307489,"delete_count":0,"lbm_write_time_us":20208,"lbm_writes_1-10_ms":2,"lbm_writes_lt_1ms":301,"reinsert_count":0,"update_count":1500}
I20260812 06:19:07.156909 28166 maintenance_manager.cc:419] P a90d5b3f20c74b4b8e452e41c378fc23: Scheduling FlushDeltaMemStoresOp(41cc8eda859d48b89eaec402e9d76753): perf score=2.188937
I20260812 06:19:07.168392 28098 maintenance_manager.cc:643] P a90d5b3f20c74b4b8e452e41c378fc23: FlushDeltaMemStoresOp(41cc8eda859d48b89eaec402e9d76753) complete. Timing: real 0.011s	user 0.005s	sys 0.005s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4253,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:07.169029 28166 maintenance_manager.cc:419] P a90d5b3f20c74b4b8e452e41c378fc23: Scheduling MajorDeltaCompactionOp(41cc8eda859d48b89eaec402e9d76753): perf score=1.000000
I20260812 06:19:07.301314 28098 maintenance_manager.cc:643] P a90d5b3f20c74b4b8e452e41c378fc23: MajorDeltaCompactionOp(41cc8eda859d48b89eaec402e9d76753) complete. Timing: real 0.132s	user 0.107s	sys 0.025s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20631311,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":50,"lbm_read_time_us":9134,"lbm_reads_lt_1ms":472,"lbm_write_time_us":25842,"lbm_writes_lt_1ms":443,"mutex_wait_us":33,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":17664,"update_count":2000}
I20260812 06:19:07.302209 28166 maintenance_manager.cc:419] P a90d5b3f20c74b4b8e452e41c378fc23: Scheduling FlushDeltaMemStoresOp(41cc8eda859d48b89eaec402e9d76753): perf score=10.126437
I20260812 06:19:07.361438 28098 maintenance_manager.cc:643] P a90d5b3f20c74b4b8e452e41c378fc23: FlushDeltaMemStoresOp(41cc8eda859d48b89eaec402e9d76753) complete. Timing: real 0.059s	user 0.024s	sys 0.032s Metrics: {"bytes_written":12307489,"delete_count":0,"lbm_write_time_us":22453,"lbm_writes_1-10_ms":3,"lbm_writes_lt_1ms":300,"reinsert_count":0,"update_count":1500}
I20260812 06:19:07.362113 28166 maintenance_manager.cc:419] P a90d5b3f20c74b4b8e452e41c378fc23: Scheduling FlushDeltaMemStoresOp(41cc8eda859d48b89eaec402e9d76753): perf score=2.188937
I20260812 06:19:07.379633 28098 maintenance_manager.cc:643] P a90d5b3f20c74b4b8e452e41c378fc23: FlushDeltaMemStoresOp(41cc8eda859d48b89eaec402e9d76753) complete. Timing: real 0.017s	user 0.013s	sys 0.004s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":6541,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:07.380373 28166 maintenance_manager.cc:419] P a90d5b3f20c74b4b8e452e41c378fc23: Scheduling MajorDeltaCompactionOp(41cc8eda859d48b89eaec402e9d76753): perf score=1.000000
I20260812 06:19:07.563983 28098 maintenance_manager.cc:643] P a90d5b3f20c74b4b8e452e41c378fc23: MajorDeltaCompactionOp(41cc8eda859d48b89eaec402e9d76753) complete. Timing: real 0.183s	user 0.108s	sys 0.066s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20631310,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":1081,"lbm_read_time_us":14770,"lbm_reads_lt_1ms":472,"lbm_write_time_us":26551,"lbm_writes_lt_1ms":443,"mutex_wait_us":82,"peak_mem_usage":50689328,"reinsert_count":0,"update_count":2000}
I20260812 06:19:07.564755 28166 maintenance_manager.cc:419] P a90d5b3f20c74b4b8e452e41c378fc23: Scheduling FlushDeltaMemStoresOp(41cc8eda859d48b89eaec402e9d76753): perf score=10.126437
I20260812 06:19:07.615453 28098 maintenance_manager.cc:643] P a90d5b3f20c74b4b8e452e41c378fc23: FlushDeltaMemStoresOp(41cc8eda859d48b89eaec402e9d76753) complete. Timing: real 0.050s	user 0.019s	sys 0.017s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":15295,"lbm_writes_lt_1ms":303,"reinsert_count":0,"spinlock_wait_cycles":1280,"update_count":1500}
I20260812 06:19:07.616118 28166 maintenance_manager.cc:419] P a90d5b3f20c74b4b8e452e41c378fc23: Scheduling FlushDeltaMemStoresOp(41cc8eda859d48b89eaec402e9d76753): perf score=2.188937
I20260812 06:19:07.628295 28098 maintenance_manager.cc:643] P a90d5b3f20c74b4b8e452e41c378fc23: FlushDeltaMemStoresOp(41cc8eda859d48b89eaec402e9d76753) complete. Timing: real 0.012s	user 0.007s	sys 0.004s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4614,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:07.628921 28166 maintenance_manager.cc:419] P a90d5b3f20c74b4b8e452e41c378fc23: Scheduling FlushMRSOp(41cc8eda859d48b89eaec402e9d76753): perf score=1.000000
I20260812 06:19:07.660974 28098 maintenance_manager.cc:643] P a90d5b3f20c74b4b8e452e41c378fc23: FlushMRSOp(41cc8eda859d48b89eaec402e9d76753) complete. Timing: real 0.032s	user 0.026s	sys 0.004s Metrics: {"bytes_written":1275444,"cfile_init":1,"dirs.queue_time_us":75,"dirs.run_cpu_time_us":286,"dirs.run_wall_time_us":1751,"drs_written":1,"lbm_read_time_us":39,"lbm_reads_lt_1ms":4,"lbm_write_time_us":2143,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":31}
I20260812 06:19:07.661828 28166 maintenance_manager.cc:419] P a90d5b3f20c74b4b8e452e41c378fc23: Scheduling LogGCOp(41cc8eda859d48b89eaec402e9d76753): free 136275163 bytes of WAL
I20260812 06:19:07.662108 28098 log_reader.cc:385] T 41cc8eda859d48b89eaec402e9d76753: removed 13 log segments from log reader
I20260812 06:19:07.662154 28098 log.cc:1079] T 41cc8eda859d48b89eaec402e9d76753 P a90d5b3f20c74b4b8e452e41c378fc23: Deleting log segment in path: /tmp/dist-test-taskt6ZbCi/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515545497762-27980-0/minicluster-data/ts-0-root/wals/41cc8eda859d48b89eaec402e9d76753/wal-000000002 (ops 7-11)
I20260812 06:19:07.662185 28098 log.cc:1079] T 41cc8eda859d48b89eaec402e9d76753 P a90d5b3f20c74b4b8e452e41c378fc23: Deleting log segment in path: /tmp/dist-test-taskt6ZbCi/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515545497762-27980-0/minicluster-data/ts-0-root/wals/41cc8eda859d48b89eaec402e9d76753/wal-000000003 (ops 12-16)
I20260812 06:19:07.662261 28098 log.cc:1079] T 41cc8eda859d48b89eaec402e9d76753 P a90d5b3f20c74b4b8e452e41c378fc23: Deleting log segment in path: /tmp/dist-test-taskt6ZbCi/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515545497762-27980-0/minicluster-data/ts-0-root/wals/41cc8eda859d48b89eaec402e9d76753/wal-000000004 (ops 17-21)
I20260812 06:19:07.662297 28098 log.cc:1079] T 41cc8eda859d48b89eaec402e9d76753 P a90d5b3f20c74b4b8e452e41c378fc23: Deleting log segment in path: /tmp/dist-test-taskt6ZbCi/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515545497762-27980-0/minicluster-data/ts-0-root/wals/41cc8eda859d48b89eaec402e9d76753/wal-000000005 (ops 22-26)
I20260812 06:19:07.662338 28098 log.cc:1079] T 41cc8eda859d48b89eaec402e9d76753 P a90d5b3f20c74b4b8e452e41c378fc23: Deleting log segment in path: /tmp/dist-test-taskt6ZbCi/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515545497762-27980-0/minicluster-data/ts-0-root/wals/41cc8eda859d48b89eaec402e9d76753/wal-000000006 (ops 27-31)
I20260812 06:19:07.662400 28098 log.cc:1079] T 41cc8eda859d48b89eaec402e9d76753 P a90d5b3f20c74b4b8e452e41c378fc23: Deleting log segment in path: /tmp/dist-test-taskt6ZbCi/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515545497762-27980-0/minicluster-data/ts-0-root/wals/41cc8eda859d48b89eaec402e9d76753/wal-000000007 (ops 32-36)
I20260812 06:19:07.662437 28098 log.cc:1079] T 41cc8eda859d48b89eaec402e9d76753 P a90d5b3f20c74b4b8e452e41c378fc23: Deleting log segment in path: /tmp/dist-test-taskt6ZbCi/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515545497762-27980-0/minicluster-data/ts-0-root/wals/41cc8eda859d48b89eaec402e9d76753/wal-000000008 (ops 37-40)
I20260812 06:19:07.662479 28098 log.cc:1079] T 41cc8eda859d48b89eaec402e9d76753 P a90d5b3f20c74b4b8e452e41c378fc23: Deleting log segment in path: /tmp/dist-test-taskt6ZbCi/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515545497762-27980-0/minicluster-data/ts-0-root/wals/41cc8eda859d48b89eaec402e9d76753/wal-000000009 (ops 41-45)
I20260812 06:19:07.662516 28098 log.cc:1079] T 41cc8eda859d48b89eaec402e9d76753 P a90d5b3f20c74b4b8e452e41c378fc23: Deleting log segment in path: /tmp/dist-test-taskt6ZbCi/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515545497762-27980-0/minicluster-data/ts-0-root/wals/41cc8eda859d48b89eaec402e9d76753/wal-000000010 (ops 46-50)
I20260812 06:19:07.662555 28098 log.cc:1079] T 41cc8eda859d48b89eaec402e9d76753 P a90d5b3f20c74b4b8e452e41c378fc23: Deleting log segment in path: /tmp/dist-test-taskt6ZbCi/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515545497762-27980-0/minicluster-data/ts-0-root/wals/41cc8eda859d48b89eaec402e9d76753/wal-000000011 (ops 51-55)
I20260812 06:19:07.662600 28098 log.cc:1079] T 41cc8eda859d48b89eaec402e9d76753 P a90d5b3f20c74b4b8e452e41c378fc23: Deleting log segment in path: /tmp/dist-test-taskt6ZbCi/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515545497762-27980-0/minicluster-data/ts-0-root/wals/41cc8eda859d48b89eaec402e9d76753/wal-000000012 (ops 56-60)
I20260812 06:19:07.662640 28098 log.cc:1079] T 41cc8eda859d48b89eaec402e9d76753 P a90d5b3f20c74b4b8e452e41c378fc23: Deleting log segment in path: /tmp/dist-test-taskt6ZbCi/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515545497762-27980-0/minicluster-data/ts-0-root/wals/41cc8eda859d48b89eaec402e9d76753/wal-000000013 (ops 61-65)
I20260812 06:19:07.662679 28098 log.cc:1079] T 41cc8eda859d48b89eaec402e9d76753 P a90d5b3f20c74b4b8e452e41c378fc23: Deleting log segment in path: /tmp/dist-test-taskt6ZbCi/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515545497762-27980-0/minicluster-data/ts-0-root/wals/41cc8eda859d48b89eaec402e9d76753/wal-000000014 (ops 66-70)
I20260812 06:19:07.694525 28098 maintenance_manager.cc:643] P a90d5b3f20c74b4b8e452e41c378fc23: LogGCOp(41cc8eda859d48b89eaec402e9d76753) complete. Timing: real 0.032s	user 0.000s	sys 0.029s Metrics: {}
I20260812 06:19:07.695015 28166 maintenance_manager.cc:419] P a90d5b3f20c74b4b8e452e41c378fc23: Scheduling UndoDeltaBlockGCOp(41cc8eda859d48b89eaec402e9d76753): 482 bytes on disk
I20260812 06:19:07.695567 28098 maintenance_manager.cc:643] P a90d5b3f20c74b4b8e452e41c378fc23: UndoDeltaBlockGCOp(41cc8eda859d48b89eaec402e9d76753) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":62,"lbm_reads_lt_1ms":4}
I20260812 06:19:07.696058 28166 maintenance_manager.cc:419] P a90d5b3f20c74b4b8e452e41c378fc23: Scheduling FlushDeltaMemStoresOp(41cc8eda859d48b89eaec402e9d76753): perf score=3.181125
I20260812 06:19:07.708743 28098 maintenance_manager.cc:643] P a90d5b3f20c74b4b8e452e41c378fc23: FlushDeltaMemStoresOp(41cc8eda859d48b89eaec402e9d76753) complete. Timing: real 0.013s	user 0.007s	sys 0.004s Metrics: {"bytes_written":4512900,"delete_count":0,"lbm_write_time_us":4622,"lbm_writes_lt_1ms":113,"reinsert_count":0,"update_count":550}
I20260812 06:19:07.709262 28166 maintenance_manager.cc:419] P a90d5b3f20c74b4b8e452e41c378fc23: Scheduling FlushDeltaMemStoresOp(41cc8eda859d48b89eaec402e9d76753): perf score=2.188937
I20260812 06:19:07.728197 28098 maintenance_manager.cc:643] P a90d5b3f20c74b4b8e452e41c378fc23: FlushDeltaMemStoresOp(41cc8eda859d48b89eaec402e9d76753) complete. Timing: real 0.019s	user 0.007s	sys 0.011s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3871,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:19:07.728833 28166 maintenance_manager.cc:419] P a90d5b3f20c74b4b8e452e41c378fc23: Scheduling MajorDeltaCompactionOp(41cc8eda859d48b89eaec402e9d76753): perf score=1.000000
I20260812 06:19:07.943131 28098 maintenance_manager.cc:643] P a90d5b3f20c74b4b8e452e41c378fc23: MajorDeltaCompactionOp(41cc8eda859d48b89eaec402e9d76753) complete. Timing: real 0.214s	user 0.159s	sys 0.052s Metrics: {"cfile_cache_miss":634,"cfile_cache_miss_bytes":28836360,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":3741,"lbm_read_time_us":15954,"lbm_reads_lt_1ms":674,"lbm_write_time_us":34674,"lbm_writes_lt_1ms":643,"mutex_wait_us":1529,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":1408,"thread_start_us":92,"threads_started":1,"update_count":3000}
I20260812 06:19:07.944010 28166 maintenance_manager.cc:419] P a90d5b3f20c74b4b8e452e41c378fc23: Scheduling FlushDeltaMemStoresOp(41cc8eda859d48b89eaec402e9d76753): perf score=14.095187
I20260812 06:19:08.017037 28098 maintenance_manager.cc:643] P a90d5b3f20c74b4b8e452e41c378fc23: FlushDeltaMemStoresOp(41cc8eda859d48b89eaec402e9d76753) complete. Timing: real 0.073s	user 0.027s	sys 0.032s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":21592,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:08.017874 28166 maintenance_manager.cc:419] P a90d5b3f20c74b4b8e452e41c378fc23: Scheduling FlushDeltaMemStoresOp(41cc8eda859d48b89eaec402e9d76753): perf score=2.188937
I20260812 06:19:08.030193 28098 maintenance_manager.cc:643] P a90d5b3f20c74b4b8e452e41c378fc23: FlushDeltaMemStoresOp(41cc8eda859d48b89eaec402e9d76753) complete. Timing: real 0.012s	user 0.003s	sys 0.007s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5114,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:08.030714 28166 maintenance_manager.cc:419] P a90d5b3f20c74b4b8e452e41c378fc23: Scheduling MajorDeltaCompactionOp(41cc8eda859d48b89eaec402e9d76753): perf score=1.000000
I20260812 06:19:08.222393 28098 maintenance_manager.cc:643] P a90d5b3f20c74b4b8e452e41c378fc23: MajorDeltaCompactionOp(41cc8eda859d48b89eaec402e9d76753) complete. Timing: real 0.191s	user 0.147s	sys 0.044s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24733724,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":213,"lbm_read_time_us":14138,"lbm_reads_lt_1ms":572,"lbm_write_time_us":32458,"lbm_writes_lt_1ms":543,"mutex_wait_us":70,"peak_mem_usage":63115900,"reinsert_count":0,"update_count":2500}
I20260812 06:19:08.223212 28166 maintenance_manager.cc:419] P a90d5b3f20c74b4b8e452e41c378fc23: Scheduling FlushDeltaMemStoresOp(41cc8eda859d48b89eaec402e9d76753): perf score=10.126437
I20260812 06:19:08.262943 28098 maintenance_manager.cc:643] P a90d5b3f20c74b4b8e452e41c378fc23: FlushDeltaMemStoresOp(41cc8eda859d48b89eaec402e9d76753) complete. Timing: real 0.039s	user 0.024s	sys 0.012s Metrics: {"bytes_written":12307491,"delete_count":0,"lbm_write_time_us":16921,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:19:08.263684 28166 maintenance_manager.cc:419] P a90d5b3f20c74b4b8e452e41c378fc23: Scheduling FlushDeltaMemStoresOp(41cc8eda859d48b89eaec402e9d76753): perf score=2.188937
I20260812 06:19:08.275983 28098 maintenance_manager.cc:643] P a90d5b3f20c74b4b8e452e41c378fc23: FlushDeltaMemStoresOp(41cc8eda859d48b89eaec402e9d76753) complete. Timing: real 0.012s	user 0.003s	sys 0.009s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4854,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:08.276572 28166 maintenance_manager.cc:419] P a90d5b3f20c74b4b8e452e41c378fc23: Scheduling MajorDeltaCompactionOp(41cc8eda859d48b89eaec402e9d76753): perf score=1.000000
I20260812 06:19:08.416890 28098 maintenance_manager.cc:643] P a90d5b3f20c74b4b8e452e41c378fc23: MajorDeltaCompactionOp(41cc8eda859d48b89eaec402e9d76753) complete. Timing: real 0.140s	user 0.111s	sys 0.028s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20631313,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":412,"lbm_read_time_us":10386,"lbm_reads_lt_1ms":472,"lbm_write_time_us":25719,"lbm_writes_lt_1ms":443,"mutex_wait_us":33,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":34304,"update_count":2000}
I20260812 06:19:08.417740 28166 maintenance_manager.cc:419] P a90d5b3f20c74b4b8e452e41c378fc23: Scheduling FlushDeltaMemStoresOp(41cc8eda859d48b89eaec402e9d76753): perf score=10.126437
I20260812 06:19:08.458513 28098 maintenance_manager.cc:643] P a90d5b3f20c74b4b8e452e41c378fc23: FlushDeltaMemStoresOp(41cc8eda859d48b89eaec402e9d76753) complete. Timing: real 0.041s	user 0.028s	sys 0.007s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":17167,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:19:08.459090 28166 maintenance_manager.cc:419] P a90d5b3f20c74b4b8e452e41c378fc23: Scheduling MajorDeltaCompactionOp(41cc8eda859d48b89eaec402e9d76753): perf score=1.000000
I20260812 06:19:08.595300 28098 maintenance_manager.cc:643] P a90d5b3f20c74b4b8e452e41c378fc23: MajorDeltaCompactionOp(41cc8eda859d48b89eaec402e9d76753) complete. Timing: real 0.136s	user 0.088s	sys 0.048s Metrics: {"cfile_cache_miss":331,"cfile_cache_miss_bytes":16528781,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":1,"delta_iterators_relevant":1,"dirs.queue_time_us":951,"lbm_read_time_us":9287,"lbm_reads_lt_1ms":363,"lbm_write_time_us":23364,"lbm_writes_lt_1ms":343,"mutex_wait_us":369,"peak_mem_usage":38262756,"reinsert_count":0,"update_count":1500}
I20260812 06:19:08.595892 28166 maintenance_manager.cc:419] P a90d5b3f20c74b4b8e452e41c378fc23: Scheduling FlushDeltaMemStoresOp(41cc8eda859d48b89eaec402e9d76753): perf score=10.126437
I20260812 06:19:08.652315 28098 maintenance_manager.cc:643] P a90d5b3f20c74b4b8e452e41c378fc23: FlushDeltaMemStoresOp(41cc8eda859d48b89eaec402e9d76753) complete. Timing: real 0.056s	user 0.033s	sys 0.015s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":22346,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":302,"reinsert_count":0,"update_count":1500}
I20260812 06:19:08.652951 28166 maintenance_manager.cc:419] P a90d5b3f20c74b4b8e452e41c378fc23: Scheduling MajorDeltaCompactionOp(41cc8eda859d48b89eaec402e9d76753): perf score=1.000000
I20260812 06:19:08.796906 28098 maintenance_manager.cc:643] P a90d5b3f20c74b4b8e452e41c378fc23: MajorDeltaCompactionOp(41cc8eda859d48b89eaec402e9d76753) complete. Timing: real 0.144s	user 0.099s	sys 0.044s Metrics: {"cfile_cache_miss":331,"cfile_cache_miss_bytes":16528781,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":1,"delta_iterators_relevant":1,"dirs.queue_time_us":220,"lbm_read_time_us":9749,"lbm_reads_lt_1ms":363,"lbm_write_time_us":25724,"lbm_writes_lt_1ms":343,"mutex_wait_us":55,"peak_mem_usage":38262756,"reinsert_count":0,"spinlock_wait_cycles":1280,"update_count":1500}
I20260812 06:19:08.797986 28166 maintenance_manager.cc:419] P a90d5b3f20c74b4b8e452e41c378fc23: Scheduling FlushDeltaMemStoresOp(41cc8eda859d48b89eaec402e9d76753): perf score=10.126437
I20260812 06:19:08.844244 28098 maintenance_manager.cc:643] P a90d5b3f20c74b4b8e452e41c378fc23: FlushDeltaMemStoresOp(41cc8eda859d48b89eaec402e9d76753) complete. Timing: real 0.046s	user 0.031s	sys 0.012s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":19392,"lbm_writes_lt_1ms":303,"reinsert_count":0,"spinlock_wait_cycles":768,"update_count":1500}
I20260812 06:19:08.844715 28166 maintenance_manager.cc:419] P a90d5b3f20c74b4b8e452e41c378fc23: Scheduling FlushDeltaMemStoresOp(41cc8eda859d48b89eaec402e9d76753): perf score=2.188937
I20260812 06:19:08.855723 28098 maintenance_manager.cc:643] P a90d5b3f20c74b4b8e452e41c378fc23: FlushDeltaMemStoresOp(41cc8eda859d48b89eaec402e9d76753) complete. Timing: real 0.011s	user 0.002s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4210,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:08.856305 28166 maintenance_manager.cc:419] P a90d5b3f20c74b4b8e452e41c378fc23: Scheduling MajorDeltaCompactionOp(41cc8eda859d48b89eaec402e9d76753): perf score=1.000000
I20260812 06:19:09.003054 28098 maintenance_manager.cc:643] P a90d5b3f20c74b4b8e452e41c378fc23: MajorDeltaCompactionOp(41cc8eda859d48b89eaec402e9d76753) complete. Timing: real 0.147s	user 0.110s	sys 0.028s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20631312,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":403,"lbm_read_time_us":9992,"lbm_reads_lt_1ms":472,"lbm_write_time_us":27440,"lbm_writes_lt_1ms":443,"mutex_wait_us":61,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":16512,"update_count":2000}
I20260812 06:19:09.003917 28166 maintenance_manager.cc:419] P a90d5b3f20c74b4b8e452e41c378fc23: Scheduling FlushDeltaMemStoresOp(41cc8eda859d48b89eaec402e9d76753): perf score=10.126437
I20260812 06:19:09.056346 28098 maintenance_manager.cc:643] P a90d5b3f20c74b4b8e452e41c378fc23: FlushDeltaMemStoresOp(41cc8eda859d48b89eaec402e9d76753) complete. Timing: real 0.052s	user 0.016s	sys 0.022s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":16884,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:19:09.057025 28166 maintenance_manager.cc:419] P a90d5b3f20c74b4b8e452e41c378fc23: Scheduling FlushDeltaMemStoresOp(41cc8eda859d48b89eaec402e9d76753): perf score=2.188937
I20260812 06:19:09.071060 28098 maintenance_manager.cc:643] P a90d5b3f20c74b4b8e452e41c378fc23: FlushDeltaMemStoresOp(41cc8eda859d48b89eaec402e9d76753) complete. Timing: real 0.014s	user 0.007s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5215,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:09.071679 28166 maintenance_manager.cc:419] P a90d5b3f20c74b4b8e452e41c378fc23: Scheduling MajorDeltaCompactionOp(41cc8eda859d48b89eaec402e9d76753): perf score=1.000000
I20260812 06:19:09.200691 28098 maintenance_manager.cc:643] P a90d5b3f20c74b4b8e452e41c378fc23: MajorDeltaCompactionOp(41cc8eda859d48b89eaec402e9d76753) complete. Timing: real 0.129s	user 0.093s	sys 0.036s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20631312,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":214,"lbm_read_time_us":9745,"lbm_reads_lt_1ms":472,"lbm_write_time_us":24651,"lbm_writes_lt_1ms":443,"mutex_wait_us":29,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":25856,"update_count":2000}
I20260812 06:19:09.201637 28166 maintenance_manager.cc:419] P a90d5b3f20c74b4b8e452e41c378fc23: Scheduling FlushDeltaMemStoresOp(41cc8eda859d48b89eaec402e9d76753): perf score=10.126437
I20260812 06:19:09.267933 28098 maintenance_manager.cc:643] P a90d5b3f20c74b4b8e452e41c378fc23: FlushDeltaMemStoresOp(41cc8eda859d48b89eaec402e9d76753) complete. Timing: real 0.066s	user 0.035s	sys 0.020s Metrics: {"bytes_written":12307491,"delete_count":0,"lbm_write_time_us":19954,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:19:09.268735 28166 maintenance_manager.cc:419] P a90d5b3f20c74b4b8e452e41c378fc23: Scheduling FlushDeltaMemStoresOp(41cc8eda859d48b89eaec402e9d76753): perf score=2.188937
I20260812 06:19:09.281529 28098 maintenance_manager.cc:643] P a90d5b3f20c74b4b8e452e41c378fc23: FlushDeltaMemStoresOp(41cc8eda859d48b89eaec402e9d76753) complete. Timing: real 0.013s	user 0.002s	sys 0.009s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4816,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:09.282088 28166 maintenance_manager.cc:419] P a90d5b3f20c74b4b8e452e41c378fc23: Scheduling FlushMRSOp(41cc8eda859d48b89eaec402e9d76753): perf score=1.000000
I20260812 06:19:09.316818 28098 maintenance_manager.cc:643] P a90d5b3f20c74b4b8e452e41c378fc23: FlushMRSOp(41cc8eda859d48b89eaec402e9d76753) complete. Timing: real 0.035s	user 0.033s	sys 0.000s Metrics: {"bytes_written":1193509,"cfile_init":1,"dirs.queue_time_us":115,"dirs.run_cpu_time_us":309,"dirs.run_wall_time_us":1757,"drs_written":1,"lbm_read_time_us":44,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1760,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":29}
I20260812 06:19:09.317613 28166 maintenance_manager.cc:419] P a90d5b3f20c74b4b8e452e41c378fc23: Scheduling UndoDeltaBlockGCOp(41cc8eda859d48b89eaec402e9d76753): 463 bytes on disk
I20260812 06:19:09.318030 28098 maintenance_manager.cc:643] P a90d5b3f20c74b4b8e452e41c378fc23: UndoDeltaBlockGCOp(41cc8eda859d48b89eaec402e9d76753) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":52,"lbm_reads_lt_1ms":4}
I20260812 06:19:09.318802 28166 maintenance_manager.cc:419] P a90d5b3f20c74b4b8e452e41c378fc23: Scheduling MajorDeltaCompactionOp(41cc8eda859d48b89eaec402e9d76753): perf score=1.000000
I20260812 06:19:09.492694 28098 maintenance_manager.cc:643] P a90d5b3f20c74b4b8e452e41c378fc23: MajorDeltaCompactionOp(41cc8eda859d48b89eaec402e9d76753) complete. Timing: real 0.174s	user 0.131s	sys 0.032s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20631313,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":1201,"lbm_read_time_us":12097,"lbm_reads_lt_1ms":464,"lbm_write_time_us":26875,"lbm_writes_lt_1ms":443,"mutex_wait_us":311,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":2560,"update_count":2000}
I20260812 06:19:09.493336 28166 maintenance_manager.cc:419] P a90d5b3f20c74b4b8e452e41c378fc23: Scheduling LogGCOp(41cc8eda859d48b89eaec402e9d76753): free 121006384 bytes of WAL
I20260812 06:19:09.493592 28098 log_reader.cc:385] T 41cc8eda859d48b89eaec402e9d76753: removed 12 log segments from log reader
I20260812 06:19:09.493651 28098 log.cc:1079] T 41cc8eda859d48b89eaec402e9d76753 P a90d5b3f20c74b4b8e452e41c378fc23: Deleting log segment in path: /tmp/dist-test-taskt6ZbCi/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515545497762-27980-0/minicluster-data/ts-0-root/wals/41cc8eda859d48b89eaec402e9d76753/wal-000000015 (ops 71-75)
I20260812 06:19:09.493750 28098 log.cc:1079] T 41cc8eda859d48b89eaec402e9d76753 P a90d5b3f20c74b4b8e452e41c378fc23: Deleting log segment in path: /tmp/dist-test-taskt6ZbCi/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515545497762-27980-0/minicluster-data/ts-0-root/wals/41cc8eda859d48b89eaec402e9d76753/wal-000000016 (ops 76-80)
I20260812 06:19:09.493793 28098 log.cc:1079] T 41cc8eda859d48b89eaec402e9d76753 P a90d5b3f20c74b4b8e452e41c378fc23: Deleting log segment in path: /tmp/dist-test-taskt6ZbCi/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515545497762-27980-0/minicluster-data/ts-0-root/wals/41cc8eda859d48b89eaec402e9d76753/wal-000000017 (ops 81-85)
I20260812 06:19:09.493834 28098 log.cc:1079] T 41cc8eda859d48b89eaec402e9d76753 P a90d5b3f20c74b4b8e452e41c378fc23: Deleting log segment in path: /tmp/dist-test-taskt6ZbCi/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515545497762-27980-0/minicluster-data/ts-0-root/wals/41cc8eda859d48b89eaec402e9d76753/wal-000000018 (ops 86-90)
I20260812 06:19:09.493880 28098 log.cc:1079] T 41cc8eda859d48b89eaec402e9d76753 P a90d5b3f20c74b4b8e452e41c378fc23: Deleting log segment in path: /tmp/dist-test-taskt6ZbCi/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515545497762-27980-0/minicluster-data/ts-0-root/wals/41cc8eda859d48b89eaec402e9d76753/wal-000000019 (ops 91-95)
I20260812 06:19:09.493924 28098 log.cc:1079] T 41cc8eda859d48b89eaec402e9d76753 P a90d5b3f20c74b4b8e452e41c378fc23: Deleting log segment in path: /tmp/dist-test-taskt6ZbCi/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515545497762-27980-0/minicluster-data/ts-0-root/wals/41cc8eda859d48b89eaec402e9d76753/wal-000000020 (ops 96-100)
I20260812 06:19:09.493970 28098 log.cc:1079] T 41cc8eda859d48b89eaec402e9d76753 P a90d5b3f20c74b4b8e452e41c378fc23: Deleting log segment in path: /tmp/dist-test-taskt6ZbCi/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515545497762-27980-0/minicluster-data/ts-0-root/wals/41cc8eda859d48b89eaec402e9d76753/wal-000000021 (ops 101-105)
I20260812 06:19:09.494014 28098 log.cc:1079] T 41cc8eda859d48b89eaec402e9d76753 P a90d5b3f20c74b4b8e452e41c378fc23: Deleting log segment in path: /tmp/dist-test-taskt6ZbCi/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515545497762-27980-0/minicluster-data/ts-0-root/wals/41cc8eda859d48b89eaec402e9d76753/wal-000000022 (ops 106-110)
I20260812 06:19:09.494081 28098 log.cc:1079] T 41cc8eda859d48b89eaec402e9d76753 P a90d5b3f20c74b4b8e452e41c378fc23: Deleting log segment in path: /tmp/dist-test-taskt6ZbCi/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515545497762-27980-0/minicluster-data/ts-0-root/wals/41cc8eda859d48b89eaec402e9d76753/wal-000000023 (ops 111-115)
I20260812 06:19:09.494120 28098 log.cc:1079] T 41cc8eda859d48b89eaec402e9d76753 P a90d5b3f20c74b4b8e452e41c378fc23: Deleting log segment in path: /tmp/dist-test-taskt6ZbCi/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515545497762-27980-0/minicluster-data/ts-0-root/wals/41cc8eda859d48b89eaec402e9d76753/wal-000000024 (ops 116-120)
I20260812 06:19:09.494159 28098 log.cc:1079] T 41cc8eda859d48b89eaec402e9d76753 P a90d5b3f20c74b4b8e452e41c378fc23: Deleting log segment in path: /tmp/dist-test-taskt6ZbCi/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515545497762-27980-0/minicluster-data/ts-0-root/wals/41cc8eda859d48b89eaec402e9d76753/wal-000000025 (ops 121-124)
I20260812 06:19:09.494197 28098 log.cc:1079] T 41cc8eda859d48b89eaec402e9d76753 P a90d5b3f20c74b4b8e452e41c378fc23: Deleting log segment in path: /tmp/dist-test-taskt6ZbCi/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515545497762-27980-0/minicluster-data/ts-0-root/wals/41cc8eda859d48b89eaec402e9d76753/wal-000000026 (ops 125-129)
I20260812 06:19:09.531674 28098 maintenance_manager.cc:643] P a90d5b3f20c74b4b8e452e41c378fc23: LogGCOp(41cc8eda859d48b89eaec402e9d76753) complete. Timing: real 0.038s	user 0.000s	sys 0.037s Metrics: {}
I20260812 06:19:09.532229 28166 maintenance_manager.cc:419] P a90d5b3f20c74b4b8e452e41c378fc23: Scheduling FlushDeltaMemStoresOp(41cc8eda859d48b89eaec402e9d76753): perf score=15.087375
I20260812 06:19:09.584789 28098 maintenance_manager.cc:643] P a90d5b3f20c74b4b8e452e41c378fc23: FlushDeltaMemStoresOp(41cc8eda859d48b89eaec402e9d76753) complete. Timing: real 0.052s	user 0.027s	sys 0.022s Metrics: {"bytes_written":16820142,"delete_count":0,"lbm_write_time_us":22885,"lbm_writes_lt_1ms":413,"reinsert_count":0,"update_count":2050}
I20260812 06:19:09.585419 28166 maintenance_manager.cc:419] P a90d5b3f20c74b4b8e452e41c378fc23: Scheduling FlushDeltaMemStoresOp(41cc8eda859d48b89eaec402e9d76753): perf score=2.188937
I20260812 06:19:09.604967 28098 maintenance_manager.cc:643] P a90d5b3f20c74b4b8e452e41c378fc23: FlushDeltaMemStoresOp(41cc8eda859d48b89eaec402e9d76753) complete. Timing: real 0.019s	user 0.005s	sys 0.012s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4478,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:09.605604 28166 maintenance_manager.cc:419] P a90d5b3f20c74b4b8e452e41c378fc23: Scheduling FlushDeltaMemStoresOp(41cc8eda859d48b89eaec402e9d76753): perf score=2.188937
I20260812 06:19:09.616549 28098 maintenance_manager.cc:643] P a90d5b3f20c74b4b8e452e41c378fc23: FlushDeltaMemStoresOp(41cc8eda859d48b89eaec402e9d76753) complete. Timing: real 0.011s	user 0.005s	sys 0.004s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":4159,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:19:09.617108 28166 maintenance_manager.cc:419] P a90d5b3f20c74b4b8e452e41c378fc23: Scheduling MajorDeltaCompactionOp(41cc8eda859d48b89eaec402e9d76753): perf score=1.000000
I20260812 06:19:09.837517 28098 maintenance_manager.cc:643] P a90d5b3f20c74b4b8e452e41c378fc23: MajorDeltaCompactionOp(41cc8eda859d48b89eaec402e9d76753) complete. Timing: real 0.220s	user 0.160s	sys 0.060s Metrics: {"cfile_cache_miss":633,"cfile_cache_miss_bytes":28836241,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":728,"lbm_read_time_us":16381,"lbm_reads_lt_1ms":673,"lbm_write_time_us":39939,"lbm_writes_lt_1ms":643,"mutex_wait_us":44,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":8704,"update_count":3000}
I20260812 06:19:09.838372 28166 maintenance_manager.cc:419] P a90d5b3f20c74b4b8e452e41c378fc23: Scheduling FlushDeltaMemStoresOp(41cc8eda859d48b89eaec402e9d76753): perf score=11.118625
I20260812 06:19:09.880975 28098 maintenance_manager.cc:643] P a90d5b3f20c74b4b8e452e41c378fc23: FlushDeltaMemStoresOp(41cc8eda859d48b89eaec402e9d76753) complete. Timing: real 0.042s	user 0.021s	sys 0.019s Metrics: {"bytes_written":12717736,"delete_count":0,"lbm_write_time_us":18275,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:19:09.881675 28166 maintenance_manager.cc:419] P a90d5b3f20c74b4b8e452e41c378fc23: Scheduling FlushDeltaMemStoresOp(41cc8eda859d48b89eaec402e9d76753): perf score=2.188937
I20260812 06:19:09.910733 28098 maintenance_manager.cc:643] P a90d5b3f20c74b4b8e452e41c378fc23: FlushDeltaMemStoresOp(41cc8eda859d48b89eaec402e9d76753) complete. Timing: real 0.029s	user 0.002s	sys 0.023s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":6890,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:19:09.911434 28166 maintenance_manager.cc:419] P a90d5b3f20c74b4b8e452e41c378fc23: Scheduling MajorDeltaCompactionOp(41cc8eda859d48b89eaec402e9d76753): perf score=1.000000
I20260812 06:19:10.083622 28098 maintenance_manager.cc:643] P a90d5b3f20c74b4b8e452e41c378fc23: MajorDeltaCompactionOp(41cc8eda859d48b89eaec402e9d76753) complete. Timing: real 0.172s	user 0.125s	sys 0.037s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20631304,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":1261,"lbm_read_time_us":11557,"lbm_reads_lt_1ms":464,"lbm_write_time_us":26665,"lbm_writes_lt_1ms":443,"mutex_wait_us":592,"peak_mem_usage":50689328,"reinsert_count":0,"update_count":2000}
I20260812 06:19:10.084456 28166 maintenance_manager.cc:419] P a90d5b3f20c74b4b8e452e41c378fc23: Scheduling FlushDeltaMemStoresOp(41cc8eda859d48b89eaec402e9d76753): perf score=14.095187
I20260812 06:19:10.163192 28098 maintenance_manager.cc:643] P a90d5b3f20c74b4b8e452e41c378fc23: FlushDeltaMemStoresOp(41cc8eda859d48b89eaec402e9d76753) complete. Timing: real 0.078s	user 0.014s	sys 0.033s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":22369,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:10.163816 28166 maintenance_manager.cc:419] P a90d5b3f20c74b4b8e452e41c378fc23: Scheduling FlushDeltaMemStoresOp(41cc8eda859d48b89eaec402e9d76753): perf score=2.188937
I20260812 06:19:10.190285 28098 maintenance_manager.cc:643] P a90d5b3f20c74b4b8e452e41c378fc23: FlushDeltaMemStoresOp(41cc8eda859d48b89eaec402e9d76753) complete. Timing: real 0.026s	user 0.010s	sys 0.004s Metrics: {"bytes_written":4102660,"delete_count":0,"lbm_write_time_us":6019,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:10.190949 28166 maintenance_manager.cc:419] P a90d5b3f20c74b4b8e452e41c378fc23: Scheduling FlushDeltaMemStoresOp(41cc8eda859d48b89eaec402e9d76753): perf score=2.188937
I20260812 06:19:10.208249 28098 maintenance_manager.cc:643] P a90d5b3f20c74b4b8e452e41c378fc23: FlushDeltaMemStoresOp(41cc8eda859d48b89eaec402e9d76753) complete. Timing: real 0.017s	user 0.013s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6656,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:10.208983 28166 maintenance_manager.cc:419] P a90d5b3f20c74b4b8e452e41c378fc23: Scheduling MajorDeltaCompactionOp(41cc8eda859d48b89eaec402e9d76753): perf score=1.000000
I20260812 06:19:10.409161 28098 maintenance_manager.cc:643] P a90d5b3f20c74b4b8e452e41c378fc23: MajorDeltaCompactionOp(41cc8eda859d48b89eaec402e9d76753) complete. Timing: real 0.200s	user 0.139s	sys 0.047s Metrics: {"cfile_cache_miss":633,"cfile_cache_miss_bytes":28836256,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":772,"lbm_read_time_us":12518,"lbm_reads_lt_1ms":673,"lbm_write_time_us":38640,"lbm_writes_lt_1ms":643,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":4864,"update_count":3000}
I20260812 06:19:10.414018 28166 maintenance_manager.cc:419] P a90d5b3f20c74b4b8e452e41c378fc23: Scheduling FlushDeltaMemStoresOp(41cc8eda859d48b89eaec402e9d76753): perf score=14.095187
I20260812 06:19:10.469281 28098 maintenance_manager.cc:643] P a90d5b3f20c74b4b8e452e41c378fc23: FlushDeltaMemStoresOp(41cc8eda859d48b89eaec402e9d76753) complete. Timing: real 0.055s	user 0.037s	sys 0.015s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":23277,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:10.469900 28166 maintenance_manager.cc:419] P a90d5b3f20c74b4b8e452e41c378fc23: Scheduling FlushDeltaMemStoresOp(41cc8eda859d48b89eaec402e9d76753): perf score=2.188937
I20260812 06:19:10.481712 28098 maintenance_manager.cc:643] P a90d5b3f20c74b4b8e452e41c378fc23: FlushDeltaMemStoresOp(41cc8eda859d48b89eaec402e9d76753) complete. Timing: real 0.012s	user 0.009s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4083,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:10.482467 28166 maintenance_manager.cc:419] P a90d5b3f20c74b4b8e452e41c378fc23: Scheduling MajorDeltaCompactionOp(41cc8eda859d48b89eaec402e9d76753): perf score=1.000000
I20260812 06:19:10.668565 28098 maintenance_manager.cc:643] P a90d5b3f20c74b4b8e452e41c378fc23: MajorDeltaCompactionOp(41cc8eda859d48b89eaec402e9d76753) complete. Timing: real 0.186s	user 0.134s	sys 0.042s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24733723,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":453,"lbm_read_time_us":10334,"lbm_reads_lt_1ms":572,"lbm_write_time_us":32261,"lbm_writes_lt_1ms":543,"peak_mem_usage":63115900,"reinsert_count":0,"update_count":2500}
I20260812 06:19:10.669195 28166 maintenance_manager.cc:419] P a90d5b3f20c74b4b8e452e41c378fc23: Scheduling FlushDeltaMemStoresOp(41cc8eda859d48b89eaec402e9d76753): perf score=11.118625
I20260812 06:19:10.712385 28098 maintenance_manager.cc:643] P a90d5b3f20c74b4b8e452e41c378fc23: FlushDeltaMemStoresOp(41cc8eda859d48b89eaec402e9d76753) complete. Timing: real 0.043s	user 0.023s	sys 0.019s Metrics: {"bytes_written":12717736,"delete_count":0,"lbm_write_time_us":18465,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:19:10.715010 28166 maintenance_manager.cc:419] P a90d5b3f20c74b4b8e452e41c378fc23: Scheduling FlushDeltaMemStoresOp(41cc8eda859d48b89eaec402e9d76753): perf score=2.188937
I20260812 06:19:10.731524 28098 maintenance_manager.cc:643] P a90d5b3f20c74b4b8e452e41c378fc23: FlushDeltaMemStoresOp(41cc8eda859d48b89eaec402e9d76753) complete. Timing: real 0.016s	user 0.015s	sys 0.000s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":5235,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:19:10.732316 28166 maintenance_manager.cc:419] P a90d5b3f20c74b4b8e452e41c378fc23: Scheduling MajorDeltaCompactionOp(41cc8eda859d48b89eaec402e9d76753): perf score=1.000000
I20260812 06:19:10.876675 28098 maintenance_manager.cc:643] P a90d5b3f20c74b4b8e452e41c378fc23: MajorDeltaCompactionOp(41cc8eda859d48b89eaec402e9d76753) complete. Timing: real 0.144s	user 0.109s	sys 0.035s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20631304,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":500,"lbm_read_time_us":9007,"lbm_reads_lt_1ms":464,"lbm_write_time_us":29098,"lbm_writes_lt_1ms":443,"mutex_wait_us":100,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":13696,"update_count":2000}
I20260812 06:19:10.877348 28166 maintenance_manager.cc:419] P a90d5b3f20c74b4b8e452e41c378fc23: Scheduling FlushDeltaMemStoresOp(41cc8eda859d48b89eaec402e9d76753): perf score=10.126437
I20260812 06:19:10.930878 28098 maintenance_manager.cc:643] P a90d5b3f20c74b4b8e452e41c378fc23: FlushDeltaMemStoresOp(41cc8eda859d48b89eaec402e9d76753) complete. Timing: real 0.053s	user 0.020s	sys 0.020s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":18563,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:19:10.931612 28166 maintenance_manager.cc:419] P a90d5b3f20c74b4b8e452e41c378fc23: Scheduling FlushDeltaMemStoresOp(41cc8eda859d48b89eaec402e9d76753): perf score=2.188937
I20260812 06:19:10.944860 28098 maintenance_manager.cc:643] P a90d5b3f20c74b4b8e452e41c378fc23: FlushDeltaMemStoresOp(41cc8eda859d48b89eaec402e9d76753) complete. Timing: real 0.013s	user 0.005s	sys 0.007s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4331,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:10.945758 28166 maintenance_manager.cc:419] P a90d5b3f20c74b4b8e452e41c378fc23: Scheduling FlushMRSOp(41cc8eda859d48b89eaec402e9d76753): perf score=1.000000
I20260812 06:19:10.983299 28098 maintenance_manager.cc:643] P a90d5b3f20c74b4b8e452e41c378fc23: FlushMRSOp(41cc8eda859d48b89eaec402e9d76753) complete. Timing: real 0.037s	user 0.031s	sys 0.004s Metrics: {"bytes_written":1193505,"cfile_init":1,"dirs.queue_time_us":110,"dirs.run_cpu_time_us":319,"dirs.run_wall_time_us":2443,"drs_written":1,"lbm_read_time_us":46,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1865,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":29}
I20260812 06:19:10.984422 28166 maintenance_manager.cc:419] P a90d5b3f20c74b4b8e452e41c378fc23: Scheduling LogGCOp(41cc8eda859d48b89eaec402e9d76753): free 120553638 bytes of WAL
I20260812 06:19:10.984925 28098 log_reader.cc:385] T 41cc8eda859d48b89eaec402e9d76753: removed 12 log segments from log reader
I20260812 06:19:10.985020 28098 log.cc:1079] T 41cc8eda859d48b89eaec402e9d76753 P a90d5b3f20c74b4b8e452e41c378fc23: Deleting log segment in path: /tmp/dist-test-taskt6ZbCi/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515545497762-27980-0/minicluster-data/ts-0-root/wals/41cc8eda859d48b89eaec402e9d76753/wal-000000027 (ops 130-134)
I20260812 06:19:10.985090 28098 log.cc:1079] T 41cc8eda859d48b89eaec402e9d76753 P a90d5b3f20c74b4b8e452e41c378fc23: Deleting log segment in path: /tmp/dist-test-taskt6ZbCi/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515545497762-27980-0/minicluster-data/ts-0-root/wals/41cc8eda859d48b89eaec402e9d76753/wal-000000028 (ops 135-138)
I20260812 06:19:10.985200 28098 log.cc:1079] T 41cc8eda859d48b89eaec402e9d76753 P a90d5b3f20c74b4b8e452e41c378fc23: Deleting log segment in path: /tmp/dist-test-taskt6ZbCi/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515545497762-27980-0/minicluster-data/ts-0-root/wals/41cc8eda859d48b89eaec402e9d76753/wal-000000029 (ops 139-143)
I20260812 06:19:10.985248 28098 log.cc:1079] T 41cc8eda859d48b89eaec402e9d76753 P a90d5b3f20c74b4b8e452e41c378fc23: Deleting log segment in path: /tmp/dist-test-taskt6ZbCi/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515545497762-27980-0/minicluster-data/ts-0-root/wals/41cc8eda859d48b89eaec402e9d76753/wal-000000030 (ops 144-148)
I20260812 06:19:10.985291 28098 log.cc:1079] T 41cc8eda859d48b89eaec402e9d76753 P a90d5b3f20c74b4b8e452e41c378fc23: Deleting log segment in path: /tmp/dist-test-taskt6ZbCi/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515545497762-27980-0/minicluster-data/ts-0-root/wals/41cc8eda859d48b89eaec402e9d76753/wal-000000031 (ops 149-152)
I20260812 06:19:10.985329 28098 log.cc:1079] T 41cc8eda859d48b89eaec402e9d76753 P a90d5b3f20c74b4b8e452e41c378fc23: Deleting log segment in path: /tmp/dist-test-taskt6ZbCi/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515545497762-27980-0/minicluster-data/ts-0-root/wals/41cc8eda859d48b89eaec402e9d76753/wal-000000032 (ops 153-157)
I20260812 06:19:10.985369 28098 log.cc:1079] T 41cc8eda859d48b89eaec402e9d76753 P a90d5b3f20c74b4b8e452e41c378fc23: Deleting log segment in path: /tmp/dist-test-taskt6ZbCi/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515545497762-27980-0/minicluster-data/ts-0-root/wals/41cc8eda859d48b89eaec402e9d76753/wal-000000033 (ops 158-162)
I20260812 06:19:10.985409 28098 log.cc:1079] T 41cc8eda859d48b89eaec402e9d76753 P a90d5b3f20c74b4b8e452e41c378fc23: Deleting log segment in path: /tmp/dist-test-taskt6ZbCi/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515545497762-27980-0/minicluster-data/ts-0-root/wals/41cc8eda859d48b89eaec402e9d76753/wal-000000034 (ops 163-167)
I20260812 06:19:10.985448 28098 log.cc:1079] T 41cc8eda859d48b89eaec402e9d76753 P a90d5b3f20c74b4b8e452e41c378fc23: Deleting log segment in path: /tmp/dist-test-taskt6ZbCi/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515545497762-27980-0/minicluster-data/ts-0-root/wals/41cc8eda859d48b89eaec402e9d76753/wal-000000035 (ops 168-172)
I20260812 06:19:10.985487 28098 log.cc:1079] T 41cc8eda859d48b89eaec402e9d76753 P a90d5b3f20c74b4b8e452e41c378fc23: Deleting log segment in path: /tmp/dist-test-taskt6ZbCi/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515545497762-27980-0/minicluster-data/ts-0-root/wals/41cc8eda859d48b89eaec402e9d76753/wal-000000036 (ops 173-177)
I20260812 06:19:10.985526 28098 log.cc:1079] T 41cc8eda859d48b89eaec402e9d76753 P a90d5b3f20c74b4b8e452e41c378fc23: Deleting log segment in path: /tmp/dist-test-taskt6ZbCi/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515545497762-27980-0/minicluster-data/ts-0-root/wals/41cc8eda859d48b89eaec402e9d76753/wal-000000037 (ops 178-182)
I20260812 06:19:10.985565 28098 log.cc:1079] T 41cc8eda859d48b89eaec402e9d76753 P a90d5b3f20c74b4b8e452e41c378fc23: Deleting log segment in path: /tmp/dist-test-taskt6ZbCi/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515545497762-27980-0/minicluster-data/ts-0-root/wals/41cc8eda859d48b89eaec402e9d76753/wal-000000038 (ops 183-187)
I20260812 06:19:11.015439 28098 maintenance_manager.cc:643] P a90d5b3f20c74b4b8e452e41c378fc23: LogGCOp(41cc8eda859d48b89eaec402e9d76753) complete. Timing: real 0.031s	user 0.000s	sys 0.031s Metrics: {}
I20260812 06:19:11.015949 28166 maintenance_manager.cc:419] P a90d5b3f20c74b4b8e452e41c378fc23: Scheduling FlushDeltaMemStoresOp(41cc8eda859d48b89eaec402e9d76753): perf score=6.157687
I20260812 06:19:11.047329 28098 maintenance_manager.cc:643] P a90d5b3f20c74b4b8e452e41c378fc23: FlushDeltaMemStoresOp(41cc8eda859d48b89eaec402e9d76753) complete. Timing: real 0.031s	user 0.018s	sys 0.005s Metrics: {"bytes_written":8205078,"delete_count":0,"lbm_write_time_us":10890,"lbm_writes_lt_1ms":203,"reinsert_count":0,"update_count":1000}
I20260812 06:19:11.048076 28166 maintenance_manager.cc:419] P a90d5b3f20c74b4b8e452e41c378fc23: Scheduling MajorDeltaCompactionOp(41cc8eda859d48b89eaec402e9d76753): perf score=1.000000
I20260812 06:19:11.236475 28098 maintenance_manager.cc:643] P a90d5b3f20c74b4b8e452e41c378fc23: MajorDeltaCompactionOp(41cc8eda859d48b89eaec402e9d76753) complete. Timing: real 0.188s	user 0.139s	sys 0.049s Metrics: {"cfile_cache_miss":633,"cfile_cache_miss_bytes":28836256,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":849,"lbm_read_time_us":14203,"lbm_reads_lt_1ms":665,"lbm_write_time_us":38235,"lbm_writes_lt_1ms":643,"mutex_wait_us":77,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":2176,"thread_start_us":88,"threads_started":1,"update_count":3000}
I20260812 06:19:11.238516 28166 maintenance_manager.cc:419] P a90d5b3f20c74b4b8e452e41c378fc23: Scheduling UndoDeltaBlockGCOp(41cc8eda859d48b89eaec402e9d76753): 461 bytes on disk
I20260812 06:19:11.239154 28098 maintenance_manager.cc:643] P a90d5b3f20c74b4b8e452e41c378fc23: UndoDeltaBlockGCOp(41cc8eda859d48b89eaec402e9d76753) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":98,"lbm_reads_lt_1ms":4}
I20260812 06:19:11.239952 28166 maintenance_manager.cc:419] P a90d5b3f20c74b4b8e452e41c378fc23: Scheduling FlushDeltaMemStoresOp(41cc8eda859d48b89eaec402e9d76753): perf score=14.095187
I20260812 06:19:11.295897 28098 maintenance_manager.cc:643] P a90d5b3f20c74b4b8e452e41c378fc23: FlushDeltaMemStoresOp(41cc8eda859d48b89eaec402e9d76753) complete. Timing: real 0.056s	user 0.040s	sys 0.015s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":25246,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:11.296651 28166 maintenance_manager.cc:419] P a90d5b3f20c74b4b8e452e41c378fc23: Scheduling FlushDeltaMemStoresOp(41cc8eda859d48b89eaec402e9d76753): perf score=2.188937
I20260812 06:19:11.310252 28098 maintenance_manager.cc:643] P a90d5b3f20c74b4b8e452e41c378fc23: FlushDeltaMemStoresOp(41cc8eda859d48b89eaec402e9d76753) complete. Timing: real 0.013s	user 0.007s	sys 0.004s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4786,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:11.310962 28166 maintenance_manager.cc:419] P a90d5b3f20c74b4b8e452e41c378fc23: Scheduling MajorDeltaCompactionOp(41cc8eda859d48b89eaec402e9d76753): perf score=1.000000
I20260812 06:19:11.342021 27980 heavy-update-compaction-itest.cc:229] Time spent updating: real 5.492s	user 1.981s	sys 0.167s
I20260812 06:19:11.402288 27980 heavy-update-compaction-itest.cc:265] Time spent scanning: real 0.059s	user 0.003s	sys 0.000s
I20260812 06:19:11.403110 27980 tablet_server.cc:179] TabletServer@127.27.83.1:0 shutting down...
I20260812 06:19:11.451133 28098 maintenance_manager.cc:643] P a90d5b3f20c74b4b8e452e41c378fc23: MajorDeltaCompactionOp(41cc8eda859d48b89eaec402e9d76753) complete. Timing: real 0.140s	user 0.090s	sys 0.047s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24733723,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":420,"lbm_read_time_us":12333,"lbm_reads_lt_1ms":568,"lbm_write_time_us":28012,"lbm_writes_lt_1ms":543,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":2048,"update_count":2500}
I20260812 06:19:11.452069 27980 ts_tablet_manager.cc:1507] Shutting down tablet manager...
I20260812 06:19:11.452536 27980 tablet_replica.cc:333] T 41cc8eda859d48b89eaec402e9d76753 P a90d5b3f20c74b4b8e452e41c378fc23: stopping tablet replica
I20260812 06:19:11.452873 27980 raft_consensus.cc:2243] T 41cc8eda859d48b89eaec402e9d76753 P a90d5b3f20c74b4b8e452e41c378fc23 [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:19:11.453171 27980 raft_consensus.cc:2272] T 41cc8eda859d48b89eaec402e9d76753 P a90d5b3f20c74b4b8e452e41c378fc23 [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:19:11.483342 27980 tablet_server.cc:196] TabletServer@127.27.83.1:0 shutdown complete.
I20260812 06:19:11.502859 27980 master.cc:562] Master@127.27.83.62:45541 shutting down...
I20260812 06:19:11.507046 27980 raft_consensus.cc:2243] T 00000000000000000000000000000000 P 5d295e22520c413c87a3e5fca01ed39d [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:19:11.507292 27980 raft_consensus.cc:2272] T 00000000000000000000000000000000 P 5d295e22520c413c87a3e5fca01ed39d [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:19:11.507411 27980 tablet_replica.cc:333] T 00000000000000000000000000000000 P 5d295e22520c413c87a3e5fca01ed39d: stopping tablet replica
I20260812 06:19:11.520521 27980 master.cc:584] Master@127.27.83.62:45541 shutdown complete.
[       OK ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/0 (6107 ms)
[ RUN      ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/1
I20260812 06:19:11.616619 27980 internal_mini_cluster.cc:156] Creating distributed mini masters. Addrs: 127.27.83.62:38021
I20260812 06:19:11.617080 27980 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:19:11.620357 28198 instance_detector.cc:116] could not retrieve AWS instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:19:11.620494 28202 instance_detector.cc:116] could not retrieve OpenStack instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:19:11.620558 28199 instance_detector.cc:116] could not retrieve Azure instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:19:11.620409 27980 server_base.cc:1061] running on GCE node
I20260812 06:19:11.620910 27980 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:19:11.620966 27980 system_unsync_time.cc:38] NTP support is disabled. Clock error bounds will not be accurate. This configuration is not suitable for distributed clusters.
I20260812 06:19:11.620983 27980 hybrid_clock.cc:648] HybridClock initialized: now 1786515551620983 us; error 0 us; skew 500 ppm
I20260812 06:19:11.621987 27980 webserver.cc:533] Webserver started at http://127.27.83.62:41801/ using document root <none> and password file <none>
I20260812 06:19:11.622148 27980 fs_manager.cc:362] Metadata directory not provided
I20260812 06:19:11.622207 27980 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:19:11.622267 27980 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:19:11.622696 27980 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskt6ZbCi/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515545497762-27980-0/minicluster-data/master-0-root/instance:
uuid: "4c79b00d8fac48128ebab29da922cecf"
format_stamp: "Formatted at 2026-08-12 06:19:11 on dist-test-slave-btw8"
I20260812 06:19:11.624737 27980 fs_manager.cc:696] Time spent creating directory manager: real 0.002s	user 0.002s	sys 0.000s
I20260812 06:19:11.626080 28208 log_block_manager.cc:4127] Time spent loading block containers with low live blocks: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:19:11.626466 27980 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.001s	sys 0.000s
I20260812 06:19:11.626612 27980 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskt6ZbCi/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515545497762-27980-0/minicluster-data/master-0-root
uuid: "4c79b00d8fac48128ebab29da922cecf"
format_stamp: "Formatted at 2026-08-12 06:19:11 on dist-test-slave-btw8"
I20260812 06:19:11.626715 27980 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskt6ZbCi/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515545497762-27980-0/minicluster-data/master-0-root
metadata directory: /tmp/dist-test-taskt6ZbCi/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515545497762-27980-0/minicluster-data/master-0-root
1 data directories: /tmp/dist-test-taskt6ZbCi/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515545497762-27980-0/minicluster-data/master-0-root/data
Total live blocks: 0
Total live bytes: 0
Total live bytes (after alignment): 0
Total number of LBM containers: 0 (0 full)
Did not check for missing blocks
Did not check for orphaned blocks
Total full LBM containers with extra space: 0 (0 repaired)
Total full LBM container extra space in bytes: 0 (0 repaired)
Total incomplete LBM containers: 0 (0 repaired)
Total LBM partial records: 0 (0 repaired)
Total corrupted LBM metadata records in RocksDB: 0 (0 repaired)
I20260812 06:19:11.636799 27980 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:19:11.637257 27980 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:19:11.644018 27980 rpc_server.cc:307] RPC server started. Bound to: 127.27.83.62:38021
I20260812 06:19:11.646847 28273 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet 00000000000000000000000000000000. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:19:11.649991 28272 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.27.83.62:38021 every 8 connection(s)
I20260812 06:19:11.653975 28273 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P 4c79b00d8fac48128ebab29da922cecf: Bootstrap starting.
I20260812 06:19:11.654909 28273 tablet_bootstrap.cc:654] T 00000000000000000000000000000000 P 4c79b00d8fac48128ebab29da922cecf: Neither blocks nor log segments found. Creating new log.
I20260812 06:19:11.656193 28273 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P 4c79b00d8fac48128ebab29da922cecf: No bootstrap required, opened a new log
I20260812 06:19:11.656662 28273 raft_consensus.cc:359] T 00000000000000000000000000000000 P 4c79b00d8fac48128ebab29da922cecf [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "4c79b00d8fac48128ebab29da922cecf" member_type: VOTER }
I20260812 06:19:11.656764 28273 raft_consensus.cc:385] T 00000000000000000000000000000000 P 4c79b00d8fac48128ebab29da922cecf [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:19:11.656826 28273 raft_consensus.cc:740] T 00000000000000000000000000000000 P 4c79b00d8fac48128ebab29da922cecf [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: 4c79b00d8fac48128ebab29da922cecf, State: Initialized, Role: FOLLOWER
I20260812 06:19:11.656991 28273 consensus_queue.cc:260] T 00000000000000000000000000000000 P 4c79b00d8fac48128ebab29da922cecf [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: "4c79b00d8fac48128ebab29da922cecf" member_type: VOTER }
I20260812 06:19:11.657064 28273 raft_consensus.cc:399] T 00000000000000000000000000000000 P 4c79b00d8fac48128ebab29da922cecf [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:19:11.657153 28273 raft_consensus.cc:493] T 00000000000000000000000000000000 P 4c79b00d8fac48128ebab29da922cecf [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:19:11.657243 28273 raft_consensus.cc:3060] T 00000000000000000000000000000000 P 4c79b00d8fac48128ebab29da922cecf [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:19:11.658018 28273 raft_consensus.cc:515] T 00000000000000000000000000000000 P 4c79b00d8fac48128ebab29da922cecf [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "4c79b00d8fac48128ebab29da922cecf" member_type: VOTER }
I20260812 06:19:11.658157 28273 leader_election.cc:304] T 00000000000000000000000000000000 P 4c79b00d8fac48128ebab29da922cecf [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: 4c79b00d8fac48128ebab29da922cecf; no voters: 
I20260812 06:19:11.658473 28273 leader_election.cc:290] T 00000000000000000000000000000000 P 4c79b00d8fac48128ebab29da922cecf [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:19:11.658576 28276 raft_consensus.cc:2804] T 00000000000000000000000000000000 P 4c79b00d8fac48128ebab29da922cecf [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:19:11.658752 28276 raft_consensus.cc:697] T 00000000000000000000000000000000 P 4c79b00d8fac48128ebab29da922cecf [term 1 LEADER]: Becoming Leader. State: Replica: 4c79b00d8fac48128ebab29da922cecf, State: Running, Role: LEADER
I20260812 06:19:11.658942 28276 consensus_queue.cc:237] T 00000000000000000000000000000000 P 4c79b00d8fac48128ebab29da922cecf [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: "4c79b00d8fac48128ebab29da922cecf" member_type: VOTER }
I20260812 06:19:11.659071 28273 sys_catalog.cc:565] T 00000000000000000000000000000000 P 4c79b00d8fac48128ebab29da922cecf [sys.catalog]: configured and running, proceeding with master startup.
I20260812 06:19:11.659453 28278 sys_catalog.cc:455] T 00000000000000000000000000000000 P 4c79b00d8fac48128ebab29da922cecf [sys.catalog]: SysCatalogTable state changed. Reason: RaftConsensus started. Latest consensus state: current_term: 1 leader_uuid: "4c79b00d8fac48128ebab29da922cecf" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "4c79b00d8fac48128ebab29da922cecf" member_type: VOTER } }
I20260812 06:19:11.659482 28279 sys_catalog.cc:455] T 00000000000000000000000000000000 P 4c79b00d8fac48128ebab29da922cecf [sys.catalog]: SysCatalogTable state changed. Reason: New leader 4c79b00d8fac48128ebab29da922cecf. Latest consensus state: current_term: 1 leader_uuid: "4c79b00d8fac48128ebab29da922cecf" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "4c79b00d8fac48128ebab29da922cecf" member_type: VOTER } }
I20260812 06:19:11.659616 28279 sys_catalog.cc:458] T 00000000000000000000000000000000 P 4c79b00d8fac48128ebab29da922cecf [sys.catalog]: This master's current role is: LEADER
I20260812 06:19:11.659866 28278 sys_catalog.cc:458] T 00000000000000000000000000000000 P 4c79b00d8fac48128ebab29da922cecf [sys.catalog]: This master's current role is: LEADER
I20260812 06:19:11.659952 28281 catalog_manager.cc:1511] Loading table and tablet metadata into memory...
I20260812 06:19:11.661093 28281 catalog_manager.cc:1520] Initializing Kudu cluster ID...
I20260812 06:19:11.661433 27980 internal_mini_cluster.cc:184] Waiting to initialize catalog manager on master 0
I20260812 06:19:11.663232 28281 catalog_manager.cc:1383] Generated new cluster ID: bde3eb6d7f65433baa6e0cdaadee0f9f
I20260812 06:19:11.663304 28281 catalog_manager.cc:1531] Initializing Kudu internal certificate authority...
I20260812 06:19:11.673206 28281 catalog_manager.cc:1406] Generated new certificate authority record
I20260812 06:19:11.673890 28281 catalog_manager.cc:1540] Loading token signing keys...
I20260812 06:19:11.683282 28281 catalog_manager.cc:6092] T 00000000000000000000000000000000 P 4c79b00d8fac48128ebab29da922cecf: Generated new TSK 0
I20260812 06:19:11.683564 28281 catalog_manager.cc:1550] Initializing in-progress tserver states...
I20260812 06:19:11.694298 27980 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:19:11.697009 28296 instance_detector.cc:116] could not retrieve AWS instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:19:11.697116 27980 server_base.cc:1061] running on GCE node
W20260812 06:19:11.697165 28300 instance_detector.cc:116] could not retrieve OpenStack instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:19:11.697324 28297 instance_detector.cc:116] could not retrieve Azure instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:19:11.697589 27980 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:19:11.697688 27980 system_unsync_time.cc:38] NTP support is disabled. Clock error bounds will not be accurate. This configuration is not suitable for distributed clusters.
I20260812 06:19:11.697710 27980 hybrid_clock.cc:648] HybridClock initialized: now 1786515551697709 us; error 0 us; skew 500 ppm
I20260812 06:19:11.698779 27980 webserver.cc:533] Webserver started at http://127.27.83.1:37349/ using document root <none> and password file <none>
I20260812 06:19:11.698956 27980 fs_manager.cc:362] Metadata directory not provided
I20260812 06:19:11.699062 27980 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:19:11.699141 27980 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:19:11.699692 27980 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskt6ZbCi/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515545497762-27980-0/minicluster-data/ts-0-root/instance:
uuid: "80b575eff86f46a3a279c4225d87e54b"
format_stamp: "Formatted at 2026-08-12 06:19:11 on dist-test-slave-btw8"
I20260812 06:19:11.701534 27980 fs_manager.cc:696] Time spent creating directory manager: real 0.002s	user 0.002s	sys 0.000s
I20260812 06:19:11.702677 28305 log_block_manager.cc:4127] Time spent loading block containers with low live blocks: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:19:11.703033 27980 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.001s	sys 0.000s
I20260812 06:19:11.703135 27980 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskt6ZbCi/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515545497762-27980-0/minicluster-data/ts-0-root
uuid: "80b575eff86f46a3a279c4225d87e54b"
format_stamp: "Formatted at 2026-08-12 06:19:11 on dist-test-slave-btw8"
I20260812 06:19:11.703279 27980 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskt6ZbCi/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515545497762-27980-0/minicluster-data/ts-0-root
metadata directory: /tmp/dist-test-taskt6ZbCi/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515545497762-27980-0/minicluster-data/ts-0-root
1 data directories: /tmp/dist-test-taskt6ZbCi/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515545497762-27980-0/minicluster-data/ts-0-root/data
Total live blocks: 0
Total live bytes: 0
Total live bytes (after alignment): 0
Total number of LBM containers: 0 (0 full)
Did not check for missing blocks
Did not check for orphaned blocks
Total full LBM containers with extra space: 0 (0 repaired)
Total full LBM container extra space in bytes: 0 (0 repaired)
Total incomplete LBM containers: 0 (0 repaired)
Total LBM partial records: 0 (0 repaired)
Total corrupted LBM metadata records in RocksDB: 0 (0 repaired)
I20260812 06:19:11.735117 27980 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:19:11.735873 27980 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:19:11.736340 27980 txn_system_client.cc:432] TxnSystemClient initialization is disabled...
I20260812 06:19:11.736891 27980 ts_tablet_manager.cc:585] Loaded tablet metadata (0 total tablets, 0 live tablets)
I20260812 06:19:11.736964 27980 ts_tablet_manager.cc:531] Time spent load tablet metadata: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:19:11.737020 27980 ts_tablet_manager.cc:616] Registered 0 tablets
I20260812 06:19:11.737071 27980 ts_tablet_manager.cc:595] Time spent register tablets: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:19:11.742213 27980 rpc_server.cc:307] RPC server started. Bound to: 127.27.83.1:35447
I20260812 06:19:11.743793 28381 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.27.83.1:35447 every 8 connection(s)
I20260812 06:19:11.753216 28382 heartbeater.cc:344] Connected to a master server at 127.27.83.62:38021
I20260812 06:19:11.753369 28382 heartbeater.cc:461] Registering TS with master...
I20260812 06:19:11.753646 28382 heartbeater.cc:507] Master 127.27.83.62:38021 requested a full tablet report, sending...
I20260812 06:19:11.754369 28223 ts_manager.cc:194] Registered new tserver with Master: 80b575eff86f46a3a279c4225d87e54b (127.27.83.1:35447)
I20260812 06:19:11.754961 27980 internal_mini_cluster.cc:371] 1 TS(s) registered with all masters after 0.011211721s
I20260812 06:19:11.755219 28223 master_service.cc:502] Signed X509 certificate for tserver {username='slave'} at 127.0.0.1:57342
I20260812 06:19:11.762789 28223 catalog_manager.cc:2283] Servicing CreateTable request from {username='slave'} at 127.0.0.1:57350:
name: "heavy-update-compaction-test"
schema {
  columns {
    name: "key"
    type: INT64
    is_key: true
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_a"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_b"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_c"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_d"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_e"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
}
num_replicas: 1
split_rows_range_bounds {
}
partition_schema {
  range_schema {
  }
}
I20260812 06:19:11.773108 28337 tablet_service.cc:1511] Processing CreateTablet for tablet 4513b85fee4a477ab7717dfb1c627b42 (DEFAULT_TABLE table=heavy-update-compaction-test [id=1e4df991c13d43c39d8ad501be962b3b]), partition=
I20260812 06:19:11.773415 28337 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet 4513b85fee4a477ab7717dfb1c627b42. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:19:11.775995 28395 tablet_bootstrap.cc:492] T 4513b85fee4a477ab7717dfb1c627b42 P 80b575eff86f46a3a279c4225d87e54b: Bootstrap starting.
I20260812 06:19:11.777122 28395 tablet_bootstrap.cc:654] T 4513b85fee4a477ab7717dfb1c627b42 P 80b575eff86f46a3a279c4225d87e54b: Neither blocks nor log segments found. Creating new log.
I20260812 06:19:11.778465 28395 tablet_bootstrap.cc:492] T 4513b85fee4a477ab7717dfb1c627b42 P 80b575eff86f46a3a279c4225d87e54b: No bootstrap required, opened a new log
I20260812 06:19:11.778599 28395 ts_tablet_manager.cc:1403] T 4513b85fee4a477ab7717dfb1c627b42 P 80b575eff86f46a3a279c4225d87e54b: Time spent bootstrapping tablet: real 0.003s	user 0.002s	sys 0.000s
I20260812 06:19:11.779167 28395 raft_consensus.cc:359] T 4513b85fee4a477ab7717dfb1c627b42 P 80b575eff86f46a3a279c4225d87e54b [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "80b575eff86f46a3a279c4225d87e54b" member_type: VOTER last_known_addr { host: "127.27.83.1" port: 35447 } }
I20260812 06:19:11.779300 28395 raft_consensus.cc:385] T 4513b85fee4a477ab7717dfb1c627b42 P 80b575eff86f46a3a279c4225d87e54b [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:19:11.779390 28395 raft_consensus.cc:740] T 4513b85fee4a477ab7717dfb1c627b42 P 80b575eff86f46a3a279c4225d87e54b [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: 80b575eff86f46a3a279c4225d87e54b, State: Initialized, Role: FOLLOWER
I20260812 06:19:11.779572 28395 consensus_queue.cc:260] T 4513b85fee4a477ab7717dfb1c627b42 P 80b575eff86f46a3a279c4225d87e54b [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: "80b575eff86f46a3a279c4225d87e54b" member_type: VOTER last_known_addr { host: "127.27.83.1" port: 35447 } }
I20260812 06:19:11.779709 28395 raft_consensus.cc:399] T 4513b85fee4a477ab7717dfb1c627b42 P 80b575eff86f46a3a279c4225d87e54b [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:19:11.779757 28395 raft_consensus.cc:493] T 4513b85fee4a477ab7717dfb1c627b42 P 80b575eff86f46a3a279c4225d87e54b [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:19:11.779812 28395 raft_consensus.cc:3060] T 4513b85fee4a477ab7717dfb1c627b42 P 80b575eff86f46a3a279c4225d87e54b [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:19:11.780624 28395 raft_consensus.cc:515] T 4513b85fee4a477ab7717dfb1c627b42 P 80b575eff86f46a3a279c4225d87e54b [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "80b575eff86f46a3a279c4225d87e54b" member_type: VOTER last_known_addr { host: "127.27.83.1" port: 35447 } }
I20260812 06:19:11.780797 28395 leader_election.cc:304] T 4513b85fee4a477ab7717dfb1c627b42 P 80b575eff86f46a3a279c4225d87e54b [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: 80b575eff86f46a3a279c4225d87e54b; no voters: 
I20260812 06:19:11.781046 28395 leader_election.cc:290] T 4513b85fee4a477ab7717dfb1c627b42 P 80b575eff86f46a3a279c4225d87e54b [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:19:11.781272 28397 raft_consensus.cc:2804] T 4513b85fee4a477ab7717dfb1c627b42 P 80b575eff86f46a3a279c4225d87e54b [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:19:11.781397 28395 ts_tablet_manager.cc:1434] T 4513b85fee4a477ab7717dfb1c627b42 P 80b575eff86f46a3a279c4225d87e54b: Time spent starting tablet: real 0.003s	user 0.000s	sys 0.003s
I20260812 06:19:11.781440 28382 heartbeater.cc:499] Master 127.27.83.62:38021 was elected leader, sending a full tablet report...
I20260812 06:19:11.781476 28397 raft_consensus.cc:697] T 4513b85fee4a477ab7717dfb1c627b42 P 80b575eff86f46a3a279c4225d87e54b [term 1 LEADER]: Becoming Leader. State: Replica: 80b575eff86f46a3a279c4225d87e54b, State: Running, Role: LEADER
I20260812 06:19:11.781656 28397 consensus_queue.cc:237] T 4513b85fee4a477ab7717dfb1c627b42 P 80b575eff86f46a3a279c4225d87e54b [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: "80b575eff86f46a3a279c4225d87e54b" member_type: VOTER last_known_addr { host: "127.27.83.1" port: 35447 } }
I20260812 06:19:11.783094 28223 catalog_manager.cc:5719] T 4513b85fee4a477ab7717dfb1c627b42 P 80b575eff86f46a3a279c4225d87e54b reported cstate change: term changed from 0 to 1, leader changed from <none> to 80b575eff86f46a3a279c4225d87e54b (127.27.83.1). New cstate: current_term: 1 leader_uuid: "80b575eff86f46a3a279c4225d87e54b" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "80b575eff86f46a3a279c4225d87e54b" member_type: VOTER last_known_addr { host: "127.27.83.1" port: 35447 } health_report { overall_health: HEALTHY } } }
I20260812 06:19:11.847674 27980 heavy-update-compaction-itest.cc:215] Time spent inserting: real 0.057s	user 0.017s	sys 0.007s
I20260812 06:19:11.994405 28383 maintenance_manager.cc:419] P 80b575eff86f46a3a279c4225d87e54b: Scheduling FlushMRSOp(4513b85fee4a477ab7717dfb1c627b42): perf score=15.086190
I20260812 06:19:12.136884 28311 maintenance_manager.cc:643] P 80b575eff86f46a3a279c4225d87e54b: FlushMRSOp(4513b85fee4a477ab7717dfb1c627b42) complete. Timing: real 0.142s	user 0.101s	sys 0.040s Metrics: {"bytes_written":11897249,"cfile_init":1,"delete_count":0,"dirs.queue_time_us":130,"dirs.run_cpu_time_us":404,"dirs.run_wall_time_us":1273,"drs_written":1,"lbm_read_time_us":74,"lbm_reads_lt_1ms":4,"lbm_write_time_us":38081,"lbm_writes_lt_1ms":657,"peak_mem_usage":0,"reinsert_count":0,"rows_written":104,"update_count":1450}
I20260812 06:19:12.137840 28383 maintenance_manager.cc:419] P 80b575eff86f46a3a279c4225d87e54b: Scheduling UndoDeltaBlockGCOp(4513b85fee4a477ab7717dfb1c627b42): 12719213 bytes on disk
I20260812 06:19:12.138470 28311 maintenance_manager.cc:643] P 80b575eff86f46a3a279c4225d87e54b: UndoDeltaBlockGCOp(4513b85fee4a477ab7717dfb1c627b42) 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:19:12.138970 28383 maintenance_manager.cc:419] P 80b575eff86f46a3a279c4225d87e54b: Scheduling LogGCOp(4513b85fee4a477ab7717dfb1c627b42): free 20743880 bytes of WAL
I20260812 06:19:12.139210 28311 log_reader.cc:385] T 4513b85fee4a477ab7717dfb1c627b42: removed 2 log segments from log reader
I20260812 06:19:12.139293 28311 log.cc:1079] T 4513b85fee4a477ab7717dfb1c627b42 P 80b575eff86f46a3a279c4225d87e54b: Deleting log segment in path: /tmp/dist-test-taskt6ZbCi/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515545497762-27980-0/minicluster-data/ts-0-root/wals/4513b85fee4a477ab7717dfb1c627b42/wal-000000001 (ops 1-6)
I20260812 06:19:12.139420 28311 log.cc:1079] T 4513b85fee4a477ab7717dfb1c627b42 P 80b575eff86f46a3a279c4225d87e54b: Deleting log segment in path: /tmp/dist-test-taskt6ZbCi/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515545497762-27980-0/minicluster-data/ts-0-root/wals/4513b85fee4a477ab7717dfb1c627b42/wal-000000002 (ops 7-11)
I20260812 06:19:12.144309 28311 maintenance_manager.cc:643] P 80b575eff86f46a3a279c4225d87e54b: LogGCOp(4513b85fee4a477ab7717dfb1c627b42) complete. Timing: real 0.005s	user 0.000s	sys 0.004s Metrics: {}
I20260812 06:19:12.144727 28383 maintenance_manager.cc:419] P 80b575eff86f46a3a279c4225d87e54b: Scheduling FlushDeltaMemStoresOp(4513b85fee4a477ab7717dfb1c627b42): perf score=2.188937
I20260812 06:19:12.159498 28311 maintenance_manager.cc:643] P 80b575eff86f46a3a279c4225d87e54b: FlushDeltaMemStoresOp(4513b85fee4a477ab7717dfb1c627b42) complete. Timing: real 0.015s	user 0.014s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5251,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:12.160140 28383 maintenance_manager.cc:419] P 80b575eff86f46a3a279c4225d87e54b: Scheduling MajorDeltaCompactionOp(4513b85fee4a477ab7717dfb1c627b42): perf score=1.000000
I20260812 06:19:12.322781 28311 maintenance_manager.cc:643] P 80b575eff86f46a3a279c4225d87e54b: MajorDeltaCompactionOp(4513b85fee4a477ab7717dfb1c627b42) complete. Timing: real 0.162s	user 0.126s	sys 0.036s Metrics: {"cfile_cache_miss":422,"cfile_cache_miss_bytes":20262036,"cfile_init":7,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":828,"lbm_read_time_us":13782,"lbm_reads_lt_1ms":450,"lbm_write_time_us":27337,"lbm_writes_lt_1ms":433,"peak_mem_usage":49238594,"reinsert_count":0,"spinlock_wait_cycles":9216,"thread_start_us":393,"threads_started":5,"update_count":1950}
I20260812 06:19:12.323822 28383 maintenance_manager.cc:419] P 80b575eff86f46a3a279c4225d87e54b: Scheduling FlushDeltaMemStoresOp(4513b85fee4a477ab7717dfb1c627b42): perf score=10.126437
I20260812 06:19:12.371837 28311 maintenance_manager.cc:643] P 80b575eff86f46a3a279c4225d87e54b: FlushDeltaMemStoresOp(4513b85fee4a477ab7717dfb1c627b42) complete. Timing: real 0.048s	user 0.027s	sys 0.020s Metrics: {"bytes_written":12307493,"delete_count":0,"lbm_write_time_us":20756,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":302,"reinsert_count":0,"update_count":1500}
I20260812 06:19:12.372480 28383 maintenance_manager.cc:419] P 80b575eff86f46a3a279c4225d87e54b: Scheduling FlushDeltaMemStoresOp(4513b85fee4a477ab7717dfb1c627b42): perf score=2.188937
I20260812 06:19:12.395900 28311 maintenance_manager.cc:643] P 80b575eff86f46a3a279c4225d87e54b: FlushDeltaMemStoresOp(4513b85fee4a477ab7717dfb1c627b42) complete. Timing: real 0.023s	user 0.011s	sys 0.011s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5997,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:12.396554 28383 maintenance_manager.cc:419] P 80b575eff86f46a3a279c4225d87e54b: Scheduling MajorDeltaCompactionOp(4513b85fee4a477ab7717dfb1c627b42): perf score=1.000000
I20260812 06:19:12.558843 28311 maintenance_manager.cc:643] P 80b575eff86f46a3a279c4225d87e54b: MajorDeltaCompactionOp(4513b85fee4a477ab7717dfb1c627b42) complete. Timing: real 0.162s	user 0.113s	sys 0.045s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672280,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":700,"lbm_read_time_us":11422,"lbm_reads_lt_1ms":464,"lbm_write_time_us":24607,"lbm_writes_lt_1ms":443,"mutex_wait_us":2,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":3072,"update_count":2000}
I20260812 06:19:12.559569 28383 maintenance_manager.cc:419] P 80b575eff86f46a3a279c4225d87e54b: Scheduling FlushDeltaMemStoresOp(4513b85fee4a477ab7717dfb1c627b42): perf score=11.118625
I20260812 06:19:12.598162 28311 maintenance_manager.cc:643] P 80b575eff86f46a3a279c4225d87e54b: FlushDeltaMemStoresOp(4513b85fee4a477ab7717dfb1c627b42) complete. Timing: real 0.038s	user 0.023s	sys 0.013s Metrics: {"bytes_written":12717735,"delete_count":0,"lbm_write_time_us":16612,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:19:12.599220 28383 maintenance_manager.cc:419] P 80b575eff86f46a3a279c4225d87e54b: Scheduling FlushDeltaMemStoresOp(4513b85fee4a477ab7717dfb1c627b42): perf score=2.188937
I20260812 06:19:12.628459 28311 maintenance_manager.cc:643] P 80b575eff86f46a3a279c4225d87e54b: FlushDeltaMemStoresOp(4513b85fee4a477ab7717dfb1c627b42) complete. Timing: real 0.029s	user 0.005s	sys 0.010s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":5738,"lbm_writes_lt_1ms":93,"reinsert_count":0,"spinlock_wait_cycles":896,"update_count":450}
I20260812 06:19:12.628945 28383 maintenance_manager.cc:419] P 80b575eff86f46a3a279c4225d87e54b: Scheduling FlushDeltaMemStoresOp(4513b85fee4a477ab7717dfb1c627b42): perf score=2.188937
I20260812 06:19:12.639911 28311 maintenance_manager.cc:643] P 80b575eff86f46a3a279c4225d87e54b: FlushDeltaMemStoresOp(4513b85fee4a477ab7717dfb1c627b42) complete. Timing: real 0.011s	user 0.005s	sys 0.005s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4087,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:12.640411 28383 maintenance_manager.cc:419] P 80b575eff86f46a3a279c4225d87e54b: Scheduling MajorDeltaCompactionOp(4513b85fee4a477ab7717dfb1c627b42): perf score=1.000000
I20260812 06:19:12.808282 28311 maintenance_manager.cc:643] P 80b575eff86f46a3a279c4225d87e54b: MajorDeltaCompactionOp(4513b85fee4a477ab7717dfb1c627b42) complete. Timing: real 0.168s	user 0.124s	sys 0.043s Metrics: {"cfile_cache_miss":533,"cfile_cache_miss_bytes":24774798,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":227,"lbm_read_time_us":13632,"lbm_reads_lt_1ms":573,"lbm_write_time_us":33794,"lbm_writes_lt_1ms":543,"mutex_wait_us":47,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":13952,"update_count":2500}
I20260812 06:19:12.809053 28383 maintenance_manager.cc:419] P 80b575eff86f46a3a279c4225d87e54b: Scheduling FlushDeltaMemStoresOp(4513b85fee4a477ab7717dfb1c627b42): perf score=10.126437
I20260812 06:19:12.852798 28311 maintenance_manager.cc:643] P 80b575eff86f46a3a279c4225d87e54b: FlushDeltaMemStoresOp(4513b85fee4a477ab7717dfb1c627b42) complete. Timing: real 0.044s	user 0.038s	sys 0.004s Metrics: {"bytes_written":12307489,"delete_count":0,"lbm_write_time_us":18748,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:19:12.853873 28383 maintenance_manager.cc:419] P 80b575eff86f46a3a279c4225d87e54b: Scheduling FlushDeltaMemStoresOp(4513b85fee4a477ab7717dfb1c627b42): perf score=2.188937
I20260812 06:19:12.869129 28311 maintenance_manager.cc:643] P 80b575eff86f46a3a279c4225d87e54b: FlushDeltaMemStoresOp(4513b85fee4a477ab7717dfb1c627b42) complete. Timing: real 0.015s	user 0.009s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5582,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:12.869697 28383 maintenance_manager.cc:419] P 80b575eff86f46a3a279c4225d87e54b: Scheduling MajorDeltaCompactionOp(4513b85fee4a477ab7717dfb1c627b42): perf score=1.000000
I20260812 06:19:13.013947 28311 maintenance_manager.cc:643] P 80b575eff86f46a3a279c4225d87e54b: MajorDeltaCompactionOp(4513b85fee4a477ab7717dfb1c627b42) complete. Timing: real 0.144s	user 0.124s	sys 0.020s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672276,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":327,"lbm_read_time_us":10785,"lbm_reads_lt_1ms":472,"lbm_write_time_us":27472,"lbm_writes_lt_1ms":443,"mutex_wait_us":43,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":18432,"update_count":2000}
I20260812 06:19:13.014757 28383 maintenance_manager.cc:419] P 80b575eff86f46a3a279c4225d87e54b: Scheduling FlushDeltaMemStoresOp(4513b85fee4a477ab7717dfb1c627b42): perf score=10.126437
I20260812 06:19:13.058926 28311 maintenance_manager.cc:643] P 80b575eff86f46a3a279c4225d87e54b: FlushDeltaMemStoresOp(4513b85fee4a477ab7717dfb1c627b42) complete. Timing: real 0.044s	user 0.028s	sys 0.008s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":17039,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:19:13.059528 28383 maintenance_manager.cc:419] P 80b575eff86f46a3a279c4225d87e54b: Scheduling FlushDeltaMemStoresOp(4513b85fee4a477ab7717dfb1c627b42): perf score=2.188937
I20260812 06:19:13.071980 28311 maintenance_manager.cc:643] P 80b575eff86f46a3a279c4225d87e54b: FlushDeltaMemStoresOp(4513b85fee4a477ab7717dfb1c627b42) complete. Timing: real 0.012s	user 0.003s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4459,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:13.072569 28383 maintenance_manager.cc:419] P 80b575eff86f46a3a279c4225d87e54b: Scheduling MajorDeltaCompactionOp(4513b85fee4a477ab7717dfb1c627b42): perf score=1.000000
I20260812 06:19:13.211971 28311 maintenance_manager.cc:643] P 80b575eff86f46a3a279c4225d87e54b: MajorDeltaCompactionOp(4513b85fee4a477ab7717dfb1c627b42) complete. Timing: real 0.139s	user 0.112s	sys 0.024s 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":3408,"lbm_read_time_us":8447,"lbm_reads_lt_1ms":472,"lbm_write_time_us":27306,"lbm_writes_lt_1ms":443,"mutex_wait_us":2258,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":11136,"update_count":2000}
I20260812 06:19:13.212735 28383 maintenance_manager.cc:419] P 80b575eff86f46a3a279c4225d87e54b: Scheduling FlushDeltaMemStoresOp(4513b85fee4a477ab7717dfb1c627b42): perf score=10.126437
I20260812 06:19:13.262364 28311 maintenance_manager.cc:643] P 80b575eff86f46a3a279c4225d87e54b: FlushDeltaMemStoresOp(4513b85fee4a477ab7717dfb1c627b42) complete. Timing: real 0.049s	user 0.029s	sys 0.015s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":15023,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:19:13.263002 28383 maintenance_manager.cc:419] P 80b575eff86f46a3a279c4225d87e54b: Scheduling FlushDeltaMemStoresOp(4513b85fee4a477ab7717dfb1c627b42): perf score=2.188937
I20260812 06:19:13.276605 28311 maintenance_manager.cc:643] P 80b575eff86f46a3a279c4225d87e54b: FlushDeltaMemStoresOp(4513b85fee4a477ab7717dfb1c627b42) complete. Timing: real 0.013s	user 0.008s	sys 0.004s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4854,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:13.277426 28383 maintenance_manager.cc:419] P 80b575eff86f46a3a279c4225d87e54b: Scheduling MajorDeltaCompactionOp(4513b85fee4a477ab7717dfb1c627b42): perf score=1.000000
I20260812 06:19:13.442951 28311 maintenance_manager.cc:643] P 80b575eff86f46a3a279c4225d87e54b: MajorDeltaCompactionOp(4513b85fee4a477ab7717dfb1c627b42) complete. Timing: real 0.165s	user 0.101s	sys 0.064s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672276,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":805,"lbm_read_time_us":14261,"lbm_reads_lt_1ms":472,"lbm_write_time_us":24025,"lbm_writes_lt_1ms":443,"mutex_wait_us":358,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":84224,"update_count":2000}
I20260812 06:19:13.443588 28383 maintenance_manager.cc:419] P 80b575eff86f46a3a279c4225d87e54b: Scheduling FlushDeltaMemStoresOp(4513b85fee4a477ab7717dfb1c627b42): perf score=10.126437
I20260812 06:19:13.492071 28311 maintenance_manager.cc:643] P 80b575eff86f46a3a279c4225d87e54b: FlushDeltaMemStoresOp(4513b85fee4a477ab7717dfb1c627b42) complete. Timing: real 0.048s	user 0.035s	sys 0.004s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":17751,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:19:13.492657 28383 maintenance_manager.cc:419] P 80b575eff86f46a3a279c4225d87e54b: Scheduling FlushDeltaMemStoresOp(4513b85fee4a477ab7717dfb1c627b42): perf score=2.188937
I20260812 06:19:13.504292 28311 maintenance_manager.cc:643] P 80b575eff86f46a3a279c4225d87e54b: FlushDeltaMemStoresOp(4513b85fee4a477ab7717dfb1c627b42) complete. Timing: real 0.011s	user 0.002s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4341,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:13.505069 28383 maintenance_manager.cc:419] P 80b575eff86f46a3a279c4225d87e54b: Scheduling FlushMRSOp(4513b85fee4a477ab7717dfb1c627b42): perf score=1.000000
I20260812 06:19:13.539155 28311 maintenance_manager.cc:643] P 80b575eff86f46a3a279c4225d87e54b: FlushMRSOp(4513b85fee4a477ab7717dfb1c627b42) complete. Timing: real 0.034s	user 0.028s	sys 0.004s Metrics: {"bytes_written":1152508,"cfile_init":1,"dirs.queue_time_us":58,"dirs.run_cpu_time_us":240,"dirs.run_wall_time_us":1853,"drs_written":1,"lbm_read_time_us":41,"lbm_reads_lt_1ms":4,"lbm_write_time_us":2304,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":28}
I20260812 06:19:13.539960 28383 maintenance_manager.cc:419] P 80b575eff86f46a3a279c4225d87e54b: Scheduling LogGCOp(4513b85fee4a477ab7717dfb1c627b42): free 115943180 bytes of WAL
I20260812 06:19:13.540279 28311 log_reader.cc:385] T 4513b85fee4a477ab7717dfb1c627b42: removed 11 log segments from log reader
I20260812 06:19:13.540365 28311 log.cc:1079] T 4513b85fee4a477ab7717dfb1c627b42 P 80b575eff86f46a3a279c4225d87e54b: Deleting log segment in path: /tmp/dist-test-taskt6ZbCi/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515545497762-27980-0/minicluster-data/ts-0-root/wals/4513b85fee4a477ab7717dfb1c627b42/wal-000000003 (ops 12-16)
I20260812 06:19:13.540421 28311 log.cc:1079] T 4513b85fee4a477ab7717dfb1c627b42 P 80b575eff86f46a3a279c4225d87e54b: Deleting log segment in path: /tmp/dist-test-taskt6ZbCi/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515545497762-27980-0/minicluster-data/ts-0-root/wals/4513b85fee4a477ab7717dfb1c627b42/wal-000000004 (ops 17-21)
I20260812 06:19:13.540479 28311 log.cc:1079] T 4513b85fee4a477ab7717dfb1c627b42 P 80b575eff86f46a3a279c4225d87e54b: Deleting log segment in path: /tmp/dist-test-taskt6ZbCi/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515545497762-27980-0/minicluster-data/ts-0-root/wals/4513b85fee4a477ab7717dfb1c627b42/wal-000000005 (ops 22-26)
I20260812 06:19:13.540522 28311 log.cc:1079] T 4513b85fee4a477ab7717dfb1c627b42 P 80b575eff86f46a3a279c4225d87e54b: Deleting log segment in path: /tmp/dist-test-taskt6ZbCi/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515545497762-27980-0/minicluster-data/ts-0-root/wals/4513b85fee4a477ab7717dfb1c627b42/wal-000000006 (ops 27-31)
I20260812 06:19:13.540560 28311 log.cc:1079] T 4513b85fee4a477ab7717dfb1c627b42 P 80b575eff86f46a3a279c4225d87e54b: Deleting log segment in path: /tmp/dist-test-taskt6ZbCi/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515545497762-27980-0/minicluster-data/ts-0-root/wals/4513b85fee4a477ab7717dfb1c627b42/wal-000000007 (ops 32-36)
I20260812 06:19:13.540585 28311 log.cc:1079] T 4513b85fee4a477ab7717dfb1c627b42 P 80b575eff86f46a3a279c4225d87e54b: Deleting log segment in path: /tmp/dist-test-taskt6ZbCi/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515545497762-27980-0/minicluster-data/ts-0-root/wals/4513b85fee4a477ab7717dfb1c627b42/wal-000000008 (ops 37-41)
I20260812 06:19:13.540609 28311 log.cc:1079] T 4513b85fee4a477ab7717dfb1c627b42 P 80b575eff86f46a3a279c4225d87e54b: Deleting log segment in path: /tmp/dist-test-taskt6ZbCi/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515545497762-27980-0/minicluster-data/ts-0-root/wals/4513b85fee4a477ab7717dfb1c627b42/wal-000000009 (ops 42-46)
I20260812 06:19:13.540632 28311 log.cc:1079] T 4513b85fee4a477ab7717dfb1c627b42 P 80b575eff86f46a3a279c4225d87e54b: Deleting log segment in path: /tmp/dist-test-taskt6ZbCi/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515545497762-27980-0/minicluster-data/ts-0-root/wals/4513b85fee4a477ab7717dfb1c627b42/wal-000000010 (ops 47-51)
I20260812 06:19:13.540659 28311 log.cc:1079] T 4513b85fee4a477ab7717dfb1c627b42 P 80b575eff86f46a3a279c4225d87e54b: Deleting log segment in path: /tmp/dist-test-taskt6ZbCi/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515545497762-27980-0/minicluster-data/ts-0-root/wals/4513b85fee4a477ab7717dfb1c627b42/wal-000000011 (ops 52-56)
I20260812 06:19:13.540700 28311 log.cc:1079] T 4513b85fee4a477ab7717dfb1c627b42 P 80b575eff86f46a3a279c4225d87e54b: Deleting log segment in path: /tmp/dist-test-taskt6ZbCi/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515545497762-27980-0/minicluster-data/ts-0-root/wals/4513b85fee4a477ab7717dfb1c627b42/wal-000000012 (ops 57-61)
I20260812 06:19:13.540737 28311 log.cc:1079] T 4513b85fee4a477ab7717dfb1c627b42 P 80b575eff86f46a3a279c4225d87e54b: Deleting log segment in path: /tmp/dist-test-taskt6ZbCi/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515545497762-27980-0/minicluster-data/ts-0-root/wals/4513b85fee4a477ab7717dfb1c627b42/wal-000000013 (ops 62-66)
I20260812 06:19:13.568948 28311 maintenance_manager.cc:643] P 80b575eff86f46a3a279c4225d87e54b: LogGCOp(4513b85fee4a477ab7717dfb1c627b42) complete. Timing: real 0.029s	user 0.000s	sys 0.027s Metrics: {}
I20260812 06:19:13.569758 28383 maintenance_manager.cc:419] P 80b575eff86f46a3a279c4225d87e54b: Scheduling FlushDeltaMemStoresOp(4513b85fee4a477ab7717dfb1c627b42): perf score=2.188937
I20260812 06:19:13.586215 28311 maintenance_manager.cc:643] P 80b575eff86f46a3a279c4225d87e54b: FlushDeltaMemStoresOp(4513b85fee4a477ab7717dfb1c627b42) complete. Timing: real 0.016s	user 0.009s	sys 0.001s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4216,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:13.586787 28383 maintenance_manager.cc:419] P 80b575eff86f46a3a279c4225d87e54b: Scheduling UndoDeltaBlockGCOp(4513b85fee4a477ab7717dfb1c627b42): 448 bytes on disk
I20260812 06:19:13.587316 28311 maintenance_manager.cc:643] P 80b575eff86f46a3a279c4225d87e54b: UndoDeltaBlockGCOp(4513b85fee4a477ab7717dfb1c627b42) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":62,"lbm_reads_lt_1ms":4}
I20260812 06:19:13.587942 28383 maintenance_manager.cc:419] P 80b575eff86f46a3a279c4225d87e54b: Scheduling FlushDeltaMemStoresOp(4513b85fee4a477ab7717dfb1c627b42): perf score=2.188937
I20260812 06:19:13.609938 28311 maintenance_manager.cc:643] P 80b575eff86f46a3a279c4225d87e54b: FlushDeltaMemStoresOp(4513b85fee4a477ab7717dfb1c627b42) complete. Timing: real 0.022s	user 0.005s	sys 0.015s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4387,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:13.610651 28383 maintenance_manager.cc:419] P 80b575eff86f46a3a279c4225d87e54b: Scheduling MajorDeltaCompactionOp(4513b85fee4a477ab7717dfb1c627b42): perf score=1.000000
I20260812 06:19:13.824234 28311 maintenance_manager.cc:643] P 80b575eff86f46a3a279c4225d87e54b: MajorDeltaCompactionOp(4513b85fee4a477ab7717dfb1c627b42) complete. Timing: real 0.213s	user 0.166s	sys 0.047s Metrics: {"cfile_cache_miss":634,"cfile_cache_miss_bytes":28877338,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":1061,"lbm_read_time_us":14914,"lbm_reads_lt_1ms":674,"lbm_write_time_us":33274,"lbm_writes_lt_1ms":643,"mutex_wait_us":76,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":24576,"thread_start_us":100,"threads_started":1,"update_count":3000}
I20260812 06:19:13.827231 28383 maintenance_manager.cc:419] P 80b575eff86f46a3a279c4225d87e54b: Scheduling FlushDeltaMemStoresOp(4513b85fee4a477ab7717dfb1c627b42): perf score=14.095187
I20260812 06:19:13.899320 28311 maintenance_manager.cc:643] P 80b575eff86f46a3a279c4225d87e54b: FlushDeltaMemStoresOp(4513b85fee4a477ab7717dfb1c627b42) complete. Timing: real 0.072s	user 0.031s	sys 0.036s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":27589,"lbm_writes_1-10_ms":2,"lbm_writes_lt_1ms":401,"reinsert_count":0,"update_count":2000}
I20260812 06:19:13.900127 28383 maintenance_manager.cc:419] P 80b575eff86f46a3a279c4225d87e54b: Scheduling FlushDeltaMemStoresOp(4513b85fee4a477ab7717dfb1c627b42): perf score=2.188937
I20260812 06:19:13.919255 28311 maintenance_manager.cc:643] P 80b575eff86f46a3a279c4225d87e54b: FlushDeltaMemStoresOp(4513b85fee4a477ab7717dfb1c627b42) complete. Timing: real 0.019s	user 0.009s	sys 0.005s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6518,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:13.919975 28383 maintenance_manager.cc:419] P 80b575eff86f46a3a279c4225d87e54b: Scheduling MajorDeltaCompactionOp(4513b85fee4a477ab7717dfb1c627b42): perf score=1.000000
I20260812 06:19:14.114270 28311 maintenance_manager.cc:643] P 80b575eff86f46a3a279c4225d87e54b: MajorDeltaCompactionOp(4513b85fee4a477ab7717dfb1c627b42) complete. Timing: real 0.194s	user 0.142s	sys 0.052s 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":215,"lbm_read_time_us":15524,"lbm_reads_lt_1ms":564,"lbm_write_time_us":27957,"lbm_writes_lt_1ms":543,"mutex_wait_us":40,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":88448,"update_count":2500}
I20260812 06:19:14.114907 28383 maintenance_manager.cc:419] P 80b575eff86f46a3a279c4225d87e54b: Scheduling FlushDeltaMemStoresOp(4513b85fee4a477ab7717dfb1c627b42): perf score=14.095187
I20260812 06:19:14.166658 28311 maintenance_manager.cc:643] P 80b575eff86f46a3a279c4225d87e54b: FlushDeltaMemStoresOp(4513b85fee4a477ab7717dfb1c627b42) complete. Timing: real 0.052s	user 0.024s	sys 0.024s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":23676,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:14.167222 28383 maintenance_manager.cc:419] P 80b575eff86f46a3a279c4225d87e54b: Scheduling FlushDeltaMemStoresOp(4513b85fee4a477ab7717dfb1c627b42): perf score=2.188937
I20260812 06:19:14.197803 28311 maintenance_manager.cc:643] P 80b575eff86f46a3a279c4225d87e54b: FlushDeltaMemStoresOp(4513b85fee4a477ab7717dfb1c627b42) complete. Timing: real 0.030s	user 0.014s	sys 0.003s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6443,"lbm_writes_lt_1ms":103,"reinsert_count":0,"spinlock_wait_cycles":896,"update_count":500}
I20260812 06:19:14.198467 28383 maintenance_manager.cc:419] P 80b575eff86f46a3a279c4225d87e54b: Scheduling FlushDeltaMemStoresOp(4513b85fee4a477ab7717dfb1c627b42): perf score=2.188937
I20260812 06:19:14.210708 28311 maintenance_manager.cc:643] P 80b575eff86f46a3a279c4225d87e54b: FlushDeltaMemStoresOp(4513b85fee4a477ab7717dfb1c627b42) complete. Timing: real 0.012s	user 0.003s	sys 0.007s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4867,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:14.211759 28383 maintenance_manager.cc:419] P 80b575eff86f46a3a279c4225d87e54b: Scheduling MajorDeltaCompactionOp(4513b85fee4a477ab7717dfb1c627b42): perf score=1.000000
I20260812 06:19:14.422138 28311 maintenance_manager.cc:643] P 80b575eff86f46a3a279c4225d87e54b: MajorDeltaCompactionOp(4513b85fee4a477ab7717dfb1c627b42) complete. Timing: real 0.209s	user 0.144s	sys 0.064s Metrics: {"cfile_cache_miss":633,"cfile_cache_miss_bytes":28877220,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":611,"lbm_read_time_us":14306,"lbm_reads_lt_1ms":673,"lbm_write_time_us":36936,"lbm_writes_lt_1ms":643,"mutex_wait_us":28,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":13184,"update_count":3000}
I20260812 06:19:14.422736 28383 maintenance_manager.cc:419] P 80b575eff86f46a3a279c4225d87e54b: Scheduling FlushDeltaMemStoresOp(4513b85fee4a477ab7717dfb1c627b42): perf score=14.095187
I20260812 06:19:14.488299 28311 maintenance_manager.cc:643] P 80b575eff86f46a3a279c4225d87e54b: FlushDeltaMemStoresOp(4513b85fee4a477ab7717dfb1c627b42) complete. Timing: real 0.065s	user 0.035s	sys 0.027s Metrics: {"bytes_written":16409904,"delete_count":0,"lbm_write_time_us":23445,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:14.489318 28383 maintenance_manager.cc:419] P 80b575eff86f46a3a279c4225d87e54b: Scheduling FlushDeltaMemStoresOp(4513b85fee4a477ab7717dfb1c627b42): perf score=2.188937
I20260812 06:19:14.501902 28311 maintenance_manager.cc:643] P 80b575eff86f46a3a279c4225d87e54b: FlushDeltaMemStoresOp(4513b85fee4a477ab7717dfb1c627b42) complete. Timing: real 0.012s	user 0.007s	sys 0.004s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4879,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:14.502417 28383 maintenance_manager.cc:419] P 80b575eff86f46a3a279c4225d87e54b: Scheduling MajorDeltaCompactionOp(4513b85fee4a477ab7717dfb1c627b42): perf score=1.000000
I20260812 06:19:14.690021 28311 maintenance_manager.cc:643] P 80b575eff86f46a3a279c4225d87e54b: MajorDeltaCompactionOp(4513b85fee4a477ab7717dfb1c627b42) complete. Timing: real 0.187s	user 0.127s	sys 0.060s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774690,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":326,"lbm_read_time_us":12965,"lbm_reads_lt_1ms":572,"lbm_write_time_us":31457,"lbm_writes_lt_1ms":543,"mutex_wait_us":70,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":17024,"update_count":2500}
I20260812 06:19:14.690641 28383 maintenance_manager.cc:419] P 80b575eff86f46a3a279c4225d87e54b: Scheduling FlushDeltaMemStoresOp(4513b85fee4a477ab7717dfb1c627b42): perf score=10.126437
I20260812 06:19:14.729790 28311 maintenance_manager.cc:643] P 80b575eff86f46a3a279c4225d87e54b: FlushDeltaMemStoresOp(4513b85fee4a477ab7717dfb1c627b42) complete. Timing: real 0.039s	user 0.017s	sys 0.020s Metrics: {"bytes_written":12307491,"delete_count":0,"lbm_write_time_us":17541,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:19:14.730422 28383 maintenance_manager.cc:419] P 80b575eff86f46a3a279c4225d87e54b: Scheduling FlushDeltaMemStoresOp(4513b85fee4a477ab7717dfb1c627b42): perf score=2.188937
I20260812 06:19:14.743037 28311 maintenance_manager.cc:643] P 80b575eff86f46a3a279c4225d87e54b: FlushDeltaMemStoresOp(4513b85fee4a477ab7717dfb1c627b42) complete. Timing: real 0.012s	user 0.007s	sys 0.003s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4507,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:14.743602 28383 maintenance_manager.cc:419] P 80b575eff86f46a3a279c4225d87e54b: Scheduling MajorDeltaCompactionOp(4513b85fee4a477ab7717dfb1c627b42): perf score=1.000000
I20260812 06:19:14.907675 28311 maintenance_manager.cc:643] P 80b575eff86f46a3a279c4225d87e54b: MajorDeltaCompactionOp(4513b85fee4a477ab7717dfb1c627b42) complete. Timing: real 0.164s	user 0.127s	sys 0.033s 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":1687,"lbm_read_time_us":9661,"lbm_reads_lt_1ms":472,"lbm_write_time_us":26710,"lbm_writes_lt_1ms":443,"mutex_wait_us":1246,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":12544,"update_count":2000}
I20260812 06:19:14.908810 28383 maintenance_manager.cc:419] P 80b575eff86f46a3a279c4225d87e54b: Scheduling FlushDeltaMemStoresOp(4513b85fee4a477ab7717dfb1c627b42): perf score=10.126437
I20260812 06:19:14.956701 28311 maintenance_manager.cc:643] P 80b575eff86f46a3a279c4225d87e54b: FlushDeltaMemStoresOp(4513b85fee4a477ab7717dfb1c627b42) complete. Timing: real 0.048s	user 0.027s	sys 0.013s Metrics: {"bytes_written":12307489,"delete_count":0,"lbm_write_time_us":18354,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:19:14.957321 28383 maintenance_manager.cc:419] P 80b575eff86f46a3a279c4225d87e54b: Scheduling FlushDeltaMemStoresOp(4513b85fee4a477ab7717dfb1c627b42): perf score=2.188937
I20260812 06:19:14.968991 28311 maintenance_manager.cc:643] P 80b575eff86f46a3a279c4225d87e54b: FlushDeltaMemStoresOp(4513b85fee4a477ab7717dfb1c627b42) complete. Timing: real 0.011s	user 0.005s	sys 0.004s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4341,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:14.969817 28383 maintenance_manager.cc:419] P 80b575eff86f46a3a279c4225d87e54b: Scheduling MajorDeltaCompactionOp(4513b85fee4a477ab7717dfb1c627b42): perf score=1.000000
I20260812 06:19:15.106627 28311 maintenance_manager.cc:643] P 80b575eff86f46a3a279c4225d87e54b: MajorDeltaCompactionOp(4513b85fee4a477ab7717dfb1c627b42) complete. Timing: real 0.136s	user 0.111s	sys 0.023s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672275,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":891,"lbm_read_time_us":8730,"lbm_reads_lt_1ms":472,"lbm_write_time_us":27896,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":442,"mutex_wait_us":52,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":1280,"update_count":2000}
I20260812 06:19:15.107566 28383 maintenance_manager.cc:419] P 80b575eff86f46a3a279c4225d87e54b: Scheduling FlushDeltaMemStoresOp(4513b85fee4a477ab7717dfb1c627b42): perf score=10.126437
I20260812 06:19:15.162115 28311 maintenance_manager.cc:643] P 80b575eff86f46a3a279c4225d87e54b: FlushDeltaMemStoresOp(4513b85fee4a477ab7717dfb1c627b42) complete. Timing: real 0.054s	user 0.031s	sys 0.013s Metrics: {"bytes_written":12307492,"delete_count":0,"lbm_write_time_us":20206,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:19:15.162664 28383 maintenance_manager.cc:419] P 80b575eff86f46a3a279c4225d87e54b: Scheduling FlushDeltaMemStoresOp(4513b85fee4a477ab7717dfb1c627b42): perf score=2.188937
I20260812 06:19:15.174461 28311 maintenance_manager.cc:643] P 80b575eff86f46a3a279c4225d87e54b: FlushDeltaMemStoresOp(4513b85fee4a477ab7717dfb1c627b42) complete. Timing: real 0.012s	user 0.006s	sys 0.003s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4251,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:15.175392 28383 maintenance_manager.cc:419] P 80b575eff86f46a3a279c4225d87e54b: Scheduling FlushMRSOp(4513b85fee4a477ab7717dfb1c627b42): perf score=1.000000
I20260812 06:19:15.209986 28311 maintenance_manager.cc:643] P 80b575eff86f46a3a279c4225d87e54b: FlushMRSOp(4513b85fee4a477ab7717dfb1c627b42) complete. Timing: real 0.034s	user 0.029s	sys 0.000s Metrics: {"bytes_written":1234479,"cfile_init":1,"dirs.queue_time_us":117,"dirs.run_cpu_time_us":600,"dirs.run_wall_time_us":2417,"drs_written":1,"lbm_read_time_us":66,"lbm_reads_lt_1ms":4,"lbm_write_time_us":2138,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":30}
I20260812 06:19:15.210714 28383 maintenance_manager.cc:419] P 80b575eff86f46a3a279c4225d87e54b: Scheduling LogGCOp(4513b85fee4a477ab7717dfb1c627b42): free 121006381 bytes of WAL
I20260812 06:19:15.210969 28311 log_reader.cc:385] T 4513b85fee4a477ab7717dfb1c627b42: removed 12 log segments from log reader
I20260812 06:19:15.211015 28311 log.cc:1079] T 4513b85fee4a477ab7717dfb1c627b42 P 80b575eff86f46a3a279c4225d87e54b: Deleting log segment in path: /tmp/dist-test-taskt6ZbCi/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515545497762-27980-0/minicluster-data/ts-0-root/wals/4513b85fee4a477ab7717dfb1c627b42/wal-000000014 (ops 67-71)
I20260812 06:19:15.211045 28311 log.cc:1079] T 4513b85fee4a477ab7717dfb1c627b42 P 80b575eff86f46a3a279c4225d87e54b: Deleting log segment in path: /tmp/dist-test-taskt6ZbCi/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515545497762-27980-0/minicluster-data/ts-0-root/wals/4513b85fee4a477ab7717dfb1c627b42/wal-000000015 (ops 72-76)
I20260812 06:19:15.211115 28311 log.cc:1079] T 4513b85fee4a477ab7717dfb1c627b42 P 80b575eff86f46a3a279c4225d87e54b: Deleting log segment in path: /tmp/dist-test-taskt6ZbCi/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515545497762-27980-0/minicluster-data/ts-0-root/wals/4513b85fee4a477ab7717dfb1c627b42/wal-000000016 (ops 77-81)
I20260812 06:19:15.211148 28311 log.cc:1079] T 4513b85fee4a477ab7717dfb1c627b42 P 80b575eff86f46a3a279c4225d87e54b: Deleting log segment in path: /tmp/dist-test-taskt6ZbCi/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515545497762-27980-0/minicluster-data/ts-0-root/wals/4513b85fee4a477ab7717dfb1c627b42/wal-000000017 (ops 82-86)
I20260812 06:19:15.211194 28311 log.cc:1079] T 4513b85fee4a477ab7717dfb1c627b42 P 80b575eff86f46a3a279c4225d87e54b: Deleting log segment in path: /tmp/dist-test-taskt6ZbCi/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515545497762-27980-0/minicluster-data/ts-0-root/wals/4513b85fee4a477ab7717dfb1c627b42/wal-000000018 (ops 87-91)
I20260812 06:19:15.211238 28311 log.cc:1079] T 4513b85fee4a477ab7717dfb1c627b42 P 80b575eff86f46a3a279c4225d87e54b: Deleting log segment in path: /tmp/dist-test-taskt6ZbCi/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515545497762-27980-0/minicluster-data/ts-0-root/wals/4513b85fee4a477ab7717dfb1c627b42/wal-000000019 (ops 92-96)
I20260812 06:19:15.211298 28311 log.cc:1079] T 4513b85fee4a477ab7717dfb1c627b42 P 80b575eff86f46a3a279c4225d87e54b: Deleting log segment in path: /tmp/dist-test-taskt6ZbCi/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515545497762-27980-0/minicluster-data/ts-0-root/wals/4513b85fee4a477ab7717dfb1c627b42/wal-000000020 (ops 97-101)
I20260812 06:19:15.211392 28311 log.cc:1079] T 4513b85fee4a477ab7717dfb1c627b42 P 80b575eff86f46a3a279c4225d87e54b: Deleting log segment in path: /tmp/dist-test-taskt6ZbCi/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515545497762-27980-0/minicluster-data/ts-0-root/wals/4513b85fee4a477ab7717dfb1c627b42/wal-000000021 (ops 102-106)
I20260812 06:19:15.211434 28311 log.cc:1079] T 4513b85fee4a477ab7717dfb1c627b42 P 80b575eff86f46a3a279c4225d87e54b: Deleting log segment in path: /tmp/dist-test-taskt6ZbCi/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515545497762-27980-0/minicluster-data/ts-0-root/wals/4513b85fee4a477ab7717dfb1c627b42/wal-000000022 (ops 107-110)
I20260812 06:19:15.211490 28311 log.cc:1079] T 4513b85fee4a477ab7717dfb1c627b42 P 80b575eff86f46a3a279c4225d87e54b: Deleting log segment in path: /tmp/dist-test-taskt6ZbCi/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515545497762-27980-0/minicluster-data/ts-0-root/wals/4513b85fee4a477ab7717dfb1c627b42/wal-000000023 (ops 111-115)
I20260812 06:19:15.211532 28311 log.cc:1079] T 4513b85fee4a477ab7717dfb1c627b42 P 80b575eff86f46a3a279c4225d87e54b: Deleting log segment in path: /tmp/dist-test-taskt6ZbCi/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515545497762-27980-0/minicluster-data/ts-0-root/wals/4513b85fee4a477ab7717dfb1c627b42/wal-000000024 (ops 116-120)
I20260812 06:19:15.211573 28311 log.cc:1079] T 4513b85fee4a477ab7717dfb1c627b42 P 80b575eff86f46a3a279c4225d87e54b: Deleting log segment in path: /tmp/dist-test-taskt6ZbCi/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515545497762-27980-0/minicluster-data/ts-0-root/wals/4513b85fee4a477ab7717dfb1c627b42/wal-000000025 (ops 121-125)
I20260812 06:19:15.240111 28311 maintenance_manager.cc:643] P 80b575eff86f46a3a279c4225d87e54b: LogGCOp(4513b85fee4a477ab7717dfb1c627b42) complete. Timing: real 0.029s	user 0.000s	sys 0.028s Metrics: {}
I20260812 06:19:15.240815 28383 maintenance_manager.cc:419] P 80b575eff86f46a3a279c4225d87e54b: Scheduling UndoDeltaBlockGCOp(4513b85fee4a477ab7717dfb1c627b42): 472 bytes on disk
I20260812 06:19:15.241551 28311 maintenance_manager.cc:643] P 80b575eff86f46a3a279c4225d87e54b: UndoDeltaBlockGCOp(4513b85fee4a477ab7717dfb1c627b42) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":74,"lbm_reads_lt_1ms":4}
I20260812 06:19:15.242442 28383 maintenance_manager.cc:419] P 80b575eff86f46a3a279c4225d87e54b: Scheduling FlushDeltaMemStoresOp(4513b85fee4a477ab7717dfb1c627b42): perf score=2.188937
I20260812 06:19:15.268836 28311 maintenance_manager.cc:643] P 80b575eff86f46a3a279c4225d87e54b: FlushDeltaMemStoresOp(4513b85fee4a477ab7717dfb1c627b42) complete. Timing: real 0.026s	user 0.014s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":7970,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:15.269415 28383 maintenance_manager.cc:419] P 80b575eff86f46a3a279c4225d87e54b: Scheduling FlushDeltaMemStoresOp(4513b85fee4a477ab7717dfb1c627b42): perf score=2.188937
I20260812 06:19:15.280972 28311 maintenance_manager.cc:643] P 80b575eff86f46a3a279c4225d87e54b: FlushDeltaMemStoresOp(4513b85fee4a477ab7717dfb1c627b42) complete. Timing: real 0.011s	user 0.006s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4280,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:15.281570 28383 maintenance_manager.cc:419] P 80b575eff86f46a3a279c4225d87e54b: Scheduling MajorDeltaCompactionOp(4513b85fee4a477ab7717dfb1c627b42): perf score=1.000000
I20260812 06:19:15.479789 28311 maintenance_manager.cc:643] P 80b575eff86f46a3a279c4225d87e54b: MajorDeltaCompactionOp(4513b85fee4a477ab7717dfb1c627b42) complete. Timing: real 0.198s	user 0.142s	sys 0.052s Metrics: {"cfile_cache_miss":634,"cfile_cache_miss_bytes":28877341,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":4879,"dirs.run_cpu_time_us":510,"dirs.run_wall_time_us":3699,"lbm_read_time_us":12992,"lbm_reads_lt_1ms":674,"lbm_write_time_us":41727,"lbm_writes_lt_1ms":643,"mutex_wait_us":4205,"peak_mem_usage":75542472,"reinsert_count":0,"update_count":3000}
I20260812 06:19:15.480865 28383 maintenance_manager.cc:419] P 80b575eff86f46a3a279c4225d87e54b: Scheduling FlushDeltaMemStoresOp(4513b85fee4a477ab7717dfb1c627b42): perf score=14.095187
I20260812 06:19:15.538589 28311 maintenance_manager.cc:643] P 80b575eff86f46a3a279c4225d87e54b: FlushDeltaMemStoresOp(4513b85fee4a477ab7717dfb1c627b42) complete. Timing: real 0.058s	user 0.029s	sys 0.025s Metrics: {"bytes_written":16409904,"delete_count":0,"lbm_write_time_us":25748,"lbm_writes_1-10_ms":2,"lbm_writes_lt_1ms":401,"reinsert_count":0,"update_count":2000}
I20260812 06:19:15.539222 28383 maintenance_manager.cc:419] P 80b575eff86f46a3a279c4225d87e54b: Scheduling FlushDeltaMemStoresOp(4513b85fee4a477ab7717dfb1c627b42): perf score=2.188937
I20260812 06:19:15.559772 28311 maintenance_manager.cc:643] P 80b575eff86f46a3a279c4225d87e54b: FlushDeltaMemStoresOp(4513b85fee4a477ab7717dfb1c627b42) complete. Timing: real 0.020s	user 0.012s	sys 0.005s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6590,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:15.560410 28383 maintenance_manager.cc:419] P 80b575eff86f46a3a279c4225d87e54b: Scheduling MajorDeltaCompactionOp(4513b85fee4a477ab7717dfb1c627b42): perf score=1.000000
I20260812 06:19:15.730052 28311 maintenance_manager.cc:643] P 80b575eff86f46a3a279c4225d87e54b: MajorDeltaCompactionOp(4513b85fee4a477ab7717dfb1c627b42) complete. Timing: real 0.169s	user 0.132s	sys 0.028s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774691,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":681,"lbm_read_time_us":11341,"lbm_reads_lt_1ms":564,"lbm_write_time_us":33035,"lbm_writes_lt_1ms":543,"mutex_wait_us":313,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":6656,"update_count":2500}
I20260812 06:19:15.730693 28383 maintenance_manager.cc:419] P 80b575eff86f46a3a279c4225d87e54b: Scheduling FlushDeltaMemStoresOp(4513b85fee4a477ab7717dfb1c627b42): perf score=14.095187
I20260812 06:19:15.787544 28311 maintenance_manager.cc:643] P 80b575eff86f46a3a279c4225d87e54b: FlushDeltaMemStoresOp(4513b85fee4a477ab7717dfb1c627b42) complete. Timing: real 0.057s	user 0.039s	sys 0.015s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":24066,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:15.788137 28383 maintenance_manager.cc:419] P 80b575eff86f46a3a279c4225d87e54b: Scheduling FlushDeltaMemStoresOp(4513b85fee4a477ab7717dfb1c627b42): perf score=2.188937
I20260812 06:19:15.801501 28311 maintenance_manager.cc:643] P 80b575eff86f46a3a279c4225d87e54b: FlushDeltaMemStoresOp(4513b85fee4a477ab7717dfb1c627b42) complete. Timing: real 0.013s	user 0.002s	sys 0.009s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4798,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:15.802047 28383 maintenance_manager.cc:419] P 80b575eff86f46a3a279c4225d87e54b: Scheduling MajorDeltaCompactionOp(4513b85fee4a477ab7717dfb1c627b42): perf score=1.000000
I20260812 06:19:16.019382 28311 maintenance_manager.cc:643] P 80b575eff86f46a3a279c4225d87e54b: MajorDeltaCompactionOp(4513b85fee4a477ab7717dfb1c627b42) complete. Timing: real 0.217s	user 0.166s	sys 0.044s 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":1277,"lbm_read_time_us":13433,"lbm_reads_lt_1ms":572,"lbm_write_time_us":36883,"lbm_writes_lt_1ms":543,"mutex_wait_us":345,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":43520,"update_count":2500}
I20260812 06:19:16.020247 28383 maintenance_manager.cc:419] P 80b575eff86f46a3a279c4225d87e54b: Scheduling FlushDeltaMemStoresOp(4513b85fee4a477ab7717dfb1c627b42): perf score=14.095187
I20260812 06:19:16.074924 28311 maintenance_manager.cc:643] P 80b575eff86f46a3a279c4225d87e54b: FlushDeltaMemStoresOp(4513b85fee4a477ab7717dfb1c627b42) complete. Timing: real 0.054s	user 0.027s	sys 0.024s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":24890,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:16.075623 28383 maintenance_manager.cc:419] P 80b575eff86f46a3a279c4225d87e54b: Scheduling MajorDeltaCompactionOp(4513b85fee4a477ab7717dfb1c627b42): perf score=1.000000
I20260812 06:19:16.266065 28311 maintenance_manager.cc:643] P 80b575eff86f46a3a279c4225d87e54b: MajorDeltaCompactionOp(4513b85fee4a477ab7717dfb1c627b42) complete. Timing: real 0.190s	user 0.137s	sys 0.045s Metrics: {"cfile_cache_miss":431,"cfile_cache_miss_bytes":20672158,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":1,"delta_iterators_relevant":1,"dirs.queue_time_us":141,"lbm_read_time_us":11688,"lbm_reads_lt_1ms":467,"lbm_write_time_us":29776,"lbm_writes_lt_1ms":443,"mutex_wait_us":32,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":896,"update_count":2000}
I20260812 06:19:16.266940 28383 maintenance_manager.cc:419] P 80b575eff86f46a3a279c4225d87e54b: Scheduling FlushDeltaMemStoresOp(4513b85fee4a477ab7717dfb1c627b42): perf score=14.095187
I20260812 06:19:16.324402 28311 maintenance_manager.cc:643] P 80b575eff86f46a3a279c4225d87e54b: FlushDeltaMemStoresOp(4513b85fee4a477ab7717dfb1c627b42) complete. Timing: real 0.057s	user 0.043s	sys 0.012s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":25259,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:16.325109 28383 maintenance_manager.cc:419] P 80b575eff86f46a3a279c4225d87e54b: Scheduling FlushDeltaMemStoresOp(4513b85fee4a477ab7717dfb1c627b42): perf score=2.188937
I20260812 06:19:16.343050 28311 maintenance_manager.cc:643] P 80b575eff86f46a3a279c4225d87e54b: FlushDeltaMemStoresOp(4513b85fee4a477ab7717dfb1c627b42) complete. Timing: real 0.018s	user 0.011s	sys 0.003s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6474,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:16.344136 28383 maintenance_manager.cc:419] P 80b575eff86f46a3a279c4225d87e54b: Scheduling MajorDeltaCompactionOp(4513b85fee4a477ab7717dfb1c627b42): perf score=1.000000
I20260812 06:19:16.562201 28311 maintenance_manager.cc:643] P 80b575eff86f46a3a279c4225d87e54b: MajorDeltaCompactionOp(4513b85fee4a477ab7717dfb1c627b42) complete. Timing: real 0.218s	user 0.146s	sys 0.057s 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":232,"lbm_read_time_us":13869,"lbm_reads_lt_1ms":572,"lbm_write_time_us":33057,"lbm_writes_lt_1ms":543,"mutex_wait_us":59,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":11264,"update_count":2500}
I20260812 06:19:16.562914 28383 maintenance_manager.cc:419] P 80b575eff86f46a3a279c4225d87e54b: Scheduling FlushDeltaMemStoresOp(4513b85fee4a477ab7717dfb1c627b42): perf score=14.095187
I20260812 06:19:16.622115 28311 maintenance_manager.cc:643] P 80b575eff86f46a3a279c4225d87e54b: FlushDeltaMemStoresOp(4513b85fee4a477ab7717dfb1c627b42) complete. Timing: real 0.059s	user 0.026s	sys 0.028s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":25830,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:16.622735 28383 maintenance_manager.cc:419] P 80b575eff86f46a3a279c4225d87e54b: Scheduling FlushDeltaMemStoresOp(4513b85fee4a477ab7717dfb1c627b42): perf score=2.188937
I20260812 06:19:16.636785 28311 maintenance_manager.cc:643] P 80b575eff86f46a3a279c4225d87e54b: FlushDeltaMemStoresOp(4513b85fee4a477ab7717dfb1c627b42) complete. Timing: real 0.014s	user 0.005s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4792,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:16.637498 28383 maintenance_manager.cc:419] P 80b575eff86f46a3a279c4225d87e54b: Scheduling MajorDeltaCompactionOp(4513b85fee4a477ab7717dfb1c627b42): perf score=1.000000
I20260812 06:19:16.815647 28311 maintenance_manager.cc:643] P 80b575eff86f46a3a279c4225d87e54b: MajorDeltaCompactionOp(4513b85fee4a477ab7717dfb1c627b42) complete. Timing: real 0.178s	user 0.113s	sys 0.063s 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":345,"lbm_read_time_us":12438,"lbm_reads_lt_1ms":572,"lbm_write_time_us":33405,"lbm_writes_lt_1ms":543,"mutex_wait_us":41,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":8832,"update_count":2500}
I20260812 06:19:16.816556 28383 maintenance_manager.cc:419] P 80b575eff86f46a3a279c4225d87e54b: Scheduling FlushDeltaMemStoresOp(4513b85fee4a477ab7717dfb1c627b42): perf score=14.095187
I20260812 06:19:16.874752 28311 maintenance_manager.cc:643] P 80b575eff86f46a3a279c4225d87e54b: FlushDeltaMemStoresOp(4513b85fee4a477ab7717dfb1c627b42) complete. Timing: real 0.058s	user 0.029s	sys 0.026s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":26087,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:16.875432 28383 maintenance_manager.cc:419] P 80b575eff86f46a3a279c4225d87e54b: Scheduling FlushDeltaMemStoresOp(4513b85fee4a477ab7717dfb1c627b42): perf score=2.188937
I20260812 06:19:16.888260 28311 maintenance_manager.cc:643] P 80b575eff86f46a3a279c4225d87e54b: FlushDeltaMemStoresOp(4513b85fee4a477ab7717dfb1c627b42) complete. Timing: real 0.013s	user 0.001s	sys 0.010s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4635,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:16.888782 28383 maintenance_manager.cc:419] P 80b575eff86f46a3a279c4225d87e54b: Scheduling FlushMRSOp(4513b85fee4a477ab7717dfb1c627b42): perf score=1.000000
I20260812 06:19:16.925185 28311 maintenance_manager.cc:643] P 80b575eff86f46a3a279c4225d87e54b: FlushMRSOp(4513b85fee4a477ab7717dfb1c627b42) complete. Timing: real 0.036s	user 0.029s	sys 0.006s Metrics: {"bytes_written":1275447,"cfile_init":1,"dirs.queue_time_us":99,"dirs.run_cpu_time_us":277,"dirs.run_wall_time_us":1605,"drs_written":1,"lbm_read_time_us":50,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1751,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":31}
I20260812 06:19:16.926033 28383 maintenance_manager.cc:419] P 80b575eff86f46a3a279c4225d87e54b: Scheduling LogGCOp(4513b85fee4a477ab7717dfb1c627b42): free 129320818 bytes of WAL
I20260812 06:19:16.926314 28311 log_reader.cc:385] T 4513b85fee4a477ab7717dfb1c627b42: removed 13 log segments from log reader
I20260812 06:19:16.926364 28311 log.cc:1079] T 4513b85fee4a477ab7717dfb1c627b42 P 80b575eff86f46a3a279c4225d87e54b: Deleting log segment in path: /tmp/dist-test-taskt6ZbCi/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515545497762-27980-0/minicluster-data/ts-0-root/wals/4513b85fee4a477ab7717dfb1c627b42/wal-000000026 (ops 126-130)
I20260812 06:19:16.926397 28311 log.cc:1079] T 4513b85fee4a477ab7717dfb1c627b42 P 80b575eff86f46a3a279c4225d87e54b: Deleting log segment in path: /tmp/dist-test-taskt6ZbCi/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515545497762-27980-0/minicluster-data/ts-0-root/wals/4513b85fee4a477ab7717dfb1c627b42/wal-000000027 (ops 131-135)
I20260812 06:19:16.926466 28311 log.cc:1079] T 4513b85fee4a477ab7717dfb1c627b42 P 80b575eff86f46a3a279c4225d87e54b: Deleting log segment in path: /tmp/dist-test-taskt6ZbCi/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515545497762-27980-0/minicluster-data/ts-0-root/wals/4513b85fee4a477ab7717dfb1c627b42/wal-000000028 (ops 136-140)
I20260812 06:19:16.926517 28311 log.cc:1079] T 4513b85fee4a477ab7717dfb1c627b42 P 80b575eff86f46a3a279c4225d87e54b: Deleting log segment in path: /tmp/dist-test-taskt6ZbCi/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515545497762-27980-0/minicluster-data/ts-0-root/wals/4513b85fee4a477ab7717dfb1c627b42/wal-000000029 (ops 141-144)
I20260812 06:19:16.926559 28311 log.cc:1079] T 4513b85fee4a477ab7717dfb1c627b42 P 80b575eff86f46a3a279c4225d87e54b: Deleting log segment in path: /tmp/dist-test-taskt6ZbCi/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515545497762-27980-0/minicluster-data/ts-0-root/wals/4513b85fee4a477ab7717dfb1c627b42/wal-000000030 (ops 145-149)
I20260812 06:19:16.926580 28311 log.cc:1079] T 4513b85fee4a477ab7717dfb1c627b42 P 80b575eff86f46a3a279c4225d87e54b: Deleting log segment in path: /tmp/dist-test-taskt6ZbCi/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515545497762-27980-0/minicluster-data/ts-0-root/wals/4513b85fee4a477ab7717dfb1c627b42/wal-000000031 (ops 150-154)
I20260812 06:19:16.926635 28311 log.cc:1079] T 4513b85fee4a477ab7717dfb1c627b42 P 80b575eff86f46a3a279c4225d87e54b: Deleting log segment in path: /tmp/dist-test-taskt6ZbCi/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515545497762-27980-0/minicluster-data/ts-0-root/wals/4513b85fee4a477ab7717dfb1c627b42/wal-000000032 (ops 155-158)
I20260812 06:19:16.926680 28311 log.cc:1079] T 4513b85fee4a477ab7717dfb1c627b42 P 80b575eff86f46a3a279c4225d87e54b: Deleting log segment in path: /tmp/dist-test-taskt6ZbCi/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515545497762-27980-0/minicluster-data/ts-0-root/wals/4513b85fee4a477ab7717dfb1c627b42/wal-000000033 (ops 159-163)
I20260812 06:19:16.926753 28311 log.cc:1079] T 4513b85fee4a477ab7717dfb1c627b42 P 80b575eff86f46a3a279c4225d87e54b: Deleting log segment in path: /tmp/dist-test-taskt6ZbCi/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515545497762-27980-0/minicluster-data/ts-0-root/wals/4513b85fee4a477ab7717dfb1c627b42/wal-000000034 (ops 164-168)
I20260812 06:19:16.926801 28311 log.cc:1079] T 4513b85fee4a477ab7717dfb1c627b42 P 80b575eff86f46a3a279c4225d87e54b: Deleting log segment in path: /tmp/dist-test-taskt6ZbCi/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515545497762-27980-0/minicluster-data/ts-0-root/wals/4513b85fee4a477ab7717dfb1c627b42/wal-000000035 (ops 169-173)
I20260812 06:19:16.926843 28311 log.cc:1079] T 4513b85fee4a477ab7717dfb1c627b42 P 80b575eff86f46a3a279c4225d87e54b: Deleting log segment in path: /tmp/dist-test-taskt6ZbCi/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515545497762-27980-0/minicluster-data/ts-0-root/wals/4513b85fee4a477ab7717dfb1c627b42/wal-000000036 (ops 174-178)
I20260812 06:19:16.926887 28311 log.cc:1079] T 4513b85fee4a477ab7717dfb1c627b42 P 80b575eff86f46a3a279c4225d87e54b: Deleting log segment in path: /tmp/dist-test-taskt6ZbCi/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515545497762-27980-0/minicluster-data/ts-0-root/wals/4513b85fee4a477ab7717dfb1c627b42/wal-000000037 (ops 179-183)
I20260812 06:19:16.926929 28311 log.cc:1079] T 4513b85fee4a477ab7717dfb1c627b42 P 80b575eff86f46a3a279c4225d87e54b: Deleting log segment in path: /tmp/dist-test-taskt6ZbCi/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515545497762-27980-0/minicluster-data/ts-0-root/wals/4513b85fee4a477ab7717dfb1c627b42/wal-000000038 (ops 184-188)
I20260812 06:19:16.959159 28311 maintenance_manager.cc:643] P 80b575eff86f46a3a279c4225d87e54b: LogGCOp(4513b85fee4a477ab7717dfb1c627b42) complete. Timing: real 0.033s	user 0.000s	sys 0.029s Metrics: {}
I20260812 06:19:16.959656 28383 maintenance_manager.cc:419] P 80b575eff86f46a3a279c4225d87e54b: Scheduling FlushDeltaMemStoresOp(4513b85fee4a477ab7717dfb1c627b42): perf score=6.157687
I20260812 06:19:16.993638 28311 maintenance_manager.cc:643] P 80b575eff86f46a3a279c4225d87e54b: FlushDeltaMemStoresOp(4513b85fee4a477ab7717dfb1c627b42) complete. Timing: real 0.034s	user 0.020s	sys 0.005s Metrics: {"bytes_written":8205077,"delete_count":0,"lbm_write_time_us":11158,"lbm_writes_lt_1ms":203,"reinsert_count":0,"update_count":1000}
I20260812 06:19:16.994283 28383 maintenance_manager.cc:419] P 80b575eff86f46a3a279c4225d87e54b: Scheduling UndoDeltaBlockGCOp(4513b85fee4a477ab7717dfb1c627b42): 483 bytes on disk
I20260812 06:19:16.994745 28311 maintenance_manager.cc:643] P 80b575eff86f46a3a279c4225d87e54b: UndoDeltaBlockGCOp(4513b85fee4a477ab7717dfb1c627b42) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":54,"lbm_reads_lt_1ms":4}
I20260812 06:19:16.995353 28383 maintenance_manager.cc:419] P 80b575eff86f46a3a279c4225d87e54b: Scheduling MajorDeltaCompactionOp(4513b85fee4a477ab7717dfb1c627b42): perf score=1.000000
I20260812 06:19:17.248709 27980 heavy-update-compaction-itest.cc:229] Time spent updating: real 5.401s	user 1.929s	sys 0.189s
I20260812 06:19:17.266619 28311 maintenance_manager.cc:643] P 80b575eff86f46a3a279c4225d87e54b: MajorDeltaCompactionOp(4513b85fee4a477ab7717dfb1c627b42) complete. Timing: real 0.271s	user 0.171s	sys 0.085s Metrics: {"cfile_cache_miss":733,"cfile_cache_miss_bytes":32979631,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":9295,"lbm_read_time_us":19308,"lbm_reads_lt_1ms":765,"lbm_write_time_us":40490,"lbm_writes_lt_1ms":743,"mutex_wait_us":2974,"peak_mem_usage":87969044,"reinsert_count":0,"spinlock_wait_cycles":8832,"thread_start_us":107,"threads_started":1,"update_count":3500}
I20260812 06:19:17.267580 28383 maintenance_manager.cc:419] P 80b575eff86f46a3a279c4225d87e54b: Scheduling FlushDeltaMemStoresOp(4513b85fee4a477ab7717dfb1c627b42): perf score=18.063937
I20260812 06:19:17.313264 27980 heavy-update-compaction-itest.cc:265] Time spent scanning: real 0.064s	user 0.003s	sys 0.000s
I20260812 06:19:17.313937 27980 tablet_server.cc:179] TabletServer@127.27.83.1:0 shutting down...
I20260812 06:19:17.327603 28311 maintenance_manager.cc:643] P 80b575eff86f46a3a279c4225d87e54b: FlushDeltaMemStoresOp(4513b85fee4a477ab7717dfb1c627b42) complete. Timing: real 0.060s	user 0.042s	sys 0.017s Metrics: {"bytes_written":20512317,"delete_count":0,"lbm_write_time_us":27594,"lbm_writes_lt_1ms":503,"reinsert_count":0,"update_count":2500}
I20260812 06:19:17.328279 27980 ts_tablet_manager.cc:1507] Shutting down tablet manager...
I20260812 06:19:17.328493 27980 tablet_replica.cc:333] T 4513b85fee4a477ab7717dfb1c627b42 P 80b575eff86f46a3a279c4225d87e54b: stopping tablet replica
I20260812 06:19:17.328627 27980 raft_consensus.cc:2243] T 4513b85fee4a477ab7717dfb1c627b42 P 80b575eff86f46a3a279c4225d87e54b [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:19:17.328835 27980 raft_consensus.cc:2272] T 4513b85fee4a477ab7717dfb1c627b42 P 80b575eff86f46a3a279c4225d87e54b [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:19:17.342707 27980 tablet_server.cc:196] TabletServer@127.27.83.1:0 shutdown complete.
I20260812 06:19:17.346413 27980 master.cc:562] Master@127.27.83.62:38021 shutting down...
I20260812 06:19:17.350327 27980 raft_consensus.cc:2243] T 00000000000000000000000000000000 P 4c79b00d8fac48128ebab29da922cecf [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:19:17.350522 27980 raft_consensus.cc:2272] T 00000000000000000000000000000000 P 4c79b00d8fac48128ebab29da922cecf [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:19:17.350574 27980 tablet_replica.cc:333] T 00000000000000000000000000000000 P 4c79b00d8fac48128ebab29da922cecf: stopping tablet replica
I20260812 06:19:17.363448 27980 master.cc:584] Master@127.27.83.62:38021 shutdown complete.
[       OK ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/1 (5846 ms)
[----------] 2 tests from EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy (11955 ms total)

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