[==========] Running 2 tests from 1 test suite.
[----------] Global test environment set-up.
[----------] 2 tests from EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy
[ RUN      ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/0
WARNING: Logging before InitGoogleLogging() is written to STDERR
I20260812 06:19:25.340095 19282 internal_mini_cluster.cc:156] Creating distributed mini masters. Addrs: 127.18.212.190:43381
I20260812 06:19:25.341058 19282 env_posix.cc:2285] Not raising this process' open files per process limit of 1048576; it is already as high as it can go
I20260812 06:19:25.341691 19282 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:19:25.348340 19287 instance_detector.cc:116] could not retrieve AWS instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:19:25.348394 19290 instance_detector.cc:116] could not retrieve OpenStack instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:19:25.348474 19282 server_base.cc:1061] running on GCE node
W20260812 06:19:25.348619 19288 instance_detector.cc:116] could not retrieve Azure instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:19:25.349092 19282 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:19:25.349177 19282 system_unsync_time.cc:38] NTP support is disabled. Clock error bounds will not be accurate. This configuration is not suitable for distributed clusters.
I20260812 06:19:25.349229 19282 hybrid_clock.cc:648] HybridClock initialized: now 1786515565349227 us; error 0 us; skew 500 ppm
I20260812 06:19:25.350893 19282 webserver.cc:533] Webserver started at http://127.18.212.190:44573/ using document root <none> and password file <none>
I20260812 06:19:25.351497 19282 fs_manager.cc:362] Metadata directory not provided
I20260812 06:19:25.351557 19282 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:19:25.351818 19282 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:19:25.353689 19282 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-tasky6MLcF/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515565329438-19282-0/minicluster-data/master-0-root/instance:
uuid: "5a666238ab684494aadfedbc11ff3a0b"
format_stamp: "Formatted at 2026-08-12 06:19:25 on dist-test-slave-1xrh"
I20260812 06:19:25.357263 19282 fs_manager.cc:696] Time spent creating directory manager: real 0.003s	user 0.002s	sys 0.003s
I20260812 06:19:25.359429 19296 log_block_manager.cc:4127] Time spent loading block containers with low live blocks: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:19:25.360387 19282 fs_manager.cc:730] Time spent opening block manager: real 0.002s	user 0.001s	sys 0.001s
I20260812 06:19:25.360512 19282 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-tasky6MLcF/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515565329438-19282-0/minicluster-data/master-0-root
uuid: "5a666238ab684494aadfedbc11ff3a0b"
format_stamp: "Formatted at 2026-08-12 06:19:25 on dist-test-slave-1xrh"
I20260812 06:19:25.360613 19282 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-tasky6MLcF/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515565329438-19282-0/minicluster-data/master-0-root
metadata directory: /tmp/dist-test-tasky6MLcF/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515565329438-19282-0/minicluster-data/master-0-root
1 data directories: /tmp/dist-test-tasky6MLcF/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515565329438-19282-0/minicluster-data/master-0-root/data
Total live blocks: 0
Total live bytes: 0
Total live bytes (after alignment): 0
Total number of LBM containers: 0 (0 full)
Did not check for missing blocks
Did not check for orphaned blocks
Total full LBM containers with extra space: 0 (0 repaired)
Total full LBM container extra space in bytes: 0 (0 repaired)
Total incomplete LBM containers: 0 (0 repaired)
Total LBM partial records: 0 (0 repaired)
Total corrupted LBM metadata records in RocksDB: 0 (0 repaired)
I20260812 06:19:25.377034 19282 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:19:25.377604 19282 env_posix.cc:2285] Not raising this process' running threads per effective uid limit of 18446744073709551615; it is already as high as it can go
I20260812 06:19:25.377789 19282 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:19:25.385406 19282 rpc_server.cc:307] RPC server started. Bound to: 127.18.212.190:43381
I20260812 06:19:25.385470 19357 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.18.212.190:43381 every 8 connection(s)
I20260812 06:19:25.387770 19359 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet 00000000000000000000000000000000. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:19:25.393105 19359 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P 5a666238ab684494aadfedbc11ff3a0b: Bootstrap starting.
I20260812 06:19:25.395476 19359 tablet_bootstrap.cc:654] T 00000000000000000000000000000000 P 5a666238ab684494aadfedbc11ff3a0b: Neither blocks nor log segments found. Creating new log.
I20260812 06:19:25.396517 19359 log.cc:826] T 00000000000000000000000000000000 P 5a666238ab684494aadfedbc11ff3a0b: Log is configured to *not* fsync() on all Append() calls
I20260812 06:19:25.398186 19359 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P 5a666238ab684494aadfedbc11ff3a0b: No bootstrap required, opened a new log
I20260812 06:19:25.401305 19359 raft_consensus.cc:359] T 00000000000000000000000000000000 P 5a666238ab684494aadfedbc11ff3a0b [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "5a666238ab684494aadfedbc11ff3a0b" member_type: VOTER }
I20260812 06:19:25.401526 19359 raft_consensus.cc:385] T 00000000000000000000000000000000 P 5a666238ab684494aadfedbc11ff3a0b [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:19:25.401638 19359 raft_consensus.cc:740] T 00000000000000000000000000000000 P 5a666238ab684494aadfedbc11ff3a0b [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: 5a666238ab684494aadfedbc11ff3a0b, State: Initialized, Role: FOLLOWER
I20260812 06:19:25.402236 19359 consensus_queue.cc:260] T 00000000000000000000000000000000 P 5a666238ab684494aadfedbc11ff3a0b [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: "5a666238ab684494aadfedbc11ff3a0b" member_type: VOTER }
I20260812 06:19:25.402407 19359 raft_consensus.cc:399] T 00000000000000000000000000000000 P 5a666238ab684494aadfedbc11ff3a0b [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:19:25.402508 19359 raft_consensus.cc:493] T 00000000000000000000000000000000 P 5a666238ab684494aadfedbc11ff3a0b [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:19:25.402663 19359 raft_consensus.cc:3060] T 00000000000000000000000000000000 P 5a666238ab684494aadfedbc11ff3a0b [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:19:25.403704 19359 raft_consensus.cc:515] T 00000000000000000000000000000000 P 5a666238ab684494aadfedbc11ff3a0b [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "5a666238ab684494aadfedbc11ff3a0b" member_type: VOTER }
I20260812 06:19:25.404311 19359 leader_election.cc:304] T 00000000000000000000000000000000 P 5a666238ab684494aadfedbc11ff3a0b [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: 5a666238ab684494aadfedbc11ff3a0b; no voters: 
I20260812 06:19:25.404644 19359 leader_election.cc:290] T 00000000000000000000000000000000 P 5a666238ab684494aadfedbc11ff3a0b [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:19:25.404742 19362 raft_consensus.cc:2804] T 00000000000000000000000000000000 P 5a666238ab684494aadfedbc11ff3a0b [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:19:25.405121 19362 raft_consensus.cc:697] T 00000000000000000000000000000000 P 5a666238ab684494aadfedbc11ff3a0b [term 1 LEADER]: Becoming Leader. State: Replica: 5a666238ab684494aadfedbc11ff3a0b, State: Running, Role: LEADER
I20260812 06:19:25.405499 19362 consensus_queue.cc:237] T 00000000000000000000000000000000 P 5a666238ab684494aadfedbc11ff3a0b [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: "5a666238ab684494aadfedbc11ff3a0b" member_type: VOTER }
I20260812 06:19:25.405763 19359 sys_catalog.cc:565] T 00000000000000000000000000000000 P 5a666238ab684494aadfedbc11ff3a0b [sys.catalog]: configured and running, proceeding with master startup.
I20260812 06:19:25.407470 19363 sys_catalog.cc:455] T 00000000000000000000000000000000 P 5a666238ab684494aadfedbc11ff3a0b [sys.catalog]: SysCatalogTable state changed. Reason: RaftConsensus started. Latest consensus state: current_term: 1 leader_uuid: "5a666238ab684494aadfedbc11ff3a0b" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "5a666238ab684494aadfedbc11ff3a0b" member_type: VOTER } }
I20260812 06:19:25.407599 19363 sys_catalog.cc:458] T 00000000000000000000000000000000 P 5a666238ab684494aadfedbc11ff3a0b [sys.catalog]: This master's current role is: LEADER
I20260812 06:19:25.407889 19364 sys_catalog.cc:455] T 00000000000000000000000000000000 P 5a666238ab684494aadfedbc11ff3a0b [sys.catalog]: SysCatalogTable state changed. Reason: New leader 5a666238ab684494aadfedbc11ff3a0b. Latest consensus state: current_term: 1 leader_uuid: "5a666238ab684494aadfedbc11ff3a0b" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "5a666238ab684494aadfedbc11ff3a0b" member_type: VOTER } }
I20260812 06:19:25.407975 19364 sys_catalog.cc:458] T 00000000000000000000000000000000 P 5a666238ab684494aadfedbc11ff3a0b [sys.catalog]: This master's current role is: LEADER
I20260812 06:19:25.408267 19373 catalog_manager.cc:1511] Loading table and tablet metadata into memory...
I20260812 06:19:25.408543 19282 internal_mini_cluster.cc:184] Waiting to initialize catalog manager on master 0
I20260812 06:19:25.410722 19373 catalog_manager.cc:1520] Initializing Kudu cluster ID...
I20260812 06:19:25.415223 19373 catalog_manager.cc:1383] Generated new cluster ID: 35d3f154f7d24cfbac4fc749feda7779
I20260812 06:19:25.415316 19373 catalog_manager.cc:1531] Initializing Kudu internal certificate authority...
I20260812 06:19:25.425294 19373 catalog_manager.cc:1406] Generated new certificate authority record
I20260812 06:19:25.426424 19373 catalog_manager.cc:1540] Loading token signing keys...
I20260812 06:19:25.441720 19373 catalog_manager.cc:6092] T 00000000000000000000000000000000 P 5a666238ab684494aadfedbc11ff3a0b: Generated new TSK 0
I20260812 06:19:25.442481 19373 catalog_manager.cc:1550] Initializing in-progress tserver states...
I20260812 06:19:25.473943 19282 file_cache.cc:504] Constructed file cache file cache with capacity 419430
I20260812 06:19:25.477092 19282 server_base.cc:1061] running on GCE node
W20260812 06:19:25.477030 19384 instance_detector.cc:116] could not retrieve Azure instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:19:25.477193 19386 instance_detector.cc:116] could not retrieve OpenStack instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:19:25.477047 19383 instance_detector.cc:116] could not retrieve AWS instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:19:25.477520 19282 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:19:25.477591 19282 system_unsync_time.cc:38] NTP support is disabled. Clock error bounds will not be accurate. This configuration is not suitable for distributed clusters.
I20260812 06:19:25.477626 19282 hybrid_clock.cc:648] HybridClock initialized: now 1786515565477625 us; error 0 us; skew 500 ppm
I20260812 06:19:25.478603 19282 webserver.cc:533] Webserver started at http://127.18.212.129:37835/ using document root <none> and password file <none>
I20260812 06:19:25.478782 19282 fs_manager.cc:362] Metadata directory not provided
I20260812 06:19:25.478859 19282 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:19:25.478960 19282 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:19:25.479447 19282 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-tasky6MLcF/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515565329438-19282-0/minicluster-data/ts-0-root/instance:
uuid: "73ec120445a34bafba012ca0e25b5f66"
format_stamp: "Formatted at 2026-08-12 06:19:25 on dist-test-slave-1xrh"
I20260812 06:19:25.480996 19282 fs_manager.cc:696] Time spent creating directory manager: real 0.001s	user 0.002s	sys 0.000s
I20260812 06:19:25.482008 19391 log_block_manager.cc:4127] Time spent loading block containers with low live blocks: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:19:25.482270 19282 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.001s	sys 0.000s
I20260812 06:19:25.482342 19282 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-tasky6MLcF/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515565329438-19282-0/minicluster-data/ts-0-root
uuid: "73ec120445a34bafba012ca0e25b5f66"
format_stamp: "Formatted at 2026-08-12 06:19:25 on dist-test-slave-1xrh"
I20260812 06:19:25.482435 19282 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-tasky6MLcF/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515565329438-19282-0/minicluster-data/ts-0-root
metadata directory: /tmp/dist-test-tasky6MLcF/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515565329438-19282-0/minicluster-data/ts-0-root
1 data directories: /tmp/dist-test-tasky6MLcF/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515565329438-19282-0/minicluster-data/ts-0-root/data
Total live blocks: 0
Total live bytes: 0
Total live bytes (after alignment): 0
Total number of LBM containers: 0 (0 full)
Did not check for missing blocks
Did not check for orphaned blocks
Total full LBM containers with extra space: 0 (0 repaired)
Total full LBM container extra space in bytes: 0 (0 repaired)
Total incomplete LBM containers: 0 (0 repaired)
Total LBM partial records: 0 (0 repaired)
Total corrupted LBM metadata records in RocksDB: 0 (0 repaired)
I20260812 06:19:25.487936 19282 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:19:25.488363 19282 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:19:25.488865 19282 txn_system_client.cc:432] TxnSystemClient initialization is disabled...
I20260812 06:19:25.489675 19282 ts_tablet_manager.cc:585] Loaded tablet metadata (0 total tablets, 0 live tablets)
I20260812 06:19:25.489723 19282 ts_tablet_manager.cc:531] Time spent load tablet metadata: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:19:25.489763 19282 ts_tablet_manager.cc:616] Registered 0 tablets
I20260812 06:19:25.489830 19282 ts_tablet_manager.cc:595] Time spent register tablets: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:19:25.498227 19282 rpc_server.cc:307] RPC server started. Bound to: 127.18.212.129:40117
I20260812 06:19:25.498296 19462 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.18.212.129:40117 every 8 connection(s)
I20260812 06:19:25.513469 19464 heartbeater.cc:344] Connected to a master server at 127.18.212.190:43381
I20260812 06:19:25.513723 19464 heartbeater.cc:461] Registering TS with master...
I20260812 06:19:25.514183 19464 heartbeater.cc:507] Master 127.18.212.190:43381 requested a full tablet report, sending...
I20260812 06:19:25.515799 19314 ts_manager.cc:194] Registered new tserver with Master: 73ec120445a34bafba012ca0e25b5f66 (127.18.212.129:40117)
I20260812 06:19:25.515875 19282 internal_mini_cluster.cc:371] 1 TS(s) registered with all masters after 0.017055058s
I20260812 06:19:25.517373 19314 master_service.cc:502] Signed X509 certificate for tserver {username='slave'} at 127.0.0.1:39828
I20260812 06:19:25.525431 19314 catalog_manager.cc:2283] Servicing CreateTable request from {username='slave'} at 127.0.0.1:39836:
name: "heavy-update-compaction-test"
schema {
  columns {
    name: "key"
    type: INT64
    is_key: true
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_a"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_b"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_c"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_d"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_e"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
}
num_replicas: 1
split_rows_range_bounds {
}
partition_schema {
  range_schema {
  }
}
I20260812 06:19:25.538815 19421 tablet_service.cc:1511] Processing CreateTablet for tablet 8b14b884363e4aff866e30d4d0c8fb81 (DEFAULT_TABLE table=heavy-update-compaction-test [id=9085403de49c49f3a148a7a7e8b7b5c2]), partition=
I20260812 06:19:25.539294 19421 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet 8b14b884363e4aff866e30d4d0c8fb81. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:19:25.541572 19480 tablet_bootstrap.cc:492] T 8b14b884363e4aff866e30d4d0c8fb81 P 73ec120445a34bafba012ca0e25b5f66: Bootstrap starting.
I20260812 06:19:25.542622 19480 tablet_bootstrap.cc:654] T 8b14b884363e4aff866e30d4d0c8fb81 P 73ec120445a34bafba012ca0e25b5f66: Neither blocks nor log segments found. Creating new log.
I20260812 06:19:25.544085 19480 tablet_bootstrap.cc:492] T 8b14b884363e4aff866e30d4d0c8fb81 P 73ec120445a34bafba012ca0e25b5f66: No bootstrap required, opened a new log
I20260812 06:19:25.544191 19480 ts_tablet_manager.cc:1403] T 8b14b884363e4aff866e30d4d0c8fb81 P 73ec120445a34bafba012ca0e25b5f66: Time spent bootstrapping tablet: real 0.003s	user 0.002s	sys 0.000s
I20260812 06:19:25.544723 19480 raft_consensus.cc:359] T 8b14b884363e4aff866e30d4d0c8fb81 P 73ec120445a34bafba012ca0e25b5f66 [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "73ec120445a34bafba012ca0e25b5f66" member_type: VOTER last_known_addr { host: "127.18.212.129" port: 40117 } }
I20260812 06:19:25.544842 19480 raft_consensus.cc:385] T 8b14b884363e4aff866e30d4d0c8fb81 P 73ec120445a34bafba012ca0e25b5f66 [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:19:25.544878 19480 raft_consensus.cc:740] T 8b14b884363e4aff866e30d4d0c8fb81 P 73ec120445a34bafba012ca0e25b5f66 [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: 73ec120445a34bafba012ca0e25b5f66, State: Initialized, Role: FOLLOWER
I20260812 06:19:25.545012 19480 consensus_queue.cc:260] T 8b14b884363e4aff866e30d4d0c8fb81 P 73ec120445a34bafba012ca0e25b5f66 [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: "73ec120445a34bafba012ca0e25b5f66" member_type: VOTER last_known_addr { host: "127.18.212.129" port: 40117 } }
I20260812 06:19:25.545109 19480 raft_consensus.cc:399] T 8b14b884363e4aff866e30d4d0c8fb81 P 73ec120445a34bafba012ca0e25b5f66 [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:19:25.545202 19480 raft_consensus.cc:493] T 8b14b884363e4aff866e30d4d0c8fb81 P 73ec120445a34bafba012ca0e25b5f66 [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:19:25.545269 19480 raft_consensus.cc:3060] T 8b14b884363e4aff866e30d4d0c8fb81 P 73ec120445a34bafba012ca0e25b5f66 [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:19:25.546370 19480 raft_consensus.cc:515] T 8b14b884363e4aff866e30d4d0c8fb81 P 73ec120445a34bafba012ca0e25b5f66 [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "73ec120445a34bafba012ca0e25b5f66" member_type: VOTER last_known_addr { host: "127.18.212.129" port: 40117 } }
I20260812 06:19:25.546550 19480 leader_election.cc:304] T 8b14b884363e4aff866e30d4d0c8fb81 P 73ec120445a34bafba012ca0e25b5f66 [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: 73ec120445a34bafba012ca0e25b5f66; no voters: 
I20260812 06:19:25.546813 19480 leader_election.cc:290] T 8b14b884363e4aff866e30d4d0c8fb81 P 73ec120445a34bafba012ca0e25b5f66 [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:19:25.547030 19482 raft_consensus.cc:2804] T 8b14b884363e4aff866e30d4d0c8fb81 P 73ec120445a34bafba012ca0e25b5f66 [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:19:25.547330 19480 ts_tablet_manager.cc:1434] T 8b14b884363e4aff866e30d4d0c8fb81 P 73ec120445a34bafba012ca0e25b5f66: Time spent starting tablet: real 0.003s	user 0.003s	sys 0.000s
I20260812 06:19:25.547327 19482 raft_consensus.cc:697] T 8b14b884363e4aff866e30d4d0c8fb81 P 73ec120445a34bafba012ca0e25b5f66 [term 1 LEADER]: Becoming Leader. State: Replica: 73ec120445a34bafba012ca0e25b5f66, State: Running, Role: LEADER
I20260812 06:19:25.547585 19482 consensus_queue.cc:237] T 8b14b884363e4aff866e30d4d0c8fb81 P 73ec120445a34bafba012ca0e25b5f66 [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: "73ec120445a34bafba012ca0e25b5f66" member_type: VOTER last_known_addr { host: "127.18.212.129" port: 40117 } }
I20260812 06:19:25.547819 19464 heartbeater.cc:499] Master 127.18.212.190:43381 was elected leader, sending a full tablet report...
I20260812 06:19:25.550540 19314 catalog_manager.cc:5719] T 8b14b884363e4aff866e30d4d0c8fb81 P 73ec120445a34bafba012ca0e25b5f66 reported cstate change: term changed from 0 to 1, leader changed from <none> to 73ec120445a34bafba012ca0e25b5f66 (127.18.212.129). New cstate: current_term: 1 leader_uuid: "73ec120445a34bafba012ca0e25b5f66" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "73ec120445a34bafba012ca0e25b5f66" member_type: VOTER last_known_addr { host: "127.18.212.129" port: 40117 } health_report { overall_health: HEALTHY } } }
I20260812 06:19:25.621733 19282 heavy-update-compaction-itest.cc:215] Time spent inserting: real 0.061s	user 0.024s	sys 0.004s
I20260812 06:19:25.749289 19465 maintenance_manager.cc:419] P 73ec120445a34bafba012ca0e25b5f66: Scheduling FlushMRSOp(8b14b884363e4aff866e30d4d0c8fb81): perf score=15.086190
I20260812 06:19:25.919467 19397 maintenance_manager.cc:643] P 73ec120445a34bafba012ca0e25b5f66: FlushMRSOp(8b14b884363e4aff866e30d4d0c8fb81) complete. Timing: real 0.170s	user 0.121s	sys 0.044s Metrics: {"bytes_written":12922857,"cfile_init":1,"compiler_manager_pool.queue_time_us":191,"delete_count":0,"dirs.queue_time_us":65,"dirs.run_cpu_time_us":223,"dirs.run_wall_time_us":1150,"drs_written":1,"lbm_read_time_us":73,"lbm_reads_lt_1ms":4,"lbm_write_time_us":44305,"lbm_writes_lt_1ms":682,"mutex_wait_us":471,"peak_mem_usage":0,"reinsert_count":0,"rows_written":104,"spinlock_wait_cycles":362880,"thread_start_us":115,"threads_started":1,"update_count":1575}
I20260812 06:19:25.920728 19465 maintenance_manager.cc:419] P 73ec120445a34bafba012ca0e25b5f66: Scheduling UndoDeltaBlockGCOp(8b14b884363e4aff866e30d4d0c8fb81): 12719216 bytes on disk
I20260812 06:19:25.921340 19397 maintenance_manager.cc:643] P 73ec120445a34bafba012ca0e25b5f66: UndoDeltaBlockGCOp(8b14b884363e4aff866e30d4d0c8fb81) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":65,"lbm_reads_lt_1ms":4}
I20260812 06:19:25.921849 19465 maintenance_manager.cc:419] P 73ec120445a34bafba012ca0e25b5f66: Scheduling FlushDeltaMemStoresOp(8b14b884363e4aff866e30d4d0c8fb81): perf score=3.181125
I20260812 06:19:25.940543 19397 maintenance_manager.cc:643] P 73ec120445a34bafba012ca0e25b5f66: FlushDeltaMemStoresOp(8b14b884363e4aff866e30d4d0c8fb81) complete. Timing: real 0.019s	user 0.008s	sys 0.009s Metrics: {"bytes_written":4718023,"delete_count":0,"lbm_write_time_us":7647,"lbm_writes_lt_1ms":118,"reinsert_count":0,"update_count":575}
I20260812 06:19:25.941089 19465 maintenance_manager.cc:419] P 73ec120445a34bafba012ca0e25b5f66: Scheduling LogGCOp(8b14b884363e4aff866e30d4d0c8fb81): free 20743880 bytes of WAL
I20260812 06:19:25.941411 19397 log_reader.cc:385] T 8b14b884363e4aff866e30d4d0c8fb81: removed 2 log segments from log reader
I20260812 06:19:25.941491 19397 log.cc:1079] T 8b14b884363e4aff866e30d4d0c8fb81 P 73ec120445a34bafba012ca0e25b5f66: Deleting log segment in path: /tmp/dist-test-tasky6MLcF/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515565329438-19282-0/minicluster-data/ts-0-root/wals/8b14b884363e4aff866e30d4d0c8fb81/wal-000000001 (ops 1-6)
I20260812 06:19:25.941563 19397 log.cc:1079] T 8b14b884363e4aff866e30d4d0c8fb81 P 73ec120445a34bafba012ca0e25b5f66: Deleting log segment in path: /tmp/dist-test-tasky6MLcF/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515565329438-19282-0/minicluster-data/ts-0-root/wals/8b14b884363e4aff866e30d4d0c8fb81/wal-000000002 (ops 7-11)
I20260812 06:19:25.946556 19397 maintenance_manager.cc:643] P 73ec120445a34bafba012ca0e25b5f66: LogGCOp(8b14b884363e4aff866e30d4d0c8fb81) complete. Timing: real 0.005s	user 0.000s	sys 0.002s Metrics: {}
I20260812 06:19:25.946856 19465 maintenance_manager.cc:419] P 73ec120445a34bafba012ca0e25b5f66: Scheduling FlushDeltaMemStoresOp(8b14b884363e4aff866e30d4d0c8fb81): perf score=1.196750
I20260812 06:19:25.955958 19397 maintenance_manager.cc:643] P 73ec120445a34bafba012ca0e25b5f66: FlushDeltaMemStoresOp(8b14b884363e4aff866e30d4d0c8fb81) complete. Timing: real 0.009s	user 0.008s	sys 0.000s Metrics: {"bytes_written":2461654,"delete_count":0,"lbm_write_time_us":2648,"lbm_writes_lt_1ms":63,"reinsert_count":0,"update_count":300}
I20260812 06:19:25.956429 19465 maintenance_manager.cc:419] P 73ec120445a34bafba012ca0e25b5f66: Scheduling MajorDeltaCompactionOp(8b14b884363e4aff866e30d4d0c8fb81): perf score=1.000000
I20260812 06:19:26.127229 19397 maintenance_manager.cc:643] P 73ec120445a34bafba012ca0e25b5f66: MajorDeltaCompactionOp(8b14b884363e4aff866e30d4d0c8fb81) complete. Timing: real 0.171s	user 0.111s	sys 0.056s Metrics: {"cfile_cache_miss":523,"cfile_cache_miss_bytes":24364534,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":961,"lbm_read_time_us":14961,"lbm_reads_lt_1ms":559,"lbm_write_time_us":28559,"lbm_writes_lt_1ms":533,"peak_mem_usage":61665166,"reinsert_count":0,"spinlock_wait_cycles":2688,"thread_start_us":342,"threads_started":5,"update_count":2450}
I20260812 06:19:26.127790 19465 maintenance_manager.cc:419] P 73ec120445a34bafba012ca0e25b5f66: Scheduling FlushDeltaMemStoresOp(8b14b884363e4aff866e30d4d0c8fb81): perf score=10.126437
I20260812 06:19:26.173086 19397 maintenance_manager.cc:643] P 73ec120445a34bafba012ca0e25b5f66: FlushDeltaMemStoresOp(8b14b884363e4aff866e30d4d0c8fb81) complete. Timing: real 0.045s	user 0.028s	sys 0.015s Metrics: {"bytes_written":12307491,"delete_count":0,"lbm_write_time_us":19948,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:19:26.173566 19465 maintenance_manager.cc:419] P 73ec120445a34bafba012ca0e25b5f66: Scheduling FlushDeltaMemStoresOp(8b14b884363e4aff866e30d4d0c8fb81): perf score=2.188937
I20260812 06:19:26.184851 19397 maintenance_manager.cc:643] P 73ec120445a34bafba012ca0e25b5f66: FlushDeltaMemStoresOp(8b14b884363e4aff866e30d4d0c8fb81) complete. Timing: real 0.011s	user 0.009s	sys 0.001s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4278,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:26.185398 19465 maintenance_manager.cc:419] P 73ec120445a34bafba012ca0e25b5f66: Scheduling MajorDeltaCompactionOp(8b14b884363e4aff866e30d4d0c8fb81): perf score=1.000000
I20260812 06:19:26.318100 19397 maintenance_manager.cc:643] P 73ec120445a34bafba012ca0e25b5f66: MajorDeltaCompactionOp(8b14b884363e4aff866e30d4d0c8fb81) complete. Timing: real 0.133s	user 0.089s	sys 0.037s 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":1686,"dirs.run_cpu_time_us":2286,"dirs.run_wall_time_us":15675,"lbm_read_time_us":10132,"lbm_reads_lt_1ms":472,"lbm_write_time_us":24436,"lbm_writes_lt_1ms":443,"mutex_wait_us":735,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":768,"update_count":2000}
I20260812 06:19:26.319391 19465 maintenance_manager.cc:419] P 73ec120445a34bafba012ca0e25b5f66: Scheduling FlushDeltaMemStoresOp(8b14b884363e4aff866e30d4d0c8fb81): perf score=11.118625
I20260812 06:19:26.363519 19397 maintenance_manager.cc:643] P 73ec120445a34bafba012ca0e25b5f66: FlushDeltaMemStoresOp(8b14b884363e4aff866e30d4d0c8fb81) complete. Timing: real 0.044s	user 0.020s	sys 0.024s Metrics: {"bytes_written":12717736,"delete_count":0,"lbm_write_time_us":19451,"lbm_writes_lt_1ms":313,"reinsert_count":0,"spinlock_wait_cycles":1408,"update_count":1550}
I20260812 06:19:26.364048 19465 maintenance_manager.cc:419] P 73ec120445a34bafba012ca0e25b5f66: Scheduling FlushDeltaMemStoresOp(8b14b884363e4aff866e30d4d0c8fb81): perf score=2.188937
I20260812 06:19:26.379679 19397 maintenance_manager.cc:643] P 73ec120445a34bafba012ca0e25b5f66: FlushDeltaMemStoresOp(8b14b884363e4aff866e30d4d0c8fb81) complete. Timing: real 0.015s	user 0.013s	sys 0.001s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":4777,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:19:26.380293 19465 maintenance_manager.cc:419] P 73ec120445a34bafba012ca0e25b5f66: Scheduling MajorDeltaCompactionOp(8b14b884363e4aff866e30d4d0c8fb81): perf score=1.000000
I20260812 06:19:26.525852 19397 maintenance_manager.cc:643] P 73ec120445a34bafba012ca0e25b5f66: MajorDeltaCompactionOp(8b14b884363e4aff866e30d4d0c8fb81) complete. Timing: real 0.145s	user 0.103s	sys 0.032s 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":579,"lbm_read_time_us":9319,"lbm_reads_lt_1ms":468,"lbm_write_time_us":27797,"lbm_writes_lt_1ms":443,"mutex_wait_us":285,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":896,"update_count":2000}
I20260812 06:19:26.526551 19465 maintenance_manager.cc:419] P 73ec120445a34bafba012ca0e25b5f66: Scheduling FlushDeltaMemStoresOp(8b14b884363e4aff866e30d4d0c8fb81): perf score=14.095187
I20260812 06:19:26.584975 19397 maintenance_manager.cc:643] P 73ec120445a34bafba012ca0e25b5f66: FlushDeltaMemStoresOp(8b14b884363e4aff866e30d4d0c8fb81) complete. Timing: real 0.058s	user 0.021s	sys 0.026s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":21242,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:26.585543 19465 maintenance_manager.cc:419] P 73ec120445a34bafba012ca0e25b5f66: Scheduling FlushDeltaMemStoresOp(8b14b884363e4aff866e30d4d0c8fb81): perf score=2.188937
I20260812 06:19:26.602103 19397 maintenance_manager.cc:643] P 73ec120445a34bafba012ca0e25b5f66: FlushDeltaMemStoresOp(8b14b884363e4aff866e30d4d0c8fb81) complete. Timing: real 0.016s	user 0.003s	sys 0.011s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6297,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:26.602603 19465 maintenance_manager.cc:419] P 73ec120445a34bafba012ca0e25b5f66: Scheduling MajorDeltaCompactionOp(8b14b884363e4aff866e30d4d0c8fb81): perf score=1.000000
I20260812 06:19:26.786775 19397 maintenance_manager.cc:643] P 73ec120445a34bafba012ca0e25b5f66: MajorDeltaCompactionOp(8b14b884363e4aff866e30d4d0c8fb81) complete. Timing: real 0.184s	user 0.120s	sys 0.052s 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":1037,"lbm_read_time_us":15137,"lbm_reads_lt_1ms":572,"lbm_write_time_us":29723,"lbm_writes_lt_1ms":543,"mutex_wait_us":307,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":23168,"update_count":2500}
I20260812 06:19:26.787395 19465 maintenance_manager.cc:419] P 73ec120445a34bafba012ca0e25b5f66: Scheduling FlushDeltaMemStoresOp(8b14b884363e4aff866e30d4d0c8fb81): perf score=14.095187
I20260812 06:19:26.850270 19397 maintenance_manager.cc:643] P 73ec120445a34bafba012ca0e25b5f66: FlushDeltaMemStoresOp(8b14b884363e4aff866e30d4d0c8fb81) complete. Timing: real 0.063s	user 0.030s	sys 0.025s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":21211,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:26.850826 19465 maintenance_manager.cc:419] P 73ec120445a34bafba012ca0e25b5f66: Scheduling FlushDeltaMemStoresOp(8b14b884363e4aff866e30d4d0c8fb81): perf score=2.188937
I20260812 06:19:26.861354 19397 maintenance_manager.cc:643] P 73ec120445a34bafba012ca0e25b5f66: FlushDeltaMemStoresOp(8b14b884363e4aff866e30d4d0c8fb81) complete. Timing: real 0.010s	user 0.006s	sys 0.003s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4050,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:26.861819 19465 maintenance_manager.cc:419] P 73ec120445a34bafba012ca0e25b5f66: Scheduling MajorDeltaCompactionOp(8b14b884363e4aff866e30d4d0c8fb81): perf score=1.000000
I20260812 06:19:27.048550 19397 maintenance_manager.cc:643] P 73ec120445a34bafba012ca0e25b5f66: MajorDeltaCompactionOp(8b14b884363e4aff866e30d4d0c8fb81) complete. Timing: real 0.187s	user 0.113s	sys 0.065s 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":958,"lbm_read_time_us":12718,"lbm_reads_lt_1ms":572,"lbm_write_time_us":30652,"lbm_writes_lt_1ms":543,"mutex_wait_us":46,"peak_mem_usage":63115900,"reinsert_count":0,"update_count":2500}
I20260812 06:19:27.049268 19465 maintenance_manager.cc:419] P 73ec120445a34bafba012ca0e25b5f66: Scheduling FlushDeltaMemStoresOp(8b14b884363e4aff866e30d4d0c8fb81): perf score=14.095187
I20260812 06:19:27.101094 19397 maintenance_manager.cc:643] P 73ec120445a34bafba012ca0e25b5f66: FlushDeltaMemStoresOp(8b14b884363e4aff866e30d4d0c8fb81) complete. Timing: real 0.052s	user 0.022s	sys 0.027s Metrics: {"bytes_written":16409905,"delete_count":0,"lbm_write_time_us":23457,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:27.101547 19465 maintenance_manager.cc:419] P 73ec120445a34bafba012ca0e25b5f66: Scheduling FlushDeltaMemStoresOp(8b14b884363e4aff866e30d4d0c8fb81): perf score=2.188937
I20260812 06:19:27.121749 19397 maintenance_manager.cc:643] P 73ec120445a34bafba012ca0e25b5f66: FlushDeltaMemStoresOp(8b14b884363e4aff866e30d4d0c8fb81) complete. Timing: real 0.020s	user 0.004s	sys 0.014s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5154,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:27.122243 19465 maintenance_manager.cc:419] P 73ec120445a34bafba012ca0e25b5f66: Scheduling MajorDeltaCompactionOp(8b14b884363e4aff866e30d4d0c8fb81): perf score=1.000000
I20260812 06:19:27.331257 19397 maintenance_manager.cc:643] P 73ec120445a34bafba012ca0e25b5f66: MajorDeltaCompactionOp(8b14b884363e4aff866e30d4d0c8fb81) complete. Timing: real 0.209s	user 0.153s	sys 0.048s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774692,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":602,"lbm_read_time_us":12641,"lbm_reads_lt_1ms":564,"lbm_write_time_us":35202,"lbm_writes_lt_1ms":543,"mutex_wait_us":331,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":34048,"update_count":2500}
I20260812 06:19:27.331888 19465 maintenance_manager.cc:419] P 73ec120445a34bafba012ca0e25b5f66: Scheduling FlushDeltaMemStoresOp(8b14b884363e4aff866e30d4d0c8fb81): perf score=14.095187
I20260812 06:19:27.389209 19397 maintenance_manager.cc:643] P 73ec120445a34bafba012ca0e25b5f66: FlushDeltaMemStoresOp(8b14b884363e4aff866e30d4d0c8fb81) complete. Timing: real 0.057s	user 0.024s	sys 0.027s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":25452,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":402,"reinsert_count":0,"update_count":2000}
I20260812 06:19:27.389753 19465 maintenance_manager.cc:419] P 73ec120445a34bafba012ca0e25b5f66: Scheduling FlushDeltaMemStoresOp(8b14b884363e4aff866e30d4d0c8fb81): perf score=2.188937
I20260812 06:19:27.401003 19397 maintenance_manager.cc:643] P 73ec120445a34bafba012ca0e25b5f66: FlushDeltaMemStoresOp(8b14b884363e4aff866e30d4d0c8fb81) complete. Timing: real 0.011s	user 0.005s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4052,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:27.401582 19465 maintenance_manager.cc:419] P 73ec120445a34bafba012ca0e25b5f66: Scheduling FlushMRSOp(8b14b884363e4aff866e30d4d0c8fb81): perf score=1.000000
I20260812 06:19:27.444684 19397 maintenance_manager.cc:643] P 73ec120445a34bafba012ca0e25b5f66: FlushMRSOp(8b14b884363e4aff866e30d4d0c8fb81) complete. Timing: real 0.043s	user 0.041s	sys 0.000s Metrics: {"bytes_written":1316413,"cfile_init":1,"dirs.queue_time_us":68,"dirs.run_cpu_time_us":260,"dirs.run_wall_time_us":1464,"drs_written":1,"lbm_read_time_us":38,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1892,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":32}
I20260812 06:19:27.445508 19465 maintenance_manager.cc:419] P 73ec120445a34bafba012ca0e25b5f66: Scheduling LogGCOp(8b14b884363e4aff866e30d4d0c8fb81): free 133024337 bytes of WAL
I20260812 06:19:27.445749 19397 log_reader.cc:385] T 8b14b884363e4aff866e30d4d0c8fb81: removed 13 log segments from log reader
I20260812 06:19:27.445798 19397 log.cc:1079] T 8b14b884363e4aff866e30d4d0c8fb81 P 73ec120445a34bafba012ca0e25b5f66: Deleting log segment in path: /tmp/dist-test-tasky6MLcF/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515565329438-19282-0/minicluster-data/ts-0-root/wals/8b14b884363e4aff866e30d4d0c8fb81/wal-000000003 (ops 12-16)
I20260812 06:19:27.445827 19397 log.cc:1079] T 8b14b884363e4aff866e30d4d0c8fb81 P 73ec120445a34bafba012ca0e25b5f66: Deleting log segment in path: /tmp/dist-test-tasky6MLcF/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515565329438-19282-0/minicluster-data/ts-0-root/wals/8b14b884363e4aff866e30d4d0c8fb81/wal-000000004 (ops 17-21)
I20260812 06:19:27.445894 19397 log.cc:1079] T 8b14b884363e4aff866e30d4d0c8fb81 P 73ec120445a34bafba012ca0e25b5f66: Deleting log segment in path: /tmp/dist-test-tasky6MLcF/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515565329438-19282-0/minicluster-data/ts-0-root/wals/8b14b884363e4aff866e30d4d0c8fb81/wal-000000005 (ops 22-26)
I20260812 06:19:27.445955 19397 log.cc:1079] T 8b14b884363e4aff866e30d4d0c8fb81 P 73ec120445a34bafba012ca0e25b5f66: Deleting log segment in path: /tmp/dist-test-tasky6MLcF/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515565329438-19282-0/minicluster-data/ts-0-root/wals/8b14b884363e4aff866e30d4d0c8fb81/wal-000000006 (ops 27-31)
I20260812 06:19:27.446017 19397 log.cc:1079] T 8b14b884363e4aff866e30d4d0c8fb81 P 73ec120445a34bafba012ca0e25b5f66: Deleting log segment in path: /tmp/dist-test-tasky6MLcF/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515565329438-19282-0/minicluster-data/ts-0-root/wals/8b14b884363e4aff866e30d4d0c8fb81/wal-000000007 (ops 32-36)
I20260812 06:19:27.446056 19397 log.cc:1079] T 8b14b884363e4aff866e30d4d0c8fb81 P 73ec120445a34bafba012ca0e25b5f66: Deleting log segment in path: /tmp/dist-test-tasky6MLcF/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515565329438-19282-0/minicluster-data/ts-0-root/wals/8b14b884363e4aff866e30d4d0c8fb81/wal-000000008 (ops 37-41)
I20260812 06:19:27.446095 19397 log.cc:1079] T 8b14b884363e4aff866e30d4d0c8fb81 P 73ec120445a34bafba012ca0e25b5f66: Deleting log segment in path: /tmp/dist-test-tasky6MLcF/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515565329438-19282-0/minicluster-data/ts-0-root/wals/8b14b884363e4aff866e30d4d0c8fb81/wal-000000009 (ops 42-46)
I20260812 06:19:27.446133 19397 log.cc:1079] T 8b14b884363e4aff866e30d4d0c8fb81 P 73ec120445a34bafba012ca0e25b5f66: Deleting log segment in path: /tmp/dist-test-tasky6MLcF/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515565329438-19282-0/minicluster-data/ts-0-root/wals/8b14b884363e4aff866e30d4d0c8fb81/wal-000000010 (ops 47-51)
I20260812 06:19:27.446171 19397 log.cc:1079] T 8b14b884363e4aff866e30d4d0c8fb81 P 73ec120445a34bafba012ca0e25b5f66: Deleting log segment in path: /tmp/dist-test-tasky6MLcF/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515565329438-19282-0/minicluster-data/ts-0-root/wals/8b14b884363e4aff866e30d4d0c8fb81/wal-000000011 (ops 52-56)
I20260812 06:19:27.446209 19397 log.cc:1079] T 8b14b884363e4aff866e30d4d0c8fb81 P 73ec120445a34bafba012ca0e25b5f66: Deleting log segment in path: /tmp/dist-test-tasky6MLcF/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515565329438-19282-0/minicluster-data/ts-0-root/wals/8b14b884363e4aff866e30d4d0c8fb81/wal-000000012 (ops 57-61)
I20260812 06:19:27.446249 19397 log.cc:1079] T 8b14b884363e4aff866e30d4d0c8fb81 P 73ec120445a34bafba012ca0e25b5f66: Deleting log segment in path: /tmp/dist-test-tasky6MLcF/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515565329438-19282-0/minicluster-data/ts-0-root/wals/8b14b884363e4aff866e30d4d0c8fb81/wal-000000013 (ops 62-66)
I20260812 06:19:27.446291 19397 log.cc:1079] T 8b14b884363e4aff866e30d4d0c8fb81 P 73ec120445a34bafba012ca0e25b5f66: Deleting log segment in path: /tmp/dist-test-tasky6MLcF/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515565329438-19282-0/minicluster-data/ts-0-root/wals/8b14b884363e4aff866e30d4d0c8fb81/wal-000000014 (ops 67-70)
I20260812 06:19:27.446333 19397 log.cc:1079] T 8b14b884363e4aff866e30d4d0c8fb81 P 73ec120445a34bafba012ca0e25b5f66: Deleting log segment in path: /tmp/dist-test-tasky6MLcF/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515565329438-19282-0/minicluster-data/ts-0-root/wals/8b14b884363e4aff866e30d4d0c8fb81/wal-000000015 (ops 71-75)
I20260812 06:19:27.477226 19397 maintenance_manager.cc:643] P 73ec120445a34bafba012ca0e25b5f66: LogGCOp(8b14b884363e4aff866e30d4d0c8fb81) complete. Timing: real 0.032s	user 0.000s	sys 0.029s Metrics: {}
I20260812 06:19:27.477619 19465 maintenance_manager.cc:419] P 73ec120445a34bafba012ca0e25b5f66: Scheduling FlushDeltaMemStoresOp(8b14b884363e4aff866e30d4d0c8fb81): perf score=3.181125
I20260812 06:19:27.490371 19397 maintenance_manager.cc:643] P 73ec120445a34bafba012ca0e25b5f66: FlushDeltaMemStoresOp(8b14b884363e4aff866e30d4d0c8fb81) complete. Timing: real 0.013s	user 0.010s	sys 0.001s Metrics: {"bytes_written":4594951,"delete_count":0,"lbm_write_time_us":4840,"lbm_writes_lt_1ms":115,"reinsert_count":0,"update_count":560}
I20260812 06:19:27.490813 19465 maintenance_manager.cc:419] P 73ec120445a34bafba012ca0e25b5f66: Scheduling UndoDeltaBlockGCOp(8b14b884363e4aff866e30d4d0c8fb81): 493 bytes on disk
I20260812 06:19:27.491650 19397 maintenance_manager.cc:643] P 73ec120445a34bafba012ca0e25b5f66: UndoDeltaBlockGCOp(8b14b884363e4aff866e30d4d0c8fb81) complete. Timing: real 0.001s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":64,"lbm_reads_lt_1ms":4}
I20260812 06:19:27.492128 19465 maintenance_manager.cc:419] P 73ec120445a34bafba012ca0e25b5f66: Scheduling FlushDeltaMemStoresOp(8b14b884363e4aff866e30d4d0c8fb81): perf score=2.188937
I20260812 06:19:27.505849 19397 maintenance_manager.cc:643] P 73ec120445a34bafba012ca0e25b5f66: FlushDeltaMemStoresOp(8b14b884363e4aff866e30d4d0c8fb81) complete. Timing: real 0.014s	user 0.011s	sys 0.000s Metrics: {"bytes_written":3610355,"delete_count":0,"lbm_write_time_us":5109,"lbm_writes_lt_1ms":91,"reinsert_count":0,"update_count":440}
I20260812 06:19:27.506346 19465 maintenance_manager.cc:419] P 73ec120445a34bafba012ca0e25b5f66: Scheduling MajorDeltaCompactionOp(8b14b884363e4aff866e30d4d0c8fb81): perf score=1.000000
I20260812 06:19:27.760241 19397 maintenance_manager.cc:643] P 73ec120445a34bafba012ca0e25b5f66: MajorDeltaCompactionOp(8b14b884363e4aff866e30d4d0c8fb81) complete. Timing: real 0.254s	user 0.161s	sys 0.082s Metrics: {"cfile_cache_miss":734,"cfile_cache_miss_bytes":32979739,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":335,"lbm_read_time_us":17237,"lbm_reads_lt_1ms":774,"lbm_write_time_us":42819,"lbm_writes_lt_1ms":743,"mutex_wait_us":54,"peak_mem_usage":87969044,"reinsert_count":0,"spinlock_wait_cycles":2560,"thread_start_us":98,"threads_started":1,"update_count":3500}
I20260812 06:19:27.761003 19465 maintenance_manager.cc:419] P 73ec120445a34bafba012ca0e25b5f66: Scheduling FlushDeltaMemStoresOp(8b14b884363e4aff866e30d4d0c8fb81): perf score=18.063937
I20260812 06:19:27.829162 19397 maintenance_manager.cc:643] P 73ec120445a34bafba012ca0e25b5f66: FlushDeltaMemStoresOp(8b14b884363e4aff866e30d4d0c8fb81) complete. Timing: real 0.068s	user 0.030s	sys 0.031s Metrics: {"bytes_written":20512315,"delete_count":0,"lbm_write_time_us":29091,"lbm_writes_lt_1ms":503,"reinsert_count":0,"update_count":2500}
I20260812 06:19:27.829664 19465 maintenance_manager.cc:419] P 73ec120445a34bafba012ca0e25b5f66: Scheduling FlushDeltaMemStoresOp(8b14b884363e4aff866e30d4d0c8fb81): perf score=2.188937
I20260812 06:19:27.845712 19397 maintenance_manager.cc:643] P 73ec120445a34bafba012ca0e25b5f66: FlushDeltaMemStoresOp(8b14b884363e4aff866e30d4d0c8fb81) complete. Timing: real 0.016s	user 0.009s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6036,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:27.846338 19465 maintenance_manager.cc:419] P 73ec120445a34bafba012ca0e25b5f66: Scheduling MajorDeltaCompactionOp(8b14b884363e4aff866e30d4d0c8fb81): perf score=1.000000
I20260812 06:19:28.060074 19397 maintenance_manager.cc:643] P 73ec120445a34bafba012ca0e25b5f66: MajorDeltaCompactionOp(8b14b884363e4aff866e30d4d0c8fb81) complete. Timing: real 0.214s	user 0.130s	sys 0.082s Metrics: {"cfile_cache_miss":632,"cfile_cache_miss_bytes":28877102,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":266,"lbm_read_time_us":16454,"lbm_reads_lt_1ms":672,"lbm_write_time_us":34733,"lbm_writes_lt_1ms":643,"mutex_wait_us":88,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":7168,"update_count":3000}
I20260812 06:19:28.060834 19465 maintenance_manager.cc:419] P 73ec120445a34bafba012ca0e25b5f66: Scheduling FlushDeltaMemStoresOp(8b14b884363e4aff866e30d4d0c8fb81): perf score=15.087375
I20260812 06:19:28.114833 19397 maintenance_manager.cc:643] P 73ec120445a34bafba012ca0e25b5f66: FlushDeltaMemStoresOp(8b14b884363e4aff866e30d4d0c8fb81) complete. Timing: real 0.054s	user 0.028s	sys 0.020s Metrics: {"bytes_written":16820145,"delete_count":0,"lbm_write_time_us":23219,"lbm_writes_lt_1ms":413,"reinsert_count":0,"update_count":2050}
I20260812 06:19:28.115401 19465 maintenance_manager.cc:419] P 73ec120445a34bafba012ca0e25b5f66: Scheduling FlushDeltaMemStoresOp(8b14b884363e4aff866e30d4d0c8fb81): perf score=2.188937
I20260812 06:19:28.127321 19397 maintenance_manager.cc:643] P 73ec120445a34bafba012ca0e25b5f66: FlushDeltaMemStoresOp(8b14b884363e4aff866e30d4d0c8fb81) complete. Timing: real 0.012s	user 0.011s	sys 0.001s Metrics: {"bytes_written":4143686,"delete_count":0,"lbm_write_time_us":4661,"lbm_writes_lt_1ms":104,"reinsert_count":0,"update_count":505}
I20260812 06:19:28.127753 19465 maintenance_manager.cc:419] P 73ec120445a34bafba012ca0e25b5f66: Scheduling FlushDeltaMemStoresOp(8b14b884363e4aff866e30d4d0c8fb81): perf score=2.188937
I20260812 06:19:28.140584 19397 maintenance_manager.cc:643] P 73ec120445a34bafba012ca0e25b5f66: FlushDeltaMemStoresOp(8b14b884363e4aff866e30d4d0c8fb81) complete. Timing: real 0.013s	user 0.011s	sys 0.000s Metrics: {"bytes_written":3651380,"delete_count":0,"lbm_write_time_us":5237,"lbm_writes_lt_1ms":92,"reinsert_count":0,"update_count":445}
I20260812 06:19:28.140980 19465 maintenance_manager.cc:419] P 73ec120445a34bafba012ca0e25b5f66: Scheduling MajorDeltaCompactionOp(8b14b884363e4aff866e30d4d0c8fb81): perf score=1.000000
I20260812 06:19:28.351076 19397 maintenance_manager.cc:643] P 73ec120445a34bafba012ca0e25b5f66: MajorDeltaCompactionOp(8b14b884363e4aff866e30d4d0c8fb81) complete. Timing: real 0.210s	user 0.130s	sys 0.080s Metrics: {"cfile_cache_miss":633,"cfile_cache_miss_bytes":28877211,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":1123,"lbm_read_time_us":15623,"lbm_reads_lt_1ms":673,"lbm_write_time_us":34990,"lbm_writes_lt_1ms":643,"mutex_wait_us":359,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":3712,"update_count":3000}
I20260812 06:19:28.351727 19465 maintenance_manager.cc:419] P 73ec120445a34bafba012ca0e25b5f66: Scheduling FlushDeltaMemStoresOp(8b14b884363e4aff866e30d4d0c8fb81): perf score=14.095187
I20260812 06:19:28.404251 19397 maintenance_manager.cc:643] P 73ec120445a34bafba012ca0e25b5f66: FlushDeltaMemStoresOp(8b14b884363e4aff866e30d4d0c8fb81) complete. Timing: real 0.052s	user 0.043s	sys 0.007s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":22428,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:28.404757 19465 maintenance_manager.cc:419] P 73ec120445a34bafba012ca0e25b5f66: Scheduling FlushDeltaMemStoresOp(8b14b884363e4aff866e30d4d0c8fb81): perf score=2.188937
I20260812 06:19:28.416640 19397 maintenance_manager.cc:643] P 73ec120445a34bafba012ca0e25b5f66: FlushDeltaMemStoresOp(8b14b884363e4aff866e30d4d0c8fb81) complete. Timing: real 0.012s	user 0.010s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4346,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:28.417174 19465 maintenance_manager.cc:419] P 73ec120445a34bafba012ca0e25b5f66: Scheduling MajorDeltaCompactionOp(8b14b884363e4aff866e30d4d0c8fb81): perf score=1.000000
I20260812 06:19:28.600582 19397 maintenance_manager.cc:643] P 73ec120445a34bafba012ca0e25b5f66: MajorDeltaCompactionOp(8b14b884363e4aff866e30d4d0c8fb81) complete. Timing: real 0.183s	user 0.132s	sys 0.049s 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":209,"lbm_read_time_us":13327,"lbm_reads_lt_1ms":572,"lbm_write_time_us":33584,"lbm_writes_lt_1ms":543,"mutex_wait_us":21,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":12544,"update_count":2500}
I20260812 06:19:28.601186 19465 maintenance_manager.cc:419] P 73ec120445a34bafba012ca0e25b5f66: Scheduling FlushDeltaMemStoresOp(8b14b884363e4aff866e30d4d0c8fb81): perf score=14.095187
I20260812 06:19:28.669324 19397 maintenance_manager.cc:643] P 73ec120445a34bafba012ca0e25b5f66: FlushDeltaMemStoresOp(8b14b884363e4aff866e30d4d0c8fb81) complete. Timing: real 0.068s	user 0.040s	sys 0.009s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":22417,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:28.669800 19465 maintenance_manager.cc:419] P 73ec120445a34bafba012ca0e25b5f66: Scheduling FlushDeltaMemStoresOp(8b14b884363e4aff866e30d4d0c8fb81): perf score=2.188937
I20260812 06:19:28.680809 19397 maintenance_manager.cc:643] P 73ec120445a34bafba012ca0e25b5f66: FlushDeltaMemStoresOp(8b14b884363e4aff866e30d4d0c8fb81) complete. Timing: real 0.011s	user 0.005s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4293,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:28.681622 19465 maintenance_manager.cc:419] P 73ec120445a34bafba012ca0e25b5f66: Scheduling MajorDeltaCompactionOp(8b14b884363e4aff866e30d4d0c8fb81): perf score=1.000000
I20260812 06:19:28.874794 19397 maintenance_manager.cc:643] P 73ec120445a34bafba012ca0e25b5f66: MajorDeltaCompactionOp(8b14b884363e4aff866e30d4d0c8fb81) complete. Timing: real 0.193s	user 0.118s	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":817,"lbm_read_time_us":14921,"lbm_reads_lt_1ms":572,"lbm_write_time_us":31203,"lbm_writes_lt_1ms":543,"mutex_wait_us":49,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":7168,"update_count":2500}
I20260812 06:19:28.875366 19465 maintenance_manager.cc:419] P 73ec120445a34bafba012ca0e25b5f66: Scheduling FlushDeltaMemStoresOp(8b14b884363e4aff866e30d4d0c8fb81): perf score=14.095187
I20260812 06:19:28.936522 19397 maintenance_manager.cc:643] P 73ec120445a34bafba012ca0e25b5f66: FlushDeltaMemStoresOp(8b14b884363e4aff866e30d4d0c8fb81) complete. Timing: real 0.061s	user 0.028s	sys 0.024s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":18587,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:28.937052 19465 maintenance_manager.cc:419] P 73ec120445a34bafba012ca0e25b5f66: Scheduling FlushDeltaMemStoresOp(8b14b884363e4aff866e30d4d0c8fb81): perf score=2.188937
I20260812 06:19:28.953711 19397 maintenance_manager.cc:643] P 73ec120445a34bafba012ca0e25b5f66: FlushDeltaMemStoresOp(8b14b884363e4aff866e30d4d0c8fb81) complete. Timing: real 0.016s	user 0.007s	sys 0.007s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6338,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:28.954315 19465 maintenance_manager.cc:419] P 73ec120445a34bafba012ca0e25b5f66: Scheduling FlushMRSOp(8b14b884363e4aff866e30d4d0c8fb81): perf score=1.000000
I20260812 06:19:28.997779 19397 maintenance_manager.cc:643] P 73ec120445a34bafba012ca0e25b5f66: FlushMRSOp(8b14b884363e4aff866e30d4d0c8fb81) complete. Timing: real 0.043s	user 0.024s	sys 0.008s Metrics: {"bytes_written":1193507,"cfile_init":1,"dirs.queue_time_us":65,"dirs.run_cpu_time_us":230,"dirs.run_wall_time_us":1436,"drs_written":1,"lbm_read_time_us":38,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1910,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":29}
I20260812 06:19:28.998520 19465 maintenance_manager.cc:419] P 73ec120445a34bafba012ca0e25b5f66: Scheduling LogGCOp(8b14b884363e4aff866e30d4d0c8fb81): free 112239380 bytes of WAL
I20260812 06:19:28.998764 19397 log_reader.cc:385] T 8b14b884363e4aff866e30d4d0c8fb81: removed 11 log segments from log reader
I20260812 06:19:28.998807 19397 log.cc:1079] T 8b14b884363e4aff866e30d4d0c8fb81 P 73ec120445a34bafba012ca0e25b5f66: Deleting log segment in path: /tmp/dist-test-tasky6MLcF/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515565329438-19282-0/minicluster-data/ts-0-root/wals/8b14b884363e4aff866e30d4d0c8fb81/wal-000000016 (ops 76-80)
I20260812 06:19:28.998837 19397 log.cc:1079] T 8b14b884363e4aff866e30d4d0c8fb81 P 73ec120445a34bafba012ca0e25b5f66: Deleting log segment in path: /tmp/dist-test-tasky6MLcF/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515565329438-19282-0/minicluster-data/ts-0-root/wals/8b14b884363e4aff866e30d4d0c8fb81/wal-000000017 (ops 81-85)
I20260812 06:19:28.998904 19397 log.cc:1079] T 8b14b884363e4aff866e30d4d0c8fb81 P 73ec120445a34bafba012ca0e25b5f66: Deleting log segment in path: /tmp/dist-test-tasky6MLcF/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515565329438-19282-0/minicluster-data/ts-0-root/wals/8b14b884363e4aff866e30d4d0c8fb81/wal-000000018 (ops 86-90)
I20260812 06:19:28.998936 19397 log.cc:1079] T 8b14b884363e4aff866e30d4d0c8fb81 P 73ec120445a34bafba012ca0e25b5f66: Deleting log segment in path: /tmp/dist-test-tasky6MLcF/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515565329438-19282-0/minicluster-data/ts-0-root/wals/8b14b884363e4aff866e30d4d0c8fb81/wal-000000019 (ops 91-94)
I20260812 06:19:28.998974 19397 log.cc:1079] T 8b14b884363e4aff866e30d4d0c8fb81 P 73ec120445a34bafba012ca0e25b5f66: Deleting log segment in path: /tmp/dist-test-tasky6MLcF/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515565329438-19282-0/minicluster-data/ts-0-root/wals/8b14b884363e4aff866e30d4d0c8fb81/wal-000000020 (ops 95-99)
I20260812 06:19:28.999037 19397 log.cc:1079] T 8b14b884363e4aff866e30d4d0c8fb81 P 73ec120445a34bafba012ca0e25b5f66: Deleting log segment in path: /tmp/dist-test-tasky6MLcF/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515565329438-19282-0/minicluster-data/ts-0-root/wals/8b14b884363e4aff866e30d4d0c8fb81/wal-000000021 (ops 100-104)
I20260812 06:19:28.999083 19397 log.cc:1079] T 8b14b884363e4aff866e30d4d0c8fb81 P 73ec120445a34bafba012ca0e25b5f66: Deleting log segment in path: /tmp/dist-test-tasky6MLcF/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515565329438-19282-0/minicluster-data/ts-0-root/wals/8b14b884363e4aff866e30d4d0c8fb81/wal-000000022 (ops 105-109)
I20260812 06:19:28.999156 19397 log.cc:1079] T 8b14b884363e4aff866e30d4d0c8fb81 P 73ec120445a34bafba012ca0e25b5f66: Deleting log segment in path: /tmp/dist-test-tasky6MLcF/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515565329438-19282-0/minicluster-data/ts-0-root/wals/8b14b884363e4aff866e30d4d0c8fb81/wal-000000023 (ops 110-114)
I20260812 06:19:28.999193 19397 log.cc:1079] T 8b14b884363e4aff866e30d4d0c8fb81 P 73ec120445a34bafba012ca0e25b5f66: Deleting log segment in path: /tmp/dist-test-tasky6MLcF/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515565329438-19282-0/minicluster-data/ts-0-root/wals/8b14b884363e4aff866e30d4d0c8fb81/wal-000000024 (ops 115-119)
I20260812 06:19:28.999231 19397 log.cc:1079] T 8b14b884363e4aff866e30d4d0c8fb81 P 73ec120445a34bafba012ca0e25b5f66: Deleting log segment in path: /tmp/dist-test-tasky6MLcF/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515565329438-19282-0/minicluster-data/ts-0-root/wals/8b14b884363e4aff866e30d4d0c8fb81/wal-000000025 (ops 120-124)
I20260812 06:19:28.999269 19397 log.cc:1079] T 8b14b884363e4aff866e30d4d0c8fb81 P 73ec120445a34bafba012ca0e25b5f66: Deleting log segment in path: /tmp/dist-test-tasky6MLcF/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515565329438-19282-0/minicluster-data/ts-0-root/wals/8b14b884363e4aff866e30d4d0c8fb81/wal-000000026 (ops 125-129)
I20260812 06:19:29.025581 19397 maintenance_manager.cc:643] P 73ec120445a34bafba012ca0e25b5f66: LogGCOp(8b14b884363e4aff866e30d4d0c8fb81) complete. Timing: real 0.027s	user 0.002s	sys 0.023s Metrics: {}
I20260812 06:19:29.025969 19465 maintenance_manager.cc:419] P 73ec120445a34bafba012ca0e25b5f66: Scheduling UndoDeltaBlockGCOp(8b14b884363e4aff866e30d4d0c8fb81): 462 bytes on disk
I20260812 06:19:29.026384 19397 maintenance_manager.cc:643] P 73ec120445a34bafba012ca0e25b5f66: UndoDeltaBlockGCOp(8b14b884363e4aff866e30d4d0c8fb81) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":51,"lbm_reads_lt_1ms":4}
I20260812 06:19:29.026902 19465 maintenance_manager.cc:419] P 73ec120445a34bafba012ca0e25b5f66: Scheduling FlushDeltaMemStoresOp(8b14b884363e4aff866e30d4d0c8fb81): perf score=3.181125
I20260812 06:19:29.041541 19397 maintenance_manager.cc:643] P 73ec120445a34bafba012ca0e25b5f66: FlushDeltaMemStoresOp(8b14b884363e4aff866e30d4d0c8fb81) complete. Timing: real 0.014s	user 0.003s	sys 0.007s Metrics: {"bytes_written":4512901,"delete_count":0,"lbm_write_time_us":4903,"lbm_writes_lt_1ms":113,"reinsert_count":0,"update_count":550}
I20260812 06:19:29.041958 19465 maintenance_manager.cc:419] P 73ec120445a34bafba012ca0e25b5f66: Scheduling FlushDeltaMemStoresOp(8b14b884363e4aff866e30d4d0c8fb81): perf score=2.188937
I20260812 06:19:29.055464 19397 maintenance_manager.cc:643] P 73ec120445a34bafba012ca0e25b5f66: FlushDeltaMemStoresOp(8b14b884363e4aff866e30d4d0c8fb81) complete. Timing: real 0.013s	user 0.009s	sys 0.004s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":5325,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:19:29.055891 19465 maintenance_manager.cc:419] P 73ec120445a34bafba012ca0e25b5f66: Scheduling MajorDeltaCompactionOp(8b14b884363e4aff866e30d4d0c8fb81): perf score=1.000000
I20260812 06:19:29.295985 19397 maintenance_manager.cc:643] P 73ec120445a34bafba012ca0e25b5f66: MajorDeltaCompactionOp(8b14b884363e4aff866e30d4d0c8fb81) complete. Timing: real 0.240s	user 0.167s	sys 0.061s Metrics: {"cfile_cache_miss":734,"cfile_cache_miss_bytes":32979738,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":212,"lbm_read_time_us":16562,"lbm_reads_lt_1ms":774,"lbm_write_time_us":40726,"lbm_writes_lt_1ms":743,"mutex_wait_us":63,"peak_mem_usage":87969044,"reinsert_count":0,"spinlock_wait_cycles":10496,"thread_start_us":76,"threads_started":1,"update_count":3500}
I20260812 06:19:29.297339 19465 maintenance_manager.cc:419] P 73ec120445a34bafba012ca0e25b5f66: Scheduling FlushDeltaMemStoresOp(8b14b884363e4aff866e30d4d0c8fb81): perf score=18.063937
I20260812 06:19:29.361975 19397 maintenance_manager.cc:643] P 73ec120445a34bafba012ca0e25b5f66: FlushDeltaMemStoresOp(8b14b884363e4aff866e30d4d0c8fb81) complete. Timing: real 0.064s	user 0.034s	sys 0.028s Metrics: {"bytes_written":20512326,"delete_count":0,"lbm_write_time_us":29655,"lbm_writes_lt_1ms":503,"reinsert_count":0,"update_count":2500}
I20260812 06:19:29.362433 19465 maintenance_manager.cc:419] P 73ec120445a34bafba012ca0e25b5f66: Scheduling FlushDeltaMemStoresOp(8b14b884363e4aff866e30d4d0c8fb81): perf score=2.188937
I20260812 06:19:29.373539 19397 maintenance_manager.cc:643] P 73ec120445a34bafba012ca0e25b5f66: FlushDeltaMemStoresOp(8b14b884363e4aff866e30d4d0c8fb81) complete. Timing: real 0.011s	user 0.006s	sys 0.003s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4162,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:29.374409 19465 maintenance_manager.cc:419] P 73ec120445a34bafba012ca0e25b5f66: Scheduling MajorDeltaCompactionOp(8b14b884363e4aff866e30d4d0c8fb81): perf score=1.000000
I20260812 06:19:29.566211 19397 maintenance_manager.cc:643] P 73ec120445a34bafba012ca0e25b5f66: MajorDeltaCompactionOp(8b14b884363e4aff866e30d4d0c8fb81) complete. Timing: real 0.192s	user 0.150s	sys 0.040s Metrics: {"cfile_cache_miss":632,"cfile_cache_miss_bytes":28877112,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":234,"lbm_read_time_us":13453,"lbm_reads_lt_1ms":672,"lbm_write_time_us":36775,"lbm_writes_lt_1ms":643,"mutex_wait_us":36,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":8448,"update_count":3000}
I20260812 06:19:29.566972 19465 maintenance_manager.cc:419] P 73ec120445a34bafba012ca0e25b5f66: Scheduling FlushDeltaMemStoresOp(8b14b884363e4aff866e30d4d0c8fb81): perf score=14.095187
I20260812 06:19:29.615842 19397 maintenance_manager.cc:643] P 73ec120445a34bafba012ca0e25b5f66: FlushDeltaMemStoresOp(8b14b884363e4aff866e30d4d0c8fb81) complete. Timing: real 0.049s	user 0.041s	sys 0.007s Metrics: {"bytes_written":16409900,"delete_count":0,"lbm_write_time_us":21658,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:29.616387 19465 maintenance_manager.cc:419] P 73ec120445a34bafba012ca0e25b5f66: Scheduling FlushDeltaMemStoresOp(8b14b884363e4aff866e30d4d0c8fb81): perf score=2.188937
I20260812 06:19:29.633339 19397 maintenance_manager.cc:643] P 73ec120445a34bafba012ca0e25b5f66: FlushDeltaMemStoresOp(8b14b884363e4aff866e30d4d0c8fb81) complete. Timing: real 0.017s	user 0.010s	sys 0.005s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6639,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:29.633894 19465 maintenance_manager.cc:419] P 73ec120445a34bafba012ca0e25b5f66: Scheduling MajorDeltaCompactionOp(8b14b884363e4aff866e30d4d0c8fb81): perf score=1.000000
I20260812 06:19:29.807785 19397 maintenance_manager.cc:643] P 73ec120445a34bafba012ca0e25b5f66: MajorDeltaCompactionOp(8b14b884363e4aff866e30d4d0c8fb81) complete. Timing: real 0.174s	user 0.112s	sys 0.054s 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":343,"lbm_read_time_us":12017,"lbm_reads_lt_1ms":572,"lbm_write_time_us":31667,"lbm_writes_lt_1ms":543,"mutex_wait_us":74,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":6016,"update_count":2500}
I20260812 06:19:29.808629 19465 maintenance_manager.cc:419] P 73ec120445a34bafba012ca0e25b5f66: Scheduling FlushDeltaMemStoresOp(8b14b884363e4aff866e30d4d0c8fb81): perf score=14.095187
I20260812 06:19:29.867605 19397 maintenance_manager.cc:643] P 73ec120445a34bafba012ca0e25b5f66: FlushDeltaMemStoresOp(8b14b884363e4aff866e30d4d0c8fb81) complete. Timing: real 0.059s	user 0.046s	sys 0.005s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":23837,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:29.868090 19465 maintenance_manager.cc:419] P 73ec120445a34bafba012ca0e25b5f66: Scheduling MajorDeltaCompactionOp(8b14b884363e4aff866e30d4d0c8fb81): perf score=1.000000
I20260812 06:19:30.024151 19397 maintenance_manager.cc:643] P 73ec120445a34bafba012ca0e25b5f66: MajorDeltaCompactionOp(8b14b884363e4aff866e30d4d0c8fb81) complete. Timing: real 0.156s	user 0.114s	sys 0.036s Metrics: {"cfile_cache_miss":431,"cfile_cache_miss_bytes":20672158,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":1,"delta_iterators_relevant":1,"dirs.queue_time_us":1039,"lbm_read_time_us":12059,"lbm_reads_lt_1ms":463,"lbm_write_time_us":25479,"lbm_writes_lt_1ms":443,"mutex_wait_us":338,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":10240,"update_count":2000}
I20260812 06:19:30.024684 19465 maintenance_manager.cc:419] P 73ec120445a34bafba012ca0e25b5f66: Scheduling FlushDeltaMemStoresOp(8b14b884363e4aff866e30d4d0c8fb81): perf score=14.095187
I20260812 06:19:30.078322 19397 maintenance_manager.cc:643] P 73ec120445a34bafba012ca0e25b5f66: FlushDeltaMemStoresOp(8b14b884363e4aff866e30d4d0c8fb81) complete. Timing: real 0.053s	user 0.038s	sys 0.004s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":20137,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:30.078908 19465 maintenance_manager.cc:419] P 73ec120445a34bafba012ca0e25b5f66: Scheduling FlushDeltaMemStoresOp(8b14b884363e4aff866e30d4d0c8fb81): perf score=2.188937
I20260812 06:19:30.091063 19397 maintenance_manager.cc:643] P 73ec120445a34bafba012ca0e25b5f66: FlushDeltaMemStoresOp(8b14b884363e4aff866e30d4d0c8fb81) complete. Timing: real 0.012s	user 0.006s	sys 0.003s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4382,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:30.091778 19465 maintenance_manager.cc:419] P 73ec120445a34bafba012ca0e25b5f66: Scheduling MajorDeltaCompactionOp(8b14b884363e4aff866e30d4d0c8fb81): perf score=1.000000
I20260812 06:19:30.287014 19397 maintenance_manager.cc:643] P 73ec120445a34bafba012ca0e25b5f66: MajorDeltaCompactionOp(8b14b884363e4aff866e30d4d0c8fb81) complete. Timing: real 0.195s	user 0.118s	sys 0.064s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774689,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":226,"lbm_read_time_us":12007,"lbm_reads_lt_1ms":572,"lbm_write_time_us":31671,"lbm_writes_lt_1ms":543,"mutex_wait_us":66,"peak_mem_usage":63115900,"reinsert_count":0,"update_count":2500}
I20260812 06:19:30.287810 19465 maintenance_manager.cc:419] P 73ec120445a34bafba012ca0e25b5f66: Scheduling FlushDeltaMemStoresOp(8b14b884363e4aff866e30d4d0c8fb81): perf score=14.095187
I20260812 06:19:30.340291 19397 maintenance_manager.cc:643] P 73ec120445a34bafba012ca0e25b5f66: FlushDeltaMemStoresOp(8b14b884363e4aff866e30d4d0c8fb81) complete. Timing: real 0.052s	user 0.030s	sys 0.020s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":22649,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:30.340796 19465 maintenance_manager.cc:419] P 73ec120445a34bafba012ca0e25b5f66: Scheduling FlushDeltaMemStoresOp(8b14b884363e4aff866e30d4d0c8fb81): perf score=2.188937
I20260812 06:19:30.353116 19397 maintenance_manager.cc:643] P 73ec120445a34bafba012ca0e25b5f66: FlushDeltaMemStoresOp(8b14b884363e4aff866e30d4d0c8fb81) complete. Timing: real 0.012s	user 0.006s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4411,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:30.354383 19465 maintenance_manager.cc:419] P 73ec120445a34bafba012ca0e25b5f66: Scheduling MajorDeltaCompactionOp(8b14b884363e4aff866e30d4d0c8fb81): perf score=1.000000
I20260812 06:19:30.516104 19397 maintenance_manager.cc:643] P 73ec120445a34bafba012ca0e25b5f66: MajorDeltaCompactionOp(8b14b884363e4aff866e30d4d0c8fb81) complete. Timing: real 0.162s	user 0.110s	sys 0.048s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774688,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":284,"lbm_read_time_us":11319,"lbm_reads_lt_1ms":572,"lbm_write_time_us":32480,"lbm_writes_lt_1ms":543,"mutex_wait_us":27,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":4608,"update_count":2500}
I20260812 06:19:30.516676 19465 maintenance_manager.cc:419] P 73ec120445a34bafba012ca0e25b5f66: Scheduling FlushDeltaMemStoresOp(8b14b884363e4aff866e30d4d0c8fb81): perf score=14.095187
I20260812 06:19:30.567950 19397 maintenance_manager.cc:643] P 73ec120445a34bafba012ca0e25b5f66: FlushDeltaMemStoresOp(8b14b884363e4aff866e30d4d0c8fb81) complete. Timing: real 0.051s	user 0.036s	sys 0.007s Metrics: {"bytes_written":16409912,"delete_count":0,"lbm_write_time_us":19711,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:30.568498 19465 maintenance_manager.cc:419] P 73ec120445a34bafba012ca0e25b5f66: Scheduling FlushDeltaMemStoresOp(8b14b884363e4aff866e30d4d0c8fb81): perf score=2.188937
I20260812 06:19:30.584511 19397 maintenance_manager.cc:643] P 73ec120445a34bafba012ca0e25b5f66: FlushDeltaMemStoresOp(8b14b884363e4aff866e30d4d0c8fb81) complete. Timing: real 0.016s	user 0.009s	sys 0.006s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6009,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:30.585086 19465 maintenance_manager.cc:419] P 73ec120445a34bafba012ca0e25b5f66: Scheduling FlushMRSOp(8b14b884363e4aff866e30d4d0c8fb81): perf score=1.000000
I20260812 06:19:30.615204 19397 maintenance_manager.cc:643] P 73ec120445a34bafba012ca0e25b5f66: FlushMRSOp(8b14b884363e4aff866e30d4d0c8fb81) complete. Timing: real 0.030s	user 0.025s	sys 0.005s Metrics: {"bytes_written":1316417,"cfile_init":1,"dirs.queue_time_us":82,"dirs.run_cpu_time_us":177,"dirs.run_wall_time_us":1730,"drs_written":1,"lbm_read_time_us":55,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1737,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":32}
I20260812 06:19:30.615952 19465 maintenance_manager.cc:419] P 73ec120445a34bafba012ca0e25b5f66: Scheduling LogGCOp(8b14b884363e4aff866e30d4d0c8fb81): free 141338678 bytes of WAL
I20260812 06:19:30.616246 19397 log_reader.cc:385] T 8b14b884363e4aff866e30d4d0c8fb81: removed 14 log segments from log reader
I20260812 06:19:30.616307 19397 log.cc:1079] T 8b14b884363e4aff866e30d4d0c8fb81 P 73ec120445a34bafba012ca0e25b5f66: Deleting log segment in path: /tmp/dist-test-tasky6MLcF/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515565329438-19282-0/minicluster-data/ts-0-root/wals/8b14b884363e4aff866e30d4d0c8fb81/wal-000000027 (ops 130-134)
I20260812 06:19:30.616345 19397 log.cc:1079] T 8b14b884363e4aff866e30d4d0c8fb81 P 73ec120445a34bafba012ca0e25b5f66: Deleting log segment in path: /tmp/dist-test-tasky6MLcF/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515565329438-19282-0/minicluster-data/ts-0-root/wals/8b14b884363e4aff866e30d4d0c8fb81/wal-000000028 (ops 135-138)
I20260812 06:19:30.616382 19397 log.cc:1079] T 8b14b884363e4aff866e30d4d0c8fb81 P 73ec120445a34bafba012ca0e25b5f66: Deleting log segment in path: /tmp/dist-test-tasky6MLcF/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515565329438-19282-0/minicluster-data/ts-0-root/wals/8b14b884363e4aff866e30d4d0c8fb81/wal-000000029 (ops 139-143)
I20260812 06:19:30.616410 19397 log.cc:1079] T 8b14b884363e4aff866e30d4d0c8fb81 P 73ec120445a34bafba012ca0e25b5f66: Deleting log segment in path: /tmp/dist-test-tasky6MLcF/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515565329438-19282-0/minicluster-data/ts-0-root/wals/8b14b884363e4aff866e30d4d0c8fb81/wal-000000030 (ops 144-148)
I20260812 06:19:30.616441 19397 log.cc:1079] T 8b14b884363e4aff866e30d4d0c8fb81 P 73ec120445a34bafba012ca0e25b5f66: Deleting log segment in path: /tmp/dist-test-tasky6MLcF/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515565329438-19282-0/minicluster-data/ts-0-root/wals/8b14b884363e4aff866e30d4d0c8fb81/wal-000000031 (ops 149-153)
I20260812 06:19:30.616470 19397 log.cc:1079] T 8b14b884363e4aff866e30d4d0c8fb81 P 73ec120445a34bafba012ca0e25b5f66: Deleting log segment in path: /tmp/dist-test-tasky6MLcF/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515565329438-19282-0/minicluster-data/ts-0-root/wals/8b14b884363e4aff866e30d4d0c8fb81/wal-000000032 (ops 154-158)
I20260812 06:19:30.616500 19397 log.cc:1079] T 8b14b884363e4aff866e30d4d0c8fb81 P 73ec120445a34bafba012ca0e25b5f66: Deleting log segment in path: /tmp/dist-test-tasky6MLcF/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515565329438-19282-0/minicluster-data/ts-0-root/wals/8b14b884363e4aff866e30d4d0c8fb81/wal-000000033 (ops 159-162)
I20260812 06:19:30.616523 19397 log.cc:1079] T 8b14b884363e4aff866e30d4d0c8fb81 P 73ec120445a34bafba012ca0e25b5f66: Deleting log segment in path: /tmp/dist-test-tasky6MLcF/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515565329438-19282-0/minicluster-data/ts-0-root/wals/8b14b884363e4aff866e30d4d0c8fb81/wal-000000034 (ops 163-167)
I20260812 06:19:30.616542 19397 log.cc:1079] T 8b14b884363e4aff866e30d4d0c8fb81 P 73ec120445a34bafba012ca0e25b5f66: Deleting log segment in path: /tmp/dist-test-tasky6MLcF/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515565329438-19282-0/minicluster-data/ts-0-root/wals/8b14b884363e4aff866e30d4d0c8fb81/wal-000000035 (ops 168-172)
I20260812 06:19:30.616564 19397 log.cc:1079] T 8b14b884363e4aff866e30d4d0c8fb81 P 73ec120445a34bafba012ca0e25b5f66: Deleting log segment in path: /tmp/dist-test-tasky6MLcF/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515565329438-19282-0/minicluster-data/ts-0-root/wals/8b14b884363e4aff866e30d4d0c8fb81/wal-000000036 (ops 173-177)
I20260812 06:19:30.616597 19397 log.cc:1079] T 8b14b884363e4aff866e30d4d0c8fb81 P 73ec120445a34bafba012ca0e25b5f66: Deleting log segment in path: /tmp/dist-test-tasky6MLcF/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515565329438-19282-0/minicluster-data/ts-0-root/wals/8b14b884363e4aff866e30d4d0c8fb81/wal-000000037 (ops 178-182)
I20260812 06:19:30.616621 19397 log.cc:1079] T 8b14b884363e4aff866e30d4d0c8fb81 P 73ec120445a34bafba012ca0e25b5f66: Deleting log segment in path: /tmp/dist-test-tasky6MLcF/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515565329438-19282-0/minicluster-data/ts-0-root/wals/8b14b884363e4aff866e30d4d0c8fb81/wal-000000038 (ops 183-187)
I20260812 06:19:30.616650 19397 log.cc:1079] T 8b14b884363e4aff866e30d4d0c8fb81 P 73ec120445a34bafba012ca0e25b5f66: Deleting log segment in path: /tmp/dist-test-tasky6MLcF/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515565329438-19282-0/minicluster-data/ts-0-root/wals/8b14b884363e4aff866e30d4d0c8fb81/wal-000000039 (ops 188-192)
I20260812 06:19:30.616679 19397 log.cc:1079] T 8b14b884363e4aff866e30d4d0c8fb81 P 73ec120445a34bafba012ca0e25b5f66: Deleting log segment in path: /tmp/dist-test-tasky6MLcF/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515565329438-19282-0/minicluster-data/ts-0-root/wals/8b14b884363e4aff866e30d4d0c8fb81/wal-000000040 (ops 193-197)
I20260812 06:19:30.655838 19397 maintenance_manager.cc:643] P 73ec120445a34bafba012ca0e25b5f66: LogGCOp(8b14b884363e4aff866e30d4d0c8fb81) complete. Timing: real 0.040s	user 0.000s	sys 0.039s Metrics: {}
I20260812 06:19:30.656589 19465 maintenance_manager.cc:419] P 73ec120445a34bafba012ca0e25b5f66: Scheduling UndoDeltaBlockGCOp(8b14b884363e4aff866e30d4d0c8fb81): 493 bytes on disk
I20260812 06:19:30.657080 19397 maintenance_manager.cc:643] P 73ec120445a34bafba012ca0e25b5f66: UndoDeltaBlockGCOp(8b14b884363e4aff866e30d4d0c8fb81) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":82,"lbm_reads_lt_1ms":4}
I20260812 06:19:30.657944 19465 maintenance_manager.cc:419] P 73ec120445a34bafba012ca0e25b5f66: Scheduling FlushDeltaMemStoresOp(8b14b884363e4aff866e30d4d0c8fb81): perf score=3.181125
I20260812 06:19:30.685330 19397 maintenance_manager.cc:643] P 73ec120445a34bafba012ca0e25b5f66: FlushDeltaMemStoresOp(8b14b884363e4aff866e30d4d0c8fb81) complete. Timing: real 0.027s	user 0.007s	sys 0.018s Metrics: {"bytes_written":4512900,"delete_count":0,"lbm_write_time_us":4752,"lbm_writes_lt_1ms":113,"reinsert_count":0,"update_count":550}
I20260812 06:19:30.685922 19465 maintenance_manager.cc:419] P 73ec120445a34bafba012ca0e25b5f66: Scheduling FlushDeltaMemStoresOp(8b14b884363e4aff866e30d4d0c8fb81): perf score=2.188937
I20260812 06:19:30.700873 19397 maintenance_manager.cc:643] P 73ec120445a34bafba012ca0e25b5f66: FlushDeltaMemStoresOp(8b14b884363e4aff866e30d4d0c8fb81) complete. Timing: real 0.015s	user 0.005s	sys 0.008s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":5685,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:19:30.701390 19465 maintenance_manager.cc:419] P 73ec120445a34bafba012ca0e25b5f66: Scheduling MajorDeltaCompactionOp(8b14b884363e4aff866e30d4d0c8fb81): perf score=1.000000
I20260812 06:19:30.756610 19282 heavy-update-compaction-itest.cc:229] Time spent updating: real 5.135s	user 1.921s	sys 0.125s
I20260812 06:19:30.878813 19282 heavy-update-compaction-itest.cc:265] Time spent scanning: real 0.122s	user 0.001s	sys 0.000s
I20260812 06:19:30.879521 19282 tablet_server.cc:179] TabletServer@127.18.212.129:0 shutting down...
I20260812 06:19:30.921937 19397 maintenance_manager.cc:643] P 73ec120445a34bafba012ca0e25b5f66: MajorDeltaCompactionOp(8b14b884363e4aff866e30d4d0c8fb81) complete. Timing: real 0.220s	user 0.157s	sys 0.064s Metrics: {"cfile_cache_miss":734,"cfile_cache_miss_bytes":32979748,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":442,"lbm_read_time_us":17488,"lbm_reads_lt_1ms":770,"lbm_write_time_us":34669,"lbm_writes_lt_1ms":743,"mutex_wait_us":54,"peak_mem_usage":87969044,"reinsert_count":0,"spinlock_wait_cycles":5888,"thread_start_us":87,"threads_started":1,"update_count":3500}
I20260812 06:19:30.922698 19282 ts_tablet_manager.cc:1507] Shutting down tablet manager...
I20260812 06:19:30.923188 19282 tablet_replica.cc:333] T 8b14b884363e4aff866e30d4d0c8fb81 P 73ec120445a34bafba012ca0e25b5f66: stopping tablet replica
I20260812 06:19:30.923476 19282 raft_consensus.cc:2243] T 8b14b884363e4aff866e30d4d0c8fb81 P 73ec120445a34bafba012ca0e25b5f66 [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:19:30.923734 19282 raft_consensus.cc:2272] T 8b14b884363e4aff866e30d4d0c8fb81 P 73ec120445a34bafba012ca0e25b5f66 [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:19:30.939935 19282 tablet_server.cc:196] TabletServer@127.18.212.129:0 shutdown complete.
I20260812 06:19:30.981578 19282 master.cc:562] Master@127.18.212.190:43381 shutting down...
I20260812 06:19:30.985942 19282 raft_consensus.cc:2243] T 00000000000000000000000000000000 P 5a666238ab684494aadfedbc11ff3a0b [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:19:30.986114 19282 raft_consensus.cc:2272] T 00000000000000000000000000000000 P 5a666238ab684494aadfedbc11ff3a0b [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:19:30.986167 19282 tablet_replica.cc:333] T 00000000000000000000000000000000 P 5a666238ab684494aadfedbc11ff3a0b: stopping tablet replica
I20260812 06:19:30.998530 19282 master.cc:584] Master@127.18.212.190:43381 shutdown complete.
[       OK ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/0 (5753 ms)
[ RUN      ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/1
I20260812 06:19:31.109019 19282 internal_mini_cluster.cc:156] Creating distributed mini masters. Addrs: 127.18.212.190:38643
I20260812 06:19:31.109400 19282 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:19:31.111927 19503 instance_detector.cc:116] could not retrieve OpenStack instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:19:31.111982 19501 instance_detector.cc:116] could not retrieve Azure instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:19:31.111950 19282 server_base.cc:1061] running on GCE node
W20260812 06:19:31.112207 19500 instance_detector.cc:116] could not retrieve AWS instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:19:31.112418 19282 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:19:31.112458 19282 system_unsync_time.cc:38] NTP support is disabled. Clock error bounds will not be accurate. This configuration is not suitable for distributed clusters.
I20260812 06:19:31.112473 19282 hybrid_clock.cc:648] HybridClock initialized: now 1786515571112473 us; error 0 us; skew 500 ppm
I20260812 06:19:31.113289 19282 webserver.cc:533] Webserver started at http://127.18.212.190:42871/ using document root <none> and password file <none>
I20260812 06:19:31.113445 19282 fs_manager.cc:362] Metadata directory not provided
I20260812 06:19:31.113489 19282 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:19:31.113543 19282 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:19:31.113879 19282 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-tasky6MLcF/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515565329438-19282-0/minicluster-data/master-0-root/instance:
uuid: "7aa9a2022dbe40eeba206bbf1b34d8e1"
format_stamp: "Formatted at 2026-08-12 06:19:31 on dist-test-slave-1xrh"
I20260812 06:19:31.115538 19282 fs_manager.cc:696] Time spent creating directory manager: real 0.001s	user 0.002s	sys 0.000s
I20260812 06:19:31.116523 19508 log_block_manager.cc:4127] Time spent loading block containers with low live blocks: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:19:31.116827 19282 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.001s	sys 0.000s
I20260812 06:19:31.116894 19282 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-tasky6MLcF/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515565329438-19282-0/minicluster-data/master-0-root
uuid: "7aa9a2022dbe40eeba206bbf1b34d8e1"
format_stamp: "Formatted at 2026-08-12 06:19:31 on dist-test-slave-1xrh"
I20260812 06:19:31.116946 19282 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-tasky6MLcF/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515565329438-19282-0/minicluster-data/master-0-root
metadata directory: /tmp/dist-test-tasky6MLcF/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515565329438-19282-0/minicluster-data/master-0-root
1 data directories: /tmp/dist-test-tasky6MLcF/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515565329438-19282-0/minicluster-data/master-0-root/data
Total live blocks: 0
Total live bytes: 0
Total live bytes (after alignment): 0
Total number of LBM containers: 0 (0 full)
Did not check for missing blocks
Did not check for orphaned blocks
Total full LBM containers with extra space: 0 (0 repaired)
Total full LBM container extra space in bytes: 0 (0 repaired)
Total incomplete LBM containers: 0 (0 repaired)
Total LBM partial records: 0 (0 repaired)
Total corrupted LBM metadata records in RocksDB: 0 (0 repaired)
I20260812 06:19:31.123893 19282 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:19:31.124178 19282 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:19:31.128031 19282 rpc_server.cc:307] RPC server started. Bound to: 127.18.212.190:38643
I20260812 06:19:31.131887 19566 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.18.212.190:38643 every 8 connection(s)
I20260812 06:19:31.133874 19569 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet 00000000000000000000000000000000. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:19:31.135731 19569 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P 7aa9a2022dbe40eeba206bbf1b34d8e1: Bootstrap starting.
I20260812 06:19:31.136534 19569 tablet_bootstrap.cc:654] T 00000000000000000000000000000000 P 7aa9a2022dbe40eeba206bbf1b34d8e1: Neither blocks nor log segments found. Creating new log.
I20260812 06:19:31.137535 19569 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P 7aa9a2022dbe40eeba206bbf1b34d8e1: No bootstrap required, opened a new log
I20260812 06:19:31.137908 19569 raft_consensus.cc:359] T 00000000000000000000000000000000 P 7aa9a2022dbe40eeba206bbf1b34d8e1 [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "7aa9a2022dbe40eeba206bbf1b34d8e1" member_type: VOTER }
I20260812 06:19:31.137991 19569 raft_consensus.cc:385] T 00000000000000000000000000000000 P 7aa9a2022dbe40eeba206bbf1b34d8e1 [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:19:31.138013 19569 raft_consensus.cc:740] T 00000000000000000000000000000000 P 7aa9a2022dbe40eeba206bbf1b34d8e1 [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: 7aa9a2022dbe40eeba206bbf1b34d8e1, State: Initialized, Role: FOLLOWER
I20260812 06:19:31.138175 19569 consensus_queue.cc:260] T 00000000000000000000000000000000 P 7aa9a2022dbe40eeba206bbf1b34d8e1 [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: "7aa9a2022dbe40eeba206bbf1b34d8e1" member_type: VOTER }
I20260812 06:19:31.138262 19569 raft_consensus.cc:399] T 00000000000000000000000000000000 P 7aa9a2022dbe40eeba206bbf1b34d8e1 [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:19:31.138288 19569 raft_consensus.cc:493] T 00000000000000000000000000000000 P 7aa9a2022dbe40eeba206bbf1b34d8e1 [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:19:31.138322 19569 raft_consensus.cc:3060] T 00000000000000000000000000000000 P 7aa9a2022dbe40eeba206bbf1b34d8e1 [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:19:31.138937 19569 raft_consensus.cc:515] T 00000000000000000000000000000000 P 7aa9a2022dbe40eeba206bbf1b34d8e1 [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "7aa9a2022dbe40eeba206bbf1b34d8e1" member_type: VOTER }
I20260812 06:19:31.139045 19569 leader_election.cc:304] T 00000000000000000000000000000000 P 7aa9a2022dbe40eeba206bbf1b34d8e1 [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: 7aa9a2022dbe40eeba206bbf1b34d8e1; no voters: 
I20260812 06:19:31.139272 19569 leader_election.cc:290] T 00000000000000000000000000000000 P 7aa9a2022dbe40eeba206bbf1b34d8e1 [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:19:31.139434 19572 raft_consensus.cc:2804] T 00000000000000000000000000000000 P 7aa9a2022dbe40eeba206bbf1b34d8e1 [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:19:31.139639 19572 raft_consensus.cc:697] T 00000000000000000000000000000000 P 7aa9a2022dbe40eeba206bbf1b34d8e1 [term 1 LEADER]: Becoming Leader. State: Replica: 7aa9a2022dbe40eeba206bbf1b34d8e1, State: Running, Role: LEADER
I20260812 06:19:31.139775 19572 consensus_queue.cc:237] T 00000000000000000000000000000000 P 7aa9a2022dbe40eeba206bbf1b34d8e1 [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: "7aa9a2022dbe40eeba206bbf1b34d8e1" member_type: VOTER }
I20260812 06:19:31.139874 19569 sys_catalog.cc:565] T 00000000000000000000000000000000 P 7aa9a2022dbe40eeba206bbf1b34d8e1 [sys.catalog]: configured and running, proceeding with master startup.
I20260812 06:19:31.140235 19573 sys_catalog.cc:455] T 00000000000000000000000000000000 P 7aa9a2022dbe40eeba206bbf1b34d8e1 [sys.catalog]: SysCatalogTable state changed. Reason: RaftConsensus started. Latest consensus state: current_term: 1 leader_uuid: "7aa9a2022dbe40eeba206bbf1b34d8e1" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "7aa9a2022dbe40eeba206bbf1b34d8e1" member_type: VOTER } }
I20260812 06:19:31.140262 19574 sys_catalog.cc:455] T 00000000000000000000000000000000 P 7aa9a2022dbe40eeba206bbf1b34d8e1 [sys.catalog]: SysCatalogTable state changed. Reason: New leader 7aa9a2022dbe40eeba206bbf1b34d8e1. Latest consensus state: current_term: 1 leader_uuid: "7aa9a2022dbe40eeba206bbf1b34d8e1" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "7aa9a2022dbe40eeba206bbf1b34d8e1" member_type: VOTER } }
I20260812 06:19:31.140323 19573 sys_catalog.cc:458] T 00000000000000000000000000000000 P 7aa9a2022dbe40eeba206bbf1b34d8e1 [sys.catalog]: This master's current role is: LEADER
I20260812 06:19:31.140345 19574 sys_catalog.cc:458] T 00000000000000000000000000000000 P 7aa9a2022dbe40eeba206bbf1b34d8e1 [sys.catalog]: This master's current role is: LEADER
I20260812 06:19:31.140583 19576 catalog_manager.cc:1511] Loading table and tablet metadata into memory...
I20260812 06:19:31.141372 19576 catalog_manager.cc:1520] Initializing Kudu cluster ID...
I20260812 06:19:31.141698 19282 internal_mini_cluster.cc:184] Waiting to initialize catalog manager on master 0
I20260812 06:19:31.143376 19576 catalog_manager.cc:1383] Generated new cluster ID: e1f5d9acf54749a9bddd0d45a150f5c0
I20260812 06:19:31.143442 19576 catalog_manager.cc:1531] Initializing Kudu internal certificate authority...
I20260812 06:19:31.151671 19576 catalog_manager.cc:1406] Generated new certificate authority record
I20260812 06:19:31.152184 19576 catalog_manager.cc:1540] Loading token signing keys...
I20260812 06:19:31.160475 19576 catalog_manager.cc:6092] T 00000000000000000000000000000000 P 7aa9a2022dbe40eeba206bbf1b34d8e1: Generated new TSK 0
I20260812 06:19:31.160638 19576 catalog_manager.cc:1550] Initializing in-progress tserver states...
I20260812 06:19:31.173925 19282 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:19:31.176016 19596 instance_detector.cc:116] could not retrieve AWS instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:19:31.176079 19282 server_base.cc:1061] running on GCE node
W20260812 06:19:31.176137 19599 instance_detector.cc:116] could not retrieve OpenStack instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:19:31.176019 19597 instance_detector.cc:116] could not retrieve Azure instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:19:31.176466 19282 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:19:31.176512 19282 system_unsync_time.cc:38] NTP support is disabled. Clock error bounds will not be accurate. This configuration is not suitable for distributed clusters.
I20260812 06:19:31.176527 19282 hybrid_clock.cc:648] HybridClock initialized: now 1786515571176527 us; error 0 us; skew 500 ppm
I20260812 06:19:31.177429 19282 webserver.cc:533] Webserver started at http://127.18.212.129:34923/ using document root <none> and password file <none>
I20260812 06:19:31.177691 19282 fs_manager.cc:362] Metadata directory not provided
I20260812 06:19:31.177752 19282 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:19:31.177839 19282 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:19:31.178256 19282 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-tasky6MLcF/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515565329438-19282-0/minicluster-data/ts-0-root/instance:
uuid: "3501e8b851634fdaaf2bd460964b3152"
format_stamp: "Formatted at 2026-08-12 06:19:31 on dist-test-slave-1xrh"
I20260812 06:19:31.179878 19282 fs_manager.cc:696] Time spent creating directory manager: real 0.001s	user 0.002s	sys 0.000s
I20260812 06:19:31.180792 19605 log_block_manager.cc:4127] Time spent loading block containers with low live blocks: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:19:31.181052 19282 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.001s	sys 0.000s
I20260812 06:19:31.181144 19282 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-tasky6MLcF/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515565329438-19282-0/minicluster-data/ts-0-root
uuid: "3501e8b851634fdaaf2bd460964b3152"
format_stamp: "Formatted at 2026-08-12 06:19:31 on dist-test-slave-1xrh"
I20260812 06:19:31.181229 19282 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-tasky6MLcF/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515565329438-19282-0/minicluster-data/ts-0-root
metadata directory: /tmp/dist-test-tasky6MLcF/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515565329438-19282-0/minicluster-data/ts-0-root
1 data directories: /tmp/dist-test-tasky6MLcF/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515565329438-19282-0/minicluster-data/ts-0-root/data
Total live blocks: 0
Total live bytes: 0
Total live bytes (after alignment): 0
Total number of LBM containers: 0 (0 full)
Did not check for missing blocks
Did not check for orphaned blocks
Total full LBM containers with extra space: 0 (0 repaired)
Total full LBM container extra space in bytes: 0 (0 repaired)
Total incomplete LBM containers: 0 (0 repaired)
Total LBM partial records: 0 (0 repaired)
Total corrupted LBM metadata records in RocksDB: 0 (0 repaired)
I20260812 06:19:31.192615 19282 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:19:31.192956 19282 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:19:31.193243 19282 txn_system_client.cc:432] TxnSystemClient initialization is disabled...
I20260812 06:19:31.193702 19282 ts_tablet_manager.cc:585] Loaded tablet metadata (0 total tablets, 0 live tablets)
I20260812 06:19:31.193763 19282 ts_tablet_manager.cc:531] Time spent load tablet metadata: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:19:31.193822 19282 ts_tablet_manager.cc:616] Registered 0 tablets
I20260812 06:19:31.193858 19282 ts_tablet_manager.cc:595] Time spent register tablets: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:19:31.198191 19282 rpc_server.cc:307] RPC server started. Bound to: 127.18.212.129:45505
I20260812 06:19:31.198729 19679 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.18.212.129:45505 every 8 connection(s)
I20260812 06:19:31.208590 19680 heartbeater.cc:344] Connected to a master server at 127.18.212.190:38643
I20260812 06:19:31.208709 19680 heartbeater.cc:461] Registering TS with master...
I20260812 06:19:31.208928 19680 heartbeater.cc:507] Master 127.18.212.190:38643 requested a full tablet report, sending...
I20260812 06:19:31.209587 19525 ts_manager.cc:194] Registered new tserver with Master: 3501e8b851634fdaaf2bd460964b3152 (127.18.212.129:45505)
I20260812 06:19:31.209861 19282 internal_mini_cluster.cc:371] 1 TS(s) registered with all masters after 0.011056272s
I20260812 06:19:31.210347 19525 master_service.cc:502] Signed X509 certificate for tserver {username='slave'} at 127.0.0.1:55322
I20260812 06:19:31.216809 19525 catalog_manager.cc:2283] Servicing CreateTable request from {username='slave'} at 127.0.0.1:55338:
name: "heavy-update-compaction-test"
schema {
  columns {
    name: "key"
    type: INT64
    is_key: true
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_a"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_b"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_c"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_d"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_e"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
}
num_replicas: 1
split_rows_range_bounds {
}
partition_schema {
  range_schema {
  }
}
I20260812 06:19:31.225771 19641 tablet_service.cc:1511] Processing CreateTablet for tablet 5f1f1b9d553c47f2a56b942ab6c2376e (DEFAULT_TABLE table=heavy-update-compaction-test [id=697961bae39140149c752ca4b86e1f21]), partition=
I20260812 06:19:31.225999 19641 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet 5f1f1b9d553c47f2a56b942ab6c2376e. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:19:31.227972 19695 tablet_bootstrap.cc:492] T 5f1f1b9d553c47f2a56b942ab6c2376e P 3501e8b851634fdaaf2bd460964b3152: Bootstrap starting.
I20260812 06:19:31.228772 19695 tablet_bootstrap.cc:654] T 5f1f1b9d553c47f2a56b942ab6c2376e P 3501e8b851634fdaaf2bd460964b3152: Neither blocks nor log segments found. Creating new log.
I20260812 06:19:31.229784 19695 tablet_bootstrap.cc:492] T 5f1f1b9d553c47f2a56b942ab6c2376e P 3501e8b851634fdaaf2bd460964b3152: No bootstrap required, opened a new log
I20260812 06:19:31.229875 19695 ts_tablet_manager.cc:1403] T 5f1f1b9d553c47f2a56b942ab6c2376e P 3501e8b851634fdaaf2bd460964b3152: Time spent bootstrapping tablet: real 0.002s	user 0.001s	sys 0.000s
I20260812 06:19:31.230301 19695 raft_consensus.cc:359] T 5f1f1b9d553c47f2a56b942ab6c2376e P 3501e8b851634fdaaf2bd460964b3152 [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "3501e8b851634fdaaf2bd460964b3152" member_type: VOTER last_known_addr { host: "127.18.212.129" port: 45505 } }
I20260812 06:19:31.230383 19695 raft_consensus.cc:385] T 5f1f1b9d553c47f2a56b942ab6c2376e P 3501e8b851634fdaaf2bd460964b3152 [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:19:31.230443 19695 raft_consensus.cc:740] T 5f1f1b9d553c47f2a56b942ab6c2376e P 3501e8b851634fdaaf2bd460964b3152 [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: 3501e8b851634fdaaf2bd460964b3152, State: Initialized, Role: FOLLOWER
I20260812 06:19:31.230588 19695 consensus_queue.cc:260] T 5f1f1b9d553c47f2a56b942ab6c2376e P 3501e8b851634fdaaf2bd460964b3152 [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: "3501e8b851634fdaaf2bd460964b3152" member_type: VOTER last_known_addr { host: "127.18.212.129" port: 45505 } }
I20260812 06:19:31.230684 19695 raft_consensus.cc:399] T 5f1f1b9d553c47f2a56b942ab6c2376e P 3501e8b851634fdaaf2bd460964b3152 [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:19:31.230739 19695 raft_consensus.cc:493] T 5f1f1b9d553c47f2a56b942ab6c2376e P 3501e8b851634fdaaf2bd460964b3152 [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:19:31.230792 19695 raft_consensus.cc:3060] T 5f1f1b9d553c47f2a56b942ab6c2376e P 3501e8b851634fdaaf2bd460964b3152 [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:19:31.231664 19695 raft_consensus.cc:515] T 5f1f1b9d553c47f2a56b942ab6c2376e P 3501e8b851634fdaaf2bd460964b3152 [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "3501e8b851634fdaaf2bd460964b3152" member_type: VOTER last_known_addr { host: "127.18.212.129" port: 45505 } }
I20260812 06:19:31.231786 19695 leader_election.cc:304] T 5f1f1b9d553c47f2a56b942ab6c2376e P 3501e8b851634fdaaf2bd460964b3152 [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: 3501e8b851634fdaaf2bd460964b3152; no voters: 
I20260812 06:19:31.231933 19695 leader_election.cc:290] T 5f1f1b9d553c47f2a56b942ab6c2376e P 3501e8b851634fdaaf2bd460964b3152 [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:19:31.232076 19698 raft_consensus.cc:2804] T 5f1f1b9d553c47f2a56b942ab6c2376e P 3501e8b851634fdaaf2bd460964b3152 [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:19:31.232234 19680 heartbeater.cc:499] Master 127.18.212.190:38643 was elected leader, sending a full tablet report...
I20260812 06:19:31.232288 19698 raft_consensus.cc:697] T 5f1f1b9d553c47f2a56b942ab6c2376e P 3501e8b851634fdaaf2bd460964b3152 [term 1 LEADER]: Becoming Leader. State: Replica: 3501e8b851634fdaaf2bd460964b3152, State: Running, Role: LEADER
I20260812 06:19:31.232523 19695 ts_tablet_manager.cc:1434] T 5f1f1b9d553c47f2a56b942ab6c2376e P 3501e8b851634fdaaf2bd460964b3152: Time spent starting tablet: real 0.003s	user 0.003s	sys 0.000s
I20260812 06:19:31.232510 19698 consensus_queue.cc:237] T 5f1f1b9d553c47f2a56b942ab6c2376e P 3501e8b851634fdaaf2bd460964b3152 [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: "3501e8b851634fdaaf2bd460964b3152" member_type: VOTER last_known_addr { host: "127.18.212.129" port: 45505 } }
I20260812 06:19:31.233800 19525 catalog_manager.cc:5719] T 5f1f1b9d553c47f2a56b942ab6c2376e P 3501e8b851634fdaaf2bd460964b3152 reported cstate change: term changed from 0 to 1, leader changed from <none> to 3501e8b851634fdaaf2bd460964b3152 (127.18.212.129). New cstate: current_term: 1 leader_uuid: "3501e8b851634fdaaf2bd460964b3152" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "3501e8b851634fdaaf2bd460964b3152" member_type: VOTER last_known_addr { host: "127.18.212.129" port: 45505 } health_report { overall_health: HEALTHY } } }
I20260812 06:19:31.294296 19282 heavy-update-compaction-itest.cc:215] Time spent inserting: real 0.053s	user 0.011s	sys 0.012s
I20260812 06:19:31.449366 19681 maintenance_manager.cc:419] P 3501e8b851634fdaaf2bd460964b3152: Scheduling FlushMRSOp(5f1f1b9d553c47f2a56b942ab6c2376e): perf score=19.054940
I20260812 06:19:31.602138 19613 maintenance_manager.cc:643] P 3501e8b851634fdaaf2bd460964b3152: FlushMRSOp(5f1f1b9d553c47f2a56b942ab6c2376e) complete. Timing: real 0.152s	user 0.106s	sys 0.043s Metrics: {"bytes_written":12307490,"cfile_init":1,"delete_count":0,"dirs.queue_time_us":65,"dirs.run_cpu_time_us":229,"dirs.run_wall_time_us":850,"drs_written":1,"lbm_read_time_us":35,"lbm_reads_lt_1ms":4,"lbm_write_time_us":36761,"lbm_writes_lt_1ms":757,"peak_mem_usage":0,"reinsert_count":0,"rows_written":104,"update_count":1500}
I20260812 06:19:31.602981 19681 maintenance_manager.cc:419] P 3501e8b851634fdaaf2bd460964b3152: Scheduling LogGCOp(5f1f1b9d553c47f2a56b942ab6c2376e): free 20743880 bytes of WAL
I20260812 06:19:31.603312 19613 log_reader.cc:385] T 5f1f1b9d553c47f2a56b942ab6c2376e: removed 2 log segments from log reader
I20260812 06:19:31.603379 19613 log.cc:1079] T 5f1f1b9d553c47f2a56b942ab6c2376e P 3501e8b851634fdaaf2bd460964b3152: Deleting log segment in path: /tmp/dist-test-tasky6MLcF/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515565329438-19282-0/minicluster-data/ts-0-root/wals/5f1f1b9d553c47f2a56b942ab6c2376e/wal-000000001 (ops 1-6)
I20260812 06:19:31.603425 19613 log.cc:1079] T 5f1f1b9d553c47f2a56b942ab6c2376e P 3501e8b851634fdaaf2bd460964b3152: Deleting log segment in path: /tmp/dist-test-tasky6MLcF/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515565329438-19282-0/minicluster-data/ts-0-root/wals/5f1f1b9d553c47f2a56b942ab6c2376e/wal-000000002 (ops 7-11)
I20260812 06:19:31.609632 19613 maintenance_manager.cc:643] P 3501e8b851634fdaaf2bd460964b3152: LogGCOp(5f1f1b9d553c47f2a56b942ab6c2376e) complete. Timing: real 0.006s	user 0.000s	sys 0.004s Metrics: {}
I20260812 06:19:31.610055 19681 maintenance_manager.cc:419] P 3501e8b851634fdaaf2bd460964b3152: Scheduling FlushDeltaMemStoresOp(5f1f1b9d553c47f2a56b942ab6c2376e): perf score=2.188937
I20260812 06:19:31.627476 19613 maintenance_manager.cc:643] P 3501e8b851634fdaaf2bd460964b3152: FlushDeltaMemStoresOp(5f1f1b9d553c47f2a56b942ab6c2376e) complete. Timing: real 0.017s	user 0.013s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6950,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:31.628036 19681 maintenance_manager.cc:419] P 3501e8b851634fdaaf2bd460964b3152: Scheduling MajorDeltaCompactionOp(5f1f1b9d553c47f2a56b942ab6c2376e): perf score=1.000000
I20260812 06:19:31.801736 19613 maintenance_manager.cc:643] P 3501e8b851634fdaaf2bd460964b3152: MajorDeltaCompactionOp(5f1f1b9d553c47f2a56b942ab6c2376e) complete. Timing: real 0.173s	user 0.102s	sys 0.072s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672277,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":690,"lbm_read_time_us":12187,"lbm_reads_lt_1ms":468,"lbm_write_time_us":30738,"lbm_writes_lt_1ms":443,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":2176,"thread_start_us":367,"threads_started":5,"update_count":2000}
I20260812 06:19:31.802505 19681 maintenance_manager.cc:419] P 3501e8b851634fdaaf2bd460964b3152: Scheduling FlushDeltaMemStoresOp(5f1f1b9d553c47f2a56b942ab6c2376e): perf score=10.126437
I20260812 06:19:31.836378 19613 maintenance_manager.cc:643] P 3501e8b851634fdaaf2bd460964b3152: FlushDeltaMemStoresOp(5f1f1b9d553c47f2a56b942ab6c2376e) complete. Timing: real 0.034s	user 0.017s	sys 0.015s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":14823,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:19:31.836899 19681 maintenance_manager.cc:419] P 3501e8b851634fdaaf2bd460964b3152: Scheduling UndoDeltaBlockGCOp(5f1f1b9d553c47f2a56b942ab6c2376e): 16411396 bytes on disk
I20260812 06:19:31.837306 19613 maintenance_manager.cc:643] P 3501e8b851634fdaaf2bd460964b3152: UndoDeltaBlockGCOp(5f1f1b9d553c47f2a56b942ab6c2376e) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":61,"lbm_reads_lt_1ms":4}
I20260812 06:19:31.837736 19681 maintenance_manager.cc:419] P 3501e8b851634fdaaf2bd460964b3152: Scheduling FlushDeltaMemStoresOp(5f1f1b9d553c47f2a56b942ab6c2376e): perf score=2.188937
I20260812 06:19:31.854194 19613 maintenance_manager.cc:643] P 3501e8b851634fdaaf2bd460964b3152: FlushDeltaMemStoresOp(5f1f1b9d553c47f2a56b942ab6c2376e) complete. Timing: real 0.016s	user 0.014s	sys 0.000s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":6371,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:31.854744 19681 maintenance_manager.cc:419] P 3501e8b851634fdaaf2bd460964b3152: Scheduling MajorDeltaCompactionOp(5f1f1b9d553c47f2a56b942ab6c2376e): perf score=1.000000
I20260812 06:19:32.015600 19613 maintenance_manager.cc:643] P 3501e8b851634fdaaf2bd460964b3152: MajorDeltaCompactionOp(5f1f1b9d553c47f2a56b942ab6c2376e) complete. Timing: real 0.161s	user 0.106s	sys 0.048s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672276,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":375,"lbm_read_time_us":9048,"lbm_reads_lt_1ms":464,"lbm_write_time_us":27550,"lbm_writes_lt_1ms":443,"mutex_wait_us":49,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":2432,"update_count":2000}
I20260812 06:19:32.016306 19681 maintenance_manager.cc:419] P 3501e8b851634fdaaf2bd460964b3152: Scheduling FlushDeltaMemStoresOp(5f1f1b9d553c47f2a56b942ab6c2376e): perf score=10.126437
I20260812 06:19:32.060966 19613 maintenance_manager.cc:643] P 3501e8b851634fdaaf2bd460964b3152: FlushDeltaMemStoresOp(5f1f1b9d553c47f2a56b942ab6c2376e) complete. Timing: real 0.044s	user 0.026s	sys 0.016s Metrics: {"bytes_written":12307491,"delete_count":0,"lbm_write_time_us":20885,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:19:32.061828 19681 maintenance_manager.cc:419] P 3501e8b851634fdaaf2bd460964b3152: Scheduling FlushDeltaMemStoresOp(5f1f1b9d553c47f2a56b942ab6c2376e): perf score=2.188937
I20260812 06:19:32.077142 19613 maintenance_manager.cc:643] P 3501e8b851634fdaaf2bd460964b3152: FlushDeltaMemStoresOp(5f1f1b9d553c47f2a56b942ab6c2376e) complete. Timing: real 0.015s	user 0.008s	sys 0.003s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4764,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:32.077689 19681 maintenance_manager.cc:419] P 3501e8b851634fdaaf2bd460964b3152: Scheduling MajorDeltaCompactionOp(5f1f1b9d553c47f2a56b942ab6c2376e): perf score=1.000000
I20260812 06:19:32.210814 19613 maintenance_manager.cc:643] P 3501e8b851634fdaaf2bd460964b3152: MajorDeltaCompactionOp(5f1f1b9d553c47f2a56b942ab6c2376e) complete. Timing: real 0.133s	user 0.105s	sys 0.028s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672278,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":1024,"lbm_read_time_us":9855,"lbm_reads_lt_1ms":464,"lbm_write_time_us":27068,"lbm_writes_lt_1ms":443,"mutex_wait_us":300,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":14848,"update_count":2000}
I20260812 06:19:32.211498 19681 maintenance_manager.cc:419] P 3501e8b851634fdaaf2bd460964b3152: Scheduling FlushDeltaMemStoresOp(5f1f1b9d553c47f2a56b942ab6c2376e): perf score=10.126437
I20260812 06:19:32.258466 19613 maintenance_manager.cc:643] P 3501e8b851634fdaaf2bd460964b3152: FlushDeltaMemStoresOp(5f1f1b9d553c47f2a56b942ab6c2376e) complete. Timing: real 0.047s	user 0.020s	sys 0.020s Metrics: {"bytes_written":12307492,"delete_count":0,"lbm_write_time_us":18556,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:19:32.258913 19681 maintenance_manager.cc:419] P 3501e8b851634fdaaf2bd460964b3152: Scheduling FlushDeltaMemStoresOp(5f1f1b9d553c47f2a56b942ab6c2376e): perf score=2.188937
I20260812 06:19:32.270080 19613 maintenance_manager.cc:643] P 3501e8b851634fdaaf2bd460964b3152: FlushDeltaMemStoresOp(5f1f1b9d553c47f2a56b942ab6c2376e) complete. Timing: real 0.011s	user 0.002s	sys 0.007s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4130,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:32.270776 19681 maintenance_manager.cc:419] P 3501e8b851634fdaaf2bd460964b3152: Scheduling MajorDeltaCompactionOp(5f1f1b9d553c47f2a56b942ab6c2376e): perf score=1.000000
I20260812 06:19:32.401705 19613 maintenance_manager.cc:643] P 3501e8b851634fdaaf2bd460964b3152: MajorDeltaCompactionOp(5f1f1b9d553c47f2a56b942ab6c2376e) complete. Timing: real 0.131s	user 0.099s	sys 0.031s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672279,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":713,"lbm_read_time_us":10300,"lbm_reads_lt_1ms":472,"lbm_write_time_us":25171,"lbm_writes_lt_1ms":443,"mutex_wait_us":61,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":28672,"update_count":2000}
I20260812 06:19:32.402443 19681 maintenance_manager.cc:419] P 3501e8b851634fdaaf2bd460964b3152: Scheduling FlushDeltaMemStoresOp(5f1f1b9d553c47f2a56b942ab6c2376e): perf score=10.126437
I20260812 06:19:32.456005 19613 maintenance_manager.cc:643] P 3501e8b851634fdaaf2bd460964b3152: FlushDeltaMemStoresOp(5f1f1b9d553c47f2a56b942ab6c2376e) complete. Timing: real 0.053s	user 0.024s	sys 0.026s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":17990,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:19:32.456508 19681 maintenance_manager.cc:419] P 3501e8b851634fdaaf2bd460964b3152: Scheduling FlushDeltaMemStoresOp(5f1f1b9d553c47f2a56b942ab6c2376e): perf score=2.188937
I20260812 06:19:32.467029 19613 maintenance_manager.cc:643] P 3501e8b851634fdaaf2bd460964b3152: FlushDeltaMemStoresOp(5f1f1b9d553c47f2a56b942ab6c2376e) complete. Timing: real 0.010s	user 0.005s	sys 0.004s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4227,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:32.467486 19681 maintenance_manager.cc:419] P 3501e8b851634fdaaf2bd460964b3152: Scheduling MajorDeltaCompactionOp(5f1f1b9d553c47f2a56b942ab6c2376e): perf score=1.000000
I20260812 06:19:32.619983 19613 maintenance_manager.cc:643] P 3501e8b851634fdaaf2bd460964b3152: MajorDeltaCompactionOp(5f1f1b9d553c47f2a56b942ab6c2376e) complete. Timing: real 0.152s	user 0.112s	sys 0.040s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672276,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":235,"lbm_read_time_us":11067,"lbm_reads_lt_1ms":472,"lbm_write_time_us":24992,"lbm_writes_lt_1ms":443,"mutex_wait_us":39,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":8064,"update_count":2000}
I20260812 06:19:32.620779 19681 maintenance_manager.cc:419] P 3501e8b851634fdaaf2bd460964b3152: Scheduling FlushDeltaMemStoresOp(5f1f1b9d553c47f2a56b942ab6c2376e): perf score=10.126437
I20260812 06:19:32.668468 19613 maintenance_manager.cc:643] P 3501e8b851634fdaaf2bd460964b3152: FlushDeltaMemStoresOp(5f1f1b9d553c47f2a56b942ab6c2376e) complete. Timing: real 0.047s	user 0.022s	sys 0.015s Metrics: {"bytes_written":12307493,"delete_count":0,"lbm_write_time_us":17296,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:19:32.668919 19681 maintenance_manager.cc:419] P 3501e8b851634fdaaf2bd460964b3152: Scheduling FlushDeltaMemStoresOp(5f1f1b9d553c47f2a56b942ab6c2376e): perf score=2.188937
I20260812 06:19:32.679859 19613 maintenance_manager.cc:643] P 3501e8b851634fdaaf2bd460964b3152: FlushDeltaMemStoresOp(5f1f1b9d553c47f2a56b942ab6c2376e) complete. Timing: real 0.011s	user 0.006s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4317,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:32.680641 19681 maintenance_manager.cc:419] P 3501e8b851634fdaaf2bd460964b3152: Scheduling MajorDeltaCompactionOp(5f1f1b9d553c47f2a56b942ab6c2376e): perf score=1.000000
I20260812 06:19:32.812856 19613 maintenance_manager.cc:643] P 3501e8b851634fdaaf2bd460964b3152: MajorDeltaCompactionOp(5f1f1b9d553c47f2a56b942ab6c2376e) complete. Timing: real 0.132s	user 0.096s	sys 0.036s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672280,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":672,"lbm_read_time_us":9268,"lbm_reads_lt_1ms":472,"lbm_write_time_us":26468,"lbm_writes_lt_1ms":443,"mutex_wait_us":299,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":11392,"update_count":2000}
I20260812 06:19:32.813604 19681 maintenance_manager.cc:419] P 3501e8b851634fdaaf2bd460964b3152: Scheduling FlushDeltaMemStoresOp(5f1f1b9d553c47f2a56b942ab6c2376e): perf score=10.126437
I20260812 06:19:32.852320 19613 maintenance_manager.cc:643] P 3501e8b851634fdaaf2bd460964b3152: FlushDeltaMemStoresOp(5f1f1b9d553c47f2a56b942ab6c2376e) complete. Timing: real 0.038s	user 0.022s	sys 0.011s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":15079,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:19:32.852800 19681 maintenance_manager.cc:419] P 3501e8b851634fdaaf2bd460964b3152: Scheduling FlushDeltaMemStoresOp(5f1f1b9d553c47f2a56b942ab6c2376e): perf score=2.188937
I20260812 06:19:32.862926 19613 maintenance_manager.cc:643] P 3501e8b851634fdaaf2bd460964b3152: FlushDeltaMemStoresOp(5f1f1b9d553c47f2a56b942ab6c2376e) complete. Timing: real 0.010s	user 0.004s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4159,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:32.863322 19681 maintenance_manager.cc:419] P 3501e8b851634fdaaf2bd460964b3152: Scheduling FlushMRSOp(5f1f1b9d553c47f2a56b942ab6c2376e): perf score=1.000000
I20260812 06:19:32.894125 19613 maintenance_manager.cc:643] P 3501e8b851634fdaaf2bd460964b3152: FlushMRSOp(5f1f1b9d553c47f2a56b942ab6c2376e) complete. Timing: real 0.031s	user 0.025s	sys 0.001s Metrics: {"bytes_written":1152508,"cfile_init":1,"dirs.queue_time_us":54,"dirs.run_cpu_time_us":239,"dirs.run_wall_time_us":1259,"drs_written":1,"lbm_read_time_us":79,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1565,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":28}
I20260812 06:19:32.894933 19681 maintenance_manager.cc:419] P 3501e8b851634fdaaf2bd460964b3152: Scheduling LogGCOp(5f1f1b9d553c47f2a56b942ab6c2376e): free 112692367 bytes of WAL
I20260812 06:19:32.895231 19613 log_reader.cc:385] T 5f1f1b9d553c47f2a56b942ab6c2376e: removed 11 log segments from log reader
I20260812 06:19:32.895289 19613 log.cc:1079] T 5f1f1b9d553c47f2a56b942ab6c2376e P 3501e8b851634fdaaf2bd460964b3152: Deleting log segment in path: /tmp/dist-test-tasky6MLcF/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515565329438-19282-0/minicluster-data/ts-0-root/wals/5f1f1b9d553c47f2a56b942ab6c2376e/wal-000000003 (ops 12-16)
I20260812 06:19:32.895329 19613 log.cc:1079] T 5f1f1b9d553c47f2a56b942ab6c2376e P 3501e8b851634fdaaf2bd460964b3152: Deleting log segment in path: /tmp/dist-test-tasky6MLcF/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515565329438-19282-0/minicluster-data/ts-0-root/wals/5f1f1b9d553c47f2a56b942ab6c2376e/wal-000000004 (ops 17-21)
I20260812 06:19:32.895356 19613 log.cc:1079] T 5f1f1b9d553c47f2a56b942ab6c2376e P 3501e8b851634fdaaf2bd460964b3152: Deleting log segment in path: /tmp/dist-test-tasky6MLcF/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515565329438-19282-0/minicluster-data/ts-0-root/wals/5f1f1b9d553c47f2a56b942ab6c2376e/wal-000000005 (ops 22-26)
I20260812 06:19:32.895385 19613 log.cc:1079] T 5f1f1b9d553c47f2a56b942ab6c2376e P 3501e8b851634fdaaf2bd460964b3152: Deleting log segment in path: /tmp/dist-test-tasky6MLcF/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515565329438-19282-0/minicluster-data/ts-0-root/wals/5f1f1b9d553c47f2a56b942ab6c2376e/wal-000000006 (ops 27-31)
I20260812 06:19:32.895406 19613 log.cc:1079] T 5f1f1b9d553c47f2a56b942ab6c2376e P 3501e8b851634fdaaf2bd460964b3152: Deleting log segment in path: /tmp/dist-test-tasky6MLcF/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515565329438-19282-0/minicluster-data/ts-0-root/wals/5f1f1b9d553c47f2a56b942ab6c2376e/wal-000000007 (ops 32-36)
I20260812 06:19:32.895445 19613 log.cc:1079] T 5f1f1b9d553c47f2a56b942ab6c2376e P 3501e8b851634fdaaf2bd460964b3152: Deleting log segment in path: /tmp/dist-test-tasky6MLcF/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515565329438-19282-0/minicluster-data/ts-0-root/wals/5f1f1b9d553c47f2a56b942ab6c2376e/wal-000000008 (ops 37-41)
I20260812 06:19:32.895471 19613 log.cc:1079] T 5f1f1b9d553c47f2a56b942ab6c2376e P 3501e8b851634fdaaf2bd460964b3152: Deleting log segment in path: /tmp/dist-test-tasky6MLcF/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515565329438-19282-0/minicluster-data/ts-0-root/wals/5f1f1b9d553c47f2a56b942ab6c2376e/wal-000000009 (ops 42-46)
I20260812 06:19:32.895498 19613 log.cc:1079] T 5f1f1b9d553c47f2a56b942ab6c2376e P 3501e8b851634fdaaf2bd460964b3152: Deleting log segment in path: /tmp/dist-test-tasky6MLcF/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515565329438-19282-0/minicluster-data/ts-0-root/wals/5f1f1b9d553c47f2a56b942ab6c2376e/wal-000000010 (ops 47-51)
I20260812 06:19:32.895529 19613 log.cc:1079] T 5f1f1b9d553c47f2a56b942ab6c2376e P 3501e8b851634fdaaf2bd460964b3152: Deleting log segment in path: /tmp/dist-test-tasky6MLcF/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515565329438-19282-0/minicluster-data/ts-0-root/wals/5f1f1b9d553c47f2a56b942ab6c2376e/wal-000000011 (ops 52-56)
I20260812 06:19:32.895551 19613 log.cc:1079] T 5f1f1b9d553c47f2a56b942ab6c2376e P 3501e8b851634fdaaf2bd460964b3152: Deleting log segment in path: /tmp/dist-test-tasky6MLcF/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515565329438-19282-0/minicluster-data/ts-0-root/wals/5f1f1b9d553c47f2a56b942ab6c2376e/wal-000000012 (ops 57-61)
I20260812 06:19:32.895581 19613 log.cc:1079] T 5f1f1b9d553c47f2a56b942ab6c2376e P 3501e8b851634fdaaf2bd460964b3152: Deleting log segment in path: /tmp/dist-test-tasky6MLcF/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515565329438-19282-0/minicluster-data/ts-0-root/wals/5f1f1b9d553c47f2a56b942ab6c2376e/wal-000000013 (ops 62-66)
I20260812 06:19:32.923803 19613 maintenance_manager.cc:643] P 3501e8b851634fdaaf2bd460964b3152: LogGCOp(5f1f1b9d553c47f2a56b942ab6c2376e) complete. Timing: real 0.029s	user 0.001s	sys 0.027s Metrics: {}
I20260812 06:19:32.924177 19681 maintenance_manager.cc:419] P 3501e8b851634fdaaf2bd460964b3152: Scheduling UndoDeltaBlockGCOp(5f1f1b9d553c47f2a56b942ab6c2376e): 447 bytes on disk
I20260812 06:19:32.924641 19613 maintenance_manager.cc:643] P 3501e8b851634fdaaf2bd460964b3152: UndoDeltaBlockGCOp(5f1f1b9d553c47f2a56b942ab6c2376e) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":51,"lbm_reads_lt_1ms":4}
I20260812 06:19:32.925180 19681 maintenance_manager.cc:419] P 3501e8b851634fdaaf2bd460964b3152: Scheduling FlushDeltaMemStoresOp(5f1f1b9d553c47f2a56b942ab6c2376e): perf score=2.188937
I20260812 06:19:32.946375 19613 maintenance_manager.cc:643] P 3501e8b851634fdaaf2bd460964b3152: FlushDeltaMemStoresOp(5f1f1b9d553c47f2a56b942ab6c2376e) complete. Timing: real 0.021s	user 0.005s	sys 0.009s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":6146,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:32.946776 19681 maintenance_manager.cc:419] P 3501e8b851634fdaaf2bd460964b3152: Scheduling FlushDeltaMemStoresOp(5f1f1b9d553c47f2a56b942ab6c2376e): perf score=2.188937
I20260812 06:19:32.957064 19613 maintenance_manager.cc:643] P 3501e8b851634fdaaf2bd460964b3152: FlushDeltaMemStoresOp(5f1f1b9d553c47f2a56b942ab6c2376e) complete. Timing: real 0.010s	user 0.002s	sys 0.007s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4199,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:32.957530 19681 maintenance_manager.cc:419] P 3501e8b851634fdaaf2bd460964b3152: Scheduling MajorDeltaCompactionOp(5f1f1b9d553c47f2a56b942ab6c2376e): perf score=1.000000
I20260812 06:19:33.131392 19613 maintenance_manager.cc:643] P 3501e8b851634fdaaf2bd460964b3152: MajorDeltaCompactionOp(5f1f1b9d553c47f2a56b942ab6c2376e) complete. Timing: real 0.174s	user 0.141s	sys 0.031s 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":1150,"lbm_read_time_us":13286,"lbm_reads_lt_1ms":674,"lbm_write_time_us":34246,"lbm_writes_lt_1ms":643,"mutex_wait_us":510,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":21120,"thread_start_us":77,"threads_started":1,"update_count":3000}
I20260812 06:19:33.132212 19681 maintenance_manager.cc:419] P 3501e8b851634fdaaf2bd460964b3152: Scheduling FlushDeltaMemStoresOp(5f1f1b9d553c47f2a56b942ab6c2376e): perf score=14.095187
I20260812 06:19:33.189906 19613 maintenance_manager.cc:643] P 3501e8b851634fdaaf2bd460964b3152: FlushDeltaMemStoresOp(5f1f1b9d553c47f2a56b942ab6c2376e) complete. Timing: real 0.057s	user 0.026s	sys 0.029s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":29000,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:33.190768 19681 maintenance_manager.cc:419] P 3501e8b851634fdaaf2bd460964b3152: Scheduling FlushDeltaMemStoresOp(5f1f1b9d553c47f2a56b942ab6c2376e): perf score=2.188937
I20260812 06:19:33.206907 19613 maintenance_manager.cc:643] P 3501e8b851634fdaaf2bd460964b3152: FlushDeltaMemStoresOp(5f1f1b9d553c47f2a56b942ab6c2376e) complete. Timing: real 0.016s	user 0.011s	sys 0.003s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5728,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:33.207487 19681 maintenance_manager.cc:419] P 3501e8b851634fdaaf2bd460964b3152: Scheduling MajorDeltaCompactionOp(5f1f1b9d553c47f2a56b942ab6c2376e): perf score=1.000000
I20260812 06:19:33.368351 19613 maintenance_manager.cc:643] P 3501e8b851634fdaaf2bd460964b3152: MajorDeltaCompactionOp(5f1f1b9d553c47f2a56b942ab6c2376e) complete. Timing: real 0.161s	user 0.116s	sys 0.044s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774688,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":246,"lbm_read_time_us":10248,"lbm_reads_lt_1ms":564,"lbm_write_time_us":30994,"lbm_writes_lt_1ms":543,"mutex_wait_us":21,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":7936,"update_count":2500}
I20260812 06:19:33.369046 19681 maintenance_manager.cc:419] P 3501e8b851634fdaaf2bd460964b3152: Scheduling FlushDeltaMemStoresOp(5f1f1b9d553c47f2a56b942ab6c2376e): perf score=14.095187
I20260812 06:19:33.411468 19613 maintenance_manager.cc:643] P 3501e8b851634fdaaf2bd460964b3152: FlushDeltaMemStoresOp(5f1f1b9d553c47f2a56b942ab6c2376e) complete. Timing: real 0.042s	user 0.034s	sys 0.008s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":19441,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:33.411936 19681 maintenance_manager.cc:419] P 3501e8b851634fdaaf2bd460964b3152: Scheduling MajorDeltaCompactionOp(5f1f1b9d553c47f2a56b942ab6c2376e): perf score=1.000000
I20260812 06:19:33.570894 19613 maintenance_manager.cc:643] P 3501e8b851634fdaaf2bd460964b3152: MajorDeltaCompactionOp(5f1f1b9d553c47f2a56b942ab6c2376e) complete. Timing: real 0.159s	user 0.113s	sys 0.045s Metrics: {"cfile_cache_miss":431,"cfile_cache_miss_bytes":20672157,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":1,"delta_iterators_relevant":1,"dirs.queue_time_us":1401,"lbm_read_time_us":11336,"lbm_reads_lt_1ms":467,"lbm_write_time_us":26352,"lbm_writes_lt_1ms":443,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":8064,"update_count":2000}
I20260812 06:19:33.572387 19681 maintenance_manager.cc:419] P 3501e8b851634fdaaf2bd460964b3152: Scheduling FlushDeltaMemStoresOp(5f1f1b9d553c47f2a56b942ab6c2376e): perf score=10.126437
I20260812 06:19:33.608340 19613 maintenance_manager.cc:643] P 3501e8b851634fdaaf2bd460964b3152: FlushDeltaMemStoresOp(5f1f1b9d553c47f2a56b942ab6c2376e) complete. Timing: real 0.036s	user 0.023s	sys 0.011s Metrics: {"bytes_written":12307491,"delete_count":0,"lbm_write_time_us":15646,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:19:33.608866 19681 maintenance_manager.cc:419] P 3501e8b851634fdaaf2bd460964b3152: Scheduling FlushDeltaMemStoresOp(5f1f1b9d553c47f2a56b942ab6c2376e): perf score=2.188937
I20260812 06:19:33.626147 19613 maintenance_manager.cc:643] P 3501e8b851634fdaaf2bd460964b3152: FlushDeltaMemStoresOp(5f1f1b9d553c47f2a56b942ab6c2376e) complete. Timing: real 0.017s	user 0.015s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6799,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:33.626617 19681 maintenance_manager.cc:419] P 3501e8b851634fdaaf2bd460964b3152: Scheduling MajorDeltaCompactionOp(5f1f1b9d553c47f2a56b942ab6c2376e): perf score=1.000000
I20260812 06:19:33.769798 19613 maintenance_manager.cc:643] P 3501e8b851634fdaaf2bd460964b3152: MajorDeltaCompactionOp(5f1f1b9d553c47f2a56b942ab6c2376e) complete. Timing: real 0.143s	user 0.110s	sys 0.033s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672278,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":319,"lbm_read_time_us":9294,"lbm_reads_lt_1ms":472,"lbm_write_time_us":28183,"lbm_writes_lt_1ms":443,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":1920,"update_count":2000}
I20260812 06:19:33.770686 19681 maintenance_manager.cc:419] P 3501e8b851634fdaaf2bd460964b3152: Scheduling FlushDeltaMemStoresOp(5f1f1b9d553c47f2a56b942ab6c2376e): perf score=10.126437
I20260812 06:19:33.817158 19613 maintenance_manager.cc:643] P 3501e8b851634fdaaf2bd460964b3152: FlushDeltaMemStoresOp(5f1f1b9d553c47f2a56b942ab6c2376e) complete. Timing: real 0.046s	user 0.028s	sys 0.013s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":18934,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:19:33.817623 19681 maintenance_manager.cc:419] P 3501e8b851634fdaaf2bd460964b3152: Scheduling FlushDeltaMemStoresOp(5f1f1b9d553c47f2a56b942ab6c2376e): perf score=2.188937
I20260812 06:19:33.828322 19613 maintenance_manager.cc:643] P 3501e8b851634fdaaf2bd460964b3152: FlushDeltaMemStoresOp(5f1f1b9d553c47f2a56b942ab6c2376e) complete. Timing: real 0.011s	user 0.000s	sys 0.009s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4114,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:33.829082 19681 maintenance_manager.cc:419] P 3501e8b851634fdaaf2bd460964b3152: Scheduling MajorDeltaCompactionOp(5f1f1b9d553c47f2a56b942ab6c2376e): perf score=1.000000
I20260812 06:19:33.957262 19613 maintenance_manager.cc:643] P 3501e8b851634fdaaf2bd460964b3152: MajorDeltaCompactionOp(5f1f1b9d553c47f2a56b942ab6c2376e) complete. Timing: real 0.128s	user 0.102s	sys 0.026s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672276,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":448,"lbm_read_time_us":9706,"lbm_reads_lt_1ms":472,"lbm_write_time_us":23566,"lbm_writes_lt_1ms":443,"mutex_wait_us":103,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":16256,"update_count":2000}
I20260812 06:19:33.958060 19681 maintenance_manager.cc:419] P 3501e8b851634fdaaf2bd460964b3152: Scheduling FlushDeltaMemStoresOp(5f1f1b9d553c47f2a56b942ab6c2376e): perf score=10.126437
I20260812 06:19:34.002790 19613 maintenance_manager.cc:643] P 3501e8b851634fdaaf2bd460964b3152: FlushDeltaMemStoresOp(5f1f1b9d553c47f2a56b942ab6c2376e) complete. Timing: real 0.045s	user 0.032s	sys 0.000s Metrics: {"bytes_written":12307489,"delete_count":0,"lbm_write_time_us":15974,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:19:34.003379 19681 maintenance_manager.cc:419] P 3501e8b851634fdaaf2bd460964b3152: Scheduling FlushDeltaMemStoresOp(5f1f1b9d553c47f2a56b942ab6c2376e): perf score=2.188937
I20260812 06:19:34.014465 19613 maintenance_manager.cc:643] P 3501e8b851634fdaaf2bd460964b3152: FlushDeltaMemStoresOp(5f1f1b9d553c47f2a56b942ab6c2376e) complete. Timing: real 0.011s	user 0.001s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4346,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:34.015548 19681 maintenance_manager.cc:419] P 3501e8b851634fdaaf2bd460964b3152: Scheduling MajorDeltaCompactionOp(5f1f1b9d553c47f2a56b942ab6c2376e): perf score=1.000000
I20260812 06:19:34.139783 19613 maintenance_manager.cc:643] P 3501e8b851634fdaaf2bd460964b3152: MajorDeltaCompactionOp(5f1f1b9d553c47f2a56b942ab6c2376e) complete. Timing: real 0.124s	user 0.090s	sys 0.033s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672276,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":493,"lbm_read_time_us":8685,"lbm_reads_lt_1ms":472,"lbm_write_time_us":23525,"lbm_writes_lt_1ms":443,"mutex_wait_us":29,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":29440,"update_count":2000}
I20260812 06:19:34.140556 19681 maintenance_manager.cc:419] P 3501e8b851634fdaaf2bd460964b3152: Scheduling FlushDeltaMemStoresOp(5f1f1b9d553c47f2a56b942ab6c2376e): perf score=10.126437
I20260812 06:19:34.191272 19613 maintenance_manager.cc:643] P 3501e8b851634fdaaf2bd460964b3152: FlushDeltaMemStoresOp(5f1f1b9d553c47f2a56b942ab6c2376e) complete. Timing: real 0.051s	user 0.022s	sys 0.027s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":16695,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:19:34.191890 19681 maintenance_manager.cc:419] P 3501e8b851634fdaaf2bd460964b3152: Scheduling FlushDeltaMemStoresOp(5f1f1b9d553c47f2a56b942ab6c2376e): perf score=2.188937
I20260812 06:19:34.208541 19613 maintenance_manager.cc:643] P 3501e8b851634fdaaf2bd460964b3152: FlushDeltaMemStoresOp(5f1f1b9d553c47f2a56b942ab6c2376e) complete. Timing: real 0.016s	user 0.014s	sys 0.001s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6291,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:34.209088 19681 maintenance_manager.cc:419] P 3501e8b851634fdaaf2bd460964b3152: Scheduling MajorDeltaCompactionOp(5f1f1b9d553c47f2a56b942ab6c2376e): perf score=1.000000
I20260812 06:19:34.356911 19613 maintenance_manager.cc:643] P 3501e8b851634fdaaf2bd460964b3152: MajorDeltaCompactionOp(5f1f1b9d553c47f2a56b942ab6c2376e) complete. Timing: real 0.148s	user 0.088s	sys 0.059s 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":886,"lbm_read_time_us":12840,"lbm_reads_lt_1ms":472,"lbm_write_time_us":23479,"lbm_writes_lt_1ms":443,"mutex_wait_us":302,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":11648,"update_count":2000}
I20260812 06:19:34.357710 19681 maintenance_manager.cc:419] P 3501e8b851634fdaaf2bd460964b3152: Scheduling FlushDeltaMemStoresOp(5f1f1b9d553c47f2a56b942ab6c2376e): perf score=10.126437
I20260812 06:19:34.397130 19613 maintenance_manager.cc:643] P 3501e8b851634fdaaf2bd460964b3152: FlushDeltaMemStoresOp(5f1f1b9d553c47f2a56b942ab6c2376e) complete. Timing: real 0.039s	user 0.016s	sys 0.018s Metrics: {"bytes_written":12307492,"delete_count":0,"lbm_write_time_us":16184,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:19:34.397608 19681 maintenance_manager.cc:419] P 3501e8b851634fdaaf2bd460964b3152: Scheduling FlushDeltaMemStoresOp(5f1f1b9d553c47f2a56b942ab6c2376e): perf score=2.188937
I20260812 06:19:34.408102 19613 maintenance_manager.cc:643] P 3501e8b851634fdaaf2bd460964b3152: FlushDeltaMemStoresOp(5f1f1b9d553c47f2a56b942ab6c2376e) complete. Timing: real 0.010s	user 0.005s	sys 0.005s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4180,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:34.408923 19681 maintenance_manager.cc:419] P 3501e8b851634fdaaf2bd460964b3152: Scheduling FlushMRSOp(5f1f1b9d553c47f2a56b942ab6c2376e): perf score=1.000000
I20260812 06:19:34.442858 19613 maintenance_manager.cc:643] P 3501e8b851634fdaaf2bd460964b3152: FlushMRSOp(5f1f1b9d553c47f2a56b942ab6c2376e) complete. Timing: real 0.034s	user 0.032s	sys 0.000s Metrics: {"bytes_written":1275449,"cfile_init":1,"dirs.queue_time_us":53,"dirs.run_cpu_time_us":169,"dirs.run_wall_time_us":1149,"drs_written":1,"lbm_read_time_us":38,"lbm_reads_lt_1ms":4,"lbm_write_time_us":2000,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":31}
I20260812 06:19:34.443774 19681 maintenance_manager.cc:419] P 3501e8b851634fdaaf2bd460964b3152: Scheduling LogGCOp(5f1f1b9d553c47f2a56b942ab6c2376e): free 124257241 bytes of WAL
I20260812 06:19:34.444070 19613 log_reader.cc:385] T 5f1f1b9d553c47f2a56b942ab6c2376e: removed 12 log segments from log reader
I20260812 06:19:34.444118 19613 log.cc:1079] T 5f1f1b9d553c47f2a56b942ab6c2376e P 3501e8b851634fdaaf2bd460964b3152: Deleting log segment in path: /tmp/dist-test-tasky6MLcF/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515565329438-19282-0/minicluster-data/ts-0-root/wals/5f1f1b9d553c47f2a56b942ab6c2376e/wal-000000014 (ops 67-70)
I20260812 06:19:34.444146 19613 log.cc:1079] T 5f1f1b9d553c47f2a56b942ab6c2376e P 3501e8b851634fdaaf2bd460964b3152: Deleting log segment in path: /tmp/dist-test-tasky6MLcF/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515565329438-19282-0/minicluster-data/ts-0-root/wals/5f1f1b9d553c47f2a56b942ab6c2376e/wal-000000015 (ops 71-75)
I20260812 06:19:34.444198 19613 log.cc:1079] T 5f1f1b9d553c47f2a56b942ab6c2376e P 3501e8b851634fdaaf2bd460964b3152: Deleting log segment in path: /tmp/dist-test-tasky6MLcF/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515565329438-19282-0/minicluster-data/ts-0-root/wals/5f1f1b9d553c47f2a56b942ab6c2376e/wal-000000016 (ops 76-80)
I20260812 06:19:34.444260 19613 log.cc:1079] T 5f1f1b9d553c47f2a56b942ab6c2376e P 3501e8b851634fdaaf2bd460964b3152: Deleting log segment in path: /tmp/dist-test-tasky6MLcF/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515565329438-19282-0/minicluster-data/ts-0-root/wals/5f1f1b9d553c47f2a56b942ab6c2376e/wal-000000017 (ops 81-85)
I20260812 06:19:34.444307 19613 log.cc:1079] T 5f1f1b9d553c47f2a56b942ab6c2376e P 3501e8b851634fdaaf2bd460964b3152: Deleting log segment in path: /tmp/dist-test-tasky6MLcF/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515565329438-19282-0/minicluster-data/ts-0-root/wals/5f1f1b9d553c47f2a56b942ab6c2376e/wal-000000018 (ops 86-90)
I20260812 06:19:34.444360 19613 log.cc:1079] T 5f1f1b9d553c47f2a56b942ab6c2376e P 3501e8b851634fdaaf2bd460964b3152: Deleting log segment in path: /tmp/dist-test-tasky6MLcF/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515565329438-19282-0/minicluster-data/ts-0-root/wals/5f1f1b9d553c47f2a56b942ab6c2376e/wal-000000019 (ops 91-95)
I20260812 06:19:34.444399 19613 log.cc:1079] T 5f1f1b9d553c47f2a56b942ab6c2376e P 3501e8b851634fdaaf2bd460964b3152: Deleting log segment in path: /tmp/dist-test-tasky6MLcF/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515565329438-19282-0/minicluster-data/ts-0-root/wals/5f1f1b9d553c47f2a56b942ab6c2376e/wal-000000020 (ops 96-100)
I20260812 06:19:34.444442 19613 log.cc:1079] T 5f1f1b9d553c47f2a56b942ab6c2376e P 3501e8b851634fdaaf2bd460964b3152: Deleting log segment in path: /tmp/dist-test-tasky6MLcF/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515565329438-19282-0/minicluster-data/ts-0-root/wals/5f1f1b9d553c47f2a56b942ab6c2376e/wal-000000021 (ops 101-105)
I20260812 06:19:34.444478 19613 log.cc:1079] T 5f1f1b9d553c47f2a56b942ab6c2376e P 3501e8b851634fdaaf2bd460964b3152: Deleting log segment in path: /tmp/dist-test-tasky6MLcF/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515565329438-19282-0/minicluster-data/ts-0-root/wals/5f1f1b9d553c47f2a56b942ab6c2376e/wal-000000022 (ops 106-110)
I20260812 06:19:34.444514 19613 log.cc:1079] T 5f1f1b9d553c47f2a56b942ab6c2376e P 3501e8b851634fdaaf2bd460964b3152: Deleting log segment in path: /tmp/dist-test-tasky6MLcF/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515565329438-19282-0/minicluster-data/ts-0-root/wals/5f1f1b9d553c47f2a56b942ab6c2376e/wal-000000023 (ops 111-115)
I20260812 06:19:34.444552 19613 log.cc:1079] T 5f1f1b9d553c47f2a56b942ab6c2376e P 3501e8b851634fdaaf2bd460964b3152: Deleting log segment in path: /tmp/dist-test-tasky6MLcF/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515565329438-19282-0/minicluster-data/ts-0-root/wals/5f1f1b9d553c47f2a56b942ab6c2376e/wal-000000024 (ops 116-120)
I20260812 06:19:34.444589 19613 log.cc:1079] T 5f1f1b9d553c47f2a56b942ab6c2376e P 3501e8b851634fdaaf2bd460964b3152: Deleting log segment in path: /tmp/dist-test-tasky6MLcF/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515565329438-19282-0/minicluster-data/ts-0-root/wals/5f1f1b9d553c47f2a56b942ab6c2376e/wal-000000025 (ops 121-125)
I20260812 06:19:34.473336 19613 maintenance_manager.cc:643] P 3501e8b851634fdaaf2bd460964b3152: LogGCOp(5f1f1b9d553c47f2a56b942ab6c2376e) complete. Timing: real 0.029s	user 0.000s	sys 0.027s Metrics: {}
I20260812 06:19:34.473817 19681 maintenance_manager.cc:419] P 3501e8b851634fdaaf2bd460964b3152: Scheduling FlushDeltaMemStoresOp(5f1f1b9d553c47f2a56b942ab6c2376e): perf score=3.181125
I20260812 06:19:34.501678 19613 maintenance_manager.cc:643] P 3501e8b851634fdaaf2bd460964b3152: FlushDeltaMemStoresOp(5f1f1b9d553c47f2a56b942ab6c2376e) complete. Timing: real 0.028s	user 0.012s	sys 0.013s Metrics: {"bytes_written":4512899,"delete_count":0,"lbm_write_time_us":7254,"lbm_writes_lt_1ms":113,"reinsert_count":0,"update_count":550}
I20260812 06:19:34.502132 19681 maintenance_manager.cc:419] P 3501e8b851634fdaaf2bd460964b3152: Scheduling LogGCOp(5f1f1b9d553c47f2a56b942ab6c2376e): free 12017940 bytes of WAL
I20260812 06:19:34.502342 19613 log_reader.cc:385] T 5f1f1b9d553c47f2a56b942ab6c2376e: removed 1 log segments from log reader
I20260812 06:19:34.502386 19613 log.cc:1079] T 5f1f1b9d553c47f2a56b942ab6c2376e P 3501e8b851634fdaaf2bd460964b3152: Deleting log segment in path: /tmp/dist-test-tasky6MLcF/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515565329438-19282-0/minicluster-data/ts-0-root/wals/5f1f1b9d553c47f2a56b942ab6c2376e/wal-000000026 (ops 126-130)
I20260812 06:19:34.504942 19613 maintenance_manager.cc:643] P 3501e8b851634fdaaf2bd460964b3152: LogGCOp(5f1f1b9d553c47f2a56b942ab6c2376e) complete. Timing: real 0.003s	user 0.000s	sys 0.001s Metrics: {}
I20260812 06:19:34.505249 19681 maintenance_manager.cc:419] P 3501e8b851634fdaaf2bd460964b3152: Scheduling FlushDeltaMemStoresOp(5f1f1b9d553c47f2a56b942ab6c2376e): perf score=2.188937
I20260812 06:19:34.514998 19613 maintenance_manager.cc:643] P 3501e8b851634fdaaf2bd460964b3152: FlushDeltaMemStoresOp(5f1f1b9d553c47f2a56b942ab6c2376e) complete. Timing: real 0.010s	user 0.003s	sys 0.005s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3822,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:19:34.515498 19681 maintenance_manager.cc:419] P 3501e8b851634fdaaf2bd460964b3152: Scheduling MajorDeltaCompactionOp(5f1f1b9d553c47f2a56b942ab6c2376e): perf score=1.000000
I20260812 06:19:34.724700 19613 maintenance_manager.cc:643] P 3501e8b851634fdaaf2bd460964b3152: MajorDeltaCompactionOp(5f1f1b9d553c47f2a56b942ab6c2376e) complete. Timing: real 0.209s	user 0.130s	sys 0.078s 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":875,"lbm_read_time_us":16041,"lbm_reads_lt_1ms":674,"lbm_write_time_us":36113,"lbm_writes_lt_1ms":643,"mutex_wait_us":19,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":13312,"thread_start_us":79,"threads_started":1,"update_count":3000}
I20260812 06:19:34.725409 19681 maintenance_manager.cc:419] P 3501e8b851634fdaaf2bd460964b3152: Scheduling FlushDeltaMemStoresOp(5f1f1b9d553c47f2a56b942ab6c2376e): perf score=14.095187
I20260812 06:19:34.786193 19613 maintenance_manager.cc:643] P 3501e8b851634fdaaf2bd460964b3152: FlushDeltaMemStoresOp(5f1f1b9d553c47f2a56b942ab6c2376e) complete. Timing: real 0.061s	user 0.031s	sys 0.023s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":20793,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:34.786751 19681 maintenance_manager.cc:419] P 3501e8b851634fdaaf2bd460964b3152: Scheduling FlushDeltaMemStoresOp(5f1f1b9d553c47f2a56b942ab6c2376e): perf score=2.188937
I20260812 06:19:34.797236 19613 maintenance_manager.cc:643] P 3501e8b851634fdaaf2bd460964b3152: FlushDeltaMemStoresOp(5f1f1b9d553c47f2a56b942ab6c2376e) complete. Timing: real 0.010s	user 0.009s	sys 0.000s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4070,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:34.797899 19681 maintenance_manager.cc:419] P 3501e8b851634fdaaf2bd460964b3152: Scheduling UndoDeltaBlockGCOp(5f1f1b9d553c47f2a56b942ab6c2376e): 483 bytes on disk
I20260812 06:19:34.798367 19613 maintenance_manager.cc:643] P 3501e8b851634fdaaf2bd460964b3152: UndoDeltaBlockGCOp(5f1f1b9d553c47f2a56b942ab6c2376e) 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:19:34.798863 19681 maintenance_manager.cc:419] P 3501e8b851634fdaaf2bd460964b3152: Scheduling MajorDeltaCompactionOp(5f1f1b9d553c47f2a56b942ab6c2376e): perf score=1.000000
I20260812 06:19:34.992244 19613 maintenance_manager.cc:643] P 3501e8b851634fdaaf2bd460964b3152: MajorDeltaCompactionOp(5f1f1b9d553c47f2a56b942ab6c2376e) complete. Timing: real 0.193s	user 0.114s	sys 0.079s 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":249,"lbm_read_time_us":14198,"lbm_reads_lt_1ms":572,"lbm_write_time_us":31867,"lbm_writes_lt_1ms":543,"mutex_wait_us":45,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":27392,"update_count":2500}
I20260812 06:19:34.992959 19681 maintenance_manager.cc:419] P 3501e8b851634fdaaf2bd460964b3152: Scheduling FlushDeltaMemStoresOp(5f1f1b9d553c47f2a56b942ab6c2376e): perf score=14.095187
I20260812 06:19:35.041693 19613 maintenance_manager.cc:643] P 3501e8b851634fdaaf2bd460964b3152: FlushDeltaMemStoresOp(5f1f1b9d553c47f2a56b942ab6c2376e) complete. Timing: real 0.049s	user 0.031s	sys 0.011s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":19008,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:35.042212 19681 maintenance_manager.cc:419] P 3501e8b851634fdaaf2bd460964b3152: Scheduling FlushDeltaMemStoresOp(5f1f1b9d553c47f2a56b942ab6c2376e): perf score=2.188937
I20260812 06:19:35.070547 19613 maintenance_manager.cc:643] P 3501e8b851634fdaaf2bd460964b3152: FlushDeltaMemStoresOp(5f1f1b9d553c47f2a56b942ab6c2376e) complete. Timing: real 0.028s	user 0.010s	sys 0.015s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5816,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:35.071198 19681 maintenance_manager.cc:419] P 3501e8b851634fdaaf2bd460964b3152: Scheduling MajorDeltaCompactionOp(5f1f1b9d553c47f2a56b942ab6c2376e): perf score=1.000000
I20260812 06:19:35.255527 19613 maintenance_manager.cc:643] P 3501e8b851634fdaaf2bd460964b3152: MajorDeltaCompactionOp(5f1f1b9d553c47f2a56b942ab6c2376e) complete. Timing: real 0.184s	user 0.102s	sys 0.081s 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":906,"lbm_read_time_us":13388,"lbm_reads_lt_1ms":572,"lbm_write_time_us":31318,"lbm_writes_lt_1ms":543,"mutex_wait_us":56,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":7424,"update_count":2500}
I20260812 06:19:35.256173 19681 maintenance_manager.cc:419] P 3501e8b851634fdaaf2bd460964b3152: Scheduling FlushDeltaMemStoresOp(5f1f1b9d553c47f2a56b942ab6c2376e): perf score=14.095187
I20260812 06:19:35.309615 19613 maintenance_manager.cc:643] P 3501e8b851634fdaaf2bd460964b3152: FlushDeltaMemStoresOp(5f1f1b9d553c47f2a56b942ab6c2376e) complete. Timing: real 0.053s	user 0.031s	sys 0.017s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":22527,"lbm_writes_lt_1ms":403,"reinsert_count":0,"spinlock_wait_cycles":896,"update_count":2000}
I20260812 06:19:35.310186 19681 maintenance_manager.cc:419] P 3501e8b851634fdaaf2bd460964b3152: Scheduling FlushDeltaMemStoresOp(5f1f1b9d553c47f2a56b942ab6c2376e): perf score=2.188937
I20260812 06:19:35.324994 19613 maintenance_manager.cc:643] P 3501e8b851634fdaaf2bd460964b3152: FlushDeltaMemStoresOp(5f1f1b9d553c47f2a56b942ab6c2376e) complete. Timing: real 0.015s	user 0.006s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5521,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:35.325651 19681 maintenance_manager.cc:419] P 3501e8b851634fdaaf2bd460964b3152: Scheduling MajorDeltaCompactionOp(5f1f1b9d553c47f2a56b942ab6c2376e): perf score=1.000000
I20260812 06:19:35.545105 19613 maintenance_manager.cc:643] P 3501e8b851634fdaaf2bd460964b3152: MajorDeltaCompactionOp(5f1f1b9d553c47f2a56b942ab6c2376e) complete. Timing: real 0.219s	user 0.139s	sys 0.072s 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":1321,"lbm_read_time_us":13421,"lbm_reads_lt_1ms":572,"lbm_write_time_us":38545,"lbm_writes_lt_1ms":543,"mutex_wait_us":409,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":7424,"update_count":2500}
I20260812 06:19:35.545881 19681 maintenance_manager.cc:419] P 3501e8b851634fdaaf2bd460964b3152: Scheduling FlushDeltaMemStoresOp(5f1f1b9d553c47f2a56b942ab6c2376e): perf score=14.095187
I20260812 06:19:35.602715 19613 maintenance_manager.cc:643] P 3501e8b851634fdaaf2bd460964b3152: FlushDeltaMemStoresOp(5f1f1b9d553c47f2a56b942ab6c2376e) complete. Timing: real 0.057s	user 0.032s	sys 0.019s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":25026,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:35.603363 19681 maintenance_manager.cc:419] P 3501e8b851634fdaaf2bd460964b3152: Scheduling FlushDeltaMemStoresOp(5f1f1b9d553c47f2a56b942ab6c2376e): perf score=2.188937
I20260812 06:19:35.615459 19613 maintenance_manager.cc:643] P 3501e8b851634fdaaf2bd460964b3152: FlushDeltaMemStoresOp(5f1f1b9d553c47f2a56b942ab6c2376e) complete. Timing: real 0.012s	user 0.007s	sys 0.004s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4400,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:35.615988 19681 maintenance_manager.cc:419] P 3501e8b851634fdaaf2bd460964b3152: Scheduling MajorDeltaCompactionOp(5f1f1b9d553c47f2a56b942ab6c2376e): perf score=1.000000
I20260812 06:19:35.775256 19613 maintenance_manager.cc:643] P 3501e8b851634fdaaf2bd460964b3152: MajorDeltaCompactionOp(5f1f1b9d553c47f2a56b942ab6c2376e) complete. Timing: real 0.159s	user 0.128s	sys 0.025s 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":621,"lbm_read_time_us":13354,"lbm_reads_lt_1ms":572,"lbm_write_time_us":30445,"lbm_writes_lt_1ms":543,"mutex_wait_us":37,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":2048,"update_count":2500}
I20260812 06:19:35.776073 19681 maintenance_manager.cc:419] P 3501e8b851634fdaaf2bd460964b3152: Scheduling FlushDeltaMemStoresOp(5f1f1b9d553c47f2a56b942ab6c2376e): perf score=14.095187
I20260812 06:19:35.830470 19613 maintenance_manager.cc:643] P 3501e8b851634fdaaf2bd460964b3152: FlushDeltaMemStoresOp(5f1f1b9d553c47f2a56b942ab6c2376e) complete. Timing: real 0.054s	user 0.033s	sys 0.017s Metrics: {"bytes_written":16409900,"delete_count":0,"lbm_write_time_us":26162,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:35.830999 19681 maintenance_manager.cc:419] P 3501e8b851634fdaaf2bd460964b3152: Scheduling FlushDeltaMemStoresOp(5f1f1b9d553c47f2a56b942ab6c2376e): perf score=2.188937
I20260812 06:19:35.843225 19613 maintenance_manager.cc:643] P 3501e8b851634fdaaf2bd460964b3152: FlushDeltaMemStoresOp(5f1f1b9d553c47f2a56b942ab6c2376e) complete. Timing: real 0.012s	user 0.001s	sys 0.011s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4465,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:35.843693 19681 maintenance_manager.cc:419] P 3501e8b851634fdaaf2bd460964b3152: Scheduling MajorDeltaCompactionOp(5f1f1b9d553c47f2a56b942ab6c2376e): perf score=1.000000
I20260812 06:19:36.009514 19613 maintenance_manager.cc:643] P 3501e8b851634fdaaf2bd460964b3152: MajorDeltaCompactionOp(5f1f1b9d553c47f2a56b942ab6c2376e) complete. Timing: real 0.166s	user 0.139s	sys 0.016s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774686,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":461,"lbm_read_time_us":11513,"lbm_reads_lt_1ms":572,"lbm_write_time_us":30633,"lbm_writes_lt_1ms":543,"mutex_wait_us":62,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":19328,"update_count":2500}
I20260812 06:19:36.010301 19681 maintenance_manager.cc:419] P 3501e8b851634fdaaf2bd460964b3152: Scheduling FlushDeltaMemStoresOp(5f1f1b9d553c47f2a56b942ab6c2376e): perf score=14.095187
I20260812 06:19:36.066989 19613 maintenance_manager.cc:643] P 3501e8b851634fdaaf2bd460964b3152: FlushDeltaMemStoresOp(5f1f1b9d553c47f2a56b942ab6c2376e) complete. Timing: real 0.057s	user 0.034s	sys 0.019s Metrics: {"bytes_written":16409900,"delete_count":0,"lbm_write_time_us":26888,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:36.067589 19681 maintenance_manager.cc:419] P 3501e8b851634fdaaf2bd460964b3152: Scheduling FlushDeltaMemStoresOp(5f1f1b9d553c47f2a56b942ab6c2376e): perf score=2.188937
I20260812 06:19:36.079751 19613 maintenance_manager.cc:643] P 3501e8b851634fdaaf2bd460964b3152: FlushDeltaMemStoresOp(5f1f1b9d553c47f2a56b942ab6c2376e) complete. Timing: real 0.012s	user 0.006s	sys 0.005s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4699,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:36.080220 19681 maintenance_manager.cc:419] P 3501e8b851634fdaaf2bd460964b3152: Scheduling FlushMRSOp(5f1f1b9d553c47f2a56b942ab6c2376e): perf score=1.000000
I20260812 06:19:36.112236 19613 maintenance_manager.cc:643] P 3501e8b851634fdaaf2bd460964b3152: FlushMRSOp(5f1f1b9d553c47f2a56b942ab6c2376e) complete. Timing: real 0.032s	user 0.027s	sys 0.004s Metrics: {"bytes_written":1316417,"cfile_init":1,"dirs.queue_time_us":69,"dirs.run_cpu_time_us":221,"dirs.run_wall_time_us":1147,"drs_written":1,"lbm_read_time_us":43,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1593,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":32}
I20260812 06:19:36.112905 19681 maintenance_manager.cc:419] P 3501e8b851634fdaaf2bd460964b3152: Scheduling LogGCOp(5f1f1b9d553c47f2a56b942ab6c2376e): free 121006640 bytes of WAL
I20260812 06:19:36.113150 19613 log_reader.cc:385] T 5f1f1b9d553c47f2a56b942ab6c2376e: removed 12 log segments from log reader
I20260812 06:19:36.113195 19613 log.cc:1079] T 5f1f1b9d553c47f2a56b942ab6c2376e P 3501e8b851634fdaaf2bd460964b3152: Deleting log segment in path: /tmp/dist-test-tasky6MLcF/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515565329438-19282-0/minicluster-data/ts-0-root/wals/5f1f1b9d553c47f2a56b942ab6c2376e/wal-000000027 (ops 131-135)
I20260812 06:19:36.113224 19613 log.cc:1079] T 5f1f1b9d553c47f2a56b942ab6c2376e P 3501e8b851634fdaaf2bd460964b3152: Deleting log segment in path: /tmp/dist-test-tasky6MLcF/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515565329438-19282-0/minicluster-data/ts-0-root/wals/5f1f1b9d553c47f2a56b942ab6c2376e/wal-000000028 (ops 136-140)
I20260812 06:19:36.113262 19613 log.cc:1079] T 5f1f1b9d553c47f2a56b942ab6c2376e P 3501e8b851634fdaaf2bd460964b3152: Deleting log segment in path: /tmp/dist-test-tasky6MLcF/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515565329438-19282-0/minicluster-data/ts-0-root/wals/5f1f1b9d553c47f2a56b942ab6c2376e/wal-000000029 (ops 141-145)
I20260812 06:19:36.113304 19613 log.cc:1079] T 5f1f1b9d553c47f2a56b942ab6c2376e P 3501e8b851634fdaaf2bd460964b3152: Deleting log segment in path: /tmp/dist-test-tasky6MLcF/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515565329438-19282-0/minicluster-data/ts-0-root/wals/5f1f1b9d553c47f2a56b942ab6c2376e/wal-000000030 (ops 146-150)
I20260812 06:19:36.113353 19613 log.cc:1079] T 5f1f1b9d553c47f2a56b942ab6c2376e P 3501e8b851634fdaaf2bd460964b3152: Deleting log segment in path: /tmp/dist-test-tasky6MLcF/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515565329438-19282-0/minicluster-data/ts-0-root/wals/5f1f1b9d553c47f2a56b942ab6c2376e/wal-000000031 (ops 151-154)
I20260812 06:19:36.113396 19613 log.cc:1079] T 5f1f1b9d553c47f2a56b942ab6c2376e P 3501e8b851634fdaaf2bd460964b3152: Deleting log segment in path: /tmp/dist-test-tasky6MLcF/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515565329438-19282-0/minicluster-data/ts-0-root/wals/5f1f1b9d553c47f2a56b942ab6c2376e/wal-000000032 (ops 155-159)
I20260812 06:19:36.113443 19613 log.cc:1079] T 5f1f1b9d553c47f2a56b942ab6c2376e P 3501e8b851634fdaaf2bd460964b3152: Deleting log segment in path: /tmp/dist-test-tasky6MLcF/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515565329438-19282-0/minicluster-data/ts-0-root/wals/5f1f1b9d553c47f2a56b942ab6c2376e/wal-000000033 (ops 160-164)
I20260812 06:19:36.113483 19613 log.cc:1079] T 5f1f1b9d553c47f2a56b942ab6c2376e P 3501e8b851634fdaaf2bd460964b3152: Deleting log segment in path: /tmp/dist-test-tasky6MLcF/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515565329438-19282-0/minicluster-data/ts-0-root/wals/5f1f1b9d553c47f2a56b942ab6c2376e/wal-000000034 (ops 165-169)
I20260812 06:19:36.113523 19613 log.cc:1079] T 5f1f1b9d553c47f2a56b942ab6c2376e P 3501e8b851634fdaaf2bd460964b3152: Deleting log segment in path: /tmp/dist-test-tasky6MLcF/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515565329438-19282-0/minicluster-data/ts-0-root/wals/5f1f1b9d553c47f2a56b942ab6c2376e/wal-000000035 (ops 170-174)
I20260812 06:19:36.113562 19613 log.cc:1079] T 5f1f1b9d553c47f2a56b942ab6c2376e P 3501e8b851634fdaaf2bd460964b3152: Deleting log segment in path: /tmp/dist-test-tasky6MLcF/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515565329438-19282-0/minicluster-data/ts-0-root/wals/5f1f1b9d553c47f2a56b942ab6c2376e/wal-000000036 (ops 175-179)
I20260812 06:19:36.113601 19613 log.cc:1079] T 5f1f1b9d553c47f2a56b942ab6c2376e P 3501e8b851634fdaaf2bd460964b3152: Deleting log segment in path: /tmp/dist-test-tasky6MLcF/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515565329438-19282-0/minicluster-data/ts-0-root/wals/5f1f1b9d553c47f2a56b942ab6c2376e/wal-000000037 (ops 180-184)
I20260812 06:19:36.113641 19613 log.cc:1079] T 5f1f1b9d553c47f2a56b942ab6c2376e P 3501e8b851634fdaaf2bd460964b3152: Deleting log segment in path: /tmp/dist-test-tasky6MLcF/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515565329438-19282-0/minicluster-data/ts-0-root/wals/5f1f1b9d553c47f2a56b942ab6c2376e/wal-000000038 (ops 185-189)
I20260812 06:19:36.144639 19613 maintenance_manager.cc:643] P 3501e8b851634fdaaf2bd460964b3152: LogGCOp(5f1f1b9d553c47f2a56b942ab6c2376e) complete. Timing: real 0.032s	user 0.000s	sys 0.030s Metrics: {}
I20260812 06:19:36.145231 19681 maintenance_manager.cc:419] P 3501e8b851634fdaaf2bd460964b3152: Scheduling UndoDeltaBlockGCOp(5f1f1b9d553c47f2a56b942ab6c2376e): 492 bytes on disk
I20260812 06:19:36.145752 19613 maintenance_manager.cc:643] P 3501e8b851634fdaaf2bd460964b3152: UndoDeltaBlockGCOp(5f1f1b9d553c47f2a56b942ab6c2376e) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":52,"lbm_reads_lt_1ms":4}
I20260812 06:19:36.146387 19681 maintenance_manager.cc:419] P 3501e8b851634fdaaf2bd460964b3152: Scheduling FlushDeltaMemStoresOp(5f1f1b9d553c47f2a56b942ab6c2376e): perf score=5.165500
I20260812 06:19:36.170058 19613 maintenance_manager.cc:643] P 3501e8b851634fdaaf2bd460964b3152: FlushDeltaMemStoresOp(5f1f1b9d553c47f2a56b942ab6c2376e) complete. Timing: real 0.023s	user 0.013s	sys 0.008s Metrics: {"bytes_written":7138449,"delete_count":0,"lbm_write_time_us":9840,"lbm_writes_lt_1ms":177,"reinsert_count":0,"update_count":870}
I20260812 06:19:36.170722 19681 maintenance_manager.cc:419] P 3501e8b851634fdaaf2bd460964b3152: Scheduling LogGCOp(5f1f1b9d553c47f2a56b942ab6c2376e): free 12018006 bytes of WAL
I20260812 06:19:36.171311 19613 log_reader.cc:385] T 5f1f1b9d553c47f2a56b942ab6c2376e: removed 1 log segments from log reader
I20260812 06:19:36.171440 19613 log.cc:1079] T 5f1f1b9d553c47f2a56b942ab6c2376e P 3501e8b851634fdaaf2bd460964b3152: Deleting log segment in path: /tmp/dist-test-tasky6MLcF/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515565329438-19282-0/minicluster-data/ts-0-root/wals/5f1f1b9d553c47f2a56b942ab6c2376e/wal-000000039 (ops 190-194)
I20260812 06:19:36.174330 19613 maintenance_manager.cc:643] P 3501e8b851634fdaaf2bd460964b3152: LogGCOp(5f1f1b9d553c47f2a56b942ab6c2376e) complete. Timing: real 0.003s	user 0.000s	sys 0.000s Metrics: {}
I20260812 06:19:36.174732 19681 maintenance_manager.cc:419] P 3501e8b851634fdaaf2bd460964b3152: Scheduling MajorDeltaCompactionOp(5f1f1b9d553c47f2a56b942ab6c2376e): perf score=1.000000
I20260812 06:19:36.292709 19282 heavy-update-compaction-itest.cc:229] Time spent updating: real 4.998s	user 1.891s	sys 0.137s
I20260812 06:19:36.353941 19613 maintenance_manager.cc:643] P 3501e8b851634fdaaf2bd460964b3152: MajorDeltaCompactionOp(5f1f1b9d553c47f2a56b942ab6c2376e) complete. Timing: real 0.179s	user 0.162s	sys 0.015s Metrics: {"cfile_cache_miss":707,"cfile_cache_miss_bytes":31913001,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"lbm_read_time_us":14443,"lbm_reads_lt_1ms":739,"lbm_write_time_us":37045,"lbm_writes_lt_1ms":717,"peak_mem_usage":84821366,"reinsert_count":0,"spinlock_wait_cycles":5376,"update_count":3370}
I20260812 06:19:36.354538 19681 maintenance_manager.cc:419] P 3501e8b851634fdaaf2bd460964b3152: Scheduling FlushDeltaMemStoresOp(5f1f1b9d553c47f2a56b942ab6c2376e): perf score=11.118625
I20260812 06:19:36.371694 19282 heavy-update-compaction-itest.cc:265] Time spent scanning: real 0.079s	user 0.002s	sys 0.000s
I20260812 06:19:36.372228 19282 tablet_server.cc:179] TabletServer@127.18.212.129:0 shutting down...
I20260812 06:19:36.391275 19613 maintenance_manager.cc:643] P 3501e8b851634fdaaf2bd460964b3152: FlushDeltaMemStoresOp(5f1f1b9d553c47f2a56b942ab6c2376e) complete. Timing: real 0.037s	user 0.021s	sys 0.015s Metrics: {"bytes_written":13374130,"delete_count":0,"lbm_write_time_us":16325,"lbm_writes_lt_1ms":329,"reinsert_count":0,"update_count":1630}
I20260812 06:19:36.391824 19282 ts_tablet_manager.cc:1507] Shutting down tablet manager...
I20260812 06:19:36.392071 19282 tablet_replica.cc:333] T 5f1f1b9d553c47f2a56b942ab6c2376e P 3501e8b851634fdaaf2bd460964b3152: stopping tablet replica
I20260812 06:19:36.392207 19282 raft_consensus.cc:2243] T 5f1f1b9d553c47f2a56b942ab6c2376e P 3501e8b851634fdaaf2bd460964b3152 [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:19:36.392380 19282 raft_consensus.cc:2272] T 5f1f1b9d553c47f2a56b942ab6c2376e P 3501e8b851634fdaaf2bd460964b3152 [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:19:36.405725 19282 tablet_server.cc:196] TabletServer@127.18.212.129:0 shutdown complete.
I20260812 06:19:36.415019 19282 master.cc:562] Master@127.18.212.190:38643 shutting down...
I20260812 06:19:36.418551 19282 raft_consensus.cc:2243] T 00000000000000000000000000000000 P 7aa9a2022dbe40eeba206bbf1b34d8e1 [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:19:36.418735 19282 raft_consensus.cc:2272] T 00000000000000000000000000000000 P 7aa9a2022dbe40eeba206bbf1b34d8e1 [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:19:36.418823 19282 tablet_replica.cc:333] T 00000000000000000000000000000000 P 7aa9a2022dbe40eeba206bbf1b34d8e1: stopping tablet replica
I20260812 06:19:36.431020 19282 master.cc:584] Master@127.18.212.190:38643 shutdown complete.
[       OK ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/1 (5429 ms)
[----------] 2 tests from EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy (11183 ms total)

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