[==========] 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:18:17.235844 25556 internal_mini_cluster.cc:156] Creating distributed mini masters. Addrs: 127.24.245.62:46861
I20260812 06:18:17.236907 25556 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:18:17.237593 25556 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:18:17.244310 25562 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:18:17.244367 25556 server_base.cc:1061] running on GCE node
W20260812 06:18:17.244310 25565 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:18:17.244568 25563 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:18:17.245134 25556 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:18:17.245227 25556 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:18:17.245252 25556 hybrid_clock.cc:648] HybridClock initialized: now 1786515497245251 us; error 0 us; skew 500 ppm
I20260812 06:18:17.247134 25556 webserver.cc:533] Webserver started at http://127.24.245.62:40605/ using document root <none> and password file <none>
I20260812 06:18:17.247663 25556 fs_manager.cc:362] Metadata directory not provided
I20260812 06:18:17.247721 25556 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:18:17.247923 25556 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:18:17.249701 25556 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskAaiyNc/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515497224838-25556-0/minicluster-data/master-0-root/instance:
uuid: "d9792771271741a48574d9d4b8e40e51"
format_stamp: "Formatted at 2026-08-12 06:18:17 on dist-test-slave-gsp7"
I20260812 06:18:17.253340 25556 fs_manager.cc:696] Time spent creating directory manager: real 0.003s	user 0.003s	sys 0.000s
I20260812 06:18:17.255591 25574 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:18:17.256652 25556 fs_manager.cc:730] Time spent opening block manager: real 0.002s	user 0.002s	sys 0.000s
I20260812 06:18:17.256793 25556 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskAaiyNc/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515497224838-25556-0/minicluster-data/master-0-root
uuid: "d9792771271741a48574d9d4b8e40e51"
format_stamp: "Formatted at 2026-08-12 06:18:17 on dist-test-slave-gsp7"
I20260812 06:18:17.256904 25556 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskAaiyNc/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515497224838-25556-0/minicluster-data/master-0-root
metadata directory: /tmp/dist-test-taskAaiyNc/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515497224838-25556-0/minicluster-data/master-0-root
1 data directories: /tmp/dist-test-taskAaiyNc/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515497224838-25556-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:18:17.268137 25556 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:18:17.268831 25556 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:18:17.269021 25556 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:18:17.277189 25556 rpc_server.cc:307] RPC server started. Bound to: 127.24.245.62:46861
I20260812 06:18:17.277194 25654 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.24.245.62:46861 every 8 connection(s)
I20260812 06:18:17.279605 25655 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:18:17.285281 25655 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P d9792771271741a48574d9d4b8e40e51: Bootstrap starting.
I20260812 06:18:17.287726 25655 tablet_bootstrap.cc:654] T 00000000000000000000000000000000 P d9792771271741a48574d9d4b8e40e51: Neither blocks nor log segments found. Creating new log.
I20260812 06:18:17.288722 25655 log.cc:826] T 00000000000000000000000000000000 P d9792771271741a48574d9d4b8e40e51: Log is configured to *not* fsync() on all Append() calls
I20260812 06:18:17.290526 25655 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P d9792771271741a48574d9d4b8e40e51: No bootstrap required, opened a new log
I20260812 06:18:17.293385 25655 raft_consensus.cc:359] T 00000000000000000000000000000000 P d9792771271741a48574d9d4b8e40e51 [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "d9792771271741a48574d9d4b8e40e51" member_type: VOTER }
I20260812 06:18:17.293630 25655 raft_consensus.cc:385] T 00000000000000000000000000000000 P d9792771271741a48574d9d4b8e40e51 [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:18:17.293754 25655 raft_consensus.cc:740] T 00000000000000000000000000000000 P d9792771271741a48574d9d4b8e40e51 [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: d9792771271741a48574d9d4b8e40e51, State: Initialized, Role: FOLLOWER
I20260812 06:18:17.294399 25655 consensus_queue.cc:260] T 00000000000000000000000000000000 P d9792771271741a48574d9d4b8e40e51 [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: "d9792771271741a48574d9d4b8e40e51" member_type: VOTER }
I20260812 06:18:17.294574 25655 raft_consensus.cc:399] T 00000000000000000000000000000000 P d9792771271741a48574d9d4b8e40e51 [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:18:17.294667 25655 raft_consensus.cc:493] T 00000000000000000000000000000000 P d9792771271741a48574d9d4b8e40e51 [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:18:17.294823 25655 raft_consensus.cc:3060] T 00000000000000000000000000000000 P d9792771271741a48574d9d4b8e40e51 [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:18:17.295680 25655 raft_consensus.cc:515] T 00000000000000000000000000000000 P d9792771271741a48574d9d4b8e40e51 [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "d9792771271741a48574d9d4b8e40e51" member_type: VOTER }
I20260812 06:18:17.296159 25655 leader_election.cc:304] T 00000000000000000000000000000000 P d9792771271741a48574d9d4b8e40e51 [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: d9792771271741a48574d9d4b8e40e51; no voters: 
I20260812 06:18:17.296500 25655 leader_election.cc:290] T 00000000000000000000000000000000 P d9792771271741a48574d9d4b8e40e51 [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:18:17.296656 25659 raft_consensus.cc:2804] T 00000000000000000000000000000000 P d9792771271741a48574d9d4b8e40e51 [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:18:17.296924 25659 raft_consensus.cc:697] T 00000000000000000000000000000000 P d9792771271741a48574d9d4b8e40e51 [term 1 LEADER]: Becoming Leader. State: Replica: d9792771271741a48574d9d4b8e40e51, State: Running, Role: LEADER
I20260812 06:18:17.297353 25659 consensus_queue.cc:237] T 00000000000000000000000000000000 P d9792771271741a48574d9d4b8e40e51 [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: "d9792771271741a48574d9d4b8e40e51" member_type: VOTER }
I20260812 06:18:17.297640 25655 sys_catalog.cc:565] T 00000000000000000000000000000000 P d9792771271741a48574d9d4b8e40e51 [sys.catalog]: configured and running, proceeding with master startup.
I20260812 06:18:17.299400 25660 sys_catalog.cc:455] T 00000000000000000000000000000000 P d9792771271741a48574d9d4b8e40e51 [sys.catalog]: SysCatalogTable state changed. Reason: RaftConsensus started. Latest consensus state: current_term: 1 leader_uuid: "d9792771271741a48574d9d4b8e40e51" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "d9792771271741a48574d9d4b8e40e51" member_type: VOTER } }
I20260812 06:18:17.299559 25660 sys_catalog.cc:458] T 00000000000000000000000000000000 P d9792771271741a48574d9d4b8e40e51 [sys.catalog]: This master's current role is: LEADER
I20260812 06:18:17.299400 25661 sys_catalog.cc:455] T 00000000000000000000000000000000 P d9792771271741a48574d9d4b8e40e51 [sys.catalog]: SysCatalogTable state changed. Reason: New leader d9792771271741a48574d9d4b8e40e51. Latest consensus state: current_term: 1 leader_uuid: "d9792771271741a48574d9d4b8e40e51" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "d9792771271741a48574d9d4b8e40e51" member_type: VOTER } }
I20260812 06:18:17.299831 25661 sys_catalog.cc:458] T 00000000000000000000000000000000 P d9792771271741a48574d9d4b8e40e51 [sys.catalog]: This master's current role is: LEADER
I20260812 06:18:17.299949 25687 catalog_manager.cc:1511] Loading table and tablet metadata into memory...
I20260812 06:18:17.299989 25556 internal_mini_cluster.cc:184] Waiting to initialize catalog manager on master 0
I20260812 06:18:17.302320 25687 catalog_manager.cc:1520] Initializing Kudu cluster ID...
I20260812 06:18:17.307435 25687 catalog_manager.cc:1383] Generated new cluster ID: b4151827e73b4a61a55db624069f65b9
I20260812 06:18:17.307520 25687 catalog_manager.cc:1531] Initializing Kudu internal certificate authority...
I20260812 06:18:17.317881 25687 catalog_manager.cc:1406] Generated new certificate authority record
I20260812 06:18:17.318790 25687 catalog_manager.cc:1540] Loading token signing keys...
I20260812 06:18:17.325963 25687 catalog_manager.cc:6092] T 00000000000000000000000000000000 P d9792771271741a48574d9d4b8e40e51: Generated new TSK 0
I20260812 06:18:17.326643 25687 catalog_manager.cc:1550] Initializing in-progress tserver states...
I20260812 06:18:17.332721 25556 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:18:17.335386 25704 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:18:17.335481 25702 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:18:17.335472 25708 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:18:17.335858 25556 server_base.cc:1061] running on GCE node
I20260812 06:18:17.336048 25556 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:18:17.336095 25556 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:18:17.336118 25556 hybrid_clock.cc:648] HybridClock initialized: now 1786515497336118 us; error 0 us; skew 500 ppm
I20260812 06:18:17.337085 25556 webserver.cc:533] Webserver started at http://127.24.245.1:44387/ using document root <none> and password file <none>
I20260812 06:18:17.337255 25556 fs_manager.cc:362] Metadata directory not provided
I20260812 06:18:17.337313 25556 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:18:17.337390 25556 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:18:17.337857 25556 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskAaiyNc/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515497224838-25556-0/minicluster-data/ts-0-root/instance:
uuid: "40519e5a9bf64e3f95c935153a6aafbf"
format_stamp: "Formatted at 2026-08-12 06:18:17 on dist-test-slave-gsp7"
I20260812 06:18:17.339730 25556 fs_manager.cc:696] Time spent creating directory manager: real 0.002s	user 0.000s	sys 0.002s
I20260812 06:18:17.340902 25714 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:18:17.341188 25556 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.001s	sys 0.000s
I20260812 06:18:17.341264 25556 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskAaiyNc/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515497224838-25556-0/minicluster-data/ts-0-root
uuid: "40519e5a9bf64e3f95c935153a6aafbf"
format_stamp: "Formatted at 2026-08-12 06:18:17 on dist-test-slave-gsp7"
I20260812 06:18:17.341364 25556 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskAaiyNc/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515497224838-25556-0/minicluster-data/ts-0-root
metadata directory: /tmp/dist-test-taskAaiyNc/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515497224838-25556-0/minicluster-data/ts-0-root
1 data directories: /tmp/dist-test-taskAaiyNc/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515497224838-25556-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:18:17.355412 25556 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:18:17.356134 25556 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:18:17.356642 25556 txn_system_client.cc:432] TxnSystemClient initialization is disabled...
I20260812 06:18:17.357656 25556 ts_tablet_manager.cc:585] Loaded tablet metadata (0 total tablets, 0 live tablets)
I20260812 06:18:17.357729 25556 ts_tablet_manager.cc:531] Time spent load tablet metadata: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:18:17.357808 25556 ts_tablet_manager.cc:616] Registered 0 tablets
I20260812 06:18:17.357859 25556 ts_tablet_manager.cc:595] Time spent register tablets: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:18:17.364751 25556 rpc_server.cc:307] RPC server started. Bound to: 127.24.245.1:44933
I20260812 06:18:17.364777 25818 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.24.245.1:44933 every 8 connection(s)
I20260812 06:18:17.375505 25820 heartbeater.cc:344] Connected to a master server at 127.24.245.62:46861
I20260812 06:18:17.375782 25820 heartbeater.cc:461] Registering TS with master...
I20260812 06:18:17.376235 25820 heartbeater.cc:507] Master 127.24.245.62:46861 requested a full tablet report, sending...
I20260812 06:18:17.377774 25604 ts_manager.cc:194] Registered new tserver with Master: 40519e5a9bf64e3f95c935153a6aafbf (127.24.245.1:44933)
I20260812 06:18:17.377878 25556 internal_mini_cluster.cc:371] 1 TS(s) registered with all masters after 0.012429675s
I20260812 06:18:17.379818 25604 master_service.cc:502] Signed X509 certificate for tserver {username='slave'} at 127.0.0.1:42890
I20260812 06:18:17.389231 25604 catalog_manager.cc:2283] Servicing CreateTable request from {username='slave'} at 127.0.0.1:42892:
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:18:17.406491 25760 tablet_service.cc:1511] Processing CreateTablet for tablet b960dda8db67439786cbcf73e0582013 (DEFAULT_TABLE table=heavy-update-compaction-test [id=20cdf61a6eea4392804571fc8b02c936]), partition=
I20260812 06:18:17.406977 25760 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet b960dda8db67439786cbcf73e0582013. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:18:17.409243 25840 tablet_bootstrap.cc:492] T b960dda8db67439786cbcf73e0582013 P 40519e5a9bf64e3f95c935153a6aafbf: Bootstrap starting.
I20260812 06:18:17.410270 25840 tablet_bootstrap.cc:654] T b960dda8db67439786cbcf73e0582013 P 40519e5a9bf64e3f95c935153a6aafbf: Neither blocks nor log segments found. Creating new log.
I20260812 06:18:17.411439 25840 tablet_bootstrap.cc:492] T b960dda8db67439786cbcf73e0582013 P 40519e5a9bf64e3f95c935153a6aafbf: No bootstrap required, opened a new log
I20260812 06:18:17.411558 25840 ts_tablet_manager.cc:1403] T b960dda8db67439786cbcf73e0582013 P 40519e5a9bf64e3f95c935153a6aafbf: Time spent bootstrapping tablet: real 0.002s	user 0.002s	sys 0.000s
I20260812 06:18:17.412168 25840 raft_consensus.cc:359] T b960dda8db67439786cbcf73e0582013 P 40519e5a9bf64e3f95c935153a6aafbf [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "40519e5a9bf64e3f95c935153a6aafbf" member_type: VOTER last_known_addr { host: "127.24.245.1" port: 44933 } }
I20260812 06:18:17.412308 25840 raft_consensus.cc:385] T b960dda8db67439786cbcf73e0582013 P 40519e5a9bf64e3f95c935153a6aafbf [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:18:17.412346 25840 raft_consensus.cc:740] T b960dda8db67439786cbcf73e0582013 P 40519e5a9bf64e3f95c935153a6aafbf [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: 40519e5a9bf64e3f95c935153a6aafbf, State: Initialized, Role: FOLLOWER
I20260812 06:18:17.412528 25840 consensus_queue.cc:260] T b960dda8db67439786cbcf73e0582013 P 40519e5a9bf64e3f95c935153a6aafbf [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: "40519e5a9bf64e3f95c935153a6aafbf" member_type: VOTER last_known_addr { host: "127.24.245.1" port: 44933 } }
I20260812 06:18:17.412674 25840 raft_consensus.cc:399] T b960dda8db67439786cbcf73e0582013 P 40519e5a9bf64e3f95c935153a6aafbf [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:18:17.412726 25840 raft_consensus.cc:493] T b960dda8db67439786cbcf73e0582013 P 40519e5a9bf64e3f95c935153a6aafbf [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:18:17.412791 25840 raft_consensus.cc:3060] T b960dda8db67439786cbcf73e0582013 P 40519e5a9bf64e3f95c935153a6aafbf [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:18:17.413631 25840 raft_consensus.cc:515] T b960dda8db67439786cbcf73e0582013 P 40519e5a9bf64e3f95c935153a6aafbf [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "40519e5a9bf64e3f95c935153a6aafbf" member_type: VOTER last_known_addr { host: "127.24.245.1" port: 44933 } }
I20260812 06:18:17.413794 25840 leader_election.cc:304] T b960dda8db67439786cbcf73e0582013 P 40519e5a9bf64e3f95c935153a6aafbf [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: 40519e5a9bf64e3f95c935153a6aafbf; no voters: 
I20260812 06:18:17.414047 25840 leader_election.cc:290] T b960dda8db67439786cbcf73e0582013 P 40519e5a9bf64e3f95c935153a6aafbf [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:18:17.414419 25845 raft_consensus.cc:2804] T b960dda8db67439786cbcf73e0582013 P 40519e5a9bf64e3f95c935153a6aafbf [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:18:17.414425 25840 ts_tablet_manager.cc:1434] T b960dda8db67439786cbcf73e0582013 P 40519e5a9bf64e3f95c935153a6aafbf: Time spent starting tablet: real 0.003s	user 0.001s	sys 0.002s
I20260812 06:18:17.414669 25820 heartbeater.cc:499] Master 127.24.245.62:46861 was elected leader, sending a full tablet report...
I20260812 06:18:17.414687 25845 raft_consensus.cc:697] T b960dda8db67439786cbcf73e0582013 P 40519e5a9bf64e3f95c935153a6aafbf [term 1 LEADER]: Becoming Leader. State: Replica: 40519e5a9bf64e3f95c935153a6aafbf, State: Running, Role: LEADER
I20260812 06:18:17.414872 25845 consensus_queue.cc:237] T b960dda8db67439786cbcf73e0582013 P 40519e5a9bf64e3f95c935153a6aafbf [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: "40519e5a9bf64e3f95c935153a6aafbf" member_type: VOTER last_known_addr { host: "127.24.245.1" port: 44933 } }
I20260812 06:18:17.417956 25604 catalog_manager.cc:5719] T b960dda8db67439786cbcf73e0582013 P 40519e5a9bf64e3f95c935153a6aafbf reported cstate change: term changed from 0 to 1, leader changed from <none> to 40519e5a9bf64e3f95c935153a6aafbf (127.24.245.1). New cstate: current_term: 1 leader_uuid: "40519e5a9bf64e3f95c935153a6aafbf" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "40519e5a9bf64e3f95c935153a6aafbf" member_type: VOTER last_known_addr { host: "127.24.245.1" port: 44933 } health_report { overall_health: HEALTHY } } }
I20260812 06:18:17.491009 25556 heavy-update-compaction-itest.cc:215] Time spent inserting: real 0.065s	user 0.015s	sys 0.016s
I20260812 06:18:17.615945 25821 maintenance_manager.cc:419] P 40519e5a9bf64e3f95c935153a6aafbf: Scheduling FlushMRSOp(b960dda8db67439786cbcf73e0582013): perf score=15.086190
I20260812 06:18:17.784740 25723 maintenance_manager.cc:643] P 40519e5a9bf64e3f95c935153a6aafbf: FlushMRSOp(b960dda8db67439786cbcf73e0582013) complete. Timing: real 0.168s	user 0.130s	sys 0.032s Metrics: {"bytes_written":12307492,"cfile_init":1,"compiler_manager_pool.queue_time_us":204,"delete_count":0,"dirs.queue_time_us":2717,"dirs.run_cpu_time_us":255,"dirs.run_wall_time_us":877,"drs_written":1,"lbm_read_time_us":92,"lbm_reads_lt_1ms":4,"lbm_write_time_us":37414,"lbm_writes_lt_1ms":667,"peak_mem_usage":0,"reinsert_count":0,"rows_written":104,"thread_start_us":132,"threads_started":1,"update_count":1500}
I20260812 06:18:17.786156 25821 maintenance_manager.cc:419] P 40519e5a9bf64e3f95c935153a6aafbf: Scheduling LogGCOp(b960dda8db67439786cbcf73e0582013): free 20743880 bytes of WAL
I20260812 06:18:17.786571 25723 log_reader.cc:385] T b960dda8db67439786cbcf73e0582013: removed 2 log segments from log reader
I20260812 06:18:17.786659 25723 log.cc:1079] T b960dda8db67439786cbcf73e0582013 P 40519e5a9bf64e3f95c935153a6aafbf: Deleting log segment in path: /tmp/dist-test-taskAaiyNc/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515497224838-25556-0/minicluster-data/ts-0-root/wals/b960dda8db67439786cbcf73e0582013/wal-000000001 (ops 1-6)
I20260812 06:18:17.786736 25723 log.cc:1079] T b960dda8db67439786cbcf73e0582013 P 40519e5a9bf64e3f95c935153a6aafbf: Deleting log segment in path: /tmp/dist-test-taskAaiyNc/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515497224838-25556-0/minicluster-data/ts-0-root/wals/b960dda8db67439786cbcf73e0582013/wal-000000002 (ops 7-11)
I20260812 06:18:17.792398 25723 maintenance_manager.cc:643] P 40519e5a9bf64e3f95c935153a6aafbf: LogGCOp(b960dda8db67439786cbcf73e0582013) complete. Timing: real 0.006s	user 0.000s	sys 0.003s Metrics: {}
I20260812 06:18:17.792829 25821 maintenance_manager.cc:419] P 40519e5a9bf64e3f95c935153a6aafbf: Scheduling UndoDeltaBlockGCOp(b960dda8db67439786cbcf73e0582013): 12719214 bytes on disk
I20260812 06:18:17.793660 25723 maintenance_manager.cc:643] P 40519e5a9bf64e3f95c935153a6aafbf: UndoDeltaBlockGCOp(b960dda8db67439786cbcf73e0582013) complete. Timing: real 0.001s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":71,"lbm_reads_lt_1ms":4}
I20260812 06:18:17.794130 25821 maintenance_manager.cc:419] P 40519e5a9bf64e3f95c935153a6aafbf: Scheduling FlushDeltaMemStoresOp(b960dda8db67439786cbcf73e0582013): perf score=2.188937
I20260812 06:18:17.817356 25723 maintenance_manager.cc:643] P 40519e5a9bf64e3f95c935153a6aafbf: FlushDeltaMemStoresOp(b960dda8db67439786cbcf73e0582013) complete. Timing: real 0.023s	user 0.005s	sys 0.007s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5603,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:17.817821 25821 maintenance_manager.cc:419] P 40519e5a9bf64e3f95c935153a6aafbf: Scheduling FlushDeltaMemStoresOp(b960dda8db67439786cbcf73e0582013): perf score=2.188937
I20260812 06:18:17.831180 25723 maintenance_manager.cc:643] P 40519e5a9bf64e3f95c935153a6aafbf: FlushDeltaMemStoresOp(b960dda8db67439786cbcf73e0582013) complete. Timing: real 0.013s	user 0.007s	sys 0.004s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":5076,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:18:17.831679 25821 maintenance_manager.cc:419] P 40519e5a9bf64e3f95c935153a6aafbf: Scheduling MajorDeltaCompactionOp(b960dda8db67439786cbcf73e0582013): perf score=1.000000
I20260812 06:18:17.988298 25723 maintenance_manager.cc:643] P 40519e5a9bf64e3f95c935153a6aafbf: MajorDeltaCompactionOp(b960dda8db67439786cbcf73e0582013) complete. Timing: real 0.156s	user 0.106s	sys 0.049s Metrics: {"cfile_cache_miss":523,"cfile_cache_miss_bytes":24364556,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":1025,"lbm_read_time_us":10570,"lbm_reads_lt_1ms":559,"lbm_write_time_us":27784,"lbm_writes_lt_1ms":533,"mutex_wait_us":1,"peak_mem_usage":61665166,"reinsert_count":0,"spinlock_wait_cycles":2816,"thread_start_us":410,"threads_started":5,"update_count":2450}
I20260812 06:18:17.989113 25821 maintenance_manager.cc:419] P 40519e5a9bf64e3f95c935153a6aafbf: Scheduling FlushDeltaMemStoresOp(b960dda8db67439786cbcf73e0582013): perf score=10.126437
I20260812 06:18:18.029778 25723 maintenance_manager.cc:643] P 40519e5a9bf64e3f95c935153a6aafbf: FlushDeltaMemStoresOp(b960dda8db67439786cbcf73e0582013) complete. Timing: real 0.040s	user 0.021s	sys 0.019s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":17959,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:18:18.030258 25821 maintenance_manager.cc:419] P 40519e5a9bf64e3f95c935153a6aafbf: Scheduling FlushDeltaMemStoresOp(b960dda8db67439786cbcf73e0582013): perf score=2.188937
I20260812 06:18:18.040993 25723 maintenance_manager.cc:643] P 40519e5a9bf64e3f95c935153a6aafbf: FlushDeltaMemStoresOp(b960dda8db67439786cbcf73e0582013) complete. Timing: real 0.011s	user 0.009s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3939,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:18.041541 25821 maintenance_manager.cc:419] P 40519e5a9bf64e3f95c935153a6aafbf: Scheduling MajorDeltaCompactionOp(b960dda8db67439786cbcf73e0582013): perf score=1.000000
I20260812 06:18:18.162376 25723 maintenance_manager.cc:643] P 40519e5a9bf64e3f95c935153a6aafbf: MajorDeltaCompactionOp(b960dda8db67439786cbcf73e0582013) complete. Timing: real 0.121s	user 0.092s	sys 0.028s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672277,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":333,"lbm_read_time_us":8775,"lbm_reads_lt_1ms":472,"lbm_write_time_us":22523,"lbm_writes_lt_1ms":443,"mutex_wait_us":63,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":10624,"update_count":2000}
I20260812 06:18:18.162951 25821 maintenance_manager.cc:419] P 40519e5a9bf64e3f95c935153a6aafbf: Scheduling FlushDeltaMemStoresOp(b960dda8db67439786cbcf73e0582013): perf score=10.126437
I20260812 06:18:18.204020 25723 maintenance_manager.cc:643] P 40519e5a9bf64e3f95c935153a6aafbf: FlushDeltaMemStoresOp(b960dda8db67439786cbcf73e0582013) complete. Timing: real 0.041s	user 0.026s	sys 0.012s Metrics: {"bytes_written":12307489,"delete_count":0,"lbm_write_time_us":18002,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:18:18.204547 25821 maintenance_manager.cc:419] P 40519e5a9bf64e3f95c935153a6aafbf: Scheduling FlushDeltaMemStoresOp(b960dda8db67439786cbcf73e0582013): perf score=2.188937
I20260812 06:18:18.216046 25723 maintenance_manager.cc:643] P 40519e5a9bf64e3f95c935153a6aafbf: FlushDeltaMemStoresOp(b960dda8db67439786cbcf73e0582013) complete. Timing: real 0.011s	user 0.006s	sys 0.003s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4081,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:18.216624 25821 maintenance_manager.cc:419] P 40519e5a9bf64e3f95c935153a6aafbf: Scheduling MajorDeltaCompactionOp(b960dda8db67439786cbcf73e0582013): perf score=1.000000
I20260812 06:18:18.339568 25723 maintenance_manager.cc:643] P 40519e5a9bf64e3f95c935153a6aafbf: MajorDeltaCompactionOp(b960dda8db67439786cbcf73e0582013) complete. Timing: real 0.123s	user 0.090s	sys 0.032s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672276,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":257,"lbm_read_time_us":8704,"lbm_reads_lt_1ms":472,"lbm_write_time_us":23080,"lbm_writes_lt_1ms":443,"mutex_wait_us":56,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":12800,"update_count":2000}
I20260812 06:18:18.340157 25821 maintenance_manager.cc:419] P 40519e5a9bf64e3f95c935153a6aafbf: Scheduling FlushDeltaMemStoresOp(b960dda8db67439786cbcf73e0582013): perf score=10.126437
I20260812 06:18:18.384130 25723 maintenance_manager.cc:643] P 40519e5a9bf64e3f95c935153a6aafbf: FlushDeltaMemStoresOp(b960dda8db67439786cbcf73e0582013) complete. Timing: real 0.044s	user 0.019s	sys 0.017s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":14234,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:18:18.384711 25821 maintenance_manager.cc:419] P 40519e5a9bf64e3f95c935153a6aafbf: Scheduling FlushDeltaMemStoresOp(b960dda8db67439786cbcf73e0582013): perf score=2.188937
I20260812 06:18:18.396266 25723 maintenance_manager.cc:643] P 40519e5a9bf64e3f95c935153a6aafbf: FlushDeltaMemStoresOp(b960dda8db67439786cbcf73e0582013) complete. Timing: real 0.011s	user 0.009s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4074,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:18.396941 25821 maintenance_manager.cc:419] P 40519e5a9bf64e3f95c935153a6aafbf: Scheduling MajorDeltaCompactionOp(b960dda8db67439786cbcf73e0582013): perf score=1.000000
I20260812 06:18:18.550879 25723 maintenance_manager.cc:643] P 40519e5a9bf64e3f95c935153a6aafbf: MajorDeltaCompactionOp(b960dda8db67439786cbcf73e0582013) complete. Timing: real 0.154s	user 0.094s	sys 0.060s 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":630,"lbm_read_time_us":11076,"lbm_reads_lt_1ms":472,"lbm_write_time_us":24231,"lbm_writes_lt_1ms":443,"mutex_wait_us":280,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":12544,"update_count":2000}
I20260812 06:18:18.551635 25821 maintenance_manager.cc:419] P 40519e5a9bf64e3f95c935153a6aafbf: Scheduling FlushDeltaMemStoresOp(b960dda8db67439786cbcf73e0582013): perf score=10.126437
I20260812 06:18:18.589162 25723 maintenance_manager.cc:643] P 40519e5a9bf64e3f95c935153a6aafbf: FlushDeltaMemStoresOp(b960dda8db67439786cbcf73e0582013) complete. Timing: real 0.037s	user 0.031s	sys 0.003s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":16587,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:18:18.589684 25821 maintenance_manager.cc:419] P 40519e5a9bf64e3f95c935153a6aafbf: Scheduling FlushDeltaMemStoresOp(b960dda8db67439786cbcf73e0582013): perf score=2.188937
I20260812 06:18:18.601653 25723 maintenance_manager.cc:643] P 40519e5a9bf64e3f95c935153a6aafbf: FlushDeltaMemStoresOp(b960dda8db67439786cbcf73e0582013) complete. Timing: real 0.012s	user 0.011s	sys 0.001s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4631,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:18.602607 25821 maintenance_manager.cc:419] P 40519e5a9bf64e3f95c935153a6aafbf: Scheduling MajorDeltaCompactionOp(b960dda8db67439786cbcf73e0582013): perf score=1.000000
I20260812 06:18:18.732996 25723 maintenance_manager.cc:643] P 40519e5a9bf64e3f95c935153a6aafbf: MajorDeltaCompactionOp(b960dda8db67439786cbcf73e0582013) complete. Timing: real 0.130s	user 0.098s	sys 0.032s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672276,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":204,"lbm_read_time_us":8872,"lbm_reads_lt_1ms":472,"lbm_write_time_us":27039,"lbm_writes_lt_1ms":443,"mutex_wait_us":92,"peak_mem_usage":50689328,"reinsert_count":0,"update_count":2000}
I20260812 06:18:18.735918 25821 maintenance_manager.cc:419] P 40519e5a9bf64e3f95c935153a6aafbf: Scheduling FlushDeltaMemStoresOp(b960dda8db67439786cbcf73e0582013): perf score=10.126437
I20260812 06:18:18.766207 25723 maintenance_manager.cc:643] P 40519e5a9bf64e3f95c935153a6aafbf: FlushDeltaMemStoresOp(b960dda8db67439786cbcf73e0582013) complete. Timing: real 0.030s	user 0.013s	sys 0.016s Metrics: {"bytes_written":12307489,"delete_count":0,"lbm_write_time_us":13421,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:18:18.766908 25821 maintenance_manager.cc:419] P 40519e5a9bf64e3f95c935153a6aafbf: Scheduling FlushDeltaMemStoresOp(b960dda8db67439786cbcf73e0582013): perf score=2.188937
I20260812 06:18:18.781105 25723 maintenance_manager.cc:643] P 40519e5a9bf64e3f95c935153a6aafbf: FlushDeltaMemStoresOp(b960dda8db67439786cbcf73e0582013) complete. Timing: real 0.014s	user 0.004s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5591,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:18.781795 25821 maintenance_manager.cc:419] P 40519e5a9bf64e3f95c935153a6aafbf: Scheduling MajorDeltaCompactionOp(b960dda8db67439786cbcf73e0582013): perf score=1.000000
I20260812 06:18:18.933899 25723 maintenance_manager.cc:643] P 40519e5a9bf64e3f95c935153a6aafbf: MajorDeltaCompactionOp(b960dda8db67439786cbcf73e0582013) complete. Timing: real 0.152s	user 0.123s	sys 0.021s 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":1038,"lbm_read_time_us":8747,"lbm_reads_lt_1ms":472,"lbm_write_time_us":24948,"lbm_writes_lt_1ms":443,"mutex_wait_us":508,"peak_mem_usage":50689328,"reinsert_count":0,"update_count":2000}
I20260812 06:18:18.934654 25821 maintenance_manager.cc:419] P 40519e5a9bf64e3f95c935153a6aafbf: Scheduling FlushDeltaMemStoresOp(b960dda8db67439786cbcf73e0582013): perf score=14.095187
I20260812 06:18:18.991752 25723 maintenance_manager.cc:643] P 40519e5a9bf64e3f95c935153a6aafbf: FlushDeltaMemStoresOp(b960dda8db67439786cbcf73e0582013) complete. Timing: real 0.057s	user 0.034s	sys 0.012s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":21248,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:18:18.992238 25821 maintenance_manager.cc:419] P 40519e5a9bf64e3f95c935153a6aafbf: Scheduling FlushDeltaMemStoresOp(b960dda8db67439786cbcf73e0582013): perf score=2.188937
I20260812 06:18:19.003139 25723 maintenance_manager.cc:643] P 40519e5a9bf64e3f95c935153a6aafbf: FlushDeltaMemStoresOp(b960dda8db67439786cbcf73e0582013) complete. Timing: real 0.011s	user 0.005s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4214,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:19.003567 25821 maintenance_manager.cc:419] P 40519e5a9bf64e3f95c935153a6aafbf: Scheduling FlushMRSOp(b960dda8db67439786cbcf73e0582013): perf score=1.000000
I20260812 06:18:19.045039 25723 maintenance_manager.cc:643] P 40519e5a9bf64e3f95c935153a6aafbf: FlushMRSOp(b960dda8db67439786cbcf73e0582013) complete. Timing: real 0.041s	user 0.035s	sys 0.000s Metrics: {"bytes_written":1193503,"cfile_init":1,"dirs.queue_time_us":112,"dirs.run_cpu_time_us":253,"dirs.run_wall_time_us":1622,"drs_written":1,"lbm_read_time_us":64,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1950,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":29}
I20260812 06:18:19.046011 25821 maintenance_manager.cc:419] P 40519e5a9bf64e3f95c935153a6aafbf: Scheduling LogGCOp(b960dda8db67439786cbcf73e0582013): free 112239253 bytes of WAL
I20260812 06:18:19.046221 25723 log_reader.cc:385] T b960dda8db67439786cbcf73e0582013: removed 11 log segments from log reader
I20260812 06:18:19.046260 25723 log.cc:1079] T b960dda8db67439786cbcf73e0582013 P 40519e5a9bf64e3f95c935153a6aafbf: Deleting log segment in path: /tmp/dist-test-taskAaiyNc/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515497224838-25556-0/minicluster-data/ts-0-root/wals/b960dda8db67439786cbcf73e0582013/wal-000000003 (ops 12-16)
I20260812 06:18:19.046295 25723 log.cc:1079] T b960dda8db67439786cbcf73e0582013 P 40519e5a9bf64e3f95c935153a6aafbf: Deleting log segment in path: /tmp/dist-test-taskAaiyNc/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515497224838-25556-0/minicluster-data/ts-0-root/wals/b960dda8db67439786cbcf73e0582013/wal-000000004 (ops 17-21)
I20260812 06:18:19.046319 25723 log.cc:1079] T b960dda8db67439786cbcf73e0582013 P 40519e5a9bf64e3f95c935153a6aafbf: Deleting log segment in path: /tmp/dist-test-taskAaiyNc/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515497224838-25556-0/minicluster-data/ts-0-root/wals/b960dda8db67439786cbcf73e0582013/wal-000000005 (ops 22-26)
I20260812 06:18:19.046339 25723 log.cc:1079] T b960dda8db67439786cbcf73e0582013 P 40519e5a9bf64e3f95c935153a6aafbf: Deleting log segment in path: /tmp/dist-test-taskAaiyNc/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515497224838-25556-0/minicluster-data/ts-0-root/wals/b960dda8db67439786cbcf73e0582013/wal-000000006 (ops 27-30)
I20260812 06:18:19.046365 25723 log.cc:1079] T b960dda8db67439786cbcf73e0582013 P 40519e5a9bf64e3f95c935153a6aafbf: Deleting log segment in path: /tmp/dist-test-taskAaiyNc/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515497224838-25556-0/minicluster-data/ts-0-root/wals/b960dda8db67439786cbcf73e0582013/wal-000000007 (ops 31-35)
I20260812 06:18:19.046391 25723 log.cc:1079] T b960dda8db67439786cbcf73e0582013 P 40519e5a9bf64e3f95c935153a6aafbf: Deleting log segment in path: /tmp/dist-test-taskAaiyNc/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515497224838-25556-0/minicluster-data/ts-0-root/wals/b960dda8db67439786cbcf73e0582013/wal-000000008 (ops 36-40)
I20260812 06:18:19.046415 25723 log.cc:1079] T b960dda8db67439786cbcf73e0582013 P 40519e5a9bf64e3f95c935153a6aafbf: Deleting log segment in path: /tmp/dist-test-taskAaiyNc/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515497224838-25556-0/minicluster-data/ts-0-root/wals/b960dda8db67439786cbcf73e0582013/wal-000000009 (ops 41-45)
I20260812 06:18:19.046437 25723 log.cc:1079] T b960dda8db67439786cbcf73e0582013 P 40519e5a9bf64e3f95c935153a6aafbf: Deleting log segment in path: /tmp/dist-test-taskAaiyNc/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515497224838-25556-0/minicluster-data/ts-0-root/wals/b960dda8db67439786cbcf73e0582013/wal-000000010 (ops 46-50)
I20260812 06:18:19.046506 25723 log.cc:1079] T b960dda8db67439786cbcf73e0582013 P 40519e5a9bf64e3f95c935153a6aafbf: Deleting log segment in path: /tmp/dist-test-taskAaiyNc/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515497224838-25556-0/minicluster-data/ts-0-root/wals/b960dda8db67439786cbcf73e0582013/wal-000000011 (ops 51-55)
I20260812 06:18:19.046530 25723 log.cc:1079] T b960dda8db67439786cbcf73e0582013 P 40519e5a9bf64e3f95c935153a6aafbf: Deleting log segment in path: /tmp/dist-test-taskAaiyNc/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515497224838-25556-0/minicluster-data/ts-0-root/wals/b960dda8db67439786cbcf73e0582013/wal-000000012 (ops 56-60)
I20260812 06:18:19.046555 25723 log.cc:1079] T b960dda8db67439786cbcf73e0582013 P 40519e5a9bf64e3f95c935153a6aafbf: Deleting log segment in path: /tmp/dist-test-taskAaiyNc/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515497224838-25556-0/minicluster-data/ts-0-root/wals/b960dda8db67439786cbcf73e0582013/wal-000000013 (ops 61-65)
I20260812 06:18:19.074576 25723 maintenance_manager.cc:643] P 40519e5a9bf64e3f95c935153a6aafbf: LogGCOp(b960dda8db67439786cbcf73e0582013) complete. Timing: real 0.028s	user 0.000s	sys 0.027s Metrics: {}
I20260812 06:18:19.075163 25821 maintenance_manager.cc:419] P 40519e5a9bf64e3f95c935153a6aafbf: Scheduling UndoDeltaBlockGCOp(b960dda8db67439786cbcf73e0582013): 463 bytes on disk
I20260812 06:18:19.075729 25723 maintenance_manager.cc:643] P 40519e5a9bf64e3f95c935153a6aafbf: UndoDeltaBlockGCOp(b960dda8db67439786cbcf73e0582013) 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:18:19.076309 25821 maintenance_manager.cc:419] P 40519e5a9bf64e3f95c935153a6aafbf: Scheduling FlushDeltaMemStoresOp(b960dda8db67439786cbcf73e0582013): perf score=2.188937
I20260812 06:18:19.091159 25723 maintenance_manager.cc:643] P 40519e5a9bf64e3f95c935153a6aafbf: FlushDeltaMemStoresOp(b960dda8db67439786cbcf73e0582013) complete. Timing: real 0.015s	user 0.012s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5476,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:19.091665 25821 maintenance_manager.cc:419] P 40519e5a9bf64e3f95c935153a6aafbf: Scheduling MajorDeltaCompactionOp(b960dda8db67439786cbcf73e0582013): perf score=1.000000
I20260812 06:18:19.330858 25723 maintenance_manager.cc:643] P 40519e5a9bf64e3f95c935153a6aafbf: MajorDeltaCompactionOp(b960dda8db67439786cbcf73e0582013) complete. Timing: real 0.239s	user 0.183s	sys 0.052s Metrics: {"cfile_cache_miss":633,"cfile_cache_miss_bytes":28877219,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":175,"lbm_read_time_us":10503,"lbm_reads_lt_1ms":665,"lbm_write_time_us":45215,"lbm_writes_lt_1ms":643,"mutex_wait_us":313,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":8192,"thread_start_us":101,"threads_started":1,"update_count":3000}
I20260812 06:18:19.331595 25821 maintenance_manager.cc:419] P 40519e5a9bf64e3f95c935153a6aafbf: Scheduling FlushDeltaMemStoresOp(b960dda8db67439786cbcf73e0582013): perf score=18.063937
I20260812 06:18:19.398926 25723 maintenance_manager.cc:643] P 40519e5a9bf64e3f95c935153a6aafbf: FlushDeltaMemStoresOp(b960dda8db67439786cbcf73e0582013) complete. Timing: real 0.067s	user 0.051s	sys 0.015s Metrics: {"bytes_written":20512317,"delete_count":0,"lbm_write_time_us":30670,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":502,"reinsert_count":0,"update_count":2500}
I20260812 06:18:19.399462 25821 maintenance_manager.cc:419] P 40519e5a9bf64e3f95c935153a6aafbf: Scheduling FlushDeltaMemStoresOp(b960dda8db67439786cbcf73e0582013): perf score=2.188937
I20260812 06:18:19.423285 25723 maintenance_manager.cc:643] P 40519e5a9bf64e3f95c935153a6aafbf: FlushDeltaMemStoresOp(b960dda8db67439786cbcf73e0582013) complete. Timing: real 0.024s	user 0.012s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5140,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:19.423723 25821 maintenance_manager.cc:419] P 40519e5a9bf64e3f95c935153a6aafbf: Scheduling FlushDeltaMemStoresOp(b960dda8db67439786cbcf73e0582013): perf score=2.188937
I20260812 06:18:19.434734 25723 maintenance_manager.cc:643] P 40519e5a9bf64e3f95c935153a6aafbf: FlushDeltaMemStoresOp(b960dda8db67439786cbcf73e0582013) complete. Timing: real 0.011s	user 0.010s	sys 0.000s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4198,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:19.435197 25821 maintenance_manager.cc:419] P 40519e5a9bf64e3f95c935153a6aafbf: Scheduling MajorDeltaCompactionOp(b960dda8db67439786cbcf73e0582013): perf score=1.000000
I20260812 06:18:19.628089 25723 maintenance_manager.cc:643] P 40519e5a9bf64e3f95c935153a6aafbf: MajorDeltaCompactionOp(b960dda8db67439786cbcf73e0582013) complete. Timing: real 0.193s	user 0.153s	sys 0.039s Metrics: {"cfile_cache_miss":733,"cfile_cache_miss_bytes":32979634,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":575,"lbm_read_time_us":13139,"lbm_reads_lt_1ms":773,"lbm_write_time_us":41108,"lbm_writes_lt_1ms":743,"mutex_wait_us":290,"peak_mem_usage":87969044,"reinsert_count":0,"spinlock_wait_cycles":768,"update_count":3500}
I20260812 06:18:19.628654 25821 maintenance_manager.cc:419] P 40519e5a9bf64e3f95c935153a6aafbf: Scheduling FlushDeltaMemStoresOp(b960dda8db67439786cbcf73e0582013): perf score=14.095187
I20260812 06:18:19.673774 25723 maintenance_manager.cc:643] P 40519e5a9bf64e3f95c935153a6aafbf: FlushDeltaMemStoresOp(b960dda8db67439786cbcf73e0582013) complete. Timing: real 0.045s	user 0.025s	sys 0.020s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":19300,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:18:19.674304 25821 maintenance_manager.cc:419] P 40519e5a9bf64e3f95c935153a6aafbf: Scheduling FlushDeltaMemStoresOp(b960dda8db67439786cbcf73e0582013): perf score=2.188937
I20260812 06:18:19.690735 25723 maintenance_manager.cc:643] P 40519e5a9bf64e3f95c935153a6aafbf: FlushDeltaMemStoresOp(b960dda8db67439786cbcf73e0582013) complete. Timing: real 0.016s	user 0.012s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5292,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:19.691253 25821 maintenance_manager.cc:419] P 40519e5a9bf64e3f95c935153a6aafbf: Scheduling MajorDeltaCompactionOp(b960dda8db67439786cbcf73e0582013): perf score=1.000000
I20260812 06:18:19.836732 25723 maintenance_manager.cc:643] P 40519e5a9bf64e3f95c935153a6aafbf: MajorDeltaCompactionOp(b960dda8db67439786cbcf73e0582013) complete. Timing: real 0.145s	user 0.118s	sys 0.016s 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":287,"lbm_read_time_us":8391,"lbm_reads_lt_1ms":564,"lbm_write_time_us":26679,"lbm_writes_lt_1ms":543,"mutex_wait_us":76,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":1920,"update_count":2500}
I20260812 06:18:19.837365 25821 maintenance_manager.cc:419] P 40519e5a9bf64e3f95c935153a6aafbf: Scheduling FlushDeltaMemStoresOp(b960dda8db67439786cbcf73e0582013): perf score=14.095187
I20260812 06:18:19.896869 25723 maintenance_manager.cc:643] P 40519e5a9bf64e3f95c935153a6aafbf: FlushDeltaMemStoresOp(b960dda8db67439786cbcf73e0582013) complete. Timing: real 0.059s	user 0.041s	sys 0.004s Metrics: {"bytes_written":16409903,"delete_count":0,"lbm_write_time_us":20989,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:18:19.897408 25821 maintenance_manager.cc:419] P 40519e5a9bf64e3f95c935153a6aafbf: Scheduling FlushDeltaMemStoresOp(b960dda8db67439786cbcf73e0582013): perf score=2.188937
I20260812 06:18:19.912937 25723 maintenance_manager.cc:643] P 40519e5a9bf64e3f95c935153a6aafbf: FlushDeltaMemStoresOp(b960dda8db67439786cbcf73e0582013) complete. Timing: real 0.015s	user 0.013s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5598,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:19.913625 25821 maintenance_manager.cc:419] P 40519e5a9bf64e3f95c935153a6aafbf: Scheduling MajorDeltaCompactionOp(b960dda8db67439786cbcf73e0582013): perf score=1.000000
I20260812 06:18:20.089262 25723 maintenance_manager.cc:643] P 40519e5a9bf64e3f95c935153a6aafbf: MajorDeltaCompactionOp(b960dda8db67439786cbcf73e0582013) complete. Timing: real 0.175s	user 0.122s	sys 0.049s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774690,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":233,"lbm_read_time_us":11240,"lbm_reads_lt_1ms":572,"lbm_write_time_us":28398,"lbm_writes_lt_1ms":543,"mutex_wait_us":24,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":13056,"update_count":2500}
I20260812 06:18:20.090027 25821 maintenance_manager.cc:419] P 40519e5a9bf64e3f95c935153a6aafbf: Scheduling FlushDeltaMemStoresOp(b960dda8db67439786cbcf73e0582013): perf score=14.095187
I20260812 06:18:20.152596 25723 maintenance_manager.cc:643] P 40519e5a9bf64e3f95c935153a6aafbf: FlushDeltaMemStoresOp(b960dda8db67439786cbcf73e0582013) complete. Timing: real 0.062s	user 0.038s	sys 0.007s Metrics: {"bytes_written":16409904,"delete_count":0,"lbm_write_time_us":21072,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:18:20.153225 25821 maintenance_manager.cc:419] P 40519e5a9bf64e3f95c935153a6aafbf: Scheduling FlushDeltaMemStoresOp(b960dda8db67439786cbcf73e0582013): perf score=2.188937
I20260812 06:18:20.164381 25723 maintenance_manager.cc:643] P 40519e5a9bf64e3f95c935153a6aafbf: FlushDeltaMemStoresOp(b960dda8db67439786cbcf73e0582013) complete. Timing: real 0.011s	user 0.009s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4091,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:20.165140 25821 maintenance_manager.cc:419] P 40519e5a9bf64e3f95c935153a6aafbf: Scheduling MajorDeltaCompactionOp(b960dda8db67439786cbcf73e0582013): perf score=1.000000
I20260812 06:18:20.334707 25723 maintenance_manager.cc:643] P 40519e5a9bf64e3f95c935153a6aafbf: MajorDeltaCompactionOp(b960dda8db67439786cbcf73e0582013) complete. Timing: real 0.169s	user 0.111s	sys 0.051s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774691,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":320,"lbm_read_time_us":12188,"lbm_reads_lt_1ms":572,"lbm_write_time_us":28319,"lbm_writes_lt_1ms":543,"mutex_wait_us":2,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":1664,"update_count":2500}
I20260812 06:18:20.335264 25821 maintenance_manager.cc:419] P 40519e5a9bf64e3f95c935153a6aafbf: Scheduling FlushDeltaMemStoresOp(b960dda8db67439786cbcf73e0582013): perf score=14.095187
I20260812 06:18:20.392467 25723 maintenance_manager.cc:643] P 40519e5a9bf64e3f95c935153a6aafbf: FlushDeltaMemStoresOp(b960dda8db67439786cbcf73e0582013) complete. Timing: real 0.057s	user 0.025s	sys 0.024s Metrics: {"bytes_written":16409900,"delete_count":0,"lbm_write_time_us":23475,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:18:20.393015 25821 maintenance_manager.cc:419] P 40519e5a9bf64e3f95c935153a6aafbf: Scheduling FlushDeltaMemStoresOp(b960dda8db67439786cbcf73e0582013): perf score=2.188937
I20260812 06:18:20.406005 25723 maintenance_manager.cc:643] P 40519e5a9bf64e3f95c935153a6aafbf: FlushDeltaMemStoresOp(b960dda8db67439786cbcf73e0582013) complete. Timing: real 0.013s	user 0.009s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4796,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:20.406513 25821 maintenance_manager.cc:419] P 40519e5a9bf64e3f95c935153a6aafbf: Scheduling FlushMRSOp(b960dda8db67439786cbcf73e0582013): perf score=1.000000
I20260812 06:18:20.434914 25723 maintenance_manager.cc:643] P 40519e5a9bf64e3f95c935153a6aafbf: FlushMRSOp(b960dda8db67439786cbcf73e0582013) complete. Timing: real 0.028s	user 0.025s	sys 0.000s Metrics: {"bytes_written":1152514,"cfile_init":1,"dirs.queue_time_us":66,"dirs.run_cpu_time_us":241,"dirs.run_wall_time_us":1415,"drs_written":1,"lbm_read_time_us":44,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1800,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":28}
I20260812 06:18:20.435715 25821 maintenance_manager.cc:419] P 40519e5a9bf64e3f95c935153a6aafbf: Scheduling LogGCOp(b960dda8db67439786cbcf73e0582013): free 120553433 bytes of WAL
I20260812 06:18:20.435987 25723 log_reader.cc:385] T b960dda8db67439786cbcf73e0582013: removed 12 log segments from log reader
I20260812 06:18:20.436053 25723 log.cc:1079] T b960dda8db67439786cbcf73e0582013 P 40519e5a9bf64e3f95c935153a6aafbf: Deleting log segment in path: /tmp/dist-test-taskAaiyNc/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515497224838-25556-0/minicluster-data/ts-0-root/wals/b960dda8db67439786cbcf73e0582013/wal-000000014 (ops 66-70)
I20260812 06:18:20.436090 25723 log.cc:1079] T b960dda8db67439786cbcf73e0582013 P 40519e5a9bf64e3f95c935153a6aafbf: Deleting log segment in path: /tmp/dist-test-taskAaiyNc/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515497224838-25556-0/minicluster-data/ts-0-root/wals/b960dda8db67439786cbcf73e0582013/wal-000000015 (ops 71-75)
I20260812 06:18:20.436118 25723 log.cc:1079] T b960dda8db67439786cbcf73e0582013 P 40519e5a9bf64e3f95c935153a6aafbf: Deleting log segment in path: /tmp/dist-test-taskAaiyNc/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515497224838-25556-0/minicluster-data/ts-0-root/wals/b960dda8db67439786cbcf73e0582013/wal-000000016 (ops 76-80)
I20260812 06:18:20.436144 25723 log.cc:1079] T b960dda8db67439786cbcf73e0582013 P 40519e5a9bf64e3f95c935153a6aafbf: Deleting log segment in path: /tmp/dist-test-taskAaiyNc/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515497224838-25556-0/minicluster-data/ts-0-root/wals/b960dda8db67439786cbcf73e0582013/wal-000000017 (ops 81-85)
I20260812 06:18:20.436172 25723 log.cc:1079] T b960dda8db67439786cbcf73e0582013 P 40519e5a9bf64e3f95c935153a6aafbf: Deleting log segment in path: /tmp/dist-test-taskAaiyNc/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515497224838-25556-0/minicluster-data/ts-0-root/wals/b960dda8db67439786cbcf73e0582013/wal-000000018 (ops 86-90)
I20260812 06:18:20.436205 25723 log.cc:1079] T b960dda8db67439786cbcf73e0582013 P 40519e5a9bf64e3f95c935153a6aafbf: Deleting log segment in path: /tmp/dist-test-taskAaiyNc/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515497224838-25556-0/minicluster-data/ts-0-root/wals/b960dda8db67439786cbcf73e0582013/wal-000000019 (ops 91-95)
I20260812 06:18:20.436228 25723 log.cc:1079] T b960dda8db67439786cbcf73e0582013 P 40519e5a9bf64e3f95c935153a6aafbf: Deleting log segment in path: /tmp/dist-test-taskAaiyNc/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515497224838-25556-0/minicluster-data/ts-0-root/wals/b960dda8db67439786cbcf73e0582013/wal-000000020 (ops 96-100)
I20260812 06:18:20.436250 25723 log.cc:1079] T b960dda8db67439786cbcf73e0582013 P 40519e5a9bf64e3f95c935153a6aafbf: Deleting log segment in path: /tmp/dist-test-taskAaiyNc/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515497224838-25556-0/minicluster-data/ts-0-root/wals/b960dda8db67439786cbcf73e0582013/wal-000000021 (ops 101-104)
I20260812 06:18:20.436275 25723 log.cc:1079] T b960dda8db67439786cbcf73e0582013 P 40519e5a9bf64e3f95c935153a6aafbf: Deleting log segment in path: /tmp/dist-test-taskAaiyNc/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515497224838-25556-0/minicluster-data/ts-0-root/wals/b960dda8db67439786cbcf73e0582013/wal-000000022 (ops 105-109)
I20260812 06:18:20.436304 25723 log.cc:1079] T b960dda8db67439786cbcf73e0582013 P 40519e5a9bf64e3f95c935153a6aafbf: Deleting log segment in path: /tmp/dist-test-taskAaiyNc/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515497224838-25556-0/minicluster-data/ts-0-root/wals/b960dda8db67439786cbcf73e0582013/wal-000000023 (ops 110-114)
I20260812 06:18:20.436348 25723 log.cc:1079] T b960dda8db67439786cbcf73e0582013 P 40519e5a9bf64e3f95c935153a6aafbf: Deleting log segment in path: /tmp/dist-test-taskAaiyNc/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515497224838-25556-0/minicluster-data/ts-0-root/wals/b960dda8db67439786cbcf73e0582013/wal-000000024 (ops 115-118)
I20260812 06:18:20.436381 25723 log.cc:1079] T b960dda8db67439786cbcf73e0582013 P 40519e5a9bf64e3f95c935153a6aafbf: Deleting log segment in path: /tmp/dist-test-taskAaiyNc/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515497224838-25556-0/minicluster-data/ts-0-root/wals/b960dda8db67439786cbcf73e0582013/wal-000000025 (ops 119-123)
I20260812 06:18:20.463032 25723 maintenance_manager.cc:643] P 40519e5a9bf64e3f95c935153a6aafbf: LogGCOp(b960dda8db67439786cbcf73e0582013) complete. Timing: real 0.027s	user 0.000s	sys 0.026s Metrics: {}
I20260812 06:18:20.463445 25821 maintenance_manager.cc:419] P 40519e5a9bf64e3f95c935153a6aafbf: Scheduling FlushDeltaMemStoresOp(b960dda8db67439786cbcf73e0582013): perf score=2.188937
I20260812 06:18:20.486481 25723 maintenance_manager.cc:643] P 40519e5a9bf64e3f95c935153a6aafbf: FlushDeltaMemStoresOp(b960dda8db67439786cbcf73e0582013) complete. Timing: real 0.023s	user 0.006s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4350,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:20.486943 25821 maintenance_manager.cc:419] P 40519e5a9bf64e3f95c935153a6aafbf: Scheduling UndoDeltaBlockGCOp(b960dda8db67439786cbcf73e0582013): 447 bytes on disk
I20260812 06:18:20.487346 25723 maintenance_manager.cc:643] P 40519e5a9bf64e3f95c935153a6aafbf: UndoDeltaBlockGCOp(b960dda8db67439786cbcf73e0582013) 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:18:20.487824 25821 maintenance_manager.cc:419] P 40519e5a9bf64e3f95c935153a6aafbf: Scheduling FlushDeltaMemStoresOp(b960dda8db67439786cbcf73e0582013): perf score=2.188937
I20260812 06:18:20.498154 25723 maintenance_manager.cc:643] P 40519e5a9bf64e3f95c935153a6aafbf: FlushDeltaMemStoresOp(b960dda8db67439786cbcf73e0582013) complete. Timing: real 0.010s	user 0.006s	sys 0.004s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":3898,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:20.498821 25821 maintenance_manager.cc:419] P 40519e5a9bf64e3f95c935153a6aafbf: Scheduling MajorDeltaCompactionOp(b960dda8db67439786cbcf73e0582013): perf score=1.000000
I20260812 06:18:20.733084 25723 maintenance_manager.cc:643] P 40519e5a9bf64e3f95c935153a6aafbf: MajorDeltaCompactionOp(b960dda8db67439786cbcf73e0582013) complete. Timing: real 0.234s	user 0.154s	sys 0.072s Metrics: {"cfile_cache_miss":734,"cfile_cache_miss_bytes":32979748,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":6895,"lbm_read_time_us":16667,"lbm_reads_lt_1ms":774,"lbm_write_time_us":40780,"lbm_writes_lt_1ms":743,"mutex_wait_us":2289,"peak_mem_usage":87969044,"reinsert_count":0,"spinlock_wait_cycles":13056,"thread_start_us":94,"threads_started":1,"update_count":3500}
I20260812 06:18:20.733763 25821 maintenance_manager.cc:419] P 40519e5a9bf64e3f95c935153a6aafbf: Scheduling FlushDeltaMemStoresOp(b960dda8db67439786cbcf73e0582013): perf score=18.063937
I20260812 06:18:20.788133 25723 maintenance_manager.cc:643] P 40519e5a9bf64e3f95c935153a6aafbf: FlushDeltaMemStoresOp(b960dda8db67439786cbcf73e0582013) complete. Timing: real 0.054s	user 0.023s	sys 0.028s Metrics: {"bytes_written":20512320,"delete_count":0,"lbm_write_time_us":24671,"lbm_writes_lt_1ms":503,"reinsert_count":0,"update_count":2500}
I20260812 06:18:20.788682 25821 maintenance_manager.cc:419] P 40519e5a9bf64e3f95c935153a6aafbf: Scheduling FlushDeltaMemStoresOp(b960dda8db67439786cbcf73e0582013): perf score=2.188937
I20260812 06:18:20.804852 25723 maintenance_manager.cc:643] P 40519e5a9bf64e3f95c935153a6aafbf: FlushDeltaMemStoresOp(b960dda8db67439786cbcf73e0582013) complete. Timing: real 0.016s	user 0.002s	sys 0.011s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6283,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:20.805536 25821 maintenance_manager.cc:419] P 40519e5a9bf64e3f95c935153a6aafbf: Scheduling MajorDeltaCompactionOp(b960dda8db67439786cbcf73e0582013): perf score=1.000000
I20260812 06:18:20.973001 25723 maintenance_manager.cc:643] P 40519e5a9bf64e3f95c935153a6aafbf: MajorDeltaCompactionOp(b960dda8db67439786cbcf73e0582013) complete. Timing: real 0.167s	user 0.130s	sys 0.037s Metrics: {"cfile_cache_miss":632,"cfile_cache_miss_bytes":28877107,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":425,"lbm_read_time_us":11354,"lbm_reads_lt_1ms":672,"lbm_write_time_us":37318,"lbm_writes_lt_1ms":643,"mutex_wait_us":85,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":4864,"update_count":3000}
I20260812 06:18:20.973675 25821 maintenance_manager.cc:419] P 40519e5a9bf64e3f95c935153a6aafbf: Scheduling FlushDeltaMemStoresOp(b960dda8db67439786cbcf73e0582013): perf score=14.095187
I20260812 06:18:21.020915 25723 maintenance_manager.cc:643] P 40519e5a9bf64e3f95c935153a6aafbf: FlushDeltaMemStoresOp(b960dda8db67439786cbcf73e0582013) complete. Timing: real 0.047s	user 0.027s	sys 0.017s Metrics: {"bytes_written":16409903,"delete_count":0,"lbm_write_time_us":21350,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:18:21.021718 25821 maintenance_manager.cc:419] P 40519e5a9bf64e3f95c935153a6aafbf: Scheduling FlushDeltaMemStoresOp(b960dda8db67439786cbcf73e0582013): perf score=2.188937
I20260812 06:18:21.038753 25723 maintenance_manager.cc:643] P 40519e5a9bf64e3f95c935153a6aafbf: FlushDeltaMemStoresOp(b960dda8db67439786cbcf73e0582013) complete. Timing: real 0.017s	user 0.007s	sys 0.009s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6472,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:21.039265 25821 maintenance_manager.cc:419] P 40519e5a9bf64e3f95c935153a6aafbf: Scheduling MajorDeltaCompactionOp(b960dda8db67439786cbcf73e0582013): perf score=1.000000
I20260812 06:18:21.195106 25723 maintenance_manager.cc:643] P 40519e5a9bf64e3f95c935153a6aafbf: MajorDeltaCompactionOp(b960dda8db67439786cbcf73e0582013) complete. Timing: real 0.156s	user 0.110s	sys 0.043s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774690,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":690,"lbm_read_time_us":10383,"lbm_reads_lt_1ms":564,"lbm_write_time_us":32980,"lbm_writes_lt_1ms":543,"mutex_wait_us":64,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":6656,"update_count":2500}
I20260812 06:18:21.197825 25821 maintenance_manager.cc:419] P 40519e5a9bf64e3f95c935153a6aafbf: Scheduling FlushDeltaMemStoresOp(b960dda8db67439786cbcf73e0582013): perf score=12.110812
I20260812 06:18:21.232507 25723 maintenance_manager.cc:643] P 40519e5a9bf64e3f95c935153a6aafbf: FlushDeltaMemStoresOp(b960dda8db67439786cbcf73e0582013) complete. Timing: real 0.034s	user 0.019s	sys 0.013s Metrics: {"bytes_written":14358697,"delete_count":0,"lbm_write_time_us":15361,"lbm_writes_lt_1ms":353,"reinsert_count":0,"update_count":1750}
I20260812 06:18:21.233120 25821 maintenance_manager.cc:419] P 40519e5a9bf64e3f95c935153a6aafbf: Scheduling FlushDeltaMemStoresOp(b960dda8db67439786cbcf73e0582013): perf score=1.000000
I20260812 06:18:21.244155 25723 maintenance_manager.cc:643] P 40519e5a9bf64e3f95c935153a6aafbf: FlushDeltaMemStoresOp(b960dda8db67439786cbcf73e0582013) complete. Timing: real 0.011s	user 0.008s	sys 0.000s Metrics: {"bytes_written":2051402,"delete_count":0,"lbm_write_time_us":3002,"lbm_writes_lt_1ms":53,"reinsert_count":0,"update_count":250}
I20260812 06:18:21.244632 25821 maintenance_manager.cc:419] P 40519e5a9bf64e3f95c935153a6aafbf: Scheduling MajorDeltaCompactionOp(b960dda8db67439786cbcf73e0582013): perf score=1.000000
I20260812 06:18:21.394482 25723 maintenance_manager.cc:643] P 40519e5a9bf64e3f95c935153a6aafbf: MajorDeltaCompactionOp(b960dda8db67439786cbcf73e0582013) complete. Timing: real 0.150s	user 0.103s	sys 0.040s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672228,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":1070,"lbm_read_time_us":8948,"lbm_reads_lt_1ms":464,"lbm_write_time_us":25523,"lbm_writes_lt_1ms":443,"mutex_wait_us":328,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":14336,"update_count":2000}
I20260812 06:18:21.395099 25821 maintenance_manager.cc:419] P 40519e5a9bf64e3f95c935153a6aafbf: Scheduling FlushDeltaMemStoresOp(b960dda8db67439786cbcf73e0582013): perf score=14.095187
I20260812 06:18:21.445878 25723 maintenance_manager.cc:643] P 40519e5a9bf64e3f95c935153a6aafbf: FlushDeltaMemStoresOp(b960dda8db67439786cbcf73e0582013) complete. Timing: real 0.051s	user 0.029s	sys 0.020s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":22727,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:18:21.446485 25821 maintenance_manager.cc:419] P 40519e5a9bf64e3f95c935153a6aafbf: Scheduling FlushDeltaMemStoresOp(b960dda8db67439786cbcf73e0582013): perf score=2.188937
I20260812 06:18:21.471642 25723 maintenance_manager.cc:643] P 40519e5a9bf64e3f95c935153a6aafbf: FlushDeltaMemStoresOp(b960dda8db67439786cbcf73e0582013) complete. Timing: real 0.025s	user 0.007s	sys 0.016s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5845,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:21.472272 25821 maintenance_manager.cc:419] P 40519e5a9bf64e3f95c935153a6aafbf: Scheduling MajorDeltaCompactionOp(b960dda8db67439786cbcf73e0582013): perf score=1.000000
I20260812 06:18:21.669564 25723 maintenance_manager.cc:643] P 40519e5a9bf64e3f95c935153a6aafbf: MajorDeltaCompactionOp(b960dda8db67439786cbcf73e0582013) complete. Timing: real 0.197s	user 0.116s	sys 0.071s 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":194,"lbm_read_time_us":13451,"lbm_reads_lt_1ms":572,"lbm_write_time_us":32526,"lbm_writes_lt_1ms":543,"mutex_wait_us":49,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":8320,"update_count":2500}
I20260812 06:18:21.670336 25821 maintenance_manager.cc:419] P 40519e5a9bf64e3f95c935153a6aafbf: Scheduling FlushDeltaMemStoresOp(b960dda8db67439786cbcf73e0582013): perf score=14.095187
I20260812 06:18:21.718696 25723 maintenance_manager.cc:643] P 40519e5a9bf64e3f95c935153a6aafbf: FlushDeltaMemStoresOp(b960dda8db67439786cbcf73e0582013) complete. Timing: real 0.048s	user 0.032s	sys 0.014s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":20853,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:18:21.719278 25821 maintenance_manager.cc:419] P 40519e5a9bf64e3f95c935153a6aafbf: Scheduling FlushDeltaMemStoresOp(b960dda8db67439786cbcf73e0582013): perf score=2.188937
I20260812 06:18:21.735001 25723 maintenance_manager.cc:643] P 40519e5a9bf64e3f95c935153a6aafbf: FlushDeltaMemStoresOp(b960dda8db67439786cbcf73e0582013) complete. Timing: real 0.016s	user 0.008s	sys 0.006s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5970,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:21.735669 25821 maintenance_manager.cc:419] P 40519e5a9bf64e3f95c935153a6aafbf: Scheduling MajorDeltaCompactionOp(b960dda8db67439786cbcf73e0582013): perf score=1.000000
I20260812 06:18:21.917508 25723 maintenance_manager.cc:643] P 40519e5a9bf64e3f95c935153a6aafbf: MajorDeltaCompactionOp(b960dda8db67439786cbcf73e0582013) complete. Timing: real 0.182s	user 0.139s	sys 0.030s 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":529,"lbm_read_time_us":10080,"lbm_reads_lt_1ms":572,"lbm_write_time_us":31257,"lbm_writes_lt_1ms":543,"mutex_wait_us":52,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":10752,"update_count":2500}
I20260812 06:18:21.918156 25821 maintenance_manager.cc:419] P 40519e5a9bf64e3f95c935153a6aafbf: Scheduling FlushDeltaMemStoresOp(b960dda8db67439786cbcf73e0582013): perf score=14.095187
I20260812 06:18:21.967530 25723 maintenance_manager.cc:643] P 40519e5a9bf64e3f95c935153a6aafbf: FlushDeltaMemStoresOp(b960dda8db67439786cbcf73e0582013) complete. Timing: real 0.049s	user 0.035s	sys 0.011s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":22014,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:18:21.968170 25821 maintenance_manager.cc:419] P 40519e5a9bf64e3f95c935153a6aafbf: Scheduling FlushDeltaMemStoresOp(b960dda8db67439786cbcf73e0582013): perf score=2.188937
I20260812 06:18:21.982235 25723 maintenance_manager.cc:643] P 40519e5a9bf64e3f95c935153a6aafbf: FlushDeltaMemStoresOp(b960dda8db67439786cbcf73e0582013) complete. Timing: real 0.014s	user 0.013s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5470,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:21.982702 25821 maintenance_manager.cc:419] P 40519e5a9bf64e3f95c935153a6aafbf: Scheduling FlushMRSOp(b960dda8db67439786cbcf73e0582013): perf score=1.000000
I20260812 06:18:22.019081 25723 maintenance_manager.cc:643] P 40519e5a9bf64e3f95c935153a6aafbf: FlushMRSOp(b960dda8db67439786cbcf73e0582013) complete. Timing: real 0.036s	user 0.035s	sys 0.000s Metrics: {"bytes_written":1316417,"cfile_init":1,"dirs.queue_time_us":86,"dirs.run_cpu_time_us":282,"dirs.run_wall_time_us":1416,"drs_written":1,"lbm_read_time_us":60,"lbm_reads_lt_1ms":4,"lbm_write_time_us":2223,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":32}
I20260812 06:18:22.019872 25821 maintenance_manager.cc:419] P 40519e5a9bf64e3f95c935153a6aafbf: Scheduling LogGCOp(b960dda8db67439786cbcf73e0582013): free 132571576 bytes of WAL
I20260812 06:18:22.020210 25723 log_reader.cc:385] T b960dda8db67439786cbcf73e0582013: removed 13 log segments from log reader
I20260812 06:18:22.020330 25723 log.cc:1079] T b960dda8db67439786cbcf73e0582013 P 40519e5a9bf64e3f95c935153a6aafbf: Deleting log segment in path: /tmp/dist-test-taskAaiyNc/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515497224838-25556-0/minicluster-data/ts-0-root/wals/b960dda8db67439786cbcf73e0582013/wal-000000026 (ops 124-128)
I20260812 06:18:22.020426 25723 log.cc:1079] T b960dda8db67439786cbcf73e0582013 P 40519e5a9bf64e3f95c935153a6aafbf: Deleting log segment in path: /tmp/dist-test-taskAaiyNc/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515497224838-25556-0/minicluster-data/ts-0-root/wals/b960dda8db67439786cbcf73e0582013/wal-000000027 (ops 129-133)
I20260812 06:18:22.020529 25723 log.cc:1079] T b960dda8db67439786cbcf73e0582013 P 40519e5a9bf64e3f95c935153a6aafbf: Deleting log segment in path: /tmp/dist-test-taskAaiyNc/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515497224838-25556-0/minicluster-data/ts-0-root/wals/b960dda8db67439786cbcf73e0582013/wal-000000028 (ops 134-138)
I20260812 06:18:22.020601 25723 log.cc:1079] T b960dda8db67439786cbcf73e0582013 P 40519e5a9bf64e3f95c935153a6aafbf: Deleting log segment in path: /tmp/dist-test-taskAaiyNc/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515497224838-25556-0/minicluster-data/ts-0-root/wals/b960dda8db67439786cbcf73e0582013/wal-000000029 (ops 139-142)
I20260812 06:18:22.020649 25723 log.cc:1079] T b960dda8db67439786cbcf73e0582013 P 40519e5a9bf64e3f95c935153a6aafbf: Deleting log segment in path: /tmp/dist-test-taskAaiyNc/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515497224838-25556-0/minicluster-data/ts-0-root/wals/b960dda8db67439786cbcf73e0582013/wal-000000030 (ops 143-147)
I20260812 06:18:22.020720 25723 log.cc:1079] T b960dda8db67439786cbcf73e0582013 P 40519e5a9bf64e3f95c935153a6aafbf: Deleting log segment in path: /tmp/dist-test-taskAaiyNc/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515497224838-25556-0/minicluster-data/ts-0-root/wals/b960dda8db67439786cbcf73e0582013/wal-000000031 (ops 148-152)
I20260812 06:18:22.020783 25723 log.cc:1079] T b960dda8db67439786cbcf73e0582013 P 40519e5a9bf64e3f95c935153a6aafbf: Deleting log segment in path: /tmp/dist-test-taskAaiyNc/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515497224838-25556-0/minicluster-data/ts-0-root/wals/b960dda8db67439786cbcf73e0582013/wal-000000032 (ops 153-157)
I20260812 06:18:22.020857 25723 log.cc:1079] T b960dda8db67439786cbcf73e0582013 P 40519e5a9bf64e3f95c935153a6aafbf: Deleting log segment in path: /tmp/dist-test-taskAaiyNc/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515497224838-25556-0/minicluster-data/ts-0-root/wals/b960dda8db67439786cbcf73e0582013/wal-000000033 (ops 158-162)
I20260812 06:18:22.020925 25723 log.cc:1079] T b960dda8db67439786cbcf73e0582013 P 40519e5a9bf64e3f95c935153a6aafbf: Deleting log segment in path: /tmp/dist-test-taskAaiyNc/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515497224838-25556-0/minicluster-data/ts-0-root/wals/b960dda8db67439786cbcf73e0582013/wal-000000034 (ops 163-167)
I20260812 06:18:22.020998 25723 log.cc:1079] T b960dda8db67439786cbcf73e0582013 P 40519e5a9bf64e3f95c935153a6aafbf: Deleting log segment in path: /tmp/dist-test-taskAaiyNc/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515497224838-25556-0/minicluster-data/ts-0-root/wals/b960dda8db67439786cbcf73e0582013/wal-000000035 (ops 168-172)
I20260812 06:18:22.021066 25723 log.cc:1079] T b960dda8db67439786cbcf73e0582013 P 40519e5a9bf64e3f95c935153a6aafbf: Deleting log segment in path: /tmp/dist-test-taskAaiyNc/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515497224838-25556-0/minicluster-data/ts-0-root/wals/b960dda8db67439786cbcf73e0582013/wal-000000036 (ops 173-177)
I20260812 06:18:22.021137 25723 log.cc:1079] T b960dda8db67439786cbcf73e0582013 P 40519e5a9bf64e3f95c935153a6aafbf: Deleting log segment in path: /tmp/dist-test-taskAaiyNc/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515497224838-25556-0/minicluster-data/ts-0-root/wals/b960dda8db67439786cbcf73e0582013/wal-000000037 (ops 178-182)
I20260812 06:18:22.021204 25723 log.cc:1079] T b960dda8db67439786cbcf73e0582013 P 40519e5a9bf64e3f95c935153a6aafbf: Deleting log segment in path: /tmp/dist-test-taskAaiyNc/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515497224838-25556-0/minicluster-data/ts-0-root/wals/b960dda8db67439786cbcf73e0582013/wal-000000038 (ops 183-186)
I20260812 06:18:22.053171 25723 maintenance_manager.cc:643] P 40519e5a9bf64e3f95c935153a6aafbf: LogGCOp(b960dda8db67439786cbcf73e0582013) complete. Timing: real 0.033s	user 0.000s	sys 0.029s Metrics: {}
I20260812 06:18:22.053689 25821 maintenance_manager.cc:419] P 40519e5a9bf64e3f95c935153a6aafbf: Scheduling UndoDeltaBlockGCOp(b960dda8db67439786cbcf73e0582013): 493 bytes on disk
I20260812 06:18:22.054299 25723 maintenance_manager.cc:643] P 40519e5a9bf64e3f95c935153a6aafbf: UndoDeltaBlockGCOp(b960dda8db67439786cbcf73e0582013) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":56,"lbm_reads_lt_1ms":4}
I20260812 06:18:22.054841 25821 maintenance_manager.cc:419] P 40519e5a9bf64e3f95c935153a6aafbf: Scheduling FlushDeltaMemStoresOp(b960dda8db67439786cbcf73e0582013): perf score=6.157687
I20260812 06:18:22.077651 25723 maintenance_manager.cc:643] P 40519e5a9bf64e3f95c935153a6aafbf: FlushDeltaMemStoresOp(b960dda8db67439786cbcf73e0582013) complete. Timing: real 0.023s	user 0.014s	sys 0.008s Metrics: {"bytes_written":7999957,"delete_count":0,"lbm_write_time_us":10161,"lbm_writes_lt_1ms":198,"reinsert_count":0,"update_count":975}
I20260812 06:18:22.078202 25821 maintenance_manager.cc:419] P 40519e5a9bf64e3f95c935153a6aafbf: Scheduling MajorDeltaCompactionOp(b960dda8db67439786cbcf73e0582013): perf score=1.000000
I20260812 06:18:22.291819 25723 maintenance_manager.cc:643] P 40519e5a9bf64e3f95c935153a6aafbf: MajorDeltaCompactionOp(b960dda8db67439786cbcf73e0582013) complete. Timing: real 0.213s	user 0.149s	sys 0.064s Metrics: {"cfile_cache_miss":728,"cfile_cache_miss_bytes":32774512,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":532,"lbm_read_time_us":15906,"lbm_reads_lt_1ms":764,"lbm_write_time_us":38702,"lbm_writes_lt_1ms":738,"mutex_wait_us":50,"peak_mem_usage":86723485,"reinsert_count":0,"spinlock_wait_cycles":12544,"thread_start_us":80,"threads_started":1,"update_count":3475}
I20260812 06:18:22.293821 25821 maintenance_manager.cc:419] P 40519e5a9bf64e3f95c935153a6aafbf: Scheduling FlushDeltaMemStoresOp(b960dda8db67439786cbcf73e0582013): perf score=15.087375
I20260812 06:18:22.331794 25556 heavy-update-compaction-itest.cc:229] Time spent updating: real 4.841s	user 1.838s	sys 0.101s
I20260812 06:18:22.347661 25723 maintenance_manager.cc:643] P 40519e5a9bf64e3f95c935153a6aafbf: FlushDeltaMemStoresOp(b960dda8db67439786cbcf73e0582013) complete. Timing: real 0.054s	user 0.048s	sys 0.004s Metrics: {"bytes_written":16615025,"delete_count":0,"lbm_write_time_us":23409,"lbm_writes_lt_1ms":408,"reinsert_count":0,"update_count":2025}
I20260812 06:18:22.348268 25821 maintenance_manager.cc:419] P 40519e5a9bf64e3f95c935153a6aafbf: Scheduling FlushDeltaMemStoresOp(b960dda8db67439786cbcf73e0582013): perf score=2.188937
I20260812 06:18:22.358659 25723 maintenance_manager.cc:643] P 40519e5a9bf64e3f95c935153a6aafbf: FlushDeltaMemStoresOp(b960dda8db67439786cbcf73e0582013) complete. Timing: real 0.010s	user 0.009s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4213,"lbm_writes_lt_1ms":103,"reinsert_count":0,"spinlock_wait_cycles":768,"update_count":500}
I20260812 06:18:22.359123 25821 maintenance_manager.cc:419] P 40519e5a9bf64e3f95c935153a6aafbf: Scheduling MajorDeltaCompactionOp(b960dda8db67439786cbcf73e0582013): perf score=1.000000
I20260812 06:18:22.411711 25556 heavy-update-compaction-itest.cc:265] Time spent scanning: real 0.079s	user 0.002s	sys 0.002s
I20260812 06:18:22.412539 25556 tablet_server.cc:179] TabletServer@127.24.245.1:0 shutting down...
I20260812 06:18:22.493709 25723 maintenance_manager.cc:643] P 40519e5a9bf64e3f95c935153a6aafbf: MajorDeltaCompactionOp(b960dda8db67439786cbcf73e0582013) complete. Timing: real 0.134s	user 0.083s	sys 0.048s Metrics: {"cfile_cache_hit":323,"cfile_cache_hit_bytes":13210978,"cfile_cache_miss":214,"cfile_cache_miss_bytes":11768834,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":3002,"lbm_read_time_us":7196,"lbm_reads_lt_1ms":246,"lbm_write_time_us":27234,"lbm_writes_lt_1ms":548,"mutex_wait_us":2314,"peak_mem_usage":63321075,"reinsert_count":0,"spinlock_wait_cycles":73344,"update_count":2525}
I20260812 06:18:22.496044 25556 ts_tablet_manager.cc:1507] Shutting down tablet manager...
I20260812 06:18:22.496490 25556 tablet_replica.cc:333] T b960dda8db67439786cbcf73e0582013 P 40519e5a9bf64e3f95c935153a6aafbf: stopping tablet replica
I20260812 06:18:22.496687 25556 raft_consensus.cc:2243] T b960dda8db67439786cbcf73e0582013 P 40519e5a9bf64e3f95c935153a6aafbf [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:18:22.496876 25556 raft_consensus.cc:2272] T b960dda8db67439786cbcf73e0582013 P 40519e5a9bf64e3f95c935153a6aafbf [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:18:22.514480 25556 tablet_server.cc:196] TabletServer@127.24.245.1:0 shutdown complete.
I20260812 06:18:22.537987 25556 master.cc:562] Master@127.24.245.62:46861 shutting down...
I20260812 06:18:22.542096 25556 raft_consensus.cc:2243] T 00000000000000000000000000000000 P d9792771271741a48574d9d4b8e40e51 [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:18:22.542326 25556 raft_consensus.cc:2272] T 00000000000000000000000000000000 P d9792771271741a48574d9d4b8e40e51 [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:18:22.542441 25556 tablet_replica.cc:333] T 00000000000000000000000000000000 P d9792771271741a48574d9d4b8e40e51: stopping tablet replica
I20260812 06:18:22.555111 25556 master.cc:584] Master@127.24.245.62:46861 shutdown complete.
[       OK ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/0 (5409 ms)
[ RUN      ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/1
I20260812 06:18:22.658932 25556 internal_mini_cluster.cc:156] Creating distributed mini masters. Addrs: 127.24.245.62:39671
I20260812 06:18:22.659502 25556 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:18:22.662004 25869 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:18:22.662086 25873 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:18:22.662256 25870 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:18:22.665657 25556 server_base.cc:1061] running on GCE node
I20260812 06:18:22.665848 25556 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:18:22.665895 25556 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:18:22.665911 25556 hybrid_clock.cc:648] HybridClock initialized: now 1786515502665911 us; error 0 us; skew 500 ppm
I20260812 06:18:22.666821 25556 webserver.cc:533] Webserver started at http://127.24.245.62:41281/ using document root <none> and password file <none>
I20260812 06:18:22.667016 25556 fs_manager.cc:362] Metadata directory not provided
I20260812 06:18:22.667092 25556 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:18:22.667179 25556 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:18:22.667718 25556 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskAaiyNc/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515497224838-25556-0/minicluster-data/master-0-root/instance:
uuid: "cafec0dc95a441b48c45cbbda8c529b9"
format_stamp: "Formatted at 2026-08-12 06:18:22 on dist-test-slave-gsp7"
I20260812 06:18:22.669574 25556 fs_manager.cc:696] Time spent creating directory manager: real 0.002s	user 0.002s	sys 0.000s
I20260812 06:18:22.670526 25880 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:18:22.670766 25556 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.001s	sys 0.000s
I20260812 06:18:22.670842 25556 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskAaiyNc/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515497224838-25556-0/minicluster-data/master-0-root
uuid: "cafec0dc95a441b48c45cbbda8c529b9"
format_stamp: "Formatted at 2026-08-12 06:18:22 on dist-test-slave-gsp7"
I20260812 06:18:22.670902 25556 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskAaiyNc/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515497224838-25556-0/minicluster-data/master-0-root
metadata directory: /tmp/dist-test-taskAaiyNc/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515497224838-25556-0/minicluster-data/master-0-root
1 data directories: /tmp/dist-test-taskAaiyNc/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515497224838-25556-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:18:22.680963 25556 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:18:22.681327 25556 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:18:22.685395 25556 rpc_server.cc:307] RPC server started. Bound to: 127.24.245.62:39671
I20260812 06:18:22.685465 25962 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.24.245.62:39671 every 8 connection(s)
I20260812 06:18:22.686323 25963 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:18:22.688131 25963 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P cafec0dc95a441b48c45cbbda8c529b9: Bootstrap starting.
I20260812 06:18:22.688886 25963 tablet_bootstrap.cc:654] T 00000000000000000000000000000000 P cafec0dc95a441b48c45cbbda8c529b9: Neither blocks nor log segments found. Creating new log.
I20260812 06:18:22.689935 25963 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P cafec0dc95a441b48c45cbbda8c529b9: No bootstrap required, opened a new log
I20260812 06:18:22.690366 25963 raft_consensus.cc:359] T 00000000000000000000000000000000 P cafec0dc95a441b48c45cbbda8c529b9 [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "cafec0dc95a441b48c45cbbda8c529b9" member_type: VOTER }
I20260812 06:18:22.690485 25963 raft_consensus.cc:385] T 00000000000000000000000000000000 P cafec0dc95a441b48c45cbbda8c529b9 [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:18:22.690552 25963 raft_consensus.cc:740] T 00000000000000000000000000000000 P cafec0dc95a441b48c45cbbda8c529b9 [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: cafec0dc95a441b48c45cbbda8c529b9, State: Initialized, Role: FOLLOWER
I20260812 06:18:22.690747 25963 consensus_queue.cc:260] T 00000000000000000000000000000000 P cafec0dc95a441b48c45cbbda8c529b9 [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: "cafec0dc95a441b48c45cbbda8c529b9" member_type: VOTER }
I20260812 06:18:22.690861 25963 raft_consensus.cc:399] T 00000000000000000000000000000000 P cafec0dc95a441b48c45cbbda8c529b9 [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:18:22.690907 25963 raft_consensus.cc:493] T 00000000000000000000000000000000 P cafec0dc95a441b48c45cbbda8c529b9 [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:18:22.690969 25963 raft_consensus.cc:3060] T 00000000000000000000000000000000 P cafec0dc95a441b48c45cbbda8c529b9 [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:18:22.691677 25963 raft_consensus.cc:515] T 00000000000000000000000000000000 P cafec0dc95a441b48c45cbbda8c529b9 [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "cafec0dc95a441b48c45cbbda8c529b9" member_type: VOTER }
I20260812 06:18:22.691823 25963 leader_election.cc:304] T 00000000000000000000000000000000 P cafec0dc95a441b48c45cbbda8c529b9 [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: cafec0dc95a441b48c45cbbda8c529b9; no voters: 
I20260812 06:18:22.692037 25963 leader_election.cc:290] T 00000000000000000000000000000000 P cafec0dc95a441b48c45cbbda8c529b9 [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:18:22.692185 25969 raft_consensus.cc:2804] T 00000000000000000000000000000000 P cafec0dc95a441b48c45cbbda8c529b9 [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:18:22.692423 25969 raft_consensus.cc:697] T 00000000000000000000000000000000 P cafec0dc95a441b48c45cbbda8c529b9 [term 1 LEADER]: Becoming Leader. State: Replica: cafec0dc95a441b48c45cbbda8c529b9, State: Running, Role: LEADER
I20260812 06:18:22.692536 25963 sys_catalog.cc:565] T 00000000000000000000000000000000 P cafec0dc95a441b48c45cbbda8c529b9 [sys.catalog]: configured and running, proceeding with master startup.
I20260812 06:18:22.692605 25969 consensus_queue.cc:237] T 00000000000000000000000000000000 P cafec0dc95a441b48c45cbbda8c529b9 [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: "cafec0dc95a441b48c45cbbda8c529b9" member_type: VOTER }
I20260812 06:18:22.693080 25970 sys_catalog.cc:455] T 00000000000000000000000000000000 P cafec0dc95a441b48c45cbbda8c529b9 [sys.catalog]: SysCatalogTable state changed. Reason: RaftConsensus started. Latest consensus state: current_term: 1 leader_uuid: "cafec0dc95a441b48c45cbbda8c529b9" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "cafec0dc95a441b48c45cbbda8c529b9" member_type: VOTER } }
I20260812 06:18:22.693107 25971 sys_catalog.cc:455] T 00000000000000000000000000000000 P cafec0dc95a441b48c45cbbda8c529b9 [sys.catalog]: SysCatalogTable state changed. Reason: New leader cafec0dc95a441b48c45cbbda8c529b9. Latest consensus state: current_term: 1 leader_uuid: "cafec0dc95a441b48c45cbbda8c529b9" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "cafec0dc95a441b48c45cbbda8c529b9" member_type: VOTER } }
I20260812 06:18:22.693192 25970 sys_catalog.cc:458] T 00000000000000000000000000000000 P cafec0dc95a441b48c45cbbda8c529b9 [sys.catalog]: This master's current role is: LEADER
I20260812 06:18:22.693202 25971 sys_catalog.cc:458] T 00000000000000000000000000000000 P cafec0dc95a441b48c45cbbda8c529b9 [sys.catalog]: This master's current role is: LEADER
I20260812 06:18:22.693531 25976 catalog_manager.cc:1511] Loading table and tablet metadata into memory...
I20260812 06:18:22.694451 25976 catalog_manager.cc:1520] Initializing Kudu cluster ID...
I20260812 06:18:22.694703 25556 internal_mini_cluster.cc:184] Waiting to initialize catalog manager on master 0
I20260812 06:18:22.696280 25976 catalog_manager.cc:1383] Generated new cluster ID: a34569cc1e2945109e795c45af5be113
I20260812 06:18:22.696357 25976 catalog_manager.cc:1531] Initializing Kudu internal certificate authority...
I20260812 06:18:22.705032 25976 catalog_manager.cc:1406] Generated new certificate authority record
I20260812 06:18:22.705686 25976 catalog_manager.cc:1540] Loading token signing keys...
I20260812 06:18:22.721215 25976 catalog_manager.cc:6092] T 00000000000000000000000000000000 P cafec0dc95a441b48c45cbbda8c529b9: Generated new TSK 0
I20260812 06:18:22.721452 25976 catalog_manager.cc:1550] Initializing in-progress tserver states...
I20260812 06:18:22.727005 25556 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:18:22.728922 26015 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:18:22.728997 26008 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:18:22.729103 26003 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:18:22.729140 25556 server_base.cc:1061] running on GCE node
I20260812 06:18:22.729357 25556 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:18:22.729405 25556 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:18:22.729421 25556 hybrid_clock.cc:648] HybridClock initialized: now 1786515502729421 us; error 0 us; skew 500 ppm
I20260812 06:18:22.730330 25556 webserver.cc:533] Webserver started at http://127.24.245.1:46123/ using document root <none> and password file <none>
I20260812 06:18:22.730525 25556 fs_manager.cc:362] Metadata directory not provided
I20260812 06:18:22.730600 25556 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:18:22.730703 25556 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:18:22.731112 25556 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskAaiyNc/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515497224838-25556-0/minicluster-data/ts-0-root/instance:
uuid: "335f41be1ab3410596f56b1eb13a65f8"
format_stamp: "Formatted at 2026-08-12 06:18:22 on dist-test-slave-gsp7"
I20260812 06:18:22.732611 25556 fs_manager.cc:696] Time spent creating directory manager: real 0.001s	user 0.002s	sys 0.000s
I20260812 06:18:22.733620 26026 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:18:22.733870 25556 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.001s	sys 0.000s
I20260812 06:18:22.733949 25556 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskAaiyNc/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515497224838-25556-0/minicluster-data/ts-0-root
uuid: "335f41be1ab3410596f56b1eb13a65f8"
format_stamp: "Formatted at 2026-08-12 06:18:22 on dist-test-slave-gsp7"
I20260812 06:18:22.734011 25556 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskAaiyNc/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515497224838-25556-0/minicluster-data/ts-0-root
metadata directory: /tmp/dist-test-taskAaiyNc/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515497224838-25556-0/minicluster-data/ts-0-root
1 data directories: /tmp/dist-test-taskAaiyNc/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515497224838-25556-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:18:22.762040 25556 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:18:22.762451 25556 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:18:22.762763 25556 txn_system_client.cc:432] TxnSystemClient initialization is disabled...
I20260812 06:18:22.763284 25556 ts_tablet_manager.cc:585] Loaded tablet metadata (0 total tablets, 0 live tablets)
I20260812 06:18:22.763330 25556 ts_tablet_manager.cc:531] Time spent load tablet metadata: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:18:22.763396 25556 ts_tablet_manager.cc:616] Registered 0 tablets
I20260812 06:18:22.763438 25556 ts_tablet_manager.cc:595] Time spent register tablets: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:18:22.767887 25556 rpc_server.cc:307] RPC server started. Bound to: 127.24.245.1:36457
I20260812 06:18:22.768262 26113 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.24.245.1:36457 every 8 connection(s)
I20260812 06:18:22.776288 26114 heartbeater.cc:344] Connected to a master server at 127.24.245.62:39671
I20260812 06:18:22.776420 26114 heartbeater.cc:461] Registering TS with master...
I20260812 06:18:22.776697 26114 heartbeater.cc:507] Master 127.24.245.62:39671 requested a full tablet report, sending...
I20260812 06:18:22.777526 25913 ts_manager.cc:194] Registered new tserver with Master: 335f41be1ab3410596f56b1eb13a65f8 (127.24.245.1:36457)
I20260812 06:18:22.778267 25913 master_service.cc:502] Signed X509 certificate for tserver {username='slave'} at 127.0.0.1:41708
I20260812 06:18:22.778478 25556 internal_mini_cluster.cc:371] 1 TS(s) registered with all masters after 0.010002368s
I20260812 06:18:22.786276 25913 catalog_manager.cc:2283] Servicing CreateTable request from {username='slave'} at 127.0.0.1:41712:
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:18:22.795816 26063 tablet_service.cc:1511] Processing CreateTablet for tablet 3ae6458ccac543e693e6da1edf15b2ea (DEFAULT_TABLE table=heavy-update-compaction-test [id=9627494b00a04467adaaaadf2e098b48]), partition=
I20260812 06:18:22.796132 26063 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet 3ae6458ccac543e693e6da1edf15b2ea. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:18:22.798211 26133 tablet_bootstrap.cc:492] T 3ae6458ccac543e693e6da1edf15b2ea P 335f41be1ab3410596f56b1eb13a65f8: Bootstrap starting.
I20260812 06:18:22.799091 26133 tablet_bootstrap.cc:654] T 3ae6458ccac543e693e6da1edf15b2ea P 335f41be1ab3410596f56b1eb13a65f8: Neither blocks nor log segments found. Creating new log.
I20260812 06:18:22.800206 26133 tablet_bootstrap.cc:492] T 3ae6458ccac543e693e6da1edf15b2ea P 335f41be1ab3410596f56b1eb13a65f8: No bootstrap required, opened a new log
I20260812 06:18:22.800284 26133 ts_tablet_manager.cc:1403] T 3ae6458ccac543e693e6da1edf15b2ea P 335f41be1ab3410596f56b1eb13a65f8: Time spent bootstrapping tablet: real 0.002s	user 0.001s	sys 0.000s
I20260812 06:18:22.800655 26133 raft_consensus.cc:359] T 3ae6458ccac543e693e6da1edf15b2ea P 335f41be1ab3410596f56b1eb13a65f8 [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "335f41be1ab3410596f56b1eb13a65f8" member_type: VOTER last_known_addr { host: "127.24.245.1" port: 36457 } }
I20260812 06:18:22.800746 26133 raft_consensus.cc:385] T 3ae6458ccac543e693e6da1edf15b2ea P 335f41be1ab3410596f56b1eb13a65f8 [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:18:22.800769 26133 raft_consensus.cc:740] T 3ae6458ccac543e693e6da1edf15b2ea P 335f41be1ab3410596f56b1eb13a65f8 [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: 335f41be1ab3410596f56b1eb13a65f8, State: Initialized, Role: FOLLOWER
I20260812 06:18:22.800911 26133 consensus_queue.cc:260] T 3ae6458ccac543e693e6da1edf15b2ea P 335f41be1ab3410596f56b1eb13a65f8 [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: "335f41be1ab3410596f56b1eb13a65f8" member_type: VOTER last_known_addr { host: "127.24.245.1" port: 36457 } }
I20260812 06:18:22.801025 26133 raft_consensus.cc:399] T 3ae6458ccac543e693e6da1edf15b2ea P 335f41be1ab3410596f56b1eb13a65f8 [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:18:22.801079 26133 raft_consensus.cc:493] T 3ae6458ccac543e693e6da1edf15b2ea P 335f41be1ab3410596f56b1eb13a65f8 [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:18:22.801131 26133 raft_consensus.cc:3060] T 3ae6458ccac543e693e6da1edf15b2ea P 335f41be1ab3410596f56b1eb13a65f8 [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:18:22.802105 26133 raft_consensus.cc:515] T 3ae6458ccac543e693e6da1edf15b2ea P 335f41be1ab3410596f56b1eb13a65f8 [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "335f41be1ab3410596f56b1eb13a65f8" member_type: VOTER last_known_addr { host: "127.24.245.1" port: 36457 } }
I20260812 06:18:22.802258 26133 leader_election.cc:304] T 3ae6458ccac543e693e6da1edf15b2ea P 335f41be1ab3410596f56b1eb13a65f8 [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: 335f41be1ab3410596f56b1eb13a65f8; no voters: 
I20260812 06:18:22.802505 26133 leader_election.cc:290] T 3ae6458ccac543e693e6da1edf15b2ea P 335f41be1ab3410596f56b1eb13a65f8 [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:18:22.802642 26137 raft_consensus.cc:2804] T 3ae6458ccac543e693e6da1edf15b2ea P 335f41be1ab3410596f56b1eb13a65f8 [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:18:22.802866 26133 ts_tablet_manager.cc:1434] T 3ae6458ccac543e693e6da1edf15b2ea P 335f41be1ab3410596f56b1eb13a65f8: Time spent starting tablet: real 0.003s	user 0.003s	sys 0.000s
I20260812 06:18:22.802899 26114 heartbeater.cc:499] Master 127.24.245.62:39671 was elected leader, sending a full tablet report...
I20260812 06:18:22.802884 26137 raft_consensus.cc:697] T 3ae6458ccac543e693e6da1edf15b2ea P 335f41be1ab3410596f56b1eb13a65f8 [term 1 LEADER]: Becoming Leader. State: Replica: 335f41be1ab3410596f56b1eb13a65f8, State: Running, Role: LEADER
I20260812 06:18:22.803258 26137 consensus_queue.cc:237] T 3ae6458ccac543e693e6da1edf15b2ea P 335f41be1ab3410596f56b1eb13a65f8 [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: "335f41be1ab3410596f56b1eb13a65f8" member_type: VOTER last_known_addr { host: "127.24.245.1" port: 36457 } }
I20260812 06:18:22.804597 25913 catalog_manager.cc:5719] T 3ae6458ccac543e693e6da1edf15b2ea P 335f41be1ab3410596f56b1eb13a65f8 reported cstate change: term changed from 0 to 1, leader changed from <none> to 335f41be1ab3410596f56b1eb13a65f8 (127.24.245.1). New cstate: current_term: 1 leader_uuid: "335f41be1ab3410596f56b1eb13a65f8" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "335f41be1ab3410596f56b1eb13a65f8" member_type: VOTER last_known_addr { host: "127.24.245.1" port: 36457 } health_report { overall_health: HEALTHY } } }
I20260812 06:18:22.863528 25556 heavy-update-compaction-itest.cc:215] Time spent inserting: real 0.052s	user 0.015s	sys 0.007s
I20260812 06:18:23.019088 26116 maintenance_manager.cc:419] P 335f41be1ab3410596f56b1eb13a65f8: Scheduling FlushMRSOp(3ae6458ccac543e693e6da1edf15b2ea): perf score=19.054940
I20260812 06:18:23.185468 26031 maintenance_manager.cc:643] P 335f41be1ab3410596f56b1eb13a65f8: FlushMRSOp(3ae6458ccac543e693e6da1edf15b2ea) complete. Timing: real 0.166s	user 0.118s	sys 0.044s Metrics: {"bytes_written":11897250,"cfile_init":1,"delete_count":0,"dirs.queue_time_us":80,"dirs.run_cpu_time_us":257,"dirs.run_wall_time_us":1006,"drs_written":1,"lbm_read_time_us":38,"lbm_reads_lt_1ms":4,"lbm_write_time_us":42925,"lbm_writes_lt_1ms":757,"peak_mem_usage":0,"reinsert_count":0,"rows_written":105,"update_count":1450}
I20260812 06:18:23.186133 26116 maintenance_manager.cc:419] P 335f41be1ab3410596f56b1eb13a65f8: Scheduling LogGCOp(3ae6458ccac543e693e6da1edf15b2ea): free 20290830 bytes of WAL
I20260812 06:18:23.186378 26031 log_reader.cc:385] T 3ae6458ccac543e693e6da1edf15b2ea: removed 2 log segments from log reader
I20260812 06:18:23.186429 26031 log.cc:1079] T 3ae6458ccac543e693e6da1edf15b2ea P 335f41be1ab3410596f56b1eb13a65f8: Deleting log segment in path: /tmp/dist-test-taskAaiyNc/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515497224838-25556-0/minicluster-data/ts-0-root/wals/3ae6458ccac543e693e6da1edf15b2ea/wal-000000001 (ops 1-6)
I20260812 06:18:23.186460 26031 log.cc:1079] T 3ae6458ccac543e693e6da1edf15b2ea P 335f41be1ab3410596f56b1eb13a65f8: Deleting log segment in path: /tmp/dist-test-taskAaiyNc/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515497224838-25556-0/minicluster-data/ts-0-root/wals/3ae6458ccac543e693e6da1edf15b2ea/wal-000000002 (ops 7-10)
I20260812 06:18:23.191435 26031 maintenance_manager.cc:643] P 335f41be1ab3410596f56b1eb13a65f8: LogGCOp(3ae6458ccac543e693e6da1edf15b2ea) complete. Timing: real 0.005s	user 0.000s	sys 0.003s Metrics: {}
I20260812 06:18:23.191854 26116 maintenance_manager.cc:419] P 335f41be1ab3410596f56b1eb13a65f8: Scheduling UndoDeltaBlockGCOp(3ae6458ccac543e693e6da1edf15b2ea): 16821648 bytes on disk
I20260812 06:18:23.192413 26031 maintenance_manager.cc:643] P 335f41be1ab3410596f56b1eb13a65f8: UndoDeltaBlockGCOp(3ae6458ccac543e693e6da1edf15b2ea) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":79,"lbm_reads_lt_1ms":4}
I20260812 06:18:23.192874 26116 maintenance_manager.cc:419] P 335f41be1ab3410596f56b1eb13a65f8: Scheduling FlushDeltaMemStoresOp(3ae6458ccac543e693e6da1edf15b2ea): perf score=2.188937
I20260812 06:18:23.226550 26031 maintenance_manager.cc:643] P 335f41be1ab3410596f56b1eb13a65f8: FlushDeltaMemStoresOp(3ae6458ccac543e693e6da1edf15b2ea) complete. Timing: real 0.033s	user 0.008s	sys 0.013s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":5379,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:23.227082 26116 maintenance_manager.cc:419] P 335f41be1ab3410596f56b1eb13a65f8: Scheduling FlushDeltaMemStoresOp(3ae6458ccac543e693e6da1edf15b2ea): perf score=2.188937
I20260812 06:18:23.238245 26031 maintenance_manager.cc:643] P 335f41be1ab3410596f56b1eb13a65f8: FlushDeltaMemStoresOp(3ae6458ccac543e693e6da1edf15b2ea) complete. Timing: real 0.011s	user 0.009s	sys 0.001s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4425,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:23.238684 26116 maintenance_manager.cc:419] P 335f41be1ab3410596f56b1eb13a65f8: Scheduling MajorDeltaCompactionOp(3ae6458ccac543e693e6da1edf15b2ea): perf score=1.000000
I20260812 06:18:23.427593 26031 maintenance_manager.cc:643] P 335f41be1ab3410596f56b1eb13a65f8: MajorDeltaCompactionOp(3ae6458ccac543e693e6da1edf15b2ea) complete. Timing: real 0.189s	user 0.126s	sys 0.059s Metrics: {"cfile_cache_miss":523,"cfile_cache_miss_bytes":24405561,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":400,"lbm_read_time_us":13353,"lbm_reads_lt_1ms":559,"lbm_write_time_us":28854,"lbm_writes_lt_1ms":533,"peak_mem_usage":61665166,"reinsert_count":0,"spinlock_wait_cycles":6272,"thread_start_us":327,"threads_started":5,"update_count":2450}
I20260812 06:18:23.428143 26116 maintenance_manager.cc:419] P 335f41be1ab3410596f56b1eb13a65f8: Scheduling FlushDeltaMemStoresOp(3ae6458ccac543e693e6da1edf15b2ea): perf score=11.118625
I20260812 06:18:23.468338 26031 maintenance_manager.cc:643] P 335f41be1ab3410596f56b1eb13a65f8: FlushDeltaMemStoresOp(3ae6458ccac543e693e6da1edf15b2ea) complete. Timing: real 0.040s	user 0.035s	sys 0.002s Metrics: {"bytes_written":12717736,"delete_count":0,"lbm_write_time_us":16713,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:18:23.469074 26116 maintenance_manager.cc:419] P 335f41be1ab3410596f56b1eb13a65f8: Scheduling FlushDeltaMemStoresOp(3ae6458ccac543e693e6da1edf15b2ea): perf score=2.188937
I20260812 06:18:23.493858 26031 maintenance_manager.cc:643] P 335f41be1ab3410596f56b1eb13a65f8: FlushDeltaMemStoresOp(3ae6458ccac543e693e6da1edf15b2ea) complete. Timing: real 0.024s	user 0.013s	sys 0.000s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":4678,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:18:23.494354 26116 maintenance_manager.cc:419] P 335f41be1ab3410596f56b1eb13a65f8: Scheduling FlushDeltaMemStoresOp(3ae6458ccac543e693e6da1edf15b2ea): perf score=2.188937
I20260812 06:18:23.505052 26031 maintenance_manager.cc:643] P 335f41be1ab3410596f56b1eb13a65f8: FlushDeltaMemStoresOp(3ae6458ccac543e693e6da1edf15b2ea) complete. Timing: real 0.011s	user 0.009s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3940,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:23.505575 26116 maintenance_manager.cc:419] P 335f41be1ab3410596f56b1eb13a65f8: Scheduling MajorDeltaCompactionOp(3ae6458ccac543e693e6da1edf15b2ea): perf score=1.000000
I20260812 06:18:23.709319 26031 maintenance_manager.cc:643] P 335f41be1ab3410596f56b1eb13a65f8: MajorDeltaCompactionOp(3ae6458ccac543e693e6da1edf15b2ea) complete. Timing: real 0.204s	user 0.116s	sys 0.074s Metrics: {"cfile_cache_miss":533,"cfile_cache_miss_bytes":24815795,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":1796,"lbm_read_time_us":11020,"lbm_reads_lt_1ms":573,"lbm_write_time_us":31318,"lbm_writes_lt_1ms":543,"mutex_wait_us":634,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":21632,"update_count":2500}
I20260812 06:18:23.709959 26116 maintenance_manager.cc:419] P 335f41be1ab3410596f56b1eb13a65f8: Scheduling FlushDeltaMemStoresOp(3ae6458ccac543e693e6da1edf15b2ea): perf score=14.095187
I20260812 06:18:23.764259 26031 maintenance_manager.cc:643] P 335f41be1ab3410596f56b1eb13a65f8: FlushDeltaMemStoresOp(3ae6458ccac543e693e6da1edf15b2ea) complete. Timing: real 0.054s	user 0.035s	sys 0.011s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":20329,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:18:23.764734 26116 maintenance_manager.cc:419] P 335f41be1ab3410596f56b1eb13a65f8: Scheduling FlushDeltaMemStoresOp(3ae6458ccac543e693e6da1edf15b2ea): perf score=2.188937
I20260812 06:18:23.775615 26031 maintenance_manager.cc:643] P 335f41be1ab3410596f56b1eb13a65f8: FlushDeltaMemStoresOp(3ae6458ccac543e693e6da1edf15b2ea) complete. Timing: real 0.011s	user 0.000s	sys 0.009s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4280,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:23.776198 26116 maintenance_manager.cc:419] P 335f41be1ab3410596f56b1eb13a65f8: Scheduling MajorDeltaCompactionOp(3ae6458ccac543e693e6da1edf15b2ea): perf score=1.000000
I20260812 06:18:23.941641 26031 maintenance_manager.cc:643] P 335f41be1ab3410596f56b1eb13a65f8: MajorDeltaCompactionOp(3ae6458ccac543e693e6da1edf15b2ea) complete. Timing: real 0.165s	user 0.111s	sys 0.049s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24815683,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":885,"lbm_read_time_us":12121,"lbm_reads_lt_1ms":572,"lbm_write_time_us":29926,"lbm_writes_lt_1ms":543,"mutex_wait_us":342,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":22272,"update_count":2500}
I20260812 06:18:23.942289 26116 maintenance_manager.cc:419] P 335f41be1ab3410596f56b1eb13a65f8: Scheduling FlushDeltaMemStoresOp(3ae6458ccac543e693e6da1edf15b2ea): perf score=11.118625
I20260812 06:18:23.979444 26031 maintenance_manager.cc:643] P 335f41be1ab3410596f56b1eb13a65f8: FlushDeltaMemStoresOp(3ae6458ccac543e693e6da1edf15b2ea) complete. Timing: real 0.037s	user 0.019s	sys 0.016s Metrics: {"bytes_written":12717734,"delete_count":0,"lbm_write_time_us":15596,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:18:23.980720 26116 maintenance_manager.cc:419] P 335f41be1ab3410596f56b1eb13a65f8: Scheduling FlushDeltaMemStoresOp(3ae6458ccac543e693e6da1edf15b2ea): perf score=2.188937
I20260812 06:18:23.997109 26031 maintenance_manager.cc:643] P 335f41be1ab3410596f56b1eb13a65f8: FlushDeltaMemStoresOp(3ae6458ccac543e693e6da1edf15b2ea) complete. Timing: real 0.015s	user 0.008s	sys 0.004s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":5563,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:18:23.997699 26116 maintenance_manager.cc:419] P 335f41be1ab3410596f56b1eb13a65f8: Scheduling MajorDeltaCompactionOp(3ae6458ccac543e693e6da1edf15b2ea): perf score=1.000000
I20260812 06:18:24.124243 26031 maintenance_manager.cc:643] P 335f41be1ab3410596f56b1eb13a65f8: MajorDeltaCompactionOp(3ae6458ccac543e693e6da1edf15b2ea) complete. Timing: real 0.126s	user 0.097s	sys 0.029s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20713262,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":787,"lbm_read_time_us":7444,"lbm_reads_lt_1ms":464,"lbm_write_time_us":24582,"lbm_writes_lt_1ms":443,"peak_mem_usage":50689328,"reinsert_count":0,"update_count":2000}
I20260812 06:18:24.124969 26116 maintenance_manager.cc:419] P 335f41be1ab3410596f56b1eb13a65f8: Scheduling FlushDeltaMemStoresOp(3ae6458ccac543e693e6da1edf15b2ea): perf score=10.126437
I20260812 06:18:24.165894 26031 maintenance_manager.cc:643] P 335f41be1ab3410596f56b1eb13a65f8: FlushDeltaMemStoresOp(3ae6458ccac543e693e6da1edf15b2ea) complete. Timing: real 0.041s	user 0.021s	sys 0.019s Metrics: {"bytes_written":12430563,"delete_count":0,"lbm_write_time_us":20122,"lbm_writes_1-10_ms":2,"lbm_writes_lt_1ms":304,"reinsert_count":0,"update_count":1515}
I20260812 06:18:24.166553 26116 maintenance_manager.cc:419] P 335f41be1ab3410596f56b1eb13a65f8: Scheduling FlushDeltaMemStoresOp(3ae6458ccac543e693e6da1edf15b2ea): perf score=2.188937
I20260812 06:18:24.181341 26031 maintenance_manager.cc:643] P 335f41be1ab3410596f56b1eb13a65f8: FlushDeltaMemStoresOp(3ae6458ccac543e693e6da1edf15b2ea) complete. Timing: real 0.015s	user 0.004s	sys 0.008s Metrics: {"bytes_written":3979584,"delete_count":0,"lbm_write_time_us":5666,"lbm_writes_lt_1ms":100,"reinsert_count":0,"update_count":485}
I20260812 06:18:24.181936 26116 maintenance_manager.cc:419] P 335f41be1ab3410596f56b1eb13a65f8: Scheduling MajorDeltaCompactionOp(3ae6458ccac543e693e6da1edf15b2ea): perf score=1.000000
I20260812 06:18:24.299021 26031 maintenance_manager.cc:643] P 335f41be1ab3410596f56b1eb13a65f8: MajorDeltaCompactionOp(3ae6458ccac543e693e6da1edf15b2ea) complete. Timing: real 0.117s	user 0.106s	sys 0.010s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20713270,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":361,"lbm_read_time_us":8034,"lbm_reads_lt_1ms":468,"lbm_write_time_us":22990,"lbm_writes_lt_1ms":443,"mutex_wait_us":41,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":13696,"update_count":2000}
I20260812 06:18:24.299605 26116 maintenance_manager.cc:419] P 335f41be1ab3410596f56b1eb13a65f8: Scheduling FlushDeltaMemStoresOp(3ae6458ccac543e693e6da1edf15b2ea): perf score=10.126437
I20260812 06:18:24.353571 26031 maintenance_manager.cc:643] P 335f41be1ab3410596f56b1eb13a65f8: FlushDeltaMemStoresOp(3ae6458ccac543e693e6da1edf15b2ea) complete. Timing: real 0.054s	user 0.030s	sys 0.023s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":16830,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:18:24.354298 26116 maintenance_manager.cc:419] P 335f41be1ab3410596f56b1eb13a65f8: Scheduling FlushDeltaMemStoresOp(3ae6458ccac543e693e6da1edf15b2ea): perf score=2.188937
I20260812 06:18:24.370975 26031 maintenance_manager.cc:643] P 335f41be1ab3410596f56b1eb13a65f8: FlushDeltaMemStoresOp(3ae6458ccac543e693e6da1edf15b2ea) complete. Timing: real 0.016s	user 0.014s	sys 0.001s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6458,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:24.371495 26116 maintenance_manager.cc:419] P 335f41be1ab3410596f56b1eb13a65f8: Scheduling MajorDeltaCompactionOp(3ae6458ccac543e693e6da1edf15b2ea): perf score=1.000000
I20260812 06:18:24.533389 26031 maintenance_manager.cc:643] P 335f41be1ab3410596f56b1eb13a65f8: MajorDeltaCompactionOp(3ae6458ccac543e693e6da1edf15b2ea) complete. Timing: real 0.162s	user 0.121s	sys 0.040s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20713272,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":844,"lbm_read_time_us":11194,"lbm_reads_lt_1ms":472,"lbm_write_time_us":25554,"lbm_writes_lt_1ms":443,"mutex_wait_us":69,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":1920,"update_count":2000}
I20260812 06:18:24.534225 26116 maintenance_manager.cc:419] P 335f41be1ab3410596f56b1eb13a65f8: Scheduling FlushDeltaMemStoresOp(3ae6458ccac543e693e6da1edf15b2ea): perf score=10.126437
I20260812 06:18:24.579190 26031 maintenance_manager.cc:643] P 335f41be1ab3410596f56b1eb13a65f8: FlushDeltaMemStoresOp(3ae6458ccac543e693e6da1edf15b2ea) complete. Timing: real 0.045s	user 0.012s	sys 0.024s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":16318,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:18:24.579753 26116 maintenance_manager.cc:419] P 335f41be1ab3410596f56b1eb13a65f8: Scheduling FlushDeltaMemStoresOp(3ae6458ccac543e693e6da1edf15b2ea): perf score=2.188937
I20260812 06:18:24.592265 26031 maintenance_manager.cc:643] P 335f41be1ab3410596f56b1eb13a65f8: FlushDeltaMemStoresOp(3ae6458ccac543e693e6da1edf15b2ea) complete. Timing: real 0.012s	user 0.009s	sys 0.000s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4223,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:24.592922 26116 maintenance_manager.cc:419] P 335f41be1ab3410596f56b1eb13a65f8: Scheduling FlushMRSOp(3ae6458ccac543e693e6da1edf15b2ea): perf score=1.000000
I20260812 06:18:24.622368 26031 maintenance_manager.cc:643] P 335f41be1ab3410596f56b1eb13a65f8: FlushMRSOp(3ae6458ccac543e693e6da1edf15b2ea) complete. Timing: real 0.029s	user 0.028s	sys 0.000s Metrics: {"bytes_written":1234473,"cfile_init":1,"dirs.queue_time_us":46,"dirs.run_cpu_time_us":255,"dirs.run_wall_time_us":1286,"drs_written":1,"lbm_read_time_us":41,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1734,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":30}
I20260812 06:18:24.622972 26116 maintenance_manager.cc:419] P 335f41be1ab3410596f56b1eb13a65f8: Scheduling LogGCOp(3ae6458ccac543e693e6da1edf15b2ea): free 121006383 bytes of WAL
I20260812 06:18:24.623211 26031 log_reader.cc:385] T 3ae6458ccac543e693e6da1edf15b2ea: removed 12 log segments from log reader
I20260812 06:18:24.623256 26031 log.cc:1079] T 3ae6458ccac543e693e6da1edf15b2ea P 335f41be1ab3410596f56b1eb13a65f8: Deleting log segment in path: /tmp/dist-test-taskAaiyNc/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515497224838-25556-0/minicluster-data/ts-0-root/wals/3ae6458ccac543e693e6da1edf15b2ea/wal-000000003 (ops 11-15)
I20260812 06:18:24.623314 26031 log.cc:1079] T 3ae6458ccac543e693e6da1edf15b2ea P 335f41be1ab3410596f56b1eb13a65f8: Deleting log segment in path: /tmp/dist-test-taskAaiyNc/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515497224838-25556-0/minicluster-data/ts-0-root/wals/3ae6458ccac543e693e6da1edf15b2ea/wal-000000004 (ops 16-20)
I20260812 06:18:24.623361 26031 log.cc:1079] T 3ae6458ccac543e693e6da1edf15b2ea P 335f41be1ab3410596f56b1eb13a65f8: Deleting log segment in path: /tmp/dist-test-taskAaiyNc/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515497224838-25556-0/minicluster-data/ts-0-root/wals/3ae6458ccac543e693e6da1edf15b2ea/wal-000000005 (ops 21-25)
I20260812 06:18:24.623400 26031 log.cc:1079] T 3ae6458ccac543e693e6da1edf15b2ea P 335f41be1ab3410596f56b1eb13a65f8: Deleting log segment in path: /tmp/dist-test-taskAaiyNc/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515497224838-25556-0/minicluster-data/ts-0-root/wals/3ae6458ccac543e693e6da1edf15b2ea/wal-000000006 (ops 26-30)
I20260812 06:18:24.623436 26031 log.cc:1079] T 3ae6458ccac543e693e6da1edf15b2ea P 335f41be1ab3410596f56b1eb13a65f8: Deleting log segment in path: /tmp/dist-test-taskAaiyNc/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515497224838-25556-0/minicluster-data/ts-0-root/wals/3ae6458ccac543e693e6da1edf15b2ea/wal-000000007 (ops 31-34)
I20260812 06:18:24.623487 26031 log.cc:1079] T 3ae6458ccac543e693e6da1edf15b2ea P 335f41be1ab3410596f56b1eb13a65f8: Deleting log segment in path: /tmp/dist-test-taskAaiyNc/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515497224838-25556-0/minicluster-data/ts-0-root/wals/3ae6458ccac543e693e6da1edf15b2ea/wal-000000008 (ops 35-39)
I20260812 06:18:24.623521 26031 log.cc:1079] T 3ae6458ccac543e693e6da1edf15b2ea P 335f41be1ab3410596f56b1eb13a65f8: Deleting log segment in path: /tmp/dist-test-taskAaiyNc/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515497224838-25556-0/minicluster-data/ts-0-root/wals/3ae6458ccac543e693e6da1edf15b2ea/wal-000000009 (ops 40-44)
I20260812 06:18:24.623561 26031 log.cc:1079] T 3ae6458ccac543e693e6da1edf15b2ea P 335f41be1ab3410596f56b1eb13a65f8: Deleting log segment in path: /tmp/dist-test-taskAaiyNc/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515497224838-25556-0/minicluster-data/ts-0-root/wals/3ae6458ccac543e693e6da1edf15b2ea/wal-000000010 (ops 45-49)
I20260812 06:18:24.623598 26031 log.cc:1079] T 3ae6458ccac543e693e6da1edf15b2ea P 335f41be1ab3410596f56b1eb13a65f8: Deleting log segment in path: /tmp/dist-test-taskAaiyNc/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515497224838-25556-0/minicluster-data/ts-0-root/wals/3ae6458ccac543e693e6da1edf15b2ea/wal-000000011 (ops 50-54)
I20260812 06:18:24.623636 26031 log.cc:1079] T 3ae6458ccac543e693e6da1edf15b2ea P 335f41be1ab3410596f56b1eb13a65f8: Deleting log segment in path: /tmp/dist-test-taskAaiyNc/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515497224838-25556-0/minicluster-data/ts-0-root/wals/3ae6458ccac543e693e6da1edf15b2ea/wal-000000012 (ops 55-59)
I20260812 06:18:24.623674 26031 log.cc:1079] T 3ae6458ccac543e693e6da1edf15b2ea P 335f41be1ab3410596f56b1eb13a65f8: Deleting log segment in path: /tmp/dist-test-taskAaiyNc/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515497224838-25556-0/minicluster-data/ts-0-root/wals/3ae6458ccac543e693e6da1edf15b2ea/wal-000000013 (ops 60-64)
I20260812 06:18:24.623711 26031 log.cc:1079] T 3ae6458ccac543e693e6da1edf15b2ea P 335f41be1ab3410596f56b1eb13a65f8: Deleting log segment in path: /tmp/dist-test-taskAaiyNc/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515497224838-25556-0/minicluster-data/ts-0-root/wals/3ae6458ccac543e693e6da1edf15b2ea/wal-000000014 (ops 65-69)
I20260812 06:18:24.649250 26031 maintenance_manager.cc:643] P 335f41be1ab3410596f56b1eb13a65f8: LogGCOp(3ae6458ccac543e693e6da1edf15b2ea) complete. Timing: real 0.026s	user 0.008s	sys 0.015s Metrics: {}
I20260812 06:18:24.649832 26116 maintenance_manager.cc:419] P 335f41be1ab3410596f56b1eb13a65f8: Scheduling UndoDeltaBlockGCOp(3ae6458ccac543e693e6da1edf15b2ea): 472 bytes on disk
I20260812 06:18:24.650364 26031 maintenance_manager.cc:643] P 335f41be1ab3410596f56b1eb13a65f8: UndoDeltaBlockGCOp(3ae6458ccac543e693e6da1edf15b2ea) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":57,"lbm_reads_lt_1ms":4}
I20260812 06:18:24.650835 26116 maintenance_manager.cc:419] P 335f41be1ab3410596f56b1eb13a65f8: Scheduling FlushDeltaMemStoresOp(3ae6458ccac543e693e6da1edf15b2ea): perf score=4.173312
I20260812 06:18:24.673264 26031 maintenance_manager.cc:643] P 335f41be1ab3410596f56b1eb13a65f8: FlushDeltaMemStoresOp(3ae6458ccac543e693e6da1edf15b2ea) complete. Timing: real 0.022s	user 0.012s	sys 0.007s Metrics: {"bytes_written":5415441,"delete_count":0,"lbm_write_time_us":5555,"lbm_writes_lt_1ms":135,"reinsert_count":0,"update_count":660}
I20260812 06:18:24.673836 26116 maintenance_manager.cc:419] P 335f41be1ab3410596f56b1eb13a65f8: Scheduling FlushDeltaMemStoresOp(3ae6458ccac543e693e6da1edf15b2ea): perf score=1.196750
I20260812 06:18:24.682147 26031 maintenance_manager.cc:643] P 335f41be1ab3410596f56b1eb13a65f8: FlushDeltaMemStoresOp(3ae6458ccac543e693e6da1edf15b2ea) complete. Timing: real 0.008s	user 0.007s	sys 0.001s Metrics: {"bytes_written":2789855,"delete_count":0,"lbm_write_time_us":2825,"lbm_writes_lt_1ms":71,"reinsert_count":0,"update_count":340}
I20260812 06:18:24.682600 26116 maintenance_manager.cc:419] P 335f41be1ab3410596f56b1eb13a65f8: Scheduling MajorDeltaCompactionOp(3ae6458ccac543e693e6da1edf15b2ea): perf score=1.000000
I20260812 06:18:24.900514 26031 maintenance_manager.cc:643] P 335f41be1ab3410596f56b1eb13a65f8: MajorDeltaCompactionOp(3ae6458ccac543e693e6da1edf15b2ea) complete. Timing: real 0.218s	user 0.130s	sys 0.087s Metrics: {"cfile_cache_miss":634,"cfile_cache_miss_bytes":28918305,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":2039,"lbm_read_time_us":15586,"lbm_reads_lt_1ms":674,"lbm_write_time_us":35259,"lbm_writes_lt_1ms":643,"mutex_wait_us":765,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":20864,"thread_start_us":77,"threads_started":1,"update_count":3000}
I20260812 06:18:24.901458 26116 maintenance_manager.cc:419] P 335f41be1ab3410596f56b1eb13a65f8: Scheduling FlushDeltaMemStoresOp(3ae6458ccac543e693e6da1edf15b2ea): perf score=14.095187
I20260812 06:18:24.961769 26031 maintenance_manager.cc:643] P 335f41be1ab3410596f56b1eb13a65f8: FlushDeltaMemStoresOp(3ae6458ccac543e693e6da1edf15b2ea) complete. Timing: real 0.060s	user 0.035s	sys 0.021s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":19834,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:18:24.962416 26116 maintenance_manager.cc:419] P 335f41be1ab3410596f56b1eb13a65f8: Scheduling FlushDeltaMemStoresOp(3ae6458ccac543e693e6da1edf15b2ea): perf score=2.188937
I20260812 06:18:24.978904 26031 maintenance_manager.cc:643] P 335f41be1ab3410596f56b1eb13a65f8: FlushDeltaMemStoresOp(3ae6458ccac543e693e6da1edf15b2ea) complete. Timing: real 0.016s	user 0.006s	sys 0.009s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":6186,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:24.979559 26116 maintenance_manager.cc:419] P 335f41be1ab3410596f56b1eb13a65f8: Scheduling MajorDeltaCompactionOp(3ae6458ccac543e693e6da1edf15b2ea): perf score=1.000000
I20260812 06:18:25.159418 26031 maintenance_manager.cc:643] P 335f41be1ab3410596f56b1eb13a65f8: MajorDeltaCompactionOp(3ae6458ccac543e693e6da1edf15b2ea) complete. Timing: real 0.180s	user 0.124s	sys 0.054s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24815682,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":69,"lbm_read_time_us":12996,"lbm_reads_lt_1ms":572,"lbm_write_time_us":30174,"lbm_writes_lt_1ms":543,"mutex_wait_us":35,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":6272,"update_count":2500}
I20260812 06:18:25.160063 26116 maintenance_manager.cc:419] P 335f41be1ab3410596f56b1eb13a65f8: Scheduling FlushDeltaMemStoresOp(3ae6458ccac543e693e6da1edf15b2ea): perf score=11.118625
I20260812 06:18:25.241726 26031 maintenance_manager.cc:643] P 335f41be1ab3410596f56b1eb13a65f8: FlushDeltaMemStoresOp(3ae6458ccac543e693e6da1edf15b2ea) complete. Timing: real 0.081s	user 0.024s	sys 0.021s Metrics: {"bytes_written":12717737,"delete_count":0,"lbm_write_time_us":34585,"lbm_writes_10-100_ms":1,"lbm_writes_lt_1ms":312,"reinsert_count":0,"update_count":1550}
I20260812 06:18:25.242413 26116 maintenance_manager.cc:419] P 335f41be1ab3410596f56b1eb13a65f8: Scheduling FlushDeltaMemStoresOp(3ae6458ccac543e693e6da1edf15b2ea): perf score=6.157687
I20260812 06:18:25.273512 26031 maintenance_manager.cc:643] P 335f41be1ab3410596f56b1eb13a65f8: FlushDeltaMemStoresOp(3ae6458ccac543e693e6da1edf15b2ea) complete. Timing: real 0.031s	user 0.013s	sys 0.016s Metrics: {"bytes_written":7794836,"delete_count":0,"lbm_write_time_us":8950,"lbm_writes_lt_1ms":193,"reinsert_count":0,"update_count":950}
I20260812 06:18:25.274168 26116 maintenance_manager.cc:419] P 335f41be1ab3410596f56b1eb13a65f8: Scheduling MajorDeltaCompactionOp(3ae6458ccac543e693e6da1edf15b2ea): perf score=1.000000
I20260812 06:18:25.452210 26031 maintenance_manager.cc:643] P 335f41be1ab3410596f56b1eb13a65f8: MajorDeltaCompactionOp(3ae6458ccac543e693e6da1edf15b2ea) complete. Timing: real 0.178s	user 0.117s	sys 0.060s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24815690,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":501,"lbm_read_time_us":10948,"lbm_reads_lt_1ms":564,"lbm_write_time_us":29753,"lbm_writes_lt_1ms":543,"mutex_wait_us":94,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":32256,"update_count":2500}
I20260812 06:18:25.452907 26116 maintenance_manager.cc:419] P 335f41be1ab3410596f56b1eb13a65f8: Scheduling FlushDeltaMemStoresOp(3ae6458ccac543e693e6da1edf15b2ea): perf score=14.095187
I20260812 06:18:25.498525 26031 maintenance_manager.cc:643] P 335f41be1ab3410596f56b1eb13a65f8: FlushDeltaMemStoresOp(3ae6458ccac543e693e6da1edf15b2ea) complete. Timing: real 0.045s	user 0.019s	sys 0.023s Metrics: {"bytes_written":16409899,"delete_count":0,"lbm_write_time_us":18441,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:18:25.499006 26116 maintenance_manager.cc:419] P 335f41be1ab3410596f56b1eb13a65f8: Scheduling FlushDeltaMemStoresOp(3ae6458ccac543e693e6da1edf15b2ea): perf score=2.188937
I20260812 06:18:25.510625 26031 maintenance_manager.cc:643] P 335f41be1ab3410596f56b1eb13a65f8: FlushDeltaMemStoresOp(3ae6458ccac543e693e6da1edf15b2ea) complete. Timing: real 0.011s	user 0.002s	sys 0.008s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4287,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:25.511091 26116 maintenance_manager.cc:419] P 335f41be1ab3410596f56b1eb13a65f8: Scheduling MajorDeltaCompactionOp(3ae6458ccac543e693e6da1edf15b2ea): perf score=1.000000
I20260812 06:18:25.674197 26031 maintenance_manager.cc:643] P 335f41be1ab3410596f56b1eb13a65f8: MajorDeltaCompactionOp(3ae6458ccac543e693e6da1edf15b2ea) complete. Timing: real 0.163s	user 0.108s	sys 0.053s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24815680,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":472,"lbm_read_time_us":10117,"lbm_reads_lt_1ms":572,"lbm_write_time_us":31472,"lbm_writes_lt_1ms":543,"mutex_wait_us":21,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":9472,"update_count":2500}
I20260812 06:18:25.674897 26116 maintenance_manager.cc:419] P 335f41be1ab3410596f56b1eb13a65f8: Scheduling FlushDeltaMemStoresOp(3ae6458ccac543e693e6da1edf15b2ea): perf score=11.118625
I20260812 06:18:25.709800 26031 maintenance_manager.cc:643] P 335f41be1ab3410596f56b1eb13a65f8: FlushDeltaMemStoresOp(3ae6458ccac543e693e6da1edf15b2ea) complete. Timing: real 0.035s	user 0.018s	sys 0.016s Metrics: {"bytes_written":12717735,"delete_count":0,"lbm_write_time_us":14781,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:18:25.710616 26116 maintenance_manager.cc:419] P 335f41be1ab3410596f56b1eb13a65f8: Scheduling FlushDeltaMemStoresOp(3ae6458ccac543e693e6da1edf15b2ea): perf score=2.188937
I20260812 06:18:25.723066 26031 maintenance_manager.cc:643] P 335f41be1ab3410596f56b1eb13a65f8: FlushDeltaMemStoresOp(3ae6458ccac543e693e6da1edf15b2ea) complete. Timing: real 0.012s	user 0.010s	sys 0.001s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":4732,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:18:25.723541 26116 maintenance_manager.cc:419] P 335f41be1ab3410596f56b1eb13a65f8: Scheduling MajorDeltaCompactionOp(3ae6458ccac543e693e6da1edf15b2ea): perf score=1.000000
I20260812 06:18:25.854385 26031 maintenance_manager.cc:643] P 335f41be1ab3410596f56b1eb13a65f8: MajorDeltaCompactionOp(3ae6458ccac543e693e6da1edf15b2ea) complete. Timing: real 0.131s	user 0.111s	sys 0.019s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20713263,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":217,"lbm_read_time_us":7922,"lbm_reads_lt_1ms":472,"lbm_write_time_us":27071,"lbm_writes_lt_1ms":443,"mutex_wait_us":33,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":5504,"update_count":2000}
I20260812 06:18:25.855155 26116 maintenance_manager.cc:419] P 335f41be1ab3410596f56b1eb13a65f8: Scheduling FlushDeltaMemStoresOp(3ae6458ccac543e693e6da1edf15b2ea): perf score=10.126437
I20260812 06:18:25.897737 26031 maintenance_manager.cc:643] P 335f41be1ab3410596f56b1eb13a65f8: FlushDeltaMemStoresOp(3ae6458ccac543e693e6da1edf15b2ea) complete. Timing: real 0.042s	user 0.028s	sys 0.008s Metrics: {"bytes_written":12307491,"delete_count":0,"lbm_write_time_us":15644,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:18:25.898254 26116 maintenance_manager.cc:419] P 335f41be1ab3410596f56b1eb13a65f8: Scheduling FlushDeltaMemStoresOp(3ae6458ccac543e693e6da1edf15b2ea): perf score=2.188937
I20260812 06:18:25.909382 26031 maintenance_manager.cc:643] P 335f41be1ab3410596f56b1eb13a65f8: FlushDeltaMemStoresOp(3ae6458ccac543e693e6da1edf15b2ea) complete. Timing: real 0.011s	user 0.001s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4075,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:25.909931 26116 maintenance_manager.cc:419] P 335f41be1ab3410596f56b1eb13a65f8: Scheduling MajorDeltaCompactionOp(3ae6458ccac543e693e6da1edf15b2ea): perf score=1.000000
I20260812 06:18:26.045210 26031 maintenance_manager.cc:643] P 335f41be1ab3410596f56b1eb13a65f8: MajorDeltaCompactionOp(3ae6458ccac543e693e6da1edf15b2ea) complete. Timing: real 0.135s	user 0.114s	sys 0.020s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20713273,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":627,"lbm_read_time_us":9868,"lbm_reads_lt_1ms":472,"lbm_write_time_us":25538,"lbm_writes_lt_1ms":443,"mutex_wait_us":63,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":9344,"update_count":2000}
I20260812 06:18:26.045897 26116 maintenance_manager.cc:419] P 335f41be1ab3410596f56b1eb13a65f8: Scheduling FlushDeltaMemStoresOp(3ae6458ccac543e693e6da1edf15b2ea): perf score=10.126437
I20260812 06:18:26.101334 26031 maintenance_manager.cc:643] P 335f41be1ab3410596f56b1eb13a65f8: FlushDeltaMemStoresOp(3ae6458ccac543e693e6da1edf15b2ea) complete. Timing: real 0.055s	user 0.027s	sys 0.024s Metrics: {"bytes_written":12307491,"delete_count":0,"lbm_write_time_us":20670,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":302,"reinsert_count":0,"update_count":1500}
I20260812 06:18:26.102002 26116 maintenance_manager.cc:419] P 335f41be1ab3410596f56b1eb13a65f8: Scheduling FlushDeltaMemStoresOp(3ae6458ccac543e693e6da1edf15b2ea): perf score=2.188937
I20260812 06:18:26.112884 26031 maintenance_manager.cc:643] P 335f41be1ab3410596f56b1eb13a65f8: FlushDeltaMemStoresOp(3ae6458ccac543e693e6da1edf15b2ea) complete. Timing: real 0.011s	user 0.009s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4232,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:26.113358 26116 maintenance_manager.cc:419] P 335f41be1ab3410596f56b1eb13a65f8: Scheduling FlushMRSOp(3ae6458ccac543e693e6da1edf15b2ea): perf score=1.000000
I20260812 06:18:26.155900 26031 maintenance_manager.cc:643] P 335f41be1ab3410596f56b1eb13a65f8: FlushMRSOp(3ae6458ccac543e693e6da1edf15b2ea) complete. Timing: real 0.042s	user 0.025s	sys 0.004s Metrics: {"bytes_written":1193509,"cfile_init":1,"dirs.queue_time_us":147,"dirs.run_cpu_time_us":264,"dirs.run_wall_time_us":1589,"drs_written":1,"lbm_read_time_us":94,"lbm_reads_lt_1ms":4,"lbm_write_time_us":2028,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":29}
I20260812 06:18:26.156612 26116 maintenance_manager.cc:419] P 335f41be1ab3410596f56b1eb13a65f8: Scheduling LogGCOp(3ae6458ccac543e693e6da1edf15b2ea): free 124257306 bytes of WAL
I20260812 06:18:26.156840 26031 log_reader.cc:385] T 3ae6458ccac543e693e6da1edf15b2ea: removed 12 log segments from log reader
I20260812 06:18:26.156888 26031 log.cc:1079] T 3ae6458ccac543e693e6da1edf15b2ea P 335f41be1ab3410596f56b1eb13a65f8: Deleting log segment in path: /tmp/dist-test-taskAaiyNc/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515497224838-25556-0/minicluster-data/ts-0-root/wals/3ae6458ccac543e693e6da1edf15b2ea/wal-000000015 (ops 70-74)
I20260812 06:18:26.156915 26031 log.cc:1079] T 3ae6458ccac543e693e6da1edf15b2ea P 335f41be1ab3410596f56b1eb13a65f8: Deleting log segment in path: /tmp/dist-test-taskAaiyNc/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515497224838-25556-0/minicluster-data/ts-0-root/wals/3ae6458ccac543e693e6da1edf15b2ea/wal-000000016 (ops 75-79)
I20260812 06:18:26.156981 26031 log.cc:1079] T 3ae6458ccac543e693e6da1edf15b2ea P 335f41be1ab3410596f56b1eb13a65f8: Deleting log segment in path: /tmp/dist-test-taskAaiyNc/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515497224838-25556-0/minicluster-data/ts-0-root/wals/3ae6458ccac543e693e6da1edf15b2ea/wal-000000017 (ops 80-84)
I20260812 06:18:26.157020 26031 log.cc:1079] T 3ae6458ccac543e693e6da1edf15b2ea P 335f41be1ab3410596f56b1eb13a65f8: Deleting log segment in path: /tmp/dist-test-taskAaiyNc/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515497224838-25556-0/minicluster-data/ts-0-root/wals/3ae6458ccac543e693e6da1edf15b2ea/wal-000000018 (ops 85-89)
I20260812 06:18:26.157075 26031 log.cc:1079] T 3ae6458ccac543e693e6da1edf15b2ea P 335f41be1ab3410596f56b1eb13a65f8: Deleting log segment in path: /tmp/dist-test-taskAaiyNc/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515497224838-25556-0/minicluster-data/ts-0-root/wals/3ae6458ccac543e693e6da1edf15b2ea/wal-000000019 (ops 90-94)
I20260812 06:18:26.157119 26031 log.cc:1079] T 3ae6458ccac543e693e6da1edf15b2ea P 335f41be1ab3410596f56b1eb13a65f8: Deleting log segment in path: /tmp/dist-test-taskAaiyNc/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515497224838-25556-0/minicluster-data/ts-0-root/wals/3ae6458ccac543e693e6da1edf15b2ea/wal-000000020 (ops 95-99)
I20260812 06:18:26.157158 26031 log.cc:1079] T 3ae6458ccac543e693e6da1edf15b2ea P 335f41be1ab3410596f56b1eb13a65f8: Deleting log segment in path: /tmp/dist-test-taskAaiyNc/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515497224838-25556-0/minicluster-data/ts-0-root/wals/3ae6458ccac543e693e6da1edf15b2ea/wal-000000021 (ops 100-104)
I20260812 06:18:26.157196 26031 log.cc:1079] T 3ae6458ccac543e693e6da1edf15b2ea P 335f41be1ab3410596f56b1eb13a65f8: Deleting log segment in path: /tmp/dist-test-taskAaiyNc/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515497224838-25556-0/minicluster-data/ts-0-root/wals/3ae6458ccac543e693e6da1edf15b2ea/wal-000000022 (ops 105-108)
I20260812 06:18:26.157235 26031 log.cc:1079] T 3ae6458ccac543e693e6da1edf15b2ea P 335f41be1ab3410596f56b1eb13a65f8: Deleting log segment in path: /tmp/dist-test-taskAaiyNc/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515497224838-25556-0/minicluster-data/ts-0-root/wals/3ae6458ccac543e693e6da1edf15b2ea/wal-000000023 (ops 109-113)
I20260812 06:18:26.157272 26031 log.cc:1079] T 3ae6458ccac543e693e6da1edf15b2ea P 335f41be1ab3410596f56b1eb13a65f8: Deleting log segment in path: /tmp/dist-test-taskAaiyNc/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515497224838-25556-0/minicluster-data/ts-0-root/wals/3ae6458ccac543e693e6da1edf15b2ea/wal-000000024 (ops 114-118)
I20260812 06:18:26.157306 26031 log.cc:1079] T 3ae6458ccac543e693e6da1edf15b2ea P 335f41be1ab3410596f56b1eb13a65f8: Deleting log segment in path: /tmp/dist-test-taskAaiyNc/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515497224838-25556-0/minicluster-data/ts-0-root/wals/3ae6458ccac543e693e6da1edf15b2ea/wal-000000025 (ops 119-123)
I20260812 06:18:26.157359 26031 log.cc:1079] T 3ae6458ccac543e693e6da1edf15b2ea P 335f41be1ab3410596f56b1eb13a65f8: Deleting log segment in path: /tmp/dist-test-taskAaiyNc/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515497224838-25556-0/minicluster-data/ts-0-root/wals/3ae6458ccac543e693e6da1edf15b2ea/wal-000000026 (ops 124-128)
I20260812 06:18:26.183673 26031 maintenance_manager.cc:643] P 335f41be1ab3410596f56b1eb13a65f8: LogGCOp(3ae6458ccac543e693e6da1edf15b2ea) complete. Timing: real 0.027s	user 0.000s	sys 0.025s Metrics: {}
I20260812 06:18:26.184333 26116 maintenance_manager.cc:419] P 335f41be1ab3410596f56b1eb13a65f8: Scheduling UndoDeltaBlockGCOp(3ae6458ccac543e693e6da1edf15b2ea): 462 bytes on disk
I20260812 06:18:26.184827 26031 maintenance_manager.cc:643] P 335f41be1ab3410596f56b1eb13a65f8: UndoDeltaBlockGCOp(3ae6458ccac543e693e6da1edf15b2ea) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":78,"lbm_reads_lt_1ms":4}
I20260812 06:18:26.185376 26116 maintenance_manager.cc:419] P 335f41be1ab3410596f56b1eb13a65f8: Scheduling FlushDeltaMemStoresOp(3ae6458ccac543e693e6da1edf15b2ea): perf score=3.181125
I20260812 06:18:26.198055 26031 maintenance_manager.cc:643] P 335f41be1ab3410596f56b1eb13a65f8: FlushDeltaMemStoresOp(3ae6458ccac543e693e6da1edf15b2ea) complete. Timing: real 0.013s	user 0.011s	sys 0.000s Metrics: {"bytes_written":4512903,"delete_count":0,"lbm_write_time_us":4469,"lbm_writes_lt_1ms":113,"reinsert_count":0,"update_count":550}
I20260812 06:18:26.198561 26116 maintenance_manager.cc:419] P 335f41be1ab3410596f56b1eb13a65f8: Scheduling FlushDeltaMemStoresOp(3ae6458ccac543e693e6da1edf15b2ea): perf score=2.188937
I20260812 06:18:26.208527 26031 maintenance_manager.cc:643] P 335f41be1ab3410596f56b1eb13a65f8: FlushDeltaMemStoresOp(3ae6458ccac543e693e6da1edf15b2ea) complete. Timing: real 0.010s	user 0.005s	sys 0.003s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3767,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:18:26.209060 26116 maintenance_manager.cc:419] P 335f41be1ab3410596f56b1eb13a65f8: Scheduling MajorDeltaCompactionOp(3ae6458ccac543e693e6da1edf15b2ea): perf score=1.000000
I20260812 06:18:26.414736 26031 maintenance_manager.cc:643] P 335f41be1ab3410596f56b1eb13a65f8: MajorDeltaCompactionOp(3ae6458ccac543e693e6da1edf15b2ea) complete. Timing: real 0.206s	user 0.113s	sys 0.092s Metrics: {"cfile_cache_miss":634,"cfile_cache_miss_bytes":28918325,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":700,"lbm_read_time_us":16421,"lbm_reads_lt_1ms":674,"lbm_write_time_us":31147,"lbm_writes_lt_1ms":643,"mutex_wait_us":23,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":23040,"thread_start_us":87,"threads_started":1,"update_count":3000}
I20260812 06:18:26.415688 26116 maintenance_manager.cc:419] P 335f41be1ab3410596f56b1eb13a65f8: Scheduling FlushDeltaMemStoresOp(3ae6458ccac543e693e6da1edf15b2ea): perf score=14.095187
I20260812 06:18:26.460814 26031 maintenance_manager.cc:643] P 335f41be1ab3410596f56b1eb13a65f8: FlushDeltaMemStoresOp(3ae6458ccac543e693e6da1edf15b2ea) complete. Timing: real 0.045s	user 0.011s	sys 0.031s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":18853,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:18:26.461361 26116 maintenance_manager.cc:419] P 335f41be1ab3410596f56b1eb13a65f8: Scheduling MajorDeltaCompactionOp(3ae6458ccac543e693e6da1edf15b2ea): perf score=1.000000
I20260812 06:18:26.618003 26031 maintenance_manager.cc:643] P 335f41be1ab3410596f56b1eb13a65f8: MajorDeltaCompactionOp(3ae6458ccac543e693e6da1edf15b2ea) complete. Timing: real 0.156s	user 0.128s	sys 0.025s Metrics: {"cfile_cache_miss":431,"cfile_cache_miss_bytes":20713152,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":1,"delta_iterators_relevant":1,"dirs.queue_time_us":215,"lbm_read_time_us":9221,"lbm_reads_lt_1ms":463,"lbm_write_time_us":24411,"lbm_writes_lt_1ms":443,"mutex_wait_us":49,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":8192,"update_count":2000}
I20260812 06:18:26.618724 26116 maintenance_manager.cc:419] P 335f41be1ab3410596f56b1eb13a65f8: Scheduling FlushDeltaMemStoresOp(3ae6458ccac543e693e6da1edf15b2ea): perf score=14.095187
I20260812 06:18:26.671029 26031 maintenance_manager.cc:643] P 335f41be1ab3410596f56b1eb13a65f8: FlushDeltaMemStoresOp(3ae6458ccac543e693e6da1edf15b2ea) complete. Timing: real 0.052s	user 0.020s	sys 0.024s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":20422,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:18:26.671598 26116 maintenance_manager.cc:419] P 335f41be1ab3410596f56b1eb13a65f8: Scheduling FlushDeltaMemStoresOp(3ae6458ccac543e693e6da1edf15b2ea): perf score=2.188937
I20260812 06:18:26.687565 26031 maintenance_manager.cc:643] P 335f41be1ab3410596f56b1eb13a65f8: FlushDeltaMemStoresOp(3ae6458ccac543e693e6da1edf15b2ea) complete. Timing: real 0.016s	user 0.009s	sys 0.004s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":5982,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:26.688272 26116 maintenance_manager.cc:419] P 335f41be1ab3410596f56b1eb13a65f8: Scheduling MajorDeltaCompactionOp(3ae6458ccac543e693e6da1edf15b2ea): perf score=1.000000
I20260812 06:18:26.886632 26031 maintenance_manager.cc:643] P 335f41be1ab3410596f56b1eb13a65f8: MajorDeltaCompactionOp(3ae6458ccac543e693e6da1edf15b2ea) complete. Timing: real 0.198s	user 0.126s	sys 0.063s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24815682,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":926,"lbm_read_time_us":12297,"lbm_reads_lt_1ms":572,"lbm_write_time_us":32044,"lbm_writes_lt_1ms":543,"mutex_wait_us":256,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":14592,"update_count":2500}
I20260812 06:18:26.887279 26116 maintenance_manager.cc:419] P 335f41be1ab3410596f56b1eb13a65f8: Scheduling FlushDeltaMemStoresOp(3ae6458ccac543e693e6da1edf15b2ea): perf score=14.095187
I20260812 06:18:26.940872 26031 maintenance_manager.cc:643] P 335f41be1ab3410596f56b1eb13a65f8: FlushDeltaMemStoresOp(3ae6458ccac543e693e6da1edf15b2ea) complete. Timing: real 0.053s	user 0.026s	sys 0.024s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":23015,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:18:26.941401 26116 maintenance_manager.cc:419] P 335f41be1ab3410596f56b1eb13a65f8: Scheduling FlushDeltaMemStoresOp(3ae6458ccac543e693e6da1edf15b2ea): perf score=2.188937
I20260812 06:18:26.958585 26031 maintenance_manager.cc:643] P 335f41be1ab3410596f56b1eb13a65f8: FlushDeltaMemStoresOp(3ae6458ccac543e693e6da1edf15b2ea) complete. Timing: real 0.017s	user 0.002s	sys 0.010s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4812,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:26.959177 26116 maintenance_manager.cc:419] P 335f41be1ab3410596f56b1eb13a65f8: Scheduling MajorDeltaCompactionOp(3ae6458ccac543e693e6da1edf15b2ea): perf score=1.000000
I20260812 06:18:27.111240 26031 maintenance_manager.cc:643] P 335f41be1ab3410596f56b1eb13a65f8: MajorDeltaCompactionOp(3ae6458ccac543e693e6da1edf15b2ea) complete. Timing: real 0.152s	user 0.103s	sys 0.047s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24815683,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":216,"lbm_read_time_us":11304,"lbm_reads_lt_1ms":564,"lbm_write_time_us":29110,"lbm_writes_lt_1ms":543,"mutex_wait_us":51,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":4608,"update_count":2500}
I20260812 06:18:27.112007 26116 maintenance_manager.cc:419] P 335f41be1ab3410596f56b1eb13a65f8: Scheduling FlushDeltaMemStoresOp(3ae6458ccac543e693e6da1edf15b2ea): perf score=14.095187
I20260812 06:18:27.169163 26031 maintenance_manager.cc:643] P 335f41be1ab3410596f56b1eb13a65f8: FlushDeltaMemStoresOp(3ae6458ccac543e693e6da1edf15b2ea) complete. Timing: real 0.057s	user 0.045s	sys 0.008s Metrics: {"bytes_written":16409900,"delete_count":0,"lbm_write_time_us":28134,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":402,"reinsert_count":0,"update_count":2000}
I20260812 06:18:27.169811 26116 maintenance_manager.cc:419] P 335f41be1ab3410596f56b1eb13a65f8: Scheduling FlushDeltaMemStoresOp(3ae6458ccac543e693e6da1edf15b2ea): perf score=2.188937
I20260812 06:18:27.187268 26031 maintenance_manager.cc:643] P 335f41be1ab3410596f56b1eb13a65f8: FlushDeltaMemStoresOp(3ae6458ccac543e693e6da1edf15b2ea) complete. Timing: real 0.017s	user 0.009s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5980,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:27.187826 26116 maintenance_manager.cc:419] P 335f41be1ab3410596f56b1eb13a65f8: Scheduling MajorDeltaCompactionOp(3ae6458ccac543e693e6da1edf15b2ea): perf score=1.000000
I20260812 06:18:27.345046 26031 maintenance_manager.cc:643] P 335f41be1ab3410596f56b1eb13a65f8: MajorDeltaCompactionOp(3ae6458ccac543e693e6da1edf15b2ea) complete. Timing: real 0.157s	user 0.134s	sys 0.021s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24815682,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":961,"lbm_read_time_us":10364,"lbm_reads_lt_1ms":564,"lbm_write_time_us":35037,"lbm_writes_lt_1ms":543,"mutex_wait_us":278,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":11904,"update_count":2500}
I20260812 06:18:27.345749 26116 maintenance_manager.cc:419] P 335f41be1ab3410596f56b1eb13a65f8: Scheduling FlushDeltaMemStoresOp(3ae6458ccac543e693e6da1edf15b2ea): perf score=14.095187
I20260812 06:18:27.393805 26031 maintenance_manager.cc:643] P 335f41be1ab3410596f56b1eb13a65f8: FlushDeltaMemStoresOp(3ae6458ccac543e693e6da1edf15b2ea) complete. Timing: real 0.048s	user 0.028s	sys 0.018s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":21446,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:18:27.394361 26116 maintenance_manager.cc:419] P 335f41be1ab3410596f56b1eb13a65f8: Scheduling FlushDeltaMemStoresOp(3ae6458ccac543e693e6da1edf15b2ea): perf score=2.188937
I20260812 06:18:27.410708 26031 maintenance_manager.cc:643] P 335f41be1ab3410596f56b1eb13a65f8: FlushDeltaMemStoresOp(3ae6458ccac543e693e6da1edf15b2ea) complete. Timing: real 0.016s	user 0.007s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6053,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:27.411315 26116 maintenance_manager.cc:419] P 335f41be1ab3410596f56b1eb13a65f8: Scheduling MajorDeltaCompactionOp(3ae6458ccac543e693e6da1edf15b2ea): perf score=1.000000
I20260812 06:18:27.564270 26031 maintenance_manager.cc:643] P 335f41be1ab3410596f56b1eb13a65f8: MajorDeltaCompactionOp(3ae6458ccac543e693e6da1edf15b2ea) complete. Timing: real 0.153s	user 0.133s	sys 0.016s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24815683,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":833,"lbm_read_time_us":12494,"lbm_reads_lt_1ms":572,"lbm_write_time_us":29763,"lbm_writes_lt_1ms":543,"mutex_wait_us":28,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":68224,"update_count":2500}
I20260812 06:18:27.565074 26116 maintenance_manager.cc:419] P 335f41be1ab3410596f56b1eb13a65f8: Scheduling FlushDeltaMemStoresOp(3ae6458ccac543e693e6da1edf15b2ea): perf score=11.118625
I20260812 06:18:27.605361 26031 maintenance_manager.cc:643] P 335f41be1ab3410596f56b1eb13a65f8: FlushDeltaMemStoresOp(3ae6458ccac543e693e6da1edf15b2ea) complete. Timing: real 0.040s	user 0.028s	sys 0.008s Metrics: {"bytes_written":12717735,"delete_count":0,"lbm_write_time_us":17167,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:18:27.606060 26116 maintenance_manager.cc:419] P 335f41be1ab3410596f56b1eb13a65f8: Scheduling FlushDeltaMemStoresOp(3ae6458ccac543e693e6da1edf15b2ea): perf score=2.188937
I20260812 06:18:27.622043 26031 maintenance_manager.cc:643] P 335f41be1ab3410596f56b1eb13a65f8: FlushDeltaMemStoresOp(3ae6458ccac543e693e6da1edf15b2ea) complete. Timing: real 0.016s	user 0.008s	sys 0.004s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":4972,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:18:27.622509 26116 maintenance_manager.cc:419] P 335f41be1ab3410596f56b1eb13a65f8: Scheduling FlushMRSOp(3ae6458ccac543e693e6da1edf15b2ea): perf score=1.000000
I20260812 06:18:27.684479 26031 maintenance_manager.cc:643] P 335f41be1ab3410596f56b1eb13a65f8: FlushMRSOp(3ae6458ccac543e693e6da1edf15b2ea) complete. Timing: real 0.062s	user 0.035s	sys 0.000s Metrics: {"bytes_written":1275447,"cfile_init":1,"dirs.queue_time_us":58,"dirs.run_cpu_time_us":182,"dirs.run_wall_time_us":1317,"drs_written":1,"lbm_read_time_us":58,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1730,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":31}
I20260812 06:18:27.685277 26116 maintenance_manager.cc:419] P 335f41be1ab3410596f56b1eb13a65f8: Scheduling LogGCOp(3ae6458ccac543e693e6da1edf15b2ea): free 121006640 bytes of WAL
I20260812 06:18:27.685528 26031 log_reader.cc:385] T 3ae6458ccac543e693e6da1edf15b2ea: removed 12 log segments from log reader
I20260812 06:18:27.685580 26031 log.cc:1079] T 3ae6458ccac543e693e6da1edf15b2ea P 335f41be1ab3410596f56b1eb13a65f8: Deleting log segment in path: /tmp/dist-test-taskAaiyNc/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515497224838-25556-0/minicluster-data/ts-0-root/wals/3ae6458ccac543e693e6da1edf15b2ea/wal-000000027 (ops 129-133)
I20260812 06:18:27.685617 26031 log.cc:1079] T 3ae6458ccac543e693e6da1edf15b2ea P 335f41be1ab3410596f56b1eb13a65f8: Deleting log segment in path: /tmp/dist-test-taskAaiyNc/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515497224838-25556-0/minicluster-data/ts-0-root/wals/3ae6458ccac543e693e6da1edf15b2ea/wal-000000028 (ops 134-138)
I20260812 06:18:27.685648 26031 log.cc:1079] T 3ae6458ccac543e693e6da1edf15b2ea P 335f41be1ab3410596f56b1eb13a65f8: Deleting log segment in path: /tmp/dist-test-taskAaiyNc/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515497224838-25556-0/minicluster-data/ts-0-root/wals/3ae6458ccac543e693e6da1edf15b2ea/wal-000000029 (ops 139-143)
I20260812 06:18:27.685683 26031 log.cc:1079] T 3ae6458ccac543e693e6da1edf15b2ea P 335f41be1ab3410596f56b1eb13a65f8: Deleting log segment in path: /tmp/dist-test-taskAaiyNc/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515497224838-25556-0/minicluster-data/ts-0-root/wals/3ae6458ccac543e693e6da1edf15b2ea/wal-000000030 (ops 144-148)
I20260812 06:18:27.685716 26031 log.cc:1079] T 3ae6458ccac543e693e6da1edf15b2ea P 335f41be1ab3410596f56b1eb13a65f8: Deleting log segment in path: /tmp/dist-test-taskAaiyNc/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515497224838-25556-0/minicluster-data/ts-0-root/wals/3ae6458ccac543e693e6da1edf15b2ea/wal-000000031 (ops 149-152)
I20260812 06:18:27.685740 26031 log.cc:1079] T 3ae6458ccac543e693e6da1edf15b2ea P 335f41be1ab3410596f56b1eb13a65f8: Deleting log segment in path: /tmp/dist-test-taskAaiyNc/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515497224838-25556-0/minicluster-data/ts-0-root/wals/3ae6458ccac543e693e6da1edf15b2ea/wal-000000032 (ops 153-157)
I20260812 06:18:27.685817 26031 log.cc:1079] T 3ae6458ccac543e693e6da1edf15b2ea P 335f41be1ab3410596f56b1eb13a65f8: Deleting log segment in path: /tmp/dist-test-taskAaiyNc/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515497224838-25556-0/minicluster-data/ts-0-root/wals/3ae6458ccac543e693e6da1edf15b2ea/wal-000000033 (ops 158-162)
I20260812 06:18:27.685858 26031 log.cc:1079] T 3ae6458ccac543e693e6da1edf15b2ea P 335f41be1ab3410596f56b1eb13a65f8: Deleting log segment in path: /tmp/dist-test-taskAaiyNc/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515497224838-25556-0/minicluster-data/ts-0-root/wals/3ae6458ccac543e693e6da1edf15b2ea/wal-000000034 (ops 163-167)
I20260812 06:18:27.685884 26031 log.cc:1079] T 3ae6458ccac543e693e6da1edf15b2ea P 335f41be1ab3410596f56b1eb13a65f8: Deleting log segment in path: /tmp/dist-test-taskAaiyNc/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515497224838-25556-0/minicluster-data/ts-0-root/wals/3ae6458ccac543e693e6da1edf15b2ea/wal-000000035 (ops 168-172)
I20260812 06:18:27.685917 26031 log.cc:1079] T 3ae6458ccac543e693e6da1edf15b2ea P 335f41be1ab3410596f56b1eb13a65f8: Deleting log segment in path: /tmp/dist-test-taskAaiyNc/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515497224838-25556-0/minicluster-data/ts-0-root/wals/3ae6458ccac543e693e6da1edf15b2ea/wal-000000036 (ops 173-177)
I20260812 06:18:27.685946 26031 log.cc:1079] T 3ae6458ccac543e693e6da1edf15b2ea P 335f41be1ab3410596f56b1eb13a65f8: Deleting log segment in path: /tmp/dist-test-taskAaiyNc/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515497224838-25556-0/minicluster-data/ts-0-root/wals/3ae6458ccac543e693e6da1edf15b2ea/wal-000000037 (ops 178-182)
I20260812 06:18:27.685976 26031 log.cc:1079] T 3ae6458ccac543e693e6da1edf15b2ea P 335f41be1ab3410596f56b1eb13a65f8: Deleting log segment in path: /tmp/dist-test-taskAaiyNc/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515497224838-25556-0/minicluster-data/ts-0-root/wals/3ae6458ccac543e693e6da1edf15b2ea/wal-000000038 (ops 183-187)
I20260812 06:18:27.717300 26031 maintenance_manager.cc:643] P 335f41be1ab3410596f56b1eb13a65f8: LogGCOp(3ae6458ccac543e693e6da1edf15b2ea) complete. Timing: real 0.032s	user 0.001s	sys 0.027s Metrics: {}
I20260812 06:18:27.717761 26116 maintenance_manager.cc:419] P 335f41be1ab3410596f56b1eb13a65f8: Scheduling UndoDeltaBlockGCOp(3ae6458ccac543e693e6da1edf15b2ea): 482 bytes on disk
I20260812 06:18:27.718206 26031 maintenance_manager.cc:643] P 335f41be1ab3410596f56b1eb13a65f8: UndoDeltaBlockGCOp(3ae6458ccac543e693e6da1edf15b2ea) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":57,"lbm_reads_lt_1ms":4}
I20260812 06:18:27.718763 26116 maintenance_manager.cc:419] P 335f41be1ab3410596f56b1eb13a65f8: Scheduling FlushDeltaMemStoresOp(3ae6458ccac543e693e6da1edf15b2ea): perf score=6.157687
I20260812 06:18:27.743544 26031 maintenance_manager.cc:643] P 335f41be1ab3410596f56b1eb13a65f8: FlushDeltaMemStoresOp(3ae6458ccac543e693e6da1edf15b2ea) complete. Timing: real 0.025s	user 0.018s	sys 0.005s Metrics: {"bytes_written":8205078,"delete_count":0,"lbm_write_time_us":10718,"lbm_writes_lt_1ms":203,"reinsert_count":0,"spinlock_wait_cycles":2432,"update_count":1000}
I20260812 06:18:27.744065 26116 maintenance_manager.cc:419] P 335f41be1ab3410596f56b1eb13a65f8: Scheduling LogGCOp(3ae6458ccac543e693e6da1edf15b2ea): free 8767195 bytes of WAL
I20260812 06:18:27.744273 26031 log_reader.cc:385] T 3ae6458ccac543e693e6da1edf15b2ea: removed 1 log segments from log reader
I20260812 06:18:27.744318 26031 log.cc:1079] T 3ae6458ccac543e693e6da1edf15b2ea P 335f41be1ab3410596f56b1eb13a65f8: Deleting log segment in path: /tmp/dist-test-taskAaiyNc/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515497224838-25556-0/minicluster-data/ts-0-root/wals/3ae6458ccac543e693e6da1edf15b2ea/wal-000000039 (ops 188-192)
I20260812 06:18:27.746183 26031 maintenance_manager.cc:643] P 335f41be1ab3410596f56b1eb13a65f8: LogGCOp(3ae6458ccac543e693e6da1edf15b2ea) complete. Timing: real 0.002s	user 0.000s	sys 0.001s Metrics: {}
I20260812 06:18:27.746506 26116 maintenance_manager.cc:419] P 335f41be1ab3410596f56b1eb13a65f8: Scheduling FlushDeltaMemStoresOp(3ae6458ccac543e693e6da1edf15b2ea): perf score=2.188937
I20260812 06:18:27.758594 26031 maintenance_manager.cc:643] P 335f41be1ab3410596f56b1eb13a65f8: FlushDeltaMemStoresOp(3ae6458ccac543e693e6da1edf15b2ea) complete. Timing: real 0.012s	user 0.005s	sys 0.005s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4437,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:27.759052 26116 maintenance_manager.cc:419] P 335f41be1ab3410596f56b1eb13a65f8: Scheduling MajorDeltaCompactionOp(3ae6458ccac543e693e6da1edf15b2ea): perf score=1.000000
I20260812 06:18:27.878577 25556 heavy-update-compaction-itest.cc:229] Time spent updating: real 5.015s	user 1.844s	sys 0.179s
I20260812 06:18:27.937283 26031 maintenance_manager.cc:643] P 335f41be1ab3410596f56b1eb13a65f8: MajorDeltaCompactionOp(3ae6458ccac543e693e6da1edf15b2ea) complete. Timing: real 0.178s	user 0.141s	sys 0.035s Metrics: {"cfile_cache_miss":734,"cfile_cache_miss_bytes":33020737,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"lbm_read_time_us":14498,"lbm_reads_lt_1ms":770,"lbm_write_time_us":37661,"lbm_writes_lt_1ms":743,"peak_mem_usage":87969044,"reinsert_count":0,"spinlock_wait_cycles":1536,"update_count":3500}
I20260812 06:18:27.937800 26116 maintenance_manager.cc:419] P 335f41be1ab3410596f56b1eb13a65f8: Scheduling FlushDeltaMemStoresOp(3ae6458ccac543e693e6da1edf15b2ea): perf score=10.126437
I20260812 06:18:27.964874 25556 heavy-update-compaction-itest.cc:265] Time spent scanning: real 0.086s	user 0.000s	sys 0.000s
I20260812 06:18:27.965402 25556 tablet_server.cc:179] TabletServer@127.24.245.1:0 shutting down...
I20260812 06:18:27.973896 26031 maintenance_manager.cc:643] P 335f41be1ab3410596f56b1eb13a65f8: FlushDeltaMemStoresOp(3ae6458ccac543e693e6da1edf15b2ea) complete. Timing: real 0.036s	user 0.016s	sys 0.020s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":16145,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:18:27.974474 25556 ts_tablet_manager.cc:1507] Shutting down tablet manager...
I20260812 06:18:27.974673 25556 tablet_replica.cc:333] T 3ae6458ccac543e693e6da1edf15b2ea P 335f41be1ab3410596f56b1eb13a65f8: stopping tablet replica
I20260812 06:18:27.974825 25556 raft_consensus.cc:2243] T 3ae6458ccac543e693e6da1edf15b2ea P 335f41be1ab3410596f56b1eb13a65f8 [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:18:27.975013 25556 raft_consensus.cc:2272] T 3ae6458ccac543e693e6da1edf15b2ea P 335f41be1ab3410596f56b1eb13a65f8 [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:18:27.988436 25556 tablet_server.cc:196] TabletServer@127.24.245.1:0 shutdown complete.
I20260812 06:18:28.001786 25556 master.cc:562] Master@127.24.245.62:39671 shutting down...
I20260812 06:18:28.005055 25556 raft_consensus.cc:2243] T 00000000000000000000000000000000 P cafec0dc95a441b48c45cbbda8c529b9 [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:18:28.005223 25556 raft_consensus.cc:2272] T 00000000000000000000000000000000 P cafec0dc95a441b48c45cbbda8c529b9 [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:18:28.005275 25556 tablet_replica.cc:333] T 00000000000000000000000000000000 P cafec0dc95a441b48c45cbbda8c529b9: stopping tablet replica
I20260812 06:18:28.017746 25556 master.cc:584] Master@127.24.245.62:39671 shutdown complete.
[       OK ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/1 (5459 ms)
[----------] 2 tests from EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy (10870 ms total)

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