[==========] Running 2 tests from 1 test suite.
[----------] Global test environment set-up.
[----------] 2 tests from EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy
[ RUN      ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/0
WARNING: Logging before InitGoogleLogging() is written to STDERR
I20260812 06:19:33.537719  8192 internal_mini_cluster.cc:156] Creating distributed mini masters. Addrs: 127.8.0.62:37347
I20260812 06:19:33.538763  8192 env_posix.cc:2285] Not raising this process' open files per process limit of 1048576; it is already as high as it can go
I20260812 06:19:33.539386  8192 file_cache.cc:504] Constructed file cache file cache with capacity 419430
I20260812 06:19:33.546164  8192 server_base.cc:1061] running on GCE node
W20260812 06:19:33.546197  8199 instance_detector.cc:116] could not retrieve AWS instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:19:33.546299  8207 instance_detector.cc:116] could not retrieve Azure instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:19:33.546442  8212 instance_detector.cc:116] could not retrieve OpenStack instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:19:33.546947  8192 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:19:33.547099  8192 system_unsync_time.cc:38] NTP support is disabled. Clock error bounds will not be accurate. This configuration is not suitable for distributed clusters.
I20260812 06:19:33.547169  8192 hybrid_clock.cc:648] HybridClock initialized: now 1786515573547166 us; error 0 us; skew 500 ppm
I20260812 06:19:33.548877  8192 webserver.cc:533] Webserver started at http://127.8.0.62:45607/ using document root <none> and password file <none>
I20260812 06:19:33.549422  8192 fs_manager.cc:362] Metadata directory not provided
I20260812 06:19:33.549510  8192 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:19:33.549773  8192 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:19:33.551491  8192 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskPRxTjs/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515573527110-8192-0/minicluster-data/master-0-root/instance:
uuid: "30a2ca1a172e46f6ab22d935e53da50b"
format_stamp: "Formatted at 2026-08-12 06:19:33 on dist-test-slave-n326"
I20260812 06:19:33.554863  8192 fs_manager.cc:696] Time spent creating directory manager: real 0.003s	user 0.003s	sys 0.000s
I20260812 06:19:33.556947  8225 log_block_manager.cc:4127] Time spent loading block containers with low live blocks: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:19:33.557883  8192 fs_manager.cc:730] Time spent opening block manager: real 0.002s	user 0.002s	sys 0.000s
I20260812 06:19:33.558017  8192 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskPRxTjs/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515573527110-8192-0/minicluster-data/master-0-root
uuid: "30a2ca1a172e46f6ab22d935e53da50b"
format_stamp: "Formatted at 2026-08-12 06:19:33 on dist-test-slave-n326"
I20260812 06:19:33.558123  8192 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskPRxTjs/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515573527110-8192-0/minicluster-data/master-0-root
metadata directory: /tmp/dist-test-taskPRxTjs/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515573527110-8192-0/minicluster-data/master-0-root
1 data directories: /tmp/dist-test-taskPRxTjs/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515573527110-8192-0/minicluster-data/master-0-root/data
Total live blocks: 0
Total live bytes: 0
Total live bytes (after alignment): 0
Total number of LBM containers: 0 (0 full)
Did not check for missing blocks
Did not check for orphaned blocks
Total full LBM containers with extra space: 0 (0 repaired)
Total full LBM container extra space in bytes: 0 (0 repaired)
Total incomplete LBM containers: 0 (0 repaired)
Total LBM partial records: 0 (0 repaired)
Total corrupted LBM metadata records in RocksDB: 0 (0 repaired)
I20260812 06:19:33.573354  8192 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:19:33.573926  8192 env_posix.cc:2285] Not raising this process' running threads per effective uid limit of 18446744073709551615; it is already as high as it can go
I20260812 06:19:33.574103  8192 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:19:33.581825  8192 rpc_server.cc:307] RPC server started. Bound to: 127.8.0.62:37347
I20260812 06:19:33.581840  8311 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.8.0.62:37347 every 8 connection(s)
I20260812 06:19:33.584003  8314 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet 00000000000000000000000000000000. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:19:33.589156  8314 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P 30a2ca1a172e46f6ab22d935e53da50b: Bootstrap starting.
I20260812 06:19:33.591435  8314 tablet_bootstrap.cc:654] T 00000000000000000000000000000000 P 30a2ca1a172e46f6ab22d935e53da50b: Neither blocks nor log segments found. Creating new log.
I20260812 06:19:33.592244  8314 log.cc:826] T 00000000000000000000000000000000 P 30a2ca1a172e46f6ab22d935e53da50b: Log is configured to *not* fsync() on all Append() calls
I20260812 06:19:33.593739  8314 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P 30a2ca1a172e46f6ab22d935e53da50b: No bootstrap required, opened a new log
I20260812 06:19:33.596320  8314 raft_consensus.cc:359] T 00000000000000000000000000000000 P 30a2ca1a172e46f6ab22d935e53da50b [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "30a2ca1a172e46f6ab22d935e53da50b" member_type: VOTER }
I20260812 06:19:33.596474  8314 raft_consensus.cc:385] T 00000000000000000000000000000000 P 30a2ca1a172e46f6ab22d935e53da50b [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:19:33.596532  8314 raft_consensus.cc:740] T 00000000000000000000000000000000 P 30a2ca1a172e46f6ab22d935e53da50b [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: 30a2ca1a172e46f6ab22d935e53da50b, State: Initialized, Role: FOLLOWER
I20260812 06:19:33.597030  8314 consensus_queue.cc:260] T 00000000000000000000000000000000 P 30a2ca1a172e46f6ab22d935e53da50b [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: "30a2ca1a172e46f6ab22d935e53da50b" member_type: VOTER }
I20260812 06:19:33.597157  8314 raft_consensus.cc:399] T 00000000000000000000000000000000 P 30a2ca1a172e46f6ab22d935e53da50b [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:19:33.597210  8314 raft_consensus.cc:493] T 00000000000000000000000000000000 P 30a2ca1a172e46f6ab22d935e53da50b [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:19:33.597299  8314 raft_consensus.cc:3060] T 00000000000000000000000000000000 P 30a2ca1a172e46f6ab22d935e53da50b [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:19:33.598002  8314 raft_consensus.cc:515] T 00000000000000000000000000000000 P 30a2ca1a172e46f6ab22d935e53da50b [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "30a2ca1a172e46f6ab22d935e53da50b" member_type: VOTER }
I20260812 06:19:33.598367  8314 leader_election.cc:304] T 00000000000000000000000000000000 P 30a2ca1a172e46f6ab22d935e53da50b [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: 30a2ca1a172e46f6ab22d935e53da50b; no voters: 
I20260812 06:19:33.598616  8314 leader_election.cc:290] T 00000000000000000000000000000000 P 30a2ca1a172e46f6ab22d935e53da50b [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:19:33.598759  8318 raft_consensus.cc:2804] T 00000000000000000000000000000000 P 30a2ca1a172e46f6ab22d935e53da50b [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:19:33.599007  8318 raft_consensus.cc:697] T 00000000000000000000000000000000 P 30a2ca1a172e46f6ab22d935e53da50b [term 1 LEADER]: Becoming Leader. State: Replica: 30a2ca1a172e46f6ab22d935e53da50b, State: Running, Role: LEADER
I20260812 06:19:33.599462  8318 consensus_queue.cc:237] T 00000000000000000000000000000000 P 30a2ca1a172e46f6ab22d935e53da50b [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: "30a2ca1a172e46f6ab22d935e53da50b" member_type: VOTER }
I20260812 06:19:33.599642  8314 sys_catalog.cc:565] T 00000000000000000000000000000000 P 30a2ca1a172e46f6ab22d935e53da50b [sys.catalog]: configured and running, proceeding with master startup.
I20260812 06:19:33.601356  8320 sys_catalog.cc:455] T 00000000000000000000000000000000 P 30a2ca1a172e46f6ab22d935e53da50b [sys.catalog]: SysCatalogTable state changed. Reason: New leader 30a2ca1a172e46f6ab22d935e53da50b. Latest consensus state: current_term: 1 leader_uuid: "30a2ca1a172e46f6ab22d935e53da50b" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "30a2ca1a172e46f6ab22d935e53da50b" member_type: VOTER } }
I20260812 06:19:33.601390  8319 sys_catalog.cc:455] T 00000000000000000000000000000000 P 30a2ca1a172e46f6ab22d935e53da50b [sys.catalog]: SysCatalogTable state changed. Reason: RaftConsensus started. Latest consensus state: current_term: 1 leader_uuid: "30a2ca1a172e46f6ab22d935e53da50b" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "30a2ca1a172e46f6ab22d935e53da50b" member_type: VOTER } }
I20260812 06:19:33.601482  8320 sys_catalog.cc:458] T 00000000000000000000000000000000 P 30a2ca1a172e46f6ab22d935e53da50b [sys.catalog]: This master's current role is: LEADER
I20260812 06:19:33.601487  8319 sys_catalog.cc:458] T 00000000000000000000000000000000 P 30a2ca1a172e46f6ab22d935e53da50b [sys.catalog]: This master's current role is: LEADER
I20260812 06:19:33.601826  8338 catalog_manager.cc:1511] Loading table and tablet metadata into memory...
I20260812 06:19:33.602007  8192 internal_mini_cluster.cc:184] Waiting to initialize catalog manager on master 0
I20260812 06:19:33.604054  8338 catalog_manager.cc:1520] Initializing Kudu cluster ID...
I20260812 06:19:33.608341  8338 catalog_manager.cc:1383] Generated new cluster ID: 48ceef4f20384629b97cf2df25c0ea19
I20260812 06:19:33.608410  8338 catalog_manager.cc:1531] Initializing Kudu internal certificate authority...
I20260812 06:19:33.616369  8338 catalog_manager.cc:1406] Generated new certificate authority record
I20260812 06:19:33.617458  8338 catalog_manager.cc:1540] Loading token signing keys...
I20260812 06:19:33.628805  8338 catalog_manager.cc:6092] T 00000000000000000000000000000000 P 30a2ca1a172e46f6ab22d935e53da50b: Generated new TSK 0
I20260812 06:19:33.629459  8338 catalog_manager.cc:1550] Initializing in-progress tserver states...
I20260812 06:19:33.634469  8192 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:19:33.637315  8354 instance_detector.cc:116] could not retrieve Azure instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:19:33.637382  8192 server_base.cc:1061] running on GCE node
W20260812 06:19:33.637331  8352 instance_detector.cc:116] could not retrieve AWS instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:19:33.637476  8356 instance_detector.cc:116] could not retrieve OpenStack instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:19:33.637723  8192 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:19:33.637768  8192 system_unsync_time.cc:38] NTP support is disabled. Clock error bounds will not be accurate. This configuration is not suitable for distributed clusters.
I20260812 06:19:33.637784  8192 hybrid_clock.cc:648] HybridClock initialized: now 1786515573637785 us; error 0 us; skew 500 ppm
I20260812 06:19:33.638758  8192 webserver.cc:533] Webserver started at http://127.8.0.1:46261/ using document root <none> and password file <none>
I20260812 06:19:33.638940  8192 fs_manager.cc:362] Metadata directory not provided
I20260812 06:19:33.638988  8192 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:19:33.639125  8192 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:19:33.639534  8192 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskPRxTjs/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515573527110-8192-0/minicluster-data/ts-0-root/instance:
uuid: "674a7fd4a3184ab39998695dc16ea78b"
format_stamp: "Formatted at 2026-08-12 06:19:33 on dist-test-slave-n326"
I20260812 06:19:33.641063  8192 fs_manager.cc:696] Time spent creating directory manager: real 0.001s	user 0.002s	sys 0.000s
I20260812 06:19:33.642077  8368 log_block_manager.cc:4127] Time spent loading block containers with low live blocks: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:19:33.642329  8192 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.001s	sys 0.000s
I20260812 06:19:33.642390  8192 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskPRxTjs/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515573527110-8192-0/minicluster-data/ts-0-root
uuid: "674a7fd4a3184ab39998695dc16ea78b"
format_stamp: "Formatted at 2026-08-12 06:19:33 on dist-test-slave-n326"
I20260812 06:19:33.642477  8192 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskPRxTjs/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515573527110-8192-0/minicluster-data/ts-0-root
metadata directory: /tmp/dist-test-taskPRxTjs/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515573527110-8192-0/minicluster-data/ts-0-root
1 data directories: /tmp/dist-test-taskPRxTjs/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515573527110-8192-0/minicluster-data/ts-0-root/data
Total live blocks: 0
Total live bytes: 0
Total live bytes (after alignment): 0
Total number of LBM containers: 0 (0 full)
Did not check for missing blocks
Did not check for orphaned blocks
Total full LBM containers with extra space: 0 (0 repaired)
Total full LBM container extra space in bytes: 0 (0 repaired)
Total incomplete LBM containers: 0 (0 repaired)
Total LBM partial records: 0 (0 repaired)
Total corrupted LBM metadata records in RocksDB: 0 (0 repaired)
I20260812 06:19:33.663118  8192 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:19:33.663609  8192 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:19:33.664144  8192 txn_system_client.cc:432] TxnSystemClient initialization is disabled...
I20260812 06:19:33.664986  8192 ts_tablet_manager.cc:585] Loaded tablet metadata (0 total tablets, 0 live tablets)
I20260812 06:19:33.665046  8192 ts_tablet_manager.cc:531] Time spent load tablet metadata: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:19:33.665115  8192 ts_tablet_manager.cc:616] Registered 0 tablets
I20260812 06:19:33.665158  8192 ts_tablet_manager.cc:595] Time spent register tablets: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:19:33.672151  8192 rpc_server.cc:307] RPC server started. Bound to: 127.8.0.1:41381
I20260812 06:19:33.672225  8479 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.8.0.1:41381 every 8 connection(s)
I20260812 06:19:33.682487  8482 heartbeater.cc:344] Connected to a master server at 127.8.0.62:37347
I20260812 06:19:33.682744  8482 heartbeater.cc:461] Registering TS with master...
I20260812 06:19:33.683280  8482 heartbeater.cc:507] Master 127.8.0.62:37347 requested a full tablet report, sending...
I20260812 06:19:33.684648  8251 ts_manager.cc:194] Registered new tserver with Master: 674a7fd4a3184ab39998695dc16ea78b (127.8.0.1:41381)
I20260812 06:19:33.685216  8192 internal_mini_cluster.cc:371] 1 TS(s) registered with all masters after 0.012391467s
I20260812 06:19:33.686125  8251 master_service.cc:502] Signed X509 certificate for tserver {username='slave'} at 127.0.0.1:55140
I20260812 06:19:33.694633  8251 catalog_manager.cc:2283] Servicing CreateTable request from {username='slave'} at 127.0.0.1:55144:
name: "heavy-update-compaction-test"
schema {
  columns {
    name: "key"
    type: INT64
    is_key: true
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_a"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_b"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_c"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_d"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_e"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
}
num_replicas: 1
split_rows_range_bounds {
}
partition_schema {
  range_schema {
  }
}
I20260812 06:19:33.708458  8409 tablet_service.cc:1511] Processing CreateTablet for tablet 8035ef853db747bfa709ef3c29ee9d58 (DEFAULT_TABLE table=heavy-update-compaction-test [id=88274990e9d04fbbbc64cd4a40db28e8]), partition=
I20260812 06:19:33.708938  8409 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet 8035ef853db747bfa709ef3c29ee9d58. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:19:33.711285  8500 tablet_bootstrap.cc:492] T 8035ef853db747bfa709ef3c29ee9d58 P 674a7fd4a3184ab39998695dc16ea78b: Bootstrap starting.
I20260812 06:19:33.712579  8500 tablet_bootstrap.cc:654] T 8035ef853db747bfa709ef3c29ee9d58 P 674a7fd4a3184ab39998695dc16ea78b: Neither blocks nor log segments found. Creating new log.
I20260812 06:19:33.713718  8500 tablet_bootstrap.cc:492] T 8035ef853db747bfa709ef3c29ee9d58 P 674a7fd4a3184ab39998695dc16ea78b: No bootstrap required, opened a new log
I20260812 06:19:33.713828  8500 ts_tablet_manager.cc:1403] T 8035ef853db747bfa709ef3c29ee9d58 P 674a7fd4a3184ab39998695dc16ea78b: Time spent bootstrapping tablet: real 0.003s	user 0.000s	sys 0.002s
I20260812 06:19:33.714253  8500 raft_consensus.cc:359] T 8035ef853db747bfa709ef3c29ee9d58 P 674a7fd4a3184ab39998695dc16ea78b [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "674a7fd4a3184ab39998695dc16ea78b" member_type: VOTER last_known_addr { host: "127.8.0.1" port: 41381 } }
I20260812 06:19:33.714354  8500 raft_consensus.cc:385] T 8035ef853db747bfa709ef3c29ee9d58 P 674a7fd4a3184ab39998695dc16ea78b [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:19:33.714377  8500 raft_consensus.cc:740] T 8035ef853db747bfa709ef3c29ee9d58 P 674a7fd4a3184ab39998695dc16ea78b [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: 674a7fd4a3184ab39998695dc16ea78b, State: Initialized, Role: FOLLOWER
I20260812 06:19:33.714576  8500 consensus_queue.cc:260] T 8035ef853db747bfa709ef3c29ee9d58 P 674a7fd4a3184ab39998695dc16ea78b [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: "674a7fd4a3184ab39998695dc16ea78b" member_type: VOTER last_known_addr { host: "127.8.0.1" port: 41381 } }
I20260812 06:19:33.714658  8500 raft_consensus.cc:399] T 8035ef853db747bfa709ef3c29ee9d58 P 674a7fd4a3184ab39998695dc16ea78b [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:19:33.714704  8500 raft_consensus.cc:493] T 8035ef853db747bfa709ef3c29ee9d58 P 674a7fd4a3184ab39998695dc16ea78b [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:19:33.714759  8500 raft_consensus.cc:3060] T 8035ef853db747bfa709ef3c29ee9d58 P 674a7fd4a3184ab39998695dc16ea78b [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:19:33.715636  8500 raft_consensus.cc:515] T 8035ef853db747bfa709ef3c29ee9d58 P 674a7fd4a3184ab39998695dc16ea78b [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "674a7fd4a3184ab39998695dc16ea78b" member_type: VOTER last_known_addr { host: "127.8.0.1" port: 41381 } }
I20260812 06:19:33.715803  8500 leader_election.cc:304] T 8035ef853db747bfa709ef3c29ee9d58 P 674a7fd4a3184ab39998695dc16ea78b [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: 674a7fd4a3184ab39998695dc16ea78b; no voters: 
I20260812 06:19:33.716039  8500 leader_election.cc:290] T 8035ef853db747bfa709ef3c29ee9d58 P 674a7fd4a3184ab39998695dc16ea78b [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:19:33.716137  8503 raft_consensus.cc:2804] T 8035ef853db747bfa709ef3c29ee9d58 P 674a7fd4a3184ab39998695dc16ea78b [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:19:33.716400  8503 raft_consensus.cc:697] T 8035ef853db747bfa709ef3c29ee9d58 P 674a7fd4a3184ab39998695dc16ea78b [term 1 LEADER]: Becoming Leader. State: Replica: 674a7fd4a3184ab39998695dc16ea78b, State: Running, Role: LEADER
I20260812 06:19:33.716428  8500 ts_tablet_manager.cc:1434] T 8035ef853db747bfa709ef3c29ee9d58 P 674a7fd4a3184ab39998695dc16ea78b: Time spent starting tablet: real 0.003s	user 0.002s	sys 0.001s
I20260812 06:19:33.716787  8482 heartbeater.cc:499] Master 127.8.0.62:37347 was elected leader, sending a full tablet report...
I20260812 06:19:33.717211  8503 consensus_queue.cc:237] T 8035ef853db747bfa709ef3c29ee9d58 P 674a7fd4a3184ab39998695dc16ea78b [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: "674a7fd4a3184ab39998695dc16ea78b" member_type: VOTER last_known_addr { host: "127.8.0.1" port: 41381 } }
I20260812 06:19:33.720250  8251 catalog_manager.cc:5719] T 8035ef853db747bfa709ef3c29ee9d58 P 674a7fd4a3184ab39998695dc16ea78b reported cstate change: term changed from 0 to 1, leader changed from <none> to 674a7fd4a3184ab39998695dc16ea78b (127.8.0.1). New cstate: current_term: 1 leader_uuid: "674a7fd4a3184ab39998695dc16ea78b" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "674a7fd4a3184ab39998695dc16ea78b" member_type: VOTER last_known_addr { host: "127.8.0.1" port: 41381 } health_report { overall_health: HEALTHY } } }
I20260812 06:19:33.790416  8192 heavy-update-compaction-itest.cc:215] Time spent inserting: real 0.061s	user 0.016s	sys 0.012s
I20260812 06:19:33.923527  8483 maintenance_manager.cc:419] P 674a7fd4a3184ab39998695dc16ea78b: Scheduling FlushMRSOp(8035ef853db747bfa709ef3c29ee9d58): perf score=15.086190
I20260812 06:19:34.105470  8379 maintenance_manager.cc:643] P 674a7fd4a3184ab39998695dc16ea78b: FlushMRSOp(8035ef853db747bfa709ef3c29ee9d58) complete. Timing: real 0.182s	user 0.140s	sys 0.035s Metrics: {"bytes_written":12307490,"cfile_init":1,"compiler_manager_pool.queue_time_us":342,"delete_count":0,"dirs.queue_time_us":60,"dirs.run_cpu_time_us":217,"dirs.run_wall_time_us":1055,"drs_written":1,"lbm_read_time_us":71,"lbm_reads_lt_1ms":4,"lbm_write_time_us":47071,"lbm_writes_lt_1ms":757,"peak_mem_usage":0,"reinsert_count":0,"rows_written":104,"thread_start_us":131,"threads_started":1,"update_count":1500}
I20260812 06:19:34.106662  8483 maintenance_manager.cc:419] P 674a7fd4a3184ab39998695dc16ea78b: Scheduling LogGCOp(8035ef853db747bfa709ef3c29ee9d58): free 20743880 bytes of WAL
I20260812 06:19:34.107043  8379 log_reader.cc:385] T 8035ef853db747bfa709ef3c29ee9d58: removed 2 log segments from log reader
I20260812 06:19:34.107189  8379 log.cc:1079] T 8035ef853db747bfa709ef3c29ee9d58 P 674a7fd4a3184ab39998695dc16ea78b: Deleting log segment in path: /tmp/dist-test-taskPRxTjs/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515573527110-8192-0/minicluster-data/ts-0-root/wals/8035ef853db747bfa709ef3c29ee9d58/wal-000000001 (ops 1-6)
I20260812 06:19:34.107307  8379 log.cc:1079] T 8035ef853db747bfa709ef3c29ee9d58 P 674a7fd4a3184ab39998695dc16ea78b: Deleting log segment in path: /tmp/dist-test-taskPRxTjs/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515573527110-8192-0/minicluster-data/ts-0-root/wals/8035ef853db747bfa709ef3c29ee9d58/wal-000000002 (ops 7-11)
I20260812 06:19:34.113332  8379 maintenance_manager.cc:643] P 674a7fd4a3184ab39998695dc16ea78b: LogGCOp(8035ef853db747bfa709ef3c29ee9d58) complete. Timing: real 0.006s	user 0.000s	sys 0.004s Metrics: {}
I20260812 06:19:34.113677  8483 maintenance_manager.cc:419] P 674a7fd4a3184ab39998695dc16ea78b: Scheduling FlushDeltaMemStoresOp(8035ef853db747bfa709ef3c29ee9d58): perf score=3.181125
I20260812 06:19:34.142328  8379 maintenance_manager.cc:643] P 674a7fd4a3184ab39998695dc16ea78b: FlushDeltaMemStoresOp(8035ef853db747bfa709ef3c29ee9d58) complete. Timing: real 0.029s	user 0.003s	sys 0.021s Metrics: {"bytes_written":4512900,"delete_count":0,"lbm_write_time_us":7260,"lbm_writes_lt_1ms":113,"reinsert_count":0,"update_count":550}
I20260812 06:19:34.142869  8483 maintenance_manager.cc:419] P 674a7fd4a3184ab39998695dc16ea78b: Scheduling FlushDeltaMemStoresOp(8035ef853db747bfa709ef3c29ee9d58): perf score=2.188937
I20260812 06:19:34.157366  8379 maintenance_manager.cc:643] P 674a7fd4a3184ab39998695dc16ea78b: FlushDeltaMemStoresOp(8035ef853db747bfa709ef3c29ee9d58) complete. Timing: real 0.014s	user 0.002s	sys 0.009s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":5377,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:19:34.157856  8483 maintenance_manager.cc:419] P 674a7fd4a3184ab39998695dc16ea78b: Scheduling UndoDeltaBlockGCOp(8035ef853db747bfa709ef3c29ee9d58): 16411391 bytes on disk
I20260812 06:19:34.158607  8379 maintenance_manager.cc:643] P 674a7fd4a3184ab39998695dc16ea78b: UndoDeltaBlockGCOp(8035ef853db747bfa709ef3c29ee9d58) complete. Timing: real 0.001s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":82,"lbm_reads_lt_1ms":4}
I20260812 06:19:34.159052  8483 maintenance_manager.cc:419] P 674a7fd4a3184ab39998695dc16ea78b: Scheduling MajorDeltaCompactionOp(8035ef853db747bfa709ef3c29ee9d58): perf score=1.000000
I20260812 06:19:34.357182  8379 maintenance_manager.cc:643] P 674a7fd4a3184ab39998695dc16ea78b: MajorDeltaCompactionOp(8035ef853db747bfa709ef3c29ee9d58) complete. Timing: real 0.198s	user 0.104s	sys 0.077s Metrics: {"cfile_cache_miss":533,"cfile_cache_miss_bytes":24774795,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":553,"lbm_read_time_us":14004,"lbm_reads_lt_1ms":569,"lbm_write_time_us":30907,"lbm_writes_lt_1ms":543,"peak_mem_usage":63115900,"reinsert_count":0,"thread_start_us":295,"threads_started":5,"update_count":2500}
I20260812 06:19:34.357723  8483 maintenance_manager.cc:419] P 674a7fd4a3184ab39998695dc16ea78b: Scheduling FlushDeltaMemStoresOp(8035ef853db747bfa709ef3c29ee9d58): perf score=10.126437
I20260812 06:19:34.404798  8379 maintenance_manager.cc:643] P 674a7fd4a3184ab39998695dc16ea78b: FlushDeltaMemStoresOp(8035ef853db747bfa709ef3c29ee9d58) complete. Timing: real 0.047s	user 0.023s	sys 0.020s Metrics: {"bytes_written":12307492,"delete_count":0,"lbm_write_time_us":19449,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:19:34.405310  8483 maintenance_manager.cc:419] P 674a7fd4a3184ab39998695dc16ea78b: Scheduling MajorDeltaCompactionOp(8035ef853db747bfa709ef3c29ee9d58): perf score=1.000000
I20260812 06:19:34.547151  8379 maintenance_manager.cc:643] P 674a7fd4a3184ab39998695dc16ea78b: MajorDeltaCompactionOp(8035ef853db747bfa709ef3c29ee9d58) complete. Timing: real 0.142s	user 0.096s	sys 0.031s Metrics: {"cfile_cache_miss":331,"cfile_cache_miss_bytes":16569748,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":1,"delta_iterators_relevant":1,"dirs.queue_time_us":1653,"lbm_read_time_us":6595,"lbm_reads_lt_1ms":363,"lbm_write_time_us":25517,"lbm_writes_lt_1ms":343,"peak_mem_usage":38262756,"reinsert_count":0,"spinlock_wait_cycles":768,"update_count":1500}
I20260812 06:19:34.547780  8483 maintenance_manager.cc:419] P 674a7fd4a3184ab39998695dc16ea78b: Scheduling FlushDeltaMemStoresOp(8035ef853db747bfa709ef3c29ee9d58): perf score=10.126437
I20260812 06:19:34.597065  8379 maintenance_manager.cc:643] P 674a7fd4a3184ab39998695dc16ea78b: FlushDeltaMemStoresOp(8035ef853db747bfa709ef3c29ee9d58) complete. Timing: real 0.049s	user 0.032s	sys 0.015s Metrics: {"bytes_written":12307491,"delete_count":0,"lbm_write_time_us":20671,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:19:34.597589  8483 maintenance_manager.cc:419] P 674a7fd4a3184ab39998695dc16ea78b: Scheduling FlushDeltaMemStoresOp(8035ef853db747bfa709ef3c29ee9d58): perf score=2.188937
I20260812 06:19:34.614249  8379 maintenance_manager.cc:643] P 674a7fd4a3184ab39998695dc16ea78b: FlushDeltaMemStoresOp(8035ef853db747bfa709ef3c29ee9d58) complete. Timing: real 0.016s	user 0.007s	sys 0.007s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6189,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:34.614764  8483 maintenance_manager.cc:419] P 674a7fd4a3184ab39998695dc16ea78b: Scheduling MajorDeltaCompactionOp(8035ef853db747bfa709ef3c29ee9d58): perf score=1.000000
I20260812 06:19:34.752321  8379 maintenance_manager.cc:643] P 674a7fd4a3184ab39998695dc16ea78b: MajorDeltaCompactionOp(8035ef853db747bfa709ef3c29ee9d58) complete. Timing: real 0.137s	user 0.105s	sys 0.031s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672278,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":672,"lbm_read_time_us":11124,"lbm_reads_lt_1ms":464,"lbm_write_time_us":24537,"lbm_writes_lt_1ms":443,"mutex_wait_us":304,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":10112,"update_count":2000}
I20260812 06:19:34.752957  8483 maintenance_manager.cc:419] P 674a7fd4a3184ab39998695dc16ea78b: Scheduling FlushDeltaMemStoresOp(8035ef853db747bfa709ef3c29ee9d58): perf score=7.149875
I20260812 06:19:34.776894  8379 maintenance_manager.cc:643] P 674a7fd4a3184ab39998695dc16ea78b: FlushDeltaMemStoresOp(8035ef853db747bfa709ef3c29ee9d58) complete. Timing: real 0.024s	user 0.010s	sys 0.012s Metrics: {"bytes_written":8615323,"delete_count":0,"lbm_write_time_us":9970,"lbm_writes_lt_1ms":213,"reinsert_count":0,"update_count":1050}
I20260812 06:19:34.777411  8483 maintenance_manager.cc:419] P 674a7fd4a3184ab39998695dc16ea78b: Scheduling FlushDeltaMemStoresOp(8035ef853db747bfa709ef3c29ee9d58): perf score=2.188937
I20260812 06:19:34.794025  8379 maintenance_manager.cc:643] P 674a7fd4a3184ab39998695dc16ea78b: FlushDeltaMemStoresOp(8035ef853db747bfa709ef3c29ee9d58) complete. Timing: real 0.016s	user 0.011s	sys 0.003s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":6184,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:19:34.794656  8483 maintenance_manager.cc:419] P 674a7fd4a3184ab39998695dc16ea78b: Scheduling MajorDeltaCompactionOp(8035ef853db747bfa709ef3c29ee9d58): perf score=1.000000
I20260812 06:19:34.915203  8379 maintenance_manager.cc:643] P 674a7fd4a3184ab39998695dc16ea78b: MajorDeltaCompactionOp(8035ef853db747bfa709ef3c29ee9d58) complete. Timing: real 0.120s	user 0.096s	sys 0.024s Metrics: {"cfile_cache_miss":332,"cfile_cache_miss_bytes":16569856,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":201,"lbm_read_time_us":8061,"lbm_reads_lt_1ms":364,"lbm_write_time_us":18970,"lbm_writes_lt_1ms":343,"mutex_wait_us":42,"peak_mem_usage":38262756,"reinsert_count":0,"spinlock_wait_cycles":23552,"update_count":1500}
I20260812 06:19:34.915834  8483 maintenance_manager.cc:419] P 674a7fd4a3184ab39998695dc16ea78b: Scheduling FlushDeltaMemStoresOp(8035ef853db747bfa709ef3c29ee9d58): perf score=10.126437
I20260812 06:19:34.954435  8379 maintenance_manager.cc:643] P 674a7fd4a3184ab39998695dc16ea78b: FlushDeltaMemStoresOp(8035ef853db747bfa709ef3c29ee9d58) complete. Timing: real 0.038s	user 0.030s	sys 0.001s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":15082,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:19:34.954918  8483 maintenance_manager.cc:419] P 674a7fd4a3184ab39998695dc16ea78b: Scheduling FlushDeltaMemStoresOp(8035ef853db747bfa709ef3c29ee9d58): perf score=2.188937
I20260812 06:19:34.965622  8379 maintenance_manager.cc:643] P 674a7fd4a3184ab39998695dc16ea78b: FlushDeltaMemStoresOp(8035ef853db747bfa709ef3c29ee9d58) complete. Timing: real 0.010s	user 0.004s	sys 0.005s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4125,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:34.966248  8483 maintenance_manager.cc:419] P 674a7fd4a3184ab39998695dc16ea78b: Scheduling MajorDeltaCompactionOp(8035ef853db747bfa709ef3c29ee9d58): perf score=1.000000
I20260812 06:19:35.100472  8379 maintenance_manager.cc:643] P 674a7fd4a3184ab39998695dc16ea78b: MajorDeltaCompactionOp(8035ef853db747bfa709ef3c29ee9d58) complete. Timing: real 0.134s	user 0.113s	sys 0.019s 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":441,"lbm_read_time_us":8893,"lbm_reads_lt_1ms":472,"lbm_write_time_us":25869,"lbm_writes_lt_1ms":443,"mutex_wait_us":85,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":12160,"update_count":2000}
I20260812 06:19:35.101176  8483 maintenance_manager.cc:419] P 674a7fd4a3184ab39998695dc16ea78b: Scheduling FlushDeltaMemStoresOp(8035ef853db747bfa709ef3c29ee9d58): perf score=10.126437
I20260812 06:19:35.146270  8379 maintenance_manager.cc:643] P 674a7fd4a3184ab39998695dc16ea78b: FlushDeltaMemStoresOp(8035ef853db747bfa709ef3c29ee9d58) complete. Timing: real 0.045s	user 0.016s	sys 0.020s Metrics: {"bytes_written":12307491,"delete_count":0,"lbm_write_time_us":19331,"lbm_writes_1-10_ms":2,"lbm_writes_lt_1ms":301,"reinsert_count":0,"update_count":1500}
I20260812 06:19:35.146795  8483 maintenance_manager.cc:419] P 674a7fd4a3184ab39998695dc16ea78b: Scheduling FlushDeltaMemStoresOp(8035ef853db747bfa709ef3c29ee9d58): perf score=2.188937
I20260812 06:19:35.158494  8379 maintenance_manager.cc:643] P 674a7fd4a3184ab39998695dc16ea78b: FlushDeltaMemStoresOp(8035ef853db747bfa709ef3c29ee9d58) complete. Timing: real 0.012s	user 0.006s	sys 0.003s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4216,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:35.159221  8483 maintenance_manager.cc:419] P 674a7fd4a3184ab39998695dc16ea78b: Scheduling MajorDeltaCompactionOp(8035ef853db747bfa709ef3c29ee9d58): perf score=1.000000
I20260812 06:19:35.290210  8379 maintenance_manager.cc:643] P 674a7fd4a3184ab39998695dc16ea78b: MajorDeltaCompactionOp(8035ef853db747bfa709ef3c29ee9d58) complete. Timing: real 0.131s	user 0.122s	sys 0.009s 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":383,"lbm_read_time_us":8641,"lbm_reads_lt_1ms":472,"lbm_write_time_us":28125,"lbm_writes_lt_1ms":443,"mutex_wait_us":41,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":12160,"update_count":2000}
I20260812 06:19:35.290879  8483 maintenance_manager.cc:419] P 674a7fd4a3184ab39998695dc16ea78b: Scheduling FlushDeltaMemStoresOp(8035ef853db747bfa709ef3c29ee9d58): perf score=10.126437
I20260812 06:19:35.346416  8379 maintenance_manager.cc:643] P 674a7fd4a3184ab39998695dc16ea78b: FlushDeltaMemStoresOp(8035ef853db747bfa709ef3c29ee9d58) complete. Timing: real 0.055s	user 0.024s	sys 0.026s Metrics: {"bytes_written":12307491,"delete_count":0,"lbm_write_time_us":19750,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":302,"reinsert_count":0,"update_count":1500}
I20260812 06:19:35.347035  8483 maintenance_manager.cc:419] P 674a7fd4a3184ab39998695dc16ea78b: Scheduling FlushDeltaMemStoresOp(8035ef853db747bfa709ef3c29ee9d58): perf score=2.188937
I20260812 06:19:35.358644  8379 maintenance_manager.cc:643] P 674a7fd4a3184ab39998695dc16ea78b: FlushDeltaMemStoresOp(8035ef853db747bfa709ef3c29ee9d58) complete. Timing: real 0.011s	user 0.005s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4535,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:35.359218  8483 maintenance_manager.cc:419] P 674a7fd4a3184ab39998695dc16ea78b: Scheduling MajorDeltaCompactionOp(8035ef853db747bfa709ef3c29ee9d58): perf score=1.000000
I20260812 06:19:35.515866  8379 maintenance_manager.cc:643] P 674a7fd4a3184ab39998695dc16ea78b: MajorDeltaCompactionOp(8035ef853db747bfa709ef3c29ee9d58) complete. Timing: real 0.156s	user 0.098s	sys 0.056s 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":311,"lbm_read_time_us":11987,"lbm_reads_lt_1ms":472,"lbm_write_time_us":24629,"lbm_writes_lt_1ms":443,"mutex_wait_us":44,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":2816,"update_count":2000}
I20260812 06:19:35.516526  8483 maintenance_manager.cc:419] P 674a7fd4a3184ab39998695dc16ea78b: Scheduling FlushDeltaMemStoresOp(8035ef853db747bfa709ef3c29ee9d58): perf score=10.126437
I20260812 06:19:35.564280  8379 maintenance_manager.cc:643] P 674a7fd4a3184ab39998695dc16ea78b: FlushDeltaMemStoresOp(8035ef853db747bfa709ef3c29ee9d58) complete. Timing: real 0.048s	user 0.022s	sys 0.015s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":15770,"lbm_writes_lt_1ms":303,"mutex_wait_us":2,"reinsert_count":0,"update_count":1500}
I20260812 06:19:35.564832  8483 maintenance_manager.cc:419] P 674a7fd4a3184ab39998695dc16ea78b: Scheduling FlushDeltaMemStoresOp(8035ef853db747bfa709ef3c29ee9d58): perf score=2.188937
I20260812 06:19:35.575522  8379 maintenance_manager.cc:643] P 674a7fd4a3184ab39998695dc16ea78b: FlushDeltaMemStoresOp(8035ef853db747bfa709ef3c29ee9d58) complete. Timing: real 0.011s	user 0.010s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4184,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:35.576233  8483 maintenance_manager.cc:419] P 674a7fd4a3184ab39998695dc16ea78b: Scheduling FlushMRSOp(8035ef853db747bfa709ef3c29ee9d58): perf score=1.000000
I20260812 06:19:35.607705  8379 maintenance_manager.cc:643] P 674a7fd4a3184ab39998695dc16ea78b: FlushMRSOp(8035ef853db747bfa709ef3c29ee9d58) complete. Timing: real 0.031s	user 0.027s	sys 0.004s Metrics: {"bytes_written":1275443,"cfile_init":1,"dirs.queue_time_us":62,"dirs.run_cpu_time_us":275,"dirs.run_wall_time_us":1404,"drs_written":1,"lbm_read_time_us":89,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1590,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":31}
I20260812 06:19:35.608464  8483 maintenance_manager.cc:419] P 674a7fd4a3184ab39998695dc16ea78b: Scheduling LogGCOp(8035ef853db747bfa709ef3c29ee9d58): free 124710294 bytes of WAL
I20260812 06:19:35.608685  8379 log_reader.cc:385] T 8035ef853db747bfa709ef3c29ee9d58: removed 12 log segments from log reader
I20260812 06:19:35.608729  8379 log.cc:1079] T 8035ef853db747bfa709ef3c29ee9d58 P 674a7fd4a3184ab39998695dc16ea78b: Deleting log segment in path: /tmp/dist-test-taskPRxTjs/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515573527110-8192-0/minicluster-data/ts-0-root/wals/8035ef853db747bfa709ef3c29ee9d58/wal-000000003 (ops 12-16)
I20260812 06:19:35.608758  8379 log.cc:1079] T 8035ef853db747bfa709ef3c29ee9d58 P 674a7fd4a3184ab39998695dc16ea78b: Deleting log segment in path: /tmp/dist-test-taskPRxTjs/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515573527110-8192-0/minicluster-data/ts-0-root/wals/8035ef853db747bfa709ef3c29ee9d58/wal-000000004 (ops 17-21)
I20260812 06:19:35.608822  8379 log.cc:1079] T 8035ef853db747bfa709ef3c29ee9d58 P 674a7fd4a3184ab39998695dc16ea78b: Deleting log segment in path: /tmp/dist-test-taskPRxTjs/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515573527110-8192-0/minicluster-data/ts-0-root/wals/8035ef853db747bfa709ef3c29ee9d58/wal-000000005 (ops 22-26)
I20260812 06:19:35.608865  8379 log.cc:1079] T 8035ef853db747bfa709ef3c29ee9d58 P 674a7fd4a3184ab39998695dc16ea78b: Deleting log segment in path: /tmp/dist-test-taskPRxTjs/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515573527110-8192-0/minicluster-data/ts-0-root/wals/8035ef853db747bfa709ef3c29ee9d58/wal-000000006 (ops 27-31)
I20260812 06:19:35.608906  8379 log.cc:1079] T 8035ef853db747bfa709ef3c29ee9d58 P 674a7fd4a3184ab39998695dc16ea78b: Deleting log segment in path: /tmp/dist-test-taskPRxTjs/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515573527110-8192-0/minicluster-data/ts-0-root/wals/8035ef853db747bfa709ef3c29ee9d58/wal-000000007 (ops 32-36)
I20260812 06:19:35.608958  8379 log.cc:1079] T 8035ef853db747bfa709ef3c29ee9d58 P 674a7fd4a3184ab39998695dc16ea78b: Deleting log segment in path: /tmp/dist-test-taskPRxTjs/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515573527110-8192-0/minicluster-data/ts-0-root/wals/8035ef853db747bfa709ef3c29ee9d58/wal-000000008 (ops 37-41)
I20260812 06:19:35.608994  8379 log.cc:1079] T 8035ef853db747bfa709ef3c29ee9d58 P 674a7fd4a3184ab39998695dc16ea78b: Deleting log segment in path: /tmp/dist-test-taskPRxTjs/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515573527110-8192-0/minicluster-data/ts-0-root/wals/8035ef853db747bfa709ef3c29ee9d58/wal-000000009 (ops 42-46)
I20260812 06:19:35.609030  8379 log.cc:1079] T 8035ef853db747bfa709ef3c29ee9d58 P 674a7fd4a3184ab39998695dc16ea78b: Deleting log segment in path: /tmp/dist-test-taskPRxTjs/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515573527110-8192-0/minicluster-data/ts-0-root/wals/8035ef853db747bfa709ef3c29ee9d58/wal-000000010 (ops 47-51)
I20260812 06:19:35.609071  8379 log.cc:1079] T 8035ef853db747bfa709ef3c29ee9d58 P 674a7fd4a3184ab39998695dc16ea78b: Deleting log segment in path: /tmp/dist-test-taskPRxTjs/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515573527110-8192-0/minicluster-data/ts-0-root/wals/8035ef853db747bfa709ef3c29ee9d58/wal-000000011 (ops 52-56)
I20260812 06:19:35.609109  8379 log.cc:1079] T 8035ef853db747bfa709ef3c29ee9d58 P 674a7fd4a3184ab39998695dc16ea78b: Deleting log segment in path: /tmp/dist-test-taskPRxTjs/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515573527110-8192-0/minicluster-data/ts-0-root/wals/8035ef853db747bfa709ef3c29ee9d58/wal-000000012 (ops 57-61)
I20260812 06:19:35.609148  8379 log.cc:1079] T 8035ef853db747bfa709ef3c29ee9d58 P 674a7fd4a3184ab39998695dc16ea78b: Deleting log segment in path: /tmp/dist-test-taskPRxTjs/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515573527110-8192-0/minicluster-data/ts-0-root/wals/8035ef853db747bfa709ef3c29ee9d58/wal-000000013 (ops 62-66)
I20260812 06:19:35.609186  8379 log.cc:1079] T 8035ef853db747bfa709ef3c29ee9d58 P 674a7fd4a3184ab39998695dc16ea78b: Deleting log segment in path: /tmp/dist-test-taskPRxTjs/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515573527110-8192-0/minicluster-data/ts-0-root/wals/8035ef853db747bfa709ef3c29ee9d58/wal-000000014 (ops 67-71)
I20260812 06:19:35.640507  8379 maintenance_manager.cc:643] P 674a7fd4a3184ab39998695dc16ea78b: LogGCOp(8035ef853db747bfa709ef3c29ee9d58) complete. Timing: real 0.032s	user 0.000s	sys 0.030s Metrics: {}
I20260812 06:19:35.641249  8483 maintenance_manager.cc:419] P 674a7fd4a3184ab39998695dc16ea78b: Scheduling FlushDeltaMemStoresOp(8035ef853db747bfa709ef3c29ee9d58): perf score=4.173312
I20260812 06:19:35.664951  8379 maintenance_manager.cc:643] P 674a7fd4a3184ab39998695dc16ea78b: FlushDeltaMemStoresOp(8035ef853db747bfa709ef3c29ee9d58) complete. Timing: real 0.023s	user 0.008s	sys 0.013s Metrics: {"bytes_written":5538513,"delete_count":0,"lbm_write_time_us":6211,"lbm_writes_lt_1ms":138,"reinsert_count":0,"update_count":675}
I20260812 06:19:35.665463  8483 maintenance_manager.cc:419] P 674a7fd4a3184ab39998695dc16ea78b: Scheduling FlushDeltaMemStoresOp(8035ef853db747bfa709ef3c29ee9d58): perf score=1.196750
I20260812 06:19:35.673614  8379 maintenance_manager.cc:643] P 674a7fd4a3184ab39998695dc16ea78b: FlushDeltaMemStoresOp(8035ef853db747bfa709ef3c29ee9d58) complete. Timing: real 0.008s	user 0.000s	sys 0.006s Metrics: {"bytes_written":2666779,"delete_count":0,"lbm_write_time_us":2908,"lbm_writes_lt_1ms":68,"reinsert_count":0,"update_count":325}
I20260812 06:19:35.674084  8483 maintenance_manager.cc:419] P 674a7fd4a3184ab39998695dc16ea78b: Scheduling MajorDeltaCompactionOp(8035ef853db747bfa709ef3c29ee9d58): perf score=1.000000
I20260812 06:19:35.879451  8379 maintenance_manager.cc:643] P 674a7fd4a3184ab39998695dc16ea78b: MajorDeltaCompactionOp(8035ef853db747bfa709ef3c29ee9d58) complete. Timing: real 0.205s	user 0.109s	sys 0.088s Metrics: {"cfile_cache_miss":634,"cfile_cache_miss_bytes":28877307,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":2543,"lbm_read_time_us":13722,"lbm_reads_lt_1ms":674,"lbm_write_time_us":33158,"lbm_writes_lt_1ms":643,"mutex_wait_us":100,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":34176,"thread_start_us":77,"threads_started":1,"update_count":3000}
I20260812 06:19:35.880123  8483 maintenance_manager.cc:419] P 674a7fd4a3184ab39998695dc16ea78b: Scheduling UndoDeltaBlockGCOp(8035ef853db747bfa709ef3c29ee9d58): 483 bytes on disk
I20260812 06:19:35.880532  8379 maintenance_manager.cc:643] P 674a7fd4a3184ab39998695dc16ea78b: UndoDeltaBlockGCOp(8035ef853db747bfa709ef3c29ee9d58) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":55,"lbm_reads_lt_1ms":4}
I20260812 06:19:35.881016  8483 maintenance_manager.cc:419] P 674a7fd4a3184ab39998695dc16ea78b: Scheduling FlushDeltaMemStoresOp(8035ef853db747bfa709ef3c29ee9d58): perf score=14.095187
I20260812 06:19:35.941495  8379 maintenance_manager.cc:643] P 674a7fd4a3184ab39998695dc16ea78b: FlushDeltaMemStoresOp(8035ef853db747bfa709ef3c29ee9d58) complete. Timing: real 0.060s	user 0.031s	sys 0.027s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":21787,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:35.942145  8483 maintenance_manager.cc:419] P 674a7fd4a3184ab39998695dc16ea78b: Scheduling FlushDeltaMemStoresOp(8035ef853db747bfa709ef3c29ee9d58): perf score=2.188937
I20260812 06:19:35.960500  8379 maintenance_manager.cc:643] P 674a7fd4a3184ab39998695dc16ea78b: FlushDeltaMemStoresOp(8035ef853db747bfa709ef3c29ee9d58) complete. Timing: real 0.018s	user 0.009s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":7011,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:35.961145  8483 maintenance_manager.cc:419] P 674a7fd4a3184ab39998695dc16ea78b: Scheduling MajorDeltaCompactionOp(8035ef853db747bfa709ef3c29ee9d58): perf score=1.000000
I20260812 06:19:36.137498  8379 maintenance_manager.cc:643] P 674a7fd4a3184ab39998695dc16ea78b: MajorDeltaCompactionOp(8035ef853db747bfa709ef3c29ee9d58) complete. Timing: real 0.176s	user 0.128s	sys 0.048s 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":375,"lbm_read_time_us":12455,"lbm_reads_lt_1ms":572,"lbm_write_time_us":30154,"lbm_writes_lt_1ms":543,"mutex_wait_us":73,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":4224,"update_count":2500}
I20260812 06:19:36.138162  8483 maintenance_manager.cc:419] P 674a7fd4a3184ab39998695dc16ea78b: Scheduling FlushDeltaMemStoresOp(8035ef853db747bfa709ef3c29ee9d58): perf score=11.118625
I20260812 06:19:36.176887  8379 maintenance_manager.cc:643] P 674a7fd4a3184ab39998695dc16ea78b: FlushDeltaMemStoresOp(8035ef853db747bfa709ef3c29ee9d58) complete. Timing: real 0.039s	user 0.021s	sys 0.016s Metrics: {"bytes_written":12717735,"delete_count":0,"lbm_write_time_us":17098,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:19:36.177636  8483 maintenance_manager.cc:419] P 674a7fd4a3184ab39998695dc16ea78b: Scheduling FlushDeltaMemStoresOp(8035ef853db747bfa709ef3c29ee9d58): perf score=2.188937
I20260812 06:19:36.197394  8379 maintenance_manager.cc:643] P 674a7fd4a3184ab39998695dc16ea78b: FlushDeltaMemStoresOp(8035ef853db747bfa709ef3c29ee9d58) complete. Timing: real 0.019s	user 0.011s	sys 0.004s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":6227,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:19:36.197973  8483 maintenance_manager.cc:419] P 674a7fd4a3184ab39998695dc16ea78b: Scheduling MajorDeltaCompactionOp(8035ef853db747bfa709ef3c29ee9d58): perf score=1.000000
I20260812 06:19:36.330706  8379 maintenance_manager.cc:643] P 674a7fd4a3184ab39998695dc16ea78b: MajorDeltaCompactionOp(8035ef853db747bfa709ef3c29ee9d58) complete. Timing: real 0.133s	user 0.098s	sys 0.033s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672268,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":317,"lbm_read_time_us":9155,"lbm_reads_lt_1ms":464,"lbm_write_time_us":25874,"lbm_writes_lt_1ms":443,"mutex_wait_us":48,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":7040,"update_count":2000}
I20260812 06:19:36.331269  8483 maintenance_manager.cc:419] P 674a7fd4a3184ab39998695dc16ea78b: Scheduling FlushDeltaMemStoresOp(8035ef853db747bfa709ef3c29ee9d58): perf score=10.126437
I20260812 06:19:36.370298  8379 maintenance_manager.cc:643] P 674a7fd4a3184ab39998695dc16ea78b: FlushDeltaMemStoresOp(8035ef853db747bfa709ef3c29ee9d58) complete. Timing: real 0.039s	user 0.009s	sys 0.025s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":16088,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:19:36.370785  8483 maintenance_manager.cc:419] P 674a7fd4a3184ab39998695dc16ea78b: Scheduling FlushDeltaMemStoresOp(8035ef853db747bfa709ef3c29ee9d58): perf score=2.188937
I20260812 06:19:36.381270  8379 maintenance_manager.cc:643] P 674a7fd4a3184ab39998695dc16ea78b: FlushDeltaMemStoresOp(8035ef853db747bfa709ef3c29ee9d58) complete. Timing: real 0.010s	user 0.009s	sys 0.000s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4000,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:36.381886  8483 maintenance_manager.cc:419] P 674a7fd4a3184ab39998695dc16ea78b: Scheduling MajorDeltaCompactionOp(8035ef853db747bfa709ef3c29ee9d58): perf score=1.000000
I20260812 06:19:36.498349  8379 maintenance_manager.cc:643] P 674a7fd4a3184ab39998695dc16ea78b: MajorDeltaCompactionOp(8035ef853db747bfa709ef3c29ee9d58) complete. Timing: real 0.116s	user 0.092s	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":1031,"lbm_read_time_us":8044,"lbm_reads_lt_1ms":472,"lbm_write_time_us":22315,"lbm_writes_lt_1ms":443,"mutex_wait_us":273,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":768,"update_count":2000}
I20260812 06:19:36.498989  8483 maintenance_manager.cc:419] P 674a7fd4a3184ab39998695dc16ea78b: Scheduling FlushDeltaMemStoresOp(8035ef853db747bfa709ef3c29ee9d58): perf score=10.126437
I20260812 06:19:36.535681  8379 maintenance_manager.cc:643] P 674a7fd4a3184ab39998695dc16ea78b: FlushDeltaMemStoresOp(8035ef853db747bfa709ef3c29ee9d58) complete. Timing: real 0.036s	user 0.016s	sys 0.017s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":14394,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:19:36.536234  8483 maintenance_manager.cc:419] P 674a7fd4a3184ab39998695dc16ea78b: Scheduling FlushDeltaMemStoresOp(8035ef853db747bfa709ef3c29ee9d58): perf score=2.188937
I20260812 06:19:36.551303  8379 maintenance_manager.cc:643] P 674a7fd4a3184ab39998695dc16ea78b: FlushDeltaMemStoresOp(8035ef853db747bfa709ef3c29ee9d58) complete. Timing: real 0.015s	user 0.007s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5925,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:36.551829  8483 maintenance_manager.cc:419] P 674a7fd4a3184ab39998695dc16ea78b: Scheduling MajorDeltaCompactionOp(8035ef853db747bfa709ef3c29ee9d58): perf score=1.000000
I20260812 06:19:36.675972  8379 maintenance_manager.cc:643] P 674a7fd4a3184ab39998695dc16ea78b: MajorDeltaCompactionOp(8035ef853db747bfa709ef3c29ee9d58) complete. Timing: real 0.124s	user 0.085s	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":746,"lbm_read_time_us":9431,"lbm_reads_lt_1ms":472,"lbm_write_time_us":23057,"lbm_writes_lt_1ms":443,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":1792,"update_count":2000}
I20260812 06:19:36.677045  8483 maintenance_manager.cc:419] P 674a7fd4a3184ab39998695dc16ea78b: Scheduling FlushDeltaMemStoresOp(8035ef853db747bfa709ef3c29ee9d58): perf score=10.126437
I20260812 06:19:36.720304  8379 maintenance_manager.cc:643] P 674a7fd4a3184ab39998695dc16ea78b: FlushDeltaMemStoresOp(8035ef853db747bfa709ef3c29ee9d58) complete. Timing: real 0.043s	user 0.019s	sys 0.023s Metrics: {"bytes_written":12307489,"delete_count":0,"lbm_write_time_us":14849,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:19:36.720888  8483 maintenance_manager.cc:419] P 674a7fd4a3184ab39998695dc16ea78b: Scheduling FlushDeltaMemStoresOp(8035ef853db747bfa709ef3c29ee9d58): perf score=2.188937
I20260812 06:19:36.732201  8379 maintenance_manager.cc:643] P 674a7fd4a3184ab39998695dc16ea78b: FlushDeltaMemStoresOp(8035ef853db747bfa709ef3c29ee9d58) complete. Timing: real 0.011s	user 0.009s	sys 0.001s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4468,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:36.732645  8483 maintenance_manager.cc:419] P 674a7fd4a3184ab39998695dc16ea78b: Scheduling MajorDeltaCompactionOp(8035ef853db747bfa709ef3c29ee9d58): perf score=1.000000
I20260812 06:19:36.889926  8379 maintenance_manager.cc:643] P 674a7fd4a3184ab39998695dc16ea78b: MajorDeltaCompactionOp(8035ef853db747bfa709ef3c29ee9d58) complete. Timing: real 0.157s	user 0.100s	sys 0.054s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672275,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":201,"lbm_read_time_us":12199,"lbm_reads_lt_1ms":472,"lbm_write_time_us":27640,"lbm_writes_lt_1ms":443,"mutex_wait_us":85,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":15360,"update_count":2000}
I20260812 06:19:36.893168  8483 maintenance_manager.cc:419] P 674a7fd4a3184ab39998695dc16ea78b: Scheduling FlushDeltaMemStoresOp(8035ef853db747bfa709ef3c29ee9d58): perf score=10.126437
I20260812 06:19:36.943861  8379 maintenance_manager.cc:643] P 674a7fd4a3184ab39998695dc16ea78b: FlushDeltaMemStoresOp(8035ef853db747bfa709ef3c29ee9d58) complete. Timing: real 0.050s	user 0.022s	sys 0.024s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":25313,"lbm_writes_1-10_ms":3,"lbm_writes_lt_1ms":300,"reinsert_count":0,"spinlock_wait_cycles":1408,"update_count":1500}
I20260812 06:19:36.944386  8483 maintenance_manager.cc:419] P 674a7fd4a3184ab39998695dc16ea78b: Scheduling FlushDeltaMemStoresOp(8035ef853db747bfa709ef3c29ee9d58): perf score=2.188937
I20260812 06:19:36.954880  8379 maintenance_manager.cc:643] P 674a7fd4a3184ab39998695dc16ea78b: FlushDeltaMemStoresOp(8035ef853db747bfa709ef3c29ee9d58) complete. Timing: real 0.010s	user 0.005s	sys 0.004s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4053,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:36.955365  8483 maintenance_manager.cc:419] P 674a7fd4a3184ab39998695dc16ea78b: Scheduling MajorDeltaCompactionOp(8035ef853db747bfa709ef3c29ee9d58): perf score=1.000000
I20260812 06:19:37.091048  8379 maintenance_manager.cc:643] P 674a7fd4a3184ab39998695dc16ea78b: MajorDeltaCompactionOp(8035ef853db747bfa709ef3c29ee9d58) complete. Timing: real 0.136s	user 0.103s	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":338,"lbm_read_time_us":10203,"lbm_reads_lt_1ms":472,"lbm_write_time_us":26124,"lbm_writes_lt_1ms":443,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":2432,"update_count":2000}
I20260812 06:19:37.091776  8483 maintenance_manager.cc:419] P 674a7fd4a3184ab39998695dc16ea78b: Scheduling FlushDeltaMemStoresOp(8035ef853db747bfa709ef3c29ee9d58): perf score=10.126437
I20260812 06:19:37.133615  8379 maintenance_manager.cc:643] P 674a7fd4a3184ab39998695dc16ea78b: FlushDeltaMemStoresOp(8035ef853db747bfa709ef3c29ee9d58) complete. Timing: real 0.042s	user 0.024s	sys 0.008s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":14816,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:19:37.134150  8483 maintenance_manager.cc:419] P 674a7fd4a3184ab39998695dc16ea78b: Scheduling FlushDeltaMemStoresOp(8035ef853db747bfa709ef3c29ee9d58): perf score=2.188937
I20260812 06:19:37.149945  8379 maintenance_manager.cc:643] P 674a7fd4a3184ab39998695dc16ea78b: FlushDeltaMemStoresOp(8035ef853db747bfa709ef3c29ee9d58) complete. Timing: real 0.016s	user 0.010s	sys 0.003s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5971,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:37.150504  8483 maintenance_manager.cc:419] P 674a7fd4a3184ab39998695dc16ea78b: Scheduling FlushMRSOp(8035ef853db747bfa709ef3c29ee9d58): perf score=1.000000
I20260812 06:19:37.179311  8379 maintenance_manager.cc:643] P 674a7fd4a3184ab39998695dc16ea78b: FlushMRSOp(8035ef853db747bfa709ef3c29ee9d58) complete. Timing: real 0.029s	user 0.028s	sys 0.000s Metrics: {"bytes_written":1275449,"cfile_init":1,"dirs.queue_time_us":74,"dirs.run_cpu_time_us":253,"dirs.run_wall_time_us":1610,"drs_written":1,"lbm_read_time_us":52,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1561,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":31}
I20260812 06:19:37.180007  8483 maintenance_manager.cc:419] P 674a7fd4a3184ab39998695dc16ea78b: Scheduling LogGCOp(8035ef853db747bfa709ef3c29ee9d58): free 124710265 bytes of WAL
I20260812 06:19:37.180233  8379 log_reader.cc:385] T 8035ef853db747bfa709ef3c29ee9d58: removed 12 log segments from log reader
I20260812 06:19:37.180279  8379 log.cc:1079] T 8035ef853db747bfa709ef3c29ee9d58 P 674a7fd4a3184ab39998695dc16ea78b: Deleting log segment in path: /tmp/dist-test-taskPRxTjs/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515573527110-8192-0/minicluster-data/ts-0-root/wals/8035ef853db747bfa709ef3c29ee9d58/wal-000000015 (ops 72-76)
I20260812 06:19:37.180310  8379 log.cc:1079] T 8035ef853db747bfa709ef3c29ee9d58 P 674a7fd4a3184ab39998695dc16ea78b: Deleting log segment in path: /tmp/dist-test-taskPRxTjs/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515573527110-8192-0/minicluster-data/ts-0-root/wals/8035ef853db747bfa709ef3c29ee9d58/wal-000000016 (ops 77-81)
I20260812 06:19:37.180373  8379 log.cc:1079] T 8035ef853db747bfa709ef3c29ee9d58 P 674a7fd4a3184ab39998695dc16ea78b: Deleting log segment in path: /tmp/dist-test-taskPRxTjs/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515573527110-8192-0/minicluster-data/ts-0-root/wals/8035ef853db747bfa709ef3c29ee9d58/wal-000000017 (ops 82-86)
I20260812 06:19:37.180406  8379 log.cc:1079] T 8035ef853db747bfa709ef3c29ee9d58 P 674a7fd4a3184ab39998695dc16ea78b: Deleting log segment in path: /tmp/dist-test-taskPRxTjs/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515573527110-8192-0/minicluster-data/ts-0-root/wals/8035ef853db747bfa709ef3c29ee9d58/wal-000000018 (ops 87-91)
I20260812 06:19:37.180449  8379 log.cc:1079] T 8035ef853db747bfa709ef3c29ee9d58 P 674a7fd4a3184ab39998695dc16ea78b: Deleting log segment in path: /tmp/dist-test-taskPRxTjs/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515573527110-8192-0/minicluster-data/ts-0-root/wals/8035ef853db747bfa709ef3c29ee9d58/wal-000000019 (ops 92-96)
I20260812 06:19:37.180496  8379 log.cc:1079] T 8035ef853db747bfa709ef3c29ee9d58 P 674a7fd4a3184ab39998695dc16ea78b: Deleting log segment in path: /tmp/dist-test-taskPRxTjs/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515573527110-8192-0/minicluster-data/ts-0-root/wals/8035ef853db747bfa709ef3c29ee9d58/wal-000000020 (ops 97-101)
I20260812 06:19:37.180536  8379 log.cc:1079] T 8035ef853db747bfa709ef3c29ee9d58 P 674a7fd4a3184ab39998695dc16ea78b: Deleting log segment in path: /tmp/dist-test-taskPRxTjs/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515573527110-8192-0/minicluster-data/ts-0-root/wals/8035ef853db747bfa709ef3c29ee9d58/wal-000000021 (ops 102-106)
I20260812 06:19:37.180593  8379 log.cc:1079] T 8035ef853db747bfa709ef3c29ee9d58 P 674a7fd4a3184ab39998695dc16ea78b: Deleting log segment in path: /tmp/dist-test-taskPRxTjs/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515573527110-8192-0/minicluster-data/ts-0-root/wals/8035ef853db747bfa709ef3c29ee9d58/wal-000000022 (ops 107-111)
I20260812 06:19:37.180639  8379 log.cc:1079] T 8035ef853db747bfa709ef3c29ee9d58 P 674a7fd4a3184ab39998695dc16ea78b: Deleting log segment in path: /tmp/dist-test-taskPRxTjs/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515573527110-8192-0/minicluster-data/ts-0-root/wals/8035ef853db747bfa709ef3c29ee9d58/wal-000000023 (ops 112-116)
I20260812 06:19:37.180680  8379 log.cc:1079] T 8035ef853db747bfa709ef3c29ee9d58 P 674a7fd4a3184ab39998695dc16ea78b: Deleting log segment in path: /tmp/dist-test-taskPRxTjs/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515573527110-8192-0/minicluster-data/ts-0-root/wals/8035ef853db747bfa709ef3c29ee9d58/wal-000000024 (ops 117-121)
I20260812 06:19:37.180720  8379 log.cc:1079] T 8035ef853db747bfa709ef3c29ee9d58 P 674a7fd4a3184ab39998695dc16ea78b: Deleting log segment in path: /tmp/dist-test-taskPRxTjs/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515573527110-8192-0/minicluster-data/ts-0-root/wals/8035ef853db747bfa709ef3c29ee9d58/wal-000000025 (ops 122-126)
I20260812 06:19:37.180759  8379 log.cc:1079] T 8035ef853db747bfa709ef3c29ee9d58 P 674a7fd4a3184ab39998695dc16ea78b: Deleting log segment in path: /tmp/dist-test-taskPRxTjs/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515573527110-8192-0/minicluster-data/ts-0-root/wals/8035ef853db747bfa709ef3c29ee9d58/wal-000000026 (ops 127-131)
I20260812 06:19:37.210150  8379 maintenance_manager.cc:643] P 674a7fd4a3184ab39998695dc16ea78b: LogGCOp(8035ef853db747bfa709ef3c29ee9d58) complete. Timing: real 0.030s	user 0.000s	sys 0.027s Metrics: {}
I20260812 06:19:37.210693  8483 maintenance_manager.cc:419] P 674a7fd4a3184ab39998695dc16ea78b: Scheduling UndoDeltaBlockGCOp(8035ef853db747bfa709ef3c29ee9d58): 482 bytes on disk
I20260812 06:19:37.211200  8379 maintenance_manager.cc:643] P 674a7fd4a3184ab39998695dc16ea78b: UndoDeltaBlockGCOp(8035ef853db747bfa709ef3c29ee9d58) 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:19:37.211716  8483 maintenance_manager.cc:419] P 674a7fd4a3184ab39998695dc16ea78b: Scheduling FlushDeltaMemStoresOp(8035ef853db747bfa709ef3c29ee9d58): perf score=3.181125
I20260812 06:19:37.223687  8379 maintenance_manager.cc:643] P 674a7fd4a3184ab39998695dc16ea78b: FlushDeltaMemStoresOp(8035ef853db747bfa709ef3c29ee9d58) complete. Timing: real 0.012s	user 0.011s	sys 0.000s Metrics: {"bytes_written":4512899,"delete_count":0,"lbm_write_time_us":4510,"lbm_writes_lt_1ms":113,"reinsert_count":0,"update_count":550}
I20260812 06:19:37.224138  8483 maintenance_manager.cc:419] P 674a7fd4a3184ab39998695dc16ea78b: Scheduling FlushDeltaMemStoresOp(8035ef853db747bfa709ef3c29ee9d58): perf score=2.188937
I20260812 06:19:37.233774  8379 maintenance_manager.cc:643] P 674a7fd4a3184ab39998695dc16ea78b: FlushDeltaMemStoresOp(8035ef853db747bfa709ef3c29ee9d58) complete. Timing: real 0.009s	user 0.005s	sys 0.003s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":4079,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:19:37.234300  8483 maintenance_manager.cc:419] P 674a7fd4a3184ab39998695dc16ea78b: Scheduling MajorDeltaCompactionOp(8035ef853db747bfa709ef3c29ee9d58): perf score=1.000000
I20260812 06:19:37.411306  8379 maintenance_manager.cc:643] P 674a7fd4a3184ab39998695dc16ea78b: MajorDeltaCompactionOp(8035ef853db747bfa709ef3c29ee9d58) complete. Timing: real 0.177s	user 0.133s	sys 0.035s Metrics: {"cfile_cache_miss":634,"cfile_cache_miss_bytes":28877325,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":5533,"lbm_read_time_us":12139,"lbm_reads_lt_1ms":674,"lbm_write_time_us":35225,"lbm_writes_lt_1ms":643,"mutex_wait_us":21,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":18816,"thread_start_us":75,"threads_started":1,"update_count":3000}
I20260812 06:19:37.411939  8483 maintenance_manager.cc:419] P 674a7fd4a3184ab39998695dc16ea78b: Scheduling FlushDeltaMemStoresOp(8035ef853db747bfa709ef3c29ee9d58): perf score=14.095187
I20260812 06:19:37.465552  8379 maintenance_manager.cc:643] P 674a7fd4a3184ab39998695dc16ea78b: FlushDeltaMemStoresOp(8035ef853db747bfa709ef3c29ee9d58) complete. Timing: real 0.053s	user 0.038s	sys 0.012s Metrics: {"bytes_written":16409903,"delete_count":0,"lbm_write_time_us":24008,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":402,"reinsert_count":0,"spinlock_wait_cycles":1280,"update_count":2000}
I20260812 06:19:37.466044  8483 maintenance_manager.cc:419] P 674a7fd4a3184ab39998695dc16ea78b: Scheduling FlushDeltaMemStoresOp(8035ef853db747bfa709ef3c29ee9d58): perf score=2.188937
I20260812 06:19:37.481873  8379 maintenance_manager.cc:643] P 674a7fd4a3184ab39998695dc16ea78b: FlushDeltaMemStoresOp(8035ef853db747bfa709ef3c29ee9d58) complete. Timing: real 0.016s	user 0.010s	sys 0.003s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6158,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:37.482402  8483 maintenance_manager.cc:419] P 674a7fd4a3184ab39998695dc16ea78b: Scheduling MajorDeltaCompactionOp(8035ef853db747bfa709ef3c29ee9d58): perf score=1.000000
I20260812 06:19:37.631197  8379 maintenance_manager.cc:643] P 674a7fd4a3184ab39998695dc16ea78b: MajorDeltaCompactionOp(8035ef853db747bfa709ef3c29ee9d58) complete. Timing: real 0.149s	user 0.110s	sys 0.037s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774690,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":1180,"lbm_read_time_us":10516,"lbm_reads_lt_1ms":572,"lbm_write_time_us":30661,"lbm_writes_lt_1ms":543,"mutex_wait_us":61,"peak_mem_usage":63115900,"reinsert_count":0,"update_count":2500}
I20260812 06:19:37.631780  8483 maintenance_manager.cc:419] P 674a7fd4a3184ab39998695dc16ea78b: Scheduling FlushDeltaMemStoresOp(8035ef853db747bfa709ef3c29ee9d58): perf score=14.095187
I20260812 06:19:37.685753  8379 maintenance_manager.cc:643] P 674a7fd4a3184ab39998695dc16ea78b: FlushDeltaMemStoresOp(8035ef853db747bfa709ef3c29ee9d58) complete. Timing: real 0.054s	user 0.029s	sys 0.018s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":22512,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:37.686316  8483 maintenance_manager.cc:419] P 674a7fd4a3184ab39998695dc16ea78b: Scheduling FlushDeltaMemStoresOp(8035ef853db747bfa709ef3c29ee9d58): perf score=2.188937
I20260812 06:19:37.698838  8379 maintenance_manager.cc:643] P 674a7fd4a3184ab39998695dc16ea78b: FlushDeltaMemStoresOp(8035ef853db747bfa709ef3c29ee9d58) complete. Timing: real 0.012s	user 0.006s	sys 0.003s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4386,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:37.699529  8483 maintenance_manager.cc:419] P 674a7fd4a3184ab39998695dc16ea78b: Scheduling MajorDeltaCompactionOp(8035ef853db747bfa709ef3c29ee9d58): perf score=1.000000
I20260812 06:19:37.858455  8379 maintenance_manager.cc:643] P 674a7fd4a3184ab39998695dc16ea78b: MajorDeltaCompactionOp(8035ef853db747bfa709ef3c29ee9d58) complete. Timing: real 0.159s	user 0.114s	sys 0.037s 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":889,"lbm_read_time_us":10405,"lbm_reads_lt_1ms":572,"lbm_write_time_us":29541,"lbm_writes_lt_1ms":543,"mutex_wait_us":312,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":2816,"update_count":2500}
I20260812 06:19:37.859166  8483 maintenance_manager.cc:419] P 674a7fd4a3184ab39998695dc16ea78b: Scheduling FlushDeltaMemStoresOp(8035ef853db747bfa709ef3c29ee9d58): perf score=14.095187
I20260812 06:19:37.905331  8379 maintenance_manager.cc:643] P 674a7fd4a3184ab39998695dc16ea78b: FlushDeltaMemStoresOp(8035ef853db747bfa709ef3c29ee9d58) complete. Timing: real 0.046s	user 0.031s	sys 0.013s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":20371,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:37.905879  8483 maintenance_manager.cc:419] P 674a7fd4a3184ab39998695dc16ea78b: Scheduling FlushDeltaMemStoresOp(8035ef853db747bfa709ef3c29ee9d58): perf score=2.188937
I20260812 06:19:37.919600  8379 maintenance_manager.cc:643] P 674a7fd4a3184ab39998695dc16ea78b: FlushDeltaMemStoresOp(8035ef853db747bfa709ef3c29ee9d58) complete. Timing: real 0.013s	user 0.009s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5497,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:37.920420  8483 maintenance_manager.cc:419] P 674a7fd4a3184ab39998695dc16ea78b: Scheduling MajorDeltaCompactionOp(8035ef853db747bfa709ef3c29ee9d58): perf score=1.000000
I20260812 06:19:38.088809  8379 maintenance_manager.cc:643] P 674a7fd4a3184ab39998695dc16ea78b: MajorDeltaCompactionOp(8035ef853db747bfa709ef3c29ee9d58) complete. Timing: real 0.168s	user 0.113s	sys 0.043s 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":215,"lbm_read_time_us":10703,"lbm_reads_lt_1ms":572,"lbm_write_time_us":30265,"lbm_writes_lt_1ms":543,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":8704,"update_count":2500}
I20260812 06:19:38.089504  8483 maintenance_manager.cc:419] P 674a7fd4a3184ab39998695dc16ea78b: Scheduling FlushDeltaMemStoresOp(8035ef853db747bfa709ef3c29ee9d58): perf score=14.095187
I20260812 06:19:38.136277  8379 maintenance_manager.cc:643] P 674a7fd4a3184ab39998695dc16ea78b: FlushDeltaMemStoresOp(8035ef853db747bfa709ef3c29ee9d58) complete. Timing: real 0.047s	user 0.029s	sys 0.016s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":20392,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:38.136977  8483 maintenance_manager.cc:419] P 674a7fd4a3184ab39998695dc16ea78b: Scheduling MajorDeltaCompactionOp(8035ef853db747bfa709ef3c29ee9d58): perf score=1.000000
I20260812 06:19:38.285616  8379 maintenance_manager.cc:643] P 674a7fd4a3184ab39998695dc16ea78b: MajorDeltaCompactionOp(8035ef853db747bfa709ef3c29ee9d58) complete. Timing: real 0.148s	user 0.091s	sys 0.056s Metrics: {"cfile_cache_miss":431,"cfile_cache_miss_bytes":20672158,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":1,"delta_iterators_relevant":1,"dirs.queue_time_us":183,"lbm_read_time_us":11301,"lbm_reads_lt_1ms":463,"lbm_write_time_us":25577,"lbm_writes_lt_1ms":443,"mutex_wait_us":69,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":5888,"update_count":2000}
I20260812 06:19:38.286407  8483 maintenance_manager.cc:419] P 674a7fd4a3184ab39998695dc16ea78b: Scheduling FlushDeltaMemStoresOp(8035ef853db747bfa709ef3c29ee9d58): perf score=11.118625
I20260812 06:19:38.326392  8379 maintenance_manager.cc:643] P 674a7fd4a3184ab39998695dc16ea78b: FlushDeltaMemStoresOp(8035ef853db747bfa709ef3c29ee9d58) complete. Timing: real 0.040s	user 0.031s	sys 0.003s Metrics: {"bytes_written":12717737,"delete_count":0,"lbm_write_time_us":15648,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:19:38.326933  8483 maintenance_manager.cc:419] P 674a7fd4a3184ab39998695dc16ea78b: Scheduling FlushDeltaMemStoresOp(8035ef853db747bfa709ef3c29ee9d58): perf score=2.188937
I20260812 06:19:38.341440  8379 maintenance_manager.cc:643] P 674a7fd4a3184ab39998695dc16ea78b: FlushDeltaMemStoresOp(8035ef853db747bfa709ef3c29ee9d58) complete. Timing: real 0.014s	user 0.002s	sys 0.007s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4369,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:38.341923  8483 maintenance_manager.cc:419] P 674a7fd4a3184ab39998695dc16ea78b: Scheduling FlushDeltaMemStoresOp(8035ef853db747bfa709ef3c29ee9d58): perf score=2.188937
I20260812 06:19:38.351595  8379 maintenance_manager.cc:643] P 674a7fd4a3184ab39998695dc16ea78b: FlushDeltaMemStoresOp(8035ef853db747bfa709ef3c29ee9d58) complete. Timing: real 0.009s	user 0.005s	sys 0.004s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3703,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:19:38.352026  8483 maintenance_manager.cc:419] P 674a7fd4a3184ab39998695dc16ea78b: Scheduling MajorDeltaCompactionOp(8035ef853db747bfa709ef3c29ee9d58): perf score=1.000000
I20260812 06:19:38.542043  8379 maintenance_manager.cc:643] P 674a7fd4a3184ab39998695dc16ea78b: MajorDeltaCompactionOp(8035ef853db747bfa709ef3c29ee9d58) complete. Timing: real 0.190s	user 0.140s	sys 0.040s Metrics: {"cfile_cache_miss":533,"cfile_cache_miss_bytes":24774801,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":903,"lbm_read_time_us":11615,"lbm_reads_lt_1ms":573,"lbm_write_time_us":30858,"lbm_writes_lt_1ms":543,"mutex_wait_us":66,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":7424,"update_count":2500}
I20260812 06:19:38.542558  8483 maintenance_manager.cc:419] P 674a7fd4a3184ab39998695dc16ea78b: Scheduling FlushDeltaMemStoresOp(8035ef853db747bfa709ef3c29ee9d58): perf score=14.095187
I20260812 06:19:38.597404  8379 maintenance_manager.cc:643] P 674a7fd4a3184ab39998695dc16ea78b: FlushDeltaMemStoresOp(8035ef853db747bfa709ef3c29ee9d58) complete. Timing: real 0.055s	user 0.029s	sys 0.019s Metrics: {"bytes_written":16409903,"delete_count":0,"lbm_write_time_us":22511,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:38.597906  8483 maintenance_manager.cc:419] P 674a7fd4a3184ab39998695dc16ea78b: Scheduling FlushDeltaMemStoresOp(8035ef853db747bfa709ef3c29ee9d58): perf score=2.188937
I20260812 06:19:38.613935  8379 maintenance_manager.cc:643] P 674a7fd4a3184ab39998695dc16ea78b: FlushDeltaMemStoresOp(8035ef853db747bfa709ef3c29ee9d58) complete. Timing: real 0.016s	user 0.006s	sys 0.007s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6126,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:38.614612  8483 maintenance_manager.cc:419] P 674a7fd4a3184ab39998695dc16ea78b: Scheduling FlushMRSOp(8035ef853db747bfa709ef3c29ee9d58): perf score=1.000000
I20260812 06:19:38.645519  8379 maintenance_manager.cc:643] P 674a7fd4a3184ab39998695dc16ea78b: FlushMRSOp(8035ef853db747bfa709ef3c29ee9d58) complete. Timing: real 0.031s	user 0.026s	sys 0.003s Metrics: {"bytes_written":1275447,"cfile_init":1,"dirs.queue_time_us":83,"dirs.run_cpu_time_us":248,"dirs.run_wall_time_us":1327,"drs_written":1,"lbm_read_time_us":59,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1945,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":31}
I20260812 06:19:38.646282  8483 maintenance_manager.cc:419] P 674a7fd4a3184ab39998695dc16ea78b: Scheduling LogGCOp(8035ef853db747bfa709ef3c29ee9d58): free 133024698 bytes of WAL
I20260812 06:19:38.646566  8379 log_reader.cc:385] T 8035ef853db747bfa709ef3c29ee9d58: removed 13 log segments from log reader
I20260812 06:19:38.646633  8379 log.cc:1079] T 8035ef853db747bfa709ef3c29ee9d58 P 674a7fd4a3184ab39998695dc16ea78b: Deleting log segment in path: /tmp/dist-test-taskPRxTjs/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515573527110-8192-0/minicluster-data/ts-0-root/wals/8035ef853db747bfa709ef3c29ee9d58/wal-000000027 (ops 132-136)
I20260812 06:19:38.646674  8379 log.cc:1079] T 8035ef853db747bfa709ef3c29ee9d58 P 674a7fd4a3184ab39998695dc16ea78b: Deleting log segment in path: /tmp/dist-test-taskPRxTjs/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515573527110-8192-0/minicluster-data/ts-0-root/wals/8035ef853db747bfa709ef3c29ee9d58/wal-000000028 (ops 137-141)
I20260812 06:19:38.646704  8379 log.cc:1079] T 8035ef853db747bfa709ef3c29ee9d58 P 674a7fd4a3184ab39998695dc16ea78b: Deleting log segment in path: /tmp/dist-test-taskPRxTjs/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515573527110-8192-0/minicluster-data/ts-0-root/wals/8035ef853db747bfa709ef3c29ee9d58/wal-000000029 (ops 142-146)
I20260812 06:19:38.646734  8379 log.cc:1079] T 8035ef853db747bfa709ef3c29ee9d58 P 674a7fd4a3184ab39998695dc16ea78b: Deleting log segment in path: /tmp/dist-test-taskPRxTjs/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515573527110-8192-0/minicluster-data/ts-0-root/wals/8035ef853db747bfa709ef3c29ee9d58/wal-000000030 (ops 147-150)
I20260812 06:19:38.646765  8379 log.cc:1079] T 8035ef853db747bfa709ef3c29ee9d58 P 674a7fd4a3184ab39998695dc16ea78b: Deleting log segment in path: /tmp/dist-test-taskPRxTjs/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515573527110-8192-0/minicluster-data/ts-0-root/wals/8035ef853db747bfa709ef3c29ee9d58/wal-000000031 (ops 151-155)
I20260812 06:19:38.646797  8379 log.cc:1079] T 8035ef853db747bfa709ef3c29ee9d58 P 674a7fd4a3184ab39998695dc16ea78b: Deleting log segment in path: /tmp/dist-test-taskPRxTjs/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515573527110-8192-0/minicluster-data/ts-0-root/wals/8035ef853db747bfa709ef3c29ee9d58/wal-000000032 (ops 156-160)
I20260812 06:19:38.646826  8379 log.cc:1079] T 8035ef853db747bfa709ef3c29ee9d58 P 674a7fd4a3184ab39998695dc16ea78b: Deleting log segment in path: /tmp/dist-test-taskPRxTjs/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515573527110-8192-0/minicluster-data/ts-0-root/wals/8035ef853db747bfa709ef3c29ee9d58/wal-000000033 (ops 161-165)
I20260812 06:19:38.646852  8379 log.cc:1079] T 8035ef853db747bfa709ef3c29ee9d58 P 674a7fd4a3184ab39998695dc16ea78b: Deleting log segment in path: /tmp/dist-test-taskPRxTjs/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515573527110-8192-0/minicluster-data/ts-0-root/wals/8035ef853db747bfa709ef3c29ee9d58/wal-000000034 (ops 166-170)
I20260812 06:19:38.646881  8379 log.cc:1079] T 8035ef853db747bfa709ef3c29ee9d58 P 674a7fd4a3184ab39998695dc16ea78b: Deleting log segment in path: /tmp/dist-test-taskPRxTjs/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515573527110-8192-0/minicluster-data/ts-0-root/wals/8035ef853db747bfa709ef3c29ee9d58/wal-000000035 (ops 171-175)
I20260812 06:19:38.646903  8379 log.cc:1079] T 8035ef853db747bfa709ef3c29ee9d58 P 674a7fd4a3184ab39998695dc16ea78b: Deleting log segment in path: /tmp/dist-test-taskPRxTjs/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515573527110-8192-0/minicluster-data/ts-0-root/wals/8035ef853db747bfa709ef3c29ee9d58/wal-000000036 (ops 176-180)
I20260812 06:19:38.646939  8379 log.cc:1079] T 8035ef853db747bfa709ef3c29ee9d58 P 674a7fd4a3184ab39998695dc16ea78b: Deleting log segment in path: /tmp/dist-test-taskPRxTjs/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515573527110-8192-0/minicluster-data/ts-0-root/wals/8035ef853db747bfa709ef3c29ee9d58/wal-000000037 (ops 181-185)
I20260812 06:19:38.646965  8379 log.cc:1079] T 8035ef853db747bfa709ef3c29ee9d58 P 674a7fd4a3184ab39998695dc16ea78b: Deleting log segment in path: /tmp/dist-test-taskPRxTjs/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515573527110-8192-0/minicluster-data/ts-0-root/wals/8035ef853db747bfa709ef3c29ee9d58/wal-000000038 (ops 186-190)
I20260812 06:19:38.646988  8379 log.cc:1079] T 8035ef853db747bfa709ef3c29ee9d58 P 674a7fd4a3184ab39998695dc16ea78b: Deleting log segment in path: /tmp/dist-test-taskPRxTjs/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515573527110-8192-0/minicluster-data/ts-0-root/wals/8035ef853db747bfa709ef3c29ee9d58/wal-000000039 (ops 191-195)
I20260812 06:19:38.681197  8379 maintenance_manager.cc:643] P 674a7fd4a3184ab39998695dc16ea78b: LogGCOp(8035ef853db747bfa709ef3c29ee9d58) complete. Timing: real 0.035s	user 0.000s	sys 0.033s Metrics: {}
I20260812 06:19:38.686410  8483 maintenance_manager.cc:419] P 674a7fd4a3184ab39998695dc16ea78b: Scheduling UndoDeltaBlockGCOp(8035ef853db747bfa709ef3c29ee9d58): 483 bytes on disk
I20260812 06:19:38.687282  8379 maintenance_manager.cc:643] P 674a7fd4a3184ab39998695dc16ea78b: UndoDeltaBlockGCOp(8035ef853db747bfa709ef3c29ee9d58) complete. Timing: real 0.001s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":93,"lbm_reads_lt_1ms":4}
I20260812 06:19:38.688086  8483 maintenance_manager.cc:419] P 674a7fd4a3184ab39998695dc16ea78b: Scheduling FlushDeltaMemStoresOp(8035ef853db747bfa709ef3c29ee9d58): perf score=2.188937
I20260812 06:19:38.709944  8379 maintenance_manager.cc:643] P 674a7fd4a3184ab39998695dc16ea78b: FlushDeltaMemStoresOp(8035ef853db747bfa709ef3c29ee9d58) complete. Timing: real 0.022s	user 0.006s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6564,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:38.710421  8483 maintenance_manager.cc:419] P 674a7fd4a3184ab39998695dc16ea78b: Scheduling FlushDeltaMemStoresOp(8035ef853db747bfa709ef3c29ee9d58): perf score=2.188937
I20260812 06:19:38.721544  8379 maintenance_manager.cc:643] P 674a7fd4a3184ab39998695dc16ea78b: FlushDeltaMemStoresOp(8035ef853db747bfa709ef3c29ee9d58) complete. Timing: real 0.011s	user 0.006s	sys 0.003s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4454,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:38.722043  8483 maintenance_manager.cc:419] P 674a7fd4a3184ab39998695dc16ea78b: Scheduling MajorDeltaCompactionOp(8035ef853db747bfa709ef3c29ee9d58): perf score=1.000000
I20260812 06:19:38.757802  8192 heavy-update-compaction-itest.cc:229] Time spent updating: real 4.967s	user 1.875s	sys 0.130s
I20260812 06:19:38.860656  8192 heavy-update-compaction-itest.cc:265] Time spent scanning: real 0.102s	user 0.002s	sys 0.000s
I20260812 06:19:38.861357  8192 tablet_server.cc:179] TabletServer@127.8.0.1:0 shutting down...
I20260812 06:19:38.917819  8379 maintenance_manager.cc:643] P 674a7fd4a3184ab39998695dc16ea78b: MajorDeltaCompactionOp(8035ef853db747bfa709ef3c29ee9d58) complete. Timing: real 0.196s	user 0.110s	sys 0.085s Metrics: {"cfile_cache_miss":734,"cfile_cache_miss_bytes":32979752,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":908,"lbm_read_time_us":15877,"lbm_reads_lt_1ms":770,"lbm_write_time_us":33632,"lbm_writes_lt_1ms":743,"mutex_wait_us":345,"peak_mem_usage":87969044,"reinsert_count":0,"spinlock_wait_cycles":12160,"thread_start_us":76,"threads_started":1,"update_count":3500}
I20260812 06:19:38.919111  8192 ts_tablet_manager.cc:1507] Shutting down tablet manager...
I20260812 06:19:38.919530  8192 tablet_replica.cc:333] T 8035ef853db747bfa709ef3c29ee9d58 P 674a7fd4a3184ab39998695dc16ea78b: stopping tablet replica
I20260812 06:19:38.919783  8192 raft_consensus.cc:2243] T 8035ef853db747bfa709ef3c29ee9d58 P 674a7fd4a3184ab39998695dc16ea78b [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:19:38.920037  8192 raft_consensus.cc:2272] T 8035ef853db747bfa709ef3c29ee9d58 P 674a7fd4a3184ab39998695dc16ea78b [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:19:38.936275  8192 tablet_server.cc:196] TabletServer@127.8.0.1:0 shutdown complete.
I20260812 06:19:38.976691  8192 master.cc:562] Master@127.8.0.62:37347 shutting down...
I20260812 06:19:38.980626  8192 raft_consensus.cc:2243] T 00000000000000000000000000000000 P 30a2ca1a172e46f6ab22d935e53da50b [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:19:38.980821  8192 raft_consensus.cc:2272] T 00000000000000000000000000000000 P 30a2ca1a172e46f6ab22d935e53da50b [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:19:38.980882  8192 tablet_replica.cc:333] T 00000000000000000000000000000000 P 30a2ca1a172e46f6ab22d935e53da50b: stopping tablet replica
I20260812 06:19:38.994331  8192 master.cc:584] Master@127.8.0.62:37347 shutdown complete.
[       OK ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/0 (5549 ms)
[ RUN      ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/1
I20260812 06:19:39.101329  8192 internal_mini_cluster.cc:156] Creating distributed mini masters. Addrs: 127.8.0.62:41661
I20260812 06:19:39.101748  8192 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:19:39.103820  8533 instance_detector.cc:116] could not retrieve Azure instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:19:39.103847  8535 instance_detector.cc:116] could not retrieve OpenStack instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:19:39.103919  8530 instance_detector.cc:116] could not retrieve AWS instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:19:39.103958  8192 server_base.cc:1061] running on GCE node
I20260812 06:19:39.104238  8192 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:19:39.104283  8192 system_unsync_time.cc:38] NTP support is disabled. Clock error bounds will not be accurate. This configuration is not suitable for distributed clusters.
I20260812 06:19:39.104300  8192 hybrid_clock.cc:648] HybridClock initialized: now 1786515579104299 us; error 0 us; skew 500 ppm
I20260812 06:19:39.105247  8192 webserver.cc:533] Webserver started at http://127.8.0.62:33931/ using document root <none> and password file <none>
I20260812 06:19:39.105440  8192 fs_manager.cc:362] Metadata directory not provided
I20260812 06:19:39.105487  8192 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:19:39.105590  8192 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:19:39.105998  8192 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskPRxTjs/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515573527110-8192-0/minicluster-data/master-0-root/instance:
uuid: "da2f32c1fd0a4def8d2e8d0f6522e944"
format_stamp: "Formatted at 2026-08-12 06:19:39 on dist-test-slave-n326"
I20260812 06:19:39.107571  8192 fs_manager.cc:696] Time spent creating directory manager: real 0.001s	user 0.000s	sys 0.002s
I20260812 06:19:39.108479  8544 log_block_manager.cc:4127] Time spent loading block containers with low live blocks: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:19:39.108790  8192 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.000s	sys 0.001s
I20260812 06:19:39.108856  8192 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskPRxTjs/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515573527110-8192-0/minicluster-data/master-0-root
uuid: "da2f32c1fd0a4def8d2e8d0f6522e944"
format_stamp: "Formatted at 2026-08-12 06:19:39 on dist-test-slave-n326"
I20260812 06:19:39.108911  8192 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskPRxTjs/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515573527110-8192-0/minicluster-data/master-0-root
metadata directory: /tmp/dist-test-taskPRxTjs/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515573527110-8192-0/minicluster-data/master-0-root
1 data directories: /tmp/dist-test-taskPRxTjs/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515573527110-8192-0/minicluster-data/master-0-root/data
Total live blocks: 0
Total live bytes: 0
Total live bytes (after alignment): 0
Total number of LBM containers: 0 (0 full)
Did not check for missing blocks
Did not check for orphaned blocks
Total full LBM containers with extra space: 0 (0 repaired)
Total full LBM container extra space in bytes: 0 (0 repaired)
Total incomplete LBM containers: 0 (0 repaired)
Total LBM partial records: 0 (0 repaired)
Total corrupted LBM metadata records in RocksDB: 0 (0 repaired)
I20260812 06:19:39.125794  8192 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:19:39.126178  8192 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:19:39.130188  8192 rpc_server.cc:307] RPC server started. Bound to: 127.8.0.62:41661
I20260812 06:19:39.132541  8638 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet 00000000000000000000000000000000. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:19:39.138139  8637 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.8.0.62:41661 every 8 connection(s)
I20260812 06:19:39.138391  8638 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P da2f32c1fd0a4def8d2e8d0f6522e944: Bootstrap starting.
I20260812 06:19:39.139278  8638 tablet_bootstrap.cc:654] T 00000000000000000000000000000000 P da2f32c1fd0a4def8d2e8d0f6522e944: Neither blocks nor log segments found. Creating new log.
I20260812 06:19:39.140338  8638 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P da2f32c1fd0a4def8d2e8d0f6522e944: No bootstrap required, opened a new log
I20260812 06:19:39.140751  8638 raft_consensus.cc:359] T 00000000000000000000000000000000 P da2f32c1fd0a4def8d2e8d0f6522e944 [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "da2f32c1fd0a4def8d2e8d0f6522e944" member_type: VOTER }
I20260812 06:19:39.140844  8638 raft_consensus.cc:385] T 00000000000000000000000000000000 P da2f32c1fd0a4def8d2e8d0f6522e944 [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:19:39.140869  8638 raft_consensus.cc:740] T 00000000000000000000000000000000 P da2f32c1fd0a4def8d2e8d0f6522e944 [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: da2f32c1fd0a4def8d2e8d0f6522e944, State: Initialized, Role: FOLLOWER
I20260812 06:19:39.141043  8638 consensus_queue.cc:260] T 00000000000000000000000000000000 P da2f32c1fd0a4def8d2e8d0f6522e944 [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: "da2f32c1fd0a4def8d2e8d0f6522e944" member_type: VOTER }
I20260812 06:19:39.141129  8638 raft_consensus.cc:399] T 00000000000000000000000000000000 P da2f32c1fd0a4def8d2e8d0f6522e944 [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:19:39.141192  8638 raft_consensus.cc:493] T 00000000000000000000000000000000 P da2f32c1fd0a4def8d2e8d0f6522e944 [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:19:39.141269  8638 raft_consensus.cc:3060] T 00000000000000000000000000000000 P da2f32c1fd0a4def8d2e8d0f6522e944 [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:19:39.142015  8638 raft_consensus.cc:515] T 00000000000000000000000000000000 P da2f32c1fd0a4def8d2e8d0f6522e944 [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "da2f32c1fd0a4def8d2e8d0f6522e944" member_type: VOTER }
I20260812 06:19:39.142180  8638 leader_election.cc:304] T 00000000000000000000000000000000 P da2f32c1fd0a4def8d2e8d0f6522e944 [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: da2f32c1fd0a4def8d2e8d0f6522e944; no voters: 
I20260812 06:19:39.142397  8638 leader_election.cc:290] T 00000000000000000000000000000000 P da2f32c1fd0a4def8d2e8d0f6522e944 [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:19:39.142668  8646 raft_consensus.cc:2804] T 00000000000000000000000000000000 P da2f32c1fd0a4def8d2e8d0f6522e944 [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:19:39.142859  8646 raft_consensus.cc:697] T 00000000000000000000000000000000 P da2f32c1fd0a4def8d2e8d0f6522e944 [term 1 LEADER]: Becoming Leader. State: Replica: da2f32c1fd0a4def8d2e8d0f6522e944, State: Running, Role: LEADER
I20260812 06:19:39.142877  8638 sys_catalog.cc:565] T 00000000000000000000000000000000 P da2f32c1fd0a4def8d2e8d0f6522e944 [sys.catalog]: configured and running, proceeding with master startup.
I20260812 06:19:39.143039  8646 consensus_queue.cc:237] T 00000000000000000000000000000000 P da2f32c1fd0a4def8d2e8d0f6522e944 [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: "da2f32c1fd0a4def8d2e8d0f6522e944" member_type: VOTER }
I20260812 06:19:39.143640  8648 sys_catalog.cc:455] T 00000000000000000000000000000000 P da2f32c1fd0a4def8d2e8d0f6522e944 [sys.catalog]: SysCatalogTable state changed. Reason: New leader da2f32c1fd0a4def8d2e8d0f6522e944. Latest consensus state: current_term: 1 leader_uuid: "da2f32c1fd0a4def8d2e8d0f6522e944" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "da2f32c1fd0a4def8d2e8d0f6522e944" member_type: VOTER } }
I20260812 06:19:39.143733  8648 sys_catalog.cc:458] T 00000000000000000000000000000000 P da2f32c1fd0a4def8d2e8d0f6522e944 [sys.catalog]: This master's current role is: LEADER
I20260812 06:19:39.143877  8647 sys_catalog.cc:455] T 00000000000000000000000000000000 P da2f32c1fd0a4def8d2e8d0f6522e944 [sys.catalog]: SysCatalogTable state changed. Reason: RaftConsensus started. Latest consensus state: current_term: 1 leader_uuid: "da2f32c1fd0a4def8d2e8d0f6522e944" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "da2f32c1fd0a4def8d2e8d0f6522e944" member_type: VOTER } }
I20260812 06:19:39.143987  8647 sys_catalog.cc:458] T 00000000000000000000000000000000 P da2f32c1fd0a4def8d2e8d0f6522e944 [sys.catalog]: This master's current role is: LEADER
I20260812 06:19:39.144385  8665 catalog_manager.cc:1511] Loading table and tablet metadata into memory...
I20260812 06:19:39.145419  8665 catalog_manager.cc:1520] Initializing Kudu cluster ID...
I20260812 06:19:39.145613  8192 internal_mini_cluster.cc:184] Waiting to initialize catalog manager on master 0
I20260812 06:19:39.147356  8665 catalog_manager.cc:1383] Generated new cluster ID: 7d186af870a44ebbaa71dc5a83763f13
I20260812 06:19:39.147419  8665 catalog_manager.cc:1531] Initializing Kudu internal certificate authority...
I20260812 06:19:39.155392  8665 catalog_manager.cc:1406] Generated new certificate authority record
I20260812 06:19:39.155925  8665 catalog_manager.cc:1540] Loading token signing keys...
I20260812 06:19:39.167444  8665 catalog_manager.cc:6092] T 00000000000000000000000000000000 P da2f32c1fd0a4def8d2e8d0f6522e944: Generated new TSK 0
I20260812 06:19:39.167615  8665 catalog_manager.cc:1550] Initializing in-progress tserver states...
I20260812 06:19:39.178025  8192 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:19:39.180230  8688 instance_detector.cc:116] could not retrieve OpenStack instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:19:39.180197  8685 instance_detector.cc:116] could not retrieve Azure instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:19:39.180222  8684 instance_detector.cc:116] could not retrieve AWS instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:19:39.180254  8192 server_base.cc:1061] running on GCE node
I20260812 06:19:39.180615  8192 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:19:39.180672  8192 system_unsync_time.cc:38] NTP support is disabled. Clock error bounds will not be accurate. This configuration is not suitable for distributed clusters.
I20260812 06:19:39.180706  8192 hybrid_clock.cc:648] HybridClock initialized: now 1786515579180706 us; error 0 us; skew 500 ppm
I20260812 06:19:39.181638  8192 webserver.cc:533] Webserver started at http://127.8.0.1:39429/ using document root <none> and password file <none>
I20260812 06:19:39.181828  8192 fs_manager.cc:362] Metadata directory not provided
I20260812 06:19:39.181900  8192 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:19:39.181981  8192 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:19:39.182405  8192 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskPRxTjs/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515573527110-8192-0/minicluster-data/ts-0-root/instance:
uuid: "8c547e315ff1493aa15d7b77106d12f5"
format_stamp: "Formatted at 2026-08-12 06:19:39 on dist-test-slave-n326"
I20260812 06:19:39.184065  8192 fs_manager.cc:696] Time spent creating directory manager: real 0.001s	user 0.000s	sys 0.002s
I20260812 06:19:39.185041  8697 log_block_manager.cc:4127] Time spent loading block containers with low live blocks: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:19:39.185400  8192 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.001s	sys 0.000s
I20260812 06:19:39.185493  8192 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskPRxTjs/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515573527110-8192-0/minicluster-data/ts-0-root
uuid: "8c547e315ff1493aa15d7b77106d12f5"
format_stamp: "Formatted at 2026-08-12 06:19:39 on dist-test-slave-n326"
I20260812 06:19:39.185583  8192 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskPRxTjs/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515573527110-8192-0/minicluster-data/ts-0-root
metadata directory: /tmp/dist-test-taskPRxTjs/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515573527110-8192-0/minicluster-data/ts-0-root
1 data directories: /tmp/dist-test-taskPRxTjs/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515573527110-8192-0/minicluster-data/ts-0-root/data
Total live blocks: 0
Total live bytes: 0
Total live bytes (after alignment): 0
Total number of LBM containers: 0 (0 full)
Did not check for missing blocks
Did not check for orphaned blocks
Total full LBM containers with extra space: 0 (0 repaired)
Total full LBM container extra space in bytes: 0 (0 repaired)
Total incomplete LBM containers: 0 (0 repaired)
Total LBM partial records: 0 (0 repaired)
Total corrupted LBM metadata records in RocksDB: 0 (0 repaired)
I20260812 06:19:39.218379  8192 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:19:39.218856  8192 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:19:39.219290  8192 txn_system_client.cc:432] TxnSystemClient initialization is disabled...
I20260812 06:19:39.219789  8192 ts_tablet_manager.cc:585] Loaded tablet metadata (0 total tablets, 0 live tablets)
I20260812 06:19:39.219853  8192 ts_tablet_manager.cc:531] Time spent load tablet metadata: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:19:39.219906  8192 ts_tablet_manager.cc:616] Registered 0 tablets
I20260812 06:19:39.219956  8192 ts_tablet_manager.cc:595] Time spent register tablets: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:19:39.224380  8192 rpc_server.cc:307] RPC server started. Bound to: 127.8.0.1:46631
I20260812 06:19:39.224416  8815 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.8.0.1:46631 every 8 connection(s)
I20260812 06:19:39.235737  8816 heartbeater.cc:344] Connected to a master server at 127.8.0.62:41661
I20260812 06:19:39.235879  8816 heartbeater.cc:461] Registering TS with master...
I20260812 06:19:39.236155  8816 heartbeater.cc:507] Master 127.8.0.62:41661 requested a full tablet report, sending...
I20260812 06:19:39.236828  8575 ts_manager.cc:194] Registered new tserver with Master: 8c547e315ff1493aa15d7b77106d12f5 (127.8.0.1:46631)
I20260812 06:19:39.236960  8192 internal_mini_cluster.cc:371] 1 TS(s) registered with all masters after 0.012157222s
I20260812 06:19:39.237620  8575 master_service.cc:502] Signed X509 certificate for tserver {username='slave'} at 127.0.0.1:36326
I20260812 06:19:39.244266  8575 catalog_manager.cc:2283] Servicing CreateTable request from {username='slave'} at 127.0.0.1:36342:
name: "heavy-update-compaction-test"
schema {
  columns {
    name: "key"
    type: INT64
    is_key: true
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_a"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_b"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_c"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_d"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_e"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
}
num_replicas: 1
split_rows_range_bounds {
}
partition_schema {
  range_schema {
  }
}
I20260812 06:19:39.253410  8763 tablet_service.cc:1511] Processing CreateTablet for tablet 69f5314346b4472fb02c8eab168ae05a (DEFAULT_TABLE table=heavy-update-compaction-test [id=63117f68eb3d4d73a1ae20488ec0e534]), partition=
I20260812 06:19:39.253739  8763 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet 69f5314346b4472fb02c8eab168ae05a. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:19:39.255918  8849 tablet_bootstrap.cc:492] T 69f5314346b4472fb02c8eab168ae05a P 8c547e315ff1493aa15d7b77106d12f5: Bootstrap starting.
I20260812 06:19:39.256886  8849 tablet_bootstrap.cc:654] T 69f5314346b4472fb02c8eab168ae05a P 8c547e315ff1493aa15d7b77106d12f5: Neither blocks nor log segments found. Creating new log.
I20260812 06:19:39.257891  8849 tablet_bootstrap.cc:492] T 69f5314346b4472fb02c8eab168ae05a P 8c547e315ff1493aa15d7b77106d12f5: No bootstrap required, opened a new log
I20260812 06:19:39.258004  8849 ts_tablet_manager.cc:1403] T 69f5314346b4472fb02c8eab168ae05a P 8c547e315ff1493aa15d7b77106d12f5: Time spent bootstrapping tablet: real 0.002s	user 0.002s	sys 0.000s
I20260812 06:19:39.258466  8849 raft_consensus.cc:359] T 69f5314346b4472fb02c8eab168ae05a P 8c547e315ff1493aa15d7b77106d12f5 [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "8c547e315ff1493aa15d7b77106d12f5" member_type: VOTER last_known_addr { host: "127.8.0.1" port: 46631 } }
I20260812 06:19:39.258559  8849 raft_consensus.cc:385] T 69f5314346b4472fb02c8eab168ae05a P 8c547e315ff1493aa15d7b77106d12f5 [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:19:39.258584  8849 raft_consensus.cc:740] T 69f5314346b4472fb02c8eab168ae05a P 8c547e315ff1493aa15d7b77106d12f5 [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: 8c547e315ff1493aa15d7b77106d12f5, State: Initialized, Role: FOLLOWER
I20260812 06:19:39.258720  8849 consensus_queue.cc:260] T 69f5314346b4472fb02c8eab168ae05a P 8c547e315ff1493aa15d7b77106d12f5 [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: "8c547e315ff1493aa15d7b77106d12f5" member_type: VOTER last_known_addr { host: "127.8.0.1" port: 46631 } }
I20260812 06:19:39.258821  8849 raft_consensus.cc:399] T 69f5314346b4472fb02c8eab168ae05a P 8c547e315ff1493aa15d7b77106d12f5 [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:19:39.258891  8849 raft_consensus.cc:493] T 69f5314346b4472fb02c8eab168ae05a P 8c547e315ff1493aa15d7b77106d12f5 [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:19:39.258944  8849 raft_consensus.cc:3060] T 69f5314346b4472fb02c8eab168ae05a P 8c547e315ff1493aa15d7b77106d12f5 [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:19:39.259716  8849 raft_consensus.cc:515] T 69f5314346b4472fb02c8eab168ae05a P 8c547e315ff1493aa15d7b77106d12f5 [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "8c547e315ff1493aa15d7b77106d12f5" member_type: VOTER last_known_addr { host: "127.8.0.1" port: 46631 } }
I20260812 06:19:39.259866  8849 leader_election.cc:304] T 69f5314346b4472fb02c8eab168ae05a P 8c547e315ff1493aa15d7b77106d12f5 [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: 8c547e315ff1493aa15d7b77106d12f5; no voters: 
I20260812 06:19:39.260097  8849 leader_election.cc:290] T 69f5314346b4472fb02c8eab168ae05a P 8c547e315ff1493aa15d7b77106d12f5 [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:19:39.260234  8853 raft_consensus.cc:2804] T 69f5314346b4472fb02c8eab168ae05a P 8c547e315ff1493aa15d7b77106d12f5 [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:19:39.260450  8849 ts_tablet_manager.cc:1434] T 69f5314346b4472fb02c8eab168ae05a P 8c547e315ff1493aa15d7b77106d12f5: Time spent starting tablet: real 0.002s	user 0.003s	sys 0.000s
I20260812 06:19:39.260468  8816 heartbeater.cc:499] Master 127.8.0.62:41661 was elected leader, sending a full tablet report...
I20260812 06:19:39.260495  8853 raft_consensus.cc:697] T 69f5314346b4472fb02c8eab168ae05a P 8c547e315ff1493aa15d7b77106d12f5 [term 1 LEADER]: Becoming Leader. State: Replica: 8c547e315ff1493aa15d7b77106d12f5, State: Running, Role: LEADER
I20260812 06:19:39.260697  8853 consensus_queue.cc:237] T 69f5314346b4472fb02c8eab168ae05a P 8c547e315ff1493aa15d7b77106d12f5 [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: "8c547e315ff1493aa15d7b77106d12f5" member_type: VOTER last_known_addr { host: "127.8.0.1" port: 46631 } }
I20260812 06:19:39.262013  8575 catalog_manager.cc:5719] T 69f5314346b4472fb02c8eab168ae05a P 8c547e315ff1493aa15d7b77106d12f5 reported cstate change: term changed from 0 to 1, leader changed from <none> to 8c547e315ff1493aa15d7b77106d12f5 (127.8.0.1). New cstate: current_term: 1 leader_uuid: "8c547e315ff1493aa15d7b77106d12f5" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "8c547e315ff1493aa15d7b77106d12f5" member_type: VOTER last_known_addr { host: "127.8.0.1" port: 46631 } health_report { overall_health: HEALTHY } } }
I20260812 06:19:39.322891  8192 heavy-update-compaction-itest.cc:215] Time spent inserting: real 0.054s	user 0.018s	sys 0.004s
I20260812 06:19:39.475355  8821 maintenance_manager.cc:419] P 8c547e315ff1493aa15d7b77106d12f5: Scheduling FlushMRSOp(69f5314346b4472fb02c8eab168ae05a): perf score=19.054940
I20260812 06:19:39.649544  8708 maintenance_manager.cc:643] P 8c547e315ff1493aa15d7b77106d12f5: FlushMRSOp(69f5314346b4472fb02c8eab168ae05a) complete. Timing: real 0.174s	user 0.143s	sys 0.028s Metrics: {"bytes_written":12307491,"cfile_init":1,"delete_count":0,"dirs.queue_time_us":77,"dirs.run_cpu_time_us":203,"dirs.run_wall_time_us":907,"drs_written":1,"lbm_read_time_us":129,"lbm_reads_lt_1ms":4,"lbm_write_time_us":40961,"lbm_writes_lt_1ms":757,"peak_mem_usage":0,"reinsert_count":0,"rows_written":104,"update_count":1500}
I20260812 06:19:39.650185  8821 maintenance_manager.cc:419] P 8c547e315ff1493aa15d7b77106d12f5: Scheduling LogGCOp(69f5314346b4472fb02c8eab168ae05a): free 20743880 bytes of WAL
I20260812 06:19:39.650425  8708 log_reader.cc:385] T 69f5314346b4472fb02c8eab168ae05a: removed 2 log segments from log reader
I20260812 06:19:39.650481  8708 log.cc:1079] T 69f5314346b4472fb02c8eab168ae05a P 8c547e315ff1493aa15d7b77106d12f5: Deleting log segment in path: /tmp/dist-test-taskPRxTjs/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515573527110-8192-0/minicluster-data/ts-0-root/wals/69f5314346b4472fb02c8eab168ae05a/wal-000000001 (ops 1-6)
I20260812 06:19:39.650513  8708 log.cc:1079] T 69f5314346b4472fb02c8eab168ae05a P 8c547e315ff1493aa15d7b77106d12f5: Deleting log segment in path: /tmp/dist-test-taskPRxTjs/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515573527110-8192-0/minicluster-data/ts-0-root/wals/69f5314346b4472fb02c8eab168ae05a/wal-000000002 (ops 7-11)
I20260812 06:19:39.655140  8708 maintenance_manager.cc:643] P 8c547e315ff1493aa15d7b77106d12f5: LogGCOp(69f5314346b4472fb02c8eab168ae05a) complete. Timing: real 0.005s	user 0.001s	sys 0.003s Metrics: {}
I20260812 06:19:39.655539  8821 maintenance_manager.cc:419] P 8c547e315ff1493aa15d7b77106d12f5: Scheduling FlushDeltaMemStoresOp(69f5314346b4472fb02c8eab168ae05a): perf score=2.188937
I20260812 06:19:39.667939  8708 maintenance_manager.cc:643] P 8c547e315ff1493aa15d7b77106d12f5: FlushDeltaMemStoresOp(69f5314346b4472fb02c8eab168ae05a) complete. Timing: real 0.012s	user 0.007s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4731,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:39.668592  8821 maintenance_manager.cc:419] P 8c547e315ff1493aa15d7b77106d12f5: Scheduling MajorDeltaCompactionOp(69f5314346b4472fb02c8eab168ae05a): perf score=1.000000
I20260812 06:19:39.837049  8708 maintenance_manager.cc:643] P 8c547e315ff1493aa15d7b77106d12f5: MajorDeltaCompactionOp(69f5314346b4472fb02c8eab168ae05a) complete. Timing: real 0.168s	user 0.116s	sys 0.052s 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":838,"lbm_read_time_us":14565,"lbm_reads_lt_1ms":472,"lbm_write_time_us":28680,"lbm_writes_lt_1ms":443,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":2816,"thread_start_us":369,"threads_started":5,"update_count":2000}
I20260812 06:19:39.837654  8821 maintenance_manager.cc:419] P 8c547e315ff1493aa15d7b77106d12f5: Scheduling UndoDeltaBlockGCOp(69f5314346b4472fb02c8eab168ae05a): 16411392 bytes on disk
I20260812 06:19:39.838094  8708 maintenance_manager.cc:643] P 8c547e315ff1493aa15d7b77106d12f5: UndoDeltaBlockGCOp(69f5314346b4472fb02c8eab168ae05a) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":66,"lbm_reads_lt_1ms":4}
I20260812 06:19:39.838569  8821 maintenance_manager.cc:419] P 8c547e315ff1493aa15d7b77106d12f5: Scheduling FlushDeltaMemStoresOp(69f5314346b4472fb02c8eab168ae05a): perf score=10.126437
I20260812 06:19:39.887738  8708 maintenance_manager.cc:643] P 8c547e315ff1493aa15d7b77106d12f5: FlushDeltaMemStoresOp(69f5314346b4472fb02c8eab168ae05a) complete. Timing: real 0.049s	user 0.013s	sys 0.035s Metrics: {"bytes_written":12307492,"delete_count":0,"lbm_write_time_us":16409,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:19:39.888195  8821 maintenance_manager.cc:419] P 8c547e315ff1493aa15d7b77106d12f5: Scheduling FlushDeltaMemStoresOp(69f5314346b4472fb02c8eab168ae05a): perf score=2.188937
I20260812 06:19:39.899101  8708 maintenance_manager.cc:643] P 8c547e315ff1493aa15d7b77106d12f5: FlushDeltaMemStoresOp(69f5314346b4472fb02c8eab168ae05a) complete. Timing: real 0.011s	user 0.005s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4333,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:39.899499  8821 maintenance_manager.cc:419] P 8c547e315ff1493aa15d7b77106d12f5: Scheduling MajorDeltaCompactionOp(69f5314346b4472fb02c8eab168ae05a): perf score=1.000000
I20260812 06:19:40.063352  8708 maintenance_manager.cc:643] P 8c547e315ff1493aa15d7b77106d12f5: MajorDeltaCompactionOp(69f5314346b4472fb02c8eab168ae05a) complete. Timing: real 0.164s	user 0.119s	sys 0.032s 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":643,"lbm_read_time_us":11571,"lbm_reads_lt_1ms":472,"lbm_write_time_us":25336,"lbm_writes_lt_1ms":443,"mutex_wait_us":22,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":20480,"update_count":2000}
I20260812 06:19:40.063980  8821 maintenance_manager.cc:419] P 8c547e315ff1493aa15d7b77106d12f5: Scheduling FlushDeltaMemStoresOp(69f5314346b4472fb02c8eab168ae05a): perf score=14.095187
I20260812 06:19:40.122856  8708 maintenance_manager.cc:643] P 8c547e315ff1493aa15d7b77106d12f5: FlushDeltaMemStoresOp(69f5314346b4472fb02c8eab168ae05a) complete. Timing: real 0.059s	user 0.025s	sys 0.021s Metrics: {"bytes_written":16409904,"delete_count":0,"lbm_write_time_us":22880,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:40.123323  8821 maintenance_manager.cc:419] P 8c547e315ff1493aa15d7b77106d12f5: Scheduling FlushDeltaMemStoresOp(69f5314346b4472fb02c8eab168ae05a): perf score=2.188937
I20260812 06:19:40.135191  8708 maintenance_manager.cc:643] P 8c547e315ff1493aa15d7b77106d12f5: FlushDeltaMemStoresOp(69f5314346b4472fb02c8eab168ae05a) complete. Timing: real 0.012s	user 0.007s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4171,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:40.135800  8821 maintenance_manager.cc:419] P 8c547e315ff1493aa15d7b77106d12f5: Scheduling MajorDeltaCompactionOp(69f5314346b4472fb02c8eab168ae05a): perf score=1.000000
I20260812 06:19:40.294129  8708 maintenance_manager.cc:643] P 8c547e315ff1493aa15d7b77106d12f5: MajorDeltaCompactionOp(69f5314346b4472fb02c8eab168ae05a) complete. Timing: real 0.158s	user 0.119s	sys 0.037s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774691,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":151,"lbm_read_time_us":10589,"lbm_reads_lt_1ms":572,"lbm_write_time_us":32756,"lbm_writes_lt_1ms":543,"mutex_wait_us":57,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":6912,"update_count":2500}
I20260812 06:19:40.294664  8821 maintenance_manager.cc:419] P 8c547e315ff1493aa15d7b77106d12f5: Scheduling FlushDeltaMemStoresOp(69f5314346b4472fb02c8eab168ae05a): perf score=11.118625
I20260812 06:19:40.334427  8708 maintenance_manager.cc:643] P 8c547e315ff1493aa15d7b77106d12f5: FlushDeltaMemStoresOp(69f5314346b4472fb02c8eab168ae05a) complete. Timing: real 0.040s	user 0.020s	sys 0.016s Metrics: {"bytes_written":12717736,"delete_count":0,"lbm_write_time_us":17582,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:19:40.335242  8821 maintenance_manager.cc:419] P 8c547e315ff1493aa15d7b77106d12f5: Scheduling FlushDeltaMemStoresOp(69f5314346b4472fb02c8eab168ae05a): perf score=2.188937
I20260812 06:19:40.348356  8708 maintenance_manager.cc:643] P 8c547e315ff1493aa15d7b77106d12f5: FlushDeltaMemStoresOp(69f5314346b4472fb02c8eab168ae05a) complete. Timing: real 0.013s	user 0.007s	sys 0.005s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":5064,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:19:40.348783  8821 maintenance_manager.cc:419] P 8c547e315ff1493aa15d7b77106d12f5: Scheduling MajorDeltaCompactionOp(69f5314346b4472fb02c8eab168ae05a): perf score=1.000000
I20260812 06:19:40.481534  8708 maintenance_manager.cc:643] P 8c547e315ff1493aa15d7b77106d12f5: MajorDeltaCompactionOp(69f5314346b4472fb02c8eab168ae05a) complete. Timing: real 0.133s	user 0.100s	sys 0.032s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672269,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":1222,"lbm_read_time_us":10850,"lbm_reads_lt_1ms":464,"lbm_write_time_us":23158,"lbm_writes_lt_1ms":443,"mutex_wait_us":393,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":2048,"update_count":2000}
I20260812 06:19:40.482257  8821 maintenance_manager.cc:419] P 8c547e315ff1493aa15d7b77106d12f5: Scheduling FlushDeltaMemStoresOp(69f5314346b4472fb02c8eab168ae05a): perf score=10.126437
I20260812 06:19:40.532522  8708 maintenance_manager.cc:643] P 8c547e315ff1493aa15d7b77106d12f5: FlushDeltaMemStoresOp(69f5314346b4472fb02c8eab168ae05a) complete. Timing: real 0.049s	user 0.027s	sys 0.020s Metrics: {"bytes_written":12307493,"delete_count":0,"lbm_write_time_us":20413,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":302,"reinsert_count":0,"update_count":1500}
I20260812 06:19:40.533092  8821 maintenance_manager.cc:419] P 8c547e315ff1493aa15d7b77106d12f5: Scheduling FlushDeltaMemStoresOp(69f5314346b4472fb02c8eab168ae05a): perf score=2.188937
I20260812 06:19:40.550534  8708 maintenance_manager.cc:643] P 8c547e315ff1493aa15d7b77106d12f5: FlushDeltaMemStoresOp(69f5314346b4472fb02c8eab168ae05a) complete. Timing: real 0.017s	user 0.007s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6681,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:40.551121  8821 maintenance_manager.cc:419] P 8c547e315ff1493aa15d7b77106d12f5: Scheduling MajorDeltaCompactionOp(69f5314346b4472fb02c8eab168ae05a): perf score=1.000000
I20260812 06:19:40.668596  8708 maintenance_manager.cc:643] P 8c547e315ff1493aa15d7b77106d12f5: MajorDeltaCompactionOp(69f5314346b4472fb02c8eab168ae05a) complete. Timing: real 0.117s	user 0.076s	sys 0.041s 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":431,"lbm_read_time_us":8328,"lbm_reads_lt_1ms":472,"lbm_write_time_us":23955,"lbm_writes_lt_1ms":443,"mutex_wait_us":42,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":21888,"update_count":2000}
I20260812 06:19:40.671787  8821 maintenance_manager.cc:419] P 8c547e315ff1493aa15d7b77106d12f5: Scheduling FlushDeltaMemStoresOp(69f5314346b4472fb02c8eab168ae05a): perf score=10.126437
I20260812 06:19:40.718667  8708 maintenance_manager.cc:643] P 8c547e315ff1493aa15d7b77106d12f5: FlushDeltaMemStoresOp(69f5314346b4472fb02c8eab168ae05a) complete. Timing: real 0.047s	user 0.020s	sys 0.023s Metrics: {"bytes_written":12307489,"delete_count":0,"lbm_write_time_us":15181,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:19:40.719367  8821 maintenance_manager.cc:419] P 8c547e315ff1493aa15d7b77106d12f5: Scheduling FlushDeltaMemStoresOp(69f5314346b4472fb02c8eab168ae05a): perf score=2.188937
I20260812 06:19:40.735988  8708 maintenance_manager.cc:643] P 8c547e315ff1493aa15d7b77106d12f5: FlushDeltaMemStoresOp(69f5314346b4472fb02c8eab168ae05a) complete. Timing: real 0.016s	user 0.015s	sys 0.001s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6362,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:40.736539  8821 maintenance_manager.cc:419] P 8c547e315ff1493aa15d7b77106d12f5: Scheduling MajorDeltaCompactionOp(69f5314346b4472fb02c8eab168ae05a): perf score=1.000000
I20260812 06:19:40.902487  8708 maintenance_manager.cc:643] P 8c547e315ff1493aa15d7b77106d12f5: MajorDeltaCompactionOp(69f5314346b4472fb02c8eab168ae05a) complete. Timing: real 0.166s	user 0.095s	sys 0.061s 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":609,"lbm_read_time_us":12588,"lbm_reads_lt_1ms":472,"lbm_write_time_us":25489,"lbm_writes_lt_1ms":443,"mutex_wait_us":312,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":896,"update_count":2000}
I20260812 06:19:40.903173  8821 maintenance_manager.cc:419] P 8c547e315ff1493aa15d7b77106d12f5: Scheduling FlushDeltaMemStoresOp(69f5314346b4472fb02c8eab168ae05a): perf score=11.118625
I20260812 06:19:40.939746  8708 maintenance_manager.cc:643] P 8c547e315ff1493aa15d7b77106d12f5: FlushDeltaMemStoresOp(69f5314346b4472fb02c8eab168ae05a) complete. Timing: real 0.036s	user 0.028s	sys 0.008s Metrics: {"bytes_written":13251052,"delete_count":0,"lbm_write_time_us":15617,"lbm_writes_lt_1ms":326,"reinsert_count":0,"update_count":1615}
I20260812 06:19:40.940268  8821 maintenance_manager.cc:419] P 8c547e315ff1493aa15d7b77106d12f5: Scheduling FlushDeltaMemStoresOp(69f5314346b4472fb02c8eab168ae05a): perf score=1.196750
I20260812 06:19:40.961170  8708 maintenance_manager.cc:643] P 8c547e315ff1493aa15d7b77106d12f5: FlushDeltaMemStoresOp(69f5314346b4472fb02c8eab168ae05a) complete. Timing: real 0.021s	user 0.008s	sys 0.004s Metrics: {"bytes_written":3159080,"delete_count":0,"lbm_write_time_us":5323,"lbm_writes_lt_1ms":80,"mutex_wait_us":2,"reinsert_count":0,"update_count":385}
I20260812 06:19:40.961630  8821 maintenance_manager.cc:419] P 8c547e315ff1493aa15d7b77106d12f5: Scheduling FlushDeltaMemStoresOp(69f5314346b4472fb02c8eab168ae05a): perf score=2.188937
I20260812 06:19:40.971904  8708 maintenance_manager.cc:643] P 8c547e315ff1493aa15d7b77106d12f5: FlushDeltaMemStoresOp(69f5314346b4472fb02c8eab168ae05a) complete. Timing: real 0.010s	user 0.008s	sys 0.001s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3998,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:40.972327  8821 maintenance_manager.cc:419] P 8c547e315ff1493aa15d7b77106d12f5: Scheduling FlushMRSOp(69f5314346b4472fb02c8eab168ae05a): perf score=1.000000
I20260812 06:19:41.005785  8708 maintenance_manager.cc:643] P 8c547e315ff1493aa15d7b77106d12f5: FlushMRSOp(69f5314346b4472fb02c8eab168ae05a) complete. Timing: real 0.033s	user 0.030s	sys 0.001s Metrics: {"bytes_written":1234473,"cfile_init":1,"dirs.queue_time_us":80,"dirs.run_cpu_time_us":257,"dirs.run_wall_time_us":1363,"drs_written":1,"lbm_read_time_us":44,"lbm_reads_lt_1ms":4,"lbm_write_time_us":2011,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":30}
I20260812 06:19:41.006408  8821 maintenance_manager.cc:419] P 8c547e315ff1493aa15d7b77106d12f5: Scheduling LogGCOp(69f5314346b4472fb02c8eab168ae05a): free 120553376 bytes of WAL
I20260812 06:19:41.006639  8708 log_reader.cc:385] T 69f5314346b4472fb02c8eab168ae05a: removed 12 log segments from log reader
I20260812 06:19:41.006687  8708 log.cc:1079] T 69f5314346b4472fb02c8eab168ae05a P 8c547e315ff1493aa15d7b77106d12f5: Deleting log segment in path: /tmp/dist-test-taskPRxTjs/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515573527110-8192-0/minicluster-data/ts-0-root/wals/69f5314346b4472fb02c8eab168ae05a/wal-000000003 (ops 12-16)
I20260812 06:19:41.006716  8708 log.cc:1079] T 69f5314346b4472fb02c8eab168ae05a P 8c547e315ff1493aa15d7b77106d12f5: Deleting log segment in path: /tmp/dist-test-taskPRxTjs/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515573527110-8192-0/minicluster-data/ts-0-root/wals/69f5314346b4472fb02c8eab168ae05a/wal-000000004 (ops 17-21)
I20260812 06:19:41.006779  8708 log.cc:1079] T 69f5314346b4472fb02c8eab168ae05a P 8c547e315ff1493aa15d7b77106d12f5: Deleting log segment in path: /tmp/dist-test-taskPRxTjs/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515573527110-8192-0/minicluster-data/ts-0-root/wals/69f5314346b4472fb02c8eab168ae05a/wal-000000005 (ops 22-26)
I20260812 06:19:41.006840  8708 log.cc:1079] T 69f5314346b4472fb02c8eab168ae05a P 8c547e315ff1493aa15d7b77106d12f5: Deleting log segment in path: /tmp/dist-test-taskPRxTjs/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515573527110-8192-0/minicluster-data/ts-0-root/wals/69f5314346b4472fb02c8eab168ae05a/wal-000000006 (ops 27-30)
I20260812 06:19:41.006879  8708 log.cc:1079] T 69f5314346b4472fb02c8eab168ae05a P 8c547e315ff1493aa15d7b77106d12f5: Deleting log segment in path: /tmp/dist-test-taskPRxTjs/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515573527110-8192-0/minicluster-data/ts-0-root/wals/69f5314346b4472fb02c8eab168ae05a/wal-000000007 (ops 31-35)
I20260812 06:19:41.006922  8708 log.cc:1079] T 69f5314346b4472fb02c8eab168ae05a P 8c547e315ff1493aa15d7b77106d12f5: Deleting log segment in path: /tmp/dist-test-taskPRxTjs/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515573527110-8192-0/minicluster-data/ts-0-root/wals/69f5314346b4472fb02c8eab168ae05a/wal-000000008 (ops 36-40)
I20260812 06:19:41.006960  8708 log.cc:1079] T 69f5314346b4472fb02c8eab168ae05a P 8c547e315ff1493aa15d7b77106d12f5: Deleting log segment in path: /tmp/dist-test-taskPRxTjs/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515573527110-8192-0/minicluster-data/ts-0-root/wals/69f5314346b4472fb02c8eab168ae05a/wal-000000009 (ops 41-44)
I20260812 06:19:41.006999  8708 log.cc:1079] T 69f5314346b4472fb02c8eab168ae05a P 8c547e315ff1493aa15d7b77106d12f5: Deleting log segment in path: /tmp/dist-test-taskPRxTjs/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515573527110-8192-0/minicluster-data/ts-0-root/wals/69f5314346b4472fb02c8eab168ae05a/wal-000000010 (ops 45-49)
I20260812 06:19:41.007036  8708 log.cc:1079] T 69f5314346b4472fb02c8eab168ae05a P 8c547e315ff1493aa15d7b77106d12f5: Deleting log segment in path: /tmp/dist-test-taskPRxTjs/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515573527110-8192-0/minicluster-data/ts-0-root/wals/69f5314346b4472fb02c8eab168ae05a/wal-000000011 (ops 50-54)
I20260812 06:19:41.007097  8708 log.cc:1079] T 69f5314346b4472fb02c8eab168ae05a P 8c547e315ff1493aa15d7b77106d12f5: Deleting log segment in path: /tmp/dist-test-taskPRxTjs/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515573527110-8192-0/minicluster-data/ts-0-root/wals/69f5314346b4472fb02c8eab168ae05a/wal-000000012 (ops 55-59)
I20260812 06:19:41.007138  8708 log.cc:1079] T 69f5314346b4472fb02c8eab168ae05a P 8c547e315ff1493aa15d7b77106d12f5: Deleting log segment in path: /tmp/dist-test-taskPRxTjs/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515573527110-8192-0/minicluster-data/ts-0-root/wals/69f5314346b4472fb02c8eab168ae05a/wal-000000013 (ops 60-64)
I20260812 06:19:41.007175  8708 log.cc:1079] T 69f5314346b4472fb02c8eab168ae05a P 8c547e315ff1493aa15d7b77106d12f5: Deleting log segment in path: /tmp/dist-test-taskPRxTjs/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515573527110-8192-0/minicluster-data/ts-0-root/wals/69f5314346b4472fb02c8eab168ae05a/wal-000000014 (ops 65-69)
I20260812 06:19:41.036450  8708 maintenance_manager.cc:643] P 8c547e315ff1493aa15d7b77106d12f5: LogGCOp(69f5314346b4472fb02c8eab168ae05a) complete. Timing: real 0.030s	user 0.001s	sys 0.027s Metrics: {}
I20260812 06:19:41.039363  8821 maintenance_manager.cc:419] P 8c547e315ff1493aa15d7b77106d12f5: Scheduling FlushDeltaMemStoresOp(69f5314346b4472fb02c8eab168ae05a): perf score=2.188937
I20260812 06:19:41.057789  8708 maintenance_manager.cc:643] P 8c547e315ff1493aa15d7b77106d12f5: FlushDeltaMemStoresOp(69f5314346b4472fb02c8eab168ae05a) complete. Timing: real 0.018s	user 0.006s	sys 0.005s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":5324,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:41.058283  8821 maintenance_manager.cc:419] P 8c547e315ff1493aa15d7b77106d12f5: Scheduling FlushDeltaMemStoresOp(69f5314346b4472fb02c8eab168ae05a): perf score=2.188937
I20260812 06:19:41.069391  8708 maintenance_manager.cc:643] P 8c547e315ff1493aa15d7b77106d12f5: FlushDeltaMemStoresOp(69f5314346b4472fb02c8eab168ae05a) complete. Timing: real 0.011s	user 0.009s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4321,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:41.069864  8821 maintenance_manager.cc:419] P 8c547e315ff1493aa15d7b77106d12f5: Scheduling MajorDeltaCompactionOp(69f5314346b4472fb02c8eab168ae05a): perf score=1.000000
I20260812 06:19:41.335454  8708 maintenance_manager.cc:643] P 8c547e315ff1493aa15d7b77106d12f5: MajorDeltaCompactionOp(69f5314346b4472fb02c8eab168ae05a) complete. Timing: real 0.265s	user 0.173s	sys 0.080s Metrics: {"cfile_cache_miss":735,"cfile_cache_miss_bytes":32979852,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":5,"delta_iterators_relevant":5,"dirs.queue_time_us":647,"lbm_read_time_us":17254,"lbm_reads_lt_1ms":775,"lbm_write_time_us":41568,"lbm_writes_lt_1ms":743,"mutex_wait_us":41,"peak_mem_usage":87969044,"reinsert_count":0,"spinlock_wait_cycles":896,"thread_start_us":81,"threads_started":1,"update_count":3500}
I20260812 06:19:41.336229  8821 maintenance_manager.cc:419] P 8c547e315ff1493aa15d7b77106d12f5: Scheduling UndoDeltaBlockGCOp(69f5314346b4472fb02c8eab168ae05a): 472 bytes on disk
I20260812 06:19:41.336735  8708 maintenance_manager.cc:643] P 8c547e315ff1493aa15d7b77106d12f5: UndoDeltaBlockGCOp(69f5314346b4472fb02c8eab168ae05a) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":61,"lbm_reads_lt_1ms":4}
I20260812 06:19:41.337261  8821 maintenance_manager.cc:419] P 8c547e315ff1493aa15d7b77106d12f5: Scheduling FlushDeltaMemStoresOp(69f5314346b4472fb02c8eab168ae05a): perf score=18.063937
I20260812 06:19:41.410040  8708 maintenance_manager.cc:643] P 8c547e315ff1493aa15d7b77106d12f5: FlushDeltaMemStoresOp(69f5314346b4472fb02c8eab168ae05a) complete. Timing: real 0.073s	user 0.051s	sys 0.012s Metrics: {"bytes_written":20512315,"delete_count":0,"lbm_write_time_us":30376,"lbm_writes_lt_1ms":503,"reinsert_count":0,"update_count":2500}
I20260812 06:19:41.410645  8821 maintenance_manager.cc:419] P 8c547e315ff1493aa15d7b77106d12f5: Scheduling FlushDeltaMemStoresOp(69f5314346b4472fb02c8eab168ae05a): perf score=2.188937
I20260812 06:19:41.424239  8708 maintenance_manager.cc:643] P 8c547e315ff1493aa15d7b77106d12f5: FlushDeltaMemStoresOp(69f5314346b4472fb02c8eab168ae05a) complete. Timing: real 0.013s	user 0.008s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5335,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:41.424808  8821 maintenance_manager.cc:419] P 8c547e315ff1493aa15d7b77106d12f5: Scheduling MajorDeltaCompactionOp(69f5314346b4472fb02c8eab168ae05a): perf score=1.000000
I20260812 06:19:41.637843  8708 maintenance_manager.cc:643] P 8c547e315ff1493aa15d7b77106d12f5: MajorDeltaCompactionOp(69f5314346b4472fb02c8eab168ae05a) complete. Timing: real 0.213s	user 0.144s	sys 0.068s Metrics: {"cfile_cache_miss":632,"cfile_cache_miss_bytes":28877102,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":557,"lbm_read_time_us":17199,"lbm_reads_1-10_ms":1,"lbm_reads_lt_1ms":671,"lbm_write_time_us":33492,"lbm_writes_lt_1ms":643,"mutex_wait_us":290,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":13696,"update_count":3000}
I20260812 06:19:41.654886  8821 maintenance_manager.cc:419] P 8c547e315ff1493aa15d7b77106d12f5: Scheduling FlushDeltaMemStoresOp(69f5314346b4472fb02c8eab168ae05a): perf score=10.126437
I20260812 06:19:41.705816  8708 maintenance_manager.cc:643] P 8c547e315ff1493aa15d7b77106d12f5: FlushDeltaMemStoresOp(69f5314346b4472fb02c8eab168ae05a) complete. Timing: real 0.051s	user 0.022s	sys 0.026s Metrics: {"bytes_written":12307492,"delete_count":0,"lbm_write_time_us":21874,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:19:41.706503  8821 maintenance_manager.cc:419] P 8c547e315ff1493aa15d7b77106d12f5: Scheduling FlushDeltaMemStoresOp(69f5314346b4472fb02c8eab168ae05a): perf score=2.188937
I20260812 06:19:41.728312  8708 maintenance_manager.cc:643] P 8c547e315ff1493aa15d7b77106d12f5: FlushDeltaMemStoresOp(69f5314346b4472fb02c8eab168ae05a) complete. Timing: real 0.022s	user 0.004s	sys 0.014s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":7356,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:41.728940  8821 maintenance_manager.cc:419] P 8c547e315ff1493aa15d7b77106d12f5: Scheduling MajorDeltaCompactionOp(69f5314346b4472fb02c8eab168ae05a): perf score=1.000000
I20260812 06:19:41.879331  8708 maintenance_manager.cc:643] P 8c547e315ff1493aa15d7b77106d12f5: MajorDeltaCompactionOp(69f5314346b4472fb02c8eab168ae05a) complete. Timing: real 0.150s	user 0.090s	sys 0.057s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672279,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":188,"lbm_read_time_us":10645,"lbm_reads_lt_1ms":464,"lbm_write_time_us":24136,"lbm_writes_lt_1ms":443,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":7168,"update_count":2000}
I20260812 06:19:41.880105  8821 maintenance_manager.cc:419] P 8c547e315ff1493aa15d7b77106d12f5: Scheduling FlushDeltaMemStoresOp(69f5314346b4472fb02c8eab168ae05a): perf score=7.149875
I20260812 06:19:41.920257  8708 maintenance_manager.cc:643] P 8c547e315ff1493aa15d7b77106d12f5: FlushDeltaMemStoresOp(69f5314346b4472fb02c8eab168ae05a) complete. Timing: real 0.040s	user 0.023s	sys 0.016s Metrics: {"bytes_written":8615322,"delete_count":0,"lbm_write_time_us":16051,"lbm_writes_lt_1ms":213,"reinsert_count":0,"update_count":1050}
I20260812 06:19:41.921170  8821 maintenance_manager.cc:419] P 8c547e315ff1493aa15d7b77106d12f5: Scheduling FlushDeltaMemStoresOp(69f5314346b4472fb02c8eab168ae05a): perf score=2.188937
I20260812 06:19:41.943456  8708 maintenance_manager.cc:643] P 8c547e315ff1493aa15d7b77106d12f5: FlushDeltaMemStoresOp(69f5314346b4472fb02c8eab168ae05a) complete. Timing: real 0.022s	user 0.015s	sys 0.004s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":7301,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:19:41.944110  8821 maintenance_manager.cc:419] P 8c547e315ff1493aa15d7b77106d12f5: Scheduling FlushDeltaMemStoresOp(69f5314346b4472fb02c8eab168ae05a): perf score=2.188937
I20260812 06:19:41.963864  8708 maintenance_manager.cc:643] P 8c547e315ff1493aa15d7b77106d12f5: FlushDeltaMemStoresOp(69f5314346b4472fb02c8eab168ae05a) complete. Timing: real 0.020s	user 0.011s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":7935,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:41.964330  8821 maintenance_manager.cc:419] P 8c547e315ff1493aa15d7b77106d12f5: Scheduling MajorDeltaCompactionOp(69f5314346b4472fb02c8eab168ae05a): perf score=1.000000
I20260812 06:19:42.104364  8708 maintenance_manager.cc:643] P 8c547e315ff1493aa15d7b77106d12f5: MajorDeltaCompactionOp(69f5314346b4472fb02c8eab168ae05a) complete. Timing: real 0.140s	user 0.115s	sys 0.023s Metrics: {"cfile_cache_miss":433,"cfile_cache_miss_bytes":20672386,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":1040,"lbm_read_time_us":10821,"lbm_reads_lt_1ms":473,"lbm_write_time_us":25748,"lbm_writes_lt_1ms":443,"mutex_wait_us":376,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":66304,"update_count":2000}
I20260812 06:19:42.105186  8821 maintenance_manager.cc:419] P 8c547e315ff1493aa15d7b77106d12f5: Scheduling FlushDeltaMemStoresOp(69f5314346b4472fb02c8eab168ae05a): perf score=10.126437
I20260812 06:19:42.144259  8708 maintenance_manager.cc:643] P 8c547e315ff1493aa15d7b77106d12f5: FlushDeltaMemStoresOp(69f5314346b4472fb02c8eab168ae05a) complete. Timing: real 0.039s	user 0.022s	sys 0.016s Metrics: {"bytes_written":12307491,"delete_count":0,"lbm_write_time_us":19774,"lbm_writes_1-10_ms":3,"lbm_writes_lt_1ms":300,"reinsert_count":0,"update_count":1500}
I20260812 06:19:42.144754  8821 maintenance_manager.cc:419] P 8c547e315ff1493aa15d7b77106d12f5: Scheduling FlushDeltaMemStoresOp(69f5314346b4472fb02c8eab168ae05a): perf score=2.188937
I20260812 06:19:42.156424  8708 maintenance_manager.cc:643] P 8c547e315ff1493aa15d7b77106d12f5: FlushDeltaMemStoresOp(69f5314346b4472fb02c8eab168ae05a) complete. Timing: real 0.011s	user 0.001s	sys 0.009s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4444,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:42.156936  8821 maintenance_manager.cc:419] P 8c547e315ff1493aa15d7b77106d12f5: Scheduling MajorDeltaCompactionOp(69f5314346b4472fb02c8eab168ae05a): perf score=1.000000
I20260812 06:19:42.301600  8708 maintenance_manager.cc:643] P 8c547e315ff1493aa15d7b77106d12f5: MajorDeltaCompactionOp(69f5314346b4472fb02c8eab168ae05a) complete. Timing: real 0.144s	user 0.097s	sys 0.046s 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":1539,"lbm_read_time_us":10544,"lbm_reads_lt_1ms":472,"lbm_write_time_us":27987,"lbm_writes_lt_1ms":443,"mutex_wait_us":360,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":8192,"update_count":2000}
I20260812 06:19:42.302219  8821 maintenance_manager.cc:419] P 8c547e315ff1493aa15d7b77106d12f5: Scheduling FlushDeltaMemStoresOp(69f5314346b4472fb02c8eab168ae05a): perf score=10.126437
I20260812 06:19:42.348059  8708 maintenance_manager.cc:643] P 8c547e315ff1493aa15d7b77106d12f5: FlushDeltaMemStoresOp(69f5314346b4472fb02c8eab168ae05a) complete. Timing: real 0.046s	user 0.021s	sys 0.015s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":16629,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:19:42.348572  8821 maintenance_manager.cc:419] P 8c547e315ff1493aa15d7b77106d12f5: Scheduling FlushDeltaMemStoresOp(69f5314346b4472fb02c8eab168ae05a): perf score=2.188937
I20260812 06:19:42.361557  8708 maintenance_manager.cc:643] P 8c547e315ff1493aa15d7b77106d12f5: FlushDeltaMemStoresOp(69f5314346b4472fb02c8eab168ae05a) complete. Timing: real 0.013s	user 0.010s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4627,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:42.362214  8821 maintenance_manager.cc:419] P 8c547e315ff1493aa15d7b77106d12f5: Scheduling MajorDeltaCompactionOp(69f5314346b4472fb02c8eab168ae05a): perf score=1.000000
I20260812 06:19:42.502451  8708 maintenance_manager.cc:643] P 8c547e315ff1493aa15d7b77106d12f5: MajorDeltaCompactionOp(69f5314346b4472fb02c8eab168ae05a) complete. Timing: real 0.140s	user 0.116s	sys 0.023s 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":1136,"lbm_read_time_us":10754,"lbm_reads_lt_1ms":472,"lbm_write_time_us":27889,"lbm_writes_lt_1ms":443,"mutex_wait_us":359,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":22784,"update_count":2000}
I20260812 06:19:42.503052  8821 maintenance_manager.cc:419] P 8c547e315ff1493aa15d7b77106d12f5: Scheduling FlushDeltaMemStoresOp(69f5314346b4472fb02c8eab168ae05a): perf score=10.126437
I20260812 06:19:42.557302  8708 maintenance_manager.cc:643] P 8c547e315ff1493aa15d7b77106d12f5: FlushDeltaMemStoresOp(69f5314346b4472fb02c8eab168ae05a) complete. Timing: real 0.054s	user 0.017s	sys 0.032s Metrics: {"bytes_written":12307491,"delete_count":0,"lbm_write_time_us":17992,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:19:42.557907  8821 maintenance_manager.cc:419] P 8c547e315ff1493aa15d7b77106d12f5: Scheduling FlushDeltaMemStoresOp(69f5314346b4472fb02c8eab168ae05a): perf score=2.188937
I20260812 06:19:42.569053  8708 maintenance_manager.cc:643] P 8c547e315ff1493aa15d7b77106d12f5: FlushDeltaMemStoresOp(69f5314346b4472fb02c8eab168ae05a) complete. Timing: real 0.011s	user 0.009s	sys 0.000s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4301,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:42.569526  8821 maintenance_manager.cc:419] P 8c547e315ff1493aa15d7b77106d12f5: Scheduling FlushMRSOp(69f5314346b4472fb02c8eab168ae05a): perf score=1.000000
I20260812 06:19:42.602723  8708 maintenance_manager.cc:643] P 8c547e315ff1493aa15d7b77106d12f5: FlushMRSOp(69f5314346b4472fb02c8eab168ae05a) complete. Timing: real 0.033s	user 0.028s	sys 0.000s Metrics: {"bytes_written":1152514,"cfile_init":1,"dirs.queue_time_us":71,"dirs.run_cpu_time_us":280,"dirs.run_wall_time_us":1416,"drs_written":1,"lbm_read_time_us":39,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1558,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":28}
I20260812 06:19:42.603583  8821 maintenance_manager.cc:419] P 8c547e315ff1493aa15d7b77106d12f5: Scheduling MajorDeltaCompactionOp(69f5314346b4472fb02c8eab168ae05a): perf score=1.000000
I20260812 06:19:42.784744  8708 maintenance_manager.cc:643] P 8c547e315ff1493aa15d7b77106d12f5: MajorDeltaCompactionOp(69f5314346b4472fb02c8eab168ae05a) complete. Timing: real 0.181s	user 0.118s	sys 0.055s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672277,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":167,"lbm_read_time_us":11666,"lbm_reads_lt_1ms":464,"lbm_write_time_us":29755,"lbm_writes_lt_1ms":443,"mutex_wait_us":39,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":5120,"update_count":2000}
I20260812 06:19:42.785521  8821 maintenance_manager.cc:419] P 8c547e315ff1493aa15d7b77106d12f5: Scheduling LogGCOp(69f5314346b4472fb02c8eab168ae05a): free 115943190 bytes of WAL
I20260812 06:19:42.785820  8708 log_reader.cc:385] T 69f5314346b4472fb02c8eab168ae05a: removed 11 log segments from log reader
I20260812 06:19:42.785873  8708 log.cc:1079] T 69f5314346b4472fb02c8eab168ae05a P 8c547e315ff1493aa15d7b77106d12f5: Deleting log segment in path: /tmp/dist-test-taskPRxTjs/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515573527110-8192-0/minicluster-data/ts-0-root/wals/69f5314346b4472fb02c8eab168ae05a/wal-000000015 (ops 70-74)
I20260812 06:19:42.785944  8708 log.cc:1079] T 69f5314346b4472fb02c8eab168ae05a P 8c547e315ff1493aa15d7b77106d12f5: Deleting log segment in path: /tmp/dist-test-taskPRxTjs/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515573527110-8192-0/minicluster-data/ts-0-root/wals/69f5314346b4472fb02c8eab168ae05a/wal-000000016 (ops 75-79)
I20260812 06:19:42.785984  8708 log.cc:1079] T 69f5314346b4472fb02c8eab168ae05a P 8c547e315ff1493aa15d7b77106d12f5: Deleting log segment in path: /tmp/dist-test-taskPRxTjs/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515573527110-8192-0/minicluster-data/ts-0-root/wals/69f5314346b4472fb02c8eab168ae05a/wal-000000017 (ops 80-84)
I20260812 06:19:42.786055  8708 log.cc:1079] T 69f5314346b4472fb02c8eab168ae05a P 8c547e315ff1493aa15d7b77106d12f5: Deleting log segment in path: /tmp/dist-test-taskPRxTjs/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515573527110-8192-0/minicluster-data/ts-0-root/wals/69f5314346b4472fb02c8eab168ae05a/wal-000000018 (ops 85-89)
I20260812 06:19:42.786094  8708 log.cc:1079] T 69f5314346b4472fb02c8eab168ae05a P 8c547e315ff1493aa15d7b77106d12f5: Deleting log segment in path: /tmp/dist-test-taskPRxTjs/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515573527110-8192-0/minicluster-data/ts-0-root/wals/69f5314346b4472fb02c8eab168ae05a/wal-000000019 (ops 90-94)
I20260812 06:19:42.786161  8708 log.cc:1079] T 69f5314346b4472fb02c8eab168ae05a P 8c547e315ff1493aa15d7b77106d12f5: Deleting log segment in path: /tmp/dist-test-taskPRxTjs/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515573527110-8192-0/minicluster-data/ts-0-root/wals/69f5314346b4472fb02c8eab168ae05a/wal-000000020 (ops 95-99)
I20260812 06:19:42.786201  8708 log.cc:1079] T 69f5314346b4472fb02c8eab168ae05a P 8c547e315ff1493aa15d7b77106d12f5: Deleting log segment in path: /tmp/dist-test-taskPRxTjs/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515573527110-8192-0/minicluster-data/ts-0-root/wals/69f5314346b4472fb02c8eab168ae05a/wal-000000021 (ops 100-104)
I20260812 06:19:42.786267  8708 log.cc:1079] T 69f5314346b4472fb02c8eab168ae05a P 8c547e315ff1493aa15d7b77106d12f5: Deleting log segment in path: /tmp/dist-test-taskPRxTjs/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515573527110-8192-0/minicluster-data/ts-0-root/wals/69f5314346b4472fb02c8eab168ae05a/wal-000000022 (ops 105-109)
I20260812 06:19:42.786305  8708 log.cc:1079] T 69f5314346b4472fb02c8eab168ae05a P 8c547e315ff1493aa15d7b77106d12f5: Deleting log segment in path: /tmp/dist-test-taskPRxTjs/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515573527110-8192-0/minicluster-data/ts-0-root/wals/69f5314346b4472fb02c8eab168ae05a/wal-000000023 (ops 110-114)
I20260812 06:19:42.786366  8708 log.cc:1079] T 69f5314346b4472fb02c8eab168ae05a P 8c547e315ff1493aa15d7b77106d12f5: Deleting log segment in path: /tmp/dist-test-taskPRxTjs/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515573527110-8192-0/minicluster-data/ts-0-root/wals/69f5314346b4472fb02c8eab168ae05a/wal-000000024 (ops 115-119)
I20260812 06:19:42.786405  8708 log.cc:1079] T 69f5314346b4472fb02c8eab168ae05a P 8c547e315ff1493aa15d7b77106d12f5: Deleting log segment in path: /tmp/dist-test-taskPRxTjs/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515573527110-8192-0/minicluster-data/ts-0-root/wals/69f5314346b4472fb02c8eab168ae05a/wal-000000025 (ops 120-124)
I20260812 06:19:42.814726  8708 maintenance_manager.cc:643] P 8c547e315ff1493aa15d7b77106d12f5: LogGCOp(69f5314346b4472fb02c8eab168ae05a) complete. Timing: real 0.029s	user 0.000s	sys 0.025s Metrics: {}
I20260812 06:19:42.815670  8821 maintenance_manager.cc:419] P 8c547e315ff1493aa15d7b77106d12f5: Scheduling UndoDeltaBlockGCOp(69f5314346b4472fb02c8eab168ae05a): 447 bytes on disk
I20260812 06:19:42.816290  8708 maintenance_manager.cc:643] P 8c547e315ff1493aa15d7b77106d12f5: UndoDeltaBlockGCOp(69f5314346b4472fb02c8eab168ae05a) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":91,"lbm_reads_lt_1ms":4}
I20260812 06:19:42.817086  8821 maintenance_manager.cc:419] P 8c547e315ff1493aa15d7b77106d12f5: Scheduling FlushDeltaMemStoresOp(69f5314346b4472fb02c8eab168ae05a): perf score=15.087375
I20260812 06:19:42.864089  8708 maintenance_manager.cc:643] P 8c547e315ff1493aa15d7b77106d12f5: FlushDeltaMemStoresOp(69f5314346b4472fb02c8eab168ae05a) complete. Timing: real 0.047s	user 0.030s	sys 0.015s Metrics: {"bytes_written":16820144,"delete_count":0,"lbm_write_time_us":21337,"lbm_writes_lt_1ms":413,"reinsert_count":0,"update_count":2050}
I20260812 06:19:42.864652  8821 maintenance_manager.cc:419] P 8c547e315ff1493aa15d7b77106d12f5: Scheduling FlushDeltaMemStoresOp(69f5314346b4472fb02c8eab168ae05a): perf score=2.188937
I20260812 06:19:42.877089  8708 maintenance_manager.cc:643] P 8c547e315ff1493aa15d7b77106d12f5: FlushDeltaMemStoresOp(69f5314346b4472fb02c8eab168ae05a) complete. Timing: real 0.012s	user 0.009s	sys 0.000s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":4105,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:19:42.877583  8821 maintenance_manager.cc:419] P 8c547e315ff1493aa15d7b77106d12f5: Scheduling MajorDeltaCompactionOp(69f5314346b4472fb02c8eab168ae05a): perf score=1.000000
I20260812 06:19:43.083384  8708 maintenance_manager.cc:643] P 8c547e315ff1493aa15d7b77106d12f5: MajorDeltaCompactionOp(69f5314346b4472fb02c8eab168ae05a) complete. Timing: real 0.206s	user 0.109s	sys 0.089s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774677,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":596,"lbm_read_time_us":14815,"lbm_reads_lt_1ms":564,"lbm_write_time_us":31101,"lbm_writes_lt_1ms":543,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":5120,"update_count":2500}
I20260812 06:19:43.084161  8821 maintenance_manager.cc:419] P 8c547e315ff1493aa15d7b77106d12f5: Scheduling FlushDeltaMemStoresOp(69f5314346b4472fb02c8eab168ae05a): perf score=14.095187
I20260812 06:19:43.125375  8708 maintenance_manager.cc:643] P 8c547e315ff1493aa15d7b77106d12f5: FlushDeltaMemStoresOp(69f5314346b4472fb02c8eab168ae05a) complete. Timing: real 0.040s	user 0.017s	sys 0.020s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":18077,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:43.125869  8821 maintenance_manager.cc:419] P 8c547e315ff1493aa15d7b77106d12f5: Scheduling FlushDeltaMemStoresOp(69f5314346b4472fb02c8eab168ae05a): perf score=2.188937
I20260812 06:19:43.137477  8708 maintenance_manager.cc:643] P 8c547e315ff1493aa15d7b77106d12f5: FlushDeltaMemStoresOp(69f5314346b4472fb02c8eab168ae05a) complete. Timing: real 0.011s	user 0.009s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4272,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:43.137938  8821 maintenance_manager.cc:419] P 8c547e315ff1493aa15d7b77106d12f5: Scheduling MajorDeltaCompactionOp(69f5314346b4472fb02c8eab168ae05a): perf score=1.000000
I20260812 06:19:43.310065  8708 maintenance_manager.cc:643] P 8c547e315ff1493aa15d7b77106d12f5: MajorDeltaCompactionOp(69f5314346b4472fb02c8eab168ae05a) complete. Timing: real 0.172s	user 0.124s	sys 0.048s 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":149,"lbm_read_time_us":11880,"lbm_reads_lt_1ms":572,"lbm_write_time_us":37010,"lbm_writes_lt_1ms":543,"mutex_wait_us":17,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":13696,"update_count":2500}
I20260812 06:19:43.310742  8821 maintenance_manager.cc:419] P 8c547e315ff1493aa15d7b77106d12f5: Scheduling FlushDeltaMemStoresOp(69f5314346b4472fb02c8eab168ae05a): perf score=10.126437
I20260812 06:19:43.350314  8708 maintenance_manager.cc:643] P 8c547e315ff1493aa15d7b77106d12f5: FlushDeltaMemStoresOp(69f5314346b4472fb02c8eab168ae05a) complete. Timing: real 0.039s	user 0.028s	sys 0.008s Metrics: {"bytes_written":12307488,"delete_count":0,"lbm_write_time_us":17351,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:19:43.350915  8821 maintenance_manager.cc:419] P 8c547e315ff1493aa15d7b77106d12f5: Scheduling FlushDeltaMemStoresOp(69f5314346b4472fb02c8eab168ae05a): perf score=2.188937
I20260812 06:19:43.366993  8708 maintenance_manager.cc:643] P 8c547e315ff1493aa15d7b77106d12f5: FlushDeltaMemStoresOp(69f5314346b4472fb02c8eab168ae05a) complete. Timing: real 0.016s	user 0.004s	sys 0.009s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5890,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:43.367599  8821 maintenance_manager.cc:419] P 8c547e315ff1493aa15d7b77106d12f5: Scheduling MajorDeltaCompactionOp(69f5314346b4472fb02c8eab168ae05a): perf score=1.000000
I20260812 06:19:43.505163  8708 maintenance_manager.cc:643] P 8c547e315ff1493aa15d7b77106d12f5: MajorDeltaCompactionOp(69f5314346b4472fb02c8eab168ae05a) complete. Timing: real 0.136s	user 0.104s	sys 0.031s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672275,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":935,"lbm_read_time_us":8528,"lbm_reads_lt_1ms":472,"lbm_write_time_us":26747,"lbm_writes_lt_1ms":443,"mutex_wait_us":78,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":4480,"update_count":2000}
I20260812 06:19:43.505959  8821 maintenance_manager.cc:419] P 8c547e315ff1493aa15d7b77106d12f5: Scheduling FlushDeltaMemStoresOp(69f5314346b4472fb02c8eab168ae05a): perf score=10.126437
I20260812 06:19:43.553524  8708 maintenance_manager.cc:643] P 8c547e315ff1493aa15d7b77106d12f5: FlushDeltaMemStoresOp(69f5314346b4472fb02c8eab168ae05a) complete. Timing: real 0.047s	user 0.027s	sys 0.008s Metrics: {"bytes_written":12307489,"delete_count":0,"lbm_write_time_us":16962,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:19:43.553990  8821 maintenance_manager.cc:419] P 8c547e315ff1493aa15d7b77106d12f5: Scheduling FlushDeltaMemStoresOp(69f5314346b4472fb02c8eab168ae05a): perf score=2.188937
I20260812 06:19:43.564417  8708 maintenance_manager.cc:643] P 8c547e315ff1493aa15d7b77106d12f5: FlushDeltaMemStoresOp(69f5314346b4472fb02c8eab168ae05a) complete. Timing: real 0.010s	user 0.009s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4015,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:43.565152  8821 maintenance_manager.cc:419] P 8c547e315ff1493aa15d7b77106d12f5: Scheduling MajorDeltaCompactionOp(69f5314346b4472fb02c8eab168ae05a): perf score=1.000000
I20260812 06:19:43.691254  8708 maintenance_manager.cc:643] P 8c547e315ff1493aa15d7b77106d12f5: MajorDeltaCompactionOp(69f5314346b4472fb02c8eab168ae05a) complete. Timing: real 0.126s	user 0.099s	sys 0.027s 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":369,"lbm_read_time_us":9185,"lbm_reads_lt_1ms":472,"lbm_write_time_us":24358,"lbm_writes_lt_1ms":443,"mutex_wait_us":24,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":9344,"update_count":2000}
I20260812 06:19:43.691854  8821 maintenance_manager.cc:419] P 8c547e315ff1493aa15d7b77106d12f5: Scheduling FlushDeltaMemStoresOp(69f5314346b4472fb02c8eab168ae05a): perf score=10.126437
I20260812 06:19:43.733479  8708 maintenance_manager.cc:643] P 8c547e315ff1493aa15d7b77106d12f5: FlushDeltaMemStoresOp(69f5314346b4472fb02c8eab168ae05a) complete. Timing: real 0.041s	user 0.014s	sys 0.023s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":14217,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:19:43.734372  8821 maintenance_manager.cc:419] P 8c547e315ff1493aa15d7b77106d12f5: Scheduling MajorDeltaCompactionOp(69f5314346b4472fb02c8eab168ae05a): perf score=1.000000
I20260812 06:19:43.864132  8708 maintenance_manager.cc:643] P 8c547e315ff1493aa15d7b77106d12f5: MajorDeltaCompactionOp(69f5314346b4472fb02c8eab168ae05a) complete. Timing: real 0.130s	user 0.105s	sys 0.023s Metrics: {"cfile_cache_miss":331,"cfile_cache_miss_bytes":16569746,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":1,"delta_iterators_relevant":1,"dirs.queue_time_us":795,"lbm_read_time_us":9172,"lbm_reads_lt_1ms":363,"lbm_write_time_us":19021,"lbm_writes_lt_1ms":343,"mutex_wait_us":395,"peak_mem_usage":38262756,"reinsert_count":0,"spinlock_wait_cycles":8448,"update_count":1500}
I20260812 06:19:43.864843  8821 maintenance_manager.cc:419] P 8c547e315ff1493aa15d7b77106d12f5: Scheduling FlushDeltaMemStoresOp(69f5314346b4472fb02c8eab168ae05a): perf score=10.126437
I20260812 06:19:43.905299  8708 maintenance_manager.cc:643] P 8c547e315ff1493aa15d7b77106d12f5: FlushDeltaMemStoresOp(69f5314346b4472fb02c8eab168ae05a) complete. Timing: real 0.040s	user 0.022s	sys 0.016s Metrics: {"bytes_written":12307491,"delete_count":0,"lbm_write_time_us":17395,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:19:43.905838  8821 maintenance_manager.cc:419] P 8c547e315ff1493aa15d7b77106d12f5: Scheduling FlushDeltaMemStoresOp(69f5314346b4472fb02c8eab168ae05a): perf score=2.188937
I20260812 06:19:43.916424  8708 maintenance_manager.cc:643] P 8c547e315ff1493aa15d7b77106d12f5: FlushDeltaMemStoresOp(69f5314346b4472fb02c8eab168ae05a) complete. Timing: real 0.010s	user 0.005s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3983,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:43.917016  8821 maintenance_manager.cc:419] P 8c547e315ff1493aa15d7b77106d12f5: Scheduling MajorDeltaCompactionOp(69f5314346b4472fb02c8eab168ae05a): perf score=1.000000
I20260812 06:19:44.051158  8708 maintenance_manager.cc:643] P 8c547e315ff1493aa15d7b77106d12f5: MajorDeltaCompactionOp(69f5314346b4472fb02c8eab168ae05a) complete. Timing: real 0.134s	user 0.103s	sys 0.031s 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":264,"lbm_read_time_us":9263,"lbm_reads_lt_1ms":472,"lbm_write_time_us":24448,"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:19:44.051717  8821 maintenance_manager.cc:419] P 8c547e315ff1493aa15d7b77106d12f5: Scheduling FlushDeltaMemStoresOp(69f5314346b4472fb02c8eab168ae05a): perf score=10.126437
I20260812 06:19:44.097762  8708 maintenance_manager.cc:643] P 8c547e315ff1493aa15d7b77106d12f5: FlushDeltaMemStoresOp(69f5314346b4472fb02c8eab168ae05a) complete. Timing: real 0.046s	user 0.018s	sys 0.016s Metrics: {"bytes_written":12307491,"delete_count":0,"lbm_write_time_us":16253,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:19:44.098289  8821 maintenance_manager.cc:419] P 8c547e315ff1493aa15d7b77106d12f5: Scheduling FlushDeltaMemStoresOp(69f5314346b4472fb02c8eab168ae05a): perf score=2.188937
I20260812 06:19:44.109062  8708 maintenance_manager.cc:643] P 8c547e315ff1493aa15d7b77106d12f5: FlushDeltaMemStoresOp(69f5314346b4472fb02c8eab168ae05a) complete. Timing: real 0.011s	user 0.009s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3972,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:44.109840  8821 maintenance_manager.cc:419] P 8c547e315ff1493aa15d7b77106d12f5: Scheduling FlushMRSOp(69f5314346b4472fb02c8eab168ae05a): perf score=1.000000
I20260812 06:19:44.145526  8708 maintenance_manager.cc:643] P 8c547e315ff1493aa15d7b77106d12f5: FlushMRSOp(69f5314346b4472fb02c8eab168ae05a) complete. Timing: real 0.035s	user 0.029s	sys 0.004s Metrics: {"bytes_written":1193505,"cfile_init":1,"dirs.queue_time_us":73,"dirs.run_cpu_time_us":174,"dirs.run_wall_time_us":1311,"drs_written":1,"lbm_read_time_us":59,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1924,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":29}
I20260812 06:19:44.146322  8821 maintenance_manager.cc:419] P 8c547e315ff1493aa15d7b77106d12f5: Scheduling LogGCOp(69f5314346b4472fb02c8eab168ae05a): free 121006622 bytes of WAL
I20260812 06:19:44.146639  8708 log_reader.cc:385] T 69f5314346b4472fb02c8eab168ae05a: removed 12 log segments from log reader
I20260812 06:19:44.146721  8708 log.cc:1079] T 69f5314346b4472fb02c8eab168ae05a P 8c547e315ff1493aa15d7b77106d12f5: Deleting log segment in path: /tmp/dist-test-taskPRxTjs/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515573527110-8192-0/minicluster-data/ts-0-root/wals/69f5314346b4472fb02c8eab168ae05a/wal-000000026 (ops 125-129)
I20260812 06:19:44.146782  8708 log.cc:1079] T 69f5314346b4472fb02c8eab168ae05a P 8c547e315ff1493aa15d7b77106d12f5: Deleting log segment in path: /tmp/dist-test-taskPRxTjs/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515573527110-8192-0/minicluster-data/ts-0-root/wals/69f5314346b4472fb02c8eab168ae05a/wal-000000027 (ops 130-134)
I20260812 06:19:44.146847  8708 log.cc:1079] T 69f5314346b4472fb02c8eab168ae05a P 8c547e315ff1493aa15d7b77106d12f5: Deleting log segment in path: /tmp/dist-test-taskPRxTjs/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515573527110-8192-0/minicluster-data/ts-0-root/wals/69f5314346b4472fb02c8eab168ae05a/wal-000000028 (ops 135-139)
I20260812 06:19:44.146891  8708 log.cc:1079] T 69f5314346b4472fb02c8eab168ae05a P 8c547e315ff1493aa15d7b77106d12f5: Deleting log segment in path: /tmp/dist-test-taskPRxTjs/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515573527110-8192-0/minicluster-data/ts-0-root/wals/69f5314346b4472fb02c8eab168ae05a/wal-000000029 (ops 140-144)
I20260812 06:19:44.146970  8708 log.cc:1079] T 69f5314346b4472fb02c8eab168ae05a P 8c547e315ff1493aa15d7b77106d12f5: Deleting log segment in path: /tmp/dist-test-taskPRxTjs/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515573527110-8192-0/minicluster-data/ts-0-root/wals/69f5314346b4472fb02c8eab168ae05a/wal-000000030 (ops 145-149)
I20260812 06:19:44.147017  8708 log.cc:1079] T 69f5314346b4472fb02c8eab168ae05a P 8c547e315ff1493aa15d7b77106d12f5: Deleting log segment in path: /tmp/dist-test-taskPRxTjs/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515573527110-8192-0/minicluster-data/ts-0-root/wals/69f5314346b4472fb02c8eab168ae05a/wal-000000031 (ops 150-154)
I20260812 06:19:44.147058  8708 log.cc:1079] T 69f5314346b4472fb02c8eab168ae05a P 8c547e315ff1493aa15d7b77106d12f5: Deleting log segment in path: /tmp/dist-test-taskPRxTjs/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515573527110-8192-0/minicluster-data/ts-0-root/wals/69f5314346b4472fb02c8eab168ae05a/wal-000000032 (ops 155-159)
I20260812 06:19:44.147135  8708 log.cc:1079] T 69f5314346b4472fb02c8eab168ae05a P 8c547e315ff1493aa15d7b77106d12f5: Deleting log segment in path: /tmp/dist-test-taskPRxTjs/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515573527110-8192-0/minicluster-data/ts-0-root/wals/69f5314346b4472fb02c8eab168ae05a/wal-000000033 (ops 160-164)
I20260812 06:19:44.147176  8708 log.cc:1079] T 69f5314346b4472fb02c8eab168ae05a P 8c547e315ff1493aa15d7b77106d12f5: Deleting log segment in path: /tmp/dist-test-taskPRxTjs/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515573527110-8192-0/minicluster-data/ts-0-root/wals/69f5314346b4472fb02c8eab168ae05a/wal-000000034 (ops 165-169)
I20260812 06:19:44.147219  8708 log.cc:1079] T 69f5314346b4472fb02c8eab168ae05a P 8c547e315ff1493aa15d7b77106d12f5: Deleting log segment in path: /tmp/dist-test-taskPRxTjs/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515573527110-8192-0/minicluster-data/ts-0-root/wals/69f5314346b4472fb02c8eab168ae05a/wal-000000035 (ops 170-174)
I20260812 06:19:44.147259  8708 log.cc:1079] T 69f5314346b4472fb02c8eab168ae05a P 8c547e315ff1493aa15d7b77106d12f5: Deleting log segment in path: /tmp/dist-test-taskPRxTjs/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515573527110-8192-0/minicluster-data/ts-0-root/wals/69f5314346b4472fb02c8eab168ae05a/wal-000000036 (ops 175-178)
I20260812 06:19:44.147300  8708 log.cc:1079] T 69f5314346b4472fb02c8eab168ae05a P 8c547e315ff1493aa15d7b77106d12f5: Deleting log segment in path: /tmp/dist-test-taskPRxTjs/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515573527110-8192-0/minicluster-data/ts-0-root/wals/69f5314346b4472fb02c8eab168ae05a/wal-000000037 (ops 179-183)
I20260812 06:19:44.180476  8708 maintenance_manager.cc:643] P 8c547e315ff1493aa15d7b77106d12f5: LogGCOp(69f5314346b4472fb02c8eab168ae05a) complete. Timing: real 0.034s	user 0.002s	sys 0.031s Metrics: {}
I20260812 06:19:44.180975  8821 maintenance_manager.cc:419] P 8c547e315ff1493aa15d7b77106d12f5: Scheduling FlushDeltaMemStoresOp(69f5314346b4472fb02c8eab168ae05a): perf score=3.181125
I20260812 06:19:44.201682  8708 maintenance_manager.cc:643] P 8c547e315ff1493aa15d7b77106d12f5: FlushDeltaMemStoresOp(69f5314346b4472fb02c8eab168ae05a) complete. Timing: real 0.020s	user 0.009s	sys 0.008s Metrics: {"bytes_written":5169286,"delete_count":0,"lbm_write_time_us":8538,"lbm_writes_lt_1ms":129,"reinsert_count":0,"update_count":630}
I20260812 06:19:44.202349  8821 maintenance_manager.cc:419] P 8c547e315ff1493aa15d7b77106d12f5: Scheduling UndoDeltaBlockGCOp(69f5314346b4472fb02c8eab168ae05a): 463 bytes on disk
I20260812 06:19:44.202888  8708 maintenance_manager.cc:643] P 8c547e315ff1493aa15d7b77106d12f5: UndoDeltaBlockGCOp(69f5314346b4472fb02c8eab168ae05a) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":69,"lbm_reads_lt_1ms":4}
I20260812 06:19:44.203455  8821 maintenance_manager.cc:419] P 8c547e315ff1493aa15d7b77106d12f5: Scheduling FlushDeltaMemStoresOp(69f5314346b4472fb02c8eab168ae05a): perf score=1.196750
I20260812 06:19:44.218003  8708 maintenance_manager.cc:643] P 8c547e315ff1493aa15d7b77106d12f5: FlushDeltaMemStoresOp(69f5314346b4472fb02c8eab168ae05a) complete. Timing: real 0.014s	user 0.006s	sys 0.007s Metrics: {"bytes_written":3036005,"delete_count":0,"lbm_write_time_us":5709,"lbm_writes_lt_1ms":77,"reinsert_count":0,"update_count":370}
I20260812 06:19:44.222193  8821 maintenance_manager.cc:419] P 8c547e315ff1493aa15d7b77106d12f5: Scheduling MajorDeltaCompactionOp(69f5314346b4472fb02c8eab168ae05a): perf score=1.000000
I20260812 06:19:44.409786  8708 maintenance_manager.cc:643] P 8c547e315ff1493aa15d7b77106d12f5: MajorDeltaCompactionOp(69f5314346b4472fb02c8eab168ae05a) complete. Timing: real 0.187s	user 0.133s	sys 0.051s Metrics: {"cfile_cache_miss":634,"cfile_cache_miss_bytes":28877313,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":68,"lbm_read_time_us":14087,"lbm_reads_lt_1ms":666,"lbm_write_time_us":36057,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":642,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":5760,"thread_start_us":98,"threads_started":1,"update_count":3000}
I20260812 06:19:44.410483  8821 maintenance_manager.cc:419] P 8c547e315ff1493aa15d7b77106d12f5: Scheduling FlushDeltaMemStoresOp(69f5314346b4472fb02c8eab168ae05a): perf score=14.095187
I20260812 06:19:44.453716  8708 maintenance_manager.cc:643] P 8c547e315ff1493aa15d7b77106d12f5: FlushDeltaMemStoresOp(69f5314346b4472fb02c8eab168ae05a) complete. Timing: real 0.043s	user 0.025s	sys 0.015s Metrics: {"bytes_written":16409900,"delete_count":0,"lbm_write_time_us":19687,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:44.454398  8821 maintenance_manager.cc:419] P 8c547e315ff1493aa15d7b77106d12f5: Scheduling FlushDeltaMemStoresOp(69f5314346b4472fb02c8eab168ae05a): perf score=2.188937
I20260812 06:19:44.468071  8708 maintenance_manager.cc:643] P 8c547e315ff1493aa15d7b77106d12f5: FlushDeltaMemStoresOp(69f5314346b4472fb02c8eab168ae05a) complete. Timing: real 0.013s	user 0.012s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4646,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:44.468566  8821 maintenance_manager.cc:419] P 8c547e315ff1493aa15d7b77106d12f5: Scheduling MajorDeltaCompactionOp(69f5314346b4472fb02c8eab168ae05a): perf score=1.000000
I20260812 06:19:44.538923  8192 heavy-update-compaction-itest.cc:229] Time spent updating: real 5.216s	user 1.923s	sys 0.177s
I20260812 06:19:44.592160  8192 heavy-update-compaction-itest.cc:265] Time spent scanning: real 0.053s	user 0.003s	sys 0.000s
I20260812 06:19:44.592744  8192 tablet_server.cc:179] TabletServer@127.8.0.1:0 shutting down...
I20260812 06:19:44.613793  8708 maintenance_manager.cc:643] P 8c547e315ff1493aa15d7b77106d12f5: MajorDeltaCompactionOp(69f5314346b4472fb02c8eab168ae05a) complete. Timing: real 0.145s	user 0.101s	sys 0.043s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774687,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":325,"lbm_read_time_us":10405,"lbm_reads_lt_1ms":568,"lbm_write_time_us":27676,"lbm_writes_lt_1ms":543,"mutex_wait_us":67,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":4352,"update_count":2500}
I20260812 06:19:44.614557  8192 ts_tablet_manager.cc:1507] Shutting down tablet manager...
I20260812 06:19:44.614856  8192 tablet_replica.cc:333] T 69f5314346b4472fb02c8eab168ae05a P 8c547e315ff1493aa15d7b77106d12f5: stopping tablet replica
I20260812 06:19:44.615011  8192 raft_consensus.cc:2243] T 69f5314346b4472fb02c8eab168ae05a P 8c547e315ff1493aa15d7b77106d12f5 [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:19:44.615239  8192 raft_consensus.cc:2272] T 69f5314346b4472fb02c8eab168ae05a P 8c547e315ff1493aa15d7b77106d12f5 [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:19:44.622634  8192 tablet_server.cc:196] TabletServer@127.8.0.1:0 shutdown complete.
I20260812 06:19:44.660091  8192 master.cc:562] Master@127.8.0.62:41661 shutting down...
I20260812 06:19:44.664011  8192 raft_consensus.cc:2243] T 00000000000000000000000000000000 P da2f32c1fd0a4def8d2e8d0f6522e944 [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:19:44.664217  8192 raft_consensus.cc:2272] T 00000000000000000000000000000000 P da2f32c1fd0a4def8d2e8d0f6522e944 [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:19:44.664315  8192 tablet_replica.cc:333] T 00000000000000000000000000000000 P da2f32c1fd0a4def8d2e8d0f6522e944: stopping tablet replica
I20260812 06:19:44.676805  8192 master.cc:584] Master@127.8.0.62:41661 shutdown complete.
[       OK ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/1 (5686 ms)
[----------] 2 tests from EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy (11236 ms total)

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