[==========] 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:06.175896 25448 internal_mini_cluster.cc:156] Creating distributed mini masters. Addrs: 127.24.218.62:45323
I20260812 06:20:06.176968 25448 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:06.177592 25448 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:20:06.184357 25456 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:06.184413 25448 server_base.cc:1061] running on GCE node
W20260812 06:20:06.184535 25458 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:06.184356 25455 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:06.185076 25448 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:20:06.185173 25448 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:06.185204 25448 hybrid_clock.cc:648] HybridClock initialized: now 1786515606185202 us; error 0 us; skew 500 ppm
I20260812 06:20:06.187129 25448 webserver.cc:533] Webserver started at http://127.24.218.62:33425/ using document root <none> and password file <none>
I20260812 06:20:06.187732 25448 fs_manager.cc:362] Metadata directory not provided
I20260812 06:20:06.187791 25448 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:20:06.187990 25448 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:20:06.189608 25448 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskWwF8e7/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515606164878-25448-0/minicluster-data/master-0-root/instance:
uuid: "5a044df8930448e9ad6755fa02848059"
format_stamp: "Formatted at 2026-08-12 06:20:06 on dist-test-slave-chsk"
I20260812 06:20:06.193252 25448 fs_manager.cc:696] Time spent creating directory manager: real 0.003s	user 0.003s	sys 0.003s
I20260812 06:20:06.195421 25463 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:06.196494 25448 fs_manager.cc:730] Time spent opening block manager: real 0.002s	user 0.001s	sys 0.001s
I20260812 06:20:06.196643 25448 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskWwF8e7/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515606164878-25448-0/minicluster-data/master-0-root
uuid: "5a044df8930448e9ad6755fa02848059"
format_stamp: "Formatted at 2026-08-12 06:20:06 on dist-test-slave-chsk"
I20260812 06:20:06.196746 25448 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskWwF8e7/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515606164878-25448-0/minicluster-data/master-0-root
metadata directory: /tmp/dist-test-taskWwF8e7/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515606164878-25448-0/minicluster-data/master-0-root
1 data directories: /tmp/dist-test-taskWwF8e7/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515606164878-25448-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:06.216673 25448 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:20:06.217469 25448 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:06.217656 25448 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:20:06.225551 25448 rpc_server.cc:307] RPC server started. Bound to: 127.24.218.62:45323
I20260812 06:20:06.225621 25520 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.24.218.62:45323 every 8 connection(s)
I20260812 06:20:06.228101 25521 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:06.233664 25521 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P 5a044df8930448e9ad6755fa02848059: Bootstrap starting.
I20260812 06:20:06.236224 25521 tablet_bootstrap.cc:654] T 00000000000000000000000000000000 P 5a044df8930448e9ad6755fa02848059: Neither blocks nor log segments found. Creating new log.
I20260812 06:20:06.237207 25521 log.cc:826] T 00000000000000000000000000000000 P 5a044df8930448e9ad6755fa02848059: Log is configured to *not* fsync() on all Append() calls
I20260812 06:20:06.239008 25521 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P 5a044df8930448e9ad6755fa02848059: No bootstrap required, opened a new log
I20260812 06:20:06.241889 25521 raft_consensus.cc:359] T 00000000000000000000000000000000 P 5a044df8930448e9ad6755fa02848059 [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "5a044df8930448e9ad6755fa02848059" member_type: VOTER }
I20260812 06:20:06.242118 25521 raft_consensus.cc:385] T 00000000000000000000000000000000 P 5a044df8930448e9ad6755fa02848059 [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:20:06.242219 25521 raft_consensus.cc:740] T 00000000000000000000000000000000 P 5a044df8930448e9ad6755fa02848059 [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: 5a044df8930448e9ad6755fa02848059, State: Initialized, Role: FOLLOWER
I20260812 06:20:06.242844 25521 consensus_queue.cc:260] T 00000000000000000000000000000000 P 5a044df8930448e9ad6755fa02848059 [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: "5a044df8930448e9ad6755fa02848059" member_type: VOTER }
I20260812 06:20:06.243032 25521 raft_consensus.cc:399] T 00000000000000000000000000000000 P 5a044df8930448e9ad6755fa02848059 [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:20:06.243119 25521 raft_consensus.cc:493] T 00000000000000000000000000000000 P 5a044df8930448e9ad6755fa02848059 [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:20:06.243288 25521 raft_consensus.cc:3060] T 00000000000000000000000000000000 P 5a044df8930448e9ad6755fa02848059 [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:20:06.244148 25521 raft_consensus.cc:515] T 00000000000000000000000000000000 P 5a044df8930448e9ad6755fa02848059 [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "5a044df8930448e9ad6755fa02848059" member_type: VOTER }
I20260812 06:20:06.244637 25521 leader_election.cc:304] T 00000000000000000000000000000000 P 5a044df8930448e9ad6755fa02848059 [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: 5a044df8930448e9ad6755fa02848059; no voters: 
I20260812 06:20:06.245000 25521 leader_election.cc:290] T 00000000000000000000000000000000 P 5a044df8930448e9ad6755fa02848059 [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:20:06.245188 25524 raft_consensus.cc:2804] T 00000000000000000000000000000000 P 5a044df8930448e9ad6755fa02848059 [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:20:06.245460 25524 raft_consensus.cc:697] T 00000000000000000000000000000000 P 5a044df8930448e9ad6755fa02848059 [term 1 LEADER]: Becoming Leader. State: Replica: 5a044df8930448e9ad6755fa02848059, State: Running, Role: LEADER
I20260812 06:20:06.245949 25524 consensus_queue.cc:237] T 00000000000000000000000000000000 P 5a044df8930448e9ad6755fa02848059 [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: "5a044df8930448e9ad6755fa02848059" member_type: VOTER }
I20260812 06:20:06.246245 25521 sys_catalog.cc:565] T 00000000000000000000000000000000 P 5a044df8930448e9ad6755fa02848059 [sys.catalog]: configured and running, proceeding with master startup.
I20260812 06:20:06.248173 25528 sys_catalog.cc:455] T 00000000000000000000000000000000 P 5a044df8930448e9ad6755fa02848059 [sys.catalog]: SysCatalogTable state changed. Reason: New leader 5a044df8930448e9ad6755fa02848059. Latest consensus state: current_term: 1 leader_uuid: "5a044df8930448e9ad6755fa02848059" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "5a044df8930448e9ad6755fa02848059" member_type: VOTER } }
I20260812 06:20:06.248202 25526 sys_catalog.cc:455] T 00000000000000000000000000000000 P 5a044df8930448e9ad6755fa02848059 [sys.catalog]: SysCatalogTable state changed. Reason: RaftConsensus started. Latest consensus state: current_term: 1 leader_uuid: "5a044df8930448e9ad6755fa02848059" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "5a044df8930448e9ad6755fa02848059" member_type: VOTER } }
I20260812 06:20:06.248335 25528 sys_catalog.cc:458] T 00000000000000000000000000000000 P 5a044df8930448e9ad6755fa02848059 [sys.catalog]: This master's current role is: LEADER
I20260812 06:20:06.248334 25526 sys_catalog.cc:458] T 00000000000000000000000000000000 P 5a044df8930448e9ad6755fa02848059 [sys.catalog]: This master's current role is: LEADER
I20260812 06:20:06.248752 25448 internal_mini_cluster.cc:184] Waiting to initialize catalog manager on master 0
I20260812 06:20:06.248798 25541 catalog_manager.cc:1511] Loading table and tablet metadata into memory...
I20260812 06:20:06.251130 25541 catalog_manager.cc:1520] Initializing Kudu cluster ID...
I20260812 06:20:06.256310 25541 catalog_manager.cc:1383] Generated new cluster ID: 92e712896d6146f1853ca883841b0545
I20260812 06:20:06.256393 25541 catalog_manager.cc:1531] Initializing Kudu internal certificate authority...
I20260812 06:20:06.283420 25541 catalog_manager.cc:1406] Generated new certificate authority record
I20260812 06:20:06.284487 25541 catalog_manager.cc:1540] Loading token signing keys...
I20260812 06:20:06.293284 25541 catalog_manager.cc:6092] T 00000000000000000000000000000000 P 5a044df8930448e9ad6755fa02848059: Generated new TSK 0
I20260812 06:20:06.293998 25541 catalog_manager.cc:1550] Initializing in-progress tserver states...
I20260812 06:20:06.313706 25448 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:20:06.316623 25550 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:06.316627 25546 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:06.316713 25548 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:06.317005 25448 server_base.cc:1061] running on GCE node
I20260812 06:20:06.317207 25448 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:20:06.317263 25448 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:06.317289 25448 hybrid_clock.cc:648] HybridClock initialized: now 1786515606317289 us; error 0 us; skew 500 ppm
I20260812 06:20:06.318339 25448 webserver.cc:533] Webserver started at http://127.24.218.1:34905/ using document root <none> and password file <none>
I20260812 06:20:06.318534 25448 fs_manager.cc:362] Metadata directory not provided
I20260812 06:20:06.318610 25448 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:20:06.318693 25448 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:20:06.319094 25448 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskWwF8e7/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515606164878-25448-0/minicluster-data/ts-0-root/instance:
uuid: "d33f733e904649f883838ef50a2d1e5c"
format_stamp: "Formatted at 2026-08-12 06:20:06 on dist-test-slave-chsk"
I20260812 06:20:06.320744 25448 fs_manager.cc:696] Time spent creating directory manager: real 0.001s	user 0.001s	sys 0.000s
I20260812 06:20:06.321761 25556 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:06.322029 25448 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.001s	sys 0.000s
I20260812 06:20:06.322105 25448 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskWwF8e7/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515606164878-25448-0/minicluster-data/ts-0-root
uuid: "d33f733e904649f883838ef50a2d1e5c"
format_stamp: "Formatted at 2026-08-12 06:20:06 on dist-test-slave-chsk"
I20260812 06:20:06.322199 25448 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskWwF8e7/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515606164878-25448-0/minicluster-data/ts-0-root
metadata directory: /tmp/dist-test-taskWwF8e7/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515606164878-25448-0/minicluster-data/ts-0-root
1 data directories: /tmp/dist-test-taskWwF8e7/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515606164878-25448-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:06.342005 25448 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:20:06.342939 25448 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:20:06.343550 25448 txn_system_client.cc:432] TxnSystemClient initialization is disabled...
I20260812 06:20:06.344532 25448 ts_tablet_manager.cc:585] Loaded tablet metadata (0 total tablets, 0 live tablets)
I20260812 06:20:06.344585 25448 ts_tablet_manager.cc:531] Time spent load tablet metadata: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:20:06.344661 25448 ts_tablet_manager.cc:616] Registered 0 tablets
I20260812 06:20:06.344708 25448 ts_tablet_manager.cc:595] Time spent register tablets: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:20:06.351730 25448 rpc_server.cc:307] RPC server started. Bound to: 127.24.218.1:43339
I20260812 06:20:06.351796 25630 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.24.218.1:43339 every 8 connection(s)
I20260812 06:20:06.365724 25632 heartbeater.cc:344] Connected to a master server at 127.24.218.62:45323
I20260812 06:20:06.366024 25632 heartbeater.cc:461] Registering TS with master...
I20260812 06:20:06.366523 25632 heartbeater.cc:507] Master 127.24.218.62:45323 requested a full tablet report, sending...
I20260812 06:20:06.368181 25482 ts_manager.cc:194] Registered new tserver with Master: d33f733e904649f883838ef50a2d1e5c (127.24.218.1:43339)
I20260812 06:20:06.368314 25448 internal_mini_cluster.cc:371] 1 TS(s) registered with all masters after 0.015922449s
I20260812 06:20:06.369768 25482 master_service.cc:502] Signed X509 certificate for tserver {username='slave'} at 127.0.0.1:35600
I20260812 06:20:06.378643 25482 catalog_manager.cc:2283] Servicing CreateTable request from {username='slave'} at 127.0.0.1:35610:
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:06.392849 25589 tablet_service.cc:1511] Processing CreateTablet for tablet dbee8380ae9346099c13cdc92c909ae7 (DEFAULT_TABLE table=heavy-update-compaction-test [id=c98dc3a1efad45f7a14c683be755f3b2]), partition=
I20260812 06:20:06.393324 25589 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet dbee8380ae9346099c13cdc92c909ae7. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:20:06.396019 25647 tablet_bootstrap.cc:492] T dbee8380ae9346099c13cdc92c909ae7 P d33f733e904649f883838ef50a2d1e5c: Bootstrap starting.
I20260812 06:20:06.397460 25647 tablet_bootstrap.cc:654] T dbee8380ae9346099c13cdc92c909ae7 P d33f733e904649f883838ef50a2d1e5c: Neither blocks nor log segments found. Creating new log.
I20260812 06:20:06.398856 25647 tablet_bootstrap.cc:492] T dbee8380ae9346099c13cdc92c909ae7 P d33f733e904649f883838ef50a2d1e5c: No bootstrap required, opened a new log
I20260812 06:20:06.398949 25647 ts_tablet_manager.cc:1403] T dbee8380ae9346099c13cdc92c909ae7 P d33f733e904649f883838ef50a2d1e5c: Time spent bootstrapping tablet: real 0.003s	user 0.002s	sys 0.000s
I20260812 06:20:06.399531 25647 raft_consensus.cc:359] T dbee8380ae9346099c13cdc92c909ae7 P d33f733e904649f883838ef50a2d1e5c [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "d33f733e904649f883838ef50a2d1e5c" member_type: VOTER last_known_addr { host: "127.24.218.1" port: 43339 } }
I20260812 06:20:06.399641 25647 raft_consensus.cc:385] T dbee8380ae9346099c13cdc92c909ae7 P d33f733e904649f883838ef50a2d1e5c [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:20:06.399667 25647 raft_consensus.cc:740] T dbee8380ae9346099c13cdc92c909ae7 P d33f733e904649f883838ef50a2d1e5c [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: d33f733e904649f883838ef50a2d1e5c, State: Initialized, Role: FOLLOWER
I20260812 06:20:06.399832 25647 consensus_queue.cc:260] T dbee8380ae9346099c13cdc92c909ae7 P d33f733e904649f883838ef50a2d1e5c [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: "d33f733e904649f883838ef50a2d1e5c" member_type: VOTER last_known_addr { host: "127.24.218.1" port: 43339 } }
I20260812 06:20:06.399904 25647 raft_consensus.cc:399] T dbee8380ae9346099c13cdc92c909ae7 P d33f733e904649f883838ef50a2d1e5c [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:20:06.399951 25647 raft_consensus.cc:493] T dbee8380ae9346099c13cdc92c909ae7 P d33f733e904649f883838ef50a2d1e5c [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:20:06.400010 25647 raft_consensus.cc:3060] T dbee8380ae9346099c13cdc92c909ae7 P d33f733e904649f883838ef50a2d1e5c [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:20:06.400915 25647 raft_consensus.cc:515] T dbee8380ae9346099c13cdc92c909ae7 P d33f733e904649f883838ef50a2d1e5c [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "d33f733e904649f883838ef50a2d1e5c" member_type: VOTER last_known_addr { host: "127.24.218.1" port: 43339 } }
I20260812 06:20:06.401083 25647 leader_election.cc:304] T dbee8380ae9346099c13cdc92c909ae7 P d33f733e904649f883838ef50a2d1e5c [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: d33f733e904649f883838ef50a2d1e5c; no voters: 
I20260812 06:20:06.401338 25647 leader_election.cc:290] T dbee8380ae9346099c13cdc92c909ae7 P d33f733e904649f883838ef50a2d1e5c [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:20:06.401451 25649 raft_consensus.cc:2804] T dbee8380ae9346099c13cdc92c909ae7 P d33f733e904649f883838ef50a2d1e5c [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:20:06.401757 25649 raft_consensus.cc:697] T dbee8380ae9346099c13cdc92c909ae7 P d33f733e904649f883838ef50a2d1e5c [term 1 LEADER]: Becoming Leader. State: Replica: d33f733e904649f883838ef50a2d1e5c, State: Running, Role: LEADER
I20260812 06:20:06.401793 25647 ts_tablet_manager.cc:1434] T dbee8380ae9346099c13cdc92c909ae7 P d33f733e904649f883838ef50a2d1e5c: Time spent starting tablet: real 0.003s	user 0.003s	sys 0.000s
I20260812 06:20:06.402248 25632 heartbeater.cc:499] Master 127.24.218.62:45323 was elected leader, sending a full tablet report...
I20260812 06:20:06.402226 25649 consensus_queue.cc:237] T dbee8380ae9346099c13cdc92c909ae7 P d33f733e904649f883838ef50a2d1e5c [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: "d33f733e904649f883838ef50a2d1e5c" member_type: VOTER last_known_addr { host: "127.24.218.1" port: 43339 } }
I20260812 06:20:06.405222 25482 catalog_manager.cc:5719] T dbee8380ae9346099c13cdc92c909ae7 P d33f733e904649f883838ef50a2d1e5c reported cstate change: term changed from 0 to 1, leader changed from <none> to d33f733e904649f883838ef50a2d1e5c (127.24.218.1). New cstate: current_term: 1 leader_uuid: "d33f733e904649f883838ef50a2d1e5c" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "d33f733e904649f883838ef50a2d1e5c" member_type: VOTER last_known_addr { host: "127.24.218.1" port: 43339 } health_report { overall_health: HEALTHY } } }
I20260812 06:20:06.470829 25448 heavy-update-compaction-itest.cc:215] Time spent inserting: real 0.056s	user 0.017s	sys 0.008s
I20260812 06:20:06.603029 25633 maintenance_manager.cc:419] P d33f733e904649f883838ef50a2d1e5c: Scheduling FlushMRSOp(dbee8380ae9346099c13cdc92c909ae7): perf score=15.086190
I20260812 06:20:06.766492 25563 maintenance_manager.cc:643] P d33f733e904649f883838ef50a2d1e5c: FlushMRSOp(dbee8380ae9346099c13cdc92c909ae7) complete. Timing: real 0.163s	user 0.107s	sys 0.052s Metrics: {"bytes_written":8615323,"cfile_init":1,"compiler_manager_pool.queue_time_us":736,"delete_count":0,"dirs.queue_time_us":51,"dirs.run_cpu_time_us":189,"dirs.run_wall_time_us":975,"drs_written":1,"lbm_read_time_us":90,"lbm_reads_lt_1ms":4,"lbm_write_time_us":39001,"lbm_writes_lt_1ms":667,"peak_mem_usage":0,"reinsert_count":0,"rows_written":104,"thread_start_us":133,"threads_started":1,"update_count":1050}
I20260812 06:20:06.767851 25633 maintenance_manager.cc:419] P d33f733e904649f883838ef50a2d1e5c: Scheduling LogGCOp(dbee8380ae9346099c13cdc92c909ae7): free 20743880 bytes of WAL
I20260812 06:20:06.768220 25563 log_reader.cc:385] T dbee8380ae9346099c13cdc92c909ae7: removed 2 log segments from log reader
I20260812 06:20:06.768308 25563 log.cc:1079] T dbee8380ae9346099c13cdc92c909ae7 P d33f733e904649f883838ef50a2d1e5c: Deleting log segment in path: /tmp/dist-test-taskWwF8e7/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515606164878-25448-0/minicluster-data/ts-0-root/wals/dbee8380ae9346099c13cdc92c909ae7/wal-000000001 (ops 1-6)
I20260812 06:20:06.768399 25563 log.cc:1079] T dbee8380ae9346099c13cdc92c909ae7 P d33f733e904649f883838ef50a2d1e5c: Deleting log segment in path: /tmp/dist-test-taskWwF8e7/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515606164878-25448-0/minicluster-data/ts-0-root/wals/dbee8380ae9346099c13cdc92c909ae7/wal-000000002 (ops 7-11)
I20260812 06:20:06.773313 25563 maintenance_manager.cc:643] P d33f733e904649f883838ef50a2d1e5c: LogGCOp(dbee8380ae9346099c13cdc92c909ae7) complete. Timing: real 0.005s	user 0.000s	sys 0.003s Metrics: {}
I20260812 06:20:06.773834 25633 maintenance_manager.cc:419] P d33f733e904649f883838ef50a2d1e5c: Scheduling UndoDeltaBlockGCOp(dbee8380ae9346099c13cdc92c909ae7): 16411392 bytes on disk
I20260812 06:20:06.774874 25563 maintenance_manager.cc:643] P d33f733e904649f883838ef50a2d1e5c: UndoDeltaBlockGCOp(dbee8380ae9346099c13cdc92c909ae7) complete. Timing: real 0.001s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":145,"lbm_reads_lt_1ms":4}
I20260812 06:20:06.775566 25633 maintenance_manager.cc:419] P d33f733e904649f883838ef50a2d1e5c: Scheduling FlushDeltaMemStoresOp(dbee8380ae9346099c13cdc92c909ae7): perf score=2.188937
I20260812 06:20:06.802116 25563 maintenance_manager.cc:643] P d33f733e904649f883838ef50a2d1e5c: FlushDeltaMemStoresOp(dbee8380ae9346099c13cdc92c909ae7) complete. Timing: real 0.026s	user 0.003s	sys 0.010s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":5656,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:20:06.802585 25633 maintenance_manager.cc:419] P d33f733e904649f883838ef50a2d1e5c: Scheduling FlushDeltaMemStoresOp(dbee8380ae9346099c13cdc92c909ae7): perf score=2.188937
I20260812 06:20:06.816049 25563 maintenance_manager.cc:643] P d33f733e904649f883838ef50a2d1e5c: FlushDeltaMemStoresOp(dbee8380ae9346099c13cdc92c909ae7) complete. Timing: real 0.013s	user 0.007s	sys 0.005s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5128,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:06.816495 25633 maintenance_manager.cc:419] P d33f733e904649f883838ef50a2d1e5c: Scheduling MajorDeltaCompactionOp(dbee8380ae9346099c13cdc92c909ae7): perf score=1.000000
I20260812 06:20:06.961897 25563 maintenance_manager.cc:643] P d33f733e904649f883838ef50a2d1e5c: MajorDeltaCompactionOp(dbee8380ae9346099c13cdc92c909ae7) complete. Timing: real 0.145s	user 0.087s	sys 0.050s Metrics: {"cfile_cache_miss":433,"cfile_cache_miss_bytes":20672387,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":1064,"lbm_read_time_us":9094,"lbm_reads_lt_1ms":469,"lbm_write_time_us":24477,"lbm_writes_lt_1ms":443,"mutex_wait_us":286,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":1536,"thread_start_us":354,"threads_started":5,"update_count":2000}
I20260812 06:20:06.962568 25633 maintenance_manager.cc:419] P d33f733e904649f883838ef50a2d1e5c: Scheduling FlushDeltaMemStoresOp(dbee8380ae9346099c13cdc92c909ae7): perf score=10.126437
I20260812 06:20:07.006227 25563 maintenance_manager.cc:643] P d33f733e904649f883838ef50a2d1e5c: FlushDeltaMemStoresOp(dbee8380ae9346099c13cdc92c909ae7) complete. Timing: real 0.043s	user 0.018s	sys 0.019s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":19207,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":302,"reinsert_count":0,"update_count":1500}
I20260812 06:20:07.006764 25633 maintenance_manager.cc:419] P d33f733e904649f883838ef50a2d1e5c: Scheduling FlushDeltaMemStoresOp(dbee8380ae9346099c13cdc92c909ae7): perf score=2.188937
I20260812 06:20:07.017813 25563 maintenance_manager.cc:643] P d33f733e904649f883838ef50a2d1e5c: FlushDeltaMemStoresOp(dbee8380ae9346099c13cdc92c909ae7) complete. Timing: real 0.011s	user 0.009s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4151,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:07.018587 25633 maintenance_manager.cc:419] P d33f733e904649f883838ef50a2d1e5c: Scheduling MajorDeltaCompactionOp(dbee8380ae9346099c13cdc92c909ae7): perf score=1.000000
I20260812 06:20:07.144655 25563 maintenance_manager.cc:643] P d33f733e904649f883838ef50a2d1e5c: MajorDeltaCompactionOp(dbee8380ae9346099c13cdc92c909ae7) complete. Timing: real 0.126s	user 0.088s	sys 0.038s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672277,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":426,"lbm_read_time_us":9450,"lbm_reads_lt_1ms":472,"lbm_write_time_us":23912,"lbm_writes_lt_1ms":443,"mutex_wait_us":110,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":2176,"update_count":2000}
I20260812 06:20:07.145267 25633 maintenance_manager.cc:419] P d33f733e904649f883838ef50a2d1e5c: Scheduling FlushDeltaMemStoresOp(dbee8380ae9346099c13cdc92c909ae7): perf score=10.126437
I20260812 06:20:07.190518 25563 maintenance_manager.cc:643] P d33f733e904649f883838ef50a2d1e5c: FlushDeltaMemStoresOp(dbee8380ae9346099c13cdc92c909ae7) complete. Timing: real 0.045s	user 0.011s	sys 0.017s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":13855,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:20:07.191102 25633 maintenance_manager.cc:419] P d33f733e904649f883838ef50a2d1e5c: Scheduling FlushDeltaMemStoresOp(dbee8380ae9346099c13cdc92c909ae7): perf score=2.188937
I20260812 06:20:07.206902 25563 maintenance_manager.cc:643] P d33f733e904649f883838ef50a2d1e5c: FlushDeltaMemStoresOp(dbee8380ae9346099c13cdc92c909ae7) complete. Timing: real 0.016s	user 0.008s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5834,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:07.207650 25633 maintenance_manager.cc:419] P d33f733e904649f883838ef50a2d1e5c: Scheduling MajorDeltaCompactionOp(dbee8380ae9346099c13cdc92c909ae7): perf score=1.000000
I20260812 06:20:07.329875 25563 maintenance_manager.cc:643] P d33f733e904649f883838ef50a2d1e5c: MajorDeltaCompactionOp(dbee8380ae9346099c13cdc92c909ae7) complete. Timing: real 0.122s	user 0.097s	sys 0.025s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672277,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":1452,"lbm_read_time_us":8324,"lbm_reads_lt_1ms":472,"lbm_write_time_us":23104,"lbm_writes_lt_1ms":443,"mutex_wait_us":285,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":1792,"update_count":2000}
I20260812 06:20:07.330432 25633 maintenance_manager.cc:419] P d33f733e904649f883838ef50a2d1e5c: Scheduling FlushDeltaMemStoresOp(dbee8380ae9346099c13cdc92c909ae7): perf score=10.126437
I20260812 06:20:07.382688 25563 maintenance_manager.cc:643] P d33f733e904649f883838ef50a2d1e5c: FlushDeltaMemStoresOp(dbee8380ae9346099c13cdc92c909ae7) complete. Timing: real 0.052s	user 0.023s	sys 0.014s Metrics: {"bytes_written":12307491,"delete_count":0,"lbm_write_time_us":14614,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:20:07.383404 25633 maintenance_manager.cc:419] P d33f733e904649f883838ef50a2d1e5c: Scheduling FlushDeltaMemStoresOp(dbee8380ae9346099c13cdc92c909ae7): perf score=2.188937
I20260812 06:20:07.402455 25563 maintenance_manager.cc:643] P d33f733e904649f883838ef50a2d1e5c: FlushDeltaMemStoresOp(dbee8380ae9346099c13cdc92c909ae7) complete. Timing: real 0.019s	user 0.016s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":7217,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:07.403059 25633 maintenance_manager.cc:419] P d33f733e904649f883838ef50a2d1e5c: Scheduling MajorDeltaCompactionOp(dbee8380ae9346099c13cdc92c909ae7): perf score=1.000000
I20260812 06:20:07.548097 25563 maintenance_manager.cc:643] P d33f733e904649f883838ef50a2d1e5c: MajorDeltaCompactionOp(dbee8380ae9346099c13cdc92c909ae7) complete. Timing: real 0.145s	user 0.120s	sys 0.024s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672278,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":909,"lbm_read_time_us":11220,"lbm_reads_lt_1ms":472,"lbm_write_time_us":24338,"lbm_writes_lt_1ms":443,"mutex_wait_us":334,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":9856,"update_count":2000}
I20260812 06:20:07.548624 25633 maintenance_manager.cc:419] P d33f733e904649f883838ef50a2d1e5c: Scheduling FlushDeltaMemStoresOp(dbee8380ae9346099c13cdc92c909ae7): perf score=10.126437
I20260812 06:20:07.596612 25563 maintenance_manager.cc:643] P d33f733e904649f883838ef50a2d1e5c: FlushDeltaMemStoresOp(dbee8380ae9346099c13cdc92c909ae7) complete. Timing: real 0.048s	user 0.025s	sys 0.007s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":14942,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:20:07.597159 25633 maintenance_manager.cc:419] P d33f733e904649f883838ef50a2d1e5c: Scheduling FlushDeltaMemStoresOp(dbee8380ae9346099c13cdc92c909ae7): perf score=2.188937
I20260812 06:20:07.609390 25563 maintenance_manager.cc:643] P d33f733e904649f883838ef50a2d1e5c: FlushDeltaMemStoresOp(dbee8380ae9346099c13cdc92c909ae7) complete. Timing: real 0.012s	user 0.005s	sys 0.005s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4769,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:07.610082 25633 maintenance_manager.cc:419] P d33f733e904649f883838ef50a2d1e5c: Scheduling MajorDeltaCompactionOp(dbee8380ae9346099c13cdc92c909ae7): perf score=1.000000
I20260812 06:20:07.735862 25563 maintenance_manager.cc:643] P d33f733e904649f883838ef50a2d1e5c: MajorDeltaCompactionOp(dbee8380ae9346099c13cdc92c909ae7) complete. Timing: real 0.126s	user 0.097s	sys 0.028s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672277,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":918,"lbm_read_time_us":10156,"lbm_reads_lt_1ms":472,"lbm_write_time_us":22425,"lbm_writes_lt_1ms":443,"mutex_wait_us":313,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":1792,"update_count":2000}
I20260812 06:20:07.736400 25633 maintenance_manager.cc:419] P d33f733e904649f883838ef50a2d1e5c: Scheduling FlushDeltaMemStoresOp(dbee8380ae9346099c13cdc92c909ae7): perf score=10.126437
I20260812 06:20:07.780289 25563 maintenance_manager.cc:643] P d33f733e904649f883838ef50a2d1e5c: FlushDeltaMemStoresOp(dbee8380ae9346099c13cdc92c909ae7) complete. Timing: real 0.044s	user 0.023s	sys 0.016s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":17644,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:20:07.780800 25633 maintenance_manager.cc:419] P d33f733e904649f883838ef50a2d1e5c: Scheduling FlushDeltaMemStoresOp(dbee8380ae9346099c13cdc92c909ae7): perf score=2.188937
I20260812 06:20:07.793221 25563 maintenance_manager.cc:643] P d33f733e904649f883838ef50a2d1e5c: FlushDeltaMemStoresOp(dbee8380ae9346099c13cdc92c909ae7) complete. Timing: real 0.012s	user 0.010s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4447,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:07.793742 25633 maintenance_manager.cc:419] P d33f733e904649f883838ef50a2d1e5c: Scheduling MajorDeltaCompactionOp(dbee8380ae9346099c13cdc92c909ae7): perf score=1.000000
I20260812 06:20:07.922927 25563 maintenance_manager.cc:643] P d33f733e904649f883838ef50a2d1e5c: MajorDeltaCompactionOp(dbee8380ae9346099c13cdc92c909ae7) complete. Timing: real 0.129s	user 0.097s	sys 0.032s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672277,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":243,"lbm_read_time_us":9548,"lbm_reads_lt_1ms":472,"lbm_write_time_us":23994,"lbm_writes_lt_1ms":443,"mutex_wait_us":47,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":896,"update_count":2000}
I20260812 06:20:07.923739 25633 maintenance_manager.cc:419] P d33f733e904649f883838ef50a2d1e5c: Scheduling FlushDeltaMemStoresOp(dbee8380ae9346099c13cdc92c909ae7): perf score=10.126437
I20260812 06:20:07.967202 25563 maintenance_manager.cc:643] P d33f733e904649f883838ef50a2d1e5c: FlushDeltaMemStoresOp(dbee8380ae9346099c13cdc92c909ae7) complete. Timing: real 0.043s	user 0.015s	sys 0.020s Metrics: {"bytes_written":12307489,"delete_count":0,"lbm_write_time_us":16539,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:20:07.967716 25633 maintenance_manager.cc:419] P d33f733e904649f883838ef50a2d1e5c: Scheduling FlushDeltaMemStoresOp(dbee8380ae9346099c13cdc92c909ae7): perf score=2.188937
I20260812 06:20:07.983958 25563 maintenance_manager.cc:643] P d33f733e904649f883838ef50a2d1e5c: FlushDeltaMemStoresOp(dbee8380ae9346099c13cdc92c909ae7) complete. Timing: real 0.016s	user 0.015s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5971,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:07.984791 25633 maintenance_manager.cc:419] P d33f733e904649f883838ef50a2d1e5c: Scheduling FlushMRSOp(dbee8380ae9346099c13cdc92c909ae7): perf score=1.000000
I20260812 06:20:08.014300 25563 maintenance_manager.cc:643] P d33f733e904649f883838ef50a2d1e5c: FlushMRSOp(dbee8380ae9346099c13cdc92c909ae7) complete. Timing: real 0.029s	user 0.022s	sys 0.004s Metrics: {"bytes_written":1152508,"cfile_init":1,"dirs.queue_time_us":109,"dirs.run_cpu_time_us":287,"dirs.run_wall_time_us":1548,"drs_written":1,"lbm_read_time_us":39,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1687,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":28}
I20260812 06:20:08.015203 25633 maintenance_manager.cc:419] P d33f733e904649f883838ef50a2d1e5c: Scheduling LogGCOp(dbee8380ae9346099c13cdc92c909ae7): free 112239304 bytes of WAL
I20260812 06:20:08.015484 25563 log_reader.cc:385] T dbee8380ae9346099c13cdc92c909ae7: removed 11 log segments from log reader
I20260812 06:20:08.015558 25563 log.cc:1079] T dbee8380ae9346099c13cdc92c909ae7 P d33f733e904649f883838ef50a2d1e5c: Deleting log segment in path: /tmp/dist-test-taskWwF8e7/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515606164878-25448-0/minicluster-data/ts-0-root/wals/dbee8380ae9346099c13cdc92c909ae7/wal-000000003 (ops 12-16)
I20260812 06:20:08.015602 25563 log.cc:1079] T dbee8380ae9346099c13cdc92c909ae7 P d33f733e904649f883838ef50a2d1e5c: Deleting log segment in path: /tmp/dist-test-taskWwF8e7/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515606164878-25448-0/minicluster-data/ts-0-root/wals/dbee8380ae9346099c13cdc92c909ae7/wal-000000004 (ops 17-20)
I20260812 06:20:08.015628 25563 log.cc:1079] T dbee8380ae9346099c13cdc92c909ae7 P d33f733e904649f883838ef50a2d1e5c: Deleting log segment in path: /tmp/dist-test-taskWwF8e7/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515606164878-25448-0/minicluster-data/ts-0-root/wals/dbee8380ae9346099c13cdc92c909ae7/wal-000000005 (ops 21-25)
I20260812 06:20:08.015671 25563 log.cc:1079] T dbee8380ae9346099c13cdc92c909ae7 P d33f733e904649f883838ef50a2d1e5c: Deleting log segment in path: /tmp/dist-test-taskWwF8e7/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515606164878-25448-0/minicluster-data/ts-0-root/wals/dbee8380ae9346099c13cdc92c909ae7/wal-000000006 (ops 26-30)
I20260812 06:20:08.015693 25563 log.cc:1079] T dbee8380ae9346099c13cdc92c909ae7 P d33f733e904649f883838ef50a2d1e5c: Deleting log segment in path: /tmp/dist-test-taskWwF8e7/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515606164878-25448-0/minicluster-data/ts-0-root/wals/dbee8380ae9346099c13cdc92c909ae7/wal-000000007 (ops 31-35)
I20260812 06:20:08.015715 25563 log.cc:1079] T dbee8380ae9346099c13cdc92c909ae7 P d33f733e904649f883838ef50a2d1e5c: Deleting log segment in path: /tmp/dist-test-taskWwF8e7/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515606164878-25448-0/minicluster-data/ts-0-root/wals/dbee8380ae9346099c13cdc92c909ae7/wal-000000008 (ops 36-40)
I20260812 06:20:08.015749 25563 log.cc:1079] T dbee8380ae9346099c13cdc92c909ae7 P d33f733e904649f883838ef50a2d1e5c: Deleting log segment in path: /tmp/dist-test-taskWwF8e7/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515606164878-25448-0/minicluster-data/ts-0-root/wals/dbee8380ae9346099c13cdc92c909ae7/wal-000000009 (ops 41-45)
I20260812 06:20:08.015776 25563 log.cc:1079] T dbee8380ae9346099c13cdc92c909ae7 P d33f733e904649f883838ef50a2d1e5c: Deleting log segment in path: /tmp/dist-test-taskWwF8e7/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515606164878-25448-0/minicluster-data/ts-0-root/wals/dbee8380ae9346099c13cdc92c909ae7/wal-000000010 (ops 46-50)
I20260812 06:20:08.015805 25563 log.cc:1079] T dbee8380ae9346099c13cdc92c909ae7 P d33f733e904649f883838ef50a2d1e5c: Deleting log segment in path: /tmp/dist-test-taskWwF8e7/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515606164878-25448-0/minicluster-data/ts-0-root/wals/dbee8380ae9346099c13cdc92c909ae7/wal-000000011 (ops 51-55)
I20260812 06:20:08.015828 25563 log.cc:1079] T dbee8380ae9346099c13cdc92c909ae7 P d33f733e904649f883838ef50a2d1e5c: Deleting log segment in path: /tmp/dist-test-taskWwF8e7/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515606164878-25448-0/minicluster-data/ts-0-root/wals/dbee8380ae9346099c13cdc92c909ae7/wal-000000012 (ops 56-60)
I20260812 06:20:08.015857 25563 log.cc:1079] T dbee8380ae9346099c13cdc92c909ae7 P d33f733e904649f883838ef50a2d1e5c: Deleting log segment in path: /tmp/dist-test-taskWwF8e7/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515606164878-25448-0/minicluster-data/ts-0-root/wals/dbee8380ae9346099c13cdc92c909ae7/wal-000000013 (ops 61-65)
I20260812 06:20:08.043882 25563 maintenance_manager.cc:643] P d33f733e904649f883838ef50a2d1e5c: LogGCOp(dbee8380ae9346099c13cdc92c909ae7) complete. Timing: real 0.028s	user 0.000s	sys 0.028s Metrics: {}
I20260812 06:20:08.044368 25633 maintenance_manager.cc:419] P d33f733e904649f883838ef50a2d1e5c: Scheduling FlushDeltaMemStoresOp(dbee8380ae9346099c13cdc92c909ae7): perf score=2.188937
I20260812 06:20:08.072603 25563 maintenance_manager.cc:643] P d33f733e904649f883838ef50a2d1e5c: FlushDeltaMemStoresOp(dbee8380ae9346099c13cdc92c909ae7) complete. Timing: real 0.028s	user 0.009s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5839,"lbm_writes_lt_1ms":103,"reinsert_count":0,"spinlock_wait_cycles":2944,"update_count":500}
I20260812 06:20:08.073120 25633 maintenance_manager.cc:419] P d33f733e904649f883838ef50a2d1e5c: Scheduling UndoDeltaBlockGCOp(dbee8380ae9346099c13cdc92c909ae7): 448 bytes on disk
I20260812 06:20:08.073699 25563 maintenance_manager.cc:643] P d33f733e904649f883838ef50a2d1e5c: UndoDeltaBlockGCOp(dbee8380ae9346099c13cdc92c909ae7) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":74,"lbm_reads_lt_1ms":4}
I20260812 06:20:08.074204 25633 maintenance_manager.cc:419] P d33f733e904649f883838ef50a2d1e5c: Scheduling FlushDeltaMemStoresOp(dbee8380ae9346099c13cdc92c909ae7): perf score=2.188937
I20260812 06:20:08.085886 25563 maintenance_manager.cc:643] P d33f733e904649f883838ef50a2d1e5c: FlushDeltaMemStoresOp(dbee8380ae9346099c13cdc92c909ae7) complete. Timing: real 0.012s	user 0.006s	sys 0.003s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4267,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:08.086537 25633 maintenance_manager.cc:419] P d33f733e904649f883838ef50a2d1e5c: Scheduling MajorDeltaCompactionOp(dbee8380ae9346099c13cdc92c909ae7): perf score=1.000000
I20260812 06:20:08.267436 25563 maintenance_manager.cc:643] P d33f733e904649f883838ef50a2d1e5c: MajorDeltaCompactionOp(dbee8380ae9346099c13cdc92c909ae7) complete. Timing: real 0.181s	user 0.146s	sys 0.025s Metrics: {"cfile_cache_miss":634,"cfile_cache_miss_bytes":28877338,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":1037,"lbm_read_time_us":12027,"lbm_reads_lt_1ms":674,"lbm_write_time_us":35343,"lbm_writes_lt_1ms":643,"mutex_wait_us":328,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":14976,"thread_start_us":101,"threads_started":1,"update_count":3000}
I20260812 06:20:08.268347 25633 maintenance_manager.cc:419] P d33f733e904649f883838ef50a2d1e5c: Scheduling FlushDeltaMemStoresOp(dbee8380ae9346099c13cdc92c909ae7): perf score=14.095187
I20260812 06:20:08.325263 25563 maintenance_manager.cc:643] P d33f733e904649f883838ef50a2d1e5c: FlushDeltaMemStoresOp(dbee8380ae9346099c13cdc92c909ae7) complete. Timing: real 0.057s	user 0.019s	sys 0.033s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":24063,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:20:08.325747 25633 maintenance_manager.cc:419] P d33f733e904649f883838ef50a2d1e5c: Scheduling FlushDeltaMemStoresOp(dbee8380ae9346099c13cdc92c909ae7): perf score=2.188937
I20260812 06:20:08.337466 25563 maintenance_manager.cc:643] P d33f733e904649f883838ef50a2d1e5c: FlushDeltaMemStoresOp(dbee8380ae9346099c13cdc92c909ae7) complete. Timing: real 0.012s	user 0.005s	sys 0.005s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4145,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:08.337975 25633 maintenance_manager.cc:419] P d33f733e904649f883838ef50a2d1e5c: Scheduling MajorDeltaCompactionOp(dbee8380ae9346099c13cdc92c909ae7): perf score=1.000000
I20260812 06:20:08.504256 25563 maintenance_manager.cc:643] P d33f733e904649f883838ef50a2d1e5c: MajorDeltaCompactionOp(dbee8380ae9346099c13cdc92c909ae7) complete. Timing: real 0.166s	user 0.131s	sys 0.017s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774687,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":224,"lbm_read_time_us":8735,"lbm_reads_lt_1ms":572,"lbm_write_time_us":30764,"lbm_writes_lt_1ms":543,"mutex_wait_us":74,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":16000,"update_count":2500}
I20260812 06:20:08.508026 25633 maintenance_manager.cc:419] P d33f733e904649f883838ef50a2d1e5c: Scheduling FlushDeltaMemStoresOp(dbee8380ae9346099c13cdc92c909ae7): perf score=14.095187
I20260812 06:20:08.564236 25563 maintenance_manager.cc:643] P d33f733e904649f883838ef50a2d1e5c: FlushDeltaMemStoresOp(dbee8380ae9346099c13cdc92c909ae7) complete. Timing: real 0.056s	user 0.030s	sys 0.016s Metrics: {"bytes_written":16409903,"delete_count":0,"lbm_write_time_us":21161,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:20:08.564805 25633 maintenance_manager.cc:419] P d33f733e904649f883838ef50a2d1e5c: Scheduling FlushDeltaMemStoresOp(dbee8380ae9346099c13cdc92c909ae7): perf score=2.188937
I20260812 06:20:08.577397 25563 maintenance_manager.cc:643] P d33f733e904649f883838ef50a2d1e5c: FlushDeltaMemStoresOp(dbee8380ae9346099c13cdc92c909ae7) complete. Timing: real 0.012s	user 0.006s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4294,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:08.578048 25633 maintenance_manager.cc:419] P d33f733e904649f883838ef50a2d1e5c: Scheduling MajorDeltaCompactionOp(dbee8380ae9346099c13cdc92c909ae7): perf score=1.000000
I20260812 06:20:08.755661 25563 maintenance_manager.cc:643] P d33f733e904649f883838ef50a2d1e5c: MajorDeltaCompactionOp(dbee8380ae9346099c13cdc92c909ae7) complete. Timing: real 0.177s	user 0.105s	sys 0.068s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774690,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":643,"lbm_read_time_us":12010,"lbm_reads_lt_1ms":572,"lbm_write_time_us":26949,"lbm_writes_lt_1ms":543,"mutex_wait_us":118,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":13056,"update_count":2500}
I20260812 06:20:08.756390 25633 maintenance_manager.cc:419] P d33f733e904649f883838ef50a2d1e5c: Scheduling FlushDeltaMemStoresOp(dbee8380ae9346099c13cdc92c909ae7): perf score=14.095187
I20260812 06:20:08.815107 25563 maintenance_manager.cc:643] P d33f733e904649f883838ef50a2d1e5c: FlushDeltaMemStoresOp(dbee8380ae9346099c13cdc92c909ae7) complete. Timing: real 0.058s	user 0.040s	sys 0.012s Metrics: {"bytes_written":16409903,"delete_count":0,"lbm_write_time_us":25341,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:20:08.815815 25633 maintenance_manager.cc:419] P d33f733e904649f883838ef50a2d1e5c: Scheduling MajorDeltaCompactionOp(dbee8380ae9346099c13cdc92c909ae7): perf score=1.000000
I20260812 06:20:08.972738 25563 maintenance_manager.cc:643] P d33f733e904649f883838ef50a2d1e5c: MajorDeltaCompactionOp(dbee8380ae9346099c13cdc92c909ae7) complete. Timing: real 0.157s	user 0.108s	sys 0.045s Metrics: {"cfile_cache_miss":431,"cfile_cache_miss_bytes":20672159,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":1,"delta_iterators_relevant":1,"dirs.queue_time_us":191,"lbm_read_time_us":12221,"lbm_reads_lt_1ms":467,"lbm_write_time_us":25033,"lbm_writes_lt_1ms":443,"mutex_wait_us":30,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":77952,"update_count":2000}
I20260812 06:20:08.973413 25633 maintenance_manager.cc:419] P d33f733e904649f883838ef50a2d1e5c: Scheduling FlushDeltaMemStoresOp(dbee8380ae9346099c13cdc92c909ae7): perf score=11.118625
I20260812 06:20:09.014343 25563 maintenance_manager.cc:643] P d33f733e904649f883838ef50a2d1e5c: FlushDeltaMemStoresOp(dbee8380ae9346099c13cdc92c909ae7) complete. Timing: real 0.041s	user 0.017s	sys 0.020s Metrics: {"bytes_written":12717738,"delete_count":0,"lbm_write_time_us":17383,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:20:09.014920 25633 maintenance_manager.cc:419] P d33f733e904649f883838ef50a2d1e5c: Scheduling FlushDeltaMemStoresOp(dbee8380ae9346099c13cdc92c909ae7): perf score=2.188937
I20260812 06:20:09.039940 25563 maintenance_manager.cc:643] P d33f733e904649f883838ef50a2d1e5c: FlushDeltaMemStoresOp(dbee8380ae9346099c13cdc92c909ae7) complete. Timing: real 0.025s	user 0.010s	sys 0.004s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":5602,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:20:09.040407 25633 maintenance_manager.cc:419] P d33f733e904649f883838ef50a2d1e5c: Scheduling FlushDeltaMemStoresOp(dbee8380ae9346099c13cdc92c909ae7): perf score=2.188937
I20260812 06:20:09.051302 25563 maintenance_manager.cc:643] P d33f733e904649f883838ef50a2d1e5c: FlushDeltaMemStoresOp(dbee8380ae9346099c13cdc92c909ae7) complete. Timing: real 0.011s	user 0.002s	sys 0.009s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4319,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:09.051765 25633 maintenance_manager.cc:419] P d33f733e904649f883838ef50a2d1e5c: Scheduling MajorDeltaCompactionOp(dbee8380ae9346099c13cdc92c909ae7): perf score=1.000000
I20260812 06:20:09.237104 25563 maintenance_manager.cc:643] P d33f733e904649f883838ef50a2d1e5c: MajorDeltaCompactionOp(dbee8380ae9346099c13cdc92c909ae7) complete. Timing: real 0.185s	user 0.122s	sys 0.055s Metrics: {"cfile_cache_miss":533,"cfile_cache_miss_bytes":24774802,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":1001,"lbm_read_time_us":9376,"lbm_reads_lt_1ms":573,"lbm_write_time_us":32455,"lbm_writes_lt_1ms":543,"mutex_wait_us":52,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":8704,"update_count":2500}
I20260812 06:20:09.237726 25633 maintenance_manager.cc:419] P d33f733e904649f883838ef50a2d1e5c: Scheduling FlushDeltaMemStoresOp(dbee8380ae9346099c13cdc92c909ae7): perf score=14.095187
I20260812 06:20:09.290251 25563 maintenance_manager.cc:643] P d33f733e904649f883838ef50a2d1e5c: FlushDeltaMemStoresOp(dbee8380ae9346099c13cdc92c909ae7) complete. Timing: real 0.052s	user 0.016s	sys 0.025s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":19684,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:20:09.290791 25633 maintenance_manager.cc:419] P d33f733e904649f883838ef50a2d1e5c: Scheduling FlushDeltaMemStoresOp(dbee8380ae9346099c13cdc92c909ae7): perf score=2.188937
I20260812 06:20:09.303117 25563 maintenance_manager.cc:643] P d33f733e904649f883838ef50a2d1e5c: FlushDeltaMemStoresOp(dbee8380ae9346099c13cdc92c909ae7) complete. Timing: real 0.012s	user 0.006s	sys 0.003s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4504,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:09.303695 25633 maintenance_manager.cc:419] P d33f733e904649f883838ef50a2d1e5c: Scheduling MajorDeltaCompactionOp(dbee8380ae9346099c13cdc92c909ae7): perf score=1.000000
I20260812 06:20:09.468214 25563 maintenance_manager.cc:643] P d33f733e904649f883838ef50a2d1e5c: MajorDeltaCompactionOp(dbee8380ae9346099c13cdc92c909ae7) complete. Timing: real 0.164s	user 0.133s	sys 0.025s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774688,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":559,"lbm_read_time_us":11918,"lbm_reads_lt_1ms":572,"lbm_write_time_us":32103,"lbm_writes_lt_1ms":543,"mutex_wait_us":279,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":18944,"update_count":2500}
I20260812 06:20:09.468961 25633 maintenance_manager.cc:419] P d33f733e904649f883838ef50a2d1e5c: Scheduling FlushDeltaMemStoresOp(dbee8380ae9346099c13cdc92c909ae7): perf score=11.118625
I20260812 06:20:09.506419 25563 maintenance_manager.cc:643] P d33f733e904649f883838ef50a2d1e5c: FlushDeltaMemStoresOp(dbee8380ae9346099c13cdc92c909ae7) complete. Timing: real 0.037s	user 0.022s	sys 0.012s Metrics: {"bytes_written":12717736,"delete_count":0,"lbm_write_time_us":15881,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:20:09.507134 25633 maintenance_manager.cc:419] P d33f733e904649f883838ef50a2d1e5c: Scheduling FlushDeltaMemStoresOp(dbee8380ae9346099c13cdc92c909ae7): perf score=2.188937
I20260812 06:20:09.521908 25563 maintenance_manager.cc:643] P d33f733e904649f883838ef50a2d1e5c: FlushDeltaMemStoresOp(dbee8380ae9346099c13cdc92c909ae7) complete. Timing: real 0.015s	user 0.011s	sys 0.001s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":5396,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:20:09.522531 25633 maintenance_manager.cc:419] P d33f733e904649f883838ef50a2d1e5c: Scheduling FlushMRSOp(dbee8380ae9346099c13cdc92c909ae7): perf score=1.000000
I20260812 06:20:09.561615 25563 maintenance_manager.cc:643] P d33f733e904649f883838ef50a2d1e5c: FlushMRSOp(dbee8380ae9346099c13cdc92c909ae7) complete. Timing: real 0.039s	user 0.026s	sys 0.001s Metrics: {"bytes_written":1275449,"cfile_init":1,"dirs.queue_time_us":70,"dirs.run_cpu_time_us":196,"dirs.run_wall_time_us":1494,"drs_written":1,"lbm_read_time_us":61,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1629,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":31}
I20260812 06:20:09.562606 25633 maintenance_manager.cc:419] P d33f733e904649f883838ef50a2d1e5c: Scheduling UndoDeltaBlockGCOp(dbee8380ae9346099c13cdc92c909ae7): 482 bytes on disk
I20260812 06:20:09.563105 25563 maintenance_manager.cc:643] P d33f733e904649f883838ef50a2d1e5c: UndoDeltaBlockGCOp(dbee8380ae9346099c13cdc92c909ae7) 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.563652 25633 maintenance_manager.cc:419] P d33f733e904649f883838ef50a2d1e5c: Scheduling FlushDeltaMemStoresOp(dbee8380ae9346099c13cdc92c909ae7): perf score=3.181125
I20260812 06:20:09.576287 25563 maintenance_manager.cc:643] P d33f733e904649f883838ef50a2d1e5c: FlushDeltaMemStoresOp(dbee8380ae9346099c13cdc92c909ae7) complete. Timing: real 0.012s	user 0.006s	sys 0.004s Metrics: {"bytes_written":4512900,"delete_count":0,"lbm_write_time_us":4493,"lbm_writes_lt_1ms":113,"reinsert_count":0,"update_count":550}
I20260812 06:20:09.576886 25633 maintenance_manager.cc:419] P d33f733e904649f883838ef50a2d1e5c: Scheduling LogGCOp(dbee8380ae9346099c13cdc92c909ae7): free 129320505 bytes of WAL
I20260812 06:20:09.577157 25563 log_reader.cc:385] T dbee8380ae9346099c13cdc92c909ae7: removed 13 log segments from log reader
I20260812 06:20:09.577242 25563 log.cc:1079] T dbee8380ae9346099c13cdc92c909ae7 P d33f733e904649f883838ef50a2d1e5c: Deleting log segment in path: /tmp/dist-test-taskWwF8e7/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515606164878-25448-0/minicluster-data/ts-0-root/wals/dbee8380ae9346099c13cdc92c909ae7/wal-000000014 (ops 66-70)
I20260812 06:20:09.577297 25563 log.cc:1079] T dbee8380ae9346099c13cdc92c909ae7 P d33f733e904649f883838ef50a2d1e5c: Deleting log segment in path: /tmp/dist-test-taskWwF8e7/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515606164878-25448-0/minicluster-data/ts-0-root/wals/dbee8380ae9346099c13cdc92c909ae7/wal-000000015 (ops 71-75)
I20260812 06:20:09.577356 25563 log.cc:1079] T dbee8380ae9346099c13cdc92c909ae7 P d33f733e904649f883838ef50a2d1e5c: Deleting log segment in path: /tmp/dist-test-taskWwF8e7/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515606164878-25448-0/minicluster-data/ts-0-root/wals/dbee8380ae9346099c13cdc92c909ae7/wal-000000016 (ops 76-80)
I20260812 06:20:09.577400 25563 log.cc:1079] T dbee8380ae9346099c13cdc92c909ae7 P d33f733e904649f883838ef50a2d1e5c: Deleting log segment in path: /tmp/dist-test-taskWwF8e7/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515606164878-25448-0/minicluster-data/ts-0-root/wals/dbee8380ae9346099c13cdc92c909ae7/wal-000000017 (ops 81-85)
I20260812 06:20:09.577437 25563 log.cc:1079] T dbee8380ae9346099c13cdc92c909ae7 P d33f733e904649f883838ef50a2d1e5c: Deleting log segment in path: /tmp/dist-test-taskWwF8e7/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515606164878-25448-0/minicluster-data/ts-0-root/wals/dbee8380ae9346099c13cdc92c909ae7/wal-000000018 (ops 86-90)
I20260812 06:20:09.577477 25563 log.cc:1079] T dbee8380ae9346099c13cdc92c909ae7 P d33f733e904649f883838ef50a2d1e5c: Deleting log segment in path: /tmp/dist-test-taskWwF8e7/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515606164878-25448-0/minicluster-data/ts-0-root/wals/dbee8380ae9346099c13cdc92c909ae7/wal-000000019 (ops 91-94)
I20260812 06:20:09.577517 25563 log.cc:1079] T dbee8380ae9346099c13cdc92c909ae7 P d33f733e904649f883838ef50a2d1e5c: Deleting log segment in path: /tmp/dist-test-taskWwF8e7/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515606164878-25448-0/minicluster-data/ts-0-root/wals/dbee8380ae9346099c13cdc92c909ae7/wal-000000020 (ops 95-99)
I20260812 06:20:09.577555 25563 log.cc:1079] T dbee8380ae9346099c13cdc92c909ae7 P d33f733e904649f883838ef50a2d1e5c: Deleting log segment in path: /tmp/dist-test-taskWwF8e7/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515606164878-25448-0/minicluster-data/ts-0-root/wals/dbee8380ae9346099c13cdc92c909ae7/wal-000000021 (ops 100-104)
I20260812 06:20:09.577591 25563 log.cc:1079] T dbee8380ae9346099c13cdc92c909ae7 P d33f733e904649f883838ef50a2d1e5c: Deleting log segment in path: /tmp/dist-test-taskWwF8e7/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515606164878-25448-0/minicluster-data/ts-0-root/wals/dbee8380ae9346099c13cdc92c909ae7/wal-000000022 (ops 105-108)
I20260812 06:20:09.577641 25563 log.cc:1079] T dbee8380ae9346099c13cdc92c909ae7 P d33f733e904649f883838ef50a2d1e5c: Deleting log segment in path: /tmp/dist-test-taskWwF8e7/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515606164878-25448-0/minicluster-data/ts-0-root/wals/dbee8380ae9346099c13cdc92c909ae7/wal-000000023 (ops 109-113)
I20260812 06:20:09.577680 25563 log.cc:1079] T dbee8380ae9346099c13cdc92c909ae7 P d33f733e904649f883838ef50a2d1e5c: Deleting log segment in path: /tmp/dist-test-taskWwF8e7/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515606164878-25448-0/minicluster-data/ts-0-root/wals/dbee8380ae9346099c13cdc92c909ae7/wal-000000024 (ops 114-118)
I20260812 06:20:09.577718 25563 log.cc:1079] T dbee8380ae9346099c13cdc92c909ae7 P d33f733e904649f883838ef50a2d1e5c: Deleting log segment in path: /tmp/dist-test-taskWwF8e7/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515606164878-25448-0/minicluster-data/ts-0-root/wals/dbee8380ae9346099c13cdc92c909ae7/wal-000000025 (ops 119-123)
I20260812 06:20:09.577759 25563 log.cc:1079] T dbee8380ae9346099c13cdc92c909ae7 P d33f733e904649f883838ef50a2d1e5c: Deleting log segment in path: /tmp/dist-test-taskWwF8e7/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515606164878-25448-0/minicluster-data/ts-0-root/wals/dbee8380ae9346099c13cdc92c909ae7/wal-000000026 (ops 124-128)
I20260812 06:20:09.605468 25563 maintenance_manager.cc:643] P d33f733e904649f883838ef50a2d1e5c: LogGCOp(dbee8380ae9346099c13cdc92c909ae7) complete. Timing: real 0.028s	user 0.000s	sys 0.026s Metrics: {}
I20260812 06:20:09.605931 25633 maintenance_manager.cc:419] P d33f733e904649f883838ef50a2d1e5c: Scheduling FlushDeltaMemStoresOp(dbee8380ae9346099c13cdc92c909ae7): perf score=2.188937
I20260812 06:20:09.631832 25563 maintenance_manager.cc:643] P d33f733e904649f883838ef50a2d1e5c: FlushDeltaMemStoresOp(dbee8380ae9346099c13cdc92c909ae7) complete. Timing: real 0.025s	user 0.011s	sys 0.000s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3840,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:20:09.632431 25633 maintenance_manager.cc:419] P d33f733e904649f883838ef50a2d1e5c: Scheduling FlushDeltaMemStoresOp(dbee8380ae9346099c13cdc92c909ae7): perf score=2.188937
I20260812 06:20:09.643599 25563 maintenance_manager.cc:643] P d33f733e904649f883838ef50a2d1e5c: FlushDeltaMemStoresOp(dbee8380ae9346099c13cdc92c909ae7) complete. Timing: real 0.011s	user 0.006s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4227,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:09.644148 25633 maintenance_manager.cc:419] P d33f733e904649f883838ef50a2d1e5c: Scheduling MajorDeltaCompactionOp(dbee8380ae9346099c13cdc92c909ae7): perf score=1.000000
I20260812 06:20:09.872664 25563 maintenance_manager.cc:643] P d33f733e904649f883838ef50a2d1e5c: MajorDeltaCompactionOp(dbee8380ae9346099c13cdc92c909ae7) complete. Timing: real 0.228s	user 0.173s	sys 0.056s Metrics: {"cfile_cache_miss":735,"cfile_cache_miss_bytes":32979849,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":5,"delta_iterators_relevant":5,"dirs.queue_time_us":566,"lbm_read_time_us":14873,"lbm_reads_lt_1ms":775,"lbm_write_time_us":41882,"lbm_writes_lt_1ms":743,"mutex_wait_us":73,"peak_mem_usage":87969044,"reinsert_count":0,"thread_start_us":80,"threads_started":1,"update_count":3500}
I20260812 06:20:09.875670 25633 maintenance_manager.cc:419] P d33f733e904649f883838ef50a2d1e5c: Scheduling FlushDeltaMemStoresOp(dbee8380ae9346099c13cdc92c909ae7): perf score=14.095187
I20260812 06:20:09.934394 25563 maintenance_manager.cc:643] P d33f733e904649f883838ef50a2d1e5c: FlushDeltaMemStoresOp(dbee8380ae9346099c13cdc92c909ae7) complete. Timing: real 0.058s	user 0.034s	sys 0.021s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":25591,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:20:09.935158 25633 maintenance_manager.cc:419] P d33f733e904649f883838ef50a2d1e5c: Scheduling FlushDeltaMemStoresOp(dbee8380ae9346099c13cdc92c909ae7): perf score=2.188937
I20260812 06:20:09.962395 25563 maintenance_manager.cc:643] P d33f733e904649f883838ef50a2d1e5c: FlushDeltaMemStoresOp(dbee8380ae9346099c13cdc92c909ae7) complete. Timing: real 0.027s	user 0.013s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5781,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:09.962889 25633 maintenance_manager.cc:419] P d33f733e904649f883838ef50a2d1e5c: Scheduling FlushDeltaMemStoresOp(dbee8380ae9346099c13cdc92c909ae7): perf score=2.188937
I20260812 06:20:09.973927 25563 maintenance_manager.cc:643] P d33f733e904649f883838ef50a2d1e5c: FlushDeltaMemStoresOp(dbee8380ae9346099c13cdc92c909ae7) complete. Timing: real 0.011s	user 0.006s	sys 0.003s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4120,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:09.974462 25633 maintenance_manager.cc:419] P d33f733e904649f883838ef50a2d1e5c: Scheduling MajorDeltaCompactionOp(dbee8380ae9346099c13cdc92c909ae7): perf score=1.000000
I20260812 06:20:10.180855 25563 maintenance_manager.cc:643] P d33f733e904649f883838ef50a2d1e5c: MajorDeltaCompactionOp(dbee8380ae9346099c13cdc92c909ae7) complete. Timing: real 0.206s	user 0.140s	sys 0.064s Metrics: {"cfile_cache_miss":633,"cfile_cache_miss_bytes":28877219,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":245,"lbm_read_time_us":15352,"lbm_reads_lt_1ms":673,"lbm_write_time_us":33709,"lbm_writes_lt_1ms":643,"mutex_wait_us":28,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":2432,"update_count":3000}
I20260812 06:20:10.181561 25633 maintenance_manager.cc:419] P d33f733e904649f883838ef50a2d1e5c: Scheduling FlushDeltaMemStoresOp(dbee8380ae9346099c13cdc92c909ae7): perf score=14.095187
I20260812 06:20:10.231771 25563 maintenance_manager.cc:643] P d33f733e904649f883838ef50a2d1e5c: FlushDeltaMemStoresOp(dbee8380ae9346099c13cdc92c909ae7) complete. Timing: real 0.050s	user 0.038s	sys 0.011s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":22099,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:20:10.232335 25633 maintenance_manager.cc:419] P d33f733e904649f883838ef50a2d1e5c: Scheduling FlushDeltaMemStoresOp(dbee8380ae9346099c13cdc92c909ae7): perf score=2.188937
I20260812 06:20:10.247865 25563 maintenance_manager.cc:643] P d33f733e904649f883838ef50a2d1e5c: FlushDeltaMemStoresOp(dbee8380ae9346099c13cdc92c909ae7) complete. Timing: real 0.015s	user 0.014s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5947,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:10.248442 25633 maintenance_manager.cc:419] P d33f733e904649f883838ef50a2d1e5c: Scheduling MajorDeltaCompactionOp(dbee8380ae9346099c13cdc92c909ae7): perf score=1.000000
I20260812 06:20:10.426903 25563 maintenance_manager.cc:643] P d33f733e904649f883838ef50a2d1e5c: MajorDeltaCompactionOp(dbee8380ae9346099c13cdc92c909ae7) complete. Timing: real 0.178s	user 0.118s	sys 0.060s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774689,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":969,"lbm_read_time_us":12551,"lbm_reads_lt_1ms":564,"lbm_write_time_us":30062,"lbm_writes_lt_1ms":543,"mutex_wait_us":293,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":5376,"update_count":2500}
I20260812 06:20:10.427556 25633 maintenance_manager.cc:419] P d33f733e904649f883838ef50a2d1e5c: Scheduling FlushDeltaMemStoresOp(dbee8380ae9346099c13cdc92c909ae7): perf score=14.095187
I20260812 06:20:10.487798 25563 maintenance_manager.cc:643] P d33f733e904649f883838ef50a2d1e5c: FlushDeltaMemStoresOp(dbee8380ae9346099c13cdc92c909ae7) complete. Timing: real 0.060s	user 0.033s	sys 0.026s Metrics: {"bytes_written":16409903,"delete_count":0,"lbm_write_time_us":23454,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:20:10.488441 25633 maintenance_manager.cc:419] P d33f733e904649f883838ef50a2d1e5c: Scheduling FlushDeltaMemStoresOp(dbee8380ae9346099c13cdc92c909ae7): perf score=2.188937
I20260812 06:20:10.499735 25563 maintenance_manager.cc:643] P d33f733e904649f883838ef50a2d1e5c: FlushDeltaMemStoresOp(dbee8380ae9346099c13cdc92c909ae7) complete. Timing: real 0.011s	user 0.010s	sys 0.000s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4379,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:10.500221 25633 maintenance_manager.cc:419] P d33f733e904649f883838ef50a2d1e5c: Scheduling MajorDeltaCompactionOp(dbee8380ae9346099c13cdc92c909ae7): perf score=1.000000
I20260812 06:20:10.675475 25563 maintenance_manager.cc:643] P d33f733e904649f883838ef50a2d1e5c: MajorDeltaCompactionOp(dbee8380ae9346099c13cdc92c909ae7) complete. Timing: real 0.175s	user 0.138s	sys 0.036s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774689,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":675,"lbm_read_time_us":13196,"lbm_reads_lt_1ms":572,"lbm_write_time_us":30997,"lbm_writes_lt_1ms":543,"mutex_wait_us":332,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":60032,"update_count":2500}
I20260812 06:20:10.676143 25633 maintenance_manager.cc:419] P d33f733e904649f883838ef50a2d1e5c: Scheduling FlushDeltaMemStoresOp(dbee8380ae9346099c13cdc92c909ae7): perf score=10.126437
I20260812 06:20:10.709626 25563 maintenance_manager.cc:643] P d33f733e904649f883838ef50a2d1e5c: FlushDeltaMemStoresOp(dbee8380ae9346099c13cdc92c909ae7) complete. Timing: real 0.033s	user 0.018s	sys 0.012s Metrics: {"bytes_written":12307493,"delete_count":0,"lbm_write_time_us":14499,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:20:10.710594 25633 maintenance_manager.cc:419] P d33f733e904649f883838ef50a2d1e5c: Scheduling FlushDeltaMemStoresOp(dbee8380ae9346099c13cdc92c909ae7): perf score=2.188937
I20260812 06:20:10.731941 25563 maintenance_manager.cc:643] P d33f733e904649f883838ef50a2d1e5c: FlushDeltaMemStoresOp(dbee8380ae9346099c13cdc92c909ae7) complete. Timing: real 0.021s	user 0.007s	sys 0.012s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6762,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:10.732731 25633 maintenance_manager.cc:419] P d33f733e904649f883838ef50a2d1e5c: Scheduling MajorDeltaCompactionOp(dbee8380ae9346099c13cdc92c909ae7): perf score=1.000000
I20260812 06:20:10.913121 25563 maintenance_manager.cc:643] P d33f733e904649f883838ef50a2d1e5c: MajorDeltaCompactionOp(dbee8380ae9346099c13cdc92c909ae7) complete. Timing: real 0.180s	user 0.120s	sys 0.047s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672280,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":144,"lbm_read_time_us":11306,"lbm_reads_lt_1ms":468,"lbm_write_time_us":27485,"lbm_writes_lt_1ms":443,"mutex_wait_us":22,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":66944,"update_count":2000}
I20260812 06:20:10.913924 25633 maintenance_manager.cc:419] P d33f733e904649f883838ef50a2d1e5c: Scheduling FlushDeltaMemStoresOp(dbee8380ae9346099c13cdc92c909ae7): perf score=14.095187
I20260812 06:20:10.967489 25563 maintenance_manager.cc:643] P d33f733e904649f883838ef50a2d1e5c: FlushDeltaMemStoresOp(dbee8380ae9346099c13cdc92c909ae7) complete. Timing: real 0.053s	user 0.032s	sys 0.012s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":19463,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:20:10.968032 25633 maintenance_manager.cc:419] P d33f733e904649f883838ef50a2d1e5c: Scheduling FlushDeltaMemStoresOp(dbee8380ae9346099c13cdc92c909ae7): perf score=2.188937
I20260812 06:20:10.980006 25563 maintenance_manager.cc:643] P d33f733e904649f883838ef50a2d1e5c: FlushDeltaMemStoresOp(dbee8380ae9346099c13cdc92c909ae7) complete. Timing: real 0.012s	user 0.007s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4247,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:10.980537 25633 maintenance_manager.cc:419] P d33f733e904649f883838ef50a2d1e5c: Scheduling MajorDeltaCompactionOp(dbee8380ae9346099c13cdc92c909ae7): perf score=1.000000
I20260812 06:20:11.140576 25563 maintenance_manager.cc:643] P d33f733e904649f883838ef50a2d1e5c: MajorDeltaCompactionOp(dbee8380ae9346099c13cdc92c909ae7) complete. Timing: real 0.160s	user 0.117s	sys 0.030s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774688,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":283,"lbm_read_time_us":10427,"lbm_reads_lt_1ms":572,"lbm_write_time_us":32364,"lbm_writes_lt_1ms":543,"mutex_wait_us":34,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":2048,"update_count":2500}
I20260812 06:20:11.141299 25633 maintenance_manager.cc:419] P d33f733e904649f883838ef50a2d1e5c: Scheduling FlushDeltaMemStoresOp(dbee8380ae9346099c13cdc92c909ae7): perf score=14.095187
I20260812 06:20:11.193720 25563 maintenance_manager.cc:643] P d33f733e904649f883838ef50a2d1e5c: FlushDeltaMemStoresOp(dbee8380ae9346099c13cdc92c909ae7) complete. Timing: real 0.052s	user 0.022s	sys 0.021s Metrics: {"bytes_written":16409900,"delete_count":0,"lbm_write_time_us":20528,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:20:11.194238 25633 maintenance_manager.cc:419] P d33f733e904649f883838ef50a2d1e5c: Scheduling FlushDeltaMemStoresOp(dbee8380ae9346099c13cdc92c909ae7): perf score=2.188937
I20260812 06:20:11.206719 25563 maintenance_manager.cc:643] P d33f733e904649f883838ef50a2d1e5c: FlushDeltaMemStoresOp(dbee8380ae9346099c13cdc92c909ae7) complete. Timing: real 0.012s	user 0.006s	sys 0.003s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4741,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:11.207302 25633 maintenance_manager.cc:419] P d33f733e904649f883838ef50a2d1e5c: Scheduling FlushMRSOp(dbee8380ae9346099c13cdc92c909ae7): perf score=1.000000
I20260812 06:20:11.237008 25563 maintenance_manager.cc:643] P d33f733e904649f883838ef50a2d1e5c: FlushMRSOp(dbee8380ae9346099c13cdc92c909ae7) complete. Timing: real 0.029s	user 0.026s	sys 0.001s Metrics: {"bytes_written":1316417,"cfile_init":1,"dirs.queue_time_us":68,"dirs.run_cpu_time_us":169,"dirs.run_wall_time_us":1421,"drs_written":1,"lbm_read_time_us":57,"lbm_reads_lt_1ms":4,"lbm_write_time_us":2094,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":32}
I20260812 06:20:11.237838 25633 maintenance_manager.cc:419] P d33f733e904649f883838ef50a2d1e5c: Scheduling LogGCOp(dbee8380ae9346099c13cdc92c909ae7): free 136275453 bytes of WAL
I20260812 06:20:11.238137 25563 log_reader.cc:385] T dbee8380ae9346099c13cdc92c909ae7: removed 13 log segments from log reader
I20260812 06:20:11.238219 25563 log.cc:1079] T dbee8380ae9346099c13cdc92c909ae7 P d33f733e904649f883838ef50a2d1e5c: Deleting log segment in path: /tmp/dist-test-taskWwF8e7/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515606164878-25448-0/minicluster-data/ts-0-root/wals/dbee8380ae9346099c13cdc92c909ae7/wal-000000027 (ops 129-132)
I20260812 06:20:11.238286 25563 log.cc:1079] T dbee8380ae9346099c13cdc92c909ae7 P d33f733e904649f883838ef50a2d1e5c: Deleting log segment in path: /tmp/dist-test-taskWwF8e7/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515606164878-25448-0/minicluster-data/ts-0-root/wals/dbee8380ae9346099c13cdc92c909ae7/wal-000000028 (ops 133-137)
I20260812 06:20:11.238353 25563 log.cc:1079] T dbee8380ae9346099c13cdc92c909ae7 P d33f733e904649f883838ef50a2d1e5c: Deleting log segment in path: /tmp/dist-test-taskWwF8e7/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515606164878-25448-0/minicluster-data/ts-0-root/wals/dbee8380ae9346099c13cdc92c909ae7/wal-000000029 (ops 138-142)
I20260812 06:20:11.238394 25563 log.cc:1079] T dbee8380ae9346099c13cdc92c909ae7 P d33f733e904649f883838ef50a2d1e5c: Deleting log segment in path: /tmp/dist-test-taskWwF8e7/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515606164878-25448-0/minicluster-data/ts-0-root/wals/dbee8380ae9346099c13cdc92c909ae7/wal-000000030 (ops 143-147)
I20260812 06:20:11.238456 25563 log.cc:1079] T dbee8380ae9346099c13cdc92c909ae7 P d33f733e904649f883838ef50a2d1e5c: Deleting log segment in path: /tmp/dist-test-taskWwF8e7/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515606164878-25448-0/minicluster-data/ts-0-root/wals/dbee8380ae9346099c13cdc92c909ae7/wal-000000031 (ops 148-152)
I20260812 06:20:11.238508 25563 log.cc:1079] T dbee8380ae9346099c13cdc92c909ae7 P d33f733e904649f883838ef50a2d1e5c: Deleting log segment in path: /tmp/dist-test-taskWwF8e7/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515606164878-25448-0/minicluster-data/ts-0-root/wals/dbee8380ae9346099c13cdc92c909ae7/wal-000000032 (ops 153-157)
I20260812 06:20:11.238555 25563 log.cc:1079] T dbee8380ae9346099c13cdc92c909ae7 P d33f733e904649f883838ef50a2d1e5c: Deleting log segment in path: /tmp/dist-test-taskWwF8e7/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515606164878-25448-0/minicluster-data/ts-0-root/wals/dbee8380ae9346099c13cdc92c909ae7/wal-000000033 (ops 158-162)
I20260812 06:20:11.238598 25563 log.cc:1079] T dbee8380ae9346099c13cdc92c909ae7 P d33f733e904649f883838ef50a2d1e5c: Deleting log segment in path: /tmp/dist-test-taskWwF8e7/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515606164878-25448-0/minicluster-data/ts-0-root/wals/dbee8380ae9346099c13cdc92c909ae7/wal-000000034 (ops 163-167)
I20260812 06:20:11.238642 25563 log.cc:1079] T dbee8380ae9346099c13cdc92c909ae7 P d33f733e904649f883838ef50a2d1e5c: Deleting log segment in path: /tmp/dist-test-taskWwF8e7/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515606164878-25448-0/minicluster-data/ts-0-root/wals/dbee8380ae9346099c13cdc92c909ae7/wal-000000035 (ops 168-172)
I20260812 06:20:11.238686 25563 log.cc:1079] T dbee8380ae9346099c13cdc92c909ae7 P d33f733e904649f883838ef50a2d1e5c: Deleting log segment in path: /tmp/dist-test-taskWwF8e7/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515606164878-25448-0/minicluster-data/ts-0-root/wals/dbee8380ae9346099c13cdc92c909ae7/wal-000000036 (ops 173-177)
I20260812 06:20:11.238729 25563 log.cc:1079] T dbee8380ae9346099c13cdc92c909ae7 P d33f733e904649f883838ef50a2d1e5c: Deleting log segment in path: /tmp/dist-test-taskWwF8e7/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515606164878-25448-0/minicluster-data/ts-0-root/wals/dbee8380ae9346099c13cdc92c909ae7/wal-000000037 (ops 178-182)
I20260812 06:20:11.238772 25563 log.cc:1079] T dbee8380ae9346099c13cdc92c909ae7 P d33f733e904649f883838ef50a2d1e5c: Deleting log segment in path: /tmp/dist-test-taskWwF8e7/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515606164878-25448-0/minicluster-data/ts-0-root/wals/dbee8380ae9346099c13cdc92c909ae7/wal-000000038 (ops 183-187)
I20260812 06:20:11.238816 25563 log.cc:1079] T dbee8380ae9346099c13cdc92c909ae7 P d33f733e904649f883838ef50a2d1e5c: Deleting log segment in path: /tmp/dist-test-taskWwF8e7/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515606164878-25448-0/minicluster-data/ts-0-root/wals/dbee8380ae9346099c13cdc92c909ae7/wal-000000039 (ops 188-192)
I20260812 06:20:11.269457 25563 maintenance_manager.cc:643] P d33f733e904649f883838ef50a2d1e5c: LogGCOp(dbee8380ae9346099c13cdc92c909ae7) complete. Timing: real 0.031s	user 0.000s	sys 0.029s Metrics: {}
I20260812 06:20:11.269884 25633 maintenance_manager.cc:419] P d33f733e904649f883838ef50a2d1e5c: Scheduling FlushDeltaMemStoresOp(dbee8380ae9346099c13cdc92c909ae7): perf score=5.165500
I20260812 06:20:11.293072 25563 maintenance_manager.cc:643] P d33f733e904649f883838ef50a2d1e5c: FlushDeltaMemStoresOp(dbee8380ae9346099c13cdc92c909ae7) complete. Timing: real 0.023s	user 0.008s	sys 0.013s Metrics: {"bytes_written":6974353,"delete_count":0,"lbm_write_time_us":9614,"lbm_writes_lt_1ms":173,"reinsert_count":0,"update_count":850}
I20260812 06:20:11.293704 25633 maintenance_manager.cc:419] P d33f733e904649f883838ef50a2d1e5c: Scheduling UndoDeltaBlockGCOp(dbee8380ae9346099c13cdc92c909ae7): 493 bytes on disk
I20260812 06:20:11.294309 25563 maintenance_manager.cc:643] P d33f733e904649f883838ef50a2d1e5c: UndoDeltaBlockGCOp(dbee8380ae9346099c13cdc92c909ae7) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":87,"lbm_reads_lt_1ms":4}
I20260812 06:20:11.294947 25633 maintenance_manager.cc:419] P d33f733e904649f883838ef50a2d1e5c: Scheduling FlushDeltaMemStoresOp(dbee8380ae9346099c13cdc92c909ae7): perf score=1.000000
I20260812 06:20:11.307258 25563 maintenance_manager.cc:643] P d33f733e904649f883838ef50a2d1e5c: FlushDeltaMemStoresOp(dbee8380ae9346099c13cdc92c909ae7) complete. Timing: real 0.012s	user 0.010s	sys 0.000s Metrics: {"bytes_written":1230902,"delete_count":0,"lbm_write_time_us":2085,"lbm_writes_lt_1ms":33,"reinsert_count":0,"update_count":150}
I20260812 06:20:11.310251 25633 maintenance_manager.cc:419] P d33f733e904649f883838ef50a2d1e5c: Scheduling MajorDeltaCompactionOp(dbee8380ae9346099c13cdc92c909ae7): perf score=1.000000
I20260812 06:20:11.463472 25448 heavy-update-compaction-itest.cc:229] Time spent updating: real 4.993s	user 1.865s	sys 0.158s
I20260812 06:20:11.525542 25563 maintenance_manager.cc:643] P d33f733e904649f883838ef50a2d1e5c: MajorDeltaCompactionOp(dbee8380ae9346099c13cdc92c909ae7) complete. Timing: real 0.215s	user 0.155s	sys 0.059s Metrics: {"cfile_cache_miss":734,"cfile_cache_miss_bytes":32979680,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"lbm_read_time_us":16221,"lbm_reads_lt_1ms":770,"lbm_write_time_us":38166,"lbm_writes_lt_1ms":743,"peak_mem_usage":87969044,"reinsert_count":0,"spinlock_wait_cycles":1280,"update_count":3500}
I20260812 06:20:11.526047 25633 maintenance_manager.cc:419] P d33f733e904649f883838ef50a2d1e5c: Scheduling FlushDeltaMemStoresOp(dbee8380ae9346099c13cdc92c909ae7): perf score=10.126437
I20260812 06:20:11.548084 25448 heavy-update-compaction-itest.cc:265] Time spent scanning: real 0.084s	user 0.004s	sys 0.000s
I20260812 06:20:11.548842 25448 tablet_server.cc:179] TabletServer@127.24.218.1:0 shutting down...
I20260812 06:20:11.564862 25563 maintenance_manager.cc:643] P d33f733e904649f883838ef50a2d1e5c: FlushDeltaMemStoresOp(dbee8380ae9346099c13cdc92c909ae7) complete. Timing: real 0.039s	user 0.013s	sys 0.024s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":17601,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:20:11.565606 25448 ts_tablet_manager.cc:1507] Shutting down tablet manager...
I20260812 06:20:11.566012 25448 tablet_replica.cc:333] T dbee8380ae9346099c13cdc92c909ae7 P d33f733e904649f883838ef50a2d1e5c: stopping tablet replica
I20260812 06:20:11.566229 25448 raft_consensus.cc:2243] T dbee8380ae9346099c13cdc92c909ae7 P d33f733e904649f883838ef50a2d1e5c [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:20:11.566423 25448 raft_consensus.cc:2272] T dbee8380ae9346099c13cdc92c909ae7 P d33f733e904649f883838ef50a2d1e5c [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:20:11.581741 25448 tablet_server.cc:196] TabletServer@127.24.218.1:0 shutdown complete.
I20260812 06:20:11.593091 25448 master.cc:562] Master@127.24.218.62:45323 shutting down...
I20260812 06:20:11.597488 25448 raft_consensus.cc:2243] T 00000000000000000000000000000000 P 5a044df8930448e9ad6755fa02848059 [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:20:11.597678 25448 raft_consensus.cc:2272] T 00000000000000000000000000000000 P 5a044df8930448e9ad6755fa02848059 [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:20:11.597731 25448 tablet_replica.cc:333] T 00000000000000000000000000000000 P 5a044df8930448e9ad6755fa02848059: stopping tablet replica
I20260812 06:20:11.610384 25448 master.cc:584] Master@127.24.218.62:45323 shutdown complete.
[       OK ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/0 (5520 ms)
[ RUN      ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/1
I20260812 06:20:11.706344 25448 internal_mini_cluster.cc:156] Creating distributed mini masters. Addrs: 127.24.218.62:44997
I20260812 06:20:11.706740 25448 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:20:11.708860 25670 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:11.708954 25448 server_base.cc:1061] running on GCE node
W20260812 06:20:11.708992 25668 instance_detector.cc:116] could not retrieve Azure instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:20:11.709028 25667 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:11.709344 25448 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:20:11.709410 25448 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:11.709445 25448 hybrid_clock.cc:648] HybridClock initialized: now 1786515611709444 us; error 0 us; skew 500 ppm
I20260812 06:20:11.710322 25448 webserver.cc:533] Webserver started at http://127.24.218.62:37905/ using document root <none> and password file <none>
I20260812 06:20:11.710511 25448 fs_manager.cc:362] Metadata directory not provided
I20260812 06:20:11.710579 25448 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:20:11.710683 25448 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:20:11.711105 25448 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskWwF8e7/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515606164878-25448-0/minicluster-data/master-0-root/instance:
uuid: "66c3e90dbcd142d695aaf5a74dcd3264"
format_stamp: "Formatted at 2026-08-12 06:20:11 on dist-test-slave-chsk"
I20260812 06:20:11.712703 25448 fs_manager.cc:696] Time spent creating directory manager: real 0.001s	user 0.001s	sys 0.000s
I20260812 06:20:11.713677 25675 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:11.713907 25448 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.001s	sys 0.000s
I20260812 06:20:11.714000 25448 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskWwF8e7/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515606164878-25448-0/minicluster-data/master-0-root
uuid: "66c3e90dbcd142d695aaf5a74dcd3264"
format_stamp: "Formatted at 2026-08-12 06:20:11 on dist-test-slave-chsk"
I20260812 06:20:11.714085 25448 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskWwF8e7/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515606164878-25448-0/minicluster-data/master-0-root
metadata directory: /tmp/dist-test-taskWwF8e7/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515606164878-25448-0/minicluster-data/master-0-root
1 data directories: /tmp/dist-test-taskWwF8e7/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515606164878-25448-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:11.732595 25448 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:20:11.733156 25448 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:20:11.739938 25448 rpc_server.cc:307] RPC server started. Bound to: 127.24.218.62:44997
I20260812 06:20:11.742056 25735 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:11.746107 25734 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.24.218.62:44997 every 8 connection(s)
I20260812 06:20:11.747447 25735 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P 66c3e90dbcd142d695aaf5a74dcd3264: Bootstrap starting.
I20260812 06:20:11.748302 25735 tablet_bootstrap.cc:654] T 00000000000000000000000000000000 P 66c3e90dbcd142d695aaf5a74dcd3264: Neither blocks nor log segments found. Creating new log.
I20260812 06:20:11.749353 25735 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P 66c3e90dbcd142d695aaf5a74dcd3264: No bootstrap required, opened a new log
I20260812 06:20:11.749768 25735 raft_consensus.cc:359] T 00000000000000000000000000000000 P 66c3e90dbcd142d695aaf5a74dcd3264 [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "66c3e90dbcd142d695aaf5a74dcd3264" member_type: VOTER }
I20260812 06:20:11.749856 25735 raft_consensus.cc:385] T 00000000000000000000000000000000 P 66c3e90dbcd142d695aaf5a74dcd3264 [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:20:11.749914 25735 raft_consensus.cc:740] T 00000000000000000000000000000000 P 66c3e90dbcd142d695aaf5a74dcd3264 [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: 66c3e90dbcd142d695aaf5a74dcd3264, State: Initialized, Role: FOLLOWER
I20260812 06:20:11.750108 25735 consensus_queue.cc:260] T 00000000000000000000000000000000 P 66c3e90dbcd142d695aaf5a74dcd3264 [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: "66c3e90dbcd142d695aaf5a74dcd3264" member_type: VOTER }
I20260812 06:20:11.750196 25735 raft_consensus.cc:399] T 00000000000000000000000000000000 P 66c3e90dbcd142d695aaf5a74dcd3264 [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:20:11.750258 25735 raft_consensus.cc:493] T 00000000000000000000000000000000 P 66c3e90dbcd142d695aaf5a74dcd3264 [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:20:11.750317 25735 raft_consensus.cc:3060] T 00000000000000000000000000000000 P 66c3e90dbcd142d695aaf5a74dcd3264 [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:20:11.751057 25735 raft_consensus.cc:515] T 00000000000000000000000000000000 P 66c3e90dbcd142d695aaf5a74dcd3264 [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "66c3e90dbcd142d695aaf5a74dcd3264" member_type: VOTER }
I20260812 06:20:11.751250 25735 leader_election.cc:304] T 00000000000000000000000000000000 P 66c3e90dbcd142d695aaf5a74dcd3264 [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: 66c3e90dbcd142d695aaf5a74dcd3264; no voters: 
I20260812 06:20:11.751405 25735 leader_election.cc:290] T 00000000000000000000000000000000 P 66c3e90dbcd142d695aaf5a74dcd3264 [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:20:11.751538 25739 raft_consensus.cc:2804] T 00000000000000000000000000000000 P 66c3e90dbcd142d695aaf5a74dcd3264 [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:20:11.751792 25739 raft_consensus.cc:697] T 00000000000000000000000000000000 P 66c3e90dbcd142d695aaf5a74dcd3264 [term 1 LEADER]: Becoming Leader. State: Replica: 66c3e90dbcd142d695aaf5a74dcd3264, State: Running, Role: LEADER
I20260812 06:20:11.751924 25735 sys_catalog.cc:565] T 00000000000000000000000000000000 P 66c3e90dbcd142d695aaf5a74dcd3264 [sys.catalog]: configured and running, proceeding with master startup.
I20260812 06:20:11.751981 25739 consensus_queue.cc:237] T 00000000000000000000000000000000 P 66c3e90dbcd142d695aaf5a74dcd3264 [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: "66c3e90dbcd142d695aaf5a74dcd3264" member_type: VOTER }
I20260812 06:20:11.752424 25741 sys_catalog.cc:455] T 00000000000000000000000000000000 P 66c3e90dbcd142d695aaf5a74dcd3264 [sys.catalog]: SysCatalogTable state changed. Reason: RaftConsensus started. Latest consensus state: current_term: 1 leader_uuid: "66c3e90dbcd142d695aaf5a74dcd3264" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "66c3e90dbcd142d695aaf5a74dcd3264" member_type: VOTER } }
I20260812 06:20:11.752559 25741 sys_catalog.cc:458] T 00000000000000000000000000000000 P 66c3e90dbcd142d695aaf5a74dcd3264 [sys.catalog]: This master's current role is: LEADER
I20260812 06:20:11.752445 25743 sys_catalog.cc:455] T 00000000000000000000000000000000 P 66c3e90dbcd142d695aaf5a74dcd3264 [sys.catalog]: SysCatalogTable state changed. Reason: New leader 66c3e90dbcd142d695aaf5a74dcd3264. Latest consensus state: current_term: 1 leader_uuid: "66c3e90dbcd142d695aaf5a74dcd3264" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "66c3e90dbcd142d695aaf5a74dcd3264" member_type: VOTER } }
I20260812 06:20:11.752708 25743 sys_catalog.cc:458] T 00000000000000000000000000000000 P 66c3e90dbcd142d695aaf5a74dcd3264 [sys.catalog]: This master's current role is: LEADER
I20260812 06:20:11.753870 25448 internal_mini_cluster.cc:184] Waiting to initialize catalog manager on master 0
W20260812 06:20:11.754350 25759 catalog_manager.cc:1594] T 00000000000000000000000000000000 P 66c3e90dbcd142d695aaf5a74dcd3264: loading cluster ID for follower catalog manager: Not found: cluster ID entry not found
W20260812 06:20:11.754432 25759 catalog_manager.cc:883] Not found: cluster ID entry not found: failed to prepare follower catalog manager, will retry
I20260812 06:20:11.754534 25747 catalog_manager.cc:1511] Loading table and tablet metadata into memory...
I20260812 06:20:11.755220 25747 catalog_manager.cc:1520] Initializing Kudu cluster ID...
I20260812 06:20:11.756968 25747 catalog_manager.cc:1383] Generated new cluster ID: e17dd4009ce4480caf7ba1bd70573831
I20260812 06:20:11.757015 25747 catalog_manager.cc:1531] Initializing Kudu internal certificate authority...
I20260812 06:20:11.765672 25747 catalog_manager.cc:1406] Generated new certificate authority record
I20260812 06:20:11.766222 25747 catalog_manager.cc:1540] Loading token signing keys...
I20260812 06:20:11.774632 25747 catalog_manager.cc:6092] T 00000000000000000000000000000000 P 66c3e90dbcd142d695aaf5a74dcd3264: Generated new TSK 0
I20260812 06:20:11.774829 25747 catalog_manager.cc:1550] Initializing in-progress tserver states...
I20260812 06:20:11.786240 25448 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:20:11.788352 25764 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:11.788461 25762 instance_detector.cc:116] could not retrieve Azure instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:20:11.788477 25761 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:11.788582 25448 server_base.cc:1061] running on GCE node
I20260812 06:20:11.788829 25448 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:20:11.788872 25448 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:11.788887 25448 hybrid_clock.cc:648] HybridClock initialized: now 1786515611788887 us; error 0 us; skew 500 ppm
I20260812 06:20:11.789805 25448 webserver.cc:533] Webserver started at http://127.24.218.1:40395/ using document root <none> and password file <none>
I20260812 06:20:11.789988 25448 fs_manager.cc:362] Metadata directory not provided
I20260812 06:20:11.790038 25448 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:20:11.790127 25448 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:20:11.790539 25448 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskWwF8e7/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515606164878-25448-0/minicluster-data/ts-0-root/instance:
uuid: "02d6dd386c2a4e0d97fe61e209e67a49"
format_stamp: "Formatted at 2026-08-12 06:20:11 on dist-test-slave-chsk"
I20260812 06:20:11.792141 25448 fs_manager.cc:696] Time spent creating directory manager: real 0.001s	user 0.000s	sys 0.002s
I20260812 06:20:11.793073 25769 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:11.793377 25448 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.000s	sys 0.001s
I20260812 06:20:11.793442 25448 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskWwF8e7/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515606164878-25448-0/minicluster-data/ts-0-root
uuid: "02d6dd386c2a4e0d97fe61e209e67a49"
format_stamp: "Formatted at 2026-08-12 06:20:11 on dist-test-slave-chsk"
I20260812 06:20:11.793535 25448 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskWwF8e7/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515606164878-25448-0/minicluster-data/ts-0-root
metadata directory: /tmp/dist-test-taskWwF8e7/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515606164878-25448-0/minicluster-data/ts-0-root
1 data directories: /tmp/dist-test-taskWwF8e7/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515606164878-25448-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:11.804293 25448 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:20:11.804647 25448 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:20:11.804914 25448 txn_system_client.cc:432] TxnSystemClient initialization is disabled...
I20260812 06:20:11.805429 25448 ts_tablet_manager.cc:585] Loaded tablet metadata (0 total tablets, 0 live tablets)
I20260812 06:20:11.805470 25448 ts_tablet_manager.cc:531] Time spent load tablet metadata: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:20:11.805531 25448 ts_tablet_manager.cc:616] Registered 0 tablets
I20260812 06:20:11.805569 25448 ts_tablet_manager.cc:595] Time spent register tablets: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:20:11.809958 25448 rpc_server.cc:307] RPC server started. Bound to: 127.24.218.1:35591
I20260812 06:20:11.811064 25837 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.24.218.1:35591 every 8 connection(s)
I20260812 06:20:11.820196 25838 heartbeater.cc:344] Connected to a master server at 127.24.218.62:44997
I20260812 06:20:11.820335 25838 heartbeater.cc:461] Registering TS with master...
I20260812 06:20:11.820591 25838 heartbeater.cc:507] Master 127.24.218.62:44997 requested a full tablet report, sending...
I20260812 06:20:11.821314 25687 ts_manager.cc:194] Registered new tserver with Master: 02d6dd386c2a4e0d97fe61e209e67a49 (127.24.218.1:35591)
I20260812 06:20:11.821830 25448 internal_mini_cluster.cc:371] 1 TS(s) registered with all masters after 0.010993693s
I20260812 06:20:11.822142 25687 master_service.cc:502] Signed X509 certificate for tserver {username='slave'} at 127.0.0.1:52716
I20260812 06:20:11.829288 25687 catalog_manager.cc:2283] Servicing CreateTable request from {username='slave'} at 127.0.0.1:52730:
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:11.838589 25802 tablet_service.cc:1511] Processing CreateTablet for tablet 870e9336c2c14a2caa588cef5073b84a (DEFAULT_TABLE table=heavy-update-compaction-test [id=bda678df19bb4d4386c5a994cc1ea22a]), partition=
I20260812 06:20:11.838845 25802 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet 870e9336c2c14a2caa588cef5073b84a. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:20:11.841499 25853 tablet_bootstrap.cc:492] T 870e9336c2c14a2caa588cef5073b84a P 02d6dd386c2a4e0d97fe61e209e67a49: Bootstrap starting.
I20260812 06:20:11.842429 25853 tablet_bootstrap.cc:654] T 870e9336c2c14a2caa588cef5073b84a P 02d6dd386c2a4e0d97fe61e209e67a49: Neither blocks nor log segments found. Creating new log.
I20260812 06:20:11.843578 25853 tablet_bootstrap.cc:492] T 870e9336c2c14a2caa588cef5073b84a P 02d6dd386c2a4e0d97fe61e209e67a49: No bootstrap required, opened a new log
I20260812 06:20:11.843653 25853 ts_tablet_manager.cc:1403] T 870e9336c2c14a2caa588cef5073b84a P 02d6dd386c2a4e0d97fe61e209e67a49: Time spent bootstrapping tablet: real 0.002s	user 0.002s	sys 0.000s
I20260812 06:20:11.844166 25853 raft_consensus.cc:359] T 870e9336c2c14a2caa588cef5073b84a P 02d6dd386c2a4e0d97fe61e209e67a49 [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "02d6dd386c2a4e0d97fe61e209e67a49" member_type: VOTER last_known_addr { host: "127.24.218.1" port: 35591 } }
I20260812 06:20:11.844285 25853 raft_consensus.cc:385] T 870e9336c2c14a2caa588cef5073b84a P 02d6dd386c2a4e0d97fe61e209e67a49 [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:20:11.844312 25853 raft_consensus.cc:740] T 870e9336c2c14a2caa588cef5073b84a P 02d6dd386c2a4e0d97fe61e209e67a49 [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: 02d6dd386c2a4e0d97fe61e209e67a49, State: Initialized, Role: FOLLOWER
I20260812 06:20:11.844480 25853 consensus_queue.cc:260] T 870e9336c2c14a2caa588cef5073b84a P 02d6dd386c2a4e0d97fe61e209e67a49 [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: "02d6dd386c2a4e0d97fe61e209e67a49" member_type: VOTER last_known_addr { host: "127.24.218.1" port: 35591 } }
I20260812 06:20:11.844574 25853 raft_consensus.cc:399] T 870e9336c2c14a2caa588cef5073b84a P 02d6dd386c2a4e0d97fe61e209e67a49 [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:20:11.844646 25853 raft_consensus.cc:493] T 870e9336c2c14a2caa588cef5073b84a P 02d6dd386c2a4e0d97fe61e209e67a49 [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:20:11.844702 25853 raft_consensus.cc:3060] T 870e9336c2c14a2caa588cef5073b84a P 02d6dd386c2a4e0d97fe61e209e67a49 [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:20:11.845422 25853 raft_consensus.cc:515] T 870e9336c2c14a2caa588cef5073b84a P 02d6dd386c2a4e0d97fe61e209e67a49 [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "02d6dd386c2a4e0d97fe61e209e67a49" member_type: VOTER last_known_addr { host: "127.24.218.1" port: 35591 } }
I20260812 06:20:11.845574 25853 leader_election.cc:304] T 870e9336c2c14a2caa588cef5073b84a P 02d6dd386c2a4e0d97fe61e209e67a49 [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: 02d6dd386c2a4e0d97fe61e209e67a49; no voters: 
I20260812 06:20:11.845798 25853 leader_election.cc:290] T 870e9336c2c14a2caa588cef5073b84a P 02d6dd386c2a4e0d97fe61e209e67a49 [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:20:11.845921 25855 raft_consensus.cc:2804] T 870e9336c2c14a2caa588cef5073b84a P 02d6dd386c2a4e0d97fe61e209e67a49 [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:20:11.846187 25853 ts_tablet_manager.cc:1434] T 870e9336c2c14a2caa588cef5073b84a P 02d6dd386c2a4e0d97fe61e209e67a49: Time spent starting tablet: real 0.002s	user 0.003s	sys 0.000s
I20260812 06:20:11.846211 25855 raft_consensus.cc:697] T 870e9336c2c14a2caa588cef5073b84a P 02d6dd386c2a4e0d97fe61e209e67a49 [term 1 LEADER]: Becoming Leader. State: Replica: 02d6dd386c2a4e0d97fe61e209e67a49, State: Running, Role: LEADER
I20260812 06:20:11.846210 25838 heartbeater.cc:499] Master 127.24.218.62:44997 was elected leader, sending a full tablet report...
I20260812 06:20:11.846385 25855 consensus_queue.cc:237] T 870e9336c2c14a2caa588cef5073b84a P 02d6dd386c2a4e0d97fe61e209e67a49 [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: "02d6dd386c2a4e0d97fe61e209e67a49" member_type: VOTER last_known_addr { host: "127.24.218.1" port: 35591 } }
I20260812 06:20:11.847730 25687 catalog_manager.cc:5719] T 870e9336c2c14a2caa588cef5073b84a P 02d6dd386c2a4e0d97fe61e209e67a49 reported cstate change: term changed from 0 to 1, leader changed from <none> to 02d6dd386c2a4e0d97fe61e209e67a49 (127.24.218.1). New cstate: current_term: 1 leader_uuid: "02d6dd386c2a4e0d97fe61e209e67a49" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "02d6dd386c2a4e0d97fe61e209e67a49" member_type: VOTER last_known_addr { host: "127.24.218.1" port: 35591 } health_report { overall_health: HEALTHY } } }
I20260812 06:20:11.916394 25448 heavy-update-compaction-itest.cc:215] Time spent inserting: real 0.062s	user 0.010s	sys 0.012s
I20260812 06:20:12.061578 25839 maintenance_manager.cc:419] P 02d6dd386c2a4e0d97fe61e209e67a49: Scheduling FlushMRSOp(870e9336c2c14a2caa588cef5073b84a): perf score=19.054940
I20260812 06:20:12.216877 25774 maintenance_manager.cc:643] P 02d6dd386c2a4e0d97fe61e209e67a49: FlushMRSOp(870e9336c2c14a2caa588cef5073b84a) complete. Timing: real 0.155s	user 0.110s	sys 0.043s Metrics: {"bytes_written":12307490,"cfile_init":1,"delete_count":0,"dirs.queue_time_us":80,"dirs.run_cpu_time_us":239,"dirs.run_wall_time_us":854,"drs_written":1,"lbm_read_time_us":72,"lbm_reads_lt_1ms":4,"lbm_write_time_us":39153,"lbm_writes_lt_1ms":757,"peak_mem_usage":0,"reinsert_count":0,"rows_written":104,"update_count":1500}
I20260812 06:20:12.217517 25839 maintenance_manager.cc:419] P 02d6dd386c2a4e0d97fe61e209e67a49: Scheduling LogGCOp(870e9336c2c14a2caa588cef5073b84a): free 20290830 bytes of WAL
I20260812 06:20:12.217772 25774 log_reader.cc:385] T 870e9336c2c14a2caa588cef5073b84a: removed 2 log segments from log reader
I20260812 06:20:12.217819 25774 log.cc:1079] T 870e9336c2c14a2caa588cef5073b84a P 02d6dd386c2a4e0d97fe61e209e67a49: Deleting log segment in path: /tmp/dist-test-taskWwF8e7/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515606164878-25448-0/minicluster-data/ts-0-root/wals/870e9336c2c14a2caa588cef5073b84a/wal-000000001 (ops 1-6)
I20260812 06:20:12.217851 25774 log.cc:1079] T 870e9336c2c14a2caa588cef5073b84a P 02d6dd386c2a4e0d97fe61e209e67a49: Deleting log segment in path: /tmp/dist-test-taskWwF8e7/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515606164878-25448-0/minicluster-data/ts-0-root/wals/870e9336c2c14a2caa588cef5073b84a/wal-000000002 (ops 7-10)
I20260812 06:20:12.222105 25774 maintenance_manager.cc:643] P 02d6dd386c2a4e0d97fe61e209e67a49: LogGCOp(870e9336c2c14a2caa588cef5073b84a) complete. Timing: real 0.004s	user 0.000s	sys 0.001s Metrics: {}
I20260812 06:20:12.222550 25839 maintenance_manager.cc:419] P 02d6dd386c2a4e0d97fe61e209e67a49: Scheduling FlushDeltaMemStoresOp(870e9336c2c14a2caa588cef5073b84a): perf score=2.188937
I20260812 06:20:12.235630 25774 maintenance_manager.cc:643] P 02d6dd386c2a4e0d97fe61e209e67a49: FlushDeltaMemStoresOp(870e9336c2c14a2caa588cef5073b84a) complete. Timing: real 0.013s	user 0.009s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4790,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:12.236088 25839 maintenance_manager.cc:419] P 02d6dd386c2a4e0d97fe61e209e67a49: Scheduling UndoDeltaBlockGCOp(870e9336c2c14a2caa588cef5073b84a): 16411395 bytes on disk
I20260812 06:20:12.236647 25774 maintenance_manager.cc:643] P 02d6dd386c2a4e0d97fe61e209e67a49: UndoDeltaBlockGCOp(870e9336c2c14a2caa588cef5073b84a) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":95,"lbm_reads_lt_1ms":4}
I20260812 06:20:12.237162 25839 maintenance_manager.cc:419] P 02d6dd386c2a4e0d97fe61e209e67a49: Scheduling MajorDeltaCompactionOp(870e9336c2c14a2caa588cef5073b84a): perf score=1.000000
I20260812 06:20:12.372916 25774 maintenance_manager.cc:643] P 02d6dd386c2a4e0d97fe61e209e67a49: MajorDeltaCompactionOp(870e9336c2c14a2caa588cef5073b84a) complete. Timing: real 0.136s	user 0.107s	sys 0.028s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672277,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":413,"lbm_read_time_us":9397,"lbm_reads_lt_1ms":464,"lbm_write_time_us":24352,"lbm_writes_lt_1ms":443,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":3456,"thread_start_us":324,"threads_started":5,"update_count":2000}
I20260812 06:20:12.373493 25839 maintenance_manager.cc:419] P 02d6dd386c2a4e0d97fe61e209e67a49: Scheduling FlushDeltaMemStoresOp(870e9336c2c14a2caa588cef5073b84a): perf score=11.118625
I20260812 06:20:12.417275 25774 maintenance_manager.cc:643] P 02d6dd386c2a4e0d97fe61e209e67a49: FlushDeltaMemStoresOp(870e9336c2c14a2caa588cef5073b84a) complete. Timing: real 0.044s	user 0.018s	sys 0.023s Metrics: {"bytes_written":12717736,"delete_count":0,"lbm_write_time_us":14599,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:20:12.417873 25839 maintenance_manager.cc:419] P 02d6dd386c2a4e0d97fe61e209e67a49: Scheduling FlushDeltaMemStoresOp(870e9336c2c14a2caa588cef5073b84a): perf score=2.188937
I20260812 06:20:12.433413 25774 maintenance_manager.cc:643] P 02d6dd386c2a4e0d97fe61e209e67a49: FlushDeltaMemStoresOp(870e9336c2c14a2caa588cef5073b84a) complete. Timing: real 0.015s	user 0.005s	sys 0.008s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":5794,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:20:12.433935 25839 maintenance_manager.cc:419] P 02d6dd386c2a4e0d97fe61e209e67a49: Scheduling MajorDeltaCompactionOp(870e9336c2c14a2caa588cef5073b84a): perf score=1.000000
I20260812 06:20:12.596575 25774 maintenance_manager.cc:643] P 02d6dd386c2a4e0d97fe61e209e67a49: MajorDeltaCompactionOp(870e9336c2c14a2caa588cef5073b84a) complete. Timing: real 0.162s	user 0.117s	sys 0.040s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672269,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":547,"lbm_read_time_us":8949,"lbm_reads_lt_1ms":468,"lbm_write_time_us":26665,"lbm_writes_lt_1ms":443,"mutex_wait_us":2,"peak_mem_usage":50689328,"reinsert_count":0,"update_count":2000}
I20260812 06:20:12.597081 25839 maintenance_manager.cc:419] P 02d6dd386c2a4e0d97fe61e209e67a49: Scheduling FlushDeltaMemStoresOp(870e9336c2c14a2caa588cef5073b84a): perf score=11.118625
I20260812 06:20:12.646477 25774 maintenance_manager.cc:643] P 02d6dd386c2a4e0d97fe61e209e67a49: FlushDeltaMemStoresOp(870e9336c2c14a2caa588cef5073b84a) complete. Timing: real 0.049s	user 0.015s	sys 0.028s Metrics: {"bytes_written":12717735,"delete_count":0,"lbm_write_time_us":19965,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":312,"reinsert_count":0,"update_count":1550}
I20260812 06:20:12.646960 25839 maintenance_manager.cc:419] P 02d6dd386c2a4e0d97fe61e209e67a49: Scheduling FlushDeltaMemStoresOp(870e9336c2c14a2caa588cef5073b84a): perf score=2.188937
I20260812 06:20:12.658128 25774 maintenance_manager.cc:643] P 02d6dd386c2a4e0d97fe61e209e67a49: FlushDeltaMemStoresOp(870e9336c2c14a2caa588cef5073b84a) complete. Timing: real 0.011s	user 0.009s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4005,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:12.658655 25839 maintenance_manager.cc:419] P 02d6dd386c2a4e0d97fe61e209e67a49: Scheduling FlushDeltaMemStoresOp(870e9336c2c14a2caa588cef5073b84a): perf score=2.188937
I20260812 06:20:12.668491 25774 maintenance_manager.cc:643] P 02d6dd386c2a4e0d97fe61e209e67a49: FlushDeltaMemStoresOp(870e9336c2c14a2caa588cef5073b84a) complete. Timing: real 0.010s	user 0.005s	sys 0.004s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3609,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:20:12.668972 25839 maintenance_manager.cc:419] P 02d6dd386c2a4e0d97fe61e209e67a49: Scheduling MajorDeltaCompactionOp(870e9336c2c14a2caa588cef5073b84a): perf score=1.000000
I20260812 06:20:12.833662 25774 maintenance_manager.cc:643] P 02d6dd386c2a4e0d97fe61e209e67a49: MajorDeltaCompactionOp(870e9336c2c14a2caa588cef5073b84a) complete. Timing: real 0.164s	user 0.130s	sys 0.031s Metrics: {"cfile_cache_miss":533,"cfile_cache_miss_bytes":24774799,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":1146,"lbm_read_time_us":12596,"lbm_reads_lt_1ms":573,"lbm_write_time_us":29604,"lbm_writes_lt_1ms":543,"mutex_wait_us":56,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":956416,"update_count":2500}
I20260812 06:20:12.834489 25839 maintenance_manager.cc:419] P 02d6dd386c2a4e0d97fe61e209e67a49: Scheduling FlushDeltaMemStoresOp(870e9336c2c14a2caa588cef5073b84a): perf score=11.118625
I20260812 06:20:12.868966 25774 maintenance_manager.cc:643] P 02d6dd386c2a4e0d97fe61e209e67a49: FlushDeltaMemStoresOp(870e9336c2c14a2caa588cef5073b84a) complete. Timing: real 0.034s	user 0.025s	sys 0.008s Metrics: {"bytes_written":12717735,"delete_count":0,"lbm_write_time_us":13882,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:20:12.869585 25839 maintenance_manager.cc:419] P 02d6dd386c2a4e0d97fe61e209e67a49: Scheduling FlushDeltaMemStoresOp(870e9336c2c14a2caa588cef5073b84a): perf score=2.188937
I20260812 06:20:12.896445 25774 maintenance_manager.cc:643] P 02d6dd386c2a4e0d97fe61e209e67a49: FlushDeltaMemStoresOp(870e9336c2c14a2caa588cef5073b84a) complete. Timing: real 0.027s	user 0.009s	sys 0.005s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":5543,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:20:12.896999 25839 maintenance_manager.cc:419] P 02d6dd386c2a4e0d97fe61e209e67a49: Scheduling FlushDeltaMemStoresOp(870e9336c2c14a2caa588cef5073b84a): perf score=2.188937
I20260812 06:20:12.912207 25774 maintenance_manager.cc:643] P 02d6dd386c2a4e0d97fe61e209e67a49: FlushDeltaMemStoresOp(870e9336c2c14a2caa588cef5073b84a) complete. Timing: real 0.015s	user 0.007s	sys 0.006s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5725,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:12.912807 25839 maintenance_manager.cc:419] P 02d6dd386c2a4e0d97fe61e209e67a49: Scheduling MajorDeltaCompactionOp(870e9336c2c14a2caa588cef5073b84a): perf score=1.000000
I20260812 06:20:13.069203 25774 maintenance_manager.cc:643] P 02d6dd386c2a4e0d97fe61e209e67a49: MajorDeltaCompactionOp(870e9336c2c14a2caa588cef5073b84a) complete. Timing: real 0.156s	user 0.119s	sys 0.031s Metrics: {"cfile_cache_miss":533,"cfile_cache_miss_bytes":24774799,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":1032,"lbm_read_time_us":9632,"lbm_reads_lt_1ms":573,"lbm_write_time_us":32297,"lbm_writes_lt_1ms":543,"mutex_wait_us":486,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":2944,"update_count":2500}
I20260812 06:20:13.069896 25839 maintenance_manager.cc:419] P 02d6dd386c2a4e0d97fe61e209e67a49: Scheduling FlushDeltaMemStoresOp(870e9336c2c14a2caa588cef5073b84a): perf score=11.118625
I20260812 06:20:13.112574 25774 maintenance_manager.cc:643] P 02d6dd386c2a4e0d97fe61e209e67a49: FlushDeltaMemStoresOp(870e9336c2c14a2caa588cef5073b84a) complete. Timing: real 0.042s	user 0.016s	sys 0.025s Metrics: {"bytes_written":12717735,"delete_count":0,"lbm_write_time_us":20043,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":312,"reinsert_count":0,"update_count":1550}
I20260812 06:20:13.113304 25839 maintenance_manager.cc:419] P 02d6dd386c2a4e0d97fe61e209e67a49: Scheduling FlushDeltaMemStoresOp(870e9336c2c14a2caa588cef5073b84a): perf score=2.188937
I20260812 06:20:13.132660 25774 maintenance_manager.cc:643] P 02d6dd386c2a4e0d97fe61e209e67a49: FlushDeltaMemStoresOp(870e9336c2c14a2caa588cef5073b84a) complete. Timing: real 0.019s	user 0.004s	sys 0.008s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":5112,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:20:13.133121 25839 maintenance_manager.cc:419] P 02d6dd386c2a4e0d97fe61e209e67a49: Scheduling FlushDeltaMemStoresOp(870e9336c2c14a2caa588cef5073b84a): perf score=2.188937
I20260812 06:20:13.143568 25774 maintenance_manager.cc:643] P 02d6dd386c2a4e0d97fe61e209e67a49: FlushDeltaMemStoresOp(870e9336c2c14a2caa588cef5073b84a) complete. Timing: real 0.010s	user 0.010s	sys 0.000s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":3901,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:13.144063 25839 maintenance_manager.cc:419] P 02d6dd386c2a4e0d97fe61e209e67a49: Scheduling MajorDeltaCompactionOp(870e9336c2c14a2caa588cef5073b84a): perf score=1.000000
I20260812 06:20:13.293304 25774 maintenance_manager.cc:643] P 02d6dd386c2a4e0d97fe61e209e67a49: MajorDeltaCompactionOp(870e9336c2c14a2caa588cef5073b84a) complete. Timing: real 0.149s	user 0.104s	sys 0.044s Metrics: {"cfile_cache_miss":533,"cfile_cache_miss_bytes":24774798,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":323,"lbm_read_time_us":10348,"lbm_reads_lt_1ms":573,"lbm_write_time_us":30540,"lbm_writes_lt_1ms":543,"mutex_wait_us":50,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":18304,"update_count":2500}
I20260812 06:20:13.295713 25839 maintenance_manager.cc:419] P 02d6dd386c2a4e0d97fe61e209e67a49: Scheduling FlushDeltaMemStoresOp(870e9336c2c14a2caa588cef5073b84a): perf score=10.126437
I20260812 06:20:13.338272 25774 maintenance_manager.cc:643] P 02d6dd386c2a4e0d97fe61e209e67a49: FlushDeltaMemStoresOp(870e9336c2c14a2caa588cef5073b84a) complete. Timing: real 0.042s	user 0.014s	sys 0.024s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":18563,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:20:13.338829 25839 maintenance_manager.cc:419] P 02d6dd386c2a4e0d97fe61e209e67a49: Scheduling FlushDeltaMemStoresOp(870e9336c2c14a2caa588cef5073b84a): perf score=2.188937
I20260812 06:20:13.350880 25774 maintenance_manager.cc:643] P 02d6dd386c2a4e0d97fe61e209e67a49: FlushDeltaMemStoresOp(870e9336c2c14a2caa588cef5073b84a) complete. Timing: real 0.012s	user 0.009s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4013,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:13.351545 25839 maintenance_manager.cc:419] P 02d6dd386c2a4e0d97fe61e209e67a49: Scheduling MajorDeltaCompactionOp(870e9336c2c14a2caa588cef5073b84a): perf score=1.000000
I20260812 06:20:13.480665 25774 maintenance_manager.cc:643] P 02d6dd386c2a4e0d97fe61e209e67a49: MajorDeltaCompactionOp(870e9336c2c14a2caa588cef5073b84a) complete. Timing: real 0.129s	user 0.109s	sys 0.020s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672277,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":962,"lbm_read_time_us":9607,"lbm_reads_lt_1ms":472,"lbm_write_time_us":24804,"lbm_writes_lt_1ms":443,"mutex_wait_us":21,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":26368,"update_count":2000}
I20260812 06:20:13.481475 25839 maintenance_manager.cc:419] P 02d6dd386c2a4e0d97fe61e209e67a49: Scheduling FlushDeltaMemStoresOp(870e9336c2c14a2caa588cef5073b84a): perf score=10.126437
I20260812 06:20:13.531772 25774 maintenance_manager.cc:643] P 02d6dd386c2a4e0d97fe61e209e67a49: FlushDeltaMemStoresOp(870e9336c2c14a2caa588cef5073b84a) complete. Timing: real 0.050s	user 0.019s	sys 0.031s Metrics: {"bytes_written":12307491,"delete_count":0,"lbm_write_time_us":16606,"lbm_writes_lt_1ms":303,"reinsert_count":0,"spinlock_wait_cycles":1280,"update_count":1500}
I20260812 06:20:13.532490 25839 maintenance_manager.cc:419] P 02d6dd386c2a4e0d97fe61e209e67a49: Scheduling FlushDeltaMemStoresOp(870e9336c2c14a2caa588cef5073b84a): perf score=2.188937
I20260812 06:20:13.545087 25774 maintenance_manager.cc:643] P 02d6dd386c2a4e0d97fe61e209e67a49: FlushDeltaMemStoresOp(870e9336c2c14a2caa588cef5073b84a) complete. Timing: real 0.012s	user 0.011s	sys 0.000s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":5101,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:13.545594 25839 maintenance_manager.cc:419] P 02d6dd386c2a4e0d97fe61e209e67a49: Scheduling FlushMRSOp(870e9336c2c14a2caa588cef5073b84a): perf score=1.000000
I20260812 06:20:13.589244 25774 maintenance_manager.cc:643] P 02d6dd386c2a4e0d97fe61e209e67a49: FlushMRSOp(870e9336c2c14a2caa588cef5073b84a) complete. Timing: real 0.043s	user 0.036s	sys 0.000s Metrics: {"bytes_written":1275443,"cfile_init":1,"dirs.queue_time_us":80,"dirs.run_cpu_time_us":216,"dirs.run_wall_time_us":1407,"drs_written":1,"lbm_read_time_us":67,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1426,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":31}
I20260812 06:20:13.589946 25839 maintenance_manager.cc:419] P 02d6dd386c2a4e0d97fe61e209e67a49: Scheduling LogGCOp(870e9336c2c14a2caa588cef5073b84a): free 129320441 bytes of WAL
I20260812 06:20:13.590197 25774 log_reader.cc:385] T 870e9336c2c14a2caa588cef5073b84a: removed 13 log segments from log reader
I20260812 06:20:13.590241 25774 log.cc:1079] T 870e9336c2c14a2caa588cef5073b84a P 02d6dd386c2a4e0d97fe61e209e67a49: Deleting log segment in path: /tmp/dist-test-taskWwF8e7/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515606164878-25448-0/minicluster-data/ts-0-root/wals/870e9336c2c14a2caa588cef5073b84a/wal-000000003 (ops 11-15)
I20260812 06:20:13.590271 25774 log.cc:1079] T 870e9336c2c14a2caa588cef5073b84a P 02d6dd386c2a4e0d97fe61e209e67a49: Deleting log segment in path: /tmp/dist-test-taskWwF8e7/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515606164878-25448-0/minicluster-data/ts-0-root/wals/870e9336c2c14a2caa588cef5073b84a/wal-000000004 (ops 16-20)
I20260812 06:20:13.590333 25774 log.cc:1079] T 870e9336c2c14a2caa588cef5073b84a P 02d6dd386c2a4e0d97fe61e209e67a49: Deleting log segment in path: /tmp/dist-test-taskWwF8e7/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515606164878-25448-0/minicluster-data/ts-0-root/wals/870e9336c2c14a2caa588cef5073b84a/wal-000000005 (ops 21-25)
I20260812 06:20:13.590397 25774 log.cc:1079] T 870e9336c2c14a2caa588cef5073b84a P 02d6dd386c2a4e0d97fe61e209e67a49: Deleting log segment in path: /tmp/dist-test-taskWwF8e7/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515606164878-25448-0/minicluster-data/ts-0-root/wals/870e9336c2c14a2caa588cef5073b84a/wal-000000006 (ops 26-30)
I20260812 06:20:13.590438 25774 log.cc:1079] T 870e9336c2c14a2caa588cef5073b84a P 02d6dd386c2a4e0d97fe61e209e67a49: Deleting log segment in path: /tmp/dist-test-taskWwF8e7/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515606164878-25448-0/minicluster-data/ts-0-root/wals/870e9336c2c14a2caa588cef5073b84a/wal-000000007 (ops 31-35)
I20260812 06:20:13.590476 25774 log.cc:1079] T 870e9336c2c14a2caa588cef5073b84a P 02d6dd386c2a4e0d97fe61e209e67a49: Deleting log segment in path: /tmp/dist-test-taskWwF8e7/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515606164878-25448-0/minicluster-data/ts-0-root/wals/870e9336c2c14a2caa588cef5073b84a/wal-000000008 (ops 36-40)
I20260812 06:20:13.590514 25774 log.cc:1079] T 870e9336c2c14a2caa588cef5073b84a P 02d6dd386c2a4e0d97fe61e209e67a49: Deleting log segment in path: /tmp/dist-test-taskWwF8e7/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515606164878-25448-0/minicluster-data/ts-0-root/wals/870e9336c2c14a2caa588cef5073b84a/wal-000000009 (ops 41-45)
I20260812 06:20:13.590551 25774 log.cc:1079] T 870e9336c2c14a2caa588cef5073b84a P 02d6dd386c2a4e0d97fe61e209e67a49: Deleting log segment in path: /tmp/dist-test-taskWwF8e7/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515606164878-25448-0/minicluster-data/ts-0-root/wals/870e9336c2c14a2caa588cef5073b84a/wal-000000010 (ops 46-50)
I20260812 06:20:13.590590 25774 log.cc:1079] T 870e9336c2c14a2caa588cef5073b84a P 02d6dd386c2a4e0d97fe61e209e67a49: Deleting log segment in path: /tmp/dist-test-taskWwF8e7/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515606164878-25448-0/minicluster-data/ts-0-root/wals/870e9336c2c14a2caa588cef5073b84a/wal-000000011 (ops 51-54)
I20260812 06:20:13.590631 25774 log.cc:1079] T 870e9336c2c14a2caa588cef5073b84a P 02d6dd386c2a4e0d97fe61e209e67a49: Deleting log segment in path: /tmp/dist-test-taskWwF8e7/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515606164878-25448-0/minicluster-data/ts-0-root/wals/870e9336c2c14a2caa588cef5073b84a/wal-000000012 (ops 55-59)
I20260812 06:20:13.590665 25774 log.cc:1079] T 870e9336c2c14a2caa588cef5073b84a P 02d6dd386c2a4e0d97fe61e209e67a49: Deleting log segment in path: /tmp/dist-test-taskWwF8e7/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515606164878-25448-0/minicluster-data/ts-0-root/wals/870e9336c2c14a2caa588cef5073b84a/wal-000000013 (ops 60-64)
I20260812 06:20:13.590700 25774 log.cc:1079] T 870e9336c2c14a2caa588cef5073b84a P 02d6dd386c2a4e0d97fe61e209e67a49: Deleting log segment in path: /tmp/dist-test-taskWwF8e7/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515606164878-25448-0/minicluster-data/ts-0-root/wals/870e9336c2c14a2caa588cef5073b84a/wal-000000014 (ops 65-68)
I20260812 06:20:13.590739 25774 log.cc:1079] T 870e9336c2c14a2caa588cef5073b84a P 02d6dd386c2a4e0d97fe61e209e67a49: Deleting log segment in path: /tmp/dist-test-taskWwF8e7/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515606164878-25448-0/minicluster-data/ts-0-root/wals/870e9336c2c14a2caa588cef5073b84a/wal-000000015 (ops 69-73)
I20260812 06:20:13.619549 25774 maintenance_manager.cc:643] P 02d6dd386c2a4e0d97fe61e209e67a49: LogGCOp(870e9336c2c14a2caa588cef5073b84a) complete. Timing: real 0.029s	user 0.000s	sys 0.029s Metrics: {}
I20260812 06:20:13.620105 25839 maintenance_manager.cc:419] P 02d6dd386c2a4e0d97fe61e209e67a49: Scheduling UndoDeltaBlockGCOp(870e9336c2c14a2caa588cef5073b84a): 482 bytes on disk
I20260812 06:20:13.620697 25774 maintenance_manager.cc:643] P 02d6dd386c2a4e0d97fe61e209e67a49: UndoDeltaBlockGCOp(870e9336c2c14a2caa588cef5073b84a) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":74,"lbm_reads_lt_1ms":4}
I20260812 06:20:13.621268 25839 maintenance_manager.cc:419] P 02d6dd386c2a4e0d97fe61e209e67a49: Scheduling FlushDeltaMemStoresOp(870e9336c2c14a2caa588cef5073b84a): perf score=3.181125
I20260812 06:20:13.642030 25774 maintenance_manager.cc:643] P 02d6dd386c2a4e0d97fe61e209e67a49: FlushDeltaMemStoresOp(870e9336c2c14a2caa588cef5073b84a) complete. Timing: real 0.021s	user 0.012s	sys 0.004s Metrics: {"bytes_written":4512900,"delete_count":0,"lbm_write_time_us":7214,"lbm_writes_lt_1ms":113,"reinsert_count":0,"update_count":550}
I20260812 06:20:13.642531 25839 maintenance_manager.cc:419] P 02d6dd386c2a4e0d97fe61e209e67a49: Scheduling FlushDeltaMemStoresOp(870e9336c2c14a2caa588cef5073b84a): perf score=2.188937
I20260812 06:20:13.652885 25774 maintenance_manager.cc:643] P 02d6dd386c2a4e0d97fe61e209e67a49: FlushDeltaMemStoresOp(870e9336c2c14a2caa588cef5073b84a) complete. Timing: real 0.010s	user 0.004s	sys 0.004s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3698,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:20:13.653375 25839 maintenance_manager.cc:419] P 02d6dd386c2a4e0d97fe61e209e67a49: Scheduling MajorDeltaCompactionOp(870e9336c2c14a2caa588cef5073b84a): perf score=1.000000
I20260812 06:20:13.856257 25774 maintenance_manager.cc:643] P 02d6dd386c2a4e0d97fe61e209e67a49: MajorDeltaCompactionOp(870e9336c2c14a2caa588cef5073b84a) complete. Timing: real 0.203s	user 0.132s	sys 0.071s Metrics: {"cfile_cache_miss":634,"cfile_cache_miss_bytes":28877326,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":338,"lbm_read_time_us":12612,"lbm_reads_lt_1ms":674,"lbm_write_time_us":31978,"lbm_writes_lt_1ms":643,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":111488,"thread_start_us":111,"threads_started":1,"update_count":3000}
I20260812 06:20:13.857344 25839 maintenance_manager.cc:419] P 02d6dd386c2a4e0d97fe61e209e67a49: Scheduling FlushDeltaMemStoresOp(870e9336c2c14a2caa588cef5073b84a): perf score=14.095187
I20260812 06:20:13.911204 25774 maintenance_manager.cc:643] P 02d6dd386c2a4e0d97fe61e209e67a49: FlushDeltaMemStoresOp(870e9336c2c14a2caa588cef5073b84a) complete. Timing: real 0.053s	user 0.039s	sys 0.011s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":24015,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:20:13.911788 25839 maintenance_manager.cc:419] P 02d6dd386c2a4e0d97fe61e209e67a49: Scheduling FlushDeltaMemStoresOp(870e9336c2c14a2caa588cef5073b84a): perf score=2.188937
I20260812 06:20:13.924248 25774 maintenance_manager.cc:643] P 02d6dd386c2a4e0d97fe61e209e67a49: FlushDeltaMemStoresOp(870e9336c2c14a2caa588cef5073b84a) complete. Timing: real 0.012s	user 0.003s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4522,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:13.924778 25839 maintenance_manager.cc:419] P 02d6dd386c2a4e0d97fe61e209e67a49: Scheduling MajorDeltaCompactionOp(870e9336c2c14a2caa588cef5073b84a): perf score=1.000000
I20260812 06:20:14.101945 25774 maintenance_manager.cc:643] P 02d6dd386c2a4e0d97fe61e209e67a49: MajorDeltaCompactionOp(870e9336c2c14a2caa588cef5073b84a) complete. Timing: real 0.177s	user 0.122s	sys 0.053s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774689,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":1364,"lbm_read_time_us":11119,"lbm_reads_lt_1ms":572,"lbm_write_time_us":30109,"lbm_writes_lt_1ms":543,"mutex_wait_us":517,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":5504,"update_count":2500}
I20260812 06:20:14.102675 25839 maintenance_manager.cc:419] P 02d6dd386c2a4e0d97fe61e209e67a49: Scheduling FlushDeltaMemStoresOp(870e9336c2c14a2caa588cef5073b84a): perf score=14.095187
I20260812 06:20:14.165372 25774 maintenance_manager.cc:643] P 02d6dd386c2a4e0d97fe61e209e67a49: FlushDeltaMemStoresOp(870e9336c2c14a2caa588cef5073b84a) complete. Timing: real 0.062s	user 0.034s	sys 0.027s Metrics: {"bytes_written":16409904,"delete_count":0,"lbm_write_time_us":24325,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:20:14.165980 25839 maintenance_manager.cc:419] P 02d6dd386c2a4e0d97fe61e209e67a49: Scheduling FlushDeltaMemStoresOp(870e9336c2c14a2caa588cef5073b84a): perf score=2.188937
I20260812 06:20:14.178254 25774 maintenance_manager.cc:643] P 02d6dd386c2a4e0d97fe61e209e67a49: FlushDeltaMemStoresOp(870e9336c2c14a2caa588cef5073b84a) complete. Timing: real 0.012s	user 0.009s	sys 0.000s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4272,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:14.178838 25839 maintenance_manager.cc:419] P 02d6dd386c2a4e0d97fe61e209e67a49: Scheduling MajorDeltaCompactionOp(870e9336c2c14a2caa588cef5073b84a): perf score=1.000000
I20260812 06:20:14.367515 25774 maintenance_manager.cc:643] P 02d6dd386c2a4e0d97fe61e209e67a49: MajorDeltaCompactionOp(870e9336c2c14a2caa588cef5073b84a) complete. Timing: real 0.188s	user 0.129s	sys 0.052s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774690,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":305,"lbm_read_time_us":14004,"lbm_reads_lt_1ms":572,"lbm_write_time_us":29031,"lbm_writes_lt_1ms":543,"mutex_wait_us":44,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":13696,"update_count":2500}
I20260812 06:20:14.368248 25839 maintenance_manager.cc:419] P 02d6dd386c2a4e0d97fe61e209e67a49: Scheduling FlushDeltaMemStoresOp(870e9336c2c14a2caa588cef5073b84a): perf score=14.095187
I20260812 06:20:14.435001 25774 maintenance_manager.cc:643] P 02d6dd386c2a4e0d97fe61e209e67a49: FlushDeltaMemStoresOp(870e9336c2c14a2caa588cef5073b84a) complete. Timing: real 0.067s	user 0.030s	sys 0.027s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":23637,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:20:14.435642 25839 maintenance_manager.cc:419] P 02d6dd386c2a4e0d97fe61e209e67a49: Scheduling FlushDeltaMemStoresOp(870e9336c2c14a2caa588cef5073b84a): perf score=2.188937
I20260812 06:20:14.446592 25774 maintenance_manager.cc:643] P 02d6dd386c2a4e0d97fe61e209e67a49: FlushDeltaMemStoresOp(870e9336c2c14a2caa588cef5073b84a) complete. Timing: real 0.011s	user 0.009s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4305,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:14.447086 25839 maintenance_manager.cc:419] P 02d6dd386c2a4e0d97fe61e209e67a49: Scheduling MajorDeltaCompactionOp(870e9336c2c14a2caa588cef5073b84a): perf score=1.000000
I20260812 06:20:14.644660 25774 maintenance_manager.cc:643] P 02d6dd386c2a4e0d97fe61e209e67a49: MajorDeltaCompactionOp(870e9336c2c14a2caa588cef5073b84a) complete. Timing: real 0.197s	user 0.128s	sys 0.064s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774688,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":1127,"lbm_read_time_us":14593,"lbm_reads_lt_1ms":572,"lbm_write_time_us":33175,"lbm_writes_lt_1ms":543,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":5504,"update_count":2500}
I20260812 06:20:14.645531 25839 maintenance_manager.cc:419] P 02d6dd386c2a4e0d97fe61e209e67a49: Scheduling FlushDeltaMemStoresOp(870e9336c2c14a2caa588cef5073b84a): perf score=11.118625
I20260812 06:20:14.685923 25774 maintenance_manager.cc:643] P 02d6dd386c2a4e0d97fe61e209e67a49: FlushDeltaMemStoresOp(870e9336c2c14a2caa588cef5073b84a) complete. Timing: real 0.040s	user 0.018s	sys 0.020s Metrics: {"bytes_written":12717735,"delete_count":0,"lbm_write_time_us":17257,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:20:14.686539 25839 maintenance_manager.cc:419] P 02d6dd386c2a4e0d97fe61e209e67a49: Scheduling FlushDeltaMemStoresOp(870e9336c2c14a2caa588cef5073b84a): perf score=2.188937
I20260812 06:20:14.703204 25774 maintenance_manager.cc:643] P 02d6dd386c2a4e0d97fe61e209e67a49: FlushDeltaMemStoresOp(870e9336c2c14a2caa588cef5073b84a) complete. Timing: real 0.016s	user 0.011s	sys 0.000s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":5234,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:20:14.703846 25839 maintenance_manager.cc:419] P 02d6dd386c2a4e0d97fe61e209e67a49: Scheduling MajorDeltaCompactionOp(870e9336c2c14a2caa588cef5073b84a): perf score=1.000000
I20260812 06:20:14.879773 25774 maintenance_manager.cc:643] P 02d6dd386c2a4e0d97fe61e209e67a49: MajorDeltaCompactionOp(870e9336c2c14a2caa588cef5073b84a) complete. Timing: real 0.176s	user 0.111s	sys 0.051s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672268,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":137,"lbm_read_time_us":10300,"lbm_reads_lt_1ms":464,"lbm_write_time_us":23991,"lbm_writes_lt_1ms":443,"mutex_wait_us":18,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":54400,"update_count":2000}
I20260812 06:20:14.880491 25839 maintenance_manager.cc:419] P 02d6dd386c2a4e0d97fe61e209e67a49: Scheduling FlushDeltaMemStoresOp(870e9336c2c14a2caa588cef5073b84a): perf score=14.095187
I20260812 06:20:14.933631 25774 maintenance_manager.cc:643] P 02d6dd386c2a4e0d97fe61e209e67a49: FlushDeltaMemStoresOp(870e9336c2c14a2caa588cef5073b84a) complete. Timing: real 0.053s	user 0.027s	sys 0.021s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":23029,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:20:14.934171 25839 maintenance_manager.cc:419] P 02d6dd386c2a4e0d97fe61e209e67a49: Scheduling FlushDeltaMemStoresOp(870e9336c2c14a2caa588cef5073b84a): perf score=2.188937
I20260812 06:20:14.945417 25774 maintenance_manager.cc:643] P 02d6dd386c2a4e0d97fe61e209e67a49: FlushDeltaMemStoresOp(870e9336c2c14a2caa588cef5073b84a) complete. Timing: real 0.011s	user 0.004s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4118,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:14.945899 25839 maintenance_manager.cc:419] P 02d6dd386c2a4e0d97fe61e209e67a49: Scheduling MajorDeltaCompactionOp(870e9336c2c14a2caa588cef5073b84a): perf score=1.000000
I20260812 06:20:15.102049 25774 maintenance_manager.cc:643] P 02d6dd386c2a4e0d97fe61e209e67a49: MajorDeltaCompactionOp(870e9336c2c14a2caa588cef5073b84a) complete. Timing: real 0.156s	user 0.126s	sys 0.029s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774688,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":243,"lbm_read_time_us":9611,"lbm_reads_lt_1ms":572,"lbm_write_time_us":32945,"lbm_writes_lt_1ms":543,"mutex_wait_us":38,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":3968,"update_count":2500}
I20260812 06:20:15.102795 25839 maintenance_manager.cc:419] P 02d6dd386c2a4e0d97fe61e209e67a49: Scheduling FlushDeltaMemStoresOp(870e9336c2c14a2caa588cef5073b84a): perf score=11.118625
I20260812 06:20:15.142684 25774 maintenance_manager.cc:643] P 02d6dd386c2a4e0d97fe61e209e67a49: FlushDeltaMemStoresOp(870e9336c2c14a2caa588cef5073b84a) complete. Timing: real 0.040s	user 0.018s	sys 0.019s Metrics: {"bytes_written":12717734,"delete_count":0,"lbm_write_time_us":17738,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:20:15.143354 25839 maintenance_manager.cc:419] P 02d6dd386c2a4e0d97fe61e209e67a49: Scheduling FlushDeltaMemStoresOp(870e9336c2c14a2caa588cef5073b84a): perf score=2.188937
I20260812 06:20:15.155120 25774 maintenance_manager.cc:643] P 02d6dd386c2a4e0d97fe61e209e67a49: FlushDeltaMemStoresOp(870e9336c2c14a2caa588cef5073b84a) complete. Timing: real 0.012s	user 0.010s	sys 0.001s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":4319,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:20:15.155627 25839 maintenance_manager.cc:419] P 02d6dd386c2a4e0d97fe61e209e67a49: Scheduling FlushMRSOp(870e9336c2c14a2caa588cef5073b84a): perf score=1.000000
I20260812 06:20:15.184996 25774 maintenance_manager.cc:643] P 02d6dd386c2a4e0d97fe61e209e67a49: FlushMRSOp(870e9336c2c14a2caa588cef5073b84a) complete. Timing: real 0.029s	user 0.026s	sys 0.002s Metrics: {"bytes_written":1234479,"cfile_init":1,"dirs.queue_time_us":76,"dirs.run_cpu_time_us":241,"dirs.run_wall_time_us":1368,"drs_written":1,"lbm_read_time_us":85,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1433,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":30}
I20260812 06:20:15.185631 25839 maintenance_manager.cc:419] P 02d6dd386c2a4e0d97fe61e209e67a49: Scheduling LogGCOp(870e9336c2c14a2caa588cef5073b84a): free 121006505 bytes of WAL
I20260812 06:20:15.185854 25774 log_reader.cc:385] T 870e9336c2c14a2caa588cef5073b84a: removed 12 log segments from log reader
I20260812 06:20:15.185897 25774 log.cc:1079] T 870e9336c2c14a2caa588cef5073b84a P 02d6dd386c2a4e0d97fe61e209e67a49: Deleting log segment in path: /tmp/dist-test-taskWwF8e7/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515606164878-25448-0/minicluster-data/ts-0-root/wals/870e9336c2c14a2caa588cef5073b84a/wal-000000016 (ops 74-78)
I20260812 06:20:15.185926 25774 log.cc:1079] T 870e9336c2c14a2caa588cef5073b84a P 02d6dd386c2a4e0d97fe61e209e67a49: Deleting log segment in path: /tmp/dist-test-taskWwF8e7/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515606164878-25448-0/minicluster-data/ts-0-root/wals/870e9336c2c14a2caa588cef5073b84a/wal-000000017 (ops 79-83)
I20260812 06:20:15.185943 25774 log.cc:1079] T 870e9336c2c14a2caa588cef5073b84a P 02d6dd386c2a4e0d97fe61e209e67a49: Deleting log segment in path: /tmp/dist-test-taskWwF8e7/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515606164878-25448-0/minicluster-data/ts-0-root/wals/870e9336c2c14a2caa588cef5073b84a/wal-000000018 (ops 84-88)
I20260812 06:20:15.186002 25774 log.cc:1079] T 870e9336c2c14a2caa588cef5073b84a P 02d6dd386c2a4e0d97fe61e209e67a49: Deleting log segment in path: /tmp/dist-test-taskWwF8e7/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515606164878-25448-0/minicluster-data/ts-0-root/wals/870e9336c2c14a2caa588cef5073b84a/wal-000000019 (ops 89-93)
I20260812 06:20:15.186045 25774 log.cc:1079] T 870e9336c2c14a2caa588cef5073b84a P 02d6dd386c2a4e0d97fe61e209e67a49: Deleting log segment in path: /tmp/dist-test-taskWwF8e7/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515606164878-25448-0/minicluster-data/ts-0-root/wals/870e9336c2c14a2caa588cef5073b84a/wal-000000020 (ops 94-98)
I20260812 06:20:15.186064 25774 log.cc:1079] T 870e9336c2c14a2caa588cef5073b84a P 02d6dd386c2a4e0d97fe61e209e67a49: Deleting log segment in path: /tmp/dist-test-taskWwF8e7/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515606164878-25448-0/minicluster-data/ts-0-root/wals/870e9336c2c14a2caa588cef5073b84a/wal-000000021 (ops 99-103)
I20260812 06:20:15.186105 25774 log.cc:1079] T 870e9336c2c14a2caa588cef5073b84a P 02d6dd386c2a4e0d97fe61e209e67a49: Deleting log segment in path: /tmp/dist-test-taskWwF8e7/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515606164878-25448-0/minicluster-data/ts-0-root/wals/870e9336c2c14a2caa588cef5073b84a/wal-000000022 (ops 104-108)
I20260812 06:20:15.186146 25774 log.cc:1079] T 870e9336c2c14a2caa588cef5073b84a P 02d6dd386c2a4e0d97fe61e209e67a49: Deleting log segment in path: /tmp/dist-test-taskWwF8e7/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515606164878-25448-0/minicluster-data/ts-0-root/wals/870e9336c2c14a2caa588cef5073b84a/wal-000000023 (ops 109-112)
I20260812 06:20:15.186199 25774 log.cc:1079] T 870e9336c2c14a2caa588cef5073b84a P 02d6dd386c2a4e0d97fe61e209e67a49: Deleting log segment in path: /tmp/dist-test-taskWwF8e7/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515606164878-25448-0/minicluster-data/ts-0-root/wals/870e9336c2c14a2caa588cef5073b84a/wal-000000024 (ops 113-117)
I20260812 06:20:15.186236 25774 log.cc:1079] T 870e9336c2c14a2caa588cef5073b84a P 02d6dd386c2a4e0d97fe61e209e67a49: Deleting log segment in path: /tmp/dist-test-taskWwF8e7/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515606164878-25448-0/minicluster-data/ts-0-root/wals/870e9336c2c14a2caa588cef5073b84a/wal-000000025 (ops 118-122)
I20260812 06:20:15.186275 25774 log.cc:1079] T 870e9336c2c14a2caa588cef5073b84a P 02d6dd386c2a4e0d97fe61e209e67a49: Deleting log segment in path: /tmp/dist-test-taskWwF8e7/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515606164878-25448-0/minicluster-data/ts-0-root/wals/870e9336c2c14a2caa588cef5073b84a/wal-000000026 (ops 123-127)
I20260812 06:20:15.186312 25774 log.cc:1079] T 870e9336c2c14a2caa588cef5073b84a P 02d6dd386c2a4e0d97fe61e209e67a49: Deleting log segment in path: /tmp/dist-test-taskWwF8e7/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515606164878-25448-0/minicluster-data/ts-0-root/wals/870e9336c2c14a2caa588cef5073b84a/wal-000000027 (ops 128-132)
I20260812 06:20:15.214357 25774 maintenance_manager.cc:643] P 02d6dd386c2a4e0d97fe61e209e67a49: LogGCOp(870e9336c2c14a2caa588cef5073b84a) complete. Timing: real 0.029s	user 0.000s	sys 0.025s Metrics: {}
I20260812 06:20:15.214857 25839 maintenance_manager.cc:419] P 02d6dd386c2a4e0d97fe61e209e67a49: Scheduling FlushDeltaMemStoresOp(870e9336c2c14a2caa588cef5073b84a): perf score=4.173312
I20260812 06:20:15.232836 25774 maintenance_manager.cc:643] P 02d6dd386c2a4e0d97fe61e209e67a49: FlushDeltaMemStoresOp(870e9336c2c14a2caa588cef5073b84a) complete. Timing: real 0.018s	user 0.012s	sys 0.004s Metrics: {"bytes_written":5251342,"delete_count":0,"lbm_write_time_us":7387,"lbm_writes_lt_1ms":131,"reinsert_count":0,"update_count":640}
I20260812 06:20:15.233304 25839 maintenance_manager.cc:419] P 02d6dd386c2a4e0d97fe61e209e67a49: Scheduling UndoDeltaBlockGCOp(870e9336c2c14a2caa588cef5073b84a): 472 bytes on disk
I20260812 06:20:15.233757 25774 maintenance_manager.cc:643] P 02d6dd386c2a4e0d97fe61e209e67a49: UndoDeltaBlockGCOp(870e9336c2c14a2caa588cef5073b84a) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":54,"lbm_reads_lt_1ms":4}
I20260812 06:20:15.234272 25839 maintenance_manager.cc:419] P 02d6dd386c2a4e0d97fe61e209e67a49: Scheduling FlushDeltaMemStoresOp(870e9336c2c14a2caa588cef5073b84a): perf score=1.196750
I20260812 06:20:15.245757 25774 maintenance_manager.cc:643] P 02d6dd386c2a4e0d97fe61e209e67a49: FlushDeltaMemStoresOp(870e9336c2c14a2caa588cef5073b84a) complete. Timing: real 0.011s	user 0.005s	sys 0.004s Metrics: {"bytes_written":2953955,"delete_count":0,"lbm_write_time_us":3720,"lbm_writes_lt_1ms":75,"reinsert_count":0,"update_count":360}
I20260812 06:20:15.246194 25839 maintenance_manager.cc:419] P 02d6dd386c2a4e0d97fe61e209e67a49: Scheduling MajorDeltaCompactionOp(870e9336c2c14a2caa588cef5073b84a): perf score=1.000000
I20260812 06:20:15.411533 25774 maintenance_manager.cc:643] P 02d6dd386c2a4e0d97fe61e209e67a49: MajorDeltaCompactionOp(870e9336c2c14a2caa588cef5073b84a) complete. Timing: real 0.165s	user 0.109s	sys 0.055s Metrics: {"cfile_cache_miss":634,"cfile_cache_miss_bytes":28877302,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":139,"lbm_read_time_us":12735,"lbm_reads_lt_1ms":674,"lbm_write_time_us":35346,"lbm_writes_lt_1ms":643,"mutex_wait_us":39,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":3712,"thread_start_us":76,"threads_started":1,"update_count":3000}
I20260812 06:20:15.412042 25839 maintenance_manager.cc:419] P 02d6dd386c2a4e0d97fe61e209e67a49: Scheduling FlushDeltaMemStoresOp(870e9336c2c14a2caa588cef5073b84a): perf score=14.095187
I20260812 06:20:15.468626 25774 maintenance_manager.cc:643] P 02d6dd386c2a4e0d97fe61e209e67a49: FlushDeltaMemStoresOp(870e9336c2c14a2caa588cef5073b84a) complete. Timing: real 0.056s	user 0.039s	sys 0.012s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":23519,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:20:15.469164 25839 maintenance_manager.cc:419] P 02d6dd386c2a4e0d97fe61e209e67a49: Scheduling FlushDeltaMemStoresOp(870e9336c2c14a2caa588cef5073b84a): perf score=2.188937
I20260812 06:20:15.480691 25774 maintenance_manager.cc:643] P 02d6dd386c2a4e0d97fe61e209e67a49: FlushDeltaMemStoresOp(870e9336c2c14a2caa588cef5073b84a) complete. Timing: real 0.011s	user 0.005s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4236,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:15.481300 25839 maintenance_manager.cc:419] P 02d6dd386c2a4e0d97fe61e209e67a49: Scheduling MajorDeltaCompactionOp(870e9336c2c14a2caa588cef5073b84a): perf score=1.000000
I20260812 06:20:15.629420 25774 maintenance_manager.cc:643] P 02d6dd386c2a4e0d97fe61e209e67a49: MajorDeltaCompactionOp(870e9336c2c14a2caa588cef5073b84a) complete. Timing: real 0.148s	user 0.104s	sys 0.043s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774688,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":187,"lbm_read_time_us":10824,"lbm_reads_lt_1ms":572,"lbm_write_time_us":28569,"lbm_writes_lt_1ms":543,"mutex_wait_us":49,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":16128,"update_count":2500}
I20260812 06:20:15.630486 25839 maintenance_manager.cc:419] P 02d6dd386c2a4e0d97fe61e209e67a49: Scheduling FlushDeltaMemStoresOp(870e9336c2c14a2caa588cef5073b84a): perf score=12.110812
I20260812 06:20:15.668915 25774 maintenance_manager.cc:643] P 02d6dd386c2a4e0d97fe61e209e67a49: FlushDeltaMemStoresOp(870e9336c2c14a2caa588cef5073b84a) complete. Timing: real 0.038s	user 0.025s	sys 0.011s Metrics: {"bytes_written":13620266,"delete_count":0,"lbm_write_time_us":16645,"lbm_writes_lt_1ms":335,"reinsert_count":0,"update_count":1660}
I20260812 06:20:15.669435 25839 maintenance_manager.cc:419] P 02d6dd386c2a4e0d97fe61e209e67a49: Scheduling FlushDeltaMemStoresOp(870e9336c2c14a2caa588cef5073b84a): perf score=1.196750
I20260812 06:20:15.684048 25774 maintenance_manager.cc:643] P 02d6dd386c2a4e0d97fe61e209e67a49: FlushDeltaMemStoresOp(870e9336c2c14a2caa588cef5073b84a) complete. Timing: real 0.014s	user 0.005s	sys 0.004s Metrics: {"bytes_written":3077034,"delete_count":0,"lbm_write_time_us":3482,"lbm_writes_lt_1ms":78,"reinsert_count":0,"update_count":375}
I20260812 06:20:15.684630 25839 maintenance_manager.cc:419] P 02d6dd386c2a4e0d97fe61e209e67a49: Scheduling MajorDeltaCompactionOp(870e9336c2c14a2caa588cef5073b84a): perf score=1.000000
I20260812 06:20:15.837617 25774 maintenance_manager.cc:643] P 02d6dd386c2a4e0d97fe61e209e67a49: MajorDeltaCompactionOp(870e9336c2c14a2caa588cef5073b84a) complete. Timing: real 0.153s	user 0.115s	sys 0.035s Metrics: {"cfile_cache_miss":439,"cfile_cache_miss_bytes":20959428,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":473,"lbm_read_time_us":10884,"lbm_reads_lt_1ms":471,"lbm_write_time_us":27329,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":449,"mutex_wait_us":235,"peak_mem_usage":50976573,"reinsert_count":0,"spinlock_wait_cycles":2688,"update_count":2035}
I20260812 06:20:15.838390 25839 maintenance_manager.cc:419] P 02d6dd386c2a4e0d97fe61e209e67a49: Scheduling FlushDeltaMemStoresOp(870e9336c2c14a2caa588cef5073b84a): perf score=11.118625
I20260812 06:20:15.888432 25774 maintenance_manager.cc:643] P 02d6dd386c2a4e0d97fe61e209e67a49: FlushDeltaMemStoresOp(870e9336c2c14a2caa588cef5073b84a) complete. Timing: real 0.050s	user 0.032s	sys 0.015s Metrics: {"bytes_written":12430566,"delete_count":0,"lbm_write_time_us":21515,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":305,"reinsert_count":0,"update_count":1515}
I20260812 06:20:15.888922 25839 maintenance_manager.cc:419] P 02d6dd386c2a4e0d97fe61e209e67a49: Scheduling FlushDeltaMemStoresOp(870e9336c2c14a2caa588cef5073b84a): perf score=2.188937
I20260812 06:20:15.899555 25774 maintenance_manager.cc:643] P 02d6dd386c2a4e0d97fe61e209e67a49: FlushDeltaMemStoresOp(870e9336c2c14a2caa588cef5073b84a) complete. Timing: real 0.010s	user 0.006s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4116,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:15.899971 25839 maintenance_manager.cc:419] P 02d6dd386c2a4e0d97fe61e209e67a49: Scheduling FlushDeltaMemStoresOp(870e9336c2c14a2caa588cef5073b84a): perf score=2.188937
I20260812 06:20:15.919581 25774 maintenance_manager.cc:643] P 02d6dd386c2a4e0d97fe61e209e67a49: FlushDeltaMemStoresOp(870e9336c2c14a2caa588cef5073b84a) complete. Timing: real 0.019s	user 0.012s	sys 0.007s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3690,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:20:15.920300 25839 maintenance_manager.cc:419] P 02d6dd386c2a4e0d97fe61e209e67a49: Scheduling MajorDeltaCompactionOp(870e9336c2c14a2caa588cef5073b84a): perf score=1.000000
I20260812 06:20:16.100314 25774 maintenance_manager.cc:643] P 02d6dd386c2a4e0d97fe61e209e67a49: MajorDeltaCompactionOp(870e9336c2c14a2caa588cef5073b84a) complete. Timing: real 0.180s	user 0.100s	sys 0.076s Metrics: {"cfile_cache_miss":526,"cfile_cache_miss_bytes":24487630,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":876,"lbm_read_time_us":12754,"lbm_reads_lt_1ms":566,"lbm_write_time_us":28768,"lbm_writes_lt_1ms":536,"mutex_wait_us":294,"peak_mem_usage":61788271,"reinsert_count":0,"spinlock_wait_cycles":768,"update_count":2465}
I20260812 06:20:16.100888 25839 maintenance_manager.cc:419] P 02d6dd386c2a4e0d97fe61e209e67a49: Scheduling FlushDeltaMemStoresOp(870e9336c2c14a2caa588cef5073b84a): perf score=14.095187
I20260812 06:20:16.152325 25774 maintenance_manager.cc:643] P 02d6dd386c2a4e0d97fe61e209e67a49: FlushDeltaMemStoresOp(870e9336c2c14a2caa588cef5073b84a) complete. Timing: real 0.051s	user 0.026s	sys 0.019s Metrics: {"bytes_written":16409903,"delete_count":0,"lbm_write_time_us":20858,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:20:16.152838 25839 maintenance_manager.cc:419] P 02d6dd386c2a4e0d97fe61e209e67a49: Scheduling FlushDeltaMemStoresOp(870e9336c2c14a2caa588cef5073b84a): perf score=2.188937
I20260812 06:20:16.164376 25774 maintenance_manager.cc:643] P 02d6dd386c2a4e0d97fe61e209e67a49: FlushDeltaMemStoresOp(870e9336c2c14a2caa588cef5073b84a) complete. Timing: real 0.011s	user 0.005s	sys 0.005s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4324,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:16.164837 25839 maintenance_manager.cc:419] P 02d6dd386c2a4e0d97fe61e209e67a49: Scheduling MajorDeltaCompactionOp(870e9336c2c14a2caa588cef5073b84a): perf score=1.000000
I20260812 06:20:16.348613 25774 maintenance_manager.cc:643] P 02d6dd386c2a4e0d97fe61e209e67a49: MajorDeltaCompactionOp(870e9336c2c14a2caa588cef5073b84a) complete. Timing: real 0.184s	user 0.121s	sys 0.059s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774690,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":784,"lbm_read_time_us":11204,"lbm_reads_lt_1ms":572,"lbm_write_time_us":30814,"lbm_writes_lt_1ms":543,"mutex_wait_us":195,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":13952,"update_count":2500}
I20260812 06:20:16.349395 25839 maintenance_manager.cc:419] P 02d6dd386c2a4e0d97fe61e209e67a49: Scheduling FlushDeltaMemStoresOp(870e9336c2c14a2caa588cef5073b84a): perf score=14.095187
I20260812 06:20:16.395325 25774 maintenance_manager.cc:643] P 02d6dd386c2a4e0d97fe61e209e67a49: FlushDeltaMemStoresOp(870e9336c2c14a2caa588cef5073b84a) complete. Timing: real 0.046s	user 0.034s	sys 0.011s Metrics: {"bytes_written":16409903,"delete_count":0,"lbm_write_time_us":20063,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:20:16.395910 25839 maintenance_manager.cc:419] P 02d6dd386c2a4e0d97fe61e209e67a49: Scheduling FlushDeltaMemStoresOp(870e9336c2c14a2caa588cef5073b84a): perf score=2.188937
I20260812 06:20:16.408397 25774 maintenance_manager.cc:643] P 02d6dd386c2a4e0d97fe61e209e67a49: FlushDeltaMemStoresOp(870e9336c2c14a2caa588cef5073b84a) complete. Timing: real 0.012s	user 0.007s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4281,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:16.409080 25839 maintenance_manager.cc:419] P 02d6dd386c2a4e0d97fe61e209e67a49: Scheduling MajorDeltaCompactionOp(870e9336c2c14a2caa588cef5073b84a): perf score=1.000000
I20260812 06:20:16.566504 25774 maintenance_manager.cc:643] P 02d6dd386c2a4e0d97fe61e209e67a49: MajorDeltaCompactionOp(870e9336c2c14a2caa588cef5073b84a) complete. Timing: real 0.157s	user 0.096s	sys 0.052s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774690,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":136,"lbm_read_time_us":9347,"lbm_reads_lt_1ms":572,"lbm_write_time_us":32737,"lbm_writes_lt_1ms":543,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":2688,"update_count":2500}
I20260812 06:20:16.567103 25839 maintenance_manager.cc:419] P 02d6dd386c2a4e0d97fe61e209e67a49: Scheduling FlushDeltaMemStoresOp(870e9336c2c14a2caa588cef5073b84a): perf score=11.118625
I20260812 06:20:16.603817 25774 maintenance_manager.cc:643] P 02d6dd386c2a4e0d97fe61e209e67a49: FlushDeltaMemStoresOp(870e9336c2c14a2caa588cef5073b84a) complete. Timing: real 0.036s	user 0.023s	sys 0.012s Metrics: {"bytes_written":12717734,"delete_count":0,"lbm_write_time_us":15898,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:20:16.604627 25839 maintenance_manager.cc:419] P 02d6dd386c2a4e0d97fe61e209e67a49: Scheduling FlushDeltaMemStoresOp(870e9336c2c14a2caa588cef5073b84a): perf score=2.188937
I20260812 06:20:16.632189 25774 maintenance_manager.cc:643] P 02d6dd386c2a4e0d97fe61e209e67a49: FlushDeltaMemStoresOp(870e9336c2c14a2caa588cef5073b84a) complete. Timing: real 0.027s	user 0.006s	sys 0.008s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":5468,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:20:16.632695 25839 maintenance_manager.cc:419] P 02d6dd386c2a4e0d97fe61e209e67a49: Scheduling FlushDeltaMemStoresOp(870e9336c2c14a2caa588cef5073b84a): perf score=2.188937
I20260812 06:20:16.643527 25774 maintenance_manager.cc:643] P 02d6dd386c2a4e0d97fe61e209e67a49: FlushDeltaMemStoresOp(870e9336c2c14a2caa588cef5073b84a) complete. Timing: real 0.011s	user 0.006s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4055,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:16.644018 25839 maintenance_manager.cc:419] P 02d6dd386c2a4e0d97fe61e209e67a49: Scheduling FlushMRSOp(870e9336c2c14a2caa588cef5073b84a): perf score=1.000000
I20260812 06:20:16.676918 25774 maintenance_manager.cc:643] P 02d6dd386c2a4e0d97fe61e209e67a49: FlushMRSOp(870e9336c2c14a2caa588cef5073b84a) complete. Timing: real 0.033s	user 0.027s	sys 0.004s Metrics: {"bytes_written":1275447,"cfile_init":1,"dirs.queue_time_us":67,"dirs.run_cpu_time_us":228,"dirs.run_wall_time_us":1451,"drs_written":1,"lbm_read_time_us":57,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1986,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":31}
I20260812 06:20:16.677722 25839 maintenance_manager.cc:419] P 02d6dd386c2a4e0d97fe61e209e67a49: Scheduling LogGCOp(870e9336c2c14a2caa588cef5073b84a): free 124257471 bytes of WAL
I20260812 06:20:16.677995 25774 log_reader.cc:385] T 870e9336c2c14a2caa588cef5073b84a: removed 12 log segments from log reader
I20260812 06:20:16.678056 25774 log.cc:1079] T 870e9336c2c14a2caa588cef5073b84a P 02d6dd386c2a4e0d97fe61e209e67a49: Deleting log segment in path: /tmp/dist-test-taskWwF8e7/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515606164878-25448-0/minicluster-data/ts-0-root/wals/870e9336c2c14a2caa588cef5073b84a/wal-000000028 (ops 133-137)
I20260812 06:20:16.678093 25774 log.cc:1079] T 870e9336c2c14a2caa588cef5073b84a P 02d6dd386c2a4e0d97fe61e209e67a49: Deleting log segment in path: /tmp/dist-test-taskWwF8e7/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515606164878-25448-0/minicluster-data/ts-0-root/wals/870e9336c2c14a2caa588cef5073b84a/wal-000000029 (ops 138-142)
I20260812 06:20:16.678126 25774 log.cc:1079] T 870e9336c2c14a2caa588cef5073b84a P 02d6dd386c2a4e0d97fe61e209e67a49: Deleting log segment in path: /tmp/dist-test-taskWwF8e7/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515606164878-25448-0/minicluster-data/ts-0-root/wals/870e9336c2c14a2caa588cef5073b84a/wal-000000030 (ops 143-147)
I20260812 06:20:16.678167 25774 log.cc:1079] T 870e9336c2c14a2caa588cef5073b84a P 02d6dd386c2a4e0d97fe61e209e67a49: Deleting log segment in path: /tmp/dist-test-taskWwF8e7/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515606164878-25448-0/minicluster-data/ts-0-root/wals/870e9336c2c14a2caa588cef5073b84a/wal-000000031 (ops 148-152)
I20260812 06:20:16.678194 25774 log.cc:1079] T 870e9336c2c14a2caa588cef5073b84a P 02d6dd386c2a4e0d97fe61e209e67a49: Deleting log segment in path: /tmp/dist-test-taskWwF8e7/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515606164878-25448-0/minicluster-data/ts-0-root/wals/870e9336c2c14a2caa588cef5073b84a/wal-000000032 (ops 153-157)
I20260812 06:20:16.678224 25774 log.cc:1079] T 870e9336c2c14a2caa588cef5073b84a P 02d6dd386c2a4e0d97fe61e209e67a49: Deleting log segment in path: /tmp/dist-test-taskWwF8e7/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515606164878-25448-0/minicluster-data/ts-0-root/wals/870e9336c2c14a2caa588cef5073b84a/wal-000000033 (ops 158-162)
I20260812 06:20:16.678253 25774 log.cc:1079] T 870e9336c2c14a2caa588cef5073b84a P 02d6dd386c2a4e0d97fe61e209e67a49: Deleting log segment in path: /tmp/dist-test-taskWwF8e7/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515606164878-25448-0/minicluster-data/ts-0-root/wals/870e9336c2c14a2caa588cef5073b84a/wal-000000034 (ops 163-167)
I20260812 06:20:16.678287 25774 log.cc:1079] T 870e9336c2c14a2caa588cef5073b84a P 02d6dd386c2a4e0d97fe61e209e67a49: Deleting log segment in path: /tmp/dist-test-taskWwF8e7/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515606164878-25448-0/minicluster-data/ts-0-root/wals/870e9336c2c14a2caa588cef5073b84a/wal-000000035 (ops 168-172)
I20260812 06:20:16.678318 25774 log.cc:1079] T 870e9336c2c14a2caa588cef5073b84a P 02d6dd386c2a4e0d97fe61e209e67a49: Deleting log segment in path: /tmp/dist-test-taskWwF8e7/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515606164878-25448-0/minicluster-data/ts-0-root/wals/870e9336c2c14a2caa588cef5073b84a/wal-000000036 (ops 173-176)
I20260812 06:20:16.678346 25774 log.cc:1079] T 870e9336c2c14a2caa588cef5073b84a P 02d6dd386c2a4e0d97fe61e209e67a49: Deleting log segment in path: /tmp/dist-test-taskWwF8e7/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515606164878-25448-0/minicluster-data/ts-0-root/wals/870e9336c2c14a2caa588cef5073b84a/wal-000000037 (ops 177-181)
I20260812 06:20:16.678372 25774 log.cc:1079] T 870e9336c2c14a2caa588cef5073b84a P 02d6dd386c2a4e0d97fe61e209e67a49: Deleting log segment in path: /tmp/dist-test-taskWwF8e7/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515606164878-25448-0/minicluster-data/ts-0-root/wals/870e9336c2c14a2caa588cef5073b84a/wal-000000038 (ops 182-186)
I20260812 06:20:16.678401 25774 log.cc:1079] T 870e9336c2c14a2caa588cef5073b84a P 02d6dd386c2a4e0d97fe61e209e67a49: Deleting log segment in path: /tmp/dist-test-taskWwF8e7/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515606164878-25448-0/minicluster-data/ts-0-root/wals/870e9336c2c14a2caa588cef5073b84a/wal-000000039 (ops 187-191)
I20260812 06:20:16.707792 25774 maintenance_manager.cc:643] P 02d6dd386c2a4e0d97fe61e209e67a49: LogGCOp(870e9336c2c14a2caa588cef5073b84a) complete. Timing: real 0.030s	user 0.000s	sys 0.029s Metrics: {}
I20260812 06:20:16.708221 25839 maintenance_manager.cc:419] P 02d6dd386c2a4e0d97fe61e209e67a49: Scheduling FlushDeltaMemStoresOp(870e9336c2c14a2caa588cef5073b84a): perf score=2.188937
I20260812 06:20:16.730685 25774 maintenance_manager.cc:643] P 02d6dd386c2a4e0d97fe61e209e67a49: FlushDeltaMemStoresOp(870e9336c2c14a2caa588cef5073b84a) complete. Timing: real 0.022s	user 0.004s	sys 0.009s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5963,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:16.731281 25839 maintenance_manager.cc:419] P 02d6dd386c2a4e0d97fe61e209e67a49: Scheduling FlushDeltaMemStoresOp(870e9336c2c14a2caa588cef5073b84a): perf score=2.188937
I20260812 06:20:16.753051 25774 maintenance_manager.cc:643] P 02d6dd386c2a4e0d97fe61e209e67a49: FlushDeltaMemStoresOp(870e9336c2c14a2caa588cef5073b84a) complete. Timing: real 0.022s	user 0.009s	sys 0.011s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4170,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:16.753698 25839 maintenance_manager.cc:419] P 02d6dd386c2a4e0d97fe61e209e67a49: Scheduling MajorDeltaCompactionOp(870e9336c2c14a2caa588cef5073b84a): perf score=1.000000
I20260812 06:20:16.846479 25448 heavy-update-compaction-itest.cc:229] Time spent updating: real 4.930s	user 1.877s	sys 0.124s
I20260812 06:20:16.953140 25448 heavy-update-compaction-itest.cc:265] Time spent scanning: real 0.106s	user 0.000s	sys 0.001s
I20260812 06:20:16.953728 25448 tablet_server.cc:179] TabletServer@127.24.218.1:0 shutting down...
I20260812 06:20:16.966187 25774 maintenance_manager.cc:643] P 02d6dd386c2a4e0d97fe61e209e67a49: MajorDeltaCompactionOp(870e9336c2c14a2caa588cef5073b84a) complete. Timing: real 0.212s	user 0.164s	sys 0.048s Metrics: {"cfile_cache_miss":735,"cfile_cache_miss_bytes":32979860,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":5,"delta_iterators_relevant":5,"dirs.queue_time_us":429,"lbm_read_time_us":15360,"lbm_reads_lt_1ms":771,"lbm_write_time_us":33313,"lbm_writes_lt_1ms":743,"mutex_wait_us":94,"peak_mem_usage":87969044,"reinsert_count":0,"spinlock_wait_cycles":1792,"thread_start_us":90,"threads_started":1,"update_count":3500}
I20260812 06:20:16.967644 25448 ts_tablet_manager.cc:1507] Shutting down tablet manager...
I20260812 06:20:16.968017 25448 tablet_replica.cc:333] T 870e9336c2c14a2caa588cef5073b84a P 02d6dd386c2a4e0d97fe61e209e67a49: stopping tablet replica
I20260812 06:20:16.968178 25448 raft_consensus.cc:2243] T 870e9336c2c14a2caa588cef5073b84a P 02d6dd386c2a4e0d97fe61e209e67a49 [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:20:16.968369 25448 raft_consensus.cc:2272] T 870e9336c2c14a2caa588cef5073b84a P 02d6dd386c2a4e0d97fe61e209e67a49 [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:20:16.973423 25448 tablet_server.cc:196] TabletServer@127.24.218.1:0 shutdown complete.
I20260812 06:20:17.024147 25448 master.cc:562] Master@127.24.218.62:44997 shutting down...
I20260812 06:20:17.028434 25448 raft_consensus.cc:2243] T 00000000000000000000000000000000 P 66c3e90dbcd142d695aaf5a74dcd3264 [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:20:17.028669 25448 raft_consensus.cc:2272] T 00000000000000000000000000000000 P 66c3e90dbcd142d695aaf5a74dcd3264 [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:20:17.028774 25448 tablet_replica.cc:333] T 00000000000000000000000000000000 P 66c3e90dbcd142d695aaf5a74dcd3264: stopping tablet replica
I20260812 06:20:17.041337 25448 master.cc:584] Master@127.24.218.62:44997 shutdown complete.
[       OK ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/1 (5429 ms)
[----------] 2 tests from EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy (10950 ms total)

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