[==========] Running 2 tests from 1 test suite.
[----------] Global test environment set-up.
[----------] 2 tests from EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy
[ RUN      ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/0
WARNING: Logging before InitGoogleLogging() is written to STDERR
I20260812 06:19:47.862282 26400 internal_mini_cluster.cc:156] Creating distributed mini masters. Addrs: 127.25.200.62:42959
I20260812 06:19:47.863602 26400 env_posix.cc:2285] Not raising this process' open files per process limit of 1048576; it is already as high as it can go
I20260812 06:19:47.864418 26400 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:19:47.871568 26407 instance_detector.cc:116] could not retrieve AWS instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:19:47.871574 26414 instance_detector.cc:116] could not retrieve OpenStack instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:19:47.871803 26400 server_base.cc:1061] running on GCE node
W20260812 06:19:47.871920 26412 instance_detector.cc:116] could not retrieve Azure instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:19:47.872493 26400 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:19:47.872634 26400 system_unsync_time.cc:38] NTP support is disabled. Clock error bounds will not be accurate. This configuration is not suitable for distributed clusters.
I20260812 06:19:47.872694 26400 hybrid_clock.cc:648] HybridClock initialized: now 1786515587872691 us; error 0 us; skew 500 ppm
I20260812 06:19:47.874707 26400 webserver.cc:533] Webserver started at http://127.25.200.62:42463/ using document root <none> and password file <none>
I20260812 06:19:47.875280 26400 fs_manager.cc:362] Metadata directory not provided
I20260812 06:19:47.875368 26400 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:19:47.875636 26400 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:19:47.877413 26400 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-tasknV3hQW/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515587845435-26400-0/minicluster-data/master-0-root/instance:
uuid: "741473cdfd7243bc96504804a3ab0b18"
format_stamp: "Formatted at 2026-08-12 06:19:47 on dist-test-slave-tk9z"
I20260812 06:19:47.881036 26400 fs_manager.cc:696] Time spent creating directory manager: real 0.003s	user 0.002s	sys 0.003s
I20260812 06:19:47.883284 26422 log_block_manager.cc:4127] Time spent loading block containers with low live blocks: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:19:47.884390 26400 fs_manager.cc:730] Time spent opening block manager: real 0.002s	user 0.003s	sys 0.000s
I20260812 06:19:47.884543 26400 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-tasknV3hQW/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515587845435-26400-0/minicluster-data/master-0-root
uuid: "741473cdfd7243bc96504804a3ab0b18"
format_stamp: "Formatted at 2026-08-12 06:19:47 on dist-test-slave-tk9z"
I20260812 06:19:47.884660 26400 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-tasknV3hQW/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515587845435-26400-0/minicluster-data/master-0-root
metadata directory: /tmp/dist-test-tasknV3hQW/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515587845435-26400-0/minicluster-data/master-0-root
1 data directories: /tmp/dist-test-tasknV3hQW/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515587845435-26400-0/minicluster-data/master-0-root/data
Total live blocks: 0
Total live bytes: 0
Total live bytes (after alignment): 0
Total number of LBM containers: 0 (0 full)
Did not check for missing blocks
Did not check for orphaned blocks
Total full LBM containers with extra space: 0 (0 repaired)
Total full LBM container extra space in bytes: 0 (0 repaired)
Total incomplete LBM containers: 0 (0 repaired)
Total LBM partial records: 0 (0 repaired)
Total corrupted LBM metadata records in RocksDB: 0 (0 repaired)
I20260812 06:19:47.894152 26400 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:19:47.894810 26400 env_posix.cc:2285] Not raising this process' running threads per effective uid limit of 18446744073709551615; it is already as high as it can go
I20260812 06:19:47.894992 26400 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:19:47.902315 26400 rpc_server.cc:307] RPC server started. Bound to: 127.25.200.62:42959
I20260812 06:19:47.902349 26506 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.25.200.62:42959 every 8 connection(s)
I20260812 06:19:47.904618 26508 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet 00000000000000000000000000000000. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:19:47.910211 26508 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P 741473cdfd7243bc96504804a3ab0b18: Bootstrap starting.
I20260812 06:19:47.912667 26508 tablet_bootstrap.cc:654] T 00000000000000000000000000000000 P 741473cdfd7243bc96504804a3ab0b18: Neither blocks nor log segments found. Creating new log.
I20260812 06:19:47.913663 26508 log.cc:826] T 00000000000000000000000000000000 P 741473cdfd7243bc96504804a3ab0b18: Log is configured to *not* fsync() on all Append() calls
I20260812 06:19:47.915412 26508 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P 741473cdfd7243bc96504804a3ab0b18: No bootstrap required, opened a new log
I20260812 06:19:47.918138 26508 raft_consensus.cc:359] T 00000000000000000000000000000000 P 741473cdfd7243bc96504804a3ab0b18 [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "741473cdfd7243bc96504804a3ab0b18" member_type: VOTER }
I20260812 06:19:47.918309 26508 raft_consensus.cc:385] T 00000000000000000000000000000000 P 741473cdfd7243bc96504804a3ab0b18 [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:19:47.918426 26508 raft_consensus.cc:740] T 00000000000000000000000000000000 P 741473cdfd7243bc96504804a3ab0b18 [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: 741473cdfd7243bc96504804a3ab0b18, State: Initialized, Role: FOLLOWER
I20260812 06:19:47.918983 26508 consensus_queue.cc:260] T 00000000000000000000000000000000 P 741473cdfd7243bc96504804a3ab0b18 [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: "741473cdfd7243bc96504804a3ab0b18" member_type: VOTER }
I20260812 06:19:47.919116 26508 raft_consensus.cc:399] T 00000000000000000000000000000000 P 741473cdfd7243bc96504804a3ab0b18 [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:19:47.919162 26508 raft_consensus.cc:493] T 00000000000000000000000000000000 P 741473cdfd7243bc96504804a3ab0b18 [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:19:47.919250 26508 raft_consensus.cc:3060] T 00000000000000000000000000000000 P 741473cdfd7243bc96504804a3ab0b18 [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:19:47.919991 26508 raft_consensus.cc:515] T 00000000000000000000000000000000 P 741473cdfd7243bc96504804a3ab0b18 [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "741473cdfd7243bc96504804a3ab0b18" member_type: VOTER }
I20260812 06:19:47.920377 26508 leader_election.cc:304] T 00000000000000000000000000000000 P 741473cdfd7243bc96504804a3ab0b18 [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: 741473cdfd7243bc96504804a3ab0b18; no voters: 
I20260812 06:19:47.920692 26508 leader_election.cc:290] T 00000000000000000000000000000000 P 741473cdfd7243bc96504804a3ab0b18 [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:19:47.920903 26511 raft_consensus.cc:2804] T 00000000000000000000000000000000 P 741473cdfd7243bc96504804a3ab0b18 [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:19:47.921208 26511 raft_consensus.cc:697] T 00000000000000000000000000000000 P 741473cdfd7243bc96504804a3ab0b18 [term 1 LEADER]: Becoming Leader. State: Replica: 741473cdfd7243bc96504804a3ab0b18, State: Running, Role: LEADER
I20260812 06:19:47.921654 26511 consensus_queue.cc:237] T 00000000000000000000000000000000 P 741473cdfd7243bc96504804a3ab0b18 [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: "741473cdfd7243bc96504804a3ab0b18" member_type: VOTER }
I20260812 06:19:47.921739 26508 sys_catalog.cc:565] T 00000000000000000000000000000000 P 741473cdfd7243bc96504804a3ab0b18 [sys.catalog]: configured and running, proceeding with master startup.
I20260812 06:19:47.923811 26513 sys_catalog.cc:455] T 00000000000000000000000000000000 P 741473cdfd7243bc96504804a3ab0b18 [sys.catalog]: SysCatalogTable state changed. Reason: New leader 741473cdfd7243bc96504804a3ab0b18. Latest consensus state: current_term: 1 leader_uuid: "741473cdfd7243bc96504804a3ab0b18" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "741473cdfd7243bc96504804a3ab0b18" member_type: VOTER } }
I20260812 06:19:47.923943 26513 sys_catalog.cc:458] T 00000000000000000000000000000000 P 741473cdfd7243bc96504804a3ab0b18 [sys.catalog]: This master's current role is: LEADER
I20260812 06:19:47.924180 26400 internal_mini_cluster.cc:184] Waiting to initialize catalog manager on master 0
I20260812 06:19:47.924280 26512 sys_catalog.cc:455] T 00000000000000000000000000000000 P 741473cdfd7243bc96504804a3ab0b18 [sys.catalog]: SysCatalogTable state changed. Reason: RaftConsensus started. Latest consensus state: current_term: 1 leader_uuid: "741473cdfd7243bc96504804a3ab0b18" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "741473cdfd7243bc96504804a3ab0b18" member_type: VOTER } }
I20260812 06:19:47.924364 26512 sys_catalog.cc:458] T 00000000000000000000000000000000 P 741473cdfd7243bc96504804a3ab0b18 [sys.catalog]: This master's current role is: LEADER
W20260812 06:19:47.926254 26527 catalog_manager.cc:1594] T 00000000000000000000000000000000 P 741473cdfd7243bc96504804a3ab0b18: loading cluster ID for follower catalog manager: Not found: cluster ID entry not found
W20260812 06:19:47.926340 26527 catalog_manager.cc:883] Not found: cluster ID entry not found: failed to prepare follower catalog manager, will retry
I20260812 06:19:47.926424 26526 catalog_manager.cc:1511] Loading table and tablet metadata into memory...
I20260812 06:19:47.927275 26526 catalog_manager.cc:1520] Initializing Kudu cluster ID...
I20260812 06:19:47.932215 26526 catalog_manager.cc:1383] Generated new cluster ID: 78a12db68f1243ff80a3d249bca84502
I20260812 06:19:47.932289 26526 catalog_manager.cc:1531] Initializing Kudu internal certificate authority...
I20260812 06:19:47.972432 26526 catalog_manager.cc:1406] Generated new certificate authority record
I20260812 06:19:47.973682 26526 catalog_manager.cc:1540] Loading token signing keys...
I20260812 06:19:47.982407 26526 catalog_manager.cc:6092] T 00000000000000000000000000000000 P 741473cdfd7243bc96504804a3ab0b18: Generated new TSK 0
I20260812 06:19:47.983181 26526 catalog_manager.cc:1550] Initializing in-progress tserver states...
I20260812 06:19:47.989107 26400 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:19:47.991916 26535 instance_detector.cc:116] could not retrieve OpenStack instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:19:47.991941 26533 instance_detector.cc:116] could not retrieve Azure instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:19:47.992038 26532 instance_detector.cc:116] could not retrieve AWS instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:19:47.992297 26400 server_base.cc:1061] running on GCE node
I20260812 06:19:47.992499 26400 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:19:47.992550 26400 system_unsync_time.cc:38] NTP support is disabled. Clock error bounds will not be accurate. This configuration is not suitable for distributed clusters.
I20260812 06:19:47.992568 26400 hybrid_clock.cc:648] HybridClock initialized: now 1786515587992567 us; error 0 us; skew 500 ppm
I20260812 06:19:47.993624 26400 webserver.cc:533] Webserver started at http://127.25.200.1:33323/ using document root <none> and password file <none>
I20260812 06:19:47.993810 26400 fs_manager.cc:362] Metadata directory not provided
I20260812 06:19:47.993868 26400 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:19:47.993966 26400 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:19:47.994428 26400 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-tasknV3hQW/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515587845435-26400-0/minicluster-data/ts-0-root/instance:
uuid: "5e3e1b6bdff44ca1b1ce4d4f3caee836"
format_stamp: "Formatted at 2026-08-12 06:19:47 on dist-test-slave-tk9z"
I20260812 06:19:47.996009 26400 fs_manager.cc:696] Time spent creating directory manager: real 0.001s	user 0.000s	sys 0.001s
I20260812 06:19:47.997069 26541 log_block_manager.cc:4127] Time spent loading block containers with low live blocks: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:19:47.997349 26400 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.000s	sys 0.001s
I20260812 06:19:47.997426 26400 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-tasknV3hQW/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515587845435-26400-0/minicluster-data/ts-0-root
uuid: "5e3e1b6bdff44ca1b1ce4d4f3caee836"
format_stamp: "Formatted at 2026-08-12 06:19:47 on dist-test-slave-tk9z"
I20260812 06:19:47.997532 26400 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-tasknV3hQW/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515587845435-26400-0/minicluster-data/ts-0-root
metadata directory: /tmp/dist-test-tasknV3hQW/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515587845435-26400-0/minicluster-data/ts-0-root
1 data directories: /tmp/dist-test-tasknV3hQW/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515587845435-26400-0/minicluster-data/ts-0-root/data
Total live blocks: 0
Total live bytes: 0
Total live bytes (after alignment): 0
Total number of LBM containers: 0 (0 full)
Did not check for missing blocks
Did not check for orphaned blocks
Total full LBM containers with extra space: 0 (0 repaired)
Total full LBM container extra space in bytes: 0 (0 repaired)
Total incomplete LBM containers: 0 (0 repaired)
Total LBM partial records: 0 (0 repaired)
Total corrupted LBM metadata records in RocksDB: 0 (0 repaired)
I20260812 06:19:48.005738 26400 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:19:48.006194 26400 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:19:48.006780 26400 txn_system_client.cc:432] TxnSystemClient initialization is disabled...
I20260812 06:19:48.007707 26400 ts_tablet_manager.cc:585] Loaded tablet metadata (0 total tablets, 0 live tablets)
I20260812 06:19:48.007761 26400 ts_tablet_manager.cc:531] Time spent load tablet metadata: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:19:48.007834 26400 ts_tablet_manager.cc:616] Registered 0 tablets
I20260812 06:19:48.007874 26400 ts_tablet_manager.cc:595] Time spent register tablets: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:19:48.014804 26400 rpc_server.cc:307] RPC server started. Bound to: 127.25.200.1:40871
I20260812 06:19:48.014861 26638 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.25.200.1:40871 every 8 connection(s)
I20260812 06:19:48.026129 26641 heartbeater.cc:344] Connected to a master server at 127.25.200.62:42959
I20260812 06:19:48.026444 26641 heartbeater.cc:461] Registering TS with master...
I20260812 06:19:48.026966 26641 heartbeater.cc:507] Master 127.25.200.62:42959 requested a full tablet report, sending...
I20260812 06:19:48.028548 26452 ts_manager.cc:194] Registered new tserver with Master: 5e3e1b6bdff44ca1b1ce4d4f3caee836 (127.25.200.1:40871)
I20260812 06:19:48.028707 26400 internal_mini_cluster.cc:371] 1 TS(s) registered with all masters after 0.013244714s
I20260812 06:19:48.030094 26452 master_service.cc:502] Signed X509 certificate for tserver {username='slave'} at 127.0.0.1:44708
I20260812 06:19:48.039585 26452 catalog_manager.cc:2283] Servicing CreateTable request from {username='slave'} at 127.0.0.1:44710:
name: "heavy-update-compaction-test"
schema {
  columns {
    name: "key"
    type: INT64
    is_key: true
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_a"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_b"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_c"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_d"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_e"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
}
num_replicas: 1
split_rows_range_bounds {
}
partition_schema {
  range_schema {
  }
}
I20260812 06:19:48.055485 26588 tablet_service.cc:1511] Processing CreateTablet for tablet 72df756055d54e458a7766f4cfbb4333 (DEFAULT_TABLE table=heavy-update-compaction-test [id=b20a0828708b46b6b070ae190fba7fc6]), partition=
I20260812 06:19:48.055948 26588 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet 72df756055d54e458a7766f4cfbb4333. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:19:48.058156 26658 tablet_bootstrap.cc:492] T 72df756055d54e458a7766f4cfbb4333 P 5e3e1b6bdff44ca1b1ce4d4f3caee836: Bootstrap starting.
I20260812 06:19:48.059226 26658 tablet_bootstrap.cc:654] T 72df756055d54e458a7766f4cfbb4333 P 5e3e1b6bdff44ca1b1ce4d4f3caee836: Neither blocks nor log segments found. Creating new log.
I20260812 06:19:48.060372 26658 tablet_bootstrap.cc:492] T 72df756055d54e458a7766f4cfbb4333 P 5e3e1b6bdff44ca1b1ce4d4f3caee836: No bootstrap required, opened a new log
I20260812 06:19:48.060458 26658 ts_tablet_manager.cc:1403] T 72df756055d54e458a7766f4cfbb4333 P 5e3e1b6bdff44ca1b1ce4d4f3caee836: Time spent bootstrapping tablet: real 0.002s	user 0.002s	sys 0.000s
I20260812 06:19:48.060912 26658 raft_consensus.cc:359] T 72df756055d54e458a7766f4cfbb4333 P 5e3e1b6bdff44ca1b1ce4d4f3caee836 [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "5e3e1b6bdff44ca1b1ce4d4f3caee836" member_type: VOTER last_known_addr { host: "127.25.200.1" port: 40871 } }
I20260812 06:19:48.061015 26658 raft_consensus.cc:385] T 72df756055d54e458a7766f4cfbb4333 P 5e3e1b6bdff44ca1b1ce4d4f3caee836 [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:19:48.061039 26658 raft_consensus.cc:740] T 72df756055d54e458a7766f4cfbb4333 P 5e3e1b6bdff44ca1b1ce4d4f3caee836 [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: 5e3e1b6bdff44ca1b1ce4d4f3caee836, State: Initialized, Role: FOLLOWER
I20260812 06:19:48.061228 26658 consensus_queue.cc:260] T 72df756055d54e458a7766f4cfbb4333 P 5e3e1b6bdff44ca1b1ce4d4f3caee836 [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: "5e3e1b6bdff44ca1b1ce4d4f3caee836" member_type: VOTER last_known_addr { host: "127.25.200.1" port: 40871 } }
I20260812 06:19:48.061302 26658 raft_consensus.cc:399] T 72df756055d54e458a7766f4cfbb4333 P 5e3e1b6bdff44ca1b1ce4d4f3caee836 [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:19:48.061353 26658 raft_consensus.cc:493] T 72df756055d54e458a7766f4cfbb4333 P 5e3e1b6bdff44ca1b1ce4d4f3caee836 [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:19:48.061411 26658 raft_consensus.cc:3060] T 72df756055d54e458a7766f4cfbb4333 P 5e3e1b6bdff44ca1b1ce4d4f3caee836 [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:19:48.062227 26658 raft_consensus.cc:515] T 72df756055d54e458a7766f4cfbb4333 P 5e3e1b6bdff44ca1b1ce4d4f3caee836 [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "5e3e1b6bdff44ca1b1ce4d4f3caee836" member_type: VOTER last_known_addr { host: "127.25.200.1" port: 40871 } }
I20260812 06:19:48.062423 26658 leader_election.cc:304] T 72df756055d54e458a7766f4cfbb4333 P 5e3e1b6bdff44ca1b1ce4d4f3caee836 [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: 5e3e1b6bdff44ca1b1ce4d4f3caee836; no voters: 
I20260812 06:19:48.062681 26658 leader_election.cc:290] T 72df756055d54e458a7766f4cfbb4333 P 5e3e1b6bdff44ca1b1ce4d4f3caee836 [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:19:48.062783 26661 raft_consensus.cc:2804] T 72df756055d54e458a7766f4cfbb4333 P 5e3e1b6bdff44ca1b1ce4d4f3caee836 [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:19:48.063087 26661 raft_consensus.cc:697] T 72df756055d54e458a7766f4cfbb4333 P 5e3e1b6bdff44ca1b1ce4d4f3caee836 [term 1 LEADER]: Becoming Leader. State: Replica: 5e3e1b6bdff44ca1b1ce4d4f3caee836, State: Running, Role: LEADER
I20260812 06:19:48.063117 26658 ts_tablet_manager.cc:1434] T 72df756055d54e458a7766f4cfbb4333 P 5e3e1b6bdff44ca1b1ce4d4f3caee836: Time spent starting tablet: real 0.003s	user 0.003s	sys 0.000s
I20260812 06:19:48.063694 26641 heartbeater.cc:499] Master 127.25.200.62:42959 was elected leader, sending a full tablet report...
I20260812 06:19:48.063509 26661 consensus_queue.cc:237] T 72df756055d54e458a7766f4cfbb4333 P 5e3e1b6bdff44ca1b1ce4d4f3caee836 [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: "5e3e1b6bdff44ca1b1ce4d4f3caee836" member_type: VOTER last_known_addr { host: "127.25.200.1" port: 40871 } }
I20260812 06:19:48.066951 26452 catalog_manager.cc:5719] T 72df756055d54e458a7766f4cfbb4333 P 5e3e1b6bdff44ca1b1ce4d4f3caee836 reported cstate change: term changed from 0 to 1, leader changed from <none> to 5e3e1b6bdff44ca1b1ce4d4f3caee836 (127.25.200.1). New cstate: current_term: 1 leader_uuid: "5e3e1b6bdff44ca1b1ce4d4f3caee836" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "5e3e1b6bdff44ca1b1ce4d4f3caee836" member_type: VOTER last_known_addr { host: "127.25.200.1" port: 40871 } health_report { overall_health: HEALTHY } } }
I20260812 06:19:48.136806 26400 heavy-update-compaction-itest.cc:215] Time spent inserting: real 0.061s	user 0.022s	sys 0.006s
I20260812 06:19:48.266024 26643 maintenance_manager.cc:419] P 5e3e1b6bdff44ca1b1ce4d4f3caee836: Scheduling FlushMRSOp(72df756055d54e458a7766f4cfbb4333): perf score=15.086190
I20260812 06:19:48.428607 26553 maintenance_manager.cc:643] P 5e3e1b6bdff44ca1b1ce4d4f3caee836: FlushMRSOp(72df756055d54e458a7766f4cfbb4333) complete. Timing: real 0.162s	user 0.132s	sys 0.024s Metrics: {"bytes_written":12307490,"cfile_init":1,"compiler_manager_pool.queue_time_us":254,"delete_count":0,"dirs.queue_time_us":63,"dirs.run_cpu_time_us":215,"dirs.run_wall_time_us":769,"drs_written":1,"lbm_read_time_us":51,"lbm_reads_lt_1ms":4,"lbm_write_time_us":39877,"lbm_writes_lt_1ms":657,"peak_mem_usage":0,"reinsert_count":0,"rows_written":103,"thread_start_us":126,"threads_started":1,"update_count":1500}
I20260812 06:19:48.429863 26643 maintenance_manager.cc:419] P 5e3e1b6bdff44ca1b1ce4d4f3caee836: Scheduling LogGCOp(72df756055d54e458a7766f4cfbb4333): free 11976772 bytes of WAL
I20260812 06:19:48.430181 26553 log_reader.cc:385] T 72df756055d54e458a7766f4cfbb4333: removed 1 log segments from log reader
I20260812 06:19:48.430264 26553 log.cc:1079] T 72df756055d54e458a7766f4cfbb4333 P 5e3e1b6bdff44ca1b1ce4d4f3caee836: Deleting log segment in path: /tmp/dist-test-tasknV3hQW/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515587845435-26400-0/minicluster-data/ts-0-root/wals/72df756055d54e458a7766f4cfbb4333/wal-000000001 (ops 1-6)
I20260812 06:19:48.433598 26553 maintenance_manager.cc:643] P 5e3e1b6bdff44ca1b1ce4d4f3caee836: LogGCOp(72df756055d54e458a7766f4cfbb4333) complete. Timing: real 0.004s	user 0.000s	sys 0.000s Metrics: {}
I20260812 06:19:48.434034 26643 maintenance_manager.cc:419] P 5e3e1b6bdff44ca1b1ce4d4f3caee836: Scheduling FlushDeltaMemStoresOp(72df756055d54e458a7766f4cfbb4333): perf score=2.188937
I20260812 06:19:48.451712 26553 maintenance_manager.cc:643] P 5e3e1b6bdff44ca1b1ce4d4f3caee836: FlushDeltaMemStoresOp(72df756055d54e458a7766f4cfbb4333) complete. Timing: real 0.017s	user 0.014s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5947,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:48.452260 26643 maintenance_manager.cc:419] P 5e3e1b6bdff44ca1b1ce4d4f3caee836: Scheduling UndoDeltaBlockGCOp(72df756055d54e458a7766f4cfbb4333): 12308959 bytes on disk
I20260812 06:19:48.452909 26553 maintenance_manager.cc:643] P 5e3e1b6bdff44ca1b1ce4d4f3caee836: UndoDeltaBlockGCOp(72df756055d54e458a7766f4cfbb4333) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":69,"lbm_reads_lt_1ms":4}
I20260812 06:19:48.453393 26643 maintenance_manager.cc:419] P 5e3e1b6bdff44ca1b1ce4d4f3caee836: Scheduling MajorDeltaCompactionOp(72df756055d54e458a7766f4cfbb4333): perf score=1.000000
I20260812 06:19:48.586807 26553 maintenance_manager.cc:643] P 5e3e1b6bdff44ca1b1ce4d4f3caee836: MajorDeltaCompactionOp(72df756055d54e458a7766f4cfbb4333) complete. Timing: real 0.133s	user 0.095s	sys 0.038s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20631312,"cfile_init":7,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":900,"lbm_read_time_us":7175,"lbm_reads_lt_1ms":460,"lbm_write_time_us":25670,"lbm_writes_lt_1ms":443,"mutex_wait_us":3,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":2304,"thread_start_us":306,"threads_started":5,"update_count":2000}
I20260812 06:19:48.587411 26643 maintenance_manager.cc:419] P 5e3e1b6bdff44ca1b1ce4d4f3caee836: Scheduling FlushDeltaMemStoresOp(72df756055d54e458a7766f4cfbb4333): perf score=10.126437
I20260812 06:19:48.632855 26553 maintenance_manager.cc:643] P 5e3e1b6bdff44ca1b1ce4d4f3caee836: FlushDeltaMemStoresOp(72df756055d54e458a7766f4cfbb4333) complete. Timing: real 0.045s	user 0.017s	sys 0.020s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":17400,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:19:48.633369 26643 maintenance_manager.cc:419] P 5e3e1b6bdff44ca1b1ce4d4f3caee836: Scheduling FlushDeltaMemStoresOp(72df756055d54e458a7766f4cfbb4333): perf score=2.188937
I20260812 06:19:48.644392 26553 maintenance_manager.cc:643] P 5e3e1b6bdff44ca1b1ce4d4f3caee836: FlushDeltaMemStoresOp(72df756055d54e458a7766f4cfbb4333) complete. Timing: real 0.011s	user 0.009s	sys 0.000s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":3944,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:48.645098 26643 maintenance_manager.cc:419] P 5e3e1b6bdff44ca1b1ce4d4f3caee836: Scheduling MajorDeltaCompactionOp(72df756055d54e458a7766f4cfbb4333): perf score=1.000000
I20260812 06:19:48.776186 26553 maintenance_manager.cc:643] P 5e3e1b6bdff44ca1b1ce4d4f3caee836: MajorDeltaCompactionOp(72df756055d54e458a7766f4cfbb4333) complete. Timing: real 0.131s	user 0.085s	sys 0.042s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20631311,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":684,"lbm_read_time_us":9751,"lbm_reads_lt_1ms":472,"lbm_write_time_us":24933,"lbm_writes_lt_1ms":443,"mutex_wait_us":302,"peak_mem_usage":50689328,"reinsert_count":0,"update_count":2000}
I20260812 06:19:48.776723 26643 maintenance_manager.cc:419] P 5e3e1b6bdff44ca1b1ce4d4f3caee836: Scheduling FlushDeltaMemStoresOp(72df756055d54e458a7766f4cfbb4333): perf score=10.126437
I20260812 06:19:48.828020 26553 maintenance_manager.cc:643] P 5e3e1b6bdff44ca1b1ce4d4f3caee836: FlushDeltaMemStoresOp(72df756055d54e458a7766f4cfbb4333) complete. Timing: real 0.051s	user 0.024s	sys 0.016s Metrics: {"bytes_written":12307491,"delete_count":0,"lbm_write_time_us":19649,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":302,"reinsert_count":0,"update_count":1500}
I20260812 06:19:48.828547 26643 maintenance_manager.cc:419] P 5e3e1b6bdff44ca1b1ce4d4f3caee836: Scheduling FlushDeltaMemStoresOp(72df756055d54e458a7766f4cfbb4333): perf score=2.188937
I20260812 06:19:48.841818 26553 maintenance_manager.cc:643] P 5e3e1b6bdff44ca1b1ce4d4f3caee836: FlushDeltaMemStoresOp(72df756055d54e458a7766f4cfbb4333) complete. Timing: real 0.013s	user 0.007s	sys 0.003s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4327,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:48.842528 26643 maintenance_manager.cc:419] P 5e3e1b6bdff44ca1b1ce4d4f3caee836: Scheduling MajorDeltaCompactionOp(72df756055d54e458a7766f4cfbb4333): perf score=1.000000
I20260812 06:19:48.977157 26553 maintenance_manager.cc:643] P 5e3e1b6bdff44ca1b1ce4d4f3caee836: MajorDeltaCompactionOp(72df756055d54e458a7766f4cfbb4333) complete. Timing: real 0.134s	user 0.113s	sys 0.021s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20631313,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":459,"lbm_read_time_us":8046,"lbm_reads_lt_1ms":472,"lbm_write_time_us":27966,"lbm_writes_lt_1ms":443,"mutex_wait_us":45,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":21376,"update_count":2000}
I20260812 06:19:48.977855 26643 maintenance_manager.cc:419] P 5e3e1b6bdff44ca1b1ce4d4f3caee836: Scheduling FlushDeltaMemStoresOp(72df756055d54e458a7766f4cfbb4333): perf score=10.126437
I20260812 06:19:49.030504 26553 maintenance_manager.cc:643] P 5e3e1b6bdff44ca1b1ce4d4f3caee836: FlushDeltaMemStoresOp(72df756055d54e458a7766f4cfbb4333) complete. Timing: real 0.052s	user 0.027s	sys 0.016s Metrics: {"bytes_written":12307492,"delete_count":0,"lbm_write_time_us":15465,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:19:49.031077 26643 maintenance_manager.cc:419] P 5e3e1b6bdff44ca1b1ce4d4f3caee836: Scheduling FlushDeltaMemStoresOp(72df756055d54e458a7766f4cfbb4333): perf score=2.188937
I20260812 06:19:49.041970 26553 maintenance_manager.cc:643] P 5e3e1b6bdff44ca1b1ce4d4f3caee836: FlushDeltaMemStoresOp(72df756055d54e458a7766f4cfbb4333) complete. Timing: real 0.011s	user 0.009s	sys 0.000s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4068,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:49.042527 26643 maintenance_manager.cc:419] P 5e3e1b6bdff44ca1b1ce4d4f3caee836: Scheduling MajorDeltaCompactionOp(72df756055d54e458a7766f4cfbb4333): perf score=1.000000
I20260812 06:19:49.192648 26553 maintenance_manager.cc:643] P 5e3e1b6bdff44ca1b1ce4d4f3caee836: MajorDeltaCompactionOp(72df756055d54e458a7766f4cfbb4333) complete. Timing: real 0.150s	user 0.109s	sys 0.039s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20631313,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":202,"lbm_read_time_us":10339,"lbm_reads_lt_1ms":472,"lbm_write_time_us":26792,"lbm_writes_lt_1ms":443,"mutex_wait_us":27,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":8064,"update_count":2000}
I20260812 06:19:49.193423 26643 maintenance_manager.cc:419] P 5e3e1b6bdff44ca1b1ce4d4f3caee836: Scheduling FlushDeltaMemStoresOp(72df756055d54e458a7766f4cfbb4333): perf score=7.149875
I20260812 06:19:49.224783 26553 maintenance_manager.cc:643] P 5e3e1b6bdff44ca1b1ce4d4f3caee836: FlushDeltaMemStoresOp(72df756055d54e458a7766f4cfbb4333) complete. Timing: real 0.031s	user 0.012s	sys 0.017s Metrics: {"bytes_written":8615323,"delete_count":0,"lbm_write_time_us":13503,"lbm_writes_lt_1ms":213,"reinsert_count":0,"update_count":1050}
I20260812 06:19:49.225353 26643 maintenance_manager.cc:419] P 5e3e1b6bdff44ca1b1ce4d4f3caee836: Scheduling FlushDeltaMemStoresOp(72df756055d54e458a7766f4cfbb4333): perf score=2.188937
I20260812 06:19:49.239184 26553 maintenance_manager.cc:643] P 5e3e1b6bdff44ca1b1ce4d4f3caee836: FlushDeltaMemStoresOp(72df756055d54e458a7766f4cfbb4333) complete. Timing: real 0.014s	user 0.013s	sys 0.000s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":5169,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:19:49.239830 26643 maintenance_manager.cc:419] P 5e3e1b6bdff44ca1b1ce4d4f3caee836: Scheduling MajorDeltaCompactionOp(72df756055d54e458a7766f4cfbb4333): perf score=1.000000
I20260812 06:19:49.355736 26553 maintenance_manager.cc:643] P 5e3e1b6bdff44ca1b1ce4d4f3caee836: MajorDeltaCompactionOp(72df756055d54e458a7766f4cfbb4333) complete. Timing: real 0.116s	user 0.100s	sys 0.016s Metrics: {"cfile_cache_miss":332,"cfile_cache_miss_bytes":16528891,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":331,"lbm_read_time_us":8220,"lbm_reads_lt_1ms":372,"lbm_write_time_us":20077,"lbm_writes_lt_1ms":343,"mutex_wait_us":42,"peak_mem_usage":38262756,"reinsert_count":0,"spinlock_wait_cycles":10368,"update_count":1500}
I20260812 06:19:49.356527 26643 maintenance_manager.cc:419] P 5e3e1b6bdff44ca1b1ce4d4f3caee836: Scheduling FlushDeltaMemStoresOp(72df756055d54e458a7766f4cfbb4333): perf score=6.157687
I20260812 06:19:49.392305 26553 maintenance_manager.cc:643] P 5e3e1b6bdff44ca1b1ce4d4f3caee836: FlushDeltaMemStoresOp(72df756055d54e458a7766f4cfbb4333) complete. Timing: real 0.034s	user 0.017s	sys 0.009s Metrics: {"bytes_written":8533273,"delete_count":0,"lbm_write_time_us":11638,"lbm_writes_lt_1ms":211,"reinsert_count":0,"update_count":1040}
I20260812 06:19:49.392850 26643 maintenance_manager.cc:419] P 5e3e1b6bdff44ca1b1ce4d4f3caee836: Scheduling FlushDeltaMemStoresOp(72df756055d54e458a7766f4cfbb4333): perf score=2.188937
I20260812 06:19:49.407714 26553 maintenance_manager.cc:643] P 5e3e1b6bdff44ca1b1ce4d4f3caee836: FlushDeltaMemStoresOp(72df756055d54e458a7766f4cfbb4333) complete. Timing: real 0.015s	user 0.008s	sys 0.006s Metrics: {"bytes_written":3774459,"delete_count":0,"lbm_write_time_us":5508,"lbm_writes_lt_1ms":95,"reinsert_count":0,"update_count":460}
I20260812 06:19:49.408324 26643 maintenance_manager.cc:419] P 5e3e1b6bdff44ca1b1ce4d4f3caee836: Scheduling MajorDeltaCompactionOp(72df756055d54e458a7766f4cfbb4333): perf score=1.000000
I20260812 06:19:49.529444 26553 maintenance_manager.cc:643] P 5e3e1b6bdff44ca1b1ce4d4f3caee836: MajorDeltaCompactionOp(72df756055d54e458a7766f4cfbb4333) complete. Timing: real 0.121s	user 0.081s	sys 0.025s Metrics: {"cfile_cache_miss":332,"cfile_cache_miss_bytes":16528895,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":130,"lbm_read_time_us":7887,"lbm_reads_lt_1ms":372,"lbm_write_time_us":18928,"lbm_writes_lt_1ms":343,"mutex_wait_us":25,"peak_mem_usage":38262756,"reinsert_count":0,"spinlock_wait_cycles":1920,"update_count":1500}
I20260812 06:19:49.530066 26643 maintenance_manager.cc:419] P 5e3e1b6bdff44ca1b1ce4d4f3caee836: Scheduling FlushDeltaMemStoresOp(72df756055d54e458a7766f4cfbb4333): perf score=10.126437
I20260812 06:19:49.575609 26553 maintenance_manager.cc:643] P 5e3e1b6bdff44ca1b1ce4d4f3caee836: FlushDeltaMemStoresOp(72df756055d54e458a7766f4cfbb4333) complete. Timing: real 0.045s	user 0.017s	sys 0.019s Metrics: {"bytes_written":12307489,"delete_count":0,"lbm_write_time_us":16295,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:19:49.576179 26643 maintenance_manager.cc:419] P 5e3e1b6bdff44ca1b1ce4d4f3caee836: Scheduling FlushDeltaMemStoresOp(72df756055d54e458a7766f4cfbb4333): perf score=2.188937
I20260812 06:19:49.587121 26553 maintenance_manager.cc:643] P 5e3e1b6bdff44ca1b1ce4d4f3caee836: FlushDeltaMemStoresOp(72df756055d54e458a7766f4cfbb4333) complete. Timing: real 0.011s	user 0.006s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3959,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:49.587867 26643 maintenance_manager.cc:419] P 5e3e1b6bdff44ca1b1ce4d4f3caee836: Scheduling MajorDeltaCompactionOp(72df756055d54e458a7766f4cfbb4333): perf score=1.000000
I20260812 06:19:49.719839 26553 maintenance_manager.cc:643] P 5e3e1b6bdff44ca1b1ce4d4f3caee836: MajorDeltaCompactionOp(72df756055d54e458a7766f4cfbb4333) complete. Timing: real 0.132s	user 0.111s	sys 0.020s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20631311,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":370,"lbm_read_time_us":8740,"lbm_reads_lt_1ms":472,"lbm_write_time_us":25177,"lbm_writes_lt_1ms":443,"mutex_wait_us":61,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":1280,"update_count":2000}
I20260812 06:19:49.720388 26643 maintenance_manager.cc:419] P 5e3e1b6bdff44ca1b1ce4d4f3caee836: Scheduling FlushDeltaMemStoresOp(72df756055d54e458a7766f4cfbb4333): perf score=10.126437
I20260812 06:19:49.764472 26553 maintenance_manager.cc:643] P 5e3e1b6bdff44ca1b1ce4d4f3caee836: FlushDeltaMemStoresOp(72df756055d54e458a7766f4cfbb4333) complete. Timing: real 0.044s	user 0.020s	sys 0.017s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":17156,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:19:49.764962 26643 maintenance_manager.cc:419] P 5e3e1b6bdff44ca1b1ce4d4f3caee836: Scheduling FlushDeltaMemStoresOp(72df756055d54e458a7766f4cfbb4333): perf score=2.188937
I20260812 06:19:49.776125 26553 maintenance_manager.cc:643] P 5e3e1b6bdff44ca1b1ce4d4f3caee836: FlushDeltaMemStoresOp(72df756055d54e458a7766f4cfbb4333) complete. Timing: real 0.011s	user 0.005s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4139,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:49.776875 26643 maintenance_manager.cc:419] P 5e3e1b6bdff44ca1b1ce4d4f3caee836: Scheduling FlushMRSOp(72df756055d54e458a7766f4cfbb4333): perf score=1.000000
I20260812 06:19:49.809546 26553 maintenance_manager.cc:643] P 5e3e1b6bdff44ca1b1ce4d4f3caee836: FlushMRSOp(72df756055d54e458a7766f4cfbb4333) complete. Timing: real 0.032s	user 0.028s	sys 0.003s Metrics: {"bytes_written":1234474,"cfile_init":1,"dirs.queue_time_us":56,"dirs.run_cpu_time_us":227,"dirs.run_wall_time_us":1477,"drs_written":1,"lbm_read_time_us":38,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1672,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":30}
I20260812 06:19:49.810475 26643 maintenance_manager.cc:419] P 5e3e1b6bdff44ca1b1ce4d4f3caee836: Scheduling LogGCOp(72df756055d54e458a7766f4cfbb4333): free 121006377 bytes of WAL
I20260812 06:19:49.810704 26553 log_reader.cc:385] T 72df756055d54e458a7766f4cfbb4333: removed 12 log segments from log reader
I20260812 06:19:49.810748 26553 log.cc:1079] T 72df756055d54e458a7766f4cfbb4333 P 5e3e1b6bdff44ca1b1ce4d4f3caee836: Deleting log segment in path: /tmp/dist-test-tasknV3hQW/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515587845435-26400-0/minicluster-data/ts-0-root/wals/72df756055d54e458a7766f4cfbb4333/wal-000000002 (ops 7-11)
I20260812 06:19:49.810777 26553 log.cc:1079] T 72df756055d54e458a7766f4cfbb4333 P 5e3e1b6bdff44ca1b1ce4d4f3caee836: Deleting log segment in path: /tmp/dist-test-tasknV3hQW/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515587845435-26400-0/minicluster-data/ts-0-root/wals/72df756055d54e458a7766f4cfbb4333/wal-000000003 (ops 12-16)
I20260812 06:19:49.810840 26553 log.cc:1079] T 72df756055d54e458a7766f4cfbb4333 P 5e3e1b6bdff44ca1b1ce4d4f3caee836: Deleting log segment in path: /tmp/dist-test-tasknV3hQW/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515587845435-26400-0/minicluster-data/ts-0-root/wals/72df756055d54e458a7766f4cfbb4333/wal-000000004 (ops 17-21)
I20260812 06:19:49.810873 26553 log.cc:1079] T 72df756055d54e458a7766f4cfbb4333 P 5e3e1b6bdff44ca1b1ce4d4f3caee836: Deleting log segment in path: /tmp/dist-test-tasknV3hQW/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515587845435-26400-0/minicluster-data/ts-0-root/wals/72df756055d54e458a7766f4cfbb4333/wal-000000005 (ops 22-26)
I20260812 06:19:49.810912 26553 log.cc:1079] T 72df756055d54e458a7766f4cfbb4333 P 5e3e1b6bdff44ca1b1ce4d4f3caee836: Deleting log segment in path: /tmp/dist-test-tasknV3hQW/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515587845435-26400-0/minicluster-data/ts-0-root/wals/72df756055d54e458a7766f4cfbb4333/wal-000000006 (ops 27-30)
I20260812 06:19:49.810956 26553 log.cc:1079] T 72df756055d54e458a7766f4cfbb4333 P 5e3e1b6bdff44ca1b1ce4d4f3caee836: Deleting log segment in path: /tmp/dist-test-tasknV3hQW/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515587845435-26400-0/minicluster-data/ts-0-root/wals/72df756055d54e458a7766f4cfbb4333/wal-000000007 (ops 31-35)
I20260812 06:19:49.810994 26553 log.cc:1079] T 72df756055d54e458a7766f4cfbb4333 P 5e3e1b6bdff44ca1b1ce4d4f3caee836: Deleting log segment in path: /tmp/dist-test-tasknV3hQW/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515587845435-26400-0/minicluster-data/ts-0-root/wals/72df756055d54e458a7766f4cfbb4333/wal-000000008 (ops 36-40)
I20260812 06:19:49.811033 26553 log.cc:1079] T 72df756055d54e458a7766f4cfbb4333 P 5e3e1b6bdff44ca1b1ce4d4f3caee836: Deleting log segment in path: /tmp/dist-test-tasknV3hQW/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515587845435-26400-0/minicluster-data/ts-0-root/wals/72df756055d54e458a7766f4cfbb4333/wal-000000009 (ops 41-45)
I20260812 06:19:49.811072 26553 log.cc:1079] T 72df756055d54e458a7766f4cfbb4333 P 5e3e1b6bdff44ca1b1ce4d4f3caee836: Deleting log segment in path: /tmp/dist-test-tasknV3hQW/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515587845435-26400-0/minicluster-data/ts-0-root/wals/72df756055d54e458a7766f4cfbb4333/wal-000000010 (ops 46-50)
I20260812 06:19:49.811110 26553 log.cc:1079] T 72df756055d54e458a7766f4cfbb4333 P 5e3e1b6bdff44ca1b1ce4d4f3caee836: Deleting log segment in path: /tmp/dist-test-tasknV3hQW/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515587845435-26400-0/minicluster-data/ts-0-root/wals/72df756055d54e458a7766f4cfbb4333/wal-000000011 (ops 51-55)
I20260812 06:19:49.811148 26553 log.cc:1079] T 72df756055d54e458a7766f4cfbb4333 P 5e3e1b6bdff44ca1b1ce4d4f3caee836: Deleting log segment in path: /tmp/dist-test-tasknV3hQW/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515587845435-26400-0/minicluster-data/ts-0-root/wals/72df756055d54e458a7766f4cfbb4333/wal-000000012 (ops 56-60)
I20260812 06:19:49.811185 26553 log.cc:1079] T 72df756055d54e458a7766f4cfbb4333 P 5e3e1b6bdff44ca1b1ce4d4f3caee836: Deleting log segment in path: /tmp/dist-test-tasknV3hQW/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515587845435-26400-0/minicluster-data/ts-0-root/wals/72df756055d54e458a7766f4cfbb4333/wal-000000013 (ops 61-65)
I20260812 06:19:49.839787 26553 maintenance_manager.cc:643] P 5e3e1b6bdff44ca1b1ce4d4f3caee836: LogGCOp(72df756055d54e458a7766f4cfbb4333) complete. Timing: real 0.029s	user 0.000s	sys 0.028s Metrics: {}
I20260812 06:19:49.840227 26643 maintenance_manager.cc:419] P 5e3e1b6bdff44ca1b1ce4d4f3caee836: Scheduling FlushDeltaMemStoresOp(72df756055d54e458a7766f4cfbb4333): perf score=3.181125
I20260812 06:19:49.855844 26553 maintenance_manager.cc:643] P 5e3e1b6bdff44ca1b1ce4d4f3caee836: FlushDeltaMemStoresOp(72df756055d54e458a7766f4cfbb4333) complete. Timing: real 0.015s	user 0.010s	sys 0.004s Metrics: {"bytes_written":4512900,"delete_count":0,"lbm_write_time_us":6283,"lbm_writes_lt_1ms":113,"reinsert_count":0,"update_count":550}
I20260812 06:19:49.856355 26643 maintenance_manager.cc:419] P 5e3e1b6bdff44ca1b1ce4d4f3caee836: Scheduling LogGCOp(72df756055d54e458a7766f4cfbb4333): free 12017983 bytes of WAL
I20260812 06:19:49.856638 26553 log_reader.cc:385] T 72df756055d54e458a7766f4cfbb4333: removed 1 log segments from log reader
I20260812 06:19:49.856712 26553 log.cc:1079] T 72df756055d54e458a7766f4cfbb4333 P 5e3e1b6bdff44ca1b1ce4d4f3caee836: Deleting log segment in path: /tmp/dist-test-tasknV3hQW/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515587845435-26400-0/minicluster-data/ts-0-root/wals/72df756055d54e458a7766f4cfbb4333/wal-000000014 (ops 66-70)
I20260812 06:19:49.859212 26553 maintenance_manager.cc:643] P 5e3e1b6bdff44ca1b1ce4d4f3caee836: LogGCOp(72df756055d54e458a7766f4cfbb4333) complete. Timing: real 0.003s	user 0.000s	sys 0.002s Metrics: {}
I20260812 06:19:49.859599 26643 maintenance_manager.cc:419] P 5e3e1b6bdff44ca1b1ce4d4f3caee836: Scheduling UndoDeltaBlockGCOp(72df756055d54e458a7766f4cfbb4333): 472 bytes on disk
I20260812 06:19:49.860131 26553 maintenance_manager.cc:643] P 5e3e1b6bdff44ca1b1ce4d4f3caee836: UndoDeltaBlockGCOp(72df756055d54e458a7766f4cfbb4333) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":61,"lbm_reads_lt_1ms":4}
I20260812 06:19:49.860659 26643 maintenance_manager.cc:419] P 5e3e1b6bdff44ca1b1ce4d4f3caee836: Scheduling FlushDeltaMemStoresOp(72df756055d54e458a7766f4cfbb4333): perf score=2.188937
I20260812 06:19:49.870945 26553 maintenance_manager.cc:643] P 5e3e1b6bdff44ca1b1ce4d4f3caee836: FlushDeltaMemStoresOp(72df756055d54e458a7766f4cfbb4333) complete. Timing: real 0.010s	user 0.006s	sys 0.004s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3567,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:19:49.871395 26643 maintenance_manager.cc:419] P 5e3e1b6bdff44ca1b1ce4d4f3caee836: Scheduling MajorDeltaCompactionOp(72df756055d54e458a7766f4cfbb4333): perf score=1.000000
I20260812 06:19:50.039346 26553 maintenance_manager.cc:643] P 5e3e1b6bdff44ca1b1ce4d4f3caee836: MajorDeltaCompactionOp(72df756055d54e458a7766f4cfbb4333) complete. Timing: real 0.168s	user 0.112s	sys 0.056s Metrics: {"cfile_cache_miss":634,"cfile_cache_miss_bytes":28836361,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":756,"lbm_read_time_us":11803,"lbm_reads_lt_1ms":674,"lbm_write_time_us":34068,"lbm_writes_lt_1ms":643,"mutex_wait_us":321,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":20736,"thread_start_us":75,"threads_started":1,"update_count":3000}
I20260812 06:19:50.039852 26643 maintenance_manager.cc:419] P 5e3e1b6bdff44ca1b1ce4d4f3caee836: Scheduling FlushDeltaMemStoresOp(72df756055d54e458a7766f4cfbb4333): perf score=14.095187
I20260812 06:19:50.096711 26553 maintenance_manager.cc:643] P 5e3e1b6bdff44ca1b1ce4d4f3caee836: FlushDeltaMemStoresOp(72df756055d54e458a7766f4cfbb4333) complete. Timing: real 0.057s	user 0.038s	sys 0.016s Metrics: {"bytes_written":16409903,"delete_count":0,"lbm_write_time_us":25033,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:50.097384 26643 maintenance_manager.cc:419] P 5e3e1b6bdff44ca1b1ce4d4f3caee836: Scheduling FlushDeltaMemStoresOp(72df756055d54e458a7766f4cfbb4333): perf score=2.188937
I20260812 06:19:50.108121 26553 maintenance_manager.cc:643] P 5e3e1b6bdff44ca1b1ce4d4f3caee836: FlushDeltaMemStoresOp(72df756055d54e458a7766f4cfbb4333) complete. Timing: real 0.011s	user 0.005s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4180,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:50.108675 26643 maintenance_manager.cc:419] P 5e3e1b6bdff44ca1b1ce4d4f3caee836: Scheduling MajorDeltaCompactionOp(72df756055d54e458a7766f4cfbb4333): perf score=1.000000
I20260812 06:19:50.273677 26553 maintenance_manager.cc:643] P 5e3e1b6bdff44ca1b1ce4d4f3caee836: MajorDeltaCompactionOp(72df756055d54e458a7766f4cfbb4333) complete. Timing: real 0.165s	user 0.123s	sys 0.036s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24733725,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":401,"lbm_read_time_us":11160,"lbm_reads_lt_1ms":572,"lbm_write_time_us":32728,"lbm_writes_lt_1ms":543,"mutex_wait_us":204,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":11648,"update_count":2500}
I20260812 06:19:50.274345 26643 maintenance_manager.cc:419] P 5e3e1b6bdff44ca1b1ce4d4f3caee836: Scheduling FlushDeltaMemStoresOp(72df756055d54e458a7766f4cfbb4333): perf score=11.118625
I20260812 06:19:50.318871 26553 maintenance_manager.cc:643] P 5e3e1b6bdff44ca1b1ce4d4f3caee836: FlushDeltaMemStoresOp(72df756055d54e458a7766f4cfbb4333) complete. Timing: real 0.044s	user 0.028s	sys 0.012s Metrics: {"bytes_written":12717734,"delete_count":0,"lbm_write_time_us":16285,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:19:50.319535 26643 maintenance_manager.cc:419] P 5e3e1b6bdff44ca1b1ce4d4f3caee836: Scheduling FlushDeltaMemStoresOp(72df756055d54e458a7766f4cfbb4333): perf score=2.188937
I20260812 06:19:50.331137 26553 maintenance_manager.cc:643] P 5e3e1b6bdff44ca1b1ce4d4f3caee836: FlushDeltaMemStoresOp(72df756055d54e458a7766f4cfbb4333) complete. Timing: real 0.011s	user 0.006s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4308,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:50.331646 26643 maintenance_manager.cc:419] P 5e3e1b6bdff44ca1b1ce4d4f3caee836: Scheduling FlushDeltaMemStoresOp(72df756055d54e458a7766f4cfbb4333): perf score=2.188937
I20260812 06:19:50.344975 26553 maintenance_manager.cc:643] P 5e3e1b6bdff44ca1b1ce4d4f3caee836: FlushDeltaMemStoresOp(72df756055d54e458a7766f4cfbb4333) complete. Timing: real 0.013s	user 0.011s	sys 0.000s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":5029,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:19:50.345468 26643 maintenance_manager.cc:419] P 5e3e1b6bdff44ca1b1ce4d4f3caee836: Scheduling MajorDeltaCompactionOp(72df756055d54e458a7766f4cfbb4333): perf score=1.000000
I20260812 06:19:50.494930 26553 maintenance_manager.cc:643] P 5e3e1b6bdff44ca1b1ce4d4f3caee836: MajorDeltaCompactionOp(72df756055d54e458a7766f4cfbb4333) complete. Timing: real 0.149s	user 0.107s	sys 0.036s Metrics: {"cfile_cache_miss":533,"cfile_cache_miss_bytes":24733833,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":1201,"lbm_read_time_us":10388,"lbm_reads_lt_1ms":573,"lbm_write_time_us":28325,"lbm_writes_lt_1ms":543,"mutex_wait_us":323,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":24064,"update_count":2500}
I20260812 06:19:50.495800 26643 maintenance_manager.cc:419] P 5e3e1b6bdff44ca1b1ce4d4f3caee836: Scheduling FlushDeltaMemStoresOp(72df756055d54e458a7766f4cfbb4333): perf score=11.118625
I20260812 06:19:50.532222 26553 maintenance_manager.cc:643] P 5e3e1b6bdff44ca1b1ce4d4f3caee836: FlushDeltaMemStoresOp(72df756055d54e458a7766f4cfbb4333) complete. Timing: real 0.036s	user 0.018s	sys 0.016s Metrics: {"bytes_written":12717734,"delete_count":0,"lbm_write_time_us":15317,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:19:50.532972 26643 maintenance_manager.cc:419] P 5e3e1b6bdff44ca1b1ce4d4f3caee836: Scheduling FlushDeltaMemStoresOp(72df756055d54e458a7766f4cfbb4333): perf score=2.188937
I20260812 06:19:50.553375 26553 maintenance_manager.cc:643] P 5e3e1b6bdff44ca1b1ce4d4f3caee836: FlushDeltaMemStoresOp(72df756055d54e458a7766f4cfbb4333) complete. Timing: real 0.020s	user 0.000s	sys 0.011s Metrics: {"bytes_written":3856509,"delete_count":0,"lbm_write_time_us":5094,"lbm_writes_lt_1ms":97,"reinsert_count":0,"update_count":470}
I20260812 06:19:50.553833 26643 maintenance_manager.cc:419] P 5e3e1b6bdff44ca1b1ce4d4f3caee836: Scheduling FlushDeltaMemStoresOp(72df756055d54e458a7766f4cfbb4333): perf score=2.188937
I20260812 06:19:50.564038 26553 maintenance_manager.cc:643] P 5e3e1b6bdff44ca1b1ce4d4f3caee836: FlushDeltaMemStoresOp(72df756055d54e458a7766f4cfbb4333) complete. Timing: real 0.010s	user 0.004s	sys 0.004s Metrics: {"bytes_written":3938559,"delete_count":0,"lbm_write_time_us":3877,"lbm_writes_lt_1ms":99,"reinsert_count":0,"update_count":480}
I20260812 06:19:50.564465 26643 maintenance_manager.cc:419] P 5e3e1b6bdff44ca1b1ce4d4f3caee836: Scheduling MajorDeltaCompactionOp(72df756055d54e458a7766f4cfbb4333): perf score=1.000000
I20260812 06:19:50.715632 26553 maintenance_manager.cc:643] P 5e3e1b6bdff44ca1b1ce4d4f3caee836: MajorDeltaCompactionOp(72df756055d54e458a7766f4cfbb4333) complete. Timing: real 0.151s	user 0.123s	sys 0.028s Metrics: {"cfile_cache_miss":533,"cfile_cache_miss_bytes":24733837,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":158,"lbm_read_time_us":10005,"lbm_reads_lt_1ms":573,"lbm_write_time_us":31790,"lbm_writes_lt_1ms":543,"mutex_wait_us":25,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":34688,"update_count":2500}
I20260812 06:19:50.716257 26643 maintenance_manager.cc:419] P 5e3e1b6bdff44ca1b1ce4d4f3caee836: Scheduling FlushDeltaMemStoresOp(72df756055d54e458a7766f4cfbb4333): perf score=11.118625
I20260812 06:19:50.752228 26553 maintenance_manager.cc:643] P 5e3e1b6bdff44ca1b1ce4d4f3caee836: FlushDeltaMemStoresOp(72df756055d54e458a7766f4cfbb4333) complete. Timing: real 0.036s	user 0.026s	sys 0.008s Metrics: {"bytes_written":12717735,"delete_count":0,"lbm_write_time_us":15387,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:19:50.753167 26643 maintenance_manager.cc:419] P 5e3e1b6bdff44ca1b1ce4d4f3caee836: Scheduling FlushDeltaMemStoresOp(72df756055d54e458a7766f4cfbb4333): perf score=2.188937
I20260812 06:19:50.770403 26553 maintenance_manager.cc:643] P 5e3e1b6bdff44ca1b1ce4d4f3caee836: FlushDeltaMemStoresOp(72df756055d54e458a7766f4cfbb4333) complete. Timing: real 0.017s	user 0.006s	sys 0.007s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":5988,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:19:50.770964 26643 maintenance_manager.cc:419] P 5e3e1b6bdff44ca1b1ce4d4f3caee836: Scheduling MajorDeltaCompactionOp(72df756055d54e458a7766f4cfbb4333): perf score=1.000000
I20260812 06:19:50.900009 26553 maintenance_manager.cc:643] P 5e3e1b6bdff44ca1b1ce4d4f3caee836: MajorDeltaCompactionOp(72df756055d54e458a7766f4cfbb4333) complete. Timing: real 0.129s	user 0.089s	sys 0.040s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20631303,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":306,"lbm_read_time_us":9208,"lbm_reads_lt_1ms":464,"lbm_write_time_us":26286,"lbm_writes_lt_1ms":443,"mutex_wait_us":41,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":78208,"update_count":2000}
I20260812 06:19:50.902805 26643 maintenance_manager.cc:419] P 5e3e1b6bdff44ca1b1ce4d4f3caee836: Scheduling FlushDeltaMemStoresOp(72df756055d54e458a7766f4cfbb4333): perf score=10.126437
I20260812 06:19:50.953094 26553 maintenance_manager.cc:643] P 5e3e1b6bdff44ca1b1ce4d4f3caee836: FlushDeltaMemStoresOp(72df756055d54e458a7766f4cfbb4333) complete. Timing: real 0.050s	user 0.020s	sys 0.028s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":17253,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:19:50.953881 26643 maintenance_manager.cc:419] P 5e3e1b6bdff44ca1b1ce4d4f3caee836: Scheduling FlushDeltaMemStoresOp(72df756055d54e458a7766f4cfbb4333): perf score=2.188937
I20260812 06:19:50.965966 26553 maintenance_manager.cc:643] P 5e3e1b6bdff44ca1b1ce4d4f3caee836: FlushDeltaMemStoresOp(72df756055d54e458a7766f4cfbb4333) complete. Timing: real 0.012s	user 0.010s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4748,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:50.966536 26643 maintenance_manager.cc:419] P 5e3e1b6bdff44ca1b1ce4d4f3caee836: Scheduling MajorDeltaCompactionOp(72df756055d54e458a7766f4cfbb4333): perf score=1.000000
I20260812 06:19:51.125083 26553 maintenance_manager.cc:643] P 5e3e1b6bdff44ca1b1ce4d4f3caee836: MajorDeltaCompactionOp(72df756055d54e458a7766f4cfbb4333) complete. Timing: real 0.158s	user 0.122s	sys 0.036s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20631312,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":1089,"lbm_read_time_us":12501,"lbm_reads_lt_1ms":472,"lbm_write_time_us":26532,"lbm_writes_lt_1ms":443,"mutex_wait_us":2,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":2688,"update_count":2000}
I20260812 06:19:51.125648 26643 maintenance_manager.cc:419] P 5e3e1b6bdff44ca1b1ce4d4f3caee836: Scheduling FlushDeltaMemStoresOp(72df756055d54e458a7766f4cfbb4333): perf score=10.126437
I20260812 06:19:51.175941 26553 maintenance_manager.cc:643] P 5e3e1b6bdff44ca1b1ce4d4f3caee836: FlushDeltaMemStoresOp(72df756055d54e458a7766f4cfbb4333) complete. Timing: real 0.050s	user 0.024s	sys 0.012s Metrics: {"bytes_written":12307493,"delete_count":0,"lbm_write_time_us":16740,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:19:51.176493 26643 maintenance_manager.cc:419] P 5e3e1b6bdff44ca1b1ce4d4f3caee836: Scheduling FlushDeltaMemStoresOp(72df756055d54e458a7766f4cfbb4333): perf score=2.188937
I20260812 06:19:51.187116 26553 maintenance_manager.cc:643] P 5e3e1b6bdff44ca1b1ce4d4f3caee836: FlushDeltaMemStoresOp(72df756055d54e458a7766f4cfbb4333) complete. Timing: real 0.010s	user 0.006s	sys 0.004s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":3995,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:51.187620 26643 maintenance_manager.cc:419] P 5e3e1b6bdff44ca1b1ce4d4f3caee836: Scheduling FlushMRSOp(72df756055d54e458a7766f4cfbb4333): perf score=1.000000
I20260812 06:19:51.220016 26553 maintenance_manager.cc:643] P 5e3e1b6bdff44ca1b1ce4d4f3caee836: FlushMRSOp(72df756055d54e458a7766f4cfbb4333) complete. Timing: real 0.032s	user 0.023s	sys 0.007s Metrics: {"bytes_written":1193509,"cfile_init":1,"dirs.queue_time_us":44,"dirs.run_cpu_time_us":257,"dirs.run_wall_time_us":1289,"drs_written":1,"lbm_read_time_us":49,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1526,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":29}
I20260812 06:19:51.221035 26643 maintenance_manager.cc:419] P 5e3e1b6bdff44ca1b1ce4d4f3caee836: Scheduling LogGCOp(72df756055d54e458a7766f4cfbb4333): free 112239324 bytes of WAL
I20260812 06:19:51.221320 26553 log_reader.cc:385] T 72df756055d54e458a7766f4cfbb4333: removed 11 log segments from log reader
I20260812 06:19:51.221401 26553 log.cc:1079] T 72df756055d54e458a7766f4cfbb4333 P 5e3e1b6bdff44ca1b1ce4d4f3caee836: Deleting log segment in path: /tmp/dist-test-tasknV3hQW/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515587845435-26400-0/minicluster-data/ts-0-root/wals/72df756055d54e458a7766f4cfbb4333/wal-000000015 (ops 71-75)
I20260812 06:19:51.221464 26553 log.cc:1079] T 72df756055d54e458a7766f4cfbb4333 P 5e3e1b6bdff44ca1b1ce4d4f3caee836: Deleting log segment in path: /tmp/dist-test-tasknV3hQW/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515587845435-26400-0/minicluster-data/ts-0-root/wals/72df756055d54e458a7766f4cfbb4333/wal-000000016 (ops 76-80)
I20260812 06:19:51.221527 26553 log.cc:1079] T 72df756055d54e458a7766f4cfbb4333 P 5e3e1b6bdff44ca1b1ce4d4f3caee836: Deleting log segment in path: /tmp/dist-test-tasknV3hQW/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515587845435-26400-0/minicluster-data/ts-0-root/wals/72df756055d54e458a7766f4cfbb4333/wal-000000017 (ops 81-84)
I20260812 06:19:51.221577 26553 log.cc:1079] T 72df756055d54e458a7766f4cfbb4333 P 5e3e1b6bdff44ca1b1ce4d4f3caee836: Deleting log segment in path: /tmp/dist-test-tasknV3hQW/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515587845435-26400-0/minicluster-data/ts-0-root/wals/72df756055d54e458a7766f4cfbb4333/wal-000000018 (ops 85-89)
I20260812 06:19:51.221621 26553 log.cc:1079] T 72df756055d54e458a7766f4cfbb4333 P 5e3e1b6bdff44ca1b1ce4d4f3caee836: Deleting log segment in path: /tmp/dist-test-tasknV3hQW/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515587845435-26400-0/minicluster-data/ts-0-root/wals/72df756055d54e458a7766f4cfbb4333/wal-000000019 (ops 90-94)
I20260812 06:19:51.221664 26553 log.cc:1079] T 72df756055d54e458a7766f4cfbb4333 P 5e3e1b6bdff44ca1b1ce4d4f3caee836: Deleting log segment in path: /tmp/dist-test-tasknV3hQW/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515587845435-26400-0/minicluster-data/ts-0-root/wals/72df756055d54e458a7766f4cfbb4333/wal-000000020 (ops 95-99)
I20260812 06:19:51.221707 26553 log.cc:1079] T 72df756055d54e458a7766f4cfbb4333 P 5e3e1b6bdff44ca1b1ce4d4f3caee836: Deleting log segment in path: /tmp/dist-test-tasknV3hQW/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515587845435-26400-0/minicluster-data/ts-0-root/wals/72df756055d54e458a7766f4cfbb4333/wal-000000021 (ops 100-104)
I20260812 06:19:51.221750 26553 log.cc:1079] T 72df756055d54e458a7766f4cfbb4333 P 5e3e1b6bdff44ca1b1ce4d4f3caee836: Deleting log segment in path: /tmp/dist-test-tasknV3hQW/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515587845435-26400-0/minicluster-data/ts-0-root/wals/72df756055d54e458a7766f4cfbb4333/wal-000000022 (ops 105-109)
I20260812 06:19:51.221812 26553 log.cc:1079] T 72df756055d54e458a7766f4cfbb4333 P 5e3e1b6bdff44ca1b1ce4d4f3caee836: Deleting log segment in path: /tmp/dist-test-tasknV3hQW/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515587845435-26400-0/minicluster-data/ts-0-root/wals/72df756055d54e458a7766f4cfbb4333/wal-000000023 (ops 110-114)
I20260812 06:19:51.221877 26553 log.cc:1079] T 72df756055d54e458a7766f4cfbb4333 P 5e3e1b6bdff44ca1b1ce4d4f3caee836: Deleting log segment in path: /tmp/dist-test-tasknV3hQW/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515587845435-26400-0/minicluster-data/ts-0-root/wals/72df756055d54e458a7766f4cfbb4333/wal-000000024 (ops 115-119)
I20260812 06:19:51.222050 26553 log.cc:1079] T 72df756055d54e458a7766f4cfbb4333 P 5e3e1b6bdff44ca1b1ce4d4f3caee836: Deleting log segment in path: /tmp/dist-test-tasknV3hQW/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515587845435-26400-0/minicluster-data/ts-0-root/wals/72df756055d54e458a7766f4cfbb4333/wal-000000025 (ops 120-124)
I20260812 06:19:51.251416 26553 maintenance_manager.cc:643] P 5e3e1b6bdff44ca1b1ce4d4f3caee836: LogGCOp(72df756055d54e458a7766f4cfbb4333) complete. Timing: real 0.030s	user 0.000s	sys 0.029s Metrics: {}
I20260812 06:19:51.251995 26643 maintenance_manager.cc:419] P 5e3e1b6bdff44ca1b1ce4d4f3caee836: Scheduling UndoDeltaBlockGCOp(72df756055d54e458a7766f4cfbb4333): 463 bytes on disk
I20260812 06:19:51.252677 26553 maintenance_manager.cc:643] P 5e3e1b6bdff44ca1b1ce4d4f3caee836: UndoDeltaBlockGCOp(72df756055d54e458a7766f4cfbb4333) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":75,"lbm_reads_lt_1ms":4}
I20260812 06:19:51.253412 26643 maintenance_manager.cc:419] P 5e3e1b6bdff44ca1b1ce4d4f3caee836: Scheduling FlushDeltaMemStoresOp(72df756055d54e458a7766f4cfbb4333): perf score=3.181125
I20260812 06:19:51.277060 26553 maintenance_manager.cc:643] P 5e3e1b6bdff44ca1b1ce4d4f3caee836: FlushDeltaMemStoresOp(72df756055d54e458a7766f4cfbb4333) complete. Timing: real 0.023s	user 0.006s	sys 0.014s Metrics: {"bytes_written":4512899,"delete_count":0,"lbm_write_time_us":4660,"lbm_writes_lt_1ms":113,"reinsert_count":0,"update_count":550}
I20260812 06:19:51.277653 26643 maintenance_manager.cc:419] P 5e3e1b6bdff44ca1b1ce4d4f3caee836: Scheduling FlushDeltaMemStoresOp(72df756055d54e458a7766f4cfbb4333): perf score=2.188937
I20260812 06:19:51.293251 26553 maintenance_manager.cc:643] P 5e3e1b6bdff44ca1b1ce4d4f3caee836: FlushDeltaMemStoresOp(72df756055d54e458a7766f4cfbb4333) complete. Timing: real 0.015s	user 0.013s	sys 0.000s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":5671,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:19:51.293885 26643 maintenance_manager.cc:419] P 5e3e1b6bdff44ca1b1ce4d4f3caee836: Scheduling MajorDeltaCompactionOp(72df756055d54e458a7766f4cfbb4333): perf score=1.000000
I20260812 06:19:51.501036 26553 maintenance_manager.cc:643] P 5e3e1b6bdff44ca1b1ce4d4f3caee836: MajorDeltaCompactionOp(72df756055d54e458a7766f4cfbb4333) complete. Timing: real 0.207s	user 0.153s	sys 0.051s Metrics: {"cfile_cache_miss":634,"cfile_cache_miss_bytes":28836362,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":549,"lbm_read_time_us":15046,"lbm_reads_lt_1ms":674,"lbm_write_time_us":36007,"lbm_writes_lt_1ms":643,"mutex_wait_us":51,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":768,"thread_start_us":80,"threads_started":1,"update_count":3000}
I20260812 06:19:51.501837 26643 maintenance_manager.cc:419] P 5e3e1b6bdff44ca1b1ce4d4f3caee836: Scheduling FlushDeltaMemStoresOp(72df756055d54e458a7766f4cfbb4333): perf score=14.095187
I20260812 06:19:51.561152 26553 maintenance_manager.cc:643] P 5e3e1b6bdff44ca1b1ce4d4f3caee836: FlushDeltaMemStoresOp(72df756055d54e458a7766f4cfbb4333) complete. Timing: real 0.059s	user 0.037s	sys 0.019s Metrics: {"bytes_written":16409900,"delete_count":0,"lbm_write_time_us":22234,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:51.561739 26643 maintenance_manager.cc:419] P 5e3e1b6bdff44ca1b1ce4d4f3caee836: Scheduling FlushDeltaMemStoresOp(72df756055d54e458a7766f4cfbb4333): perf score=2.188937
I20260812 06:19:51.573254 26553 maintenance_manager.cc:643] P 5e3e1b6bdff44ca1b1ce4d4f3caee836: FlushDeltaMemStoresOp(72df756055d54e458a7766f4cfbb4333) complete. Timing: real 0.011s	user 0.006s	sys 0.003s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4333,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:51.573830 26643 maintenance_manager.cc:419] P 5e3e1b6bdff44ca1b1ce4d4f3caee836: Scheduling MajorDeltaCompactionOp(72df756055d54e458a7766f4cfbb4333): perf score=1.000000
I20260812 06:19:51.745971 26553 maintenance_manager.cc:643] P 5e3e1b6bdff44ca1b1ce4d4f3caee836: MajorDeltaCompactionOp(72df756055d54e458a7766f4cfbb4333) complete. Timing: real 0.172s	user 0.105s	sys 0.064s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24733721,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":763,"lbm_read_time_us":12711,"lbm_reads_lt_1ms":572,"lbm_write_time_us":29444,"lbm_writes_lt_1ms":543,"mutex_wait_us":80,"peak_mem_usage":63115900,"reinsert_count":0,"update_count":2500}
I20260812 06:19:51.746711 26643 maintenance_manager.cc:419] P 5e3e1b6bdff44ca1b1ce4d4f3caee836: Scheduling FlushDeltaMemStoresOp(72df756055d54e458a7766f4cfbb4333): perf score=11.118625
I20260812 06:19:51.792763 26553 maintenance_manager.cc:643] P 5e3e1b6bdff44ca1b1ce4d4f3caee836: FlushDeltaMemStoresOp(72df756055d54e458a7766f4cfbb4333) complete. Timing: real 0.046s	user 0.029s	sys 0.009s Metrics: {"bytes_written":12717735,"delete_count":0,"lbm_write_time_us":17331,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:19:51.793365 26643 maintenance_manager.cc:419] P 5e3e1b6bdff44ca1b1ce4d4f3caee836: Scheduling FlushDeltaMemStoresOp(72df756055d54e458a7766f4cfbb4333): perf score=2.188937
I20260812 06:19:51.815704 26553 maintenance_manager.cc:643] P 5e3e1b6bdff44ca1b1ce4d4f3caee836: FlushDeltaMemStoresOp(72df756055d54e458a7766f4cfbb4333) complete. Timing: real 0.022s	user 0.013s	sys 0.007s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4590,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:51.816304 26643 maintenance_manager.cc:419] P 5e3e1b6bdff44ca1b1ce4d4f3caee836: Scheduling FlushDeltaMemStoresOp(72df756055d54e458a7766f4cfbb4333): perf score=2.188937
I20260812 06:19:51.826814 26553 maintenance_manager.cc:643] P 5e3e1b6bdff44ca1b1ce4d4f3caee836: FlushDeltaMemStoresOp(72df756055d54e458a7766f4cfbb4333) complete. Timing: real 0.010s	user 0.010s	sys 0.000s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3853,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:19:51.827383 26643 maintenance_manager.cc:419] P 5e3e1b6bdff44ca1b1ce4d4f3caee836: Scheduling MajorDeltaCompactionOp(72df756055d54e458a7766f4cfbb4333): perf score=1.000000
I20260812 06:19:51.999958 26553 maintenance_manager.cc:643] P 5e3e1b6bdff44ca1b1ce4d4f3caee836: MajorDeltaCompactionOp(72df756055d54e458a7766f4cfbb4333) complete. Timing: real 0.172s	user 0.124s	sys 0.048s Metrics: {"cfile_cache_miss":533,"cfile_cache_miss_bytes":24733834,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":1312,"lbm_read_time_us":13705,"lbm_reads_lt_1ms":573,"lbm_write_time_us":30965,"lbm_writes_lt_1ms":543,"mutex_wait_us":392,"peak_mem_usage":63115900,"reinsert_count":0,"update_count":2500}
I20260812 06:19:52.000674 26643 maintenance_manager.cc:419] P 5e3e1b6bdff44ca1b1ce4d4f3caee836: Scheduling FlushDeltaMemStoresOp(72df756055d54e458a7766f4cfbb4333): perf score=10.126437
I20260812 06:19:52.046993 26553 maintenance_manager.cc:643] P 5e3e1b6bdff44ca1b1ce4d4f3caee836: FlushDeltaMemStoresOp(72df756055d54e458a7766f4cfbb4333) complete. Timing: real 0.046s	user 0.024s	sys 0.012s Metrics: {"bytes_written":12307492,"delete_count":0,"lbm_write_time_us":15621,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:19:52.047861 26643 maintenance_manager.cc:419] P 5e3e1b6bdff44ca1b1ce4d4f3caee836: Scheduling FlushDeltaMemStoresOp(72df756055d54e458a7766f4cfbb4333): perf score=2.188937
I20260812 06:19:52.066998 26553 maintenance_manager.cc:643] P 5e3e1b6bdff44ca1b1ce4d4f3caee836: FlushDeltaMemStoresOp(72df756055d54e458a7766f4cfbb4333) complete. Timing: real 0.019s	user 0.014s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":7283,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:52.067481 26643 maintenance_manager.cc:419] P 5e3e1b6bdff44ca1b1ce4d4f3caee836: Scheduling MajorDeltaCompactionOp(72df756055d54e458a7766f4cfbb4333): perf score=1.000000
I20260812 06:19:52.208954 26553 maintenance_manager.cc:643] P 5e3e1b6bdff44ca1b1ce4d4f3caee836: MajorDeltaCompactionOp(72df756055d54e458a7766f4cfbb4333) complete. Timing: real 0.141s	user 0.110s	sys 0.029s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20631314,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":1036,"lbm_read_time_us":10308,"lbm_reads_lt_1ms":472,"lbm_write_time_us":25572,"lbm_writes_lt_1ms":443,"mutex_wait_us":24,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":16128,"update_count":2000}
I20260812 06:19:52.209928 26643 maintenance_manager.cc:419] P 5e3e1b6bdff44ca1b1ce4d4f3caee836: Scheduling FlushDeltaMemStoresOp(72df756055d54e458a7766f4cfbb4333): perf score=10.126437
I20260812 06:19:52.257635 26553 maintenance_manager.cc:643] P 5e3e1b6bdff44ca1b1ce4d4f3caee836: FlushDeltaMemStoresOp(72df756055d54e458a7766f4cfbb4333) complete. Timing: real 0.047s	user 0.030s	sys 0.011s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":19624,"lbm_writes_lt_1ms":303,"reinsert_count":0,"spinlock_wait_cycles":58624,"update_count":1500}
I20260812 06:19:52.258138 26643 maintenance_manager.cc:419] P 5e3e1b6bdff44ca1b1ce4d4f3caee836: Scheduling FlushDeltaMemStoresOp(72df756055d54e458a7766f4cfbb4333): perf score=2.188937
I20260812 06:19:52.269972 26553 maintenance_manager.cc:643] P 5e3e1b6bdff44ca1b1ce4d4f3caee836: FlushDeltaMemStoresOp(72df756055d54e458a7766f4cfbb4333) complete. Timing: real 0.012s	user 0.009s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4268,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:52.271063 26643 maintenance_manager.cc:419] P 5e3e1b6bdff44ca1b1ce4d4f3caee836: Scheduling MajorDeltaCompactionOp(72df756055d54e458a7766f4cfbb4333): perf score=1.000000
I20260812 06:19:52.402545 26553 maintenance_manager.cc:643] P 5e3e1b6bdff44ca1b1ce4d4f3caee836: MajorDeltaCompactionOp(72df756055d54e458a7766f4cfbb4333) complete. Timing: real 0.131s	user 0.117s	sys 0.013s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20631312,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":741,"lbm_read_time_us":9465,"lbm_reads_lt_1ms":472,"lbm_write_time_us":23942,"lbm_writes_lt_1ms":443,"mutex_wait_us":323,"peak_mem_usage":50689328,"reinsert_count":0,"update_count":2000}
I20260812 06:19:52.403312 26643 maintenance_manager.cc:419] P 5e3e1b6bdff44ca1b1ce4d4f3caee836: Scheduling FlushDeltaMemStoresOp(72df756055d54e458a7766f4cfbb4333): perf score=10.126437
I20260812 06:19:52.449034 26553 maintenance_manager.cc:643] P 5e3e1b6bdff44ca1b1ce4d4f3caee836: FlushDeltaMemStoresOp(72df756055d54e458a7766f4cfbb4333) complete. Timing: real 0.046s	user 0.030s	sys 0.008s Metrics: {"bytes_written":12307492,"delete_count":0,"lbm_write_time_us":18496,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:19:52.449594 26643 maintenance_manager.cc:419] P 5e3e1b6bdff44ca1b1ce4d4f3caee836: Scheduling FlushDeltaMemStoresOp(72df756055d54e458a7766f4cfbb4333): perf score=2.188937
I20260812 06:19:52.460391 26553 maintenance_manager.cc:643] P 5e3e1b6bdff44ca1b1ce4d4f3caee836: FlushDeltaMemStoresOp(72df756055d54e458a7766f4cfbb4333) complete. Timing: real 0.011s	user 0.006s	sys 0.003s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4133,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:52.461202 26643 maintenance_manager.cc:419] P 5e3e1b6bdff44ca1b1ce4d4f3caee836: Scheduling MajorDeltaCompactionOp(72df756055d54e458a7766f4cfbb4333): perf score=1.000000
I20260812 06:19:52.593588 26553 maintenance_manager.cc:643] P 5e3e1b6bdff44ca1b1ce4d4f3caee836: MajorDeltaCompactionOp(72df756055d54e458a7766f4cfbb4333) complete. Timing: real 0.132s	user 0.108s	sys 0.024s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20631314,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":1071,"lbm_read_time_us":10021,"lbm_reads_lt_1ms":472,"lbm_write_time_us":25670,"lbm_writes_lt_1ms":443,"mutex_wait_us":234,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":16512,"update_count":2000}
I20260812 06:19:52.594192 26643 maintenance_manager.cc:419] P 5e3e1b6bdff44ca1b1ce4d4f3caee836: Scheduling FlushDeltaMemStoresOp(72df756055d54e458a7766f4cfbb4333): perf score=10.126437
I20260812 06:19:52.637217 26553 maintenance_manager.cc:643] P 5e3e1b6bdff44ca1b1ce4d4f3caee836: FlushDeltaMemStoresOp(72df756055d54e458a7766f4cfbb4333) complete. Timing: real 0.043s	user 0.027s	sys 0.012s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":14571,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:19:52.637780 26643 maintenance_manager.cc:419] P 5e3e1b6bdff44ca1b1ce4d4f3caee836: Scheduling FlushDeltaMemStoresOp(72df756055d54e458a7766f4cfbb4333): perf score=1.000000
I20260812 06:19:52.646632 26553 maintenance_manager.cc:643] P 5e3e1b6bdff44ca1b1ce4d4f3caee836: FlushDeltaMemStoresOp(72df756055d54e458a7766f4cfbb4333) complete. Timing: real 0.009s	user 0.001s	sys 0.004s Metrics: {"bytes_written":1230906,"delete_count":0,"lbm_write_time_us":1253,"lbm_writes_lt_1ms":33,"reinsert_count":0,"update_count":150}
I20260812 06:19:52.647127 26643 maintenance_manager.cc:419] P 5e3e1b6bdff44ca1b1ce4d4f3caee836: Scheduling FlushDeltaMemStoresOp(72df756055d54e458a7766f4cfbb4333): perf score=1.196750
I20260812 06:19:52.655409 26553 maintenance_manager.cc:643] P 5e3e1b6bdff44ca1b1ce4d4f3caee836: FlushDeltaMemStoresOp(72df756055d54e458a7766f4cfbb4333) complete. Timing: real 0.008s	user 0.002s	sys 0.005s Metrics: {"bytes_written":2871905,"delete_count":0,"lbm_write_time_us":3026,"lbm_writes_lt_1ms":73,"reinsert_count":0,"update_count":350}
I20260812 06:19:52.655845 26643 maintenance_manager.cc:419] P 5e3e1b6bdff44ca1b1ce4d4f3caee836: Scheduling FlushMRSOp(72df756055d54e458a7766f4cfbb4333): perf score=1.000000
I20260812 06:19:52.697149 26553 maintenance_manager.cc:643] P 5e3e1b6bdff44ca1b1ce4d4f3caee836: FlushMRSOp(72df756055d54e458a7766f4cfbb4333) complete. Timing: real 0.041s	user 0.027s	sys 0.000s Metrics: {"bytes_written":1152510,"cfile_init":1,"dirs.queue_time_us":59,"dirs.run_cpu_time_us":179,"dirs.run_wall_time_us":1324,"drs_written":1,"lbm_read_time_us":44,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1414,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":28}
I20260812 06:19:52.697975 26643 maintenance_manager.cc:419] P 5e3e1b6bdff44ca1b1ce4d4f3caee836: Scheduling LogGCOp(72df756055d54e458a7766f4cfbb4333): free 121006674 bytes of WAL
I20260812 06:19:52.698232 26553 log_reader.cc:385] T 72df756055d54e458a7766f4cfbb4333: removed 12 log segments from log reader
I20260812 06:19:52.698287 26553 log.cc:1079] T 72df756055d54e458a7766f4cfbb4333 P 5e3e1b6bdff44ca1b1ce4d4f3caee836: Deleting log segment in path: /tmp/dist-test-tasknV3hQW/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515587845435-26400-0/minicluster-data/ts-0-root/wals/72df756055d54e458a7766f4cfbb4333/wal-000000026 (ops 125-129)
I20260812 06:19:52.698328 26553 log.cc:1079] T 72df756055d54e458a7766f4cfbb4333 P 5e3e1b6bdff44ca1b1ce4d4f3caee836: Deleting log segment in path: /tmp/dist-test-tasknV3hQW/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515587845435-26400-0/minicluster-data/ts-0-root/wals/72df756055d54e458a7766f4cfbb4333/wal-000000027 (ops 130-134)
I20260812 06:19:52.698364 26553 log.cc:1079] T 72df756055d54e458a7766f4cfbb4333 P 5e3e1b6bdff44ca1b1ce4d4f3caee836: Deleting log segment in path: /tmp/dist-test-tasknV3hQW/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515587845435-26400-0/minicluster-data/ts-0-root/wals/72df756055d54e458a7766f4cfbb4333/wal-000000028 (ops 135-139)
I20260812 06:19:52.698432 26553 log.cc:1079] T 72df756055d54e458a7766f4cfbb4333 P 5e3e1b6bdff44ca1b1ce4d4f3caee836: Deleting log segment in path: /tmp/dist-test-tasknV3hQW/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515587845435-26400-0/minicluster-data/ts-0-root/wals/72df756055d54e458a7766f4cfbb4333/wal-000000029 (ops 140-144)
I20260812 06:19:52.698454 26553 log.cc:1079] T 72df756055d54e458a7766f4cfbb4333 P 5e3e1b6bdff44ca1b1ce4d4f3caee836: Deleting log segment in path: /tmp/dist-test-tasknV3hQW/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515587845435-26400-0/minicluster-data/ts-0-root/wals/72df756055d54e458a7766f4cfbb4333/wal-000000030 (ops 145-149)
I20260812 06:19:52.698475 26553 log.cc:1079] T 72df756055d54e458a7766f4cfbb4333 P 5e3e1b6bdff44ca1b1ce4d4f3caee836: Deleting log segment in path: /tmp/dist-test-tasknV3hQW/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515587845435-26400-0/minicluster-data/ts-0-root/wals/72df756055d54e458a7766f4cfbb4333/wal-000000031 (ops 150-154)
I20260812 06:19:52.698505 26553 log.cc:1079] T 72df756055d54e458a7766f4cfbb4333 P 5e3e1b6bdff44ca1b1ce4d4f3caee836: Deleting log segment in path: /tmp/dist-test-tasknV3hQW/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515587845435-26400-0/minicluster-data/ts-0-root/wals/72df756055d54e458a7766f4cfbb4333/wal-000000032 (ops 155-159)
I20260812 06:19:52.698539 26553 log.cc:1079] T 72df756055d54e458a7766f4cfbb4333 P 5e3e1b6bdff44ca1b1ce4d4f3caee836: Deleting log segment in path: /tmp/dist-test-tasknV3hQW/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515587845435-26400-0/minicluster-data/ts-0-root/wals/72df756055d54e458a7766f4cfbb4333/wal-000000033 (ops 160-164)
I20260812 06:19:52.698570 26553 log.cc:1079] T 72df756055d54e458a7766f4cfbb4333 P 5e3e1b6bdff44ca1b1ce4d4f3caee836: Deleting log segment in path: /tmp/dist-test-tasknV3hQW/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515587845435-26400-0/minicluster-data/ts-0-root/wals/72df756055d54e458a7766f4cfbb4333/wal-000000034 (ops 165-168)
I20260812 06:19:52.698597 26553 log.cc:1079] T 72df756055d54e458a7766f4cfbb4333 P 5e3e1b6bdff44ca1b1ce4d4f3caee836: Deleting log segment in path: /tmp/dist-test-tasknV3hQW/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515587845435-26400-0/minicluster-data/ts-0-root/wals/72df756055d54e458a7766f4cfbb4333/wal-000000035 (ops 169-173)
I20260812 06:19:52.698626 26553 log.cc:1079] T 72df756055d54e458a7766f4cfbb4333 P 5e3e1b6bdff44ca1b1ce4d4f3caee836: Deleting log segment in path: /tmp/dist-test-tasknV3hQW/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515587845435-26400-0/minicluster-data/ts-0-root/wals/72df756055d54e458a7766f4cfbb4333/wal-000000036 (ops 174-178)
I20260812 06:19:52.698657 26553 log.cc:1079] T 72df756055d54e458a7766f4cfbb4333 P 5e3e1b6bdff44ca1b1ce4d4f3caee836: Deleting log segment in path: /tmp/dist-test-tasknV3hQW/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515587845435-26400-0/minicluster-data/ts-0-root/wals/72df756055d54e458a7766f4cfbb4333/wal-000000037 (ops 179-183)
I20260812 06:19:52.730230 26553 maintenance_manager.cc:643] P 5e3e1b6bdff44ca1b1ce4d4f3caee836: LogGCOp(72df756055d54e458a7766f4cfbb4333) complete. Timing: real 0.032s	user 0.008s	sys 0.024s Metrics: {}
I20260812 06:19:52.730700 26643 maintenance_manager.cc:419] P 5e3e1b6bdff44ca1b1ce4d4f3caee836: Scheduling FlushDeltaMemStoresOp(72df756055d54e458a7766f4cfbb4333): perf score=2.188937
I20260812 06:19:52.757562 26553 maintenance_manager.cc:643] P 5e3e1b6bdff44ca1b1ce4d4f3caee836: FlushDeltaMemStoresOp(72df756055d54e458a7766f4cfbb4333) complete. Timing: real 0.027s	user 0.006s	sys 0.006s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5271,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:52.758091 26643 maintenance_manager.cc:419] P 5e3e1b6bdff44ca1b1ce4d4f3caee836: Scheduling UndoDeltaBlockGCOp(72df756055d54e458a7766f4cfbb4333): 446 bytes on disk
I20260812 06:19:52.758556 26553 maintenance_manager.cc:643] P 5e3e1b6bdff44ca1b1ce4d4f3caee836: UndoDeltaBlockGCOp(72df756055d54e458a7766f4cfbb4333) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":84,"lbm_reads_lt_1ms":4}
I20260812 06:19:52.759084 26643 maintenance_manager.cc:419] P 5e3e1b6bdff44ca1b1ce4d4f3caee836: Scheduling FlushDeltaMemStoresOp(72df756055d54e458a7766f4cfbb4333): perf score=2.188937
I20260812 06:19:52.769794 26553 maintenance_manager.cc:643] P 5e3e1b6bdff44ca1b1ce4d4f3caee836: FlushDeltaMemStoresOp(72df756055d54e458a7766f4cfbb4333) complete. Timing: real 0.011s	user 0.006s	sys 0.003s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4053,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:52.770664 26643 maintenance_manager.cc:419] P 5e3e1b6bdff44ca1b1ce4d4f3caee836: Scheduling MajorDeltaCompactionOp(72df756055d54e458a7766f4cfbb4333): perf score=1.000000
I20260812 06:19:52.977043 26553 maintenance_manager.cc:643] P 5e3e1b6bdff44ca1b1ce4d4f3caee836: MajorDeltaCompactionOp(72df756055d54e458a7766f4cfbb4333) complete. Timing: real 0.206s	user 0.128s	sys 0.076s Metrics: {"cfile_cache_miss":635,"cfile_cache_miss_bytes":28836399,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":5,"delta_iterators_relevant":5,"dirs.queue_time_us":968,"lbm_read_time_us":13832,"lbm_reads_lt_1ms":675,"lbm_write_time_us":34938,"lbm_writes_lt_1ms":643,"mutex_wait_us":48,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":2048,"thread_start_us":101,"threads_started":1,"update_count":3000}
I20260812 06:19:52.977870 26643 maintenance_manager.cc:419] P 5e3e1b6bdff44ca1b1ce4d4f3caee836: Scheduling FlushDeltaMemStoresOp(72df756055d54e458a7766f4cfbb4333): perf score=14.095187
I20260812 06:19:53.032646 26553 maintenance_manager.cc:643] P 5e3e1b6bdff44ca1b1ce4d4f3caee836: FlushDeltaMemStoresOp(72df756055d54e458a7766f4cfbb4333) complete. Timing: real 0.055s	user 0.033s	sys 0.016s Metrics: {"bytes_written":16409903,"delete_count":0,"lbm_write_time_us":22435,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:53.033180 26643 maintenance_manager.cc:419] P 5e3e1b6bdff44ca1b1ce4d4f3caee836: Scheduling MajorDeltaCompactionOp(72df756055d54e458a7766f4cfbb4333): perf score=1.000000
I20260812 06:19:53.180915 26553 maintenance_manager.cc:643] P 5e3e1b6bdff44ca1b1ce4d4f3caee836: MajorDeltaCompactionOp(72df756055d54e458a7766f4cfbb4333) complete. Timing: real 0.148s	user 0.085s	sys 0.060s Metrics: {"cfile_cache_miss":431,"cfile_cache_miss_bytes":20631194,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":1,"delta_iterators_relevant":1,"dirs.queue_time_us":697,"lbm_read_time_us":9427,"lbm_reads_lt_1ms":463,"lbm_write_time_us":25626,"lbm_writes_lt_1ms":443,"mutex_wait_us":282,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":7808,"update_count":2000}
I20260812 06:19:53.181594 26643 maintenance_manager.cc:419] P 5e3e1b6bdff44ca1b1ce4d4f3caee836: Scheduling FlushDeltaMemStoresOp(72df756055d54e458a7766f4cfbb4333): perf score=11.118625
I20260812 06:19:53.194398 26400 heavy-update-compaction-itest.cc:229] Time spent updating: real 5.057s	user 1.855s	sys 0.142s
I20260812 06:19:53.210671 26553 maintenance_manager.cc:643] P 5e3e1b6bdff44ca1b1ce4d4f3caee836: FlushDeltaMemStoresOp(72df756055d54e458a7766f4cfbb4333) complete. Timing: real 0.029s	user 0.020s	sys 0.008s Metrics: {"bytes_written":12717738,"delete_count":0,"lbm_write_time_us":13408,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:19:53.211185 26643 maintenance_manager.cc:419] P 5e3e1b6bdff44ca1b1ce4d4f3caee836: Scheduling FlushDeltaMemStoresOp(72df756055d54e458a7766f4cfbb4333): perf score=2.188937
I20260812 06:19:53.223044 26553 maintenance_manager.cc:643] P 5e3e1b6bdff44ca1b1ce4d4f3caee836: FlushDeltaMemStoresOp(72df756055d54e458a7766f4cfbb4333) complete. Timing: real 0.012s	user 0.009s	sys 0.002s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":4408,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:19:53.223884 26643 maintenance_manager.cc:419] P 5e3e1b6bdff44ca1b1ce4d4f3caee836: Scheduling MajorDeltaCompactionOp(72df756055d54e458a7766f4cfbb4333): perf score=1.000000
I20260812 06:19:53.228824 26400 heavy-update-compaction-itest.cc:265] Time spent scanning: real 0.034s	user 0.003s	sys 0.000s
I20260812 06:19:53.229604 26400 tablet_server.cc:179] TabletServer@127.25.200.1:0 shutting down...
I20260812 06:19:53.333847 26553 maintenance_manager.cc:643] P 5e3e1b6bdff44ca1b1ce4d4f3caee836: MajorDeltaCompactionOp(72df756055d54e458a7766f4cfbb4333) complete. Timing: real 0.110s	user 0.077s	sys 0.032s Metrics: {"cfile_cache_hit":30,"cfile_cache_hit_bytes":4221425,"cfile_cache_miss":402,"cfile_cache_miss_bytes":16409881,"cfile_init":4,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":372,"lbm_read_time_us":6876,"lbm_reads_lt_1ms":418,"lbm_write_time_us":20807,"lbm_writes_lt_1ms":443,"mutex_wait_us":66,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":10112,"update_count":2000}
I20260812 06:19:53.334712 26400 ts_tablet_manager.cc:1507] Shutting down tablet manager...
I20260812 06:19:53.335153 26400 tablet_replica.cc:333] T 72df756055d54e458a7766f4cfbb4333 P 5e3e1b6bdff44ca1b1ce4d4f3caee836: stopping tablet replica
I20260812 06:19:53.335430 26400 raft_consensus.cc:2243] T 72df756055d54e458a7766f4cfbb4333 P 5e3e1b6bdff44ca1b1ce4d4f3caee836 [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:19:53.335688 26400 raft_consensus.cc:2272] T 72df756055d54e458a7766f4cfbb4333 P 5e3e1b6bdff44ca1b1ce4d4f3caee836 [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:19:53.353081 26400 tablet_server.cc:196] TabletServer@127.25.200.1:0 shutdown complete.
I20260812 06:19:53.372709 26400 master.cc:562] Master@127.25.200.62:42959 shutting down...
I20260812 06:19:53.377362 26400 raft_consensus.cc:2243] T 00000000000000000000000000000000 P 741473cdfd7243bc96504804a3ab0b18 [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:19:53.377575 26400 raft_consensus.cc:2272] T 00000000000000000000000000000000 P 741473cdfd7243bc96504804a3ab0b18 [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:19:53.377678 26400 tablet_replica.cc:333] T 00000000000000000000000000000000 P 741473cdfd7243bc96504804a3ab0b18: stopping tablet replica
I20260812 06:19:53.390110 26400 master.cc:584] Master@127.25.200.62:42959 shutdown complete.
[       OK ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/0 (5629 ms)
[ RUN      ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/1
I20260812 06:19:53.484846 26400 internal_mini_cluster.cc:156] Creating distributed mini masters. Addrs: 127.25.200.62:37001
I20260812 06:19:53.485257 26400 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:19:53.487599 26689 instance_detector.cc:116] could not retrieve Azure instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:19:53.487725 26400 server_base.cc:1061] running on GCE node
W20260812 06:19:53.487737 26691 instance_detector.cc:116] could not retrieve OpenStack instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:19:53.487803 26688 instance_detector.cc:116] could not retrieve AWS instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:19:53.488003 26400 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:19:53.488049 26400 system_unsync_time.cc:38] NTP support is disabled. Clock error bounds will not be accurate. This configuration is not suitable for distributed clusters.
I20260812 06:19:53.488065 26400 hybrid_clock.cc:648] HybridClock initialized: now 1786515593488064 us; error 0 us; skew 500 ppm
I20260812 06:19:53.488906 26400 webserver.cc:533] Webserver started at http://127.25.200.62:42157/ using document root <none> and password file <none>
I20260812 06:19:53.489096 26400 fs_manager.cc:362] Metadata directory not provided
I20260812 06:19:53.489151 26400 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:19:53.489259 26400 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:19:53.489666 26400 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-tasknV3hQW/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515587845435-26400-0/minicluster-data/master-0-root/instance:
uuid: "7ee42b1bd3ba4f52967050a3b11e8d57"
format_stamp: "Formatted at 2026-08-12 06:19:53 on dist-test-slave-tk9z"
I20260812 06:19:53.491389 26400 fs_manager.cc:696] Time spent creating directory manager: real 0.001s	user 0.000s	sys 0.002s
I20260812 06:19:53.492357 26696 log_block_manager.cc:4127] Time spent loading block containers with low live blocks: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:19:53.492653 26400 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.000s	sys 0.001s
I20260812 06:19:53.492756 26400 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-tasknV3hQW/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515587845435-26400-0/minicluster-data/master-0-root
uuid: "7ee42b1bd3ba4f52967050a3b11e8d57"
format_stamp: "Formatted at 2026-08-12 06:19:53 on dist-test-slave-tk9z"
I20260812 06:19:53.492873 26400 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-tasknV3hQW/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515587845435-26400-0/minicluster-data/master-0-root
metadata directory: /tmp/dist-test-tasknV3hQW/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515587845435-26400-0/minicluster-data/master-0-root
1 data directories: /tmp/dist-test-tasknV3hQW/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515587845435-26400-0/minicluster-data/master-0-root/data
Total live blocks: 0
Total live bytes: 0
Total live bytes (after alignment): 0
Total number of LBM containers: 0 (0 full)
Did not check for missing blocks
Did not check for orphaned blocks
Total full LBM containers with extra space: 0 (0 repaired)
Total full LBM container extra space in bytes: 0 (0 repaired)
Total incomplete LBM containers: 0 (0 repaired)
Total LBM partial records: 0 (0 repaired)
Total corrupted LBM metadata records in RocksDB: 0 (0 repaired)
I20260812 06:19:53.498170 26400 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:19:53.498646 26400 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:19:53.502943 26400 rpc_server.cc:307] RPC server started. Bound to: 127.25.200.62:37001
I20260812 06:19:53.506708 26770 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.25.200.62:37001 every 8 connection(s)
I20260812 06:19:53.507325 26771 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet 00000000000000000000000000000000. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:19:53.519083 26771 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P 7ee42b1bd3ba4f52967050a3b11e8d57: Bootstrap starting.
I20260812 06:19:53.519917 26771 tablet_bootstrap.cc:654] T 00000000000000000000000000000000 P 7ee42b1bd3ba4f52967050a3b11e8d57: Neither blocks nor log segments found. Creating new log.
I20260812 06:19:53.521064 26771 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P 7ee42b1bd3ba4f52967050a3b11e8d57: No bootstrap required, opened a new log
I20260812 06:19:53.521448 26771 raft_consensus.cc:359] T 00000000000000000000000000000000 P 7ee42b1bd3ba4f52967050a3b11e8d57 [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "7ee42b1bd3ba4f52967050a3b11e8d57" member_type: VOTER }
I20260812 06:19:53.521543 26771 raft_consensus.cc:385] T 00000000000000000000000000000000 P 7ee42b1bd3ba4f52967050a3b11e8d57 [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:19:53.521565 26771 raft_consensus.cc:740] T 00000000000000000000000000000000 P 7ee42b1bd3ba4f52967050a3b11e8d57 [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: 7ee42b1bd3ba4f52967050a3b11e8d57, State: Initialized, Role: FOLLOWER
I20260812 06:19:53.521720 26771 consensus_queue.cc:260] T 00000000000000000000000000000000 P 7ee42b1bd3ba4f52967050a3b11e8d57 [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: "7ee42b1bd3ba4f52967050a3b11e8d57" member_type: VOTER }
I20260812 06:19:53.521821 26771 raft_consensus.cc:399] T 00000000000000000000000000000000 P 7ee42b1bd3ba4f52967050a3b11e8d57 [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:19:53.521855 26771 raft_consensus.cc:493] T 00000000000000000000000000000000 P 7ee42b1bd3ba4f52967050a3b11e8d57 [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:19:53.521893 26771 raft_consensus.cc:3060] T 00000000000000000000000000000000 P 7ee42b1bd3ba4f52967050a3b11e8d57 [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:19:53.522578 26771 raft_consensus.cc:515] T 00000000000000000000000000000000 P 7ee42b1bd3ba4f52967050a3b11e8d57 [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "7ee42b1bd3ba4f52967050a3b11e8d57" member_type: VOTER }
I20260812 06:19:53.522691 26771 leader_election.cc:304] T 00000000000000000000000000000000 P 7ee42b1bd3ba4f52967050a3b11e8d57 [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: 7ee42b1bd3ba4f52967050a3b11e8d57; no voters: 
I20260812 06:19:53.522861 26771 leader_election.cc:290] T 00000000000000000000000000000000 P 7ee42b1bd3ba4f52967050a3b11e8d57 [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:19:53.523028 26776 raft_consensus.cc:2804] T 00000000000000000000000000000000 P 7ee42b1bd3ba4f52967050a3b11e8d57 [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:19:53.523221 26776 raft_consensus.cc:697] T 00000000000000000000000000000000 P 7ee42b1bd3ba4f52967050a3b11e8d57 [term 1 LEADER]: Becoming Leader. State: Replica: 7ee42b1bd3ba4f52967050a3b11e8d57, State: Running, Role: LEADER
I20260812 06:19:53.523370 26771 sys_catalog.cc:565] T 00000000000000000000000000000000 P 7ee42b1bd3ba4f52967050a3b11e8d57 [sys.catalog]: configured and running, proceeding with master startup.
I20260812 06:19:53.523368 26776 consensus_queue.cc:237] T 00000000000000000000000000000000 P 7ee42b1bd3ba4f52967050a3b11e8d57 [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: "7ee42b1bd3ba4f52967050a3b11e8d57" member_type: VOTER }
I20260812 06:19:53.523905 26777 sys_catalog.cc:455] T 00000000000000000000000000000000 P 7ee42b1bd3ba4f52967050a3b11e8d57 [sys.catalog]: SysCatalogTable state changed. Reason: RaftConsensus started. Latest consensus state: current_term: 1 leader_uuid: "7ee42b1bd3ba4f52967050a3b11e8d57" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "7ee42b1bd3ba4f52967050a3b11e8d57" member_type: VOTER } }
I20260812 06:19:53.523954 26779 sys_catalog.cc:455] T 00000000000000000000000000000000 P 7ee42b1bd3ba4f52967050a3b11e8d57 [sys.catalog]: SysCatalogTable state changed. Reason: New leader 7ee42b1bd3ba4f52967050a3b11e8d57. Latest consensus state: current_term: 1 leader_uuid: "7ee42b1bd3ba4f52967050a3b11e8d57" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "7ee42b1bd3ba4f52967050a3b11e8d57" member_type: VOTER } }
I20260812 06:19:53.524072 26777 sys_catalog.cc:458] T 00000000000000000000000000000000 P 7ee42b1bd3ba4f52967050a3b11e8d57 [sys.catalog]: This master's current role is: LEADER
I20260812 06:19:53.524154 26779 sys_catalog.cc:458] T 00000000000000000000000000000000 P 7ee42b1bd3ba4f52967050a3b11e8d57 [sys.catalog]: This master's current role is: LEADER
I20260812 06:19:53.524814 26785 catalog_manager.cc:1511] Loading table and tablet metadata into memory...
I20260812 06:19:53.525493 26785 catalog_manager.cc:1520] Initializing Kudu cluster ID...
I20260812 06:19:53.525679 26400 internal_mini_cluster.cc:184] Waiting to initialize catalog manager on master 0
I20260812 06:19:53.527406 26785 catalog_manager.cc:1383] Generated new cluster ID: 2273c7d7854f4cb7a5ed5da8773bb33e
I20260812 06:19:53.527465 26785 catalog_manager.cc:1531] Initializing Kudu internal certificate authority...
I20260812 06:19:53.536732 26785 catalog_manager.cc:1406] Generated new certificate authority record
I20260812 06:19:53.537330 26785 catalog_manager.cc:1540] Loading token signing keys...
I20260812 06:19:53.541337 26785 catalog_manager.cc:6092] T 00000000000000000000000000000000 P 7ee42b1bd3ba4f52967050a3b11e8d57: Generated new TSK 0
I20260812 06:19:53.541507 26785 catalog_manager.cc:1550] Initializing in-progress tserver states...
I20260812 06:19:53.558135 26400 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:19:53.560395 26807 instance_detector.cc:116] could not retrieve Azure instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:19:53.560396 26809 instance_detector.cc:116] could not retrieve OpenStack instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:19:53.560510 26400 server_base.cc:1061] running on GCE node
W20260812 06:19:53.560511 26806 instance_detector.cc:116] could not retrieve AWS instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:19:53.560855 26400 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:19:53.560947 26400 system_unsync_time.cc:38] NTP support is disabled. Clock error bounds will not be accurate. This configuration is not suitable for distributed clusters.
I20260812 06:19:53.560966 26400 hybrid_clock.cc:648] HybridClock initialized: now 1786515593560966 us; error 0 us; skew 500 ppm
I20260812 06:19:53.561913 26400 webserver.cc:533] Webserver started at http://127.25.200.1:43951/ using document root <none> and password file <none>
I20260812 06:19:53.562057 26400 fs_manager.cc:362] Metadata directory not provided
I20260812 06:19:53.562104 26400 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:19:53.562160 26400 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:19:53.562616 26400 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-tasknV3hQW/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515587845435-26400-0/minicluster-data/ts-0-root/instance:
uuid: "0626f87c94e74ed7ab65882331b34fbd"
format_stamp: "Formatted at 2026-08-12 06:19:53 on dist-test-slave-tk9z"
I20260812 06:19:53.564275 26400 fs_manager.cc:696] Time spent creating directory manager: real 0.001s	user 0.002s	sys 0.000s
I20260812 06:19:53.565336 26818 log_block_manager.cc:4127] Time spent loading block containers with low live blocks: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:19:53.565626 26400 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.001s	sys 0.000s
I20260812 06:19:53.565690 26400 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-tasknV3hQW/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515587845435-26400-0/minicluster-data/ts-0-root
uuid: "0626f87c94e74ed7ab65882331b34fbd"
format_stamp: "Formatted at 2026-08-12 06:19:53 on dist-test-slave-tk9z"
I20260812 06:19:53.565747 26400 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-tasknV3hQW/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515587845435-26400-0/minicluster-data/ts-0-root
metadata directory: /tmp/dist-test-tasknV3hQW/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515587845435-26400-0/minicluster-data/ts-0-root
1 data directories: /tmp/dist-test-tasknV3hQW/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515587845435-26400-0/minicluster-data/ts-0-root/data
Total live blocks: 0
Total live bytes: 0
Total live bytes (after alignment): 0
Total number of LBM containers: 0 (0 full)
Did not check for missing blocks
Did not check for orphaned blocks
Total full LBM containers with extra space: 0 (0 repaired)
Total full LBM container extra space in bytes: 0 (0 repaired)
Total incomplete LBM containers: 0 (0 repaired)
Total LBM partial records: 0 (0 repaired)
Total corrupted LBM metadata records in RocksDB: 0 (0 repaired)
I20260812 06:19:53.583245 26400 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:19:53.583601 26400 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:19:53.583873 26400 txn_system_client.cc:432] TxnSystemClient initialization is disabled...
I20260812 06:19:53.584388 26400 ts_tablet_manager.cc:585] Loaded tablet metadata (0 total tablets, 0 live tablets)
I20260812 06:19:53.584430 26400 ts_tablet_manager.cc:531] Time spent load tablet metadata: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:19:53.584465 26400 ts_tablet_manager.cc:616] Registered 0 tablets
I20260812 06:19:53.584522 26400 ts_tablet_manager.cc:595] Time spent register tablets: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:19:53.588908 26400 rpc_server.cc:307] RPC server started. Bound to: 127.25.200.1:33081
I20260812 06:19:53.588936 26904 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.25.200.1:33081 every 8 connection(s)
I20260812 06:19:53.598698 26906 heartbeater.cc:344] Connected to a master server at 127.25.200.62:37001
I20260812 06:19:53.598874 26906 heartbeater.cc:461] Registering TS with master...
I20260812 06:19:53.599145 26906 heartbeater.cc:507] Master 127.25.200.62:37001 requested a full tablet report, sending...
I20260812 06:19:53.599877 26715 ts_manager.cc:194] Registered new tserver with Master: 0626f87c94e74ed7ab65882331b34fbd (127.25.200.1:33081)
I20260812 06:19:53.600684 26715 master_service.cc:502] Signed X509 certificate for tserver {username='slave'} at 127.0.0.1:54734
I20260812 06:19:53.600684 26400 internal_mini_cluster.cc:371] 1 TS(s) registered with all masters after 0.011384649s
I20260812 06:19:53.608103 26715 catalog_manager.cc:2283] Servicing CreateTable request from {username='slave'} at 127.0.0.1:54746:
name: "heavy-update-compaction-test"
schema {
  columns {
    name: "key"
    type: INT64
    is_key: true
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_a"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_b"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_c"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_d"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_e"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
}
num_replicas: 1
split_rows_range_bounds {
}
partition_schema {
  range_schema {
  }
}
I20260812 06:19:53.616894 26853 tablet_service.cc:1511] Processing CreateTablet for tablet 348c282a3ce14575a7d092c9521a679c (DEFAULT_TABLE table=heavy-update-compaction-test [id=507f1d084dbc4c6bae097c4bb0399aaf]), partition=
I20260812 06:19:53.617197 26853 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet 348c282a3ce14575a7d092c9521a679c. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:19:53.619357 26922 tablet_bootstrap.cc:492] T 348c282a3ce14575a7d092c9521a679c P 0626f87c94e74ed7ab65882331b34fbd: Bootstrap starting.
I20260812 06:19:53.620210 26922 tablet_bootstrap.cc:654] T 348c282a3ce14575a7d092c9521a679c P 0626f87c94e74ed7ab65882331b34fbd: Neither blocks nor log segments found. Creating new log.
I20260812 06:19:53.621294 26922 tablet_bootstrap.cc:492] T 348c282a3ce14575a7d092c9521a679c P 0626f87c94e74ed7ab65882331b34fbd: No bootstrap required, opened a new log
I20260812 06:19:53.621446 26922 ts_tablet_manager.cc:1403] T 348c282a3ce14575a7d092c9521a679c P 0626f87c94e74ed7ab65882331b34fbd: Time spent bootstrapping tablet: real 0.002s	user 0.001s	sys 0.000s
I20260812 06:19:53.621874 26922 raft_consensus.cc:359] T 348c282a3ce14575a7d092c9521a679c P 0626f87c94e74ed7ab65882331b34fbd [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "0626f87c94e74ed7ab65882331b34fbd" member_type: VOTER last_known_addr { host: "127.25.200.1" port: 33081 } }
I20260812 06:19:53.621985 26922 raft_consensus.cc:385] T 348c282a3ce14575a7d092c9521a679c P 0626f87c94e74ed7ab65882331b34fbd [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:19:53.622041 26922 raft_consensus.cc:740] T 348c282a3ce14575a7d092c9521a679c P 0626f87c94e74ed7ab65882331b34fbd [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: 0626f87c94e74ed7ab65882331b34fbd, State: Initialized, Role: FOLLOWER
I20260812 06:19:53.622203 26922 consensus_queue.cc:260] T 348c282a3ce14575a7d092c9521a679c P 0626f87c94e74ed7ab65882331b34fbd [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: "0626f87c94e74ed7ab65882331b34fbd" member_type: VOTER last_known_addr { host: "127.25.200.1" port: 33081 } }
I20260812 06:19:53.622300 26922 raft_consensus.cc:399] T 348c282a3ce14575a7d092c9521a679c P 0626f87c94e74ed7ab65882331b34fbd [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:19:53.622354 26922 raft_consensus.cc:493] T 348c282a3ce14575a7d092c9521a679c P 0626f87c94e74ed7ab65882331b34fbd [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:19:53.622439 26922 raft_consensus.cc:3060] T 348c282a3ce14575a7d092c9521a679c P 0626f87c94e74ed7ab65882331b34fbd [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:19:53.623224 26922 raft_consensus.cc:515] T 348c282a3ce14575a7d092c9521a679c P 0626f87c94e74ed7ab65882331b34fbd [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "0626f87c94e74ed7ab65882331b34fbd" member_type: VOTER last_known_addr { host: "127.25.200.1" port: 33081 } }
I20260812 06:19:53.623355 26922 leader_election.cc:304] T 348c282a3ce14575a7d092c9521a679c P 0626f87c94e74ed7ab65882331b34fbd [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: 0626f87c94e74ed7ab65882331b34fbd; no voters: 
I20260812 06:19:53.623508 26922 leader_election.cc:290] T 348c282a3ce14575a7d092c9521a679c P 0626f87c94e74ed7ab65882331b34fbd [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:19:53.623637 26924 raft_consensus.cc:2804] T 348c282a3ce14575a7d092c9521a679c P 0626f87c94e74ed7ab65882331b34fbd [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:19:53.623871 26922 ts_tablet_manager.cc:1434] T 348c282a3ce14575a7d092c9521a679c P 0626f87c94e74ed7ab65882331b34fbd: Time spent starting tablet: real 0.002s	user 0.003s	sys 0.000s
I20260812 06:19:53.623907 26906 heartbeater.cc:499] Master 127.25.200.62:37001 was elected leader, sending a full tablet report...
I20260812 06:19:53.623881 26924 raft_consensus.cc:697] T 348c282a3ce14575a7d092c9521a679c P 0626f87c94e74ed7ab65882331b34fbd [term 1 LEADER]: Becoming Leader. State: Replica: 0626f87c94e74ed7ab65882331b34fbd, State: Running, Role: LEADER
I20260812 06:19:53.624130 26924 consensus_queue.cc:237] T 348c282a3ce14575a7d092c9521a679c P 0626f87c94e74ed7ab65882331b34fbd [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: "0626f87c94e74ed7ab65882331b34fbd" member_type: VOTER last_known_addr { host: "127.25.200.1" port: 33081 } }
I20260812 06:19:53.625459 26715 catalog_manager.cc:5719] T 348c282a3ce14575a7d092c9521a679c P 0626f87c94e74ed7ab65882331b34fbd reported cstate change: term changed from 0 to 1, leader changed from <none> to 0626f87c94e74ed7ab65882331b34fbd (127.25.200.1). New cstate: current_term: 1 leader_uuid: "0626f87c94e74ed7ab65882331b34fbd" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "0626f87c94e74ed7ab65882331b34fbd" member_type: VOTER last_known_addr { host: "127.25.200.1" port: 33081 } health_report { overall_health: HEALTHY } } }
I20260812 06:19:53.686152 26400 heavy-update-compaction-itest.cc:215] Time spent inserting: real 0.054s	user 0.010s	sys 0.012s
I20260812 06:19:53.839973 26908 maintenance_manager.cc:419] P 0626f87c94e74ed7ab65882331b34fbd: Scheduling FlushMRSOp(348c282a3ce14575a7d092c9521a679c): perf score=19.054940
I20260812 06:19:53.987311 26823 maintenance_manager.cc:643] P 0626f87c94e74ed7ab65882331b34fbd: FlushMRSOp(348c282a3ce14575a7d092c9521a679c) complete. Timing: real 0.147s	user 0.114s	sys 0.032s Metrics: {"bytes_written":12307491,"cfile_init":1,"delete_count":0,"dirs.queue_time_us":112,"dirs.run_cpu_time_us":232,"dirs.run_wall_time_us":859,"drs_written":1,"lbm_read_time_us":78,"lbm_reads_lt_1ms":4,"lbm_write_time_us":36121,"lbm_writes_lt_1ms":767,"peak_mem_usage":0,"reinsert_count":0,"rows_written":105,"update_count":1500}
I20260812 06:19:53.988101 26908 maintenance_manager.cc:419] P 0626f87c94e74ed7ab65882331b34fbd: Scheduling LogGCOp(348c282a3ce14575a7d092c9521a679c): free 20290830 bytes of WAL
I20260812 06:19:53.988353 26823 log_reader.cc:385] T 348c282a3ce14575a7d092c9521a679c: removed 2 log segments from log reader
I20260812 06:19:53.988417 26823 log.cc:1079] T 348c282a3ce14575a7d092c9521a679c P 0626f87c94e74ed7ab65882331b34fbd: Deleting log segment in path: /tmp/dist-test-tasknV3hQW/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515587845435-26400-0/minicluster-data/ts-0-root/wals/348c282a3ce14575a7d092c9521a679c/wal-000000001 (ops 1-6)
I20260812 06:19:53.988474 26823 log.cc:1079] T 348c282a3ce14575a7d092c9521a679c P 0626f87c94e74ed7ab65882331b34fbd: Deleting log segment in path: /tmp/dist-test-tasknV3hQW/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515587845435-26400-0/minicluster-data/ts-0-root/wals/348c282a3ce14575a7d092c9521a679c/wal-000000002 (ops 7-10)
I20260812 06:19:53.993536 26823 maintenance_manager.cc:643] P 0626f87c94e74ed7ab65882331b34fbd: LogGCOp(348c282a3ce14575a7d092c9521a679c) complete. Timing: real 0.005s	user 0.000s	sys 0.002s Metrics: {}
I20260812 06:19:53.994053 26908 maintenance_manager.cc:419] P 0626f87c94e74ed7ab65882331b34fbd: Scheduling FlushDeltaMemStoresOp(348c282a3ce14575a7d092c9521a679c): perf score=2.188937
I20260812 06:19:54.011032 26823 maintenance_manager.cc:643] P 0626f87c94e74ed7ab65882331b34fbd: FlushDeltaMemStoresOp(348c282a3ce14575a7d092c9521a679c) complete. Timing: real 0.017s	user 0.016s	sys 0.000s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":6044,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:19:54.011511 26908 maintenance_manager.cc:419] P 0626f87c94e74ed7ab65882331b34fbd: Scheduling UndoDeltaBlockGCOp(348c282a3ce14575a7d092c9521a679c): 16821650 bytes on disk
I20260812 06:19:54.011934 26823 maintenance_manager.cc:643] P 0626f87c94e74ed7ab65882331b34fbd: UndoDeltaBlockGCOp(348c282a3ce14575a7d092c9521a679c) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":54,"lbm_reads_lt_1ms":4}
I20260812 06:19:54.012327 26908 maintenance_manager.cc:419] P 0626f87c94e74ed7ab65882331b34fbd: Scheduling MajorDeltaCompactionOp(348c282a3ce14575a7d092c9521a679c): perf score=1.000000
I20260812 06:19:54.163108 26823 maintenance_manager.cc:643] P 0626f87c94e74ed7ab65882331b34fbd: MajorDeltaCompactionOp(348c282a3ce14575a7d092c9521a679c) complete. Timing: real 0.151s	user 0.100s	sys 0.039s Metrics: {"cfile_cache_miss":422,"cfile_cache_miss_bytes":20303019,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":623,"lbm_read_time_us":10681,"lbm_reads_lt_1ms":454,"lbm_write_time_us":24115,"lbm_writes_lt_1ms":433,"peak_mem_usage":49238594,"reinsert_count":0,"spinlock_wait_cycles":1280,"thread_start_us":329,"threads_started":5,"update_count":1950}
I20260812 06:19:54.163852 26908 maintenance_manager.cc:419] P 0626f87c94e74ed7ab65882331b34fbd: Scheduling FlushDeltaMemStoresOp(348c282a3ce14575a7d092c9521a679c): perf score=14.095187
I20260812 06:19:54.221845 26823 maintenance_manager.cc:643] P 0626f87c94e74ed7ab65882331b34fbd: FlushDeltaMemStoresOp(348c282a3ce14575a7d092c9521a679c) complete. Timing: real 0.058s	user 0.029s	sys 0.015s Metrics: {"bytes_written":16409905,"delete_count":0,"lbm_write_time_us":19403,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:54.222566 26908 maintenance_manager.cc:419] P 0626f87c94e74ed7ab65882331b34fbd: Scheduling FlushDeltaMemStoresOp(348c282a3ce14575a7d092c9521a679c): perf score=2.188937
I20260812 06:19:54.235487 26823 maintenance_manager.cc:643] P 0626f87c94e74ed7ab65882331b34fbd: FlushDeltaMemStoresOp(348c282a3ce14575a7d092c9521a679c) complete. Timing: real 0.013s	user 0.011s	sys 0.001s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4647,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:54.236125 26908 maintenance_manager.cc:419] P 0626f87c94e74ed7ab65882331b34fbd: Scheduling MajorDeltaCompactionOp(348c282a3ce14575a7d092c9521a679c): perf score=1.000000
I20260812 06:19:54.418047 26823 maintenance_manager.cc:643] P 0626f87c94e74ed7ab65882331b34fbd: MajorDeltaCompactionOp(348c282a3ce14575a7d092c9521a679c) complete. Timing: real 0.182s	user 0.129s	sys 0.052s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24815687,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":267,"lbm_read_time_us":12029,"lbm_reads_lt_1ms":572,"lbm_write_time_us":30717,"lbm_writes_lt_1ms":543,"mutex_wait_us":49,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":7936,"update_count":2500}
I20260812 06:19:54.418713 26908 maintenance_manager.cc:419] P 0626f87c94e74ed7ab65882331b34fbd: Scheduling FlushDeltaMemStoresOp(348c282a3ce14575a7d092c9521a679c): perf score=14.095187
I20260812 06:19:54.483651 26823 maintenance_manager.cc:643] P 0626f87c94e74ed7ab65882331b34fbd: FlushDeltaMemStoresOp(348c282a3ce14575a7d092c9521a679c) complete. Timing: real 0.065s	user 0.034s	sys 0.025s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":21208,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:54.484175 26908 maintenance_manager.cc:419] P 0626f87c94e74ed7ab65882331b34fbd: Scheduling FlushDeltaMemStoresOp(348c282a3ce14575a7d092c9521a679c): perf score=2.188937
I20260812 06:19:54.495514 26823 maintenance_manager.cc:643] P 0626f87c94e74ed7ab65882331b34fbd: FlushDeltaMemStoresOp(348c282a3ce14575a7d092c9521a679c) complete. Timing: real 0.011s	user 0.005s	sys 0.005s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4489,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:54.496027 26908 maintenance_manager.cc:419] P 0626f87c94e74ed7ab65882331b34fbd: Scheduling MajorDeltaCompactionOp(348c282a3ce14575a7d092c9521a679c): perf score=1.000000
I20260812 06:19:54.692942 26823 maintenance_manager.cc:643] P 0626f87c94e74ed7ab65882331b34fbd: MajorDeltaCompactionOp(348c282a3ce14575a7d092c9521a679c) complete. Timing: real 0.197s	user 0.130s	sys 0.056s 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":878,"lbm_read_time_us":12490,"lbm_reads_lt_1ms":572,"lbm_write_time_us":30825,"lbm_writes_lt_1ms":543,"mutex_wait_us":282,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":14464,"update_count":2500}
I20260812 06:19:54.693502 26908 maintenance_manager.cc:419] P 0626f87c94e74ed7ab65882331b34fbd: Scheduling FlushDeltaMemStoresOp(348c282a3ce14575a7d092c9521a679c): perf score=14.095187
I20260812 06:19:54.744553 26823 maintenance_manager.cc:643] P 0626f87c94e74ed7ab65882331b34fbd: FlushDeltaMemStoresOp(348c282a3ce14575a7d092c9521a679c) complete. Timing: real 0.051s	user 0.016s	sys 0.025s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":19060,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:54.745136 26908 maintenance_manager.cc:419] P 0626f87c94e74ed7ab65882331b34fbd: Scheduling FlushDeltaMemStoresOp(348c282a3ce14575a7d092c9521a679c): perf score=2.188937
I20260812 06:19:54.766590 26823 maintenance_manager.cc:643] P 0626f87c94e74ed7ab65882331b34fbd: FlushDeltaMemStoresOp(348c282a3ce14575a7d092c9521a679c) complete. Timing: real 0.021s	user 0.010s	sys 0.011s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":3977,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:54.767204 26908 maintenance_manager.cc:419] P 0626f87c94e74ed7ab65882331b34fbd: Scheduling MajorDeltaCompactionOp(348c282a3ce14575a7d092c9521a679c): perf score=1.000000
I20260812 06:19:54.945820 26823 maintenance_manager.cc:643] P 0626f87c94e74ed7ab65882331b34fbd: MajorDeltaCompactionOp(348c282a3ce14575a7d092c9521a679c) complete. Timing: real 0.178s	user 0.142s	sys 0.037s 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":277,"lbm_read_time_us":12899,"lbm_reads_lt_1ms":572,"lbm_write_time_us":28377,"lbm_writes_lt_1ms":543,"mutex_wait_us":29,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":13184,"update_count":2500}
I20260812 06:19:54.946403 26908 maintenance_manager.cc:419] P 0626f87c94e74ed7ab65882331b34fbd: Scheduling FlushDeltaMemStoresOp(348c282a3ce14575a7d092c9521a679c): perf score=14.095187
I20260812 06:19:55.001150 26823 maintenance_manager.cc:643] P 0626f87c94e74ed7ab65882331b34fbd: FlushDeltaMemStoresOp(348c282a3ce14575a7d092c9521a679c) complete. Timing: real 0.055s	user 0.031s	sys 0.017s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":23087,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:55.001565 26908 maintenance_manager.cc:419] P 0626f87c94e74ed7ab65882331b34fbd: Scheduling FlushDeltaMemStoresOp(348c282a3ce14575a7d092c9521a679c): perf score=2.188937
I20260812 06:19:55.012050 26823 maintenance_manager.cc:643] P 0626f87c94e74ed7ab65882331b34fbd: FlushDeltaMemStoresOp(348c282a3ce14575a7d092c9521a679c) complete. Timing: real 0.010s	user 0.005s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3896,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:55.012877 26908 maintenance_manager.cc:419] P 0626f87c94e74ed7ab65882331b34fbd: Scheduling MajorDeltaCompactionOp(348c282a3ce14575a7d092c9521a679c): perf score=1.000000
I20260812 06:19:55.199934 26823 maintenance_manager.cc:643] P 0626f87c94e74ed7ab65882331b34fbd: MajorDeltaCompactionOp(348c282a3ce14575a7d092c9521a679c) complete. Timing: real 0.187s	user 0.103s	sys 0.067s 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":419,"lbm_read_time_us":11588,"lbm_reads_lt_1ms":572,"lbm_write_time_us":29188,"lbm_writes_lt_1ms":543,"mutex_wait_us":31,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":8064,"update_count":2500}
I20260812 06:19:55.200532 26908 maintenance_manager.cc:419] P 0626f87c94e74ed7ab65882331b34fbd: Scheduling FlushDeltaMemStoresOp(348c282a3ce14575a7d092c9521a679c): perf score=14.095187
I20260812 06:19:55.257611 26823 maintenance_manager.cc:643] P 0626f87c94e74ed7ab65882331b34fbd: FlushDeltaMemStoresOp(348c282a3ce14575a7d092c9521a679c) complete. Timing: real 0.057s	user 0.020s	sys 0.032s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":26155,"lbm_writes_1-10_ms":2,"lbm_writes_lt_1ms":401,"reinsert_count":0,"update_count":2000}
I20260812 06:19:55.258128 26908 maintenance_manager.cc:419] P 0626f87c94e74ed7ab65882331b34fbd: Scheduling FlushDeltaMemStoresOp(348c282a3ce14575a7d092c9521a679c): perf score=2.188937
I20260812 06:19:55.270455 26823 maintenance_manager.cc:643] P 0626f87c94e74ed7ab65882331b34fbd: FlushDeltaMemStoresOp(348c282a3ce14575a7d092c9521a679c) complete. Timing: real 0.012s	user 0.009s	sys 0.003s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4011,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:55.271085 26908 maintenance_manager.cc:419] P 0626f87c94e74ed7ab65882331b34fbd: Scheduling FlushMRSOp(348c282a3ce14575a7d092c9521a679c): perf score=1.000000
I20260812 06:19:55.303146 26823 maintenance_manager.cc:643] P 0626f87c94e74ed7ab65882331b34fbd: FlushMRSOp(348c282a3ce14575a7d092c9521a679c) complete. Timing: real 0.032s	user 0.027s	sys 0.004s Metrics: {"bytes_written":1152508,"cfile_init":1,"dirs.queue_time_us":71,"dirs.run_cpu_time_us":277,"dirs.run_wall_time_us":1535,"drs_written":1,"lbm_read_time_us":38,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1783,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":28}
I20260812 06:19:55.303790 26908 maintenance_manager.cc:419] P 0626f87c94e74ed7ab65882331b34fbd: Scheduling LogGCOp(348c282a3ce14575a7d092c9521a679c): free 112692309 bytes of WAL
I20260812 06:19:55.304014 26823 log_reader.cc:385] T 348c282a3ce14575a7d092c9521a679c: removed 11 log segments from log reader
I20260812 06:19:55.304075 26823 log.cc:1079] T 348c282a3ce14575a7d092c9521a679c P 0626f87c94e74ed7ab65882331b34fbd: Deleting log segment in path: /tmp/dist-test-tasknV3hQW/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515587845435-26400-0/minicluster-data/ts-0-root/wals/348c282a3ce14575a7d092c9521a679c/wal-000000003 (ops 11-15)
I20260812 06:19:55.304134 26823 log.cc:1079] T 348c282a3ce14575a7d092c9521a679c P 0626f87c94e74ed7ab65882331b34fbd: Deleting log segment in path: /tmp/dist-test-tasknV3hQW/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515587845435-26400-0/minicluster-data/ts-0-root/wals/348c282a3ce14575a7d092c9521a679c/wal-000000004 (ops 16-20)
I20260812 06:19:55.304193 26823 log.cc:1079] T 348c282a3ce14575a7d092c9521a679c P 0626f87c94e74ed7ab65882331b34fbd: Deleting log segment in path: /tmp/dist-test-tasknV3hQW/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515587845435-26400-0/minicluster-data/ts-0-root/wals/348c282a3ce14575a7d092c9521a679c/wal-000000005 (ops 21-25)
I20260812 06:19:55.304232 26823 log.cc:1079] T 348c282a3ce14575a7d092c9521a679c P 0626f87c94e74ed7ab65882331b34fbd: Deleting log segment in path: /tmp/dist-test-tasknV3hQW/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515587845435-26400-0/minicluster-data/ts-0-root/wals/348c282a3ce14575a7d092c9521a679c/wal-000000006 (ops 26-30)
I20260812 06:19:55.304270 26823 log.cc:1079] T 348c282a3ce14575a7d092c9521a679c P 0626f87c94e74ed7ab65882331b34fbd: Deleting log segment in path: /tmp/dist-test-tasknV3hQW/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515587845435-26400-0/minicluster-data/ts-0-root/wals/348c282a3ce14575a7d092c9521a679c/wal-000000007 (ops 31-35)
I20260812 06:19:55.304306 26823 log.cc:1079] T 348c282a3ce14575a7d092c9521a679c P 0626f87c94e74ed7ab65882331b34fbd: Deleting log segment in path: /tmp/dist-test-tasknV3hQW/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515587845435-26400-0/minicluster-data/ts-0-root/wals/348c282a3ce14575a7d092c9521a679c/wal-000000008 (ops 36-40)
I20260812 06:19:55.304351 26823 log.cc:1079] T 348c282a3ce14575a7d092c9521a679c P 0626f87c94e74ed7ab65882331b34fbd: Deleting log segment in path: /tmp/dist-test-tasknV3hQW/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515587845435-26400-0/minicluster-data/ts-0-root/wals/348c282a3ce14575a7d092c9521a679c/wal-000000009 (ops 41-45)
I20260812 06:19:55.304387 26823 log.cc:1079] T 348c282a3ce14575a7d092c9521a679c P 0626f87c94e74ed7ab65882331b34fbd: Deleting log segment in path: /tmp/dist-test-tasknV3hQW/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515587845435-26400-0/minicluster-data/ts-0-root/wals/348c282a3ce14575a7d092c9521a679c/wal-000000010 (ops 46-50)
I20260812 06:19:55.304431 26823 log.cc:1079] T 348c282a3ce14575a7d092c9521a679c P 0626f87c94e74ed7ab65882331b34fbd: Deleting log segment in path: /tmp/dist-test-tasknV3hQW/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515587845435-26400-0/minicluster-data/ts-0-root/wals/348c282a3ce14575a7d092c9521a679c/wal-000000011 (ops 51-55)
I20260812 06:19:55.304467 26823 log.cc:1079] T 348c282a3ce14575a7d092c9521a679c P 0626f87c94e74ed7ab65882331b34fbd: Deleting log segment in path: /tmp/dist-test-tasknV3hQW/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515587845435-26400-0/minicluster-data/ts-0-root/wals/348c282a3ce14575a7d092c9521a679c/wal-000000012 (ops 56-60)
I20260812 06:19:55.304503 26823 log.cc:1079] T 348c282a3ce14575a7d092c9521a679c P 0626f87c94e74ed7ab65882331b34fbd: Deleting log segment in path: /tmp/dist-test-tasknV3hQW/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515587845435-26400-0/minicluster-data/ts-0-root/wals/348c282a3ce14575a7d092c9521a679c/wal-000000013 (ops 61-65)
I20260812 06:19:55.331175 26823 maintenance_manager.cc:643] P 0626f87c94e74ed7ab65882331b34fbd: LogGCOp(348c282a3ce14575a7d092c9521a679c) complete. Timing: real 0.027s	user 0.004s	sys 0.023s Metrics: {}
I20260812 06:19:55.331724 26908 maintenance_manager.cc:419] P 0626f87c94e74ed7ab65882331b34fbd: Scheduling FlushDeltaMemStoresOp(348c282a3ce14575a7d092c9521a679c): perf score=3.181125
I20260812 06:19:55.364145 26823 maintenance_manager.cc:643] P 0626f87c94e74ed7ab65882331b34fbd: FlushDeltaMemStoresOp(348c282a3ce14575a7d092c9521a679c) complete. Timing: real 0.032s	user 0.021s	sys 0.000s Metrics: {"bytes_written":4512900,"delete_count":0,"lbm_write_time_us":6942,"lbm_writes_lt_1ms":113,"reinsert_count":0,"update_count":550}
I20260812 06:19:55.364740 26908 maintenance_manager.cc:419] P 0626f87c94e74ed7ab65882331b34fbd: Scheduling LogGCOp(348c282a3ce14575a7d092c9521a679c): free 12017983 bytes of WAL
I20260812 06:19:55.364962 26823 log_reader.cc:385] T 348c282a3ce14575a7d092c9521a679c: removed 1 log segments from log reader
I20260812 06:19:55.365021 26823 log.cc:1079] T 348c282a3ce14575a7d092c9521a679c P 0626f87c94e74ed7ab65882331b34fbd: Deleting log segment in path: /tmp/dist-test-tasknV3hQW/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515587845435-26400-0/minicluster-data/ts-0-root/wals/348c282a3ce14575a7d092c9521a679c/wal-000000014 (ops 66-70)
I20260812 06:19:55.367472 26823 maintenance_manager.cc:643] P 0626f87c94e74ed7ab65882331b34fbd: LogGCOp(348c282a3ce14575a7d092c9521a679c) complete. Timing: real 0.003s	user 0.000s	sys 0.002s Metrics: {}
I20260812 06:19:55.367853 26908 maintenance_manager.cc:419] P 0626f87c94e74ed7ab65882331b34fbd: Scheduling FlushDeltaMemStoresOp(348c282a3ce14575a7d092c9521a679c): perf score=2.188937
I20260812 06:19:55.387324 26823 maintenance_manager.cc:643] P 0626f87c94e74ed7ab65882331b34fbd: FlushDeltaMemStoresOp(348c282a3ce14575a7d092c9521a679c) complete. Timing: real 0.019s	user 0.009s	sys 0.005s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":5736,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:19:55.387883 26908 maintenance_manager.cc:419] P 0626f87c94e74ed7ab65882331b34fbd: Scheduling MajorDeltaCompactionOp(348c282a3ce14575a7d092c9521a679c): perf score=1.000000
I20260812 06:19:55.643126 26823 maintenance_manager.cc:643] P 0626f87c94e74ed7ab65882331b34fbd: MajorDeltaCompactionOp(348c282a3ce14575a7d092c9521a679c) complete. Timing: real 0.255s	user 0.161s	sys 0.088s Metrics: {"cfile_cache_miss":734,"cfile_cache_miss_bytes":33020732,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":1469,"lbm_read_time_us":18214,"lbm_reads_lt_1ms":774,"lbm_write_time_us":43188,"lbm_writes_lt_1ms":743,"mutex_wait_us":407,"peak_mem_usage":87969044,"reinsert_count":0,"spinlock_wait_cycles":21504,"thread_start_us":101,"threads_started":1,"update_count":3500}
I20260812 06:19:55.643846 26908 maintenance_manager.cc:419] P 0626f87c94e74ed7ab65882331b34fbd: Scheduling FlushDeltaMemStoresOp(348c282a3ce14575a7d092c9521a679c): perf score=18.063937
I20260812 06:19:55.725438 26823 maintenance_manager.cc:643] P 0626f87c94e74ed7ab65882331b34fbd: FlushDeltaMemStoresOp(348c282a3ce14575a7d092c9521a679c) complete. Timing: real 0.081s	user 0.039s	sys 0.032s Metrics: {"bytes_written":20512315,"delete_count":0,"lbm_write_time_us":32250,"lbm_writes_lt_1ms":503,"reinsert_count":0,"update_count":2500}
I20260812 06:19:55.726112 26908 maintenance_manager.cc:419] P 0626f87c94e74ed7ab65882331b34fbd: Scheduling UndoDeltaBlockGCOp(348c282a3ce14575a7d092c9521a679c): 448 bytes on disk
I20260812 06:19:55.726722 26823 maintenance_manager.cc:643] P 0626f87c94e74ed7ab65882331b34fbd: UndoDeltaBlockGCOp(348c282a3ce14575a7d092c9521a679c) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":65,"lbm_reads_lt_1ms":4}
I20260812 06:19:55.727303 26908 maintenance_manager.cc:419] P 0626f87c94e74ed7ab65882331b34fbd: Scheduling FlushDeltaMemStoresOp(348c282a3ce14575a7d092c9521a679c): perf score=2.188937
I20260812 06:19:55.740423 26823 maintenance_manager.cc:643] P 0626f87c94e74ed7ab65882331b34fbd: FlushDeltaMemStoresOp(348c282a3ce14575a7d092c9521a679c) complete. Timing: real 0.013s	user 0.007s	sys 0.003s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4453,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:55.741168 26908 maintenance_manager.cc:419] P 0626f87c94e74ed7ab65882331b34fbd: Scheduling MajorDeltaCompactionOp(348c282a3ce14575a7d092c9521a679c): perf score=1.000000
I20260812 06:19:55.954342 26823 maintenance_manager.cc:643] P 0626f87c94e74ed7ab65882331b34fbd: MajorDeltaCompactionOp(348c282a3ce14575a7d092c9521a679c) complete. Timing: real 0.213s	user 0.122s	sys 0.089s 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":1028,"lbm_read_time_us":14356,"lbm_reads_lt_1ms":672,"lbm_write_time_us":33736,"lbm_writes_lt_1ms":643,"mutex_wait_us":65,"peak_mem_usage":75542472,"reinsert_count":0,"update_count":3000}
I20260812 06:19:55.955219 26908 maintenance_manager.cc:419] P 0626f87c94e74ed7ab65882331b34fbd: Scheduling FlushDeltaMemStoresOp(348c282a3ce14575a7d092c9521a679c): perf score=16.079562
I20260812 06:19:56.004567 26823 maintenance_manager.cc:643] P 0626f87c94e74ed7ab65882331b34fbd: FlushDeltaMemStoresOp(348c282a3ce14575a7d092c9521a679c) complete. Timing: real 0.049s	user 0.020s	sys 0.026s Metrics: {"bytes_written":17845751,"delete_count":0,"lbm_write_time_us":21021,"lbm_writes_lt_1ms":438,"reinsert_count":0,"update_count":2175}
I20260812 06:19:56.005200 26908 maintenance_manager.cc:419] P 0626f87c94e74ed7ab65882331b34fbd: Scheduling FlushDeltaMemStoresOp(348c282a3ce14575a7d092c9521a679c): perf score=1.196750
I20260812 06:19:56.026103 26823 maintenance_manager.cc:643] P 0626f87c94e74ed7ab65882331b34fbd: FlushDeltaMemStoresOp(348c282a3ce14575a7d092c9521a679c) complete. Timing: real 0.021s	user 0.008s	sys 0.004s Metrics: {"bytes_written":3077034,"delete_count":0,"lbm_write_time_us":4853,"lbm_writes_lt_1ms":78,"reinsert_count":0,"update_count":375}
I20260812 06:19:56.026599 26908 maintenance_manager.cc:419] P 0626f87c94e74ed7ab65882331b34fbd: Scheduling FlushDeltaMemStoresOp(348c282a3ce14575a7d092c9521a679c): perf score=2.188937
I20260812 06:19:56.036283 26823 maintenance_manager.cc:643] P 0626f87c94e74ed7ab65882331b34fbd: FlushDeltaMemStoresOp(348c282a3ce14575a7d092c9521a679c) complete. Timing: real 0.009s	user 0.004s	sys 0.004s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3604,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:19:56.036736 26908 maintenance_manager.cc:419] P 0626f87c94e74ed7ab65882331b34fbd: Scheduling MajorDeltaCompactionOp(348c282a3ce14575a7d092c9521a679c): perf score=1.000000
I20260812 06:19:56.261901 26823 maintenance_manager.cc:643] P 0626f87c94e74ed7ab65882331b34fbd: MajorDeltaCompactionOp(348c282a3ce14575a7d092c9521a679c) complete. Timing: real 0.225s	user 0.145s	sys 0.080s Metrics: {"cfile_cache_miss":633,"cfile_cache_miss_bytes":28918185,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":290,"lbm_read_time_us":15350,"lbm_reads_lt_1ms":673,"lbm_write_time_us":38192,"lbm_writes_lt_1ms":643,"mutex_wait_us":24,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":16384,"update_count":3000}
I20260812 06:19:56.266543 26908 maintenance_manager.cc:419] P 0626f87c94e74ed7ab65882331b34fbd: Scheduling FlushDeltaMemStoresOp(348c282a3ce14575a7d092c9521a679c): perf score=14.095187
I20260812 06:19:56.308109 26823 maintenance_manager.cc:643] P 0626f87c94e74ed7ab65882331b34fbd: FlushDeltaMemStoresOp(348c282a3ce14575a7d092c9521a679c) complete. Timing: real 0.041s	user 0.031s	sys 0.009s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":18793,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:56.308650 26908 maintenance_manager.cc:419] P 0626f87c94e74ed7ab65882331b34fbd: Scheduling FlushDeltaMemStoresOp(348c282a3ce14575a7d092c9521a679c): perf score=2.188937
I20260812 06:19:56.319988 26823 maintenance_manager.cc:643] P 0626f87c94e74ed7ab65882331b34fbd: FlushDeltaMemStoresOp(348c282a3ce14575a7d092c9521a679c) complete. Timing: real 0.011s	user 0.005s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4392,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:56.320447 26908 maintenance_manager.cc:419] P 0626f87c94e74ed7ab65882331b34fbd: Scheduling MajorDeltaCompactionOp(348c282a3ce14575a7d092c9521a679c): perf score=1.000000
I20260812 06:19:56.509312 26823 maintenance_manager.cc:643] P 0626f87c94e74ed7ab65882331b34fbd: MajorDeltaCompactionOp(348c282a3ce14575a7d092c9521a679c) complete. Timing: real 0.189s	user 0.118s	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":724,"lbm_read_time_us":12089,"lbm_reads_lt_1ms":572,"lbm_write_time_us":32390,"lbm_writes_lt_1ms":543,"mutex_wait_us":26,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":8064,"update_count":2500}
I20260812 06:19:56.509961 26908 maintenance_manager.cc:419] P 0626f87c94e74ed7ab65882331b34fbd: Scheduling FlushDeltaMemStoresOp(348c282a3ce14575a7d092c9521a679c): perf score=14.095187
I20260812 06:19:56.566840 26823 maintenance_manager.cc:643] P 0626f87c94e74ed7ab65882331b34fbd: FlushDeltaMemStoresOp(348c282a3ce14575a7d092c9521a679c) complete. Timing: real 0.057s	user 0.035s	sys 0.011s Metrics: {"bytes_written":16409900,"delete_count":0,"lbm_write_time_us":19552,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:56.567474 26908 maintenance_manager.cc:419] P 0626f87c94e74ed7ab65882331b34fbd: Scheduling FlushDeltaMemStoresOp(348c282a3ce14575a7d092c9521a679c): perf score=2.188937
I20260812 06:19:56.584295 26823 maintenance_manager.cc:643] P 0626f87c94e74ed7ab65882331b34fbd: FlushDeltaMemStoresOp(348c282a3ce14575a7d092c9521a679c) complete. Timing: real 0.017s	user 0.015s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6347,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:56.586306 26908 maintenance_manager.cc:419] P 0626f87c94e74ed7ab65882331b34fbd: Scheduling MajorDeltaCompactionOp(348c282a3ce14575a7d092c9521a679c): perf score=1.000000
I20260812 06:19:56.768927 26823 maintenance_manager.cc:643] P 0626f87c94e74ed7ab65882331b34fbd: MajorDeltaCompactionOp(348c282a3ce14575a7d092c9521a679c) complete. Timing: real 0.182s	user 0.129s	sys 0.051s 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":582,"lbm_read_time_us":13236,"lbm_reads_lt_1ms":572,"lbm_write_time_us":30047,"lbm_writes_lt_1ms":543,"mutex_wait_us":71,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":768,"update_count":2500}
I20260812 06:19:56.769686 26908 maintenance_manager.cc:419] P 0626f87c94e74ed7ab65882331b34fbd: Scheduling FlushDeltaMemStoresOp(348c282a3ce14575a7d092c9521a679c): perf score=14.095187
I20260812 06:19:56.833506 26823 maintenance_manager.cc:643] P 0626f87c94e74ed7ab65882331b34fbd: FlushDeltaMemStoresOp(348c282a3ce14575a7d092c9521a679c) complete. Timing: real 0.064s	user 0.028s	sys 0.023s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":19196,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:56.834075 26908 maintenance_manager.cc:419] P 0626f87c94e74ed7ab65882331b34fbd: Scheduling FlushDeltaMemStoresOp(348c282a3ce14575a7d092c9521a679c): perf score=2.188937
I20260812 06:19:56.844987 26823 maintenance_manager.cc:643] P 0626f87c94e74ed7ab65882331b34fbd: FlushDeltaMemStoresOp(348c282a3ce14575a7d092c9521a679c) complete. Timing: real 0.011s	user 0.009s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4176,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:56.845498 26908 maintenance_manager.cc:419] P 0626f87c94e74ed7ab65882331b34fbd: Scheduling FlushMRSOp(348c282a3ce14575a7d092c9521a679c): perf score=1.000000
I20260812 06:19:56.876786 26823 maintenance_manager.cc:643] P 0626f87c94e74ed7ab65882331b34fbd: FlushMRSOp(348c282a3ce14575a7d092c9521a679c) complete. Timing: real 0.031s	user 0.025s	sys 0.004s Metrics: {"bytes_written":1193509,"cfile_init":1,"dirs.queue_time_us":60,"dirs.run_cpu_time_us":168,"dirs.run_wall_time_us":1191,"drs_written":1,"lbm_read_time_us":42,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1467,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":29,"spinlock_wait_cycles":768}
I20260812 06:19:56.877687 26908 maintenance_manager.cc:419] P 0626f87c94e74ed7ab65882331b34fbd: Scheduling UndoDeltaBlockGCOp(348c282a3ce14575a7d092c9521a679c): 462 bytes on disk
I20260812 06:19:56.878226 26823 maintenance_manager.cc:643] P 0626f87c94e74ed7ab65882331b34fbd: UndoDeltaBlockGCOp(348c282a3ce14575a7d092c9521a679c) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":65,"lbm_reads_lt_1ms":4}
I20260812 06:19:56.878798 26908 maintenance_manager.cc:419] P 0626f87c94e74ed7ab65882331b34fbd: Scheduling MajorDeltaCompactionOp(348c282a3ce14575a7d092c9521a679c): perf score=1.000000
I20260812 06:19:57.071545 26823 maintenance_manager.cc:643] P 0626f87c94e74ed7ab65882331b34fbd: MajorDeltaCompactionOp(348c282a3ce14575a7d092c9521a679c) complete. Timing: real 0.193s	user 0.131s	sys 0.060s 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":596,"lbm_read_time_us":13429,"lbm_reads_lt_1ms":564,"lbm_write_time_us":31032,"lbm_writes_lt_1ms":543,"mutex_wait_us":42,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":17536,"update_count":2500}
I20260812 06:19:57.072213 26908 maintenance_manager.cc:419] P 0626f87c94e74ed7ab65882331b34fbd: Scheduling LogGCOp(348c282a3ce14575a7d092c9521a679c): free 112239323 bytes of WAL
I20260812 06:19:57.072530 26823 log_reader.cc:385] T 348c282a3ce14575a7d092c9521a679c: removed 11 log segments from log reader
I20260812 06:19:57.072608 26823 log.cc:1079] T 348c282a3ce14575a7d092c9521a679c P 0626f87c94e74ed7ab65882331b34fbd: Deleting log segment in path: /tmp/dist-test-tasknV3hQW/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515587845435-26400-0/minicluster-data/ts-0-root/wals/348c282a3ce14575a7d092c9521a679c/wal-000000015 (ops 71-75)
I20260812 06:19:57.072695 26823 log.cc:1079] T 348c282a3ce14575a7d092c9521a679c P 0626f87c94e74ed7ab65882331b34fbd: Deleting log segment in path: /tmp/dist-test-tasknV3hQW/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515587845435-26400-0/minicluster-data/ts-0-root/wals/348c282a3ce14575a7d092c9521a679c/wal-000000016 (ops 76-80)
I20260812 06:19:57.072765 26823 log.cc:1079] T 348c282a3ce14575a7d092c9521a679c P 0626f87c94e74ed7ab65882331b34fbd: Deleting log segment in path: /tmp/dist-test-tasknV3hQW/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515587845435-26400-0/minicluster-data/ts-0-root/wals/348c282a3ce14575a7d092c9521a679c/wal-000000017 (ops 81-85)
I20260812 06:19:57.072850 26823 log.cc:1079] T 348c282a3ce14575a7d092c9521a679c P 0626f87c94e74ed7ab65882331b34fbd: Deleting log segment in path: /tmp/dist-test-tasknV3hQW/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515587845435-26400-0/minicluster-data/ts-0-root/wals/348c282a3ce14575a7d092c9521a679c/wal-000000018 (ops 86-90)
I20260812 06:19:57.072901 26823 log.cc:1079] T 348c282a3ce14575a7d092c9521a679c P 0626f87c94e74ed7ab65882331b34fbd: Deleting log segment in path: /tmp/dist-test-tasknV3hQW/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515587845435-26400-0/minicluster-data/ts-0-root/wals/348c282a3ce14575a7d092c9521a679c/wal-000000019 (ops 91-95)
I20260812 06:19:57.072979 26823 log.cc:1079] T 348c282a3ce14575a7d092c9521a679c P 0626f87c94e74ed7ab65882331b34fbd: Deleting log segment in path: /tmp/dist-test-tasknV3hQW/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515587845435-26400-0/minicluster-data/ts-0-root/wals/348c282a3ce14575a7d092c9521a679c/wal-000000020 (ops 96-100)
I20260812 06:19:57.073024 26823 log.cc:1079] T 348c282a3ce14575a7d092c9521a679c P 0626f87c94e74ed7ab65882331b34fbd: Deleting log segment in path: /tmp/dist-test-tasknV3hQW/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515587845435-26400-0/minicluster-data/ts-0-root/wals/348c282a3ce14575a7d092c9521a679c/wal-000000021 (ops 101-105)
I20260812 06:19:57.073067 26823 log.cc:1079] T 348c282a3ce14575a7d092c9521a679c P 0626f87c94e74ed7ab65882331b34fbd: Deleting log segment in path: /tmp/dist-test-tasknV3hQW/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515587845435-26400-0/minicluster-data/ts-0-root/wals/348c282a3ce14575a7d092c9521a679c/wal-000000022 (ops 106-110)
I20260812 06:19:57.073112 26823 log.cc:1079] T 348c282a3ce14575a7d092c9521a679c P 0626f87c94e74ed7ab65882331b34fbd: Deleting log segment in path: /tmp/dist-test-tasknV3hQW/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515587845435-26400-0/minicluster-data/ts-0-root/wals/348c282a3ce14575a7d092c9521a679c/wal-000000023 (ops 111-114)
I20260812 06:19:57.073194 26823 log.cc:1079] T 348c282a3ce14575a7d092c9521a679c P 0626f87c94e74ed7ab65882331b34fbd: Deleting log segment in path: /tmp/dist-test-tasknV3hQW/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515587845435-26400-0/minicluster-data/ts-0-root/wals/348c282a3ce14575a7d092c9521a679c/wal-000000024 (ops 115-119)
I20260812 06:19:57.073238 26823 log.cc:1079] T 348c282a3ce14575a7d092c9521a679c P 0626f87c94e74ed7ab65882331b34fbd: Deleting log segment in path: /tmp/dist-test-tasknV3hQW/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515587845435-26400-0/minicluster-data/ts-0-root/wals/348c282a3ce14575a7d092c9521a679c/wal-000000025 (ops 120-124)
I20260812 06:19:57.099826 26823 maintenance_manager.cc:643] P 0626f87c94e74ed7ab65882331b34fbd: LogGCOp(348c282a3ce14575a7d092c9521a679c) complete. Timing: real 0.027s	user 0.000s	sys 0.025s Metrics: {}
I20260812 06:19:57.100310 26908 maintenance_manager.cc:419] P 0626f87c94e74ed7ab65882331b34fbd: Scheduling FlushDeltaMemStoresOp(348c282a3ce14575a7d092c9521a679c): perf score=18.063937
I20260812 06:19:57.167313 26823 maintenance_manager.cc:643] P 0626f87c94e74ed7ab65882331b34fbd: FlushDeltaMemStoresOp(348c282a3ce14575a7d092c9521a679c) complete. Timing: real 0.067s	user 0.026s	sys 0.040s Metrics: {"bytes_written":20512317,"delete_count":0,"lbm_write_time_us":26469,"lbm_writes_lt_1ms":503,"reinsert_count":0,"update_count":2500}
I20260812 06:19:57.167840 26908 maintenance_manager.cc:419] P 0626f87c94e74ed7ab65882331b34fbd: Scheduling FlushDeltaMemStoresOp(348c282a3ce14575a7d092c9521a679c): perf score=2.188937
I20260812 06:19:57.178612 26823 maintenance_manager.cc:643] P 0626f87c94e74ed7ab65882331b34fbd: FlushDeltaMemStoresOp(348c282a3ce14575a7d092c9521a679c) complete. Timing: real 0.011s	user 0.006s	sys 0.004s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4183,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:57.179128 26908 maintenance_manager.cc:419] P 0626f87c94e74ed7ab65882331b34fbd: Scheduling MajorDeltaCompactionOp(348c282a3ce14575a7d092c9521a679c): perf score=1.000000
I20260812 06:19:57.389760 26823 maintenance_manager.cc:643] P 0626f87c94e74ed7ab65882331b34fbd: MajorDeltaCompactionOp(348c282a3ce14575a7d092c9521a679c) complete. Timing: real 0.210s	user 0.134s	sys 0.076s Metrics: {"cfile_cache_miss":632,"cfile_cache_miss_bytes":28918098,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":477,"lbm_read_time_us":15475,"lbm_reads_lt_1ms":672,"lbm_write_time_us":37105,"lbm_writes_lt_1ms":643,"mutex_wait_us":32,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":27648,"update_count":3000}
I20260812 06:19:57.390655 26908 maintenance_manager.cc:419] P 0626f87c94e74ed7ab65882331b34fbd: Scheduling FlushDeltaMemStoresOp(348c282a3ce14575a7d092c9521a679c): perf score=14.095187
I20260812 06:19:57.446312 26823 maintenance_manager.cc:643] P 0626f87c94e74ed7ab65882331b34fbd: FlushDeltaMemStoresOp(348c282a3ce14575a7d092c9521a679c) complete. Timing: real 0.055s	user 0.035s	sys 0.017s Metrics: {"bytes_written":16409905,"delete_count":0,"lbm_write_time_us":24501,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:57.446949 26908 maintenance_manager.cc:419] P 0626f87c94e74ed7ab65882331b34fbd: Scheduling FlushDeltaMemStoresOp(348c282a3ce14575a7d092c9521a679c): perf score=2.188937
I20260812 06:19:57.460804 26823 maintenance_manager.cc:643] P 0626f87c94e74ed7ab65882331b34fbd: FlushDeltaMemStoresOp(348c282a3ce14575a7d092c9521a679c) complete. Timing: real 0.014s	user 0.006s	sys 0.005s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5216,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:57.461527 26908 maintenance_manager.cc:419] P 0626f87c94e74ed7ab65882331b34fbd: Scheduling MajorDeltaCompactionOp(348c282a3ce14575a7d092c9521a679c): perf score=1.000000
I20260812 06:19:57.639729 26823 maintenance_manager.cc:643] P 0626f87c94e74ed7ab65882331b34fbd: MajorDeltaCompactionOp(348c282a3ce14575a7d092c9521a679c) complete. Timing: real 0.178s	user 0.134s	sys 0.043s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24815687,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":1235,"lbm_read_time_us":14877,"lbm_reads_lt_1ms":564,"lbm_write_time_us":28201,"lbm_writes_lt_1ms":543,"mutex_wait_us":417,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":11520,"update_count":2500}
I20260812 06:19:57.640375 26908 maintenance_manager.cc:419] P 0626f87c94e74ed7ab65882331b34fbd: Scheduling FlushDeltaMemStoresOp(348c282a3ce14575a7d092c9521a679c): perf score=14.095187
I20260812 06:19:57.702831 26823 maintenance_manager.cc:643] P 0626f87c94e74ed7ab65882331b34fbd: FlushDeltaMemStoresOp(348c282a3ce14575a7d092c9521a679c) complete. Timing: real 0.062s	user 0.015s	sys 0.047s Metrics: {"bytes_written":16409903,"delete_count":0,"lbm_write_time_us":21868,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:57.703441 26908 maintenance_manager.cc:419] P 0626f87c94e74ed7ab65882331b34fbd: Scheduling FlushDeltaMemStoresOp(348c282a3ce14575a7d092c9521a679c): perf score=2.188937
I20260812 06:19:57.714294 26823 maintenance_manager.cc:643] P 0626f87c94e74ed7ab65882331b34fbd: FlushDeltaMemStoresOp(348c282a3ce14575a7d092c9521a679c) complete. Timing: real 0.011s	user 0.005s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4298,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:57.714844 26908 maintenance_manager.cc:419] P 0626f87c94e74ed7ab65882331b34fbd: Scheduling MajorDeltaCompactionOp(348c282a3ce14575a7d092c9521a679c): perf score=1.000000
I20260812 06:19:57.897037 26823 maintenance_manager.cc:643] P 0626f87c94e74ed7ab65882331b34fbd: MajorDeltaCompactionOp(348c282a3ce14575a7d092c9521a679c) complete. Timing: real 0.182s	user 0.123s	sys 0.055s 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":567,"lbm_read_time_us":12582,"lbm_reads_lt_1ms":572,"lbm_write_time_us":32215,"lbm_writes_lt_1ms":543,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":768,"update_count":2500}
I20260812 06:19:57.897688 26908 maintenance_manager.cc:419] P 0626f87c94e74ed7ab65882331b34fbd: Scheduling FlushDeltaMemStoresOp(348c282a3ce14575a7d092c9521a679c): perf score=11.118625
I20260812 06:19:57.935029 26823 maintenance_manager.cc:643] P 0626f87c94e74ed7ab65882331b34fbd: FlushDeltaMemStoresOp(348c282a3ce14575a7d092c9521a679c) complete. Timing: real 0.037s	user 0.030s	sys 0.007s Metrics: {"bytes_written":12717736,"delete_count":0,"lbm_write_time_us":15833,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:19:57.935729 26908 maintenance_manager.cc:419] P 0626f87c94e74ed7ab65882331b34fbd: Scheduling FlushDeltaMemStoresOp(348c282a3ce14575a7d092c9521a679c): perf score=2.188937
I20260812 06:19:57.949780 26823 maintenance_manager.cc:643] P 0626f87c94e74ed7ab65882331b34fbd: FlushDeltaMemStoresOp(348c282a3ce14575a7d092c9521a679c) complete. Timing: real 0.014s	user 0.007s	sys 0.004s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":4729,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:19:57.950814 26908 maintenance_manager.cc:419] P 0626f87c94e74ed7ab65882331b34fbd: Scheduling MajorDeltaCompactionOp(348c282a3ce14575a7d092c9521a679c): perf score=1.000000
I20260812 06:19:58.132555 26823 maintenance_manager.cc:643] P 0626f87c94e74ed7ab65882331b34fbd: MajorDeltaCompactionOp(348c282a3ce14575a7d092c9521a679c) complete. Timing: real 0.182s	user 0.125s	sys 0.049s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20713264,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":646,"lbm_read_time_us":10024,"lbm_reads_lt_1ms":464,"lbm_write_time_us":28326,"lbm_writes_lt_1ms":443,"mutex_wait_us":92,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":1792,"update_count":2000}
I20260812 06:19:58.133303 26908 maintenance_manager.cc:419] P 0626f87c94e74ed7ab65882331b34fbd: Scheduling FlushDeltaMemStoresOp(348c282a3ce14575a7d092c9521a679c): perf score=14.095187
I20260812 06:19:58.185503 26823 maintenance_manager.cc:643] P 0626f87c94e74ed7ab65882331b34fbd: FlushDeltaMemStoresOp(348c282a3ce14575a7d092c9521a679c) complete. Timing: real 0.052s	user 0.023s	sys 0.023s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":22270,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:58.186017 26908 maintenance_manager.cc:419] P 0626f87c94e74ed7ab65882331b34fbd: Scheduling FlushDeltaMemStoresOp(348c282a3ce14575a7d092c9521a679c): perf score=2.188937
I20260812 06:19:58.197254 26823 maintenance_manager.cc:643] P 0626f87c94e74ed7ab65882331b34fbd: FlushDeltaMemStoresOp(348c282a3ce14575a7d092c9521a679c) complete. Timing: real 0.011s	user 0.004s	sys 0.004s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":3936,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:58.197738 26908 maintenance_manager.cc:419] P 0626f87c94e74ed7ab65882331b34fbd: Scheduling MajorDeltaCompactionOp(348c282a3ce14575a7d092c9521a679c): perf score=1.000000
I20260812 06:19:58.341423 26823 maintenance_manager.cc:643] P 0626f87c94e74ed7ab65882331b34fbd: MajorDeltaCompactionOp(348c282a3ce14575a7d092c9521a679c) complete. Timing: real 0.143s	user 0.104s	sys 0.032s 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":425,"lbm_read_time_us":8696,"lbm_reads_lt_1ms":572,"lbm_write_time_us":27717,"lbm_writes_lt_1ms":543,"mutex_wait_us":87,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":7424,"update_count":2500}
I20260812 06:19:58.342239 26908 maintenance_manager.cc:419] P 0626f87c94e74ed7ab65882331b34fbd: Scheduling FlushDeltaMemStoresOp(348c282a3ce14575a7d092c9521a679c): perf score=14.095187
I20260812 06:19:58.392544 26823 maintenance_manager.cc:643] P 0626f87c94e74ed7ab65882331b34fbd: FlushDeltaMemStoresOp(348c282a3ce14575a7d092c9521a679c) complete. Timing: real 0.050s	user 0.024s	sys 0.015s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":18249,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:58.393065 26908 maintenance_manager.cc:419] P 0626f87c94e74ed7ab65882331b34fbd: Scheduling FlushDeltaMemStoresOp(348c282a3ce14575a7d092c9521a679c): perf score=2.188937
I20260812 06:19:58.404670 26823 maintenance_manager.cc:643] P 0626f87c94e74ed7ab65882331b34fbd: FlushDeltaMemStoresOp(348c282a3ce14575a7d092c9521a679c) complete. Timing: real 0.011s	user 0.009s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4125,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:58.405325 26908 maintenance_manager.cc:419] P 0626f87c94e74ed7ab65882331b34fbd: Scheduling FlushMRSOp(348c282a3ce14575a7d092c9521a679c): perf score=1.000000
I20260812 06:19:58.438726 26823 maintenance_manager.cc:643] P 0626f87c94e74ed7ab65882331b34fbd: FlushMRSOp(348c282a3ce14575a7d092c9521a679c) complete. Timing: real 0.033s	user 0.028s	sys 0.005s Metrics: {"bytes_written":1234475,"cfile_init":1,"dirs.queue_time_us":69,"dirs.run_cpu_time_us":249,"dirs.run_wall_time_us":1220,"drs_written":1,"lbm_read_time_us":43,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1573,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":30}
I20260812 06:19:58.439440 26908 maintenance_manager.cc:419] P 0626f87c94e74ed7ab65882331b34fbd: Scheduling LogGCOp(348c282a3ce14575a7d092c9521a679c): free 129320758 bytes of WAL
I20260812 06:19:58.439713 26823 log_reader.cc:385] T 348c282a3ce14575a7d092c9521a679c: removed 13 log segments from log reader
I20260812 06:19:58.439785 26823 log.cc:1079] T 348c282a3ce14575a7d092c9521a679c P 0626f87c94e74ed7ab65882331b34fbd: Deleting log segment in path: /tmp/dist-test-tasknV3hQW/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515587845435-26400-0/minicluster-data/ts-0-root/wals/348c282a3ce14575a7d092c9521a679c/wal-000000026 (ops 125-129)
I20260812 06:19:58.439888 26823 log.cc:1079] T 348c282a3ce14575a7d092c9521a679c P 0626f87c94e74ed7ab65882331b34fbd: Deleting log segment in path: /tmp/dist-test-tasknV3hQW/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515587845435-26400-0/minicluster-data/ts-0-root/wals/348c282a3ce14575a7d092c9521a679c/wal-000000027 (ops 130-134)
I20260812 06:19:58.439929 26823 log.cc:1079] T 348c282a3ce14575a7d092c9521a679c P 0626f87c94e74ed7ab65882331b34fbd: Deleting log segment in path: /tmp/dist-test-tasknV3hQW/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515587845435-26400-0/minicluster-data/ts-0-root/wals/348c282a3ce14575a7d092c9521a679c/wal-000000028 (ops 135-138)
I20260812 06:19:58.439970 26823 log.cc:1079] T 348c282a3ce14575a7d092c9521a679c P 0626f87c94e74ed7ab65882331b34fbd: Deleting log segment in path: /tmp/dist-test-tasknV3hQW/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515587845435-26400-0/minicluster-data/ts-0-root/wals/348c282a3ce14575a7d092c9521a679c/wal-000000029 (ops 139-143)
I20260812 06:19:58.440009 26823 log.cc:1079] T 348c282a3ce14575a7d092c9521a679c P 0626f87c94e74ed7ab65882331b34fbd: Deleting log segment in path: /tmp/dist-test-tasknV3hQW/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515587845435-26400-0/minicluster-data/ts-0-root/wals/348c282a3ce14575a7d092c9521a679c/wal-000000030 (ops 144-148)
I20260812 06:19:58.440048 26823 log.cc:1079] T 348c282a3ce14575a7d092c9521a679c P 0626f87c94e74ed7ab65882331b34fbd: Deleting log segment in path: /tmp/dist-test-tasknV3hQW/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515587845435-26400-0/minicluster-data/ts-0-root/wals/348c282a3ce14575a7d092c9521a679c/wal-000000031 (ops 149-153)
I20260812 06:19:58.440088 26823 log.cc:1079] T 348c282a3ce14575a7d092c9521a679c P 0626f87c94e74ed7ab65882331b34fbd: Deleting log segment in path: /tmp/dist-test-tasknV3hQW/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515587845435-26400-0/minicluster-data/ts-0-root/wals/348c282a3ce14575a7d092c9521a679c/wal-000000032 (ops 154-158)
I20260812 06:19:58.440126 26823 log.cc:1079] T 348c282a3ce14575a7d092c9521a679c P 0626f87c94e74ed7ab65882331b34fbd: Deleting log segment in path: /tmp/dist-test-tasknV3hQW/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515587845435-26400-0/minicluster-data/ts-0-root/wals/348c282a3ce14575a7d092c9521a679c/wal-000000033 (ops 159-162)
I20260812 06:19:58.440164 26823 log.cc:1079] T 348c282a3ce14575a7d092c9521a679c P 0626f87c94e74ed7ab65882331b34fbd: Deleting log segment in path: /tmp/dist-test-tasknV3hQW/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515587845435-26400-0/minicluster-data/ts-0-root/wals/348c282a3ce14575a7d092c9521a679c/wal-000000034 (ops 163-167)
I20260812 06:19:58.440202 26823 log.cc:1079] T 348c282a3ce14575a7d092c9521a679c P 0626f87c94e74ed7ab65882331b34fbd: Deleting log segment in path: /tmp/dist-test-tasknV3hQW/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515587845435-26400-0/minicluster-data/ts-0-root/wals/348c282a3ce14575a7d092c9521a679c/wal-000000035 (ops 168-172)
I20260812 06:19:58.440241 26823 log.cc:1079] T 348c282a3ce14575a7d092c9521a679c P 0626f87c94e74ed7ab65882331b34fbd: Deleting log segment in path: /tmp/dist-test-tasknV3hQW/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515587845435-26400-0/minicluster-data/ts-0-root/wals/348c282a3ce14575a7d092c9521a679c/wal-000000036 (ops 173-177)
I20260812 06:19:58.440279 26823 log.cc:1079] T 348c282a3ce14575a7d092c9521a679c P 0626f87c94e74ed7ab65882331b34fbd: Deleting log segment in path: /tmp/dist-test-tasknV3hQW/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515587845435-26400-0/minicluster-data/ts-0-root/wals/348c282a3ce14575a7d092c9521a679c/wal-000000037 (ops 178-182)
I20260812 06:19:58.440315 26823 log.cc:1079] T 348c282a3ce14575a7d092c9521a679c P 0626f87c94e74ed7ab65882331b34fbd: Deleting log segment in path: /tmp/dist-test-tasknV3hQW/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515587845435-26400-0/minicluster-data/ts-0-root/wals/348c282a3ce14575a7d092c9521a679c/wal-000000038 (ops 183-187)
I20260812 06:19:58.466943 26823 maintenance_manager.cc:643] P 0626f87c94e74ed7ab65882331b34fbd: LogGCOp(348c282a3ce14575a7d092c9521a679c) complete. Timing: real 0.027s	user 0.000s	sys 0.027s Metrics: {}
I20260812 06:19:58.467689 26908 maintenance_manager.cc:419] P 0626f87c94e74ed7ab65882331b34fbd: Scheduling UndoDeltaBlockGCOp(348c282a3ce14575a7d092c9521a679c): 473 bytes on disk
I20260812 06:19:58.468169 26823 maintenance_manager.cc:643] P 0626f87c94e74ed7ab65882331b34fbd: UndoDeltaBlockGCOp(348c282a3ce14575a7d092c9521a679c) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":54,"lbm_reads_lt_1ms":4}
I20260812 06:19:58.468763 26908 maintenance_manager.cc:419] P 0626f87c94e74ed7ab65882331b34fbd: Scheduling FlushDeltaMemStoresOp(348c282a3ce14575a7d092c9521a679c): perf score=5.165500
I20260812 06:19:58.490047 26823 maintenance_manager.cc:643] P 0626f87c94e74ed7ab65882331b34fbd: FlushDeltaMemStoresOp(348c282a3ce14575a7d092c9521a679c) complete. Timing: real 0.021s	user 0.003s	sys 0.015s Metrics: {"bytes_written":6810257,"delete_count":0,"lbm_write_time_us":8958,"lbm_writes_lt_1ms":169,"reinsert_count":0,"update_count":830}
I20260812 06:19:58.490599 26908 maintenance_manager.cc:419] P 0626f87c94e74ed7ab65882331b34fbd: Scheduling FlushDeltaMemStoresOp(348c282a3ce14575a7d092c9521a679c): perf score=1.000000
I20260812 06:19:58.496887 26823 maintenance_manager.cc:643] P 0626f87c94e74ed7ab65882331b34fbd: FlushDeltaMemStoresOp(348c282a3ce14575a7d092c9521a679c) complete. Timing: real 0.006s	user 0.004s	sys 0.001s Metrics: {"bytes_written":1395002,"delete_count":0,"lbm_write_time_us":1479,"lbm_writes_lt_1ms":37,"reinsert_count":0,"update_count":170}
I20260812 06:19:58.497368 26908 maintenance_manager.cc:419] P 0626f87c94e74ed7ab65882331b34fbd: Scheduling MajorDeltaCompactionOp(348c282a3ce14575a7d092c9521a679c): perf score=1.000000
I20260812 06:19:58.675915 26823 maintenance_manager.cc:643] P 0626f87c94e74ed7ab65882331b34fbd: MajorDeltaCompactionOp(348c282a3ce14575a7d092c9521a679c) complete. Timing: real 0.178s	user 0.136s	sys 0.042s Metrics: {"cfile_cache_miss":734,"cfile_cache_miss_bytes":33020682,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":907,"lbm_read_time_us":13622,"lbm_reads_lt_1ms":774,"lbm_write_time_us":38367,"lbm_writes_lt_1ms":743,"mutex_wait_us":89,"peak_mem_usage":87969044,"reinsert_count":0,"spinlock_wait_cycles":1920,"thread_start_us":80,"threads_started":1,"update_count":3500}
I20260812 06:19:58.676717 26908 maintenance_manager.cc:419] P 0626f87c94e74ed7ab65882331b34fbd: Scheduling FlushDeltaMemStoresOp(348c282a3ce14575a7d092c9521a679c): perf score=14.095187
I20260812 06:19:58.722455 26823 maintenance_manager.cc:643] P 0626f87c94e74ed7ab65882331b34fbd: FlushDeltaMemStoresOp(348c282a3ce14575a7d092c9521a679c) complete. Timing: real 0.045s	user 0.037s	sys 0.008s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":20121,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:58.723037 26908 maintenance_manager.cc:419] P 0626f87c94e74ed7ab65882331b34fbd: Scheduling FlushDeltaMemStoresOp(348c282a3ce14575a7d092c9521a679c): perf score=2.188937
I20260812 06:19:58.736768 26823 maintenance_manager.cc:643] P 0626f87c94e74ed7ab65882331b34fbd: FlushDeltaMemStoresOp(348c282a3ce14575a7d092c9521a679c) complete. Timing: real 0.014s	user 0.000s	sys 0.011s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5110,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:58.737237 26908 maintenance_manager.cc:419] P 0626f87c94e74ed7ab65882331b34fbd: Scheduling MajorDeltaCompactionOp(348c282a3ce14575a7d092c9521a679c): perf score=1.000000
I20260812 06:19:58.759168 26400 heavy-update-compaction-itest.cc:229] Time spent updating: real 5.073s	user 1.881s	sys 0.183s
I20260812 06:19:58.825045 26400 heavy-update-compaction-itest.cc:265] Time spent scanning: real 0.065s	user 0.001s	sys 0.000s
I20260812 06:19:58.825613 26400 tablet_server.cc:179] TabletServer@127.25.200.1:0 shutting down...
I20260812 06:19:58.883054 26823 maintenance_manager.cc:643] P 0626f87c94e74ed7ab65882331b34fbd: MajorDeltaCompactionOp(348c282a3ce14575a7d092c9521a679c) complete. Timing: real 0.146s	user 0.117s	sys 0.028s 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":810,"lbm_read_time_us":11687,"lbm_reads_lt_1ms":568,"lbm_write_time_us":29341,"lbm_writes_lt_1ms":543,"mutex_wait_us":284,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":17152,"update_count":2500}
I20260812 06:19:58.883787 26400 ts_tablet_manager.cc:1507] Shutting down tablet manager...
I20260812 06:19:58.884027 26400 tablet_replica.cc:333] T 348c282a3ce14575a7d092c9521a679c P 0626f87c94e74ed7ab65882331b34fbd: stopping tablet replica
I20260812 06:19:58.884199 26400 raft_consensus.cc:2243] T 348c282a3ce14575a7d092c9521a679c P 0626f87c94e74ed7ab65882331b34fbd [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:19:58.895594 26400 raft_consensus.cc:2272] T 348c282a3ce14575a7d092c9521a679c P 0626f87c94e74ed7ab65882331b34fbd [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:19:58.900148 26400 tablet_server.cc:196] TabletServer@127.25.200.1:0 shutdown complete.
I20260812 06:19:58.928036 26400 master.cc:562] Master@127.25.200.62:37001 shutting down...
I20260812 06:19:58.931540 26400 raft_consensus.cc:2243] T 00000000000000000000000000000000 P 7ee42b1bd3ba4f52967050a3b11e8d57 [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:19:58.931746 26400 raft_consensus.cc:2272] T 00000000000000000000000000000000 P 7ee42b1bd3ba4f52967050a3b11e8d57 [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:19:58.931851 26400 tablet_replica.cc:333] T 00000000000000000000000000000000 P 7ee42b1bd3ba4f52967050a3b11e8d57: stopping tablet replica
I20260812 06:19:58.944095 26400 master.cc:584] Master@127.25.200.62:37001 shutdown complete.
[       OK ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/1 (5549 ms)
[----------] 2 tests from EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy (11180 ms total)

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