[==========] Running 2 tests from 1 test suite.
[----------] Global test environment set-up.
[----------] 2 tests from EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy
[ RUN      ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/0
WARNING: Logging before InitGoogleLogging() is written to STDERR
I20260812 06:17:27.732627 31279 internal_mini_cluster.cc:156] Creating distributed mini masters. Addrs: 127.30.139.254:39755
I20260812 06:17:27.733553 31279 env_posix.cc:2285] Not raising this process' open files per process limit of 1048576; it is already as high as it can go
I20260812 06:17:27.734138 31279 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:17:27.739996 31287 instance_detector.cc:116] could not retrieve Azure instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:17:27.740101 31290 instance_detector.cc:116] could not retrieve OpenStack instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:17:27.740183 31279 server_base.cc:1061] running on GCE node
W20260812 06:17:27.740248 31285 instance_detector.cc:116] could not retrieve AWS instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:17:27.740684 31279 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:17:27.740788 31279 system_unsync_time.cc:38] NTP support is disabled. Clock error bounds will not be accurate. This configuration is not suitable for distributed clusters.
I20260812 06:17:27.740828 31279 hybrid_clock.cc:648] HybridClock initialized: now 1786515447740826 us; error 0 us; skew 500 ppm
I20260812 06:17:27.742424 31279 webserver.cc:533] Webserver started at http://127.30.139.254:32769/ using document root <none> and password file <none>
I20260812 06:17:27.742915 31279 fs_manager.cc:362] Metadata directory not provided
I20260812 06:17:27.742973 31279 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:17:27.743175 31279 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:17:27.744709 31279 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskNVEfdO/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515447722411-31279-0/minicluster-data/master-0-root/instance:
uuid: "6e6dbd9b2099484b927b2b6e2a180360"
format_stamp: "Formatted at 2026-08-12 06:17:27 on dist-test-slave-cvwc"
I20260812 06:17:27.747881 31279 fs_manager.cc:696] Time spent creating directory manager: real 0.003s	user 0.001s	sys 0.004s
I20260812 06:17:27.749650 31298 log_block_manager.cc:4127] Time spent loading block containers with low live blocks: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:17:27.750618 31279 fs_manager.cc:730] Time spent opening block manager: real 0.002s	user 0.002s	sys 0.000s
I20260812 06:17:27.750718 31279 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskNVEfdO/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515447722411-31279-0/minicluster-data/master-0-root
uuid: "6e6dbd9b2099484b927b2b6e2a180360"
format_stamp: "Formatted at 2026-08-12 06:17:27 on dist-test-slave-cvwc"
I20260812 06:17:27.750808 31279 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskNVEfdO/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515447722411-31279-0/minicluster-data/master-0-root
metadata directory: /tmp/dist-test-taskNVEfdO/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515447722411-31279-0/minicluster-data/master-0-root
1 data directories: /tmp/dist-test-taskNVEfdO/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515447722411-31279-0/minicluster-data/master-0-root/data
Total live blocks: 0
Total live bytes: 0
Total live bytes (after alignment): 0
Total number of LBM containers: 0 (0 full)
Did not check for missing blocks
Did not check for orphaned blocks
Total full LBM containers with extra space: 0 (0 repaired)
Total full LBM container extra space in bytes: 0 (0 repaired)
Total incomplete LBM containers: 0 (0 repaired)
Total LBM partial records: 0 (0 repaired)
Total corrupted LBM metadata records in RocksDB: 0 (0 repaired)
I20260812 06:17:27.767040 31279 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:17:27.767635 31279 env_posix.cc:2285] Not raising this process' running threads per effective uid limit of 18446744073709551615; it is already as high as it can go
I20260812 06:17:27.767795 31279 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:17:27.774895 31279 rpc_server.cc:307] RPC server started. Bound to: 127.30.139.254:39755
I20260812 06:17:27.774976 31379 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.30.139.254:39755 every 8 connection(s)
I20260812 06:17:27.777148 31380 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet 00000000000000000000000000000000. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:17:27.782560 31380 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P 6e6dbd9b2099484b927b2b6e2a180360: Bootstrap starting.
I20260812 06:17:27.784891 31380 tablet_bootstrap.cc:654] T 00000000000000000000000000000000 P 6e6dbd9b2099484b927b2b6e2a180360: Neither blocks nor log segments found. Creating new log.
I20260812 06:17:27.785768 31380 log.cc:826] T 00000000000000000000000000000000 P 6e6dbd9b2099484b927b2b6e2a180360: Log is configured to *not* fsync() on all Append() calls
I20260812 06:17:27.787343 31380 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P 6e6dbd9b2099484b927b2b6e2a180360: No bootstrap required, opened a new log
I20260812 06:17:27.790032 31380 raft_consensus.cc:359] T 00000000000000000000000000000000 P 6e6dbd9b2099484b927b2b6e2a180360 [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "6e6dbd9b2099484b927b2b6e2a180360" member_type: VOTER }
I20260812 06:17:27.790191 31380 raft_consensus.cc:385] T 00000000000000000000000000000000 P 6e6dbd9b2099484b927b2b6e2a180360 [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:17:27.790230 31380 raft_consensus.cc:740] T 00000000000000000000000000000000 P 6e6dbd9b2099484b927b2b6e2a180360 [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: 6e6dbd9b2099484b927b2b6e2a180360, State: Initialized, Role: FOLLOWER
I20260812 06:17:27.790783 31380 consensus_queue.cc:260] T 00000000000000000000000000000000 P 6e6dbd9b2099484b927b2b6e2a180360 [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: "6e6dbd9b2099484b927b2b6e2a180360" member_type: VOTER }
I20260812 06:17:27.790926 31380 raft_consensus.cc:399] T 00000000000000000000000000000000 P 6e6dbd9b2099484b927b2b6e2a180360 [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:17:27.790971 31380 raft_consensus.cc:493] T 00000000000000000000000000000000 P 6e6dbd9b2099484b927b2b6e2a180360 [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:17:27.791056 31380 raft_consensus.cc:3060] T 00000000000000000000000000000000 P 6e6dbd9b2099484b927b2b6e2a180360 [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:17:27.791754 31380 raft_consensus.cc:515] T 00000000000000000000000000000000 P 6e6dbd9b2099484b927b2b6e2a180360 [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "6e6dbd9b2099484b927b2b6e2a180360" member_type: VOTER }
I20260812 06:17:27.792125 31380 leader_election.cc:304] T 00000000000000000000000000000000 P 6e6dbd9b2099484b927b2b6e2a180360 [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: 6e6dbd9b2099484b927b2b6e2a180360; no voters: 
I20260812 06:17:27.792378 31380 leader_election.cc:290] T 00000000000000000000000000000000 P 6e6dbd9b2099484b927b2b6e2a180360 [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:17:27.792505 31387 raft_consensus.cc:2804] T 00000000000000000000000000000000 P 6e6dbd9b2099484b927b2b6e2a180360 [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:17:27.792721 31387 raft_consensus.cc:697] T 00000000000000000000000000000000 P 6e6dbd9b2099484b927b2b6e2a180360 [term 1 LEADER]: Becoming Leader. State: Replica: 6e6dbd9b2099484b927b2b6e2a180360, State: Running, Role: LEADER
I20260812 06:17:27.793066 31387 consensus_queue.cc:237] T 00000000000000000000000000000000 P 6e6dbd9b2099484b927b2b6e2a180360 [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: "6e6dbd9b2099484b927b2b6e2a180360" member_type: VOTER }
I20260812 06:17:27.793267 31380 sys_catalog.cc:565] T 00000000000000000000000000000000 P 6e6dbd9b2099484b927b2b6e2a180360 [sys.catalog]: configured and running, proceeding with master startup.
I20260812 06:17:27.794822 31389 sys_catalog.cc:455] T 00000000000000000000000000000000 P 6e6dbd9b2099484b927b2b6e2a180360 [sys.catalog]: SysCatalogTable state changed. Reason: RaftConsensus started. Latest consensus state: current_term: 1 leader_uuid: "6e6dbd9b2099484b927b2b6e2a180360" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "6e6dbd9b2099484b927b2b6e2a180360" member_type: VOTER } }
I20260812 06:17:27.794986 31389 sys_catalog.cc:458] T 00000000000000000000000000000000 P 6e6dbd9b2099484b927b2b6e2a180360 [sys.catalog]: This master's current role is: LEADER
I20260812 06:17:27.794859 31390 sys_catalog.cc:455] T 00000000000000000000000000000000 P 6e6dbd9b2099484b927b2b6e2a180360 [sys.catalog]: SysCatalogTable state changed. Reason: New leader 6e6dbd9b2099484b927b2b6e2a180360. Latest consensus state: current_term: 1 leader_uuid: "6e6dbd9b2099484b927b2b6e2a180360" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "6e6dbd9b2099484b927b2b6e2a180360" member_type: VOTER } }
I20260812 06:17:27.795212 31390 sys_catalog.cc:458] T 00000000000000000000000000000000 P 6e6dbd9b2099484b927b2b6e2a180360 [sys.catalog]: This master's current role is: LEADER
I20260812 06:17:27.795284 31406 catalog_manager.cc:1511] Loading table and tablet metadata into memory...
I20260812 06:17:27.795469 31279 internal_mini_cluster.cc:184] Waiting to initialize catalog manager on master 0
I20260812 06:17:27.797366 31406 catalog_manager.cc:1520] Initializing Kudu cluster ID...
I20260812 06:17:27.801980 31406 catalog_manager.cc:1383] Generated new cluster ID: 5f55997f1c7f4a85808bf179edede3a2
I20260812 06:17:27.802031 31406 catalog_manager.cc:1531] Initializing Kudu internal certificate authority...
I20260812 06:17:27.820890 31406 catalog_manager.cc:1406] Generated new certificate authority record
I20260812 06:17:27.821669 31406 catalog_manager.cc:1540] Loading token signing keys...
I20260812 06:17:27.827527 31406 catalog_manager.cc:6092] T 00000000000000000000000000000000 P 6e6dbd9b2099484b927b2b6e2a180360: Generated new TSK 0
I20260812 06:17:27.828055 31406 catalog_manager.cc:1550] Initializing in-progress tserver states...
I20260812 06:17:27.860107 31279 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:17:27.862700 31416 instance_detector.cc:116] could not retrieve Azure instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:17:27.862716 31415 instance_detector.cc:116] could not retrieve AWS instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:17:27.862867 31419 instance_detector.cc:116] could not retrieve OpenStack instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:17:27.863020 31279 server_base.cc:1061] running on GCE node
I20260812 06:17:27.863246 31279 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:17:27.863289 31279 system_unsync_time.cc:38] NTP support is disabled. Clock error bounds will not be accurate. This configuration is not suitable for distributed clusters.
I20260812 06:17:27.863307 31279 hybrid_clock.cc:648] HybridClock initialized: now 1786515447863308 us; error 0 us; skew 500 ppm
I20260812 06:17:27.864111 31279 webserver.cc:533] Webserver started at http://127.30.139.193:45249/ using document root <none> and password file <none>
I20260812 06:17:27.864269 31279 fs_manager.cc:362] Metadata directory not provided
I20260812 06:17:27.864316 31279 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:17:27.864389 31279 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:17:27.864749 31279 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskNVEfdO/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515447722411-31279-0/minicluster-data/ts-0-root/instance:
uuid: "f5fdf36185874a7a8cb879c56f869891"
format_stamp: "Formatted at 2026-08-12 06:17:27 on dist-test-slave-cvwc"
I20260812 06:17:27.866483 31279 fs_manager.cc:696] Time spent creating directory manager: real 0.002s	user 0.000s	sys 0.002s
I20260812 06:17:27.867440 31428 log_block_manager.cc:4127] Time spent loading block containers with low live blocks: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:17:27.867683 31279 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.000s	sys 0.000s
I20260812 06:17:27.867751 31279 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskNVEfdO/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515447722411-31279-0/minicluster-data/ts-0-root
uuid: "f5fdf36185874a7a8cb879c56f869891"
format_stamp: "Formatted at 2026-08-12 06:17:27 on dist-test-slave-cvwc"
I20260812 06:17:27.867849 31279 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskNVEfdO/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515447722411-31279-0/minicluster-data/ts-0-root
metadata directory: /tmp/dist-test-taskNVEfdO/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515447722411-31279-0/minicluster-data/ts-0-root
1 data directories: /tmp/dist-test-taskNVEfdO/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515447722411-31279-0/minicluster-data/ts-0-root/data
Total live blocks: 0
Total live bytes: 0
Total live bytes (after alignment): 0
Total number of LBM containers: 0 (0 full)
Did not check for missing blocks
Did not check for orphaned blocks
Total full LBM containers with extra space: 0 (0 repaired)
Total full LBM container extra space in bytes: 0 (0 repaired)
Total incomplete LBM containers: 0 (0 repaired)
Total LBM partial records: 0 (0 repaired)
Total corrupted LBM metadata records in RocksDB: 0 (0 repaired)
I20260812 06:17:27.877225 31279 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:17:27.877578 31279 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:17:27.878048 31279 txn_system_client.cc:432] TxnSystemClient initialization is disabled...
I20260812 06:17:27.878836 31279 ts_tablet_manager.cc:585] Loaded tablet metadata (0 total tablets, 0 live tablets)
I20260812 06:17:27.878887 31279 ts_tablet_manager.cc:531] Time spent load tablet metadata: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:17:27.878943 31279 ts_tablet_manager.cc:616] Registered 0 tablets
I20260812 06:17:27.878968 31279 ts_tablet_manager.cc:595] Time spent register tablets: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:17:27.885058 31279 rpc_server.cc:307] RPC server started. Bound to: 127.30.139.193:43525
I20260812 06:17:27.885097 31528 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.30.139.193:43525 every 8 connection(s)
I20260812 06:17:27.894433 31531 heartbeater.cc:344] Connected to a master server at 127.30.139.254:39755
I20260812 06:17:27.894665 31531 heartbeater.cc:461] Registering TS with master...
I20260812 06:17:27.895059 31531 heartbeater.cc:507] Master 127.30.139.254:39755 requested a full tablet report, sending...
I20260812 06:17:27.896430 31325 ts_manager.cc:194] Registered new tserver with Master: f5fdf36185874a7a8cb879c56f869891 (127.30.139.193:43525)
I20260812 06:17:27.896756 31279 internal_mini_cluster.cc:371] 1 TS(s) registered with all masters after 0.011130714s
I20260812 06:17:27.897833 31325 master_service.cc:502] Signed X509 certificate for tserver {username='slave'} at 127.0.0.1:44120
I20260812 06:17:27.905807 31325 catalog_manager.cc:2283] Servicing CreateTable request from {username='slave'} at 127.0.0.1:44124:
name: "heavy-update-compaction-test"
schema {
  columns {
    name: "key"
    type: INT64
    is_key: true
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_a"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_b"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_c"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_d"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_e"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
}
num_replicas: 1
split_rows_range_bounds {
}
partition_schema {
  range_schema {
  }
}
I20260812 06:17:27.920691 31478 tablet_service.cc:1511] Processing CreateTablet for tablet aa1844f8d8354659ade1bcffcae7d29d (DEFAULT_TABLE table=heavy-update-compaction-test [id=2a5619e5fc1c487e8f08cfe55662b035]), partition=
I20260812 06:17:27.921144 31478 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet aa1844f8d8354659ade1bcffcae7d29d. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:17:27.923311 31550 tablet_bootstrap.cc:492] T aa1844f8d8354659ade1bcffcae7d29d P f5fdf36185874a7a8cb879c56f869891: Bootstrap starting.
I20260812 06:17:27.924203 31550 tablet_bootstrap.cc:654] T aa1844f8d8354659ade1bcffcae7d29d P f5fdf36185874a7a8cb879c56f869891: Neither blocks nor log segments found. Creating new log.
I20260812 06:17:27.925426 31550 tablet_bootstrap.cc:492] T aa1844f8d8354659ade1bcffcae7d29d P f5fdf36185874a7a8cb879c56f869891: No bootstrap required, opened a new log
I20260812 06:17:27.925520 31550 ts_tablet_manager.cc:1403] T aa1844f8d8354659ade1bcffcae7d29d P f5fdf36185874a7a8cb879c56f869891: Time spent bootstrapping tablet: real 0.002s	user 0.002s	sys 0.000s
I20260812 06:17:27.926188 31550 raft_consensus.cc:359] T aa1844f8d8354659ade1bcffcae7d29d P f5fdf36185874a7a8cb879c56f869891 [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "f5fdf36185874a7a8cb879c56f869891" member_type: VOTER last_known_addr { host: "127.30.139.193" port: 43525 } }
I20260812 06:17:27.926288 31550 raft_consensus.cc:385] T aa1844f8d8354659ade1bcffcae7d29d P f5fdf36185874a7a8cb879c56f869891 [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:17:27.926321 31550 raft_consensus.cc:740] T aa1844f8d8354659ade1bcffcae7d29d P f5fdf36185874a7a8cb879c56f869891 [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: f5fdf36185874a7a8cb879c56f869891, State: Initialized, Role: FOLLOWER
I20260812 06:17:27.926441 31550 consensus_queue.cc:260] T aa1844f8d8354659ade1bcffcae7d29d P f5fdf36185874a7a8cb879c56f869891 [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: "f5fdf36185874a7a8cb879c56f869891" member_type: VOTER last_known_addr { host: "127.30.139.193" port: 43525 } }
I20260812 06:17:27.926510 31550 raft_consensus.cc:399] T aa1844f8d8354659ade1bcffcae7d29d P f5fdf36185874a7a8cb879c56f869891 [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:17:27.926553 31550 raft_consensus.cc:493] T aa1844f8d8354659ade1bcffcae7d29d P f5fdf36185874a7a8cb879c56f869891 [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:17:27.926599 31550 raft_consensus.cc:3060] T aa1844f8d8354659ade1bcffcae7d29d P f5fdf36185874a7a8cb879c56f869891 [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:17:27.927274 31550 raft_consensus.cc:515] T aa1844f8d8354659ade1bcffcae7d29d P f5fdf36185874a7a8cb879c56f869891 [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "f5fdf36185874a7a8cb879c56f869891" member_type: VOTER last_known_addr { host: "127.30.139.193" port: 43525 } }
I20260812 06:17:27.927400 31550 leader_election.cc:304] T aa1844f8d8354659ade1bcffcae7d29d P f5fdf36185874a7a8cb879c56f869891 [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: f5fdf36185874a7a8cb879c56f869891; no voters: 
I20260812 06:17:27.927577 31550 leader_election.cc:290] T aa1844f8d8354659ade1bcffcae7d29d P f5fdf36185874a7a8cb879c56f869891 [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:17:27.927683 31554 raft_consensus.cc:2804] T aa1844f8d8354659ade1bcffcae7d29d P f5fdf36185874a7a8cb879c56f869891 [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:17:27.927901 31550 ts_tablet_manager.cc:1434] T aa1844f8d8354659ade1bcffcae7d29d P f5fdf36185874a7a8cb879c56f869891: Time spent starting tablet: real 0.002s	user 0.000s	sys 0.003s
I20260812 06:17:27.927918 31554 raft_consensus.cc:697] T aa1844f8d8354659ade1bcffcae7d29d P f5fdf36185874a7a8cb879c56f869891 [term 1 LEADER]: Becoming Leader. State: Replica: f5fdf36185874a7a8cb879c56f869891, State: Running, Role: LEADER
I20260812 06:17:27.928133 31531 heartbeater.cc:499] Master 127.30.139.254:39755 was elected leader, sending a full tablet report...
I20260812 06:17:27.928114 31554 consensus_queue.cc:237] T aa1844f8d8354659ade1bcffcae7d29d P f5fdf36185874a7a8cb879c56f869891 [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: "f5fdf36185874a7a8cb879c56f869891" member_type: VOTER last_known_addr { host: "127.30.139.193" port: 43525 } }
I20260812 06:17:27.930857 31325 catalog_manager.cc:5719] T aa1844f8d8354659ade1bcffcae7d29d P f5fdf36185874a7a8cb879c56f869891 reported cstate change: term changed from 0 to 1, leader changed from <none> to f5fdf36185874a7a8cb879c56f869891 (127.30.139.193). New cstate: current_term: 1 leader_uuid: "f5fdf36185874a7a8cb879c56f869891" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "f5fdf36185874a7a8cb879c56f869891" member_type: VOTER last_known_addr { host: "127.30.139.193" port: 43525 } health_report { overall_health: HEALTHY } } }
I20260812 06:17:27.994500 31279 heavy-update-compaction-itest.cc:215] Time spent inserting: real 0.058s	user 0.027s	sys 0.003s
I20260812 06:17:28.136122 31534 maintenance_manager.cc:419] P f5fdf36185874a7a8cb879c56f869891: Scheduling FlushMRSOp(aa1844f8d8354659ade1bcffcae7d29d): perf score=19.054940
I20260812 06:17:28.339376 31439 maintenance_manager.cc:643] P f5fdf36185874a7a8cb879c56f869891: FlushMRSOp(aa1844f8d8354659ade1bcffcae7d29d) complete. Timing: real 0.203s	user 0.153s	sys 0.047s Metrics: {"bytes_written":16491951,"cfile_init":1,"compiler_manager_pool.queue_time_us":221,"delete_count":0,"dirs.queue_time_us":51,"dirs.run_cpu_time_us":187,"dirs.run_wall_time_us":706,"drs_written":1,"lbm_read_time_us":63,"lbm_reads_lt_1ms":4,"lbm_write_time_us":53579,"lbm_writes_lt_1ms":859,"peak_mem_usage":0,"reinsert_count":0,"rows_written":104,"spinlock_wait_cycles":305920,"thread_start_us":132,"threads_started":1,"update_count":2010}
I20260812 06:17:28.340358 31534 maintenance_manager.cc:419] P f5fdf36185874a7a8cb879c56f869891: Scheduling LogGCOp(aa1844f8d8354659ade1bcffcae7d29d): free 20743880 bytes of WAL
I20260812 06:17:28.340642 31439 log_reader.cc:385] T aa1844f8d8354659ade1bcffcae7d29d: removed 2 log segments from log reader
I20260812 06:17:28.340704 31439 log.cc:1079] T aa1844f8d8354659ade1bcffcae7d29d P f5fdf36185874a7a8cb879c56f869891: Deleting log segment in path: /tmp/dist-test-taskNVEfdO/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515447722411-31279-0/minicluster-data/ts-0-root/wals/aa1844f8d8354659ade1bcffcae7d29d/wal-000000001 (ops 1-6)
I20260812 06:17:28.340752 31439 log.cc:1079] T aa1844f8d8354659ade1bcffcae7d29d P f5fdf36185874a7a8cb879c56f869891: Deleting log segment in path: /tmp/dist-test-taskNVEfdO/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515447722411-31279-0/minicluster-data/ts-0-root/wals/aa1844f8d8354659ade1bcffcae7d29d/wal-000000002 (ops 7-11)
I20260812 06:17:28.343930 31439 maintenance_manager.cc:643] P f5fdf36185874a7a8cb879c56f869891: LogGCOp(aa1844f8d8354659ade1bcffcae7d29d) complete. Timing: real 0.003s	user 0.000s	sys 0.001s Metrics: {}
I20260812 06:17:28.344187 31534 maintenance_manager.cc:419] P f5fdf36185874a7a8cb879c56f869891: Scheduling UndoDeltaBlockGCOp(aa1844f8d8354659ade1bcffcae7d29d): 16411393 bytes on disk
I20260812 06:17:28.344735 31439 maintenance_manager.cc:643] P f5fdf36185874a7a8cb879c56f869891: UndoDeltaBlockGCOp(aa1844f8d8354659ade1bcffcae7d29d) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":58,"lbm_reads_lt_1ms":4}
I20260812 06:17:28.345149 31534 maintenance_manager.cc:419] P f5fdf36185874a7a8cb879c56f869891: Scheduling FlushDeltaMemStoresOp(aa1844f8d8354659ade1bcffcae7d29d): perf score=3.181125
I20260812 06:17:28.368777 31439 maintenance_manager.cc:643] P f5fdf36185874a7a8cb879c56f869891: FlushDeltaMemStoresOp(aa1844f8d8354659ade1bcffcae7d29d) complete. Timing: real 0.023s	user 0.010s	sys 0.003s Metrics: {"bytes_written":4430858,"delete_count":0,"lbm_write_time_us":5783,"lbm_writes_lt_1ms":111,"reinsert_count":0,"update_count":540}
I20260812 06:17:28.369221 31534 maintenance_manager.cc:419] P f5fdf36185874a7a8cb879c56f869891: Scheduling FlushDeltaMemStoresOp(aa1844f8d8354659ade1bcffcae7d29d): perf score=2.188937
I20260812 06:17:28.377840 31439 maintenance_manager.cc:643] P f5fdf36185874a7a8cb879c56f869891: FlushDeltaMemStoresOp(aa1844f8d8354659ade1bcffcae7d29d) complete. Timing: real 0.008s	user 0.008s	sys 0.000s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3061,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:17:28.378286 31534 maintenance_manager.cc:419] P f5fdf36185874a7a8cb879c56f869891: Scheduling MajorDeltaCompactionOp(aa1844f8d8354659ade1bcffcae7d29d): perf score=1.000000
I20260812 06:17:28.567016 31439 maintenance_manager.cc:643] P f5fdf36185874a7a8cb879c56f869891: MajorDeltaCompactionOp(aa1844f8d8354659ade1bcffcae7d29d) complete. Timing: real 0.189s	user 0.133s	sys 0.044s Metrics: {"cfile_cache_miss":633,"cfile_cache_miss_bytes":28877214,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":941,"lbm_read_time_us":11381,"lbm_reads_lt_1ms":669,"lbm_write_time_us":37735,"lbm_writes_lt_1ms":643,"mutex_wait_us":128,"peak_mem_usage":75542472,"reinsert_count":0,"thread_start_us":315,"threads_started":5,"update_count":3000}
I20260812 06:17:28.567502 31534 maintenance_manager.cc:419] P f5fdf36185874a7a8cb879c56f869891: Scheduling FlushDeltaMemStoresOp(aa1844f8d8354659ade1bcffcae7d29d): perf score=14.095187
I20260812 06:17:28.627760 31439 maintenance_manager.cc:643] P f5fdf36185874a7a8cb879c56f869891: FlushDeltaMemStoresOp(aa1844f8d8354659ade1bcffcae7d29d) complete. Timing: real 0.060s	user 0.029s	sys 0.019s Metrics: {"bytes_written":16409900,"delete_count":0,"lbm_write_time_us":23757,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:17:28.628242 31534 maintenance_manager.cc:419] P f5fdf36185874a7a8cb879c56f869891: Scheduling FlushDeltaMemStoresOp(aa1844f8d8354659ade1bcffcae7d29d): perf score=2.188937
I20260812 06:17:28.638996 31439 maintenance_manager.cc:643] P f5fdf36185874a7a8cb879c56f869891: FlushDeltaMemStoresOp(aa1844f8d8354659ade1bcffcae7d29d) complete. Timing: real 0.011s	user 0.005s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4250,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:28.639386 31534 maintenance_manager.cc:419] P f5fdf36185874a7a8cb879c56f869891: Scheduling MajorDeltaCompactionOp(aa1844f8d8354659ade1bcffcae7d29d): perf score=1.000000
I20260812 06:17:28.802769 31439 maintenance_manager.cc:643] P f5fdf36185874a7a8cb879c56f869891: MajorDeltaCompactionOp(aa1844f8d8354659ade1bcffcae7d29d) complete. Timing: real 0.163s	user 0.108s	sys 0.044s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774687,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":338,"lbm_read_time_us":9745,"lbm_reads_lt_1ms":572,"lbm_write_time_us":30118,"lbm_writes_lt_1ms":543,"mutex_wait_us":27,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":1792,"update_count":2500}
I20260812 06:17:28.803256 31534 maintenance_manager.cc:419] P f5fdf36185874a7a8cb879c56f869891: Scheduling FlushDeltaMemStoresOp(aa1844f8d8354659ade1bcffcae7d29d): perf score=14.095187
I20260812 06:17:28.860163 31439 maintenance_manager.cc:643] P f5fdf36185874a7a8cb879c56f869891: FlushDeltaMemStoresOp(aa1844f8d8354659ade1bcffcae7d29d) complete. Timing: real 0.057s	user 0.025s	sys 0.024s Metrics: {"bytes_written":16409900,"delete_count":0,"lbm_write_time_us":19900,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:17:28.860641 31534 maintenance_manager.cc:419] P f5fdf36185874a7a8cb879c56f869891: Scheduling FlushDeltaMemStoresOp(aa1844f8d8354659ade1bcffcae7d29d): perf score=2.188937
I20260812 06:17:28.871645 31439 maintenance_manager.cc:643] P f5fdf36185874a7a8cb879c56f869891: FlushDeltaMemStoresOp(aa1844f8d8354659ade1bcffcae7d29d) complete. Timing: real 0.011s	user 0.009s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4446,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:28.872038 31534 maintenance_manager.cc:419] P f5fdf36185874a7a8cb879c56f869891: Scheduling MajorDeltaCompactionOp(aa1844f8d8354659ade1bcffcae7d29d): perf score=1.000000
I20260812 06:17:29.048405 31439 maintenance_manager.cc:643] P f5fdf36185874a7a8cb879c56f869891: MajorDeltaCompactionOp(aa1844f8d8354659ade1bcffcae7d29d) complete. Timing: real 0.176s	user 0.097s	sys 0.072s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774687,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":206,"lbm_read_time_us":10988,"lbm_reads_lt_1ms":572,"lbm_write_time_us":34073,"lbm_writes_lt_1ms":543,"mutex_wait_us":39,"peak_mem_usage":63115900,"reinsert_count":0,"update_count":2500}
I20260812 06:17:29.048856 31534 maintenance_manager.cc:419] P f5fdf36185874a7a8cb879c56f869891: Scheduling FlushDeltaMemStoresOp(aa1844f8d8354659ade1bcffcae7d29d): perf score=14.095187
I20260812 06:17:29.102813 31439 maintenance_manager.cc:643] P f5fdf36185874a7a8cb879c56f869891: FlushDeltaMemStoresOp(aa1844f8d8354659ade1bcffcae7d29d) complete. Timing: real 0.054s	user 0.040s	sys 0.010s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":20117,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:17:29.103384 31534 maintenance_manager.cc:419] P f5fdf36185874a7a8cb879c56f869891: Scheduling FlushDeltaMemStoresOp(aa1844f8d8354659ade1bcffcae7d29d): perf score=2.188937
I20260812 06:17:29.113884 31439 maintenance_manager.cc:643] P f5fdf36185874a7a8cb879c56f869891: FlushDeltaMemStoresOp(aa1844f8d8354659ade1bcffcae7d29d) complete. Timing: real 0.010s	user 0.006s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3961,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:29.114394 31534 maintenance_manager.cc:419] P f5fdf36185874a7a8cb879c56f869891: Scheduling MajorDeltaCompactionOp(aa1844f8d8354659ade1bcffcae7d29d): perf score=1.000000
I20260812 06:17:29.289821 31439 maintenance_manager.cc:643] P f5fdf36185874a7a8cb879c56f869891: MajorDeltaCompactionOp(aa1844f8d8354659ade1bcffcae7d29d) complete. Timing: real 0.175s	user 0.115s	sys 0.052s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774688,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":249,"lbm_read_time_us":10913,"lbm_reads_lt_1ms":572,"lbm_write_time_us":31825,"lbm_writes_lt_1ms":543,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":768,"update_count":2500}
I20260812 06:17:29.290439 31534 maintenance_manager.cc:419] P f5fdf36185874a7a8cb879c56f869891: Scheduling FlushDeltaMemStoresOp(aa1844f8d8354659ade1bcffcae7d29d): perf score=14.095187
I20260812 06:17:29.336231 31439 maintenance_manager.cc:643] P f5fdf36185874a7a8cb879c56f869891: FlushDeltaMemStoresOp(aa1844f8d8354659ade1bcffcae7d29d) complete. Timing: real 0.046s	user 0.031s	sys 0.012s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":20891,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:17:29.336728 31534 maintenance_manager.cc:419] P f5fdf36185874a7a8cb879c56f869891: Scheduling FlushDeltaMemStoresOp(aa1844f8d8354659ade1bcffcae7d29d): perf score=2.188937
I20260812 06:17:29.357324 31439 maintenance_manager.cc:643] P f5fdf36185874a7a8cb879c56f869891: FlushDeltaMemStoresOp(aa1844f8d8354659ade1bcffcae7d29d) complete. Timing: real 0.020s	user 0.014s	sys 0.003s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5867,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:29.357872 31534 maintenance_manager.cc:419] P f5fdf36185874a7a8cb879c56f869891: Scheduling MajorDeltaCompactionOp(aa1844f8d8354659ade1bcffcae7d29d): perf score=1.000000
I20260812 06:17:29.523272 31439 maintenance_manager.cc:643] P f5fdf36185874a7a8cb879c56f869891: MajorDeltaCompactionOp(aa1844f8d8354659ade1bcffcae7d29d) complete. Timing: real 0.165s	user 0.125s	sys 0.039s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774688,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":633,"lbm_read_time_us":11312,"lbm_reads_lt_1ms":572,"lbm_write_time_us":27506,"lbm_writes_lt_1ms":543,"mutex_wait_us":258,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":1792,"update_count":2500}
I20260812 06:17:29.523795 31534 maintenance_manager.cc:419] P f5fdf36185874a7a8cb879c56f869891: Scheduling FlushDeltaMemStoresOp(aa1844f8d8354659ade1bcffcae7d29d): perf score=11.118625
I20260812 06:17:29.564174 31439 maintenance_manager.cc:643] P f5fdf36185874a7a8cb879c56f869891: FlushDeltaMemStoresOp(aa1844f8d8354659ade1bcffcae7d29d) complete. Timing: real 0.040s	user 0.020s	sys 0.017s Metrics: {"bytes_written":12717737,"delete_count":0,"lbm_write_time_us":19260,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":312,"reinsert_count":0,"update_count":1550}
I20260812 06:17:29.564674 31534 maintenance_manager.cc:419] P f5fdf36185874a7a8cb879c56f869891: Scheduling FlushDeltaMemStoresOp(aa1844f8d8354659ade1bcffcae7d29d): perf score=2.188937
I20260812 06:17:29.580547 31439 maintenance_manager.cc:643] P f5fdf36185874a7a8cb879c56f869891: FlushDeltaMemStoresOp(aa1844f8d8354659ade1bcffcae7d29d) complete. Timing: real 0.016s	user 0.008s	sys 0.000s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3718,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:17:29.581005 31534 maintenance_manager.cc:419] P f5fdf36185874a7a8cb879c56f869891: Scheduling FlushDeltaMemStoresOp(aa1844f8d8354659ade1bcffcae7d29d): perf score=2.188937
I20260812 06:17:29.590304 31439 maintenance_manager.cc:643] P f5fdf36185874a7a8cb879c56f869891: FlushDeltaMemStoresOp(aa1844f8d8354659ade1bcffcae7d29d) complete. Timing: real 0.009s	user 0.009s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3394,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:29.590785 31534 maintenance_manager.cc:419] P f5fdf36185874a7a8cb879c56f869891: Scheduling FlushMRSOp(aa1844f8d8354659ade1bcffcae7d29d): perf score=1.000000
I20260812 06:17:29.617908 31439 maintenance_manager.cc:643] P f5fdf36185874a7a8cb879c56f869891: FlushMRSOp(aa1844f8d8354659ade1bcffcae7d29d) complete. Timing: real 0.027s	user 0.026s	sys 0.000s Metrics: {"bytes_written":1275443,"cfile_init":1,"dirs.queue_time_us":65,"dirs.run_cpu_time_us":253,"dirs.run_wall_time_us":1230,"drs_written":1,"lbm_read_time_us":37,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1401,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":31,"spinlock_wait_cycles":768}
I20260812 06:17:29.619094 31534 maintenance_manager.cc:419] P f5fdf36185874a7a8cb879c56f869891: Scheduling UndoDeltaBlockGCOp(aa1844f8d8354659ade1bcffcae7d29d): 483 bytes on disk
I20260812 06:17:29.619540 31439 maintenance_manager.cc:643] P f5fdf36185874a7a8cb879c56f869891: UndoDeltaBlockGCOp(aa1844f8d8354659ade1bcffcae7d29d) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":67,"lbm_reads_lt_1ms":4}
I20260812 06:17:29.620060 31534 maintenance_manager.cc:419] P f5fdf36185874a7a8cb879c56f869891: Scheduling FlushDeltaMemStoresOp(aa1844f8d8354659ade1bcffcae7d29d): perf score=2.188937
I20260812 06:17:29.633306 31439 maintenance_manager.cc:643] P f5fdf36185874a7a8cb879c56f869891: FlushDeltaMemStoresOp(aa1844f8d8354659ade1bcffcae7d29d) complete. Timing: real 0.013s	user 0.011s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5011,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:29.633728 31534 maintenance_manager.cc:419] P f5fdf36185874a7a8cb879c56f869891: Scheduling LogGCOp(aa1844f8d8354659ade1bcffcae7d29d): free 124710295 bytes of WAL
I20260812 06:17:29.633929 31439 log_reader.cc:385] T aa1844f8d8354659ade1bcffcae7d29d: removed 12 log segments from log reader
I20260812 06:17:29.633970 31439 log.cc:1079] T aa1844f8d8354659ade1bcffcae7d29d P f5fdf36185874a7a8cb879c56f869891: Deleting log segment in path: /tmp/dist-test-taskNVEfdO/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515447722411-31279-0/minicluster-data/ts-0-root/wals/aa1844f8d8354659ade1bcffcae7d29d/wal-000000003 (ops 12-16)
I20260812 06:17:29.633997 31439 log.cc:1079] T aa1844f8d8354659ade1bcffcae7d29d P f5fdf36185874a7a8cb879c56f869891: Deleting log segment in path: /tmp/dist-test-taskNVEfdO/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515447722411-31279-0/minicluster-data/ts-0-root/wals/aa1844f8d8354659ade1bcffcae7d29d/wal-000000004 (ops 17-21)
I20260812 06:17:29.634029 31439 log.cc:1079] T aa1844f8d8354659ade1bcffcae7d29d P f5fdf36185874a7a8cb879c56f869891: Deleting log segment in path: /tmp/dist-test-taskNVEfdO/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515447722411-31279-0/minicluster-data/ts-0-root/wals/aa1844f8d8354659ade1bcffcae7d29d/wal-000000005 (ops 22-26)
I20260812 06:17:29.634061 31439 log.cc:1079] T aa1844f8d8354659ade1bcffcae7d29d P f5fdf36185874a7a8cb879c56f869891: Deleting log segment in path: /tmp/dist-test-taskNVEfdO/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515447722411-31279-0/minicluster-data/ts-0-root/wals/aa1844f8d8354659ade1bcffcae7d29d/wal-000000006 (ops 27-31)
I20260812 06:17:29.634093 31439 log.cc:1079] T aa1844f8d8354659ade1bcffcae7d29d P f5fdf36185874a7a8cb879c56f869891: Deleting log segment in path: /tmp/dist-test-taskNVEfdO/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515447722411-31279-0/minicluster-data/ts-0-root/wals/aa1844f8d8354659ade1bcffcae7d29d/wal-000000007 (ops 32-36)
I20260812 06:17:29.634125 31439 log.cc:1079] T aa1844f8d8354659ade1bcffcae7d29d P f5fdf36185874a7a8cb879c56f869891: Deleting log segment in path: /tmp/dist-test-taskNVEfdO/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515447722411-31279-0/minicluster-data/ts-0-root/wals/aa1844f8d8354659ade1bcffcae7d29d/wal-000000008 (ops 37-41)
I20260812 06:17:29.634157 31439 log.cc:1079] T aa1844f8d8354659ade1bcffcae7d29d P f5fdf36185874a7a8cb879c56f869891: Deleting log segment in path: /tmp/dist-test-taskNVEfdO/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515447722411-31279-0/minicluster-data/ts-0-root/wals/aa1844f8d8354659ade1bcffcae7d29d/wal-000000009 (ops 42-46)
I20260812 06:17:29.634189 31439 log.cc:1079] T aa1844f8d8354659ade1bcffcae7d29d P f5fdf36185874a7a8cb879c56f869891: Deleting log segment in path: /tmp/dist-test-taskNVEfdO/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515447722411-31279-0/minicluster-data/ts-0-root/wals/aa1844f8d8354659ade1bcffcae7d29d/wal-000000010 (ops 47-51)
I20260812 06:17:29.634220 31439 log.cc:1079] T aa1844f8d8354659ade1bcffcae7d29d P f5fdf36185874a7a8cb879c56f869891: Deleting log segment in path: /tmp/dist-test-taskNVEfdO/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515447722411-31279-0/minicluster-data/ts-0-root/wals/aa1844f8d8354659ade1bcffcae7d29d/wal-000000011 (ops 52-56)
I20260812 06:17:29.634253 31439 log.cc:1079] T aa1844f8d8354659ade1bcffcae7d29d P f5fdf36185874a7a8cb879c56f869891: Deleting log segment in path: /tmp/dist-test-taskNVEfdO/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515447722411-31279-0/minicluster-data/ts-0-root/wals/aa1844f8d8354659ade1bcffcae7d29d/wal-000000012 (ops 57-61)
I20260812 06:17:29.634284 31439 log.cc:1079] T aa1844f8d8354659ade1bcffcae7d29d P f5fdf36185874a7a8cb879c56f869891: Deleting log segment in path: /tmp/dist-test-taskNVEfdO/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515447722411-31279-0/minicluster-data/ts-0-root/wals/aa1844f8d8354659ade1bcffcae7d29d/wal-000000013 (ops 62-66)
I20260812 06:17:29.634315 31439 log.cc:1079] T aa1844f8d8354659ade1bcffcae7d29d P f5fdf36185874a7a8cb879c56f869891: Deleting log segment in path: /tmp/dist-test-taskNVEfdO/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515447722411-31279-0/minicluster-data/ts-0-root/wals/aa1844f8d8354659ade1bcffcae7d29d/wal-000000014 (ops 67-71)
I20260812 06:17:29.654829 31439 maintenance_manager.cc:643] P f5fdf36185874a7a8cb879c56f869891: LogGCOp(aa1844f8d8354659ade1bcffcae7d29d) complete. Timing: real 0.021s	user 0.001s	sys 0.019s Metrics: {}
I20260812 06:17:29.655309 31534 maintenance_manager.cc:419] P f5fdf36185874a7a8cb879c56f869891: Scheduling MajorDeltaCompactionOp(aa1844f8d8354659ade1bcffcae7d29d): perf score=1.000000
I20260812 06:17:29.834823 31439 maintenance_manager.cc:643] P f5fdf36185874a7a8cb879c56f869891: MajorDeltaCompactionOp(aa1844f8d8354659ade1bcffcae7d29d) complete. Timing: real 0.179s	user 0.118s	sys 0.060s Metrics: {"cfile_cache_miss":634,"cfile_cache_miss_bytes":28877332,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":1228,"lbm_read_time_us":12014,"lbm_reads_lt_1ms":666,"lbm_write_time_us":30454,"lbm_writes_lt_1ms":643,"mutex_wait_us":279,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":4992,"thread_start_us":80,"threads_started":1,"update_count":3000}
I20260812 06:17:29.835578 31534 maintenance_manager.cc:419] P f5fdf36185874a7a8cb879c56f869891: Scheduling FlushDeltaMemStoresOp(aa1844f8d8354659ade1bcffcae7d29d): perf score=15.087375
I20260812 06:17:29.879273 31439 maintenance_manager.cc:643] P f5fdf36185874a7a8cb879c56f869891: FlushDeltaMemStoresOp(aa1844f8d8354659ade1bcffcae7d29d) complete. Timing: real 0.043s	user 0.031s	sys 0.011s Metrics: {"bytes_written":16820143,"delete_count":0,"lbm_write_time_us":15649,"lbm_writes_lt_1ms":413,"reinsert_count":0,"update_count":2050}
I20260812 06:17:29.879858 31534 maintenance_manager.cc:419] P f5fdf36185874a7a8cb879c56f869891: Scheduling FlushDeltaMemStoresOp(aa1844f8d8354659ade1bcffcae7d29d): perf score=2.188937
I20260812 06:17:29.906855 31439 maintenance_manager.cc:643] P f5fdf36185874a7a8cb879c56f869891: FlushDeltaMemStoresOp(aa1844f8d8354659ade1bcffcae7d29d) complete. Timing: real 0.027s	user 0.004s	sys 0.007s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":4663,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:17:29.907315 31534 maintenance_manager.cc:419] P f5fdf36185874a7a8cb879c56f869891: Scheduling FlushDeltaMemStoresOp(aa1844f8d8354659ade1bcffcae7d29d): perf score=2.188937
I20260812 06:17:29.921281 31439 maintenance_manager.cc:643] P f5fdf36185874a7a8cb879c56f869891: FlushDeltaMemStoresOp(aa1844f8d8354659ade1bcffcae7d29d) complete. Timing: real 0.014s	user 0.008s	sys 0.003s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5172,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:29.921814 31534 maintenance_manager.cc:419] P f5fdf36185874a7a8cb879c56f869891: Scheduling MajorDeltaCompactionOp(aa1844f8d8354659ade1bcffcae7d29d): perf score=1.000000
I20260812 06:17:30.102131 31439 maintenance_manager.cc:643] P f5fdf36185874a7a8cb879c56f869891: MajorDeltaCompactionOp(aa1844f8d8354659ade1bcffcae7d29d) complete. Timing: real 0.180s	user 0.131s	sys 0.049s Metrics: {"cfile_cache_miss":633,"cfile_cache_miss_bytes":28877207,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":165,"lbm_read_time_us":13979,"lbm_reads_lt_1ms":673,"lbm_write_time_us":32390,"lbm_writes_lt_1ms":643,"mutex_wait_us":23,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":9984,"update_count":3000}
I20260812 06:17:30.102622 31534 maintenance_manager.cc:419] P f5fdf36185874a7a8cb879c56f869891: Scheduling FlushDeltaMemStoresOp(aa1844f8d8354659ade1bcffcae7d29d): perf score=14.095187
I20260812 06:17:30.162499 31439 maintenance_manager.cc:643] P f5fdf36185874a7a8cb879c56f869891: FlushDeltaMemStoresOp(aa1844f8d8354659ade1bcffcae7d29d) complete. Timing: real 0.060s	user 0.032s	sys 0.016s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":21442,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:17:30.162984 31534 maintenance_manager.cc:419] P f5fdf36185874a7a8cb879c56f869891: Scheduling FlushDeltaMemStoresOp(aa1844f8d8354659ade1bcffcae7d29d): perf score=2.188937
I20260812 06:17:30.172789 31439 maintenance_manager.cc:643] P f5fdf36185874a7a8cb879c56f869891: FlushDeltaMemStoresOp(aa1844f8d8354659ade1bcffcae7d29d) complete. Timing: real 0.010s	user 0.004s	sys 0.004s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":3575,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:30.173202 31534 maintenance_manager.cc:419] P f5fdf36185874a7a8cb879c56f869891: Scheduling MajorDeltaCompactionOp(aa1844f8d8354659ade1bcffcae7d29d): perf score=1.000000
I20260812 06:17:30.334453 31439 maintenance_manager.cc:643] P f5fdf36185874a7a8cb879c56f869891: MajorDeltaCompactionOp(aa1844f8d8354659ade1bcffcae7d29d) complete. Timing: real 0.161s	user 0.110s	sys 0.044s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774688,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":118,"lbm_read_time_us":11517,"lbm_reads_lt_1ms":572,"lbm_write_time_us":24196,"lbm_writes_lt_1ms":543,"mutex_wait_us":28,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":80384,"update_count":2500}
I20260812 06:17:30.335043 31534 maintenance_manager.cc:419] P f5fdf36185874a7a8cb879c56f869891: Scheduling FlushDeltaMemStoresOp(aa1844f8d8354659ade1bcffcae7d29d): perf score=14.095187
I20260812 06:17:30.392912 31439 maintenance_manager.cc:643] P f5fdf36185874a7a8cb879c56f869891: FlushDeltaMemStoresOp(aa1844f8d8354659ade1bcffcae7d29d) complete. Timing: real 0.058s	user 0.030s	sys 0.023s Metrics: {"bytes_written":16409900,"delete_count":0,"lbm_write_time_us":22289,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:17:30.393415 31534 maintenance_manager.cc:419] P f5fdf36185874a7a8cb879c56f869891: Scheduling FlushDeltaMemStoresOp(aa1844f8d8354659ade1bcffcae7d29d): perf score=2.188937
I20260812 06:17:30.403252 31439 maintenance_manager.cc:643] P f5fdf36185874a7a8cb879c56f869891: FlushDeltaMemStoresOp(aa1844f8d8354659ade1bcffcae7d29d) complete. Timing: real 0.010s	user 0.001s	sys 0.007s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3691,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:30.403635 31534 maintenance_manager.cc:419] P f5fdf36185874a7a8cb879c56f869891: Scheduling MajorDeltaCompactionOp(aa1844f8d8354659ade1bcffcae7d29d): perf score=1.000000
I20260812 06:17:30.554715 31439 maintenance_manager.cc:643] P f5fdf36185874a7a8cb879c56f869891: MajorDeltaCompactionOp(aa1844f8d8354659ade1bcffcae7d29d) complete. Timing: real 0.151s	user 0.115s	sys 0.036s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774687,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":155,"lbm_read_time_us":10559,"lbm_reads_lt_1ms":572,"lbm_write_time_us":26063,"lbm_writes_lt_1ms":543,"mutex_wait_us":41,"peak_mem_usage":63115900,"reinsert_count":0,"update_count":2500}
I20260812 06:17:30.555415 31534 maintenance_manager.cc:419] P f5fdf36185874a7a8cb879c56f869891: Scheduling FlushDeltaMemStoresOp(aa1844f8d8354659ade1bcffcae7d29d): perf score=11.118625
I20260812 06:17:30.586300 31439 maintenance_manager.cc:643] P f5fdf36185874a7a8cb879c56f869891: FlushDeltaMemStoresOp(aa1844f8d8354659ade1bcffcae7d29d) complete. Timing: real 0.031s	user 0.019s	sys 0.012s Metrics: {"bytes_written":12512613,"delete_count":0,"lbm_write_time_us":13295,"lbm_writes_lt_1ms":308,"reinsert_count":0,"update_count":1525}
I20260812 06:17:30.586800 31534 maintenance_manager.cc:419] P f5fdf36185874a7a8cb879c56f869891: Scheduling FlushDeltaMemStoresOp(aa1844f8d8354659ade1bcffcae7d29d): perf score=2.188937
I20260812 06:17:30.601231 31439 maintenance_manager.cc:643] P f5fdf36185874a7a8cb879c56f869891: FlushDeltaMemStoresOp(aa1844f8d8354659ade1bcffcae7d29d) complete. Timing: real 0.014s	user 0.008s	sys 0.004s Metrics: {"bytes_written":3897534,"delete_count":0,"lbm_write_time_us":5510,"lbm_writes_lt_1ms":98,"reinsert_count":0,"update_count":475}
I20260812 06:17:30.601797 31534 maintenance_manager.cc:419] P f5fdf36185874a7a8cb879c56f869891: Scheduling MajorDeltaCompactionOp(aa1844f8d8354659ade1bcffcae7d29d): perf score=1.000000
I20260812 06:17:30.748198 31439 maintenance_manager.cc:643] P f5fdf36185874a7a8cb879c56f869891: MajorDeltaCompactionOp(aa1844f8d8354659ade1bcffcae7d29d) complete. Timing: real 0.146s	user 0.099s	sys 0.041s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672275,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":45,"lbm_read_time_us":8602,"lbm_reads_lt_1ms":472,"lbm_write_time_us":25146,"lbm_writes_lt_1ms":443,"mutex_wait_us":2,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":1792,"update_count":2000}
I20260812 06:17:30.748863 31534 maintenance_manager.cc:419] P f5fdf36185874a7a8cb879c56f869891: Scheduling FlushDeltaMemStoresOp(aa1844f8d8354659ade1bcffcae7d29d): perf score=10.126437
I20260812 06:17:30.789081 31439 maintenance_manager.cc:643] P f5fdf36185874a7a8cb879c56f869891: FlushDeltaMemStoresOp(aa1844f8d8354659ade1bcffcae7d29d) complete. Timing: real 0.040s	user 0.026s	sys 0.011s Metrics: {"bytes_written":12307492,"delete_count":0,"lbm_write_time_us":18914,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:17:30.789501 31534 maintenance_manager.cc:419] P f5fdf36185874a7a8cb879c56f869891: Scheduling FlushDeltaMemStoresOp(aa1844f8d8354659ade1bcffcae7d29d): perf score=2.188937
I20260812 06:17:30.802500 31439 maintenance_manager.cc:643] P f5fdf36185874a7a8cb879c56f869891: FlushDeltaMemStoresOp(aa1844f8d8354659ade1bcffcae7d29d) complete. Timing: real 0.013s	user 0.008s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4878,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:30.803049 31534 maintenance_manager.cc:419] P f5fdf36185874a7a8cb879c56f869891: Scheduling MajorDeltaCompactionOp(aa1844f8d8354659ade1bcffcae7d29d): perf score=1.000000
I20260812 06:17:30.928257 31439 maintenance_manager.cc:643] P f5fdf36185874a7a8cb879c56f869891: MajorDeltaCompactionOp(aa1844f8d8354659ade1bcffcae7d29d) complete. Timing: real 0.125s	user 0.089s	sys 0.036s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672279,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":892,"lbm_read_time_us":8623,"lbm_reads_lt_1ms":472,"lbm_write_time_us":28908,"lbm_writes_lt_1ms":443,"mutex_wait_us":265,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":20352,"update_count":2000}
I20260812 06:17:30.928778 31534 maintenance_manager.cc:419] P f5fdf36185874a7a8cb879c56f869891: Scheduling FlushDeltaMemStoresOp(aa1844f8d8354659ade1bcffcae7d29d): perf score=10.126437
I20260812 06:17:30.964931 31439 maintenance_manager.cc:643] P f5fdf36185874a7a8cb879c56f869891: FlushDeltaMemStoresOp(aa1844f8d8354659ade1bcffcae7d29d) complete. Timing: real 0.036s	user 0.026s	sys 0.007s Metrics: {"bytes_written":12307489,"delete_count":0,"lbm_write_time_us":16679,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:17:30.965391 31534 maintenance_manager.cc:419] P f5fdf36185874a7a8cb879c56f869891: Scheduling FlushDeltaMemStoresOp(aa1844f8d8354659ade1bcffcae7d29d): perf score=2.188937
I20260812 06:17:30.977834 31439 maintenance_manager.cc:643] P f5fdf36185874a7a8cb879c56f869891: FlushDeltaMemStoresOp(aa1844f8d8354659ade1bcffcae7d29d) complete. Timing: real 0.012s	user 0.008s	sys 0.003s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4053,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:30.978240 31534 maintenance_manager.cc:419] P f5fdf36185874a7a8cb879c56f869891: Scheduling FlushMRSOp(aa1844f8d8354659ade1bcffcae7d29d): perf score=1.000000
I20260812 06:17:31.005295 31439 maintenance_manager.cc:643] P f5fdf36185874a7a8cb879c56f869891: FlushMRSOp(aa1844f8d8354659ade1bcffcae7d29d) complete. Timing: real 0.027s	user 0.025s	sys 0.000s Metrics: {"bytes_written":1193509,"cfile_init":1,"dirs.queue_time_us":61,"dirs.run_cpu_time_us":130,"dirs.run_wall_time_us":997,"drs_written":1,"lbm_read_time_us":53,"lbm_reads_lt_1ms":4,"lbm_write_time_us":2040,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":29}
I20260812 06:17:31.006114 31534 maintenance_manager.cc:419] P f5fdf36185874a7a8cb879c56f869891: Scheduling LogGCOp(aa1844f8d8354659ade1bcffcae7d29d): free 120553340 bytes of WAL
I20260812 06:17:31.006342 31439 log_reader.cc:385] T aa1844f8d8354659ade1bcffcae7d29d: removed 12 log segments from log reader
I20260812 06:17:31.006402 31439 log.cc:1079] T aa1844f8d8354659ade1bcffcae7d29d P f5fdf36185874a7a8cb879c56f869891: Deleting log segment in path: /tmp/dist-test-taskNVEfdO/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515447722411-31279-0/minicluster-data/ts-0-root/wals/aa1844f8d8354659ade1bcffcae7d29d/wal-000000015 (ops 72-76)
I20260812 06:17:31.006446 31439 log.cc:1079] T aa1844f8d8354659ade1bcffcae7d29d P f5fdf36185874a7a8cb879c56f869891: Deleting log segment in path: /tmp/dist-test-taskNVEfdO/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515447722411-31279-0/minicluster-data/ts-0-root/wals/aa1844f8d8354659ade1bcffcae7d29d/wal-000000016 (ops 77-81)
I20260812 06:17:31.006484 31439 log.cc:1079] T aa1844f8d8354659ade1bcffcae7d29d P f5fdf36185874a7a8cb879c56f869891: Deleting log segment in path: /tmp/dist-test-taskNVEfdO/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515447722411-31279-0/minicluster-data/ts-0-root/wals/aa1844f8d8354659ade1bcffcae7d29d/wal-000000017 (ops 82-86)
I20260812 06:17:31.006512 31439 log.cc:1079] T aa1844f8d8354659ade1bcffcae7d29d P f5fdf36185874a7a8cb879c56f869891: Deleting log segment in path: /tmp/dist-test-taskNVEfdO/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515447722411-31279-0/minicluster-data/ts-0-root/wals/aa1844f8d8354659ade1bcffcae7d29d/wal-000000018 (ops 87-91)
I20260812 06:17:31.006541 31439 log.cc:1079] T aa1844f8d8354659ade1bcffcae7d29d P f5fdf36185874a7a8cb879c56f869891: Deleting log segment in path: /tmp/dist-test-taskNVEfdO/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515447722411-31279-0/minicluster-data/ts-0-root/wals/aa1844f8d8354659ade1bcffcae7d29d/wal-000000019 (ops 92-96)
I20260812 06:17:31.006568 31439 log.cc:1079] T aa1844f8d8354659ade1bcffcae7d29d P f5fdf36185874a7a8cb879c56f869891: Deleting log segment in path: /tmp/dist-test-taskNVEfdO/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515447722411-31279-0/minicluster-data/ts-0-root/wals/aa1844f8d8354659ade1bcffcae7d29d/wal-000000020 (ops 97-101)
I20260812 06:17:31.006598 31439 log.cc:1079] T aa1844f8d8354659ade1bcffcae7d29d P f5fdf36185874a7a8cb879c56f869891: Deleting log segment in path: /tmp/dist-test-taskNVEfdO/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515447722411-31279-0/minicluster-data/ts-0-root/wals/aa1844f8d8354659ade1bcffcae7d29d/wal-000000021 (ops 102-106)
I20260812 06:17:31.006629 31439 log.cc:1079] T aa1844f8d8354659ade1bcffcae7d29d P f5fdf36185874a7a8cb879c56f869891: Deleting log segment in path: /tmp/dist-test-taskNVEfdO/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515447722411-31279-0/minicluster-data/ts-0-root/wals/aa1844f8d8354659ade1bcffcae7d29d/wal-000000022 (ops 107-110)
I20260812 06:17:31.006659 31439 log.cc:1079] T aa1844f8d8354659ade1bcffcae7d29d P f5fdf36185874a7a8cb879c56f869891: Deleting log segment in path: /tmp/dist-test-taskNVEfdO/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515447722411-31279-0/minicluster-data/ts-0-root/wals/aa1844f8d8354659ade1bcffcae7d29d/wal-000000023 (ops 111-115)
I20260812 06:17:31.006685 31439 log.cc:1079] T aa1844f8d8354659ade1bcffcae7d29d P f5fdf36185874a7a8cb879c56f869891: Deleting log segment in path: /tmp/dist-test-taskNVEfdO/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515447722411-31279-0/minicluster-data/ts-0-root/wals/aa1844f8d8354659ade1bcffcae7d29d/wal-000000024 (ops 116-120)
I20260812 06:17:31.006713 31439 log.cc:1079] T aa1844f8d8354659ade1bcffcae7d29d P f5fdf36185874a7a8cb879c56f869891: Deleting log segment in path: /tmp/dist-test-taskNVEfdO/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515447722411-31279-0/minicluster-data/ts-0-root/wals/aa1844f8d8354659ade1bcffcae7d29d/wal-000000025 (ops 121-124)
I20260812 06:17:31.006743 31439 log.cc:1079] T aa1844f8d8354659ade1bcffcae7d29d P f5fdf36185874a7a8cb879c56f869891: Deleting log segment in path: /tmp/dist-test-taskNVEfdO/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515447722411-31279-0/minicluster-data/ts-0-root/wals/aa1844f8d8354659ade1bcffcae7d29d/wal-000000026 (ops 125-129)
I20260812 06:17:31.029971 31439 maintenance_manager.cc:643] P f5fdf36185874a7a8cb879c56f869891: LogGCOp(aa1844f8d8354659ade1bcffcae7d29d) complete. Timing: real 0.024s	user 0.000s	sys 0.023s Metrics: {}
I20260812 06:17:31.030352 31534 maintenance_manager.cc:419] P f5fdf36185874a7a8cb879c56f869891: Scheduling FlushDeltaMemStoresOp(aa1844f8d8354659ade1bcffcae7d29d): perf score=3.181125
I20260812 06:17:31.041958 31439 maintenance_manager.cc:643] P f5fdf36185874a7a8cb879c56f869891: FlushDeltaMemStoresOp(aa1844f8d8354659ade1bcffcae7d29d) complete. Timing: real 0.011s	user 0.006s	sys 0.004s Metrics: {"bytes_written":4512903,"delete_count":0,"lbm_write_time_us":3992,"lbm_writes_lt_1ms":113,"reinsert_count":0,"update_count":550}
I20260812 06:17:31.042351 31534 maintenance_manager.cc:419] P f5fdf36185874a7a8cb879c56f869891: Scheduling UndoDeltaBlockGCOp(aa1844f8d8354659ade1bcffcae7d29d): 462 bytes on disk
I20260812 06:17:31.042765 31439 maintenance_manager.cc:643] P f5fdf36185874a7a8cb879c56f869891: UndoDeltaBlockGCOp(aa1844f8d8354659ade1bcffcae7d29d) 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:17:31.043255 31534 maintenance_manager.cc:419] P f5fdf36185874a7a8cb879c56f869891: Scheduling FlushDeltaMemStoresOp(aa1844f8d8354659ade1bcffcae7d29d): perf score=2.188937
I20260812 06:17:31.052174 31439 maintenance_manager.cc:643] P f5fdf36185874a7a8cb879c56f869891: FlushDeltaMemStoresOp(aa1844f8d8354659ade1bcffcae7d29d) complete. Timing: real 0.009s	user 0.007s	sys 0.000s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3197,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:17:31.052538 31534 maintenance_manager.cc:419] P f5fdf36185874a7a8cb879c56f869891: Scheduling MajorDeltaCompactionOp(aa1844f8d8354659ade1bcffcae7d29d): perf score=1.000000
I20260812 06:17:31.217644 31439 maintenance_manager.cc:643] P f5fdf36185874a7a8cb879c56f869891: MajorDeltaCompactionOp(aa1844f8d8354659ade1bcffcae7d29d) complete. Timing: real 0.165s	user 0.122s	sys 0.040s Metrics: {"cfile_cache_miss":634,"cfile_cache_miss_bytes":28877328,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":4760,"lbm_read_time_us":12627,"lbm_reads_lt_1ms":674,"lbm_write_time_us":33390,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":642,"mutex_wait_us":1485,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":3328,"thread_start_us":72,"threads_started":1,"update_count":3000}
I20260812 06:17:31.218220 31534 maintenance_manager.cc:419] P f5fdf36185874a7a8cb879c56f869891: Scheduling FlushDeltaMemStoresOp(aa1844f8d8354659ade1bcffcae7d29d): perf score=14.095187
I20260812 06:17:31.258152 31439 maintenance_manager.cc:643] P f5fdf36185874a7a8cb879c56f869891: FlushDeltaMemStoresOp(aa1844f8d8354659ade1bcffcae7d29d) complete. Timing: real 0.040s	user 0.024s	sys 0.014s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":16911,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:17:31.258595 31534 maintenance_manager.cc:419] P f5fdf36185874a7a8cb879c56f869891: Scheduling FlushDeltaMemStoresOp(aa1844f8d8354659ade1bcffcae7d29d): perf score=2.188937
I20260812 06:17:31.269059 31439 maintenance_manager.cc:643] P f5fdf36185874a7a8cb879c56f869891: FlushDeltaMemStoresOp(aa1844f8d8354659ade1bcffcae7d29d) complete. Timing: real 0.010s	user 0.004s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3706,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:31.269493 31534 maintenance_manager.cc:419] P f5fdf36185874a7a8cb879c56f869891: Scheduling MajorDeltaCompactionOp(aa1844f8d8354659ade1bcffcae7d29d): perf score=1.000000
I20260812 06:17:31.433584 31439 maintenance_manager.cc:643] P f5fdf36185874a7a8cb879c56f869891: MajorDeltaCompactionOp(aa1844f8d8354659ade1bcffcae7d29d) complete. Timing: real 0.164s	user 0.136s	sys 0.016s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774688,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":911,"lbm_read_time_us":11130,"lbm_reads_lt_1ms":572,"lbm_write_time_us":29419,"lbm_writes_lt_1ms":543,"mutex_wait_us":47,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":15104,"update_count":2500}
I20260812 06:17:31.434108 31534 maintenance_manager.cc:419] P f5fdf36185874a7a8cb879c56f869891: Scheduling FlushDeltaMemStoresOp(aa1844f8d8354659ade1bcffcae7d29d): perf score=14.095187
I20260812 06:17:31.472419 31439 maintenance_manager.cc:643] P f5fdf36185874a7a8cb879c56f869891: FlushDeltaMemStoresOp(aa1844f8d8354659ade1bcffcae7d29d) complete. Timing: real 0.038s	user 0.032s	sys 0.004s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":16756,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:17:31.472872 31534 maintenance_manager.cc:419] P f5fdf36185874a7a8cb879c56f869891: Scheduling MajorDeltaCompactionOp(aa1844f8d8354659ade1bcffcae7d29d): perf score=1.000000
I20260812 06:17:31.599859 31439 maintenance_manager.cc:643] P f5fdf36185874a7a8cb879c56f869891: MajorDeltaCompactionOp(aa1844f8d8354659ade1bcffcae7d29d) complete. Timing: real 0.127s	user 0.098s	sys 0.028s Metrics: {"cfile_cache_miss":431,"cfile_cache_miss_bytes":20672157,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":1,"delta_iterators_relevant":1,"dirs.queue_time_us":545,"lbm_read_time_us":9059,"lbm_reads_lt_1ms":467,"lbm_write_time_us":21492,"lbm_writes_lt_1ms":443,"mutex_wait_us":276,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":2048,"update_count":2000}
I20260812 06:17:31.602077 31534 maintenance_manager.cc:419] P f5fdf36185874a7a8cb879c56f869891: Scheduling FlushDeltaMemStoresOp(aa1844f8d8354659ade1bcffcae7d29d): perf score=10.126437
I20260812 06:17:31.638192 31439 maintenance_manager.cc:643] P f5fdf36185874a7a8cb879c56f869891: FlushDeltaMemStoresOp(aa1844f8d8354659ade1bcffcae7d29d) complete. Timing: real 0.036s	user 0.018s	sys 0.016s Metrics: {"bytes_written":12307492,"delete_count":0,"lbm_write_time_us":14490,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:17:31.638687 31534 maintenance_manager.cc:419] P f5fdf36185874a7a8cb879c56f869891: Scheduling FlushDeltaMemStoresOp(aa1844f8d8354659ade1bcffcae7d29d): perf score=3.181125
I20260812 06:17:31.659523 31439 maintenance_manager.cc:643] P f5fdf36185874a7a8cb879c56f869891: FlushDeltaMemStoresOp(aa1844f8d8354659ade1bcffcae7d29d) complete. Timing: real 0.021s	user 0.011s	sys 0.000s Metrics: {"bytes_written":4389831,"delete_count":0,"lbm_write_time_us":4779,"lbm_writes_lt_1ms":110,"reinsert_count":0,"update_count":535}
I20260812 06:17:31.659981 31534 maintenance_manager.cc:419] P f5fdf36185874a7a8cb879c56f869891: Scheduling FlushDeltaMemStoresOp(aa1844f8d8354659ade1bcffcae7d29d): perf score=2.188937
I20260812 06:17:31.668831 31439 maintenance_manager.cc:643] P f5fdf36185874a7a8cb879c56f869891: FlushDeltaMemStoresOp(aa1844f8d8354659ade1bcffcae7d29d) complete. Timing: real 0.009s	user 0.008s	sys 0.000s Metrics: {"bytes_written":3815484,"delete_count":0,"lbm_write_time_us":3269,"lbm_writes_lt_1ms":96,"reinsert_count":0,"update_count":465}
I20260812 06:17:31.669200 31534 maintenance_manager.cc:419] P f5fdf36185874a7a8cb879c56f869891: Scheduling MajorDeltaCompactionOp(aa1844f8d8354659ade1bcffcae7d29d): perf score=1.000000
I20260812 06:17:31.855424 31439 maintenance_manager.cc:643] P f5fdf36185874a7a8cb879c56f869891: MajorDeltaCompactionOp(aa1844f8d8354659ade1bcffcae7d29d) complete. Timing: real 0.186s	user 0.110s	sys 0.064s Metrics: {"cfile_cache_miss":533,"cfile_cache_miss_bytes":24774807,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":268,"lbm_read_time_us":11365,"lbm_reads_lt_1ms":573,"lbm_write_time_us":35047,"lbm_writes_lt_1ms":543,"mutex_wait_us":23,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":3968,"update_count":2500}
I20260812 06:17:31.855973 31534 maintenance_manager.cc:419] P f5fdf36185874a7a8cb879c56f869891: Scheduling FlushDeltaMemStoresOp(aa1844f8d8354659ade1bcffcae7d29d): perf score=14.095187
I20260812 06:17:31.909453 31439 maintenance_manager.cc:643] P f5fdf36185874a7a8cb879c56f869891: FlushDeltaMemStoresOp(aa1844f8d8354659ade1bcffcae7d29d) complete. Timing: real 0.053s	user 0.031s	sys 0.019s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":25002,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":402,"reinsert_count":0,"update_count":2000}
I20260812 06:17:31.910154 31534 maintenance_manager.cc:419] P f5fdf36185874a7a8cb879c56f869891: Scheduling FlushDeltaMemStoresOp(aa1844f8d8354659ade1bcffcae7d29d): perf score=2.188937
I20260812 06:17:31.926234 31439 maintenance_manager.cc:643] P f5fdf36185874a7a8cb879c56f869891: FlushDeltaMemStoresOp(aa1844f8d8354659ade1bcffcae7d29d) complete. Timing: real 0.016s	user 0.014s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6222,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:31.926751 31534 maintenance_manager.cc:419] P f5fdf36185874a7a8cb879c56f869891: Scheduling MajorDeltaCompactionOp(aa1844f8d8354659ade1bcffcae7d29d): perf score=1.000000
I20260812 06:17:32.081530 31439 maintenance_manager.cc:643] P f5fdf36185874a7a8cb879c56f869891: MajorDeltaCompactionOp(aa1844f8d8354659ade1bcffcae7d29d) complete. Timing: real 0.155s	user 0.107s	sys 0.044s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774688,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":118,"lbm_read_time_us":8205,"lbm_reads_lt_1ms":564,"lbm_write_time_us":34206,"lbm_writes_lt_1ms":543,"mutex_wait_us":21,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":8192,"update_count":2500}
I20260812 06:17:32.082114 31534 maintenance_manager.cc:419] P f5fdf36185874a7a8cb879c56f869891: Scheduling FlushDeltaMemStoresOp(aa1844f8d8354659ade1bcffcae7d29d): perf score=14.095187
I20260812 06:17:32.132994 31439 maintenance_manager.cc:643] P f5fdf36185874a7a8cb879c56f869891: FlushDeltaMemStoresOp(aa1844f8d8354659ade1bcffcae7d29d) complete. Timing: real 0.051s	user 0.017s	sys 0.030s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":24892,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":402,"reinsert_count":0,"spinlock_wait_cycles":768,"update_count":2000}
I20260812 06:17:32.133563 31534 maintenance_manager.cc:419] P f5fdf36185874a7a8cb879c56f869891: Scheduling FlushDeltaMemStoresOp(aa1844f8d8354659ade1bcffcae7d29d): perf score=2.188937
I20260812 06:17:32.145704 31439 maintenance_manager.cc:643] P f5fdf36185874a7a8cb879c56f869891: FlushDeltaMemStoresOp(aa1844f8d8354659ade1bcffcae7d29d) complete. Timing: real 0.012s	user 0.010s	sys 0.000s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4734,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:32.146266 31534 maintenance_manager.cc:419] P f5fdf36185874a7a8cb879c56f869891: Scheduling MajorDeltaCompactionOp(aa1844f8d8354659ade1bcffcae7d29d): perf score=1.000000
I20260812 06:17:32.293892 31439 maintenance_manager.cc:643] P f5fdf36185874a7a8cb879c56f869891: MajorDeltaCompactionOp(aa1844f8d8354659ade1bcffcae7d29d) complete. Timing: real 0.147s	user 0.117s	sys 0.030s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774687,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":163,"lbm_read_time_us":10446,"lbm_reads_lt_1ms":572,"lbm_write_time_us":33170,"lbm_writes_lt_1ms":543,"mutex_wait_us":16,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":2432,"update_count":2500}
I20260812 06:17:32.294603 31534 maintenance_manager.cc:419] P f5fdf36185874a7a8cb879c56f869891: Scheduling FlushDeltaMemStoresOp(aa1844f8d8354659ade1bcffcae7d29d): perf score=14.095187
I20260812 06:17:32.343475 31439 maintenance_manager.cc:643] P f5fdf36185874a7a8cb879c56f869891: FlushDeltaMemStoresOp(aa1844f8d8354659ade1bcffcae7d29d) complete. Timing: real 0.049s	user 0.027s	sys 0.018s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":21953,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:17:32.344022 31534 maintenance_manager.cc:419] P f5fdf36185874a7a8cb879c56f869891: Scheduling FlushDeltaMemStoresOp(aa1844f8d8354659ade1bcffcae7d29d): perf score=2.188937
I20260812 06:17:32.354815 31439 maintenance_manager.cc:643] P f5fdf36185874a7a8cb879c56f869891: FlushDeltaMemStoresOp(aa1844f8d8354659ade1bcffcae7d29d) complete. Timing: real 0.011s	user 0.004s	sys 0.005s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3904,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:32.355369 31534 maintenance_manager.cc:419] P f5fdf36185874a7a8cb879c56f869891: Scheduling FlushMRSOp(aa1844f8d8354659ade1bcffcae7d29d): perf score=1.000000
I20260812 06:17:32.382617 31439 maintenance_manager.cc:643] P f5fdf36185874a7a8cb879c56f869891: FlushMRSOp(aa1844f8d8354659ade1bcffcae7d29d) complete. Timing: real 0.027s	user 0.021s	sys 0.006s Metrics: {"bytes_written":1275447,"cfile_init":1,"dirs.queue_time_us":59,"dirs.run_cpu_time_us":230,"dirs.run_wall_time_us":1163,"drs_written":1,"lbm_read_time_us":43,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1586,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":31}
I20260812 06:17:32.383378 31534 maintenance_manager.cc:419] P f5fdf36185874a7a8cb879c56f869891: Scheduling LogGCOp(aa1844f8d8354659ade1bcffcae7d29d): free 132571649 bytes of WAL
I20260812 06:17:32.383606 31439 log_reader.cc:385] T aa1844f8d8354659ade1bcffcae7d29d: removed 13 log segments from log reader
I20260812 06:17:32.383656 31439 log.cc:1079] T aa1844f8d8354659ade1bcffcae7d29d P f5fdf36185874a7a8cb879c56f869891: Deleting log segment in path: /tmp/dist-test-taskNVEfdO/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515447722411-31279-0/minicluster-data/ts-0-root/wals/aa1844f8d8354659ade1bcffcae7d29d/wal-000000027 (ops 130-134)
I20260812 06:17:32.383693 31439 log.cc:1079] T aa1844f8d8354659ade1bcffcae7d29d P f5fdf36185874a7a8cb879c56f869891: Deleting log segment in path: /tmp/dist-test-taskNVEfdO/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515447722411-31279-0/minicluster-data/ts-0-root/wals/aa1844f8d8354659ade1bcffcae7d29d/wal-000000028 (ops 135-138)
I20260812 06:17:32.383726 31439 log.cc:1079] T aa1844f8d8354659ade1bcffcae7d29d P f5fdf36185874a7a8cb879c56f869891: Deleting log segment in path: /tmp/dist-test-taskNVEfdO/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515447722411-31279-0/minicluster-data/ts-0-root/wals/aa1844f8d8354659ade1bcffcae7d29d/wal-000000029 (ops 139-143)
I20260812 06:17:32.383759 31439 log.cc:1079] T aa1844f8d8354659ade1bcffcae7d29d P f5fdf36185874a7a8cb879c56f869891: Deleting log segment in path: /tmp/dist-test-taskNVEfdO/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515447722411-31279-0/minicluster-data/ts-0-root/wals/aa1844f8d8354659ade1bcffcae7d29d/wal-000000030 (ops 144-148)
I20260812 06:17:32.383788 31439 log.cc:1079] T aa1844f8d8354659ade1bcffcae7d29d P f5fdf36185874a7a8cb879c56f869891: Deleting log segment in path: /tmp/dist-test-taskNVEfdO/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515447722411-31279-0/minicluster-data/ts-0-root/wals/aa1844f8d8354659ade1bcffcae7d29d/wal-000000031 (ops 149-153)
I20260812 06:17:32.383818 31439 log.cc:1079] T aa1844f8d8354659ade1bcffcae7d29d P f5fdf36185874a7a8cb879c56f869891: Deleting log segment in path: /tmp/dist-test-taskNVEfdO/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515447722411-31279-0/minicluster-data/ts-0-root/wals/aa1844f8d8354659ade1bcffcae7d29d/wal-000000032 (ops 154-158)
I20260812 06:17:32.383848 31439 log.cc:1079] T aa1844f8d8354659ade1bcffcae7d29d P f5fdf36185874a7a8cb879c56f869891: Deleting log segment in path: /tmp/dist-test-taskNVEfdO/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515447722411-31279-0/minicluster-data/ts-0-root/wals/aa1844f8d8354659ade1bcffcae7d29d/wal-000000033 (ops 159-163)
I20260812 06:17:32.383878 31439 log.cc:1079] T aa1844f8d8354659ade1bcffcae7d29d P f5fdf36185874a7a8cb879c56f869891: Deleting log segment in path: /tmp/dist-test-taskNVEfdO/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515447722411-31279-0/minicluster-data/ts-0-root/wals/aa1844f8d8354659ade1bcffcae7d29d/wal-000000034 (ops 164-168)
I20260812 06:17:32.383908 31439 log.cc:1079] T aa1844f8d8354659ade1bcffcae7d29d P f5fdf36185874a7a8cb879c56f869891: Deleting log segment in path: /tmp/dist-test-taskNVEfdO/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515447722411-31279-0/minicluster-data/ts-0-root/wals/aa1844f8d8354659ade1bcffcae7d29d/wal-000000035 (ops 169-172)
I20260812 06:17:32.383939 31439 log.cc:1079] T aa1844f8d8354659ade1bcffcae7d29d P f5fdf36185874a7a8cb879c56f869891: Deleting log segment in path: /tmp/dist-test-taskNVEfdO/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515447722411-31279-0/minicluster-data/ts-0-root/wals/aa1844f8d8354659ade1bcffcae7d29d/wal-000000036 (ops 173-177)
I20260812 06:17:32.383970 31439 log.cc:1079] T aa1844f8d8354659ade1bcffcae7d29d P f5fdf36185874a7a8cb879c56f869891: Deleting log segment in path: /tmp/dist-test-taskNVEfdO/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515447722411-31279-0/minicluster-data/ts-0-root/wals/aa1844f8d8354659ade1bcffcae7d29d/wal-000000037 (ops 178-182)
I20260812 06:17:32.383999 31439 log.cc:1079] T aa1844f8d8354659ade1bcffcae7d29d P f5fdf36185874a7a8cb879c56f869891: Deleting log segment in path: /tmp/dist-test-taskNVEfdO/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515447722411-31279-0/minicluster-data/ts-0-root/wals/aa1844f8d8354659ade1bcffcae7d29d/wal-000000038 (ops 183-187)
I20260812 06:17:32.384029 31439 log.cc:1079] T aa1844f8d8354659ade1bcffcae7d29d P f5fdf36185874a7a8cb879c56f869891: Deleting log segment in path: /tmp/dist-test-taskNVEfdO/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515447722411-31279-0/minicluster-data/ts-0-root/wals/aa1844f8d8354659ade1bcffcae7d29d/wal-000000039 (ops 188-192)
I20260812 06:17:32.407492 31439 maintenance_manager.cc:643] P f5fdf36185874a7a8cb879c56f869891: LogGCOp(aa1844f8d8354659ade1bcffcae7d29d) complete. Timing: real 0.024s	user 0.000s	sys 0.022s Metrics: {}
I20260812 06:17:32.408018 31534 maintenance_manager.cc:419] P f5fdf36185874a7a8cb879c56f869891: Scheduling FlushDeltaMemStoresOp(aa1844f8d8354659ade1bcffcae7d29d): perf score=3.181125
I20260812 06:17:32.424346 31439 maintenance_manager.cc:643] P f5fdf36185874a7a8cb879c56f869891: FlushDeltaMemStoresOp(aa1844f8d8354659ade1bcffcae7d29d) complete. Timing: real 0.016s	user 0.014s	sys 0.000s Metrics: {"bytes_written":4800077,"delete_count":0,"lbm_write_time_us":6404,"lbm_writes_lt_1ms":120,"reinsert_count":0,"update_count":585}
I20260812 06:17:32.424763 31534 maintenance_manager.cc:419] P f5fdf36185874a7a8cb879c56f869891: Scheduling UndoDeltaBlockGCOp(aa1844f8d8354659ade1bcffcae7d29d): 481 bytes on disk
I20260812 06:17:32.425117 31439 maintenance_manager.cc:643] P f5fdf36185874a7a8cb879c56f869891: UndoDeltaBlockGCOp(aa1844f8d8354659ade1bcffcae7d29d) 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:17:32.425613 31534 maintenance_manager.cc:419] P f5fdf36185874a7a8cb879c56f869891: Scheduling FlushDeltaMemStoresOp(aa1844f8d8354659ade1bcffcae7d29d): perf score=2.188937
I20260812 06:17:32.434742 31439 maintenance_manager.cc:643] P f5fdf36185874a7a8cb879c56f869891: FlushDeltaMemStoresOp(aa1844f8d8354659ade1bcffcae7d29d) complete. Timing: real 0.009s	user 0.008s	sys 0.000s Metrics: {"bytes_written":3405230,"delete_count":0,"lbm_write_time_us":2976,"lbm_writes_lt_1ms":86,"reinsert_count":0,"update_count":415}
I20260812 06:17:32.435163 31534 maintenance_manager.cc:419] P f5fdf36185874a7a8cb879c56f869891: Scheduling MajorDeltaCompactionOp(aa1844f8d8354659ade1bcffcae7d29d): perf score=1.000000
I20260812 06:17:32.578481 31279 heavy-update-compaction-itest.cc:229] Time spent updating: real 4.584s	user 1.628s	sys 0.121s
I20260812 06:17:32.639206 31439 maintenance_manager.cc:643] P f5fdf36185874a7a8cb879c56f869891: MajorDeltaCompactionOp(aa1844f8d8354659ade1bcffcae7d29d) complete. Timing: real 0.204s	user 0.152s	sys 0.044s Metrics: {"cfile_cache_miss":734,"cfile_cache_miss_bytes":32979740,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"lbm_read_time_us":13249,"lbm_reads_lt_1ms":770,"lbm_write_time_us":36128,"lbm_writes_lt_1ms":743,"peak_mem_usage":87969044,"reinsert_count":0,"spinlock_wait_cycles":896,"update_count":3500}
I20260812 06:17:32.639792 31534 maintenance_manager.cc:419] P f5fdf36185874a7a8cb879c56f869891: Scheduling FlushDeltaMemStoresOp(aa1844f8d8354659ade1bcffcae7d29d): perf score=10.126437
I20260812 06:17:32.659605 31279 heavy-update-compaction-itest.cc:265] Time spent scanning: real 0.081s	user 0.001s	sys 0.000s
I20260812 06:17:32.660218 31279 tablet_server.cc:179] TabletServer@127.30.139.193:0 shutting down...
I20260812 06:17:32.672660 31439 maintenance_manager.cc:643] P f5fdf36185874a7a8cb879c56f869891: FlushDeltaMemStoresOp(aa1844f8d8354659ade1bcffcae7d29d) complete. Timing: real 0.033s	user 0.023s	sys 0.007s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":14615,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:17:32.673153 31279 ts_tablet_manager.cc:1507] Shutting down tablet manager...
I20260812 06:17:32.673535 31279 tablet_replica.cc:333] T aa1844f8d8354659ade1bcffcae7d29d P f5fdf36185874a7a8cb879c56f869891: stopping tablet replica
I20260812 06:17:32.673801 31279 raft_consensus.cc:2243] T aa1844f8d8354659ade1bcffcae7d29d P f5fdf36185874a7a8cb879c56f869891 [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:17:32.674012 31279 raft_consensus.cc:2272] T aa1844f8d8354659ade1bcffcae7d29d P f5fdf36185874a7a8cb879c56f869891 [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:17:32.688082 31279 tablet_server.cc:196] TabletServer@127.30.139.193:0 shutdown complete.
I20260812 06:17:32.706735 31279 master.cc:562] Master@127.30.139.254:39755 shutting down...
I20260812 06:17:32.710168 31279 raft_consensus.cc:2243] T 00000000000000000000000000000000 P 6e6dbd9b2099484b927b2b6e2a180360 [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:17:32.710332 31279 raft_consensus.cc:2272] T 00000000000000000000000000000000 P 6e6dbd9b2099484b927b2b6e2a180360 [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:17:32.710402 31279 tablet_replica.cc:333] T 00000000000000000000000000000000 P 6e6dbd9b2099484b927b2b6e2a180360: stopping tablet replica
I20260812 06:17:32.722364 31279 master.cc:584] Master@127.30.139.254:39755 shutdown complete.
[       OK ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/0 (5055 ms)
[ RUN      ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/1
I20260812 06:17:32.796801 31279 internal_mini_cluster.cc:156] Creating distributed mini masters. Addrs: 127.30.139.254:46715
I20260812 06:17:32.797188 31279 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:17:32.799100 31576 instance_detector.cc:116] could not retrieve Azure instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:17:32.799149 31574 instance_detector.cc:116] could not retrieve AWS instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:17:32.799270 31279 server_base.cc:1061] running on GCE node
W20260812 06:17:32.799309 31578 instance_detector.cc:116] could not retrieve OpenStack instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:17:32.799500 31279 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:17:32.799538 31279 system_unsync_time.cc:38] NTP support is disabled. Clock error bounds will not be accurate. This configuration is not suitable for distributed clusters.
I20260812 06:17:32.799552 31279 hybrid_clock.cc:648] HybridClock initialized: now 1786515452799553 us; error 0 us; skew 500 ppm
I20260812 06:17:32.800311 31279 webserver.cc:533] Webserver started at http://127.30.139.254:40007/ using document root <none> and password file <none>
I20260812 06:17:32.800441 31279 fs_manager.cc:362] Metadata directory not provided
I20260812 06:17:32.800477 31279 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:17:32.800530 31279 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:17:32.800880 31279 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskNVEfdO/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515447722411-31279-0/minicluster-data/master-0-root/instance:
uuid: "1d7a361defbe4180857dd9bf3de21d97"
format_stamp: "Formatted at 2026-08-12 06:17:32 on dist-test-slave-cvwc"
I20260812 06:17:32.802798 31279 fs_manager.cc:696] Time spent creating directory manager: real 0.002s	user 0.002s	sys 0.000s
I20260812 06:17:32.803607 31586 log_block_manager.cc:4127] Time spent loading block containers with low live blocks: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:17:32.803813 31279 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.001s	sys 0.000s
I20260812 06:17:32.803887 31279 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskNVEfdO/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515447722411-31279-0/minicluster-data/master-0-root
uuid: "1d7a361defbe4180857dd9bf3de21d97"
format_stamp: "Formatted at 2026-08-12 06:17:32 on dist-test-slave-cvwc"
I20260812 06:17:32.803953 31279 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskNVEfdO/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515447722411-31279-0/minicluster-data/master-0-root
metadata directory: /tmp/dist-test-taskNVEfdO/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515447722411-31279-0/minicluster-data/master-0-root
1 data directories: /tmp/dist-test-taskNVEfdO/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515447722411-31279-0/minicluster-data/master-0-root/data
Total live blocks: 0
Total live bytes: 0
Total live bytes (after alignment): 0
Total number of LBM containers: 0 (0 full)
Did not check for missing blocks
Did not check for orphaned blocks
Total full LBM containers with extra space: 0 (0 repaired)
Total full LBM container extra space in bytes: 0 (0 repaired)
Total incomplete LBM containers: 0 (0 repaired)
Total LBM partial records: 0 (0 repaired)
Total corrupted LBM metadata records in RocksDB: 0 (0 repaired)
I20260812 06:17:32.811339 31279 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:17:32.811627 31279 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:17:32.815382 31279 rpc_server.cc:307] RPC server started. Bound to: 127.30.139.254:46715
I20260812 06:17:32.820816 31670 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.30.139.254:46715 every 8 connection(s)
I20260812 06:17:32.821220 31671 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet 00000000000000000000000000000000. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:17:32.823017 31671 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P 1d7a361defbe4180857dd9bf3de21d97: Bootstrap starting.
I20260812 06:17:32.823763 31671 tablet_bootstrap.cc:654] T 00000000000000000000000000000000 P 1d7a361defbe4180857dd9bf3de21d97: Neither blocks nor log segments found. Creating new log.
I20260812 06:17:32.824657 31671 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P 1d7a361defbe4180857dd9bf3de21d97: No bootstrap required, opened a new log
I20260812 06:17:32.825023 31671 raft_consensus.cc:359] T 00000000000000000000000000000000 P 1d7a361defbe4180857dd9bf3de21d97 [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "1d7a361defbe4180857dd9bf3de21d97" member_type: VOTER }
I20260812 06:17:32.825110 31671 raft_consensus.cc:385] T 00000000000000000000000000000000 P 1d7a361defbe4180857dd9bf3de21d97 [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:17:32.825142 31671 raft_consensus.cc:740] T 00000000000000000000000000000000 P 1d7a361defbe4180857dd9bf3de21d97 [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: 1d7a361defbe4180857dd9bf3de21d97, State: Initialized, Role: FOLLOWER
I20260812 06:17:32.825270 31671 consensus_queue.cc:260] T 00000000000000000000000000000000 P 1d7a361defbe4180857dd9bf3de21d97 [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: "1d7a361defbe4180857dd9bf3de21d97" member_type: VOTER }
I20260812 06:17:32.825348 31671 raft_consensus.cc:399] T 00000000000000000000000000000000 P 1d7a361defbe4180857dd9bf3de21d97 [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:17:32.825388 31671 raft_consensus.cc:493] T 00000000000000000000000000000000 P 1d7a361defbe4180857dd9bf3de21d97 [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:17:32.825436 31671 raft_consensus.cc:3060] T 00000000000000000000000000000000 P 1d7a361defbe4180857dd9bf3de21d97 [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:17:32.826126 31671 raft_consensus.cc:515] T 00000000000000000000000000000000 P 1d7a361defbe4180857dd9bf3de21d97 [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "1d7a361defbe4180857dd9bf3de21d97" member_type: VOTER }
I20260812 06:17:32.826251 31671 leader_election.cc:304] T 00000000000000000000000000000000 P 1d7a361defbe4180857dd9bf3de21d97 [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: 1d7a361defbe4180857dd9bf3de21d97; no voters: 
I20260812 06:17:32.826419 31671 leader_election.cc:290] T 00000000000000000000000000000000 P 1d7a361defbe4180857dd9bf3de21d97 [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:17:32.826522 31674 raft_consensus.cc:2804] T 00000000000000000000000000000000 P 1d7a361defbe4180857dd9bf3de21d97 [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:17:32.826709 31674 raft_consensus.cc:697] T 00000000000000000000000000000000 P 1d7a361defbe4180857dd9bf3de21d97 [term 1 LEADER]: Becoming Leader. State: Replica: 1d7a361defbe4180857dd9bf3de21d97, State: Running, Role: LEADER
I20260812 06:17:32.826845 31671 sys_catalog.cc:565] T 00000000000000000000000000000000 P 1d7a361defbe4180857dd9bf3de21d97 [sys.catalog]: configured and running, proceeding with master startup.
I20260812 06:17:32.826841 31674 consensus_queue.cc:237] T 00000000000000000000000000000000 P 1d7a361defbe4180857dd9bf3de21d97 [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: "1d7a361defbe4180857dd9bf3de21d97" member_type: VOTER }
I20260812 06:17:32.827277 31676 sys_catalog.cc:455] T 00000000000000000000000000000000 P 1d7a361defbe4180857dd9bf3de21d97 [sys.catalog]: SysCatalogTable state changed. Reason: New leader 1d7a361defbe4180857dd9bf3de21d97. Latest consensus state: current_term: 1 leader_uuid: "1d7a361defbe4180857dd9bf3de21d97" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "1d7a361defbe4180857dd9bf3de21d97" member_type: VOTER } }
I20260812 06:17:32.827265 31675 sys_catalog.cc:455] T 00000000000000000000000000000000 P 1d7a361defbe4180857dd9bf3de21d97 [sys.catalog]: SysCatalogTable state changed. Reason: RaftConsensus started. Latest consensus state: current_term: 1 leader_uuid: "1d7a361defbe4180857dd9bf3de21d97" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "1d7a361defbe4180857dd9bf3de21d97" member_type: VOTER } }
I20260812 06:17:32.827379 31676 sys_catalog.cc:458] T 00000000000000000000000000000000 P 1d7a361defbe4180857dd9bf3de21d97 [sys.catalog]: This master's current role is: LEADER
I20260812 06:17:32.827392 31675 sys_catalog.cc:458] T 00000000000000000000000000000000 P 1d7a361defbe4180857dd9bf3de21d97 [sys.catalog]: This master's current role is: LEADER
I20260812 06:17:32.827651 31681 catalog_manager.cc:1511] Loading table and tablet metadata into memory...
I20260812 06:17:32.828373 31681 catalog_manager.cc:1520] Initializing Kudu cluster ID...
I20260812 06:17:32.828665 31279 internal_mini_cluster.cc:184] Waiting to initialize catalog manager on master 0
I20260812 06:17:32.830075 31681 catalog_manager.cc:1383] Generated new cluster ID: 320c0e2d2fb042e8b79f2e6852baba16
I20260812 06:17:32.830130 31681 catalog_manager.cc:1531] Initializing Kudu internal certificate authority...
I20260812 06:17:32.839139 31681 catalog_manager.cc:1406] Generated new certificate authority record
I20260812 06:17:32.839644 31681 catalog_manager.cc:1540] Loading token signing keys...
I20260812 06:17:32.846342 31681 catalog_manager.cc:6092] T 00000000000000000000000000000000 P 1d7a361defbe4180857dd9bf3de21d97: Generated new TSK 0
I20260812 06:17:32.846516 31681 catalog_manager.cc:1550] Initializing in-progress tserver states...
I20260812 06:17:32.860782 31279 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:17:32.862562 31704 instance_detector.cc:116] could not retrieve AWS instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:17:32.862651 31279 server_base.cc:1061] running on GCE node
W20260812 06:17:32.862710 31705 instance_detector.cc:116] could not retrieve Azure instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:17:32.862622 31707 instance_detector.cc:116] could not retrieve OpenStack instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:17:32.862970 31279 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:17:32.863013 31279 system_unsync_time.cc:38] NTP support is disabled. Clock error bounds will not be accurate. This configuration is not suitable for distributed clusters.
I20260812 06:17:32.863027 31279 hybrid_clock.cc:648] HybridClock initialized: now 1786515452863028 us; error 0 us; skew 500 ppm
I20260812 06:17:32.863786 31279 webserver.cc:533] Webserver started at http://127.30.139.193:40365/ using document root <none> and password file <none>
I20260812 06:17:32.863924 31279 fs_manager.cc:362] Metadata directory not provided
I20260812 06:17:32.863965 31279 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:17:32.864020 31279 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:17:32.864339 31279 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskNVEfdO/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515447722411-31279-0/minicluster-data/ts-0-root/instance:
uuid: "27d891b4777c49d0862a5f3a6a8206d3"
format_stamp: "Formatted at 2026-08-12 06:17:32 on dist-test-slave-cvwc"
I20260812 06:17:32.865692 31279 fs_manager.cc:696] Time spent creating directory manager: real 0.001s	user 0.000s	sys 0.002s
I20260812 06:17:32.866583 31712 log_block_manager.cc:4127] Time spent loading block containers with low live blocks: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:17:32.866787 31279 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.000s	sys 0.001s
I20260812 06:17:32.866865 31279 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskNVEfdO/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515447722411-31279-0/minicluster-data/ts-0-root
uuid: "27d891b4777c49d0862a5f3a6a8206d3"
format_stamp: "Formatted at 2026-08-12 06:17:32 on dist-test-slave-cvwc"
I20260812 06:17:32.866931 31279 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskNVEfdO/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515447722411-31279-0/minicluster-data/ts-0-root
metadata directory: /tmp/dist-test-taskNVEfdO/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515447722411-31279-0/minicluster-data/ts-0-root
1 data directories: /tmp/dist-test-taskNVEfdO/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515447722411-31279-0/minicluster-data/ts-0-root/data
Total live blocks: 0
Total live bytes: 0
Total live bytes (after alignment): 0
Total number of LBM containers: 0 (0 full)
Did not check for missing blocks
Did not check for orphaned blocks
Total full LBM containers with extra space: 0 (0 repaired)
Total full LBM container extra space in bytes: 0 (0 repaired)
Total incomplete LBM containers: 0 (0 repaired)
Total LBM partial records: 0 (0 repaired)
Total corrupted LBM metadata records in RocksDB: 0 (0 repaired)
I20260812 06:17:32.878759 31279 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:17:32.879083 31279 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:17:32.879328 31279 txn_system_client.cc:432] TxnSystemClient initialization is disabled...
I20260812 06:17:32.879729 31279 ts_tablet_manager.cc:585] Loaded tablet metadata (0 total tablets, 0 live tablets)
I20260812 06:17:32.879766 31279 ts_tablet_manager.cc:531] Time spent load tablet metadata: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:17:32.879806 31279 ts_tablet_manager.cc:616] Registered 0 tablets
I20260812 06:17:32.879839 31279 ts_tablet_manager.cc:595] Time spent register tablets: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:17:32.883728 31279 rpc_server.cc:307] RPC server started. Bound to: 127.30.139.193:44705
I20260812 06:17:32.884088 31820 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.30.139.193:44705 every 8 connection(s)
I20260812 06:17:32.891716 31821 heartbeater.cc:344] Connected to a master server at 127.30.139.254:46715
I20260812 06:17:32.891803 31821 heartbeater.cc:461] Registering TS with master...
I20260812 06:17:32.891993 31821 heartbeater.cc:507] Master 127.30.139.254:46715 requested a full tablet report, sending...
I20260812 06:17:32.892581 31614 ts_manager.cc:194] Registered new tserver with Master: 27d891b4777c49d0862a5f3a6a8206d3 (127.30.139.193:44705)
I20260812 06:17:32.892961 31279 internal_mini_cluster.cc:371] 1 TS(s) registered with all masters after 0.0087315s
I20260812 06:17:32.893304 31614 master_service.cc:502] Signed X509 certificate for tserver {username='slave'} at 127.0.0.1:54700
I20260812 06:17:32.899451 31614 catalog_manager.cc:2283] Servicing CreateTable request from {username='slave'} at 127.0.0.1:54716:
name: "heavy-update-compaction-test"
schema {
  columns {
    name: "key"
    type: INT64
    is_key: true
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_a"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_b"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_c"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_d"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_e"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
}
num_replicas: 1
split_rows_range_bounds {
}
partition_schema {
  range_schema {
  }
}
I20260812 06:17:32.907579 31762 tablet_service.cc:1511] Processing CreateTablet for tablet 7c4b346b400142589fccbe7feafab4ee (DEFAULT_TABLE table=heavy-update-compaction-test [id=af45a008a87749b197b9a618842b2202]), partition=
I20260812 06:17:32.907837 31762 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet 7c4b346b400142589fccbe7feafab4ee. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:17:32.909643 31840 tablet_bootstrap.cc:492] T 7c4b346b400142589fccbe7feafab4ee P 27d891b4777c49d0862a5f3a6a8206d3: Bootstrap starting.
I20260812 06:17:32.910491 31840 tablet_bootstrap.cc:654] T 7c4b346b400142589fccbe7feafab4ee P 27d891b4777c49d0862a5f3a6a8206d3: Neither blocks nor log segments found. Creating new log.
I20260812 06:17:32.911410 31840 tablet_bootstrap.cc:492] T 7c4b346b400142589fccbe7feafab4ee P 27d891b4777c49d0862a5f3a6a8206d3: No bootstrap required, opened a new log
I20260812 06:17:32.911479 31840 ts_tablet_manager.cc:1403] T 7c4b346b400142589fccbe7feafab4ee P 27d891b4777c49d0862a5f3a6a8206d3: Time spent bootstrapping tablet: real 0.002s	user 0.001s	sys 0.000s
I20260812 06:17:32.911818 31840 raft_consensus.cc:359] T 7c4b346b400142589fccbe7feafab4ee P 27d891b4777c49d0862a5f3a6a8206d3 [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "27d891b4777c49d0862a5f3a6a8206d3" member_type: VOTER last_known_addr { host: "127.30.139.193" port: 44705 } }
I20260812 06:17:32.911898 31840 raft_consensus.cc:385] T 7c4b346b400142589fccbe7feafab4ee P 27d891b4777c49d0862a5f3a6a8206d3 [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:17:32.911924 31840 raft_consensus.cc:740] T 7c4b346b400142589fccbe7feafab4ee P 27d891b4777c49d0862a5f3a6a8206d3 [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: 27d891b4777c49d0862a5f3a6a8206d3, State: Initialized, Role: FOLLOWER
I20260812 06:17:32.912019 31840 consensus_queue.cc:260] T 7c4b346b400142589fccbe7feafab4ee P 27d891b4777c49d0862a5f3a6a8206d3 [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: "27d891b4777c49d0862a5f3a6a8206d3" member_type: VOTER last_known_addr { host: "127.30.139.193" port: 44705 } }
I20260812 06:17:32.912075 31840 raft_consensus.cc:399] T 7c4b346b400142589fccbe7feafab4ee P 27d891b4777c49d0862a5f3a6a8206d3 [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:17:32.912102 31840 raft_consensus.cc:493] T 7c4b346b400142589fccbe7feafab4ee P 27d891b4777c49d0862a5f3a6a8206d3 [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:17:32.912134 31840 raft_consensus.cc:3060] T 7c4b346b400142589fccbe7feafab4ee P 27d891b4777c49d0862a5f3a6a8206d3 [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:17:32.912775 31840 raft_consensus.cc:515] T 7c4b346b400142589fccbe7feafab4ee P 27d891b4777c49d0862a5f3a6a8206d3 [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "27d891b4777c49d0862a5f3a6a8206d3" member_type: VOTER last_known_addr { host: "127.30.139.193" port: 44705 } }
I20260812 06:17:32.912911 31840 leader_election.cc:304] T 7c4b346b400142589fccbe7feafab4ee P 27d891b4777c49d0862a5f3a6a8206d3 [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: 27d891b4777c49d0862a5f3a6a8206d3; no voters: 
I20260812 06:17:32.913107 31840 leader_election.cc:290] T 7c4b346b400142589fccbe7feafab4ee P 27d891b4777c49d0862a5f3a6a8206d3 [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:17:32.913213 31842 raft_consensus.cc:2804] T 7c4b346b400142589fccbe7feafab4ee P 27d891b4777c49d0862a5f3a6a8206d3 [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:17:32.913378 31842 raft_consensus.cc:697] T 7c4b346b400142589fccbe7feafab4ee P 27d891b4777c49d0862a5f3a6a8206d3 [term 1 LEADER]: Becoming Leader. State: Replica: 27d891b4777c49d0862a5f3a6a8206d3, State: Running, Role: LEADER
I20260812 06:17:32.913435 31821 heartbeater.cc:499] Master 127.30.139.254:46715 was elected leader, sending a full tablet report...
I20260812 06:17:32.913509 31842 consensus_queue.cc:237] T 7c4b346b400142589fccbe7feafab4ee P 27d891b4777c49d0862a5f3a6a8206d3 [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: "27d891b4777c49d0862a5f3a6a8206d3" member_type: VOTER last_known_addr { host: "127.30.139.193" port: 44705 } }
I20260812 06:17:32.913690 31840 ts_tablet_manager.cc:1434] T 7c4b346b400142589fccbe7feafab4ee P 27d891b4777c49d0862a5f3a6a8206d3: Time spent starting tablet: real 0.002s	user 0.002s	sys 0.000s
I20260812 06:17:32.914741 31614 catalog_manager.cc:5719] T 7c4b346b400142589fccbe7feafab4ee P 27d891b4777c49d0862a5f3a6a8206d3 reported cstate change: term changed from 0 to 1, leader changed from <none> to 27d891b4777c49d0862a5f3a6a8206d3 (127.30.139.193). New cstate: current_term: 1 leader_uuid: "27d891b4777c49d0862a5f3a6a8206d3" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "27d891b4777c49d0862a5f3a6a8206d3" member_type: VOTER last_known_addr { host: "127.30.139.193" port: 44705 } health_report { overall_health: HEALTHY } } }
I20260812 06:17:32.966229 31279 heavy-update-compaction-itest.cc:215] Time spent inserting: real 0.048s	user 0.013s	sys 0.008s
I20260812 06:17:33.134706 31822 maintenance_manager.cc:419] P 27d891b4777c49d0862a5f3a6a8206d3: Scheduling FlushMRSOp(7c4b346b400142589fccbe7feafab4ee): perf score=23.023690
I20260812 06:17:33.285696 31719 maintenance_manager.cc:643] P 27d891b4777c49d0862a5f3a6a8206d3: FlushMRSOp(7c4b346b400142589fccbe7feafab4ee) complete. Timing: real 0.151s	user 0.102s	sys 0.044s Metrics: {"bytes_written":13784357,"cfile_init":1,"delete_count":0,"dirs.queue_time_us":50,"dirs.run_cpu_time_us":175,"dirs.run_wall_time_us":694,"drs_written":1,"lbm_read_time_us":45,"lbm_reads_lt_1ms":4,"lbm_write_time_us":40480,"lbm_writes_lt_1ms":903,"mutex_wait_us":181,"peak_mem_usage":0,"reinsert_count":0,"rows_written":106,"spinlock_wait_cycles":4352,"update_count":1680}
I20260812 06:17:33.286410 31822 maintenance_manager.cc:419] P 27d891b4777c49d0862a5f3a6a8206d3: Scheduling LogGCOp(7c4b346b400142589fccbe7feafab4ee): free 29057938 bytes of WAL
I20260812 06:17:33.286664 31719 log_reader.cc:385] T 7c4b346b400142589fccbe7feafab4ee: removed 3 log segments from log reader
I20260812 06:17:33.286713 31719 log.cc:1079] T 7c4b346b400142589fccbe7feafab4ee P 27d891b4777c49d0862a5f3a6a8206d3: Deleting log segment in path: /tmp/dist-test-taskNVEfdO/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515447722411-31279-0/minicluster-data/ts-0-root/wals/7c4b346b400142589fccbe7feafab4ee/wal-000000001 (ops 1-6)
I20260812 06:17:33.286752 31719 log.cc:1079] T 7c4b346b400142589fccbe7feafab4ee P 27d891b4777c49d0862a5f3a6a8206d3: Deleting log segment in path: /tmp/dist-test-taskNVEfdO/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515447722411-31279-0/minicluster-data/ts-0-root/wals/7c4b346b400142589fccbe7feafab4ee/wal-000000002 (ops 7-10)
I20260812 06:17:33.286785 31719 log.cc:1079] T 7c4b346b400142589fccbe7feafab4ee P 27d891b4777c49d0862a5f3a6a8206d3: Deleting log segment in path: /tmp/dist-test-taskNVEfdO/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515447722411-31279-0/minicluster-data/ts-0-root/wals/7c4b346b400142589fccbe7feafab4ee/wal-000000003 (ops 11-15)
I20260812 06:17:33.291060 31719 maintenance_manager.cc:643] P 27d891b4777c49d0862a5f3a6a8206d3: LogGCOp(7c4b346b400142589fccbe7feafab4ee) complete. Timing: real 0.004s	user 0.000s	sys 0.003s Metrics: {}
I20260812 06:17:33.291501 31822 maintenance_manager.cc:419] P 27d891b4777c49d0862a5f3a6a8206d3: Scheduling UndoDeltaBlockGCOp(7c4b346b400142589fccbe7feafab4ee): 20924071 bytes on disk
I20260812 06:17:33.291975 31719 maintenance_manager.cc:643] P 27d891b4777c49d0862a5f3a6a8206d3: UndoDeltaBlockGCOp(7c4b346b400142589fccbe7feafab4ee) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":49,"lbm_reads_lt_1ms":4}
I20260812 06:17:33.292397 31822 maintenance_manager.cc:419] P 27d891b4777c49d0862a5f3a6a8206d3: Scheduling FlushDeltaMemStoresOp(7c4b346b400142589fccbe7feafab4ee): perf score=2.188937
I20260812 06:17:33.301864 31719 maintenance_manager.cc:643] P 27d891b4777c49d0862a5f3a6a8206d3: FlushDeltaMemStoresOp(7c4b346b400142589fccbe7feafab4ee) complete. Timing: real 0.009s	user 0.009s	sys 0.000s Metrics: {"bytes_written":3651388,"delete_count":0,"lbm_write_time_us":3199,"lbm_writes_lt_1ms":92,"reinsert_count":0,"update_count":445}
I20260812 06:17:33.302225 31822 maintenance_manager.cc:419] P 27d891b4777c49d0862a5f3a6a8206d3: Scheduling FlushDeltaMemStoresOp(7c4b346b400142589fccbe7feafab4ee): perf score=1.196750
I20260812 06:17:33.311563 31719 maintenance_manager.cc:643] P 27d891b4777c49d0862a5f3a6a8206d3: FlushDeltaMemStoresOp(7c4b346b400142589fccbe7feafab4ee) complete. Timing: real 0.009s	user 0.008s	sys 0.000s Metrics: {"bytes_written":2666779,"delete_count":0,"lbm_write_time_us":3284,"lbm_writes_lt_1ms":68,"reinsert_count":0,"update_count":325}
I20260812 06:17:33.311896 31822 maintenance_manager.cc:419] P 27d891b4777c49d0862a5f3a6a8206d3: Scheduling MajorDeltaCompactionOp(7c4b346b400142589fccbe7feafab4ee): perf score=1.000000
I20260812 06:17:33.462013 31719 maintenance_manager.cc:643] P 27d891b4777c49d0862a5f3a6a8206d3: MajorDeltaCompactionOp(7c4b346b400142589fccbe7feafab4ee) complete. Timing: real 0.150s	user 0.121s	sys 0.024s Metrics: {"cfile_cache_miss":523,"cfile_cache_miss_bytes":24446489,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":846,"lbm_read_time_us":11725,"lbm_reads_lt_1ms":559,"lbm_write_time_us":24914,"lbm_writes_lt_1ms":533,"mutex_wait_us":45,"peak_mem_usage":61665166,"reinsert_count":0,"spinlock_wait_cycles":8320,"thread_start_us":320,"threads_started":5,"update_count":2450}
I20260812 06:17:33.462489 31822 maintenance_manager.cc:419] P 27d891b4777c49d0862a5f3a6a8206d3: Scheduling FlushDeltaMemStoresOp(7c4b346b400142589fccbe7feafab4ee): perf score=14.095187
I20260812 06:17:33.508996 31719 maintenance_manager.cc:643] P 27d891b4777c49d0862a5f3a6a8206d3: FlushDeltaMemStoresOp(7c4b346b400142589fccbe7feafab4ee) complete. Timing: real 0.046s	user 0.017s	sys 0.024s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":19296,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:17:33.509438 31822 maintenance_manager.cc:419] P 27d891b4777c49d0862a5f3a6a8206d3: Scheduling FlushDeltaMemStoresOp(7c4b346b400142589fccbe7feafab4ee): perf score=2.188937
I20260812 06:17:33.518888 31719 maintenance_manager.cc:643] P 27d891b4777c49d0862a5f3a6a8206d3: FlushDeltaMemStoresOp(7c4b346b400142589fccbe7feafab4ee) complete. Timing: real 0.009s	user 0.008s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3349,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:33.519330 31822 maintenance_manager.cc:419] P 27d891b4777c49d0862a5f3a6a8206d3: Scheduling MajorDeltaCompactionOp(7c4b346b400142589fccbe7feafab4ee): perf score=1.000000
I20260812 06:17:33.669034 31719 maintenance_manager.cc:643] P 27d891b4777c49d0862a5f3a6a8206d3: MajorDeltaCompactionOp(7c4b346b400142589fccbe7feafab4ee) complete. Timing: real 0.149s	user 0.117s	sys 0.026s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24856654,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":152,"lbm_read_time_us":10182,"lbm_reads_lt_1ms":572,"lbm_write_time_us":25868,"lbm_writes_lt_1ms":543,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":16640,"update_count":2500}
I20260812 06:17:33.669654 31822 maintenance_manager.cc:419] P 27d891b4777c49d0862a5f3a6a8206d3: Scheduling FlushDeltaMemStoresOp(7c4b346b400142589fccbe7feafab4ee): perf score=12.110812
I20260812 06:17:33.715768 31719 maintenance_manager.cc:643] P 27d891b4777c49d0862a5f3a6a8206d3: FlushDeltaMemStoresOp(7c4b346b400142589fccbe7feafab4ee) complete. Timing: real 0.046s	user 0.027s	sys 0.016s Metrics: {"bytes_written":13661284,"delete_count":0,"lbm_write_time_us":20108,"lbm_writes_lt_1ms":336,"reinsert_count":0,"update_count":1665}
I20260812 06:17:33.716279 31822 maintenance_manager.cc:419] P 27d891b4777c49d0862a5f3a6a8206d3: Scheduling FlushDeltaMemStoresOp(7c4b346b400142589fccbe7feafab4ee): perf score=1.196750
I20260812 06:17:33.734900 31719 maintenance_manager.cc:643] P 27d891b4777c49d0862a5f3a6a8206d3: FlushDeltaMemStoresOp(7c4b346b400142589fccbe7feafab4ee) complete. Timing: real 0.018s	user 0.004s	sys 0.004s Metrics: {"bytes_written":3159084,"delete_count":0,"lbm_write_time_us":3142,"lbm_writes_lt_1ms":80,"reinsert_count":0,"update_count":385}
I20260812 06:17:33.735360 31822 maintenance_manager.cc:419] P 27d891b4777c49d0862a5f3a6a8206d3: Scheduling FlushDeltaMemStoresOp(7c4b346b400142589fccbe7feafab4ee): perf score=2.188937
I20260812 06:17:33.748111 31719 maintenance_manager.cc:643] P 27d891b4777c49d0862a5f3a6a8206d3: FlushDeltaMemStoresOp(7c4b346b400142589fccbe7feafab4ee) complete. Timing: real 0.013s	user 0.011s	sys 0.000s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":4622,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:17:33.748610 31822 maintenance_manager.cc:419] P 27d891b4777c49d0862a5f3a6a8206d3: Scheduling MajorDeltaCompactionOp(7c4b346b400142589fccbe7feafab4ee): perf score=1.000000
I20260812 06:17:33.909866 31719 maintenance_manager.cc:643] P 27d891b4777c49d0862a5f3a6a8206d3: MajorDeltaCompactionOp(7c4b346b400142589fccbe7feafab4ee) complete. Timing: real 0.161s	user 0.106s	sys 0.048s Metrics: {"cfile_cache_miss":533,"cfile_cache_miss_bytes":24856738,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":500,"lbm_read_time_us":11169,"lbm_reads_lt_1ms":573,"lbm_write_time_us":26123,"lbm_writes_lt_1ms":543,"mutex_wait_us":22,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":9856,"update_count":2500}
I20260812 06:17:33.910465 31822 maintenance_manager.cc:419] P 27d891b4777c49d0862a5f3a6a8206d3: Scheduling FlushDeltaMemStoresOp(7c4b346b400142589fccbe7feafab4ee): perf score=14.095187
I20260812 06:17:33.960256 31719 maintenance_manager.cc:643] P 27d891b4777c49d0862a5f3a6a8206d3: FlushDeltaMemStoresOp(7c4b346b400142589fccbe7feafab4ee) complete. Timing: real 0.050s	user 0.020s	sys 0.020s Metrics: {"bytes_written":16409900,"delete_count":0,"lbm_write_time_us":18830,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:17:33.960714 31822 maintenance_manager.cc:419] P 27d891b4777c49d0862a5f3a6a8206d3: Scheduling FlushDeltaMemStoresOp(7c4b346b400142589fccbe7feafab4ee): perf score=2.188937
I20260812 06:17:33.970141 31719 maintenance_manager.cc:643] P 27d891b4777c49d0862a5f3a6a8206d3: FlushDeltaMemStoresOp(7c4b346b400142589fccbe7feafab4ee) complete. Timing: real 0.009s	user 0.009s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3532,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:33.970531 31822 maintenance_manager.cc:419] P 27d891b4777c49d0862a5f3a6a8206d3: Scheduling MajorDeltaCompactionOp(7c4b346b400142589fccbe7feafab4ee): perf score=1.000000
I20260812 06:17:34.133591 31719 maintenance_manager.cc:643] P 27d891b4777c49d0862a5f3a6a8206d3: MajorDeltaCompactionOp(7c4b346b400142589fccbe7feafab4ee) complete. Timing: real 0.163s	user 0.107s	sys 0.056s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24856652,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":231,"lbm_read_time_us":11555,"lbm_reads_lt_1ms":572,"lbm_write_time_us":25567,"lbm_writes_lt_1ms":543,"mutex_wait_us":31,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":20352,"update_count":2500}
I20260812 06:17:34.134135 31822 maintenance_manager.cc:419] P 27d891b4777c49d0862a5f3a6a8206d3: Scheduling FlushDeltaMemStoresOp(7c4b346b400142589fccbe7feafab4ee): perf score=14.095187
I20260812 06:17:34.187711 31719 maintenance_manager.cc:643] P 27d891b4777c49d0862a5f3a6a8206d3: FlushDeltaMemStoresOp(7c4b346b400142589fccbe7feafab4ee) complete. Timing: real 0.053s	user 0.033s	sys 0.019s Metrics: {"bytes_written":16409900,"delete_count":0,"lbm_write_time_us":19740,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:17:34.188194 31822 maintenance_manager.cc:419] P 27d891b4777c49d0862a5f3a6a8206d3: Scheduling FlushDeltaMemStoresOp(7c4b346b400142589fccbe7feafab4ee): perf score=2.188937
I20260812 06:17:34.202430 31719 maintenance_manager.cc:643] P 27d891b4777c49d0862a5f3a6a8206d3: FlushDeltaMemStoresOp(7c4b346b400142589fccbe7feafab4ee) complete. Timing: real 0.014s	user 0.008s	sys 0.005s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":5472,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:34.202816 31822 maintenance_manager.cc:419] P 27d891b4777c49d0862a5f3a6a8206d3: Scheduling MajorDeltaCompactionOp(7c4b346b400142589fccbe7feafab4ee): perf score=1.000000
I20260812 06:17:34.367578 31719 maintenance_manager.cc:643] P 27d891b4777c49d0862a5f3a6a8206d3: MajorDeltaCompactionOp(7c4b346b400142589fccbe7feafab4ee) complete. Timing: real 0.165s	user 0.109s	sys 0.053s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24856651,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":114,"lbm_read_time_us":10890,"lbm_reads_lt_1ms":572,"lbm_write_time_us":25774,"lbm_writes_lt_1ms":543,"mutex_wait_us":61,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":768,"update_count":2500}
I20260812 06:17:34.368369 31822 maintenance_manager.cc:419] P 27d891b4777c49d0862a5f3a6a8206d3: Scheduling FlushDeltaMemStoresOp(7c4b346b400142589fccbe7feafab4ee): perf score=11.118625
I20260812 06:17:34.397995 31719 maintenance_manager.cc:643] P 27d891b4777c49d0862a5f3a6a8206d3: FlushDeltaMemStoresOp(7c4b346b400142589fccbe7feafab4ee) complete. Timing: real 0.029s	user 0.017s	sys 0.012s Metrics: {"bytes_written":12717736,"delete_count":0,"lbm_write_time_us":11977,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:17:34.398430 31822 maintenance_manager.cc:419] P 27d891b4777c49d0862a5f3a6a8206d3: Scheduling FlushDeltaMemStoresOp(7c4b346b400142589fccbe7feafab4ee): perf score=2.188937
I20260812 06:17:34.426263 31719 maintenance_manager.cc:643] P 27d891b4777c49d0862a5f3a6a8206d3: FlushDeltaMemStoresOp(7c4b346b400142589fccbe7feafab4ee) complete. Timing: real 0.028s	user 0.011s	sys 0.000s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3671,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:17:34.426774 31822 maintenance_manager.cc:419] P 27d891b4777c49d0862a5f3a6a8206d3: Scheduling FlushDeltaMemStoresOp(7c4b346b400142589fccbe7feafab4ee): perf score=2.188937
I20260812 06:17:34.441402 31719 maintenance_manager.cc:643] P 27d891b4777c49d0862a5f3a6a8206d3: FlushDeltaMemStoresOp(7c4b346b400142589fccbe7feafab4ee) complete. Timing: real 0.014s	user 0.008s	sys 0.004s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":5482,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:34.441907 31822 maintenance_manager.cc:419] P 27d891b4777c49d0862a5f3a6a8206d3: Scheduling FlushMRSOp(7c4b346b400142589fccbe7feafab4ee): perf score=1.000000
I20260812 06:17:34.474898 31719 maintenance_manager.cc:643] P 27d891b4777c49d0862a5f3a6a8206d3: FlushMRSOp(7c4b346b400142589fccbe7feafab4ee) complete. Timing: real 0.033s	user 0.025s	sys 0.000s Metrics: {"bytes_written":1193503,"cfile_init":1,"dirs.queue_time_us":63,"dirs.run_cpu_time_us":176,"dirs.run_wall_time_us":1178,"drs_written":1,"lbm_read_time_us":40,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1268,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":29}
I20260812 06:17:34.475495 31822 maintenance_manager.cc:419] P 27d891b4777c49d0862a5f3a6a8206d3: Scheduling LogGCOp(7c4b346b400142589fccbe7feafab4ee): free 112239338 bytes of WAL
I20260812 06:17:34.475708 31719 log_reader.cc:385] T 7c4b346b400142589fccbe7feafab4ee: removed 11 log segments from log reader
I20260812 06:17:34.475765 31719 log.cc:1079] T 7c4b346b400142589fccbe7feafab4ee P 27d891b4777c49d0862a5f3a6a8206d3: Deleting log segment in path: /tmp/dist-test-taskNVEfdO/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515447722411-31279-0/minicluster-data/ts-0-root/wals/7c4b346b400142589fccbe7feafab4ee/wal-000000004 (ops 16-20)
I20260812 06:17:34.475811 31719 log.cc:1079] T 7c4b346b400142589fccbe7feafab4ee P 27d891b4777c49d0862a5f3a6a8206d3: Deleting log segment in path: /tmp/dist-test-taskNVEfdO/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515447722411-31279-0/minicluster-data/ts-0-root/wals/7c4b346b400142589fccbe7feafab4ee/wal-000000005 (ops 21-25)
I20260812 06:17:34.475840 31719 log.cc:1079] T 7c4b346b400142589fccbe7feafab4ee P 27d891b4777c49d0862a5f3a6a8206d3: Deleting log segment in path: /tmp/dist-test-taskNVEfdO/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515447722411-31279-0/minicluster-data/ts-0-root/wals/7c4b346b400142589fccbe7feafab4ee/wal-000000006 (ops 26-30)
I20260812 06:17:34.475870 31719 log.cc:1079] T 7c4b346b400142589fccbe7feafab4ee P 27d891b4777c49d0862a5f3a6a8206d3: Deleting log segment in path: /tmp/dist-test-taskNVEfdO/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515447722411-31279-0/minicluster-data/ts-0-root/wals/7c4b346b400142589fccbe7feafab4ee/wal-000000007 (ops 31-34)
I20260812 06:17:34.475901 31719 log.cc:1079] T 7c4b346b400142589fccbe7feafab4ee P 27d891b4777c49d0862a5f3a6a8206d3: Deleting log segment in path: /tmp/dist-test-taskNVEfdO/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515447722411-31279-0/minicluster-data/ts-0-root/wals/7c4b346b400142589fccbe7feafab4ee/wal-000000008 (ops 35-39)
I20260812 06:17:34.475934 31719 log.cc:1079] T 7c4b346b400142589fccbe7feafab4ee P 27d891b4777c49d0862a5f3a6a8206d3: Deleting log segment in path: /tmp/dist-test-taskNVEfdO/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515447722411-31279-0/minicluster-data/ts-0-root/wals/7c4b346b400142589fccbe7feafab4ee/wal-000000009 (ops 40-44)
I20260812 06:17:34.475962 31719 log.cc:1079] T 7c4b346b400142589fccbe7feafab4ee P 27d891b4777c49d0862a5f3a6a8206d3: Deleting log segment in path: /tmp/dist-test-taskNVEfdO/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515447722411-31279-0/minicluster-data/ts-0-root/wals/7c4b346b400142589fccbe7feafab4ee/wal-000000010 (ops 45-49)
I20260812 06:17:34.475989 31719 log.cc:1079] T 7c4b346b400142589fccbe7feafab4ee P 27d891b4777c49d0862a5f3a6a8206d3: Deleting log segment in path: /tmp/dist-test-taskNVEfdO/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515447722411-31279-0/minicluster-data/ts-0-root/wals/7c4b346b400142589fccbe7feafab4ee/wal-000000011 (ops 50-54)
I20260812 06:17:34.476016 31719 log.cc:1079] T 7c4b346b400142589fccbe7feafab4ee P 27d891b4777c49d0862a5f3a6a8206d3: Deleting log segment in path: /tmp/dist-test-taskNVEfdO/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515447722411-31279-0/minicluster-data/ts-0-root/wals/7c4b346b400142589fccbe7feafab4ee/wal-000000012 (ops 55-59)
I20260812 06:17:34.476048 31719 log.cc:1079] T 7c4b346b400142589fccbe7feafab4ee P 27d891b4777c49d0862a5f3a6a8206d3: Deleting log segment in path: /tmp/dist-test-taskNVEfdO/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515447722411-31279-0/minicluster-data/ts-0-root/wals/7c4b346b400142589fccbe7feafab4ee/wal-000000013 (ops 60-64)
I20260812 06:17:34.476079 31719 log.cc:1079] T 7c4b346b400142589fccbe7feafab4ee P 27d891b4777c49d0862a5f3a6a8206d3: Deleting log segment in path: /tmp/dist-test-taskNVEfdO/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515447722411-31279-0/minicluster-data/ts-0-root/wals/7c4b346b400142589fccbe7feafab4ee/wal-000000014 (ops 65-69)
I20260812 06:17:34.497998 31719 maintenance_manager.cc:643] P 27d891b4777c49d0862a5f3a6a8206d3: LogGCOp(7c4b346b400142589fccbe7feafab4ee) complete. Timing: real 0.022s	user 0.000s	sys 0.022s Metrics: {}
I20260812 06:17:34.498404 31822 maintenance_manager.cc:419] P 27d891b4777c49d0862a5f3a6a8206d3: Scheduling FlushDeltaMemStoresOp(7c4b346b400142589fccbe7feafab4ee): perf score=3.181125
I20260812 06:17:34.517889 31719 maintenance_manager.cc:643] P 27d891b4777c49d0862a5f3a6a8206d3: FlushDeltaMemStoresOp(7c4b346b400142589fccbe7feafab4ee) complete. Timing: real 0.019s	user 0.007s	sys 0.005s Metrics: {"bytes_written":4512903,"delete_count":0,"lbm_write_time_us":4473,"lbm_writes_lt_1ms":113,"reinsert_count":0,"update_count":550}
I20260812 06:17:34.518352 31822 maintenance_manager.cc:419] P 27d891b4777c49d0862a5f3a6a8206d3: Scheduling UndoDeltaBlockGCOp(7c4b346b400142589fccbe7feafab4ee): 462 bytes on disk
I20260812 06:17:34.518734 31719 maintenance_manager.cc:643] P 27d891b4777c49d0862a5f3a6a8206d3: UndoDeltaBlockGCOp(7c4b346b400142589fccbe7feafab4ee) 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:17:34.519178 31822 maintenance_manager.cc:419] P 27d891b4777c49d0862a5f3a6a8206d3: Scheduling FlushDeltaMemStoresOp(7c4b346b400142589fccbe7feafab4ee): perf score=2.188937
I20260812 06:17:34.527908 31719 maintenance_manager.cc:643] P 27d891b4777c49d0862a5f3a6a8206d3: FlushDeltaMemStoresOp(7c4b346b400142589fccbe7feafab4ee) complete. Timing: real 0.009s	user 0.000s	sys 0.007s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3109,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:17:34.528287 31822 maintenance_manager.cc:419] P 27d891b4777c49d0862a5f3a6a8206d3: Scheduling MajorDeltaCompactionOp(7c4b346b400142589fccbe7feafab4ee): perf score=1.000000
I20260812 06:17:34.741400 31719 maintenance_manager.cc:643] P 27d891b4777c49d0862a5f3a6a8206d3: MajorDeltaCompactionOp(7c4b346b400142589fccbe7feafab4ee) complete. Timing: real 0.213s	user 0.141s	sys 0.069s Metrics: {"cfile_cache_miss":735,"cfile_cache_miss_bytes":33061816,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":5,"delta_iterators_relevant":5,"dirs.queue_time_us":124,"lbm_read_time_us":13853,"lbm_reads_lt_1ms":775,"lbm_write_time_us":37069,"lbm_writes_lt_1ms":743,"mutex_wait_us":34,"peak_mem_usage":87969044,"reinsert_count":0,"spinlock_wait_cycles":2816,"thread_start_us":70,"threads_started":1,"update_count":3500}
I20260812 06:17:34.744035 31822 maintenance_manager.cc:419] P 27d891b4777c49d0862a5f3a6a8206d3: Scheduling FlushDeltaMemStoresOp(7c4b346b400142589fccbe7feafab4ee): perf score=18.063937
I20260812 06:17:34.794546 31719 maintenance_manager.cc:643] P 27d891b4777c49d0862a5f3a6a8206d3: FlushDeltaMemStoresOp(7c4b346b400142589fccbe7feafab4ee) complete. Timing: real 0.050s	user 0.035s	sys 0.014s Metrics: {"bytes_written":20512317,"delete_count":0,"lbm_write_time_us":21746,"lbm_writes_lt_1ms":503,"reinsert_count":0,"update_count":2500}
I20260812 06:17:34.795037 31822 maintenance_manager.cc:419] P 27d891b4777c49d0862a5f3a6a8206d3: Scheduling FlushDeltaMemStoresOp(7c4b346b400142589fccbe7feafab4ee): perf score=2.188937
I20260812 06:17:34.806083 31719 maintenance_manager.cc:643] P 27d891b4777c49d0862a5f3a6a8206d3: FlushDeltaMemStoresOp(7c4b346b400142589fccbe7feafab4ee) complete. Timing: real 0.011s	user 0.010s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4031,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:34.806514 31822 maintenance_manager.cc:419] P 27d891b4777c49d0862a5f3a6a8206d3: Scheduling MajorDeltaCompactionOp(7c4b346b400142589fccbe7feafab4ee): perf score=1.000000
I20260812 06:17:34.962543 31719 maintenance_manager.cc:643] P 27d891b4777c49d0862a5f3a6a8206d3: MajorDeltaCompactionOp(7c4b346b400142589fccbe7feafab4ee) complete. Timing: real 0.156s	user 0.128s	sys 0.028s Metrics: {"cfile_cache_miss":632,"cfile_cache_miss_bytes":28959069,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":229,"lbm_read_time_us":10702,"lbm_reads_lt_1ms":664,"lbm_write_time_us":30568,"lbm_writes_lt_1ms":643,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":2688,"update_count":3000}
I20260812 06:17:34.963127 31822 maintenance_manager.cc:419] P 27d891b4777c49d0862a5f3a6a8206d3: Scheduling FlushDeltaMemStoresOp(7c4b346b400142589fccbe7feafab4ee): perf score=14.095187
I20260812 06:17:35.012897 31719 maintenance_manager.cc:643] P 27d891b4777c49d0862a5f3a6a8206d3: FlushDeltaMemStoresOp(7c4b346b400142589fccbe7feafab4ee) complete. Timing: real 0.050s	user 0.030s	sys 0.012s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":18890,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:17:35.013406 31822 maintenance_manager.cc:419] P 27d891b4777c49d0862a5f3a6a8206d3: Scheduling FlushDeltaMemStoresOp(7c4b346b400142589fccbe7feafab4ee): perf score=2.188937
I20260812 06:17:35.025446 31719 maintenance_manager.cc:643] P 27d891b4777c49d0862a5f3a6a8206d3: FlushDeltaMemStoresOp(7c4b346b400142589fccbe7feafab4ee) complete. Timing: real 0.012s	user 0.006s	sys 0.003s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4029,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:35.026082 31822 maintenance_manager.cc:419] P 27d891b4777c49d0862a5f3a6a8206d3: Scheduling MajorDeltaCompactionOp(7c4b346b400142589fccbe7feafab4ee): perf score=1.000000
I20260812 06:17:35.169747 31719 maintenance_manager.cc:643] P 27d891b4777c49d0862a5f3a6a8206d3: MajorDeltaCompactionOp(7c4b346b400142589fccbe7feafab4ee) complete. Timing: real 0.143s	user 0.114s	sys 0.027s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24856653,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":372,"lbm_read_time_us":8875,"lbm_reads_lt_1ms":572,"lbm_write_time_us":27219,"lbm_writes_lt_1ms":543,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":2944,"update_count":2500}
I20260812 06:17:35.170509 31822 maintenance_manager.cc:419] P 27d891b4777c49d0862a5f3a6a8206d3: Scheduling FlushDeltaMemStoresOp(7c4b346b400142589fccbe7feafab4ee): perf score=11.118625
I20260812 06:17:35.198076 31719 maintenance_manager.cc:643] P 27d891b4777c49d0862a5f3a6a8206d3: FlushDeltaMemStoresOp(7c4b346b400142589fccbe7feafab4ee) complete. Timing: real 0.027s	user 0.019s	sys 0.008s Metrics: {"bytes_written":12717736,"delete_count":0,"lbm_write_time_us":11734,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:17:35.198683 31822 maintenance_manager.cc:419] P 27d891b4777c49d0862a5f3a6a8206d3: Scheduling FlushDeltaMemStoresOp(7c4b346b400142589fccbe7feafab4ee): perf score=2.188937
I20260812 06:17:35.220117 31719 maintenance_manager.cc:643] P 27d891b4777c49d0862a5f3a6a8206d3: FlushDeltaMemStoresOp(7c4b346b400142589fccbe7feafab4ee) complete. Timing: real 0.021s	user 0.008s	sys 0.008s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":6013,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:17:35.220755 31822 maintenance_manager.cc:419] P 27d891b4777c49d0862a5f3a6a8206d3: Scheduling MajorDeltaCompactionOp(7c4b346b400142589fccbe7feafab4ee): perf score=1.000000
I20260812 06:17:35.371325 31719 maintenance_manager.cc:643] P 27d891b4777c49d0862a5f3a6a8206d3: MajorDeltaCompactionOp(7c4b346b400142589fccbe7feafab4ee) complete. Timing: real 0.150s	user 0.104s	sys 0.036s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20754234,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":116,"lbm_read_time_us":9604,"lbm_reads_lt_1ms":464,"lbm_write_time_us":23131,"lbm_writes_lt_1ms":443,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":5248,"update_count":2000}
I20260812 06:17:35.371804 31822 maintenance_manager.cc:419] P 27d891b4777c49d0862a5f3a6a8206d3: Scheduling FlushDeltaMemStoresOp(7c4b346b400142589fccbe7feafab4ee): perf score=14.095187
I20260812 06:17:35.420889 31719 maintenance_manager.cc:643] P 27d891b4777c49d0862a5f3a6a8206d3: FlushDeltaMemStoresOp(7c4b346b400142589fccbe7feafab4ee) complete. Timing: real 0.049s	user 0.036s	sys 0.007s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":20022,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:17:35.421371 31822 maintenance_manager.cc:419] P 27d891b4777c49d0862a5f3a6a8206d3: Scheduling FlushDeltaMemStoresOp(7c4b346b400142589fccbe7feafab4ee): perf score=2.188937
I20260812 06:17:35.442799 31719 maintenance_manager.cc:643] P 27d891b4777c49d0862a5f3a6a8206d3: FlushDeltaMemStoresOp(7c4b346b400142589fccbe7feafab4ee) complete. Timing: real 0.021s	user 0.010s	sys 0.010s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5631,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:35.443392 31822 maintenance_manager.cc:419] P 27d891b4777c49d0862a5f3a6a8206d3: Scheduling MajorDeltaCompactionOp(7c4b346b400142589fccbe7feafab4ee): perf score=1.000000
I20260812 06:17:35.605950 31719 maintenance_manager.cc:643] P 27d891b4777c49d0862a5f3a6a8206d3: MajorDeltaCompactionOp(7c4b346b400142589fccbe7feafab4ee) complete. Timing: real 0.162s	user 0.099s	sys 0.061s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24856653,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":603,"lbm_read_time_us":10086,"lbm_reads_lt_1ms":572,"lbm_write_time_us":25559,"lbm_writes_lt_1ms":543,"mutex_wait_us":50,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":12928,"update_count":2500}
I20260812 06:17:35.606480 31822 maintenance_manager.cc:419] P 27d891b4777c49d0862a5f3a6a8206d3: Scheduling FlushDeltaMemStoresOp(7c4b346b400142589fccbe7feafab4ee): perf score=14.095187
I20260812 06:17:35.652576 31719 maintenance_manager.cc:643] P 27d891b4777c49d0862a5f3a6a8206d3: FlushDeltaMemStoresOp(7c4b346b400142589fccbe7feafab4ee) complete. Timing: real 0.046s	user 0.014s	sys 0.021s Metrics: {"bytes_written":16409903,"delete_count":0,"lbm_write_time_us":16165,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:17:35.653142 31822 maintenance_manager.cc:419] P 27d891b4777c49d0862a5f3a6a8206d3: Scheduling FlushDeltaMemStoresOp(7c4b346b400142589fccbe7feafab4ee): perf score=2.188937
I20260812 06:17:35.663488 31719 maintenance_manager.cc:643] P 27d891b4777c49d0862a5f3a6a8206d3: FlushDeltaMemStoresOp(7c4b346b400142589fccbe7feafab4ee) complete. Timing: real 0.010s	user 0.006s	sys 0.003s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":3720,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:35.664113 31822 maintenance_manager.cc:419] P 27d891b4777c49d0862a5f3a6a8206d3: Scheduling MajorDeltaCompactionOp(7c4b346b400142589fccbe7feafab4ee): perf score=1.000000
I20260812 06:17:35.831537 31719 maintenance_manager.cc:643] P 27d891b4777c49d0862a5f3a6a8206d3: MajorDeltaCompactionOp(7c4b346b400142589fccbe7feafab4ee) complete. Timing: real 0.167s	user 0.105s	sys 0.047s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24856654,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":1781,"lbm_read_time_us":9782,"lbm_reads_lt_1ms":572,"lbm_write_time_us":25267,"lbm_writes_lt_1ms":543,"mutex_wait_us":600,"peak_mem_usage":63115900,"reinsert_count":0,"update_count":2500}
I20260812 06:17:35.832017 31822 maintenance_manager.cc:419] P 27d891b4777c49d0862a5f3a6a8206d3: Scheduling FlushDeltaMemStoresOp(7c4b346b400142589fccbe7feafab4ee): perf score=14.095187
I20260812 06:17:35.880867 31719 maintenance_manager.cc:643] P 27d891b4777c49d0862a5f3a6a8206d3: FlushDeltaMemStoresOp(7c4b346b400142589fccbe7feafab4ee) complete. Timing: real 0.049s	user 0.037s	sys 0.004s Metrics: {"bytes_written":16409903,"delete_count":0,"lbm_write_time_us":18906,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:17:35.881419 31822 maintenance_manager.cc:419] P 27d891b4777c49d0862a5f3a6a8206d3: Scheduling FlushDeltaMemStoresOp(7c4b346b400142589fccbe7feafab4ee): perf score=2.188937
I20260812 06:17:35.891592 31719 maintenance_manager.cc:643] P 27d891b4777c49d0862a5f3a6a8206d3: FlushDeltaMemStoresOp(7c4b346b400142589fccbe7feafab4ee) complete. Timing: real 0.010s	user 0.006s	sys 0.003s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3746,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:35.892107 31822 maintenance_manager.cc:419] P 27d891b4777c49d0862a5f3a6a8206d3: Scheduling FlushMRSOp(7c4b346b400142589fccbe7feafab4ee): perf score=1.000000
I20260812 06:17:35.919478 31719 maintenance_manager.cc:643] P 27d891b4777c49d0862a5f3a6a8206d3: FlushMRSOp(7c4b346b400142589fccbe7feafab4ee) complete. Timing: real 0.027s	user 0.025s	sys 0.000s Metrics: {"bytes_written":1316419,"cfile_init":1,"dirs.queue_time_us":61,"dirs.run_cpu_time_us":219,"dirs.run_wall_time_us":1202,"drs_written":1,"lbm_read_time_us":54,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1448,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":32}
I20260812 06:17:35.920147 31822 maintenance_manager.cc:419] P 27d891b4777c49d0862a5f3a6a8206d3: Scheduling LogGCOp(7c4b346b400142589fccbe7feafab4ee): free 133024334 bytes of WAL
I20260812 06:17:35.920368 31719 log_reader.cc:385] T 7c4b346b400142589fccbe7feafab4ee: removed 13 log segments from log reader
I20260812 06:17:35.920426 31719 log.cc:1079] T 7c4b346b400142589fccbe7feafab4ee P 27d891b4777c49d0862a5f3a6a8206d3: Deleting log segment in path: /tmp/dist-test-taskNVEfdO/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515447722411-31279-0/minicluster-data/ts-0-root/wals/7c4b346b400142589fccbe7feafab4ee/wal-000000015 (ops 70-74)
I20260812 06:17:35.920468 31719 log.cc:1079] T 7c4b346b400142589fccbe7feafab4ee P 27d891b4777c49d0862a5f3a6a8206d3: Deleting log segment in path: /tmp/dist-test-taskNVEfdO/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515447722411-31279-0/minicluster-data/ts-0-root/wals/7c4b346b400142589fccbe7feafab4ee/wal-000000016 (ops 75-78)
I20260812 06:17:35.920497 31719 log.cc:1079] T 7c4b346b400142589fccbe7feafab4ee P 27d891b4777c49d0862a5f3a6a8206d3: Deleting log segment in path: /tmp/dist-test-taskNVEfdO/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515447722411-31279-0/minicluster-data/ts-0-root/wals/7c4b346b400142589fccbe7feafab4ee/wal-000000017 (ops 79-83)
I20260812 06:17:35.920529 31719 log.cc:1079] T 7c4b346b400142589fccbe7feafab4ee P 27d891b4777c49d0862a5f3a6a8206d3: Deleting log segment in path: /tmp/dist-test-taskNVEfdO/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515447722411-31279-0/minicluster-data/ts-0-root/wals/7c4b346b400142589fccbe7feafab4ee/wal-000000018 (ops 84-88)
I20260812 06:17:35.920562 31719 log.cc:1079] T 7c4b346b400142589fccbe7feafab4ee P 27d891b4777c49d0862a5f3a6a8206d3: Deleting log segment in path: /tmp/dist-test-taskNVEfdO/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515447722411-31279-0/minicluster-data/ts-0-root/wals/7c4b346b400142589fccbe7feafab4ee/wal-000000019 (ops 89-93)
I20260812 06:17:35.920590 31719 log.cc:1079] T 7c4b346b400142589fccbe7feafab4ee P 27d891b4777c49d0862a5f3a6a8206d3: Deleting log segment in path: /tmp/dist-test-taskNVEfdO/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515447722411-31279-0/minicluster-data/ts-0-root/wals/7c4b346b400142589fccbe7feafab4ee/wal-000000020 (ops 94-98)
I20260812 06:17:35.920617 31719 log.cc:1079] T 7c4b346b400142589fccbe7feafab4ee P 27d891b4777c49d0862a5f3a6a8206d3: Deleting log segment in path: /tmp/dist-test-taskNVEfdO/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515447722411-31279-0/minicluster-data/ts-0-root/wals/7c4b346b400142589fccbe7feafab4ee/wal-000000021 (ops 99-103)
I20260812 06:17:35.920643 31719 log.cc:1079] T 7c4b346b400142589fccbe7feafab4ee P 27d891b4777c49d0862a5f3a6a8206d3: Deleting log segment in path: /tmp/dist-test-taskNVEfdO/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515447722411-31279-0/minicluster-data/ts-0-root/wals/7c4b346b400142589fccbe7feafab4ee/wal-000000022 (ops 104-108)
I20260812 06:17:35.920671 31719 log.cc:1079] T 7c4b346b400142589fccbe7feafab4ee P 27d891b4777c49d0862a5f3a6a8206d3: Deleting log segment in path: /tmp/dist-test-taskNVEfdO/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515447722411-31279-0/minicluster-data/ts-0-root/wals/7c4b346b400142589fccbe7feafab4ee/wal-000000023 (ops 109-113)
I20260812 06:17:35.920703 31719 log.cc:1079] T 7c4b346b400142589fccbe7feafab4ee P 27d891b4777c49d0862a5f3a6a8206d3: Deleting log segment in path: /tmp/dist-test-taskNVEfdO/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515447722411-31279-0/minicluster-data/ts-0-root/wals/7c4b346b400142589fccbe7feafab4ee/wal-000000024 (ops 114-118)
I20260812 06:17:35.920732 31719 log.cc:1079] T 7c4b346b400142589fccbe7feafab4ee P 27d891b4777c49d0862a5f3a6a8206d3: Deleting log segment in path: /tmp/dist-test-taskNVEfdO/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515447722411-31279-0/minicluster-data/ts-0-root/wals/7c4b346b400142589fccbe7feafab4ee/wal-000000025 (ops 119-123)
I20260812 06:17:35.920756 31719 log.cc:1079] T 7c4b346b400142589fccbe7feafab4ee P 27d891b4777c49d0862a5f3a6a8206d3: Deleting log segment in path: /tmp/dist-test-taskNVEfdO/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515447722411-31279-0/minicluster-data/ts-0-root/wals/7c4b346b400142589fccbe7feafab4ee/wal-000000026 (ops 124-128)
I20260812 06:17:35.920783 31719 log.cc:1079] T 7c4b346b400142589fccbe7feafab4ee P 27d891b4777c49d0862a5f3a6a8206d3: Deleting log segment in path: /tmp/dist-test-taskNVEfdO/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515447722411-31279-0/minicluster-data/ts-0-root/wals/7c4b346b400142589fccbe7feafab4ee/wal-000000027 (ops 129-133)
I20260812 06:17:35.947045 31719 maintenance_manager.cc:643] P 27d891b4777c49d0862a5f3a6a8206d3: LogGCOp(7c4b346b400142589fccbe7feafab4ee) complete. Timing: real 0.027s	user 0.000s	sys 0.025s Metrics: {}
I20260812 06:17:35.947460 31822 maintenance_manager.cc:419] P 27d891b4777c49d0862a5f3a6a8206d3: Scheduling UndoDeltaBlockGCOp(7c4b346b400142589fccbe7feafab4ee): 493 bytes on disk
I20260812 06:17:35.948050 31719 maintenance_manager.cc:643] P 27d891b4777c49d0862a5f3a6a8206d3: UndoDeltaBlockGCOp(7c4b346b400142589fccbe7feafab4ee) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":49,"lbm_reads_lt_1ms":4}
I20260812 06:17:35.948729 31822 maintenance_manager.cc:419] P 27d891b4777c49d0862a5f3a6a8206d3: Scheduling FlushDeltaMemStoresOp(7c4b346b400142589fccbe7feafab4ee): perf score=3.181125
I20260812 06:17:35.971382 31719 maintenance_manager.cc:643] P 27d891b4777c49d0862a5f3a6a8206d3: FlushDeltaMemStoresOp(7c4b346b400142589fccbe7feafab4ee) complete. Timing: real 0.022s	user 0.008s	sys 0.004s Metrics: {"bytes_written":4512903,"delete_count":0,"lbm_write_time_us":4281,"lbm_writes_lt_1ms":113,"reinsert_count":0,"update_count":550}
I20260812 06:17:35.971881 31822 maintenance_manager.cc:419] P 27d891b4777c49d0862a5f3a6a8206d3: Scheduling FlushDeltaMemStoresOp(7c4b346b400142589fccbe7feafab4ee): perf score=2.188937
I20260812 06:17:35.984508 31719 maintenance_manager.cc:643] P 27d891b4777c49d0862a5f3a6a8206d3: FlushDeltaMemStoresOp(7c4b346b400142589fccbe7feafab4ee) complete. Timing: real 0.012s	user 0.003s	sys 0.008s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":4805,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:17:35.985042 31822 maintenance_manager.cc:419] P 27d891b4777c49d0862a5f3a6a8206d3: Scheduling MajorDeltaCompactionOp(7c4b346b400142589fccbe7feafab4ee): perf score=1.000000
I20260812 06:17:36.209765 31719 maintenance_manager.cc:643] P 27d891b4777c49d0862a5f3a6a8206d3: MajorDeltaCompactionOp(7c4b346b400142589fccbe7feafab4ee) complete. Timing: real 0.225s	user 0.161s	sys 0.059s Metrics: {"cfile_cache_miss":734,"cfile_cache_miss_bytes":33061707,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":919,"lbm_read_time_us":15080,"lbm_reads_lt_1ms":774,"lbm_write_time_us":38269,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":742,"mutex_wait_us":228,"peak_mem_usage":87969044,"reinsert_count":0,"spinlock_wait_cycles":4352,"thread_start_us":70,"threads_started":1,"update_count":3500}
I20260812 06:17:36.210394 31822 maintenance_manager.cc:419] P 27d891b4777c49d0862a5f3a6a8206d3: Scheduling FlushDeltaMemStoresOp(7c4b346b400142589fccbe7feafab4ee): perf score=15.087375
I20260812 06:17:36.284296 31719 maintenance_manager.cc:643] P 27d891b4777c49d0862a5f3a6a8206d3: FlushDeltaMemStoresOp(7c4b346b400142589fccbe7feafab4ee) complete. Timing: real 0.074s	user 0.027s	sys 0.025s Metrics: {"bytes_written":16984244,"delete_count":0,"lbm_write_time_us":27207,"lbm_writes_1-10_ms":2,"lbm_writes_lt_1ms":415,"reinsert_count":0,"update_count":2070}
I20260812 06:17:36.284883 31822 maintenance_manager.cc:419] P 27d891b4777c49d0862a5f3a6a8206d3: Scheduling FlushDeltaMemStoresOp(7c4b346b400142589fccbe7feafab4ee): perf score=6.157687
I20260812 06:17:36.303383 31719 maintenance_manager.cc:643] P 27d891b4777c49d0862a5f3a6a8206d3: FlushDeltaMemStoresOp(7c4b346b400142589fccbe7feafab4ee) complete. Timing: real 0.018s	user 0.005s	sys 0.012s Metrics: {"bytes_written":7630744,"delete_count":0,"lbm_write_time_us":6791,"lbm_writes_lt_1ms":189,"reinsert_count":0,"update_count":930}
I20260812 06:17:36.304100 31822 maintenance_manager.cc:419] P 27d891b4777c49d0862a5f3a6a8206d3: Scheduling MajorDeltaCompactionOp(7c4b346b400142589fccbe7feafab4ee): perf score=1.000000
I20260812 06:17:36.503211 31719 maintenance_manager.cc:643] P 27d891b4777c49d0862a5f3a6a8206d3: MajorDeltaCompactionOp(7c4b346b400142589fccbe7feafab4ee) complete. Timing: real 0.199s	user 0.109s	sys 0.084s Metrics: {"cfile_cache_miss":632,"cfile_cache_miss_bytes":28959075,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":856,"lbm_read_time_us":13394,"lbm_reads_lt_1ms":672,"lbm_write_time_us":31237,"lbm_writes_lt_1ms":643,"mutex_wait_us":321,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":13184,"update_count":3000}
I20260812 06:17:36.503897 31822 maintenance_manager.cc:419] P 27d891b4777c49d0862a5f3a6a8206d3: Scheduling FlushDeltaMemStoresOp(7c4b346b400142589fccbe7feafab4ee): perf score=14.095187
I20260812 06:17:36.547209 31719 maintenance_manager.cc:643] P 27d891b4777c49d0862a5f3a6a8206d3: FlushDeltaMemStoresOp(7c4b346b400142589fccbe7feafab4ee) complete. Timing: real 0.043s	user 0.034s	sys 0.008s Metrics: {"bytes_written":16409903,"delete_count":0,"lbm_write_time_us":18821,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:17:36.547706 31822 maintenance_manager.cc:419] P 27d891b4777c49d0862a5f3a6a8206d3: Scheduling MajorDeltaCompactionOp(7c4b346b400142589fccbe7feafab4ee): perf score=1.000000
I20260812 06:17:36.685498 31719 maintenance_manager.cc:643] P 27d891b4777c49d0862a5f3a6a8206d3: MajorDeltaCompactionOp(7c4b346b400142589fccbe7feafab4ee) complete. Timing: real 0.138s	user 0.093s	sys 0.040s Metrics: {"cfile_cache_miss":431,"cfile_cache_miss_bytes":20754124,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":1,"delta_iterators_relevant":1,"dirs.queue_time_us":866,"lbm_read_time_us":8747,"lbm_reads_lt_1ms":467,"lbm_write_time_us":21626,"lbm_writes_lt_1ms":443,"mutex_wait_us":300,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":10880,"update_count":2000}
I20260812 06:17:36.686133 31822 maintenance_manager.cc:419] P 27d891b4777c49d0862a5f3a6a8206d3: Scheduling FlushDeltaMemStoresOp(7c4b346b400142589fccbe7feafab4ee): perf score=11.118625
I20260812 06:17:36.728796 31719 maintenance_manager.cc:643] P 27d891b4777c49d0862a5f3a6a8206d3: FlushDeltaMemStoresOp(7c4b346b400142589fccbe7feafab4ee) complete. Timing: real 0.042s	user 0.033s	sys 0.008s Metrics: {"bytes_written":12717737,"delete_count":0,"lbm_write_time_us":18009,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:17:36.729272 31822 maintenance_manager.cc:419] P 27d891b4777c49d0862a5f3a6a8206d3: Scheduling FlushDeltaMemStoresOp(7c4b346b400142589fccbe7feafab4ee): perf score=2.188937
I20260812 06:17:36.746531 31719 maintenance_manager.cc:643] P 27d891b4777c49d0862a5f3a6a8206d3: FlushDeltaMemStoresOp(7c4b346b400142589fccbe7feafab4ee) complete. Timing: real 0.017s	user 0.009s	sys 0.001s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4140,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:36.747020 31822 maintenance_manager.cc:419] P 27d891b4777c49d0862a5f3a6a8206d3: Scheduling FlushDeltaMemStoresOp(7c4b346b400142589fccbe7feafab4ee): perf score=2.188937
I20260812 06:17:36.757027 31719 maintenance_manager.cc:643] P 27d891b4777c49d0862a5f3a6a8206d3: FlushDeltaMemStoresOp(7c4b346b400142589fccbe7feafab4ee) complete. Timing: real 0.010s	user 0.008s	sys 0.001s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3676,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:17:36.757472 31822 maintenance_manager.cc:419] P 27d891b4777c49d0862a5f3a6a8206d3: Scheduling MajorDeltaCompactionOp(7c4b346b400142589fccbe7feafab4ee): perf score=1.000000
I20260812 06:17:36.949458 31719 maintenance_manager.cc:643] P 27d891b4777c49d0862a5f3a6a8206d3: MajorDeltaCompactionOp(7c4b346b400142589fccbe7feafab4ee) complete. Timing: real 0.192s	user 0.129s	sys 0.060s Metrics: {"cfile_cache_miss":533,"cfile_cache_miss_bytes":24856766,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":116,"lbm_read_time_us":11587,"lbm_reads_lt_1ms":573,"lbm_write_time_us":32996,"lbm_writes_lt_1ms":543,"mutex_wait_us":39,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":9216,"update_count":2500}
I20260812 06:17:36.949993 31822 maintenance_manager.cc:419] P 27d891b4777c49d0862a5f3a6a8206d3: Scheduling FlushDeltaMemStoresOp(7c4b346b400142589fccbe7feafab4ee): perf score=14.095187
I20260812 06:17:36.993675 31719 maintenance_manager.cc:643] P 27d891b4777c49d0862a5f3a6a8206d3: FlushDeltaMemStoresOp(7c4b346b400142589fccbe7feafab4ee) complete. Timing: real 0.044s	user 0.031s	sys 0.008s Metrics: {"bytes_written":16409907,"delete_count":0,"lbm_write_time_us":17839,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:17:36.994184 31822 maintenance_manager.cc:419] P 27d891b4777c49d0862a5f3a6a8206d3: Scheduling FlushDeltaMemStoresOp(7c4b346b400142589fccbe7feafab4ee): perf score=2.188937
I20260812 06:17:37.009007 31719 maintenance_manager.cc:643] P 27d891b4777c49d0862a5f3a6a8206d3: FlushDeltaMemStoresOp(7c4b346b400142589fccbe7feafab4ee) complete. Timing: real 0.015s	user 0.009s	sys 0.002s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5319,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:37.009446 31822 maintenance_manager.cc:419] P 27d891b4777c49d0862a5f3a6a8206d3: Scheduling MajorDeltaCompactionOp(7c4b346b400142589fccbe7feafab4ee): perf score=1.000000
I20260812 06:17:37.149235 31719 maintenance_manager.cc:643] P 27d891b4777c49d0862a5f3a6a8206d3: MajorDeltaCompactionOp(7c4b346b400142589fccbe7feafab4ee) complete. Timing: real 0.140s	user 0.110s	sys 0.023s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24856659,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":199,"lbm_read_time_us":8384,"lbm_reads_lt_1ms":572,"lbm_write_time_us":25345,"lbm_writes_lt_1ms":543,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":15232,"update_count":2500}
I20260812 06:17:37.149854 31822 maintenance_manager.cc:419] P 27d891b4777c49d0862a5f3a6a8206d3: Scheduling FlushDeltaMemStoresOp(7c4b346b400142589fccbe7feafab4ee): perf score=11.118625
I20260812 06:17:37.184980 31719 maintenance_manager.cc:643] P 27d891b4777c49d0862a5f3a6a8206d3: FlushDeltaMemStoresOp(7c4b346b400142589fccbe7feafab4ee) complete. Timing: real 0.035s	user 0.021s	sys 0.010s Metrics: {"bytes_written":12717735,"delete_count":0,"lbm_write_time_us":13890,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:17:37.185591 31822 maintenance_manager.cc:419] P 27d891b4777c49d0862a5f3a6a8206d3: Scheduling FlushDeltaMemStoresOp(7c4b346b400142589fccbe7feafab4ee): perf score=2.188937
I20260812 06:17:37.207845 31719 maintenance_manager.cc:643] P 27d891b4777c49d0862a5f3a6a8206d3: FlushDeltaMemStoresOp(7c4b346b400142589fccbe7feafab4ee) complete. Timing: real 0.022s	user 0.005s	sys 0.005s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":4293,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:17:37.208459 31822 maintenance_manager.cc:419] P 27d891b4777c49d0862a5f3a6a8206d3: Scheduling FlushDeltaMemStoresOp(7c4b346b400142589fccbe7feafab4ee): perf score=2.188937
I20260812 06:17:37.222749 31719 maintenance_manager.cc:643] P 27d891b4777c49d0862a5f3a6a8206d3: FlushDeltaMemStoresOp(7c4b346b400142589fccbe7feafab4ee) complete. Timing: real 0.014s	user 0.005s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5289,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:37.223240 31822 maintenance_manager.cc:419] P 27d891b4777c49d0862a5f3a6a8206d3: Scheduling MajorDeltaCompactionOp(7c4b346b400142589fccbe7feafab4ee): perf score=1.000000
I20260812 06:17:37.359388 31719 maintenance_manager.cc:643] P 27d891b4777c49d0862a5f3a6a8206d3: MajorDeltaCompactionOp(7c4b346b400142589fccbe7feafab4ee) complete. Timing: real 0.136s	user 0.108s	sys 0.028s Metrics: {"cfile_cache_miss":533,"cfile_cache_miss_bytes":24856764,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":186,"lbm_read_time_us":10216,"lbm_reads_lt_1ms":573,"lbm_write_time_us":26807,"lbm_writes_lt_1ms":543,"mutex_wait_us":20,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":13952,"update_count":2500}
I20260812 06:17:37.359917 31822 maintenance_manager.cc:419] P 27d891b4777c49d0862a5f3a6a8206d3: Scheduling FlushDeltaMemStoresOp(7c4b346b400142589fccbe7feafab4ee): perf score=10.126437
I20260812 06:17:37.391237 31719 maintenance_manager.cc:643] P 27d891b4777c49d0862a5f3a6a8206d3: FlushDeltaMemStoresOp(7c4b346b400142589fccbe7feafab4ee) complete. Timing: real 0.031s	user 0.014s	sys 0.016s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":13479,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:17:37.391830 31822 maintenance_manager.cc:419] P 27d891b4777c49d0862a5f3a6a8206d3: Scheduling FlushDeltaMemStoresOp(7c4b346b400142589fccbe7feafab4ee): perf score=2.188937
I20260812 06:17:37.406745 31719 maintenance_manager.cc:643] P 27d891b4777c49d0862a5f3a6a8206d3: FlushDeltaMemStoresOp(7c4b346b400142589fccbe7feafab4ee) complete. Timing: real 0.015s	user 0.012s	sys 0.001s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":5657,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:37.407263 31822 maintenance_manager.cc:419] P 27d891b4777c49d0862a5f3a6a8206d3: Scheduling FlushMRSOp(7c4b346b400142589fccbe7feafab4ee): perf score=1.000000
I20260812 06:17:37.433976 31719 maintenance_manager.cc:643] P 27d891b4777c49d0862a5f3a6a8206d3: FlushMRSOp(7c4b346b400142589fccbe7feafab4ee) complete. Timing: real 0.026s	user 0.025s	sys 0.001s Metrics: {"bytes_written":1316417,"cfile_init":1,"dirs.queue_time_us":60,"dirs.run_cpu_time_us":209,"dirs.run_wall_time_us":1144,"drs_written":1,"lbm_read_time_us":44,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1611,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":32}
I20260812 06:17:37.434646 31822 maintenance_manager.cc:419] P 27d891b4777c49d0862a5f3a6a8206d3: Scheduling LogGCOp(7c4b346b400142589fccbe7feafab4ee): free 133024706 bytes of WAL
I20260812 06:17:37.434885 31719 log_reader.cc:385] T 7c4b346b400142589fccbe7feafab4ee: removed 13 log segments from log reader
I20260812 06:17:37.434933 31719 log.cc:1079] T 7c4b346b400142589fccbe7feafab4ee P 27d891b4777c49d0862a5f3a6a8206d3: Deleting log segment in path: /tmp/dist-test-taskNVEfdO/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515447722411-31279-0/minicluster-data/ts-0-root/wals/7c4b346b400142589fccbe7feafab4ee/wal-000000028 (ops 134-138)
I20260812 06:17:37.434966 31719 log.cc:1079] T 7c4b346b400142589fccbe7feafab4ee P 27d891b4777c49d0862a5f3a6a8206d3: Deleting log segment in path: /tmp/dist-test-taskNVEfdO/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515447722411-31279-0/minicluster-data/ts-0-root/wals/7c4b346b400142589fccbe7feafab4ee/wal-000000029 (ops 139-143)
I20260812 06:17:37.435012 31719 log.cc:1079] T 7c4b346b400142589fccbe7feafab4ee P 27d891b4777c49d0862a5f3a6a8206d3: Deleting log segment in path: /tmp/dist-test-taskNVEfdO/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515447722411-31279-0/minicluster-data/ts-0-root/wals/7c4b346b400142589fccbe7feafab4ee/wal-000000030 (ops 144-148)
I20260812 06:17:37.435052 31719 log.cc:1079] T 7c4b346b400142589fccbe7feafab4ee P 27d891b4777c49d0862a5f3a6a8206d3: Deleting log segment in path: /tmp/dist-test-taskNVEfdO/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515447722411-31279-0/minicluster-data/ts-0-root/wals/7c4b346b400142589fccbe7feafab4ee/wal-000000031 (ops 149-153)
I20260812 06:17:37.435088 31719 log.cc:1079] T 7c4b346b400142589fccbe7feafab4ee P 27d891b4777c49d0862a5f3a6a8206d3: Deleting log segment in path: /tmp/dist-test-taskNVEfdO/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515447722411-31279-0/minicluster-data/ts-0-root/wals/7c4b346b400142589fccbe7feafab4ee/wal-000000032 (ops 154-158)
I20260812 06:17:37.435127 31719 log.cc:1079] T 7c4b346b400142589fccbe7feafab4ee P 27d891b4777c49d0862a5f3a6a8206d3: Deleting log segment in path: /tmp/dist-test-taskNVEfdO/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515447722411-31279-0/minicluster-data/ts-0-root/wals/7c4b346b400142589fccbe7feafab4ee/wal-000000033 (ops 159-163)
I20260812 06:17:37.435170 31719 log.cc:1079] T 7c4b346b400142589fccbe7feafab4ee P 27d891b4777c49d0862a5f3a6a8206d3: Deleting log segment in path: /tmp/dist-test-taskNVEfdO/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515447722411-31279-0/minicluster-data/ts-0-root/wals/7c4b346b400142589fccbe7feafab4ee/wal-000000034 (ops 164-168)
I20260812 06:17:37.435209 31719 log.cc:1079] T 7c4b346b400142589fccbe7feafab4ee P 27d891b4777c49d0862a5f3a6a8206d3: Deleting log segment in path: /tmp/dist-test-taskNVEfdO/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515447722411-31279-0/minicluster-data/ts-0-root/wals/7c4b346b400142589fccbe7feafab4ee/wal-000000035 (ops 169-173)
I20260812 06:17:37.435247 31719 log.cc:1079] T 7c4b346b400142589fccbe7feafab4ee P 27d891b4777c49d0862a5f3a6a8206d3: Deleting log segment in path: /tmp/dist-test-taskNVEfdO/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515447722411-31279-0/minicluster-data/ts-0-root/wals/7c4b346b400142589fccbe7feafab4ee/wal-000000036 (ops 174-178)
I20260812 06:17:37.435286 31719 log.cc:1079] T 7c4b346b400142589fccbe7feafab4ee P 27d891b4777c49d0862a5f3a6a8206d3: Deleting log segment in path: /tmp/dist-test-taskNVEfdO/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515447722411-31279-0/minicluster-data/ts-0-root/wals/7c4b346b400142589fccbe7feafab4ee/wal-000000037 (ops 179-182)
I20260812 06:17:37.435325 31719 log.cc:1079] T 7c4b346b400142589fccbe7feafab4ee P 27d891b4777c49d0862a5f3a6a8206d3: Deleting log segment in path: /tmp/dist-test-taskNVEfdO/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515447722411-31279-0/minicluster-data/ts-0-root/wals/7c4b346b400142589fccbe7feafab4ee/wal-000000038 (ops 183-187)
I20260812 06:17:37.435364 31719 log.cc:1079] T 7c4b346b400142589fccbe7feafab4ee P 27d891b4777c49d0862a5f3a6a8206d3: Deleting log segment in path: /tmp/dist-test-taskNVEfdO/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515447722411-31279-0/minicluster-data/ts-0-root/wals/7c4b346b400142589fccbe7feafab4ee/wal-000000039 (ops 188-192)
I20260812 06:17:37.435401 31719 log.cc:1079] T 7c4b346b400142589fccbe7feafab4ee P 27d891b4777c49d0862a5f3a6a8206d3: Deleting log segment in path: /tmp/dist-test-taskNVEfdO/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515447722411-31279-0/minicluster-data/ts-0-root/wals/7c4b346b400142589fccbe7feafab4ee/wal-000000040 (ops 193-197)
I20260812 06:17:37.459295 31719 maintenance_manager.cc:643] P 27d891b4777c49d0862a5f3a6a8206d3: LogGCOp(7c4b346b400142589fccbe7feafab4ee) complete. Timing: real 0.024s	user 0.000s	sys 0.023s Metrics: {}
I20260812 06:17:37.459762 31822 maintenance_manager.cc:419] P 27d891b4777c49d0862a5f3a6a8206d3: Scheduling FlushDeltaMemStoresOp(7c4b346b400142589fccbe7feafab4ee): perf score=3.181125
I20260812 06:17:37.469519 31279 heavy-update-compaction-itest.cc:229] Time spent updating: real 4.503s	user 1.662s	sys 0.144s
I20260812 06:17:37.477187 31719 maintenance_manager.cc:643] P 27d891b4777c49d0862a5f3a6a8206d3: FlushDeltaMemStoresOp(7c4b346b400142589fccbe7feafab4ee) complete. Timing: real 0.017s	user 0.016s	sys 0.000s Metrics: {"bytes_written":4923143,"delete_count":0,"lbm_write_time_us":7196,"lbm_writes_lt_1ms":123,"reinsert_count":0,"update_count":600}
I20260812 06:17:37.477630 31822 maintenance_manager.cc:419] P 27d891b4777c49d0862a5f3a6a8206d3: Scheduling UndoDeltaBlockGCOp(7c4b346b400142589fccbe7feafab4ee): 492 bytes on disk
I20260812 06:17:37.478354 31719 maintenance_manager.cc:643] P 27d891b4777c49d0862a5f3a6a8206d3: UndoDeltaBlockGCOp(7c4b346b400142589fccbe7feafab4ee) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":68,"lbm_reads_lt_1ms":4}
I20260812 06:17:37.479540 31822 maintenance_manager.cc:419] P 27d891b4777c49d0862a5f3a6a8206d3: Scheduling FlushDeltaMemStoresOp(7c4b346b400142589fccbe7feafab4ee): perf score=2.188937
I20260812 06:17:37.487120 31719 maintenance_manager.cc:643] P 27d891b4777c49d0862a5f3a6a8206d3: FlushDeltaMemStoresOp(7c4b346b400142589fccbe7feafab4ee) complete. Timing: real 0.007s	user 0.003s	sys 0.004s Metrics: {"bytes_written":3282155,"delete_count":0,"lbm_write_time_us":2931,"lbm_writes_lt_1ms":83,"reinsert_count":0,"update_count":400}
I20260812 06:17:37.487483 31822 maintenance_manager.cc:419] P 27d891b4777c49d0862a5f3a6a8206d3: Scheduling MajorDeltaCompactionOp(7c4b346b400142589fccbe7feafab4ee): perf score=1.000000
I20260812 06:17:37.525136 31279 heavy-update-compaction-itest.cc:265] Time spent scanning: real 0.055s	user 0.001s	sys 0.000s
I20260812 06:17:37.525707 31279 tablet_server.cc:179] TabletServer@127.30.139.193:0 shutting down...
I20260812 06:17:37.614156 31719 maintenance_manager.cc:643] P 27d891b4777c49d0862a5f3a6a8206d3: MajorDeltaCompactionOp(7c4b346b400142589fccbe7feafab4ee) complete. Timing: real 0.127s	user 0.081s	sys 0.045s Metrics: {"cfile_cache_hit":365,"cfile_cache_hit_bytes":14892479,"cfile_cache_miss":269,"cfile_cache_miss_bytes":14066804,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":710,"lbm_read_time_us":4980,"lbm_reads_lt_1ms":305,"lbm_write_time_us":27880,"lbm_writes_lt_1ms":643,"mutex_wait_us":290,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":29056,"thread_start_us":77,"threads_started":1,"update_count":3000}
I20260812 06:17:37.615274 31279 ts_tablet_manager.cc:1507] Shutting down tablet manager...
I20260812 06:17:37.615550 31279 tablet_replica.cc:333] T 7c4b346b400142589fccbe7feafab4ee P 27d891b4777c49d0862a5f3a6a8206d3: stopping tablet replica
I20260812 06:17:37.615676 31279 raft_consensus.cc:2243] T 7c4b346b400142589fccbe7feafab4ee P 27d891b4777c49d0862a5f3a6a8206d3 [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:17:37.615819 31279 raft_consensus.cc:2272] T 7c4b346b400142589fccbe7feafab4ee P 27d891b4777c49d0862a5f3a6a8206d3 [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:17:37.630096 31279 tablet_server.cc:196] TabletServer@127.30.139.193:0 shutdown complete.
I20260812 06:17:37.664625 31279 master.cc:562] Master@127.30.139.254:46715 shutting down...
I20260812 06:17:37.667794 31279 raft_consensus.cc:2243] T 00000000000000000000000000000000 P 1d7a361defbe4180857dd9bf3de21d97 [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:17:37.667953 31279 raft_consensus.cc:2272] T 00000000000000000000000000000000 P 1d7a361defbe4180857dd9bf3de21d97 [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:17:37.668020 31279 tablet_replica.cc:333] T 00000000000000000000000000000000 P 1d7a361defbe4180857dd9bf3de21d97: stopping tablet replica
I20260812 06:17:37.681074 31279 master.cc:584] Master@127.30.139.254:46715 shutdown complete.
[       OK ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/1 (4956 ms)
[----------] 2 tests from EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy (10013 ms total)

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