[==========] Running 2 tests from 1 test suite.
[----------] Global test environment set-up.
[----------] 2 tests from EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy
[ RUN      ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/0
WARNING: Logging before InitGoogleLogging() is written to STDERR
I20260812 06:20:09.116070 29068 internal_mini_cluster.cc:156] Creating distributed mini masters. Addrs: 127.28.99.62:34973
I20260812 06:20:09.116953 29068 env_posix.cc:2285] Not raising this process' open files per process limit of 1048576; it is already as high as it can go
I20260812 06:20:09.117463 29068 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:20:09.123019 29081 instance_detector.cc:116] could not retrieve OpenStack instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:20:09.123040 29078 instance_detector.cc:116] could not retrieve Azure instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:20:09.123167 29068 server_base.cc:1061] running on GCE node
W20260812 06:20:09.123214 29075 instance_detector.cc:116] could not retrieve AWS instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:20:09.123674 29068 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:20:09.123766 29068 system_unsync_time.cc:38] NTP support is disabled. Clock error bounds will not be accurate. This configuration is not suitable for distributed clusters.
I20260812 06:20:09.123796 29068 hybrid_clock.cc:648] HybridClock initialized: now 1786515609123795 us; error 0 us; skew 500 ppm
I20260812 06:20:09.125293 29068 webserver.cc:533] Webserver started at http://127.28.99.62:40771/ using document root <none> and password file <none>
I20260812 06:20:09.125746 29068 fs_manager.cc:362] Metadata directory not provided
I20260812 06:20:09.125798 29068 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:20:09.125968 29068 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:20:09.127456 29068 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-tasksggqpW/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515609106051-29068-0/minicluster-data/master-0-root/instance:
uuid: "337499c1138c491080a6cb45765f87d6"
format_stamp: "Formatted at 2026-08-12 06:20:09 on dist-test-slave-fgb3"
I20260812 06:20:09.130529 29068 fs_manager.cc:696] Time spent creating directory manager: real 0.003s	user 0.004s	sys 0.000s
I20260812 06:20:09.132351 29088 log_block_manager.cc:4127] Time spent loading block containers with low live blocks: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:20:09.133241 29068 fs_manager.cc:730] Time spent opening block manager: real 0.002s	user 0.002s	sys 0.000s
I20260812 06:20:09.133334 29068 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-tasksggqpW/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515609106051-29068-0/minicluster-data/master-0-root
uuid: "337499c1138c491080a6cb45765f87d6"
format_stamp: "Formatted at 2026-08-12 06:20:09 on dist-test-slave-fgb3"
I20260812 06:20:09.133424 29068 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-tasksggqpW/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515609106051-29068-0/minicluster-data/master-0-root
metadata directory: /tmp/dist-test-tasksggqpW/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515609106051-29068-0/minicluster-data/master-0-root
1 data directories: /tmp/dist-test-tasksggqpW/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515609106051-29068-0/minicluster-data/master-0-root/data
Total live blocks: 0
Total live bytes: 0
Total live bytes (after alignment): 0
Total number of LBM containers: 0 (0 full)
Did not check for missing blocks
Did not check for orphaned blocks
Total full LBM containers with extra space: 0 (0 repaired)
Total full LBM container extra space in bytes: 0 (0 repaired)
Total incomplete LBM containers: 0 (0 repaired)
Total LBM partial records: 0 (0 repaired)
Total corrupted LBM metadata records in RocksDB: 0 (0 repaired)
I20260812 06:20:09.149688 29068 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:20:09.150240 29068 env_posix.cc:2285] Not raising this process' running threads per effective uid limit of 18446744073709551615; it is already as high as it can go
I20260812 06:20:09.150418 29068 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:20:09.157025 29068 rpc_server.cc:307] RPC server started. Bound to: 127.28.99.62:34973
I20260812 06:20:09.157063 29179 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.28.99.62:34973 every 8 connection(s)
I20260812 06:20:09.159107 29181 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet 00000000000000000000000000000000. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:20:09.164188 29181 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P 337499c1138c491080a6cb45765f87d6: Bootstrap starting.
I20260812 06:20:09.166344 29181 tablet_bootstrap.cc:654] T 00000000000000000000000000000000 P 337499c1138c491080a6cb45765f87d6: Neither blocks nor log segments found. Creating new log.
I20260812 06:20:09.167150 29181 log.cc:826] T 00000000000000000000000000000000 P 337499c1138c491080a6cb45765f87d6: Log is configured to *not* fsync() on all Append() calls
I20260812 06:20:09.168624 29181 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P 337499c1138c491080a6cb45765f87d6: No bootstrap required, opened a new log
I20260812 06:20:09.171263 29181 raft_consensus.cc:359] T 00000000000000000000000000000000 P 337499c1138c491080a6cb45765f87d6 [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "337499c1138c491080a6cb45765f87d6" member_type: VOTER }
I20260812 06:20:09.171427 29181 raft_consensus.cc:385] T 00000000000000000000000000000000 P 337499c1138c491080a6cb45765f87d6 [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:20:09.171496 29181 raft_consensus.cc:740] T 00000000000000000000000000000000 P 337499c1138c491080a6cb45765f87d6 [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: 337499c1138c491080a6cb45765f87d6, State: Initialized, Role: FOLLOWER
I20260812 06:20:09.172071 29181 consensus_queue.cc:260] T 00000000000000000000000000000000 P 337499c1138c491080a6cb45765f87d6 [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: "337499c1138c491080a6cb45765f87d6" member_type: VOTER }
I20260812 06:20:09.172219 29181 raft_consensus.cc:399] T 00000000000000000000000000000000 P 337499c1138c491080a6cb45765f87d6 [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:20:09.172282 29181 raft_consensus.cc:493] T 00000000000000000000000000000000 P 337499c1138c491080a6cb45765f87d6 [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:20:09.172396 29181 raft_consensus.cc:3060] T 00000000000000000000000000000000 P 337499c1138c491080a6cb45765f87d6 [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:20:09.173100 29181 raft_consensus.cc:515] T 00000000000000000000000000000000 P 337499c1138c491080a6cb45765f87d6 [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "337499c1138c491080a6cb45765f87d6" member_type: VOTER }
I20260812 06:20:09.173509 29181 leader_election.cc:304] T 00000000000000000000000000000000 P 337499c1138c491080a6cb45765f87d6 [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: 337499c1138c491080a6cb45765f87d6; no voters: 
I20260812 06:20:09.173780 29181 leader_election.cc:290] T 00000000000000000000000000000000 P 337499c1138c491080a6cb45765f87d6 [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:20:09.173872 29186 raft_consensus.cc:2804] T 00000000000000000000000000000000 P 337499c1138c491080a6cb45765f87d6 [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:20:09.174094 29186 raft_consensus.cc:697] T 00000000000000000000000000000000 P 337499c1138c491080a6cb45765f87d6 [term 1 LEADER]: Becoming Leader. State: Replica: 337499c1138c491080a6cb45765f87d6, State: Running, Role: LEADER
I20260812 06:20:09.174517 29186 consensus_queue.cc:237] T 00000000000000000000000000000000 P 337499c1138c491080a6cb45765f87d6 [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: "337499c1138c491080a6cb45765f87d6" member_type: VOTER }
I20260812 06:20:09.174764 29181 sys_catalog.cc:565] T 00000000000000000000000000000000 P 337499c1138c491080a6cb45765f87d6 [sys.catalog]: configured and running, proceeding with master startup.
I20260812 06:20:09.176177 29188 sys_catalog.cc:455] T 00000000000000000000000000000000 P 337499c1138c491080a6cb45765f87d6 [sys.catalog]: SysCatalogTable state changed. Reason: New leader 337499c1138c491080a6cb45765f87d6. Latest consensus state: current_term: 1 leader_uuid: "337499c1138c491080a6cb45765f87d6" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "337499c1138c491080a6cb45765f87d6" member_type: VOTER } }
I20260812 06:20:09.176165 29190 sys_catalog.cc:455] T 00000000000000000000000000000000 P 337499c1138c491080a6cb45765f87d6 [sys.catalog]: SysCatalogTable state changed. Reason: RaftConsensus started. Latest consensus state: current_term: 1 leader_uuid: "337499c1138c491080a6cb45765f87d6" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "337499c1138c491080a6cb45765f87d6" member_type: VOTER } }
I20260812 06:20:09.176301 29188 sys_catalog.cc:458] T 00000000000000000000000000000000 P 337499c1138c491080a6cb45765f87d6 [sys.catalog]: This master's current role is: LEADER
I20260812 06:20:09.176301 29190 sys_catalog.cc:458] T 00000000000000000000000000000000 P 337499c1138c491080a6cb45765f87d6 [sys.catalog]: This master's current role is: LEADER
I20260812 06:20:09.176697 29206 catalog_manager.cc:1511] Loading table and tablet metadata into memory...
I20260812 06:20:09.176847 29068 internal_mini_cluster.cc:184] Waiting to initialize catalog manager on master 0
I20260812 06:20:09.178896 29206 catalog_manager.cc:1520] Initializing Kudu cluster ID...
I20260812 06:20:09.183368 29206 catalog_manager.cc:1383] Generated new cluster ID: f33534fe5224426eaa48924e38fa8630
I20260812 06:20:09.183421 29206 catalog_manager.cc:1531] Initializing Kudu internal certificate authority...
I20260812 06:20:09.193822 29206 catalog_manager.cc:1406] Generated new certificate authority record
I20260812 06:20:09.194617 29206 catalog_manager.cc:1540] Loading token signing keys...
I20260812 06:20:09.203078 29206 catalog_manager.cc:6092] T 00000000000000000000000000000000 P 337499c1138c491080a6cb45765f87d6: Generated new TSK 0
I20260812 06:20:09.203621 29206 catalog_manager.cc:1550] Initializing in-progress tserver states...
I20260812 06:20:09.209576 29068 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:20:09.212029 29219 instance_detector.cc:116] could not retrieve AWS instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:20:09.212169 29230 instance_detector.cc:116] could not retrieve OpenStack instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:20:09.212198 29226 instance_detector.cc:116] could not retrieve Azure instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:20:09.212387 29068 server_base.cc:1061] running on GCE node
I20260812 06:20:09.212565 29068 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:20:09.212620 29068 system_unsync_time.cc:38] NTP support is disabled. Clock error bounds will not be accurate. This configuration is not suitable for distributed clusters.
I20260812 06:20:09.212649 29068 hybrid_clock.cc:648] HybridClock initialized: now 1786515609212649 us; error 0 us; skew 500 ppm
I20260812 06:20:09.213526 29068 webserver.cc:533] Webserver started at http://127.28.99.1:44707/ using document root <none> and password file <none>
I20260812 06:20:09.213689 29068 fs_manager.cc:362] Metadata directory not provided
I20260812 06:20:09.213745 29068 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:20:09.213815 29068 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:20:09.214233 29068 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-tasksggqpW/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515609106051-29068-0/minicluster-data/ts-0-root/instance:
uuid: "9bea50cf131c4f10af0c0a4ae639b2e2"
format_stamp: "Formatted at 2026-08-12 06:20:09 on dist-test-slave-fgb3"
I20260812 06:20:09.216028 29068 fs_manager.cc:696] Time spent creating directory manager: real 0.002s	user 0.001s	sys 0.000s
I20260812 06:20:09.217092 29237 log_block_manager.cc:4127] Time spent loading block containers with low live blocks: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:20:09.217343 29068 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.001s	sys 0.000s
I20260812 06:20:09.217428 29068 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-tasksggqpW/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515609106051-29068-0/minicluster-data/ts-0-root
uuid: "9bea50cf131c4f10af0c0a4ae639b2e2"
format_stamp: "Formatted at 2026-08-12 06:20:09 on dist-test-slave-fgb3"
I20260812 06:20:09.217499 29068 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-tasksggqpW/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515609106051-29068-0/minicluster-data/ts-0-root
metadata directory: /tmp/dist-test-tasksggqpW/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515609106051-29068-0/minicluster-data/ts-0-root
1 data directories: /tmp/dist-test-tasksggqpW/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515609106051-29068-0/minicluster-data/ts-0-root/data
Total live blocks: 0
Total live bytes: 0
Total live bytes (after alignment): 0
Total number of LBM containers: 0 (0 full)
Did not check for missing blocks
Did not check for orphaned blocks
Total full LBM containers with extra space: 0 (0 repaired)
Total full LBM container extra space in bytes: 0 (0 repaired)
Total incomplete LBM containers: 0 (0 repaired)
Total LBM partial records: 0 (0 repaired)
Total corrupted LBM metadata records in RocksDB: 0 (0 repaired)
I20260812 06:20:09.227330 29068 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:20:09.227751 29068 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:20:09.228212 29068 txn_system_client.cc:432] TxnSystemClient initialization is disabled...
I20260812 06:20:09.229167 29068 ts_tablet_manager.cc:585] Loaded tablet metadata (0 total tablets, 0 live tablets)
I20260812 06:20:09.229233 29068 ts_tablet_manager.cc:531] Time spent load tablet metadata: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:20:09.229291 29068 ts_tablet_manager.cc:616] Registered 0 tablets
I20260812 06:20:09.229322 29068 ts_tablet_manager.cc:595] Time spent register tablets: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:20:09.236116 29068 rpc_server.cc:307] RPC server started. Bound to: 127.28.99.1:40029
I20260812 06:20:09.236151 29350 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.28.99.1:40029 every 8 connection(s)
I20260812 06:20:09.248129 29351 heartbeater.cc:344] Connected to a master server at 127.28.99.62:34973
I20260812 06:20:09.248353 29351 heartbeater.cc:461] Registering TS with master...
I20260812 06:20:09.248752 29351 heartbeater.cc:507] Master 127.28.99.62:34973 requested a full tablet report, sending...
I20260812 06:20:09.250128 29115 ts_manager.cc:194] Registered new tserver with Master: 9bea50cf131c4f10af0c0a4ae639b2e2 (127.28.99.1:40029)
I20260812 06:20:09.250227 29068 internal_mini_cluster.cc:371] 1 TS(s) registered with all masters after 0.013485789s
I20260812 06:20:09.251653 29115 master_service.cc:502] Signed X509 certificate for tserver {username='slave'} at 127.0.0.1:38222
I20260812 06:20:09.259155 29115 catalog_manager.cc:2283] Servicing CreateTable request from {username='slave'} at 127.0.0.1:38230:
name: "heavy-update-compaction-test"
schema {
  columns {
    name: "key"
    type: INT64
    is_key: true
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_a"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_b"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_c"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_d"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_e"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
}
num_replicas: 1
split_rows_range_bounds {
}
partition_schema {
  range_schema {
  }
}
I20260812 06:20:09.273064 29285 tablet_service.cc:1511] Processing CreateTablet for tablet 4737420254b24010b8f48017abbe2903 (DEFAULT_TABLE table=heavy-update-compaction-test [id=b8852500030545b1bb3f2500ea3bfd99]), partition=
I20260812 06:20:09.273527 29285 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet 4737420254b24010b8f48017abbe2903. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:20:09.275691 29371 tablet_bootstrap.cc:492] T 4737420254b24010b8f48017abbe2903 P 9bea50cf131c4f10af0c0a4ae639b2e2: Bootstrap starting.
I20260812 06:20:09.276782 29371 tablet_bootstrap.cc:654] T 4737420254b24010b8f48017abbe2903 P 9bea50cf131c4f10af0c0a4ae639b2e2: Neither blocks nor log segments found. Creating new log.
I20260812 06:20:09.277818 29371 tablet_bootstrap.cc:492] T 4737420254b24010b8f48017abbe2903 P 9bea50cf131c4f10af0c0a4ae639b2e2: No bootstrap required, opened a new log
I20260812 06:20:09.277909 29371 ts_tablet_manager.cc:1403] T 4737420254b24010b8f48017abbe2903 P 9bea50cf131c4f10af0c0a4ae639b2e2: Time spent bootstrapping tablet: real 0.002s	user 0.002s	sys 0.000s
I20260812 06:20:09.278338 29371 raft_consensus.cc:359] T 4737420254b24010b8f48017abbe2903 P 9bea50cf131c4f10af0c0a4ae639b2e2 [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "9bea50cf131c4f10af0c0a4ae639b2e2" member_type: VOTER last_known_addr { host: "127.28.99.1" port: 40029 } }
I20260812 06:20:09.278457 29371 raft_consensus.cc:385] T 4737420254b24010b8f48017abbe2903 P 9bea50cf131c4f10af0c0a4ae639b2e2 [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:20:09.278513 29371 raft_consensus.cc:740] T 4737420254b24010b8f48017abbe2903 P 9bea50cf131c4f10af0c0a4ae639b2e2 [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: 9bea50cf131c4f10af0c0a4ae639b2e2, State: Initialized, Role: FOLLOWER
I20260812 06:20:09.278640 29371 consensus_queue.cc:260] T 4737420254b24010b8f48017abbe2903 P 9bea50cf131c4f10af0c0a4ae639b2e2 [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: "9bea50cf131c4f10af0c0a4ae639b2e2" member_type: VOTER last_known_addr { host: "127.28.99.1" port: 40029 } }
I20260812 06:20:09.278733 29371 raft_consensus.cc:399] T 4737420254b24010b8f48017abbe2903 P 9bea50cf131c4f10af0c0a4ae639b2e2 [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:20:09.278775 29371 raft_consensus.cc:493] T 4737420254b24010b8f48017abbe2903 P 9bea50cf131c4f10af0c0a4ae639b2e2 [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:20:09.278824 29371 raft_consensus.cc:3060] T 4737420254b24010b8f48017abbe2903 P 9bea50cf131c4f10af0c0a4ae639b2e2 [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:20:09.279520 29371 raft_consensus.cc:515] T 4737420254b24010b8f48017abbe2903 P 9bea50cf131c4f10af0c0a4ae639b2e2 [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "9bea50cf131c4f10af0c0a4ae639b2e2" member_type: VOTER last_known_addr { host: "127.28.99.1" port: 40029 } }
I20260812 06:20:09.279645 29371 leader_election.cc:304] T 4737420254b24010b8f48017abbe2903 P 9bea50cf131c4f10af0c0a4ae639b2e2 [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: 9bea50cf131c4f10af0c0a4ae639b2e2; no voters: 
I20260812 06:20:09.279825 29371 leader_election.cc:290] T 4737420254b24010b8f48017abbe2903 P 9bea50cf131c4f10af0c0a4ae639b2e2 [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:20:09.279961 29375 raft_consensus.cc:2804] T 4737420254b24010b8f48017abbe2903 P 9bea50cf131c4f10af0c0a4ae639b2e2 [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:20:09.280174 29371 ts_tablet_manager.cc:1434] T 4737420254b24010b8f48017abbe2903 P 9bea50cf131c4f10af0c0a4ae639b2e2: Time spent starting tablet: real 0.002s	user 0.002s	sys 0.000s
I20260812 06:20:09.280337 29375 raft_consensus.cc:697] T 4737420254b24010b8f48017abbe2903 P 9bea50cf131c4f10af0c0a4ae639b2e2 [term 1 LEADER]: Becoming Leader. State: Replica: 9bea50cf131c4f10af0c0a4ae639b2e2, State: Running, Role: LEADER
I20260812 06:20:09.280624 29351 heartbeater.cc:499] Master 127.28.99.62:34973 was elected leader, sending a full tablet report...
I20260812 06:20:09.280651 29375 consensus_queue.cc:237] T 4737420254b24010b8f48017abbe2903 P 9bea50cf131c4f10af0c0a4ae639b2e2 [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: "9bea50cf131c4f10af0c0a4ae639b2e2" member_type: VOTER last_known_addr { host: "127.28.99.1" port: 40029 } }
I20260812 06:20:09.283159 29115 catalog_manager.cc:5719] T 4737420254b24010b8f48017abbe2903 P 9bea50cf131c4f10af0c0a4ae639b2e2 reported cstate change: term changed from 0 to 1, leader changed from <none> to 9bea50cf131c4f10af0c0a4ae639b2e2 (127.28.99.1). New cstate: current_term: 1 leader_uuid: "9bea50cf131c4f10af0c0a4ae639b2e2" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "9bea50cf131c4f10af0c0a4ae639b2e2" member_type: VOTER last_known_addr { host: "127.28.99.1" port: 40029 } health_report { overall_health: HEALTHY } } }
I20260812 06:20:09.347380 29068 heavy-update-compaction-itest.cc:215] Time spent inserting: real 0.055s	user 0.022s	sys 0.003s
I20260812 06:20:09.487157 29353 maintenance_manager.cc:419] P 9bea50cf131c4f10af0c0a4ae639b2e2: Scheduling FlushMRSOp(4737420254b24010b8f48017abbe2903): perf score=19.054940
I20260812 06:20:09.654606 29243 maintenance_manager.cc:643] P 9bea50cf131c4f10af0c0a4ae639b2e2: FlushMRSOp(4737420254b24010b8f48017abbe2903) complete. Timing: real 0.167s	user 0.142s	sys 0.024s Metrics: {"bytes_written":12307490,"cfile_init":1,"compiler_manager_pool.queue_time_us":197,"delete_count":0,"dirs.queue_time_us":79,"dirs.run_cpu_time_us":197,"dirs.run_wall_time_us":3026,"drs_written":1,"lbm_read_time_us":71,"lbm_reads_lt_1ms":4,"lbm_write_time_us":42897,"lbm_writes_lt_1ms":767,"peak_mem_usage":0,"reinsert_count":0,"rows_written":105,"spinlock_wait_cycles":298880,"thread_start_us":85,"threads_started":1,"update_count":1500}
I20260812 06:20:09.655745 29353 maintenance_manager.cc:419] P 9bea50cf131c4f10af0c0a4ae639b2e2: Scheduling LogGCOp(4737420254b24010b8f48017abbe2903): free 20743880 bytes of WAL
I20260812 06:20:09.656082 29243 log_reader.cc:385] T 4737420254b24010b8f48017abbe2903: removed 2 log segments from log reader
I20260812 06:20:09.656178 29243 log.cc:1079] T 4737420254b24010b8f48017abbe2903 P 9bea50cf131c4f10af0c0a4ae639b2e2: Deleting log segment in path: /tmp/dist-test-tasksggqpW/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515609106051-29068-0/minicluster-data/ts-0-root/wals/4737420254b24010b8f48017abbe2903/wal-000000001 (ops 1-6)
I20260812 06:20:09.656266 29243 log.cc:1079] T 4737420254b24010b8f48017abbe2903 P 9bea50cf131c4f10af0c0a4ae639b2e2: Deleting log segment in path: /tmp/dist-test-tasksggqpW/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515609106051-29068-0/minicluster-data/ts-0-root/wals/4737420254b24010b8f48017abbe2903/wal-000000002 (ops 7-11)
I20260812 06:20:09.661007 29243 maintenance_manager.cc:643] P 9bea50cf131c4f10af0c0a4ae639b2e2: LogGCOp(4737420254b24010b8f48017abbe2903) complete. Timing: real 0.005s	user 0.000s	sys 0.002s Metrics: {}
I20260812 06:20:09.661403 29353 maintenance_manager.cc:419] P 9bea50cf131c4f10af0c0a4ae639b2e2: Scheduling FlushDeltaMemStoresOp(4737420254b24010b8f48017abbe2903): perf score=2.188937
I20260812 06:20:09.681612 29243 maintenance_manager.cc:643] P 9bea50cf131c4f10af0c0a4ae639b2e2: FlushDeltaMemStoresOp(4737420254b24010b8f48017abbe2903) complete. Timing: real 0.020s	user 0.005s	sys 0.007s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3662,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:09.682047 29353 maintenance_manager.cc:419] P 9bea50cf131c4f10af0c0a4ae639b2e2: Scheduling UndoDeltaBlockGCOp(4737420254b24010b8f48017abbe2903): 16821646 bytes on disk
I20260812 06:20:09.682598 29243 maintenance_manager.cc:643] P 9bea50cf131c4f10af0c0a4ae639b2e2: UndoDeltaBlockGCOp(4737420254b24010b8f48017abbe2903) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":49,"lbm_reads_lt_1ms":4}
I20260812 06:20:09.683056 29353 maintenance_manager.cc:419] P 9bea50cf131c4f10af0c0a4ae639b2e2: Scheduling FlushDeltaMemStoresOp(4737420254b24010b8f48017abbe2903): perf score=2.188937
I20260812 06:20:09.692350 29243 maintenance_manager.cc:643] P 9bea50cf131c4f10af0c0a4ae639b2e2: FlushDeltaMemStoresOp(4737420254b24010b8f48017abbe2903) complete. Timing: real 0.009s	user 0.008s	sys 0.000s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3477,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:20:09.692830 29353 maintenance_manager.cc:419] P 9bea50cf131c4f10af0c0a4ae639b2e2: Scheduling MajorDeltaCompactionOp(4737420254b24010b8f48017abbe2903): perf score=1.000000
I20260812 06:20:09.854490 29243 maintenance_manager.cc:643] P 9bea50cf131c4f10af0c0a4ae639b2e2: MajorDeltaCompactionOp(4737420254b24010b8f48017abbe2903) complete. Timing: real 0.161s	user 0.101s	sys 0.060s Metrics: {"cfile_cache_miss":523,"cfile_cache_miss_bytes":24405549,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":543,"lbm_read_time_us":10877,"lbm_reads_lt_1ms":559,"lbm_write_time_us":27223,"lbm_writes_lt_1ms":533,"peak_mem_usage":61665166,"reinsert_count":0,"thread_start_us":284,"threads_started":5,"update_count":2450}
I20260812 06:20:09.854938 29353 maintenance_manager.cc:419] P 9bea50cf131c4f10af0c0a4ae639b2e2: Scheduling FlushDeltaMemStoresOp(4737420254b24010b8f48017abbe2903): perf score=10.126437
I20260812 06:20:09.893386 29243 maintenance_manager.cc:643] P 9bea50cf131c4f10af0c0a4ae639b2e2: FlushDeltaMemStoresOp(4737420254b24010b8f48017abbe2903) complete. Timing: real 0.038s	user 0.026s	sys 0.007s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":14751,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:20:09.893852 29353 maintenance_manager.cc:419] P 9bea50cf131c4f10af0c0a4ae639b2e2: Scheduling FlushDeltaMemStoresOp(4737420254b24010b8f48017abbe2903): perf score=2.188937
I20260812 06:20:09.905951 29243 maintenance_manager.cc:643] P 9bea50cf131c4f10af0c0a4ae639b2e2: FlushDeltaMemStoresOp(4737420254b24010b8f48017abbe2903) complete. Timing: real 0.012s	user 0.006s	sys 0.003s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4201,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:09.906575 29353 maintenance_manager.cc:419] P 9bea50cf131c4f10af0c0a4ae639b2e2: Scheduling MajorDeltaCompactionOp(4737420254b24010b8f48017abbe2903): perf score=1.000000
I20260812 06:20:10.024447 29243 maintenance_manager.cc:643] P 9bea50cf131c4f10af0c0a4ae639b2e2: MajorDeltaCompactionOp(4737420254b24010b8f48017abbe2903) complete. Timing: real 0.117s	user 0.087s	sys 0.029s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20713271,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":1110,"lbm_read_time_us":8539,"lbm_reads_lt_1ms":472,"lbm_write_time_us":24147,"lbm_writes_lt_1ms":443,"mutex_wait_us":317,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":13056,"update_count":2000}
I20260812 06:20:10.024947 29353 maintenance_manager.cc:419] P 9bea50cf131c4f10af0c0a4ae639b2e2: Scheduling FlushDeltaMemStoresOp(4737420254b24010b8f48017abbe2903): perf score=10.126437
I20260812 06:20:10.062693 29243 maintenance_manager.cc:643] P 9bea50cf131c4f10af0c0a4ae639b2e2: FlushDeltaMemStoresOp(4737420254b24010b8f48017abbe2903) complete. Timing: real 0.038s	user 0.026s	sys 0.011s Metrics: {"bytes_written":12307489,"delete_count":0,"lbm_write_time_us":17344,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:20:10.063174 29353 maintenance_manager.cc:419] P 9bea50cf131c4f10af0c0a4ae639b2e2: Scheduling FlushDeltaMemStoresOp(4737420254b24010b8f48017abbe2903): perf score=2.188937
I20260812 06:20:10.075682 29243 maintenance_manager.cc:643] P 9bea50cf131c4f10af0c0a4ae639b2e2: FlushDeltaMemStoresOp(4737420254b24010b8f48017abbe2903) complete. Timing: real 0.012s	user 0.003s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4467,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:10.076190 29353 maintenance_manager.cc:419] P 9bea50cf131c4f10af0c0a4ae639b2e2: Scheduling MajorDeltaCompactionOp(4737420254b24010b8f48017abbe2903): perf score=1.000000
I20260812 06:20:10.199796 29243 maintenance_manager.cc:643] P 9bea50cf131c4f10af0c0a4ae639b2e2: MajorDeltaCompactionOp(4737420254b24010b8f48017abbe2903) complete. Timing: real 0.123s	user 0.108s	sys 0.014s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20713271,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":199,"lbm_read_time_us":8164,"lbm_reads_lt_1ms":464,"lbm_write_time_us":26897,"lbm_writes_lt_1ms":443,"mutex_wait_us":25,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":52480,"update_count":2000}
I20260812 06:20:10.200291 29353 maintenance_manager.cc:419] P 9bea50cf131c4f10af0c0a4ae639b2e2: Scheduling FlushDeltaMemStoresOp(4737420254b24010b8f48017abbe2903): perf score=10.126437
I20260812 06:20:10.242928 29243 maintenance_manager.cc:643] P 9bea50cf131c4f10af0c0a4ae639b2e2: FlushDeltaMemStoresOp(4737420254b24010b8f48017abbe2903) complete. Timing: real 0.042s	user 0.014s	sys 0.021s Metrics: {"bytes_written":12307491,"delete_count":0,"lbm_write_time_us":15860,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:20:10.243425 29353 maintenance_manager.cc:419] P 9bea50cf131c4f10af0c0a4ae639b2e2: Scheduling FlushDeltaMemStoresOp(4737420254b24010b8f48017abbe2903): perf score=2.188937
I20260812 06:20:10.258816 29243 maintenance_manager.cc:643] P 9bea50cf131c4f10af0c0a4ae639b2e2: FlushDeltaMemStoresOp(4737420254b24010b8f48017abbe2903) complete. Timing: real 0.015s	user 0.011s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5666,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:10.259374 29353 maintenance_manager.cc:419] P 9bea50cf131c4f10af0c0a4ae639b2e2: Scheduling MajorDeltaCompactionOp(4737420254b24010b8f48017abbe2903): perf score=1.000000
I20260812 06:20:10.374922 29243 maintenance_manager.cc:643] P 9bea50cf131c4f10af0c0a4ae639b2e2: MajorDeltaCompactionOp(4737420254b24010b8f48017abbe2903) complete. Timing: real 0.115s	user 0.099s	sys 0.016s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20713273,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":563,"lbm_read_time_us":10256,"lbm_reads_lt_1ms":472,"lbm_write_time_us":21732,"lbm_writes_lt_1ms":443,"mutex_wait_us":276,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":768,"update_count":2000}
I20260812 06:20:10.375384 29353 maintenance_manager.cc:419] P 9bea50cf131c4f10af0c0a4ae639b2e2: Scheduling FlushDeltaMemStoresOp(4737420254b24010b8f48017abbe2903): perf score=10.126437
I20260812 06:20:10.415896 29243 maintenance_manager.cc:643] P 9bea50cf131c4f10af0c0a4ae639b2e2: FlushDeltaMemStoresOp(4737420254b24010b8f48017abbe2903) complete. Timing: real 0.040s	user 0.018s	sys 0.019s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":13645,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:20:10.416442 29353 maintenance_manager.cc:419] P 9bea50cf131c4f10af0c0a4ae639b2e2: Scheduling FlushDeltaMemStoresOp(4737420254b24010b8f48017abbe2903): perf score=2.188937
I20260812 06:20:10.431169 29243 maintenance_manager.cc:643] P 9bea50cf131c4f10af0c0a4ae639b2e2: FlushDeltaMemStoresOp(4737420254b24010b8f48017abbe2903) complete. Timing: real 0.015s	user 0.010s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5590,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:10.431639 29353 maintenance_manager.cc:419] P 9bea50cf131c4f10af0c0a4ae639b2e2: Scheduling MajorDeltaCompactionOp(4737420254b24010b8f48017abbe2903): perf score=1.000000
I20260812 06:20:10.569571 29243 maintenance_manager.cc:643] P 9bea50cf131c4f10af0c0a4ae639b2e2: MajorDeltaCompactionOp(4737420254b24010b8f48017abbe2903) complete. Timing: real 0.138s	user 0.098s	sys 0.040s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20713272,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":249,"lbm_read_time_us":11996,"lbm_reads_lt_1ms":472,"lbm_write_time_us":21091,"lbm_writes_lt_1ms":443,"mutex_wait_us":86,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":1664,"update_count":2000}
I20260812 06:20:10.570067 29353 maintenance_manager.cc:419] P 9bea50cf131c4f10af0c0a4ae639b2e2: Scheduling FlushDeltaMemStoresOp(4737420254b24010b8f48017abbe2903): perf score=10.126437
I20260812 06:20:10.607654 29243 maintenance_manager.cc:643] P 9bea50cf131c4f10af0c0a4ae639b2e2: FlushDeltaMemStoresOp(4737420254b24010b8f48017abbe2903) complete. Timing: real 0.037s	user 0.015s	sys 0.015s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":14253,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:20:10.608183 29353 maintenance_manager.cc:419] P 9bea50cf131c4f10af0c0a4ae639b2e2: Scheduling FlushDeltaMemStoresOp(4737420254b24010b8f48017abbe2903): perf score=2.188937
I20260812 06:20:10.618254 29243 maintenance_manager.cc:643] P 9bea50cf131c4f10af0c0a4ae639b2e2: FlushDeltaMemStoresOp(4737420254b24010b8f48017abbe2903) complete. Timing: real 0.010s	user 0.008s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3708,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:10.618744 29353 maintenance_manager.cc:419] P 9bea50cf131c4f10af0c0a4ae639b2e2: Scheduling MajorDeltaCompactionOp(4737420254b24010b8f48017abbe2903): perf score=1.000000
I20260812 06:20:10.741847 29243 maintenance_manager.cc:643] P 9bea50cf131c4f10af0c0a4ae639b2e2: MajorDeltaCompactionOp(4737420254b24010b8f48017abbe2903) complete. Timing: real 0.123s	user 0.102s	sys 0.020s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20713272,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":1696,"lbm_read_time_us":10010,"lbm_reads_lt_1ms":472,"lbm_write_time_us":23387,"lbm_writes_lt_1ms":443,"mutex_wait_us":556,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":768,"update_count":2000}
I20260812 06:20:10.742436 29353 maintenance_manager.cc:419] P 9bea50cf131c4f10af0c0a4ae639b2e2: Scheduling FlushDeltaMemStoresOp(4737420254b24010b8f48017abbe2903): perf score=10.126437
I20260812 06:20:10.778084 29243 maintenance_manager.cc:643] P 9bea50cf131c4f10af0c0a4ae639b2e2: FlushDeltaMemStoresOp(4737420254b24010b8f48017abbe2903) complete. Timing: real 0.035s	user 0.018s	sys 0.009s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":12540,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:20:10.778625 29353 maintenance_manager.cc:419] P 9bea50cf131c4f10af0c0a4ae639b2e2: Scheduling FlushDeltaMemStoresOp(4737420254b24010b8f48017abbe2903): perf score=2.188937
I20260812 06:20:10.793466 29243 maintenance_manager.cc:643] P 9bea50cf131c4f10af0c0a4ae639b2e2: FlushDeltaMemStoresOp(4737420254b24010b8f48017abbe2903) complete. Timing: real 0.015s	user 0.012s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5437,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:10.794009 29353 maintenance_manager.cc:419] P 9bea50cf131c4f10af0c0a4ae639b2e2: Scheduling FlushMRSOp(4737420254b24010b8f48017abbe2903): perf score=1.000000
I20260812 06:20:10.825537 29243 maintenance_manager.cc:643] P 9bea50cf131c4f10af0c0a4ae639b2e2: FlushMRSOp(4737420254b24010b8f48017abbe2903) complete. Timing: real 0.031s	user 0.029s	sys 0.000s Metrics: {"bytes_written":1152508,"cfile_init":1,"dirs.queue_time_us":47,"dirs.run_cpu_time_us":293,"dirs.run_wall_time_us":1460,"drs_written":1,"lbm_read_time_us":52,"lbm_reads_lt_1ms":4,"lbm_write_time_us":2017,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":28}
I20260812 06:20:10.826423 29353 maintenance_manager.cc:419] P 9bea50cf131c4f10af0c0a4ae639b2e2: Scheduling LogGCOp(4737420254b24010b8f48017abbe2903): free 112692371 bytes of WAL
I20260812 06:20:10.826644 29243 log_reader.cc:385] T 4737420254b24010b8f48017abbe2903: removed 11 log segments from log reader
I20260812 06:20:10.826706 29243 log.cc:1079] T 4737420254b24010b8f48017abbe2903 P 9bea50cf131c4f10af0c0a4ae639b2e2: Deleting log segment in path: /tmp/dist-test-tasksggqpW/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515609106051-29068-0/minicluster-data/ts-0-root/wals/4737420254b24010b8f48017abbe2903/wal-000000003 (ops 12-16)
I20260812 06:20:10.826751 29243 log.cc:1079] T 4737420254b24010b8f48017abbe2903 P 9bea50cf131c4f10af0c0a4ae639b2e2: Deleting log segment in path: /tmp/dist-test-tasksggqpW/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515609106051-29068-0/minicluster-data/ts-0-root/wals/4737420254b24010b8f48017abbe2903/wal-000000004 (ops 17-21)
I20260812 06:20:10.826781 29243 log.cc:1079] T 4737420254b24010b8f48017abbe2903 P 9bea50cf131c4f10af0c0a4ae639b2e2: Deleting log segment in path: /tmp/dist-test-tasksggqpW/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515609106051-29068-0/minicluster-data/ts-0-root/wals/4737420254b24010b8f48017abbe2903/wal-000000005 (ops 22-26)
I20260812 06:20:10.826807 29243 log.cc:1079] T 4737420254b24010b8f48017abbe2903 P 9bea50cf131c4f10af0c0a4ae639b2e2: Deleting log segment in path: /tmp/dist-test-tasksggqpW/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515609106051-29068-0/minicluster-data/ts-0-root/wals/4737420254b24010b8f48017abbe2903/wal-000000006 (ops 27-31)
I20260812 06:20:10.826835 29243 log.cc:1079] T 4737420254b24010b8f48017abbe2903 P 9bea50cf131c4f10af0c0a4ae639b2e2: Deleting log segment in path: /tmp/dist-test-tasksggqpW/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515609106051-29068-0/minicluster-data/ts-0-root/wals/4737420254b24010b8f48017abbe2903/wal-000000007 (ops 32-36)
I20260812 06:20:10.826867 29243 log.cc:1079] T 4737420254b24010b8f48017abbe2903 P 9bea50cf131c4f10af0c0a4ae639b2e2: Deleting log segment in path: /tmp/dist-test-tasksggqpW/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515609106051-29068-0/minicluster-data/ts-0-root/wals/4737420254b24010b8f48017abbe2903/wal-000000008 (ops 37-41)
I20260812 06:20:10.826897 29243 log.cc:1079] T 4737420254b24010b8f48017abbe2903 P 9bea50cf131c4f10af0c0a4ae639b2e2: Deleting log segment in path: /tmp/dist-test-tasksggqpW/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515609106051-29068-0/minicluster-data/ts-0-root/wals/4737420254b24010b8f48017abbe2903/wal-000000009 (ops 42-46)
I20260812 06:20:10.826926 29243 log.cc:1079] T 4737420254b24010b8f48017abbe2903 P 9bea50cf131c4f10af0c0a4ae639b2e2: Deleting log segment in path: /tmp/dist-test-tasksggqpW/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515609106051-29068-0/minicluster-data/ts-0-root/wals/4737420254b24010b8f48017abbe2903/wal-000000010 (ops 47-51)
I20260812 06:20:10.826956 29243 log.cc:1079] T 4737420254b24010b8f48017abbe2903 P 9bea50cf131c4f10af0c0a4ae639b2e2: Deleting log segment in path: /tmp/dist-test-tasksggqpW/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515609106051-29068-0/minicluster-data/ts-0-root/wals/4737420254b24010b8f48017abbe2903/wal-000000011 (ops 52-56)
I20260812 06:20:10.826982 29243 log.cc:1079] T 4737420254b24010b8f48017abbe2903 P 9bea50cf131c4f10af0c0a4ae639b2e2: Deleting log segment in path: /tmp/dist-test-tasksggqpW/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515609106051-29068-0/minicluster-data/ts-0-root/wals/4737420254b24010b8f48017abbe2903/wal-000000012 (ops 57-61)
I20260812 06:20:10.827014 29243 log.cc:1079] T 4737420254b24010b8f48017abbe2903 P 9bea50cf131c4f10af0c0a4ae639b2e2: Deleting log segment in path: /tmp/dist-test-tasksggqpW/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515609106051-29068-0/minicluster-data/ts-0-root/wals/4737420254b24010b8f48017abbe2903/wal-000000013 (ops 62-66)
I20260812 06:20:10.852239 29243 maintenance_manager.cc:643] P 9bea50cf131c4f10af0c0a4ae639b2e2: LogGCOp(4737420254b24010b8f48017abbe2903) complete. Timing: real 0.026s	user 0.004s	sys 0.020s Metrics: {}
I20260812 06:20:10.852698 29353 maintenance_manager.cc:419] P 9bea50cf131c4f10af0c0a4ae639b2e2: Scheduling FlushDeltaMemStoresOp(4737420254b24010b8f48017abbe2903): perf score=2.188937
I20260812 06:20:10.873514 29243 maintenance_manager.cc:643] P 9bea50cf131c4f10af0c0a4ae639b2e2: FlushDeltaMemStoresOp(4737420254b24010b8f48017abbe2903) complete. Timing: real 0.021s	user 0.009s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5601,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:10.873972 29353 maintenance_manager.cc:419] P 9bea50cf131c4f10af0c0a4ae639b2e2: Scheduling LogGCOp(4737420254b24010b8f48017abbe2903): free 11564875 bytes of WAL
I20260812 06:20:10.874171 29243 log_reader.cc:385] T 4737420254b24010b8f48017abbe2903: removed 1 log segments from log reader
I20260812 06:20:10.874233 29243 log.cc:1079] T 4737420254b24010b8f48017abbe2903 P 9bea50cf131c4f10af0c0a4ae639b2e2: Deleting log segment in path: /tmp/dist-test-tasksggqpW/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515609106051-29068-0/minicluster-data/ts-0-root/wals/4737420254b24010b8f48017abbe2903/wal-000000014 (ops 67-70)
I20260812 06:20:10.876912 29243 maintenance_manager.cc:643] P 9bea50cf131c4f10af0c0a4ae639b2e2: LogGCOp(4737420254b24010b8f48017abbe2903) complete. Timing: real 0.003s	user 0.000s	sys 0.000s Metrics: {}
I20260812 06:20:10.877208 29353 maintenance_manager.cc:419] P 9bea50cf131c4f10af0c0a4ae639b2e2: Scheduling FlushDeltaMemStoresOp(4737420254b24010b8f48017abbe2903): perf score=2.188937
I20260812 06:20:10.892017 29243 maintenance_manager.cc:643] P 9bea50cf131c4f10af0c0a4ae639b2e2: FlushDeltaMemStoresOp(4737420254b24010b8f48017abbe2903) complete. Timing: real 0.015s	user 0.004s	sys 0.009s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5621,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:10.892563 29353 maintenance_manager.cc:419] P 9bea50cf131c4f10af0c0a4ae639b2e2: Scheduling UndoDeltaBlockGCOp(4737420254b24010b8f48017abbe2903): 446 bytes on disk
I20260812 06:20:10.892935 29243 maintenance_manager.cc:643] P 9bea50cf131c4f10af0c0a4ae639b2e2: UndoDeltaBlockGCOp(4737420254b24010b8f48017abbe2903) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":46,"lbm_reads_lt_1ms":4}
I20260812 06:20:10.893401 29353 maintenance_manager.cc:419] P 9bea50cf131c4f10af0c0a4ae639b2e2: Scheduling MajorDeltaCompactionOp(4737420254b24010b8f48017abbe2903): perf score=1.000000
I20260812 06:20:11.058431 29243 maintenance_manager.cc:643] P 9bea50cf131c4f10af0c0a4ae639b2e2: MajorDeltaCompactionOp(4737420254b24010b8f48017abbe2903) complete. Timing: real 0.165s	user 0.121s	sys 0.039s Metrics: {"cfile_cache_miss":634,"cfile_cache_miss_bytes":28918334,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":806,"lbm_read_time_us":10095,"lbm_reads_lt_1ms":670,"lbm_write_time_us":33514,"lbm_writes_lt_1ms":643,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":4608,"thread_start_us":120,"threads_started":1,"update_count":3000}
I20260812 06:20:11.059003 29353 maintenance_manager.cc:419] P 9bea50cf131c4f10af0c0a4ae639b2e2: Scheduling FlushDeltaMemStoresOp(4737420254b24010b8f48017abbe2903): perf score=14.095187
I20260812 06:20:11.108459 29243 maintenance_manager.cc:643] P 9bea50cf131c4f10af0c0a4ae639b2e2: FlushDeltaMemStoresOp(4737420254b24010b8f48017abbe2903) complete. Timing: real 0.049s	user 0.022s	sys 0.025s Metrics: {"bytes_written":16409909,"delete_count":0,"lbm_write_time_us":22327,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:20:11.109005 29353 maintenance_manager.cc:419] P 9bea50cf131c4f10af0c0a4ae639b2e2: Scheduling FlushDeltaMemStoresOp(4737420254b24010b8f48017abbe2903): perf score=2.188937
I20260812 06:20:11.123348 29243 maintenance_manager.cc:643] P 9bea50cf131c4f10af0c0a4ae639b2e2: FlushDeltaMemStoresOp(4737420254b24010b8f48017abbe2903) complete. Timing: real 0.014s	user 0.012s	sys 0.001s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5149,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:11.123837 29353 maintenance_manager.cc:419] P 9bea50cf131c4f10af0c0a4ae639b2e2: Scheduling MajorDeltaCompactionOp(4737420254b24010b8f48017abbe2903): perf score=1.000000
I20260812 06:20:11.282689 29243 maintenance_manager.cc:643] P 9bea50cf131c4f10af0c0a4ae639b2e2: MajorDeltaCompactionOp(4737420254b24010b8f48017abbe2903) complete. Timing: real 0.159s	user 0.124s	sys 0.033s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24815691,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":166,"lbm_read_time_us":10240,"lbm_reads_lt_1ms":564,"lbm_write_time_us":32549,"lbm_writes_lt_1ms":543,"mutex_wait_us":30,"peak_mem_usage":63115900,"reinsert_count":0,"update_count":2500}
I20260812 06:20:11.283169 29353 maintenance_manager.cc:419] P 9bea50cf131c4f10af0c0a4ae639b2e2: Scheduling FlushDeltaMemStoresOp(4737420254b24010b8f48017abbe2903): perf score=14.095187
I20260812 06:20:11.340962 29243 maintenance_manager.cc:643] P 9bea50cf131c4f10af0c0a4ae639b2e2: FlushDeltaMemStoresOp(4737420254b24010b8f48017abbe2903) complete. Timing: real 0.058s	user 0.032s	sys 0.017s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":23369,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:20:11.341444 29353 maintenance_manager.cc:419] P 9bea50cf131c4f10af0c0a4ae639b2e2: Scheduling MajorDeltaCompactionOp(4737420254b24010b8f48017abbe2903): perf score=1.000000
I20260812 06:20:11.490940 29243 maintenance_manager.cc:643] P 9bea50cf131c4f10af0c0a4ae639b2e2: MajorDeltaCompactionOp(4737420254b24010b8f48017abbe2903) complete. Timing: real 0.149s	user 0.108s	sys 0.036s Metrics: {"cfile_cache_miss":431,"cfile_cache_miss_bytes":20713153,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":1,"delta_iterators_relevant":1,"dirs.queue_time_us":785,"lbm_read_time_us":9536,"lbm_reads_lt_1ms":463,"lbm_write_time_us":23277,"lbm_writes_lt_1ms":443,"mutex_wait_us":29,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":7168,"update_count":2000}
I20260812 06:20:11.491478 29353 maintenance_manager.cc:419] P 9bea50cf131c4f10af0c0a4ae639b2e2: Scheduling FlushDeltaMemStoresOp(4737420254b24010b8f48017abbe2903): perf score=14.095187
I20260812 06:20:11.535390 29243 maintenance_manager.cc:643] P 9bea50cf131c4f10af0c0a4ae639b2e2: FlushDeltaMemStoresOp(4737420254b24010b8f48017abbe2903) complete. Timing: real 0.044s	user 0.023s	sys 0.020s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":20104,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:20:11.535969 29353 maintenance_manager.cc:419] P 9bea50cf131c4f10af0c0a4ae639b2e2: Scheduling FlushDeltaMemStoresOp(4737420254b24010b8f48017abbe2903): perf score=2.188937
I20260812 06:20:11.556543 29243 maintenance_manager.cc:643] P 9bea50cf131c4f10af0c0a4ae639b2e2: FlushDeltaMemStoresOp(4737420254b24010b8f48017abbe2903) complete. Timing: real 0.020s	user 0.007s	sys 0.011s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4892,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:11.557063 29353 maintenance_manager.cc:419] P 9bea50cf131c4f10af0c0a4ae639b2e2: Scheduling MajorDeltaCompactionOp(4737420254b24010b8f48017abbe2903): perf score=1.000000
I20260812 06:20:11.733984 29243 maintenance_manager.cc:643] P 9bea50cf131c4f10af0c0a4ae639b2e2: MajorDeltaCompactionOp(4737420254b24010b8f48017abbe2903) complete. Timing: real 0.177s	user 0.112s	sys 0.056s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24815684,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":157,"lbm_read_time_us":11254,"lbm_reads_lt_1ms":564,"lbm_write_time_us":28151,"lbm_writes_lt_1ms":543,"mutex_wait_us":51,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":13824,"update_count":2500}
I20260812 06:20:11.734506 29353 maintenance_manager.cc:419] P 9bea50cf131c4f10af0c0a4ae639b2e2: Scheduling FlushDeltaMemStoresOp(4737420254b24010b8f48017abbe2903): perf score=14.095187
I20260812 06:20:11.787643 29243 maintenance_manager.cc:643] P 9bea50cf131c4f10af0c0a4ae639b2e2: FlushDeltaMemStoresOp(4737420254b24010b8f48017abbe2903) complete. Timing: real 0.053s	user 0.028s	sys 0.017s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":20274,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:20:11.788141 29353 maintenance_manager.cc:419] P 9bea50cf131c4f10af0c0a4ae639b2e2: Scheduling FlushDeltaMemStoresOp(4737420254b24010b8f48017abbe2903): perf score=2.188937
I20260812 06:20:11.803324 29243 maintenance_manager.cc:643] P 9bea50cf131c4f10af0c0a4ae639b2e2: FlushDeltaMemStoresOp(4737420254b24010b8f48017abbe2903) complete. Timing: real 0.015s	user 0.008s	sys 0.005s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":5762,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:11.803830 29353 maintenance_manager.cc:419] P 9bea50cf131c4f10af0c0a4ae639b2e2: Scheduling MajorDeltaCompactionOp(4737420254b24010b8f48017abbe2903): perf score=1.000000
I20260812 06:20:11.947361 29243 maintenance_manager.cc:643] P 9bea50cf131c4f10af0c0a4ae639b2e2: MajorDeltaCompactionOp(4737420254b24010b8f48017abbe2903) complete. Timing: real 0.143s	user 0.110s	sys 0.029s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24815683,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":949,"lbm_read_time_us":9437,"lbm_reads_lt_1ms":572,"lbm_write_time_us":28892,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":542,"mutex_wait_us":243,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":135296,"update_count":2500}
I20260812 06:20:11.947861 29353 maintenance_manager.cc:419] P 9bea50cf131c4f10af0c0a4ae639b2e2: Scheduling FlushDeltaMemStoresOp(4737420254b24010b8f48017abbe2903): perf score=11.118625
I20260812 06:20:11.980690 29243 maintenance_manager.cc:643] P 9bea50cf131c4f10af0c0a4ae639b2e2: FlushDeltaMemStoresOp(4737420254b24010b8f48017abbe2903) complete. Timing: real 0.033s	user 0.005s	sys 0.024s Metrics: {"bytes_written":12717735,"delete_count":0,"lbm_write_time_us":13551,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":312,"reinsert_count":0,"update_count":1550}
I20260812 06:20:11.981801 29353 maintenance_manager.cc:419] P 9bea50cf131c4f10af0c0a4ae639b2e2: Scheduling FlushDeltaMemStoresOp(4737420254b24010b8f48017abbe2903): perf score=2.188937
I20260812 06:20:11.999616 29243 maintenance_manager.cc:643] P 9bea50cf131c4f10af0c0a4ae639b2e2: FlushDeltaMemStoresOp(4737420254b24010b8f48017abbe2903) complete. Timing: real 0.018s	user 0.000s	sys 0.011s Metrics: {"bytes_written":4102660,"delete_count":0,"lbm_write_time_us":4753,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:12.000137 29353 maintenance_manager.cc:419] P 9bea50cf131c4f10af0c0a4ae639b2e2: Scheduling FlushDeltaMemStoresOp(4737420254b24010b8f48017abbe2903): perf score=2.188937
I20260812 06:20:12.009264 29243 maintenance_manager.cc:643] P 9bea50cf131c4f10af0c0a4ae639b2e2: FlushDeltaMemStoresOp(4737420254b24010b8f48017abbe2903) complete. Timing: real 0.009s	user 0.001s	sys 0.006s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3392,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:20:12.009687 29353 maintenance_manager.cc:419] P 9bea50cf131c4f10af0c0a4ae639b2e2: Scheduling MajorDeltaCompactionOp(4737420254b24010b8f48017abbe2903): perf score=1.000000
I20260812 06:20:12.156529 29243 maintenance_manager.cc:643] P 9bea50cf131c4f10af0c0a4ae639b2e2: MajorDeltaCompactionOp(4737420254b24010b8f48017abbe2903) complete. Timing: real 0.147s	user 0.120s	sys 0.022s Metrics: {"cfile_cache_miss":533,"cfile_cache_miss_bytes":24815795,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":418,"lbm_read_time_us":10258,"lbm_reads_lt_1ms":573,"lbm_write_time_us":29720,"lbm_writes_lt_1ms":543,"mutex_wait_us":263,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":9344,"update_count":2500}
I20260812 06:20:12.156983 29353 maintenance_manager.cc:419] P 9bea50cf131c4f10af0c0a4ae639b2e2: Scheduling FlushDeltaMemStoresOp(4737420254b24010b8f48017abbe2903): perf score=11.118625
I20260812 06:20:12.186918 29243 maintenance_manager.cc:643] P 9bea50cf131c4f10af0c0a4ae639b2e2: FlushDeltaMemStoresOp(4737420254b24010b8f48017abbe2903) complete. Timing: real 0.030s	user 0.016s	sys 0.013s Metrics: {"bytes_written":12717735,"delete_count":0,"lbm_write_time_us":12649,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:20:12.189280 29353 maintenance_manager.cc:419] P 9bea50cf131c4f10af0c0a4ae639b2e2: Scheduling FlushDeltaMemStoresOp(4737420254b24010b8f48017abbe2903): perf score=2.188937
I20260812 06:20:12.212162 29243 maintenance_manager.cc:643] P 9bea50cf131c4f10af0c0a4ae639b2e2: FlushDeltaMemStoresOp(4737420254b24010b8f48017abbe2903) complete. Timing: real 0.023s	user 0.007s	sys 0.003s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":4522,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:20:12.212710 29353 maintenance_manager.cc:419] P 9bea50cf131c4f10af0c0a4ae639b2e2: Scheduling FlushDeltaMemStoresOp(4737420254b24010b8f48017abbe2903): perf score=2.188937
I20260812 06:20:12.222776 29243 maintenance_manager.cc:643] P 9bea50cf131c4f10af0c0a4ae639b2e2: FlushDeltaMemStoresOp(4737420254b24010b8f48017abbe2903) complete. Timing: real 0.010s	user 0.005s	sys 0.004s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":3786,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:12.223232 29353 maintenance_manager.cc:419] P 9bea50cf131c4f10af0c0a4ae639b2e2: Scheduling FlushMRSOp(4737420254b24010b8f48017abbe2903): perf score=1.000000
I20260812 06:20:12.256385 29243 maintenance_manager.cc:643] P 9bea50cf131c4f10af0c0a4ae639b2e2: FlushMRSOp(4737420254b24010b8f48017abbe2903) complete. Timing: real 0.033s	user 0.031s	sys 0.000s Metrics: {"bytes_written":1275449,"cfile_init":1,"dirs.queue_time_us":67,"dirs.run_cpu_time_us":256,"dirs.run_wall_time_us":1409,"drs_written":1,"lbm_read_time_us":38,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1748,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":31}
I20260812 06:20:12.257103 29353 maintenance_manager.cc:419] P 9bea50cf131c4f10af0c0a4ae639b2e2: Scheduling LogGCOp(4737420254b24010b8f48017abbe2903): free 120553382 bytes of WAL
I20260812 06:20:12.257334 29243 log_reader.cc:385] T 4737420254b24010b8f48017abbe2903: removed 12 log segments from log reader
I20260812 06:20:12.257381 29243 log.cc:1079] T 4737420254b24010b8f48017abbe2903 P 9bea50cf131c4f10af0c0a4ae639b2e2: Deleting log segment in path: /tmp/dist-test-tasksggqpW/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515609106051-29068-0/minicluster-data/ts-0-root/wals/4737420254b24010b8f48017abbe2903/wal-000000015 (ops 71-75)
I20260812 06:20:12.257411 29243 log.cc:1079] T 4737420254b24010b8f48017abbe2903 P 9bea50cf131c4f10af0c0a4ae639b2e2: Deleting log segment in path: /tmp/dist-test-tasksggqpW/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515609106051-29068-0/minicluster-data/ts-0-root/wals/4737420254b24010b8f48017abbe2903/wal-000000016 (ops 76-80)
I20260812 06:20:12.257442 29243 log.cc:1079] T 4737420254b24010b8f48017abbe2903 P 9bea50cf131c4f10af0c0a4ae639b2e2: Deleting log segment in path: /tmp/dist-test-tasksggqpW/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515609106051-29068-0/minicluster-data/ts-0-root/wals/4737420254b24010b8f48017abbe2903/wal-000000017 (ops 81-85)
I20260812 06:20:12.257481 29243 log.cc:1079] T 4737420254b24010b8f48017abbe2903 P 9bea50cf131c4f10af0c0a4ae639b2e2: Deleting log segment in path: /tmp/dist-test-tasksggqpW/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515609106051-29068-0/minicluster-data/ts-0-root/wals/4737420254b24010b8f48017abbe2903/wal-000000018 (ops 86-90)
I20260812 06:20:12.257515 29243 log.cc:1079] T 4737420254b24010b8f48017abbe2903 P 9bea50cf131c4f10af0c0a4ae639b2e2: Deleting log segment in path: /tmp/dist-test-tasksggqpW/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515609106051-29068-0/minicluster-data/ts-0-root/wals/4737420254b24010b8f48017abbe2903/wal-000000019 (ops 91-95)
I20260812 06:20:12.257548 29243 log.cc:1079] T 4737420254b24010b8f48017abbe2903 P 9bea50cf131c4f10af0c0a4ae639b2e2: Deleting log segment in path: /tmp/dist-test-tasksggqpW/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515609106051-29068-0/minicluster-data/ts-0-root/wals/4737420254b24010b8f48017abbe2903/wal-000000020 (ops 96-100)
I20260812 06:20:12.257580 29243 log.cc:1079] T 4737420254b24010b8f48017abbe2903 P 9bea50cf131c4f10af0c0a4ae639b2e2: Deleting log segment in path: /tmp/dist-test-tasksggqpW/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515609106051-29068-0/minicluster-data/ts-0-root/wals/4737420254b24010b8f48017abbe2903/wal-000000021 (ops 101-104)
I20260812 06:20:12.257612 29243 log.cc:1079] T 4737420254b24010b8f48017abbe2903 P 9bea50cf131c4f10af0c0a4ae639b2e2: Deleting log segment in path: /tmp/dist-test-tasksggqpW/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515609106051-29068-0/minicluster-data/ts-0-root/wals/4737420254b24010b8f48017abbe2903/wal-000000022 (ops 105-109)
I20260812 06:20:12.257645 29243 log.cc:1079] T 4737420254b24010b8f48017abbe2903 P 9bea50cf131c4f10af0c0a4ae639b2e2: Deleting log segment in path: /tmp/dist-test-tasksggqpW/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515609106051-29068-0/minicluster-data/ts-0-root/wals/4737420254b24010b8f48017abbe2903/wal-000000023 (ops 110-114)
I20260812 06:20:12.257676 29243 log.cc:1079] T 4737420254b24010b8f48017abbe2903 P 9bea50cf131c4f10af0c0a4ae639b2e2: Deleting log segment in path: /tmp/dist-test-tasksggqpW/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515609106051-29068-0/minicluster-data/ts-0-root/wals/4737420254b24010b8f48017abbe2903/wal-000000024 (ops 115-119)
I20260812 06:20:12.257709 29243 log.cc:1079] T 4737420254b24010b8f48017abbe2903 P 9bea50cf131c4f10af0c0a4ae639b2e2: Deleting log segment in path: /tmp/dist-test-tasksggqpW/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515609106051-29068-0/minicluster-data/ts-0-root/wals/4737420254b24010b8f48017abbe2903/wal-000000025 (ops 120-124)
I20260812 06:20:12.257741 29243 log.cc:1079] T 4737420254b24010b8f48017abbe2903 P 9bea50cf131c4f10af0c0a4ae639b2e2: Deleting log segment in path: /tmp/dist-test-tasksggqpW/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515609106051-29068-0/minicluster-data/ts-0-root/wals/4737420254b24010b8f48017abbe2903/wal-000000026 (ops 125-128)
I20260812 06:20:12.279722 29243 maintenance_manager.cc:643] P 9bea50cf131c4f10af0c0a4ae639b2e2: LogGCOp(4737420254b24010b8f48017abbe2903) complete. Timing: real 0.022s	user 0.000s	sys 0.021s Metrics: {}
I20260812 06:20:12.280159 29353 maintenance_manager.cc:419] P 9bea50cf131c4f10af0c0a4ae639b2e2: Scheduling UndoDeltaBlockGCOp(4737420254b24010b8f48017abbe2903): 483 bytes on disk
I20260812 06:20:12.280583 29243 maintenance_manager.cc:643] P 9bea50cf131c4f10af0c0a4ae639b2e2: UndoDeltaBlockGCOp(4737420254b24010b8f48017abbe2903) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":49,"lbm_reads_lt_1ms":4}
I20260812 06:20:12.281175 29353 maintenance_manager.cc:419] P 9bea50cf131c4f10af0c0a4ae639b2e2: Scheduling FlushDeltaMemStoresOp(4737420254b24010b8f48017abbe2903): perf score=3.181125
I20260812 06:20:12.292693 29243 maintenance_manager.cc:643] P 9bea50cf131c4f10af0c0a4ae639b2e2: FlushDeltaMemStoresOp(4737420254b24010b8f48017abbe2903) complete. Timing: real 0.011s	user 0.008s	sys 0.001s Metrics: {"bytes_written":4512900,"delete_count":0,"lbm_write_time_us":3887,"lbm_writes_lt_1ms":113,"reinsert_count":0,"update_count":550}
I20260812 06:20:12.293102 29353 maintenance_manager.cc:419] P 9bea50cf131c4f10af0c0a4ae639b2e2: Scheduling FlushDeltaMemStoresOp(4737420254b24010b8f48017abbe2903): perf score=2.188937
I20260812 06:20:12.309512 29243 maintenance_manager.cc:643] P 9bea50cf131c4f10af0c0a4ae639b2e2: FlushDeltaMemStoresOp(4737420254b24010b8f48017abbe2903) complete. Timing: real 0.016s	user 0.007s	sys 0.006s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3400,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:20:12.309957 29353 maintenance_manager.cc:419] P 9bea50cf131c4f10af0c0a4ae639b2e2: Scheduling MajorDeltaCompactionOp(4737420254b24010b8f48017abbe2903): perf score=1.000000
I20260812 06:20:12.519687 29243 maintenance_manager.cc:643] P 9bea50cf131c4f10af0c0a4ae639b2e2: MajorDeltaCompactionOp(4737420254b24010b8f48017abbe2903) complete. Timing: real 0.210s	user 0.159s	sys 0.050s Metrics: {"cfile_cache_miss":735,"cfile_cache_miss_bytes":33020842,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":5,"delta_iterators_relevant":5,"dirs.queue_time_us":352,"lbm_read_time_us":15934,"lbm_reads_lt_1ms":775,"lbm_write_time_us":36557,"lbm_writes_lt_1ms":743,"mutex_wait_us":56,"peak_mem_usage":87969044,"reinsert_count":0,"spinlock_wait_cycles":12672,"thread_start_us":94,"threads_started":1,"update_count":3500}
I20260812 06:20:12.520147 29353 maintenance_manager.cc:419] P 9bea50cf131c4f10af0c0a4ae639b2e2: Scheduling FlushDeltaMemStoresOp(4737420254b24010b8f48017abbe2903): perf score=14.095187
I20260812 06:20:12.570791 29243 maintenance_manager.cc:643] P 9bea50cf131c4f10af0c0a4ae639b2e2: FlushDeltaMemStoresOp(4737420254b24010b8f48017abbe2903) complete. Timing: real 0.050s	user 0.026s	sys 0.024s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":17858,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:20:12.571290 29353 maintenance_manager.cc:419] P 9bea50cf131c4f10af0c0a4ae639b2e2: Scheduling FlushDeltaMemStoresOp(4737420254b24010b8f48017abbe2903): perf score=2.188937
I20260812 06:20:12.586187 29243 maintenance_manager.cc:643] P 9bea50cf131c4f10af0c0a4ae639b2e2: FlushDeltaMemStoresOp(4737420254b24010b8f48017abbe2903) complete. Timing: real 0.015s	user 0.004s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5717,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:12.586735 29353 maintenance_manager.cc:419] P 9bea50cf131c4f10af0c0a4ae639b2e2: Scheduling MajorDeltaCompactionOp(4737420254b24010b8f48017abbe2903): perf score=1.000000
I20260812 06:20:12.757606 29243 maintenance_manager.cc:643] P 9bea50cf131c4f10af0c0a4ae639b2e2: MajorDeltaCompactionOp(4737420254b24010b8f48017abbe2903) complete. Timing: real 0.171s	user 0.092s	sys 0.077s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24815683,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":581,"lbm_read_time_us":12706,"lbm_reads_lt_1ms":572,"lbm_write_time_us":29407,"lbm_writes_lt_1ms":543,"mutex_wait_us":277,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":4992,"update_count":2500}
I20260812 06:20:12.760040 29353 maintenance_manager.cc:419] P 9bea50cf131c4f10af0c0a4ae639b2e2: Scheduling FlushDeltaMemStoresOp(4737420254b24010b8f48017abbe2903): perf score=11.118625
I20260812 06:20:12.796447 29243 maintenance_manager.cc:643] P 9bea50cf131c4f10af0c0a4ae639b2e2: FlushDeltaMemStoresOp(4737420254b24010b8f48017abbe2903) complete. Timing: real 0.036s	user 0.019s	sys 0.014s Metrics: {"bytes_written":12717738,"delete_count":0,"lbm_write_time_us":13770,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:20:12.797101 29353 maintenance_manager.cc:419] P 9bea50cf131c4f10af0c0a4ae639b2e2: Scheduling FlushDeltaMemStoresOp(4737420254b24010b8f48017abbe2903): perf score=2.188937
I20260812 06:20:12.822036 29243 maintenance_manager.cc:643] P 9bea50cf131c4f10af0c0a4ae639b2e2: FlushDeltaMemStoresOp(4737420254b24010b8f48017abbe2903) complete. Timing: real 0.025s	user 0.012s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6050,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:12.822536 29353 maintenance_manager.cc:419] P 9bea50cf131c4f10af0c0a4ae639b2e2: Scheduling FlushDeltaMemStoresOp(4737420254b24010b8f48017abbe2903): perf score=2.188937
I20260812 06:20:12.831944 29243 maintenance_manager.cc:643] P 9bea50cf131c4f10af0c0a4ae639b2e2: FlushDeltaMemStoresOp(4737420254b24010b8f48017abbe2903) complete. Timing: real 0.009s	user 0.003s	sys 0.005s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3453,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:20:12.832417 29353 maintenance_manager.cc:419] P 9bea50cf131c4f10af0c0a4ae639b2e2: Scheduling MajorDeltaCompactionOp(4737420254b24010b8f48017abbe2903): perf score=1.000000
I20260812 06:20:13.001663 29243 maintenance_manager.cc:643] P 9bea50cf131c4f10af0c0a4ae639b2e2: MajorDeltaCompactionOp(4737420254b24010b8f48017abbe2903) complete. Timing: real 0.169s	user 0.120s	sys 0.044s Metrics: {"cfile_cache_miss":533,"cfile_cache_miss_bytes":24815797,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":1219,"lbm_read_time_us":13006,"lbm_reads_lt_1ms":573,"lbm_write_time_us":27546,"lbm_writes_lt_1ms":543,"mutex_wait_us":257,"peak_mem_usage":63115900,"reinsert_count":0,"update_count":2500}
I20260812 06:20:13.002139 29353 maintenance_manager.cc:419] P 9bea50cf131c4f10af0c0a4ae639b2e2: Scheduling FlushDeltaMemStoresOp(4737420254b24010b8f48017abbe2903): perf score=14.095187
I20260812 06:20:13.047762 29243 maintenance_manager.cc:643] P 9bea50cf131c4f10af0c0a4ae639b2e2: FlushDeltaMemStoresOp(4737420254b24010b8f48017abbe2903) complete. Timing: real 0.045s	user 0.022s	sys 0.016s Metrics: {"bytes_written":16409900,"delete_count":0,"lbm_write_time_us":16774,"lbm_writes_lt_1ms":403,"reinsert_count":0,"spinlock_wait_cycles":1920,"update_count":2000}
I20260812 06:20:13.048328 29353 maintenance_manager.cc:419] P 9bea50cf131c4f10af0c0a4ae639b2e2: Scheduling FlushDeltaMemStoresOp(4737420254b24010b8f48017abbe2903): perf score=2.188937
I20260812 06:20:13.072410 29243 maintenance_manager.cc:643] P 9bea50cf131c4f10af0c0a4ae639b2e2: FlushDeltaMemStoresOp(4737420254b24010b8f48017abbe2903) complete. Timing: real 0.024s	user 0.009s	sys 0.013s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6184,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:13.072991 29353 maintenance_manager.cc:419] P 9bea50cf131c4f10af0c0a4ae639b2e2: Scheduling MajorDeltaCompactionOp(4737420254b24010b8f48017abbe2903): perf score=1.000000
I20260812 06:20:13.250993 29243 maintenance_manager.cc:643] P 9bea50cf131c4f10af0c0a4ae639b2e2: MajorDeltaCompactionOp(4737420254b24010b8f48017abbe2903) complete. Timing: real 0.178s	user 0.121s	sys 0.049s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24815682,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":945,"lbm_read_time_us":10953,"lbm_reads_lt_1ms":572,"lbm_write_time_us":31300,"lbm_writes_lt_1ms":543,"mutex_wait_us":1,"peak_mem_usage":63115900,"reinsert_count":0,"update_count":2500}
I20260812 06:20:13.251485 29353 maintenance_manager.cc:419] P 9bea50cf131c4f10af0c0a4ae639b2e2: Scheduling FlushDeltaMemStoresOp(4737420254b24010b8f48017abbe2903): perf score=14.095187
I20260812 06:20:13.293740 29243 maintenance_manager.cc:643] P 9bea50cf131c4f10af0c0a4ae639b2e2: FlushDeltaMemStoresOp(4737420254b24010b8f48017abbe2903) complete. Timing: real 0.042s	user 0.030s	sys 0.008s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":19046,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:20:13.294247 29353 maintenance_manager.cc:419] P 9bea50cf131c4f10af0c0a4ae639b2e2: Scheduling FlushDeltaMemStoresOp(4737420254b24010b8f48017abbe2903): perf score=2.188937
I20260812 06:20:13.304615 29243 maintenance_manager.cc:643] P 9bea50cf131c4f10af0c0a4ae639b2e2: FlushDeltaMemStoresOp(4737420254b24010b8f48017abbe2903) complete. Timing: real 0.010s	user 0.008s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3693,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:13.305137 29353 maintenance_manager.cc:419] P 9bea50cf131c4f10af0c0a4ae639b2e2: Scheduling MajorDeltaCompactionOp(4737420254b24010b8f48017abbe2903): perf score=1.000000
I20260812 06:20:13.456969 29243 maintenance_manager.cc:643] P 9bea50cf131c4f10af0c0a4ae639b2e2: MajorDeltaCompactionOp(4737420254b24010b8f48017abbe2903) complete. Timing: real 0.152s	user 0.112s	sys 0.038s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24815683,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":567,"lbm_read_time_us":9418,"lbm_reads_lt_1ms":572,"lbm_write_time_us":29069,"lbm_writes_lt_1ms":543,"mutex_wait_us":23,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":10112,"update_count":2500}
I20260812 06:20:13.457553 29353 maintenance_manager.cc:419] P 9bea50cf131c4f10af0c0a4ae639b2e2: Scheduling FlushDeltaMemStoresOp(4737420254b24010b8f48017abbe2903): perf score=11.118625
I20260812 06:20:13.497081 29243 maintenance_manager.cc:643] P 9bea50cf131c4f10af0c0a4ae639b2e2: FlushDeltaMemStoresOp(4737420254b24010b8f48017abbe2903) complete. Timing: real 0.039s	user 0.023s	sys 0.014s Metrics: {"bytes_written":12717734,"delete_count":0,"lbm_write_time_us":16588,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":312,"reinsert_count":0,"update_count":1550}
I20260812 06:20:13.497905 29353 maintenance_manager.cc:419] P 9bea50cf131c4f10af0c0a4ae639b2e2: Scheduling FlushDeltaMemStoresOp(4737420254b24010b8f48017abbe2903): perf score=2.188937
I20260812 06:20:13.512385 29243 maintenance_manager.cc:643] P 9bea50cf131c4f10af0c0a4ae639b2e2: FlushDeltaMemStoresOp(4737420254b24010b8f48017abbe2903) complete. Timing: real 0.014s	user 0.004s	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:20:13.512840 29353 maintenance_manager.cc:419] P 9bea50cf131c4f10af0c0a4ae639b2e2: Scheduling FlushDeltaMemStoresOp(4737420254b24010b8f48017abbe2903): perf score=2.188937
I20260812 06:20:13.527180 29243 maintenance_manager.cc:643] P 9bea50cf131c4f10af0c0a4ae639b2e2: FlushDeltaMemStoresOp(4737420254b24010b8f48017abbe2903) complete. Timing: real 0.014s	user 0.005s	sys 0.008s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":5332,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:13.527696 29353 maintenance_manager.cc:419] P 9bea50cf131c4f10af0c0a4ae639b2e2: Scheduling MajorDeltaCompactionOp(4737420254b24010b8f48017abbe2903): perf score=1.000000
I20260812 06:20:13.671842 29243 maintenance_manager.cc:643] P 9bea50cf131c4f10af0c0a4ae639b2e2: MajorDeltaCompactionOp(4737420254b24010b8f48017abbe2903) complete. Timing: real 0.144s	user 0.112s	sys 0.028s Metrics: {"cfile_cache_miss":533,"cfile_cache_miss_bytes":24815792,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":105,"lbm_read_time_us":9388,"lbm_reads_lt_1ms":573,"lbm_write_time_us":27601,"lbm_writes_lt_1ms":543,"mutex_wait_us":31,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":68096,"update_count":2500}
I20260812 06:20:13.672453 29353 maintenance_manager.cc:419] P 9bea50cf131c4f10af0c0a4ae639b2e2: Scheduling FlushDeltaMemStoresOp(4737420254b24010b8f48017abbe2903): perf score=11.118625
I20260812 06:20:13.711269 29243 maintenance_manager.cc:643] P 9bea50cf131c4f10af0c0a4ae639b2e2: FlushDeltaMemStoresOp(4737420254b24010b8f48017abbe2903) complete. Timing: real 0.039s	user 0.020s	sys 0.018s Metrics: {"bytes_written":12717735,"delete_count":0,"lbm_write_time_us":16671,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:20:13.711853 29353 maintenance_manager.cc:419] P 9bea50cf131c4f10af0c0a4ae639b2e2: Scheduling FlushDeltaMemStoresOp(4737420254b24010b8f48017abbe2903): perf score=2.188937
I20260812 06:20:13.730998 29243 maintenance_manager.cc:643] P 9bea50cf131c4f10af0c0a4ae639b2e2: FlushDeltaMemStoresOp(4737420254b24010b8f48017abbe2903) complete. Timing: real 0.019s	user 0.009s	sys 0.004s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":5620,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:20:13.731451 29353 maintenance_manager.cc:419] P 9bea50cf131c4f10af0c0a4ae639b2e2: Scheduling FlushDeltaMemStoresOp(4737420254b24010b8f48017abbe2903): perf score=2.188937
I20260812 06:20:13.741007 29243 maintenance_manager.cc:643] P 9bea50cf131c4f10af0c0a4ae639b2e2: FlushDeltaMemStoresOp(4737420254b24010b8f48017abbe2903) complete. Timing: real 0.009s	user 0.008s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3644,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:13.741422 29353 maintenance_manager.cc:419] P 9bea50cf131c4f10af0c0a4ae639b2e2: Scheduling FlushMRSOp(4737420254b24010b8f48017abbe2903): perf score=1.000000
I20260812 06:20:13.774717 29243 maintenance_manager.cc:643] P 9bea50cf131c4f10af0c0a4ae639b2e2: FlushMRSOp(4737420254b24010b8f48017abbe2903) complete. Timing: real 0.033s	user 0.033s	sys 0.000s Metrics: {"bytes_written":1316417,"cfile_init":1,"dirs.queue_time_us":44,"dirs.run_cpu_time_us":199,"dirs.run_wall_time_us":1382,"drs_written":1,"lbm_read_time_us":36,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1671,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":32}
I20260812 06:20:13.775424 29353 maintenance_manager.cc:419] P 9bea50cf131c4f10af0c0a4ae639b2e2: Scheduling LogGCOp(4737420254b24010b8f48017abbe2903): free 129773835 bytes of WAL
I20260812 06:20:13.775637 29243 log_reader.cc:385] T 4737420254b24010b8f48017abbe2903: removed 13 log segments from log reader
I20260812 06:20:13.775682 29243 log.cc:1079] T 4737420254b24010b8f48017abbe2903 P 9bea50cf131c4f10af0c0a4ae639b2e2: Deleting log segment in path: /tmp/dist-test-tasksggqpW/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515609106051-29068-0/minicluster-data/ts-0-root/wals/4737420254b24010b8f48017abbe2903/wal-000000027 (ops 129-133)
I20260812 06:20:13.775710 29243 log.cc:1079] T 4737420254b24010b8f48017abbe2903 P 9bea50cf131c4f10af0c0a4ae639b2e2: Deleting log segment in path: /tmp/dist-test-tasksggqpW/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515609106051-29068-0/minicluster-data/ts-0-root/wals/4737420254b24010b8f48017abbe2903/wal-000000028 (ops 134-138)
I20260812 06:20:13.775743 29243 log.cc:1079] T 4737420254b24010b8f48017abbe2903 P 9bea50cf131c4f10af0c0a4ae639b2e2: Deleting log segment in path: /tmp/dist-test-tasksggqpW/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515609106051-29068-0/minicluster-data/ts-0-root/wals/4737420254b24010b8f48017abbe2903/wal-000000029 (ops 139-143)
I20260812 06:20:13.775785 29243 log.cc:1079] T 4737420254b24010b8f48017abbe2903 P 9bea50cf131c4f10af0c0a4ae639b2e2: Deleting log segment in path: /tmp/dist-test-tasksggqpW/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515609106051-29068-0/minicluster-data/ts-0-root/wals/4737420254b24010b8f48017abbe2903/wal-000000030 (ops 144-148)
I20260812 06:20:13.775817 29243 log.cc:1079] T 4737420254b24010b8f48017abbe2903 P 9bea50cf131c4f10af0c0a4ae639b2e2: Deleting log segment in path: /tmp/dist-test-tasksggqpW/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515609106051-29068-0/minicluster-data/ts-0-root/wals/4737420254b24010b8f48017abbe2903/wal-000000031 (ops 149-153)
I20260812 06:20:13.775848 29243 log.cc:1079] T 4737420254b24010b8f48017abbe2903 P 9bea50cf131c4f10af0c0a4ae639b2e2: Deleting log segment in path: /tmp/dist-test-tasksggqpW/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515609106051-29068-0/minicluster-data/ts-0-root/wals/4737420254b24010b8f48017abbe2903/wal-000000032 (ops 154-158)
I20260812 06:20:13.775880 29243 log.cc:1079] T 4737420254b24010b8f48017abbe2903 P 9bea50cf131c4f10af0c0a4ae639b2e2: Deleting log segment in path: /tmp/dist-test-tasksggqpW/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515609106051-29068-0/minicluster-data/ts-0-root/wals/4737420254b24010b8f48017abbe2903/wal-000000033 (ops 159-163)
I20260812 06:20:13.775911 29243 log.cc:1079] T 4737420254b24010b8f48017abbe2903 P 9bea50cf131c4f10af0c0a4ae639b2e2: Deleting log segment in path: /tmp/dist-test-tasksggqpW/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515609106051-29068-0/minicluster-data/ts-0-root/wals/4737420254b24010b8f48017abbe2903/wal-000000034 (ops 164-168)
I20260812 06:20:13.775943 29243 log.cc:1079] T 4737420254b24010b8f48017abbe2903 P 9bea50cf131c4f10af0c0a4ae639b2e2: Deleting log segment in path: /tmp/dist-test-tasksggqpW/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515609106051-29068-0/minicluster-data/ts-0-root/wals/4737420254b24010b8f48017abbe2903/wal-000000035 (ops 169-173)
I20260812 06:20:13.775975 29243 log.cc:1079] T 4737420254b24010b8f48017abbe2903 P 9bea50cf131c4f10af0c0a4ae639b2e2: Deleting log segment in path: /tmp/dist-test-tasksggqpW/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515609106051-29068-0/minicluster-data/ts-0-root/wals/4737420254b24010b8f48017abbe2903/wal-000000036 (ops 174-178)
I20260812 06:20:13.776006 29243 log.cc:1079] T 4737420254b24010b8f48017abbe2903 P 9bea50cf131c4f10af0c0a4ae639b2e2: Deleting log segment in path: /tmp/dist-test-tasksggqpW/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515609106051-29068-0/minicluster-data/ts-0-root/wals/4737420254b24010b8f48017abbe2903/wal-000000037 (ops 179-182)
I20260812 06:20:13.776038 29243 log.cc:1079] T 4737420254b24010b8f48017abbe2903 P 9bea50cf131c4f10af0c0a4ae639b2e2: Deleting log segment in path: /tmp/dist-test-tasksggqpW/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515609106051-29068-0/minicluster-data/ts-0-root/wals/4737420254b24010b8f48017abbe2903/wal-000000038 (ops 183-187)
I20260812 06:20:13.776069 29243 log.cc:1079] T 4737420254b24010b8f48017abbe2903 P 9bea50cf131c4f10af0c0a4ae639b2e2: Deleting log segment in path: /tmp/dist-test-tasksggqpW/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515609106051-29068-0/minicluster-data/ts-0-root/wals/4737420254b24010b8f48017abbe2903/wal-000000039 (ops 188-192)
I20260812 06:20:13.799199 29243 maintenance_manager.cc:643] P 9bea50cf131c4f10af0c0a4ae639b2e2: LogGCOp(4737420254b24010b8f48017abbe2903) complete. Timing: real 0.024s	user 0.000s	sys 0.023s Metrics: {}
I20260812 06:20:13.799649 29353 maintenance_manager.cc:419] P 9bea50cf131c4f10af0c0a4ae639b2e2: Scheduling FlushDeltaMemStoresOp(4737420254b24010b8f48017abbe2903): perf score=3.181125
I20260812 06:20:13.810988 29243 maintenance_manager.cc:643] P 9bea50cf131c4f10af0c0a4ae639b2e2: FlushDeltaMemStoresOp(4737420254b24010b8f48017abbe2903) complete. Timing: real 0.011s	user 0.010s	sys 0.000s Metrics: {"bytes_written":4512899,"delete_count":0,"lbm_write_time_us":3968,"lbm_writes_lt_1ms":113,"reinsert_count":0,"update_count":550}
I20260812 06:20:13.811415 29353 maintenance_manager.cc:419] P 9bea50cf131c4f10af0c0a4ae639b2e2: Scheduling FlushDeltaMemStoresOp(4737420254b24010b8f48017abbe2903): perf score=2.188937
I20260812 06:20:13.835793 29243 maintenance_manager.cc:643] P 9bea50cf131c4f10af0c0a4ae639b2e2: FlushDeltaMemStoresOp(4737420254b24010b8f48017abbe2903) complete. Timing: real 0.024s	user 0.010s	sys 0.008s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":4646,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:20:13.836452 29353 maintenance_manager.cc:419] P 9bea50cf131c4f10af0c0a4ae639b2e2: Scheduling UndoDeltaBlockGCOp(4737420254b24010b8f48017abbe2903): 491 bytes on disk
I20260812 06:20:13.837033 29243 maintenance_manager.cc:643] P 9bea50cf131c4f10af0c0a4ae639b2e2: UndoDeltaBlockGCOp(4737420254b24010b8f48017abbe2903) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":78,"lbm_reads_lt_1ms":4}
I20260812 06:20:13.837693 29353 maintenance_manager.cc:419] P 9bea50cf131c4f10af0c0a4ae639b2e2: Scheduling MajorDeltaCompactionOp(4737420254b24010b8f48017abbe2903): perf score=1.000000
I20260812 06:20:13.914278 29068 heavy-update-compaction-itest.cc:229] Time spent updating: real 4.567s	user 1.721s	sys 0.106s
I20260812 06:20:14.011466 29068 heavy-update-compaction-itest.cc:265] Time spent scanning: real 0.097s	user 0.000s	sys 0.002s
I20260812 06:20:14.012065 29068 tablet_server.cc:179] TabletServer@127.28.99.1:0 shutting down...
I20260812 06:20:14.028571 29243 maintenance_manager.cc:643] P 9bea50cf131c4f10af0c0a4ae639b2e2: MajorDeltaCompactionOp(4737420254b24010b8f48017abbe2903) complete. Timing: real 0.191s	user 0.111s	sys 0.077s Metrics: {"cfile_cache_miss":735,"cfile_cache_miss_bytes":33020842,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":5,"delta_iterators_relevant":5,"dirs.queue_time_us":2389,"lbm_read_time_us":12928,"lbm_reads_lt_1ms":771,"lbm_write_time_us":29526,"lbm_writes_lt_1ms":743,"mutex_wait_us":44,"peak_mem_usage":87969044,"reinsert_count":0,"spinlock_wait_cycles":5632,"thread_start_us":83,"threads_started":1,"update_count":3500}
I20260812 06:20:14.029138 29068 ts_tablet_manager.cc:1507] Shutting down tablet manager...
I20260812 06:20:14.029539 29068 tablet_replica.cc:333] T 4737420254b24010b8f48017abbe2903 P 9bea50cf131c4f10af0c0a4ae639b2e2: stopping tablet replica
I20260812 06:20:14.029778 29068 raft_consensus.cc:2243] T 4737420254b24010b8f48017abbe2903 P 9bea50cf131c4f10af0c0a4ae639b2e2 [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:20:14.030555 29068 raft_consensus.cc:2272] T 4737420254b24010b8f48017abbe2903 P 9bea50cf131c4f10af0c0a4ae639b2e2 [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:20:14.047535 29068 tablet_server.cc:196] TabletServer@127.28.99.1:0 shutdown complete.
I20260812 06:20:14.085368 29068 master.cc:562] Master@127.28.99.62:34973 shutting down...
I20260812 06:20:14.088958 29068 raft_consensus.cc:2243] T 00000000000000000000000000000000 P 337499c1138c491080a6cb45765f87d6 [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:20:14.089148 29068 raft_consensus.cc:2272] T 00000000000000000000000000000000 P 337499c1138c491080a6cb45765f87d6 [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:20:14.089210 29068 tablet_replica.cc:333] T 00000000000000000000000000000000 P 337499c1138c491080a6cb45765f87d6: stopping tablet replica
I20260812 06:20:14.101377 29068 master.cc:584] Master@127.28.99.62:34973 shutdown complete.
[       OK ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/0 (5058 ms)
[ RUN      ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/1
I20260812 06:20:14.187283 29068 internal_mini_cluster.cc:156] Creating distributed mini masters. Addrs: 127.28.99.62:35255
I20260812 06:20:14.187683 29068 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:20:14.189628 29416 instance_detector.cc:116] could not retrieve Azure instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:20:14.189746 29068 server_base.cc:1061] running on GCE node
W20260812 06:20:14.189838 29415 instance_detector.cc:116] could not retrieve AWS instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:20:14.189936 29418 instance_detector.cc:116] could not retrieve OpenStack instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:20:14.190132 29068 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:20:14.190186 29068 system_unsync_time.cc:38] NTP support is disabled. Clock error bounds will not be accurate. This configuration is not suitable for distributed clusters.
I20260812 06:20:14.190209 29068 hybrid_clock.cc:648] HybridClock initialized: now 1786515614190209 us; error 0 us; skew 500 ppm
I20260812 06:20:14.191310 29068 webserver.cc:533] Webserver started at http://127.28.99.62:42333/ using document root <none> and password file <none>
I20260812 06:20:14.191488 29068 fs_manager.cc:362] Metadata directory not provided
I20260812 06:20:14.191551 29068 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:20:14.191619 29068 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:20:14.191992 29068 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-tasksggqpW/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515609106051-29068-0/minicluster-data/master-0-root/instance:
uuid: "633885fd4be94291b9c4f5cad8a933d0"
format_stamp: "Formatted at 2026-08-12 06:20:14 on dist-test-slave-fgb3"
I20260812 06:20:14.193521 29068 fs_manager.cc:696] Time spent creating directory manager: real 0.001s	user 0.002s	sys 0.000s
I20260812 06:20:14.194422 29427 log_block_manager.cc:4127] Time spent loading block containers with low live blocks: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:20:14.194648 29068 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.001s	sys 0.000s
I20260812 06:20:14.194722 29068 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-tasksggqpW/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515609106051-29068-0/minicluster-data/master-0-root
uuid: "633885fd4be94291b9c4f5cad8a933d0"
format_stamp: "Formatted at 2026-08-12 06:20:14 on dist-test-slave-fgb3"
I20260812 06:20:14.194798 29068 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-tasksggqpW/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515609106051-29068-0/minicluster-data/master-0-root
metadata directory: /tmp/dist-test-tasksggqpW/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515609106051-29068-0/minicluster-data/master-0-root
1 data directories: /tmp/dist-test-tasksggqpW/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515609106051-29068-0/minicluster-data/master-0-root/data
Total live blocks: 0
Total live bytes: 0
Total live bytes (after alignment): 0
Total number of LBM containers: 0 (0 full)
Did not check for missing blocks
Did not check for orphaned blocks
Total full LBM containers with extra space: 0 (0 repaired)
Total full LBM container extra space in bytes: 0 (0 repaired)
Total incomplete LBM containers: 0 (0 repaired)
Total LBM partial records: 0 (0 repaired)
Total corrupted LBM metadata records in RocksDB: 0 (0 repaired)
I20260812 06:20:14.201646 29068 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:20:14.202000 29068 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:20:14.206336 29068 rpc_server.cc:307] RPC server started. Bound to: 127.28.99.62:35255
I20260812 06:20:14.211894 29516 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.28.99.62:35255 every 8 connection(s)
I20260812 06:20:14.212414 29518 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet 00000000000000000000000000000000. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:20:14.214376 29518 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P 633885fd4be94291b9c4f5cad8a933d0: Bootstrap starting.
I20260812 06:20:14.215233 29518 tablet_bootstrap.cc:654] T 00000000000000000000000000000000 P 633885fd4be94291b9c4f5cad8a933d0: Neither blocks nor log segments found. Creating new log.
I20260812 06:20:14.216318 29518 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P 633885fd4be94291b9c4f5cad8a933d0: No bootstrap required, opened a new log
I20260812 06:20:14.216729 29518 raft_consensus.cc:359] T 00000000000000000000000000000000 P 633885fd4be94291b9c4f5cad8a933d0 [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "633885fd4be94291b9c4f5cad8a933d0" member_type: VOTER }
I20260812 06:20:14.216828 29518 raft_consensus.cc:385] T 00000000000000000000000000000000 P 633885fd4be94291b9c4f5cad8a933d0 [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:20:14.216866 29518 raft_consensus.cc:740] T 00000000000000000000000000000000 P 633885fd4be94291b9c4f5cad8a933d0 [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: 633885fd4be94291b9c4f5cad8a933d0, State: Initialized, Role: FOLLOWER
I20260812 06:20:14.217012 29518 consensus_queue.cc:260] T 00000000000000000000000000000000 P 633885fd4be94291b9c4f5cad8a933d0 [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: "633885fd4be94291b9c4f5cad8a933d0" member_type: VOTER }
I20260812 06:20:14.217093 29518 raft_consensus.cc:399] T 00000000000000000000000000000000 P 633885fd4be94291b9c4f5cad8a933d0 [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:20:14.217139 29518 raft_consensus.cc:493] T 00000000000000000000000000000000 P 633885fd4be94291b9c4f5cad8a933d0 [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:20:14.217195 29518 raft_consensus.cc:3060] T 00000000000000000000000000000000 P 633885fd4be94291b9c4f5cad8a933d0 [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:20:14.217890 29518 raft_consensus.cc:515] T 00000000000000000000000000000000 P 633885fd4be94291b9c4f5cad8a933d0 [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "633885fd4be94291b9c4f5cad8a933d0" member_type: VOTER }
I20260812 06:20:14.218472 29518 leader_election.cc:304] T 00000000000000000000000000000000 P 633885fd4be94291b9c4f5cad8a933d0 [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: 633885fd4be94291b9c4f5cad8a933d0; no voters: 
I20260812 06:20:14.218681 29518 leader_election.cc:290] T 00000000000000000000000000000000 P 633885fd4be94291b9c4f5cad8a933d0 [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:20:14.218837 29525 raft_consensus.cc:2804] T 00000000000000000000000000000000 P 633885fd4be94291b9c4f5cad8a933d0 [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:20:14.219028 29525 raft_consensus.cc:697] T 00000000000000000000000000000000 P 633885fd4be94291b9c4f5cad8a933d0 [term 1 LEADER]: Becoming Leader. State: Replica: 633885fd4be94291b9c4f5cad8a933d0, State: Running, Role: LEADER
I20260812 06:20:14.219128 29518 sys_catalog.cc:565] T 00000000000000000000000000000000 P 633885fd4be94291b9c4f5cad8a933d0 [sys.catalog]: configured and running, proceeding with master startup.
I20260812 06:20:14.219172 29525 consensus_queue.cc:237] T 00000000000000000000000000000000 P 633885fd4be94291b9c4f5cad8a933d0 [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: "633885fd4be94291b9c4f5cad8a933d0" member_type: VOTER }
I20260812 06:20:14.219645 29526 sys_catalog.cc:455] T 00000000000000000000000000000000 P 633885fd4be94291b9c4f5cad8a933d0 [sys.catalog]: SysCatalogTable state changed. Reason: RaftConsensus started. Latest consensus state: current_term: 1 leader_uuid: "633885fd4be94291b9c4f5cad8a933d0" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "633885fd4be94291b9c4f5cad8a933d0" member_type: VOTER } }
I20260812 06:20:14.219682 29529 sys_catalog.cc:455] T 00000000000000000000000000000000 P 633885fd4be94291b9c4f5cad8a933d0 [sys.catalog]: SysCatalogTable state changed. Reason: New leader 633885fd4be94291b9c4f5cad8a933d0. Latest consensus state: current_term: 1 leader_uuid: "633885fd4be94291b9c4f5cad8a933d0" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "633885fd4be94291b9c4f5cad8a933d0" member_type: VOTER } }
I20260812 06:20:14.219817 29529 sys_catalog.cc:458] T 00000000000000000000000000000000 P 633885fd4be94291b9c4f5cad8a933d0 [sys.catalog]: This master's current role is: LEADER
I20260812 06:20:14.220077 29537 catalog_manager.cc:1511] Loading table and tablet metadata into memory...
I20260812 06:20:14.220314 29526 sys_catalog.cc:458] T 00000000000000000000000000000000 P 633885fd4be94291b9c4f5cad8a933d0 [sys.catalog]: This master's current role is: LEADER
I20260812 06:20:14.220957 29537 catalog_manager.cc:1520] Initializing Kudu cluster ID...
I20260812 06:20:14.221184 29068 internal_mini_cluster.cc:184] Waiting to initialize catalog manager on master 0
I20260812 06:20:14.222754 29537 catalog_manager.cc:1383] Generated new cluster ID: 4b287a6831084b2a94e32ec6f9e704c3
I20260812 06:20:14.222802 29537 catalog_manager.cc:1531] Initializing Kudu internal certificate authority...
I20260812 06:20:14.227737 29537 catalog_manager.cc:1406] Generated new certificate authority record
I20260812 06:20:14.228235 29537 catalog_manager.cc:1540] Loading token signing keys...
I20260812 06:20:14.234243 29537 catalog_manager.cc:6092] T 00000000000000000000000000000000 P 633885fd4be94291b9c4f5cad8a933d0: Generated new TSK 0
I20260812 06:20:14.234421 29537 catalog_manager.cc:1550] Initializing in-progress tserver states...
I20260812 06:20:14.237206 29068 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:20:14.238997 29558 instance_detector.cc:116] could not retrieve AWS instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:20:14.239115 29068 server_base.cc:1061] running on GCE node
W20260812 06:20:14.239130 29564 instance_detector.cc:116] could not retrieve OpenStack instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:20:14.239287 29561 instance_detector.cc:116] could not retrieve Azure instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:20:14.239496 29068 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:20:14.239540 29068 system_unsync_time.cc:38] NTP support is disabled. Clock error bounds will not be accurate. This configuration is not suitable for distributed clusters.
I20260812 06:20:14.239576 29068 hybrid_clock.cc:648] HybridClock initialized: now 1786515614239576 us; error 0 us; skew 500 ppm
I20260812 06:20:14.240306 29068 webserver.cc:533] Webserver started at http://127.28.99.1:43999/ using document root <none> and password file <none>
I20260812 06:20:14.240460 29068 fs_manager.cc:362] Metadata directory not provided
I20260812 06:20:14.240510 29068 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:20:14.240581 29068 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:20:14.240934 29068 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-tasksggqpW/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515609106051-29068-0/minicluster-data/ts-0-root/instance:
uuid: "3ba6fa63bba94351bf8c522fd5eafa1d"
format_stamp: "Formatted at 2026-08-12 06:20:14 on dist-test-slave-fgb3"
I20260812 06:20:14.242304 29068 fs_manager.cc:696] Time spent creating directory manager: real 0.001s	user 0.002s	sys 0.000s
I20260812 06:20:14.243176 29572 log_block_manager.cc:4127] Time spent loading block containers with low live blocks: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:20:14.243391 29068 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.001s	sys 0.000s
I20260812 06:20:14.243450 29068 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-tasksggqpW/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515609106051-29068-0/minicluster-data/ts-0-root
uuid: "3ba6fa63bba94351bf8c522fd5eafa1d"
format_stamp: "Formatted at 2026-08-12 06:20:14 on dist-test-slave-fgb3"
I20260812 06:20:14.243515 29068 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-tasksggqpW/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515609106051-29068-0/minicluster-data/ts-0-root
metadata directory: /tmp/dist-test-tasksggqpW/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515609106051-29068-0/minicluster-data/ts-0-root
1 data directories: /tmp/dist-test-tasksggqpW/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515609106051-29068-0/minicluster-data/ts-0-root/data
Total live blocks: 0
Total live bytes: 0
Total live bytes (after alignment): 0
Total number of LBM containers: 0 (0 full)
Did not check for missing blocks
Did not check for orphaned blocks
Total full LBM containers with extra space: 0 (0 repaired)
Total full LBM container extra space in bytes: 0 (0 repaired)
Total incomplete LBM containers: 0 (0 repaired)
Total LBM partial records: 0 (0 repaired)
Total corrupted LBM metadata records in RocksDB: 0 (0 repaired)
I20260812 06:20:14.255609 29068 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:20:14.256049 29068 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:20:14.256356 29068 txn_system_client.cc:432] TxnSystemClient initialization is disabled...
I20260812 06:20:14.256815 29068 ts_tablet_manager.cc:585] Loaded tablet metadata (0 total tablets, 0 live tablets)
I20260812 06:20:14.256855 29068 ts_tablet_manager.cc:531] Time spent load tablet metadata: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:20:14.256899 29068 ts_tablet_manager.cc:616] Registered 0 tablets
I20260812 06:20:14.256928 29068 ts_tablet_manager.cc:595] Time spent register tablets: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:20:14.260931 29068 rpc_server.cc:307] RPC server started. Bound to: 127.28.99.1:46009
I20260812 06:20:14.260987 29675 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.28.99.1:46009 every 8 connection(s)
I20260812 06:20:14.269531 29676 heartbeater.cc:344] Connected to a master server at 127.28.99.62:35255
I20260812 06:20:14.269652 29676 heartbeater.cc:461] Registering TS with master...
I20260812 06:20:14.269901 29676 heartbeater.cc:507] Master 127.28.99.62:35255 requested a full tablet report, sending...
I20260812 06:20:14.270572 29457 ts_manager.cc:194] Registered new tserver with Master: 3ba6fa63bba94351bf8c522fd5eafa1d (127.28.99.1:46009)
I20260812 06:20:14.271157 29068 internal_mini_cluster.cc:371] 1 TS(s) registered with all masters after 0.009825178s
I20260812 06:20:14.271333 29457 master_service.cc:502] Signed X509 certificate for tserver {username='slave'} at 127.0.0.1:56406
I20260812 06:20:14.277549 29457 catalog_manager.cc:2283] Servicing CreateTable request from {username='slave'} at 127.0.0.1:56412:
name: "heavy-update-compaction-test"
schema {
  columns {
    name: "key"
    type: INT64
    is_key: true
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_a"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_b"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_c"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_d"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_e"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
}
num_replicas: 1
split_rows_range_bounds {
}
partition_schema {
  range_schema {
  }
}
I20260812 06:20:14.285482 29618 tablet_service.cc:1511] Processing CreateTablet for tablet f57255de3d8e425bbdf9e88a906b4a49 (DEFAULT_TABLE table=heavy-update-compaction-test [id=4a23fe97035c44009b45854dc15f39bd]), partition=
I20260812 06:20:14.285729 29618 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet f57255de3d8e425bbdf9e88a906b4a49. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:20:14.287612 29702 tablet_bootstrap.cc:492] T f57255de3d8e425bbdf9e88a906b4a49 P 3ba6fa63bba94351bf8c522fd5eafa1d: Bootstrap starting.
I20260812 06:20:14.288491 29702 tablet_bootstrap.cc:654] T f57255de3d8e425bbdf9e88a906b4a49 P 3ba6fa63bba94351bf8c522fd5eafa1d: Neither blocks nor log segments found. Creating new log.
I20260812 06:20:14.289427 29702 tablet_bootstrap.cc:492] T f57255de3d8e425bbdf9e88a906b4a49 P 3ba6fa63bba94351bf8c522fd5eafa1d: No bootstrap required, opened a new log
I20260812 06:20:14.289506 29702 ts_tablet_manager.cc:1403] T f57255de3d8e425bbdf9e88a906b4a49 P 3ba6fa63bba94351bf8c522fd5eafa1d: Time spent bootstrapping tablet: real 0.002s	user 0.001s	sys 0.000s
I20260812 06:20:14.289887 29702 raft_consensus.cc:359] T f57255de3d8e425bbdf9e88a906b4a49 P 3ba6fa63bba94351bf8c522fd5eafa1d [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "3ba6fa63bba94351bf8c522fd5eafa1d" member_type: VOTER last_known_addr { host: "127.28.99.1" port: 46009 } }
I20260812 06:20:14.289979 29702 raft_consensus.cc:385] T f57255de3d8e425bbdf9e88a906b4a49 P 3ba6fa63bba94351bf8c522fd5eafa1d [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:20:14.290009 29702 raft_consensus.cc:740] T f57255de3d8e425bbdf9e88a906b4a49 P 3ba6fa63bba94351bf8c522fd5eafa1d [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: 3ba6fa63bba94351bf8c522fd5eafa1d, State: Initialized, Role: FOLLOWER
I20260812 06:20:14.290128 29702 consensus_queue.cc:260] T f57255de3d8e425bbdf9e88a906b4a49 P 3ba6fa63bba94351bf8c522fd5eafa1d [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: "3ba6fa63bba94351bf8c522fd5eafa1d" member_type: VOTER last_known_addr { host: "127.28.99.1" port: 46009 } }
I20260812 06:20:14.290196 29702 raft_consensus.cc:399] T f57255de3d8e425bbdf9e88a906b4a49 P 3ba6fa63bba94351bf8c522fd5eafa1d [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:20:14.290233 29702 raft_consensus.cc:493] T f57255de3d8e425bbdf9e88a906b4a49 P 3ba6fa63bba94351bf8c522fd5eafa1d [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:20:14.290280 29702 raft_consensus.cc:3060] T f57255de3d8e425bbdf9e88a906b4a49 P 3ba6fa63bba94351bf8c522fd5eafa1d [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:20:14.291169 29702 raft_consensus.cc:515] T f57255de3d8e425bbdf9e88a906b4a49 P 3ba6fa63bba94351bf8c522fd5eafa1d [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "3ba6fa63bba94351bf8c522fd5eafa1d" member_type: VOTER last_known_addr { host: "127.28.99.1" port: 46009 } }
I20260812 06:20:14.291309 29702 leader_election.cc:304] T f57255de3d8e425bbdf9e88a906b4a49 P 3ba6fa63bba94351bf8c522fd5eafa1d [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: 3ba6fa63bba94351bf8c522fd5eafa1d; no voters: 
I20260812 06:20:14.291469 29702 leader_election.cc:290] T f57255de3d8e425bbdf9e88a906b4a49 P 3ba6fa63bba94351bf8c522fd5eafa1d [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:20:14.291580 29704 raft_consensus.cc:2804] T f57255de3d8e425bbdf9e88a906b4a49 P 3ba6fa63bba94351bf8c522fd5eafa1d [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:20:14.291730 29702 ts_tablet_manager.cc:1434] T f57255de3d8e425bbdf9e88a906b4a49 P 3ba6fa63bba94351bf8c522fd5eafa1d: Time spent starting tablet: real 0.002s	user 0.000s	sys 0.002s
I20260812 06:20:14.291779 29676 heartbeater.cc:499] Master 127.28.99.62:35255 was elected leader, sending a full tablet report...
I20260812 06:20:14.291779 29704 raft_consensus.cc:697] T f57255de3d8e425bbdf9e88a906b4a49 P 3ba6fa63bba94351bf8c522fd5eafa1d [term 1 LEADER]: Becoming Leader. State: Replica: 3ba6fa63bba94351bf8c522fd5eafa1d, State: Running, Role: LEADER
I20260812 06:20:14.291934 29704 consensus_queue.cc:237] T f57255de3d8e425bbdf9e88a906b4a49 P 3ba6fa63bba94351bf8c522fd5eafa1d [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: "3ba6fa63bba94351bf8c522fd5eafa1d" member_type: VOTER last_known_addr { host: "127.28.99.1" port: 46009 } }
I20260812 06:20:14.293115 29457 catalog_manager.cc:5719] T f57255de3d8e425bbdf9e88a906b4a49 P 3ba6fa63bba94351bf8c522fd5eafa1d reported cstate change: term changed from 0 to 1, leader changed from <none> to 3ba6fa63bba94351bf8c522fd5eafa1d (127.28.99.1). New cstate: current_term: 1 leader_uuid: "3ba6fa63bba94351bf8c522fd5eafa1d" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "3ba6fa63bba94351bf8c522fd5eafa1d" member_type: VOTER last_known_addr { host: "127.28.99.1" port: 46009 } health_report { overall_health: HEALTHY } } }
I20260812 06:20:14.346823 29068 heavy-update-compaction-itest.cc:215] Time spent inserting: real 0.050s	user 0.012s	sys 0.010s
I20260812 06:20:14.511837 29679 maintenance_manager.cc:419] P 3ba6fa63bba94351bf8c522fd5eafa1d: Scheduling FlushMRSOp(f57255de3d8e425bbdf9e88a906b4a49): perf score=23.023690
I20260812 06:20:14.660156 29580 maintenance_manager.cc:643] P 3ba6fa63bba94351bf8c522fd5eafa1d: FlushMRSOp(f57255de3d8e425bbdf9e88a906b4a49) complete. Timing: real 0.148s	user 0.090s	sys 0.056s Metrics: {"bytes_written":12307489,"cfile_init":1,"delete_count":0,"dirs.queue_time_us":78,"dirs.run_cpu_time_us":276,"dirs.run_wall_time_us":843,"drs_written":1,"lbm_read_time_us":35,"lbm_reads_lt_1ms":4,"lbm_write_time_us":38796,"lbm_writes_lt_1ms":857,"peak_mem_usage":0,"reinsert_count":0,"rows_written":105,"update_count":1500}
I20260812 06:20:14.660765 29679 maintenance_manager.cc:419] P 3ba6fa63bba94351bf8c522fd5eafa1d: Scheduling LogGCOp(f57255de3d8e425bbdf9e88a906b4a49): free 20290830 bytes of WAL
I20260812 06:20:14.661000 29580 log_reader.cc:385] T f57255de3d8e425bbdf9e88a906b4a49: removed 2 log segments from log reader
I20260812 06:20:14.661051 29580 log.cc:1079] T f57255de3d8e425bbdf9e88a906b4a49 P 3ba6fa63bba94351bf8c522fd5eafa1d: Deleting log segment in path: /tmp/dist-test-tasksggqpW/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515609106051-29068-0/minicluster-data/ts-0-root/wals/f57255de3d8e425bbdf9e88a906b4a49/wal-000000001 (ops 1-6)
I20260812 06:20:14.661078 29580 log.cc:1079] T f57255de3d8e425bbdf9e88a906b4a49 P 3ba6fa63bba94351bf8c522fd5eafa1d: Deleting log segment in path: /tmp/dist-test-tasksggqpW/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515609106051-29068-0/minicluster-data/ts-0-root/wals/f57255de3d8e425bbdf9e88a906b4a49/wal-000000002 (ops 7-10)
I20260812 06:20:14.664476 29580 maintenance_manager.cc:643] P 3ba6fa63bba94351bf8c522fd5eafa1d: LogGCOp(f57255de3d8e425bbdf9e88a906b4a49) complete. Timing: real 0.004s	user 0.000s	sys 0.001s Metrics: {}
I20260812 06:20:14.664775 29679 maintenance_manager.cc:419] P 3ba6fa63bba94351bf8c522fd5eafa1d: Scheduling UndoDeltaBlockGCOp(f57255de3d8e425bbdf9e88a906b4a49): 20513812 bytes on disk
I20260812 06:20:14.665148 29580 maintenance_manager.cc:643] P 3ba6fa63bba94351bf8c522fd5eafa1d: UndoDeltaBlockGCOp(f57255de3d8e425bbdf9e88a906b4a49) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":53,"lbm_reads_lt_1ms":4}
I20260812 06:20:14.665500 29679 maintenance_manager.cc:419] P 3ba6fa63bba94351bf8c522fd5eafa1d: Scheduling FlushDeltaMemStoresOp(f57255de3d8e425bbdf9e88a906b4a49): perf score=2.188937
I20260812 06:20:14.677174 29580 maintenance_manager.cc:643] P 3ba6fa63bba94351bf8c522fd5eafa1d: FlushDeltaMemStoresOp(f57255de3d8e425bbdf9e88a906b4a49) complete. Timing: real 0.012s	user 0.007s	sys 0.003s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4512,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:14.677675 29679 maintenance_manager.cc:419] P 3ba6fa63bba94351bf8c522fd5eafa1d: Scheduling MajorDeltaCompactionOp(f57255de3d8e425bbdf9e88a906b4a49): perf score=1.000000
I20260812 06:20:14.811136 29580 maintenance_manager.cc:643] P 3ba6fa63bba94351bf8c522fd5eafa1d: MajorDeltaCompactionOp(f57255de3d8e425bbdf9e88a906b4a49) complete. Timing: real 0.133s	user 0.090s	sys 0.043s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20713271,"cfile_init":7,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":530,"lbm_read_time_us":10050,"lbm_reads_lt_1ms":460,"lbm_write_time_us":21834,"lbm_writes_lt_1ms":443,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":71680,"thread_start_us":283,"threads_started":5,"update_count":2000}
I20260812 06:20:14.811735 29679 maintenance_manager.cc:419] P 3ba6fa63bba94351bf8c522fd5eafa1d: Scheduling FlushDeltaMemStoresOp(f57255de3d8e425bbdf9e88a906b4a49): perf score=10.126437
I20260812 06:20:14.852185 29580 maintenance_manager.cc:643] P 3ba6fa63bba94351bf8c522fd5eafa1d: FlushDeltaMemStoresOp(f57255de3d8e425bbdf9e88a906b4a49) complete. Timing: real 0.040s	user 0.012s	sys 0.026s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":13853,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:20:14.852696 29679 maintenance_manager.cc:419] P 3ba6fa63bba94351bf8c522fd5eafa1d: Scheduling FlushDeltaMemStoresOp(f57255de3d8e425bbdf9e88a906b4a49): perf score=2.188937
I20260812 06:20:14.867435 29580 maintenance_manager.cc:643] P 3ba6fa63bba94351bf8c522fd5eafa1d: FlushDeltaMemStoresOp(f57255de3d8e425bbdf9e88a906b4a49) complete. Timing: real 0.015s	user 0.013s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5635,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:14.867851 29679 maintenance_manager.cc:419] P 3ba6fa63bba94351bf8c522fd5eafa1d: Scheduling MajorDeltaCompactionOp(f57255de3d8e425bbdf9e88a906b4a49): perf score=1.000000
I20260812 06:20:15.002869 29580 maintenance_manager.cc:643] P 3ba6fa63bba94351bf8c522fd5eafa1d: MajorDeltaCompactionOp(f57255de3d8e425bbdf9e88a906b4a49) complete. Timing: real 0.135s	user 0.099s	sys 0.036s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20713272,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":904,"lbm_read_time_us":11323,"lbm_reads_lt_1ms":472,"lbm_write_time_us":20962,"lbm_writes_lt_1ms":443,"mutex_wait_us":300,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":11392,"update_count":2000}
I20260812 06:20:15.003444 29679 maintenance_manager.cc:419] P 3ba6fa63bba94351bf8c522fd5eafa1d: Scheduling FlushDeltaMemStoresOp(f57255de3d8e425bbdf9e88a906b4a49): perf score=10.126437
I20260812 06:20:15.034821 29580 maintenance_manager.cc:643] P 3ba6fa63bba94351bf8c522fd5eafa1d: FlushDeltaMemStoresOp(f57255de3d8e425bbdf9e88a906b4a49) complete. Timing: real 0.031s	user 0.027s	sys 0.004s Metrics: {"bytes_written":12307491,"delete_count":0,"lbm_write_time_us":14205,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:20:15.035290 29679 maintenance_manager.cc:419] P 3ba6fa63bba94351bf8c522fd5eafa1d: Scheduling FlushDeltaMemStoresOp(f57255de3d8e425bbdf9e88a906b4a49): perf score=2.188937
I20260812 06:20:15.048549 29580 maintenance_manager.cc:643] P 3ba6fa63bba94351bf8c522fd5eafa1d: FlushDeltaMemStoresOp(f57255de3d8e425bbdf9e88a906b4a49) complete. Timing: real 0.013s	user 0.010s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4691,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:15.049000 29679 maintenance_manager.cc:419] P 3ba6fa63bba94351bf8c522fd5eafa1d: Scheduling MajorDeltaCompactionOp(f57255de3d8e425bbdf9e88a906b4a49): perf score=1.000000
I20260812 06:20:15.174250 29580 maintenance_manager.cc:643] P 3ba6fa63bba94351bf8c522fd5eafa1d: MajorDeltaCompactionOp(f57255de3d8e425bbdf9e88a906b4a49) complete. Timing: real 0.125s	user 0.089s	sys 0.036s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20713273,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":117,"lbm_read_time_us":9947,"lbm_reads_lt_1ms":472,"lbm_write_time_us":25020,"lbm_writes_lt_1ms":443,"mutex_wait_us":27,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":8320,"update_count":2000}
I20260812 06:20:15.174954 29679 maintenance_manager.cc:419] P 3ba6fa63bba94351bf8c522fd5eafa1d: Scheduling FlushDeltaMemStoresOp(f57255de3d8e425bbdf9e88a906b4a49): perf score=10.126437
I20260812 06:20:15.205739 29580 maintenance_manager.cc:643] P 3ba6fa63bba94351bf8c522fd5eafa1d: FlushDeltaMemStoresOp(f57255de3d8e425bbdf9e88a906b4a49) complete. Timing: real 0.031s	user 0.017s	sys 0.011s Metrics: {"bytes_written":12307493,"delete_count":0,"lbm_write_time_us":13544,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:20:15.206137 29679 maintenance_manager.cc:419] P 3ba6fa63bba94351bf8c522fd5eafa1d: Scheduling FlushDeltaMemStoresOp(f57255de3d8e425bbdf9e88a906b4a49): perf score=2.188937
I20260812 06:20:15.218292 29580 maintenance_manager.cc:643] P 3ba6fa63bba94351bf8c522fd5eafa1d: FlushDeltaMemStoresOp(f57255de3d8e425bbdf9e88a906b4a49) complete. Timing: real 0.012s	user 0.007s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4439,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:15.218724 29679 maintenance_manager.cc:419] P 3ba6fa63bba94351bf8c522fd5eafa1d: Scheduling MajorDeltaCompactionOp(f57255de3d8e425bbdf9e88a906b4a49): perf score=1.000000
I20260812 06:20:15.337812 29580 maintenance_manager.cc:643] P 3ba6fa63bba94351bf8c522fd5eafa1d: MajorDeltaCompactionOp(f57255de3d8e425bbdf9e88a906b4a49) complete. Timing: real 0.119s	user 0.104s	sys 0.015s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20713275,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":99,"lbm_read_time_us":9337,"lbm_reads_lt_1ms":472,"lbm_write_time_us":22445,"lbm_writes_lt_1ms":443,"mutex_wait_us":43,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":6784,"update_count":2000}
I20260812 06:20:15.338558 29679 maintenance_manager.cc:419] P 3ba6fa63bba94351bf8c522fd5eafa1d: Scheduling FlushDeltaMemStoresOp(f57255de3d8e425bbdf9e88a906b4a49): perf score=10.126437
I20260812 06:20:15.373306 29580 maintenance_manager.cc:643] P 3ba6fa63bba94351bf8c522fd5eafa1d: FlushDeltaMemStoresOp(f57255de3d8e425bbdf9e88a906b4a49) complete. Timing: real 0.035s	user 0.016s	sys 0.012s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":13806,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:20:15.373731 29679 maintenance_manager.cc:419] P 3ba6fa63bba94351bf8c522fd5eafa1d: Scheduling FlushDeltaMemStoresOp(f57255de3d8e425bbdf9e88a906b4a49): perf score=2.188937
I20260812 06:20:15.383466 29580 maintenance_manager.cc:643] P 3ba6fa63bba94351bf8c522fd5eafa1d: FlushDeltaMemStoresOp(f57255de3d8e425bbdf9e88a906b4a49) complete. Timing: real 0.010s	user 0.008s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3667,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:15.384087 29679 maintenance_manager.cc:419] P 3ba6fa63bba94351bf8c522fd5eafa1d: Scheduling MajorDeltaCompactionOp(f57255de3d8e425bbdf9e88a906b4a49): perf score=1.000000
I20260812 06:20:15.504554 29580 maintenance_manager.cc:643] P 3ba6fa63bba94351bf8c522fd5eafa1d: MajorDeltaCompactionOp(f57255de3d8e425bbdf9e88a906b4a49) complete. Timing: real 0.120s	user 0.096s	sys 0.024s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20713272,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":137,"lbm_read_time_us":9826,"lbm_reads_lt_1ms":472,"lbm_write_time_us":22858,"lbm_writes_lt_1ms":443,"mutex_wait_us":48,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":17024,"update_count":2000}
I20260812 06:20:15.505043 29679 maintenance_manager.cc:419] P 3ba6fa63bba94351bf8c522fd5eafa1d: Scheduling FlushDeltaMemStoresOp(f57255de3d8e425bbdf9e88a906b4a49): perf score=10.126437
I20260812 06:20:15.555383 29580 maintenance_manager.cc:643] P 3ba6fa63bba94351bf8c522fd5eafa1d: FlushDeltaMemStoresOp(f57255de3d8e425bbdf9e88a906b4a49) complete. Timing: real 0.050s	user 0.029s	sys 0.020s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":17795,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:20:15.555882 29679 maintenance_manager.cc:419] P 3ba6fa63bba94351bf8c522fd5eafa1d: Scheduling FlushDeltaMemStoresOp(f57255de3d8e425bbdf9e88a906b4a49): perf score=2.188937
I20260812 06:20:15.570690 29580 maintenance_manager.cc:643] P 3ba6fa63bba94351bf8c522fd5eafa1d: FlushDeltaMemStoresOp(f57255de3d8e425bbdf9e88a906b4a49) complete. Timing: real 0.015s	user 0.014s	sys 0.000s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":5619,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:15.571115 29679 maintenance_manager.cc:419] P 3ba6fa63bba94351bf8c522fd5eafa1d: Scheduling MajorDeltaCompactionOp(f57255de3d8e425bbdf9e88a906b4a49): perf score=1.000000
I20260812 06:20:15.711215 29580 maintenance_manager.cc:643] P 3ba6fa63bba94351bf8c522fd5eafa1d: MajorDeltaCompactionOp(f57255de3d8e425bbdf9e88a906b4a49) complete. Timing: real 0.140s	user 0.091s	sys 0.048s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20713271,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":544,"lbm_read_time_us":11674,"lbm_reads_lt_1ms":472,"lbm_write_time_us":22206,"lbm_writes_lt_1ms":443,"mutex_wait_us":46,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":13952,"update_count":2000}
I20260812 06:20:15.711835 29679 maintenance_manager.cc:419] P 3ba6fa63bba94351bf8c522fd5eafa1d: Scheduling FlushDeltaMemStoresOp(f57255de3d8e425bbdf9e88a906b4a49): perf score=10.126437
I20260812 06:20:15.750209 29580 maintenance_manager.cc:643] P 3ba6fa63bba94351bf8c522fd5eafa1d: FlushDeltaMemStoresOp(f57255de3d8e425bbdf9e88a906b4a49) complete. Timing: real 0.038s	user 0.020s	sys 0.011s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":14752,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:20:15.750674 29679 maintenance_manager.cc:419] P 3ba6fa63bba94351bf8c522fd5eafa1d: Scheduling FlushDeltaMemStoresOp(f57255de3d8e425bbdf9e88a906b4a49): perf score=2.188937
I20260812 06:20:15.765924 29580 maintenance_manager.cc:643] P 3ba6fa63bba94351bf8c522fd5eafa1d: FlushDeltaMemStoresOp(f57255de3d8e425bbdf9e88a906b4a49) complete. Timing: real 0.015s	user 0.009s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5871,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:15.766712 29679 maintenance_manager.cc:419] P 3ba6fa63bba94351bf8c522fd5eafa1d: Scheduling FlushMRSOp(f57255de3d8e425bbdf9e88a906b4a49): perf score=1.000000
I20260812 06:20:15.791539 29580 maintenance_manager.cc:643] P 3ba6fa63bba94351bf8c522fd5eafa1d: FlushMRSOp(f57255de3d8e425bbdf9e88a906b4a49) complete. Timing: real 0.025s	user 0.018s	sys 0.005s Metrics: {"bytes_written":1152508,"cfile_init":1,"dirs.queue_time_us":75,"dirs.run_cpu_time_us":254,"dirs.run_wall_time_us":1364,"drs_written":1,"lbm_read_time_us":37,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1417,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":28}
I20260812 06:20:15.792213 29679 maintenance_manager.cc:419] P 3ba6fa63bba94351bf8c522fd5eafa1d: Scheduling LogGCOp(f57255de3d8e425bbdf9e88a906b4a49): free 121006422 bytes of WAL
I20260812 06:20:15.792452 29580 log_reader.cc:385] T f57255de3d8e425bbdf9e88a906b4a49: removed 12 log segments from log reader
I20260812 06:20:15.792513 29580 log.cc:1079] T f57255de3d8e425bbdf9e88a906b4a49 P 3ba6fa63bba94351bf8c522fd5eafa1d: Deleting log segment in path: /tmp/dist-test-tasksggqpW/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515609106051-29068-0/minicluster-data/ts-0-root/wals/f57255de3d8e425bbdf9e88a906b4a49/wal-000000003 (ops 11-15)
I20260812 06:20:15.792551 29580 log.cc:1079] T f57255de3d8e425bbdf9e88a906b4a49 P 3ba6fa63bba94351bf8c522fd5eafa1d: Deleting log segment in path: /tmp/dist-test-tasksggqpW/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515609106051-29068-0/minicluster-data/ts-0-root/wals/f57255de3d8e425bbdf9e88a906b4a49/wal-000000004 (ops 16-20)
I20260812 06:20:15.792584 29580 log.cc:1079] T f57255de3d8e425bbdf9e88a906b4a49 P 3ba6fa63bba94351bf8c522fd5eafa1d: Deleting log segment in path: /tmp/dist-test-tasksggqpW/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515609106051-29068-0/minicluster-data/ts-0-root/wals/f57255de3d8e425bbdf9e88a906b4a49/wal-000000005 (ops 21-25)
I20260812 06:20:15.792616 29580 log.cc:1079] T f57255de3d8e425bbdf9e88a906b4a49 P 3ba6fa63bba94351bf8c522fd5eafa1d: Deleting log segment in path: /tmp/dist-test-tasksggqpW/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515609106051-29068-0/minicluster-data/ts-0-root/wals/f57255de3d8e425bbdf9e88a906b4a49/wal-000000006 (ops 26-30)
I20260812 06:20:15.792647 29580 log.cc:1079] T f57255de3d8e425bbdf9e88a906b4a49 P 3ba6fa63bba94351bf8c522fd5eafa1d: Deleting log segment in path: /tmp/dist-test-tasksggqpW/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515609106051-29068-0/minicluster-data/ts-0-root/wals/f57255de3d8e425bbdf9e88a906b4a49/wal-000000007 (ops 31-35)
I20260812 06:20:15.792677 29580 log.cc:1079] T f57255de3d8e425bbdf9e88a906b4a49 P 3ba6fa63bba94351bf8c522fd5eafa1d: Deleting log segment in path: /tmp/dist-test-tasksggqpW/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515609106051-29068-0/minicluster-data/ts-0-root/wals/f57255de3d8e425bbdf9e88a906b4a49/wal-000000008 (ops 36-40)
I20260812 06:20:15.792707 29580 log.cc:1079] T f57255de3d8e425bbdf9e88a906b4a49 P 3ba6fa63bba94351bf8c522fd5eafa1d: Deleting log segment in path: /tmp/dist-test-tasksggqpW/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515609106051-29068-0/minicluster-data/ts-0-root/wals/f57255de3d8e425bbdf9e88a906b4a49/wal-000000009 (ops 41-44)
I20260812 06:20:15.792737 29580 log.cc:1079] T f57255de3d8e425bbdf9e88a906b4a49 P 3ba6fa63bba94351bf8c522fd5eafa1d: Deleting log segment in path: /tmp/dist-test-tasksggqpW/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515609106051-29068-0/minicluster-data/ts-0-root/wals/f57255de3d8e425bbdf9e88a906b4a49/wal-000000010 (ops 45-49)
I20260812 06:20:15.792766 29580 log.cc:1079] T f57255de3d8e425bbdf9e88a906b4a49 P 3ba6fa63bba94351bf8c522fd5eafa1d: Deleting log segment in path: /tmp/dist-test-tasksggqpW/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515609106051-29068-0/minicluster-data/ts-0-root/wals/f57255de3d8e425bbdf9e88a906b4a49/wal-000000011 (ops 50-54)
I20260812 06:20:15.792796 29580 log.cc:1079] T f57255de3d8e425bbdf9e88a906b4a49 P 3ba6fa63bba94351bf8c522fd5eafa1d: Deleting log segment in path: /tmp/dist-test-tasksggqpW/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515609106051-29068-0/minicluster-data/ts-0-root/wals/f57255de3d8e425bbdf9e88a906b4a49/wal-000000012 (ops 55-59)
I20260812 06:20:15.792825 29580 log.cc:1079] T f57255de3d8e425bbdf9e88a906b4a49 P 3ba6fa63bba94351bf8c522fd5eafa1d: Deleting log segment in path: /tmp/dist-test-tasksggqpW/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515609106051-29068-0/minicluster-data/ts-0-root/wals/f57255de3d8e425bbdf9e88a906b4a49/wal-000000013 (ops 60-64)
I20260812 06:20:15.792856 29580 log.cc:1079] T f57255de3d8e425bbdf9e88a906b4a49 P 3ba6fa63bba94351bf8c522fd5eafa1d: Deleting log segment in path: /tmp/dist-test-tasksggqpW/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515609106051-29068-0/minicluster-data/ts-0-root/wals/f57255de3d8e425bbdf9e88a906b4a49/wal-000000014 (ops 65-69)
I20260812 06:20:15.814371 29580 maintenance_manager.cc:643] P 3ba6fa63bba94351bf8c522fd5eafa1d: LogGCOp(f57255de3d8e425bbdf9e88a906b4a49) complete. Timing: real 0.022s	user 0.003s	sys 0.019s Metrics: {}
I20260812 06:20:15.814813 29679 maintenance_manager.cc:419] P 3ba6fa63bba94351bf8c522fd5eafa1d: Scheduling FlushDeltaMemStoresOp(f57255de3d8e425bbdf9e88a906b4a49): perf score=2.188937
I20260812 06:20:15.837512 29580 maintenance_manager.cc:643] P 3ba6fa63bba94351bf8c522fd5eafa1d: FlushDeltaMemStoresOp(f57255de3d8e425bbdf9e88a906b4a49) complete. Timing: real 0.023s	user 0.008s	sys 0.006s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3642,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:15.838070 29679 maintenance_manager.cc:419] P 3ba6fa63bba94351bf8c522fd5eafa1d: Scheduling UndoDeltaBlockGCOp(f57255de3d8e425bbdf9e88a906b4a49): 447 bytes on disk
I20260812 06:20:15.838572 29580 maintenance_manager.cc:643] P 3ba6fa63bba94351bf8c522fd5eafa1d: UndoDeltaBlockGCOp(f57255de3d8e425bbdf9e88a906b4a49) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":62,"lbm_reads_lt_1ms":4}
I20260812 06:20:15.839053 29679 maintenance_manager.cc:419] P 3ba6fa63bba94351bf8c522fd5eafa1d: Scheduling FlushDeltaMemStoresOp(f57255de3d8e425bbdf9e88a906b4a49): perf score=2.188937
I20260812 06:20:15.849282 29580 maintenance_manager.cc:643] P 3ba6fa63bba94351bf8c522fd5eafa1d: FlushDeltaMemStoresOp(f57255de3d8e425bbdf9e88a906b4a49) complete. Timing: real 0.010s	user 0.008s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3970,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:15.849790 29679 maintenance_manager.cc:419] P 3ba6fa63bba94351bf8c522fd5eafa1d: Scheduling MajorDeltaCompactionOp(f57255de3d8e425bbdf9e88a906b4a49): perf score=1.000000
I20260812 06:20:16.049706 29580 maintenance_manager.cc:643] P 3ba6fa63bba94351bf8c522fd5eafa1d: MajorDeltaCompactionOp(f57255de3d8e425bbdf9e88a906b4a49) complete. Timing: real 0.200s	user 0.152s	sys 0.047s Metrics: {"cfile_cache_miss":634,"cfile_cache_miss_bytes":28918334,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":122,"lbm_read_time_us":14473,"lbm_reads_lt_1ms":674,"lbm_write_time_us":35042,"lbm_writes_lt_1ms":643,"mutex_wait_us":57,"peak_mem_usage":75542472,"reinsert_count":0,"thread_start_us":74,"threads_started":1,"update_count":3000}
I20260812 06:20:16.050364 29679 maintenance_manager.cc:419] P 3ba6fa63bba94351bf8c522fd5eafa1d: Scheduling FlushDeltaMemStoresOp(f57255de3d8e425bbdf9e88a906b4a49): perf score=14.095187
I20260812 06:20:16.106788 29580 maintenance_manager.cc:643] P 3ba6fa63bba94351bf8c522fd5eafa1d: FlushDeltaMemStoresOp(f57255de3d8e425bbdf9e88a906b4a49) complete. Timing: real 0.055s	user 0.023s	sys 0.032s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":18904,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:20:16.107457 29679 maintenance_manager.cc:419] P 3ba6fa63bba94351bf8c522fd5eafa1d: Scheduling FlushDeltaMemStoresOp(f57255de3d8e425bbdf9e88a906b4a49): perf score=2.188937
I20260812 06:20:16.122689 29580 maintenance_manager.cc:643] P 3ba6fa63bba94351bf8c522fd5eafa1d: FlushDeltaMemStoresOp(f57255de3d8e425bbdf9e88a906b4a49) complete. Timing: real 0.015s	user 0.010s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5848,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:16.123183 29679 maintenance_manager.cc:419] P 3ba6fa63bba94351bf8c522fd5eafa1d: Scheduling MajorDeltaCompactionOp(f57255de3d8e425bbdf9e88a906b4a49): perf score=1.000000
I20260812 06:20:16.294881 29580 maintenance_manager.cc:643] P 3ba6fa63bba94351bf8c522fd5eafa1d: MajorDeltaCompactionOp(f57255de3d8e425bbdf9e88a906b4a49) complete. Timing: real 0.172s	user 0.115s	sys 0.052s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24815684,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":240,"lbm_read_time_us":11895,"lbm_reads_lt_1ms":572,"lbm_write_time_us":27497,"lbm_writes_lt_1ms":543,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":31232,"update_count":2500}
I20260812 06:20:16.295404 29679 maintenance_manager.cc:419] P 3ba6fa63bba94351bf8c522fd5eafa1d: Scheduling FlushDeltaMemStoresOp(f57255de3d8e425bbdf9e88a906b4a49): perf score=14.095187
I20260812 06:20:16.372148 29580 maintenance_manager.cc:643] P 3ba6fa63bba94351bf8c522fd5eafa1d: FlushDeltaMemStoresOp(f57255de3d8e425bbdf9e88a906b4a49) complete. Timing: real 0.077s	user 0.020s	sys 0.024s Metrics: {"bytes_written":16409903,"delete_count":0,"lbm_write_time_us":20431,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:20:16.372618 29679 maintenance_manager.cc:419] P 3ba6fa63bba94351bf8c522fd5eafa1d: Scheduling FlushDeltaMemStoresOp(f57255de3d8e425bbdf9e88a906b4a49): perf score=2.188937
I20260812 06:20:16.392539 29580 maintenance_manager.cc:643] P 3ba6fa63bba94351bf8c522fd5eafa1d: FlushDeltaMemStoresOp(f57255de3d8e425bbdf9e88a906b4a49) complete. Timing: real 0.020s	user 0.003s	sys 0.007s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4840,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:16.393088 29679 maintenance_manager.cc:419] P 3ba6fa63bba94351bf8c522fd5eafa1d: Scheduling MajorDeltaCompactionOp(f57255de3d8e425bbdf9e88a906b4a49): perf score=1.000000
I20260812 06:20:16.566406 29580 maintenance_manager.cc:643] P 3ba6fa63bba94351bf8c522fd5eafa1d: MajorDeltaCompactionOp(f57255de3d8e425bbdf9e88a906b4a49) complete. Timing: real 0.173s	user 0.136s	sys 0.036s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24815685,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":311,"lbm_read_time_us":11572,"lbm_reads_lt_1ms":564,"lbm_write_time_us":31033,"lbm_writes_lt_1ms":543,"peak_mem_usage":63115900,"reinsert_count":0,"update_count":2500}
I20260812 06:20:16.566915 29679 maintenance_manager.cc:419] P 3ba6fa63bba94351bf8c522fd5eafa1d: Scheduling FlushDeltaMemStoresOp(f57255de3d8e425bbdf9e88a906b4a49): perf score=14.095187
I20260812 06:20:16.604892 29580 maintenance_manager.cc:643] P 3ba6fa63bba94351bf8c522fd5eafa1d: FlushDeltaMemStoresOp(f57255de3d8e425bbdf9e88a906b4a49) complete. Timing: real 0.038s	user 0.027s	sys 0.008s Metrics: {"bytes_written":16409903,"delete_count":0,"lbm_write_time_us":15927,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:20:16.605430 29679 maintenance_manager.cc:419] P 3ba6fa63bba94351bf8c522fd5eafa1d: Scheduling FlushDeltaMemStoresOp(f57255de3d8e425bbdf9e88a906b4a49): perf score=2.188937
I20260812 06:20:16.637691 29580 maintenance_manager.cc:643] P 3ba6fa63bba94351bf8c522fd5eafa1d: FlushDeltaMemStoresOp(f57255de3d8e425bbdf9e88a906b4a49) complete. Timing: real 0.032s	user 0.007s	sys 0.010s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4954,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:16.638208 29679 maintenance_manager.cc:419] P 3ba6fa63bba94351bf8c522fd5eafa1d: Scheduling FlushDeltaMemStoresOp(f57255de3d8e425bbdf9e88a906b4a49): perf score=2.188937
I20260812 06:20:16.648397 29580 maintenance_manager.cc:643] P 3ba6fa63bba94351bf8c522fd5eafa1d: FlushDeltaMemStoresOp(f57255de3d8e425bbdf9e88a906b4a49) complete. Timing: real 0.010s	user 0.004s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3837,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:16.648833 29679 maintenance_manager.cc:419] P 3ba6fa63bba94351bf8c522fd5eafa1d: Scheduling MajorDeltaCompactionOp(f57255de3d8e425bbdf9e88a906b4a49): perf score=1.000000
I20260812 06:20:16.836555 29580 maintenance_manager.cc:643] P 3ba6fa63bba94351bf8c522fd5eafa1d: MajorDeltaCompactionOp(f57255de3d8e425bbdf9e88a906b4a49) complete. Timing: real 0.188s	user 0.135s	sys 0.052s Metrics: {"cfile_cache_miss":633,"cfile_cache_miss_bytes":28918216,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":345,"lbm_read_time_us":13266,"lbm_reads_lt_1ms":673,"lbm_write_time_us":30105,"lbm_writes_lt_1ms":643,"mutex_wait_us":21,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":13440,"update_count":3000}
I20260812 06:20:16.837018 29679 maintenance_manager.cc:419] P 3ba6fa63bba94351bf8c522fd5eafa1d: Scheduling FlushDeltaMemStoresOp(f57255de3d8e425bbdf9e88a906b4a49): perf score=14.095187
I20260812 06:20:16.901981 29580 maintenance_manager.cc:643] P 3ba6fa63bba94351bf8c522fd5eafa1d: FlushDeltaMemStoresOp(f57255de3d8e425bbdf9e88a906b4a49) complete. Timing: real 0.065s	user 0.030s	sys 0.031s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":24360,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":402,"reinsert_count":0,"update_count":2000}
I20260812 06:20:16.902606 29679 maintenance_manager.cc:419] P 3ba6fa63bba94351bf8c522fd5eafa1d: Scheduling FlushDeltaMemStoresOp(f57255de3d8e425bbdf9e88a906b4a49): perf score=2.188937
I20260812 06:20:16.918200 29580 maintenance_manager.cc:643] P 3ba6fa63bba94351bf8c522fd5eafa1d: FlushDeltaMemStoresOp(f57255de3d8e425bbdf9e88a906b4a49) complete. Timing: real 0.015s	user 0.013s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5916,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:16.918771 29679 maintenance_manager.cc:419] P 3ba6fa63bba94351bf8c522fd5eafa1d: Scheduling MajorDeltaCompactionOp(f57255de3d8e425bbdf9e88a906b4a49): perf score=1.000000
I20260812 06:20:17.079958 29580 maintenance_manager.cc:643] P 3ba6fa63bba94351bf8c522fd5eafa1d: MajorDeltaCompactionOp(f57255de3d8e425bbdf9e88a906b4a49) complete. Timing: real 0.161s	user 0.123s	sys 0.035s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24815683,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":779,"lbm_read_time_us":11708,"lbm_reads_lt_1ms":572,"lbm_write_time_us":26067,"lbm_writes_lt_1ms":543,"mutex_wait_us":250,"peak_mem_usage":63115900,"reinsert_count":0,"update_count":2500}
I20260812 06:20:17.080554 29679 maintenance_manager.cc:419] P 3ba6fa63bba94351bf8c522fd5eafa1d: Scheduling FlushDeltaMemStoresOp(f57255de3d8e425bbdf9e88a906b4a49): perf score=11.118625
I20260812 06:20:17.127100 29580 maintenance_manager.cc:643] P 3ba6fa63bba94351bf8c522fd5eafa1d: FlushDeltaMemStoresOp(f57255de3d8e425bbdf9e88a906b4a49) complete. Timing: real 0.046s	user 0.030s	sys 0.015s Metrics: {"bytes_written":12717735,"delete_count":0,"lbm_write_time_us":22213,"lbm_writes_1-10_ms":3,"lbm_writes_lt_1ms":310,"reinsert_count":0,"update_count":1550}
I20260812 06:20:17.127564 29679 maintenance_manager.cc:419] P 3ba6fa63bba94351bf8c522fd5eafa1d: Scheduling FlushDeltaMemStoresOp(f57255de3d8e425bbdf9e88a906b4a49): perf score=2.188937
I20260812 06:20:17.139003 29580 maintenance_manager.cc:643] P 3ba6fa63bba94351bf8c522fd5eafa1d: FlushDeltaMemStoresOp(f57255de3d8e425bbdf9e88a906b4a49) complete. Timing: real 0.011s	user 0.006s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3744,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:17.139430 29679 maintenance_manager.cc:419] P 3ba6fa63bba94351bf8c522fd5eafa1d: Scheduling FlushDeltaMemStoresOp(f57255de3d8e425bbdf9e88a906b4a49): perf score=2.188937
I20260812 06:20:17.160651 29580 maintenance_manager.cc:643] P 3ba6fa63bba94351bf8c522fd5eafa1d: FlushDeltaMemStoresOp(f57255de3d8e425bbdf9e88a906b4a49) complete. Timing: real 0.021s	user 0.006s	sys 0.012s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":4904,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:20:17.161149 29679 maintenance_manager.cc:419] P 3ba6fa63bba94351bf8c522fd5eafa1d: Scheduling FlushMRSOp(f57255de3d8e425bbdf9e88a906b4a49): perf score=1.000000
I20260812 06:20:17.187824 29580 maintenance_manager.cc:643] P 3ba6fa63bba94351bf8c522fd5eafa1d: FlushMRSOp(f57255de3d8e425bbdf9e88a906b4a49) complete. Timing: real 0.026s	user 0.025s	sys 0.000s Metrics: {"bytes_written":1152514,"cfile_init":1,"dirs.queue_time_us":60,"dirs.run_cpu_time_us":230,"dirs.run_wall_time_us":1333,"drs_written":1,"lbm_read_time_us":36,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1267,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":28}
I20260812 06:20:17.188454 29679 maintenance_manager.cc:419] P 3ba6fa63bba94351bf8c522fd5eafa1d: Scheduling LogGCOp(f57255de3d8e425bbdf9e88a906b4a49): free 108535455 bytes of WAL
I20260812 06:20:17.188683 29580 log_reader.cc:385] T f57255de3d8e425bbdf9e88a906b4a49: removed 11 log segments from log reader
I20260812 06:20:17.188727 29580 log.cc:1079] T f57255de3d8e425bbdf9e88a906b4a49 P 3ba6fa63bba94351bf8c522fd5eafa1d: Deleting log segment in path: /tmp/dist-test-tasksggqpW/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515609106051-29068-0/minicluster-data/ts-0-root/wals/f57255de3d8e425bbdf9e88a906b4a49/wal-000000015 (ops 70-74)
I20260812 06:20:17.188755 29580 log.cc:1079] T f57255de3d8e425bbdf9e88a906b4a49 P 3ba6fa63bba94351bf8c522fd5eafa1d: Deleting log segment in path: /tmp/dist-test-tasksggqpW/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515609106051-29068-0/minicluster-data/ts-0-root/wals/f57255de3d8e425bbdf9e88a906b4a49/wal-000000016 (ops 75-79)
I20260812 06:20:17.188784 29580 log.cc:1079] T f57255de3d8e425bbdf9e88a906b4a49 P 3ba6fa63bba94351bf8c522fd5eafa1d: Deleting log segment in path: /tmp/dist-test-tasksggqpW/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515609106051-29068-0/minicluster-data/ts-0-root/wals/f57255de3d8e425bbdf9e88a906b4a49/wal-000000017 (ops 80-84)
I20260812 06:20:17.188817 29580 log.cc:1079] T f57255de3d8e425bbdf9e88a906b4a49 P 3ba6fa63bba94351bf8c522fd5eafa1d: Deleting log segment in path: /tmp/dist-test-tasksggqpW/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515609106051-29068-0/minicluster-data/ts-0-root/wals/f57255de3d8e425bbdf9e88a906b4a49/wal-000000018 (ops 85-88)
I20260812 06:20:17.188848 29580 log.cc:1079] T f57255de3d8e425bbdf9e88a906b4a49 P 3ba6fa63bba94351bf8c522fd5eafa1d: Deleting log segment in path: /tmp/dist-test-tasksggqpW/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515609106051-29068-0/minicluster-data/ts-0-root/wals/f57255de3d8e425bbdf9e88a906b4a49/wal-000000019 (ops 89-93)
I20260812 06:20:17.188881 29580 log.cc:1079] T f57255de3d8e425bbdf9e88a906b4a49 P 3ba6fa63bba94351bf8c522fd5eafa1d: Deleting log segment in path: /tmp/dist-test-tasksggqpW/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515609106051-29068-0/minicluster-data/ts-0-root/wals/f57255de3d8e425bbdf9e88a906b4a49/wal-000000020 (ops 94-98)
I20260812 06:20:17.188912 29580 log.cc:1079] T f57255de3d8e425bbdf9e88a906b4a49 P 3ba6fa63bba94351bf8c522fd5eafa1d: Deleting log segment in path: /tmp/dist-test-tasksggqpW/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515609106051-29068-0/minicluster-data/ts-0-root/wals/f57255de3d8e425bbdf9e88a906b4a49/wal-000000021 (ops 99-102)
I20260812 06:20:17.188943 29580 log.cc:1079] T f57255de3d8e425bbdf9e88a906b4a49 P 3ba6fa63bba94351bf8c522fd5eafa1d: Deleting log segment in path: /tmp/dist-test-tasksggqpW/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515609106051-29068-0/minicluster-data/ts-0-root/wals/f57255de3d8e425bbdf9e88a906b4a49/wal-000000022 (ops 103-107)
I20260812 06:20:17.188984 29580 log.cc:1079] T f57255de3d8e425bbdf9e88a906b4a49 P 3ba6fa63bba94351bf8c522fd5eafa1d: Deleting log segment in path: /tmp/dist-test-tasksggqpW/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515609106051-29068-0/minicluster-data/ts-0-root/wals/f57255de3d8e425bbdf9e88a906b4a49/wal-000000023 (ops 108-112)
I20260812 06:20:17.189005 29580 log.cc:1079] T f57255de3d8e425bbdf9e88a906b4a49 P 3ba6fa63bba94351bf8c522fd5eafa1d: Deleting log segment in path: /tmp/dist-test-tasksggqpW/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515609106051-29068-0/minicluster-data/ts-0-root/wals/f57255de3d8e425bbdf9e88a906b4a49/wal-000000024 (ops 113-117)
I20260812 06:20:17.189036 29580 log.cc:1079] T f57255de3d8e425bbdf9e88a906b4a49 P 3ba6fa63bba94351bf8c522fd5eafa1d: Deleting log segment in path: /tmp/dist-test-tasksggqpW/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515609106051-29068-0/minicluster-data/ts-0-root/wals/f57255de3d8e425bbdf9e88a906b4a49/wal-000000025 (ops 118-122)
I20260812 06:20:17.206607 29580 maintenance_manager.cc:643] P 3ba6fa63bba94351bf8c522fd5eafa1d: LogGCOp(f57255de3d8e425bbdf9e88a906b4a49) complete. Timing: real 0.018s	user 0.000s	sys 0.018s Metrics: {}
I20260812 06:20:17.206965 29679 maintenance_manager.cc:419] P 3ba6fa63bba94351bf8c522fd5eafa1d: Scheduling UndoDeltaBlockGCOp(f57255de3d8e425bbdf9e88a906b4a49): 447 bytes on disk
I20260812 06:20:17.207387 29580 maintenance_manager.cc:643] P 3ba6fa63bba94351bf8c522fd5eafa1d: UndoDeltaBlockGCOp(f57255de3d8e425bbdf9e88a906b4a49) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":59,"lbm_reads_lt_1ms":4}
I20260812 06:20:17.207888 29679 maintenance_manager.cc:419] P 3ba6fa63bba94351bf8c522fd5eafa1d: Scheduling FlushDeltaMemStoresOp(f57255de3d8e425bbdf9e88a906b4a49): perf score=2.188937
I20260812 06:20:17.222493 29580 maintenance_manager.cc:643] P 3ba6fa63bba94351bf8c522fd5eafa1d: FlushDeltaMemStoresOp(f57255de3d8e425bbdf9e88a906b4a49) complete. Timing: real 0.014s	user 0.005s	sys 0.009s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5246,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:17.222978 29679 maintenance_manager.cc:419] P 3ba6fa63bba94351bf8c522fd5eafa1d: Scheduling MajorDeltaCompactionOp(f57255de3d8e425bbdf9e88a906b4a49): perf score=1.000000
I20260812 06:20:17.406163 29580 maintenance_manager.cc:643] P 3ba6fa63bba94351bf8c522fd5eafa1d: MajorDeltaCompactionOp(f57255de3d8e425bbdf9e88a906b4a49) complete. Timing: real 0.183s	user 0.114s	sys 0.069s Metrics: {"cfile_cache_miss":634,"cfile_cache_miss_bytes":28918325,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":164,"lbm_read_time_us":12217,"lbm_reads_lt_1ms":670,"lbm_write_time_us":31360,"lbm_writes_lt_1ms":643,"mutex_wait_us":295,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":1664,"thread_start_us":101,"threads_started":1,"update_count":3000}
I20260812 06:20:17.406766 29679 maintenance_manager.cc:419] P 3ba6fa63bba94351bf8c522fd5eafa1d: Scheduling FlushDeltaMemStoresOp(f57255de3d8e425bbdf9e88a906b4a49): perf score=14.095187
I20260812 06:20:17.454900 29580 maintenance_manager.cc:643] P 3ba6fa63bba94351bf8c522fd5eafa1d: FlushDeltaMemStoresOp(f57255de3d8e425bbdf9e88a906b4a49) complete. Timing: real 0.048s	user 0.032s	sys 0.014s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":17577,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":402,"reinsert_count":0,"update_count":2000}
I20260812 06:20:17.455511 29679 maintenance_manager.cc:419] P 3ba6fa63bba94351bf8c522fd5eafa1d: Scheduling FlushDeltaMemStoresOp(f57255de3d8e425bbdf9e88a906b4a49): perf score=2.188937
I20260812 06:20:17.466245 29580 maintenance_manager.cc:643] P 3ba6fa63bba94351bf8c522fd5eafa1d: FlushDeltaMemStoresOp(f57255de3d8e425bbdf9e88a906b4a49) complete. Timing: real 0.011s	user 0.005s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4097,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:17.466702 29679 maintenance_manager.cc:419] P 3ba6fa63bba94351bf8c522fd5eafa1d: Scheduling MajorDeltaCompactionOp(f57255de3d8e425bbdf9e88a906b4a49): perf score=1.000000
I20260812 06:20:17.644138 29580 maintenance_manager.cc:643] P 3ba6fa63bba94351bf8c522fd5eafa1d: MajorDeltaCompactionOp(f57255de3d8e425bbdf9e88a906b4a49) complete. Timing: real 0.177s	user 0.102s	sys 0.066s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24815683,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":869,"lbm_read_time_us":11922,"lbm_reads_lt_1ms":572,"lbm_write_time_us":28753,"lbm_writes_lt_1ms":543,"mutex_wait_us":272,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":768,"update_count":2500}
I20260812 06:20:17.644668 29679 maintenance_manager.cc:419] P 3ba6fa63bba94351bf8c522fd5eafa1d: Scheduling FlushDeltaMemStoresOp(f57255de3d8e425bbdf9e88a906b4a49): perf score=14.095187
I20260812 06:20:17.698506 29580 maintenance_manager.cc:643] P 3ba6fa63bba94351bf8c522fd5eafa1d: FlushDeltaMemStoresOp(f57255de3d8e425bbdf9e88a906b4a49) complete. Timing: real 0.054s	user 0.022s	sys 0.025s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":17415,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:20:17.699039 29679 maintenance_manager.cc:419] P 3ba6fa63bba94351bf8c522fd5eafa1d: Scheduling FlushDeltaMemStoresOp(f57255de3d8e425bbdf9e88a906b4a49): perf score=2.188937
I20260812 06:20:17.709172 29580 maintenance_manager.cc:643] P 3ba6fa63bba94351bf8c522fd5eafa1d: FlushDeltaMemStoresOp(f57255de3d8e425bbdf9e88a906b4a49) complete. Timing: real 0.010s	user 0.004s	sys 0.004s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":3890,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:17.709582 29679 maintenance_manager.cc:419] P 3ba6fa63bba94351bf8c522fd5eafa1d: Scheduling MajorDeltaCompactionOp(f57255de3d8e425bbdf9e88a906b4a49): perf score=1.000000
I20260812 06:20:17.880232 29580 maintenance_manager.cc:643] P 3ba6fa63bba94351bf8c522fd5eafa1d: MajorDeltaCompactionOp(f57255de3d8e425bbdf9e88a906b4a49) complete. Timing: real 0.170s	user 0.117s	sys 0.051s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24815683,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":571,"lbm_read_time_us":12442,"lbm_reads_lt_1ms":572,"lbm_write_time_us":28325,"lbm_writes_lt_1ms":543,"mutex_wait_us":265,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":3712,"update_count":2500}
I20260812 06:20:17.880874 29679 maintenance_manager.cc:419] P 3ba6fa63bba94351bf8c522fd5eafa1d: Scheduling FlushDeltaMemStoresOp(f57255de3d8e425bbdf9e88a906b4a49): perf score=11.118625
I20260812 06:20:17.912735 29580 maintenance_manager.cc:643] P 3ba6fa63bba94351bf8c522fd5eafa1d: FlushDeltaMemStoresOp(f57255de3d8e425bbdf9e88a906b4a49) complete. Timing: real 0.032s	user 0.013s	sys 0.016s Metrics: {"bytes_written":12717735,"delete_count":0,"lbm_write_time_us":13435,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:20:17.913378 29679 maintenance_manager.cc:419] P 3ba6fa63bba94351bf8c522fd5eafa1d: Scheduling FlushDeltaMemStoresOp(f57255de3d8e425bbdf9e88a906b4a49): perf score=2.188937
I20260812 06:20:17.938943 29580 maintenance_manager.cc:643] P 3ba6fa63bba94351bf8c522fd5eafa1d: FlushDeltaMemStoresOp(f57255de3d8e425bbdf9e88a906b4a49) complete. Timing: real 0.025s	user 0.014s	sys 0.000s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":6202,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:20:17.939486 29679 maintenance_manager.cc:419] P 3ba6fa63bba94351bf8c522fd5eafa1d: Scheduling FlushDeltaMemStoresOp(f57255de3d8e425bbdf9e88a906b4a49): perf score=2.188937
I20260812 06:20:17.962607 29580 maintenance_manager.cc:643] P 3ba6fa63bba94351bf8c522fd5eafa1d: FlushDeltaMemStoresOp(f57255de3d8e425bbdf9e88a906b4a49) complete. Timing: real 0.023s	user 0.012s	sys 0.010s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5501,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:17.963115 29679 maintenance_manager.cc:419] P 3ba6fa63bba94351bf8c522fd5eafa1d: Scheduling MajorDeltaCompactionOp(f57255de3d8e425bbdf9e88a906b4a49): perf score=1.000000
I20260812 06:20:18.124533 29580 maintenance_manager.cc:643] P 3ba6fa63bba94351bf8c522fd5eafa1d: MajorDeltaCompactionOp(f57255de3d8e425bbdf9e88a906b4a49) complete. Timing: real 0.161s	user 0.112s	sys 0.049s Metrics: {"cfile_cache_miss":533,"cfile_cache_miss_bytes":24815794,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":514,"lbm_read_time_us":11476,"lbm_reads_lt_1ms":573,"lbm_write_time_us":26772,"lbm_writes_lt_1ms":543,"mutex_wait_us":26,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":44416,"update_count":2500}
I20260812 06:20:18.125064 29679 maintenance_manager.cc:419] P 3ba6fa63bba94351bf8c522fd5eafa1d: Scheduling FlushDeltaMemStoresOp(f57255de3d8e425bbdf9e88a906b4a49): perf score=11.118625
I20260812 06:20:18.159053 29580 maintenance_manager.cc:643] P 3ba6fa63bba94351bf8c522fd5eafa1d: FlushDeltaMemStoresOp(f57255de3d8e425bbdf9e88a906b4a49) complete. Timing: real 0.034s	user 0.014s	sys 0.019s Metrics: {"bytes_written":12717735,"delete_count":0,"lbm_write_time_us":13846,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:20:18.159669 29679 maintenance_manager.cc:419] P 3ba6fa63bba94351bf8c522fd5eafa1d: Scheduling FlushDeltaMemStoresOp(f57255de3d8e425bbdf9e88a906b4a49): perf score=2.188937
I20260812 06:20:18.181497 29580 maintenance_manager.cc:643] P 3ba6fa63bba94351bf8c522fd5eafa1d: FlushDeltaMemStoresOp(f57255de3d8e425bbdf9e88a906b4a49) complete. Timing: real 0.022s	user 0.008s	sys 0.004s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3947,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:20:18.182021 29679 maintenance_manager.cc:419] P 3ba6fa63bba94351bf8c522fd5eafa1d: Scheduling FlushDeltaMemStoresOp(f57255de3d8e425bbdf9e88a906b4a49): perf score=2.188937
I20260812 06:20:18.192267 29580 maintenance_manager.cc:643] P 3ba6fa63bba94351bf8c522fd5eafa1d: FlushDeltaMemStoresOp(f57255de3d8e425bbdf9e88a906b4a49) complete. Timing: real 0.010s	user 0.006s	sys 0.003s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3708,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:18.192767 29679 maintenance_manager.cc:419] P 3ba6fa63bba94351bf8c522fd5eafa1d: Scheduling MajorDeltaCompactionOp(f57255de3d8e425bbdf9e88a906b4a49): perf score=1.000000
I20260812 06:20:18.374054 29580 maintenance_manager.cc:643] P 3ba6fa63bba94351bf8c522fd5eafa1d: MajorDeltaCompactionOp(f57255de3d8e425bbdf9e88a906b4a49) complete. Timing: real 0.181s	user 0.089s	sys 0.081s Metrics: {"cfile_cache_miss":533,"cfile_cache_miss_bytes":24815794,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":458,"lbm_read_time_us":11268,"lbm_reads_lt_1ms":573,"lbm_write_time_us":27497,"lbm_writes_lt_1ms":543,"mutex_wait_us":36,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":17920,"update_count":2500}
I20260812 06:20:18.374586 29679 maintenance_manager.cc:419] P 3ba6fa63bba94351bf8c522fd5eafa1d: Scheduling FlushDeltaMemStoresOp(f57255de3d8e425bbdf9e88a906b4a49): perf score=14.095187
I20260812 06:20:18.426297 29580 maintenance_manager.cc:643] P 3ba6fa63bba94351bf8c522fd5eafa1d: FlushDeltaMemStoresOp(f57255de3d8e425bbdf9e88a906b4a49) complete. Timing: real 0.052s	user 0.024s	sys 0.023s Metrics: {"bytes_written":16409903,"delete_count":0,"lbm_write_time_us":23119,"lbm_writes_1-10_ms":2,"lbm_writes_lt_1ms":401,"reinsert_count":0,"update_count":2000}
I20260812 06:20:18.426900 29679 maintenance_manager.cc:419] P 3ba6fa63bba94351bf8c522fd5eafa1d: Scheduling FlushDeltaMemStoresOp(f57255de3d8e425bbdf9e88a906b4a49): perf score=2.188937
I20260812 06:20:18.438601 29580 maintenance_manager.cc:643] P 3ba6fa63bba94351bf8c522fd5eafa1d: FlushDeltaMemStoresOp(f57255de3d8e425bbdf9e88a906b4a49) complete. Timing: real 0.012s	user 0.011s	sys 0.001s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4396,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:18.439080 29679 maintenance_manager.cc:419] P 3ba6fa63bba94351bf8c522fd5eafa1d: Scheduling MajorDeltaCompactionOp(f57255de3d8e425bbdf9e88a906b4a49): perf score=1.000000
I20260812 06:20:18.589875 29580 maintenance_manager.cc:643] P 3ba6fa63bba94351bf8c522fd5eafa1d: MajorDeltaCompactionOp(f57255de3d8e425bbdf9e88a906b4a49) complete. Timing: real 0.151s	user 0.123s	sys 0.020s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24815685,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":225,"lbm_read_time_us":9251,"lbm_reads_lt_1ms":572,"lbm_write_time_us":27063,"lbm_writes_lt_1ms":543,"mutex_wait_us":25,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":18432,"update_count":2500}
I20260812 06:20:18.590464 29679 maintenance_manager.cc:419] P 3ba6fa63bba94351bf8c522fd5eafa1d: Scheduling FlushDeltaMemStoresOp(f57255de3d8e425bbdf9e88a906b4a49): perf score=14.095187
I20260812 06:20:18.634446 29580 maintenance_manager.cc:643] P 3ba6fa63bba94351bf8c522fd5eafa1d: FlushDeltaMemStoresOp(f57255de3d8e425bbdf9e88a906b4a49) complete. Timing: real 0.044s	user 0.036s	sys 0.004s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":17333,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:20:18.634919 29679 maintenance_manager.cc:419] P 3ba6fa63bba94351bf8c522fd5eafa1d: Scheduling FlushDeltaMemStoresOp(f57255de3d8e425bbdf9e88a906b4a49): perf score=2.188937
I20260812 06:20:18.644969 29580 maintenance_manager.cc:643] P 3ba6fa63bba94351bf8c522fd5eafa1d: FlushDeltaMemStoresOp(f57255de3d8e425bbdf9e88a906b4a49) complete. Timing: real 0.010s	user 0.008s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3654,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:18.645540 29679 maintenance_manager.cc:419] P 3ba6fa63bba94351bf8c522fd5eafa1d: Scheduling FlushMRSOp(f57255de3d8e425bbdf9e88a906b4a49): perf score=1.000000
I20260812 06:20:18.678102 29580 maintenance_manager.cc:643] P 3ba6fa63bba94351bf8c522fd5eafa1d: FlushMRSOp(f57255de3d8e425bbdf9e88a906b4a49) complete. Timing: real 0.032s	user 0.030s	sys 0.000s Metrics: {"bytes_written":1275445,"cfile_init":1,"dirs.queue_time_us":146,"dirs.run_cpu_time_us":176,"dirs.run_wall_time_us":1348,"drs_written":1,"lbm_read_time_us":51,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1683,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":31}
I20260812 06:20:18.678824 29679 maintenance_manager.cc:419] P 3ba6fa63bba94351bf8c522fd5eafa1d: Scheduling LogGCOp(f57255de3d8e425bbdf9e88a906b4a49): free 132118502 bytes of WAL
I20260812 06:20:18.679059 29580 log_reader.cc:385] T f57255de3d8e425bbdf9e88a906b4a49: removed 13 log segments from log reader
I20260812 06:20:18.679121 29580 log.cc:1079] T f57255de3d8e425bbdf9e88a906b4a49 P 3ba6fa63bba94351bf8c522fd5eafa1d: Deleting log segment in path: /tmp/dist-test-tasksggqpW/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515609106051-29068-0/minicluster-data/ts-0-root/wals/f57255de3d8e425bbdf9e88a906b4a49/wal-000000026 (ops 123-127)
I20260812 06:20:18.679165 29580 log.cc:1079] T f57255de3d8e425bbdf9e88a906b4a49 P 3ba6fa63bba94351bf8c522fd5eafa1d: Deleting log segment in path: /tmp/dist-test-tasksggqpW/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515609106051-29068-0/minicluster-data/ts-0-root/wals/f57255de3d8e425bbdf9e88a906b4a49/wal-000000027 (ops 128-132)
I20260812 06:20:18.679193 29580 log.cc:1079] T f57255de3d8e425bbdf9e88a906b4a49 P 3ba6fa63bba94351bf8c522fd5eafa1d: Deleting log segment in path: /tmp/dist-test-tasksggqpW/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515609106051-29068-0/minicluster-data/ts-0-root/wals/f57255de3d8e425bbdf9e88a906b4a49/wal-000000028 (ops 133-137)
I20260812 06:20:18.679222 29580 log.cc:1079] T f57255de3d8e425bbdf9e88a906b4a49 P 3ba6fa63bba94351bf8c522fd5eafa1d: Deleting log segment in path: /tmp/dist-test-tasksggqpW/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515609106051-29068-0/minicluster-data/ts-0-root/wals/f57255de3d8e425bbdf9e88a906b4a49/wal-000000029 (ops 138-142)
I20260812 06:20:18.679255 29580 log.cc:1079] T f57255de3d8e425bbdf9e88a906b4a49 P 3ba6fa63bba94351bf8c522fd5eafa1d: Deleting log segment in path: /tmp/dist-test-tasksggqpW/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515609106051-29068-0/minicluster-data/ts-0-root/wals/f57255de3d8e425bbdf9e88a906b4a49/wal-000000030 (ops 143-147)
I20260812 06:20:18.679286 29580 log.cc:1079] T f57255de3d8e425bbdf9e88a906b4a49 P 3ba6fa63bba94351bf8c522fd5eafa1d: Deleting log segment in path: /tmp/dist-test-tasksggqpW/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515609106051-29068-0/minicluster-data/ts-0-root/wals/f57255de3d8e425bbdf9e88a906b4a49/wal-000000031 (ops 148-152)
I20260812 06:20:18.679313 29580 log.cc:1079] T f57255de3d8e425bbdf9e88a906b4a49 P 3ba6fa63bba94351bf8c522fd5eafa1d: Deleting log segment in path: /tmp/dist-test-tasksggqpW/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515609106051-29068-0/minicluster-data/ts-0-root/wals/f57255de3d8e425bbdf9e88a906b4a49/wal-000000032 (ops 153-156)
I20260812 06:20:18.679340 29580 log.cc:1079] T f57255de3d8e425bbdf9e88a906b4a49 P 3ba6fa63bba94351bf8c522fd5eafa1d: Deleting log segment in path: /tmp/dist-test-tasksggqpW/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515609106051-29068-0/minicluster-data/ts-0-root/wals/f57255de3d8e425bbdf9e88a906b4a49/wal-000000033 (ops 157-161)
I20260812 06:20:18.679368 29580 log.cc:1079] T f57255de3d8e425bbdf9e88a906b4a49 P 3ba6fa63bba94351bf8c522fd5eafa1d: Deleting log segment in path: /tmp/dist-test-tasksggqpW/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515609106051-29068-0/minicluster-data/ts-0-root/wals/f57255de3d8e425bbdf9e88a906b4a49/wal-000000034 (ops 162-166)
I20260812 06:20:18.679401 29580 log.cc:1079] T f57255de3d8e425bbdf9e88a906b4a49 P 3ba6fa63bba94351bf8c522fd5eafa1d: Deleting log segment in path: /tmp/dist-test-tasksggqpW/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515609106051-29068-0/minicluster-data/ts-0-root/wals/f57255de3d8e425bbdf9e88a906b4a49/wal-000000035 (ops 167-170)
I20260812 06:20:18.679432 29580 log.cc:1079] T f57255de3d8e425bbdf9e88a906b4a49 P 3ba6fa63bba94351bf8c522fd5eafa1d: Deleting log segment in path: /tmp/dist-test-tasksggqpW/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515609106051-29068-0/minicluster-data/ts-0-root/wals/f57255de3d8e425bbdf9e88a906b4a49/wal-000000036 (ops 171-175)
I20260812 06:20:18.679461 29580 log.cc:1079] T f57255de3d8e425bbdf9e88a906b4a49 P 3ba6fa63bba94351bf8c522fd5eafa1d: Deleting log segment in path: /tmp/dist-test-tasksggqpW/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515609106051-29068-0/minicluster-data/ts-0-root/wals/f57255de3d8e425bbdf9e88a906b4a49/wal-000000037 (ops 176-180)
I20260812 06:20:18.679488 29580 log.cc:1079] T f57255de3d8e425bbdf9e88a906b4a49 P 3ba6fa63bba94351bf8c522fd5eafa1d: Deleting log segment in path: /tmp/dist-test-tasksggqpW/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515609106051-29068-0/minicluster-data/ts-0-root/wals/f57255de3d8e425bbdf9e88a906b4a49/wal-000000038 (ops 181-184)
I20260812 06:20:18.707330 29580 maintenance_manager.cc:643] P 3ba6fa63bba94351bf8c522fd5eafa1d: LogGCOp(f57255de3d8e425bbdf9e88a906b4a49) complete. Timing: real 0.028s	user 0.001s	sys 0.027s Metrics: {}
I20260812 06:20:18.707697 29679 maintenance_manager.cc:419] P 3ba6fa63bba94351bf8c522fd5eafa1d: Scheduling UndoDeltaBlockGCOp(f57255de3d8e425bbdf9e88a906b4a49): 482 bytes on disk
I20260812 06:20:18.708119 29580 maintenance_manager.cc:643] P 3ba6fa63bba94351bf8c522fd5eafa1d: UndoDeltaBlockGCOp(f57255de3d8e425bbdf9e88a906b4a49) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":50,"lbm_reads_lt_1ms":4}
I20260812 06:20:18.708614 29679 maintenance_manager.cc:419] P 3ba6fa63bba94351bf8c522fd5eafa1d: Scheduling FlushDeltaMemStoresOp(f57255de3d8e425bbdf9e88a906b4a49): perf score=3.181125
I20260812 06:20:18.728384 29580 maintenance_manager.cc:643] P 3ba6fa63bba94351bf8c522fd5eafa1d: FlushDeltaMemStoresOp(f57255de3d8e425bbdf9e88a906b4a49) complete. Timing: real 0.020s	user 0.002s	sys 0.015s Metrics: {"bytes_written":4512900,"delete_count":0,"lbm_write_time_us":4101,"lbm_writes_lt_1ms":113,"reinsert_count":0,"spinlock_wait_cycles":28544,"update_count":550}
I20260812 06:20:18.728881 29679 maintenance_manager.cc:419] P 3ba6fa63bba94351bf8c522fd5eafa1d: Scheduling FlushDeltaMemStoresOp(f57255de3d8e425bbdf9e88a906b4a49): perf score=2.188937
I20260812 06:20:18.738581 29580 maintenance_manager.cc:643] P 3ba6fa63bba94351bf8c522fd5eafa1d: FlushDeltaMemStoresOp(f57255de3d8e425bbdf9e88a906b4a49) complete. Timing: real 0.010s	user 0.009s	sys 0.000s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3567,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:20:18.738986 29679 maintenance_manager.cc:419] P 3ba6fa63bba94351bf8c522fd5eafa1d: Scheduling MajorDeltaCompactionOp(f57255de3d8e425bbdf9e88a906b4a49): perf score=1.000000
I20260812 06:20:18.950897 29580 maintenance_manager.cc:643] P 3ba6fa63bba94351bf8c522fd5eafa1d: MajorDeltaCompactionOp(f57255de3d8e425bbdf9e88a906b4a49) complete. Timing: real 0.212s	user 0.123s	sys 0.084s Metrics: {"cfile_cache_miss":734,"cfile_cache_miss_bytes":33020732,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":7660,"dirs.run_cpu_time_us":508,"dirs.run_wall_time_us":2677,"lbm_read_time_us":15239,"lbm_reads_lt_1ms":774,"lbm_write_time_us":34496,"lbm_writes_lt_1ms":743,"mutex_wait_us":3171,"peak_mem_usage":87969044,"reinsert_count":0,"spinlock_wait_cycles":2944,"update_count":3500}
I20260812 06:20:18.951422 29679 maintenance_manager.cc:419] P 3ba6fa63bba94351bf8c522fd5eafa1d: Scheduling FlushDeltaMemStoresOp(f57255de3d8e425bbdf9e88a906b4a49): perf score=15.087375
I20260812 06:20:18.997676 29580 maintenance_manager.cc:643] P 3ba6fa63bba94351bf8c522fd5eafa1d: FlushDeltaMemStoresOp(f57255de3d8e425bbdf9e88a906b4a49) complete. Timing: real 0.046s	user 0.022s	sys 0.020s Metrics: {"bytes_written":16820143,"delete_count":0,"lbm_write_time_us":19053,"lbm_writes_lt_1ms":413,"reinsert_count":0,"update_count":2050}
I20260812 06:20:18.998842 29679 maintenance_manager.cc:419] P 3ba6fa63bba94351bf8c522fd5eafa1d: Scheduling FlushDeltaMemStoresOp(f57255de3d8e425bbdf9e88a906b4a49): perf score=2.188937
I20260812 06:20:19.009925 29580 maintenance_manager.cc:643] P 3ba6fa63bba94351bf8c522fd5eafa1d: FlushDeltaMemStoresOp(f57255de3d8e425bbdf9e88a906b4a49) complete. Timing: real 0.011s	user 0.009s	sys 0.000s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3986,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:20:19.010387 29679 maintenance_manager.cc:419] P 3ba6fa63bba94351bf8c522fd5eafa1d: Scheduling MajorDeltaCompactionOp(f57255de3d8e425bbdf9e88a906b4a49): perf score=1.000000
I20260812 06:20:19.025799 29068 heavy-update-compaction-itest.cc:229] Time spent updating: real 4.679s	user 1.700s	sys 0.199s
I20260812 06:20:19.101090 29068 heavy-update-compaction-itest.cc:265] Time spent scanning: real 0.075s	user 0.001s	sys 0.000s
I20260812 06:20:19.101540 29068 tablet_server.cc:179] TabletServer@127.28.99.1:0 shutting down...
I20260812 06:20:19.158874 29580 maintenance_manager.cc:643] P 3ba6fa63bba94351bf8c522fd5eafa1d: MajorDeltaCompactionOp(f57255de3d8e425bbdf9e88a906b4a49) complete. Timing: real 0.148s	user 0.083s	sys 0.065s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24815671,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":255,"lbm_read_time_us":11578,"lbm_reads_lt_1ms":564,"lbm_write_time_us":24005,"lbm_writes_lt_1ms":543,"mutex_wait_us":24,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":139392,"update_count":2500}
I20260812 06:20:19.159489 29068 ts_tablet_manager.cc:1507] Shutting down tablet manager...
I20260812 06:20:19.159791 29068 tablet_replica.cc:333] T f57255de3d8e425bbdf9e88a906b4a49 P 3ba6fa63bba94351bf8c522fd5eafa1d: stopping tablet replica
I20260812 06:20:19.159919 29068 raft_consensus.cc:2243] T f57255de3d8e425bbdf9e88a906b4a49 P 3ba6fa63bba94351bf8c522fd5eafa1d [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:20:19.160113 29068 raft_consensus.cc:2272] T f57255de3d8e425bbdf9e88a906b4a49 P 3ba6fa63bba94351bf8c522fd5eafa1d [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:20:19.174371 29068 tablet_server.cc:196] TabletServer@127.28.99.1:0 shutdown complete.
I20260812 06:20:19.203680 29068 master.cc:562] Master@127.28.99.62:35255 shutting down...
I20260812 06:20:19.206790 29068 raft_consensus.cc:2243] T 00000000000000000000000000000000 P 633885fd4be94291b9c4f5cad8a933d0 [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:20:19.206984 29068 raft_consensus.cc:2272] T 00000000000000000000000000000000 P 633885fd4be94291b9c4f5cad8a933d0 [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:20:19.207055 29068 tablet_replica.cc:333] T 00000000000000000000000000000000 P 633885fd4be94291b9c4f5cad8a933d0: stopping tablet replica
I20260812 06:20:19.219172 29068 master.cc:584] Master@127.28.99.62:35255 shutdown complete.
[       OK ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/1 (5117 ms)
[----------] 2 tests from EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy (10177 ms total)

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