[==========] Running 2 tests from 1 test suite.
[----------] Global test environment set-up.
[----------] 2 tests from EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy
[ RUN      ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/0
WARNING: Logging before InitGoogleLogging() is written to STDERR
I20260812 06:19:34.278810 11048 internal_mini_cluster.cc:156] Creating distributed mini masters. Addrs: 127.10.202.62:37477
I20260812 06:19:34.279735 11048 env_posix.cc:2285] Not raising this process' open files per process limit of 1048576; it is already as high as it can go
I20260812 06:19:34.280293 11048 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:19:34.286067 11066 instance_detector.cc:116] could not retrieve OpenStack instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:19:34.286082 11064 instance_detector.cc:116] could not retrieve Azure instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:19:34.286293 11048 server_base.cc:1061] running on GCE node
W20260812 06:19:34.286417 11060 instance_detector.cc:116] could not retrieve AWS instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:19:34.286847 11048 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:19:34.286940 11048 system_unsync_time.cc:38] NTP support is disabled. Clock error bounds will not be accurate. This configuration is not suitable for distributed clusters.
I20260812 06:19:34.286980 11048 hybrid_clock.cc:648] HybridClock initialized: now 1786515574286978 us; error 0 us; skew 500 ppm
I20260812 06:19:34.288551 11048 webserver.cc:533] Webserver started at http://127.10.202.62:34313/ using document root <none> and password file <none>
I20260812 06:19:34.289026 11048 fs_manager.cc:362] Metadata directory not provided
I20260812 06:19:34.289083 11048 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:19:34.289345 11048 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:19:34.290855 11048 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskQYaTMS/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515574268619-11048-0/minicluster-data/master-0-root/instance:
uuid: "63352395157d4165af2a43abd8d36141"
format_stamp: "Formatted at 2026-08-12 06:19:34 on dist-test-slave-266d"
I20260812 06:19:34.294026 11048 fs_manager.cc:696] Time spent creating directory manager: real 0.003s	user 0.004s	sys 0.000s
I20260812 06:19:34.295895 11075 log_block_manager.cc:4127] Time spent loading block containers with low live blocks: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:19:34.296806 11048 fs_manager.cc:730] Time spent opening block manager: real 0.002s	user 0.002s	sys 0.000s
I20260812 06:19:34.296914 11048 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskQYaTMS/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515574268619-11048-0/minicluster-data/master-0-root
uuid: "63352395157d4165af2a43abd8d36141"
format_stamp: "Formatted at 2026-08-12 06:19:34 on dist-test-slave-266d"
I20260812 06:19:34.296999 11048 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskQYaTMS/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515574268619-11048-0/minicluster-data/master-0-root
metadata directory: /tmp/dist-test-taskQYaTMS/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515574268619-11048-0/minicluster-data/master-0-root
1 data directories: /tmp/dist-test-taskQYaTMS/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515574268619-11048-0/minicluster-data/master-0-root/data
Total live blocks: 0
Total live bytes: 0
Total live bytes (after alignment): 0
Total number of LBM containers: 0 (0 full)
Did not check for missing blocks
Did not check for orphaned blocks
Total full LBM containers with extra space: 0 (0 repaired)
Total full LBM container extra space in bytes: 0 (0 repaired)
Total incomplete LBM containers: 0 (0 repaired)
Total LBM partial records: 0 (0 repaired)
Total corrupted LBM metadata records in RocksDB: 0 (0 repaired)
I20260812 06:19:34.312523 11048 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:19:34.313035 11048 env_posix.cc:2285] Not raising this process' running threads per effective uid limit of 18446744073709551615; it is already as high as it can go
I20260812 06:19:34.313194 11048 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:19:34.319905 11048 rpc_server.cc:307] RPC server started. Bound to: 127.10.202.62:37477
I20260812 06:19:34.319931 11173 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.10.202.62:37477 every 8 connection(s)
I20260812 06:19:34.321954 11177 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet 00000000000000000000000000000000. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:19:34.326877 11177 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P 63352395157d4165af2a43abd8d36141: Bootstrap starting.
I20260812 06:19:34.329013 11177 tablet_bootstrap.cc:654] T 00000000000000000000000000000000 P 63352395157d4165af2a43abd8d36141: Neither blocks nor log segments found. Creating new log.
I20260812 06:19:34.329841 11177 log.cc:826] T 00000000000000000000000000000000 P 63352395157d4165af2a43abd8d36141: Log is configured to *not* fsync() on all Append() calls
I20260812 06:19:34.331254 11177 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P 63352395157d4165af2a43abd8d36141: No bootstrap required, opened a new log
I20260812 06:19:34.333849 11177 raft_consensus.cc:359] T 00000000000000000000000000000000 P 63352395157d4165af2a43abd8d36141 [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "63352395157d4165af2a43abd8d36141" member_type: VOTER }
I20260812 06:19:34.334000 11177 raft_consensus.cc:385] T 00000000000000000000000000000000 P 63352395157d4165af2a43abd8d36141 [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:19:34.334065 11177 raft_consensus.cc:740] T 00000000000000000000000000000000 P 63352395157d4165af2a43abd8d36141 [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: 63352395157d4165af2a43abd8d36141, State: Initialized, Role: FOLLOWER
I20260812 06:19:34.334595 11177 consensus_queue.cc:260] T 00000000000000000000000000000000 P 63352395157d4165af2a43abd8d36141 [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: "63352395157d4165af2a43abd8d36141" member_type: VOTER }
I20260812 06:19:34.334733 11177 raft_consensus.cc:399] T 00000000000000000000000000000000 P 63352395157d4165af2a43abd8d36141 [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:19:34.334796 11177 raft_consensus.cc:493] T 00000000000000000000000000000000 P 63352395157d4165af2a43abd8d36141 [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:19:34.334911 11177 raft_consensus.cc:3060] T 00000000000000000000000000000000 P 63352395157d4165af2a43abd8d36141 [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:19:34.335600 11177 raft_consensus.cc:515] T 00000000000000000000000000000000 P 63352395157d4165af2a43abd8d36141 [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "63352395157d4165af2a43abd8d36141" member_type: VOTER }
I20260812 06:19:34.335990 11177 leader_election.cc:304] T 00000000000000000000000000000000 P 63352395157d4165af2a43abd8d36141 [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: 63352395157d4165af2a43abd8d36141; no voters: 
I20260812 06:19:34.336254 11177 leader_election.cc:290] T 00000000000000000000000000000000 P 63352395157d4165af2a43abd8d36141 [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:19:34.336366 11181 raft_consensus.cc:2804] T 00000000000000000000000000000000 P 63352395157d4165af2a43abd8d36141 [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:19:34.336573 11181 raft_consensus.cc:697] T 00000000000000000000000000000000 P 63352395157d4165af2a43abd8d36141 [term 1 LEADER]: Becoming Leader. State: Replica: 63352395157d4165af2a43abd8d36141, State: Running, Role: LEADER
I20260812 06:19:34.336979 11181 consensus_queue.cc:237] T 00000000000000000000000000000000 P 63352395157d4165af2a43abd8d36141 [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: "63352395157d4165af2a43abd8d36141" member_type: VOTER }
I20260812 06:19:34.337143 11177 sys_catalog.cc:565] T 00000000000000000000000000000000 P 63352395157d4165af2a43abd8d36141 [sys.catalog]: configured and running, proceeding with master startup.
I20260812 06:19:34.338692 11183 sys_catalog.cc:455] T 00000000000000000000000000000000 P 63352395157d4165af2a43abd8d36141 [sys.catalog]: SysCatalogTable state changed. Reason: RaftConsensus started. Latest consensus state: current_term: 1 leader_uuid: "63352395157d4165af2a43abd8d36141" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "63352395157d4165af2a43abd8d36141" member_type: VOTER } }
I20260812 06:19:34.338733 11187 sys_catalog.cc:455] T 00000000000000000000000000000000 P 63352395157d4165af2a43abd8d36141 [sys.catalog]: SysCatalogTable state changed. Reason: New leader 63352395157d4165af2a43abd8d36141. Latest consensus state: current_term: 1 leader_uuid: "63352395157d4165af2a43abd8d36141" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "63352395157d4165af2a43abd8d36141" member_type: VOTER } }
I20260812 06:19:34.338811 11183 sys_catalog.cc:458] T 00000000000000000000000000000000 P 63352395157d4165af2a43abd8d36141 [sys.catalog]: This master's current role is: LEADER
I20260812 06:19:34.338821 11187 sys_catalog.cc:458] T 00000000000000000000000000000000 P 63352395157d4165af2a43abd8d36141 [sys.catalog]: This master's current role is: LEADER
I20260812 06:19:34.339118 11208 catalog_manager.cc:1511] Loading table and tablet metadata into memory...
I20260812 06:19:34.339421 11048 internal_mini_cluster.cc:184] Waiting to initialize catalog manager on master 0
I20260812 06:19:34.341336 11208 catalog_manager.cc:1520] Initializing Kudu cluster ID...
I20260812 06:19:34.345121 11208 catalog_manager.cc:1383] Generated new cluster ID: b7accf42dc394b0a85712e7bc46bf91e
I20260812 06:19:34.345180 11208 catalog_manager.cc:1531] Initializing Kudu internal certificate authority...
I20260812 06:19:34.356766 11208 catalog_manager.cc:1406] Generated new certificate authority record
I20260812 06:19:34.357496 11208 catalog_manager.cc:1540] Loading token signing keys...
I20260812 06:19:34.364219 11208 catalog_manager.cc:6092] T 00000000000000000000000000000000 P 63352395157d4165af2a43abd8d36141: Generated new TSK 0
I20260812 06:19:34.364679 11208 catalog_manager.cc:1550] Initializing in-progress tserver states...
I20260812 06:19:34.372196 11048 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:19:34.374704 11227 instance_detector.cc:116] could not retrieve AWS instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:19:34.374745 11230 instance_detector.cc:116] could not retrieve Azure instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:19:34.374799 11234 instance_detector.cc:116] could not retrieve OpenStack instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:19:34.375130 11048 server_base.cc:1061] running on GCE node
I20260812 06:19:34.375315 11048 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:19:34.375355 11048 system_unsync_time.cc:38] NTP support is disabled. Clock error bounds will not be accurate. This configuration is not suitable for distributed clusters.
I20260812 06:19:34.375370 11048 hybrid_clock.cc:648] HybridClock initialized: now 1786515574375369 us; error 0 us; skew 500 ppm
I20260812 06:19:34.376188 11048 webserver.cc:533] Webserver started at http://127.10.202.1:45267/ using document root <none> and password file <none>
I20260812 06:19:34.376361 11048 fs_manager.cc:362] Metadata directory not provided
I20260812 06:19:34.376411 11048 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:19:34.376484 11048 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:19:34.376804 11048 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskQYaTMS/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515574268619-11048-0/minicluster-data/ts-0-root/instance:
uuid: "c2bb14e4c0eb403cbc4fc75c53ce28b2"
format_stamp: "Formatted at 2026-08-12 06:19:34 on dist-test-slave-266d"
I20260812 06:19:34.378211 11048 fs_manager.cc:696] Time spent creating directory manager: real 0.001s	user 0.002s	sys 0.000s
I20260812 06:19:34.379124 11240 log_block_manager.cc:4127] Time spent loading block containers with low live blocks: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:19:34.379364 11048 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.001s	sys 0.000s
I20260812 06:19:34.379431 11048 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskQYaTMS/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515574268619-11048-0/minicluster-data/ts-0-root
uuid: "c2bb14e4c0eb403cbc4fc75c53ce28b2"
format_stamp: "Formatted at 2026-08-12 06:19:34 on dist-test-slave-266d"
I20260812 06:19:34.379494 11048 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskQYaTMS/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515574268619-11048-0/minicluster-data/ts-0-root
metadata directory: /tmp/dist-test-taskQYaTMS/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515574268619-11048-0/minicluster-data/ts-0-root
1 data directories: /tmp/dist-test-taskQYaTMS/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515574268619-11048-0/minicluster-data/ts-0-root/data
Total live blocks: 0
Total live bytes: 0
Total live bytes (after alignment): 0
Total number of LBM containers: 0 (0 full)
Did not check for missing blocks
Did not check for orphaned blocks
Total full LBM containers with extra space: 0 (0 repaired)
Total full LBM container extra space in bytes: 0 (0 repaired)
Total incomplete LBM containers: 0 (0 repaired)
Total LBM partial records: 0 (0 repaired)
Total corrupted LBM metadata records in RocksDB: 0 (0 repaired)
I20260812 06:19:34.393879 11048 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:19:34.394210 11048 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:19:34.394599 11048 txn_system_client.cc:432] TxnSystemClient initialization is disabled...
I20260812 06:19:34.395359 11048 ts_tablet_manager.cc:585] Loaded tablet metadata (0 total tablets, 0 live tablets)
I20260812 06:19:34.395411 11048 ts_tablet_manager.cc:531] Time spent load tablet metadata: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:19:34.395452 11048 ts_tablet_manager.cc:616] Registered 0 tablets
I20260812 06:19:34.395481 11048 ts_tablet_manager.cc:595] Time spent register tablets: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:19:34.401593 11048 rpc_server.cc:307] RPC server started. Bound to: 127.10.202.1:41385
I20260812 06:19:34.401638 11350 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.10.202.1:41385 every 8 connection(s)
I20260812 06:19:34.410568 11353 heartbeater.cc:344] Connected to a master server at 127.10.202.62:37477
I20260812 06:19:34.410765 11353 heartbeater.cc:461] Registering TS with master...
I20260812 06:19:34.411135 11353 heartbeater.cc:507] Master 127.10.202.62:37477 requested a full tablet report, sending...
I20260812 06:19:34.412360 11106 ts_manager.cc:194] Registered new tserver with Master: c2bb14e4c0eb403cbc4fc75c53ce28b2 (127.10.202.1:41385)
I20260812 06:19:34.413206 11048 internal_mini_cluster.cc:371] 1 TS(s) registered with all masters after 0.011070462s
I20260812 06:19:34.413517 11106 master_service.cc:502] Signed X509 certificate for tserver {username='slave'} at 127.0.0.1:43892
I20260812 06:19:34.421712 11106 catalog_manager.cc:2283] Servicing CreateTable request from {username='slave'} at 127.0.0.1:43898:
name: "heavy-update-compaction-test"
schema {
  columns {
    name: "key"
    type: INT64
    is_key: true
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_a"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_b"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_c"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_d"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_e"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
}
num_replicas: 1
split_rows_range_bounds {
}
partition_schema {
  range_schema {
  }
}
I20260812 06:19:34.434566 11287 tablet_service.cc:1511] Processing CreateTablet for tablet cd1d2b607c74458e89b7af1c836f38dc (DEFAULT_TABLE table=heavy-update-compaction-test [id=320e7b939e5449b5ad3bc23b0c7ba712]), partition=
I20260812 06:19:34.434974 11287 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet cd1d2b607c74458e89b7af1c836f38dc. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:19:34.437107 11371 tablet_bootstrap.cc:492] T cd1d2b607c74458e89b7af1c836f38dc P c2bb14e4c0eb403cbc4fc75c53ce28b2: Bootstrap starting.
I20260812 06:19:34.438066 11371 tablet_bootstrap.cc:654] T cd1d2b607c74458e89b7af1c836f38dc P c2bb14e4c0eb403cbc4fc75c53ce28b2: Neither blocks nor log segments found. Creating new log.
I20260812 06:19:34.439081 11371 tablet_bootstrap.cc:492] T cd1d2b607c74458e89b7af1c836f38dc P c2bb14e4c0eb403cbc4fc75c53ce28b2: No bootstrap required, opened a new log
I20260812 06:19:34.439173 11371 ts_tablet_manager.cc:1403] T cd1d2b607c74458e89b7af1c836f38dc P c2bb14e4c0eb403cbc4fc75c53ce28b2: Time spent bootstrapping tablet: real 0.002s	user 0.000s	sys 0.002s
I20260812 06:19:34.439553 11371 raft_consensus.cc:359] T cd1d2b607c74458e89b7af1c836f38dc P c2bb14e4c0eb403cbc4fc75c53ce28b2 [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "c2bb14e4c0eb403cbc4fc75c53ce28b2" member_type: VOTER last_known_addr { host: "127.10.202.1" port: 41385 } }
I20260812 06:19:34.439642 11371 raft_consensus.cc:385] T cd1d2b607c74458e89b7af1c836f38dc P c2bb14e4c0eb403cbc4fc75c53ce28b2 [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:19:34.439674 11371 raft_consensus.cc:740] T cd1d2b607c74458e89b7af1c836f38dc P c2bb14e4c0eb403cbc4fc75c53ce28b2 [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: c2bb14e4c0eb403cbc4fc75c53ce28b2, State: Initialized, Role: FOLLOWER
I20260812 06:19:34.439801 11371 consensus_queue.cc:260] T cd1d2b607c74458e89b7af1c836f38dc P c2bb14e4c0eb403cbc4fc75c53ce28b2 [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: "c2bb14e4c0eb403cbc4fc75c53ce28b2" member_type: VOTER last_known_addr { host: "127.10.202.1" port: 41385 } }
I20260812 06:19:34.439877 11371 raft_consensus.cc:399] T cd1d2b607c74458e89b7af1c836f38dc P c2bb14e4c0eb403cbc4fc75c53ce28b2 [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:19:34.439920 11371 raft_consensus.cc:493] T cd1d2b607c74458e89b7af1c836f38dc P c2bb14e4c0eb403cbc4fc75c53ce28b2 [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:19:34.439967 11371 raft_consensus.cc:3060] T cd1d2b607c74458e89b7af1c836f38dc P c2bb14e4c0eb403cbc4fc75c53ce28b2 [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:19:34.440591 11371 raft_consensus.cc:515] T cd1d2b607c74458e89b7af1c836f38dc P c2bb14e4c0eb403cbc4fc75c53ce28b2 [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "c2bb14e4c0eb403cbc4fc75c53ce28b2" member_type: VOTER last_known_addr { host: "127.10.202.1" port: 41385 } }
I20260812 06:19:34.440717 11371 leader_election.cc:304] T cd1d2b607c74458e89b7af1c836f38dc P c2bb14e4c0eb403cbc4fc75c53ce28b2 [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: c2bb14e4c0eb403cbc4fc75c53ce28b2; no voters: 
I20260812 06:19:34.440901 11371 leader_election.cc:290] T cd1d2b607c74458e89b7af1c836f38dc P c2bb14e4c0eb403cbc4fc75c53ce28b2 [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:19:34.441004 11380 raft_consensus.cc:2804] T cd1d2b607c74458e89b7af1c836f38dc P c2bb14e4c0eb403cbc4fc75c53ce28b2 [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:19:34.441242 11371 ts_tablet_manager.cc:1434] T cd1d2b607c74458e89b7af1c836f38dc P c2bb14e4c0eb403cbc4fc75c53ce28b2: Time spent starting tablet: real 0.002s	user 0.000s	sys 0.002s
I20260812 06:19:34.441287 11380 raft_consensus.cc:697] T cd1d2b607c74458e89b7af1c836f38dc P c2bb14e4c0eb403cbc4fc75c53ce28b2 [term 1 LEADER]: Becoming Leader. State: Replica: c2bb14e4c0eb403cbc4fc75c53ce28b2, State: Running, Role: LEADER
I20260812 06:19:34.441547 11353 heartbeater.cc:499] Master 127.10.202.62:37477 was elected leader, sending a full tablet report...
I20260812 06:19:34.441913 11380 consensus_queue.cc:237] T cd1d2b607c74458e89b7af1c836f38dc P c2bb14e4c0eb403cbc4fc75c53ce28b2 [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: "c2bb14e4c0eb403cbc4fc75c53ce28b2" member_type: VOTER last_known_addr { host: "127.10.202.1" port: 41385 } }
I20260812 06:19:34.444222 11106 catalog_manager.cc:5719] T cd1d2b607c74458e89b7af1c836f38dc P c2bb14e4c0eb403cbc4fc75c53ce28b2 reported cstate change: term changed from 0 to 1, leader changed from <none> to c2bb14e4c0eb403cbc4fc75c53ce28b2 (127.10.202.1). New cstate: current_term: 1 leader_uuid: "c2bb14e4c0eb403cbc4fc75c53ce28b2" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "c2bb14e4c0eb403cbc4fc75c53ce28b2" member_type: VOTER last_known_addr { host: "127.10.202.1" port: 41385 } health_report { overall_health: HEALTHY } } }
I20260812 06:19:34.507484 11048 heavy-update-compaction-itest.cc:215] Time spent inserting: real 0.054s	user 0.018s	sys 0.008s
I20260812 06:19:34.652536 11354 maintenance_manager.cc:419] P c2bb14e4c0eb403cbc4fc75c53ce28b2: Scheduling FlushMRSOp(cd1d2b607c74458e89b7af1c836f38dc): perf score=23.023690
I20260812 06:19:34.859496 11247 maintenance_manager.cc:643] P c2bb14e4c0eb403cbc4fc75c53ce28b2: FlushMRSOp(cd1d2b607c74458e89b7af1c836f38dc) complete. Timing: real 0.207s	user 0.160s	sys 0.036s Metrics: {"bytes_written":15425325,"cfile_init":1,"compiler_manager_pool.queue_time_us":183,"delete_count":0,"dirs.queue_time_us":71,"dirs.run_cpu_time_us":177,"dirs.run_wall_time_us":963,"drs_written":1,"lbm_read_time_us":68,"lbm_reads_lt_1ms":4,"lbm_write_time_us":50374,"lbm_writes_lt_1ms":933,"mutex_wait_us":2686,"peak_mem_usage":0,"reinsert_count":0,"rows_written":105,"spinlock_wait_cycles":2048,"thread_start_us":89,"threads_started":1,"update_count":1880}
I20260812 06:19:34.860580 11354 maintenance_manager.cc:419] P c2bb14e4c0eb403cbc4fc75c53ce28b2: Scheduling LogGCOp(cd1d2b607c74458e89b7af1c836f38dc): free 20743880 bytes of WAL
I20260812 06:19:34.860879 11247 log_reader.cc:385] T cd1d2b607c74458e89b7af1c836f38dc: removed 2 log segments from log reader
I20260812 06:19:34.860934 11247 log.cc:1079] T cd1d2b607c74458e89b7af1c836f38dc P c2bb14e4c0eb403cbc4fc75c53ce28b2: Deleting log segment in path: /tmp/dist-test-taskQYaTMS/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515574268619-11048-0/minicluster-data/ts-0-root/wals/cd1d2b607c74458e89b7af1c836f38dc/wal-000000001 (ops 1-6)
I20260812 06:19:34.860980 11247 log.cc:1079] T cd1d2b607c74458e89b7af1c836f38dc P c2bb14e4c0eb403cbc4fc75c53ce28b2: Deleting log segment in path: /tmp/dist-test-taskQYaTMS/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515574268619-11048-0/minicluster-data/ts-0-root/wals/cd1d2b607c74458e89b7af1c836f38dc/wal-000000002 (ops 7-11)
I20260812 06:19:34.865950 11247 maintenance_manager.cc:643] P c2bb14e4c0eb403cbc4fc75c53ce28b2: LogGCOp(cd1d2b607c74458e89b7af1c836f38dc) complete. Timing: real 0.005s	user 0.000s	sys 0.004s Metrics: {}
I20260812 06:19:34.866333 11354 maintenance_manager.cc:419] P c2bb14e4c0eb403cbc4fc75c53ce28b2: Scheduling FlushDeltaMemStoresOp(cd1d2b607c74458e89b7af1c836f38dc): perf score=3.181125
I20260812 06:19:34.884179 11247 maintenance_manager.cc:643] P c2bb14e4c0eb403cbc4fc75c53ce28b2: FlushDeltaMemStoresOp(cd1d2b607c74458e89b7af1c836f38dc) complete. Timing: real 0.018s	user 0.003s	sys 0.010s Metrics: {"bytes_written":5087239,"delete_count":0,"lbm_write_time_us":6168,"lbm_writes_lt_1ms":127,"reinsert_count":0,"update_count":620}
I20260812 06:19:34.884663 11354 maintenance_manager.cc:419] P c2bb14e4c0eb403cbc4fc75c53ce28b2: Scheduling MajorDeltaCompactionOp(cd1d2b607c74458e89b7af1c836f38dc): perf score=1.000000
I20260812 06:19:35.056835 11247 maintenance_manager.cc:643] P c2bb14e4c0eb403cbc4fc75c53ce28b2: MajorDeltaCompactionOp(cd1d2b607c74458e89b7af1c836f38dc) complete. Timing: real 0.172s	user 0.110s	sys 0.053s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24815687,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":457,"lbm_read_time_us":11693,"lbm_reads_lt_1ms":568,"lbm_write_time_us":27839,"lbm_writes_lt_1ms":543,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":896,"thread_start_us":290,"threads_started":5,"update_count":2500}
I20260812 06:19:35.057303 11354 maintenance_manager.cc:419] P c2bb14e4c0eb403cbc4fc75c53ce28b2: Scheduling FlushDeltaMemStoresOp(cd1d2b607c74458e89b7af1c836f38dc): perf score=14.095187
I20260812 06:19:35.110132 11247 maintenance_manager.cc:643] P c2bb14e4c0eb403cbc4fc75c53ce28b2: FlushDeltaMemStoresOp(cd1d2b607c74458e89b7af1c836f38dc) complete. Timing: real 0.053s	user 0.033s	sys 0.016s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":18665,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:35.110589 11354 maintenance_manager.cc:419] P c2bb14e4c0eb403cbc4fc75c53ce28b2: Scheduling UndoDeltaBlockGCOp(cd1d2b607c74458e89b7af1c836f38dc): 20513813 bytes on disk
I20260812 06:19:35.111078 11247 maintenance_manager.cc:643] P c2bb14e4c0eb403cbc4fc75c53ce28b2: UndoDeltaBlockGCOp(cd1d2b607c74458e89b7af1c836f38dc) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":45,"lbm_reads_lt_1ms":4}
I20260812 06:19:35.111474 11354 maintenance_manager.cc:419] P c2bb14e4c0eb403cbc4fc75c53ce28b2: Scheduling FlushDeltaMemStoresOp(cd1d2b607c74458e89b7af1c836f38dc): perf score=2.188937
I20260812 06:19:35.121183 11247 maintenance_manager.cc:643] P c2bb14e4c0eb403cbc4fc75c53ce28b2: FlushDeltaMemStoresOp(cd1d2b607c74458e89b7af1c836f38dc) complete. Timing: real 0.010s	user 0.009s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3647,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:35.121500 11354 maintenance_manager.cc:419] P c2bb14e4c0eb403cbc4fc75c53ce28b2: Scheduling MajorDeltaCompactionOp(cd1d2b607c74458e89b7af1c836f38dc): perf score=1.000000
I20260812 06:19:35.291723 11247 maintenance_manager.cc:643] P c2bb14e4c0eb403cbc4fc75c53ce28b2: MajorDeltaCompactionOp(cd1d2b607c74458e89b7af1c836f38dc) complete. Timing: real 0.170s	user 0.124s	sys 0.044s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24815684,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":693,"lbm_read_time_us":11308,"lbm_reads_lt_1ms":572,"lbm_write_time_us":30787,"lbm_writes_lt_1ms":543,"mutex_wait_us":331,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":2176,"update_count":2500}
I20260812 06:19:35.292188 11354 maintenance_manager.cc:419] P c2bb14e4c0eb403cbc4fc75c53ce28b2: Scheduling FlushDeltaMemStoresOp(cd1d2b607c74458e89b7af1c836f38dc): perf score=11.118625
I20260812 06:19:35.319669 11247 maintenance_manager.cc:643] P c2bb14e4c0eb403cbc4fc75c53ce28b2: FlushDeltaMemStoresOp(cd1d2b607c74458e89b7af1c836f38dc) complete. Timing: real 0.027s	user 0.017s	sys 0.008s Metrics: {"bytes_written":12717736,"delete_count":0,"lbm_write_time_us":11565,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:19:35.320120 11354 maintenance_manager.cc:419] P c2bb14e4c0eb403cbc4fc75c53ce28b2: Scheduling FlushDeltaMemStoresOp(cd1d2b607c74458e89b7af1c836f38dc): perf score=2.188937
I20260812 06:19:35.333225 11247 maintenance_manager.cc:643] P c2bb14e4c0eb403cbc4fc75c53ce28b2: FlushDeltaMemStoresOp(cd1d2b607c74458e89b7af1c836f38dc) complete. Timing: real 0.013s	user 0.001s	sys 0.011s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":4695,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:19:35.333757 11354 maintenance_manager.cc:419] P c2bb14e4c0eb403cbc4fc75c53ce28b2: Scheduling MajorDeltaCompactionOp(cd1d2b607c74458e89b7af1c836f38dc): perf score=1.000000
I20260812 06:19:35.470496 11247 maintenance_manager.cc:643] P c2bb14e4c0eb403cbc4fc75c53ce28b2: MajorDeltaCompactionOp(cd1d2b607c74458e89b7af1c836f38dc) complete. Timing: real 0.137s	user 0.078s	sys 0.052s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20713264,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":760,"lbm_read_time_us":6864,"lbm_reads_lt_1ms":464,"lbm_write_time_us":21352,"lbm_writes_lt_1ms":443,"mutex_wait_us":69,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":8832,"update_count":2000}
I20260812 06:19:35.471081 11354 maintenance_manager.cc:419] P c2bb14e4c0eb403cbc4fc75c53ce28b2: Scheduling FlushDeltaMemStoresOp(cd1d2b607c74458e89b7af1c836f38dc): perf score=11.118625
I20260812 06:19:35.505381 11247 maintenance_manager.cc:643] P c2bb14e4c0eb403cbc4fc75c53ce28b2: FlushDeltaMemStoresOp(cd1d2b607c74458e89b7af1c836f38dc) complete. Timing: real 0.034s	user 0.023s	sys 0.011s Metrics: {"bytes_written":12717734,"delete_count":0,"lbm_write_time_us":14368,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:19:35.505954 11354 maintenance_manager.cc:419] P c2bb14e4c0eb403cbc4fc75c53ce28b2: Scheduling FlushDeltaMemStoresOp(cd1d2b607c74458e89b7af1c836f38dc): perf score=2.188937
I20260812 06:19:35.522375 11247 maintenance_manager.cc:643] P c2bb14e4c0eb403cbc4fc75c53ce28b2: FlushDeltaMemStoresOp(cd1d2b607c74458e89b7af1c836f38dc) complete. Timing: real 0.016s	user 0.004s	sys 0.009s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":5346,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:19:35.522861 11354 maintenance_manager.cc:419] P c2bb14e4c0eb403cbc4fc75c53ce28b2: Scheduling MajorDeltaCompactionOp(cd1d2b607c74458e89b7af1c836f38dc): perf score=1.000000
I20260812 06:19:35.640187 11247 maintenance_manager.cc:643] P c2bb14e4c0eb403cbc4fc75c53ce28b2: MajorDeltaCompactionOp(cd1d2b607c74458e89b7af1c836f38dc) complete. Timing: real 0.117s	user 0.083s	sys 0.033s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20713262,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":154,"lbm_read_time_us":8403,"lbm_reads_lt_1ms":464,"lbm_write_time_us":21488,"lbm_writes_lt_1ms":443,"mutex_wait_us":36,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":9088,"update_count":2000}
I20260812 06:19:35.640740 11354 maintenance_manager.cc:419] P c2bb14e4c0eb403cbc4fc75c53ce28b2: Scheduling FlushDeltaMemStoresOp(cd1d2b607c74458e89b7af1c836f38dc): perf score=10.126437
I20260812 06:19:35.679147 11247 maintenance_manager.cc:643] P c2bb14e4c0eb403cbc4fc75c53ce28b2: FlushDeltaMemStoresOp(cd1d2b607c74458e89b7af1c836f38dc) complete. Timing: real 0.038s	user 0.026s	sys 0.008s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":15544,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:19:35.679622 11354 maintenance_manager.cc:419] P c2bb14e4c0eb403cbc4fc75c53ce28b2: Scheduling FlushDeltaMemStoresOp(cd1d2b607c74458e89b7af1c836f38dc): perf score=2.188937
I20260812 06:19:35.689324 11247 maintenance_manager.cc:643] P c2bb14e4c0eb403cbc4fc75c53ce28b2: FlushDeltaMemStoresOp(cd1d2b607c74458e89b7af1c836f38dc) complete. Timing: real 0.010s	user 0.005s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3668,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:35.689785 11354 maintenance_manager.cc:419] P c2bb14e4c0eb403cbc4fc75c53ce28b2: Scheduling MajorDeltaCompactionOp(cd1d2b607c74458e89b7af1c836f38dc): perf score=1.000000
I20260812 06:19:35.805220 11247 maintenance_manager.cc:643] P c2bb14e4c0eb403cbc4fc75c53ce28b2: MajorDeltaCompactionOp(cd1d2b607c74458e89b7af1c836f38dc) complete. Timing: real 0.115s	user 0.087s	sys 0.028s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20713272,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":166,"lbm_read_time_us":7977,"lbm_reads_lt_1ms":472,"lbm_write_time_us":21675,"lbm_writes_lt_1ms":443,"mutex_wait_us":67,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":384,"update_count":2000}
I20260812 06:19:35.805778 11354 maintenance_manager.cc:419] P c2bb14e4c0eb403cbc4fc75c53ce28b2: Scheduling FlushDeltaMemStoresOp(cd1d2b607c74458e89b7af1c836f38dc): perf score=10.126437
I20260812 06:19:35.853236 11247 maintenance_manager.cc:643] P c2bb14e4c0eb403cbc4fc75c53ce28b2: FlushDeltaMemStoresOp(cd1d2b607c74458e89b7af1c836f38dc) complete. Timing: real 0.047s	user 0.014s	sys 0.027s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":14741,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:19:35.853792 11354 maintenance_manager.cc:419] P c2bb14e4c0eb403cbc4fc75c53ce28b2: Scheduling FlushDeltaMemStoresOp(cd1d2b607c74458e89b7af1c836f38dc): perf score=2.188937
I20260812 06:19:35.863399 11247 maintenance_manager.cc:643] P c2bb14e4c0eb403cbc4fc75c53ce28b2: FlushDeltaMemStoresOp(cd1d2b607c74458e89b7af1c836f38dc) complete. Timing: real 0.009s	user 0.008s	sys 0.000s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":3675,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:35.863854 11354 maintenance_manager.cc:419] P c2bb14e4c0eb403cbc4fc75c53ce28b2: Scheduling MajorDeltaCompactionOp(cd1d2b607c74458e89b7af1c836f38dc): perf score=1.000000
I20260812 06:19:35.998713 11247 maintenance_manager.cc:643] P c2bb14e4c0eb403cbc4fc75c53ce28b2: MajorDeltaCompactionOp(cd1d2b607c74458e89b7af1c836f38dc) complete. Timing: real 0.135s	user 0.070s	sys 0.064s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20713271,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":257,"lbm_read_time_us":10176,"lbm_reads_lt_1ms":472,"lbm_write_time_us":20325,"lbm_writes_lt_1ms":443,"mutex_wait_us":3,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":896,"update_count":2000}
I20260812 06:19:35.999189 11354 maintenance_manager.cc:419] P c2bb14e4c0eb403cbc4fc75c53ce28b2: Scheduling FlushDeltaMemStoresOp(cd1d2b607c74458e89b7af1c836f38dc): perf score=10.126437
I20260812 06:19:36.041019 11247 maintenance_manager.cc:643] P c2bb14e4c0eb403cbc4fc75c53ce28b2: FlushDeltaMemStoresOp(cd1d2b607c74458e89b7af1c836f38dc) complete. Timing: real 0.042s	user 0.021s	sys 0.008s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":13759,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:19:36.041558 11354 maintenance_manager.cc:419] P c2bb14e4c0eb403cbc4fc75c53ce28b2: Scheduling FlushDeltaMemStoresOp(cd1d2b607c74458e89b7af1c836f38dc): perf score=2.188937
I20260812 06:19:36.050998 11247 maintenance_manager.cc:643] P c2bb14e4c0eb403cbc4fc75c53ce28b2: FlushDeltaMemStoresOp(cd1d2b607c74458e89b7af1c836f38dc) complete. Timing: real 0.009s	user 0.008s	sys 0.000s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":3541,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:36.051466 11354 maintenance_manager.cc:419] P c2bb14e4c0eb403cbc4fc75c53ce28b2: Scheduling FlushMRSOp(cd1d2b607c74458e89b7af1c836f38dc): perf score=1.000000
I20260812 06:19:36.083297 11247 maintenance_manager.cc:643] P c2bb14e4c0eb403cbc4fc75c53ce28b2: FlushMRSOp(cd1d2b607c74458e89b7af1c836f38dc) complete. Timing: real 0.032s	user 0.027s	sys 0.003s Metrics: {"bytes_written":1234473,"cfile_init":1,"dirs.queue_time_us":45,"dirs.run_cpu_time_us":212,"dirs.run_wall_time_us":1132,"drs_written":1,"lbm_read_time_us":40,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1494,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":30}
I20260812 06:19:36.084172 11354 maintenance_manager.cc:419] P c2bb14e4c0eb403cbc4fc75c53ce28b2: Scheduling LogGCOp(cd1d2b607c74458e89b7af1c836f38dc): free 124257249 bytes of WAL
I20260812 06:19:36.084398 11247 log_reader.cc:385] T cd1d2b607c74458e89b7af1c836f38dc: removed 12 log segments from log reader
I20260812 06:19:36.084446 11247 log.cc:1079] T cd1d2b607c74458e89b7af1c836f38dc P c2bb14e4c0eb403cbc4fc75c53ce28b2: Deleting log segment in path: /tmp/dist-test-taskQYaTMS/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515574268619-11048-0/minicluster-data/ts-0-root/wals/cd1d2b607c74458e89b7af1c836f38dc/wal-000000003 (ops 12-16)
I20260812 06:19:36.084486 11247 log.cc:1079] T cd1d2b607c74458e89b7af1c836f38dc P c2bb14e4c0eb403cbc4fc75c53ce28b2: Deleting log segment in path: /tmp/dist-test-taskQYaTMS/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515574268619-11048-0/minicluster-data/ts-0-root/wals/cd1d2b607c74458e89b7af1c836f38dc/wal-000000004 (ops 17-21)
I20260812 06:19:36.084519 11247 log.cc:1079] T cd1d2b607c74458e89b7af1c836f38dc P c2bb14e4c0eb403cbc4fc75c53ce28b2: Deleting log segment in path: /tmp/dist-test-taskQYaTMS/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515574268619-11048-0/minicluster-data/ts-0-root/wals/cd1d2b607c74458e89b7af1c836f38dc/wal-000000005 (ops 22-26)
I20260812 06:19:36.084544 11247 log.cc:1079] T cd1d2b607c74458e89b7af1c836f38dc P c2bb14e4c0eb403cbc4fc75c53ce28b2: Deleting log segment in path: /tmp/dist-test-taskQYaTMS/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515574268619-11048-0/minicluster-data/ts-0-root/wals/cd1d2b607c74458e89b7af1c836f38dc/wal-000000006 (ops 27-31)
I20260812 06:19:36.084575 11247 log.cc:1079] T cd1d2b607c74458e89b7af1c836f38dc P c2bb14e4c0eb403cbc4fc75c53ce28b2: Deleting log segment in path: /tmp/dist-test-taskQYaTMS/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515574268619-11048-0/minicluster-data/ts-0-root/wals/cd1d2b607c74458e89b7af1c836f38dc/wal-000000007 (ops 32-36)
I20260812 06:19:36.084605 11247 log.cc:1079] T cd1d2b607c74458e89b7af1c836f38dc P c2bb14e4c0eb403cbc4fc75c53ce28b2: Deleting log segment in path: /tmp/dist-test-taskQYaTMS/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515574268619-11048-0/minicluster-data/ts-0-root/wals/cd1d2b607c74458e89b7af1c836f38dc/wal-000000008 (ops 37-41)
I20260812 06:19:36.084637 11247 log.cc:1079] T cd1d2b607c74458e89b7af1c836f38dc P c2bb14e4c0eb403cbc4fc75c53ce28b2: Deleting log segment in path: /tmp/dist-test-taskQYaTMS/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515574268619-11048-0/minicluster-data/ts-0-root/wals/cd1d2b607c74458e89b7af1c836f38dc/wal-000000009 (ops 42-46)
I20260812 06:19:36.084668 11247 log.cc:1079] T cd1d2b607c74458e89b7af1c836f38dc P c2bb14e4c0eb403cbc4fc75c53ce28b2: Deleting log segment in path: /tmp/dist-test-taskQYaTMS/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515574268619-11048-0/minicluster-data/ts-0-root/wals/cd1d2b607c74458e89b7af1c836f38dc/wal-000000010 (ops 47-51)
I20260812 06:19:36.084698 11247 log.cc:1079] T cd1d2b607c74458e89b7af1c836f38dc P c2bb14e4c0eb403cbc4fc75c53ce28b2: Deleting log segment in path: /tmp/dist-test-taskQYaTMS/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515574268619-11048-0/minicluster-data/ts-0-root/wals/cd1d2b607c74458e89b7af1c836f38dc/wal-000000011 (ops 52-56)
I20260812 06:19:36.084729 11247 log.cc:1079] T cd1d2b607c74458e89b7af1c836f38dc P c2bb14e4c0eb403cbc4fc75c53ce28b2: Deleting log segment in path: /tmp/dist-test-taskQYaTMS/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515574268619-11048-0/minicluster-data/ts-0-root/wals/cd1d2b607c74458e89b7af1c836f38dc/wal-000000012 (ops 57-61)
I20260812 06:19:36.084767 11247 log.cc:1079] T cd1d2b607c74458e89b7af1c836f38dc P c2bb14e4c0eb403cbc4fc75c53ce28b2: Deleting log segment in path: /tmp/dist-test-taskQYaTMS/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515574268619-11048-0/minicluster-data/ts-0-root/wals/cd1d2b607c74458e89b7af1c836f38dc/wal-000000013 (ops 62-66)
I20260812 06:19:36.084800 11247 log.cc:1079] T cd1d2b607c74458e89b7af1c836f38dc P c2bb14e4c0eb403cbc4fc75c53ce28b2: Deleting log segment in path: /tmp/dist-test-taskQYaTMS/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515574268619-11048-0/minicluster-data/ts-0-root/wals/cd1d2b607c74458e89b7af1c836f38dc/wal-000000014 (ops 67-70)
I20260812 06:19:36.107676 11247 maintenance_manager.cc:643] P c2bb14e4c0eb403cbc4fc75c53ce28b2: LogGCOp(cd1d2b607c74458e89b7af1c836f38dc) complete. Timing: real 0.023s	user 0.000s	sys 0.021s Metrics: {}
I20260812 06:19:36.108203 11354 maintenance_manager.cc:419] P c2bb14e4c0eb403cbc4fc75c53ce28b2: Scheduling FlushDeltaMemStoresOp(cd1d2b607c74458e89b7af1c836f38dc): perf score=3.181125
I20260812 06:19:36.119110 11247 maintenance_manager.cc:643] P c2bb14e4c0eb403cbc4fc75c53ce28b2: FlushDeltaMemStoresOp(cd1d2b607c74458e89b7af1c836f38dc) complete. Timing: real 0.011s	user 0.006s	sys 0.003s Metrics: {"bytes_written":4635977,"delete_count":0,"lbm_write_time_us":4144,"lbm_writes_lt_1ms":116,"reinsert_count":0,"update_count":565}
I20260812 06:19:36.119529 11354 maintenance_manager.cc:419] P c2bb14e4c0eb403cbc4fc75c53ce28b2: Scheduling FlushDeltaMemStoresOp(cd1d2b607c74458e89b7af1c836f38dc): perf score=2.188937
I20260812 06:19:36.140318 11247 maintenance_manager.cc:643] P c2bb14e4c0eb403cbc4fc75c53ce28b2: FlushDeltaMemStoresOp(cd1d2b607c74458e89b7af1c836f38dc) complete. Timing: real 0.021s	user 0.008s	sys 0.004s Metrics: {"bytes_written":3569330,"delete_count":0,"lbm_write_time_us":3352,"lbm_writes_lt_1ms":90,"reinsert_count":0,"update_count":435}
I20260812 06:19:36.140823 11354 maintenance_manager.cc:419] P c2bb14e4c0eb403cbc4fc75c53ce28b2: Scheduling MajorDeltaCompactionOp(cd1d2b607c74458e89b7af1c836f38dc): perf score=1.000000
I20260812 06:19:36.331362 11247 maintenance_manager.cc:643] P c2bb14e4c0eb403cbc4fc75c53ce28b2: MajorDeltaCompactionOp(cd1d2b607c74458e89b7af1c836f38dc) complete. Timing: real 0.190s	user 0.140s	sys 0.050s Metrics: {"cfile_cache_miss":634,"cfile_cache_miss_bytes":28918322,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":929,"lbm_read_time_us":14052,"lbm_reads_lt_1ms":674,"lbm_write_time_us":35018,"lbm_writes_lt_1ms":643,"mutex_wait_us":727,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":896,"thread_start_us":110,"threads_started":1,"update_count":3000}
I20260812 06:19:36.331885 11354 maintenance_manager.cc:419] P c2bb14e4c0eb403cbc4fc75c53ce28b2: Scheduling FlushDeltaMemStoresOp(cd1d2b607c74458e89b7af1c836f38dc): perf score=14.095187
I20260812 06:19:36.390720 11247 maintenance_manager.cc:643] P c2bb14e4c0eb403cbc4fc75c53ce28b2: FlushDeltaMemStoresOp(cd1d2b607c74458e89b7af1c836f38dc) complete. Timing: real 0.059s	user 0.033s	sys 0.024s Metrics: {"bytes_written":16409898,"delete_count":0,"lbm_write_time_us":22746,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:36.391295 11354 maintenance_manager.cc:419] P c2bb14e4c0eb403cbc4fc75c53ce28b2: Scheduling FlushDeltaMemStoresOp(cd1d2b607c74458e89b7af1c836f38dc): perf score=2.188937
I20260812 06:19:36.403002 11247 maintenance_manager.cc:643] P c2bb14e4c0eb403cbc4fc75c53ce28b2: FlushDeltaMemStoresOp(cd1d2b607c74458e89b7af1c836f38dc) complete. Timing: real 0.012s	user 0.007s	sys 0.003s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4482,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:36.403448 11354 maintenance_manager.cc:419] P c2bb14e4c0eb403cbc4fc75c53ce28b2: Scheduling MajorDeltaCompactionOp(cd1d2b607c74458e89b7af1c836f38dc): perf score=1.000000
I20260812 06:19:36.570058 11247 maintenance_manager.cc:643] P c2bb14e4c0eb403cbc4fc75c53ce28b2: MajorDeltaCompactionOp(cd1d2b607c74458e89b7af1c836f38dc) complete. Timing: real 0.166s	user 0.130s	sys 0.036s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24815680,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":835,"lbm_read_time_us":12778,"lbm_reads_lt_1ms":572,"lbm_write_time_us":25485,"lbm_writes_lt_1ms":543,"mutex_wait_us":260,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":3072,"update_count":2500}
I20260812 06:19:36.570693 11354 maintenance_manager.cc:419] P c2bb14e4c0eb403cbc4fc75c53ce28b2: Scheduling UndoDeltaBlockGCOp(cd1d2b607c74458e89b7af1c836f38dc): 472 bytes on disk
I20260812 06:19:36.571043 11247 maintenance_manager.cc:643] P c2bb14e4c0eb403cbc4fc75c53ce28b2: UndoDeltaBlockGCOp(cd1d2b607c74458e89b7af1c836f38dc) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":43,"lbm_reads_lt_1ms":4}
I20260812 06:19:36.571457 11354 maintenance_manager.cc:419] P c2bb14e4c0eb403cbc4fc75c53ce28b2: Scheduling FlushDeltaMemStoresOp(cd1d2b607c74458e89b7af1c836f38dc): perf score=14.095187
I20260812 06:19:36.613513 11247 maintenance_manager.cc:643] P c2bb14e4c0eb403cbc4fc75c53ce28b2: FlushDeltaMemStoresOp(cd1d2b607c74458e89b7af1c836f38dc) complete. Timing: real 0.042s	user 0.025s	sys 0.016s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":17772,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":402,"reinsert_count":0,"update_count":2000}
I20260812 06:19:36.614068 11354 maintenance_manager.cc:419] P c2bb14e4c0eb403cbc4fc75c53ce28b2: Scheduling FlushDeltaMemStoresOp(cd1d2b607c74458e89b7af1c836f38dc): perf score=2.188937
I20260812 06:19:36.629173 11247 maintenance_manager.cc:643] P c2bb14e4c0eb403cbc4fc75c53ce28b2: FlushDeltaMemStoresOp(cd1d2b607c74458e89b7af1c836f38dc) complete. Timing: real 0.015s	user 0.015s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5775,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:36.629719 11354 maintenance_manager.cc:419] P c2bb14e4c0eb403cbc4fc75c53ce28b2: Scheduling MajorDeltaCompactionOp(cd1d2b607c74458e89b7af1c836f38dc): perf score=1.000000
I20260812 06:19:36.805264 11247 maintenance_manager.cc:643] P c2bb14e4c0eb403cbc4fc75c53ce28b2: MajorDeltaCompactionOp(cd1d2b607c74458e89b7af1c836f38dc) complete. Timing: real 0.175s	user 0.101s	sys 0.058s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24815683,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":1012,"lbm_read_time_us":9666,"lbm_reads_lt_1ms":572,"lbm_write_time_us":25654,"lbm_writes_lt_1ms":543,"mutex_wait_us":311,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":1920,"update_count":2500}
I20260812 06:19:36.805732 11354 maintenance_manager.cc:419] P c2bb14e4c0eb403cbc4fc75c53ce28b2: Scheduling FlushDeltaMemStoresOp(cd1d2b607c74458e89b7af1c836f38dc): perf score=14.095187
I20260812 06:19:36.850888 11247 maintenance_manager.cc:643] P c2bb14e4c0eb403cbc4fc75c53ce28b2: FlushDeltaMemStoresOp(cd1d2b607c74458e89b7af1c836f38dc) complete. Timing: real 0.045s	user 0.028s	sys 0.009s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":16847,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:36.851435 11354 maintenance_manager.cc:419] P c2bb14e4c0eb403cbc4fc75c53ce28b2: Scheduling FlushDeltaMemStoresOp(cd1d2b607c74458e89b7af1c836f38dc): perf score=2.188937
I20260812 06:19:36.861194 11247 maintenance_manager.cc:643] P c2bb14e4c0eb403cbc4fc75c53ce28b2: FlushDeltaMemStoresOp(cd1d2b607c74458e89b7af1c836f38dc) complete. Timing: real 0.010s	user 0.006s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3590,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:36.861796 11354 maintenance_manager.cc:419] P c2bb14e4c0eb403cbc4fc75c53ce28b2: Scheduling MajorDeltaCompactionOp(cd1d2b607c74458e89b7af1c836f38dc): perf score=1.000000
I20260812 06:19:36.998004 11247 maintenance_manager.cc:643] P c2bb14e4c0eb403cbc4fc75c53ce28b2: MajorDeltaCompactionOp(cd1d2b607c74458e89b7af1c836f38dc) complete. Timing: real 0.136s	user 0.099s	sys 0.036s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24815683,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":274,"lbm_read_time_us":8984,"lbm_reads_lt_1ms":572,"lbm_write_time_us":26335,"lbm_writes_lt_1ms":543,"peak_mem_usage":63115900,"reinsert_count":0,"update_count":2500}
I20260812 06:19:36.998620 11354 maintenance_manager.cc:419] P c2bb14e4c0eb403cbc4fc75c53ce28b2: Scheduling FlushDeltaMemStoresOp(cd1d2b607c74458e89b7af1c836f38dc): perf score=10.126437
I20260812 06:19:37.032936 11247 maintenance_manager.cc:643] P c2bb14e4c0eb403cbc4fc75c53ce28b2: FlushDeltaMemStoresOp(cd1d2b607c74458e89b7af1c836f38dc) complete. Timing: real 0.034s	user 0.023s	sys 0.003s Metrics: {"bytes_written":12307489,"delete_count":0,"lbm_write_time_us":12335,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:19:37.033437 11354 maintenance_manager.cc:419] P c2bb14e4c0eb403cbc4fc75c53ce28b2: Scheduling FlushDeltaMemStoresOp(cd1d2b607c74458e89b7af1c836f38dc): perf score=2.188937
I20260812 06:19:37.043076 11247 maintenance_manager.cc:643] P c2bb14e4c0eb403cbc4fc75c53ce28b2: FlushDeltaMemStoresOp(cd1d2b607c74458e89b7af1c836f38dc) complete. Timing: real 0.009s	user 0.008s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3596,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:37.043470 11354 maintenance_manager.cc:419] P c2bb14e4c0eb403cbc4fc75c53ce28b2: Scheduling MajorDeltaCompactionOp(cd1d2b607c74458e89b7af1c836f38dc): perf score=1.000000
I20260812 06:19:37.161438 11247 maintenance_manager.cc:643] P c2bb14e4c0eb403cbc4fc75c53ce28b2: MajorDeltaCompactionOp(cd1d2b607c74458e89b7af1c836f38dc) complete. Timing: real 0.118s	user 0.085s	sys 0.032s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20713271,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":795,"lbm_read_time_us":7893,"lbm_reads_lt_1ms":472,"lbm_write_time_us":22895,"lbm_writes_lt_1ms":443,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":2048,"update_count":2000}
I20260812 06:19:37.161954 11354 maintenance_manager.cc:419] P c2bb14e4c0eb403cbc4fc75c53ce28b2: Scheduling FlushDeltaMemStoresOp(cd1d2b607c74458e89b7af1c836f38dc): perf score=10.126437
I20260812 06:19:37.203989 11247 maintenance_manager.cc:643] P c2bb14e4c0eb403cbc4fc75c53ce28b2: FlushDeltaMemStoresOp(cd1d2b607c74458e89b7af1c836f38dc) complete. Timing: real 0.042s	user 0.016s	sys 0.012s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":13496,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:19:37.204545 11354 maintenance_manager.cc:419] P c2bb14e4c0eb403cbc4fc75c53ce28b2: Scheduling FlushDeltaMemStoresOp(cd1d2b607c74458e89b7af1c836f38dc): perf score=2.188937
I20260812 06:19:37.213817 11247 maintenance_manager.cc:643] P c2bb14e4c0eb403cbc4fc75c53ce28b2: FlushDeltaMemStoresOp(cd1d2b607c74458e89b7af1c836f38dc) complete. Timing: real 0.009s	user 0.004s	sys 0.005s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3392,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:37.214247 11354 maintenance_manager.cc:419] P c2bb14e4c0eb403cbc4fc75c53ce28b2: Scheduling MajorDeltaCompactionOp(cd1d2b607c74458e89b7af1c836f38dc): perf score=1.000000
I20260812 06:19:37.330318 11247 maintenance_manager.cc:643] P c2bb14e4c0eb403cbc4fc75c53ce28b2: MajorDeltaCompactionOp(cd1d2b607c74458e89b7af1c836f38dc) complete. Timing: real 0.116s	user 0.081s	sys 0.034s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20713272,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":869,"lbm_read_time_us":7679,"lbm_reads_lt_1ms":472,"lbm_write_time_us":22492,"lbm_writes_lt_1ms":443,"mutex_wait_us":306,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":30976,"update_count":2000}
I20260812 06:19:37.330817 11354 maintenance_manager.cc:419] P c2bb14e4c0eb403cbc4fc75c53ce28b2: Scheduling FlushDeltaMemStoresOp(cd1d2b607c74458e89b7af1c836f38dc): perf score=10.126437
I20260812 06:19:37.368331 11247 maintenance_manager.cc:643] P c2bb14e4c0eb403cbc4fc75c53ce28b2: FlushDeltaMemStoresOp(cd1d2b607c74458e89b7af1c836f38dc) complete. Timing: real 0.037s	user 0.022s	sys 0.011s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":12473,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:19:37.368909 11354 maintenance_manager.cc:419] P c2bb14e4c0eb403cbc4fc75c53ce28b2: Scheduling FlushDeltaMemStoresOp(cd1d2b607c74458e89b7af1c836f38dc): perf score=2.188937
I20260812 06:19:37.378631 11247 maintenance_manager.cc:643] P c2bb14e4c0eb403cbc4fc75c53ce28b2: FlushDeltaMemStoresOp(cd1d2b607c74458e89b7af1c836f38dc) complete. Timing: real 0.010s	user 0.003s	sys 0.005s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3687,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:37.379208 11354 maintenance_manager.cc:419] P c2bb14e4c0eb403cbc4fc75c53ce28b2: Scheduling FlushMRSOp(cd1d2b607c74458e89b7af1c836f38dc): perf score=1.000000
I20260812 06:19:37.409482 11247 maintenance_manager.cc:643] P c2bb14e4c0eb403cbc4fc75c53ce28b2: FlushMRSOp(cd1d2b607c74458e89b7af1c836f38dc) complete. Timing: real 0.030s	user 0.022s	sys 0.004s Metrics: {"bytes_written":1193509,"cfile_init":1,"dirs.queue_time_us":64,"dirs.run_cpu_time_us":203,"dirs.run_wall_time_us":1147,"drs_written":1,"lbm_read_time_us":42,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1405,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":29}
I20260812 06:19:37.410208 11354 maintenance_manager.cc:419] P c2bb14e4c0eb403cbc4fc75c53ce28b2: Scheduling LogGCOp(cd1d2b607c74458e89b7af1c836f38dc): free 121459505 bytes of WAL
I20260812 06:19:37.410439 11247 log_reader.cc:385] T cd1d2b607c74458e89b7af1c836f38dc: removed 12 log segments from log reader
I20260812 06:19:37.410497 11247 log.cc:1079] T cd1d2b607c74458e89b7af1c836f38dc P c2bb14e4c0eb403cbc4fc75c53ce28b2: Deleting log segment in path: /tmp/dist-test-taskQYaTMS/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515574268619-11048-0/minicluster-data/ts-0-root/wals/cd1d2b607c74458e89b7af1c836f38dc/wal-000000015 (ops 71-75)
I20260812 06:19:37.410539 11247 log.cc:1079] T cd1d2b607c74458e89b7af1c836f38dc P c2bb14e4c0eb403cbc4fc75c53ce28b2: Deleting log segment in path: /tmp/dist-test-taskQYaTMS/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515574268619-11048-0/minicluster-data/ts-0-root/wals/cd1d2b607c74458e89b7af1c836f38dc/wal-000000016 (ops 76-80)
I20260812 06:19:37.410576 11247 log.cc:1079] T cd1d2b607c74458e89b7af1c836f38dc P c2bb14e4c0eb403cbc4fc75c53ce28b2: Deleting log segment in path: /tmp/dist-test-taskQYaTMS/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515574268619-11048-0/minicluster-data/ts-0-root/wals/cd1d2b607c74458e89b7af1c836f38dc/wal-000000017 (ops 81-85)
I20260812 06:19:37.410606 11247 log.cc:1079] T cd1d2b607c74458e89b7af1c836f38dc P c2bb14e4c0eb403cbc4fc75c53ce28b2: Deleting log segment in path: /tmp/dist-test-taskQYaTMS/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515574268619-11048-0/minicluster-data/ts-0-root/wals/cd1d2b607c74458e89b7af1c836f38dc/wal-000000018 (ops 86-90)
I20260812 06:19:37.410635 11247 log.cc:1079] T cd1d2b607c74458e89b7af1c836f38dc P c2bb14e4c0eb403cbc4fc75c53ce28b2: Deleting log segment in path: /tmp/dist-test-taskQYaTMS/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515574268619-11048-0/minicluster-data/ts-0-root/wals/cd1d2b607c74458e89b7af1c836f38dc/wal-000000019 (ops 91-95)
I20260812 06:19:37.410663 11247 log.cc:1079] T cd1d2b607c74458e89b7af1c836f38dc P c2bb14e4c0eb403cbc4fc75c53ce28b2: Deleting log segment in path: /tmp/dist-test-taskQYaTMS/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515574268619-11048-0/minicluster-data/ts-0-root/wals/cd1d2b607c74458e89b7af1c836f38dc/wal-000000020 (ops 96-100)
I20260812 06:19:37.410692 11247 log.cc:1079] T cd1d2b607c74458e89b7af1c836f38dc P c2bb14e4c0eb403cbc4fc75c53ce28b2: Deleting log segment in path: /tmp/dist-test-taskQYaTMS/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515574268619-11048-0/minicluster-data/ts-0-root/wals/cd1d2b607c74458e89b7af1c836f38dc/wal-000000021 (ops 101-105)
I20260812 06:19:37.410725 11247 log.cc:1079] T cd1d2b607c74458e89b7af1c836f38dc P c2bb14e4c0eb403cbc4fc75c53ce28b2: Deleting log segment in path: /tmp/dist-test-taskQYaTMS/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515574268619-11048-0/minicluster-data/ts-0-root/wals/cd1d2b607c74458e89b7af1c836f38dc/wal-000000022 (ops 106-110)
I20260812 06:19:37.410754 11247 log.cc:1079] T cd1d2b607c74458e89b7af1c836f38dc P c2bb14e4c0eb403cbc4fc75c53ce28b2: Deleting log segment in path: /tmp/dist-test-taskQYaTMS/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515574268619-11048-0/minicluster-data/ts-0-root/wals/cd1d2b607c74458e89b7af1c836f38dc/wal-000000023 (ops 111-115)
I20260812 06:19:37.410784 11247 log.cc:1079] T cd1d2b607c74458e89b7af1c836f38dc P c2bb14e4c0eb403cbc4fc75c53ce28b2: Deleting log segment in path: /tmp/dist-test-taskQYaTMS/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515574268619-11048-0/minicluster-data/ts-0-root/wals/cd1d2b607c74458e89b7af1c836f38dc/wal-000000024 (ops 116-120)
I20260812 06:19:37.410810 11247 log.cc:1079] T cd1d2b607c74458e89b7af1c836f38dc P c2bb14e4c0eb403cbc4fc75c53ce28b2: Deleting log segment in path: /tmp/dist-test-taskQYaTMS/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515574268619-11048-0/minicluster-data/ts-0-root/wals/cd1d2b607c74458e89b7af1c836f38dc/wal-000000025 (ops 121-125)
I20260812 06:19:37.410835 11247 log.cc:1079] T cd1d2b607c74458e89b7af1c836f38dc P c2bb14e4c0eb403cbc4fc75c53ce28b2: Deleting log segment in path: /tmp/dist-test-taskQYaTMS/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515574268619-11048-0/minicluster-data/ts-0-root/wals/cd1d2b607c74458e89b7af1c836f38dc/wal-000000026 (ops 126-130)
I20260812 06:19:37.436967 11247 maintenance_manager.cc:643] P c2bb14e4c0eb403cbc4fc75c53ce28b2: LogGCOp(cd1d2b607c74458e89b7af1c836f38dc) complete. Timing: real 0.027s	user 0.000s	sys 0.023s Metrics: {}
I20260812 06:19:37.437428 11354 maintenance_manager.cc:419] P c2bb14e4c0eb403cbc4fc75c53ce28b2: Scheduling UndoDeltaBlockGCOp(cd1d2b607c74458e89b7af1c836f38dc): 461 bytes on disk
I20260812 06:19:37.437937 11247 maintenance_manager.cc:643] P c2bb14e4c0eb403cbc4fc75c53ce28b2: UndoDeltaBlockGCOp(cd1d2b607c74458e89b7af1c836f38dc) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":74,"lbm_reads_lt_1ms":4}
I20260812 06:19:37.438452 11354 maintenance_manager.cc:419] P c2bb14e4c0eb403cbc4fc75c53ce28b2: Scheduling FlushDeltaMemStoresOp(cd1d2b607c74458e89b7af1c836f38dc): perf score=3.181125
I20260812 06:19:37.458523 11247 maintenance_manager.cc:643] P c2bb14e4c0eb403cbc4fc75c53ce28b2: FlushDeltaMemStoresOp(cd1d2b607c74458e89b7af1c836f38dc) complete. Timing: real 0.020s	user 0.015s	sys 0.000s Metrics: {"bytes_written":4512900,"delete_count":0,"lbm_write_time_us":6486,"lbm_writes_lt_1ms":113,"reinsert_count":0,"update_count":550}
I20260812 06:19:37.458935 11354 maintenance_manager.cc:419] P c2bb14e4c0eb403cbc4fc75c53ce28b2: Scheduling FlushDeltaMemStoresOp(cd1d2b607c74458e89b7af1c836f38dc): perf score=2.188937
I20260812 06:19:37.467449 11247 maintenance_manager.cc:643] P c2bb14e4c0eb403cbc4fc75c53ce28b2: FlushDeltaMemStoresOp(cd1d2b607c74458e89b7af1c836f38dc) complete. Timing: real 0.008s	user 0.004s	sys 0.003s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3202,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:19:37.467947 11354 maintenance_manager.cc:419] P c2bb14e4c0eb403cbc4fc75c53ce28b2: Scheduling MajorDeltaCompactionOp(cd1d2b607c74458e89b7af1c836f38dc): perf score=1.000000
I20260812 06:19:37.659175 11247 maintenance_manager.cc:643] P c2bb14e4c0eb403cbc4fc75c53ce28b2: MajorDeltaCompactionOp(cd1d2b607c74458e89b7af1c836f38dc) complete. Timing: real 0.191s	user 0.127s	sys 0.064s Metrics: {"cfile_cache_miss":634,"cfile_cache_miss_bytes":28918321,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":460,"lbm_read_time_us":13665,"lbm_reads_lt_1ms":674,"lbm_write_time_us":31329,"lbm_writes_lt_1ms":643,"mutex_wait_us":40,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":1792,"thread_start_us":79,"threads_started":1,"update_count":3000}
I20260812 06:19:37.660648 11354 maintenance_manager.cc:419] P c2bb14e4c0eb403cbc4fc75c53ce28b2: Scheduling FlushDeltaMemStoresOp(cd1d2b607c74458e89b7af1c836f38dc): perf score=14.095187
I20260812 06:19:37.709380 11247 maintenance_manager.cc:643] P c2bb14e4c0eb403cbc4fc75c53ce28b2: FlushDeltaMemStoresOp(cd1d2b607c74458e89b7af1c836f38dc) complete. Timing: real 0.049s	user 0.031s	sys 0.012s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":19243,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:37.709863 11354 maintenance_manager.cc:419] P c2bb14e4c0eb403cbc4fc75c53ce28b2: Scheduling FlushDeltaMemStoresOp(cd1d2b607c74458e89b7af1c836f38dc): perf score=2.188937
I20260812 06:19:37.724012 11247 maintenance_manager.cc:643] P c2bb14e4c0eb403cbc4fc75c53ce28b2: FlushDeltaMemStoresOp(cd1d2b607c74458e89b7af1c836f38dc) complete. Timing: real 0.014s	user 0.012s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5374,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:37.724506 11354 maintenance_manager.cc:419] P c2bb14e4c0eb403cbc4fc75c53ce28b2: Scheduling MajorDeltaCompactionOp(cd1d2b607c74458e89b7af1c836f38dc): perf score=1.000000
I20260812 06:19:37.883208 11247 maintenance_manager.cc:643] P c2bb14e4c0eb403cbc4fc75c53ce28b2: MajorDeltaCompactionOp(cd1d2b607c74458e89b7af1c836f38dc) complete. Timing: real 0.159s	user 0.114s	sys 0.044s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24815683,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":538,"lbm_read_time_us":10929,"lbm_reads_lt_1ms":572,"lbm_write_time_us":26931,"lbm_writes_lt_1ms":543,"mutex_wait_us":36,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":15488,"update_count":2500}
I20260812 06:19:37.883956 11354 maintenance_manager.cc:419] P c2bb14e4c0eb403cbc4fc75c53ce28b2: Scheduling FlushDeltaMemStoresOp(cd1d2b607c74458e89b7af1c836f38dc): perf score=11.118625
I20260812 06:19:37.932132 11247 maintenance_manager.cc:643] P c2bb14e4c0eb403cbc4fc75c53ce28b2: FlushDeltaMemStoresOp(cd1d2b607c74458e89b7af1c836f38dc) complete. Timing: real 0.048s	user 0.026s	sys 0.019s Metrics: {"bytes_written":12717736,"delete_count":0,"lbm_write_time_us":17356,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:19:37.932711 11354 maintenance_manager.cc:419] P c2bb14e4c0eb403cbc4fc75c53ce28b2: Scheduling FlushDeltaMemStoresOp(cd1d2b607c74458e89b7af1c836f38dc): perf score=2.188937
I20260812 06:19:37.944852 11247 maintenance_manager.cc:643] P c2bb14e4c0eb403cbc4fc75c53ce28b2: FlushDeltaMemStoresOp(cd1d2b607c74458e89b7af1c836f38dc) complete. Timing: real 0.012s	user 0.009s	sys 0.000s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3844,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:19:37.945513 11354 maintenance_manager.cc:419] P c2bb14e4c0eb403cbc4fc75c53ce28b2: Scheduling MajorDeltaCompactionOp(cd1d2b607c74458e89b7af1c836f38dc): perf score=1.000000
I20260812 06:19:38.092024 11247 maintenance_manager.cc:643] P c2bb14e4c0eb403cbc4fc75c53ce28b2: MajorDeltaCompactionOp(cd1d2b607c74458e89b7af1c836f38dc) complete. Timing: real 0.146s	user 0.081s	sys 0.056s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20713264,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":257,"lbm_read_time_us":7854,"lbm_reads_lt_1ms":464,"lbm_write_time_us":21782,"lbm_writes_lt_1ms":443,"mutex_wait_us":255,"peak_mem_usage":50689328,"reinsert_count":0,"update_count":2000}
I20260812 06:19:38.092661 11354 maintenance_manager.cc:419] P c2bb14e4c0eb403cbc4fc75c53ce28b2: Scheduling FlushDeltaMemStoresOp(cd1d2b607c74458e89b7af1c836f38dc): perf score=14.095187
I20260812 06:19:38.143101 11247 maintenance_manager.cc:643] P c2bb14e4c0eb403cbc4fc75c53ce28b2: FlushDeltaMemStoresOp(cd1d2b607c74458e89b7af1c836f38dc) complete. Timing: real 0.050s	user 0.025s	sys 0.012s Metrics: {"bytes_written":16409904,"delete_count":0,"lbm_write_time_us":16718,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:38.143694 11354 maintenance_manager.cc:419] P c2bb14e4c0eb403cbc4fc75c53ce28b2: Scheduling FlushDeltaMemStoresOp(cd1d2b607c74458e89b7af1c836f38dc): perf score=2.188937
I20260812 06:19:38.154721 11247 maintenance_manager.cc:643] P c2bb14e4c0eb403cbc4fc75c53ce28b2: FlushDeltaMemStoresOp(cd1d2b607c74458e89b7af1c836f38dc) complete. Timing: real 0.011s	user 0.005s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3921,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:38.155189 11354 maintenance_manager.cc:419] P c2bb14e4c0eb403cbc4fc75c53ce28b2: Scheduling MajorDeltaCompactionOp(cd1d2b607c74458e89b7af1c836f38dc): perf score=1.000000
I20260812 06:19:38.321203 11247 maintenance_manager.cc:643] P c2bb14e4c0eb403cbc4fc75c53ce28b2: MajorDeltaCompactionOp(cd1d2b607c74458e89b7af1c836f38dc) complete. Timing: real 0.166s	user 0.100s	sys 0.053s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24815686,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":795,"lbm_read_time_us":11023,"lbm_reads_lt_1ms":572,"lbm_write_time_us":28291,"lbm_writes_lt_1ms":543,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":768,"update_count":2500}
I20260812 06:19:38.321655 11354 maintenance_manager.cc:419] P c2bb14e4c0eb403cbc4fc75c53ce28b2: Scheduling FlushDeltaMemStoresOp(cd1d2b607c74458e89b7af1c836f38dc): perf score=14.095187
I20260812 06:19:38.364441 11247 maintenance_manager.cc:643] P c2bb14e4c0eb403cbc4fc75c53ce28b2: FlushDeltaMemStoresOp(cd1d2b607c74458e89b7af1c836f38dc) complete. Timing: real 0.043s	user 0.024s	sys 0.012s Metrics: {"bytes_written":16409899,"delete_count":0,"lbm_write_time_us":16954,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:38.364914 11354 maintenance_manager.cc:419] P c2bb14e4c0eb403cbc4fc75c53ce28b2: Scheduling FlushDeltaMemStoresOp(cd1d2b607c74458e89b7af1c836f38dc): perf score=2.188937
I20260812 06:19:38.374827 11247 maintenance_manager.cc:643] P c2bb14e4c0eb403cbc4fc75c53ce28b2: FlushDeltaMemStoresOp(cd1d2b607c74458e89b7af1c836f38dc) complete. Timing: real 0.010s	user 0.008s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3722,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:38.375380 11354 maintenance_manager.cc:419] P c2bb14e4c0eb403cbc4fc75c53ce28b2: Scheduling MajorDeltaCompactionOp(cd1d2b607c74458e89b7af1c836f38dc): perf score=1.000000
I20260812 06:19:38.524513 11247 maintenance_manager.cc:643] P c2bb14e4c0eb403cbc4fc75c53ce28b2: MajorDeltaCompactionOp(cd1d2b607c74458e89b7af1c836f38dc) complete. Timing: real 0.149s	user 0.090s	sys 0.048s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24815681,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":114,"lbm_read_time_us":9362,"lbm_reads_lt_1ms":572,"lbm_write_time_us":26729,"lbm_writes_lt_1ms":543,"mutex_wait_us":30,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":2944,"update_count":2500}
I20260812 06:19:38.525081 11354 maintenance_manager.cc:419] P c2bb14e4c0eb403cbc4fc75c53ce28b2: Scheduling FlushDeltaMemStoresOp(cd1d2b607c74458e89b7af1c836f38dc): perf score=14.095187
I20260812 06:19:38.567415 11247 maintenance_manager.cc:643] P c2bb14e4c0eb403cbc4fc75c53ce28b2: FlushDeltaMemStoresOp(cd1d2b607c74458e89b7af1c836f38dc) complete. Timing: real 0.042s	user 0.034s	sys 0.004s Metrics: {"bytes_written":16409903,"delete_count":0,"lbm_write_time_us":18001,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:38.567878 11354 maintenance_manager.cc:419] P c2bb14e4c0eb403cbc4fc75c53ce28b2: Scheduling FlushDeltaMemStoresOp(cd1d2b607c74458e89b7af1c836f38dc): perf score=2.188937
I20260812 06:19:38.578588 11247 maintenance_manager.cc:643] P c2bb14e4c0eb403cbc4fc75c53ce28b2: FlushDeltaMemStoresOp(cd1d2b607c74458e89b7af1c836f38dc) complete. Timing: real 0.011s	user 0.005s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3971,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:38.579193 11354 maintenance_manager.cc:419] P c2bb14e4c0eb403cbc4fc75c53ce28b2: Scheduling MajorDeltaCompactionOp(cd1d2b607c74458e89b7af1c836f38dc): perf score=1.000000
I20260812 06:19:38.716363 11247 maintenance_manager.cc:643] P c2bb14e4c0eb403cbc4fc75c53ce28b2: MajorDeltaCompactionOp(cd1d2b607c74458e89b7af1c836f38dc) complete. Timing: real 0.137s	user 0.112s	sys 0.025s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24815685,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":541,"lbm_read_time_us":10041,"lbm_reads_lt_1ms":572,"lbm_write_time_us":27249,"lbm_writes_lt_1ms":543,"mutex_wait_us":26,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":59776,"update_count":2500}
I20260812 06:19:38.716965 11354 maintenance_manager.cc:419] P c2bb14e4c0eb403cbc4fc75c53ce28b2: Scheduling FlushDeltaMemStoresOp(cd1d2b607c74458e89b7af1c836f38dc): perf score=14.095187
I20260812 06:19:38.763736 11247 maintenance_manager.cc:643] P c2bb14e4c0eb403cbc4fc75c53ce28b2: FlushDeltaMemStoresOp(cd1d2b607c74458e89b7af1c836f38dc) complete. Timing: real 0.047s	user 0.016s	sys 0.019s Metrics: {"bytes_written":16409903,"delete_count":0,"lbm_write_time_us":16961,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:38.764215 11354 maintenance_manager.cc:419] P c2bb14e4c0eb403cbc4fc75c53ce28b2: Scheduling FlushDeltaMemStoresOp(cd1d2b607c74458e89b7af1c836f38dc): perf score=2.188937
I20260812 06:19:38.773739 11247 maintenance_manager.cc:643] P c2bb14e4c0eb403cbc4fc75c53ce28b2: FlushDeltaMemStoresOp(cd1d2b607c74458e89b7af1c836f38dc) complete. Timing: real 0.009s	user 0.009s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3551,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:38.774374 11354 maintenance_manager.cc:419] P c2bb14e4c0eb403cbc4fc75c53ce28b2: Scheduling FlushMRSOp(cd1d2b607c74458e89b7af1c836f38dc): perf score=1.000000
I20260812 06:19:38.807962 11247 maintenance_manager.cc:643] P c2bb14e4c0eb403cbc4fc75c53ce28b2: FlushMRSOp(cd1d2b607c74458e89b7af1c836f38dc) complete. Timing: real 0.033s	user 0.029s	sys 0.003s Metrics: {"bytes_written":1275447,"cfile_init":1,"dirs.queue_time_us":56,"dirs.run_cpu_time_us":201,"dirs.run_wall_time_us":1154,"drs_written":1,"lbm_read_time_us":36,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1509,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":31}
I20260812 06:19:38.808626 11354 maintenance_manager.cc:419] P c2bb14e4c0eb403cbc4fc75c53ce28b2: Scheduling LogGCOp(cd1d2b607c74458e89b7af1c836f38dc): free 132571585 bytes of WAL
I20260812 06:19:38.808861 11247 log_reader.cc:385] T cd1d2b607c74458e89b7af1c836f38dc: removed 13 log segments from log reader
I20260812 06:19:38.808908 11247 log.cc:1079] T cd1d2b607c74458e89b7af1c836f38dc P c2bb14e4c0eb403cbc4fc75c53ce28b2: Deleting log segment in path: /tmp/dist-test-taskQYaTMS/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515574268619-11048-0/minicluster-data/ts-0-root/wals/cd1d2b607c74458e89b7af1c836f38dc/wal-000000027 (ops 131-135)
I20260812 06:19:38.808936 11247 log.cc:1079] T cd1d2b607c74458e89b7af1c836f38dc P c2bb14e4c0eb403cbc4fc75c53ce28b2: Deleting log segment in path: /tmp/dist-test-taskQYaTMS/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515574268619-11048-0/minicluster-data/ts-0-root/wals/cd1d2b607c74458e89b7af1c836f38dc/wal-000000028 (ops 136-140)
I20260812 06:19:38.808967 11247 log.cc:1079] T cd1d2b607c74458e89b7af1c836f38dc P c2bb14e4c0eb403cbc4fc75c53ce28b2: Deleting log segment in path: /tmp/dist-test-taskQYaTMS/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515574268619-11048-0/minicluster-data/ts-0-root/wals/cd1d2b607c74458e89b7af1c836f38dc/wal-000000029 (ops 141-145)
I20260812 06:19:38.809000 11247 log.cc:1079] T cd1d2b607c74458e89b7af1c836f38dc P c2bb14e4c0eb403cbc4fc75c53ce28b2: Deleting log segment in path: /tmp/dist-test-taskQYaTMS/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515574268619-11048-0/minicluster-data/ts-0-root/wals/cd1d2b607c74458e89b7af1c836f38dc/wal-000000030 (ops 146-150)
I20260812 06:19:38.809028 11247 log.cc:1079] T cd1d2b607c74458e89b7af1c836f38dc P c2bb14e4c0eb403cbc4fc75c53ce28b2: Deleting log segment in path: /tmp/dist-test-taskQYaTMS/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515574268619-11048-0/minicluster-data/ts-0-root/wals/cd1d2b607c74458e89b7af1c836f38dc/wal-000000031 (ops 151-154)
I20260812 06:19:38.809070 11247 log.cc:1079] T cd1d2b607c74458e89b7af1c836f38dc P c2bb14e4c0eb403cbc4fc75c53ce28b2: Deleting log segment in path: /tmp/dist-test-taskQYaTMS/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515574268619-11048-0/minicluster-data/ts-0-root/wals/cd1d2b607c74458e89b7af1c836f38dc/wal-000000032 (ops 155-159)
I20260812 06:19:38.809129 11247 log.cc:1079] T cd1d2b607c74458e89b7af1c836f38dc P c2bb14e4c0eb403cbc4fc75c53ce28b2: Deleting log segment in path: /tmp/dist-test-taskQYaTMS/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515574268619-11048-0/minicluster-data/ts-0-root/wals/cd1d2b607c74458e89b7af1c836f38dc/wal-000000033 (ops 160-164)
I20260812 06:19:38.809154 11247 log.cc:1079] T cd1d2b607c74458e89b7af1c836f38dc P c2bb14e4c0eb403cbc4fc75c53ce28b2: Deleting log segment in path: /tmp/dist-test-taskQYaTMS/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515574268619-11048-0/minicluster-data/ts-0-root/wals/cd1d2b607c74458e89b7af1c836f38dc/wal-000000034 (ops 165-169)
I20260812 06:19:38.809185 11247 log.cc:1079] T cd1d2b607c74458e89b7af1c836f38dc P c2bb14e4c0eb403cbc4fc75c53ce28b2: Deleting log segment in path: /tmp/dist-test-taskQYaTMS/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515574268619-11048-0/minicluster-data/ts-0-root/wals/cd1d2b607c74458e89b7af1c836f38dc/wal-000000035 (ops 170-174)
I20260812 06:19:38.809216 11247 log.cc:1079] T cd1d2b607c74458e89b7af1c836f38dc P c2bb14e4c0eb403cbc4fc75c53ce28b2: Deleting log segment in path: /tmp/dist-test-taskQYaTMS/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515574268619-11048-0/minicluster-data/ts-0-root/wals/cd1d2b607c74458e89b7af1c836f38dc/wal-000000036 (ops 175-179)
I20260812 06:19:38.809247 11247 log.cc:1079] T cd1d2b607c74458e89b7af1c836f38dc P c2bb14e4c0eb403cbc4fc75c53ce28b2: Deleting log segment in path: /tmp/dist-test-taskQYaTMS/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515574268619-11048-0/minicluster-data/ts-0-root/wals/cd1d2b607c74458e89b7af1c836f38dc/wal-000000037 (ops 180-184)
I20260812 06:19:38.809278 11247 log.cc:1079] T cd1d2b607c74458e89b7af1c836f38dc P c2bb14e4c0eb403cbc4fc75c53ce28b2: Deleting log segment in path: /tmp/dist-test-taskQYaTMS/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515574268619-11048-0/minicluster-data/ts-0-root/wals/cd1d2b607c74458e89b7af1c836f38dc/wal-000000038 (ops 185-188)
I20260812 06:19:38.809301 11247 log.cc:1079] T cd1d2b607c74458e89b7af1c836f38dc P c2bb14e4c0eb403cbc4fc75c53ce28b2: Deleting log segment in path: /tmp/dist-test-taskQYaTMS/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515574268619-11048-0/minicluster-data/ts-0-root/wals/cd1d2b607c74458e89b7af1c836f38dc/wal-000000039 (ops 189-193)
I20260812 06:19:38.834906 11247 maintenance_manager.cc:643] P c2bb14e4c0eb403cbc4fc75c53ce28b2: LogGCOp(cd1d2b607c74458e89b7af1c836f38dc) complete. Timing: real 0.026s	user 0.001s	sys 0.023s Metrics: {}
I20260812 06:19:38.835274 11354 maintenance_manager.cc:419] P c2bb14e4c0eb403cbc4fc75c53ce28b2: Scheduling UndoDeltaBlockGCOp(cd1d2b607c74458e89b7af1c836f38dc): 482 bytes on disk
I20260812 06:19:38.835906 11247 maintenance_manager.cc:643] P c2bb14e4c0eb403cbc4fc75c53ce28b2: UndoDeltaBlockGCOp(cd1d2b607c74458e89b7af1c836f38dc) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":66,"lbm_reads_lt_1ms":4}
I20260812 06:19:38.836560 11354 maintenance_manager.cc:419] P c2bb14e4c0eb403cbc4fc75c53ce28b2: Scheduling FlushDeltaMemStoresOp(cd1d2b607c74458e89b7af1c836f38dc): perf score=4.173312
I20260812 06:19:38.853436 11247 maintenance_manager.cc:643] P c2bb14e4c0eb403cbc4fc75c53ce28b2: FlushDeltaMemStoresOp(cd1d2b607c74458e89b7af1c836f38dc) complete. Timing: real 0.017s	user 0.013s	sys 0.004s Metrics: {"bytes_written":6235918,"delete_count":0,"lbm_write_time_us":6773,"lbm_writes_lt_1ms":155,"reinsert_count":0,"update_count":760}
I20260812 06:19:38.853832 11354 maintenance_manager.cc:419] P c2bb14e4c0eb403cbc4fc75c53ce28b2: Scheduling FlushDeltaMemStoresOp(cd1d2b607c74458e89b7af1c836f38dc): perf score=1.000000
I20260812 06:19:38.860582 11247 maintenance_manager.cc:643] P c2bb14e4c0eb403cbc4fc75c53ce28b2: FlushDeltaMemStoresOp(cd1d2b607c74458e89b7af1c836f38dc) complete. Timing: real 0.007s	user 0.005s	sys 0.000s Metrics: {"bytes_written":1969352,"delete_count":0,"lbm_write_time_us":2093,"lbm_writes_lt_1ms":51,"reinsert_count":0,"update_count":240}
I20260812 06:19:38.860986 11354 maintenance_manager.cc:419] P c2bb14e4c0eb403cbc4fc75c53ce28b2: Scheduling MajorDeltaCompactionOp(cd1d2b607c74458e89b7af1c836f38dc): perf score=1.000000
I20260812 06:19:38.978150 11048 heavy-update-compaction-itest.cc:229] Time spent updating: real 4.471s	user 1.585s	sys 0.135s
I20260812 06:19:39.044075 11247 maintenance_manager.cc:643] P c2bb14e4c0eb403cbc4fc75c53ce28b2: MajorDeltaCompactionOp(cd1d2b607c74458e89b7af1c836f38dc) complete. Timing: real 0.183s	user 0.155s	sys 0.024s Metrics: {"cfile_cache_miss":734,"cfile_cache_miss_bytes":33020694,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"lbm_read_time_us":11994,"lbm_reads_lt_1ms":770,"lbm_write_time_us":34704,"lbm_writes_lt_1ms":743,"peak_mem_usage":87969044,"reinsert_count":0,"spinlock_wait_cycles":1664,"update_count":3500}
I20260812 06:19:39.044610 11354 maintenance_manager.cc:419] P c2bb14e4c0eb403cbc4fc75c53ce28b2: Scheduling FlushDeltaMemStoresOp(cd1d2b607c74458e89b7af1c836f38dc): perf score=10.126437
I20260812 06:19:39.068121 11048 heavy-update-compaction-itest.cc:265] Time spent scanning: real 0.089s	user 0.001s	sys 0.000s
I20260812 06:19:39.068734 11048 tablet_server.cc:179] TabletServer@127.10.202.1:0 shutting down...
I20260812 06:19:39.072387 11247 maintenance_manager.cc:643] P c2bb14e4c0eb403cbc4fc75c53ce28b2: FlushDeltaMemStoresOp(cd1d2b607c74458e89b7af1c836f38dc) complete. Timing: real 0.028s	user 0.012s	sys 0.012s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":11506,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:19:39.072839 11354 maintenance_manager.cc:419] P c2bb14e4c0eb403cbc4fc75c53ce28b2: Scheduling MajorDeltaCompactionOp(cd1d2b607c74458e89b7af1c836f38dc): perf score=1.000000
I20260812 06:19:39.164287 11247 maintenance_manager.cc:643] P c2bb14e4c0eb403cbc4fc75c53ce28b2: MajorDeltaCompactionOp(cd1d2b607c74458e89b7af1c836f38dc) complete. Timing: real 0.091s	user 0.075s	sys 0.016s Metrics: {"cfile_cache_miss":331,"cfile_cache_miss_bytes":16610741,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":1,"delta_iterators_relevant":1,"dirs.queue_time_us":348,"lbm_read_time_us":5550,"lbm_reads_lt_1ms":367,"lbm_write_time_us":16442,"lbm_writes_lt_1ms":343,"mutex_wait_us":28,"peak_mem_usage":38262756,"reinsert_count":0,"update_count":1500}
I20260812 06:19:39.165155 11048 ts_tablet_manager.cc:1507] Shutting down tablet manager...
I20260812 06:19:39.165576 11048 tablet_replica.cc:333] T cd1d2b607c74458e89b7af1c836f38dc P c2bb14e4c0eb403cbc4fc75c53ce28b2: stopping tablet replica
I20260812 06:19:39.165815 11048 raft_consensus.cc:2243] T cd1d2b607c74458e89b7af1c836f38dc P c2bb14e4c0eb403cbc4fc75c53ce28b2 [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:19:39.166069 11048 raft_consensus.cc:2272] T cd1d2b607c74458e89b7af1c836f38dc P c2bb14e4c0eb403cbc4fc75c53ce28b2 [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:19:39.180869 11048 tablet_server.cc:196] TabletServer@127.10.202.1:0 shutdown complete.
I20260812 06:19:39.195930 11048 master.cc:562] Master@127.10.202.62:37477 shutting down...
I20260812 06:19:39.199404 11048 raft_consensus.cc:2243] T 00000000000000000000000000000000 P 63352395157d4165af2a43abd8d36141 [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:19:39.199568 11048 raft_consensus.cc:2272] T 00000000000000000000000000000000 P 63352395157d4165af2a43abd8d36141 [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:19:39.199644 11048 tablet_replica.cc:333] T 00000000000000000000000000000000 P 63352395157d4165af2a43abd8d36141: stopping tablet replica
I20260812 06:19:39.211673 11048 master.cc:584] Master@127.10.202.62:37477 shutdown complete.
[       OK ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/0 (5004 ms)
[ RUN      ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/1
I20260812 06:19:39.283607 11048 internal_mini_cluster.cc:156] Creating distributed mini masters. Addrs: 127.10.202.62:44783
I20260812 06:19:39.283986 11048 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:19:39.285881 11412 instance_detector.cc:116] could not retrieve Azure instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:19:39.285965 11414 instance_detector.cc:116] could not retrieve OpenStack instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:19:39.286041 11411 instance_detector.cc:116] could not retrieve AWS instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:19:39.286094 11048 server_base.cc:1061] running on GCE node
I20260812 06:19:39.286247 11048 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:19:39.286288 11048 system_unsync_time.cc:38] NTP support is disabled. Clock error bounds will not be accurate. This configuration is not suitable for distributed clusters.
I20260812 06:19:39.286307 11048 hybrid_clock.cc:648] HybridClock initialized: now 1786515579286307 us; error 0 us; skew 500 ppm
I20260812 06:19:39.287161 11048 webserver.cc:533] Webserver started at http://127.10.202.62:38847/ using document root <none> and password file <none>
I20260812 06:19:39.287313 11048 fs_manager.cc:362] Metadata directory not provided
I20260812 06:19:39.287359 11048 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:19:39.287433 11048 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:19:39.287792 11048 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskQYaTMS/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515574268619-11048-0/minicluster-data/master-0-root/instance:
uuid: "9908857d41a54a03833395d917805fb1"
format_stamp: "Formatted at 2026-08-12 06:19:39 on dist-test-slave-266d"
I20260812 06:19:39.289242 11048 fs_manager.cc:696] Time spent creating directory manager: real 0.001s	user 0.002s	sys 0.000s
I20260812 06:19:39.290109 11424 log_block_manager.cc:4127] Time spent loading block containers with low live blocks: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:19:39.290321 11048 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.001s	sys 0.000s
I20260812 06:19:39.290390 11048 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskQYaTMS/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515574268619-11048-0/minicluster-data/master-0-root
uuid: "9908857d41a54a03833395d917805fb1"
format_stamp: "Formatted at 2026-08-12 06:19:39 on dist-test-slave-266d"
I20260812 06:19:39.290457 11048 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskQYaTMS/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515574268619-11048-0/minicluster-data/master-0-root
metadata directory: /tmp/dist-test-taskQYaTMS/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515574268619-11048-0/minicluster-data/master-0-root
1 data directories: /tmp/dist-test-taskQYaTMS/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515574268619-11048-0/minicluster-data/master-0-root/data
Total live blocks: 0
Total live bytes: 0
Total live bytes (after alignment): 0
Total number of LBM containers: 0 (0 full)
Did not check for missing blocks
Did not check for orphaned blocks
Total full LBM containers with extra space: 0 (0 repaired)
Total full LBM container extra space in bytes: 0 (0 repaired)
Total incomplete LBM containers: 0 (0 repaired)
Total LBM partial records: 0 (0 repaired)
Total corrupted LBM metadata records in RocksDB: 0 (0 repaired)
I20260812 06:19:39.295481 11048 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:19:39.295765 11048 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:19:39.299691 11048 rpc_server.cc:307] RPC server started. Bound to: 127.10.202.62:44783
I20260812 06:19:39.309502 11505 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.10.202.62:44783 every 8 connection(s)
I20260812 06:19:39.309913 11506 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet 00000000000000000000000000000000. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:19:39.311563 11506 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P 9908857d41a54a03833395d917805fb1: Bootstrap starting.
I20260812 06:19:39.312275 11506 tablet_bootstrap.cc:654] T 00000000000000000000000000000000 P 9908857d41a54a03833395d917805fb1: Neither blocks nor log segments found. Creating new log.
I20260812 06:19:39.313177 11506 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P 9908857d41a54a03833395d917805fb1: No bootstrap required, opened a new log
I20260812 06:19:39.313546 11506 raft_consensus.cc:359] T 00000000000000000000000000000000 P 9908857d41a54a03833395d917805fb1 [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "9908857d41a54a03833395d917805fb1" member_type: VOTER }
I20260812 06:19:39.313627 11506 raft_consensus.cc:385] T 00000000000000000000000000000000 P 9908857d41a54a03833395d917805fb1 [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:19:39.313657 11506 raft_consensus.cc:740] T 00000000000000000000000000000000 P 9908857d41a54a03833395d917805fb1 [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: 9908857d41a54a03833395d917805fb1, State: Initialized, Role: FOLLOWER
I20260812 06:19:39.313788 11506 consensus_queue.cc:260] T 00000000000000000000000000000000 P 9908857d41a54a03833395d917805fb1 [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: "9908857d41a54a03833395d917805fb1" member_type: VOTER }
I20260812 06:19:39.313860 11506 raft_consensus.cc:399] T 00000000000000000000000000000000 P 9908857d41a54a03833395d917805fb1 [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:19:39.313899 11506 raft_consensus.cc:493] T 00000000000000000000000000000000 P 9908857d41a54a03833395d917805fb1 [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:19:39.313946 11506 raft_consensus.cc:3060] T 00000000000000000000000000000000 P 9908857d41a54a03833395d917805fb1 [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:19:39.314592 11506 raft_consensus.cc:515] T 00000000000000000000000000000000 P 9908857d41a54a03833395d917805fb1 [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "9908857d41a54a03833395d917805fb1" member_type: VOTER }
I20260812 06:19:39.314716 11506 leader_election.cc:304] T 00000000000000000000000000000000 P 9908857d41a54a03833395d917805fb1 [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: 9908857d41a54a03833395d917805fb1; no voters: 
I20260812 06:19:39.314877 11506 leader_election.cc:290] T 00000000000000000000000000000000 P 9908857d41a54a03833395d917805fb1 [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:19:39.314965 11513 raft_consensus.cc:2804] T 00000000000000000000000000000000 P 9908857d41a54a03833395d917805fb1 [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:19:39.315169 11513 raft_consensus.cc:697] T 00000000000000000000000000000000 P 9908857d41a54a03833395d917805fb1 [term 1 LEADER]: Becoming Leader. State: Replica: 9908857d41a54a03833395d917805fb1, State: Running, Role: LEADER
I20260812 06:19:39.315303 11506 sys_catalog.cc:565] T 00000000000000000000000000000000 P 9908857d41a54a03833395d917805fb1 [sys.catalog]: configured and running, proceeding with master startup.
I20260812 06:19:39.315300 11513 consensus_queue.cc:237] T 00000000000000000000000000000000 P 9908857d41a54a03833395d917805fb1 [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: "9908857d41a54a03833395d917805fb1" member_type: VOTER }
I20260812 06:19:39.315724 11516 sys_catalog.cc:455] T 00000000000000000000000000000000 P 9908857d41a54a03833395d917805fb1 [sys.catalog]: SysCatalogTable state changed. Reason: New leader 9908857d41a54a03833395d917805fb1. Latest consensus state: current_term: 1 leader_uuid: "9908857d41a54a03833395d917805fb1" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "9908857d41a54a03833395d917805fb1" member_type: VOTER } }
I20260812 06:19:39.315711 11515 sys_catalog.cc:455] T 00000000000000000000000000000000 P 9908857d41a54a03833395d917805fb1 [sys.catalog]: SysCatalogTable state changed. Reason: RaftConsensus started. Latest consensus state: current_term: 1 leader_uuid: "9908857d41a54a03833395d917805fb1" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "9908857d41a54a03833395d917805fb1" member_type: VOTER } }
I20260812 06:19:39.315819 11516 sys_catalog.cc:458] T 00000000000000000000000000000000 P 9908857d41a54a03833395d917805fb1 [sys.catalog]: This master's current role is: LEADER
I20260812 06:19:39.315832 11515 sys_catalog.cc:458] T 00000000000000000000000000000000 P 9908857d41a54a03833395d917805fb1 [sys.catalog]: This master's current role is: LEADER
I20260812 06:19:39.316077 11524 catalog_manager.cc:1511] Loading table and tablet metadata into memory...
I20260812 06:19:39.316848 11524 catalog_manager.cc:1520] Initializing Kudu cluster ID...
I20260812 06:19:39.317137 11048 internal_mini_cluster.cc:184] Waiting to initialize catalog manager on master 0
I20260812 06:19:39.318555 11524 catalog_manager.cc:1383] Generated new cluster ID: 1d4948d5bcec43ddbe73876e88a06912
I20260812 06:19:39.318611 11524 catalog_manager.cc:1531] Initializing Kudu internal certificate authority...
I20260812 06:19:39.325161 11524 catalog_manager.cc:1406] Generated new certificate authority record
I20260812 06:19:39.325646 11524 catalog_manager.cc:1540] Loading token signing keys...
I20260812 06:19:39.335088 11524 catalog_manager.cc:6092] T 00000000000000000000000000000000 P 9908857d41a54a03833395d917805fb1: Generated new TSK 0
I20260812 06:19:39.335235 11524 catalog_manager.cc:1550] Initializing in-progress tserver states...
I20260812 06:19:39.349373 11048 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:19:39.351023 11547 instance_detector.cc:116] could not retrieve AWS instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:19:39.351138 11559 instance_detector.cc:116] could not retrieve OpenStack instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:19:39.351193 11048 server_base.cc:1061] running on GCE node
W20260812 06:19:39.351225 11551 instance_detector.cc:116] could not retrieve Azure instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:19:39.351432 11048 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:19:39.351475 11048 system_unsync_time.cc:38] NTP support is disabled. Clock error bounds will not be accurate. This configuration is not suitable for distributed clusters.
I20260812 06:19:39.351495 11048 hybrid_clock.cc:648] HybridClock initialized: now 1786515579351494 us; error 0 us; skew 500 ppm
I20260812 06:19:39.352269 11048 webserver.cc:533] Webserver started at http://127.10.202.1:43867/ using document root <none> and password file <none>
I20260812 06:19:39.352419 11048 fs_manager.cc:362] Metadata directory not provided
I20260812 06:19:39.352463 11048 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:19:39.352535 11048 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:19:39.352877 11048 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskQYaTMS/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515574268619-11048-0/minicluster-data/ts-0-root/instance:
uuid: "7d7eea69744f4e0f8eb3b84a1e8c8cb4"
format_stamp: "Formatted at 2026-08-12 06:19:39 on dist-test-slave-266d"
I20260812 06:19:39.354224 11048 fs_manager.cc:696] Time spent creating directory manager: real 0.001s	user 0.001s	sys 0.001s
I20260812 06:19:39.355050 11567 log_block_manager.cc:4127] Time spent loading block containers with low live blocks: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:19:39.355280 11048 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.001s	sys 0.000s
I20260812 06:19:39.355346 11048 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskQYaTMS/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515574268619-11048-0/minicluster-data/ts-0-root
uuid: "7d7eea69744f4e0f8eb3b84a1e8c8cb4"
format_stamp: "Formatted at 2026-08-12 06:19:39 on dist-test-slave-266d"
I20260812 06:19:39.355408 11048 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskQYaTMS/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515574268619-11048-0/minicluster-data/ts-0-root
metadata directory: /tmp/dist-test-taskQYaTMS/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515574268619-11048-0/minicluster-data/ts-0-root
1 data directories: /tmp/dist-test-taskQYaTMS/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515574268619-11048-0/minicluster-data/ts-0-root/data
Total live blocks: 0
Total live bytes: 0
Total live bytes (after alignment): 0
Total number of LBM containers: 0 (0 full)
Did not check for missing blocks
Did not check for orphaned blocks
Total full LBM containers with extra space: 0 (0 repaired)
Total full LBM container extra space in bytes: 0 (0 repaired)
Total incomplete LBM containers: 0 (0 repaired)
Total LBM partial records: 0 (0 repaired)
Total corrupted LBM metadata records in RocksDB: 0 (0 repaired)
I20260812 06:19:39.367139 11048 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:19:39.367417 11048 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:19:39.367658 11048 txn_system_client.cc:432] TxnSystemClient initialization is disabled...
I20260812 06:19:39.368067 11048 ts_tablet_manager.cc:585] Loaded tablet metadata (0 total tablets, 0 live tablets)
I20260812 06:19:39.368103 11048 ts_tablet_manager.cc:531] Time spent load tablet metadata: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:19:39.368144 11048 ts_tablet_manager.cc:616] Registered 0 tablets
I20260812 06:19:39.368170 11048 ts_tablet_manager.cc:595] Time spent register tablets: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:19:39.371996 11048 rpc_server.cc:307] RPC server started. Bound to: 127.10.202.1:43071
I20260812 06:19:39.372668 11682 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.10.202.1:43071 every 8 connection(s)
I20260812 06:19:39.379668 11683 heartbeater.cc:344] Connected to a master server at 127.10.202.62:44783
I20260812 06:19:39.379756 11683 heartbeater.cc:461] Registering TS with master...
I20260812 06:19:39.379954 11683 heartbeater.cc:507] Master 127.10.202.62:44783 requested a full tablet report, sending...
I20260812 06:19:39.380539 11449 ts_manager.cc:194] Registered new tserver with Master: 7d7eea69744f4e0f8eb3b84a1e8c8cb4 (127.10.202.1:43071)
I20260812 06:19:39.381338 11449 master_service.cc:502] Signed X509 certificate for tserver {username='slave'} at 127.0.0.1:37422
I20260812 06:19:39.381461 11048 internal_mini_cluster.cc:371] 1 TS(s) registered with all masters after 0.008726248s
I20260812 06:19:39.387717 11449 catalog_manager.cc:2283] Servicing CreateTable request from {username='slave'} at 127.0.0.1:37426:
name: "heavy-update-compaction-test"
schema {
  columns {
    name: "key"
    type: INT64
    is_key: true
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_a"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_b"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_c"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_d"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_e"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
}
num_replicas: 1
split_rows_range_bounds {
}
partition_schema {
  range_schema {
  }
}
I20260812 06:19:39.395346 11621 tablet_service.cc:1511] Processing CreateTablet for tablet d5863b19187242f7b7ffad98f0344693 (DEFAULT_TABLE table=heavy-update-compaction-test [id=fb98b24214454f57b8176ff6aa2b83c5]), partition=
I20260812 06:19:39.395582 11621 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet d5863b19187242f7b7ffad98f0344693. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:19:39.397372 11707 tablet_bootstrap.cc:492] T d5863b19187242f7b7ffad98f0344693 P 7d7eea69744f4e0f8eb3b84a1e8c8cb4: Bootstrap starting.
I20260812 06:19:39.398315 11707 tablet_bootstrap.cc:654] T d5863b19187242f7b7ffad98f0344693 P 7d7eea69744f4e0f8eb3b84a1e8c8cb4: Neither blocks nor log segments found. Creating new log.
I20260812 06:19:39.399209 11707 tablet_bootstrap.cc:492] T d5863b19187242f7b7ffad98f0344693 P 7d7eea69744f4e0f8eb3b84a1e8c8cb4: No bootstrap required, opened a new log
I20260812 06:19:39.399282 11707 ts_tablet_manager.cc:1403] T d5863b19187242f7b7ffad98f0344693 P 7d7eea69744f4e0f8eb3b84a1e8c8cb4: Time spent bootstrapping tablet: real 0.002s	user 0.001s	sys 0.000s
I20260812 06:19:39.399616 11707 raft_consensus.cc:359] T d5863b19187242f7b7ffad98f0344693 P 7d7eea69744f4e0f8eb3b84a1e8c8cb4 [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "7d7eea69744f4e0f8eb3b84a1e8c8cb4" member_type: VOTER last_known_addr { host: "127.10.202.1" port: 43071 } }
I20260812 06:19:39.399693 11707 raft_consensus.cc:385] T d5863b19187242f7b7ffad98f0344693 P 7d7eea69744f4e0f8eb3b84a1e8c8cb4 [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:19:39.399718 11707 raft_consensus.cc:740] T d5863b19187242f7b7ffad98f0344693 P 7d7eea69744f4e0f8eb3b84a1e8c8cb4 [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: 7d7eea69744f4e0f8eb3b84a1e8c8cb4, State: Initialized, Role: FOLLOWER
I20260812 06:19:39.399832 11707 consensus_queue.cc:260] T d5863b19187242f7b7ffad98f0344693 P 7d7eea69744f4e0f8eb3b84a1e8c8cb4 [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: "7d7eea69744f4e0f8eb3b84a1e8c8cb4" member_type: VOTER last_known_addr { host: "127.10.202.1" port: 43071 } }
I20260812 06:19:39.399891 11707 raft_consensus.cc:399] T d5863b19187242f7b7ffad98f0344693 P 7d7eea69744f4e0f8eb3b84a1e8c8cb4 [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:19:39.399919 11707 raft_consensus.cc:493] T d5863b19187242f7b7ffad98f0344693 P 7d7eea69744f4e0f8eb3b84a1e8c8cb4 [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:19:39.399950 11707 raft_consensus.cc:3060] T d5863b19187242f7b7ffad98f0344693 P 7d7eea69744f4e0f8eb3b84a1e8c8cb4 [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:19:39.400628 11707 raft_consensus.cc:515] T d5863b19187242f7b7ffad98f0344693 P 7d7eea69744f4e0f8eb3b84a1e8c8cb4 [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "7d7eea69744f4e0f8eb3b84a1e8c8cb4" member_type: VOTER last_known_addr { host: "127.10.202.1" port: 43071 } }
I20260812 06:19:39.400775 11707 leader_election.cc:304] T d5863b19187242f7b7ffad98f0344693 P 7d7eea69744f4e0f8eb3b84a1e8c8cb4 [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: 7d7eea69744f4e0f8eb3b84a1e8c8cb4; no voters: 
I20260812 06:19:39.400979 11707 leader_election.cc:290] T d5863b19187242f7b7ffad98f0344693 P 7d7eea69744f4e0f8eb3b84a1e8c8cb4 [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:19:39.401072 11711 raft_consensus.cc:2804] T d5863b19187242f7b7ffad98f0344693 P 7d7eea69744f4e0f8eb3b84a1e8c8cb4 [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:19:39.401302 11707 ts_tablet_manager.cc:1434] T d5863b19187242f7b7ffad98f0344693 P 7d7eea69744f4e0f8eb3b84a1e8c8cb4: Time spent starting tablet: real 0.002s	user 0.002s	sys 0.000s
I20260812 06:19:39.401350 11711 raft_consensus.cc:697] T d5863b19187242f7b7ffad98f0344693 P 7d7eea69744f4e0f8eb3b84a1e8c8cb4 [term 1 LEADER]: Becoming Leader. State: Replica: 7d7eea69744f4e0f8eb3b84a1e8c8cb4, State: Running, Role: LEADER
I20260812 06:19:39.401401 11683 heartbeater.cc:499] Master 127.10.202.62:44783 was elected leader, sending a full tablet report...
I20260812 06:19:39.401547 11711 consensus_queue.cc:237] T d5863b19187242f7b7ffad98f0344693 P 7d7eea69744f4e0f8eb3b84a1e8c8cb4 [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: "7d7eea69744f4e0f8eb3b84a1e8c8cb4" member_type: VOTER last_known_addr { host: "127.10.202.1" port: 43071 } }
I20260812 06:19:39.402741 11449 catalog_manager.cc:5719] T d5863b19187242f7b7ffad98f0344693 P 7d7eea69744f4e0f8eb3b84a1e8c8cb4 reported cstate change: term changed from 0 to 1, leader changed from <none> to 7d7eea69744f4e0f8eb3b84a1e8c8cb4 (127.10.202.1). New cstate: current_term: 1 leader_uuid: "7d7eea69744f4e0f8eb3b84a1e8c8cb4" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "7d7eea69744f4e0f8eb3b84a1e8c8cb4" member_type: VOTER last_known_addr { host: "127.10.202.1" port: 43071 } health_report { overall_health: HEALTHY } } }
I20260812 06:19:39.455055 11048 heavy-update-compaction-itest.cc:215] Time spent inserting: real 0.049s	user 0.014s	sys 0.008s
I20260812 06:19:39.623202 11684 maintenance_manager.cc:419] P 7d7eea69744f4e0f8eb3b84a1e8c8cb4: Scheduling FlushMRSOp(d5863b19187242f7b7ffad98f0344693): perf score=23.023690
I20260812 06:19:39.769516 11574 maintenance_manager.cc:643] P 7d7eea69744f4e0f8eb3b84a1e8c8cb4: FlushMRSOp(d5863b19187242f7b7ffad98f0344693) complete. Timing: real 0.146s	user 0.106s	sys 0.039s Metrics: {"bytes_written":12881835,"cfile_init":1,"delete_count":0,"dirs.queue_time_us":52,"dirs.run_cpu_time_us":194,"dirs.run_wall_time_us":780,"drs_written":1,"lbm_read_time_us":47,"lbm_reads_lt_1ms":4,"lbm_write_time_us":39185,"lbm_writes_lt_1ms":871,"peak_mem_usage":0,"reinsert_count":0,"rows_written":105,"spinlock_wait_cycles":12160,"update_count":1570}
I20260812 06:19:39.770164 11684 maintenance_manager.cc:419] P 7d7eea69744f4e0f8eb3b84a1e8c8cb4: Scheduling LogGCOp(d5863b19187242f7b7ffad98f0344693): free 20743880 bytes of WAL
I20260812 06:19:39.770403 11574 log_reader.cc:385] T d5863b19187242f7b7ffad98f0344693: removed 2 log segments from log reader
I20260812 06:19:39.770453 11574 log.cc:1079] T d5863b19187242f7b7ffad98f0344693 P 7d7eea69744f4e0f8eb3b84a1e8c8cb4: Deleting log segment in path: /tmp/dist-test-taskQYaTMS/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515574268619-11048-0/minicluster-data/ts-0-root/wals/d5863b19187242f7b7ffad98f0344693/wal-000000001 (ops 1-6)
I20260812 06:19:39.770484 11574 log.cc:1079] T d5863b19187242f7b7ffad98f0344693 P 7d7eea69744f4e0f8eb3b84a1e8c8cb4: Deleting log segment in path: /tmp/dist-test-taskQYaTMS/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515574268619-11048-0/minicluster-data/ts-0-root/wals/d5863b19187242f7b7ffad98f0344693/wal-000000002 (ops 7-11)
I20260812 06:19:39.774247 11574 maintenance_manager.cc:643] P 7d7eea69744f4e0f8eb3b84a1e8c8cb4: LogGCOp(d5863b19187242f7b7ffad98f0344693) complete. Timing: real 0.004s	user 0.000s	sys 0.003s Metrics: {}
I20260812 06:19:39.774550 11684 maintenance_manager.cc:419] P 7d7eea69744f4e0f8eb3b84a1e8c8cb4: Scheduling UndoDeltaBlockGCOp(d5863b19187242f7b7ffad98f0344693): 20513813 bytes on disk
I20260812 06:19:39.774899 11574 maintenance_manager.cc:643] P 7d7eea69744f4e0f8eb3b84a1e8c8cb4: UndoDeltaBlockGCOp(d5863b19187242f7b7ffad98f0344693) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":50,"lbm_reads_lt_1ms":4}
I20260812 06:19:39.775264 11684 maintenance_manager.cc:419] P 7d7eea69744f4e0f8eb3b84a1e8c8cb4: Scheduling FlushDeltaMemStoresOp(d5863b19187242f7b7ffad98f0344693): perf score=2.188937
I20260812 06:19:39.786345 11574 maintenance_manager.cc:643] P 7d7eea69744f4e0f8eb3b84a1e8c8cb4: FlushDeltaMemStoresOp(d5863b19187242f7b7ffad98f0344693) complete. Timing: real 0.011s	user 0.008s	sys 0.000s Metrics: {"bytes_written":3938559,"delete_count":0,"lbm_write_time_us":3375,"lbm_writes_lt_1ms":99,"reinsert_count":0,"update_count":480}
I20260812 06:19:39.786701 11684 maintenance_manager.cc:419] P 7d7eea69744f4e0f8eb3b84a1e8c8cb4: Scheduling FlushDeltaMemStoresOp(d5863b19187242f7b7ffad98f0344693): perf score=2.188937
I20260812 06:19:39.795279 11574 maintenance_manager.cc:643] P 7d7eea69744f4e0f8eb3b84a1e8c8cb4: FlushDeltaMemStoresOp(d5863b19187242f7b7ffad98f0344693) complete. Timing: real 0.008s	user 0.007s	sys 0.000s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3190,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:19:39.795673 11684 maintenance_manager.cc:419] P 7d7eea69744f4e0f8eb3b84a1e8c8cb4: Scheduling MajorDeltaCompactionOp(d5863b19187242f7b7ffad98f0344693): perf score=1.000000
I20260812 06:19:39.959620 11574 maintenance_manager.cc:643] P 7d7eea69744f4e0f8eb3b84a1e8c8cb4: MajorDeltaCompactionOp(d5863b19187242f7b7ffad98f0344693) complete. Timing: real 0.164s	user 0.104s	sys 0.051s Metrics: {"cfile_cache_miss":533,"cfile_cache_miss_bytes":24815794,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":481,"lbm_read_time_us":10666,"lbm_reads_lt_1ms":569,"lbm_write_time_us":29790,"lbm_writes_lt_1ms":543,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":3072,"thread_start_us":294,"threads_started":5,"update_count":2500}
I20260812 06:19:39.960130 11684 maintenance_manager.cc:419] P 7d7eea69744f4e0f8eb3b84a1e8c8cb4: Scheduling FlushDeltaMemStoresOp(d5863b19187242f7b7ffad98f0344693): perf score=14.095187
I20260812 06:19:40.012063 11574 maintenance_manager.cc:643] P 7d7eea69744f4e0f8eb3b84a1e8c8cb4: FlushDeltaMemStoresOp(d5863b19187242f7b7ffad98f0344693) complete. Timing: real 0.052s	user 0.020s	sys 0.017s Metrics: {"bytes_written":16409903,"delete_count":0,"lbm_write_time_us":17366,"lbm_writes_lt_1ms":403,"reinsert_count":0,"spinlock_wait_cycles":6400,"update_count":2000}
I20260812 06:19:40.012548 11684 maintenance_manager.cc:419] P 7d7eea69744f4e0f8eb3b84a1e8c8cb4: Scheduling FlushDeltaMemStoresOp(d5863b19187242f7b7ffad98f0344693): perf score=2.188937
I20260812 06:19:40.027091 11574 maintenance_manager.cc:643] P 7d7eea69744f4e0f8eb3b84a1e8c8cb4: FlushDeltaMemStoresOp(d5863b19187242f7b7ffad98f0344693) complete. Timing: real 0.014s	user 0.008s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5417,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:40.027554 11684 maintenance_manager.cc:419] P 7d7eea69744f4e0f8eb3b84a1e8c8cb4: Scheduling MajorDeltaCompactionOp(d5863b19187242f7b7ffad98f0344693): perf score=1.000000
I20260812 06:19:40.185413 11574 maintenance_manager.cc:643] P 7d7eea69744f4e0f8eb3b84a1e8c8cb4: MajorDeltaCompactionOp(d5863b19187242f7b7ffad98f0344693) complete. Timing: real 0.158s	user 0.114s	sys 0.040s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24815685,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":76,"lbm_read_time_us":8914,"lbm_reads_lt_1ms":564,"lbm_write_time_us":31406,"lbm_writes_lt_1ms":543,"mutex_wait_us":19,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":19072,"update_count":2500}
I20260812 06:19:40.186017 11684 maintenance_manager.cc:419] P 7d7eea69744f4e0f8eb3b84a1e8c8cb4: Scheduling FlushDeltaMemStoresOp(d5863b19187242f7b7ffad98f0344693): perf score=12.110812
I20260812 06:19:40.221570 11574 maintenance_manager.cc:643] P 7d7eea69744f4e0f8eb3b84a1e8c8cb4: FlushDeltaMemStoresOp(d5863b19187242f7b7ffad98f0344693) complete. Timing: real 0.035s	user 0.024s	sys 0.011s Metrics: {"bytes_written":13579242,"delete_count":0,"lbm_write_time_us":14649,"lbm_writes_lt_1ms":334,"reinsert_count":0,"update_count":1655}
I20260812 06:19:40.222179 11684 maintenance_manager.cc:419] P 7d7eea69744f4e0f8eb3b84a1e8c8cb4: Scheduling FlushDeltaMemStoresOp(d5863b19187242f7b7ffad98f0344693): perf score=2.188937
I20260812 06:19:40.232048 11574 maintenance_manager.cc:643] P 7d7eea69744f4e0f8eb3b84a1e8c8cb4: FlushDeltaMemStoresOp(d5863b19187242f7b7ffad98f0344693) complete. Timing: real 0.010s	user 0.008s	sys 0.000s Metrics: {"bytes_written":3241134,"delete_count":0,"lbm_write_time_us":3166,"lbm_writes_lt_1ms":82,"reinsert_count":0,"update_count":395}
I20260812 06:19:40.232467 11684 maintenance_manager.cc:419] P 7d7eea69744f4e0f8eb3b84a1e8c8cb4: Scheduling MajorDeltaCompactionOp(d5863b19187242f7b7ffad98f0344693): perf score=1.000000
I20260812 06:19:40.375710 11574 maintenance_manager.cc:643] P 7d7eea69744f4e0f8eb3b84a1e8c8cb4: MajorDeltaCompactionOp(d5863b19187242f7b7ffad98f0344693) complete. Timing: real 0.143s	user 0.088s	sys 0.052s Metrics: {"cfile_cache_miss":442,"cfile_cache_miss_bytes":21123499,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":124,"lbm_read_time_us":11418,"lbm_reads_lt_1ms":474,"lbm_write_time_us":20886,"lbm_writes_lt_1ms":453,"mutex_wait_us":25,"peak_mem_usage":51099678,"reinsert_count":0,"spinlock_wait_cycles":10112,"update_count":2050}
I20260812 06:19:40.376446 11684 maintenance_manager.cc:419] P 7d7eea69744f4e0f8eb3b84a1e8c8cb4: Scheduling FlushDeltaMemStoresOp(d5863b19187242f7b7ffad98f0344693): perf score=14.095187
I20260812 06:19:40.428464 11574 maintenance_manager.cc:643] P 7d7eea69744f4e0f8eb3b84a1e8c8cb4: FlushDeltaMemStoresOp(d5863b19187242f7b7ffad98f0344693) complete. Timing: real 0.052s	user 0.022s	sys 0.027s Metrics: {"bytes_written":15999662,"delete_count":0,"lbm_write_time_us":22277,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":392,"reinsert_count":0,"update_count":1950}
I20260812 06:19:40.429008 11684 maintenance_manager.cc:419] P 7d7eea69744f4e0f8eb3b84a1e8c8cb4: Scheduling FlushDeltaMemStoresOp(d5863b19187242f7b7ffad98f0344693): perf score=2.188937
I20260812 06:19:40.448020 11574 maintenance_manager.cc:643] P 7d7eea69744f4e0f8eb3b84a1e8c8cb4: FlushDeltaMemStoresOp(d5863b19187242f7b7ffad98f0344693) complete. Timing: real 0.019s	user 0.012s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5462,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:40.448451 11684 maintenance_manager.cc:419] P 7d7eea69744f4e0f8eb3b84a1e8c8cb4: Scheduling MajorDeltaCompactionOp(d5863b19187242f7b7ffad98f0344693): perf score=1.000000
I20260812 06:19:40.638015 11574 maintenance_manager.cc:643] P 7d7eea69744f4e0f8eb3b84a1e8c8cb4: MajorDeltaCompactionOp(d5863b19187242f7b7ffad98f0344693) complete. Timing: real 0.189s	user 0.150s	sys 0.040s Metrics: {"cfile_cache_miss":522,"cfile_cache_miss_bytes":24405444,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":111,"lbm_read_time_us":14871,"lbm_reads_lt_1ms":562,"lbm_write_time_us":30693,"lbm_writes_lt_1ms":533,"mutex_wait_us":23,"peak_mem_usage":61665166,"reinsert_count":0,"spinlock_wait_cycles":41984,"update_count":2450}
I20260812 06:19:40.638530 11684 maintenance_manager.cc:419] P 7d7eea69744f4e0f8eb3b84a1e8c8cb4: Scheduling FlushDeltaMemStoresOp(d5863b19187242f7b7ffad98f0344693): perf score=14.095187
I20260812 06:19:40.685959 11574 maintenance_manager.cc:643] P 7d7eea69744f4e0f8eb3b84a1e8c8cb4: FlushDeltaMemStoresOp(d5863b19187242f7b7ffad98f0344693) complete. Timing: real 0.047s	user 0.036s	sys 0.010s Metrics: {"bytes_written":16409900,"delete_count":0,"lbm_write_time_us":21224,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:40.686451 11684 maintenance_manager.cc:419] P 7d7eea69744f4e0f8eb3b84a1e8c8cb4: Scheduling FlushDeltaMemStoresOp(d5863b19187242f7b7ffad98f0344693): perf score=2.188937
I20260812 06:19:40.697538 11574 maintenance_manager.cc:643] P 7d7eea69744f4e0f8eb3b84a1e8c8cb4: FlushDeltaMemStoresOp(d5863b19187242f7b7ffad98f0344693) complete. Timing: real 0.011s	user 0.006s	sys 0.005s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4118,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:40.698027 11684 maintenance_manager.cc:419] P 7d7eea69744f4e0f8eb3b84a1e8c8cb4: Scheduling MajorDeltaCompactionOp(d5863b19187242f7b7ffad98f0344693): perf score=1.000000
I20260812 06:19:40.858278 11574 maintenance_manager.cc:643] P 7d7eea69744f4e0f8eb3b84a1e8c8cb4: MajorDeltaCompactionOp(d5863b19187242f7b7ffad98f0344693) complete. Timing: real 0.160s	user 0.115s	sys 0.036s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24815682,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":531,"lbm_read_time_us":10896,"lbm_reads_lt_1ms":572,"lbm_write_time_us":29797,"lbm_writes_lt_1ms":543,"mutex_wait_us":238,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":9216,"update_count":2500}
I20260812 06:19:40.858791 11684 maintenance_manager.cc:419] P 7d7eea69744f4e0f8eb3b84a1e8c8cb4: Scheduling FlushDeltaMemStoresOp(d5863b19187242f7b7ffad98f0344693): perf score=14.095187
I20260812 06:19:40.901659 11574 maintenance_manager.cc:643] P 7d7eea69744f4e0f8eb3b84a1e8c8cb4: FlushDeltaMemStoresOp(d5863b19187242f7b7ffad98f0344693) complete. Timing: real 0.043s	user 0.031s	sys 0.007s Metrics: {"bytes_written":16409900,"delete_count":0,"lbm_write_time_us":16828,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:40.902161 11684 maintenance_manager.cc:419] P 7d7eea69744f4e0f8eb3b84a1e8c8cb4: Scheduling FlushDeltaMemStoresOp(d5863b19187242f7b7ffad98f0344693): perf score=2.188937
I20260812 06:19:40.912020 11574 maintenance_manager.cc:643] P 7d7eea69744f4e0f8eb3b84a1e8c8cb4: FlushDeltaMemStoresOp(d5863b19187242f7b7ffad98f0344693) complete. Timing: real 0.010s	user 0.008s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3636,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:40.912580 11684 maintenance_manager.cc:419] P 7d7eea69744f4e0f8eb3b84a1e8c8cb4: Scheduling FlushMRSOp(d5863b19187242f7b7ffad98f0344693): perf score=1.000000
I20260812 06:19:40.943270 11574 maintenance_manager.cc:643] P 7d7eea69744f4e0f8eb3b84a1e8c8cb4: FlushMRSOp(d5863b19187242f7b7ffad98f0344693) complete. Timing: real 0.030s	user 0.029s	sys 0.000s Metrics: {"bytes_written":1193503,"cfile_init":1,"dirs.queue_time_us":57,"dirs.run_cpu_time_us":238,"dirs.run_wall_time_us":1287,"drs_written":1,"lbm_read_time_us":42,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1474,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":29}
I20260812 06:19:40.943812 11684 maintenance_manager.cc:419] P 7d7eea69744f4e0f8eb3b84a1e8c8cb4: Scheduling LogGCOp(d5863b19187242f7b7ffad98f0344693): free 120553325 bytes of WAL
I20260812 06:19:40.944010 11574 log_reader.cc:385] T d5863b19187242f7b7ffad98f0344693: removed 12 log segments from log reader
I20260812 06:19:40.944057 11574 log.cc:1079] T d5863b19187242f7b7ffad98f0344693 P 7d7eea69744f4e0f8eb3b84a1e8c8cb4: Deleting log segment in path: /tmp/dist-test-taskQYaTMS/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515574268619-11048-0/minicluster-data/ts-0-root/wals/d5863b19187242f7b7ffad98f0344693/wal-000000003 (ops 12-16)
I20260812 06:19:40.944085 11574 log.cc:1079] T d5863b19187242f7b7ffad98f0344693 P 7d7eea69744f4e0f8eb3b84a1e8c8cb4: Deleting log segment in path: /tmp/dist-test-taskQYaTMS/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515574268619-11048-0/minicluster-data/ts-0-root/wals/d5863b19187242f7b7ffad98f0344693/wal-000000004 (ops 17-21)
I20260812 06:19:40.944118 11574 log.cc:1079] T d5863b19187242f7b7ffad98f0344693 P 7d7eea69744f4e0f8eb3b84a1e8c8cb4: Deleting log segment in path: /tmp/dist-test-taskQYaTMS/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515574268619-11048-0/minicluster-data/ts-0-root/wals/d5863b19187242f7b7ffad98f0344693/wal-000000005 (ops 22-26)
I20260812 06:19:40.944150 11574 log.cc:1079] T d5863b19187242f7b7ffad98f0344693 P 7d7eea69744f4e0f8eb3b84a1e8c8cb4: Deleting log segment in path: /tmp/dist-test-taskQYaTMS/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515574268619-11048-0/minicluster-data/ts-0-root/wals/d5863b19187242f7b7ffad98f0344693/wal-000000006 (ops 27-30)
I20260812 06:19:40.944172 11574 log.cc:1079] T d5863b19187242f7b7ffad98f0344693 P 7d7eea69744f4e0f8eb3b84a1e8c8cb4: Deleting log segment in path: /tmp/dist-test-taskQYaTMS/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515574268619-11048-0/minicluster-data/ts-0-root/wals/d5863b19187242f7b7ffad98f0344693/wal-000000007 (ops 31-35)
I20260812 06:19:40.944202 11574 log.cc:1079] T d5863b19187242f7b7ffad98f0344693 P 7d7eea69744f4e0f8eb3b84a1e8c8cb4: Deleting log segment in path: /tmp/dist-test-taskQYaTMS/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515574268619-11048-0/minicluster-data/ts-0-root/wals/d5863b19187242f7b7ffad98f0344693/wal-000000008 (ops 36-40)
I20260812 06:19:40.944234 11574 log.cc:1079] T d5863b19187242f7b7ffad98f0344693 P 7d7eea69744f4e0f8eb3b84a1e8c8cb4: Deleting log segment in path: /tmp/dist-test-taskQYaTMS/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515574268619-11048-0/minicluster-data/ts-0-root/wals/d5863b19187242f7b7ffad98f0344693/wal-000000009 (ops 41-45)
I20260812 06:19:40.944272 11574 log.cc:1079] T d5863b19187242f7b7ffad98f0344693 P 7d7eea69744f4e0f8eb3b84a1e8c8cb4: Deleting log segment in path: /tmp/dist-test-taskQYaTMS/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515574268619-11048-0/minicluster-data/ts-0-root/wals/d5863b19187242f7b7ffad98f0344693/wal-000000010 (ops 46-50)
I20260812 06:19:40.944304 11574 log.cc:1079] T d5863b19187242f7b7ffad98f0344693 P 7d7eea69744f4e0f8eb3b84a1e8c8cb4: Deleting log segment in path: /tmp/dist-test-taskQYaTMS/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515574268619-11048-0/minicluster-data/ts-0-root/wals/d5863b19187242f7b7ffad98f0344693/wal-000000011 (ops 51-55)
I20260812 06:19:40.944337 11574 log.cc:1079] T d5863b19187242f7b7ffad98f0344693 P 7d7eea69744f4e0f8eb3b84a1e8c8cb4: Deleting log segment in path: /tmp/dist-test-taskQYaTMS/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515574268619-11048-0/minicluster-data/ts-0-root/wals/d5863b19187242f7b7ffad98f0344693/wal-000000012 (ops 56-60)
I20260812 06:19:40.944368 11574 log.cc:1079] T d5863b19187242f7b7ffad98f0344693 P 7d7eea69744f4e0f8eb3b84a1e8c8cb4: Deleting log segment in path: /tmp/dist-test-taskQYaTMS/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515574268619-11048-0/minicluster-data/ts-0-root/wals/d5863b19187242f7b7ffad98f0344693/wal-000000013 (ops 61-64)
I20260812 06:19:40.944401 11574 log.cc:1079] T d5863b19187242f7b7ffad98f0344693 P 7d7eea69744f4e0f8eb3b84a1e8c8cb4: Deleting log segment in path: /tmp/dist-test-taskQYaTMS/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515574268619-11048-0/minicluster-data/ts-0-root/wals/d5863b19187242f7b7ffad98f0344693/wal-000000014 (ops 65-69)
I20260812 06:19:40.964324 11574 maintenance_manager.cc:643] P 7d7eea69744f4e0f8eb3b84a1e8c8cb4: LogGCOp(d5863b19187242f7b7ffad98f0344693) complete. Timing: real 0.020s	user 0.000s	sys 0.017s Metrics: {}
I20260812 06:19:40.964771 11684 maintenance_manager.cc:419] P 7d7eea69744f4e0f8eb3b84a1e8c8cb4: Scheduling UndoDeltaBlockGCOp(d5863b19187242f7b7ffad98f0344693): 462 bytes on disk
I20260812 06:19:40.965200 11574 maintenance_manager.cc:643] P 7d7eea69744f4e0f8eb3b84a1e8c8cb4: UndoDeltaBlockGCOp(d5863b19187242f7b7ffad98f0344693) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":65,"lbm_reads_lt_1ms":4}
I20260812 06:19:40.965646 11684 maintenance_manager.cc:419] P 7d7eea69744f4e0f8eb3b84a1e8c8cb4: Scheduling FlushDeltaMemStoresOp(d5863b19187242f7b7ffad98f0344693): perf score=3.181125
I20260812 06:19:40.987286 11574 maintenance_manager.cc:643] P 7d7eea69744f4e0f8eb3b84a1e8c8cb4: FlushDeltaMemStoresOp(d5863b19187242f7b7ffad98f0344693) complete. Timing: real 0.022s	user 0.008s	sys 0.010s Metrics: {"bytes_written":4512900,"delete_count":0,"lbm_write_time_us":3799,"lbm_writes_lt_1ms":113,"reinsert_count":0,"update_count":550}
I20260812 06:19:40.987641 11684 maintenance_manager.cc:419] P 7d7eea69744f4e0f8eb3b84a1e8c8cb4: Scheduling FlushDeltaMemStoresOp(d5863b19187242f7b7ffad98f0344693): perf score=2.188937
I20260812 06:19:41.000674 11574 maintenance_manager.cc:643] P 7d7eea69744f4e0f8eb3b84a1e8c8cb4: FlushDeltaMemStoresOp(d5863b19187242f7b7ffad98f0344693) complete. Timing: real 0.013s	user 0.011s	sys 0.000s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":4899,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:19:41.001057 11684 maintenance_manager.cc:419] P 7d7eea69744f4e0f8eb3b84a1e8c8cb4: Scheduling MajorDeltaCompactionOp(d5863b19187242f7b7ffad98f0344693): perf score=1.000000
I20260812 06:19:41.219902 11574 maintenance_manager.cc:643] P 7d7eea69744f4e0f8eb3b84a1e8c8cb4: MajorDeltaCompactionOp(d5863b19187242f7b7ffad98f0344693) complete. Timing: real 0.219s	user 0.135s	sys 0.080s Metrics: {"cfile_cache_miss":734,"cfile_cache_miss_bytes":33020731,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":1164,"lbm_read_time_us":15444,"lbm_reads_lt_1ms":774,"lbm_write_time_us":34824,"lbm_writes_lt_1ms":743,"mutex_wait_us":708,"peak_mem_usage":87969044,"reinsert_count":0,"spinlock_wait_cycles":19712,"thread_start_us":97,"threads_started":1,"update_count":3500}
I20260812 06:19:41.220433 11684 maintenance_manager.cc:419] P 7d7eea69744f4e0f8eb3b84a1e8c8cb4: Scheduling FlushDeltaMemStoresOp(d5863b19187242f7b7ffad98f0344693): perf score=15.087375
I20260812 06:19:41.267923 11574 maintenance_manager.cc:643] P 7d7eea69744f4e0f8eb3b84a1e8c8cb4: FlushDeltaMemStoresOp(d5863b19187242f7b7ffad98f0344693) complete. Timing: real 0.047s	user 0.020s	sys 0.025s Metrics: {"bytes_written":16820143,"delete_count":0,"lbm_write_time_us":21338,"lbm_writes_lt_1ms":413,"reinsert_count":0,"update_count":2050}
I20260812 06:19:41.268318 11684 maintenance_manager.cc:419] P 7d7eea69744f4e0f8eb3b84a1e8c8cb4: Scheduling FlushDeltaMemStoresOp(d5863b19187242f7b7ffad98f0344693): perf score=2.188937
I20260812 06:19:41.293032 11574 maintenance_manager.cc:643] P 7d7eea69744f4e0f8eb3b84a1e8c8cb4: FlushDeltaMemStoresOp(d5863b19187242f7b7ffad98f0344693) complete. Timing: real 0.025s	user 0.007s	sys 0.003s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4972,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:41.293478 11684 maintenance_manager.cc:419] P 7d7eea69744f4e0f8eb3b84a1e8c8cb4: Scheduling FlushDeltaMemStoresOp(d5863b19187242f7b7ffad98f0344693): perf score=2.188937
I20260812 06:19:41.305874 11574 maintenance_manager.cc:643] P 7d7eea69744f4e0f8eb3b84a1e8c8cb4: FlushDeltaMemStoresOp(d5863b19187242f7b7ffad98f0344693) complete. Timing: real 0.012s	user 0.002s	sys 0.009s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":4740,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:19:41.306244 11684 maintenance_manager.cc:419] P 7d7eea69744f4e0f8eb3b84a1e8c8cb4: Scheduling MajorDeltaCompactionOp(d5863b19187242f7b7ffad98f0344693): perf score=1.000000
I20260812 06:19:41.493649 11574 maintenance_manager.cc:643] P 7d7eea69744f4e0f8eb3b84a1e8c8cb4: MajorDeltaCompactionOp(d5863b19187242f7b7ffad98f0344693) complete. Timing: real 0.187s	user 0.122s	sys 0.065s Metrics: {"cfile_cache_miss":633,"cfile_cache_miss_bytes":28918202,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":258,"lbm_read_time_us":13552,"lbm_reads_lt_1ms":673,"lbm_write_time_us":29096,"lbm_writes_lt_1ms":643,"mutex_wait_us":39,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":1792,"update_count":3000}
I20260812 06:19:41.494192 11684 maintenance_manager.cc:419] P 7d7eea69744f4e0f8eb3b84a1e8c8cb4: Scheduling FlushDeltaMemStoresOp(d5863b19187242f7b7ffad98f0344693): perf score=14.095187
I20260812 06:19:41.542187 11574 maintenance_manager.cc:643] P 7d7eea69744f4e0f8eb3b84a1e8c8cb4: FlushDeltaMemStoresOp(d5863b19187242f7b7ffad98f0344693) complete. Timing: real 0.048s	user 0.031s	sys 0.016s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":21366,"lbm_writes_lt_1ms":403,"reinsert_count":0,"spinlock_wait_cycles":2304,"update_count":2000}
I20260812 06:19:41.542667 11684 maintenance_manager.cc:419] P 7d7eea69744f4e0f8eb3b84a1e8c8cb4: Scheduling FlushDeltaMemStoresOp(d5863b19187242f7b7ffad98f0344693): perf score=2.188937
I20260812 06:19:41.553180 11574 maintenance_manager.cc:643] P 7d7eea69744f4e0f8eb3b84a1e8c8cb4: FlushDeltaMemStoresOp(d5863b19187242f7b7ffad98f0344693) complete. Timing: real 0.010s	user 0.006s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3708,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:41.553618 11684 maintenance_manager.cc:419] P 7d7eea69744f4e0f8eb3b84a1e8c8cb4: Scheduling MajorDeltaCompactionOp(d5863b19187242f7b7ffad98f0344693): perf score=1.000000
I20260812 06:19:41.713403 11574 maintenance_manager.cc:643] P 7d7eea69744f4e0f8eb3b84a1e8c8cb4: MajorDeltaCompactionOp(d5863b19187242f7b7ffad98f0344693) complete. Timing: real 0.160s	user 0.114s	sys 0.043s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24815683,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":88,"lbm_read_time_us":11488,"lbm_reads_lt_1ms":572,"lbm_write_time_us":26241,"lbm_writes_lt_1ms":543,"mutex_wait_us":17,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":15616,"update_count":2500}
I20260812 06:19:41.713878 11684 maintenance_manager.cc:419] P 7d7eea69744f4e0f8eb3b84a1e8c8cb4: Scheduling FlushDeltaMemStoresOp(d5863b19187242f7b7ffad98f0344693): perf score=14.095187
I20260812 06:19:41.768337 11574 maintenance_manager.cc:643] P 7d7eea69744f4e0f8eb3b84a1e8c8cb4: FlushDeltaMemStoresOp(d5863b19187242f7b7ffad98f0344693) complete. Timing: real 0.054s	user 0.032s	sys 0.013s Metrics: {"bytes_written":16409903,"delete_count":0,"lbm_write_time_us":20011,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:41.768815 11684 maintenance_manager.cc:419] P 7d7eea69744f4e0f8eb3b84a1e8c8cb4: Scheduling FlushDeltaMemStoresOp(d5863b19187242f7b7ffad98f0344693): perf score=2.188937
I20260812 06:19:41.778828 11574 maintenance_manager.cc:643] P 7d7eea69744f4e0f8eb3b84a1e8c8cb4: FlushDeltaMemStoresOp(d5863b19187242f7b7ffad98f0344693) complete. Timing: real 0.010s	user 0.005s	sys 0.003s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3819,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:41.781160 11684 maintenance_manager.cc:419] P 7d7eea69744f4e0f8eb3b84a1e8c8cb4: Scheduling MajorDeltaCompactionOp(d5863b19187242f7b7ffad98f0344693): perf score=1.000000
I20260812 06:19:41.958604 11574 maintenance_manager.cc:643] P 7d7eea69744f4e0f8eb3b84a1e8c8cb4: MajorDeltaCompactionOp(d5863b19187242f7b7ffad98f0344693) complete. Timing: real 0.177s	user 0.140s	sys 0.037s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24815685,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":376,"lbm_read_time_us":11529,"lbm_reads_lt_1ms":572,"lbm_write_time_us":31552,"lbm_writes_lt_1ms":543,"mutex_wait_us":27,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":19968,"update_count":2500}
I20260812 06:19:41.959103 11684 maintenance_manager.cc:419] P 7d7eea69744f4e0f8eb3b84a1e8c8cb4: Scheduling FlushDeltaMemStoresOp(d5863b19187242f7b7ffad98f0344693): perf score=14.095187
I20260812 06:19:42.019209 11574 maintenance_manager.cc:643] P 7d7eea69744f4e0f8eb3b84a1e8c8cb4: FlushDeltaMemStoresOp(d5863b19187242f7b7ffad98f0344693) complete. Timing: real 0.060s	user 0.030s	sys 0.027s Metrics: {"bytes_written":16409904,"delete_count":0,"lbm_write_time_us":22359,"lbm_writes_lt_1ms":403,"mutex_wait_us":3,"reinsert_count":0,"update_count":2000}
I20260812 06:19:42.019843 11684 maintenance_manager.cc:419] P 7d7eea69744f4e0f8eb3b84a1e8c8cb4: Scheduling FlushDeltaMemStoresOp(d5863b19187242f7b7ffad98f0344693): perf score=2.188937
I20260812 06:19:42.031997 11574 maintenance_manager.cc:643] P 7d7eea69744f4e0f8eb3b84a1e8c8cb4: FlushDeltaMemStoresOp(d5863b19187242f7b7ffad98f0344693) complete. Timing: real 0.012s	user 0.007s	sys 0.003s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4822,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:42.032574 11684 maintenance_manager.cc:419] P 7d7eea69744f4e0f8eb3b84a1e8c8cb4: Scheduling MajorDeltaCompactionOp(d5863b19187242f7b7ffad98f0344693): perf score=1.000000
I20260812 06:19:42.217342 11574 maintenance_manager.cc:643] P 7d7eea69744f4e0f8eb3b84a1e8c8cb4: MajorDeltaCompactionOp(d5863b19187242f7b7ffad98f0344693) complete. Timing: real 0.185s	user 0.138s	sys 0.040s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24815685,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":94,"lbm_read_time_us":12706,"lbm_reads_lt_1ms":572,"lbm_write_time_us":29990,"lbm_writes_lt_1ms":543,"mutex_wait_us":38,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":896,"update_count":2500}
I20260812 06:19:42.217985 11684 maintenance_manager.cc:419] P 7d7eea69744f4e0f8eb3b84a1e8c8cb4: Scheduling FlushDeltaMemStoresOp(d5863b19187242f7b7ffad98f0344693): perf score=14.095187
I20260812 06:19:42.272421 11574 maintenance_manager.cc:643] P 7d7eea69744f4e0f8eb3b84a1e8c8cb4: FlushDeltaMemStoresOp(d5863b19187242f7b7ffad98f0344693) complete. Timing: real 0.054s	user 0.035s	sys 0.015s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":21102,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:42.272943 11684 maintenance_manager.cc:419] P 7d7eea69744f4e0f8eb3b84a1e8c8cb4: Scheduling FlushDeltaMemStoresOp(d5863b19187242f7b7ffad98f0344693): perf score=2.188937
I20260812 06:19:42.292974 11574 maintenance_manager.cc:643] P 7d7eea69744f4e0f8eb3b84a1e8c8cb4: FlushDeltaMemStoresOp(d5863b19187242f7b7ffad98f0344693) complete. Timing: real 0.020s	user 0.006s	sys 0.005s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4610,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:42.293603 11684 maintenance_manager.cc:419] P 7d7eea69744f4e0f8eb3b84a1e8c8cb4: Scheduling FlushMRSOp(d5863b19187242f7b7ffad98f0344693): perf score=1.000000
I20260812 06:19:42.336140 11574 maintenance_manager.cc:643] P 7d7eea69744f4e0f8eb3b84a1e8c8cb4: FlushMRSOp(d5863b19187242f7b7ffad98f0344693) complete. Timing: real 0.042s	user 0.021s	sys 0.004s Metrics: {"bytes_written":1193509,"cfile_init":1,"dirs.queue_time_us":66,"dirs.run_cpu_time_us":328,"dirs.run_wall_time_us":1285,"drs_written":1,"lbm_read_time_us":48,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1628,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":29}
I20260812 06:19:42.336930 11684 maintenance_manager.cc:419] P 7d7eea69744f4e0f8eb3b84a1e8c8cb4: Scheduling UndoDeltaBlockGCOp(d5863b19187242f7b7ffad98f0344693): 462 bytes on disk
I20260812 06:19:42.337502 11574 maintenance_manager.cc:643] P 7d7eea69744f4e0f8eb3b84a1e8c8cb4: UndoDeltaBlockGCOp(d5863b19187242f7b7ffad98f0344693) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":66,"lbm_reads_lt_1ms":4}
I20260812 06:19:42.338186 11684 maintenance_manager.cc:419] P 7d7eea69744f4e0f8eb3b84a1e8c8cb4: Scheduling FlushDeltaMemStoresOp(d5863b19187242f7b7ffad98f0344693): perf score=3.181125
I20260812 06:19:42.357555 11574 maintenance_manager.cc:643] P 7d7eea69744f4e0f8eb3b84a1e8c8cb4: FlushDeltaMemStoresOp(d5863b19187242f7b7ffad98f0344693) complete. Timing: real 0.019s	user 0.008s	sys 0.008s Metrics: {"bytes_written":4512899,"delete_count":0,"lbm_write_time_us":6376,"lbm_writes_lt_1ms":113,"reinsert_count":0,"update_count":550}
I20260812 06:19:42.358013 11684 maintenance_manager.cc:419] P 7d7eea69744f4e0f8eb3b84a1e8c8cb4: Scheduling LogGCOp(d5863b19187242f7b7ffad98f0344693): free 120100379 bytes of WAL
I20260812 06:19:42.358234 11574 log_reader.cc:385] T d5863b19187242f7b7ffad98f0344693: removed 12 log segments from log reader
I20260812 06:19:42.358286 11574 log.cc:1079] T d5863b19187242f7b7ffad98f0344693 P 7d7eea69744f4e0f8eb3b84a1e8c8cb4: Deleting log segment in path: /tmp/dist-test-taskQYaTMS/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515574268619-11048-0/minicluster-data/ts-0-root/wals/d5863b19187242f7b7ffad98f0344693/wal-000000015 (ops 70-74)
I20260812 06:19:42.358338 11574 log.cc:1079] T d5863b19187242f7b7ffad98f0344693 P 7d7eea69744f4e0f8eb3b84a1e8c8cb4: Deleting log segment in path: /tmp/dist-test-taskQYaTMS/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515574268619-11048-0/minicluster-data/ts-0-root/wals/d5863b19187242f7b7ffad98f0344693/wal-000000016 (ops 75-79)
I20260812 06:19:42.358377 11574 log.cc:1079] T d5863b19187242f7b7ffad98f0344693 P 7d7eea69744f4e0f8eb3b84a1e8c8cb4: Deleting log segment in path: /tmp/dist-test-taskQYaTMS/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515574268619-11048-0/minicluster-data/ts-0-root/wals/d5863b19187242f7b7ffad98f0344693/wal-000000017 (ops 80-84)
I20260812 06:19:42.358414 11574 log.cc:1079] T d5863b19187242f7b7ffad98f0344693 P 7d7eea69744f4e0f8eb3b84a1e8c8cb4: Deleting log segment in path: /tmp/dist-test-taskQYaTMS/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515574268619-11048-0/minicluster-data/ts-0-root/wals/d5863b19187242f7b7ffad98f0344693/wal-000000018 (ops 85-89)
I20260812 06:19:42.358451 11574 log.cc:1079] T d5863b19187242f7b7ffad98f0344693 P 7d7eea69744f4e0f8eb3b84a1e8c8cb4: Deleting log segment in path: /tmp/dist-test-taskQYaTMS/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515574268619-11048-0/minicluster-data/ts-0-root/wals/d5863b19187242f7b7ffad98f0344693/wal-000000019 (ops 90-94)
I20260812 06:19:42.358490 11574 log.cc:1079] T d5863b19187242f7b7ffad98f0344693 P 7d7eea69744f4e0f8eb3b84a1e8c8cb4: Deleting log segment in path: /tmp/dist-test-taskQYaTMS/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515574268619-11048-0/minicluster-data/ts-0-root/wals/d5863b19187242f7b7ffad98f0344693/wal-000000020 (ops 95-98)
I20260812 06:19:42.358525 11574 log.cc:1079] T d5863b19187242f7b7ffad98f0344693 P 7d7eea69744f4e0f8eb3b84a1e8c8cb4: Deleting log segment in path: /tmp/dist-test-taskQYaTMS/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515574268619-11048-0/minicluster-data/ts-0-root/wals/d5863b19187242f7b7ffad98f0344693/wal-000000021 (ops 99-103)
I20260812 06:19:42.358562 11574 log.cc:1079] T d5863b19187242f7b7ffad98f0344693 P 7d7eea69744f4e0f8eb3b84a1e8c8cb4: Deleting log segment in path: /tmp/dist-test-taskQYaTMS/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515574268619-11048-0/minicluster-data/ts-0-root/wals/d5863b19187242f7b7ffad98f0344693/wal-000000022 (ops 104-108)
I20260812 06:19:42.358598 11574 log.cc:1079] T d5863b19187242f7b7ffad98f0344693 P 7d7eea69744f4e0f8eb3b84a1e8c8cb4: Deleting log segment in path: /tmp/dist-test-taskQYaTMS/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515574268619-11048-0/minicluster-data/ts-0-root/wals/d5863b19187242f7b7ffad98f0344693/wal-000000023 (ops 109-112)
I20260812 06:19:42.358637 11574 log.cc:1079] T d5863b19187242f7b7ffad98f0344693 P 7d7eea69744f4e0f8eb3b84a1e8c8cb4: Deleting log segment in path: /tmp/dist-test-taskQYaTMS/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515574268619-11048-0/minicluster-data/ts-0-root/wals/d5863b19187242f7b7ffad98f0344693/wal-000000024 (ops 113-117)
I20260812 06:19:42.358673 11574 log.cc:1079] T d5863b19187242f7b7ffad98f0344693 P 7d7eea69744f4e0f8eb3b84a1e8c8cb4: Deleting log segment in path: /tmp/dist-test-taskQYaTMS/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515574268619-11048-0/minicluster-data/ts-0-root/wals/d5863b19187242f7b7ffad98f0344693/wal-000000025 (ops 118-122)
I20260812 06:19:42.358709 11574 log.cc:1079] T d5863b19187242f7b7ffad98f0344693 P 7d7eea69744f4e0f8eb3b84a1e8c8cb4: Deleting log segment in path: /tmp/dist-test-taskQYaTMS/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515574268619-11048-0/minicluster-data/ts-0-root/wals/d5863b19187242f7b7ffad98f0344693/wal-000000026 (ops 123-126)
I20260812 06:19:42.384711 11574 maintenance_manager.cc:643] P 7d7eea69744f4e0f8eb3b84a1e8c8cb4: LogGCOp(d5863b19187242f7b7ffad98f0344693) complete. Timing: real 0.027s	user 0.000s	sys 0.023s Metrics: {}
I20260812 06:19:42.385154 11684 maintenance_manager.cc:419] P 7d7eea69744f4e0f8eb3b84a1e8c8cb4: Scheduling FlushDeltaMemStoresOp(d5863b19187242f7b7ffad98f0344693): perf score=2.188937
I20260812 06:19:42.408260 11574 maintenance_manager.cc:643] P 7d7eea69744f4e0f8eb3b84a1e8c8cb4: FlushDeltaMemStoresOp(d5863b19187242f7b7ffad98f0344693) complete. Timing: real 0.023s	user 0.008s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5537,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:42.408788 11684 maintenance_manager.cc:419] P 7d7eea69744f4e0f8eb3b84a1e8c8cb4: Scheduling FlushDeltaMemStoresOp(d5863b19187242f7b7ffad98f0344693): perf score=2.188937
I20260812 06:19:42.418992 11574 maintenance_manager.cc:643] P 7d7eea69744f4e0f8eb3b84a1e8c8cb4: FlushDeltaMemStoresOp(d5863b19187242f7b7ffad98f0344693) complete. Timing: real 0.010s	user 0.006s	sys 0.003s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3746,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:19:42.419507 11684 maintenance_manager.cc:419] P 7d7eea69744f4e0f8eb3b84a1e8c8cb4: Scheduling MajorDeltaCompactionOp(d5863b19187242f7b7ffad98f0344693): perf score=1.000000
I20260812 06:19:42.652674 11574 maintenance_manager.cc:643] P 7d7eea69744f4e0f8eb3b84a1e8c8cb4: MajorDeltaCompactionOp(d5863b19187242f7b7ffad98f0344693) complete. Timing: real 0.233s	user 0.156s	sys 0.076s Metrics: {"cfile_cache_miss":835,"cfile_cache_miss_bytes":37123261,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":5,"delta_iterators_relevant":5,"dirs.queue_time_us":982,"lbm_read_time_us":16760,"lbm_reads_lt_1ms":875,"lbm_write_time_us":40040,"lbm_writes_lt_1ms":843,"mutex_wait_us":657,"peak_mem_usage":100395616,"reinsert_count":0,"spinlock_wait_cycles":10368,"thread_start_us":79,"threads_started":1,"update_count":4000}
I20260812 06:19:42.654860 11684 maintenance_manager.cc:419] P 7d7eea69744f4e0f8eb3b84a1e8c8cb4: Scheduling FlushDeltaMemStoresOp(d5863b19187242f7b7ffad98f0344693): perf score=18.063937
I20260812 06:19:42.729851 11574 maintenance_manager.cc:643] P 7d7eea69744f4e0f8eb3b84a1e8c8cb4: FlushDeltaMemStoresOp(d5863b19187242f7b7ffad98f0344693) complete. Timing: real 0.075s	user 0.041s	sys 0.033s Metrics: {"bytes_written":20512318,"delete_count":0,"lbm_write_time_us":34806,"lbm_writes_1-10_ms":3,"lbm_writes_lt_1ms":500,"reinsert_count":0,"update_count":2500}
I20260812 06:19:42.730370 11684 maintenance_manager.cc:419] P 7d7eea69744f4e0f8eb3b84a1e8c8cb4: Scheduling FlushDeltaMemStoresOp(d5863b19187242f7b7ffad98f0344693): perf score=6.157687
I20260812 06:19:42.753280 11574 maintenance_manager.cc:643] P 7d7eea69744f4e0f8eb3b84a1e8c8cb4: FlushDeltaMemStoresOp(d5863b19187242f7b7ffad98f0344693) complete. Timing: real 0.023s	user 0.016s	sys 0.005s Metrics: {"bytes_written":8205078,"delete_count":0,"lbm_write_time_us":8682,"lbm_writes_lt_1ms":203,"reinsert_count":0,"update_count":1000}
I20260812 06:19:42.753749 11684 maintenance_manager.cc:419] P 7d7eea69744f4e0f8eb3b84a1e8c8cb4: Scheduling MajorDeltaCompactionOp(d5863b19187242f7b7ffad98f0344693): perf score=1.000000
I20260812 06:19:42.939152 11574 maintenance_manager.cc:643] P 7d7eea69744f4e0f8eb3b84a1e8c8cb4: MajorDeltaCompactionOp(d5863b19187242f7b7ffad98f0344693) complete. Timing: real 0.185s	user 0.146s	sys 0.037s Metrics: {"cfile_cache_miss":732,"cfile_cache_miss_bytes":33020513,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":241,"lbm_read_time_us":16202,"lbm_reads_lt_1ms":764,"lbm_write_time_us":33524,"lbm_writes_lt_1ms":743,"mutex_wait_us":24,"peak_mem_usage":87969044,"reinsert_count":0,"spinlock_wait_cycles":42368,"update_count":3500}
I20260812 06:19:42.939729 11684 maintenance_manager.cc:419] P 7d7eea69744f4e0f8eb3b84a1e8c8cb4: Scheduling FlushDeltaMemStoresOp(d5863b19187242f7b7ffad98f0344693): perf score=15.087375
I20260812 06:19:42.998986 11574 maintenance_manager.cc:643] P 7d7eea69744f4e0f8eb3b84a1e8c8cb4: FlushDeltaMemStoresOp(d5863b19187242f7b7ffad98f0344693) complete. Timing: real 0.059s	user 0.035s	sys 0.008s Metrics: {"bytes_written":16820142,"delete_count":0,"lbm_write_time_us":19697,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":412,"reinsert_count":0,"update_count":2050}
I20260812 06:19:42.999514 11684 maintenance_manager.cc:419] P 7d7eea69744f4e0f8eb3b84a1e8c8cb4: Scheduling FlushDeltaMemStoresOp(d5863b19187242f7b7ffad98f0344693): perf score=6.157687
I20260812 06:19:43.026407 11574 maintenance_manager.cc:643] P 7d7eea69744f4e0f8eb3b84a1e8c8cb4: FlushDeltaMemStoresOp(d5863b19187242f7b7ffad98f0344693) complete. Timing: real 0.027s	user 0.013s	sys 0.008s Metrics: {"bytes_written":7794836,"delete_count":0,"lbm_write_time_us":9510,"lbm_writes_lt_1ms":193,"reinsert_count":0,"update_count":950}
I20260812 06:19:43.026926 11684 maintenance_manager.cc:419] P 7d7eea69744f4e0f8eb3b84a1e8c8cb4: Scheduling MajorDeltaCompactionOp(d5863b19187242f7b7ffad98f0344693): perf score=1.000000
I20260812 06:19:43.194546 11574 maintenance_manager.cc:643] P 7d7eea69744f4e0f8eb3b84a1e8c8cb4: MajorDeltaCompactionOp(d5863b19187242f7b7ffad98f0344693) complete. Timing: real 0.167s	user 0.129s	sys 0.035s Metrics: {"cfile_cache_miss":632,"cfile_cache_miss_bytes":28918095,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":239,"lbm_read_time_us":12167,"lbm_reads_lt_1ms":664,"lbm_write_time_us":33873,"lbm_writes_lt_1ms":643,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":1408,"update_count":3000}
I20260812 06:19:43.195165 11684 maintenance_manager.cc:419] P 7d7eea69744f4e0f8eb3b84a1e8c8cb4: Scheduling FlushDeltaMemStoresOp(d5863b19187242f7b7ffad98f0344693): perf score=15.087375
I20260812 06:19:43.230893 11574 maintenance_manager.cc:643] P 7d7eea69744f4e0f8eb3b84a1e8c8cb4: FlushDeltaMemStoresOp(d5863b19187242f7b7ffad98f0344693) complete. Timing: real 0.036s	user 0.017s	sys 0.017s Metrics: {"bytes_written":16820142,"delete_count":0,"lbm_write_time_us":15355,"lbm_writes_lt_1ms":413,"reinsert_count":0,"update_count":2050}
I20260812 06:19:43.231618 11684 maintenance_manager.cc:419] P 7d7eea69744f4e0f8eb3b84a1e8c8cb4: Scheduling FlushDeltaMemStoresOp(d5863b19187242f7b7ffad98f0344693): perf score=2.188937
I20260812 06:19:43.251910 11574 maintenance_manager.cc:643] P 7d7eea69744f4e0f8eb3b84a1e8c8cb4: FlushDeltaMemStoresOp(d5863b19187242f7b7ffad98f0344693) complete. Timing: real 0.020s	user 0.011s	sys 0.004s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":6047,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:19:43.252481 11684 maintenance_manager.cc:419] P 7d7eea69744f4e0f8eb3b84a1e8c8cb4: Scheduling MajorDeltaCompactionOp(d5863b19187242f7b7ffad98f0344693): perf score=1.000000
I20260812 06:19:43.401773 11574 maintenance_manager.cc:643] P 7d7eea69744f4e0f8eb3b84a1e8c8cb4: MajorDeltaCompactionOp(d5863b19187242f7b7ffad98f0344693) complete. Timing: real 0.149s	user 0.105s	sys 0.039s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24815670,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":114,"lbm_read_time_us":9433,"lbm_reads_lt_1ms":564,"lbm_write_time_us":25821,"lbm_writes_lt_1ms":543,"mutex_wait_us":22,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":35456,"update_count":2500}
I20260812 06:19:43.402392 11684 maintenance_manager.cc:419] P 7d7eea69744f4e0f8eb3b84a1e8c8cb4: Scheduling FlushDeltaMemStoresOp(d5863b19187242f7b7ffad98f0344693): perf score=14.095187
I20260812 06:19:43.441623 11574 maintenance_manager.cc:643] P 7d7eea69744f4e0f8eb3b84a1e8c8cb4: FlushDeltaMemStoresOp(d5863b19187242f7b7ffad98f0344693) complete. Timing: real 0.039s	user 0.027s	sys 0.012s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":17562,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:43.442091 11684 maintenance_manager.cc:419] P 7d7eea69744f4e0f8eb3b84a1e8c8cb4: Scheduling MajorDeltaCompactionOp(d5863b19187242f7b7ffad98f0344693): perf score=1.000000
I20260812 06:19:43.576800 11574 maintenance_manager.cc:643] P 7d7eea69744f4e0f8eb3b84a1e8c8cb4: MajorDeltaCompactionOp(d5863b19187242f7b7ffad98f0344693) complete. Timing: real 0.135s	user 0.102s	sys 0.033s Metrics: {"cfile_cache_miss":431,"cfile_cache_miss_bytes":20713153,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":1,"delta_iterators_relevant":1,"dirs.queue_time_us":178,"lbm_read_time_us":8669,"lbm_reads_lt_1ms":467,"lbm_write_time_us":23549,"lbm_writes_lt_1ms":443,"mutex_wait_us":27,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":8960,"update_count":2000}
I20260812 06:19:43.577694 11684 maintenance_manager.cc:419] P 7d7eea69744f4e0f8eb3b84a1e8c8cb4: Scheduling FlushDeltaMemStoresOp(d5863b19187242f7b7ffad98f0344693): perf score=10.126437
I20260812 06:19:43.606731 11574 maintenance_manager.cc:643] P 7d7eea69744f4e0f8eb3b84a1e8c8cb4: FlushDeltaMemStoresOp(d5863b19187242f7b7ffad98f0344693) complete. Timing: real 0.029s	user 0.016s	sys 0.012s Metrics: {"bytes_written":12307491,"delete_count":0,"lbm_write_time_us":12273,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:19:43.607251 11684 maintenance_manager.cc:419] P 7d7eea69744f4e0f8eb3b84a1e8c8cb4: Scheduling FlushDeltaMemStoresOp(d5863b19187242f7b7ffad98f0344693): perf score=2.188937
I20260812 06:19:43.619336 11574 maintenance_manager.cc:643] P 7d7eea69744f4e0f8eb3b84a1e8c8cb4: FlushDeltaMemStoresOp(d5863b19187242f7b7ffad98f0344693) complete. Timing: real 0.012s	user 0.002s	sys 0.008s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4316,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:43.619938 11684 maintenance_manager.cc:419] P 7d7eea69744f4e0f8eb3b84a1e8c8cb4: Scheduling FlushMRSOp(d5863b19187242f7b7ffad98f0344693): perf score=1.000000
I20260812 06:19:43.648967 11574 maintenance_manager.cc:643] P 7d7eea69744f4e0f8eb3b84a1e8c8cb4: FlushMRSOp(d5863b19187242f7b7ffad98f0344693) complete. Timing: real 0.029s	user 0.024s	sys 0.003s Metrics: {"bytes_written":1193505,"cfile_init":1,"dirs.queue_time_us":51,"dirs.run_cpu_time_us":220,"dirs.run_wall_time_us":1171,"drs_written":1,"lbm_read_time_us":45,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1423,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":29}
I20260812 06:19:43.649600 11684 maintenance_manager.cc:419] P 7d7eea69744f4e0f8eb3b84a1e8c8cb4: Scheduling LogGCOp(d5863b19187242f7b7ffad98f0344693): free 120553628 bytes of WAL
I20260812 06:19:43.649819 11574 log_reader.cc:385] T d5863b19187242f7b7ffad98f0344693: removed 12 log segments from log reader
I20260812 06:19:43.649863 11574 log.cc:1079] T d5863b19187242f7b7ffad98f0344693 P 7d7eea69744f4e0f8eb3b84a1e8c8cb4: Deleting log segment in path: /tmp/dist-test-taskQYaTMS/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515574268619-11048-0/minicluster-data/ts-0-root/wals/d5863b19187242f7b7ffad98f0344693/wal-000000027 (ops 127-131)
I20260812 06:19:43.649892 11574 log.cc:1079] T d5863b19187242f7b7ffad98f0344693 P 7d7eea69744f4e0f8eb3b84a1e8c8cb4: Deleting log segment in path: /tmp/dist-test-taskQYaTMS/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515574268619-11048-0/minicluster-data/ts-0-root/wals/d5863b19187242f7b7ffad98f0344693/wal-000000028 (ops 132-136)
I20260812 06:19:43.649922 11574 log.cc:1079] T d5863b19187242f7b7ffad98f0344693 P 7d7eea69744f4e0f8eb3b84a1e8c8cb4: Deleting log segment in path: /tmp/dist-test-taskQYaTMS/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515574268619-11048-0/minicluster-data/ts-0-root/wals/d5863b19187242f7b7ffad98f0344693/wal-000000029 (ops 137-141)
I20260812 06:19:43.649947 11574 log.cc:1079] T d5863b19187242f7b7ffad98f0344693 P 7d7eea69744f4e0f8eb3b84a1e8c8cb4: Deleting log segment in path: /tmp/dist-test-taskQYaTMS/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515574268619-11048-0/minicluster-data/ts-0-root/wals/d5863b19187242f7b7ffad98f0344693/wal-000000030 (ops 142-146)
I20260812 06:19:43.649979 11574 log.cc:1079] T d5863b19187242f7b7ffad98f0344693 P 7d7eea69744f4e0f8eb3b84a1e8c8cb4: Deleting log segment in path: /tmp/dist-test-taskQYaTMS/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515574268619-11048-0/minicluster-data/ts-0-root/wals/d5863b19187242f7b7ffad98f0344693/wal-000000031 (ops 147-150)
I20260812 06:19:43.650002 11574 log.cc:1079] T d5863b19187242f7b7ffad98f0344693 P 7d7eea69744f4e0f8eb3b84a1e8c8cb4: Deleting log segment in path: /tmp/dist-test-taskQYaTMS/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515574268619-11048-0/minicluster-data/ts-0-root/wals/d5863b19187242f7b7ffad98f0344693/wal-000000032 (ops 151-155)
I20260812 06:19:43.650033 11574 log.cc:1079] T d5863b19187242f7b7ffad98f0344693 P 7d7eea69744f4e0f8eb3b84a1e8c8cb4: Deleting log segment in path: /tmp/dist-test-taskQYaTMS/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515574268619-11048-0/minicluster-data/ts-0-root/wals/d5863b19187242f7b7ffad98f0344693/wal-000000033 (ops 156-160)
I20260812 06:19:43.650063 11574 log.cc:1079] T d5863b19187242f7b7ffad98f0344693 P 7d7eea69744f4e0f8eb3b84a1e8c8cb4: Deleting log segment in path: /tmp/dist-test-taskQYaTMS/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515574268619-11048-0/minicluster-data/ts-0-root/wals/d5863b19187242f7b7ffad98f0344693/wal-000000034 (ops 161-164)
I20260812 06:19:43.650102 11574 log.cc:1079] T d5863b19187242f7b7ffad98f0344693 P 7d7eea69744f4e0f8eb3b84a1e8c8cb4: Deleting log segment in path: /tmp/dist-test-taskQYaTMS/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515574268619-11048-0/minicluster-data/ts-0-root/wals/d5863b19187242f7b7ffad98f0344693/wal-000000035 (ops 165-169)
I20260812 06:19:43.650131 11574 log.cc:1079] T d5863b19187242f7b7ffad98f0344693 P 7d7eea69744f4e0f8eb3b84a1e8c8cb4: Deleting log segment in path: /tmp/dist-test-taskQYaTMS/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515574268619-11048-0/minicluster-data/ts-0-root/wals/d5863b19187242f7b7ffad98f0344693/wal-000000036 (ops 170-174)
I20260812 06:19:43.650161 11574 log.cc:1079] T d5863b19187242f7b7ffad98f0344693 P 7d7eea69744f4e0f8eb3b84a1e8c8cb4: Deleting log segment in path: /tmp/dist-test-taskQYaTMS/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515574268619-11048-0/minicluster-data/ts-0-root/wals/d5863b19187242f7b7ffad98f0344693/wal-000000037 (ops 175-179)
I20260812 06:19:43.650192 11574 log.cc:1079] T d5863b19187242f7b7ffad98f0344693 P 7d7eea69744f4e0f8eb3b84a1e8c8cb4: Deleting log segment in path: /tmp/dist-test-taskQYaTMS/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515574268619-11048-0/minicluster-data/ts-0-root/wals/d5863b19187242f7b7ffad98f0344693/wal-000000038 (ops 180-184)
I20260812 06:19:43.671983 11574 maintenance_manager.cc:643] P 7d7eea69744f4e0f8eb3b84a1e8c8cb4: LogGCOp(d5863b19187242f7b7ffad98f0344693) complete. Timing: real 0.022s	user 0.000s	sys 0.019s Metrics: {}
I20260812 06:19:43.672484 11684 maintenance_manager.cc:419] P 7d7eea69744f4e0f8eb3b84a1e8c8cb4: Scheduling FlushDeltaMemStoresOp(d5863b19187242f7b7ffad98f0344693): perf score=4.173312
I20260812 06:19:43.688916 11574 maintenance_manager.cc:643] P 7d7eea69744f4e0f8eb3b84a1e8c8cb4: FlushDeltaMemStoresOp(d5863b19187242f7b7ffad98f0344693) complete. Timing: real 0.016s	user 0.014s	sys 0.000s Metrics: {"bytes_written":5743633,"delete_count":0,"lbm_write_time_us":6790,"lbm_writes_lt_1ms":143,"reinsert_count":0,"update_count":700}
I20260812 06:19:43.689349 11684 maintenance_manager.cc:419] P 7d7eea69744f4e0f8eb3b84a1e8c8cb4: Scheduling FlushDeltaMemStoresOp(d5863b19187242f7b7ffad98f0344693): perf score=1.196750
I20260812 06:19:43.696100 11574 maintenance_manager.cc:643] P 7d7eea69744f4e0f8eb3b84a1e8c8cb4: FlushDeltaMemStoresOp(d5863b19187242f7b7ffad98f0344693) complete. Timing: real 0.007s	user 0.004s	sys 0.001s Metrics: {"bytes_written":2461654,"delete_count":0,"lbm_write_time_us":2372,"lbm_writes_lt_1ms":63,"reinsert_count":0,"update_count":300}
I20260812 06:19:43.696466 11684 maintenance_manager.cc:419] P 7d7eea69744f4e0f8eb3b84a1e8c8cb4: Scheduling UndoDeltaBlockGCOp(d5863b19187242f7b7ffad98f0344693): 462 bytes on disk
I20260812 06:19:43.696930 11574 maintenance_manager.cc:643] P 7d7eea69744f4e0f8eb3b84a1e8c8cb4: UndoDeltaBlockGCOp(d5863b19187242f7b7ffad98f0344693) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":72,"lbm_reads_lt_1ms":4}
I20260812 06:19:43.697463 11684 maintenance_manager.cc:419] P 7d7eea69744f4e0f8eb3b84a1e8c8cb4: Scheduling MajorDeltaCompactionOp(d5863b19187242f7b7ffad98f0344693): perf score=1.000000
I20260812 06:19:43.901950 11574 maintenance_manager.cc:643] P 7d7eea69744f4e0f8eb3b84a1e8c8cb4: MajorDeltaCompactionOp(d5863b19187242f7b7ffad98f0344693) complete. Timing: real 0.204s	user 0.125s	sys 0.079s Metrics: {"cfile_cache_miss":634,"cfile_cache_miss_bytes":28918297,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":179,"lbm_read_time_us":14052,"lbm_reads_lt_1ms":674,"lbm_write_time_us":35757,"lbm_writes_lt_1ms":643,"mutex_wait_us":35,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":11008,"thread_start_us":63,"threads_started":1,"update_count":3000}
I20260812 06:19:43.905540 11684 maintenance_manager.cc:419] P 7d7eea69744f4e0f8eb3b84a1e8c8cb4: Scheduling FlushDeltaMemStoresOp(d5863b19187242f7b7ffad98f0344693): perf score=14.095187
I20260812 06:19:43.976495 11574 maintenance_manager.cc:643] P 7d7eea69744f4e0f8eb3b84a1e8c8cb4: FlushDeltaMemStoresOp(d5863b19187242f7b7ffad98f0344693) complete. Timing: real 0.071s	user 0.038s	sys 0.012s Metrics: {"bytes_written":16409903,"delete_count":0,"lbm_write_time_us":31363,"lbm_writes_10-100_ms":1,"lbm_writes_lt_1ms":402,"reinsert_count":0,"update_count":2000}
I20260812 06:19:43.977159 11684 maintenance_manager.cc:419] P 7d7eea69744f4e0f8eb3b84a1e8c8cb4: Scheduling FlushDeltaMemStoresOp(d5863b19187242f7b7ffad98f0344693): perf score=2.188937
I20260812 06:19:43.992153 11574 maintenance_manager.cc:643] P 7d7eea69744f4e0f8eb3b84a1e8c8cb4: FlushDeltaMemStoresOp(d5863b19187242f7b7ffad98f0344693) complete. Timing: real 0.015s	user 0.008s	sys 0.004s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":5697,"lbm_writes_lt_1ms":103,"reinsert_count":0,"spinlock_wait_cycles":896,"update_count":500}
I20260812 06:19:43.992537 11684 maintenance_manager.cc:419] P 7d7eea69744f4e0f8eb3b84a1e8c8cb4: Scheduling MajorDeltaCompactionOp(d5863b19187242f7b7ffad98f0344693): perf score=1.000000
I20260812 06:19:44.061455 11048 heavy-update-compaction-itest.cc:229] Time spent updating: real 4.606s	user 1.672s	sys 0.124s
I20260812 06:19:44.122195 11048 heavy-update-compaction-itest.cc:265] Time spent scanning: real 0.060s	user 0.001s	sys 0.000s
I20260812 06:19:44.122654 11048 tablet_server.cc:179] TabletServer@127.10.202.1:0 shutting down...
I20260812 06:19:44.143220 11574 maintenance_manager.cc:643] P 7d7eea69744f4e0f8eb3b84a1e8c8cb4: MajorDeltaCompactionOp(d5863b19187242f7b7ffad98f0344693) complete. Timing: real 0.151s	user 0.099s	sys 0.052s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24815684,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":206,"lbm_read_time_us":9609,"lbm_reads_lt_1ms":564,"lbm_write_time_us":24685,"lbm_writes_lt_1ms":543,"mutex_wait_us":55,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":768,"update_count":2500}
I20260812 06:19:44.143846 11048 ts_tablet_manager.cc:1507] Shutting down tablet manager...
I20260812 06:19:44.144073 11048 tablet_replica.cc:333] T d5863b19187242f7b7ffad98f0344693 P 7d7eea69744f4e0f8eb3b84a1e8c8cb4: stopping tablet replica
I20260812 06:19:44.144196 11048 raft_consensus.cc:2243] T d5863b19187242f7b7ffad98f0344693 P 7d7eea69744f4e0f8eb3b84a1e8c8cb4 [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:19:44.144352 11048 raft_consensus.cc:2272] T d5863b19187242f7b7ffad98f0344693 P 7d7eea69744f4e0f8eb3b84a1e8c8cb4 [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:19:44.149616 11048 tablet_server.cc:196] TabletServer@127.10.202.1:0 shutdown complete.
I20260812 06:19:44.188040 11048 master.cc:562] Master@127.10.202.62:44783 shutting down...
I20260812 06:19:44.190940 11048 raft_consensus.cc:2243] T 00000000000000000000000000000000 P 9908857d41a54a03833395d917805fb1 [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:19:44.191097 11048 raft_consensus.cc:2272] T 00000000000000000000000000000000 P 9908857d41a54a03833395d917805fb1 [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:19:44.191145 11048 tablet_replica.cc:333] T 00000000000000000000000000000000 P 9908857d41a54a03833395d917805fb1: stopping tablet replica
I20260812 06:19:44.203016 11048 master.cc:584] Master@127.10.202.62:44783 shutdown complete.
[       OK ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/1 (4991 ms)
[----------] 2 tests from EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy (9997 ms total)

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