[==========] Running 2 tests from 1 test suite.
[----------] Global test environment set-up.
[----------] 2 tests from EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy
[ RUN      ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/0
WARNING: Logging before InitGoogleLogging() is written to STDERR
I20260812 06:17:26.350176 13589 internal_mini_cluster.cc:156] Creating distributed mini masters. Addrs: 127.13.69.126:37947
I20260812 06:17:26.351086 13589 env_posix.cc:2285] Not raising this process' open files per process limit of 1048576; it is already as high as it can go
I20260812 06:17:26.351615 13589 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:17:26.357005 13599 instance_detector.cc:116] could not retrieve Azure instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:17:26.357093 13597 instance_detector.cc:116] could not retrieve AWS instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:17:26.357144 13589 server_base.cc:1061] running on GCE node
W20260812 06:17:26.357266 13603 instance_detector.cc:116] could not retrieve OpenStack instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:17:26.357661 13589 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:17:26.357744 13589 system_unsync_time.cc:38] NTP support is disabled. Clock error bounds will not be accurate. This configuration is not suitable for distributed clusters.
I20260812 06:17:26.357771 13589 hybrid_clock.cc:648] HybridClock initialized: now 1786515446357770 us; error 0 us; skew 500 ppm
I20260812 06:17:26.359298 13589 webserver.cc:533] Webserver started at http://127.13.69.126:36551/ using document root <none> and password file <none>
I20260812 06:17:26.359723 13589 fs_manager.cc:362] Metadata directory not provided
I20260812 06:17:26.359771 13589 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:17:26.359941 13589 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:17:26.361361 13589 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskttNqZw/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515446340069-13589-0/minicluster-data/master-0-root/instance:
uuid: "dcd870acdfe04d268cd92c6c4de631aa"
format_stamp: "Formatted at 2026-08-12 06:17:26 on dist-test-slave-6zbq"
I20260812 06:17:26.364399 13589 fs_manager.cc:696] Time spent creating directory manager: real 0.003s	user 0.004s	sys 0.000s
I20260812 06:17:26.366178 13614 log_block_manager.cc:4127] Time spent loading block containers with low live blocks: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:17:26.367071 13589 fs_manager.cc:730] Time spent opening block manager: real 0.002s	user 0.002s	sys 0.000s
I20260812 06:17:26.367172 13589 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskttNqZw/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515446340069-13589-0/minicluster-data/master-0-root
uuid: "dcd870acdfe04d268cd92c6c4de631aa"
format_stamp: "Formatted at 2026-08-12 06:17:26 on dist-test-slave-6zbq"
I20260812 06:17:26.367245 13589 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskttNqZw/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515446340069-13589-0/minicluster-data/master-0-root
metadata directory: /tmp/dist-test-taskttNqZw/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515446340069-13589-0/minicluster-data/master-0-root
1 data directories: /tmp/dist-test-taskttNqZw/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515446340069-13589-0/minicluster-data/master-0-root/data
Total live blocks: 0
Total live bytes: 0
Total live bytes (after alignment): 0
Total number of LBM containers: 0 (0 full)
Did not check for missing blocks
Did not check for orphaned blocks
Total full LBM containers with extra space: 0 (0 repaired)
Total full LBM container extra space in bytes: 0 (0 repaired)
Total incomplete LBM containers: 0 (0 repaired)
Total LBM partial records: 0 (0 repaired)
Total corrupted LBM metadata records in RocksDB: 0 (0 repaired)
I20260812 06:17:26.382081 13589 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:17:26.382592 13589 env_posix.cc:2285] Not raising this process' running threads per effective uid limit of 18446744073709551615; it is already as high as it can go
I20260812 06:17:26.382725 13589 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:17:26.389389 13711 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.13.69.126:37947 every 8 connection(s)
I20260812 06:17:26.389389 13589 rpc_server.cc:307] RPC server started. Bound to: 127.13.69.126:37947
I20260812 06:17:26.391453 13714 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet 00000000000000000000000000000000. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:17:26.396561 13714 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P dcd870acdfe04d268cd92c6c4de631aa: Bootstrap starting.
I20260812 06:17:26.398756 13714 tablet_bootstrap.cc:654] T 00000000000000000000000000000000 P dcd870acdfe04d268cd92c6c4de631aa: Neither blocks nor log segments found. Creating new log.
I20260812 06:17:26.399587 13714 log.cc:826] T 00000000000000000000000000000000 P dcd870acdfe04d268cd92c6c4de631aa: Log is configured to *not* fsync() on all Append() calls
I20260812 06:17:26.401006 13714 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P dcd870acdfe04d268cd92c6c4de631aa: No bootstrap required, opened a new log
I20260812 06:17:26.404109 13714 raft_consensus.cc:359] T 00000000000000000000000000000000 P dcd870acdfe04d268cd92c6c4de631aa [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "dcd870acdfe04d268cd92c6c4de631aa" member_type: VOTER }
I20260812 06:17:26.404259 13714 raft_consensus.cc:385] T 00000000000000000000000000000000 P dcd870acdfe04d268cd92c6c4de631aa [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:17:26.404330 13714 raft_consensus.cc:740] T 00000000000000000000000000000000 P dcd870acdfe04d268cd92c6c4de631aa [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: dcd870acdfe04d268cd92c6c4de631aa, State: Initialized, Role: FOLLOWER
I20260812 06:17:26.404850 13714 consensus_queue.cc:260] T 00000000000000000000000000000000 P dcd870acdfe04d268cd92c6c4de631aa [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: "dcd870acdfe04d268cd92c6c4de631aa" member_type: VOTER }
I20260812 06:17:26.404980 13714 raft_consensus.cc:399] T 00000000000000000000000000000000 P dcd870acdfe04d268cd92c6c4de631aa [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:17:26.405040 13714 raft_consensus.cc:493] T 00000000000000000000000000000000 P dcd870acdfe04d268cd92c6c4de631aa [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:17:26.405151 13714 raft_consensus.cc:3060] T 00000000000000000000000000000000 P dcd870acdfe04d268cd92c6c4de631aa [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:17:26.479350 13714 raft_consensus.cc:515] T 00000000000000000000000000000000 P dcd870acdfe04d268cd92c6c4de631aa [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "dcd870acdfe04d268cd92c6c4de631aa" member_type: VOTER }
I20260812 06:17:26.479964 13714 leader_election.cc:304] T 00000000000000000000000000000000 P dcd870acdfe04d268cd92c6c4de631aa [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: dcd870acdfe04d268cd92c6c4de631aa; no voters: 
I20260812 06:17:26.480355 13714 leader_election.cc:290] T 00000000000000000000000000000000 P dcd870acdfe04d268cd92c6c4de631aa [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:17:26.480486 13724 raft_consensus.cc:2804] T 00000000000000000000000000000000 P dcd870acdfe04d268cd92c6c4de631aa [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:17:26.480705 13724 raft_consensus.cc:697] T 00000000000000000000000000000000 P dcd870acdfe04d268cd92c6c4de631aa [term 1 LEADER]: Becoming Leader. State: Replica: dcd870acdfe04d268cd92c6c4de631aa, State: Running, Role: LEADER
I20260812 06:17:26.481142 13724 consensus_queue.cc:237] T 00000000000000000000000000000000 P dcd870acdfe04d268cd92c6c4de631aa [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: "dcd870acdfe04d268cd92c6c4de631aa" member_type: VOTER }
I20260812 06:17:26.481492 13714 sys_catalog.cc:565] T 00000000000000000000000000000000 P dcd870acdfe04d268cd92c6c4de631aa [sys.catalog]: configured and running, proceeding with master startup.
I20260812 06:17:26.482941 13726 sys_catalog.cc:455] T 00000000000000000000000000000000 P dcd870acdfe04d268cd92c6c4de631aa [sys.catalog]: SysCatalogTable state changed. Reason: New leader dcd870acdfe04d268cd92c6c4de631aa. Latest consensus state: current_term: 1 leader_uuid: "dcd870acdfe04d268cd92c6c4de631aa" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "dcd870acdfe04d268cd92c6c4de631aa" member_type: VOTER } }
I20260812 06:17:26.483060 13726 sys_catalog.cc:458] T 00000000000000000000000000000000 P dcd870acdfe04d268cd92c6c4de631aa [sys.catalog]: This master's current role is: LEADER
I20260812 06:17:26.483377 13725 sys_catalog.cc:455] T 00000000000000000000000000000000 P dcd870acdfe04d268cd92c6c4de631aa [sys.catalog]: SysCatalogTable state changed. Reason: RaftConsensus started. Latest consensus state: current_term: 1 leader_uuid: "dcd870acdfe04d268cd92c6c4de631aa" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "dcd870acdfe04d268cd92c6c4de631aa" member_type: VOTER } }
I20260812 06:17:26.483448 13725 sys_catalog.cc:458] T 00000000000000000000000000000000 P dcd870acdfe04d268cd92c6c4de631aa [sys.catalog]: This master's current role is: LEADER
I20260812 06:17:26.483736 13589 internal_mini_cluster.cc:184] Waiting to initialize catalog manager on master 0
W20260812 06:17:26.485934 13748 catalog_manager.cc:1594] T 00000000000000000000000000000000 P dcd870acdfe04d268cd92c6c4de631aa: loading cluster ID for follower catalog manager: Not found: cluster ID entry not found
W20260812 06:17:26.485993 13748 catalog_manager.cc:883] Not found: cluster ID entry not found: failed to prepare follower catalog manager, will retry
I20260812 06:17:26.486063 13739 catalog_manager.cc:1511] Loading table and tablet metadata into memory...
I20260812 06:17:26.486824 13739 catalog_manager.cc:1520] Initializing Kudu cluster ID...
I20260812 06:17:26.491053 13739 catalog_manager.cc:1383] Generated new cluster ID: f5aa5decc7614c0da0bb6de9b037151a
I20260812 06:17:26.491101 13739 catalog_manager.cc:1531] Initializing Kudu internal certificate authority...
I20260812 06:17:26.501196 13739 catalog_manager.cc:1406] Generated new certificate authority record
I20260812 06:17:26.501870 13739 catalog_manager.cc:1540] Loading token signing keys...
I20260812 06:17:26.512111 13739 catalog_manager.cc:6092] T 00000000000000000000000000000000 P dcd870acdfe04d268cd92c6c4de631aa: Generated new TSK 0
I20260812 06:17:26.512560 13739 catalog_manager.cc:1550] Initializing in-progress tserver states...
I20260812 06:17:26.516052 13589 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:17:26.518277 13757 instance_detector.cc:116] could not retrieve AWS instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:17:26.518324 13760 instance_detector.cc:116] could not retrieve OpenStack instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:17:26.518498 13589 server_base.cc:1061] running on GCE node
W20260812 06:17:26.518306 13758 instance_detector.cc:116] could not retrieve Azure instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:17:26.518749 13589 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:17:26.518795 13589 system_unsync_time.cc:38] NTP support is disabled. Clock error bounds will not be accurate. This configuration is not suitable for distributed clusters.
I20260812 06:17:26.518814 13589 hybrid_clock.cc:648] HybridClock initialized: now 1786515446518814 us; error 0 us; skew 500 ppm
I20260812 06:17:26.519640 13589 webserver.cc:533] Webserver started at http://127.13.69.65:37955/ using document root <none> and password file <none>
I20260812 06:17:26.519794 13589 fs_manager.cc:362] Metadata directory not provided
I20260812 06:17:26.519843 13589 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:17:26.519914 13589 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:17:26.520249 13589 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskttNqZw/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515446340069-13589-0/minicluster-data/ts-0-root/instance:
uuid: "b0d1f062011a482b8bdb5f689b27b2ec"
format_stamp: "Formatted at 2026-08-12 06:17:26 on dist-test-slave-6zbq"
I20260812 06:17:26.521591 13589 fs_manager.cc:696] Time spent creating directory manager: real 0.001s	user 0.000s	sys 0.002s
I20260812 06:17:26.522542 13765 log_block_manager.cc:4127] Time spent loading block containers with low live blocks: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:17:26.522781 13589 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.000s	sys 0.001s
I20260812 06:17:26.522846 13589 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskttNqZw/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515446340069-13589-0/minicluster-data/ts-0-root
uuid: "b0d1f062011a482b8bdb5f689b27b2ec"
format_stamp: "Formatted at 2026-08-12 06:17:26 on dist-test-slave-6zbq"
I20260812 06:17:26.522909 13589 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskttNqZw/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515446340069-13589-0/minicluster-data/ts-0-root
metadata directory: /tmp/dist-test-taskttNqZw/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515446340069-13589-0/minicluster-data/ts-0-root
1 data directories: /tmp/dist-test-taskttNqZw/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515446340069-13589-0/minicluster-data/ts-0-root/data
Total live blocks: 0
Total live bytes: 0
Total live bytes (after alignment): 0
Total number of LBM containers: 0 (0 full)
Did not check for missing blocks
Did not check for orphaned blocks
Total full LBM containers with extra space: 0 (0 repaired)
Total full LBM container extra space in bytes: 0 (0 repaired)
Total incomplete LBM containers: 0 (0 repaired)
Total LBM partial records: 0 (0 repaired)
Total corrupted LBM metadata records in RocksDB: 0 (0 repaired)
I20260812 06:17:26.543229 13589 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:17:26.543562 13589 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:17:26.543946 13589 txn_system_client.cc:432] TxnSystemClient initialization is disabled...
I20260812 06:17:26.544704 13589 ts_tablet_manager.cc:585] Loaded tablet metadata (0 total tablets, 0 live tablets)
I20260812 06:17:26.544752 13589 ts_tablet_manager.cc:531] Time spent load tablet metadata: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:17:26.544792 13589 ts_tablet_manager.cc:616] Registered 0 tablets
I20260812 06:17:26.544821 13589 ts_tablet_manager.cc:595] Time spent register tablets: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:17:26.550838 13589 rpc_server.cc:307] RPC server started. Bound to: 127.13.69.65:37665
I20260812 06:17:26.550892 13880 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.13.69.65:37665 every 8 connection(s)
I20260812 06:17:26.563553 13882 heartbeater.cc:344] Connected to a master server at 127.13.69.126:37947
I20260812 06:17:26.563781 13882 heartbeater.cc:461] Registering TS with master...
I20260812 06:17:26.564219 13882 heartbeater.cc:507] Master 127.13.69.126:37947 requested a full tablet report, sending...
I20260812 06:17:26.565711 13641 ts_manager.cc:194] Registered new tserver with Master: b0d1f062011a482b8bdb5f689b27b2ec (127.13.69.65:37665)
I20260812 06:17:26.565858 13589 internal_mini_cluster.cc:371] 1 TS(s) registered with all masters after 0.014460301s
I20260812 06:17:26.567212 13641 master_service.cc:502] Signed X509 certificate for tserver {username='slave'} at 127.0.0.1:35984
I20260812 06:17:26.574011 13641 catalog_manager.cc:2283] Servicing CreateTable request from {username='slave'} at 127.0.0.1:35988:
name: "heavy-update-compaction-test"
schema {
  columns {
    name: "key"
    type: INT64
    is_key: true
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_a"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_b"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_c"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_d"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_e"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
}
num_replicas: 1
split_rows_range_bounds {
}
partition_schema {
  range_schema {
  }
}
I20260812 06:17:26.589911 13810 tablet_service.cc:1511] Processing CreateTablet for tablet 250de4b1b48b41709a8d05c8b0f79461 (DEFAULT_TABLE table=heavy-update-compaction-test [id=d48fa4f7b53b4b568f5c51670181d7f1]), partition=
I20260812 06:17:26.590332 13810 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet 250de4b1b48b41709a8d05c8b0f79461. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:17:26.592384 13901 tablet_bootstrap.cc:492] T 250de4b1b48b41709a8d05c8b0f79461 P b0d1f062011a482b8bdb5f689b27b2ec: Bootstrap starting.
I20260812 06:17:26.593151 13901 tablet_bootstrap.cc:654] T 250de4b1b48b41709a8d05c8b0f79461 P b0d1f062011a482b8bdb5f689b27b2ec: Neither blocks nor log segments found. Creating new log.
I20260812 06:17:26.594147 13901 tablet_bootstrap.cc:492] T 250de4b1b48b41709a8d05c8b0f79461 P b0d1f062011a482b8bdb5f689b27b2ec: No bootstrap required, opened a new log
I20260812 06:17:26.594249 13901 ts_tablet_manager.cc:1403] T 250de4b1b48b41709a8d05c8b0f79461 P b0d1f062011a482b8bdb5f689b27b2ec: Time spent bootstrapping tablet: real 0.002s	user 0.001s	sys 0.000s
I20260812 06:17:26.594935 13901 raft_consensus.cc:359] T 250de4b1b48b41709a8d05c8b0f79461 P b0d1f062011a482b8bdb5f689b27b2ec [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "b0d1f062011a482b8bdb5f689b27b2ec" member_type: VOTER last_known_addr { host: "127.13.69.65" port: 37665 } }
I20260812 06:17:26.595024 13901 raft_consensus.cc:385] T 250de4b1b48b41709a8d05c8b0f79461 P b0d1f062011a482b8bdb5f689b27b2ec [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:17:26.595046 13901 raft_consensus.cc:740] T 250de4b1b48b41709a8d05c8b0f79461 P b0d1f062011a482b8bdb5f689b27b2ec [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: b0d1f062011a482b8bdb5f689b27b2ec, State: Initialized, Role: FOLLOWER
I20260812 06:17:26.595156 13901 consensus_queue.cc:260] T 250de4b1b48b41709a8d05c8b0f79461 P b0d1f062011a482b8bdb5f689b27b2ec [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: "b0d1f062011a482b8bdb5f689b27b2ec" member_type: VOTER last_known_addr { host: "127.13.69.65" port: 37665 } }
I20260812 06:17:26.595227 13901 raft_consensus.cc:399] T 250de4b1b48b41709a8d05c8b0f79461 P b0d1f062011a482b8bdb5f689b27b2ec [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:17:26.595254 13901 raft_consensus.cc:493] T 250de4b1b48b41709a8d05c8b0f79461 P b0d1f062011a482b8bdb5f689b27b2ec [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:17:26.595302 13901 raft_consensus.cc:3060] T 250de4b1b48b41709a8d05c8b0f79461 P b0d1f062011a482b8bdb5f689b27b2ec [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:17:26.684286 13901 raft_consensus.cc:515] T 250de4b1b48b41709a8d05c8b0f79461 P b0d1f062011a482b8bdb5f689b27b2ec [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "b0d1f062011a482b8bdb5f689b27b2ec" member_type: VOTER last_known_addr { host: "127.13.69.65" port: 37665 } }
I20260812 06:17:26.684485 13901 leader_election.cc:304] T 250de4b1b48b41709a8d05c8b0f79461 P b0d1f062011a482b8bdb5f689b27b2ec [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: b0d1f062011a482b8bdb5f689b27b2ec; no voters: 
I20260812 06:17:26.684693 13901 leader_election.cc:290] T 250de4b1b48b41709a8d05c8b0f79461 P b0d1f062011a482b8bdb5f689b27b2ec [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:17:26.684932 13903 raft_consensus.cc:2804] T 250de4b1b48b41709a8d05c8b0f79461 P b0d1f062011a482b8bdb5f689b27b2ec [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:17:26.685048 13901 ts_tablet_manager.cc:1434] T 250de4b1b48b41709a8d05c8b0f79461 P b0d1f062011a482b8bdb5f689b27b2ec: Time spent starting tablet: real 0.091s	user 0.000s	sys 0.003s
I20260812 06:17:26.685129 13903 raft_consensus.cc:697] T 250de4b1b48b41709a8d05c8b0f79461 P b0d1f062011a482b8bdb5f689b27b2ec [term 1 LEADER]: Becoming Leader. State: Replica: b0d1f062011a482b8bdb5f689b27b2ec, State: Running, Role: LEADER
I20260812 06:17:26.685499 13882 heartbeater.cc:499] Master 127.13.69.126:37947 was elected leader, sending a full tablet report...
I20260812 06:17:26.685319 13903 consensus_queue.cc:237] T 250de4b1b48b41709a8d05c8b0f79461 P b0d1f062011a482b8bdb5f689b27b2ec [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: "b0d1f062011a482b8bdb5f689b27b2ec" member_type: VOTER last_known_addr { host: "127.13.69.65" port: 37665 } }
I20260812 06:17:26.688446 13641 catalog_manager.cc:5719] T 250de4b1b48b41709a8d05c8b0f79461 P b0d1f062011a482b8bdb5f689b27b2ec reported cstate change: term changed from 0 to 1, leader changed from <none> to b0d1f062011a482b8bdb5f689b27b2ec (127.13.69.65). New cstate: current_term: 1 leader_uuid: "b0d1f062011a482b8bdb5f689b27b2ec" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "b0d1f062011a482b8bdb5f689b27b2ec" member_type: VOTER last_known_addr { host: "127.13.69.65" port: 37665 } health_report { overall_health: HEALTHY } } }
I20260812 06:17:26.752282 13589 heavy-update-compaction-itest.cc:215] Time spent inserting: real 0.047s	user 0.015s	sys 0.008s
I20260812 06:17:26.802030 13883 maintenance_manager.cc:419] P b0d1f062011a482b8bdb5f689b27b2ec: Scheduling FlushMRSOp(250de4b1b48b41709a8d05c8b0f79461): perf score=6.156503
I20260812 06:17:26.991465 13772 maintenance_manager.cc:643] P b0d1f062011a482b8bdb5f689b27b2ec: FlushMRSOp(250de4b1b48b41709a8d05c8b0f79461) complete. Timing: real 0.189s	user 0.092s	sys 0.020s Metrics: {"bytes_written":9271708,"cfile_init":1,"compiler_manager_pool.queue_time_us":190,"delete_count":0,"dirs.queue_time_us":62,"dirs.run_cpu_time_us":242,"dirs.run_wall_time_us":7861,"drs_written":1,"lbm_read_time_us":78,"lbm_reads_lt_1ms":4,"lbm_write_time_us":21598,"lbm_writes_lt_1ms":383,"mutex_wait_us":1313,"peak_mem_usage":0,"reinsert_count":0,"rows_written":101,"spinlock_wait_cycles":106752,"thread_start_us":90,"threads_started":1,"update_count":1130}
I20260812 06:17:26.992642 13883 maintenance_manager.cc:419] P b0d1f062011a482b8bdb5f689b27b2ec: Scheduling UndoDeltaBlockGCOp(250de4b1b48b41709a8d05c8b0f79461): 4103815 bytes on disk
I20260812 06:17:26.993335 13772 maintenance_manager.cc:643] P b0d1f062011a482b8bdb5f689b27b2ec: UndoDeltaBlockGCOp(250de4b1b48b41709a8d05c8b0f79461) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":77,"lbm_reads_lt_1ms":4}
I20260812 06:17:26.993757 13883 maintenance_manager.cc:419] P b0d1f062011a482b8bdb5f689b27b2ec: Scheduling FlushDeltaMemStoresOp(250de4b1b48b41709a8d05c8b0f79461): perf score=9.134250
I20260812 06:17:27.085602 13772 maintenance_manager.cc:643] P b0d1f062011a482b8bdb5f689b27b2ec: FlushDeltaMemStoresOp(250de4b1b48b41709a8d05c8b0f79461) complete. Timing: real 0.092s	user 0.010s	sys 0.015s Metrics: {"bytes_written":11240863,"delete_count":0,"lbm_write_time_us":10993,"lbm_writes_lt_1ms":277,"reinsert_count":0,"update_count":1370}
I20260812 06:17:27.086117 13883 maintenance_manager.cc:419] P b0d1f062011a482b8bdb5f689b27b2ec: Scheduling FlushDeltaMemStoresOp(250de4b1b48b41709a8d05c8b0f79461): perf score=10.126437
I20260812 06:17:27.186018 13772 maintenance_manager.cc:643] P b0d1f062011a482b8bdb5f689b27b2ec: FlushDeltaMemStoresOp(250de4b1b48b41709a8d05c8b0f79461) complete. Timing: real 0.100s	user 0.017s	sys 0.008s Metrics: {"bytes_written":12020322,"delete_count":0,"lbm_write_time_us":11189,"lbm_writes_lt_1ms":296,"reinsert_count":0,"update_count":1465}
I20260812 06:17:27.186519 13883 maintenance_manager.cc:419] P b0d1f062011a482b8bdb5f689b27b2ec: Scheduling FlushDeltaMemStoresOp(250de4b1b48b41709a8d05c8b0f79461): perf score=7.149875
I20260812 06:17:27.285917 13772 maintenance_manager.cc:643] P b0d1f062011a482b8bdb5f689b27b2ec: FlushDeltaMemStoresOp(250de4b1b48b41709a8d05c8b0f79461) complete. Timing: real 0.099s	user 0.018s	sys 0.000s Metrics: {"bytes_written":8492254,"delete_count":0,"lbm_write_time_us":7749,"lbm_writes_lt_1ms":210,"reinsert_count":0,"update_count":1035}
I20260812 06:17:27.286553 13883 maintenance_manager.cc:419] P b0d1f062011a482b8bdb5f689b27b2ec: Scheduling FlushDeltaMemStoresOp(250de4b1b48b41709a8d05c8b0f79461): perf score=10.126437
I20260812 06:17:27.384958 13772 maintenance_manager.cc:643] P b0d1f062011a482b8bdb5f689b27b2ec: FlushDeltaMemStoresOp(250de4b1b48b41709a8d05c8b0f79461) complete. Timing: real 0.098s	user 0.016s	sys 0.011s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":11174,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:17:27.385460 13883 maintenance_manager.cc:419] P b0d1f062011a482b8bdb5f689b27b2ec: Scheduling FlushDeltaMemStoresOp(250de4b1b48b41709a8d05c8b0f79461): perf score=7.149875
I20260812 06:17:27.485697 13772 maintenance_manager.cc:643] P b0d1f062011a482b8bdb5f689b27b2ec: FlushDeltaMemStoresOp(250de4b1b48b41709a8d05c8b0f79461) complete. Timing: real 0.100s	user 0.007s	sys 0.012s Metrics: {"bytes_written":8615324,"delete_count":0,"lbm_write_time_us":8618,"lbm_writes_lt_1ms":213,"reinsert_count":0,"update_count":1050}
I20260812 06:17:27.486229 13883 maintenance_manager.cc:419] P b0d1f062011a482b8bdb5f689b27b2ec: Scheduling FlushDeltaMemStoresOp(250de4b1b48b41709a8d05c8b0f79461): perf score=10.126437
I20260812 06:17:27.589003 13772 maintenance_manager.cc:643] P b0d1f062011a482b8bdb5f689b27b2ec: FlushDeltaMemStoresOp(250de4b1b48b41709a8d05c8b0f79461) complete. Timing: real 0.103s	user 0.023s	sys 0.012s Metrics: {"bytes_written":11897249,"delete_count":0,"lbm_write_time_us":15937,"lbm_writes_lt_1ms":293,"reinsert_count":0,"update_count":1450}
I20260812 06:17:27.589489 13883 maintenance_manager.cc:419] P b0d1f062011a482b8bdb5f689b27b2ec: Scheduling FlushDeltaMemStoresOp(250de4b1b48b41709a8d05c8b0f79461): perf score=6.157687
I20260812 06:17:27.680608 13772 maintenance_manager.cc:643] P b0d1f062011a482b8bdb5f689b27b2ec: FlushDeltaMemStoresOp(250de4b1b48b41709a8d05c8b0f79461) complete. Timing: real 0.091s	user 0.013s	sys 0.004s Metrics: {"bytes_written":8205078,"delete_count":0,"lbm_write_time_us":7510,"lbm_writes_lt_1ms":203,"reinsert_count":0,"update_count":1000}
I20260812 06:17:27.681233 13883 maintenance_manager.cc:419] P b0d1f062011a482b8bdb5f689b27b2ec: Scheduling FlushDeltaMemStoresOp(250de4b1b48b41709a8d05c8b0f79461): perf score=9.134250
I20260812 06:17:27.782444 13772 maintenance_manager.cc:643] P b0d1f062011a482b8bdb5f689b27b2ec: FlushDeltaMemStoresOp(250de4b1b48b41709a8d05c8b0f79461) complete. Timing: real 0.101s	user 0.019s	sys 0.008s Metrics: {"bytes_written":10871654,"delete_count":0,"lbm_write_time_us":11438,"lbm_writes_lt_1ms":268,"reinsert_count":0,"update_count":1325}
I20260812 06:17:27.782991 13883 maintenance_manager.cc:419] P b0d1f062011a482b8bdb5f689b27b2ec: Scheduling FlushDeltaMemStoresOp(250de4b1b48b41709a8d05c8b0f79461): perf score=8.142062
I20260812 06:17:27.881685 13772 maintenance_manager.cc:643] P b0d1f062011a482b8bdb5f689b27b2ec: FlushDeltaMemStoresOp(250de4b1b48b41709a8d05c8b0f79461) complete. Timing: real 0.099s	user 0.014s	sys 0.007s Metrics: {"bytes_written":10051161,"delete_count":0,"lbm_write_time_us":9358,"lbm_writes_lt_1ms":248,"reinsert_count":0,"update_count":1225}
I20260812 06:17:27.882259 13883 maintenance_manager.cc:419] P b0d1f062011a482b8bdb5f689b27b2ec: Scheduling FlushDeltaMemStoresOp(250de4b1b48b41709a8d05c8b0f79461): perf score=10.126437
I20260812 06:17:27.987030 13772 maintenance_manager.cc:643] P b0d1f062011a482b8bdb5f689b27b2ec: FlushDeltaMemStoresOp(250de4b1b48b41709a8d05c8b0f79461) complete. Timing: real 0.105s	user 0.030s	sys 0.000s Metrics: {"bytes_written":11897249,"delete_count":0,"lbm_write_time_us":11386,"lbm_writes_lt_1ms":293,"reinsert_count":0,"update_count":1450}
I20260812 06:17:27.987540 13883 maintenance_manager.cc:419] P b0d1f062011a482b8bdb5f689b27b2ec: Scheduling FlushDeltaMemStoresOp(250de4b1b48b41709a8d05c8b0f79461): perf score=8.142062
I20260812 06:17:28.080751 13772 maintenance_manager.cc:643] P b0d1f062011a482b8bdb5f689b27b2ec: FlushDeltaMemStoresOp(250de4b1b48b41709a8d05c8b0f79461) complete. Timing: real 0.093s	user 0.016s	sys 0.008s Metrics: {"bytes_written":9805020,"delete_count":0,"lbm_write_time_us":10712,"lbm_writes_lt_1ms":242,"reinsert_count":0,"update_count":1195}
I20260812 06:17:28.081384 13883 maintenance_manager.cc:419] P b0d1f062011a482b8bdb5f689b27b2ec: Scheduling FlushDeltaMemStoresOp(250de4b1b48b41709a8d05c8b0f79461): perf score=9.134250
I20260812 06:17:28.181051 13772 maintenance_manager.cc:643] P b0d1f062011a482b8bdb5f689b27b2ec: FlushDeltaMemStoresOp(250de4b1b48b41709a8d05c8b0f79461) complete. Timing: real 0.099s	user 0.019s	sys 0.004s Metrics: {"bytes_written":10707559,"delete_count":0,"lbm_write_time_us":10269,"lbm_writes_lt_1ms":264,"reinsert_count":0,"update_count":1305}
I20260812 06:17:28.181614 13883 maintenance_manager.cc:419] P b0d1f062011a482b8bdb5f689b27b2ec: Scheduling FlushDeltaMemStoresOp(250de4b1b48b41709a8d05c8b0f79461): perf score=7.149875
I20260812 06:17:28.279708 13772 maintenance_manager.cc:643] P b0d1f062011a482b8bdb5f689b27b2ec: FlushDeltaMemStoresOp(250de4b1b48b41709a8d05c8b0f79461) complete. Timing: real 0.098s	user 0.015s	sys 0.003s Metrics: {"bytes_written":8615323,"delete_count":0,"lbm_write_time_us":7951,"lbm_writes_lt_1ms":213,"reinsert_count":0,"update_count":1050}
I20260812 06:17:28.280282 13883 maintenance_manager.cc:419] P b0d1f062011a482b8bdb5f689b27b2ec: Scheduling FlushDeltaMemStoresOp(250de4b1b48b41709a8d05c8b0f79461): perf score=10.126437
I20260812 06:17:28.317349 13772 maintenance_manager.cc:643] P b0d1f062011a482b8bdb5f689b27b2ec: FlushDeltaMemStoresOp(250de4b1b48b41709a8d05c8b0f79461) complete. Timing: real 0.037s	user 0.016s	sys 0.016s Metrics: {"bytes_written":11897249,"delete_count":0,"lbm_write_time_us":14151,"lbm_writes_lt_1ms":293,"reinsert_count":0,"update_count":1450}
I20260812 06:17:28.317786 13883 maintenance_manager.cc:419] P b0d1f062011a482b8bdb5f689b27b2ec: Scheduling FlushDeltaMemStoresOp(250de4b1b48b41709a8d05c8b0f79461): perf score=2.188937
I20260812 06:17:28.327526 13772 maintenance_manager.cc:643] P b0d1f062011a482b8bdb5f689b27b2ec: FlushDeltaMemStoresOp(250de4b1b48b41709a8d05c8b0f79461) complete. Timing: real 0.010s	user 0.001s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3687,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:28.328104 13883 maintenance_manager.cc:419] P b0d1f062011a482b8bdb5f689b27b2ec: Scheduling FlushMRSOp(250de4b1b48b41709a8d05c8b0f79461): perf score=1.000000
I20260812 06:17:28.363843 13772 maintenance_manager.cc:643] P b0d1f062011a482b8bdb5f689b27b2ec: FlushMRSOp(250de4b1b48b41709a8d05c8b0f79461) complete. Timing: real 0.036s	user 0.030s	sys 0.003s Metrics: {"bytes_written":1603404,"cfile_init":1,"dirs.queue_time_us":164,"dirs.run_cpu_time_us":188,"dirs.run_wall_time_us":966,"drs_written":1,"lbm_read_time_us":37,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1700,"lbm_writes_lt_1ms":44,"peak_mem_usage":0,"rows_written":39,"thread_start_us":79,"threads_started":1}
I20260812 06:17:28.364616 13883 maintenance_manager.cc:419] P b0d1f062011a482b8bdb5f689b27b2ec: Scheduling LogGCOp(250de4b1b48b41709a8d05c8b0f79461): free 162535423 bytes of WAL
I20260812 06:17:28.364902 13772 log_reader.cc:385] T 250de4b1b48b41709a8d05c8b0f79461: removed 16 log segments from log reader
I20260812 06:17:28.364959 13772 log.cc:1079] T 250de4b1b48b41709a8d05c8b0f79461 P b0d1f062011a482b8bdb5f689b27b2ec: Deleting log segment in path: /tmp/dist-test-taskttNqZw/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515446340069-13589-0/minicluster-data/ts-0-root/wals/250de4b1b48b41709a8d05c8b0f79461/wal-000000001 (ops 1-6)
I20260812 06:17:28.365001 13772 log.cc:1079] T 250de4b1b48b41709a8d05c8b0f79461 P b0d1f062011a482b8bdb5f689b27b2ec: Deleting log segment in path: /tmp/dist-test-taskttNqZw/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515446340069-13589-0/minicluster-data/ts-0-root/wals/250de4b1b48b41709a8d05c8b0f79461/wal-000000002 (ops 7-11)
I20260812 06:17:28.365036 13772 log.cc:1079] T 250de4b1b48b41709a8d05c8b0f79461 P b0d1f062011a482b8bdb5f689b27b2ec: Deleting log segment in path: /tmp/dist-test-taskttNqZw/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515446340069-13589-0/minicluster-data/ts-0-root/wals/250de4b1b48b41709a8d05c8b0f79461/wal-000000003 (ops 12-16)
I20260812 06:17:28.365068 13772 log.cc:1079] T 250de4b1b48b41709a8d05c8b0f79461 P b0d1f062011a482b8bdb5f689b27b2ec: Deleting log segment in path: /tmp/dist-test-taskttNqZw/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515446340069-13589-0/minicluster-data/ts-0-root/wals/250de4b1b48b41709a8d05c8b0f79461/wal-000000004 (ops 17-21)
I20260812 06:17:28.365101 13772 log.cc:1079] T 250de4b1b48b41709a8d05c8b0f79461 P b0d1f062011a482b8bdb5f689b27b2ec: Deleting log segment in path: /tmp/dist-test-taskttNqZw/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515446340069-13589-0/minicluster-data/ts-0-root/wals/250de4b1b48b41709a8d05c8b0f79461/wal-000000005 (ops 22-26)
I20260812 06:17:28.365134 13772 log.cc:1079] T 250de4b1b48b41709a8d05c8b0f79461 P b0d1f062011a482b8bdb5f689b27b2ec: Deleting log segment in path: /tmp/dist-test-taskttNqZw/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515446340069-13589-0/minicluster-data/ts-0-root/wals/250de4b1b48b41709a8d05c8b0f79461/wal-000000006 (ops 27-31)
I20260812 06:17:28.365166 13772 log.cc:1079] T 250de4b1b48b41709a8d05c8b0f79461 P b0d1f062011a482b8bdb5f689b27b2ec: Deleting log segment in path: /tmp/dist-test-taskttNqZw/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515446340069-13589-0/minicluster-data/ts-0-root/wals/250de4b1b48b41709a8d05c8b0f79461/wal-000000007 (ops 32-36)
I20260812 06:17:28.365206 13772 log.cc:1079] T 250de4b1b48b41709a8d05c8b0f79461 P b0d1f062011a482b8bdb5f689b27b2ec: Deleting log segment in path: /tmp/dist-test-taskttNqZw/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515446340069-13589-0/minicluster-data/ts-0-root/wals/250de4b1b48b41709a8d05c8b0f79461/wal-000000008 (ops 37-40)
I20260812 06:17:28.365239 13772 log.cc:1079] T 250de4b1b48b41709a8d05c8b0f79461 P b0d1f062011a482b8bdb5f689b27b2ec: Deleting log segment in path: /tmp/dist-test-taskttNqZw/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515446340069-13589-0/minicluster-data/ts-0-root/wals/250de4b1b48b41709a8d05c8b0f79461/wal-000000009 (ops 41-45)
I20260812 06:17:28.365271 13772 log.cc:1079] T 250de4b1b48b41709a8d05c8b0f79461 P b0d1f062011a482b8bdb5f689b27b2ec: Deleting log segment in path: /tmp/dist-test-taskttNqZw/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515446340069-13589-0/minicluster-data/ts-0-root/wals/250de4b1b48b41709a8d05c8b0f79461/wal-000000010 (ops 46-50)
I20260812 06:17:28.365303 13772 log.cc:1079] T 250de4b1b48b41709a8d05c8b0f79461 P b0d1f062011a482b8bdb5f689b27b2ec: Deleting log segment in path: /tmp/dist-test-taskttNqZw/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515446340069-13589-0/minicluster-data/ts-0-root/wals/250de4b1b48b41709a8d05c8b0f79461/wal-000000011 (ops 51-55)
I20260812 06:17:28.365335 13772 log.cc:1079] T 250de4b1b48b41709a8d05c8b0f79461 P b0d1f062011a482b8bdb5f689b27b2ec: Deleting log segment in path: /tmp/dist-test-taskttNqZw/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515446340069-13589-0/minicluster-data/ts-0-root/wals/250de4b1b48b41709a8d05c8b0f79461/wal-000000012 (ops 56-60)
I20260812 06:17:28.365366 13772 log.cc:1079] T 250de4b1b48b41709a8d05c8b0f79461 P b0d1f062011a482b8bdb5f689b27b2ec: Deleting log segment in path: /tmp/dist-test-taskttNqZw/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515446340069-13589-0/minicluster-data/ts-0-root/wals/250de4b1b48b41709a8d05c8b0f79461/wal-000000013 (ops 61-65)
I20260812 06:17:28.365398 13772 log.cc:1079] T 250de4b1b48b41709a8d05c8b0f79461 P b0d1f062011a482b8bdb5f689b27b2ec: Deleting log segment in path: /tmp/dist-test-taskttNqZw/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515446340069-13589-0/minicluster-data/ts-0-root/wals/250de4b1b48b41709a8d05c8b0f79461/wal-000000014 (ops 66-70)
I20260812 06:17:28.365429 13772 log.cc:1079] T 250de4b1b48b41709a8d05c8b0f79461 P b0d1f062011a482b8bdb5f689b27b2ec: Deleting log segment in path: /tmp/dist-test-taskttNqZw/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515446340069-13589-0/minicluster-data/ts-0-root/wals/250de4b1b48b41709a8d05c8b0f79461/wal-000000015 (ops 71-75)
I20260812 06:17:28.365461 13772 log.cc:1079] T 250de4b1b48b41709a8d05c8b0f79461 P b0d1f062011a482b8bdb5f689b27b2ec: Deleting log segment in path: /tmp/dist-test-taskttNqZw/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515446340069-13589-0/minicluster-data/ts-0-root/wals/250de4b1b48b41709a8d05c8b0f79461/wal-000000016 (ops 76-80)
I20260812 06:17:28.396382 13772 maintenance_manager.cc:643] P b0d1f062011a482b8bdb5f689b27b2ec: LogGCOp(250de4b1b48b41709a8d05c8b0f79461) complete. Timing: real 0.032s	user 0.000s	sys 0.030s Metrics: {}
I20260812 06:17:28.396747 13883 maintenance_manager.cc:419] P b0d1f062011a482b8bdb5f689b27b2ec: Scheduling UndoDeltaBlockGCOp(250de4b1b48b41709a8d05c8b0f79461): 572 bytes on disk
I20260812 06:17:28.397192 13772 maintenance_manager.cc:643] P b0d1f062011a482b8bdb5f689b27b2ec: UndoDeltaBlockGCOp(250de4b1b48b41709a8d05c8b0f79461) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":60,"lbm_reads_lt_1ms":4}
I20260812 06:17:28.397650 13883 maintenance_manager.cc:419] P b0d1f062011a482b8bdb5f689b27b2ec: Scheduling FlushDeltaMemStoresOp(250de4b1b48b41709a8d05c8b0f79461): perf score=6.157687
I20260812 06:17:28.421922 13772 maintenance_manager.cc:643] P b0d1f062011a482b8bdb5f689b27b2ec: FlushDeltaMemStoresOp(250de4b1b48b41709a8d05c8b0f79461) complete. Timing: real 0.024s	user 0.014s	sys 0.007s Metrics: {"bytes_written":8205078,"delete_count":0,"lbm_write_time_us":10063,"lbm_writes_lt_1ms":203,"reinsert_count":0,"update_count":1000}
I20260812 06:17:28.422400 13883 maintenance_manager.cc:419] P b0d1f062011a482b8bdb5f689b27b2ec: Scheduling MajorDeltaCompactionOp(250de4b1b48b41709a8d05c8b0f79461): perf score=1.000000
I20260812 06:17:29.400242 13772 maintenance_manager.cc:643] P b0d1f062011a482b8bdb5f689b27b2ec: MajorDeltaCompactionOp(250de4b1b48b41709a8d05c8b0f79461) complete. Timing: real 0.978s	user 0.625s	sys 0.340s Metrics: {"cfile_cache_miss":4147,"cfile_cache_miss_bytes":172340463,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":17,"delta_iterators_relevant":17,"dirs.queue_time_us":182,"lbm_read_time_us":63206,"lbm_reads_lt_1ms":4179,"lbm_write_time_us":180089,"lbm_writes_lt_1ms":4146,"peak_mem_usage":510472492,"reinsert_count":0,"spinlock_wait_cycles":3968,"thread_start_us":290,"threads_started":7,"update_count":20500}
I20260812 06:17:29.400775 13883 maintenance_manager.cc:419] P b0d1f062011a482b8bdb5f689b27b2ec: Scheduling FlushDeltaMemStoresOp(250de4b1b48b41709a8d05c8b0f79461): perf score=73.626437
I20260812 06:17:29.614204 13772 maintenance_manager.cc:643] P b0d1f062011a482b8bdb5f689b27b2ec: FlushDeltaMemStoresOp(250de4b1b48b41709a8d05c8b0f79461) complete. Timing: real 0.213s	user 0.110s	sys 0.068s Metrics: {"bytes_written":77946206,"delete_count":0,"lbm_write_time_us":81449,"lbm_writes_lt_1ms":1905,"reinsert_count":0,"update_count":9500}
I20260812 06:17:29.614688 13883 maintenance_manager.cc:419] P b0d1f062011a482b8bdb5f689b27b2ec: Scheduling FlushDeltaMemStoresOp(250de4b1b48b41709a8d05c8b0f79461): perf score=14.095187
I20260812 06:17:29.806644 13772 maintenance_manager.cc:643] P b0d1f062011a482b8bdb5f689b27b2ec: FlushDeltaMemStoresOp(250de4b1b48b41709a8d05c8b0f79461) complete. Timing: real 0.192s	user 0.036s	sys 0.004s Metrics: {"bytes_written":16409904,"delete_count":0,"lbm_write_time_us":17464,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:17:29.807132 13883 maintenance_manager.cc:419] P b0d1f062011a482b8bdb5f689b27b2ec: Scheduling FlushDeltaMemStoresOp(250de4b1b48b41709a8d05c8b0f79461): perf score=15.087375
I20260812 06:17:30.007475 13772 maintenance_manager.cc:643] P b0d1f062011a482b8bdb5f689b27b2ec: FlushDeltaMemStoresOp(250de4b1b48b41709a8d05c8b0f79461) complete. Timing: real 0.200s	user 0.020s	sys 0.017s Metrics: {"bytes_written":17025271,"delete_count":0,"lbm_write_time_us":16598,"lbm_writes_lt_1ms":418,"reinsert_count":0,"update_count":2075}
I20260812 06:17:30.008002 13883 maintenance_manager.cc:419] P b0d1f062011a482b8bdb5f689b27b2ec: Scheduling FlushDeltaMemStoresOp(250de4b1b48b41709a8d05c8b0f79461): perf score=20.048312
I20260812 06:17:30.066293 13772 maintenance_manager.cc:643] P b0d1f062011a482b8bdb5f689b27b2ec: FlushDeltaMemStoresOp(250de4b1b48b41709a8d05c8b0f79461) complete. Timing: real 0.058s	user 0.042s	sys 0.011s Metrics: {"bytes_written":22522502,"delete_count":0,"lbm_write_time_us":25878,"lbm_writes_lt_1ms":552,"reinsert_count":0,"update_count":2745}
I20260812 06:17:30.066865 13883 maintenance_manager.cc:419] P b0d1f062011a482b8bdb5f689b27b2ec: Scheduling FlushDeltaMemStoresOp(250de4b1b48b41709a8d05c8b0f79461): perf score=4.173312
I20260812 06:17:30.091277 13772 maintenance_manager.cc:643] P b0d1f062011a482b8bdb5f689b27b2ec: FlushDeltaMemStoresOp(250de4b1b48b41709a8d05c8b0f79461) complete. Timing: real 0.024s	user 0.010s	sys 0.011s Metrics: {"bytes_written":5579537,"delete_count":0,"lbm_write_time_us":7678,"lbm_writes_lt_1ms":139,"reinsert_count":0,"update_count":680}
I20260812 06:17:30.091741 13883 maintenance_manager.cc:419] P b0d1f062011a482b8bdb5f689b27b2ec: Scheduling FlushMRSOp(250de4b1b48b41709a8d05c8b0f79461): perf score=1.000000
I20260812 06:17:30.151523 13772 maintenance_manager.cc:643] P b0d1f062011a482b8bdb5f689b27b2ec: FlushMRSOp(250de4b1b48b41709a8d05c8b0f79461) complete. Timing: real 0.060s	user 0.033s	sys 0.004s Metrics: {"bytes_written":1521477,"cfile_init":1,"dirs.queue_time_us":55,"dirs.run_cpu_time_us":185,"dirs.run_wall_time_us":1071,"drs_written":1,"lbm_read_time_us":41,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1823,"lbm_writes_lt_1ms":44,"peak_mem_usage":0,"rows_written":37}
I20260812 06:17:30.152324 13883 maintenance_manager.cc:419] P b0d1f062011a482b8bdb5f689b27b2ec: Scheduling LogGCOp(250de4b1b48b41709a8d05c8b0f79461): free 157513408 bytes of WAL
I20260812 06:17:30.152565 13772 log_reader.cc:385] T 250de4b1b48b41709a8d05c8b0f79461: removed 15 log segments from log reader
I20260812 06:17:30.152633 13772 log.cc:1079] T 250de4b1b48b41709a8d05c8b0f79461 P b0d1f062011a482b8bdb5f689b27b2ec: Deleting log segment in path: /tmp/dist-test-taskttNqZw/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515446340069-13589-0/minicluster-data/ts-0-root/wals/250de4b1b48b41709a8d05c8b0f79461/wal-000000017 (ops 81-85)
I20260812 06:17:30.152679 13772 log.cc:1079] T 250de4b1b48b41709a8d05c8b0f79461 P b0d1f062011a482b8bdb5f689b27b2ec: Deleting log segment in path: /tmp/dist-test-taskttNqZw/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515446340069-13589-0/minicluster-data/ts-0-root/wals/250de4b1b48b41709a8d05c8b0f79461/wal-000000018 (ops 86-90)
I20260812 06:17:30.152710 13772 log.cc:1079] T 250de4b1b48b41709a8d05c8b0f79461 P b0d1f062011a482b8bdb5f689b27b2ec: Deleting log segment in path: /tmp/dist-test-taskttNqZw/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515446340069-13589-0/minicluster-data/ts-0-root/wals/250de4b1b48b41709a8d05c8b0f79461/wal-000000019 (ops 91-95)
I20260812 06:17:30.152738 13772 log.cc:1079] T 250de4b1b48b41709a8d05c8b0f79461 P b0d1f062011a482b8bdb5f689b27b2ec: Deleting log segment in path: /tmp/dist-test-taskttNqZw/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515446340069-13589-0/minicluster-data/ts-0-root/wals/250de4b1b48b41709a8d05c8b0f79461/wal-000000020 (ops 96-100)
I20260812 06:17:30.152766 13772 log.cc:1079] T 250de4b1b48b41709a8d05c8b0f79461 P b0d1f062011a482b8bdb5f689b27b2ec: Deleting log segment in path: /tmp/dist-test-taskttNqZw/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515446340069-13589-0/minicluster-data/ts-0-root/wals/250de4b1b48b41709a8d05c8b0f79461/wal-000000021 (ops 101-105)
I20260812 06:17:30.152798 13772 log.cc:1079] T 250de4b1b48b41709a8d05c8b0f79461 P b0d1f062011a482b8bdb5f689b27b2ec: Deleting log segment in path: /tmp/dist-test-taskttNqZw/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515446340069-13589-0/minicluster-data/ts-0-root/wals/250de4b1b48b41709a8d05c8b0f79461/wal-000000022 (ops 106-110)
I20260812 06:17:30.152830 13772 log.cc:1079] T 250de4b1b48b41709a8d05c8b0f79461 P b0d1f062011a482b8bdb5f689b27b2ec: Deleting log segment in path: /tmp/dist-test-taskttNqZw/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515446340069-13589-0/minicluster-data/ts-0-root/wals/250de4b1b48b41709a8d05c8b0f79461/wal-000000023 (ops 111-115)
I20260812 06:17:30.152858 13772 log.cc:1079] T 250de4b1b48b41709a8d05c8b0f79461 P b0d1f062011a482b8bdb5f689b27b2ec: Deleting log segment in path: /tmp/dist-test-taskttNqZw/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515446340069-13589-0/minicluster-data/ts-0-root/wals/250de4b1b48b41709a8d05c8b0f79461/wal-000000024 (ops 116-120)
I20260812 06:17:30.152884 13772 log.cc:1079] T 250de4b1b48b41709a8d05c8b0f79461 P b0d1f062011a482b8bdb5f689b27b2ec: Deleting log segment in path: /tmp/dist-test-taskttNqZw/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515446340069-13589-0/minicluster-data/ts-0-root/wals/250de4b1b48b41709a8d05c8b0f79461/wal-000000025 (ops 121-125)
I20260812 06:17:30.152911 13772 log.cc:1079] T 250de4b1b48b41709a8d05c8b0f79461 P b0d1f062011a482b8bdb5f689b27b2ec: Deleting log segment in path: /tmp/dist-test-taskttNqZw/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515446340069-13589-0/minicluster-data/ts-0-root/wals/250de4b1b48b41709a8d05c8b0f79461/wal-000000026 (ops 126-130)
I20260812 06:17:30.152942 13772 log.cc:1079] T 250de4b1b48b41709a8d05c8b0f79461 P b0d1f062011a482b8bdb5f689b27b2ec: Deleting log segment in path: /tmp/dist-test-taskttNqZw/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515446340069-13589-0/minicluster-data/ts-0-root/wals/250de4b1b48b41709a8d05c8b0f79461/wal-000000027 (ops 131-135)
I20260812 06:17:30.152972 13772 log.cc:1079] T 250de4b1b48b41709a8d05c8b0f79461 P b0d1f062011a482b8bdb5f689b27b2ec: Deleting log segment in path: /tmp/dist-test-taskttNqZw/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515446340069-13589-0/minicluster-data/ts-0-root/wals/250de4b1b48b41709a8d05c8b0f79461/wal-000000028 (ops 136-140)
I20260812 06:17:30.153002 13772 log.cc:1079] T 250de4b1b48b41709a8d05c8b0f79461 P b0d1f062011a482b8bdb5f689b27b2ec: Deleting log segment in path: /tmp/dist-test-taskttNqZw/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515446340069-13589-0/minicluster-data/ts-0-root/wals/250de4b1b48b41709a8d05c8b0f79461/wal-000000029 (ops 141-145)
I20260812 06:17:30.153028 13772 log.cc:1079] T 250de4b1b48b41709a8d05c8b0f79461 P b0d1f062011a482b8bdb5f689b27b2ec: Deleting log segment in path: /tmp/dist-test-taskttNqZw/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515446340069-13589-0/minicluster-data/ts-0-root/wals/250de4b1b48b41709a8d05c8b0f79461/wal-000000030 (ops 146-150)
I20260812 06:17:30.153055 13772 log.cc:1079] T 250de4b1b48b41709a8d05c8b0f79461 P b0d1f062011a482b8bdb5f689b27b2ec: Deleting log segment in path: /tmp/dist-test-taskttNqZw/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515446340069-13589-0/minicluster-data/ts-0-root/wals/250de4b1b48b41709a8d05c8b0f79461/wal-000000031 (ops 151-155)
I20260812 06:17:30.185364 13772 maintenance_manager.cc:643] P b0d1f062011a482b8bdb5f689b27b2ec: LogGCOp(250de4b1b48b41709a8d05c8b0f79461) complete. Timing: real 0.033s	user 0.000s	sys 0.030s Metrics: {}
I20260812 06:17:30.186221 13883 maintenance_manager.cc:419] P b0d1f062011a482b8bdb5f689b27b2ec: Scheduling UndoDeltaBlockGCOp(250de4b1b48b41709a8d05c8b0f79461): 553 bytes on disk
I20260812 06:17:30.186733 13772 maintenance_manager.cc:643] P b0d1f062011a482b8bdb5f689b27b2ec: UndoDeltaBlockGCOp(250de4b1b48b41709a8d05c8b0f79461) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":50,"lbm_reads_lt_1ms":4}
I20260812 06:17:30.187222 13883 maintenance_manager.cc:419] P b0d1f062011a482b8bdb5f689b27b2ec: Scheduling FlushDeltaMemStoresOp(250de4b1b48b41709a8d05c8b0f79461): perf score=8.142062
I20260812 06:17:30.214736 13772 maintenance_manager.cc:643] P b0d1f062011a482b8bdb5f689b27b2ec: FlushDeltaMemStoresOp(250de4b1b48b41709a8d05c8b0f79461) complete. Timing: real 0.027s	user 0.015s	sys 0.012s Metrics: {"bytes_written":9969116,"delete_count":0,"lbm_write_time_us":11081,"lbm_writes_lt_1ms":246,"reinsert_count":0,"update_count":1215}
I20260812 06:17:30.215178 13883 maintenance_manager.cc:419] P b0d1f062011a482b8bdb5f689b27b2ec: Scheduling FlushDeltaMemStoresOp(250de4b1b48b41709a8d05c8b0f79461): perf score=1.196750
I20260812 06:17:30.227861 13772 maintenance_manager.cc:643] P b0d1f062011a482b8bdb5f689b27b2ec: FlushDeltaMemStoresOp(250de4b1b48b41709a8d05c8b0f79461) complete. Timing: real 0.013s	user 0.001s	sys 0.004s Metrics: {"bytes_written":2338579,"delete_count":0,"lbm_write_time_us":2327,"lbm_writes_lt_1ms":60,"reinsert_count":0,"update_count":285}
I20260812 06:17:30.228255 13883 maintenance_manager.cc:419] P b0d1f062011a482b8bdb5f689b27b2ec: Scheduling MajorDeltaCompactionOp(250de4b1b48b41709a8d05c8b0f79461): perf score=1.000000
I20260812 06:17:31.106083 13772 maintenance_manager.cc:643] P b0d1f062011a482b8bdb5f689b27b2ec: MajorDeltaCompactionOp(250de4b1b48b41709a8d05c8b0f79461) complete. Timing: real 0.878s	user 0.562s	sys 0.316s Metrics: {"cfile_cache_miss":3739,"cfile_cache_miss_bytes":155929679,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":7,"delta_iterators_relevant":7,"dirs.queue_time_us":240,"lbm_read_time_us":59944,"lbm_reads_lt_1ms":3771,"lbm_write_time_us":158588,"lbm_writes_lt_1ms":3746,"peak_mem_usage":460766204,"reinsert_count":0,"spinlock_wait_cycles":6656,"thread_start_us":382,"threads_started":7,"update_count":18500}
I20260812 06:17:31.106848 13883 maintenance_manager.cc:419] P b0d1f062011a482b8bdb5f689b27b2ec: Scheduling FlushDeltaMemStoresOp(250de4b1b48b41709a8d05c8b0f79461): perf score=69.657687
I20260812 06:17:31.248376 13589 heavy-update-compaction-itest.cc:229] Time spent updating: real 4.496s	user 1.528s	sys 0.151s
I20260812 06:17:31.292951 13589 heavy-update-compaction-itest.cc:265] Time spent scanning: real 0.044s	user 0.002s	sys 0.000s
I20260812 06:17:31.293525 13589 tablet_server.cc:179] TabletServer@127.13.69.65:0 shutting down...
I20260812 06:17:31.463773 13772 maintenance_manager.cc:643] P b0d1f062011a482b8bdb5f689b27b2ec: FlushDeltaMemStoresOp(250de4b1b48b41709a8d05c8b0f79461) complete. Timing: real 0.357s	user 0.091s	sys 0.077s Metrics: {"bytes_written":73843787,"delete_count":0,"lbm_write_time_us":76394,"lbm_writes_lt_1ms":1805,"reinsert_count":0,"update_count":9000}
I20260812 06:17:31.464382 13589 ts_tablet_manager.cc:1507] Shutting down tablet manager...
I20260812 06:17:31.464783 13589 tablet_replica.cc:333] T 250de4b1b48b41709a8d05c8b0f79461 P b0d1f062011a482b8bdb5f689b27b2ec: stopping tablet replica
I20260812 06:17:31.465004 13589 raft_consensus.cc:2243] T 250de4b1b48b41709a8d05c8b0f79461 P b0d1f062011a482b8bdb5f689b27b2ec [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:17:31.465204 13589 raft_consensus.cc:2272] T 250de4b1b48b41709a8d05c8b0f79461 P b0d1f062011a482b8bdb5f689b27b2ec [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:17:31.481508 13589 tablet_server.cc:196] TabletServer@127.13.69.65:0 shutdown complete.
I20260812 06:17:31.665163 13589 master.cc:562] Master@127.13.69.126:37947 shutting down...
I20260812 06:17:31.668639 13589 raft_consensus.cc:2243] T 00000000000000000000000000000000 P dcd870acdfe04d268cd92c6c4de631aa [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:17:31.668785 13589 raft_consensus.cc:2272] T 00000000000000000000000000000000 P dcd870acdfe04d268cd92c6c4de631aa [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:17:31.668838 13589 tablet_replica.cc:333] T 00000000000000000000000000000000 P dcd870acdfe04d268cd92c6c4de631aa: stopping tablet replica
I20260812 06:17:31.680680 13589 master.cc:584] Master@127.13.69.126:37947 shutdown complete.
[       OK ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/0 (5412 ms)
[ RUN      ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/1
I20260812 06:17:31.762257 13589 internal_mini_cluster.cc:156] Creating distributed mini masters. Addrs: 127.13.69.126:34083
I20260812 06:17:31.762671 13589 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:17:31.764605 13944 instance_detector.cc:116] could not retrieve AWS instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:17:31.764690 13947 instance_detector.cc:116] could not retrieve Azure instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:17:31.764726 13950 instance_detector.cc:116] could not retrieve OpenStack instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:17:31.764736 13589 server_base.cc:1061] running on GCE node
I20260812 06:17:31.764983 13589 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:17:31.765021 13589 system_unsync_time.cc:38] NTP support is disabled. Clock error bounds will not be accurate. This configuration is not suitable for distributed clusters.
I20260812 06:17:31.765041 13589 hybrid_clock.cc:648] HybridClock initialized: now 1786515451765041 us; error 0 us; skew 500 ppm
I20260812 06:17:31.765770 13589 webserver.cc:533] Webserver started at http://127.13.69.126:36941/ using document root <none> and password file <none>
I20260812 06:17:31.765908 13589 fs_manager.cc:362] Metadata directory not provided
I20260812 06:17:31.765951 13589 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:17:31.766024 13589 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:17:31.766412 13589 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskttNqZw/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515446340069-13589-0/minicluster-data/master-0-root/instance:
uuid: "df9fcaf385f249768e920a99d2a17258"
format_stamp: "Formatted at 2026-08-12 06:17:31 on dist-test-slave-6zbq"
I20260812 06:17:31.767712 13589 fs_manager.cc:696] Time spent creating directory manager: real 0.001s	user 0.001s	sys 0.000s
I20260812 06:17:31.768508 13957 log_block_manager.cc:4127] Time spent loading block containers with low live blocks: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:17:31.768702 13589 fs_manager.cc:730] Time spent opening block manager: real 0.000s	user 0.001s	sys 0.000s
I20260812 06:17:31.768766 13589 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskttNqZw/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515446340069-13589-0/minicluster-data/master-0-root
uuid: "df9fcaf385f249768e920a99d2a17258"
format_stamp: "Formatted at 2026-08-12 06:17:31 on dist-test-slave-6zbq"
I20260812 06:17:31.768831 13589 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskttNqZw/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515446340069-13589-0/minicluster-data/master-0-root
metadata directory: /tmp/dist-test-taskttNqZw/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515446340069-13589-0/minicluster-data/master-0-root
1 data directories: /tmp/dist-test-taskttNqZw/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515446340069-13589-0/minicluster-data/master-0-root/data
Total live blocks: 0
Total live bytes: 0
Total live bytes (after alignment): 0
Total number of LBM containers: 0 (0 full)
Did not check for missing blocks
Did not check for orphaned blocks
Total full LBM containers with extra space: 0 (0 repaired)
Total full LBM container extra space in bytes: 0 (0 repaired)
Total incomplete LBM containers: 0 (0 repaired)
Total LBM partial records: 0 (0 repaired)
Total corrupted LBM metadata records in RocksDB: 0 (0 repaired)
I20260812 06:17:31.777833 13589 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:17:31.778101 13589 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:17:31.782032 13589 rpc_server.cc:307] RPC server started. Bound to: 127.13.69.126:34083
I20260812 06:17:31.794899 14055 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.13.69.126:34083 every 8 connection(s)
I20260812 06:17:31.795331 14056 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet 00000000000000000000000000000000. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:17:31.796932 14056 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P df9fcaf385f249768e920a99d2a17258: Bootstrap starting.
I20260812 06:17:31.797663 14056 tablet_bootstrap.cc:654] T 00000000000000000000000000000000 P df9fcaf385f249768e920a99d2a17258: Neither blocks nor log segments found. Creating new log.
I20260812 06:17:31.798563 14056 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P df9fcaf385f249768e920a99d2a17258: No bootstrap required, opened a new log
I20260812 06:17:31.798921 14056 raft_consensus.cc:359] T 00000000000000000000000000000000 P df9fcaf385f249768e920a99d2a17258 [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "df9fcaf385f249768e920a99d2a17258" member_type: VOTER }
I20260812 06:17:31.798998 14056 raft_consensus.cc:385] T 00000000000000000000000000000000 P df9fcaf385f249768e920a99d2a17258 [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:17:31.799031 14056 raft_consensus.cc:740] T 00000000000000000000000000000000 P df9fcaf385f249768e920a99d2a17258 [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: df9fcaf385f249768e920a99d2a17258, State: Initialized, Role: FOLLOWER
I20260812 06:17:31.799158 14056 consensus_queue.cc:260] T 00000000000000000000000000000000 P df9fcaf385f249768e920a99d2a17258 [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: "df9fcaf385f249768e920a99d2a17258" member_type: VOTER }
I20260812 06:17:31.799229 14056 raft_consensus.cc:399] T 00000000000000000000000000000000 P df9fcaf385f249768e920a99d2a17258 [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:17:31.799265 14056 raft_consensus.cc:493] T 00000000000000000000000000000000 P df9fcaf385f249768e920a99d2a17258 [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:17:31.799314 14056 raft_consensus.cc:3060] T 00000000000000000000000000000000 P df9fcaf385f249768e920a99d2a17258 [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:17:31.799930 14056 raft_consensus.cc:515] T 00000000000000000000000000000000 P df9fcaf385f249768e920a99d2a17258 [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "df9fcaf385f249768e920a99d2a17258" member_type: VOTER }
I20260812 06:17:31.800055 14056 leader_election.cc:304] T 00000000000000000000000000000000 P df9fcaf385f249768e920a99d2a17258 [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: df9fcaf385f249768e920a99d2a17258; no voters: 
I20260812 06:17:31.800210 14056 leader_election.cc:290] T 00000000000000000000000000000000 P df9fcaf385f249768e920a99d2a17258 [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:17:31.800309 14061 raft_consensus.cc:2804] T 00000000000000000000000000000000 P df9fcaf385f249768e920a99d2a17258 [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:17:31.800491 14061 raft_consensus.cc:697] T 00000000000000000000000000000000 P df9fcaf385f249768e920a99d2a17258 [term 1 LEADER]: Becoming Leader. State: Replica: df9fcaf385f249768e920a99d2a17258, State: Running, Role: LEADER
I20260812 06:17:31.800618 14056 sys_catalog.cc:565] T 00000000000000000000000000000000 P df9fcaf385f249768e920a99d2a17258 [sys.catalog]: configured and running, proceeding with master startup.
I20260812 06:17:31.800616 14061 consensus_queue.cc:237] T 00000000000000000000000000000000 P df9fcaf385f249768e920a99d2a17258 [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: "df9fcaf385f249768e920a99d2a17258" member_type: VOTER }
I20260812 06:17:31.801036 14065 sys_catalog.cc:455] T 00000000000000000000000000000000 P df9fcaf385f249768e920a99d2a17258 [sys.catalog]: SysCatalogTable state changed. Reason: RaftConsensus started. Latest consensus state: current_term: 1 leader_uuid: "df9fcaf385f249768e920a99d2a17258" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "df9fcaf385f249768e920a99d2a17258" member_type: VOTER } }
I20260812 06:17:31.801059 14066 sys_catalog.cc:455] T 00000000000000000000000000000000 P df9fcaf385f249768e920a99d2a17258 [sys.catalog]: SysCatalogTable state changed. Reason: New leader df9fcaf385f249768e920a99d2a17258. Latest consensus state: current_term: 1 leader_uuid: "df9fcaf385f249768e920a99d2a17258" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "df9fcaf385f249768e920a99d2a17258" member_type: VOTER } }
I20260812 06:17:31.801146 14065 sys_catalog.cc:458] T 00000000000000000000000000000000 P df9fcaf385f249768e920a99d2a17258 [sys.catalog]: This master's current role is: LEADER
I20260812 06:17:31.801160 14066 sys_catalog.cc:458] T 00000000000000000000000000000000 P df9fcaf385f249768e920a99d2a17258 [sys.catalog]: This master's current role is: LEADER
I20260812 06:17:31.801537 14070 catalog_manager.cc:1511] Loading table and tablet metadata into memory...
I20260812 06:17:31.802304 14070 catalog_manager.cc:1520] Initializing Kudu cluster ID...
I20260812 06:17:31.802491 13589 internal_mini_cluster.cc:184] Waiting to initialize catalog manager on master 0
I20260812 06:17:31.803975 14070 catalog_manager.cc:1383] Generated new cluster ID: 7fb6fa235758441298d826fe90cde868
I20260812 06:17:31.804030 14070 catalog_manager.cc:1531] Initializing Kudu internal certificate authority...
I20260812 06:17:31.816169 14070 catalog_manager.cc:1406] Generated new certificate authority record
I20260812 06:17:31.816656 14070 catalog_manager.cc:1540] Loading token signing keys...
I20260812 06:17:31.821022 14070 catalog_manager.cc:6092] T 00000000000000000000000000000000 P df9fcaf385f249768e920a99d2a17258: Generated new TSK 0
I20260812 06:17:31.821182 14070 catalog_manager.cc:1550] Initializing in-progress tserver states...
I20260812 06:17:31.834553 13589 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:17:31.836094 14097 instance_detector.cc:116] could not retrieve AWS instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:17:31.836153 14098 instance_detector.cc:116] could not retrieve Azure instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:17:31.836236 13589 server_base.cc:1061] running on GCE node
W20260812 06:17:31.836328 14100 instance_detector.cc:116] could not retrieve OpenStack instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:17:31.836483 13589 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:17:31.836534 13589 system_unsync_time.cc:38] NTP support is disabled. Clock error bounds will not be accurate. This configuration is not suitable for distributed clusters.
I20260812 06:17:31.836562 13589 hybrid_clock.cc:648] HybridClock initialized: now 1786515451836562 us; error 0 us; skew 500 ppm
I20260812 06:17:31.837288 13589 webserver.cc:533] Webserver started at http://127.13.69.65:43095/ using document root <none> and password file <none>
I20260812 06:17:31.837430 13589 fs_manager.cc:362] Metadata directory not provided
I20260812 06:17:31.837476 13589 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:17:31.837544 13589 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:17:31.837849 13589 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskttNqZw/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515446340069-13589-0/minicluster-data/ts-0-root/instance:
uuid: "ecbe51cc6fec4d8e9c9676f4c32a1114"
format_stamp: "Formatted at 2026-08-12 06:17:31 on dist-test-slave-6zbq"
I20260812 06:17:31.839190 13589 fs_manager.cc:696] Time spent creating directory manager: real 0.001s	user 0.000s	sys 0.002s
I20260812 06:17:31.839980 14120 log_block_manager.cc:4127] Time spent loading block containers with low live blocks: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:17:31.840183 13589 fs_manager.cc:730] Time spent opening block manager: real 0.000s	user 0.000s	sys 0.001s
I20260812 06:17:31.840245 13589 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskttNqZw/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515446340069-13589-0/minicluster-data/ts-0-root
uuid: "ecbe51cc6fec4d8e9c9676f4c32a1114"
format_stamp: "Formatted at 2026-08-12 06:17:31 on dist-test-slave-6zbq"
I20260812 06:17:31.840306 13589 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskttNqZw/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515446340069-13589-0/minicluster-data/ts-0-root
metadata directory: /tmp/dist-test-taskttNqZw/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515446340069-13589-0/minicluster-data/ts-0-root
1 data directories: /tmp/dist-test-taskttNqZw/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515446340069-13589-0/minicluster-data/ts-0-root/data
Total live blocks: 0
Total live bytes: 0
Total live bytes (after alignment): 0
Total number of LBM containers: 0 (0 full)
Did not check for missing blocks
Did not check for orphaned blocks
Total full LBM containers with extra space: 0 (0 repaired)
Total full LBM container extra space in bytes: 0 (0 repaired)
Total incomplete LBM containers: 0 (0 repaired)
Total LBM partial records: 0 (0 repaired)
Total corrupted LBM metadata records in RocksDB: 0 (0 repaired)
I20260812 06:17:31.851431 13589 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:17:31.851693 13589 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:17:31.851925 13589 txn_system_client.cc:432] TxnSystemClient initialization is disabled...
I20260812 06:17:31.852310 13589 ts_tablet_manager.cc:585] Loaded tablet metadata (0 total tablets, 0 live tablets)
I20260812 06:17:31.852345 13589 ts_tablet_manager.cc:531] Time spent load tablet metadata: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:17:31.852384 13589 ts_tablet_manager.cc:616] Registered 0 tablets
I20260812 06:17:31.852413 13589 ts_tablet_manager.cc:595] Time spent register tablets: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:17:31.856158 13589 rpc_server.cc:307] RPC server started. Bound to: 127.13.69.65:44883
I20260812 06:17:31.856657 14222 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.13.69.65:44883 every 8 connection(s)
I20260812 06:17:31.864679 14223 heartbeater.cc:344] Connected to a master server at 127.13.69.126:34083
I20260812 06:17:31.864764 14223 heartbeater.cc:461] Registering TS with master...
I20260812 06:17:31.864917 14223 heartbeater.cc:507] Master 127.13.69.126:34083 requested a full tablet report, sending...
I20260812 06:17:31.865443 13985 ts_manager.cc:194] Registered new tserver with Master: ecbe51cc6fec4d8e9c9676f4c32a1114 (127.13.69.65:44883)
I20260812 06:17:31.865473 13589 internal_mini_cluster.cc:371] 1 TS(s) registered with all masters after 0.00873736s
I20260812 06:17:31.866369 13985 master_service.cc:502] Signed X509 certificate for tserver {username='slave'} at 127.0.0.1:54704
I20260812 06:17:31.871659 13985 catalog_manager.cc:2283] Servicing CreateTable request from {username='slave'} at 127.0.0.1:54718:
name: "heavy-update-compaction-test"
schema {
  columns {
    name: "key"
    type: INT64
    is_key: true
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_a"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_b"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_c"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_d"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_e"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
}
num_replicas: 1
split_rows_range_bounds {
}
partition_schema {
  range_schema {
  }
}
I20260812 06:17:31.878887 14165 tablet_service.cc:1511] Processing CreateTablet for tablet f7f6d6abdccf4972b6ec24f38dceb108 (DEFAULT_TABLE table=heavy-update-compaction-test [id=06e1c0eccab64166a9350bebfa053b0d]), partition=
I20260812 06:17:31.879109 14165 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet f7f6d6abdccf4972b6ec24f38dceb108. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:17:31.880719 14244 tablet_bootstrap.cc:492] T f7f6d6abdccf4972b6ec24f38dceb108 P ecbe51cc6fec4d8e9c9676f4c32a1114: Bootstrap starting.
I20260812 06:17:31.881492 14244 tablet_bootstrap.cc:654] T f7f6d6abdccf4972b6ec24f38dceb108 P ecbe51cc6fec4d8e9c9676f4c32a1114: Neither blocks nor log segments found. Creating new log.
I20260812 06:17:31.882510 14244 tablet_bootstrap.cc:492] T f7f6d6abdccf4972b6ec24f38dceb108 P ecbe51cc6fec4d8e9c9676f4c32a1114: No bootstrap required, opened a new log
I20260812 06:17:31.882578 14244 ts_tablet_manager.cc:1403] T f7f6d6abdccf4972b6ec24f38dceb108 P ecbe51cc6fec4d8e9c9676f4c32a1114: Time spent bootstrapping tablet: real 0.002s	user 0.001s	sys 0.000s
I20260812 06:17:31.882903 14244 raft_consensus.cc:359] T f7f6d6abdccf4972b6ec24f38dceb108 P ecbe51cc6fec4d8e9c9676f4c32a1114 [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "ecbe51cc6fec4d8e9c9676f4c32a1114" member_type: VOTER last_known_addr { host: "127.13.69.65" port: 44883 } }
I20260812 06:17:31.882974 14244 raft_consensus.cc:385] T f7f6d6abdccf4972b6ec24f38dceb108 P ecbe51cc6fec4d8e9c9676f4c32a1114 [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:17:31.882999 14244 raft_consensus.cc:740] T f7f6d6abdccf4972b6ec24f38dceb108 P ecbe51cc6fec4d8e9c9676f4c32a1114 [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: ecbe51cc6fec4d8e9c9676f4c32a1114, State: Initialized, Role: FOLLOWER
I20260812 06:17:31.883100 14244 consensus_queue.cc:260] T f7f6d6abdccf4972b6ec24f38dceb108 P ecbe51cc6fec4d8e9c9676f4c32a1114 [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: "ecbe51cc6fec4d8e9c9676f4c32a1114" member_type: VOTER last_known_addr { host: "127.13.69.65" port: 44883 } }
I20260812 06:17:31.883183 14244 raft_consensus.cc:399] T f7f6d6abdccf4972b6ec24f38dceb108 P ecbe51cc6fec4d8e9c9676f4c32a1114 [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:17:31.883213 14244 raft_consensus.cc:493] T f7f6d6abdccf4972b6ec24f38dceb108 P ecbe51cc6fec4d8e9c9676f4c32a1114 [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:17:31.883244 14244 raft_consensus.cc:3060] T f7f6d6abdccf4972b6ec24f38dceb108 P ecbe51cc6fec4d8e9c9676f4c32a1114 [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:17:31.883854 14244 raft_consensus.cc:515] T f7f6d6abdccf4972b6ec24f38dceb108 P ecbe51cc6fec4d8e9c9676f4c32a1114 [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "ecbe51cc6fec4d8e9c9676f4c32a1114" member_type: VOTER last_known_addr { host: "127.13.69.65" port: 44883 } }
I20260812 06:17:31.883960 14244 leader_election.cc:304] T f7f6d6abdccf4972b6ec24f38dceb108 P ecbe51cc6fec4d8e9c9676f4c32a1114 [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: ecbe51cc6fec4d8e9c9676f4c32a1114; no voters: 
I20260812 06:17:31.884095 14244 leader_election.cc:290] T f7f6d6abdccf4972b6ec24f38dceb108 P ecbe51cc6fec4d8e9c9676f4c32a1114 [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:17:31.884223 14246 raft_consensus.cc:2804] T f7f6d6abdccf4972b6ec24f38dceb108 P ecbe51cc6fec4d8e9c9676f4c32a1114 [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:17:31.884440 14223 heartbeater.cc:499] Master 127.13.69.126:34083 was elected leader, sending a full tablet report...
I20260812 06:17:31.884389 14246 raft_consensus.cc:697] T f7f6d6abdccf4972b6ec24f38dceb108 P ecbe51cc6fec4d8e9c9676f4c32a1114 [term 1 LEADER]: Becoming Leader. State: Replica: ecbe51cc6fec4d8e9c9676f4c32a1114, State: Running, Role: LEADER
I20260812 06:17:31.884567 14244 ts_tablet_manager.cc:1434] T f7f6d6abdccf4972b6ec24f38dceb108 P ecbe51cc6fec4d8e9c9676f4c32a1114: Time spent starting tablet: real 0.002s	user 0.002s	sys 0.000s
I20260812 06:17:31.884634 14246 consensus_queue.cc:237] T f7f6d6abdccf4972b6ec24f38dceb108 P ecbe51cc6fec4d8e9c9676f4c32a1114 [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: "ecbe51cc6fec4d8e9c9676f4c32a1114" member_type: VOTER last_known_addr { host: "127.13.69.65" port: 44883 } }
I20260812 06:17:31.885802 13985 catalog_manager.cc:5719] T f7f6d6abdccf4972b6ec24f38dceb108 P ecbe51cc6fec4d8e9c9676f4c32a1114 reported cstate change: term changed from 0 to 1, leader changed from <none> to ecbe51cc6fec4d8e9c9676f4c32a1114 (127.13.69.65). New cstate: current_term: 1 leader_uuid: "ecbe51cc6fec4d8e9c9676f4c32a1114" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "ecbe51cc6fec4d8e9c9676f4c32a1114" member_type: VOTER last_known_addr { host: "127.13.69.65" port: 44883 } health_report { overall_health: HEALTHY } } }
I20260812 06:17:31.939847 13589 heavy-update-compaction-itest.cc:215] Time spent inserting: real 0.050s	user 0.023s	sys 0.000s
I20260812 06:17:32.107272 14224 maintenance_manager.cc:419] P ecbe51cc6fec4d8e9c9676f4c32a1114: Scheduling FlushMRSOp(f7f6d6abdccf4972b6ec24f38dceb108): perf score=23.023690
I20260812 06:17:32.271529 14128 maintenance_manager.cc:643] P ecbe51cc6fec4d8e9c9676f4c32a1114: FlushMRSOp(f7f6d6abdccf4972b6ec24f38dceb108) complete. Timing: real 0.164s	user 0.111s	sys 0.052s Metrics: {"bytes_written":15999661,"cfile_init":1,"delete_count":0,"dirs.queue_time_us":62,"dirs.run_cpu_time_us":171,"dirs.run_wall_time_us":735,"drs_written":1,"lbm_read_time_us":59,"lbm_reads_lt_1ms":4,"lbm_write_time_us":42349,"lbm_writes_lt_1ms":957,"peak_mem_usage":0,"reinsert_count":0,"rows_written":106,"spinlock_wait_cycles":9984,"update_count":1950}
I20260812 06:17:32.272135 14224 maintenance_manager.cc:419] P ecbe51cc6fec4d8e9c9676f4c32a1114: Scheduling LogGCOp(f7f6d6abdccf4972b6ec24f38dceb108): free 20743880 bytes of WAL
I20260812 06:17:32.272356 14128 log_reader.cc:385] T f7f6d6abdccf4972b6ec24f38dceb108: removed 2 log segments from log reader
I20260812 06:17:32.272414 14128 log.cc:1079] T f7f6d6abdccf4972b6ec24f38dceb108 P ecbe51cc6fec4d8e9c9676f4c32a1114: Deleting log segment in path: /tmp/dist-test-taskttNqZw/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515446340069-13589-0/minicluster-data/ts-0-root/wals/f7f6d6abdccf4972b6ec24f38dceb108/wal-000000001 (ops 1-6)
I20260812 06:17:32.272507 14128 log.cc:1079] T f7f6d6abdccf4972b6ec24f38dceb108 P ecbe51cc6fec4d8e9c9676f4c32a1114: Deleting log segment in path: /tmp/dist-test-taskttNqZw/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515446340069-13589-0/minicluster-data/ts-0-root/wals/f7f6d6abdccf4972b6ec24f38dceb108/wal-000000002 (ops 7-11)
I20260812 06:17:32.276968 14128 maintenance_manager.cc:643] P ecbe51cc6fec4d8e9c9676f4c32a1114: LogGCOp(f7f6d6abdccf4972b6ec24f38dceb108) complete. Timing: real 0.005s	user 0.000s	sys 0.002s Metrics: {}
I20260812 06:17:32.277295 14224 maintenance_manager.cc:419] P ecbe51cc6fec4d8e9c9676f4c32a1114: Scheduling UndoDeltaBlockGCOp(f7f6d6abdccf4972b6ec24f38dceb108): 20924070 bytes on disk
I20260812 06:17:32.277786 14128 maintenance_manager.cc:643] P ecbe51cc6fec4d8e9c9676f4c32a1114: UndoDeltaBlockGCOp(f7f6d6abdccf4972b6ec24f38dceb108) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":76,"lbm_reads_lt_1ms":4}
I20260812 06:17:32.278257 14224 maintenance_manager.cc:419] P ecbe51cc6fec4d8e9c9676f4c32a1114: Scheduling FlushDeltaMemStoresOp(f7f6d6abdccf4972b6ec24f38dceb108): perf score=2.188937
I20260812 06:17:32.289120 14128 maintenance_manager.cc:643] P ecbe51cc6fec4d8e9c9676f4c32a1114: FlushDeltaMemStoresOp(f7f6d6abdccf4972b6ec24f38dceb108) complete. Timing: real 0.011s	user 0.005s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4260,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:32.289467 14224 maintenance_manager.cc:419] P ecbe51cc6fec4d8e9c9676f4c32a1114: Scheduling MajorDeltaCompactionOp(f7f6d6abdccf4972b6ec24f38dceb108): perf score=1.000000
I20260812 06:17:32.455806 14128 maintenance_manager.cc:643] P ecbe51cc6fec4d8e9c9676f4c32a1114: MajorDeltaCompactionOp(f7f6d6abdccf4972b6ec24f38dceb108) complete. Timing: real 0.166s	user 0.117s	sys 0.049s Metrics: {"cfile_cache_miss":522,"cfile_cache_miss_bytes":24446413,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":403,"lbm_read_time_us":10304,"lbm_reads_lt_1ms":554,"lbm_write_time_us":28202,"lbm_writes_lt_1ms":533,"peak_mem_usage":61665166,"reinsert_count":0,"spinlock_wait_cycles":8832,"thread_start_us":342,"threads_started":5,"update_count":2450}
I20260812 06:17:32.456382 14224 maintenance_manager.cc:419] P ecbe51cc6fec4d8e9c9676f4c32a1114: Scheduling FlushDeltaMemStoresOp(f7f6d6abdccf4972b6ec24f38dceb108): perf score=14.095187
I20260812 06:17:32.493381 14128 maintenance_manager.cc:643] P ecbe51cc6fec4d8e9c9676f4c32a1114: FlushDeltaMemStoresOp(f7f6d6abdccf4972b6ec24f38dceb108) complete. Timing: real 0.037s	user 0.026s	sys 0.008s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":16121,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:17:32.493798 14224 maintenance_manager.cc:419] P ecbe51cc6fec4d8e9c9676f4c32a1114: Scheduling FlushDeltaMemStoresOp(f7f6d6abdccf4972b6ec24f38dceb108): perf score=2.188937
I20260812 06:17:32.514854 14128 maintenance_manager.cc:643] P ecbe51cc6fec4d8e9c9676f4c32a1114: FlushDeltaMemStoresOp(f7f6d6abdccf4972b6ec24f38dceb108) complete. Timing: real 0.021s	user 0.010s	sys 0.010s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4696,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:32.515297 14224 maintenance_manager.cc:419] P ecbe51cc6fec4d8e9c9676f4c32a1114: Scheduling MajorDeltaCompactionOp(f7f6d6abdccf4972b6ec24f38dceb108): perf score=1.000000
I20260812 06:17:32.674479 14128 maintenance_manager.cc:643] P ecbe51cc6fec4d8e9c9676f4c32a1114: MajorDeltaCompactionOp(f7f6d6abdccf4972b6ec24f38dceb108) complete. Timing: real 0.159s	user 0.102s	sys 0.057s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24856653,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":222,"lbm_read_time_us":10892,"lbm_reads_lt_1ms":564,"lbm_write_time_us":26746,"lbm_writes_lt_1ms":543,"mutex_wait_us":78,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":2816,"update_count":2500}
I20260812 06:17:32.674957 14224 maintenance_manager.cc:419] P ecbe51cc6fec4d8e9c9676f4c32a1114: Scheduling FlushDeltaMemStoresOp(f7f6d6abdccf4972b6ec24f38dceb108): perf score=14.095187
I20260812 06:17:32.713640 14128 maintenance_manager.cc:643] P ecbe51cc6fec4d8e9c9676f4c32a1114: FlushDeltaMemStoresOp(f7f6d6abdccf4972b6ec24f38dceb108) complete. Timing: real 0.039s	user 0.018s	sys 0.017s Metrics: {"bytes_written":16409904,"delete_count":0,"lbm_write_time_us":17221,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:17:32.714126 14224 maintenance_manager.cc:419] P ecbe51cc6fec4d8e9c9676f4c32a1114: Scheduling FlushDeltaMemStoresOp(f7f6d6abdccf4972b6ec24f38dceb108): perf score=2.188937
I20260812 06:17:32.731784 14128 maintenance_manager.cc:643] P ecbe51cc6fec4d8e9c9676f4c32a1114: FlushDeltaMemStoresOp(f7f6d6abdccf4972b6ec24f38dceb108) complete. Timing: real 0.018s	user 0.004s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4818,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:32.732215 14224 maintenance_manager.cc:419] P ecbe51cc6fec4d8e9c9676f4c32a1114: Scheduling MajorDeltaCompactionOp(f7f6d6abdccf4972b6ec24f38dceb108): perf score=1.000000
I20260812 06:17:32.871753 14128 maintenance_manager.cc:643] P ecbe51cc6fec4d8e9c9676f4c32a1114: MajorDeltaCompactionOp(f7f6d6abdccf4972b6ec24f38dceb108) complete. Timing: real 0.139s	user 0.087s	sys 0.052s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24856656,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":89,"lbm_read_time_us":10191,"lbm_reads_lt_1ms":564,"lbm_write_time_us":24973,"lbm_writes_lt_1ms":543,"mutex_wait_us":40,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":4224,"update_count":2500}
I20260812 06:17:32.872463 14224 maintenance_manager.cc:419] P ecbe51cc6fec4d8e9c9676f4c32a1114: Scheduling FlushDeltaMemStoresOp(f7f6d6abdccf4972b6ec24f38dceb108): perf score=14.095187
I20260812 06:17:32.921708 14128 maintenance_manager.cc:643] P ecbe51cc6fec4d8e9c9676f4c32a1114: FlushDeltaMemStoresOp(f7f6d6abdccf4972b6ec24f38dceb108) complete. Timing: real 0.049s	user 0.015s	sys 0.031s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":21866,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:17:32.922173 14224 maintenance_manager.cc:419] P ecbe51cc6fec4d8e9c9676f4c32a1114: Scheduling FlushDeltaMemStoresOp(f7f6d6abdccf4972b6ec24f38dceb108): perf score=2.188937
I20260812 06:17:32.932884 14128 maintenance_manager.cc:643] P ecbe51cc6fec4d8e9c9676f4c32a1114: FlushDeltaMemStoresOp(f7f6d6abdccf4972b6ec24f38dceb108) complete. Timing: real 0.011s	user 0.009s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4024,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:32.933372 14224 maintenance_manager.cc:419] P ecbe51cc6fec4d8e9c9676f4c32a1114: Scheduling MajorDeltaCompactionOp(f7f6d6abdccf4972b6ec24f38dceb108): perf score=1.000000
I20260812 06:17:33.078004 14128 maintenance_manager.cc:643] P ecbe51cc6fec4d8e9c9676f4c32a1114: MajorDeltaCompactionOp(f7f6d6abdccf4972b6ec24f38dceb108) complete. Timing: real 0.144s	user 0.102s	sys 0.040s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24856653,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":967,"lbm_read_time_us":9567,"lbm_reads_lt_1ms":572,"lbm_write_time_us":28569,"lbm_writes_lt_1ms":543,"mutex_wait_us":373,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":20224,"update_count":2500}
I20260812 06:17:33.078598 14224 maintenance_manager.cc:419] P ecbe51cc6fec4d8e9c9676f4c32a1114: Scheduling FlushDeltaMemStoresOp(f7f6d6abdccf4972b6ec24f38dceb108): perf score=14.095187
I20260812 06:17:33.123970 14128 maintenance_manager.cc:643] P ecbe51cc6fec4d8e9c9676f4c32a1114: FlushDeltaMemStoresOp(f7f6d6abdccf4972b6ec24f38dceb108) complete. Timing: real 0.045s	user 0.027s	sys 0.013s Metrics: {"bytes_written":16409900,"delete_count":0,"lbm_write_time_us":18424,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:17:33.124388 14224 maintenance_manager.cc:419] P ecbe51cc6fec4d8e9c9676f4c32a1114: Scheduling FlushDeltaMemStoresOp(f7f6d6abdccf4972b6ec24f38dceb108): perf score=2.188937
I20260812 06:17:33.133689 14128 maintenance_manager.cc:643] P ecbe51cc6fec4d8e9c9676f4c32a1114: FlushDeltaMemStoresOp(f7f6d6abdccf4972b6ec24f38dceb108) complete. Timing: real 0.009s	user 0.004s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3613,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:33.134150 14224 maintenance_manager.cc:419] P ecbe51cc6fec4d8e9c9676f4c32a1114: Scheduling MajorDeltaCompactionOp(f7f6d6abdccf4972b6ec24f38dceb108): perf score=1.000000
I20260812 06:17:33.277823 14128 maintenance_manager.cc:643] P ecbe51cc6fec4d8e9c9676f4c32a1114: MajorDeltaCompactionOp(f7f6d6abdccf4972b6ec24f38dceb108) complete. Timing: real 0.144s	user 0.108s	sys 0.032s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24856652,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":1817,"lbm_read_time_us":9854,"lbm_reads_lt_1ms":572,"lbm_write_time_us":27774,"lbm_writes_lt_1ms":543,"mutex_wait_us":513,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":2048,"update_count":2500}
I20260812 06:17:33.278288 14224 maintenance_manager.cc:419] P ecbe51cc6fec4d8e9c9676f4c32a1114: Scheduling FlushDeltaMemStoresOp(f7f6d6abdccf4972b6ec24f38dceb108): perf score=11.118625
I20260812 06:17:33.304659 14128 maintenance_manager.cc:643] P ecbe51cc6fec4d8e9c9676f4c32a1114: FlushDeltaMemStoresOp(f7f6d6abdccf4972b6ec24f38dceb108) complete. Timing: real 0.026s	user 0.019s	sys 0.005s Metrics: {"bytes_written":12717735,"delete_count":0,"lbm_write_time_us":11300,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:17:33.305235 14224 maintenance_manager.cc:419] P ecbe51cc6fec4d8e9c9676f4c32a1114: Scheduling FlushDeltaMemStoresOp(f7f6d6abdccf4972b6ec24f38dceb108): perf score=2.188937
I20260812 06:17:33.333307 14128 maintenance_manager.cc:643] P ecbe51cc6fec4d8e9c9676f4c32a1114: FlushDeltaMemStoresOp(f7f6d6abdccf4972b6ec24f38dceb108) complete. Timing: real 0.028s	user 0.000s	sys 0.015s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":5764,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:17:33.333725 14224 maintenance_manager.cc:419] P ecbe51cc6fec4d8e9c9676f4c32a1114: Scheduling FlushDeltaMemStoresOp(f7f6d6abdccf4972b6ec24f38dceb108): perf score=2.188937
I20260812 06:17:33.343019 14128 maintenance_manager.cc:643] P ecbe51cc6fec4d8e9c9676f4c32a1114: FlushDeltaMemStoresOp(f7f6d6abdccf4972b6ec24f38dceb108) complete. Timing: real 0.009s	user 0.008s	sys 0.001s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3608,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:33.343405 14224 maintenance_manager.cc:419] P ecbe51cc6fec4d8e9c9676f4c32a1114: Scheduling FlushMRSOp(f7f6d6abdccf4972b6ec24f38dceb108): perf score=1.000000
I20260812 06:17:33.373098 14128 maintenance_manager.cc:643] P ecbe51cc6fec4d8e9c9676f4c32a1114: FlushMRSOp(f7f6d6abdccf4972b6ec24f38dceb108) complete. Timing: real 0.030s	user 0.027s	sys 0.001s Metrics: {"bytes_written":1193503,"cfile_init":1,"dirs.queue_time_us":42,"dirs.run_cpu_time_us":163,"dirs.run_wall_time_us":990,"drs_written":1,"lbm_read_time_us":56,"lbm_reads_lt_1ms":4,"lbm_write_time_us":2005,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":29}
I20260812 06:17:33.373682 14224 maintenance_manager.cc:419] P ecbe51cc6fec4d8e9c9676f4c32a1114: Scheduling LogGCOp(f7f6d6abdccf4972b6ec24f38dceb108): free 121006425 bytes of WAL
I20260812 06:17:33.373886 14128 log_reader.cc:385] T f7f6d6abdccf4972b6ec24f38dceb108: removed 12 log segments from log reader
I20260812 06:17:33.373929 14128 log.cc:1079] T f7f6d6abdccf4972b6ec24f38dceb108 P ecbe51cc6fec4d8e9c9676f4c32a1114: Deleting log segment in path: /tmp/dist-test-taskttNqZw/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515446340069-13589-0/minicluster-data/ts-0-root/wals/f7f6d6abdccf4972b6ec24f38dceb108/wal-000000003 (ops 12-16)
I20260812 06:17:33.373957 14128 log.cc:1079] T f7f6d6abdccf4972b6ec24f38dceb108 P ecbe51cc6fec4d8e9c9676f4c32a1114: Deleting log segment in path: /tmp/dist-test-taskttNqZw/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515446340069-13589-0/minicluster-data/ts-0-root/wals/f7f6d6abdccf4972b6ec24f38dceb108/wal-000000004 (ops 17-21)
I20260812 06:17:33.373987 14128 log.cc:1079] T f7f6d6abdccf4972b6ec24f38dceb108 P ecbe51cc6fec4d8e9c9676f4c32a1114: Deleting log segment in path: /tmp/dist-test-taskttNqZw/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515446340069-13589-0/minicluster-data/ts-0-root/wals/f7f6d6abdccf4972b6ec24f38dceb108/wal-000000005 (ops 22-26)
I20260812 06:17:33.374020 14128 log.cc:1079] T f7f6d6abdccf4972b6ec24f38dceb108 P ecbe51cc6fec4d8e9c9676f4c32a1114: Deleting log segment in path: /tmp/dist-test-taskttNqZw/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515446340069-13589-0/minicluster-data/ts-0-root/wals/f7f6d6abdccf4972b6ec24f38dceb108/wal-000000006 (ops 27-31)
I20260812 06:17:33.374053 14128 log.cc:1079] T f7f6d6abdccf4972b6ec24f38dceb108 P ecbe51cc6fec4d8e9c9676f4c32a1114: Deleting log segment in path: /tmp/dist-test-taskttNqZw/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515446340069-13589-0/minicluster-data/ts-0-root/wals/f7f6d6abdccf4972b6ec24f38dceb108/wal-000000007 (ops 32-36)
I20260812 06:17:33.374084 14128 log.cc:1079] T f7f6d6abdccf4972b6ec24f38dceb108 P ecbe51cc6fec4d8e9c9676f4c32a1114: Deleting log segment in path: /tmp/dist-test-taskttNqZw/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515446340069-13589-0/minicluster-data/ts-0-root/wals/f7f6d6abdccf4972b6ec24f38dceb108/wal-000000008 (ops 37-40)
I20260812 06:17:33.374116 14128 log.cc:1079] T f7f6d6abdccf4972b6ec24f38dceb108 P ecbe51cc6fec4d8e9c9676f4c32a1114: Deleting log segment in path: /tmp/dist-test-taskttNqZw/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515446340069-13589-0/minicluster-data/ts-0-root/wals/f7f6d6abdccf4972b6ec24f38dceb108/wal-000000009 (ops 41-45)
I20260812 06:17:33.374146 14128 log.cc:1079] T f7f6d6abdccf4972b6ec24f38dceb108 P ecbe51cc6fec4d8e9c9676f4c32a1114: Deleting log segment in path: /tmp/dist-test-taskttNqZw/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515446340069-13589-0/minicluster-data/ts-0-root/wals/f7f6d6abdccf4972b6ec24f38dceb108/wal-000000010 (ops 46-50)
I20260812 06:17:33.374178 14128 log.cc:1079] T f7f6d6abdccf4972b6ec24f38dceb108 P ecbe51cc6fec4d8e9c9676f4c32a1114: Deleting log segment in path: /tmp/dist-test-taskttNqZw/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515446340069-13589-0/minicluster-data/ts-0-root/wals/f7f6d6abdccf4972b6ec24f38dceb108/wal-000000011 (ops 51-55)
I20260812 06:17:33.374208 14128 log.cc:1079] T f7f6d6abdccf4972b6ec24f38dceb108 P ecbe51cc6fec4d8e9c9676f4c32a1114: Deleting log segment in path: /tmp/dist-test-taskttNqZw/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515446340069-13589-0/minicluster-data/ts-0-root/wals/f7f6d6abdccf4972b6ec24f38dceb108/wal-000000012 (ops 56-60)
I20260812 06:17:33.374239 14128 log.cc:1079] T f7f6d6abdccf4972b6ec24f38dceb108 P ecbe51cc6fec4d8e9c9676f4c32a1114: Deleting log segment in path: /tmp/dist-test-taskttNqZw/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515446340069-13589-0/minicluster-data/ts-0-root/wals/f7f6d6abdccf4972b6ec24f38dceb108/wal-000000013 (ops 61-65)
I20260812 06:17:33.374270 14128 log.cc:1079] T f7f6d6abdccf4972b6ec24f38dceb108 P ecbe51cc6fec4d8e9c9676f4c32a1114: Deleting log segment in path: /tmp/dist-test-taskttNqZw/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515446340069-13589-0/minicluster-data/ts-0-root/wals/f7f6d6abdccf4972b6ec24f38dceb108/wal-000000014 (ops 66-70)
I20260812 06:17:33.396317 14128 maintenance_manager.cc:643] P ecbe51cc6fec4d8e9c9676f4c32a1114: LogGCOp(f7f6d6abdccf4972b6ec24f38dceb108) complete. Timing: real 0.022s	user 0.000s	sys 0.021s Metrics: {}
I20260812 06:17:33.396708 14224 maintenance_manager.cc:419] P ecbe51cc6fec4d8e9c9676f4c32a1114: Scheduling UndoDeltaBlockGCOp(f7f6d6abdccf4972b6ec24f38dceb108): 462 bytes on disk
I20260812 06:17:33.397133 14128 maintenance_manager.cc:643] P ecbe51cc6fec4d8e9c9676f4c32a1114: UndoDeltaBlockGCOp(f7f6d6abdccf4972b6ec24f38dceb108) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":58,"lbm_reads_lt_1ms":4}
I20260812 06:17:33.397586 14224 maintenance_manager.cc:419] P ecbe51cc6fec4d8e9c9676f4c32a1114: Scheduling FlushDeltaMemStoresOp(f7f6d6abdccf4972b6ec24f38dceb108): perf score=3.181125
I20260812 06:17:33.411553 14128 maintenance_manager.cc:643] P ecbe51cc6fec4d8e9c9676f4c32a1114: FlushDeltaMemStoresOp(f7f6d6abdccf4972b6ec24f38dceb108) complete. Timing: real 0.014s	user 0.006s	sys 0.004s Metrics: {"bytes_written":4512902,"delete_count":0,"lbm_write_time_us":3986,"lbm_writes_lt_1ms":113,"reinsert_count":0,"update_count":550}
I20260812 06:17:33.411924 14224 maintenance_manager.cc:419] P ecbe51cc6fec4d8e9c9676f4c32a1114: Scheduling LogGCOp(f7f6d6abdccf4972b6ec24f38dceb108): free 11564875 bytes of WAL
I20260812 06:17:33.412112 14128 log_reader.cc:385] T f7f6d6abdccf4972b6ec24f38dceb108: removed 1 log segments from log reader
I20260812 06:17:33.412155 14128 log.cc:1079] T f7f6d6abdccf4972b6ec24f38dceb108 P ecbe51cc6fec4d8e9c9676f4c32a1114: Deleting log segment in path: /tmp/dist-test-taskttNqZw/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515446340069-13589-0/minicluster-data/ts-0-root/wals/f7f6d6abdccf4972b6ec24f38dceb108/wal-000000015 (ops 71-74)
I20260812 06:17:33.414026 14128 maintenance_manager.cc:643] P ecbe51cc6fec4d8e9c9676f4c32a1114: LogGCOp(f7f6d6abdccf4972b6ec24f38dceb108) complete. Timing: real 0.002s	user 0.000s	sys 0.000s Metrics: {}
I20260812 06:17:33.414309 14224 maintenance_manager.cc:419] P ecbe51cc6fec4d8e9c9676f4c32a1114: Scheduling FlushDeltaMemStoresOp(f7f6d6abdccf4972b6ec24f38dceb108): perf score=2.188937
I20260812 06:17:33.422751 14128 maintenance_manager.cc:643] P ecbe51cc6fec4d8e9c9676f4c32a1114: FlushDeltaMemStoresOp(f7f6d6abdccf4972b6ec24f38dceb108) complete. Timing: real 0.008s	user 0.007s	sys 0.001s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3109,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:17:33.423214 14224 maintenance_manager.cc:419] P ecbe51cc6fec4d8e9c9676f4c32a1114: Scheduling MajorDeltaCompactionOp(f7f6d6abdccf4972b6ec24f38dceb108): perf score=1.000000
I20260812 06:17:33.600582 14128 maintenance_manager.cc:643] P ecbe51cc6fec4d8e9c9676f4c32a1114: MajorDeltaCompactionOp(f7f6d6abdccf4972b6ec24f38dceb108) complete. Timing: real 0.177s	user 0.142s	sys 0.034s Metrics: {"cfile_cache_miss":735,"cfile_cache_miss_bytes":33061815,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":5,"delta_iterators_relevant":5,"dirs.queue_time_us":1466,"lbm_read_time_us":12672,"lbm_reads_lt_1ms":775,"lbm_write_time_us":33633,"lbm_writes_lt_1ms":743,"mutex_wait_us":495,"peak_mem_usage":87969044,"reinsert_count":0,"spinlock_wait_cycles":2432,"thread_start_us":73,"threads_started":1,"update_count":3500}
I20260812 06:17:33.601666 14224 maintenance_manager.cc:419] P ecbe51cc6fec4d8e9c9676f4c32a1114: Scheduling FlushDeltaMemStoresOp(f7f6d6abdccf4972b6ec24f38dceb108): perf score=15.087375
I20260812 06:17:33.638576 14128 maintenance_manager.cc:643] P ecbe51cc6fec4d8e9c9676f4c32a1114: FlushDeltaMemStoresOp(f7f6d6abdccf4972b6ec24f38dceb108) complete. Timing: real 0.037s	user 0.013s	sys 0.024s Metrics: {"bytes_written":16820143,"delete_count":0,"lbm_write_time_us":16181,"lbm_writes_lt_1ms":413,"reinsert_count":0,"update_count":2050}
I20260812 06:17:33.639036 14224 maintenance_manager.cc:419] P ecbe51cc6fec4d8e9c9676f4c32a1114: Scheduling FlushDeltaMemStoresOp(f7f6d6abdccf4972b6ec24f38dceb108): perf score=2.188937
I20260812 06:17:33.653656 14128 maintenance_manager.cc:643] P ecbe51cc6fec4d8e9c9676f4c32a1114: FlushDeltaMemStoresOp(f7f6d6abdccf4972b6ec24f38dceb108) complete. Timing: real 0.014s	user 0.005s	sys 0.004s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":4126,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:17:33.654070 14224 maintenance_manager.cc:419] P ecbe51cc6fec4d8e9c9676f4c32a1114: Scheduling MajorDeltaCompactionOp(f7f6d6abdccf4972b6ec24f38dceb108): perf score=1.000000
I20260812 06:17:33.800168 14128 maintenance_manager.cc:643] P ecbe51cc6fec4d8e9c9676f4c32a1114: MajorDeltaCompactionOp(f7f6d6abdccf4972b6ec24f38dceb108) complete. Timing: real 0.146s	user 0.098s	sys 0.039s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24856641,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":115,"lbm_read_time_us":10908,"lbm_reads_lt_1ms":564,"lbm_write_time_us":27681,"lbm_writes_lt_1ms":543,"mutex_wait_us":2,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":9600,"update_count":2500}
I20260812 06:17:33.800721 14224 maintenance_manager.cc:419] P ecbe51cc6fec4d8e9c9676f4c32a1114: Scheduling FlushDeltaMemStoresOp(f7f6d6abdccf4972b6ec24f38dceb108): perf score=14.095187
I20260812 06:17:33.848773 14128 maintenance_manager.cc:643] P ecbe51cc6fec4d8e9c9676f4c32a1114: FlushDeltaMemStoresOp(f7f6d6abdccf4972b6ec24f38dceb108) complete. Timing: real 0.048s	user 0.019s	sys 0.021s Metrics: {"bytes_written":16409904,"delete_count":0,"lbm_write_time_us":18995,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:17:33.849169 14224 maintenance_manager.cc:419] P ecbe51cc6fec4d8e9c9676f4c32a1114: Scheduling FlushDeltaMemStoresOp(f7f6d6abdccf4972b6ec24f38dceb108): perf score=2.188937
I20260812 06:17:33.858749 14128 maintenance_manager.cc:643] P ecbe51cc6fec4d8e9c9676f4c32a1114: FlushDeltaMemStoresOp(f7f6d6abdccf4972b6ec24f38dceb108) complete. Timing: real 0.009s	user 0.005s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3652,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:33.859315 14224 maintenance_manager.cc:419] P ecbe51cc6fec4d8e9c9676f4c32a1114: Scheduling MajorDeltaCompactionOp(f7f6d6abdccf4972b6ec24f38dceb108): perf score=1.000000
I20260812 06:17:34.022869 14128 maintenance_manager.cc:643] P ecbe51cc6fec4d8e9c9676f4c32a1114: MajorDeltaCompactionOp(f7f6d6abdccf4972b6ec24f38dceb108) complete. Timing: real 0.163s	user 0.124s	sys 0.039s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24856656,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":522,"lbm_read_time_us":11073,"lbm_reads_lt_1ms":572,"lbm_write_time_us":26327,"lbm_writes_lt_1ms":543,"mutex_wait_us":298,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":38656,"update_count":2500}
I20260812 06:17:34.023397 14224 maintenance_manager.cc:419] P ecbe51cc6fec4d8e9c9676f4c32a1114: Scheduling FlushDeltaMemStoresOp(f7f6d6abdccf4972b6ec24f38dceb108): perf score=14.095187
I20260812 06:17:34.068635 14128 maintenance_manager.cc:643] P ecbe51cc6fec4d8e9c9676f4c32a1114: FlushDeltaMemStoresOp(f7f6d6abdccf4972b6ec24f38dceb108) complete. Timing: real 0.045s	user 0.030s	sys 0.012s Metrics: {"bytes_written":16409897,"delete_count":0,"lbm_write_time_us":20300,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:17:34.069063 14224 maintenance_manager.cc:419] P ecbe51cc6fec4d8e9c9676f4c32a1114: Scheduling MajorDeltaCompactionOp(f7f6d6abdccf4972b6ec24f38dceb108): perf score=1.000000
I20260812 06:17:34.204315 14128 maintenance_manager.cc:643] P ecbe51cc6fec4d8e9c9676f4c32a1114: MajorDeltaCompactionOp(f7f6d6abdccf4972b6ec24f38dceb108) complete. Timing: real 0.135s	user 0.097s	sys 0.031s Metrics: {"cfile_cache_miss":431,"cfile_cache_miss_bytes":20754118,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":1,"delta_iterators_relevant":1,"dirs.queue_time_us":622,"lbm_read_time_us":8810,"lbm_reads_lt_1ms":463,"lbm_write_time_us":20611,"lbm_writes_lt_1ms":443,"mutex_wait_us":320,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":768,"update_count":2000}
I20260812 06:17:34.204879 14224 maintenance_manager.cc:419] P ecbe51cc6fec4d8e9c9676f4c32a1114: Scheduling FlushDeltaMemStoresOp(f7f6d6abdccf4972b6ec24f38dceb108): perf score=14.095187
I20260812 06:17:34.254786 14128 maintenance_manager.cc:643] P ecbe51cc6fec4d8e9c9676f4c32a1114: FlushDeltaMemStoresOp(f7f6d6abdccf4972b6ec24f38dceb108) complete. Timing: real 0.050s	user 0.049s	sys 0.000s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":22087,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:17:34.255232 14224 maintenance_manager.cc:419] P ecbe51cc6fec4d8e9c9676f4c32a1114: Scheduling FlushDeltaMemStoresOp(f7f6d6abdccf4972b6ec24f38dceb108): perf score=2.188937
I20260812 06:17:34.265076 14128 maintenance_manager.cc:643] P ecbe51cc6fec4d8e9c9676f4c32a1114: FlushDeltaMemStoresOp(f7f6d6abdccf4972b6ec24f38dceb108) complete. Timing: real 0.010s	user 0.008s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3710,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:34.265609 14224 maintenance_manager.cc:419] P ecbe51cc6fec4d8e9c9676f4c32a1114: Scheduling MajorDeltaCompactionOp(f7f6d6abdccf4972b6ec24f38dceb108): perf score=1.000000
I20260812 06:17:34.427953 14128 maintenance_manager.cc:643] P ecbe51cc6fec4d8e9c9676f4c32a1114: MajorDeltaCompactionOp(f7f6d6abdccf4972b6ec24f38dceb108) complete. Timing: real 0.162s	user 0.090s	sys 0.067s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24856653,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":188,"lbm_read_time_us":9528,"lbm_reads_lt_1ms":572,"lbm_write_time_us":24469,"lbm_writes_lt_1ms":543,"mutex_wait_us":34,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":4224,"update_count":2500}
I20260812 06:17:34.428439 14224 maintenance_manager.cc:419] P ecbe51cc6fec4d8e9c9676f4c32a1114: Scheduling FlushDeltaMemStoresOp(f7f6d6abdccf4972b6ec24f38dceb108): perf score=14.095187
I20260812 06:17:34.466920 14128 maintenance_manager.cc:643] P ecbe51cc6fec4d8e9c9676f4c32a1114: FlushDeltaMemStoresOp(f7f6d6abdccf4972b6ec24f38dceb108) complete. Timing: real 0.038s	user 0.031s	sys 0.007s Metrics: {"bytes_written":16409898,"delete_count":0,"lbm_write_time_us":17056,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:17:34.467381 14224 maintenance_manager.cc:419] P ecbe51cc6fec4d8e9c9676f4c32a1114: Scheduling FlushDeltaMemStoresOp(f7f6d6abdccf4972b6ec24f38dceb108): perf score=2.188937
I20260812 06:17:34.480473 14128 maintenance_manager.cc:643] P ecbe51cc6fec4d8e9c9676f4c32a1114: FlushDeltaMemStoresOp(f7f6d6abdccf4972b6ec24f38dceb108) complete. Timing: real 0.013s	user 0.008s	sys 0.004s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":5202,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:34.481138 14224 maintenance_manager.cc:419] P ecbe51cc6fec4d8e9c9676f4c32a1114: Scheduling MajorDeltaCompactionOp(f7f6d6abdccf4972b6ec24f38dceb108): perf score=1.000000
I20260812 06:17:34.632131 14128 maintenance_manager.cc:643] P ecbe51cc6fec4d8e9c9676f4c32a1114: MajorDeltaCompactionOp(f7f6d6abdccf4972b6ec24f38dceb108) complete. Timing: real 0.151s	user 0.110s	sys 0.030s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24856649,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":274,"lbm_read_time_us":9902,"lbm_reads_lt_1ms":564,"lbm_write_time_us":27543,"lbm_writes_lt_1ms":543,"mutex_wait_us":23,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":7680,"update_count":2500}
I20260812 06:17:34.632769 14224 maintenance_manager.cc:419] P ecbe51cc6fec4d8e9c9676f4c32a1114: Scheduling FlushDeltaMemStoresOp(f7f6d6abdccf4972b6ec24f38dceb108): perf score=14.095187
I20260812 06:17:34.684558 14128 maintenance_manager.cc:643] P ecbe51cc6fec4d8e9c9676f4c32a1114: FlushDeltaMemStoresOp(f7f6d6abdccf4972b6ec24f38dceb108) complete. Timing: real 0.052s	user 0.032s	sys 0.016s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":22220,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:17:34.685032 14224 maintenance_manager.cc:419] P ecbe51cc6fec4d8e9c9676f4c32a1114: Scheduling FlushDeltaMemStoresOp(f7f6d6abdccf4972b6ec24f38dceb108): perf score=2.188937
I20260812 06:17:34.694497 14128 maintenance_manager.cc:643] P ecbe51cc6fec4d8e9c9676f4c32a1114: FlushDeltaMemStoresOp(f7f6d6abdccf4972b6ec24f38dceb108) complete. Timing: real 0.009s	user 0.009s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3531,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:34.695055 14224 maintenance_manager.cc:419] P ecbe51cc6fec4d8e9c9676f4c32a1114: Scheduling FlushMRSOp(f7f6d6abdccf4972b6ec24f38dceb108): perf score=1.000000
I20260812 06:17:34.725155 14128 maintenance_manager.cc:643] P ecbe51cc6fec4d8e9c9676f4c32a1114: FlushMRSOp(f7f6d6abdccf4972b6ec24f38dceb108) complete. Timing: real 0.030s	user 0.028s	sys 0.000s Metrics: {"bytes_written":1275449,"cfile_init":1,"dirs.queue_time_us":40,"dirs.run_cpu_time_us":146,"dirs.run_wall_time_us":1042,"drs_written":1,"lbm_read_time_us":34,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1542,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":31}
I20260812 06:17:34.725821 14224 maintenance_manager.cc:419] P ecbe51cc6fec4d8e9c9676f4c32a1114: Scheduling LogGCOp(f7f6d6abdccf4972b6ec24f38dceb108): free 117302588 bytes of WAL
I20260812 06:17:34.726049 14128 log_reader.cc:385] T f7f6d6abdccf4972b6ec24f38dceb108: removed 12 log segments from log reader
I20260812 06:17:34.726096 14128 log.cc:1079] T f7f6d6abdccf4972b6ec24f38dceb108 P ecbe51cc6fec4d8e9c9676f4c32a1114: Deleting log segment in path: /tmp/dist-test-taskttNqZw/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515446340069-13589-0/minicluster-data/ts-0-root/wals/f7f6d6abdccf4972b6ec24f38dceb108/wal-000000016 (ops 75-79)
I20260812 06:17:34.726143 14128 log.cc:1079] T f7f6d6abdccf4972b6ec24f38dceb108 P ecbe51cc6fec4d8e9c9676f4c32a1114: Deleting log segment in path: /tmp/dist-test-taskttNqZw/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515446340069-13589-0/minicluster-data/ts-0-root/wals/f7f6d6abdccf4972b6ec24f38dceb108/wal-000000017 (ops 80-84)
I20260812 06:17:34.726177 14128 log.cc:1079] T f7f6d6abdccf4972b6ec24f38dceb108 P ecbe51cc6fec4d8e9c9676f4c32a1114: Deleting log segment in path: /tmp/dist-test-taskttNqZw/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515446340069-13589-0/minicluster-data/ts-0-root/wals/f7f6d6abdccf4972b6ec24f38dceb108/wal-000000018 (ops 85-88)
I20260812 06:17:34.726202 14128 log.cc:1079] T f7f6d6abdccf4972b6ec24f38dceb108 P ecbe51cc6fec4d8e9c9676f4c32a1114: Deleting log segment in path: /tmp/dist-test-taskttNqZw/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515446340069-13589-0/minicluster-data/ts-0-root/wals/f7f6d6abdccf4972b6ec24f38dceb108/wal-000000019 (ops 89-93)
I20260812 06:17:34.726233 14128 log.cc:1079] T f7f6d6abdccf4972b6ec24f38dceb108 P ecbe51cc6fec4d8e9c9676f4c32a1114: Deleting log segment in path: /tmp/dist-test-taskttNqZw/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515446340069-13589-0/minicluster-data/ts-0-root/wals/f7f6d6abdccf4972b6ec24f38dceb108/wal-000000020 (ops 94-98)
I20260812 06:17:34.726265 14128 log.cc:1079] T f7f6d6abdccf4972b6ec24f38dceb108 P ecbe51cc6fec4d8e9c9676f4c32a1114: Deleting log segment in path: /tmp/dist-test-taskttNqZw/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515446340069-13589-0/minicluster-data/ts-0-root/wals/f7f6d6abdccf4972b6ec24f38dceb108/wal-000000021 (ops 99-103)
I20260812 06:17:34.726297 14128 log.cc:1079] T f7f6d6abdccf4972b6ec24f38dceb108 P ecbe51cc6fec4d8e9c9676f4c32a1114: Deleting log segment in path: /tmp/dist-test-taskttNqZw/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515446340069-13589-0/minicluster-data/ts-0-root/wals/f7f6d6abdccf4972b6ec24f38dceb108/wal-000000022 (ops 104-108)
I20260812 06:17:34.726328 14128 log.cc:1079] T f7f6d6abdccf4972b6ec24f38dceb108 P ecbe51cc6fec4d8e9c9676f4c32a1114: Deleting log segment in path: /tmp/dist-test-taskttNqZw/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515446340069-13589-0/minicluster-data/ts-0-root/wals/f7f6d6abdccf4972b6ec24f38dceb108/wal-000000023 (ops 109-113)
I20260812 06:17:34.726390 14128 log.cc:1079] T f7f6d6abdccf4972b6ec24f38dceb108 P ecbe51cc6fec4d8e9c9676f4c32a1114: Deleting log segment in path: /tmp/dist-test-taskttNqZw/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515446340069-13589-0/minicluster-data/ts-0-root/wals/f7f6d6abdccf4972b6ec24f38dceb108/wal-000000024 (ops 114-118)
I20260812 06:17:34.726423 14128 log.cc:1079] T f7f6d6abdccf4972b6ec24f38dceb108 P ecbe51cc6fec4d8e9c9676f4c32a1114: Deleting log segment in path: /tmp/dist-test-taskttNqZw/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515446340069-13589-0/minicluster-data/ts-0-root/wals/f7f6d6abdccf4972b6ec24f38dceb108/wal-000000025 (ops 119-122)
I20260812 06:17:34.726454 14128 log.cc:1079] T f7f6d6abdccf4972b6ec24f38dceb108 P ecbe51cc6fec4d8e9c9676f4c32a1114: Deleting log segment in path: /tmp/dist-test-taskttNqZw/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515446340069-13589-0/minicluster-data/ts-0-root/wals/f7f6d6abdccf4972b6ec24f38dceb108/wal-000000026 (ops 123-127)
I20260812 06:17:34.726483 14128 log.cc:1079] T f7f6d6abdccf4972b6ec24f38dceb108 P ecbe51cc6fec4d8e9c9676f4c32a1114: Deleting log segment in path: /tmp/dist-test-taskttNqZw/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515446340069-13589-0/minicluster-data/ts-0-root/wals/f7f6d6abdccf4972b6ec24f38dceb108/wal-000000027 (ops 128-132)
I20260812 06:17:34.747138 14128 maintenance_manager.cc:643] P ecbe51cc6fec4d8e9c9676f4c32a1114: LogGCOp(f7f6d6abdccf4972b6ec24f38dceb108) complete. Timing: real 0.021s	user 0.000s	sys 0.020s Metrics: {}
I20260812 06:17:34.747516 14224 maintenance_manager.cc:419] P ecbe51cc6fec4d8e9c9676f4c32a1114: Scheduling FlushDeltaMemStoresOp(f7f6d6abdccf4972b6ec24f38dceb108): perf score=3.181125
I20260812 06:17:34.764930 14128 maintenance_manager.cc:643] P ecbe51cc6fec4d8e9c9676f4c32a1114: FlushDeltaMemStoresOp(f7f6d6abdccf4972b6ec24f38dceb108) complete. Timing: real 0.017s	user 0.006s	sys 0.009s Metrics: {"bytes_written":4512903,"delete_count":0,"lbm_write_time_us":6833,"lbm_writes_lt_1ms":113,"reinsert_count":0,"update_count":550}
I20260812 06:17:34.765311 14224 maintenance_manager.cc:419] P ecbe51cc6fec4d8e9c9676f4c32a1114: Scheduling LogGCOp(f7f6d6abdccf4972b6ec24f38dceb108): free 11564893 bytes of WAL
I20260812 06:17:34.765493 14128 log_reader.cc:385] T f7f6d6abdccf4972b6ec24f38dceb108: removed 1 log segments from log reader
I20260812 06:17:34.765535 14128 log.cc:1079] T f7f6d6abdccf4972b6ec24f38dceb108 P ecbe51cc6fec4d8e9c9676f4c32a1114: Deleting log segment in path: /tmp/dist-test-taskttNqZw/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515446340069-13589-0/minicluster-data/ts-0-root/wals/f7f6d6abdccf4972b6ec24f38dceb108/wal-000000028 (ops 133-136)
I20260812 06:17:34.767648 14128 maintenance_manager.cc:643] P ecbe51cc6fec4d8e9c9676f4c32a1114: LogGCOp(f7f6d6abdccf4972b6ec24f38dceb108) complete. Timing: real 0.002s	user 0.000s	sys 0.001s Metrics: {}
I20260812 06:17:34.767921 14224 maintenance_manager.cc:419] P ecbe51cc6fec4d8e9c9676f4c32a1114: Scheduling UndoDeltaBlockGCOp(f7f6d6abdccf4972b6ec24f38dceb108): 482 bytes on disk
I20260812 06:17:34.768267 14128 maintenance_manager.cc:643] P ecbe51cc6fec4d8e9c9676f4c32a1114: UndoDeltaBlockGCOp(f7f6d6abdccf4972b6ec24f38dceb108) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":53,"lbm_reads_lt_1ms":4}
I20260812 06:17:34.768700 14224 maintenance_manager.cc:419] P ecbe51cc6fec4d8e9c9676f4c32a1114: Scheduling FlushDeltaMemStoresOp(f7f6d6abdccf4972b6ec24f38dceb108): perf score=2.188937
I20260812 06:17:34.785638 14128 maintenance_manager.cc:643] P ecbe51cc6fec4d8e9c9676f4c32a1114: FlushDeltaMemStoresOp(f7f6d6abdccf4972b6ec24f38dceb108) complete. Timing: real 0.017s	user 0.007s	sys 0.007s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3310,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:17:34.786152 14224 maintenance_manager.cc:419] P ecbe51cc6fec4d8e9c9676f4c32a1114: Scheduling MajorDeltaCompactionOp(f7f6d6abdccf4972b6ec24f38dceb108): perf score=1.000000
I20260812 06:17:35.012537 14128 maintenance_manager.cc:643] P ecbe51cc6fec4d8e9c9676f4c32a1114: MajorDeltaCompactionOp(f7f6d6abdccf4972b6ec24f38dceb108) complete. Timing: real 0.226s	user 0.127s	sys 0.098s Metrics: {"cfile_cache_miss":734,"cfile_cache_miss_bytes":33061705,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":249,"lbm_read_time_us":15634,"lbm_reads_lt_1ms":774,"lbm_write_time_us":36127,"lbm_writes_lt_1ms":743,"mutex_wait_us":37,"peak_mem_usage":87969044,"reinsert_count":0,"spinlock_wait_cycles":18048,"thread_start_us":92,"threads_started":1,"update_count":3500}
I20260812 06:17:35.013041 14224 maintenance_manager.cc:419] P ecbe51cc6fec4d8e9c9676f4c32a1114: Scheduling FlushDeltaMemStoresOp(f7f6d6abdccf4972b6ec24f38dceb108): perf score=18.063937
I20260812 06:17:35.076944 14128 maintenance_manager.cc:643] P ecbe51cc6fec4d8e9c9676f4c32a1114: FlushDeltaMemStoresOp(f7f6d6abdccf4972b6ec24f38dceb108) complete. Timing: real 0.064s	user 0.051s	sys 0.004s Metrics: {"bytes_written":20512316,"delete_count":0,"lbm_write_time_us":26051,"lbm_writes_lt_1ms":503,"reinsert_count":0,"update_count":2500}
I20260812 06:17:35.077466 14224 maintenance_manager.cc:419] P ecbe51cc6fec4d8e9c9676f4c32a1114: Scheduling FlushDeltaMemStoresOp(f7f6d6abdccf4972b6ec24f38dceb108): perf score=2.188937
I20260812 06:17:35.087028 14128 maintenance_manager.cc:643] P ecbe51cc6fec4d8e9c9676f4c32a1114: FlushDeltaMemStoresOp(f7f6d6abdccf4972b6ec24f38dceb108) complete. Timing: real 0.009s	user 0.009s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3589,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:35.087671 14224 maintenance_manager.cc:419] P ecbe51cc6fec4d8e9c9676f4c32a1114: Scheduling MajorDeltaCompactionOp(f7f6d6abdccf4972b6ec24f38dceb108): perf score=1.000000
I20260812 06:17:35.293558 14128 maintenance_manager.cc:643] P ecbe51cc6fec4d8e9c9676f4c32a1114: MajorDeltaCompactionOp(f7f6d6abdccf4972b6ec24f38dceb108) complete. Timing: real 0.206s	user 0.138s	sys 0.060s Metrics: {"cfile_cache_miss":632,"cfile_cache_miss_bytes":28959068,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":958,"lbm_read_time_us":13288,"lbm_reads_lt_1ms":672,"lbm_write_time_us":31112,"lbm_writes_lt_1ms":643,"mutex_wait_us":2,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":5504,"update_count":3000}
I20260812 06:17:35.294067 14224 maintenance_manager.cc:419] P ecbe51cc6fec4d8e9c9676f4c32a1114: Scheduling FlushDeltaMemStoresOp(f7f6d6abdccf4972b6ec24f38dceb108): perf score=18.063937
I20260812 06:17:35.358181 14128 maintenance_manager.cc:643] P ecbe51cc6fec4d8e9c9676f4c32a1114: FlushDeltaMemStoresOp(f7f6d6abdccf4972b6ec24f38dceb108) complete. Timing: real 0.064s	user 0.040s	sys 0.020s Metrics: {"bytes_written":20512315,"delete_count":0,"lbm_write_time_us":28016,"lbm_writes_lt_1ms":503,"reinsert_count":0,"update_count":2500}
I20260812 06:17:35.358644 14224 maintenance_manager.cc:419] P ecbe51cc6fec4d8e9c9676f4c32a1114: Scheduling FlushDeltaMemStoresOp(f7f6d6abdccf4972b6ec24f38dceb108): perf score=2.188937
I20260812 06:17:35.368520 14128 maintenance_manager.cc:643] P ecbe51cc6fec4d8e9c9676f4c32a1114: FlushDeltaMemStoresOp(f7f6d6abdccf4972b6ec24f38dceb108) complete. Timing: real 0.010s	user 0.004s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3640,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:35.369060 14224 maintenance_manager.cc:419] P ecbe51cc6fec4d8e9c9676f4c32a1114: Scheduling MajorDeltaCompactionOp(f7f6d6abdccf4972b6ec24f38dceb108): perf score=1.000000
I20260812 06:17:35.562829 14128 maintenance_manager.cc:643] P ecbe51cc6fec4d8e9c9676f4c32a1114: MajorDeltaCompactionOp(f7f6d6abdccf4972b6ec24f38dceb108) complete. Timing: real 0.194s	user 0.138s	sys 0.055s Metrics: {"cfile_cache_miss":632,"cfile_cache_miss_bytes":28959067,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":554,"lbm_read_time_us":13322,"lbm_reads_lt_1ms":672,"lbm_write_time_us":31760,"lbm_writes_lt_1ms":643,"mutex_wait_us":311,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":18688,"update_count":3000}
I20260812 06:17:35.563366 14224 maintenance_manager.cc:419] P ecbe51cc6fec4d8e9c9676f4c32a1114: Scheduling FlushDeltaMemStoresOp(f7f6d6abdccf4972b6ec24f38dceb108): perf score=14.095187
I20260812 06:17:35.614035 14128 maintenance_manager.cc:643] P ecbe51cc6fec4d8e9c9676f4c32a1114: FlushDeltaMemStoresOp(f7f6d6abdccf4972b6ec24f38dceb108) complete. Timing: real 0.050s	user 0.031s	sys 0.016s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":21165,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":402,"reinsert_count":0,"update_count":2000}
I20260812 06:17:35.614748 14224 maintenance_manager.cc:419] P ecbe51cc6fec4d8e9c9676f4c32a1114: Scheduling FlushDeltaMemStoresOp(f7f6d6abdccf4972b6ec24f38dceb108): perf score=2.188937
I20260812 06:17:35.627070 14128 maintenance_manager.cc:643] P ecbe51cc6fec4d8e9c9676f4c32a1114: FlushDeltaMemStoresOp(f7f6d6abdccf4972b6ec24f38dceb108) complete. Timing: real 0.012s	user 0.010s	sys 0.001s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4808,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:35.627492 14224 maintenance_manager.cc:419] P ecbe51cc6fec4d8e9c9676f4c32a1114: Scheduling MajorDeltaCompactionOp(f7f6d6abdccf4972b6ec24f38dceb108): perf score=1.000000
I20260812 06:17:35.785730 14128 maintenance_manager.cc:643] P ecbe51cc6fec4d8e9c9676f4c32a1114: MajorDeltaCompactionOp(f7f6d6abdccf4972b6ec24f38dceb108) complete. Timing: real 0.158s	user 0.110s	sys 0.048s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24856653,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":63,"lbm_read_time_us":10439,"lbm_reads_lt_1ms":564,"lbm_write_time_us":26339,"lbm_writes_lt_1ms":543,"mutex_wait_us":20,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":10880,"update_count":2500}
I20260812 06:17:35.786757 14224 maintenance_manager.cc:419] P ecbe51cc6fec4d8e9c9676f4c32a1114: Scheduling FlushDeltaMemStoresOp(f7f6d6abdccf4972b6ec24f38dceb108): perf score=14.095187
I20260812 06:17:35.829619 14128 maintenance_manager.cc:643] P ecbe51cc6fec4d8e9c9676f4c32a1114: FlushDeltaMemStoresOp(f7f6d6abdccf4972b6ec24f38dceb108) complete. Timing: real 0.043s	user 0.022s	sys 0.017s Metrics: {"bytes_written":16409904,"delete_count":0,"lbm_write_time_us":18998,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:17:35.830068 14224 maintenance_manager.cc:419] P ecbe51cc6fec4d8e9c9676f4c32a1114: Scheduling FlushDeltaMemStoresOp(f7f6d6abdccf4972b6ec24f38dceb108): perf score=2.188937
I20260812 06:17:35.842792 14128 maintenance_manager.cc:643] P ecbe51cc6fec4d8e9c9676f4c32a1114: FlushDeltaMemStoresOp(f7f6d6abdccf4972b6ec24f38dceb108) complete. Timing: real 0.013s	user 0.009s	sys 0.003s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4648,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:35.843320 14224 maintenance_manager.cc:419] P ecbe51cc6fec4d8e9c9676f4c32a1114: Scheduling MajorDeltaCompactionOp(f7f6d6abdccf4972b6ec24f38dceb108): perf score=1.000000
I20260812 06:17:35.998481 14128 maintenance_manager.cc:643] P ecbe51cc6fec4d8e9c9676f4c32a1114: MajorDeltaCompactionOp(f7f6d6abdccf4972b6ec24f38dceb108) complete. Timing: real 0.155s	user 0.094s	sys 0.060s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24856656,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":314,"lbm_read_time_us":12404,"lbm_reads_lt_1ms":564,"lbm_write_time_us":25239,"lbm_writes_lt_1ms":543,"mutex_wait_us":66,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":14336,"update_count":2500}
I20260812 06:17:35.999051 14224 maintenance_manager.cc:419] P ecbe51cc6fec4d8e9c9676f4c32a1114: Scheduling FlushDeltaMemStoresOp(f7f6d6abdccf4972b6ec24f38dceb108): perf score=14.095187
I20260812 06:17:36.055302 14128 maintenance_manager.cc:643] P ecbe51cc6fec4d8e9c9676f4c32a1114: FlushDeltaMemStoresOp(f7f6d6abdccf4972b6ec24f38dceb108) complete. Timing: real 0.056s	user 0.039s	sys 0.017s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":22120,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:17:36.055795 14224 maintenance_manager.cc:419] P ecbe51cc6fec4d8e9c9676f4c32a1114: Scheduling FlushDeltaMemStoresOp(f7f6d6abdccf4972b6ec24f38dceb108): perf score=2.188937
I20260812 06:17:36.065361 14128 maintenance_manager.cc:643] P ecbe51cc6fec4d8e9c9676f4c32a1114: FlushDeltaMemStoresOp(f7f6d6abdccf4972b6ec24f38dceb108) complete. Timing: real 0.009s	user 0.008s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3680,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:36.068229 14224 maintenance_manager.cc:419] P ecbe51cc6fec4d8e9c9676f4c32a1114: Scheduling FlushMRSOp(f7f6d6abdccf4972b6ec24f38dceb108): perf score=1.000000
I20260812 06:17:36.098922 14128 maintenance_manager.cc:643] P ecbe51cc6fec4d8e9c9676f4c32a1114: FlushMRSOp(f7f6d6abdccf4972b6ec24f38dceb108) complete. Timing: real 0.031s	user 0.021s	sys 0.004s Metrics: {"bytes_written":1193507,"cfile_init":1,"dirs.queue_time_us":60,"dirs.run_cpu_time_us":222,"dirs.run_wall_time_us":1251,"drs_written":1,"lbm_read_time_us":39,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1472,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":29}
I20260812 06:17:36.099535 14224 maintenance_manager.cc:419] P ecbe51cc6fec4d8e9c9676f4c32a1114: Scheduling LogGCOp(f7f6d6abdccf4972b6ec24f38dceb108): free 108988743 bytes of WAL
I20260812 06:17:36.099740 14128 log_reader.cc:385] T f7f6d6abdccf4972b6ec24f38dceb108: removed 11 log segments from log reader
I20260812 06:17:36.099785 14128 log.cc:1079] T f7f6d6abdccf4972b6ec24f38dceb108 P ecbe51cc6fec4d8e9c9676f4c32a1114: Deleting log segment in path: /tmp/dist-test-taskttNqZw/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515446340069-13589-0/minicluster-data/ts-0-root/wals/f7f6d6abdccf4972b6ec24f38dceb108/wal-000000029 (ops 137-141)
I20260812 06:17:36.099810 14128 log.cc:1079] T f7f6d6abdccf4972b6ec24f38dceb108 P ecbe51cc6fec4d8e9c9676f4c32a1114: Deleting log segment in path: /tmp/dist-test-taskttNqZw/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515446340069-13589-0/minicluster-data/ts-0-root/wals/f7f6d6abdccf4972b6ec24f38dceb108/wal-000000030 (ops 142-146)
I20260812 06:17:36.099841 14128 log.cc:1079] T f7f6d6abdccf4972b6ec24f38dceb108 P ecbe51cc6fec4d8e9c9676f4c32a1114: Deleting log segment in path: /tmp/dist-test-taskttNqZw/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515446340069-13589-0/minicluster-data/ts-0-root/wals/f7f6d6abdccf4972b6ec24f38dceb108/wal-000000031 (ops 147-151)
I20260812 06:17:36.099874 14128 log.cc:1079] T f7f6d6abdccf4972b6ec24f38dceb108 P ecbe51cc6fec4d8e9c9676f4c32a1114: Deleting log segment in path: /tmp/dist-test-taskttNqZw/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515446340069-13589-0/minicluster-data/ts-0-root/wals/f7f6d6abdccf4972b6ec24f38dceb108/wal-000000032 (ops 152-156)
I20260812 06:17:36.099907 14128 log.cc:1079] T f7f6d6abdccf4972b6ec24f38dceb108 P ecbe51cc6fec4d8e9c9676f4c32a1114: Deleting log segment in path: /tmp/dist-test-taskttNqZw/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515446340069-13589-0/minicluster-data/ts-0-root/wals/f7f6d6abdccf4972b6ec24f38dceb108/wal-000000033 (ops 157-161)
I20260812 06:17:36.099938 14128 log.cc:1079] T f7f6d6abdccf4972b6ec24f38dceb108 P ecbe51cc6fec4d8e9c9676f4c32a1114: Deleting log segment in path: /tmp/dist-test-taskttNqZw/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515446340069-13589-0/minicluster-data/ts-0-root/wals/f7f6d6abdccf4972b6ec24f38dceb108/wal-000000034 (ops 162-166)
I20260812 06:17:36.099972 14128 log.cc:1079] T f7f6d6abdccf4972b6ec24f38dceb108 P ecbe51cc6fec4d8e9c9676f4c32a1114: Deleting log segment in path: /tmp/dist-test-taskttNqZw/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515446340069-13589-0/minicluster-data/ts-0-root/wals/f7f6d6abdccf4972b6ec24f38dceb108/wal-000000035 (ops 167-171)
I20260812 06:17:36.100003 14128 log.cc:1079] T f7f6d6abdccf4972b6ec24f38dceb108 P ecbe51cc6fec4d8e9c9676f4c32a1114: Deleting log segment in path: /tmp/dist-test-taskttNqZw/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515446340069-13589-0/minicluster-data/ts-0-root/wals/f7f6d6abdccf4972b6ec24f38dceb108/wal-000000036 (ops 172-176)
I20260812 06:17:36.100034 14128 log.cc:1079] T f7f6d6abdccf4972b6ec24f38dceb108 P ecbe51cc6fec4d8e9c9676f4c32a1114: Deleting log segment in path: /tmp/dist-test-taskttNqZw/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515446340069-13589-0/minicluster-data/ts-0-root/wals/f7f6d6abdccf4972b6ec24f38dceb108/wal-000000037 (ops 177-180)
I20260812 06:17:36.100065 14128 log.cc:1079] T f7f6d6abdccf4972b6ec24f38dceb108 P ecbe51cc6fec4d8e9c9676f4c32a1114: Deleting log segment in path: /tmp/dist-test-taskttNqZw/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515446340069-13589-0/minicluster-data/ts-0-root/wals/f7f6d6abdccf4972b6ec24f38dceb108/wal-000000038 (ops 181-185)
I20260812 06:17:36.100097 14128 log.cc:1079] T f7f6d6abdccf4972b6ec24f38dceb108 P ecbe51cc6fec4d8e9c9676f4c32a1114: Deleting log segment in path: /tmp/dist-test-taskttNqZw/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515446340069-13589-0/minicluster-data/ts-0-root/wals/f7f6d6abdccf4972b6ec24f38dceb108/wal-000000039 (ops 186-190)
I20260812 06:17:36.118901 14128 maintenance_manager.cc:643] P ecbe51cc6fec4d8e9c9676f4c32a1114: LogGCOp(f7f6d6abdccf4972b6ec24f38dceb108) complete. Timing: real 0.019s	user 0.004s	sys 0.015s Metrics: {}
I20260812 06:17:36.119292 14224 maintenance_manager.cc:419] P ecbe51cc6fec4d8e9c9676f4c32a1114: Scheduling FlushDeltaMemStoresOp(f7f6d6abdccf4972b6ec24f38dceb108): perf score=2.188937
I20260812 06:17:36.137012 14128 maintenance_manager.cc:643] P ecbe51cc6fec4d8e9c9676f4c32a1114: FlushDeltaMemStoresOp(f7f6d6abdccf4972b6ec24f38dceb108) complete. Timing: real 0.018s	user 0.005s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4057,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:36.137449 14224 maintenance_manager.cc:419] P ecbe51cc6fec4d8e9c9676f4c32a1114: Scheduling FlushDeltaMemStoresOp(f7f6d6abdccf4972b6ec24f38dceb108): perf score=2.188937
I20260812 06:17:36.147146 14128 maintenance_manager.cc:643] P ecbe51cc6fec4d8e9c9676f4c32a1114: FlushDeltaMemStoresOp(f7f6d6abdccf4972b6ec24f38dceb108) complete. Timing: real 0.010s	user 0.008s	sys 0.001s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3696,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:36.147634 14224 maintenance_manager.cc:419] P ecbe51cc6fec4d8e9c9676f4c32a1114: Scheduling MajorDeltaCompactionOp(f7f6d6abdccf4972b6ec24f38dceb108): perf score=1.000000
I20260812 06:17:36.270651 13589 heavy-update-compaction-itest.cc:229] Time spent updating: real 4.331s	user 1.550s	sys 0.146s
I20260812 06:17:36.358649 13589 heavy-update-compaction-itest.cc:265] Time spent scanning: real 0.088s	user 0.004s	sys 0.000s
I20260812 06:17:36.358865 14128 maintenance_manager.cc:643] P ecbe51cc6fec4d8e9c9676f4c32a1114: MajorDeltaCompactionOp(f7f6d6abdccf4972b6ec24f38dceb108) complete. Timing: real 0.211s	user 0.126s	sys 0.085s Metrics: {"cfile_cache_miss":734,"cfile_cache_miss_bytes":33061716,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":180,"lbm_read_time_us":15988,"lbm_reads_lt_1ms":770,"lbm_write_time_us":31244,"lbm_writes_lt_1ms":743,"mutex_wait_us":27,"peak_mem_usage":87969044,"reinsert_count":0,"spinlock_wait_cycles":9216,"thread_start_us":92,"threads_started":1,"update_count":3500}
I20260812 06:17:36.359237 13589 tablet_server.cc:179] TabletServer@127.13.69.65:0 shutting down...
I20260812 06:17:36.359584 14224 maintenance_manager.cc:419] P ecbe51cc6fec4d8e9c9676f4c32a1114: Scheduling UndoDeltaBlockGCOp(f7f6d6abdccf4972b6ec24f38dceb108): 462 bytes on disk
I20260812 06:17:36.360051 14128 maintenance_manager.cc:643] P ecbe51cc6fec4d8e9c9676f4c32a1114: UndoDeltaBlockGCOp(f7f6d6abdccf4972b6ec24f38dceb108) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":62,"lbm_reads_lt_1ms":4}
I20260812 06:17:36.360702 14224 maintenance_manager.cc:419] P ecbe51cc6fec4d8e9c9676f4c32a1114: Scheduling FlushDeltaMemStoresOp(f7f6d6abdccf4972b6ec24f38dceb108): perf score=10.126437
I20260812 06:17:36.387791 14128 maintenance_manager.cc:643] P ecbe51cc6fec4d8e9c9676f4c32a1114: FlushDeltaMemStoresOp(f7f6d6abdccf4972b6ec24f38dceb108) complete. Timing: real 0.027s	user 0.017s	sys 0.008s Metrics: {"bytes_written":12307489,"delete_count":0,"lbm_write_time_us":11832,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:17:36.388296 13589 ts_tablet_manager.cc:1507] Shutting down tablet manager...
I20260812 06:17:36.388505 13589 tablet_replica.cc:333] T f7f6d6abdccf4972b6ec24f38dceb108 P ecbe51cc6fec4d8e9c9676f4c32a1114: stopping tablet replica
I20260812 06:17:36.388624 13589 raft_consensus.cc:2243] T f7f6d6abdccf4972b6ec24f38dceb108 P ecbe51cc6fec4d8e9c9676f4c32a1114 [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:17:36.388787 13589 raft_consensus.cc:2272] T f7f6d6abdccf4972b6ec24f38dceb108 P ecbe51cc6fec4d8e9c9676f4c32a1114 [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:17:36.391822 13589 tablet_server.cc:196] TabletServer@127.13.69.65:0 shutdown complete.
I20260812 06:17:36.414773 13589 master.cc:562] Master@127.13.69.126:34083 shutting down...
I20260812 06:17:36.418680 13589 raft_consensus.cc:2243] T 00000000000000000000000000000000 P df9fcaf385f249768e920a99d2a17258 [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:17:36.418810 13589 raft_consensus.cc:2272] T 00000000000000000000000000000000 P df9fcaf385f249768e920a99d2a17258 [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:17:36.418856 13589 tablet_replica.cc:333] T 00000000000000000000000000000000 P df9fcaf385f249768e920a99d2a17258: stopping tablet replica
I20260812 06:17:36.430558 13589 master.cc:584] Master@127.13.69.126:34083 shutdown complete.
[       OK ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/1 (4740 ms)
[----------] 2 tests from EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy (10154 ms total)

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