[==========] 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:16:53.153359  5786 internal_mini_cluster.cc:156] Creating distributed mini masters. Addrs: 127.5.166.190:35371
I20260812 06:16:53.154304  5786 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:16:53.154884  5786 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:16:53.160739  5795 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:16:53.160761  5796 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:16:53.160924  5786 server_base.cc:1061] running on GCE node
W20260812 06:16:53.161056  5798 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:16:53.161535  5786 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:16:53.161638  5786 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:16:53.161691  5786 hybrid_clock.cc:648] HybridClock initialized: now 1786515413161689 us; error 0 us; skew 500 ppm
I20260812 06:16:53.163450  5786 webserver.cc:533] Webserver started at http://127.5.166.190:43223/ using document root <none> and password file <none>
I20260812 06:16:53.163992  5786 fs_manager.cc:362] Metadata directory not provided
I20260812 06:16:53.164053  5786 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:16:53.164376  5786 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:16:53.165937  5786 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taske_2AlB/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515413143058-5786-0/minicluster-data/master-0-root/instance:
uuid: "e3fde12c031e4a319f94b0fdd4ebc87a"
format_stamp: "Formatted at 2026-08-12 06:16:53 on dist-test-slave-2d19"
I20260812 06:16:53.169263  5786 fs_manager.cc:696] Time spent creating directory manager: real 0.003s	user 0.004s	sys 0.000s
I20260812 06:16:53.171236  5803 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:16:53.172202  5786 fs_manager.cc:730] Time spent opening block manager: real 0.002s	user 0.002s	sys 0.000s
I20260812 06:16:53.172353  5786 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taske_2AlB/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515413143058-5786-0/minicluster-data/master-0-root
uuid: "e3fde12c031e4a319f94b0fdd4ebc87a"
format_stamp: "Formatted at 2026-08-12 06:16:53 on dist-test-slave-2d19"
I20260812 06:16:53.172453  5786 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taske_2AlB/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515413143058-5786-0/minicluster-data/master-0-root
metadata directory: /tmp/dist-test-taske_2AlB/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515413143058-5786-0/minicluster-data/master-0-root
1 data directories: /tmp/dist-test-taske_2AlB/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515413143058-5786-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:16:53.186439  5786 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:16:53.187067  5786 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:16:53.187251  5786 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:16:53.195154  5786 rpc_server.cc:307] RPC server started. Bound to: 127.5.166.190:35371
I20260812 06:16:53.195178  5897 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.5.166.190:35371 every 8 connection(s)
I20260812 06:16:53.197464  5904 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:16:53.202757  5904 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P e3fde12c031e4a319f94b0fdd4ebc87a: Bootstrap starting.
I20260812 06:16:53.205247  5904 tablet_bootstrap.cc:654] T 00000000000000000000000000000000 P e3fde12c031e4a319f94b0fdd4ebc87a: Neither blocks nor log segments found. Creating new log.
I20260812 06:16:53.206169  5904 log.cc:826] T 00000000000000000000000000000000 P e3fde12c031e4a319f94b0fdd4ebc87a: Log is configured to *not* fsync() on all Append() calls
I20260812 06:16:53.207875  5904 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P e3fde12c031e4a319f94b0fdd4ebc87a: No bootstrap required, opened a new log
I20260812 06:16:53.210701  5904 raft_consensus.cc:359] T 00000000000000000000000000000000 P e3fde12c031e4a319f94b0fdd4ebc87a [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "e3fde12c031e4a319f94b0fdd4ebc87a" member_type: VOTER }
I20260812 06:16:53.210861  5904 raft_consensus.cc:385] T 00000000000000000000000000000000 P e3fde12c031e4a319f94b0fdd4ebc87a [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:16:53.210988  5904 raft_consensus.cc:740] T 00000000000000000000000000000000 P e3fde12c031e4a319f94b0fdd4ebc87a [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: e3fde12c031e4a319f94b0fdd4ebc87a, State: Initialized, Role: FOLLOWER
I20260812 06:16:53.211570  5904 consensus_queue.cc:260] T 00000000000000000000000000000000 P e3fde12c031e4a319f94b0fdd4ebc87a [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: "e3fde12c031e4a319f94b0fdd4ebc87a" member_type: VOTER }
I20260812 06:16:53.211732  5904 raft_consensus.cc:399] T 00000000000000000000000000000000 P e3fde12c031e4a319f94b0fdd4ebc87a [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:16:53.211807  5904 raft_consensus.cc:493] T 00000000000000000000000000000000 P e3fde12c031e4a319f94b0fdd4ebc87a [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:16:53.211998  5904 raft_consensus.cc:3060] T 00000000000000000000000000000000 P e3fde12c031e4a319f94b0fdd4ebc87a [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:16:53.212865  5904 raft_consensus.cc:515] T 00000000000000000000000000000000 P e3fde12c031e4a319f94b0fdd4ebc87a [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "e3fde12c031e4a319f94b0fdd4ebc87a" member_type: VOTER }
I20260812 06:16:53.213348  5904 leader_election.cc:304] T 00000000000000000000000000000000 P e3fde12c031e4a319f94b0fdd4ebc87a [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: e3fde12c031e4a319f94b0fdd4ebc87a; no voters: 
I20260812 06:16:53.213678  5904 leader_election.cc:290] T 00000000000000000000000000000000 P e3fde12c031e4a319f94b0fdd4ebc87a [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:16:53.213825  5909 raft_consensus.cc:2804] T 00000000000000000000000000000000 P e3fde12c031e4a319f94b0fdd4ebc87a [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:16:53.214074  5909 raft_consensus.cc:697] T 00000000000000000000000000000000 P e3fde12c031e4a319f94b0fdd4ebc87a [term 1 LEADER]: Becoming Leader. State: Replica: e3fde12c031e4a319f94b0fdd4ebc87a, State: Running, Role: LEADER
I20260812 06:16:53.214550  5909 consensus_queue.cc:237] T 00000000000000000000000000000000 P e3fde12c031e4a319f94b0fdd4ebc87a [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: "e3fde12c031e4a319f94b0fdd4ebc87a" member_type: VOTER }
I20260812 06:16:53.214660  5904 sys_catalog.cc:565] T 00000000000000000000000000000000 P e3fde12c031e4a319f94b0fdd4ebc87a [sys.catalog]: configured and running, proceeding with master startup.
I20260812 06:16:53.216398  5912 sys_catalog.cc:455] T 00000000000000000000000000000000 P e3fde12c031e4a319f94b0fdd4ebc87a [sys.catalog]: SysCatalogTable state changed. Reason: New leader e3fde12c031e4a319f94b0fdd4ebc87a. Latest consensus state: current_term: 1 leader_uuid: "e3fde12c031e4a319f94b0fdd4ebc87a" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "e3fde12c031e4a319f94b0fdd4ebc87a" member_type: VOTER } }
I20260812 06:16:53.216445  5910 sys_catalog.cc:455] T 00000000000000000000000000000000 P e3fde12c031e4a319f94b0fdd4ebc87a [sys.catalog]: SysCatalogTable state changed. Reason: RaftConsensus started. Latest consensus state: current_term: 1 leader_uuid: "e3fde12c031e4a319f94b0fdd4ebc87a" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "e3fde12c031e4a319f94b0fdd4ebc87a" member_type: VOTER } }
I20260812 06:16:53.216570  5910 sys_catalog.cc:458] T 00000000000000000000000000000000 P e3fde12c031e4a319f94b0fdd4ebc87a [sys.catalog]: This master's current role is: LEADER
I20260812 06:16:53.216511  5912 sys_catalog.cc:458] T 00000000000000000000000000000000 P e3fde12c031e4a319f94b0fdd4ebc87a [sys.catalog]: This master's current role is: LEADER
I20260812 06:16:53.217024  5786 internal_mini_cluster.cc:184] Waiting to initialize catalog manager on master 0
W20260812 06:16:53.218909  5942 catalog_manager.cc:1594] T 00000000000000000000000000000000 P e3fde12c031e4a319f94b0fdd4ebc87a: loading cluster ID for follower catalog manager: Not found: cluster ID entry not found
W20260812 06:16:53.218972  5942 catalog_manager.cc:883] Not found: cluster ID entry not found: failed to prepare follower catalog manager, will retry
I20260812 06:16:53.219054  5940 catalog_manager.cc:1511] Loading table and tablet metadata into memory...
I20260812 06:16:53.219810  5940 catalog_manager.cc:1520] Initializing Kudu cluster ID...
I20260812 06:16:53.224717  5940 catalog_manager.cc:1383] Generated new cluster ID: 89eccd4867d6451ba92322b7682de571
I20260812 06:16:53.224794  5940 catalog_manager.cc:1531] Initializing Kudu internal certificate authority...
I20260812 06:16:53.235863  5940 catalog_manager.cc:1406] Generated new certificate authority record
I20260812 06:16:53.237021  5940 catalog_manager.cc:1540] Loading token signing keys...
I20260812 06:16:53.251929  5940 catalog_manager.cc:6092] T 00000000000000000000000000000000 P e3fde12c031e4a319f94b0fdd4ebc87a: Generated new TSK 0
I20260812 06:16:53.252734  5940 catalog_manager.cc:1550] Initializing in-progress tserver states...
I20260812 06:16:53.281773  5786 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:16:53.284547  5947 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:16:53.284582  5951 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:16:53.284603  5954 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:16:53.285161  5786 server_base.cc:1061] running on GCE node
I20260812 06:16:53.285346  5786 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:16:53.285387  5786 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:16:53.285403  5786 hybrid_clock.cc:648] HybridClock initialized: now 1786515413285403 us; error 0 us; skew 500 ppm
I20260812 06:16:53.286407  5786 webserver.cc:533] Webserver started at http://127.5.166.129:39089/ using document root <none> and password file <none>
I20260812 06:16:53.286602  5786 fs_manager.cc:362] Metadata directory not provided
I20260812 06:16:53.286649  5786 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:16:53.286747  5786 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:16:53.287150  5786 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taske_2AlB/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515413143058-5786-0/minicluster-data/ts-0-root/instance:
uuid: "a61e97207a4d49b990e87b0e8bd3bb2a"
format_stamp: "Formatted at 2026-08-12 06:16:53 on dist-test-slave-2d19"
I20260812 06:16:53.288785  5786 fs_manager.cc:696] Time spent creating directory manager: real 0.001s	user 0.000s	sys 0.002s
I20260812 06:16:53.289786  5960 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:16:53.290030  5786 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.000s	sys 0.001s
I20260812 06:16:53.290102  5786 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taske_2AlB/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515413143058-5786-0/minicluster-data/ts-0-root
uuid: "a61e97207a4d49b990e87b0e8bd3bb2a"
format_stamp: "Formatted at 2026-08-12 06:16:53 on dist-test-slave-2d19"
I20260812 06:16:53.290187  5786 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taske_2AlB/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515413143058-5786-0/minicluster-data/ts-0-root
metadata directory: /tmp/dist-test-taske_2AlB/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515413143058-5786-0/minicluster-data/ts-0-root
1 data directories: /tmp/dist-test-taske_2AlB/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515413143058-5786-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:16:53.298568  5786 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:16:53.299034  5786 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:16:53.299568  5786 txn_system_client.cc:432] TxnSystemClient initialization is disabled...
I20260812 06:16:53.300442  5786 ts_tablet_manager.cc:585] Loaded tablet metadata (0 total tablets, 0 live tablets)
I20260812 06:16:53.300498  5786 ts_tablet_manager.cc:531] Time spent load tablet metadata: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:16:53.300577  5786 ts_tablet_manager.cc:616] Registered 0 tablets
I20260812 06:16:53.300614  5786 ts_tablet_manager.cc:595] Time spent register tablets: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:16:53.307545  5786 rpc_server.cc:307] RPC server started. Bound to: 127.5.166.129:42689
I20260812 06:16:53.307583  6083 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.5.166.129:42689 every 8 connection(s)
I20260812 06:16:53.321134  6084 heartbeater.cc:344] Connected to a master server at 127.5.166.190:35371
I20260812 06:16:53.321404  6084 heartbeater.cc:461] Registering TS with master...
I20260812 06:16:53.321906  6084 heartbeater.cc:507] Master 127.5.166.190:35371 requested a full tablet report, sending...
I20260812 06:16:53.323392  5832 ts_manager.cc:194] Registered new tserver with Master: a61e97207a4d49b990e87b0e8bd3bb2a (127.5.166.129:42689)
I20260812 06:16:53.323951  5786 internal_mini_cluster.cc:371] 1 TS(s) registered with all masters after 0.015757535s
I20260812 06:16:53.324918  5832 master_service.cc:502] Signed X509 certificate for tserver {username='slave'} at 127.0.0.1:34958
I20260812 06:16:53.333889  5832 catalog_manager.cc:2283] Servicing CreateTable request from {username='slave'} at 127.0.0.1:34968:
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:16:53.350163  6010 tablet_service.cc:1511] Processing CreateTablet for tablet e37f2709215e40df9584f236d5837c2f (DEFAULT_TABLE table=heavy-update-compaction-test [id=df77d357aa104977bed7fcce1f0a00a9]), partition=
I20260812 06:16:53.350625  6010 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet e37f2709215e40df9584f236d5837c2f. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:16:53.353106  6106 tablet_bootstrap.cc:492] T e37f2709215e40df9584f236d5837c2f P a61e97207a4d49b990e87b0e8bd3bb2a: Bootstrap starting.
I20260812 06:16:53.354339  6106 tablet_bootstrap.cc:654] T e37f2709215e40df9584f236d5837c2f P a61e97207a4d49b990e87b0e8bd3bb2a: Neither blocks nor log segments found. Creating new log.
I20260812 06:16:53.355664  6106 tablet_bootstrap.cc:492] T e37f2709215e40df9584f236d5837c2f P a61e97207a4d49b990e87b0e8bd3bb2a: No bootstrap required, opened a new log
I20260812 06:16:53.355772  6106 ts_tablet_manager.cc:1403] T e37f2709215e40df9584f236d5837c2f P a61e97207a4d49b990e87b0e8bd3bb2a: Time spent bootstrapping tablet: real 0.003s	user 0.002s	sys 0.000s
I20260812 06:16:53.356318  6106 raft_consensus.cc:359] T e37f2709215e40df9584f236d5837c2f P a61e97207a4d49b990e87b0e8bd3bb2a [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "a61e97207a4d49b990e87b0e8bd3bb2a" member_type: VOTER last_known_addr { host: "127.5.166.129" port: 42689 } }
I20260812 06:16:53.356460  6106 raft_consensus.cc:385] T e37f2709215e40df9584f236d5837c2f P a61e97207a4d49b990e87b0e8bd3bb2a [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:16:53.356518  6106 raft_consensus.cc:740] T e37f2709215e40df9584f236d5837c2f P a61e97207a4d49b990e87b0e8bd3bb2a [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: a61e97207a4d49b990e87b0e8bd3bb2a, State: Initialized, Role: FOLLOWER
I20260812 06:16:53.356693  6106 consensus_queue.cc:260] T e37f2709215e40df9584f236d5837c2f P a61e97207a4d49b990e87b0e8bd3bb2a [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: "a61e97207a4d49b990e87b0e8bd3bb2a" member_type: VOTER last_known_addr { host: "127.5.166.129" port: 42689 } }
I20260812 06:16:53.356787  6106 raft_consensus.cc:399] T e37f2709215e40df9584f236d5837c2f P a61e97207a4d49b990e87b0e8bd3bb2a [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:16:53.356871  6106 raft_consensus.cc:493] T e37f2709215e40df9584f236d5837c2f P a61e97207a4d49b990e87b0e8bd3bb2a [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:16:53.356930  6106 raft_consensus.cc:3060] T e37f2709215e40df9584f236d5837c2f P a61e97207a4d49b990e87b0e8bd3bb2a [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:16:53.357944  6106 raft_consensus.cc:515] T e37f2709215e40df9584f236d5837c2f P a61e97207a4d49b990e87b0e8bd3bb2a [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "a61e97207a4d49b990e87b0e8bd3bb2a" member_type: VOTER last_known_addr { host: "127.5.166.129" port: 42689 } }
I20260812 06:16:53.358089  6106 leader_election.cc:304] T e37f2709215e40df9584f236d5837c2f P a61e97207a4d49b990e87b0e8bd3bb2a [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: a61e97207a4d49b990e87b0e8bd3bb2a; no voters: 
I20260812 06:16:53.358307  6106 leader_election.cc:290] T e37f2709215e40df9584f236d5837c2f P a61e97207a4d49b990e87b0e8bd3bb2a [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:16:53.358434  6108 raft_consensus.cc:2804] T e37f2709215e40df9584f236d5837c2f P a61e97207a4d49b990e87b0e8bd3bb2a [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:16:53.358698  6106 ts_tablet_manager.cc:1434] T e37f2709215e40df9584f236d5837c2f P a61e97207a4d49b990e87b0e8bd3bb2a: Time spent starting tablet: real 0.003s	user 0.000s	sys 0.003s
I20260812 06:16:53.358726  6108 raft_consensus.cc:697] T e37f2709215e40df9584f236d5837c2f P a61e97207a4d49b990e87b0e8bd3bb2a [term 1 LEADER]: Becoming Leader. State: Replica: a61e97207a4d49b990e87b0e8bd3bb2a, State: Running, Role: LEADER
I20260812 06:16:53.358974  6084 heartbeater.cc:499] Master 127.5.166.190:35371 was elected leader, sending a full tablet report...
I20260812 06:16:53.359083  6108 consensus_queue.cc:237] T e37f2709215e40df9584f236d5837c2f P a61e97207a4d49b990e87b0e8bd3bb2a [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: "a61e97207a4d49b990e87b0e8bd3bb2a" member_type: VOTER last_known_addr { host: "127.5.166.129" port: 42689 } }
I20260812 06:16:53.361976  5832 catalog_manager.cc:5719] T e37f2709215e40df9584f236d5837c2f P a61e97207a4d49b990e87b0e8bd3bb2a reported cstate change: term changed from 0 to 1, leader changed from <none> to a61e97207a4d49b990e87b0e8bd3bb2a (127.5.166.129). New cstate: current_term: 1 leader_uuid: "a61e97207a4d49b990e87b0e8bd3bb2a" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "a61e97207a4d49b990e87b0e8bd3bb2a" member_type: VOTER last_known_addr { host: "127.5.166.129" port: 42689 } health_report { overall_health: HEALTHY } } }
I20260812 06:16:53.431365  5786 heavy-update-compaction-itest.cc:215] Time spent inserting: real 0.061s	user 0.023s	sys 0.009s
I20260812 06:16:53.558650  6085 maintenance_manager.cc:419] P a61e97207a4d49b990e87b0e8bd3bb2a: Scheduling FlushMRSOp(e37f2709215e40df9584f236d5837c2f): perf score=19.054940
I20260812 06:16:53.741778  5965 maintenance_manager.cc:643] P a61e97207a4d49b990e87b0e8bd3bb2a: FlushMRSOp(e37f2709215e40df9584f236d5837c2f) complete. Timing: real 0.183s	user 0.133s	sys 0.048s Metrics: {"bytes_written":12717736,"cfile_init":1,"compiler_manager_pool.queue_time_us":195,"delete_count":0,"dirs.queue_time_us":50,"dirs.run_cpu_time_us":170,"dirs.run_wall_time_us":913,"drs_written":1,"lbm_read_time_us":69,"lbm_reads_lt_1ms":4,"lbm_write_time_us":44840,"lbm_writes_lt_1ms":767,"peak_mem_usage":0,"reinsert_count":0,"rows_written":104,"spinlock_wait_cycles":148096,"thread_start_us":131,"threads_started":1,"update_count":1550}
I20260812 06:16:53.743232  6085 maintenance_manager.cc:419] P a61e97207a4d49b990e87b0e8bd3bb2a: Scheduling LogGCOp(e37f2709215e40df9584f236d5837c2f): free 20743880 bytes of WAL
I20260812 06:16:53.743614  5965 log_reader.cc:385] T e37f2709215e40df9584f236d5837c2f: removed 2 log segments from log reader
I20260812 06:16:53.743723  5965 log.cc:1079] T e37f2709215e40df9584f236d5837c2f P a61e97207a4d49b990e87b0e8bd3bb2a: Deleting log segment in path: /tmp/dist-test-taske_2AlB/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515413143058-5786-0/minicluster-data/ts-0-root/wals/e37f2709215e40df9584f236d5837c2f/wal-000000001 (ops 1-6)
I20260812 06:16:53.743815  5965 log.cc:1079] T e37f2709215e40df9584f236d5837c2f P a61e97207a4d49b990e87b0e8bd3bb2a: Deleting log segment in path: /tmp/dist-test-taske_2AlB/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515413143058-5786-0/minicluster-data/ts-0-root/wals/e37f2709215e40df9584f236d5837c2f/wal-000000002 (ops 7-11)
I20260812 06:16:53.748389  5965 maintenance_manager.cc:643] P a61e97207a4d49b990e87b0e8bd3bb2a: LogGCOp(e37f2709215e40df9584f236d5837c2f) complete. Timing: real 0.005s	user 0.000s	sys 0.005s Metrics: {}
I20260812 06:16:53.748720  6085 maintenance_manager.cc:419] P a61e97207a4d49b990e87b0e8bd3bb2a: Scheduling UndoDeltaBlockGCOp(e37f2709215e40df9584f236d5837c2f): 16411396 bytes on disk
I20260812 06:16:53.749218  5965 maintenance_manager.cc:643] P a61e97207a4d49b990e87b0e8bd3bb2a: UndoDeltaBlockGCOp(e37f2709215e40df9584f236d5837c2f) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":46,"lbm_reads_lt_1ms":4}
I20260812 06:16:53.749699  6085 maintenance_manager.cc:419] P a61e97207a4d49b990e87b0e8bd3bb2a: Scheduling FlushDeltaMemStoresOp(e37f2709215e40df9584f236d5837c2f): perf score=3.181125
I20260812 06:16:53.770468  5965 maintenance_manager.cc:643] P a61e97207a4d49b990e87b0e8bd3bb2a: FlushDeltaMemStoresOp(e37f2709215e40df9584f236d5837c2f) complete. Timing: real 0.021s	user 0.010s	sys 0.008s Metrics: {"bytes_written":5087238,"delete_count":0,"lbm_write_time_us":5348,"lbm_writes_lt_1ms":127,"reinsert_count":0,"update_count":620}
I20260812 06:16:53.770931  6085 maintenance_manager.cc:419] P a61e97207a4d49b990e87b0e8bd3bb2a: Scheduling FlushDeltaMemStoresOp(e37f2709215e40df9584f236d5837c2f): perf score=1.196750
I20260812 06:16:53.781927  5965 maintenance_manager.cc:643] P a61e97207a4d49b990e87b0e8bd3bb2a: FlushDeltaMemStoresOp(e37f2709215e40df9584f236d5837c2f) complete. Timing: real 0.011s	user 0.005s	sys 0.004s Metrics: {"bytes_written":2707805,"delete_count":0,"lbm_write_time_us":3913,"lbm_writes_lt_1ms":69,"reinsert_count":0,"update_count":330}
I20260812 06:16:53.782363  6085 maintenance_manager.cc:419] P a61e97207a4d49b990e87b0e8bd3bb2a: Scheduling MajorDeltaCompactionOp(e37f2709215e40df9584f236d5837c2f): perf score=1.000000
I20260812 06:16:53.961988  5965 maintenance_manager.cc:643] P a61e97207a4d49b990e87b0e8bd3bb2a: MajorDeltaCompactionOp(e37f2709215e40df9584f236d5837c2f) complete. Timing: real 0.179s	user 0.117s	sys 0.062s Metrics: {"cfile_cache_miss":533,"cfile_cache_miss_bytes":24774779,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":551,"lbm_read_time_us":14431,"lbm_reads_lt_1ms":569,"lbm_write_time_us":29168,"lbm_writes_lt_1ms":543,"mutex_wait_us":24,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":12288,"thread_start_us":332,"threads_started":5,"update_count":2500}
I20260812 06:16:53.962605  6085 maintenance_manager.cc:419] P a61e97207a4d49b990e87b0e8bd3bb2a: Scheduling FlushDeltaMemStoresOp(e37f2709215e40df9584f236d5837c2f): perf score=10.126437
I20260812 06:16:54.004238  5965 maintenance_manager.cc:643] P a61e97207a4d49b990e87b0e8bd3bb2a: FlushDeltaMemStoresOp(e37f2709215e40df9584f236d5837c2f) complete. Timing: real 0.041s	user 0.026s	sys 0.012s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":17709,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:16:54.004793  6085 maintenance_manager.cc:419] P a61e97207a4d49b990e87b0e8bd3bb2a: Scheduling FlushDeltaMemStoresOp(e37f2709215e40df9584f236d5837c2f): perf score=2.188937
I20260812 06:16:54.015774  5965 maintenance_manager.cc:643] P a61e97207a4d49b990e87b0e8bd3bb2a: FlushDeltaMemStoresOp(e37f2709215e40df9584f236d5837c2f) complete. Timing: real 0.011s	user 0.001s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4205,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:54.016347  6085 maintenance_manager.cc:419] P a61e97207a4d49b990e87b0e8bd3bb2a: Scheduling MajorDeltaCompactionOp(e37f2709215e40df9584f236d5837c2f): perf score=1.000000
I20260812 06:16:54.142850  5965 maintenance_manager.cc:643] P a61e97207a4d49b990e87b0e8bd3bb2a: MajorDeltaCompactionOp(e37f2709215e40df9584f236d5837c2f) complete. Timing: real 0.126s	user 0.106s	sys 0.017s 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":204,"lbm_read_time_us":7924,"lbm_reads_lt_1ms":472,"lbm_write_time_us":25104,"lbm_writes_lt_1ms":443,"mutex_wait_us":26,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":10112,"update_count":2000}
I20260812 06:16:54.143447  6085 maintenance_manager.cc:419] P a61e97207a4d49b990e87b0e8bd3bb2a: Scheduling FlushDeltaMemStoresOp(e37f2709215e40df9584f236d5837c2f): perf score=10.126437
I20260812 06:16:54.189761  5965 maintenance_manager.cc:643] P a61e97207a4d49b990e87b0e8bd3bb2a: FlushDeltaMemStoresOp(e37f2709215e40df9584f236d5837c2f) complete. Timing: real 0.046s	user 0.029s	sys 0.004s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":15048,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:16:54.190191  6085 maintenance_manager.cc:419] P a61e97207a4d49b990e87b0e8bd3bb2a: Scheduling FlushDeltaMemStoresOp(e37f2709215e40df9584f236d5837c2f): perf score=2.188937
I20260812 06:16:54.201045  5965 maintenance_manager.cc:643] P a61e97207a4d49b990e87b0e8bd3bb2a: FlushDeltaMemStoresOp(e37f2709215e40df9584f236d5837c2f) complete. Timing: real 0.011s	user 0.006s	sys 0.004s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4081,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:54.201722  6085 maintenance_manager.cc:419] P a61e97207a4d49b990e87b0e8bd3bb2a: Scheduling MajorDeltaCompactionOp(e37f2709215e40df9584f236d5837c2f): perf score=1.000000
I20260812 06:16:54.317968  5965 maintenance_manager.cc:643] P a61e97207a4d49b990e87b0e8bd3bb2a: MajorDeltaCompactionOp(e37f2709215e40df9584f236d5837c2f) complete. Timing: real 0.116s	user 0.092s	sys 0.024s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672276,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":680,"lbm_read_time_us":7671,"lbm_reads_lt_1ms":472,"lbm_write_time_us":22390,"lbm_writes_lt_1ms":443,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":7040,"update_count":2000}
I20260812 06:16:54.318537  6085 maintenance_manager.cc:419] P a61e97207a4d49b990e87b0e8bd3bb2a: Scheduling FlushDeltaMemStoresOp(e37f2709215e40df9584f236d5837c2f): perf score=10.126437
I20260812 06:16:54.364792  5965 maintenance_manager.cc:643] P a61e97207a4d49b990e87b0e8bd3bb2a: FlushDeltaMemStoresOp(e37f2709215e40df9584f236d5837c2f) complete. Timing: real 0.046s	user 0.024s	sys 0.016s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":17760,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:16:54.365284  6085 maintenance_manager.cc:419] P a61e97207a4d49b990e87b0e8bd3bb2a: Scheduling FlushDeltaMemStoresOp(e37f2709215e40df9584f236d5837c2f): perf score=2.188937
I20260812 06:16:54.376515  5965 maintenance_manager.cc:643] P a61e97207a4d49b990e87b0e8bd3bb2a: FlushDeltaMemStoresOp(e37f2709215e40df9584f236d5837c2f) complete. Timing: real 0.011s	user 0.004s	sys 0.007s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4258,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:54.377238  6085 maintenance_manager.cc:419] P a61e97207a4d49b990e87b0e8bd3bb2a: Scheduling MajorDeltaCompactionOp(e37f2709215e40df9584f236d5837c2f): perf score=1.000000
I20260812 06:16:54.496212  5965 maintenance_manager.cc:643] P a61e97207a4d49b990e87b0e8bd3bb2a: MajorDeltaCompactionOp(e37f2709215e40df9584f236d5837c2f) complete. Timing: real 0.119s	user 0.093s	sys 0.024s 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":179,"lbm_read_time_us":8538,"lbm_reads_lt_1ms":472,"lbm_write_time_us":24081,"lbm_writes_lt_1ms":443,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":17152,"update_count":2000}
I20260812 06:16:54.496711  6085 maintenance_manager.cc:419] P a61e97207a4d49b990e87b0e8bd3bb2a: Scheduling FlushDeltaMemStoresOp(e37f2709215e40df9584f236d5837c2f): perf score=10.126437
I20260812 06:16:54.548894  5965 maintenance_manager.cc:643] P a61e97207a4d49b990e87b0e8bd3bb2a: FlushDeltaMemStoresOp(e37f2709215e40df9584f236d5837c2f) complete. Timing: real 0.052s	user 0.023s	sys 0.025s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":17068,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":302,"reinsert_count":0,"update_count":1500}
I20260812 06:16:54.549549  6085 maintenance_manager.cc:419] P a61e97207a4d49b990e87b0e8bd3bb2a: Scheduling FlushDeltaMemStoresOp(e37f2709215e40df9584f236d5837c2f): perf score=2.188937
I20260812 06:16:54.565932  5965 maintenance_manager.cc:643] P a61e97207a4d49b990e87b0e8bd3bb2a: FlushDeltaMemStoresOp(e37f2709215e40df9584f236d5837c2f) complete. Timing: real 0.016s	user 0.006s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6176,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:54.566462  6085 maintenance_manager.cc:419] P a61e97207a4d49b990e87b0e8bd3bb2a: Scheduling MajorDeltaCompactionOp(e37f2709215e40df9584f236d5837c2f): perf score=1.000000
I20260812 06:16:54.712455  5965 maintenance_manager.cc:643] P a61e97207a4d49b990e87b0e8bd3bb2a: MajorDeltaCompactionOp(e37f2709215e40df9584f236d5837c2f) complete. Timing: real 0.146s	user 0.089s	sys 0.056s 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":882,"lbm_read_time_us":10720,"lbm_reads_lt_1ms":472,"lbm_write_time_us":26220,"lbm_writes_lt_1ms":443,"mutex_wait_us":22,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":7296,"update_count":2000}
I20260812 06:16:54.713050  6085 maintenance_manager.cc:419] P a61e97207a4d49b990e87b0e8bd3bb2a: Scheduling FlushDeltaMemStoresOp(e37f2709215e40df9584f236d5837c2f): perf score=10.126437
I20260812 06:16:54.754662  5965 maintenance_manager.cc:643] P a61e97207a4d49b990e87b0e8bd3bb2a: FlushDeltaMemStoresOp(e37f2709215e40df9584f236d5837c2f) complete. Timing: real 0.041s	user 0.021s	sys 0.016s Metrics: {"bytes_written":12307491,"delete_count":0,"lbm_write_time_us":17052,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:16:54.755203  6085 maintenance_manager.cc:419] P a61e97207a4d49b990e87b0e8bd3bb2a: Scheduling FlushDeltaMemStoresOp(e37f2709215e40df9584f236d5837c2f): perf score=2.188937
I20260812 06:16:54.765754  5965 maintenance_manager.cc:643] P a61e97207a4d49b990e87b0e8bd3bb2a: FlushDeltaMemStoresOp(e37f2709215e40df9584f236d5837c2f) complete. Timing: real 0.010s	user 0.009s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4139,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:54.766472  6085 maintenance_manager.cc:419] P a61e97207a4d49b990e87b0e8bd3bb2a: Scheduling MajorDeltaCompactionOp(e37f2709215e40df9584f236d5837c2f): perf score=1.000000
I20260812 06:16:54.886812  5965 maintenance_manager.cc:643] P a61e97207a4d49b990e87b0e8bd3bb2a: MajorDeltaCompactionOp(e37f2709215e40df9584f236d5837c2f) complete. Timing: real 0.120s	user 0.093s	sys 0.027s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672278,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":292,"lbm_read_time_us":9502,"lbm_reads_lt_1ms":472,"lbm_write_time_us":21941,"lbm_writes_lt_1ms":443,"mutex_wait_us":34,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":14336,"update_count":2000}
I20260812 06:16:54.887343  6085 maintenance_manager.cc:419] P a61e97207a4d49b990e87b0e8bd3bb2a: Scheduling FlushDeltaMemStoresOp(e37f2709215e40df9584f236d5837c2f): perf score=10.126437
I20260812 06:16:54.926404  5965 maintenance_manager.cc:643] P a61e97207a4d49b990e87b0e8bd3bb2a: FlushDeltaMemStoresOp(e37f2709215e40df9584f236d5837c2f) complete. Timing: real 0.039s	user 0.015s	sys 0.019s Metrics: {"bytes_written":12307492,"delete_count":0,"lbm_write_time_us":16110,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:16:54.926945  6085 maintenance_manager.cc:419] P a61e97207a4d49b990e87b0e8bd3bb2a: Scheduling FlushDeltaMemStoresOp(e37f2709215e40df9584f236d5837c2f): perf score=2.188937
I20260812 06:16:54.937124  5965 maintenance_manager.cc:643] P a61e97207a4d49b990e87b0e8bd3bb2a: FlushDeltaMemStoresOp(e37f2709215e40df9584f236d5837c2f) complete. Timing: real 0.010s	user 0.004s	sys 0.005s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4019,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:54.937706  6085 maintenance_manager.cc:419] P a61e97207a4d49b990e87b0e8bd3bb2a: Scheduling FlushMRSOp(e37f2709215e40df9584f236d5837c2f): perf score=1.000000
I20260812 06:16:54.969548  5965 maintenance_manager.cc:643] P a61e97207a4d49b990e87b0e8bd3bb2a: FlushMRSOp(e37f2709215e40df9584f236d5837c2f) complete. Timing: real 0.032s	user 0.026s	sys 0.003s Metrics: {"bytes_written":1193503,"cfile_init":1,"dirs.queue_time_us":81,"dirs.run_cpu_time_us":253,"dirs.run_wall_time_us":1675,"drs_written":1,"lbm_read_time_us":63,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1910,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":29}
I20260812 06:16:54.970443  6085 maintenance_manager.cc:419] P a61e97207a4d49b990e87b0e8bd3bb2a: Scheduling LogGCOp(e37f2709215e40df9584f236d5837c2f): free 120553330 bytes of WAL
I20260812 06:16:54.970703  5965 log_reader.cc:385] T e37f2709215e40df9584f236d5837c2f: removed 12 log segments from log reader
I20260812 06:16:54.970772  5965 log.cc:1079] T e37f2709215e40df9584f236d5837c2f P a61e97207a4d49b990e87b0e8bd3bb2a: Deleting log segment in path: /tmp/dist-test-taske_2AlB/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515413143058-5786-0/minicluster-data/ts-0-root/wals/e37f2709215e40df9584f236d5837c2f/wal-000000003 (ops 12-16)
I20260812 06:16:54.970829  5965 log.cc:1079] T e37f2709215e40df9584f236d5837c2f P a61e97207a4d49b990e87b0e8bd3bb2a: Deleting log segment in path: /tmp/dist-test-taske_2AlB/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515413143058-5786-0/minicluster-data/ts-0-root/wals/e37f2709215e40df9584f236d5837c2f/wal-000000004 (ops 17-21)
I20260812 06:16:54.970885  5965 log.cc:1079] T e37f2709215e40df9584f236d5837c2f P a61e97207a4d49b990e87b0e8bd3bb2a: Deleting log segment in path: /tmp/dist-test-taske_2AlB/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515413143058-5786-0/minicluster-data/ts-0-root/wals/e37f2709215e40df9584f236d5837c2f/wal-000000005 (ops 22-26)
I20260812 06:16:54.970928  5965 log.cc:1079] T e37f2709215e40df9584f236d5837c2f P a61e97207a4d49b990e87b0e8bd3bb2a: Deleting log segment in path: /tmp/dist-test-taske_2AlB/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515413143058-5786-0/minicluster-data/ts-0-root/wals/e37f2709215e40df9584f236d5837c2f/wal-000000006 (ops 27-30)
I20260812 06:16:54.970978  5965 log.cc:1079] T e37f2709215e40df9584f236d5837c2f P a61e97207a4d49b990e87b0e8bd3bb2a: Deleting log segment in path: /tmp/dist-test-taske_2AlB/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515413143058-5786-0/minicluster-data/ts-0-root/wals/e37f2709215e40df9584f236d5837c2f/wal-000000007 (ops 31-35)
I20260812 06:16:54.971015  5965 log.cc:1079] T e37f2709215e40df9584f236d5837c2f P a61e97207a4d49b990e87b0e8bd3bb2a: Deleting log segment in path: /tmp/dist-test-taske_2AlB/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515413143058-5786-0/minicluster-data/ts-0-root/wals/e37f2709215e40df9584f236d5837c2f/wal-000000008 (ops 36-40)
I20260812 06:16:54.971055  5965 log.cc:1079] T e37f2709215e40df9584f236d5837c2f P a61e97207a4d49b990e87b0e8bd3bb2a: Deleting log segment in path: /tmp/dist-test-taske_2AlB/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515413143058-5786-0/minicluster-data/ts-0-root/wals/e37f2709215e40df9584f236d5837c2f/wal-000000009 (ops 41-45)
I20260812 06:16:54.971093  5965 log.cc:1079] T e37f2709215e40df9584f236d5837c2f P a61e97207a4d49b990e87b0e8bd3bb2a: Deleting log segment in path: /tmp/dist-test-taske_2AlB/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515413143058-5786-0/minicluster-data/ts-0-root/wals/e37f2709215e40df9584f236d5837c2f/wal-000000010 (ops 46-50)
I20260812 06:16:54.971133  5965 log.cc:1079] T e37f2709215e40df9584f236d5837c2f P a61e97207a4d49b990e87b0e8bd3bb2a: Deleting log segment in path: /tmp/dist-test-taske_2AlB/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515413143058-5786-0/minicluster-data/ts-0-root/wals/e37f2709215e40df9584f236d5837c2f/wal-000000011 (ops 51-55)
I20260812 06:16:54.971174  5965 log.cc:1079] T e37f2709215e40df9584f236d5837c2f P a61e97207a4d49b990e87b0e8bd3bb2a: Deleting log segment in path: /tmp/dist-test-taske_2AlB/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515413143058-5786-0/minicluster-data/ts-0-root/wals/e37f2709215e40df9584f236d5837c2f/wal-000000012 (ops 56-60)
I20260812 06:16:54.971212  5965 log.cc:1079] T e37f2709215e40df9584f236d5837c2f P a61e97207a4d49b990e87b0e8bd3bb2a: Deleting log segment in path: /tmp/dist-test-taske_2AlB/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515413143058-5786-0/minicluster-data/ts-0-root/wals/e37f2709215e40df9584f236d5837c2f/wal-000000013 (ops 61-64)
I20260812 06:16:54.971252  5965 log.cc:1079] T e37f2709215e40df9584f236d5837c2f P a61e97207a4d49b990e87b0e8bd3bb2a: Deleting log segment in path: /tmp/dist-test-taske_2AlB/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515413143058-5786-0/minicluster-data/ts-0-root/wals/e37f2709215e40df9584f236d5837c2f/wal-000000014 (ops 65-69)
I20260812 06:16:54.997463  5965 maintenance_manager.cc:643] P a61e97207a4d49b990e87b0e8bd3bb2a: LogGCOp(e37f2709215e40df9584f236d5837c2f) complete. Timing: real 0.027s	user 0.000s	sys 0.026s Metrics: {}
I20260812 06:16:54.998037  6085 maintenance_manager.cc:419] P a61e97207a4d49b990e87b0e8bd3bb2a: Scheduling FlushDeltaMemStoresOp(e37f2709215e40df9584f236d5837c2f): perf score=2.188937
I20260812 06:16:55.018055  5965 maintenance_manager.cc:643] P a61e97207a4d49b990e87b0e8bd3bb2a: FlushDeltaMemStoresOp(e37f2709215e40df9584f236d5837c2f) complete. Timing: real 0.020s	user 0.015s	sys 0.000s Metrics: {"bytes_written":4225734,"delete_count":0,"lbm_write_time_us":6439,"lbm_writes_lt_1ms":106,"mutex_wait_us":162,"reinsert_count":0,"update_count":515}
I20260812 06:16:55.018584  6085 maintenance_manager.cc:419] P a61e97207a4d49b990e87b0e8bd3bb2a: Scheduling UndoDeltaBlockGCOp(e37f2709215e40df9584f236d5837c2f): 463 bytes on disk
I20260812 06:16:55.019224  5965 maintenance_manager.cc:643] P a61e97207a4d49b990e87b0e8bd3bb2a: UndoDeltaBlockGCOp(e37f2709215e40df9584f236d5837c2f) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":64,"lbm_reads_lt_1ms":4}
I20260812 06:16:55.019706  6085 maintenance_manager.cc:419] P a61e97207a4d49b990e87b0e8bd3bb2a: Scheduling FlushDeltaMemStoresOp(e37f2709215e40df9584f236d5837c2f): perf score=2.188937
I20260812 06:16:55.034337  5965 maintenance_manager.cc:643] P a61e97207a4d49b990e87b0e8bd3bb2a: FlushDeltaMemStoresOp(e37f2709215e40df9584f236d5837c2f) complete. Timing: real 0.014s	user 0.012s	sys 0.000s Metrics: {"bytes_written":3979583,"delete_count":0,"lbm_write_time_us":5365,"lbm_writes_lt_1ms":100,"reinsert_count":0,"update_count":485}
I20260812 06:16:55.034933  6085 maintenance_manager.cc:419] P a61e97207a4d49b990e87b0e8bd3bb2a: Scheduling MajorDeltaCompactionOp(e37f2709215e40df9584f236d5837c2f): perf score=1.000000
I20260812 06:16:55.212529  5965 maintenance_manager.cc:643] P a61e97207a4d49b990e87b0e8bd3bb2a: MajorDeltaCompactionOp(e37f2709215e40df9584f236d5837c2f) complete. Timing: real 0.177s	user 0.131s	sys 0.035s Metrics: {"cfile_cache_miss":634,"cfile_cache_miss_bytes":28877339,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":2990,"lbm_read_time_us":10812,"lbm_reads_lt_1ms":674,"lbm_write_time_us":34539,"lbm_writes_lt_1ms":643,"mutex_wait_us":1877,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":6912,"thread_start_us":92,"threads_started":1,"update_count":3000}
I20260812 06:16:55.213214  6085 maintenance_manager.cc:419] P a61e97207a4d49b990e87b0e8bd3bb2a: Scheduling FlushDeltaMemStoresOp(e37f2709215e40df9584f236d5837c2f): perf score=14.095187
I20260812 06:16:55.268571  5965 maintenance_manager.cc:643] P a61e97207a4d49b990e87b0e8bd3bb2a: FlushDeltaMemStoresOp(e37f2709215e40df9584f236d5837c2f) complete. Timing: real 0.055s	user 0.036s	sys 0.015s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":22195,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:16:55.269568  6085 maintenance_manager.cc:419] P a61e97207a4d49b990e87b0e8bd3bb2a: Scheduling FlushDeltaMemStoresOp(e37f2709215e40df9584f236d5837c2f): perf score=2.188937
I20260812 06:16:55.288219  5965 maintenance_manager.cc:643] P a61e97207a4d49b990e87b0e8bd3bb2a: FlushDeltaMemStoresOp(e37f2709215e40df9584f236d5837c2f) complete. Timing: real 0.018s	user 0.013s	sys 0.003s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6719,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:55.290297  6085 maintenance_manager.cc:419] P a61e97207a4d49b990e87b0e8bd3bb2a: Scheduling MajorDeltaCompactionOp(e37f2709215e40df9584f236d5837c2f): perf score=1.000000
I20260812 06:16:55.451510  5965 maintenance_manager.cc:643] P a61e97207a4d49b990e87b0e8bd3bb2a: MajorDeltaCompactionOp(e37f2709215e40df9584f236d5837c2f) complete. Timing: real 0.161s	user 0.120s	sys 0.031s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774689,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":204,"lbm_read_time_us":8861,"lbm_reads_lt_1ms":564,"lbm_write_time_us":34667,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":542,"mutex_wait_us":54,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":10496,"update_count":2500}
I20260812 06:16:55.452147  6085 maintenance_manager.cc:419] P a61e97207a4d49b990e87b0e8bd3bb2a: Scheduling FlushDeltaMemStoresOp(e37f2709215e40df9584f236d5837c2f): perf score=14.095187
I20260812 06:16:55.515036  5965 maintenance_manager.cc:643] P a61e97207a4d49b990e87b0e8bd3bb2a: FlushDeltaMemStoresOp(e37f2709215e40df9584f236d5837c2f) complete. Timing: real 0.063s	user 0.019s	sys 0.026s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":21239,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:16:55.515707  6085 maintenance_manager.cc:419] P a61e97207a4d49b990e87b0e8bd3bb2a: Scheduling FlushDeltaMemStoresOp(e37f2709215e40df9584f236d5837c2f): perf score=2.188937
I20260812 06:16:55.526147  5965 maintenance_manager.cc:643] P a61e97207a4d49b990e87b0e8bd3bb2a: FlushDeltaMemStoresOp(e37f2709215e40df9584f236d5837c2f) complete. Timing: real 0.010s	user 0.008s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3894,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:55.526780  6085 maintenance_manager.cc:419] P a61e97207a4d49b990e87b0e8bd3bb2a: Scheduling MajorDeltaCompactionOp(e37f2709215e40df9584f236d5837c2f): perf score=1.000000
I20260812 06:16:55.704433  5965 maintenance_manager.cc:643] P a61e97207a4d49b990e87b0e8bd3bb2a: MajorDeltaCompactionOp(e37f2709215e40df9584f236d5837c2f) complete. Timing: real 0.177s	user 0.110s	sys 0.060s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774688,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":658,"lbm_read_time_us":11010,"lbm_reads_lt_1ms":572,"lbm_write_time_us":31056,"lbm_writes_lt_1ms":543,"mutex_wait_us":27,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":141056,"update_count":2500}
I20260812 06:16:55.705168  6085 maintenance_manager.cc:419] P a61e97207a4d49b990e87b0e8bd3bb2a: Scheduling FlushDeltaMemStoresOp(e37f2709215e40df9584f236d5837c2f): perf score=14.095187
I20260812 06:16:55.765761  5965 maintenance_manager.cc:643] P a61e97207a4d49b990e87b0e8bd3bb2a: FlushDeltaMemStoresOp(e37f2709215e40df9584f236d5837c2f) complete. Timing: real 0.060s	user 0.041s	sys 0.001s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":18980,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:16:55.766287  6085 maintenance_manager.cc:419] P a61e97207a4d49b990e87b0e8bd3bb2a: Scheduling FlushDeltaMemStoresOp(e37f2709215e40df9584f236d5837c2f): perf score=2.188937
I20260812 06:16:55.781863  5965 maintenance_manager.cc:643] P a61e97207a4d49b990e87b0e8bd3bb2a: FlushDeltaMemStoresOp(e37f2709215e40df9584f236d5837c2f) complete. Timing: real 0.015s	user 0.010s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5695,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:55.782496  6085 maintenance_manager.cc:419] P a61e97207a4d49b990e87b0e8bd3bb2a: Scheduling MajorDeltaCompactionOp(e37f2709215e40df9584f236d5837c2f): perf score=1.000000
I20260812 06:16:55.962328  5965 maintenance_manager.cc:643] P a61e97207a4d49b990e87b0e8bd3bb2a: MajorDeltaCompactionOp(e37f2709215e40df9584f236d5837c2f) complete. Timing: real 0.180s	user 0.122s	sys 0.051s 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":565,"lbm_read_time_us":12806,"lbm_reads_lt_1ms":572,"lbm_write_time_us":30136,"lbm_writes_lt_1ms":543,"mutex_wait_us":32,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":2816,"update_count":2500}
I20260812 06:16:55.963093  6085 maintenance_manager.cc:419] P a61e97207a4d49b990e87b0e8bd3bb2a: Scheduling FlushDeltaMemStoresOp(e37f2709215e40df9584f236d5837c2f): perf score=14.095187
I20260812 06:16:56.015604  5965 maintenance_manager.cc:643] P a61e97207a4d49b990e87b0e8bd3bb2a: FlushDeltaMemStoresOp(e37f2709215e40df9584f236d5837c2f) complete. Timing: real 0.052s	user 0.025s	sys 0.024s Metrics: {"bytes_written":16409903,"delete_count":0,"lbm_write_time_us":23623,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":402,"reinsert_count":0,"update_count":2000}
I20260812 06:16:56.016376  6085 maintenance_manager.cc:419] P a61e97207a4d49b990e87b0e8bd3bb2a: Scheduling FlushDeltaMemStoresOp(e37f2709215e40df9584f236d5837c2f): perf score=2.188937
I20260812 06:16:56.033371  5965 maintenance_manager.cc:643] P a61e97207a4d49b990e87b0e8bd3bb2a: FlushDeltaMemStoresOp(e37f2709215e40df9584f236d5837c2f) complete. Timing: real 0.017s	user 0.015s	sys 0.001s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6581,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:56.035277  6085 maintenance_manager.cc:419] P a61e97207a4d49b990e87b0e8bd3bb2a: Scheduling MajorDeltaCompactionOp(e37f2709215e40df9584f236d5837c2f): perf score=1.000000
I20260812 06:16:56.209813  5965 maintenance_manager.cc:643] P a61e97207a4d49b990e87b0e8bd3bb2a: MajorDeltaCompactionOp(e37f2709215e40df9584f236d5837c2f) complete. Timing: real 0.174s	user 0.110s	sys 0.063s 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":169,"lbm_read_time_us":12030,"lbm_reads_lt_1ms":564,"lbm_write_time_us":29297,"lbm_writes_lt_1ms":543,"mutex_wait_us":37,"peak_mem_usage":63115900,"reinsert_count":0,"update_count":2500}
I20260812 06:16:56.210892  6085 maintenance_manager.cc:419] P a61e97207a4d49b990e87b0e8bd3bb2a: Scheduling FlushDeltaMemStoresOp(e37f2709215e40df9584f236d5837c2f): perf score=14.095187
I20260812 06:16:56.275368  5965 maintenance_manager.cc:643] P a61e97207a4d49b990e87b0e8bd3bb2a: FlushDeltaMemStoresOp(e37f2709215e40df9584f236d5837c2f) complete. Timing: real 0.064s	user 0.031s	sys 0.027s Metrics: {"bytes_written":16409903,"delete_count":0,"lbm_write_time_us":23430,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:16:56.275978  6085 maintenance_manager.cc:419] P a61e97207a4d49b990e87b0e8bd3bb2a: Scheduling FlushDeltaMemStoresOp(e37f2709215e40df9584f236d5837c2f): perf score=2.188937
I20260812 06:16:56.286505  5965 maintenance_manager.cc:643] P a61e97207a4d49b990e87b0e8bd3bb2a: FlushDeltaMemStoresOp(e37f2709215e40df9584f236d5837c2f) complete. Timing: real 0.010s	user 0.006s	sys 0.003s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4058,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:56.286904  6085 maintenance_manager.cc:419] P a61e97207a4d49b990e87b0e8bd3bb2a: Scheduling MajorDeltaCompactionOp(e37f2709215e40df9584f236d5837c2f): perf score=1.000000
I20260812 06:16:56.458463  5965 maintenance_manager.cc:643] P a61e97207a4d49b990e87b0e8bd3bb2a: MajorDeltaCompactionOp(e37f2709215e40df9584f236d5837c2f) complete. Timing: real 0.171s	user 0.117s	sys 0.052s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774690,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":156,"lbm_read_time_us":13046,"lbm_reads_lt_1ms":572,"lbm_write_time_us":30599,"lbm_writes_lt_1ms":543,"peak_mem_usage":63115900,"reinsert_count":0,"update_count":2500}
I20260812 06:16:56.459224  6085 maintenance_manager.cc:419] P a61e97207a4d49b990e87b0e8bd3bb2a: Scheduling FlushDeltaMemStoresOp(e37f2709215e40df9584f236d5837c2f): perf score=10.126437
I20260812 06:16:56.491086  5965 maintenance_manager.cc:643] P a61e97207a4d49b990e87b0e8bd3bb2a: FlushDeltaMemStoresOp(e37f2709215e40df9584f236d5837c2f) complete. Timing: real 0.032s	user 0.021s	sys 0.008s Metrics: {"bytes_written":12307491,"delete_count":0,"lbm_write_time_us":13622,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:16:56.491732  6085 maintenance_manager.cc:419] P a61e97207a4d49b990e87b0e8bd3bb2a: Scheduling FlushDeltaMemStoresOp(e37f2709215e40df9584f236d5837c2f): perf score=2.188937
I20260812 06:16:56.508993  5965 maintenance_manager.cc:643] P a61e97207a4d49b990e87b0e8bd3bb2a: FlushDeltaMemStoresOp(e37f2709215e40df9584f236d5837c2f) complete. Timing: real 0.017s	user 0.011s	sys 0.003s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":7777,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":102,"reinsert_count":0,"update_count":500}
I20260812 06:16:56.509546  6085 maintenance_manager.cc:419] P a61e97207a4d49b990e87b0e8bd3bb2a: Scheduling FlushMRSOp(e37f2709215e40df9584f236d5837c2f): perf score=1.000000
I20260812 06:16:56.545063  5965 maintenance_manager.cc:643] P a61e97207a4d49b990e87b0e8bd3bb2a: FlushMRSOp(e37f2709215e40df9584f236d5837c2f) complete. Timing: real 0.035s	user 0.021s	sys 0.012s Metrics: {"bytes_written":1275449,"cfile_init":1,"dirs.queue_time_us":60,"dirs.run_cpu_time_us":238,"dirs.run_wall_time_us":1356,"drs_written":1,"lbm_read_time_us":85,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1547,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":31}
I20260812 06:16:56.545874  6085 maintenance_manager.cc:419] P a61e97207a4d49b990e87b0e8bd3bb2a: Scheduling LogGCOp(e37f2709215e40df9584f236d5837c2f): free 124257307 bytes of WAL
I20260812 06:16:56.546126  5965 log_reader.cc:385] T e37f2709215e40df9584f236d5837c2f: removed 12 log segments from log reader
I20260812 06:16:56.546173  5965 log.cc:1079] T e37f2709215e40df9584f236d5837c2f P a61e97207a4d49b990e87b0e8bd3bb2a: Deleting log segment in path: /tmp/dist-test-taske_2AlB/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515413143058-5786-0/minicluster-data/ts-0-root/wals/e37f2709215e40df9584f236d5837c2f/wal-000000015 (ops 70-74)
I20260812 06:16:56.546202  5965 log.cc:1079] T e37f2709215e40df9584f236d5837c2f P a61e97207a4d49b990e87b0e8bd3bb2a: Deleting log segment in path: /tmp/dist-test-taske_2AlB/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515413143058-5786-0/minicluster-data/ts-0-root/wals/e37f2709215e40df9584f236d5837c2f/wal-000000016 (ops 75-79)
I20260812 06:16:56.546262  5965 log.cc:1079] T e37f2709215e40df9584f236d5837c2f P a61e97207a4d49b990e87b0e8bd3bb2a: Deleting log segment in path: /tmp/dist-test-taske_2AlB/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515413143058-5786-0/minicluster-data/ts-0-root/wals/e37f2709215e40df9584f236d5837c2f/wal-000000017 (ops 80-84)
I20260812 06:16:56.546295  5965 log.cc:1079] T e37f2709215e40df9584f236d5837c2f P a61e97207a4d49b990e87b0e8bd3bb2a: Deleting log segment in path: /tmp/dist-test-taske_2AlB/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515413143058-5786-0/minicluster-data/ts-0-root/wals/e37f2709215e40df9584f236d5837c2f/wal-000000018 (ops 85-89)
I20260812 06:16:56.546339  5965 log.cc:1079] T e37f2709215e40df9584f236d5837c2f P a61e97207a4d49b990e87b0e8bd3bb2a: Deleting log segment in path: /tmp/dist-test-taske_2AlB/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515413143058-5786-0/minicluster-data/ts-0-root/wals/e37f2709215e40df9584f236d5837c2f/wal-000000019 (ops 90-94)
I20260812 06:16:56.546399  5965 log.cc:1079] T e37f2709215e40df9584f236d5837c2f P a61e97207a4d49b990e87b0e8bd3bb2a: Deleting log segment in path: /tmp/dist-test-taske_2AlB/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515413143058-5786-0/minicluster-data/ts-0-root/wals/e37f2709215e40df9584f236d5837c2f/wal-000000020 (ops 95-99)
I20260812 06:16:56.546439  5965 log.cc:1079] T e37f2709215e40df9584f236d5837c2f P a61e97207a4d49b990e87b0e8bd3bb2a: Deleting log segment in path: /tmp/dist-test-taske_2AlB/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515413143058-5786-0/minicluster-data/ts-0-root/wals/e37f2709215e40df9584f236d5837c2f/wal-000000021 (ops 100-104)
I20260812 06:16:56.546482  5965 log.cc:1079] T e37f2709215e40df9584f236d5837c2f P a61e97207a4d49b990e87b0e8bd3bb2a: Deleting log segment in path: /tmp/dist-test-taske_2AlB/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515413143058-5786-0/minicluster-data/ts-0-root/wals/e37f2709215e40df9584f236d5837c2f/wal-000000022 (ops 105-108)
I20260812 06:16:56.546521  5965 log.cc:1079] T e37f2709215e40df9584f236d5837c2f P a61e97207a4d49b990e87b0e8bd3bb2a: Deleting log segment in path: /tmp/dist-test-taske_2AlB/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515413143058-5786-0/minicluster-data/ts-0-root/wals/e37f2709215e40df9584f236d5837c2f/wal-000000023 (ops 109-113)
I20260812 06:16:56.546561  5965 log.cc:1079] T e37f2709215e40df9584f236d5837c2f P a61e97207a4d49b990e87b0e8bd3bb2a: Deleting log segment in path: /tmp/dist-test-taske_2AlB/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515413143058-5786-0/minicluster-data/ts-0-root/wals/e37f2709215e40df9584f236d5837c2f/wal-000000024 (ops 114-118)
I20260812 06:16:56.546597  5965 log.cc:1079] T e37f2709215e40df9584f236d5837c2f P a61e97207a4d49b990e87b0e8bd3bb2a: Deleting log segment in path: /tmp/dist-test-taske_2AlB/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515413143058-5786-0/minicluster-data/ts-0-root/wals/e37f2709215e40df9584f236d5837c2f/wal-000000025 (ops 119-123)
I20260812 06:16:56.546635  5965 log.cc:1079] T e37f2709215e40df9584f236d5837c2f P a61e97207a4d49b990e87b0e8bd3bb2a: Deleting log segment in path: /tmp/dist-test-taske_2AlB/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515413143058-5786-0/minicluster-data/ts-0-root/wals/e37f2709215e40df9584f236d5837c2f/wal-000000026 (ops 124-128)
I20260812 06:16:56.573252  5965 maintenance_manager.cc:643] P a61e97207a4d49b990e87b0e8bd3bb2a: LogGCOp(e37f2709215e40df9584f236d5837c2f) complete. Timing: real 0.027s	user 0.000s	sys 0.026s Metrics: {}
I20260812 06:16:56.573638  6085 maintenance_manager.cc:419] P a61e97207a4d49b990e87b0e8bd3bb2a: Scheduling FlushDeltaMemStoresOp(e37f2709215e40df9584f236d5837c2f): perf score=3.181125
I20260812 06:16:56.602502  5965 maintenance_manager.cc:643] P a61e97207a4d49b990e87b0e8bd3bb2a: FlushDeltaMemStoresOp(e37f2709215e40df9584f236d5837c2f) complete. Timing: real 0.029s	user 0.007s	sys 0.006s Metrics: {"bytes_written":4512902,"delete_count":0,"lbm_write_time_us":6107,"lbm_writes_lt_1ms":113,"reinsert_count":0,"update_count":550}
I20260812 06:16:56.602988  6085 maintenance_manager.cc:419] P a61e97207a4d49b990e87b0e8bd3bb2a: Scheduling FlushDeltaMemStoresOp(e37f2709215e40df9584f236d5837c2f): perf score=2.188937
I20260812 06:16:56.612412  5965 maintenance_manager.cc:643] P a61e97207a4d49b990e87b0e8bd3bb2a: FlushDeltaMemStoresOp(e37f2709215e40df9584f236d5837c2f) complete. Timing: real 0.009s	user 0.009s	sys 0.000s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3416,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:16:56.612814  6085 maintenance_manager.cc:419] P a61e97207a4d49b990e87b0e8bd3bb2a: Scheduling UndoDeltaBlockGCOp(e37f2709215e40df9584f236d5837c2f): 482 bytes on disk
I20260812 06:16:56.613209  5965 maintenance_manager.cc:643] P a61e97207a4d49b990e87b0e8bd3bb2a: UndoDeltaBlockGCOp(e37f2709215e40df9584f236d5837c2f) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":52,"lbm_reads_lt_1ms":4}
I20260812 06:16:56.613730  6085 maintenance_manager.cc:419] P a61e97207a4d49b990e87b0e8bd3bb2a: Scheduling MajorDeltaCompactionOp(e37f2709215e40df9584f236d5837c2f): perf score=1.000000
I20260812 06:16:56.808761  5965 maintenance_manager.cc:643] P a61e97207a4d49b990e87b0e8bd3bb2a: MajorDeltaCompactionOp(e37f2709215e40df9584f236d5837c2f) complete. Timing: real 0.195s	user 0.145s	sys 0.048s Metrics: {"cfile_cache_miss":634,"cfile_cache_miss_bytes":28877328,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":517,"lbm_read_time_us":13000,"lbm_reads_lt_1ms":674,"lbm_write_time_us":34447,"lbm_writes_lt_1ms":643,"mutex_wait_us":38,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":896,"thread_start_us":77,"threads_started":1,"update_count":3000}
I20260812 06:16:56.809667  6085 maintenance_manager.cc:419] P a61e97207a4d49b990e87b0e8bd3bb2a: Scheduling FlushDeltaMemStoresOp(e37f2709215e40df9584f236d5837c2f): perf score=14.095187
I20260812 06:16:56.862983  5965 maintenance_manager.cc:643] P a61e97207a4d49b990e87b0e8bd3bb2a: FlushDeltaMemStoresOp(e37f2709215e40df9584f236d5837c2f) complete. Timing: real 0.053s	user 0.036s	sys 0.012s Metrics: {"bytes_written":16409903,"delete_count":0,"lbm_write_time_us":21678,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:16:56.863571  6085 maintenance_manager.cc:419] P a61e97207a4d49b990e87b0e8bd3bb2a: Scheduling FlushDeltaMemStoresOp(e37f2709215e40df9584f236d5837c2f): perf score=2.188937
I20260812 06:16:56.880854  5965 maintenance_manager.cc:643] P a61e97207a4d49b990e87b0e8bd3bb2a: FlushDeltaMemStoresOp(e37f2709215e40df9584f236d5837c2f) complete. Timing: real 0.017s	user 0.005s	sys 0.012s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":6843,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:56.886577  6085 maintenance_manager.cc:419] P a61e97207a4d49b990e87b0e8bd3bb2a: Scheduling MajorDeltaCompactionOp(e37f2709215e40df9584f236d5837c2f): perf score=1.000000
I20260812 06:16:57.069363  5965 maintenance_manager.cc:643] P a61e97207a4d49b990e87b0e8bd3bb2a: MajorDeltaCompactionOp(e37f2709215e40df9584f236d5837c2f) complete. Timing: real 0.183s	user 0.147s	sys 0.028s 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":610,"lbm_read_time_us":12965,"lbm_reads_lt_1ms":572,"lbm_write_time_us":29808,"lbm_writes_lt_1ms":543,"mutex_wait_us":36,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":88960,"update_count":2500}
I20260812 06:16:57.069993  6085 maintenance_manager.cc:419] P a61e97207a4d49b990e87b0e8bd3bb2a: Scheduling FlushDeltaMemStoresOp(e37f2709215e40df9584f236d5837c2f): perf score=14.095187
I20260812 06:16:57.131228  5965 maintenance_manager.cc:643] P a61e97207a4d49b990e87b0e8bd3bb2a: FlushDeltaMemStoresOp(e37f2709215e40df9584f236d5837c2f) complete. Timing: real 0.061s	user 0.042s	sys 0.015s Metrics: {"bytes_written":16409904,"delete_count":0,"lbm_write_time_us":22153,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":402,"reinsert_count":0,"update_count":2000}
I20260812 06:16:57.131717  6085 maintenance_manager.cc:419] P a61e97207a4d49b990e87b0e8bd3bb2a: Scheduling FlushDeltaMemStoresOp(e37f2709215e40df9584f236d5837c2f): perf score=2.188937
I20260812 06:16:57.142215  5965 maintenance_manager.cc:643] P a61e97207a4d49b990e87b0e8bd3bb2a: FlushDeltaMemStoresOp(e37f2709215e40df9584f236d5837c2f) complete. Timing: real 0.010s	user 0.002s	sys 0.007s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4031,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:57.142721  6085 maintenance_manager.cc:419] P a61e97207a4d49b990e87b0e8bd3bb2a: Scheduling MajorDeltaCompactionOp(e37f2709215e40df9584f236d5837c2f): perf score=1.000000
I20260812 06:16:57.317950  5965 maintenance_manager.cc:643] P a61e97207a4d49b990e87b0e8bd3bb2a: MajorDeltaCompactionOp(e37f2709215e40df9584f236d5837c2f) complete. Timing: real 0.175s	user 0.118s	sys 0.056s 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":161,"lbm_read_time_us":13674,"lbm_reads_lt_1ms":572,"lbm_write_time_us":28581,"lbm_writes_lt_1ms":543,"mutex_wait_us":51,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":7296,"update_count":2500}
I20260812 06:16:57.318483  6085 maintenance_manager.cc:419] P a61e97207a4d49b990e87b0e8bd3bb2a: Scheduling FlushDeltaMemStoresOp(e37f2709215e40df9584f236d5837c2f): perf score=11.118625
I20260812 06:16:57.352327  5965 maintenance_manager.cc:643] P a61e97207a4d49b990e87b0e8bd3bb2a: FlushDeltaMemStoresOp(e37f2709215e40df9584f236d5837c2f) complete. Timing: real 0.034s	user 0.010s	sys 0.023s Metrics: {"bytes_written":12717735,"delete_count":0,"lbm_write_time_us":14660,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:16:57.352933  6085 maintenance_manager.cc:419] P a61e97207a4d49b990e87b0e8bd3bb2a: Scheduling FlushDeltaMemStoresOp(e37f2709215e40df9584f236d5837c2f): perf score=2.188937
I20260812 06:16:57.381533  5965 maintenance_manager.cc:643] P a61e97207a4d49b990e87b0e8bd3bb2a: FlushDeltaMemStoresOp(e37f2709215e40df9584f236d5837c2f) complete. Timing: real 0.028s	user 0.008s	sys 0.012s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":4999,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:16:57.381996  6085 maintenance_manager.cc:419] P a61e97207a4d49b990e87b0e8bd3bb2a: Scheduling FlushDeltaMemStoresOp(e37f2709215e40df9584f236d5837c2f): perf score=2.188937
I20260812 06:16:57.392443  5965 maintenance_manager.cc:643] P a61e97207a4d49b990e87b0e8bd3bb2a: FlushDeltaMemStoresOp(e37f2709215e40df9584f236d5837c2f) complete. Timing: real 0.010s	user 0.006s	sys 0.004s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4089,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:57.392858  6085 maintenance_manager.cc:419] P a61e97207a4d49b990e87b0e8bd3bb2a: Scheduling MajorDeltaCompactionOp(e37f2709215e40df9584f236d5837c2f): perf score=1.000000
I20260812 06:16:57.576211  5965 maintenance_manager.cc:643] P a61e97207a4d49b990e87b0e8bd3bb2a: MajorDeltaCompactionOp(e37f2709215e40df9584f236d5837c2f) complete. Timing: real 0.183s	user 0.120s	sys 0.056s Metrics: {"cfile_cache_miss":533,"cfile_cache_miss_bytes":24774798,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":1861,"lbm_read_time_us":11620,"lbm_reads_lt_1ms":573,"lbm_write_time_us":29711,"lbm_writes_lt_1ms":543,"mutex_wait_us":722,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":768,"update_count":2500}
I20260812 06:16:57.577066  6085 maintenance_manager.cc:419] P a61e97207a4d49b990e87b0e8bd3bb2a: Scheduling FlushDeltaMemStoresOp(e37f2709215e40df9584f236d5837c2f): perf score=11.118625
I20260812 06:16:57.616310  5965 maintenance_manager.cc:643] P a61e97207a4d49b990e87b0e8bd3bb2a: FlushDeltaMemStoresOp(e37f2709215e40df9584f236d5837c2f) complete. Timing: real 0.039s	user 0.024s	sys 0.015s Metrics: {"bytes_written":12922847,"delete_count":0,"lbm_write_time_us":16657,"lbm_writes_lt_1ms":318,"reinsert_count":0,"update_count":1575}
I20260812 06:16:57.616956  6085 maintenance_manager.cc:419] P a61e97207a4d49b990e87b0e8bd3bb2a: Scheduling FlushDeltaMemStoresOp(e37f2709215e40df9584f236d5837c2f): perf score=2.188937
I20260812 06:16:57.637727  5965 maintenance_manager.cc:643] P a61e97207a4d49b990e87b0e8bd3bb2a: FlushDeltaMemStoresOp(e37f2709215e40df9584f236d5837c2f) complete. Timing: real 0.021s	user 0.012s	sys 0.000s Metrics: {"bytes_written":3774459,"delete_count":0,"lbm_write_time_us":5041,"lbm_writes_lt_1ms":95,"reinsert_count":0,"update_count":460}
I20260812 06:16:57.638191  6085 maintenance_manager.cc:419] P a61e97207a4d49b990e87b0e8bd3bb2a: Scheduling FlushDeltaMemStoresOp(e37f2709215e40df9584f236d5837c2f): perf score=2.188937
I20260812 06:16:57.648593  5965 maintenance_manager.cc:643] P a61e97207a4d49b990e87b0e8bd3bb2a: FlushDeltaMemStoresOp(e37f2709215e40df9584f236d5837c2f) complete. Timing: real 0.010s	user 0.010s	sys 0.000s Metrics: {"bytes_written":3815484,"delete_count":0,"lbm_write_time_us":3831,"lbm_writes_lt_1ms":96,"reinsert_count":0,"update_count":465}
I20260812 06:16:57.649056  6085 maintenance_manager.cc:419] P a61e97207a4d49b990e87b0e8bd3bb2a: Scheduling MajorDeltaCompactionOp(e37f2709215e40df9584f236d5837c2f): perf score=1.000000
I20260812 06:16:57.830833  5965 maintenance_manager.cc:643] P a61e97207a4d49b990e87b0e8bd3bb2a: MajorDeltaCompactionOp(e37f2709215e40df9584f236d5837c2f) complete. Timing: real 0.182s	user 0.137s	sys 0.040s Metrics: {"cfile_cache_miss":533,"cfile_cache_miss_bytes":24774790,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":340,"lbm_read_time_us":11904,"lbm_reads_lt_1ms":573,"lbm_write_time_us":30467,"lbm_writes_lt_1ms":543,"mutex_wait_us":21,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":11520,"update_count":2500}
I20260812 06:16:57.831393  6085 maintenance_manager.cc:419] P a61e97207a4d49b990e87b0e8bd3bb2a: Scheduling FlushDeltaMemStoresOp(e37f2709215e40df9584f236d5837c2f): perf score=14.095187
I20260812 06:16:57.881135  5965 maintenance_manager.cc:643] P a61e97207a4d49b990e87b0e8bd3bb2a: FlushDeltaMemStoresOp(e37f2709215e40df9584f236d5837c2f) complete. Timing: real 0.050s	user 0.036s	sys 0.008s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":20301,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:16:57.881649  6085 maintenance_manager.cc:419] P a61e97207a4d49b990e87b0e8bd3bb2a: Scheduling FlushDeltaMemStoresOp(e37f2709215e40df9584f236d5837c2f): perf score=2.188937
I20260812 06:16:57.892395  5965 maintenance_manager.cc:643] P a61e97207a4d49b990e87b0e8bd3bb2a: FlushDeltaMemStoresOp(e37f2709215e40df9584f236d5837c2f) complete. Timing: real 0.011s	user 0.010s	sys 0.000s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":3876,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:57.892912  6085 maintenance_manager.cc:419] P a61e97207a4d49b990e87b0e8bd3bb2a: Scheduling MajorDeltaCompactionOp(e37f2709215e40df9584f236d5837c2f): perf score=1.000000
I20260812 06:16:58.069170  5965 maintenance_manager.cc:643] P a61e97207a4d49b990e87b0e8bd3bb2a: MajorDeltaCompactionOp(e37f2709215e40df9584f236d5837c2f) complete. Timing: real 0.176s	user 0.116s	sys 0.056s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774687,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":127,"lbm_read_time_us":9773,"lbm_reads_lt_1ms":572,"lbm_write_time_us":31810,"lbm_writes_lt_1ms":543,"mutex_wait_us":58,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":3584,"update_count":2500}
I20260812 06:16:58.069761  6085 maintenance_manager.cc:419] P a61e97207a4d49b990e87b0e8bd3bb2a: Scheduling FlushDeltaMemStoresOp(e37f2709215e40df9584f236d5837c2f): perf score=11.118625
I20260812 06:16:58.108510  5965 maintenance_manager.cc:643] P a61e97207a4d49b990e87b0e8bd3bb2a: FlushDeltaMemStoresOp(e37f2709215e40df9584f236d5837c2f) complete. Timing: real 0.039s	user 0.022s	sys 0.016s Metrics: {"bytes_written":12717738,"delete_count":0,"lbm_write_time_us":16289,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:16:58.109242  6085 maintenance_manager.cc:419] P a61e97207a4d49b990e87b0e8bd3bb2a: Scheduling FlushDeltaMemStoresOp(e37f2709215e40df9584f236d5837c2f): perf score=2.188937
I20260812 06:16:58.124317  5965 maintenance_manager.cc:643] P a61e97207a4d49b990e87b0e8bd3bb2a: FlushDeltaMemStoresOp(e37f2709215e40df9584f236d5837c2f) complete. Timing: real 0.015s	user 0.007s	sys 0.004s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":4906,"lbm_writes_lt_1ms":93,"reinsert_count":0,"spinlock_wait_cycles":896,"update_count":450}
I20260812 06:16:58.124936  6085 maintenance_manager.cc:419] P a61e97207a4d49b990e87b0e8bd3bb2a: Scheduling FlushMRSOp(e37f2709215e40df9584f236d5837c2f): perf score=1.000000
I20260812 06:16:58.175390  5965 maintenance_manager.cc:643] P a61e97207a4d49b990e87b0e8bd3bb2a: FlushMRSOp(e37f2709215e40df9584f236d5837c2f) complete. Timing: real 0.050s	user 0.032s	sys 0.000s Metrics: {"bytes_written":1316417,"cfile_init":1,"dirs.queue_time_us":38,"dirs.run_cpu_time_us":235,"dirs.run_wall_time_us":1424,"drs_written":1,"lbm_read_time_us":44,"lbm_reads_lt_1ms":4,"lbm_write_time_us":2271,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":32,"spinlock_wait_cycles":47872}
I20260812 06:16:58.176126  6085 maintenance_manager.cc:419] P a61e97207a4d49b990e87b0e8bd3bb2a: Scheduling LogGCOp(e37f2709215e40df9584f236d5837c2f): free 133477715 bytes of WAL
I20260812 06:16:58.176674  5965 log_reader.cc:385] T e37f2709215e40df9584f236d5837c2f: removed 13 log segments from log reader
I20260812 06:16:58.176744  5965 log.cc:1079] T e37f2709215e40df9584f236d5837c2f P a61e97207a4d49b990e87b0e8bd3bb2a: Deleting log segment in path: /tmp/dist-test-taske_2AlB/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515413143058-5786-0/minicluster-data/ts-0-root/wals/e37f2709215e40df9584f236d5837c2f/wal-000000027 (ops 129-133)
I20260812 06:16:58.176790  5965 log.cc:1079] T e37f2709215e40df9584f236d5837c2f P a61e97207a4d49b990e87b0e8bd3bb2a: Deleting log segment in path: /tmp/dist-test-taske_2AlB/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515413143058-5786-0/minicluster-data/ts-0-root/wals/e37f2709215e40df9584f236d5837c2f/wal-000000028 (ops 134-138)
I20260812 06:16:58.176829  5965 log.cc:1079] T e37f2709215e40df9584f236d5837c2f P a61e97207a4d49b990e87b0e8bd3bb2a: Deleting log segment in path: /tmp/dist-test-taske_2AlB/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515413143058-5786-0/minicluster-data/ts-0-root/wals/e37f2709215e40df9584f236d5837c2f/wal-000000029 (ops 139-143)
I20260812 06:16:58.176854  5965 log.cc:1079] T e37f2709215e40df9584f236d5837c2f P a61e97207a4d49b990e87b0e8bd3bb2a: Deleting log segment in path: /tmp/dist-test-taske_2AlB/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515413143058-5786-0/minicluster-data/ts-0-root/wals/e37f2709215e40df9584f236d5837c2f/wal-000000030 (ops 144-148)
I20260812 06:16:58.176883  5965 log.cc:1079] T e37f2709215e40df9584f236d5837c2f P a61e97207a4d49b990e87b0e8bd3bb2a: Deleting log segment in path: /tmp/dist-test-taske_2AlB/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515413143058-5786-0/minicluster-data/ts-0-root/wals/e37f2709215e40df9584f236d5837c2f/wal-000000031 (ops 149-153)
I20260812 06:16:58.176913  5965 log.cc:1079] T e37f2709215e40df9584f236d5837c2f P a61e97207a4d49b990e87b0e8bd3bb2a: Deleting log segment in path: /tmp/dist-test-taske_2AlB/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515413143058-5786-0/minicluster-data/ts-0-root/wals/e37f2709215e40df9584f236d5837c2f/wal-000000032 (ops 154-158)
I20260812 06:16:58.176944  5965 log.cc:1079] T e37f2709215e40df9584f236d5837c2f P a61e97207a4d49b990e87b0e8bd3bb2a: Deleting log segment in path: /tmp/dist-test-taske_2AlB/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515413143058-5786-0/minicluster-data/ts-0-root/wals/e37f2709215e40df9584f236d5837c2f/wal-000000033 (ops 159-163)
I20260812 06:16:58.176971  5965 log.cc:1079] T e37f2709215e40df9584f236d5837c2f P a61e97207a4d49b990e87b0e8bd3bb2a: Deleting log segment in path: /tmp/dist-test-taske_2AlB/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515413143058-5786-0/minicluster-data/ts-0-root/wals/e37f2709215e40df9584f236d5837c2f/wal-000000034 (ops 164-168)
I20260812 06:16:58.177004  5965 log.cc:1079] T e37f2709215e40df9584f236d5837c2f P a61e97207a4d49b990e87b0e8bd3bb2a: Deleting log segment in path: /tmp/dist-test-taske_2AlB/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515413143058-5786-0/minicluster-data/ts-0-root/wals/e37f2709215e40df9584f236d5837c2f/wal-000000035 (ops 169-173)
I20260812 06:16:58.177035  5965 log.cc:1079] T e37f2709215e40df9584f236d5837c2f P a61e97207a4d49b990e87b0e8bd3bb2a: Deleting log segment in path: /tmp/dist-test-taske_2AlB/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515413143058-5786-0/minicluster-data/ts-0-root/wals/e37f2709215e40df9584f236d5837c2f/wal-000000036 (ops 174-178)
I20260812 06:16:58.177064  5965 log.cc:1079] T e37f2709215e40df9584f236d5837c2f P a61e97207a4d49b990e87b0e8bd3bb2a: Deleting log segment in path: /tmp/dist-test-taske_2AlB/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515413143058-5786-0/minicluster-data/ts-0-root/wals/e37f2709215e40df9584f236d5837c2f/wal-000000037 (ops 179-183)
I20260812 06:16:58.177093  5965 log.cc:1079] T e37f2709215e40df9584f236d5837c2f P a61e97207a4d49b990e87b0e8bd3bb2a: Deleting log segment in path: /tmp/dist-test-taske_2AlB/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515413143058-5786-0/minicluster-data/ts-0-root/wals/e37f2709215e40df9584f236d5837c2f/wal-000000038 (ops 184-188)
I20260812 06:16:58.177125  5965 log.cc:1079] T e37f2709215e40df9584f236d5837c2f P a61e97207a4d49b990e87b0e8bd3bb2a: Deleting log segment in path: /tmp/dist-test-taske_2AlB/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515413143058-5786-0/minicluster-data/ts-0-root/wals/e37f2709215e40df9584f236d5837c2f/wal-000000039 (ops 189-193)
I20260812 06:16:58.208211  5965 maintenance_manager.cc:643] P a61e97207a4d49b990e87b0e8bd3bb2a: LogGCOp(e37f2709215e40df9584f236d5837c2f) complete. Timing: real 0.032s	user 0.000s	sys 0.028s Metrics: {}
I20260812 06:16:58.208791  6085 maintenance_manager.cc:419] P a61e97207a4d49b990e87b0e8bd3bb2a: Scheduling UndoDeltaBlockGCOp(e37f2709215e40df9584f236d5837c2f): 493 bytes on disk
I20260812 06:16:58.209444  5965 maintenance_manager.cc:643] P a61e97207a4d49b990e87b0e8bd3bb2a: UndoDeltaBlockGCOp(e37f2709215e40df9584f236d5837c2f) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":109,"lbm_reads_lt_1ms":4}
I20260812 06:16:58.210125  6085 maintenance_manager.cc:419] P a61e97207a4d49b990e87b0e8bd3bb2a: Scheduling FlushDeltaMemStoresOp(e37f2709215e40df9584f236d5837c2f): perf score=7.149875
I20260812 06:16:58.240171  5965 maintenance_manager.cc:643] P a61e97207a4d49b990e87b0e8bd3bb2a: FlushDeltaMemStoresOp(e37f2709215e40df9584f236d5837c2f) complete. Timing: real 0.030s	user 0.011s	sys 0.015s Metrics: {"bytes_written":8615322,"delete_count":0,"lbm_write_time_us":9253,"lbm_writes_lt_1ms":213,"reinsert_count":0,"update_count":1050}
I20260812 06:16:58.240764  6085 maintenance_manager.cc:419] P a61e97207a4d49b990e87b0e8bd3bb2a: Scheduling FlushDeltaMemStoresOp(e37f2709215e40df9584f236d5837c2f): perf score=2.188937
I20260812 06:16:58.250279  5965 maintenance_manager.cc:643] P a61e97207a4d49b990e87b0e8bd3bb2a: FlushDeltaMemStoresOp(e37f2709215e40df9584f236d5837c2f) complete. Timing: real 0.009s	user 0.008s	sys 0.000s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3557,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:16:58.250728  6085 maintenance_manager.cc:419] P a61e97207a4d49b990e87b0e8bd3bb2a: Scheduling MajorDeltaCompactionOp(e37f2709215e40df9584f236d5837c2f): perf score=1.000000
I20260812 06:16:58.362326  5786 heavy-update-compaction-itest.cc:229] Time spent updating: real 4.931s	user 1.814s	sys 0.189s
I20260812 06:16:58.461469  5786 heavy-update-compaction-itest.cc:265] Time spent scanning: real 0.099s	user 0.002s	sys 0.000s
I20260812 06:16:58.462100  5786 tablet_server.cc:179] TabletServer@127.5.166.129:0 shutting down...
I20260812 06:16:58.465807  5965 maintenance_manager.cc:643] P a61e97207a4d49b990e87b0e8bd3bb2a: MajorDeltaCompactionOp(e37f2709215e40df9584f236d5837c2f) complete. Timing: real 0.215s	user 0.163s	sys 0.052s Metrics: {"cfile_cache_miss":734,"cfile_cache_miss_bytes":32979736,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":806,"lbm_read_time_us":17794,"lbm_reads_lt_1ms":770,"lbm_write_time_us":34848,"lbm_writes_lt_1ms":743,"mutex_wait_us":51,"peak_mem_usage":87969044,"reinsert_count":0,"spinlock_wait_cycles":30592,"thread_start_us":68,"threads_started":1,"update_count":3500}
I20260812 06:16:58.468660  6085 maintenance_manager.cc:419] P a61e97207a4d49b990e87b0e8bd3bb2a: Scheduling FlushDeltaMemStoresOp(e37f2709215e40df9584f236d5837c2f): perf score=6.157687
I20260812 06:16:58.506264  5965 maintenance_manager.cc:643] P a61e97207a4d49b990e87b0e8bd3bb2a: FlushDeltaMemStoresOp(e37f2709215e40df9584f236d5837c2f) complete. Timing: real 0.037s	user 0.014s	sys 0.004s Metrics: {"bytes_written":8205079,"delete_count":0,"lbm_write_time_us":8224,"lbm_writes_lt_1ms":203,"reinsert_count":0,"update_count":1000}
I20260812 06:16:58.507030  5786 ts_tablet_manager.cc:1507] Shutting down tablet manager...
I20260812 06:16:58.507488  5786 tablet_replica.cc:333] T e37f2709215e40df9584f236d5837c2f P a61e97207a4d49b990e87b0e8bd3bb2a: stopping tablet replica
I20260812 06:16:58.507704  5786 raft_consensus.cc:2243] T e37f2709215e40df9584f236d5837c2f P a61e97207a4d49b990e87b0e8bd3bb2a [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:16:58.507921  5786 raft_consensus.cc:2272] T e37f2709215e40df9584f236d5837c2f P a61e97207a4d49b990e87b0e8bd3bb2a [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:16:58.512921  5786 tablet_server.cc:196] TabletServer@127.5.166.129:0 shutdown complete.
I20260812 06:16:58.530562  5786 master.cc:562] Master@127.5.166.190:35371 shutting down...
I20260812 06:16:58.534765  5786 raft_consensus.cc:2243] T 00000000000000000000000000000000 P e3fde12c031e4a319f94b0fdd4ebc87a [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:16:58.534941  5786 raft_consensus.cc:2272] T 00000000000000000000000000000000 P e3fde12c031e4a319f94b0fdd4ebc87a [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:16:58.534996  5786 tablet_replica.cc:333] T 00000000000000000000000000000000 P e3fde12c031e4a319f94b0fdd4ebc87a: stopping tablet replica
I20260812 06:16:58.547437  5786 master.cc:584] Master@127.5.166.190:35371 shutdown complete.
[       OK ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/0 (5481 ms)
[ RUN      ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/1
I20260812 06:16:58.646433  5786 internal_mini_cluster.cc:156] Creating distributed mini masters. Addrs: 127.5.166.190:33609
I20260812 06:16:58.646809  5786 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:16:58.648866  6139 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:16:58.649001  6140 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:16:58.648883  6142 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:16:58.649349  5786 server_base.cc:1061] running on GCE node
I20260812 06:16:58.649547  5786 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:16:58.649587  5786 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:16:58.649603  5786 hybrid_clock.cc:648] HybridClock initialized: now 1786515418649603 us; error 0 us; skew 500 ppm
I20260812 06:16:58.650574  5786 webserver.cc:533] Webserver started at http://127.5.166.190:35317/ using document root <none> and password file <none>
I20260812 06:16:58.650759  5786 fs_manager.cc:362] Metadata directory not provided
I20260812 06:16:58.650820  5786 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:16:58.650996  5786 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:16:58.651428  5786 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taske_2AlB/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515413143058-5786-0/minicluster-data/master-0-root/instance:
uuid: "28b0f4bda6204876b89aa5113840dd7a"
format_stamp: "Formatted at 2026-08-12 06:16:58 on dist-test-slave-2d19"
I20260812 06:16:58.653112  5786 fs_manager.cc:696] Time spent creating directory manager: real 0.001s	user 0.002s	sys 0.000s
I20260812 06:16:58.654103  6148 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:16:58.654347  5786 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.001s	sys 0.000s
I20260812 06:16:58.654443  5786 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taske_2AlB/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515413143058-5786-0/minicluster-data/master-0-root
uuid: "28b0f4bda6204876b89aa5113840dd7a"
format_stamp: "Formatted at 2026-08-12 06:16:58 on dist-test-slave-2d19"
I20260812 06:16:58.654539  5786 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taske_2AlB/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515413143058-5786-0/minicluster-data/master-0-root
metadata directory: /tmp/dist-test-taske_2AlB/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515413143058-5786-0/minicluster-data/master-0-root
1 data directories: /tmp/dist-test-taske_2AlB/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515413143058-5786-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:16:58.665879  5786 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:16:58.666318  5786 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:16:58.670797  5786 rpc_server.cc:307] RPC server started. Bound to: 127.5.166.190:33609
I20260812 06:16:58.672071  6241 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.5.166.190:33609 every 8 connection(s)
I20260812 06:16:58.672989  6242 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:16:58.677845  6242 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P 28b0f4bda6204876b89aa5113840dd7a: Bootstrap starting.
I20260812 06:16:58.678699  6242 tablet_bootstrap.cc:654] T 00000000000000000000000000000000 P 28b0f4bda6204876b89aa5113840dd7a: Neither blocks nor log segments found. Creating new log.
I20260812 06:16:58.679790  6242 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P 28b0f4bda6204876b89aa5113840dd7a: No bootstrap required, opened a new log
I20260812 06:16:58.680281  6242 raft_consensus.cc:359] T 00000000000000000000000000000000 P 28b0f4bda6204876b89aa5113840dd7a [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "28b0f4bda6204876b89aa5113840dd7a" member_type: VOTER }
I20260812 06:16:58.680369  6242 raft_consensus.cc:385] T 00000000000000000000000000000000 P 28b0f4bda6204876b89aa5113840dd7a [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:16:58.680444  6242 raft_consensus.cc:740] T 00000000000000000000000000000000 P 28b0f4bda6204876b89aa5113840dd7a [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: 28b0f4bda6204876b89aa5113840dd7a, State: Initialized, Role: FOLLOWER
I20260812 06:16:58.680632  6242 consensus_queue.cc:260] T 00000000000000000000000000000000 P 28b0f4bda6204876b89aa5113840dd7a [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: "28b0f4bda6204876b89aa5113840dd7a" member_type: VOTER }
I20260812 06:16:58.680708  6242 raft_consensus.cc:399] T 00000000000000000000000000000000 P 28b0f4bda6204876b89aa5113840dd7a [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:16:58.680766  6242 raft_consensus.cc:493] T 00000000000000000000000000000000 P 28b0f4bda6204876b89aa5113840dd7a [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:16:58.680830  6242 raft_consensus.cc:3060] T 00000000000000000000000000000000 P 28b0f4bda6204876b89aa5113840dd7a [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:16:58.681532  6242 raft_consensus.cc:515] T 00000000000000000000000000000000 P 28b0f4bda6204876b89aa5113840dd7a [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "28b0f4bda6204876b89aa5113840dd7a" member_type: VOTER }
I20260812 06:16:58.681680  6242 leader_election.cc:304] T 00000000000000000000000000000000 P 28b0f4bda6204876b89aa5113840dd7a [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: 28b0f4bda6204876b89aa5113840dd7a; no voters: 
I20260812 06:16:58.681922  6242 leader_election.cc:290] T 00000000000000000000000000000000 P 28b0f4bda6204876b89aa5113840dd7a [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:16:58.682075  6255 raft_consensus.cc:2804] T 00000000000000000000000000000000 P 28b0f4bda6204876b89aa5113840dd7a [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:16:58.682291  6255 raft_consensus.cc:697] T 00000000000000000000000000000000 P 28b0f4bda6204876b89aa5113840dd7a [term 1 LEADER]: Becoming Leader. State: Replica: 28b0f4bda6204876b89aa5113840dd7a, State: Running, Role: LEADER
I20260812 06:16:58.682377  6242 sys_catalog.cc:565] T 00000000000000000000000000000000 P 28b0f4bda6204876b89aa5113840dd7a [sys.catalog]: configured and running, proceeding with master startup.
I20260812 06:16:58.682446  6255 consensus_queue.cc:237] T 00000000000000000000000000000000 P 28b0f4bda6204876b89aa5113840dd7a [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: "28b0f4bda6204876b89aa5113840dd7a" member_type: VOTER }
I20260812 06:16:58.682927  6256 sys_catalog.cc:455] T 00000000000000000000000000000000 P 28b0f4bda6204876b89aa5113840dd7a [sys.catalog]: SysCatalogTable state changed. Reason: RaftConsensus started. Latest consensus state: current_term: 1 leader_uuid: "28b0f4bda6204876b89aa5113840dd7a" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "28b0f4bda6204876b89aa5113840dd7a" member_type: VOTER } }
I20260812 06:16:58.682957  6257 sys_catalog.cc:455] T 00000000000000000000000000000000 P 28b0f4bda6204876b89aa5113840dd7a [sys.catalog]: SysCatalogTable state changed. Reason: New leader 28b0f4bda6204876b89aa5113840dd7a. Latest consensus state: current_term: 1 leader_uuid: "28b0f4bda6204876b89aa5113840dd7a" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "28b0f4bda6204876b89aa5113840dd7a" member_type: VOTER } }
I20260812 06:16:58.683027  6256 sys_catalog.cc:458] T 00000000000000000000000000000000 P 28b0f4bda6204876b89aa5113840dd7a [sys.catalog]: This master's current role is: LEADER
I20260812 06:16:58.683046  6257 sys_catalog.cc:458] T 00000000000000000000000000000000 P 28b0f4bda6204876b89aa5113840dd7a [sys.catalog]: This master's current role is: LEADER
I20260812 06:16:58.683629  6265 catalog_manager.cc:1511] Loading table and tablet metadata into memory...
I20260812 06:16:58.684635  6265 catalog_manager.cc:1520] Initializing Kudu cluster ID...
I20260812 06:16:58.684860  5786 internal_mini_cluster.cc:184] Waiting to initialize catalog manager on master 0
I20260812 06:16:58.686630  6265 catalog_manager.cc:1383] Generated new cluster ID: 23d1383a10ef47a3ac17a7d7e75709ad
I20260812 06:16:58.686684  6265 catalog_manager.cc:1531] Initializing Kudu internal certificate authority...
I20260812 06:16:58.711500  6265 catalog_manager.cc:1406] Generated new certificate authority record
I20260812 06:16:58.712082  6265 catalog_manager.cc:1540] Loading token signing keys...
I20260812 06:16:58.719671  6265 catalog_manager.cc:6092] T 00000000000000000000000000000000 P 28b0f4bda6204876b89aa5113840dd7a: Generated new TSK 0
I20260812 06:16:58.719815  6265 catalog_manager.cc:1550] Initializing in-progress tserver states...
I20260812 06:16:58.749691  5786 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:16:58.751837  6293 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:16:58.751978  6290 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:16:58.751968  5786 server_base.cc:1061] running on GCE node
W20260812 06:16:58.751842  6295 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:16:58.752395  5786 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:16:58.752446  5786 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:16:58.752465  5786 hybrid_clock.cc:648] HybridClock initialized: now 1786515418752464 us; error 0 us; skew 500 ppm
I20260812 06:16:58.753417  5786 webserver.cc:533] Webserver started at http://127.5.166.129:40869/ using document root <none> and password file <none>
I20260812 06:16:58.753616  5786 fs_manager.cc:362] Metadata directory not provided
I20260812 06:16:58.753669  5786 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:16:58.753747  5786 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:16:58.754168  5786 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taske_2AlB/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515413143058-5786-0/minicluster-data/ts-0-root/instance:
uuid: "e902b5d83f6b419086fddde248ac1e42"
format_stamp: "Formatted at 2026-08-12 06:16:58 on dist-test-slave-2d19"
I20260812 06:16:58.755795  5786 fs_manager.cc:696] Time spent creating directory manager: real 0.001s	user 0.000s	sys 0.002s
I20260812 06:16:58.756896  6301 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:16:58.757205  5786 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.000s	sys 0.000s
I20260812 06:16:58.757268  5786 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taske_2AlB/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515413143058-5786-0/minicluster-data/ts-0-root
uuid: "e902b5d83f6b419086fddde248ac1e42"
format_stamp: "Formatted at 2026-08-12 06:16:58 on dist-test-slave-2d19"
I20260812 06:16:58.757359  5786 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taske_2AlB/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515413143058-5786-0/minicluster-data/ts-0-root
metadata directory: /tmp/dist-test-taske_2AlB/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515413143058-5786-0/minicluster-data/ts-0-root
1 data directories: /tmp/dist-test-taske_2AlB/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515413143058-5786-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:16:58.772758  5786 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:16:58.773145  5786 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:16:58.773460  5786 txn_system_client.cc:432] TxnSystemClient initialization is disabled...
I20260812 06:16:58.773962  5786 ts_tablet_manager.cc:585] Loaded tablet metadata (0 total tablets, 0 live tablets)
I20260812 06:16:58.774003  5786 ts_tablet_manager.cc:531] Time spent load tablet metadata: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:16:58.774057  5786 ts_tablet_manager.cc:616] Registered 0 tablets
I20260812 06:16:58.774097  5786 ts_tablet_manager.cc:595] Time spent register tablets: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:16:58.778446  5786 rpc_server.cc:307] RPC server started. Bound to: 127.5.166.129:42961
I20260812 06:16:58.779351  6420 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.5.166.129:42961 every 8 connection(s)
I20260812 06:16:58.787397  6422 heartbeater.cc:344] Connected to a master server at 127.5.166.190:33609
I20260812 06:16:58.787525  6422 heartbeater.cc:461] Registering TS with master...
I20260812 06:16:58.787758  6422 heartbeater.cc:507] Master 127.5.166.190:33609 requested a full tablet report, sending...
I20260812 06:16:58.788540  6179 ts_manager.cc:194] Registered new tserver with Master: e902b5d83f6b419086fddde248ac1e42 (127.5.166.129:42961)
I20260812 06:16:58.789300  5786 internal_mini_cluster.cc:371] 1 TS(s) registered with all masters after 0.010059228s
I20260812 06:16:58.789314  6179 master_service.cc:502] Signed X509 certificate for tserver {username='slave'} at 127.0.0.1:33020
I20260812 06:16:58.796656  6179 catalog_manager.cc:2283] Servicing CreateTable request from {username='slave'} at 127.0.0.1:33028:
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:16:58.805435  6354 tablet_service.cc:1511] Processing CreateTablet for tablet 24c2661cbc8447c8aa38e511c647dd60 (DEFAULT_TABLE table=heavy-update-compaction-test [id=d05d307b72234fb8b0cf6bf8ab3d61e6]), partition=
I20260812 06:16:58.805721  6354 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet 24c2661cbc8447c8aa38e511c647dd60. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:16:58.807964  6442 tablet_bootstrap.cc:492] T 24c2661cbc8447c8aa38e511c647dd60 P e902b5d83f6b419086fddde248ac1e42: Bootstrap starting.
I20260812 06:16:58.808991  6442 tablet_bootstrap.cc:654] T 24c2661cbc8447c8aa38e511c647dd60 P e902b5d83f6b419086fddde248ac1e42: Neither blocks nor log segments found. Creating new log.
I20260812 06:16:58.810143  6442 tablet_bootstrap.cc:492] T 24c2661cbc8447c8aa38e511c647dd60 P e902b5d83f6b419086fddde248ac1e42: No bootstrap required, opened a new log
I20260812 06:16:58.810238  6442 ts_tablet_manager.cc:1403] T 24c2661cbc8447c8aa38e511c647dd60 P e902b5d83f6b419086fddde248ac1e42: Time spent bootstrapping tablet: real 0.002s	user 0.002s	sys 0.000s
I20260812 06:16:58.810662  6442 raft_consensus.cc:359] T 24c2661cbc8447c8aa38e511c647dd60 P e902b5d83f6b419086fddde248ac1e42 [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "e902b5d83f6b419086fddde248ac1e42" member_type: VOTER last_known_addr { host: "127.5.166.129" port: 42961 } }
I20260812 06:16:58.810758  6442 raft_consensus.cc:385] T 24c2661cbc8447c8aa38e511c647dd60 P e902b5d83f6b419086fddde248ac1e42 [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:16:58.810784  6442 raft_consensus.cc:740] T 24c2661cbc8447c8aa38e511c647dd60 P e902b5d83f6b419086fddde248ac1e42 [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: e902b5d83f6b419086fddde248ac1e42, State: Initialized, Role: FOLLOWER
I20260812 06:16:58.811023  6442 consensus_queue.cc:260] T 24c2661cbc8447c8aa38e511c647dd60 P e902b5d83f6b419086fddde248ac1e42 [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: "e902b5d83f6b419086fddde248ac1e42" member_type: VOTER last_known_addr { host: "127.5.166.129" port: 42961 } }
I20260812 06:16:58.811156  6442 raft_consensus.cc:399] T 24c2661cbc8447c8aa38e511c647dd60 P e902b5d83f6b419086fddde248ac1e42 [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:16:58.811225  6442 raft_consensus.cc:493] T 24c2661cbc8447c8aa38e511c647dd60 P e902b5d83f6b419086fddde248ac1e42 [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:16:58.811287  6442 raft_consensus.cc:3060] T 24c2661cbc8447c8aa38e511c647dd60 P e902b5d83f6b419086fddde248ac1e42 [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:16:58.812830  6442 raft_consensus.cc:515] T 24c2661cbc8447c8aa38e511c647dd60 P e902b5d83f6b419086fddde248ac1e42 [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "e902b5d83f6b419086fddde248ac1e42" member_type: VOTER last_known_addr { host: "127.5.166.129" port: 42961 } }
I20260812 06:16:58.812976  6442 leader_election.cc:304] T 24c2661cbc8447c8aa38e511c647dd60 P e902b5d83f6b419086fddde248ac1e42 [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: e902b5d83f6b419086fddde248ac1e42; no voters: 
I20260812 06:16:58.813136  6442 leader_election.cc:290] T 24c2661cbc8447c8aa38e511c647dd60 P e902b5d83f6b419086fddde248ac1e42 [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:16:58.813285  6451 raft_consensus.cc:2804] T 24c2661cbc8447c8aa38e511c647dd60 P e902b5d83f6b419086fddde248ac1e42 [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:16:58.813493  6422 heartbeater.cc:499] Master 127.5.166.190:33609 was elected leader, sending a full tablet report...
I20260812 06:16:58.813529  6451 raft_consensus.cc:697] T 24c2661cbc8447c8aa38e511c647dd60 P e902b5d83f6b419086fddde248ac1e42 [term 1 LEADER]: Becoming Leader. State: Replica: e902b5d83f6b419086fddde248ac1e42, State: Running, Role: LEADER
I20260812 06:16:58.813504  6442 ts_tablet_manager.cc:1434] T 24c2661cbc8447c8aa38e511c647dd60 P e902b5d83f6b419086fddde248ac1e42: Time spent starting tablet: real 0.003s	user 0.004s	sys 0.000s
I20260812 06:16:58.813695  6451 consensus_queue.cc:237] T 24c2661cbc8447c8aa38e511c647dd60 P e902b5d83f6b419086fddde248ac1e42 [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: "e902b5d83f6b419086fddde248ac1e42" member_type: VOTER last_known_addr { host: "127.5.166.129" port: 42961 } }
I20260812 06:16:58.815168  6179 catalog_manager.cc:5719] T 24c2661cbc8447c8aa38e511c647dd60 P e902b5d83f6b419086fddde248ac1e42 reported cstate change: term changed from 0 to 1, leader changed from <none> to e902b5d83f6b419086fddde248ac1e42 (127.5.166.129). New cstate: current_term: 1 leader_uuid: "e902b5d83f6b419086fddde248ac1e42" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "e902b5d83f6b419086fddde248ac1e42" member_type: VOTER last_known_addr { host: "127.5.166.129" port: 42961 } health_report { overall_health: HEALTHY } } }
I20260812 06:16:58.874974  5786 heavy-update-compaction-itest.cc:215] Time spent inserting: real 0.053s	user 0.012s	sys 0.012s
I20260812 06:16:59.029770  6424 maintenance_manager.cc:419] P e902b5d83f6b419086fddde248ac1e42: Scheduling FlushMRSOp(24c2661cbc8447c8aa38e511c647dd60): perf score=19.054940
I20260812 06:16:59.177703  6308 maintenance_manager.cc:643] P e902b5d83f6b419086fddde248ac1e42: FlushMRSOp(24c2661cbc8447c8aa38e511c647dd60) complete. Timing: real 0.148s	user 0.109s	sys 0.036s Metrics: {"bytes_written":12799788,"cfile_init":1,"delete_count":0,"dirs.queue_time_us":87,"dirs.run_cpu_time_us":227,"dirs.run_wall_time_us":1071,"drs_written":1,"lbm_read_time_us":81,"lbm_reads_lt_1ms":4,"lbm_write_time_us":35794,"lbm_writes_lt_1ms":779,"mutex_wait_us":800,"peak_mem_usage":0,"reinsert_count":0,"rows_written":105,"spinlock_wait_cycles":768,"update_count":1560}
I20260812 06:16:59.178646  6424 maintenance_manager.cc:419] P e902b5d83f6b419086fddde248ac1e42: Scheduling LogGCOp(24c2661cbc8447c8aa38e511c647dd60): free 20743831 bytes of WAL
I20260812 06:16:59.178894  6308 log_reader.cc:385] T 24c2661cbc8447c8aa38e511c647dd60: removed 2 log segments from log reader
I20260812 06:16:59.178951  6308 log.cc:1079] T 24c2661cbc8447c8aa38e511c647dd60 P e902b5d83f6b419086fddde248ac1e42: Deleting log segment in path: /tmp/dist-test-taske_2AlB/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515413143058-5786-0/minicluster-data/ts-0-root/wals/24c2661cbc8447c8aa38e511c647dd60/wal-000000001 (ops 1-6)
I20260812 06:16:59.178989  6308 log.cc:1079] T 24c2661cbc8447c8aa38e511c647dd60 P e902b5d83f6b419086fddde248ac1e42: Deleting log segment in path: /tmp/dist-test-taske_2AlB/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515413143058-5786-0/minicluster-data/ts-0-root/wals/24c2661cbc8447c8aa38e511c647dd60/wal-000000002 (ops 7-11)
I20260812 06:16:59.184588  6308 maintenance_manager.cc:643] P e902b5d83f6b419086fddde248ac1e42: LogGCOp(24c2661cbc8447c8aa38e511c647dd60) complete. Timing: real 0.006s	user 0.000s	sys 0.005s Metrics: {}
I20260812 06:16:59.185021  6424 maintenance_manager.cc:419] P e902b5d83f6b419086fddde248ac1e42: Scheduling FlushDeltaMemStoresOp(24c2661cbc8447c8aa38e511c647dd60): perf score=2.188937
I20260812 06:16:59.208940  6308 maintenance_manager.cc:643] P e902b5d83f6b419086fddde248ac1e42: FlushDeltaMemStoresOp(24c2661cbc8447c8aa38e511c647dd60) complete. Timing: real 0.024s	user 0.011s	sys 0.001s Metrics: {"bytes_written":3610362,"delete_count":0,"lbm_write_time_us":5147,"lbm_writes_lt_1ms":91,"reinsert_count":0,"update_count":440}
I20260812 06:16:59.209364  6424 maintenance_manager.cc:419] P e902b5d83f6b419086fddde248ac1e42: Scheduling UndoDeltaBlockGCOp(24c2661cbc8447c8aa38e511c647dd60): 16821647 bytes on disk
I20260812 06:16:59.209746  6308 maintenance_manager.cc:643] P e902b5d83f6b419086fddde248ac1e42: UndoDeltaBlockGCOp(24c2661cbc8447c8aa38e511c647dd60) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":49,"lbm_reads_lt_1ms":4}
I20260812 06:16:59.210134  6424 maintenance_manager.cc:419] P e902b5d83f6b419086fddde248ac1e42: Scheduling FlushDeltaMemStoresOp(24c2661cbc8447c8aa38e511c647dd60): perf score=2.188937
I20260812 06:16:59.219455  6308 maintenance_manager.cc:643] P e902b5d83f6b419086fddde248ac1e42: FlushDeltaMemStoresOp(24c2661cbc8447c8aa38e511c647dd60) complete. Timing: real 0.009s	user 0.004s	sys 0.003s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3437,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:16:59.219918  6424 maintenance_manager.cc:419] P e902b5d83f6b419086fddde248ac1e42: Scheduling MajorDeltaCompactionOp(24c2661cbc8447c8aa38e511c647dd60): perf score=1.000000
I20260812 06:16:59.412226  6308 maintenance_manager.cc:643] P e902b5d83f6b419086fddde248ac1e42: MajorDeltaCompactionOp(24c2661cbc8447c8aa38e511c647dd60) complete. Timing: real 0.192s	user 0.117s	sys 0.064s Metrics: {"cfile_cache_miss":523,"cfile_cache_miss_bytes":24405550,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":534,"lbm_read_time_us":13405,"lbm_reads_lt_1ms":559,"lbm_write_time_us":32716,"lbm_writes_lt_1ms":533,"mutex_wait_us":46,"peak_mem_usage":61665166,"reinsert_count":0,"spinlock_wait_cycles":43264,"thread_start_us":341,"threads_started":5,"update_count":2450}
I20260812 06:16:59.412869  6424 maintenance_manager.cc:419] P e902b5d83f6b419086fddde248ac1e42: Scheduling FlushDeltaMemStoresOp(24c2661cbc8447c8aa38e511c647dd60): perf score=14.095187
I20260812 06:16:59.472800  6308 maintenance_manager.cc:643] P e902b5d83f6b419086fddde248ac1e42: FlushDeltaMemStoresOp(24c2661cbc8447c8aa38e511c647dd60) complete. Timing: real 0.060s	user 0.025s	sys 0.026s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":23732,"lbm_writes_1-10_ms":2,"lbm_writes_lt_1ms":401,"reinsert_count":0,"update_count":2000}
I20260812 06:16:59.473235  6424 maintenance_manager.cc:419] P e902b5d83f6b419086fddde248ac1e42: Scheduling FlushDeltaMemStoresOp(24c2661cbc8447c8aa38e511c647dd60): perf score=2.188937
I20260812 06:16:59.485369  6308 maintenance_manager.cc:643] P e902b5d83f6b419086fddde248ac1e42: FlushDeltaMemStoresOp(24c2661cbc8447c8aa38e511c647dd60) complete. Timing: real 0.012s	user 0.006s	sys 0.005s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4140,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:59.486028  6424 maintenance_manager.cc:419] P e902b5d83f6b419086fddde248ac1e42: Scheduling MajorDeltaCompactionOp(24c2661cbc8447c8aa38e511c647dd60): perf score=1.000000
I20260812 06:16:59.653800  6308 maintenance_manager.cc:643] P e902b5d83f6b419086fddde248ac1e42: MajorDeltaCompactionOp(24c2661cbc8447c8aa38e511c647dd60) complete. Timing: real 0.168s	user 0.147s	sys 0.020s 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":585,"lbm_read_time_us":12598,"lbm_reads_lt_1ms":572,"lbm_write_time_us":26250,"lbm_writes_lt_1ms":543,"mutex_wait_us":336,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":22272,"update_count":2500}
I20260812 06:16:59.654537  6424 maintenance_manager.cc:419] P e902b5d83f6b419086fddde248ac1e42: Scheduling FlushDeltaMemStoresOp(24c2661cbc8447c8aa38e511c647dd60): perf score=14.095187
I20260812 06:16:59.705363  6308 maintenance_manager.cc:643] P e902b5d83f6b419086fddde248ac1e42: FlushDeltaMemStoresOp(24c2661cbc8447c8aa38e511c647dd60) complete. Timing: real 0.050s	user 0.030s	sys 0.019s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":22279,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:16:59.705927  6424 maintenance_manager.cc:419] P e902b5d83f6b419086fddde248ac1e42: Scheduling FlushDeltaMemStoresOp(24c2661cbc8447c8aa38e511c647dd60): perf score=2.188937
I20260812 06:16:59.723613  6308 maintenance_manager.cc:643] P e902b5d83f6b419086fddde248ac1e42: FlushDeltaMemStoresOp(24c2661cbc8447c8aa38e511c647dd60) complete. Timing: real 0.017s	user 0.015s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6709,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:59.724479  6424 maintenance_manager.cc:419] P e902b5d83f6b419086fddde248ac1e42: Scheduling MajorDeltaCompactionOp(24c2661cbc8447c8aa38e511c647dd60): perf score=1.000000
I20260812 06:16:59.925019  6308 maintenance_manager.cc:643] P e902b5d83f6b419086fddde248ac1e42: MajorDeltaCompactionOp(24c2661cbc8447c8aa38e511c647dd60) complete. Timing: real 0.200s	user 0.151s	sys 0.048s 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":625,"lbm_read_time_us":14287,"lbm_reads_lt_1ms":564,"lbm_write_time_us":30438,"lbm_writes_lt_1ms":543,"mutex_wait_us":47,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":27648,"update_count":2500}
I20260812 06:16:59.925686  6424 maintenance_manager.cc:419] P e902b5d83f6b419086fddde248ac1e42: Scheduling FlushDeltaMemStoresOp(24c2661cbc8447c8aa38e511c647dd60): perf score=14.095187
I20260812 06:16:59.980417  6308 maintenance_manager.cc:643] P e902b5d83f6b419086fddde248ac1e42: FlushDeltaMemStoresOp(24c2661cbc8447c8aa38e511c647dd60) complete. Timing: real 0.055s	user 0.039s	sys 0.012s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":20808,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:16:59.980947  6424 maintenance_manager.cc:419] P e902b5d83f6b419086fddde248ac1e42: Scheduling FlushDeltaMemStoresOp(24c2661cbc8447c8aa38e511c647dd60): perf score=2.188937
I20260812 06:17:00.008895  6308 maintenance_manager.cc:643] P e902b5d83f6b419086fddde248ac1e42: FlushDeltaMemStoresOp(24c2661cbc8447c8aa38e511c647dd60) complete. Timing: real 0.028s	user 0.010s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5779,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:00.009338  6424 maintenance_manager.cc:419] P e902b5d83f6b419086fddde248ac1e42: Scheduling FlushDeltaMemStoresOp(24c2661cbc8447c8aa38e511c647dd60): perf score=2.188937
I20260812 06:17:00.019383  6308 maintenance_manager.cc:643] P e902b5d83f6b419086fddde248ac1e42: FlushDeltaMemStoresOp(24c2661cbc8447c8aa38e511c647dd60) complete. Timing: real 0.010s	user 0.001s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3963,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:00.019887  6424 maintenance_manager.cc:419] P e902b5d83f6b419086fddde248ac1e42: Scheduling MajorDeltaCompactionOp(24c2661cbc8447c8aa38e511c647dd60): perf score=1.000000
I20260812 06:17:00.209918  6308 maintenance_manager.cc:643] P e902b5d83f6b419086fddde248ac1e42: MajorDeltaCompactionOp(24c2661cbc8447c8aa38e511c647dd60) complete. Timing: real 0.190s	user 0.128s	sys 0.062s Metrics: {"cfile_cache_miss":633,"cfile_cache_miss_bytes":28918214,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":200,"lbm_read_time_us":12804,"lbm_reads_lt_1ms":673,"lbm_write_time_us":32561,"lbm_writes_lt_1ms":643,"mutex_wait_us":52,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":69760,"update_count":3000}
I20260812 06:17:00.210577  6424 maintenance_manager.cc:419] P e902b5d83f6b419086fddde248ac1e42: Scheduling FlushDeltaMemStoresOp(24c2661cbc8447c8aa38e511c647dd60): perf score=14.095187
I20260812 06:17:00.268760  6308 maintenance_manager.cc:643] P e902b5d83f6b419086fddde248ac1e42: FlushDeltaMemStoresOp(24c2661cbc8447c8aa38e511c647dd60) complete. Timing: real 0.058s	user 0.031s	sys 0.025s Metrics: {"bytes_written":16409904,"delete_count":0,"lbm_write_time_us":25509,"lbm_writes_lt_1ms":403,"reinsert_count":0,"spinlock_wait_cycles":768,"update_count":2000}
I20260812 06:17:00.269277  6424 maintenance_manager.cc:419] P e902b5d83f6b419086fddde248ac1e42: Scheduling FlushDeltaMemStoresOp(24c2661cbc8447c8aa38e511c647dd60): perf score=2.188937
I20260812 06:17:00.279734  6308 maintenance_manager.cc:643] P e902b5d83f6b419086fddde248ac1e42: FlushDeltaMemStoresOp(24c2661cbc8447c8aa38e511c647dd60) complete. Timing: real 0.010s	user 0.005s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4174,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:00.280153  6424 maintenance_manager.cc:419] P e902b5d83f6b419086fddde248ac1e42: Scheduling MajorDeltaCompactionOp(24c2661cbc8447c8aa38e511c647dd60): perf score=1.000000
I20260812 06:17:00.458947  6308 maintenance_manager.cc:643] P e902b5d83f6b419086fddde248ac1e42: MajorDeltaCompactionOp(24c2661cbc8447c8aa38e511c647dd60) complete. Timing: real 0.179s	user 0.106s	sys 0.072s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24815686,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":587,"lbm_read_time_us":13084,"lbm_reads_lt_1ms":572,"lbm_write_time_us":28885,"lbm_writes_lt_1ms":543,"mutex_wait_us":78,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":768,"update_count":2500}
I20260812 06:17:00.459548  6424 maintenance_manager.cc:419] P e902b5d83f6b419086fddde248ac1e42: Scheduling FlushDeltaMemStoresOp(24c2661cbc8447c8aa38e511c647dd60): perf score=14.095187
I20260812 06:17:00.514262  6308 maintenance_manager.cc:643] P e902b5d83f6b419086fddde248ac1e42: FlushDeltaMemStoresOp(24c2661cbc8447c8aa38e511c647dd60) complete. Timing: real 0.055s	user 0.029s	sys 0.022s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":18733,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:17:00.514870  6424 maintenance_manager.cc:419] P e902b5d83f6b419086fddde248ac1e42: Scheduling FlushDeltaMemStoresOp(24c2661cbc8447c8aa38e511c647dd60): perf score=2.188937
I20260812 06:17:00.531543  6308 maintenance_manager.cc:643] P e902b5d83f6b419086fddde248ac1e42: FlushDeltaMemStoresOp(24c2661cbc8447c8aa38e511c647dd60) complete. Timing: real 0.016s	user 0.003s	sys 0.011s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6372,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:00.532186  6424 maintenance_manager.cc:419] P e902b5d83f6b419086fddde248ac1e42: Scheduling FlushMRSOp(24c2661cbc8447c8aa38e511c647dd60): perf score=1.000000
I20260812 06:17:00.573058  6308 maintenance_manager.cc:643] P e902b5d83f6b419086fddde248ac1e42: FlushMRSOp(24c2661cbc8447c8aa38e511c647dd60) complete. Timing: real 0.041s	user 0.026s	sys 0.006s Metrics: {"bytes_written":1234473,"cfile_init":1,"dirs.queue_time_us":66,"dirs.run_cpu_time_us":242,"dirs.run_wall_time_us":1304,"drs_written":1,"lbm_read_time_us":59,"lbm_reads_lt_1ms":4,"lbm_write_time_us":2125,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":30}
I20260812 06:17:00.573685  6424 maintenance_manager.cc:419] P e902b5d83f6b419086fddde248ac1e42: Scheduling LogGCOp(24c2661cbc8447c8aa38e511c647dd60): free 124257297 bytes of WAL
I20260812 06:17:00.573910  6308 log_reader.cc:385] T 24c2661cbc8447c8aa38e511c647dd60: removed 12 log segments from log reader
I20260812 06:17:00.573954  6308 log.cc:1079] T 24c2661cbc8447c8aa38e511c647dd60 P e902b5d83f6b419086fddde248ac1e42: Deleting log segment in path: /tmp/dist-test-taske_2AlB/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515413143058-5786-0/minicluster-data/ts-0-root/wals/24c2661cbc8447c8aa38e511c647dd60/wal-000000003 (ops 12-16)
I20260812 06:17:00.573983  6308 log.cc:1079] T 24c2661cbc8447c8aa38e511c647dd60 P e902b5d83f6b419086fddde248ac1e42: Deleting log segment in path: /tmp/dist-test-taske_2AlB/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515413143058-5786-0/minicluster-data/ts-0-root/wals/24c2661cbc8447c8aa38e511c647dd60/wal-000000004 (ops 17-21)
I20260812 06:17:00.574051  6308 log.cc:1079] T 24c2661cbc8447c8aa38e511c647dd60 P e902b5d83f6b419086fddde248ac1e42: Deleting log segment in path: /tmp/dist-test-taske_2AlB/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515413143058-5786-0/minicluster-data/ts-0-root/wals/24c2661cbc8447c8aa38e511c647dd60/wal-000000005 (ops 22-26)
I20260812 06:17:00.574092  6308 log.cc:1079] T 24c2661cbc8447c8aa38e511c647dd60 P e902b5d83f6b419086fddde248ac1e42: Deleting log segment in path: /tmp/dist-test-taske_2AlB/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515413143058-5786-0/minicluster-data/ts-0-root/wals/24c2661cbc8447c8aa38e511c647dd60/wal-000000006 (ops 27-31)
I20260812 06:17:00.574136  6308 log.cc:1079] T 24c2661cbc8447c8aa38e511c647dd60 P e902b5d83f6b419086fddde248ac1e42: Deleting log segment in path: /tmp/dist-test-taske_2AlB/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515413143058-5786-0/minicluster-data/ts-0-root/wals/24c2661cbc8447c8aa38e511c647dd60/wal-000000007 (ops 32-36)
I20260812 06:17:00.574201  6308 log.cc:1079] T 24c2661cbc8447c8aa38e511c647dd60 P e902b5d83f6b419086fddde248ac1e42: Deleting log segment in path: /tmp/dist-test-taske_2AlB/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515413143058-5786-0/minicluster-data/ts-0-root/wals/24c2661cbc8447c8aa38e511c647dd60/wal-000000008 (ops 37-40)
I20260812 06:17:00.574239  6308 log.cc:1079] T 24c2661cbc8447c8aa38e511c647dd60 P e902b5d83f6b419086fddde248ac1e42: Deleting log segment in path: /tmp/dist-test-taske_2AlB/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515413143058-5786-0/minicluster-data/ts-0-root/wals/24c2661cbc8447c8aa38e511c647dd60/wal-000000009 (ops 41-45)
I20260812 06:17:00.574277  6308 log.cc:1079] T 24c2661cbc8447c8aa38e511c647dd60 P e902b5d83f6b419086fddde248ac1e42: Deleting log segment in path: /tmp/dist-test-taske_2AlB/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515413143058-5786-0/minicluster-data/ts-0-root/wals/24c2661cbc8447c8aa38e511c647dd60/wal-000000010 (ops 46-50)
I20260812 06:17:00.574318  6308 log.cc:1079] T 24c2661cbc8447c8aa38e511c647dd60 P e902b5d83f6b419086fddde248ac1e42: Deleting log segment in path: /tmp/dist-test-taske_2AlB/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515413143058-5786-0/minicluster-data/ts-0-root/wals/24c2661cbc8447c8aa38e511c647dd60/wal-000000011 (ops 51-55)
I20260812 06:17:00.574357  6308 log.cc:1079] T 24c2661cbc8447c8aa38e511c647dd60 P e902b5d83f6b419086fddde248ac1e42: Deleting log segment in path: /tmp/dist-test-taske_2AlB/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515413143058-5786-0/minicluster-data/ts-0-root/wals/24c2661cbc8447c8aa38e511c647dd60/wal-000000012 (ops 56-60)
I20260812 06:17:00.574395  6308 log.cc:1079] T 24c2661cbc8447c8aa38e511c647dd60 P e902b5d83f6b419086fddde248ac1e42: Deleting log segment in path: /tmp/dist-test-taske_2AlB/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515413143058-5786-0/minicluster-data/ts-0-root/wals/24c2661cbc8447c8aa38e511c647dd60/wal-000000013 (ops 61-65)
I20260812 06:17:00.574434  6308 log.cc:1079] T 24c2661cbc8447c8aa38e511c647dd60 P e902b5d83f6b419086fddde248ac1e42: Deleting log segment in path: /tmp/dist-test-taske_2AlB/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515413143058-5786-0/minicluster-data/ts-0-root/wals/24c2661cbc8447c8aa38e511c647dd60/wal-000000014 (ops 66-70)
I20260812 06:17:00.599457  6308 maintenance_manager.cc:643] P e902b5d83f6b419086fddde248ac1e42: LogGCOp(24c2661cbc8447c8aa38e511c647dd60) complete. Timing: real 0.026s	user 0.000s	sys 0.022s Metrics: {}
I20260812 06:17:00.599967  6424 maintenance_manager.cc:419] P e902b5d83f6b419086fddde248ac1e42: Scheduling FlushDeltaMemStoresOp(24c2661cbc8447c8aa38e511c647dd60): perf score=2.188937
I20260812 06:17:00.617321  6308 maintenance_manager.cc:643] P e902b5d83f6b419086fddde248ac1e42: FlushDeltaMemStoresOp(24c2661cbc8447c8aa38e511c647dd60) complete. Timing: real 0.017s	user 0.008s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4958,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:00.617761  6424 maintenance_manager.cc:419] P e902b5d83f6b419086fddde248ac1e42: Scheduling FlushDeltaMemStoresOp(24c2661cbc8447c8aa38e511c647dd60): perf score=2.188937
I20260812 06:17:00.628098  6308 maintenance_manager.cc:643] P e902b5d83f6b419086fddde248ac1e42: FlushDeltaMemStoresOp(24c2661cbc8447c8aa38e511c647dd60) complete. Timing: real 0.010s	user 0.008s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3884,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:00.628731  6424 maintenance_manager.cc:419] P e902b5d83f6b419086fddde248ac1e42: Scheduling MajorDeltaCompactionOp(24c2661cbc8447c8aa38e511c647dd60): perf score=1.000000
I20260812 06:17:00.880517  6308 maintenance_manager.cc:643] P e902b5d83f6b419086fddde248ac1e42: MajorDeltaCompactionOp(24c2661cbc8447c8aa38e511c647dd60) complete. Timing: real 0.252s	user 0.162s	sys 0.082s Metrics: {"cfile_cache_miss":734,"cfile_cache_miss_bytes":33020745,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":701,"lbm_read_time_us":15964,"lbm_reads_lt_1ms":774,"lbm_write_time_us":42130,"lbm_writes_lt_1ms":743,"mutex_wait_us":24,"peak_mem_usage":87969044,"reinsert_count":0,"spinlock_wait_cycles":13824,"thread_start_us":85,"threads_started":1,"update_count":3500}
I20260812 06:17:00.881266  6424 maintenance_manager.cc:419] P e902b5d83f6b419086fddde248ac1e42: Scheduling UndoDeltaBlockGCOp(24c2661cbc8447c8aa38e511c647dd60): 472 bytes on disk
I20260812 06:17:00.881821  6308 maintenance_manager.cc:643] P e902b5d83f6b419086fddde248ac1e42: UndoDeltaBlockGCOp(24c2661cbc8447c8aa38e511c647dd60) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":106,"lbm_reads_lt_1ms":4}
I20260812 06:17:00.882562  6424 maintenance_manager.cc:419] P e902b5d83f6b419086fddde248ac1e42: Scheduling FlushDeltaMemStoresOp(24c2661cbc8447c8aa38e511c647dd60): perf score=18.063937
I20260812 06:17:00.934616  6308 maintenance_manager.cc:643] P e902b5d83f6b419086fddde248ac1e42: FlushDeltaMemStoresOp(24c2661cbc8447c8aa38e511c647dd60) complete. Timing: real 0.052s	user 0.037s	sys 0.012s Metrics: {"bytes_written":20512316,"delete_count":0,"lbm_write_time_us":23252,"lbm_writes_lt_1ms":503,"reinsert_count":0,"update_count":2500}
I20260812 06:17:00.935088  6424 maintenance_manager.cc:419] P e902b5d83f6b419086fddde248ac1e42: Scheduling FlushDeltaMemStoresOp(24c2661cbc8447c8aa38e511c647dd60): perf score=2.188937
I20260812 06:17:00.946468  6308 maintenance_manager.cc:643] P e902b5d83f6b419086fddde248ac1e42: FlushDeltaMemStoresOp(24c2661cbc8447c8aa38e511c647dd60) complete. Timing: real 0.011s	user 0.009s	sys 0.000s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":3997,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:00.946909  6424 maintenance_manager.cc:419] P e902b5d83f6b419086fddde248ac1e42: Scheduling MajorDeltaCompactionOp(24c2661cbc8447c8aa38e511c647dd60): perf score=1.000000
I20260812 06:17:01.107389  6308 maintenance_manager.cc:643] P e902b5d83f6b419086fddde248ac1e42: MajorDeltaCompactionOp(24c2661cbc8447c8aa38e511c647dd60) complete. Timing: real 0.160s	user 0.136s	sys 0.024s Metrics: {"cfile_cache_miss":632,"cfile_cache_miss_bytes":28918097,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":797,"lbm_read_time_us":12066,"lbm_reads_lt_1ms":672,"lbm_write_time_us":32343,"lbm_writes_lt_1ms":643,"mutex_wait_us":324,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":4992,"update_count":3000}
I20260812 06:17:01.107961  6424 maintenance_manager.cc:419] P e902b5d83f6b419086fddde248ac1e42: Scheduling FlushDeltaMemStoresOp(24c2661cbc8447c8aa38e511c647dd60): perf score=14.095187
I20260812 06:17:01.151719  6308 maintenance_manager.cc:643] P e902b5d83f6b419086fddde248ac1e42: FlushDeltaMemStoresOp(24c2661cbc8447c8aa38e511c647dd60) complete. Timing: real 0.044s	user 0.019s	sys 0.020s Metrics: {"bytes_written":16409900,"delete_count":0,"lbm_write_time_us":18838,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:17:01.152299  6424 maintenance_manager.cc:419] P e902b5d83f6b419086fddde248ac1e42: Scheduling FlushDeltaMemStoresOp(24c2661cbc8447c8aa38e511c647dd60): perf score=2.188937
I20260812 06:17:01.163051  6308 maintenance_manager.cc:643] P e902b5d83f6b419086fddde248ac1e42: FlushDeltaMemStoresOp(24c2661cbc8447c8aa38e511c647dd60) complete. Timing: real 0.011s	user 0.005s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4239,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:01.163470  6424 maintenance_manager.cc:419] P e902b5d83f6b419086fddde248ac1e42: Scheduling MajorDeltaCompactionOp(24c2661cbc8447c8aa38e511c647dd60): perf score=1.000000
I20260812 06:17:01.322576  6308 maintenance_manager.cc:643] P e902b5d83f6b419086fddde248ac1e42: MajorDeltaCompactionOp(24c2661cbc8447c8aa38e511c647dd60) complete. Timing: real 0.159s	user 0.110s	sys 0.049s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24815682,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":851,"lbm_read_time_us":11694,"lbm_reads_lt_1ms":572,"lbm_write_time_us":30692,"lbm_writes_lt_1ms":543,"mutex_wait_us":57,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":27264,"update_count":2500}
I20260812 06:17:01.323141  6424 maintenance_manager.cc:419] P e902b5d83f6b419086fddde248ac1e42: Scheduling FlushDeltaMemStoresOp(24c2661cbc8447c8aa38e511c647dd60): perf score=11.118625
I20260812 06:17:01.357481  6308 maintenance_manager.cc:643] P e902b5d83f6b419086fddde248ac1e42: FlushDeltaMemStoresOp(24c2661cbc8447c8aa38e511c647dd60) complete. Timing: real 0.034s	user 0.017s	sys 0.015s Metrics: {"bytes_written":12717735,"delete_count":0,"lbm_write_time_us":14938,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:17:01.358228  6424 maintenance_manager.cc:419] P e902b5d83f6b419086fddde248ac1e42: Scheduling FlushDeltaMemStoresOp(24c2661cbc8447c8aa38e511c647dd60): perf score=2.188937
I20260812 06:17:01.373728  6308 maintenance_manager.cc:643] P e902b5d83f6b419086fddde248ac1e42: FlushDeltaMemStoresOp(24c2661cbc8447c8aa38e511c647dd60) complete. Timing: real 0.015s	user 0.005s	sys 0.008s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":5914,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:17:01.374205  6424 maintenance_manager.cc:419] P e902b5d83f6b419086fddde248ac1e42: Scheduling MajorDeltaCompactionOp(24c2661cbc8447c8aa38e511c647dd60): perf score=1.000000
I20260812 06:17:01.518618  6308 maintenance_manager.cc:643] P e902b5d83f6b419086fddde248ac1e42: MajorDeltaCompactionOp(24c2661cbc8447c8aa38e511c647dd60) complete. Timing: real 0.144s	user 0.099s	sys 0.039s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20713263,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":1011,"lbm_read_time_us":9649,"lbm_reads_lt_1ms":464,"lbm_write_time_us":22843,"lbm_writes_lt_1ms":443,"mutex_wait_us":512,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":2304,"update_count":2000}
I20260812 06:17:01.519320  6424 maintenance_manager.cc:419] P e902b5d83f6b419086fddde248ac1e42: Scheduling FlushDeltaMemStoresOp(24c2661cbc8447c8aa38e511c647dd60): perf score=11.118625
I20260812 06:17:01.556347  6308 maintenance_manager.cc:643] P e902b5d83f6b419086fddde248ac1e42: FlushDeltaMemStoresOp(24c2661cbc8447c8aa38e511c647dd60) complete. Timing: real 0.037s	user 0.037s	sys 0.000s Metrics: {"bytes_written":12717735,"delete_count":0,"lbm_write_time_us":15748,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:17:01.557037  6424 maintenance_manager.cc:419] P e902b5d83f6b419086fddde248ac1e42: Scheduling FlushDeltaMemStoresOp(24c2661cbc8447c8aa38e511c647dd60): perf score=2.188937
I20260812 06:17:01.572757  6308 maintenance_manager.cc:643] P e902b5d83f6b419086fddde248ac1e42: FlushDeltaMemStoresOp(24c2661cbc8447c8aa38e511c647dd60) complete. Timing: real 0.015s	user 0.011s	sys 0.000s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":4490,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:17:01.573563  6424 maintenance_manager.cc:419] P e902b5d83f6b419086fddde248ac1e42: Scheduling MajorDeltaCompactionOp(24c2661cbc8447c8aa38e511c647dd60): perf score=1.000000
I20260812 06:17:01.705492  6308 maintenance_manager.cc:643] P e902b5d83f6b419086fddde248ac1e42: MajorDeltaCompactionOp(24c2661cbc8447c8aa38e511c647dd60) complete. Timing: real 0.132s	user 0.104s	sys 0.023s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20713263,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":154,"lbm_read_time_us":7401,"lbm_reads_lt_1ms":464,"lbm_write_time_us":24965,"lbm_writes_lt_1ms":443,"peak_mem_usage":50689328,"reinsert_count":0,"update_count":2000}
I20260812 06:17:01.706108  6424 maintenance_manager.cc:419] P e902b5d83f6b419086fddde248ac1e42: Scheduling FlushDeltaMemStoresOp(24c2661cbc8447c8aa38e511c647dd60): perf score=11.118625
I20260812 06:17:01.739567  6308 maintenance_manager.cc:643] P e902b5d83f6b419086fddde248ac1e42: FlushDeltaMemStoresOp(24c2661cbc8447c8aa38e511c647dd60) complete. Timing: real 0.033s	user 0.022s	sys 0.008s Metrics: {"bytes_written":12717735,"delete_count":0,"lbm_write_time_us":13970,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:17:01.740301  6424 maintenance_manager.cc:419] P e902b5d83f6b419086fddde248ac1e42: Scheduling FlushDeltaMemStoresOp(24c2661cbc8447c8aa38e511c647dd60): perf score=2.188937
I20260812 06:17:01.763706  6308 maintenance_manager.cc:643] P e902b5d83f6b419086fddde248ac1e42: FlushDeltaMemStoresOp(24c2661cbc8447c8aa38e511c647dd60) complete. Timing: real 0.023s	user 0.006s	sys 0.005s Metrics: {"bytes_written":3938559,"delete_count":0,"lbm_write_time_us":4899,"lbm_writes_lt_1ms":99,"reinsert_count":0,"update_count":480}
I20260812 06:17:01.764200  6424 maintenance_manager.cc:419] P e902b5d83f6b419086fddde248ac1e42: Scheduling FlushDeltaMemStoresOp(24c2661cbc8447c8aa38e511c647dd60): perf score=2.188937
I20260812 06:17:01.773950  6308 maintenance_manager.cc:643] P e902b5d83f6b419086fddde248ac1e42: FlushDeltaMemStoresOp(24c2661cbc8447c8aa38e511c647dd60) complete. Timing: real 0.010s	user 0.007s	sys 0.001s Metrics: {"bytes_written":3856509,"delete_count":0,"lbm_write_time_us":3549,"lbm_writes_lt_1ms":97,"reinsert_count":0,"update_count":470}
I20260812 06:17:01.774398  6424 maintenance_manager.cc:419] P e902b5d83f6b419086fddde248ac1e42: Scheduling MajorDeltaCompactionOp(24c2661cbc8447c8aa38e511c647dd60): perf score=1.000000
I20260812 06:17:01.927922  6308 maintenance_manager.cc:643] P e902b5d83f6b419086fddde248ac1e42: MajorDeltaCompactionOp(24c2661cbc8447c8aa38e511c647dd60) complete. Timing: real 0.153s	user 0.127s	sys 0.023s Metrics: {"cfile_cache_miss":533,"cfile_cache_miss_bytes":24815798,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":187,"lbm_read_time_us":11346,"lbm_reads_lt_1ms":573,"lbm_write_time_us":30629,"lbm_writes_lt_1ms":543,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":768,"update_count":2500}
I20260812 06:17:01.928936  6424 maintenance_manager.cc:419] P e902b5d83f6b419086fddde248ac1e42: Scheduling FlushDeltaMemStoresOp(24c2661cbc8447c8aa38e511c647dd60): perf score=10.126437
I20260812 06:17:01.964761  6308 maintenance_manager.cc:643] P e902b5d83f6b419086fddde248ac1e42: FlushDeltaMemStoresOp(24c2661cbc8447c8aa38e511c647dd60) complete. Timing: real 0.036s	user 0.019s	sys 0.012s Metrics: {"bytes_written":12307491,"delete_count":0,"lbm_write_time_us":13825,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:17:01.965327  6424 maintenance_manager.cc:419] P e902b5d83f6b419086fddde248ac1e42: Scheduling FlushDeltaMemStoresOp(24c2661cbc8447c8aa38e511c647dd60): perf score=2.188937
I20260812 06:17:01.976725  6308 maintenance_manager.cc:643] P e902b5d83f6b419086fddde248ac1e42: FlushDeltaMemStoresOp(24c2661cbc8447c8aa38e511c647dd60) complete. Timing: real 0.011s	user 0.006s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4332,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:01.977151  6424 maintenance_manager.cc:419] P e902b5d83f6b419086fddde248ac1e42: Scheduling FlushMRSOp(24c2661cbc8447c8aa38e511c647dd60): perf score=1.000000
I20260812 06:17:02.006649  6308 maintenance_manager.cc:643] P e902b5d83f6b419086fddde248ac1e42: FlushMRSOp(24c2661cbc8447c8aa38e511c647dd60) complete. Timing: real 0.029s	user 0.023s	sys 0.003s Metrics: {"bytes_written":1234479,"cfile_init":1,"dirs.queue_time_us":67,"dirs.run_cpu_time_us":239,"dirs.run_wall_time_us":1476,"drs_written":1,"lbm_read_time_us":39,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1671,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":30}
I20260812 06:17:02.007310  6424 maintenance_manager.cc:419] P e902b5d83f6b419086fddde248ac1e42: Scheduling LogGCOp(24c2661cbc8447c8aa38e511c647dd60): free 121006443 bytes of WAL
I20260812 06:17:02.007575  6308 log_reader.cc:385] T 24c2661cbc8447c8aa38e511c647dd60: removed 12 log segments from log reader
I20260812 06:17:02.007637  6308 log.cc:1079] T 24c2661cbc8447c8aa38e511c647dd60 P e902b5d83f6b419086fddde248ac1e42: Deleting log segment in path: /tmp/dist-test-taske_2AlB/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515413143058-5786-0/minicluster-data/ts-0-root/wals/24c2661cbc8447c8aa38e511c647dd60/wal-000000015 (ops 71-75)
I20260812 06:17:02.007676  6308 log.cc:1079] T 24c2661cbc8447c8aa38e511c647dd60 P e902b5d83f6b419086fddde248ac1e42: Deleting log segment in path: /tmp/dist-test-taske_2AlB/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515413143058-5786-0/minicluster-data/ts-0-root/wals/24c2661cbc8447c8aa38e511c647dd60/wal-000000016 (ops 76-80)
I20260812 06:17:02.007700  6308 log.cc:1079] T 24c2661cbc8447c8aa38e511c647dd60 P e902b5d83f6b419086fddde248ac1e42: Deleting log segment in path: /tmp/dist-test-taske_2AlB/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515413143058-5786-0/minicluster-data/ts-0-root/wals/24c2661cbc8447c8aa38e511c647dd60/wal-000000017 (ops 81-85)
I20260812 06:17:02.007725  6308 log.cc:1079] T 24c2661cbc8447c8aa38e511c647dd60 P e902b5d83f6b419086fddde248ac1e42: Deleting log segment in path: /tmp/dist-test-taske_2AlB/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515413143058-5786-0/minicluster-data/ts-0-root/wals/24c2661cbc8447c8aa38e511c647dd60/wal-000000018 (ops 86-90)
I20260812 06:17:02.007751  6308 log.cc:1079] T 24c2661cbc8447c8aa38e511c647dd60 P e902b5d83f6b419086fddde248ac1e42: Deleting log segment in path: /tmp/dist-test-taske_2AlB/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515413143058-5786-0/minicluster-data/ts-0-root/wals/24c2661cbc8447c8aa38e511c647dd60/wal-000000019 (ops 91-95)
I20260812 06:17:02.007776  6308 log.cc:1079] T 24c2661cbc8447c8aa38e511c647dd60 P e902b5d83f6b419086fddde248ac1e42: Deleting log segment in path: /tmp/dist-test-taske_2AlB/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515413143058-5786-0/minicluster-data/ts-0-root/wals/24c2661cbc8447c8aa38e511c647dd60/wal-000000020 (ops 96-100)
I20260812 06:17:02.007807  6308 log.cc:1079] T 24c2661cbc8447c8aa38e511c647dd60 P e902b5d83f6b419086fddde248ac1e42: Deleting log segment in path: /tmp/dist-test-taske_2AlB/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515413143058-5786-0/minicluster-data/ts-0-root/wals/24c2661cbc8447c8aa38e511c647dd60/wal-000000021 (ops 101-105)
I20260812 06:17:02.007829  6308 log.cc:1079] T 24c2661cbc8447c8aa38e511c647dd60 P e902b5d83f6b419086fddde248ac1e42: Deleting log segment in path: /tmp/dist-test-taske_2AlB/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515413143058-5786-0/minicluster-data/ts-0-root/wals/24c2661cbc8447c8aa38e511c647dd60/wal-000000022 (ops 106-110)
I20260812 06:17:02.007854  6308 log.cc:1079] T 24c2661cbc8447c8aa38e511c647dd60 P e902b5d83f6b419086fddde248ac1e42: Deleting log segment in path: /tmp/dist-test-taske_2AlB/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515413143058-5786-0/minicluster-data/ts-0-root/wals/24c2661cbc8447c8aa38e511c647dd60/wal-000000023 (ops 111-114)
I20260812 06:17:02.007884  6308 log.cc:1079] T 24c2661cbc8447c8aa38e511c647dd60 P e902b5d83f6b419086fddde248ac1e42: Deleting log segment in path: /tmp/dist-test-taske_2AlB/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515413143058-5786-0/minicluster-data/ts-0-root/wals/24c2661cbc8447c8aa38e511c647dd60/wal-000000024 (ops 115-119)
I20260812 06:17:02.007915  6308 log.cc:1079] T 24c2661cbc8447c8aa38e511c647dd60 P e902b5d83f6b419086fddde248ac1e42: Deleting log segment in path: /tmp/dist-test-taske_2AlB/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515413143058-5786-0/minicluster-data/ts-0-root/wals/24c2661cbc8447c8aa38e511c647dd60/wal-000000025 (ops 120-124)
I20260812 06:17:02.007958  6308 log.cc:1079] T 24c2661cbc8447c8aa38e511c647dd60 P e902b5d83f6b419086fddde248ac1e42: Deleting log segment in path: /tmp/dist-test-taske_2AlB/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515413143058-5786-0/minicluster-data/ts-0-root/wals/24c2661cbc8447c8aa38e511c647dd60/wal-000000026 (ops 125-129)
I20260812 06:17:02.035481  6308 maintenance_manager.cc:643] P e902b5d83f6b419086fddde248ac1e42: LogGCOp(24c2661cbc8447c8aa38e511c647dd60) complete. Timing: real 0.028s	user 0.000s	sys 0.025s Metrics: {}
I20260812 06:17:02.035888  6424 maintenance_manager.cc:419] P e902b5d83f6b419086fddde248ac1e42: Scheduling UndoDeltaBlockGCOp(24c2661cbc8447c8aa38e511c647dd60): 472 bytes on disk
I20260812 06:17:02.036386  6308 maintenance_manager.cc:643] P e902b5d83f6b419086fddde248ac1e42: UndoDeltaBlockGCOp(24c2661cbc8447c8aa38e511c647dd60) 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:17:02.036890  6424 maintenance_manager.cc:419] P e902b5d83f6b419086fddde248ac1e42: Scheduling FlushDeltaMemStoresOp(24c2661cbc8447c8aa38e511c647dd60): perf score=2.188937
I20260812 06:17:02.059192  6308 maintenance_manager.cc:643] P e902b5d83f6b419086fddde248ac1e42: FlushDeltaMemStoresOp(24c2661cbc8447c8aa38e511c647dd60) complete. Timing: real 0.022s	user 0.006s	sys 0.003s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4331,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:02.059630  6424 maintenance_manager.cc:419] P e902b5d83f6b419086fddde248ac1e42: Scheduling FlushDeltaMemStoresOp(24c2661cbc8447c8aa38e511c647dd60): perf score=2.188937
I20260812 06:17:02.070245  6308 maintenance_manager.cc:643] P e902b5d83f6b419086fddde248ac1e42: FlushDeltaMemStoresOp(24c2661cbc8447c8aa38e511c647dd60) complete. Timing: real 0.010s	user 0.002s	sys 0.007s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4141,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:02.070775  6424 maintenance_manager.cc:419] P e902b5d83f6b419086fddde248ac1e42: Scheduling MajorDeltaCompactionOp(24c2661cbc8447c8aa38e511c647dd60): perf score=1.000000
I20260812 06:17:02.230298  6308 maintenance_manager.cc:643] P e902b5d83f6b419086fddde248ac1e42: MajorDeltaCompactionOp(24c2661cbc8447c8aa38e511c647dd60) complete. Timing: real 0.159s	user 0.128s	sys 0.030s Metrics: {"cfile_cache_miss":634,"cfile_cache_miss_bytes":28918334,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":1077,"lbm_read_time_us":11133,"lbm_reads_lt_1ms":674,"lbm_write_time_us":32084,"lbm_writes_lt_1ms":643,"mutex_wait_us":520,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":7296,"thread_start_us":79,"threads_started":1,"update_count":3000}
I20260812 06:17:02.230993  6424 maintenance_manager.cc:419] P e902b5d83f6b419086fddde248ac1e42: Scheduling FlushDeltaMemStoresOp(24c2661cbc8447c8aa38e511c647dd60): perf score=14.095187
I20260812 06:17:02.277995  6308 maintenance_manager.cc:643] P e902b5d83f6b419086fddde248ac1e42: FlushDeltaMemStoresOp(24c2661cbc8447c8aa38e511c647dd60) complete. Timing: real 0.047s	user 0.033s	sys 0.012s Metrics: {"bytes_written":16409903,"delete_count":0,"lbm_write_time_us":20635,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:17:02.278553  6424 maintenance_manager.cc:419] P e902b5d83f6b419086fddde248ac1e42: Scheduling FlushDeltaMemStoresOp(24c2661cbc8447c8aa38e511c647dd60): perf score=2.188937
I20260812 06:17:02.293819  6308 maintenance_manager.cc:643] P e902b5d83f6b419086fddde248ac1e42: FlushDeltaMemStoresOp(24c2661cbc8447c8aa38e511c647dd60) complete. Timing: real 0.015s	user 0.013s	sys 0.001s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6028,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:02.294276  6424 maintenance_manager.cc:419] P e902b5d83f6b419086fddde248ac1e42: Scheduling MajorDeltaCompactionOp(24c2661cbc8447c8aa38e511c647dd60): perf score=1.000000
I20260812 06:17:02.461299  6308 maintenance_manager.cc:643] P e902b5d83f6b419086fddde248ac1e42: MajorDeltaCompactionOp(24c2661cbc8447c8aa38e511c647dd60) complete. Timing: real 0.167s	user 0.123s	sys 0.033s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24815685,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":344,"lbm_read_time_us":9138,"lbm_reads_lt_1ms":572,"lbm_write_time_us":31769,"lbm_writes_lt_1ms":543,"mutex_wait_us":64,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":5248,"update_count":2500}
I20260812 06:17:02.461959  6424 maintenance_manager.cc:419] P e902b5d83f6b419086fddde248ac1e42: Scheduling FlushDeltaMemStoresOp(24c2661cbc8447c8aa38e511c647dd60): perf score=14.095187
I20260812 06:17:02.514304  6308 maintenance_manager.cc:643] P e902b5d83f6b419086fddde248ac1e42: FlushDeltaMemStoresOp(24c2661cbc8447c8aa38e511c647dd60) complete. Timing: real 0.052s	user 0.035s	sys 0.013s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":22221,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:17:02.514855  6424 maintenance_manager.cc:419] P e902b5d83f6b419086fddde248ac1e42: Scheduling MajorDeltaCompactionOp(24c2661cbc8447c8aa38e511c647dd60): perf score=1.000000
I20260812 06:17:02.678512  6308 maintenance_manager.cc:643] P e902b5d83f6b419086fddde248ac1e42: MajorDeltaCompactionOp(24c2661cbc8447c8aa38e511c647dd60) complete. Timing: real 0.163s	user 0.105s	sys 0.050s 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":236,"lbm_read_time_us":10642,"lbm_reads_lt_1ms":463,"lbm_write_time_us":26312,"lbm_writes_lt_1ms":443,"mutex_wait_us":55,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":3584,"update_count":2000}
I20260812 06:17:02.679103  6424 maintenance_manager.cc:419] P e902b5d83f6b419086fddde248ac1e42: Scheduling FlushDeltaMemStoresOp(24c2661cbc8447c8aa38e511c647dd60): perf score=14.095187
I20260812 06:17:02.726094  6308 maintenance_manager.cc:643] P e902b5d83f6b419086fddde248ac1e42: FlushDeltaMemStoresOp(24c2661cbc8447c8aa38e511c647dd60) complete. Timing: real 0.047s	user 0.028s	sys 0.013s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":18629,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:17:02.726650  6424 maintenance_manager.cc:419] P e902b5d83f6b419086fddde248ac1e42: Scheduling FlushDeltaMemStoresOp(24c2661cbc8447c8aa38e511c647dd60): perf score=2.188937
I20260812 06:17:02.742442  6308 maintenance_manager.cc:643] P e902b5d83f6b419086fddde248ac1e42: FlushDeltaMemStoresOp(24c2661cbc8447c8aa38e511c647dd60) complete. Timing: real 0.016s	user 0.009s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5972,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:02.742977  6424 maintenance_manager.cc:419] P e902b5d83f6b419086fddde248ac1e42: Scheduling MajorDeltaCompactionOp(24c2661cbc8447c8aa38e511c647dd60): perf score=1.000000
I20260812 06:17:02.923998  6308 maintenance_manager.cc:643] P e902b5d83f6b419086fddde248ac1e42: MajorDeltaCompactionOp(24c2661cbc8447c8aa38e511c647dd60) complete. Timing: real 0.181s	user 0.117s	sys 0.056s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24815684,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":139,"lbm_read_time_us":12973,"lbm_reads_lt_1ms":572,"lbm_write_time_us":26496,"lbm_writes_lt_1ms":543,"mutex_wait_us":21,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":117120,"update_count":2500}
I20260812 06:17:02.924679  6424 maintenance_manager.cc:419] P e902b5d83f6b419086fddde248ac1e42: Scheduling FlushDeltaMemStoresOp(24c2661cbc8447c8aa38e511c647dd60): perf score=14.095187
I20260812 06:17:02.974659  6308 maintenance_manager.cc:643] P e902b5d83f6b419086fddde248ac1e42: FlushDeltaMemStoresOp(24c2661cbc8447c8aa38e511c647dd60) complete. Timing: real 0.050s	user 0.036s	sys 0.005s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":18799,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:17:02.975225  6424 maintenance_manager.cc:419] P e902b5d83f6b419086fddde248ac1e42: Scheduling FlushDeltaMemStoresOp(24c2661cbc8447c8aa38e511c647dd60): perf score=2.188937
I20260812 06:17:02.988531  6308 maintenance_manager.cc:643] P e902b5d83f6b419086fddde248ac1e42: FlushDeltaMemStoresOp(24c2661cbc8447c8aa38e511c647dd60) complete. Timing: real 0.013s	user 0.005s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5462,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:02.988970  6424 maintenance_manager.cc:419] P e902b5d83f6b419086fddde248ac1e42: Scheduling MajorDeltaCompactionOp(24c2661cbc8447c8aa38e511c647dd60): perf score=1.000000
I20260812 06:17:03.146171  6308 maintenance_manager.cc:643] P e902b5d83f6b419086fddde248ac1e42: MajorDeltaCompactionOp(24c2661cbc8447c8aa38e511c647dd60) complete. Timing: real 0.157s	user 0.116s	sys 0.032s 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":179,"lbm_read_time_us":9864,"lbm_reads_lt_1ms":572,"lbm_write_time_us":29356,"lbm_writes_lt_1ms":543,"mutex_wait_us":21,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":6400,"update_count":2500}
I20260812 06:17:03.146958  6424 maintenance_manager.cc:419] P e902b5d83f6b419086fddde248ac1e42: Scheduling FlushDeltaMemStoresOp(24c2661cbc8447c8aa38e511c647dd60): perf score=14.095187
I20260812 06:17:03.194455  6308 maintenance_manager.cc:643] P e902b5d83f6b419086fddde248ac1e42: FlushDeltaMemStoresOp(24c2661cbc8447c8aa38e511c647dd60) complete. Timing: real 0.047s	user 0.025s	sys 0.020s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":20664,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:17:03.194960  6424 maintenance_manager.cc:419] P e902b5d83f6b419086fddde248ac1e42: Scheduling FlushDeltaMemStoresOp(24c2661cbc8447c8aa38e511c647dd60): perf score=2.188937
I20260812 06:17:03.205380  6308 maintenance_manager.cc:643] P e902b5d83f6b419086fddde248ac1e42: FlushDeltaMemStoresOp(24c2661cbc8447c8aa38e511c647dd60) complete. Timing: real 0.010s	user 0.008s	sys 0.001s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4046,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:03.205813  6424 maintenance_manager.cc:419] P e902b5d83f6b419086fddde248ac1e42: Scheduling MajorDeltaCompactionOp(24c2661cbc8447c8aa38e511c647dd60): perf score=1.000000
I20260812 06:17:03.357954  6308 maintenance_manager.cc:643] P e902b5d83f6b419086fddde248ac1e42: MajorDeltaCompactionOp(24c2661cbc8447c8aa38e511c647dd60) complete. Timing: real 0.152s	user 0.110s	sys 0.030s 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":342,"lbm_read_time_us":11829,"lbm_reads_lt_1ms":572,"lbm_write_time_us":27328,"lbm_writes_lt_1ms":543,"mutex_wait_us":41,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":27136,"update_count":2500}
I20260812 06:17:03.358798  6424 maintenance_manager.cc:419] P e902b5d83f6b419086fddde248ac1e42: Scheduling FlushDeltaMemStoresOp(24c2661cbc8447c8aa38e511c647dd60): perf score=14.095187
I20260812 06:17:03.414230  6308 maintenance_manager.cc:643] P e902b5d83f6b419086fddde248ac1e42: FlushDeltaMemStoresOp(24c2661cbc8447c8aa38e511c647dd60) complete. Timing: real 0.055s	user 0.029s	sys 0.024s Metrics: {"bytes_written":16409907,"delete_count":0,"lbm_write_time_us":25556,"lbm_writes_1-10_ms":2,"lbm_writes_lt_1ms":401,"reinsert_count":0,"update_count":2000}
I20260812 06:17:03.414757  6424 maintenance_manager.cc:419] P e902b5d83f6b419086fddde248ac1e42: Scheduling FlushDeltaMemStoresOp(24c2661cbc8447c8aa38e511c647dd60): perf score=2.188937
I20260812 06:17:03.428167  6308 maintenance_manager.cc:643] P e902b5d83f6b419086fddde248ac1e42: FlushDeltaMemStoresOp(24c2661cbc8447c8aa38e511c647dd60) complete. Timing: real 0.013s	user 0.007s	sys 0.003s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4768,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:03.428686  6424 maintenance_manager.cc:419] P e902b5d83f6b419086fddde248ac1e42: Scheduling FlushMRSOp(24c2661cbc8447c8aa38e511c647dd60): perf score=1.000000
I20260812 06:17:03.459136  6308 maintenance_manager.cc:643] P e902b5d83f6b419086fddde248ac1e42: FlushMRSOp(24c2661cbc8447c8aa38e511c647dd60) complete. Timing: real 0.030s	user 0.029s	sys 0.000s Metrics: {"bytes_written":1275447,"cfile_init":1,"dirs.queue_time_us":60,"dirs.run_cpu_time_us":239,"dirs.run_wall_time_us":1373,"drs_written":1,"lbm_read_time_us":45,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1405,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":31}
I20260812 06:17:03.459821  6424 maintenance_manager.cc:419] P e902b5d83f6b419086fddde248ac1e42: Scheduling LogGCOp(24c2661cbc8447c8aa38e511c647dd60): free 129320781 bytes of WAL
I20260812 06:17:03.460070  6308 log_reader.cc:385] T 24c2661cbc8447c8aa38e511c647dd60: removed 13 log segments from log reader
I20260812 06:17:03.460135  6308 log.cc:1079] T 24c2661cbc8447c8aa38e511c647dd60 P e902b5d83f6b419086fddde248ac1e42: Deleting log segment in path: /tmp/dist-test-taske_2AlB/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515413143058-5786-0/minicluster-data/ts-0-root/wals/24c2661cbc8447c8aa38e511c647dd60/wal-000000027 (ops 130-134)
I20260812 06:17:03.460186  6308 log.cc:1079] T 24c2661cbc8447c8aa38e511c647dd60 P e902b5d83f6b419086fddde248ac1e42: Deleting log segment in path: /tmp/dist-test-taske_2AlB/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515413143058-5786-0/minicluster-data/ts-0-root/wals/24c2661cbc8447c8aa38e511c647dd60/wal-000000028 (ops 135-139)
I20260812 06:17:03.460242  6308 log.cc:1079] T 24c2661cbc8447c8aa38e511c647dd60 P e902b5d83f6b419086fddde248ac1e42: Deleting log segment in path: /tmp/dist-test-taske_2AlB/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515413143058-5786-0/minicluster-data/ts-0-root/wals/24c2661cbc8447c8aa38e511c647dd60/wal-000000029 (ops 140-144)
I20260812 06:17:03.460330  6308 log.cc:1079] T 24c2661cbc8447c8aa38e511c647dd60 P e902b5d83f6b419086fddde248ac1e42: Deleting log segment in path: /tmp/dist-test-taske_2AlB/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515413143058-5786-0/minicluster-data/ts-0-root/wals/24c2661cbc8447c8aa38e511c647dd60/wal-000000030 (ops 145-149)
I20260812 06:17:03.460374  6308 log.cc:1079] T 24c2661cbc8447c8aa38e511c647dd60 P e902b5d83f6b419086fddde248ac1e42: Deleting log segment in path: /tmp/dist-test-taske_2AlB/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515413143058-5786-0/minicluster-data/ts-0-root/wals/24c2661cbc8447c8aa38e511c647dd60/wal-000000031 (ops 150-154)
I20260812 06:17:03.460408  6308 log.cc:1079] T 24c2661cbc8447c8aa38e511c647dd60 P e902b5d83f6b419086fddde248ac1e42: Deleting log segment in path: /tmp/dist-test-taske_2AlB/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515413143058-5786-0/minicluster-data/ts-0-root/wals/24c2661cbc8447c8aa38e511c647dd60/wal-000000032 (ops 155-158)
I20260812 06:17:03.460457  6308 log.cc:1079] T 24c2661cbc8447c8aa38e511c647dd60 P e902b5d83f6b419086fddde248ac1e42: Deleting log segment in path: /tmp/dist-test-taske_2AlB/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515413143058-5786-0/minicluster-data/ts-0-root/wals/24c2661cbc8447c8aa38e511c647dd60/wal-000000033 (ops 159-163)
I20260812 06:17:03.460497  6308 log.cc:1079] T 24c2661cbc8447c8aa38e511c647dd60 P e902b5d83f6b419086fddde248ac1e42: Deleting log segment in path: /tmp/dist-test-taske_2AlB/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515413143058-5786-0/minicluster-data/ts-0-root/wals/24c2661cbc8447c8aa38e511c647dd60/wal-000000034 (ops 164-168)
I20260812 06:17:03.460537  6308 log.cc:1079] T 24c2661cbc8447c8aa38e511c647dd60 P e902b5d83f6b419086fddde248ac1e42: Deleting log segment in path: /tmp/dist-test-taske_2AlB/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515413143058-5786-0/minicluster-data/ts-0-root/wals/24c2661cbc8447c8aa38e511c647dd60/wal-000000035 (ops 169-172)
I20260812 06:17:03.460582  6308 log.cc:1079] T 24c2661cbc8447c8aa38e511c647dd60 P e902b5d83f6b419086fddde248ac1e42: Deleting log segment in path: /tmp/dist-test-taske_2AlB/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515413143058-5786-0/minicluster-data/ts-0-root/wals/24c2661cbc8447c8aa38e511c647dd60/wal-000000036 (ops 173-177)
I20260812 06:17:03.460628  6308 log.cc:1079] T 24c2661cbc8447c8aa38e511c647dd60 P e902b5d83f6b419086fddde248ac1e42: Deleting log segment in path: /tmp/dist-test-taske_2AlB/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515413143058-5786-0/minicluster-data/ts-0-root/wals/24c2661cbc8447c8aa38e511c647dd60/wal-000000037 (ops 178-182)
I20260812 06:17:03.460672  6308 log.cc:1079] T 24c2661cbc8447c8aa38e511c647dd60 P e902b5d83f6b419086fddde248ac1e42: Deleting log segment in path: /tmp/dist-test-taske_2AlB/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515413143058-5786-0/minicluster-data/ts-0-root/wals/24c2661cbc8447c8aa38e511c647dd60/wal-000000038 (ops 183-187)
I20260812 06:17:03.460747  6308 log.cc:1079] T 24c2661cbc8447c8aa38e511c647dd60 P e902b5d83f6b419086fddde248ac1e42: Deleting log segment in path: /tmp/dist-test-taske_2AlB/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515413143058-5786-0/minicluster-data/ts-0-root/wals/24c2661cbc8447c8aa38e511c647dd60/wal-000000039 (ops 188-192)
I20260812 06:17:03.486068  6308 maintenance_manager.cc:643] P e902b5d83f6b419086fddde248ac1e42: LogGCOp(24c2661cbc8447c8aa38e511c647dd60) complete. Timing: real 0.026s	user 0.001s	sys 0.023s Metrics: {}
I20260812 06:17:03.486507  6424 maintenance_manager.cc:419] P e902b5d83f6b419086fddde248ac1e42: Scheduling FlushDeltaMemStoresOp(24c2661cbc8447c8aa38e511c647dd60): perf score=6.157687
I20260812 06:17:03.511335  6308 maintenance_manager.cc:643] P e902b5d83f6b419086fddde248ac1e42: FlushDeltaMemStoresOp(24c2661cbc8447c8aa38e511c647dd60) complete. Timing: real 0.025s	user 0.016s	sys 0.004s Metrics: {"bytes_written":8205080,"delete_count":0,"lbm_write_time_us":9520,"lbm_writes_lt_1ms":203,"reinsert_count":0,"update_count":1000}
I20260812 06:17:03.511934  6424 maintenance_manager.cc:419] P e902b5d83f6b419086fddde248ac1e42: Scheduling LogGCOp(24c2661cbc8447c8aa38e511c647dd60): free 11564893 bytes of WAL
I20260812 06:17:03.512228  6308 log_reader.cc:385] T 24c2661cbc8447c8aa38e511c647dd60: removed 1 log segments from log reader
I20260812 06:17:03.512326  6308 log.cc:1079] T 24c2661cbc8447c8aa38e511c647dd60 P e902b5d83f6b419086fddde248ac1e42: Deleting log segment in path: /tmp/dist-test-taske_2AlB/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515413143058-5786-0/minicluster-data/ts-0-root/wals/24c2661cbc8447c8aa38e511c647dd60/wal-000000040 (ops 193-196)
I20260812 06:17:03.514645  6308 maintenance_manager.cc:643] P e902b5d83f6b419086fddde248ac1e42: LogGCOp(24c2661cbc8447c8aa38e511c647dd60) complete. Timing: real 0.002s	user 0.000s	sys 0.000s Metrics: {}
I20260812 06:17:03.514955  6424 maintenance_manager.cc:419] P e902b5d83f6b419086fddde248ac1e42: Scheduling UndoDeltaBlockGCOp(24c2661cbc8447c8aa38e511c647dd60): 483 bytes on disk
I20260812 06:17:03.515311  6308 maintenance_manager.cc:643] P e902b5d83f6b419086fddde248ac1e42: UndoDeltaBlockGCOp(24c2661cbc8447c8aa38e511c647dd60) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":47,"lbm_reads_lt_1ms":4}
I20260812 06:17:03.515846  6424 maintenance_manager.cc:419] P e902b5d83f6b419086fddde248ac1e42: Scheduling MajorDeltaCompactionOp(24c2661cbc8447c8aa38e511c647dd60): perf score=1.000000
I20260812 06:17:03.610697  5786 heavy-update-compaction-itest.cc:229] Time spent updating: real 4.736s	user 1.812s	sys 0.131s
I20260812 06:17:03.697254  5786 heavy-update-compaction-itest.cc:265] Time spent scanning: real 0.086s	user 0.002s	sys 0.000s
I20260812 06:17:03.697794  5786 tablet_server.cc:179] TabletServer@127.5.166.129:0 shutting down...
I20260812 06:17:03.728123  6308 maintenance_manager.cc:643] P e902b5d83f6b419086fddde248ac1e42: MajorDeltaCompactionOp(24c2661cbc8447c8aa38e511c647dd60) complete. Timing: real 0.212s	user 0.143s	sys 0.064s Metrics: {"cfile_cache_miss":733,"cfile_cache_miss_bytes":33020635,"cfile_init":7,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":324,"lbm_read_time_us":14985,"lbm_reads_lt_1ms":761,"lbm_write_time_us":32452,"lbm_writes_lt_1ms":743,"mutex_wait_us":22,"peak_mem_usage":87969044,"reinsert_count":0,"spinlock_wait_cycles":14592,"thread_start_us":75,"threads_started":1,"update_count":3500}
I20260812 06:17:03.729118  5786 ts_tablet_manager.cc:1507] Shutting down tablet manager...
I20260812 06:17:03.729367  5786 tablet_replica.cc:333] T 24c2661cbc8447c8aa38e511c647dd60 P e902b5d83f6b419086fddde248ac1e42: stopping tablet replica
I20260812 06:17:03.729534  5786 raft_consensus.cc:2243] T 24c2661cbc8447c8aa38e511c647dd60 P e902b5d83f6b419086fddde248ac1e42 [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:17:03.729697  5786 raft_consensus.cc:2272] T 24c2661cbc8447c8aa38e511c647dd60 P e902b5d83f6b419086fddde248ac1e42 [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:17:03.745371  5786 tablet_server.cc:196] TabletServer@127.5.166.129:0 shutdown complete.
I20260812 06:17:03.790189  5786 master.cc:562] Master@127.5.166.190:33609 shutting down...
I20260812 06:17:03.793601  5786 raft_consensus.cc:2243] T 00000000000000000000000000000000 P 28b0f4bda6204876b89aa5113840dd7a [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:17:03.793759  5786 raft_consensus.cc:2272] T 00000000000000000000000000000000 P 28b0f4bda6204876b89aa5113840dd7a [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:17:03.793808  5786 tablet_replica.cc:333] T 00000000000000000000000000000000 P 28b0f4bda6204876b89aa5113840dd7a: stopping tablet replica
I20260812 06:17:03.806147  5786 master.cc:584] Master@127.5.166.190:33609 shutdown complete.
[       OK ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/1 (5253 ms)
[----------] 2 tests from EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy (10735 ms total)

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