[==========] 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:16:52.351666 10539 internal_mini_cluster.cc:156] Creating distributed mini masters. Addrs: 127.10.74.254:42589
I20260812 06:16:52.352958 10539 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:16:52.353715 10539 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:16:52.361146 10550 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:16:52.361162 10553 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:16:52.361337 10539 server_base.cc:1061] running on GCE node
W20260812 06:16:52.361619 10548 instance_detector.cc:116] could not retrieve AWS instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:16:52.362205 10539 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:16:52.362309 10539 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:16:52.362344 10539 hybrid_clock.cc:648] HybridClock initialized: now 1786515412362341 us; error 0 us; skew 500 ppm
I20260812 06:16:52.364434 10539 webserver.cc:533] Webserver started at http://127.10.74.254:40203/ using document root <none> and password file <none>
I20260812 06:16:52.365096 10539 fs_manager.cc:362] Metadata directory not provided
I20260812 06:16:52.365165 10539 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:16:52.365411 10539 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:16:52.367426 10539 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskQQcY3W/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515412339501-10539-0/minicluster-data/master-0-root/instance:
uuid: "b48c2949bd794437b9cfd934c15a67de"
format_stamp: "Formatted at 2026-08-12 06:16:52 on dist-test-slave-nfb5"
I20260812 06:16:52.371475 10539 fs_manager.cc:696] Time spent creating directory manager: real 0.004s	user 0.004s	sys 0.000s
I20260812 06:16:52.373926 10558 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:16:52.375195 10539 fs_manager.cc:730] Time spent opening block manager: real 0.002s	user 0.003s	sys 0.000s
I20260812 06:16:52.375331 10539 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskQQcY3W/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515412339501-10539-0/minicluster-data/master-0-root
uuid: "b48c2949bd794437b9cfd934c15a67de"
format_stamp: "Formatted at 2026-08-12 06:16:52 on dist-test-slave-nfb5"
I20260812 06:16:52.375452 10539 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskQQcY3W/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515412339501-10539-0/minicluster-data/master-0-root
metadata directory: /tmp/dist-test-taskQQcY3W/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515412339501-10539-0/minicluster-data/master-0-root
1 data directories: /tmp/dist-test-taskQQcY3W/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515412339501-10539-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:16:52.394080 10539 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:16:52.394995 10539 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:16:52.395208 10539 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:16:52.404851 10539 rpc_server.cc:307] RPC server started. Bound to: 127.10.74.254:42589
I20260812 06:16:52.404868 10643 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.10.74.254:42589 every 8 connection(s)
I20260812 06:16:52.407896 10646 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:16:52.414866 10646 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P b48c2949bd794437b9cfd934c15a67de: Bootstrap starting.
I20260812 06:16:52.418006 10646 tablet_bootstrap.cc:654] T 00000000000000000000000000000000 P b48c2949bd794437b9cfd934c15a67de: Neither blocks nor log segments found. Creating new log.
I20260812 06:16:52.419212 10646 log.cc:826] T 00000000000000000000000000000000 P b48c2949bd794437b9cfd934c15a67de: Log is configured to *not* fsync() on all Append() calls
I20260812 06:16:52.421316 10646 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P b48c2949bd794437b9cfd934c15a67de: No bootstrap required, opened a new log
I20260812 06:16:52.424961 10646 raft_consensus.cc:359] T 00000000000000000000000000000000 P b48c2949bd794437b9cfd934c15a67de [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "b48c2949bd794437b9cfd934c15a67de" member_type: VOTER }
I20260812 06:16:52.425191 10646 raft_consensus.cc:385] T 00000000000000000000000000000000 P b48c2949bd794437b9cfd934c15a67de [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:16:52.425248 10646 raft_consensus.cc:740] T 00000000000000000000000000000000 P b48c2949bd794437b9cfd934c15a67de [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: b48c2949bd794437b9cfd934c15a67de, State: Initialized, Role: FOLLOWER
I20260812 06:16:52.426086 10646 consensus_queue.cc:260] T 00000000000000000000000000000000 P b48c2949bd794437b9cfd934c15a67de [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: "b48c2949bd794437b9cfd934c15a67de" member_type: VOTER }
I20260812 06:16:52.426265 10646 raft_consensus.cc:399] T 00000000000000000000000000000000 P b48c2949bd794437b9cfd934c15a67de [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:16:52.426322 10646 raft_consensus.cc:493] T 00000000000000000000000000000000 P b48c2949bd794437b9cfd934c15a67de [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:16:52.426436 10646 raft_consensus.cc:3060] T 00000000000000000000000000000000 P b48c2949bd794437b9cfd934c15a67de [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:16:52.427452 10646 raft_consensus.cc:515] T 00000000000000000000000000000000 P b48c2949bd794437b9cfd934c15a67de [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "b48c2949bd794437b9cfd934c15a67de" member_type: VOTER }
I20260812 06:16:52.427987 10646 leader_election.cc:304] T 00000000000000000000000000000000 P b48c2949bd794437b9cfd934c15a67de [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: b48c2949bd794437b9cfd934c15a67de; no voters: 
I20260812 06:16:52.428354 10646 leader_election.cc:290] T 00000000000000000000000000000000 P b48c2949bd794437b9cfd934c15a67de [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:16:52.428508 10650 raft_consensus.cc:2804] T 00000000000000000000000000000000 P b48c2949bd794437b9cfd934c15a67de [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:16:52.428786 10650 raft_consensus.cc:697] T 00000000000000000000000000000000 P b48c2949bd794437b9cfd934c15a67de [term 1 LEADER]: Becoming Leader. State: Replica: b48c2949bd794437b9cfd934c15a67de, State: Running, Role: LEADER
I20260812 06:16:52.429325 10650 consensus_queue.cc:237] T 00000000000000000000000000000000 P b48c2949bd794437b9cfd934c15a67de [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: "b48c2949bd794437b9cfd934c15a67de" member_type: VOTER }
I20260812 06:16:52.429764 10646 sys_catalog.cc:565] T 00000000000000000000000000000000 P b48c2949bd794437b9cfd934c15a67de [sys.catalog]: configured and running, proceeding with master startup.
I20260812 06:16:52.431550 10657 sys_catalog.cc:455] T 00000000000000000000000000000000 P b48c2949bd794437b9cfd934c15a67de [sys.catalog]: SysCatalogTable state changed. Reason: New leader b48c2949bd794437b9cfd934c15a67de. Latest consensus state: current_term: 1 leader_uuid: "b48c2949bd794437b9cfd934c15a67de" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "b48c2949bd794437b9cfd934c15a67de" member_type: VOTER } }
I20260812 06:16:52.431569 10652 sys_catalog.cc:455] T 00000000000000000000000000000000 P b48c2949bd794437b9cfd934c15a67de [sys.catalog]: SysCatalogTable state changed. Reason: RaftConsensus started. Latest consensus state: current_term: 1 leader_uuid: "b48c2949bd794437b9cfd934c15a67de" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "b48c2949bd794437b9cfd934c15a67de" member_type: VOTER } }
I20260812 06:16:52.431677 10657 sys_catalog.cc:458] T 00000000000000000000000000000000 P b48c2949bd794437b9cfd934c15a67de [sys.catalog]: This master's current role is: LEADER
I20260812 06:16:52.431677 10652 sys_catalog.cc:458] T 00000000000000000000000000000000 P b48c2949bd794437b9cfd934c15a67de [sys.catalog]: This master's current role is: LEADER
I20260812 06:16:52.432116 10668 catalog_manager.cc:1511] Loading table and tablet metadata into memory...
I20260812 06:16:52.434852 10668 catalog_manager.cc:1520] Initializing Kudu cluster ID...
I20260812 06:16:52.435261 10539 internal_mini_cluster.cc:184] Waiting to initialize catalog manager on master 0
I20260812 06:16:52.441017 10668 catalog_manager.cc:1383] Generated new cluster ID: 94ed9301320a490bb0fda4b86f2c26c0
I20260812 06:16:52.441085 10668 catalog_manager.cc:1531] Initializing Kudu internal certificate authority...
I20260812 06:16:52.449674 10668 catalog_manager.cc:1406] Generated new certificate authority record
I20260812 06:16:52.451072 10668 catalog_manager.cc:1540] Loading token signing keys...
I20260812 06:16:52.461457 10668 catalog_manager.cc:6092] T 00000000000000000000000000000000 P b48c2949bd794437b9cfd934c15a67de: Generated new TSK 0
I20260812 06:16:52.462416 10668 catalog_manager.cc:1550] Initializing in-progress tserver states...
I20260812 06:16:52.468014 10539 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:16:52.471087 10683 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:16:52.471109 10689 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:16:52.471228 10684 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:16:52.471724 10539 server_base.cc:1061] running on GCE node
I20260812 06:16:52.471951 10539 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:16:52.472009 10539 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:16:52.472043 10539 hybrid_clock.cc:648] HybridClock initialized: now 1786515412472042 us; error 0 us; skew 500 ppm
I20260812 06:16:52.473117 10539 webserver.cc:533] Webserver started at http://127.10.74.193:36449/ using document root <none> and password file <none>
I20260812 06:16:52.473328 10539 fs_manager.cc:362] Metadata directory not provided
I20260812 06:16:52.473414 10539 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:16:52.473511 10539 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:16:52.473984 10539 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskQQcY3W/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515412339501-10539-0/minicluster-data/ts-0-root/instance:
uuid: "99cc7996da6743109e7a1ce05b7b4a82"
format_stamp: "Formatted at 2026-08-12 06:16:52 on dist-test-slave-nfb5"
I20260812 06:16:52.475767 10539 fs_manager.cc:696] Time spent creating directory manager: real 0.001s	user 0.002s	sys 0.000s
I20260812 06:16:52.476903 10700 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:16:52.477180 10539 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.001s	sys 0.000s
I20260812 06:16:52.477252 10539 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskQQcY3W/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515412339501-10539-0/minicluster-data/ts-0-root
uuid: "99cc7996da6743109e7a1ce05b7b4a82"
format_stamp: "Formatted at 2026-08-12 06:16:52 on dist-test-slave-nfb5"
I20260812 06:16:52.477348 10539 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskQQcY3W/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515412339501-10539-0/minicluster-data/ts-0-root
metadata directory: /tmp/dist-test-taskQQcY3W/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515412339501-10539-0/minicluster-data/ts-0-root
1 data directories: /tmp/dist-test-taskQQcY3W/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515412339501-10539-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:16:52.508888 10539 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:16:52.509536 10539 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:16:52.510188 10539 txn_system_client.cc:432] TxnSystemClient initialization is disabled...
I20260812 06:16:52.511400 10539 ts_tablet_manager.cc:585] Loaded tablet metadata (0 total tablets, 0 live tablets)
I20260812 06:16:52.511461 10539 ts_tablet_manager.cc:531] Time spent load tablet metadata: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:16:52.511539 10539 ts_tablet_manager.cc:616] Registered 0 tablets
I20260812 06:16:52.511581 10539 ts_tablet_manager.cc:595] Time spent register tablets: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:16:52.519326 10539 rpc_server.cc:307] RPC server started. Bound to: 127.10.74.193:40995
I20260812 06:16:52.519367 10794 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.10.74.193:40995 every 8 connection(s)
I20260812 06:16:52.531606 10795 heartbeater.cc:344] Connected to a master server at 127.10.74.254:42589
I20260812 06:16:52.531906 10795 heartbeater.cc:461] Registering TS with master...
I20260812 06:16:52.532517 10795 heartbeater.cc:507] Master 127.10.74.254:42589 requested a full tablet report, sending...
I20260812 06:16:52.534245 10587 ts_manager.cc:194] Registered new tserver with Master: 99cc7996da6743109e7a1ce05b7b4a82 (127.10.74.193:40995)
I20260812 06:16:52.534688 10539 internal_mini_cluster.cc:371] 1 TS(s) registered with all masters after 0.014574506s
I20260812 06:16:52.535990 10587 master_service.cc:502] Signed X509 certificate for tserver {username='slave'} at 127.0.0.1:46210
I20260812 06:16:52.545674 10587 catalog_manager.cc:2283] Servicing CreateTable request from {username='slave'} at 127.0.0.1:46226:
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:16:52.571285 10743 tablet_service.cc:1511] Processing CreateTablet for tablet 26d3bd820f754fe0af3d6fac5b39dd2d (DEFAULT_TABLE table=heavy-update-compaction-test [id=df04ca79021a42819f65290c0b5f313a]), partition=
I20260812 06:16:52.571929 10743 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet 26d3bd820f754fe0af3d6fac5b39dd2d. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:16:52.574795 10812 tablet_bootstrap.cc:492] T 26d3bd820f754fe0af3d6fac5b39dd2d P 99cc7996da6743109e7a1ce05b7b4a82: Bootstrap starting.
I20260812 06:16:52.576705 10812 tablet_bootstrap.cc:654] T 26d3bd820f754fe0af3d6fac5b39dd2d P 99cc7996da6743109e7a1ce05b7b4a82: Neither blocks nor log segments found. Creating new log.
I20260812 06:16:52.578183 10812 tablet_bootstrap.cc:492] T 26d3bd820f754fe0af3d6fac5b39dd2d P 99cc7996da6743109e7a1ce05b7b4a82: No bootstrap required, opened a new log
I20260812 06:16:52.578374 10812 ts_tablet_manager.cc:1403] T 26d3bd820f754fe0af3d6fac5b39dd2d P 99cc7996da6743109e7a1ce05b7b4a82: Time spent bootstrapping tablet: real 0.004s	user 0.003s	sys 0.000s
I20260812 06:16:52.579051 10812 raft_consensus.cc:359] T 26d3bd820f754fe0af3d6fac5b39dd2d P 99cc7996da6743109e7a1ce05b7b4a82 [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "99cc7996da6743109e7a1ce05b7b4a82" member_type: VOTER last_known_addr { host: "127.10.74.193" port: 40995 } }
I20260812 06:16:52.579202 10812 raft_consensus.cc:385] T 26d3bd820f754fe0af3d6fac5b39dd2d P 99cc7996da6743109e7a1ce05b7b4a82 [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:16:52.579260 10812 raft_consensus.cc:740] T 26d3bd820f754fe0af3d6fac5b39dd2d P 99cc7996da6743109e7a1ce05b7b4a82 [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: 99cc7996da6743109e7a1ce05b7b4a82, State: Initialized, Role: FOLLOWER
I20260812 06:16:52.579483 10812 consensus_queue.cc:260] T 26d3bd820f754fe0af3d6fac5b39dd2d P 99cc7996da6743109e7a1ce05b7b4a82 [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: "99cc7996da6743109e7a1ce05b7b4a82" member_type: VOTER last_known_addr { host: "127.10.74.193" port: 40995 } }
I20260812 06:16:52.579622 10812 raft_consensus.cc:399] T 26d3bd820f754fe0af3d6fac5b39dd2d P 99cc7996da6743109e7a1ce05b7b4a82 [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:16:52.579663 10812 raft_consensus.cc:493] T 26d3bd820f754fe0af3d6fac5b39dd2d P 99cc7996da6743109e7a1ce05b7b4a82 [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:16:52.579706 10812 raft_consensus.cc:3060] T 26d3bd820f754fe0af3d6fac5b39dd2d P 99cc7996da6743109e7a1ce05b7b4a82 [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:16:52.580878 10812 raft_consensus.cc:515] T 26d3bd820f754fe0af3d6fac5b39dd2d P 99cc7996da6743109e7a1ce05b7b4a82 [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "99cc7996da6743109e7a1ce05b7b4a82" member_type: VOTER last_known_addr { host: "127.10.74.193" port: 40995 } }
I20260812 06:16:52.581053 10812 leader_election.cc:304] T 26d3bd820f754fe0af3d6fac5b39dd2d P 99cc7996da6743109e7a1ce05b7b4a82 [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: 99cc7996da6743109e7a1ce05b7b4a82; no voters: 
I20260812 06:16:52.581331 10812 leader_election.cc:290] T 26d3bd820f754fe0af3d6fac5b39dd2d P 99cc7996da6743109e7a1ce05b7b4a82 [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:16:52.581678 10817 raft_consensus.cc:2804] T 26d3bd820f754fe0af3d6fac5b39dd2d P 99cc7996da6743109e7a1ce05b7b4a82 [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:16:52.581825 10812 ts_tablet_manager.cc:1434] T 26d3bd820f754fe0af3d6fac5b39dd2d P 99cc7996da6743109e7a1ce05b7b4a82: Time spent starting tablet: real 0.003s	user 0.003s	sys 0.000s
I20260812 06:16:52.581962 10817 raft_consensus.cc:697] T 26d3bd820f754fe0af3d6fac5b39dd2d P 99cc7996da6743109e7a1ce05b7b4a82 [term 1 LEADER]: Becoming Leader. State: Replica: 99cc7996da6743109e7a1ce05b7b4a82, State: Running, Role: LEADER
I20260812 06:16:52.582157 10817 consensus_queue.cc:237] T 26d3bd820f754fe0af3d6fac5b39dd2d P 99cc7996da6743109e7a1ce05b7b4a82 [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: "99cc7996da6743109e7a1ce05b7b4a82" member_type: VOTER last_known_addr { host: "127.10.74.193" port: 40995 } }
I20260812 06:16:52.582468 10795 heartbeater.cc:499] Master 127.10.74.254:42589 was elected leader, sending a full tablet report...
I20260812 06:16:52.585633 10587 catalog_manager.cc:5719] T 26d3bd820f754fe0af3d6fac5b39dd2d P 99cc7996da6743109e7a1ce05b7b4a82 reported cstate change: term changed from 0 to 1, leader changed from <none> to 99cc7996da6743109e7a1ce05b7b4a82 (127.10.74.193). New cstate: current_term: 1 leader_uuid: "99cc7996da6743109e7a1ce05b7b4a82" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "99cc7996da6743109e7a1ce05b7b4a82" member_type: VOTER last_known_addr { host: "127.10.74.193" port: 40995 } health_report { overall_health: HEALTHY } } }
I20260812 06:16:52.673605 10539 heavy-update-compaction-itest.cc:215] Time spent inserting: real 0.077s	user 0.022s	sys 0.015s
I20260812 06:16:52.770694 10796 maintenance_manager.cc:419] P 99cc7996da6743109e7a1ce05b7b4a82: Scheduling FlushMRSOp(26d3bd820f754fe0af3d6fac5b39dd2d): perf score=10.125253
I20260812 06:16:52.944494 10707 maintenance_manager.cc:643] P 99cc7996da6743109e7a1ce05b7b4a82: FlushMRSOp(26d3bd820f754fe0af3d6fac5b39dd2d) complete. Timing: real 0.173s	user 0.110s	sys 0.044s Metrics: {"bytes_written":8205078,"cfile_init":1,"compiler_manager_pool.queue_time_us":60,"delete_count":0,"dirs.queue_time_us":50,"dirs.run_cpu_time_us":205,"dirs.run_wall_time_us":822,"drs_written":1,"lbm_read_time_us":77,"lbm_reads_lt_1ms":4,"lbm_write_time_us":44725,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":456,"mutex_wait_us":231,"peak_mem_usage":0,"reinsert_count":0,"rows_written":102,"spinlock_wait_cycles":340224,"update_count":1000}
I20260812 06:16:52.946233 10796 maintenance_manager.cc:419] P 99cc7996da6743109e7a1ce05b7b4a82: Scheduling LogGCOp(26d3bd820f754fe0af3d6fac5b39dd2d): free 8725963 bytes of WAL
I20260812 06:16:52.946727 10707 log_reader.cc:385] T 26d3bd820f754fe0af3d6fac5b39dd2d: removed 1 log segments from log reader
I20260812 06:16:52.946870 10707 log.cc:1079] T 26d3bd820f754fe0af3d6fac5b39dd2d P 99cc7996da6743109e7a1ce05b7b4a82: Deleting log segment in path: /tmp/dist-test-taskQQcY3W/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515412339501-10539-0/minicluster-data/ts-0-root/wals/26d3bd820f754fe0af3d6fac5b39dd2d/wal-000000001 (ops 1-6)
I20260812 06:16:52.949939 10707 maintenance_manager.cc:643] P 99cc7996da6743109e7a1ce05b7b4a82: LogGCOp(26d3bd820f754fe0af3d6fac5b39dd2d) complete. Timing: real 0.003s	user 0.000s	sys 0.000s Metrics: {}
I20260812 06:16:52.950510 10796 maintenance_manager.cc:419] P 99cc7996da6743109e7a1ce05b7b4a82: Scheduling MajorDeltaCompactionOp(26d3bd820f754fe0af3d6fac5b39dd2d): perf score=1.000000
I20260812 06:16:53.110095 10707 maintenance_manager.cc:643] P 99cc7996da6743109e7a1ce05b7b4a82: MajorDeltaCompactionOp(26d3bd820f754fe0af3d6fac5b39dd2d) complete. Timing: real 0.159s	user 0.142s	sys 0.012s Metrics: {"cfile_cache_miss":231,"cfile_cache_miss_bytes":12385404,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":1,"delta_iterators_relevant":1,"dirs.queue_time_us":854,"lbm_read_time_us":9148,"lbm_reads_lt_1ms":263,"lbm_write_time_us":22482,"lbm_writes_lt_1ms":243,"mutex_wait_us":116,"peak_mem_usage":25836184,"reinsert_count":0,"thread_start_us":425,"threads_started":5,"update_count":1000}
I20260812 06:16:53.110900 10796 maintenance_manager.cc:419] P 99cc7996da6743109e7a1ce05b7b4a82: Scheduling FlushDeltaMemStoresOp(26d3bd820f754fe0af3d6fac5b39dd2d): perf score=7.149875
I20260812 06:16:53.146147 10707 maintenance_manager.cc:643] P 99cc7996da6743109e7a1ce05b7b4a82: FlushDeltaMemStoresOp(26d3bd820f754fe0af3d6fac5b39dd2d) complete. Timing: real 0.035s	user 0.021s	sys 0.010s Metrics: {"bytes_written":8615323,"delete_count":0,"lbm_write_time_us":13679,"lbm_writes_lt_1ms":213,"reinsert_count":0,"update_count":1050}
I20260812 06:16:53.147214 10796 maintenance_manager.cc:419] P 99cc7996da6743109e7a1ce05b7b4a82: Scheduling UndoDeltaBlockGCOp(26d3bd820f754fe0af3d6fac5b39dd2d): 8206538 bytes on disk
I20260812 06:16:53.148149 10707 maintenance_manager.cc:643] P 99cc7996da6743109e7a1ce05b7b4a82: UndoDeltaBlockGCOp(26d3bd820f754fe0af3d6fac5b39dd2d) complete. Timing: real 0.001s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":117,"lbm_reads_lt_1ms":4}
I20260812 06:16:53.148618 10796 maintenance_manager.cc:419] P 99cc7996da6743109e7a1ce05b7b4a82: Scheduling FlushDeltaMemStoresOp(26d3bd820f754fe0af3d6fac5b39dd2d): perf score=2.188937
I20260812 06:16:53.169468 10707 maintenance_manager.cc:643] P 99cc7996da6743109e7a1ce05b7b4a82: FlushDeltaMemStoresOp(26d3bd820f754fe0af3d6fac5b39dd2d) complete. Timing: real 0.021s	user 0.004s	sys 0.012s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":5734,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:16:53.170173 10796 maintenance_manager.cc:419] P 99cc7996da6743109e7a1ce05b7b4a82: Scheduling MajorDeltaCompactionOp(26d3bd820f754fe0af3d6fac5b39dd2d): perf score=1.000000
I20260812 06:16:53.317504 10707 maintenance_manager.cc:643] P 99cc7996da6743109e7a1ce05b7b4a82: MajorDeltaCompactionOp(26d3bd820f754fe0af3d6fac5b39dd2d) complete. Timing: real 0.147s	user 0.102s	sys 0.044s Metrics: {"cfile_cache_miss":332,"cfile_cache_miss_bytes":16487926,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":808,"lbm_read_time_us":10973,"lbm_reads_lt_1ms":364,"lbm_write_time_us":21798,"lbm_writes_lt_1ms":343,"mutex_wait_us":344,"peak_mem_usage":38262756,"reinsert_count":0,"update_count":1500}
I20260812 06:16:53.318071 10796 maintenance_manager.cc:419] P 99cc7996da6743109e7a1ce05b7b4a82: Scheduling FlushDeltaMemStoresOp(26d3bd820f754fe0af3d6fac5b39dd2d): perf score=10.126437
I20260812 06:16:53.375988 10707 maintenance_manager.cc:643] P 99cc7996da6743109e7a1ce05b7b4a82: FlushDeltaMemStoresOp(26d3bd820f754fe0af3d6fac5b39dd2d) complete. Timing: real 0.058s	user 0.037s	sys 0.007s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":20525,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:16:53.376669 10796 maintenance_manager.cc:419] P 99cc7996da6743109e7a1ce05b7b4a82: Scheduling FlushDeltaMemStoresOp(26d3bd820f754fe0af3d6fac5b39dd2d): perf score=2.188937
I20260812 06:16:53.392247 10707 maintenance_manager.cc:643] P 99cc7996da6743109e7a1ce05b7b4a82: FlushDeltaMemStoresOp(26d3bd820f754fe0af3d6fac5b39dd2d) complete. Timing: real 0.015s	user 0.012s	sys 0.002s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5710,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:53.392829 10796 maintenance_manager.cc:419] P 99cc7996da6743109e7a1ce05b7b4a82: Scheduling MajorDeltaCompactionOp(26d3bd820f754fe0af3d6fac5b39dd2d): perf score=1.000000
I20260812 06:16:53.543469 10707 maintenance_manager.cc:643] P 99cc7996da6743109e7a1ce05b7b4a82: MajorDeltaCompactionOp(26d3bd820f754fe0af3d6fac5b39dd2d) complete. Timing: real 0.150s	user 0.105s	sys 0.045s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20590347,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":665,"lbm_read_time_us":10316,"lbm_reads_lt_1ms":472,"lbm_write_time_us":29520,"lbm_writes_lt_1ms":443,"mutex_wait_us":306,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":14080,"update_count":2000}
I20260812 06:16:53.544083 10796 maintenance_manager.cc:419] P 99cc7996da6743109e7a1ce05b7b4a82: Scheduling FlushDeltaMemStoresOp(26d3bd820f754fe0af3d6fac5b39dd2d): perf score=10.126437
I20260812 06:16:53.594055 10707 maintenance_manager.cc:643] P 99cc7996da6743109e7a1ce05b7b4a82: FlushDeltaMemStoresOp(26d3bd820f754fe0af3d6fac5b39dd2d) complete. Timing: real 0.050s	user 0.025s	sys 0.014s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":19245,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:16:53.594755 10796 maintenance_manager.cc:419] P 99cc7996da6743109e7a1ce05b7b4a82: Scheduling FlushDeltaMemStoresOp(26d3bd820f754fe0af3d6fac5b39dd2d): perf score=2.188937
I20260812 06:16:53.607851 10707 maintenance_manager.cc:643] P 99cc7996da6743109e7a1ce05b7b4a82: FlushDeltaMemStoresOp(26d3bd820f754fe0af3d6fac5b39dd2d) complete. Timing: real 0.013s	user 0.011s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4593,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:53.608582 10796 maintenance_manager.cc:419] P 99cc7996da6743109e7a1ce05b7b4a82: Scheduling MajorDeltaCompactionOp(26d3bd820f754fe0af3d6fac5b39dd2d): perf score=1.000000
I20260812 06:16:53.754459 10707 maintenance_manager.cc:643] P 99cc7996da6743109e7a1ce05b7b4a82: MajorDeltaCompactionOp(26d3bd820f754fe0af3d6fac5b39dd2d) complete. Timing: real 0.146s	user 0.121s	sys 0.024s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20590347,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":270,"lbm_read_time_us":10362,"lbm_reads_lt_1ms":472,"lbm_write_time_us":30003,"lbm_writes_lt_1ms":443,"mutex_wait_us":42,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":2816,"update_count":2000}
I20260812 06:16:53.755330 10796 maintenance_manager.cc:419] P 99cc7996da6743109e7a1ce05b7b4a82: Scheduling FlushDeltaMemStoresOp(26d3bd820f754fe0af3d6fac5b39dd2d): perf score=10.126437
I20260812 06:16:53.812597 10707 maintenance_manager.cc:643] P 99cc7996da6743109e7a1ce05b7b4a82: FlushDeltaMemStoresOp(26d3bd820f754fe0af3d6fac5b39dd2d) complete. Timing: real 0.057s	user 0.023s	sys 0.020s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":17025,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:16:53.813184 10796 maintenance_manager.cc:419] P 99cc7996da6743109e7a1ce05b7b4a82: Scheduling FlushDeltaMemStoresOp(26d3bd820f754fe0af3d6fac5b39dd2d): perf score=2.188937
I20260812 06:16:53.825038 10707 maintenance_manager.cc:643] P 99cc7996da6743109e7a1ce05b7b4a82: FlushDeltaMemStoresOp(26d3bd820f754fe0af3d6fac5b39dd2d) complete. Timing: real 0.012s	user 0.006s	sys 0.003s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4709,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:53.825538 10796 maintenance_manager.cc:419] P 99cc7996da6743109e7a1ce05b7b4a82: Scheduling MajorDeltaCompactionOp(26d3bd820f754fe0af3d6fac5b39dd2d): perf score=1.000000
I20260812 06:16:53.997500 10707 maintenance_manager.cc:643] P 99cc7996da6743109e7a1ce05b7b4a82: MajorDeltaCompactionOp(26d3bd820f754fe0af3d6fac5b39dd2d) complete. Timing: real 0.172s	user 0.103s	sys 0.064s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20590347,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":290,"lbm_read_time_us":12600,"lbm_reads_lt_1ms":472,"lbm_write_time_us":29482,"lbm_writes_lt_1ms":443,"mutex_wait_us":43,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":9728,"update_count":2000}
I20260812 06:16:53.998090 10796 maintenance_manager.cc:419] P 99cc7996da6743109e7a1ce05b7b4a82: Scheduling FlushDeltaMemStoresOp(26d3bd820f754fe0af3d6fac5b39dd2d): perf score=10.126437
I20260812 06:16:54.049751 10707 maintenance_manager.cc:643] P 99cc7996da6743109e7a1ce05b7b4a82: FlushDeltaMemStoresOp(26d3bd820f754fe0af3d6fac5b39dd2d) complete. Timing: real 0.051s	user 0.026s	sys 0.012s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":18312,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:16:54.050364 10796 maintenance_manager.cc:419] P 99cc7996da6743109e7a1ce05b7b4a82: Scheduling FlushDeltaMemStoresOp(26d3bd820f754fe0af3d6fac5b39dd2d): perf score=2.188937
I20260812 06:16:54.063162 10707 maintenance_manager.cc:643] P 99cc7996da6743109e7a1ce05b7b4a82: FlushDeltaMemStoresOp(26d3bd820f754fe0af3d6fac5b39dd2d) complete. Timing: real 0.013s	user 0.005s	sys 0.007s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4665,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:54.063886 10796 maintenance_manager.cc:419] P 99cc7996da6743109e7a1ce05b7b4a82: Scheduling MajorDeltaCompactionOp(26d3bd820f754fe0af3d6fac5b39dd2d): perf score=1.000000
I20260812 06:16:54.213673 10707 maintenance_manager.cc:643] P 99cc7996da6743109e7a1ce05b7b4a82: MajorDeltaCompactionOp(26d3bd820f754fe0af3d6fac5b39dd2d) complete. Timing: real 0.149s	user 0.109s	sys 0.040s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20590347,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":211,"lbm_read_time_us":11873,"lbm_reads_lt_1ms":472,"lbm_write_time_us":28421,"lbm_writes_lt_1ms":443,"mutex_wait_us":24,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":896,"update_count":2000}
I20260812 06:16:54.214661 10796 maintenance_manager.cc:419] P 99cc7996da6743109e7a1ce05b7b4a82: Scheduling FlushDeltaMemStoresOp(26d3bd820f754fe0af3d6fac5b39dd2d): perf score=10.126437
I20260812 06:16:54.260366 10707 maintenance_manager.cc:643] P 99cc7996da6743109e7a1ce05b7b4a82: FlushDeltaMemStoresOp(26d3bd820f754fe0af3d6fac5b39dd2d) complete. Timing: real 0.045s	user 0.032s	sys 0.011s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":19471,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":302,"reinsert_count":0,"update_count":1500}
I20260812 06:16:54.260946 10796 maintenance_manager.cc:419] P 99cc7996da6743109e7a1ce05b7b4a82: Scheduling FlushDeltaMemStoresOp(26d3bd820f754fe0af3d6fac5b39dd2d): perf score=2.188937
I20260812 06:16:54.274816 10707 maintenance_manager.cc:643] P 99cc7996da6743109e7a1ce05b7b4a82: FlushDeltaMemStoresOp(26d3bd820f754fe0af3d6fac5b39dd2d) complete. Timing: real 0.014s	user 0.007s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5230,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:54.275596 10796 maintenance_manager.cc:419] P 99cc7996da6743109e7a1ce05b7b4a82: Scheduling MajorDeltaCompactionOp(26d3bd820f754fe0af3d6fac5b39dd2d): perf score=1.000000
I20260812 06:16:54.425202 10707 maintenance_manager.cc:643] P 99cc7996da6743109e7a1ce05b7b4a82: MajorDeltaCompactionOp(26d3bd820f754fe0af3d6fac5b39dd2d) complete. Timing: real 0.149s	user 0.133s	sys 0.016s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20590347,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":262,"lbm_read_time_us":9838,"lbm_reads_lt_1ms":464,"lbm_write_time_us":30034,"lbm_writes_lt_1ms":443,"mutex_wait_us":42,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":18560,"update_count":2000}
I20260812 06:16:54.426110 10796 maintenance_manager.cc:419] P 99cc7996da6743109e7a1ce05b7b4a82: Scheduling FlushDeltaMemStoresOp(26d3bd820f754fe0af3d6fac5b39dd2d): perf score=10.126437
I20260812 06:16:54.477602 10707 maintenance_manager.cc:643] P 99cc7996da6743109e7a1ce05b7b4a82: FlushDeltaMemStoresOp(26d3bd820f754fe0af3d6fac5b39dd2d) complete. Timing: real 0.051s	user 0.033s	sys 0.015s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":20245,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:16:54.478296 10796 maintenance_manager.cc:419] P 99cc7996da6743109e7a1ce05b7b4a82: Scheduling FlushDeltaMemStoresOp(26d3bd820f754fe0af3d6fac5b39dd2d): perf score=2.188937
I20260812 06:16:54.491581 10707 maintenance_manager.cc:643] P 99cc7996da6743109e7a1ce05b7b4a82: FlushDeltaMemStoresOp(26d3bd820f754fe0af3d6fac5b39dd2d) complete. Timing: real 0.013s	user 0.012s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5108,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:54.492352 10796 maintenance_manager.cc:419] P 99cc7996da6743109e7a1ce05b7b4a82: Scheduling FlushMRSOp(26d3bd820f754fe0af3d6fac5b39dd2d): perf score=1.000000
I20260812 06:16:54.523272 10707 maintenance_manager.cc:643] P 99cc7996da6743109e7a1ce05b7b4a82: FlushMRSOp(26d3bd820f754fe0af3d6fac5b39dd2d) complete. Timing: real 0.031s	user 0.019s	sys 0.008s Metrics: {"bytes_written":1193504,"cfile_init":1,"dirs.queue_time_us":87,"dirs.run_cpu_time_us":384,"dirs.run_wall_time_us":1437,"drs_written":1,"lbm_read_time_us":44,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1954,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":29}
I20260812 06:16:54.524389 10796 maintenance_manager.cc:419] P 99cc7996da6743109e7a1ce05b7b4a82: Scheduling MajorDeltaCompactionOp(26d3bd820f754fe0af3d6fac5b39dd2d): perf score=1.000000
I20260812 06:16:54.702099 10707 maintenance_manager.cc:643] P 99cc7996da6743109e7a1ce05b7b4a82: MajorDeltaCompactionOp(26d3bd820f754fe0af3d6fac5b39dd2d) complete. Timing: real 0.178s	user 0.118s	sys 0.056s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20590347,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":304,"lbm_read_time_us":11673,"lbm_reads_lt_1ms":464,"lbm_write_time_us":29319,"lbm_writes_lt_1ms":443,"mutex_wait_us":40,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":6784,"update_count":2000}
I20260812 06:16:54.703207 10796 maintenance_manager.cc:419] P 99cc7996da6743109e7a1ce05b7b4a82: Scheduling LogGCOp(26d3bd820f754fe0af3d6fac5b39dd2d): free 123804181 bytes of WAL
I20260812 06:16:54.703568 10707 log_reader.cc:385] T 26d3bd820f754fe0af3d6fac5b39dd2d: removed 12 log segments from log reader
I20260812 06:16:54.703646 10707 log.cc:1079] T 26d3bd820f754fe0af3d6fac5b39dd2d P 99cc7996da6743109e7a1ce05b7b4a82: Deleting log segment in path: /tmp/dist-test-taskQQcY3W/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515412339501-10539-0/minicluster-data/ts-0-root/wals/26d3bd820f754fe0af3d6fac5b39dd2d/wal-000000002 (ops 7-10)
I20260812 06:16:54.703701 10707 log.cc:1079] T 26d3bd820f754fe0af3d6fac5b39dd2d P 99cc7996da6743109e7a1ce05b7b4a82: Deleting log segment in path: /tmp/dist-test-taskQQcY3W/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515412339501-10539-0/minicluster-data/ts-0-root/wals/26d3bd820f754fe0af3d6fac5b39dd2d/wal-000000003 (ops 11-15)
I20260812 06:16:54.703743 10707 log.cc:1079] T 26d3bd820f754fe0af3d6fac5b39dd2d P 99cc7996da6743109e7a1ce05b7b4a82: Deleting log segment in path: /tmp/dist-test-taskQQcY3W/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515412339501-10539-0/minicluster-data/ts-0-root/wals/26d3bd820f754fe0af3d6fac5b39dd2d/wal-000000004 (ops 16-20)
I20260812 06:16:54.703781 10707 log.cc:1079] T 26d3bd820f754fe0af3d6fac5b39dd2d P 99cc7996da6743109e7a1ce05b7b4a82: Deleting log segment in path: /tmp/dist-test-taskQQcY3W/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515412339501-10539-0/minicluster-data/ts-0-root/wals/26d3bd820f754fe0af3d6fac5b39dd2d/wal-000000005 (ops 21-25)
I20260812 06:16:54.703824 10707 log.cc:1079] T 26d3bd820f754fe0af3d6fac5b39dd2d P 99cc7996da6743109e7a1ce05b7b4a82: Deleting log segment in path: /tmp/dist-test-taskQQcY3W/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515412339501-10539-0/minicluster-data/ts-0-root/wals/26d3bd820f754fe0af3d6fac5b39dd2d/wal-000000006 (ops 26-30)
I20260812 06:16:54.703869 10707 log.cc:1079] T 26d3bd820f754fe0af3d6fac5b39dd2d P 99cc7996da6743109e7a1ce05b7b4a82: Deleting log segment in path: /tmp/dist-test-taskQQcY3W/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515412339501-10539-0/minicluster-data/ts-0-root/wals/26d3bd820f754fe0af3d6fac5b39dd2d/wal-000000007 (ops 31-35)
I20260812 06:16:54.703912 10707 log.cc:1079] T 26d3bd820f754fe0af3d6fac5b39dd2d P 99cc7996da6743109e7a1ce05b7b4a82: Deleting log segment in path: /tmp/dist-test-taskQQcY3W/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515412339501-10539-0/minicluster-data/ts-0-root/wals/26d3bd820f754fe0af3d6fac5b39dd2d/wal-000000008 (ops 36-40)
I20260812 06:16:54.703954 10707 log.cc:1079] T 26d3bd820f754fe0af3d6fac5b39dd2d P 99cc7996da6743109e7a1ce05b7b4a82: Deleting log segment in path: /tmp/dist-test-taskQQcY3W/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515412339501-10539-0/minicluster-data/ts-0-root/wals/26d3bd820f754fe0af3d6fac5b39dd2d/wal-000000009 (ops 41-45)
I20260812 06:16:54.704003 10707 log.cc:1079] T 26d3bd820f754fe0af3d6fac5b39dd2d P 99cc7996da6743109e7a1ce05b7b4a82: Deleting log segment in path: /tmp/dist-test-taskQQcY3W/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515412339501-10539-0/minicluster-data/ts-0-root/wals/26d3bd820f754fe0af3d6fac5b39dd2d/wal-000000010 (ops 46-50)
I20260812 06:16:54.704044 10707 log.cc:1079] T 26d3bd820f754fe0af3d6fac5b39dd2d P 99cc7996da6743109e7a1ce05b7b4a82: Deleting log segment in path: /tmp/dist-test-taskQQcY3W/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515412339501-10539-0/minicluster-data/ts-0-root/wals/26d3bd820f754fe0af3d6fac5b39dd2d/wal-000000011 (ops 51-54)
I20260812 06:16:54.704082 10707 log.cc:1079] T 26d3bd820f754fe0af3d6fac5b39dd2d P 99cc7996da6743109e7a1ce05b7b4a82: Deleting log segment in path: /tmp/dist-test-taskQQcY3W/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515412339501-10539-0/minicluster-data/ts-0-root/wals/26d3bd820f754fe0af3d6fac5b39dd2d/wal-000000012 (ops 55-59)
I20260812 06:16:54.704120 10707 log.cc:1079] T 26d3bd820f754fe0af3d6fac5b39dd2d P 99cc7996da6743109e7a1ce05b7b4a82: Deleting log segment in path: /tmp/dist-test-taskQQcY3W/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515412339501-10539-0/minicluster-data/ts-0-root/wals/26d3bd820f754fe0af3d6fac5b39dd2d/wal-000000013 (ops 60-64)
I20260812 06:16:54.734136 10707 maintenance_manager.cc:643] P 99cc7996da6743109e7a1ce05b7b4a82: LogGCOp(26d3bd820f754fe0af3d6fac5b39dd2d) complete. Timing: real 0.031s	user 0.004s	sys 0.024s Metrics: {}
I20260812 06:16:54.734800 10796 maintenance_manager.cc:419] P 99cc7996da6743109e7a1ce05b7b4a82: Scheduling FlushDeltaMemStoresOp(26d3bd820f754fe0af3d6fac5b39dd2d): perf score=14.095187
I20260812 06:16:54.790599 10707 maintenance_manager.cc:643] P 99cc7996da6743109e7a1ce05b7b4a82: FlushDeltaMemStoresOp(26d3bd820f754fe0af3d6fac5b39dd2d) complete. Timing: real 0.056s	user 0.035s	sys 0.017s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":25308,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:16:54.791371 10796 maintenance_manager.cc:419] P 99cc7996da6743109e7a1ce05b7b4a82: Scheduling UndoDeltaBlockGCOp(26d3bd820f754fe0af3d6fac5b39dd2d): 462 bytes on disk
I20260812 06:16:54.791941 10707 maintenance_manager.cc:643] P 99cc7996da6743109e7a1ce05b7b4a82: UndoDeltaBlockGCOp(26d3bd820f754fe0af3d6fac5b39dd2d) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":87,"lbm_reads_lt_1ms":4}
I20260812 06:16:54.792580 10796 maintenance_manager.cc:419] P 99cc7996da6743109e7a1ce05b7b4a82: Scheduling FlushDeltaMemStoresOp(26d3bd820f754fe0af3d6fac5b39dd2d): perf score=2.188937
I20260812 06:16:54.809563 10707 maintenance_manager.cc:643] P 99cc7996da6743109e7a1ce05b7b4a82: FlushDeltaMemStoresOp(26d3bd820f754fe0af3d6fac5b39dd2d) complete. Timing: real 0.017s	user 0.010s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6375,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:54.810115 10796 maintenance_manager.cc:419] P 99cc7996da6743109e7a1ce05b7b4a82: Scheduling MajorDeltaCompactionOp(26d3bd820f754fe0af3d6fac5b39dd2d): perf score=1.000000
I20260812 06:16:55.008575 10707 maintenance_manager.cc:643] P 99cc7996da6743109e7a1ce05b7b4a82: MajorDeltaCompactionOp(26d3bd820f754fe0af3d6fac5b39dd2d) complete. Timing: real 0.198s	user 0.135s	sys 0.056s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24692758,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":1198,"lbm_read_time_us":13817,"lbm_reads_lt_1ms":572,"lbm_write_time_us":34288,"lbm_writes_lt_1ms":543,"mutex_wait_us":804,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":2688,"update_count":2500}
I20260812 06:16:55.009434 10796 maintenance_manager.cc:419] P 99cc7996da6743109e7a1ce05b7b4a82: Scheduling FlushDeltaMemStoresOp(26d3bd820f754fe0af3d6fac5b39dd2d): perf score=11.118625
I20260812 06:16:55.050844 10707 maintenance_manager.cc:643] P 99cc7996da6743109e7a1ce05b7b4a82: FlushDeltaMemStoresOp(26d3bd820f754fe0af3d6fac5b39dd2d) complete. Timing: real 0.041s	user 0.017s	sys 0.020s Metrics: {"bytes_written":12717737,"delete_count":0,"lbm_write_time_us":18266,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:16:55.051729 10796 maintenance_manager.cc:419] P 99cc7996da6743109e7a1ce05b7b4a82: Scheduling FlushDeltaMemStoresOp(26d3bd820f754fe0af3d6fac5b39dd2d): perf score=2.188937
I20260812 06:16:55.071452 10707 maintenance_manager.cc:643] P 99cc7996da6743109e7a1ce05b7b4a82: FlushDeltaMemStoresOp(26d3bd820f754fe0af3d6fac5b39dd2d) complete. Timing: real 0.019s	user 0.015s	sys 0.000s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":5951,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:16:55.072069 10796 maintenance_manager.cc:419] P 99cc7996da6743109e7a1ce05b7b4a82: Scheduling MajorDeltaCompactionOp(26d3bd820f754fe0af3d6fac5b39dd2d): perf score=1.000000
I20260812 06:16:55.217381 10707 maintenance_manager.cc:643] P 99cc7996da6743109e7a1ce05b7b4a82: MajorDeltaCompactionOp(26d3bd820f754fe0af3d6fac5b39dd2d) complete. Timing: real 0.145s	user 0.096s	sys 0.047s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20590340,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":1763,"lbm_read_time_us":9263,"lbm_reads_lt_1ms":464,"lbm_write_time_us":25692,"lbm_writes_lt_1ms":443,"mutex_wait_us":1571,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":2560,"update_count":2000}
I20260812 06:16:55.218199 10796 maintenance_manager.cc:419] P 99cc7996da6743109e7a1ce05b7b4a82: Scheduling FlushDeltaMemStoresOp(26d3bd820f754fe0af3d6fac5b39dd2d): perf score=10.126437
I20260812 06:16:55.271041 10707 maintenance_manager.cc:643] P 99cc7996da6743109e7a1ce05b7b4a82: FlushDeltaMemStoresOp(26d3bd820f754fe0af3d6fac5b39dd2d) complete. Timing: real 0.052s	user 0.034s	sys 0.011s Metrics: {"bytes_written":12307492,"delete_count":0,"lbm_write_time_us":19853,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:16:55.271670 10796 maintenance_manager.cc:419] P 99cc7996da6743109e7a1ce05b7b4a82: Scheduling FlushDeltaMemStoresOp(26d3bd820f754fe0af3d6fac5b39dd2d): perf score=2.188937
I20260812 06:16:55.283936 10707 maintenance_manager.cc:643] P 99cc7996da6743109e7a1ce05b7b4a82: FlushDeltaMemStoresOp(26d3bd820f754fe0af3d6fac5b39dd2d) complete. Timing: real 0.012s	user 0.011s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4533,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:55.284799 10796 maintenance_manager.cc:419] P 99cc7996da6743109e7a1ce05b7b4a82: Scheduling MajorDeltaCompactionOp(26d3bd820f754fe0af3d6fac5b39dd2d): perf score=1.000000
I20260812 06:16:55.434345 10707 maintenance_manager.cc:643] P 99cc7996da6743109e7a1ce05b7b4a82: MajorDeltaCompactionOp(26d3bd820f754fe0af3d6fac5b39dd2d) complete. Timing: real 0.149s	user 0.116s	sys 0.032s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20590349,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":1110,"lbm_read_time_us":9601,"lbm_reads_lt_1ms":472,"lbm_write_time_us":27851,"lbm_writes_lt_1ms":443,"mutex_wait_us":64,"peak_mem_usage":50689328,"reinsert_count":0,"update_count":2000}
I20260812 06:16:55.435370 10796 maintenance_manager.cc:419] P 99cc7996da6743109e7a1ce05b7b4a82: Scheduling FlushDeltaMemStoresOp(26d3bd820f754fe0af3d6fac5b39dd2d): perf score=10.126437
I20260812 06:16:55.495846 10707 maintenance_manager.cc:643] P 99cc7996da6743109e7a1ce05b7b4a82: FlushDeltaMemStoresOp(26d3bd820f754fe0af3d6fac5b39dd2d) complete. Timing: real 0.060s	user 0.036s	sys 0.023s Metrics: {"bytes_written":12307491,"delete_count":0,"lbm_write_time_us":23594,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":302,"reinsert_count":0,"update_count":1500}
I20260812 06:16:55.496538 10796 maintenance_manager.cc:419] P 99cc7996da6743109e7a1ce05b7b4a82: Scheduling FlushDeltaMemStoresOp(26d3bd820f754fe0af3d6fac5b39dd2d): perf score=2.188937
I20260812 06:16:55.513815 10707 maintenance_manager.cc:643] P 99cc7996da6743109e7a1ce05b7b4a82: FlushDeltaMemStoresOp(26d3bd820f754fe0af3d6fac5b39dd2d) complete. Timing: real 0.017s	user 0.007s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5020,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:55.514451 10796 maintenance_manager.cc:419] P 99cc7996da6743109e7a1ce05b7b4a82: Scheduling MajorDeltaCompactionOp(26d3bd820f754fe0af3d6fac5b39dd2d): perf score=1.000000
I20260812 06:16:55.688439 10707 maintenance_manager.cc:643] P 99cc7996da6743109e7a1ce05b7b4a82: MajorDeltaCompactionOp(26d3bd820f754fe0af3d6fac5b39dd2d) complete. Timing: real 0.174s	user 0.118s	sys 0.052s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20590348,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":631,"lbm_read_time_us":12673,"lbm_reads_lt_1ms":472,"lbm_write_time_us":28350,"lbm_writes_lt_1ms":443,"mutex_wait_us":342,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":128768,"update_count":2000}
I20260812 06:16:55.689016 10796 maintenance_manager.cc:419] P 99cc7996da6743109e7a1ce05b7b4a82: Scheduling FlushDeltaMemStoresOp(26d3bd820f754fe0af3d6fac5b39dd2d): perf score=10.126437
I20260812 06:16:55.750828 10707 maintenance_manager.cc:643] P 99cc7996da6743109e7a1ce05b7b4a82: FlushDeltaMemStoresOp(26d3bd820f754fe0af3d6fac5b39dd2d) complete. Timing: real 0.061s	user 0.035s	sys 0.015s Metrics: {"bytes_written":12307505,"delete_count":0,"lbm_write_time_us":26633,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":302,"reinsert_count":0,"update_count":1500}
I20260812 06:16:55.751484 10796 maintenance_manager.cc:419] P 99cc7996da6743109e7a1ce05b7b4a82: Scheduling FlushDeltaMemStoresOp(26d3bd820f754fe0af3d6fac5b39dd2d): perf score=2.188937
I20260812 06:16:55.766273 10707 maintenance_manager.cc:643] P 99cc7996da6743109e7a1ce05b7b4a82: FlushDeltaMemStoresOp(26d3bd820f754fe0af3d6fac5b39dd2d) complete. Timing: real 0.015s	user 0.003s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5013,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:55.767328 10796 maintenance_manager.cc:419] P 99cc7996da6743109e7a1ce05b7b4a82: Scheduling MajorDeltaCompactionOp(26d3bd820f754fe0af3d6fac5b39dd2d): perf score=1.000000
I20260812 06:16:55.916955 10707 maintenance_manager.cc:643] P 99cc7996da6743109e7a1ce05b7b4a82: MajorDeltaCompactionOp(26d3bd820f754fe0af3d6fac5b39dd2d) complete. Timing: real 0.149s	user 0.120s	sys 0.025s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20590362,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":530,"lbm_read_time_us":11154,"lbm_reads_lt_1ms":472,"lbm_write_time_us":29620,"lbm_writes_lt_1ms":443,"peak_mem_usage":50689328,"reinsert_count":0,"update_count":2000}
I20260812 06:16:55.917747 10796 maintenance_manager.cc:419] P 99cc7996da6743109e7a1ce05b7b4a82: Scheduling FlushDeltaMemStoresOp(26d3bd820f754fe0af3d6fac5b39dd2d): perf score=10.126437
I20260812 06:16:55.969528 10707 maintenance_manager.cc:643] P 99cc7996da6743109e7a1ce05b7b4a82: FlushDeltaMemStoresOp(26d3bd820f754fe0af3d6fac5b39dd2d) complete. Timing: real 0.052s	user 0.016s	sys 0.025s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":20837,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:16:55.970091 10796 maintenance_manager.cc:419] P 99cc7996da6743109e7a1ce05b7b4a82: Scheduling FlushDeltaMemStoresOp(26d3bd820f754fe0af3d6fac5b39dd2d): perf score=2.188937
I20260812 06:16:55.982479 10707 maintenance_manager.cc:643] P 99cc7996da6743109e7a1ce05b7b4a82: FlushDeltaMemStoresOp(26d3bd820f754fe0af3d6fac5b39dd2d) complete. Timing: real 0.012s	user 0.006s	sys 0.003s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4542,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:55.983206 10796 maintenance_manager.cc:419] P 99cc7996da6743109e7a1ce05b7b4a82: Scheduling MajorDeltaCompactionOp(26d3bd820f754fe0af3d6fac5b39dd2d): perf score=1.000000
I20260812 06:16:56.130945 10707 maintenance_manager.cc:643] P 99cc7996da6743109e7a1ce05b7b4a82: MajorDeltaCompactionOp(26d3bd820f754fe0af3d6fac5b39dd2d) complete. Timing: real 0.147s	user 0.126s	sys 0.021s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20590347,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":226,"lbm_read_time_us":9008,"lbm_reads_lt_1ms":472,"lbm_write_time_us":31561,"lbm_writes_lt_1ms":443,"mutex_wait_us":64,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":7040,"update_count":2000}
I20260812 06:16:56.131742 10796 maintenance_manager.cc:419] P 99cc7996da6743109e7a1ce05b7b4a82: Scheduling FlushDeltaMemStoresOp(26d3bd820f754fe0af3d6fac5b39dd2d): perf score=10.126437
I20260812 06:16:56.186277 10707 maintenance_manager.cc:643] P 99cc7996da6743109e7a1ce05b7b4a82: FlushDeltaMemStoresOp(26d3bd820f754fe0af3d6fac5b39dd2d) complete. Timing: real 0.054s	user 0.022s	sys 0.027s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":19376,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:16:56.187119 10796 maintenance_manager.cc:419] P 99cc7996da6743109e7a1ce05b7b4a82: Scheduling FlushDeltaMemStoresOp(26d3bd820f754fe0af3d6fac5b39dd2d): perf score=2.188937
I20260812 06:16:56.207020 10707 maintenance_manager.cc:643] P 99cc7996da6743109e7a1ce05b7b4a82: FlushDeltaMemStoresOp(26d3bd820f754fe0af3d6fac5b39dd2d) complete. Timing: real 0.020s	user 0.015s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":7423,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:56.207582 10796 maintenance_manager.cc:419] P 99cc7996da6743109e7a1ce05b7b4a82: Scheduling FlushMRSOp(26d3bd820f754fe0af3d6fac5b39dd2d): perf score=1.000000
I20260812 06:16:56.251741 10707 maintenance_manager.cc:643] P 99cc7996da6743109e7a1ce05b7b4a82: FlushMRSOp(26d3bd820f754fe0af3d6fac5b39dd2d) complete. Timing: real 0.044s	user 0.036s	sys 0.005s Metrics: {"bytes_written":1193503,"cfile_init":1,"dirs.queue_time_us":73,"dirs.run_cpu_time_us":284,"dirs.run_wall_time_us":1308,"drs_written":1,"lbm_read_time_us":59,"lbm_reads_lt_1ms":4,"lbm_write_time_us":2407,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":29}
I20260812 06:16:56.252740 10796 maintenance_manager.cc:419] P 99cc7996da6743109e7a1ce05b7b4a82: Scheduling LogGCOp(26d3bd820f754fe0af3d6fac5b39dd2d): free 112692368 bytes of WAL
I20260812 06:16:56.253046 10707 log_reader.cc:385] T 26d3bd820f754fe0af3d6fac5b39dd2d: removed 11 log segments from log reader
I20260812 06:16:56.253116 10707 log.cc:1079] T 26d3bd820f754fe0af3d6fac5b39dd2d P 99cc7996da6743109e7a1ce05b7b4a82: Deleting log segment in path: /tmp/dist-test-taskQQcY3W/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515412339501-10539-0/minicluster-data/ts-0-root/wals/26d3bd820f754fe0af3d6fac5b39dd2d/wal-000000014 (ops 65-69)
I20260812 06:16:56.253160 10707 log.cc:1079] T 26d3bd820f754fe0af3d6fac5b39dd2d P 99cc7996da6743109e7a1ce05b7b4a82: Deleting log segment in path: /tmp/dist-test-taskQQcY3W/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515412339501-10539-0/minicluster-data/ts-0-root/wals/26d3bd820f754fe0af3d6fac5b39dd2d/wal-000000015 (ops 70-74)
I20260812 06:16:56.253191 10707 log.cc:1079] T 26d3bd820f754fe0af3d6fac5b39dd2d P 99cc7996da6743109e7a1ce05b7b4a82: Deleting log segment in path: /tmp/dist-test-taskQQcY3W/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515412339501-10539-0/minicluster-data/ts-0-root/wals/26d3bd820f754fe0af3d6fac5b39dd2d/wal-000000016 (ops 75-79)
I20260812 06:16:56.253223 10707 log.cc:1079] T 26d3bd820f754fe0af3d6fac5b39dd2d P 99cc7996da6743109e7a1ce05b7b4a82: Deleting log segment in path: /tmp/dist-test-taskQQcY3W/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515412339501-10539-0/minicluster-data/ts-0-root/wals/26d3bd820f754fe0af3d6fac5b39dd2d/wal-000000017 (ops 80-84)
I20260812 06:16:56.253252 10707 log.cc:1079] T 26d3bd820f754fe0af3d6fac5b39dd2d P 99cc7996da6743109e7a1ce05b7b4a82: Deleting log segment in path: /tmp/dist-test-taskQQcY3W/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515412339501-10539-0/minicluster-data/ts-0-root/wals/26d3bd820f754fe0af3d6fac5b39dd2d/wal-000000018 (ops 85-89)
I20260812 06:16:56.253286 10707 log.cc:1079] T 26d3bd820f754fe0af3d6fac5b39dd2d P 99cc7996da6743109e7a1ce05b7b4a82: Deleting log segment in path: /tmp/dist-test-taskQQcY3W/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515412339501-10539-0/minicluster-data/ts-0-root/wals/26d3bd820f754fe0af3d6fac5b39dd2d/wal-000000019 (ops 90-94)
I20260812 06:16:56.253314 10707 log.cc:1079] T 26d3bd820f754fe0af3d6fac5b39dd2d P 99cc7996da6743109e7a1ce05b7b4a82: Deleting log segment in path: /tmp/dist-test-taskQQcY3W/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515412339501-10539-0/minicluster-data/ts-0-root/wals/26d3bd820f754fe0af3d6fac5b39dd2d/wal-000000020 (ops 95-99)
I20260812 06:16:56.253340 10707 log.cc:1079] T 26d3bd820f754fe0af3d6fac5b39dd2d P 99cc7996da6743109e7a1ce05b7b4a82: Deleting log segment in path: /tmp/dist-test-taskQQcY3W/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515412339501-10539-0/minicluster-data/ts-0-root/wals/26d3bd820f754fe0af3d6fac5b39dd2d/wal-000000021 (ops 100-104)
I20260812 06:16:56.253367 10707 log.cc:1079] T 26d3bd820f754fe0af3d6fac5b39dd2d P 99cc7996da6743109e7a1ce05b7b4a82: Deleting log segment in path: /tmp/dist-test-taskQQcY3W/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515412339501-10539-0/minicluster-data/ts-0-root/wals/26d3bd820f754fe0af3d6fac5b39dd2d/wal-000000022 (ops 105-109)
I20260812 06:16:56.253397 10707 log.cc:1079] T 26d3bd820f754fe0af3d6fac5b39dd2d P 99cc7996da6743109e7a1ce05b7b4a82: Deleting log segment in path: /tmp/dist-test-taskQQcY3W/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515412339501-10539-0/minicluster-data/ts-0-root/wals/26d3bd820f754fe0af3d6fac5b39dd2d/wal-000000023 (ops 110-114)
I20260812 06:16:56.253432 10707 log.cc:1079] T 26d3bd820f754fe0af3d6fac5b39dd2d P 99cc7996da6743109e7a1ce05b7b4a82: Deleting log segment in path: /tmp/dist-test-taskQQcY3W/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515412339501-10539-0/minicluster-data/ts-0-root/wals/26d3bd820f754fe0af3d6fac5b39dd2d/wal-000000024 (ops 115-119)
I20260812 06:16:56.284207 10707 maintenance_manager.cc:643] P 99cc7996da6743109e7a1ce05b7b4a82: LogGCOp(26d3bd820f754fe0af3d6fac5b39dd2d) complete. Timing: real 0.031s	user 0.000s	sys 0.030s Metrics: {}
I20260812 06:16:56.284937 10796 maintenance_manager.cc:419] P 99cc7996da6743109e7a1ce05b7b4a82: Scheduling FlushDeltaMemStoresOp(26d3bd820f754fe0af3d6fac5b39dd2d): perf score=2.188937
I20260812 06:16:56.316896 10707 maintenance_manager.cc:643] P 99cc7996da6743109e7a1ce05b7b4a82: FlushDeltaMemStoresOp(26d3bd820f754fe0af3d6fac5b39dd2d) complete. Timing: real 0.032s	user 0.016s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":7316,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:56.317531 10796 maintenance_manager.cc:419] P 99cc7996da6743109e7a1ce05b7b4a82: Scheduling UndoDeltaBlockGCOp(26d3bd820f754fe0af3d6fac5b39dd2d): 463 bytes on disk
I20260812 06:16:56.318014 10707 maintenance_manager.cc:643] P 99cc7996da6743109e7a1ce05b7b4a82: UndoDeltaBlockGCOp(26d3bd820f754fe0af3d6fac5b39dd2d) 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:16:56.318588 10796 maintenance_manager.cc:419] P 99cc7996da6743109e7a1ce05b7b4a82: Scheduling FlushDeltaMemStoresOp(26d3bd820f754fe0af3d6fac5b39dd2d): perf score=2.188937
I20260812 06:16:56.330964 10707 maintenance_manager.cc:643] P 99cc7996da6743109e7a1ce05b7b4a82: FlushDeltaMemStoresOp(26d3bd820f754fe0af3d6fac5b39dd2d) complete. Timing: real 0.012s	user 0.008s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4748,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:56.331532 10796 maintenance_manager.cc:419] P 99cc7996da6743109e7a1ce05b7b4a82: Scheduling MajorDeltaCompactionOp(26d3bd820f754fe0af3d6fac5b39dd2d): perf score=1.000000
I20260812 06:16:56.566679 10707 maintenance_manager.cc:643] P 99cc7996da6743109e7a1ce05b7b4a82: MajorDeltaCompactionOp(26d3bd820f754fe0af3d6fac5b39dd2d) complete. Timing: real 0.235s	user 0.172s	sys 0.059s Metrics: {"cfile_cache_miss":634,"cfile_cache_miss_bytes":28795409,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":5133,"lbm_read_time_us":16456,"lbm_reads_lt_1ms":674,"lbm_write_time_us":39640,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":642,"mutex_wait_us":1304,"peak_mem_usage":75542472,"reinsert_count":0,"thread_start_us":102,"threads_started":1,"update_count":3000}
I20260812 06:16:56.567446 10796 maintenance_manager.cc:419] P 99cc7996da6743109e7a1ce05b7b4a82: Scheduling FlushDeltaMemStoresOp(26d3bd820f754fe0af3d6fac5b39dd2d): perf score=14.095187
I20260812 06:16:56.636032 10707 maintenance_manager.cc:643] P 99cc7996da6743109e7a1ce05b7b4a82: FlushDeltaMemStoresOp(26d3bd820f754fe0af3d6fac5b39dd2d) complete. Timing: real 0.068s	user 0.034s	sys 0.020s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":25159,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:16:56.636693 10796 maintenance_manager.cc:419] P 99cc7996da6743109e7a1ce05b7b4a82: Scheduling FlushDeltaMemStoresOp(26d3bd820f754fe0af3d6fac5b39dd2d): perf score=2.188937
I20260812 06:16:56.649420 10707 maintenance_manager.cc:643] P 99cc7996da6743109e7a1ce05b7b4a82: FlushDeltaMemStoresOp(26d3bd820f754fe0af3d6fac5b39dd2d) complete. Timing: real 0.012s	user 0.010s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4568,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:56.650270 10796 maintenance_manager.cc:419] P 99cc7996da6743109e7a1ce05b7b4a82: Scheduling MajorDeltaCompactionOp(26d3bd820f754fe0af3d6fac5b39dd2d): perf score=1.000000
I20260812 06:16:56.846131 10707 maintenance_manager.cc:643] P 99cc7996da6743109e7a1ce05b7b4a82: MajorDeltaCompactionOp(26d3bd820f754fe0af3d6fac5b39dd2d) complete. Timing: real 0.196s	user 0.136s	sys 0.060s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24692759,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":226,"lbm_read_time_us":12695,"lbm_reads_lt_1ms":572,"lbm_write_time_us":32531,"lbm_writes_lt_1ms":543,"mutex_wait_us":23,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":5248,"update_count":2500}
I20260812 06:16:56.846894 10796 maintenance_manager.cc:419] P 99cc7996da6743109e7a1ce05b7b4a82: Scheduling FlushDeltaMemStoresOp(26d3bd820f754fe0af3d6fac5b39dd2d): perf score=14.095187
I20260812 06:16:56.916808 10707 maintenance_manager.cc:643] P 99cc7996da6743109e7a1ce05b7b4a82: FlushDeltaMemStoresOp(26d3bd820f754fe0af3d6fac5b39dd2d) complete. Timing: real 0.070s	user 0.047s	sys 0.017s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":29143,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:16:56.917413 10796 maintenance_manager.cc:419] P 99cc7996da6743109e7a1ce05b7b4a82: Scheduling FlushDeltaMemStoresOp(26d3bd820f754fe0af3d6fac5b39dd2d): perf score=2.188937
I20260812 06:16:56.929342 10707 maintenance_manager.cc:643] P 99cc7996da6743109e7a1ce05b7b4a82: FlushDeltaMemStoresOp(26d3bd820f754fe0af3d6fac5b39dd2d) complete. Timing: real 0.012s	user 0.008s	sys 0.002s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4766,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:56.929886 10796 maintenance_manager.cc:419] P 99cc7996da6743109e7a1ce05b7b4a82: Scheduling MajorDeltaCompactionOp(26d3bd820f754fe0af3d6fac5b39dd2d): perf score=1.000000
I20260812 06:16:57.139238 10707 maintenance_manager.cc:643] P 99cc7996da6743109e7a1ce05b7b4a82: MajorDeltaCompactionOp(26d3bd820f754fe0af3d6fac5b39dd2d) complete. Timing: real 0.209s	user 0.122s	sys 0.080s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24692759,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":172,"lbm_read_time_us":15682,"lbm_reads_lt_1ms":572,"lbm_write_time_us":35967,"lbm_writes_lt_1ms":543,"mutex_wait_us":45,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":1280,"update_count":2500}
I20260812 06:16:57.139966 10796 maintenance_manager.cc:419] P 99cc7996da6743109e7a1ce05b7b4a82: Scheduling FlushDeltaMemStoresOp(26d3bd820f754fe0af3d6fac5b39dd2d): perf score=14.095187
I20260812 06:16:57.210186 10707 maintenance_manager.cc:643] P 99cc7996da6743109e7a1ce05b7b4a82: FlushDeltaMemStoresOp(26d3bd820f754fe0af3d6fac5b39dd2d) complete. Timing: real 0.070s	user 0.024s	sys 0.036s Metrics: {"bytes_written":16409904,"delete_count":0,"lbm_write_time_us":25837,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:16:57.210870 10796 maintenance_manager.cc:419] P 99cc7996da6743109e7a1ce05b7b4a82: Scheduling FlushDeltaMemStoresOp(26d3bd820f754fe0af3d6fac5b39dd2d): perf score=2.188937
I20260812 06:16:57.223450 10707 maintenance_manager.cc:643] P 99cc7996da6743109e7a1ce05b7b4a82: FlushDeltaMemStoresOp(26d3bd820f754fe0af3d6fac5b39dd2d) complete. Timing: real 0.012s	user 0.011s	sys 0.001s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4967,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:57.223953 10796 maintenance_manager.cc:419] P 99cc7996da6743109e7a1ce05b7b4a82: Scheduling MajorDeltaCompactionOp(26d3bd820f754fe0af3d6fac5b39dd2d): perf score=1.000000
I20260812 06:16:57.446179 10707 maintenance_manager.cc:643] P 99cc7996da6743109e7a1ce05b7b4a82: MajorDeltaCompactionOp(26d3bd820f754fe0af3d6fac5b39dd2d) complete. Timing: real 0.222s	user 0.147s	sys 0.067s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24692761,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":704,"lbm_read_time_us":15810,"lbm_reads_lt_1ms":572,"lbm_write_time_us":35581,"lbm_writes_lt_1ms":543,"mutex_wait_us":332,"peak_mem_usage":63115900,"reinsert_count":0,"update_count":2500}
I20260812 06:16:57.446820 10796 maintenance_manager.cc:419] P 99cc7996da6743109e7a1ce05b7b4a82: Scheduling FlushDeltaMemStoresOp(26d3bd820f754fe0af3d6fac5b39dd2d): perf score=14.095187
I20260812 06:16:57.504649 10707 maintenance_manager.cc:643] P 99cc7996da6743109e7a1ce05b7b4a82: FlushDeltaMemStoresOp(26d3bd820f754fe0af3d6fac5b39dd2d) complete. Timing: real 0.058s	user 0.021s	sys 0.029s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":24507,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:16:57.505302 10796 maintenance_manager.cc:419] P 99cc7996da6743109e7a1ce05b7b4a82: Scheduling FlushDeltaMemStoresOp(26d3bd820f754fe0af3d6fac5b39dd2d): perf score=2.188937
I20260812 06:16:57.534314 10707 maintenance_manager.cc:643] P 99cc7996da6743109e7a1ce05b7b4a82: FlushDeltaMemStoresOp(26d3bd820f754fe0af3d6fac5b39dd2d) complete. Timing: real 0.029s	user 0.012s	sys 0.014s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":7259,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:57.535110 10796 maintenance_manager.cc:419] P 99cc7996da6743109e7a1ce05b7b4a82: Scheduling MajorDeltaCompactionOp(26d3bd820f754fe0af3d6fac5b39dd2d): perf score=1.000000
I20260812 06:16:57.752748 10707 maintenance_manager.cc:643] P 99cc7996da6743109e7a1ce05b7b4a82: MajorDeltaCompactionOp(26d3bd820f754fe0af3d6fac5b39dd2d) complete. Timing: real 0.217s	user 0.126s	sys 0.085s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24692758,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":699,"lbm_read_time_us":14514,"lbm_reads_lt_1ms":572,"lbm_write_time_us":37079,"lbm_writes_lt_1ms":543,"mutex_wait_us":405,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":16256,"update_count":2500}
I20260812 06:16:57.753434 10796 maintenance_manager.cc:419] P 99cc7996da6743109e7a1ce05b7b4a82: Scheduling FlushDeltaMemStoresOp(26d3bd820f754fe0af3d6fac5b39dd2d): perf score=14.095187
I20260812 06:16:57.813338 10707 maintenance_manager.cc:643] P 99cc7996da6743109e7a1ce05b7b4a82: FlushDeltaMemStoresOp(26d3bd820f754fe0af3d6fac5b39dd2d) complete. Timing: real 0.060s	user 0.023s	sys 0.031s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":26082,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:16:57.813958 10796 maintenance_manager.cc:419] P 99cc7996da6743109e7a1ce05b7b4a82: Scheduling FlushDeltaMemStoresOp(26d3bd820f754fe0af3d6fac5b39dd2d): perf score=2.188937
I20260812 06:16:57.828817 10707 maintenance_manager.cc:643] P 99cc7996da6743109e7a1ce05b7b4a82: FlushDeltaMemStoresOp(26d3bd820f754fe0af3d6fac5b39dd2d) complete. Timing: real 0.015s	user 0.007s	sys 0.006s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5051,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:57.829726 10796 maintenance_manager.cc:419] P 99cc7996da6743109e7a1ce05b7b4a82: Scheduling MajorDeltaCompactionOp(26d3bd820f754fe0af3d6fac5b39dd2d): perf score=1.000000
I20260812 06:16:58.058019 10707 maintenance_manager.cc:643] P 99cc7996da6743109e7a1ce05b7b4a82: MajorDeltaCompactionOp(26d3bd820f754fe0af3d6fac5b39dd2d) complete. Timing: real 0.228s	user 0.164s	sys 0.051s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24692759,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":427,"lbm_read_time_us":14275,"lbm_reads_lt_1ms":572,"lbm_write_time_us":35735,"lbm_writes_lt_1ms":543,"peak_mem_usage":63115900,"reinsert_count":0,"update_count":2500}
I20260812 06:16:58.058905 10796 maintenance_manager.cc:419] P 99cc7996da6743109e7a1ce05b7b4a82: Scheduling FlushDeltaMemStoresOp(26d3bd820f754fe0af3d6fac5b39dd2d): perf score=14.095187
I20260812 06:16:58.122373 10707 maintenance_manager.cc:643] P 99cc7996da6743109e7a1ce05b7b4a82: FlushDeltaMemStoresOp(26d3bd820f754fe0af3d6fac5b39dd2d) complete. Timing: real 0.063s	user 0.037s	sys 0.017s Metrics: {"bytes_written":16409904,"delete_count":0,"lbm_write_time_us":26337,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:16:58.123283 10796 maintenance_manager.cc:419] P 99cc7996da6743109e7a1ce05b7b4a82: Scheduling FlushDeltaMemStoresOp(26d3bd820f754fe0af3d6fac5b39dd2d): perf score=2.188937
I20260812 06:16:58.136464 10707 maintenance_manager.cc:643] P 99cc7996da6743109e7a1ce05b7b4a82: FlushDeltaMemStoresOp(26d3bd820f754fe0af3d6fac5b39dd2d) complete. Timing: real 0.013s	user 0.011s	sys 0.001s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4708,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:58.137612 10796 maintenance_manager.cc:419] P 99cc7996da6743109e7a1ce05b7b4a82: Scheduling FlushMRSOp(26d3bd820f754fe0af3d6fac5b39dd2d): perf score=1.000000
I20260812 06:16:58.172107 10707 maintenance_manager.cc:643] P 99cc7996da6743109e7a1ce05b7b4a82: FlushMRSOp(26d3bd820f754fe0af3d6fac5b39dd2d) complete. Timing: real 0.034s	user 0.024s	sys 0.005s Metrics: {"bytes_written":1316414,"cfile_init":1,"dirs.queue_time_us":57,"dirs.run_cpu_time_us":219,"dirs.run_wall_time_us":1271,"drs_written":1,"lbm_read_time_us":47,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1871,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":32}
I20260812 06:16:58.172964 10796 maintenance_manager.cc:419] P 99cc7996da6743109e7a1ce05b7b4a82: Scheduling LogGCOp(26d3bd820f754fe0af3d6fac5b39dd2d): free 133477667 bytes of WAL
I20260812 06:16:58.173274 10707 log_reader.cc:385] T 26d3bd820f754fe0af3d6fac5b39dd2d: removed 13 log segments from log reader
I20260812 06:16:58.173342 10707 log.cc:1079] T 26d3bd820f754fe0af3d6fac5b39dd2d P 99cc7996da6743109e7a1ce05b7b4a82: Deleting log segment in path: /tmp/dist-test-taskQQcY3W/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515412339501-10539-0/minicluster-data/ts-0-root/wals/26d3bd820f754fe0af3d6fac5b39dd2d/wal-000000025 (ops 120-124)
I20260812 06:16:58.173389 10707 log.cc:1079] T 26d3bd820f754fe0af3d6fac5b39dd2d P 99cc7996da6743109e7a1ce05b7b4a82: Deleting log segment in path: /tmp/dist-test-taskQQcY3W/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515412339501-10539-0/minicluster-data/ts-0-root/wals/26d3bd820f754fe0af3d6fac5b39dd2d/wal-000000026 (ops 125-129)
I20260812 06:16:58.173422 10707 log.cc:1079] T 26d3bd820f754fe0af3d6fac5b39dd2d P 99cc7996da6743109e7a1ce05b7b4a82: Deleting log segment in path: /tmp/dist-test-taskQQcY3W/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515412339501-10539-0/minicluster-data/ts-0-root/wals/26d3bd820f754fe0af3d6fac5b39dd2d/wal-000000027 (ops 130-134)
I20260812 06:16:58.173446 10707 log.cc:1079] T 26d3bd820f754fe0af3d6fac5b39dd2d P 99cc7996da6743109e7a1ce05b7b4a82: Deleting log segment in path: /tmp/dist-test-taskQQcY3W/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515412339501-10539-0/minicluster-data/ts-0-root/wals/26d3bd820f754fe0af3d6fac5b39dd2d/wal-000000028 (ops 135-139)
I20260812 06:16:58.173470 10707 log.cc:1079] T 26d3bd820f754fe0af3d6fac5b39dd2d P 99cc7996da6743109e7a1ce05b7b4a82: Deleting log segment in path: /tmp/dist-test-taskQQcY3W/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515412339501-10539-0/minicluster-data/ts-0-root/wals/26d3bd820f754fe0af3d6fac5b39dd2d/wal-000000029 (ops 140-144)
I20260812 06:16:58.173506 10707 log.cc:1079] T 26d3bd820f754fe0af3d6fac5b39dd2d P 99cc7996da6743109e7a1ce05b7b4a82: Deleting log segment in path: /tmp/dist-test-taskQQcY3W/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515412339501-10539-0/minicluster-data/ts-0-root/wals/26d3bd820f754fe0af3d6fac5b39dd2d/wal-000000030 (ops 145-149)
I20260812 06:16:58.173540 10707 log.cc:1079] T 26d3bd820f754fe0af3d6fac5b39dd2d P 99cc7996da6743109e7a1ce05b7b4a82: Deleting log segment in path: /tmp/dist-test-taskQQcY3W/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515412339501-10539-0/minicluster-data/ts-0-root/wals/26d3bd820f754fe0af3d6fac5b39dd2d/wal-000000031 (ops 150-154)
I20260812 06:16:58.173568 10707 log.cc:1079] T 26d3bd820f754fe0af3d6fac5b39dd2d P 99cc7996da6743109e7a1ce05b7b4a82: Deleting log segment in path: /tmp/dist-test-taskQQcY3W/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515412339501-10539-0/minicluster-data/ts-0-root/wals/26d3bd820f754fe0af3d6fac5b39dd2d/wal-000000032 (ops 155-159)
I20260812 06:16:58.173597 10707 log.cc:1079] T 26d3bd820f754fe0af3d6fac5b39dd2d P 99cc7996da6743109e7a1ce05b7b4a82: Deleting log segment in path: /tmp/dist-test-taskQQcY3W/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515412339501-10539-0/minicluster-data/ts-0-root/wals/26d3bd820f754fe0af3d6fac5b39dd2d/wal-000000033 (ops 160-164)
I20260812 06:16:58.173621 10707 log.cc:1079] T 26d3bd820f754fe0af3d6fac5b39dd2d P 99cc7996da6743109e7a1ce05b7b4a82: Deleting log segment in path: /tmp/dist-test-taskQQcY3W/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515412339501-10539-0/minicluster-data/ts-0-root/wals/26d3bd820f754fe0af3d6fac5b39dd2d/wal-000000034 (ops 165-169)
I20260812 06:16:58.173655 10707 log.cc:1079] T 26d3bd820f754fe0af3d6fac5b39dd2d P 99cc7996da6743109e7a1ce05b7b4a82: Deleting log segment in path: /tmp/dist-test-taskQQcY3W/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515412339501-10539-0/minicluster-data/ts-0-root/wals/26d3bd820f754fe0af3d6fac5b39dd2d/wal-000000035 (ops 170-174)
I20260812 06:16:58.173689 10707 log.cc:1079] T 26d3bd820f754fe0af3d6fac5b39dd2d P 99cc7996da6743109e7a1ce05b7b4a82: Deleting log segment in path: /tmp/dist-test-taskQQcY3W/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515412339501-10539-0/minicluster-data/ts-0-root/wals/26d3bd820f754fe0af3d6fac5b39dd2d/wal-000000036 (ops 175-179)
I20260812 06:16:58.173722 10707 log.cc:1079] T 26d3bd820f754fe0af3d6fac5b39dd2d P 99cc7996da6743109e7a1ce05b7b4a82: Deleting log segment in path: /tmp/dist-test-taskQQcY3W/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515412339501-10539-0/minicluster-data/ts-0-root/wals/26d3bd820f754fe0af3d6fac5b39dd2d/wal-000000037 (ops 180-184)
I20260812 06:16:58.206259 10707 maintenance_manager.cc:643] P 99cc7996da6743109e7a1ce05b7b4a82: LogGCOp(26d3bd820f754fe0af3d6fac5b39dd2d) complete. Timing: real 0.033s	user 0.002s	sys 0.028s Metrics: {}
I20260812 06:16:58.206983 10796 maintenance_manager.cc:419] P 99cc7996da6743109e7a1ce05b7b4a82: Scheduling UndoDeltaBlockGCOp(26d3bd820f754fe0af3d6fac5b39dd2d): 493 bytes on disk
I20260812 06:16:58.207762 10707 maintenance_manager.cc:643] P 99cc7996da6743109e7a1ce05b7b4a82: UndoDeltaBlockGCOp(26d3bd820f754fe0af3d6fac5b39dd2d) complete. Timing: real 0.001s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":123,"lbm_reads_lt_1ms":4}
I20260812 06:16:58.214772 10796 maintenance_manager.cc:419] P 99cc7996da6743109e7a1ce05b7b4a82: Scheduling FlushDeltaMemStoresOp(26d3bd820f754fe0af3d6fac5b39dd2d): perf score=2.188937
I20260812 06:16:58.233083 10707 maintenance_manager.cc:643] P 99cc7996da6743109e7a1ce05b7b4a82: FlushDeltaMemStoresOp(26d3bd820f754fe0af3d6fac5b39dd2d) complete. Timing: real 0.018s	user 0.011s	sys 0.000s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":5413,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:58.233757 10796 maintenance_manager.cc:419] P 99cc7996da6743109e7a1ce05b7b4a82: Scheduling LogGCOp(26d3bd820f754fe0af3d6fac5b39dd2d): free 11564893 bytes of WAL
I20260812 06:16:58.234022 10707 log_reader.cc:385] T 26d3bd820f754fe0af3d6fac5b39dd2d: removed 1 log segments from log reader
I20260812 06:16:58.234097 10707 log.cc:1079] T 26d3bd820f754fe0af3d6fac5b39dd2d P 99cc7996da6743109e7a1ce05b7b4a82: Deleting log segment in path: /tmp/dist-test-taskQQcY3W/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515412339501-10539-0/minicluster-data/ts-0-root/wals/26d3bd820f754fe0af3d6fac5b39dd2d/wal-000000038 (ops 185-188)
I20260812 06:16:58.236527 10707 maintenance_manager.cc:643] P 99cc7996da6743109e7a1ce05b7b4a82: LogGCOp(26d3bd820f754fe0af3d6fac5b39dd2d) complete. Timing: real 0.003s	user 0.000s	sys 0.001s Metrics: {}
I20260812 06:16:58.236899 10796 maintenance_manager.cc:419] P 99cc7996da6743109e7a1ce05b7b4a82: Scheduling MajorDeltaCompactionOp(26d3bd820f754fe0af3d6fac5b39dd2d): perf score=1.000000
I20260812 06:16:58.473994 10707 maintenance_manager.cc:643] P 99cc7996da6743109e7a1ce05b7b4a82: MajorDeltaCompactionOp(26d3bd820f754fe0af3d6fac5b39dd2d) complete. Timing: real 0.237s	user 0.161s	sys 0.066s Metrics: {"cfile_cache_miss":633,"cfile_cache_miss_bytes":28795291,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":638,"lbm_read_time_us":16676,"lbm_reads_lt_1ms":665,"lbm_write_time_us":40565,"lbm_writes_lt_1ms":643,"mutex_wait_us":43,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":7936,"thread_start_us":97,"threads_started":1,"update_count":3000}
I20260812 06:16:58.475221 10796 maintenance_manager.cc:419] P 99cc7996da6743109e7a1ce05b7b4a82: Scheduling FlushDeltaMemStoresOp(26d3bd820f754fe0af3d6fac5b39dd2d): perf score=18.063937
I20260812 06:16:58.560500 10707 maintenance_manager.cc:643] P 99cc7996da6743109e7a1ce05b7b4a82: FlushDeltaMemStoresOp(26d3bd820f754fe0af3d6fac5b39dd2d) complete. Timing: real 0.085s	user 0.060s	sys 0.024s Metrics: {"bytes_written":20512343,"delete_count":0,"lbm_write_time_us":34816,"lbm_writes_lt_1ms":503,"reinsert_count":0,"update_count":2500}
I20260812 06:16:58.561247 10796 maintenance_manager.cc:419] P 99cc7996da6743109e7a1ce05b7b4a82: Scheduling FlushDeltaMemStoresOp(26d3bd820f754fe0af3d6fac5b39dd2d): perf score=2.188937
I20260812 06:16:58.573809 10707 maintenance_manager.cc:643] P 99cc7996da6743109e7a1ce05b7b4a82: FlushDeltaMemStoresOp(26d3bd820f754fe0af3d6fac5b39dd2d) complete. Timing: real 0.012s	user 0.003s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5095,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:58.574348 10796 maintenance_manager.cc:419] P 99cc7996da6743109e7a1ce05b7b4a82: Scheduling MajorDeltaCompactionOp(26d3bd820f754fe0af3d6fac5b39dd2d): perf score=1.000000
I20260812 06:16:58.635923 10539 heavy-update-compaction-itest.cc:229] Time spent updating: real 5.962s	user 2.127s	sys 0.256s
I20260812 06:16:58.734120 10539 heavy-update-compaction-itest.cc:265] Time spent scanning: real 0.097s	user 0.000s	sys 0.001s
I20260812 06:16:58.734977 10539 tablet_server.cc:179] TabletServer@127.10.74.193:0 shutting down...
I20260812 06:16:58.778656 10707 maintenance_manager.cc:643] P 99cc7996da6743109e7a1ce05b7b4a82: MajorDeltaCompactionOp(26d3bd820f754fe0af3d6fac5b39dd2d) complete. Timing: real 0.204s	user 0.141s	sys 0.060s Metrics: {"cfile_cache_miss":632,"cfile_cache_miss_bytes":28795200,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":3733,"lbm_read_time_us":17316,"lbm_reads_lt_1ms":668,"lbm_write_time_us":32585,"lbm_writes_lt_1ms":643,"mutex_wait_us":2919,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":2560,"update_count":3000}
I20260812 06:16:58.780277 10539 ts_tablet_manager.cc:1507] Shutting down tablet manager...
I20260812 06:16:58.780787 10539 tablet_replica.cc:333] T 26d3bd820f754fe0af3d6fac5b39dd2d P 99cc7996da6743109e7a1ce05b7b4a82: stopping tablet replica
I20260812 06:16:58.781157 10539 raft_consensus.cc:2243] T 26d3bd820f754fe0af3d6fac5b39dd2d P 99cc7996da6743109e7a1ce05b7b4a82 [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:16:58.781459 10539 raft_consensus.cc:2272] T 26d3bd820f754fe0af3d6fac5b39dd2d P 99cc7996da6743109e7a1ce05b7b4a82 [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:16:58.799921 10539 tablet_server.cc:196] TabletServer@127.10.74.193:0 shutdown complete.
I20260812 06:16:58.829913 10539 master.cc:562] Master@127.10.74.254:42589 shutting down...
I20260812 06:16:58.834400 10539 raft_consensus.cc:2243] T 00000000000000000000000000000000 P b48c2949bd794437b9cfd934c15a67de [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:16:58.834676 10539 raft_consensus.cc:2272] T 00000000000000000000000000000000 P b48c2949bd794437b9cfd934c15a67de [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:16:58.834791 10539 tablet_replica.cc:333] T 00000000000000000000000000000000 P b48c2949bd794437b9cfd934c15a67de: stopping tablet replica
I20260812 06:16:58.848675 10539 master.cc:584] Master@127.10.74.254:42589 shutdown complete.
[       OK ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/0 (6592 ms)
[ RUN      ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/1
I20260812 06:16:58.958196 10539 internal_mini_cluster.cc:156] Creating distributed mini masters. Addrs: 127.10.74.254:39727
I20260812 06:16:58.958761 10539 file_cache.cc:504] Constructed file cache file cache with capacity 419430
I20260812 06:16:58.961664 10539 server_base.cc:1061] running on GCE node
W20260812 06:16:58.961755 10840 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:16:58.961820 10844 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:16:58.961766 10846 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:16:58.962121 10539 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:16:58.962169 10539 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:16:58.962186 10539 hybrid_clock.cc:648] HybridClock initialized: now 1786515418962186 us; error 0 us; skew 500 ppm
I20260812 06:16:58.964221 10539 webserver.cc:533] Webserver started at http://127.10.74.254:40421/ using document root <none> and password file <none>
I20260812 06:16:58.964426 10539 fs_manager.cc:362] Metadata directory not provided
I20260812 06:16:58.964495 10539 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:16:58.964604 10539 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:16:58.965090 10539 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskQQcY3W/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515412339501-10539-0/minicluster-data/master-0-root/instance:
uuid: "3e0bf1d3d4294f79bc4cb49d4cec3ed8"
format_stamp: "Formatted at 2026-08-12 06:16:58 on dist-test-slave-nfb5"
I20260812 06:16:58.966686 10539 fs_manager.cc:696] Time spent creating directory manager: real 0.001s	user 0.002s	sys 0.000s
I20260812 06:16:58.967854 10855 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:16:58.968154 10539 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.001s	sys 0.000s
I20260812 06:16:58.968236 10539 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskQQcY3W/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515412339501-10539-0/minicluster-data/master-0-root
uuid: "3e0bf1d3d4294f79bc4cb49d4cec3ed8"
format_stamp: "Formatted at 2026-08-12 06:16:58 on dist-test-slave-nfb5"
I20260812 06:16:58.968353 10539 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskQQcY3W/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515412339501-10539-0/minicluster-data/master-0-root
metadata directory: /tmp/dist-test-taskQQcY3W/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515412339501-10539-0/minicluster-data/master-0-root
1 data directories: /tmp/dist-test-taskQQcY3W/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515412339501-10539-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:16:58.988785 10539 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:16:58.989334 10539 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:16:58.994751 10539 rpc_server.cc:307] RPC server started. Bound to: 127.10.74.254:39727
I20260812 06:16:58.999629 10939 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.10.74.254:39727 every 8 connection(s)
I20260812 06:16:59.000274 10940 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:16:59.002422 10940 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P 3e0bf1d3d4294f79bc4cb49d4cec3ed8: Bootstrap starting.
I20260812 06:16:59.003312 10940 tablet_bootstrap.cc:654] T 00000000000000000000000000000000 P 3e0bf1d3d4294f79bc4cb49d4cec3ed8: Neither blocks nor log segments found. Creating new log.
I20260812 06:16:59.004395 10940 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P 3e0bf1d3d4294f79bc4cb49d4cec3ed8: No bootstrap required, opened a new log
I20260812 06:16:59.004923 10940 raft_consensus.cc:359] T 00000000000000000000000000000000 P 3e0bf1d3d4294f79bc4cb49d4cec3ed8 [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "3e0bf1d3d4294f79bc4cb49d4cec3ed8" member_type: VOTER }
I20260812 06:16:59.005021 10940 raft_consensus.cc:385] T 00000000000000000000000000000000 P 3e0bf1d3d4294f79bc4cb49d4cec3ed8 [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:16:59.005044 10940 raft_consensus.cc:740] T 00000000000000000000000000000000 P 3e0bf1d3d4294f79bc4cb49d4cec3ed8 [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: 3e0bf1d3d4294f79bc4cb49d4cec3ed8, State: Initialized, Role: FOLLOWER
I20260812 06:16:59.005208 10940 consensus_queue.cc:260] T 00000000000000000000000000000000 P 3e0bf1d3d4294f79bc4cb49d4cec3ed8 [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: "3e0bf1d3d4294f79bc4cb49d4cec3ed8" member_type: VOTER }
I20260812 06:16:59.005309 10940 raft_consensus.cc:399] T 00000000000000000000000000000000 P 3e0bf1d3d4294f79bc4cb49d4cec3ed8 [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:16:59.005335 10940 raft_consensus.cc:493] T 00000000000000000000000000000000 P 3e0bf1d3d4294f79bc4cb49d4cec3ed8 [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:16:59.005371 10940 raft_consensus.cc:3060] T 00000000000000000000000000000000 P 3e0bf1d3d4294f79bc4cb49d4cec3ed8 [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:16:59.006073 10940 raft_consensus.cc:515] T 00000000000000000000000000000000 P 3e0bf1d3d4294f79bc4cb49d4cec3ed8 [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "3e0bf1d3d4294f79bc4cb49d4cec3ed8" member_type: VOTER }
I20260812 06:16:59.006206 10940 leader_election.cc:304] T 00000000000000000000000000000000 P 3e0bf1d3d4294f79bc4cb49d4cec3ed8 [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: 3e0bf1d3d4294f79bc4cb49d4cec3ed8; no voters: 
I20260812 06:16:59.006367 10940 leader_election.cc:290] T 00000000000000000000000000000000 P 3e0bf1d3d4294f79bc4cb49d4cec3ed8 [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:16:59.006547 10944 raft_consensus.cc:2804] T 00000000000000000000000000000000 P 3e0bf1d3d4294f79bc4cb49d4cec3ed8 [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:16:59.006759 10944 raft_consensus.cc:697] T 00000000000000000000000000000000 P 3e0bf1d3d4294f79bc4cb49d4cec3ed8 [term 1 LEADER]: Becoming Leader. State: Replica: 3e0bf1d3d4294f79bc4cb49d4cec3ed8, State: Running, Role: LEADER
I20260812 06:16:59.006870 10940 sys_catalog.cc:565] T 00000000000000000000000000000000 P 3e0bf1d3d4294f79bc4cb49d4cec3ed8 [sys.catalog]: configured and running, proceeding with master startup.
I20260812 06:16:59.006954 10944 consensus_queue.cc:237] T 00000000000000000000000000000000 P 3e0bf1d3d4294f79bc4cb49d4cec3ed8 [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: "3e0bf1d3d4294f79bc4cb49d4cec3ed8" member_type: VOTER }
I20260812 06:16:59.007476 10945 sys_catalog.cc:455] T 00000000000000000000000000000000 P 3e0bf1d3d4294f79bc4cb49d4cec3ed8 [sys.catalog]: SysCatalogTable state changed. Reason: RaftConsensus started. Latest consensus state: current_term: 1 leader_uuid: "3e0bf1d3d4294f79bc4cb49d4cec3ed8" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "3e0bf1d3d4294f79bc4cb49d4cec3ed8" member_type: VOTER } }
I20260812 06:16:59.007534 10946 sys_catalog.cc:455] T 00000000000000000000000000000000 P 3e0bf1d3d4294f79bc4cb49d4cec3ed8 [sys.catalog]: SysCatalogTable state changed. Reason: New leader 3e0bf1d3d4294f79bc4cb49d4cec3ed8. Latest consensus state: current_term: 1 leader_uuid: "3e0bf1d3d4294f79bc4cb49d4cec3ed8" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "3e0bf1d3d4294f79bc4cb49d4cec3ed8" member_type: VOTER } }
I20260812 06:16:59.007658 10945 sys_catalog.cc:458] T 00000000000000000000000000000000 P 3e0bf1d3d4294f79bc4cb49d4cec3ed8 [sys.catalog]: This master's current role is: LEADER
I20260812 06:16:59.007754 10946 sys_catalog.cc:458] T 00000000000000000000000000000000 P 3e0bf1d3d4294f79bc4cb49d4cec3ed8 [sys.catalog]: This master's current role is: LEADER
I20260812 06:16:59.008260 10957 catalog_manager.cc:1511] Loading table and tablet metadata into memory...
I20260812 06:16:59.009027 10957 catalog_manager.cc:1520] Initializing Kudu cluster ID...
I20260812 06:16:59.009315 10539 internal_mini_cluster.cc:184] Waiting to initialize catalog manager on master 0
I20260812 06:16:59.010989 10957 catalog_manager.cc:1383] Generated new cluster ID: a79c1d71093249c9a00a8498be446cb1
I20260812 06:16:59.011046 10957 catalog_manager.cc:1531] Initializing Kudu internal certificate authority...
I20260812 06:16:59.018766 10957 catalog_manager.cc:1406] Generated new certificate authority record
I20260812 06:16:59.019341 10957 catalog_manager.cc:1540] Loading token signing keys...
I20260812 06:16:59.024631 10957 catalog_manager.cc:6092] T 00000000000000000000000000000000 P 3e0bf1d3d4294f79bc4cb49d4cec3ed8: Generated new TSK 0
I20260812 06:16:59.024783 10957 catalog_manager.cc:1550] Initializing in-progress tserver states...
I20260812 06:16:59.041863 10539 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:16:59.044087 10977 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:16:59.044276 10981 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:16:59.044340 10978 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:16:59.044433 10539 server_base.cc:1061] running on GCE node
I20260812 06:16:59.044629 10539 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:16:59.044680 10539 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:16:59.044697 10539 hybrid_clock.cc:648] HybridClock initialized: now 1786515419044697 us; error 0 us; skew 500 ppm
I20260812 06:16:59.045670 10539 webserver.cc:533] Webserver started at http://127.10.74.193:42423/ using document root <none> and password file <none>
I20260812 06:16:59.045871 10539 fs_manager.cc:362] Metadata directory not provided
I20260812 06:16:59.045954 10539 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:16:59.046044 10539 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:16:59.046520 10539 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskQQcY3W/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515412339501-10539-0/minicluster-data/ts-0-root/instance:
uuid: "c9769c5c7dc64561a4d4afb140afd606"
format_stamp: "Formatted at 2026-08-12 06:16:59 on dist-test-slave-nfb5"
I20260812 06:16:59.048358 10539 fs_manager.cc:696] Time spent creating directory manager: real 0.002s	user 0.000s	sys 0.002s
I20260812 06:16:59.049453 10989 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:16:59.049760 10539 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.000s	sys 0.001s
I20260812 06:16:59.049825 10539 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskQQcY3W/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515412339501-10539-0/minicluster-data/ts-0-root
uuid: "c9769c5c7dc64561a4d4afb140afd606"
format_stamp: "Formatted at 2026-08-12 06:16:59 on dist-test-slave-nfb5"
I20260812 06:16:59.049922 10539 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskQQcY3W/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515412339501-10539-0/minicluster-data/ts-0-root
metadata directory: /tmp/dist-test-taskQQcY3W/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515412339501-10539-0/minicluster-data/ts-0-root
1 data directories: /tmp/dist-test-taskQQcY3W/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515412339501-10539-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:16:59.069669 10539 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:16:59.070148 10539 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:16:59.070508 10539 txn_system_client.cc:432] TxnSystemClient initialization is disabled...
I20260812 06:16:59.071061 10539 ts_tablet_manager.cc:585] Loaded tablet metadata (0 total tablets, 0 live tablets)
I20260812 06:16:59.071128 10539 ts_tablet_manager.cc:531] Time spent load tablet metadata: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:16:59.071205 10539 ts_tablet_manager.cc:616] Registered 0 tablets
I20260812 06:16:59.071257 10539 ts_tablet_manager.cc:595] Time spent register tablets: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:16:59.076426 10539 rpc_server.cc:307] RPC server started. Bound to: 127.10.74.193:37935
I20260812 06:16:59.078403 11095 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.10.74.193:37935 every 8 connection(s)
I20260812 06:16:59.087478 11098 heartbeater.cc:344] Connected to a master server at 127.10.74.254:39727
I20260812 06:16:59.087625 11098 heartbeater.cc:461] Registering TS with master...
I20260812 06:16:59.087913 11098 heartbeater.cc:507] Master 127.10.74.254:39727 requested a full tablet report, sending...
I20260812 06:16:59.088694 10886 ts_manager.cc:194] Registered new tserver with Master: c9769c5c7dc64561a4d4afb140afd606 (127.10.74.193:37935)
I20260812 06:16:59.089521 10886 master_service.cc:502] Signed X509 certificate for tserver {username='slave'} at 127.0.0.1:58968
I20260812 06:16:59.089692 10539 internal_mini_cluster.cc:371] 1 TS(s) registered with all masters after 0.012184977s
I20260812 06:16:59.097869 10886 catalog_manager.cc:2283] Servicing CreateTable request from {username='slave'} at 127.0.0.1:58974:
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:16:59.107587 11035 tablet_service.cc:1511] Processing CreateTablet for tablet fdc3a6bf51e24184ad791417b3f69568 (DEFAULT_TABLE table=heavy-update-compaction-test [id=3c8da18ba68f4130a4d26f43fbd13b77]), partition=
I20260812 06:16:59.107959 11035 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet fdc3a6bf51e24184ad791417b3f69568. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:16:59.110683 11112 tablet_bootstrap.cc:492] T fdc3a6bf51e24184ad791417b3f69568 P c9769c5c7dc64561a4d4afb140afd606: Bootstrap starting.
I20260812 06:16:59.111742 11112 tablet_bootstrap.cc:654] T fdc3a6bf51e24184ad791417b3f69568 P c9769c5c7dc64561a4d4afb140afd606: Neither blocks nor log segments found. Creating new log.
I20260812 06:16:59.113183 11112 tablet_bootstrap.cc:492] T fdc3a6bf51e24184ad791417b3f69568 P c9769c5c7dc64561a4d4afb140afd606: No bootstrap required, opened a new log
I20260812 06:16:59.113267 11112 ts_tablet_manager.cc:1403] T fdc3a6bf51e24184ad791417b3f69568 P c9769c5c7dc64561a4d4afb140afd606: Time spent bootstrapping tablet: real 0.003s	user 0.002s	sys 0.000s
I20260812 06:16:59.113688 11112 raft_consensus.cc:359] T fdc3a6bf51e24184ad791417b3f69568 P c9769c5c7dc64561a4d4afb140afd606 [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "c9769c5c7dc64561a4d4afb140afd606" member_type: VOTER last_known_addr { host: "127.10.74.193" port: 37935 } }
I20260812 06:16:59.113785 11112 raft_consensus.cc:385] T fdc3a6bf51e24184ad791417b3f69568 P c9769c5c7dc64561a4d4afb140afd606 [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:16:59.113811 11112 raft_consensus.cc:740] T fdc3a6bf51e24184ad791417b3f69568 P c9769c5c7dc64561a4d4afb140afd606 [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: c9769c5c7dc64561a4d4afb140afd606, State: Initialized, Role: FOLLOWER
I20260812 06:16:59.113916 11112 consensus_queue.cc:260] T fdc3a6bf51e24184ad791417b3f69568 P c9769c5c7dc64561a4d4afb140afd606 [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: "c9769c5c7dc64561a4d4afb140afd606" member_type: VOTER last_known_addr { host: "127.10.74.193" port: 37935 } }
I20260812 06:16:59.113978 11112 raft_consensus.cc:399] T fdc3a6bf51e24184ad791417b3f69568 P c9769c5c7dc64561a4d4afb140afd606 [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:16:59.114001 11112 raft_consensus.cc:493] T fdc3a6bf51e24184ad791417b3f69568 P c9769c5c7dc64561a4d4afb140afd606 [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:16:59.114033 11112 raft_consensus.cc:3060] T fdc3a6bf51e24184ad791417b3f69568 P c9769c5c7dc64561a4d4afb140afd606 [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:16:59.114823 11112 raft_consensus.cc:515] T fdc3a6bf51e24184ad791417b3f69568 P c9769c5c7dc64561a4d4afb140afd606 [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "c9769c5c7dc64561a4d4afb140afd606" member_type: VOTER last_known_addr { host: "127.10.74.193" port: 37935 } }
I20260812 06:16:59.115031 11112 leader_election.cc:304] T fdc3a6bf51e24184ad791417b3f69568 P c9769c5c7dc64561a4d4afb140afd606 [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: c9769c5c7dc64561a4d4afb140afd606; no voters: 
I20260812 06:16:59.115264 11112 leader_election.cc:290] T fdc3a6bf51e24184ad791417b3f69568 P c9769c5c7dc64561a4d4afb140afd606 [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:16:59.115466 11117 raft_consensus.cc:2804] T fdc3a6bf51e24184ad791417b3f69568 P c9769c5c7dc64561a4d4afb140afd606 [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:16:59.115705 11112 ts_tablet_manager.cc:1434] T fdc3a6bf51e24184ad791417b3f69568 P c9769c5c7dc64561a4d4afb140afd606: Time spent starting tablet: real 0.002s	user 0.003s	sys 0.000s
I20260812 06:16:59.115710 11117 raft_consensus.cc:697] T fdc3a6bf51e24184ad791417b3f69568 P c9769c5c7dc64561a4d4afb140afd606 [term 1 LEADER]: Becoming Leader. State: Replica: c9769c5c7dc64561a4d4afb140afd606, State: Running, Role: LEADER
I20260812 06:16:59.115799 11098 heartbeater.cc:499] Master 127.10.74.254:39727 was elected leader, sending a full tablet report...
I20260812 06:16:59.116011 11117 consensus_queue.cc:237] T fdc3a6bf51e24184ad791417b3f69568 P c9769c5c7dc64561a4d4afb140afd606 [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: "c9769c5c7dc64561a4d4afb140afd606" member_type: VOTER last_known_addr { host: "127.10.74.193" port: 37935 } }
I20260812 06:16:59.117513 10886 catalog_manager.cc:5719] T fdc3a6bf51e24184ad791417b3f69568 P c9769c5c7dc64561a4d4afb140afd606 reported cstate change: term changed from 0 to 1, leader changed from <none> to c9769c5c7dc64561a4d4afb140afd606 (127.10.74.193). New cstate: current_term: 1 leader_uuid: "c9769c5c7dc64561a4d4afb140afd606" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "c9769c5c7dc64561a4d4afb140afd606" member_type: VOTER last_known_addr { host: "127.10.74.193" port: 37935 } health_report { overall_health: HEALTHY } } }
I20260812 06:16:59.185375 10539 heavy-update-compaction-itest.cc:215] Time spent inserting: real 0.062s	user 0.022s	sys 0.003s
I20260812 06:16:59.329198 11099 maintenance_manager.cc:419] P c9769c5c7dc64561a4d4afb140afd606: Scheduling FlushMRSOp(fdc3a6bf51e24184ad791417b3f69568): perf score=15.086190
I20260812 06:16:59.476672 10995 maintenance_manager.cc:643] P c9769c5c7dc64561a4d4afb140afd606: FlushMRSOp(fdc3a6bf51e24184ad791417b3f69568) complete. Timing: real 0.147s	user 0.098s	sys 0.048s Metrics: {"bytes_written":8615323,"cfile_init":1,"delete_count":0,"dirs.queue_time_us":80,"dirs.run_cpu_time_us":253,"dirs.run_wall_time_us":1058,"drs_written":1,"lbm_read_time_us":72,"lbm_reads_lt_1ms":4,"lbm_write_time_us":39279,"lbm_writes_lt_1ms":567,"peak_mem_usage":0,"reinsert_count":0,"rows_written":103,"spinlock_wait_cycles":1280,"update_count":1050}
I20260812 06:16:59.477734 11099 maintenance_manager.cc:419] P c9769c5c7dc64561a4d4afb140afd606: Scheduling LogGCOp(fdc3a6bf51e24184ad791417b3f69568): free 8725963 bytes of WAL
I20260812 06:16:59.478035 10995 log_reader.cc:385] T fdc3a6bf51e24184ad791417b3f69568: removed 1 log segments from log reader
I20260812 06:16:59.478139 10995 log.cc:1079] T fdc3a6bf51e24184ad791417b3f69568 P c9769c5c7dc64561a4d4afb140afd606: Deleting log segment in path: /tmp/dist-test-taskQQcY3W/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515412339501-10539-0/minicluster-data/ts-0-root/wals/fdc3a6bf51e24184ad791417b3f69568/wal-000000001 (ops 1-6)
I20260812 06:16:59.480872 10995 maintenance_manager.cc:643] P c9769c5c7dc64561a4d4afb140afd606: LogGCOp(fdc3a6bf51e24184ad791417b3f69568) complete. Timing: real 0.003s	user 0.000s	sys 0.001s Metrics: {}
I20260812 06:16:59.481345 11099 maintenance_manager.cc:419] P c9769c5c7dc64561a4d4afb140afd606: Scheduling FlushDeltaMemStoresOp(fdc3a6bf51e24184ad791417b3f69568): perf score=2.188937
I20260812 06:16:59.507339 10995 maintenance_manager.cc:643] P c9769c5c7dc64561a4d4afb140afd606: FlushDeltaMemStoresOp(fdc3a6bf51e24184ad791417b3f69568) complete. Timing: real 0.026s	user 0.006s	sys 0.019s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":6775,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:16:59.508076 11099 maintenance_manager.cc:419] P c9769c5c7dc64561a4d4afb140afd606: Scheduling MajorDeltaCompactionOp(fdc3a6bf51e24184ad791417b3f69568): perf score=1.000000
I20260812 06:16:59.670292 10995 maintenance_manager.cc:643] P c9769c5c7dc64561a4d4afb140afd606: MajorDeltaCompactionOp(fdc3a6bf51e24184ad791417b3f69568) complete. Timing: real 0.162s	user 0.101s	sys 0.061s Metrics: {"cfile_cache_miss":332,"cfile_cache_miss_bytes":16528891,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":815,"lbm_read_time_us":12855,"lbm_reads_lt_1ms":364,"lbm_write_time_us":23356,"lbm_writes_lt_1ms":343,"mutex_wait_us":29,"peak_mem_usage":38262756,"reinsert_count":0,"spinlock_wait_cycles":1408,"thread_start_us":390,"threads_started":5,"update_count":1500}
I20260812 06:16:59.670903 11099 maintenance_manager.cc:419] P c9769c5c7dc64561a4d4afb140afd606: Scheduling FlushDeltaMemStoresOp(fdc3a6bf51e24184ad791417b3f69568): perf score=10.126437
I20260812 06:16:59.724483 10995 maintenance_manager.cc:643] P c9769c5c7dc64561a4d4afb140afd606: FlushDeltaMemStoresOp(fdc3a6bf51e24184ad791417b3f69568) complete. Timing: real 0.053s	user 0.023s	sys 0.020s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":20170,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:16:59.725073 11099 maintenance_manager.cc:419] P c9769c5c7dc64561a4d4afb140afd606: Scheduling FlushDeltaMemStoresOp(fdc3a6bf51e24184ad791417b3f69568): perf score=2.188937
I20260812 06:16:59.736603 10995 maintenance_manager.cc:643] P c9769c5c7dc64561a4d4afb140afd606: FlushDeltaMemStoresOp(fdc3a6bf51e24184ad791417b3f69568) complete. Timing: real 0.011s	user 0.009s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4417,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:59.737488 11099 maintenance_manager.cc:419] P c9769c5c7dc64561a4d4afb140afd606: Scheduling MajorDeltaCompactionOp(fdc3a6bf51e24184ad791417b3f69568): perf score=1.000000
I20260812 06:16:59.892539 10995 maintenance_manager.cc:643] P c9769c5c7dc64561a4d4afb140afd606: MajorDeltaCompactionOp(fdc3a6bf51e24184ad791417b3f69568) complete. Timing: real 0.155s	user 0.103s	sys 0.051s 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":355,"lbm_read_time_us":11304,"lbm_reads_lt_1ms":472,"lbm_write_time_us":29431,"lbm_writes_lt_1ms":443,"mutex_wait_us":27,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":2304,"update_count":2000}
I20260812 06:16:59.893321 11099 maintenance_manager.cc:419] P c9769c5c7dc64561a4d4afb140afd606: Scheduling FlushDeltaMemStoresOp(fdc3a6bf51e24184ad791417b3f69568): perf score=10.126437
I20260812 06:16:59.940619 10995 maintenance_manager.cc:643] P c9769c5c7dc64561a4d4afb140afd606: FlushDeltaMemStoresOp(fdc3a6bf51e24184ad791417b3f69568) complete. Timing: real 0.047s	user 0.030s	sys 0.011s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":18964,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:16:59.941242 11099 maintenance_manager.cc:419] P c9769c5c7dc64561a4d4afb140afd606: Scheduling UndoDeltaBlockGCOp(fdc3a6bf51e24184ad791417b3f69568): 12308960 bytes on disk
I20260812 06:16:59.941707 10995 maintenance_manager.cc:643] P c9769c5c7dc64561a4d4afb140afd606: UndoDeltaBlockGCOp(fdc3a6bf51e24184ad791417b3f69568) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":56,"lbm_reads_lt_1ms":4}
I20260812 06:16:59.942169 11099 maintenance_manager.cc:419] P c9769c5c7dc64561a4d4afb140afd606: Scheduling FlushDeltaMemStoresOp(fdc3a6bf51e24184ad791417b3f69568): perf score=2.188937
I20260812 06:16:59.955634 10995 maintenance_manager.cc:643] P c9769c5c7dc64561a4d4afb140afd606: FlushDeltaMemStoresOp(fdc3a6bf51e24184ad791417b3f69568) complete. Timing: real 0.013s	user 0.013s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4607,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:59.956398 11099 maintenance_manager.cc:419] P c9769c5c7dc64561a4d4afb140afd606: Scheduling MajorDeltaCompactionOp(fdc3a6bf51e24184ad791417b3f69568): perf score=1.000000
I20260812 06:17:00.103823 10995 maintenance_manager.cc:643] P c9769c5c7dc64561a4d4afb140afd606: MajorDeltaCompactionOp(fdc3a6bf51e24184ad791417b3f69568) complete. Timing: real 0.147s	user 0.092s	sys 0.055s 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":262,"lbm_read_time_us":12482,"lbm_reads_lt_1ms":472,"lbm_write_time_us":27731,"lbm_writes_lt_1ms":443,"mutex_wait_us":29,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":23936,"update_count":2000}
I20260812 06:17:00.104640 11099 maintenance_manager.cc:419] P c9769c5c7dc64561a4d4afb140afd606: Scheduling FlushDeltaMemStoresOp(fdc3a6bf51e24184ad791417b3f69568): perf score=10.126437
I20260812 06:17:00.159602 10995 maintenance_manager.cc:643] P c9769c5c7dc64561a4d4afb140afd606: FlushDeltaMemStoresOp(fdc3a6bf51e24184ad791417b3f69568) complete. Timing: real 0.052s	user 0.023s	sys 0.023s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":16466,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:17:00.160341 11099 maintenance_manager.cc:419] P c9769c5c7dc64561a4d4afb140afd606: Scheduling FlushDeltaMemStoresOp(fdc3a6bf51e24184ad791417b3f69568): perf score=2.188937
I20260812 06:17:00.173939 10995 maintenance_manager.cc:643] P c9769c5c7dc64561a4d4afb140afd606: FlushDeltaMemStoresOp(fdc3a6bf51e24184ad791417b3f69568) complete. Timing: real 0.013s	user 0.008s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5421,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:00.174543 11099 maintenance_manager.cc:419] P c9769c5c7dc64561a4d4afb140afd606: Scheduling MajorDeltaCompactionOp(fdc3a6bf51e24184ad791417b3f69568): perf score=1.000000
I20260812 06:17:00.351722 10995 maintenance_manager.cc:643] P c9769c5c7dc64561a4d4afb140afd606: MajorDeltaCompactionOp(fdc3a6bf51e24184ad791417b3f69568) complete. Timing: real 0.177s	user 0.113s	sys 0.063s 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":192,"lbm_read_time_us":14406,"lbm_reads_lt_1ms":472,"lbm_write_time_us":27837,"lbm_writes_lt_1ms":443,"mutex_wait_us":37,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":73728,"update_count":2000}
I20260812 06:17:00.352407 11099 maintenance_manager.cc:419] P c9769c5c7dc64561a4d4afb140afd606: Scheduling FlushDeltaMemStoresOp(fdc3a6bf51e24184ad791417b3f69568): perf score=10.126437
I20260812 06:17:00.401620 10995 maintenance_manager.cc:643] P c9769c5c7dc64561a4d4afb140afd606: FlushDeltaMemStoresOp(fdc3a6bf51e24184ad791417b3f69568) complete. Timing: real 0.049s	user 0.025s	sys 0.006s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":15179,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:17:00.402297 11099 maintenance_manager.cc:419] P c9769c5c7dc64561a4d4afb140afd606: Scheduling FlushDeltaMemStoresOp(fdc3a6bf51e24184ad791417b3f69568): perf score=2.188937
I20260812 06:17:00.415802 10995 maintenance_manager.cc:643] P c9769c5c7dc64561a4d4afb140afd606: FlushDeltaMemStoresOp(fdc3a6bf51e24184ad791417b3f69568) complete. Timing: real 0.013s	user 0.008s	sys 0.004s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4957,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:00.416617 11099 maintenance_manager.cc:419] P c9769c5c7dc64561a4d4afb140afd606: Scheduling MajorDeltaCompactionOp(fdc3a6bf51e24184ad791417b3f69568): perf score=1.000000
I20260812 06:17:00.578051 10995 maintenance_manager.cc:643] P c9769c5c7dc64561a4d4afb140afd606: MajorDeltaCompactionOp(fdc3a6bf51e24184ad791417b3f69568) complete. Timing: real 0.161s	user 0.120s	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":1021,"lbm_read_time_us":13710,"lbm_reads_lt_1ms":472,"lbm_write_time_us":29227,"lbm_writes_lt_1ms":443,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":8192,"update_count":2000}
I20260812 06:17:00.578711 11099 maintenance_manager.cc:419] P c9769c5c7dc64561a4d4afb140afd606: Scheduling FlushDeltaMemStoresOp(fdc3a6bf51e24184ad791417b3f69568): perf score=10.126437
I20260812 06:17:00.630563 10995 maintenance_manager.cc:643] P c9769c5c7dc64561a4d4afb140afd606: FlushDeltaMemStoresOp(fdc3a6bf51e24184ad791417b3f69568) complete. Timing: real 0.052s	user 0.030s	sys 0.011s Metrics: {"bytes_written":12307491,"delete_count":0,"lbm_write_time_us":20001,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:17:00.631265 11099 maintenance_manager.cc:419] P c9769c5c7dc64561a4d4afb140afd606: Scheduling FlushDeltaMemStoresOp(fdc3a6bf51e24184ad791417b3f69568): perf score=2.188937
I20260812 06:17:00.644045 10995 maintenance_manager.cc:643] P c9769c5c7dc64561a4d4afb140afd606: FlushDeltaMemStoresOp(fdc3a6bf51e24184ad791417b3f69568) complete. Timing: real 0.013s	user 0.001s	sys 0.010s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4750,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:00.644819 11099 maintenance_manager.cc:419] P c9769c5c7dc64561a4d4afb140afd606: Scheduling MajorDeltaCompactionOp(fdc3a6bf51e24184ad791417b3f69568): perf score=1.000000
I20260812 06:17:00.795763 10995 maintenance_manager.cc:643] P c9769c5c7dc64561a4d4afb140afd606: MajorDeltaCompactionOp(fdc3a6bf51e24184ad791417b3f69568) complete. Timing: real 0.151s	user 0.138s	sys 0.012s 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":1278,"lbm_read_time_us":11064,"lbm_reads_lt_1ms":472,"lbm_write_time_us":29137,"lbm_writes_lt_1ms":443,"mutex_wait_us":578,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":6400,"update_count":2000}
I20260812 06:17:00.796511 11099 maintenance_manager.cc:419] P c9769c5c7dc64561a4d4afb140afd606: Scheduling FlushDeltaMemStoresOp(fdc3a6bf51e24184ad791417b3f69568): perf score=10.126437
I20260812 06:17:00.858453 10995 maintenance_manager.cc:643] P c9769c5c7dc64561a4d4afb140afd606: FlushDeltaMemStoresOp(fdc3a6bf51e24184ad791417b3f69568) complete. Timing: real 0.062s	user 0.030s	sys 0.019s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":19140,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:17:00.859166 11099 maintenance_manager.cc:419] P c9769c5c7dc64561a4d4afb140afd606: Scheduling FlushDeltaMemStoresOp(fdc3a6bf51e24184ad791417b3f69568): perf score=2.188937
I20260812 06:17:00.871228 10995 maintenance_manager.cc:643] P c9769c5c7dc64561a4d4afb140afd606: FlushDeltaMemStoresOp(fdc3a6bf51e24184ad791417b3f69568) complete. Timing: real 0.012s	user 0.007s	sys 0.005s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4715,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:00.871737 11099 maintenance_manager.cc:419] P c9769c5c7dc64561a4d4afb140afd606: Scheduling MajorDeltaCompactionOp(fdc3a6bf51e24184ad791417b3f69568): perf score=1.000000
I20260812 06:17:01.049163 10995 maintenance_manager.cc:643] P c9769c5c7dc64561a4d4afb140afd606: MajorDeltaCompactionOp(fdc3a6bf51e24184ad791417b3f69568) complete. Timing: real 0.177s	user 0.117s	sys 0.060s 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":412,"lbm_read_time_us":13064,"lbm_reads_lt_1ms":472,"lbm_write_time_us":29925,"lbm_writes_lt_1ms":443,"mutex_wait_us":57,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":2432,"update_count":2000}
I20260812 06:17:01.049945 11099 maintenance_manager.cc:419] P c9769c5c7dc64561a4d4afb140afd606: Scheduling FlushDeltaMemStoresOp(fdc3a6bf51e24184ad791417b3f69568): perf score=10.126437
I20260812 06:17:01.103168 10995 maintenance_manager.cc:643] P c9769c5c7dc64561a4d4afb140afd606: FlushDeltaMemStoresOp(fdc3a6bf51e24184ad791417b3f69568) complete. Timing: real 0.053s	user 0.021s	sys 0.022s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":19399,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:17:01.103853 11099 maintenance_manager.cc:419] P c9769c5c7dc64561a4d4afb140afd606: Scheduling FlushDeltaMemStoresOp(fdc3a6bf51e24184ad791417b3f69568): perf score=2.188937
I20260812 06:17:01.118815 10995 maintenance_manager.cc:643] P c9769c5c7dc64561a4d4afb140afd606: FlushDeltaMemStoresOp(fdc3a6bf51e24184ad791417b3f69568) complete. Timing: real 0.015s	user 0.008s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5335,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:01.119513 11099 maintenance_manager.cc:419] P c9769c5c7dc64561a4d4afb140afd606: Scheduling FlushMRSOp(fdc3a6bf51e24184ad791417b3f69568): perf score=1.000000
I20260812 06:17:01.157691 10995 maintenance_manager.cc:643] P c9769c5c7dc64561a4d4afb140afd606: FlushMRSOp(fdc3a6bf51e24184ad791417b3f69568) complete. Timing: real 0.038s	user 0.036s	sys 0.000s Metrics: {"bytes_written":1275444,"cfile_init":1,"dirs.queue_time_us":73,"dirs.run_cpu_time_us":253,"dirs.run_wall_time_us":1301,"drs_written":1,"lbm_read_time_us":66,"lbm_reads_lt_1ms":4,"lbm_write_time_us":2444,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":31}
I20260812 06:17:01.158540 11099 maintenance_manager.cc:419] P c9769c5c7dc64561a4d4afb140afd606: Scheduling LogGCOp(fdc3a6bf51e24184ad791417b3f69568): free 132571301 bytes of WAL
I20260812 06:17:01.158839 10995 log_reader.cc:385] T fdc3a6bf51e24184ad791417b3f69568: removed 13 log segments from log reader
I20260812 06:17:01.158906 10995 log.cc:1079] T fdc3a6bf51e24184ad791417b3f69568 P c9769c5c7dc64561a4d4afb140afd606: Deleting log segment in path: /tmp/dist-test-taskQQcY3W/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515412339501-10539-0/minicluster-data/ts-0-root/wals/fdc3a6bf51e24184ad791417b3f69568/wal-000000002 (ops 7-11)
I20260812 06:17:01.158995 10995 log.cc:1079] T fdc3a6bf51e24184ad791417b3f69568 P c9769c5c7dc64561a4d4afb140afd606: Deleting log segment in path: /tmp/dist-test-taskQQcY3W/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515412339501-10539-0/minicluster-data/ts-0-root/wals/fdc3a6bf51e24184ad791417b3f69568/wal-000000003 (ops 12-16)
I20260812 06:17:01.159032 10995 log.cc:1079] T fdc3a6bf51e24184ad791417b3f69568 P c9769c5c7dc64561a4d4afb140afd606: Deleting log segment in path: /tmp/dist-test-taskQQcY3W/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515412339501-10539-0/minicluster-data/ts-0-root/wals/fdc3a6bf51e24184ad791417b3f69568/wal-000000004 (ops 17-20)
I20260812 06:17:01.159057 10995 log.cc:1079] T fdc3a6bf51e24184ad791417b3f69568 P c9769c5c7dc64561a4d4afb140afd606: Deleting log segment in path: /tmp/dist-test-taskQQcY3W/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515412339501-10539-0/minicluster-data/ts-0-root/wals/fdc3a6bf51e24184ad791417b3f69568/wal-000000005 (ops 21-25)
I20260812 06:17:01.159085 10995 log.cc:1079] T fdc3a6bf51e24184ad791417b3f69568 P c9769c5c7dc64561a4d4afb140afd606: Deleting log segment in path: /tmp/dist-test-taskQQcY3W/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515412339501-10539-0/minicluster-data/ts-0-root/wals/fdc3a6bf51e24184ad791417b3f69568/wal-000000006 (ops 26-30)
I20260812 06:17:01.159118 10995 log.cc:1079] T fdc3a6bf51e24184ad791417b3f69568 P c9769c5c7dc64561a4d4afb140afd606: Deleting log segment in path: /tmp/dist-test-taskQQcY3W/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515412339501-10539-0/minicluster-data/ts-0-root/wals/fdc3a6bf51e24184ad791417b3f69568/wal-000000007 (ops 31-34)
I20260812 06:17:01.159152 10995 log.cc:1079] T fdc3a6bf51e24184ad791417b3f69568 P c9769c5c7dc64561a4d4afb140afd606: Deleting log segment in path: /tmp/dist-test-taskQQcY3W/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515412339501-10539-0/minicluster-data/ts-0-root/wals/fdc3a6bf51e24184ad791417b3f69568/wal-000000008 (ops 35-39)
I20260812 06:17:01.159183 10995 log.cc:1079] T fdc3a6bf51e24184ad791417b3f69568 P c9769c5c7dc64561a4d4afb140afd606: Deleting log segment in path: /tmp/dist-test-taskQQcY3W/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515412339501-10539-0/minicluster-data/ts-0-root/wals/fdc3a6bf51e24184ad791417b3f69568/wal-000000009 (ops 40-44)
I20260812 06:17:01.159214 10995 log.cc:1079] T fdc3a6bf51e24184ad791417b3f69568 P c9769c5c7dc64561a4d4afb140afd606: Deleting log segment in path: /tmp/dist-test-taskQQcY3W/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515412339501-10539-0/minicluster-data/ts-0-root/wals/fdc3a6bf51e24184ad791417b3f69568/wal-000000010 (ops 45-49)
I20260812 06:17:01.159245 10995 log.cc:1079] T fdc3a6bf51e24184ad791417b3f69568 P c9769c5c7dc64561a4d4afb140afd606: Deleting log segment in path: /tmp/dist-test-taskQQcY3W/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515412339501-10539-0/minicluster-data/ts-0-root/wals/fdc3a6bf51e24184ad791417b3f69568/wal-000000011 (ops 50-54)
I20260812 06:17:01.159281 10995 log.cc:1079] T fdc3a6bf51e24184ad791417b3f69568 P c9769c5c7dc64561a4d4afb140afd606: Deleting log segment in path: /tmp/dist-test-taskQQcY3W/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515412339501-10539-0/minicluster-data/ts-0-root/wals/fdc3a6bf51e24184ad791417b3f69568/wal-000000012 (ops 55-59)
I20260812 06:17:01.159315 10995 log.cc:1079] T fdc3a6bf51e24184ad791417b3f69568 P c9769c5c7dc64561a4d4afb140afd606: Deleting log segment in path: /tmp/dist-test-taskQQcY3W/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515412339501-10539-0/minicluster-data/ts-0-root/wals/fdc3a6bf51e24184ad791417b3f69568/wal-000000013 (ops 60-64)
I20260812 06:17:01.159346 10995 log.cc:1079] T fdc3a6bf51e24184ad791417b3f69568 P c9769c5c7dc64561a4d4afb140afd606: Deleting log segment in path: /tmp/dist-test-taskQQcY3W/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515412339501-10539-0/minicluster-data/ts-0-root/wals/fdc3a6bf51e24184ad791417b3f69568/wal-000000014 (ops 65-69)
I20260812 06:17:01.194226 10995 maintenance_manager.cc:643] P c9769c5c7dc64561a4d4afb140afd606: LogGCOp(fdc3a6bf51e24184ad791417b3f69568) complete. Timing: real 0.035s	user 0.002s	sys 0.031s Metrics: {}
I20260812 06:17:01.194767 11099 maintenance_manager.cc:419] P c9769c5c7dc64561a4d4afb140afd606: Scheduling UndoDeltaBlockGCOp(fdc3a6bf51e24184ad791417b3f69568): 482 bytes on disk
I20260812 06:17:01.195292 10995 maintenance_manager.cc:643] P c9769c5c7dc64561a4d4afb140afd606: UndoDeltaBlockGCOp(fdc3a6bf51e24184ad791417b3f69568) 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:17:01.195865 11099 maintenance_manager.cc:419] P c9769c5c7dc64561a4d4afb140afd606: Scheduling FlushDeltaMemStoresOp(fdc3a6bf51e24184ad791417b3f69568): perf score=3.181125
I20260812 06:17:01.221015 10995 maintenance_manager.cc:643] P c9769c5c7dc64561a4d4afb140afd606: FlushDeltaMemStoresOp(fdc3a6bf51e24184ad791417b3f69568) complete. Timing: real 0.025s	user 0.008s	sys 0.015s Metrics: {"bytes_written":4512904,"delete_count":0,"lbm_write_time_us":5331,"lbm_writes_lt_1ms":113,"reinsert_count":0,"update_count":550}
I20260812 06:17:01.221701 11099 maintenance_manager.cc:419] P c9769c5c7dc64561a4d4afb140afd606: Scheduling FlushDeltaMemStoresOp(fdc3a6bf51e24184ad791417b3f69568): perf score=2.188937
I20260812 06:17:01.233286 10995 maintenance_manager.cc:643] P c9769c5c7dc64561a4d4afb140afd606: FlushDeltaMemStoresOp(fdc3a6bf51e24184ad791417b3f69568) complete. Timing: real 0.011s	user 0.006s	sys 0.003s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":4548,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:17:01.233774 11099 maintenance_manager.cc:419] P c9769c5c7dc64561a4d4afb140afd606: Scheduling MajorDeltaCompactionOp(fdc3a6bf51e24184ad791417b3f69568): perf score=1.000000
I20260812 06:17:01.463264 10995 maintenance_manager.cc:643] P c9769c5c7dc64561a4d4afb140afd606: MajorDeltaCompactionOp(fdc3a6bf51e24184ad791417b3f69568) complete. Timing: real 0.229s	user 0.136s	sys 0.092s Metrics: {"cfile_cache_miss":634,"cfile_cache_miss_bytes":28836365,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":341,"lbm_read_time_us":16280,"lbm_reads_lt_1ms":674,"lbm_write_time_us":38707,"lbm_writes_lt_1ms":643,"mutex_wait_us":93,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":12288,"thread_start_us":99,"threads_started":1,"update_count":3000}
I20260812 06:17:01.464099 11099 maintenance_manager.cc:419] P c9769c5c7dc64561a4d4afb140afd606: Scheduling FlushDeltaMemStoresOp(fdc3a6bf51e24184ad791417b3f69568): perf score=14.095187
I20260812 06:17:01.553433 10995 maintenance_manager.cc:643] P c9769c5c7dc64561a4d4afb140afd606: FlushDeltaMemStoresOp(fdc3a6bf51e24184ad791417b3f69568) complete. Timing: real 0.089s	user 0.034s	sys 0.027s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":48530,"lbm_writes_10-100_ms":1,"lbm_writes_lt_1ms":402,"reinsert_count":0,"update_count":2000}
I20260812 06:17:01.554219 11099 maintenance_manager.cc:419] P c9769c5c7dc64561a4d4afb140afd606: Scheduling FlushDeltaMemStoresOp(fdc3a6bf51e24184ad791417b3f69568): perf score=2.188937
I20260812 06:17:01.566964 10995 maintenance_manager.cc:643] P c9769c5c7dc64561a4d4afb140afd606: FlushDeltaMemStoresOp(fdc3a6bf51e24184ad791417b3f69568) complete. Timing: real 0.013s	user 0.007s	sys 0.003s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4863,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:01.567571 11099 maintenance_manager.cc:419] P c9769c5c7dc64561a4d4afb140afd606: Scheduling MajorDeltaCompactionOp(fdc3a6bf51e24184ad791417b3f69568): perf score=1.000000
I20260812 06:17:01.786042 10995 maintenance_manager.cc:643] P c9769c5c7dc64561a4d4afb140afd606: MajorDeltaCompactionOp(fdc3a6bf51e24184ad791417b3f69568) complete. Timing: real 0.218s	user 0.124s	sys 0.094s 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":464,"lbm_read_time_us":15628,"lbm_reads_lt_1ms":572,"lbm_write_time_us":36825,"lbm_writes_lt_1ms":543,"mutex_wait_us":82,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":4096,"update_count":2500}
I20260812 06:17:01.787025 11099 maintenance_manager.cc:419] P c9769c5c7dc64561a4d4afb140afd606: Scheduling FlushDeltaMemStoresOp(fdc3a6bf51e24184ad791417b3f69568): perf score=11.118625
I20260812 06:17:01.831961 10995 maintenance_manager.cc:643] P c9769c5c7dc64561a4d4afb140afd606: FlushDeltaMemStoresOp(fdc3a6bf51e24184ad791417b3f69568) complete. Timing: real 0.045s	user 0.031s	sys 0.012s Metrics: {"bytes_written":12717737,"delete_count":0,"lbm_write_time_us":20016,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:17:01.832837 11099 maintenance_manager.cc:419] P c9769c5c7dc64561a4d4afb140afd606: Scheduling FlushDeltaMemStoresOp(fdc3a6bf51e24184ad791417b3f69568): perf score=2.188937
I20260812 06:17:01.851694 10995 maintenance_manager.cc:643] P c9769c5c7dc64561a4d4afb140afd606: FlushDeltaMemStoresOp(fdc3a6bf51e24184ad791417b3f69568) complete. Timing: real 0.019s	user 0.005s	sys 0.008s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":5131,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:17:01.852273 11099 maintenance_manager.cc:419] P c9769c5c7dc64561a4d4afb140afd606: Scheduling MajorDeltaCompactionOp(fdc3a6bf51e24184ad791417b3f69568): perf score=1.000000
I20260812 06:17:02.009924 10995 maintenance_manager.cc:643] P c9769c5c7dc64561a4d4afb140afd606: MajorDeltaCompactionOp(fdc3a6bf51e24184ad791417b3f69568) complete. Timing: real 0.157s	user 0.126s	sys 0.029s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20631305,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":1023,"lbm_read_time_us":11205,"lbm_reads_lt_1ms":464,"lbm_write_time_us":29785,"lbm_writes_lt_1ms":443,"mutex_wait_us":79,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":17280,"update_count":2000}
I20260812 06:17:02.010644 11099 maintenance_manager.cc:419] P c9769c5c7dc64561a4d4afb140afd606: Scheduling FlushDeltaMemStoresOp(fdc3a6bf51e24184ad791417b3f69568): perf score=10.126437
I20260812 06:17:02.057736 10995 maintenance_manager.cc:643] P c9769c5c7dc64561a4d4afb140afd606: FlushDeltaMemStoresOp(fdc3a6bf51e24184ad791417b3f69568) complete. Timing: real 0.047s	user 0.020s	sys 0.019s Metrics: {"bytes_written":12307491,"delete_count":0,"lbm_write_time_us":18060,"lbm_writes_lt_1ms":303,"mutex_wait_us":2,"reinsert_count":0,"update_count":1500}
I20260812 06:17:02.058434 11099 maintenance_manager.cc:419] P c9769c5c7dc64561a4d4afb140afd606: Scheduling FlushDeltaMemStoresOp(fdc3a6bf51e24184ad791417b3f69568): perf score=2.188937
I20260812 06:17:02.076550 10995 maintenance_manager.cc:643] P c9769c5c7dc64561a4d4afb140afd606: FlushDeltaMemStoresOp(fdc3a6bf51e24184ad791417b3f69568) complete. Timing: real 0.018s	user 0.009s	sys 0.007s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6566,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:02.077335 11099 maintenance_manager.cc:419] P c9769c5c7dc64561a4d4afb140afd606: Scheduling MajorDeltaCompactionOp(fdc3a6bf51e24184ad791417b3f69568): perf score=1.000000
I20260812 06:17:02.225605 10995 maintenance_manager.cc:643] P c9769c5c7dc64561a4d4afb140afd606: MajorDeltaCompactionOp(fdc3a6bf51e24184ad791417b3f69568) complete. Timing: real 0.148s	user 0.118s	sys 0.030s 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":292,"lbm_read_time_us":10032,"lbm_reads_lt_1ms":472,"lbm_write_time_us":28454,"lbm_writes_lt_1ms":443,"mutex_wait_us":26,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":14720,"update_count":2000}
I20260812 06:17:02.226533 11099 maintenance_manager.cc:419] P c9769c5c7dc64561a4d4afb140afd606: Scheduling FlushDeltaMemStoresOp(fdc3a6bf51e24184ad791417b3f69568): perf score=10.126437
I20260812 06:17:02.276721 10995 maintenance_manager.cc:643] P c9769c5c7dc64561a4d4afb140afd606: FlushDeltaMemStoresOp(fdc3a6bf51e24184ad791417b3f69568) complete. Timing: real 0.050s	user 0.030s	sys 0.012s Metrics: {"bytes_written":12307493,"delete_count":0,"lbm_write_time_us":19276,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:17:02.277307 11099 maintenance_manager.cc:419] P c9769c5c7dc64561a4d4afb140afd606: Scheduling FlushDeltaMemStoresOp(fdc3a6bf51e24184ad791417b3f69568): perf score=2.188937
I20260812 06:17:02.289218 10995 maintenance_manager.cc:643] P c9769c5c7dc64561a4d4afb140afd606: FlushDeltaMemStoresOp(fdc3a6bf51e24184ad791417b3f69568) complete. Timing: real 0.012s	user 0.005s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4504,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:02.290074 11099 maintenance_manager.cc:419] P c9769c5c7dc64561a4d4afb140afd606: Scheduling MajorDeltaCompactionOp(fdc3a6bf51e24184ad791417b3f69568): perf score=1.000000
I20260812 06:17:02.435010 10995 maintenance_manager.cc:643] P c9769c5c7dc64561a4d4afb140afd606: MajorDeltaCompactionOp(fdc3a6bf51e24184ad791417b3f69568) complete. Timing: real 0.145s	user 0.123s	sys 0.022s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20631315,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":481,"lbm_read_time_us":10777,"lbm_reads_lt_1ms":472,"lbm_write_time_us":28784,"lbm_writes_lt_1ms":443,"mutex_wait_us":47,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":10624,"update_count":2000}
I20260812 06:17:02.435952 11099 maintenance_manager.cc:419] P c9769c5c7dc64561a4d4afb140afd606: Scheduling FlushDeltaMemStoresOp(fdc3a6bf51e24184ad791417b3f69568): perf score=10.126437
I20260812 06:17:02.495024 10995 maintenance_manager.cc:643] P c9769c5c7dc64561a4d4afb140afd606: FlushDeltaMemStoresOp(fdc3a6bf51e24184ad791417b3f69568) complete. Timing: real 0.059s	user 0.027s	sys 0.024s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":18128,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:17:02.495757 11099 maintenance_manager.cc:419] P c9769c5c7dc64561a4d4afb140afd606: Scheduling FlushDeltaMemStoresOp(fdc3a6bf51e24184ad791417b3f69568): perf score=2.188937
I20260812 06:17:02.508496 10995 maintenance_manager.cc:643] P c9769c5c7dc64561a4d4afb140afd606: FlushDeltaMemStoresOp(fdc3a6bf51e24184ad791417b3f69568) complete. Timing: real 0.013s	user 0.006s	sys 0.005s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":5023,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:02.509042 11099 maintenance_manager.cc:419] P c9769c5c7dc64561a4d4afb140afd606: Scheduling MajorDeltaCompactionOp(fdc3a6bf51e24184ad791417b3f69568): perf score=1.000000
I20260812 06:17:02.678889 10995 maintenance_manager.cc:643] P c9769c5c7dc64561a4d4afb140afd606: MajorDeltaCompactionOp(fdc3a6bf51e24184ad791417b3f69568) complete. Timing: real 0.170s	user 0.100s	sys 0.067s 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":284,"lbm_read_time_us":14343,"lbm_reads_lt_1ms":472,"lbm_write_time_us":29818,"lbm_writes_lt_1ms":443,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":10112,"update_count":2000}
I20260812 06:17:02.679792 11099 maintenance_manager.cc:419] P c9769c5c7dc64561a4d4afb140afd606: Scheduling FlushDeltaMemStoresOp(fdc3a6bf51e24184ad791417b3f69568): perf score=10.126437
I20260812 06:17:02.730592 10995 maintenance_manager.cc:643] P c9769c5c7dc64561a4d4afb140afd606: FlushDeltaMemStoresOp(fdc3a6bf51e24184ad791417b3f69568) complete. Timing: real 0.051s	user 0.017s	sys 0.021s Metrics: {"bytes_written":12307491,"delete_count":0,"lbm_write_time_us":17985,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:17:02.731251 11099 maintenance_manager.cc:419] P c9769c5c7dc64561a4d4afb140afd606: Scheduling FlushDeltaMemStoresOp(fdc3a6bf51e24184ad791417b3f69568): perf score=2.188937
I20260812 06:17:02.743603 10995 maintenance_manager.cc:643] P c9769c5c7dc64561a4d4afb140afd606: FlushDeltaMemStoresOp(fdc3a6bf51e24184ad791417b3f69568) complete. Timing: real 0.012s	user 0.003s	sys 0.009s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4683,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:02.744571 11099 maintenance_manager.cc:419] P c9769c5c7dc64561a4d4afb140afd606: Scheduling MajorDeltaCompactionOp(fdc3a6bf51e24184ad791417b3f69568): perf score=1.000000
I20260812 06:17:02.899127 10995 maintenance_manager.cc:643] P c9769c5c7dc64561a4d4afb140afd606: MajorDeltaCompactionOp(fdc3a6bf51e24184ad791417b3f69568) complete. Timing: real 0.154s	user 0.116s	sys 0.036s 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":385,"lbm_read_time_us":11663,"lbm_reads_lt_1ms":472,"lbm_write_time_us":28740,"lbm_writes_lt_1ms":443,"mutex_wait_us":27,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":12416,"update_count":2000}
I20260812 06:17:02.899973 11099 maintenance_manager.cc:419] P c9769c5c7dc64561a4d4afb140afd606: Scheduling FlushDeltaMemStoresOp(fdc3a6bf51e24184ad791417b3f69568): perf score=10.126437
I20260812 06:17:02.951176 10995 maintenance_manager.cc:643] P c9769c5c7dc64561a4d4afb140afd606: FlushDeltaMemStoresOp(fdc3a6bf51e24184ad791417b3f69568) complete. Timing: real 0.051s	user 0.015s	sys 0.027s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":18245,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":302,"reinsert_count":0,"update_count":1500}
I20260812 06:17:02.951864 11099 maintenance_manager.cc:419] P c9769c5c7dc64561a4d4afb140afd606: Scheduling FlushDeltaMemStoresOp(fdc3a6bf51e24184ad791417b3f69568): perf score=2.188937
I20260812 06:17:02.971393 10995 maintenance_manager.cc:643] P c9769c5c7dc64561a4d4afb140afd606: FlushDeltaMemStoresOp(fdc3a6bf51e24184ad791417b3f69568) complete. Timing: real 0.019s	user 0.011s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":7398,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:02.972275 11099 maintenance_manager.cc:419] P c9769c5c7dc64561a4d4afb140afd606: Scheduling FlushMRSOp(fdc3a6bf51e24184ad791417b3f69568): perf score=1.000000
I20260812 06:17:03.010838 10995 maintenance_manager.cc:643] P c9769c5c7dc64561a4d4afb140afd606: FlushMRSOp(fdc3a6bf51e24184ad791417b3f69568) complete. Timing: real 0.038s	user 0.032s	sys 0.004s Metrics: {"bytes_written":1275449,"cfile_init":1,"dirs.queue_time_us":89,"dirs.run_cpu_time_us":236,"dirs.run_wall_time_us":1200,"drs_written":1,"lbm_read_time_us":48,"lbm_reads_lt_1ms":4,"lbm_write_time_us":2687,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":31}
I20260812 06:17:03.011667 11099 maintenance_manager.cc:419] P c9769c5c7dc64561a4d4afb140afd606: Scheduling LogGCOp(fdc3a6bf51e24184ad791417b3f69568): free 132571329 bytes of WAL
I20260812 06:17:03.011946 10995 log_reader.cc:385] T fdc3a6bf51e24184ad791417b3f69568: removed 13 log segments from log reader
I20260812 06:17:03.012001 10995 log.cc:1079] T fdc3a6bf51e24184ad791417b3f69568 P c9769c5c7dc64561a4d4afb140afd606: Deleting log segment in path: /tmp/dist-test-taskQQcY3W/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515412339501-10539-0/minicluster-data/ts-0-root/wals/fdc3a6bf51e24184ad791417b3f69568/wal-000000015 (ops 70-74)
I20260812 06:17:03.012058 10995 log.cc:1079] T fdc3a6bf51e24184ad791417b3f69568 P c9769c5c7dc64561a4d4afb140afd606: Deleting log segment in path: /tmp/dist-test-taskQQcY3W/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515412339501-10539-0/minicluster-data/ts-0-root/wals/fdc3a6bf51e24184ad791417b3f69568/wal-000000016 (ops 75-78)
I20260812 06:17:03.012104 10995 log.cc:1079] T fdc3a6bf51e24184ad791417b3f69568 P c9769c5c7dc64561a4d4afb140afd606: Deleting log segment in path: /tmp/dist-test-taskQQcY3W/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515412339501-10539-0/minicluster-data/ts-0-root/wals/fdc3a6bf51e24184ad791417b3f69568/wal-000000017 (ops 79-83)
I20260812 06:17:03.012179 10995 log.cc:1079] T fdc3a6bf51e24184ad791417b3f69568 P c9769c5c7dc64561a4d4afb140afd606: Deleting log segment in path: /tmp/dist-test-taskQQcY3W/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515412339501-10539-0/minicluster-data/ts-0-root/wals/fdc3a6bf51e24184ad791417b3f69568/wal-000000018 (ops 84-88)
I20260812 06:17:03.012223 10995 log.cc:1079] T fdc3a6bf51e24184ad791417b3f69568 P c9769c5c7dc64561a4d4afb140afd606: Deleting log segment in path: /tmp/dist-test-taskQQcY3W/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515412339501-10539-0/minicluster-data/ts-0-root/wals/fdc3a6bf51e24184ad791417b3f69568/wal-000000019 (ops 89-93)
I20260812 06:17:03.012267 10995 log.cc:1079] T fdc3a6bf51e24184ad791417b3f69568 P c9769c5c7dc64561a4d4afb140afd606: Deleting log segment in path: /tmp/dist-test-taskQQcY3W/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515412339501-10539-0/minicluster-data/ts-0-root/wals/fdc3a6bf51e24184ad791417b3f69568/wal-000000020 (ops 94-98)
I20260812 06:17:03.012328 10995 log.cc:1079] T fdc3a6bf51e24184ad791417b3f69568 P c9769c5c7dc64561a4d4afb140afd606: Deleting log segment in path: /tmp/dist-test-taskQQcY3W/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515412339501-10539-0/minicluster-data/ts-0-root/wals/fdc3a6bf51e24184ad791417b3f69568/wal-000000021 (ops 99-103)
I20260812 06:17:03.012372 10995 log.cc:1079] T fdc3a6bf51e24184ad791417b3f69568 P c9769c5c7dc64561a4d4afb140afd606: Deleting log segment in path: /tmp/dist-test-taskQQcY3W/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515412339501-10539-0/minicluster-data/ts-0-root/wals/fdc3a6bf51e24184ad791417b3f69568/wal-000000022 (ops 104-108)
I20260812 06:17:03.012414 10995 log.cc:1079] T fdc3a6bf51e24184ad791417b3f69568 P c9769c5c7dc64561a4d4afb140afd606: Deleting log segment in path: /tmp/dist-test-taskQQcY3W/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515412339501-10539-0/minicluster-data/ts-0-root/wals/fdc3a6bf51e24184ad791417b3f69568/wal-000000023 (ops 109-113)
I20260812 06:17:03.012461 10995 log.cc:1079] T fdc3a6bf51e24184ad791417b3f69568 P c9769c5c7dc64561a4d4afb140afd606: Deleting log segment in path: /tmp/dist-test-taskQQcY3W/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515412339501-10539-0/minicluster-data/ts-0-root/wals/fdc3a6bf51e24184ad791417b3f69568/wal-000000024 (ops 114-118)
I20260812 06:17:03.012503 10995 log.cc:1079] T fdc3a6bf51e24184ad791417b3f69568 P c9769c5c7dc64561a4d4afb140afd606: Deleting log segment in path: /tmp/dist-test-taskQQcY3W/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515412339501-10539-0/minicluster-data/ts-0-root/wals/fdc3a6bf51e24184ad791417b3f69568/wal-000000025 (ops 119-122)
I20260812 06:17:03.012542 10995 log.cc:1079] T fdc3a6bf51e24184ad791417b3f69568 P c9769c5c7dc64561a4d4afb140afd606: Deleting log segment in path: /tmp/dist-test-taskQQcY3W/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515412339501-10539-0/minicluster-data/ts-0-root/wals/fdc3a6bf51e24184ad791417b3f69568/wal-000000026 (ops 123-127)
I20260812 06:17:03.012583 10995 log.cc:1079] T fdc3a6bf51e24184ad791417b3f69568 P c9769c5c7dc64561a4d4afb140afd606: Deleting log segment in path: /tmp/dist-test-taskQQcY3W/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515412339501-10539-0/minicluster-data/ts-0-root/wals/fdc3a6bf51e24184ad791417b3f69568/wal-000000027 (ops 128-132)
I20260812 06:17:03.040984 10995 maintenance_manager.cc:643] P c9769c5c7dc64561a4d4afb140afd606: LogGCOp(fdc3a6bf51e24184ad791417b3f69568) complete. Timing: real 0.029s	user 0.000s	sys 0.027s Metrics: {}
I20260812 06:17:03.041443 11099 maintenance_manager.cc:419] P c9769c5c7dc64561a4d4afb140afd606: Scheduling UndoDeltaBlockGCOp(fdc3a6bf51e24184ad791417b3f69568): 483 bytes on disk
I20260812 06:17:03.042222 10995 maintenance_manager.cc:643] P c9769c5c7dc64561a4d4afb140afd606: UndoDeltaBlockGCOp(fdc3a6bf51e24184ad791417b3f69568) complete. Timing: real 0.001s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":76,"lbm_reads_lt_1ms":4}
I20260812 06:17:03.042796 11099 maintenance_manager.cc:419] P c9769c5c7dc64561a4d4afb140afd606: Scheduling FlushDeltaMemStoresOp(fdc3a6bf51e24184ad791417b3f69568): perf score=3.181125
I20260812 06:17:03.058504 10995 maintenance_manager.cc:643] P c9769c5c7dc64561a4d4afb140afd606: FlushDeltaMemStoresOp(fdc3a6bf51e24184ad791417b3f69568) complete. Timing: real 0.015s	user 0.006s	sys 0.005s Metrics: {"bytes_written":4512903,"delete_count":0,"lbm_write_time_us":5695,"lbm_writes_lt_1ms":113,"reinsert_count":0,"update_count":550}
I20260812 06:17:03.059072 11099 maintenance_manager.cc:419] P c9769c5c7dc64561a4d4afb140afd606: Scheduling FlushDeltaMemStoresOp(fdc3a6bf51e24184ad791417b3f69568): perf score=2.188937
I20260812 06:17:03.069994 10995 maintenance_manager.cc:643] P c9769c5c7dc64561a4d4afb140afd606: FlushDeltaMemStoresOp(fdc3a6bf51e24184ad791417b3f69568) complete. Timing: real 0.011s	user 0.008s	sys 0.000s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":4211,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:17:03.070535 11099 maintenance_manager.cc:419] P c9769c5c7dc64561a4d4afb140afd606: Scheduling MajorDeltaCompactionOp(fdc3a6bf51e24184ad791417b3f69568): perf score=1.000000
I20260812 06:17:03.283519 10995 maintenance_manager.cc:643] P c9769c5c7dc64561a4d4afb140afd606: MajorDeltaCompactionOp(fdc3a6bf51e24184ad791417b3f69568) complete. Timing: real 0.213s	user 0.151s	sys 0.054s Metrics: {"cfile_cache_miss":634,"cfile_cache_miss_bytes":28836364,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":1051,"lbm_read_time_us":15961,"lbm_reads_lt_1ms":674,"lbm_write_time_us":42460,"lbm_writes_lt_1ms":643,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":3328,"thread_start_us":103,"threads_started":1,"update_count":3000}
I20260812 06:17:03.284346 11099 maintenance_manager.cc:419] P c9769c5c7dc64561a4d4afb140afd606: Scheduling FlushDeltaMemStoresOp(fdc3a6bf51e24184ad791417b3f69568): perf score=14.095187
I20260812 06:17:03.343276 10995 maintenance_manager.cc:643] P c9769c5c7dc64561a4d4afb140afd606: FlushDeltaMemStoresOp(fdc3a6bf51e24184ad791417b3f69568) complete. Timing: real 0.059s	user 0.025s	sys 0.032s Metrics: {"bytes_written":16409903,"delete_count":0,"lbm_write_time_us":24184,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":402,"reinsert_count":0,"update_count":2000}
I20260812 06:17:03.343873 11099 maintenance_manager.cc:419] P c9769c5c7dc64561a4d4afb140afd606: Scheduling FlushDeltaMemStoresOp(fdc3a6bf51e24184ad791417b3f69568): perf score=2.188937
I20260812 06:17:03.358289 10995 maintenance_manager.cc:643] P c9769c5c7dc64561a4d4afb140afd606: FlushDeltaMemStoresOp(fdc3a6bf51e24184ad791417b3f69568) complete. Timing: real 0.014s	user 0.012s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5666,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:03.359251 11099 maintenance_manager.cc:419] P c9769c5c7dc64561a4d4afb140afd606: Scheduling MajorDeltaCompactionOp(fdc3a6bf51e24184ad791417b3f69568): perf score=1.000000
I20260812 06:17:03.548640 10995 maintenance_manager.cc:643] P c9769c5c7dc64561a4d4afb140afd606: MajorDeltaCompactionOp(fdc3a6bf51e24184ad791417b3f69568) complete. Timing: real 0.189s	user 0.129s	sys 0.056s 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":1166,"lbm_read_time_us":13412,"lbm_reads_lt_1ms":572,"lbm_write_time_us":34153,"lbm_writes_lt_1ms":543,"mutex_wait_us":26,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":14976,"update_count":2500}
I20260812 06:17:03.549553 11099 maintenance_manager.cc:419] P c9769c5c7dc64561a4d4afb140afd606: Scheduling FlushDeltaMemStoresOp(fdc3a6bf51e24184ad791417b3f69568): perf score=13.103000
I20260812 06:17:03.607928 10995 maintenance_manager.cc:643] P c9769c5c7dc64561a4d4afb140afd606: FlushDeltaMemStoresOp(fdc3a6bf51e24184ad791417b3f69568) complete. Timing: real 0.058s	user 0.040s	sys 0.016s Metrics: {"bytes_written":15056104,"delete_count":0,"lbm_write_time_us":25916,"lbm_writes_lt_1ms":370,"reinsert_count":0,"update_count":1835}
I20260812 06:17:03.608561 11099 maintenance_manager.cc:419] P c9769c5c7dc64561a4d4afb140afd606: Scheduling FlushDeltaMemStoresOp(fdc3a6bf51e24184ad791417b3f69568): perf score=1.000000
I20260812 06:17:03.634603 10995 maintenance_manager.cc:643] P c9769c5c7dc64561a4d4afb140afd606: FlushDeltaMemStoresOp(fdc3a6bf51e24184ad791417b3f69568) complete. Timing: real 0.026s	user 0.005s	sys 0.004s Metrics: {"bytes_written":1764231,"delete_count":0,"lbm_write_time_us":3875,"lbm_writes_lt_1ms":46,"reinsert_count":0,"update_count":215}
I20260812 06:17:03.635213 11099 maintenance_manager.cc:419] P c9769c5c7dc64561a4d4afb140afd606: Scheduling FlushDeltaMemStoresOp(fdc3a6bf51e24184ad791417b3f69568): perf score=2.188937
I20260812 06:17:03.646165 10995 maintenance_manager.cc:643] P c9769c5c7dc64561a4d4afb140afd606: FlushDeltaMemStoresOp(fdc3a6bf51e24184ad791417b3f69568) complete. Timing: real 0.011s	user 0.005s	sys 0.004s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":4169,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:17:03.646792 11099 maintenance_manager.cc:419] P c9769c5c7dc64561a4d4afb140afd606: Scheduling MajorDeltaCompactionOp(fdc3a6bf51e24184ad791417b3f69568): perf score=1.000000
I20260812 06:17:03.853608 10995 maintenance_manager.cc:643] P c9769c5c7dc64561a4d4afb140afd606: MajorDeltaCompactionOp(fdc3a6bf51e24184ad791417b3f69568) complete. Timing: real 0.207s	user 0.133s	sys 0.072s Metrics: {"cfile_cache_miss":533,"cfile_cache_miss_bytes":24733776,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":541,"lbm_read_time_us":15706,"lbm_reads_lt_1ms":573,"lbm_write_time_us":37827,"lbm_writes_lt_1ms":543,"mutex_wait_us":93,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":16896,"update_count":2500}
I20260812 06:17:03.854275 11099 maintenance_manager.cc:419] P c9769c5c7dc64561a4d4afb140afd606: Scheduling FlushDeltaMemStoresOp(fdc3a6bf51e24184ad791417b3f69568): perf score=10.126437
I20260812 06:17:03.901603 10995 maintenance_manager.cc:643] P c9769c5c7dc64561a4d4afb140afd606: FlushDeltaMemStoresOp(fdc3a6bf51e24184ad791417b3f69568) complete. Timing: real 0.047s	user 0.026s	sys 0.018s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":16839,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:17:03.902302 11099 maintenance_manager.cc:419] P c9769c5c7dc64561a4d4afb140afd606: Scheduling FlushDeltaMemStoresOp(fdc3a6bf51e24184ad791417b3f69568): perf score=2.188937
I20260812 06:17:03.915108 10995 maintenance_manager.cc:643] P c9769c5c7dc64561a4d4afb140afd606: FlushDeltaMemStoresOp(fdc3a6bf51e24184ad791417b3f69568) complete. Timing: real 0.013s	user 0.012s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4974,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:03.915652 11099 maintenance_manager.cc:419] P c9769c5c7dc64561a4d4afb140afd606: Scheduling MajorDeltaCompactionOp(fdc3a6bf51e24184ad791417b3f69568): perf score=1.000000
I20260812 06:17:04.087625 10995 maintenance_manager.cc:643] P c9769c5c7dc64561a4d4afb140afd606: MajorDeltaCompactionOp(fdc3a6bf51e24184ad791417b3f69568) complete. Timing: real 0.172s	user 0.112s	sys 0.059s 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":1029,"lbm_read_time_us":13178,"lbm_reads_lt_1ms":472,"lbm_write_time_us":29946,"lbm_writes_lt_1ms":443,"mutex_wait_us":59,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":768,"update_count":2000}
I20260812 06:17:04.088424 11099 maintenance_manager.cc:419] P c9769c5c7dc64561a4d4afb140afd606: Scheduling FlushDeltaMemStoresOp(fdc3a6bf51e24184ad791417b3f69568): perf score=10.126437
I20260812 06:17:04.137442 10995 maintenance_manager.cc:643] P c9769c5c7dc64561a4d4afb140afd606: FlushDeltaMemStoresOp(fdc3a6bf51e24184ad791417b3f69568) complete. Timing: real 0.049s	user 0.030s	sys 0.012s Metrics: {"bytes_written":12307491,"delete_count":0,"lbm_write_time_us":19745,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:17:04.138060 11099 maintenance_manager.cc:419] P c9769c5c7dc64561a4d4afb140afd606: Scheduling FlushDeltaMemStoresOp(fdc3a6bf51e24184ad791417b3f69568): perf score=2.188937
I20260812 06:17:04.150729 10995 maintenance_manager.cc:643] P c9769c5c7dc64561a4d4afb140afd606: FlushDeltaMemStoresOp(fdc3a6bf51e24184ad791417b3f69568) complete. Timing: real 0.012s	user 0.000s	sys 0.010s 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:17:04.151999 11099 maintenance_manager.cc:419] P c9769c5c7dc64561a4d4afb140afd606: Scheduling MajorDeltaCompactionOp(fdc3a6bf51e24184ad791417b3f69568): perf score=1.000000
I20260812 06:17:04.310568 10995 maintenance_manager.cc:643] P c9769c5c7dc64561a4d4afb140afd606: MajorDeltaCompactionOp(fdc3a6bf51e24184ad791417b3f69568) complete. Timing: real 0.158s	user 0.126s	sys 0.029s 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":178,"lbm_read_time_us":13177,"lbm_reads_lt_1ms":472,"lbm_write_time_us":29947,"lbm_writes_lt_1ms":443,"mutex_wait_us":37,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":6912,"update_count":2000}
I20260812 06:17:04.311399 11099 maintenance_manager.cc:419] P c9769c5c7dc64561a4d4afb140afd606: Scheduling FlushDeltaMemStoresOp(fdc3a6bf51e24184ad791417b3f69568): perf score=10.126437
I20260812 06:17:04.345527 10995 maintenance_manager.cc:643] P c9769c5c7dc64561a4d4afb140afd606: FlushDeltaMemStoresOp(fdc3a6bf51e24184ad791417b3f69568) complete. Timing: real 0.034s	user 0.024s	sys 0.007s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":15077,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:17:04.346331 11099 maintenance_manager.cc:419] P c9769c5c7dc64561a4d4afb140afd606: Scheduling MajorDeltaCompactionOp(fdc3a6bf51e24184ad791417b3f69568): perf score=1.000000
I20260812 06:17:04.473227 10995 maintenance_manager.cc:643] P c9769c5c7dc64561a4d4afb140afd606: MajorDeltaCompactionOp(fdc3a6bf51e24184ad791417b3f69568) complete. Timing: real 0.127s	user 0.103s	sys 0.024s Metrics: {"cfile_cache_miss":331,"cfile_cache_miss_bytes":16528781,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":1,"delta_iterators_relevant":1,"dirs.queue_time_us":1088,"lbm_read_time_us":8309,"lbm_reads_lt_1ms":367,"lbm_write_time_us":24627,"lbm_writes_lt_1ms":343,"mutex_wait_us":330,"peak_mem_usage":38262756,"reinsert_count":0,"spinlock_wait_cycles":36224,"update_count":1500}
I20260812 06:17:04.474118 11099 maintenance_manager.cc:419] P c9769c5c7dc64561a4d4afb140afd606: Scheduling FlushDeltaMemStoresOp(fdc3a6bf51e24184ad791417b3f69568): perf score=10.126437
I20260812 06:17:04.519090 10995 maintenance_manager.cc:643] P c9769c5c7dc64561a4d4afb140afd606: FlushDeltaMemStoresOp(fdc3a6bf51e24184ad791417b3f69568) complete. Timing: real 0.045s	user 0.025s	sys 0.020s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":19118,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:17:04.520082 11099 maintenance_manager.cc:419] P c9769c5c7dc64561a4d4afb140afd606: Scheduling MajorDeltaCompactionOp(fdc3a6bf51e24184ad791417b3f69568): perf score=1.000000
I20260812 06:17:04.665777 10995 maintenance_manager.cc:643] P c9769c5c7dc64561a4d4afb140afd606: MajorDeltaCompactionOp(fdc3a6bf51e24184ad791417b3f69568) complete. Timing: real 0.145s	user 0.088s	sys 0.057s Metrics: {"cfile_cache_miss":331,"cfile_cache_miss_bytes":16528781,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":1,"delta_iterators_relevant":1,"dirs.queue_time_us":298,"lbm_read_time_us":11532,"lbm_reads_lt_1ms":367,"lbm_write_time_us":23605,"lbm_writes_lt_1ms":343,"mutex_wait_us":101,"peak_mem_usage":38262756,"reinsert_count":0,"spinlock_wait_cycles":14848,"update_count":1500}
I20260812 06:17:04.666733 11099 maintenance_manager.cc:419] P c9769c5c7dc64561a4d4afb140afd606: Scheduling FlushDeltaMemStoresOp(fdc3a6bf51e24184ad791417b3f69568): perf score=10.126437
I20260812 06:17:04.716074 10995 maintenance_manager.cc:643] P c9769c5c7dc64561a4d4afb140afd606: FlushDeltaMemStoresOp(fdc3a6bf51e24184ad791417b3f69568) complete. Timing: real 0.049s	user 0.021s	sys 0.023s Metrics: {"bytes_written":12307492,"delete_count":0,"lbm_write_time_us":20375,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:17:04.716714 11099 maintenance_manager.cc:419] P c9769c5c7dc64561a4d4afb140afd606: Scheduling FlushDeltaMemStoresOp(fdc3a6bf51e24184ad791417b3f69568): perf score=2.188937
I20260812 06:17:04.728878 10995 maintenance_manager.cc:643] P c9769c5c7dc64561a4d4afb140afd606: FlushDeltaMemStoresOp(fdc3a6bf51e24184ad791417b3f69568) complete. Timing: real 0.012s	user 0.010s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4354,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:04.729882 11099 maintenance_manager.cc:419] P c9769c5c7dc64561a4d4afb140afd606: Scheduling FlushMRSOp(fdc3a6bf51e24184ad791417b3f69568): perf score=1.000000
I20260812 06:17:04.764183 10995 maintenance_manager.cc:643] P c9769c5c7dc64561a4d4afb140afd606: FlushMRSOp(fdc3a6bf51e24184ad791417b3f69568) complete. Timing: real 0.034s	user 0.024s	sys 0.007s Metrics: {"bytes_written":1234477,"cfile_init":1,"dirs.queue_time_us":160,"dirs.run_cpu_time_us":339,"dirs.run_wall_time_us":1436,"drs_written":1,"lbm_read_time_us":105,"lbm_reads_lt_1ms":4,"lbm_write_time_us":2425,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":30,"spinlock_wait_cycles":5888}
I20260812 06:17:04.764943 11099 maintenance_manager.cc:419] P c9769c5c7dc64561a4d4afb140afd606: Scheduling LogGCOp(fdc3a6bf51e24184ad791417b3f69568): free 121006699 bytes of WAL
I20260812 06:17:04.765187 10995 log_reader.cc:385] T fdc3a6bf51e24184ad791417b3f69568: removed 12 log segments from log reader
I20260812 06:17:04.765234 10995 log.cc:1079] T fdc3a6bf51e24184ad791417b3f69568 P c9769c5c7dc64561a4d4afb140afd606: Deleting log segment in path: /tmp/dist-test-taskQQcY3W/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515412339501-10539-0/minicluster-data/ts-0-root/wals/fdc3a6bf51e24184ad791417b3f69568/wal-000000028 (ops 133-137)
I20260812 06:17:04.765266 10995 log.cc:1079] T fdc3a6bf51e24184ad791417b3f69568 P c9769c5c7dc64561a4d4afb140afd606: Deleting log segment in path: /tmp/dist-test-taskQQcY3W/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515412339501-10539-0/minicluster-data/ts-0-root/wals/fdc3a6bf51e24184ad791417b3f69568/wal-000000029 (ops 138-142)
I20260812 06:17:04.765336 10995 log.cc:1079] T fdc3a6bf51e24184ad791417b3f69568 P c9769c5c7dc64561a4d4afb140afd606: Deleting log segment in path: /tmp/dist-test-taskQQcY3W/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515412339501-10539-0/minicluster-data/ts-0-root/wals/fdc3a6bf51e24184ad791417b3f69568/wal-000000030 (ops 143-147)
I20260812 06:17:04.765396 10995 log.cc:1079] T fdc3a6bf51e24184ad791417b3f69568 P c9769c5c7dc64561a4d4afb140afd606: Deleting log segment in path: /tmp/dist-test-taskQQcY3W/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515412339501-10539-0/minicluster-data/ts-0-root/wals/fdc3a6bf51e24184ad791417b3f69568/wal-000000031 (ops 148-152)
I20260812 06:17:04.765440 10995 log.cc:1079] T fdc3a6bf51e24184ad791417b3f69568 P c9769c5c7dc64561a4d4afb140afd606: Deleting log segment in path: /tmp/dist-test-taskQQcY3W/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515412339501-10539-0/minicluster-data/ts-0-root/wals/fdc3a6bf51e24184ad791417b3f69568/wal-000000032 (ops 153-157)
I20260812 06:17:04.765503 10995 log.cc:1079] T fdc3a6bf51e24184ad791417b3f69568 P c9769c5c7dc64561a4d4afb140afd606: Deleting log segment in path: /tmp/dist-test-taskQQcY3W/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515412339501-10539-0/minicluster-data/ts-0-root/wals/fdc3a6bf51e24184ad791417b3f69568/wal-000000033 (ops 158-162)
I20260812 06:17:04.765547 10995 log.cc:1079] T fdc3a6bf51e24184ad791417b3f69568 P c9769c5c7dc64561a4d4afb140afd606: Deleting log segment in path: /tmp/dist-test-taskQQcY3W/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515412339501-10539-0/minicluster-data/ts-0-root/wals/fdc3a6bf51e24184ad791417b3f69568/wal-000000034 (ops 163-167)
I20260812 06:17:04.765586 10995 log.cc:1079] T fdc3a6bf51e24184ad791417b3f69568 P c9769c5c7dc64561a4d4afb140afd606: Deleting log segment in path: /tmp/dist-test-taskQQcY3W/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515412339501-10539-0/minicluster-data/ts-0-root/wals/fdc3a6bf51e24184ad791417b3f69568/wal-000000035 (ops 168-172)
I20260812 06:17:04.765626 10995 log.cc:1079] T fdc3a6bf51e24184ad791417b3f69568 P c9769c5c7dc64561a4d4afb140afd606: Deleting log segment in path: /tmp/dist-test-taskQQcY3W/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515412339501-10539-0/minicluster-data/ts-0-root/wals/fdc3a6bf51e24184ad791417b3f69568/wal-000000036 (ops 173-176)
I20260812 06:17:04.765667 10995 log.cc:1079] T fdc3a6bf51e24184ad791417b3f69568 P c9769c5c7dc64561a4d4afb140afd606: Deleting log segment in path: /tmp/dist-test-taskQQcY3W/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515412339501-10539-0/minicluster-data/ts-0-root/wals/fdc3a6bf51e24184ad791417b3f69568/wal-000000037 (ops 177-181)
I20260812 06:17:04.765707 10995 log.cc:1079] T fdc3a6bf51e24184ad791417b3f69568 P c9769c5c7dc64561a4d4afb140afd606: Deleting log segment in path: /tmp/dist-test-taskQQcY3W/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515412339501-10539-0/minicluster-data/ts-0-root/wals/fdc3a6bf51e24184ad791417b3f69568/wal-000000038 (ops 182-186)
I20260812 06:17:04.765746 10995 log.cc:1079] T fdc3a6bf51e24184ad791417b3f69568 P c9769c5c7dc64561a4d4afb140afd606: Deleting log segment in path: /tmp/dist-test-taskQQcY3W/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515412339501-10539-0/minicluster-data/ts-0-root/wals/fdc3a6bf51e24184ad791417b3f69568/wal-000000039 (ops 187-191)
I20260812 06:17:04.793447 10995 maintenance_manager.cc:643] P c9769c5c7dc64561a4d4afb140afd606: LogGCOp(fdc3a6bf51e24184ad791417b3f69568) complete. Timing: real 0.028s	user 0.000s	sys 0.026s Metrics: {}
I20260812 06:17:04.794082 11099 maintenance_manager.cc:419] P c9769c5c7dc64561a4d4afb140afd606: Scheduling FlushDeltaMemStoresOp(fdc3a6bf51e24184ad791417b3f69568): perf score=2.188937
I20260812 06:17:04.820360 10995 maintenance_manager.cc:643] P c9769c5c7dc64561a4d4afb140afd606: FlushDeltaMemStoresOp(fdc3a6bf51e24184ad791417b3f69568) complete. Timing: real 0.026s	user 0.017s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":7501,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:04.820890 11099 maintenance_manager.cc:419] P c9769c5c7dc64561a4d4afb140afd606: Scheduling FlushDeltaMemStoresOp(fdc3a6bf51e24184ad791417b3f69568): perf score=2.188937
I20260812 06:17:04.832885 10995 maintenance_manager.cc:643] P c9769c5c7dc64561a4d4afb140afd606: FlushDeltaMemStoresOp(fdc3a6bf51e24184ad791417b3f69568) complete. Timing: real 0.012s	user 0.006s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4776,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:04.833493 11099 maintenance_manager.cc:419] P c9769c5c7dc64561a4d4afb140afd606: Scheduling UndoDeltaBlockGCOp(fdc3a6bf51e24184ad791417b3f69568): 473 bytes on disk
I20260812 06:17:04.834306 10995 maintenance_manager.cc:643] P c9769c5c7dc64561a4d4afb140afd606: UndoDeltaBlockGCOp(fdc3a6bf51e24184ad791417b3f69568) complete. Timing: real 0.001s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":121,"lbm_reads_lt_1ms":4}
I20260812 06:17:04.835645 11099 maintenance_manager.cc:419] P c9769c5c7dc64561a4d4afb140afd606: Scheduling MajorDeltaCompactionOp(fdc3a6bf51e24184ad791417b3f69568): perf score=1.000000
I20260812 06:17:04.984498 10539 heavy-update-compaction-itest.cc:229] Time spent updating: real 5.799s	user 2.133s	sys 0.208s
I20260812 06:17:05.028189 10995 maintenance_manager.cc:643] P c9769c5c7dc64561a4d4afb140afd606: MajorDeltaCompactionOp(fdc3a6bf51e24184ad791417b3f69568) complete. Timing: real 0.192s	user 0.161s	sys 0.030s Metrics: {"cfile_cache_miss":634,"cfile_cache_miss_bytes":28836376,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"lbm_read_time_us":14575,"lbm_reads_lt_1ms":670,"lbm_write_time_us":37512,"lbm_writes_lt_1ms":643,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":15360,"update_count":3000}
I20260812 06:17:05.028769 11099 maintenance_manager.cc:419] P c9769c5c7dc64561a4d4afb140afd606: Scheduling FlushDeltaMemStoresOp(fdc3a6bf51e24184ad791417b3f69568): perf score=10.126437
I20260812 06:17:05.066936 10995 maintenance_manager.cc:643] P c9769c5c7dc64561a4d4afb140afd606: FlushDeltaMemStoresOp(fdc3a6bf51e24184ad791417b3f69568) complete. Timing: real 0.038s	user 0.017s	sys 0.017s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":17156,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:17:05.067914 11099 maintenance_manager.cc:419] P c9769c5c7dc64561a4d4afb140afd606: Scheduling MajorDeltaCompactionOp(fdc3a6bf51e24184ad791417b3f69568): perf score=1.000000
I20260812 06:17:05.069473 10539 heavy-update-compaction-itest.cc:265] Time spent scanning: real 0.084s	user 0.002s	sys 0.000s
I20260812 06:17:05.070116 10539 tablet_server.cc:179] TabletServer@127.10.74.193:0 shutting down...
I20260812 06:17:05.180747 10995 maintenance_manager.cc:643] P c9769c5c7dc64561a4d4afb140afd606: MajorDeltaCompactionOp(fdc3a6bf51e24184ad791417b3f69568) complete. Timing: real 0.113s	user 0.074s	sys 0.037s Metrics: {"cfile_cache_miss":331,"cfile_cache_miss_bytes":16528781,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":1,"delta_iterators_relevant":1,"dirs.queue_time_us":952,"lbm_read_time_us":8049,"lbm_reads_lt_1ms":367,"lbm_write_time_us":19725,"lbm_writes_lt_1ms":343,"mutex_wait_us":420,"peak_mem_usage":38262756,"reinsert_count":0,"spinlock_wait_cycles":1280,"update_count":1500}
I20260812 06:17:05.181573 10539 ts_tablet_manager.cc:1507] Shutting down tablet manager...
I20260812 06:17:05.181946 10539 tablet_replica.cc:333] T fdc3a6bf51e24184ad791417b3f69568 P c9769c5c7dc64561a4d4afb140afd606: stopping tablet replica
I20260812 06:17:05.182194 10539 raft_consensus.cc:2243] T fdc3a6bf51e24184ad791417b3f69568 P c9769c5c7dc64561a4d4afb140afd606 [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:17:05.182435 10539 raft_consensus.cc:2272] T fdc3a6bf51e24184ad791417b3f69568 P c9769c5c7dc64561a4d4afb140afd606 [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:17:05.187124 10539 tablet_server.cc:196] TabletServer@127.10.74.193:0 shutdown complete.
I20260812 06:17:05.212531 10539 master.cc:562] Master@127.10.74.254:39727 shutting down...
I20260812 06:17:05.216044 10539 raft_consensus.cc:2243] T 00000000000000000000000000000000 P 3e0bf1d3d4294f79bc4cb49d4cec3ed8 [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:17:05.216302 10539 raft_consensus.cc:2272] T 00000000000000000000000000000000 P 3e0bf1d3d4294f79bc4cb49d4cec3ed8 [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:17:05.216372 10539 tablet_replica.cc:333] T 00000000000000000000000000000000 P 3e0bf1d3d4294f79bc4cb49d4cec3ed8: stopping tablet replica
I20260812 06:17:05.229112 10539 master.cc:584] Master@127.10.74.254:39727 shutdown complete.
[       OK ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/1 (6377 ms)
[----------] 2 tests from EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy (12971 ms total)

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