[==========] 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:20:16.235430 22919 internal_mini_cluster.cc:156] Creating distributed mini masters. Addrs: 127.22.97.254:40727
I20260812 06:20:16.236521 22919 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:20:16.237154 22919 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:20:16.243542 22929 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:20:16.243628 22919 server_base.cc:1061] running on GCE node
W20260812 06:20:16.243577 22930 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:20:16.243871 22932 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:20:16.244381 22919 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:20:16.244475 22919 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:20:16.244500 22919 hybrid_clock.cc:648] HybridClock initialized: now 1786515616244500 us; error 0 us; skew 500 ppm
I20260812 06:20:16.246301 22919 webserver.cc:533] Webserver started at http://127.22.97.254:33967/ using document root <none> and password file <none>
I20260812 06:20:16.246826 22919 fs_manager.cc:362] Metadata directory not provided
I20260812 06:20:16.246882 22919 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:20:16.247109 22919 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:20:16.249127 22919 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskdP7EeR/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515616224519-22919-0/minicluster-data/master-0-root/instance:
uuid: "27a404240c924b61b31551403395d507"
format_stamp: "Formatted at 2026-08-12 06:20:16 on dist-test-slave-7f01"
I20260812 06:20:16.252683 22919 fs_manager.cc:696] Time spent creating directory manager: real 0.003s	user 0.004s	sys 0.000s
I20260812 06:20:16.254719 22939 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:20:16.255826 22919 fs_manager.cc:730] Time spent opening block manager: real 0.002s	user 0.002s	sys 0.001s
I20260812 06:20:16.255972 22919 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskdP7EeR/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515616224519-22919-0/minicluster-data/master-0-root
uuid: "27a404240c924b61b31551403395d507"
format_stamp: "Formatted at 2026-08-12 06:20:16 on dist-test-slave-7f01"
I20260812 06:20:16.256078 22919 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskdP7EeR/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515616224519-22919-0/minicluster-data/master-0-root
metadata directory: /tmp/dist-test-taskdP7EeR/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515616224519-22919-0/minicluster-data/master-0-root
1 data directories: /tmp/dist-test-taskdP7EeR/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515616224519-22919-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:20:16.277427 22919 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:20:16.278079 22919 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:20:16.278263 22919 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:20:16.286749 23029 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.22.97.254:40727 every 8 connection(s)
I20260812 06:20:16.286749 22919 rpc_server.cc:307] RPC server started. Bound to: 127.22.97.254:40727
I20260812 06:20:16.289301 23030 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:20:16.295040 23030 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P 27a404240c924b61b31551403395d507: Bootstrap starting.
I20260812 06:20:16.297567 23030 tablet_bootstrap.cc:654] T 00000000000000000000000000000000 P 27a404240c924b61b31551403395d507: Neither blocks nor log segments found. Creating new log.
I20260812 06:20:16.298461 23030 log.cc:826] T 00000000000000000000000000000000 P 27a404240c924b61b31551403395d507: Log is configured to *not* fsync() on all Append() calls
I20260812 06:20:16.300148 23030 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P 27a404240c924b61b31551403395d507: No bootstrap required, opened a new log
I20260812 06:20:16.302821 23030 raft_consensus.cc:359] T 00000000000000000000000000000000 P 27a404240c924b61b31551403395d507 [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "27a404240c924b61b31551403395d507" member_type: VOTER }
I20260812 06:20:16.302991 23030 raft_consensus.cc:385] T 00000000000000000000000000000000 P 27a404240c924b61b31551403395d507 [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:20:16.303041 23030 raft_consensus.cc:740] T 00000000000000000000000000000000 P 27a404240c924b61b31551403395d507 [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: 27a404240c924b61b31551403395d507, State: Initialized, Role: FOLLOWER
I20260812 06:20:16.303593 23030 consensus_queue.cc:260] T 00000000000000000000000000000000 P 27a404240c924b61b31551403395d507 [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: "27a404240c924b61b31551403395d507" member_type: VOTER }
I20260812 06:20:16.303725 23030 raft_consensus.cc:399] T 00000000000000000000000000000000 P 27a404240c924b61b31551403395d507 [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:20:16.303850 23030 raft_consensus.cc:493] T 00000000000000000000000000000000 P 27a404240c924b61b31551403395d507 [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:20:16.303948 23030 raft_consensus.cc:3060] T 00000000000000000000000000000000 P 27a404240c924b61b31551403395d507 [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:20:16.304731 23030 raft_consensus.cc:515] T 00000000000000000000000000000000 P 27a404240c924b61b31551403395d507 [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "27a404240c924b61b31551403395d507" member_type: VOTER }
I20260812 06:20:16.305145 23030 leader_election.cc:304] T 00000000000000000000000000000000 P 27a404240c924b61b31551403395d507 [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: 27a404240c924b61b31551403395d507; no voters: 
I20260812 06:20:16.305409 23030 leader_election.cc:290] T 00000000000000000000000000000000 P 27a404240c924b61b31551403395d507 [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:20:16.305603 23037 raft_consensus.cc:2804] T 00000000000000000000000000000000 P 27a404240c924b61b31551403395d507 [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:20:16.305881 23037 raft_consensus.cc:697] T 00000000000000000000000000000000 P 27a404240c924b61b31551403395d507 [term 1 LEADER]: Becoming Leader. State: Replica: 27a404240c924b61b31551403395d507, State: Running, Role: LEADER
I20260812 06:20:16.306295 23037 consensus_queue.cc:237] T 00000000000000000000000000000000 P 27a404240c924b61b31551403395d507 [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: "27a404240c924b61b31551403395d507" member_type: VOTER }
I20260812 06:20:16.306519 23030 sys_catalog.cc:565] T 00000000000000000000000000000000 P 27a404240c924b61b31551403395d507 [sys.catalog]: configured and running, proceeding with master startup.
I20260812 06:20:16.308419 23041 sys_catalog.cc:455] T 00000000000000000000000000000000 P 27a404240c924b61b31551403395d507 [sys.catalog]: SysCatalogTable state changed. Reason: New leader 27a404240c924b61b31551403395d507. Latest consensus state: current_term: 1 leader_uuid: "27a404240c924b61b31551403395d507" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "27a404240c924b61b31551403395d507" member_type: VOTER } }
I20260812 06:20:16.308424 23039 sys_catalog.cc:455] T 00000000000000000000000000000000 P 27a404240c924b61b31551403395d507 [sys.catalog]: SysCatalogTable state changed. Reason: RaftConsensus started. Latest consensus state: current_term: 1 leader_uuid: "27a404240c924b61b31551403395d507" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "27a404240c924b61b31551403395d507" member_type: VOTER } }
I20260812 06:20:16.308568 23039 sys_catalog.cc:458] T 00000000000000000000000000000000 P 27a404240c924b61b31551403395d507 [sys.catalog]: This master's current role is: LEADER
I20260812 06:20:16.308568 23041 sys_catalog.cc:458] T 00000000000000000000000000000000 P 27a404240c924b61b31551403395d507 [sys.catalog]: This master's current role is: LEADER
I20260812 06:20:16.308950 23064 catalog_manager.cc:1511] Loading table and tablet metadata into memory...
I20260812 06:20:16.309087 22919 internal_mini_cluster.cc:184] Waiting to initialize catalog manager on master 0
I20260812 06:20:16.311589 23064 catalog_manager.cc:1520] Initializing Kudu cluster ID...
I20260812 06:20:16.316510 23064 catalog_manager.cc:1383] Generated new cluster ID: aa18ee867bff47e58b8f21ede934f846
I20260812 06:20:16.316613 23064 catalog_manager.cc:1531] Initializing Kudu internal certificate authority...
I20260812 06:20:16.338102 23064 catalog_manager.cc:1406] Generated new certificate authority record
I20260812 06:20:16.338946 23064 catalog_manager.cc:1540] Loading token signing keys...
I20260812 06:20:16.345924 23064 catalog_manager.cc:6092] T 00000000000000000000000000000000 P 27a404240c924b61b31551403395d507: Generated new TSK 0
I20260812 06:20:16.346527 23064 catalog_manager.cc:1550] Initializing in-progress tserver states...
I20260812 06:20:16.373997 22919 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:20:16.377115 23074 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:20:16.377269 23073 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:20:16.377379 23079 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:20:16.377560 22919 server_base.cc:1061] running on GCE node
I20260812 06:20:16.377717 22919 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:20:16.377763 22919 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:20:16.377787 22919 hybrid_clock.cc:648] HybridClock initialized: now 1786515616377787 us; error 0 us; skew 500 ppm
I20260812 06:20:16.378726 22919 webserver.cc:533] Webserver started at http://127.22.97.193:41071/ using document root <none> and password file <none>
I20260812 06:20:16.378901 22919 fs_manager.cc:362] Metadata directory not provided
I20260812 06:20:16.378965 22919 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:20:16.379036 22919 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:20:16.379468 22919 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskdP7EeR/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515616224519-22919-0/minicluster-data/ts-0-root/instance:
uuid: "a169b45d5a1a4211bc9e1f28b36a2a3a"
format_stamp: "Formatted at 2026-08-12 06:20:16 on dist-test-slave-7f01"
I20260812 06:20:16.381381 22919 fs_manager.cc:696] Time spent creating directory manager: real 0.002s	user 0.002s	sys 0.000s
I20260812 06:20:16.382480 23087 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:20:16.382814 22919 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.001s	sys 0.000s
I20260812 06:20:16.382880 22919 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskdP7EeR/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515616224519-22919-0/minicluster-data/ts-0-root
uuid: "a169b45d5a1a4211bc9e1f28b36a2a3a"
format_stamp: "Formatted at 2026-08-12 06:20:16 on dist-test-slave-7f01"
I20260812 06:20:16.382968 22919 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskdP7EeR/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515616224519-22919-0/minicluster-data/ts-0-root
metadata directory: /tmp/dist-test-taskdP7EeR/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515616224519-22919-0/minicluster-data/ts-0-root
1 data directories: /tmp/dist-test-taskdP7EeR/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515616224519-22919-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:20:16.393989 22919 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:20:16.394412 22919 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:20:16.394946 22919 txn_system_client.cc:432] TxnSystemClient initialization is disabled...
I20260812 06:20:16.395870 22919 ts_tablet_manager.cc:585] Loaded tablet metadata (0 total tablets, 0 live tablets)
I20260812 06:20:16.395927 22919 ts_tablet_manager.cc:531] Time spent load tablet metadata: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:20:16.395990 22919 ts_tablet_manager.cc:616] Registered 0 tablets
I20260812 06:20:16.396030 22919 ts_tablet_manager.cc:595] Time spent register tablets: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:20:16.402871 22919 rpc_server.cc:307] RPC server started. Bound to: 127.22.97.193:34829
I20260812 06:20:16.402935 23202 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.22.97.193:34829 every 8 connection(s)
I20260812 06:20:16.415311 23205 heartbeater.cc:344] Connected to a master server at 127.22.97.254:40727
I20260812 06:20:16.415575 23205 heartbeater.cc:461] Registering TS with master...
I20260812 06:20:16.416049 23205 heartbeater.cc:507] Master 127.22.97.254:40727 requested a full tablet report, sending...
I20260812 06:20:16.417474 22973 ts_manager.cc:194] Registered new tserver with Master: a169b45d5a1a4211bc9e1f28b36a2a3a (127.22.97.193:34829)
I20260812 06:20:16.418184 22919 internal_mini_cluster.cc:371] 1 TS(s) registered with all masters after 0.014674076s
I20260812 06:20:16.418704 22973 master_service.cc:502] Signed X509 certificate for tserver {username='slave'} at 127.0.0.1:50142
I20260812 06:20:16.427597 22973 catalog_manager.cc:2283] Servicing CreateTable request from {username='slave'} at 127.0.0.1:50144:
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:20:16.441574 23132 tablet_service.cc:1511] Processing CreateTablet for tablet 061aaf5bcf924900833957edc42cab04 (DEFAULT_TABLE table=heavy-update-compaction-test [id=3e5110f98f5346d0865ce2c597e91d7e]), partition=
I20260812 06:20:16.442049 23132 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet 061aaf5bcf924900833957edc42cab04. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:20:16.444916 23221 tablet_bootstrap.cc:492] T 061aaf5bcf924900833957edc42cab04 P a169b45d5a1a4211bc9e1f28b36a2a3a: Bootstrap starting.
I20260812 06:20:16.446201 23221 tablet_bootstrap.cc:654] T 061aaf5bcf924900833957edc42cab04 P a169b45d5a1a4211bc9e1f28b36a2a3a: Neither blocks nor log segments found. Creating new log.
I20260812 06:20:16.447444 23221 tablet_bootstrap.cc:492] T 061aaf5bcf924900833957edc42cab04 P a169b45d5a1a4211bc9e1f28b36a2a3a: No bootstrap required, opened a new log
I20260812 06:20:16.447556 23221 ts_tablet_manager.cc:1403] T 061aaf5bcf924900833957edc42cab04 P a169b45d5a1a4211bc9e1f28b36a2a3a: Time spent bootstrapping tablet: real 0.003s	user 0.002s	sys 0.000s
I20260812 06:20:16.448050 23221 raft_consensus.cc:359] T 061aaf5bcf924900833957edc42cab04 P a169b45d5a1a4211bc9e1f28b36a2a3a [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "a169b45d5a1a4211bc9e1f28b36a2a3a" member_type: VOTER last_known_addr { host: "127.22.97.193" port: 34829 } }
I20260812 06:20:16.448148 23221 raft_consensus.cc:385] T 061aaf5bcf924900833957edc42cab04 P a169b45d5a1a4211bc9e1f28b36a2a3a [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:20:16.448171 23221 raft_consensus.cc:740] T 061aaf5bcf924900833957edc42cab04 P a169b45d5a1a4211bc9e1f28b36a2a3a [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: a169b45d5a1a4211bc9e1f28b36a2a3a, State: Initialized, Role: FOLLOWER
I20260812 06:20:16.448328 23221 consensus_queue.cc:260] T 061aaf5bcf924900833957edc42cab04 P a169b45d5a1a4211bc9e1f28b36a2a3a [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: "a169b45d5a1a4211bc9e1f28b36a2a3a" member_type: VOTER last_known_addr { host: "127.22.97.193" port: 34829 } }
I20260812 06:20:16.448453 23221 raft_consensus.cc:399] T 061aaf5bcf924900833957edc42cab04 P a169b45d5a1a4211bc9e1f28b36a2a3a [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:20:16.448542 23221 raft_consensus.cc:493] T 061aaf5bcf924900833957edc42cab04 P a169b45d5a1a4211bc9e1f28b36a2a3a [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:20:16.448608 23221 raft_consensus.cc:3060] T 061aaf5bcf924900833957edc42cab04 P a169b45d5a1a4211bc9e1f28b36a2a3a [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:20:16.449606 23221 raft_consensus.cc:515] T 061aaf5bcf924900833957edc42cab04 P a169b45d5a1a4211bc9e1f28b36a2a3a [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "a169b45d5a1a4211bc9e1f28b36a2a3a" member_type: VOTER last_known_addr { host: "127.22.97.193" port: 34829 } }
I20260812 06:20:16.449750 23221 leader_election.cc:304] T 061aaf5bcf924900833957edc42cab04 P a169b45d5a1a4211bc9e1f28b36a2a3a [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: a169b45d5a1a4211bc9e1f28b36a2a3a; no voters: 
I20260812 06:20:16.449993 23221 leader_election.cc:290] T 061aaf5bcf924900833957edc42cab04 P a169b45d5a1a4211bc9e1f28b36a2a3a [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:20:16.450091 23223 raft_consensus.cc:2804] T 061aaf5bcf924900833957edc42cab04 P a169b45d5a1a4211bc9e1f28b36a2a3a [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:20:16.450277 23223 raft_consensus.cc:697] T 061aaf5bcf924900833957edc42cab04 P a169b45d5a1a4211bc9e1f28b36a2a3a [term 1 LEADER]: Becoming Leader. State: Replica: a169b45d5a1a4211bc9e1f28b36a2a3a, State: Running, Role: LEADER
I20260812 06:20:16.450424 23221 ts_tablet_manager.cc:1434] T 061aaf5bcf924900833957edc42cab04 P a169b45d5a1a4211bc9e1f28b36a2a3a: Time spent starting tablet: real 0.003s	user 0.000s	sys 0.003s
I20260812 06:20:16.450489 23223 consensus_queue.cc:237] T 061aaf5bcf924900833957edc42cab04 P a169b45d5a1a4211bc9e1f28b36a2a3a [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: "a169b45d5a1a4211bc9e1f28b36a2a3a" member_type: VOTER last_known_addr { host: "127.22.97.193" port: 34829 } }
I20260812 06:20:16.450690 23205 heartbeater.cc:499] Master 127.22.97.254:40727 was elected leader, sending a full tablet report...
I20260812 06:20:16.453451 22973 catalog_manager.cc:5719] T 061aaf5bcf924900833957edc42cab04 P a169b45d5a1a4211bc9e1f28b36a2a3a reported cstate change: term changed from 0 to 1, leader changed from <none> to a169b45d5a1a4211bc9e1f28b36a2a3a (127.22.97.193). New cstate: current_term: 1 leader_uuid: "a169b45d5a1a4211bc9e1f28b36a2a3a" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "a169b45d5a1a4211bc9e1f28b36a2a3a" member_type: VOTER last_known_addr { host: "127.22.97.193" port: 34829 } health_report { overall_health: HEALTHY } } }
I20260812 06:20:16.527248 22919 heavy-update-compaction-itest.cc:215] Time spent inserting: real 0.065s	user 0.026s	sys 0.007s
I20260812 06:20:16.654174 23206 maintenance_manager.cc:419] P a169b45d5a1a4211bc9e1f28b36a2a3a: Scheduling FlushMRSOp(061aaf5bcf924900833957edc42cab04): perf score=15.086190
I20260812 06:20:16.780900 23097 maintenance_manager.cc:643] P a169b45d5a1a4211bc9e1f28b36a2a3a: FlushMRSOp(061aaf5bcf924900833957edc42cab04) complete. Timing: real 0.126s	user 0.093s	sys 0.032s Metrics: {"bytes_written":8205078,"cfile_init":1,"compiler_manager_pool.queue_time_us":217,"delete_count":0,"dirs.queue_time_us":106,"dirs.run_cpu_time_us":206,"dirs.run_wall_time_us":792,"drs_written":1,"lbm_read_time_us":52,"lbm_reads_lt_1ms":4,"lbm_write_time_us":29780,"lbm_writes_lt_1ms":567,"peak_mem_usage":0,"reinsert_count":0,"rows_written":104,"thread_start_us":131,"threads_started":1,"update_count":1000}
I20260812 06:20:16.781948 23206 maintenance_manager.cc:419] P a169b45d5a1a4211bc9e1f28b36a2a3a: Scheduling LogGCOp(061aaf5bcf924900833957edc42cab04): free 20743880 bytes of WAL
I20260812 06:20:16.782259 23097 log_reader.cc:385] T 061aaf5bcf924900833957edc42cab04: removed 2 log segments from log reader
I20260812 06:20:16.782341 23097 log.cc:1079] T 061aaf5bcf924900833957edc42cab04 P a169b45d5a1a4211bc9e1f28b36a2a3a: Deleting log segment in path: /tmp/dist-test-taskdP7EeR/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515616224519-22919-0/minicluster-data/ts-0-root/wals/061aaf5bcf924900833957edc42cab04/wal-000000001 (ops 1-6)
I20260812 06:20:16.782451 23097 log.cc:1079] T 061aaf5bcf924900833957edc42cab04 P a169b45d5a1a4211bc9e1f28b36a2a3a: Deleting log segment in path: /tmp/dist-test-taskdP7EeR/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515616224519-22919-0/minicluster-data/ts-0-root/wals/061aaf5bcf924900833957edc42cab04/wal-000000002 (ops 7-11)
I20260812 06:20:16.787154 23097 maintenance_manager.cc:643] P a169b45d5a1a4211bc9e1f28b36a2a3a: LogGCOp(061aaf5bcf924900833957edc42cab04) complete. Timing: real 0.005s	user 0.000s	sys 0.002s Metrics: {}
I20260812 06:20:16.787616 23206 maintenance_manager.cc:419] P a169b45d5a1a4211bc9e1f28b36a2a3a: Scheduling UndoDeltaBlockGCOp(061aaf5bcf924900833957edc42cab04): 12719216 bytes on disk
I20260812 06:20:16.788200 23097 maintenance_manager.cc:643] P a169b45d5a1a4211bc9e1f28b36a2a3a: UndoDeltaBlockGCOp(061aaf5bcf924900833957edc42cab04) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":51,"lbm_reads_lt_1ms":4}
I20260812 06:20:16.788594 23206 maintenance_manager.cc:419] P a169b45d5a1a4211bc9e1f28b36a2a3a: Scheduling FlushDeltaMemStoresOp(061aaf5bcf924900833957edc42cab04): perf score=2.188937
I20260812 06:20:16.805279 23097 maintenance_manager.cc:643] P a169b45d5a1a4211bc9e1f28b36a2a3a: FlushDeltaMemStoresOp(061aaf5bcf924900833957edc42cab04) complete. Timing: real 0.017s	user 0.009s	sys 0.004s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":5782,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:20:16.805822 23206 maintenance_manager.cc:419] P a169b45d5a1a4211bc9e1f28b36a2a3a: Scheduling MajorDeltaCompactionOp(061aaf5bcf924900833957edc42cab04): perf score=1.000000
I20260812 06:20:16.916184 23097 maintenance_manager.cc:643] P a169b45d5a1a4211bc9e1f28b36a2a3a: MajorDeltaCompactionOp(061aaf5bcf924900833957edc42cab04) complete. Timing: real 0.110s	user 0.086s	sys 0.024s Metrics: {"cfile_cache_miss":322,"cfile_cache_miss_bytes":16159611,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":411,"lbm_read_time_us":6342,"lbm_reads_lt_1ms":354,"lbm_write_time_us":20446,"lbm_writes_lt_1ms":333,"peak_mem_usage":36812022,"reinsert_count":0,"spinlock_wait_cycles":1536,"thread_start_us":501,"threads_started":5,"update_count":1450}
I20260812 06:20:16.916785 23206 maintenance_manager.cc:419] P a169b45d5a1a4211bc9e1f28b36a2a3a: Scheduling FlushDeltaMemStoresOp(061aaf5bcf924900833957edc42cab04): perf score=7.149875
I20260812 06:20:16.954360 23097 maintenance_manager.cc:643] P a169b45d5a1a4211bc9e1f28b36a2a3a: FlushDeltaMemStoresOp(061aaf5bcf924900833957edc42cab04) complete. Timing: real 0.037s	user 0.016s	sys 0.007s Metrics: {"bytes_written":8574299,"delete_count":0,"lbm_write_time_us":10599,"lbm_writes_lt_1ms":212,"reinsert_count":0,"update_count":1045}
I20260812 06:20:16.954931 23206 maintenance_manager.cc:419] P a169b45d5a1a4211bc9e1f28b36a2a3a: Scheduling FlushDeltaMemStoresOp(061aaf5bcf924900833957edc42cab04): perf score=2.188937
I20260812 06:20:16.965565 23097 maintenance_manager.cc:643] P a169b45d5a1a4211bc9e1f28b36a2a3a: FlushDeltaMemStoresOp(061aaf5bcf924900833957edc42cab04) complete. Timing: real 0.010s	user 0.005s	sys 0.004s Metrics: {"bytes_written":3733434,"delete_count":0,"lbm_write_time_us":4122,"lbm_writes_lt_1ms":94,"reinsert_count":0,"update_count":455}
I20260812 06:20:16.965997 23206 maintenance_manager.cc:419] P a169b45d5a1a4211bc9e1f28b36a2a3a: Scheduling MajorDeltaCompactionOp(061aaf5bcf924900833957edc42cab04): perf score=1.000000
I20260812 06:20:17.097671 23097 maintenance_manager.cc:643] P a169b45d5a1a4211bc9e1f28b36a2a3a: MajorDeltaCompactionOp(061aaf5bcf924900833957edc42cab04) complete. Timing: real 0.131s	user 0.104s	sys 0.016s Metrics: {"cfile_cache_miss":332,"cfile_cache_miss_bytes":16569861,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":208,"lbm_read_time_us":8274,"lbm_reads_lt_1ms":372,"lbm_write_time_us":23340,"lbm_writes_lt_1ms":343,"mutex_wait_us":20,"peak_mem_usage":38262756,"reinsert_count":0,"spinlock_wait_cycles":6912,"update_count":1500}
I20260812 06:20:17.098245 23206 maintenance_manager.cc:419] P a169b45d5a1a4211bc9e1f28b36a2a3a: Scheduling FlushDeltaMemStoresOp(061aaf5bcf924900833957edc42cab04): perf score=10.126437
I20260812 06:20:17.144097 23097 maintenance_manager.cc:643] P a169b45d5a1a4211bc9e1f28b36a2a3a: FlushDeltaMemStoresOp(061aaf5bcf924900833957edc42cab04) complete. Timing: real 0.046s	user 0.020s	sys 0.020s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":19304,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":302,"reinsert_count":0,"update_count":1500}
I20260812 06:20:17.144639 23206 maintenance_manager.cc:419] P a169b45d5a1a4211bc9e1f28b36a2a3a: Scheduling FlushDeltaMemStoresOp(061aaf5bcf924900833957edc42cab04): perf score=2.188937
I20260812 06:20:17.160065 23097 maintenance_manager.cc:643] P a169b45d5a1a4211bc9e1f28b36a2a3a: FlushDeltaMemStoresOp(061aaf5bcf924900833957edc42cab04) complete. Timing: real 0.015s	user 0.015s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5723,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:17.160576 23206 maintenance_manager.cc:419] P a169b45d5a1a4211bc9e1f28b36a2a3a: Scheduling MajorDeltaCompactionOp(061aaf5bcf924900833957edc42cab04): perf score=1.000000
I20260812 06:20:17.303328 23097 maintenance_manager.cc:643] P a169b45d5a1a4211bc9e1f28b36a2a3a: MajorDeltaCompactionOp(061aaf5bcf924900833957edc42cab04) complete. Timing: real 0.143s	user 0.100s	sys 0.040s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672277,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":487,"lbm_read_time_us":9384,"lbm_reads_lt_1ms":472,"lbm_write_time_us":28018,"lbm_writes_lt_1ms":443,"mutex_wait_us":18,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":9472,"update_count":2000}
I20260812 06:20:17.304109 23206 maintenance_manager.cc:419] P a169b45d5a1a4211bc9e1f28b36a2a3a: Scheduling FlushDeltaMemStoresOp(061aaf5bcf924900833957edc42cab04): perf score=10.126437
I20260812 06:20:17.340345 23097 maintenance_manager.cc:643] P a169b45d5a1a4211bc9e1f28b36a2a3a: FlushDeltaMemStoresOp(061aaf5bcf924900833957edc42cab04) complete. Timing: real 0.036s	user 0.023s	sys 0.012s Metrics: {"bytes_written":12307494,"delete_count":0,"lbm_write_time_us":15729,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:20:17.340811 23206 maintenance_manager.cc:419] P a169b45d5a1a4211bc9e1f28b36a2a3a: Scheduling MajorDeltaCompactionOp(061aaf5bcf924900833957edc42cab04): perf score=1.000000
I20260812 06:20:17.463219 23097 maintenance_manager.cc:643] P a169b45d5a1a4211bc9e1f28b36a2a3a: MajorDeltaCompactionOp(061aaf5bcf924900833957edc42cab04) complete. Timing: real 0.122s	user 0.074s	sys 0.048s Metrics: {"cfile_cache_miss":331,"cfile_cache_miss_bytes":16569750,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":1,"delta_iterators_relevant":1,"dirs.queue_time_us":285,"lbm_read_time_us":6426,"lbm_reads_lt_1ms":363,"lbm_write_time_us":22099,"lbm_writes_lt_1ms":343,"mutex_wait_us":40,"peak_mem_usage":38262756,"reinsert_count":0,"spinlock_wait_cycles":49024,"update_count":1500}
I20260812 06:20:17.463898 23206 maintenance_manager.cc:419] P a169b45d5a1a4211bc9e1f28b36a2a3a: Scheduling FlushDeltaMemStoresOp(061aaf5bcf924900833957edc42cab04): perf score=10.126437
I20260812 06:20:17.498142 23097 maintenance_manager.cc:643] P a169b45d5a1a4211bc9e1f28b36a2a3a: FlushDeltaMemStoresOp(061aaf5bcf924900833957edc42cab04) complete. Timing: real 0.034s	user 0.015s	sys 0.017s Metrics: {"bytes_written":12307493,"delete_count":0,"lbm_write_time_us":15034,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:20:17.498596 23206 maintenance_manager.cc:419] P a169b45d5a1a4211bc9e1f28b36a2a3a: Scheduling MajorDeltaCompactionOp(061aaf5bcf924900833957edc42cab04): perf score=1.000000
I20260812 06:20:17.634057 23097 maintenance_manager.cc:643] P a169b45d5a1a4211bc9e1f28b36a2a3a: MajorDeltaCompactionOp(061aaf5bcf924900833957edc42cab04) complete. Timing: real 0.135s	user 0.097s	sys 0.027s Metrics: {"cfile_cache_miss":331,"cfile_cache_miss_bytes":16569749,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":1,"delta_iterators_relevant":1,"dirs.queue_time_us":623,"lbm_read_time_us":9848,"lbm_reads_lt_1ms":363,"lbm_write_time_us":21257,"lbm_writes_lt_1ms":343,"peak_mem_usage":38262756,"reinsert_count":0,"spinlock_wait_cycles":768,"update_count":1500}
I20260812 06:20:17.634609 23206 maintenance_manager.cc:419] P a169b45d5a1a4211bc9e1f28b36a2a3a: Scheduling FlushDeltaMemStoresOp(061aaf5bcf924900833957edc42cab04): perf score=10.126437
I20260812 06:20:17.680855 23097 maintenance_manager.cc:643] P a169b45d5a1a4211bc9e1f28b36a2a3a: FlushDeltaMemStoresOp(061aaf5bcf924900833957edc42cab04) complete. Timing: real 0.046s	user 0.023s	sys 0.012s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":15897,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:20:17.681389 23206 maintenance_manager.cc:419] P a169b45d5a1a4211bc9e1f28b36a2a3a: Scheduling FlushDeltaMemStoresOp(061aaf5bcf924900833957edc42cab04): perf score=2.188937
I20260812 06:20:17.692739 23097 maintenance_manager.cc:643] P a169b45d5a1a4211bc9e1f28b36a2a3a: FlushDeltaMemStoresOp(061aaf5bcf924900833957edc42cab04) complete. Timing: real 0.011s	user 0.006s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4424,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:17.693382 23206 maintenance_manager.cc:419] P a169b45d5a1a4211bc9e1f28b36a2a3a: Scheduling MajorDeltaCompactionOp(061aaf5bcf924900833957edc42cab04): perf score=1.000000
I20260812 06:20:17.827471 23097 maintenance_manager.cc:643] P a169b45d5a1a4211bc9e1f28b36a2a3a: MajorDeltaCompactionOp(061aaf5bcf924900833957edc42cab04) complete. Timing: real 0.133s	user 0.089s	sys 0.044s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672277,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":223,"lbm_read_time_us":10204,"lbm_reads_lt_1ms":472,"lbm_write_time_us":25835,"lbm_writes_lt_1ms":443,"mutex_wait_us":47,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":60544,"update_count":2000}
I20260812 06:20:17.828222 23206 maintenance_manager.cc:419] P a169b45d5a1a4211bc9e1f28b36a2a3a: Scheduling FlushDeltaMemStoresOp(061aaf5bcf924900833957edc42cab04): perf score=10.126437
I20260812 06:20:17.877038 23097 maintenance_manager.cc:643] P a169b45d5a1a4211bc9e1f28b36a2a3a: FlushDeltaMemStoresOp(061aaf5bcf924900833957edc42cab04) complete. Timing: real 0.049s	user 0.028s	sys 0.011s Metrics: {"bytes_written":12307489,"delete_count":0,"lbm_write_time_us":17645,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:20:17.877720 23206 maintenance_manager.cc:419] P a169b45d5a1a4211bc9e1f28b36a2a3a: Scheduling FlushDeltaMemStoresOp(061aaf5bcf924900833957edc42cab04): perf score=2.188937
I20260812 06:20:17.891867 23097 maintenance_manager.cc:643] P a169b45d5a1a4211bc9e1f28b36a2a3a: FlushDeltaMemStoresOp(061aaf5bcf924900833957edc42cab04) complete. Timing: real 0.014s	user 0.006s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5603,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:17.892490 23206 maintenance_manager.cc:419] P a169b45d5a1a4211bc9e1f28b36a2a3a: Scheduling MajorDeltaCompactionOp(061aaf5bcf924900833957edc42cab04): perf score=1.000000
I20260812 06:20:18.015372 23097 maintenance_manager.cc:643] P a169b45d5a1a4211bc9e1f28b36a2a3a: MajorDeltaCompactionOp(061aaf5bcf924900833957edc42cab04) complete. Timing: real 0.123s	user 0.094s	sys 0.028s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672276,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":727,"lbm_read_time_us":8387,"lbm_reads_lt_1ms":472,"lbm_write_time_us":24109,"lbm_writes_lt_1ms":443,"mutex_wait_us":46,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":768,"update_count":2000}
I20260812 06:20:18.016173 23206 maintenance_manager.cc:419] P a169b45d5a1a4211bc9e1f28b36a2a3a: Scheduling FlushDeltaMemStoresOp(061aaf5bcf924900833957edc42cab04): perf score=10.126437
I20260812 06:20:18.066831 23097 maintenance_manager.cc:643] P a169b45d5a1a4211bc9e1f28b36a2a3a: FlushDeltaMemStoresOp(061aaf5bcf924900833957edc42cab04) complete. Timing: real 0.050s	user 0.017s	sys 0.027s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":16038,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:20:18.067448 23206 maintenance_manager.cc:419] P a169b45d5a1a4211bc9e1f28b36a2a3a: Scheduling FlushDeltaMemStoresOp(061aaf5bcf924900833957edc42cab04): perf score=2.188937
I20260812 06:20:18.079015 23097 maintenance_manager.cc:643] P a169b45d5a1a4211bc9e1f28b36a2a3a: FlushDeltaMemStoresOp(061aaf5bcf924900833957edc42cab04) complete. Timing: real 0.011s	user 0.006s	sys 0.003s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4644,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:18.079491 23206 maintenance_manager.cc:419] P a169b45d5a1a4211bc9e1f28b36a2a3a: Scheduling MajorDeltaCompactionOp(061aaf5bcf924900833957edc42cab04): perf score=1.000000
I20260812 06:20:18.240953 23097 maintenance_manager.cc:643] P a169b45d5a1a4211bc9e1f28b36a2a3a: MajorDeltaCompactionOp(061aaf5bcf924900833957edc42cab04) complete. Timing: real 0.161s	user 0.117s	sys 0.043s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672277,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":640,"lbm_read_time_us":11084,"lbm_reads_lt_1ms":472,"lbm_write_time_us":27385,"lbm_writes_lt_1ms":443,"mutex_wait_us":290,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":10624,"update_count":2000}
I20260812 06:20:18.241503 23206 maintenance_manager.cc:419] P a169b45d5a1a4211bc9e1f28b36a2a3a: Scheduling FlushDeltaMemStoresOp(061aaf5bcf924900833957edc42cab04): perf score=10.126437
I20260812 06:20:18.288717 23097 maintenance_manager.cc:643] P a169b45d5a1a4211bc9e1f28b36a2a3a: FlushDeltaMemStoresOp(061aaf5bcf924900833957edc42cab04) complete. Timing: real 0.047s	user 0.030s	sys 0.007s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":16989,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:20:18.289218 23206 maintenance_manager.cc:419] P a169b45d5a1a4211bc9e1f28b36a2a3a: Scheduling FlushDeltaMemStoresOp(061aaf5bcf924900833957edc42cab04): perf score=2.188937
I20260812 06:20:18.300203 23097 maintenance_manager.cc:643] P a169b45d5a1a4211bc9e1f28b36a2a3a: FlushDeltaMemStoresOp(061aaf5bcf924900833957edc42cab04) complete. Timing: real 0.011s	user 0.010s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4232,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:18.300730 23206 maintenance_manager.cc:419] P a169b45d5a1a4211bc9e1f28b36a2a3a: Scheduling FlushMRSOp(061aaf5bcf924900833957edc42cab04): perf score=1.000000
I20260812 06:20:18.335090 23097 maintenance_manager.cc:643] P a169b45d5a1a4211bc9e1f28b36a2a3a: FlushMRSOp(061aaf5bcf924900833957edc42cab04) complete. Timing: real 0.034s	user 0.033s	sys 0.000s Metrics: {"bytes_written":1275443,"cfile_init":1,"dirs.queue_time_us":59,"dirs.run_cpu_time_us":247,"dirs.run_wall_time_us":1296,"drs_written":1,"lbm_read_time_us":35,"lbm_reads_lt_1ms":4,"lbm_write_time_us":2063,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":31}
I20260812 06:20:18.336043 23206 maintenance_manager.cc:419] P a169b45d5a1a4211bc9e1f28b36a2a3a: Scheduling LogGCOp(061aaf5bcf924900833957edc42cab04): free 121006435 bytes of WAL
I20260812 06:20:18.336274 23097 log_reader.cc:385] T 061aaf5bcf924900833957edc42cab04: removed 12 log segments from log reader
I20260812 06:20:18.336320 23097 log.cc:1079] T 061aaf5bcf924900833957edc42cab04 P a169b45d5a1a4211bc9e1f28b36a2a3a: Deleting log segment in path: /tmp/dist-test-taskdP7EeR/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515616224519-22919-0/minicluster-data/ts-0-root/wals/061aaf5bcf924900833957edc42cab04/wal-000000003 (ops 12-16)
I20260812 06:20:18.336349 23097 log.cc:1079] T 061aaf5bcf924900833957edc42cab04 P a169b45d5a1a4211bc9e1f28b36a2a3a: Deleting log segment in path: /tmp/dist-test-taskdP7EeR/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515616224519-22919-0/minicluster-data/ts-0-root/wals/061aaf5bcf924900833957edc42cab04/wal-000000004 (ops 17-21)
I20260812 06:20:18.336416 23097 log.cc:1079] T 061aaf5bcf924900833957edc42cab04 P a169b45d5a1a4211bc9e1f28b36a2a3a: Deleting log segment in path: /tmp/dist-test-taskdP7EeR/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515616224519-22919-0/minicluster-data/ts-0-root/wals/061aaf5bcf924900833957edc42cab04/wal-000000005 (ops 22-26)
I20260812 06:20:18.336447 23097 log.cc:1079] T 061aaf5bcf924900833957edc42cab04 P a169b45d5a1a4211bc9e1f28b36a2a3a: Deleting log segment in path: /tmp/dist-test-taskdP7EeR/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515616224519-22919-0/minicluster-data/ts-0-root/wals/061aaf5bcf924900833957edc42cab04/wal-000000006 (ops 27-31)
I20260812 06:20:18.336488 23097 log.cc:1079] T 061aaf5bcf924900833957edc42cab04 P a169b45d5a1a4211bc9e1f28b36a2a3a: Deleting log segment in path: /tmp/dist-test-taskdP7EeR/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515616224519-22919-0/minicluster-data/ts-0-root/wals/061aaf5bcf924900833957edc42cab04/wal-000000007 (ops 32-36)
I20260812 06:20:18.336529 23097 log.cc:1079] T 061aaf5bcf924900833957edc42cab04 P a169b45d5a1a4211bc9e1f28b36a2a3a: Deleting log segment in path: /tmp/dist-test-taskdP7EeR/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515616224519-22919-0/minicluster-data/ts-0-root/wals/061aaf5bcf924900833957edc42cab04/wal-000000008 (ops 37-40)
I20260812 06:20:18.336570 23097 log.cc:1079] T 061aaf5bcf924900833957edc42cab04 P a169b45d5a1a4211bc9e1f28b36a2a3a: Deleting log segment in path: /tmp/dist-test-taskdP7EeR/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515616224519-22919-0/minicluster-data/ts-0-root/wals/061aaf5bcf924900833957edc42cab04/wal-000000009 (ops 41-45)
I20260812 06:20:18.336609 23097 log.cc:1079] T 061aaf5bcf924900833957edc42cab04 P a169b45d5a1a4211bc9e1f28b36a2a3a: Deleting log segment in path: /tmp/dist-test-taskdP7EeR/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515616224519-22919-0/minicluster-data/ts-0-root/wals/061aaf5bcf924900833957edc42cab04/wal-000000010 (ops 46-50)
I20260812 06:20:18.336648 23097 log.cc:1079] T 061aaf5bcf924900833957edc42cab04 P a169b45d5a1a4211bc9e1f28b36a2a3a: Deleting log segment in path: /tmp/dist-test-taskdP7EeR/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515616224519-22919-0/minicluster-data/ts-0-root/wals/061aaf5bcf924900833957edc42cab04/wal-000000011 (ops 51-55)
I20260812 06:20:18.336688 23097 log.cc:1079] T 061aaf5bcf924900833957edc42cab04 P a169b45d5a1a4211bc9e1f28b36a2a3a: Deleting log segment in path: /tmp/dist-test-taskdP7EeR/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515616224519-22919-0/minicluster-data/ts-0-root/wals/061aaf5bcf924900833957edc42cab04/wal-000000012 (ops 56-60)
I20260812 06:20:18.336727 23097 log.cc:1079] T 061aaf5bcf924900833957edc42cab04 P a169b45d5a1a4211bc9e1f28b36a2a3a: Deleting log segment in path: /tmp/dist-test-taskdP7EeR/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515616224519-22919-0/minicluster-data/ts-0-root/wals/061aaf5bcf924900833957edc42cab04/wal-000000013 (ops 61-65)
I20260812 06:20:18.336767 23097 log.cc:1079] T 061aaf5bcf924900833957edc42cab04 P a169b45d5a1a4211bc9e1f28b36a2a3a: Deleting log segment in path: /tmp/dist-test-taskdP7EeR/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515616224519-22919-0/minicluster-data/ts-0-root/wals/061aaf5bcf924900833957edc42cab04/wal-000000014 (ops 66-70)
I20260812 06:20:18.364215 23097 maintenance_manager.cc:643] P a169b45d5a1a4211bc9e1f28b36a2a3a: LogGCOp(061aaf5bcf924900833957edc42cab04) complete. Timing: real 0.028s	user 0.000s	sys 0.028s Metrics: {}
I20260812 06:20:18.364609 23206 maintenance_manager.cc:419] P a169b45d5a1a4211bc9e1f28b36a2a3a: Scheduling FlushDeltaMemStoresOp(061aaf5bcf924900833957edc42cab04): perf score=4.173312
I20260812 06:20:18.386463 23097 maintenance_manager.cc:643] P a169b45d5a1a4211bc9e1f28b36a2a3a: FlushDeltaMemStoresOp(061aaf5bcf924900833957edc42cab04) complete. Timing: real 0.022s	user 0.008s	sys 0.011s Metrics: {"bytes_written":5374417,"delete_count":0,"lbm_write_time_us":5796,"lbm_writes_lt_1ms":134,"reinsert_count":0,"update_count":655}
I20260812 06:20:18.387055 23206 maintenance_manager.cc:419] P a169b45d5a1a4211bc9e1f28b36a2a3a: Scheduling FlushDeltaMemStoresOp(061aaf5bcf924900833957edc42cab04): perf score=1.196750
I20260812 06:20:18.395509 23097 maintenance_manager.cc:643] P a169b45d5a1a4211bc9e1f28b36a2a3a: FlushDeltaMemStoresOp(061aaf5bcf924900833957edc42cab04) complete. Timing: real 0.008s	user 0.003s	sys 0.004s Metrics: {"bytes_written":2830880,"delete_count":0,"lbm_write_time_us":3267,"lbm_writes_lt_1ms":72,"reinsert_count":0,"update_count":345}
I20260812 06:20:18.395963 23206 maintenance_manager.cc:419] P a169b45d5a1a4211bc9e1f28b36a2a3a: Scheduling UndoDeltaBlockGCOp(061aaf5bcf924900833957edc42cab04): 481 bytes on disk
I20260812 06:20:18.396387 23097 maintenance_manager.cc:643] P a169b45d5a1a4211bc9e1f28b36a2a3a: UndoDeltaBlockGCOp(061aaf5bcf924900833957edc42cab04) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":51,"lbm_reads_lt_1ms":4}
I20260812 06:20:18.396845 23206 maintenance_manager.cc:419] P a169b45d5a1a4211bc9e1f28b36a2a3a: Scheduling MajorDeltaCompactionOp(061aaf5bcf924900833957edc42cab04): perf score=1.000000
I20260812 06:20:18.615473 23097 maintenance_manager.cc:643] P a169b45d5a1a4211bc9e1f28b36a2a3a: MajorDeltaCompactionOp(061aaf5bcf924900833957edc42cab04) complete. Timing: real 0.218s	user 0.137s	sys 0.068s Metrics: {"cfile_cache_miss":634,"cfile_cache_miss_bytes":28877312,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":278,"lbm_read_time_us":14758,"lbm_reads_lt_1ms":674,"lbm_write_time_us":38440,"lbm_writes_lt_1ms":643,"mutex_wait_us":85,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":1280,"thread_start_us":81,"threads_started":1,"update_count":3000}
I20260812 06:20:18.616890 23206 maintenance_manager.cc:419] P a169b45d5a1a4211bc9e1f28b36a2a3a: Scheduling FlushDeltaMemStoresOp(061aaf5bcf924900833957edc42cab04): perf score=14.095187
I20260812 06:20:18.680933 23097 maintenance_manager.cc:643] P a169b45d5a1a4211bc9e1f28b36a2a3a: FlushDeltaMemStoresOp(061aaf5bcf924900833957edc42cab04) complete. Timing: real 0.064s	user 0.012s	sys 0.050s Metrics: {"bytes_written":16409905,"delete_count":0,"lbm_write_time_us":21601,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:20:18.681646 23206 maintenance_manager.cc:419] P a169b45d5a1a4211bc9e1f28b36a2a3a: Scheduling FlushDeltaMemStoresOp(061aaf5bcf924900833957edc42cab04): perf score=2.188937
I20260812 06:20:18.693015 23097 maintenance_manager.cc:643] P a169b45d5a1a4211bc9e1f28b36a2a3a: FlushDeltaMemStoresOp(061aaf5bcf924900833957edc42cab04) complete. Timing: real 0.011s	user 0.009s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4346,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:18.693493 23206 maintenance_manager.cc:419] P a169b45d5a1a4211bc9e1f28b36a2a3a: Scheduling MajorDeltaCompactionOp(061aaf5bcf924900833957edc42cab04): perf score=1.000000
I20260812 06:20:18.866089 23097 maintenance_manager.cc:643] P a169b45d5a1a4211bc9e1f28b36a2a3a: MajorDeltaCompactionOp(061aaf5bcf924900833957edc42cab04) complete. Timing: real 0.172s	user 0.093s	sys 0.079s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774692,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":471,"lbm_read_time_us":13681,"lbm_reads_lt_1ms":572,"lbm_write_time_us":31130,"lbm_writes_lt_1ms":543,"mutex_wait_us":84,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":1408,"update_count":2500}
I20260812 06:20:18.866833 23206 maintenance_manager.cc:419] P a169b45d5a1a4211bc9e1f28b36a2a3a: Scheduling FlushDeltaMemStoresOp(061aaf5bcf924900833957edc42cab04): perf score=10.126437
I20260812 06:20:18.902727 23097 maintenance_manager.cc:643] P a169b45d5a1a4211bc9e1f28b36a2a3a: FlushDeltaMemStoresOp(061aaf5bcf924900833957edc42cab04) complete. Timing: real 0.036s	user 0.024s	sys 0.008s Metrics: {"bytes_written":12307491,"delete_count":0,"lbm_write_time_us":15577,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:20:18.903286 23206 maintenance_manager.cc:419] P a169b45d5a1a4211bc9e1f28b36a2a3a: Scheduling FlushDeltaMemStoresOp(061aaf5bcf924900833957edc42cab04): perf score=2.188937
I20260812 06:20:18.914577 23097 maintenance_manager.cc:643] P a169b45d5a1a4211bc9e1f28b36a2a3a: FlushDeltaMemStoresOp(061aaf5bcf924900833957edc42cab04) complete. Timing: real 0.011s	user 0.009s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4372,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:18.915014 23206 maintenance_manager.cc:419] P a169b45d5a1a4211bc9e1f28b36a2a3a: Scheduling MajorDeltaCompactionOp(061aaf5bcf924900833957edc42cab04): perf score=1.000000
I20260812 06:20:19.049743 23097 maintenance_manager.cc:643] P a169b45d5a1a4211bc9e1f28b36a2a3a: MajorDeltaCompactionOp(061aaf5bcf924900833957edc42cab04) complete. Timing: real 0.135s	user 0.099s	sys 0.036s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672278,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":336,"lbm_read_time_us":9725,"lbm_reads_lt_1ms":472,"lbm_write_time_us":26465,"lbm_writes_lt_1ms":443,"mutex_wait_us":51,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":12032,"update_count":2000}
I20260812 06:20:19.050424 23206 maintenance_manager.cc:419] P a169b45d5a1a4211bc9e1f28b36a2a3a: Scheduling FlushDeltaMemStoresOp(061aaf5bcf924900833957edc42cab04): perf score=10.126437
I20260812 06:20:19.097674 23097 maintenance_manager.cc:643] P a169b45d5a1a4211bc9e1f28b36a2a3a: FlushDeltaMemStoresOp(061aaf5bcf924900833957edc42cab04) complete. Timing: real 0.047s	user 0.021s	sys 0.015s Metrics: {"bytes_written":12307489,"delete_count":0,"lbm_write_time_us":16491,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:20:19.098172 23206 maintenance_manager.cc:419] P a169b45d5a1a4211bc9e1f28b36a2a3a: Scheduling FlushDeltaMemStoresOp(061aaf5bcf924900833957edc42cab04): perf score=2.188937
I20260812 06:20:19.109416 23097 maintenance_manager.cc:643] P a169b45d5a1a4211bc9e1f28b36a2a3a: FlushDeltaMemStoresOp(061aaf5bcf924900833957edc42cab04) complete. Timing: real 0.011s	user 0.005s	sys 0.005s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4107,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:19.110162 23206 maintenance_manager.cc:419] P a169b45d5a1a4211bc9e1f28b36a2a3a: Scheduling MajorDeltaCompactionOp(061aaf5bcf924900833957edc42cab04): perf score=1.000000
I20260812 06:20:19.246630 23097 maintenance_manager.cc:643] P a169b45d5a1a4211bc9e1f28b36a2a3a: MajorDeltaCompactionOp(061aaf5bcf924900833957edc42cab04) complete. Timing: real 0.136s	user 0.110s	sys 0.024s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672276,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":277,"lbm_read_time_us":10520,"lbm_reads_lt_1ms":472,"lbm_write_time_us":24230,"lbm_writes_lt_1ms":443,"mutex_wait_us":2,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":3200,"update_count":2000}
I20260812 06:20:19.247414 23206 maintenance_manager.cc:419] P a169b45d5a1a4211bc9e1f28b36a2a3a: Scheduling FlushDeltaMemStoresOp(061aaf5bcf924900833957edc42cab04): perf score=10.126437
I20260812 06:20:19.294503 23097 maintenance_manager.cc:643] P a169b45d5a1a4211bc9e1f28b36a2a3a: FlushDeltaMemStoresOp(061aaf5bcf924900833957edc42cab04) complete. Timing: real 0.047s	user 0.027s	sys 0.015s Metrics: {"bytes_written":12307493,"delete_count":0,"lbm_write_time_us":19561,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:20:19.295003 23206 maintenance_manager.cc:419] P a169b45d5a1a4211bc9e1f28b36a2a3a: Scheduling FlushDeltaMemStoresOp(061aaf5bcf924900833957edc42cab04): perf score=2.188937
I20260812 06:20:19.305425 23097 maintenance_manager.cc:643] P a169b45d5a1a4211bc9e1f28b36a2a3a: FlushDeltaMemStoresOp(061aaf5bcf924900833957edc42cab04) complete. Timing: real 0.010s	user 0.004s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4045,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:19.306174 23206 maintenance_manager.cc:419] P a169b45d5a1a4211bc9e1f28b36a2a3a: Scheduling MajorDeltaCompactionOp(061aaf5bcf924900833957edc42cab04): perf score=1.000000
I20260812 06:20:19.442880 23097 maintenance_manager.cc:643] P a169b45d5a1a4211bc9e1f28b36a2a3a: MajorDeltaCompactionOp(061aaf5bcf924900833957edc42cab04) complete. Timing: real 0.136s	user 0.112s	sys 0.024s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672280,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":1197,"lbm_read_time_us":10489,"lbm_reads_lt_1ms":472,"lbm_write_time_us":25338,"lbm_writes_lt_1ms":443,"mutex_wait_us":328,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":12288,"update_count":2000}
I20260812 06:20:19.443446 23206 maintenance_manager.cc:419] P a169b45d5a1a4211bc9e1f28b36a2a3a: Scheduling FlushDeltaMemStoresOp(061aaf5bcf924900833957edc42cab04): perf score=10.126437
I20260812 06:20:19.497519 23097 maintenance_manager.cc:643] P a169b45d5a1a4211bc9e1f28b36a2a3a: FlushDeltaMemStoresOp(061aaf5bcf924900833957edc42cab04) complete. Timing: real 0.054s	user 0.017s	sys 0.027s Metrics: {"bytes_written":12307493,"delete_count":0,"lbm_write_time_us":16387,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:20:19.498330 23206 maintenance_manager.cc:419] P a169b45d5a1a4211bc9e1f28b36a2a3a: Scheduling FlushDeltaMemStoresOp(061aaf5bcf924900833957edc42cab04): perf score=2.188937
I20260812 06:20:19.510597 23097 maintenance_manager.cc:643] P a169b45d5a1a4211bc9e1f28b36a2a3a: FlushDeltaMemStoresOp(061aaf5bcf924900833957edc42cab04) complete. Timing: real 0.012s	user 0.007s	sys 0.003s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4796,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:19.511237 23206 maintenance_manager.cc:419] P a169b45d5a1a4211bc9e1f28b36a2a3a: Scheduling MajorDeltaCompactionOp(061aaf5bcf924900833957edc42cab04): perf score=1.000000
I20260812 06:20:19.674475 23097 maintenance_manager.cc:643] P a169b45d5a1a4211bc9e1f28b36a2a3a: MajorDeltaCompactionOp(061aaf5bcf924900833957edc42cab04) complete. Timing: real 0.163s	user 0.125s	sys 0.035s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672280,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":601,"lbm_read_time_us":12558,"lbm_reads_lt_1ms":472,"lbm_write_time_us":27253,"lbm_writes_lt_1ms":443,"mutex_wait_us":30,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":13568,"update_count":2000}
I20260812 06:20:19.675164 23206 maintenance_manager.cc:419] P a169b45d5a1a4211bc9e1f28b36a2a3a: Scheduling FlushDeltaMemStoresOp(061aaf5bcf924900833957edc42cab04): perf score=11.118625
I20260812 06:20:19.706667 23097 maintenance_manager.cc:643] P a169b45d5a1a4211bc9e1f28b36a2a3a: FlushDeltaMemStoresOp(061aaf5bcf924900833957edc42cab04) complete. Timing: real 0.031s	user 0.022s	sys 0.006s Metrics: {"bytes_written":12717737,"delete_count":0,"lbm_write_time_us":13435,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:20:19.707329 23206 maintenance_manager.cc:419] P a169b45d5a1a4211bc9e1f28b36a2a3a: Scheduling FlushDeltaMemStoresOp(061aaf5bcf924900833957edc42cab04): perf score=2.188937
I20260812 06:20:19.723433 23097 maintenance_manager.cc:643] P a169b45d5a1a4211bc9e1f28b36a2a3a: FlushDeltaMemStoresOp(061aaf5bcf924900833957edc42cab04) complete. Timing: real 0.016s	user 0.006s	sys 0.007s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":5747,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:20:19.723965 23206 maintenance_manager.cc:419] P a169b45d5a1a4211bc9e1f28b36a2a3a: Scheduling FlushMRSOp(061aaf5bcf924900833957edc42cab04): perf score=1.000000
I20260812 06:20:19.747891 23097 maintenance_manager.cc:643] P a169b45d5a1a4211bc9e1f28b36a2a3a: FlushMRSOp(061aaf5bcf924900833957edc42cab04) complete. Timing: real 0.024s	user 0.023s	sys 0.001s Metrics: {"bytes_written":1152514,"cfile_init":1,"dirs.queue_time_us":65,"dirs.run_cpu_time_us":241,"dirs.run_wall_time_us":1503,"drs_written":1,"lbm_read_time_us":37,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1390,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":28}
I20260812 06:20:19.748618 23206 maintenance_manager.cc:419] P a169b45d5a1a4211bc9e1f28b36a2a3a: Scheduling LogGCOp(061aaf5bcf924900833957edc42cab04): free 115943183 bytes of WAL
I20260812 06:20:19.748859 23097 log_reader.cc:385] T 061aaf5bcf924900833957edc42cab04: removed 11 log segments from log reader
I20260812 06:20:19.748908 23097 log.cc:1079] T 061aaf5bcf924900833957edc42cab04 P a169b45d5a1a4211bc9e1f28b36a2a3a: Deleting log segment in path: /tmp/dist-test-taskdP7EeR/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515616224519-22919-0/minicluster-data/ts-0-root/wals/061aaf5bcf924900833957edc42cab04/wal-000000015 (ops 71-75)
I20260812 06:20:19.748937 23097 log.cc:1079] T 061aaf5bcf924900833957edc42cab04 P a169b45d5a1a4211bc9e1f28b36a2a3a: Deleting log segment in path: /tmp/dist-test-taskdP7EeR/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515616224519-22919-0/minicluster-data/ts-0-root/wals/061aaf5bcf924900833957edc42cab04/wal-000000016 (ops 76-80)
I20260812 06:20:19.749001 23097 log.cc:1079] T 061aaf5bcf924900833957edc42cab04 P a169b45d5a1a4211bc9e1f28b36a2a3a: Deleting log segment in path: /tmp/dist-test-taskdP7EeR/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515616224519-22919-0/minicluster-data/ts-0-root/wals/061aaf5bcf924900833957edc42cab04/wal-000000017 (ops 81-85)
I20260812 06:20:19.749030 23097 log.cc:1079] T 061aaf5bcf924900833957edc42cab04 P a169b45d5a1a4211bc9e1f28b36a2a3a: Deleting log segment in path: /tmp/dist-test-taskdP7EeR/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515616224519-22919-0/minicluster-data/ts-0-root/wals/061aaf5bcf924900833957edc42cab04/wal-000000018 (ops 86-90)
I20260812 06:20:19.749070 23097 log.cc:1079] T 061aaf5bcf924900833957edc42cab04 P a169b45d5a1a4211bc9e1f28b36a2a3a: Deleting log segment in path: /tmp/dist-test-taskdP7EeR/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515616224519-22919-0/minicluster-data/ts-0-root/wals/061aaf5bcf924900833957edc42cab04/wal-000000019 (ops 91-95)
I20260812 06:20:19.749121 23097 log.cc:1079] T 061aaf5bcf924900833957edc42cab04 P a169b45d5a1a4211bc9e1f28b36a2a3a: Deleting log segment in path: /tmp/dist-test-taskdP7EeR/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515616224519-22919-0/minicluster-data/ts-0-root/wals/061aaf5bcf924900833957edc42cab04/wal-000000020 (ops 96-100)
I20260812 06:20:19.749158 23097 log.cc:1079] T 061aaf5bcf924900833957edc42cab04 P a169b45d5a1a4211bc9e1f28b36a2a3a: Deleting log segment in path: /tmp/dist-test-taskdP7EeR/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515616224519-22919-0/minicluster-data/ts-0-root/wals/061aaf5bcf924900833957edc42cab04/wal-000000021 (ops 101-105)
I20260812 06:20:19.749215 23097 log.cc:1079] T 061aaf5bcf924900833957edc42cab04 P a169b45d5a1a4211bc9e1f28b36a2a3a: Deleting log segment in path: /tmp/dist-test-taskdP7EeR/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515616224519-22919-0/minicluster-data/ts-0-root/wals/061aaf5bcf924900833957edc42cab04/wal-000000022 (ops 106-110)
I20260812 06:20:19.749255 23097 log.cc:1079] T 061aaf5bcf924900833957edc42cab04 P a169b45d5a1a4211bc9e1f28b36a2a3a: Deleting log segment in path: /tmp/dist-test-taskdP7EeR/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515616224519-22919-0/minicluster-data/ts-0-root/wals/061aaf5bcf924900833957edc42cab04/wal-000000023 (ops 111-115)
I20260812 06:20:19.749295 23097 log.cc:1079] T 061aaf5bcf924900833957edc42cab04 P a169b45d5a1a4211bc9e1f28b36a2a3a: Deleting log segment in path: /tmp/dist-test-taskdP7EeR/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515616224519-22919-0/minicluster-data/ts-0-root/wals/061aaf5bcf924900833957edc42cab04/wal-000000024 (ops 116-120)
I20260812 06:20:19.749336 23097 log.cc:1079] T 061aaf5bcf924900833957edc42cab04 P a169b45d5a1a4211bc9e1f28b36a2a3a: Deleting log segment in path: /tmp/dist-test-taskdP7EeR/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515616224519-22919-0/minicluster-data/ts-0-root/wals/061aaf5bcf924900833957edc42cab04/wal-000000025 (ops 121-125)
I20260812 06:20:19.776546 23097 maintenance_manager.cc:643] P a169b45d5a1a4211bc9e1f28b36a2a3a: LogGCOp(061aaf5bcf924900833957edc42cab04) complete. Timing: real 0.028s	user 0.000s	sys 0.027s Metrics: {}
I20260812 06:20:19.777123 23206 maintenance_manager.cc:419] P a169b45d5a1a4211bc9e1f28b36a2a3a: Scheduling FlushDeltaMemStoresOp(061aaf5bcf924900833957edc42cab04): perf score=3.181125
I20260812 06:20:19.804057 23097 maintenance_manager.cc:643] P a169b45d5a1a4211bc9e1f28b36a2a3a: FlushDeltaMemStoresOp(061aaf5bcf924900833957edc42cab04) complete. Timing: real 0.027s	user 0.008s	sys 0.018s Metrics: {"bytes_written":4512900,"delete_count":0,"lbm_write_time_us":7560,"lbm_writes_lt_1ms":113,"reinsert_count":0,"update_count":550}
I20260812 06:20:19.804567 23206 maintenance_manager.cc:419] P a169b45d5a1a4211bc9e1f28b36a2a3a: Scheduling UndoDeltaBlockGCOp(061aaf5bcf924900833957edc42cab04): 447 bytes on disk
I20260812 06:20:19.805024 23097 maintenance_manager.cc:643] P a169b45d5a1a4211bc9e1f28b36a2a3a: UndoDeltaBlockGCOp(061aaf5bcf924900833957edc42cab04) 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:20:19.805549 23206 maintenance_manager.cc:419] P a169b45d5a1a4211bc9e1f28b36a2a3a: Scheduling FlushDeltaMemStoresOp(061aaf5bcf924900833957edc42cab04): perf score=2.188937
I20260812 06:20:19.816088 23097 maintenance_manager.cc:643] P a169b45d5a1a4211bc9e1f28b36a2a3a: FlushDeltaMemStoresOp(061aaf5bcf924900833957edc42cab04) complete. Timing: real 0.010s	user 0.005s	sys 0.005s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3997,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:20:19.816560 23206 maintenance_manager.cc:419] P a169b45d5a1a4211bc9e1f28b36a2a3a: Scheduling MajorDeltaCompactionOp(061aaf5bcf924900833957edc42cab04): perf score=1.000000
I20260812 06:20:20.044855 23097 maintenance_manager.cc:643] P a169b45d5a1a4211bc9e1f28b36a2a3a: MajorDeltaCompactionOp(061aaf5bcf924900833957edc42cab04) complete. Timing: real 0.228s	user 0.156s	sys 0.068s Metrics: {"cfile_cache_miss":634,"cfile_cache_miss_bytes":28877319,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":540,"lbm_read_time_us":15735,"lbm_reads_lt_1ms":674,"lbm_write_time_us":40744,"lbm_writes_lt_1ms":643,"mutex_wait_us":65,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":4864,"thread_start_us":79,"threads_started":1,"update_count":3000}
I20260812 06:20:20.045876 23206 maintenance_manager.cc:419] P a169b45d5a1a4211bc9e1f28b36a2a3a: Scheduling FlushDeltaMemStoresOp(061aaf5bcf924900833957edc42cab04): perf score=14.095187
I20260812 06:20:20.108325 23097 maintenance_manager.cc:643] P a169b45d5a1a4211bc9e1f28b36a2a3a: FlushDeltaMemStoresOp(061aaf5bcf924900833957edc42cab04) complete. Timing: real 0.062s	user 0.026s	sys 0.031s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":20971,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:20:20.108954 23206 maintenance_manager.cc:419] P a169b45d5a1a4211bc9e1f28b36a2a3a: Scheduling FlushDeltaMemStoresOp(061aaf5bcf924900833957edc42cab04): perf score=2.188937
I20260812 06:20:20.120113 23097 maintenance_manager.cc:643] P a169b45d5a1a4211bc9e1f28b36a2a3a: FlushDeltaMemStoresOp(061aaf5bcf924900833957edc42cab04) complete. Timing: real 0.011s	user 0.006s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4326,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:20.120568 23206 maintenance_manager.cc:419] P a169b45d5a1a4211bc9e1f28b36a2a3a: Scheduling MajorDeltaCompactionOp(061aaf5bcf924900833957edc42cab04): perf score=1.000000
I20260812 06:20:20.303665 23097 maintenance_manager.cc:643] P a169b45d5a1a4211bc9e1f28b36a2a3a: MajorDeltaCompactionOp(061aaf5bcf924900833957edc42cab04) complete. Timing: real 0.183s	user 0.118s	sys 0.064s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774689,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":629,"lbm_read_time_us":13017,"lbm_reads_lt_1ms":572,"lbm_write_time_us":32028,"lbm_writes_lt_1ms":543,"mutex_wait_us":259,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":3328,"update_count":2500}
I20260812 06:20:20.304431 23206 maintenance_manager.cc:419] P a169b45d5a1a4211bc9e1f28b36a2a3a: Scheduling FlushDeltaMemStoresOp(061aaf5bcf924900833957edc42cab04): perf score=11.118625
I20260812 06:20:20.337658 23097 maintenance_manager.cc:643] P a169b45d5a1a4211bc9e1f28b36a2a3a: FlushDeltaMemStoresOp(061aaf5bcf924900833957edc42cab04) complete. Timing: real 0.033s	user 0.016s	sys 0.015s Metrics: {"bytes_written":12471587,"delete_count":0,"lbm_write_time_us":14313,"lbm_writes_lt_1ms":307,"reinsert_count":0,"update_count":1520}
I20260812 06:20:20.338243 23206 maintenance_manager.cc:419] P a169b45d5a1a4211bc9e1f28b36a2a3a: Scheduling FlushDeltaMemStoresOp(061aaf5bcf924900833957edc42cab04): perf score=2.188937
I20260812 06:20:20.351454 23097 maintenance_manager.cc:643] P a169b45d5a1a4211bc9e1f28b36a2a3a: FlushDeltaMemStoresOp(061aaf5bcf924900833957edc42cab04) complete. Timing: real 0.013s	user 0.002s	sys 0.007s Metrics: {"bytes_written":3938559,"delete_count":0,"lbm_write_time_us":4175,"lbm_writes_lt_1ms":99,"reinsert_count":0,"update_count":480}
I20260812 06:20:20.352007 23206 maintenance_manager.cc:419] P a169b45d5a1a4211bc9e1f28b36a2a3a: Scheduling MajorDeltaCompactionOp(061aaf5bcf924900833957edc42cab04): perf score=1.000000
I20260812 06:20:20.492067 23097 maintenance_manager.cc:643] P a169b45d5a1a4211bc9e1f28b36a2a3a: MajorDeltaCompactionOp(061aaf5bcf924900833957edc42cab04) complete. Timing: real 0.140s	user 0.102s	sys 0.037s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672274,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":962,"lbm_read_time_us":8562,"lbm_reads_lt_1ms":472,"lbm_write_time_us":26674,"lbm_writes_lt_1ms":443,"mutex_wait_us":23,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":3456,"update_count":2000}
I20260812 06:20:20.492725 23206 maintenance_manager.cc:419] P a169b45d5a1a4211bc9e1f28b36a2a3a: Scheduling FlushDeltaMemStoresOp(061aaf5bcf924900833957edc42cab04): perf score=10.126437
I20260812 06:20:20.544466 23097 maintenance_manager.cc:643] P a169b45d5a1a4211bc9e1f28b36a2a3a: FlushDeltaMemStoresOp(061aaf5bcf924900833957edc42cab04) complete. Timing: real 0.052s	user 0.028s	sys 0.016s Metrics: {"bytes_written":12307492,"delete_count":0,"lbm_write_time_us":18518,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:20:20.545018 23206 maintenance_manager.cc:419] P a169b45d5a1a4211bc9e1f28b36a2a3a: Scheduling FlushDeltaMemStoresOp(061aaf5bcf924900833957edc42cab04): perf score=2.188937
I20260812 06:20:20.556383 23097 maintenance_manager.cc:643] P a169b45d5a1a4211bc9e1f28b36a2a3a: FlushDeltaMemStoresOp(061aaf5bcf924900833957edc42cab04) complete. Timing: real 0.011s	user 0.010s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4230,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:20.557006 23206 maintenance_manager.cc:419] P a169b45d5a1a4211bc9e1f28b36a2a3a: Scheduling MajorDeltaCompactionOp(061aaf5bcf924900833957edc42cab04): perf score=1.000000
I20260812 06:20:20.678946 23097 maintenance_manager.cc:643] P a169b45d5a1a4211bc9e1f28b36a2a3a: MajorDeltaCompactionOp(061aaf5bcf924900833957edc42cab04) complete. Timing: real 0.122s	user 0.101s	sys 0.020s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672279,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":404,"lbm_read_time_us":7923,"lbm_reads_lt_1ms":472,"lbm_write_time_us":24198,"lbm_writes_lt_1ms":443,"mutex_wait_us":1,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":10752,"update_count":2000}
I20260812 06:20:20.679580 23206 maintenance_manager.cc:419] P a169b45d5a1a4211bc9e1f28b36a2a3a: Scheduling FlushDeltaMemStoresOp(061aaf5bcf924900833957edc42cab04): perf score=10.126437
I20260812 06:20:20.727523 23097 maintenance_manager.cc:643] P a169b45d5a1a4211bc9e1f28b36a2a3a: FlushDeltaMemStoresOp(061aaf5bcf924900833957edc42cab04) complete. Timing: real 0.048s	user 0.024s	sys 0.012s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":17978,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:20:20.728191 23206 maintenance_manager.cc:419] P a169b45d5a1a4211bc9e1f28b36a2a3a: Scheduling FlushDeltaMemStoresOp(061aaf5bcf924900833957edc42cab04): perf score=2.188937
I20260812 06:20:20.739795 23097 maintenance_manager.cc:643] P a169b45d5a1a4211bc9e1f28b36a2a3a: FlushDeltaMemStoresOp(061aaf5bcf924900833957edc42cab04) complete. Timing: real 0.011s	user 0.005s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4203,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:20.740520 23206 maintenance_manager.cc:419] P a169b45d5a1a4211bc9e1f28b36a2a3a: Scheduling MajorDeltaCompactionOp(061aaf5bcf924900833957edc42cab04): perf score=1.000000
I20260812 06:20:20.867616 23097 maintenance_manager.cc:643] P a169b45d5a1a4211bc9e1f28b36a2a3a: MajorDeltaCompactionOp(061aaf5bcf924900833957edc42cab04) complete. Timing: real 0.127s	user 0.106s	sys 0.020s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672277,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":619,"lbm_read_time_us":9087,"lbm_reads_lt_1ms":472,"lbm_write_time_us":23393,"lbm_writes_lt_1ms":443,"mutex_wait_us":317,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":12416,"update_count":2000}
I20260812 06:20:20.868393 23206 maintenance_manager.cc:419] P a169b45d5a1a4211bc9e1f28b36a2a3a: Scheduling FlushDeltaMemStoresOp(061aaf5bcf924900833957edc42cab04): perf score=10.126437
I20260812 06:20:20.919781 23097 maintenance_manager.cc:643] P a169b45d5a1a4211bc9e1f28b36a2a3a: FlushDeltaMemStoresOp(061aaf5bcf924900833957edc42cab04) complete. Timing: real 0.051s	user 0.032s	sys 0.014s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":18234,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:20:20.920388 23206 maintenance_manager.cc:419] P a169b45d5a1a4211bc9e1f28b36a2a3a: Scheduling FlushDeltaMemStoresOp(061aaf5bcf924900833957edc42cab04): perf score=2.188937
I20260812 06:20:20.932659 23097 maintenance_manager.cc:643] P a169b45d5a1a4211bc9e1f28b36a2a3a: FlushDeltaMemStoresOp(061aaf5bcf924900833957edc42cab04) complete. Timing: real 0.012s	user 0.007s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4426,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:20.933385 23206 maintenance_manager.cc:419] P a169b45d5a1a4211bc9e1f28b36a2a3a: Scheduling MajorDeltaCompactionOp(061aaf5bcf924900833957edc42cab04): perf score=1.000000
I20260812 06:20:21.097371 23097 maintenance_manager.cc:643] P a169b45d5a1a4211bc9e1f28b36a2a3a: MajorDeltaCompactionOp(061aaf5bcf924900833957edc42cab04) complete. Timing: real 0.164s	user 0.125s	sys 0.038s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672277,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":966,"lbm_read_time_us":12320,"lbm_reads_lt_1ms":472,"lbm_write_time_us":27178,"lbm_writes_lt_1ms":443,"mutex_wait_us":277,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":8832,"update_count":2000}
I20260812 06:20:21.098070 23206 maintenance_manager.cc:419] P a169b45d5a1a4211bc9e1f28b36a2a3a: Scheduling FlushDeltaMemStoresOp(061aaf5bcf924900833957edc42cab04): perf score=10.126437
I20260812 06:20:21.144860 23097 maintenance_manager.cc:643] P a169b45d5a1a4211bc9e1f28b36a2a3a: FlushDeltaMemStoresOp(061aaf5bcf924900833957edc42cab04) complete. Timing: real 0.047s	user 0.018s	sys 0.017s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":16146,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:20:21.145744 23206 maintenance_manager.cc:419] P a169b45d5a1a4211bc9e1f28b36a2a3a: Scheduling FlushDeltaMemStoresOp(061aaf5bcf924900833957edc42cab04): perf score=2.188937
I20260812 06:20:21.158021 23097 maintenance_manager.cc:643] P a169b45d5a1a4211bc9e1f28b36a2a3a: FlushDeltaMemStoresOp(061aaf5bcf924900833957edc42cab04) complete. Timing: real 0.012s	user 0.010s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4791,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:21.158820 23206 maintenance_manager.cc:419] P a169b45d5a1a4211bc9e1f28b36a2a3a: Scheduling MajorDeltaCompactionOp(061aaf5bcf924900833957edc42cab04): perf score=1.000000
I20260812 06:20:21.297147 23097 maintenance_manager.cc:643] P a169b45d5a1a4211bc9e1f28b36a2a3a: MajorDeltaCompactionOp(061aaf5bcf924900833957edc42cab04) complete. Timing: real 0.138s	user 0.102s	sys 0.034s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672277,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":1409,"lbm_read_time_us":11650,"lbm_reads_lt_1ms":472,"lbm_write_time_us":27707,"lbm_writes_lt_1ms":443,"mutex_wait_us":279,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":7680,"update_count":2000}
I20260812 06:20:21.299052 23206 maintenance_manager.cc:419] P a169b45d5a1a4211bc9e1f28b36a2a3a: Scheduling FlushDeltaMemStoresOp(061aaf5bcf924900833957edc42cab04): perf score=10.126437
I20260812 06:20:21.334695 23097 maintenance_manager.cc:643] P a169b45d5a1a4211bc9e1f28b36a2a3a: FlushDeltaMemStoresOp(061aaf5bcf924900833957edc42cab04) complete. Timing: real 0.035s	user 0.024s	sys 0.009s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":15928,"lbm_writes_lt_1ms":303,"reinsert_count":0,"spinlock_wait_cycles":2304,"update_count":1500}
I20260812 06:20:21.335242 23206 maintenance_manager.cc:419] P a169b45d5a1a4211bc9e1f28b36a2a3a: Scheduling FlushDeltaMemStoresOp(061aaf5bcf924900833957edc42cab04): perf score=2.188937
I20260812 06:20:21.347316 23097 maintenance_manager.cc:643] P a169b45d5a1a4211bc9e1f28b36a2a3a: FlushDeltaMemStoresOp(061aaf5bcf924900833957edc42cab04) complete. Timing: real 0.012s	user 0.002s	sys 0.007s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4415,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:21.348083 23206 maintenance_manager.cc:419] P a169b45d5a1a4211bc9e1f28b36a2a3a: Scheduling FlushMRSOp(061aaf5bcf924900833957edc42cab04): perf score=1.000000
I20260812 06:20:21.376865 23097 maintenance_manager.cc:643] P a169b45d5a1a4211bc9e1f28b36a2a3a: FlushMRSOp(061aaf5bcf924900833957edc42cab04) complete. Timing: real 0.029s	user 0.027s	sys 0.001s Metrics: {"bytes_written":1234477,"cfile_init":1,"dirs.queue_time_us":58,"dirs.run_cpu_time_us":212,"dirs.run_wall_time_us":1459,"drs_written":1,"lbm_read_time_us":51,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1708,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":30}
I20260812 06:20:21.377607 23206 maintenance_manager.cc:419] P a169b45d5a1a4211bc9e1f28b36a2a3a: Scheduling LogGCOp(061aaf5bcf924900833957edc42cab04): free 124710506 bytes of WAL
I20260812 06:20:21.377893 23097 log_reader.cc:385] T 061aaf5bcf924900833957edc42cab04: removed 12 log segments from log reader
I20260812 06:20:21.377956 23097 log.cc:1079] T 061aaf5bcf924900833957edc42cab04 P a169b45d5a1a4211bc9e1f28b36a2a3a: Deleting log segment in path: /tmp/dist-test-taskdP7EeR/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515616224519-22919-0/minicluster-data/ts-0-root/wals/061aaf5bcf924900833957edc42cab04/wal-000000026 (ops 126-130)
I20260812 06:20:21.377996 23097 log.cc:1079] T 061aaf5bcf924900833957edc42cab04 P a169b45d5a1a4211bc9e1f28b36a2a3a: Deleting log segment in path: /tmp/dist-test-taskdP7EeR/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515616224519-22919-0/minicluster-data/ts-0-root/wals/061aaf5bcf924900833957edc42cab04/wal-000000027 (ops 131-135)
I20260812 06:20:21.378024 23097 log.cc:1079] T 061aaf5bcf924900833957edc42cab04 P a169b45d5a1a4211bc9e1f28b36a2a3a: Deleting log segment in path: /tmp/dist-test-taskdP7EeR/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515616224519-22919-0/minicluster-data/ts-0-root/wals/061aaf5bcf924900833957edc42cab04/wal-000000028 (ops 136-140)
I20260812 06:20:21.378052 23097 log.cc:1079] T 061aaf5bcf924900833957edc42cab04 P a169b45d5a1a4211bc9e1f28b36a2a3a: Deleting log segment in path: /tmp/dist-test-taskdP7EeR/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515616224519-22919-0/minicluster-data/ts-0-root/wals/061aaf5bcf924900833957edc42cab04/wal-000000029 (ops 141-145)
I20260812 06:20:21.378086 23097 log.cc:1079] T 061aaf5bcf924900833957edc42cab04 P a169b45d5a1a4211bc9e1f28b36a2a3a: Deleting log segment in path: /tmp/dist-test-taskdP7EeR/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515616224519-22919-0/minicluster-data/ts-0-root/wals/061aaf5bcf924900833957edc42cab04/wal-000000030 (ops 146-150)
I20260812 06:20:21.378121 23097 log.cc:1079] T 061aaf5bcf924900833957edc42cab04 P a169b45d5a1a4211bc9e1f28b36a2a3a: Deleting log segment in path: /tmp/dist-test-taskdP7EeR/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515616224519-22919-0/minicluster-data/ts-0-root/wals/061aaf5bcf924900833957edc42cab04/wal-000000031 (ops 151-155)
I20260812 06:20:21.378149 23097 log.cc:1079] T 061aaf5bcf924900833957edc42cab04 P a169b45d5a1a4211bc9e1f28b36a2a3a: Deleting log segment in path: /tmp/dist-test-taskdP7EeR/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515616224519-22919-0/minicluster-data/ts-0-root/wals/061aaf5bcf924900833957edc42cab04/wal-000000032 (ops 156-160)
I20260812 06:20:21.378176 23097 log.cc:1079] T 061aaf5bcf924900833957edc42cab04 P a169b45d5a1a4211bc9e1f28b36a2a3a: Deleting log segment in path: /tmp/dist-test-taskdP7EeR/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515616224519-22919-0/minicluster-data/ts-0-root/wals/061aaf5bcf924900833957edc42cab04/wal-000000033 (ops 161-165)
I20260812 06:20:21.378204 23097 log.cc:1079] T 061aaf5bcf924900833957edc42cab04 P a169b45d5a1a4211bc9e1f28b36a2a3a: Deleting log segment in path: /tmp/dist-test-taskdP7EeR/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515616224519-22919-0/minicluster-data/ts-0-root/wals/061aaf5bcf924900833957edc42cab04/wal-000000034 (ops 166-170)
I20260812 06:20:21.378242 23097 log.cc:1079] T 061aaf5bcf924900833957edc42cab04 P a169b45d5a1a4211bc9e1f28b36a2a3a: Deleting log segment in path: /tmp/dist-test-taskdP7EeR/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515616224519-22919-0/minicluster-data/ts-0-root/wals/061aaf5bcf924900833957edc42cab04/wal-000000035 (ops 171-175)
I20260812 06:20:21.378278 23097 log.cc:1079] T 061aaf5bcf924900833957edc42cab04 P a169b45d5a1a4211bc9e1f28b36a2a3a: Deleting log segment in path: /tmp/dist-test-taskdP7EeR/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515616224519-22919-0/minicluster-data/ts-0-root/wals/061aaf5bcf924900833957edc42cab04/wal-000000036 (ops 176-180)
I20260812 06:20:21.378302 23097 log.cc:1079] T 061aaf5bcf924900833957edc42cab04 P a169b45d5a1a4211bc9e1f28b36a2a3a: Deleting log segment in path: /tmp/dist-test-taskdP7EeR/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515616224519-22919-0/minicluster-data/ts-0-root/wals/061aaf5bcf924900833957edc42cab04/wal-000000037 (ops 181-185)
I20260812 06:20:21.408516 23097 maintenance_manager.cc:643] P a169b45d5a1a4211bc9e1f28b36a2a3a: LogGCOp(061aaf5bcf924900833957edc42cab04) complete. Timing: real 0.031s	user 0.003s	sys 0.027s Metrics: {}
I20260812 06:20:21.409019 23206 maintenance_manager.cc:419] P a169b45d5a1a4211bc9e1f28b36a2a3a: Scheduling FlushDeltaMemStoresOp(061aaf5bcf924900833957edc42cab04): perf score=3.181125
I20260812 06:20:21.425034 23097 maintenance_manager.cc:643] P a169b45d5a1a4211bc9e1f28b36a2a3a: FlushDeltaMemStoresOp(061aaf5bcf924900833957edc42cab04) complete. Timing: real 0.016s	user 0.007s	sys 0.005s Metrics: {"bytes_written":4512900,"delete_count":0,"lbm_write_time_us":5015,"lbm_writes_lt_1ms":113,"reinsert_count":0,"update_count":550}
I20260812 06:20:21.425508 23206 maintenance_manager.cc:419] P a169b45d5a1a4211bc9e1f28b36a2a3a: Scheduling UndoDeltaBlockGCOp(061aaf5bcf924900833957edc42cab04): 472 bytes on disk
I20260812 06:20:21.425951 23097 maintenance_manager.cc:643] P a169b45d5a1a4211bc9e1f28b36a2a3a: UndoDeltaBlockGCOp(061aaf5bcf924900833957edc42cab04) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":49,"lbm_reads_lt_1ms":4}
I20260812 06:20:21.426489 23206 maintenance_manager.cc:419] P a169b45d5a1a4211bc9e1f28b36a2a3a: Scheduling FlushDeltaMemStoresOp(061aaf5bcf924900833957edc42cab04): perf score=2.188937
I20260812 06:20:21.436398 23097 maintenance_manager.cc:643] P a169b45d5a1a4211bc9e1f28b36a2a3a: FlushDeltaMemStoresOp(061aaf5bcf924900833957edc42cab04) complete. Timing: real 0.010s	user 0.009s	sys 0.000s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3900,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:20:21.436852 23206 maintenance_manager.cc:419] P a169b45d5a1a4211bc9e1f28b36a2a3a: Scheduling MajorDeltaCompactionOp(061aaf5bcf924900833957edc42cab04): perf score=1.000000
I20260812 06:20:21.626899 23097 maintenance_manager.cc:643] P a169b45d5a1a4211bc9e1f28b36a2a3a: MajorDeltaCompactionOp(061aaf5bcf924900833957edc42cab04) complete. Timing: real 0.190s	user 0.132s	sys 0.053s Metrics: {"cfile_cache_miss":634,"cfile_cache_miss_bytes":28877326,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":595,"lbm_read_time_us":14306,"lbm_reads_lt_1ms":674,"lbm_write_time_us":38514,"lbm_writes_lt_1ms":643,"mutex_wait_us":2,"peak_mem_usage":75542472,"reinsert_count":0,"thread_start_us":105,"threads_started":1,"update_count":3000}
I20260812 06:20:21.627678 23206 maintenance_manager.cc:419] P a169b45d5a1a4211bc9e1f28b36a2a3a: Scheduling FlushDeltaMemStoresOp(061aaf5bcf924900833957edc42cab04): perf score=14.095187
I20260812 06:20:21.687043 22919 heavy-update-compaction-itest.cc:229] Time spent updating: real 5.160s	user 1.901s	sys 0.174s
I20260812 06:20:21.690773 23097 maintenance_manager.cc:643] P a169b45d5a1a4211bc9e1f28b36a2a3a: FlushDeltaMemStoresOp(061aaf5bcf924900833957edc42cab04) complete. Timing: real 0.063s	user 0.034s	sys 0.019s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":25126,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:20:21.691344 23206 maintenance_manager.cc:419] P a169b45d5a1a4211bc9e1f28b36a2a3a: Scheduling FlushDeltaMemStoresOp(061aaf5bcf924900833957edc42cab04): perf score=2.188937
I20260812 06:20:21.708559 23097 maintenance_manager.cc:643] P a169b45d5a1a4211bc9e1f28b36a2a3a: FlushDeltaMemStoresOp(061aaf5bcf924900833957edc42cab04) complete. Timing: real 0.017s	user 0.012s	sys 0.004s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":6872,"lbm_writes_lt_1ms":103,"reinsert_count":0,"spinlock_wait_cycles":2048,"update_count":500}
I20260812 06:20:21.709017 23206 maintenance_manager.cc:419] P a169b45d5a1a4211bc9e1f28b36a2a3a: Scheduling MajorDeltaCompactionOp(061aaf5bcf924900833957edc42cab04): perf score=1.000000
I20260812 06:20:21.742825 22919 heavy-update-compaction-itest.cc:265] Time spent scanning: real 0.055s	user 0.002s	sys 0.000s
I20260812 06:20:21.743541 22919 tablet_server.cc:179] TabletServer@127.22.97.193:0 shutting down...
I20260812 06:20:21.827198 23097 maintenance_manager.cc:643] P a169b45d5a1a4211bc9e1f28b36a2a3a: MajorDeltaCompactionOp(061aaf5bcf924900833957edc42cab04) complete. Timing: real 0.118s	user 0.102s	sys 0.016s Metrics: {"cfile_cache_hit":354,"cfile_cache_hit_bytes":14482251,"cfile_cache_miss":178,"cfile_cache_miss_bytes":10292437,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":492,"lbm_read_time_us":4416,"lbm_reads_lt_1ms":210,"lbm_write_time_us":26937,"lbm_writes_lt_1ms":543,"mutex_wait_us":93,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":64000,"update_count":2500}
I20260812 06:20:21.828087 22919 ts_tablet_manager.cc:1507] Shutting down tablet manager...
I20260812 06:20:21.828570 22919 tablet_replica.cc:333] T 061aaf5bcf924900833957edc42cab04 P a169b45d5a1a4211bc9e1f28b36a2a3a: stopping tablet replica
I20260812 06:20:21.828886 22919 raft_consensus.cc:2243] T 061aaf5bcf924900833957edc42cab04 P a169b45d5a1a4211bc9e1f28b36a2a3a [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:20:21.829172 22919 raft_consensus.cc:2272] T 061aaf5bcf924900833957edc42cab04 P a169b45d5a1a4211bc9e1f28b36a2a3a [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:20:21.846632 22919 tablet_server.cc:196] TabletServer@127.22.97.193:0 shutdown complete.
I20260812 06:20:21.874577 22919 master.cc:562] Master@127.22.97.254:40727 shutting down...
I20260812 06:20:21.880987 22919 raft_consensus.cc:2243] T 00000000000000000000000000000000 P 27a404240c924b61b31551403395d507 [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:20:21.881220 22919 raft_consensus.cc:2272] T 00000000000000000000000000000000 P 27a404240c924b61b31551403395d507 [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:20:21.881335 22919 tablet_replica.cc:333] T 00000000000000000000000000000000 P 27a404240c924b61b31551403395d507: stopping tablet replica
I20260812 06:20:21.895278 22919 master.cc:584] Master@127.22.97.254:40727 shutdown complete.
[       OK ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/0 (5764 ms)
[ RUN      ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/1
I20260812 06:20:22.010968 22919 internal_mini_cluster.cc:156] Creating distributed mini masters. Addrs: 127.22.97.254:35303
I20260812 06:20:22.011463 22919 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:20:22.014407 23249 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:20:22.014511 23253 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:20:22.014608 22919 server_base.cc:1061] running on GCE node
W20260812 06:20:22.014640 23251 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:20:22.014851 22919 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:20:22.014901 22919 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:20:22.014918 22919 hybrid_clock.cc:648] HybridClock initialized: now 1786515622014919 us; error 0 us; skew 500 ppm
I20260812 06:20:22.015820 22919 webserver.cc:533] Webserver started at http://127.22.97.254:42385/ using document root <none> and password file <none>
I20260812 06:20:22.015995 22919 fs_manager.cc:362] Metadata directory not provided
I20260812 06:20:22.016041 22919 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:20:22.016103 22919 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:20:22.016501 22919 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskdP7EeR/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515616224519-22919-0/minicluster-data/master-0-root/instance:
uuid: "d81575c6679448c78bf06323230e20c2"
format_stamp: "Formatted at 2026-08-12 06:20:22 on dist-test-slave-7f01"
I20260812 06:20:22.018184 22919 fs_manager.cc:696] Time spent creating directory manager: real 0.001s	user 0.000s	sys 0.002s
I20260812 06:20:22.019353 23263 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:20:22.019685 22919 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.000s	sys 0.001s
I20260812 06:20:22.019817 22919 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskdP7EeR/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515616224519-22919-0/minicluster-data/master-0-root
uuid: "d81575c6679448c78bf06323230e20c2"
format_stamp: "Formatted at 2026-08-12 06:20:22 on dist-test-slave-7f01"
I20260812 06:20:22.019902 22919 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskdP7EeR/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515616224519-22919-0/minicluster-data/master-0-root
metadata directory: /tmp/dist-test-taskdP7EeR/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515616224519-22919-0/minicluster-data/master-0-root
1 data directories: /tmp/dist-test-taskdP7EeR/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515616224519-22919-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:20:22.049762 22919 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:20:22.050243 22919 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:20:22.054687 22919 rpc_server.cc:307] RPC server started. Bound to: 127.22.97.254:35303
I20260812 06:20:22.057768 23354 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.22.97.254:35303 every 8 connection(s)
I20260812 06:20:22.061244 23357 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:20:22.063268 23357 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P d81575c6679448c78bf06323230e20c2: Bootstrap starting.
I20260812 06:20:22.064236 23357 tablet_bootstrap.cc:654] T 00000000000000000000000000000000 P d81575c6679448c78bf06323230e20c2: Neither blocks nor log segments found. Creating new log.
I20260812 06:20:22.065315 23357 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P d81575c6679448c78bf06323230e20c2: No bootstrap required, opened a new log
I20260812 06:20:22.065763 23357 raft_consensus.cc:359] T 00000000000000000000000000000000 P d81575c6679448c78bf06323230e20c2 [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "d81575c6679448c78bf06323230e20c2" member_type: VOTER }
I20260812 06:20:22.065855 23357 raft_consensus.cc:385] T 00000000000000000000000000000000 P d81575c6679448c78bf06323230e20c2 [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:20:22.065878 23357 raft_consensus.cc:740] T 00000000000000000000000000000000 P d81575c6679448c78bf06323230e20c2 [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: d81575c6679448c78bf06323230e20c2, State: Initialized, Role: FOLLOWER
I20260812 06:20:22.066090 23357 consensus_queue.cc:260] T 00000000000000000000000000000000 P d81575c6679448c78bf06323230e20c2 [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: "d81575c6679448c78bf06323230e20c2" member_type: VOTER }
I20260812 06:20:22.066179 23357 raft_consensus.cc:399] T 00000000000000000000000000000000 P d81575c6679448c78bf06323230e20c2 [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:20:22.066203 23357 raft_consensus.cc:493] T 00000000000000000000000000000000 P d81575c6679448c78bf06323230e20c2 [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:20:22.066234 23357 raft_consensus.cc:3060] T 00000000000000000000000000000000 P d81575c6679448c78bf06323230e20c2 [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:20:22.066902 23357 raft_consensus.cc:515] T 00000000000000000000000000000000 P d81575c6679448c78bf06323230e20c2 [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "d81575c6679448c78bf06323230e20c2" member_type: VOTER }
I20260812 06:20:22.067044 23357 leader_election.cc:304] T 00000000000000000000000000000000 P d81575c6679448c78bf06323230e20c2 [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: d81575c6679448c78bf06323230e20c2; no voters: 
I20260812 06:20:22.067181 23357 leader_election.cc:290] T 00000000000000000000000000000000 P d81575c6679448c78bf06323230e20c2 [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:20:22.067332 23361 raft_consensus.cc:2804] T 00000000000000000000000000000000 P d81575c6679448c78bf06323230e20c2 [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:20:22.067529 23361 raft_consensus.cc:697] T 00000000000000000000000000000000 P d81575c6679448c78bf06323230e20c2 [term 1 LEADER]: Becoming Leader. State: Replica: d81575c6679448c78bf06323230e20c2, State: Running, Role: LEADER
I20260812 06:20:22.067689 23357 sys_catalog.cc:565] T 00000000000000000000000000000000 P d81575c6679448c78bf06323230e20c2 [sys.catalog]: configured and running, proceeding with master startup.
I20260812 06:20:22.067711 23361 consensus_queue.cc:237] T 00000000000000000000000000000000 P d81575c6679448c78bf06323230e20c2 [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: "d81575c6679448c78bf06323230e20c2" member_type: VOTER }
I20260812 06:20:22.068193 23362 sys_catalog.cc:455] T 00000000000000000000000000000000 P d81575c6679448c78bf06323230e20c2 [sys.catalog]: SysCatalogTable state changed. Reason: RaftConsensus started. Latest consensus state: current_term: 1 leader_uuid: "d81575c6679448c78bf06323230e20c2" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "d81575c6679448c78bf06323230e20c2" member_type: VOTER } }
I20260812 06:20:22.068207 23363 sys_catalog.cc:455] T 00000000000000000000000000000000 P d81575c6679448c78bf06323230e20c2 [sys.catalog]: SysCatalogTable state changed. Reason: New leader d81575c6679448c78bf06323230e20c2. Latest consensus state: current_term: 1 leader_uuid: "d81575c6679448c78bf06323230e20c2" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "d81575c6679448c78bf06323230e20c2" member_type: VOTER } }
I20260812 06:20:22.068315 23363 sys_catalog.cc:458] T 00000000000000000000000000000000 P d81575c6679448c78bf06323230e20c2 [sys.catalog]: This master's current role is: LEADER
I20260812 06:20:22.068550 23362 sys_catalog.cc:458] T 00000000000000000000000000000000 P d81575c6679448c78bf06323230e20c2 [sys.catalog]: This master's current role is: LEADER
I20260812 06:20:22.069023 23370 catalog_manager.cc:1511] Loading table and tablet metadata into memory...
I20260812 06:20:22.069707 23370 catalog_manager.cc:1520] Initializing Kudu cluster ID...
I20260812 06:20:22.069957 22919 internal_mini_cluster.cc:184] Waiting to initialize catalog manager on master 0
I20260812 06:20:22.071579 23370 catalog_manager.cc:1383] Generated new cluster ID: 8daa2a81059f4e939d3e7d0eddfe5fd2
I20260812 06:20:22.071640 23370 catalog_manager.cc:1531] Initializing Kudu internal certificate authority...
I20260812 06:20:22.089341 23370 catalog_manager.cc:1406] Generated new certificate authority record
I20260812 06:20:22.089931 23370 catalog_manager.cc:1540] Loading token signing keys...
I20260812 06:20:22.096845 23370 catalog_manager.cc:6092] T 00000000000000000000000000000000 P d81575c6679448c78bf06323230e20c2: Generated new TSK 0
I20260812 06:20:22.097054 23370 catalog_manager.cc:1550] Initializing in-progress tserver states...
I20260812 06:20:22.102300 22919 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:20:22.104763 23395 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:20:22.104769 23392 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:20:22.104782 23391 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:20:22.105150 22919 server_base.cc:1061] running on GCE node
I20260812 06:20:22.105360 22919 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:20:22.105400 22919 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:20:22.105417 22919 hybrid_clock.cc:648] HybridClock initialized: now 1786515622105417 us; error 0 us; skew 500 ppm
I20260812 06:20:22.106274 22919 webserver.cc:533] Webserver started at http://127.22.97.193:38181/ using document root <none> and password file <none>
I20260812 06:20:22.106473 22919 fs_manager.cc:362] Metadata directory not provided
I20260812 06:20:22.106549 22919 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:20:22.106657 22919 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:20:22.107087 22919 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskdP7EeR/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515616224519-22919-0/minicluster-data/ts-0-root/instance:
uuid: "73e367e3d4e14f8dbfb383271bc75f2e"
format_stamp: "Formatted at 2026-08-12 06:20:22 on dist-test-slave-7f01"
I20260812 06:20:22.108707 22919 fs_manager.cc:696] Time spent creating directory manager: real 0.001s	user 0.002s	sys 0.000s
I20260812 06:20:22.109678 23402 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:20:22.109935 22919 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.001s	sys 0.000s
I20260812 06:20:22.110031 22919 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskdP7EeR/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515616224519-22919-0/minicluster-data/ts-0-root
uuid: "73e367e3d4e14f8dbfb383271bc75f2e"
format_stamp: "Formatted at 2026-08-12 06:20:22 on dist-test-slave-7f01"
I20260812 06:20:22.110116 22919 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskdP7EeR/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515616224519-22919-0/minicluster-data/ts-0-root
metadata directory: /tmp/dist-test-taskdP7EeR/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515616224519-22919-0/minicluster-data/ts-0-root
1 data directories: /tmp/dist-test-taskdP7EeR/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515616224519-22919-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:20:22.125294 22919 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:20:22.125669 22919 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:20:22.125993 22919 txn_system_client.cc:432] TxnSystemClient initialization is disabled...
I20260812 06:20:22.126462 22919 ts_tablet_manager.cc:585] Loaded tablet metadata (0 total tablets, 0 live tablets)
I20260812 06:20:22.126529 22919 ts_tablet_manager.cc:531] Time spent load tablet metadata: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:20:22.126581 22919 ts_tablet_manager.cc:616] Registered 0 tablets
I20260812 06:20:22.126633 22919 ts_tablet_manager.cc:595] Time spent register tablets: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:20:22.131326 22919 rpc_server.cc:307] RPC server started. Bound to: 127.22.97.193:42223
I20260812 06:20:22.133018 23510 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.22.97.193:42223 every 8 connection(s)
I20260812 06:20:22.141816 23512 heartbeater.cc:344] Connected to a master server at 127.22.97.254:35303
I20260812 06:20:22.141969 23512 heartbeater.cc:461] Registering TS with master...
I20260812 06:20:22.142217 23512 heartbeater.cc:507] Master 127.22.97.254:35303 requested a full tablet report, sending...
I20260812 06:20:22.143004 23297 ts_manager.cc:194] Registered new tserver with Master: 73e367e3d4e14f8dbfb383271bc75f2e (127.22.97.193:42223)
I20260812 06:20:22.143503 22919 internal_mini_cluster.cc:371] 1 TS(s) registered with all masters after 0.011298528s
I20260812 06:20:22.144177 23297 master_service.cc:502] Signed X509 certificate for tserver {username='slave'} at 127.0.0.1:41634
I20260812 06:20:22.153538 23297 catalog_manager.cc:2283] Servicing CreateTable request from {username='slave'} at 127.0.0.1:41636:
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:20:22.162555 23445 tablet_service.cc:1511] Processing CreateTablet for tablet 69101d24565b48d79f53ebb54a175042 (DEFAULT_TABLE table=heavy-update-compaction-test [id=e487e7606b0b454b87ed7a2348b79c37]), partition=
I20260812 06:20:22.162859 23445 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet 69101d24565b48d79f53ebb54a175042. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:20:22.164889 23527 tablet_bootstrap.cc:492] T 69101d24565b48d79f53ebb54a175042 P 73e367e3d4e14f8dbfb383271bc75f2e: Bootstrap starting.
I20260812 06:20:22.165774 23527 tablet_bootstrap.cc:654] T 69101d24565b48d79f53ebb54a175042 P 73e367e3d4e14f8dbfb383271bc75f2e: Neither blocks nor log segments found. Creating new log.
I20260812 06:20:22.167127 23527 tablet_bootstrap.cc:492] T 69101d24565b48d79f53ebb54a175042 P 73e367e3d4e14f8dbfb383271bc75f2e: No bootstrap required, opened a new log
I20260812 06:20:22.167270 23527 ts_tablet_manager.cc:1403] T 69101d24565b48d79f53ebb54a175042 P 73e367e3d4e14f8dbfb383271bc75f2e: Time spent bootstrapping tablet: real 0.002s	user 0.002s	sys 0.000s
I20260812 06:20:22.167822 23527 raft_consensus.cc:359] T 69101d24565b48d79f53ebb54a175042 P 73e367e3d4e14f8dbfb383271bc75f2e [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "73e367e3d4e14f8dbfb383271bc75f2e" member_type: VOTER last_known_addr { host: "127.22.97.193" port: 42223 } }
I20260812 06:20:22.167956 23527 raft_consensus.cc:385] T 69101d24565b48d79f53ebb54a175042 P 73e367e3d4e14f8dbfb383271bc75f2e [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:20:22.168011 23527 raft_consensus.cc:740] T 69101d24565b48d79f53ebb54a175042 P 73e367e3d4e14f8dbfb383271bc75f2e [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: 73e367e3d4e14f8dbfb383271bc75f2e, State: Initialized, Role: FOLLOWER
I20260812 06:20:22.168167 23527 consensus_queue.cc:260] T 69101d24565b48d79f53ebb54a175042 P 73e367e3d4e14f8dbfb383271bc75f2e [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: "73e367e3d4e14f8dbfb383271bc75f2e" member_type: VOTER last_known_addr { host: "127.22.97.193" port: 42223 } }
I20260812 06:20:22.168256 23527 raft_consensus.cc:399] T 69101d24565b48d79f53ebb54a175042 P 73e367e3d4e14f8dbfb383271bc75f2e [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:20:22.168319 23527 raft_consensus.cc:493] T 69101d24565b48d79f53ebb54a175042 P 73e367e3d4e14f8dbfb383271bc75f2e [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:20:22.168380 23527 raft_consensus.cc:3060] T 69101d24565b48d79f53ebb54a175042 P 73e367e3d4e14f8dbfb383271bc75f2e [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:20:22.169126 23527 raft_consensus.cc:515] T 69101d24565b48d79f53ebb54a175042 P 73e367e3d4e14f8dbfb383271bc75f2e [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "73e367e3d4e14f8dbfb383271bc75f2e" member_type: VOTER last_known_addr { host: "127.22.97.193" port: 42223 } }
I20260812 06:20:22.169247 23527 leader_election.cc:304] T 69101d24565b48d79f53ebb54a175042 P 73e367e3d4e14f8dbfb383271bc75f2e [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: 73e367e3d4e14f8dbfb383271bc75f2e; no voters: 
I20260812 06:20:22.169487 23527 leader_election.cc:290] T 69101d24565b48d79f53ebb54a175042 P 73e367e3d4e14f8dbfb383271bc75f2e [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:20:22.169625 23530 raft_consensus.cc:2804] T 69101d24565b48d79f53ebb54a175042 P 73e367e3d4e14f8dbfb383271bc75f2e [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:20:22.169800 23530 raft_consensus.cc:697] T 69101d24565b48d79f53ebb54a175042 P 73e367e3d4e14f8dbfb383271bc75f2e [term 1 LEADER]: Becoming Leader. State: Replica: 73e367e3d4e14f8dbfb383271bc75f2e, State: Running, Role: LEADER
I20260812 06:20:22.169864 23527 ts_tablet_manager.cc:1434] T 69101d24565b48d79f53ebb54a175042 P 73e367e3d4e14f8dbfb383271bc75f2e: Time spent starting tablet: real 0.003s	user 0.003s	sys 0.000s
I20260812 06:20:22.169900 23512 heartbeater.cc:499] Master 127.22.97.254:35303 was elected leader, sending a full tablet report...
I20260812 06:20:22.170007 23530 consensus_queue.cc:237] T 69101d24565b48d79f53ebb54a175042 P 73e367e3d4e14f8dbfb383271bc75f2e [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: "73e367e3d4e14f8dbfb383271bc75f2e" member_type: VOTER last_known_addr { host: "127.22.97.193" port: 42223 } }
I20260812 06:20:22.171451 23297 catalog_manager.cc:5719] T 69101d24565b48d79f53ebb54a175042 P 73e367e3d4e14f8dbfb383271bc75f2e reported cstate change: term changed from 0 to 1, leader changed from <none> to 73e367e3d4e14f8dbfb383271bc75f2e (127.22.97.193). New cstate: current_term: 1 leader_uuid: "73e367e3d4e14f8dbfb383271bc75f2e" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "73e367e3d4e14f8dbfb383271bc75f2e" member_type: VOTER last_known_addr { host: "127.22.97.193" port: 42223 } health_report { overall_health: HEALTHY } } }
I20260812 06:20:22.235275 22919 heavy-update-compaction-itest.cc:215] Time spent inserting: real 0.057s	user 0.011s	sys 0.012s
I20260812 06:20:22.383658 23513 maintenance_manager.cc:419] P 73e367e3d4e14f8dbfb383271bc75f2e: Scheduling FlushMRSOp(69101d24565b48d79f53ebb54a175042): perf score=19.054940
I20260812 06:20:22.537887 23409 maintenance_manager.cc:643] P 73e367e3d4e14f8dbfb383271bc75f2e: FlushMRSOp(69101d24565b48d79f53ebb54a175042) complete. Timing: real 0.154s	user 0.100s	sys 0.052s Metrics: {"bytes_written":9025567,"cfile_init":1,"delete_count":0,"dirs.queue_time_us":74,"dirs.run_cpu_time_us":182,"dirs.run_wall_time_us":950,"drs_written":1,"lbm_read_time_us":36,"lbm_reads_lt_1ms":4,"lbm_write_time_us":39429,"lbm_writes_lt_1ms":677,"peak_mem_usage":0,"reinsert_count":0,"rows_written":104,"update_count":1100}
I20260812 06:20:22.538719 23513 maintenance_manager.cc:419] P 73e367e3d4e14f8dbfb383271bc75f2e: Scheduling LogGCOp(69101d24565b48d79f53ebb54a175042): free 20743831 bytes of WAL
I20260812 06:20:22.539002 23409 log_reader.cc:385] T 69101d24565b48d79f53ebb54a175042: removed 2 log segments from log reader
I20260812 06:20:22.539052 23409 log.cc:1079] T 69101d24565b48d79f53ebb54a175042 P 73e367e3d4e14f8dbfb383271bc75f2e: Deleting log segment in path: /tmp/dist-test-taskdP7EeR/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515616224519-22919-0/minicluster-data/ts-0-root/wals/69101d24565b48d79f53ebb54a175042/wal-000000001 (ops 1-6)
I20260812 06:20:22.539083 23409 log.cc:1079] T 69101d24565b48d79f53ebb54a175042 P 73e367e3d4e14f8dbfb383271bc75f2e: Deleting log segment in path: /tmp/dist-test-taskdP7EeR/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515616224519-22919-0/minicluster-data/ts-0-root/wals/69101d24565b48d79f53ebb54a175042/wal-000000002 (ops 7-11)
I20260812 06:20:22.543972 23409 maintenance_manager.cc:643] P 73e367e3d4e14f8dbfb383271bc75f2e: LogGCOp(69101d24565b48d79f53ebb54a175042) complete. Timing: real 0.005s	user 0.000s	sys 0.005s Metrics: {}
I20260812 06:20:22.544534 23513 maintenance_manager.cc:419] P 73e367e3d4e14f8dbfb383271bc75f2e: Scheduling FlushDeltaMemStoresOp(69101d24565b48d79f53ebb54a175042): perf score=2.188937
I20260812 06:20:22.558862 23409 maintenance_manager.cc:643] P 73e367e3d4e14f8dbfb383271bc75f2e: FlushDeltaMemStoresOp(69101d24565b48d79f53ebb54a175042) complete. Timing: real 0.014s	user 0.007s	sys 0.002s Metrics: {"bytes_written":3282155,"delete_count":0,"lbm_write_time_us":4511,"lbm_writes_lt_1ms":83,"reinsert_count":0,"update_count":400}
I20260812 06:20:22.559285 23513 maintenance_manager.cc:419] P 73e367e3d4e14f8dbfb383271bc75f2e: Scheduling MajorDeltaCompactionOp(69101d24565b48d79f53ebb54a175042): perf score=1.000000
I20260812 06:20:22.693806 23409 maintenance_manager.cc:643] P 73e367e3d4e14f8dbfb383271bc75f2e: MajorDeltaCompactionOp(69101d24565b48d79f53ebb54a175042) complete. Timing: real 0.134s	user 0.083s	sys 0.050s Metrics: {"cfile_cache_miss":332,"cfile_cache_miss_bytes":16569850,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":516,"lbm_read_time_us":10119,"lbm_reads_lt_1ms":368,"lbm_write_time_us":21910,"lbm_writes_lt_1ms":343,"mutex_wait_us":36,"peak_mem_usage":38262756,"reinsert_count":0,"spinlock_wait_cycles":9728,"thread_start_us":333,"threads_started":5,"update_count":1500}
I20260812 06:20:22.694566 23513 maintenance_manager.cc:419] P 73e367e3d4e14f8dbfb383271bc75f2e: Scheduling UndoDeltaBlockGCOp(69101d24565b48d79f53ebb54a175042): 16411395 bytes on disk
I20260812 06:20:22.695221 23409 maintenance_manager.cc:643] P 73e367e3d4e14f8dbfb383271bc75f2e: UndoDeltaBlockGCOp(69101d24565b48d79f53ebb54a175042) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":153,"lbm_reads_lt_1ms":4}
I20260812 06:20:22.695832 23513 maintenance_manager.cc:419] P 73e367e3d4e14f8dbfb383271bc75f2e: Scheduling FlushDeltaMemStoresOp(69101d24565b48d79f53ebb54a175042): perf score=10.126437
I20260812 06:20:22.740712 23409 maintenance_manager.cc:643] P 73e367e3d4e14f8dbfb383271bc75f2e: FlushDeltaMemStoresOp(69101d24565b48d79f53ebb54a175042) complete. Timing: real 0.045s	user 0.022s	sys 0.012s Metrics: {"bytes_written":12307491,"delete_count":0,"lbm_write_time_us":15494,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:20:22.741195 23513 maintenance_manager.cc:419] P 73e367e3d4e14f8dbfb383271bc75f2e: Scheduling FlushDeltaMemStoresOp(69101d24565b48d79f53ebb54a175042): perf score=2.188937
I20260812 06:20:22.752555 23409 maintenance_manager.cc:643] P 73e367e3d4e14f8dbfb383271bc75f2e: FlushDeltaMemStoresOp(69101d24565b48d79f53ebb54a175042) complete. Timing: real 0.011s	user 0.006s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4320,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:22.753358 23513 maintenance_manager.cc:419] P 73e367e3d4e14f8dbfb383271bc75f2e: Scheduling MajorDeltaCompactionOp(69101d24565b48d79f53ebb54a175042): perf score=1.000000
I20260812 06:20:22.889323 23409 maintenance_manager.cc:643] P 73e367e3d4e14f8dbfb383271bc75f2e: MajorDeltaCompactionOp(69101d24565b48d79f53ebb54a175042) complete. Timing: real 0.136s	user 0.101s	sys 0.033s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672278,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":247,"lbm_read_time_us":9639,"lbm_reads_lt_1ms":472,"lbm_write_time_us":25251,"lbm_writes_lt_1ms":443,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":7680,"update_count":2000}
I20260812 06:20:22.889914 23513 maintenance_manager.cc:419] P 73e367e3d4e14f8dbfb383271bc75f2e: Scheduling FlushDeltaMemStoresOp(69101d24565b48d79f53ebb54a175042): perf score=10.126437
I20260812 06:20:22.940142 23409 maintenance_manager.cc:643] P 73e367e3d4e14f8dbfb383271bc75f2e: FlushDeltaMemStoresOp(69101d24565b48d79f53ebb54a175042) complete. Timing: real 0.050s	user 0.017s	sys 0.024s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":18419,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:20:22.940632 23513 maintenance_manager.cc:419] P 73e367e3d4e14f8dbfb383271bc75f2e: Scheduling FlushDeltaMemStoresOp(69101d24565b48d79f53ebb54a175042): perf score=2.188937
I20260812 06:20:22.953405 23409 maintenance_manager.cc:643] P 73e367e3d4e14f8dbfb383271bc75f2e: FlushDeltaMemStoresOp(69101d24565b48d79f53ebb54a175042) complete. Timing: real 0.013s	user 0.010s	sys 0.001s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4949,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:22.954046 23513 maintenance_manager.cc:419] P 73e367e3d4e14f8dbfb383271bc75f2e: Scheduling MajorDeltaCompactionOp(69101d24565b48d79f53ebb54a175042): perf score=1.000000
I20260812 06:20:23.102735 23409 maintenance_manager.cc:643] P 73e367e3d4e14f8dbfb383271bc75f2e: MajorDeltaCompactionOp(69101d24565b48d79f53ebb54a175042) complete. Timing: real 0.148s	user 0.101s	sys 0.047s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672277,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":616,"lbm_read_time_us":8985,"lbm_reads_lt_1ms":472,"lbm_write_time_us":29261,"lbm_writes_lt_1ms":443,"mutex_wait_us":323,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":169088,"update_count":2000}
I20260812 06:20:23.103454 23513 maintenance_manager.cc:419] P 73e367e3d4e14f8dbfb383271bc75f2e: Scheduling FlushDeltaMemStoresOp(69101d24565b48d79f53ebb54a175042): perf score=10.126437
I20260812 06:20:23.146703 23409 maintenance_manager.cc:643] P 73e367e3d4e14f8dbfb383271bc75f2e: FlushDeltaMemStoresOp(69101d24565b48d79f53ebb54a175042) complete. Timing: real 0.043s	user 0.021s	sys 0.019s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":14791,"lbm_writes_lt_1ms":303,"reinsert_count":0,"spinlock_wait_cycles":12544,"update_count":1500}
I20260812 06:20:23.147430 23513 maintenance_manager.cc:419] P 73e367e3d4e14f8dbfb383271bc75f2e: Scheduling FlushDeltaMemStoresOp(69101d24565b48d79f53ebb54a175042): perf score=2.188937
I20260812 06:20:23.158447 23409 maintenance_manager.cc:643] P 73e367e3d4e14f8dbfb383271bc75f2e: FlushDeltaMemStoresOp(69101d24565b48d79f53ebb54a175042) complete. Timing: real 0.011s	user 0.002s	sys 0.007s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4402,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:23.158952 23513 maintenance_manager.cc:419] P 73e367e3d4e14f8dbfb383271bc75f2e: Scheduling MajorDeltaCompactionOp(69101d24565b48d79f53ebb54a175042): perf score=1.000000
I20260812 06:20:23.319556 23409 maintenance_manager.cc:643] P 73e367e3d4e14f8dbfb383271bc75f2e: MajorDeltaCompactionOp(69101d24565b48d79f53ebb54a175042) complete. Timing: real 0.160s	user 0.128s	sys 0.032s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672276,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":225,"lbm_read_time_us":11955,"lbm_reads_lt_1ms":472,"lbm_write_time_us":24109,"lbm_writes_lt_1ms":443,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":4480,"update_count":2000}
I20260812 06:20:23.320364 23513 maintenance_manager.cc:419] P 73e367e3d4e14f8dbfb383271bc75f2e: Scheduling FlushDeltaMemStoresOp(69101d24565b48d79f53ebb54a175042): perf score=10.126437
I20260812 06:20:23.367398 23409 maintenance_manager.cc:643] P 73e367e3d4e14f8dbfb383271bc75f2e: FlushDeltaMemStoresOp(69101d24565b48d79f53ebb54a175042) complete. Timing: real 0.047s	user 0.027s	sys 0.012s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":18576,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:20:23.367977 23513 maintenance_manager.cc:419] P 73e367e3d4e14f8dbfb383271bc75f2e: Scheduling FlushDeltaMemStoresOp(69101d24565b48d79f53ebb54a175042): perf score=2.188937
I20260812 06:20:23.379371 23409 maintenance_manager.cc:643] P 73e367e3d4e14f8dbfb383271bc75f2e: FlushDeltaMemStoresOp(69101d24565b48d79f53ebb54a175042) complete. Timing: real 0.011s	user 0.009s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4247,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:23.380160 23513 maintenance_manager.cc:419] P 73e367e3d4e14f8dbfb383271bc75f2e: Scheduling MajorDeltaCompactionOp(69101d24565b48d79f53ebb54a175042): perf score=1.000000
I20260812 06:20:23.515825 23409 maintenance_manager.cc:643] P 73e367e3d4e14f8dbfb383271bc75f2e: MajorDeltaCompactionOp(69101d24565b48d79f53ebb54a175042) complete. Timing: real 0.135s	user 0.107s	sys 0.028s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672277,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":191,"lbm_read_time_us":10791,"lbm_reads_lt_1ms":472,"lbm_write_time_us":25643,"lbm_writes_lt_1ms":443,"mutex_wait_us":2,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":4736,"update_count":2000}
I20260812 06:20:23.516407 23513 maintenance_manager.cc:419] P 73e367e3d4e14f8dbfb383271bc75f2e: Scheduling FlushDeltaMemStoresOp(69101d24565b48d79f53ebb54a175042): perf score=10.126437
I20260812 06:20:23.563920 23409 maintenance_manager.cc:643] P 73e367e3d4e14f8dbfb383271bc75f2e: FlushDeltaMemStoresOp(69101d24565b48d79f53ebb54a175042) complete. Timing: real 0.047s	user 0.034s	sys 0.012s Metrics: {"bytes_written":12307489,"delete_count":0,"lbm_write_time_us":21113,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:20:23.564399 23513 maintenance_manager.cc:419] P 73e367e3d4e14f8dbfb383271bc75f2e: Scheduling MajorDeltaCompactionOp(69101d24565b48d79f53ebb54a175042): perf score=1.000000
I20260812 06:20:23.671451 23409 maintenance_manager.cc:643] P 73e367e3d4e14f8dbfb383271bc75f2e: MajorDeltaCompactionOp(69101d24565b48d79f53ebb54a175042) complete. Timing: real 0.107s	user 0.094s	sys 0.013s Metrics: {"cfile_cache_miss":331,"cfile_cache_miss_bytes":16569745,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":1,"delta_iterators_relevant":1,"dirs.queue_time_us":958,"lbm_read_time_us":6694,"lbm_reads_lt_1ms":363,"lbm_write_time_us":22316,"lbm_writes_lt_1ms":343,"mutex_wait_us":306,"peak_mem_usage":38262756,"reinsert_count":0,"spinlock_wait_cycles":8704,"update_count":1500}
I20260812 06:20:23.671985 23513 maintenance_manager.cc:419] P 73e367e3d4e14f8dbfb383271bc75f2e: Scheduling FlushDeltaMemStoresOp(69101d24565b48d79f53ebb54a175042): perf score=10.126437
I20260812 06:20:23.732196 23409 maintenance_manager.cc:643] P 73e367e3d4e14f8dbfb383271bc75f2e: FlushDeltaMemStoresOp(69101d24565b48d79f53ebb54a175042) complete. Timing: real 0.060s	user 0.023s	sys 0.016s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":18075,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:20:23.732774 23513 maintenance_manager.cc:419] P 73e367e3d4e14f8dbfb383271bc75f2e: Scheduling FlushDeltaMemStoresOp(69101d24565b48d79f53ebb54a175042): perf score=2.188937
I20260812 06:20:23.743587 23409 maintenance_manager.cc:643] P 73e367e3d4e14f8dbfb383271bc75f2e: FlushDeltaMemStoresOp(69101d24565b48d79f53ebb54a175042) complete. Timing: real 0.011s	user 0.001s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4347,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:23.744184 23513 maintenance_manager.cc:419] P 73e367e3d4e14f8dbfb383271bc75f2e: Scheduling MajorDeltaCompactionOp(69101d24565b48d79f53ebb54a175042): perf score=1.000000
I20260812 06:20:23.904691 23409 maintenance_manager.cc:643] P 73e367e3d4e14f8dbfb383271bc75f2e: MajorDeltaCompactionOp(69101d24565b48d79f53ebb54a175042) complete. Timing: real 0.160s	user 0.109s	sys 0.048s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672277,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":276,"lbm_read_time_us":11682,"lbm_reads_lt_1ms":472,"lbm_write_time_us":26683,"lbm_writes_lt_1ms":443,"peak_mem_usage":50689328,"reinsert_count":0,"update_count":2000}
I20260812 06:20:23.905493 23513 maintenance_manager.cc:419] P 73e367e3d4e14f8dbfb383271bc75f2e: Scheduling FlushDeltaMemStoresOp(69101d24565b48d79f53ebb54a175042): perf score=11.118625
I20260812 06:20:23.946038 23409 maintenance_manager.cc:643] P 73e367e3d4e14f8dbfb383271bc75f2e: FlushDeltaMemStoresOp(69101d24565b48d79f53ebb54a175042) complete. Timing: real 0.040s	user 0.025s	sys 0.013s Metrics: {"bytes_written":12717734,"delete_count":0,"lbm_write_time_us":18197,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:20:23.946636 23513 maintenance_manager.cc:419] P 73e367e3d4e14f8dbfb383271bc75f2e: Scheduling FlushDeltaMemStoresOp(69101d24565b48d79f53ebb54a175042): perf score=2.188937
I20260812 06:20:23.964059 23409 maintenance_manager.cc:643] P 73e367e3d4e14f8dbfb383271bc75f2e: FlushDeltaMemStoresOp(69101d24565b48d79f53ebb54a175042) complete. Timing: real 0.017s	user 0.009s	sys 0.008s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":6443,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:20:23.964602 23513 maintenance_manager.cc:419] P 73e367e3d4e14f8dbfb383271bc75f2e: Scheduling FlushMRSOp(69101d24565b48d79f53ebb54a175042): perf score=1.000000
I20260812 06:20:23.991268 23409 maintenance_manager.cc:643] P 73e367e3d4e14f8dbfb383271bc75f2e: FlushMRSOp(69101d24565b48d79f53ebb54a175042) complete. Timing: real 0.026s	user 0.025s	sys 0.000s Metrics: {"bytes_written":1234473,"cfile_init":1,"dirs.queue_time_us":89,"dirs.run_cpu_time_us":260,"dirs.run_wall_time_us":1580,"drs_written":1,"lbm_read_time_us":37,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1477,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":30}
I20260812 06:20:23.992046 23513 maintenance_manager.cc:419] P 73e367e3d4e14f8dbfb383271bc75f2e: Scheduling LogGCOp(69101d24565b48d79f53ebb54a175042): free 120553428 bytes of WAL
I20260812 06:20:23.992280 23409 log_reader.cc:385] T 69101d24565b48d79f53ebb54a175042: removed 12 log segments from log reader
I20260812 06:20:23.992333 23409 log.cc:1079] T 69101d24565b48d79f53ebb54a175042 P 73e367e3d4e14f8dbfb383271bc75f2e: Deleting log segment in path: /tmp/dist-test-taskdP7EeR/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515616224519-22919-0/minicluster-data/ts-0-root/wals/69101d24565b48d79f53ebb54a175042/wal-000000003 (ops 12-16)
I20260812 06:20:23.992363 23409 log.cc:1079] T 69101d24565b48d79f53ebb54a175042 P 73e367e3d4e14f8dbfb383271bc75f2e: Deleting log segment in path: /tmp/dist-test-taskdP7EeR/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515616224519-22919-0/minicluster-data/ts-0-root/wals/69101d24565b48d79f53ebb54a175042/wal-000000004 (ops 17-20)
I20260812 06:20:23.992408 23409 log.cc:1079] T 69101d24565b48d79f53ebb54a175042 P 73e367e3d4e14f8dbfb383271bc75f2e: Deleting log segment in path: /tmp/dist-test-taskdP7EeR/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515616224519-22919-0/minicluster-data/ts-0-root/wals/69101d24565b48d79f53ebb54a175042/wal-000000005 (ops 21-25)
I20260812 06:20:23.992455 23409 log.cc:1079] T 69101d24565b48d79f53ebb54a175042 P 73e367e3d4e14f8dbfb383271bc75f2e: Deleting log segment in path: /tmp/dist-test-taskdP7EeR/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515616224519-22919-0/minicluster-data/ts-0-root/wals/69101d24565b48d79f53ebb54a175042/wal-000000006 (ops 26-30)
I20260812 06:20:23.992496 23409 log.cc:1079] T 69101d24565b48d79f53ebb54a175042 P 73e367e3d4e14f8dbfb383271bc75f2e: Deleting log segment in path: /tmp/dist-test-taskdP7EeR/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515616224519-22919-0/minicluster-data/ts-0-root/wals/69101d24565b48d79f53ebb54a175042/wal-000000007 (ops 31-34)
I20260812 06:20:23.992535 23409 log.cc:1079] T 69101d24565b48d79f53ebb54a175042 P 73e367e3d4e14f8dbfb383271bc75f2e: Deleting log segment in path: /tmp/dist-test-taskdP7EeR/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515616224519-22919-0/minicluster-data/ts-0-root/wals/69101d24565b48d79f53ebb54a175042/wal-000000008 (ops 35-39)
I20260812 06:20:23.992595 23409 log.cc:1079] T 69101d24565b48d79f53ebb54a175042 P 73e367e3d4e14f8dbfb383271bc75f2e: Deleting log segment in path: /tmp/dist-test-taskdP7EeR/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515616224519-22919-0/minicluster-data/ts-0-root/wals/69101d24565b48d79f53ebb54a175042/wal-000000009 (ops 40-44)
I20260812 06:20:23.992635 23409 log.cc:1079] T 69101d24565b48d79f53ebb54a175042 P 73e367e3d4e14f8dbfb383271bc75f2e: Deleting log segment in path: /tmp/dist-test-taskdP7EeR/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515616224519-22919-0/minicluster-data/ts-0-root/wals/69101d24565b48d79f53ebb54a175042/wal-000000010 (ops 45-49)
I20260812 06:20:23.992673 23409 log.cc:1079] T 69101d24565b48d79f53ebb54a175042 P 73e367e3d4e14f8dbfb383271bc75f2e: Deleting log segment in path: /tmp/dist-test-taskdP7EeR/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515616224519-22919-0/minicluster-data/ts-0-root/wals/69101d24565b48d79f53ebb54a175042/wal-000000011 (ops 50-54)
I20260812 06:20:23.992712 23409 log.cc:1079] T 69101d24565b48d79f53ebb54a175042 P 73e367e3d4e14f8dbfb383271bc75f2e: Deleting log segment in path: /tmp/dist-test-taskdP7EeR/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515616224519-22919-0/minicluster-data/ts-0-root/wals/69101d24565b48d79f53ebb54a175042/wal-000000012 (ops 55-59)
I20260812 06:20:23.992750 23409 log.cc:1079] T 69101d24565b48d79f53ebb54a175042 P 73e367e3d4e14f8dbfb383271bc75f2e: Deleting log segment in path: /tmp/dist-test-taskdP7EeR/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515616224519-22919-0/minicluster-data/ts-0-root/wals/69101d24565b48d79f53ebb54a175042/wal-000000013 (ops 60-64)
I20260812 06:20:23.992789 23409 log.cc:1079] T 69101d24565b48d79f53ebb54a175042 P 73e367e3d4e14f8dbfb383271bc75f2e: Deleting log segment in path: /tmp/dist-test-taskdP7EeR/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515616224519-22919-0/minicluster-data/ts-0-root/wals/69101d24565b48d79f53ebb54a175042/wal-000000014 (ops 65-69)
I20260812 06:20:24.021217 23409 maintenance_manager.cc:643] P 73e367e3d4e14f8dbfb383271bc75f2e: LogGCOp(69101d24565b48d79f53ebb54a175042) complete. Timing: real 0.029s	user 0.000s	sys 0.028s Metrics: {}
I20260812 06:20:24.021858 23513 maintenance_manager.cc:419] P 73e367e3d4e14f8dbfb383271bc75f2e: Scheduling FlushDeltaMemStoresOp(69101d24565b48d79f53ebb54a175042): perf score=2.188937
I20260812 06:20:24.040191 23409 maintenance_manager.cc:643] P 73e367e3d4e14f8dbfb383271bc75f2e: FlushDeltaMemStoresOp(69101d24565b48d79f53ebb54a175042) complete. Timing: real 0.018s	user 0.007s	sys 0.004s Metrics: {"bytes_written":4184708,"delete_count":0,"lbm_write_time_us":4586,"lbm_writes_lt_1ms":105,"reinsert_count":0,"update_count":510}
I20260812 06:20:24.040640 23513 maintenance_manager.cc:419] P 73e367e3d4e14f8dbfb383271bc75f2e: Scheduling UndoDeltaBlockGCOp(69101d24565b48d79f53ebb54a175042): 472 bytes on disk
I20260812 06:20:24.041046 23409 maintenance_manager.cc:643] P 73e367e3d4e14f8dbfb383271bc75f2e: UndoDeltaBlockGCOp(69101d24565b48d79f53ebb54a175042) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":51,"lbm_reads_lt_1ms":4}
I20260812 06:20:24.041488 23513 maintenance_manager.cc:419] P 73e367e3d4e14f8dbfb383271bc75f2e: Scheduling FlushDeltaMemStoresOp(69101d24565b48d79f53ebb54a175042): perf score=2.188937
I20260812 06:20:24.052582 23409 maintenance_manager.cc:643] P 73e367e3d4e14f8dbfb383271bc75f2e: FlushDeltaMemStoresOp(69101d24565b48d79f53ebb54a175042) complete. Timing: real 0.011s	user 0.001s	sys 0.009s Metrics: {"bytes_written":4020609,"delete_count":0,"lbm_write_time_us":4591,"lbm_writes_lt_1ms":101,"reinsert_count":0,"update_count":490}
I20260812 06:20:24.052975 23513 maintenance_manager.cc:419] P 73e367e3d4e14f8dbfb383271bc75f2e: Scheduling MajorDeltaCompactionOp(69101d24565b48d79f53ebb54a175042): perf score=1.000000
I20260812 06:20:24.264230 23409 maintenance_manager.cc:643] P 73e367e3d4e14f8dbfb383271bc75f2e: MajorDeltaCompactionOp(69101d24565b48d79f53ebb54a175042) complete. Timing: real 0.211s	user 0.140s	sys 0.070s Metrics: {"cfile_cache_miss":634,"cfile_cache_miss_bytes":28877328,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":123,"lbm_read_time_us":14808,"lbm_reads_lt_1ms":674,"lbm_write_time_us":37820,"lbm_writes_lt_1ms":643,"mutex_wait_us":23,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":13440,"thread_start_us":81,"threads_started":1,"update_count":3000}
I20260812 06:20:24.264995 23513 maintenance_manager.cc:419] P 73e367e3d4e14f8dbfb383271bc75f2e: Scheduling FlushDeltaMemStoresOp(69101d24565b48d79f53ebb54a175042): perf score=15.087375
I20260812 06:20:24.321961 23409 maintenance_manager.cc:643] P 73e367e3d4e14f8dbfb383271bc75f2e: FlushDeltaMemStoresOp(69101d24565b48d79f53ebb54a175042) complete. Timing: real 0.057s	user 0.025s	sys 0.029s Metrics: {"bytes_written":16820143,"delete_count":0,"lbm_write_time_us":28140,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":412,"reinsert_count":0,"update_count":2050}
I20260812 06:20:24.322439 23513 maintenance_manager.cc:419] P 73e367e3d4e14f8dbfb383271bc75f2e: Scheduling FlushDeltaMemStoresOp(69101d24565b48d79f53ebb54a175042): perf score=2.188937
I20260812 06:20:24.341602 23409 maintenance_manager.cc:643] P 73e367e3d4e14f8dbfb383271bc75f2e: FlushDeltaMemStoresOp(69101d24565b48d79f53ebb54a175042) complete. Timing: real 0.019s	user 0.005s	sys 0.004s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":4380,"lbm_writes_lt_1ms":93,"reinsert_count":0,"spinlock_wait_cycles":768,"update_count":450}
I20260812 06:20:24.342113 23513 maintenance_manager.cc:419] P 73e367e3d4e14f8dbfb383271bc75f2e: Scheduling FlushDeltaMemStoresOp(69101d24565b48d79f53ebb54a175042): perf score=2.188937
I20260812 06:20:24.357126 23409 maintenance_manager.cc:643] P 73e367e3d4e14f8dbfb383271bc75f2e: FlushDeltaMemStoresOp(69101d24565b48d79f53ebb54a175042) complete. Timing: real 0.015s	user 0.010s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6085,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:24.357688 23513 maintenance_manager.cc:419] P 73e367e3d4e14f8dbfb383271bc75f2e: Scheduling MajorDeltaCompactionOp(69101d24565b48d79f53ebb54a175042): perf score=1.000000
I20260812 06:20:24.571152 23409 maintenance_manager.cc:643] P 73e367e3d4e14f8dbfb383271bc75f2e: MajorDeltaCompactionOp(69101d24565b48d79f53ebb54a175042) complete. Timing: real 0.213s	user 0.136s	sys 0.075s Metrics: {"cfile_cache_miss":633,"cfile_cache_miss_bytes":28877207,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":3150,"lbm_read_time_us":14992,"lbm_reads_lt_1ms":673,"lbm_write_time_us":35691,"lbm_writes_lt_1ms":643,"mutex_wait_us":1400,"peak_mem_usage":75542472,"reinsert_count":0,"update_count":3000}
I20260812 06:20:24.572017 23513 maintenance_manager.cc:419] P 73e367e3d4e14f8dbfb383271bc75f2e: Scheduling FlushDeltaMemStoresOp(69101d24565b48d79f53ebb54a175042): perf score=14.095187
I20260812 06:20:24.623836 23409 maintenance_manager.cc:643] P 73e367e3d4e14f8dbfb383271bc75f2e: FlushDeltaMemStoresOp(69101d24565b48d79f53ebb54a175042) complete. Timing: real 0.052s	user 0.038s	sys 0.008s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":21098,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:20:24.624529 23513 maintenance_manager.cc:419] P 73e367e3d4e14f8dbfb383271bc75f2e: Scheduling FlushDeltaMemStoresOp(69101d24565b48d79f53ebb54a175042): perf score=2.188937
I20260812 06:20:24.635680 23409 maintenance_manager.cc:643] P 73e367e3d4e14f8dbfb383271bc75f2e: FlushDeltaMemStoresOp(69101d24565b48d79f53ebb54a175042) complete. Timing: real 0.011s	user 0.002s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4508,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:24.636235 23513 maintenance_manager.cc:419] P 73e367e3d4e14f8dbfb383271bc75f2e: Scheduling MajorDeltaCompactionOp(69101d24565b48d79f53ebb54a175042): perf score=1.000000
I20260812 06:20:24.827900 23409 maintenance_manager.cc:643] P 73e367e3d4e14f8dbfb383271bc75f2e: MajorDeltaCompactionOp(69101d24565b48d79f53ebb54a175042) complete. Timing: real 0.191s	user 0.137s	sys 0.050s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774688,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":991,"lbm_read_time_us":13600,"lbm_reads_lt_1ms":572,"lbm_write_time_us":33478,"lbm_writes_lt_1ms":543,"mutex_wait_us":118,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":3456,"update_count":2500}
I20260812 06:20:24.828706 23513 maintenance_manager.cc:419] P 73e367e3d4e14f8dbfb383271bc75f2e: Scheduling FlushDeltaMemStoresOp(69101d24565b48d79f53ebb54a175042): perf score=11.118625
I20260812 06:20:24.881796 23409 maintenance_manager.cc:643] P 73e367e3d4e14f8dbfb383271bc75f2e: FlushDeltaMemStoresOp(69101d24565b48d79f53ebb54a175042) complete. Timing: real 0.053s	user 0.027s	sys 0.024s Metrics: {"bytes_written":13004905,"delete_count":0,"lbm_write_time_us":18545,"lbm_writes_lt_1ms":320,"reinsert_count":0,"update_count":1585}
I20260812 06:20:24.882400 23513 maintenance_manager.cc:419] P 73e367e3d4e14f8dbfb383271bc75f2e: Scheduling FlushDeltaMemStoresOp(69101d24565b48d79f53ebb54a175042): perf score=2.188937
I20260812 06:20:24.903906 23409 maintenance_manager.cc:643] P 73e367e3d4e14f8dbfb383271bc75f2e: FlushDeltaMemStoresOp(69101d24565b48d79f53ebb54a175042) complete. Timing: real 0.021s	user 0.013s	sys 0.003s Metrics: {"bytes_written":3815484,"delete_count":0,"lbm_write_time_us":6407,"lbm_writes_lt_1ms":96,"reinsert_count":0,"update_count":465}
I20260812 06:20:24.904489 23513 maintenance_manager.cc:419] P 73e367e3d4e14f8dbfb383271bc75f2e: Scheduling FlushDeltaMemStoresOp(69101d24565b48d79f53ebb54a175042): perf score=2.188937
I20260812 06:20:24.918664 23409 maintenance_manager.cc:643] P 73e367e3d4e14f8dbfb383271bc75f2e: FlushDeltaMemStoresOp(69101d24565b48d79f53ebb54a175042) complete. Timing: real 0.014s	user 0.012s	sys 0.000s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":5565,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:20:24.919196 23513 maintenance_manager.cc:419] P 73e367e3d4e14f8dbfb383271bc75f2e: Scheduling MajorDeltaCompactionOp(69101d24565b48d79f53ebb54a175042): perf score=1.000000
I20260812 06:20:25.106936 23409 maintenance_manager.cc:643] P 73e367e3d4e14f8dbfb383271bc75f2e: MajorDeltaCompactionOp(69101d24565b48d79f53ebb54a175042) complete. Timing: real 0.188s	user 0.113s	sys 0.071s Metrics: {"cfile_cache_miss":533,"cfile_cache_miss_bytes":24774794,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":711,"lbm_read_time_us":13266,"lbm_reads_lt_1ms":573,"lbm_write_time_us":30348,"lbm_writes_lt_1ms":543,"peak_mem_usage":63115900,"reinsert_count":0,"update_count":2500}
I20260812 06:20:25.107627 23513 maintenance_manager.cc:419] P 73e367e3d4e14f8dbfb383271bc75f2e: Scheduling FlushDeltaMemStoresOp(69101d24565b48d79f53ebb54a175042): perf score=14.095187
I20260812 06:20:25.166458 23409 maintenance_manager.cc:643] P 73e367e3d4e14f8dbfb383271bc75f2e: FlushDeltaMemStoresOp(69101d24565b48d79f53ebb54a175042) complete. Timing: real 0.059s	user 0.032s	sys 0.020s Metrics: {"bytes_written":16409906,"delete_count":0,"lbm_write_time_us":20466,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:20:25.167155 23513 maintenance_manager.cc:419] P 73e367e3d4e14f8dbfb383271bc75f2e: Scheduling FlushDeltaMemStoresOp(69101d24565b48d79f53ebb54a175042): perf score=2.188937
I20260812 06:20:25.183293 23409 maintenance_manager.cc:643] P 73e367e3d4e14f8dbfb383271bc75f2e: FlushDeltaMemStoresOp(69101d24565b48d79f53ebb54a175042) complete. Timing: real 0.016s	user 0.010s	sys 0.003s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6095,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:25.183974 23513 maintenance_manager.cc:419] P 73e367e3d4e14f8dbfb383271bc75f2e: Scheduling MajorDeltaCompactionOp(69101d24565b48d79f53ebb54a175042): perf score=1.000000
I20260812 06:20:25.376010 23409 maintenance_manager.cc:643] P 73e367e3d4e14f8dbfb383271bc75f2e: MajorDeltaCompactionOp(69101d24565b48d79f53ebb54a175042) complete. Timing: real 0.192s	user 0.127s	sys 0.053s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774693,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":505,"lbm_read_time_us":14098,"lbm_reads_lt_1ms":572,"lbm_write_time_us":31580,"lbm_writes_lt_1ms":543,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":13568,"update_count":2500}
I20260812 06:20:25.376778 23513 maintenance_manager.cc:419] P 73e367e3d4e14f8dbfb383271bc75f2e: Scheduling FlushDeltaMemStoresOp(69101d24565b48d79f53ebb54a175042): perf score=14.095187
I20260812 06:20:25.445192 23409 maintenance_manager.cc:643] P 73e367e3d4e14f8dbfb383271bc75f2e: FlushDeltaMemStoresOp(69101d24565b48d79f53ebb54a175042) complete. Timing: real 0.068s	user 0.031s	sys 0.027s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":22287,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:20:25.445788 23513 maintenance_manager.cc:419] P 73e367e3d4e14f8dbfb383271bc75f2e: Scheduling FlushDeltaMemStoresOp(69101d24565b48d79f53ebb54a175042): perf score=2.188937
I20260812 06:20:25.457268 23409 maintenance_manager.cc:643] P 73e367e3d4e14f8dbfb383271bc75f2e: FlushDeltaMemStoresOp(69101d24565b48d79f53ebb54a175042) complete. Timing: real 0.011s	user 0.005s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4415,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:25.457816 23513 maintenance_manager.cc:419] P 73e367e3d4e14f8dbfb383271bc75f2e: Scheduling FlushMRSOp(69101d24565b48d79f53ebb54a175042): perf score=1.000000
I20260812 06:20:25.490394 23409 maintenance_manager.cc:643] P 73e367e3d4e14f8dbfb383271bc75f2e: FlushMRSOp(69101d24565b48d79f53ebb54a175042) complete. Timing: real 0.032s	user 0.029s	sys 0.000s Metrics: {"bytes_written":1152514,"cfile_init":1,"dirs.queue_time_us":78,"dirs.run_cpu_time_us":232,"dirs.run_wall_time_us":1642,"drs_written":1,"lbm_read_time_us":69,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1528,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":28}
I20260812 06:20:25.491245 23513 maintenance_manager.cc:419] P 73e367e3d4e14f8dbfb383271bc75f2e: Scheduling UndoDeltaBlockGCOp(69101d24565b48d79f53ebb54a175042): 447 bytes on disk
I20260812 06:20:25.491791 23409 maintenance_manager.cc:643] P 73e367e3d4e14f8dbfb383271bc75f2e: UndoDeltaBlockGCOp(69101d24565b48d79f53ebb54a175042) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":70,"lbm_reads_lt_1ms":4}
I20260812 06:20:25.492339 23513 maintenance_manager.cc:419] P 73e367e3d4e14f8dbfb383271bc75f2e: Scheduling MajorDeltaCompactionOp(69101d24565b48d79f53ebb54a175042): perf score=1.000000
I20260812 06:20:25.674644 23409 maintenance_manager.cc:643] P 73e367e3d4e14f8dbfb383271bc75f2e: MajorDeltaCompactionOp(69101d24565b48d79f53ebb54a175042) complete. Timing: real 0.182s	user 0.093s	sys 0.086s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774689,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":568,"lbm_read_time_us":13756,"lbm_reads_lt_1ms":564,"lbm_write_time_us":30874,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":542,"mutex_wait_us":40,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":51328,"update_count":2500}
I20260812 06:20:25.675495 23513 maintenance_manager.cc:419] P 73e367e3d4e14f8dbfb383271bc75f2e: Scheduling LogGCOp(69101d24565b48d79f53ebb54a175042): free 120553395 bytes of WAL
I20260812 06:20:25.675905 23409 log_reader.cc:385] T 69101d24565b48d79f53ebb54a175042: removed 12 log segments from log reader
I20260812 06:20:25.676024 23409 log.cc:1079] T 69101d24565b48d79f53ebb54a175042 P 73e367e3d4e14f8dbfb383271bc75f2e: Deleting log segment in path: /tmp/dist-test-taskdP7EeR/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515616224519-22919-0/minicluster-data/ts-0-root/wals/69101d24565b48d79f53ebb54a175042/wal-000000015 (ops 70-74)
I20260812 06:20:25.676088 23409 log.cc:1079] T 69101d24565b48d79f53ebb54a175042 P 73e367e3d4e14f8dbfb383271bc75f2e: Deleting log segment in path: /tmp/dist-test-taskdP7EeR/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515616224519-22919-0/minicluster-data/ts-0-root/wals/69101d24565b48d79f53ebb54a175042/wal-000000016 (ops 75-79)
I20260812 06:20:25.676142 23409 log.cc:1079] T 69101d24565b48d79f53ebb54a175042 P 73e367e3d4e14f8dbfb383271bc75f2e: Deleting log segment in path: /tmp/dist-test-taskdP7EeR/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515616224519-22919-0/minicluster-data/ts-0-root/wals/69101d24565b48d79f53ebb54a175042/wal-000000017 (ops 80-84)
I20260812 06:20:25.676195 23409 log.cc:1079] T 69101d24565b48d79f53ebb54a175042 P 73e367e3d4e14f8dbfb383271bc75f2e: Deleting log segment in path: /tmp/dist-test-taskdP7EeR/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515616224519-22919-0/minicluster-data/ts-0-root/wals/69101d24565b48d79f53ebb54a175042/wal-000000018 (ops 85-88)
I20260812 06:20:25.676244 23409 log.cc:1079] T 69101d24565b48d79f53ebb54a175042 P 73e367e3d4e14f8dbfb383271bc75f2e: Deleting log segment in path: /tmp/dist-test-taskdP7EeR/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515616224519-22919-0/minicluster-data/ts-0-root/wals/69101d24565b48d79f53ebb54a175042/wal-000000019 (ops 89-93)
I20260812 06:20:25.676371 23409 log.cc:1079] T 69101d24565b48d79f53ebb54a175042 P 73e367e3d4e14f8dbfb383271bc75f2e: Deleting log segment in path: /tmp/dist-test-taskdP7EeR/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515616224519-22919-0/minicluster-data/ts-0-root/wals/69101d24565b48d79f53ebb54a175042/wal-000000020 (ops 94-98)
I20260812 06:20:25.676435 23409 log.cc:1079] T 69101d24565b48d79f53ebb54a175042 P 73e367e3d4e14f8dbfb383271bc75f2e: Deleting log segment in path: /tmp/dist-test-taskdP7EeR/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515616224519-22919-0/minicluster-data/ts-0-root/wals/69101d24565b48d79f53ebb54a175042/wal-000000021 (ops 99-102)
I20260812 06:20:25.676471 23409 log.cc:1079] T 69101d24565b48d79f53ebb54a175042 P 73e367e3d4e14f8dbfb383271bc75f2e: Deleting log segment in path: /tmp/dist-test-taskdP7EeR/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515616224519-22919-0/minicluster-data/ts-0-root/wals/69101d24565b48d79f53ebb54a175042/wal-000000022 (ops 103-107)
I20260812 06:20:25.676518 23409 log.cc:1079] T 69101d24565b48d79f53ebb54a175042 P 73e367e3d4e14f8dbfb383271bc75f2e: Deleting log segment in path: /tmp/dist-test-taskdP7EeR/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515616224519-22919-0/minicluster-data/ts-0-root/wals/69101d24565b48d79f53ebb54a175042/wal-000000023 (ops 108-112)
I20260812 06:20:25.676566 23409 log.cc:1079] T 69101d24565b48d79f53ebb54a175042 P 73e367e3d4e14f8dbfb383271bc75f2e: Deleting log segment in path: /tmp/dist-test-taskdP7EeR/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515616224519-22919-0/minicluster-data/ts-0-root/wals/69101d24565b48d79f53ebb54a175042/wal-000000024 (ops 113-117)
I20260812 06:20:25.676614 23409 log.cc:1079] T 69101d24565b48d79f53ebb54a175042 P 73e367e3d4e14f8dbfb383271bc75f2e: Deleting log segment in path: /tmp/dist-test-taskdP7EeR/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515616224519-22919-0/minicluster-data/ts-0-root/wals/69101d24565b48d79f53ebb54a175042/wal-000000025 (ops 118-122)
I20260812 06:20:25.676661 23409 log.cc:1079] T 69101d24565b48d79f53ebb54a175042 P 73e367e3d4e14f8dbfb383271bc75f2e: Deleting log segment in path: /tmp/dist-test-taskdP7EeR/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515616224519-22919-0/minicluster-data/ts-0-root/wals/69101d24565b48d79f53ebb54a175042/wal-000000026 (ops 123-127)
I20260812 06:20:25.709632 23409 maintenance_manager.cc:643] P 73e367e3d4e14f8dbfb383271bc75f2e: LogGCOp(69101d24565b48d79f53ebb54a175042) complete. Timing: real 0.034s	user 0.000s	sys 0.031s Metrics: {}
I20260812 06:20:25.710932 23513 maintenance_manager.cc:419] P 73e367e3d4e14f8dbfb383271bc75f2e: Scheduling FlushDeltaMemStoresOp(69101d24565b48d79f53ebb54a175042): perf score=17.071750
I20260812 06:20:25.789680 23409 maintenance_manager.cc:643] P 73e367e3d4e14f8dbfb383271bc75f2e: FlushDeltaMemStoresOp(69101d24565b48d79f53ebb54a175042) complete. Timing: real 0.079s	user 0.040s	sys 0.026s Metrics: {"bytes_written":18748279,"delete_count":0,"lbm_write_time_us":26800,"lbm_writes_lt_1ms":460,"reinsert_count":0,"update_count":2285}
I20260812 06:20:25.790303 23513 maintenance_manager.cc:419] P 73e367e3d4e14f8dbfb383271bc75f2e: Scheduling FlushDeltaMemStoresOp(69101d24565b48d79f53ebb54a175042): perf score=4.173312
I20260812 06:20:25.805025 23409 maintenance_manager.cc:643] P 73e367e3d4e14f8dbfb383271bc75f2e: FlushDeltaMemStoresOp(69101d24565b48d79f53ebb54a175042) complete. Timing: real 0.014s	user 0.008s	sys 0.005s Metrics: {"bytes_written":5866708,"delete_count":0,"lbm_write_time_us":6045,"lbm_writes_lt_1ms":146,"reinsert_count":0,"update_count":715}
I20260812 06:20:25.805537 23513 maintenance_manager.cc:419] P 73e367e3d4e14f8dbfb383271bc75f2e: Scheduling MajorDeltaCompactionOp(69101d24565b48d79f53ebb54a175042): perf score=1.000000
I20260812 06:20:26.023341 23409 maintenance_manager.cc:643] P 73e367e3d4e14f8dbfb383271bc75f2e: MajorDeltaCompactionOp(69101d24565b48d79f53ebb54a175042) complete. Timing: real 0.218s	user 0.152s	sys 0.065s Metrics: {"cfile_cache_miss":632,"cfile_cache_miss_bytes":28877109,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":163,"lbm_read_time_us":17377,"lbm_reads_lt_1ms":672,"lbm_write_time_us":36121,"lbm_writes_lt_1ms":643,"mutex_wait_us":28,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":9216,"update_count":3000}
I20260812 06:20:26.024214 23513 maintenance_manager.cc:419] P 73e367e3d4e14f8dbfb383271bc75f2e: Scheduling FlushDeltaMemStoresOp(69101d24565b48d79f53ebb54a175042): perf score=14.095187
I20260812 06:20:26.089258 23409 maintenance_manager.cc:643] P 73e367e3d4e14f8dbfb383271bc75f2e: FlushDeltaMemStoresOp(69101d24565b48d79f53ebb54a175042) complete. Timing: real 0.064s	user 0.024s	sys 0.037s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":25639,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":402,"reinsert_count":0,"update_count":2000}
I20260812 06:20:26.089803 23513 maintenance_manager.cc:419] P 73e367e3d4e14f8dbfb383271bc75f2e: Scheduling FlushDeltaMemStoresOp(69101d24565b48d79f53ebb54a175042): perf score=2.188937
I20260812 06:20:26.104751 23409 maintenance_manager.cc:643] P 73e367e3d4e14f8dbfb383271bc75f2e: FlushDeltaMemStoresOp(69101d24565b48d79f53ebb54a175042) complete. Timing: real 0.015s	user 0.001s	sys 0.010s Metrics: {"bytes_written":4143684,"delete_count":0,"lbm_write_time_us":4688,"lbm_writes_lt_1ms":104,"reinsert_count":0,"update_count":505}
I20260812 06:20:26.105217 23513 maintenance_manager.cc:419] P 73e367e3d4e14f8dbfb383271bc75f2e: Scheduling FlushDeltaMemStoresOp(69101d24565b48d79f53ebb54a175042): perf score=2.188937
I20260812 06:20:26.116271 23409 maintenance_manager.cc:643] P 73e367e3d4e14f8dbfb383271bc75f2e: FlushDeltaMemStoresOp(69101d24565b48d79f53ebb54a175042) complete. Timing: real 0.011s	user 0.001s	sys 0.009s Metrics: {"bytes_written":4061633,"delete_count":0,"lbm_write_time_us":4562,"lbm_writes_lt_1ms":102,"reinsert_count":0,"update_count":495}
I20260812 06:20:26.116732 23513 maintenance_manager.cc:419] P 73e367e3d4e14f8dbfb383271bc75f2e: Scheduling MajorDeltaCompactionOp(69101d24565b48d79f53ebb54a175042): perf score=1.000000
I20260812 06:20:26.339956 23409 maintenance_manager.cc:643] P 73e367e3d4e14f8dbfb383271bc75f2e: MajorDeltaCompactionOp(69101d24565b48d79f53ebb54a175042) complete. Timing: real 0.223s	user 0.130s	sys 0.093s Metrics: {"cfile_cache_miss":633,"cfile_cache_miss_bytes":28877218,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":269,"lbm_read_time_us":16261,"lbm_reads_lt_1ms":673,"lbm_write_time_us":38733,"lbm_writes_lt_1ms":643,"mutex_wait_us":45,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":9344,"update_count":3000}
I20260812 06:20:26.340663 23513 maintenance_manager.cc:419] P 73e367e3d4e14f8dbfb383271bc75f2e: Scheduling FlushDeltaMemStoresOp(69101d24565b48d79f53ebb54a175042): perf score=14.095187
I20260812 06:20:26.396936 23409 maintenance_manager.cc:643] P 73e367e3d4e14f8dbfb383271bc75f2e: FlushDeltaMemStoresOp(69101d24565b48d79f53ebb54a175042) complete. Timing: real 0.056s	user 0.043s	sys 0.011s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":24598,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":402,"reinsert_count":0,"update_count":2000}
I20260812 06:20:26.397658 23513 maintenance_manager.cc:419] P 73e367e3d4e14f8dbfb383271bc75f2e: Scheduling FlushDeltaMemStoresOp(69101d24565b48d79f53ebb54a175042): perf score=2.188937
I20260812 06:20:26.419329 23409 maintenance_manager.cc:643] P 73e367e3d4e14f8dbfb383271bc75f2e: FlushDeltaMemStoresOp(69101d24565b48d79f53ebb54a175042) complete. Timing: real 0.021s	user 0.012s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6942,"lbm_writes_lt_1ms":103,"reinsert_count":0,"spinlock_wait_cycles":1408,"update_count":500}
I20260812 06:20:26.419935 23513 maintenance_manager.cc:419] P 73e367e3d4e14f8dbfb383271bc75f2e: Scheduling MajorDeltaCompactionOp(69101d24565b48d79f53ebb54a175042): perf score=1.000000
I20260812 06:20:26.598891 23409 maintenance_manager.cc:643] P 73e367e3d4e14f8dbfb383271bc75f2e: MajorDeltaCompactionOp(69101d24565b48d79f53ebb54a175042) complete. Timing: real 0.179s	user 0.118s	sys 0.061s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774689,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":626,"lbm_read_time_us":11500,"lbm_reads_lt_1ms":564,"lbm_write_time_us":33148,"lbm_writes_lt_1ms":543,"mutex_wait_us":291,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":9088,"update_count":2500}
I20260812 06:20:26.599727 23513 maintenance_manager.cc:419] P 73e367e3d4e14f8dbfb383271bc75f2e: Scheduling FlushDeltaMemStoresOp(69101d24565b48d79f53ebb54a175042): perf score=14.095187
I20260812 06:20:26.658114 23409 maintenance_manager.cc:643] P 73e367e3d4e14f8dbfb383271bc75f2e: FlushDeltaMemStoresOp(69101d24565b48d79f53ebb54a175042) complete. Timing: real 0.058s	user 0.047s	sys 0.009s Metrics: {"bytes_written":16409899,"delete_count":0,"lbm_write_time_us":26288,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:20:26.658679 23513 maintenance_manager.cc:419] P 73e367e3d4e14f8dbfb383271bc75f2e: Scheduling FlushDeltaMemStoresOp(69101d24565b48d79f53ebb54a175042): perf score=2.188937
I20260812 06:20:26.672940 23409 maintenance_manager.cc:643] P 73e367e3d4e14f8dbfb383271bc75f2e: FlushDeltaMemStoresOp(69101d24565b48d79f53ebb54a175042) complete. Timing: real 0.014s	user 0.008s	sys 0.005s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5411,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:26.673475 23513 maintenance_manager.cc:419] P 73e367e3d4e14f8dbfb383271bc75f2e: Scheduling MajorDeltaCompactionOp(69101d24565b48d79f53ebb54a175042): perf score=1.000000
I20260812 06:20:26.855013 23409 maintenance_manager.cc:643] P 73e367e3d4e14f8dbfb383271bc75f2e: MajorDeltaCompactionOp(69101d24565b48d79f53ebb54a175042) complete. Timing: real 0.181s	user 0.126s	sys 0.052s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774686,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":305,"lbm_read_time_us":12781,"lbm_reads_lt_1ms":568,"lbm_write_time_us":31360,"lbm_writes_lt_1ms":543,"mutex_wait_us":2,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":2304,"update_count":2500}
I20260812 06:20:26.855715 23513 maintenance_manager.cc:419] P 73e367e3d4e14f8dbfb383271bc75f2e: Scheduling FlushDeltaMemStoresOp(69101d24565b48d79f53ebb54a175042): perf score=14.095187
I20260812 06:20:26.915946 23409 maintenance_manager.cc:643] P 73e367e3d4e14f8dbfb383271bc75f2e: FlushDeltaMemStoresOp(69101d24565b48d79f53ebb54a175042) complete. Timing: real 0.060s	user 0.044s	sys 0.016s Metrics: {"bytes_written":16409903,"delete_count":0,"lbm_write_time_us":22738,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:20:26.916520 23513 maintenance_manager.cc:419] P 73e367e3d4e14f8dbfb383271bc75f2e: Scheduling FlushDeltaMemStoresOp(69101d24565b48d79f53ebb54a175042): perf score=2.188937
I20260812 06:20:26.928217 23409 maintenance_manager.cc:643] P 73e367e3d4e14f8dbfb383271bc75f2e: FlushDeltaMemStoresOp(69101d24565b48d79f53ebb54a175042) complete. Timing: real 0.011s	user 0.009s	sys 0.002s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4445,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:26.928733 23513 maintenance_manager.cc:419] P 73e367e3d4e14f8dbfb383271bc75f2e: Scheduling MajorDeltaCompactionOp(69101d24565b48d79f53ebb54a175042): perf score=1.000000
I20260812 06:20:27.124230 23409 maintenance_manager.cc:643] P 73e367e3d4e14f8dbfb383271bc75f2e: MajorDeltaCompactionOp(69101d24565b48d79f53ebb54a175042) complete. Timing: real 0.195s	user 0.095s	sys 0.090s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774689,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":229,"lbm_read_time_us":14029,"lbm_reads_lt_1ms":572,"lbm_write_time_us":32486,"lbm_writes_lt_1ms":543,"mutex_wait_us":25,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":56704,"update_count":2500}
I20260812 06:20:27.124979 23513 maintenance_manager.cc:419] P 73e367e3d4e14f8dbfb383271bc75f2e: Scheduling FlushDeltaMemStoresOp(69101d24565b48d79f53ebb54a175042): perf score=14.095187
I20260812 06:20:27.180033 23409 maintenance_manager.cc:643] P 73e367e3d4e14f8dbfb383271bc75f2e: FlushDeltaMemStoresOp(69101d24565b48d79f53ebb54a175042) complete. Timing: real 0.055s	user 0.042s	sys 0.009s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":22821,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:20:27.180603 23513 maintenance_manager.cc:419] P 73e367e3d4e14f8dbfb383271bc75f2e: Scheduling FlushDeltaMemStoresOp(69101d24565b48d79f53ebb54a175042): perf score=2.188937
I20260812 06:20:27.201256 23409 maintenance_manager.cc:643] P 73e367e3d4e14f8dbfb383271bc75f2e: FlushDeltaMemStoresOp(69101d24565b48d79f53ebb54a175042) complete. Timing: real 0.020s	user 0.007s	sys 0.012s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4991,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:27.201825 23513 maintenance_manager.cc:419] P 73e367e3d4e14f8dbfb383271bc75f2e: Scheduling FlushMRSOp(69101d24565b48d79f53ebb54a175042): perf score=1.000000
I20260812 06:20:27.235306 23409 maintenance_manager.cc:643] P 73e367e3d4e14f8dbfb383271bc75f2e: FlushMRSOp(69101d24565b48d79f53ebb54a175042) complete. Timing: real 0.033s	user 0.032s	sys 0.000s Metrics: {"bytes_written":1316417,"cfile_init":1,"dirs.queue_time_us":77,"dirs.run_cpu_time_us":182,"dirs.run_wall_time_us":1423,"drs_written":1,"lbm_read_time_us":37,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1815,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":32}
I20260812 06:20:27.236214 23513 maintenance_manager.cc:419] P 73e367e3d4e14f8dbfb383271bc75f2e: Scheduling LogGCOp(69101d24565b48d79f53ebb54a175042): free 128867675 bytes of WAL
I20260812 06:20:27.236487 23409 log_reader.cc:385] T 69101d24565b48d79f53ebb54a175042: removed 13 log segments from log reader
I20260812 06:20:27.236565 23409 log.cc:1079] T 69101d24565b48d79f53ebb54a175042 P 73e367e3d4e14f8dbfb383271bc75f2e: Deleting log segment in path: /tmp/dist-test-taskdP7EeR/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515616224519-22919-0/minicluster-data/ts-0-root/wals/69101d24565b48d79f53ebb54a175042/wal-000000027 (ops 128-132)
I20260812 06:20:27.236617 23409 log.cc:1079] T 69101d24565b48d79f53ebb54a175042 P 73e367e3d4e14f8dbfb383271bc75f2e: Deleting log segment in path: /tmp/dist-test-taskdP7EeR/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515616224519-22919-0/minicluster-data/ts-0-root/wals/69101d24565b48d79f53ebb54a175042/wal-000000028 (ops 133-136)
I20260812 06:20:27.236681 23409 log.cc:1079] T 69101d24565b48d79f53ebb54a175042 P 73e367e3d4e14f8dbfb383271bc75f2e: Deleting log segment in path: /tmp/dist-test-taskdP7EeR/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515616224519-22919-0/minicluster-data/ts-0-root/wals/69101d24565b48d79f53ebb54a175042/wal-000000029 (ops 137-141)
I20260812 06:20:27.236725 23409 log.cc:1079] T 69101d24565b48d79f53ebb54a175042 P 73e367e3d4e14f8dbfb383271bc75f2e: Deleting log segment in path: /tmp/dist-test-taskdP7EeR/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515616224519-22919-0/minicluster-data/ts-0-root/wals/69101d24565b48d79f53ebb54a175042/wal-000000030 (ops 142-146)
I20260812 06:20:27.236763 23409 log.cc:1079] T 69101d24565b48d79f53ebb54a175042 P 73e367e3d4e14f8dbfb383271bc75f2e: Deleting log segment in path: /tmp/dist-test-taskdP7EeR/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515616224519-22919-0/minicluster-data/ts-0-root/wals/69101d24565b48d79f53ebb54a175042/wal-000000031 (ops 147-150)
I20260812 06:20:27.236802 23409 log.cc:1079] T 69101d24565b48d79f53ebb54a175042 P 73e367e3d4e14f8dbfb383271bc75f2e: Deleting log segment in path: /tmp/dist-test-taskdP7EeR/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515616224519-22919-0/minicluster-data/ts-0-root/wals/69101d24565b48d79f53ebb54a175042/wal-000000032 (ops 151-155)
I20260812 06:20:27.236842 23409 log.cc:1079] T 69101d24565b48d79f53ebb54a175042 P 73e367e3d4e14f8dbfb383271bc75f2e: Deleting log segment in path: /tmp/dist-test-taskdP7EeR/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515616224519-22919-0/minicluster-data/ts-0-root/wals/69101d24565b48d79f53ebb54a175042/wal-000000033 (ops 156-160)
I20260812 06:20:27.236882 23409 log.cc:1079] T 69101d24565b48d79f53ebb54a175042 P 73e367e3d4e14f8dbfb383271bc75f2e: Deleting log segment in path: /tmp/dist-test-taskdP7EeR/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515616224519-22919-0/minicluster-data/ts-0-root/wals/69101d24565b48d79f53ebb54a175042/wal-000000034 (ops 161-165)
I20260812 06:20:27.236922 23409 log.cc:1079] T 69101d24565b48d79f53ebb54a175042 P 73e367e3d4e14f8dbfb383271bc75f2e: Deleting log segment in path: /tmp/dist-test-taskdP7EeR/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515616224519-22919-0/minicluster-data/ts-0-root/wals/69101d24565b48d79f53ebb54a175042/wal-000000035 (ops 166-170)
I20260812 06:20:27.236969 23409 log.cc:1079] T 69101d24565b48d79f53ebb54a175042 P 73e367e3d4e14f8dbfb383271bc75f2e: Deleting log segment in path: /tmp/dist-test-taskdP7EeR/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515616224519-22919-0/minicluster-data/ts-0-root/wals/69101d24565b48d79f53ebb54a175042/wal-000000036 (ops 171-175)
I20260812 06:20:27.237010 23409 log.cc:1079] T 69101d24565b48d79f53ebb54a175042 P 73e367e3d4e14f8dbfb383271bc75f2e: Deleting log segment in path: /tmp/dist-test-taskdP7EeR/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515616224519-22919-0/minicluster-data/ts-0-root/wals/69101d24565b48d79f53ebb54a175042/wal-000000037 (ops 176-180)
I20260812 06:20:27.237049 23409 log.cc:1079] T 69101d24565b48d79f53ebb54a175042 P 73e367e3d4e14f8dbfb383271bc75f2e: Deleting log segment in path: /tmp/dist-test-taskdP7EeR/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515616224519-22919-0/minicluster-data/ts-0-root/wals/69101d24565b48d79f53ebb54a175042/wal-000000038 (ops 181-184)
I20260812 06:20:27.237087 23409 log.cc:1079] T 69101d24565b48d79f53ebb54a175042 P 73e367e3d4e14f8dbfb383271bc75f2e: Deleting log segment in path: /tmp/dist-test-taskdP7EeR/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515616224519-22919-0/minicluster-data/ts-0-root/wals/69101d24565b48d79f53ebb54a175042/wal-000000039 (ops 185-189)
I20260812 06:20:27.266995 23409 maintenance_manager.cc:643] P 73e367e3d4e14f8dbfb383271bc75f2e: LogGCOp(69101d24565b48d79f53ebb54a175042) complete. Timing: real 0.031s	user 0.000s	sys 0.027s Metrics: {}
I20260812 06:20:27.267560 23513 maintenance_manager.cc:419] P 73e367e3d4e14f8dbfb383271bc75f2e: Scheduling FlushDeltaMemStoresOp(69101d24565b48d79f53ebb54a175042): perf score=4.173312
I20260812 06:20:27.282114 23409 maintenance_manager.cc:643] P 73e367e3d4e14f8dbfb383271bc75f2e: FlushDeltaMemStoresOp(69101d24565b48d79f53ebb54a175042) complete. Timing: real 0.014s	user 0.012s	sys 0.000s Metrics: {"bytes_written":5620561,"delete_count":0,"lbm_write_time_us":6031,"lbm_writes_lt_1ms":140,"reinsert_count":0,"update_count":685}
I20260812 06:20:27.282570 23513 maintenance_manager.cc:419] P 73e367e3d4e14f8dbfb383271bc75f2e: Scheduling UndoDeltaBlockGCOp(69101d24565b48d79f53ebb54a175042): 493 bytes on disk
I20260812 06:20:27.282979 23409 maintenance_manager.cc:643] P 73e367e3d4e14f8dbfb383271bc75f2e: UndoDeltaBlockGCOp(69101d24565b48d79f53ebb54a175042) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":50,"lbm_reads_lt_1ms":4}
I20260812 06:20:27.283725 23513 maintenance_manager.cc:419] P 73e367e3d4e14f8dbfb383271bc75f2e: Scheduling FlushDeltaMemStoresOp(69101d24565b48d79f53ebb54a175042): perf score=1.196750
I20260812 06:20:27.292076 23409 maintenance_manager.cc:643] P 73e367e3d4e14f8dbfb383271bc75f2e: FlushDeltaMemStoresOp(69101d24565b48d79f53ebb54a175042) complete. Timing: real 0.008s	user 0.007s	sys 0.001s Metrics: {"bytes_written":2584729,"delete_count":0,"lbm_write_time_us":2663,"lbm_writes_lt_1ms":66,"reinsert_count":0,"update_count":315}
I20260812 06:20:27.292610 23513 maintenance_manager.cc:419] P 73e367e3d4e14f8dbfb383271bc75f2e: Scheduling MajorDeltaCompactionOp(69101d24565b48d79f53ebb54a175042): perf score=1.000000
I20260812 06:20:27.487093 22919 heavy-update-compaction-itest.cc:229] Time spent updating: real 5.252s	user 1.940s	sys 0.164s
I20260812 06:20:27.527494 23409 maintenance_manager.cc:643] P 73e367e3d4e14f8dbfb383271bc75f2e: MajorDeltaCompactionOp(69101d24565b48d79f53ebb54a175042) complete. Timing: real 0.235s	user 0.132s	sys 0.099s Metrics: {"cfile_cache_miss":734,"cfile_cache_miss_bytes":32979717,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"lbm_read_time_us":17679,"lbm_reads_lt_1ms":770,"lbm_write_time_us":39518,"lbm_writes_lt_1ms":743,"peak_mem_usage":87969044,"reinsert_count":0,"spinlock_wait_cycles":1408,"update_count":3500}
I20260812 06:20:27.528072 23513 maintenance_manager.cc:419] P 73e367e3d4e14f8dbfb383271bc75f2e: Scheduling FlushDeltaMemStoresOp(69101d24565b48d79f53ebb54a175042): perf score=14.095187
I20260812 06:20:27.562942 23409 maintenance_manager.cc:643] P 73e367e3d4e14f8dbfb383271bc75f2e: FlushDeltaMemStoresOp(69101d24565b48d79f53ebb54a175042) complete. Timing: real 0.035s	user 0.017s	sys 0.017s Metrics: {"bytes_written":16409903,"delete_count":0,"lbm_write_time_us":17200,"lbm_writes_lt_1ms":403,"reinsert_count":0,"spinlock_wait_cycles":1280,"update_count":2000}
I20260812 06:20:27.563501 23513 maintenance_manager.cc:419] P 73e367e3d4e14f8dbfb383271bc75f2e: Scheduling MajorDeltaCompactionOp(69101d24565b48d79f53ebb54a175042): perf score=1.000000
I20260812 06:20:27.595561 22919 heavy-update-compaction-itest.cc:265] Time spent scanning: real 0.108s	user 0.001s	sys 0.000s
I20260812 06:20:27.596211 22919 tablet_server.cc:179] TabletServer@127.22.97.193:0 shutting down...
I20260812 06:20:27.700067 23409 maintenance_manager.cc:643] P 73e367e3d4e14f8dbfb383271bc75f2e: MajorDeltaCompactionOp(69101d24565b48d79f53ebb54a175042) complete. Timing: real 0.136s	user 0.092s	sys 0.044s Metrics: {"cfile_cache_miss":431,"cfile_cache_miss_bytes":20672159,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":1,"delta_iterators_relevant":1,"dirs.queue_time_us":1077,"lbm_read_time_us":10915,"lbm_reads_lt_1ms":467,"lbm_write_time_us":24562,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":442,"mutex_wait_us":575,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":1280,"update_count":2000}
I20260812 06:20:27.700798 22919 ts_tablet_manager.cc:1507] Shutting down tablet manager...
I20260812 06:20:27.701076 22919 tablet_replica.cc:333] T 69101d24565b48d79f53ebb54a175042 P 73e367e3d4e14f8dbfb383271bc75f2e: stopping tablet replica
I20260812 06:20:27.701254 22919 raft_consensus.cc:2243] T 69101d24565b48d79f53ebb54a175042 P 73e367e3d4e14f8dbfb383271bc75f2e [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:20:27.701447 22919 raft_consensus.cc:2272] T 69101d24565b48d79f53ebb54a175042 P 73e367e3d4e14f8dbfb383271bc75f2e [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:20:27.705304 22919 tablet_server.cc:196] TabletServer@127.22.97.193:0 shutdown complete.
I20260812 06:20:27.738327 22919 master.cc:562] Master@127.22.97.254:35303 shutting down...
I20260812 06:20:27.742208 22919 raft_consensus.cc:2243] T 00000000000000000000000000000000 P d81575c6679448c78bf06323230e20c2 [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:20:27.742431 22919 raft_consensus.cc:2272] T 00000000000000000000000000000000 P d81575c6679448c78bf06323230e20c2 [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:20:27.742534 22919 tablet_replica.cc:333] T 00000000000000000000000000000000 P d81575c6679448c78bf06323230e20c2: stopping tablet replica
I20260812 06:20:27.754973 22919 master.cc:584] Master@127.22.97.254:35303 shutdown complete.
[       OK ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/1 (5844 ms)
[----------] 2 tests from EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy (11610 ms total)

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