[==========] 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:24.956727 24506 internal_mini_cluster.cc:156] Creating distributed mini masters. Addrs: 127.23.238.190:39379
I20260812 06:19:24.957906 24506 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:24.958583 24506 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:19:24.965811 24512 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:24.965870 24506 server_base.cc:1061] running on GCE node
W20260812 06:19:24.965811 24517 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:24.966109 24513 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:24.966668 24506 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:19:24.966799 24506 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:24.966847 24506 hybrid_clock.cc:648] HybridClock initialized: now 1786515564966845 us; error 0 us; skew 500 ppm
I20260812 06:19:24.969239 24506 webserver.cc:533] Webserver started at http://127.23.238.190:41347/ using document root <none> and password file <none>
I20260812 06:19:24.969919 24506 fs_manager.cc:362] Metadata directory not provided
I20260812 06:19:24.969990 24506 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:19:24.970270 24506 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:19:24.972210 24506 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskseRmjK/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515564944993-24506-0/minicluster-data/master-0-root/instance:
uuid: "091d44e105654242be64d4d27238da9d"
format_stamp: "Formatted at 2026-08-12 06:19:24 on dist-test-slave-sb2z"
I20260812 06:19:24.976114 24506 fs_manager.cc:696] Time spent creating directory manager: real 0.003s	user 0.003s	sys 0.001s
I20260812 06:19:24.978439 24526 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:24.979641 24506 fs_manager.cc:730] Time spent opening block manager: real 0.002s	user 0.003s	sys 0.000s
I20260812 06:19:24.979787 24506 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskseRmjK/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515564944993-24506-0/minicluster-data/master-0-root
uuid: "091d44e105654242be64d4d27238da9d"
format_stamp: "Formatted at 2026-08-12 06:19:24 on dist-test-slave-sb2z"
I20260812 06:19:24.979914 24506 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskseRmjK/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515564944993-24506-0/minicluster-data/master-0-root
metadata directory: /tmp/dist-test-taskseRmjK/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515564944993-24506-0/minicluster-data/master-0-root
1 data directories: /tmp/dist-test-taskseRmjK/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515564944993-24506-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:24.993680 24506 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:19:24.994392 24506 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:24.994596 24506 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:19:25.002815 24506 rpc_server.cc:307] RPC server started. Bound to: 127.23.238.190:39379
I20260812 06:19:25.002908 24612 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.23.238.190:39379 every 8 connection(s)
I20260812 06:19:25.005442 24613 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:25.011880 24613 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P 091d44e105654242be64d4d27238da9d: Bootstrap starting.
I20260812 06:19:25.014532 24613 tablet_bootstrap.cc:654] T 00000000000000000000000000000000 P 091d44e105654242be64d4d27238da9d: Neither blocks nor log segments found. Creating new log.
I20260812 06:19:25.015650 24613 log.cc:826] T 00000000000000000000000000000000 P 091d44e105654242be64d4d27238da9d: Log is configured to *not* fsync() on all Append() calls
I20260812 06:19:25.017812 24613 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P 091d44e105654242be64d4d27238da9d: No bootstrap required, opened a new log
I20260812 06:19:25.021131 24613 raft_consensus.cc:359] T 00000000000000000000000000000000 P 091d44e105654242be64d4d27238da9d [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "091d44e105654242be64d4d27238da9d" member_type: VOTER }
I20260812 06:19:25.021337 24613 raft_consensus.cc:385] T 00000000000000000000000000000000 P 091d44e105654242be64d4d27238da9d [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:19:25.021418 24613 raft_consensus.cc:740] T 00000000000000000000000000000000 P 091d44e105654242be64d4d27238da9d [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: 091d44e105654242be64d4d27238da9d, State: Initialized, Role: FOLLOWER
I20260812 06:19:25.022141 24613 consensus_queue.cc:260] T 00000000000000000000000000000000 P 091d44e105654242be64d4d27238da9d [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: "091d44e105654242be64d4d27238da9d" member_type: VOTER }
I20260812 06:19:25.022320 24613 raft_consensus.cc:399] T 00000000000000000000000000000000 P 091d44e105654242be64d4d27238da9d [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:19:25.022408 24613 raft_consensus.cc:493] T 00000000000000000000000000000000 P 091d44e105654242be64d4d27238da9d [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:19:25.022547 24613 raft_consensus.cc:3060] T 00000000000000000000000000000000 P 091d44e105654242be64d4d27238da9d [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:19:25.023474 24613 raft_consensus.cc:515] T 00000000000000000000000000000000 P 091d44e105654242be64d4d27238da9d [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "091d44e105654242be64d4d27238da9d" member_type: VOTER }
I20260812 06:19:25.024013 24613 leader_election.cc:304] T 00000000000000000000000000000000 P 091d44e105654242be64d4d27238da9d [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: 091d44e105654242be64d4d27238da9d; no voters: 
I20260812 06:19:25.024382 24613 leader_election.cc:290] T 00000000000000000000000000000000 P 091d44e105654242be64d4d27238da9d [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:19:25.024597 24617 raft_consensus.cc:2804] T 00000000000000000000000000000000 P 091d44e105654242be64d4d27238da9d [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:19:25.024899 24617 raft_consensus.cc:697] T 00000000000000000000000000000000 P 091d44e105654242be64d4d27238da9d [term 1 LEADER]: Becoming Leader. State: Replica: 091d44e105654242be64d4d27238da9d, State: Running, Role: LEADER
I20260812 06:19:25.025476 24617 consensus_queue.cc:237] T 00000000000000000000000000000000 P 091d44e105654242be64d4d27238da9d [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: "091d44e105654242be64d4d27238da9d" member_type: VOTER }
I20260812 06:19:25.025579 24613 sys_catalog.cc:565] T 00000000000000000000000000000000 P 091d44e105654242be64d4d27238da9d [sys.catalog]: configured and running, proceeding with master startup.
I20260812 06:19:25.027714 24619 sys_catalog.cc:455] T 00000000000000000000000000000000 P 091d44e105654242be64d4d27238da9d [sys.catalog]: SysCatalogTable state changed. Reason: New leader 091d44e105654242be64d4d27238da9d. Latest consensus state: current_term: 1 leader_uuid: "091d44e105654242be64d4d27238da9d" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "091d44e105654242be64d4d27238da9d" member_type: VOTER } }
I20260812 06:19:25.027882 24619 sys_catalog.cc:458] T 00000000000000000000000000000000 P 091d44e105654242be64d4d27238da9d [sys.catalog]: This master's current role is: LEADER
I20260812 06:19:25.028115 24506 internal_mini_cluster.cc:184] Waiting to initialize catalog manager on master 0
I20260812 06:19:25.028198 24618 sys_catalog.cc:455] T 00000000000000000000000000000000 P 091d44e105654242be64d4d27238da9d [sys.catalog]: SysCatalogTable state changed. Reason: RaftConsensus started. Latest consensus state: current_term: 1 leader_uuid: "091d44e105654242be64d4d27238da9d" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "091d44e105654242be64d4d27238da9d" member_type: VOTER } }
I20260812 06:19:25.028282 24618 sys_catalog.cc:458] T 00000000000000000000000000000000 P 091d44e105654242be64d4d27238da9d [sys.catalog]: This master's current role is: LEADER
W20260812 06:19:25.030583 24631 catalog_manager.cc:1594] T 00000000000000000000000000000000 P 091d44e105654242be64d4d27238da9d: loading cluster ID for follower catalog manager: Not found: cluster ID entry not found
W20260812 06:19:25.030671 24631 catalog_manager.cc:883] Not found: cluster ID entry not found: failed to prepare follower catalog manager, will retry
I20260812 06:19:25.030773 24632 catalog_manager.cc:1511] Loading table and tablet metadata into memory...
I20260812 06:19:25.031677 24632 catalog_manager.cc:1520] Initializing Kudu cluster ID...
I20260812 06:19:25.036636 24632 catalog_manager.cc:1383] Generated new cluster ID: 71282d2aa1964bc895412ef1af5efb3c
I20260812 06:19:25.036718 24632 catalog_manager.cc:1531] Initializing Kudu internal certificate authority...
I20260812 06:19:25.048251 24632 catalog_manager.cc:1406] Generated new certificate authority record
I20260812 06:19:25.049185 24632 catalog_manager.cc:1540] Loading token signing keys...
I20260812 06:19:25.063139 24632 catalog_manager.cc:6092] T 00000000000000000000000000000000 P 091d44e105654242be64d4d27238da9d: Generated new TSK 0
I20260812 06:19:25.063964 24632 catalog_manager.cc:1550] Initializing in-progress tserver states...
I20260812 06:19:25.093159 24506 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:19:25.096141 24643 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:25.096187 24638 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:25.096176 24637 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:25.096763 24506 server_base.cc:1061] running on GCE node
I20260812 06:19:25.096984 24506 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:19:25.097026 24506 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:25.097043 24506 hybrid_clock.cc:648] HybridClock initialized: now 1786515565097043 us; error 0 us; skew 500 ppm
I20260812 06:19:25.098073 24506 webserver.cc:533] Webserver started at http://127.23.238.129:44419/ using document root <none> and password file <none>
I20260812 06:19:25.098274 24506 fs_manager.cc:362] Metadata directory not provided
I20260812 06:19:25.098322 24506 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:19:25.098426 24506 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:19:25.098837 24506 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskseRmjK/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515564944993-24506-0/minicluster-data/ts-0-root/instance:
uuid: "2d337fafbc4d4b31a1e02abeb1082be3"
format_stamp: "Formatted at 2026-08-12 06:19:25 on dist-test-slave-sb2z"
I20260812 06:19:25.100518 24506 fs_manager.cc:696] Time spent creating directory manager: real 0.001s	user 0.002s	sys 0.000s
I20260812 06:19:25.101629 24651 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:25.101979 24506 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.001s	sys 0.000s
I20260812 06:19:25.102126 24506 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskseRmjK/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515564944993-24506-0/minicluster-data/ts-0-root
uuid: "2d337fafbc4d4b31a1e02abeb1082be3"
format_stamp: "Formatted at 2026-08-12 06:19:25 on dist-test-slave-sb2z"
I20260812 06:19:25.102221 24506 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskseRmjK/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515564944993-24506-0/minicluster-data/ts-0-root
metadata directory: /tmp/dist-test-taskseRmjK/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515564944993-24506-0/minicluster-data/ts-0-root
1 data directories: /tmp/dist-test-taskseRmjK/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515564944993-24506-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:25.114686 24506 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:19:25.115429 24506 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:19:25.116051 24506 txn_system_client.cc:432] TxnSystemClient initialization is disabled...
I20260812 06:19:25.116945 24506 ts_tablet_manager.cc:585] Loaded tablet metadata (0 total tablets, 0 live tablets)
I20260812 06:19:25.117025 24506 ts_tablet_manager.cc:531] Time spent load tablet metadata: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:19:25.117115 24506 ts_tablet_manager.cc:616] Registered 0 tablets
I20260812 06:19:25.117159 24506 ts_tablet_manager.cc:595] Time spent register tablets: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:19:25.124395 24506 rpc_server.cc:307] RPC server started. Bound to: 127.23.238.129:34901
I20260812 06:19:25.124478 24751 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.23.238.129:34901 every 8 connection(s)
I20260812 06:19:25.139359 24754 heartbeater.cc:344] Connected to a master server at 127.23.238.190:39379
I20260812 06:19:25.139696 24754 heartbeater.cc:461] Registering TS with master...
I20260812 06:19:25.140298 24754 heartbeater.cc:507] Master 127.23.238.190:39379 requested a full tablet report, sending...
I20260812 06:19:25.142030 24550 ts_manager.cc:194] Registered new tserver with Master: 2d337fafbc4d4b31a1e02abeb1082be3 (127.23.238.129:34901)
I20260812 06:19:25.142268 24506 internal_mini_cluster.cc:371] 1 TS(s) registered with all masters after 0.017141144s
I20260812 06:19:25.143687 24550 master_service.cc:502] Signed X509 certificate for tserver {username='slave'} at 127.0.0.1:48198
I20260812 06:19:25.153180 24550 catalog_manager.cc:2283] Servicing CreateTable request from {username='slave'} at 127.0.0.1:48206:
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:25.169987 24696 tablet_service.cc:1511] Processing CreateTablet for tablet 68567d8f78d34c5fae216e9eea115f87 (DEFAULT_TABLE table=heavy-update-compaction-test [id=75e031fb56e4448bad26e68c07035539]), partition=
I20260812 06:19:25.170544 24696 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet 68567d8f78d34c5fae216e9eea115f87. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:19:25.173488 24774 tablet_bootstrap.cc:492] T 68567d8f78d34c5fae216e9eea115f87 P 2d337fafbc4d4b31a1e02abeb1082be3: Bootstrap starting.
I20260812 06:19:25.174860 24774 tablet_bootstrap.cc:654] T 68567d8f78d34c5fae216e9eea115f87 P 2d337fafbc4d4b31a1e02abeb1082be3: Neither blocks nor log segments found. Creating new log.
I20260812 06:19:25.176169 24774 tablet_bootstrap.cc:492] T 68567d8f78d34c5fae216e9eea115f87 P 2d337fafbc4d4b31a1e02abeb1082be3: No bootstrap required, opened a new log
I20260812 06:19:25.176455 24774 ts_tablet_manager.cc:1403] T 68567d8f78d34c5fae216e9eea115f87 P 2d337fafbc4d4b31a1e02abeb1082be3: Time spent bootstrapping tablet: real 0.003s	user 0.003s	sys 0.000s
I20260812 06:19:25.177194 24774 raft_consensus.cc:359] T 68567d8f78d34c5fae216e9eea115f87 P 2d337fafbc4d4b31a1e02abeb1082be3 [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "2d337fafbc4d4b31a1e02abeb1082be3" member_type: VOTER last_known_addr { host: "127.23.238.129" port: 34901 } }
I20260812 06:19:25.177332 24774 raft_consensus.cc:385] T 68567d8f78d34c5fae216e9eea115f87 P 2d337fafbc4d4b31a1e02abeb1082be3 [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:19:25.177393 24774 raft_consensus.cc:740] T 68567d8f78d34c5fae216e9eea115f87 P 2d337fafbc4d4b31a1e02abeb1082be3 [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: 2d337fafbc4d4b31a1e02abeb1082be3, State: Initialized, Role: FOLLOWER
I20260812 06:19:25.177574 24774 consensus_queue.cc:260] T 68567d8f78d34c5fae216e9eea115f87 P 2d337fafbc4d4b31a1e02abeb1082be3 [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: "2d337fafbc4d4b31a1e02abeb1082be3" member_type: VOTER last_known_addr { host: "127.23.238.129" port: 34901 } }
I20260812 06:19:25.177691 24774 raft_consensus.cc:399] T 68567d8f78d34c5fae216e9eea115f87 P 2d337fafbc4d4b31a1e02abeb1082be3 [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:19:25.177752 24774 raft_consensus.cc:493] T 68567d8f78d34c5fae216e9eea115f87 P 2d337fafbc4d4b31a1e02abeb1082be3 [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:19:25.177820 24774 raft_consensus.cc:3060] T 68567d8f78d34c5fae216e9eea115f87 P 2d337fafbc4d4b31a1e02abeb1082be3 [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:19:25.178684 24774 raft_consensus.cc:515] T 68567d8f78d34c5fae216e9eea115f87 P 2d337fafbc4d4b31a1e02abeb1082be3 [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "2d337fafbc4d4b31a1e02abeb1082be3" member_type: VOTER last_known_addr { host: "127.23.238.129" port: 34901 } }
I20260812 06:19:25.178861 24774 leader_election.cc:304] T 68567d8f78d34c5fae216e9eea115f87 P 2d337fafbc4d4b31a1e02abeb1082be3 [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: 2d337fafbc4d4b31a1e02abeb1082be3; no voters: 
I20260812 06:19:25.179153 24774 leader_election.cc:290] T 68567d8f78d34c5fae216e9eea115f87 P 2d337fafbc4d4b31a1e02abeb1082be3 [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:19:25.179286 24776 raft_consensus.cc:2804] T 68567d8f78d34c5fae216e9eea115f87 P 2d337fafbc4d4b31a1e02abeb1082be3 [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:19:25.179518 24776 raft_consensus.cc:697] T 68567d8f78d34c5fae216e9eea115f87 P 2d337fafbc4d4b31a1e02abeb1082be3 [term 1 LEADER]: Becoming Leader. State: Replica: 2d337fafbc4d4b31a1e02abeb1082be3, State: Running, Role: LEADER
I20260812 06:19:25.179665 24774 ts_tablet_manager.cc:1434] T 68567d8f78d34c5fae216e9eea115f87 P 2d337fafbc4d4b31a1e02abeb1082be3: Time spent starting tablet: real 0.003s	user 0.003s	sys 0.000s
I20260812 06:19:25.179773 24776 consensus_queue.cc:237] T 68567d8f78d34c5fae216e9eea115f87 P 2d337fafbc4d4b31a1e02abeb1082be3 [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: "2d337fafbc4d4b31a1e02abeb1082be3" member_type: VOTER last_known_addr { host: "127.23.238.129" port: 34901 } }
I20260812 06:19:25.179958 24754 heartbeater.cc:499] Master 127.23.238.190:39379 was elected leader, sending a full tablet report...
I20260812 06:19:25.182871 24550 catalog_manager.cc:5719] T 68567d8f78d34c5fae216e9eea115f87 P 2d337fafbc4d4b31a1e02abeb1082be3 reported cstate change: term changed from 0 to 1, leader changed from <none> to 2d337fafbc4d4b31a1e02abeb1082be3 (127.23.238.129). New cstate: current_term: 1 leader_uuid: "2d337fafbc4d4b31a1e02abeb1082be3" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "2d337fafbc4d4b31a1e02abeb1082be3" member_type: VOTER last_known_addr { host: "127.23.238.129" port: 34901 } health_report { overall_health: HEALTHY } } }
I20260812 06:19:25.255875 24506 heavy-update-compaction-itest.cc:215] Time spent inserting: real 0.065s	user 0.020s	sys 0.008s
I20260812 06:19:25.375761 24755 maintenance_manager.cc:419] P 2d337fafbc4d4b31a1e02abeb1082be3: Scheduling FlushMRSOp(68567d8f78d34c5fae216e9eea115f87): perf score=11.117440
I20260812 06:19:25.541330 24657 maintenance_manager.cc:643] P 2d337fafbc4d4b31a1e02abeb1082be3: FlushMRSOp(68567d8f78d34c5fae216e9eea115f87) complete. Timing: real 0.165s	user 0.134s	sys 0.029s Metrics: {"bytes_written":11897249,"cfile_init":1,"compiler_manager_pool.queue_time_us":261,"delete_count":0,"dirs.queue_time_us":108,"dirs.run_cpu_time_us":325,"dirs.run_wall_time_us":1009,"drs_written":1,"lbm_read_time_us":85,"lbm_reads_lt_1ms":4,"lbm_write_time_us":36748,"lbm_writes_lt_1ms":557,"peak_mem_usage":0,"reinsert_count":0,"rows_written":103,"thread_start_us":164,"threads_started":1,"update_count":1450}
I20260812 06:19:25.542639 24755 maintenance_manager.cc:419] P 2d337fafbc4d4b31a1e02abeb1082be3: Scheduling LogGCOp(68567d8f78d34c5fae216e9eea115f87): free 11976772 bytes of WAL
I20260812 06:19:25.542953 24657 log_reader.cc:385] T 68567d8f78d34c5fae216e9eea115f87: removed 1 log segments from log reader
I20260812 06:19:25.543020 24657 log.cc:1079] T 68567d8f78d34c5fae216e9eea115f87 P 2d337fafbc4d4b31a1e02abeb1082be3: Deleting log segment in path: /tmp/dist-test-taskseRmjK/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515564944993-24506-0/minicluster-data/ts-0-root/wals/68567d8f78d34c5fae216e9eea115f87/wal-000000001 (ops 1-6)
I20260812 06:19:25.547209 24657 maintenance_manager.cc:643] P 2d337fafbc4d4b31a1e02abeb1082be3: LogGCOp(68567d8f78d34c5fae216e9eea115f87) complete. Timing: real 0.004s	user 0.000s	sys 0.001s Metrics: {}
I20260812 06:19:25.547760 24755 maintenance_manager.cc:419] P 2d337fafbc4d4b31a1e02abeb1082be3: Scheduling FlushDeltaMemStoresOp(68567d8f78d34c5fae216e9eea115f87): perf score=2.188937
I20260812 06:19:25.564033 24657 maintenance_manager.cc:643] P 2d337fafbc4d4b31a1e02abeb1082be3: FlushDeltaMemStoresOp(68567d8f78d34c5fae216e9eea115f87) complete. Timing: real 0.016s	user 0.011s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6042,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:25.564503 24755 maintenance_manager.cc:419] P 2d337fafbc4d4b31a1e02abeb1082be3: Scheduling FlushDeltaMemStoresOp(68567d8f78d34c5fae216e9eea115f87): perf score=2.188937
I20260812 06:19:25.579408 24657 maintenance_manager.cc:643] P 2d337fafbc4d4b31a1e02abeb1082be3: FlushDeltaMemStoresOp(68567d8f78d34c5fae216e9eea115f87) complete. Timing: real 0.015s	user 0.012s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5757,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:25.579926 24755 maintenance_manager.cc:419] P 2d337fafbc4d4b31a1e02abeb1082be3: Scheduling MajorDeltaCompactionOp(68567d8f78d34c5fae216e9eea115f87): perf score=1.000000
I20260812 06:19:25.754276 24657 maintenance_manager.cc:643] P 2d337fafbc4d4b31a1e02abeb1082be3: MajorDeltaCompactionOp(68567d8f78d34c5fae216e9eea115f87) complete. Timing: real 0.174s	user 0.129s	sys 0.043s Metrics: {"cfile_cache_miss":523,"cfile_cache_miss_bytes":24323602,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":1042,"lbm_read_time_us":12117,"lbm_reads_lt_1ms":563,"lbm_write_time_us":32848,"lbm_writes_lt_1ms":533,"peak_mem_usage":61665166,"reinsert_count":0,"thread_start_us":330,"threads_started":5,"update_count":2450}
I20260812 06:19:25.754969 24755 maintenance_manager.cc:419] P 2d337fafbc4d4b31a1e02abeb1082be3: Scheduling FlushDeltaMemStoresOp(68567d8f78d34c5fae216e9eea115f87): perf score=11.118625
I20260812 06:19:25.813159 24657 maintenance_manager.cc:643] P 2d337fafbc4d4b31a1e02abeb1082be3: FlushDeltaMemStoresOp(68567d8f78d34c5fae216e9eea115f87) complete. Timing: real 0.058s	user 0.016s	sys 0.036s Metrics: {"bytes_written":12717735,"delete_count":0,"lbm_write_time_us":24634,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":312,"reinsert_count":0,"update_count":1550}
I20260812 06:19:25.813661 24755 maintenance_manager.cc:419] P 2d337fafbc4d4b31a1e02abeb1082be3: Scheduling FlushDeltaMemStoresOp(68567d8f78d34c5fae216e9eea115f87): perf score=2.188937
I20260812 06:19:25.828212 24657 maintenance_manager.cc:643] P 2d337fafbc4d4b31a1e02abeb1082be3: FlushDeltaMemStoresOp(68567d8f78d34c5fae216e9eea115f87) complete. Timing: real 0.014s	user 0.008s	sys 0.003s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4443,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:25.828749 24755 maintenance_manager.cc:419] P 2d337fafbc4d4b31a1e02abeb1082be3: Scheduling UndoDeltaBlockGCOp(68567d8f78d34c5fae216e9eea115f87): 8616791 bytes on disk
I20260812 06:19:25.829391 24657 maintenance_manager.cc:643] P 2d337fafbc4d4b31a1e02abeb1082be3: UndoDeltaBlockGCOp(68567d8f78d34c5fae216e9eea115f87) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":66,"lbm_reads_lt_1ms":4}
I20260812 06:19:25.829916 24755 maintenance_manager.cc:419] P 2d337fafbc4d4b31a1e02abeb1082be3: Scheduling FlushDeltaMemStoresOp(68567d8f78d34c5fae216e9eea115f87): perf score=2.188937
I20260812 06:19:25.840937 24657 maintenance_manager.cc:643] P 2d337fafbc4d4b31a1e02abeb1082be3: FlushDeltaMemStoresOp(68567d8f78d34c5fae216e9eea115f87) complete. Timing: real 0.011s	user 0.005s	sys 0.004s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":4057,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:19:25.841781 24755 maintenance_manager.cc:419] P 2d337fafbc4d4b31a1e02abeb1082be3: Scheduling MajorDeltaCompactionOp(68567d8f78d34c5fae216e9eea115f87): perf score=1.000000
I20260812 06:19:26.012279 24657 maintenance_manager.cc:643] P 2d337fafbc4d4b31a1e02abeb1082be3: MajorDeltaCompactionOp(68567d8f78d34c5fae216e9eea115f87) complete. Timing: real 0.170s	user 0.118s	sys 0.039s 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":761,"lbm_read_time_us":12229,"lbm_reads_lt_1ms":573,"lbm_write_time_us":31872,"lbm_writes_lt_1ms":543,"mutex_wait_us":29,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":14848,"update_count":2500}
I20260812 06:19:26.013005 24755 maintenance_manager.cc:419] P 2d337fafbc4d4b31a1e02abeb1082be3: Scheduling FlushDeltaMemStoresOp(68567d8f78d34c5fae216e9eea115f87): perf score=14.095187
I20260812 06:19:26.063843 24657 maintenance_manager.cc:643] P 2d337fafbc4d4b31a1e02abeb1082be3: FlushDeltaMemStoresOp(68567d8f78d34c5fae216e9eea115f87) complete. Timing: real 0.051s	user 0.032s	sys 0.012s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":19780,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:26.064356 24755 maintenance_manager.cc:419] P 2d337fafbc4d4b31a1e02abeb1082be3: Scheduling FlushDeltaMemStoresOp(68567d8f78d34c5fae216e9eea115f87): perf score=2.188937
I20260812 06:19:26.076930 24657 maintenance_manager.cc:643] P 2d337fafbc4d4b31a1e02abeb1082be3: FlushDeltaMemStoresOp(68567d8f78d34c5fae216e9eea115f87) complete. Timing: real 0.012s	user 0.005s	sys 0.006s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4282,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:26.077540 24755 maintenance_manager.cc:419] P 2d337fafbc4d4b31a1e02abeb1082be3: Scheduling MajorDeltaCompactionOp(68567d8f78d34c5fae216e9eea115f87): perf score=1.000000
I20260812 06:19:26.255436 24657 maintenance_manager.cc:643] P 2d337fafbc4d4b31a1e02abeb1082be3: MajorDeltaCompactionOp(68567d8f78d34c5fae216e9eea115f87) complete. Timing: real 0.178s	user 0.129s	sys 0.033s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24733723,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":286,"lbm_read_time_us":10672,"lbm_reads_lt_1ms":572,"lbm_write_time_us":33415,"lbm_writes_lt_1ms":543,"mutex_wait_us":28,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":23040,"update_count":2500}
I20260812 06:19:26.256006 24755 maintenance_manager.cc:419] P 2d337fafbc4d4b31a1e02abeb1082be3: Scheduling FlushDeltaMemStoresOp(68567d8f78d34c5fae216e9eea115f87): perf score=14.095187
I20260812 06:19:26.317392 24657 maintenance_manager.cc:643] P 2d337fafbc4d4b31a1e02abeb1082be3: FlushDeltaMemStoresOp(68567d8f78d34c5fae216e9eea115f87) complete. Timing: real 0.061s	user 0.041s	sys 0.012s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":24729,"lbm_writes_lt_1ms":403,"reinsert_count":0,"spinlock_wait_cycles":1280,"update_count":2000}
I20260812 06:19:26.317901 24755 maintenance_manager.cc:419] P 2d337fafbc4d4b31a1e02abeb1082be3: Scheduling FlushDeltaMemStoresOp(68567d8f78d34c5fae216e9eea115f87): perf score=2.188937
I20260812 06:19:26.328908 24657 maintenance_manager.cc:643] P 2d337fafbc4d4b31a1e02abeb1082be3: FlushDeltaMemStoresOp(68567d8f78d34c5fae216e9eea115f87) complete. Timing: real 0.011s	user 0.005s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4175,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:26.329385 24755 maintenance_manager.cc:419] P 2d337fafbc4d4b31a1e02abeb1082be3: Scheduling MajorDeltaCompactionOp(68567d8f78d34c5fae216e9eea115f87): perf score=1.000000
I20260812 06:19:26.520936 24657 maintenance_manager.cc:643] P 2d337fafbc4d4b31a1e02abeb1082be3: MajorDeltaCompactionOp(68567d8f78d34c5fae216e9eea115f87) complete. Timing: real 0.191s	user 0.143s	sys 0.044s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24733724,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":372,"lbm_read_time_us":14105,"lbm_reads_lt_1ms":572,"lbm_write_time_us":32795,"lbm_writes_lt_1ms":543,"mutex_wait_us":2,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":9856,"update_count":2500}
I20260812 06:19:26.521878 24755 maintenance_manager.cc:419] P 2d337fafbc4d4b31a1e02abeb1082be3: Scheduling FlushDeltaMemStoresOp(68567d8f78d34c5fae216e9eea115f87): perf score=14.095187
I20260812 06:19:26.570312 24657 maintenance_manager.cc:643] P 2d337fafbc4d4b31a1e02abeb1082be3: FlushDeltaMemStoresOp(68567d8f78d34c5fae216e9eea115f87) complete. Timing: real 0.048s	user 0.037s	sys 0.008s Metrics: {"bytes_written":16409903,"delete_count":0,"lbm_write_time_us":21220,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:26.570940 24755 maintenance_manager.cc:419] P 2d337fafbc4d4b31a1e02abeb1082be3: Scheduling MajorDeltaCompactionOp(68567d8f78d34c5fae216e9eea115f87): perf score=1.000000
I20260812 06:19:26.722543 24657 maintenance_manager.cc:643] P 2d337fafbc4d4b31a1e02abeb1082be3: MajorDeltaCompactionOp(68567d8f78d34c5fae216e9eea115f87) complete. Timing: real 0.151s	user 0.087s	sys 0.063s Metrics: {"cfile_cache_miss":431,"cfile_cache_miss_bytes":20631194,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":1,"delta_iterators_relevant":1,"dirs.queue_time_us":1151,"lbm_read_time_us":10066,"lbm_reads_lt_1ms":467,"lbm_write_time_us":26205,"lbm_writes_lt_1ms":443,"mutex_wait_us":431,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":17280,"update_count":2000}
I20260812 06:19:26.723707 24755 maintenance_manager.cc:419] P 2d337fafbc4d4b31a1e02abeb1082be3: Scheduling FlushDeltaMemStoresOp(68567d8f78d34c5fae216e9eea115f87): perf score=10.126437
I20260812 06:19:26.759738 24657 maintenance_manager.cc:643] P 2d337fafbc4d4b31a1e02abeb1082be3: FlushDeltaMemStoresOp(68567d8f78d34c5fae216e9eea115f87) complete. Timing: real 0.036s	user 0.024s	sys 0.012s Metrics: {"bytes_written":12307501,"delete_count":0,"lbm_write_time_us":15203,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:19:26.760500 24755 maintenance_manager.cc:419] P 2d337fafbc4d4b31a1e02abeb1082be3: Scheduling FlushDeltaMemStoresOp(68567d8f78d34c5fae216e9eea115f87): perf score=2.188937
I20260812 06:19:26.774729 24657 maintenance_manager.cc:643] P 2d337fafbc4d4b31a1e02abeb1082be3: FlushDeltaMemStoresOp(68567d8f78d34c5fae216e9eea115f87) complete. Timing: real 0.014s	user 0.004s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5613,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:26.775256 24755 maintenance_manager.cc:419] P 2d337fafbc4d4b31a1e02abeb1082be3: Scheduling MajorDeltaCompactionOp(68567d8f78d34c5fae216e9eea115f87): perf score=1.000000
I20260812 06:19:26.904395 24657 maintenance_manager.cc:643] P 2d337fafbc4d4b31a1e02abeb1082be3: MajorDeltaCompactionOp(68567d8f78d34c5fae216e9eea115f87) complete. Timing: real 0.129s	user 0.105s	sys 0.024s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20631323,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":239,"lbm_read_time_us":8920,"lbm_reads_lt_1ms":464,"lbm_write_time_us":26170,"lbm_writes_lt_1ms":443,"mutex_wait_us":55,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":896,"update_count":2000}
I20260812 06:19:26.905081 24755 maintenance_manager.cc:419] P 2d337fafbc4d4b31a1e02abeb1082be3: Scheduling FlushDeltaMemStoresOp(68567d8f78d34c5fae216e9eea115f87): perf score=10.126437
I20260812 06:19:26.949790 24657 maintenance_manager.cc:643] P 2d337fafbc4d4b31a1e02abeb1082be3: FlushDeltaMemStoresOp(68567d8f78d34c5fae216e9eea115f87) complete. Timing: real 0.045s	user 0.021s	sys 0.019s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":18472,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:19:26.950352 24755 maintenance_manager.cc:419] P 2d337fafbc4d4b31a1e02abeb1082be3: Scheduling FlushDeltaMemStoresOp(68567d8f78d34c5fae216e9eea115f87): perf score=2.188937
I20260812 06:19:26.962224 24657 maintenance_manager.cc:643] P 2d337fafbc4d4b31a1e02abeb1082be3: FlushDeltaMemStoresOp(68567d8f78d34c5fae216e9eea115f87) complete. Timing: real 0.012s	user 0.009s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4212,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:26.964184 24755 maintenance_manager.cc:419] P 2d337fafbc4d4b31a1e02abeb1082be3: Scheduling FlushMRSOp(68567d8f78d34c5fae216e9eea115f87): perf score=1.000000
I20260812 06:19:26.996196 24657 maintenance_manager.cc:643] P 2d337fafbc4d4b31a1e02abeb1082be3: FlushMRSOp(68567d8f78d34c5fae216e9eea115f87) complete. Timing: real 0.032s	user 0.027s	sys 0.004s Metrics: {"bytes_written":1275444,"cfile_init":1,"dirs.queue_time_us":67,"dirs.run_cpu_time_us":260,"dirs.run_wall_time_us":1293,"drs_written":1,"lbm_read_time_us":46,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1987,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":31}
I20260812 06:19:26.997000 24755 maintenance_manager.cc:419] P 2d337fafbc4d4b31a1e02abeb1082be3: Scheduling LogGCOp(68567d8f78d34c5fae216e9eea115f87): free 129773549 bytes of WAL
I20260812 06:19:26.997236 24657 log_reader.cc:385] T 68567d8f78d34c5fae216e9eea115f87: removed 13 log segments from log reader
I20260812 06:19:26.997296 24657 log.cc:1079] T 68567d8f78d34c5fae216e9eea115f87 P 2d337fafbc4d4b31a1e02abeb1082be3: Deleting log segment in path: /tmp/dist-test-taskseRmjK/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515564944993-24506-0/minicluster-data/ts-0-root/wals/68567d8f78d34c5fae216e9eea115f87/wal-000000002 (ops 7-11)
I20260812 06:19:26.997350 24657 log.cc:1079] T 68567d8f78d34c5fae216e9eea115f87 P 2d337fafbc4d4b31a1e02abeb1082be3: Deleting log segment in path: /tmp/dist-test-taskseRmjK/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515564944993-24506-0/minicluster-data/ts-0-root/wals/68567d8f78d34c5fae216e9eea115f87/wal-000000003 (ops 12-16)
I20260812 06:19:26.997409 24657 log.cc:1079] T 68567d8f78d34c5fae216e9eea115f87 P 2d337fafbc4d4b31a1e02abeb1082be3: Deleting log segment in path: /tmp/dist-test-taskseRmjK/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515564944993-24506-0/minicluster-data/ts-0-root/wals/68567d8f78d34c5fae216e9eea115f87/wal-000000004 (ops 17-21)
I20260812 06:19:26.997457 24657 log.cc:1079] T 68567d8f78d34c5fae216e9eea115f87 P 2d337fafbc4d4b31a1e02abeb1082be3: Deleting log segment in path: /tmp/dist-test-taskseRmjK/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515564944993-24506-0/minicluster-data/ts-0-root/wals/68567d8f78d34c5fae216e9eea115f87/wal-000000005 (ops 22-26)
I20260812 06:19:26.997496 24657 log.cc:1079] T 68567d8f78d34c5fae216e9eea115f87 P 2d337fafbc4d4b31a1e02abeb1082be3: Deleting log segment in path: /tmp/dist-test-taskseRmjK/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515564944993-24506-0/minicluster-data/ts-0-root/wals/68567d8f78d34c5fae216e9eea115f87/wal-000000006 (ops 27-30)
I20260812 06:19:26.997532 24657 log.cc:1079] T 68567d8f78d34c5fae216e9eea115f87 P 2d337fafbc4d4b31a1e02abeb1082be3: Deleting log segment in path: /tmp/dist-test-taskseRmjK/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515564944993-24506-0/minicluster-data/ts-0-root/wals/68567d8f78d34c5fae216e9eea115f87/wal-000000007 (ops 31-35)
I20260812 06:19:26.997570 24657 log.cc:1079] T 68567d8f78d34c5fae216e9eea115f87 P 2d337fafbc4d4b31a1e02abeb1082be3: Deleting log segment in path: /tmp/dist-test-taskseRmjK/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515564944993-24506-0/minicluster-data/ts-0-root/wals/68567d8f78d34c5fae216e9eea115f87/wal-000000008 (ops 36-40)
I20260812 06:19:26.997605 24657 log.cc:1079] T 68567d8f78d34c5fae216e9eea115f87 P 2d337fafbc4d4b31a1e02abeb1082be3: Deleting log segment in path: /tmp/dist-test-taskseRmjK/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515564944993-24506-0/minicluster-data/ts-0-root/wals/68567d8f78d34c5fae216e9eea115f87/wal-000000009 (ops 41-45)
I20260812 06:19:26.997642 24657 log.cc:1079] T 68567d8f78d34c5fae216e9eea115f87 P 2d337fafbc4d4b31a1e02abeb1082be3: Deleting log segment in path: /tmp/dist-test-taskseRmjK/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515564944993-24506-0/minicluster-data/ts-0-root/wals/68567d8f78d34c5fae216e9eea115f87/wal-000000010 (ops 46-50)
I20260812 06:19:26.997678 24657 log.cc:1079] T 68567d8f78d34c5fae216e9eea115f87 P 2d337fafbc4d4b31a1e02abeb1082be3: Deleting log segment in path: /tmp/dist-test-taskseRmjK/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515564944993-24506-0/minicluster-data/ts-0-root/wals/68567d8f78d34c5fae216e9eea115f87/wal-000000011 (ops 51-55)
I20260812 06:19:26.997715 24657 log.cc:1079] T 68567d8f78d34c5fae216e9eea115f87 P 2d337fafbc4d4b31a1e02abeb1082be3: Deleting log segment in path: /tmp/dist-test-taskseRmjK/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515564944993-24506-0/minicluster-data/ts-0-root/wals/68567d8f78d34c5fae216e9eea115f87/wal-000000012 (ops 56-60)
I20260812 06:19:26.997752 24657 log.cc:1079] T 68567d8f78d34c5fae216e9eea115f87 P 2d337fafbc4d4b31a1e02abeb1082be3: Deleting log segment in path: /tmp/dist-test-taskseRmjK/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515564944993-24506-0/minicluster-data/ts-0-root/wals/68567d8f78d34c5fae216e9eea115f87/wal-000000013 (ops 61-65)
I20260812 06:19:26.997790 24657 log.cc:1079] T 68567d8f78d34c5fae216e9eea115f87 P 2d337fafbc4d4b31a1e02abeb1082be3: Deleting log segment in path: /tmp/dist-test-taskseRmjK/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515564944993-24506-0/minicluster-data/ts-0-root/wals/68567d8f78d34c5fae216e9eea115f87/wal-000000014 (ops 66-70)
I20260812 06:19:27.031663 24657 maintenance_manager.cc:643] P 2d337fafbc4d4b31a1e02abeb1082be3: LogGCOp(68567d8f78d34c5fae216e9eea115f87) complete. Timing: real 0.034s	user 0.000s	sys 0.034s Metrics: {}
I20260812 06:19:27.032287 24755 maintenance_manager.cc:419] P 2d337fafbc4d4b31a1e02abeb1082be3: Scheduling UndoDeltaBlockGCOp(68567d8f78d34c5fae216e9eea115f87): 483 bytes on disk
I20260812 06:19:27.032893 24657 maintenance_manager.cc:643] P 2d337fafbc4d4b31a1e02abeb1082be3: UndoDeltaBlockGCOp(68567d8f78d34c5fae216e9eea115f87) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":79,"lbm_reads_lt_1ms":4}
I20260812 06:19:27.033541 24755 maintenance_manager.cc:419] P 2d337fafbc4d4b31a1e02abeb1082be3: Scheduling FlushDeltaMemStoresOp(68567d8f78d34c5fae216e9eea115f87): perf score=5.165500
I20260812 06:19:27.052589 24657 maintenance_manager.cc:643] P 2d337fafbc4d4b31a1e02abeb1082be3: FlushDeltaMemStoresOp(68567d8f78d34c5fae216e9eea115f87) complete. Timing: real 0.019s	user 0.006s	sys 0.012s Metrics: {"bytes_written":6810259,"delete_count":0,"lbm_write_time_us":7966,"lbm_writes_lt_1ms":169,"reinsert_count":0,"update_count":830}
I20260812 06:19:27.053089 24755 maintenance_manager.cc:419] P 2d337fafbc4d4b31a1e02abeb1082be3: Scheduling FlushDeltaMemStoresOp(68567d8f78d34c5fae216e9eea115f87): perf score=1.000000
I20260812 06:19:27.061069 24657 maintenance_manager.cc:643] P 2d337fafbc4d4b31a1e02abeb1082be3: FlushDeltaMemStoresOp(68567d8f78d34c5fae216e9eea115f87) complete. Timing: real 0.007s	user 0.002s	sys 0.004s Metrics: {"bytes_written":1395002,"delete_count":0,"lbm_write_time_us":2221,"lbm_writes_lt_1ms":37,"reinsert_count":0,"update_count":170}
I20260812 06:19:27.061599 24755 maintenance_manager.cc:419] P 2d337fafbc4d4b31a1e02abeb1082be3: Scheduling MajorDeltaCompactionOp(68567d8f78d34c5fae216e9eea115f87): perf score=1.000000
I20260812 06:19:27.238368 24657 maintenance_manager.cc:643] P 2d337fafbc4d4b31a1e02abeb1082be3: MajorDeltaCompactionOp(68567d8f78d34c5fae216e9eea115f87) complete. Timing: real 0.177s	user 0.158s	sys 0.015s Metrics: {"cfile_cache_miss":634,"cfile_cache_miss_bytes":28836312,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":573,"lbm_read_time_us":12610,"lbm_reads_lt_1ms":674,"lbm_write_time_us":34683,"lbm_writes_lt_1ms":643,"mutex_wait_us":38,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":7552,"thread_start_us":83,"threads_started":1,"update_count":3000}
I20260812 06:19:27.238997 24755 maintenance_manager.cc:419] P 2d337fafbc4d4b31a1e02abeb1082be3: Scheduling FlushDeltaMemStoresOp(68567d8f78d34c5fae216e9eea115f87): perf score=14.095187
I20260812 06:19:27.291893 24657 maintenance_manager.cc:643] P 2d337fafbc4d4b31a1e02abeb1082be3: FlushDeltaMemStoresOp(68567d8f78d34c5fae216e9eea115f87) complete. Timing: real 0.053s	user 0.025s	sys 0.027s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":24404,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":402,"reinsert_count":0,"update_count":2000}
I20260812 06:19:27.292448 24755 maintenance_manager.cc:419] P 2d337fafbc4d4b31a1e02abeb1082be3: Scheduling FlushDeltaMemStoresOp(68567d8f78d34c5fae216e9eea115f87): perf score=2.188937
I20260812 06:19:27.309566 24657 maintenance_manager.cc:643] P 2d337fafbc4d4b31a1e02abeb1082be3: FlushDeltaMemStoresOp(68567d8f78d34c5fae216e9eea115f87) complete. Timing: real 0.017s	user 0.001s	sys 0.012s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6295,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:27.310050 24755 maintenance_manager.cc:419] P 2d337fafbc4d4b31a1e02abeb1082be3: Scheduling MajorDeltaCompactionOp(68567d8f78d34c5fae216e9eea115f87): perf score=1.000000
I20260812 06:19:27.459618 24657 maintenance_manager.cc:643] P 2d337fafbc4d4b31a1e02abeb1082be3: MajorDeltaCompactionOp(68567d8f78d34c5fae216e9eea115f87) complete. Timing: real 0.149s	user 0.123s	sys 0.024s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24733724,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":946,"lbm_read_time_us":10687,"lbm_reads_lt_1ms":564,"lbm_write_time_us":28642,"lbm_writes_lt_1ms":543,"mutex_wait_us":24,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":13056,"update_count":2500}
I20260812 06:19:27.460280 24755 maintenance_manager.cc:419] P 2d337fafbc4d4b31a1e02abeb1082be3: Scheduling FlushDeltaMemStoresOp(68567d8f78d34c5fae216e9eea115f87): perf score=14.095187
I20260812 06:19:27.515364 24657 maintenance_manager.cc:643] P 2d337fafbc4d4b31a1e02abeb1082be3: FlushDeltaMemStoresOp(68567d8f78d34c5fae216e9eea115f87) complete. Timing: real 0.055s	user 0.032s	sys 0.020s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":25400,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:27.516006 24755 maintenance_manager.cc:419] P 2d337fafbc4d4b31a1e02abeb1082be3: Scheduling FlushDeltaMemStoresOp(68567d8f78d34c5fae216e9eea115f87): perf score=2.188937
I20260812 06:19:27.530725 24657 maintenance_manager.cc:643] P 2d337fafbc4d4b31a1e02abeb1082be3: FlushDeltaMemStoresOp(68567d8f78d34c5fae216e9eea115f87) complete. Timing: real 0.015s	user 0.009s	sys 0.004s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":5379,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:27.531473 24755 maintenance_manager.cc:419] P 2d337fafbc4d4b31a1e02abeb1082be3: Scheduling MajorDeltaCompactionOp(68567d8f78d34c5fae216e9eea115f87): perf score=1.000000
I20260812 06:19:27.702720 24657 maintenance_manager.cc:643] P 2d337fafbc4d4b31a1e02abeb1082be3: MajorDeltaCompactionOp(68567d8f78d34c5fae216e9eea115f87) complete. Timing: real 0.171s	user 0.098s	sys 0.057s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24733723,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":347,"lbm_read_time_us":12602,"lbm_reads_lt_1ms":564,"lbm_write_time_us":32385,"lbm_writes_lt_1ms":543,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":4992,"update_count":2500}
I20260812 06:19:27.703492 24755 maintenance_manager.cc:419] P 2d337fafbc4d4b31a1e02abeb1082be3: Scheduling FlushDeltaMemStoresOp(68567d8f78d34c5fae216e9eea115f87): perf score=14.095187
I20260812 06:19:27.761662 24657 maintenance_manager.cc:643] P 2d337fafbc4d4b31a1e02abeb1082be3: FlushDeltaMemStoresOp(68567d8f78d34c5fae216e9eea115f87) complete. Timing: real 0.058s	user 0.032s	sys 0.013s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":20476,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:27.762281 24755 maintenance_manager.cc:419] P 2d337fafbc4d4b31a1e02abeb1082be3: Scheduling FlushDeltaMemStoresOp(68567d8f78d34c5fae216e9eea115f87): perf score=2.188937
I20260812 06:19:27.780176 24657 maintenance_manager.cc:643] P 2d337fafbc4d4b31a1e02abeb1082be3: FlushDeltaMemStoresOp(68567d8f78d34c5fae216e9eea115f87) complete. Timing: real 0.018s	user 0.013s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6819,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:27.781112 24755 maintenance_manager.cc:419] P 2d337fafbc4d4b31a1e02abeb1082be3: Scheduling MajorDeltaCompactionOp(68567d8f78d34c5fae216e9eea115f87): perf score=1.000000
I20260812 06:19:27.968190 24657 maintenance_manager.cc:643] P 2d337fafbc4d4b31a1e02abeb1082be3: MajorDeltaCompactionOp(68567d8f78d34c5fae216e9eea115f87) complete. Timing: real 0.187s	user 0.120s	sys 0.056s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24733724,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":1175,"lbm_read_time_us":13564,"lbm_reads_lt_1ms":572,"lbm_write_time_us":32367,"lbm_writes_lt_1ms":543,"mutex_wait_us":44,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":10240,"update_count":2500}
I20260812 06:19:27.968924 24755 maintenance_manager.cc:419] P 2d337fafbc4d4b31a1e02abeb1082be3: Scheduling FlushDeltaMemStoresOp(68567d8f78d34c5fae216e9eea115f87): perf score=14.095187
I20260812 06:19:28.041411 24657 maintenance_manager.cc:643] P 2d337fafbc4d4b31a1e02abeb1082be3: FlushDeltaMemStoresOp(68567d8f78d34c5fae216e9eea115f87) complete. Timing: real 0.071s	user 0.027s	sys 0.028s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":25263,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:28.041944 24755 maintenance_manager.cc:419] P 2d337fafbc4d4b31a1e02abeb1082be3: Scheduling FlushDeltaMemStoresOp(68567d8f78d34c5fae216e9eea115f87): perf score=2.188937
I20260812 06:19:28.054591 24657 maintenance_manager.cc:643] P 2d337fafbc4d4b31a1e02abeb1082be3: FlushDeltaMemStoresOp(68567d8f78d34c5fae216e9eea115f87) complete. Timing: real 0.012s	user 0.002s	sys 0.007s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4303,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:28.055266 24755 maintenance_manager.cc:419] P 2d337fafbc4d4b31a1e02abeb1082be3: Scheduling MajorDeltaCompactionOp(68567d8f78d34c5fae216e9eea115f87): perf score=1.000000
I20260812 06:19:28.239732 24657 maintenance_manager.cc:643] P 2d337fafbc4d4b31a1e02abeb1082be3: MajorDeltaCompactionOp(68567d8f78d34c5fae216e9eea115f87) complete. Timing: real 0.184s	user 0.101s	sys 0.083s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24733723,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":176,"lbm_read_time_us":13261,"lbm_reads_lt_1ms":572,"lbm_write_time_us":32071,"lbm_writes_lt_1ms":543,"mutex_wait_us":29,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":5376,"update_count":2500}
I20260812 06:19:28.240352 24755 maintenance_manager.cc:419] P 2d337fafbc4d4b31a1e02abeb1082be3: Scheduling FlushDeltaMemStoresOp(68567d8f78d34c5fae216e9eea115f87): perf score=14.095187
I20260812 06:19:28.300838 24657 maintenance_manager.cc:643] P 2d337fafbc4d4b31a1e02abeb1082be3: FlushDeltaMemStoresOp(68567d8f78d34c5fae216e9eea115f87) complete. Timing: real 0.060s	user 0.042s	sys 0.008s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":22657,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:28.301422 24755 maintenance_manager.cc:419] P 2d337fafbc4d4b31a1e02abeb1082be3: Scheduling FlushDeltaMemStoresOp(68567d8f78d34c5fae216e9eea115f87): perf score=2.188937
I20260812 06:19:28.313874 24657 maintenance_manager.cc:643] P 2d337fafbc4d4b31a1e02abeb1082be3: FlushDeltaMemStoresOp(68567d8f78d34c5fae216e9eea115f87) complete. Timing: real 0.012s	user 0.006s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4681,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:28.314693 24755 maintenance_manager.cc:419] P 2d337fafbc4d4b31a1e02abeb1082be3: Scheduling MajorDeltaCompactionOp(68567d8f78d34c5fae216e9eea115f87): perf score=1.000000
I20260812 06:19:28.509804 24657 maintenance_manager.cc:643] P 2d337fafbc4d4b31a1e02abeb1082be3: MajorDeltaCompactionOp(68567d8f78d34c5fae216e9eea115f87) complete. Timing: real 0.195s	user 0.150s	sys 0.044s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24733723,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":568,"lbm_read_time_us":13336,"lbm_reads_lt_1ms":572,"lbm_write_time_us":31636,"lbm_writes_lt_1ms":543,"mutex_wait_us":353,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":7680,"update_count":2500}
I20260812 06:19:28.510604 24755 maintenance_manager.cc:419] P 2d337fafbc4d4b31a1e02abeb1082be3: Scheduling FlushDeltaMemStoresOp(68567d8f78d34c5fae216e9eea115f87): perf score=14.095187
I20260812 06:19:28.574636 24657 maintenance_manager.cc:643] P 2d337fafbc4d4b31a1e02abeb1082be3: FlushDeltaMemStoresOp(68567d8f78d34c5fae216e9eea115f87) complete. Timing: real 0.063s	user 0.023s	sys 0.031s Metrics: {"bytes_written":16409904,"delete_count":0,"lbm_write_time_us":24433,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":402,"reinsert_count":0,"update_count":2000}
I20260812 06:19:28.575260 24755 maintenance_manager.cc:419] P 2d337fafbc4d4b31a1e02abeb1082be3: Scheduling FlushDeltaMemStoresOp(68567d8f78d34c5fae216e9eea115f87): perf score=4.173312
I20260812 06:19:28.591012 24657 maintenance_manager.cc:643] P 2d337fafbc4d4b31a1e02abeb1082be3: FlushDeltaMemStoresOp(68567d8f78d34c5fae216e9eea115f87) complete. Timing: real 0.016s	user 0.010s	sys 0.004s Metrics: {"bytes_written":5784657,"delete_count":0,"lbm_write_time_us":6453,"lbm_writes_lt_1ms":144,"reinsert_count":0,"update_count":705}
I20260812 06:19:28.591624 24755 maintenance_manager.cc:419] P 2d337fafbc4d4b31a1e02abeb1082be3: Scheduling FlushDeltaMemStoresOp(68567d8f78d34c5fae216e9eea115f87): perf score=1.196750
I20260812 06:19:28.599095 24657 maintenance_manager.cc:643] P 2d337fafbc4d4b31a1e02abeb1082be3: FlushDeltaMemStoresOp(68567d8f78d34c5fae216e9eea115f87) complete. Timing: real 0.007s	user 0.005s	sys 0.001s Metrics: {"bytes_written":2420629,"delete_count":0,"lbm_write_time_us":2465,"lbm_writes_lt_1ms":62,"reinsert_count":0,"update_count":295}
I20260812 06:19:28.599653 24755 maintenance_manager.cc:419] P 2d337fafbc4d4b31a1e02abeb1082be3: Scheduling FlushMRSOp(68567d8f78d34c5fae216e9eea115f87): perf score=1.000000
I20260812 06:19:28.644937 24657 maintenance_manager.cc:643] P 2d337fafbc4d4b31a1e02abeb1082be3: FlushMRSOp(68567d8f78d34c5fae216e9eea115f87) complete. Timing: real 0.045s	user 0.043s	sys 0.001s Metrics: {"bytes_written":1357580,"cfile_init":1,"dirs.queue_time_us":52,"dirs.run_cpu_time_us":223,"dirs.run_wall_time_us":1665,"drs_written":1,"lbm_read_time_us":46,"lbm_reads_lt_1ms":4,"lbm_write_time_us":2852,"lbm_writes_lt_1ms":44,"peak_mem_usage":0,"rows_written":33}
I20260812 06:19:28.645722 24755 maintenance_manager.cc:419] P 2d337fafbc4d4b31a1e02abeb1082be3: Scheduling LogGCOp(68567d8f78d34c5fae216e9eea115f87): free 132571284 bytes of WAL
I20260812 06:19:28.645991 24657 log_reader.cc:385] T 68567d8f78d34c5fae216e9eea115f87: removed 13 log segments from log reader
I20260812 06:19:28.646042 24657 log.cc:1079] T 68567d8f78d34c5fae216e9eea115f87 P 2d337fafbc4d4b31a1e02abeb1082be3: Deleting log segment in path: /tmp/dist-test-taskseRmjK/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515564944993-24506-0/minicluster-data/ts-0-root/wals/68567d8f78d34c5fae216e9eea115f87/wal-000000015 (ops 71-75)
I20260812 06:19:28.646075 24657 log.cc:1079] T 68567d8f78d34c5fae216e9eea115f87 P 2d337fafbc4d4b31a1e02abeb1082be3: Deleting log segment in path: /tmp/dist-test-taskseRmjK/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515564944993-24506-0/minicluster-data/ts-0-root/wals/68567d8f78d34c5fae216e9eea115f87/wal-000000016 (ops 76-80)
I20260812 06:19:28.646149 24657 log.cc:1079] T 68567d8f78d34c5fae216e9eea115f87 P 2d337fafbc4d4b31a1e02abeb1082be3: Deleting log segment in path: /tmp/dist-test-taskseRmjK/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515564944993-24506-0/minicluster-data/ts-0-root/wals/68567d8f78d34c5fae216e9eea115f87/wal-000000017 (ops 81-85)
I20260812 06:19:28.646201 24657 log.cc:1079] T 68567d8f78d34c5fae216e9eea115f87 P 2d337fafbc4d4b31a1e02abeb1082be3: Deleting log segment in path: /tmp/dist-test-taskseRmjK/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515564944993-24506-0/minicluster-data/ts-0-root/wals/68567d8f78d34c5fae216e9eea115f87/wal-000000018 (ops 86-90)
I20260812 06:19:28.646252 24657 log.cc:1079] T 68567d8f78d34c5fae216e9eea115f87 P 2d337fafbc4d4b31a1e02abeb1082be3: Deleting log segment in path: /tmp/dist-test-taskseRmjK/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515564944993-24506-0/minicluster-data/ts-0-root/wals/68567d8f78d34c5fae216e9eea115f87/wal-000000019 (ops 91-94)
I20260812 06:19:28.646317 24657 log.cc:1079] T 68567d8f78d34c5fae216e9eea115f87 P 2d337fafbc4d4b31a1e02abeb1082be3: Deleting log segment in path: /tmp/dist-test-taskseRmjK/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515564944993-24506-0/minicluster-data/ts-0-root/wals/68567d8f78d34c5fae216e9eea115f87/wal-000000020 (ops 95-99)
I20260812 06:19:28.646363 24657 log.cc:1079] T 68567d8f78d34c5fae216e9eea115f87 P 2d337fafbc4d4b31a1e02abeb1082be3: Deleting log segment in path: /tmp/dist-test-taskseRmjK/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515564944993-24506-0/minicluster-data/ts-0-root/wals/68567d8f78d34c5fae216e9eea115f87/wal-000000021 (ops 100-104)
I20260812 06:19:28.646420 24657 log.cc:1079] T 68567d8f78d34c5fae216e9eea115f87 P 2d337fafbc4d4b31a1e02abeb1082be3: Deleting log segment in path: /tmp/dist-test-taskseRmjK/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515564944993-24506-0/minicluster-data/ts-0-root/wals/68567d8f78d34c5fae216e9eea115f87/wal-000000022 (ops 105-109)
I20260812 06:19:28.646461 24657 log.cc:1079] T 68567d8f78d34c5fae216e9eea115f87 P 2d337fafbc4d4b31a1e02abeb1082be3: Deleting log segment in path: /tmp/dist-test-taskseRmjK/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515564944993-24506-0/minicluster-data/ts-0-root/wals/68567d8f78d34c5fae216e9eea115f87/wal-000000023 (ops 110-114)
I20260812 06:19:28.646512 24657 log.cc:1079] T 68567d8f78d34c5fae216e9eea115f87 P 2d337fafbc4d4b31a1e02abeb1082be3: Deleting log segment in path: /tmp/dist-test-taskseRmjK/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515564944993-24506-0/minicluster-data/ts-0-root/wals/68567d8f78d34c5fae216e9eea115f87/wal-000000024 (ops 115-118)
I20260812 06:19:28.646554 24657 log.cc:1079] T 68567d8f78d34c5fae216e9eea115f87 P 2d337fafbc4d4b31a1e02abeb1082be3: Deleting log segment in path: /tmp/dist-test-taskseRmjK/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515564944993-24506-0/minicluster-data/ts-0-root/wals/68567d8f78d34c5fae216e9eea115f87/wal-000000025 (ops 119-123)
I20260812 06:19:28.646600 24657 log.cc:1079] T 68567d8f78d34c5fae216e9eea115f87 P 2d337fafbc4d4b31a1e02abeb1082be3: Deleting log segment in path: /tmp/dist-test-taskseRmjK/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515564944993-24506-0/minicluster-data/ts-0-root/wals/68567d8f78d34c5fae216e9eea115f87/wal-000000026 (ops 124-128)
I20260812 06:19:28.646646 24657 log.cc:1079] T 68567d8f78d34c5fae216e9eea115f87 P 2d337fafbc4d4b31a1e02abeb1082be3: Deleting log segment in path: /tmp/dist-test-taskseRmjK/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515564944993-24506-0/minicluster-data/ts-0-root/wals/68567d8f78d34c5fae216e9eea115f87/wal-000000027 (ops 129-133)
I20260812 06:19:28.681320 24657 maintenance_manager.cc:643] P 2d337fafbc4d4b31a1e02abeb1082be3: LogGCOp(68567d8f78d34c5fae216e9eea115f87) complete. Timing: real 0.035s	user 0.000s	sys 0.034s Metrics: {}
I20260812 06:19:28.681842 24755 maintenance_manager.cc:419] P 2d337fafbc4d4b31a1e02abeb1082be3: Scheduling FlushDeltaMemStoresOp(68567d8f78d34c5fae216e9eea115f87): perf score=3.181125
I20260812 06:19:28.694404 24657 maintenance_manager.cc:643] P 2d337fafbc4d4b31a1e02abeb1082be3: FlushDeltaMemStoresOp(68567d8f78d34c5fae216e9eea115f87) complete. Timing: real 0.012s	user 0.007s	sys 0.003s Metrics: {"bytes_written":4512900,"delete_count":0,"lbm_write_time_us":4730,"lbm_writes_lt_1ms":113,"reinsert_count":0,"update_count":550}
I20260812 06:19:28.694900 24755 maintenance_manager.cc:419] P 2d337fafbc4d4b31a1e02abeb1082be3: Scheduling LogGCOp(68567d8f78d34c5fae216e9eea115f87): free 12018013 bytes of WAL
I20260812 06:19:28.695128 24657 log_reader.cc:385] T 68567d8f78d34c5fae216e9eea115f87: removed 1 log segments from log reader
I20260812 06:19:28.695173 24657 log.cc:1079] T 68567d8f78d34c5fae216e9eea115f87 P 2d337fafbc4d4b31a1e02abeb1082be3: Deleting log segment in path: /tmp/dist-test-taskseRmjK/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515564944993-24506-0/minicluster-data/ts-0-root/wals/68567d8f78d34c5fae216e9eea115f87/wal-000000028 (ops 134-138)
I20260812 06:19:28.697723 24657 maintenance_manager.cc:643] P 2d337fafbc4d4b31a1e02abeb1082be3: LogGCOp(68567d8f78d34c5fae216e9eea115f87) complete. Timing: real 0.003s	user 0.000s	sys 0.001s Metrics: {}
I20260812 06:19:28.698052 24755 maintenance_manager.cc:419] P 2d337fafbc4d4b31a1e02abeb1082be3: Scheduling FlushDeltaMemStoresOp(68567d8f78d34c5fae216e9eea115f87): perf score=2.188937
I20260812 06:19:28.708353 24657 maintenance_manager.cc:643] P 2d337fafbc4d4b31a1e02abeb1082be3: FlushDeltaMemStoresOp(68567d8f78d34c5fae216e9eea115f87) complete. Timing: real 0.010s	user 0.001s	sys 0.008s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3955,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:19:28.709087 24755 maintenance_manager.cc:419] P 2d337fafbc4d4b31a1e02abeb1082be3: Scheduling MajorDeltaCompactionOp(68567d8f78d34c5fae216e9eea115f87): perf score=1.000000
I20260812 06:19:28.964272 24657 maintenance_manager.cc:643] P 2d337fafbc4d4b31a1e02abeb1082be3: MajorDeltaCompactionOp(68567d8f78d34c5fae216e9eea115f87) complete. Timing: real 0.255s	user 0.197s	sys 0.057s Metrics: {"cfile_cache_miss":835,"cfile_cache_miss_bytes":37041268,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":5,"delta_iterators_relevant":5,"dirs.queue_time_us":1558,"lbm_read_time_us":18201,"lbm_reads_lt_1ms":875,"lbm_write_time_us":47946,"lbm_writes_lt_1ms":843,"mutex_wait_us":838,"peak_mem_usage":100395616,"reinsert_count":0,"spinlock_wait_cycles":2176,"thread_start_us":95,"threads_started":1,"update_count":4000}
I20260812 06:19:28.964917 24755 maintenance_manager.cc:419] P 2d337fafbc4d4b31a1e02abeb1082be3: Scheduling FlushDeltaMemStoresOp(68567d8f78d34c5fae216e9eea115f87): perf score=18.063937
I20260812 06:19:29.022015 24657 maintenance_manager.cc:643] P 2d337fafbc4d4b31a1e02abeb1082be3: FlushDeltaMemStoresOp(68567d8f78d34c5fae216e9eea115f87) complete. Timing: real 0.057s	user 0.042s	sys 0.012s Metrics: {"bytes_written":20512315,"delete_count":0,"lbm_write_time_us":25410,"lbm_writes_lt_1ms":503,"reinsert_count":0,"update_count":2500}
I20260812 06:19:29.022603 24755 maintenance_manager.cc:419] P 2d337fafbc4d4b31a1e02abeb1082be3: Scheduling UndoDeltaBlockGCOp(68567d8f78d34c5fae216e9eea115f87): 507 bytes on disk
I20260812 06:19:29.023094 24657 maintenance_manager.cc:643] P 2d337fafbc4d4b31a1e02abeb1082be3: UndoDeltaBlockGCOp(68567d8f78d34c5fae216e9eea115f87) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":66,"lbm_reads_lt_1ms":4}
I20260812 06:19:29.023747 24755 maintenance_manager.cc:419] P 2d337fafbc4d4b31a1e02abeb1082be3: Scheduling FlushDeltaMemStoresOp(68567d8f78d34c5fae216e9eea115f87): perf score=2.188937
I20260812 06:19:29.039161 24657 maintenance_manager.cc:643] P 2d337fafbc4d4b31a1e02abeb1082be3: FlushDeltaMemStoresOp(68567d8f78d34c5fae216e9eea115f87) complete. Timing: real 0.015s	user 0.013s	sys 0.000s Metrics: {"bytes_written":4102660,"delete_count":0,"lbm_write_time_us":6052,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:29.039723 24755 maintenance_manager.cc:419] P 2d337fafbc4d4b31a1e02abeb1082be3: Scheduling MajorDeltaCompactionOp(68567d8f78d34c5fae216e9eea115f87): perf score=1.000000
I20260812 06:19:29.203234 24657 maintenance_manager.cc:643] P 2d337fafbc4d4b31a1e02abeb1082be3: MajorDeltaCompactionOp(68567d8f78d34c5fae216e9eea115f87) complete. Timing: real 0.163s	user 0.118s	sys 0.045s Metrics: {"cfile_cache_miss":632,"cfile_cache_miss_bytes":28836138,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":316,"lbm_read_time_us":13154,"lbm_reads_lt_1ms":672,"lbm_write_time_us":31907,"lbm_writes_lt_1ms":643,"mutex_wait_us":27,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":24576,"update_count":3000}
I20260812 06:19:29.203959 24755 maintenance_manager.cc:419] P 2d337fafbc4d4b31a1e02abeb1082be3: Scheduling FlushDeltaMemStoresOp(68567d8f78d34c5fae216e9eea115f87): perf score=14.095187
I20260812 06:19:29.254766 24657 maintenance_manager.cc:643] P 2d337fafbc4d4b31a1e02abeb1082be3: FlushDeltaMemStoresOp(68567d8f78d34c5fae216e9eea115f87) complete. Timing: real 0.051s	user 0.017s	sys 0.027s Metrics: {"bytes_written":16409900,"delete_count":0,"lbm_write_time_us":20227,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:29.255429 24755 maintenance_manager.cc:419] P 2d337fafbc4d4b31a1e02abeb1082be3: Scheduling FlushDeltaMemStoresOp(68567d8f78d34c5fae216e9eea115f87): perf score=2.188937
I20260812 06:19:29.267719 24657 maintenance_manager.cc:643] P 2d337fafbc4d4b31a1e02abeb1082be3: FlushDeltaMemStoresOp(68567d8f78d34c5fae216e9eea115f87) complete. Timing: real 0.012s	user 0.007s	sys 0.005s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4522,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:29.268196 24755 maintenance_manager.cc:419] P 2d337fafbc4d4b31a1e02abeb1082be3: Scheduling MajorDeltaCompactionOp(68567d8f78d34c5fae216e9eea115f87): perf score=1.000000
I20260812 06:19:29.445323 24657 maintenance_manager.cc:643] P 2d337fafbc4d4b31a1e02abeb1082be3: MajorDeltaCompactionOp(68567d8f78d34c5fae216e9eea115f87) complete. Timing: real 0.177s	user 0.126s	sys 0.044s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24733722,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":402,"lbm_read_time_us":12967,"lbm_reads_lt_1ms":572,"lbm_write_time_us":32995,"lbm_writes_lt_1ms":543,"mutex_wait_us":105,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":2688,"update_count":2500}
I20260812 06:19:29.446149 24755 maintenance_manager.cc:419] P 2d337fafbc4d4b31a1e02abeb1082be3: Scheduling FlushDeltaMemStoresOp(68567d8f78d34c5fae216e9eea115f87): perf score=14.095187
I20260812 06:19:29.492268 24657 maintenance_manager.cc:643] P 2d337fafbc4d4b31a1e02abeb1082be3: FlushDeltaMemStoresOp(68567d8f78d34c5fae216e9eea115f87) complete. Timing: real 0.046s	user 0.033s	sys 0.011s Metrics: {"bytes_written":16409903,"delete_count":0,"lbm_write_time_us":19549,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:29.492832 24755 maintenance_manager.cc:419] P 2d337fafbc4d4b31a1e02abeb1082be3: Scheduling MajorDeltaCompactionOp(68567d8f78d34c5fae216e9eea115f87): perf score=1.000000
I20260812 06:19:29.643764 24657 maintenance_manager.cc:643] P 2d337fafbc4d4b31a1e02abeb1082be3: MajorDeltaCompactionOp(68567d8f78d34c5fae216e9eea115f87) complete. Timing: real 0.151s	user 0.106s	sys 0.044s Metrics: {"cfile_cache_miss":431,"cfile_cache_miss_bytes":20631194,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":1,"delta_iterators_relevant":1,"dirs.queue_time_us":282,"lbm_read_time_us":10705,"lbm_reads_lt_1ms":467,"lbm_write_time_us":25834,"lbm_writes_lt_1ms":443,"mutex_wait_us":90,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":48640,"update_count":2000}
I20260812 06:19:29.644541 24755 maintenance_manager.cc:419] P 2d337fafbc4d4b31a1e02abeb1082be3: Scheduling FlushDeltaMemStoresOp(68567d8f78d34c5fae216e9eea115f87): perf score=10.126437
I20260812 06:19:29.687656 24657 maintenance_manager.cc:643] P 2d337fafbc4d4b31a1e02abeb1082be3: FlushDeltaMemStoresOp(68567d8f78d34c5fae216e9eea115f87) complete. Timing: real 0.043s	user 0.025s	sys 0.012s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":16400,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:19:29.688323 24755 maintenance_manager.cc:419] P 2d337fafbc4d4b31a1e02abeb1082be3: Scheduling FlushDeltaMemStoresOp(68567d8f78d34c5fae216e9eea115f87): perf score=2.188937
I20260812 06:19:29.706645 24657 maintenance_manager.cc:643] P 2d337fafbc4d4b31a1e02abeb1082be3: FlushDeltaMemStoresOp(68567d8f78d34c5fae216e9eea115f87) complete. Timing: real 0.018s	user 0.015s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6986,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:29.707182 24755 maintenance_manager.cc:419] P 2d337fafbc4d4b31a1e02abeb1082be3: Scheduling MajorDeltaCompactionOp(68567d8f78d34c5fae216e9eea115f87): perf score=1.000000
I20260812 06:19:29.845417 24657 maintenance_manager.cc:643] P 2d337fafbc4d4b31a1e02abeb1082be3: MajorDeltaCompactionOp(68567d8f78d34c5fae216e9eea115f87) complete. Timing: real 0.138s	user 0.096s	sys 0.035s 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":1751,"lbm_read_time_us":9350,"lbm_reads_lt_1ms":472,"lbm_write_time_us":27017,"lbm_writes_lt_1ms":443,"mutex_wait_us":606,"peak_mem_usage":50689328,"reinsert_count":0,"update_count":2000}
I20260812 06:19:29.846125 24755 maintenance_manager.cc:419] P 2d337fafbc4d4b31a1e02abeb1082be3: Scheduling FlushDeltaMemStoresOp(68567d8f78d34c5fae216e9eea115f87): perf score=10.126437
I20260812 06:19:29.891880 24657 maintenance_manager.cc:643] P 2d337fafbc4d4b31a1e02abeb1082be3: FlushDeltaMemStoresOp(68567d8f78d34c5fae216e9eea115f87) complete. Timing: real 0.046s	user 0.018s	sys 0.023s Metrics: {"bytes_written":12307489,"delete_count":0,"lbm_write_time_us":19514,"lbm_writes_1-10_ms":2,"lbm_writes_lt_1ms":301,"reinsert_count":0,"update_count":1500}
I20260812 06:19:29.892406 24755 maintenance_manager.cc:419] P 2d337fafbc4d4b31a1e02abeb1082be3: Scheduling FlushDeltaMemStoresOp(68567d8f78d34c5fae216e9eea115f87): perf score=2.188937
I20260812 06:19:29.904536 24657 maintenance_manager.cc:643] P 2d337fafbc4d4b31a1e02abeb1082be3: FlushDeltaMemStoresOp(68567d8f78d34c5fae216e9eea115f87) complete. Timing: real 0.012s	user 0.007s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4290,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:29.905273 24755 maintenance_manager.cc:419] P 2d337fafbc4d4b31a1e02abeb1082be3: Scheduling MajorDeltaCompactionOp(68567d8f78d34c5fae216e9eea115f87): perf score=1.000000
I20260812 06:19:30.040475 24657 maintenance_manager.cc:643] P 2d337fafbc4d4b31a1e02abeb1082be3: MajorDeltaCompactionOp(68567d8f78d34c5fae216e9eea115f87) complete. Timing: real 0.135s	user 0.100s	sys 0.034s 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":246,"lbm_read_time_us":10191,"lbm_reads_lt_1ms":472,"lbm_write_time_us":26457,"lbm_writes_lt_1ms":443,"mutex_wait_us":99,"peak_mem_usage":50689328,"reinsert_count":0,"update_count":2000}
I20260812 06:19:30.041244 24755 maintenance_manager.cc:419] P 2d337fafbc4d4b31a1e02abeb1082be3: Scheduling FlushDeltaMemStoresOp(68567d8f78d34c5fae216e9eea115f87): perf score=10.126437
I20260812 06:19:30.090761 24657 maintenance_manager.cc:643] P 2d337fafbc4d4b31a1e02abeb1082be3: FlushDeltaMemStoresOp(68567d8f78d34c5fae216e9eea115f87) complete. Timing: real 0.049s	user 0.019s	sys 0.020s Metrics: {"bytes_written":12307493,"delete_count":0,"lbm_write_time_us":19742,"lbm_writes_1-10_ms":2,"lbm_writes_lt_1ms":301,"reinsert_count":0,"update_count":1500}
I20260812 06:19:30.091424 24755 maintenance_manager.cc:419] P 2d337fafbc4d4b31a1e02abeb1082be3: Scheduling FlushDeltaMemStoresOp(68567d8f78d34c5fae216e9eea115f87): perf score=2.188937
I20260812 06:19:30.108170 24657 maintenance_manager.cc:643] P 2d337fafbc4d4b31a1e02abeb1082be3: FlushDeltaMemStoresOp(68567d8f78d34c5fae216e9eea115f87) complete. Timing: real 0.016s	user 0.011s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6166,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:30.108821 24755 maintenance_manager.cc:419] P 2d337fafbc4d4b31a1e02abeb1082be3: Scheduling FlushMRSOp(68567d8f78d34c5fae216e9eea115f87): perf score=1.000000
I20260812 06:19:30.137419 24657 maintenance_manager.cc:643] P 2d337fafbc4d4b31a1e02abeb1082be3: FlushMRSOp(68567d8f78d34c5fae216e9eea115f87) complete. Timing: real 0.028s	user 0.027s	sys 0.000s Metrics: {"bytes_written":1193507,"cfile_init":1,"dirs.queue_time_us":84,"dirs.run_cpu_time_us":227,"dirs.run_wall_time_us":1872,"drs_written":1,"lbm_read_time_us":127,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1575,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":29}
I20260812 06:19:30.138141 24755 maintenance_manager.cc:419] P 2d337fafbc4d4b31a1e02abeb1082be3: Scheduling LogGCOp(68567d8f78d34c5fae216e9eea115f87): free 112239552 bytes of WAL
I20260812 06:19:30.138382 24657 log_reader.cc:385] T 68567d8f78d34c5fae216e9eea115f87: removed 11 log segments from log reader
I20260812 06:19:30.138427 24657 log.cc:1079] T 68567d8f78d34c5fae216e9eea115f87 P 2d337fafbc4d4b31a1e02abeb1082be3: Deleting log segment in path: /tmp/dist-test-taskseRmjK/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515564944993-24506-0/minicluster-data/ts-0-root/wals/68567d8f78d34c5fae216e9eea115f87/wal-000000029 (ops 139-143)
I20260812 06:19:30.138458 24657 log.cc:1079] T 68567d8f78d34c5fae216e9eea115f87 P 2d337fafbc4d4b31a1e02abeb1082be3: Deleting log segment in path: /tmp/dist-test-taskseRmjK/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515564944993-24506-0/minicluster-data/ts-0-root/wals/68567d8f78d34c5fae216e9eea115f87/wal-000000030 (ops 144-148)
I20260812 06:19:30.138525 24657 log.cc:1079] T 68567d8f78d34c5fae216e9eea115f87 P 2d337fafbc4d4b31a1e02abeb1082be3: Deleting log segment in path: /tmp/dist-test-taskseRmjK/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515564944993-24506-0/minicluster-data/ts-0-root/wals/68567d8f78d34c5fae216e9eea115f87/wal-000000031 (ops 149-153)
I20260812 06:19:30.138557 24657 log.cc:1079] T 68567d8f78d34c5fae216e9eea115f87 P 2d337fafbc4d4b31a1e02abeb1082be3: Deleting log segment in path: /tmp/dist-test-taskseRmjK/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515564944993-24506-0/minicluster-data/ts-0-root/wals/68567d8f78d34c5fae216e9eea115f87/wal-000000032 (ops 154-158)
I20260812 06:19:30.138597 24657 log.cc:1079] T 68567d8f78d34c5fae216e9eea115f87 P 2d337fafbc4d4b31a1e02abeb1082be3: Deleting log segment in path: /tmp/dist-test-taskseRmjK/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515564944993-24506-0/minicluster-data/ts-0-root/wals/68567d8f78d34c5fae216e9eea115f87/wal-000000033 (ops 159-163)
I20260812 06:19:30.138639 24657 log.cc:1079] T 68567d8f78d34c5fae216e9eea115f87 P 2d337fafbc4d4b31a1e02abeb1082be3: Deleting log segment in path: /tmp/dist-test-taskseRmjK/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515564944993-24506-0/minicluster-data/ts-0-root/wals/68567d8f78d34c5fae216e9eea115f87/wal-000000034 (ops 164-168)
I20260812 06:19:30.138677 24657 log.cc:1079] T 68567d8f78d34c5fae216e9eea115f87 P 2d337fafbc4d4b31a1e02abeb1082be3: Deleting log segment in path: /tmp/dist-test-taskseRmjK/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515564944993-24506-0/minicluster-data/ts-0-root/wals/68567d8f78d34c5fae216e9eea115f87/wal-000000035 (ops 169-173)
I20260812 06:19:30.138720 24657 log.cc:1079] T 68567d8f78d34c5fae216e9eea115f87 P 2d337fafbc4d4b31a1e02abeb1082be3: Deleting log segment in path: /tmp/dist-test-taskseRmjK/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515564944993-24506-0/minicluster-data/ts-0-root/wals/68567d8f78d34c5fae216e9eea115f87/wal-000000036 (ops 174-178)
I20260812 06:19:30.138759 24657 log.cc:1079] T 68567d8f78d34c5fae216e9eea115f87 P 2d337fafbc4d4b31a1e02abeb1082be3: Deleting log segment in path: /tmp/dist-test-taskseRmjK/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515564944993-24506-0/minicluster-data/ts-0-root/wals/68567d8f78d34c5fae216e9eea115f87/wal-000000037 (ops 179-183)
I20260812 06:19:30.138798 24657 log.cc:1079] T 68567d8f78d34c5fae216e9eea115f87 P 2d337fafbc4d4b31a1e02abeb1082be3: Deleting log segment in path: /tmp/dist-test-taskseRmjK/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515564944993-24506-0/minicluster-data/ts-0-root/wals/68567d8f78d34c5fae216e9eea115f87/wal-000000038 (ops 184-188)
I20260812 06:19:30.138836 24657 log.cc:1079] T 68567d8f78d34c5fae216e9eea115f87 P 2d337fafbc4d4b31a1e02abeb1082be3: Deleting log segment in path: /tmp/dist-test-taskseRmjK/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515564944993-24506-0/minicluster-data/ts-0-root/wals/68567d8f78d34c5fae216e9eea115f87/wal-000000039 (ops 189-192)
I20260812 06:19:30.166893 24657 maintenance_manager.cc:643] P 2d337fafbc4d4b31a1e02abeb1082be3: LogGCOp(68567d8f78d34c5fae216e9eea115f87) complete. Timing: real 0.029s	user 0.000s	sys 0.025s Metrics: {}
I20260812 06:19:30.167580 24755 maintenance_manager.cc:419] P 2d337fafbc4d4b31a1e02abeb1082be3: Scheduling UndoDeltaBlockGCOp(68567d8f78d34c5fae216e9eea115f87): 463 bytes on disk
I20260812 06:19:30.168104 24657 maintenance_manager.cc:643] P 2d337fafbc4d4b31a1e02abeb1082be3: UndoDeltaBlockGCOp(68567d8f78d34c5fae216e9eea115f87) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":74,"lbm_reads_lt_1ms":4}
I20260812 06:19:30.168789 24755 maintenance_manager.cc:419] P 2d337fafbc4d4b31a1e02abeb1082be3: Scheduling FlushDeltaMemStoresOp(68567d8f78d34c5fae216e9eea115f87): perf score=3.181125
I20260812 06:19:30.187939 24657 maintenance_manager.cc:643] P 2d337fafbc4d4b31a1e02abeb1082be3: FlushDeltaMemStoresOp(68567d8f78d34c5fae216e9eea115f87) complete. Timing: real 0.019s	user 0.018s	sys 0.000s Metrics: {"bytes_written":4594951,"delete_count":0,"lbm_write_time_us":7823,"lbm_writes_lt_1ms":115,"reinsert_count":0,"update_count":560}
I20260812 06:19:30.188431 24755 maintenance_manager.cc:419] P 2d337fafbc4d4b31a1e02abeb1082be3: Scheduling FlushDeltaMemStoresOp(68567d8f78d34c5fae216e9eea115f87): perf score=2.188937
I20260812 06:19:30.199057 24657 maintenance_manager.cc:643] P 2d337fafbc4d4b31a1e02abeb1082be3: FlushDeltaMemStoresOp(68567d8f78d34c5fae216e9eea115f87) complete. Timing: real 0.010s	user 0.005s	sys 0.004s Metrics: {"bytes_written":3610355,"delete_count":0,"lbm_write_time_us":3869,"lbm_writes_lt_1ms":91,"reinsert_count":0,"update_count":440}
I20260812 06:19:30.199666 24755 maintenance_manager.cc:419] P 2d337fafbc4d4b31a1e02abeb1082be3: Scheduling MajorDeltaCompactionOp(68567d8f78d34c5fae216e9eea115f87): perf score=1.000000
I20260812 06:19:30.274053 24506 heavy-update-compaction-itest.cc:229] Time spent updating: real 5.018s	user 1.890s	sys 0.135s
I20260812 06:19:30.365764 24657 maintenance_manager.cc:643] P 2d337fafbc4d4b31a1e02abeb1082be3: MajorDeltaCompactionOp(68567d8f78d34c5fae216e9eea115f87) complete. Timing: real 0.166s	user 0.125s	sys 0.041s Metrics: {"cfile_cache_miss":634,"cfile_cache_miss_bytes":28836365,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":170,"lbm_read_time_us":13032,"lbm_reads_lt_1ms":670,"lbm_write_time_us":33796,"lbm_writes_lt_1ms":643,"mutex_wait_us":31,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":3200,"thread_start_us":79,"threads_started":1,"update_count":3000}
I20260812 06:19:30.366514 24755 maintenance_manager.cc:419] P 2d337fafbc4d4b31a1e02abeb1082be3: Scheduling FlushDeltaMemStoresOp(68567d8f78d34c5fae216e9eea115f87): perf score=6.157687
I20260812 06:19:30.369671 24506 heavy-update-compaction-itest.cc:265] Time spent scanning: real 0.095s	user 0.004s	sys 0.000s
I20260812 06:19:30.370530 24506 tablet_server.cc:179] TabletServer@127.23.238.129:0 shutting down...
I20260812 06:19:30.394899 24657 maintenance_manager.cc:643] P 2d337fafbc4d4b31a1e02abeb1082be3: FlushDeltaMemStoresOp(68567d8f78d34c5fae216e9eea115f87) complete. Timing: real 0.028s	user 0.009s	sys 0.015s Metrics: {"bytes_written":8205078,"delete_count":0,"lbm_write_time_us":11866,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":202,"reinsert_count":0,"update_count":1000}
I20260812 06:19:30.395699 24506 ts_tablet_manager.cc:1507] Shutting down tablet manager...
I20260812 06:19:30.396202 24506 tablet_replica.cc:333] T 68567d8f78d34c5fae216e9eea115f87 P 2d337fafbc4d4b31a1e02abeb1082be3: stopping tablet replica
I20260812 06:19:30.396463 24506 raft_consensus.cc:2243] T 68567d8f78d34c5fae216e9eea115f87 P 2d337fafbc4d4b31a1e02abeb1082be3 [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:19:30.396708 24506 raft_consensus.cc:2272] T 68567d8f78d34c5fae216e9eea115f87 P 2d337fafbc4d4b31a1e02abeb1082be3 [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:19:30.412346 24506 tablet_server.cc:196] TabletServer@127.23.238.129:0 shutdown complete.
I20260812 06:19:30.418092 24506 master.cc:562] Master@127.23.238.190:39379 shutting down...
I20260812 06:19:30.422024 24506 raft_consensus.cc:2243] T 00000000000000000000000000000000 P 091d44e105654242be64d4d27238da9d [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:19:30.422209 24506 raft_consensus.cc:2272] T 00000000000000000000000000000000 P 091d44e105654242be64d4d27238da9d [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:19:30.422269 24506 tablet_replica.cc:333] T 00000000000000000000000000000000 P 091d44e105654242be64d4d27238da9d: stopping tablet replica
I20260812 06:19:30.435182 24506 master.cc:584] Master@127.23.238.190:39379 shutdown complete.
[       OK ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/0 (5572 ms)
[ RUN      ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/1
I20260812 06:19:30.528595 24506 internal_mini_cluster.cc:156] Creating distributed mini masters. Addrs: 127.23.238.190:34809
I20260812 06:19:30.528950 24506 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:19:30.531126 24797 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:30.531267 24798 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:30.531307 24506 server_base.cc:1061] running on GCE node
W20260812 06:19:30.531404 24800 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:30.531733 24506 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:19:30.531790 24506 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:30.531807 24506 hybrid_clock.cc:648] HybridClock initialized: now 1786515570531807 us; error 0 us; skew 500 ppm
I20260812 06:19:30.532874 24506 webserver.cc:533] Webserver started at http://127.23.238.190:43177/ using document root <none> and password file <none>
I20260812 06:19:30.533077 24506 fs_manager.cc:362] Metadata directory not provided
I20260812 06:19:30.533129 24506 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:19:30.533185 24506 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:19:30.533551 24506 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskseRmjK/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515564944993-24506-0/minicluster-data/master-0-root/instance:
uuid: "7a4e0b8c3832438b89e77e79a4e28bce"
format_stamp: "Formatted at 2026-08-12 06:19:30 on dist-test-slave-sb2z"
I20260812 06:19:30.535197 24506 fs_manager.cc:696] Time spent creating directory manager: real 0.001s	user 0.002s	sys 0.000s
I20260812 06:19:30.536520 24807 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:30.536821 24506 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.001s	sys 0.000s
I20260812 06:19:30.536902 24506 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskseRmjK/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515564944993-24506-0/minicluster-data/master-0-root
uuid: "7a4e0b8c3832438b89e77e79a4e28bce"
format_stamp: "Formatted at 2026-08-12 06:19:30 on dist-test-slave-sb2z"
I20260812 06:19:30.536970 24506 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskseRmjK/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515564944993-24506-0/minicluster-data/master-0-root
metadata directory: /tmp/dist-test-taskseRmjK/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515564944993-24506-0/minicluster-data/master-0-root
1 data directories: /tmp/dist-test-taskseRmjK/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515564944993-24506-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:30.552194 24506 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:19:30.552613 24506 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:19:30.556897 24506 rpc_server.cc:307] RPC server started. Bound to: 127.23.238.190:34809
I20260812 06:19:30.558745 24894 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:30.559378 24893 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.23.238.190:34809 every 8 connection(s)
I20260812 06:19:30.577901 24894 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P 7a4e0b8c3832438b89e77e79a4e28bce: Bootstrap starting.
I20260812 06:19:30.578907 24894 tablet_bootstrap.cc:654] T 00000000000000000000000000000000 P 7a4e0b8c3832438b89e77e79a4e28bce: Neither blocks nor log segments found. Creating new log.
I20260812 06:19:30.580286 24894 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P 7a4e0b8c3832438b89e77e79a4e28bce: No bootstrap required, opened a new log
I20260812 06:19:30.580780 24894 raft_consensus.cc:359] T 00000000000000000000000000000000 P 7a4e0b8c3832438b89e77e79a4e28bce [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "7a4e0b8c3832438b89e77e79a4e28bce" member_type: VOTER }
I20260812 06:19:30.580936 24894 raft_consensus.cc:385] T 00000000000000000000000000000000 P 7a4e0b8c3832438b89e77e79a4e28bce [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:19:30.581027 24894 raft_consensus.cc:740] T 00000000000000000000000000000000 P 7a4e0b8c3832438b89e77e79a4e28bce [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: 7a4e0b8c3832438b89e77e79a4e28bce, State: Initialized, Role: FOLLOWER
I20260812 06:19:30.581214 24894 consensus_queue.cc:260] T 00000000000000000000000000000000 P 7a4e0b8c3832438b89e77e79a4e28bce [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: "7a4e0b8c3832438b89e77e79a4e28bce" member_type: VOTER }
I20260812 06:19:30.581321 24894 raft_consensus.cc:399] T 00000000000000000000000000000000 P 7a4e0b8c3832438b89e77e79a4e28bce [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:19:30.581375 24894 raft_consensus.cc:493] T 00000000000000000000000000000000 P 7a4e0b8c3832438b89e77e79a4e28bce [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:19:30.581439 24894 raft_consensus.cc:3060] T 00000000000000000000000000000000 P 7a4e0b8c3832438b89e77e79a4e28bce [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:19:30.582284 24894 raft_consensus.cc:515] T 00000000000000000000000000000000 P 7a4e0b8c3832438b89e77e79a4e28bce [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "7a4e0b8c3832438b89e77e79a4e28bce" member_type: VOTER }
I20260812 06:19:30.582455 24894 leader_election.cc:304] T 00000000000000000000000000000000 P 7a4e0b8c3832438b89e77e79a4e28bce [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: 7a4e0b8c3832438b89e77e79a4e28bce; no voters: 
I20260812 06:19:30.582707 24894 leader_election.cc:290] T 00000000000000000000000000000000 P 7a4e0b8c3832438b89e77e79a4e28bce [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:19:30.582911 24897 raft_consensus.cc:2804] T 00000000000000000000000000000000 P 7a4e0b8c3832438b89e77e79a4e28bce [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:19:30.583144 24897 raft_consensus.cc:697] T 00000000000000000000000000000000 P 7a4e0b8c3832438b89e77e79a4e28bce [term 1 LEADER]: Becoming Leader. State: Replica: 7a4e0b8c3832438b89e77e79a4e28bce, State: Running, Role: LEADER
I20260812 06:19:30.583362 24897 consensus_queue.cc:237] T 00000000000000000000000000000000 P 7a4e0b8c3832438b89e77e79a4e28bce [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: "7a4e0b8c3832438b89e77e79a4e28bce" member_type: VOTER }
I20260812 06:19:30.583422 24894 sys_catalog.cc:565] T 00000000000000000000000000000000 P 7a4e0b8c3832438b89e77e79a4e28bce [sys.catalog]: configured and running, proceeding with master startup.
I20260812 06:19:30.583913 24899 sys_catalog.cc:455] T 00000000000000000000000000000000 P 7a4e0b8c3832438b89e77e79a4e28bce [sys.catalog]: SysCatalogTable state changed. Reason: New leader 7a4e0b8c3832438b89e77e79a4e28bce. Latest consensus state: current_term: 1 leader_uuid: "7a4e0b8c3832438b89e77e79a4e28bce" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "7a4e0b8c3832438b89e77e79a4e28bce" member_type: VOTER } }
I20260812 06:19:30.584020 24898 sys_catalog.cc:455] T 00000000000000000000000000000000 P 7a4e0b8c3832438b89e77e79a4e28bce [sys.catalog]: SysCatalogTable state changed. Reason: RaftConsensus started. Latest consensus state: current_term: 1 leader_uuid: "7a4e0b8c3832438b89e77e79a4e28bce" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "7a4e0b8c3832438b89e77e79a4e28bce" member_type: VOTER } }
I20260812 06:19:30.584074 24899 sys_catalog.cc:458] T 00000000000000000000000000000000 P 7a4e0b8c3832438b89e77e79a4e28bce [sys.catalog]: This master's current role is: LEADER
I20260812 06:19:30.584131 24898 sys_catalog.cc:458] T 00000000000000000000000000000000 P 7a4e0b8c3832438b89e77e79a4e28bce [sys.catalog]: This master's current role is: LEADER
I20260812 06:19:30.584640 24903 catalog_manager.cc:1511] Loading table and tablet metadata into memory...
I20260812 06:19:30.585846 24903 catalog_manager.cc:1520] Initializing Kudu cluster ID...
I20260812 06:19:30.586118 24506 internal_mini_cluster.cc:184] Waiting to initialize catalog manager on master 0
I20260812 06:19:30.587955 24903 catalog_manager.cc:1383] Generated new cluster ID: 65bd625af0f646ac9bf1ce5779dcdd86
I20260812 06:19:30.588018 24903 catalog_manager.cc:1531] Initializing Kudu internal certificate authority...
I20260812 06:19:30.599466 24903 catalog_manager.cc:1406] Generated new certificate authority record
I20260812 06:19:30.600195 24903 catalog_manager.cc:1540] Loading token signing keys...
I20260812 06:19:30.606248 24903 catalog_manager.cc:6092] T 00000000000000000000000000000000 P 7a4e0b8c3832438b89e77e79a4e28bce: Generated new TSK 0
I20260812 06:19:30.606485 24903 catalog_manager.cc:1550] Initializing in-progress tserver states...
I20260812 06:19:30.618762 24506 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:19:30.621287 24921 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:30.621439 24918 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:30.621464 24919 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:30.621486 24506 server_base.cc:1061] running on GCE node
I20260812 06:19:30.621830 24506 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:19:30.621877 24506 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:30.621894 24506 hybrid_clock.cc:648] HybridClock initialized: now 1786515570621895 us; error 0 us; skew 500 ppm
I20260812 06:19:30.623070 24506 webserver.cc:533] Webserver started at http://127.23.238.129:43511/ using document root <none> and password file <none>
I20260812 06:19:30.623296 24506 fs_manager.cc:362] Metadata directory not provided
I20260812 06:19:30.623389 24506 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:19:30.623492 24506 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:19:30.624002 24506 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskseRmjK/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515564944993-24506-0/minicluster-data/ts-0-root/instance:
uuid: "ec1f864124be4b048a3aca4402da4160"
format_stamp: "Formatted at 2026-08-12 06:19:30 on dist-test-slave-sb2z"
I20260812 06:19:30.625775 24506 fs_manager.cc:696] Time spent creating directory manager: real 0.002s	user 0.000s	sys 0.002s
I20260812 06:19:30.626916 24928 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:30.627288 24506 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.000s	sys 0.001s
I20260812 06:19:30.627381 24506 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskseRmjK/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515564944993-24506-0/minicluster-data/ts-0-root
uuid: "ec1f864124be4b048a3aca4402da4160"
format_stamp: "Formatted at 2026-08-12 06:19:30 on dist-test-slave-sb2z"
I20260812 06:19:30.627480 24506 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskseRmjK/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515564944993-24506-0/minicluster-data/ts-0-root
metadata directory: /tmp/dist-test-taskseRmjK/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515564944993-24506-0/minicluster-data/ts-0-root
1 data directories: /tmp/dist-test-taskseRmjK/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515564944993-24506-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:30.634866 24506 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:19:30.635277 24506 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:19:30.635644 24506 txn_system_client.cc:432] TxnSystemClient initialization is disabled...
I20260812 06:19:30.636124 24506 ts_tablet_manager.cc:585] Loaded tablet metadata (0 total tablets, 0 live tablets)
I20260812 06:19:30.636184 24506 ts_tablet_manager.cc:531] Time spent load tablet metadata: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:19:30.636243 24506 ts_tablet_manager.cc:616] Registered 0 tablets
I20260812 06:19:30.636293 24506 ts_tablet_manager.cc:595] Time spent register tablets: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:19:30.641355 24506 rpc_server.cc:307] RPC server started. Bound to: 127.23.238.129:45591
I20260812 06:19:30.641440 25038 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.23.238.129:45591 every 8 connection(s)
I20260812 06:19:30.650807 25040 heartbeater.cc:344] Connected to a master server at 127.23.238.190:34809
I20260812 06:19:30.650981 25040 heartbeater.cc:461] Registering TS with master...
I20260812 06:19:30.651280 25040 heartbeater.cc:507] Master 127.23.238.190:34809 requested a full tablet report, sending...
I20260812 06:19:30.652029 24828 ts_manager.cc:194] Registered new tserver with Master: ec1f864124be4b048a3aca4402da4160 (127.23.238.129:45591)
I20260812 06:19:30.652128 24506 internal_mini_cluster.cc:371] 1 TS(s) registered with all masters after 0.010258671s
I20260812 06:19:30.652945 24828 master_service.cc:502] Signed X509 certificate for tserver {username='slave'} at 127.0.0.1:50680
I20260812 06:19:30.660372 24828 catalog_manager.cc:2283] Servicing CreateTable request from {username='slave'} at 127.0.0.1:50684:
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:30.670202 24976 tablet_service.cc:1511] Processing CreateTablet for tablet e3fe7a3d8a6d4ee7ad19b69fd53aff70 (DEFAULT_TABLE table=heavy-update-compaction-test [id=13912973f21b4bd5938c0e8a3ba14fa4]), partition=
I20260812 06:19:30.670517 24976 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet e3fe7a3d8a6d4ee7ad19b69fd53aff70. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:19:30.673069 25057 tablet_bootstrap.cc:492] T e3fe7a3d8a6d4ee7ad19b69fd53aff70 P ec1f864124be4b048a3aca4402da4160: Bootstrap starting.
I20260812 06:19:30.673945 25057 tablet_bootstrap.cc:654] T e3fe7a3d8a6d4ee7ad19b69fd53aff70 P ec1f864124be4b048a3aca4402da4160: Neither blocks nor log segments found. Creating new log.
I20260812 06:19:30.675148 25057 tablet_bootstrap.cc:492] T e3fe7a3d8a6d4ee7ad19b69fd53aff70 P ec1f864124be4b048a3aca4402da4160: No bootstrap required, opened a new log
I20260812 06:19:30.675271 25057 ts_tablet_manager.cc:1403] T e3fe7a3d8a6d4ee7ad19b69fd53aff70 P ec1f864124be4b048a3aca4402da4160: Time spent bootstrapping tablet: real 0.002s	user 0.002s	sys 0.000s
I20260812 06:19:30.675918 25057 raft_consensus.cc:359] T e3fe7a3d8a6d4ee7ad19b69fd53aff70 P ec1f864124be4b048a3aca4402da4160 [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "ec1f864124be4b048a3aca4402da4160" member_type: VOTER last_known_addr { host: "127.23.238.129" port: 45591 } }
I20260812 06:19:30.676018 25057 raft_consensus.cc:385] T e3fe7a3d8a6d4ee7ad19b69fd53aff70 P ec1f864124be4b048a3aca4402da4160 [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:19:30.676043 25057 raft_consensus.cc:740] T e3fe7a3d8a6d4ee7ad19b69fd53aff70 P ec1f864124be4b048a3aca4402da4160 [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: ec1f864124be4b048a3aca4402da4160, State: Initialized, Role: FOLLOWER
I20260812 06:19:30.676142 25057 consensus_queue.cc:260] T e3fe7a3d8a6d4ee7ad19b69fd53aff70 P ec1f864124be4b048a3aca4402da4160 [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: "ec1f864124be4b048a3aca4402da4160" member_type: VOTER last_known_addr { host: "127.23.238.129" port: 45591 } }
I20260812 06:19:30.676201 25057 raft_consensus.cc:399] T e3fe7a3d8a6d4ee7ad19b69fd53aff70 P ec1f864124be4b048a3aca4402da4160 [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:19:30.676224 25057 raft_consensus.cc:493] T e3fe7a3d8a6d4ee7ad19b69fd53aff70 P ec1f864124be4b048a3aca4402da4160 [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:19:30.676257 25057 raft_consensus.cc:3060] T e3fe7a3d8a6d4ee7ad19b69fd53aff70 P ec1f864124be4b048a3aca4402da4160 [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:19:30.677035 25057 raft_consensus.cc:515] T e3fe7a3d8a6d4ee7ad19b69fd53aff70 P ec1f864124be4b048a3aca4402da4160 [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "ec1f864124be4b048a3aca4402da4160" member_type: VOTER last_known_addr { host: "127.23.238.129" port: 45591 } }
I20260812 06:19:30.677157 25057 leader_election.cc:304] T e3fe7a3d8a6d4ee7ad19b69fd53aff70 P ec1f864124be4b048a3aca4402da4160 [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: ec1f864124be4b048a3aca4402da4160; no voters: 
I20260812 06:19:30.677325 25057 leader_election.cc:290] T e3fe7a3d8a6d4ee7ad19b69fd53aff70 P ec1f864124be4b048a3aca4402da4160 [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:19:30.677486 25059 raft_consensus.cc:2804] T e3fe7a3d8a6d4ee7ad19b69fd53aff70 P ec1f864124be4b048a3aca4402da4160 [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:19:30.677665 25057 ts_tablet_manager.cc:1434] T e3fe7a3d8a6d4ee7ad19b69fd53aff70 P ec1f864124be4b048a3aca4402da4160: Time spent starting tablet: real 0.002s	user 0.003s	sys 0.000s
I20260812 06:19:30.677726 25040 heartbeater.cc:499] Master 127.23.238.190:34809 was elected leader, sending a full tablet report...
I20260812 06:19:30.677748 25059 raft_consensus.cc:697] T e3fe7a3d8a6d4ee7ad19b69fd53aff70 P ec1f864124be4b048a3aca4402da4160 [term 1 LEADER]: Becoming Leader. State: Replica: ec1f864124be4b048a3aca4402da4160, State: Running, Role: LEADER
I20260812 06:19:30.677901 25059 consensus_queue.cc:237] T e3fe7a3d8a6d4ee7ad19b69fd53aff70 P ec1f864124be4b048a3aca4402da4160 [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: "ec1f864124be4b048a3aca4402da4160" member_type: VOTER last_known_addr { host: "127.23.238.129" port: 45591 } }
I20260812 06:19:30.679706 24828 catalog_manager.cc:5719] T e3fe7a3d8a6d4ee7ad19b69fd53aff70 P ec1f864124be4b048a3aca4402da4160 reported cstate change: term changed from 0 to 1, leader changed from <none> to ec1f864124be4b048a3aca4402da4160 (127.23.238.129). New cstate: current_term: 1 leader_uuid: "ec1f864124be4b048a3aca4402da4160" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "ec1f864124be4b048a3aca4402da4160" member_type: VOTER last_known_addr { host: "127.23.238.129" port: 45591 } health_report { overall_health: HEALTHY } } }
I20260812 06:19:30.744910 24506 heavy-update-compaction-itest.cc:215] Time spent inserting: real 0.057s	user 0.020s	sys 0.003s
I20260812 06:19:30.892361 25043 maintenance_manager.cc:419] P ec1f864124be4b048a3aca4402da4160: Scheduling FlushMRSOp(e3fe7a3d8a6d4ee7ad19b69fd53aff70): perf score=19.054940
I20260812 06:19:31.059425 24934 maintenance_manager.cc:643] P ec1f864124be4b048a3aca4402da4160: FlushMRSOp(e3fe7a3d8a6d4ee7ad19b69fd53aff70) complete. Timing: real 0.167s	user 0.112s	sys 0.048s Metrics: {"bytes_written":12307491,"cfile_init":1,"delete_count":0,"dirs.queue_time_us":84,"dirs.run_cpu_time_us":247,"dirs.run_wall_time_us":1020,"drs_written":1,"lbm_read_time_us":43,"lbm_reads_lt_1ms":4,"lbm_write_time_us":44722,"lbm_writes_lt_1ms":757,"peak_mem_usage":0,"reinsert_count":0,"rows_written":104,"update_count":1500}
I20260812 06:19:31.060273 25043 maintenance_manager.cc:419] P ec1f864124be4b048a3aca4402da4160: Scheduling LogGCOp(e3fe7a3d8a6d4ee7ad19b69fd53aff70): free 20743831 bytes of WAL
I20260812 06:19:31.060597 24934 log_reader.cc:385] T e3fe7a3d8a6d4ee7ad19b69fd53aff70: removed 2 log segments from log reader
I20260812 06:19:31.060680 24934 log.cc:1079] T e3fe7a3d8a6d4ee7ad19b69fd53aff70 P ec1f864124be4b048a3aca4402da4160: Deleting log segment in path: /tmp/dist-test-taskseRmjK/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515564944993-24506-0/minicluster-data/ts-0-root/wals/e3fe7a3d8a6d4ee7ad19b69fd53aff70/wal-000000001 (ops 1-6)
I20260812 06:19:31.060741 24934 log.cc:1079] T e3fe7a3d8a6d4ee7ad19b69fd53aff70 P ec1f864124be4b048a3aca4402da4160: Deleting log segment in path: /tmp/dist-test-taskseRmjK/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515564944993-24506-0/minicluster-data/ts-0-root/wals/e3fe7a3d8a6d4ee7ad19b69fd53aff70/wal-000000002 (ops 7-11)
I20260812 06:19:31.065590 24934 maintenance_manager.cc:643] P ec1f864124be4b048a3aca4402da4160: LogGCOp(e3fe7a3d8a6d4ee7ad19b69fd53aff70) complete. Timing: real 0.005s	user 0.000s	sys 0.003s Metrics: {}
I20260812 06:19:31.066159 25043 maintenance_manager.cc:419] P ec1f864124be4b048a3aca4402da4160: Scheduling UndoDeltaBlockGCOp(e3fe7a3d8a6d4ee7ad19b69fd53aff70): 16411394 bytes on disk
I20260812 06:19:31.066691 24934 maintenance_manager.cc:643] P ec1f864124be4b048a3aca4402da4160: UndoDeltaBlockGCOp(e3fe7a3d8a6d4ee7ad19b69fd53aff70) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":93,"lbm_reads_lt_1ms":4}
I20260812 06:19:31.067237 25043 maintenance_manager.cc:419] P ec1f864124be4b048a3aca4402da4160: Scheduling FlushDeltaMemStoresOp(e3fe7a3d8a6d4ee7ad19b69fd53aff70): perf score=2.188937
I20260812 06:19:31.084429 24934 maintenance_manager.cc:643] P ec1f864124be4b048a3aca4402da4160: FlushDeltaMemStoresOp(e3fe7a3d8a6d4ee7ad19b69fd53aff70) complete. Timing: real 0.017s	user 0.012s	sys 0.003s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6102,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:31.084887 25043 maintenance_manager.cc:419] P ec1f864124be4b048a3aca4402da4160: Scheduling MajorDeltaCompactionOp(e3fe7a3d8a6d4ee7ad19b69fd53aff70): perf score=1.000000
I20260812 06:19:31.238380 24934 maintenance_manager.cc:643] P ec1f864124be4b048a3aca4402da4160: MajorDeltaCompactionOp(e3fe7a3d8a6d4ee7ad19b69fd53aff70) complete. Timing: real 0.153s	user 0.108s	sys 0.040s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672278,"cfile_init":7,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":603,"lbm_read_time_us":11194,"lbm_reads_lt_1ms":460,"lbm_write_time_us":26431,"lbm_writes_lt_1ms":443,"peak_mem_usage":50689328,"reinsert_count":0,"thread_start_us":380,"threads_started":5,"update_count":2000}
I20260812 06:19:31.239135 25043 maintenance_manager.cc:419] P ec1f864124be4b048a3aca4402da4160: Scheduling FlushDeltaMemStoresOp(e3fe7a3d8a6d4ee7ad19b69fd53aff70): perf score=14.095187
I20260812 06:19:31.296988 24934 maintenance_manager.cc:643] P ec1f864124be4b048a3aca4402da4160: FlushDeltaMemStoresOp(e3fe7a3d8a6d4ee7ad19b69fd53aff70) complete. Timing: real 0.058s	user 0.033s	sys 0.023s Metrics: {"bytes_written":16409904,"delete_count":0,"lbm_write_time_us":26701,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:31.297549 25043 maintenance_manager.cc:419] P ec1f864124be4b048a3aca4402da4160: Scheduling FlushDeltaMemStoresOp(e3fe7a3d8a6d4ee7ad19b69fd53aff70): perf score=2.188937
I20260812 06:19:31.309644 24934 maintenance_manager.cc:643] P ec1f864124be4b048a3aca4402da4160: FlushDeltaMemStoresOp(e3fe7a3d8a6d4ee7ad19b69fd53aff70) complete. Timing: real 0.012s	user 0.005s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4239,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:31.310148 25043 maintenance_manager.cc:419] P ec1f864124be4b048a3aca4402da4160: Scheduling MajorDeltaCompactionOp(e3fe7a3d8a6d4ee7ad19b69fd53aff70): perf score=1.000000
I20260812 06:19:31.477696 24934 maintenance_manager.cc:643] P ec1f864124be4b048a3aca4402da4160: MajorDeltaCompactionOp(e3fe7a3d8a6d4ee7ad19b69fd53aff70) complete. Timing: real 0.167s	user 0.138s	sys 0.027s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774691,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":407,"lbm_read_time_us":11706,"lbm_reads_lt_1ms":572,"lbm_write_time_us":32103,"lbm_writes_lt_1ms":543,"mutex_wait_us":30,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":22272,"update_count":2500}
I20260812 06:19:31.478451 25043 maintenance_manager.cc:419] P ec1f864124be4b048a3aca4402da4160: Scheduling FlushDeltaMemStoresOp(e3fe7a3d8a6d4ee7ad19b69fd53aff70): perf score=12.110812
I20260812 06:19:31.525701 24934 maintenance_manager.cc:643] P ec1f864124be4b048a3aca4402da4160: FlushDeltaMemStoresOp(e3fe7a3d8a6d4ee7ad19b69fd53aff70) complete. Timing: real 0.047s	user 0.033s	sys 0.012s Metrics: {"bytes_written":13866409,"delete_count":0,"lbm_write_time_us":21011,"lbm_writes_lt_1ms":341,"reinsert_count":0,"update_count":1690}
I20260812 06:19:31.526217 25043 maintenance_manager.cc:419] P ec1f864124be4b048a3aca4402da4160: Scheduling FlushDeltaMemStoresOp(e3fe7a3d8a6d4ee7ad19b69fd53aff70): perf score=1.196750
I20260812 06:19:31.541497 24934 maintenance_manager.cc:643] P ec1f864124be4b048a3aca4402da4160: FlushDeltaMemStoresOp(e3fe7a3d8a6d4ee7ad19b69fd53aff70) complete. Timing: real 0.015s	user 0.002s	sys 0.009s Metrics: {"bytes_written":2543704,"delete_count":0,"lbm_write_time_us":3975,"lbm_writes_lt_1ms":65,"reinsert_count":0,"update_count":310}
I20260812 06:19:31.542106 25043 maintenance_manager.cc:419] P ec1f864124be4b048a3aca4402da4160: Scheduling MajorDeltaCompactionOp(e3fe7a3d8a6d4ee7ad19b69fd53aff70): perf score=1.000000
I20260812 06:19:31.722236 24934 maintenance_manager.cc:643] P ec1f864124be4b048a3aca4402da4160: MajorDeltaCompactionOp(e3fe7a3d8a6d4ee7ad19b69fd53aff70) complete. Timing: real 0.180s	user 0.105s	sys 0.063s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672241,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":260,"lbm_read_time_us":11899,"lbm_reads_lt_1ms":464,"lbm_write_time_us":28669,"lbm_writes_lt_1ms":443,"mutex_wait_us":62,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":46336,"update_count":2000}
I20260812 06:19:31.723075 25043 maintenance_manager.cc:419] P ec1f864124be4b048a3aca4402da4160: Scheduling FlushDeltaMemStoresOp(e3fe7a3d8a6d4ee7ad19b69fd53aff70): perf score=14.095187
I20260812 06:19:31.775069 24934 maintenance_manager.cc:643] P ec1f864124be4b048a3aca4402da4160: FlushDeltaMemStoresOp(e3fe7a3d8a6d4ee7ad19b69fd53aff70) complete. Timing: real 0.052s	user 0.032s	sys 0.016s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":23314,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:31.775710 25043 maintenance_manager.cc:419] P ec1f864124be4b048a3aca4402da4160: Scheduling FlushDeltaMemStoresOp(e3fe7a3d8a6d4ee7ad19b69fd53aff70): perf score=2.188937
I20260812 06:19:31.800246 24934 maintenance_manager.cc:643] P ec1f864124be4b048a3aca4402da4160: FlushDeltaMemStoresOp(e3fe7a3d8a6d4ee7ad19b69fd53aff70) complete. Timing: real 0.024s	user 0.006s	sys 0.017s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5134,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:31.801023 25043 maintenance_manager.cc:419] P ec1f864124be4b048a3aca4402da4160: Scheduling MajorDeltaCompactionOp(e3fe7a3d8a6d4ee7ad19b69fd53aff70): perf score=1.000000
I20260812 06:19:32.004487 24934 maintenance_manager.cc:643] P ec1f864124be4b048a3aca4402da4160: MajorDeltaCompactionOp(e3fe7a3d8a6d4ee7ad19b69fd53aff70) complete. Timing: real 0.203s	user 0.120s	sys 0.078s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774689,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":219,"lbm_read_time_us":14892,"lbm_reads_lt_1ms":564,"lbm_write_time_us":34369,"lbm_writes_lt_1ms":543,"mutex_wait_us":37,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":35072,"update_count":2500}
I20260812 06:19:32.005275 25043 maintenance_manager.cc:419] P ec1f864124be4b048a3aca4402da4160: Scheduling FlushDeltaMemStoresOp(e3fe7a3d8a6d4ee7ad19b69fd53aff70): perf score=14.095187
I20260812 06:19:32.060323 24934 maintenance_manager.cc:643] P ec1f864124be4b048a3aca4402da4160: FlushDeltaMemStoresOp(e3fe7a3d8a6d4ee7ad19b69fd53aff70) complete. Timing: real 0.055s	user 0.036s	sys 0.012s Metrics: {"bytes_written":16409903,"delete_count":0,"lbm_write_time_us":22131,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:32.060837 25043 maintenance_manager.cc:419] P ec1f864124be4b048a3aca4402da4160: Scheduling FlushDeltaMemStoresOp(e3fe7a3d8a6d4ee7ad19b69fd53aff70): perf score=2.188937
I20260812 06:19:32.073434 24934 maintenance_manager.cc:643] P ec1f864124be4b048a3aca4402da4160: FlushDeltaMemStoresOp(e3fe7a3d8a6d4ee7ad19b69fd53aff70) complete. Timing: real 0.012s	user 0.002s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4402,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:32.074198 25043 maintenance_manager.cc:419] P ec1f864124be4b048a3aca4402da4160: Scheduling MajorDeltaCompactionOp(e3fe7a3d8a6d4ee7ad19b69fd53aff70): perf score=1.000000
I20260812 06:19:32.264643 24934 maintenance_manager.cc:643] P ec1f864124be4b048a3aca4402da4160: MajorDeltaCompactionOp(e3fe7a3d8a6d4ee7ad19b69fd53aff70) complete. Timing: real 0.190s	user 0.124s	sys 0.048s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774690,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":405,"lbm_read_time_us":12600,"lbm_reads_lt_1ms":572,"lbm_write_time_us":29610,"lbm_writes_lt_1ms":543,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":27392,"update_count":2500}
I20260812 06:19:32.265307 25043 maintenance_manager.cc:419] P ec1f864124be4b048a3aca4402da4160: Scheduling FlushDeltaMemStoresOp(e3fe7a3d8a6d4ee7ad19b69fd53aff70): perf score=14.095187
I20260812 06:19:32.322729 24934 maintenance_manager.cc:643] P ec1f864124be4b048a3aca4402da4160: FlushDeltaMemStoresOp(e3fe7a3d8a6d4ee7ad19b69fd53aff70) complete. Timing: real 0.057s	user 0.025s	sys 0.024s Metrics: {"bytes_written":16409903,"delete_count":0,"lbm_write_time_us":23678,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:32.323232 25043 maintenance_manager.cc:419] P ec1f864124be4b048a3aca4402da4160: Scheduling FlushDeltaMemStoresOp(e3fe7a3d8a6d4ee7ad19b69fd53aff70): perf score=2.188937
I20260812 06:19:32.335321 24934 maintenance_manager.cc:643] P ec1f864124be4b048a3aca4402da4160: FlushDeltaMemStoresOp(e3fe7a3d8a6d4ee7ad19b69fd53aff70) complete. Timing: real 0.012s	user 0.006s	sys 0.003s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4414,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:32.335924 25043 maintenance_manager.cc:419] P ec1f864124be4b048a3aca4402da4160: Scheduling FlushMRSOp(e3fe7a3d8a6d4ee7ad19b69fd53aff70): perf score=1.000000
I20260812 06:19:32.365718 24934 maintenance_manager.cc:643] P ec1f864124be4b048a3aca4402da4160: FlushMRSOp(e3fe7a3d8a6d4ee7ad19b69fd53aff70) complete. Timing: real 0.030s	user 0.027s	sys 0.001s Metrics: {"bytes_written":1152508,"cfile_init":1,"dirs.queue_time_us":72,"dirs.run_cpu_time_us":275,"dirs.run_wall_time_us":1677,"drs_written":1,"lbm_read_time_us":37,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1632,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":28}
I20260812 06:19:32.366379 25043 maintenance_manager.cc:419] P ec1f864124be4b048a3aca4402da4160: Scheduling LogGCOp(e3fe7a3d8a6d4ee7ad19b69fd53aff70): free 115943232 bytes of WAL
I20260812 06:19:32.366613 24934 log_reader.cc:385] T e3fe7a3d8a6d4ee7ad19b69fd53aff70: removed 11 log segments from log reader
I20260812 06:19:32.366676 24934 log.cc:1079] T e3fe7a3d8a6d4ee7ad19b69fd53aff70 P ec1f864124be4b048a3aca4402da4160: Deleting log segment in path: /tmp/dist-test-taskseRmjK/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515564944993-24506-0/minicluster-data/ts-0-root/wals/e3fe7a3d8a6d4ee7ad19b69fd53aff70/wal-000000003 (ops 12-16)
I20260812 06:19:32.366729 24934 log.cc:1079] T e3fe7a3d8a6d4ee7ad19b69fd53aff70 P ec1f864124be4b048a3aca4402da4160: Deleting log segment in path: /tmp/dist-test-taskseRmjK/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515564944993-24506-0/minicluster-data/ts-0-root/wals/e3fe7a3d8a6d4ee7ad19b69fd53aff70/wal-000000004 (ops 17-21)
I20260812 06:19:32.366786 24934 log.cc:1079] T e3fe7a3d8a6d4ee7ad19b69fd53aff70 P ec1f864124be4b048a3aca4402da4160: Deleting log segment in path: /tmp/dist-test-taskseRmjK/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515564944993-24506-0/minicluster-data/ts-0-root/wals/e3fe7a3d8a6d4ee7ad19b69fd53aff70/wal-000000005 (ops 22-26)
I20260812 06:19:32.366829 24934 log.cc:1079] T e3fe7a3d8a6d4ee7ad19b69fd53aff70 P ec1f864124be4b048a3aca4402da4160: Deleting log segment in path: /tmp/dist-test-taskseRmjK/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515564944993-24506-0/minicluster-data/ts-0-root/wals/e3fe7a3d8a6d4ee7ad19b69fd53aff70/wal-000000006 (ops 27-31)
I20260812 06:19:32.366871 24934 log.cc:1079] T e3fe7a3d8a6d4ee7ad19b69fd53aff70 P ec1f864124be4b048a3aca4402da4160: Deleting log segment in path: /tmp/dist-test-taskseRmjK/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515564944993-24506-0/minicluster-data/ts-0-root/wals/e3fe7a3d8a6d4ee7ad19b69fd53aff70/wal-000000007 (ops 32-36)
I20260812 06:19:32.366911 24934 log.cc:1079] T e3fe7a3d8a6d4ee7ad19b69fd53aff70 P ec1f864124be4b048a3aca4402da4160: Deleting log segment in path: /tmp/dist-test-taskseRmjK/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515564944993-24506-0/minicluster-data/ts-0-root/wals/e3fe7a3d8a6d4ee7ad19b69fd53aff70/wal-000000008 (ops 37-41)
I20260812 06:19:32.366958 24934 log.cc:1079] T e3fe7a3d8a6d4ee7ad19b69fd53aff70 P ec1f864124be4b048a3aca4402da4160: Deleting log segment in path: /tmp/dist-test-taskseRmjK/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515564944993-24506-0/minicluster-data/ts-0-root/wals/e3fe7a3d8a6d4ee7ad19b69fd53aff70/wal-000000009 (ops 42-46)
I20260812 06:19:32.366999 24934 log.cc:1079] T e3fe7a3d8a6d4ee7ad19b69fd53aff70 P ec1f864124be4b048a3aca4402da4160: Deleting log segment in path: /tmp/dist-test-taskseRmjK/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515564944993-24506-0/minicluster-data/ts-0-root/wals/e3fe7a3d8a6d4ee7ad19b69fd53aff70/wal-000000010 (ops 47-51)
I20260812 06:19:32.367038 24934 log.cc:1079] T e3fe7a3d8a6d4ee7ad19b69fd53aff70 P ec1f864124be4b048a3aca4402da4160: Deleting log segment in path: /tmp/dist-test-taskseRmjK/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515564944993-24506-0/minicluster-data/ts-0-root/wals/e3fe7a3d8a6d4ee7ad19b69fd53aff70/wal-000000011 (ops 52-56)
I20260812 06:19:32.367077 24934 log.cc:1079] T e3fe7a3d8a6d4ee7ad19b69fd53aff70 P ec1f864124be4b048a3aca4402da4160: Deleting log segment in path: /tmp/dist-test-taskseRmjK/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515564944993-24506-0/minicluster-data/ts-0-root/wals/e3fe7a3d8a6d4ee7ad19b69fd53aff70/wal-000000012 (ops 57-61)
I20260812 06:19:32.367116 24934 log.cc:1079] T e3fe7a3d8a6d4ee7ad19b69fd53aff70 P ec1f864124be4b048a3aca4402da4160: Deleting log segment in path: /tmp/dist-test-taskseRmjK/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515564944993-24506-0/minicluster-data/ts-0-root/wals/e3fe7a3d8a6d4ee7ad19b69fd53aff70/wal-000000013 (ops 62-66)
I20260812 06:19:32.395376 24934 maintenance_manager.cc:643] P ec1f864124be4b048a3aca4402da4160: LogGCOp(e3fe7a3d8a6d4ee7ad19b69fd53aff70) complete. Timing: real 0.029s	user 0.000s	sys 0.025s Metrics: {}
I20260812 06:19:32.395812 25043 maintenance_manager.cc:419] P ec1f864124be4b048a3aca4402da4160: Scheduling FlushDeltaMemStoresOp(e3fe7a3d8a6d4ee7ad19b69fd53aff70): perf score=5.165500
I20260812 06:19:32.418258 24934 maintenance_manager.cc:643] P ec1f864124be4b048a3aca4402da4160: FlushDeltaMemStoresOp(e3fe7a3d8a6d4ee7ad19b69fd53aff70) complete. Timing: real 0.022s	user 0.006s	sys 0.013s Metrics: {"bytes_written":6687182,"delete_count":0,"lbm_write_time_us":9205,"lbm_writes_lt_1ms":166,"reinsert_count":0,"update_count":815}
I20260812 06:19:32.418849 25043 maintenance_manager.cc:419] P ec1f864124be4b048a3aca4402da4160: Scheduling UndoDeltaBlockGCOp(e3fe7a3d8a6d4ee7ad19b69fd53aff70): 448 bytes on disk
I20260812 06:19:32.419368 24934 maintenance_manager.cc:643] P ec1f864124be4b048a3aca4402da4160: UndoDeltaBlockGCOp(e3fe7a3d8a6d4ee7ad19b69fd53aff70) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":73,"lbm_reads_lt_1ms":4}
I20260812 06:19:32.419888 25043 maintenance_manager.cc:419] P ec1f864124be4b048a3aca4402da4160: Scheduling FlushDeltaMemStoresOp(e3fe7a3d8a6d4ee7ad19b69fd53aff70): perf score=1.000000
I20260812 06:19:32.429215 24934 maintenance_manager.cc:643] P ec1f864124be4b048a3aca4402da4160: FlushDeltaMemStoresOp(e3fe7a3d8a6d4ee7ad19b69fd53aff70) complete. Timing: real 0.009s	user 0.005s	sys 0.003s Metrics: {"bytes_written":1518077,"delete_count":0,"lbm_write_time_us":2684,"lbm_writes_lt_1ms":40,"reinsert_count":0,"update_count":185}
I20260812 06:19:32.429845 25043 maintenance_manager.cc:419] P ec1f864124be4b048a3aca4402da4160: Scheduling MajorDeltaCompactionOp(e3fe7a3d8a6d4ee7ad19b69fd53aff70): perf score=1.000000
I20260812 06:19:32.663089 24934 maintenance_manager.cc:643] P ec1f864124be4b048a3aca4402da4160: MajorDeltaCompactionOp(e3fe7a3d8a6d4ee7ad19b69fd53aff70) complete. Timing: real 0.233s	user 0.151s	sys 0.079s Metrics: {"cfile_cache_miss":734,"cfile_cache_miss_bytes":32979688,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":3777,"lbm_read_time_us":17562,"lbm_reads_lt_1ms":774,"lbm_write_time_us":42452,"lbm_writes_lt_1ms":743,"mutex_wait_us":2330,"peak_mem_usage":87969044,"reinsert_count":0,"spinlock_wait_cycles":19584,"thread_start_us":109,"threads_started":1,"update_count":3500}
I20260812 06:19:32.663967 25043 maintenance_manager.cc:419] P ec1f864124be4b048a3aca4402da4160: Scheduling FlushDeltaMemStoresOp(e3fe7a3d8a6d4ee7ad19b69fd53aff70): perf score=14.095187
I20260812 06:19:32.722584 24934 maintenance_manager.cc:643] P ec1f864124be4b048a3aca4402da4160: FlushDeltaMemStoresOp(e3fe7a3d8a6d4ee7ad19b69fd53aff70) complete. Timing: real 0.058s	user 0.044s	sys 0.011s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":25879,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:32.723290 25043 maintenance_manager.cc:419] P ec1f864124be4b048a3aca4402da4160: Scheduling FlushDeltaMemStoresOp(e3fe7a3d8a6d4ee7ad19b69fd53aff70): perf score=2.188937
I20260812 06:19:32.738688 24934 maintenance_manager.cc:643] P ec1f864124be4b048a3aca4402da4160: FlushDeltaMemStoresOp(e3fe7a3d8a6d4ee7ad19b69fd53aff70) complete. Timing: real 0.015s	user 0.010s	sys 0.003s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5811,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:32.739246 25043 maintenance_manager.cc:419] P ec1f864124be4b048a3aca4402da4160: Scheduling MajorDeltaCompactionOp(e3fe7a3d8a6d4ee7ad19b69fd53aff70): perf score=1.000000
I20260812 06:19:32.938292 24934 maintenance_manager.cc:643] P ec1f864124be4b048a3aca4402da4160: MajorDeltaCompactionOp(e3fe7a3d8a6d4ee7ad19b69fd53aff70) complete. Timing: real 0.199s	user 0.131s	sys 0.068s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774688,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":728,"lbm_read_time_us":16266,"lbm_reads_lt_1ms":572,"lbm_write_time_us":33376,"lbm_writes_lt_1ms":543,"mutex_wait_us":144,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":11520,"update_count":2500}
I20260812 06:19:32.938975 25043 maintenance_manager.cc:419] P ec1f864124be4b048a3aca4402da4160: Scheduling FlushDeltaMemStoresOp(e3fe7a3d8a6d4ee7ad19b69fd53aff70): perf score=14.095187
I20260812 06:19:33.000743 24934 maintenance_manager.cc:643] P ec1f864124be4b048a3aca4402da4160: FlushDeltaMemStoresOp(e3fe7a3d8a6d4ee7ad19b69fd53aff70) complete. Timing: real 0.062s	user 0.034s	sys 0.027s Metrics: {"bytes_written":16409898,"delete_count":0,"lbm_write_time_us":21489,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:33.001444 25043 maintenance_manager.cc:419] P ec1f864124be4b048a3aca4402da4160: Scheduling FlushDeltaMemStoresOp(e3fe7a3d8a6d4ee7ad19b69fd53aff70): perf score=2.188937
I20260812 06:19:33.018098 24934 maintenance_manager.cc:643] P ec1f864124be4b048a3aca4402da4160: FlushDeltaMemStoresOp(e3fe7a3d8a6d4ee7ad19b69fd53aff70) complete. Timing: real 0.016s	user 0.011s	sys 0.003s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6274,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:33.018759 25043 maintenance_manager.cc:419] P ec1f864124be4b048a3aca4402da4160: Scheduling MajorDeltaCompactionOp(e3fe7a3d8a6d4ee7ad19b69fd53aff70): perf score=1.000000
I20260812 06:19:33.212842 24934 maintenance_manager.cc:643] P ec1f864124be4b048a3aca4402da4160: MajorDeltaCompactionOp(e3fe7a3d8a6d4ee7ad19b69fd53aff70) complete. Timing: real 0.194s	user 0.125s	sys 0.063s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774685,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":295,"lbm_read_time_us":13736,"lbm_reads_lt_1ms":572,"lbm_write_time_us":33376,"lbm_writes_lt_1ms":543,"mutex_wait_us":32,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":13568,"update_count":2500}
I20260812 06:19:33.213510 25043 maintenance_manager.cc:419] P ec1f864124be4b048a3aca4402da4160: Scheduling FlushDeltaMemStoresOp(e3fe7a3d8a6d4ee7ad19b69fd53aff70): perf score=14.095187
I20260812 06:19:33.274109 24934 maintenance_manager.cc:643] P ec1f864124be4b048a3aca4402da4160: FlushDeltaMemStoresOp(e3fe7a3d8a6d4ee7ad19b69fd53aff70) complete. Timing: real 0.060s	user 0.040s	sys 0.016s Metrics: {"bytes_written":16409903,"delete_count":0,"lbm_write_time_us":23203,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:33.274747 25043 maintenance_manager.cc:419] P ec1f864124be4b048a3aca4402da4160: Scheduling FlushDeltaMemStoresOp(e3fe7a3d8a6d4ee7ad19b69fd53aff70): perf score=2.188937
I20260812 06:19:33.287859 24934 maintenance_manager.cc:643] P ec1f864124be4b048a3aca4402da4160: FlushDeltaMemStoresOp(e3fe7a3d8a6d4ee7ad19b69fd53aff70) complete. Timing: real 0.013s	user 0.009s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5116,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:33.288522 25043 maintenance_manager.cc:419] P ec1f864124be4b048a3aca4402da4160: Scheduling MajorDeltaCompactionOp(e3fe7a3d8a6d4ee7ad19b69fd53aff70): perf score=1.000000
I20260812 06:19:33.488296 24934 maintenance_manager.cc:643] P ec1f864124be4b048a3aca4402da4160: MajorDeltaCompactionOp(e3fe7a3d8a6d4ee7ad19b69fd53aff70) complete. Timing: real 0.199s	user 0.117s	sys 0.068s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774690,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":266,"lbm_read_time_us":14393,"lbm_reads_lt_1ms":572,"lbm_write_time_us":31418,"lbm_writes_lt_1ms":543,"mutex_wait_us":29,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":45312,"update_count":2500}
I20260812 06:19:33.489136 25043 maintenance_manager.cc:419] P ec1f864124be4b048a3aca4402da4160: Scheduling FlushDeltaMemStoresOp(e3fe7a3d8a6d4ee7ad19b69fd53aff70): perf score=14.095187
I20260812 06:19:33.539304 24934 maintenance_manager.cc:643] P ec1f864124be4b048a3aca4402da4160: FlushDeltaMemStoresOp(e3fe7a3d8a6d4ee7ad19b69fd53aff70) complete. Timing: real 0.050s	user 0.021s	sys 0.025s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":22029,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:33.539883 25043 maintenance_manager.cc:419] P ec1f864124be4b048a3aca4402da4160: Scheduling FlushDeltaMemStoresOp(e3fe7a3d8a6d4ee7ad19b69fd53aff70): perf score=2.188937
I20260812 06:19:33.565690 24934 maintenance_manager.cc:643] P ec1f864124be4b048a3aca4402da4160: FlushDeltaMemStoresOp(e3fe7a3d8a6d4ee7ad19b69fd53aff70) complete. Timing: real 0.026s	user 0.012s	sys 0.012s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4920,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:33.566237 25043 maintenance_manager.cc:419] P ec1f864124be4b048a3aca4402da4160: Scheduling MajorDeltaCompactionOp(e3fe7a3d8a6d4ee7ad19b69fd53aff70): perf score=1.000000
I20260812 06:19:33.757552 24934 maintenance_manager.cc:643] P ec1f864124be4b048a3aca4402da4160: MajorDeltaCompactionOp(e3fe7a3d8a6d4ee7ad19b69fd53aff70) complete. Timing: real 0.191s	user 0.139s	sys 0.048s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774688,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":276,"lbm_read_time_us":14019,"lbm_reads_lt_1ms":564,"lbm_write_time_us":30595,"lbm_writes_lt_1ms":543,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":20480,"update_count":2500}
I20260812 06:19:33.758329 25043 maintenance_manager.cc:419] P ec1f864124be4b048a3aca4402da4160: Scheduling FlushDeltaMemStoresOp(e3fe7a3d8a6d4ee7ad19b69fd53aff70): perf score=14.095187
I20260812 06:19:33.824080 24934 maintenance_manager.cc:643] P ec1f864124be4b048a3aca4402da4160: FlushDeltaMemStoresOp(e3fe7a3d8a6d4ee7ad19b69fd53aff70) complete. Timing: real 0.066s	user 0.050s	sys 0.007s Metrics: {"bytes_written":16409899,"delete_count":0,"lbm_write_time_us":25711,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:33.824692 25043 maintenance_manager.cc:419] P ec1f864124be4b048a3aca4402da4160: Scheduling FlushDeltaMemStoresOp(e3fe7a3d8a6d4ee7ad19b69fd53aff70): perf score=2.188937
I20260812 06:19:33.836987 24934 maintenance_manager.cc:643] P ec1f864124be4b048a3aca4402da4160: FlushDeltaMemStoresOp(e3fe7a3d8a6d4ee7ad19b69fd53aff70) complete. Timing: real 0.012s	user 0.002s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4277,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:33.837538 25043 maintenance_manager.cc:419] P ec1f864124be4b048a3aca4402da4160: Scheduling MajorDeltaCompactionOp(e3fe7a3d8a6d4ee7ad19b69fd53aff70): perf score=1.000000
I20260812 06:19:33.996364 24934 maintenance_manager.cc:643] P ec1f864124be4b048a3aca4402da4160: MajorDeltaCompactionOp(e3fe7a3d8a6d4ee7ad19b69fd53aff70) complete. Timing: real 0.159s	user 0.111s	sys 0.047s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774686,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":412,"lbm_read_time_us":11589,"lbm_reads_lt_1ms":572,"lbm_write_time_us":31606,"lbm_writes_lt_1ms":543,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":4352,"update_count":2500}
I20260812 06:19:33.997010 25043 maintenance_manager.cc:419] P ec1f864124be4b048a3aca4402da4160: Scheduling FlushDeltaMemStoresOp(e3fe7a3d8a6d4ee7ad19b69fd53aff70): perf score=10.126437
I20260812 06:19:34.038211 24934 maintenance_manager.cc:643] P ec1f864124be4b048a3aca4402da4160: FlushDeltaMemStoresOp(e3fe7a3d8a6d4ee7ad19b69fd53aff70) complete. Timing: real 0.041s	user 0.029s	sys 0.012s Metrics: {"bytes_written":12307489,"delete_count":0,"lbm_write_time_us":17012,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:19:34.038977 25043 maintenance_manager.cc:419] P ec1f864124be4b048a3aca4402da4160: Scheduling FlushDeltaMemStoresOp(e3fe7a3d8a6d4ee7ad19b69fd53aff70): perf score=2.188937
I20260812 06:19:34.066504 24934 maintenance_manager.cc:643] P ec1f864124be4b048a3aca4402da4160: FlushDeltaMemStoresOp(e3fe7a3d8a6d4ee7ad19b69fd53aff70) complete. Timing: real 0.027s	user 0.008s	sys 0.004s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":5167,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:34.067032 25043 maintenance_manager.cc:419] P ec1f864124be4b048a3aca4402da4160: Scheduling FlushDeltaMemStoresOp(e3fe7a3d8a6d4ee7ad19b69fd53aff70): perf score=2.188937
I20260812 06:19:34.077965 24934 maintenance_manager.cc:643] P ec1f864124be4b048a3aca4402da4160: FlushDeltaMemStoresOp(e3fe7a3d8a6d4ee7ad19b69fd53aff70) complete. Timing: real 0.011s	user 0.006s	sys 0.003s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3989,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:34.078500 25043 maintenance_manager.cc:419] P ec1f864124be4b048a3aca4402da4160: Scheduling FlushMRSOp(e3fe7a3d8a6d4ee7ad19b69fd53aff70): perf score=1.000000
I20260812 06:19:34.121606 24934 maintenance_manager.cc:643] P ec1f864124be4b048a3aca4402da4160: FlushMRSOp(e3fe7a3d8a6d4ee7ad19b69fd53aff70) complete. Timing: real 0.043s	user 0.038s	sys 0.003s Metrics: {"bytes_written":1316419,"cfile_init":1,"dirs.queue_time_us":78,"dirs.run_cpu_time_us":276,"dirs.run_wall_time_us":1961,"drs_written":1,"lbm_read_time_us":45,"lbm_reads_lt_1ms":4,"lbm_write_time_us":2121,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":32}
I20260812 06:19:34.122445 25043 maintenance_manager.cc:419] P ec1f864124be4b048a3aca4402da4160: Scheduling LogGCOp(e3fe7a3d8a6d4ee7ad19b69fd53aff70): free 129320458 bytes of WAL
I20260812 06:19:34.122774 24934 log_reader.cc:385] T e3fe7a3d8a6d4ee7ad19b69fd53aff70: removed 13 log segments from log reader
I20260812 06:19:34.122825 24934 log.cc:1079] T e3fe7a3d8a6d4ee7ad19b69fd53aff70 P ec1f864124be4b048a3aca4402da4160: Deleting log segment in path: /tmp/dist-test-taskseRmjK/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515564944993-24506-0/minicluster-data/ts-0-root/wals/e3fe7a3d8a6d4ee7ad19b69fd53aff70/wal-000000014 (ops 67-71)
I20260812 06:19:34.122861 24934 log.cc:1079] T e3fe7a3d8a6d4ee7ad19b69fd53aff70 P ec1f864124be4b048a3aca4402da4160: Deleting log segment in path: /tmp/dist-test-taskseRmjK/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515564944993-24506-0/minicluster-data/ts-0-root/wals/e3fe7a3d8a6d4ee7ad19b69fd53aff70/wal-000000015 (ops 72-76)
I20260812 06:19:34.122924 24934 log.cc:1079] T e3fe7a3d8a6d4ee7ad19b69fd53aff70 P ec1f864124be4b048a3aca4402da4160: Deleting log segment in path: /tmp/dist-test-taskseRmjK/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515564944993-24506-0/minicluster-data/ts-0-root/wals/e3fe7a3d8a6d4ee7ad19b69fd53aff70/wal-000000016 (ops 77-80)
I20260812 06:19:34.122974 24934 log.cc:1079] T e3fe7a3d8a6d4ee7ad19b69fd53aff70 P ec1f864124be4b048a3aca4402da4160: Deleting log segment in path: /tmp/dist-test-taskseRmjK/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515564944993-24506-0/minicluster-data/ts-0-root/wals/e3fe7a3d8a6d4ee7ad19b69fd53aff70/wal-000000017 (ops 81-85)
I20260812 06:19:34.123047 24934 log.cc:1079] T e3fe7a3d8a6d4ee7ad19b69fd53aff70 P ec1f864124be4b048a3aca4402da4160: Deleting log segment in path: /tmp/dist-test-taskseRmjK/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515564944993-24506-0/minicluster-data/ts-0-root/wals/e3fe7a3d8a6d4ee7ad19b69fd53aff70/wal-000000018 (ops 86-90)
I20260812 06:19:34.123095 24934 log.cc:1079] T e3fe7a3d8a6d4ee7ad19b69fd53aff70 P ec1f864124be4b048a3aca4402da4160: Deleting log segment in path: /tmp/dist-test-taskseRmjK/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515564944993-24506-0/minicluster-data/ts-0-root/wals/e3fe7a3d8a6d4ee7ad19b69fd53aff70/wal-000000019 (ops 91-95)
I20260812 06:19:34.123139 24934 log.cc:1079] T e3fe7a3d8a6d4ee7ad19b69fd53aff70 P ec1f864124be4b048a3aca4402da4160: Deleting log segment in path: /tmp/dist-test-taskseRmjK/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515564944993-24506-0/minicluster-data/ts-0-root/wals/e3fe7a3d8a6d4ee7ad19b69fd53aff70/wal-000000020 (ops 96-100)
I20260812 06:19:34.123183 24934 log.cc:1079] T e3fe7a3d8a6d4ee7ad19b69fd53aff70 P ec1f864124be4b048a3aca4402da4160: Deleting log segment in path: /tmp/dist-test-taskseRmjK/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515564944993-24506-0/minicluster-data/ts-0-root/wals/e3fe7a3d8a6d4ee7ad19b69fd53aff70/wal-000000021 (ops 101-104)
I20260812 06:19:34.123229 24934 log.cc:1079] T e3fe7a3d8a6d4ee7ad19b69fd53aff70 P ec1f864124be4b048a3aca4402da4160: Deleting log segment in path: /tmp/dist-test-taskseRmjK/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515564944993-24506-0/minicluster-data/ts-0-root/wals/e3fe7a3d8a6d4ee7ad19b69fd53aff70/wal-000000022 (ops 105-109)
I20260812 06:19:34.123273 24934 log.cc:1079] T e3fe7a3d8a6d4ee7ad19b69fd53aff70 P ec1f864124be4b048a3aca4402da4160: Deleting log segment in path: /tmp/dist-test-taskseRmjK/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515564944993-24506-0/minicluster-data/ts-0-root/wals/e3fe7a3d8a6d4ee7ad19b69fd53aff70/wal-000000023 (ops 110-114)
I20260812 06:19:34.123303 24934 log.cc:1079] T e3fe7a3d8a6d4ee7ad19b69fd53aff70 P ec1f864124be4b048a3aca4402da4160: Deleting log segment in path: /tmp/dist-test-taskseRmjK/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515564944993-24506-0/minicluster-data/ts-0-root/wals/e3fe7a3d8a6d4ee7ad19b69fd53aff70/wal-000000024 (ops 115-119)
I20260812 06:19:34.123347 24934 log.cc:1079] T e3fe7a3d8a6d4ee7ad19b69fd53aff70 P ec1f864124be4b048a3aca4402da4160: Deleting log segment in path: /tmp/dist-test-taskseRmjK/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515564944993-24506-0/minicluster-data/ts-0-root/wals/e3fe7a3d8a6d4ee7ad19b69fd53aff70/wal-000000025 (ops 120-124)
I20260812 06:19:34.123394 24934 log.cc:1079] T e3fe7a3d8a6d4ee7ad19b69fd53aff70 P ec1f864124be4b048a3aca4402da4160: Deleting log segment in path: /tmp/dist-test-taskseRmjK/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515564944993-24506-0/minicluster-data/ts-0-root/wals/e3fe7a3d8a6d4ee7ad19b69fd53aff70/wal-000000026 (ops 125-129)
I20260812 06:19:34.158248 24934 maintenance_manager.cc:643] P ec1f864124be4b048a3aca4402da4160: LogGCOp(e3fe7a3d8a6d4ee7ad19b69fd53aff70) complete. Timing: real 0.036s	user 0.000s	sys 0.033s Metrics: {}
I20260812 06:19:34.158730 25043 maintenance_manager.cc:419] P ec1f864124be4b048a3aca4402da4160: Scheduling UndoDeltaBlockGCOp(e3fe7a3d8a6d4ee7ad19b69fd53aff70): 492 bytes on disk
I20260812 06:19:34.159231 24934 maintenance_manager.cc:643] P ec1f864124be4b048a3aca4402da4160: UndoDeltaBlockGCOp(e3fe7a3d8a6d4ee7ad19b69fd53aff70) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":64,"lbm_reads_lt_1ms":4}
I20260812 06:19:34.159905 25043 maintenance_manager.cc:419] P ec1f864124be4b048a3aca4402da4160: Scheduling FlushDeltaMemStoresOp(e3fe7a3d8a6d4ee7ad19b69fd53aff70): perf score=6.157687
I20260812 06:19:34.192011 24934 maintenance_manager.cc:643] P ec1f864124be4b048a3aca4402da4160: FlushDeltaMemStoresOp(e3fe7a3d8a6d4ee7ad19b69fd53aff70) complete. Timing: real 0.032s	user 0.015s	sys 0.016s Metrics: {"bytes_written":8205079,"delete_count":0,"lbm_write_time_us":13729,"lbm_writes_lt_1ms":203,"reinsert_count":0,"update_count":1000}
I20260812 06:19:34.192557 25043 maintenance_manager.cc:419] P ec1f864124be4b048a3aca4402da4160: Scheduling MajorDeltaCompactionOp(e3fe7a3d8a6d4ee7ad19b69fd53aff70): perf score=1.000000
I20260812 06:19:34.451361 24934 maintenance_manager.cc:643] P ec1f864124be4b048a3aca4402da4160: MajorDeltaCompactionOp(e3fe7a3d8a6d4ee7ad19b69fd53aff70) complete. Timing: real 0.259s	user 0.154s	sys 0.104s Metrics: {"cfile_cache_miss":734,"cfile_cache_miss_bytes":32979751,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":986,"lbm_read_time_us":19774,"lbm_reads_lt_1ms":766,"lbm_write_time_us":41781,"lbm_writes_lt_1ms":743,"mutex_wait_us":374,"peak_mem_usage":87969044,"reinsert_count":0,"spinlock_wait_cycles":12800,"thread_start_us":85,"threads_started":1,"update_count":3500}
I20260812 06:19:34.452258 25043 maintenance_manager.cc:419] P ec1f864124be4b048a3aca4402da4160: Scheduling FlushDeltaMemStoresOp(e3fe7a3d8a6d4ee7ad19b69fd53aff70): perf score=18.063937
I20260812 06:19:34.511408 24934 maintenance_manager.cc:643] P ec1f864124be4b048a3aca4402da4160: FlushDeltaMemStoresOp(e3fe7a3d8a6d4ee7ad19b69fd53aff70) complete. Timing: real 0.056s	user 0.034s	sys 0.018s Metrics: {"bytes_written":20512319,"delete_count":0,"lbm_write_time_us":24551,"lbm_writes_lt_1ms":503,"reinsert_count":0,"update_count":2500}
I20260812 06:19:34.512099 25043 maintenance_manager.cc:419] P ec1f864124be4b048a3aca4402da4160: Scheduling FlushDeltaMemStoresOp(e3fe7a3d8a6d4ee7ad19b69fd53aff70): perf score=3.181125
I20260812 06:19:34.525974 24934 maintenance_manager.cc:643] P ec1f864124be4b048a3aca4402da4160: FlushDeltaMemStoresOp(e3fe7a3d8a6d4ee7ad19b69fd53aff70) complete. Timing: real 0.014s	user 0.007s	sys 0.005s Metrics: {"bytes_written":4512900,"delete_count":0,"lbm_write_time_us":5325,"lbm_writes_lt_1ms":113,"reinsert_count":0,"update_count":550}
I20260812 06:19:34.526443 25043 maintenance_manager.cc:419] P ec1f864124be4b048a3aca4402da4160: Scheduling MajorDeltaCompactionOp(e3fe7a3d8a6d4ee7ad19b69fd53aff70): perf score=1.000000
I20260812 06:19:34.735040 24934 maintenance_manager.cc:643] P ec1f864124be4b048a3aca4402da4160: MajorDeltaCompactionOp(e3fe7a3d8a6d4ee7ad19b69fd53aff70) complete. Timing: real 0.208s	user 0.142s	sys 0.065s Metrics: {"cfile_cache_miss":642,"cfile_cache_miss_bytes":29287347,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":346,"lbm_read_time_us":13593,"lbm_reads_lt_1ms":674,"lbm_write_time_us":35804,"lbm_writes_lt_1ms":653,"mutex_wait_us":4,"peak_mem_usage":75952822,"reinsert_count":0,"spinlock_wait_cycles":4224,"update_count":3050}
I20260812 06:19:34.735749 25043 maintenance_manager.cc:419] P ec1f864124be4b048a3aca4402da4160: Scheduling FlushDeltaMemStoresOp(e3fe7a3d8a6d4ee7ad19b69fd53aff70): perf score=14.095187
I20260812 06:19:34.784946 24934 maintenance_manager.cc:643] P ec1f864124be4b048a3aca4402da4160: FlushDeltaMemStoresOp(e3fe7a3d8a6d4ee7ad19b69fd53aff70) complete. Timing: real 0.049s	user 0.027s	sys 0.020s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":22441,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:34.785902 25043 maintenance_manager.cc:419] P ec1f864124be4b048a3aca4402da4160: Scheduling FlushDeltaMemStoresOp(e3fe7a3d8a6d4ee7ad19b69fd53aff70): perf score=2.188937
I20260812 06:19:34.800969 24934 maintenance_manager.cc:643] P ec1f864124be4b048a3aca4402da4160: FlushDeltaMemStoresOp(e3fe7a3d8a6d4ee7ad19b69fd53aff70) complete. Timing: real 0.015s	user 0.013s	sys 0.000s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":5846,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:19:34.801463 25043 maintenance_manager.cc:419] P ec1f864124be4b048a3aca4402da4160: Scheduling MajorDeltaCompactionOp(e3fe7a3d8a6d4ee7ad19b69fd53aff70): perf score=1.000000
I20260812 06:19:34.986229 24934 maintenance_manager.cc:643] P ec1f864124be4b048a3aca4402da4160: MajorDeltaCompactionOp(e3fe7a3d8a6d4ee7ad19b69fd53aff70) complete. Timing: real 0.185s	user 0.125s	sys 0.059s Metrics: {"cfile_cache_miss":522,"cfile_cache_miss_bytes":24364434,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":228,"lbm_read_time_us":11634,"lbm_reads_lt_1ms":558,"lbm_write_time_us":32552,"lbm_writes_lt_1ms":533,"mutex_wait_us":42,"peak_mem_usage":61665166,"reinsert_count":0,"spinlock_wait_cycles":6528,"update_count":2450}
I20260812 06:19:34.986907 25043 maintenance_manager.cc:419] P ec1f864124be4b048a3aca4402da4160: Scheduling FlushDeltaMemStoresOp(e3fe7a3d8a6d4ee7ad19b69fd53aff70): perf score=14.095187
I20260812 06:19:35.055758 24934 maintenance_manager.cc:643] P ec1f864124be4b048a3aca4402da4160: FlushDeltaMemStoresOp(e3fe7a3d8a6d4ee7ad19b69fd53aff70) complete. Timing: real 0.069s	user 0.030s	sys 0.024s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":19040,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:35.056331 25043 maintenance_manager.cc:419] P ec1f864124be4b048a3aca4402da4160: Scheduling FlushDeltaMemStoresOp(e3fe7a3d8a6d4ee7ad19b69fd53aff70): perf score=2.188937
I20260812 06:19:35.067621 24934 maintenance_manager.cc:643] P ec1f864124be4b048a3aca4402da4160: FlushDeltaMemStoresOp(e3fe7a3d8a6d4ee7ad19b69fd53aff70) complete. Timing: real 0.011s	user 0.007s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4354,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:35.068122 25043 maintenance_manager.cc:419] P ec1f864124be4b048a3aca4402da4160: Scheduling MajorDeltaCompactionOp(e3fe7a3d8a6d4ee7ad19b69fd53aff70): perf score=1.000000
I20260812 06:19:35.256987 24934 maintenance_manager.cc:643] P ec1f864124be4b048a3aca4402da4160: MajorDeltaCompactionOp(e3fe7a3d8a6d4ee7ad19b69fd53aff70) complete. Timing: real 0.189s	user 0.117s	sys 0.066s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774689,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":169,"lbm_read_time_us":13348,"lbm_reads_lt_1ms":572,"lbm_write_time_us":32565,"lbm_writes_lt_1ms":543,"mutex_wait_us":25,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":4352,"update_count":2500}
I20260812 06:19:35.258081 25043 maintenance_manager.cc:419] P ec1f864124be4b048a3aca4402da4160: Scheduling FlushDeltaMemStoresOp(e3fe7a3d8a6d4ee7ad19b69fd53aff70): perf score=11.118625
I20260812 06:19:35.293251 24934 maintenance_manager.cc:643] P ec1f864124be4b048a3aca4402da4160: FlushDeltaMemStoresOp(e3fe7a3d8a6d4ee7ad19b69fd53aff70) complete. Timing: real 0.035s	user 0.021s	sys 0.012s Metrics: {"bytes_written":12717735,"delete_count":0,"lbm_write_time_us":15003,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:19:35.293859 25043 maintenance_manager.cc:419] P ec1f864124be4b048a3aca4402da4160: Scheduling FlushDeltaMemStoresOp(e3fe7a3d8a6d4ee7ad19b69fd53aff70): perf score=2.188937
I20260812 06:19:35.333611 24934 maintenance_manager.cc:643] P ec1f864124be4b048a3aca4402da4160: FlushDeltaMemStoresOp(e3fe7a3d8a6d4ee7ad19b69fd53aff70) complete. Timing: real 0.040s	user 0.004s	sys 0.021s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":5112,"lbm_writes_lt_1ms":93,"mutex_wait_us":1,"reinsert_count":0,"update_count":450}
I20260812 06:19:35.334235 25043 maintenance_manager.cc:419] P ec1f864124be4b048a3aca4402da4160: Scheduling FlushDeltaMemStoresOp(e3fe7a3d8a6d4ee7ad19b69fd53aff70): perf score=2.188937
I20260812 06:19:35.345595 24934 maintenance_manager.cc:643] P ec1f864124be4b048a3aca4402da4160: FlushDeltaMemStoresOp(e3fe7a3d8a6d4ee7ad19b69fd53aff70) complete. Timing: real 0.011s	user 0.006s	sys 0.004s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4402,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:35.346170 25043 maintenance_manager.cc:419] P ec1f864124be4b048a3aca4402da4160: Scheduling MajorDeltaCompactionOp(e3fe7a3d8a6d4ee7ad19b69fd53aff70): perf score=1.000000
I20260812 06:19:35.534305 24934 maintenance_manager.cc:643] P ec1f864124be4b048a3aca4402da4160: MajorDeltaCompactionOp(e3fe7a3d8a6d4ee7ad19b69fd53aff70) complete. Timing: real 0.188s	user 0.131s	sys 0.048s Metrics: {"cfile_cache_miss":533,"cfile_cache_miss_bytes":24774798,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":276,"lbm_read_time_us":13374,"lbm_reads_lt_1ms":573,"lbm_write_time_us":28107,"lbm_writes_lt_1ms":543,"mutex_wait_us":76,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":67456,"update_count":2500}
I20260812 06:19:35.535001 25043 maintenance_manager.cc:419] P ec1f864124be4b048a3aca4402da4160: Scheduling FlushDeltaMemStoresOp(e3fe7a3d8a6d4ee7ad19b69fd53aff70): perf score=14.095187
I20260812 06:19:35.587903 24934 maintenance_manager.cc:643] P ec1f864124be4b048a3aca4402da4160: FlushDeltaMemStoresOp(e3fe7a3d8a6d4ee7ad19b69fd53aff70) complete. Timing: real 0.053s	user 0.038s	sys 0.011s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":21465,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:35.588653 25043 maintenance_manager.cc:419] P ec1f864124be4b048a3aca4402da4160: Scheduling FlushDeltaMemStoresOp(e3fe7a3d8a6d4ee7ad19b69fd53aff70): perf score=2.188937
I20260812 06:19:35.600706 24934 maintenance_manager.cc:643] P ec1f864124be4b048a3aca4402da4160: FlushDeltaMemStoresOp(e3fe7a3d8a6d4ee7ad19b69fd53aff70) complete. Timing: real 0.012s	user 0.009s	sys 0.002s 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:35.601428 25043 maintenance_manager.cc:419] P ec1f864124be4b048a3aca4402da4160: Scheduling FlushMRSOp(e3fe7a3d8a6d4ee7ad19b69fd53aff70): perf score=1.000000
I20260812 06:19:35.649924 24934 maintenance_manager.cc:643] P ec1f864124be4b048a3aca4402da4160: FlushMRSOp(e3fe7a3d8a6d4ee7ad19b69fd53aff70) complete. Timing: real 0.048s	user 0.026s	sys 0.002s Metrics: {"bytes_written":1152510,"cfile_init":1,"dirs.queue_time_us":70,"dirs.run_cpu_time_us":213,"dirs.run_wall_time_us":1561,"drs_written":1,"lbm_read_time_us":43,"lbm_reads_lt_1ms":4,"lbm_write_time_us":2021,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":28}
I20260812 06:19:35.650861 25043 maintenance_manager.cc:419] P ec1f864124be4b048a3aca4402da4160: Scheduling LogGCOp(e3fe7a3d8a6d4ee7ad19b69fd53aff70): free 115943476 bytes of WAL
I20260812 06:19:35.651192 24934 log_reader.cc:385] T e3fe7a3d8a6d4ee7ad19b69fd53aff70: removed 11 log segments from log reader
I20260812 06:19:35.651260 24934 log.cc:1079] T e3fe7a3d8a6d4ee7ad19b69fd53aff70 P ec1f864124be4b048a3aca4402da4160: Deleting log segment in path: /tmp/dist-test-taskseRmjK/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515564944993-24506-0/minicluster-data/ts-0-root/wals/e3fe7a3d8a6d4ee7ad19b69fd53aff70/wal-000000027 (ops 130-134)
I20260812 06:19:35.651299 24934 log.cc:1079] T e3fe7a3d8a6d4ee7ad19b69fd53aff70 P ec1f864124be4b048a3aca4402da4160: Deleting log segment in path: /tmp/dist-test-taskseRmjK/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515564944993-24506-0/minicluster-data/ts-0-root/wals/e3fe7a3d8a6d4ee7ad19b69fd53aff70/wal-000000028 (ops 135-139)
I20260812 06:19:35.651322 24934 log.cc:1079] T e3fe7a3d8a6d4ee7ad19b69fd53aff70 P ec1f864124be4b048a3aca4402da4160: Deleting log segment in path: /tmp/dist-test-taskseRmjK/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515564944993-24506-0/minicluster-data/ts-0-root/wals/e3fe7a3d8a6d4ee7ad19b69fd53aff70/wal-000000029 (ops 140-144)
I20260812 06:19:35.651356 24934 log.cc:1079] T e3fe7a3d8a6d4ee7ad19b69fd53aff70 P ec1f864124be4b048a3aca4402da4160: Deleting log segment in path: /tmp/dist-test-taskseRmjK/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515564944993-24506-0/minicluster-data/ts-0-root/wals/e3fe7a3d8a6d4ee7ad19b69fd53aff70/wal-000000030 (ops 145-149)
I20260812 06:19:35.651391 24934 log.cc:1079] T e3fe7a3d8a6d4ee7ad19b69fd53aff70 P ec1f864124be4b048a3aca4402da4160: Deleting log segment in path: /tmp/dist-test-taskseRmjK/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515564944993-24506-0/minicluster-data/ts-0-root/wals/e3fe7a3d8a6d4ee7ad19b69fd53aff70/wal-000000031 (ops 150-154)
I20260812 06:19:35.651419 24934 log.cc:1079] T e3fe7a3d8a6d4ee7ad19b69fd53aff70 P ec1f864124be4b048a3aca4402da4160: Deleting log segment in path: /tmp/dist-test-taskseRmjK/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515564944993-24506-0/minicluster-data/ts-0-root/wals/e3fe7a3d8a6d4ee7ad19b69fd53aff70/wal-000000032 (ops 155-159)
I20260812 06:19:35.651443 24934 log.cc:1079] T e3fe7a3d8a6d4ee7ad19b69fd53aff70 P ec1f864124be4b048a3aca4402da4160: Deleting log segment in path: /tmp/dist-test-taskseRmjK/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515564944993-24506-0/minicluster-data/ts-0-root/wals/e3fe7a3d8a6d4ee7ad19b69fd53aff70/wal-000000033 (ops 160-164)
I20260812 06:19:35.651472 24934 log.cc:1079] T e3fe7a3d8a6d4ee7ad19b69fd53aff70 P ec1f864124be4b048a3aca4402da4160: Deleting log segment in path: /tmp/dist-test-taskseRmjK/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515564944993-24506-0/minicluster-data/ts-0-root/wals/e3fe7a3d8a6d4ee7ad19b69fd53aff70/wal-000000034 (ops 165-169)
I20260812 06:19:35.651501 24934 log.cc:1079] T e3fe7a3d8a6d4ee7ad19b69fd53aff70 P ec1f864124be4b048a3aca4402da4160: Deleting log segment in path: /tmp/dist-test-taskseRmjK/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515564944993-24506-0/minicluster-data/ts-0-root/wals/e3fe7a3d8a6d4ee7ad19b69fd53aff70/wal-000000035 (ops 170-174)
I20260812 06:19:35.651552 24934 log.cc:1079] T e3fe7a3d8a6d4ee7ad19b69fd53aff70 P ec1f864124be4b048a3aca4402da4160: Deleting log segment in path: /tmp/dist-test-taskseRmjK/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515564944993-24506-0/minicluster-data/ts-0-root/wals/e3fe7a3d8a6d4ee7ad19b69fd53aff70/wal-000000036 (ops 175-179)
I20260812 06:19:35.651592 24934 log.cc:1079] T e3fe7a3d8a6d4ee7ad19b69fd53aff70 P ec1f864124be4b048a3aca4402da4160: Deleting log segment in path: /tmp/dist-test-taskseRmjK/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515564944993-24506-0/minicluster-data/ts-0-root/wals/e3fe7a3d8a6d4ee7ad19b69fd53aff70/wal-000000037 (ops 180-184)
I20260812 06:19:35.684005 24934 maintenance_manager.cc:643] P ec1f864124be4b048a3aca4402da4160: LogGCOp(e3fe7a3d8a6d4ee7ad19b69fd53aff70) complete. Timing: real 0.033s	user 0.002s	sys 0.031s Metrics: {}
I20260812 06:19:35.684643 25043 maintenance_manager.cc:419] P ec1f864124be4b048a3aca4402da4160: Scheduling UndoDeltaBlockGCOp(e3fe7a3d8a6d4ee7ad19b69fd53aff70): 448 bytes on disk
I20260812 06:19:35.685242 24934 maintenance_manager.cc:643] P ec1f864124be4b048a3aca4402da4160: UndoDeltaBlockGCOp(e3fe7a3d8a6d4ee7ad19b69fd53aff70) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":66,"lbm_reads_lt_1ms":4}
I20260812 06:19:35.685993 25043 maintenance_manager.cc:419] P ec1f864124be4b048a3aca4402da4160: Scheduling FlushDeltaMemStoresOp(e3fe7a3d8a6d4ee7ad19b69fd53aff70): perf score=2.188937
I20260812 06:19:35.708911 24934 maintenance_manager.cc:643] P ec1f864124be4b048a3aca4402da4160: FlushDeltaMemStoresOp(e3fe7a3d8a6d4ee7ad19b69fd53aff70) complete. Timing: real 0.023s	user 0.008s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5190,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:35.709458 25043 maintenance_manager.cc:419] P ec1f864124be4b048a3aca4402da4160: Scheduling FlushDeltaMemStoresOp(e3fe7a3d8a6d4ee7ad19b69fd53aff70): perf score=2.188937
I20260812 06:19:35.720693 24934 maintenance_manager.cc:643] P ec1f864124be4b048a3aca4402da4160: FlushDeltaMemStoresOp(e3fe7a3d8a6d4ee7ad19b69fd53aff70) complete. Timing: real 0.011s	user 0.002s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4153,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:35.721369 25043 maintenance_manager.cc:419] P ec1f864124be4b048a3aca4402da4160: Scheduling MajorDeltaCompactionOp(e3fe7a3d8a6d4ee7ad19b69fd53aff70): perf score=1.000000
I20260812 06:19:35.973079 24934 maintenance_manager.cc:643] P ec1f864124be4b048a3aca4402da4160: MajorDeltaCompactionOp(e3fe7a3d8a6d4ee7ad19b69fd53aff70) complete. Timing: real 0.251s	user 0.174s	sys 0.066s Metrics: {"cfile_cache_miss":734,"cfile_cache_miss_bytes":32979750,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":901,"lbm_read_time_us":16265,"lbm_reads_lt_1ms":774,"lbm_write_time_us":41091,"lbm_writes_lt_1ms":743,"mutex_wait_us":413,"peak_mem_usage":87969044,"reinsert_count":0,"spinlock_wait_cycles":9728,"thread_start_us":89,"threads_started":1,"update_count":3500}
I20260812 06:19:35.974016 25043 maintenance_manager.cc:419] P ec1f864124be4b048a3aca4402da4160: Scheduling FlushDeltaMemStoresOp(e3fe7a3d8a6d4ee7ad19b69fd53aff70): perf score=18.063937
I20260812 06:19:36.037016 24934 maintenance_manager.cc:643] P ec1f864124be4b048a3aca4402da4160: FlushDeltaMemStoresOp(e3fe7a3d8a6d4ee7ad19b69fd53aff70) complete. Timing: real 0.063s	user 0.040s	sys 0.019s Metrics: {"bytes_written":20512315,"delete_count":0,"lbm_write_time_us":27493,"lbm_writes_lt_1ms":503,"reinsert_count":0,"update_count":2500}
I20260812 06:19:36.037626 25043 maintenance_manager.cc:419] P ec1f864124be4b048a3aca4402da4160: Scheduling MajorDeltaCompactionOp(e3fe7a3d8a6d4ee7ad19b69fd53aff70): perf score=1.000000
I20260812 06:19:36.046944 24506 heavy-update-compaction-itest.cc:229] Time spent updating: real 5.302s	user 1.900s	sys 0.189s
I20260812 06:19:36.117071 24506 heavy-update-compaction-itest.cc:265] Time spent scanning: real 0.070s	user 0.001s	sys 0.000s
I20260812 06:19:36.117681 24506 tablet_server.cc:179] TabletServer@127.23.238.129:0 shutting down...
I20260812 06:19:36.185951 24934 maintenance_manager.cc:643] P ec1f864124be4b048a3aca4402da4160: MajorDeltaCompactionOp(e3fe7a3d8a6d4ee7ad19b69fd53aff70) complete. Timing: real 0.148s	user 0.095s	sys 0.052s Metrics: {"cfile_cache_miss":531,"cfile_cache_miss_bytes":24774571,"cfile_init":7,"delete_count":0,"delta_blocks_compacted":1,"delta_iterators_relevant":1,"dirs.queue_time_us":504,"lbm_read_time_us":11953,"lbm_reads_lt_1ms":559,"lbm_write_time_us":25671,"lbm_writes_lt_1ms":543,"mutex_wait_us":21,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":19968,"update_count":2500}
I20260812 06:19:36.187073 24506 ts_tablet_manager.cc:1507] Shutting down tablet manager...
I20260812 06:19:36.187335 24506 tablet_replica.cc:333] T e3fe7a3d8a6d4ee7ad19b69fd53aff70 P ec1f864124be4b048a3aca4402da4160: stopping tablet replica
I20260812 06:19:36.187515 24506 raft_consensus.cc:2243] T e3fe7a3d8a6d4ee7ad19b69fd53aff70 P ec1f864124be4b048a3aca4402da4160 [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:19:36.187793 24506 raft_consensus.cc:2272] T e3fe7a3d8a6d4ee7ad19b69fd53aff70 P ec1f864124be4b048a3aca4402da4160 [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:19:36.193740 24506 tablet_server.cc:196] TabletServer@127.23.238.129:0 shutdown complete.
I20260812 06:19:36.232362 24506 master.cc:562] Master@127.23.238.190:34809 shutting down...
I20260812 06:19:36.236408 24506 raft_consensus.cc:2243] T 00000000000000000000000000000000 P 7a4e0b8c3832438b89e77e79a4e28bce [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:19:36.236609 24506 raft_consensus.cc:2272] T 00000000000000000000000000000000 P 7a4e0b8c3832438b89e77e79a4e28bce [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:19:36.236661 24506 tablet_replica.cc:333] T 00000000000000000000000000000000 P 7a4e0b8c3832438b89e77e79a4e28bce: stopping tablet replica
I20260812 06:19:36.249347 24506 master.cc:584] Master@127.23.238.190:34809 shutdown complete.
[       OK ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/1 (5819 ms)
[----------] 2 tests from EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy (11392 ms total)

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