[==========] 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:18:38.388926 32341 internal_mini_cluster.cc:156] Creating distributed mini masters. Addrs: 127.31.149.126:44019
I20260812 06:18:38.390249 32341 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:18:38.390935 32341 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:18:38.399287 32347 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:18:38.399358 32346 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:18:38.399426 32349 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:18:38.399646 32341 server_base.cc:1061] running on GCE node
I20260812 06:18:38.400180 32341 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:18:38.400322 32341 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:18:38.400399 32341 hybrid_clock.cc:648] HybridClock initialized: now 1786515518400395 us; error 0 us; skew 500 ppm
I20260812 06:18:38.402642 32341 webserver.cc:533] Webserver started at http://127.31.149.126:35395/ using document root <none> and password file <none>
I20260812 06:18:38.403258 32341 fs_manager.cc:362] Metadata directory not provided
I20260812 06:18:38.403352 32341 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:18:38.403626 32341 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:18:38.405427 32341 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskchnxcB/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515518376868-32341-0/minicluster-data/master-0-root/instance:
uuid: "0bf776899ff541f8835efb2975e33980"
format_stamp: "Formatted at 2026-08-12 06:18:38 on dist-test-slave-rgb1"
I20260812 06:18:38.409307 32341 fs_manager.cc:696] Time spent creating directory manager: real 0.003s	user 0.004s	sys 0.000s
I20260812 06:18:38.411885 32354 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:18:38.413604 32341 fs_manager.cc:730] Time spent opening block manager: real 0.003s	user 0.003s	sys 0.000s
I20260812 06:18:38.413987 32341 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskchnxcB/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515518376868-32341-0/minicluster-data/master-0-root
uuid: "0bf776899ff541f8835efb2975e33980"
format_stamp: "Formatted at 2026-08-12 06:18:38 on dist-test-slave-rgb1"
I20260812 06:18:38.414176 32341 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskchnxcB/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515518376868-32341-0/minicluster-data/master-0-root
metadata directory: /tmp/dist-test-taskchnxcB/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515518376868-32341-0/minicluster-data/master-0-root
1 data directories: /tmp/dist-test-taskchnxcB/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515518376868-32341-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:18:38.447873 32341 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:18:38.448684 32341 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:18:38.448892 32341 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:18:38.457659 32341 rpc_server.cc:307] RPC server started. Bound to: 127.31.149.126:44019
I20260812 06:18:38.457744 32413 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.31.149.126:44019 every 8 connection(s)
I20260812 06:18:38.460214 32414 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:18:38.466234 32414 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P 0bf776899ff541f8835efb2975e33980: Bootstrap starting.
I20260812 06:18:38.469120 32414 tablet_bootstrap.cc:654] T 00000000000000000000000000000000 P 0bf776899ff541f8835efb2975e33980: Neither blocks nor log segments found. Creating new log.
I20260812 06:18:38.470152 32414 log.cc:826] T 00000000000000000000000000000000 P 0bf776899ff541f8835efb2975e33980: Log is configured to *not* fsync() on all Append() calls
I20260812 06:18:38.473483 32414 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P 0bf776899ff541f8835efb2975e33980: No bootstrap required, opened a new log
I20260812 06:18:38.476639 32414 raft_consensus.cc:359] T 00000000000000000000000000000000 P 0bf776899ff541f8835efb2975e33980 [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "0bf776899ff541f8835efb2975e33980" member_type: VOTER }
I20260812 06:18:38.476851 32414 raft_consensus.cc:385] T 00000000000000000000000000000000 P 0bf776899ff541f8835efb2975e33980 [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:18:38.476907 32414 raft_consensus.cc:740] T 00000000000000000000000000000000 P 0bf776899ff541f8835efb2975e33980 [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: 0bf776899ff541f8835efb2975e33980, State: Initialized, Role: FOLLOWER
I20260812 06:18:38.477497 32414 consensus_queue.cc:260] T 00000000000000000000000000000000 P 0bf776899ff541f8835efb2975e33980 [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: "0bf776899ff541f8835efb2975e33980" member_type: VOTER }
I20260812 06:18:38.477646 32414 raft_consensus.cc:399] T 00000000000000000000000000000000 P 0bf776899ff541f8835efb2975e33980 [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:18:38.477699 32414 raft_consensus.cc:493] T 00000000000000000000000000000000 P 0bf776899ff541f8835efb2975e33980 [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:18:38.477797 32414 raft_consensus.cc:3060] T 00000000000000000000000000000000 P 0bf776899ff541f8835efb2975e33980 [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:18:38.478766 32414 raft_consensus.cc:515] T 00000000000000000000000000000000 P 0bf776899ff541f8835efb2975e33980 [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "0bf776899ff541f8835efb2975e33980" member_type: VOTER }
I20260812 06:18:38.479212 32414 leader_election.cc:304] T 00000000000000000000000000000000 P 0bf776899ff541f8835efb2975e33980 [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: 0bf776899ff541f8835efb2975e33980; no voters: 
I20260812 06:18:38.479516 32414 leader_election.cc:290] T 00000000000000000000000000000000 P 0bf776899ff541f8835efb2975e33980 [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:18:38.479696 32417 raft_consensus.cc:2804] T 00000000000000000000000000000000 P 0bf776899ff541f8835efb2975e33980 [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:18:38.480008 32417 raft_consensus.cc:697] T 00000000000000000000000000000000 P 0bf776899ff541f8835efb2975e33980 [term 1 LEADER]: Becoming Leader. State: Replica: 0bf776899ff541f8835efb2975e33980, State: Running, Role: LEADER
I20260812 06:18:38.480430 32417 consensus_queue.cc:237] T 00000000000000000000000000000000 P 0bf776899ff541f8835efb2975e33980 [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: "0bf776899ff541f8835efb2975e33980" member_type: VOTER }
I20260812 06:18:38.480716 32414 sys_catalog.cc:565] T 00000000000000000000000000000000 P 0bf776899ff541f8835efb2975e33980 [sys.catalog]: configured and running, proceeding with master startup.
I20260812 06:18:38.482622 32418 sys_catalog.cc:455] T 00000000000000000000000000000000 P 0bf776899ff541f8835efb2975e33980 [sys.catalog]: SysCatalogTable state changed. Reason: RaftConsensus started. Latest consensus state: current_term: 1 leader_uuid: "0bf776899ff541f8835efb2975e33980" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "0bf776899ff541f8835efb2975e33980" member_type: VOTER } }
I20260812 06:18:38.482666 32419 sys_catalog.cc:455] T 00000000000000000000000000000000 P 0bf776899ff541f8835efb2975e33980 [sys.catalog]: SysCatalogTable state changed. Reason: New leader 0bf776899ff541f8835efb2975e33980. Latest consensus state: current_term: 1 leader_uuid: "0bf776899ff541f8835efb2975e33980" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "0bf776899ff541f8835efb2975e33980" member_type: VOTER } }
I20260812 06:18:38.482779 32418 sys_catalog.cc:458] T 00000000000000000000000000000000 P 0bf776899ff541f8835efb2975e33980 [sys.catalog]: This master's current role is: LEADER
I20260812 06:18:38.482779 32419 sys_catalog.cc:458] T 00000000000000000000000000000000 P 0bf776899ff541f8835efb2975e33980 [sys.catalog]: This master's current role is: LEADER
I20260812 06:18:38.483173 32430 catalog_manager.cc:1511] Loading table and tablet metadata into memory...
I20260812 06:18:38.483318 32341 internal_mini_cluster.cc:184] Waiting to initialize catalog manager on master 0
I20260812 06:18:38.486186 32430 catalog_manager.cc:1520] Initializing Kudu cluster ID...
I20260812 06:18:38.491577 32430 catalog_manager.cc:1383] Generated new cluster ID: 106d359d5e674dbe8a647fc8d0c0b0a5
I20260812 06:18:38.491761 32430 catalog_manager.cc:1531] Initializing Kudu internal certificate authority...
I20260812 06:18:38.501585 32430 catalog_manager.cc:1406] Generated new certificate authority record
I20260812 06:18:38.502673 32430 catalog_manager.cc:1540] Loading token signing keys...
I20260812 06:18:38.513033 32430 catalog_manager.cc:6092] T 00000000000000000000000000000000 P 0bf776899ff541f8835efb2975e33980: Generated new TSK 0
I20260812 06:18:38.514117 32430 catalog_manager.cc:1550] Initializing in-progress tserver states...
I20260812 06:18:38.516350 32341 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:18:38.520344 32440 instance_detector.cc:116] could not retrieve OpenStack instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:18:38.520339 32437 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:18:38.520648 32438 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:18:38.520660 32341 server_base.cc:1061] running on GCE node
I20260812 06:18:38.520961 32341 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:18:38.521008 32341 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:18:38.521024 32341 hybrid_clock.cc:648] HybridClock initialized: now 1786515518521024 us; error 0 us; skew 500 ppm
I20260812 06:18:38.522027 32341 webserver.cc:533] Webserver started at http://127.31.149.65:40819/ using document root <none> and password file <none>
I20260812 06:18:38.522233 32341 fs_manager.cc:362] Metadata directory not provided
I20260812 06:18:38.522287 32341 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:18:38.522459 32341 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:18:38.522943 32341 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskchnxcB/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515518376868-32341-0/minicluster-data/ts-0-root/instance:
uuid: "6a064629f15d4284adc23539cabd9f2a"
format_stamp: "Formatted at 2026-08-12 06:18:38 on dist-test-slave-rgb1"
I20260812 06:18:38.524674 32341 fs_manager.cc:696] Time spent creating directory manager: real 0.001s	user 0.002s	sys 0.000s
I20260812 06:18:38.525826 32447 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:18:38.526144 32341 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.001s	sys 0.000s
I20260812 06:18:38.526245 32341 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskchnxcB/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515518376868-32341-0/minicluster-data/ts-0-root
uuid: "6a064629f15d4284adc23539cabd9f2a"
format_stamp: "Formatted at 2026-08-12 06:18:38 on dist-test-slave-rgb1"
I20260812 06:18:38.526343 32341 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskchnxcB/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515518376868-32341-0/minicluster-data/ts-0-root
metadata directory: /tmp/dist-test-taskchnxcB/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515518376868-32341-0/minicluster-data/ts-0-root
1 data directories: /tmp/dist-test-taskchnxcB/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515518376868-32341-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:18:38.550467 32341 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:18:38.551074 32341 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:18:38.551647 32341 txn_system_client.cc:432] TxnSystemClient initialization is disabled...
I20260812 06:18:38.552542 32341 ts_tablet_manager.cc:585] Loaded tablet metadata (0 total tablets, 0 live tablets)
I20260812 06:18:38.552656 32341 ts_tablet_manager.cc:531] Time spent load tablet metadata: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:18:38.552738 32341 ts_tablet_manager.cc:616] Registered 0 tablets
I20260812 06:18:38.552776 32341 ts_tablet_manager.cc:595] Time spent register tablets: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:18:38.561093 32341 rpc_server.cc:307] RPC server started. Bound to: 127.31.149.65:35459
I20260812 06:18:38.561156 32519 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.31.149.65:35459 every 8 connection(s)
I20260812 06:18:38.574239 32520 heartbeater.cc:344] Connected to a master server at 127.31.149.126:44019
I20260812 06:18:38.574553 32520 heartbeater.cc:461] Registering TS with master...
I20260812 06:18:38.575106 32520 heartbeater.cc:507] Master 127.31.149.126:44019 requested a full tablet report, sending...
I20260812 06:18:38.577389 32371 ts_manager.cc:194] Registered new tserver with Master: 6a064629f15d4284adc23539cabd9f2a (127.31.149.65:35459)
I20260812 06:18:38.577455 32341 internal_mini_cluster.cc:371] 1 TS(s) registered with all masters after 0.015567366s
I20260812 06:18:38.579025 32371 master_service.cc:502] Signed X509 certificate for tserver {username='slave'} at 127.0.0.1:39508
I20260812 06:18:38.590835 32371 catalog_manager.cc:2283] Servicing CreateTable request from {username='slave'} at 127.0.0.1:39524:
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:18:38.609560 32479 tablet_service.cc:1511] Processing CreateTablet for tablet bef69f4bfe7c403d8ed967b9ddb2b1b5 (DEFAULT_TABLE table=heavy-update-compaction-test [id=ff54bdbd2d45436884b12de50b7d02e3]), partition=
I20260812 06:18:38.610096 32479 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet bef69f4bfe7c403d8ed967b9ddb2b1b5. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:18:38.613730 32532 tablet_bootstrap.cc:492] T bef69f4bfe7c403d8ed967b9ddb2b1b5 P 6a064629f15d4284adc23539cabd9f2a: Bootstrap starting.
I20260812 06:18:38.614842 32532 tablet_bootstrap.cc:654] T bef69f4bfe7c403d8ed967b9ddb2b1b5 P 6a064629f15d4284adc23539cabd9f2a: Neither blocks nor log segments found. Creating new log.
I20260812 06:18:38.616683 32532 tablet_bootstrap.cc:492] T bef69f4bfe7c403d8ed967b9ddb2b1b5 P 6a064629f15d4284adc23539cabd9f2a: No bootstrap required, opened a new log
I20260812 06:18:38.616899 32532 ts_tablet_manager.cc:1403] T bef69f4bfe7c403d8ed967b9ddb2b1b5 P 6a064629f15d4284adc23539cabd9f2a: Time spent bootstrapping tablet: real 0.003s	user 0.003s	sys 0.000s
I20260812 06:18:38.617573 32532 raft_consensus.cc:359] T bef69f4bfe7c403d8ed967b9ddb2b1b5 P 6a064629f15d4284adc23539cabd9f2a [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "6a064629f15d4284adc23539cabd9f2a" member_type: VOTER last_known_addr { host: "127.31.149.65" port: 35459 } }
I20260812 06:18:38.617935 32532 raft_consensus.cc:385] T bef69f4bfe7c403d8ed967b9ddb2b1b5 P 6a064629f15d4284adc23539cabd9f2a [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:18:38.618057 32532 raft_consensus.cc:740] T bef69f4bfe7c403d8ed967b9ddb2b1b5 P 6a064629f15d4284adc23539cabd9f2a [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: 6a064629f15d4284adc23539cabd9f2a, State: Initialized, Role: FOLLOWER
I20260812 06:18:38.618281 32532 consensus_queue.cc:260] T bef69f4bfe7c403d8ed967b9ddb2b1b5 P 6a064629f15d4284adc23539cabd9f2a [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: "6a064629f15d4284adc23539cabd9f2a" member_type: VOTER last_known_addr { host: "127.31.149.65" port: 35459 } }
I20260812 06:18:38.618502 32532 raft_consensus.cc:399] T bef69f4bfe7c403d8ed967b9ddb2b1b5 P 6a064629f15d4284adc23539cabd9f2a [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:18:38.618587 32532 raft_consensus.cc:493] T bef69f4bfe7c403d8ed967b9ddb2b1b5 P 6a064629f15d4284adc23539cabd9f2a [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:18:38.618660 32532 raft_consensus.cc:3060] T bef69f4bfe7c403d8ed967b9ddb2b1b5 P 6a064629f15d4284adc23539cabd9f2a [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:18:38.619715 32532 raft_consensus.cc:515] T bef69f4bfe7c403d8ed967b9ddb2b1b5 P 6a064629f15d4284adc23539cabd9f2a [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "6a064629f15d4284adc23539cabd9f2a" member_type: VOTER last_known_addr { host: "127.31.149.65" port: 35459 } }
I20260812 06:18:38.619913 32532 leader_election.cc:304] T bef69f4bfe7c403d8ed967b9ddb2b1b5 P 6a064629f15d4284adc23539cabd9f2a [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: 6a064629f15d4284adc23539cabd9f2a; no voters: 
I20260812 06:18:38.620215 32532 leader_election.cc:290] T bef69f4bfe7c403d8ed967b9ddb2b1b5 P 6a064629f15d4284adc23539cabd9f2a [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:18:38.620352 32534 raft_consensus.cc:2804] T bef69f4bfe7c403d8ed967b9ddb2b1b5 P 6a064629f15d4284adc23539cabd9f2a [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:18:38.620601 32534 raft_consensus.cc:697] T bef69f4bfe7c403d8ed967b9ddb2b1b5 P 6a064629f15d4284adc23539cabd9f2a [term 1 LEADER]: Becoming Leader. State: Replica: 6a064629f15d4284adc23539cabd9f2a, State: Running, Role: LEADER
I20260812 06:18:38.620769 32532 ts_tablet_manager.cc:1434] T bef69f4bfe7c403d8ed967b9ddb2b1b5 P 6a064629f15d4284adc23539cabd9f2a: Time spent starting tablet: real 0.004s	user 0.004s	sys 0.000s
I20260812 06:18:38.620858 32534 consensus_queue.cc:237] T bef69f4bfe7c403d8ed967b9ddb2b1b5 P 6a064629f15d4284adc23539cabd9f2a [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: "6a064629f15d4284adc23539cabd9f2a" member_type: VOTER last_known_addr { host: "127.31.149.65" port: 35459 } }
I20260812 06:18:38.621680 32520 heartbeater.cc:499] Master 127.31.149.126:44019 was elected leader, sending a full tablet report...
I20260812 06:18:38.624675 32371 catalog_manager.cc:5719] T bef69f4bfe7c403d8ed967b9ddb2b1b5 P 6a064629f15d4284adc23539cabd9f2a reported cstate change: term changed from 0 to 1, leader changed from <none> to 6a064629f15d4284adc23539cabd9f2a (127.31.149.65). New cstate: current_term: 1 leader_uuid: "6a064629f15d4284adc23539cabd9f2a" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "6a064629f15d4284adc23539cabd9f2a" member_type: VOTER last_known_addr { host: "127.31.149.65" port: 35459 } health_report { overall_health: HEALTHY } } }
I20260812 06:18:38.696776 32341 heavy-update-compaction-itest.cc:215] Time spent inserting: real 0.066s	user 0.014s	sys 0.016s
I20260812 06:18:38.812507 32521 maintenance_manager.cc:419] P 6a064629f15d4284adc23539cabd9f2a: Scheduling FlushMRSOp(bef69f4bfe7c403d8ed967b9ddb2b1b5): perf score=11.117440
I20260812 06:18:38.978511 32453 maintenance_manager.cc:643] P 6a064629f15d4284adc23539cabd9f2a: FlushMRSOp(bef69f4bfe7c403d8ed967b9ddb2b1b5) complete. Timing: real 0.166s	user 0.115s	sys 0.042s Metrics: {"bytes_written":8615323,"cfile_init":1,"compiler_manager_pool.queue_time_us":284,"delete_count":0,"dirs.queue_time_us":89,"dirs.run_cpu_time_us":273,"dirs.run_wall_time_us":1056,"drs_written":1,"lbm_read_time_us":87,"lbm_reads_lt_1ms":4,"lbm_write_time_us":36073,"lbm_writes_lt_1ms":567,"peak_mem_usage":0,"reinsert_count":0,"rows_written":103,"spinlock_wait_cycles":178560,"thread_start_us":143,"threads_started":1,"update_count":1050}
I20260812 06:18:38.979787 32521 maintenance_manager.cc:419] P 6a064629f15d4284adc23539cabd9f2a: Scheduling LogGCOp(bef69f4bfe7c403d8ed967b9ddb2b1b5): free 11976772 bytes of WAL
I20260812 06:18:38.980249 32453 log_reader.cc:385] T bef69f4bfe7c403d8ed967b9ddb2b1b5: removed 1 log segments from log reader
I20260812 06:18:38.980367 32453 log.cc:1079] T bef69f4bfe7c403d8ed967b9ddb2b1b5 P 6a064629f15d4284adc23539cabd9f2a: Deleting log segment in path: /tmp/dist-test-taskchnxcB/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515518376868-32341-0/minicluster-data/ts-0-root/wals/bef69f4bfe7c403d8ed967b9ddb2b1b5/wal-000000001 (ops 1-6)
I20260812 06:18:38.984470 32453 maintenance_manager.cc:643] P 6a064629f15d4284adc23539cabd9f2a: LogGCOp(bef69f4bfe7c403d8ed967b9ddb2b1b5) complete. Timing: real 0.004s	user 0.003s	sys 0.000s Metrics: {}
I20260812 06:18:38.984977 32521 maintenance_manager.cc:419] P 6a064629f15d4284adc23539cabd9f2a: Scheduling FlushDeltaMemStoresOp(bef69f4bfe7c403d8ed967b9ddb2b1b5): perf score=2.188937
I20260812 06:18:38.998268 32453 maintenance_manager.cc:643] P 6a064629f15d4284adc23539cabd9f2a: FlushDeltaMemStoresOp(bef69f4bfe7c403d8ed967b9ddb2b1b5) complete. Timing: real 0.013s	user 0.008s	sys 0.004s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":4774,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:18:38.998802 32521 maintenance_manager.cc:419] P 6a064629f15d4284adc23539cabd9f2a: Scheduling UndoDeltaBlockGCOp(bef69f4bfe7c403d8ed967b9ddb2b1b5): 12308958 bytes on disk
I20260812 06:18:38.999557 32453 maintenance_manager.cc:643] P 6a064629f15d4284adc23539cabd9f2a: UndoDeltaBlockGCOp(bef69f4bfe7c403d8ed967b9ddb2b1b5) complete. Timing: real 0.001s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":78,"lbm_reads_lt_1ms":4}
I20260812 06:18:39.000360 32521 maintenance_manager.cc:419] P 6a064629f15d4284adc23539cabd9f2a: Scheduling MajorDeltaCompactionOp(bef69f4bfe7c403d8ed967b9ddb2b1b5): perf score=1.000000
I20260812 06:18:39.127418 32453 maintenance_manager.cc:643] P 6a064629f15d4284adc23539cabd9f2a: MajorDeltaCompactionOp(bef69f4bfe7c403d8ed967b9ddb2b1b5) complete. Timing: real 0.127s	user 0.106s	sys 0.020s Metrics: {"cfile_cache_miss":332,"cfile_cache_miss_bytes":16528891,"cfile_init":7,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":532,"lbm_read_time_us":7231,"lbm_reads_lt_1ms":360,"lbm_write_time_us":21904,"lbm_writes_lt_1ms":343,"peak_mem_usage":38262756,"reinsert_count":0,"spinlock_wait_cycles":2816,"thread_start_us":315,"threads_started":5,"update_count":1500}
I20260812 06:18:39.128085 32521 maintenance_manager.cc:419] P 6a064629f15d4284adc23539cabd9f2a: Scheduling FlushDeltaMemStoresOp(bef69f4bfe7c403d8ed967b9ddb2b1b5): perf score=6.157687
I20260812 06:18:39.162658 32453 maintenance_manager.cc:643] P 6a064629f15d4284adc23539cabd9f2a: FlushDeltaMemStoresOp(bef69f4bfe7c403d8ed967b9ddb2b1b5) complete. Timing: real 0.034s	user 0.018s	sys 0.008s Metrics: {"bytes_written":8205078,"delete_count":0,"lbm_write_time_us":11982,"lbm_writes_lt_1ms":203,"reinsert_count":0,"update_count":1000}
I20260812 06:18:39.163269 32521 maintenance_manager.cc:419] P 6a064629f15d4284adc23539cabd9f2a: Scheduling FlushDeltaMemStoresOp(bef69f4bfe7c403d8ed967b9ddb2b1b5): perf score=2.188937
I20260812 06:18:39.174886 32453 maintenance_manager.cc:643] P 6a064629f15d4284adc23539cabd9f2a: FlushDeltaMemStoresOp(bef69f4bfe7c403d8ed967b9ddb2b1b5) complete. Timing: real 0.011s	user 0.007s	sys 0.003s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4673,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:39.175490 32521 maintenance_manager.cc:419] P 6a064629f15d4284adc23539cabd9f2a: Scheduling MajorDeltaCompactionOp(bef69f4bfe7c403d8ed967b9ddb2b1b5): perf score=1.000000
I20260812 06:18:39.300048 32453 maintenance_manager.cc:643] P 6a064629f15d4284adc23539cabd9f2a: MajorDeltaCompactionOp(bef69f4bfe7c403d8ed967b9ddb2b1b5) complete. Timing: real 0.124s	user 0.099s	sys 0.017s Metrics: {"cfile_cache_miss":332,"cfile_cache_miss_bytes":16528900,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":557,"lbm_read_time_us":8545,"lbm_reads_lt_1ms":372,"lbm_write_time_us":19279,"lbm_writes_lt_1ms":343,"mutex_wait_us":208,"peak_mem_usage":38262756,"reinsert_count":0,"spinlock_wait_cycles":185984,"update_count":1500}
I20260812 06:18:39.300773 32521 maintenance_manager.cc:419] P 6a064629f15d4284adc23539cabd9f2a: Scheduling FlushDeltaMemStoresOp(bef69f4bfe7c403d8ed967b9ddb2b1b5): perf score=10.126437
I20260812 06:18:39.356208 32453 maintenance_manager.cc:643] P 6a064629f15d4284adc23539cabd9f2a: FlushDeltaMemStoresOp(bef69f4bfe7c403d8ed967b9ddb2b1b5) complete. Timing: real 0.055s	user 0.017s	sys 0.029s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":22102,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":302,"reinsert_count":0,"update_count":1500}
I20260812 06:18:39.356835 32521 maintenance_manager.cc:419] P 6a064629f15d4284adc23539cabd9f2a: Scheduling FlushDeltaMemStoresOp(bef69f4bfe7c403d8ed967b9ddb2b1b5): perf score=2.188937
I20260812 06:18:39.371678 32453 maintenance_manager.cc:643] P 6a064629f15d4284adc23539cabd9f2a: FlushDeltaMemStoresOp(bef69f4bfe7c403d8ed967b9ddb2b1b5) complete. Timing: real 0.015s	user 0.002s	sys 0.009s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5975,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":102,"reinsert_count":0,"update_count":500}
I20260812 06:18:39.372435 32521 maintenance_manager.cc:419] P 6a064629f15d4284adc23539cabd9f2a: Scheduling MajorDeltaCompactionOp(bef69f4bfe7c403d8ed967b9ddb2b1b5): perf score=1.000000
I20260812 06:18:39.507723 32453 maintenance_manager.cc:643] P 6a064629f15d4284adc23539cabd9f2a: MajorDeltaCompactionOp(bef69f4bfe7c403d8ed967b9ddb2b1b5) complete. Timing: real 0.135s	user 0.092s	sys 0.040s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20631312,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":322,"lbm_read_time_us":10400,"lbm_reads_lt_1ms":472,"lbm_write_time_us":24860,"lbm_writes_lt_1ms":443,"mutex_wait_us":2,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":15744,"update_count":2000}
I20260812 06:18:39.508373 32521 maintenance_manager.cc:419] P 6a064629f15d4284adc23539cabd9f2a: Scheduling FlushDeltaMemStoresOp(bef69f4bfe7c403d8ed967b9ddb2b1b5): perf score=10.126437
I20260812 06:18:39.562580 32453 maintenance_manager.cc:643] P 6a064629f15d4284adc23539cabd9f2a: FlushDeltaMemStoresOp(bef69f4bfe7c403d8ed967b9ddb2b1b5) complete. Timing: real 0.054s	user 0.037s	sys 0.009s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":23362,"lbm_writes_1-10_ms":2,"lbm_writes_lt_1ms":301,"reinsert_count":0,"update_count":1500}
I20260812 06:18:39.563127 32521 maintenance_manager.cc:419] P 6a064629f15d4284adc23539cabd9f2a: Scheduling FlushDeltaMemStoresOp(bef69f4bfe7c403d8ed967b9ddb2b1b5): perf score=2.188937
I20260812 06:18:39.574847 32453 maintenance_manager.cc:643] P 6a064629f15d4284adc23539cabd9f2a: FlushDeltaMemStoresOp(bef69f4bfe7c403d8ed967b9ddb2b1b5) complete. Timing: real 0.012s	user 0.006s	sys 0.004s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4389,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:39.576179 32521 maintenance_manager.cc:419] P 6a064629f15d4284adc23539cabd9f2a: Scheduling MajorDeltaCompactionOp(bef69f4bfe7c403d8ed967b9ddb2b1b5): perf score=1.000000
I20260812 06:18:39.720873 32453 maintenance_manager.cc:643] P 6a064629f15d4284adc23539cabd9f2a: MajorDeltaCompactionOp(bef69f4bfe7c403d8ed967b9ddb2b1b5) complete. Timing: real 0.144s	user 0.102s	sys 0.040s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20631311,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":2198,"lbm_read_time_us":9514,"lbm_reads_lt_1ms":472,"lbm_write_time_us":29273,"lbm_writes_lt_1ms":443,"mutex_wait_us":1933,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":1408,"update_count":2000}
I20260812 06:18:39.722138 32521 maintenance_manager.cc:419] P 6a064629f15d4284adc23539cabd9f2a: Scheduling FlushDeltaMemStoresOp(bef69f4bfe7c403d8ed967b9ddb2b1b5): perf score=10.126437
I20260812 06:18:39.768748 32453 maintenance_manager.cc:643] P 6a064629f15d4284adc23539cabd9f2a: FlushDeltaMemStoresOp(bef69f4bfe7c403d8ed967b9ddb2b1b5) complete. Timing: real 0.046s	user 0.024s	sys 0.020s Metrics: {"bytes_written":12307489,"delete_count":0,"lbm_write_time_us":19738,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:18:39.769219 32521 maintenance_manager.cc:419] P 6a064629f15d4284adc23539cabd9f2a: Scheduling FlushDeltaMemStoresOp(bef69f4bfe7c403d8ed967b9ddb2b1b5): perf score=2.188937
I20260812 06:18:39.780057 32453 maintenance_manager.cc:643] P 6a064629f15d4284adc23539cabd9f2a: FlushDeltaMemStoresOp(bef69f4bfe7c403d8ed967b9ddb2b1b5) complete. Timing: real 0.011s	user 0.001s	sys 0.008s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4194,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:39.780678 32521 maintenance_manager.cc:419] P 6a064629f15d4284adc23539cabd9f2a: Scheduling MajorDeltaCompactionOp(bef69f4bfe7c403d8ed967b9ddb2b1b5): perf score=1.000000
I20260812 06:18:39.913074 32453 maintenance_manager.cc:643] P 6a064629f15d4284adc23539cabd9f2a: MajorDeltaCompactionOp(bef69f4bfe7c403d8ed967b9ddb2b1b5) complete. Timing: real 0.132s	user 0.098s	sys 0.029s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20631310,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":380,"lbm_read_time_us":8662,"lbm_reads_lt_1ms":472,"lbm_write_time_us":25821,"lbm_writes_lt_1ms":443,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":1280,"update_count":2000}
I20260812 06:18:39.913564 32521 maintenance_manager.cc:419] P 6a064629f15d4284adc23539cabd9f2a: Scheduling FlushDeltaMemStoresOp(bef69f4bfe7c403d8ed967b9ddb2b1b5): perf score=10.126437
I20260812 06:18:39.958113 32453 maintenance_manager.cc:643] P 6a064629f15d4284adc23539cabd9f2a: FlushDeltaMemStoresOp(bef69f4bfe7c403d8ed967b9ddb2b1b5) complete. Timing: real 0.044s	user 0.026s	sys 0.016s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":17041,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:18:39.958881 32521 maintenance_manager.cc:419] P 6a064629f15d4284adc23539cabd9f2a: Scheduling FlushDeltaMemStoresOp(bef69f4bfe7c403d8ed967b9ddb2b1b5): perf score=1.196750
I20260812 06:18:39.967592 32453 maintenance_manager.cc:643] P 6a064629f15d4284adc23539cabd9f2a: FlushDeltaMemStoresOp(bef69f4bfe7c403d8ed967b9ddb2b1b5) complete. Timing: real 0.009s	user 0.003s	sys 0.004s Metrics: {"bytes_written":2297558,"delete_count":0,"lbm_write_time_us":2781,"lbm_writes_lt_1ms":59,"reinsert_count":0,"update_count":280}
I20260812 06:18:39.968303 32521 maintenance_manager.cc:419] P 6a064629f15d4284adc23539cabd9f2a: Scheduling FlushDeltaMemStoresOp(bef69f4bfe7c403d8ed967b9ddb2b1b5): perf score=1.000000
I20260812 06:18:39.975240 32453 maintenance_manager.cc:643] P 6a064629f15d4284adc23539cabd9f2a: FlushDeltaMemStoresOp(bef69f4bfe7c403d8ed967b9ddb2b1b5) complete. Timing: real 0.007s	user 0.005s	sys 0.000s Metrics: {"bytes_written":1805252,"delete_count":0,"lbm_write_time_us":2196,"lbm_writes_lt_1ms":47,"reinsert_count":0,"update_count":220}
I20260812 06:18:39.975752 32521 maintenance_manager.cc:419] P 6a064629f15d4284adc23539cabd9f2a: Scheduling MajorDeltaCompactionOp(bef69f4bfe7c403d8ed967b9ddb2b1b5): perf score=1.000000
I20260812 06:18:40.137555 32453 maintenance_manager.cc:643] P 6a064629f15d4284adc23539cabd9f2a: MajorDeltaCompactionOp(bef69f4bfe7c403d8ed967b9ddb2b1b5) complete. Timing: real 0.162s	user 0.145s	sys 0.011s Metrics: {"cfile_cache_miss":433,"cfile_cache_miss_bytes":20631336,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":790,"lbm_read_time_us":10181,"lbm_reads_lt_1ms":473,"lbm_write_time_us":28429,"lbm_writes_lt_1ms":443,"mutex_wait_us":304,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":3456,"update_count":2000}
I20260812 06:18:40.138304 32521 maintenance_manager.cc:419] P 6a064629f15d4284adc23539cabd9f2a: Scheduling FlushDeltaMemStoresOp(bef69f4bfe7c403d8ed967b9ddb2b1b5): perf score=10.126437
I20260812 06:18:40.189864 32453 maintenance_manager.cc:643] P 6a064629f15d4284adc23539cabd9f2a: FlushDeltaMemStoresOp(bef69f4bfe7c403d8ed967b9ddb2b1b5) complete. Timing: real 0.051s	user 0.022s	sys 0.016s Metrics: {"bytes_written":12307491,"delete_count":0,"lbm_write_time_us":17446,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:18:40.190346 32521 maintenance_manager.cc:419] P 6a064629f15d4284adc23539cabd9f2a: Scheduling FlushDeltaMemStoresOp(bef69f4bfe7c403d8ed967b9ddb2b1b5): perf score=2.188937
I20260812 06:18:40.201638 32453 maintenance_manager.cc:643] P 6a064629f15d4284adc23539cabd9f2a: FlushDeltaMemStoresOp(bef69f4bfe7c403d8ed967b9ddb2b1b5) complete. Timing: real 0.011s	user 0.006s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4199,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:40.202327 32521 maintenance_manager.cc:419] P 6a064629f15d4284adc23539cabd9f2a: Scheduling MajorDeltaCompactionOp(bef69f4bfe7c403d8ed967b9ddb2b1b5): perf score=1.000000
I20260812 06:18:40.336624 32453 maintenance_manager.cc:643] P 6a064629f15d4284adc23539cabd9f2a: MajorDeltaCompactionOp(bef69f4bfe7c403d8ed967b9ddb2b1b5) complete. Timing: real 0.134s	user 0.091s	sys 0.043s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20631313,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":266,"lbm_read_time_us":8467,"lbm_reads_lt_1ms":472,"lbm_write_time_us":26902,"lbm_writes_lt_1ms":443,"mutex_wait_us":18,"peak_mem_usage":50689328,"reinsert_count":0,"update_count":2000}
I20260812 06:18:40.337312 32521 maintenance_manager.cc:419] P 6a064629f15d4284adc23539cabd9f2a: Scheduling FlushDeltaMemStoresOp(bef69f4bfe7c403d8ed967b9ddb2b1b5): perf score=10.126437
I20260812 06:18:40.375190 32453 maintenance_manager.cc:643] P 6a064629f15d4284adc23539cabd9f2a: FlushDeltaMemStoresOp(bef69f4bfe7c403d8ed967b9ddb2b1b5) complete. Timing: real 0.038s	user 0.023s	sys 0.012s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":15512,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:18:40.375910 32521 maintenance_manager.cc:419] P 6a064629f15d4284adc23539cabd9f2a: Scheduling FlushDeltaMemStoresOp(bef69f4bfe7c403d8ed967b9ddb2b1b5): perf score=2.188937
I20260812 06:18:40.393262 32453 maintenance_manager.cc:643] P 6a064629f15d4284adc23539cabd9f2a: FlushDeltaMemStoresOp(bef69f4bfe7c403d8ed967b9ddb2b1b5) complete. Timing: real 0.017s	user 0.008s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6930,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:40.393800 32521 maintenance_manager.cc:419] P 6a064629f15d4284adc23539cabd9f2a: Scheduling FlushMRSOp(bef69f4bfe7c403d8ed967b9ddb2b1b5): perf score=1.000000
I20260812 06:18:40.449507 32453 maintenance_manager.cc:643] P 6a064629f15d4284adc23539cabd9f2a: FlushMRSOp(bef69f4bfe7c403d8ed967b9ddb2b1b5) complete. Timing: real 0.056s	user 0.026s	sys 0.005s Metrics: {"bytes_written":1275444,"cfile_init":1,"dirs.queue_time_us":103,"dirs.run_cpu_time_us":400,"dirs.run_wall_time_us":2391,"drs_written":1,"lbm_read_time_us":115,"lbm_reads_lt_1ms":4,"lbm_write_time_us":2325,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":31}
I20260812 06:18:40.450444 32521 maintenance_manager.cc:419] P 6a064629f15d4284adc23539cabd9f2a: Scheduling LogGCOp(bef69f4bfe7c403d8ed967b9ddb2b1b5): free 121006434 bytes of WAL
I20260812 06:18:40.450711 32453 log_reader.cc:385] T bef69f4bfe7c403d8ed967b9ddb2b1b5: removed 12 log segments from log reader
I20260812 06:18:40.450758 32453 log.cc:1079] T bef69f4bfe7c403d8ed967b9ddb2b1b5 P 6a064629f15d4284adc23539cabd9f2a: Deleting log segment in path: /tmp/dist-test-taskchnxcB/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515518376868-32341-0/minicluster-data/ts-0-root/wals/bef69f4bfe7c403d8ed967b9ddb2b1b5/wal-000000002 (ops 7-11)
I20260812 06:18:40.450816 32453 log.cc:1079] T bef69f4bfe7c403d8ed967b9ddb2b1b5 P 6a064629f15d4284adc23539cabd9f2a: Deleting log segment in path: /tmp/dist-test-taskchnxcB/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515518376868-32341-0/minicluster-data/ts-0-root/wals/bef69f4bfe7c403d8ed967b9ddb2b1b5/wal-000000003 (ops 12-16)
I20260812 06:18:40.450868 32453 log.cc:1079] T bef69f4bfe7c403d8ed967b9ddb2b1b5 P 6a064629f15d4284adc23539cabd9f2a: Deleting log segment in path: /tmp/dist-test-taskchnxcB/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515518376868-32341-0/minicluster-data/ts-0-root/wals/bef69f4bfe7c403d8ed967b9ddb2b1b5/wal-000000004 (ops 17-21)
I20260812 06:18:40.450942 32453 log.cc:1079] T bef69f4bfe7c403d8ed967b9ddb2b1b5 P 6a064629f15d4284adc23539cabd9f2a: Deleting log segment in path: /tmp/dist-test-taskchnxcB/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515518376868-32341-0/minicluster-data/ts-0-root/wals/bef69f4bfe7c403d8ed967b9ddb2b1b5/wal-000000005 (ops 22-26)
I20260812 06:18:40.450992 32453 log.cc:1079] T bef69f4bfe7c403d8ed967b9ddb2b1b5 P 6a064629f15d4284adc23539cabd9f2a: Deleting log segment in path: /tmp/dist-test-taskchnxcB/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515518376868-32341-0/minicluster-data/ts-0-root/wals/bef69f4bfe7c403d8ed967b9ddb2b1b5/wal-000000006 (ops 27-30)
I20260812 06:18:40.451033 32453 log.cc:1079] T bef69f4bfe7c403d8ed967b9ddb2b1b5 P 6a064629f15d4284adc23539cabd9f2a: Deleting log segment in path: /tmp/dist-test-taskchnxcB/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515518376868-32341-0/minicluster-data/ts-0-root/wals/bef69f4bfe7c403d8ed967b9ddb2b1b5/wal-000000007 (ops 31-35)
I20260812 06:18:40.451076 32453 log.cc:1079] T bef69f4bfe7c403d8ed967b9ddb2b1b5 P 6a064629f15d4284adc23539cabd9f2a: Deleting log segment in path: /tmp/dist-test-taskchnxcB/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515518376868-32341-0/minicluster-data/ts-0-root/wals/bef69f4bfe7c403d8ed967b9ddb2b1b5/wal-000000008 (ops 36-40)
I20260812 06:18:40.451128 32453 log.cc:1079] T bef69f4bfe7c403d8ed967b9ddb2b1b5 P 6a064629f15d4284adc23539cabd9f2a: Deleting log segment in path: /tmp/dist-test-taskchnxcB/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515518376868-32341-0/minicluster-data/ts-0-root/wals/bef69f4bfe7c403d8ed967b9ddb2b1b5/wal-000000009 (ops 41-45)
I20260812 06:18:40.451174 32453 log.cc:1079] T bef69f4bfe7c403d8ed967b9ddb2b1b5 P 6a064629f15d4284adc23539cabd9f2a: Deleting log segment in path: /tmp/dist-test-taskchnxcB/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515518376868-32341-0/minicluster-data/ts-0-root/wals/bef69f4bfe7c403d8ed967b9ddb2b1b5/wal-000000010 (ops 46-50)
I20260812 06:18:40.451216 32453 log.cc:1079] T bef69f4bfe7c403d8ed967b9ddb2b1b5 P 6a064629f15d4284adc23539cabd9f2a: Deleting log segment in path: /tmp/dist-test-taskchnxcB/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515518376868-32341-0/minicluster-data/ts-0-root/wals/bef69f4bfe7c403d8ed967b9ddb2b1b5/wal-000000011 (ops 51-55)
I20260812 06:18:40.451261 32453 log.cc:1079] T bef69f4bfe7c403d8ed967b9ddb2b1b5 P 6a064629f15d4284adc23539cabd9f2a: Deleting log segment in path: /tmp/dist-test-taskchnxcB/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515518376868-32341-0/minicluster-data/ts-0-root/wals/bef69f4bfe7c403d8ed967b9ddb2b1b5/wal-000000012 (ops 56-60)
I20260812 06:18:40.451308 32453 log.cc:1079] T bef69f4bfe7c403d8ed967b9ddb2b1b5 P 6a064629f15d4284adc23539cabd9f2a: Deleting log segment in path: /tmp/dist-test-taskchnxcB/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515518376868-32341-0/minicluster-data/ts-0-root/wals/bef69f4bfe7c403d8ed967b9ddb2b1b5/wal-000000013 (ops 61-65)
I20260812 06:18:40.480000 32453 maintenance_manager.cc:643] P 6a064629f15d4284adc23539cabd9f2a: LogGCOp(bef69f4bfe7c403d8ed967b9ddb2b1b5) complete. Timing: real 0.029s	user 0.000s	sys 0.026s Metrics: {}
I20260812 06:18:40.480537 32521 maintenance_manager.cc:419] P 6a064629f15d4284adc23539cabd9f2a: Scheduling FlushDeltaMemStoresOp(bef69f4bfe7c403d8ed967b9ddb2b1b5): perf score=7.149875
I20260812 06:18:40.506630 32453 maintenance_manager.cc:643] P 6a064629f15d4284adc23539cabd9f2a: FlushDeltaMemStoresOp(bef69f4bfe7c403d8ed967b9ddb2b1b5) complete. Timing: real 0.026s	user 0.018s	sys 0.006s Metrics: {"bytes_written":8615323,"delete_count":0,"lbm_write_time_us":10853,"lbm_writes_lt_1ms":213,"reinsert_count":0,"update_count":1050}
I20260812 06:18:40.507402 32521 maintenance_manager.cc:419] P 6a064629f15d4284adc23539cabd9f2a: Scheduling LogGCOp(bef69f4bfe7c403d8ed967b9ddb2b1b5): free 8767123 bytes of WAL
I20260812 06:18:40.507616 32453 log_reader.cc:385] T bef69f4bfe7c403d8ed967b9ddb2b1b5: removed 1 log segments from log reader
I20260812 06:18:40.507669 32453 log.cc:1079] T bef69f4bfe7c403d8ed967b9ddb2b1b5 P 6a064629f15d4284adc23539cabd9f2a: Deleting log segment in path: /tmp/dist-test-taskchnxcB/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515518376868-32341-0/minicluster-data/ts-0-root/wals/bef69f4bfe7c403d8ed967b9ddb2b1b5/wal-000000014 (ops 66-70)
I20260812 06:18:40.509521 32453 maintenance_manager.cc:643] P 6a064629f15d4284adc23539cabd9f2a: LogGCOp(bef69f4bfe7c403d8ed967b9ddb2b1b5) complete. Timing: real 0.002s	user 0.000s	sys 0.001s Metrics: {}
I20260812 06:18:40.509873 32521 maintenance_manager.cc:419] P 6a064629f15d4284adc23539cabd9f2a: Scheduling FlushDeltaMemStoresOp(bef69f4bfe7c403d8ed967b9ddb2b1b5): perf score=2.188937
I20260812 06:18:40.524922 32453 maintenance_manager.cc:643] P 6a064629f15d4284adc23539cabd9f2a: FlushDeltaMemStoresOp(bef69f4bfe7c403d8ed967b9ddb2b1b5) complete. Timing: real 0.015s	user 0.003s	sys 0.010s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":4901,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:18:40.525373 32521 maintenance_manager.cc:419] P 6a064629f15d4284adc23539cabd9f2a: Scheduling MajorDeltaCompactionOp(bef69f4bfe7c403d8ed967b9ddb2b1b5): perf score=1.000000
I20260812 06:18:40.726295 32453 maintenance_manager.cc:643] P 6a064629f15d4284adc23539cabd9f2a: MajorDeltaCompactionOp(bef69f4bfe7c403d8ed967b9ddb2b1b5) complete. Timing: real 0.201s	user 0.152s	sys 0.047s Metrics: {"cfile_cache_miss":734,"cfile_cache_miss_bytes":32938778,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":589,"lbm_read_time_us":13074,"lbm_reads_lt_1ms":770,"lbm_write_time_us":42554,"lbm_writes_lt_1ms":743,"mutex_wait_us":357,"peak_mem_usage":87969044,"reinsert_count":0,"thread_start_us":87,"threads_started":1,"update_count":3500}
I20260812 06:18:40.727031 32521 maintenance_manager.cc:419] P 6a064629f15d4284adc23539cabd9f2a: Scheduling UndoDeltaBlockGCOp(bef69f4bfe7c403d8ed967b9ddb2b1b5): 482 bytes on disk
I20260812 06:18:40.727626 32453 maintenance_manager.cc:643] P 6a064629f15d4284adc23539cabd9f2a: UndoDeltaBlockGCOp(bef69f4bfe7c403d8ed967b9ddb2b1b5) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":75,"lbm_reads_lt_1ms":4}
I20260812 06:18:40.728837 32521 maintenance_manager.cc:419] P 6a064629f15d4284adc23539cabd9f2a: Scheduling FlushDeltaMemStoresOp(bef69f4bfe7c403d8ed967b9ddb2b1b5): perf score=14.095187
I20260812 06:18:40.777024 32453 maintenance_manager.cc:643] P 6a064629f15d4284adc23539cabd9f2a: FlushDeltaMemStoresOp(bef69f4bfe7c403d8ed967b9ddb2b1b5) complete. Timing: real 0.048s	user 0.031s	sys 0.017s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":20814,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:18:40.788691 32521 maintenance_manager.cc:419] P 6a064629f15d4284adc23539cabd9f2a: Scheduling FlushDeltaMemStoresOp(bef69f4bfe7c403d8ed967b9ddb2b1b5): perf score=2.188937
I20260812 06:18:40.806684 32453 maintenance_manager.cc:643] P 6a064629f15d4284adc23539cabd9f2a: FlushDeltaMemStoresOp(bef69f4bfe7c403d8ed967b9ddb2b1b5) complete. Timing: real 0.018s	user 0.005s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5826,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:40.807235 32521 maintenance_manager.cc:419] P 6a064629f15d4284adc23539cabd9f2a: Scheduling MajorDeltaCompactionOp(bef69f4bfe7c403d8ed967b9ddb2b1b5): perf score=1.000000
I20260812 06:18:40.986749 32453 maintenance_manager.cc:643] P 6a064629f15d4284adc23539cabd9f2a: MajorDeltaCompactionOp(bef69f4bfe7c403d8ed967b9ddb2b1b5) complete. Timing: real 0.179s	user 0.131s	sys 0.040s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24733723,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":156,"lbm_read_time_us":11923,"lbm_reads_lt_1ms":564,"lbm_write_time_us":27093,"lbm_writes_lt_1ms":543,"mutex_wait_us":29,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":14976,"update_count":2500}
I20260812 06:18:40.987458 32521 maintenance_manager.cc:419] P 6a064629f15d4284adc23539cabd9f2a: Scheduling FlushDeltaMemStoresOp(bef69f4bfe7c403d8ed967b9ddb2b1b5): perf score=14.095187
I20260812 06:18:41.044258 32453 maintenance_manager.cc:643] P 6a064629f15d4284adc23539cabd9f2a: FlushDeltaMemStoresOp(bef69f4bfe7c403d8ed967b9ddb2b1b5) complete. Timing: real 0.057s	user 0.043s	sys 0.007s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":23822,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:18:41.044782 32521 maintenance_manager.cc:419] P 6a064629f15d4284adc23539cabd9f2a: Scheduling FlushDeltaMemStoresOp(bef69f4bfe7c403d8ed967b9ddb2b1b5): perf score=2.188937
I20260812 06:18:41.056301 32453 maintenance_manager.cc:643] P 6a064629f15d4284adc23539cabd9f2a: FlushDeltaMemStoresOp(bef69f4bfe7c403d8ed967b9ddb2b1b5) complete. Timing: real 0.011s	user 0.009s	sys 0.000s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4195,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:41.057021 32521 maintenance_manager.cc:419] P 6a064629f15d4284adc23539cabd9f2a: Scheduling MajorDeltaCompactionOp(bef69f4bfe7c403d8ed967b9ddb2b1b5): perf score=1.000000
I20260812 06:18:41.254956 32453 maintenance_manager.cc:643] P 6a064629f15d4284adc23539cabd9f2a: MajorDeltaCompactionOp(bef69f4bfe7c403d8ed967b9ddb2b1b5) complete. Timing: real 0.198s	user 0.133s	sys 0.048s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24733722,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":892,"lbm_read_time_us":10861,"lbm_reads_lt_1ms":572,"lbm_write_time_us":36572,"lbm_writes_lt_1ms":543,"mutex_wait_us":22,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":24448,"update_count":2500}
I20260812 06:18:41.255682 32521 maintenance_manager.cc:419] P 6a064629f15d4284adc23539cabd9f2a: Scheduling FlushDeltaMemStoresOp(bef69f4bfe7c403d8ed967b9ddb2b1b5): perf score=14.095187
I20260812 06:18:41.310460 32453 maintenance_manager.cc:643] P 6a064629f15d4284adc23539cabd9f2a: FlushDeltaMemStoresOp(bef69f4bfe7c403d8ed967b9ddb2b1b5) complete. Timing: real 0.055s	user 0.035s	sys 0.016s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":23253,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:18:41.311017 32521 maintenance_manager.cc:419] P 6a064629f15d4284adc23539cabd9f2a: Scheduling FlushDeltaMemStoresOp(bef69f4bfe7c403d8ed967b9ddb2b1b5): perf score=2.188937
I20260812 06:18:41.323742 32453 maintenance_manager.cc:643] P 6a064629f15d4284adc23539cabd9f2a: FlushDeltaMemStoresOp(bef69f4bfe7c403d8ed967b9ddb2b1b5) complete. Timing: real 0.013s	user 0.003s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4729,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:41.324378 32521 maintenance_manager.cc:419] P 6a064629f15d4284adc23539cabd9f2a: Scheduling MajorDeltaCompactionOp(bef69f4bfe7c403d8ed967b9ddb2b1b5): perf score=1.000000
I20260812 06:18:41.494335 32453 maintenance_manager.cc:643] P 6a064629f15d4284adc23539cabd9f2a: MajorDeltaCompactionOp(bef69f4bfe7c403d8ed967b9ddb2b1b5) complete. Timing: real 0.170s	user 0.130s	sys 0.027s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24733723,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":350,"lbm_read_time_us":12141,"lbm_reads_lt_1ms":572,"lbm_write_time_us":32076,"lbm_writes_lt_1ms":543,"mutex_wait_us":48,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":2816,"update_count":2500}
I20260812 06:18:41.495164 32521 maintenance_manager.cc:419] P 6a064629f15d4284adc23539cabd9f2a: Scheduling FlushDeltaMemStoresOp(bef69f4bfe7c403d8ed967b9ddb2b1b5): perf score=14.095187
I20260812 06:18:41.550653 32453 maintenance_manager.cc:643] P 6a064629f15d4284adc23539cabd9f2a: FlushDeltaMemStoresOp(bef69f4bfe7c403d8ed967b9ddb2b1b5) complete. Timing: real 0.055s	user 0.023s	sys 0.025s Metrics: {"bytes_written":16409903,"delete_count":0,"lbm_write_time_us":21809,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:18:41.551349 32521 maintenance_manager.cc:419] P 6a064629f15d4284adc23539cabd9f2a: Scheduling FlushDeltaMemStoresOp(bef69f4bfe7c403d8ed967b9ddb2b1b5): perf score=2.188937
I20260812 06:18:41.567605 32453 maintenance_manager.cc:643] P 6a064629f15d4284adc23539cabd9f2a: FlushDeltaMemStoresOp(bef69f4bfe7c403d8ed967b9ddb2b1b5) complete. Timing: real 0.016s	user 0.010s	sys 0.003s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6109,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:41.568406 32521 maintenance_manager.cc:419] P 6a064629f15d4284adc23539cabd9f2a: Scheduling MajorDeltaCompactionOp(bef69f4bfe7c403d8ed967b9ddb2b1b5): perf score=1.000000
I20260812 06:18:41.748396 32453 maintenance_manager.cc:643] P 6a064629f15d4284adc23539cabd9f2a: MajorDeltaCompactionOp(bef69f4bfe7c403d8ed967b9ddb2b1b5) complete. Timing: real 0.180s	user 0.139s	sys 0.029s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24733725,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":369,"lbm_read_time_us":12269,"lbm_reads_lt_1ms":572,"lbm_write_time_us":33821,"lbm_writes_lt_1ms":543,"mutex_wait_us":34,"peak_mem_usage":63115900,"reinsert_count":0,"update_count":2500}
I20260812 06:18:41.749204 32521 maintenance_manager.cc:419] P 6a064629f15d4284adc23539cabd9f2a: Scheduling FlushDeltaMemStoresOp(bef69f4bfe7c403d8ed967b9ddb2b1b5): perf score=14.095187
I20260812 06:18:41.803881 32453 maintenance_manager.cc:643] P 6a064629f15d4284adc23539cabd9f2a: FlushDeltaMemStoresOp(bef69f4bfe7c403d8ed967b9ddb2b1b5) complete. Timing: real 0.054s	user 0.016s	sys 0.035s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":26005,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":402,"reinsert_count":0,"spinlock_wait_cycles":1408,"update_count":2000}
I20260812 06:18:41.804425 32521 maintenance_manager.cc:419] P 6a064629f15d4284adc23539cabd9f2a: Scheduling FlushDeltaMemStoresOp(bef69f4bfe7c403d8ed967b9ddb2b1b5): perf score=2.188937
I20260812 06:18:41.817458 32453 maintenance_manager.cc:643] P 6a064629f15d4284adc23539cabd9f2a: FlushDeltaMemStoresOp(bef69f4bfe7c403d8ed967b9ddb2b1b5) complete. Timing: real 0.013s	user 0.006s	sys 0.006s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4946,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:41.817906 32521 maintenance_manager.cc:419] P 6a064629f15d4284adc23539cabd9f2a: Scheduling MajorDeltaCompactionOp(bef69f4bfe7c403d8ed967b9ddb2b1b5): perf score=1.000000
I20260812 06:18:41.982488 32453 maintenance_manager.cc:643] P 6a064629f15d4284adc23539cabd9f2a: MajorDeltaCompactionOp(bef69f4bfe7c403d8ed967b9ddb2b1b5) complete. Timing: real 0.164s	user 0.128s	sys 0.034s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24733724,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":922,"lbm_read_time_us":10642,"lbm_reads_lt_1ms":572,"lbm_write_time_us":34224,"lbm_writes_lt_1ms":543,"mutex_wait_us":625,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":1664,"update_count":2500}
I20260812 06:18:41.984295 32521 maintenance_manager.cc:419] P 6a064629f15d4284adc23539cabd9f2a: Scheduling FlushDeltaMemStoresOp(bef69f4bfe7c403d8ed967b9ddb2b1b5): perf score=11.118625
I20260812 06:18:42.023093 32453 maintenance_manager.cc:643] P 6a064629f15d4284adc23539cabd9f2a: FlushDeltaMemStoresOp(bef69f4bfe7c403d8ed967b9ddb2b1b5) complete. Timing: real 0.038s	user 0.023s	sys 0.013s Metrics: {"bytes_written":12594659,"delete_count":0,"lbm_write_time_us":16872,"lbm_writes_lt_1ms":310,"reinsert_count":0,"update_count":1535}
I20260812 06:18:42.023841 32521 maintenance_manager.cc:419] P 6a064629f15d4284adc23539cabd9f2a: Scheduling FlushDeltaMemStoresOp(bef69f4bfe7c403d8ed967b9ddb2b1b5): perf score=2.188937
I20260812 06:18:42.045666 32453 maintenance_manager.cc:643] P 6a064629f15d4284adc23539cabd9f2a: FlushDeltaMemStoresOp(bef69f4bfe7c403d8ed967b9ddb2b1b5) complete. Timing: real 0.022s	user 0.009s	sys 0.004s Metrics: {"bytes_written":3815484,"delete_count":0,"lbm_write_time_us":6517,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":95,"reinsert_count":0,"update_count":465}
I20260812 06:18:42.046204 32521 maintenance_manager.cc:419] P 6a064629f15d4284adc23539cabd9f2a: Scheduling FlushMRSOp(bef69f4bfe7c403d8ed967b9ddb2b1b5): perf score=1.000000
I20260812 06:18:42.108129 32453 maintenance_manager.cc:643] P 6a064629f15d4284adc23539cabd9f2a: FlushMRSOp(bef69f4bfe7c403d8ed967b9ddb2b1b5) complete. Timing: real 0.062s	user 0.035s	sys 0.001s Metrics: {"bytes_written":1316419,"cfile_init":1,"dirs.queue_time_us":69,"dirs.run_cpu_time_us":272,"dirs.run_wall_time_us":1754,"drs_written":1,"lbm_read_time_us":68,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1890,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":32}
I20260812 06:18:42.109251 32521 maintenance_manager.cc:419] P 6a064629f15d4284adc23539cabd9f2a: Scheduling LogGCOp(bef69f4bfe7c403d8ed967b9ddb2b1b5): free 132571336 bytes of WAL
I20260812 06:18:42.109601 32453 log_reader.cc:385] T bef69f4bfe7c403d8ed967b9ddb2b1b5: removed 13 log segments from log reader
I20260812 06:18:42.109678 32453 log.cc:1079] T bef69f4bfe7c403d8ed967b9ddb2b1b5 P 6a064629f15d4284adc23539cabd9f2a: Deleting log segment in path: /tmp/dist-test-taskchnxcB/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515518376868-32341-0/minicluster-data/ts-0-root/wals/bef69f4bfe7c403d8ed967b9ddb2b1b5/wal-000000015 (ops 71-75)
I20260812 06:18:42.109723 32453 log.cc:1079] T bef69f4bfe7c403d8ed967b9ddb2b1b5 P 6a064629f15d4284adc23539cabd9f2a: Deleting log segment in path: /tmp/dist-test-taskchnxcB/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515518376868-32341-0/minicluster-data/ts-0-root/wals/bef69f4bfe7c403d8ed967b9ddb2b1b5/wal-000000016 (ops 76-80)
I20260812 06:18:42.109753 32453 log.cc:1079] T bef69f4bfe7c403d8ed967b9ddb2b1b5 P 6a064629f15d4284adc23539cabd9f2a: Deleting log segment in path: /tmp/dist-test-taskchnxcB/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515518376868-32341-0/minicluster-data/ts-0-root/wals/bef69f4bfe7c403d8ed967b9ddb2b1b5/wal-000000017 (ops 81-85)
I20260812 06:18:42.109776 32453 log.cc:1079] T bef69f4bfe7c403d8ed967b9ddb2b1b5 P 6a064629f15d4284adc23539cabd9f2a: Deleting log segment in path: /tmp/dist-test-taskchnxcB/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515518376868-32341-0/minicluster-data/ts-0-root/wals/bef69f4bfe7c403d8ed967b9ddb2b1b5/wal-000000018 (ops 86-90)
I20260812 06:18:42.109809 32453 log.cc:1079] T bef69f4bfe7c403d8ed967b9ddb2b1b5 P 6a064629f15d4284adc23539cabd9f2a: Deleting log segment in path: /tmp/dist-test-taskchnxcB/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515518376868-32341-0/minicluster-data/ts-0-root/wals/bef69f4bfe7c403d8ed967b9ddb2b1b5/wal-000000019 (ops 91-94)
I20260812 06:18:42.109833 32453 log.cc:1079] T bef69f4bfe7c403d8ed967b9ddb2b1b5 P 6a064629f15d4284adc23539cabd9f2a: Deleting log segment in path: /tmp/dist-test-taskchnxcB/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515518376868-32341-0/minicluster-data/ts-0-root/wals/bef69f4bfe7c403d8ed967b9ddb2b1b5/wal-000000020 (ops 95-99)
I20260812 06:18:42.109867 32453 log.cc:1079] T bef69f4bfe7c403d8ed967b9ddb2b1b5 P 6a064629f15d4284adc23539cabd9f2a: Deleting log segment in path: /tmp/dist-test-taskchnxcB/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515518376868-32341-0/minicluster-data/ts-0-root/wals/bef69f4bfe7c403d8ed967b9ddb2b1b5/wal-000000021 (ops 100-104)
I20260812 06:18:42.109901 32453 log.cc:1079] T bef69f4bfe7c403d8ed967b9ddb2b1b5 P 6a064629f15d4284adc23539cabd9f2a: Deleting log segment in path: /tmp/dist-test-taskchnxcB/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515518376868-32341-0/minicluster-data/ts-0-root/wals/bef69f4bfe7c403d8ed967b9ddb2b1b5/wal-000000022 (ops 105-108)
I20260812 06:18:42.109932 32453 log.cc:1079] T bef69f4bfe7c403d8ed967b9ddb2b1b5 P 6a064629f15d4284adc23539cabd9f2a: Deleting log segment in path: /tmp/dist-test-taskchnxcB/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515518376868-32341-0/minicluster-data/ts-0-root/wals/bef69f4bfe7c403d8ed967b9ddb2b1b5/wal-000000023 (ops 109-113)
I20260812 06:18:42.109954 32453 log.cc:1079] T bef69f4bfe7c403d8ed967b9ddb2b1b5 P 6a064629f15d4284adc23539cabd9f2a: Deleting log segment in path: /tmp/dist-test-taskchnxcB/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515518376868-32341-0/minicluster-data/ts-0-root/wals/bef69f4bfe7c403d8ed967b9ddb2b1b5/wal-000000024 (ops 114-118)
I20260812 06:18:42.109983 32453 log.cc:1079] T bef69f4bfe7c403d8ed967b9ddb2b1b5 P 6a064629f15d4284adc23539cabd9f2a: Deleting log segment in path: /tmp/dist-test-taskchnxcB/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515518376868-32341-0/minicluster-data/ts-0-root/wals/bef69f4bfe7c403d8ed967b9ddb2b1b5/wal-000000025 (ops 119-123)
I20260812 06:18:42.110018 32453 log.cc:1079] T bef69f4bfe7c403d8ed967b9ddb2b1b5 P 6a064629f15d4284adc23539cabd9f2a: Deleting log segment in path: /tmp/dist-test-taskchnxcB/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515518376868-32341-0/minicluster-data/ts-0-root/wals/bef69f4bfe7c403d8ed967b9ddb2b1b5/wal-000000026 (ops 124-128)
I20260812 06:18:42.110044 32453 log.cc:1079] T bef69f4bfe7c403d8ed967b9ddb2b1b5 P 6a064629f15d4284adc23539cabd9f2a: Deleting log segment in path: /tmp/dist-test-taskchnxcB/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515518376868-32341-0/minicluster-data/ts-0-root/wals/bef69f4bfe7c403d8ed967b9ddb2b1b5/wal-000000027 (ops 129-133)
I20260812 06:18:42.140233 32453 maintenance_manager.cc:643] P 6a064629f15d4284adc23539cabd9f2a: LogGCOp(bef69f4bfe7c403d8ed967b9ddb2b1b5) complete. Timing: real 0.031s	user 0.000s	sys 0.027s Metrics: {}
I20260812 06:18:42.140795 32521 maintenance_manager.cc:419] P 6a064629f15d4284adc23539cabd9f2a: Scheduling FlushDeltaMemStoresOp(bef69f4bfe7c403d8ed967b9ddb2b1b5): perf score=6.157687
I20260812 06:18:42.174199 32453 maintenance_manager.cc:643] P 6a064629f15d4284adc23539cabd9f2a: FlushDeltaMemStoresOp(bef69f4bfe7c403d8ed967b9ddb2b1b5) complete. Timing: real 0.033s	user 0.019s	sys 0.009s Metrics: {"bytes_written":8205078,"delete_count":0,"lbm_write_time_us":12724,"lbm_writes_lt_1ms":203,"reinsert_count":0,"update_count":1000}
I20260812 06:18:42.174894 32521 maintenance_manager.cc:419] P 6a064629f15d4284adc23539cabd9f2a: Scheduling FlushDeltaMemStoresOp(bef69f4bfe7c403d8ed967b9ddb2b1b5): perf score=2.188937
I20260812 06:18:42.187598 32453 maintenance_manager.cc:643] P 6a064629f15d4284adc23539cabd9f2a: FlushDeltaMemStoresOp(bef69f4bfe7c403d8ed967b9ddb2b1b5) complete. Timing: real 0.012s	user 0.010s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4741,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:42.188305 32521 maintenance_manager.cc:419] P 6a064629f15d4284adc23539cabd9f2a: Scheduling UndoDeltaBlockGCOp(bef69f4bfe7c403d8ed967b9ddb2b1b5): 493 bytes on disk
I20260812 06:18:42.188849 32453 maintenance_manager.cc:643] P 6a064629f15d4284adc23539cabd9f2a: UndoDeltaBlockGCOp(bef69f4bfe7c403d8ed967b9ddb2b1b5) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":61,"lbm_reads_lt_1ms":4}
I20260812 06:18:42.189357 32521 maintenance_manager.cc:419] P 6a064629f15d4284adc23539cabd9f2a: Scheduling MajorDeltaCompactionOp(bef69f4bfe7c403d8ed967b9ddb2b1b5): perf score=1.000000
I20260812 06:18:42.423641 32453 maintenance_manager.cc:643] P 6a064629f15d4284adc23539cabd9f2a: MajorDeltaCompactionOp(bef69f4bfe7c403d8ed967b9ddb2b1b5) complete. Timing: real 0.234s	user 0.161s	sys 0.060s Metrics: {"cfile_cache_miss":734,"cfile_cache_miss_bytes":32938781,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":558,"lbm_read_time_us":15856,"lbm_reads_lt_1ms":774,"lbm_write_time_us":41389,"lbm_writes_lt_1ms":743,"mutex_wait_us":81,"peak_mem_usage":87969044,"reinsert_count":0,"spinlock_wait_cycles":7040,"thread_start_us":82,"threads_started":1,"update_count":3500}
I20260812 06:18:42.424757 32521 maintenance_manager.cc:419] P 6a064629f15d4284adc23539cabd9f2a: Scheduling FlushDeltaMemStoresOp(bef69f4bfe7c403d8ed967b9ddb2b1b5): perf score=18.063937
I20260812 06:18:42.495652 32453 maintenance_manager.cc:643] P 6a064629f15d4284adc23539cabd9f2a: FlushDeltaMemStoresOp(bef69f4bfe7c403d8ed967b9ddb2b1b5) complete. Timing: real 0.071s	user 0.023s	sys 0.045s Metrics: {"bytes_written":20512318,"delete_count":0,"lbm_write_time_us":33577,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":502,"reinsert_count":0,"update_count":2500}
I20260812 06:18:42.496445 32521 maintenance_manager.cc:419] P 6a064629f15d4284adc23539cabd9f2a: Scheduling FlushDeltaMemStoresOp(bef69f4bfe7c403d8ed967b9ddb2b1b5): perf score=2.188937
I20260812 06:18:42.516289 32453 maintenance_manager.cc:643] P 6a064629f15d4284adc23539cabd9f2a: FlushDeltaMemStoresOp(bef69f4bfe7c403d8ed967b9ddb2b1b5) complete. Timing: real 0.020s	user 0.015s	sys 0.001s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6398,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:42.516877 32521 maintenance_manager.cc:419] P 6a064629f15d4284adc23539cabd9f2a: Scheduling MajorDeltaCompactionOp(bef69f4bfe7c403d8ed967b9ddb2b1b5): perf score=1.000000
I20260812 06:18:42.697346 32453 maintenance_manager.cc:643] P 6a064629f15d4284adc23539cabd9f2a: MajorDeltaCompactionOp(bef69f4bfe7c403d8ed967b9ddb2b1b5) complete. Timing: real 0.180s	user 0.136s	sys 0.043s Metrics: {"cfile_cache_miss":632,"cfile_cache_miss_bytes":28836140,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":1286,"lbm_read_time_us":12603,"lbm_reads_lt_1ms":664,"lbm_write_time_us":40273,"lbm_writes_lt_1ms":643,"mutex_wait_us":394,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":3328,"update_count":3000}
I20260812 06:18:42.697921 32521 maintenance_manager.cc:419] P 6a064629f15d4284adc23539cabd9f2a: Scheduling FlushDeltaMemStoresOp(bef69f4bfe7c403d8ed967b9ddb2b1b5): perf score=14.095187
I20260812 06:18:42.752904 32453 maintenance_manager.cc:643] P 6a064629f15d4284adc23539cabd9f2a: FlushDeltaMemStoresOp(bef69f4bfe7c403d8ed967b9ddb2b1b5) complete. Timing: real 0.055s	user 0.027s	sys 0.027s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":24256,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":402,"reinsert_count":0,"update_count":2000}
I20260812 06:18:42.753607 32521 maintenance_manager.cc:419] P 6a064629f15d4284adc23539cabd9f2a: Scheduling FlushDeltaMemStoresOp(bef69f4bfe7c403d8ed967b9ddb2b1b5): perf score=2.188937
I20260812 06:18:42.771148 32453 maintenance_manager.cc:643] P 6a064629f15d4284adc23539cabd9f2a: FlushDeltaMemStoresOp(bef69f4bfe7c403d8ed967b9ddb2b1b5) complete. Timing: real 0.017s	user 0.009s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5797,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:42.771883 32521 maintenance_manager.cc:419] P 6a064629f15d4284adc23539cabd9f2a: Scheduling MajorDeltaCompactionOp(bef69f4bfe7c403d8ed967b9ddb2b1b5): perf score=1.000000
I20260812 06:18:42.943400 32453 maintenance_manager.cc:643] P 6a064629f15d4284adc23539cabd9f2a: MajorDeltaCompactionOp(bef69f4bfe7c403d8ed967b9ddb2b1b5) complete. Timing: real 0.171s	user 0.106s	sys 0.058s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24733724,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":1035,"lbm_read_time_us":10574,"lbm_reads_lt_1ms":564,"lbm_write_time_us":32557,"lbm_writes_lt_1ms":543,"mutex_wait_us":260,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":1664,"update_count":2500}
I20260812 06:18:42.943974 32521 maintenance_manager.cc:419] P 6a064629f15d4284adc23539cabd9f2a: Scheduling FlushDeltaMemStoresOp(bef69f4bfe7c403d8ed967b9ddb2b1b5): perf score=14.095187
I20260812 06:18:42.995527 32453 maintenance_manager.cc:643] P 6a064629f15d4284adc23539cabd9f2a: FlushDeltaMemStoresOp(bef69f4bfe7c403d8ed967b9ddb2b1b5) complete. Timing: real 0.051s	user 0.027s	sys 0.013s Metrics: {"bytes_written":16409905,"delete_count":0,"lbm_write_time_us":19472,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:18:42.996158 32521 maintenance_manager.cc:419] P 6a064629f15d4284adc23539cabd9f2a: Scheduling FlushDeltaMemStoresOp(bef69f4bfe7c403d8ed967b9ddb2b1b5): perf score=2.188937
I20260812 06:18:43.009222 32453 maintenance_manager.cc:643] P 6a064629f15d4284adc23539cabd9f2a: FlushDeltaMemStoresOp(bef69f4bfe7c403d8ed967b9ddb2b1b5) complete. Timing: real 0.013s	user 0.012s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4359,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:43.009752 32521 maintenance_manager.cc:419] P 6a064629f15d4284adc23539cabd9f2a: Scheduling MajorDeltaCompactionOp(bef69f4bfe7c403d8ed967b9ddb2b1b5): perf score=1.000000
I20260812 06:18:43.183876 32453 maintenance_manager.cc:643] P 6a064629f15d4284adc23539cabd9f2a: MajorDeltaCompactionOp(bef69f4bfe7c403d8ed967b9ddb2b1b5) complete. Timing: real 0.174s	user 0.137s	sys 0.034s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24733727,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":1065,"lbm_read_time_us":12543,"lbm_reads_lt_1ms":572,"lbm_write_time_us":30049,"lbm_writes_lt_1ms":543,"mutex_wait_us":371,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":18944,"update_count":2500}
I20260812 06:18:43.184787 32521 maintenance_manager.cc:419] P 6a064629f15d4284adc23539cabd9f2a: Scheduling FlushDeltaMemStoresOp(bef69f4bfe7c403d8ed967b9ddb2b1b5): perf score=14.095187
I20260812 06:18:43.239257 32453 maintenance_manager.cc:643] P 6a064629f15d4284adc23539cabd9f2a: FlushDeltaMemStoresOp(bef69f4bfe7c403d8ed967b9ddb2b1b5) complete. Timing: real 0.054s	user 0.023s	sys 0.025s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":22906,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:18:43.239871 32521 maintenance_manager.cc:419] P 6a064629f15d4284adc23539cabd9f2a: Scheduling MajorDeltaCompactionOp(bef69f4bfe7c403d8ed967b9ddb2b1b5): perf score=1.000000
I20260812 06:18:43.397094 32453 maintenance_manager.cc:643] P 6a064629f15d4284adc23539cabd9f2a: MajorDeltaCompactionOp(bef69f4bfe7c403d8ed967b9ddb2b1b5) complete. Timing: real 0.157s	user 0.121s	sys 0.032s Metrics: {"cfile_cache_miss":431,"cfile_cache_miss_bytes":20631192,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":1,"delta_iterators_relevant":1,"dirs.queue_time_us":896,"lbm_read_time_us":10768,"lbm_reads_lt_1ms":463,"lbm_write_time_us":26479,"lbm_writes_lt_1ms":443,"mutex_wait_us":798,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":2816,"update_count":2000}
I20260812 06:18:43.397936 32521 maintenance_manager.cc:419] P 6a064629f15d4284adc23539cabd9f2a: Scheduling FlushDeltaMemStoresOp(bef69f4bfe7c403d8ed967b9ddb2b1b5): perf score=11.118625
I20260812 06:18:43.437932 32453 maintenance_manager.cc:643] P 6a064629f15d4284adc23539cabd9f2a: FlushDeltaMemStoresOp(bef69f4bfe7c403d8ed967b9ddb2b1b5) complete. Timing: real 0.040s	user 0.032s	sys 0.005s Metrics: {"bytes_written":12717735,"delete_count":0,"lbm_write_time_us":17100,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:18:43.438458 32521 maintenance_manager.cc:419] P 6a064629f15d4284adc23539cabd9f2a: Scheduling FlushDeltaMemStoresOp(bef69f4bfe7c403d8ed967b9ddb2b1b5): perf score=2.188937
I20260812 06:18:43.462626 32453 maintenance_manager.cc:643] P 6a064629f15d4284adc23539cabd9f2a: FlushDeltaMemStoresOp(bef69f4bfe7c403d8ed967b9ddb2b1b5) complete. Timing: real 0.024s	user 0.013s	sys 0.000s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":5782,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:18:43.463124 32521 maintenance_manager.cc:419] P 6a064629f15d4284adc23539cabd9f2a: Scheduling FlushDeltaMemStoresOp(bef69f4bfe7c403d8ed967b9ddb2b1b5): perf score=2.188937
I20260812 06:18:43.477293 32453 maintenance_manager.cc:643] P 6a064629f15d4284adc23539cabd9f2a: FlushDeltaMemStoresOp(bef69f4bfe7c403d8ed967b9ddb2b1b5) complete. Timing: real 0.014s	user 0.004s	sys 0.009s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4685,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:43.478086 32521 maintenance_manager.cc:419] P 6a064629f15d4284adc23539cabd9f2a: Scheduling MajorDeltaCompactionOp(bef69f4bfe7c403d8ed967b9ddb2b1b5): perf score=1.000000
I20260812 06:18:43.675468 32453 maintenance_manager.cc:643] P 6a064629f15d4284adc23539cabd9f2a: MajorDeltaCompactionOp(bef69f4bfe7c403d8ed967b9ddb2b1b5) complete. Timing: real 0.197s	user 0.114s	sys 0.076s Metrics: {"cfile_cache_miss":533,"cfile_cache_miss_bytes":24733833,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":317,"lbm_read_time_us":13106,"lbm_reads_1-10_ms":1,"lbm_reads_lt_1ms":572,"lbm_write_time_us":32844,"lbm_writes_lt_1ms":543,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":1280,"update_count":2500}
I20260812 06:18:43.676260 32521 maintenance_manager.cc:419] P 6a064629f15d4284adc23539cabd9f2a: Scheduling FlushDeltaMemStoresOp(bef69f4bfe7c403d8ed967b9ddb2b1b5): perf score=11.118625
I20260812 06:18:43.715715 32453 maintenance_manager.cc:643] P 6a064629f15d4284adc23539cabd9f2a: FlushDeltaMemStoresOp(bef69f4bfe7c403d8ed967b9ddb2b1b5) complete. Timing: real 0.039s	user 0.022s	sys 0.016s Metrics: {"bytes_written":12717737,"delete_count":0,"lbm_write_time_us":17017,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:18:43.716985 32521 maintenance_manager.cc:419] P 6a064629f15d4284adc23539cabd9f2a: Scheduling FlushDeltaMemStoresOp(bef69f4bfe7c403d8ed967b9ddb2b1b5): perf score=2.188937
I20260812 06:18:43.743659 32453 maintenance_manager.cc:643] P 6a064629f15d4284adc23539cabd9f2a: FlushDeltaMemStoresOp(bef69f4bfe7c403d8ed967b9ddb2b1b5) complete. Timing: real 0.026s	user 0.002s	sys 0.009s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":5231,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:18:43.744325 32521 maintenance_manager.cc:419] P 6a064629f15d4284adc23539cabd9f2a: Scheduling FlushDeltaMemStoresOp(bef69f4bfe7c403d8ed967b9ddb2b1b5): perf score=2.188937
I20260812 06:18:43.755288 32453 maintenance_manager.cc:643] P 6a064629f15d4284adc23539cabd9f2a: FlushDeltaMemStoresOp(bef69f4bfe7c403d8ed967b9ddb2b1b5) complete. Timing: real 0.011s	user 0.003s	sys 0.006s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4182,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:43.755818 32521 maintenance_manager.cc:419] P 6a064629f15d4284adc23539cabd9f2a: Scheduling FlushMRSOp(bef69f4bfe7c403d8ed967b9ddb2b1b5): perf score=1.000000
I20260812 06:18:43.794184 32453 maintenance_manager.cc:643] P 6a064629f15d4284adc23539cabd9f2a: FlushMRSOp(bef69f4bfe7c403d8ed967b9ddb2b1b5) complete. Timing: real 0.038s	user 0.032s	sys 0.004s Metrics: {"bytes_written":1316417,"cfile_init":1,"dirs.queue_time_us":83,"dirs.run_cpu_time_us":197,"dirs.run_wall_time_us":1321,"drs_written":1,"lbm_read_time_us":41,"lbm_reads_lt_1ms":4,"lbm_write_time_us":2431,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":32}
I20260812 06:18:43.794945 32521 maintenance_manager.cc:419] P 6a064629f15d4284adc23539cabd9f2a: Scheduling LogGCOp(bef69f4bfe7c403d8ed967b9ddb2b1b5): free 133024594 bytes of WAL
I20260812 06:18:43.795183 32453 log_reader.cc:385] T bef69f4bfe7c403d8ed967b9ddb2b1b5: removed 13 log segments from log reader
I20260812 06:18:43.795225 32453 log.cc:1079] T bef69f4bfe7c403d8ed967b9ddb2b1b5 P 6a064629f15d4284adc23539cabd9f2a: Deleting log segment in path: /tmp/dist-test-taskchnxcB/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515518376868-32341-0/minicluster-data/ts-0-root/wals/bef69f4bfe7c403d8ed967b9ddb2b1b5/wal-000000028 (ops 134-138)
I20260812 06:18:43.795254 32453 log.cc:1079] T bef69f4bfe7c403d8ed967b9ddb2b1b5 P 6a064629f15d4284adc23539cabd9f2a: Deleting log segment in path: /tmp/dist-test-taskchnxcB/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515518376868-32341-0/minicluster-data/ts-0-root/wals/bef69f4bfe7c403d8ed967b9ddb2b1b5/wal-000000029 (ops 139-143)
I20260812 06:18:43.795312 32453 log.cc:1079] T bef69f4bfe7c403d8ed967b9ddb2b1b5 P 6a064629f15d4284adc23539cabd9f2a: Deleting log segment in path: /tmp/dist-test-taskchnxcB/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515518376868-32341-0/minicluster-data/ts-0-root/wals/bef69f4bfe7c403d8ed967b9ddb2b1b5/wal-000000030 (ops 144-148)
I20260812 06:18:43.795356 32453 log.cc:1079] T bef69f4bfe7c403d8ed967b9ddb2b1b5 P 6a064629f15d4284adc23539cabd9f2a: Deleting log segment in path: /tmp/dist-test-taskchnxcB/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515518376868-32341-0/minicluster-data/ts-0-root/wals/bef69f4bfe7c403d8ed967b9ddb2b1b5/wal-000000031 (ops 149-153)
I20260812 06:18:43.795382 32453 log.cc:1079] T bef69f4bfe7c403d8ed967b9ddb2b1b5 P 6a064629f15d4284adc23539cabd9f2a: Deleting log segment in path: /tmp/dist-test-taskchnxcB/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515518376868-32341-0/minicluster-data/ts-0-root/wals/bef69f4bfe7c403d8ed967b9ddb2b1b5/wal-000000032 (ops 154-158)
I20260812 06:18:43.795421 32453 log.cc:1079] T bef69f4bfe7c403d8ed967b9ddb2b1b5 P 6a064629f15d4284adc23539cabd9f2a: Deleting log segment in path: /tmp/dist-test-taskchnxcB/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515518376868-32341-0/minicluster-data/ts-0-root/wals/bef69f4bfe7c403d8ed967b9ddb2b1b5/wal-000000033 (ops 159-163)
I20260812 06:18:43.795469 32453 log.cc:1079] T bef69f4bfe7c403d8ed967b9ddb2b1b5 P 6a064629f15d4284adc23539cabd9f2a: Deleting log segment in path: /tmp/dist-test-taskchnxcB/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515518376868-32341-0/minicluster-data/ts-0-root/wals/bef69f4bfe7c403d8ed967b9ddb2b1b5/wal-000000034 (ops 164-168)
I20260812 06:18:43.795511 32453 log.cc:1079] T bef69f4bfe7c403d8ed967b9ddb2b1b5 P 6a064629f15d4284adc23539cabd9f2a: Deleting log segment in path: /tmp/dist-test-taskchnxcB/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515518376868-32341-0/minicluster-data/ts-0-root/wals/bef69f4bfe7c403d8ed967b9ddb2b1b5/wal-000000035 (ops 169-172)
I20260812 06:18:43.795552 32453 log.cc:1079] T bef69f4bfe7c403d8ed967b9ddb2b1b5 P 6a064629f15d4284adc23539cabd9f2a: Deleting log segment in path: /tmp/dist-test-taskchnxcB/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515518376868-32341-0/minicluster-data/ts-0-root/wals/bef69f4bfe7c403d8ed967b9ddb2b1b5/wal-000000036 (ops 173-177)
I20260812 06:18:43.795593 32453 log.cc:1079] T bef69f4bfe7c403d8ed967b9ddb2b1b5 P 6a064629f15d4284adc23539cabd9f2a: Deleting log segment in path: /tmp/dist-test-taskchnxcB/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515518376868-32341-0/minicluster-data/ts-0-root/wals/bef69f4bfe7c403d8ed967b9ddb2b1b5/wal-000000037 (ops 178-182)
I20260812 06:18:43.795636 32453 log.cc:1079] T bef69f4bfe7c403d8ed967b9ddb2b1b5 P 6a064629f15d4284adc23539cabd9f2a: Deleting log segment in path: /tmp/dist-test-taskchnxcB/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515518376868-32341-0/minicluster-data/ts-0-root/wals/bef69f4bfe7c403d8ed967b9ddb2b1b5/wal-000000038 (ops 183-187)
I20260812 06:18:43.795677 32453 log.cc:1079] T bef69f4bfe7c403d8ed967b9ddb2b1b5 P 6a064629f15d4284adc23539cabd9f2a: Deleting log segment in path: /tmp/dist-test-taskchnxcB/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515518376868-32341-0/minicluster-data/ts-0-root/wals/bef69f4bfe7c403d8ed967b9ddb2b1b5/wal-000000039 (ops 188-192)
I20260812 06:18:43.795717 32453 log.cc:1079] T bef69f4bfe7c403d8ed967b9ddb2b1b5 P 6a064629f15d4284adc23539cabd9f2a: Deleting log segment in path: /tmp/dist-test-taskchnxcB/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515518376868-32341-0/minicluster-data/ts-0-root/wals/bef69f4bfe7c403d8ed967b9ddb2b1b5/wal-000000040 (ops 193-197)
I20260812 06:18:43.822587 32453 maintenance_manager.cc:643] P 6a064629f15d4284adc23539cabd9f2a: LogGCOp(bef69f4bfe7c403d8ed967b9ddb2b1b5) complete. Timing: real 0.027s	user 0.000s	sys 0.026s Metrics: {}
I20260812 06:18:43.826508 32521 maintenance_manager.cc:419] P 6a064629f15d4284adc23539cabd9f2a: Scheduling FlushDeltaMemStoresOp(bef69f4bfe7c403d8ed967b9ddb2b1b5): perf score=2.188937
I20260812 06:18:43.849094 32341 heavy-update-compaction-itest.cc:229] Time spent updating: real 5.152s	user 1.910s	sys 0.117s
I20260812 06:18:43.850523 32453 maintenance_manager.cc:643] P 6a064629f15d4284adc23539cabd9f2a: FlushDeltaMemStoresOp(bef69f4bfe7c403d8ed967b9ddb2b1b5) complete. Timing: real 0.024s	user 0.007s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6935,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:43.851035 32521 maintenance_manager.cc:419] P 6a064629f15d4284adc23539cabd9f2a: Scheduling FlushDeltaMemStoresOp(bef69f4bfe7c403d8ed967b9ddb2b1b5): perf score=2.188937
I20260812 06:18:43.862548 32453 maintenance_manager.cc:643] P 6a064629f15d4284adc23539cabd9f2a: FlushDeltaMemStoresOp(bef69f4bfe7c403d8ed967b9ddb2b1b5) complete. Timing: real 0.011s	user 0.005s	sys 0.005s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4905,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:43.863183 32521 maintenance_manager.cc:419] P 6a064629f15d4284adc23539cabd9f2a: Scheduling UndoDeltaBlockGCOp(bef69f4bfe7c403d8ed967b9ddb2b1b5): 492 bytes on disk
I20260812 06:18:43.863713 32453 maintenance_manager.cc:643] P 6a064629f15d4284adc23539cabd9f2a: UndoDeltaBlockGCOp(bef69f4bfe7c403d8ed967b9ddb2b1b5) 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:18:43.864349 32521 maintenance_manager.cc:419] P 6a064629f15d4284adc23539cabd9f2a: Scheduling MajorDeltaCompactionOp(bef69f4bfe7c403d8ed967b9ddb2b1b5): perf score=1.000000
I20260812 06:18:43.948781 32341 heavy-update-compaction-itest.cc:265] Time spent scanning: real 0.099s	user 0.004s	sys 0.000s
I20260812 06:18:43.949469 32341 tablet_server.cc:179] TabletServer@127.31.149.65:0 shutting down...
I20260812 06:18:44.063020 32453 maintenance_manager.cc:643] P 6a064629f15d4284adc23539cabd9f2a: MajorDeltaCompactionOp(bef69f4bfe7c403d8ed967b9ddb2b1b5) complete. Timing: real 0.198s	user 0.150s	sys 0.048s Metrics: {"cfile_cache_hit":256,"cfile_cache_hit_bytes":10343113,"cfile_cache_miss":479,"cfile_cache_miss_bytes":22595784,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":5,"delta_iterators_relevant":5,"dirs.queue_time_us":948,"lbm_read_time_us":10347,"lbm_reads_lt_1ms":511,"lbm_write_time_us":41694,"lbm_writes_lt_1ms":743,"mutex_wait_us":317,"peak_mem_usage":87969044,"reinsert_count":0,"spinlock_wait_cycles":109696,"thread_start_us":86,"threads_started":1,"update_count":3500}
I20260812 06:18:44.064366 32341 ts_tablet_manager.cc:1507] Shutting down tablet manager...
I20260812 06:18:44.064841 32341 tablet_replica.cc:333] T bef69f4bfe7c403d8ed967b9ddb2b1b5 P 6a064629f15d4284adc23539cabd9f2a: stopping tablet replica
I20260812 06:18:44.065114 32341 raft_consensus.cc:2243] T bef69f4bfe7c403d8ed967b9ddb2b1b5 P 6a064629f15d4284adc23539cabd9f2a [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:18:44.065376 32341 raft_consensus.cc:2272] T bef69f4bfe7c403d8ed967b9ddb2b1b5 P 6a064629f15d4284adc23539cabd9f2a [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:18:44.081773 32341 tablet_server.cc:196] TabletServer@127.31.149.65:0 shutdown complete.
I20260812 06:18:44.123191 32341 master.cc:562] Master@127.31.149.126:44019 shutting down...
I20260812 06:18:44.127526 32341 raft_consensus.cc:2243] T 00000000000000000000000000000000 P 0bf776899ff541f8835efb2975e33980 [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:18:44.127769 32341 raft_consensus.cc:2272] T 00000000000000000000000000000000 P 0bf776899ff541f8835efb2975e33980 [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:18:44.127871 32341 tablet_replica.cc:333] T 00000000000000000000000000000000 P 0bf776899ff541f8835efb2975e33980: stopping tablet replica
I20260812 06:18:44.141578 32341 master.cc:584] Master@127.31.149.126:44019 shutdown complete.
[       OK ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/0 (5840 ms)
[ RUN      ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/1
I20260812 06:18:44.240032 32341 internal_mini_cluster.cc:156] Creating distributed mini masters. Addrs: 127.31.149.126:36959
I20260812 06:18:44.240439 32341 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:18:44.243124 32555 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:18:44.243124 32553 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:18:44.243124 32557 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:18:44.243176 32341 server_base.cc:1061] running on GCE node
I20260812 06:18:44.243521 32341 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:18:44.243554 32341 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:18:44.243570 32341 hybrid_clock.cc:648] HybridClock initialized: now 1786515524243570 us; error 0 us; skew 500 ppm
I20260812 06:18:44.244534 32341 webserver.cc:533] Webserver started at http://127.31.149.126:38969/ using document root <none> and password file <none>
I20260812 06:18:44.244791 32341 fs_manager.cc:362] Metadata directory not provided
I20260812 06:18:44.244844 32341 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:18:44.244941 32341 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:18:44.245394 32341 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskchnxcB/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515518376868-32341-0/minicluster-data/master-0-root/instance:
uuid: "9e823c92132248f0b3a45df8806c5d56"
format_stamp: "Formatted at 2026-08-12 06:18:44 on dist-test-slave-rgb1"
I20260812 06:18:44.247008 32341 fs_manager.cc:696] Time spent creating directory manager: real 0.001s	user 0.002s	sys 0.000s
I20260812 06:18:44.248256 32562 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:18:44.248611 32341 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.001s	sys 0.000s
I20260812 06:18:44.248692 32341 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskchnxcB/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515518376868-32341-0/minicluster-data/master-0-root
uuid: "9e823c92132248f0b3a45df8806c5d56"
format_stamp: "Formatted at 2026-08-12 06:18:44 on dist-test-slave-rgb1"
I20260812 06:18:44.248751 32341 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskchnxcB/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515518376868-32341-0/minicluster-data/master-0-root
metadata directory: /tmp/dist-test-taskchnxcB/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515518376868-32341-0/minicluster-data/master-0-root
1 data directories: /tmp/dist-test-taskchnxcB/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515518376868-32341-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:18:44.263492 32341 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:18:44.263924 32341 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:18:44.268365 32341 rpc_server.cc:307] RPC server started. Bound to: 127.31.149.126:36959
I20260812 06:18:44.276808 32625 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.31.149.126:36959 every 8 connection(s)
I20260812 06:18:44.277381 32626 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:18:44.279317 32626 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P 9e823c92132248f0b3a45df8806c5d56: Bootstrap starting.
I20260812 06:18:44.280292 32626 tablet_bootstrap.cc:654] T 00000000000000000000000000000000 P 9e823c92132248f0b3a45df8806c5d56: Neither blocks nor log segments found. Creating new log.
I20260812 06:18:44.281594 32626 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P 9e823c92132248f0b3a45df8806c5d56: No bootstrap required, opened a new log
I20260812 06:18:44.282016 32626 raft_consensus.cc:359] T 00000000000000000000000000000000 P 9e823c92132248f0b3a45df8806c5d56 [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "9e823c92132248f0b3a45df8806c5d56" member_type: VOTER }
I20260812 06:18:44.282107 32626 raft_consensus.cc:385] T 00000000000000000000000000000000 P 9e823c92132248f0b3a45df8806c5d56 [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:18:44.282130 32626 raft_consensus.cc:740] T 00000000000000000000000000000000 P 9e823c92132248f0b3a45df8806c5d56 [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: 9e823c92132248f0b3a45df8806c5d56, State: Initialized, Role: FOLLOWER
I20260812 06:18:44.282291 32626 consensus_queue.cc:260] T 00000000000000000000000000000000 P 9e823c92132248f0b3a45df8806c5d56 [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: "9e823c92132248f0b3a45df8806c5d56" member_type: VOTER }
I20260812 06:18:44.282383 32626 raft_consensus.cc:399] T 00000000000000000000000000000000 P 9e823c92132248f0b3a45df8806c5d56 [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:18:44.282415 32626 raft_consensus.cc:493] T 00000000000000000000000000000000 P 9e823c92132248f0b3a45df8806c5d56 [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:18:44.282454 32626 raft_consensus.cc:3060] T 00000000000000000000000000000000 P 9e823c92132248f0b3a45df8806c5d56 [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:18:44.283154 32626 raft_consensus.cc:515] T 00000000000000000000000000000000 P 9e823c92132248f0b3a45df8806c5d56 [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "9e823c92132248f0b3a45df8806c5d56" member_type: VOTER }
I20260812 06:18:44.283268 32626 leader_election.cc:304] T 00000000000000000000000000000000 P 9e823c92132248f0b3a45df8806c5d56 [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: 9e823c92132248f0b3a45df8806c5d56; no voters: 
I20260812 06:18:44.283433 32626 leader_election.cc:290] T 00000000000000000000000000000000 P 9e823c92132248f0b3a45df8806c5d56 [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:18:44.283631 32629 raft_consensus.cc:2804] T 00000000000000000000000000000000 P 9e823c92132248f0b3a45df8806c5d56 [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:18:44.283851 32629 raft_consensus.cc:697] T 00000000000000000000000000000000 P 9e823c92132248f0b3a45df8806c5d56 [term 1 LEADER]: Becoming Leader. State: Replica: 9e823c92132248f0b3a45df8806c5d56, State: Running, Role: LEADER
I20260812 06:18:44.283926 32626 sys_catalog.cc:565] T 00000000000000000000000000000000 P 9e823c92132248f0b3a45df8806c5d56 [sys.catalog]: configured and running, proceeding with master startup.
I20260812 06:18:44.283989 32629 consensus_queue.cc:237] T 00000000000000000000000000000000 P 9e823c92132248f0b3a45df8806c5d56 [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: "9e823c92132248f0b3a45df8806c5d56" member_type: VOTER }
I20260812 06:18:44.284466 32630 sys_catalog.cc:455] T 00000000000000000000000000000000 P 9e823c92132248f0b3a45df8806c5d56 [sys.catalog]: SysCatalogTable state changed. Reason: RaftConsensus started. Latest consensus state: current_term: 1 leader_uuid: "9e823c92132248f0b3a45df8806c5d56" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "9e823c92132248f0b3a45df8806c5d56" member_type: VOTER } }
I20260812 06:18:44.284502 32631 sys_catalog.cc:455] T 00000000000000000000000000000000 P 9e823c92132248f0b3a45df8806c5d56 [sys.catalog]: SysCatalogTable state changed. Reason: New leader 9e823c92132248f0b3a45df8806c5d56. Latest consensus state: current_term: 1 leader_uuid: "9e823c92132248f0b3a45df8806c5d56" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "9e823c92132248f0b3a45df8806c5d56" member_type: VOTER } }
I20260812 06:18:44.284581 32630 sys_catalog.cc:458] T 00000000000000000000000000000000 P 9e823c92132248f0b3a45df8806c5d56 [sys.catalog]: This master's current role is: LEADER
I20260812 06:18:44.284607 32631 sys_catalog.cc:458] T 00000000000000000000000000000000 P 9e823c92132248f0b3a45df8806c5d56 [sys.catalog]: This master's current role is: LEADER
I20260812 06:18:44.285215 32637 catalog_manager.cc:1511] Loading table and tablet metadata into memory...
I20260812 06:18:44.285904 32637 catalog_manager.cc:1520] Initializing Kudu cluster ID...
I20260812 06:18:44.286085 32341 internal_mini_cluster.cc:184] Waiting to initialize catalog manager on master 0
I20260812 06:18:44.287741 32637 catalog_manager.cc:1383] Generated new cluster ID: d99eaa702451475f85ded1181d8b3d7c
I20260812 06:18:44.287806 32637 catalog_manager.cc:1531] Initializing Kudu internal certificate authority...
I20260812 06:18:44.308260 32637 catalog_manager.cc:1406] Generated new certificate authority record
I20260812 06:18:44.309123 32637 catalog_manager.cc:1540] Loading token signing keys...
I20260812 06:18:44.314455 32637 catalog_manager.cc:6092] T 00000000000000000000000000000000 P 9e823c92132248f0b3a45df8806c5d56: Generated new TSK 0
I20260812 06:18:44.314690 32637 catalog_manager.cc:1550] Initializing in-progress tserver states...
I20260812 06:18:44.318888 32341 file_cache.cc:504] Constructed file cache file cache with capacity 419430
I20260812 06:18:44.321544 32341 server_base.cc:1061] running on GCE node
W20260812 06:18:44.321592 32650 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:18:44.321587 32649 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:18:44.321559 32652 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:18:44.321954 32341 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:18:44.322007 32341 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:18:44.322024 32341 hybrid_clock.cc:648] HybridClock initialized: now 1786515524322024 us; error 0 us; skew 500 ppm
I20260812 06:18:44.322872 32341 webserver.cc:533] Webserver started at http://127.31.149.65:40343/ using document root <none> and password file <none>
I20260812 06:18:44.323071 32341 fs_manager.cc:362] Metadata directory not provided
I20260812 06:18:44.323124 32341 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:18:44.323180 32341 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:18:44.323611 32341 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskchnxcB/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515518376868-32341-0/minicluster-data/ts-0-root/instance:
uuid: "e5f5a784f9b5488e91d309863a3a17dc"
format_stamp: "Formatted at 2026-08-12 06:18:44 on dist-test-slave-rgb1"
I20260812 06:18:44.325357 32341 fs_manager.cc:696] Time spent creating directory manager: real 0.002s	user 0.000s	sys 0.002s
I20260812 06:18:44.326651 32657 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:18:44.327203 32341 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.000s	sys 0.001s
I20260812 06:18:44.327322 32341 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskchnxcB/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515518376868-32341-0/minicluster-data/ts-0-root
uuid: "e5f5a784f9b5488e91d309863a3a17dc"
format_stamp: "Formatted at 2026-08-12 06:18:44 on dist-test-slave-rgb1"
I20260812 06:18:44.327430 32341 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskchnxcB/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515518376868-32341-0/minicluster-data/ts-0-root
metadata directory: /tmp/dist-test-taskchnxcB/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515518376868-32341-0/minicluster-data/ts-0-root
1 data directories: /tmp/dist-test-taskchnxcB/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515518376868-32341-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:18:44.368237 32341 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:18:44.368762 32341 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:18:44.369104 32341 txn_system_client.cc:432] TxnSystemClient initialization is disabled...
I20260812 06:18:44.369581 32341 ts_tablet_manager.cc:585] Loaded tablet metadata (0 total tablets, 0 live tablets)
I20260812 06:18:44.369640 32341 ts_tablet_manager.cc:531] Time spent load tablet metadata: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:18:44.369701 32341 ts_tablet_manager.cc:616] Registered 0 tablets
I20260812 06:18:44.369751 32341 ts_tablet_manager.cc:595] Time spent register tablets: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:18:44.374387 32341 rpc_server.cc:307] RPC server started. Bound to: 127.31.149.65:43977
I20260812 06:18:44.375142 32724 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.31.149.65:43977 every 8 connection(s)
I20260812 06:18:44.380704 32726 heartbeater.cc:344] Connected to a master server at 127.31.149.126:36959
I20260812 06:18:44.380890 32726 heartbeater.cc:461] Registering TS with master...
I20260812 06:18:44.381121 32726 heartbeater.cc:507] Master 127.31.149.126:36959 requested a full tablet report, sending...
I20260812 06:18:44.382009 32580 ts_manager.cc:194] Registered new tserver with Master: e5f5a784f9b5488e91d309863a3a17dc (127.31.149.65:43977)
I20260812 06:18:44.382382 32341 internal_mini_cluster.cc:371] 1 TS(s) registered with all masters after 0.006930237s
I20260812 06:18:44.382910 32580 master_service.cc:502] Signed X509 certificate for tserver {username='slave'} at 127.0.0.1:56194
I20260812 06:18:44.391284 32580 catalog_manager.cc:2283] Servicing CreateTable request from {username='slave'} at 127.0.0.1:56202:
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:18:44.401451 32686 tablet_service.cc:1511] Processing CreateTablet for tablet 06769acc457c4bcd811ff29d953de070 (DEFAULT_TABLE table=heavy-update-compaction-test [id=5dbe153ebdc146849c0e1483b7e60ce1]), partition=
I20260812 06:18:44.401795 32686 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet 06769acc457c4bcd811ff29d953de070. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:18:44.404212 32739 tablet_bootstrap.cc:492] T 06769acc457c4bcd811ff29d953de070 P e5f5a784f9b5488e91d309863a3a17dc: Bootstrap starting.
I20260812 06:18:44.405237 32739 tablet_bootstrap.cc:654] T 06769acc457c4bcd811ff29d953de070 P e5f5a784f9b5488e91d309863a3a17dc: Neither blocks nor log segments found. Creating new log.
I20260812 06:18:44.406350 32739 tablet_bootstrap.cc:492] T 06769acc457c4bcd811ff29d953de070 P e5f5a784f9b5488e91d309863a3a17dc: No bootstrap required, opened a new log
I20260812 06:18:44.406450 32739 ts_tablet_manager.cc:1403] T 06769acc457c4bcd811ff29d953de070 P e5f5a784f9b5488e91d309863a3a17dc: Time spent bootstrapping tablet: real 0.002s	user 0.002s	sys 0.000s
I20260812 06:18:44.407015 32739 raft_consensus.cc:359] T 06769acc457c4bcd811ff29d953de070 P e5f5a784f9b5488e91d309863a3a17dc [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "e5f5a784f9b5488e91d309863a3a17dc" member_type: VOTER last_known_addr { host: "127.31.149.65" port: 43977 } }
I20260812 06:18:44.407125 32739 raft_consensus.cc:385] T 06769acc457c4bcd811ff29d953de070 P e5f5a784f9b5488e91d309863a3a17dc [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:18:44.407178 32739 raft_consensus.cc:740] T 06769acc457c4bcd811ff29d953de070 P e5f5a784f9b5488e91d309863a3a17dc [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: e5f5a784f9b5488e91d309863a3a17dc, State: Initialized, Role: FOLLOWER
I20260812 06:18:44.407320 32739 consensus_queue.cc:260] T 06769acc457c4bcd811ff29d953de070 P e5f5a784f9b5488e91d309863a3a17dc [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: "e5f5a784f9b5488e91d309863a3a17dc" member_type: VOTER last_known_addr { host: "127.31.149.65" port: 43977 } }
I20260812 06:18:44.407394 32739 raft_consensus.cc:399] T 06769acc457c4bcd811ff29d953de070 P e5f5a784f9b5488e91d309863a3a17dc [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:18:44.407437 32739 raft_consensus.cc:493] T 06769acc457c4bcd811ff29d953de070 P e5f5a784f9b5488e91d309863a3a17dc [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:18:44.407505 32739 raft_consensus.cc:3060] T 06769acc457c4bcd811ff29d953de070 P e5f5a784f9b5488e91d309863a3a17dc [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:18:44.408444 32739 raft_consensus.cc:515] T 06769acc457c4bcd811ff29d953de070 P e5f5a784f9b5488e91d309863a3a17dc [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "e5f5a784f9b5488e91d309863a3a17dc" member_type: VOTER last_known_addr { host: "127.31.149.65" port: 43977 } }
I20260812 06:18:44.408713 32739 leader_election.cc:304] T 06769acc457c4bcd811ff29d953de070 P e5f5a784f9b5488e91d309863a3a17dc [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: e5f5a784f9b5488e91d309863a3a17dc; no voters: 
I20260812 06:18:44.409006 32739 leader_election.cc:290] T 06769acc457c4bcd811ff29d953de070 P e5f5a784f9b5488e91d309863a3a17dc [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:18:44.409219 32741 raft_consensus.cc:2804] T 06769acc457c4bcd811ff29d953de070 P e5f5a784f9b5488e91d309863a3a17dc [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:18:44.409387 32726 heartbeater.cc:499] Master 127.31.149.126:36959 was elected leader, sending a full tablet report...
I20260812 06:18:44.409404 32739 ts_tablet_manager.cc:1434] T 06769acc457c4bcd811ff29d953de070 P e5f5a784f9b5488e91d309863a3a17dc: Time spent starting tablet: real 0.003s	user 0.003s	sys 0.000s
I20260812 06:18:44.409479 32741 raft_consensus.cc:697] T 06769acc457c4bcd811ff29d953de070 P e5f5a784f9b5488e91d309863a3a17dc [term 1 LEADER]: Becoming Leader. State: Replica: e5f5a784f9b5488e91d309863a3a17dc, State: Running, Role: LEADER
I20260812 06:18:44.409632 32741 consensus_queue.cc:237] T 06769acc457c4bcd811ff29d953de070 P e5f5a784f9b5488e91d309863a3a17dc [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: "e5f5a784f9b5488e91d309863a3a17dc" member_type: VOTER last_known_addr { host: "127.31.149.65" port: 43977 } }
I20260812 06:18:44.411367 32580 catalog_manager.cc:5719] T 06769acc457c4bcd811ff29d953de070 P e5f5a784f9b5488e91d309863a3a17dc reported cstate change: term changed from 0 to 1, leader changed from <none> to e5f5a784f9b5488e91d309863a3a17dc (127.31.149.65). New cstate: current_term: 1 leader_uuid: "e5f5a784f9b5488e91d309863a3a17dc" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "e5f5a784f9b5488e91d309863a3a17dc" member_type: VOTER last_known_addr { host: "127.31.149.65" port: 43977 } health_report { overall_health: HEALTHY } } }
I20260812 06:18:44.477195 32341 heavy-update-compaction-itest.cc:215] Time spent inserting: real 0.056s	user 0.016s	sys 0.008s
I20260812 06:18:44.626036 32727 maintenance_manager.cc:419] P e5f5a784f9b5488e91d309863a3a17dc: Scheduling FlushMRSOp(06769acc457c4bcd811ff29d953de070): perf score=16.078378
I20260812 06:18:44.793771 32662 maintenance_manager.cc:643] P e5f5a784f9b5488e91d309863a3a17dc: FlushMRSOp(06769acc457c4bcd811ff29d953de070) complete. Timing: real 0.167s	user 0.130s	sys 0.029s Metrics: {"bytes_written":12307489,"cfile_init":1,"delete_count":0,"dirs.queue_time_us":76,"dirs.run_cpu_time_us":202,"dirs.run_wall_time_us":1016,"drs_written":1,"lbm_read_time_us":58,"lbm_reads_lt_1ms":4,"lbm_write_time_us":37808,"lbm_writes_lt_1ms":757,"peak_mem_usage":0,"reinsert_count":0,"rows_written":104,"update_count":1500}
I20260812 06:18:44.794487 32727 maintenance_manager.cc:419] P e5f5a784f9b5488e91d309863a3a17dc: Scheduling LogGCOp(06769acc457c4bcd811ff29d953de070): free 20743880 bytes of WAL
I20260812 06:18:44.794766 32662 log_reader.cc:385] T 06769acc457c4bcd811ff29d953de070: removed 2 log segments from log reader
I20260812 06:18:44.794850 32662 log.cc:1079] T 06769acc457c4bcd811ff29d953de070 P e5f5a784f9b5488e91d309863a3a17dc: Deleting log segment in path: /tmp/dist-test-taskchnxcB/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515518376868-32341-0/minicluster-data/ts-0-root/wals/06769acc457c4bcd811ff29d953de070/wal-000000001 (ops 1-6)
I20260812 06:18:44.794914 32662 log.cc:1079] T 06769acc457c4bcd811ff29d953de070 P e5f5a784f9b5488e91d309863a3a17dc: Deleting log segment in path: /tmp/dist-test-taskchnxcB/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515518376868-32341-0/minicluster-data/ts-0-root/wals/06769acc457c4bcd811ff29d953de070/wal-000000002 (ops 7-11)
I20260812 06:18:44.799038 32662 maintenance_manager.cc:643] P e5f5a784f9b5488e91d309863a3a17dc: LogGCOp(06769acc457c4bcd811ff29d953de070) complete. Timing: real 0.004s	user 0.000s	sys 0.002s Metrics: {}
I20260812 06:18:44.799437 32727 maintenance_manager.cc:419] P e5f5a784f9b5488e91d309863a3a17dc: Scheduling UndoDeltaBlockGCOp(06769acc457c4bcd811ff29d953de070): 16411394 bytes on disk
I20260812 06:18:44.799947 32662 maintenance_manager.cc:643] P e5f5a784f9b5488e91d309863a3a17dc: UndoDeltaBlockGCOp(06769acc457c4bcd811ff29d953de070) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":61,"lbm_reads_lt_1ms":4}
I20260812 06:18:44.800379 32727 maintenance_manager.cc:419] P e5f5a784f9b5488e91d309863a3a17dc: Scheduling FlushDeltaMemStoresOp(06769acc457c4bcd811ff29d953de070): perf score=2.188937
I20260812 06:18:44.811743 32662 maintenance_manager.cc:643] P e5f5a784f9b5488e91d309863a3a17dc: FlushDeltaMemStoresOp(06769acc457c4bcd811ff29d953de070) complete. Timing: real 0.011s	user 0.001s	sys 0.007s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4301,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:44.812527 32727 maintenance_manager.cc:419] P e5f5a784f9b5488e91d309863a3a17dc: Scheduling MajorDeltaCompactionOp(06769acc457c4bcd811ff29d953de070): perf score=1.000000
I20260812 06:18:44.967801 32662 maintenance_manager.cc:643] P e5f5a784f9b5488e91d309863a3a17dc: MajorDeltaCompactionOp(06769acc457c4bcd811ff29d953de070) complete. Timing: real 0.155s	user 0.122s	sys 0.033s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672276,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":541,"lbm_read_time_us":11270,"lbm_reads_lt_1ms":464,"lbm_write_time_us":25618,"lbm_writes_lt_1ms":443,"peak_mem_usage":50689328,"reinsert_count":0,"thread_start_us":336,"threads_started":5,"update_count":2000}
I20260812 06:18:44.968971 32727 maintenance_manager.cc:419] P e5f5a784f9b5488e91d309863a3a17dc: Scheduling FlushDeltaMemStoresOp(06769acc457c4bcd811ff29d953de070): perf score=10.126437
I20260812 06:18:45.014513 32662 maintenance_manager.cc:643] P e5f5a784f9b5488e91d309863a3a17dc: FlushDeltaMemStoresOp(06769acc457c4bcd811ff29d953de070) complete. Timing: real 0.045s	user 0.018s	sys 0.025s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":21160,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":302,"reinsert_count":0,"update_count":1500}
I20260812 06:18:45.015126 32727 maintenance_manager.cc:419] P e5f5a784f9b5488e91d309863a3a17dc: Scheduling FlushDeltaMemStoresOp(06769acc457c4bcd811ff29d953de070): perf score=2.188937
I20260812 06:18:45.033569 32662 maintenance_manager.cc:643] P e5f5a784f9b5488e91d309863a3a17dc: FlushDeltaMemStoresOp(06769acc457c4bcd811ff29d953de070) complete. Timing: real 0.018s	user 0.008s	sys 0.009s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":6930,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:45.034155 32727 maintenance_manager.cc:419] P e5f5a784f9b5488e91d309863a3a17dc: Scheduling MajorDeltaCompactionOp(06769acc457c4bcd811ff29d953de070): perf score=1.000000
I20260812 06:18:45.173089 32662 maintenance_manager.cc:643] P e5f5a784f9b5488e91d309863a3a17dc: MajorDeltaCompactionOp(06769acc457c4bcd811ff29d953de070) complete. Timing: real 0.139s	user 0.090s	sys 0.047s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672276,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":902,"lbm_read_time_us":7566,"lbm_reads_lt_1ms":464,"lbm_write_time_us":27558,"lbm_writes_lt_1ms":443,"mutex_wait_us":26,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":7424,"update_count":2000}
I20260812 06:18:45.174993 32727 maintenance_manager.cc:419] P e5f5a784f9b5488e91d309863a3a17dc: Scheduling FlushDeltaMemStoresOp(06769acc457c4bcd811ff29d953de070): perf score=10.126437
I20260812 06:18:45.218283 32662 maintenance_manager.cc:643] P e5f5a784f9b5488e91d309863a3a17dc: FlushDeltaMemStoresOp(06769acc457c4bcd811ff29d953de070) complete. Timing: real 0.043s	user 0.029s	sys 0.012s Metrics: {"bytes_written":12307491,"delete_count":0,"lbm_write_time_us":19247,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:18:45.218832 32727 maintenance_manager.cc:419] P e5f5a784f9b5488e91d309863a3a17dc: Scheduling FlushDeltaMemStoresOp(06769acc457c4bcd811ff29d953de070): perf score=2.188937
I20260812 06:18:45.238168 32662 maintenance_manager.cc:643] P e5f5a784f9b5488e91d309863a3a17dc: FlushDeltaMemStoresOp(06769acc457c4bcd811ff29d953de070) complete. Timing: real 0.019s	user 0.013s	sys 0.000s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":5070,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:45.238950 32727 maintenance_manager.cc:419] P e5f5a784f9b5488e91d309863a3a17dc: Scheduling MajorDeltaCompactionOp(06769acc457c4bcd811ff29d953de070): perf score=1.000000
I20260812 06:18:45.378263 32662 maintenance_manager.cc:643] P e5f5a784f9b5488e91d309863a3a17dc: MajorDeltaCompactionOp(06769acc457c4bcd811ff29d953de070) complete. Timing: real 0.139s	user 0.116s	sys 0.023s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672277,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":1133,"lbm_read_time_us":9569,"lbm_reads_lt_1ms":464,"lbm_write_time_us":27086,"lbm_writes_lt_1ms":443,"mutex_wait_us":42,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":7552,"update_count":2000}
I20260812 06:18:45.378984 32727 maintenance_manager.cc:419] P e5f5a784f9b5488e91d309863a3a17dc: Scheduling FlushDeltaMemStoresOp(06769acc457c4bcd811ff29d953de070): perf score=10.126437
I20260812 06:18:45.429543 32662 maintenance_manager.cc:643] P e5f5a784f9b5488e91d309863a3a17dc: FlushDeltaMemStoresOp(06769acc457c4bcd811ff29d953de070) complete. Timing: real 0.050s	user 0.038s	sys 0.003s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":18187,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:18:45.430480 32727 maintenance_manager.cc:419] P e5f5a784f9b5488e91d309863a3a17dc: Scheduling FlushDeltaMemStoresOp(06769acc457c4bcd811ff29d953de070): perf score=2.188937
I20260812 06:18:45.441632 32662 maintenance_manager.cc:643] P e5f5a784f9b5488e91d309863a3a17dc: FlushDeltaMemStoresOp(06769acc457c4bcd811ff29d953de070) complete. Timing: real 0.011s	user 0.010s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4116,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:45.442338 32727 maintenance_manager.cc:419] P e5f5a784f9b5488e91d309863a3a17dc: Scheduling MajorDeltaCompactionOp(06769acc457c4bcd811ff29d953de070): perf score=1.000000
I20260812 06:18:45.584388 32662 maintenance_manager.cc:643] P e5f5a784f9b5488e91d309863a3a17dc: MajorDeltaCompactionOp(06769acc457c4bcd811ff29d953de070) complete. Timing: real 0.142s	user 0.109s	sys 0.032s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672277,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":1659,"lbm_read_time_us":9256,"lbm_reads_lt_1ms":472,"lbm_write_time_us":28410,"lbm_writes_lt_1ms":443,"mutex_wait_us":150,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":6784,"update_count":2000}
I20260812 06:18:45.585716 32727 maintenance_manager.cc:419] P e5f5a784f9b5488e91d309863a3a17dc: Scheduling FlushDeltaMemStoresOp(06769acc457c4bcd811ff29d953de070): perf score=10.126437
I20260812 06:18:45.636879 32662 maintenance_manager.cc:643] P e5f5a784f9b5488e91d309863a3a17dc: FlushDeltaMemStoresOp(06769acc457c4bcd811ff29d953de070) complete. Timing: real 0.050s	user 0.029s	sys 0.015s Metrics: {"bytes_written":12307491,"delete_count":0,"lbm_write_time_us":16050,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:18:45.637696 32727 maintenance_manager.cc:419] P e5f5a784f9b5488e91d309863a3a17dc: Scheduling FlushDeltaMemStoresOp(06769acc457c4bcd811ff29d953de070): perf score=2.188937
I20260812 06:18:45.648958 32662 maintenance_manager.cc:643] P e5f5a784f9b5488e91d309863a3a17dc: FlushDeltaMemStoresOp(06769acc457c4bcd811ff29d953de070) complete. Timing: real 0.011s	user 0.006s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4303,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:45.649446 32727 maintenance_manager.cc:419] P e5f5a784f9b5488e91d309863a3a17dc: Scheduling MajorDeltaCompactionOp(06769acc457c4bcd811ff29d953de070): perf score=1.000000
I20260812 06:18:45.803133 32662 maintenance_manager.cc:643] P e5f5a784f9b5488e91d309863a3a17dc: MajorDeltaCompactionOp(06769acc457c4bcd811ff29d953de070) complete. Timing: real 0.154s	user 0.118s	sys 0.036s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672278,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":218,"lbm_read_time_us":10673,"lbm_reads_lt_1ms":472,"lbm_write_time_us":24407,"lbm_writes_lt_1ms":443,"mutex_wait_us":53,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":14848,"update_count":2000}
I20260812 06:18:45.803824 32727 maintenance_manager.cc:419] P e5f5a784f9b5488e91d309863a3a17dc: Scheduling FlushDeltaMemStoresOp(06769acc457c4bcd811ff29d953de070): perf score=10.126437
I20260812 06:18:45.852941 32662 maintenance_manager.cc:643] P e5f5a784f9b5488e91d309863a3a17dc: FlushDeltaMemStoresOp(06769acc457c4bcd811ff29d953de070) complete. Timing: real 0.049s	user 0.018s	sys 0.016s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":14859,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:18:45.853781 32727 maintenance_manager.cc:419] P e5f5a784f9b5488e91d309863a3a17dc: Scheduling FlushDeltaMemStoresOp(06769acc457c4bcd811ff29d953de070): perf score=2.188937
I20260812 06:18:45.867831 32662 maintenance_manager.cc:643] P e5f5a784f9b5488e91d309863a3a17dc: FlushDeltaMemStoresOp(06769acc457c4bcd811ff29d953de070) complete. Timing: real 0.014s	user 0.008s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4961,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:45.868314 32727 maintenance_manager.cc:419] P e5f5a784f9b5488e91d309863a3a17dc: Scheduling MajorDeltaCompactionOp(06769acc457c4bcd811ff29d953de070): perf score=1.000000
I20260812 06:18:46.009864 32662 maintenance_manager.cc:643] P e5f5a784f9b5488e91d309863a3a17dc: MajorDeltaCompactionOp(06769acc457c4bcd811ff29d953de070) complete. Timing: real 0.141s	user 0.109s	sys 0.031s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672277,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":1045,"lbm_read_time_us":11042,"lbm_reads_lt_1ms":472,"lbm_write_time_us":27149,"lbm_writes_lt_1ms":443,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":896,"update_count":2000}
I20260812 06:18:46.010941 32727 maintenance_manager.cc:419] P e5f5a784f9b5488e91d309863a3a17dc: Scheduling FlushDeltaMemStoresOp(06769acc457c4bcd811ff29d953de070): perf score=10.126437
I20260812 06:18:46.054045 32662 maintenance_manager.cc:643] P e5f5a784f9b5488e91d309863a3a17dc: FlushDeltaMemStoresOp(06769acc457c4bcd811ff29d953de070) complete. Timing: real 0.043s	user 0.029s	sys 0.012s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":18572,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:18:46.054625 32727 maintenance_manager.cc:419] P e5f5a784f9b5488e91d309863a3a17dc: Scheduling FlushDeltaMemStoresOp(06769acc457c4bcd811ff29d953de070): perf score=2.188937
I20260812 06:18:46.071323 32662 maintenance_manager.cc:643] P e5f5a784f9b5488e91d309863a3a17dc: FlushDeltaMemStoresOp(06769acc457c4bcd811ff29d953de070) complete. Timing: real 0.016s	user 0.009s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6314,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:46.072052 32727 maintenance_manager.cc:419] P e5f5a784f9b5488e91d309863a3a17dc: Scheduling FlushMRSOp(06769acc457c4bcd811ff29d953de070): perf score=1.000000
I20260812 06:18:46.104534 32662 maintenance_manager.cc:643] P e5f5a784f9b5488e91d309863a3a17dc: FlushMRSOp(06769acc457c4bcd811ff29d953de070) complete. Timing: real 0.032s	user 0.027s	sys 0.004s Metrics: {"bytes_written":1152508,"cfile_init":1,"dirs.queue_time_us":99,"dirs.run_cpu_time_us":340,"dirs.run_wall_time_us":1717,"drs_written":1,"lbm_read_time_us":65,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1565,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":28}
I20260812 06:18:46.105428 32727 maintenance_manager.cc:419] P e5f5a784f9b5488e91d309863a3a17dc: Scheduling LogGCOp(06769acc457c4bcd811ff29d953de070): free 112692375 bytes of WAL
I20260812 06:18:46.105705 32662 log_reader.cc:385] T 06769acc457c4bcd811ff29d953de070: removed 11 log segments from log reader
I20260812 06:18:46.105785 32662 log.cc:1079] T 06769acc457c4bcd811ff29d953de070 P e5f5a784f9b5488e91d309863a3a17dc: Deleting log segment in path: /tmp/dist-test-taskchnxcB/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515518376868-32341-0/minicluster-data/ts-0-root/wals/06769acc457c4bcd811ff29d953de070/wal-000000003 (ops 12-16)
I20260812 06:18:46.105847 32662 log.cc:1079] T 06769acc457c4bcd811ff29d953de070 P e5f5a784f9b5488e91d309863a3a17dc: Deleting log segment in path: /tmp/dist-test-taskchnxcB/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515518376868-32341-0/minicluster-data/ts-0-root/wals/06769acc457c4bcd811ff29d953de070/wal-000000004 (ops 17-21)
I20260812 06:18:46.105887 32662 log.cc:1079] T 06769acc457c4bcd811ff29d953de070 P e5f5a784f9b5488e91d309863a3a17dc: Deleting log segment in path: /tmp/dist-test-taskchnxcB/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515518376868-32341-0/minicluster-data/ts-0-root/wals/06769acc457c4bcd811ff29d953de070/wal-000000005 (ops 22-26)
I20260812 06:18:46.105924 32662 log.cc:1079] T 06769acc457c4bcd811ff29d953de070 P e5f5a784f9b5488e91d309863a3a17dc: Deleting log segment in path: /tmp/dist-test-taskchnxcB/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515518376868-32341-0/minicluster-data/ts-0-root/wals/06769acc457c4bcd811ff29d953de070/wal-000000006 (ops 27-31)
I20260812 06:18:46.105962 32662 log.cc:1079] T 06769acc457c4bcd811ff29d953de070 P e5f5a784f9b5488e91d309863a3a17dc: Deleting log segment in path: /tmp/dist-test-taskchnxcB/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515518376868-32341-0/minicluster-data/ts-0-root/wals/06769acc457c4bcd811ff29d953de070/wal-000000007 (ops 32-36)
I20260812 06:18:46.106010 32662 log.cc:1079] T 06769acc457c4bcd811ff29d953de070 P e5f5a784f9b5488e91d309863a3a17dc: Deleting log segment in path: /tmp/dist-test-taskchnxcB/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515518376868-32341-0/minicluster-data/ts-0-root/wals/06769acc457c4bcd811ff29d953de070/wal-000000008 (ops 37-41)
I20260812 06:18:46.106052 32662 log.cc:1079] T 06769acc457c4bcd811ff29d953de070 P e5f5a784f9b5488e91d309863a3a17dc: Deleting log segment in path: /tmp/dist-test-taskchnxcB/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515518376868-32341-0/minicluster-data/ts-0-root/wals/06769acc457c4bcd811ff29d953de070/wal-000000009 (ops 42-46)
I20260812 06:18:46.106093 32662 log.cc:1079] T 06769acc457c4bcd811ff29d953de070 P e5f5a784f9b5488e91d309863a3a17dc: Deleting log segment in path: /tmp/dist-test-taskchnxcB/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515518376868-32341-0/minicluster-data/ts-0-root/wals/06769acc457c4bcd811ff29d953de070/wal-000000010 (ops 47-51)
I20260812 06:18:46.106134 32662 log.cc:1079] T 06769acc457c4bcd811ff29d953de070 P e5f5a784f9b5488e91d309863a3a17dc: Deleting log segment in path: /tmp/dist-test-taskchnxcB/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515518376868-32341-0/minicluster-data/ts-0-root/wals/06769acc457c4bcd811ff29d953de070/wal-000000011 (ops 52-56)
I20260812 06:18:46.106174 32662 log.cc:1079] T 06769acc457c4bcd811ff29d953de070 P e5f5a784f9b5488e91d309863a3a17dc: Deleting log segment in path: /tmp/dist-test-taskchnxcB/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515518376868-32341-0/minicluster-data/ts-0-root/wals/06769acc457c4bcd811ff29d953de070/wal-000000012 (ops 57-61)
I20260812 06:18:46.106215 32662 log.cc:1079] T 06769acc457c4bcd811ff29d953de070 P e5f5a784f9b5488e91d309863a3a17dc: Deleting log segment in path: /tmp/dist-test-taskchnxcB/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515518376868-32341-0/minicluster-data/ts-0-root/wals/06769acc457c4bcd811ff29d953de070/wal-000000013 (ops 62-66)
I20260812 06:18:46.132694 32662 maintenance_manager.cc:643] P e5f5a784f9b5488e91d309863a3a17dc: LogGCOp(06769acc457c4bcd811ff29d953de070) complete. Timing: real 0.027s	user 0.000s	sys 0.027s Metrics: {}
I20260812 06:18:46.133225 32727 maintenance_manager.cc:419] P e5f5a784f9b5488e91d309863a3a17dc: Scheduling FlushDeltaMemStoresOp(06769acc457c4bcd811ff29d953de070): perf score=3.181125
I20260812 06:18:46.150192 32662 maintenance_manager.cc:643] P e5f5a784f9b5488e91d309863a3a17dc: FlushDeltaMemStoresOp(06769acc457c4bcd811ff29d953de070) complete. Timing: real 0.017s	user 0.003s	sys 0.009s Metrics: {"bytes_written":4512903,"delete_count":0,"lbm_write_time_us":5424,"lbm_writes_lt_1ms":113,"reinsert_count":0,"update_count":550}
I20260812 06:18:46.150642 32727 maintenance_manager.cc:419] P e5f5a784f9b5488e91d309863a3a17dc: Scheduling UndoDeltaBlockGCOp(06769acc457c4bcd811ff29d953de070): 448 bytes on disk
I20260812 06:18:46.151036 32662 maintenance_manager.cc:643] P e5f5a784f9b5488e91d309863a3a17dc: UndoDeltaBlockGCOp(06769acc457c4bcd811ff29d953de070) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":54,"lbm_reads_lt_1ms":4}
I20260812 06:18:46.151453 32727 maintenance_manager.cc:419] P e5f5a784f9b5488e91d309863a3a17dc: Scheduling FlushDeltaMemStoresOp(06769acc457c4bcd811ff29d953de070): perf score=2.188937
I20260812 06:18:46.161852 32662 maintenance_manager.cc:643] P e5f5a784f9b5488e91d309863a3a17dc: FlushDeltaMemStoresOp(06769acc457c4bcd811ff29d953de070) complete. Timing: real 0.010s	user 0.005s	sys 0.004s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3866,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:18:46.162348 32727 maintenance_manager.cc:419] P e5f5a784f9b5488e91d309863a3a17dc: Scheduling MajorDeltaCompactionOp(06769acc457c4bcd811ff29d953de070): perf score=1.000000
I20260812 06:18:46.358680 32662 maintenance_manager.cc:643] P e5f5a784f9b5488e91d309863a3a17dc: MajorDeltaCompactionOp(06769acc457c4bcd811ff29d953de070) complete. Timing: real 0.196s	user 0.171s	sys 0.023s Metrics: {"cfile_cache_miss":634,"cfile_cache_miss_bytes":28877329,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":485,"lbm_read_time_us":14140,"lbm_reads_lt_1ms":674,"lbm_write_time_us":39748,"lbm_writes_lt_1ms":643,"mutex_wait_us":47,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":4864,"thread_start_us":85,"threads_started":1,"update_count":3000}
I20260812 06:18:46.359454 32727 maintenance_manager.cc:419] P e5f5a784f9b5488e91d309863a3a17dc: Scheduling FlushDeltaMemStoresOp(06769acc457c4bcd811ff29d953de070): perf score=14.095187
I20260812 06:18:46.418658 32662 maintenance_manager.cc:643] P e5f5a784f9b5488e91d309863a3a17dc: FlushDeltaMemStoresOp(06769acc457c4bcd811ff29d953de070) complete. Timing: real 0.059s	user 0.021s	sys 0.035s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":25706,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":402,"reinsert_count":0,"update_count":2000}
I20260812 06:18:46.419324 32727 maintenance_manager.cc:419] P e5f5a784f9b5488e91d309863a3a17dc: Scheduling FlushDeltaMemStoresOp(06769acc457c4bcd811ff29d953de070): perf score=2.188937
I20260812 06:18:46.433204 32662 maintenance_manager.cc:643] P e5f5a784f9b5488e91d309863a3a17dc: FlushDeltaMemStoresOp(06769acc457c4bcd811ff29d953de070) complete. Timing: real 0.014s	user 0.009s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4755,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:46.433797 32727 maintenance_manager.cc:419] P e5f5a784f9b5488e91d309863a3a17dc: Scheduling MajorDeltaCompactionOp(06769acc457c4bcd811ff29d953de070): perf score=1.000000
I20260812 06:18:46.615938 32662 maintenance_manager.cc:643] P e5f5a784f9b5488e91d309863a3a17dc: MajorDeltaCompactionOp(06769acc457c4bcd811ff29d953de070) complete. Timing: real 0.182s	user 0.120s	sys 0.061s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774689,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":231,"lbm_read_time_us":11573,"lbm_reads_lt_1ms":572,"lbm_write_time_us":35685,"lbm_writes_lt_1ms":543,"mutex_wait_us":37,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":34176,"update_count":2500}
I20260812 06:18:46.617601 32727 maintenance_manager.cc:419] P e5f5a784f9b5488e91d309863a3a17dc: Scheduling FlushDeltaMemStoresOp(06769acc457c4bcd811ff29d953de070): perf score=12.110812
I20260812 06:18:46.664155 32662 maintenance_manager.cc:643] P e5f5a784f9b5488e91d309863a3a17dc: FlushDeltaMemStoresOp(06769acc457c4bcd811ff29d953de070) complete. Timing: real 0.046s	user 0.030s	sys 0.012s Metrics: {"bytes_written":13538208,"delete_count":0,"lbm_write_time_us":20434,"lbm_writes_lt_1ms":333,"reinsert_count":0,"update_count":1650}
I20260812 06:18:46.664907 32727 maintenance_manager.cc:419] P e5f5a784f9b5488e91d309863a3a17dc: Scheduling FlushDeltaMemStoresOp(06769acc457c4bcd811ff29d953de070): perf score=1.196750
I20260812 06:18:46.679571 32662 maintenance_manager.cc:643] P e5f5a784f9b5488e91d309863a3a17dc: FlushDeltaMemStoresOp(06769acc457c4bcd811ff29d953de070) complete. Timing: real 0.014s	user 0.004s	sys 0.004s Metrics: {"bytes_written":2871905,"delete_count":0,"lbm_write_time_us":3366,"lbm_writes_lt_1ms":73,"reinsert_count":0,"update_count":350}
I20260812 06:18:46.680080 32727 maintenance_manager.cc:419] P e5f5a784f9b5488e91d309863a3a17dc: Scheduling MajorDeltaCompactionOp(06769acc457c4bcd811ff29d953de070): perf score=1.000000
I20260812 06:18:46.866703 32662 maintenance_manager.cc:643] P e5f5a784f9b5488e91d309863a3a17dc: MajorDeltaCompactionOp(06769acc457c4bcd811ff29d953de070) complete. Timing: real 0.186s	user 0.127s	sys 0.055s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672241,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":837,"lbm_read_time_us":11295,"lbm_reads_lt_1ms":464,"lbm_write_time_us":32154,"lbm_writes_lt_1ms":443,"mutex_wait_us":322,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":10112,"update_count":2000}
I20260812 06:18:46.867530 32727 maintenance_manager.cc:419] P e5f5a784f9b5488e91d309863a3a17dc: Scheduling FlushDeltaMemStoresOp(06769acc457c4bcd811ff29d953de070): perf score=11.118625
I20260812 06:18:46.908658 32662 maintenance_manager.cc:643] P e5f5a784f9b5488e91d309863a3a17dc: FlushDeltaMemStoresOp(06769acc457c4bcd811ff29d953de070) complete. Timing: real 0.041s	user 0.028s	sys 0.012s Metrics: {"bytes_written":12717735,"delete_count":0,"lbm_write_time_us":17261,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:18:46.909360 32727 maintenance_manager.cc:419] P e5f5a784f9b5488e91d309863a3a17dc: Scheduling FlushDeltaMemStoresOp(06769acc457c4bcd811ff29d953de070): perf score=2.188937
I20260812 06:18:46.924528 32662 maintenance_manager.cc:643] P e5f5a784f9b5488e91d309863a3a17dc: FlushDeltaMemStoresOp(06769acc457c4bcd811ff29d953de070) complete. Timing: real 0.015s	user 0.012s	sys 0.000s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":5385,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:18:46.925057 32727 maintenance_manager.cc:419] P e5f5a784f9b5488e91d309863a3a17dc: Scheduling MajorDeltaCompactionOp(06769acc457c4bcd811ff29d953de070): perf score=1.000000
I20260812 06:18:47.068627 32662 maintenance_manager.cc:643] P e5f5a784f9b5488e91d309863a3a17dc: MajorDeltaCompactionOp(06769acc457c4bcd811ff29d953de070) complete. Timing: real 0.143s	user 0.090s	sys 0.052s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672268,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":402,"lbm_read_time_us":8071,"lbm_reads_lt_1ms":464,"lbm_write_time_us":30179,"lbm_writes_lt_1ms":443,"mutex_wait_us":67,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":21760,"update_count":2000}
I20260812 06:18:47.069278 32727 maintenance_manager.cc:419] P e5f5a784f9b5488e91d309863a3a17dc: Scheduling FlushDeltaMemStoresOp(06769acc457c4bcd811ff29d953de070): perf score=10.126437
I20260812 06:18:47.110540 32662 maintenance_manager.cc:643] P e5f5a784f9b5488e91d309863a3a17dc: FlushDeltaMemStoresOp(06769acc457c4bcd811ff29d953de070) complete. Timing: real 0.041s	user 0.030s	sys 0.009s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":18382,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:18:47.111014 32727 maintenance_manager.cc:419] P e5f5a784f9b5488e91d309863a3a17dc: Scheduling FlushDeltaMemStoresOp(06769acc457c4bcd811ff29d953de070): perf score=2.188937
I20260812 06:18:47.124321 32662 maintenance_manager.cc:643] P e5f5a784f9b5488e91d309863a3a17dc: FlushDeltaMemStoresOp(06769acc457c4bcd811ff29d953de070) complete. Timing: real 0.013s	user 0.010s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4855,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:47.124938 32727 maintenance_manager.cc:419] P e5f5a784f9b5488e91d309863a3a17dc: Scheduling MajorDeltaCompactionOp(06769acc457c4bcd811ff29d953de070): perf score=1.000000
I20260812 06:18:47.260253 32662 maintenance_manager.cc:643] P e5f5a784f9b5488e91d309863a3a17dc: MajorDeltaCompactionOp(06769acc457c4bcd811ff29d953de070) complete. Timing: real 0.135s	user 0.130s	sys 0.004s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672277,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":224,"lbm_read_time_us":9904,"lbm_reads_lt_1ms":472,"lbm_write_time_us":23923,"lbm_writes_lt_1ms":443,"mutex_wait_us":2,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":2304,"update_count":2000}
I20260812 06:18:47.263546 32727 maintenance_manager.cc:419] P e5f5a784f9b5488e91d309863a3a17dc: Scheduling FlushDeltaMemStoresOp(06769acc457c4bcd811ff29d953de070): perf score=10.126437
I20260812 06:18:47.317257 32662 maintenance_manager.cc:643] P e5f5a784f9b5488e91d309863a3a17dc: FlushDeltaMemStoresOp(06769acc457c4bcd811ff29d953de070) complete. Timing: real 0.053s	user 0.029s	sys 0.019s Metrics: {"bytes_written":12307491,"delete_count":0,"lbm_write_time_us":21554,"lbm_writes_lt_1ms":303,"mutex_wait_us":60,"reinsert_count":0,"update_count":1500}
I20260812 06:18:47.317785 32727 maintenance_manager.cc:419] P e5f5a784f9b5488e91d309863a3a17dc: Scheduling FlushDeltaMemStoresOp(06769acc457c4bcd811ff29d953de070): perf score=2.188937
I20260812 06:18:47.328811 32662 maintenance_manager.cc:643] P e5f5a784f9b5488e91d309863a3a17dc: FlushDeltaMemStoresOp(06769acc457c4bcd811ff29d953de070) complete. Timing: real 0.011s	user 0.006s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4066,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:47.329430 32727 maintenance_manager.cc:419] P e5f5a784f9b5488e91d309863a3a17dc: Scheduling MajorDeltaCompactionOp(06769acc457c4bcd811ff29d953de070): perf score=1.000000
I20260812 06:18:47.470062 32662 maintenance_manager.cc:643] P e5f5a784f9b5488e91d309863a3a17dc: MajorDeltaCompactionOp(06769acc457c4bcd811ff29d953de070) complete. Timing: real 0.140s	user 0.100s	sys 0.040s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672278,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":406,"lbm_read_time_us":9412,"lbm_reads_lt_1ms":472,"lbm_write_time_us":29128,"lbm_writes_lt_1ms":443,"mutex_wait_us":48,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":13184,"update_count":2000}
I20260812 06:18:47.470889 32727 maintenance_manager.cc:419] P e5f5a784f9b5488e91d309863a3a17dc: Scheduling FlushDeltaMemStoresOp(06769acc457c4bcd811ff29d953de070): perf score=10.126437
I20260812 06:18:47.525494 32662 maintenance_manager.cc:643] P e5f5a784f9b5488e91d309863a3a17dc: FlushDeltaMemStoresOp(06769acc457c4bcd811ff29d953de070) complete. Timing: real 0.054s	user 0.028s	sys 0.020s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":17687,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:18:47.526070 32727 maintenance_manager.cc:419] P e5f5a784f9b5488e91d309863a3a17dc: Scheduling FlushDeltaMemStoresOp(06769acc457c4bcd811ff29d953de070): perf score=2.188937
I20260812 06:18:47.538451 32662 maintenance_manager.cc:643] P e5f5a784f9b5488e91d309863a3a17dc: FlushDeltaMemStoresOp(06769acc457c4bcd811ff29d953de070) complete. Timing: real 0.012s	user 0.003s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4926,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:47.538970 32727 maintenance_manager.cc:419] P e5f5a784f9b5488e91d309863a3a17dc: Scheduling MajorDeltaCompactionOp(06769acc457c4bcd811ff29d953de070): perf score=1.000000
I20260812 06:18:47.690953 32662 maintenance_manager.cc:643] P e5f5a784f9b5488e91d309863a3a17dc: MajorDeltaCompactionOp(06769acc457c4bcd811ff29d953de070) complete. Timing: real 0.152s	user 0.087s	sys 0.064s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672277,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":1004,"lbm_read_time_us":10922,"lbm_reads_lt_1ms":472,"lbm_write_time_us":24269,"lbm_writes_lt_1ms":443,"mutex_wait_us":276,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":7936,"update_count":2000}
I20260812 06:18:47.691664 32727 maintenance_manager.cc:419] P e5f5a784f9b5488e91d309863a3a17dc: Scheduling FlushDeltaMemStoresOp(06769acc457c4bcd811ff29d953de070): perf score=10.126437
I20260812 06:18:47.732245 32662 maintenance_manager.cc:643] P e5f5a784f9b5488e91d309863a3a17dc: FlushDeltaMemStoresOp(06769acc457c4bcd811ff29d953de070) complete. Timing: real 0.040s	user 0.020s	sys 0.016s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":17131,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:18:47.732861 32727 maintenance_manager.cc:419] P e5f5a784f9b5488e91d309863a3a17dc: Scheduling FlushMRSOp(06769acc457c4bcd811ff29d953de070): perf score=1.000000
I20260812 06:18:47.775494 32662 maintenance_manager.cc:643] P e5f5a784f9b5488e91d309863a3a17dc: FlushMRSOp(06769acc457c4bcd811ff29d953de070) complete. Timing: real 0.042s	user 0.028s	sys 0.000s Metrics: {"bytes_written":1275449,"cfile_init":1,"dirs.queue_time_us":67,"dirs.run_cpu_time_us":252,"dirs.run_wall_time_us":1460,"drs_written":1,"lbm_read_time_us":58,"lbm_reads_lt_1ms":4,"lbm_write_time_us":2474,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":31}
I20260812 06:18:47.776295 32727 maintenance_manager.cc:419] P e5f5a784f9b5488e91d309863a3a17dc: Scheduling UndoDeltaBlockGCOp(06769acc457c4bcd811ff29d953de070): 482 bytes on disk
I20260812 06:18:47.776748 32662 maintenance_manager.cc:643] P e5f5a784f9b5488e91d309863a3a17dc: UndoDeltaBlockGCOp(06769acc457c4bcd811ff29d953de070) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":98,"lbm_reads_lt_1ms":4}
I20260812 06:18:47.777313 32727 maintenance_manager.cc:419] P e5f5a784f9b5488e91d309863a3a17dc: Scheduling FlushDeltaMemStoresOp(06769acc457c4bcd811ff29d953de070): perf score=3.181125
I20260812 06:18:47.790983 32662 maintenance_manager.cc:643] P e5f5a784f9b5488e91d309863a3a17dc: FlushDeltaMemStoresOp(06769acc457c4bcd811ff29d953de070) complete. Timing: real 0.013s	user 0.012s	sys 0.000s Metrics: {"bytes_written":4512903,"delete_count":0,"lbm_write_time_us":5506,"lbm_writes_lt_1ms":113,"reinsert_count":0,"update_count":550}
I20260812 06:18:47.791497 32727 maintenance_manager.cc:419] P e5f5a784f9b5488e91d309863a3a17dc: Scheduling LogGCOp(06769acc457c4bcd811ff29d953de070): free 124257198 bytes of WAL
I20260812 06:18:47.791728 32662 log_reader.cc:385] T 06769acc457c4bcd811ff29d953de070: removed 12 log segments from log reader
I20260812 06:18:47.791772 32662 log.cc:1079] T 06769acc457c4bcd811ff29d953de070 P e5f5a784f9b5488e91d309863a3a17dc: Deleting log segment in path: /tmp/dist-test-taskchnxcB/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515518376868-32341-0/minicluster-data/ts-0-root/wals/06769acc457c4bcd811ff29d953de070/wal-000000014 (ops 67-71)
I20260812 06:18:47.791805 32662 log.cc:1079] T 06769acc457c4bcd811ff29d953de070 P e5f5a784f9b5488e91d309863a3a17dc: Deleting log segment in path: /tmp/dist-test-taskchnxcB/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515518376868-32341-0/minicluster-data/ts-0-root/wals/06769acc457c4bcd811ff29d953de070/wal-000000015 (ops 72-76)
I20260812 06:18:47.791878 32662 log.cc:1079] T 06769acc457c4bcd811ff29d953de070 P e5f5a784f9b5488e91d309863a3a17dc: Deleting log segment in path: /tmp/dist-test-taskchnxcB/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515518376868-32341-0/minicluster-data/ts-0-root/wals/06769acc457c4bcd811ff29d953de070/wal-000000016 (ops 77-81)
I20260812 06:18:47.791927 32662 log.cc:1079] T 06769acc457c4bcd811ff29d953de070 P e5f5a784f9b5488e91d309863a3a17dc: Deleting log segment in path: /tmp/dist-test-taskchnxcB/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515518376868-32341-0/minicluster-data/ts-0-root/wals/06769acc457c4bcd811ff29d953de070/wal-000000017 (ops 82-86)
I20260812 06:18:47.791993 32662 log.cc:1079] T 06769acc457c4bcd811ff29d953de070 P e5f5a784f9b5488e91d309863a3a17dc: Deleting log segment in path: /tmp/dist-test-taskchnxcB/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515518376868-32341-0/minicluster-data/ts-0-root/wals/06769acc457c4bcd811ff29d953de070/wal-000000018 (ops 87-91)
I20260812 06:18:47.792061 32662 log.cc:1079] T 06769acc457c4bcd811ff29d953de070 P e5f5a784f9b5488e91d309863a3a17dc: Deleting log segment in path: /tmp/dist-test-taskchnxcB/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515518376868-32341-0/minicluster-data/ts-0-root/wals/06769acc457c4bcd811ff29d953de070/wal-000000019 (ops 92-96)
I20260812 06:18:47.792109 32662 log.cc:1079] T 06769acc457c4bcd811ff29d953de070 P e5f5a784f9b5488e91d309863a3a17dc: Deleting log segment in path: /tmp/dist-test-taskchnxcB/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515518376868-32341-0/minicluster-data/ts-0-root/wals/06769acc457c4bcd811ff29d953de070/wal-000000020 (ops 97-101)
I20260812 06:18:47.792157 32662 log.cc:1079] T 06769acc457c4bcd811ff29d953de070 P e5f5a784f9b5488e91d309863a3a17dc: Deleting log segment in path: /tmp/dist-test-taskchnxcB/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515518376868-32341-0/minicluster-data/ts-0-root/wals/06769acc457c4bcd811ff29d953de070/wal-000000021 (ops 102-106)
I20260812 06:18:47.792205 32662 log.cc:1079] T 06769acc457c4bcd811ff29d953de070 P e5f5a784f9b5488e91d309863a3a17dc: Deleting log segment in path: /tmp/dist-test-taskchnxcB/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515518376868-32341-0/minicluster-data/ts-0-root/wals/06769acc457c4bcd811ff29d953de070/wal-000000022 (ops 107-111)
I20260812 06:18:47.792250 32662 log.cc:1079] T 06769acc457c4bcd811ff29d953de070 P e5f5a784f9b5488e91d309863a3a17dc: Deleting log segment in path: /tmp/dist-test-taskchnxcB/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515518376868-32341-0/minicluster-data/ts-0-root/wals/06769acc457c4bcd811ff29d953de070/wal-000000023 (ops 112-116)
I20260812 06:18:47.792294 32662 log.cc:1079] T 06769acc457c4bcd811ff29d953de070 P e5f5a784f9b5488e91d309863a3a17dc: Deleting log segment in path: /tmp/dist-test-taskchnxcB/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515518376868-32341-0/minicluster-data/ts-0-root/wals/06769acc457c4bcd811ff29d953de070/wal-000000024 (ops 117-120)
I20260812 06:18:47.792340 32662 log.cc:1079] T 06769acc457c4bcd811ff29d953de070 P e5f5a784f9b5488e91d309863a3a17dc: Deleting log segment in path: /tmp/dist-test-taskchnxcB/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515518376868-32341-0/minicluster-data/ts-0-root/wals/06769acc457c4bcd811ff29d953de070/wal-000000025 (ops 121-125)
I20260812 06:18:47.821688 32662 maintenance_manager.cc:643] P e5f5a784f9b5488e91d309863a3a17dc: LogGCOp(06769acc457c4bcd811ff29d953de070) complete. Timing: real 0.030s	user 0.000s	sys 0.029s Metrics: {}
I20260812 06:18:47.822181 32727 maintenance_manager.cc:419] P e5f5a784f9b5488e91d309863a3a17dc: Scheduling FlushDeltaMemStoresOp(06769acc457c4bcd811ff29d953de070): perf score=2.188937
I20260812 06:18:47.843627 32662 maintenance_manager.cc:643] P e5f5a784f9b5488e91d309863a3a17dc: FlushDeltaMemStoresOp(06769acc457c4bcd811ff29d953de070) complete. Timing: real 0.021s	user 0.005s	sys 0.013s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4864,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:47.844213 32727 maintenance_manager.cc:419] P e5f5a784f9b5488e91d309863a3a17dc: Scheduling LogGCOp(06769acc457c4bcd811ff29d953de070): free 12017991 bytes of WAL
I20260812 06:18:47.844447 32662 log_reader.cc:385] T 06769acc457c4bcd811ff29d953de070: removed 1 log segments from log reader
I20260812 06:18:47.844494 32662 log.cc:1079] T 06769acc457c4bcd811ff29d953de070 P e5f5a784f9b5488e91d309863a3a17dc: Deleting log segment in path: /tmp/dist-test-taskchnxcB/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515518376868-32341-0/minicluster-data/ts-0-root/wals/06769acc457c4bcd811ff29d953de070/wal-000000026 (ops 126-130)
I20260812 06:18:47.847083 32662 maintenance_manager.cc:643] P e5f5a784f9b5488e91d309863a3a17dc: LogGCOp(06769acc457c4bcd811ff29d953de070) complete. Timing: real 0.003s	user 0.000s	sys 0.000s Metrics: {}
I20260812 06:18:47.847508 32727 maintenance_manager.cc:419] P e5f5a784f9b5488e91d309863a3a17dc: Scheduling FlushDeltaMemStoresOp(06769acc457c4bcd811ff29d953de070): perf score=2.188937
I20260812 06:18:47.858650 32662 maintenance_manager.cc:643] P e5f5a784f9b5488e91d309863a3a17dc: FlushDeltaMemStoresOp(06769acc457c4bcd811ff29d953de070) complete. Timing: real 0.011s	user 0.002s	sys 0.007s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":4434,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:18:47.859174 32727 maintenance_manager.cc:419] P e5f5a784f9b5488e91d309863a3a17dc: Scheduling MajorDeltaCompactionOp(06769acc457c4bcd811ff29d953de070): perf score=1.000000
I20260812 06:18:48.096756 32662 maintenance_manager.cc:643] P e5f5a784f9b5488e91d309863a3a17dc: MajorDeltaCompactionOp(06769acc457c4bcd811ff29d953de070) complete. Timing: real 0.237s	user 0.164s	sys 0.071s Metrics: {"cfile_cache_miss":634,"cfile_cache_miss_bytes":28877329,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":702,"lbm_read_time_us":16473,"lbm_reads_lt_1ms":674,"lbm_write_time_us":40695,"lbm_writes_lt_1ms":643,"mutex_wait_us":31,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":10112,"thread_start_us":133,"threads_started":1,"update_count":3000}
I20260812 06:18:48.097481 32727 maintenance_manager.cc:419] P e5f5a784f9b5488e91d309863a3a17dc: Scheduling FlushDeltaMemStoresOp(06769acc457c4bcd811ff29d953de070): perf score=14.095187
I20260812 06:18:48.165427 32662 maintenance_manager.cc:643] P e5f5a784f9b5488e91d309863a3a17dc: FlushDeltaMemStoresOp(06769acc457c4bcd811ff29d953de070) complete. Timing: real 0.068s	user 0.038s	sys 0.027s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":27038,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":402,"reinsert_count":0,"update_count":2000}
I20260812 06:18:48.166086 32727 maintenance_manager.cc:419] P e5f5a784f9b5488e91d309863a3a17dc: Scheduling FlushDeltaMemStoresOp(06769acc457c4bcd811ff29d953de070): perf score=2.188937
I20260812 06:18:48.184849 32662 maintenance_manager.cc:643] P e5f5a784f9b5488e91d309863a3a17dc: FlushDeltaMemStoresOp(06769acc457c4bcd811ff29d953de070) complete. Timing: real 0.019s	user 0.013s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6797,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:48.185560 32727 maintenance_manager.cc:419] P e5f5a784f9b5488e91d309863a3a17dc: Scheduling MajorDeltaCompactionOp(06769acc457c4bcd811ff29d953de070): perf score=1.000000
I20260812 06:18:48.377274 32662 maintenance_manager.cc:643] P e5f5a784f9b5488e91d309863a3a17dc: MajorDeltaCompactionOp(06769acc457c4bcd811ff29d953de070) complete. Timing: real 0.192s	user 0.110s	sys 0.080s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774688,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":641,"lbm_read_time_us":12465,"lbm_reads_lt_1ms":564,"lbm_write_time_us":29824,"lbm_writes_lt_1ms":543,"mutex_wait_us":97,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":1792,"update_count":2500}
I20260812 06:18:48.377815 32727 maintenance_manager.cc:419] P e5f5a784f9b5488e91d309863a3a17dc: Scheduling FlushDeltaMemStoresOp(06769acc457c4bcd811ff29d953de070): perf score=14.095187
I20260812 06:18:48.424293 32662 maintenance_manager.cc:643] P e5f5a784f9b5488e91d309863a3a17dc: FlushDeltaMemStoresOp(06769acc457c4bcd811ff29d953de070) complete. Timing: real 0.046s	user 0.028s	sys 0.014s Metrics: {"bytes_written":16409906,"delete_count":0,"lbm_write_time_us":19725,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:18:48.425395 32727 maintenance_manager.cc:419] P e5f5a784f9b5488e91d309863a3a17dc: Scheduling FlushDeltaMemStoresOp(06769acc457c4bcd811ff29d953de070): perf score=2.188937
I20260812 06:18:48.448402 32662 maintenance_manager.cc:643] P e5f5a784f9b5488e91d309863a3a17dc: FlushDeltaMemStoresOp(06769acc457c4bcd811ff29d953de070) complete. Timing: real 0.023s	user 0.011s	sys 0.008s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4346,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:48.449167 32727 maintenance_manager.cc:419] P e5f5a784f9b5488e91d309863a3a17dc: Scheduling MajorDeltaCompactionOp(06769acc457c4bcd811ff29d953de070): perf score=1.000000
I20260812 06:18:48.652812 32662 maintenance_manager.cc:643] P e5f5a784f9b5488e91d309863a3a17dc: MajorDeltaCompactionOp(06769acc457c4bcd811ff29d953de070) complete. Timing: real 0.203s	user 0.151s	sys 0.048s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774692,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":389,"lbm_read_time_us":13953,"lbm_reads_lt_1ms":572,"lbm_write_time_us":32543,"lbm_writes_lt_1ms":543,"mutex_wait_us":47,"peak_mem_usage":63115900,"reinsert_count":0,"update_count":2500}
I20260812 06:18:48.654719 32727 maintenance_manager.cc:419] P e5f5a784f9b5488e91d309863a3a17dc: Scheduling FlushDeltaMemStoresOp(06769acc457c4bcd811ff29d953de070): perf score=14.095187
I20260812 06:18:48.714212 32662 maintenance_manager.cc:643] P e5f5a784f9b5488e91d309863a3a17dc: FlushDeltaMemStoresOp(06769acc457c4bcd811ff29d953de070) complete. Timing: real 0.059s	user 0.037s	sys 0.020s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":24412,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:18:48.714805 32727 maintenance_manager.cc:419] P e5f5a784f9b5488e91d309863a3a17dc: Scheduling FlushDeltaMemStoresOp(06769acc457c4bcd811ff29d953de070): perf score=2.188937
I20260812 06:18:48.728967 32662 maintenance_manager.cc:643] P e5f5a784f9b5488e91d309863a3a17dc: FlushDeltaMemStoresOp(06769acc457c4bcd811ff29d953de070) complete. Timing: real 0.014s	user 0.010s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5426,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:48.729423 32727 maintenance_manager.cc:419] P e5f5a784f9b5488e91d309863a3a17dc: Scheduling MajorDeltaCompactionOp(06769acc457c4bcd811ff29d953de070): perf score=1.000000
I20260812 06:18:48.917742 32662 maintenance_manager.cc:643] P e5f5a784f9b5488e91d309863a3a17dc: MajorDeltaCompactionOp(06769acc457c4bcd811ff29d953de070) complete. Timing: real 0.188s	user 0.123s	sys 0.060s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774689,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":298,"lbm_read_time_us":11101,"lbm_reads_lt_1ms":572,"lbm_write_time_us":30024,"lbm_writes_lt_1ms":543,"mutex_wait_us":2,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":3200,"update_count":2500}
I20260812 06:18:48.918672 32727 maintenance_manager.cc:419] P e5f5a784f9b5488e91d309863a3a17dc: Scheduling FlushDeltaMemStoresOp(06769acc457c4bcd811ff29d953de070): perf score=14.095187
I20260812 06:18:48.971534 32662 maintenance_manager.cc:643] P e5f5a784f9b5488e91d309863a3a17dc: FlushDeltaMemStoresOp(06769acc457c4bcd811ff29d953de070) complete. Timing: real 0.053s	user 0.022s	sys 0.028s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":23093,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":402,"reinsert_count":0,"update_count":2000}
I20260812 06:18:48.972081 32727 maintenance_manager.cc:419] P e5f5a784f9b5488e91d309863a3a17dc: Scheduling FlushDeltaMemStoresOp(06769acc457c4bcd811ff29d953de070): perf score=2.188937
I20260812 06:18:48.994103 32662 maintenance_manager.cc:643] P e5f5a784f9b5488e91d309863a3a17dc: FlushDeltaMemStoresOp(06769acc457c4bcd811ff29d953de070) complete. Timing: real 0.022s	user 0.015s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6350,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:48.994663 32727 maintenance_manager.cc:419] P e5f5a784f9b5488e91d309863a3a17dc: Scheduling MajorDeltaCompactionOp(06769acc457c4bcd811ff29d953de070): perf score=1.000000
I20260812 06:18:49.149885 32662 maintenance_manager.cc:643] P e5f5a784f9b5488e91d309863a3a17dc: MajorDeltaCompactionOp(06769acc457c4bcd811ff29d953de070) complete. Timing: real 0.155s	user 0.128s	sys 0.024s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774689,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":347,"lbm_read_time_us":9108,"lbm_reads_lt_1ms":564,"lbm_write_time_us":32116,"lbm_writes_lt_1ms":543,"peak_mem_usage":63115900,"reinsert_count":0,"update_count":2500}
I20260812 06:18:49.150705 32727 maintenance_manager.cc:419] P e5f5a784f9b5488e91d309863a3a17dc: Scheduling FlushDeltaMemStoresOp(06769acc457c4bcd811ff29d953de070): perf score=14.095187
I20260812 06:18:49.208200 32662 maintenance_manager.cc:643] P e5f5a784f9b5488e91d309863a3a17dc: FlushDeltaMemStoresOp(06769acc457c4bcd811ff29d953de070) complete. Timing: real 0.057s	user 0.033s	sys 0.020s Metrics: {"bytes_written":16409900,"delete_count":0,"lbm_write_time_us":25507,"lbm_writes_1-10_ms":2,"lbm_writes_lt_1ms":401,"reinsert_count":0,"update_count":2000}
I20260812 06:18:49.208930 32727 maintenance_manager.cc:419] P e5f5a784f9b5488e91d309863a3a17dc: Scheduling FlushDeltaMemStoresOp(06769acc457c4bcd811ff29d953de070): perf score=2.188937
I20260812 06:18:49.223531 32662 maintenance_manager.cc:643] P e5f5a784f9b5488e91d309863a3a17dc: FlushDeltaMemStoresOp(06769acc457c4bcd811ff29d953de070) complete. Timing: real 0.014s	user 0.006s	sys 0.005s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5168,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:49.224295 32727 maintenance_manager.cc:419] P e5f5a784f9b5488e91d309863a3a17dc: Scheduling MajorDeltaCompactionOp(06769acc457c4bcd811ff29d953de070): perf score=1.000000
I20260812 06:18:49.382560 32662 maintenance_manager.cc:643] P e5f5a784f9b5488e91d309863a3a17dc: MajorDeltaCompactionOp(06769acc457c4bcd811ff29d953de070) complete. Timing: real 0.158s	user 0.137s	sys 0.016s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774687,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":223,"lbm_read_time_us":10126,"lbm_reads_lt_1ms":572,"lbm_write_time_us":31014,"lbm_writes_lt_1ms":543,"mutex_wait_us":23,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":3456,"update_count":2500}
I20260812 06:18:49.383394 32727 maintenance_manager.cc:419] P e5f5a784f9b5488e91d309863a3a17dc: Scheduling FlushDeltaMemStoresOp(06769acc457c4bcd811ff29d953de070): perf score=14.095187
I20260812 06:18:49.443516 32662 maintenance_manager.cc:643] P e5f5a784f9b5488e91d309863a3a17dc: FlushDeltaMemStoresOp(06769acc457c4bcd811ff29d953de070) complete. Timing: real 0.060s	user 0.041s	sys 0.008s Metrics: {"bytes_written":16409899,"delete_count":0,"lbm_write_time_us":23918,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:18:49.444182 32727 maintenance_manager.cc:419] P e5f5a784f9b5488e91d309863a3a17dc: Scheduling FlushDeltaMemStoresOp(06769acc457c4bcd811ff29d953de070): perf score=2.188937
I20260812 06:18:49.456019 32662 maintenance_manager.cc:643] P e5f5a784f9b5488e91d309863a3a17dc: FlushDeltaMemStoresOp(06769acc457c4bcd811ff29d953de070) complete. Timing: real 0.012s	user 0.002s	sys 0.007s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4366,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:49.456537 32727 maintenance_manager.cc:419] P e5f5a784f9b5488e91d309863a3a17dc: Scheduling FlushMRSOp(06769acc457c4bcd811ff29d953de070): perf score=1.000000
I20260812 06:18:49.487157 32662 maintenance_manager.cc:643] P e5f5a784f9b5488e91d309863a3a17dc: FlushMRSOp(06769acc457c4bcd811ff29d953de070) complete. Timing: real 0.030s	user 0.028s	sys 0.000s Metrics: {"bytes_written":1316417,"cfile_init":1,"dirs.queue_time_us":67,"dirs.run_cpu_time_us":317,"dirs.run_wall_time_us":1784,"drs_written":1,"lbm_read_time_us":58,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1801,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":32}
I20260812 06:18:49.488051 32727 maintenance_manager.cc:419] P e5f5a784f9b5488e91d309863a3a17dc: Scheduling LogGCOp(06769acc457c4bcd811ff29d953de070): free 129320776 bytes of WAL
I20260812 06:18:49.488336 32662 log_reader.cc:385] T 06769acc457c4bcd811ff29d953de070: removed 13 log segments from log reader
I20260812 06:18:49.488399 32662 log.cc:1079] T 06769acc457c4bcd811ff29d953de070 P e5f5a784f9b5488e91d309863a3a17dc: Deleting log segment in path: /tmp/dist-test-taskchnxcB/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515518376868-32341-0/minicluster-data/ts-0-root/wals/06769acc457c4bcd811ff29d953de070/wal-000000027 (ops 131-135)
I20260812 06:18:49.488442 32662 log.cc:1079] T 06769acc457c4bcd811ff29d953de070 P e5f5a784f9b5488e91d309863a3a17dc: Deleting log segment in path: /tmp/dist-test-taskchnxcB/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515518376868-32341-0/minicluster-data/ts-0-root/wals/06769acc457c4bcd811ff29d953de070/wal-000000028 (ops 136-140)
I20260812 06:18:49.488467 32662 log.cc:1079] T 06769acc457c4bcd811ff29d953de070 P e5f5a784f9b5488e91d309863a3a17dc: Deleting log segment in path: /tmp/dist-test-taskchnxcB/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515518376868-32341-0/minicluster-data/ts-0-root/wals/06769acc457c4bcd811ff29d953de070/wal-000000029 (ops 141-144)
I20260812 06:18:49.488490 32662 log.cc:1079] T 06769acc457c4bcd811ff29d953de070 P e5f5a784f9b5488e91d309863a3a17dc: Deleting log segment in path: /tmp/dist-test-taskchnxcB/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515518376868-32341-0/minicluster-data/ts-0-root/wals/06769acc457c4bcd811ff29d953de070/wal-000000030 (ops 145-149)
I20260812 06:18:49.488513 32662 log.cc:1079] T 06769acc457c4bcd811ff29d953de070 P e5f5a784f9b5488e91d309863a3a17dc: Deleting log segment in path: /tmp/dist-test-taskchnxcB/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515518376868-32341-0/minicluster-data/ts-0-root/wals/06769acc457c4bcd811ff29d953de070/wal-000000031 (ops 150-154)
I20260812 06:18:49.488585 32662 log.cc:1079] T 06769acc457c4bcd811ff29d953de070 P e5f5a784f9b5488e91d309863a3a17dc: Deleting log segment in path: /tmp/dist-test-taskchnxcB/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515518376868-32341-0/minicluster-data/ts-0-root/wals/06769acc457c4bcd811ff29d953de070/wal-000000032 (ops 155-159)
I20260812 06:18:49.488617 32662 log.cc:1079] T 06769acc457c4bcd811ff29d953de070 P e5f5a784f9b5488e91d309863a3a17dc: Deleting log segment in path: /tmp/dist-test-taskchnxcB/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515518376868-32341-0/minicluster-data/ts-0-root/wals/06769acc457c4bcd811ff29d953de070/wal-000000033 (ops 160-164)
I20260812 06:18:49.488643 32662 log.cc:1079] T 06769acc457c4bcd811ff29d953de070 P e5f5a784f9b5488e91d309863a3a17dc: Deleting log segment in path: /tmp/dist-test-taskchnxcB/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515518376868-32341-0/minicluster-data/ts-0-root/wals/06769acc457c4bcd811ff29d953de070/wal-000000034 (ops 165-169)
I20260812 06:18:49.488668 32662 log.cc:1079] T 06769acc457c4bcd811ff29d953de070 P e5f5a784f9b5488e91d309863a3a17dc: Deleting log segment in path: /tmp/dist-test-taskchnxcB/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515518376868-32341-0/minicluster-data/ts-0-root/wals/06769acc457c4bcd811ff29d953de070/wal-000000035 (ops 170-174)
I20260812 06:18:49.488708 32662 log.cc:1079] T 06769acc457c4bcd811ff29d953de070 P e5f5a784f9b5488e91d309863a3a17dc: Deleting log segment in path: /tmp/dist-test-taskchnxcB/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515518376868-32341-0/minicluster-data/ts-0-root/wals/06769acc457c4bcd811ff29d953de070/wal-000000036 (ops 175-178)
I20260812 06:18:49.488731 32662 log.cc:1079] T 06769acc457c4bcd811ff29d953de070 P e5f5a784f9b5488e91d309863a3a17dc: Deleting log segment in path: /tmp/dist-test-taskchnxcB/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515518376868-32341-0/minicluster-data/ts-0-root/wals/06769acc457c4bcd811ff29d953de070/wal-000000037 (ops 179-183)
I20260812 06:18:49.488754 32662 log.cc:1079] T 06769acc457c4bcd811ff29d953de070 P e5f5a784f9b5488e91d309863a3a17dc: Deleting log segment in path: /tmp/dist-test-taskchnxcB/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515518376868-32341-0/minicluster-data/ts-0-root/wals/06769acc457c4bcd811ff29d953de070/wal-000000038 (ops 184-188)
I20260812 06:18:49.488777 32662 log.cc:1079] T 06769acc457c4bcd811ff29d953de070 P e5f5a784f9b5488e91d309863a3a17dc: Deleting log segment in path: /tmp/dist-test-taskchnxcB/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515518376868-32341-0/minicluster-data/ts-0-root/wals/06769acc457c4bcd811ff29d953de070/wal-000000039 (ops 189-193)
I20260812 06:18:49.519696 32662 maintenance_manager.cc:643] P e5f5a784f9b5488e91d309863a3a17dc: LogGCOp(06769acc457c4bcd811ff29d953de070) complete. Timing: real 0.031s	user 0.001s	sys 0.027s Metrics: {}
I20260812 06:18:49.520313 32727 maintenance_manager.cc:419] P e5f5a784f9b5488e91d309863a3a17dc: Scheduling UndoDeltaBlockGCOp(06769acc457c4bcd811ff29d953de070): 493 bytes on disk
I20260812 06:18:49.520924 32662 maintenance_manager.cc:643] P e5f5a784f9b5488e91d309863a3a17dc: UndoDeltaBlockGCOp(06769acc457c4bcd811ff29d953de070) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":69,"lbm_reads_lt_1ms":4}
I20260812 06:18:49.521826 32727 maintenance_manager.cc:419] P e5f5a784f9b5488e91d309863a3a17dc: Scheduling FlushDeltaMemStoresOp(06769acc457c4bcd811ff29d953de070): perf score=2.188937
I20260812 06:18:49.547668 32662 maintenance_manager.cc:643] P e5f5a784f9b5488e91d309863a3a17dc: FlushDeltaMemStoresOp(06769acc457c4bcd811ff29d953de070) complete. Timing: real 0.026s	user 0.011s	sys 0.004s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":6557,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:49.548281 32727 maintenance_manager.cc:419] P e5f5a784f9b5488e91d309863a3a17dc: Scheduling FlushDeltaMemStoresOp(06769acc457c4bcd811ff29d953de070): perf score=2.188937
I20260812 06:18:49.559695 32662 maintenance_manager.cc:643] P e5f5a784f9b5488e91d309863a3a17dc: FlushDeltaMemStoresOp(06769acc457c4bcd811ff29d953de070) complete. Timing: real 0.011s	user 0.009s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4285,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:49.560940 32727 maintenance_manager.cc:419] P e5f5a784f9b5488e91d309863a3a17dc: Scheduling MajorDeltaCompactionOp(06769acc457c4bcd811ff29d953de070): perf score=1.000000
I20260812 06:18:49.693842 32341 heavy-update-compaction-itest.cc:229] Time spent updating: real 5.217s	user 1.998s	sys 0.104s
I20260812 06:18:49.748188 32662 maintenance_manager.cc:643] P e5f5a784f9b5488e91d309863a3a17dc: MajorDeltaCompactionOp(06769acc457c4bcd811ff29d953de070) complete. Timing: real 0.187s	user 0.117s	sys 0.068s Metrics: {"cfile_cache_miss":734,"cfile_cache_miss_bytes":32979747,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"lbm_read_time_us":13031,"lbm_reads_lt_1ms":770,"lbm_write_time_us":40640,"lbm_writes_lt_1ms":743,"peak_mem_usage":87969044,"reinsert_count":0,"spinlock_wait_cycles":2176,"update_count":3500}
I20260812 06:18:49.748772 32727 maintenance_manager.cc:419] P e5f5a784f9b5488e91d309863a3a17dc: Scheduling FlushDeltaMemStoresOp(06769acc457c4bcd811ff29d953de070): perf score=10.126437
I20260812 06:18:49.767886 32341 heavy-update-compaction-itest.cc:265] Time spent scanning: real 0.074s	user 0.001s	sys 0.000s
I20260812 06:18:49.768395 32341 tablet_server.cc:179] TabletServer@127.31.149.65:0 shutting down...
I20260812 06:18:49.783649 32662 maintenance_manager.cc:643] P e5f5a784f9b5488e91d309863a3a17dc: FlushDeltaMemStoresOp(06769acc457c4bcd811ff29d953de070) complete. Timing: real 0.035s	user 0.031s	sys 0.001s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":14610,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:18:49.784296 32341 ts_tablet_manager.cc:1507] Shutting down tablet manager...
I20260812 06:18:49.784682 32341 tablet_replica.cc:333] T 06769acc457c4bcd811ff29d953de070 P e5f5a784f9b5488e91d309863a3a17dc: stopping tablet replica
I20260812 06:18:49.784874 32341 raft_consensus.cc:2243] T 06769acc457c4bcd811ff29d953de070 P e5f5a784f9b5488e91d309863a3a17dc [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:18:49.785193 32341 raft_consensus.cc:2272] T 06769acc457c4bcd811ff29d953de070 P e5f5a784f9b5488e91d309863a3a17dc [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:18:49.800186 32341 tablet_server.cc:196] TabletServer@127.31.149.65:0 shutdown complete.
I20260812 06:18:49.814672 32341 master.cc:562] Master@127.31.149.126:36959 shutting down...
I20260812 06:18:49.819384 32341 raft_consensus.cc:2243] T 00000000000000000000000000000000 P 9e823c92132248f0b3a45df8806c5d56 [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:18:49.819592 32341 raft_consensus.cc:2272] T 00000000000000000000000000000000 P 9e823c92132248f0b3a45df8806c5d56 [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:18:49.819670 32341 tablet_replica.cc:333] T 00000000000000000000000000000000 P 9e823c92132248f0b3a45df8806c5d56: stopping tablet replica
I20260812 06:18:49.832705 32341 master.cc:584] Master@127.31.149.126:36959 shutdown complete.
[       OK ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/1 (5690 ms)
[----------] 2 tests from EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy (11531 ms total)

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