[==========] 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:17:22.890661 26137 internal_mini_cluster.cc:156] Creating distributed mini masters. Addrs: 127.25.134.126:35903
I20260812 06:17:22.892024 26137 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:17:22.892772 26137 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:17:22.899830 26145 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:17:22.899827 26143 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:17:22.900094 26137 server_base.cc:1061] running on GCE node
W20260812 06:17:22.900071 26142 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:17:22.900879 26137 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:17:22.901021 26137 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:17:22.901094 26137 hybrid_clock.cc:648] HybridClock initialized: now 1786515442901090 us; error 0 us; skew 500 ppm
I20260812 06:17:22.903412 26137 webserver.cc:533] Webserver started at http://127.25.134.126:35623/ using document root <none> and password file <none>
I20260812 06:17:22.904122 26137 fs_manager.cc:362] Metadata directory not provided
I20260812 06:17:22.904234 26137 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:17:22.904532 26137 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:17:22.906463 26137 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskZj6Cvv/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515442878833-26137-0/minicluster-data/master-0-root/instance:
uuid: "a91c15e501514c90af15ffbf0669a41a"
format_stamp: "Formatted at 2026-08-12 06:17:22 on dist-test-slave-9zdj"
I20260812 06:17:22.910442 26137 fs_manager.cc:696] Time spent creating directory manager: real 0.003s	user 0.001s	sys 0.003s
I20260812 06:17:22.913087 26150 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:17:22.914321 26137 fs_manager.cc:730] Time spent opening block manager: real 0.003s	user 0.002s	sys 0.001s
I20260812 06:17:22.914500 26137 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskZj6Cvv/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515442878833-26137-0/minicluster-data/master-0-root
uuid: "a91c15e501514c90af15ffbf0669a41a"
format_stamp: "Formatted at 2026-08-12 06:17:22 on dist-test-slave-9zdj"
I20260812 06:17:22.914625 26137 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskZj6Cvv/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515442878833-26137-0/minicluster-data/master-0-root
metadata directory: /tmp/dist-test-taskZj6Cvv/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515442878833-26137-0/minicluster-data/master-0-root
1 data directories: /tmp/dist-test-taskZj6Cvv/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515442878833-26137-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:17:22.928968 26137 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:17:22.929800 26137 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:17:22.929996 26137 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:17:22.938402 26137 rpc_server.cc:307] RPC server started. Bound to: 127.25.134.126:35903
I20260812 06:17:22.938457 26212 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.25.134.126:35903 every 8 connection(s)
I20260812 06:17:22.940961 26213 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:17:22.947515 26213 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P a91c15e501514c90af15ffbf0669a41a: Bootstrap starting.
I20260812 06:17:22.950258 26213 tablet_bootstrap.cc:654] T 00000000000000000000000000000000 P a91c15e501514c90af15ffbf0669a41a: Neither blocks nor log segments found. Creating new log.
I20260812 06:17:22.951390 26213 log.cc:826] T 00000000000000000000000000000000 P a91c15e501514c90af15ffbf0669a41a: Log is configured to *not* fsync() on all Append() calls
I20260812 06:17:22.953599 26213 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P a91c15e501514c90af15ffbf0669a41a: No bootstrap required, opened a new log
I20260812 06:17:22.956871 26213 raft_consensus.cc:359] T 00000000000000000000000000000000 P a91c15e501514c90af15ffbf0669a41a [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "a91c15e501514c90af15ffbf0669a41a" member_type: VOTER }
I20260812 06:17:22.957073 26213 raft_consensus.cc:385] T 00000000000000000000000000000000 P a91c15e501514c90af15ffbf0669a41a [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:17:22.957118 26213 raft_consensus.cc:740] T 00000000000000000000000000000000 P a91c15e501514c90af15ffbf0669a41a [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: a91c15e501514c90af15ffbf0669a41a, State: Initialized, Role: FOLLOWER
I20260812 06:17:22.957909 26213 consensus_queue.cc:260] T 00000000000000000000000000000000 P a91c15e501514c90af15ffbf0669a41a [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: "a91c15e501514c90af15ffbf0669a41a" member_type: VOTER }
I20260812 06:17:22.958078 26213 raft_consensus.cc:399] T 00000000000000000000000000000000 P a91c15e501514c90af15ffbf0669a41a [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:17:22.958173 26213 raft_consensus.cc:493] T 00000000000000000000000000000000 P a91c15e501514c90af15ffbf0669a41a [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:17:22.958334 26213 raft_consensus.cc:3060] T 00000000000000000000000000000000 P a91c15e501514c90af15ffbf0669a41a [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:17:22.959275 26213 raft_consensus.cc:515] T 00000000000000000000000000000000 P a91c15e501514c90af15ffbf0669a41a [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "a91c15e501514c90af15ffbf0669a41a" member_type: VOTER }
I20260812 06:17:22.959817 26213 leader_election.cc:304] T 00000000000000000000000000000000 P a91c15e501514c90af15ffbf0669a41a [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: a91c15e501514c90af15ffbf0669a41a; no voters: 
I20260812 06:17:22.960232 26213 leader_election.cc:290] T 00000000000000000000000000000000 P a91c15e501514c90af15ffbf0669a41a [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:17:22.960513 26216 raft_consensus.cc:2804] T 00000000000000000000000000000000 P a91c15e501514c90af15ffbf0669a41a [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:17:22.960829 26216 raft_consensus.cc:697] T 00000000000000000000000000000000 P a91c15e501514c90af15ffbf0669a41a [term 1 LEADER]: Becoming Leader. State: Replica: a91c15e501514c90af15ffbf0669a41a, State: Running, Role: LEADER
I20260812 06:17:22.961257 26216 consensus_queue.cc:237] T 00000000000000000000000000000000 P a91c15e501514c90af15ffbf0669a41a [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: "a91c15e501514c90af15ffbf0669a41a" member_type: VOTER }
I20260812 06:17:22.961511 26213 sys_catalog.cc:565] T 00000000000000000000000000000000 P a91c15e501514c90af15ffbf0669a41a [sys.catalog]: configured and running, proceeding with master startup.
I20260812 06:17:22.963502 26218 sys_catalog.cc:455] T 00000000000000000000000000000000 P a91c15e501514c90af15ffbf0669a41a [sys.catalog]: SysCatalogTable state changed. Reason: New leader a91c15e501514c90af15ffbf0669a41a. Latest consensus state: current_term: 1 leader_uuid: "a91c15e501514c90af15ffbf0669a41a" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "a91c15e501514c90af15ffbf0669a41a" member_type: VOTER } }
I20260812 06:17:22.963795 26218 sys_catalog.cc:458] T 00000000000000000000000000000000 P a91c15e501514c90af15ffbf0669a41a [sys.catalog]: This master's current role is: LEADER
I20260812 06:17:22.964067 26137 internal_mini_cluster.cc:184] Waiting to initialize catalog manager on master 0
I20260812 06:17:22.963519 26217 sys_catalog.cc:455] T 00000000000000000000000000000000 P a91c15e501514c90af15ffbf0669a41a [sys.catalog]: SysCatalogTable state changed. Reason: RaftConsensus started. Latest consensus state: current_term: 1 leader_uuid: "a91c15e501514c90af15ffbf0669a41a" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "a91c15e501514c90af15ffbf0669a41a" member_type: VOTER } }
I20260812 06:17:22.964183 26217 sys_catalog.cc:458] T 00000000000000000000000000000000 P a91c15e501514c90af15ffbf0669a41a [sys.catalog]: This master's current role is: LEADER
I20260812 06:17:22.964241 26231 catalog_manager.cc:1511] Loading table and tablet metadata into memory...
I20260812 06:17:22.966861 26231 catalog_manager.cc:1520] Initializing Kudu cluster ID...
I20260812 06:17:22.972332 26231 catalog_manager.cc:1383] Generated new cluster ID: ec9ae043b21641d3b1577e01538980b7
I20260812 06:17:22.972440 26231 catalog_manager.cc:1531] Initializing Kudu internal certificate authority...
I20260812 06:17:22.992336 26231 catalog_manager.cc:1406] Generated new certificate authority record
I20260812 06:17:22.993278 26231 catalog_manager.cc:1540] Loading token signing keys...
I20260812 06:17:23.000772 26231 catalog_manager.cc:6092] T 00000000000000000000000000000000 P a91c15e501514c90af15ffbf0669a41a: Generated new TSK 0
I20260812 06:17:23.001545 26231 catalog_manager.cc:1550] Initializing in-progress tserver states...
I20260812 06:17:23.029453 26137 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:17:23.033176 26237 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:17:23.033365 26242 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:17:23.033390 26239 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:17:23.033602 26137 server_base.cc:1061] running on GCE node
I20260812 06:17:23.033876 26137 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:17:23.033955 26137 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:17:23.033984 26137 hybrid_clock.cc:648] HybridClock initialized: now 1786515443033983 us; error 0 us; skew 500 ppm
I20260812 06:17:23.035195 26137 webserver.cc:533] Webserver started at http://127.25.134.65:37215/ using document root <none> and password file <none>
I20260812 06:17:23.035413 26137 fs_manager.cc:362] Metadata directory not provided
I20260812 06:17:23.035497 26137 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:17:23.035589 26137 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:17:23.036055 26137 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskZj6Cvv/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515442878833-26137-0/minicluster-data/ts-0-root/instance:
uuid: "c26dd947a8e24bafa03b6f777a994afa"
format_stamp: "Formatted at 2026-08-12 06:17:23 on dist-test-slave-9zdj"
I20260812 06:17:23.037879 26137 fs_manager.cc:696] Time spent creating directory manager: real 0.002s	user 0.000s	sys 0.002s
I20260812 06:17:23.039136 26247 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:17:23.039539 26137 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.001s	sys 0.001s
I20260812 06:17:23.039626 26137 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskZj6Cvv/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515442878833-26137-0/minicluster-data/ts-0-root
uuid: "c26dd947a8e24bafa03b6f777a994afa"
format_stamp: "Formatted at 2026-08-12 06:17:23 on dist-test-slave-9zdj"
I20260812 06:17:23.039738 26137 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskZj6Cvv/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515442878833-26137-0/minicluster-data/ts-0-root
metadata directory: /tmp/dist-test-taskZj6Cvv/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515442878833-26137-0/minicluster-data/ts-0-root
1 data directories: /tmp/dist-test-taskZj6Cvv/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515442878833-26137-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:17:23.047426 26137 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:17:23.047979 26137 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:17:23.048606 26137 txn_system_client.cc:432] TxnSystemClient initialization is disabled...
I20260812 06:17:23.049759 26137 ts_tablet_manager.cc:585] Loaded tablet metadata (0 total tablets, 0 live tablets)
I20260812 06:17:23.049849 26137 ts_tablet_manager.cc:531] Time spent load tablet metadata: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:17:23.049932 26137 ts_tablet_manager.cc:616] Registered 0 tablets
I20260812 06:17:23.049976 26137 ts_tablet_manager.cc:595] Time spent register tablets: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:17:23.059831 26137 rpc_server.cc:307] RPC server started. Bound to: 127.25.134.65:33093
I20260812 06:17:23.059964 26320 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.25.134.65:33093 every 8 connection(s)
I20260812 06:17:23.073256 26322 heartbeater.cc:344] Connected to a master server at 127.25.134.126:35903
I20260812 06:17:23.073679 26322 heartbeater.cc:461] Registering TS with master...
I20260812 06:17:23.074229 26322 heartbeater.cc:507] Master 127.25.134.126:35903 requested a full tablet report, sending...
I20260812 06:17:23.076050 26169 ts_manager.cc:194] Registered new tserver with Master: c26dd947a8e24bafa03b6f777a994afa (127.25.134.65:33093)
I20260812 06:17:23.076766 26137 internal_mini_cluster.cc:371] 1 TS(s) registered with all masters after 0.015856842s
I20260812 06:17:23.077710 26169 master_service.cc:502] Signed X509 certificate for tserver {username='slave'} at 127.0.0.1:36382
I20260812 06:17:23.089178 26169 catalog_manager.cc:2283] Servicing CreateTable request from {username='slave'} at 127.0.0.1:36388:
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:17:23.107180 26273 tablet_service.cc:1511] Processing CreateTablet for tablet 5eebf01c804d420f9a1f6f7560b8906a (DEFAULT_TABLE table=heavy-update-compaction-test [id=2101964e45c340598206dd0c176207cc]), partition=
I20260812 06:17:23.107744 26273 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet 5eebf01c804d420f9a1f6f7560b8906a. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:17:23.110944 26341 tablet_bootstrap.cc:492] T 5eebf01c804d420f9a1f6f7560b8906a P c26dd947a8e24bafa03b6f777a994afa: Bootstrap starting.
I20260812 06:17:23.112071 26341 tablet_bootstrap.cc:654] T 5eebf01c804d420f9a1f6f7560b8906a P c26dd947a8e24bafa03b6f777a994afa: Neither blocks nor log segments found. Creating new log.
I20260812 06:17:23.113433 26341 tablet_bootstrap.cc:492] T 5eebf01c804d420f9a1f6f7560b8906a P c26dd947a8e24bafa03b6f777a994afa: No bootstrap required, opened a new log
I20260812 06:17:23.113595 26341 ts_tablet_manager.cc:1403] T 5eebf01c804d420f9a1f6f7560b8906a P c26dd947a8e24bafa03b6f777a994afa: Time spent bootstrapping tablet: real 0.003s	user 0.002s	sys 0.000s
I20260812 06:17:23.114154 26341 raft_consensus.cc:359] T 5eebf01c804d420f9a1f6f7560b8906a P c26dd947a8e24bafa03b6f777a994afa [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "c26dd947a8e24bafa03b6f777a994afa" member_type: VOTER last_known_addr { host: "127.25.134.65" port: 33093 } }
I20260812 06:17:23.114310 26341 raft_consensus.cc:385] T 5eebf01c804d420f9a1f6f7560b8906a P c26dd947a8e24bafa03b6f777a994afa [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:17:23.114359 26341 raft_consensus.cc:740] T 5eebf01c804d420f9a1f6f7560b8906a P c26dd947a8e24bafa03b6f777a994afa [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: c26dd947a8e24bafa03b6f777a994afa, State: Initialized, Role: FOLLOWER
I20260812 06:17:23.114543 26341 consensus_queue.cc:260] T 5eebf01c804d420f9a1f6f7560b8906a P c26dd947a8e24bafa03b6f777a994afa [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: "c26dd947a8e24bafa03b6f777a994afa" member_type: VOTER last_known_addr { host: "127.25.134.65" port: 33093 } }
I20260812 06:17:23.114686 26341 raft_consensus.cc:399] T 5eebf01c804d420f9a1f6f7560b8906a P c26dd947a8e24bafa03b6f777a994afa [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:17:23.114785 26341 raft_consensus.cc:493] T 5eebf01c804d420f9a1f6f7560b8906a P c26dd947a8e24bafa03b6f777a994afa [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:17:23.114872 26341 raft_consensus.cc:3060] T 5eebf01c804d420f9a1f6f7560b8906a P c26dd947a8e24bafa03b6f777a994afa [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:17:23.115828 26341 raft_consensus.cc:515] T 5eebf01c804d420f9a1f6f7560b8906a P c26dd947a8e24bafa03b6f777a994afa [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "c26dd947a8e24bafa03b6f777a994afa" member_type: VOTER last_known_addr { host: "127.25.134.65" port: 33093 } }
I20260812 06:17:23.116024 26341 leader_election.cc:304] T 5eebf01c804d420f9a1f6f7560b8906a P c26dd947a8e24bafa03b6f777a994afa [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: c26dd947a8e24bafa03b6f777a994afa; no voters: 
I20260812 06:17:23.116299 26341 leader_election.cc:290] T 5eebf01c804d420f9a1f6f7560b8906a P c26dd947a8e24bafa03b6f777a994afa [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:17:23.116418 26343 raft_consensus.cc:2804] T 5eebf01c804d420f9a1f6f7560b8906a P c26dd947a8e24bafa03b6f777a994afa [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:17:23.116701 26341 ts_tablet_manager.cc:1434] T 5eebf01c804d420f9a1f6f7560b8906a P c26dd947a8e24bafa03b6f777a994afa: Time spent starting tablet: real 0.003s	user 0.003s	sys 0.000s
I20260812 06:17:23.116751 26343 raft_consensus.cc:697] T 5eebf01c804d420f9a1f6f7560b8906a P c26dd947a8e24bafa03b6f777a994afa [term 1 LEADER]: Becoming Leader. State: Replica: c26dd947a8e24bafa03b6f777a994afa, State: Running, Role: LEADER
I20260812 06:17:23.116959 26322 heartbeater.cc:499] Master 127.25.134.126:35903 was elected leader, sending a full tablet report...
I20260812 06:17:23.117122 26343 consensus_queue.cc:237] T 5eebf01c804d420f9a1f6f7560b8906a P c26dd947a8e24bafa03b6f777a994afa [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: "c26dd947a8e24bafa03b6f777a994afa" member_type: VOTER last_known_addr { host: "127.25.134.65" port: 33093 } }
I20260812 06:17:23.120554 26169 catalog_manager.cc:5719] T 5eebf01c804d420f9a1f6f7560b8906a P c26dd947a8e24bafa03b6f777a994afa reported cstate change: term changed from 0 to 1, leader changed from <none> to c26dd947a8e24bafa03b6f777a994afa (127.25.134.65). New cstate: current_term: 1 leader_uuid: "c26dd947a8e24bafa03b6f777a994afa" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "c26dd947a8e24bafa03b6f777a994afa" member_type: VOTER last_known_addr { host: "127.25.134.65" port: 33093 } health_report { overall_health: HEALTHY } } }
I20260812 06:17:23.199225 26137 heavy-update-compaction-itest.cc:215] Time spent inserting: real 0.070s	user 0.029s	sys 0.007s
I20260812 06:17:23.312698 26323 maintenance_manager.cc:419] P c26dd947a8e24bafa03b6f777a994afa: Scheduling FlushMRSOp(5eebf01c804d420f9a1f6f7560b8906a): perf score=11.117440
I20260812 06:17:23.474426 26253 maintenance_manager.cc:643] P c26dd947a8e24bafa03b6f777a994afa: FlushMRSOp(5eebf01c804d420f9a1f6f7560b8906a) complete. Timing: real 0.161s	user 0.125s	sys 0.035s Metrics: {"bytes_written":12307491,"cfile_init":1,"compiler_manager_pool.queue_time_us":233,"delete_count":0,"dirs.queue_time_us":52,"dirs.run_cpu_time_us":247,"dirs.run_wall_time_us":999,"drs_written":1,"lbm_read_time_us":78,"lbm_reads_lt_1ms":4,"lbm_write_time_us":36124,"lbm_writes_lt_1ms":567,"peak_mem_usage":0,"reinsert_count":0,"rows_written":103,"spinlock_wait_cycles":397056,"thread_start_us":141,"threads_started":1,"update_count":1500}
I20260812 06:17:23.475811 26323 maintenance_manager.cc:419] P c26dd947a8e24bafa03b6f777a994afa: Scheduling LogGCOp(5eebf01c804d420f9a1f6f7560b8906a): free 20290830 bytes of WAL
I20260812 06:17:23.476150 26253 log_reader.cc:385] T 5eebf01c804d420f9a1f6f7560b8906a: removed 2 log segments from log reader
I20260812 06:17:23.476238 26253 log.cc:1079] T 5eebf01c804d420f9a1f6f7560b8906a P c26dd947a8e24bafa03b6f777a994afa: Deleting log segment in path: /tmp/dist-test-taskZj6Cvv/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515442878833-26137-0/minicluster-data/ts-0-root/wals/5eebf01c804d420f9a1f6f7560b8906a/wal-000000001 (ops 1-6)
I20260812 06:17:23.476325 26253 log.cc:1079] T 5eebf01c804d420f9a1f6f7560b8906a P c26dd947a8e24bafa03b6f777a994afa: Deleting log segment in path: /tmp/dist-test-taskZj6Cvv/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515442878833-26137-0/minicluster-data/ts-0-root/wals/5eebf01c804d420f9a1f6f7560b8906a/wal-000000002 (ops 7-10)
I20260812 06:17:23.482263 26253 maintenance_manager.cc:643] P c26dd947a8e24bafa03b6f777a994afa: LogGCOp(5eebf01c804d420f9a1f6f7560b8906a) complete. Timing: real 0.006s	user 0.000s	sys 0.005s Metrics: {}
I20260812 06:17:23.482875 26323 maintenance_manager.cc:419] P c26dd947a8e24bafa03b6f777a994afa: Scheduling FlushDeltaMemStoresOp(5eebf01c804d420f9a1f6f7560b8906a): perf score=3.181125
I20260812 06:17:23.500051 26253 maintenance_manager.cc:643] P c26dd947a8e24bafa03b6f777a994afa: FlushDeltaMemStoresOp(5eebf01c804d420f9a1f6f7560b8906a) complete. Timing: real 0.017s	user 0.014s	sys 0.001s Metrics: {"bytes_written":4964166,"delete_count":0,"lbm_write_time_us":6861,"lbm_writes_lt_1ms":124,"reinsert_count":0,"update_count":605}
I20260812 06:17:23.500577 26323 maintenance_manager.cc:419] P c26dd947a8e24bafa03b6f777a994afa: Scheduling UndoDeltaBlockGCOp(5eebf01c804d420f9a1f6f7560b8906a): 8616791 bytes on disk
I20260812 06:17:23.501219 26253 maintenance_manager.cc:643] P c26dd947a8e24bafa03b6f777a994afa: UndoDeltaBlockGCOp(5eebf01c804d420f9a1f6f7560b8906a) 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:17:23.501787 26323 maintenance_manager.cc:419] P c26dd947a8e24bafa03b6f777a994afa: Scheduling FlushDeltaMemStoresOp(5eebf01c804d420f9a1f6f7560b8906a): perf score=1.196750
I20260812 06:17:23.512820 26253 maintenance_manager.cc:643] P c26dd947a8e24bafa03b6f777a994afa: FlushDeltaMemStoresOp(5eebf01c804d420f9a1f6f7560b8906a) complete. Timing: real 0.011s	user 0.005s	sys 0.004s Metrics: {"bytes_written":2830880,"delete_count":0,"lbm_write_time_us":4135,"lbm_writes_lt_1ms":72,"reinsert_count":0,"update_count":345}
I20260812 06:17:23.513338 26323 maintenance_manager.cc:419] P c26dd947a8e24bafa03b6f777a994afa: Scheduling MajorDeltaCompactionOp(5eebf01c804d420f9a1f6f7560b8906a): perf score=1.000000
I20260812 06:17:23.682349 26253 maintenance_manager.cc:643] P c26dd947a8e24bafa03b6f777a994afa: MajorDeltaCompactionOp(5eebf01c804d420f9a1f6f7560b8906a) complete. Timing: real 0.169s	user 0.135s	sys 0.032s Metrics: {"cfile_cache_miss":523,"cfile_cache_miss_bytes":24323572,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":789,"lbm_read_time_us":11650,"lbm_reads_lt_1ms":559,"lbm_write_time_us":32309,"lbm_writes_lt_1ms":533,"peak_mem_usage":61665166,"reinsert_count":0,"thread_start_us":350,"threads_started":5,"update_count":2450}
I20260812 06:17:23.682824 26323 maintenance_manager.cc:419] P c26dd947a8e24bafa03b6f777a994afa: Scheduling FlushDeltaMemStoresOp(5eebf01c804d420f9a1f6f7560b8906a): perf score=11.118625
I20260812 06:17:23.733057 26253 maintenance_manager.cc:643] P c26dd947a8e24bafa03b6f777a994afa: FlushDeltaMemStoresOp(5eebf01c804d420f9a1f6f7560b8906a) complete. Timing: real 0.050s	user 0.026s	sys 0.017s Metrics: {"bytes_written":12717735,"delete_count":0,"lbm_write_time_us":20174,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:17:23.733558 26323 maintenance_manager.cc:419] P c26dd947a8e24bafa03b6f777a994afa: Scheduling FlushDeltaMemStoresOp(5eebf01c804d420f9a1f6f7560b8906a): perf score=2.188937
I20260812 06:17:23.750583 26253 maintenance_manager.cc:643] P c26dd947a8e24bafa03b6f777a994afa: FlushDeltaMemStoresOp(5eebf01c804d420f9a1f6f7560b8906a) complete. Timing: real 0.017s	user 0.014s	sys 0.002s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6645,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:23.751207 26323 maintenance_manager.cc:419] P c26dd947a8e24bafa03b6f777a994afa: Scheduling FlushDeltaMemStoresOp(5eebf01c804d420f9a1f6f7560b8906a): perf score=2.188937
I20260812 06:17:23.763239 26253 maintenance_manager.cc:643] P c26dd947a8e24bafa03b6f777a994afa: FlushDeltaMemStoresOp(5eebf01c804d420f9a1f6f7560b8906a) complete. Timing: real 0.012s	user 0.000s	sys 0.010s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":4414,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:17:23.763734 26323 maintenance_manager.cc:419] P c26dd947a8e24bafa03b6f777a994afa: Scheduling MajorDeltaCompactionOp(5eebf01c804d420f9a1f6f7560b8906a): perf score=1.000000
I20260812 06:17:23.923259 26253 maintenance_manager.cc:643] P c26dd947a8e24bafa03b6f777a994afa: MajorDeltaCompactionOp(5eebf01c804d420f9a1f6f7560b8906a) complete. Timing: real 0.159s	user 0.129s	sys 0.028s Metrics: {"cfile_cache_miss":533,"cfile_cache_miss_bytes":24733834,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":882,"lbm_read_time_us":12345,"lbm_reads_lt_1ms":573,"lbm_write_time_us":31313,"lbm_writes_lt_1ms":543,"mutex_wait_us":376,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":896,"update_count":2500}
I20260812 06:17:23.923873 26323 maintenance_manager.cc:419] P c26dd947a8e24bafa03b6f777a994afa: Scheduling FlushDeltaMemStoresOp(5eebf01c804d420f9a1f6f7560b8906a): perf score=10.126437
I20260812 06:17:23.970427 26253 maintenance_manager.cc:643] P c26dd947a8e24bafa03b6f777a994afa: FlushDeltaMemStoresOp(5eebf01c804d420f9a1f6f7560b8906a) complete. Timing: real 0.046s	user 0.029s	sys 0.016s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":21747,"lbm_writes_1-10_ms":2,"lbm_writes_lt_1ms":301,"reinsert_count":0,"update_count":1500}
I20260812 06:17:23.971055 26323 maintenance_manager.cc:419] P c26dd947a8e24bafa03b6f777a994afa: Scheduling FlushDeltaMemStoresOp(5eebf01c804d420f9a1f6f7560b8906a): perf score=2.188937
I20260812 06:17:23.987576 26253 maintenance_manager.cc:643] P c26dd947a8e24bafa03b6f777a994afa: FlushDeltaMemStoresOp(5eebf01c804d420f9a1f6f7560b8906a) complete. Timing: real 0.016s	user 0.006s	sys 0.009s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6451,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:23.988312 26323 maintenance_manager.cc:419] P c26dd947a8e24bafa03b6f777a994afa: Scheduling MajorDeltaCompactionOp(5eebf01c804d420f9a1f6f7560b8906a): perf score=1.000000
I20260812 06:17:24.135785 26253 maintenance_manager.cc:643] P c26dd947a8e24bafa03b6f777a994afa: MajorDeltaCompactionOp(5eebf01c804d420f9a1f6f7560b8906a) complete. Timing: real 0.147s	user 0.112s	sys 0.034s 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":924,"lbm_read_time_us":10263,"lbm_reads_lt_1ms":472,"lbm_write_time_us":26965,"lbm_writes_lt_1ms":443,"mutex_wait_us":122,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":2688,"update_count":2000}
I20260812 06:17:24.136636 26323 maintenance_manager.cc:419] P c26dd947a8e24bafa03b6f777a994afa: Scheduling FlushDeltaMemStoresOp(5eebf01c804d420f9a1f6f7560b8906a): perf score=10.126437
I20260812 06:17:24.192073 26253 maintenance_manager.cc:643] P c26dd947a8e24bafa03b6f777a994afa: FlushDeltaMemStoresOp(5eebf01c804d420f9a1f6f7560b8906a) complete. Timing: real 0.055s	user 0.030s	sys 0.020s Metrics: {"bytes_written":12307489,"delete_count":0,"lbm_write_time_us":18632,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:17:24.192644 26323 maintenance_manager.cc:419] P c26dd947a8e24bafa03b6f777a994afa: Scheduling FlushDeltaMemStoresOp(5eebf01c804d420f9a1f6f7560b8906a): perf score=2.188937
I20260812 06:17:24.204308 26253 maintenance_manager.cc:643] P c26dd947a8e24bafa03b6f777a994afa: FlushDeltaMemStoresOp(5eebf01c804d420f9a1f6f7560b8906a) complete. Timing: real 0.011s	user 0.006s	sys 0.003s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4653,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:24.204846 26323 maintenance_manager.cc:419] P c26dd947a8e24bafa03b6f777a994afa: Scheduling MajorDeltaCompactionOp(5eebf01c804d420f9a1f6f7560b8906a): perf score=1.000000
I20260812 06:17:24.361161 26253 maintenance_manager.cc:643] P c26dd947a8e24bafa03b6f777a994afa: MajorDeltaCompactionOp(5eebf01c804d420f9a1f6f7560b8906a) complete. Timing: real 0.156s	user 0.108s	sys 0.048s 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":307,"lbm_read_time_us":12237,"lbm_reads_lt_1ms":472,"lbm_write_time_us":23456,"lbm_writes_lt_1ms":443,"mutex_wait_us":60,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":91776,"update_count":2000}
I20260812 06:17:24.361940 26323 maintenance_manager.cc:419] P c26dd947a8e24bafa03b6f777a994afa: Scheduling FlushDeltaMemStoresOp(5eebf01c804d420f9a1f6f7560b8906a): perf score=10.126437
I20260812 06:17:24.399315 26253 maintenance_manager.cc:643] P c26dd947a8e24bafa03b6f777a994afa: FlushDeltaMemStoresOp(5eebf01c804d420f9a1f6f7560b8906a) complete. Timing: real 0.037s	user 0.031s	sys 0.004s Metrics: {"bytes_written":12307491,"delete_count":0,"lbm_write_time_us":15486,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:17:24.399930 26323 maintenance_manager.cc:419] P c26dd947a8e24bafa03b6f777a994afa: Scheduling MajorDeltaCompactionOp(5eebf01c804d420f9a1f6f7560b8906a): perf score=1.000000
I20260812 06:17:24.516220 26253 maintenance_manager.cc:643] P c26dd947a8e24bafa03b6f777a994afa: MajorDeltaCompactionOp(5eebf01c804d420f9a1f6f7560b8906a) complete. Timing: real 0.116s	user 0.095s	sys 0.020s Metrics: {"cfile_cache_miss":331,"cfile_cache_miss_bytes":16528782,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":1,"delta_iterators_relevant":1,"dirs.queue_time_us":708,"lbm_read_time_us":7850,"lbm_reads_lt_1ms":363,"lbm_write_time_us":21049,"lbm_writes_lt_1ms":343,"mutex_wait_us":293,"peak_mem_usage":38262756,"reinsert_count":0,"spinlock_wait_cycles":5760,"update_count":1500}
I20260812 06:17:24.516929 26323 maintenance_manager.cc:419] P c26dd947a8e24bafa03b6f777a994afa: Scheduling FlushDeltaMemStoresOp(5eebf01c804d420f9a1f6f7560b8906a): perf score=10.126437
I20260812 06:17:24.564746 26253 maintenance_manager.cc:643] P c26dd947a8e24bafa03b6f777a994afa: FlushDeltaMemStoresOp(5eebf01c804d420f9a1f6f7560b8906a) complete. Timing: real 0.048s	user 0.023s	sys 0.019s Metrics: {"bytes_written":12307489,"delete_count":0,"lbm_write_time_us":19483,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":302,"reinsert_count":0,"update_count":1500}
I20260812 06:17:24.565347 26323 maintenance_manager.cc:419] P c26dd947a8e24bafa03b6f777a994afa: Scheduling FlushDeltaMemStoresOp(5eebf01c804d420f9a1f6f7560b8906a): perf score=2.188937
I20260812 06:17:24.577140 26253 maintenance_manager.cc:643] P c26dd947a8e24bafa03b6f777a994afa: FlushDeltaMemStoresOp(5eebf01c804d420f9a1f6f7560b8906a) complete. Timing: real 0.012s	user 0.006s	sys 0.003s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4174,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:24.577924 26323 maintenance_manager.cc:419] P c26dd947a8e24bafa03b6f777a994afa: Scheduling MajorDeltaCompactionOp(5eebf01c804d420f9a1f6f7560b8906a): perf score=1.000000
I20260812 06:17:24.709283 26253 maintenance_manager.cc:643] P c26dd947a8e24bafa03b6f777a994afa: MajorDeltaCompactionOp(5eebf01c804d420f9a1f6f7560b8906a) complete. Timing: real 0.131s	user 0.098s	sys 0.033s 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":179,"lbm_read_time_us":10449,"lbm_reads_lt_1ms":472,"lbm_write_time_us":25082,"lbm_writes_lt_1ms":443,"mutex_wait_us":48,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":2432,"update_count":2000}
I20260812 06:17:24.709949 26323 maintenance_manager.cc:419] P c26dd947a8e24bafa03b6f777a994afa: Scheduling FlushDeltaMemStoresOp(5eebf01c804d420f9a1f6f7560b8906a): perf score=10.126437
I20260812 06:17:24.764917 26253 maintenance_manager.cc:643] P c26dd947a8e24bafa03b6f777a994afa: FlushDeltaMemStoresOp(5eebf01c804d420f9a1f6f7560b8906a) complete. Timing: real 0.055s	user 0.024s	sys 0.019s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":15929,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:17:24.765508 26323 maintenance_manager.cc:419] P c26dd947a8e24bafa03b6f777a994afa: Scheduling FlushDeltaMemStoresOp(5eebf01c804d420f9a1f6f7560b8906a): perf score=2.188937
I20260812 06:17:24.776615 26253 maintenance_manager.cc:643] P c26dd947a8e24bafa03b6f777a994afa: FlushDeltaMemStoresOp(5eebf01c804d420f9a1f6f7560b8906a) complete. Timing: real 0.011s	user 0.005s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4424,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:24.777163 26323 maintenance_manager.cc:419] P c26dd947a8e24bafa03b6f777a994afa: Scheduling FlushMRSOp(5eebf01c804d420f9a1f6f7560b8906a): perf score=1.000000
I20260812 06:17:24.821012 26253 maintenance_manager.cc:643] P c26dd947a8e24bafa03b6f777a994afa: FlushMRSOp(5eebf01c804d420f9a1f6f7560b8906a) complete. Timing: real 0.044s	user 0.034s	sys 0.000s Metrics: {"bytes_written":1152509,"cfile_init":1,"dirs.queue_time_us":87,"dirs.run_cpu_time_us":268,"dirs.run_wall_time_us":2147,"drs_written":1,"lbm_read_time_us":41,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1437,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":28}
I20260812 06:17:24.822057 26323 maintenance_manager.cc:419] P c26dd947a8e24bafa03b6f777a994afa: Scheduling LogGCOp(5eebf01c804d420f9a1f6f7560b8906a): free 108535458 bytes of WAL
I20260812 06:17:24.822336 26253 log_reader.cc:385] T 5eebf01c804d420f9a1f6f7560b8906a: removed 11 log segments from log reader
I20260812 06:17:24.822386 26253 log.cc:1079] T 5eebf01c804d420f9a1f6f7560b8906a P c26dd947a8e24bafa03b6f777a994afa: Deleting log segment in path: /tmp/dist-test-taskZj6Cvv/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515442878833-26137-0/minicluster-data/ts-0-root/wals/5eebf01c804d420f9a1f6f7560b8906a/wal-000000003 (ops 11-15)
I20260812 06:17:24.822419 26253 log.cc:1079] T 5eebf01c804d420f9a1f6f7560b8906a P c26dd947a8e24bafa03b6f777a994afa: Deleting log segment in path: /tmp/dist-test-taskZj6Cvv/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515442878833-26137-0/minicluster-data/ts-0-root/wals/5eebf01c804d420f9a1f6f7560b8906a/wal-000000004 (ops 16-20)
I20260812 06:17:24.822494 26253 log.cc:1079] T 5eebf01c804d420f9a1f6f7560b8906a P c26dd947a8e24bafa03b6f777a994afa: Deleting log segment in path: /tmp/dist-test-taskZj6Cvv/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515442878833-26137-0/minicluster-data/ts-0-root/wals/5eebf01c804d420f9a1f6f7560b8906a/wal-000000005 (ops 21-24)
I20260812 06:17:24.822566 26253 log.cc:1079] T 5eebf01c804d420f9a1f6f7560b8906a P c26dd947a8e24bafa03b6f777a994afa: Deleting log segment in path: /tmp/dist-test-taskZj6Cvv/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515442878833-26137-0/minicluster-data/ts-0-root/wals/5eebf01c804d420f9a1f6f7560b8906a/wal-000000006 (ops 25-29)
I20260812 06:17:24.822610 26253 log.cc:1079] T 5eebf01c804d420f9a1f6f7560b8906a P c26dd947a8e24bafa03b6f777a994afa: Deleting log segment in path: /tmp/dist-test-taskZj6Cvv/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515442878833-26137-0/minicluster-data/ts-0-root/wals/5eebf01c804d420f9a1f6f7560b8906a/wal-000000007 (ops 30-34)
I20260812 06:17:24.822664 26253 log.cc:1079] T 5eebf01c804d420f9a1f6f7560b8906a P c26dd947a8e24bafa03b6f777a994afa: Deleting log segment in path: /tmp/dist-test-taskZj6Cvv/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515442878833-26137-0/minicluster-data/ts-0-root/wals/5eebf01c804d420f9a1f6f7560b8906a/wal-000000008 (ops 35-39)
I20260812 06:17:24.822707 26253 log.cc:1079] T 5eebf01c804d420f9a1f6f7560b8906a P c26dd947a8e24bafa03b6f777a994afa: Deleting log segment in path: /tmp/dist-test-taskZj6Cvv/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515442878833-26137-0/minicluster-data/ts-0-root/wals/5eebf01c804d420f9a1f6f7560b8906a/wal-000000009 (ops 40-44)
I20260812 06:17:24.822752 26253 log.cc:1079] T 5eebf01c804d420f9a1f6f7560b8906a P c26dd947a8e24bafa03b6f777a994afa: Deleting log segment in path: /tmp/dist-test-taskZj6Cvv/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515442878833-26137-0/minicluster-data/ts-0-root/wals/5eebf01c804d420f9a1f6f7560b8906a/wal-000000010 (ops 45-48)
I20260812 06:17:24.822794 26253 log.cc:1079] T 5eebf01c804d420f9a1f6f7560b8906a P c26dd947a8e24bafa03b6f777a994afa: Deleting log segment in path: /tmp/dist-test-taskZj6Cvv/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515442878833-26137-0/minicluster-data/ts-0-root/wals/5eebf01c804d420f9a1f6f7560b8906a/wal-000000011 (ops 49-53)
I20260812 06:17:24.822836 26253 log.cc:1079] T 5eebf01c804d420f9a1f6f7560b8906a P c26dd947a8e24bafa03b6f777a994afa: Deleting log segment in path: /tmp/dist-test-taskZj6Cvv/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515442878833-26137-0/minicluster-data/ts-0-root/wals/5eebf01c804d420f9a1f6f7560b8906a/wal-000000012 (ops 54-58)
I20260812 06:17:24.822880 26253 log.cc:1079] T 5eebf01c804d420f9a1f6f7560b8906a P c26dd947a8e24bafa03b6f777a994afa: Deleting log segment in path: /tmp/dist-test-taskZj6Cvv/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515442878833-26137-0/minicluster-data/ts-0-root/wals/5eebf01c804d420f9a1f6f7560b8906a/wal-000000013 (ops 59-63)
I20260812 06:17:24.851539 26253 maintenance_manager.cc:643] P c26dd947a8e24bafa03b6f777a994afa: LogGCOp(5eebf01c804d420f9a1f6f7560b8906a) complete. Timing: real 0.029s	user 0.000s	sys 0.027s Metrics: {}
I20260812 06:17:24.852183 26323 maintenance_manager.cc:419] P c26dd947a8e24bafa03b6f777a994afa: Scheduling UndoDeltaBlockGCOp(5eebf01c804d420f9a1f6f7560b8906a): 447 bytes on disk
I20260812 06:17:24.852680 26253 maintenance_manager.cc:643] P c26dd947a8e24bafa03b6f777a994afa: UndoDeltaBlockGCOp(5eebf01c804d420f9a1f6f7560b8906a) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":57,"lbm_reads_lt_1ms":4}
I20260812 06:17:24.853188 26323 maintenance_manager.cc:419] P c26dd947a8e24bafa03b6f777a994afa: Scheduling FlushDeltaMemStoresOp(5eebf01c804d420f9a1f6f7560b8906a): perf score=3.181125
I20260812 06:17:24.869128 26253 maintenance_manager.cc:643] P c26dd947a8e24bafa03b6f777a994afa: FlushDeltaMemStoresOp(5eebf01c804d420f9a1f6f7560b8906a) complete. Timing: real 0.016s	user 0.002s	sys 0.007s Metrics: {"bytes_written":4512903,"delete_count":0,"lbm_write_time_us":4616,"lbm_writes_lt_1ms":113,"reinsert_count":0,"update_count":550}
I20260812 06:17:24.869727 26323 maintenance_manager.cc:419] P c26dd947a8e24bafa03b6f777a994afa: Scheduling FlushDeltaMemStoresOp(5eebf01c804d420f9a1f6f7560b8906a): perf score=2.188937
I20260812 06:17:24.881011 26253 maintenance_manager.cc:643] P c26dd947a8e24bafa03b6f777a994afa: FlushDeltaMemStoresOp(5eebf01c804d420f9a1f6f7560b8906a) complete. Timing: real 0.011s	user 0.001s	sys 0.008s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":4094,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:17:24.881517 26323 maintenance_manager.cc:419] P c26dd947a8e24bafa03b6f777a994afa: Scheduling MajorDeltaCompactionOp(5eebf01c804d420f9a1f6f7560b8906a): perf score=1.000000
I20260812 06:17:25.176378 26253 maintenance_manager.cc:643] P c26dd947a8e24bafa03b6f777a994afa: MajorDeltaCompactionOp(5eebf01c804d420f9a1f6f7560b8906a) complete. Timing: real 0.295s	user 0.185s	sys 0.105s Metrics: {"cfile_cache_miss":634,"cfile_cache_miss_bytes":28836364,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":330,"lbm_read_time_us":15962,"lbm_reads_lt_1ms":674,"lbm_write_time_us":47884,"lbm_writes_lt_1ms":643,"mutex_wait_us":2,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":3584,"thread_start_us":102,"threads_started":1,"update_count":3000}
I20260812 06:17:25.178900 26323 maintenance_manager.cc:419] P c26dd947a8e24bafa03b6f777a994afa: Scheduling FlushDeltaMemStoresOp(5eebf01c804d420f9a1f6f7560b8906a): perf score=18.063937
I20260812 06:17:25.262180 26253 maintenance_manager.cc:643] P c26dd947a8e24bafa03b6f777a994afa: FlushDeltaMemStoresOp(5eebf01c804d420f9a1f6f7560b8906a) complete. Timing: real 0.083s	user 0.043s	sys 0.040s Metrics: {"bytes_written":20512315,"delete_count":0,"lbm_write_time_us":36312,"lbm_writes_lt_1ms":503,"reinsert_count":0,"update_count":2500}
I20260812 06:17:25.262823 26323 maintenance_manager.cc:419] P c26dd947a8e24bafa03b6f777a994afa: Scheduling FlushDeltaMemStoresOp(5eebf01c804d420f9a1f6f7560b8906a): perf score=2.188937
I20260812 06:17:25.290537 26253 maintenance_manager.cc:643] P c26dd947a8e24bafa03b6f777a994afa: FlushDeltaMemStoresOp(5eebf01c804d420f9a1f6f7560b8906a) complete. Timing: real 0.027s	user 0.018s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":7212,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:25.291262 26323 maintenance_manager.cc:419] P c26dd947a8e24bafa03b6f777a994afa: Scheduling FlushDeltaMemStoresOp(5eebf01c804d420f9a1f6f7560b8906a): perf score=2.188937
I20260812 06:17:25.311331 26253 maintenance_manager.cc:643] P c26dd947a8e24bafa03b6f777a994afa: FlushDeltaMemStoresOp(5eebf01c804d420f9a1f6f7560b8906a) complete. Timing: real 0.020s	user 0.010s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":7027,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:25.311944 26323 maintenance_manager.cc:419] P c26dd947a8e24bafa03b6f777a994afa: Scheduling MajorDeltaCompactionOp(5eebf01c804d420f9a1f6f7560b8906a): perf score=1.000000
I20260812 06:17:25.529893 26253 maintenance_manager.cc:643] P c26dd947a8e24bafa03b6f777a994afa: MajorDeltaCompactionOp(5eebf01c804d420f9a1f6f7560b8906a) complete. Timing: real 0.218s	user 0.141s	sys 0.070s Metrics: {"cfile_cache_miss":733,"cfile_cache_miss_bytes":32938668,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":829,"lbm_read_time_us":14450,"lbm_reads_lt_1ms":765,"lbm_write_time_us":38227,"lbm_writes_lt_1ms":743,"mutex_wait_us":460,"peak_mem_usage":87969044,"reinsert_count":0,"spinlock_wait_cycles":20480,"update_count":3500}
I20260812 06:17:25.530606 26323 maintenance_manager.cc:419] P c26dd947a8e24bafa03b6f777a994afa: Scheduling FlushDeltaMemStoresOp(5eebf01c804d420f9a1f6f7560b8906a): perf score=10.126437
I20260812 06:17:25.575726 26253 maintenance_manager.cc:643] P c26dd947a8e24bafa03b6f777a994afa: FlushDeltaMemStoresOp(5eebf01c804d420f9a1f6f7560b8906a) complete. Timing: real 0.045s	user 0.027s	sys 0.014s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":20108,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":302,"reinsert_count":0,"update_count":1500}
I20260812 06:17:25.576275 26323 maintenance_manager.cc:419] P c26dd947a8e24bafa03b6f777a994afa: Scheduling MajorDeltaCompactionOp(5eebf01c804d420f9a1f6f7560b8906a): perf score=1.000000
I20260812 06:17:25.703856 26253 maintenance_manager.cc:643] P c26dd947a8e24bafa03b6f777a994afa: MajorDeltaCompactionOp(5eebf01c804d420f9a1f6f7560b8906a) complete. Timing: real 0.127s	user 0.083s	sys 0.044s Metrics: {"cfile_cache_miss":331,"cfile_cache_miss_bytes":16528781,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":1,"delta_iterators_relevant":1,"dirs.queue_time_us":325,"lbm_read_time_us":11587,"lbm_reads_1-10_ms":1,"lbm_reads_lt_1ms":366,"lbm_write_time_us":18909,"lbm_writes_lt_1ms":343,"mutex_wait_us":25,"peak_mem_usage":38262756,"reinsert_count":0,"spinlock_wait_cycles":13056,"update_count":1500}
I20260812 06:17:25.704505 26323 maintenance_manager.cc:419] P c26dd947a8e24bafa03b6f777a994afa: Scheduling FlushDeltaMemStoresOp(5eebf01c804d420f9a1f6f7560b8906a): perf score=10.126437
I20260812 06:17:25.753793 26253 maintenance_manager.cc:643] P c26dd947a8e24bafa03b6f777a994afa: FlushDeltaMemStoresOp(5eebf01c804d420f9a1f6f7560b8906a) complete. Timing: real 0.049s	user 0.022s	sys 0.027s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":22453,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":302,"reinsert_count":0,"update_count":1500}
I20260812 06:17:25.754412 26323 maintenance_manager.cc:419] P c26dd947a8e24bafa03b6f777a994afa: Scheduling FlushDeltaMemStoresOp(5eebf01c804d420f9a1f6f7560b8906a): perf score=2.188937
I20260812 06:17:25.766299 26253 maintenance_manager.cc:643] P c26dd947a8e24bafa03b6f777a994afa: FlushDeltaMemStoresOp(5eebf01c804d420f9a1f6f7560b8906a) complete. Timing: real 0.012s	user 0.003s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4298,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:25.766961 26323 maintenance_manager.cc:419] P c26dd947a8e24bafa03b6f777a994afa: Scheduling MajorDeltaCompactionOp(5eebf01c804d420f9a1f6f7560b8906a): perf score=1.000000
I20260812 06:17:25.906213 26253 maintenance_manager.cc:643] P c26dd947a8e24bafa03b6f777a994afa: MajorDeltaCompactionOp(5eebf01c804d420f9a1f6f7560b8906a) complete. Timing: real 0.139s	user 0.092s	sys 0.046s 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":1208,"lbm_read_time_us":10449,"lbm_reads_lt_1ms":472,"lbm_write_time_us":24735,"lbm_writes_lt_1ms":443,"mutex_wait_us":322,"peak_mem_usage":50689328,"reinsert_count":0,"update_count":2000}
I20260812 06:17:25.907136 26323 maintenance_manager.cc:419] P c26dd947a8e24bafa03b6f777a994afa: Scheduling FlushDeltaMemStoresOp(5eebf01c804d420f9a1f6f7560b8906a): perf score=10.126437
I20260812 06:17:25.948092 26253 maintenance_manager.cc:643] P c26dd947a8e24bafa03b6f777a994afa: FlushDeltaMemStoresOp(5eebf01c804d420f9a1f6f7560b8906a) complete. Timing: real 0.041s	user 0.005s	sys 0.029s Metrics: {"bytes_written":12307489,"delete_count":0,"lbm_write_time_us":16023,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:17:25.948720 26323 maintenance_manager.cc:419] P c26dd947a8e24bafa03b6f777a994afa: Scheduling FlushDeltaMemStoresOp(5eebf01c804d420f9a1f6f7560b8906a): perf score=2.188937
I20260812 06:17:25.961452 26253 maintenance_manager.cc:643] P c26dd947a8e24bafa03b6f777a994afa: FlushDeltaMemStoresOp(5eebf01c804d420f9a1f6f7560b8906a) complete. Timing: real 0.012s	user 0.003s	sys 0.007s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4783,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:25.962070 26323 maintenance_manager.cc:419] P c26dd947a8e24bafa03b6f777a994afa: Scheduling MajorDeltaCompactionOp(5eebf01c804d420f9a1f6f7560b8906a): perf score=1.000000
I20260812 06:17:26.086804 26253 maintenance_manager.cc:643] P c26dd947a8e24bafa03b6f777a994afa: MajorDeltaCompactionOp(5eebf01c804d420f9a1f6f7560b8906a) complete. Timing: real 0.124s	user 0.103s	sys 0.021s 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":1167,"lbm_read_time_us":9469,"lbm_reads_lt_1ms":472,"lbm_write_time_us":23895,"lbm_writes_lt_1ms":443,"mutex_wait_us":303,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":4864,"update_count":2000}
I20260812 06:17:26.087498 26323 maintenance_manager.cc:419] P c26dd947a8e24bafa03b6f777a994afa: Scheduling FlushDeltaMemStoresOp(5eebf01c804d420f9a1f6f7560b8906a): perf score=10.126437
I20260812 06:17:26.140882 26253 maintenance_manager.cc:643] P c26dd947a8e24bafa03b6f777a994afa: FlushDeltaMemStoresOp(5eebf01c804d420f9a1f6f7560b8906a) complete. Timing: real 0.053s	user 0.030s	sys 0.019s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":18186,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":302,"reinsert_count":0,"update_count":1500}
I20260812 06:17:26.141507 26323 maintenance_manager.cc:419] P c26dd947a8e24bafa03b6f777a994afa: Scheduling FlushDeltaMemStoresOp(5eebf01c804d420f9a1f6f7560b8906a): perf score=2.188937
I20260812 06:17:26.152608 26253 maintenance_manager.cc:643] P c26dd947a8e24bafa03b6f777a994afa: FlushDeltaMemStoresOp(5eebf01c804d420f9a1f6f7560b8906a) complete. Timing: real 0.011s	user 0.005s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4369,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:26.153134 26323 maintenance_manager.cc:419] P c26dd947a8e24bafa03b6f777a994afa: Scheduling MajorDeltaCompactionOp(5eebf01c804d420f9a1f6f7560b8906a): perf score=1.000000
I20260812 06:17:26.309146 26253 maintenance_manager.cc:643] P c26dd947a8e24bafa03b6f777a994afa: MajorDeltaCompactionOp(5eebf01c804d420f9a1f6f7560b8906a) complete. Timing: real 0.156s	user 0.132s	sys 0.024s 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":243,"lbm_read_time_us":11801,"lbm_reads_lt_1ms":472,"lbm_write_time_us":23457,"lbm_writes_lt_1ms":443,"mutex_wait_us":26,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":18944,"update_count":2000}
I20260812 06:17:26.309929 26323 maintenance_manager.cc:419] P c26dd947a8e24bafa03b6f777a994afa: Scheduling FlushDeltaMemStoresOp(5eebf01c804d420f9a1f6f7560b8906a): perf score=10.126437
I20260812 06:17:26.355477 26253 maintenance_manager.cc:643] P c26dd947a8e24bafa03b6f777a994afa: FlushDeltaMemStoresOp(5eebf01c804d420f9a1f6f7560b8906a) complete. Timing: real 0.045s	user 0.022s	sys 0.016s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":17005,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:17:26.356014 26323 maintenance_manager.cc:419] P c26dd947a8e24bafa03b6f777a994afa: Scheduling FlushDeltaMemStoresOp(5eebf01c804d420f9a1f6f7560b8906a): perf score=2.188937
I20260812 06:17:26.372210 26253 maintenance_manager.cc:643] P c26dd947a8e24bafa03b6f777a994afa: FlushDeltaMemStoresOp(5eebf01c804d420f9a1f6f7560b8906a) complete. Timing: real 0.016s	user 0.009s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6108,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:26.372968 26323 maintenance_manager.cc:419] P c26dd947a8e24bafa03b6f777a994afa: Scheduling FlushMRSOp(5eebf01c804d420f9a1f6f7560b8906a): perf score=1.000000
I20260812 06:17:26.405869 26253 maintenance_manager.cc:643] P c26dd947a8e24bafa03b6f777a994afa: FlushMRSOp(5eebf01c804d420f9a1f6f7560b8906a) complete. Timing: real 0.033s	user 0.029s	sys 0.000s Metrics: {"bytes_written":1152508,"cfile_init":1,"dirs.queue_time_us":91,"dirs.run_cpu_time_us":252,"dirs.run_wall_time_us":2113,"drs_written":1,"lbm_read_time_us":68,"lbm_reads_lt_1ms":4,"lbm_write_time_us":2149,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":28}
I20260812 06:17:26.406644 26323 maintenance_manager.cc:419] P c26dd947a8e24bafa03b6f777a994afa: Scheduling LogGCOp(5eebf01c804d420f9a1f6f7560b8906a): free 120553331 bytes of WAL
I20260812 06:17:26.406894 26253 log_reader.cc:385] T 5eebf01c804d420f9a1f6f7560b8906a: removed 12 log segments from log reader
I20260812 06:17:26.406941 26253 log.cc:1079] T 5eebf01c804d420f9a1f6f7560b8906a P c26dd947a8e24bafa03b6f777a994afa: Deleting log segment in path: /tmp/dist-test-taskZj6Cvv/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515442878833-26137-0/minicluster-data/ts-0-root/wals/5eebf01c804d420f9a1f6f7560b8906a/wal-000000014 (ops 64-68)
I20260812 06:17:26.406973 26253 log.cc:1079] T 5eebf01c804d420f9a1f6f7560b8906a P c26dd947a8e24bafa03b6f777a994afa: Deleting log segment in path: /tmp/dist-test-taskZj6Cvv/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515442878833-26137-0/minicluster-data/ts-0-root/wals/5eebf01c804d420f9a1f6f7560b8906a/wal-000000015 (ops 69-72)
I20260812 06:17:26.407043 26253 log.cc:1079] T 5eebf01c804d420f9a1f6f7560b8906a P c26dd947a8e24bafa03b6f777a994afa: Deleting log segment in path: /tmp/dist-test-taskZj6Cvv/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515442878833-26137-0/minicluster-data/ts-0-root/wals/5eebf01c804d420f9a1f6f7560b8906a/wal-000000016 (ops 73-77)
I20260812 06:17:26.407087 26253 log.cc:1079] T 5eebf01c804d420f9a1f6f7560b8906a P c26dd947a8e24bafa03b6f777a994afa: Deleting log segment in path: /tmp/dist-test-taskZj6Cvv/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515442878833-26137-0/minicluster-data/ts-0-root/wals/5eebf01c804d420f9a1f6f7560b8906a/wal-000000017 (ops 78-82)
I20260812 06:17:26.407131 26253 log.cc:1079] T 5eebf01c804d420f9a1f6f7560b8906a P c26dd947a8e24bafa03b6f777a994afa: Deleting log segment in path: /tmp/dist-test-taskZj6Cvv/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515442878833-26137-0/minicluster-data/ts-0-root/wals/5eebf01c804d420f9a1f6f7560b8906a/wal-000000018 (ops 83-87)
I20260812 06:17:26.407177 26253 log.cc:1079] T 5eebf01c804d420f9a1f6f7560b8906a P c26dd947a8e24bafa03b6f777a994afa: Deleting log segment in path: /tmp/dist-test-taskZj6Cvv/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515442878833-26137-0/minicluster-data/ts-0-root/wals/5eebf01c804d420f9a1f6f7560b8906a/wal-000000019 (ops 88-92)
I20260812 06:17:26.407243 26253 log.cc:1079] T 5eebf01c804d420f9a1f6f7560b8906a P c26dd947a8e24bafa03b6f777a994afa: Deleting log segment in path: /tmp/dist-test-taskZj6Cvv/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515442878833-26137-0/minicluster-data/ts-0-root/wals/5eebf01c804d420f9a1f6f7560b8906a/wal-000000020 (ops 93-97)
I20260812 06:17:26.407272 26253 log.cc:1079] T 5eebf01c804d420f9a1f6f7560b8906a P c26dd947a8e24bafa03b6f777a994afa: Deleting log segment in path: /tmp/dist-test-taskZj6Cvv/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515442878833-26137-0/minicluster-data/ts-0-root/wals/5eebf01c804d420f9a1f6f7560b8906a/wal-000000021 (ops 98-102)
I20260812 06:17:26.407313 26253 log.cc:1079] T 5eebf01c804d420f9a1f6f7560b8906a P c26dd947a8e24bafa03b6f777a994afa: Deleting log segment in path: /tmp/dist-test-taskZj6Cvv/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515442878833-26137-0/minicluster-data/ts-0-root/wals/5eebf01c804d420f9a1f6f7560b8906a/wal-000000022 (ops 103-106)
I20260812 06:17:26.407356 26253 log.cc:1079] T 5eebf01c804d420f9a1f6f7560b8906a P c26dd947a8e24bafa03b6f777a994afa: Deleting log segment in path: /tmp/dist-test-taskZj6Cvv/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515442878833-26137-0/minicluster-data/ts-0-root/wals/5eebf01c804d420f9a1f6f7560b8906a/wal-000000023 (ops 107-111)
I20260812 06:17:26.407397 26253 log.cc:1079] T 5eebf01c804d420f9a1f6f7560b8906a P c26dd947a8e24bafa03b6f777a994afa: Deleting log segment in path: /tmp/dist-test-taskZj6Cvv/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515442878833-26137-0/minicluster-data/ts-0-root/wals/5eebf01c804d420f9a1f6f7560b8906a/wal-000000024 (ops 112-116)
I20260812 06:17:26.407439 26253 log.cc:1079] T 5eebf01c804d420f9a1f6f7560b8906a P c26dd947a8e24bafa03b6f777a994afa: Deleting log segment in path: /tmp/dist-test-taskZj6Cvv/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515442878833-26137-0/minicluster-data/ts-0-root/wals/5eebf01c804d420f9a1f6f7560b8906a/wal-000000025 (ops 117-121)
I20260812 06:17:26.435484 26253 maintenance_manager.cc:643] P c26dd947a8e24bafa03b6f777a994afa: LogGCOp(5eebf01c804d420f9a1f6f7560b8906a) complete. Timing: real 0.029s	user 0.000s	sys 0.027s Metrics: {}
I20260812 06:17:26.435931 26323 maintenance_manager.cc:419] P c26dd947a8e24bafa03b6f777a994afa: Scheduling FlushDeltaMemStoresOp(5eebf01c804d420f9a1f6f7560b8906a): perf score=2.188937
I20260812 06:17:26.466194 26253 maintenance_manager.cc:643] P c26dd947a8e24bafa03b6f777a994afa: FlushDeltaMemStoresOp(5eebf01c804d420f9a1f6f7560b8906a) complete. Timing: real 0.030s	user 0.017s	sys 0.007s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6403,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:26.466737 26323 maintenance_manager.cc:419] P c26dd947a8e24bafa03b6f777a994afa: Scheduling UndoDeltaBlockGCOp(5eebf01c804d420f9a1f6f7560b8906a): 448 bytes on disk
I20260812 06:17:26.467212 26253 maintenance_manager.cc:643] P c26dd947a8e24bafa03b6f777a994afa: UndoDeltaBlockGCOp(5eebf01c804d420f9a1f6f7560b8906a) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":63,"lbm_reads_lt_1ms":4}
I20260812 06:17:26.467731 26323 maintenance_manager.cc:419] P c26dd947a8e24bafa03b6f777a994afa: Scheduling FlushDeltaMemStoresOp(5eebf01c804d420f9a1f6f7560b8906a): perf score=2.188937
I20260812 06:17:26.478782 26253 maintenance_manager.cc:643] P c26dd947a8e24bafa03b6f777a994afa: FlushDeltaMemStoresOp(5eebf01c804d420f9a1f6f7560b8906a) complete. Timing: real 0.011s	user 0.009s	sys 0.000s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4260,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:26.479244 26323 maintenance_manager.cc:419] P c26dd947a8e24bafa03b6f777a994afa: Scheduling MajorDeltaCompactionOp(5eebf01c804d420f9a1f6f7560b8906a): perf score=1.000000
I20260812 06:17:26.684352 26253 maintenance_manager.cc:643] P c26dd947a8e24bafa03b6f777a994afa: MajorDeltaCompactionOp(5eebf01c804d420f9a1f6f7560b8906a) complete. Timing: real 0.205s	user 0.147s	sys 0.056s Metrics: {"cfile_cache_miss":634,"cfile_cache_miss_bytes":28836373,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":797,"lbm_read_time_us":16340,"lbm_reads_lt_1ms":674,"lbm_write_time_us":35998,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":642,"mutex_wait_us":101,"peak_mem_usage":75542472,"reinsert_count":0,"thread_start_us":83,"threads_started":1,"update_count":3000}
I20260812 06:17:26.685173 26323 maintenance_manager.cc:419] P c26dd947a8e24bafa03b6f777a994afa: Scheduling FlushDeltaMemStoresOp(5eebf01c804d420f9a1f6f7560b8906a): perf score=14.095187
I20260812 06:17:26.751171 26253 maintenance_manager.cc:643] P c26dd947a8e24bafa03b6f777a994afa: FlushDeltaMemStoresOp(5eebf01c804d420f9a1f6f7560b8906a) complete. Timing: real 0.066s	user 0.029s	sys 0.035s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":24808,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":402,"reinsert_count":0,"update_count":2000}
I20260812 06:17:26.751796 26323 maintenance_manager.cc:419] P c26dd947a8e24bafa03b6f777a994afa: Scheduling FlushDeltaMemStoresOp(5eebf01c804d420f9a1f6f7560b8906a): perf score=2.188937
I20260812 06:17:26.766028 26253 maintenance_manager.cc:643] P c26dd947a8e24bafa03b6f777a994afa: FlushDeltaMemStoresOp(5eebf01c804d420f9a1f6f7560b8906a) complete. Timing: real 0.014s	user 0.014s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5126,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:26.766707 26323 maintenance_manager.cc:419] P c26dd947a8e24bafa03b6f777a994afa: Scheduling MajorDeltaCompactionOp(5eebf01c804d420f9a1f6f7560b8906a): perf score=1.000000
I20260812 06:17:26.959008 26253 maintenance_manager.cc:643] P c26dd947a8e24bafa03b6f777a994afa: MajorDeltaCompactionOp(5eebf01c804d420f9a1f6f7560b8906a) complete. Timing: real 0.192s	user 0.123s	sys 0.060s 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":350,"lbm_read_time_us":13036,"lbm_reads_lt_1ms":572,"lbm_write_time_us":31299,"lbm_writes_lt_1ms":543,"peak_mem_usage":63115900,"reinsert_count":0,"update_count":2500}
I20260812 06:17:26.959718 26323 maintenance_manager.cc:419] P c26dd947a8e24bafa03b6f777a994afa: Scheduling FlushDeltaMemStoresOp(5eebf01c804d420f9a1f6f7560b8906a): perf score=14.095187
I20260812 06:17:27.020421 26253 maintenance_manager.cc:643] P c26dd947a8e24bafa03b6f777a994afa: FlushDeltaMemStoresOp(5eebf01c804d420f9a1f6f7560b8906a) complete. Timing: real 0.060s	user 0.037s	sys 0.021s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":28393,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":402,"reinsert_count":0,"update_count":2000}
I20260812 06:17:27.020939 26323 maintenance_manager.cc:419] P c26dd947a8e24bafa03b6f777a994afa: Scheduling FlushDeltaMemStoresOp(5eebf01c804d420f9a1f6f7560b8906a): perf score=2.188937
I20260812 06:17:27.038223 26253 maintenance_manager.cc:643] P c26dd947a8e24bafa03b6f777a994afa: FlushDeltaMemStoresOp(5eebf01c804d420f9a1f6f7560b8906a) complete. Timing: real 0.017s	user 0.011s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5113,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:27.043329 26323 maintenance_manager.cc:419] P c26dd947a8e24bafa03b6f777a994afa: Scheduling MajorDeltaCompactionOp(5eebf01c804d420f9a1f6f7560b8906a): perf score=1.000000
I20260812 06:17:27.244870 26253 maintenance_manager.cc:643] P c26dd947a8e24bafa03b6f777a994afa: MajorDeltaCompactionOp(5eebf01c804d420f9a1f6f7560b8906a) complete. Timing: real 0.201s	user 0.123s	sys 0.072s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24733724,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":1442,"lbm_read_time_us":15309,"lbm_reads_lt_1ms":564,"lbm_write_time_us":32785,"lbm_writes_lt_1ms":543,"mutex_wait_us":341,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":4096,"update_count":2500}
I20260812 06:17:27.245683 26323 maintenance_manager.cc:419] P c26dd947a8e24bafa03b6f777a994afa: Scheduling FlushDeltaMemStoresOp(5eebf01c804d420f9a1f6f7560b8906a): perf score=14.095187
I20260812 06:17:27.305488 26253 maintenance_manager.cc:643] P c26dd947a8e24bafa03b6f777a994afa: FlushDeltaMemStoresOp(5eebf01c804d420f9a1f6f7560b8906a) complete. Timing: real 0.060s	user 0.022s	sys 0.025s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":23011,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:17:27.306167 26323 maintenance_manager.cc:419] P c26dd947a8e24bafa03b6f777a994afa: Scheduling FlushDeltaMemStoresOp(5eebf01c804d420f9a1f6f7560b8906a): perf score=2.188937
I20260812 06:17:27.319135 26253 maintenance_manager.cc:643] P c26dd947a8e24bafa03b6f777a994afa: FlushDeltaMemStoresOp(5eebf01c804d420f9a1f6f7560b8906a) complete. Timing: real 0.013s	user 0.005s	sys 0.006s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4508,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:27.319813 26323 maintenance_manager.cc:419] P c26dd947a8e24bafa03b6f777a994afa: Scheduling MajorDeltaCompactionOp(5eebf01c804d420f9a1f6f7560b8906a): perf score=1.000000
I20260812 06:17:27.499996 26253 maintenance_manager.cc:643] P c26dd947a8e24bafa03b6f777a994afa: MajorDeltaCompactionOp(5eebf01c804d420f9a1f6f7560b8906a) complete. Timing: real 0.180s	user 0.124s	sys 0.049s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24733724,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":252,"lbm_read_time_us":12716,"lbm_reads_lt_1ms":568,"lbm_write_time_us":28896,"lbm_writes_lt_1ms":543,"mutex_wait_us":32,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":7680,"update_count":2500}
I20260812 06:17:27.501068 26323 maintenance_manager.cc:419] P c26dd947a8e24bafa03b6f777a994afa: Scheduling FlushDeltaMemStoresOp(5eebf01c804d420f9a1f6f7560b8906a): perf score=10.126437
I20260812 06:17:27.533875 26253 maintenance_manager.cc:643] P c26dd947a8e24bafa03b6f777a994afa: FlushDeltaMemStoresOp(5eebf01c804d420f9a1f6f7560b8906a) complete. Timing: real 0.033s	user 0.021s	sys 0.011s Metrics: {"bytes_written":12307492,"delete_count":0,"lbm_write_time_us":14365,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:17:27.534512 26323 maintenance_manager.cc:419] P c26dd947a8e24bafa03b6f777a994afa: Scheduling FlushDeltaMemStoresOp(5eebf01c804d420f9a1f6f7560b8906a): perf score=2.188937
I20260812 06:17:27.555969 26253 maintenance_manager.cc:643] P c26dd947a8e24bafa03b6f777a994afa: FlushDeltaMemStoresOp(5eebf01c804d420f9a1f6f7560b8906a) complete. Timing: real 0.021s	user 0.009s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5635,"lbm_writes_lt_1ms":103,"mutex_wait_us":27,"reinsert_count":0,"update_count":500}
I20260812 06:17:27.556583 26323 maintenance_manager.cc:419] P c26dd947a8e24bafa03b6f777a994afa: Scheduling MajorDeltaCompactionOp(5eebf01c804d420f9a1f6f7560b8906a): perf score=1.000000
I20260812 06:17:27.687038 26253 maintenance_manager.cc:643] P c26dd947a8e24bafa03b6f777a994afa: MajorDeltaCompactionOp(5eebf01c804d420f9a1f6f7560b8906a) complete. Timing: real 0.130s	user 0.091s	sys 0.039s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20631314,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":710,"lbm_read_time_us":8072,"lbm_reads_lt_1ms":464,"lbm_write_time_us":25387,"lbm_writes_lt_1ms":443,"mutex_wait_us":30,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":10112,"update_count":2000}
I20260812 06:17:27.687824 26323 maintenance_manager.cc:419] P c26dd947a8e24bafa03b6f777a994afa: Scheduling FlushDeltaMemStoresOp(5eebf01c804d420f9a1f6f7560b8906a): perf score=11.118625
I20260812 06:17:27.723176 26253 maintenance_manager.cc:643] P c26dd947a8e24bafa03b6f777a994afa: FlushDeltaMemStoresOp(5eebf01c804d420f9a1f6f7560b8906a) complete. Timing: real 0.035s	user 0.017s	sys 0.016s Metrics: {"bytes_written":12717734,"delete_count":0,"lbm_write_time_us":15490,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:17:27.723948 26323 maintenance_manager.cc:419] P c26dd947a8e24bafa03b6f777a994afa: Scheduling FlushDeltaMemStoresOp(5eebf01c804d420f9a1f6f7560b8906a): perf score=2.188937
I20260812 06:17:27.740792 26253 maintenance_manager.cc:643] P c26dd947a8e24bafa03b6f777a994afa: FlushDeltaMemStoresOp(5eebf01c804d420f9a1f6f7560b8906a) complete. Timing: real 0.017s	user 0.010s	sys 0.000s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":4567,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:17:27.741408 26323 maintenance_manager.cc:419] P c26dd947a8e24bafa03b6f777a994afa: Scheduling MajorDeltaCompactionOp(5eebf01c804d420f9a1f6f7560b8906a): perf score=1.000000
I20260812 06:17:27.866854 26253 maintenance_manager.cc:643] P c26dd947a8e24bafa03b6f777a994afa: MajorDeltaCompactionOp(5eebf01c804d420f9a1f6f7560b8906a) complete. Timing: real 0.125s	user 0.090s	sys 0.032s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20631302,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":847,"lbm_read_time_us":8041,"lbm_reads_lt_1ms":464,"lbm_write_time_us":23942,"lbm_writes_lt_1ms":443,"mutex_wait_us":302,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":1920,"update_count":2000}
I20260812 06:17:27.867640 26323 maintenance_manager.cc:419] P c26dd947a8e24bafa03b6f777a994afa: Scheduling FlushDeltaMemStoresOp(5eebf01c804d420f9a1f6f7560b8906a): perf score=11.118625
I20260812 06:17:27.913105 26253 maintenance_manager.cc:643] P c26dd947a8e24bafa03b6f777a994afa: FlushDeltaMemStoresOp(5eebf01c804d420f9a1f6f7560b8906a) complete. Timing: real 0.045s	user 0.035s	sys 0.007s Metrics: {"bytes_written":12717735,"delete_count":0,"lbm_write_time_us":16450,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:17:27.913681 26323 maintenance_manager.cc:419] P c26dd947a8e24bafa03b6f777a994afa: Scheduling FlushDeltaMemStoresOp(5eebf01c804d420f9a1f6f7560b8906a): perf score=2.188937
I20260812 06:17:27.927001 26253 maintenance_manager.cc:643] P c26dd947a8e24bafa03b6f777a994afa: FlushDeltaMemStoresOp(5eebf01c804d420f9a1f6f7560b8906a) complete. Timing: real 0.013s	user 0.005s	sys 0.005s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4285,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:27.927480 26323 maintenance_manager.cc:419] P c26dd947a8e24bafa03b6f777a994afa: Scheduling FlushDeltaMemStoresOp(5eebf01c804d420f9a1f6f7560b8906a): perf score=2.188937
I20260812 06:17:27.937981 26253 maintenance_manager.cc:643] P c26dd947a8e24bafa03b6f777a994afa: FlushDeltaMemStoresOp(5eebf01c804d420f9a1f6f7560b8906a) complete. Timing: real 0.010s	user 0.002s	sys 0.008s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":4109,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:17:27.938480 26323 maintenance_manager.cc:419] P c26dd947a8e24bafa03b6f777a994afa: Scheduling FlushMRSOp(5eebf01c804d420f9a1f6f7560b8906a): perf score=1.000000
I20260812 06:17:27.976876 26253 maintenance_manager.cc:643] P c26dd947a8e24bafa03b6f777a994afa: FlushMRSOp(5eebf01c804d420f9a1f6f7560b8906a) complete. Timing: real 0.038s	user 0.033s	sys 0.000s Metrics: {"bytes_written":1234476,"cfile_init":1,"dirs.queue_time_us":209,"dirs.run_cpu_time_us":217,"dirs.run_wall_time_us":1784,"drs_written":1,"lbm_read_time_us":59,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1484,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":30}
I20260812 06:17:27.977862 26323 maintenance_manager.cc:419] P c26dd947a8e24bafa03b6f777a994afa: Scheduling LogGCOp(5eebf01c804d420f9a1f6f7560b8906a): free 120553603 bytes of WAL
I20260812 06:17:27.978117 26253 log_reader.cc:385] T 5eebf01c804d420f9a1f6f7560b8906a: removed 12 log segments from log reader
I20260812 06:17:27.978166 26253 log.cc:1079] T 5eebf01c804d420f9a1f6f7560b8906a P c26dd947a8e24bafa03b6f777a994afa: Deleting log segment in path: /tmp/dist-test-taskZj6Cvv/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515442878833-26137-0/minicluster-data/ts-0-root/wals/5eebf01c804d420f9a1f6f7560b8906a/wal-000000026 (ops 122-126)
I20260812 06:17:27.978219 26253 log.cc:1079] T 5eebf01c804d420f9a1f6f7560b8906a P c26dd947a8e24bafa03b6f777a994afa: Deleting log segment in path: /tmp/dist-test-taskZj6Cvv/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515442878833-26137-0/minicluster-data/ts-0-root/wals/5eebf01c804d420f9a1f6f7560b8906a/wal-000000027 (ops 127-131)
I20260812 06:17:27.978259 26253 log.cc:1079] T 5eebf01c804d420f9a1f6f7560b8906a P c26dd947a8e24bafa03b6f777a994afa: Deleting log segment in path: /tmp/dist-test-taskZj6Cvv/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515442878833-26137-0/minicluster-data/ts-0-root/wals/5eebf01c804d420f9a1f6f7560b8906a/wal-000000028 (ops 132-136)
I20260812 06:17:27.978293 26253 log.cc:1079] T 5eebf01c804d420f9a1f6f7560b8906a P c26dd947a8e24bafa03b6f777a994afa: Deleting log segment in path: /tmp/dist-test-taskZj6Cvv/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515442878833-26137-0/minicluster-data/ts-0-root/wals/5eebf01c804d420f9a1f6f7560b8906a/wal-000000029 (ops 137-140)
I20260812 06:17:27.978340 26253 log.cc:1079] T 5eebf01c804d420f9a1f6f7560b8906a P c26dd947a8e24bafa03b6f777a994afa: Deleting log segment in path: /tmp/dist-test-taskZj6Cvv/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515442878833-26137-0/minicluster-data/ts-0-root/wals/5eebf01c804d420f9a1f6f7560b8906a/wal-000000030 (ops 141-145)
I20260812 06:17:27.978384 26253 log.cc:1079] T 5eebf01c804d420f9a1f6f7560b8906a P c26dd947a8e24bafa03b6f777a994afa: Deleting log segment in path: /tmp/dist-test-taskZj6Cvv/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515442878833-26137-0/minicluster-data/ts-0-root/wals/5eebf01c804d420f9a1f6f7560b8906a/wal-000000031 (ops 146-150)
I20260812 06:17:27.978422 26253 log.cc:1079] T 5eebf01c804d420f9a1f6f7560b8906a P c26dd947a8e24bafa03b6f777a994afa: Deleting log segment in path: /tmp/dist-test-taskZj6Cvv/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515442878833-26137-0/minicluster-data/ts-0-root/wals/5eebf01c804d420f9a1f6f7560b8906a/wal-000000032 (ops 151-155)
I20260812 06:17:27.978457 26253 log.cc:1079] T 5eebf01c804d420f9a1f6f7560b8906a P c26dd947a8e24bafa03b6f777a994afa: Deleting log segment in path: /tmp/dist-test-taskZj6Cvv/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515442878833-26137-0/minicluster-data/ts-0-root/wals/5eebf01c804d420f9a1f6f7560b8906a/wal-000000033 (ops 156-160)
I20260812 06:17:27.978500 26253 log.cc:1079] T 5eebf01c804d420f9a1f6f7560b8906a P c26dd947a8e24bafa03b6f777a994afa: Deleting log segment in path: /tmp/dist-test-taskZj6Cvv/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515442878833-26137-0/minicluster-data/ts-0-root/wals/5eebf01c804d420f9a1f6f7560b8906a/wal-000000034 (ops 161-164)
I20260812 06:17:27.978535 26253 log.cc:1079] T 5eebf01c804d420f9a1f6f7560b8906a P c26dd947a8e24bafa03b6f777a994afa: Deleting log segment in path: /tmp/dist-test-taskZj6Cvv/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515442878833-26137-0/minicluster-data/ts-0-root/wals/5eebf01c804d420f9a1f6f7560b8906a/wal-000000035 (ops 165-169)
I20260812 06:17:27.978574 26253 log.cc:1079] T 5eebf01c804d420f9a1f6f7560b8906a P c26dd947a8e24bafa03b6f777a994afa: Deleting log segment in path: /tmp/dist-test-taskZj6Cvv/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515442878833-26137-0/minicluster-data/ts-0-root/wals/5eebf01c804d420f9a1f6f7560b8906a/wal-000000036 (ops 170-174)
I20260812 06:17:27.978615 26253 log.cc:1079] T 5eebf01c804d420f9a1f6f7560b8906a P c26dd947a8e24bafa03b6f777a994afa: Deleting log segment in path: /tmp/dist-test-taskZj6Cvv/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515442878833-26137-0/minicluster-data/ts-0-root/wals/5eebf01c804d420f9a1f6f7560b8906a/wal-000000037 (ops 175-179)
I20260812 06:17:28.007848 26253 maintenance_manager.cc:643] P c26dd947a8e24bafa03b6f777a994afa: LogGCOp(5eebf01c804d420f9a1f6f7560b8906a) complete. Timing: real 0.030s	user 0.000s	sys 0.028s Metrics: {}
I20260812 06:17:28.008335 26323 maintenance_manager.cc:419] P c26dd947a8e24bafa03b6f777a994afa: Scheduling FlushDeltaMemStoresOp(5eebf01c804d420f9a1f6f7560b8906a): perf score=3.181125
I20260812 06:17:28.029029 26253 maintenance_manager.cc:643] P c26dd947a8e24bafa03b6f777a994afa: FlushDeltaMemStoresOp(5eebf01c804d420f9a1f6f7560b8906a) complete. Timing: real 0.020s	user 0.007s	sys 0.004s Metrics: {"bytes_written":4512903,"delete_count":0,"lbm_write_time_us":4797,"lbm_writes_lt_1ms":113,"reinsert_count":0,"update_count":550}
I20260812 06:17:28.029709 26323 maintenance_manager.cc:419] P c26dd947a8e24bafa03b6f777a994afa: Scheduling FlushDeltaMemStoresOp(5eebf01c804d420f9a1f6f7560b8906a): perf score=2.188937
I20260812 06:17:28.039997 26253 maintenance_manager.cc:643] P c26dd947a8e24bafa03b6f777a994afa: FlushDeltaMemStoresOp(5eebf01c804d420f9a1f6f7560b8906a) complete. Timing: real 0.010s	user 0.004s	sys 0.004s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3835,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:17:28.040511 26323 maintenance_manager.cc:419] P c26dd947a8e24bafa03b6f777a994afa: Scheduling UndoDeltaBlockGCOp(5eebf01c804d420f9a1f6f7560b8906a): 471 bytes on disk
I20260812 06:17:28.041060 26253 maintenance_manager.cc:643] P c26dd947a8e24bafa03b6f777a994afa: UndoDeltaBlockGCOp(5eebf01c804d420f9a1f6f7560b8906a) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":70,"lbm_reads_lt_1ms":4}
I20260812 06:17:28.041702 26323 maintenance_manager.cc:419] P c26dd947a8e24bafa03b6f777a994afa: Scheduling MajorDeltaCompactionOp(5eebf01c804d420f9a1f6f7560b8906a): perf score=1.000000
I20260812 06:17:28.265982 26253 maintenance_manager.cc:643] P c26dd947a8e24bafa03b6f777a994afa: MajorDeltaCompactionOp(5eebf01c804d420f9a1f6f7560b8906a) complete. Timing: real 0.224s	user 0.165s	sys 0.057s Metrics: {"cfile_cache_miss":735,"cfile_cache_miss_bytes":32938886,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":5,"delta_iterators_relevant":5,"dirs.queue_time_us":572,"lbm_read_time_us":18056,"lbm_reads_lt_1ms":775,"lbm_write_time_us":39175,"lbm_writes_lt_1ms":743,"mutex_wait_us":73,"peak_mem_usage":87969044,"reinsert_count":0,"spinlock_wait_cycles":2304,"thread_start_us":94,"threads_started":1,"update_count":3500}
I20260812 06:17:28.266860 26323 maintenance_manager.cc:419] P c26dd947a8e24bafa03b6f777a994afa: Scheduling FlushDeltaMemStoresOp(5eebf01c804d420f9a1f6f7560b8906a): perf score=14.095187
I20260812 06:17:28.317674 26253 maintenance_manager.cc:643] P c26dd947a8e24bafa03b6f777a994afa: FlushDeltaMemStoresOp(5eebf01c804d420f9a1f6f7560b8906a) complete. Timing: real 0.050s	user 0.025s	sys 0.025s Metrics: {"bytes_written":16409897,"delete_count":0,"lbm_write_time_us":22323,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:17:28.318357 26323 maintenance_manager.cc:419] P c26dd947a8e24bafa03b6f777a994afa: Scheduling FlushDeltaMemStoresOp(5eebf01c804d420f9a1f6f7560b8906a): perf score=2.188937
I20260812 06:17:28.344614 26253 maintenance_manager.cc:643] P c26dd947a8e24bafa03b6f777a994afa: FlushDeltaMemStoresOp(5eebf01c804d420f9a1f6f7560b8906a) complete. Timing: real 0.026s	user 0.010s	sys 0.003s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6031,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:28.345096 26323 maintenance_manager.cc:419] P c26dd947a8e24bafa03b6f777a994afa: Scheduling FlushDeltaMemStoresOp(5eebf01c804d420f9a1f6f7560b8906a): perf score=2.188937
I20260812 06:17:28.356447 26253 maintenance_manager.cc:643] P c26dd947a8e24bafa03b6f777a994afa: FlushDeltaMemStoresOp(5eebf01c804d420f9a1f6f7560b8906a) complete. Timing: real 0.011s	user 0.006s	sys 0.003s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4211,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:28.357012 26323 maintenance_manager.cc:419] P c26dd947a8e24bafa03b6f777a994afa: Scheduling MajorDeltaCompactionOp(5eebf01c804d420f9a1f6f7560b8906a): perf score=1.000000
I20260812 06:17:28.489199 26137 heavy-update-compaction-itest.cc:229] Time spent updating: real 5.290s	user 1.822s	sys 0.226s
I20260812 06:17:28.528093 26253 maintenance_manager.cc:643] P c26dd947a8e24bafa03b6f777a994afa: MajorDeltaCompactionOp(5eebf01c804d420f9a1f6f7560b8906a) complete. Timing: real 0.171s	user 0.134s	sys 0.035s Metrics: {"cfile_cache_miss":633,"cfile_cache_miss_bytes":28836249,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"lbm_read_time_us":14350,"lbm_reads_lt_1ms":669,"lbm_write_time_us":35294,"lbm_writes_lt_1ms":643,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":2176,"update_count":3000}
I20260812 06:17:28.528599 26323 maintenance_manager.cc:419] P c26dd947a8e24bafa03b6f777a994afa: Scheduling FlushDeltaMemStoresOp(5eebf01c804d420f9a1f6f7560b8906a): perf score=10.126437
I20260812 06:17:28.567591 26253 maintenance_manager.cc:643] P c26dd947a8e24bafa03b6f777a994afa: FlushDeltaMemStoresOp(5eebf01c804d420f9a1f6f7560b8906a) complete. Timing: real 0.039s	user 0.020s	sys 0.016s Metrics: {"bytes_written":12307492,"delete_count":0,"lbm_write_time_us":16113,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:17:28.568367 26323 maintenance_manager.cc:419] P c26dd947a8e24bafa03b6f777a994afa: Scheduling MajorDeltaCompactionOp(5eebf01c804d420f9a1f6f7560b8906a): perf score=1.000000
I20260812 06:17:28.576654 26137 heavy-update-compaction-itest.cc:265] Time spent scanning: real 0.087s	user 0.002s	sys 0.000s
I20260812 06:17:28.577687 26137 tablet_server.cc:179] TabletServer@127.25.134.65:0 shutting down...
I20260812 06:17:28.677963 26253 maintenance_manager.cc:643] P c26dd947a8e24bafa03b6f777a994afa: MajorDeltaCompactionOp(5eebf01c804d420f9a1f6f7560b8906a) complete. Timing: real 0.109s	user 0.086s	sys 0.023s Metrics: {"cfile_cache_miss":331,"cfile_cache_miss_bytes":16528783,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":1,"delta_iterators_relevant":1,"dirs.queue_time_us":535,"lbm_read_time_us":9905,"lbm_reads_lt_1ms":367,"lbm_write_time_us":23656,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":342,"mutex_wait_us":78,"peak_mem_usage":38262756,"reinsert_count":0,"update_count":1500}
I20260812 06:17:28.678833 26137 ts_tablet_manager.cc:1507] Shutting down tablet manager...
I20260812 06:17:28.679455 26137 tablet_replica.cc:333] T 5eebf01c804d420f9a1f6f7560b8906a P c26dd947a8e24bafa03b6f777a994afa: stopping tablet replica
I20260812 06:17:28.679714 26137 raft_consensus.cc:2243] T 5eebf01c804d420f9a1f6f7560b8906a P c26dd947a8e24bafa03b6f777a994afa [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:17:28.679962 26137 raft_consensus.cc:2272] T 5eebf01c804d420f9a1f6f7560b8906a P c26dd947a8e24bafa03b6f777a994afa [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:17:28.697696 26137 tablet_server.cc:196] TabletServer@127.25.134.65:0 shutdown complete.
I20260812 06:17:28.712389 26137 master.cc:562] Master@127.25.134.126:35903 shutting down...
I20260812 06:17:28.717588 26137 raft_consensus.cc:2243] T 00000000000000000000000000000000 P a91c15e501514c90af15ffbf0669a41a [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:17:28.717880 26137 raft_consensus.cc:2272] T 00000000000000000000000000000000 P a91c15e501514c90af15ffbf0669a41a [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:17:28.717971 26137 tablet_replica.cc:333] T 00000000000000000000000000000000 P a91c15e501514c90af15ffbf0669a41a: stopping tablet replica
I20260812 06:17:28.730926 26137 master.cc:584] Master@127.25.134.126:35903 shutdown complete.
[       OK ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/0 (5943 ms)
[ RUN      ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/1
I20260812 06:17:28.848632 26137 internal_mini_cluster.cc:156] Creating distributed mini masters. Addrs: 127.25.134.126:43163
I20260812 06:17:28.849234 26137 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:17:28.852560 26364 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:17:28.852577 26366 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:17:28.853979 26137 server_base.cc:1061] running on GCE node
W20260812 06:17:28.854126 26363 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:17:28.854558 26137 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:17:28.854616 26137 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:17:28.854635 26137 hybrid_clock.cc:648] HybridClock initialized: now 1786515448854635 us; error 0 us; skew 500 ppm
I20260812 06:17:28.855746 26137 webserver.cc:533] Webserver started at http://127.25.134.126:36545/ using document root <none> and password file <none>
I20260812 06:17:28.855966 26137 fs_manager.cc:362] Metadata directory not provided
I20260812 06:17:28.856050 26137 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:17:28.856146 26137 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:17:28.856683 26137 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskZj6Cvv/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515442878833-26137-0/minicluster-data/master-0-root/instance:
uuid: "e3dfa1baf7cf4cc391c3225f0f9e0896"
format_stamp: "Formatted at 2026-08-12 06:17:28 on dist-test-slave-9zdj"
I20260812 06:17:28.858644 26137 fs_manager.cc:696] Time spent creating directory manager: real 0.002s	user 0.003s	sys 0.000s
I20260812 06:17:28.860111 26371 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:17:28.860427 26137 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.001s	sys 0.000s
I20260812 06:17:28.860513 26137 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskZj6Cvv/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515442878833-26137-0/minicluster-data/master-0-root
uuid: "e3dfa1baf7cf4cc391c3225f0f9e0896"
format_stamp: "Formatted at 2026-08-12 06:17:28 on dist-test-slave-9zdj"
I20260812 06:17:28.860580 26137 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskZj6Cvv/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515442878833-26137-0/minicluster-data/master-0-root
metadata directory: /tmp/dist-test-taskZj6Cvv/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515442878833-26137-0/minicluster-data/master-0-root
1 data directories: /tmp/dist-test-taskZj6Cvv/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515442878833-26137-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:17:28.868947 26137 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:17:28.869328 26137 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:17:28.873543 26137 rpc_server.cc:307] RPC server started. Bound to: 127.25.134.126:43163
I20260812 06:17:28.875018 26437 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.25.134.126:43163 every 8 connection(s)
I20260812 06:17:28.875494 26438 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:17:28.877401 26438 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P e3dfa1baf7cf4cc391c3225f0f9e0896: Bootstrap starting.
I20260812 06:17:28.878290 26438 tablet_bootstrap.cc:654] T 00000000000000000000000000000000 P e3dfa1baf7cf4cc391c3225f0f9e0896: Neither blocks nor log segments found. Creating new log.
I20260812 06:17:28.879575 26438 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P e3dfa1baf7cf4cc391c3225f0f9e0896: No bootstrap required, opened a new log
I20260812 06:17:28.880038 26438 raft_consensus.cc:359] T 00000000000000000000000000000000 P e3dfa1baf7cf4cc391c3225f0f9e0896 [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "e3dfa1baf7cf4cc391c3225f0f9e0896" member_type: VOTER }
I20260812 06:17:28.880153 26438 raft_consensus.cc:385] T 00000000000000000000000000000000 P e3dfa1baf7cf4cc391c3225f0f9e0896 [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:17:28.880210 26438 raft_consensus.cc:740] T 00000000000000000000000000000000 P e3dfa1baf7cf4cc391c3225f0f9e0896 [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: e3dfa1baf7cf4cc391c3225f0f9e0896, State: Initialized, Role: FOLLOWER
I20260812 06:17:28.880395 26438 consensus_queue.cc:260] T 00000000000000000000000000000000 P e3dfa1baf7cf4cc391c3225f0f9e0896 [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: "e3dfa1baf7cf4cc391c3225f0f9e0896" member_type: VOTER }
I20260812 06:17:28.880487 26438 raft_consensus.cc:399] T 00000000000000000000000000000000 P e3dfa1baf7cf4cc391c3225f0f9e0896 [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:17:28.880532 26438 raft_consensus.cc:493] T 00000000000000000000000000000000 P e3dfa1baf7cf4cc391c3225f0f9e0896 [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:17:28.880589 26438 raft_consensus.cc:3060] T 00000000000000000000000000000000 P e3dfa1baf7cf4cc391c3225f0f9e0896 [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:17:28.881456 26438 raft_consensus.cc:515] T 00000000000000000000000000000000 P e3dfa1baf7cf4cc391c3225f0f9e0896 [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "e3dfa1baf7cf4cc391c3225f0f9e0896" member_type: VOTER }
I20260812 06:17:28.881664 26438 leader_election.cc:304] T 00000000000000000000000000000000 P e3dfa1baf7cf4cc391c3225f0f9e0896 [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: e3dfa1baf7cf4cc391c3225f0f9e0896; no voters: 
I20260812 06:17:28.881888 26438 leader_election.cc:290] T 00000000000000000000000000000000 P e3dfa1baf7cf4cc391c3225f0f9e0896 [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:17:28.882028 26441 raft_consensus.cc:2804] T 00000000000000000000000000000000 P e3dfa1baf7cf4cc391c3225f0f9e0896 [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:17:28.882386 26441 raft_consensus.cc:697] T 00000000000000000000000000000000 P e3dfa1baf7cf4cc391c3225f0f9e0896 [term 1 LEADER]: Becoming Leader. State: Replica: e3dfa1baf7cf4cc391c3225f0f9e0896, State: Running, Role: LEADER
I20260812 06:17:28.882409 26438 sys_catalog.cc:565] T 00000000000000000000000000000000 P e3dfa1baf7cf4cc391c3225f0f9e0896 [sys.catalog]: configured and running, proceeding with master startup.
I20260812 06:17:28.882596 26441 consensus_queue.cc:237] T 00000000000000000000000000000000 P e3dfa1baf7cf4cc391c3225f0f9e0896 [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: "e3dfa1baf7cf4cc391c3225f0f9e0896" member_type: VOTER }
I20260812 06:17:28.883283 26443 sys_catalog.cc:455] T 00000000000000000000000000000000 P e3dfa1baf7cf4cc391c3225f0f9e0896 [sys.catalog]: SysCatalogTable state changed. Reason: New leader e3dfa1baf7cf4cc391c3225f0f9e0896. Latest consensus state: current_term: 1 leader_uuid: "e3dfa1baf7cf4cc391c3225f0f9e0896" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "e3dfa1baf7cf4cc391c3225f0f9e0896" member_type: VOTER } }
I20260812 06:17:28.883414 26443 sys_catalog.cc:458] T 00000000000000000000000000000000 P e3dfa1baf7cf4cc391c3225f0f9e0896 [sys.catalog]: This master's current role is: LEADER
I20260812 06:17:28.883606 26442 sys_catalog.cc:455] T 00000000000000000000000000000000 P e3dfa1baf7cf4cc391c3225f0f9e0896 [sys.catalog]: SysCatalogTable state changed. Reason: RaftConsensus started. Latest consensus state: current_term: 1 leader_uuid: "e3dfa1baf7cf4cc391c3225f0f9e0896" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "e3dfa1baf7cf4cc391c3225f0f9e0896" member_type: VOTER } }
I20260812 06:17:28.883709 26442 sys_catalog.cc:458] T 00000000000000000000000000000000 P e3dfa1baf7cf4cc391c3225f0f9e0896 [sys.catalog]: This master's current role is: LEADER
I20260812 06:17:28.883760 26451 catalog_manager.cc:1511] Loading table and tablet metadata into memory...
I20260812 06:17:28.884773 26451 catalog_manager.cc:1520] Initializing Kudu cluster ID...
I20260812 06:17:28.885040 26137 internal_mini_cluster.cc:184] Waiting to initialize catalog manager on master 0
I20260812 06:17:28.887035 26451 catalog_manager.cc:1383] Generated new cluster ID: 24bc5af9657448d993b51df35176b2d3
I20260812 06:17:28.887246 26451 catalog_manager.cc:1531] Initializing Kudu internal certificate authority...
I20260812 06:17:28.894868 26451 catalog_manager.cc:1406] Generated new certificate authority record
I20260812 06:17:28.895552 26451 catalog_manager.cc:1540] Loading token signing keys...
I20260812 06:17:28.909901 26451 catalog_manager.cc:6092] T 00000000000000000000000000000000 P e3dfa1baf7cf4cc391c3225f0f9e0896: Generated new TSK 0
I20260812 06:17:28.910175 26451 catalog_manager.cc:1550] Initializing in-progress tserver states...
I20260812 06:17:28.917593 26137 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:17:28.919961 26464 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:17:28.920173 26467 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:17:28.920091 26137 server_base.cc:1061] running on GCE node
W20260812 06:17:28.920030 26465 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:17:28.920601 26137 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:17:28.920671 26137 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:17:28.920691 26137 hybrid_clock.cc:648] HybridClock initialized: now 1786515448920690 us; error 0 us; skew 500 ppm
I20260812 06:17:28.921823 26137 webserver.cc:533] Webserver started at http://127.25.134.65:46639/ using document root <none> and password file <none>
I20260812 06:17:28.922043 26137 fs_manager.cc:362] Metadata directory not provided
I20260812 06:17:28.922106 26137 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:17:28.922209 26137 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:17:28.922742 26137 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskZj6Cvv/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515442878833-26137-0/minicluster-data/ts-0-root/instance:
uuid: "42116023caab453792040d26a2370c7b"
format_stamp: "Formatted at 2026-08-12 06:17:28 on dist-test-slave-9zdj"
I20260812 06:17:28.924614 26137 fs_manager.cc:696] Time spent creating directory manager: real 0.002s	user 0.000s	sys 0.002s
I20260812 06:17:28.925971 26473 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:17:28.926362 26137 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.000s	sys 0.001s
I20260812 06:17:28.926436 26137 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskZj6Cvv/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515442878833-26137-0/minicluster-data/ts-0-root
uuid: "42116023caab453792040d26a2370c7b"
format_stamp: "Formatted at 2026-08-12 06:17:28 on dist-test-slave-9zdj"
I20260812 06:17:28.926542 26137 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskZj6Cvv/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515442878833-26137-0/minicluster-data/ts-0-root
metadata directory: /tmp/dist-test-taskZj6Cvv/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515442878833-26137-0/minicluster-data/ts-0-root
1 data directories: /tmp/dist-test-taskZj6Cvv/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515442878833-26137-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:17:28.931269 26137 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:17:28.931720 26137 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:17:28.932065 26137 txn_system_client.cc:432] TxnSystemClient initialization is disabled...
I20260812 06:17:28.932588 26137 ts_tablet_manager.cc:585] Loaded tablet metadata (0 total tablets, 0 live tablets)
I20260812 06:17:28.932627 26137 ts_tablet_manager.cc:531] Time spent load tablet metadata: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:17:28.932662 26137 ts_tablet_manager.cc:616] Registered 0 tablets
I20260812 06:17:28.932679 26137 ts_tablet_manager.cc:595] Time spent register tablets: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:17:28.937424 26137 rpc_server.cc:307] RPC server started. Bound to: 127.25.134.65:44081
I20260812 06:17:28.937718 26549 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.25.134.65:44081 every 8 connection(s)
I20260812 06:17:28.943557 26550 heartbeater.cc:344] Connected to a master server at 127.25.134.126:43163
I20260812 06:17:28.943735 26550 heartbeater.cc:461] Registering TS with master...
I20260812 06:17:28.944036 26550 heartbeater.cc:507] Master 127.25.134.126:43163 requested a full tablet report, sending...
I20260812 06:17:28.944862 26390 ts_manager.cc:194] Registered new tserver with Master: 42116023caab453792040d26a2370c7b (127.25.134.65:44081)
I20260812 06:17:28.945705 26390 master_service.cc:502] Signed X509 certificate for tserver {username='slave'} at 127.0.0.1:39838
I20260812 06:17:28.945899 26137 internal_mini_cluster.cc:371] 1 TS(s) registered with all masters after 0.007871894s
I20260812 06:17:28.955025 26390 catalog_manager.cc:2283] Servicing CreateTable request from {username='slave'} at 127.0.0.1:39848:
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:17:28.965696 26509 tablet_service.cc:1511] Processing CreateTablet for tablet dbe42619d21b4b70a13f14e2931208ea (DEFAULT_TABLE table=heavy-update-compaction-test [id=a89d6cc9b9fc4ae585a7f94fc0c3992d]), partition=
I20260812 06:17:28.965993 26509 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet dbe42619d21b4b70a13f14e2931208ea. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:17:28.968151 26563 tablet_bootstrap.cc:492] T dbe42619d21b4b70a13f14e2931208ea P 42116023caab453792040d26a2370c7b: Bootstrap starting.
I20260812 06:17:28.969210 26563 tablet_bootstrap.cc:654] T dbe42619d21b4b70a13f14e2931208ea P 42116023caab453792040d26a2370c7b: Neither blocks nor log segments found. Creating new log.
I20260812 06:17:28.970438 26563 tablet_bootstrap.cc:492] T dbe42619d21b4b70a13f14e2931208ea P 42116023caab453792040d26a2370c7b: No bootstrap required, opened a new log
I20260812 06:17:28.970552 26563 ts_tablet_manager.cc:1403] T dbe42619d21b4b70a13f14e2931208ea P 42116023caab453792040d26a2370c7b: Time spent bootstrapping tablet: real 0.002s	user 0.002s	sys 0.000s
I20260812 06:17:28.971032 26563 raft_consensus.cc:359] T dbe42619d21b4b70a13f14e2931208ea P 42116023caab453792040d26a2370c7b [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "42116023caab453792040d26a2370c7b" member_type: VOTER last_known_addr { host: "127.25.134.65" port: 44081 } }
I20260812 06:17:28.971159 26563 raft_consensus.cc:385] T dbe42619d21b4b70a13f14e2931208ea P 42116023caab453792040d26a2370c7b [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:17:28.971231 26563 raft_consensus.cc:740] T dbe42619d21b4b70a13f14e2931208ea P 42116023caab453792040d26a2370c7b [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: 42116023caab453792040d26a2370c7b, State: Initialized, Role: FOLLOWER
I20260812 06:17:28.971442 26563 consensus_queue.cc:260] T dbe42619d21b4b70a13f14e2931208ea P 42116023caab453792040d26a2370c7b [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: "42116023caab453792040d26a2370c7b" member_type: VOTER last_known_addr { host: "127.25.134.65" port: 44081 } }
I20260812 06:17:28.971545 26563 raft_consensus.cc:399] T dbe42619d21b4b70a13f14e2931208ea P 42116023caab453792040d26a2370c7b [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:17:28.971591 26563 raft_consensus.cc:493] T dbe42619d21b4b70a13f14e2931208ea P 42116023caab453792040d26a2370c7b [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:17:28.971637 26563 raft_consensus.cc:3060] T dbe42619d21b4b70a13f14e2931208ea P 42116023caab453792040d26a2370c7b [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:17:28.972687 26563 raft_consensus.cc:515] T dbe42619d21b4b70a13f14e2931208ea P 42116023caab453792040d26a2370c7b [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "42116023caab453792040d26a2370c7b" member_type: VOTER last_known_addr { host: "127.25.134.65" port: 44081 } }
I20260812 06:17:28.972856 26563 leader_election.cc:304] T dbe42619d21b4b70a13f14e2931208ea P 42116023caab453792040d26a2370c7b [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: 42116023caab453792040d26a2370c7b; no voters: 
I20260812 06:17:28.973100 26563 leader_election.cc:290] T dbe42619d21b4b70a13f14e2931208ea P 42116023caab453792040d26a2370c7b [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:17:28.973440 26565 raft_consensus.cc:2804] T dbe42619d21b4b70a13f14e2931208ea P 42116023caab453792040d26a2370c7b [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:17:28.973762 26550 heartbeater.cc:499] Master 127.25.134.126:43163 was elected leader, sending a full tablet report...
I20260812 06:17:28.973706 26563 ts_tablet_manager.cc:1434] T dbe42619d21b4b70a13f14e2931208ea P 42116023caab453792040d26a2370c7b: Time spent starting tablet: real 0.003s	user 0.003s	sys 0.000s
I20260812 06:17:28.973730 26565 raft_consensus.cc:697] T dbe42619d21b4b70a13f14e2931208ea P 42116023caab453792040d26a2370c7b [term 1 LEADER]: Becoming Leader. State: Replica: 42116023caab453792040d26a2370c7b, State: Running, Role: LEADER
I20260812 06:17:28.973963 26565 consensus_queue.cc:237] T dbe42619d21b4b70a13f14e2931208ea P 42116023caab453792040d26a2370c7b [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: "42116023caab453792040d26a2370c7b" member_type: VOTER last_known_addr { host: "127.25.134.65" port: 44081 } }
I20260812 06:17:28.975458 26390 catalog_manager.cc:5719] T dbe42619d21b4b70a13f14e2931208ea P 42116023caab453792040d26a2370c7b reported cstate change: term changed from 0 to 1, leader changed from <none> to 42116023caab453792040d26a2370c7b (127.25.134.65). New cstate: current_term: 1 leader_uuid: "42116023caab453792040d26a2370c7b" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "42116023caab453792040d26a2370c7b" member_type: VOTER last_known_addr { host: "127.25.134.65" port: 44081 } health_report { overall_health: HEALTHY } } }
I20260812 06:17:29.043190 26137 heavy-update-compaction-itest.cc:215] Time spent inserting: real 0.060s	user 0.022s	sys 0.004s
I20260812 06:17:29.188611 26551 maintenance_manager.cc:419] P 42116023caab453792040d26a2370c7b: Scheduling FlushMRSOp(dbe42619d21b4b70a13f14e2931208ea): perf score=15.086190
I20260812 06:17:29.325055 26479 maintenance_manager.cc:643] P 42116023caab453792040d26a2370c7b: FlushMRSOp(dbe42619d21b4b70a13f14e2931208ea) complete. Timing: real 0.136s	user 0.093s	sys 0.040s Metrics: {"bytes_written":11897249,"cfile_init":1,"delete_count":0,"dirs.queue_time_us":106,"dirs.run_cpu_time_us":251,"dirs.run_wall_time_us":1041,"drs_written":1,"lbm_read_time_us":41,"lbm_reads_lt_1ms":4,"lbm_write_time_us":34253,"lbm_writes_lt_1ms":657,"peak_mem_usage":0,"reinsert_count":0,"rows_written":104,"update_count":1450}
I20260812 06:17:29.326073 26551 maintenance_manager.cc:419] P 42116023caab453792040d26a2370c7b: Scheduling LogGCOp(dbe42619d21b4b70a13f14e2931208ea): free 20743880 bytes of WAL
I20260812 06:17:29.326503 26479 log_reader.cc:385] T dbe42619d21b4b70a13f14e2931208ea: removed 2 log segments from log reader
I20260812 06:17:29.326603 26479 log.cc:1079] T dbe42619d21b4b70a13f14e2931208ea P 42116023caab453792040d26a2370c7b: Deleting log segment in path: /tmp/dist-test-taskZj6Cvv/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515442878833-26137-0/minicluster-data/ts-0-root/wals/dbe42619d21b4b70a13f14e2931208ea/wal-000000001 (ops 1-6)
I20260812 06:17:29.326673 26479 log.cc:1079] T dbe42619d21b4b70a13f14e2931208ea P 42116023caab453792040d26a2370c7b: Deleting log segment in path: /tmp/dist-test-taskZj6Cvv/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515442878833-26137-0/minicluster-data/ts-0-root/wals/dbe42619d21b4b70a13f14e2931208ea/wal-000000002 (ops 7-11)
I20260812 06:17:29.331465 26479 maintenance_manager.cc:643] P 42116023caab453792040d26a2370c7b: LogGCOp(dbe42619d21b4b70a13f14e2931208ea) complete. Timing: real 0.005s	user 0.000s	sys 0.003s Metrics: {}
I20260812 06:17:29.331933 26551 maintenance_manager.cc:419] P 42116023caab453792040d26a2370c7b: Scheduling UndoDeltaBlockGCOp(dbe42619d21b4b70a13f14e2931208ea): 12719217 bytes on disk
I20260812 06:17:29.332430 26479 maintenance_manager.cc:643] P 42116023caab453792040d26a2370c7b: UndoDeltaBlockGCOp(dbe42619d21b4b70a13f14e2931208ea) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":64,"lbm_reads_lt_1ms":4}
I20260812 06:17:29.332882 26551 maintenance_manager.cc:419] P 42116023caab453792040d26a2370c7b: Scheduling FlushDeltaMemStoresOp(dbe42619d21b4b70a13f14e2931208ea): perf score=2.188937
I20260812 06:17:29.350423 26479 maintenance_manager.cc:643] P 42116023caab453792040d26a2370c7b: FlushDeltaMemStoresOp(dbe42619d21b4b70a13f14e2931208ea) complete. Timing: real 0.017s	user 0.013s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5043,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:29.350884 26551 maintenance_manager.cc:419] P 42116023caab453792040d26a2370c7b: Scheduling MajorDeltaCompactionOp(dbe42619d21b4b70a13f14e2931208ea): perf score=1.000000
I20260812 06:17:29.496059 26479 maintenance_manager.cc:643] P 42116023caab453792040d26a2370c7b: MajorDeltaCompactionOp(dbe42619d21b4b70a13f14e2931208ea) complete. Timing: real 0.145s	user 0.113s	sys 0.032s 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":602,"lbm_read_time_us":12169,"lbm_reads_lt_1ms":450,"lbm_write_time_us":25959,"lbm_writes_lt_1ms":433,"peak_mem_usage":49238594,"reinsert_count":0,"spinlock_wait_cycles":3328,"thread_start_us":367,"threads_started":5,"update_count":1950}
I20260812 06:17:29.496775 26551 maintenance_manager.cc:419] P 42116023caab453792040d26a2370c7b: Scheduling FlushDeltaMemStoresOp(dbe42619d21b4b70a13f14e2931208ea): perf score=10.126437
I20260812 06:17:29.540200 26479 maintenance_manager.cc:643] P 42116023caab453792040d26a2370c7b: FlushDeltaMemStoresOp(dbe42619d21b4b70a13f14e2931208ea) complete. Timing: real 0.043s	user 0.019s	sys 0.016s Metrics: {"bytes_written":12307492,"delete_count":0,"lbm_write_time_us":16598,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:17:29.540889 26551 maintenance_manager.cc:419] P 42116023caab453792040d26a2370c7b: Scheduling FlushDeltaMemStoresOp(dbe42619d21b4b70a13f14e2931208ea): perf score=2.188937
I20260812 06:17:29.553344 26479 maintenance_manager.cc:643] P 42116023caab453792040d26a2370c7b: FlushDeltaMemStoresOp(dbe42619d21b4b70a13f14e2931208ea) complete. Timing: real 0.012s	user 0.006s	sys 0.003s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4356,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:29.554104 26551 maintenance_manager.cc:419] P 42116023caab453792040d26a2370c7b: Scheduling MajorDeltaCompactionOp(dbe42619d21b4b70a13f14e2931208ea): perf score=1.000000
I20260812 06:17:29.691810 26479 maintenance_manager.cc:643] P 42116023caab453792040d26a2370c7b: MajorDeltaCompactionOp(dbe42619d21b4b70a13f14e2931208ea) complete. Timing: real 0.137s	user 0.096s	sys 0.040s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672279,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":1104,"lbm_read_time_us":9066,"lbm_reads_lt_1ms":472,"lbm_write_time_us":27031,"lbm_writes_lt_1ms":443,"mutex_wait_us":40,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":9216,"update_count":2000}
I20260812 06:17:29.692587 26551 maintenance_manager.cc:419] P 42116023caab453792040d26a2370c7b: Scheduling FlushDeltaMemStoresOp(dbe42619d21b4b70a13f14e2931208ea): perf score=10.126437
I20260812 06:17:29.730322 26479 maintenance_manager.cc:643] P 42116023caab453792040d26a2370c7b: FlushDeltaMemStoresOp(dbe42619d21b4b70a13f14e2931208ea) complete. Timing: real 0.038s	user 0.015s	sys 0.020s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":15649,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:17:29.730962 26551 maintenance_manager.cc:419] P 42116023caab453792040d26a2370c7b: Scheduling FlushDeltaMemStoresOp(dbe42619d21b4b70a13f14e2931208ea): perf score=2.188937
I20260812 06:17:29.743381 26479 maintenance_manager.cc:643] P 42116023caab453792040d26a2370c7b: FlushDeltaMemStoresOp(dbe42619d21b4b70a13f14e2931208ea) complete. Timing: real 0.012s	user 0.002s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4439,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:29.744320 26551 maintenance_manager.cc:419] P 42116023caab453792040d26a2370c7b: Scheduling MajorDeltaCompactionOp(dbe42619d21b4b70a13f14e2931208ea): perf score=1.000000
I20260812 06:17:29.885777 26479 maintenance_manager.cc:643] P 42116023caab453792040d26a2370c7b: MajorDeltaCompactionOp(dbe42619d21b4b70a13f14e2931208ea) complete. Timing: real 0.141s	user 0.101s	sys 0.040s 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":1101,"lbm_read_time_us":10368,"lbm_reads_lt_1ms":472,"lbm_write_time_us":28201,"lbm_writes_lt_1ms":443,"mutex_wait_us":233,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":9856,"update_count":2000}
I20260812 06:17:29.886564 26551 maintenance_manager.cc:419] P 42116023caab453792040d26a2370c7b: Scheduling FlushDeltaMemStoresOp(dbe42619d21b4b70a13f14e2931208ea): perf score=10.126437
I20260812 06:17:29.946823 26479 maintenance_manager.cc:643] P 42116023caab453792040d26a2370c7b: FlushDeltaMemStoresOp(dbe42619d21b4b70a13f14e2931208ea) complete. Timing: real 0.060s	user 0.026s	sys 0.023s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":17224,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:17:29.947448 26551 maintenance_manager.cc:419] P 42116023caab453792040d26a2370c7b: Scheduling FlushDeltaMemStoresOp(dbe42619d21b4b70a13f14e2931208ea): perf score=2.188937
I20260812 06:17:29.959080 26479 maintenance_manager.cc:643] P 42116023caab453792040d26a2370c7b: FlushDeltaMemStoresOp(dbe42619d21b4b70a13f14e2931208ea) complete. Timing: real 0.011s	user 0.001s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4579,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:29.959720 26551 maintenance_manager.cc:419] P 42116023caab453792040d26a2370c7b: Scheduling MajorDeltaCompactionOp(dbe42619d21b4b70a13f14e2931208ea): perf score=1.000000
I20260812 06:17:30.122222 26479 maintenance_manager.cc:643] P 42116023caab453792040d26a2370c7b: MajorDeltaCompactionOp(dbe42619d21b4b70a13f14e2931208ea) complete. Timing: real 0.162s	user 0.122s	sys 0.040s 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":1436,"lbm_read_time_us":12214,"lbm_reads_lt_1ms":472,"lbm_write_time_us":25335,"lbm_writes_lt_1ms":443,"mutex_wait_us":427,"peak_mem_usage":50689328,"reinsert_count":0,"update_count":2000}
I20260812 06:17:30.122736 26551 maintenance_manager.cc:419] P 42116023caab453792040d26a2370c7b: Scheduling FlushDeltaMemStoresOp(dbe42619d21b4b70a13f14e2931208ea): perf score=10.126437
I20260812 06:17:30.164021 26479 maintenance_manager.cc:643] P 42116023caab453792040d26a2370c7b: FlushDeltaMemStoresOp(dbe42619d21b4b70a13f14e2931208ea) complete. Timing: real 0.041s	user 0.021s	sys 0.013s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":16090,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:17:30.164659 26551 maintenance_manager.cc:419] P 42116023caab453792040d26a2370c7b: Scheduling FlushDeltaMemStoresOp(dbe42619d21b4b70a13f14e2931208ea): perf score=2.188937
I20260812 06:17:30.179991 26479 maintenance_manager.cc:643] P 42116023caab453792040d26a2370c7b: FlushDeltaMemStoresOp(dbe42619d21b4b70a13f14e2931208ea) complete. Timing: real 0.015s	user 0.010s	sys 0.003s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6251,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:30.180591 26551 maintenance_manager.cc:419] P 42116023caab453792040d26a2370c7b: Scheduling MajorDeltaCompactionOp(dbe42619d21b4b70a13f14e2931208ea): perf score=1.000000
I20260812 06:17:30.318535 26479 maintenance_manager.cc:643] P 42116023caab453792040d26a2370c7b: MajorDeltaCompactionOp(dbe42619d21b4b70a13f14e2931208ea) complete. Timing: real 0.138s	user 0.106s	sys 0.032s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672277,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":428,"lbm_read_time_us":10040,"lbm_reads_lt_1ms":472,"lbm_write_time_us":27349,"lbm_writes_lt_1ms":443,"mutex_wait_us":129,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":2176,"update_count":2000}
I20260812 06:17:30.319324 26551 maintenance_manager.cc:419] P 42116023caab453792040d26a2370c7b: Scheduling FlushDeltaMemStoresOp(dbe42619d21b4b70a13f14e2931208ea): perf score=10.126437
I20260812 06:17:30.371685 26479 maintenance_manager.cc:643] P 42116023caab453792040d26a2370c7b: FlushDeltaMemStoresOp(dbe42619d21b4b70a13f14e2931208ea) complete. Timing: real 0.052s	user 0.031s	sys 0.009s Metrics: {"bytes_written":12307489,"delete_count":0,"lbm_write_time_us":18725,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:17:30.372156 26551 maintenance_manager.cc:419] P 42116023caab453792040d26a2370c7b: Scheduling FlushDeltaMemStoresOp(dbe42619d21b4b70a13f14e2931208ea): perf score=2.188937
I20260812 06:17:30.383548 26479 maintenance_manager.cc:643] P 42116023caab453792040d26a2370c7b: FlushDeltaMemStoresOp(dbe42619d21b4b70a13f14e2931208ea) complete. Timing: real 0.011s	user 0.009s	sys 0.001s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4162,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:30.384310 26551 maintenance_manager.cc:419] P 42116023caab453792040d26a2370c7b: Scheduling MajorDeltaCompactionOp(dbe42619d21b4b70a13f14e2931208ea): perf score=1.000000
I20260812 06:17:30.521850 26479 maintenance_manager.cc:643] P 42116023caab453792040d26a2370c7b: MajorDeltaCompactionOp(dbe42619d21b4b70a13f14e2931208ea) complete. Timing: real 0.137s	user 0.107s	sys 0.030s 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":413,"lbm_read_time_us":10048,"lbm_reads_lt_1ms":472,"lbm_write_time_us":26491,"lbm_writes_lt_1ms":443,"mutex_wait_us":2,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":2176,"update_count":2000}
I20260812 06:17:30.522738 26551 maintenance_manager.cc:419] P 42116023caab453792040d26a2370c7b: Scheduling FlushDeltaMemStoresOp(dbe42619d21b4b70a13f14e2931208ea): perf score=10.126437
I20260812 06:17:30.580693 26479 maintenance_manager.cc:643] P 42116023caab453792040d26a2370c7b: FlushDeltaMemStoresOp(dbe42619d21b4b70a13f14e2931208ea) complete. Timing: real 0.058s	user 0.023s	sys 0.028s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":19805,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:17:30.581295 26551 maintenance_manager.cc:419] P 42116023caab453792040d26a2370c7b: Scheduling FlushDeltaMemStoresOp(dbe42619d21b4b70a13f14e2931208ea): perf score=2.188937
I20260812 06:17:30.593032 26479 maintenance_manager.cc:643] P 42116023caab453792040d26a2370c7b: FlushDeltaMemStoresOp(dbe42619d21b4b70a13f14e2931208ea) complete. Timing: real 0.012s	user 0.010s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4612,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:30.593803 26551 maintenance_manager.cc:419] P 42116023caab453792040d26a2370c7b: Scheduling MajorDeltaCompactionOp(dbe42619d21b4b70a13f14e2931208ea): perf score=1.000000
I20260812 06:17:30.755438 26479 maintenance_manager.cc:643] P 42116023caab453792040d26a2370c7b: MajorDeltaCompactionOp(dbe42619d21b4b70a13f14e2931208ea) complete. Timing: real 0.161s	user 0.099s	sys 0.060s 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":298,"lbm_read_time_us":11177,"lbm_reads_lt_1ms":472,"lbm_write_time_us":25876,"lbm_writes_lt_1ms":443,"mutex_wait_us":57,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":25984,"update_count":2000}
I20260812 06:17:30.756297 26551 maintenance_manager.cc:419] P 42116023caab453792040d26a2370c7b: Scheduling FlushDeltaMemStoresOp(dbe42619d21b4b70a13f14e2931208ea): perf score=10.126437
I20260812 06:17:30.806550 26479 maintenance_manager.cc:643] P 42116023caab453792040d26a2370c7b: FlushDeltaMemStoresOp(dbe42619d21b4b70a13f14e2931208ea) complete. Timing: real 0.050s	user 0.026s	sys 0.016s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":18516,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:17:30.807158 26551 maintenance_manager.cc:419] P 42116023caab453792040d26a2370c7b: Scheduling FlushDeltaMemStoresOp(dbe42619d21b4b70a13f14e2931208ea): perf score=2.188937
I20260812 06:17:30.819423 26479 maintenance_manager.cc:643] P 42116023caab453792040d26a2370c7b: FlushDeltaMemStoresOp(dbe42619d21b4b70a13f14e2931208ea) complete. Timing: real 0.012s	user 0.006s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4285,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:30.819980 26551 maintenance_manager.cc:419] P 42116023caab453792040d26a2370c7b: Scheduling FlushMRSOp(dbe42619d21b4b70a13f14e2931208ea): perf score=1.000000
I20260812 06:17:30.854679 26479 maintenance_manager.cc:643] P 42116023caab453792040d26a2370c7b: FlushMRSOp(dbe42619d21b4b70a13f14e2931208ea) complete. Timing: real 0.034s	user 0.033s	sys 0.000s Metrics: {"bytes_written":1275443,"cfile_init":1,"dirs.queue_time_us":75,"dirs.run_cpu_time_us":302,"dirs.run_wall_time_us":1704,"drs_written":1,"lbm_read_time_us":40,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1628,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":31}
I20260812 06:17:30.855376 26551 maintenance_manager.cc:419] P 42116023caab453792040d26a2370c7b: Scheduling LogGCOp(dbe42619d21b4b70a13f14e2931208ea): free 128867446 bytes of WAL
I20260812 06:17:30.855650 26479 log_reader.cc:385] T dbe42619d21b4b70a13f14e2931208ea: removed 13 log segments from log reader
I20260812 06:17:30.855721 26479 log.cc:1079] T dbe42619d21b4b70a13f14e2931208ea P 42116023caab453792040d26a2370c7b: Deleting log segment in path: /tmp/dist-test-taskZj6Cvv/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515442878833-26137-0/minicluster-data/ts-0-root/wals/dbe42619d21b4b70a13f14e2931208ea/wal-000000003 (ops 12-16)
I20260812 06:17:30.855775 26479 log.cc:1079] T dbe42619d21b4b70a13f14e2931208ea P 42116023caab453792040d26a2370c7b: Deleting log segment in path: /tmp/dist-test-taskZj6Cvv/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515442878833-26137-0/minicluster-data/ts-0-root/wals/dbe42619d21b4b70a13f14e2931208ea/wal-000000004 (ops 17-20)
I20260812 06:17:30.855849 26479 log.cc:1079] T dbe42619d21b4b70a13f14e2931208ea P 42116023caab453792040d26a2370c7b: Deleting log segment in path: /tmp/dist-test-taskZj6Cvv/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515442878833-26137-0/minicluster-data/ts-0-root/wals/dbe42619d21b4b70a13f14e2931208ea/wal-000000005 (ops 21-25)
I20260812 06:17:30.855890 26479 log.cc:1079] T dbe42619d21b4b70a13f14e2931208ea P 42116023caab453792040d26a2370c7b: Deleting log segment in path: /tmp/dist-test-taskZj6Cvv/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515442878833-26137-0/minicluster-data/ts-0-root/wals/dbe42619d21b4b70a13f14e2931208ea/wal-000000006 (ops 26-30)
I20260812 06:17:30.855930 26479 log.cc:1079] T dbe42619d21b4b70a13f14e2931208ea P 42116023caab453792040d26a2370c7b: Deleting log segment in path: /tmp/dist-test-taskZj6Cvv/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515442878833-26137-0/minicluster-data/ts-0-root/wals/dbe42619d21b4b70a13f14e2931208ea/wal-000000007 (ops 31-35)
I20260812 06:17:30.855970 26479 log.cc:1079] T dbe42619d21b4b70a13f14e2931208ea P 42116023caab453792040d26a2370c7b: Deleting log segment in path: /tmp/dist-test-taskZj6Cvv/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515442878833-26137-0/minicluster-data/ts-0-root/wals/dbe42619d21b4b70a13f14e2931208ea/wal-000000008 (ops 36-40)
I20260812 06:17:30.856007 26479 log.cc:1079] T dbe42619d21b4b70a13f14e2931208ea P 42116023caab453792040d26a2370c7b: Deleting log segment in path: /tmp/dist-test-taskZj6Cvv/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515442878833-26137-0/minicluster-data/ts-0-root/wals/dbe42619d21b4b70a13f14e2931208ea/wal-000000009 (ops 41-44)
I20260812 06:17:30.856048 26479 log.cc:1079] T dbe42619d21b4b70a13f14e2931208ea P 42116023caab453792040d26a2370c7b: Deleting log segment in path: /tmp/dist-test-taskZj6Cvv/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515442878833-26137-0/minicluster-data/ts-0-root/wals/dbe42619d21b4b70a13f14e2931208ea/wal-000000010 (ops 45-49)
I20260812 06:17:30.856088 26479 log.cc:1079] T dbe42619d21b4b70a13f14e2931208ea P 42116023caab453792040d26a2370c7b: Deleting log segment in path: /tmp/dist-test-taskZj6Cvv/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515442878833-26137-0/minicluster-data/ts-0-root/wals/dbe42619d21b4b70a13f14e2931208ea/wal-000000011 (ops 50-54)
I20260812 06:17:30.856134 26479 log.cc:1079] T dbe42619d21b4b70a13f14e2931208ea P 42116023caab453792040d26a2370c7b: Deleting log segment in path: /tmp/dist-test-taskZj6Cvv/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515442878833-26137-0/minicluster-data/ts-0-root/wals/dbe42619d21b4b70a13f14e2931208ea/wal-000000012 (ops 55-59)
I20260812 06:17:30.856175 26479 log.cc:1079] T dbe42619d21b4b70a13f14e2931208ea P 42116023caab453792040d26a2370c7b: Deleting log segment in path: /tmp/dist-test-taskZj6Cvv/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515442878833-26137-0/minicluster-data/ts-0-root/wals/dbe42619d21b4b70a13f14e2931208ea/wal-000000013 (ops 60-64)
I20260812 06:17:30.856216 26479 log.cc:1079] T dbe42619d21b4b70a13f14e2931208ea P 42116023caab453792040d26a2370c7b: Deleting log segment in path: /tmp/dist-test-taskZj6Cvv/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515442878833-26137-0/minicluster-data/ts-0-root/wals/dbe42619d21b4b70a13f14e2931208ea/wal-000000014 (ops 65-68)
I20260812 06:17:30.856257 26479 log.cc:1079] T dbe42619d21b4b70a13f14e2931208ea P 42116023caab453792040d26a2370c7b: Deleting log segment in path: /tmp/dist-test-taskZj6Cvv/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515442878833-26137-0/minicluster-data/ts-0-root/wals/dbe42619d21b4b70a13f14e2931208ea/wal-000000015 (ops 69-73)
I20260812 06:17:30.885339 26479 maintenance_manager.cc:643] P 42116023caab453792040d26a2370c7b: LogGCOp(dbe42619d21b4b70a13f14e2931208ea) complete. Timing: real 0.030s	user 0.000s	sys 0.026s Metrics: {"spinlock_wait_cycles":1920}
I20260812 06:17:30.885993 26551 maintenance_manager.cc:419] P 42116023caab453792040d26a2370c7b: Scheduling UndoDeltaBlockGCOp(dbe42619d21b4b70a13f14e2931208ea): 483 bytes on disk
I20260812 06:17:30.886464 26479 maintenance_manager.cc:643] P 42116023caab453792040d26a2370c7b: UndoDeltaBlockGCOp(dbe42619d21b4b70a13f14e2931208ea) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":57,"lbm_reads_lt_1ms":4}
I20260812 06:17:30.886937 26551 maintenance_manager.cc:419] P 42116023caab453792040d26a2370c7b: Scheduling FlushDeltaMemStoresOp(dbe42619d21b4b70a13f14e2931208ea): perf score=5.165500
I20260812 06:17:30.921231 26479 maintenance_manager.cc:643] P 42116023caab453792040d26a2370c7b: FlushDeltaMemStoresOp(dbe42619d21b4b70a13f14e2931208ea) complete. Timing: real 0.034s	user 0.008s	sys 0.023s Metrics: {"bytes_written":6892306,"delete_count":0,"lbm_write_time_us":9663,"lbm_writes_lt_1ms":171,"reinsert_count":0,"update_count":840}
I20260812 06:17:30.922042 26551 maintenance_manager.cc:419] P 42116023caab453792040d26a2370c7b: Scheduling FlushDeltaMemStoresOp(dbe42619d21b4b70a13f14e2931208ea): perf score=1.000000
I20260812 06:17:30.928066 26479 maintenance_manager.cc:643] P 42116023caab453792040d26a2370c7b: FlushDeltaMemStoresOp(dbe42619d21b4b70a13f14e2931208ea) complete. Timing: real 0.006s	user 0.003s	sys 0.001s Metrics: {"bytes_written":1312952,"delete_count":0,"lbm_write_time_us":1589,"lbm_writes_lt_1ms":35,"reinsert_count":0,"update_count":160}
I20260812 06:17:30.928547 26551 maintenance_manager.cc:419] P 42116023caab453792040d26a2370c7b: Scheduling MajorDeltaCompactionOp(dbe42619d21b4b70a13f14e2931208ea): perf score=1.000000
I20260812 06:17:31.153431 26479 maintenance_manager.cc:643] P 42116023caab453792040d26a2370c7b: MajorDeltaCompactionOp(dbe42619d21b4b70a13f14e2931208ea) complete. Timing: real 0.225s	user 0.140s	sys 0.084s Metrics: {"cfile_cache_miss":634,"cfile_cache_miss_bytes":28877274,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":1092,"lbm_read_time_us":15804,"lbm_reads_lt_1ms":674,"lbm_write_time_us":38391,"lbm_writes_lt_1ms":643,"mutex_wait_us":112,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":1792,"thread_start_us":86,"threads_started":1,"update_count":3000}
I20260812 06:17:31.154217 26551 maintenance_manager.cc:419] P 42116023caab453792040d26a2370c7b: Scheduling FlushDeltaMemStoresOp(dbe42619d21b4b70a13f14e2931208ea): perf score=14.095187
I20260812 06:17:31.218372 26479 maintenance_manager.cc:643] P 42116023caab453792040d26a2370c7b: FlushDeltaMemStoresOp(dbe42619d21b4b70a13f14e2931208ea) complete. Timing: real 0.064s	user 0.040s	sys 0.022s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":22347,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:17:31.218998 26551 maintenance_manager.cc:419] P 42116023caab453792040d26a2370c7b: Scheduling FlushDeltaMemStoresOp(dbe42619d21b4b70a13f14e2931208ea): perf score=2.188937
I20260812 06:17:31.231103 26479 maintenance_manager.cc:643] P 42116023caab453792040d26a2370c7b: FlushDeltaMemStoresOp(dbe42619d21b4b70a13f14e2931208ea) complete. Timing: real 0.012s	user 0.006s	sys 0.005s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4637,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:31.231686 26551 maintenance_manager.cc:419] P 42116023caab453792040d26a2370c7b: Scheduling MajorDeltaCompactionOp(dbe42619d21b4b70a13f14e2931208ea): perf score=1.000000
I20260812 06:17:31.429446 26479 maintenance_manager.cc:643] P 42116023caab453792040d26a2370c7b: MajorDeltaCompactionOp(dbe42619d21b4b70a13f14e2931208ea) complete. Timing: real 0.198s	user 0.127s	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":1444,"lbm_read_time_us":15359,"lbm_reads_lt_1ms":572,"lbm_write_time_us":30552,"lbm_writes_lt_1ms":543,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":9984,"update_count":2500}
I20260812 06:17:31.430120 26551 maintenance_manager.cc:419] P 42116023caab453792040d26a2370c7b: Scheduling FlushDeltaMemStoresOp(dbe42619d21b4b70a13f14e2931208ea): perf score=11.118625
I20260812 06:17:31.473502 26479 maintenance_manager.cc:643] P 42116023caab453792040d26a2370c7b: FlushDeltaMemStoresOp(dbe42619d21b4b70a13f14e2931208ea) complete. Timing: real 0.043s	user 0.032s	sys 0.007s Metrics: {"bytes_written":12717736,"delete_count":0,"lbm_write_time_us":18175,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:17:31.474251 26551 maintenance_manager.cc:419] P 42116023caab453792040d26a2370c7b: Scheduling FlushDeltaMemStoresOp(dbe42619d21b4b70a13f14e2931208ea): perf score=2.188937
I20260812 06:17:31.499043 26479 maintenance_manager.cc:643] P 42116023caab453792040d26a2370c7b: FlushDeltaMemStoresOp(dbe42619d21b4b70a13f14e2931208ea) complete. Timing: real 0.025s	user 0.010s	sys 0.000s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":4285,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:17:31.499661 26551 maintenance_manager.cc:419] P 42116023caab453792040d26a2370c7b: Scheduling FlushDeltaMemStoresOp(dbe42619d21b4b70a13f14e2931208ea): perf score=2.188937
I20260812 06:17:31.529574 26479 maintenance_manager.cc:643] P 42116023caab453792040d26a2370c7b: FlushDeltaMemStoresOp(dbe42619d21b4b70a13f14e2931208ea) complete. Timing: real 0.030s	user 0.011s	sys 0.014s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5988,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:31.530412 26551 maintenance_manager.cc:419] P 42116023caab453792040d26a2370c7b: Scheduling MajorDeltaCompactionOp(dbe42619d21b4b70a13f14e2931208ea): perf score=1.000000
I20260812 06:17:31.730628 26479 maintenance_manager.cc:643] P 42116023caab453792040d26a2370c7b: MajorDeltaCompactionOp(dbe42619d21b4b70a13f14e2931208ea) complete. Timing: real 0.200s	user 0.128s	sys 0.064s Metrics: {"cfile_cache_miss":533,"cfile_cache_miss_bytes":24774800,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":272,"lbm_read_time_us":13718,"lbm_reads_lt_1ms":573,"lbm_write_time_us":32414,"lbm_writes_lt_1ms":543,"mutex_wait_us":30,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":13056,"update_count":2500}
I20260812 06:17:31.731422 26551 maintenance_manager.cc:419] P 42116023caab453792040d26a2370c7b: Scheduling FlushDeltaMemStoresOp(dbe42619d21b4b70a13f14e2931208ea): perf score=14.095187
I20260812 06:17:31.790804 26479 maintenance_manager.cc:643] P 42116023caab453792040d26a2370c7b: FlushDeltaMemStoresOp(dbe42619d21b4b70a13f14e2931208ea) complete. Timing: real 0.059s	user 0.035s	sys 0.012s Metrics: {"bytes_written":16409905,"delete_count":0,"lbm_write_time_us":21841,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:17:31.791363 26551 maintenance_manager.cc:419] P 42116023caab453792040d26a2370c7b: Scheduling FlushDeltaMemStoresOp(dbe42619d21b4b70a13f14e2931208ea): perf score=2.188937
I20260812 06:17:31.803651 26479 maintenance_manager.cc:643] P 42116023caab453792040d26a2370c7b: FlushDeltaMemStoresOp(dbe42619d21b4b70a13f14e2931208ea) complete. Timing: real 0.012s	user 0.006s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4345,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:31.804240 26551 maintenance_manager.cc:419] P 42116023caab453792040d26a2370c7b: Scheduling MajorDeltaCompactionOp(dbe42619d21b4b70a13f14e2931208ea): perf score=1.000000
I20260812 06:17:31.998653 26479 maintenance_manager.cc:643] P 42116023caab453792040d26a2370c7b: MajorDeltaCompactionOp(dbe42619d21b4b70a13f14e2931208ea) complete. Timing: real 0.194s	user 0.124s	sys 0.062s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774692,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":1507,"lbm_read_time_us":12961,"lbm_reads_lt_1ms":572,"lbm_write_time_us":29253,"lbm_writes_lt_1ms":543,"mutex_wait_us":26,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":9472,"update_count":2500}
I20260812 06:17:31.999221 26551 maintenance_manager.cc:419] P 42116023caab453792040d26a2370c7b: Scheduling FlushDeltaMemStoresOp(dbe42619d21b4b70a13f14e2931208ea): perf score=14.095187
I20260812 06:17:32.058730 26479 maintenance_manager.cc:643] P 42116023caab453792040d26a2370c7b: FlushDeltaMemStoresOp(dbe42619d21b4b70a13f14e2931208ea) complete. Timing: real 0.059s	user 0.042s	sys 0.012s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":24990,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:17:32.059252 26551 maintenance_manager.cc:419] P 42116023caab453792040d26a2370c7b: Scheduling FlushDeltaMemStoresOp(dbe42619d21b4b70a13f14e2931208ea): perf score=2.188937
I20260812 06:17:32.072177 26479 maintenance_manager.cc:643] P 42116023caab453792040d26a2370c7b: FlushDeltaMemStoresOp(dbe42619d21b4b70a13f14e2931208ea) complete. Timing: real 0.013s	user 0.006s	sys 0.005s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4577,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:32.072723 26551 maintenance_manager.cc:419] P 42116023caab453792040d26a2370c7b: Scheduling MajorDeltaCompactionOp(dbe42619d21b4b70a13f14e2931208ea): perf score=1.000000
I20260812 06:17:32.228482 26479 maintenance_manager.cc:643] P 42116023caab453792040d26a2370c7b: MajorDeltaCompactionOp(dbe42619d21b4b70a13f14e2931208ea) complete. Timing: real 0.156s	user 0.108s	sys 0.046s 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":794,"lbm_read_time_us":11442,"lbm_reads_lt_1ms":572,"lbm_write_time_us":31333,"lbm_writes_lt_1ms":543,"mutex_wait_us":398,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":11904,"update_count":2500}
I20260812 06:17:32.229215 26551 maintenance_manager.cc:419] P 42116023caab453792040d26a2370c7b: Scheduling FlushDeltaMemStoresOp(dbe42619d21b4b70a13f14e2931208ea): perf score=10.126437
I20260812 06:17:32.263969 26479 maintenance_manager.cc:643] P 42116023caab453792040d26a2370c7b: FlushDeltaMemStoresOp(dbe42619d21b4b70a13f14e2931208ea) complete. Timing: real 0.035s	user 0.019s	sys 0.013s Metrics: {"bytes_written":12307489,"delete_count":0,"lbm_write_time_us":15076,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:17:32.264528 26551 maintenance_manager.cc:419] P 42116023caab453792040d26a2370c7b: Scheduling FlushDeltaMemStoresOp(dbe42619d21b4b70a13f14e2931208ea): perf score=2.188937
I20260812 06:17:32.284025 26479 maintenance_manager.cc:643] P 42116023caab453792040d26a2370c7b: FlushDeltaMemStoresOp(dbe42619d21b4b70a13f14e2931208ea) complete. Timing: real 0.019s	user 0.013s	sys 0.001s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5812,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:32.284845 26551 maintenance_manager.cc:419] P 42116023caab453792040d26a2370c7b: Scheduling MajorDeltaCompactionOp(dbe42619d21b4b70a13f14e2931208ea): perf score=1.000000
I20260812 06:17:32.426731 26479 maintenance_manager.cc:643] P 42116023caab453792040d26a2370c7b: MajorDeltaCompactionOp(dbe42619d21b4b70a13f14e2931208ea) complete. Timing: real 0.142s	user 0.097s	sys 0.044s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672276,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":198,"lbm_read_time_us":8919,"lbm_reads_lt_1ms":468,"lbm_write_time_us":29298,"lbm_writes_lt_1ms":443,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":3584,"update_count":2000}
I20260812 06:17:32.427318 26551 maintenance_manager.cc:419] P 42116023caab453792040d26a2370c7b: Scheduling FlushDeltaMemStoresOp(dbe42619d21b4b70a13f14e2931208ea): perf score=10.126437
I20260812 06:17:32.478274 26479 maintenance_manager.cc:643] P 42116023caab453792040d26a2370c7b: FlushDeltaMemStoresOp(dbe42619d21b4b70a13f14e2931208ea) complete. Timing: real 0.051s	user 0.038s	sys 0.000s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":16798,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:17:32.478878 26551 maintenance_manager.cc:419] P 42116023caab453792040d26a2370c7b: Scheduling FlushDeltaMemStoresOp(dbe42619d21b4b70a13f14e2931208ea): perf score=2.188937
I20260812 06:17:32.490778 26479 maintenance_manager.cc:643] P 42116023caab453792040d26a2370c7b: FlushDeltaMemStoresOp(dbe42619d21b4b70a13f14e2931208ea) complete. Timing: real 0.012s	user 0.007s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4217,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:32.491501 26551 maintenance_manager.cc:419] P 42116023caab453792040d26a2370c7b: Scheduling FlushMRSOp(dbe42619d21b4b70a13f14e2931208ea): perf score=1.000000
I20260812 06:17:32.525898 26479 maintenance_manager.cc:643] P 42116023caab453792040d26a2370c7b: FlushMRSOp(dbe42619d21b4b70a13f14e2931208ea) complete. Timing: real 0.034s	user 0.034s	sys 0.000s Metrics: {"bytes_written":1234479,"cfile_init":1,"dirs.queue_time_us":84,"dirs.run_cpu_time_us":282,"dirs.run_wall_time_us":1845,"drs_written":1,"lbm_read_time_us":41,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1654,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":30}
I20260812 06:17:32.526659 26551 maintenance_manager.cc:419] P 42116023caab453792040d26a2370c7b: Scheduling LogGCOp(dbe42619d21b4b70a13f14e2931208ea): free 121006461 bytes of WAL
I20260812 06:17:32.526939 26479 log_reader.cc:385] T dbe42619d21b4b70a13f14e2931208ea: removed 12 log segments from log reader
I20260812 06:17:32.526988 26479 log.cc:1079] T dbe42619d21b4b70a13f14e2931208ea P 42116023caab453792040d26a2370c7b: Deleting log segment in path: /tmp/dist-test-taskZj6Cvv/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515442878833-26137-0/minicluster-data/ts-0-root/wals/dbe42619d21b4b70a13f14e2931208ea/wal-000000016 (ops 74-78)
I20260812 06:17:32.527019 26479 log.cc:1079] T dbe42619d21b4b70a13f14e2931208ea P 42116023caab453792040d26a2370c7b: Deleting log segment in path: /tmp/dist-test-taskZj6Cvv/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515442878833-26137-0/minicluster-data/ts-0-root/wals/dbe42619d21b4b70a13f14e2931208ea/wal-000000017 (ops 79-83)
I20260812 06:17:32.527133 26479 log.cc:1079] T dbe42619d21b4b70a13f14e2931208ea P 42116023caab453792040d26a2370c7b: Deleting log segment in path: /tmp/dist-test-taskZj6Cvv/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515442878833-26137-0/minicluster-data/ts-0-root/wals/dbe42619d21b4b70a13f14e2931208ea/wal-000000018 (ops 84-88)
I20260812 06:17:32.527182 26479 log.cc:1079] T dbe42619d21b4b70a13f14e2931208ea P 42116023caab453792040d26a2370c7b: Deleting log segment in path: /tmp/dist-test-taskZj6Cvv/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515442878833-26137-0/minicluster-data/ts-0-root/wals/dbe42619d21b4b70a13f14e2931208ea/wal-000000019 (ops 89-92)
I20260812 06:17:32.527200 26479 log.cc:1079] T dbe42619d21b4b70a13f14e2931208ea P 42116023caab453792040d26a2370c7b: Deleting log segment in path: /tmp/dist-test-taskZj6Cvv/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515442878833-26137-0/minicluster-data/ts-0-root/wals/dbe42619d21b4b70a13f14e2931208ea/wal-000000020 (ops 93-97)
I20260812 06:17:32.527269 26479 log.cc:1079] T dbe42619d21b4b70a13f14e2931208ea P 42116023caab453792040d26a2370c7b: Deleting log segment in path: /tmp/dist-test-taskZj6Cvv/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515442878833-26137-0/minicluster-data/ts-0-root/wals/dbe42619d21b4b70a13f14e2931208ea/wal-000000021 (ops 98-102)
I20260812 06:17:32.527316 26479 log.cc:1079] T dbe42619d21b4b70a13f14e2931208ea P 42116023caab453792040d26a2370c7b: Deleting log segment in path: /tmp/dist-test-taskZj6Cvv/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515442878833-26137-0/minicluster-data/ts-0-root/wals/dbe42619d21b4b70a13f14e2931208ea/wal-000000022 (ops 103-107)
I20260812 06:17:32.527359 26479 log.cc:1079] T dbe42619d21b4b70a13f14e2931208ea P 42116023caab453792040d26a2370c7b: Deleting log segment in path: /tmp/dist-test-taskZj6Cvv/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515442878833-26137-0/minicluster-data/ts-0-root/wals/dbe42619d21b4b70a13f14e2931208ea/wal-000000023 (ops 108-112)
I20260812 06:17:32.527397 26479 log.cc:1079] T dbe42619d21b4b70a13f14e2931208ea P 42116023caab453792040d26a2370c7b: Deleting log segment in path: /tmp/dist-test-taskZj6Cvv/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515442878833-26137-0/minicluster-data/ts-0-root/wals/dbe42619d21b4b70a13f14e2931208ea/wal-000000024 (ops 113-117)
I20260812 06:17:32.527453 26479 log.cc:1079] T dbe42619d21b4b70a13f14e2931208ea P 42116023caab453792040d26a2370c7b: Deleting log segment in path: /tmp/dist-test-taskZj6Cvv/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515442878833-26137-0/minicluster-data/ts-0-root/wals/dbe42619d21b4b70a13f14e2931208ea/wal-000000025 (ops 118-122)
I20260812 06:17:32.527495 26479 log.cc:1079] T dbe42619d21b4b70a13f14e2931208ea P 42116023caab453792040d26a2370c7b: Deleting log segment in path: /tmp/dist-test-taskZj6Cvv/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515442878833-26137-0/minicluster-data/ts-0-root/wals/dbe42619d21b4b70a13f14e2931208ea/wal-000000026 (ops 123-127)
I20260812 06:17:32.527534 26479 log.cc:1079] T dbe42619d21b4b70a13f14e2931208ea P 42116023caab453792040d26a2370c7b: Deleting log segment in path: /tmp/dist-test-taskZj6Cvv/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515442878833-26137-0/minicluster-data/ts-0-root/wals/dbe42619d21b4b70a13f14e2931208ea/wal-000000027 (ops 128-132)
I20260812 06:17:32.556741 26479 maintenance_manager.cc:643] P 42116023caab453792040d26a2370c7b: LogGCOp(dbe42619d21b4b70a13f14e2931208ea) complete. Timing: real 0.030s	user 0.000s	sys 0.027s Metrics: {}
I20260812 06:17:32.557283 26551 maintenance_manager.cc:419] P 42116023caab453792040d26a2370c7b: Scheduling FlushDeltaMemStoresOp(dbe42619d21b4b70a13f14e2931208ea): perf score=3.181125
I20260812 06:17:32.576429 26479 maintenance_manager.cc:643] P 42116023caab453792040d26a2370c7b: FlushDeltaMemStoresOp(dbe42619d21b4b70a13f14e2931208ea) complete. Timing: real 0.019s	user 0.016s	sys 0.000s Metrics: {"bytes_written":4512902,"delete_count":0,"lbm_write_time_us":7771,"lbm_writes_lt_1ms":113,"reinsert_count":0,"update_count":550}
I20260812 06:17:32.576936 26551 maintenance_manager.cc:419] P 42116023caab453792040d26a2370c7b: Scheduling UndoDeltaBlockGCOp(dbe42619d21b4b70a13f14e2931208ea): 472 bytes on disk
I20260812 06:17:32.577407 26479 maintenance_manager.cc:643] P 42116023caab453792040d26a2370c7b: UndoDeltaBlockGCOp(dbe42619d21b4b70a13f14e2931208ea) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":61,"lbm_reads_lt_1ms":4}
I20260812 06:17:32.578006 26551 maintenance_manager.cc:419] P 42116023caab453792040d26a2370c7b: Scheduling FlushDeltaMemStoresOp(dbe42619d21b4b70a13f14e2931208ea): perf score=2.188937
I20260812 06:17:32.588701 26479 maintenance_manager.cc:643] P 42116023caab453792040d26a2370c7b: FlushDeltaMemStoresOp(dbe42619d21b4b70a13f14e2931208ea) complete. Timing: real 0.011s	user 0.001s	sys 0.008s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":4172,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:17:32.589437 26551 maintenance_manager.cc:419] P 42116023caab453792040d26a2370c7b: Scheduling MajorDeltaCompactionOp(dbe42619d21b4b70a13f14e2931208ea): perf score=1.000000
I20260812 06:17:32.776855 26479 maintenance_manager.cc:643] P 42116023caab453792040d26a2370c7b: MajorDeltaCompactionOp(dbe42619d21b4b70a13f14e2931208ea) complete. Timing: real 0.187s	user 0.132s	sys 0.052s Metrics: {"cfile_cache_miss":634,"cfile_cache_miss_bytes":28877328,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":3181,"lbm_read_time_us":12927,"lbm_reads_lt_1ms":674,"lbm_write_time_us":38718,"lbm_writes_lt_1ms":643,"mutex_wait_us":2271,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":12160,"thread_start_us":89,"threads_started":1,"update_count":3000}
I20260812 06:17:32.777592 26551 maintenance_manager.cc:419] P 42116023caab453792040d26a2370c7b: Scheduling FlushDeltaMemStoresOp(dbe42619d21b4b70a13f14e2931208ea): perf score=14.095187
I20260812 06:17:32.828960 26479 maintenance_manager.cc:643] P 42116023caab453792040d26a2370c7b: FlushDeltaMemStoresOp(dbe42619d21b4b70a13f14e2931208ea) complete. Timing: real 0.051s	user 0.035s	sys 0.009s Metrics: {"bytes_written":16409900,"delete_count":0,"lbm_write_time_us":20653,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:17:32.829501 26551 maintenance_manager.cc:419] P 42116023caab453792040d26a2370c7b: Scheduling FlushDeltaMemStoresOp(dbe42619d21b4b70a13f14e2931208ea): perf score=2.188937
I20260812 06:17:32.841557 26479 maintenance_manager.cc:643] P 42116023caab453792040d26a2370c7b: FlushDeltaMemStoresOp(dbe42619d21b4b70a13f14e2931208ea) complete. Timing: real 0.012s	user 0.005s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4247,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:32.842159 26551 maintenance_manager.cc:419] P 42116023caab453792040d26a2370c7b: Scheduling MajorDeltaCompactionOp(dbe42619d21b4b70a13f14e2931208ea): perf score=1.000000
I20260812 06:17:33.005921 26479 maintenance_manager.cc:643] P 42116023caab453792040d26a2370c7b: MajorDeltaCompactionOp(dbe42619d21b4b70a13f14e2931208ea) complete. Timing: real 0.164s	user 0.116s	sys 0.040s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774687,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":773,"lbm_read_time_us":12062,"lbm_reads_lt_1ms":572,"lbm_write_time_us":28790,"lbm_writes_lt_1ms":543,"mutex_wait_us":85,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":5248,"update_count":2500}
I20260812 06:17:33.006729 26551 maintenance_manager.cc:419] P 42116023caab453792040d26a2370c7b: Scheduling FlushDeltaMemStoresOp(dbe42619d21b4b70a13f14e2931208ea): perf score=14.095187
I20260812 06:17:33.075800 26479 maintenance_manager.cc:643] P 42116023caab453792040d26a2370c7b: FlushDeltaMemStoresOp(dbe42619d21b4b70a13f14e2931208ea) complete. Timing: real 0.068s	user 0.021s	sys 0.036s Metrics: {"bytes_written":16327853,"delete_count":0,"lbm_write_time_us":28817,"lbm_writes_1-10_ms":4,"lbm_writes_lt_1ms":397,"reinsert_count":0,"update_count":1990}
I20260812 06:17:33.076552 26551 maintenance_manager.cc:419] P 42116023caab453792040d26a2370c7b: Scheduling FlushDeltaMemStoresOp(dbe42619d21b4b70a13f14e2931208ea): perf score=2.188937
I20260812 06:17:33.091172 26479 maintenance_manager.cc:643] P 42116023caab453792040d26a2370c7b: FlushDeltaMemStoresOp(dbe42619d21b4b70a13f14e2931208ea) complete. Timing: real 0.014s	user 0.011s	sys 0.002s Metrics: {"bytes_written":4184711,"delete_count":0,"lbm_write_time_us":4954,"lbm_writes_lt_1ms":105,"reinsert_count":0,"update_count":510}
I20260812 06:17:33.091781 26551 maintenance_manager.cc:419] P 42116023caab453792040d26a2370c7b: Scheduling MajorDeltaCompactionOp(dbe42619d21b4b70a13f14e2931208ea): perf score=1.000000
I20260812 06:17:33.280831 26479 maintenance_manager.cc:643] P 42116023caab453792040d26a2370c7b: MajorDeltaCompactionOp(dbe42619d21b4b70a13f14e2931208ea) complete. Timing: real 0.189s	user 0.111s	sys 0.069s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774692,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":365,"lbm_read_time_us":12807,"lbm_reads_lt_1ms":572,"lbm_write_time_us":33592,"lbm_writes_lt_1ms":543,"mutex_wait_us":27,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":92416,"update_count":2500}
I20260812 06:17:33.281424 26551 maintenance_manager.cc:419] P 42116023caab453792040d26a2370c7b: Scheduling FlushDeltaMemStoresOp(dbe42619d21b4b70a13f14e2931208ea): perf score=14.095187
I20260812 06:17:33.344414 26479 maintenance_manager.cc:643] P 42116023caab453792040d26a2370c7b: FlushDeltaMemStoresOp(dbe42619d21b4b70a13f14e2931208ea) complete. Timing: real 0.063s	user 0.028s	sys 0.019s Metrics: {"bytes_written":16409900,"delete_count":0,"lbm_write_time_us":21940,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:17:33.345024 26551 maintenance_manager.cc:419] P 42116023caab453792040d26a2370c7b: Scheduling FlushDeltaMemStoresOp(dbe42619d21b4b70a13f14e2931208ea): perf score=2.188937
I20260812 06:17:33.361490 26479 maintenance_manager.cc:643] P 42116023caab453792040d26a2370c7b: FlushDeltaMemStoresOp(dbe42619d21b4b70a13f14e2931208ea) complete. Timing: real 0.016s	user 0.006s	sys 0.007s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6298,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:33.362295 26551 maintenance_manager.cc:419] P 42116023caab453792040d26a2370c7b: Scheduling MajorDeltaCompactionOp(dbe42619d21b4b70a13f14e2931208ea): perf score=1.000000
I20260812 06:17:33.552932 26479 maintenance_manager.cc:643] P 42116023caab453792040d26a2370c7b: MajorDeltaCompactionOp(dbe42619d21b4b70a13f14e2931208ea) complete. Timing: real 0.190s	user 0.114s	sys 0.076s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774687,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":770,"lbm_read_time_us":14135,"lbm_reads_lt_1ms":572,"lbm_write_time_us":32828,"lbm_writes_lt_1ms":543,"mutex_wait_us":31,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":33792,"update_count":2500}
I20260812 06:17:33.553766 26551 maintenance_manager.cc:419] P 42116023caab453792040d26a2370c7b: Scheduling FlushDeltaMemStoresOp(dbe42619d21b4b70a13f14e2931208ea): perf score=14.095187
I20260812 06:17:33.618111 26479 maintenance_manager.cc:643] P 42116023caab453792040d26a2370c7b: FlushDeltaMemStoresOp(dbe42619d21b4b70a13f14e2931208ea) complete. Timing: real 0.064s	user 0.032s	sys 0.028s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":22098,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:17:33.618774 26551 maintenance_manager.cc:419] P 42116023caab453792040d26a2370c7b: Scheduling FlushDeltaMemStoresOp(dbe42619d21b4b70a13f14e2931208ea): perf score=2.188937
I20260812 06:17:33.630381 26479 maintenance_manager.cc:643] P 42116023caab453792040d26a2370c7b: FlushDeltaMemStoresOp(dbe42619d21b4b70a13f14e2931208ea) complete. Timing: real 0.011s	user 0.006s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4432,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:33.630911 26551 maintenance_manager.cc:419] P 42116023caab453792040d26a2370c7b: Scheduling MajorDeltaCompactionOp(dbe42619d21b4b70a13f14e2931208ea): perf score=1.000000
I20260812 06:17:33.829162 26479 maintenance_manager.cc:643] P 42116023caab453792040d26a2370c7b: MajorDeltaCompactionOp(dbe42619d21b4b70a13f14e2931208ea) complete. Timing: real 0.198s	user 0.105s	sys 0.083s 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":461,"lbm_read_time_us":13901,"lbm_reads_lt_1ms":572,"lbm_write_time_us":31054,"lbm_writes_lt_1ms":543,"mutex_wait_us":83,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":8320,"update_count":2500}
I20260812 06:17:33.829906 26551 maintenance_manager.cc:419] P 42116023caab453792040d26a2370c7b: Scheduling FlushDeltaMemStoresOp(dbe42619d21b4b70a13f14e2931208ea): perf score=14.095187
I20260812 06:17:33.893914 26479 maintenance_manager.cc:643] P 42116023caab453792040d26a2370c7b: FlushDeltaMemStoresOp(dbe42619d21b4b70a13f14e2931208ea) complete. Timing: real 0.061s	user 0.021s	sys 0.039s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":21452,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:17:33.894660 26551 maintenance_manager.cc:419] P 42116023caab453792040d26a2370c7b: Scheduling FlushDeltaMemStoresOp(dbe42619d21b4b70a13f14e2931208ea): perf score=2.188937
I20260812 06:17:33.913259 26479 maintenance_manager.cc:643] P 42116023caab453792040d26a2370c7b: FlushDeltaMemStoresOp(dbe42619d21b4b70a13f14e2931208ea) complete. Timing: real 0.018s	user 0.008s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6972,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:33.913985 26551 maintenance_manager.cc:419] P 42116023caab453792040d26a2370c7b: Scheduling MajorDeltaCompactionOp(dbe42619d21b4b70a13f14e2931208ea): perf score=1.000000
I20260812 06:17:34.104295 26479 maintenance_manager.cc:643] P 42116023caab453792040d26a2370c7b: MajorDeltaCompactionOp(dbe42619d21b4b70a13f14e2931208ea) complete. Timing: real 0.190s	user 0.121s	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":972,"lbm_read_time_us":13330,"lbm_reads_lt_1ms":572,"lbm_write_time_us":31286,"lbm_writes_lt_1ms":543,"mutex_wait_us":40,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":768,"update_count":2500}
I20260812 06:17:34.105048 26551 maintenance_manager.cc:419] P 42116023caab453792040d26a2370c7b: Scheduling FlushDeltaMemStoresOp(dbe42619d21b4b70a13f14e2931208ea): perf score=14.095187
I20260812 06:17:34.164135 26479 maintenance_manager.cc:643] P 42116023caab453792040d26a2370c7b: FlushDeltaMemStoresOp(dbe42619d21b4b70a13f14e2931208ea) complete. Timing: real 0.059s	user 0.021s	sys 0.035s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":26436,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":402,"reinsert_count":0,"update_count":2000}
I20260812 06:17:34.164732 26551 maintenance_manager.cc:419] P 42116023caab453792040d26a2370c7b: Scheduling FlushDeltaMemStoresOp(dbe42619d21b4b70a13f14e2931208ea): perf score=2.188937
I20260812 06:17:34.187147 26479 maintenance_manager.cc:643] P 42116023caab453792040d26a2370c7b: FlushDeltaMemStoresOp(dbe42619d21b4b70a13f14e2931208ea) complete. Timing: real 0.022s	user 0.002s	sys 0.018s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4403,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:34.187700 26551 maintenance_manager.cc:419] P 42116023caab453792040d26a2370c7b: Scheduling FlushMRSOp(dbe42619d21b4b70a13f14e2931208ea): perf score=1.000000
I20260812 06:17:34.223698 26479 maintenance_manager.cc:643] P 42116023caab453792040d26a2370c7b: FlushMRSOp(dbe42619d21b4b70a13f14e2931208ea) complete. Timing: real 0.036s	user 0.031s	sys 0.003s Metrics: {"bytes_written":1316417,"cfile_init":1,"dirs.queue_time_us":108,"dirs.run_cpu_time_us":383,"dirs.run_wall_time_us":1627,"drs_written":1,"lbm_read_time_us":40,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1715,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":32,"spinlock_wait_cycles":2944}
I20260812 06:17:34.224421 26551 maintenance_manager.cc:419] P 42116023caab453792040d26a2370c7b: Scheduling LogGCOp(dbe42619d21b4b70a13f14e2931208ea): free 136275459 bytes of WAL
I20260812 06:17:34.224671 26479 log_reader.cc:385] T dbe42619d21b4b70a13f14e2931208ea: removed 13 log segments from log reader
I20260812 06:17:34.224750 26479 log.cc:1079] T dbe42619d21b4b70a13f14e2931208ea P 42116023caab453792040d26a2370c7b: Deleting log segment in path: /tmp/dist-test-taskZj6Cvv/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515442878833-26137-0/minicluster-data/ts-0-root/wals/dbe42619d21b4b70a13f14e2931208ea/wal-000000028 (ops 133-136)
I20260812 06:17:34.224808 26479 log.cc:1079] T dbe42619d21b4b70a13f14e2931208ea P 42116023caab453792040d26a2370c7b: Deleting log segment in path: /tmp/dist-test-taskZj6Cvv/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515442878833-26137-0/minicluster-data/ts-0-root/wals/dbe42619d21b4b70a13f14e2931208ea/wal-000000029 (ops 137-141)
I20260812 06:17:34.224876 26479 log.cc:1079] T dbe42619d21b4b70a13f14e2931208ea P 42116023caab453792040d26a2370c7b: Deleting log segment in path: /tmp/dist-test-taskZj6Cvv/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515442878833-26137-0/minicluster-data/ts-0-root/wals/dbe42619d21b4b70a13f14e2931208ea/wal-000000030 (ops 142-146)
I20260812 06:17:34.224922 26479 log.cc:1079] T dbe42619d21b4b70a13f14e2931208ea P 42116023caab453792040d26a2370c7b: Deleting log segment in path: /tmp/dist-test-taskZj6Cvv/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515442878833-26137-0/minicluster-data/ts-0-root/wals/dbe42619d21b4b70a13f14e2931208ea/wal-000000031 (ops 147-151)
I20260812 06:17:34.224959 26479 log.cc:1079] T dbe42619d21b4b70a13f14e2931208ea P 42116023caab453792040d26a2370c7b: Deleting log segment in path: /tmp/dist-test-taskZj6Cvv/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515442878833-26137-0/minicluster-data/ts-0-root/wals/dbe42619d21b4b70a13f14e2931208ea/wal-000000032 (ops 152-156)
I20260812 06:17:34.224999 26479 log.cc:1079] T dbe42619d21b4b70a13f14e2931208ea P 42116023caab453792040d26a2370c7b: Deleting log segment in path: /tmp/dist-test-taskZj6Cvv/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515442878833-26137-0/minicluster-data/ts-0-root/wals/dbe42619d21b4b70a13f14e2931208ea/wal-000000033 (ops 157-161)
I20260812 06:17:34.225039 26479 log.cc:1079] T dbe42619d21b4b70a13f14e2931208ea P 42116023caab453792040d26a2370c7b: Deleting log segment in path: /tmp/dist-test-taskZj6Cvv/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515442878833-26137-0/minicluster-data/ts-0-root/wals/dbe42619d21b4b70a13f14e2931208ea/wal-000000034 (ops 162-166)
I20260812 06:17:34.225085 26479 log.cc:1079] T dbe42619d21b4b70a13f14e2931208ea P 42116023caab453792040d26a2370c7b: Deleting log segment in path: /tmp/dist-test-taskZj6Cvv/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515442878833-26137-0/minicluster-data/ts-0-root/wals/dbe42619d21b4b70a13f14e2931208ea/wal-000000035 (ops 167-171)
I20260812 06:17:34.225124 26479 log.cc:1079] T dbe42619d21b4b70a13f14e2931208ea P 42116023caab453792040d26a2370c7b: Deleting log segment in path: /tmp/dist-test-taskZj6Cvv/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515442878833-26137-0/minicluster-data/ts-0-root/wals/dbe42619d21b4b70a13f14e2931208ea/wal-000000036 (ops 172-176)
I20260812 06:17:34.225188 26479 log.cc:1079] T dbe42619d21b4b70a13f14e2931208ea P 42116023caab453792040d26a2370c7b: Deleting log segment in path: /tmp/dist-test-taskZj6Cvv/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515442878833-26137-0/minicluster-data/ts-0-root/wals/dbe42619d21b4b70a13f14e2931208ea/wal-000000037 (ops 177-181)
I20260812 06:17:34.225227 26479 log.cc:1079] T dbe42619d21b4b70a13f14e2931208ea P 42116023caab453792040d26a2370c7b: Deleting log segment in path: /tmp/dist-test-taskZj6Cvv/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515442878833-26137-0/minicluster-data/ts-0-root/wals/dbe42619d21b4b70a13f14e2931208ea/wal-000000038 (ops 182-186)
I20260812 06:17:34.225267 26479 log.cc:1079] T dbe42619d21b4b70a13f14e2931208ea P 42116023caab453792040d26a2370c7b: Deleting log segment in path: /tmp/dist-test-taskZj6Cvv/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515442878833-26137-0/minicluster-data/ts-0-root/wals/dbe42619d21b4b70a13f14e2931208ea/wal-000000039 (ops 187-191)
I20260812 06:17:34.225306 26479 log.cc:1079] T dbe42619d21b4b70a13f14e2931208ea P 42116023caab453792040d26a2370c7b: Deleting log segment in path: /tmp/dist-test-taskZj6Cvv/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515442878833-26137-0/minicluster-data/ts-0-root/wals/dbe42619d21b4b70a13f14e2931208ea/wal-000000040 (ops 192-196)
I20260812 06:17:34.257915 26479 maintenance_manager.cc:643] P 42116023caab453792040d26a2370c7b: LogGCOp(dbe42619d21b4b70a13f14e2931208ea) complete. Timing: real 0.033s	user 0.000s	sys 0.033s Metrics: {}
I20260812 06:17:34.258492 26551 maintenance_manager.cc:419] P 42116023caab453792040d26a2370c7b: Scheduling UndoDeltaBlockGCOp(dbe42619d21b4b70a13f14e2931208ea): 493 bytes on disk
I20260812 06:17:34.259069 26479 maintenance_manager.cc:643] P 42116023caab453792040d26a2370c7b: UndoDeltaBlockGCOp(dbe42619d21b4b70a13f14e2931208ea) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":81,"lbm_reads_lt_1ms":4}
I20260812 06:17:34.259908 26551 maintenance_manager.cc:419] P 42116023caab453792040d26a2370c7b: Scheduling FlushDeltaMemStoresOp(dbe42619d21b4b70a13f14e2931208ea): perf score=3.181125
I20260812 06:17:34.281869 26479 maintenance_manager.cc:643] P 42116023caab453792040d26a2370c7b: FlushDeltaMemStoresOp(dbe42619d21b4b70a13f14e2931208ea) complete. Timing: real 0.022s	user 0.015s	sys 0.004s Metrics: {"bytes_written":4512903,"delete_count":0,"lbm_write_time_us":7831,"lbm_writes_lt_1ms":113,"reinsert_count":0,"update_count":550}
I20260812 06:17:34.282547 26551 maintenance_manager.cc:419] P 42116023caab453792040d26a2370c7b: Scheduling FlushDeltaMemStoresOp(dbe42619d21b4b70a13f14e2931208ea): perf score=2.188937
I20260812 06:17:34.294279 26479 maintenance_manager.cc:643] P 42116023caab453792040d26a2370c7b: FlushDeltaMemStoresOp(dbe42619d21b4b70a13f14e2931208ea) complete. Timing: real 0.011s	user 0.007s	sys 0.004s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":4342,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:17:34.294983 26551 maintenance_manager.cc:419] P 42116023caab453792040d26a2370c7b: Scheduling MajorDeltaCompactionOp(dbe42619d21b4b70a13f14e2931208ea): perf score=1.000000
I20260812 06:17:34.342926 26137 heavy-update-compaction-itest.cc:229] Time spent updating: real 5.300s	user 1.944s	sys 0.168s
I20260812 06:17:34.448750 26137 heavy-update-compaction-itest.cc:265] Time spent scanning: real 0.105s	user 0.001s	sys 0.000s
I20260812 06:17:34.449343 26137 tablet_server.cc:179] TabletServer@127.25.134.65:0 shutting down...
I20260812 06:17:34.504185 26479 maintenance_manager.cc:643] P 42116023caab453792040d26a2370c7b: MajorDeltaCompactionOp(dbe42619d21b4b70a13f14e2931208ea) complete. Timing: real 0.209s	user 0.117s	sys 0.092s Metrics: {"cfile_cache_miss":734,"cfile_cache_miss_bytes":32979739,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":773,"lbm_read_time_us":18059,"lbm_reads_lt_1ms":770,"lbm_write_time_us":35231,"lbm_writes_lt_1ms":743,"mutex_wait_us":97,"peak_mem_usage":87969044,"reinsert_count":0,"spinlock_wait_cycles":6656,"thread_start_us":81,"threads_started":1,"update_count":3500}
I20260812 06:17:34.505290 26137 ts_tablet_manager.cc:1507] Shutting down tablet manager...
I20260812 06:17:34.505801 26137 tablet_replica.cc:333] T dbe42619d21b4b70a13f14e2931208ea P 42116023caab453792040d26a2370c7b: stopping tablet replica
I20260812 06:17:34.505987 26137 raft_consensus.cc:2243] T dbe42619d21b4b70a13f14e2931208ea P 42116023caab453792040d26a2370c7b [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:17:34.506186 26137 raft_consensus.cc:2272] T dbe42619d21b4b70a13f14e2931208ea P 42116023caab453792040d26a2370c7b [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:17:34.521330 26137 tablet_server.cc:196] TabletServer@127.25.134.65:0 shutdown complete.
I20260812 06:17:34.563547 26137 master.cc:562] Master@127.25.134.126:43163 shutting down...
I20260812 06:17:34.567628 26137 raft_consensus.cc:2243] T 00000000000000000000000000000000 P e3dfa1baf7cf4cc391c3225f0f9e0896 [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:17:34.567899 26137 raft_consensus.cc:2272] T 00000000000000000000000000000000 P e3dfa1baf7cf4cc391c3225f0f9e0896 [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:17:34.567984 26137 tablet_replica.cc:333] T 00000000000000000000000000000000 P e3dfa1baf7cf4cc391c3225f0f9e0896: stopping tablet replica
I20260812 06:17:34.580842 26137 master.cc:584] Master@127.25.134.126:43163 shutdown complete.
[       OK ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/1 (5837 ms)
[----------] 2 tests from EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy (11782 ms total)

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