[==========] 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:23.308408 22369 internal_mini_cluster.cc:156] Creating distributed mini masters. Addrs: 127.21.216.126:39691
I20260812 06:17:23.309289 22369 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:23.309836 22369 file_cache.cc:504] Constructed file cache file cache with capacity 419430
I20260812 06:17:23.315902 22369 server_base.cc:1061] running on GCE node
W20260812 06:17:23.316082 22376 instance_detector.cc:116] could not retrieve AWS instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:17:23.316345 22383 instance_detector.cc:116] could not retrieve OpenStack instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:17:23.316444 22380 instance_detector.cc:116] could not retrieve Azure instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:17:23.317226 22369 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:17:23.317312 22369 system_unsync_time.cc:38] NTP support is disabled. Clock error bounds will not be accurate. This configuration is not suitable for distributed clusters.
I20260812 06:17:23.317338 22369 hybrid_clock.cc:648] HybridClock initialized: now 1786515443317337 us; error 0 us; skew 500 ppm
I20260812 06:17:23.318858 22369 webserver.cc:533] Webserver started at http://127.21.216.126:35557/ using document root <none> and password file <none>
I20260812 06:17:23.319355 22369 fs_manager.cc:362] Metadata directory not provided
I20260812 06:17:23.319413 22369 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:17:23.319589 22369 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:17:23.321076 22369 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskw4CMs_/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515443298492-22369-0/minicluster-data/master-0-root/instance:
uuid: "4cacd3c44df5455c9b2c7c98a814d317"
format_stamp: "Formatted at 2026-08-12 06:17:23 on dist-test-slave-1vmg"
I20260812 06:17:23.324218 22369 fs_manager.cc:696] Time spent creating directory manager: real 0.003s	user 0.001s	sys 0.004s
I20260812 06:17:23.327261 22391 log_block_manager.cc:4127] Time spent loading block containers with low live blocks: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:17:23.328404 22369 fs_manager.cc:730] Time spent opening block manager: real 0.003s	user 0.002s	sys 0.000s
I20260812 06:17:23.328519 22369 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskw4CMs_/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515443298492-22369-0/minicluster-data/master-0-root
uuid: "4cacd3c44df5455c9b2c7c98a814d317"
format_stamp: "Formatted at 2026-08-12 06:17:23 on dist-test-slave-1vmg"
I20260812 06:17:23.328658 22369 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskw4CMs_/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515443298492-22369-0/minicluster-data/master-0-root
metadata directory: /tmp/dist-test-taskw4CMs_/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515443298492-22369-0/minicluster-data/master-0-root
1 data directories: /tmp/dist-test-taskw4CMs_/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515443298492-22369-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:23.337944 22369 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:17:23.338440 22369 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:23.338572 22369 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:17:23.345496 22369 rpc_server.cc:307] RPC server started. Bound to: 127.21.216.126:39691
I20260812 06:17:23.345510 22485 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.21.216.126:39691 every 8 connection(s)
I20260812 06:17:23.347530 22486 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:23.352487 22486 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P 4cacd3c44df5455c9b2c7c98a814d317: Bootstrap starting.
I20260812 06:17:23.354647 22486 tablet_bootstrap.cc:654] T 00000000000000000000000000000000 P 4cacd3c44df5455c9b2c7c98a814d317: Neither blocks nor log segments found. Creating new log.
I20260812 06:17:23.355497 22486 log.cc:826] T 00000000000000000000000000000000 P 4cacd3c44df5455c9b2c7c98a814d317: Log is configured to *not* fsync() on all Append() calls
I20260812 06:17:23.356945 22486 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P 4cacd3c44df5455c9b2c7c98a814d317: No bootstrap required, opened a new log
I20260812 06:17:23.359485 22486 raft_consensus.cc:359] T 00000000000000000000000000000000 P 4cacd3c44df5455c9b2c7c98a814d317 [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "4cacd3c44df5455c9b2c7c98a814d317" member_type: VOTER }
I20260812 06:17:23.359642 22486 raft_consensus.cc:385] T 00000000000000000000000000000000 P 4cacd3c44df5455c9b2c7c98a814d317 [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:17:23.359707 22486 raft_consensus.cc:740] T 00000000000000000000000000000000 P 4cacd3c44df5455c9b2c7c98a814d317 [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: 4cacd3c44df5455c9b2c7c98a814d317, State: Initialized, Role: FOLLOWER
I20260812 06:17:23.360237 22486 consensus_queue.cc:260] T 00000000000000000000000000000000 P 4cacd3c44df5455c9b2c7c98a814d317 [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: "4cacd3c44df5455c9b2c7c98a814d317" member_type: VOTER }
I20260812 06:17:23.360380 22486 raft_consensus.cc:399] T 00000000000000000000000000000000 P 4cacd3c44df5455c9b2c7c98a814d317 [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:17:23.360445 22486 raft_consensus.cc:493] T 00000000000000000000000000000000 P 4cacd3c44df5455c9b2c7c98a814d317 [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:17:23.360555 22486 raft_consensus.cc:3060] T 00000000000000000000000000000000 P 4cacd3c44df5455c9b2c7c98a814d317 [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:17:23.361244 22486 raft_consensus.cc:515] T 00000000000000000000000000000000 P 4cacd3c44df5455c9b2c7c98a814d317 [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "4cacd3c44df5455c9b2c7c98a814d317" member_type: VOTER }
I20260812 06:17:23.361619 22486 leader_election.cc:304] T 00000000000000000000000000000000 P 4cacd3c44df5455c9b2c7c98a814d317 [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: 4cacd3c44df5455c9b2c7c98a814d317; no voters: 
I20260812 06:17:23.361881 22486 leader_election.cc:290] T 00000000000000000000000000000000 P 4cacd3c44df5455c9b2c7c98a814d317 [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:17:23.361971 22493 raft_consensus.cc:2804] T 00000000000000000000000000000000 P 4cacd3c44df5455c9b2c7c98a814d317 [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:17:23.362177 22493 raft_consensus.cc:697] T 00000000000000000000000000000000 P 4cacd3c44df5455c9b2c7c98a814d317 [term 1 LEADER]: Becoming Leader. State: Replica: 4cacd3c44df5455c9b2c7c98a814d317, State: Running, Role: LEADER
I20260812 06:17:23.362567 22493 consensus_queue.cc:237] T 00000000000000000000000000000000 P 4cacd3c44df5455c9b2c7c98a814d317 [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: "4cacd3c44df5455c9b2c7c98a814d317" member_type: VOTER }
I20260812 06:17:23.362710 22486 sys_catalog.cc:565] T 00000000000000000000000000000000 P 4cacd3c44df5455c9b2c7c98a814d317 [sys.catalog]: configured and running, proceeding with master startup.
I20260812 06:17:23.364382 22496 sys_catalog.cc:455] T 00000000000000000000000000000000 P 4cacd3c44df5455c9b2c7c98a814d317 [sys.catalog]: SysCatalogTable state changed. Reason: New leader 4cacd3c44df5455c9b2c7c98a814d317. Latest consensus state: current_term: 1 leader_uuid: "4cacd3c44df5455c9b2c7c98a814d317" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "4cacd3c44df5455c9b2c7c98a814d317" member_type: VOTER } }
I20260812 06:17:23.364419 22495 sys_catalog.cc:455] T 00000000000000000000000000000000 P 4cacd3c44df5455c9b2c7c98a814d317 [sys.catalog]: SysCatalogTable state changed. Reason: RaftConsensus started. Latest consensus state: current_term: 1 leader_uuid: "4cacd3c44df5455c9b2c7c98a814d317" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "4cacd3c44df5455c9b2c7c98a814d317" member_type: VOTER } }
I20260812 06:17:23.364497 22496 sys_catalog.cc:458] T 00000000000000000000000000000000 P 4cacd3c44df5455c9b2c7c98a814d317 [sys.catalog]: This master's current role is: LEADER
I20260812 06:17:23.364506 22495 sys_catalog.cc:458] T 00000000000000000000000000000000 P 4cacd3c44df5455c9b2c7c98a814d317 [sys.catalog]: This master's current role is: LEADER
I20260812 06:17:23.364912 22369 internal_mini_cluster.cc:184] Waiting to initialize catalog manager on master 0
I20260812 06:17:23.364895 22516 catalog_manager.cc:1511] Loading table and tablet metadata into memory...
I20260812 06:17:23.367012 22516 catalog_manager.cc:1520] Initializing Kudu cluster ID...
I20260812 06:17:23.371351 22516 catalog_manager.cc:1383] Generated new cluster ID: 12697ee699b74419b22650a4f860985e
I20260812 06:17:23.371410 22516 catalog_manager.cc:1531] Initializing Kudu internal certificate authority...
I20260812 06:17:23.380846 22516 catalog_manager.cc:1406] Generated new certificate authority record
I20260812 06:17:23.381840 22516 catalog_manager.cc:1540] Loading token signing keys...
I20260812 06:17:23.396060 22516 catalog_manager.cc:6092] T 00000000000000000000000000000000 P 4cacd3c44df5455c9b2c7c98a814d317: Generated new TSK 0
I20260812 06:17:23.396682 22516 catalog_manager.cc:1550] Initializing in-progress tserver states...
I20260812 06:17:23.429479 22369 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:17:23.432024 22533 instance_detector.cc:116] could not retrieve OpenStack instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:17:23.432044 22527 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:23.432097 22525 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:23.432310 22369 server_base.cc:1061] running on GCE node
I20260812 06:17:23.432543 22369 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:17:23.432600 22369 system_unsync_time.cc:38] NTP support is disabled. Clock error bounds will not be accurate. This configuration is not suitable for distributed clusters.
I20260812 06:17:23.432641 22369 hybrid_clock.cc:648] HybridClock initialized: now 1786515443432640 us; error 0 us; skew 500 ppm
I20260812 06:17:23.433557 22369 webserver.cc:533] Webserver started at http://127.21.216.65:41953/ using document root <none> and password file <none>
I20260812 06:17:23.433732 22369 fs_manager.cc:362] Metadata directory not provided
I20260812 06:17:23.433789 22369 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:17:23.433861 22369 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:17:23.434314 22369 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskw4CMs_/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515443298492-22369-0/minicluster-data/ts-0-root/instance:
uuid: "983de806fb0b45168f91ed578f107970"
format_stamp: "Formatted at 2026-08-12 06:17:23 on dist-test-slave-1vmg"
I20260812 06:17:23.436076 22369 fs_manager.cc:696] Time spent creating directory manager: real 0.002s	user 0.000s	sys 0.002s
I20260812 06:17:23.437165 22539 log_block_manager.cc:4127] Time spent loading block containers with low live blocks: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:17:23.437428 22369 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.000s	sys 0.001s
I20260812 06:17:23.437503 22369 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskw4CMs_/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515443298492-22369-0/minicluster-data/ts-0-root
uuid: "983de806fb0b45168f91ed578f107970"
format_stamp: "Formatted at 2026-08-12 06:17:23 on dist-test-slave-1vmg"
I20260812 06:17:23.437567 22369 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskw4CMs_/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515443298492-22369-0/minicluster-data/ts-0-root
metadata directory: /tmp/dist-test-taskw4CMs_/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515443298492-22369-0/minicluster-data/ts-0-root
1 data directories: /tmp/dist-test-taskw4CMs_/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515443298492-22369-0/minicluster-data/ts-0-root/data
Total live blocks: 0
Total live bytes: 0
Total live bytes (after alignment): 0
Total number of LBM containers: 0 (0 full)
Did not check for missing blocks
Did not check for orphaned blocks
Total full LBM containers with extra space: 0 (0 repaired)
Total full LBM container extra space in bytes: 0 (0 repaired)
Total incomplete LBM containers: 0 (0 repaired)
Total LBM partial records: 0 (0 repaired)
Total corrupted LBM metadata records in RocksDB: 0 (0 repaired)
I20260812 06:17:23.474239 22369 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:17:23.474763 22369 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:17:23.475319 22369 txn_system_client.cc:432] TxnSystemClient initialization is disabled...
I20260812 06:17:23.476336 22369 ts_tablet_manager.cc:585] Loaded tablet metadata (0 total tablets, 0 live tablets)
I20260812 06:17:23.476402 22369 ts_tablet_manager.cc:531] Time spent load tablet metadata: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:17:23.476464 22369 ts_tablet_manager.cc:616] Registered 0 tablets
I20260812 06:17:23.476495 22369 ts_tablet_manager.cc:595] Time spent register tablets: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:17:23.483127 22369 rpc_server.cc:307] RPC server started. Bound to: 127.21.216.65:38835
I20260812 06:17:23.483214 22648 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.21.216.65:38835 every 8 connection(s)
I20260812 06:17:23.492038 22650 heartbeater.cc:344] Connected to a master server at 127.21.216.126:39691
I20260812 06:17:23.492247 22650 heartbeater.cc:461] Registering TS with master...
I20260812 06:17:23.492636 22650 heartbeater.cc:507] Master 127.21.216.126:39691 requested a full tablet report, sending...
I20260812 06:17:23.494102 22417 ts_manager.cc:194] Registered new tserver with Master: 983de806fb0b45168f91ed578f107970 (127.21.216.65:38835)
I20260812 06:17:23.495051 22369 internal_mini_cluster.cc:371] 1 TS(s) registered with all masters after 0.011281368s
I20260812 06:17:23.495570 22417 master_service.cc:502] Signed X509 certificate for tserver {username='slave'} at 127.0.0.1:49240
I20260812 06:17:23.507422 22417 catalog_manager.cc:2283] Servicing CreateTable request from {username='slave'} at 127.0.0.1:49242:
name: "heavy-update-compaction-test"
schema {
  columns {
    name: "key"
    type: INT64
    is_key: true
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_a"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_b"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_c"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_d"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_e"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
}
num_replicas: 1
split_rows_range_bounds {
}
partition_schema {
  range_schema {
  }
}
I20260812 06:17:23.521999 22593 tablet_service.cc:1511] Processing CreateTablet for tablet 65b521f285f94f8b8dfd2dbb93869b8b (DEFAULT_TABLE table=heavy-update-compaction-test [id=c3e7f7844e8e4b5d8b70b07080286772]), partition=
I20260812 06:17:23.522396 22593 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet 65b521f285f94f8b8dfd2dbb93869b8b. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:17:23.524464 22678 tablet_bootstrap.cc:492] T 65b521f285f94f8b8dfd2dbb93869b8b P 983de806fb0b45168f91ed578f107970: Bootstrap starting.
I20260812 06:17:23.525457 22678 tablet_bootstrap.cc:654] T 65b521f285f94f8b8dfd2dbb93869b8b P 983de806fb0b45168f91ed578f107970: Neither blocks nor log segments found. Creating new log.
I20260812 06:17:23.526908 22678 tablet_bootstrap.cc:492] T 65b521f285f94f8b8dfd2dbb93869b8b P 983de806fb0b45168f91ed578f107970: No bootstrap required, opened a new log
I20260812 06:17:23.527091 22678 ts_tablet_manager.cc:1403] T 65b521f285f94f8b8dfd2dbb93869b8b P 983de806fb0b45168f91ed578f107970: Time spent bootstrapping tablet: real 0.003s	user 0.002s	sys 0.000s
I20260812 06:17:23.527527 22678 raft_consensus.cc:359] T 65b521f285f94f8b8dfd2dbb93869b8b P 983de806fb0b45168f91ed578f107970 [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "983de806fb0b45168f91ed578f107970" member_type: VOTER last_known_addr { host: "127.21.216.65" port: 38835 } }
I20260812 06:17:23.527622 22678 raft_consensus.cc:385] T 65b521f285f94f8b8dfd2dbb93869b8b P 983de806fb0b45168f91ed578f107970 [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:17:23.527655 22678 raft_consensus.cc:740] T 65b521f285f94f8b8dfd2dbb93869b8b P 983de806fb0b45168f91ed578f107970 [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: 983de806fb0b45168f91ed578f107970, State: Initialized, Role: FOLLOWER
I20260812 06:17:23.527783 22678 consensus_queue.cc:260] T 65b521f285f94f8b8dfd2dbb93869b8b P 983de806fb0b45168f91ed578f107970 [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: "983de806fb0b45168f91ed578f107970" member_type: VOTER last_known_addr { host: "127.21.216.65" port: 38835 } }
I20260812 06:17:23.527865 22678 raft_consensus.cc:399] T 65b521f285f94f8b8dfd2dbb93869b8b P 983de806fb0b45168f91ed578f107970 [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:17:23.527890 22678 raft_consensus.cc:493] T 65b521f285f94f8b8dfd2dbb93869b8b P 983de806fb0b45168f91ed578f107970 [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:17:23.527935 22678 raft_consensus.cc:3060] T 65b521f285f94f8b8dfd2dbb93869b8b P 983de806fb0b45168f91ed578f107970 [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:17:23.528617 22678 raft_consensus.cc:515] T 65b521f285f94f8b8dfd2dbb93869b8b P 983de806fb0b45168f91ed578f107970 [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "983de806fb0b45168f91ed578f107970" member_type: VOTER last_known_addr { host: "127.21.216.65" port: 38835 } }
I20260812 06:17:23.528759 22678 leader_election.cc:304] T 65b521f285f94f8b8dfd2dbb93869b8b P 983de806fb0b45168f91ed578f107970 [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: 983de806fb0b45168f91ed578f107970; no voters: 
I20260812 06:17:23.528955 22678 leader_election.cc:290] T 65b521f285f94f8b8dfd2dbb93869b8b P 983de806fb0b45168f91ed578f107970 [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:17:23.529084 22680 raft_consensus.cc:2804] T 65b521f285f94f8b8dfd2dbb93869b8b P 983de806fb0b45168f91ed578f107970 [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:17:23.529349 22680 raft_consensus.cc:697] T 65b521f285f94f8b8dfd2dbb93869b8b P 983de806fb0b45168f91ed578f107970 [term 1 LEADER]: Becoming Leader. State: Replica: 983de806fb0b45168f91ed578f107970, State: Running, Role: LEADER
I20260812 06:17:23.529407 22678 ts_tablet_manager.cc:1434] T 65b521f285f94f8b8dfd2dbb93869b8b P 983de806fb0b45168f91ed578f107970: Time spent starting tablet: real 0.002s	user 0.002s	sys 0.000s
I20260812 06:17:23.529760 22650 heartbeater.cc:499] Master 127.21.216.126:39691 was elected leader, sending a full tablet report...
I20260812 06:17:23.529838 22680 consensus_queue.cc:237] T 65b521f285f94f8b8dfd2dbb93869b8b P 983de806fb0b45168f91ed578f107970 [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: "983de806fb0b45168f91ed578f107970" member_type: VOTER last_known_addr { host: "127.21.216.65" port: 38835 } }
I20260812 06:17:23.532207 22417 catalog_manager.cc:5719] T 65b521f285f94f8b8dfd2dbb93869b8b P 983de806fb0b45168f91ed578f107970 reported cstate change: term changed from 0 to 1, leader changed from <none> to 983de806fb0b45168f91ed578f107970 (127.21.216.65). New cstate: current_term: 1 leader_uuid: "983de806fb0b45168f91ed578f107970" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "983de806fb0b45168f91ed578f107970" member_type: VOTER last_known_addr { host: "127.21.216.65" port: 38835 } health_report { overall_health: HEALTHY } } }
I20260812 06:17:23.589893 22369 heavy-update-compaction-itest.cc:215] Time spent inserting: real 0.048s	user 0.006s	sys 0.017s
I20260812 06:17:23.734189 22652 maintenance_manager.cc:419] P 983de806fb0b45168f91ed578f107970: Scheduling FlushMRSOp(65b521f285f94f8b8dfd2dbb93869b8b): perf score=19.054940
I20260812 06:17:23.935688 22549 maintenance_manager.cc:643] P 983de806fb0b45168f91ed578f107970: FlushMRSOp(65b521f285f94f8b8dfd2dbb93869b8b) complete. Timing: real 0.201s	user 0.159s	sys 0.039s Metrics: {"bytes_written":17681644,"cfile_init":1,"compiler_manager_pool.queue_time_us":194,"delete_count":0,"dirs.queue_time_us":47,"dirs.run_cpu_time_us":170,"dirs.run_wall_time_us":808,"drs_written":1,"lbm_read_time_us":71,"lbm_reads_lt_1ms":4,"lbm_write_time_us":49256,"lbm_writes_lt_1ms":898,"mutex_wait_us":874,"peak_mem_usage":0,"reinsert_count":0,"rows_written":105,"spinlock_wait_cycles":162048,"thread_start_us":113,"threads_started":1,"update_count":2155}
I20260812 06:17:23.936718 22652 maintenance_manager.cc:419] P 983de806fb0b45168f91ed578f107970: Scheduling LogGCOp(65b521f285f94f8b8dfd2dbb93869b8b): free 20743880 bytes of WAL
I20260812 06:17:23.937005 22549 log_reader.cc:385] T 65b521f285f94f8b8dfd2dbb93869b8b: removed 2 log segments from log reader
I20260812 06:17:23.937067 22549 log.cc:1079] T 65b521f285f94f8b8dfd2dbb93869b8b P 983de806fb0b45168f91ed578f107970: Deleting log segment in path: /tmp/dist-test-taskw4CMs_/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515443298492-22369-0/minicluster-data/ts-0-root/wals/65b521f285f94f8b8dfd2dbb93869b8b/wal-000000001 (ops 1-6)
I20260812 06:17:23.937137 22549 log.cc:1079] T 65b521f285f94f8b8dfd2dbb93869b8b P 983de806fb0b45168f91ed578f107970: Deleting log segment in path: /tmp/dist-test-taskw4CMs_/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515443298492-22369-0/minicluster-data/ts-0-root/wals/65b521f285f94f8b8dfd2dbb93869b8b/wal-000000002 (ops 7-11)
I20260812 06:17:23.940696 22549 maintenance_manager.cc:643] P 983de806fb0b45168f91ed578f107970: LogGCOp(65b521f285f94f8b8dfd2dbb93869b8b) complete. Timing: real 0.004s	user 0.000s	sys 0.002s Metrics: {}
I20260812 06:17:23.940992 22652 maintenance_manager.cc:419] P 983de806fb0b45168f91ed578f107970: Scheduling UndoDeltaBlockGCOp(65b521f285f94f8b8dfd2dbb93869b8b): 16821646 bytes on disk
I20260812 06:17:23.941481 22549 maintenance_manager.cc:643] P 983de806fb0b45168f91ed578f107970: UndoDeltaBlockGCOp(65b521f285f94f8b8dfd2dbb93869b8b) 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:23.941849 22652 maintenance_manager.cc:419] P 983de806fb0b45168f91ed578f107970: Scheduling FlushDeltaMemStoresOp(65b521f285f94f8b8dfd2dbb93869b8b): perf score=5.165500
I20260812 06:17:23.957968 22549 maintenance_manager.cc:643] P 983de806fb0b45168f91ed578f107970: FlushDeltaMemStoresOp(65b521f285f94f8b8dfd2dbb93869b8b) complete. Timing: real 0.016s	user 0.006s	sys 0.007s Metrics: {"bytes_written":6523096,"delete_count":0,"lbm_write_time_us":6333,"lbm_writes_lt_1ms":162,"reinsert_count":0,"update_count":795}
I20260812 06:17:23.958477 22652 maintenance_manager.cc:419] P 983de806fb0b45168f91ed578f107970: Scheduling MajorDeltaCompactionOp(65b521f285f94f8b8dfd2dbb93869b8b): perf score=1.000000
I20260812 06:17:24.139510 22549 maintenance_manager.cc:643] P 983de806fb0b45168f91ed578f107970: MajorDeltaCompactionOp(65b521f285f94f8b8dfd2dbb93869b8b) complete. Timing: real 0.181s	user 0.122s	sys 0.055s Metrics: {"cfile_cache_miss":622,"cfile_cache_miss_bytes":28507857,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":414,"lbm_read_time_us":11544,"lbm_reads_lt_1ms":654,"lbm_write_time_us":30864,"lbm_writes_lt_1ms":633,"peak_mem_usage":74091738,"reinsert_count":0,"thread_start_us":218,"threads_started":5,"update_count":2950}
I20260812 06:17:24.139946 22652 maintenance_manager.cc:419] P 983de806fb0b45168f91ed578f107970: Scheduling FlushDeltaMemStoresOp(65b521f285f94f8b8dfd2dbb93869b8b): perf score=14.095187
I20260812 06:17:24.197073 22549 maintenance_manager.cc:643] P 983de806fb0b45168f91ed578f107970: FlushDeltaMemStoresOp(65b521f285f94f8b8dfd2dbb93869b8b) complete. Timing: real 0.057s	user 0.024s	sys 0.017s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":19171,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:17:24.197520 22652 maintenance_manager.cc:419] P 983de806fb0b45168f91ed578f107970: Scheduling FlushDeltaMemStoresOp(65b521f285f94f8b8dfd2dbb93869b8b): perf score=2.188937
I20260812 06:17:24.207094 22549 maintenance_manager.cc:643] P 983de806fb0b45168f91ed578f107970: FlushDeltaMemStoresOp(65b521f285f94f8b8dfd2dbb93869b8b) complete. Timing: real 0.009s	user 0.005s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3714,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:24.207454 22652 maintenance_manager.cc:419] P 983de806fb0b45168f91ed578f107970: Scheduling MajorDeltaCompactionOp(65b521f285f94f8b8dfd2dbb93869b8b): perf score=1.000000
I20260812 06:17:24.359761 22549 maintenance_manager.cc:643] P 983de806fb0b45168f91ed578f107970: MajorDeltaCompactionOp(65b521f285f94f8b8dfd2dbb93869b8b) complete. Timing: real 0.152s	user 0.120s	sys 0.032s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24815683,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":121,"lbm_read_time_us":11002,"lbm_reads_lt_1ms":572,"lbm_write_time_us":26233,"lbm_writes_lt_1ms":543,"mutex_wait_us":22,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":8960,"update_count":2500}
I20260812 06:17:24.360355 22652 maintenance_manager.cc:419] P 983de806fb0b45168f91ed578f107970: Scheduling FlushDeltaMemStoresOp(65b521f285f94f8b8dfd2dbb93869b8b): perf score=11.118625
I20260812 06:17:24.406358 22549 maintenance_manager.cc:643] P 983de806fb0b45168f91ed578f107970: FlushDeltaMemStoresOp(65b521f285f94f8b8dfd2dbb93869b8b) complete. Timing: real 0.046s	user 0.023s	sys 0.017s Metrics: {"bytes_written":12717735,"delete_count":0,"lbm_write_time_us":14768,"lbm_writes_1-10_ms":2,"lbm_writes_lt_1ms":311,"reinsert_count":0,"update_count":1550}
I20260812 06:17:24.406951 22652 maintenance_manager.cc:419] P 983de806fb0b45168f91ed578f107970: Scheduling FlushDeltaMemStoresOp(65b521f285f94f8b8dfd2dbb93869b8b): perf score=3.181125
I20260812 06:17:24.422833 22549 maintenance_manager.cc:643] P 983de806fb0b45168f91ed578f107970: FlushDeltaMemStoresOp(65b521f285f94f8b8dfd2dbb93869b8b) complete. Timing: real 0.016s	user 0.013s	sys 0.001s Metrics: {"bytes_written":4553929,"delete_count":0,"lbm_write_time_us":6606,"lbm_writes_lt_1ms":114,"reinsert_count":0,"update_count":555}
I20260812 06:17:24.423244 22652 maintenance_manager.cc:419] P 983de806fb0b45168f91ed578f107970: Scheduling FlushDeltaMemStoresOp(65b521f285f94f8b8dfd2dbb93869b8b): perf score=2.188937
I20260812 06:17:24.431311 22549 maintenance_manager.cc:643] P 983de806fb0b45168f91ed578f107970: FlushDeltaMemStoresOp(65b521f285f94f8b8dfd2dbb93869b8b) complete. Timing: real 0.008s	user 0.007s	sys 0.000s Metrics: {"bytes_written":3241130,"delete_count":0,"lbm_write_time_us":3021,"lbm_writes_lt_1ms":82,"reinsert_count":0,"update_count":395}
I20260812 06:17:24.431661 22652 maintenance_manager.cc:419] P 983de806fb0b45168f91ed578f107970: Scheduling MajorDeltaCompactionOp(65b521f285f94f8b8dfd2dbb93869b8b): perf score=1.000000
I20260812 06:17:24.613984 22549 maintenance_manager.cc:643] P 983de806fb0b45168f91ed578f107970: MajorDeltaCompactionOp(65b521f285f94f8b8dfd2dbb93869b8b) complete. Timing: real 0.182s	user 0.116s	sys 0.053s Metrics: {"cfile_cache_miss":533,"cfile_cache_miss_bytes":24815789,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":211,"lbm_read_time_us":12080,"lbm_reads_lt_1ms":573,"lbm_write_time_us":32689,"lbm_writes_lt_1ms":543,"peak_mem_usage":63115900,"reinsert_count":0,"update_count":2500}
I20260812 06:17:24.614472 22652 maintenance_manager.cc:419] P 983de806fb0b45168f91ed578f107970: Scheduling FlushDeltaMemStoresOp(65b521f285f94f8b8dfd2dbb93869b8b): perf score=14.095187
I20260812 06:17:24.672479 22549 maintenance_manager.cc:643] P 983de806fb0b45168f91ed578f107970: FlushDeltaMemStoresOp(65b521f285f94f8b8dfd2dbb93869b8b) complete. Timing: real 0.058s	user 0.029s	sys 0.027s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":22354,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:17:24.672981 22652 maintenance_manager.cc:419] P 983de806fb0b45168f91ed578f107970: Scheduling FlushDeltaMemStoresOp(65b521f285f94f8b8dfd2dbb93869b8b): perf score=2.188937
I20260812 06:17:24.689385 22549 maintenance_manager.cc:643] P 983de806fb0b45168f91ed578f107970: FlushDeltaMemStoresOp(65b521f285f94f8b8dfd2dbb93869b8b) complete. Timing: real 0.016s	user 0.011s	sys 0.003s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":6574,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:24.689899 22652 maintenance_manager.cc:419] P 983de806fb0b45168f91ed578f107970: Scheduling MajorDeltaCompactionOp(65b521f285f94f8b8dfd2dbb93869b8b): perf score=1.000000
I20260812 06:17:24.865301 22549 maintenance_manager.cc:643] P 983de806fb0b45168f91ed578f107970: MajorDeltaCompactionOp(65b521f285f94f8b8dfd2dbb93869b8b) complete. Timing: real 0.175s	user 0.121s	sys 0.044s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24815683,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":130,"lbm_read_time_us":14267,"lbm_reads_lt_1ms":572,"lbm_write_time_us":28288,"lbm_writes_lt_1ms":543,"mutex_wait_us":54,"peak_mem_usage":63115900,"reinsert_count":0,"update_count":2500}
I20260812 06:17:24.865796 22652 maintenance_manager.cc:419] P 983de806fb0b45168f91ed578f107970: Scheduling FlushDeltaMemStoresOp(65b521f285f94f8b8dfd2dbb93869b8b): perf score=14.095187
I20260812 06:17:24.915234 22549 maintenance_manager.cc:643] P 983de806fb0b45168f91ed578f107970: FlushDeltaMemStoresOp(65b521f285f94f8b8dfd2dbb93869b8b) complete. Timing: real 0.049s	user 0.032s	sys 0.012s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":19618,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:17:24.915767 22652 maintenance_manager.cc:419] P 983de806fb0b45168f91ed578f107970: Scheduling FlushDeltaMemStoresOp(65b521f285f94f8b8dfd2dbb93869b8b): perf score=2.188937
I20260812 06:17:24.933931 22549 maintenance_manager.cc:643] P 983de806fb0b45168f91ed578f107970: FlushDeltaMemStoresOp(65b521f285f94f8b8dfd2dbb93869b8b) complete. Timing: real 0.018s	user 0.008s	sys 0.007s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3826,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:24.934515 22652 maintenance_manager.cc:419] P 983de806fb0b45168f91ed578f107970: Scheduling MajorDeltaCompactionOp(65b521f285f94f8b8dfd2dbb93869b8b): perf score=1.000000
I20260812 06:17:25.083807 22549 maintenance_manager.cc:643] P 983de806fb0b45168f91ed578f107970: MajorDeltaCompactionOp(65b521f285f94f8b8dfd2dbb93869b8b) complete. Timing: real 0.149s	user 0.105s	sys 0.043s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24815683,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":210,"lbm_read_time_us":11724,"lbm_reads_lt_1ms":572,"lbm_write_time_us":25042,"lbm_writes_lt_1ms":543,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":768,"update_count":2500}
I20260812 06:17:25.084412 22652 maintenance_manager.cc:419] P 983de806fb0b45168f91ed578f107970: Scheduling FlushDeltaMemStoresOp(65b521f285f94f8b8dfd2dbb93869b8b): perf score=10.126437
I20260812 06:17:25.117527 22549 maintenance_manager.cc:643] P 983de806fb0b45168f91ed578f107970: FlushDeltaMemStoresOp(65b521f285f94f8b8dfd2dbb93869b8b) complete. Timing: real 0.033s	user 0.018s	sys 0.008s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":12316,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:17:25.118014 22652 maintenance_manager.cc:419] P 983de806fb0b45168f91ed578f107970: Scheduling FlushDeltaMemStoresOp(65b521f285f94f8b8dfd2dbb93869b8b): perf score=2.188937
I20260812 06:17:25.129987 22549 maintenance_manager.cc:643] P 983de806fb0b45168f91ed578f107970: FlushDeltaMemStoresOp(65b521f285f94f8b8dfd2dbb93869b8b) complete. Timing: real 0.012s	user 0.007s	sys 0.003s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4361,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:25.130491 22652 maintenance_manager.cc:419] P 983de806fb0b45168f91ed578f107970: Scheduling FlushMRSOp(65b521f285f94f8b8dfd2dbb93869b8b): perf score=1.000000
I20260812 06:17:25.160147 22549 maintenance_manager.cc:643] P 983de806fb0b45168f91ed578f107970: FlushMRSOp(65b521f285f94f8b8dfd2dbb93869b8b) complete. Timing: real 0.029s	user 0.028s	sys 0.000s Metrics: {"bytes_written":1193503,"cfile_init":1,"dirs.queue_time_us":57,"dirs.run_cpu_time_us":222,"dirs.run_wall_time_us":1231,"drs_written":1,"lbm_read_time_us":48,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1395,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":29}
I20260812 06:17:25.160908 22652 maintenance_manager.cc:419] P 983de806fb0b45168f91ed578f107970: Scheduling LogGCOp(65b521f285f94f8b8dfd2dbb93869b8b): free 124710308 bytes of WAL
I20260812 06:17:25.161128 22549 log_reader.cc:385] T 65b521f285f94f8b8dfd2dbb93869b8b: removed 12 log segments from log reader
I20260812 06:17:25.161176 22549 log.cc:1079] T 65b521f285f94f8b8dfd2dbb93869b8b P 983de806fb0b45168f91ed578f107970: Deleting log segment in path: /tmp/dist-test-taskw4CMs_/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515443298492-22369-0/minicluster-data/ts-0-root/wals/65b521f285f94f8b8dfd2dbb93869b8b/wal-000000003 (ops 12-16)
I20260812 06:17:25.161203 22549 log.cc:1079] T 65b521f285f94f8b8dfd2dbb93869b8b P 983de806fb0b45168f91ed578f107970: Deleting log segment in path: /tmp/dist-test-taskw4CMs_/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515443298492-22369-0/minicluster-data/ts-0-root/wals/65b521f285f94f8b8dfd2dbb93869b8b/wal-000000004 (ops 17-21)
I20260812 06:17:25.161230 22549 log.cc:1079] T 65b521f285f94f8b8dfd2dbb93869b8b P 983de806fb0b45168f91ed578f107970: Deleting log segment in path: /tmp/dist-test-taskw4CMs_/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515443298492-22369-0/minicluster-data/ts-0-root/wals/65b521f285f94f8b8dfd2dbb93869b8b/wal-000000005 (ops 22-26)
I20260812 06:17:25.161260 22549 log.cc:1079] T 65b521f285f94f8b8dfd2dbb93869b8b P 983de806fb0b45168f91ed578f107970: Deleting log segment in path: /tmp/dist-test-taskw4CMs_/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515443298492-22369-0/minicluster-data/ts-0-root/wals/65b521f285f94f8b8dfd2dbb93869b8b/wal-000000006 (ops 27-31)
I20260812 06:17:25.161294 22549 log.cc:1079] T 65b521f285f94f8b8dfd2dbb93869b8b P 983de806fb0b45168f91ed578f107970: Deleting log segment in path: /tmp/dist-test-taskw4CMs_/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515443298492-22369-0/minicluster-data/ts-0-root/wals/65b521f285f94f8b8dfd2dbb93869b8b/wal-000000007 (ops 32-36)
I20260812 06:17:25.161329 22549 log.cc:1079] T 65b521f285f94f8b8dfd2dbb93869b8b P 983de806fb0b45168f91ed578f107970: Deleting log segment in path: /tmp/dist-test-taskw4CMs_/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515443298492-22369-0/minicluster-data/ts-0-root/wals/65b521f285f94f8b8dfd2dbb93869b8b/wal-000000008 (ops 37-41)
I20260812 06:17:25.161351 22549 log.cc:1079] T 65b521f285f94f8b8dfd2dbb93869b8b P 983de806fb0b45168f91ed578f107970: Deleting log segment in path: /tmp/dist-test-taskw4CMs_/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515443298492-22369-0/minicluster-data/ts-0-root/wals/65b521f285f94f8b8dfd2dbb93869b8b/wal-000000009 (ops 42-46)
I20260812 06:17:25.161382 22549 log.cc:1079] T 65b521f285f94f8b8dfd2dbb93869b8b P 983de806fb0b45168f91ed578f107970: Deleting log segment in path: /tmp/dist-test-taskw4CMs_/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515443298492-22369-0/minicluster-data/ts-0-root/wals/65b521f285f94f8b8dfd2dbb93869b8b/wal-000000010 (ops 47-51)
I20260812 06:17:25.161414 22549 log.cc:1079] T 65b521f285f94f8b8dfd2dbb93869b8b P 983de806fb0b45168f91ed578f107970: Deleting log segment in path: /tmp/dist-test-taskw4CMs_/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515443298492-22369-0/minicluster-data/ts-0-root/wals/65b521f285f94f8b8dfd2dbb93869b8b/wal-000000011 (ops 52-56)
I20260812 06:17:25.161446 22549 log.cc:1079] T 65b521f285f94f8b8dfd2dbb93869b8b P 983de806fb0b45168f91ed578f107970: Deleting log segment in path: /tmp/dist-test-taskw4CMs_/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515443298492-22369-0/minicluster-data/ts-0-root/wals/65b521f285f94f8b8dfd2dbb93869b8b/wal-000000012 (ops 57-61)
I20260812 06:17:25.161477 22549 log.cc:1079] T 65b521f285f94f8b8dfd2dbb93869b8b P 983de806fb0b45168f91ed578f107970: Deleting log segment in path: /tmp/dist-test-taskw4CMs_/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515443298492-22369-0/minicluster-data/ts-0-root/wals/65b521f285f94f8b8dfd2dbb93869b8b/wal-000000013 (ops 62-66)
I20260812 06:17:25.161509 22549 log.cc:1079] T 65b521f285f94f8b8dfd2dbb93869b8b P 983de806fb0b45168f91ed578f107970: Deleting log segment in path: /tmp/dist-test-taskw4CMs_/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515443298492-22369-0/minicluster-data/ts-0-root/wals/65b521f285f94f8b8dfd2dbb93869b8b/wal-000000014 (ops 67-71)
I20260812 06:17:25.184281 22549 maintenance_manager.cc:643] P 983de806fb0b45168f91ed578f107970: LogGCOp(65b521f285f94f8b8dfd2dbb93869b8b) complete. Timing: real 0.023s	user 0.000s	sys 0.022s Metrics: {}
I20260812 06:17:25.184784 22652 maintenance_manager.cc:419] P 983de806fb0b45168f91ed578f107970: Scheduling UndoDeltaBlockGCOp(65b521f285f94f8b8dfd2dbb93869b8b): 462 bytes on disk
I20260812 06:17:25.185261 22549 maintenance_manager.cc:643] P 983de806fb0b45168f91ed578f107970: UndoDeltaBlockGCOp(65b521f285f94f8b8dfd2dbb93869b8b) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":79,"lbm_reads_lt_1ms":4}
I20260812 06:17:25.185729 22652 maintenance_manager.cc:419] P 983de806fb0b45168f91ed578f107970: Scheduling FlushDeltaMemStoresOp(65b521f285f94f8b8dfd2dbb93869b8b): perf score=3.181125
I20260812 06:17:25.205679 22549 maintenance_manager.cc:643] P 983de806fb0b45168f91ed578f107970: FlushDeltaMemStoresOp(65b521f285f94f8b8dfd2dbb93869b8b) complete. Timing: real 0.020s	user 0.007s	sys 0.010s Metrics: {"bytes_written":5210310,"delete_count":0,"lbm_write_time_us":4712,"lbm_writes_lt_1ms":130,"reinsert_count":0,"update_count":635}
I20260812 06:17:25.206064 22652 maintenance_manager.cc:419] P 983de806fb0b45168f91ed578f107970: Scheduling FlushDeltaMemStoresOp(65b521f285f94f8b8dfd2dbb93869b8b): perf score=1.196750
I20260812 06:17:25.217094 22549 maintenance_manager.cc:643] P 983de806fb0b45168f91ed578f107970: FlushDeltaMemStoresOp(65b521f285f94f8b8dfd2dbb93869b8b) complete. Timing: real 0.011s	user 0.002s	sys 0.007s Metrics: {"bytes_written":2994980,"delete_count":0,"lbm_write_time_us":4063,"lbm_writes_lt_1ms":76,"reinsert_count":0,"update_count":365}
I20260812 06:17:25.217483 22652 maintenance_manager.cc:419] P 983de806fb0b45168f91ed578f107970: Scheduling MajorDeltaCompactionOp(65b521f285f94f8b8dfd2dbb93869b8b): perf score=1.000000
I20260812 06:17:25.412894 22549 maintenance_manager.cc:643] P 983de806fb0b45168f91ed578f107970: MajorDeltaCompactionOp(65b521f285f94f8b8dfd2dbb93869b8b) complete. Timing: real 0.195s	user 0.134s	sys 0.053s Metrics: {"cfile_cache_miss":634,"cfile_cache_miss_bytes":28918306,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":2859,"lbm_read_time_us":14039,"lbm_reads_lt_1ms":674,"lbm_write_time_us":33958,"lbm_writes_lt_1ms":643,"mutex_wait_us":1896,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":768,"thread_start_us":144,"threads_started":1,"update_count":3000}
I20260812 06:17:25.413359 22652 maintenance_manager.cc:419] P 983de806fb0b45168f91ed578f107970: Scheduling FlushDeltaMemStoresOp(65b521f285f94f8b8dfd2dbb93869b8b): perf score=14.095187
I20260812 06:17:25.468601 22549 maintenance_manager.cc:643] P 983de806fb0b45168f91ed578f107970: FlushDeltaMemStoresOp(65b521f285f94f8b8dfd2dbb93869b8b) complete. Timing: real 0.055s	user 0.034s	sys 0.019s Metrics: {"bytes_written":16409903,"delete_count":0,"lbm_write_time_us":21446,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:17:25.469069 22652 maintenance_manager.cc:419] P 983de806fb0b45168f91ed578f107970: Scheduling FlushDeltaMemStoresOp(65b521f285f94f8b8dfd2dbb93869b8b): perf score=2.188937
I20260812 06:17:25.479005 22549 maintenance_manager.cc:643] P 983de806fb0b45168f91ed578f107970: FlushDeltaMemStoresOp(65b521f285f94f8b8dfd2dbb93869b8b) complete. Timing: real 0.010s	user 0.006s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3763,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:25.479395 22652 maintenance_manager.cc:419] P 983de806fb0b45168f91ed578f107970: Scheduling MajorDeltaCompactionOp(65b521f285f94f8b8dfd2dbb93869b8b): perf score=1.000000
I20260812 06:17:25.664973 22549 maintenance_manager.cc:643] P 983de806fb0b45168f91ed578f107970: MajorDeltaCompactionOp(65b521f285f94f8b8dfd2dbb93869b8b) complete. Timing: real 0.185s	user 0.123s	sys 0.051s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24815685,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":665,"lbm_read_time_us":12205,"lbm_reads_lt_1ms":572,"lbm_write_time_us":31680,"lbm_writes_lt_1ms":543,"mutex_wait_us":384,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":817792,"update_count":2500}
I20260812 06:17:25.665459 22652 maintenance_manager.cc:419] P 983de806fb0b45168f91ed578f107970: Scheduling FlushDeltaMemStoresOp(65b521f285f94f8b8dfd2dbb93869b8b): perf score=14.095187
I20260812 06:17:25.714344 22549 maintenance_manager.cc:643] P 983de806fb0b45168f91ed578f107970: FlushDeltaMemStoresOp(65b521f285f94f8b8dfd2dbb93869b8b) complete. Timing: real 0.049s	user 0.021s	sys 0.024s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":21843,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:17:25.714828 22652 maintenance_manager.cc:419] P 983de806fb0b45168f91ed578f107970: Scheduling FlushDeltaMemStoresOp(65b521f285f94f8b8dfd2dbb93869b8b): perf score=2.188937
I20260812 06:17:25.731878 22549 maintenance_manager.cc:643] P 983de806fb0b45168f91ed578f107970: FlushDeltaMemStoresOp(65b521f285f94f8b8dfd2dbb93869b8b) complete. Timing: real 0.017s	user 0.012s	sys 0.004s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":3835,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:25.732336 22652 maintenance_manager.cc:419] P 983de806fb0b45168f91ed578f107970: Scheduling MajorDeltaCompactionOp(65b521f285f94f8b8dfd2dbb93869b8b): perf score=1.000000
I20260812 06:17:25.900569 22549 maintenance_manager.cc:643] P 983de806fb0b45168f91ed578f107970: MajorDeltaCompactionOp(65b521f285f94f8b8dfd2dbb93869b8b) complete. Timing: real 0.168s	user 0.106s	sys 0.060s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24815683,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":968,"lbm_read_time_us":11464,"lbm_reads_lt_1ms":572,"lbm_write_time_us":26870,"lbm_writes_lt_1ms":543,"mutex_wait_us":298,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":2560,"update_count":2500}
I20260812 06:17:25.901078 22652 maintenance_manager.cc:419] P 983de806fb0b45168f91ed578f107970: Scheduling FlushDeltaMemStoresOp(65b521f285f94f8b8dfd2dbb93869b8b): perf score=11.118625
I20260812 06:17:25.929455 22549 maintenance_manager.cc:643] P 983de806fb0b45168f91ed578f107970: FlushDeltaMemStoresOp(65b521f285f94f8b8dfd2dbb93869b8b) complete. Timing: real 0.028s	user 0.014s	sys 0.012s Metrics: {"bytes_written":12717735,"delete_count":0,"lbm_write_time_us":12046,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:17:25.930002 22652 maintenance_manager.cc:419] P 983de806fb0b45168f91ed578f107970: Scheduling FlushDeltaMemStoresOp(65b521f285f94f8b8dfd2dbb93869b8b): perf score=2.188937
I20260812 06:17:25.944801 22549 maintenance_manager.cc:643] P 983de806fb0b45168f91ed578f107970: FlushDeltaMemStoresOp(65b521f285f94f8b8dfd2dbb93869b8b) complete. Timing: real 0.015s	user 0.009s	sys 0.004s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":5445,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:17:25.945250 22652 maintenance_manager.cc:419] P 983de806fb0b45168f91ed578f107970: Scheduling MajorDeltaCompactionOp(65b521f285f94f8b8dfd2dbb93869b8b): perf score=1.000000
I20260812 06:17:26.057606 22549 maintenance_manager.cc:643] P 983de806fb0b45168f91ed578f107970: MajorDeltaCompactionOp(65b521f285f94f8b8dfd2dbb93869b8b) complete. Timing: real 0.112s	user 0.068s	sys 0.040s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20713263,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":178,"lbm_read_time_us":7099,"lbm_reads_lt_1ms":464,"lbm_write_time_us":21340,"lbm_writes_lt_1ms":443,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":768,"update_count":2000}
I20260812 06:17:26.058128 22652 maintenance_manager.cc:419] P 983de806fb0b45168f91ed578f107970: Scheduling FlushDeltaMemStoresOp(65b521f285f94f8b8dfd2dbb93869b8b): perf score=10.126437
I20260812 06:17:26.090843 22549 maintenance_manager.cc:643] P 983de806fb0b45168f91ed578f107970: FlushDeltaMemStoresOp(65b521f285f94f8b8dfd2dbb93869b8b) complete. Timing: real 0.033s	user 0.019s	sys 0.008s Metrics: {"bytes_written":12307491,"delete_count":0,"lbm_write_time_us":13173,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:17:26.091357 22652 maintenance_manager.cc:419] P 983de806fb0b45168f91ed578f107970: Scheduling FlushDeltaMemStoresOp(65b521f285f94f8b8dfd2dbb93869b8b): perf score=2.188937
I20260812 06:17:26.100984 22549 maintenance_manager.cc:643] P 983de806fb0b45168f91ed578f107970: FlushDeltaMemStoresOp(65b521f285f94f8b8dfd2dbb93869b8b) complete. Timing: real 0.009s	user 0.004s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3695,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:26.101528 22652 maintenance_manager.cc:419] P 983de806fb0b45168f91ed578f107970: Scheduling MajorDeltaCompactionOp(65b521f285f94f8b8dfd2dbb93869b8b): perf score=1.000000
I20260812 06:17:26.217183 22549 maintenance_manager.cc:643] P 983de806fb0b45168f91ed578f107970: MajorDeltaCompactionOp(65b521f285f94f8b8dfd2dbb93869b8b) complete. Timing: real 0.115s	user 0.095s	sys 0.020s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20713273,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":675,"lbm_read_time_us":8297,"lbm_reads_lt_1ms":472,"lbm_write_time_us":22082,"lbm_writes_lt_1ms":443,"mutex_wait_us":289,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":896,"update_count":2000}
I20260812 06:17:26.217738 22652 maintenance_manager.cc:419] P 983de806fb0b45168f91ed578f107970: Scheduling FlushDeltaMemStoresOp(65b521f285f94f8b8dfd2dbb93869b8b): perf score=10.126437
I20260812 06:17:26.263053 22549 maintenance_manager.cc:643] P 983de806fb0b45168f91ed578f107970: FlushDeltaMemStoresOp(65b521f285f94f8b8dfd2dbb93869b8b) complete. Timing: real 0.045s	user 0.018s	sys 0.019s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":16447,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:17:26.263572 22652 maintenance_manager.cc:419] P 983de806fb0b45168f91ed578f107970: Scheduling FlushDeltaMemStoresOp(65b521f285f94f8b8dfd2dbb93869b8b): perf score=2.188937
I20260812 06:17:26.273209 22549 maintenance_manager.cc:643] P 983de806fb0b45168f91ed578f107970: FlushDeltaMemStoresOp(65b521f285f94f8b8dfd2dbb93869b8b) complete. Timing: real 0.009s	user 0.004s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3658,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:26.273788 22652 maintenance_manager.cc:419] P 983de806fb0b45168f91ed578f107970: Scheduling MajorDeltaCompactionOp(65b521f285f94f8b8dfd2dbb93869b8b): perf score=1.000000
I20260812 06:17:26.386132 22549 maintenance_manager.cc:643] P 983de806fb0b45168f91ed578f107970: MajorDeltaCompactionOp(65b521f285f94f8b8dfd2dbb93869b8b) complete. Timing: real 0.112s	user 0.096s	sys 0.016s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20713272,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":769,"lbm_read_time_us":7207,"lbm_reads_lt_1ms":472,"lbm_write_time_us":21816,"lbm_writes_lt_1ms":443,"mutex_wait_us":292,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":768,"update_count":2000}
I20260812 06:17:26.386646 22652 maintenance_manager.cc:419] P 983de806fb0b45168f91ed578f107970: Scheduling FlushDeltaMemStoresOp(65b521f285f94f8b8dfd2dbb93869b8b): perf score=10.126437
I20260812 06:17:26.428598 22549 maintenance_manager.cc:643] P 983de806fb0b45168f91ed578f107970: FlushDeltaMemStoresOp(65b521f285f94f8b8dfd2dbb93869b8b) complete. Timing: real 0.042s	user 0.027s	sys 0.011s Metrics: {"bytes_written":12307492,"delete_count":0,"lbm_write_time_us":13482,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:17:26.429111 22652 maintenance_manager.cc:419] P 983de806fb0b45168f91ed578f107970: Scheduling FlushDeltaMemStoresOp(65b521f285f94f8b8dfd2dbb93869b8b): perf score=2.188937
I20260812 06:17:26.438881 22549 maintenance_manager.cc:643] P 983de806fb0b45168f91ed578f107970: FlushDeltaMemStoresOp(65b521f285f94f8b8dfd2dbb93869b8b) complete. Timing: real 0.010s	user 0.008s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3735,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:26.439270 22652 maintenance_manager.cc:419] P 983de806fb0b45168f91ed578f107970: Scheduling FlushMRSOp(65b521f285f94f8b8dfd2dbb93869b8b): perf score=1.000000
I20260812 06:17:26.470116 22549 maintenance_manager.cc:643] P 983de806fb0b45168f91ed578f107970: FlushMRSOp(65b521f285f94f8b8dfd2dbb93869b8b) complete. Timing: real 0.031s	user 0.026s	sys 0.000s Metrics: {"bytes_written":1152514,"cfile_init":1,"dirs.queue_time_us":43,"dirs.run_cpu_time_us":167,"dirs.run_wall_time_us":1141,"drs_written":1,"lbm_read_time_us":132,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1343,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":28}
I20260812 06:17:26.470872 22652 maintenance_manager.cc:419] P 983de806fb0b45168f91ed578f107970: Scheduling MajorDeltaCompactionOp(65b521f285f94f8b8dfd2dbb93869b8b): perf score=1.000000
I20260812 06:17:26.625041 22549 maintenance_manager.cc:643] P 983de806fb0b45168f91ed578f107970: MajorDeltaCompactionOp(65b521f285f94f8b8dfd2dbb93869b8b) complete. Timing: real 0.154s	user 0.118s	sys 0.024s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20713274,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":523,"lbm_read_time_us":8706,"lbm_reads_lt_1ms":464,"lbm_write_time_us":24209,"lbm_writes_lt_1ms":443,"peak_mem_usage":50689328,"reinsert_count":0,"update_count":2000}
I20260812 06:17:26.625667 22652 maintenance_manager.cc:419] P 983de806fb0b45168f91ed578f107970: Scheduling LogGCOp(65b521f285f94f8b8dfd2dbb93869b8b): free 112692379 bytes of WAL
I20260812 06:17:26.627337 22549 log_reader.cc:385] T 65b521f285f94f8b8dfd2dbb93869b8b: removed 11 log segments from log reader
I20260812 06:17:26.627494 22549 log.cc:1079] T 65b521f285f94f8b8dfd2dbb93869b8b P 983de806fb0b45168f91ed578f107970: Deleting log segment in path: /tmp/dist-test-taskw4CMs_/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515443298492-22369-0/minicluster-data/ts-0-root/wals/65b521f285f94f8b8dfd2dbb93869b8b/wal-000000015 (ops 72-76)
I20260812 06:17:26.627591 22549 log.cc:1079] T 65b521f285f94f8b8dfd2dbb93869b8b P 983de806fb0b45168f91ed578f107970: Deleting log segment in path: /tmp/dist-test-taskw4CMs_/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515443298492-22369-0/minicluster-data/ts-0-root/wals/65b521f285f94f8b8dfd2dbb93869b8b/wal-000000016 (ops 77-81)
I20260812 06:17:26.627671 22549 log.cc:1079] T 65b521f285f94f8b8dfd2dbb93869b8b P 983de806fb0b45168f91ed578f107970: Deleting log segment in path: /tmp/dist-test-taskw4CMs_/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515443298492-22369-0/minicluster-data/ts-0-root/wals/65b521f285f94f8b8dfd2dbb93869b8b/wal-000000017 (ops 82-86)
I20260812 06:17:26.627749 22549 log.cc:1079] T 65b521f285f94f8b8dfd2dbb93869b8b P 983de806fb0b45168f91ed578f107970: Deleting log segment in path: /tmp/dist-test-taskw4CMs_/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515443298492-22369-0/minicluster-data/ts-0-root/wals/65b521f285f94f8b8dfd2dbb93869b8b/wal-000000018 (ops 87-91)
I20260812 06:17:26.627837 22549 log.cc:1079] T 65b521f285f94f8b8dfd2dbb93869b8b P 983de806fb0b45168f91ed578f107970: Deleting log segment in path: /tmp/dist-test-taskw4CMs_/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515443298492-22369-0/minicluster-data/ts-0-root/wals/65b521f285f94f8b8dfd2dbb93869b8b/wal-000000019 (ops 92-96)
I20260812 06:17:26.627916 22549 log.cc:1079] T 65b521f285f94f8b8dfd2dbb93869b8b P 983de806fb0b45168f91ed578f107970: Deleting log segment in path: /tmp/dist-test-taskw4CMs_/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515443298492-22369-0/minicluster-data/ts-0-root/wals/65b521f285f94f8b8dfd2dbb93869b8b/wal-000000020 (ops 97-101)
I20260812 06:17:26.628005 22549 log.cc:1079] T 65b521f285f94f8b8dfd2dbb93869b8b P 983de806fb0b45168f91ed578f107970: Deleting log segment in path: /tmp/dist-test-taskw4CMs_/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515443298492-22369-0/minicluster-data/ts-0-root/wals/65b521f285f94f8b8dfd2dbb93869b8b/wal-000000021 (ops 102-106)
I20260812 06:17:26.628051 22549 log.cc:1079] T 65b521f285f94f8b8dfd2dbb93869b8b P 983de806fb0b45168f91ed578f107970: Deleting log segment in path: /tmp/dist-test-taskw4CMs_/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515443298492-22369-0/minicluster-data/ts-0-root/wals/65b521f285f94f8b8dfd2dbb93869b8b/wal-000000022 (ops 107-111)
I20260812 06:17:26.628106 22549 log.cc:1079] T 65b521f285f94f8b8dfd2dbb93869b8b P 983de806fb0b45168f91ed578f107970: Deleting log segment in path: /tmp/dist-test-taskw4CMs_/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515443298492-22369-0/minicluster-data/ts-0-root/wals/65b521f285f94f8b8dfd2dbb93869b8b/wal-000000023 (ops 112-116)
I20260812 06:17:26.628146 22549 log.cc:1079] T 65b521f285f94f8b8dfd2dbb93869b8b P 983de806fb0b45168f91ed578f107970: Deleting log segment in path: /tmp/dist-test-taskw4CMs_/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515443298492-22369-0/minicluster-data/ts-0-root/wals/65b521f285f94f8b8dfd2dbb93869b8b/wal-000000024 (ops 117-121)
I20260812 06:17:26.629316 22549 log.cc:1079] T 65b521f285f94f8b8dfd2dbb93869b8b P 983de806fb0b45168f91ed578f107970: Deleting log segment in path: /tmp/dist-test-taskw4CMs_/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515443298492-22369-0/minicluster-data/ts-0-root/wals/65b521f285f94f8b8dfd2dbb93869b8b/wal-000000025 (ops 122-126)
I20260812 06:17:26.657930 22549 maintenance_manager.cc:643] P 983de806fb0b45168f91ed578f107970: LogGCOp(65b521f285f94f8b8dfd2dbb93869b8b) complete. Timing: real 0.031s	user 0.000s	sys 0.026s Metrics: {}
I20260812 06:17:26.658468 22652 maintenance_manager.cc:419] P 983de806fb0b45168f91ed578f107970: Scheduling UndoDeltaBlockGCOp(65b521f285f94f8b8dfd2dbb93869b8b): 448 bytes on disk
I20260812 06:17:26.661664 22549 maintenance_manager.cc:643] P 983de806fb0b45168f91ed578f107970: UndoDeltaBlockGCOp(65b521f285f94f8b8dfd2dbb93869b8b) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":76,"lbm_reads_lt_1ms":4}
I20260812 06:17:26.662346 22652 maintenance_manager.cc:419] P 983de806fb0b45168f91ed578f107970: Scheduling FlushDeltaMemStoresOp(65b521f285f94f8b8dfd2dbb93869b8b): perf score=15.087375
I20260812 06:17:26.729575 22549 maintenance_manager.cc:643] P 983de806fb0b45168f91ed578f107970: FlushDeltaMemStoresOp(65b521f285f94f8b8dfd2dbb93869b8b) complete. Timing: real 0.067s	user 0.029s	sys 0.020s Metrics: {"bytes_written":17025272,"delete_count":0,"lbm_write_time_us":23104,"lbm_writes_lt_1ms":418,"reinsert_count":0,"update_count":2075}
I20260812 06:17:26.730099 22652 maintenance_manager.cc:419] P 983de806fb0b45168f91ed578f107970: Scheduling FlushDeltaMemStoresOp(65b521f285f94f8b8dfd2dbb93869b8b): perf score=6.157687
I20260812 06:17:26.759653 22549 maintenance_manager.cc:643] P 983de806fb0b45168f91ed578f107970: FlushDeltaMemStoresOp(65b521f285f94f8b8dfd2dbb93869b8b) complete. Timing: real 0.029s	user 0.005s	sys 0.020s Metrics: {"bytes_written":7589721,"delete_count":0,"lbm_write_time_us":10848,"lbm_writes_lt_1ms":188,"reinsert_count":0,"update_count":925}
I20260812 06:17:26.760152 22652 maintenance_manager.cc:419] P 983de806fb0b45168f91ed578f107970: Scheduling MajorDeltaCompactionOp(65b521f285f94f8b8dfd2dbb93869b8b): perf score=1.000000
I20260812 06:17:26.959347 22549 maintenance_manager.cc:643] P 983de806fb0b45168f91ed578f107970: MajorDeltaCompactionOp(65b521f285f94f8b8dfd2dbb93869b8b) complete. Timing: real 0.199s	user 0.124s	sys 0.072s Metrics: {"cfile_cache_miss":632,"cfile_cache_miss_bytes":28918110,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":604,"lbm_read_time_us":15785,"lbm_reads_lt_1ms":664,"lbm_write_time_us":31202,"lbm_writes_lt_1ms":643,"mutex_wait_us":262,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":3456,"update_count":3000}
I20260812 06:17:26.959796 22652 maintenance_manager.cc:419] P 983de806fb0b45168f91ed578f107970: Scheduling FlushDeltaMemStoresOp(65b521f285f94f8b8dfd2dbb93869b8b): perf score=14.095187
I20260812 06:17:27.018770 22549 maintenance_manager.cc:643] P 983de806fb0b45168f91ed578f107970: FlushDeltaMemStoresOp(65b521f285f94f8b8dfd2dbb93869b8b) complete. Timing: real 0.059s	user 0.020s	sys 0.028s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":19564,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:17:27.019251 22652 maintenance_manager.cc:419] P 983de806fb0b45168f91ed578f107970: Scheduling FlushDeltaMemStoresOp(65b521f285f94f8b8dfd2dbb93869b8b): perf score=2.188937
I20260812 06:17:27.029747 22549 maintenance_manager.cc:643] P 983de806fb0b45168f91ed578f107970: FlushDeltaMemStoresOp(65b521f285f94f8b8dfd2dbb93869b8b) complete. Timing: real 0.010s	user 0.000s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3781,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:27.030362 22652 maintenance_manager.cc:419] P 983de806fb0b45168f91ed578f107970: Scheduling MajorDeltaCompactionOp(65b521f285f94f8b8dfd2dbb93869b8b): perf score=1.000000
I20260812 06:17:27.207744 22549 maintenance_manager.cc:643] P 983de806fb0b45168f91ed578f107970: MajorDeltaCompactionOp(65b521f285f94f8b8dfd2dbb93869b8b) complete. Timing: real 0.177s	user 0.137s	sys 0.040s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24815684,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":197,"lbm_read_time_us":12870,"lbm_reads_lt_1ms":572,"lbm_write_time_us":30541,"lbm_writes_lt_1ms":543,"mutex_wait_us":68,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":896,"update_count":2500}
I20260812 06:17:27.208297 22652 maintenance_manager.cc:419] P 983de806fb0b45168f91ed578f107970: Scheduling FlushDeltaMemStoresOp(65b521f285f94f8b8dfd2dbb93869b8b): perf score=14.095187
I20260812 06:17:27.265865 22549 maintenance_manager.cc:643] P 983de806fb0b45168f91ed578f107970: FlushDeltaMemStoresOp(65b521f285f94f8b8dfd2dbb93869b8b) complete. Timing: real 0.057s	user 0.034s	sys 0.020s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":24725,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":402,"reinsert_count":0,"update_count":2000}
I20260812 06:17:27.266508 22652 maintenance_manager.cc:419] P 983de806fb0b45168f91ed578f107970: Scheduling FlushDeltaMemStoresOp(65b521f285f94f8b8dfd2dbb93869b8b): perf score=2.188937
I20260812 06:17:27.285759 22549 maintenance_manager.cc:643] P 983de806fb0b45168f91ed578f107970: FlushDeltaMemStoresOp(65b521f285f94f8b8dfd2dbb93869b8b) complete. Timing: real 0.019s	user 0.007s	sys 0.008s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":6896,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:27.286290 22652 maintenance_manager.cc:419] P 983de806fb0b45168f91ed578f107970: Scheduling MajorDeltaCompactionOp(65b521f285f94f8b8dfd2dbb93869b8b): perf score=1.000000
I20260812 06:17:27.467324 22549 maintenance_manager.cc:643] P 983de806fb0b45168f91ed578f107970: MajorDeltaCompactionOp(65b521f285f94f8b8dfd2dbb93869b8b) complete. Timing: real 0.181s	user 0.136s	sys 0.044s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24815683,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":219,"lbm_read_time_us":13177,"lbm_reads_lt_1ms":564,"lbm_write_time_us":31274,"lbm_writes_lt_1ms":543,"mutex_wait_us":319,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":896,"update_count":2500}
I20260812 06:17:27.467893 22652 maintenance_manager.cc:419] P 983de806fb0b45168f91ed578f107970: Scheduling FlushDeltaMemStoresOp(65b521f285f94f8b8dfd2dbb93869b8b): perf score=14.095187
I20260812 06:17:27.521968 22549 maintenance_manager.cc:643] P 983de806fb0b45168f91ed578f107970: FlushDeltaMemStoresOp(65b521f285f94f8b8dfd2dbb93869b8b) complete. Timing: real 0.054s	user 0.034s	sys 0.017s Metrics: {"bytes_written":16409903,"delete_count":0,"lbm_write_time_us":24466,"lbm_writes_1-10_ms":2,"lbm_writes_lt_1ms":401,"reinsert_count":0,"update_count":2000}
I20260812 06:17:27.522648 22652 maintenance_manager.cc:419] P 983de806fb0b45168f91ed578f107970: Scheduling FlushDeltaMemStoresOp(65b521f285f94f8b8dfd2dbb93869b8b): perf score=3.181125
I20260812 06:17:27.551368 22549 maintenance_manager.cc:643] P 983de806fb0b45168f91ed578f107970: FlushDeltaMemStoresOp(65b521f285f94f8b8dfd2dbb93869b8b) complete. Timing: real 0.028s	user 0.015s	sys 0.008s Metrics: {"bytes_written":4512903,"delete_count":0,"lbm_write_time_us":5055,"lbm_writes_lt_1ms":113,"reinsert_count":0,"update_count":550}
I20260812 06:17:27.551904 22652 maintenance_manager.cc:419] P 983de806fb0b45168f91ed578f107970: Scheduling FlushDeltaMemStoresOp(65b521f285f94f8b8dfd2dbb93869b8b): perf score=2.188937
I20260812 06:17:27.565383 22549 maintenance_manager.cc:643] P 983de806fb0b45168f91ed578f107970: FlushDeltaMemStoresOp(65b521f285f94f8b8dfd2dbb93869b8b) complete. Timing: real 0.013s	user 0.011s	sys 0.000s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":5024,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:17:27.565837 22652 maintenance_manager.cc:419] P 983de806fb0b45168f91ed578f107970: Scheduling MajorDeltaCompactionOp(65b521f285f94f8b8dfd2dbb93869b8b): perf score=1.000000
I20260812 06:17:27.753051 22549 maintenance_manager.cc:643] P 983de806fb0b45168f91ed578f107970: MajorDeltaCompactionOp(65b521f285f94f8b8dfd2dbb93869b8b) complete. Timing: real 0.187s	user 0.124s	sys 0.060s Metrics: {"cfile_cache_miss":633,"cfile_cache_miss_bytes":28918206,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":106,"lbm_read_time_us":13809,"lbm_reads_lt_1ms":673,"lbm_write_time_us":30551,"lbm_writes_lt_1ms":643,"mutex_wait_us":44,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":13568,"update_count":3000}
I20260812 06:17:27.753567 22652 maintenance_manager.cc:419] P 983de806fb0b45168f91ed578f107970: Scheduling FlushDeltaMemStoresOp(65b521f285f94f8b8dfd2dbb93869b8b): perf score=14.095187
I20260812 06:17:27.811630 22549 maintenance_manager.cc:643] P 983de806fb0b45168f91ed578f107970: FlushDeltaMemStoresOp(65b521f285f94f8b8dfd2dbb93869b8b) complete. Timing: real 0.058s	user 0.026s	sys 0.031s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":22027,"lbm_writes_1-10_ms":2,"lbm_writes_lt_1ms":401,"reinsert_count":0,"update_count":2000}
I20260812 06:17:27.812222 22652 maintenance_manager.cc:419] P 983de806fb0b45168f91ed578f107970: Scheduling FlushDeltaMemStoresOp(65b521f285f94f8b8dfd2dbb93869b8b): perf score=2.188937
I20260812 06:17:27.821969 22549 maintenance_manager.cc:643] P 983de806fb0b45168f91ed578f107970: FlushDeltaMemStoresOp(65b521f285f94f8b8dfd2dbb93869b8b) complete. Timing: real 0.010s	user 0.004s	sys 0.004s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":3744,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:27.822489 22652 maintenance_manager.cc:419] P 983de806fb0b45168f91ed578f107970: Scheduling MajorDeltaCompactionOp(65b521f285f94f8b8dfd2dbb93869b8b): perf score=1.000000
I20260812 06:17:27.988945 22549 maintenance_manager.cc:643] P 983de806fb0b45168f91ed578f107970: MajorDeltaCompactionOp(65b521f285f94f8b8dfd2dbb93869b8b) complete. Timing: real 0.166s	user 0.100s	sys 0.058s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24815682,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":633,"lbm_read_time_us":12713,"lbm_reads_lt_1ms":572,"lbm_write_time_us":24205,"lbm_writes_lt_1ms":543,"mutex_wait_us":49,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":1664,"update_count":2500}
I20260812 06:17:27.989519 22652 maintenance_manager.cc:419] P 983de806fb0b45168f91ed578f107970: Scheduling FlushDeltaMemStoresOp(65b521f285f94f8b8dfd2dbb93869b8b): perf score=14.095187
I20260812 06:17:28.042775 22549 maintenance_manager.cc:643] P 983de806fb0b45168f91ed578f107970: FlushDeltaMemStoresOp(65b521f285f94f8b8dfd2dbb93869b8b) complete. Timing: real 0.053s	user 0.020s	sys 0.022s Metrics: {"bytes_written":16409903,"delete_count":0,"lbm_write_time_us":20147,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:17:28.043351 22652 maintenance_manager.cc:419] P 983de806fb0b45168f91ed578f107970: Scheduling FlushDeltaMemStoresOp(65b521f285f94f8b8dfd2dbb93869b8b): perf score=2.188937
I20260812 06:17:28.066681 22549 maintenance_manager.cc:643] P 983de806fb0b45168f91ed578f107970: FlushDeltaMemStoresOp(65b521f285f94f8b8dfd2dbb93869b8b) complete. Timing: real 0.023s	user 0.009s	sys 0.011s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5903,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:28.067261 22652 maintenance_manager.cc:419] P 983de806fb0b45168f91ed578f107970: Scheduling FlushMRSOp(65b521f285f94f8b8dfd2dbb93869b8b): perf score=1.000000
I20260812 06:17:28.104666 22549 maintenance_manager.cc:643] P 983de806fb0b45168f91ed578f107970: FlushMRSOp(65b521f285f94f8b8dfd2dbb93869b8b) complete. Timing: real 0.037s	user 0.028s	sys 0.002s Metrics: {"bytes_written":1316417,"cfile_init":1,"dirs.queue_time_us":41,"dirs.run_cpu_time_us":245,"dirs.run_wall_time_us":1338,"drs_written":1,"lbm_read_time_us":37,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1402,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":32}
I20260812 06:17:28.105430 22652 maintenance_manager.cc:419] P 983de806fb0b45168f91ed578f107970: Scheduling LogGCOp(65b521f285f94f8b8dfd2dbb93869b8b): free 132571583 bytes of WAL
I20260812 06:17:28.105692 22549 log_reader.cc:385] T 65b521f285f94f8b8dfd2dbb93869b8b: removed 13 log segments from log reader
I20260812 06:17:28.105747 22549 log.cc:1079] T 65b521f285f94f8b8dfd2dbb93869b8b P 983de806fb0b45168f91ed578f107970: Deleting log segment in path: /tmp/dist-test-taskw4CMs_/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515443298492-22369-0/minicluster-data/ts-0-root/wals/65b521f285f94f8b8dfd2dbb93869b8b/wal-000000026 (ops 127-130)
I20260812 06:17:28.105786 22549 log.cc:1079] T 65b521f285f94f8b8dfd2dbb93869b8b P 983de806fb0b45168f91ed578f107970: Deleting log segment in path: /tmp/dist-test-taskw4CMs_/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515443298492-22369-0/minicluster-data/ts-0-root/wals/65b521f285f94f8b8dfd2dbb93869b8b/wal-000000027 (ops 131-135)
I20260812 06:17:28.105819 22549 log.cc:1079] T 65b521f285f94f8b8dfd2dbb93869b8b P 983de806fb0b45168f91ed578f107970: Deleting log segment in path: /tmp/dist-test-taskw4CMs_/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515443298492-22369-0/minicluster-data/ts-0-root/wals/65b521f285f94f8b8dfd2dbb93869b8b/wal-000000028 (ops 136-140)
I20260812 06:17:28.105849 22549 log.cc:1079] T 65b521f285f94f8b8dfd2dbb93869b8b P 983de806fb0b45168f91ed578f107970: Deleting log segment in path: /tmp/dist-test-taskw4CMs_/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515443298492-22369-0/minicluster-data/ts-0-root/wals/65b521f285f94f8b8dfd2dbb93869b8b/wal-000000029 (ops 141-145)
I20260812 06:17:28.105880 22549 log.cc:1079] T 65b521f285f94f8b8dfd2dbb93869b8b P 983de806fb0b45168f91ed578f107970: Deleting log segment in path: /tmp/dist-test-taskw4CMs_/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515443298492-22369-0/minicluster-data/ts-0-root/wals/65b521f285f94f8b8dfd2dbb93869b8b/wal-000000030 (ops 146-150)
I20260812 06:17:28.105911 22549 log.cc:1079] T 65b521f285f94f8b8dfd2dbb93869b8b P 983de806fb0b45168f91ed578f107970: Deleting log segment in path: /tmp/dist-test-taskw4CMs_/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515443298492-22369-0/minicluster-data/ts-0-root/wals/65b521f285f94f8b8dfd2dbb93869b8b/wal-000000031 (ops 151-155)
I20260812 06:17:28.105940 22549 log.cc:1079] T 65b521f285f94f8b8dfd2dbb93869b8b P 983de806fb0b45168f91ed578f107970: Deleting log segment in path: /tmp/dist-test-taskw4CMs_/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515443298492-22369-0/minicluster-data/ts-0-root/wals/65b521f285f94f8b8dfd2dbb93869b8b/wal-000000032 (ops 156-160)
I20260812 06:17:28.105971 22549 log.cc:1079] T 65b521f285f94f8b8dfd2dbb93869b8b P 983de806fb0b45168f91ed578f107970: Deleting log segment in path: /tmp/dist-test-taskw4CMs_/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515443298492-22369-0/minicluster-data/ts-0-root/wals/65b521f285f94f8b8dfd2dbb93869b8b/wal-000000033 (ops 161-164)
I20260812 06:17:28.106001 22549 log.cc:1079] T 65b521f285f94f8b8dfd2dbb93869b8b P 983de806fb0b45168f91ed578f107970: Deleting log segment in path: /tmp/dist-test-taskw4CMs_/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515443298492-22369-0/minicluster-data/ts-0-root/wals/65b521f285f94f8b8dfd2dbb93869b8b/wal-000000034 (ops 165-169)
I20260812 06:17:28.106025 22549 log.cc:1079] T 65b521f285f94f8b8dfd2dbb93869b8b P 983de806fb0b45168f91ed578f107970: Deleting log segment in path: /tmp/dist-test-taskw4CMs_/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515443298492-22369-0/minicluster-data/ts-0-root/wals/65b521f285f94f8b8dfd2dbb93869b8b/wal-000000035 (ops 170-174)
I20260812 06:17:28.106056 22549 log.cc:1079] T 65b521f285f94f8b8dfd2dbb93869b8b P 983de806fb0b45168f91ed578f107970: Deleting log segment in path: /tmp/dist-test-taskw4CMs_/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515443298492-22369-0/minicluster-data/ts-0-root/wals/65b521f285f94f8b8dfd2dbb93869b8b/wal-000000036 (ops 175-179)
I20260812 06:17:28.106083 22549 log.cc:1079] T 65b521f285f94f8b8dfd2dbb93869b8b P 983de806fb0b45168f91ed578f107970: Deleting log segment in path: /tmp/dist-test-taskw4CMs_/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515443298492-22369-0/minicluster-data/ts-0-root/wals/65b521f285f94f8b8dfd2dbb93869b8b/wal-000000037 (ops 180-184)
I20260812 06:17:28.106110 22549 log.cc:1079] T 65b521f285f94f8b8dfd2dbb93869b8b P 983de806fb0b45168f91ed578f107970: Deleting log segment in path: /tmp/dist-test-taskw4CMs_/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515443298492-22369-0/minicluster-data/ts-0-root/wals/65b521f285f94f8b8dfd2dbb93869b8b/wal-000000038 (ops 185-189)
I20260812 06:17:28.128928 22549 maintenance_manager.cc:643] P 983de806fb0b45168f91ed578f107970: LogGCOp(65b521f285f94f8b8dfd2dbb93869b8b) complete. Timing: real 0.023s	user 0.000s	sys 0.021s Metrics: {}
I20260812 06:17:28.129361 22652 maintenance_manager.cc:419] P 983de806fb0b45168f91ed578f107970: Scheduling FlushDeltaMemStoresOp(65b521f285f94f8b8dfd2dbb93869b8b): perf score=2.188937
I20260812 06:17:28.145948 22549 maintenance_manager.cc:643] P 983de806fb0b45168f91ed578f107970: FlushDeltaMemStoresOp(65b521f285f94f8b8dfd2dbb93869b8b) complete. Timing: real 0.016s	user 0.004s	sys 0.005s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3979,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:28.146487 22652 maintenance_manager.cc:419] P 983de806fb0b45168f91ed578f107970: Scheduling FlushDeltaMemStoresOp(65b521f285f94f8b8dfd2dbb93869b8b): perf score=2.188937
I20260812 06:17:28.155943 22549 maintenance_manager.cc:643] P 983de806fb0b45168f91ed578f107970: FlushDeltaMemStoresOp(65b521f285f94f8b8dfd2dbb93869b8b) complete. Timing: real 0.009s	user 0.008s	sys 0.000s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":3513,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:28.156366 22652 maintenance_manager.cc:419] P 983de806fb0b45168f91ed578f107970: Scheduling UndoDeltaBlockGCOp(65b521f285f94f8b8dfd2dbb93869b8b): 492 bytes on disk
I20260812 06:17:28.156778 22549 maintenance_manager.cc:643] P 983de806fb0b45168f91ed578f107970: UndoDeltaBlockGCOp(65b521f285f94f8b8dfd2dbb93869b8b) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":50,"lbm_reads_lt_1ms":4}
I20260812 06:17:28.157572 22652 maintenance_manager.cc:419] P 983de806fb0b45168f91ed578f107970: Scheduling MajorDeltaCompactionOp(65b521f285f94f8b8dfd2dbb93869b8b): perf score=1.000000
I20260812 06:17:28.347175 22369 heavy-update-compaction-itest.cc:229] Time spent updating: real 4.757s	user 1.652s	sys 0.189s
I20260812 06:17:28.369205 22549 maintenance_manager.cc:643] P 983de806fb0b45168f91ed578f107970: MajorDeltaCompactionOp(65b521f285f94f8b8dfd2dbb93869b8b) complete. Timing: real 0.211s	user 0.132s	sys 0.077s Metrics: {"cfile_cache_miss":734,"cfile_cache_miss_bytes":33020746,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"lbm_read_time_us":14393,"lbm_reads_lt_1ms":770,"lbm_write_time_us":37911,"lbm_writes_lt_1ms":743,"peak_mem_usage":87969044,"reinsert_count":0,"update_count":3500}
I20260812 06:17:28.369741 22652 maintenance_manager.cc:419] P 983de806fb0b45168f91ed578f107970: Scheduling FlushDeltaMemStoresOp(65b521f285f94f8b8dfd2dbb93869b8b): perf score=14.095187
I20260812 06:17:28.420356 22549 maintenance_manager.cc:643] P 983de806fb0b45168f91ed578f107970: FlushDeltaMemStoresOp(65b521f285f94f8b8dfd2dbb93869b8b) complete. Timing: real 0.050s	user 0.033s	sys 0.016s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":23099,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:17:28.420902 22652 maintenance_manager.cc:419] P 983de806fb0b45168f91ed578f107970: Scheduling MajorDeltaCompactionOp(65b521f285f94f8b8dfd2dbb93869b8b): perf score=1.000000
I20260812 06:17:28.491142 22369 heavy-update-compaction-itest.cc:265] Time spent scanning: real 0.143s	user 0.004s	sys 0.000s
I20260812 06:17:28.491714 22369 tablet_server.cc:179] TabletServer@127.21.216.65:0 shutting down...
I20260812 06:17:28.556416 22549 maintenance_manager.cc:643] P 983de806fb0b45168f91ed578f107970: MajorDeltaCompactionOp(65b521f285f94f8b8dfd2dbb93869b8b) complete. Timing: real 0.135s	user 0.093s	sys 0.041s Metrics: {"cfile_cache_miss":431,"cfile_cache_miss_bytes":20713152,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":1,"delta_iterators_relevant":1,"dirs.queue_time_us":566,"lbm_read_time_us":12484,"lbm_reads_lt_1ms":467,"lbm_write_time_us":25443,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":442,"mutex_wait_us":62,"peak_mem_usage":50689328,"reinsert_count":0,"update_count":2000}
I20260812 06:17:28.557010 22369 ts_tablet_manager.cc:1507] Shutting down tablet manager...
I20260812 06:17:28.557476 22369 tablet_replica.cc:333] T 65b521f285f94f8b8dfd2dbb93869b8b P 983de806fb0b45168f91ed578f107970: stopping tablet replica
I20260812 06:17:28.557685 22369 raft_consensus.cc:2243] T 65b521f285f94f8b8dfd2dbb93869b8b P 983de806fb0b45168f91ed578f107970 [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:17:28.557881 22369 raft_consensus.cc:2272] T 65b521f285f94f8b8dfd2dbb93869b8b P 983de806fb0b45168f91ed578f107970 [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:17:28.572409 22369 tablet_server.cc:196] TabletServer@127.21.216.65:0 shutdown complete.
I20260812 06:17:28.607935 22369 master.cc:562] Master@127.21.216.126:39691 shutting down...
I20260812 06:17:28.611509 22369 raft_consensus.cc:2243] T 00000000000000000000000000000000 P 4cacd3c44df5455c9b2c7c98a814d317 [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:17:28.611676 22369 raft_consensus.cc:2272] T 00000000000000000000000000000000 P 4cacd3c44df5455c9b2c7c98a814d317 [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:17:28.611756 22369 tablet_replica.cc:333] T 00000000000000000000000000000000 P 4cacd3c44df5455c9b2c7c98a814d317: stopping tablet replica
I20260812 06:17:28.624694 22369 master.cc:584] Master@127.21.216.126:39691 shutdown complete.
[       OK ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/0 (5391 ms)
[ RUN      ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/1
I20260812 06:17:28.700363 22369 internal_mini_cluster.cc:156] Creating distributed mini masters. Addrs: 127.21.216.126:40629
I20260812 06:17:28.700829 22369 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:17:28.702822 22711 instance_detector.cc:116] could not retrieve Azure instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:17:28.702934 22710 instance_detector.cc:116] could not retrieve AWS instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:17:28.702823 22716 instance_detector.cc:116] could not retrieve OpenStack instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:17:28.703065 22369 server_base.cc:1061] running on GCE node
I20260812 06:17:28.703302 22369 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:17:28.703363 22369 system_unsync_time.cc:38] NTP support is disabled. Clock error bounds will not be accurate. This configuration is not suitable for distributed clusters.
I20260812 06:17:28.703387 22369 hybrid_clock.cc:648] HybridClock initialized: now 1786515448703387 us; error 0 us; skew 500 ppm
I20260812 06:17:28.704193 22369 webserver.cc:533] Webserver started at http://127.21.216.126:44505/ using document root <none> and password file <none>
I20260812 06:17:28.704329 22369 fs_manager.cc:362] Metadata directory not provided
I20260812 06:17:28.704375 22369 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:17:28.704437 22369 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:17:28.704795 22369 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskw4CMs_/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515443298492-22369-0/minicluster-data/master-0-root/instance:
uuid: "5c0dedbace1a410791024610a89e5b7d"
format_stamp: "Formatted at 2026-08-12 06:17:28 on dist-test-slave-1vmg"
I20260812 06:17:28.706297 22369 fs_manager.cc:696] Time spent creating directory manager: real 0.001s	user 0.000s	sys 0.002s
I20260812 06:17:28.707320 22723 log_block_manager.cc:4127] Time spent loading block containers with low live blocks: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:17:28.707540 22369 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.000s	sys 0.001s
I20260812 06:17:28.707620 22369 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskw4CMs_/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515443298492-22369-0/minicluster-data/master-0-root
uuid: "5c0dedbace1a410791024610a89e5b7d"
format_stamp: "Formatted at 2026-08-12 06:17:28 on dist-test-slave-1vmg"
I20260812 06:17:28.707695 22369 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskw4CMs_/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515443298492-22369-0/minicluster-data/master-0-root
metadata directory: /tmp/dist-test-taskw4CMs_/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515443298492-22369-0/minicluster-data/master-0-root
1 data directories: /tmp/dist-test-taskw4CMs_/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515443298492-22369-0/minicluster-data/master-0-root/data
Total live blocks: 0
Total live bytes: 0
Total live bytes (after alignment): 0
Total number of LBM containers: 0 (0 full)
Did not check for missing blocks
Did not check for orphaned blocks
Total full LBM containers with extra space: 0 (0 repaired)
Total full LBM container extra space in bytes: 0 (0 repaired)
Total incomplete LBM containers: 0 (0 repaired)
Total LBM partial records: 0 (0 repaired)
Total corrupted LBM metadata records in RocksDB: 0 (0 repaired)
I20260812 06:17:28.719717 22369 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:17:28.720052 22369 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:17:28.723825 22369 rpc_server.cc:307] RPC server started. Bound to: 127.21.216.126:40629
I20260812 06:17:28.736805 22802 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.21.216.126:40629 every 8 connection(s)
I20260812 06:17:28.737226 22803 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet 00000000000000000000000000000000. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:17:28.738902 22803 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P 5c0dedbace1a410791024610a89e5b7d: Bootstrap starting.
I20260812 06:17:28.739660 22803 tablet_bootstrap.cc:654] T 00000000000000000000000000000000 P 5c0dedbace1a410791024610a89e5b7d: Neither blocks nor log segments found. Creating new log.
I20260812 06:17:28.740552 22803 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P 5c0dedbace1a410791024610a89e5b7d: No bootstrap required, opened a new log
I20260812 06:17:28.740904 22803 raft_consensus.cc:359] T 00000000000000000000000000000000 P 5c0dedbace1a410791024610a89e5b7d [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "5c0dedbace1a410791024610a89e5b7d" member_type: VOTER }
I20260812 06:17:28.740984 22803 raft_consensus.cc:385] T 00000000000000000000000000000000 P 5c0dedbace1a410791024610a89e5b7d [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:17:28.741010 22803 raft_consensus.cc:740] T 00000000000000000000000000000000 P 5c0dedbace1a410791024610a89e5b7d [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: 5c0dedbace1a410791024610a89e5b7d, State: Initialized, Role: FOLLOWER
I20260812 06:17:28.741110 22803 consensus_queue.cc:260] T 00000000000000000000000000000000 P 5c0dedbace1a410791024610a89e5b7d [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: "5c0dedbace1a410791024610a89e5b7d" member_type: VOTER }
I20260812 06:17:28.741176 22803 raft_consensus.cc:399] T 00000000000000000000000000000000 P 5c0dedbace1a410791024610a89e5b7d [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:17:28.741202 22803 raft_consensus.cc:493] T 00000000000000000000000000000000 P 5c0dedbace1a410791024610a89e5b7d [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:17:28.741235 22803 raft_consensus.cc:3060] T 00000000000000000000000000000000 P 5c0dedbace1a410791024610a89e5b7d [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:17:28.741827 22803 raft_consensus.cc:515] T 00000000000000000000000000000000 P 5c0dedbace1a410791024610a89e5b7d [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "5c0dedbace1a410791024610a89e5b7d" member_type: VOTER }
I20260812 06:17:28.741937 22803 leader_election.cc:304] T 00000000000000000000000000000000 P 5c0dedbace1a410791024610a89e5b7d [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: 5c0dedbace1a410791024610a89e5b7d; no voters: 
I20260812 06:17:28.742079 22803 leader_election.cc:290] T 00000000000000000000000000000000 P 5c0dedbace1a410791024610a89e5b7d [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:17:28.742184 22807 raft_consensus.cc:2804] T 00000000000000000000000000000000 P 5c0dedbace1a410791024610a89e5b7d [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:17:28.742389 22807 raft_consensus.cc:697] T 00000000000000000000000000000000 P 5c0dedbace1a410791024610a89e5b7d [term 1 LEADER]: Becoming Leader. State: Replica: 5c0dedbace1a410791024610a89e5b7d, State: Running, Role: LEADER
I20260812 06:17:28.742465 22803 sys_catalog.cc:565] T 00000000000000000000000000000000 P 5c0dedbace1a410791024610a89e5b7d [sys.catalog]: configured and running, proceeding with master startup.
I20260812 06:17:28.742525 22807 consensus_queue.cc:237] T 00000000000000000000000000000000 P 5c0dedbace1a410791024610a89e5b7d [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: "5c0dedbace1a410791024610a89e5b7d" member_type: VOTER }
I20260812 06:17:28.742971 22809 sys_catalog.cc:455] T 00000000000000000000000000000000 P 5c0dedbace1a410791024610a89e5b7d [sys.catalog]: SysCatalogTable state changed. Reason: RaftConsensus started. Latest consensus state: current_term: 1 leader_uuid: "5c0dedbace1a410791024610a89e5b7d" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "5c0dedbace1a410791024610a89e5b7d" member_type: VOTER } }
I20260812 06:17:28.742996 22814 sys_catalog.cc:455] T 00000000000000000000000000000000 P 5c0dedbace1a410791024610a89e5b7d [sys.catalog]: SysCatalogTable state changed. Reason: New leader 5c0dedbace1a410791024610a89e5b7d. Latest consensus state: current_term: 1 leader_uuid: "5c0dedbace1a410791024610a89e5b7d" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "5c0dedbace1a410791024610a89e5b7d" member_type: VOTER } }
I20260812 06:17:28.743139 22814 sys_catalog.cc:458] T 00000000000000000000000000000000 P 5c0dedbace1a410791024610a89e5b7d [sys.catalog]: This master's current role is: LEADER
I20260812 06:17:28.743379 22809 sys_catalog.cc:458] T 00000000000000000000000000000000 P 5c0dedbace1a410791024610a89e5b7d [sys.catalog]: This master's current role is: LEADER
I20260812 06:17:28.743638 22820 catalog_manager.cc:1511] Loading table and tablet metadata into memory...
I20260812 06:17:28.744333 22820 catalog_manager.cc:1520] Initializing Kudu cluster ID...
I20260812 06:17:28.744472 22369 internal_mini_cluster.cc:184] Waiting to initialize catalog manager on master 0
I20260812 06:17:28.745997 22820 catalog_manager.cc:1383] Generated new cluster ID: 36d334513e374249a19b3adc069be1bd
I20260812 06:17:28.746060 22820 catalog_manager.cc:1531] Initializing Kudu internal certificate authority...
I20260812 06:17:28.754530 22820 catalog_manager.cc:1406] Generated new certificate authority record
I20260812 06:17:28.755045 22820 catalog_manager.cc:1540] Loading token signing keys...
I20260812 06:17:28.761656 22820 catalog_manager.cc:6092] T 00000000000000000000000000000000 P 5c0dedbace1a410791024610a89e5b7d: Generated new TSK 0
I20260812 06:17:28.761787 22820 catalog_manager.cc:1550] Initializing in-progress tserver states...
I20260812 06:17:28.776533 22369 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:17:28.778403 22851 instance_detector.cc:116] could not retrieve OpenStack instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:17:28.778442 22847 instance_detector.cc:116] could not retrieve AWS instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:17:28.778517 22848 instance_detector.cc:116] could not retrieve Azure instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:17:28.778496 22369 server_base.cc:1061] running on GCE node
I20260812 06:17:28.778752 22369 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:17:28.778791 22369 system_unsync_time.cc:38] NTP support is disabled. Clock error bounds will not be accurate. This configuration is not suitable for distributed clusters.
I20260812 06:17:28.778811 22369 hybrid_clock.cc:648] HybridClock initialized: now 1786515448778811 us; error 0 us; skew 500 ppm
I20260812 06:17:28.779632 22369 webserver.cc:533] Webserver started at http://127.21.216.65:44661/ using document root <none> and password file <none>
I20260812 06:17:28.779794 22369 fs_manager.cc:362] Metadata directory not provided
I20260812 06:17:28.779844 22369 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:17:28.779917 22369 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:17:28.780256 22369 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskw4CMs_/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515443298492-22369-0/minicluster-data/ts-0-root/instance:
uuid: "1f78d8c8394c4abcb63ba33c8b600354"
format_stamp: "Formatted at 2026-08-12 06:17:28 on dist-test-slave-1vmg"
I20260812 06:17:28.781637 22369 fs_manager.cc:696] Time spent creating directory manager: real 0.001s	user 0.002s	sys 0.000s
I20260812 06:17:28.782541 22859 log_block_manager.cc:4127] Time spent loading block containers with low live blocks: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:17:28.782752 22369 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.001s	sys 0.000s
I20260812 06:17:28.782817 22369 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskw4CMs_/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515443298492-22369-0/minicluster-data/ts-0-root
uuid: "1f78d8c8394c4abcb63ba33c8b600354"
format_stamp: "Formatted at 2026-08-12 06:17:28 on dist-test-slave-1vmg"
I20260812 06:17:28.782881 22369 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskw4CMs_/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515443298492-22369-0/minicluster-data/ts-0-root
metadata directory: /tmp/dist-test-taskw4CMs_/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515443298492-22369-0/minicluster-data/ts-0-root
1 data directories: /tmp/dist-test-taskw4CMs_/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515443298492-22369-0/minicluster-data/ts-0-root/data
Total live blocks: 0
Total live bytes: 0
Total live bytes (after alignment): 0
Total number of LBM containers: 0 (0 full)
Did not check for missing blocks
Did not check for orphaned blocks
Total full LBM containers with extra space: 0 (0 repaired)
Total full LBM container extra space in bytes: 0 (0 repaired)
Total incomplete LBM containers: 0 (0 repaired)
Total LBM partial records: 0 (0 repaired)
Total corrupted LBM metadata records in RocksDB: 0 (0 repaired)
I20260812 06:17:28.791631 22369 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:17:28.791901 22369 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:17:28.792146 22369 txn_system_client.cc:432] TxnSystemClient initialization is disabled...
I20260812 06:17:28.792531 22369 ts_tablet_manager.cc:585] Loaded tablet metadata (0 total tablets, 0 live tablets)
I20260812 06:17:28.792567 22369 ts_tablet_manager.cc:531] Time spent load tablet metadata: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:17:28.792608 22369 ts_tablet_manager.cc:616] Registered 0 tablets
I20260812 06:17:28.792635 22369 ts_tablet_manager.cc:595] Time spent register tablets: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:17:28.796538 22369 rpc_server.cc:307] RPC server started. Bound to: 127.21.216.65:43869
I20260812 06:17:28.796571 22961 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.21.216.65:43869 every 8 connection(s)
I20260812 06:17:28.804780 22962 heartbeater.cc:344] Connected to a master server at 127.21.216.126:40629
I20260812 06:17:28.804872 22962 heartbeater.cc:461] Registering TS with master...
I20260812 06:17:28.805060 22962 heartbeater.cc:507] Master 127.21.216.126:40629 requested a full tablet report, sending...
I20260812 06:17:28.805600 22753 ts_manager.cc:194] Registered new tserver with Master: 1f78d8c8394c4abcb63ba33c8b600354 (127.21.216.65:43869)
I20260812 06:17:28.805660 22369 internal_mini_cluster.cc:371] 1 TS(s) registered with all masters after 0.008752908s
I20260812 06:17:28.806329 22753 master_service.cc:502] Signed X509 certificate for tserver {username='slave'} at 127.0.0.1:50910
I20260812 06:17:28.812034 22753 catalog_manager.cc:2283] Servicing CreateTable request from {username='slave'} at 127.0.0.1:50912:
name: "heavy-update-compaction-test"
schema {
  columns {
    name: "key"
    type: INT64
    is_key: true
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_a"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_b"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_c"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_d"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_e"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
}
num_replicas: 1
split_rows_range_bounds {
}
partition_schema {
  range_schema {
  }
}
I20260812 06:17:28.819754 22908 tablet_service.cc:1511] Processing CreateTablet for tablet 26c4eeba0f794819b78cd3eb793375f5 (DEFAULT_TABLE table=heavy-update-compaction-test [id=98a42001134a423ead909cff18ac96d8]), partition=
I20260812 06:17:28.819967 22908 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet 26c4eeba0f794819b78cd3eb793375f5. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:17:28.821663 22986 tablet_bootstrap.cc:492] T 26c4eeba0f794819b78cd3eb793375f5 P 1f78d8c8394c4abcb63ba33c8b600354: Bootstrap starting.
I20260812 06:17:28.822467 22986 tablet_bootstrap.cc:654] T 26c4eeba0f794819b78cd3eb793375f5 P 1f78d8c8394c4abcb63ba33c8b600354: Neither blocks nor log segments found. Creating new log.
I20260812 06:17:28.823428 22986 tablet_bootstrap.cc:492] T 26c4eeba0f794819b78cd3eb793375f5 P 1f78d8c8394c4abcb63ba33c8b600354: No bootstrap required, opened a new log
I20260812 06:17:28.823503 22986 ts_tablet_manager.cc:1403] T 26c4eeba0f794819b78cd3eb793375f5 P 1f78d8c8394c4abcb63ba33c8b600354: Time spent bootstrapping tablet: real 0.002s	user 0.000s	sys 0.001s
I20260812 06:17:28.823864 22986 raft_consensus.cc:359] T 26c4eeba0f794819b78cd3eb793375f5 P 1f78d8c8394c4abcb63ba33c8b600354 [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "1f78d8c8394c4abcb63ba33c8b600354" member_type: VOTER last_known_addr { host: "127.21.216.65" port: 43869 } }
I20260812 06:17:28.823952 22986 raft_consensus.cc:385] T 26c4eeba0f794819b78cd3eb793375f5 P 1f78d8c8394c4abcb63ba33c8b600354 [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:17:28.823992 22986 raft_consensus.cc:740] T 26c4eeba0f794819b78cd3eb793375f5 P 1f78d8c8394c4abcb63ba33c8b600354 [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: 1f78d8c8394c4abcb63ba33c8b600354, State: Initialized, Role: FOLLOWER
I20260812 06:17:28.824143 22986 consensus_queue.cc:260] T 26c4eeba0f794819b78cd3eb793375f5 P 1f78d8c8394c4abcb63ba33c8b600354 [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: "1f78d8c8394c4abcb63ba33c8b600354" member_type: VOTER last_known_addr { host: "127.21.216.65" port: 43869 } }
I20260812 06:17:28.824249 22986 raft_consensus.cc:399] T 26c4eeba0f794819b78cd3eb793375f5 P 1f78d8c8394c4abcb63ba33c8b600354 [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:17:28.824286 22986 raft_consensus.cc:493] T 26c4eeba0f794819b78cd3eb793375f5 P 1f78d8c8394c4abcb63ba33c8b600354 [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:17:28.824337 22986 raft_consensus.cc:3060] T 26c4eeba0f794819b78cd3eb793375f5 P 1f78d8c8394c4abcb63ba33c8b600354 [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:17:28.825011 22986 raft_consensus.cc:515] T 26c4eeba0f794819b78cd3eb793375f5 P 1f78d8c8394c4abcb63ba33c8b600354 [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "1f78d8c8394c4abcb63ba33c8b600354" member_type: VOTER last_known_addr { host: "127.21.216.65" port: 43869 } }
I20260812 06:17:28.825134 22986 leader_election.cc:304] T 26c4eeba0f794819b78cd3eb793375f5 P 1f78d8c8394c4abcb63ba33c8b600354 [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: 1f78d8c8394c4abcb63ba33c8b600354; no voters: 
I20260812 06:17:28.825279 22986 leader_election.cc:290] T 26c4eeba0f794819b78cd3eb793375f5 P 1f78d8c8394c4abcb63ba33c8b600354 [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:17:28.825409 22991 raft_consensus.cc:2804] T 26c4eeba0f794819b78cd3eb793375f5 P 1f78d8c8394c4abcb63ba33c8b600354 [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:17:28.825577 22986 ts_tablet_manager.cc:1434] T 26c4eeba0f794819b78cd3eb793375f5 P 1f78d8c8394c4abcb63ba33c8b600354: Time spent starting tablet: real 0.002s	user 0.000s	sys 0.002s
I20260812 06:17:28.825620 22991 raft_consensus.cc:697] T 26c4eeba0f794819b78cd3eb793375f5 P 1f78d8c8394c4abcb63ba33c8b600354 [term 1 LEADER]: Becoming Leader. State: Replica: 1f78d8c8394c4abcb63ba33c8b600354, State: Running, Role: LEADER
I20260812 06:17:28.825626 22962 heartbeater.cc:499] Master 127.21.216.126:40629 was elected leader, sending a full tablet report...
I20260812 06:17:28.825791 22991 consensus_queue.cc:237] T 26c4eeba0f794819b78cd3eb793375f5 P 1f78d8c8394c4abcb63ba33c8b600354 [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: "1f78d8c8394c4abcb63ba33c8b600354" member_type: VOTER last_known_addr { host: "127.21.216.65" port: 43869 } }
I20260812 06:17:28.826960 22753 catalog_manager.cc:5719] T 26c4eeba0f794819b78cd3eb793375f5 P 1f78d8c8394c4abcb63ba33c8b600354 reported cstate change: term changed from 0 to 1, leader changed from <none> to 1f78d8c8394c4abcb63ba33c8b600354 (127.21.216.65). New cstate: current_term: 1 leader_uuid: "1f78d8c8394c4abcb63ba33c8b600354" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "1f78d8c8394c4abcb63ba33c8b600354" member_type: VOTER last_known_addr { host: "127.21.216.65" port: 43869 } health_report { overall_health: HEALTHY } } }
I20260812 06:17:28.882107 22369 heavy-update-compaction-itest.cc:215] Time spent inserting: real 0.049s	user 0.015s	sys 0.007s
I20260812 06:17:29.047415 22965 maintenance_manager.cc:419] P 1f78d8c8394c4abcb63ba33c8b600354: Scheduling FlushMRSOp(26c4eeba0f794819b78cd3eb793375f5): perf score=23.023690
I20260812 06:17:29.212476 22866 maintenance_manager.cc:643] P 1f78d8c8394c4abcb63ba33c8b600354: FlushMRSOp(26c4eeba0f794819b78cd3eb793375f5) complete. Timing: real 0.165s	user 0.109s	sys 0.053s Metrics: {"bytes_written":13333097,"cfile_init":1,"delete_count":0,"dirs.queue_time_us":59,"dirs.run_cpu_time_us":187,"dirs.run_wall_time_us":1095,"drs_written":1,"lbm_read_time_us":51,"lbm_reads_lt_1ms":4,"lbm_write_time_us":42470,"lbm_writes_lt_1ms":882,"peak_mem_usage":0,"reinsert_count":0,"rows_written":105,"spinlock_wait_cycles":7936,"update_count":1625}
I20260812 06:17:29.213053 22965 maintenance_manager.cc:419] P 1f78d8c8394c4abcb63ba33c8b600354: Scheduling LogGCOp(26c4eeba0f794819b78cd3eb793375f5): free 20743880 bytes of WAL
I20260812 06:17:29.213272 22866 log_reader.cc:385] T 26c4eeba0f794819b78cd3eb793375f5: removed 2 log segments from log reader
I20260812 06:17:29.213320 22866 log.cc:1079] T 26c4eeba0f794819b78cd3eb793375f5 P 1f78d8c8394c4abcb63ba33c8b600354: Deleting log segment in path: /tmp/dist-test-taskw4CMs_/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515443298492-22369-0/minicluster-data/ts-0-root/wals/26c4eeba0f794819b78cd3eb793375f5/wal-000000001 (ops 1-6)
I20260812 06:17:29.213347 22866 log.cc:1079] T 26c4eeba0f794819b78cd3eb793375f5 P 1f78d8c8394c4abcb63ba33c8b600354: Deleting log segment in path: /tmp/dist-test-taskw4CMs_/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515443298492-22369-0/minicluster-data/ts-0-root/wals/26c4eeba0f794819b78cd3eb793375f5/wal-000000002 (ops 7-11)
I20260812 06:17:29.216852 22866 maintenance_manager.cc:643] P 1f78d8c8394c4abcb63ba33c8b600354: LogGCOp(26c4eeba0f794819b78cd3eb793375f5) complete. Timing: real 0.004s	user 0.002s	sys 0.000s Metrics: {}
I20260812 06:17:29.217286 22965 maintenance_manager.cc:419] P 1f78d8c8394c4abcb63ba33c8b600354: Scheduling FlushDeltaMemStoresOp(26c4eeba0f794819b78cd3eb793375f5): perf score=4.173312
I20260812 06:17:29.231856 22866 maintenance_manager.cc:643] P 1f78d8c8394c4abcb63ba33c8b600354: FlushDeltaMemStoresOp(26c4eeba0f794819b78cd3eb793375f5) complete. Timing: real 0.014s	user 0.005s	sys 0.008s Metrics: {"bytes_written":6358998,"delete_count":0,"lbm_write_time_us":6106,"lbm_writes_lt_1ms":158,"reinsert_count":0,"update_count":775}
I20260812 06:17:29.232225 22965 maintenance_manager.cc:419] P 1f78d8c8394c4abcb63ba33c8b600354: Scheduling MajorDeltaCompactionOp(26c4eeba0f794819b78cd3eb793375f5): perf score=1.000000
I20260812 06:17:29.405284 22866 maintenance_manager.cc:643] P 1f78d8c8394c4abcb63ba33c8b600354: MajorDeltaCompactionOp(26c4eeba0f794819b78cd3eb793375f5) complete. Timing: real 0.173s	user 0.101s	sys 0.070s Metrics: {"cfile_cache_miss":512,"cfile_cache_miss_bytes":23995212,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":565,"lbm_read_time_us":11709,"lbm_reads_lt_1ms":548,"lbm_write_time_us":27956,"lbm_writes_lt_1ms":523,"peak_mem_usage":60214432,"reinsert_count":0,"spinlock_wait_cycles":13952,"thread_start_us":303,"threads_started":5,"update_count":2400}
I20260812 06:17:29.405767 22965 maintenance_manager.cc:419] P 1f78d8c8394c4abcb63ba33c8b600354: Scheduling FlushDeltaMemStoresOp(26c4eeba0f794819b78cd3eb793375f5): perf score=15.087375
I20260812 06:17:29.463565 22866 maintenance_manager.cc:643] P 1f78d8c8394c4abcb63ba33c8b600354: FlushDeltaMemStoresOp(26c4eeba0f794819b78cd3eb793375f5) complete. Timing: real 0.058s	user 0.019s	sys 0.033s Metrics: {"bytes_written":17230395,"delete_count":0,"lbm_write_time_us":19175,"lbm_writes_lt_1ms":423,"reinsert_count":0,"update_count":2100}
I20260812 06:17:29.464098 22965 maintenance_manager.cc:419] P 1f78d8c8394c4abcb63ba33c8b600354: Scheduling UndoDeltaBlockGCOp(26c4eeba0f794819b78cd3eb793375f5): 20513812 bytes on disk
I20260812 06:17:29.464478 22866 maintenance_manager.cc:643] P 1f78d8c8394c4abcb63ba33c8b600354: UndoDeltaBlockGCOp(26c4eeba0f794819b78cd3eb793375f5) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":44,"lbm_reads_lt_1ms":4}
I20260812 06:17:29.464885 22965 maintenance_manager.cc:419] P 1f78d8c8394c4abcb63ba33c8b600354: Scheduling FlushDeltaMemStoresOp(26c4eeba0f794819b78cd3eb793375f5): perf score=2.188937
I20260812 06:17:29.474295 22866 maintenance_manager.cc:643] P 1f78d8c8394c4abcb63ba33c8b600354: FlushDeltaMemStoresOp(26c4eeba0f794819b78cd3eb793375f5) complete. Timing: real 0.009s	user 0.008s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3715,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:29.474648 22965 maintenance_manager.cc:419] P 1f78d8c8394c4abcb63ba33c8b600354: Scheduling MajorDeltaCompactionOp(26c4eeba0f794819b78cd3eb793375f5): perf score=1.000000
I20260812 06:17:29.650259 22866 maintenance_manager.cc:643] P 1f78d8c8394c4abcb63ba33c8b600354: MajorDeltaCompactionOp(26c4eeba0f794819b78cd3eb793375f5) complete. Timing: real 0.175s	user 0.103s	sys 0.068s Metrics: {"cfile_cache_miss":552,"cfile_cache_miss_bytes":25636177,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":116,"lbm_read_time_us":11848,"lbm_reads_lt_1ms":592,"lbm_write_time_us":27567,"lbm_writes_lt_1ms":563,"mutex_wait_us":24,"peak_mem_usage":64976984,"reinsert_count":0,"spinlock_wait_cycles":7424,"update_count":2600}
I20260812 06:17:29.650951 22965 maintenance_manager.cc:419] P 1f78d8c8394c4abcb63ba33c8b600354: Scheduling FlushDeltaMemStoresOp(26c4eeba0f794819b78cd3eb793375f5): perf score=14.095187
I20260812 06:17:29.700801 22866 maintenance_manager.cc:643] P 1f78d8c8394c4abcb63ba33c8b600354: FlushDeltaMemStoresOp(26c4eeba0f794819b78cd3eb793375f5) complete. Timing: real 0.050s	user 0.018s	sys 0.029s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":20802,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:17:29.701318 22965 maintenance_manager.cc:419] P 1f78d8c8394c4abcb63ba33c8b600354: Scheduling FlushDeltaMemStoresOp(26c4eeba0f794819b78cd3eb793375f5): perf score=2.188937
I20260812 06:17:29.727298 22866 maintenance_manager.cc:643] P 1f78d8c8394c4abcb63ba33c8b600354: FlushDeltaMemStoresOp(26c4eeba0f794819b78cd3eb793375f5) complete. Timing: real 0.026s	user 0.005s	sys 0.014s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4835,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:29.727692 22965 maintenance_manager.cc:419] P 1f78d8c8394c4abcb63ba33c8b600354: Scheduling MajorDeltaCompactionOp(26c4eeba0f794819b78cd3eb793375f5): perf score=1.000000
I20260812 06:17:29.914633 22866 maintenance_manager.cc:643] P 1f78d8c8394c4abcb63ba33c8b600354: MajorDeltaCompactionOp(26c4eeba0f794819b78cd3eb793375f5) complete. Timing: real 0.187s	user 0.129s	sys 0.053s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24815682,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":106,"lbm_read_time_us":14041,"lbm_reads_lt_1ms":564,"lbm_write_time_us":28669,"lbm_writes_lt_1ms":543,"mutex_wait_us":41,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":1792,"update_count":2500}
I20260812 06:17:29.915278 22965 maintenance_manager.cc:419] P 1f78d8c8394c4abcb63ba33c8b600354: Scheduling FlushDeltaMemStoresOp(26c4eeba0f794819b78cd3eb793375f5): perf score=15.087375
I20260812 06:17:29.957592 22866 maintenance_manager.cc:643] P 1f78d8c8394c4abcb63ba33c8b600354: FlushDeltaMemStoresOp(26c4eeba0f794819b78cd3eb793375f5) complete. Timing: real 0.042s	user 0.020s	sys 0.015s Metrics: {"bytes_written":16820142,"delete_count":0,"lbm_write_time_us":16170,"lbm_writes_lt_1ms":413,"reinsert_count":0,"update_count":2050}
I20260812 06:17:29.958000 22965 maintenance_manager.cc:419] P 1f78d8c8394c4abcb63ba33c8b600354: Scheduling FlushDeltaMemStoresOp(26c4eeba0f794819b78cd3eb793375f5): perf score=2.188937
I20260812 06:17:29.968495 22866 maintenance_manager.cc:643] P 1f78d8c8394c4abcb63ba33c8b600354: FlushDeltaMemStoresOp(26c4eeba0f794819b78cd3eb793375f5) complete. Timing: real 0.010s	user 0.009s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3868,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:29.968993 22965 maintenance_manager.cc:419] P 1f78d8c8394c4abcb63ba33c8b600354: Scheduling FlushDeltaMemStoresOp(26c4eeba0f794819b78cd3eb793375f5): perf score=2.188937
I20260812 06:17:29.990818 22866 maintenance_manager.cc:643] P 1f78d8c8394c4abcb63ba33c8b600354: FlushDeltaMemStoresOp(26c4eeba0f794819b78cd3eb793375f5) complete. Timing: real 0.022s	user 0.008s	sys 0.010s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":4880,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:17:29.991271 22965 maintenance_manager.cc:419] P 1f78d8c8394c4abcb63ba33c8b600354: Scheduling MajorDeltaCompactionOp(26c4eeba0f794819b78cd3eb793375f5): perf score=1.000000
I20260812 06:17:30.180279 22866 maintenance_manager.cc:643] P 1f78d8c8394c4abcb63ba33c8b600354: MajorDeltaCompactionOp(26c4eeba0f794819b78cd3eb793375f5) complete. Timing: real 0.189s	user 0.118s	sys 0.071s Metrics: {"cfile_cache_miss":633,"cfile_cache_miss_bytes":28918201,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":136,"lbm_read_time_us":13006,"lbm_reads_lt_1ms":673,"lbm_write_time_us":31507,"lbm_writes_lt_1ms":643,"mutex_wait_us":25,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":4608,"update_count":3000}
I20260812 06:17:30.180989 22965 maintenance_manager.cc:419] P 1f78d8c8394c4abcb63ba33c8b600354: Scheduling FlushDeltaMemStoresOp(26c4eeba0f794819b78cd3eb793375f5): perf score=14.095187
I20260812 06:17:30.243880 22866 maintenance_manager.cc:643] P 1f78d8c8394c4abcb63ba33c8b600354: FlushDeltaMemStoresOp(26c4eeba0f794819b78cd3eb793375f5) complete. Timing: real 0.062s	user 0.035s	sys 0.021s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":21389,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:17:30.244306 22965 maintenance_manager.cc:419] P 1f78d8c8394c4abcb63ba33c8b600354: Scheduling FlushDeltaMemStoresOp(26c4eeba0f794819b78cd3eb793375f5): perf score=2.188937
I20260812 06:17:30.254112 22866 maintenance_manager.cc:643] P 1f78d8c8394c4abcb63ba33c8b600354: FlushDeltaMemStoresOp(26c4eeba0f794819b78cd3eb793375f5) complete. Timing: real 0.010s	user 0.008s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3744,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:30.254504 22965 maintenance_manager.cc:419] P 1f78d8c8394c4abcb63ba33c8b600354: Scheduling MajorDeltaCompactionOp(26c4eeba0f794819b78cd3eb793375f5): perf score=1.000000
I20260812 06:17:30.426144 22866 maintenance_manager.cc:643] P 1f78d8c8394c4abcb63ba33c8b600354: MajorDeltaCompactionOp(26c4eeba0f794819b78cd3eb793375f5) complete. Timing: real 0.171s	user 0.094s	sys 0.072s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24815683,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":622,"dirs.run_cpu_time_us":500,"dirs.run_wall_time_us":2764,"lbm_read_time_us":11518,"lbm_reads_lt_1ms":572,"lbm_write_time_us":26206,"lbm_writes_lt_1ms":543,"mutex_wait_us":32,"peak_mem_usage":63115900,"reinsert_count":0,"update_count":2500}
I20260812 06:17:30.426671 22965 maintenance_manager.cc:419] P 1f78d8c8394c4abcb63ba33c8b600354: Scheduling FlushDeltaMemStoresOp(26c4eeba0f794819b78cd3eb793375f5): perf score=11.118625
I20260812 06:17:30.464064 22866 maintenance_manager.cc:643] P 1f78d8c8394c4abcb63ba33c8b600354: FlushDeltaMemStoresOp(26c4eeba0f794819b78cd3eb793375f5) complete. Timing: real 0.037s	user 0.021s	sys 0.014s Metrics: {"bytes_written":12963877,"delete_count":0,"lbm_write_time_us":15738,"lbm_writes_lt_1ms":319,"reinsert_count":0,"update_count":1580}
I20260812 06:17:30.464581 22965 maintenance_manager.cc:419] P 1f78d8c8394c4abcb63ba33c8b600354: Scheduling FlushDeltaMemStoresOp(26c4eeba0f794819b78cd3eb793375f5): perf score=2.188937
I20260812 06:17:30.481921 22866 maintenance_manager.cc:643] P 1f78d8c8394c4abcb63ba33c8b600354: FlushDeltaMemStoresOp(26c4eeba0f794819b78cd3eb793375f5) complete. Timing: real 0.017s	user 0.004s	sys 0.004s Metrics: {"bytes_written":3856509,"delete_count":0,"lbm_write_time_us":3633,"lbm_writes_lt_1ms":97,"reinsert_count":0,"update_count":470}
I20260812 06:17:30.482371 22965 maintenance_manager.cc:419] P 1f78d8c8394c4abcb63ba33c8b600354: Scheduling FlushDeltaMemStoresOp(26c4eeba0f794819b78cd3eb793375f5): perf score=2.188937
I20260812 06:17:30.499173 22866 maintenance_manager.cc:643] P 1f78d8c8394c4abcb63ba33c8b600354: FlushDeltaMemStoresOp(26c4eeba0f794819b78cd3eb793375f5) complete. Timing: real 0.017s	user 0.010s	sys 0.007s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3259,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:17:30.499663 22965 maintenance_manager.cc:419] P 1f78d8c8394c4abcb63ba33c8b600354: Scheduling FlushMRSOp(26c4eeba0f794819b78cd3eb793375f5): perf score=1.000000
I20260812 06:17:30.529618 22866 maintenance_manager.cc:643] P 1f78d8c8394c4abcb63ba33c8b600354: FlushMRSOp(26c4eeba0f794819b78cd3eb793375f5) complete. Timing: real 0.030s	user 0.022s	sys 0.005s Metrics: {"bytes_written":1275444,"cfile_init":1,"dirs.queue_time_us":90,"dirs.run_cpu_time_us":295,"dirs.run_wall_time_us":1460,"drs_written":1,"lbm_read_time_us":35,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1355,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":31}
I20260812 06:17:30.530246 22965 maintenance_manager.cc:419] P 1f78d8c8394c4abcb63ba33c8b600354: Scheduling MajorDeltaCompactionOp(26c4eeba0f794819b78cd3eb793375f5): perf score=1.000000
I20260812 06:17:30.700868 22866 maintenance_manager.cc:643] P 1f78d8c8394c4abcb63ba33c8b600354: MajorDeltaCompactionOp(26c4eeba0f794819b78cd3eb793375f5) complete. Timing: real 0.170s	user 0.115s	sys 0.054s Metrics: {"cfile_cache_miss":533,"cfile_cache_miss_bytes":24815786,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":600,"lbm_read_time_us":12123,"lbm_reads_lt_1ms":565,"lbm_write_time_us":27285,"lbm_writes_lt_1ms":543,"mutex_wait_us":343,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":4352,"update_count":2500}
I20260812 06:17:30.701385 22965 maintenance_manager.cc:419] P 1f78d8c8394c4abcb63ba33c8b600354: Scheduling LogGCOp(26c4eeba0f794819b78cd3eb793375f5): free 128867408 bytes of WAL
I20260812 06:17:30.701608 22866 log_reader.cc:385] T 26c4eeba0f794819b78cd3eb793375f5: removed 13 log segments from log reader
I20260812 06:17:30.701651 22866 log.cc:1079] T 26c4eeba0f794819b78cd3eb793375f5 P 1f78d8c8394c4abcb63ba33c8b600354: Deleting log segment in path: /tmp/dist-test-taskw4CMs_/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515443298492-22369-0/minicluster-data/ts-0-root/wals/26c4eeba0f794819b78cd3eb793375f5/wal-000000003 (ops 12-16)
I20260812 06:17:30.701685 22866 log.cc:1079] T 26c4eeba0f794819b78cd3eb793375f5 P 1f78d8c8394c4abcb63ba33c8b600354: Deleting log segment in path: /tmp/dist-test-taskw4CMs_/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515443298492-22369-0/minicluster-data/ts-0-root/wals/26c4eeba0f794819b78cd3eb793375f5/wal-000000004 (ops 17-20)
I20260812 06:17:30.701707 22866 log.cc:1079] T 26c4eeba0f794819b78cd3eb793375f5 P 1f78d8c8394c4abcb63ba33c8b600354: Deleting log segment in path: /tmp/dist-test-taskw4CMs_/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515443298492-22369-0/minicluster-data/ts-0-root/wals/26c4eeba0f794819b78cd3eb793375f5/wal-000000005 (ops 21-25)
I20260812 06:17:30.701766 22866 log.cc:1079] T 26c4eeba0f794819b78cd3eb793375f5 P 1f78d8c8394c4abcb63ba33c8b600354: Deleting log segment in path: /tmp/dist-test-taskw4CMs_/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515443298492-22369-0/minicluster-data/ts-0-root/wals/26c4eeba0f794819b78cd3eb793375f5/wal-000000006 (ops 26-30)
I20260812 06:17:30.701797 22866 log.cc:1079] T 26c4eeba0f794819b78cd3eb793375f5 P 1f78d8c8394c4abcb63ba33c8b600354: Deleting log segment in path: /tmp/dist-test-taskw4CMs_/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515443298492-22369-0/minicluster-data/ts-0-root/wals/26c4eeba0f794819b78cd3eb793375f5/wal-000000007 (ops 31-35)
I20260812 06:17:30.701819 22866 log.cc:1079] T 26c4eeba0f794819b78cd3eb793375f5 P 1f78d8c8394c4abcb63ba33c8b600354: Deleting log segment in path: /tmp/dist-test-taskw4CMs_/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515443298492-22369-0/minicluster-data/ts-0-root/wals/26c4eeba0f794819b78cd3eb793375f5/wal-000000008 (ops 36-40)
I20260812 06:17:30.701862 22866 log.cc:1079] T 26c4eeba0f794819b78cd3eb793375f5 P 1f78d8c8394c4abcb63ba33c8b600354: Deleting log segment in path: /tmp/dist-test-taskw4CMs_/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515443298492-22369-0/minicluster-data/ts-0-root/wals/26c4eeba0f794819b78cd3eb793375f5/wal-000000009 (ops 41-45)
I20260812 06:17:30.701891 22866 log.cc:1079] T 26c4eeba0f794819b78cd3eb793375f5 P 1f78d8c8394c4abcb63ba33c8b600354: Deleting log segment in path: /tmp/dist-test-taskw4CMs_/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515443298492-22369-0/minicluster-data/ts-0-root/wals/26c4eeba0f794819b78cd3eb793375f5/wal-000000010 (ops 46-50)
I20260812 06:17:30.701912 22866 log.cc:1079] T 26c4eeba0f794819b78cd3eb793375f5 P 1f78d8c8394c4abcb63ba33c8b600354: Deleting log segment in path: /tmp/dist-test-taskw4CMs_/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515443298492-22369-0/minicluster-data/ts-0-root/wals/26c4eeba0f794819b78cd3eb793375f5/wal-000000011 (ops 51-54)
I20260812 06:17:30.701952 22866 log.cc:1079] T 26c4eeba0f794819b78cd3eb793375f5 P 1f78d8c8394c4abcb63ba33c8b600354: Deleting log segment in path: /tmp/dist-test-taskw4CMs_/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515443298492-22369-0/minicluster-data/ts-0-root/wals/26c4eeba0f794819b78cd3eb793375f5/wal-000000012 (ops 55-59)
I20260812 06:17:30.701982 22866 log.cc:1079] T 26c4eeba0f794819b78cd3eb793375f5 P 1f78d8c8394c4abcb63ba33c8b600354: Deleting log segment in path: /tmp/dist-test-taskw4CMs_/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515443298492-22369-0/minicluster-data/ts-0-root/wals/26c4eeba0f794819b78cd3eb793375f5/wal-000000013 (ops 60-64)
I20260812 06:17:30.702003 22866 log.cc:1079] T 26c4eeba0f794819b78cd3eb793375f5 P 1f78d8c8394c4abcb63ba33c8b600354: Deleting log segment in path: /tmp/dist-test-taskw4CMs_/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515443298492-22369-0/minicluster-data/ts-0-root/wals/26c4eeba0f794819b78cd3eb793375f5/wal-000000014 (ops 65-68)
I20260812 06:17:30.702045 22866 log.cc:1079] T 26c4eeba0f794819b78cd3eb793375f5 P 1f78d8c8394c4abcb63ba33c8b600354: Deleting log segment in path: /tmp/dist-test-taskw4CMs_/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515443298492-22369-0/minicluster-data/ts-0-root/wals/26c4eeba0f794819b78cd3eb793375f5/wal-000000015 (ops 69-73)
I20260812 06:17:30.729207 22866 maintenance_manager.cc:643] P 1f78d8c8394c4abcb63ba33c8b600354: LogGCOp(26c4eeba0f794819b78cd3eb793375f5) complete. Timing: real 0.028s	user 0.000s	sys 0.025s Metrics: {}
I20260812 06:17:30.729604 22965 maintenance_manager.cc:419] P 1f78d8c8394c4abcb63ba33c8b600354: Scheduling UndoDeltaBlockGCOp(26c4eeba0f794819b78cd3eb793375f5): 482 bytes on disk
I20260812 06:17:30.730073 22866 maintenance_manager.cc:643] P 1f78d8c8394c4abcb63ba33c8b600354: UndoDeltaBlockGCOp(26c4eeba0f794819b78cd3eb793375f5) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":60,"lbm_reads_lt_1ms":4}
I20260812 06:17:30.730602 22965 maintenance_manager.cc:419] P 1f78d8c8394c4abcb63ba33c8b600354: Scheduling FlushDeltaMemStoresOp(26c4eeba0f794819b78cd3eb793375f5): perf score=18.063937
I20260812 06:17:30.786060 22866 maintenance_manager.cc:643] P 1f78d8c8394c4abcb63ba33c8b600354: FlushDeltaMemStoresOp(26c4eeba0f794819b78cd3eb793375f5) complete. Timing: real 0.055s	user 0.021s	sys 0.031s Metrics: {"bytes_written":20512315,"delete_count":0,"lbm_write_time_us":21003,"lbm_writes_lt_1ms":503,"reinsert_count":0,"update_count":2500}
I20260812 06:17:30.786566 22965 maintenance_manager.cc:419] P 1f78d8c8394c4abcb63ba33c8b600354: Scheduling FlushDeltaMemStoresOp(26c4eeba0f794819b78cd3eb793375f5): perf score=2.188937
I20260812 06:17:30.796582 22866 maintenance_manager.cc:643] P 1f78d8c8394c4abcb63ba33c8b600354: FlushDeltaMemStoresOp(26c4eeba0f794819b78cd3eb793375f5) complete. Timing: real 0.010s	user 0.008s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3839,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:30.796978 22965 maintenance_manager.cc:419] P 1f78d8c8394c4abcb63ba33c8b600354: Scheduling MajorDeltaCompactionOp(26c4eeba0f794819b78cd3eb793375f5): perf score=1.000000
I20260812 06:17:30.991562 22866 maintenance_manager.cc:643] P 1f78d8c8394c4abcb63ba33c8b600354: MajorDeltaCompactionOp(26c4eeba0f794819b78cd3eb793375f5) complete. Timing: real 0.194s	user 0.115s	sys 0.079s Metrics: {"cfile_cache_miss":632,"cfile_cache_miss_bytes":28918097,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":486,"lbm_read_time_us":14606,"lbm_reads_lt_1ms":672,"lbm_write_time_us":32140,"lbm_writes_lt_1ms":643,"mutex_wait_us":39,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":10880,"update_count":3000}
I20260812 06:17:30.992012 22965 maintenance_manager.cc:419] P 1f78d8c8394c4abcb63ba33c8b600354: Scheduling FlushDeltaMemStoresOp(26c4eeba0f794819b78cd3eb793375f5): perf score=14.095187
I20260812 06:17:31.047395 22866 maintenance_manager.cc:643] P 1f78d8c8394c4abcb63ba33c8b600354: FlushDeltaMemStoresOp(26c4eeba0f794819b78cd3eb793375f5) complete. Timing: real 0.055s	user 0.034s	sys 0.014s Metrics: {"bytes_written":16409903,"delete_count":0,"lbm_write_time_us":17071,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:17:31.047977 22965 maintenance_manager.cc:419] P 1f78d8c8394c4abcb63ba33c8b600354: Scheduling FlushDeltaMemStoresOp(26c4eeba0f794819b78cd3eb793375f5): perf score=2.188937
I20260812 06:17:31.058079 22866 maintenance_manager.cc:643] P 1f78d8c8394c4abcb63ba33c8b600354: FlushDeltaMemStoresOp(26c4eeba0f794819b78cd3eb793375f5) complete. Timing: real 0.010s	user 0.004s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3910,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:31.058557 22965 maintenance_manager.cc:419] P 1f78d8c8394c4abcb63ba33c8b600354: Scheduling MajorDeltaCompactionOp(26c4eeba0f794819b78cd3eb793375f5): perf score=1.000000
I20260812 06:17:31.227658 22866 maintenance_manager.cc:643] P 1f78d8c8394c4abcb63ba33c8b600354: MajorDeltaCompactionOp(26c4eeba0f794819b78cd3eb793375f5) complete. Timing: real 0.169s	user 0.112s	sys 0.051s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24815685,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":105,"lbm_read_time_us":11506,"lbm_reads_lt_1ms":572,"lbm_write_time_us":25722,"lbm_writes_lt_1ms":543,"mutex_wait_us":35,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":12288,"update_count":2500}
I20260812 06:17:31.228310 22965 maintenance_manager.cc:419] P 1f78d8c8394c4abcb63ba33c8b600354: Scheduling FlushDeltaMemStoresOp(26c4eeba0f794819b78cd3eb793375f5): perf score=14.095187
I20260812 06:17:31.277585 22866 maintenance_manager.cc:643] P 1f78d8c8394c4abcb63ba33c8b600354: FlushDeltaMemStoresOp(26c4eeba0f794819b78cd3eb793375f5) complete. Timing: real 0.049s	user 0.034s	sys 0.012s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":22011,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":402,"reinsert_count":0,"update_count":2000}
I20260812 06:17:31.278136 22965 maintenance_manager.cc:419] P 1f78d8c8394c4abcb63ba33c8b600354: Scheduling FlushDeltaMemStoresOp(26c4eeba0f794819b78cd3eb793375f5): perf score=2.188937
I20260812 06:17:31.296912 22866 maintenance_manager.cc:643] P 1f78d8c8394c4abcb63ba33c8b600354: FlushDeltaMemStoresOp(26c4eeba0f794819b78cd3eb793375f5) complete. Timing: real 0.019s	user 0.013s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4642,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:31.297462 22965 maintenance_manager.cc:419] P 1f78d8c8394c4abcb63ba33c8b600354: Scheduling MajorDeltaCompactionOp(26c4eeba0f794819b78cd3eb793375f5): perf score=1.000000
I20260812 06:17:31.469339 22866 maintenance_manager.cc:643] P 1f78d8c8394c4abcb63ba33c8b600354: MajorDeltaCompactionOp(26c4eeba0f794819b78cd3eb793375f5) complete. Timing: real 0.172s	user 0.121s	sys 0.051s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24815683,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":140,"lbm_read_time_us":12637,"lbm_reads_lt_1ms":564,"lbm_write_time_us":27539,"lbm_writes_lt_1ms":543,"mutex_wait_us":16,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":1920,"update_count":2500}
I20260812 06:17:31.469851 22965 maintenance_manager.cc:419] P 1f78d8c8394c4abcb63ba33c8b600354: Scheduling FlushDeltaMemStoresOp(26c4eeba0f794819b78cd3eb793375f5): perf score=14.095187
I20260812 06:17:31.518603 22866 maintenance_manager.cc:643] P 1f78d8c8394c4abcb63ba33c8b600354: FlushDeltaMemStoresOp(26c4eeba0f794819b78cd3eb793375f5) complete. Timing: real 0.049s	user 0.017s	sys 0.028s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":21487,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:17:31.519181 22965 maintenance_manager.cc:419] P 1f78d8c8394c4abcb63ba33c8b600354: Scheduling FlushDeltaMemStoresOp(26c4eeba0f794819b78cd3eb793375f5): perf score=2.188937
I20260812 06:17:31.534706 22866 maintenance_manager.cc:643] P 1f78d8c8394c4abcb63ba33c8b600354: FlushDeltaMemStoresOp(26c4eeba0f794819b78cd3eb793375f5) complete. Timing: real 0.015s	user 0.013s	sys 0.001s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6167,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:31.535193 22965 maintenance_manager.cc:419] P 1f78d8c8394c4abcb63ba33c8b600354: Scheduling MajorDeltaCompactionOp(26c4eeba0f794819b78cd3eb793375f5): perf score=1.000000
I20260812 06:17:31.709455 22866 maintenance_manager.cc:643] P 1f78d8c8394c4abcb63ba33c8b600354: MajorDeltaCompactionOp(26c4eeba0f794819b78cd3eb793375f5) complete. Timing: real 0.174s	user 0.108s	sys 0.058s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24815683,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":146,"lbm_read_time_us":9858,"lbm_reads_lt_1ms":568,"lbm_write_time_us":29500,"lbm_writes_lt_1ms":543,"mutex_wait_us":39,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":7808,"update_count":2500}
I20260812 06:17:31.709913 22965 maintenance_manager.cc:419] P 1f78d8c8394c4abcb63ba33c8b600354: Scheduling FlushDeltaMemStoresOp(26c4eeba0f794819b78cd3eb793375f5): perf score=14.095187
I20260812 06:17:31.754173 22866 maintenance_manager.cc:643] P 1f78d8c8394c4abcb63ba33c8b600354: FlushDeltaMemStoresOp(26c4eeba0f794819b78cd3eb793375f5) complete. Timing: real 0.044s	user 0.015s	sys 0.020s Metrics: {"bytes_written":16409903,"delete_count":0,"lbm_write_time_us":16454,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:17:31.754730 22965 maintenance_manager.cc:419] P 1f78d8c8394c4abcb63ba33c8b600354: Scheduling FlushDeltaMemStoresOp(26c4eeba0f794819b78cd3eb793375f5): perf score=2.188937
I20260812 06:17:31.770304 22866 maintenance_manager.cc:643] P 1f78d8c8394c4abcb63ba33c8b600354: FlushDeltaMemStoresOp(26c4eeba0f794819b78cd3eb793375f5) complete. Timing: real 0.015s	user 0.006s	sys 0.007s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5877,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:31.770872 22965 maintenance_manager.cc:419] P 1f78d8c8394c4abcb63ba33c8b600354: Scheduling MajorDeltaCompactionOp(26c4eeba0f794819b78cd3eb793375f5): perf score=1.000000
I20260812 06:17:31.931668 22866 maintenance_manager.cc:643] P 1f78d8c8394c4abcb63ba33c8b600354: MajorDeltaCompactionOp(26c4eeba0f794819b78cd3eb793375f5) complete. Timing: real 0.161s	user 0.120s	sys 0.033s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24815685,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":116,"lbm_read_time_us":9875,"lbm_reads_lt_1ms":572,"lbm_write_time_us":33201,"lbm_writes_lt_1ms":543,"mutex_wait_us":24,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":11008,"update_count":2500}
I20260812 06:17:31.932195 22965 maintenance_manager.cc:419] P 1f78d8c8394c4abcb63ba33c8b600354: Scheduling FlushDeltaMemStoresOp(26c4eeba0f794819b78cd3eb793375f5): perf score=14.095187
I20260812 06:17:31.978442 22866 maintenance_manager.cc:643] P 1f78d8c8394c4abcb63ba33c8b600354: FlushDeltaMemStoresOp(26c4eeba0f794819b78cd3eb793375f5) complete. Timing: real 0.046s	user 0.025s	sys 0.011s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":17370,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:17:31.979012 22965 maintenance_manager.cc:419] P 1f78d8c8394c4abcb63ba33c8b600354: Scheduling FlushDeltaMemStoresOp(26c4eeba0f794819b78cd3eb793375f5): perf score=2.188937
I20260812 06:17:31.989228 22866 maintenance_manager.cc:643] P 1f78d8c8394c4abcb63ba33c8b600354: FlushDeltaMemStoresOp(26c4eeba0f794819b78cd3eb793375f5) complete. Timing: real 0.010s	user 0.004s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3893,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:31.989836 22965 maintenance_manager.cc:419] P 1f78d8c8394c4abcb63ba33c8b600354: Scheduling FlushMRSOp(26c4eeba0f794819b78cd3eb793375f5): perf score=1.000000
I20260812 06:17:32.022477 22866 maintenance_manager.cc:643] P 1f78d8c8394c4abcb63ba33c8b600354: FlushMRSOp(26c4eeba0f794819b78cd3eb793375f5) complete. Timing: real 0.032s	user 0.031s	sys 0.000s Metrics: {"bytes_written":1275447,"cfile_init":1,"dirs.queue_time_us":52,"dirs.run_cpu_time_us":238,"dirs.run_wall_time_us":1219,"drs_written":1,"lbm_read_time_us":36,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1938,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":31}
I20260812 06:17:32.023216 22965 maintenance_manager.cc:419] P 1f78d8c8394c4abcb63ba33c8b600354: Scheduling LogGCOp(26c4eeba0f794819b78cd3eb793375f5): free 124710327 bytes of WAL
I20260812 06:17:32.023438 22866 log_reader.cc:385] T 26c4eeba0f794819b78cd3eb793375f5: removed 12 log segments from log reader
I20260812 06:17:32.023486 22866 log.cc:1079] T 26c4eeba0f794819b78cd3eb793375f5 P 1f78d8c8394c4abcb63ba33c8b600354: Deleting log segment in path: /tmp/dist-test-taskw4CMs_/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515443298492-22369-0/minicluster-data/ts-0-root/wals/26c4eeba0f794819b78cd3eb793375f5/wal-000000016 (ops 74-78)
I20260812 06:17:32.023536 22866 log.cc:1079] T 26c4eeba0f794819b78cd3eb793375f5 P 1f78d8c8394c4abcb63ba33c8b600354: Deleting log segment in path: /tmp/dist-test-taskw4CMs_/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515443298492-22369-0/minicluster-data/ts-0-root/wals/26c4eeba0f794819b78cd3eb793375f5/wal-000000017 (ops 79-83)
I20260812 06:17:32.023568 22866 log.cc:1079] T 26c4eeba0f794819b78cd3eb793375f5 P 1f78d8c8394c4abcb63ba33c8b600354: Deleting log segment in path: /tmp/dist-test-taskw4CMs_/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515443298492-22369-0/minicluster-data/ts-0-root/wals/26c4eeba0f794819b78cd3eb793375f5/wal-000000018 (ops 84-88)
I20260812 06:17:32.023600 22866 log.cc:1079] T 26c4eeba0f794819b78cd3eb793375f5 P 1f78d8c8394c4abcb63ba33c8b600354: Deleting log segment in path: /tmp/dist-test-taskw4CMs_/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515443298492-22369-0/minicluster-data/ts-0-root/wals/26c4eeba0f794819b78cd3eb793375f5/wal-000000019 (ops 89-93)
I20260812 06:17:32.023633 22866 log.cc:1079] T 26c4eeba0f794819b78cd3eb793375f5 P 1f78d8c8394c4abcb63ba33c8b600354: Deleting log segment in path: /tmp/dist-test-taskw4CMs_/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515443298492-22369-0/minicluster-data/ts-0-root/wals/26c4eeba0f794819b78cd3eb793375f5/wal-000000020 (ops 94-98)
I20260812 06:17:32.023662 22866 log.cc:1079] T 26c4eeba0f794819b78cd3eb793375f5 P 1f78d8c8394c4abcb63ba33c8b600354: Deleting log segment in path: /tmp/dist-test-taskw4CMs_/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515443298492-22369-0/minicluster-data/ts-0-root/wals/26c4eeba0f794819b78cd3eb793375f5/wal-000000021 (ops 99-103)
I20260812 06:17:32.023692 22866 log.cc:1079] T 26c4eeba0f794819b78cd3eb793375f5 P 1f78d8c8394c4abcb63ba33c8b600354: Deleting log segment in path: /tmp/dist-test-taskw4CMs_/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515443298492-22369-0/minicluster-data/ts-0-root/wals/26c4eeba0f794819b78cd3eb793375f5/wal-000000022 (ops 104-108)
I20260812 06:17:32.023723 22866 log.cc:1079] T 26c4eeba0f794819b78cd3eb793375f5 P 1f78d8c8394c4abcb63ba33c8b600354: Deleting log segment in path: /tmp/dist-test-taskw4CMs_/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515443298492-22369-0/minicluster-data/ts-0-root/wals/26c4eeba0f794819b78cd3eb793375f5/wal-000000023 (ops 109-113)
I20260812 06:17:32.023753 22866 log.cc:1079] T 26c4eeba0f794819b78cd3eb793375f5 P 1f78d8c8394c4abcb63ba33c8b600354: Deleting log segment in path: /tmp/dist-test-taskw4CMs_/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515443298492-22369-0/minicluster-data/ts-0-root/wals/26c4eeba0f794819b78cd3eb793375f5/wal-000000024 (ops 114-118)
I20260812 06:17:32.023783 22866 log.cc:1079] T 26c4eeba0f794819b78cd3eb793375f5 P 1f78d8c8394c4abcb63ba33c8b600354: Deleting log segment in path: /tmp/dist-test-taskw4CMs_/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515443298492-22369-0/minicluster-data/ts-0-root/wals/26c4eeba0f794819b78cd3eb793375f5/wal-000000025 (ops 119-123)
I20260812 06:17:32.023813 22866 log.cc:1079] T 26c4eeba0f794819b78cd3eb793375f5 P 1f78d8c8394c4abcb63ba33c8b600354: Deleting log segment in path: /tmp/dist-test-taskw4CMs_/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515443298492-22369-0/minicluster-data/ts-0-root/wals/26c4eeba0f794819b78cd3eb793375f5/wal-000000026 (ops 124-128)
I20260812 06:17:32.023844 22866 log.cc:1079] T 26c4eeba0f794819b78cd3eb793375f5 P 1f78d8c8394c4abcb63ba33c8b600354: Deleting log segment in path: /tmp/dist-test-taskw4CMs_/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515443298492-22369-0/minicluster-data/ts-0-root/wals/26c4eeba0f794819b78cd3eb793375f5/wal-000000027 (ops 129-133)
I20260812 06:17:32.047641 22866 maintenance_manager.cc:643] P 1f78d8c8394c4abcb63ba33c8b600354: LogGCOp(26c4eeba0f794819b78cd3eb793375f5) complete. Timing: real 0.024s	user 0.004s	sys 0.020s Metrics: {}
I20260812 06:17:32.048060 22965 maintenance_manager.cc:419] P 1f78d8c8394c4abcb63ba33c8b600354: Scheduling FlushDeltaMemStoresOp(26c4eeba0f794819b78cd3eb793375f5): perf score=3.181125
I20260812 06:17:32.064832 22866 maintenance_manager.cc:643] P 1f78d8c8394c4abcb63ba33c8b600354: FlushDeltaMemStoresOp(26c4eeba0f794819b78cd3eb793375f5) complete. Timing: real 0.017s	user 0.007s	sys 0.008s Metrics: {"bytes_written":4512903,"delete_count":0,"lbm_write_time_us":6796,"lbm_writes_lt_1ms":113,"reinsert_count":0,"update_count":550}
I20260812 06:17:32.065222 22965 maintenance_manager.cc:419] P 1f78d8c8394c4abcb63ba33c8b600354: Scheduling UndoDeltaBlockGCOp(26c4eeba0f794819b78cd3eb793375f5): 482 bytes on disk
I20260812 06:17:32.065570 22866 maintenance_manager.cc:643] P 1f78d8c8394c4abcb63ba33c8b600354: UndoDeltaBlockGCOp(26c4eeba0f794819b78cd3eb793375f5) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":48,"lbm_reads_lt_1ms":4}
I20260812 06:17:32.066021 22965 maintenance_manager.cc:419] P 1f78d8c8394c4abcb63ba33c8b600354: Scheduling FlushDeltaMemStoresOp(26c4eeba0f794819b78cd3eb793375f5): perf score=2.188937
I20260812 06:17:32.074596 22866 maintenance_manager.cc:643] P 1f78d8c8394c4abcb63ba33c8b600354: FlushDeltaMemStoresOp(26c4eeba0f794819b78cd3eb793375f5) complete. Timing: real 0.008s	user 0.003s	sys 0.004s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3193,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:17:32.075279 22965 maintenance_manager.cc:419] P 1f78d8c8394c4abcb63ba33c8b600354: Scheduling MajorDeltaCompactionOp(26c4eeba0f794819b78cd3eb793375f5): perf score=1.000000
I20260812 06:17:32.300966 22866 maintenance_manager.cc:643] P 1f78d8c8394c4abcb63ba33c8b600354: MajorDeltaCompactionOp(26c4eeba0f794819b78cd3eb793375f5) complete. Timing: real 0.225s	user 0.155s	sys 0.056s Metrics: {"cfile_cache_miss":734,"cfile_cache_miss_bytes":33020735,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":100,"lbm_read_time_us":13609,"lbm_reads_lt_1ms":774,"lbm_write_time_us":36393,"lbm_writes_lt_1ms":743,"mutex_wait_us":37,"peak_mem_usage":87969044,"reinsert_count":0,"spinlock_wait_cycles":8960,"thread_start_us":71,"threads_started":1,"update_count":3500}
I20260812 06:17:32.301545 22965 maintenance_manager.cc:419] P 1f78d8c8394c4abcb63ba33c8b600354: Scheduling FlushDeltaMemStoresOp(26c4eeba0f794819b78cd3eb793375f5): perf score=18.063937
I20260812 06:17:32.373351 22866 maintenance_manager.cc:643] P 1f78d8c8394c4abcb63ba33c8b600354: FlushDeltaMemStoresOp(26c4eeba0f794819b78cd3eb793375f5) complete. Timing: real 0.072s	user 0.042s	sys 0.028s Metrics: {"bytes_written":20512314,"delete_count":0,"lbm_write_time_us":27043,"lbm_writes_lt_1ms":503,"reinsert_count":0,"update_count":2500}
I20260812 06:17:32.373905 22965 maintenance_manager.cc:419] P 1f78d8c8394c4abcb63ba33c8b600354: Scheduling FlushDeltaMemStoresOp(26c4eeba0f794819b78cd3eb793375f5): perf score=2.188937
I20260812 06:17:32.384120 22866 maintenance_manager.cc:643] P 1f78d8c8394c4abcb63ba33c8b600354: FlushDeltaMemStoresOp(26c4eeba0f794819b78cd3eb793375f5) complete. Timing: real 0.010s	user 0.005s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3921,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:32.384528 22965 maintenance_manager.cc:419] P 1f78d8c8394c4abcb63ba33c8b600354: Scheduling MajorDeltaCompactionOp(26c4eeba0f794819b78cd3eb793375f5): perf score=1.000000
I20260812 06:17:32.573283 22866 maintenance_manager.cc:643] P 1f78d8c8394c4abcb63ba33c8b600354: MajorDeltaCompactionOp(26c4eeba0f794819b78cd3eb793375f5) complete. Timing: real 0.189s	user 0.136s	sys 0.052s Metrics: {"cfile_cache_miss":632,"cfile_cache_miss_bytes":28918096,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":1043,"lbm_read_time_us":14227,"lbm_reads_lt_1ms":672,"lbm_write_time_us":31740,"lbm_writes_lt_1ms":643,"mutex_wait_us":326,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":33280,"update_count":3000}
I20260812 06:17:32.573925 22965 maintenance_manager.cc:419] P 1f78d8c8394c4abcb63ba33c8b600354: Scheduling FlushDeltaMemStoresOp(26c4eeba0f794819b78cd3eb793375f5): perf score=14.095187
I20260812 06:17:32.619395 22866 maintenance_manager.cc:643] P 1f78d8c8394c4abcb63ba33c8b600354: FlushDeltaMemStoresOp(26c4eeba0f794819b78cd3eb793375f5) complete. Timing: real 0.045s	user 0.026s	sys 0.018s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":20038,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:17:32.619871 22965 maintenance_manager.cc:419] P 1f78d8c8394c4abcb63ba33c8b600354: Scheduling FlushDeltaMemStoresOp(26c4eeba0f794819b78cd3eb793375f5): perf score=2.188937
I20260812 06:17:32.629509 22866 maintenance_manager.cc:643] P 1f78d8c8394c4abcb63ba33c8b600354: FlushDeltaMemStoresOp(26c4eeba0f794819b78cd3eb793375f5) complete. Timing: real 0.009s	user 0.004s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3831,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:32.630036 22965 maintenance_manager.cc:419] P 1f78d8c8394c4abcb63ba33c8b600354: Scheduling MajorDeltaCompactionOp(26c4eeba0f794819b78cd3eb793375f5): perf score=1.000000
I20260812 06:17:32.798959 22866 maintenance_manager.cc:643] P 1f78d8c8394c4abcb63ba33c8b600354: MajorDeltaCompactionOp(26c4eeba0f794819b78cd3eb793375f5) complete. Timing: real 0.169s	user 0.114s	sys 0.048s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24815684,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":832,"lbm_read_time_us":13055,"lbm_reads_lt_1ms":572,"lbm_write_time_us":27086,"lbm_writes_lt_1ms":543,"mutex_wait_us":256,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":8448,"update_count":2500}
I20260812 06:17:32.799467 22965 maintenance_manager.cc:419] P 1f78d8c8394c4abcb63ba33c8b600354: Scheduling FlushDeltaMemStoresOp(26c4eeba0f794819b78cd3eb793375f5): perf score=14.095187
I20260812 06:17:32.854434 22866 maintenance_manager.cc:643] P 1f78d8c8394c4abcb63ba33c8b600354: FlushDeltaMemStoresOp(26c4eeba0f794819b78cd3eb793375f5) complete. Timing: real 0.055s	user 0.028s	sys 0.023s Metrics: {"bytes_written":16409898,"delete_count":0,"lbm_write_time_us":19581,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:17:32.855013 22965 maintenance_manager.cc:419] P 1f78d8c8394c4abcb63ba33c8b600354: Scheduling FlushDeltaMemStoresOp(26c4eeba0f794819b78cd3eb793375f5): perf score=2.188937
I20260812 06:17:32.870405 22866 maintenance_manager.cc:643] P 1f78d8c8394c4abcb63ba33c8b600354: FlushDeltaMemStoresOp(26c4eeba0f794819b78cd3eb793375f5) complete. Timing: real 0.015s	user 0.005s	sys 0.008s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":5983,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:32.871009 22965 maintenance_manager.cc:419] P 1f78d8c8394c4abcb63ba33c8b600354: Scheduling MajorDeltaCompactionOp(26c4eeba0f794819b78cd3eb793375f5): perf score=1.000000
I20260812 06:17:33.049239 22866 maintenance_manager.cc:643] P 1f78d8c8394c4abcb63ba33c8b600354: MajorDeltaCompactionOp(26c4eeba0f794819b78cd3eb793375f5) complete. Timing: real 0.178s	user 0.117s	sys 0.052s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24815679,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":152,"lbm_read_time_us":13073,"lbm_reads_lt_1ms":572,"lbm_write_time_us":29134,"lbm_writes_lt_1ms":543,"mutex_wait_us":2,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":4096,"update_count":2500}
I20260812 06:17:33.049774 22965 maintenance_manager.cc:419] P 1f78d8c8394c4abcb63ba33c8b600354: Scheduling FlushDeltaMemStoresOp(26c4eeba0f794819b78cd3eb793375f5): perf score=14.095187
I20260812 06:17:33.115275 22866 maintenance_manager.cc:643] P 1f78d8c8394c4abcb63ba33c8b600354: FlushDeltaMemStoresOp(26c4eeba0f794819b78cd3eb793375f5) complete. Timing: real 0.065s	user 0.026s	sys 0.031s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":20265,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:17:33.115835 22965 maintenance_manager.cc:419] P 1f78d8c8394c4abcb63ba33c8b600354: Scheduling FlushDeltaMemStoresOp(26c4eeba0f794819b78cd3eb793375f5): perf score=2.188937
I20260812 06:17:33.130576 22866 maintenance_manager.cc:643] P 1f78d8c8394c4abcb63ba33c8b600354: FlushDeltaMemStoresOp(26c4eeba0f794819b78cd3eb793375f5) complete. Timing: real 0.015s	user 0.004s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5597,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:33.131132 22965 maintenance_manager.cc:419] P 1f78d8c8394c4abcb63ba33c8b600354: Scheduling MajorDeltaCompactionOp(26c4eeba0f794819b78cd3eb793375f5): perf score=1.000000
I20260812 06:17:33.307878 22866 maintenance_manager.cc:643] P 1f78d8c8394c4abcb63ba33c8b600354: MajorDeltaCompactionOp(26c4eeba0f794819b78cd3eb793375f5) complete. Timing: real 0.177s	user 0.095s	sys 0.073s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24815684,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":219,"lbm_read_time_us":13292,"lbm_reads_lt_1ms":572,"lbm_write_time_us":28253,"lbm_writes_lt_1ms":543,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":2304,"update_count":2500}
I20260812 06:17:33.308405 22965 maintenance_manager.cc:419] P 1f78d8c8394c4abcb63ba33c8b600354: Scheduling FlushDeltaMemStoresOp(26c4eeba0f794819b78cd3eb793375f5): perf score=14.095187
I20260812 06:17:33.354002 22866 maintenance_manager.cc:643] P 1f78d8c8394c4abcb63ba33c8b600354: FlushDeltaMemStoresOp(26c4eeba0f794819b78cd3eb793375f5) complete. Timing: real 0.045s	user 0.030s	sys 0.008s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":18140,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:17:33.354542 22965 maintenance_manager.cc:419] P 1f78d8c8394c4abcb63ba33c8b600354: Scheduling FlushDeltaMemStoresOp(26c4eeba0f794819b78cd3eb793375f5): perf score=2.188937
I20260812 06:17:33.377871 22866 maintenance_manager.cc:643] P 1f78d8c8394c4abcb63ba33c8b600354: FlushDeltaMemStoresOp(26c4eeba0f794819b78cd3eb793375f5) complete. Timing: real 0.023s	user 0.014s	sys 0.007s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5738,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:33.378383 22965 maintenance_manager.cc:419] P 1f78d8c8394c4abcb63ba33c8b600354: Scheduling FlushMRSOp(26c4eeba0f794819b78cd3eb793375f5): perf score=1.000000
I20260812 06:17:33.414606 22866 maintenance_manager.cc:643] P 1f78d8c8394c4abcb63ba33c8b600354: FlushMRSOp(26c4eeba0f794819b78cd3eb793375f5) complete. Timing: real 0.036s	user 0.025s	sys 0.000s Metrics: {"bytes_written":1152512,"cfile_init":1,"dirs.queue_time_us":64,"dirs.run_cpu_time_us":240,"dirs.run_wall_time_us":1350,"drs_written":1,"lbm_read_time_us":44,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1298,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":28}
I20260812 06:17:33.415398 22965 maintenance_manager.cc:419] P 1f78d8c8394c4abcb63ba33c8b600354: Scheduling LogGCOp(26c4eeba0f794819b78cd3eb793375f5): free 120553636 bytes of WAL
I20260812 06:17:33.415638 22866 log_reader.cc:385] T 26c4eeba0f794819b78cd3eb793375f5: removed 12 log segments from log reader
I20260812 06:17:33.415704 22866 log.cc:1079] T 26c4eeba0f794819b78cd3eb793375f5 P 1f78d8c8394c4abcb63ba33c8b600354: Deleting log segment in path: /tmp/dist-test-taskw4CMs_/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515443298492-22369-0/minicluster-data/ts-0-root/wals/26c4eeba0f794819b78cd3eb793375f5/wal-000000028 (ops 134-138)
I20260812 06:17:33.415750 22866 log.cc:1079] T 26c4eeba0f794819b78cd3eb793375f5 P 1f78d8c8394c4abcb63ba33c8b600354: Deleting log segment in path: /tmp/dist-test-taskw4CMs_/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515443298492-22369-0/minicluster-data/ts-0-root/wals/26c4eeba0f794819b78cd3eb793375f5/wal-000000029 (ops 139-142)
I20260812 06:17:33.415778 22866 log.cc:1079] T 26c4eeba0f794819b78cd3eb793375f5 P 1f78d8c8394c4abcb63ba33c8b600354: Deleting log segment in path: /tmp/dist-test-taskw4CMs_/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515443298492-22369-0/minicluster-data/ts-0-root/wals/26c4eeba0f794819b78cd3eb793375f5/wal-000000030 (ops 143-147)
I20260812 06:17:33.415803 22866 log.cc:1079] T 26c4eeba0f794819b78cd3eb793375f5 P 1f78d8c8394c4abcb63ba33c8b600354: Deleting log segment in path: /tmp/dist-test-taskw4CMs_/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515443298492-22369-0/minicluster-data/ts-0-root/wals/26c4eeba0f794819b78cd3eb793375f5/wal-000000031 (ops 148-152)
I20260812 06:17:33.415834 22866 log.cc:1079] T 26c4eeba0f794819b78cd3eb793375f5 P 1f78d8c8394c4abcb63ba33c8b600354: Deleting log segment in path: /tmp/dist-test-taskw4CMs_/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515443298492-22369-0/minicluster-data/ts-0-root/wals/26c4eeba0f794819b78cd3eb793375f5/wal-000000032 (ops 153-157)
I20260812 06:17:33.415866 22866 log.cc:1079] T 26c4eeba0f794819b78cd3eb793375f5 P 1f78d8c8394c4abcb63ba33c8b600354: Deleting log segment in path: /tmp/dist-test-taskw4CMs_/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515443298492-22369-0/minicluster-data/ts-0-root/wals/26c4eeba0f794819b78cd3eb793375f5/wal-000000033 (ops 158-162)
I20260812 06:17:33.415894 22866 log.cc:1079] T 26c4eeba0f794819b78cd3eb793375f5 P 1f78d8c8394c4abcb63ba33c8b600354: Deleting log segment in path: /tmp/dist-test-taskw4CMs_/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515443298492-22369-0/minicluster-data/ts-0-root/wals/26c4eeba0f794819b78cd3eb793375f5/wal-000000034 (ops 163-166)
I20260812 06:17:33.415918 22866 log.cc:1079] T 26c4eeba0f794819b78cd3eb793375f5 P 1f78d8c8394c4abcb63ba33c8b600354: Deleting log segment in path: /tmp/dist-test-taskw4CMs_/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515443298492-22369-0/minicluster-data/ts-0-root/wals/26c4eeba0f794819b78cd3eb793375f5/wal-000000035 (ops 167-171)
I20260812 06:17:33.415946 22866 log.cc:1079] T 26c4eeba0f794819b78cd3eb793375f5 P 1f78d8c8394c4abcb63ba33c8b600354: Deleting log segment in path: /tmp/dist-test-taskw4CMs_/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515443298492-22369-0/minicluster-data/ts-0-root/wals/26c4eeba0f794819b78cd3eb793375f5/wal-000000036 (ops 172-176)
I20260812 06:17:33.415977 22866 log.cc:1079] T 26c4eeba0f794819b78cd3eb793375f5 P 1f78d8c8394c4abcb63ba33c8b600354: Deleting log segment in path: /tmp/dist-test-taskw4CMs_/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515443298492-22369-0/minicluster-data/ts-0-root/wals/26c4eeba0f794819b78cd3eb793375f5/wal-000000037 (ops 177-181)
I20260812 06:17:33.416007 22866 log.cc:1079] T 26c4eeba0f794819b78cd3eb793375f5 P 1f78d8c8394c4abcb63ba33c8b600354: Deleting log segment in path: /tmp/dist-test-taskw4CMs_/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515443298492-22369-0/minicluster-data/ts-0-root/wals/26c4eeba0f794819b78cd3eb793375f5/wal-000000038 (ops 182-186)
I20260812 06:17:33.416035 22866 log.cc:1079] T 26c4eeba0f794819b78cd3eb793375f5 P 1f78d8c8394c4abcb63ba33c8b600354: Deleting log segment in path: /tmp/dist-test-taskw4CMs_/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515443298492-22369-0/minicluster-data/ts-0-root/wals/26c4eeba0f794819b78cd3eb793375f5/wal-000000039 (ops 187-191)
I20260812 06:17:33.443179 22866 maintenance_manager.cc:643] P 1f78d8c8394c4abcb63ba33c8b600354: LogGCOp(26c4eeba0f794819b78cd3eb793375f5) complete. Timing: real 0.028s	user 0.000s	sys 0.027s Metrics: {}
I20260812 06:17:33.443536 22965 maintenance_manager.cc:419] P 1f78d8c8394c4abcb63ba33c8b600354: Scheduling FlushDeltaMemStoresOp(26c4eeba0f794819b78cd3eb793375f5): perf score=3.181125
I20260812 06:17:33.459786 22866 maintenance_manager.cc:643] P 1f78d8c8394c4abcb63ba33c8b600354: FlushDeltaMemStoresOp(26c4eeba0f794819b78cd3eb793375f5) complete. Timing: real 0.016s	user 0.002s	sys 0.008s Metrics: {"bytes_written":4512902,"delete_count":0,"lbm_write_time_us":4011,"lbm_writes_lt_1ms":113,"reinsert_count":0,"update_count":550}
I20260812 06:17:33.460196 22965 maintenance_manager.cc:419] P 1f78d8c8394c4abcb63ba33c8b600354: Scheduling FlushDeltaMemStoresOp(26c4eeba0f794819b78cd3eb793375f5): perf score=2.188937
I20260812 06:17:33.468904 22866 maintenance_manager.cc:643] P 1f78d8c8394c4abcb63ba33c8b600354: FlushDeltaMemStoresOp(26c4eeba0f794819b78cd3eb793375f5) complete. Timing: real 0.009s	user 0.007s	sys 0.000s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3121,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:17:33.469344 22965 maintenance_manager.cc:419] P 1f78d8c8394c4abcb63ba33c8b600354: Scheduling UndoDeltaBlockGCOp(26c4eeba0f794819b78cd3eb793375f5): 447 bytes on disk
I20260812 06:17:33.469723 22866 maintenance_manager.cc:643] P 1f78d8c8394c4abcb63ba33c8b600354: UndoDeltaBlockGCOp(26c4eeba0f794819b78cd3eb793375f5) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":47,"lbm_reads_lt_1ms":4}
I20260812 06:17:33.470194 22965 maintenance_manager.cc:419] P 1f78d8c8394c4abcb63ba33c8b600354: Scheduling MajorDeltaCompactionOp(26c4eeba0f794819b78cd3eb793375f5): perf score=1.000000
I20260812 06:17:33.589530 22369 heavy-update-compaction-itest.cc:229] Time spent updating: real 4.707s	user 1.695s	sys 0.217s
I20260812 06:17:33.676193 22866 maintenance_manager.cc:643] P 1f78d8c8394c4abcb63ba33c8b600354: MajorDeltaCompactionOp(26c4eeba0f794819b78cd3eb793375f5) complete. Timing: real 0.206s	user 0.123s	sys 0.083s Metrics: {"cfile_cache_miss":734,"cfile_cache_miss_bytes":33020734,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":239,"lbm_read_time_us":14232,"lbm_reads_lt_1ms":770,"lbm_write_time_us":32625,"lbm_writes_lt_1ms":743,"mutex_wait_us":20,"peak_mem_usage":87969044,"reinsert_count":0,"spinlock_wait_cycles":13952,"thread_start_us":72,"threads_started":1,"update_count":3500}
I20260812 06:17:33.679255 22965 maintenance_manager.cc:419] P 1f78d8c8394c4abcb63ba33c8b600354: Scheduling FlushDeltaMemStoresOp(26c4eeba0f794819b78cd3eb793375f5): perf score=10.126437
I20260812 06:17:33.688544 22369 heavy-update-compaction-itest.cc:265] Time spent scanning: real 0.099s	user 0.001s	sys 0.000s
I20260812 06:17:33.688967 22369 tablet_server.cc:179] TabletServer@127.21.216.65:0 shutting down...
I20260812 06:17:33.709064 22866 maintenance_manager.cc:643] P 1f78d8c8394c4abcb63ba33c8b600354: FlushDeltaMemStoresOp(26c4eeba0f794819b78cd3eb793375f5) complete. Timing: real 0.030s	user 0.006s	sys 0.022s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":12936,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:17:33.709532 22369 ts_tablet_manager.cc:1507] Shutting down tablet manager...
I20260812 06:17:33.709723 22369 tablet_replica.cc:333] T 26c4eeba0f794819b78cd3eb793375f5 P 1f78d8c8394c4abcb63ba33c8b600354: stopping tablet replica
I20260812 06:17:33.709838 22369 raft_consensus.cc:2243] T 26c4eeba0f794819b78cd3eb793375f5 P 1f78d8c8394c4abcb63ba33c8b600354 [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:17:33.710006 22369 raft_consensus.cc:2272] T 26c4eeba0f794819b78cd3eb793375f5 P 1f78d8c8394c4abcb63ba33c8b600354 [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:17:33.723153 22369 tablet_server.cc:196] TabletServer@127.21.216.65:0 shutdown complete.
I20260812 06:17:33.732899 22369 master.cc:562] Master@127.21.216.126:40629 shutting down...
I20260812 06:17:33.735909 22369 raft_consensus.cc:2243] T 00000000000000000000000000000000 P 5c0dedbace1a410791024610a89e5b7d [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:17:33.736047 22369 raft_consensus.cc:2272] T 00000000000000000000000000000000 P 5c0dedbace1a410791024610a89e5b7d [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:17:33.736095 22369 tablet_replica.cc:333] T 00000000000000000000000000000000 P 5c0dedbace1a410791024610a89e5b7d: stopping tablet replica
I20260812 06:17:33.748034 22369 master.cc:584] Master@127.21.216.126:40629 shutdown complete.
[       OK ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/1 (5121 ms)
[----------] 2 tests from EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy (10514 ms total)

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