[==========] 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:22.916004 13641 internal_mini_cluster.cc:156] Creating distributed mini masters. Addrs: 127.13.82.126:46585
I20260812 06:16:22.917012 13641 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:22.917683 13641 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:16:22.924208 13646 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:22.924300 13641 server_base.cc:1061] running on GCE node
W20260812 06:16:22.924259 13651 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:22.924559 13656 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:22.925145 13641 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:16:22.925290 13641 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:22.925328 13641 hybrid_clock.cc:648] HybridClock initialized: now 1786515382925327 us; error 0 us; skew 500 ppm
I20260812 06:16:22.927016 13641 webserver.cc:533] Webserver started at http://127.13.82.126:45269/ using document root <none> and password file <none>
I20260812 06:16:22.927493 13641 fs_manager.cc:362] Metadata directory not provided
I20260812 06:16:22.927549 13641 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:16:22.927728 13641 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:16:22.929461 13641 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskNmQegX/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515382905434-13641-0/minicluster-data/master-0-root/instance:
uuid: "96d419d118a547599e0a0b235bd6f415"
format_stamp: "Formatted at 2026-08-12 06:16:22 on dist-test-slave-8hhm"
I20260812 06:16:22.932729 13641 fs_manager.cc:696] Time spent creating directory manager: real 0.003s	user 0.003s	sys 0.000s
I20260812 06:16:22.934866 13662 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:22.935899 13641 fs_manager.cc:730] Time spent opening block manager: real 0.002s	user 0.001s	sys 0.000s
I20260812 06:16:22.936064 13641 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskNmQegX/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515382905434-13641-0/minicluster-data/master-0-root
uuid: "96d419d118a547599e0a0b235bd6f415"
format_stamp: "Formatted at 2026-08-12 06:16:22 on dist-test-slave-8hhm"
I20260812 06:16:22.936172 13641 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskNmQegX/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515382905434-13641-0/minicluster-data/master-0-root
metadata directory: /tmp/dist-test-taskNmQegX/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515382905434-13641-0/minicluster-data/master-0-root
1 data directories: /tmp/dist-test-taskNmQegX/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515382905434-13641-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:22.953680 13641 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:16:22.954322 13641 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:22.954523 13641 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:16:22.962312 13641 rpc_server.cc:307] RPC server started. Bound to: 127.13.82.126:46585
I20260812 06:16:22.962320 13756 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.13.82.126:46585 every 8 connection(s)
I20260812 06:16:22.964481 13760 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:22.969822 13760 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P 96d419d118a547599e0a0b235bd6f415: Bootstrap starting.
I20260812 06:16:22.972375 13760 tablet_bootstrap.cc:654] T 00000000000000000000000000000000 P 96d419d118a547599e0a0b235bd6f415: Neither blocks nor log segments found. Creating new log.
I20260812 06:16:22.973235 13760 log.cc:826] T 00000000000000000000000000000000 P 96d419d118a547599e0a0b235bd6f415: Log is configured to *not* fsync() on all Append() calls
I20260812 06:16:22.974843 13760 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P 96d419d118a547599e0a0b235bd6f415: No bootstrap required, opened a new log
I20260812 06:16:22.977617 13760 raft_consensus.cc:359] T 00000000000000000000000000000000 P 96d419d118a547599e0a0b235bd6f415 [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "96d419d118a547599e0a0b235bd6f415" member_type: VOTER }
I20260812 06:16:22.977772 13760 raft_consensus.cc:385] T 00000000000000000000000000000000 P 96d419d118a547599e0a0b235bd6f415 [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:16:22.977811 13760 raft_consensus.cc:740] T 00000000000000000000000000000000 P 96d419d118a547599e0a0b235bd6f415 [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: 96d419d118a547599e0a0b235bd6f415, State: Initialized, Role: FOLLOWER
I20260812 06:16:22.978406 13760 consensus_queue.cc:260] T 00000000000000000000000000000000 P 96d419d118a547599e0a0b235bd6f415 [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: "96d419d118a547599e0a0b235bd6f415" member_type: VOTER }
I20260812 06:16:22.978556 13760 raft_consensus.cc:399] T 00000000000000000000000000000000 P 96d419d118a547599e0a0b235bd6f415 [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:16:22.978605 13760 raft_consensus.cc:493] T 00000000000000000000000000000000 P 96d419d118a547599e0a0b235bd6f415 [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:16:22.978686 13760 raft_consensus.cc:3060] T 00000000000000000000000000000000 P 96d419d118a547599e0a0b235bd6f415 [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:16:22.979398 13760 raft_consensus.cc:515] T 00000000000000000000000000000000 P 96d419d118a547599e0a0b235bd6f415 [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "96d419d118a547599e0a0b235bd6f415" member_type: VOTER }
I20260812 06:16:22.979764 13760 leader_election.cc:304] T 00000000000000000000000000000000 P 96d419d118a547599e0a0b235bd6f415 [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: 96d419d118a547599e0a0b235bd6f415; no voters: 
I20260812 06:16:22.980077 13760 leader_election.cc:290] T 00000000000000000000000000000000 P 96d419d118a547599e0a0b235bd6f415 [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:16:22.980284 13764 raft_consensus.cc:2804] T 00000000000000000000000000000000 P 96d419d118a547599e0a0b235bd6f415 [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:16:22.980556 13764 raft_consensus.cc:697] T 00000000000000000000000000000000 P 96d419d118a547599e0a0b235bd6f415 [term 1 LEADER]: Becoming Leader. State: Replica: 96d419d118a547599e0a0b235bd6f415, State: Running, Role: LEADER
I20260812 06:16:22.980976 13764 consensus_queue.cc:237] T 00000000000000000000000000000000 P 96d419d118a547599e0a0b235bd6f415 [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: "96d419d118a547599e0a0b235bd6f415" member_type: VOTER }
I20260812 06:16:22.981122 13760 sys_catalog.cc:565] T 00000000000000000000000000000000 P 96d419d118a547599e0a0b235bd6f415 [sys.catalog]: configured and running, proceeding with master startup.
I20260812 06:16:22.983096 13767 sys_catalog.cc:455] T 00000000000000000000000000000000 P 96d419d118a547599e0a0b235bd6f415 [sys.catalog]: SysCatalogTable state changed. Reason: New leader 96d419d118a547599e0a0b235bd6f415. Latest consensus state: current_term: 1 leader_uuid: "96d419d118a547599e0a0b235bd6f415" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "96d419d118a547599e0a0b235bd6f415" member_type: VOTER } }
I20260812 06:16:22.983147 13766 sys_catalog.cc:455] T 00000000000000000000000000000000 P 96d419d118a547599e0a0b235bd6f415 [sys.catalog]: SysCatalogTable state changed. Reason: RaftConsensus started. Latest consensus state: current_term: 1 leader_uuid: "96d419d118a547599e0a0b235bd6f415" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "96d419d118a547599e0a0b235bd6f415" member_type: VOTER } }
I20260812 06:16:22.983223 13767 sys_catalog.cc:458] T 00000000000000000000000000000000 P 96d419d118a547599e0a0b235bd6f415 [sys.catalog]: This master's current role is: LEADER
I20260812 06:16:22.983247 13766 sys_catalog.cc:458] T 00000000000000000000000000000000 P 96d419d118a547599e0a0b235bd6f415 [sys.catalog]: This master's current role is: LEADER
I20260812 06:16:22.983587 13782 catalog_manager.cc:1511] Loading table and tablet metadata into memory...
I20260812 06:16:22.983709 13641 internal_mini_cluster.cc:184] Waiting to initialize catalog manager on master 0
I20260812 06:16:22.985869 13782 catalog_manager.cc:1520] Initializing Kudu cluster ID...
I20260812 06:16:22.990327 13782 catalog_manager.cc:1383] Generated new cluster ID: 75fc14c6fe1147afbef7fdd08cb7f595
I20260812 06:16:22.990396 13782 catalog_manager.cc:1531] Initializing Kudu internal certificate authority...
I20260812 06:16:23.007833 13782 catalog_manager.cc:1406] Generated new certificate authority record
I20260812 06:16:23.009037 13782 catalog_manager.cc:1540] Loading token signing keys...
I20260812 06:16:23.021358 13782 catalog_manager.cc:6092] T 00000000000000000000000000000000 P 96d419d118a547599e0a0b235bd6f415: Generated new TSK 0
I20260812 06:16:23.022130 13782 catalog_manager.cc:1550] Initializing in-progress tserver states...
I20260812 06:16:23.048470 13641 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:16:23.051232 13790 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:23.051332 13791 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:23.051347 13793 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:23.051568 13641 server_base.cc:1061] running on GCE node
I20260812 06:16:23.051750 13641 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:16:23.051810 13641 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:23.051836 13641 hybrid_clock.cc:648] HybridClock initialized: now 1786515383051835 us; error 0 us; skew 500 ppm
I20260812 06:16:23.052778 13641 webserver.cc:533] Webserver started at http://127.13.82.65:33989/ using document root <none> and password file <none>
I20260812 06:16:23.052968 13641 fs_manager.cc:362] Metadata directory not provided
I20260812 06:16:23.053045 13641 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:16:23.053120 13641 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:16:23.053582 13641 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskNmQegX/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515382905434-13641-0/minicluster-data/ts-0-root/instance:
uuid: "a5d058d6aea040dc844d590bbd39eb38"
format_stamp: "Formatted at 2026-08-12 06:16:23 on dist-test-slave-8hhm"
I20260812 06:16:23.055152 13641 fs_manager.cc:696] Time spent creating directory manager: real 0.001s	user 0.000s	sys 0.002s
I20260812 06:16:23.056144 13800 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:23.056372 13641 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.000s	sys 0.001s
I20260812 06:16:23.056442 13641 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskNmQegX/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515382905434-13641-0/minicluster-data/ts-0-root
uuid: "a5d058d6aea040dc844d590bbd39eb38"
format_stamp: "Formatted at 2026-08-12 06:16:23 on dist-test-slave-8hhm"
I20260812 06:16:23.056528 13641 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskNmQegX/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515382905434-13641-0/minicluster-data/ts-0-root
metadata directory: /tmp/dist-test-taskNmQegX/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515382905434-13641-0/minicluster-data/ts-0-root
1 data directories: /tmp/dist-test-taskNmQegX/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515382905434-13641-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:23.063043 13641 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:16:23.063482 13641 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:16:23.063931 13641 txn_system_client.cc:432] TxnSystemClient initialization is disabled...
I20260812 06:16:23.064750 13641 ts_tablet_manager.cc:585] Loaded tablet metadata (0 total tablets, 0 live tablets)
I20260812 06:16:23.064826 13641 ts_tablet_manager.cc:531] Time spent load tablet metadata: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:16:23.064899 13641 ts_tablet_manager.cc:616] Registered 0 tablets
I20260812 06:16:23.064953 13641 ts_tablet_manager.cc:595] Time spent register tablets: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:16:23.072221 13641 rpc_server.cc:307] RPC server started. Bound to: 127.13.82.65:33757
I20260812 06:16:23.072285 13914 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.13.82.65:33757 every 8 connection(s)
I20260812 06:16:23.082157 13915 heartbeater.cc:344] Connected to a master server at 127.13.82.126:46585
I20260812 06:16:23.082436 13915 heartbeater.cc:461] Registering TS with master...
I20260812 06:16:23.082870 13915 heartbeater.cc:507] Master 127.13.82.126:46585 requested a full tablet report, sending...
I20260812 06:16:23.084465 13687 ts_manager.cc:194] Registered new tserver with Master: a5d058d6aea040dc844d590bbd39eb38 (127.13.82.65:33757)
I20260812 06:16:23.085253 13641 internal_mini_cluster.cc:371] 1 TS(s) registered with all masters after 0.012366807s
I20260812 06:16:23.086045 13687 master_service.cc:502] Signed X509 certificate for tserver {username='slave'} at 127.0.0.1:36910
I20260812 06:16:23.094866 13687 catalog_manager.cc:2283] Servicing CreateTable request from {username='slave'} at 127.0.0.1:36916:
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:23.108906 13847 tablet_service.cc:1511] Processing CreateTablet for tablet ef7c519e0bdc4364816a01ee052d29c4 (DEFAULT_TABLE table=heavy-update-compaction-test [id=e53a8e05eac440bf880c78112b68f549]), partition=
I20260812 06:16:23.109460 13847 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet ef7c519e0bdc4364816a01ee052d29c4. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:16:23.111871 13929 tablet_bootstrap.cc:492] T ef7c519e0bdc4364816a01ee052d29c4 P a5d058d6aea040dc844d590bbd39eb38: Bootstrap starting.
I20260812 06:16:23.113200 13929 tablet_bootstrap.cc:654] T ef7c519e0bdc4364816a01ee052d29c4 P a5d058d6aea040dc844d590bbd39eb38: Neither blocks nor log segments found. Creating new log.
I20260812 06:16:23.114722 13929 tablet_bootstrap.cc:492] T ef7c519e0bdc4364816a01ee052d29c4 P a5d058d6aea040dc844d590bbd39eb38: No bootstrap required, opened a new log
I20260812 06:16:23.114850 13929 ts_tablet_manager.cc:1403] T ef7c519e0bdc4364816a01ee052d29c4 P a5d058d6aea040dc844d590bbd39eb38: Time spent bootstrapping tablet: real 0.003s	user 0.000s	sys 0.002s
I20260812 06:16:23.115401 13929 raft_consensus.cc:359] T ef7c519e0bdc4364816a01ee052d29c4 P a5d058d6aea040dc844d590bbd39eb38 [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "a5d058d6aea040dc844d590bbd39eb38" member_type: VOTER last_known_addr { host: "127.13.82.65" port: 33757 } }
I20260812 06:16:23.115530 13929 raft_consensus.cc:385] T ef7c519e0bdc4364816a01ee052d29c4 P a5d058d6aea040dc844d590bbd39eb38 [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:16:23.115576 13929 raft_consensus.cc:740] T ef7c519e0bdc4364816a01ee052d29c4 P a5d058d6aea040dc844d590bbd39eb38 [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: a5d058d6aea040dc844d590bbd39eb38, State: Initialized, Role: FOLLOWER
I20260812 06:16:23.115737 13929 consensus_queue.cc:260] T ef7c519e0bdc4364816a01ee052d29c4 P a5d058d6aea040dc844d590bbd39eb38 [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: "a5d058d6aea040dc844d590bbd39eb38" member_type: VOTER last_known_addr { host: "127.13.82.65" port: 33757 } }
I20260812 06:16:23.115833 13929 raft_consensus.cc:399] T ef7c519e0bdc4364816a01ee052d29c4 P a5d058d6aea040dc844d590bbd39eb38 [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:16:23.115882 13929 raft_consensus.cc:493] T ef7c519e0bdc4364816a01ee052d29c4 P a5d058d6aea040dc844d590bbd39eb38 [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:16:23.115936 13929 raft_consensus.cc:3060] T ef7c519e0bdc4364816a01ee052d29c4 P a5d058d6aea040dc844d590bbd39eb38 [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:16:23.117077 13929 raft_consensus.cc:515] T ef7c519e0bdc4364816a01ee052d29c4 P a5d058d6aea040dc844d590bbd39eb38 [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "a5d058d6aea040dc844d590bbd39eb38" member_type: VOTER last_known_addr { host: "127.13.82.65" port: 33757 } }
I20260812 06:16:23.117281 13929 leader_election.cc:304] T ef7c519e0bdc4364816a01ee052d29c4 P a5d058d6aea040dc844d590bbd39eb38 [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: a5d058d6aea040dc844d590bbd39eb38; no voters: 
I20260812 06:16:23.117517 13929 leader_election.cc:290] T ef7c519e0bdc4364816a01ee052d29c4 P a5d058d6aea040dc844d590bbd39eb38 [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:16:23.117650 13931 raft_consensus.cc:2804] T ef7c519e0bdc4364816a01ee052d29c4 P a5d058d6aea040dc844d590bbd39eb38 [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:16:23.117877 13929 ts_tablet_manager.cc:1434] T ef7c519e0bdc4364816a01ee052d29c4 P a5d058d6aea040dc844d590bbd39eb38: Time spent starting tablet: real 0.003s	user 0.002s	sys 0.001s
I20260812 06:16:23.117945 13931 raft_consensus.cc:697] T ef7c519e0bdc4364816a01ee052d29c4 P a5d058d6aea040dc844d590bbd39eb38 [term 1 LEADER]: Becoming Leader. State: Replica: a5d058d6aea040dc844d590bbd39eb38, State: Running, Role: LEADER
I20260812 06:16:23.118121 13915 heartbeater.cc:499] Master 127.13.82.126:46585 was elected leader, sending a full tablet report...
I20260812 06:16:23.118131 13931 consensus_queue.cc:237] T ef7c519e0bdc4364816a01ee052d29c4 P a5d058d6aea040dc844d590bbd39eb38 [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: "a5d058d6aea040dc844d590bbd39eb38" member_type: VOTER last_known_addr { host: "127.13.82.65" port: 33757 } }
I20260812 06:16:23.121388 13687 catalog_manager.cc:5719] T ef7c519e0bdc4364816a01ee052d29c4 P a5d058d6aea040dc844d590bbd39eb38 reported cstate change: term changed from 0 to 1, leader changed from <none> to a5d058d6aea040dc844d590bbd39eb38 (127.13.82.65). New cstate: current_term: 1 leader_uuid: "a5d058d6aea040dc844d590bbd39eb38" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "a5d058d6aea040dc844d590bbd39eb38" member_type: VOTER last_known_addr { host: "127.13.82.65" port: 33757 } health_report { overall_health: HEALTHY } } }
I20260812 06:16:23.221616 13641 heavy-update-compaction-itest.cc:215] Time spent inserting: real 0.091s	user 0.013s	sys 0.025s
I20260812 06:16:23.323438 13916 maintenance_manager.cc:419] P a5d058d6aea040dc844d590bbd39eb38: Scheduling FlushMRSOp(ef7c519e0bdc4364816a01ee052d29c4): perf score=6.156503
I20260812 06:16:23.465425 13807 maintenance_manager.cc:643] P a5d058d6aea040dc844d590bbd39eb38: FlushMRSOp(ef7c519e0bdc4364816a01ee052d29c4) complete. Timing: real 0.142s	user 0.094s	sys 0.044s Metrics: {"bytes_written":12307492,"cfile_init":1,"compiler_manager_pool.queue_time_us":209,"delete_count":0,"dirs.queue_time_us":88,"dirs.run_cpu_time_us":231,"dirs.run_wall_time_us":847,"drs_written":1,"lbm_read_time_us":72,"lbm_reads_lt_1ms":4,"lbm_write_time_us":32907,"lbm_writes_lt_1ms":457,"peak_mem_usage":0,"reinsert_count":0,"rows_written":101,"thread_start_us":129,"threads_started":1,"update_count":1500}
I20260812 06:16:23.466547 13916 maintenance_manager.cc:419] P a5d058d6aea040dc844d590bbd39eb38: Scheduling UndoDeltaBlockGCOp(ef7c519e0bdc4364816a01ee052d29c4): 4103815 bytes on disk
I20260812 06:16:23.467165 13807 maintenance_manager.cc:643] P a5d058d6aea040dc844d590bbd39eb38: UndoDeltaBlockGCOp(ef7c519e0bdc4364816a01ee052d29c4) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":74,"lbm_reads_lt_1ms":4}
I20260812 06:16:23.467665 13916 maintenance_manager.cc:419] P a5d058d6aea040dc844d590bbd39eb38: Scheduling FlushDeltaMemStoresOp(ef7c519e0bdc4364816a01ee052d29c4): perf score=1.000000
I20260812 06:16:23.476769 13807 maintenance_manager.cc:643] P a5d058d6aea040dc844d590bbd39eb38: FlushDeltaMemStoresOp(ef7c519e0bdc4364816a01ee052d29c4) complete. Timing: real 0.009s	user 0.003s	sys 0.003s Metrics: {"bytes_written":1641156,"delete_count":0,"lbm_write_time_us":2745,"lbm_writes_lt_1ms":43,"reinsert_count":0,"update_count":200}
I20260812 06:16:23.477330 13916 maintenance_manager.cc:419] P a5d058d6aea040dc844d590bbd39eb38: Scheduling LogGCOp(ef7c519e0bdc4364816a01ee052d29c4): free 11976772 bytes of WAL
I20260812 06:16:23.477648 13807 log_reader.cc:385] T ef7c519e0bdc4364816a01ee052d29c4: removed 1 log segments from log reader
I20260812 06:16:23.477728 13807 log.cc:1079] T ef7c519e0bdc4364816a01ee052d29c4 P a5d058d6aea040dc844d590bbd39eb38: Deleting log segment in path: /tmp/dist-test-taskNmQegX/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515382905434-13641-0/minicluster-data/ts-0-root/wals/ef7c519e0bdc4364816a01ee052d29c4/wal-000000001 (ops 1-6)
I20260812 06:16:23.481148 13807 maintenance_manager.cc:643] P a5d058d6aea040dc844d590bbd39eb38: LogGCOp(ef7c519e0bdc4364816a01ee052d29c4) complete. Timing: real 0.004s	user 0.001s	sys 0.000s Metrics: {}
I20260812 06:16:23.481508 13916 maintenance_manager.cc:419] P a5d058d6aea040dc844d590bbd39eb38: Scheduling FlushDeltaMemStoresOp(ef7c519e0bdc4364816a01ee052d29c4): perf score=1.196750
I20260812 06:16:23.492100 13807 maintenance_manager.cc:643] P a5d058d6aea040dc844d590bbd39eb38: FlushDeltaMemStoresOp(ef7c519e0bdc4364816a01ee052d29c4) complete. Timing: real 0.010s	user 0.005s	sys 0.004s Metrics: {"bytes_written":2461654,"delete_count":0,"lbm_write_time_us":3794,"lbm_writes_lt_1ms":63,"reinsert_count":0,"update_count":300}
I20260812 06:16:23.492640 13916 maintenance_manager.cc:419] P a5d058d6aea040dc844d590bbd39eb38: Scheduling MajorDeltaCompactionOp(ef7c519e0bdc4364816a01ee052d29c4): perf score=1.000000
I20260812 06:16:23.632452 13807 maintenance_manager.cc:643] P a5d058d6aea040dc844d590bbd39eb38: MajorDeltaCompactionOp(ef7c519e0bdc4364816a01ee052d29c4) complete. Timing: real 0.140s	user 0.092s	sys 0.048s Metrics: {"cfile_cache_miss":433,"cfile_cache_miss_bytes":20549408,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":949,"lbm_read_time_us":9470,"lbm_reads_lt_1ms":469,"lbm_write_time_us":28284,"lbm_writes_lt_1ms":443,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":2560,"thread_start_us":317,"threads_started":5,"update_count":2000}
I20260812 06:16:23.633071 13916 maintenance_manager.cc:419] P a5d058d6aea040dc844d590bbd39eb38: Scheduling FlushDeltaMemStoresOp(ef7c519e0bdc4364816a01ee052d29c4): perf score=10.126437
I20260812 06:16:23.672297 13807 maintenance_manager.cc:643] P a5d058d6aea040dc844d590bbd39eb38: FlushDeltaMemStoresOp(ef7c519e0bdc4364816a01ee052d29c4) complete. Timing: real 0.039s	user 0.029s	sys 0.007s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":18910,"lbm_writes_1-10_ms":2,"lbm_writes_lt_1ms":301,"reinsert_count":0,"update_count":1500}
I20260812 06:16:23.672739 13916 maintenance_manager.cc:419] P a5d058d6aea040dc844d590bbd39eb38: Scheduling FlushDeltaMemStoresOp(ef7c519e0bdc4364816a01ee052d29c4): perf score=2.188937
I20260812 06:16:23.683194 13807 maintenance_manager.cc:643] P a5d058d6aea040dc844d590bbd39eb38: FlushDeltaMemStoresOp(ef7c519e0bdc4364816a01ee052d29c4) complete. Timing: real 0.010s	user 0.009s	sys 0.000s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4022,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:23.683619 13916 maintenance_manager.cc:419] P a5d058d6aea040dc844d590bbd39eb38: Scheduling MajorDeltaCompactionOp(ef7c519e0bdc4364816a01ee052d29c4): perf score=1.000000
I20260812 06:16:23.805917 13807 maintenance_manager.cc:643] P a5d058d6aea040dc844d590bbd39eb38: MajorDeltaCompactionOp(ef7c519e0bdc4364816a01ee052d29c4) complete. Timing: real 0.122s	user 0.103s	sys 0.019s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20549381,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":716,"lbm_read_time_us":8808,"lbm_reads_lt_1ms":472,"lbm_write_time_us":22777,"lbm_writes_lt_1ms":443,"mutex_wait_us":288,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":6656,"update_count":2000}
I20260812 06:16:23.806615 13916 maintenance_manager.cc:419] P a5d058d6aea040dc844d590bbd39eb38: Scheduling FlushDeltaMemStoresOp(ef7c519e0bdc4364816a01ee052d29c4): perf score=10.126437
I20260812 06:16:23.856149 13807 maintenance_manager.cc:643] P a5d058d6aea040dc844d590bbd39eb38: FlushDeltaMemStoresOp(ef7c519e0bdc4364816a01ee052d29c4) complete. Timing: real 0.049s	user 0.020s	sys 0.026s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":17233,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:16:23.856693 13916 maintenance_manager.cc:419] P a5d058d6aea040dc844d590bbd39eb38: Scheduling FlushDeltaMemStoresOp(ef7c519e0bdc4364816a01ee052d29c4): perf score=2.188937
I20260812 06:16:23.871866 13807 maintenance_manager.cc:643] P a5d058d6aea040dc844d590bbd39eb38: FlushDeltaMemStoresOp(ef7c519e0bdc4364816a01ee052d29c4) complete. Timing: real 0.015s	user 0.007s	sys 0.003s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4748,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:23.872282 13916 maintenance_manager.cc:419] P a5d058d6aea040dc844d590bbd39eb38: Scheduling MajorDeltaCompactionOp(ef7c519e0bdc4364816a01ee052d29c4): perf score=1.000000
I20260812 06:16:24.013525 13807 maintenance_manager.cc:643] P a5d058d6aea040dc844d590bbd39eb38: MajorDeltaCompactionOp(ef7c519e0bdc4364816a01ee052d29c4) complete. Timing: real 0.141s	user 0.093s	sys 0.045s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20549381,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":1084,"lbm_read_time_us":9090,"lbm_reads_lt_1ms":468,"lbm_write_time_us":23700,"lbm_writes_lt_1ms":443,"mutex_wait_us":312,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":6016,"update_count":2000}
I20260812 06:16:24.014077 13916 maintenance_manager.cc:419] P a5d058d6aea040dc844d590bbd39eb38: Scheduling FlushDeltaMemStoresOp(ef7c519e0bdc4364816a01ee052d29c4): perf score=11.118625
I20260812 06:16:24.048774 13807 maintenance_manager.cc:643] P a5d058d6aea040dc844d590bbd39eb38: FlushDeltaMemStoresOp(ef7c519e0bdc4364816a01ee052d29c4) complete. Timing: real 0.035s	user 0.011s	sys 0.020s Metrics: {"bytes_written":12717735,"delete_count":0,"lbm_write_time_us":15842,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:16:24.049439 13916 maintenance_manager.cc:419] P a5d058d6aea040dc844d590bbd39eb38: Scheduling FlushDeltaMemStoresOp(ef7c519e0bdc4364816a01ee052d29c4): perf score=2.188937
I20260812 06:16:24.077298 13807 maintenance_manager.cc:643] P a5d058d6aea040dc844d590bbd39eb38: FlushDeltaMemStoresOp(ef7c519e0bdc4364816a01ee052d29c4) complete. Timing: real 0.028s	user 0.014s	sys 0.000s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":5156,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:16:24.077790 13916 maintenance_manager.cc:419] P a5d058d6aea040dc844d590bbd39eb38: Scheduling FlushDeltaMemStoresOp(ef7c519e0bdc4364816a01ee052d29c4): perf score=2.188937
I20260812 06:16:24.088153 13807 maintenance_manager.cc:643] P a5d058d6aea040dc844d590bbd39eb38: FlushDeltaMemStoresOp(ef7c519e0bdc4364816a01ee052d29c4) complete. Timing: real 0.010s	user 0.005s	sys 0.004s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":3875,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:24.088554 13916 maintenance_manager.cc:419] P a5d058d6aea040dc844d590bbd39eb38: Scheduling MajorDeltaCompactionOp(ef7c519e0bdc4364816a01ee052d29c4): perf score=1.000000
I20260812 06:16:24.232406 13807 maintenance_manager.cc:643] P a5d058d6aea040dc844d590bbd39eb38: MajorDeltaCompactionOp(ef7c519e0bdc4364816a01ee052d29c4) complete. Timing: real 0.144s	user 0.104s	sys 0.036s Metrics: {"cfile_cache_miss":533,"cfile_cache_miss_bytes":24651903,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":373,"lbm_read_time_us":9389,"lbm_reads_lt_1ms":573,"lbm_write_time_us":27456,"lbm_writes_lt_1ms":543,"mutex_wait_us":81,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":12928,"update_count":2500}
I20260812 06:16:24.233063 13916 maintenance_manager.cc:419] P a5d058d6aea040dc844d590bbd39eb38: Scheduling FlushDeltaMemStoresOp(ef7c519e0bdc4364816a01ee052d29c4): perf score=10.126437
I20260812 06:16:24.267952 13807 maintenance_manager.cc:643] P a5d058d6aea040dc844d590bbd39eb38: FlushDeltaMemStoresOp(ef7c519e0bdc4364816a01ee052d29c4) complete. Timing: real 0.035s	user 0.019s	sys 0.012s Metrics: {"bytes_written":12307491,"delete_count":0,"lbm_write_time_us":15073,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:16:24.268404 13916 maintenance_manager.cc:419] P a5d058d6aea040dc844d590bbd39eb38: Scheduling FlushDeltaMemStoresOp(ef7c519e0bdc4364816a01ee052d29c4): perf score=2.188937
I20260812 06:16:24.283619 13807 maintenance_manager.cc:643] P a5d058d6aea040dc844d590bbd39eb38: FlushDeltaMemStoresOp(ef7c519e0bdc4364816a01ee052d29c4) complete. Timing: real 0.015s	user 0.010s	sys 0.003s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5528,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:24.284112 13916 maintenance_manager.cc:419] P a5d058d6aea040dc844d590bbd39eb38: Scheduling MajorDeltaCompactionOp(ef7c519e0bdc4364816a01ee052d29c4): perf score=1.000000
I20260812 06:16:24.403246 13807 maintenance_manager.cc:643] P a5d058d6aea040dc844d590bbd39eb38: MajorDeltaCompactionOp(ef7c519e0bdc4364816a01ee052d29c4) complete. Timing: real 0.119s	user 0.111s	sys 0.008s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20549383,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":695,"lbm_read_time_us":7203,"lbm_reads_lt_1ms":472,"lbm_write_time_us":22320,"lbm_writes_lt_1ms":443,"mutex_wait_us":128,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":23808,"update_count":2000}
I20260812 06:16:24.403818 13916 maintenance_manager.cc:419] P a5d058d6aea040dc844d590bbd39eb38: Scheduling FlushDeltaMemStoresOp(ef7c519e0bdc4364816a01ee052d29c4): perf score=10.126437
I20260812 06:16:24.439890 13807 maintenance_manager.cc:643] P a5d058d6aea040dc844d590bbd39eb38: FlushDeltaMemStoresOp(ef7c519e0bdc4364816a01ee052d29c4) complete. Timing: real 0.036s	user 0.017s	sys 0.016s Metrics: {"bytes_written":12307491,"delete_count":0,"lbm_write_time_us":15962,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:16:24.440486 13916 maintenance_manager.cc:419] P a5d058d6aea040dc844d590bbd39eb38: Scheduling FlushDeltaMemStoresOp(ef7c519e0bdc4364816a01ee052d29c4): perf score=2.188937
I20260812 06:16:24.450600 13807 maintenance_manager.cc:643] P a5d058d6aea040dc844d590bbd39eb38: FlushDeltaMemStoresOp(ef7c519e0bdc4364816a01ee052d29c4) complete. Timing: real 0.010s	user 0.005s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3828,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:24.451010 13916 maintenance_manager.cc:419] P a5d058d6aea040dc844d590bbd39eb38: Scheduling MajorDeltaCompactionOp(ef7c519e0bdc4364816a01ee052d29c4): perf score=1.000000
I20260812 06:16:24.575963 13807 maintenance_manager.cc:643] P a5d058d6aea040dc844d590bbd39eb38: MajorDeltaCompactionOp(ef7c519e0bdc4364816a01ee052d29c4) complete. Timing: real 0.125s	user 0.105s	sys 0.020s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20549383,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":239,"lbm_read_time_us":9380,"lbm_reads_lt_1ms":472,"lbm_write_time_us":22901,"lbm_writes_lt_1ms":443,"mutex_wait_us":120,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":1408,"update_count":2000}
I20260812 06:16:24.576661 13916 maintenance_manager.cc:419] P a5d058d6aea040dc844d590bbd39eb38: Scheduling FlushDeltaMemStoresOp(ef7c519e0bdc4364816a01ee052d29c4): perf score=10.126437
I20260812 06:16:24.623526 13807 maintenance_manager.cc:643] P a5d058d6aea040dc844d590bbd39eb38: FlushDeltaMemStoresOp(ef7c519e0bdc4364816a01ee052d29c4) complete. Timing: real 0.047s	user 0.025s	sys 0.019s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":17165,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:16:24.624075 13916 maintenance_manager.cc:419] P a5d058d6aea040dc844d590bbd39eb38: Scheduling FlushDeltaMemStoresOp(ef7c519e0bdc4364816a01ee052d29c4): perf score=2.188937
I20260812 06:16:24.634549 13807 maintenance_manager.cc:643] P a5d058d6aea040dc844d590bbd39eb38: FlushDeltaMemStoresOp(ef7c519e0bdc4364816a01ee052d29c4) complete. Timing: real 0.010s	user 0.005s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4115,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:24.635031 13916 maintenance_manager.cc:419] P a5d058d6aea040dc844d590bbd39eb38: Scheduling FlushMRSOp(ef7c519e0bdc4364816a01ee052d29c4): perf score=1.000000
I20260812 06:16:24.673967 13807 maintenance_manager.cc:643] P a5d058d6aea040dc844d590bbd39eb38: FlushMRSOp(ef7c519e0bdc4364816a01ee052d29c4) complete. Timing: real 0.039s	user 0.032s	sys 0.001s Metrics: {"bytes_written":1193504,"cfile_init":1,"dirs.queue_time_us":79,"dirs.run_cpu_time_us":205,"dirs.run_wall_time_us":1469,"drs_written":1,"lbm_read_time_us":39,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1453,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":29}
I20260812 06:16:24.674855 13916 maintenance_manager.cc:419] P a5d058d6aea040dc844d590bbd39eb38: Scheduling LogGCOp(ef7c519e0bdc4364816a01ee052d29c4): free 112239327 bytes of WAL
I20260812 06:16:24.675089 13807 log_reader.cc:385] T ef7c519e0bdc4364816a01ee052d29c4: removed 11 log segments from log reader
I20260812 06:16:24.675133 13807 log.cc:1079] T ef7c519e0bdc4364816a01ee052d29c4 P a5d058d6aea040dc844d590bbd39eb38: Deleting log segment in path: /tmp/dist-test-taskNmQegX/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515382905434-13641-0/minicluster-data/ts-0-root/wals/ef7c519e0bdc4364816a01ee052d29c4/wal-000000002 (ops 7-11)
I20260812 06:16:24.675160 13807 log.cc:1079] T ef7c519e0bdc4364816a01ee052d29c4 P a5d058d6aea040dc844d590bbd39eb38: Deleting log segment in path: /tmp/dist-test-taskNmQegX/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515382905434-13641-0/minicluster-data/ts-0-root/wals/ef7c519e0bdc4364816a01ee052d29c4/wal-000000003 (ops 12-16)
I20260812 06:16:24.675215 13807 log.cc:1079] T ef7c519e0bdc4364816a01ee052d29c4 P a5d058d6aea040dc844d590bbd39eb38: Deleting log segment in path: /tmp/dist-test-taskNmQegX/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515382905434-13641-0/minicluster-data/ts-0-root/wals/ef7c519e0bdc4364816a01ee052d29c4/wal-000000004 (ops 17-20)
I20260812 06:16:24.675261 13807 log.cc:1079] T ef7c519e0bdc4364816a01ee052d29c4 P a5d058d6aea040dc844d590bbd39eb38: Deleting log segment in path: /tmp/dist-test-taskNmQegX/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515382905434-13641-0/minicluster-data/ts-0-root/wals/ef7c519e0bdc4364816a01ee052d29c4/wal-000000005 (ops 21-25)
I20260812 06:16:24.675297 13807 log.cc:1079] T ef7c519e0bdc4364816a01ee052d29c4 P a5d058d6aea040dc844d590bbd39eb38: Deleting log segment in path: /tmp/dist-test-taskNmQegX/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515382905434-13641-0/minicluster-data/ts-0-root/wals/ef7c519e0bdc4364816a01ee052d29c4/wal-000000006 (ops 26-30)
I20260812 06:16:24.675338 13807 log.cc:1079] T ef7c519e0bdc4364816a01ee052d29c4 P a5d058d6aea040dc844d590bbd39eb38: Deleting log segment in path: /tmp/dist-test-taskNmQegX/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515382905434-13641-0/minicluster-data/ts-0-root/wals/ef7c519e0bdc4364816a01ee052d29c4/wal-000000007 (ops 31-35)
I20260812 06:16:24.675385 13807 log.cc:1079] T ef7c519e0bdc4364816a01ee052d29c4 P a5d058d6aea040dc844d590bbd39eb38: Deleting log segment in path: /tmp/dist-test-taskNmQegX/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515382905434-13641-0/minicluster-data/ts-0-root/wals/ef7c519e0bdc4364816a01ee052d29c4/wal-000000008 (ops 36-40)
I20260812 06:16:24.675421 13807 log.cc:1079] T ef7c519e0bdc4364816a01ee052d29c4 P a5d058d6aea040dc844d590bbd39eb38: Deleting log segment in path: /tmp/dist-test-taskNmQegX/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515382905434-13641-0/minicluster-data/ts-0-root/wals/ef7c519e0bdc4364816a01ee052d29c4/wal-000000009 (ops 41-45)
I20260812 06:16:24.675463 13807 log.cc:1079] T ef7c519e0bdc4364816a01ee052d29c4 P a5d058d6aea040dc844d590bbd39eb38: Deleting log segment in path: /tmp/dist-test-taskNmQegX/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515382905434-13641-0/minicluster-data/ts-0-root/wals/ef7c519e0bdc4364816a01ee052d29c4/wal-000000010 (ops 46-50)
I20260812 06:16:24.675501 13807 log.cc:1079] T ef7c519e0bdc4364816a01ee052d29c4 P a5d058d6aea040dc844d590bbd39eb38: Deleting log segment in path: /tmp/dist-test-taskNmQegX/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515382905434-13641-0/minicluster-data/ts-0-root/wals/ef7c519e0bdc4364816a01ee052d29c4/wal-000000011 (ops 51-55)
I20260812 06:16:24.675542 13807 log.cc:1079] T ef7c519e0bdc4364816a01ee052d29c4 P a5d058d6aea040dc844d590bbd39eb38: Deleting log segment in path: /tmp/dist-test-taskNmQegX/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515382905434-13641-0/minicluster-data/ts-0-root/wals/ef7c519e0bdc4364816a01ee052d29c4/wal-000000012 (ops 56-60)
I20260812 06:16:24.699378 13807 maintenance_manager.cc:643] P a5d058d6aea040dc844d590bbd39eb38: LogGCOp(ef7c519e0bdc4364816a01ee052d29c4) complete. Timing: real 0.024s	user 0.000s	sys 0.022s Metrics: {}
I20260812 06:16:24.699759 13916 maintenance_manager.cc:419] P a5d058d6aea040dc844d590bbd39eb38: Scheduling FlushDeltaMemStoresOp(ef7c519e0bdc4364816a01ee052d29c4): perf score=3.181125
I20260812 06:16:24.715101 13807 maintenance_manager.cc:643] P a5d058d6aea040dc844d590bbd39eb38: FlushDeltaMemStoresOp(ef7c519e0bdc4364816a01ee052d29c4) complete. Timing: real 0.015s	user 0.004s	sys 0.005s Metrics: {"bytes_written":4512903,"delete_count":0,"lbm_write_time_us":4323,"lbm_writes_lt_1ms":113,"reinsert_count":0,"update_count":550}
I20260812 06:16:24.715513 13916 maintenance_manager.cc:419] P a5d058d6aea040dc844d590bbd39eb38: Scheduling UndoDeltaBlockGCOp(ef7c519e0bdc4364816a01ee052d29c4): 463 bytes on disk
I20260812 06:16:24.715909 13807 maintenance_manager.cc:643] P a5d058d6aea040dc844d590bbd39eb38: UndoDeltaBlockGCOp(ef7c519e0bdc4364816a01ee052d29c4) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":50,"lbm_reads_lt_1ms":4}
I20260812 06:16:24.716351 13916 maintenance_manager.cc:419] P a5d058d6aea040dc844d590bbd39eb38: Scheduling FlushDeltaMemStoresOp(ef7c519e0bdc4364816a01ee052d29c4): perf score=2.188937
I20260812 06:16:24.726212 13807 maintenance_manager.cc:643] P a5d058d6aea040dc844d590bbd39eb38: FlushDeltaMemStoresOp(ef7c519e0bdc4364816a01ee052d29c4) complete. Timing: real 0.010s	user 0.004s	sys 0.004s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3661,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:16:24.726648 13916 maintenance_manager.cc:419] P a5d058d6aea040dc844d590bbd39eb38: Scheduling MajorDeltaCompactionOp(ef7c519e0bdc4364816a01ee052d29c4): perf score=1.000000
I20260812 06:16:24.922261 13807 maintenance_manager.cc:643] P a5d058d6aea040dc844d590bbd39eb38: MajorDeltaCompactionOp(ef7c519e0bdc4364816a01ee052d29c4) complete. Timing: real 0.195s	user 0.129s	sys 0.066s Metrics: {"cfile_cache_miss":634,"cfile_cache_miss_bytes":28754434,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":574,"lbm_read_time_us":13139,"lbm_reads_lt_1ms":674,"lbm_write_time_us":32351,"lbm_writes_lt_1ms":643,"mutex_wait_us":111,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":20864,"thread_start_us":79,"threads_started":1,"update_count":3000}
I20260812 06:16:24.923460 13916 maintenance_manager.cc:419] P a5d058d6aea040dc844d590bbd39eb38: Scheduling FlushDeltaMemStoresOp(ef7c519e0bdc4364816a01ee052d29c4): perf score=14.095187
I20260812 06:16:24.973847 13807 maintenance_manager.cc:643] P a5d058d6aea040dc844d590bbd39eb38: FlushDeltaMemStoresOp(ef7c519e0bdc4364816a01ee052d29c4) complete. Timing: real 0.050s	user 0.030s	sys 0.015s Metrics: {"bytes_written":16409900,"delete_count":0,"lbm_write_time_us":20526,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:16:24.974315 13916 maintenance_manager.cc:419] P a5d058d6aea040dc844d590bbd39eb38: Scheduling MajorDeltaCompactionOp(ef7c519e0bdc4364816a01ee052d29c4): perf score=1.000000
I20260812 06:16:25.115690 13807 maintenance_manager.cc:643] P a5d058d6aea040dc844d590bbd39eb38: MajorDeltaCompactionOp(ef7c519e0bdc4364816a01ee052d29c4) complete. Timing: real 0.141s	user 0.096s	sys 0.045s Metrics: {"cfile_cache_miss":431,"cfile_cache_miss_bytes":20549261,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":1,"delta_iterators_relevant":1,"dirs.queue_time_us":343,"lbm_read_time_us":10905,"lbm_reads_lt_1ms":463,"lbm_write_time_us":22760,"lbm_writes_lt_1ms":443,"mutex_wait_us":60,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":768,"update_count":2000}
I20260812 06:16:25.116243 13916 maintenance_manager.cc:419] P a5d058d6aea040dc844d590bbd39eb38: Scheduling FlushDeltaMemStoresOp(ef7c519e0bdc4364816a01ee052d29c4): perf score=10.126437
I20260812 06:16:25.147766 13807 maintenance_manager.cc:643] P a5d058d6aea040dc844d590bbd39eb38: FlushDeltaMemStoresOp(ef7c519e0bdc4364816a01ee052d29c4) complete. Timing: real 0.031s	user 0.021s	sys 0.008s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":13524,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:16:25.148249 13916 maintenance_manager.cc:419] P a5d058d6aea040dc844d590bbd39eb38: Scheduling FlushDeltaMemStoresOp(ef7c519e0bdc4364816a01ee052d29c4): perf score=2.188937
I20260812 06:16:25.164146 13807 maintenance_manager.cc:643] P a5d058d6aea040dc844d590bbd39eb38: FlushDeltaMemStoresOp(ef7c519e0bdc4364816a01ee052d29c4) complete. Timing: real 0.016s	user 0.014s	sys 0.000s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":6022,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:25.164752 13916 maintenance_manager.cc:419] P a5d058d6aea040dc844d590bbd39eb38: Scheduling MajorDeltaCompactionOp(ef7c519e0bdc4364816a01ee052d29c4): perf score=1.000000
I20260812 06:16:25.290086 13807 maintenance_manager.cc:643] P a5d058d6aea040dc844d590bbd39eb38: MajorDeltaCompactionOp(ef7c519e0bdc4364816a01ee052d29c4) complete. Timing: real 0.125s	user 0.086s	sys 0.039s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20549381,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":338,"lbm_read_time_us":7914,"lbm_reads_lt_1ms":464,"lbm_write_time_us":26832,"lbm_writes_lt_1ms":443,"mutex_wait_us":24,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":2048,"update_count":2000}
I20260812 06:16:25.290695 13916 maintenance_manager.cc:419] P a5d058d6aea040dc844d590bbd39eb38: Scheduling FlushDeltaMemStoresOp(ef7c519e0bdc4364816a01ee052d29c4): perf score=10.126437
I20260812 06:16:25.333822 13807 maintenance_manager.cc:643] P a5d058d6aea040dc844d590bbd39eb38: FlushDeltaMemStoresOp(ef7c519e0bdc4364816a01ee052d29c4) complete. Timing: real 0.043s	user 0.016s	sys 0.020s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":16379,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:16:25.334338 13916 maintenance_manager.cc:419] P a5d058d6aea040dc844d590bbd39eb38: Scheduling FlushDeltaMemStoresOp(ef7c519e0bdc4364816a01ee052d29c4): perf score=2.188937
I20260812 06:16:25.350183 13807 maintenance_manager.cc:643] P a5d058d6aea040dc844d590bbd39eb38: FlushDeltaMemStoresOp(ef7c519e0bdc4364816a01ee052d29c4) complete. Timing: real 0.016s	user 0.013s	sys 0.002s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":6338,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:25.350819 13916 maintenance_manager.cc:419] P a5d058d6aea040dc844d590bbd39eb38: Scheduling MajorDeltaCompactionOp(ef7c519e0bdc4364816a01ee052d29c4): perf score=1.000000
I20260812 06:16:25.483736 13807 maintenance_manager.cc:643] P a5d058d6aea040dc844d590bbd39eb38: MajorDeltaCompactionOp(ef7c519e0bdc4364816a01ee052d29c4) complete. Timing: real 0.133s	user 0.102s	sys 0.029s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20549381,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":344,"lbm_read_time_us":7516,"lbm_reads_lt_1ms":472,"lbm_write_time_us":28952,"lbm_writes_lt_1ms":443,"mutex_wait_us":111,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":12672,"update_count":2000}
I20260812 06:16:25.484364 13916 maintenance_manager.cc:419] P a5d058d6aea040dc844d590bbd39eb38: Scheduling FlushDeltaMemStoresOp(ef7c519e0bdc4364816a01ee052d29c4): perf score=10.126437
I20260812 06:16:25.531471 13807 maintenance_manager.cc:643] P a5d058d6aea040dc844d590bbd39eb38: FlushDeltaMemStoresOp(ef7c519e0bdc4364816a01ee052d29c4) complete. Timing: real 0.047s	user 0.021s	sys 0.012s Metrics: {"bytes_written":12307489,"delete_count":0,"lbm_write_time_us":16161,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:16:25.531948 13916 maintenance_manager.cc:419] P a5d058d6aea040dc844d590bbd39eb38: Scheduling FlushDeltaMemStoresOp(ef7c519e0bdc4364816a01ee052d29c4): perf score=2.188937
I20260812 06:16:25.542631 13807 maintenance_manager.cc:643] P a5d058d6aea040dc844d590bbd39eb38: FlushDeltaMemStoresOp(ef7c519e0bdc4364816a01ee052d29c4) complete. Timing: real 0.010s	user 0.005s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4212,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:25.543344 13916 maintenance_manager.cc:419] P a5d058d6aea040dc844d590bbd39eb38: Scheduling MajorDeltaCompactionOp(ef7c519e0bdc4364816a01ee052d29c4): perf score=1.000000
I20260812 06:16:25.682621 13807 maintenance_manager.cc:643] P a5d058d6aea040dc844d590bbd39eb38: MajorDeltaCompactionOp(ef7c519e0bdc4364816a01ee052d29c4) complete. Timing: real 0.139s	user 0.111s	sys 0.027s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20549381,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":274,"lbm_read_time_us":9303,"lbm_reads_lt_1ms":472,"lbm_write_time_us":30801,"lbm_writes_lt_1ms":443,"mutex_wait_us":78,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":896,"update_count":2000}
I20260812 06:16:25.683241 13916 maintenance_manager.cc:419] P a5d058d6aea040dc844d590bbd39eb38: Scheduling FlushDeltaMemStoresOp(ef7c519e0bdc4364816a01ee052d29c4): perf score=10.126437
I20260812 06:16:25.739430 13807 maintenance_manager.cc:643] P a5d058d6aea040dc844d590bbd39eb38: FlushDeltaMemStoresOp(ef7c519e0bdc4364816a01ee052d29c4) complete. Timing: real 0.056s	user 0.030s	sys 0.019s Metrics: {"bytes_written":12307489,"delete_count":0,"lbm_write_time_us":19524,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:16:25.740026 13916 maintenance_manager.cc:419] P a5d058d6aea040dc844d590bbd39eb38: Scheduling FlushDeltaMemStoresOp(ef7c519e0bdc4364816a01ee052d29c4): perf score=2.188937
I20260812 06:16:25.750712 13807 maintenance_manager.cc:643] P a5d058d6aea040dc844d590bbd39eb38: FlushDeltaMemStoresOp(ef7c519e0bdc4364816a01ee052d29c4) complete. Timing: real 0.011s	user 0.001s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4272,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:25.751149 13916 maintenance_manager.cc:419] P a5d058d6aea040dc844d590bbd39eb38: Scheduling MajorDeltaCompactionOp(ef7c519e0bdc4364816a01ee052d29c4): perf score=1.000000
I20260812 06:16:25.900628 13807 maintenance_manager.cc:643] P a5d058d6aea040dc844d590bbd39eb38: MajorDeltaCompactionOp(ef7c519e0bdc4364816a01ee052d29c4) complete. Timing: real 0.149s	user 0.098s	sys 0.049s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20549381,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":342,"lbm_read_time_us":10535,"lbm_reads_lt_1ms":472,"lbm_write_time_us":25634,"lbm_writes_lt_1ms":443,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":1536,"update_count":2000}
I20260812 06:16:25.901396 13916 maintenance_manager.cc:419] P a5d058d6aea040dc844d590bbd39eb38: Scheduling FlushDeltaMemStoresOp(ef7c519e0bdc4364816a01ee052d29c4): perf score=10.126437
I20260812 06:16:25.945176 13807 maintenance_manager.cc:643] P a5d058d6aea040dc844d590bbd39eb38: FlushDeltaMemStoresOp(ef7c519e0bdc4364816a01ee052d29c4) complete. Timing: real 0.044s	user 0.028s	sys 0.004s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":16025,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:16:25.945747 13916 maintenance_manager.cc:419] P a5d058d6aea040dc844d590bbd39eb38: Scheduling FlushDeltaMemStoresOp(ef7c519e0bdc4364816a01ee052d29c4): perf score=2.188937
I20260812 06:16:25.956420 13807 maintenance_manager.cc:643] P a5d058d6aea040dc844d590bbd39eb38: FlushDeltaMemStoresOp(ef7c519e0bdc4364816a01ee052d29c4) complete. Timing: real 0.010s	user 0.004s	sys 0.005s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4155,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:25.957170 13916 maintenance_manager.cc:419] P a5d058d6aea040dc844d590bbd39eb38: Scheduling MajorDeltaCompactionOp(ef7c519e0bdc4364816a01ee052d29c4): perf score=1.000000
I20260812 06:16:26.091059 13807 maintenance_manager.cc:643] P a5d058d6aea040dc844d590bbd39eb38: MajorDeltaCompactionOp(ef7c519e0bdc4364816a01ee052d29c4) complete. Timing: real 0.134s	user 0.106s	sys 0.027s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20549381,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":1171,"lbm_read_time_us":10062,"lbm_reads_lt_1ms":472,"lbm_write_time_us":26641,"lbm_writes_lt_1ms":443,"mutex_wait_us":317,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":3968,"update_count":2000}
I20260812 06:16:26.091656 13916 maintenance_manager.cc:419] P a5d058d6aea040dc844d590bbd39eb38: Scheduling FlushDeltaMemStoresOp(ef7c519e0bdc4364816a01ee052d29c4): perf score=10.126437
I20260812 06:16:26.136482 13807 maintenance_manager.cc:643] P a5d058d6aea040dc844d590bbd39eb38: FlushDeltaMemStoresOp(ef7c519e0bdc4364816a01ee052d29c4) complete. Timing: real 0.045s	user 0.023s	sys 0.013s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":17770,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:16:26.136993 13916 maintenance_manager.cc:419] P a5d058d6aea040dc844d590bbd39eb38: Scheduling FlushDeltaMemStoresOp(ef7c519e0bdc4364816a01ee052d29c4): perf score=2.188937
I20260812 06:16:26.147688 13807 maintenance_manager.cc:643] P a5d058d6aea040dc844d590bbd39eb38: FlushDeltaMemStoresOp(ef7c519e0bdc4364816a01ee052d29c4) complete. Timing: real 0.011s	user 0.009s	sys 0.000s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4113,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:26.148475 13916 maintenance_manager.cc:419] P a5d058d6aea040dc844d590bbd39eb38: Scheduling FlushMRSOp(ef7c519e0bdc4364816a01ee052d29c4): perf score=1.000000
I20260812 06:16:26.176960 13807 maintenance_manager.cc:643] P a5d058d6aea040dc844d590bbd39eb38: FlushMRSOp(ef7c519e0bdc4364816a01ee052d29c4) complete. Timing: real 0.028s	user 0.026s	sys 0.000s Metrics: {"bytes_written":1234473,"cfile_init":1,"dirs.queue_time_us":54,"dirs.run_cpu_time_us":225,"dirs.run_wall_time_us":1427,"drs_written":1,"lbm_read_time_us":52,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1338,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":30}
I20260812 06:16:26.177754 13916 maintenance_manager.cc:419] P a5d058d6aea040dc844d590bbd39eb38: Scheduling LogGCOp(ef7c519e0bdc4364816a01ee052d29c4): free 124710298 bytes of WAL
I20260812 06:16:26.178027 13807 log_reader.cc:385] T ef7c519e0bdc4364816a01ee052d29c4: removed 12 log segments from log reader
I20260812 06:16:26.178090 13807 log.cc:1079] T ef7c519e0bdc4364816a01ee052d29c4 P a5d058d6aea040dc844d590bbd39eb38: Deleting log segment in path: /tmp/dist-test-taskNmQegX/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515382905434-13641-0/minicluster-data/ts-0-root/wals/ef7c519e0bdc4364816a01ee052d29c4/wal-000000013 (ops 61-65)
I20260812 06:16:26.178128 13807 log.cc:1079] T ef7c519e0bdc4364816a01ee052d29c4 P a5d058d6aea040dc844d590bbd39eb38: Deleting log segment in path: /tmp/dist-test-taskNmQegX/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515382905434-13641-0/minicluster-data/ts-0-root/wals/ef7c519e0bdc4364816a01ee052d29c4/wal-000000014 (ops 66-70)
I20260812 06:16:26.178153 13807 log.cc:1079] T ef7c519e0bdc4364816a01ee052d29c4 P a5d058d6aea040dc844d590bbd39eb38: Deleting log segment in path: /tmp/dist-test-taskNmQegX/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515382905434-13641-0/minicluster-data/ts-0-root/wals/ef7c519e0bdc4364816a01ee052d29c4/wal-000000015 (ops 71-75)
I20260812 06:16:26.178174 13807 log.cc:1079] T ef7c519e0bdc4364816a01ee052d29c4 P a5d058d6aea040dc844d590bbd39eb38: Deleting log segment in path: /tmp/dist-test-taskNmQegX/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515382905434-13641-0/minicluster-data/ts-0-root/wals/ef7c519e0bdc4364816a01ee052d29c4/wal-000000016 (ops 76-80)
I20260812 06:16:26.178198 13807 log.cc:1079] T ef7c519e0bdc4364816a01ee052d29c4 P a5d058d6aea040dc844d590bbd39eb38: Deleting log segment in path: /tmp/dist-test-taskNmQegX/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515382905434-13641-0/minicluster-data/ts-0-root/wals/ef7c519e0bdc4364816a01ee052d29c4/wal-000000017 (ops 81-85)
I20260812 06:16:26.178232 13807 log.cc:1079] T ef7c519e0bdc4364816a01ee052d29c4 P a5d058d6aea040dc844d590bbd39eb38: Deleting log segment in path: /tmp/dist-test-taskNmQegX/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515382905434-13641-0/minicluster-data/ts-0-root/wals/ef7c519e0bdc4364816a01ee052d29c4/wal-000000018 (ops 86-90)
I20260812 06:16:26.178259 13807 log.cc:1079] T ef7c519e0bdc4364816a01ee052d29c4 P a5d058d6aea040dc844d590bbd39eb38: Deleting log segment in path: /tmp/dist-test-taskNmQegX/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515382905434-13641-0/minicluster-data/ts-0-root/wals/ef7c519e0bdc4364816a01ee052d29c4/wal-000000019 (ops 91-95)
I20260812 06:16:26.178284 13807 log.cc:1079] T ef7c519e0bdc4364816a01ee052d29c4 P a5d058d6aea040dc844d590bbd39eb38: Deleting log segment in path: /tmp/dist-test-taskNmQegX/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515382905434-13641-0/minicluster-data/ts-0-root/wals/ef7c519e0bdc4364816a01ee052d29c4/wal-000000020 (ops 96-100)
I20260812 06:16:26.178313 13807 log.cc:1079] T ef7c519e0bdc4364816a01ee052d29c4 P a5d058d6aea040dc844d590bbd39eb38: Deleting log segment in path: /tmp/dist-test-taskNmQegX/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515382905434-13641-0/minicluster-data/ts-0-root/wals/ef7c519e0bdc4364816a01ee052d29c4/wal-000000021 (ops 101-105)
I20260812 06:16:26.178340 13807 log.cc:1079] T ef7c519e0bdc4364816a01ee052d29c4 P a5d058d6aea040dc844d590bbd39eb38: Deleting log segment in path: /tmp/dist-test-taskNmQegX/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515382905434-13641-0/minicluster-data/ts-0-root/wals/ef7c519e0bdc4364816a01ee052d29c4/wal-000000022 (ops 106-110)
I20260812 06:16:26.178372 13807 log.cc:1079] T ef7c519e0bdc4364816a01ee052d29c4 P a5d058d6aea040dc844d590bbd39eb38: Deleting log segment in path: /tmp/dist-test-taskNmQegX/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515382905434-13641-0/minicluster-data/ts-0-root/wals/ef7c519e0bdc4364816a01ee052d29c4/wal-000000023 (ops 111-115)
I20260812 06:16:26.178406 13807 log.cc:1079] T ef7c519e0bdc4364816a01ee052d29c4 P a5d058d6aea040dc844d590bbd39eb38: Deleting log segment in path: /tmp/dist-test-taskNmQegX/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515382905434-13641-0/minicluster-data/ts-0-root/wals/ef7c519e0bdc4364816a01ee052d29c4/wal-000000024 (ops 116-120)
I20260812 06:16:26.207782 13807 maintenance_manager.cc:643] P a5d058d6aea040dc844d590bbd39eb38: LogGCOp(ef7c519e0bdc4364816a01ee052d29c4) complete. Timing: real 0.030s	user 0.001s	sys 0.026s Metrics: {}
I20260812 06:16:26.208268 13916 maintenance_manager.cc:419] P a5d058d6aea040dc844d590bbd39eb38: Scheduling UndoDeltaBlockGCOp(ef7c519e0bdc4364816a01ee052d29c4): 472 bytes on disk
I20260812 06:16:26.208817 13807 maintenance_manager.cc:643] P a5d058d6aea040dc844d590bbd39eb38: UndoDeltaBlockGCOp(ef7c519e0bdc4364816a01ee052d29c4) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":81,"lbm_reads_lt_1ms":4}
I20260812 06:16:26.209452 13916 maintenance_manager.cc:419] P a5d058d6aea040dc844d590bbd39eb38: Scheduling FlushDeltaMemStoresOp(ef7c519e0bdc4364816a01ee052d29c4): perf score=2.188937
I20260812 06:16:26.231705 13807 maintenance_manager.cc:643] P a5d058d6aea040dc844d590bbd39eb38: FlushDeltaMemStoresOp(ef7c519e0bdc4364816a01ee052d29c4) complete. Timing: real 0.022s	user 0.006s	sys 0.005s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5329,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:26.232189 13916 maintenance_manager.cc:419] P a5d058d6aea040dc844d590bbd39eb38: Scheduling FlushDeltaMemStoresOp(ef7c519e0bdc4364816a01ee052d29c4): perf score=2.188937
I20260812 06:16:26.242756 13807 maintenance_manager.cc:643] P a5d058d6aea040dc844d590bbd39eb38: FlushDeltaMemStoresOp(ef7c519e0bdc4364816a01ee052d29c4) complete. Timing: real 0.010s	user 0.009s	sys 0.000s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4055,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:26.243234 13916 maintenance_manager.cc:419] P a5d058d6aea040dc844d590bbd39eb38: Scheduling MajorDeltaCompactionOp(ef7c519e0bdc4364816a01ee052d29c4): perf score=1.000000
I20260812 06:16:26.417519 13807 maintenance_manager.cc:643] P a5d058d6aea040dc844d590bbd39eb38: MajorDeltaCompactionOp(ef7c519e0bdc4364816a01ee052d29c4) complete. Timing: real 0.174s	user 0.130s	sys 0.032s Metrics: {"cfile_cache_miss":634,"cfile_cache_miss_bytes":28754442,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":699,"lbm_read_time_us":10777,"lbm_reads_lt_1ms":674,"lbm_write_time_us":36243,"lbm_writes_lt_1ms":643,"mutex_wait_us":90,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":33664,"thread_start_us":88,"threads_started":1,"update_count":3000}
I20260812 06:16:26.418195 13916 maintenance_manager.cc:419] P a5d058d6aea040dc844d590bbd39eb38: Scheduling FlushDeltaMemStoresOp(ef7c519e0bdc4364816a01ee052d29c4): perf score=14.095187
I20260812 06:16:26.469329 13807 maintenance_manager.cc:643] P a5d058d6aea040dc844d590bbd39eb38: FlushDeltaMemStoresOp(ef7c519e0bdc4364816a01ee052d29c4) complete. Timing: real 0.051s	user 0.037s	sys 0.013s Metrics: {"bytes_written":16409898,"delete_count":0,"lbm_write_time_us":22030,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:16:26.469767 13916 maintenance_manager.cc:419] P a5d058d6aea040dc844d590bbd39eb38: Scheduling FlushDeltaMemStoresOp(ef7c519e0bdc4364816a01ee052d29c4): perf score=2.188937
I20260812 06:16:26.481027 13807 maintenance_manager.cc:643] P a5d058d6aea040dc844d590bbd39eb38: FlushDeltaMemStoresOp(ef7c519e0bdc4364816a01ee052d29c4) complete. Timing: real 0.011s	user 0.005s	sys 0.004s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4262,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:26.481539 13916 maintenance_manager.cc:419] P a5d058d6aea040dc844d590bbd39eb38: Scheduling MajorDeltaCompactionOp(ef7c519e0bdc4364816a01ee052d29c4): perf score=1.000000
I20260812 06:16:26.636621 13807 maintenance_manager.cc:643] P a5d058d6aea040dc844d590bbd39eb38: MajorDeltaCompactionOp(ef7c519e0bdc4364816a01ee052d29c4) complete. Timing: real 0.155s	user 0.111s	sys 0.033s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24651789,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":942,"lbm_read_time_us":10259,"lbm_reads_lt_1ms":572,"lbm_write_time_us":30231,"lbm_writes_lt_1ms":543,"mutex_wait_us":380,"peak_mem_usage":63115900,"reinsert_count":0,"update_count":2500}
I20260812 06:16:26.637171 13916 maintenance_manager.cc:419] P a5d058d6aea040dc844d590bbd39eb38: Scheduling FlushDeltaMemStoresOp(ef7c519e0bdc4364816a01ee052d29c4): perf score=14.095187
I20260812 06:16:26.697711 13807 maintenance_manager.cc:643] P a5d058d6aea040dc844d590bbd39eb38: FlushDeltaMemStoresOp(ef7c519e0bdc4364816a01ee052d29c4) complete. Timing: real 0.060s	user 0.033s	sys 0.017s Metrics: {"bytes_written":16409900,"delete_count":0,"lbm_write_time_us":22880,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:16:26.698220 13916 maintenance_manager.cc:419] P a5d058d6aea040dc844d590bbd39eb38: Scheduling FlushDeltaMemStoresOp(ef7c519e0bdc4364816a01ee052d29c4): perf score=2.188937
I20260812 06:16:26.710642 13807 maintenance_manager.cc:643] P a5d058d6aea040dc844d590bbd39eb38: FlushDeltaMemStoresOp(ef7c519e0bdc4364816a01ee052d29c4) complete. Timing: real 0.012s	user 0.001s	sys 0.010s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4390,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:26.711192 13916 maintenance_manager.cc:419] P a5d058d6aea040dc844d590bbd39eb38: Scheduling MajorDeltaCompactionOp(ef7c519e0bdc4364816a01ee052d29c4): perf score=1.000000
I20260812 06:16:26.888916 13807 maintenance_manager.cc:643] P a5d058d6aea040dc844d590bbd39eb38: MajorDeltaCompactionOp(ef7c519e0bdc4364816a01ee052d29c4) complete. Timing: real 0.178s	user 0.109s	sys 0.060s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24651792,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":4613,"dirs.run_cpu_time_us":745,"dirs.run_wall_time_us":4578,"lbm_read_time_us":10240,"lbm_reads_lt_1ms":572,"lbm_write_time_us":31136,"lbm_writes_lt_1ms":543,"mutex_wait_us":3833,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":2816,"update_count":2500}
I20260812 06:16:26.889762 13916 maintenance_manager.cc:419] P a5d058d6aea040dc844d590bbd39eb38: Scheduling FlushDeltaMemStoresOp(ef7c519e0bdc4364816a01ee052d29c4): perf score=14.095187
I20260812 06:16:26.950295 13807 maintenance_manager.cc:643] P a5d058d6aea040dc844d590bbd39eb38: FlushDeltaMemStoresOp(ef7c519e0bdc4364816a01ee052d29c4) complete. Timing: real 0.060s	user 0.024s	sys 0.024s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":21405,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:16:26.950764 13916 maintenance_manager.cc:419] P a5d058d6aea040dc844d590bbd39eb38: Scheduling FlushDeltaMemStoresOp(ef7c519e0bdc4364816a01ee052d29c4): perf score=2.188937
I20260812 06:16:26.962069 13807 maintenance_manager.cc:643] P a5d058d6aea040dc844d590bbd39eb38: FlushDeltaMemStoresOp(ef7c519e0bdc4364816a01ee052d29c4) complete. Timing: real 0.011s	user 0.002s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4072,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:26.962527 13916 maintenance_manager.cc:419] P a5d058d6aea040dc844d590bbd39eb38: Scheduling MajorDeltaCompactionOp(ef7c519e0bdc4364816a01ee052d29c4): perf score=1.000000
I20260812 06:16:27.143944 13807 maintenance_manager.cc:643] P a5d058d6aea040dc844d590bbd39eb38: MajorDeltaCompactionOp(ef7c519e0bdc4364816a01ee052d29c4) complete. Timing: real 0.181s	user 0.147s	sys 0.028s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24651793,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":597,"lbm_read_time_us":12833,"lbm_reads_lt_1ms":572,"lbm_write_time_us":33095,"lbm_writes_lt_1ms":543,"mutex_wait_us":26,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":9600,"update_count":2500}
I20260812 06:16:27.144542 13916 maintenance_manager.cc:419] P a5d058d6aea040dc844d590bbd39eb38: Scheduling FlushDeltaMemStoresOp(ef7c519e0bdc4364816a01ee052d29c4): perf score=14.095187
I20260812 06:16:27.199643 13807 maintenance_manager.cc:643] P a5d058d6aea040dc844d590bbd39eb38: FlushDeltaMemStoresOp(ef7c519e0bdc4364816a01ee052d29c4) complete. Timing: real 0.055s	user 0.032s	sys 0.019s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":25334,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:16:27.200150 13916 maintenance_manager.cc:419] P a5d058d6aea040dc844d590bbd39eb38: Scheduling FlushDeltaMemStoresOp(ef7c519e0bdc4364816a01ee052d29c4): perf score=2.188937
I20260812 06:16:27.210593 13807 maintenance_manager.cc:643] P a5d058d6aea040dc844d590bbd39eb38: FlushDeltaMemStoresOp(ef7c519e0bdc4364816a01ee052d29c4) complete. Timing: real 0.010s	user 0.009s	sys 0.000s 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:27.211184 13916 maintenance_manager.cc:419] P a5d058d6aea040dc844d590bbd39eb38: Scheduling MajorDeltaCompactionOp(ef7c519e0bdc4364816a01ee052d29c4): perf score=1.000000
I20260812 06:16:27.382510 13807 maintenance_manager.cc:643] P a5d058d6aea040dc844d590bbd39eb38: MajorDeltaCompactionOp(ef7c519e0bdc4364816a01ee052d29c4) complete. Timing: real 0.171s	user 0.096s	sys 0.068s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24651792,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":166,"lbm_read_time_us":11974,"lbm_reads_lt_1ms":572,"lbm_write_time_us":31247,"lbm_writes_lt_1ms":543,"mutex_wait_us":21,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":9344,"update_count":2500}
I20260812 06:16:27.383301 13916 maintenance_manager.cc:419] P a5d058d6aea040dc844d590bbd39eb38: Scheduling FlushDeltaMemStoresOp(ef7c519e0bdc4364816a01ee052d29c4): perf score=14.095187
I20260812 06:16:27.441906 13807 maintenance_manager.cc:643] P a5d058d6aea040dc844d590bbd39eb38: FlushDeltaMemStoresOp(ef7c519e0bdc4364816a01ee052d29c4) complete. Timing: real 0.058s	user 0.027s	sys 0.031s Metrics: {"bytes_written":16409905,"delete_count":0,"lbm_write_time_us":25793,"lbm_writes_1-10_ms":3,"lbm_writes_lt_1ms":400,"reinsert_count":0,"update_count":2000}
I20260812 06:16:27.442457 13916 maintenance_manager.cc:419] P a5d058d6aea040dc844d590bbd39eb38: Scheduling FlushDeltaMemStoresOp(ef7c519e0bdc4364816a01ee052d29c4): perf score=2.188937
I20260812 06:16:27.453112 13807 maintenance_manager.cc:643] P a5d058d6aea040dc844d590bbd39eb38: FlushDeltaMemStoresOp(ef7c519e0bdc4364816a01ee052d29c4) complete. Timing: real 0.010s	user 0.009s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4117,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:27.453599 13916 maintenance_manager.cc:419] P a5d058d6aea040dc844d590bbd39eb38: Scheduling MajorDeltaCompactionOp(ef7c519e0bdc4364816a01ee052d29c4): perf score=1.000000
I20260812 06:16:27.621834 13807 maintenance_manager.cc:643] P a5d058d6aea040dc844d590bbd39eb38: MajorDeltaCompactionOp(ef7c519e0bdc4364816a01ee052d29c4) complete. Timing: real 0.168s	user 0.118s	sys 0.047s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24651797,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":193,"lbm_read_time_us":12111,"lbm_reads_lt_1ms":572,"lbm_write_time_us":31485,"lbm_writes_lt_1ms":543,"mutex_wait_us":46,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":4224,"update_count":2500}
I20260812 06:16:27.622530 13916 maintenance_manager.cc:419] P a5d058d6aea040dc844d590bbd39eb38: Scheduling FlushDeltaMemStoresOp(ef7c519e0bdc4364816a01ee052d29c4): perf score=11.118625
I20260812 06:16:27.660701 13807 maintenance_manager.cc:643] P a5d058d6aea040dc844d590bbd39eb38: FlushDeltaMemStoresOp(ef7c519e0bdc4364816a01ee052d29c4) complete. Timing: real 0.038s	user 0.026s	sys 0.008s Metrics: {"bytes_written":12717737,"delete_count":0,"lbm_write_time_us":17233,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:16:27.661381 13916 maintenance_manager.cc:419] P a5d058d6aea040dc844d590bbd39eb38: Scheduling FlushDeltaMemStoresOp(ef7c519e0bdc4364816a01ee052d29c4): perf score=2.188937
I20260812 06:16:27.677006 13807 maintenance_manager.cc:643] P a5d058d6aea040dc844d590bbd39eb38: FlushDeltaMemStoresOp(ef7c519e0bdc4364816a01ee052d29c4) complete. Timing: real 0.015s	user 0.001s	sys 0.012s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":6139,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:16:27.677596 13916 maintenance_manager.cc:419] P a5d058d6aea040dc844d590bbd39eb38: Scheduling FlushMRSOp(ef7c519e0bdc4364816a01ee052d29c4): perf score=1.000000
I20260812 06:16:27.709802 13807 maintenance_manager.cc:643] P a5d058d6aea040dc844d590bbd39eb38: FlushMRSOp(ef7c519e0bdc4364816a01ee052d29c4) complete. Timing: real 0.032s	user 0.030s	sys 0.002s Metrics: {"bytes_written":1275445,"cfile_init":1,"dirs.queue_time_us":68,"dirs.run_cpu_time_us":264,"dirs.run_wall_time_us":1451,"drs_written":1,"lbm_read_time_us":87,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1649,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":31}
I20260812 06:16:27.710477 13916 maintenance_manager.cc:419] P a5d058d6aea040dc844d590bbd39eb38: Scheduling LogGCOp(ef7c519e0bdc4364816a01ee052d29c4): free 129773801 bytes of WAL
I20260812 06:16:27.710706 13807 log_reader.cc:385] T ef7c519e0bdc4364816a01ee052d29c4: removed 13 log segments from log reader
I20260812 06:16:27.710749 13807 log.cc:1079] T ef7c519e0bdc4364816a01ee052d29c4 P a5d058d6aea040dc844d590bbd39eb38: Deleting log segment in path: /tmp/dist-test-taskNmQegX/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515382905434-13641-0/minicluster-data/ts-0-root/wals/ef7c519e0bdc4364816a01ee052d29c4/wal-000000025 (ops 121-125)
I20260812 06:16:27.710777 13807 log.cc:1079] T ef7c519e0bdc4364816a01ee052d29c4 P a5d058d6aea040dc844d590bbd39eb38: Deleting log segment in path: /tmp/dist-test-taskNmQegX/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515382905434-13641-0/minicluster-data/ts-0-root/wals/ef7c519e0bdc4364816a01ee052d29c4/wal-000000026 (ops 126-130)
I20260812 06:16:27.710817 13807 log.cc:1079] T ef7c519e0bdc4364816a01ee052d29c4 P a5d058d6aea040dc844d590bbd39eb38: Deleting log segment in path: /tmp/dist-test-taskNmQegX/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515382905434-13641-0/minicluster-data/ts-0-root/wals/ef7c519e0bdc4364816a01ee052d29c4/wal-000000027 (ops 131-135)
I20260812 06:16:27.710860 13807 log.cc:1079] T ef7c519e0bdc4364816a01ee052d29c4 P a5d058d6aea040dc844d590bbd39eb38: Deleting log segment in path: /tmp/dist-test-taskNmQegX/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515382905434-13641-0/minicluster-data/ts-0-root/wals/ef7c519e0bdc4364816a01ee052d29c4/wal-000000028 (ops 136-140)
I20260812 06:16:27.710908 13807 log.cc:1079] T ef7c519e0bdc4364816a01ee052d29c4 P a5d058d6aea040dc844d590bbd39eb38: Deleting log segment in path: /tmp/dist-test-taskNmQegX/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515382905434-13641-0/minicluster-data/ts-0-root/wals/ef7c519e0bdc4364816a01ee052d29c4/wal-000000029 (ops 141-145)
I20260812 06:16:27.710958 13807 log.cc:1079] T ef7c519e0bdc4364816a01ee052d29c4 P a5d058d6aea040dc844d590bbd39eb38: Deleting log segment in path: /tmp/dist-test-taskNmQegX/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515382905434-13641-0/minicluster-data/ts-0-root/wals/ef7c519e0bdc4364816a01ee052d29c4/wal-000000030 (ops 146-150)
I20260812 06:16:27.710986 13807 log.cc:1079] T ef7c519e0bdc4364816a01ee052d29c4 P a5d058d6aea040dc844d590bbd39eb38: Deleting log segment in path: /tmp/dist-test-taskNmQegX/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515382905434-13641-0/minicluster-data/ts-0-root/wals/ef7c519e0bdc4364816a01ee052d29c4/wal-000000031 (ops 151-154)
I20260812 06:16:27.711045 13807 log.cc:1079] T ef7c519e0bdc4364816a01ee052d29c4 P a5d058d6aea040dc844d590bbd39eb38: Deleting log segment in path: /tmp/dist-test-taskNmQegX/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515382905434-13641-0/minicluster-data/ts-0-root/wals/ef7c519e0bdc4364816a01ee052d29c4/wal-000000032 (ops 155-159)
I20260812 06:16:27.711086 13807 log.cc:1079] T ef7c519e0bdc4364816a01ee052d29c4 P a5d058d6aea040dc844d590bbd39eb38: Deleting log segment in path: /tmp/dist-test-taskNmQegX/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515382905434-13641-0/minicluster-data/ts-0-root/wals/ef7c519e0bdc4364816a01ee052d29c4/wal-000000033 (ops 160-164)
I20260812 06:16:27.711122 13807 log.cc:1079] T ef7c519e0bdc4364816a01ee052d29c4 P a5d058d6aea040dc844d590bbd39eb38: Deleting log segment in path: /tmp/dist-test-taskNmQegX/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515382905434-13641-0/minicluster-data/ts-0-root/wals/ef7c519e0bdc4364816a01ee052d29c4/wal-000000034 (ops 165-169)
I20260812 06:16:27.711160 13807 log.cc:1079] T ef7c519e0bdc4364816a01ee052d29c4 P a5d058d6aea040dc844d590bbd39eb38: Deleting log segment in path: /tmp/dist-test-taskNmQegX/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515382905434-13641-0/minicluster-data/ts-0-root/wals/ef7c519e0bdc4364816a01ee052d29c4/wal-000000035 (ops 170-174)
I20260812 06:16:27.711200 13807 log.cc:1079] T ef7c519e0bdc4364816a01ee052d29c4 P a5d058d6aea040dc844d590bbd39eb38: Deleting log segment in path: /tmp/dist-test-taskNmQegX/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515382905434-13641-0/minicluster-data/ts-0-root/wals/ef7c519e0bdc4364816a01ee052d29c4/wal-000000036 (ops 175-179)
I20260812 06:16:27.711238 13807 log.cc:1079] T ef7c519e0bdc4364816a01ee052d29c4 P a5d058d6aea040dc844d590bbd39eb38: Deleting log segment in path: /tmp/dist-test-taskNmQegX/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515382905434-13641-0/minicluster-data/ts-0-root/wals/ef7c519e0bdc4364816a01ee052d29c4/wal-000000037 (ops 180-184)
I20260812 06:16:27.738449 13807 maintenance_manager.cc:643] P a5d058d6aea040dc844d590bbd39eb38: LogGCOp(ef7c519e0bdc4364816a01ee052d29c4) complete. Timing: real 0.028s	user 0.000s	sys 0.027s Metrics: {}
I20260812 06:16:27.738863 13916 maintenance_manager.cc:419] P a5d058d6aea040dc844d590bbd39eb38: Scheduling UndoDeltaBlockGCOp(ef7c519e0bdc4364816a01ee052d29c4): 483 bytes on disk
I20260812 06:16:27.739289 13807 maintenance_manager.cc:643] P a5d058d6aea040dc844d590bbd39eb38: UndoDeltaBlockGCOp(ef7c519e0bdc4364816a01ee052d29c4) 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:27.739820 13916 maintenance_manager.cc:419] P a5d058d6aea040dc844d590bbd39eb38: Scheduling FlushDeltaMemStoresOp(ef7c519e0bdc4364816a01ee052d29c4): perf score=3.181125
I20260812 06:16:27.753630 13807 maintenance_manager.cc:643] P a5d058d6aea040dc844d590bbd39eb38: FlushDeltaMemStoresOp(ef7c519e0bdc4364816a01ee052d29c4) complete. Timing: real 0.014s	user 0.011s	sys 0.000s Metrics: {"bytes_written":4512902,"delete_count":0,"lbm_write_time_us":4279,"lbm_writes_lt_1ms":113,"reinsert_count":0,"update_count":550}
I20260812 06:16:27.754063 13916 maintenance_manager.cc:419] P a5d058d6aea040dc844d590bbd39eb38: Scheduling FlushDeltaMemStoresOp(ef7c519e0bdc4364816a01ee052d29c4): perf score=2.188937
I20260812 06:16:27.763880 13807 maintenance_manager.cc:643] P a5d058d6aea040dc844d590bbd39eb38: FlushDeltaMemStoresOp(ef7c519e0bdc4364816a01ee052d29c4) complete. Timing: real 0.010s	user 0.005s	sys 0.003s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3821,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:16:27.764359 13916 maintenance_manager.cc:419] P a5d058d6aea040dc844d590bbd39eb38: Scheduling MajorDeltaCompactionOp(ef7c519e0bdc4364816a01ee052d29c4): perf score=1.000000
I20260812 06:16:27.946308 13807 maintenance_manager.cc:643] P a5d058d6aea040dc844d590bbd39eb38: MajorDeltaCompactionOp(ef7c519e0bdc4364816a01ee052d29c4) complete. Timing: real 0.182s	user 0.110s	sys 0.071s Metrics: {"cfile_cache_miss":634,"cfile_cache_miss_bytes":28754426,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":450,"lbm_read_time_us":12386,"lbm_reads_lt_1ms":674,"lbm_write_time_us":31686,"lbm_writes_lt_1ms":643,"peak_mem_usage":75542472,"reinsert_count":0,"thread_start_us":95,"threads_started":1,"update_count":3000}
I20260812 06:16:27.947960 13916 maintenance_manager.cc:419] P a5d058d6aea040dc844d590bbd39eb38: Scheduling FlushDeltaMemStoresOp(ef7c519e0bdc4364816a01ee052d29c4): perf score=14.095187
I20260812 06:16:28.010643 13807 maintenance_manager.cc:643] P a5d058d6aea040dc844d590bbd39eb38: FlushDeltaMemStoresOp(ef7c519e0bdc4364816a01ee052d29c4) complete. Timing: real 0.062s	user 0.033s	sys 0.027s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":29125,"lbm_writes_1-10_ms":3,"lbm_writes_lt_1ms":400,"reinsert_count":0,"update_count":2000}
I20260812 06:16:28.011129 13916 maintenance_manager.cc:419] P a5d058d6aea040dc844d590bbd39eb38: Scheduling FlushDeltaMemStoresOp(ef7c519e0bdc4364816a01ee052d29c4): perf score=2.188937
I20260812 06:16:28.025607 13807 maintenance_manager.cc:643] P a5d058d6aea040dc844d590bbd39eb38: FlushDeltaMemStoresOp(ef7c519e0bdc4364816a01ee052d29c4) complete. Timing: real 0.014s	user 0.006s	sys 0.008s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":5301,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:28.026109 13916 maintenance_manager.cc:419] P a5d058d6aea040dc844d590bbd39eb38: Scheduling MajorDeltaCompactionOp(ef7c519e0bdc4364816a01ee052d29c4): perf score=1.000000
I20260812 06:16:28.099323 13641 heavy-update-compaction-itest.cc:229] Time spent updating: real 4.878s	user 1.804s	sys 0.165s
I20260812 06:16:28.162089 13641 heavy-update-compaction-itest.cc:265] Time spent scanning: real 0.062s	user 0.004s	sys 0.000s
I20260812 06:16:28.162822 13641 tablet_server.cc:179] TabletServer@127.13.82.65:0 shutting down...
I20260812 06:16:28.176530 13807 maintenance_manager.cc:643] P a5d058d6aea040dc844d590bbd39eb38: MajorDeltaCompactionOp(ef7c519e0bdc4364816a01ee052d29c4) complete. Timing: real 0.150s	user 0.102s	sys 0.045s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24651792,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":4098,"dirs.run_cpu_time_us":1989,"dirs.run_wall_time_us":12200,"lbm_read_time_us":10435,"lbm_reads_lt_1ms":564,"lbm_write_time_us":25628,"lbm_writes_lt_1ms":543,"mutex_wait_us":3304,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":896,"update_count":2500}
I20260812 06:16:28.177903 13641 ts_tablet_manager.cc:1507] Shutting down tablet manager...
I20260812 06:16:28.178337 13641 tablet_replica.cc:333] T ef7c519e0bdc4364816a01ee052d29c4 P a5d058d6aea040dc844d590bbd39eb38: stopping tablet replica
I20260812 06:16:28.178527 13641 raft_consensus.cc:2243] T ef7c519e0bdc4364816a01ee052d29c4 P a5d058d6aea040dc844d590bbd39eb38 [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:16:28.178710 13641 raft_consensus.cc:2272] T ef7c519e0bdc4364816a01ee052d29c4 P a5d058d6aea040dc844d590bbd39eb38 [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:16:28.184484 13641 tablet_server.cc:196] TabletServer@127.13.82.65:0 shutdown complete.
I20260812 06:16:28.220286 13641 master.cc:562] Master@127.13.82.126:46585 shutting down...
I20260812 06:16:28.223650 13641 raft_consensus.cc:2243] T 00000000000000000000000000000000 P 96d419d118a547599e0a0b235bd6f415 [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:16:28.223811 13641 raft_consensus.cc:2272] T 00000000000000000000000000000000 P 96d419d118a547599e0a0b235bd6f415 [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:16:28.223862 13641 tablet_replica.cc:333] T 00000000000000000000000000000000 P 96d419d118a547599e0a0b235bd6f415: stopping tablet replica
I20260812 06:16:28.236155 13641 master.cc:584] Master@127.13.82.126:46585 shutdown complete.
[       OK ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/0 (5406 ms)
[ RUN      ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/1
I20260812 06:16:28.333827 13641 internal_mini_cluster.cc:156] Creating distributed mini masters. Addrs: 127.13.82.126:42181
I20260812 06:16:28.334182 13641 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:16:28.336159 13961 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:28.336320 13965 instance_detector.cc:116] could not retrieve OpenStack instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:16:28.336369 13962 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:28.336501 13641 server_base.cc:1061] running on GCE node
I20260812 06:16:28.336774 13641 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:16:28.336822 13641 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:28.336838 13641 hybrid_clock.cc:648] HybridClock initialized: now 1786515388336838 us; error 0 us; skew 500 ppm
I20260812 06:16:28.337764 13641 webserver.cc:533] Webserver started at http://127.13.82.126:45639/ using document root <none> and password file <none>
I20260812 06:16:28.337942 13641 fs_manager.cc:362] Metadata directory not provided
I20260812 06:16:28.338011 13641 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:16:28.338105 13641 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:16:28.338544 13641 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskNmQegX/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515382905434-13641-0/minicluster-data/master-0-root/instance:
uuid: "2381d032a2c9416ba9941fe21efee686"
format_stamp: "Formatted at 2026-08-12 06:16:28 on dist-test-slave-8hhm"
I20260812 06:16:28.340060 13641 fs_manager.cc:696] Time spent creating directory manager: real 0.001s	user 0.002s	sys 0.000s
I20260812 06:16:28.340946 13974 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:28.341192 13641 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.001s	sys 0.000s
I20260812 06:16:28.341348 13641 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskNmQegX/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515382905434-13641-0/minicluster-data/master-0-root
uuid: "2381d032a2c9416ba9941fe21efee686"
format_stamp: "Formatted at 2026-08-12 06:16:28 on dist-test-slave-8hhm"
I20260812 06:16:28.341434 13641 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskNmQegX/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515382905434-13641-0/minicluster-data/master-0-root
metadata directory: /tmp/dist-test-taskNmQegX/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515382905434-13641-0/minicluster-data/master-0-root
1 data directories: /tmp/dist-test-taskNmQegX/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515382905434-13641-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:28.365031 13641 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:16:28.365581 13641 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:16:28.370627 13641 rpc_server.cc:307] RPC server started. Bound to: 127.13.82.126:42181
I20260812 06:16:28.375511 14055 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:28.375506 14053 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.13.82.126:42181 every 8 connection(s)
I20260812 06:16:28.377398 14055 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P 2381d032a2c9416ba9941fe21efee686: Bootstrap starting.
I20260812 06:16:28.378141 14055 tablet_bootstrap.cc:654] T 00000000000000000000000000000000 P 2381d032a2c9416ba9941fe21efee686: Neither blocks nor log segments found. Creating new log.
I20260812 06:16:28.379143 14055 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P 2381d032a2c9416ba9941fe21efee686: No bootstrap required, opened a new log
I20260812 06:16:28.379494 14055 raft_consensus.cc:359] T 00000000000000000000000000000000 P 2381d032a2c9416ba9941fe21efee686 [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "2381d032a2c9416ba9941fe21efee686" member_type: VOTER }
I20260812 06:16:28.379580 14055 raft_consensus.cc:385] T 00000000000000000000000000000000 P 2381d032a2c9416ba9941fe21efee686 [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:16:28.379602 14055 raft_consensus.cc:740] T 00000000000000000000000000000000 P 2381d032a2c9416ba9941fe21efee686 [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: 2381d032a2c9416ba9941fe21efee686, State: Initialized, Role: FOLLOWER
I20260812 06:16:28.379703 14055 consensus_queue.cc:260] T 00000000000000000000000000000000 P 2381d032a2c9416ba9941fe21efee686 [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: "2381d032a2c9416ba9941fe21efee686" member_type: VOTER }
I20260812 06:16:28.379758 14055 raft_consensus.cc:399] T 00000000000000000000000000000000 P 2381d032a2c9416ba9941fe21efee686 [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:16:28.379781 14055 raft_consensus.cc:493] T 00000000000000000000000000000000 P 2381d032a2c9416ba9941fe21efee686 [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:16:28.379817 14055 raft_consensus.cc:3060] T 00000000000000000000000000000000 P 2381d032a2c9416ba9941fe21efee686 [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:16:28.380437 14055 raft_consensus.cc:515] T 00000000000000000000000000000000 P 2381d032a2c9416ba9941fe21efee686 [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "2381d032a2c9416ba9941fe21efee686" member_type: VOTER }
I20260812 06:16:28.380558 14055 leader_election.cc:304] T 00000000000000000000000000000000 P 2381d032a2c9416ba9941fe21efee686 [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: 2381d032a2c9416ba9941fe21efee686; no voters: 
I20260812 06:16:28.380728 14055 leader_election.cc:290] T 00000000000000000000000000000000 P 2381d032a2c9416ba9941fe21efee686 [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:16:28.380905 14058 raft_consensus.cc:2804] T 00000000000000000000000000000000 P 2381d032a2c9416ba9941fe21efee686 [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:16:28.381096 14058 raft_consensus.cc:697] T 00000000000000000000000000000000 P 2381d032a2c9416ba9941fe21efee686 [term 1 LEADER]: Becoming Leader. State: Replica: 2381d032a2c9416ba9941fe21efee686, State: Running, Role: LEADER
I20260812 06:16:28.381253 14055 sys_catalog.cc:565] T 00000000000000000000000000000000 P 2381d032a2c9416ba9941fe21efee686 [sys.catalog]: configured and running, proceeding with master startup.
I20260812 06:16:28.381290 14058 consensus_queue.cc:237] T 00000000000000000000000000000000 P 2381d032a2c9416ba9941fe21efee686 [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: "2381d032a2c9416ba9941fe21efee686" member_type: VOTER }
I20260812 06:16:28.381776 14059 sys_catalog.cc:455] T 00000000000000000000000000000000 P 2381d032a2c9416ba9941fe21efee686 [sys.catalog]: SysCatalogTable state changed. Reason: RaftConsensus started. Latest consensus state: current_term: 1 leader_uuid: "2381d032a2c9416ba9941fe21efee686" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "2381d032a2c9416ba9941fe21efee686" member_type: VOTER } }
I20260812 06:16:28.381949 14059 sys_catalog.cc:458] T 00000000000000000000000000000000 P 2381d032a2c9416ba9941fe21efee686 [sys.catalog]: This master's current role is: LEADER
I20260812 06:16:28.381834 14062 sys_catalog.cc:455] T 00000000000000000000000000000000 P 2381d032a2c9416ba9941fe21efee686 [sys.catalog]: SysCatalogTable state changed. Reason: New leader 2381d032a2c9416ba9941fe21efee686. Latest consensus state: current_term: 1 leader_uuid: "2381d032a2c9416ba9941fe21efee686" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "2381d032a2c9416ba9941fe21efee686" member_type: VOTER } }
I20260812 06:16:28.382232 14062 sys_catalog.cc:458] T 00000000000000000000000000000000 P 2381d032a2c9416ba9941fe21efee686 [sys.catalog]: This master's current role is: LEADER
I20260812 06:16:28.382244 14070 catalog_manager.cc:1511] Loading table and tablet metadata into memory...
I20260812 06:16:28.383147 14070 catalog_manager.cc:1520] Initializing Kudu cluster ID...
I20260812 06:16:28.383391 13641 internal_mini_cluster.cc:184] Waiting to initialize catalog manager on master 0
I20260812 06:16:28.384986 14070 catalog_manager.cc:1383] Generated new cluster ID: bff9d40178db406e91df94699ef2556d
I20260812 06:16:28.385047 14070 catalog_manager.cc:1531] Initializing Kudu internal certificate authority...
I20260812 06:16:28.395449 14070 catalog_manager.cc:1406] Generated new certificate authority record
I20260812 06:16:28.395961 14070 catalog_manager.cc:1540] Loading token signing keys...
I20260812 06:16:28.401880 14070 catalog_manager.cc:6092] T 00000000000000000000000000000000 P 2381d032a2c9416ba9941fe21efee686: Generated new TSK 0
I20260812 06:16:28.402040 14070 catalog_manager.cc:1550] Initializing in-progress tserver states...
I20260812 06:16:28.415863 13641 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:16:28.418087 14087 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:28.418219 13641 server_base.cc:1061] running on GCE node
W20260812 06:16:28.418222 14089 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:28.418397 14091 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:28.418650 13641 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:16:28.418694 13641 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:28.418710 13641 hybrid_clock.cc:648] HybridClock initialized: now 1786515388418710 us; error 0 us; skew 500 ppm
I20260812 06:16:28.419557 13641 webserver.cc:533] Webserver started at http://127.13.82.65:35157/ using document root <none> and password file <none>
I20260812 06:16:28.419693 13641 fs_manager.cc:362] Metadata directory not provided
I20260812 06:16:28.419737 13641 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:16:28.419793 13641 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:16:28.420186 13641 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskNmQegX/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515382905434-13641-0/minicluster-data/ts-0-root/instance:
uuid: "0aafca2cb24c4b7b879775e574be2df8"
format_stamp: "Formatted at 2026-08-12 06:16:28 on dist-test-slave-8hhm"
I20260812 06:16:28.421728 13641 fs_manager.cc:696] Time spent creating directory manager: real 0.001s	user 0.000s	sys 0.002s
I20260812 06:16:28.422786 14097 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:28.423054 13641 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.000s	sys 0.001s
I20260812 06:16:28.423151 13641 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskNmQegX/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515382905434-13641-0/minicluster-data/ts-0-root
uuid: "0aafca2cb24c4b7b879775e574be2df8"
format_stamp: "Formatted at 2026-08-12 06:16:28 on dist-test-slave-8hhm"
I20260812 06:16:28.423244 13641 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskNmQegX/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515382905434-13641-0/minicluster-data/ts-0-root
metadata directory: /tmp/dist-test-taskNmQegX/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515382905434-13641-0/minicluster-data/ts-0-root
1 data directories: /tmp/dist-test-taskNmQegX/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515382905434-13641-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:28.439299 13641 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:16:28.439734 13641 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:16:28.440057 13641 txn_system_client.cc:432] TxnSystemClient initialization is disabled...
I20260812 06:16:28.440542 13641 ts_tablet_manager.cc:585] Loaded tablet metadata (0 total tablets, 0 live tablets)
I20260812 06:16:28.440603 13641 ts_tablet_manager.cc:531] Time spent load tablet metadata: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:16:28.440665 13641 ts_tablet_manager.cc:616] Registered 0 tablets
I20260812 06:16:28.440699 13641 ts_tablet_manager.cc:595] Time spent register tablets: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:16:28.445518 13641 rpc_server.cc:307] RPC server started. Bound to: 127.13.82.65:34057
I20260812 06:16:28.445989 14213 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.13.82.65:34057 every 8 connection(s)
I20260812 06:16:28.454658 14215 heartbeater.cc:344] Connected to a master server at 127.13.82.126:42181
I20260812 06:16:28.454766 14215 heartbeater.cc:461] Registering TS with master...
I20260812 06:16:28.454967 14215 heartbeater.cc:507] Master 127.13.82.126:42181 requested a full tablet report, sending...
I20260812 06:16:28.455641 13998 ts_manager.cc:194] Registered new tserver with Master: 0aafca2cb24c4b7b879775e574be2df8 (127.13.82.65:34057)
I20260812 06:16:28.456269 13641 internal_mini_cluster.cc:371] 1 TS(s) registered with all masters after 0.010052103s
I20260812 06:16:28.456477 13998 master_service.cc:502] Signed X509 certificate for tserver {username='slave'} at 127.0.0.1:48906
I20260812 06:16:28.463869 13998 catalog_manager.cc:2283] Servicing CreateTable request from {username='slave'} at 127.0.0.1:48910:
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:28.472700 14149 tablet_service.cc:1511] Processing CreateTablet for tablet ab3ea8c9499542ae9bef866e6cf1af52 (DEFAULT_TABLE table=heavy-update-compaction-test [id=abe136ad3e4140bebe01b34c2e924a9a]), partition=
I20260812 06:16:28.473033 14149 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet ab3ea8c9499542ae9bef866e6cf1af52. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:16:28.475047 14232 tablet_bootstrap.cc:492] T ab3ea8c9499542ae9bef866e6cf1af52 P 0aafca2cb24c4b7b879775e574be2df8: Bootstrap starting.
I20260812 06:16:28.475802 14232 tablet_bootstrap.cc:654] T ab3ea8c9499542ae9bef866e6cf1af52 P 0aafca2cb24c4b7b879775e574be2df8: Neither blocks nor log segments found. Creating new log.
I20260812 06:16:28.476858 14232 tablet_bootstrap.cc:492] T ab3ea8c9499542ae9bef866e6cf1af52 P 0aafca2cb24c4b7b879775e574be2df8: No bootstrap required, opened a new log
I20260812 06:16:28.476969 14232 ts_tablet_manager.cc:1403] T ab3ea8c9499542ae9bef866e6cf1af52 P 0aafca2cb24c4b7b879775e574be2df8: Time spent bootstrapping tablet: real 0.002s	user 0.001s	sys 0.000s
I20260812 06:16:28.477456 14232 raft_consensus.cc:359] T ab3ea8c9499542ae9bef866e6cf1af52 P 0aafca2cb24c4b7b879775e574be2df8 [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "0aafca2cb24c4b7b879775e574be2df8" member_type: VOTER last_known_addr { host: "127.13.82.65" port: 34057 } }
I20260812 06:16:28.477566 14232 raft_consensus.cc:385] T ab3ea8c9499542ae9bef866e6cf1af52 P 0aafca2cb24c4b7b879775e574be2df8 [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:16:28.477613 14232 raft_consensus.cc:740] T ab3ea8c9499542ae9bef866e6cf1af52 P 0aafca2cb24c4b7b879775e574be2df8 [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: 0aafca2cb24c4b7b879775e574be2df8, State: Initialized, Role: FOLLOWER
I20260812 06:16:28.477751 14232 consensus_queue.cc:260] T ab3ea8c9499542ae9bef866e6cf1af52 P 0aafca2cb24c4b7b879775e574be2df8 [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: "0aafca2cb24c4b7b879775e574be2df8" member_type: VOTER last_known_addr { host: "127.13.82.65" port: 34057 } }
I20260812 06:16:28.477857 14232 raft_consensus.cc:399] T ab3ea8c9499542ae9bef866e6cf1af52 P 0aafca2cb24c4b7b879775e574be2df8 [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:16:28.477903 14232 raft_consensus.cc:493] T ab3ea8c9499542ae9bef866e6cf1af52 P 0aafca2cb24c4b7b879775e574be2df8 [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:16:28.477960 14232 raft_consensus.cc:3060] T ab3ea8c9499542ae9bef866e6cf1af52 P 0aafca2cb24c4b7b879775e574be2df8 [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:16:28.478699 14232 raft_consensus.cc:515] T ab3ea8c9499542ae9bef866e6cf1af52 P 0aafca2cb24c4b7b879775e574be2df8 [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "0aafca2cb24c4b7b879775e574be2df8" member_type: VOTER last_known_addr { host: "127.13.82.65" port: 34057 } }
I20260812 06:16:28.478856 14232 leader_election.cc:304] T ab3ea8c9499542ae9bef866e6cf1af52 P 0aafca2cb24c4b7b879775e574be2df8 [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: 0aafca2cb24c4b7b879775e574be2df8; no voters: 
I20260812 06:16:28.479072 14232 leader_election.cc:290] T ab3ea8c9499542ae9bef866e6cf1af52 P 0aafca2cb24c4b7b879775e574be2df8 [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:16:28.479244 14234 raft_consensus.cc:2804] T ab3ea8c9499542ae9bef866e6cf1af52 P 0aafca2cb24c4b7b879775e574be2df8 [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:16:28.479451 14215 heartbeater.cc:499] Master 127.13.82.126:42181 was elected leader, sending a full tablet report...
I20260812 06:16:28.479485 14234 raft_consensus.cc:697] T ab3ea8c9499542ae9bef866e6cf1af52 P 0aafca2cb24c4b7b879775e574be2df8 [term 1 LEADER]: Becoming Leader. State: Replica: 0aafca2cb24c4b7b879775e574be2df8, State: Running, Role: LEADER
I20260812 06:16:28.479463 14232 ts_tablet_manager.cc:1434] T ab3ea8c9499542ae9bef866e6cf1af52 P 0aafca2cb24c4b7b879775e574be2df8: Time spent starting tablet: real 0.002s	user 0.003s	sys 0.000s
I20260812 06:16:28.479602 14234 consensus_queue.cc:237] T ab3ea8c9499542ae9bef866e6cf1af52 P 0aafca2cb24c4b7b879775e574be2df8 [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: "0aafca2cb24c4b7b879775e574be2df8" member_type: VOTER last_known_addr { host: "127.13.82.65" port: 34057 } }
I20260812 06:16:28.480924 13998 catalog_manager.cc:5719] T ab3ea8c9499542ae9bef866e6cf1af52 P 0aafca2cb24c4b7b879775e574be2df8 reported cstate change: term changed from 0 to 1, leader changed from <none> to 0aafca2cb24c4b7b879775e574be2df8 (127.13.82.65). New cstate: current_term: 1 leader_uuid: "0aafca2cb24c4b7b879775e574be2df8" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "0aafca2cb24c4b7b879775e574be2df8" member_type: VOTER last_known_addr { host: "127.13.82.65" port: 34057 } health_report { overall_health: HEALTHY } } }
I20260812 06:16:28.543563 13641 heavy-update-compaction-itest.cc:215] Time spent inserting: real 0.055s	user 0.017s	sys 0.008s
I20260812 06:16:28.696669 14216 maintenance_manager.cc:419] P 0aafca2cb24c4b7b879775e574be2df8: Scheduling FlushMRSOp(ab3ea8c9499542ae9bef866e6cf1af52): perf score=19.054940
I20260812 06:16:28.850016 14106 maintenance_manager.cc:643] P 0aafca2cb24c4b7b879775e574be2df8: FlushMRSOp(ab3ea8c9499542ae9bef866e6cf1af52) complete. Timing: real 0.153s	user 0.113s	sys 0.039s Metrics: {"bytes_written":12307490,"cfile_init":1,"delete_count":0,"dirs.queue_time_us":87,"dirs.run_cpu_time_us":230,"dirs.run_wall_time_us":893,"drs_written":1,"lbm_read_time_us":36,"lbm_reads_lt_1ms":4,"lbm_write_time_us":40061,"lbm_writes_lt_1ms":757,"peak_mem_usage":0,"reinsert_count":0,"rows_written":104,"update_count":1500}
I20260812 06:16:28.850682 14216 maintenance_manager.cc:419] P 0aafca2cb24c4b7b879775e574be2df8: Scheduling LogGCOp(ab3ea8c9499542ae9bef866e6cf1af52): free 20743831 bytes of WAL
I20260812 06:16:28.850930 14106 log_reader.cc:385] T ab3ea8c9499542ae9bef866e6cf1af52: removed 2 log segments from log reader
I20260812 06:16:28.850981 14106 log.cc:1079] T ab3ea8c9499542ae9bef866e6cf1af52 P 0aafca2cb24c4b7b879775e574be2df8: Deleting log segment in path: /tmp/dist-test-taskNmQegX/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515382905434-13641-0/minicluster-data/ts-0-root/wals/ab3ea8c9499542ae9bef866e6cf1af52/wal-000000001 (ops 1-6)
I20260812 06:16:28.851013 14106 log.cc:1079] T ab3ea8c9499542ae9bef866e6cf1af52 P 0aafca2cb24c4b7b879775e574be2df8: Deleting log segment in path: /tmp/dist-test-taskNmQegX/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515382905434-13641-0/minicluster-data/ts-0-root/wals/ab3ea8c9499542ae9bef866e6cf1af52/wal-000000002 (ops 7-11)
I20260812 06:16:28.855366 14106 maintenance_manager.cc:643] P 0aafca2cb24c4b7b879775e574be2df8: LogGCOp(ab3ea8c9499542ae9bef866e6cf1af52) complete. Timing: real 0.004s	user 0.000s	sys 0.002s Metrics: {}
I20260812 06:16:28.855741 14216 maintenance_manager.cc:419] P 0aafca2cb24c4b7b879775e574be2df8: Scheduling UndoDeltaBlockGCOp(ab3ea8c9499542ae9bef866e6cf1af52): 16411394 bytes on disk
I20260812 06:16:28.856179 14106 maintenance_manager.cc:643] P 0aafca2cb24c4b7b879775e574be2df8: UndoDeltaBlockGCOp(ab3ea8c9499542ae9bef866e6cf1af52) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":58,"lbm_reads_lt_1ms":4}
I20260812 06:16:28.856698 14216 maintenance_manager.cc:419] P 0aafca2cb24c4b7b879775e574be2df8: Scheduling FlushDeltaMemStoresOp(ab3ea8c9499542ae9bef866e6cf1af52): perf score=2.188937
I20260812 06:16:28.874293 14106 maintenance_manager.cc:643] P 0aafca2cb24c4b7b879775e574be2df8: FlushDeltaMemStoresOp(ab3ea8c9499542ae9bef866e6cf1af52) complete. Timing: real 0.017s	user 0.007s	sys 0.007s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6316,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:28.874881 14216 maintenance_manager.cc:419] P 0aafca2cb24c4b7b879775e574be2df8: Scheduling MajorDeltaCompactionOp(ab3ea8c9499542ae9bef866e6cf1af52): perf score=1.000000
I20260812 06:16:29.030511 14106 maintenance_manager.cc:643] P 0aafca2cb24c4b7b879775e574be2df8: MajorDeltaCompactionOp(ab3ea8c9499542ae9bef866e6cf1af52) complete. Timing: real 0.155s	user 0.099s	sys 0.051s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672277,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":1418,"lbm_read_time_us":10179,"lbm_reads_lt_1ms":464,"lbm_write_time_us":24086,"lbm_writes_lt_1ms":443,"mutex_wait_us":108,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":1408,"thread_start_us":470,"threads_started":5,"update_count":2000}
I20260812 06:16:29.031147 14216 maintenance_manager.cc:419] P 0aafca2cb24c4b7b879775e574be2df8: Scheduling FlushDeltaMemStoresOp(ab3ea8c9499542ae9bef866e6cf1af52): perf score=11.118625
I20260812 06:16:29.070672 14106 maintenance_manager.cc:643] P 0aafca2cb24c4b7b879775e574be2df8: FlushDeltaMemStoresOp(ab3ea8c9499542ae9bef866e6cf1af52) complete. Timing: real 0.039s	user 0.018s	sys 0.019s Metrics: {"bytes_written":12717735,"delete_count":0,"lbm_write_time_us":16927,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:16:29.071237 14216 maintenance_manager.cc:419] P 0aafca2cb24c4b7b879775e574be2df8: Scheduling FlushDeltaMemStoresOp(ab3ea8c9499542ae9bef866e6cf1af52): perf score=2.188937
I20260812 06:16:29.103029 14106 maintenance_manager.cc:643] P 0aafca2cb24c4b7b879775e574be2df8: FlushDeltaMemStoresOp(ab3ea8c9499542ae9bef866e6cf1af52) complete. Timing: real 0.032s	user 0.013s	sys 0.007s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":4874,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:16:29.103499 14216 maintenance_manager.cc:419] P 0aafca2cb24c4b7b879775e574be2df8: Scheduling FlushDeltaMemStoresOp(ab3ea8c9499542ae9bef866e6cf1af52): perf score=2.188937
I20260812 06:16:29.114494 14106 maintenance_manager.cc:643] P 0aafca2cb24c4b7b879775e574be2df8: FlushDeltaMemStoresOp(ab3ea8c9499542ae9bef866e6cf1af52) complete. Timing: real 0.011s	user 0.001s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4425,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:29.114912 14216 maintenance_manager.cc:419] P 0aafca2cb24c4b7b879775e574be2df8: Scheduling MajorDeltaCompactionOp(ab3ea8c9499542ae9bef866e6cf1af52): perf score=1.000000
I20260812 06:16:29.303608 14106 maintenance_manager.cc:643] P 0aafca2cb24c4b7b879775e574be2df8: MajorDeltaCompactionOp(ab3ea8c9499542ae9bef866e6cf1af52) complete. Timing: real 0.189s	user 0.118s	sys 0.063s Metrics: {"cfile_cache_miss":533,"cfile_cache_miss_bytes":24774799,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":970,"lbm_read_time_us":12459,"lbm_reads_lt_1ms":573,"lbm_write_time_us":29701,"lbm_writes_lt_1ms":543,"mutex_wait_us":308,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":7168,"update_count":2500}
I20260812 06:16:29.304203 14216 maintenance_manager.cc:419] P 0aafca2cb24c4b7b879775e574be2df8: Scheduling FlushDeltaMemStoresOp(ab3ea8c9499542ae9bef866e6cf1af52): perf score=14.095187
I20260812 06:16:29.355590 14106 maintenance_manager.cc:643] P 0aafca2cb24c4b7b879775e574be2df8: FlushDeltaMemStoresOp(ab3ea8c9499542ae9bef866e6cf1af52) complete. Timing: real 0.051s	user 0.019s	sys 0.028s Metrics: {"bytes_written":16409900,"delete_count":0,"lbm_write_time_us":23101,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":402,"reinsert_count":0,"update_count":2000}
I20260812 06:16:29.356069 14216 maintenance_manager.cc:419] P 0aafca2cb24c4b7b879775e574be2df8: Scheduling FlushDeltaMemStoresOp(ab3ea8c9499542ae9bef866e6cf1af52): perf score=2.188937
I20260812 06:16:29.367676 14106 maintenance_manager.cc:643] P 0aafca2cb24c4b7b879775e574be2df8: FlushDeltaMemStoresOp(ab3ea8c9499542ae9bef866e6cf1af52) complete. Timing: real 0.011s	user 0.005s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4277,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:29.368076 14216 maintenance_manager.cc:419] P 0aafca2cb24c4b7b879775e574be2df8: Scheduling MajorDeltaCompactionOp(ab3ea8c9499542ae9bef866e6cf1af52): perf score=1.000000
I20260812 06:16:29.554347 14106 maintenance_manager.cc:643] P 0aafca2cb24c4b7b879775e574be2df8: MajorDeltaCompactionOp(ab3ea8c9499542ae9bef866e6cf1af52) complete. Timing: real 0.186s	user 0.109s	sys 0.063s 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":380,"lbm_read_time_us":10669,"lbm_reads_lt_1ms":572,"lbm_write_time_us":27739,"lbm_writes_lt_1ms":543,"mutex_wait_us":44,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":11520,"update_count":2500}
I20260812 06:16:29.554943 14216 maintenance_manager.cc:419] P 0aafca2cb24c4b7b879775e574be2df8: Scheduling FlushDeltaMemStoresOp(ab3ea8c9499542ae9bef866e6cf1af52): perf score=14.095187
I20260812 06:16:29.603308 14106 maintenance_manager.cc:643] P 0aafca2cb24c4b7b879775e574be2df8: FlushDeltaMemStoresOp(ab3ea8c9499542ae9bef866e6cf1af52) complete. Timing: real 0.048s	user 0.017s	sys 0.023s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":18493,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:16:29.603860 14216 maintenance_manager.cc:419] P 0aafca2cb24c4b7b879775e574be2df8: Scheduling FlushDeltaMemStoresOp(ab3ea8c9499542ae9bef866e6cf1af52): perf score=2.188937
I20260812 06:16:29.615346 14106 maintenance_manager.cc:643] P 0aafca2cb24c4b7b879775e574be2df8: FlushDeltaMemStoresOp(ab3ea8c9499542ae9bef866e6cf1af52) complete. Timing: real 0.011s	user 0.009s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4197,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:29.615957 14216 maintenance_manager.cc:419] P 0aafca2cb24c4b7b879775e574be2df8: Scheduling MajorDeltaCompactionOp(ab3ea8c9499542ae9bef866e6cf1af52): perf score=1.000000
I20260812 06:16:29.770114 14106 maintenance_manager.cc:643] P 0aafca2cb24c4b7b879775e574be2df8: MajorDeltaCompactionOp(ab3ea8c9499542ae9bef866e6cf1af52) complete. Timing: real 0.154s	user 0.118s	sys 0.035s 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":676,"lbm_read_time_us":11433,"lbm_reads_lt_1ms":572,"lbm_write_time_us":30052,"lbm_writes_lt_1ms":543,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":8832,"update_count":2500}
I20260812 06:16:29.770874 14216 maintenance_manager.cc:419] P 0aafca2cb24c4b7b879775e574be2df8: Scheduling FlushDeltaMemStoresOp(ab3ea8c9499542ae9bef866e6cf1af52): perf score=11.118625
I20260812 06:16:29.807531 14106 maintenance_manager.cc:643] P 0aafca2cb24c4b7b879775e574be2df8: FlushDeltaMemStoresOp(ab3ea8c9499542ae9bef866e6cf1af52) complete. Timing: real 0.036s	user 0.019s	sys 0.015s Metrics: {"bytes_written":12717737,"delete_count":0,"lbm_write_time_us":16283,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":312,"reinsert_count":0,"update_count":1550}
I20260812 06:16:29.808033 14216 maintenance_manager.cc:419] P 0aafca2cb24c4b7b879775e574be2df8: Scheduling FlushDeltaMemStoresOp(ab3ea8c9499542ae9bef866e6cf1af52): perf score=2.188937
I20260812 06:16:29.829180 14106 maintenance_manager.cc:643] P 0aafca2cb24c4b7b879775e574be2df8: FlushDeltaMemStoresOp(ab3ea8c9499542ae9bef866e6cf1af52) complete. Timing: real 0.021s	user 0.004s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4949,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:29.829670 14216 maintenance_manager.cc:419] P 0aafca2cb24c4b7b879775e574be2df8: Scheduling FlushDeltaMemStoresOp(ab3ea8c9499542ae9bef866e6cf1af52): perf score=2.188937
I20260812 06:16:29.838905 14106 maintenance_manager.cc:643] P 0aafca2cb24c4b7b879775e574be2df8: FlushDeltaMemStoresOp(ab3ea8c9499542ae9bef866e6cf1af52) complete. Timing: real 0.009s	user 0.004s	sys 0.003s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3469,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:16:29.839325 14216 maintenance_manager.cc:419] P 0aafca2cb24c4b7b879775e574be2df8: Scheduling MajorDeltaCompactionOp(ab3ea8c9499542ae9bef866e6cf1af52): perf score=1.000000
I20260812 06:16:29.987159 14106 maintenance_manager.cc:643] P 0aafca2cb24c4b7b879775e574be2df8: MajorDeltaCompactionOp(ab3ea8c9499542ae9bef866e6cf1af52) complete. Timing: real 0.148s	user 0.122s	sys 0.025s Metrics: {"cfile_cache_miss":533,"cfile_cache_miss_bytes":24774801,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":892,"lbm_read_time_us":10238,"lbm_reads_lt_1ms":573,"lbm_write_time_us":31790,"lbm_writes_lt_1ms":543,"mutex_wait_us":267,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":148224,"update_count":2500}
I20260812 06:16:29.987746 14216 maintenance_manager.cc:419] P 0aafca2cb24c4b7b879775e574be2df8: Scheduling FlushDeltaMemStoresOp(ab3ea8c9499542ae9bef866e6cf1af52): perf score=10.126437
I20260812 06:16:30.028673 14106 maintenance_manager.cc:643] P 0aafca2cb24c4b7b879775e574be2df8: FlushDeltaMemStoresOp(ab3ea8c9499542ae9bef866e6cf1af52) complete. Timing: real 0.041s	user 0.022s	sys 0.015s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":20618,"lbm_writes_1-10_ms":2,"lbm_writes_lt_1ms":301,"reinsert_count":0,"update_count":1500}
I20260812 06:16:30.029417 14216 maintenance_manager.cc:419] P 0aafca2cb24c4b7b879775e574be2df8: Scheduling FlushDeltaMemStoresOp(ab3ea8c9499542ae9bef866e6cf1af52): perf score=2.188937
I20260812 06:16:30.044536 14106 maintenance_manager.cc:643] P 0aafca2cb24c4b7b879775e574be2df8: FlushDeltaMemStoresOp(ab3ea8c9499542ae9bef866e6cf1af52) complete. Timing: real 0.015s	user 0.010s	sys 0.001s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4214,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:30.044993 14216 maintenance_manager.cc:419] P 0aafca2cb24c4b7b879775e574be2df8: Scheduling FlushMRSOp(ab3ea8c9499542ae9bef866e6cf1af52): perf score=1.000000
I20260812 06:16:30.100145 14106 maintenance_manager.cc:643] P 0aafca2cb24c4b7b879775e574be2df8: FlushMRSOp(ab3ea8c9499542ae9bef866e6cf1af52) complete. Timing: real 0.055s	user 0.033s	sys 0.000s Metrics: {"bytes_written":1193503,"cfile_init":1,"dirs.queue_time_us":65,"dirs.run_cpu_time_us":269,"dirs.run_wall_time_us":1295,"drs_written":1,"lbm_read_time_us":80,"lbm_reads_lt_1ms":4,"lbm_write_time_us":2428,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":29}
I20260812 06:16:30.100870 14216 maintenance_manager.cc:419] P 0aafca2cb24c4b7b879775e574be2df8: Scheduling LogGCOp(ab3ea8c9499542ae9bef866e6cf1af52): free 111786304 bytes of WAL
I20260812 06:16:30.101122 14106 log_reader.cc:385] T ab3ea8c9499542ae9bef866e6cf1af52: removed 11 log segments from log reader
I20260812 06:16:30.101188 14106 log.cc:1079] T ab3ea8c9499542ae9bef866e6cf1af52 P 0aafca2cb24c4b7b879775e574be2df8: Deleting log segment in path: /tmp/dist-test-taskNmQegX/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515382905434-13641-0/minicluster-data/ts-0-root/wals/ab3ea8c9499542ae9bef866e6cf1af52/wal-000000003 (ops 12-16)
I20260812 06:16:30.101254 14106 log.cc:1079] T ab3ea8c9499542ae9bef866e6cf1af52 P 0aafca2cb24c4b7b879775e574be2df8: Deleting log segment in path: /tmp/dist-test-taskNmQegX/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515382905434-13641-0/minicluster-data/ts-0-root/wals/ab3ea8c9499542ae9bef866e6cf1af52/wal-000000004 (ops 17-21)
I20260812 06:16:30.101306 14106 log.cc:1079] T ab3ea8c9499542ae9bef866e6cf1af52 P 0aafca2cb24c4b7b879775e574be2df8: Deleting log segment in path: /tmp/dist-test-taskNmQegX/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515382905434-13641-0/minicluster-data/ts-0-root/wals/ab3ea8c9499542ae9bef866e6cf1af52/wal-000000005 (ops 22-26)
I20260812 06:16:30.101338 14106 log.cc:1079] T ab3ea8c9499542ae9bef866e6cf1af52 P 0aafca2cb24c4b7b879775e574be2df8: Deleting log segment in path: /tmp/dist-test-taskNmQegX/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515382905434-13641-0/minicluster-data/ts-0-root/wals/ab3ea8c9499542ae9bef866e6cf1af52/wal-000000006 (ops 27-31)
I20260812 06:16:30.101368 14106 log.cc:1079] T ab3ea8c9499542ae9bef866e6cf1af52 P 0aafca2cb24c4b7b879775e574be2df8: Deleting log segment in path: /tmp/dist-test-taskNmQegX/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515382905434-13641-0/minicluster-data/ts-0-root/wals/ab3ea8c9499542ae9bef866e6cf1af52/wal-000000007 (ops 32-36)
I20260812 06:16:30.101397 14106 log.cc:1079] T ab3ea8c9499542ae9bef866e6cf1af52 P 0aafca2cb24c4b7b879775e574be2df8: Deleting log segment in path: /tmp/dist-test-taskNmQegX/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515382905434-13641-0/minicluster-data/ts-0-root/wals/ab3ea8c9499542ae9bef866e6cf1af52/wal-000000008 (ops 37-40)
I20260812 06:16:30.101429 14106 log.cc:1079] T ab3ea8c9499542ae9bef866e6cf1af52 P 0aafca2cb24c4b7b879775e574be2df8: Deleting log segment in path: /tmp/dist-test-taskNmQegX/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515382905434-13641-0/minicluster-data/ts-0-root/wals/ab3ea8c9499542ae9bef866e6cf1af52/wal-000000009 (ops 41-45)
I20260812 06:16:30.101459 14106 log.cc:1079] T ab3ea8c9499542ae9bef866e6cf1af52 P 0aafca2cb24c4b7b879775e574be2df8: Deleting log segment in path: /tmp/dist-test-taskNmQegX/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515382905434-13641-0/minicluster-data/ts-0-root/wals/ab3ea8c9499542ae9bef866e6cf1af52/wal-000000010 (ops 46-50)
I20260812 06:16:30.101485 14106 log.cc:1079] T ab3ea8c9499542ae9bef866e6cf1af52 P 0aafca2cb24c4b7b879775e574be2df8: Deleting log segment in path: /tmp/dist-test-taskNmQegX/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515382905434-13641-0/minicluster-data/ts-0-root/wals/ab3ea8c9499542ae9bef866e6cf1af52/wal-000000011 (ops 51-55)
I20260812 06:16:30.101511 14106 log.cc:1079] T ab3ea8c9499542ae9bef866e6cf1af52 P 0aafca2cb24c4b7b879775e574be2df8: Deleting log segment in path: /tmp/dist-test-taskNmQegX/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515382905434-13641-0/minicluster-data/ts-0-root/wals/ab3ea8c9499542ae9bef866e6cf1af52/wal-000000012 (ops 56-60)
I20260812 06:16:30.101549 14106 log.cc:1079] T ab3ea8c9499542ae9bef866e6cf1af52 P 0aafca2cb24c4b7b879775e574be2df8: Deleting log segment in path: /tmp/dist-test-taskNmQegX/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515382905434-13641-0/minicluster-data/ts-0-root/wals/ab3ea8c9499542ae9bef866e6cf1af52/wal-000000013 (ops 61-64)
I20260812 06:16:30.126637 14106 maintenance_manager.cc:643] P 0aafca2cb24c4b7b879775e574be2df8: LogGCOp(ab3ea8c9499542ae9bef866e6cf1af52) complete. Timing: real 0.026s	user 0.002s	sys 0.023s Metrics: {}
I20260812 06:16:30.127077 14216 maintenance_manager.cc:419] P 0aafca2cb24c4b7b879775e574be2df8: Scheduling UndoDeltaBlockGCOp(ab3ea8c9499542ae9bef866e6cf1af52): 462 bytes on disk
I20260812 06:16:30.127668 14106 maintenance_manager.cc:643] P 0aafca2cb24c4b7b879775e574be2df8: UndoDeltaBlockGCOp(ab3ea8c9499542ae9bef866e6cf1af52) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":77,"lbm_reads_lt_1ms":4}
I20260812 06:16:30.128276 14216 maintenance_manager.cc:419] P 0aafca2cb24c4b7b879775e574be2df8: Scheduling FlushDeltaMemStoresOp(ab3ea8c9499542ae9bef866e6cf1af52): perf score=6.157687
I20260812 06:16:30.151839 14106 maintenance_manager.cc:643] P 0aafca2cb24c4b7b879775e574be2df8: FlushDeltaMemStoresOp(ab3ea8c9499542ae9bef866e6cf1af52) complete. Timing: real 0.023s	user 0.010s	sys 0.007s Metrics: {"bytes_written":8205078,"delete_count":0,"lbm_write_time_us":8785,"lbm_writes_lt_1ms":203,"reinsert_count":0,"update_count":1000}
I20260812 06:16:30.152320 14216 maintenance_manager.cc:419] P 0aafca2cb24c4b7b879775e574be2df8: Scheduling LogGCOp(ab3ea8c9499542ae9bef866e6cf1af52): free 8767067 bytes of WAL
I20260812 06:16:30.152541 14106 log_reader.cc:385] T ab3ea8c9499542ae9bef866e6cf1af52: removed 1 log segments from log reader
I20260812 06:16:30.152604 14106 log.cc:1079] T ab3ea8c9499542ae9bef866e6cf1af52 P 0aafca2cb24c4b7b879775e574be2df8: Deleting log segment in path: /tmp/dist-test-taskNmQegX/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515382905434-13641-0/minicluster-data/ts-0-root/wals/ab3ea8c9499542ae9bef866e6cf1af52/wal-000000014 (ops 65-69)
I20260812 06:16:30.154354 14106 maintenance_manager.cc:643] P 0aafca2cb24c4b7b879775e574be2df8: LogGCOp(ab3ea8c9499542ae9bef866e6cf1af52) complete. Timing: real 0.002s	user 0.000s	sys 0.001s Metrics: {}
I20260812 06:16:30.154630 14216 maintenance_manager.cc:419] P 0aafca2cb24c4b7b879775e574be2df8: Scheduling FlushDeltaMemStoresOp(ab3ea8c9499542ae9bef866e6cf1af52): perf score=2.188937
I20260812 06:16:30.165771 14106 maintenance_manager.cc:643] P 0aafca2cb24c4b7b879775e574be2df8: FlushDeltaMemStoresOp(ab3ea8c9499542ae9bef866e6cf1af52) complete. Timing: real 0.011s	user 0.009s	sys 0.001s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":3952,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:30.166178 14216 maintenance_manager.cc:419] P 0aafca2cb24c4b7b879775e574be2df8: Scheduling MajorDeltaCompactionOp(ab3ea8c9499542ae9bef866e6cf1af52): perf score=1.000000
I20260812 06:16:30.388981 14106 maintenance_manager.cc:643] P 0aafca2cb24c4b7b879775e574be2df8: MajorDeltaCompactionOp(ab3ea8c9499542ae9bef866e6cf1af52) complete. Timing: real 0.223s	user 0.150s	sys 0.057s Metrics: {"cfile_cache_miss":734,"cfile_cache_miss_bytes":32979751,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":171,"lbm_read_time_us":12073,"lbm_reads_lt_1ms":774,"lbm_write_time_us":40186,"lbm_writes_lt_1ms":743,"mutex_wait_us":2,"peak_mem_usage":87969044,"reinsert_count":0,"spinlock_wait_cycles":1280,"thread_start_us":93,"threads_started":1,"update_count":3500}
I20260812 06:16:30.390170 14216 maintenance_manager.cc:419] P 0aafca2cb24c4b7b879775e574be2df8: Scheduling FlushDeltaMemStoresOp(ab3ea8c9499542ae9bef866e6cf1af52): perf score=18.063937
I20260812 06:16:30.465150 14106 maintenance_manager.cc:643] P 0aafca2cb24c4b7b879775e574be2df8: FlushDeltaMemStoresOp(ab3ea8c9499542ae9bef866e6cf1af52) complete. Timing: real 0.075s	user 0.024s	sys 0.046s Metrics: {"bytes_written":20512314,"delete_count":0,"lbm_write_time_us":29701,"lbm_writes_lt_1ms":503,"reinsert_count":0,"update_count":2500}
I20260812 06:16:30.465763 14216 maintenance_manager.cc:419] P 0aafca2cb24c4b7b879775e574be2df8: Scheduling FlushDeltaMemStoresOp(ab3ea8c9499542ae9bef866e6cf1af52): perf score=2.188937
I20260812 06:16:30.476485 14106 maintenance_manager.cc:643] P 0aafca2cb24c4b7b879775e574be2df8: FlushDeltaMemStoresOp(ab3ea8c9499542ae9bef866e6cf1af52) complete. Timing: real 0.011s	user 0.001s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4276,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:30.476931 14216 maintenance_manager.cc:419] P 0aafca2cb24c4b7b879775e574be2df8: Scheduling MajorDeltaCompactionOp(ab3ea8c9499542ae9bef866e6cf1af52): perf score=1.000000
I20260812 06:16:30.677821 14106 maintenance_manager.cc:643] P 0aafca2cb24c4b7b879775e574be2df8: MajorDeltaCompactionOp(ab3ea8c9499542ae9bef866e6cf1af52) complete. Timing: real 0.201s	user 0.117s	sys 0.083s Metrics: {"cfile_cache_miss":632,"cfile_cache_miss_bytes":28877101,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":299,"lbm_read_time_us":14665,"lbm_reads_lt_1ms":672,"lbm_write_time_us":35231,"lbm_writes_lt_1ms":643,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":1408,"update_count":3000}
I20260812 06:16:30.678735 14216 maintenance_manager.cc:419] P 0aafca2cb24c4b7b879775e574be2df8: Scheduling FlushDeltaMemStoresOp(ab3ea8c9499542ae9bef866e6cf1af52): perf score=14.095187
I20260812 06:16:30.740186 14106 maintenance_manager.cc:643] P 0aafca2cb24c4b7b879775e574be2df8: FlushDeltaMemStoresOp(ab3ea8c9499542ae9bef866e6cf1af52) complete. Timing: real 0.061s	user 0.046s	sys 0.012s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":27287,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:16:30.740777 14216 maintenance_manager.cc:419] P 0aafca2cb24c4b7b879775e574be2df8: Scheduling FlushDeltaMemStoresOp(ab3ea8c9499542ae9bef866e6cf1af52): perf score=2.188937
I20260812 06:16:30.767585 14106 maintenance_manager.cc:643] P 0aafca2cb24c4b7b879775e574be2df8: FlushDeltaMemStoresOp(ab3ea8c9499542ae9bef866e6cf1af52) complete. Timing: real 0.027s	user 0.011s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6589,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:30.768086 14216 maintenance_manager.cc:419] P 0aafca2cb24c4b7b879775e574be2df8: Scheduling FlushDeltaMemStoresOp(ab3ea8c9499542ae9bef866e6cf1af52): perf score=2.188937
I20260812 06:16:30.781580 14106 maintenance_manager.cc:643] P 0aafca2cb24c4b7b879775e574be2df8: FlushDeltaMemStoresOp(ab3ea8c9499542ae9bef866e6cf1af52) complete. Timing: real 0.013s	user 0.006s	sys 0.007s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4852,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:30.782253 14216 maintenance_manager.cc:419] P 0aafca2cb24c4b7b879775e574be2df8: Scheduling MajorDeltaCompactionOp(ab3ea8c9499542ae9bef866e6cf1af52): perf score=1.000000
I20260812 06:16:31.007407 14106 maintenance_manager.cc:643] P 0aafca2cb24c4b7b879775e574be2df8: MajorDeltaCompactionOp(ab3ea8c9499542ae9bef866e6cf1af52) complete. Timing: real 0.225s	user 0.117s	sys 0.100s Metrics: {"cfile_cache_miss":633,"cfile_cache_miss_bytes":28877219,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":332,"lbm_read_time_us":19411,"lbm_reads_lt_1ms":673,"lbm_write_time_us":32953,"lbm_writes_lt_1ms":643,"mutex_wait_us":2,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":6193152,"update_count":3000}
I20260812 06:16:31.008139 14216 maintenance_manager.cc:419] P 0aafca2cb24c4b7b879775e574be2df8: Scheduling FlushDeltaMemStoresOp(ab3ea8c9499542ae9bef866e6cf1af52): perf score=15.087375
I20260812 06:16:31.058377 14106 maintenance_manager.cc:643] P 0aafca2cb24c4b7b879775e574be2df8: FlushDeltaMemStoresOp(ab3ea8c9499542ae9bef866e6cf1af52) complete. Timing: real 0.050s	user 0.031s	sys 0.016s Metrics: {"bytes_written":17435503,"delete_count":0,"lbm_write_time_us":21386,"lbm_writes_lt_1ms":428,"reinsert_count":0,"update_count":2125}
I20260812 06:16:31.059068 14216 maintenance_manager.cc:419] P 0aafca2cb24c4b7b879775e574be2df8: Scheduling FlushDeltaMemStoresOp(ab3ea8c9499542ae9bef866e6cf1af52): perf score=2.188937
I20260812 06:16:31.075111 14106 maintenance_manager.cc:643] P 0aafca2cb24c4b7b879775e574be2df8: FlushDeltaMemStoresOp(ab3ea8c9499542ae9bef866e6cf1af52) complete. Timing: real 0.015s	user 0.008s	sys 0.004s Metrics: {"bytes_written":3487284,"delete_count":0,"lbm_write_time_us":5649,"lbm_writes_lt_1ms":88,"reinsert_count":0,"update_count":425}
I20260812 06:16:31.075567 14216 maintenance_manager.cc:419] P 0aafca2cb24c4b7b879775e574be2df8: Scheduling FlushDeltaMemStoresOp(ab3ea8c9499542ae9bef866e6cf1af52): perf score=2.188937
I20260812 06:16:31.085768 14106 maintenance_manager.cc:643] P 0aafca2cb24c4b7b879775e574be2df8: FlushDeltaMemStoresOp(ab3ea8c9499542ae9bef866e6cf1af52) complete. Timing: real 0.010s	user 0.009s	sys 0.000s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":4164,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:16:31.086241 14216 maintenance_manager.cc:419] P 0aafca2cb24c4b7b879775e574be2df8: Scheduling MajorDeltaCompactionOp(ab3ea8c9499542ae9bef866e6cf1af52): perf score=1.000000
I20260812 06:16:31.289794 14106 maintenance_manager.cc:643] P 0aafca2cb24c4b7b879775e574be2df8: MajorDeltaCompactionOp(ab3ea8c9499542ae9bef866e6cf1af52) complete. Timing: real 0.203s	user 0.154s	sys 0.048s Metrics: {"cfile_cache_miss":633,"cfile_cache_miss_bytes":28877192,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":191,"lbm_read_time_us":14537,"lbm_reads_lt_1ms":673,"lbm_write_time_us":34150,"lbm_writes_lt_1ms":643,"mutex_wait_us":21,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":11392,"update_count":3000}
I20260812 06:16:31.290436 14216 maintenance_manager.cc:419] P 0aafca2cb24c4b7b879775e574be2df8: Scheduling FlushDeltaMemStoresOp(ab3ea8c9499542ae9bef866e6cf1af52): perf score=16.079562
I20260812 06:16:31.361507 14106 maintenance_manager.cc:643] P 0aafca2cb24c4b7b879775e574be2df8: FlushDeltaMemStoresOp(ab3ea8c9499542ae9bef866e6cf1af52) complete. Timing: real 0.071s	user 0.026s	sys 0.032s Metrics: {"bytes_written":17804726,"delete_count":0,"lbm_write_time_us":25674,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":436,"mutex_wait_us":23,"reinsert_count":0,"update_count":2170}
I20260812 06:16:31.361989 14216 maintenance_manager.cc:419] P 0aafca2cb24c4b7b879775e574be2df8: Scheduling FlushDeltaMemStoresOp(ab3ea8c9499542ae9bef866e6cf1af52): perf score=5.165500
I20260812 06:16:31.389468 14106 maintenance_manager.cc:643] P 0aafca2cb24c4b7b879775e574be2df8: FlushDeltaMemStoresOp(ab3ea8c9499542ae9bef866e6cf1af52) complete. Timing: real 0.027s	user 0.012s	sys 0.009s Metrics: {"bytes_written":6810264,"delete_count":0,"lbm_write_time_us":8325,"lbm_writes_lt_1ms":169,"reinsert_count":0,"update_count":830}
I20260812 06:16:31.390103 14216 maintenance_manager.cc:419] P 0aafca2cb24c4b7b879775e574be2df8: Scheduling MajorDeltaCompactionOp(ab3ea8c9499542ae9bef866e6cf1af52): perf score=1.000000
I20260812 06:16:31.598228 14106 maintenance_manager.cc:643] P 0aafca2cb24c4b7b879775e574be2df8: MajorDeltaCompactionOp(ab3ea8c9499542ae9bef866e6cf1af52) complete. Timing: real 0.208s	user 0.145s	sys 0.052s Metrics: {"cfile_cache_miss":632,"cfile_cache_miss_bytes":28877112,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":473,"lbm_read_time_us":13736,"lbm_reads_lt_1ms":664,"lbm_write_time_us":32731,"lbm_writes_lt_1ms":643,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":9216,"update_count":3000}
I20260812 06:16:31.599056 14216 maintenance_manager.cc:419] P 0aafca2cb24c4b7b879775e574be2df8: Scheduling FlushDeltaMemStoresOp(ab3ea8c9499542ae9bef866e6cf1af52): perf score=18.063937
I20260812 06:16:31.667987 14106 maintenance_manager.cc:643] P 0aafca2cb24c4b7b879775e574be2df8: FlushDeltaMemStoresOp(ab3ea8c9499542ae9bef866e6cf1af52) complete. Timing: real 0.069s	user 0.046s	sys 0.008s Metrics: {"bytes_written":20512316,"delete_count":0,"lbm_write_time_us":26044,"lbm_writes_lt_1ms":503,"reinsert_count":0,"update_count":2500}
I20260812 06:16:31.668520 14216 maintenance_manager.cc:419] P 0aafca2cb24c4b7b879775e574be2df8: Scheduling FlushDeltaMemStoresOp(ab3ea8c9499542ae9bef866e6cf1af52): perf score=2.188937
I20260812 06:16:31.680002 14106 maintenance_manager.cc:643] P 0aafca2cb24c4b7b879775e574be2df8: FlushDeltaMemStoresOp(ab3ea8c9499542ae9bef866e6cf1af52) complete. Timing: real 0.011s	user 0.002s	sys 0.007s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4083,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:31.680550 14216 maintenance_manager.cc:419] P 0aafca2cb24c4b7b879775e574be2df8: Scheduling FlushMRSOp(ab3ea8c9499542ae9bef866e6cf1af52): perf score=1.000000
I20260812 06:16:31.708508 14106 maintenance_manager.cc:643] P 0aafca2cb24c4b7b879775e574be2df8: FlushMRSOp(ab3ea8c9499542ae9bef866e6cf1af52) complete. Timing: real 0.028s	user 0.023s	sys 0.003s Metrics: {"bytes_written":1316419,"cfile_init":1,"dirs.queue_time_us":81,"dirs.run_cpu_time_us":227,"dirs.run_wall_time_us":1453,"drs_written":1,"lbm_read_time_us":58,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1608,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":32}
I20260812 06:16:31.709286 14216 maintenance_manager.cc:419] P 0aafca2cb24c4b7b879775e574be2df8: Scheduling LogGCOp(ab3ea8c9499542ae9bef866e6cf1af52): free 129320586 bytes of WAL
I20260812 06:16:31.709545 14106 log_reader.cc:385] T ab3ea8c9499542ae9bef866e6cf1af52: removed 13 log segments from log reader
I20260812 06:16:31.709617 14106 log.cc:1079] T ab3ea8c9499542ae9bef866e6cf1af52 P 0aafca2cb24c4b7b879775e574be2df8: Deleting log segment in path: /tmp/dist-test-taskNmQegX/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515382905434-13641-0/minicluster-data/ts-0-root/wals/ab3ea8c9499542ae9bef866e6cf1af52/wal-000000015 (ops 70-74)
I20260812 06:16:31.709669 14106 log.cc:1079] T ab3ea8c9499542ae9bef866e6cf1af52 P 0aafca2cb24c4b7b879775e574be2df8: Deleting log segment in path: /tmp/dist-test-taskNmQegX/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515382905434-13641-0/minicluster-data/ts-0-root/wals/ab3ea8c9499542ae9bef866e6cf1af52/wal-000000016 (ops 75-79)
I20260812 06:16:31.709708 14106 log.cc:1079] T ab3ea8c9499542ae9bef866e6cf1af52 P 0aafca2cb24c4b7b879775e574be2df8: Deleting log segment in path: /tmp/dist-test-taskNmQegX/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515382905434-13641-0/minicluster-data/ts-0-root/wals/ab3ea8c9499542ae9bef866e6cf1af52/wal-000000017 (ops 80-84)
I20260812 06:16:31.709748 14106 log.cc:1079] T ab3ea8c9499542ae9bef866e6cf1af52 P 0aafca2cb24c4b7b879775e574be2df8: Deleting log segment in path: /tmp/dist-test-taskNmQegX/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515382905434-13641-0/minicluster-data/ts-0-root/wals/ab3ea8c9499542ae9bef866e6cf1af52/wal-000000018 (ops 85-89)
I20260812 06:16:31.709785 14106 log.cc:1079] T ab3ea8c9499542ae9bef866e6cf1af52 P 0aafca2cb24c4b7b879775e574be2df8: Deleting log segment in path: /tmp/dist-test-taskNmQegX/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515382905434-13641-0/minicluster-data/ts-0-root/wals/ab3ea8c9499542ae9bef866e6cf1af52/wal-000000019 (ops 90-94)
I20260812 06:16:31.709826 14106 log.cc:1079] T ab3ea8c9499542ae9bef866e6cf1af52 P 0aafca2cb24c4b7b879775e574be2df8: Deleting log segment in path: /tmp/dist-test-taskNmQegX/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515382905434-13641-0/minicluster-data/ts-0-root/wals/ab3ea8c9499542ae9bef866e6cf1af52/wal-000000020 (ops 95-99)
I20260812 06:16:31.709864 14106 log.cc:1079] T ab3ea8c9499542ae9bef866e6cf1af52 P 0aafca2cb24c4b7b879775e574be2df8: Deleting log segment in path: /tmp/dist-test-taskNmQegX/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515382905434-13641-0/minicluster-data/ts-0-root/wals/ab3ea8c9499542ae9bef866e6cf1af52/wal-000000021 (ops 100-104)
I20260812 06:16:31.709904 14106 log.cc:1079] T ab3ea8c9499542ae9bef866e6cf1af52 P 0aafca2cb24c4b7b879775e574be2df8: Deleting log segment in path: /tmp/dist-test-taskNmQegX/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515382905434-13641-0/minicluster-data/ts-0-root/wals/ab3ea8c9499542ae9bef866e6cf1af52/wal-000000022 (ops 105-108)
I20260812 06:16:31.709942 14106 log.cc:1079] T ab3ea8c9499542ae9bef866e6cf1af52 P 0aafca2cb24c4b7b879775e574be2df8: Deleting log segment in path: /tmp/dist-test-taskNmQegX/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515382905434-13641-0/minicluster-data/ts-0-root/wals/ab3ea8c9499542ae9bef866e6cf1af52/wal-000000023 (ops 109-113)
I20260812 06:16:31.710000 14106 log.cc:1079] T ab3ea8c9499542ae9bef866e6cf1af52 P 0aafca2cb24c4b7b879775e574be2df8: Deleting log segment in path: /tmp/dist-test-taskNmQegX/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515382905434-13641-0/minicluster-data/ts-0-root/wals/ab3ea8c9499542ae9bef866e6cf1af52/wal-000000024 (ops 114-118)
I20260812 06:16:31.710038 14106 log.cc:1079] T ab3ea8c9499542ae9bef866e6cf1af52 P 0aafca2cb24c4b7b879775e574be2df8: Deleting log segment in path: /tmp/dist-test-taskNmQegX/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515382905434-13641-0/minicluster-data/ts-0-root/wals/ab3ea8c9499542ae9bef866e6cf1af52/wal-000000025 (ops 119-122)
I20260812 06:16:31.710078 14106 log.cc:1079] T ab3ea8c9499542ae9bef866e6cf1af52 P 0aafca2cb24c4b7b879775e574be2df8: Deleting log segment in path: /tmp/dist-test-taskNmQegX/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515382905434-13641-0/minicluster-data/ts-0-root/wals/ab3ea8c9499542ae9bef866e6cf1af52/wal-000000026 (ops 123-127)
I20260812 06:16:31.710120 14106 log.cc:1079] T ab3ea8c9499542ae9bef866e6cf1af52 P 0aafca2cb24c4b7b879775e574be2df8: Deleting log segment in path: /tmp/dist-test-taskNmQegX/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515382905434-13641-0/minicluster-data/ts-0-root/wals/ab3ea8c9499542ae9bef866e6cf1af52/wal-000000027 (ops 128-132)
I20260812 06:16:31.738798 14106 maintenance_manager.cc:643] P 0aafca2cb24c4b7b879775e574be2df8: LogGCOp(ab3ea8c9499542ae9bef866e6cf1af52) complete. Timing: real 0.029s	user 0.001s	sys 0.028s Metrics: {}
I20260812 06:16:31.739328 14216 maintenance_manager.cc:419] P 0aafca2cb24c4b7b879775e574be2df8: Scheduling UndoDeltaBlockGCOp(ab3ea8c9499542ae9bef866e6cf1af52): 492 bytes on disk
I20260812 06:16:31.739866 14106 maintenance_manager.cc:643] P 0aafca2cb24c4b7b879775e574be2df8: UndoDeltaBlockGCOp(ab3ea8c9499542ae9bef866e6cf1af52) 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:31.740463 14216 maintenance_manager.cc:419] P 0aafca2cb24c4b7b879775e574be2df8: Scheduling FlushDeltaMemStoresOp(ab3ea8c9499542ae9bef866e6cf1af52): perf score=4.173312
I20260812 06:16:31.754285 14106 maintenance_manager.cc:643] P 0aafca2cb24c4b7b879775e574be2df8: FlushDeltaMemStoresOp(ab3ea8c9499542ae9bef866e6cf1af52) complete. Timing: real 0.014s	user 0.004s	sys 0.009s Metrics: {"bytes_written":5538512,"delete_count":0,"lbm_write_time_us":5759,"lbm_writes_lt_1ms":138,"reinsert_count":0,"update_count":675}
I20260812 06:16:31.754714 14216 maintenance_manager.cc:419] P 0aafca2cb24c4b7b879775e574be2df8: Scheduling FlushDeltaMemStoresOp(ab3ea8c9499542ae9bef866e6cf1af52): perf score=1.196750
I20260812 06:16:31.763602 14106 maintenance_manager.cc:643] P 0aafca2cb24c4b7b879775e574be2df8: FlushDeltaMemStoresOp(ab3ea8c9499542ae9bef866e6cf1af52) complete. Timing: real 0.009s	user 0.000s	sys 0.006s Metrics: {"bytes_written":2666779,"delete_count":0,"lbm_write_time_us":3088,"lbm_writes_lt_1ms":68,"reinsert_count":0,"update_count":325}
I20260812 06:16:31.764290 14216 maintenance_manager.cc:419] P 0aafca2cb24c4b7b879775e574be2df8: Scheduling MajorDeltaCompactionOp(ab3ea8c9499542ae9bef866e6cf1af52): perf score=1.000000
I20260812 06:16:32.007571 14106 maintenance_manager.cc:643] P 0aafca2cb24c4b7b879775e574be2df8: MajorDeltaCompactionOp(ab3ea8c9499542ae9bef866e6cf1af52) complete. Timing: real 0.243s	user 0.159s	sys 0.082s Metrics: {"cfile_cache_miss":834,"cfile_cache_miss_bytes":37082132,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":2873,"lbm_read_time_us":17482,"lbm_reads_lt_1ms":874,"lbm_write_time_us":46355,"lbm_writes_lt_1ms":843,"peak_mem_usage":100395616,"reinsert_count":0,"spinlock_wait_cycles":2560,"thread_start_us":92,"threads_started":1,"update_count":4000}
I20260812 06:16:32.008518 14216 maintenance_manager.cc:419] P 0aafca2cb24c4b7b879775e574be2df8: Scheduling FlushDeltaMemStoresOp(ab3ea8c9499542ae9bef866e6cf1af52): perf score=18.063937
I20260812 06:16:32.060894 14106 maintenance_manager.cc:643] P 0aafca2cb24c4b7b879775e574be2df8: FlushDeltaMemStoresOp(ab3ea8c9499542ae9bef866e6cf1af52) complete. Timing: real 0.052s	user 0.032s	sys 0.016s Metrics: {"bytes_written":20512319,"delete_count":0,"lbm_write_time_us":22643,"lbm_writes_lt_1ms":503,"reinsert_count":0,"update_count":2500}
I20260812 06:16:32.061496 14216 maintenance_manager.cc:419] P 0aafca2cb24c4b7b879775e574be2df8: Scheduling FlushDeltaMemStoresOp(ab3ea8c9499542ae9bef866e6cf1af52): perf score=2.188937
I20260812 06:16:32.088171 14106 maintenance_manager.cc:643] P 0aafca2cb24c4b7b879775e574be2df8: FlushDeltaMemStoresOp(ab3ea8c9499542ae9bef866e6cf1af52) complete. Timing: real 0.023s	user 0.004s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5751,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:32.088608 14216 maintenance_manager.cc:419] P 0aafca2cb24c4b7b879775e574be2df8: Scheduling FlushDeltaMemStoresOp(ab3ea8c9499542ae9bef866e6cf1af52): perf score=2.188937
I20260812 06:16:32.099396 14106 maintenance_manager.cc:643] P 0aafca2cb24c4b7b879775e574be2df8: FlushDeltaMemStoresOp(ab3ea8c9499542ae9bef866e6cf1af52) complete. Timing: real 0.011s	user 0.002s	sys 0.007s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4383,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:32.099861 14216 maintenance_manager.cc:419] P 0aafca2cb24c4b7b879775e574be2df8: Scheduling MajorDeltaCompactionOp(ab3ea8c9499542ae9bef866e6cf1af52): perf score=1.000000
I20260812 06:16:32.290777 14106 maintenance_manager.cc:643] P 0aafca2cb24c4b7b879775e574be2df8: MajorDeltaCompactionOp(ab3ea8c9499542ae9bef866e6cf1af52) complete. Timing: real 0.191s	user 0.142s	sys 0.048s Metrics: {"cfile_cache_miss":733,"cfile_cache_miss_bytes":32979637,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":185,"lbm_read_time_us":12852,"lbm_reads_lt_1ms":773,"lbm_write_time_us":42246,"lbm_writes_lt_1ms":743,"mutex_wait_us":51,"peak_mem_usage":87969044,"reinsert_count":0,"spinlock_wait_cycles":14848,"update_count":3500}
I20260812 06:16:32.292021 14216 maintenance_manager.cc:419] P 0aafca2cb24c4b7b879775e574be2df8: Scheduling FlushDeltaMemStoresOp(ab3ea8c9499542ae9bef866e6cf1af52): perf score=14.095187
I20260812 06:16:32.345523 14106 maintenance_manager.cc:643] P 0aafca2cb24c4b7b879775e574be2df8: FlushDeltaMemStoresOp(ab3ea8c9499542ae9bef866e6cf1af52) complete. Timing: real 0.053s	user 0.037s	sys 0.016s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":23474,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:16:32.346282 14216 maintenance_manager.cc:419] P 0aafca2cb24c4b7b879775e574be2df8: Scheduling FlushDeltaMemStoresOp(ab3ea8c9499542ae9bef866e6cf1af52): perf score=2.188937
I20260812 06:16:32.363333 14106 maintenance_manager.cc:643] P 0aafca2cb24c4b7b879775e574be2df8: FlushDeltaMemStoresOp(ab3ea8c9499542ae9bef866e6cf1af52) complete. Timing: real 0.017s	user 0.010s	sys 0.003s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6498,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:32.363770 14216 maintenance_manager.cc:419] P 0aafca2cb24c4b7b879775e574be2df8: Scheduling MajorDeltaCompactionOp(ab3ea8c9499542ae9bef866e6cf1af52): perf score=1.000000
I20260812 06:16:32.532804 14106 maintenance_manager.cc:643] P 0aafca2cb24c4b7b879775e574be2df8: MajorDeltaCompactionOp(ab3ea8c9499542ae9bef866e6cf1af52) complete. Timing: real 0.169s	user 0.119s	sys 0.032s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774688,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":431,"lbm_read_time_us":8711,"lbm_reads_lt_1ms":564,"lbm_write_time_us":34136,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":542,"mutex_wait_us":28,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":6272,"update_count":2500}
I20260812 06:16:32.533454 14216 maintenance_manager.cc:419] P 0aafca2cb24c4b7b879775e574be2df8: Scheduling FlushDeltaMemStoresOp(ab3ea8c9499542ae9bef866e6cf1af52): perf score=14.095187
I20260812 06:16:32.586587 14106 maintenance_manager.cc:643] P 0aafca2cb24c4b7b879775e574be2df8: FlushDeltaMemStoresOp(ab3ea8c9499542ae9bef866e6cf1af52) complete. Timing: real 0.053s	user 0.033s	sys 0.017s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":23362,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:16:32.587194 14216 maintenance_manager.cc:419] P 0aafca2cb24c4b7b879775e574be2df8: Scheduling FlushDeltaMemStoresOp(ab3ea8c9499542ae9bef866e6cf1af52): perf score=2.188937
I20260812 06:16:32.598157 14106 maintenance_manager.cc:643] P 0aafca2cb24c4b7b879775e574be2df8: FlushDeltaMemStoresOp(ab3ea8c9499542ae9bef866e6cf1af52) complete. Timing: real 0.011s	user 0.006s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3928,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:32.598659 14216 maintenance_manager.cc:419] P 0aafca2cb24c4b7b879775e574be2df8: Scheduling MajorDeltaCompactionOp(ab3ea8c9499542ae9bef866e6cf1af52): perf score=1.000000
I20260812 06:16:32.779767 14106 maintenance_manager.cc:643] P 0aafca2cb24c4b7b879775e574be2df8: MajorDeltaCompactionOp(ab3ea8c9499542ae9bef866e6cf1af52) complete. Timing: real 0.181s	user 0.117s	sys 0.064s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774688,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":844,"lbm_read_time_us":15247,"lbm_reads_lt_1ms":572,"lbm_write_time_us":26914,"lbm_writes_lt_1ms":543,"mutex_wait_us":313,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":7680,"update_count":2500}
I20260812 06:16:32.780516 14216 maintenance_manager.cc:419] P 0aafca2cb24c4b7b879775e574be2df8: Scheduling FlushDeltaMemStoresOp(ab3ea8c9499542ae9bef866e6cf1af52): perf score=14.095187
I20260812 06:16:32.847242 14106 maintenance_manager.cc:643] P 0aafca2cb24c4b7b879775e574be2df8: FlushDeltaMemStoresOp(ab3ea8c9499542ae9bef866e6cf1af52) complete. Timing: real 0.067s	user 0.030s	sys 0.020s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":23915,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:16:32.847772 14216 maintenance_manager.cc:419] P 0aafca2cb24c4b7b879775e574be2df8: Scheduling FlushDeltaMemStoresOp(ab3ea8c9499542ae9bef866e6cf1af52): perf score=2.188937
I20260812 06:16:32.863744 14106 maintenance_manager.cc:643] P 0aafca2cb24c4b7b879775e574be2df8: FlushDeltaMemStoresOp(ab3ea8c9499542ae9bef866e6cf1af52) complete. Timing: real 0.016s	user 0.009s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6271,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:32.864308 14216 maintenance_manager.cc:419] P 0aafca2cb24c4b7b879775e574be2df8: Scheduling MajorDeltaCompactionOp(ab3ea8c9499542ae9bef866e6cf1af52): perf score=1.000000
I20260812 06:16:33.038715 14106 maintenance_manager.cc:643] P 0aafca2cb24c4b7b879775e574be2df8: MajorDeltaCompactionOp(ab3ea8c9499542ae9bef866e6cf1af52) complete. Timing: real 0.174s	user 0.132s	sys 0.035s 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":742,"lbm_read_time_us":13872,"lbm_reads_lt_1ms":572,"lbm_write_time_us":28730,"lbm_writes_lt_1ms":543,"mutex_wait_us":60,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":7936,"update_count":2500}
I20260812 06:16:33.039450 14216 maintenance_manager.cc:419] P 0aafca2cb24c4b7b879775e574be2df8: Scheduling FlushDeltaMemStoresOp(ab3ea8c9499542ae9bef866e6cf1af52): perf score=14.095187
I20260812 06:16:33.093658 14106 maintenance_manager.cc:643] P 0aafca2cb24c4b7b879775e574be2df8: FlushDeltaMemStoresOp(ab3ea8c9499542ae9bef866e6cf1af52) complete. Timing: real 0.054s	user 0.021s	sys 0.024s Metrics: {"bytes_written":16409904,"delete_count":0,"lbm_write_time_us":19595,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:16:33.094177 14216 maintenance_manager.cc:419] P 0aafca2cb24c4b7b879775e574be2df8: Scheduling FlushDeltaMemStoresOp(ab3ea8c9499542ae9bef866e6cf1af52): perf score=2.188937
I20260812 06:16:33.105844 14106 maintenance_manager.cc:643] P 0aafca2cb24c4b7b879775e574be2df8: FlushDeltaMemStoresOp(ab3ea8c9499542ae9bef866e6cf1af52) complete. Timing: real 0.011s	user 0.003s	sys 0.008s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4397,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:33.107479 14216 maintenance_manager.cc:419] P 0aafca2cb24c4b7b879775e574be2df8: Scheduling FlushMRSOp(ab3ea8c9499542ae9bef866e6cf1af52): perf score=1.000000
I20260812 06:16:33.139309 14106 maintenance_manager.cc:643] P 0aafca2cb24c4b7b879775e574be2df8: FlushMRSOp(ab3ea8c9499542ae9bef866e6cf1af52) complete. Timing: real 0.032s	user 0.030s	sys 0.000s Metrics: {"bytes_written":1193507,"cfile_init":1,"dirs.queue_time_us":71,"dirs.run_cpu_time_us":245,"dirs.run_wall_time_us":1601,"drs_written":1,"lbm_read_time_us":59,"lbm_reads_lt_1ms":4,"lbm_write_time_us":2026,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":29}
I20260812 06:16:33.139976 14216 maintenance_manager.cc:419] P 0aafca2cb24c4b7b879775e574be2df8: Scheduling LogGCOp(ab3ea8c9499542ae9bef866e6cf1af52): free 120100582 bytes of WAL
I20260812 06:16:33.140194 14106 log_reader.cc:385] T ab3ea8c9499542ae9bef866e6cf1af52: removed 12 log segments from log reader
I20260812 06:16:33.140255 14106 log.cc:1079] T ab3ea8c9499542ae9bef866e6cf1af52 P 0aafca2cb24c4b7b879775e574be2df8: Deleting log segment in path: /tmp/dist-test-taskNmQegX/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515382905434-13641-0/minicluster-data/ts-0-root/wals/ab3ea8c9499542ae9bef866e6cf1af52/wal-000000028 (ops 133-136)
I20260812 06:16:33.140307 14106 log.cc:1079] T ab3ea8c9499542ae9bef866e6cf1af52 P 0aafca2cb24c4b7b879775e574be2df8: Deleting log segment in path: /tmp/dist-test-taskNmQegX/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515382905434-13641-0/minicluster-data/ts-0-root/wals/ab3ea8c9499542ae9bef866e6cf1af52/wal-000000029 (ops 137-141)
I20260812 06:16:33.140365 14106 log.cc:1079] T ab3ea8c9499542ae9bef866e6cf1af52 P 0aafca2cb24c4b7b879775e574be2df8: Deleting log segment in path: /tmp/dist-test-taskNmQegX/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515382905434-13641-0/minicluster-data/ts-0-root/wals/ab3ea8c9499542ae9bef866e6cf1af52/wal-000000030 (ops 142-146)
I20260812 06:16:33.140416 14106 log.cc:1079] T ab3ea8c9499542ae9bef866e6cf1af52 P 0aafca2cb24c4b7b879775e574be2df8: Deleting log segment in path: /tmp/dist-test-taskNmQegX/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515382905434-13641-0/minicluster-data/ts-0-root/wals/ab3ea8c9499542ae9bef866e6cf1af52/wal-000000031 (ops 147-150)
I20260812 06:16:33.140460 14106 log.cc:1079] T ab3ea8c9499542ae9bef866e6cf1af52 P 0aafca2cb24c4b7b879775e574be2df8: Deleting log segment in path: /tmp/dist-test-taskNmQegX/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515382905434-13641-0/minicluster-data/ts-0-root/wals/ab3ea8c9499542ae9bef866e6cf1af52/wal-000000032 (ops 151-155)
I20260812 06:16:33.140496 14106 log.cc:1079] T ab3ea8c9499542ae9bef866e6cf1af52 P 0aafca2cb24c4b7b879775e574be2df8: Deleting log segment in path: /tmp/dist-test-taskNmQegX/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515382905434-13641-0/minicluster-data/ts-0-root/wals/ab3ea8c9499542ae9bef866e6cf1af52/wal-000000033 (ops 156-160)
I20260812 06:16:33.140533 14106 log.cc:1079] T ab3ea8c9499542ae9bef866e6cf1af52 P 0aafca2cb24c4b7b879775e574be2df8: Deleting log segment in path: /tmp/dist-test-taskNmQegX/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515382905434-13641-0/minicluster-data/ts-0-root/wals/ab3ea8c9499542ae9bef866e6cf1af52/wal-000000034 (ops 161-165)
I20260812 06:16:33.140568 14106 log.cc:1079] T ab3ea8c9499542ae9bef866e6cf1af52 P 0aafca2cb24c4b7b879775e574be2df8: Deleting log segment in path: /tmp/dist-test-taskNmQegX/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515382905434-13641-0/minicluster-data/ts-0-root/wals/ab3ea8c9499542ae9bef866e6cf1af52/wal-000000035 (ops 166-170)
I20260812 06:16:33.140605 14106 log.cc:1079] T ab3ea8c9499542ae9bef866e6cf1af52 P 0aafca2cb24c4b7b879775e574be2df8: Deleting log segment in path: /tmp/dist-test-taskNmQegX/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515382905434-13641-0/minicluster-data/ts-0-root/wals/ab3ea8c9499542ae9bef866e6cf1af52/wal-000000036 (ops 171-174)
I20260812 06:16:33.140650 14106 log.cc:1079] T ab3ea8c9499542ae9bef866e6cf1af52 P 0aafca2cb24c4b7b879775e574be2df8: Deleting log segment in path: /tmp/dist-test-taskNmQegX/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515382905434-13641-0/minicluster-data/ts-0-root/wals/ab3ea8c9499542ae9bef866e6cf1af52/wal-000000037 (ops 175-179)
I20260812 06:16:33.140686 14106 log.cc:1079] T ab3ea8c9499542ae9bef866e6cf1af52 P 0aafca2cb24c4b7b879775e574be2df8: Deleting log segment in path: /tmp/dist-test-taskNmQegX/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515382905434-13641-0/minicluster-data/ts-0-root/wals/ab3ea8c9499542ae9bef866e6cf1af52/wal-000000038 (ops 180-184)
I20260812 06:16:33.140722 14106 log.cc:1079] T ab3ea8c9499542ae9bef866e6cf1af52 P 0aafca2cb24c4b7b879775e574be2df8: Deleting log segment in path: /tmp/dist-test-taskNmQegX/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515382905434-13641-0/minicluster-data/ts-0-root/wals/ab3ea8c9499542ae9bef866e6cf1af52/wal-000000039 (ops 185-189)
I20260812 06:16:33.166879 14106 maintenance_manager.cc:643] P 0aafca2cb24c4b7b879775e574be2df8: LogGCOp(ab3ea8c9499542ae9bef866e6cf1af52) complete. Timing: real 0.027s	user 0.003s	sys 0.023s Metrics: {}
I20260812 06:16:33.167255 14216 maintenance_manager.cc:419] P 0aafca2cb24c4b7b879775e574be2df8: Scheduling FlushDeltaMemStoresOp(ab3ea8c9499542ae9bef866e6cf1af52): perf score=2.188937
I20260812 06:16:33.190311 14106 maintenance_manager.cc:643] P 0aafca2cb24c4b7b879775e574be2df8: FlushDeltaMemStoresOp(ab3ea8c9499542ae9bef866e6cf1af52) complete. Timing: real 0.023s	user 0.009s	sys 0.005s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6104,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:33.190861 14216 maintenance_manager.cc:419] P 0aafca2cb24c4b7b879775e574be2df8: Scheduling FlushDeltaMemStoresOp(ab3ea8c9499542ae9bef866e6cf1af52): perf score=2.188937
I20260812 06:16:33.201471 14106 maintenance_manager.cc:643] P 0aafca2cb24c4b7b879775e574be2df8: FlushDeltaMemStoresOp(ab3ea8c9499542ae9bef866e6cf1af52) complete. Timing: real 0.010s	user 0.009s	sys 0.001s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4047,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:33.202059 14216 maintenance_manager.cc:419] P 0aafca2cb24c4b7b879775e574be2df8: Scheduling MajorDeltaCompactionOp(ab3ea8c9499542ae9bef866e6cf1af52): perf score=1.000000
I20260812 06:16:33.359496 13641 heavy-update-compaction-itest.cc:229] Time spent updating: real 4.816s	user 1.871s	sys 0.117s
I20260812 06:16:33.402025 14106 maintenance_manager.cc:643] P 0aafca2cb24c4b7b879775e574be2df8: MajorDeltaCompactionOp(ab3ea8c9499542ae9bef866e6cf1af52) complete. Timing: real 0.200s	user 0.121s	sys 0.077s Metrics: {"cfile_cache_miss":734,"cfile_cache_miss_bytes":32979752,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"lbm_read_time_us":15336,"lbm_reads_lt_1ms":770,"lbm_write_time_us":36497,"lbm_writes_lt_1ms":743,"peak_mem_usage":87969044,"reinsert_count":0,"spinlock_wait_cycles":1408,"update_count":3500}
I20260812 06:16:33.402513 14216 maintenance_manager.cc:419] P 0aafca2cb24c4b7b879775e574be2df8: Scheduling FlushDeltaMemStoresOp(ab3ea8c9499542ae9bef866e6cf1af52): perf score=14.095187
I20260812 06:16:33.436185 13641 heavy-update-compaction-itest.cc:265] Time spent scanning: real 0.076s	user 0.001s	sys 0.000s
I20260812 06:16:33.436703 13641 tablet_server.cc:179] TabletServer@127.13.82.65:0 shutting down...
I20260812 06:16:33.449872 14106 maintenance_manager.cc:643] P 0aafca2cb24c4b7b879775e574be2df8: FlushDeltaMemStoresOp(ab3ea8c9499542ae9bef866e6cf1af52) complete. Timing: real 0.047s	user 0.027s	sys 0.019s Metrics: {"bytes_written":16409900,"delete_count":0,"lbm_write_time_us":21020,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:16:33.450516 13641 ts_tablet_manager.cc:1507] Shutting down tablet manager...
I20260812 06:16:33.450752 13641 tablet_replica.cc:333] T ab3ea8c9499542ae9bef866e6cf1af52 P 0aafca2cb24c4b7b879775e574be2df8: stopping tablet replica
I20260812 06:16:33.450888 13641 raft_consensus.cc:2243] T ab3ea8c9499542ae9bef866e6cf1af52 P 0aafca2cb24c4b7b879775e574be2df8 [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:16:33.451030 13641 raft_consensus.cc:2272] T ab3ea8c9499542ae9bef866e6cf1af52 P 0aafca2cb24c4b7b879775e574be2df8 [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:16:33.466787 13641 tablet_server.cc:196] TabletServer@127.13.82.65:0 shutdown complete.
I20260812 06:16:33.472364 13641 master.cc:562] Master@127.13.82.126:42181 shutting down...
I20260812 06:16:33.476034 13641 raft_consensus.cc:2243] T 00000000000000000000000000000000 P 2381d032a2c9416ba9941fe21efee686 [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:16:33.476227 13641 raft_consensus.cc:2272] T 00000000000000000000000000000000 P 2381d032a2c9416ba9941fe21efee686 [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:16:33.476315 13641 tablet_replica.cc:333] T 00000000000000000000000000000000 P 2381d032a2c9416ba9941fe21efee686: stopping tablet replica
I20260812 06:16:33.488677 13641 master.cc:584] Master@127.13.82.126:42181 shutdown complete.
[       OK ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/1 (5251 ms)
[----------] 2 tests from EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy (10659 ms total)

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