[==========] Running 2 tests from 1 test suite.
[----------] Global test environment set-up.
[----------] 2 tests from EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy
[ RUN      ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/0
WARNING: Logging before InitGoogleLogging() is written to STDERR
I20260812 06:18:25.015094 26863 internal_mini_cluster.cc:156] Creating distributed mini masters. Addrs: 127.26.59.254:34433
I20260812 06:18:25.016207 26863 env_posix.cc:2285] Not raising this process' open files per process limit of 1048576; it is already as high as it can go
I20260812 06:18:25.016868 26863 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:18:25.023710 26870 instance_detector.cc:116] could not retrieve Azure instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:18:25.023710 26872 instance_detector.cc:116] could not retrieve OpenStack instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:18:25.023978 26869 instance_detector.cc:116] could not retrieve AWS instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:18:25.023798 26863 server_base.cc:1061] running on GCE node
I20260812 06:18:25.024520 26863 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:18:25.024650 26863 system_unsync_time.cc:38] NTP support is disabled. Clock error bounds will not be accurate. This configuration is not suitable for distributed clusters.
I20260812 06:18:25.024717 26863 hybrid_clock.cc:648] HybridClock initialized: now 1786515505024714 us; error 0 us; skew 500 ppm
I20260812 06:18:25.026650 26863 webserver.cc:533] Webserver started at http://127.26.59.254:34661/ using document root <none> and password file <none>
I20260812 06:18:25.027261 26863 fs_manager.cc:362] Metadata directory not provided
I20260812 06:18:25.027360 26863 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:18:25.027632 26863 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:18:25.029379 26863 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskn9P66M/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515505003970-26863-0/minicluster-data/master-0-root/instance:
uuid: "ab4bf59a5cec444da26f0a0a148c317b"
format_stamp: "Formatted at 2026-08-12 06:18:25 on dist-test-slave-njxd"
I20260812 06:18:25.033087 26863 fs_manager.cc:696] Time spent creating directory manager: real 0.003s	user 0.002s	sys 0.000s
I20260812 06:18:25.035425 26877 log_block_manager.cc:4127] Time spent loading block containers with low live blocks: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:18:25.036571 26863 fs_manager.cc:730] Time spent opening block manager: real 0.002s	user 0.002s	sys 0.000s
I20260812 06:18:25.036731 26863 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskn9P66M/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515505003970-26863-0/minicluster-data/master-0-root
uuid: "ab4bf59a5cec444da26f0a0a148c317b"
format_stamp: "Formatted at 2026-08-12 06:18:25 on dist-test-slave-njxd"
I20260812 06:18:25.036851 26863 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskn9P66M/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515505003970-26863-0/minicluster-data/master-0-root
metadata directory: /tmp/dist-test-taskn9P66M/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515505003970-26863-0/minicluster-data/master-0-root
1 data directories: /tmp/dist-test-taskn9P66M/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515505003970-26863-0/minicluster-data/master-0-root/data
Total live blocks: 0
Total live bytes: 0
Total live bytes (after alignment): 0
Total number of LBM containers: 0 (0 full)
Did not check for missing blocks
Did not check for orphaned blocks
Total full LBM containers with extra space: 0 (0 repaired)
Total full LBM container extra space in bytes: 0 (0 repaired)
Total incomplete LBM containers: 0 (0 repaired)
Total LBM partial records: 0 (0 repaired)
Total corrupted LBM metadata records in RocksDB: 0 (0 repaired)
I20260812 06:18:25.052876 26863 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:18:25.053609 26863 env_posix.cc:2285] Not raising this process' running threads per effective uid limit of 18446744073709551615; it is already as high as it can go
I20260812 06:18:25.053813 26863 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:18:25.062207 26863 rpc_server.cc:307] RPC server started. Bound to: 127.26.59.254:34433
I20260812 06:18:25.062209 26939 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.26.59.254:34433 every 8 connection(s)
I20260812 06:18:25.064558 26940 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet 00000000000000000000000000000000. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:18:25.070461 26940 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P ab4bf59a5cec444da26f0a0a148c317b: Bootstrap starting.
I20260812 06:18:25.073024 26940 tablet_bootstrap.cc:654] T 00000000000000000000000000000000 P ab4bf59a5cec444da26f0a0a148c317b: Neither blocks nor log segments found. Creating new log.
I20260812 06:18:25.074100 26940 log.cc:826] T 00000000000000000000000000000000 P ab4bf59a5cec444da26f0a0a148c317b: Log is configured to *not* fsync() on all Append() calls
I20260812 06:18:25.076646 26940 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P ab4bf59a5cec444da26f0a0a148c317b: No bootstrap required, opened a new log
I20260812 06:18:25.080804 26940 raft_consensus.cc:359] T 00000000000000000000000000000000 P ab4bf59a5cec444da26f0a0a148c317b [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "ab4bf59a5cec444da26f0a0a148c317b" member_type: VOTER }
I20260812 06:18:25.080993 26940 raft_consensus.cc:385] T 00000000000000000000000000000000 P ab4bf59a5cec444da26f0a0a148c317b [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:18:25.081092 26940 raft_consensus.cc:740] T 00000000000000000000000000000000 P ab4bf59a5cec444da26f0a0a148c317b [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: ab4bf59a5cec444da26f0a0a148c317b, State: Initialized, Role: FOLLOWER
I20260812 06:18:25.081838 26940 consensus_queue.cc:260] T 00000000000000000000000000000000 P ab4bf59a5cec444da26f0a0a148c317b [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: "ab4bf59a5cec444da26f0a0a148c317b" member_type: VOTER }
I20260812 06:18:25.082026 26940 raft_consensus.cc:399] T 00000000000000000000000000000000 P ab4bf59a5cec444da26f0a0a148c317b [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:18:25.082118 26940 raft_consensus.cc:493] T 00000000000000000000000000000000 P ab4bf59a5cec444da26f0a0a148c317b [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:18:25.082264 26940 raft_consensus.cc:3060] T 00000000000000000000000000000000 P ab4bf59a5cec444da26f0a0a148c317b [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:18:25.083151 26940 raft_consensus.cc:515] T 00000000000000000000000000000000 P ab4bf59a5cec444da26f0a0a148c317b [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "ab4bf59a5cec444da26f0a0a148c317b" member_type: VOTER }
I20260812 06:18:25.083638 26940 leader_election.cc:304] T 00000000000000000000000000000000 P ab4bf59a5cec444da26f0a0a148c317b [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: ab4bf59a5cec444da26f0a0a148c317b; no voters: 
I20260812 06:18:25.084003 26940 leader_election.cc:290] T 00000000000000000000000000000000 P ab4bf59a5cec444da26f0a0a148c317b [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:18:25.084204 26944 raft_consensus.cc:2804] T 00000000000000000000000000000000 P ab4bf59a5cec444da26f0a0a148c317b [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:18:25.084471 26944 raft_consensus.cc:697] T 00000000000000000000000000000000 P ab4bf59a5cec444da26f0a0a148c317b [term 1 LEADER]: Becoming Leader. State: Replica: ab4bf59a5cec444da26f0a0a148c317b, State: Running, Role: LEADER
I20260812 06:18:25.084932 26944 consensus_queue.cc:237] T 00000000000000000000000000000000 P ab4bf59a5cec444da26f0a0a148c317b [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: "ab4bf59a5cec444da26f0a0a148c317b" member_type: VOTER }
I20260812 06:18:25.085058 26940 sys_catalog.cc:565] T 00000000000000000000000000000000 P ab4bf59a5cec444da26f0a0a148c317b [sys.catalog]: configured and running, proceeding with master startup.
I20260812 06:18:25.086913 26946 sys_catalog.cc:455] T 00000000000000000000000000000000 P ab4bf59a5cec444da26f0a0a148c317b [sys.catalog]: SysCatalogTable state changed. Reason: New leader ab4bf59a5cec444da26f0a0a148c317b. Latest consensus state: current_term: 1 leader_uuid: "ab4bf59a5cec444da26f0a0a148c317b" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "ab4bf59a5cec444da26f0a0a148c317b" member_type: VOTER } }
I20260812 06:18:25.086957 26945 sys_catalog.cc:455] T 00000000000000000000000000000000 P ab4bf59a5cec444da26f0a0a148c317b [sys.catalog]: SysCatalogTable state changed. Reason: RaftConsensus started. Latest consensus state: current_term: 1 leader_uuid: "ab4bf59a5cec444da26f0a0a148c317b" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "ab4bf59a5cec444da26f0a0a148c317b" member_type: VOTER } }
I20260812 06:18:25.087044 26946 sys_catalog.cc:458] T 00000000000000000000000000000000 P ab4bf59a5cec444da26f0a0a148c317b [sys.catalog]: This master's current role is: LEADER
I20260812 06:18:25.087071 26945 sys_catalog.cc:458] T 00000000000000000000000000000000 P ab4bf59a5cec444da26f0a0a148c317b [sys.catalog]: This master's current role is: LEADER
I20260812 06:18:25.087625 26863 internal_mini_cluster.cc:184] Waiting to initialize catalog manager on master 0
W20260812 06:18:25.089874 26959 catalog_manager.cc:1594] T 00000000000000000000000000000000 P ab4bf59a5cec444da26f0a0a148c317b: loading cluster ID for follower catalog manager: Not found: cluster ID entry not found
W20260812 06:18:25.089942 26959 catalog_manager.cc:883] Not found: cluster ID entry not found: failed to prepare follower catalog manager, will retry
I20260812 06:18:25.090029 26955 catalog_manager.cc:1511] Loading table and tablet metadata into memory...
I20260812 06:18:25.090806 26955 catalog_manager.cc:1520] Initializing Kudu cluster ID...
I20260812 06:18:25.095963 26955 catalog_manager.cc:1383] Generated new cluster ID: d1296641743544c88c78dd9cf1fb6423
I20260812 06:18:25.096055 26955 catalog_manager.cc:1531] Initializing Kudu internal certificate authority...
I20260812 06:18:25.116207 26955 catalog_manager.cc:1406] Generated new certificate authority record
I20260812 06:18:25.117156 26955 catalog_manager.cc:1540] Loading token signing keys...
I20260812 06:18:25.122638 26955 catalog_manager.cc:6092] T 00000000000000000000000000000000 P ab4bf59a5cec444da26f0a0a148c317b: Generated new TSK 0
I20260812 06:18:25.123375 26955 catalog_manager.cc:1550] Initializing in-progress tserver states...
I20260812 06:18:25.152746 26863 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:18:25.155975 26964 instance_detector.cc:116] could not retrieve Azure instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:18:25.155979 26963 instance_detector.cc:116] could not retrieve AWS instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:18:25.156307 26863 server_base.cc:1061] running on GCE node
W20260812 06:18:25.156306 26966 instance_detector.cc:116] could not retrieve OpenStack instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:18:25.156632 26863 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:18:25.156706 26863 system_unsync_time.cc:38] NTP support is disabled. Clock error bounds will not be accurate. This configuration is not suitable for distributed clusters.
I20260812 06:18:25.156731 26863 hybrid_clock.cc:648] HybridClock initialized: now 1786515505156731 us; error 0 us; skew 500 ppm
I20260812 06:18:25.157742 26863 webserver.cc:533] Webserver started at http://127.26.59.193:33859/ using document root <none> and password file <none>
I20260812 06:18:25.157917 26863 fs_manager.cc:362] Metadata directory not provided
I20260812 06:18:25.157974 26863 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:18:25.158052 26863 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:18:25.158481 26863 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskn9P66M/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515505003970-26863-0/minicluster-data/ts-0-root/instance:
uuid: "52c654370626484fa8e52950b6feff61"
format_stamp: "Formatted at 2026-08-12 06:18:25 on dist-test-slave-njxd"
I20260812 06:18:25.160422 26863 fs_manager.cc:696] Time spent creating directory manager: real 0.002s	user 0.002s	sys 0.000s
I20260812 06:18:25.161705 26971 log_block_manager.cc:4127] Time spent loading block containers with low live blocks: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:18:25.162073 26863 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.001s	sys 0.000s
I20260812 06:18:25.162241 26863 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskn9P66M/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515505003970-26863-0/minicluster-data/ts-0-root
uuid: "52c654370626484fa8e52950b6feff61"
format_stamp: "Formatted at 2026-08-12 06:18:25 on dist-test-slave-njxd"
I20260812 06:18:25.162346 26863 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskn9P66M/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515505003970-26863-0/minicluster-data/ts-0-root
metadata directory: /tmp/dist-test-taskn9P66M/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515505003970-26863-0/minicluster-data/ts-0-root
1 data directories: /tmp/dist-test-taskn9P66M/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515505003970-26863-0/minicluster-data/ts-0-root/data
Total live blocks: 0
Total live bytes: 0
Total live bytes (after alignment): 0
Total number of LBM containers: 0 (0 full)
Did not check for missing blocks
Did not check for orphaned blocks
Total full LBM containers with extra space: 0 (0 repaired)
Total full LBM container extra space in bytes: 0 (0 repaired)
Total incomplete LBM containers: 0 (0 repaired)
Total LBM partial records: 0 (0 repaired)
Total corrupted LBM metadata records in RocksDB: 0 (0 repaired)
I20260812 06:18:25.171557 26863 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:18:25.172071 26863 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:18:25.172643 26863 txn_system_client.cc:432] TxnSystemClient initialization is disabled...
I20260812 06:18:25.173674 26863 ts_tablet_manager.cc:585] Loaded tablet metadata (0 total tablets, 0 live tablets)
I20260812 06:18:25.173748 26863 ts_tablet_manager.cc:531] Time spent load tablet metadata: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:18:25.173806 26863 ts_tablet_manager.cc:616] Registered 0 tablets
I20260812 06:18:25.173837 26863 ts_tablet_manager.cc:595] Time spent register tablets: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:18:25.180889 26863 rpc_server.cc:307] RPC server started. Bound to: 127.26.59.193:34759
I20260812 06:18:25.180922 27042 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.26.59.193:34759 every 8 connection(s)
I20260812 06:18:25.191769 27044 heartbeater.cc:344] Connected to a master server at 127.26.59.254:34433
I20260812 06:18:25.192062 27044 heartbeater.cc:461] Registering TS with master...
I20260812 06:18:25.192525 27044 heartbeater.cc:507] Master 127.26.59.254:34433 requested a full tablet report, sending...
I20260812 06:18:25.194183 26898 ts_manager.cc:194] Registered new tserver with Master: 52c654370626484fa8e52950b6feff61 (127.26.59.193:34759)
I20260812 06:18:25.194243 26863 internal_mini_cluster.cc:371] 1 TS(s) registered with all masters after 0.012577766s
I20260812 06:18:25.195773 26898 master_service.cc:502] Signed X509 certificate for tserver {username='slave'} at 127.0.0.1:45992
I20260812 06:18:25.205050 26898 catalog_manager.cc:2283] Servicing CreateTable request from {username='slave'} at 127.0.0.1:46002:
name: "heavy-update-compaction-test"
schema {
  columns {
    name: "key"
    type: INT64
    is_key: true
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_a"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_b"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_c"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_d"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_e"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
}
num_replicas: 1
split_rows_range_bounds {
}
partition_schema {
  range_schema {
  }
}
I20260812 06:18:25.221946 27000 tablet_service.cc:1511] Processing CreateTablet for tablet dde6a5ea3c6a4e55ab79a2fc194788cd (DEFAULT_TABLE table=heavy-update-compaction-test [id=3a3afa1b339540dda1001af35fc6351e]), partition=
I20260812 06:18:25.222433 27000 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet dde6a5ea3c6a4e55ab79a2fc194788cd. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:18:25.225409 27059 tablet_bootstrap.cc:492] T dde6a5ea3c6a4e55ab79a2fc194788cd P 52c654370626484fa8e52950b6feff61: Bootstrap starting.
I20260812 06:18:25.226481 27059 tablet_bootstrap.cc:654] T dde6a5ea3c6a4e55ab79a2fc194788cd P 52c654370626484fa8e52950b6feff61: Neither blocks nor log segments found. Creating new log.
I20260812 06:18:25.227855 27059 tablet_bootstrap.cc:492] T dde6a5ea3c6a4e55ab79a2fc194788cd P 52c654370626484fa8e52950b6feff61: No bootstrap required, opened a new log
I20260812 06:18:25.227998 27059 ts_tablet_manager.cc:1403] T dde6a5ea3c6a4e55ab79a2fc194788cd P 52c654370626484fa8e52950b6feff61: Time spent bootstrapping tablet: real 0.003s	user 0.002s	sys 0.000s
I20260812 06:18:25.228677 27059 raft_consensus.cc:359] T dde6a5ea3c6a4e55ab79a2fc194788cd P 52c654370626484fa8e52950b6feff61 [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "52c654370626484fa8e52950b6feff61" member_type: VOTER last_known_addr { host: "127.26.59.193" port: 34759 } }
I20260812 06:18:25.228930 27059 raft_consensus.cc:385] T dde6a5ea3c6a4e55ab79a2fc194788cd P 52c654370626484fa8e52950b6feff61 [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:18:25.229034 27059 raft_consensus.cc:740] T dde6a5ea3c6a4e55ab79a2fc194788cd P 52c654370626484fa8e52950b6feff61 [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: 52c654370626484fa8e52950b6feff61, State: Initialized, Role: FOLLOWER
I20260812 06:18:25.229279 27059 consensus_queue.cc:260] T dde6a5ea3c6a4e55ab79a2fc194788cd P 52c654370626484fa8e52950b6feff61 [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: "52c654370626484fa8e52950b6feff61" member_type: VOTER last_known_addr { host: "127.26.59.193" port: 34759 } }
I20260812 06:18:25.229393 27059 raft_consensus.cc:399] T dde6a5ea3c6a4e55ab79a2fc194788cd P 52c654370626484fa8e52950b6feff61 [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:18:25.229449 27059 raft_consensus.cc:493] T dde6a5ea3c6a4e55ab79a2fc194788cd P 52c654370626484fa8e52950b6feff61 [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:18:25.229506 27059 raft_consensus.cc:3060] T dde6a5ea3c6a4e55ab79a2fc194788cd P 52c654370626484fa8e52950b6feff61 [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:18:25.230362 27059 raft_consensus.cc:515] T dde6a5ea3c6a4e55ab79a2fc194788cd P 52c654370626484fa8e52950b6feff61 [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "52c654370626484fa8e52950b6feff61" member_type: VOTER last_known_addr { host: "127.26.59.193" port: 34759 } }
I20260812 06:18:25.230533 27059 leader_election.cc:304] T dde6a5ea3c6a4e55ab79a2fc194788cd P 52c654370626484fa8e52950b6feff61 [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: 52c654370626484fa8e52950b6feff61; no voters: 
I20260812 06:18:25.230806 27059 leader_election.cc:290] T dde6a5ea3c6a4e55ab79a2fc194788cd P 52c654370626484fa8e52950b6feff61 [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:18:25.230918 27061 raft_consensus.cc:2804] T dde6a5ea3c6a4e55ab79a2fc194788cd P 52c654370626484fa8e52950b6feff61 [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:18:25.231169 27061 raft_consensus.cc:697] T dde6a5ea3c6a4e55ab79a2fc194788cd P 52c654370626484fa8e52950b6feff61 [term 1 LEADER]: Becoming Leader. State: Replica: 52c654370626484fa8e52950b6feff61, State: Running, Role: LEADER
I20260812 06:18:25.231431 27044 heartbeater.cc:499] Master 127.26.59.254:34433 was elected leader, sending a full tablet report...
I20260812 06:18:25.231392 27061 consensus_queue.cc:237] T dde6a5ea3c6a4e55ab79a2fc194788cd P 52c654370626484fa8e52950b6feff61 [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: "52c654370626484fa8e52950b6feff61" member_type: VOTER last_known_addr { host: "127.26.59.193" port: 34759 } }
I20260812 06:18:25.231200 27059 ts_tablet_manager.cc:1434] T dde6a5ea3c6a4e55ab79a2fc194788cd P 52c654370626484fa8e52950b6feff61: Time spent starting tablet: real 0.003s	user 0.001s	sys 0.003s
I20260812 06:18:25.234390 26898 catalog_manager.cc:5719] T dde6a5ea3c6a4e55ab79a2fc194788cd P 52c654370626484fa8e52950b6feff61 reported cstate change: term changed from 0 to 1, leader changed from <none> to 52c654370626484fa8e52950b6feff61 (127.26.59.193). New cstate: current_term: 1 leader_uuid: "52c654370626484fa8e52950b6feff61" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "52c654370626484fa8e52950b6feff61" member_type: VOTER last_known_addr { host: "127.26.59.193" port: 34759 } health_report { overall_health: HEALTHY } } }
I20260812 06:18:25.303699 26863 heavy-update-compaction-itest.cc:215] Time spent inserting: real 0.062s	user 0.022s	sys 0.000s
I20260812 06:18:25.432149 27047 maintenance_manager.cc:419] P 52c654370626484fa8e52950b6feff61: Scheduling FlushMRSOp(dde6a5ea3c6a4e55ab79a2fc194788cd): perf score=15.086190
I20260812 06:18:25.600538 26976 maintenance_manager.cc:643] P 52c654370626484fa8e52950b6feff61: FlushMRSOp(dde6a5ea3c6a4e55ab79a2fc194788cd) complete. Timing: real 0.168s	user 0.128s	sys 0.036s Metrics: {"bytes_written":12307493,"cfile_init":1,"compiler_manager_pool.queue_time_us":222,"delete_count":0,"dirs.queue_time_us":57,"dirs.run_cpu_time_us":232,"dirs.run_wall_time_us":1041,"drs_written":1,"lbm_read_time_us":75,"lbm_reads_lt_1ms":4,"lbm_write_time_us":43071,"lbm_writes_lt_1ms":667,"mutex_wait_us":213,"peak_mem_usage":0,"reinsert_count":0,"rows_written":104,"spinlock_wait_cycles":479104,"thread_start_us":150,"threads_started":1,"update_count":1500}
I20260812 06:18:25.601833 27047 maintenance_manager.cc:419] P 52c654370626484fa8e52950b6feff61: Scheduling LogGCOp(dde6a5ea3c6a4e55ab79a2fc194788cd): free 20743880 bytes of WAL
I20260812 06:18:25.602144 26976 log_reader.cc:385] T dde6a5ea3c6a4e55ab79a2fc194788cd: removed 2 log segments from log reader
I20260812 06:18:25.602200 26976 log.cc:1079] T dde6a5ea3c6a4e55ab79a2fc194788cd P 52c654370626484fa8e52950b6feff61: Deleting log segment in path: /tmp/dist-test-taskn9P66M/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515505003970-26863-0/minicluster-data/ts-0-root/wals/dde6a5ea3c6a4e55ab79a2fc194788cd/wal-000000001 (ops 1-6)
I20260812 06:18:25.602250 26976 log.cc:1079] T dde6a5ea3c6a4e55ab79a2fc194788cd P 52c654370626484fa8e52950b6feff61: Deleting log segment in path: /tmp/dist-test-taskn9P66M/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515505003970-26863-0/minicluster-data/ts-0-root/wals/dde6a5ea3c6a4e55ab79a2fc194788cd/wal-000000002 (ops 7-11)
I20260812 06:18:25.607677 26976 maintenance_manager.cc:643] P 52c654370626484fa8e52950b6feff61: LogGCOp(dde6a5ea3c6a4e55ab79a2fc194788cd) complete. Timing: real 0.006s	user 0.000s	sys 0.004s Metrics: {}
I20260812 06:18:25.608033 27047 maintenance_manager.cc:419] P 52c654370626484fa8e52950b6feff61: Scheduling FlushDeltaMemStoresOp(dde6a5ea3c6a4e55ab79a2fc194788cd): perf score=2.188937
I20260812 06:18:25.622427 26976 maintenance_manager.cc:643] P 52c654370626484fa8e52950b6feff61: FlushDeltaMemStoresOp(dde6a5ea3c6a4e55ab79a2fc194788cd) complete. Timing: real 0.014s	user 0.005s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5481,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:25.622879 27047 maintenance_manager.cc:419] P 52c654370626484fa8e52950b6feff61: Scheduling UndoDeltaBlockGCOp(dde6a5ea3c6a4e55ab79a2fc194788cd): 12719216 bytes on disk
I20260812 06:18:25.623451 26976 maintenance_manager.cc:643] P 52c654370626484fa8e52950b6feff61: UndoDeltaBlockGCOp(dde6a5ea3c6a4e55ab79a2fc194788cd) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":69,"lbm_reads_lt_1ms":4}
I20260812 06:18:25.623867 27047 maintenance_manager.cc:419] P 52c654370626484fa8e52950b6feff61: Scheduling FlushDeltaMemStoresOp(dde6a5ea3c6a4e55ab79a2fc194788cd): perf score=2.188937
I20260812 06:18:25.636579 26976 maintenance_manager.cc:643] P 52c654370626484fa8e52950b6feff61: FlushDeltaMemStoresOp(dde6a5ea3c6a4e55ab79a2fc194788cd) complete. Timing: real 0.013s	user 0.007s	sys 0.003s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":4881,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:18:25.637033 27047 maintenance_manager.cc:419] P 52c654370626484fa8e52950b6feff61: Scheduling MajorDeltaCompactionOp(dde6a5ea3c6a4e55ab79a2fc194788cd): perf score=1.000000
I20260812 06:18:25.815918 26976 maintenance_manager.cc:643] P 52c654370626484fa8e52950b6feff61: MajorDeltaCompactionOp(dde6a5ea3c6a4e55ab79a2fc194788cd) complete. Timing: real 0.179s	user 0.120s	sys 0.056s Metrics: {"cfile_cache_miss":523,"cfile_cache_miss_bytes":24364557,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":852,"lbm_read_time_us":11685,"lbm_reads_lt_1ms":559,"lbm_write_time_us":32984,"lbm_writes_lt_1ms":533,"peak_mem_usage":61665166,"reinsert_count":0,"thread_start_us":391,"threads_started":5,"update_count":2450}
I20260812 06:18:25.816536 27047 maintenance_manager.cc:419] P 52c654370626484fa8e52950b6feff61: Scheduling FlushDeltaMemStoresOp(dde6a5ea3c6a4e55ab79a2fc194788cd): perf score=10.126437
I20260812 06:18:25.851840 26976 maintenance_manager.cc:643] P 52c654370626484fa8e52950b6feff61: FlushDeltaMemStoresOp(dde6a5ea3c6a4e55ab79a2fc194788cd) complete. Timing: real 0.035s	user 0.006s	sys 0.024s Metrics: {"bytes_written":12307489,"delete_count":0,"lbm_write_time_us":14436,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:18:25.852437 27047 maintenance_manager.cc:419] P 52c654370626484fa8e52950b6feff61: Scheduling FlushDeltaMemStoresOp(dde6a5ea3c6a4e55ab79a2fc194788cd): perf score=2.188937
I20260812 06:18:25.868130 26976 maintenance_manager.cc:643] P 52c654370626484fa8e52950b6feff61: FlushDeltaMemStoresOp(dde6a5ea3c6a4e55ab79a2fc194788cd) complete. Timing: real 0.016s	user 0.013s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5898,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:25.868749 27047 maintenance_manager.cc:419] P 52c654370626484fa8e52950b6feff61: Scheduling MajorDeltaCompactionOp(dde6a5ea3c6a4e55ab79a2fc194788cd): perf score=1.000000
I20260812 06:18:25.996522 26976 maintenance_manager.cc:643] P 52c654370626484fa8e52950b6feff61: MajorDeltaCompactionOp(dde6a5ea3c6a4e55ab79a2fc194788cd) complete. Timing: real 0.128s	user 0.103s	sys 0.024s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672276,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":1107,"lbm_read_time_us":8830,"lbm_reads_lt_1ms":472,"lbm_write_time_us":24701,"lbm_writes_lt_1ms":443,"mutex_wait_us":360,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":18688,"update_count":2000}
I20260812 06:18:25.997238 27047 maintenance_manager.cc:419] P 52c654370626484fa8e52950b6feff61: Scheduling FlushDeltaMemStoresOp(dde6a5ea3c6a4e55ab79a2fc194788cd): perf score=10.126437
I20260812 06:18:26.042222 26976 maintenance_manager.cc:643] P 52c654370626484fa8e52950b6feff61: FlushDeltaMemStoresOp(dde6a5ea3c6a4e55ab79a2fc194788cd) complete. Timing: real 0.045s	user 0.024s	sys 0.015s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":17913,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:18:26.042680 27047 maintenance_manager.cc:419] P 52c654370626484fa8e52950b6feff61: Scheduling FlushDeltaMemStoresOp(dde6a5ea3c6a4e55ab79a2fc194788cd): perf score=2.188937
I20260812 06:18:26.053720 26976 maintenance_manager.cc:643] P 52c654370626484fa8e52950b6feff61: FlushDeltaMemStoresOp(dde6a5ea3c6a4e55ab79a2fc194788cd) complete. Timing: real 0.011s	user 0.007s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4251,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:26.054450 27047 maintenance_manager.cc:419] P 52c654370626484fa8e52950b6feff61: Scheduling MajorDeltaCompactionOp(dde6a5ea3c6a4e55ab79a2fc194788cd): perf score=1.000000
I20260812 06:18:26.186293 26976 maintenance_manager.cc:643] P 52c654370626484fa8e52950b6feff61: MajorDeltaCompactionOp(dde6a5ea3c6a4e55ab79a2fc194788cd) complete. Timing: real 0.132s	user 0.111s	sys 0.020s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672277,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":293,"lbm_read_time_us":10514,"lbm_reads_lt_1ms":472,"lbm_write_time_us":24970,"lbm_writes_lt_1ms":443,"mutex_wait_us":68,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":29440,"update_count":2000}
I20260812 06:18:26.186951 27047 maintenance_manager.cc:419] P 52c654370626484fa8e52950b6feff61: Scheduling FlushDeltaMemStoresOp(dde6a5ea3c6a4e55ab79a2fc194788cd): perf score=10.126437
I20260812 06:18:26.241765 26976 maintenance_manager.cc:643] P 52c654370626484fa8e52950b6feff61: FlushDeltaMemStoresOp(dde6a5ea3c6a4e55ab79a2fc194788cd) complete. Timing: real 0.055s	user 0.027s	sys 0.023s Metrics: {"bytes_written":12307491,"delete_count":0,"lbm_write_time_us":18405,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:18:26.242321 27047 maintenance_manager.cc:419] P 52c654370626484fa8e52950b6feff61: Scheduling FlushDeltaMemStoresOp(dde6a5ea3c6a4e55ab79a2fc194788cd): perf score=2.188937
I20260812 06:18:26.253242 26976 maintenance_manager.cc:643] P 52c654370626484fa8e52950b6feff61: FlushDeltaMemStoresOp(dde6a5ea3c6a4e55ab79a2fc194788cd) complete. Timing: real 0.011s	user 0.005s	sys 0.004s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4226,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:26.253762 27047 maintenance_manager.cc:419] P 52c654370626484fa8e52950b6feff61: Scheduling MajorDeltaCompactionOp(dde6a5ea3c6a4e55ab79a2fc194788cd): perf score=1.000000
I20260812 06:18:26.412569 26976 maintenance_manager.cc:643] P 52c654370626484fa8e52950b6feff61: MajorDeltaCompactionOp(dde6a5ea3c6a4e55ab79a2fc194788cd) complete. Timing: real 0.159s	user 0.103s	sys 0.044s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672277,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":1228,"lbm_read_time_us":10677,"lbm_reads_lt_1ms":472,"lbm_write_time_us":25595,"lbm_writes_lt_1ms":443,"mutex_wait_us":384,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":768,"update_count":2000}
I20260812 06:18:26.415565 27047 maintenance_manager.cc:419] P 52c654370626484fa8e52950b6feff61: Scheduling FlushDeltaMemStoresOp(dde6a5ea3c6a4e55ab79a2fc194788cd): perf score=10.126437
I20260812 06:18:26.458506 26976 maintenance_manager.cc:643] P 52c654370626484fa8e52950b6feff61: FlushDeltaMemStoresOp(dde6a5ea3c6a4e55ab79a2fc194788cd) complete. Timing: real 0.043s	user 0.014s	sys 0.024s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":19136,"lbm_writes_1-10_ms":2,"lbm_writes_lt_1ms":301,"reinsert_count":0,"update_count":1500}
I20260812 06:18:26.458984 27047 maintenance_manager.cc:419] P 52c654370626484fa8e52950b6feff61: Scheduling FlushDeltaMemStoresOp(dde6a5ea3c6a4e55ab79a2fc194788cd): perf score=2.188937
I20260812 06:18:26.470525 26976 maintenance_manager.cc:643] P 52c654370626484fa8e52950b6feff61: FlushDeltaMemStoresOp(dde6a5ea3c6a4e55ab79a2fc194788cd) complete. Timing: real 0.011s	user 0.005s	sys 0.005s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4371,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:26.471115 27047 maintenance_manager.cc:419] P 52c654370626484fa8e52950b6feff61: Scheduling MajorDeltaCompactionOp(dde6a5ea3c6a4e55ab79a2fc194788cd): perf score=1.000000
I20260812 06:18:26.601931 26976 maintenance_manager.cc:643] P 52c654370626484fa8e52950b6feff61: MajorDeltaCompactionOp(dde6a5ea3c6a4e55ab79a2fc194788cd) complete. Timing: real 0.131s	user 0.105s	sys 0.025s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672277,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":417,"lbm_read_time_us":10064,"lbm_reads_lt_1ms":472,"lbm_write_time_us":25501,"lbm_writes_lt_1ms":443,"mutex_wait_us":56,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":16640,"update_count":2000}
I20260812 06:18:26.602538 27047 maintenance_manager.cc:419] P 52c654370626484fa8e52950b6feff61: Scheduling FlushDeltaMemStoresOp(dde6a5ea3c6a4e55ab79a2fc194788cd): perf score=10.126437
I20260812 06:18:26.641881 26976 maintenance_manager.cc:643] P 52c654370626484fa8e52950b6feff61: FlushDeltaMemStoresOp(dde6a5ea3c6a4e55ab79a2fc194788cd) complete. Timing: real 0.039s	user 0.023s	sys 0.016s Metrics: {"bytes_written":12307489,"delete_count":0,"lbm_write_time_us":17409,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:18:26.642432 27047 maintenance_manager.cc:419] P 52c654370626484fa8e52950b6feff61: Scheduling FlushDeltaMemStoresOp(dde6a5ea3c6a4e55ab79a2fc194788cd): perf score=2.188937
I20260812 06:18:26.655623 26976 maintenance_manager.cc:643] P 52c654370626484fa8e52950b6feff61: FlushDeltaMemStoresOp(dde6a5ea3c6a4e55ab79a2fc194788cd) complete. Timing: real 0.013s	user 0.001s	sys 0.009s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4497,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:26.656152 27047 maintenance_manager.cc:419] P 52c654370626484fa8e52950b6feff61: Scheduling MajorDeltaCompactionOp(dde6a5ea3c6a4e55ab79a2fc194788cd): perf score=1.000000
I20260812 06:18:26.785497 26976 maintenance_manager.cc:643] P 52c654370626484fa8e52950b6feff61: MajorDeltaCompactionOp(dde6a5ea3c6a4e55ab79a2fc194788cd) complete. Timing: real 0.129s	user 0.112s	sys 0.017s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672276,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":143,"lbm_read_time_us":8610,"lbm_reads_lt_1ms":472,"lbm_write_time_us":23254,"lbm_writes_lt_1ms":443,"mutex_wait_us":28,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":1280,"update_count":2000}
I20260812 06:18:26.789506 27047 maintenance_manager.cc:419] P 52c654370626484fa8e52950b6feff61: Scheduling FlushDeltaMemStoresOp(dde6a5ea3c6a4e55ab79a2fc194788cd): perf score=10.126437
I20260812 06:18:26.837401 26976 maintenance_manager.cc:643] P 52c654370626484fa8e52950b6feff61: FlushDeltaMemStoresOp(dde6a5ea3c6a4e55ab79a2fc194788cd) complete. Timing: real 0.047s	user 0.029s	sys 0.015s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":19063,"lbm_writes_1-10_ms":2,"lbm_writes_lt_1ms":301,"reinsert_count":0,"update_count":1500}
I20260812 06:18:26.838148 27047 maintenance_manager.cc:419] P 52c654370626484fa8e52950b6feff61: Scheduling FlushDeltaMemStoresOp(dde6a5ea3c6a4e55ab79a2fc194788cd): perf score=2.188937
I20260812 06:18:26.853892 26976 maintenance_manager.cc:643] P 52c654370626484fa8e52950b6feff61: FlushDeltaMemStoresOp(dde6a5ea3c6a4e55ab79a2fc194788cd) complete. Timing: real 0.016s	user 0.009s	sys 0.006s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":5853,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:26.854573 27047 maintenance_manager.cc:419] P 52c654370626484fa8e52950b6feff61: Scheduling FlushMRSOp(dde6a5ea3c6a4e55ab79a2fc194788cd): perf score=1.000000
I20260812 06:18:26.882360 26976 maintenance_manager.cc:643] P 52c654370626484fa8e52950b6feff61: FlushMRSOp(dde6a5ea3c6a4e55ab79a2fc194788cd) complete. Timing: real 0.028s	user 0.025s	sys 0.001s Metrics: {"bytes_written":1193503,"cfile_init":1,"dirs.queue_time_us":61,"dirs.run_cpu_time_us":218,"dirs.run_wall_time_us":1590,"drs_written":1,"lbm_read_time_us":60,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1964,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":29}
I20260812 06:18:26.883244 27047 maintenance_manager.cc:419] P 52c654370626484fa8e52950b6feff61: Scheduling LogGCOp(dde6a5ea3c6a4e55ab79a2fc194788cd): free 111786260 bytes of WAL
I20260812 06:18:26.883538 26976 log_reader.cc:385] T dde6a5ea3c6a4e55ab79a2fc194788cd: removed 11 log segments from log reader
I20260812 06:18:26.883611 26976 log.cc:1079] T dde6a5ea3c6a4e55ab79a2fc194788cd P 52c654370626484fa8e52950b6feff61: Deleting log segment in path: /tmp/dist-test-taskn9P66M/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515505003970-26863-0/minicluster-data/ts-0-root/wals/dde6a5ea3c6a4e55ab79a2fc194788cd/wal-000000003 (ops 12-16)
I20260812 06:18:26.883658 26976 log.cc:1079] T dde6a5ea3c6a4e55ab79a2fc194788cd P 52c654370626484fa8e52950b6feff61: Deleting log segment in path: /tmp/dist-test-taskn9P66M/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515505003970-26863-0/minicluster-data/ts-0-root/wals/dde6a5ea3c6a4e55ab79a2fc194788cd/wal-000000004 (ops 17-20)
I20260812 06:18:26.883692 26976 log.cc:1079] T dde6a5ea3c6a4e55ab79a2fc194788cd P 52c654370626484fa8e52950b6feff61: Deleting log segment in path: /tmp/dist-test-taskn9P66M/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515505003970-26863-0/minicluster-data/ts-0-root/wals/dde6a5ea3c6a4e55ab79a2fc194788cd/wal-000000005 (ops 21-25)
I20260812 06:18:26.883724 26976 log.cc:1079] T dde6a5ea3c6a4e55ab79a2fc194788cd P 52c654370626484fa8e52950b6feff61: Deleting log segment in path: /tmp/dist-test-taskn9P66M/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515505003970-26863-0/minicluster-data/ts-0-root/wals/dde6a5ea3c6a4e55ab79a2fc194788cd/wal-000000006 (ops 26-30)
I20260812 06:18:26.883764 26976 log.cc:1079] T dde6a5ea3c6a4e55ab79a2fc194788cd P 52c654370626484fa8e52950b6feff61: Deleting log segment in path: /tmp/dist-test-taskn9P66M/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515505003970-26863-0/minicluster-data/ts-0-root/wals/dde6a5ea3c6a4e55ab79a2fc194788cd/wal-000000007 (ops 31-35)
I20260812 06:18:26.883790 26976 log.cc:1079] T dde6a5ea3c6a4e55ab79a2fc194788cd P 52c654370626484fa8e52950b6feff61: Deleting log segment in path: /tmp/dist-test-taskn9P66M/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515505003970-26863-0/minicluster-data/ts-0-root/wals/dde6a5ea3c6a4e55ab79a2fc194788cd/wal-000000008 (ops 36-40)
I20260812 06:18:26.883811 26976 log.cc:1079] T dde6a5ea3c6a4e55ab79a2fc194788cd P 52c654370626484fa8e52950b6feff61: Deleting log segment in path: /tmp/dist-test-taskn9P66M/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515505003970-26863-0/minicluster-data/ts-0-root/wals/dde6a5ea3c6a4e55ab79a2fc194788cd/wal-000000009 (ops 41-45)
I20260812 06:18:26.883844 26976 log.cc:1079] T dde6a5ea3c6a4e55ab79a2fc194788cd P 52c654370626484fa8e52950b6feff61: Deleting log segment in path: /tmp/dist-test-taskn9P66M/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515505003970-26863-0/minicluster-data/ts-0-root/wals/dde6a5ea3c6a4e55ab79a2fc194788cd/wal-000000010 (ops 46-50)
I20260812 06:18:26.883872 26976 log.cc:1079] T dde6a5ea3c6a4e55ab79a2fc194788cd P 52c654370626484fa8e52950b6feff61: Deleting log segment in path: /tmp/dist-test-taskn9P66M/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515505003970-26863-0/minicluster-data/ts-0-root/wals/dde6a5ea3c6a4e55ab79a2fc194788cd/wal-000000011 (ops 51-55)
I20260812 06:18:26.883904 26976 log.cc:1079] T dde6a5ea3c6a4e55ab79a2fc194788cd P 52c654370626484fa8e52950b6feff61: Deleting log segment in path: /tmp/dist-test-taskn9P66M/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515505003970-26863-0/minicluster-data/ts-0-root/wals/dde6a5ea3c6a4e55ab79a2fc194788cd/wal-000000012 (ops 56-60)
I20260812 06:18:26.883939 26976 log.cc:1079] T dde6a5ea3c6a4e55ab79a2fc194788cd P 52c654370626484fa8e52950b6feff61: Deleting log segment in path: /tmp/dist-test-taskn9P66M/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515505003970-26863-0/minicluster-data/ts-0-root/wals/dde6a5ea3c6a4e55ab79a2fc194788cd/wal-000000013 (ops 61-64)
I20260812 06:18:26.911900 26976 maintenance_manager.cc:643] P 52c654370626484fa8e52950b6feff61: LogGCOp(dde6a5ea3c6a4e55ab79a2fc194788cd) complete. Timing: real 0.028s	user 0.000s	sys 0.026s Metrics: {}
I20260812 06:18:26.912330 27047 maintenance_manager.cc:419] P 52c654370626484fa8e52950b6feff61: Scheduling UndoDeltaBlockGCOp(dde6a5ea3c6a4e55ab79a2fc194788cd): 462 bytes on disk
I20260812 06:18:26.913021 26976 maintenance_manager.cc:643] P 52c654370626484fa8e52950b6feff61: UndoDeltaBlockGCOp(dde6a5ea3c6a4e55ab79a2fc194788cd) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":101,"lbm_reads_lt_1ms":4}
I20260812 06:18:26.913667 27047 maintenance_manager.cc:419] P 52c654370626484fa8e52950b6feff61: Scheduling FlushDeltaMemStoresOp(dde6a5ea3c6a4e55ab79a2fc194788cd): perf score=2.188937
I20260812 06:18:26.937928 26976 maintenance_manager.cc:643] P 52c654370626484fa8e52950b6feff61: FlushDeltaMemStoresOp(dde6a5ea3c6a4e55ab79a2fc194788cd) complete. Timing: real 0.024s	user 0.012s	sys 0.001s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5196,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:26.938393 27047 maintenance_manager.cc:419] P 52c654370626484fa8e52950b6feff61: Scheduling LogGCOp(dde6a5ea3c6a4e55ab79a2fc194788cd): free 8767118 bytes of WAL
I20260812 06:18:26.938611 26976 log_reader.cc:385] T dde6a5ea3c6a4e55ab79a2fc194788cd: removed 1 log segments from log reader
I20260812 06:18:26.938660 26976 log.cc:1079] T dde6a5ea3c6a4e55ab79a2fc194788cd P 52c654370626484fa8e52950b6feff61: Deleting log segment in path: /tmp/dist-test-taskn9P66M/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515505003970-26863-0/minicluster-data/ts-0-root/wals/dde6a5ea3c6a4e55ab79a2fc194788cd/wal-000000014 (ops 65-69)
I20260812 06:18:26.940416 26976 maintenance_manager.cc:643] P 52c654370626484fa8e52950b6feff61: LogGCOp(dde6a5ea3c6a4e55ab79a2fc194788cd) complete. Timing: real 0.002s	user 0.000s	sys 0.000s Metrics: {}
I20260812 06:18:26.940788 27047 maintenance_manager.cc:419] P 52c654370626484fa8e52950b6feff61: Scheduling FlushDeltaMemStoresOp(dde6a5ea3c6a4e55ab79a2fc194788cd): perf score=2.188937
I20260812 06:18:26.951339 26976 maintenance_manager.cc:643] P 52c654370626484fa8e52950b6feff61: FlushDeltaMemStoresOp(dde6a5ea3c6a4e55ab79a2fc194788cd) complete. Timing: real 0.010s	user 0.004s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3888,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:26.951947 27047 maintenance_manager.cc:419] P 52c654370626484fa8e52950b6feff61: Scheduling MajorDeltaCompactionOp(dde6a5ea3c6a4e55ab79a2fc194788cd): perf score=1.000000
I20260812 06:18:27.164999 26976 maintenance_manager.cc:643] P 52c654370626484fa8e52950b6feff61: MajorDeltaCompactionOp(dde6a5ea3c6a4e55ab79a2fc194788cd) complete. Timing: real 0.213s	user 0.132s	sys 0.080s Metrics: {"cfile_cache_miss":634,"cfile_cache_miss_bytes":28877338,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":1214,"lbm_read_time_us":14371,"lbm_reads_lt_1ms":674,"lbm_write_time_us":37169,"lbm_writes_lt_1ms":643,"mutex_wait_us":577,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":19328,"thread_start_us":83,"threads_started":1,"update_count":3000}
I20260812 06:18:27.165974 27047 maintenance_manager.cc:419] P 52c654370626484fa8e52950b6feff61: Scheduling FlushDeltaMemStoresOp(dde6a5ea3c6a4e55ab79a2fc194788cd): perf score=14.095187
I20260812 06:18:27.224248 26976 maintenance_manager.cc:643] P 52c654370626484fa8e52950b6feff61: FlushDeltaMemStoresOp(dde6a5ea3c6a4e55ab79a2fc194788cd) complete. Timing: real 0.058s	user 0.031s	sys 0.025s Metrics: {"bytes_written":16409903,"delete_count":0,"lbm_write_time_us":25519,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:18:27.224789 27047 maintenance_manager.cc:419] P 52c654370626484fa8e52950b6feff61: Scheduling MajorDeltaCompactionOp(dde6a5ea3c6a4e55ab79a2fc194788cd): perf score=1.000000
I20260812 06:18:27.376694 26976 maintenance_manager.cc:643] P 52c654370626484fa8e52950b6feff61: MajorDeltaCompactionOp(dde6a5ea3c6a4e55ab79a2fc194788cd) complete. Timing: real 0.152s	user 0.112s	sys 0.040s Metrics: {"cfile_cache_miss":431,"cfile_cache_miss_bytes":20672159,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":1,"delta_iterators_relevant":1,"dirs.queue_time_us":538,"lbm_read_time_us":10248,"lbm_reads_lt_1ms":467,"lbm_write_time_us":25530,"lbm_writes_lt_1ms":443,"mutex_wait_us":34,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":21248,"update_count":2000}
I20260812 06:18:27.377502 27047 maintenance_manager.cc:419] P 52c654370626484fa8e52950b6feff61: Scheduling FlushDeltaMemStoresOp(dde6a5ea3c6a4e55ab79a2fc194788cd): perf score=10.126437
I20260812 06:18:27.414803 26976 maintenance_manager.cc:643] P 52c654370626484fa8e52950b6feff61: FlushDeltaMemStoresOp(dde6a5ea3c6a4e55ab79a2fc194788cd) complete. Timing: real 0.037s	user 0.020s	sys 0.016s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":15848,"lbm_writes_lt_1ms":303,"reinsert_count":0,"spinlock_wait_cycles":1280,"update_count":1500}
I20260812 06:18:27.415453 27047 maintenance_manager.cc:419] P 52c654370626484fa8e52950b6feff61: Scheduling FlushDeltaMemStoresOp(dde6a5ea3c6a4e55ab79a2fc194788cd): perf score=2.188937
I20260812 06:18:27.438588 26976 maintenance_manager.cc:643] P 52c654370626484fa8e52950b6feff61: FlushDeltaMemStoresOp(dde6a5ea3c6a4e55ab79a2fc194788cd) complete. Timing: real 0.023s	user 0.008s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4903,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:27.439184 27047 maintenance_manager.cc:419] P 52c654370626484fa8e52950b6feff61: Scheduling FlushDeltaMemStoresOp(dde6a5ea3c6a4e55ab79a2fc194788cd): perf score=2.188937
I20260812 06:18:27.449890 26976 maintenance_manager.cc:643] P 52c654370626484fa8e52950b6feff61: FlushDeltaMemStoresOp(dde6a5ea3c6a4e55ab79a2fc194788cd) complete. Timing: real 0.011s	user 0.006s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4034,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:27.450382 27047 maintenance_manager.cc:419] P 52c654370626484fa8e52950b6feff61: Scheduling MajorDeltaCompactionOp(dde6a5ea3c6a4e55ab79a2fc194788cd): perf score=1.000000
I20260812 06:18:27.631593 26976 maintenance_manager.cc:643] P 52c654370626484fa8e52950b6feff61: MajorDeltaCompactionOp(dde6a5ea3c6a4e55ab79a2fc194788cd) complete. Timing: real 0.181s	user 0.119s	sys 0.057s Metrics: {"cfile_cache_miss":533,"cfile_cache_miss_bytes":24774808,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":573,"lbm_read_time_us":10444,"lbm_reads_lt_1ms":573,"lbm_write_time_us":30078,"lbm_writes_lt_1ms":543,"mutex_wait_us":56,"peak_mem_usage":63115900,"reinsert_count":0,"update_count":2500}
I20260812 06:18:27.632246 27047 maintenance_manager.cc:419] P 52c654370626484fa8e52950b6feff61: Scheduling FlushDeltaMemStoresOp(dde6a5ea3c6a4e55ab79a2fc194788cd): perf score=14.095187
I20260812 06:18:27.681408 26976 maintenance_manager.cc:643] P 52c654370626484fa8e52950b6feff61: FlushDeltaMemStoresOp(dde6a5ea3c6a4e55ab79a2fc194788cd) complete. Timing: real 0.049s	user 0.034s	sys 0.012s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":21718,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:18:27.682066 27047 maintenance_manager.cc:419] P 52c654370626484fa8e52950b6feff61: Scheduling FlushDeltaMemStoresOp(dde6a5ea3c6a4e55ab79a2fc194788cd): perf score=2.188937
I20260812 06:18:27.695794 26976 maintenance_manager.cc:643] P 52c654370626484fa8e52950b6feff61: FlushDeltaMemStoresOp(dde6a5ea3c6a4e55ab79a2fc194788cd) complete. Timing: real 0.013s	user 0.006s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4294,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:27.696339 27047 maintenance_manager.cc:419] P 52c654370626484fa8e52950b6feff61: Scheduling MajorDeltaCompactionOp(dde6a5ea3c6a4e55ab79a2fc194788cd): perf score=1.000000
I20260812 06:18:27.849881 26976 maintenance_manager.cc:643] P 52c654370626484fa8e52950b6feff61: MajorDeltaCompactionOp(dde6a5ea3c6a4e55ab79a2fc194788cd) complete. Timing: real 0.153s	user 0.126s	sys 0.025s 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":728,"lbm_read_time_us":9568,"lbm_reads_lt_1ms":564,"lbm_write_time_us":31866,"lbm_writes_lt_1ms":543,"mutex_wait_us":57,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":10368,"update_count":2500}
I20260812 06:18:27.850586 27047 maintenance_manager.cc:419] P 52c654370626484fa8e52950b6feff61: Scheduling FlushDeltaMemStoresOp(dde6a5ea3c6a4e55ab79a2fc194788cd): perf score=11.118625
I20260812 06:18:27.894876 26976 maintenance_manager.cc:643] P 52c654370626484fa8e52950b6feff61: FlushDeltaMemStoresOp(dde6a5ea3c6a4e55ab79a2fc194788cd) complete. Timing: real 0.044s	user 0.036s	sys 0.005s Metrics: {"bytes_written":12717734,"delete_count":0,"lbm_write_time_us":18677,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":312,"reinsert_count":0,"update_count":1550}
I20260812 06:18:27.895476 27047 maintenance_manager.cc:419] P 52c654370626484fa8e52950b6feff61: Scheduling FlushDeltaMemStoresOp(dde6a5ea3c6a4e55ab79a2fc194788cd): perf score=2.188937
I20260812 06:18:27.914103 26976 maintenance_manager.cc:643] P 52c654370626484fa8e52950b6feff61: FlushDeltaMemStoresOp(dde6a5ea3c6a4e55ab79a2fc194788cd) complete. Timing: real 0.018s	user 0.007s	sys 0.009s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6577,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:27.914669 27047 maintenance_manager.cc:419] P 52c654370626484fa8e52950b6feff61: Scheduling FlushDeltaMemStoresOp(dde6a5ea3c6a4e55ab79a2fc194788cd): perf score=2.188937
I20260812 06:18:27.924553 26976 maintenance_manager.cc:643] P 52c654370626484fa8e52950b6feff61: FlushDeltaMemStoresOp(dde6a5ea3c6a4e55ab79a2fc194788cd) complete. Timing: real 0.010s	user 0.005s	sys 0.003s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3737,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:18:27.925171 27047 maintenance_manager.cc:419] P 52c654370626484fa8e52950b6feff61: Scheduling MajorDeltaCompactionOp(dde6a5ea3c6a4e55ab79a2fc194788cd): perf score=1.000000
I20260812 06:18:28.074023 26976 maintenance_manager.cc:643] P 52c654370626484fa8e52950b6feff61: MajorDeltaCompactionOp(dde6a5ea3c6a4e55ab79a2fc194788cd) complete. Timing: real 0.149s	user 0.112s	sys 0.036s Metrics: {"cfile_cache_miss":533,"cfile_cache_miss_bytes":24774798,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":1042,"lbm_read_time_us":11865,"lbm_reads_lt_1ms":573,"lbm_write_time_us":29231,"lbm_writes_lt_1ms":543,"mutex_wait_us":369,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":10240,"update_count":2500}
I20260812 06:18:28.074677 27047 maintenance_manager.cc:419] P 52c654370626484fa8e52950b6feff61: Scheduling FlushDeltaMemStoresOp(dde6a5ea3c6a4e55ab79a2fc194788cd): perf score=11.118625
I20260812 06:18:28.109385 26976 maintenance_manager.cc:643] P 52c654370626484fa8e52950b6feff61: FlushDeltaMemStoresOp(dde6a5ea3c6a4e55ab79a2fc194788cd) complete. Timing: real 0.035s	user 0.015s	sys 0.016s Metrics: {"bytes_written":12717734,"delete_count":0,"lbm_write_time_us":15192,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:18:28.110005 27047 maintenance_manager.cc:419] P 52c654370626484fa8e52950b6feff61: Scheduling FlushDeltaMemStoresOp(dde6a5ea3c6a4e55ab79a2fc194788cd): perf score=2.188937
I20260812 06:18:28.131088 26976 maintenance_manager.cc:643] P 52c654370626484fa8e52950b6feff61: FlushDeltaMemStoresOp(dde6a5ea3c6a4e55ab79a2fc194788cd) complete. Timing: real 0.021s	user 0.009s	sys 0.004s Metrics: {"bytes_written":3815484,"delete_count":0,"lbm_write_time_us":5496,"lbm_writes_lt_1ms":96,"reinsert_count":0,"update_count":465}
I20260812 06:18:28.131646 27047 maintenance_manager.cc:419] P 52c654370626484fa8e52950b6feff61: Scheduling FlushDeltaMemStoresOp(dde6a5ea3c6a4e55ab79a2fc194788cd): perf score=2.188937
I20260812 06:18:28.146067 26976 maintenance_manager.cc:643] P 52c654370626484fa8e52950b6feff61: FlushDeltaMemStoresOp(dde6a5ea3c6a4e55ab79a2fc194788cd) complete. Timing: real 0.014s	user 0.014s	sys 0.000s Metrics: {"bytes_written":3979584,"delete_count":0,"lbm_write_time_us":5583,"lbm_writes_lt_1ms":100,"reinsert_count":0,"update_count":485}
I20260812 06:18:28.146606 27047 maintenance_manager.cc:419] P 52c654370626484fa8e52950b6feff61: Scheduling MajorDeltaCompactionOp(dde6a5ea3c6a4e55ab79a2fc194788cd): perf score=1.000000
I20260812 06:18:28.304538 26976 maintenance_manager.cc:643] P 52c654370626484fa8e52950b6feff61: MajorDeltaCompactionOp(dde6a5ea3c6a4e55ab79a2fc194788cd) complete. Timing: real 0.158s	user 0.129s	sys 0.027s Metrics: {"cfile_cache_miss":533,"cfile_cache_miss_bytes":24774802,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":376,"lbm_read_time_us":10767,"lbm_reads_lt_1ms":573,"lbm_write_time_us":33057,"lbm_writes_lt_1ms":543,"mutex_wait_us":42,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":20224,"update_count":2500}
I20260812 06:18:28.305070 27047 maintenance_manager.cc:419] P 52c654370626484fa8e52950b6feff61: Scheduling FlushDeltaMemStoresOp(dde6a5ea3c6a4e55ab79a2fc194788cd): perf score=11.118625
I20260812 06:18:28.351892 26976 maintenance_manager.cc:643] P 52c654370626484fa8e52950b6feff61: FlushDeltaMemStoresOp(dde6a5ea3c6a4e55ab79a2fc194788cd) complete. Timing: real 0.047s	user 0.021s	sys 0.023s Metrics: {"bytes_written":12717737,"delete_count":0,"lbm_write_time_us":20207,"lbm_writes_1-10_ms":2,"lbm_writes_lt_1ms":311,"reinsert_count":0,"update_count":1550}
I20260812 06:18:28.352559 27047 maintenance_manager.cc:419] P 52c654370626484fa8e52950b6feff61: Scheduling FlushDeltaMemStoresOp(dde6a5ea3c6a4e55ab79a2fc194788cd): perf score=2.188937
I20260812 06:18:28.373134 26976 maintenance_manager.cc:643] P 52c654370626484fa8e52950b6feff61: FlushDeltaMemStoresOp(dde6a5ea3c6a4e55ab79a2fc194788cd) complete. Timing: real 0.020s	user 0.009s	sys 0.004s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":5720,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:18:28.373677 27047 maintenance_manager.cc:419] P 52c654370626484fa8e52950b6feff61: Scheduling FlushDeltaMemStoresOp(dde6a5ea3c6a4e55ab79a2fc194788cd): perf score=2.188937
I20260812 06:18:28.384366 26976 maintenance_manager.cc:643] P 52c654370626484fa8e52950b6feff61: FlushDeltaMemStoresOp(dde6a5ea3c6a4e55ab79a2fc194788cd) complete. Timing: real 0.011s	user 0.009s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4085,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:28.384873 27047 maintenance_manager.cc:419] P 52c654370626484fa8e52950b6feff61: Scheduling FlushMRSOp(dde6a5ea3c6a4e55ab79a2fc194788cd): perf score=1.000000
I20260812 06:18:28.416391 26976 maintenance_manager.cc:643] P 52c654370626484fa8e52950b6feff61: FlushMRSOp(dde6a5ea3c6a4e55ab79a2fc194788cd) complete. Timing: real 0.031s	user 0.029s	sys 0.000s Metrics: {"bytes_written":1234479,"cfile_init":1,"dirs.queue_time_us":72,"dirs.run_cpu_time_us":297,"dirs.run_wall_time_us":1611,"drs_written":1,"lbm_read_time_us":90,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1920,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":30,"spinlock_wait_cycles":3328}
I20260812 06:18:28.417244 27047 maintenance_manager.cc:419] P 52c654370626484fa8e52950b6feff61: Scheduling LogGCOp(dde6a5ea3c6a4e55ab79a2fc194788cd): free 124257256 bytes of WAL
I20260812 06:18:28.417528 26976 log_reader.cc:385] T dde6a5ea3c6a4e55ab79a2fc194788cd: removed 12 log segments from log reader
I20260812 06:18:28.417631 26976 log.cc:1079] T dde6a5ea3c6a4e55ab79a2fc194788cd P 52c654370626484fa8e52950b6feff61: Deleting log segment in path: /tmp/dist-test-taskn9P66M/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515505003970-26863-0/minicluster-data/ts-0-root/wals/dde6a5ea3c6a4e55ab79a2fc194788cd/wal-000000015 (ops 70-74)
I20260812 06:18:28.417689 26976 log.cc:1079] T dde6a5ea3c6a4e55ab79a2fc194788cd P 52c654370626484fa8e52950b6feff61: Deleting log segment in path: /tmp/dist-test-taskn9P66M/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515505003970-26863-0/minicluster-data/ts-0-root/wals/dde6a5ea3c6a4e55ab79a2fc194788cd/wal-000000016 (ops 75-79)
I20260812 06:18:28.417758 26976 log.cc:1079] T dde6a5ea3c6a4e55ab79a2fc194788cd P 52c654370626484fa8e52950b6feff61: Deleting log segment in path: /tmp/dist-test-taskn9P66M/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515505003970-26863-0/minicluster-data/ts-0-root/wals/dde6a5ea3c6a4e55ab79a2fc194788cd/wal-000000017 (ops 80-84)
I20260812 06:18:28.417805 26976 log.cc:1079] T dde6a5ea3c6a4e55ab79a2fc194788cd P 52c654370626484fa8e52950b6feff61: Deleting log segment in path: /tmp/dist-test-taskn9P66M/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515505003970-26863-0/minicluster-data/ts-0-root/wals/dde6a5ea3c6a4e55ab79a2fc194788cd/wal-000000018 (ops 85-89)
I20260812 06:18:28.417850 26976 log.cc:1079] T dde6a5ea3c6a4e55ab79a2fc194788cd P 52c654370626484fa8e52950b6feff61: Deleting log segment in path: /tmp/dist-test-taskn9P66M/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515505003970-26863-0/minicluster-data/ts-0-root/wals/dde6a5ea3c6a4e55ab79a2fc194788cd/wal-000000019 (ops 90-94)
I20260812 06:18:28.417892 26976 log.cc:1079] T dde6a5ea3c6a4e55ab79a2fc194788cd P 52c654370626484fa8e52950b6feff61: Deleting log segment in path: /tmp/dist-test-taskn9P66M/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515505003970-26863-0/minicluster-data/ts-0-root/wals/dde6a5ea3c6a4e55ab79a2fc194788cd/wal-000000020 (ops 95-99)
I20260812 06:18:28.417936 26976 log.cc:1079] T dde6a5ea3c6a4e55ab79a2fc194788cd P 52c654370626484fa8e52950b6feff61: Deleting log segment in path: /tmp/dist-test-taskn9P66M/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515505003970-26863-0/minicluster-data/ts-0-root/wals/dde6a5ea3c6a4e55ab79a2fc194788cd/wal-000000021 (ops 100-104)
I20260812 06:18:28.417979 26976 log.cc:1079] T dde6a5ea3c6a4e55ab79a2fc194788cd P 52c654370626484fa8e52950b6feff61: Deleting log segment in path: /tmp/dist-test-taskn9P66M/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515505003970-26863-0/minicluster-data/ts-0-root/wals/dde6a5ea3c6a4e55ab79a2fc194788cd/wal-000000022 (ops 105-109)
I20260812 06:18:28.418022 26976 log.cc:1079] T dde6a5ea3c6a4e55ab79a2fc194788cd P 52c654370626484fa8e52950b6feff61: Deleting log segment in path: /tmp/dist-test-taskn9P66M/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515505003970-26863-0/minicluster-data/ts-0-root/wals/dde6a5ea3c6a4e55ab79a2fc194788cd/wal-000000023 (ops 110-114)
I20260812 06:18:28.418066 26976 log.cc:1079] T dde6a5ea3c6a4e55ab79a2fc194788cd P 52c654370626484fa8e52950b6feff61: Deleting log segment in path: /tmp/dist-test-taskn9P66M/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515505003970-26863-0/minicluster-data/ts-0-root/wals/dde6a5ea3c6a4e55ab79a2fc194788cd/wal-000000024 (ops 115-119)
I20260812 06:18:28.418115 26976 log.cc:1079] T dde6a5ea3c6a4e55ab79a2fc194788cd P 52c654370626484fa8e52950b6feff61: Deleting log segment in path: /tmp/dist-test-taskn9P66M/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515505003970-26863-0/minicluster-data/ts-0-root/wals/dde6a5ea3c6a4e55ab79a2fc194788cd/wal-000000025 (ops 120-124)
I20260812 06:18:28.418159 26976 log.cc:1079] T dde6a5ea3c6a4e55ab79a2fc194788cd P 52c654370626484fa8e52950b6feff61: Deleting log segment in path: /tmp/dist-test-taskn9P66M/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515505003970-26863-0/minicluster-data/ts-0-root/wals/dde6a5ea3c6a4e55ab79a2fc194788cd/wal-000000026 (ops 125-128)
I20260812 06:18:28.450680 26976 maintenance_manager.cc:643] P 52c654370626484fa8e52950b6feff61: LogGCOp(dde6a5ea3c6a4e55ab79a2fc194788cd) complete. Timing: real 0.033s	user 0.000s	sys 0.032s Metrics: {}
I20260812 06:18:28.451231 27047 maintenance_manager.cc:419] P 52c654370626484fa8e52950b6feff61: Scheduling UndoDeltaBlockGCOp(dde6a5ea3c6a4e55ab79a2fc194788cd): 473 bytes on disk
I20260812 06:18:28.451864 26976 maintenance_manager.cc:643] P 52c654370626484fa8e52950b6feff61: UndoDeltaBlockGCOp(dde6a5ea3c6a4e55ab79a2fc194788cd) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":85,"lbm_reads_lt_1ms":4}
I20260812 06:18:28.452545 27047 maintenance_manager.cc:419] P 52c654370626484fa8e52950b6feff61: Scheduling FlushDeltaMemStoresOp(dde6a5ea3c6a4e55ab79a2fc194788cd): perf score=3.181125
I20260812 06:18:28.467125 26976 maintenance_manager.cc:643] P 52c654370626484fa8e52950b6feff61: FlushDeltaMemStoresOp(dde6a5ea3c6a4e55ab79a2fc194788cd) complete. Timing: real 0.014s	user 0.007s	sys 0.006s Metrics: {"bytes_written":5087239,"delete_count":0,"lbm_write_time_us":5717,"lbm_writes_lt_1ms":127,"reinsert_count":0,"update_count":620}
I20260812 06:18:28.467685 27047 maintenance_manager.cc:419] P 52c654370626484fa8e52950b6feff61: Scheduling FlushDeltaMemStoresOp(dde6a5ea3c6a4e55ab79a2fc194788cd): perf score=1.196750
I20260812 06:18:28.480278 26976 maintenance_manager.cc:643] P 52c654370626484fa8e52950b6feff61: FlushDeltaMemStoresOp(dde6a5ea3c6a4e55ab79a2fc194788cd) complete. Timing: real 0.012s	user 0.005s	sys 0.004s Metrics: {"bytes_written":3118055,"delete_count":0,"lbm_write_time_us":4205,"lbm_writes_lt_1ms":79,"reinsert_count":0,"update_count":380}
I20260812 06:18:28.480813 27047 maintenance_manager.cc:419] P 52c654370626484fa8e52950b6feff61: Scheduling MajorDeltaCompactionOp(dde6a5ea3c6a4e55ab79a2fc194788cd): perf score=1.000000
I20260812 06:18:28.670082 26976 maintenance_manager.cc:643] P 52c654370626484fa8e52950b6feff61: MajorDeltaCompactionOp(dde6a5ea3c6a4e55ab79a2fc194788cd) complete. Timing: real 0.189s	user 0.151s	sys 0.036s Metrics: {"cfile_cache_miss":735,"cfile_cache_miss_bytes":32979839,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":5,"delta_iterators_relevant":5,"dirs.queue_time_us":1700,"lbm_read_time_us":12727,"lbm_reads_lt_1ms":775,"lbm_write_time_us":40540,"lbm_writes_lt_1ms":743,"mutex_wait_us":585,"peak_mem_usage":87969044,"reinsert_count":0,"thread_start_us":87,"threads_started":1,"update_count":3500}
I20260812 06:18:28.671003 27047 maintenance_manager.cc:419] P 52c654370626484fa8e52950b6feff61: Scheduling FlushDeltaMemStoresOp(dde6a5ea3c6a4e55ab79a2fc194788cd): perf score=14.095187
I20260812 06:18:28.716077 26976 maintenance_manager.cc:643] P 52c654370626484fa8e52950b6feff61: FlushDeltaMemStoresOp(dde6a5ea3c6a4e55ab79a2fc194788cd) complete. Timing: real 0.045s	user 0.026s	sys 0.016s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":20195,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:18:28.716617 27047 maintenance_manager.cc:419] P 52c654370626484fa8e52950b6feff61: Scheduling FlushDeltaMemStoresOp(dde6a5ea3c6a4e55ab79a2fc194788cd): perf score=2.188937
I20260812 06:18:28.735421 26976 maintenance_manager.cc:643] P 52c654370626484fa8e52950b6feff61: FlushDeltaMemStoresOp(dde6a5ea3c6a4e55ab79a2fc194788cd) complete. Timing: real 0.019s	user 0.006s	sys 0.007s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6336,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:28.736001 27047 maintenance_manager.cc:419] P 52c654370626484fa8e52950b6feff61: Scheduling MajorDeltaCompactionOp(dde6a5ea3c6a4e55ab79a2fc194788cd): perf score=1.000000
I20260812 06:18:28.885237 26976 maintenance_manager.cc:643] P 52c654370626484fa8e52950b6feff61: MajorDeltaCompactionOp(dde6a5ea3c6a4e55ab79a2fc194788cd) complete. Timing: real 0.149s	user 0.108s	sys 0.034s 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":1474,"lbm_read_time_us":9084,"lbm_reads_lt_1ms":572,"lbm_write_time_us":29348,"lbm_writes_lt_1ms":543,"mutex_wait_us":2,"peak_mem_usage":63115900,"reinsert_count":0,"update_count":2500}
I20260812 06:18:28.888854 27047 maintenance_manager.cc:419] P 52c654370626484fa8e52950b6feff61: Scheduling FlushDeltaMemStoresOp(dde6a5ea3c6a4e55ab79a2fc194788cd): perf score=14.095187
I20260812 06:18:28.937428 26976 maintenance_manager.cc:643] P 52c654370626484fa8e52950b6feff61: FlushDeltaMemStoresOp(dde6a5ea3c6a4e55ab79a2fc194788cd) complete. Timing: real 0.048s	user 0.019s	sys 0.022s Metrics: {"bytes_written":16409904,"delete_count":0,"lbm_write_time_us":19963,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:18:28.938023 27047 maintenance_manager.cc:419] P 52c654370626484fa8e52950b6feff61: Scheduling MajorDeltaCompactionOp(dde6a5ea3c6a4e55ab79a2fc194788cd): perf score=1.000000
I20260812 06:18:29.087450 26976 maintenance_manager.cc:643] P 52c654370626484fa8e52950b6feff61: MajorDeltaCompactionOp(dde6a5ea3c6a4e55ab79a2fc194788cd) complete. Timing: real 0.149s	user 0.100s	sys 0.047s Metrics: {"cfile_cache_miss":431,"cfile_cache_miss_bytes":20672160,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":1,"delta_iterators_relevant":1,"dirs.queue_time_us":884,"lbm_read_time_us":9860,"lbm_reads_lt_1ms":463,"lbm_write_time_us":24744,"lbm_writes_lt_1ms":443,"mutex_wait_us":38,"peak_mem_usage":50689328,"reinsert_count":0,"update_count":2000}
I20260812 06:18:29.087944 27047 maintenance_manager.cc:419] P 52c654370626484fa8e52950b6feff61: Scheduling FlushDeltaMemStoresOp(dde6a5ea3c6a4e55ab79a2fc194788cd): perf score=11.118625
I20260812 06:18:29.132898 26976 maintenance_manager.cc:643] P 52c654370626484fa8e52950b6feff61: FlushDeltaMemStoresOp(dde6a5ea3c6a4e55ab79a2fc194788cd) complete. Timing: real 0.045s	user 0.017s	sys 0.024s Metrics: {"bytes_written":12717736,"delete_count":0,"lbm_write_time_us":15889,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:18:29.133533 27047 maintenance_manager.cc:419] P 52c654370626484fa8e52950b6feff61: Scheduling FlushDeltaMemStoresOp(dde6a5ea3c6a4e55ab79a2fc194788cd): perf score=2.188937
I20260812 06:18:29.145258 26976 maintenance_manager.cc:643] P 52c654370626484fa8e52950b6feff61: FlushDeltaMemStoresOp(dde6a5ea3c6a4e55ab79a2fc194788cd) complete. Timing: real 0.011s	user 0.006s	sys 0.005s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":4176,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:18:29.145813 27047 maintenance_manager.cc:419] P 52c654370626484fa8e52950b6feff61: Scheduling MajorDeltaCompactionOp(dde6a5ea3c6a4e55ab79a2fc194788cd): perf score=1.000000
I20260812 06:18:29.309820 26976 maintenance_manager.cc:643] P 52c654370626484fa8e52950b6feff61: MajorDeltaCompactionOp(dde6a5ea3c6a4e55ab79a2fc194788cd) complete. Timing: real 0.164s	user 0.119s	sys 0.044s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672269,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":104,"lbm_read_time_us":12125,"lbm_reads_lt_1ms":464,"lbm_write_time_us":28692,"lbm_writes_lt_1ms":443,"mutex_wait_us":58,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":2688,"update_count":2000}
I20260812 06:18:29.310454 27047 maintenance_manager.cc:419] P 52c654370626484fa8e52950b6feff61: Scheduling FlushDeltaMemStoresOp(dde6a5ea3c6a4e55ab79a2fc194788cd): perf score=11.118625
I20260812 06:18:29.351817 26976 maintenance_manager.cc:643] P 52c654370626484fa8e52950b6feff61: FlushDeltaMemStoresOp(dde6a5ea3c6a4e55ab79a2fc194788cd) complete. Timing: real 0.041s	user 0.022s	sys 0.017s Metrics: {"bytes_written":12717737,"delete_count":0,"lbm_write_time_us":18622,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:18:29.352382 27047 maintenance_manager.cc:419] P 52c654370626484fa8e52950b6feff61: Scheduling FlushDeltaMemStoresOp(dde6a5ea3c6a4e55ab79a2fc194788cd): perf score=2.188937
I20260812 06:18:29.363505 26976 maintenance_manager.cc:643] P 52c654370626484fa8e52950b6feff61: FlushDeltaMemStoresOp(dde6a5ea3c6a4e55ab79a2fc194788cd) complete. Timing: real 0.011s	user 0.004s	sys 0.005s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":4190,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:18:29.363957 27047 maintenance_manager.cc:419] P 52c654370626484fa8e52950b6feff61: Scheduling MajorDeltaCompactionOp(dde6a5ea3c6a4e55ab79a2fc194788cd): perf score=1.000000
I20260812 06:18:29.495787 26976 maintenance_manager.cc:643] P 52c654370626484fa8e52950b6feff61: MajorDeltaCompactionOp(dde6a5ea3c6a4e55ab79a2fc194788cd) complete. Timing: real 0.132s	user 0.099s	sys 0.032s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672270,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":107,"lbm_read_time_us":9272,"lbm_reads_lt_1ms":472,"lbm_write_time_us":28328,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":442,"mutex_wait_us":28,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":17408,"update_count":2000}
I20260812 06:18:29.499176 27047 maintenance_manager.cc:419] P 52c654370626484fa8e52950b6feff61: Scheduling FlushDeltaMemStoresOp(dde6a5ea3c6a4e55ab79a2fc194788cd): perf score=10.126437
I20260812 06:18:29.536453 26976 maintenance_manager.cc:643] P 52c654370626484fa8e52950b6feff61: FlushDeltaMemStoresOp(dde6a5ea3c6a4e55ab79a2fc194788cd) complete. Timing: real 0.037s	user 0.013s	sys 0.020s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":16213,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:18:29.537063 27047 maintenance_manager.cc:419] P 52c654370626484fa8e52950b6feff61: Scheduling FlushDeltaMemStoresOp(dde6a5ea3c6a4e55ab79a2fc194788cd): perf score=2.188937
I20260812 06:18:29.553828 26976 maintenance_manager.cc:643] P 52c654370626484fa8e52950b6feff61: FlushDeltaMemStoresOp(dde6a5ea3c6a4e55ab79a2fc194788cd) complete. Timing: real 0.017s	user 0.009s	sys 0.007s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6530,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:29.554530 27047 maintenance_manager.cc:419] P 52c654370626484fa8e52950b6feff61: Scheduling MajorDeltaCompactionOp(dde6a5ea3c6a4e55ab79a2fc194788cd): perf score=1.000000
I20260812 06:18:29.686089 26976 maintenance_manager.cc:643] P 52c654370626484fa8e52950b6feff61: MajorDeltaCompactionOp(dde6a5ea3c6a4e55ab79a2fc194788cd) complete. Timing: real 0.131s	user 0.111s	sys 0.020s 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":128,"lbm_read_time_us":8070,"lbm_reads_lt_1ms":464,"lbm_write_time_us":28318,"lbm_writes_lt_1ms":443,"mutex_wait_us":44,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":11648,"update_count":2000}
I20260812 06:18:29.686829 27047 maintenance_manager.cc:419] P 52c654370626484fa8e52950b6feff61: Scheduling FlushDeltaMemStoresOp(dde6a5ea3c6a4e55ab79a2fc194788cd): perf score=10.126437
I20260812 06:18:29.734579 26976 maintenance_manager.cc:643] P 52c654370626484fa8e52950b6feff61: FlushDeltaMemStoresOp(dde6a5ea3c6a4e55ab79a2fc194788cd) complete. Timing: real 0.048s	user 0.027s	sys 0.019s Metrics: {"bytes_written":12307491,"delete_count":0,"lbm_write_time_us":17412,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:18:29.735188 27047 maintenance_manager.cc:419] P 52c654370626484fa8e52950b6feff61: Scheduling FlushDeltaMemStoresOp(dde6a5ea3c6a4e55ab79a2fc194788cd): perf score=2.188937
I20260812 06:18:29.746206 26976 maintenance_manager.cc:643] P 52c654370626484fa8e52950b6feff61: FlushDeltaMemStoresOp(dde6a5ea3c6a4e55ab79a2fc194788cd) complete. Timing: real 0.011s	user 0.006s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4166,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:29.746723 27047 maintenance_manager.cc:419] P 52c654370626484fa8e52950b6feff61: Scheduling MajorDeltaCompactionOp(dde6a5ea3c6a4e55ab79a2fc194788cd): perf score=1.000000
I20260812 06:18:29.892334 26976 maintenance_manager.cc:643] P 52c654370626484fa8e52950b6feff61: MajorDeltaCompactionOp(dde6a5ea3c6a4e55ab79a2fc194788cd) complete. Timing: real 0.145s	user 0.093s	sys 0.052s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672278,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":770,"lbm_read_time_us":10499,"lbm_reads_lt_1ms":472,"lbm_write_time_us":23547,"lbm_writes_lt_1ms":443,"mutex_wait_us":269,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":8576,"update_count":2000}
I20260812 06:18:29.892867 27047 maintenance_manager.cc:419] P 52c654370626484fa8e52950b6feff61: Scheduling FlushDeltaMemStoresOp(dde6a5ea3c6a4e55ab79a2fc194788cd): perf score=10.126437
I20260812 06:18:29.940748 26976 maintenance_manager.cc:643] P 52c654370626484fa8e52950b6feff61: FlushDeltaMemStoresOp(dde6a5ea3c6a4e55ab79a2fc194788cd) complete. Timing: real 0.048s	user 0.032s	sys 0.004s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":17209,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:18:29.941365 27047 maintenance_manager.cc:419] P 52c654370626484fa8e52950b6feff61: Scheduling FlushDeltaMemStoresOp(dde6a5ea3c6a4e55ab79a2fc194788cd): perf score=2.188937
I20260812 06:18:29.952692 26976 maintenance_manager.cc:643] P 52c654370626484fa8e52950b6feff61: FlushDeltaMemStoresOp(dde6a5ea3c6a4e55ab79a2fc194788cd) complete. Timing: real 0.011s	user 0.009s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4050,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:29.953416 27047 maintenance_manager.cc:419] P 52c654370626484fa8e52950b6feff61: Scheduling FlushMRSOp(dde6a5ea3c6a4e55ab79a2fc194788cd): perf score=1.000000
I20260812 06:18:29.980654 26976 maintenance_manager.cc:643] P 52c654370626484fa8e52950b6feff61: FlushMRSOp(dde6a5ea3c6a4e55ab79a2fc194788cd) complete. Timing: real 0.027s	user 0.021s	sys 0.004s Metrics: {"bytes_written":1275447,"cfile_init":1,"dirs.queue_time_us":90,"dirs.run_cpu_time_us":214,"dirs.run_wall_time_us":1727,"drs_written":1,"lbm_read_time_us":73,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1524,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":31}
I20260812 06:18:29.981329 27047 maintenance_manager.cc:419] P 52c654370626484fa8e52950b6feff61: Scheduling LogGCOp(dde6a5ea3c6a4e55ab79a2fc194788cd): free 124710570 bytes of WAL
I20260812 06:18:29.981627 26976 log_reader.cc:385] T dde6a5ea3c6a4e55ab79a2fc194788cd: removed 12 log segments from log reader
I20260812 06:18:29.981701 26976 log.cc:1079] T dde6a5ea3c6a4e55ab79a2fc194788cd P 52c654370626484fa8e52950b6feff61: Deleting log segment in path: /tmp/dist-test-taskn9P66M/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515505003970-26863-0/minicluster-data/ts-0-root/wals/dde6a5ea3c6a4e55ab79a2fc194788cd/wal-000000027 (ops 129-133)
I20260812 06:18:29.981755 26976 log.cc:1079] T dde6a5ea3c6a4e55ab79a2fc194788cd P 52c654370626484fa8e52950b6feff61: Deleting log segment in path: /tmp/dist-test-taskn9P66M/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515505003970-26863-0/minicluster-data/ts-0-root/wals/dde6a5ea3c6a4e55ab79a2fc194788cd/wal-000000028 (ops 134-138)
I20260812 06:18:29.981814 26976 log.cc:1079] T dde6a5ea3c6a4e55ab79a2fc194788cd P 52c654370626484fa8e52950b6feff61: Deleting log segment in path: /tmp/dist-test-taskn9P66M/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515505003970-26863-0/minicluster-data/ts-0-root/wals/dde6a5ea3c6a4e55ab79a2fc194788cd/wal-000000029 (ops 139-143)
I20260812 06:18:29.981854 26976 log.cc:1079] T dde6a5ea3c6a4e55ab79a2fc194788cd P 52c654370626484fa8e52950b6feff61: Deleting log segment in path: /tmp/dist-test-taskn9P66M/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515505003970-26863-0/minicluster-data/ts-0-root/wals/dde6a5ea3c6a4e55ab79a2fc194788cd/wal-000000030 (ops 144-148)
I20260812 06:18:29.981890 26976 log.cc:1079] T dde6a5ea3c6a4e55ab79a2fc194788cd P 52c654370626484fa8e52950b6feff61: Deleting log segment in path: /tmp/dist-test-taskn9P66M/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515505003970-26863-0/minicluster-data/ts-0-root/wals/dde6a5ea3c6a4e55ab79a2fc194788cd/wal-000000031 (ops 149-153)
I20260812 06:18:29.981927 26976 log.cc:1079] T dde6a5ea3c6a4e55ab79a2fc194788cd P 52c654370626484fa8e52950b6feff61: Deleting log segment in path: /tmp/dist-test-taskn9P66M/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515505003970-26863-0/minicluster-data/ts-0-root/wals/dde6a5ea3c6a4e55ab79a2fc194788cd/wal-000000032 (ops 154-158)
I20260812 06:18:29.981964 26976 log.cc:1079] T dde6a5ea3c6a4e55ab79a2fc194788cd P 52c654370626484fa8e52950b6feff61: Deleting log segment in path: /tmp/dist-test-taskn9P66M/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515505003970-26863-0/minicluster-data/ts-0-root/wals/dde6a5ea3c6a4e55ab79a2fc194788cd/wal-000000033 (ops 159-163)
I20260812 06:18:29.982002 26976 log.cc:1079] T dde6a5ea3c6a4e55ab79a2fc194788cd P 52c654370626484fa8e52950b6feff61: Deleting log segment in path: /tmp/dist-test-taskn9P66M/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515505003970-26863-0/minicluster-data/ts-0-root/wals/dde6a5ea3c6a4e55ab79a2fc194788cd/wal-000000034 (ops 164-168)
I20260812 06:18:29.982038 26976 log.cc:1079] T dde6a5ea3c6a4e55ab79a2fc194788cd P 52c654370626484fa8e52950b6feff61: Deleting log segment in path: /tmp/dist-test-taskn9P66M/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515505003970-26863-0/minicluster-data/ts-0-root/wals/dde6a5ea3c6a4e55ab79a2fc194788cd/wal-000000035 (ops 169-173)
I20260812 06:18:29.982074 26976 log.cc:1079] T dde6a5ea3c6a4e55ab79a2fc194788cd P 52c654370626484fa8e52950b6feff61: Deleting log segment in path: /tmp/dist-test-taskn9P66M/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515505003970-26863-0/minicluster-data/ts-0-root/wals/dde6a5ea3c6a4e55ab79a2fc194788cd/wal-000000036 (ops 174-178)
I20260812 06:18:29.982111 26976 log.cc:1079] T dde6a5ea3c6a4e55ab79a2fc194788cd P 52c654370626484fa8e52950b6feff61: Deleting log segment in path: /tmp/dist-test-taskn9P66M/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515505003970-26863-0/minicluster-data/ts-0-root/wals/dde6a5ea3c6a4e55ab79a2fc194788cd/wal-000000037 (ops 179-183)
I20260812 06:18:29.982147 26976 log.cc:1079] T dde6a5ea3c6a4e55ab79a2fc194788cd P 52c654370626484fa8e52950b6feff61: Deleting log segment in path: /tmp/dist-test-taskn9P66M/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515505003970-26863-0/minicluster-data/ts-0-root/wals/dde6a5ea3c6a4e55ab79a2fc194788cd/wal-000000038 (ops 184-188)
I20260812 06:18:30.008875 26976 maintenance_manager.cc:643] P 52c654370626484fa8e52950b6feff61: LogGCOp(dde6a5ea3c6a4e55ab79a2fc194788cd) complete. Timing: real 0.027s	user 0.001s	sys 0.023s Metrics: {}
I20260812 06:18:30.009297 27047 maintenance_manager.cc:419] P 52c654370626484fa8e52950b6feff61: Scheduling UndoDeltaBlockGCOp(dde6a5ea3c6a4e55ab79a2fc194788cd): 482 bytes on disk
I20260812 06:18:30.009801 26976 maintenance_manager.cc:643] P 52c654370626484fa8e52950b6feff61: UndoDeltaBlockGCOp(dde6a5ea3c6a4e55ab79a2fc194788cd) 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:18:30.010381 27047 maintenance_manager.cc:419] P 52c654370626484fa8e52950b6feff61: Scheduling FlushDeltaMemStoresOp(dde6a5ea3c6a4e55ab79a2fc194788cd): perf score=3.181125
I20260812 06:18:30.022706 26976 maintenance_manager.cc:643] P 52c654370626484fa8e52950b6feff61: FlushDeltaMemStoresOp(dde6a5ea3c6a4e55ab79a2fc194788cd) complete. Timing: real 0.012s	user 0.002s	sys 0.009s Metrics: {"bytes_written":4512903,"delete_count":0,"lbm_write_time_us":4646,"lbm_writes_lt_1ms":113,"reinsert_count":0,"update_count":550}
I20260812 06:18:30.023181 27047 maintenance_manager.cc:419] P 52c654370626484fa8e52950b6feff61: Scheduling FlushDeltaMemStoresOp(dde6a5ea3c6a4e55ab79a2fc194788cd): perf score=2.188937
I20260812 06:18:30.047068 26976 maintenance_manager.cc:643] P 52c654370626484fa8e52950b6feff61: FlushDeltaMemStoresOp(dde6a5ea3c6a4e55ab79a2fc194788cd) complete. Timing: real 0.024s	user 0.007s	sys 0.015s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":5143,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:18:30.047871 27047 maintenance_manager.cc:419] P 52c654370626484fa8e52950b6feff61: Scheduling MajorDeltaCompactionOp(dde6a5ea3c6a4e55ab79a2fc194788cd): perf score=1.000000
I20260812 06:18:30.252130 26863 heavy-update-compaction-itest.cc:229] Time spent updating: real 4.948s	user 1.810s	sys 0.165s
I20260812 06:18:30.258013 26976 maintenance_manager.cc:643] P 52c654370626484fa8e52950b6feff61: MajorDeltaCompactionOp(dde6a5ea3c6a4e55ab79a2fc194788cd) complete. Timing: real 0.210s	user 0.149s	sys 0.060s Metrics: {"cfile_cache_miss":634,"cfile_cache_miss_bytes":28877329,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":1055,"lbm_read_time_us":14343,"lbm_reads_lt_1ms":674,"lbm_write_time_us":36676,"lbm_writes_lt_1ms":643,"mutex_wait_us":834,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":3584,"thread_start_us":80,"threads_started":1,"update_count":3000}
I20260812 06:18:30.258687 27047 maintenance_manager.cc:419] P 52c654370626484fa8e52950b6feff61: Scheduling FlushDeltaMemStoresOp(dde6a5ea3c6a4e55ab79a2fc194788cd): perf score=14.095187
I20260812 06:18:30.288770 26863 heavy-update-compaction-itest.cc:265] Time spent scanning: real 0.036s	user 0.002s	sys 0.000s
I20260812 06:18:30.290242 26863 tablet_server.cc:179] TabletServer@127.26.59.193:0 shutting down...
I20260812 06:18:30.311151 26976 maintenance_manager.cc:643] P 52c654370626484fa8e52950b6feff61: FlushDeltaMemStoresOp(dde6a5ea3c6a4e55ab79a2fc194788cd) complete. Timing: real 0.052s	user 0.038s	sys 0.012s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":23767,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:18:30.311931 26863 ts_tablet_manager.cc:1507] Shutting down tablet manager...
I20260812 06:18:30.312361 26863 tablet_replica.cc:333] T dde6a5ea3c6a4e55ab79a2fc194788cd P 52c654370626484fa8e52950b6feff61: stopping tablet replica
I20260812 06:18:30.312618 26863 raft_consensus.cc:2243] T dde6a5ea3c6a4e55ab79a2fc194788cd P 52c654370626484fa8e52950b6feff61 [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:18:30.312860 26863 raft_consensus.cc:2272] T dde6a5ea3c6a4e55ab79a2fc194788cd P 52c654370626484fa8e52950b6feff61 [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:18:30.327647 26863 tablet_server.cc:196] TabletServer@127.26.59.193:0 shutdown complete.
I20260812 06:18:30.332356 26863 master.cc:562] Master@127.26.59.254:34433 shutting down...
I20260812 06:18:30.336560 26863 raft_consensus.cc:2243] T 00000000000000000000000000000000 P ab4bf59a5cec444da26f0a0a148c317b [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:18:30.336731 26863 raft_consensus.cc:2272] T 00000000000000000000000000000000 P ab4bf59a5cec444da26f0a0a148c317b [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:18:30.336784 26863 tablet_replica.cc:333] T 00000000000000000000000000000000 P ab4bf59a5cec444da26f0a0a148c317b: stopping tablet replica
I20260812 06:18:30.349792 26863 master.cc:584] Master@127.26.59.254:34433 shutdown complete.
[       OK ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/0 (5425 ms)
[ RUN      ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/1
I20260812 06:18:30.451575 26863 internal_mini_cluster.cc:156] Creating distributed mini masters. Addrs: 127.26.59.254:45763
I20260812 06:18:30.451960 26863 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:18:30.454075 27081 instance_detector.cc:116] could not retrieve AWS instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:18:30.454175 27082 instance_detector.cc:116] could not retrieve Azure instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:18:30.454142 27084 instance_detector.cc:116] could not retrieve OpenStack instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:18:30.454324 26863 server_base.cc:1061] running on GCE node
I20260812 06:18:30.454457 26863 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:18:30.454489 26863 system_unsync_time.cc:38] NTP support is disabled. Clock error bounds will not be accurate. This configuration is not suitable for distributed clusters.
I20260812 06:18:30.454504 26863 hybrid_clock.cc:648] HybridClock initialized: now 1786515510454505 us; error 0 us; skew 500 ppm
I20260812 06:18:30.455369 26863 webserver.cc:533] Webserver started at http://127.26.59.254:45475/ using document root <none> and password file <none>
I20260812 06:18:30.455519 26863 fs_manager.cc:362] Metadata directory not provided
I20260812 06:18:30.455590 26863 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:18:30.455654 26863 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:18:30.456012 26863 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskn9P66M/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515505003970-26863-0/minicluster-data/master-0-root/instance:
uuid: "13ba9107224342c2a62b762433525e19"
format_stamp: "Formatted at 2026-08-12 06:18:30 on dist-test-slave-njxd"
I20260812 06:18:30.457482 26863 fs_manager.cc:696] Time spent creating directory manager: real 0.001s	user 0.002s	sys 0.000s
I20260812 06:18:30.458469 27091 log_block_manager.cc:4127] Time spent loading block containers with low live blocks: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:18:30.458693 26863 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.001s	sys 0.000s
I20260812 06:18:30.458758 26863 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskn9P66M/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515505003970-26863-0/minicluster-data/master-0-root
uuid: "13ba9107224342c2a62b762433525e19"
format_stamp: "Formatted at 2026-08-12 06:18:30 on dist-test-slave-njxd"
I20260812 06:18:30.458813 26863 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskn9P66M/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515505003970-26863-0/minicluster-data/master-0-root
metadata directory: /tmp/dist-test-taskn9P66M/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515505003970-26863-0/minicluster-data/master-0-root
1 data directories: /tmp/dist-test-taskn9P66M/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515505003970-26863-0/minicluster-data/master-0-root/data
Total live blocks: 0
Total live bytes: 0
Total live bytes (after alignment): 0
Total number of LBM containers: 0 (0 full)
Did not check for missing blocks
Did not check for orphaned blocks
Total full LBM containers with extra space: 0 (0 repaired)
Total full LBM container extra space in bytes: 0 (0 repaired)
Total incomplete LBM containers: 0 (0 repaired)
Total LBM partial records: 0 (0 repaired)
Total corrupted LBM metadata records in RocksDB: 0 (0 repaired)
I20260812 06:18:30.472777 26863 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:18:30.473137 26863 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:18:30.477849 26863 rpc_server.cc:307] RPC server started. Bound to: 127.26.59.254:45763
I20260812 06:18:30.479116 27148 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet 00000000000000000000000000000000. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:18:30.481348 27147 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.26.59.254:45763 every 8 connection(s)
I20260812 06:18:30.481855 27148 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P 13ba9107224342c2a62b762433525e19: Bootstrap starting.
I20260812 06:18:30.482637 27148 tablet_bootstrap.cc:654] T 00000000000000000000000000000000 P 13ba9107224342c2a62b762433525e19: Neither blocks nor log segments found. Creating new log.
I20260812 06:18:30.483635 27148 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P 13ba9107224342c2a62b762433525e19: No bootstrap required, opened a new log
I20260812 06:18:30.484033 27148 raft_consensus.cc:359] T 00000000000000000000000000000000 P 13ba9107224342c2a62b762433525e19 [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "13ba9107224342c2a62b762433525e19" member_type: VOTER }
I20260812 06:18:30.484127 27148 raft_consensus.cc:385] T 00000000000000000000000000000000 P 13ba9107224342c2a62b762433525e19 [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:18:30.484184 27148 raft_consensus.cc:740] T 00000000000000000000000000000000 P 13ba9107224342c2a62b762433525e19 [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: 13ba9107224342c2a62b762433525e19, State: Initialized, Role: FOLLOWER
I20260812 06:18:30.484360 27148 consensus_queue.cc:260] T 00000000000000000000000000000000 P 13ba9107224342c2a62b762433525e19 [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: "13ba9107224342c2a62b762433525e19" member_type: VOTER }
I20260812 06:18:30.484429 27148 raft_consensus.cc:399] T 00000000000000000000000000000000 P 13ba9107224342c2a62b762433525e19 [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:18:30.484494 27148 raft_consensus.cc:493] T 00000000000000000000000000000000 P 13ba9107224342c2a62b762433525e19 [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:18:30.484578 27148 raft_consensus.cc:3060] T 00000000000000000000000000000000 P 13ba9107224342c2a62b762433525e19 [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:18:30.485249 27148 raft_consensus.cc:515] T 00000000000000000000000000000000 P 13ba9107224342c2a62b762433525e19 [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "13ba9107224342c2a62b762433525e19" member_type: VOTER }
I20260812 06:18:30.485394 27148 leader_election.cc:304] T 00000000000000000000000000000000 P 13ba9107224342c2a62b762433525e19 [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: 13ba9107224342c2a62b762433525e19; no voters: 
I20260812 06:18:30.485656 27148 leader_election.cc:290] T 00000000000000000000000000000000 P 13ba9107224342c2a62b762433525e19 [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:18:30.485765 27152 raft_consensus.cc:2804] T 00000000000000000000000000000000 P 13ba9107224342c2a62b762433525e19 [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:18:30.485952 27152 raft_consensus.cc:697] T 00000000000000000000000000000000 P 13ba9107224342c2a62b762433525e19 [term 1 LEADER]: Becoming Leader. State: Replica: 13ba9107224342c2a62b762433525e19, State: Running, Role: LEADER
I20260812 06:18:30.486131 27152 consensus_queue.cc:237] T 00000000000000000000000000000000 P 13ba9107224342c2a62b762433525e19 [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: "13ba9107224342c2a62b762433525e19" member_type: VOTER }
I20260812 06:18:30.486143 27148 sys_catalog.cc:565] T 00000000000000000000000000000000 P 13ba9107224342c2a62b762433525e19 [sys.catalog]: configured and running, proceeding with master startup.
I20260812 06:18:30.486610 27153 sys_catalog.cc:455] T 00000000000000000000000000000000 P 13ba9107224342c2a62b762433525e19 [sys.catalog]: SysCatalogTable state changed. Reason: RaftConsensus started. Latest consensus state: current_term: 1 leader_uuid: "13ba9107224342c2a62b762433525e19" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "13ba9107224342c2a62b762433525e19" member_type: VOTER } }
I20260812 06:18:30.486647 27154 sys_catalog.cc:455] T 00000000000000000000000000000000 P 13ba9107224342c2a62b762433525e19 [sys.catalog]: SysCatalogTable state changed. Reason: New leader 13ba9107224342c2a62b762433525e19. Latest consensus state: current_term: 1 leader_uuid: "13ba9107224342c2a62b762433525e19" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "13ba9107224342c2a62b762433525e19" member_type: VOTER } }
I20260812 06:18:30.486774 27153 sys_catalog.cc:458] T 00000000000000000000000000000000 P 13ba9107224342c2a62b762433525e19 [sys.catalog]: This master's current role is: LEADER
I20260812 06:18:30.486856 27154 sys_catalog.cc:458] T 00000000000000000000000000000000 P 13ba9107224342c2a62b762433525e19 [sys.catalog]: This master's current role is: LEADER
I20260812 06:18:30.487354 27159 catalog_manager.cc:1511] Loading table and tablet metadata into memory...
I20260812 06:18:30.488246 27159 catalog_manager.cc:1520] Initializing Kudu cluster ID...
I20260812 06:18:30.488466 26863 internal_mini_cluster.cc:184] Waiting to initialize catalog manager on master 0
I20260812 06:18:30.490118 27159 catalog_manager.cc:1383] Generated new cluster ID: 86f60f92cf0147fe9e4dcfef11850da4
I20260812 06:18:30.490176 27159 catalog_manager.cc:1531] Initializing Kudu internal certificate authority...
I20260812 06:18:30.500177 27159 catalog_manager.cc:1406] Generated new certificate authority record
I20260812 06:18:30.500742 27159 catalog_manager.cc:1540] Loading token signing keys...
I20260812 06:18:30.512936 27159 catalog_manager.cc:6092] T 00000000000000000000000000000000 P 13ba9107224342c2a62b762433525e19: Generated new TSK 0
I20260812 06:18:30.513139 27159 catalog_manager.cc:1550] Initializing in-progress tserver states...
I20260812 06:18:30.520992 26863 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:18:30.523070 27171 instance_detector.cc:116] could not retrieve AWS instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:18:30.523118 27172 instance_detector.cc:116] could not retrieve Azure instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:18:30.523207 26863 server_base.cc:1061] running on GCE node
W20260812 06:18:30.523097 27174 instance_detector.cc:116] could not retrieve OpenStack instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:18:30.523620 26863 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:18:30.523666 26863 system_unsync_time.cc:38] NTP support is disabled. Clock error bounds will not be accurate. This configuration is not suitable for distributed clusters.
I20260812 06:18:30.523684 26863 hybrid_clock.cc:648] HybridClock initialized: now 1786515510523683 us; error 0 us; skew 500 ppm
I20260812 06:18:30.524578 26863 webserver.cc:533] Webserver started at http://127.26.59.193:37221/ using document root <none> and password file <none>
I20260812 06:18:30.524714 26863 fs_manager.cc:362] Metadata directory not provided
I20260812 06:18:30.524770 26863 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:18:30.524832 26863 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:18:30.525246 26863 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskn9P66M/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515505003970-26863-0/minicluster-data/ts-0-root/instance:
uuid: "e492fe812dfd45e8b3701e03fd864e18"
format_stamp: "Formatted at 2026-08-12 06:18:30 on dist-test-slave-njxd"
I20260812 06:18:30.526832 26863 fs_manager.cc:696] Time spent creating directory manager: real 0.001s	user 0.000s	sys 0.002s
I20260812 06:18:30.527720 27180 log_block_manager.cc:4127] Time spent loading block containers with low live blocks: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:18:30.527958 26863 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.000s	sys 0.001s
I20260812 06:18:30.528023 26863 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskn9P66M/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515505003970-26863-0/minicluster-data/ts-0-root
uuid: "e492fe812dfd45e8b3701e03fd864e18"
format_stamp: "Formatted at 2026-08-12 06:18:30 on dist-test-slave-njxd"
I20260812 06:18:30.528123 26863 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskn9P66M/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515505003970-26863-0/minicluster-data/ts-0-root
metadata directory: /tmp/dist-test-taskn9P66M/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515505003970-26863-0/minicluster-data/ts-0-root
1 data directories: /tmp/dist-test-taskn9P66M/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515505003970-26863-0/minicluster-data/ts-0-root/data
Total live blocks: 0
Total live bytes: 0
Total live bytes (after alignment): 0
Total number of LBM containers: 0 (0 full)
Did not check for missing blocks
Did not check for orphaned blocks
Total full LBM containers with extra space: 0 (0 repaired)
Total full LBM container extra space in bytes: 0 (0 repaired)
Total incomplete LBM containers: 0 (0 repaired)
Total LBM partial records: 0 (0 repaired)
Total corrupted LBM metadata records in RocksDB: 0 (0 repaired)
I20260812 06:18:30.552831 26863 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:18:30.553289 26863 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:18:30.553668 26863 txn_system_client.cc:432] TxnSystemClient initialization is disabled...
I20260812 06:18:30.554188 26863 ts_tablet_manager.cc:585] Loaded tablet metadata (0 total tablets, 0 live tablets)
I20260812 06:18:30.554256 26863 ts_tablet_manager.cc:531] Time spent load tablet metadata: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:18:30.554320 26863 ts_tablet_manager.cc:616] Registered 0 tablets
I20260812 06:18:30.554366 26863 ts_tablet_manager.cc:595] Time spent register tablets: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:18:30.558804 26863 rpc_server.cc:307] RPC server started. Bound to: 127.26.59.193:46827
I20260812 06:18:30.560384 27249 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.26.59.193:46827 every 8 connection(s)
I20260812 06:18:30.569132 27250 heartbeater.cc:344] Connected to a master server at 127.26.59.254:45763
I20260812 06:18:30.569291 27250 heartbeater.cc:461] Registering TS with master...
I20260812 06:18:30.569553 27250 heartbeater.cc:507] Master 127.26.59.254:45763 requested a full tablet report, sending...
I20260812 06:18:30.570326 27109 ts_manager.cc:194] Registered new tserver with Master: e492fe812dfd45e8b3701e03fd864e18 (127.26.59.193:46827)
I20260812 06:18:30.570829 26863 internal_mini_cluster.cc:371] 1 TS(s) registered with all masters after 0.011157788s
I20260812 06:18:30.571100 27109 master_service.cc:502] Signed X509 certificate for tserver {username='slave'} at 127.0.0.1:47004
I20260812 06:18:30.578442 27109 catalog_manager.cc:2283] Servicing CreateTable request from {username='slave'} at 127.0.0.1:47010:
name: "heavy-update-compaction-test"
schema {
  columns {
    name: "key"
    type: INT64
    is_key: true
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_a"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_b"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_c"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_d"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_e"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
}
num_replicas: 1
split_rows_range_bounds {
}
partition_schema {
  range_schema {
  }
}
I20260812 06:18:30.587221 27211 tablet_service.cc:1511] Processing CreateTablet for tablet aa6341a9648b4ea4b2d5d604b5f98b36 (DEFAULT_TABLE table=heavy-update-compaction-test [id=1d23a1a3dc6943f1b36f36a647bb3e03]), partition=
I20260812 06:18:30.587574 27211 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet aa6341a9648b4ea4b2d5d604b5f98b36. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:18:30.589538 27266 tablet_bootstrap.cc:492] T aa6341a9648b4ea4b2d5d604b5f98b36 P e492fe812dfd45e8b3701e03fd864e18: Bootstrap starting.
I20260812 06:18:30.590435 27266 tablet_bootstrap.cc:654] T aa6341a9648b4ea4b2d5d604b5f98b36 P e492fe812dfd45e8b3701e03fd864e18: Neither blocks nor log segments found. Creating new log.
I20260812 06:18:30.591522 27266 tablet_bootstrap.cc:492] T aa6341a9648b4ea4b2d5d604b5f98b36 P e492fe812dfd45e8b3701e03fd864e18: No bootstrap required, opened a new log
I20260812 06:18:30.591642 27266 ts_tablet_manager.cc:1403] T aa6341a9648b4ea4b2d5d604b5f98b36 P e492fe812dfd45e8b3701e03fd864e18: Time spent bootstrapping tablet: real 0.002s	user 0.000s	sys 0.001s
I20260812 06:18:30.592073 27266 raft_consensus.cc:359] T aa6341a9648b4ea4b2d5d604b5f98b36 P e492fe812dfd45e8b3701e03fd864e18 [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "e492fe812dfd45e8b3701e03fd864e18" member_type: VOTER last_known_addr { host: "127.26.59.193" port: 46827 } }
I20260812 06:18:30.592182 27266 raft_consensus.cc:385] T aa6341a9648b4ea4b2d5d604b5f98b36 P e492fe812dfd45e8b3701e03fd864e18 [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:18:30.592236 27266 raft_consensus.cc:740] T aa6341a9648b4ea4b2d5d604b5f98b36 P e492fe812dfd45e8b3701e03fd864e18 [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: e492fe812dfd45e8b3701e03fd864e18, State: Initialized, Role: FOLLOWER
I20260812 06:18:30.592406 27266 consensus_queue.cc:260] T aa6341a9648b4ea4b2d5d604b5f98b36 P e492fe812dfd45e8b3701e03fd864e18 [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: "e492fe812dfd45e8b3701e03fd864e18" member_type: VOTER last_known_addr { host: "127.26.59.193" port: 46827 } }
I20260812 06:18:30.592518 27266 raft_consensus.cc:399] T aa6341a9648b4ea4b2d5d604b5f98b36 P e492fe812dfd45e8b3701e03fd864e18 [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:18:30.592566 27266 raft_consensus.cc:493] T aa6341a9648b4ea4b2d5d604b5f98b36 P e492fe812dfd45e8b3701e03fd864e18 [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:18:30.592619 27266 raft_consensus.cc:3060] T aa6341a9648b4ea4b2d5d604b5f98b36 P e492fe812dfd45e8b3701e03fd864e18 [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:18:30.593331 27266 raft_consensus.cc:515] T aa6341a9648b4ea4b2d5d604b5f98b36 P e492fe812dfd45e8b3701e03fd864e18 [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "e492fe812dfd45e8b3701e03fd864e18" member_type: VOTER last_known_addr { host: "127.26.59.193" port: 46827 } }
I20260812 06:18:30.593482 27266 leader_election.cc:304] T aa6341a9648b4ea4b2d5d604b5f98b36 P e492fe812dfd45e8b3701e03fd864e18 [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: e492fe812dfd45e8b3701e03fd864e18; no voters: 
I20260812 06:18:30.593708 27266 leader_election.cc:290] T aa6341a9648b4ea4b2d5d604b5f98b36 P e492fe812dfd45e8b3701e03fd864e18 [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:18:30.593840 27268 raft_consensus.cc:2804] T aa6341a9648b4ea4b2d5d604b5f98b36 P e492fe812dfd45e8b3701e03fd864e18 [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:18:30.594081 27266 ts_tablet_manager.cc:1434] T aa6341a9648b4ea4b2d5d604b5f98b36 P e492fe812dfd45e8b3701e03fd864e18: Time spent starting tablet: real 0.002s	user 0.002s	sys 0.001s
I20260812 06:18:30.594130 27268 raft_consensus.cc:697] T aa6341a9648b4ea4b2d5d604b5f98b36 P e492fe812dfd45e8b3701e03fd864e18 [term 1 LEADER]: Becoming Leader. State: Replica: e492fe812dfd45e8b3701e03fd864e18, State: Running, Role: LEADER
I20260812 06:18:30.594137 27250 heartbeater.cc:499] Master 127.26.59.254:45763 was elected leader, sending a full tablet report...
I20260812 06:18:30.594310 27268 consensus_queue.cc:237] T aa6341a9648b4ea4b2d5d604b5f98b36 P e492fe812dfd45e8b3701e03fd864e18 [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: "e492fe812dfd45e8b3701e03fd864e18" member_type: VOTER last_known_addr { host: "127.26.59.193" port: 46827 } }
I20260812 06:18:30.595520 27109 catalog_manager.cc:5719] T aa6341a9648b4ea4b2d5d604b5f98b36 P e492fe812dfd45e8b3701e03fd864e18 reported cstate change: term changed from 0 to 1, leader changed from <none> to e492fe812dfd45e8b3701e03fd864e18 (127.26.59.193). New cstate: current_term: 1 leader_uuid: "e492fe812dfd45e8b3701e03fd864e18" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "e492fe812dfd45e8b3701e03fd864e18" member_type: VOTER last_known_addr { host: "127.26.59.193" port: 46827 } health_report { overall_health: HEALTHY } } }
I20260812 06:18:30.654946 26863 heavy-update-compaction-itest.cc:215] Time spent inserting: real 0.052s	user 0.015s	sys 0.008s
I20260812 06:18:30.810823 27251 maintenance_manager.cc:419] P e492fe812dfd45e8b3701e03fd864e18: Scheduling FlushMRSOp(aa6341a9648b4ea4b2d5d604b5f98b36): perf score=19.054940
I20260812 06:18:30.976564 27186 maintenance_manager.cc:643] P e492fe812dfd45e8b3701e03fd864e18: FlushMRSOp(aa6341a9648b4ea4b2d5d604b5f98b36) complete. Timing: real 0.165s	user 0.111s	sys 0.052s Metrics: {"bytes_written":12717736,"cfile_init":1,"delete_count":0,"dirs.queue_time_us":62,"dirs.run_cpu_time_us":227,"dirs.run_wall_time_us":882,"drs_written":1,"lbm_read_time_us":63,"lbm_reads_lt_1ms":4,"lbm_write_time_us":42427,"lbm_writes_lt_1ms":767,"peak_mem_usage":0,"reinsert_count":0,"rows_written":104,"update_count":1550}
I20260812 06:18:30.977291 27251 maintenance_manager.cc:419] P e492fe812dfd45e8b3701e03fd864e18: Scheduling LogGCOp(aa6341a9648b4ea4b2d5d604b5f98b36): free 20743880 bytes of WAL
I20260812 06:18:30.977599 27186 log_reader.cc:385] T aa6341a9648b4ea4b2d5d604b5f98b36: removed 2 log segments from log reader
I20260812 06:18:30.977694 27186 log.cc:1079] T aa6341a9648b4ea4b2d5d604b5f98b36 P e492fe812dfd45e8b3701e03fd864e18: Deleting log segment in path: /tmp/dist-test-taskn9P66M/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515505003970-26863-0/minicluster-data/ts-0-root/wals/aa6341a9648b4ea4b2d5d604b5f98b36/wal-000000001 (ops 1-6)
I20260812 06:18:30.977756 27186 log.cc:1079] T aa6341a9648b4ea4b2d5d604b5f98b36 P e492fe812dfd45e8b3701e03fd864e18: Deleting log segment in path: /tmp/dist-test-taskn9P66M/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515505003970-26863-0/minicluster-data/ts-0-root/wals/aa6341a9648b4ea4b2d5d604b5f98b36/wal-000000002 (ops 7-11)
I20260812 06:18:30.983618 27186 maintenance_manager.cc:643] P e492fe812dfd45e8b3701e03fd864e18: LogGCOp(aa6341a9648b4ea4b2d5d604b5f98b36) complete. Timing: real 0.006s	user 0.001s	sys 0.003s Metrics: {}
I20260812 06:18:30.984208 27251 maintenance_manager.cc:419] P e492fe812dfd45e8b3701e03fd864e18: Scheduling UndoDeltaBlockGCOp(aa6341a9648b4ea4b2d5d604b5f98b36): 16411393 bytes on disk
I20260812 06:18:30.984846 27186 maintenance_manager.cc:643] P e492fe812dfd45e8b3701e03fd864e18: UndoDeltaBlockGCOp(aa6341a9648b4ea4b2d5d604b5f98b36) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":104,"lbm_reads_lt_1ms":4}
I20260812 06:18:30.985433 27251 maintenance_manager.cc:419] P e492fe812dfd45e8b3701e03fd864e18: Scheduling FlushDeltaMemStoresOp(aa6341a9648b4ea4b2d5d604b5f98b36): perf score=2.188937
I20260812 06:18:31.001658 27186 maintenance_manager.cc:643] P e492fe812dfd45e8b3701e03fd864e18: FlushDeltaMemStoresOp(aa6341a9648b4ea4b2d5d604b5f98b36) complete. Timing: real 0.016s	user 0.006s	sys 0.007s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":4977,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:18:31.002087 27251 maintenance_manager.cc:419] P e492fe812dfd45e8b3701e03fd864e18: Scheduling MajorDeltaCompactionOp(aa6341a9648b4ea4b2d5d604b5f98b36): perf score=1.000000
I20260812 06:18:31.180919 27186 maintenance_manager.cc:643] P e492fe812dfd45e8b3701e03fd864e18: MajorDeltaCompactionOp(aa6341a9648b4ea4b2d5d604b5f98b36) complete. Timing: real 0.179s	user 0.110s	sys 0.056s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672269,"cfile_init":7,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":1095,"lbm_read_time_us":9237,"lbm_reads_lt_1ms":460,"lbm_write_time_us":30100,"lbm_writes_lt_1ms":443,"mutex_wait_us":323,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":5376,"thread_start_us":370,"threads_started":5,"update_count":2000}
I20260812 06:18:31.181531 27251 maintenance_manager.cc:419] P e492fe812dfd45e8b3701e03fd864e18: Scheduling FlushDeltaMemStoresOp(aa6341a9648b4ea4b2d5d604b5f98b36): perf score=14.095187
I20260812 06:18:31.231633 27186 maintenance_manager.cc:643] P e492fe812dfd45e8b3701e03fd864e18: FlushDeltaMemStoresOp(aa6341a9648b4ea4b2d5d604b5f98b36) complete. Timing: real 0.050s	user 0.036s	sys 0.009s Metrics: {"bytes_written":16409904,"delete_count":0,"lbm_write_time_us":21354,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:18:31.232120 27251 maintenance_manager.cc:419] P e492fe812dfd45e8b3701e03fd864e18: Scheduling FlushDeltaMemStoresOp(aa6341a9648b4ea4b2d5d604b5f98b36): perf score=2.188937
I20260812 06:18:31.243548 27186 maintenance_manager.cc:643] P e492fe812dfd45e8b3701e03fd864e18: FlushDeltaMemStoresOp(aa6341a9648b4ea4b2d5d604b5f98b36) complete. Timing: real 0.011s	user 0.005s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4217,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:31.244082 27251 maintenance_manager.cc:419] P e492fe812dfd45e8b3701e03fd864e18: Scheduling MajorDeltaCompactionOp(aa6341a9648b4ea4b2d5d604b5f98b36): perf score=1.000000
I20260812 06:18:31.450446 27186 maintenance_manager.cc:643] P e492fe812dfd45e8b3701e03fd864e18: MajorDeltaCompactionOp(aa6341a9648b4ea4b2d5d604b5f98b36) complete. Timing: real 0.206s	user 0.122s	sys 0.073s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774691,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":120,"lbm_read_time_us":12367,"lbm_reads_lt_1ms":572,"lbm_write_time_us":32992,"lbm_writes_lt_1ms":543,"mutex_wait_us":34,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":55936,"update_count":2500}
I20260812 06:18:31.451293 27251 maintenance_manager.cc:419] P e492fe812dfd45e8b3701e03fd864e18: Scheduling FlushDeltaMemStoresOp(aa6341a9648b4ea4b2d5d604b5f98b36): perf score=14.095187
I20260812 06:18:31.503432 27186 maintenance_manager.cc:643] P e492fe812dfd45e8b3701e03fd864e18: FlushDeltaMemStoresOp(aa6341a9648b4ea4b2d5d604b5f98b36) complete. Timing: real 0.052s	user 0.031s	sys 0.008s Metrics: {"bytes_written":16409905,"delete_count":0,"lbm_write_time_us":18178,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:18:31.504037 27251 maintenance_manager.cc:419] P e492fe812dfd45e8b3701e03fd864e18: Scheduling FlushDeltaMemStoresOp(aa6341a9648b4ea4b2d5d604b5f98b36): perf score=2.188937
I20260812 06:18:31.519001 27186 maintenance_manager.cc:643] P e492fe812dfd45e8b3701e03fd864e18: FlushDeltaMemStoresOp(aa6341a9648b4ea4b2d5d604b5f98b36) complete. Timing: real 0.015s	user 0.009s	sys 0.004s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":5955,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:31.519676 27251 maintenance_manager.cc:419] P e492fe812dfd45e8b3701e03fd864e18: Scheduling MajorDeltaCompactionOp(aa6341a9648b4ea4b2d5d604b5f98b36): perf score=1.000000
I20260812 06:18:31.697703 27186 maintenance_manager.cc:643] P e492fe812dfd45e8b3701e03fd864e18: MajorDeltaCompactionOp(aa6341a9648b4ea4b2d5d604b5f98b36) complete. Timing: real 0.178s	user 0.135s	sys 0.032s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774691,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":423,"lbm_read_time_us":10447,"lbm_reads_lt_1ms":572,"lbm_write_time_us":33054,"lbm_writes_lt_1ms":543,"mutex_wait_us":67,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":26368,"update_count":2500}
I20260812 06:18:31.698184 27251 maintenance_manager.cc:419] P e492fe812dfd45e8b3701e03fd864e18: Scheduling FlushDeltaMemStoresOp(aa6341a9648b4ea4b2d5d604b5f98b36): perf score=14.095187
I20260812 06:18:31.749073 27186 maintenance_manager.cc:643] P e492fe812dfd45e8b3701e03fd864e18: FlushDeltaMemStoresOp(aa6341a9648b4ea4b2d5d604b5f98b36) complete. Timing: real 0.051s	user 0.027s	sys 0.014s Metrics: {"bytes_written":16409900,"delete_count":0,"lbm_write_time_us":20144,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:18:31.749550 27251 maintenance_manager.cc:419] P e492fe812dfd45e8b3701e03fd864e18: Scheduling FlushDeltaMemStoresOp(aa6341a9648b4ea4b2d5d604b5f98b36): perf score=2.188937
I20260812 06:18:31.760963 27186 maintenance_manager.cc:643] P e492fe812dfd45e8b3701e03fd864e18: FlushDeltaMemStoresOp(aa6341a9648b4ea4b2d5d604b5f98b36) complete. Timing: real 0.011s	user 0.001s	sys 0.009s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4256,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:31.761544 27251 maintenance_manager.cc:419] P e492fe812dfd45e8b3701e03fd864e18: Scheduling MajorDeltaCompactionOp(aa6341a9648b4ea4b2d5d604b5f98b36): perf score=1.000000
I20260812 06:18:31.914492 27186 maintenance_manager.cc:643] P e492fe812dfd45e8b3701e03fd864e18: MajorDeltaCompactionOp(aa6341a9648b4ea4b2d5d604b5f98b36) complete. Timing: real 0.153s	user 0.120s	sys 0.028s 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":576,"lbm_read_time_us":10685,"lbm_reads_lt_1ms":572,"lbm_write_time_us":30962,"lbm_writes_lt_1ms":543,"mutex_wait_us":263,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":6528,"update_count":2500}
I20260812 06:18:31.915246 27251 maintenance_manager.cc:419] P e492fe812dfd45e8b3701e03fd864e18: Scheduling FlushDeltaMemStoresOp(aa6341a9648b4ea4b2d5d604b5f98b36): perf score=11.118625
I20260812 06:18:31.958595 27186 maintenance_manager.cc:643] P e492fe812dfd45e8b3701e03fd864e18: FlushDeltaMemStoresOp(aa6341a9648b4ea4b2d5d604b5f98b36) complete. Timing: real 0.043s	user 0.026s	sys 0.016s Metrics: {"bytes_written":12717735,"delete_count":0,"lbm_write_time_us":18176,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:18:31.959112 27251 maintenance_manager.cc:419] P e492fe812dfd45e8b3701e03fd864e18: Scheduling FlushDeltaMemStoresOp(aa6341a9648b4ea4b2d5d604b5f98b36): perf score=2.188937
I20260812 06:18:31.980841 27186 maintenance_manager.cc:643] P e492fe812dfd45e8b3701e03fd864e18: FlushDeltaMemStoresOp(aa6341a9648b4ea4b2d5d604b5f98b36) complete. Timing: real 0.022s	user 0.005s	sys 0.008s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":5868,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:18:31.981385 27251 maintenance_manager.cc:419] P e492fe812dfd45e8b3701e03fd864e18: Scheduling FlushDeltaMemStoresOp(aa6341a9648b4ea4b2d5d604b5f98b36): perf score=2.188937
I20260812 06:18:31.996788 27186 maintenance_manager.cc:643] P e492fe812dfd45e8b3701e03fd864e18: FlushDeltaMemStoresOp(aa6341a9648b4ea4b2d5d604b5f98b36) complete. Timing: real 0.015s	user 0.009s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6011,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:31.997349 27251 maintenance_manager.cc:419] P e492fe812dfd45e8b3701e03fd864e18: Scheduling MajorDeltaCompactionOp(aa6341a9648b4ea4b2d5d604b5f98b36): perf score=1.000000
I20260812 06:18:32.154816 27186 maintenance_manager.cc:643] P e492fe812dfd45e8b3701e03fd864e18: MajorDeltaCompactionOp(aa6341a9648b4ea4b2d5d604b5f98b36) complete. Timing: real 0.157s	user 0.124s	sys 0.032s 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":107,"lbm_read_time_us":9865,"lbm_reads_lt_1ms":573,"lbm_write_time_us":31523,"lbm_writes_lt_1ms":543,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":4992,"update_count":2500}
I20260812 06:18:32.155511 27251 maintenance_manager.cc:419] P e492fe812dfd45e8b3701e03fd864e18: Scheduling FlushDeltaMemStoresOp(aa6341a9648b4ea4b2d5d604b5f98b36): perf score=11.118625
I20260812 06:18:32.197327 27186 maintenance_manager.cc:643] P e492fe812dfd45e8b3701e03fd864e18: FlushDeltaMemStoresOp(aa6341a9648b4ea4b2d5d604b5f98b36) complete. Timing: real 0.042s	user 0.028s	sys 0.008s Metrics: {"bytes_written":12717736,"delete_count":0,"lbm_write_time_us":17590,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:18:32.198067 27251 maintenance_manager.cc:419] P e492fe812dfd45e8b3701e03fd864e18: Scheduling FlushDeltaMemStoresOp(aa6341a9648b4ea4b2d5d604b5f98b36): perf score=2.188937
I20260812 06:18:32.210361 27186 maintenance_manager.cc:643] P e492fe812dfd45e8b3701e03fd864e18: FlushDeltaMemStoresOp(aa6341a9648b4ea4b2d5d604b5f98b36) complete. Timing: real 0.012s	user 0.003s	sys 0.008s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":4281,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:18:32.210835 27251 maintenance_manager.cc:419] P e492fe812dfd45e8b3701e03fd864e18: Scheduling FlushMRSOp(aa6341a9648b4ea4b2d5d604b5f98b36): perf score=1.000000
I20260812 06:18:32.238811 27186 maintenance_manager.cc:643] P e492fe812dfd45e8b3701e03fd864e18: FlushMRSOp(aa6341a9648b4ea4b2d5d604b5f98b36) complete. Timing: real 0.028s	user 0.026s	sys 0.001s Metrics: {"bytes_written":1152508,"cfile_init":1,"dirs.queue_time_us":67,"dirs.run_cpu_time_us":248,"dirs.run_wall_time_us":1958,"drs_written":1,"lbm_read_time_us":53,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1644,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":28}
I20260812 06:18:32.239439 27251 maintenance_manager.cc:419] P e492fe812dfd45e8b3701e03fd864e18: Scheduling LogGCOp(aa6341a9648b4ea4b2d5d604b5f98b36): free 112692367 bytes of WAL
I20260812 06:18:32.239713 27186 log_reader.cc:385] T aa6341a9648b4ea4b2d5d604b5f98b36: removed 11 log segments from log reader
I20260812 06:18:32.239776 27186 log.cc:1079] T aa6341a9648b4ea4b2d5d604b5f98b36 P e492fe812dfd45e8b3701e03fd864e18: Deleting log segment in path: /tmp/dist-test-taskn9P66M/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515505003970-26863-0/minicluster-data/ts-0-root/wals/aa6341a9648b4ea4b2d5d604b5f98b36/wal-000000003 (ops 12-16)
I20260812 06:18:32.239817 27186 log.cc:1079] T aa6341a9648b4ea4b2d5d604b5f98b36 P e492fe812dfd45e8b3701e03fd864e18: Deleting log segment in path: /tmp/dist-test-taskn9P66M/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515505003970-26863-0/minicluster-data/ts-0-root/wals/aa6341a9648b4ea4b2d5d604b5f98b36/wal-000000004 (ops 17-21)
I20260812 06:18:32.239845 27186 log.cc:1079] T aa6341a9648b4ea4b2d5d604b5f98b36 P e492fe812dfd45e8b3701e03fd864e18: Deleting log segment in path: /tmp/dist-test-taskn9P66M/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515505003970-26863-0/minicluster-data/ts-0-root/wals/aa6341a9648b4ea4b2d5d604b5f98b36/wal-000000005 (ops 22-26)
I20260812 06:18:32.239866 27186 log.cc:1079] T aa6341a9648b4ea4b2d5d604b5f98b36 P e492fe812dfd45e8b3701e03fd864e18: Deleting log segment in path: /tmp/dist-test-taskn9P66M/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515505003970-26863-0/minicluster-data/ts-0-root/wals/aa6341a9648b4ea4b2d5d604b5f98b36/wal-000000006 (ops 27-31)
I20260812 06:18:32.239898 27186 log.cc:1079] T aa6341a9648b4ea4b2d5d604b5f98b36 P e492fe812dfd45e8b3701e03fd864e18: Deleting log segment in path: /tmp/dist-test-taskn9P66M/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515505003970-26863-0/minicluster-data/ts-0-root/wals/aa6341a9648b4ea4b2d5d604b5f98b36/wal-000000007 (ops 32-36)
I20260812 06:18:32.239926 27186 log.cc:1079] T aa6341a9648b4ea4b2d5d604b5f98b36 P e492fe812dfd45e8b3701e03fd864e18: Deleting log segment in path: /tmp/dist-test-taskn9P66M/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515505003970-26863-0/minicluster-data/ts-0-root/wals/aa6341a9648b4ea4b2d5d604b5f98b36/wal-000000008 (ops 37-41)
I20260812 06:18:32.239956 27186 log.cc:1079] T aa6341a9648b4ea4b2d5d604b5f98b36 P e492fe812dfd45e8b3701e03fd864e18: Deleting log segment in path: /tmp/dist-test-taskn9P66M/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515505003970-26863-0/minicluster-data/ts-0-root/wals/aa6341a9648b4ea4b2d5d604b5f98b36/wal-000000009 (ops 42-46)
I20260812 06:18:32.239979 27186 log.cc:1079] T aa6341a9648b4ea4b2d5d604b5f98b36 P e492fe812dfd45e8b3701e03fd864e18: Deleting log segment in path: /tmp/dist-test-taskn9P66M/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515505003970-26863-0/minicluster-data/ts-0-root/wals/aa6341a9648b4ea4b2d5d604b5f98b36/wal-000000010 (ops 47-51)
I20260812 06:18:32.240005 27186 log.cc:1079] T aa6341a9648b4ea4b2d5d604b5f98b36 P e492fe812dfd45e8b3701e03fd864e18: Deleting log segment in path: /tmp/dist-test-taskn9P66M/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515505003970-26863-0/minicluster-data/ts-0-root/wals/aa6341a9648b4ea4b2d5d604b5f98b36/wal-000000011 (ops 52-56)
I20260812 06:18:32.240034 27186 log.cc:1079] T aa6341a9648b4ea4b2d5d604b5f98b36 P e492fe812dfd45e8b3701e03fd864e18: Deleting log segment in path: /tmp/dist-test-taskn9P66M/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515505003970-26863-0/minicluster-data/ts-0-root/wals/aa6341a9648b4ea4b2d5d604b5f98b36/wal-000000012 (ops 57-61)
I20260812 06:18:32.240065 27186 log.cc:1079] T aa6341a9648b4ea4b2d5d604b5f98b36 P e492fe812dfd45e8b3701e03fd864e18: Deleting log segment in path: /tmp/dist-test-taskn9P66M/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515505003970-26863-0/minicluster-data/ts-0-root/wals/aa6341a9648b4ea4b2d5d604b5f98b36/wal-000000013 (ops 62-66)
I20260812 06:18:32.269371 27186 maintenance_manager.cc:643] P e492fe812dfd45e8b3701e03fd864e18: LogGCOp(aa6341a9648b4ea4b2d5d604b5f98b36) complete. Timing: real 0.030s	user 0.000s	sys 0.026s Metrics: {}
I20260812 06:18:32.269925 27251 maintenance_manager.cc:419] P e492fe812dfd45e8b3701e03fd864e18: Scheduling UndoDeltaBlockGCOp(aa6341a9648b4ea4b2d5d604b5f98b36): 447 bytes on disk
I20260812 06:18:32.270430 27186 maintenance_manager.cc:643] P e492fe812dfd45e8b3701e03fd864e18: UndoDeltaBlockGCOp(aa6341a9648b4ea4b2d5d604b5f98b36) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":57,"lbm_reads_lt_1ms":4}
I20260812 06:18:32.270943 27251 maintenance_manager.cc:419] P e492fe812dfd45e8b3701e03fd864e18: Scheduling FlushDeltaMemStoresOp(aa6341a9648b4ea4b2d5d604b5f98b36): perf score=2.188937
I20260812 06:18:32.295269 27186 maintenance_manager.cc:643] P e492fe812dfd45e8b3701e03fd864e18: FlushDeltaMemStoresOp(aa6341a9648b4ea4b2d5d604b5f98b36) complete. Timing: real 0.024s	user 0.008s	sys 0.007s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6135,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:32.295715 27251 maintenance_manager.cc:419] P e492fe812dfd45e8b3701e03fd864e18: Scheduling FlushDeltaMemStoresOp(aa6341a9648b4ea4b2d5d604b5f98b36): perf score=2.188937
I20260812 06:18:32.306571 27186 maintenance_manager.cc:643] P e492fe812dfd45e8b3701e03fd864e18: FlushDeltaMemStoresOp(aa6341a9648b4ea4b2d5d604b5f98b36) complete. Timing: real 0.011s	user 0.005s	sys 0.005s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4102,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:32.307102 27251 maintenance_manager.cc:419] P e492fe812dfd45e8b3701e03fd864e18: Scheduling MajorDeltaCompactionOp(aa6341a9648b4ea4b2d5d604b5f98b36): perf score=1.000000
I20260812 06:18:32.476649 27186 maintenance_manager.cc:643] P e492fe812dfd45e8b3701e03fd864e18: MajorDeltaCompactionOp(aa6341a9648b4ea4b2d5d604b5f98b36) complete. Timing: real 0.169s	user 0.114s	sys 0.054s Metrics: {"cfile_cache_miss":634,"cfile_cache_miss_bytes":28877330,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":1088,"lbm_read_time_us":12483,"lbm_reads_lt_1ms":674,"lbm_write_time_us":34297,"lbm_writes_lt_1ms":643,"mutex_wait_us":78,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":1280,"thread_start_us":85,"threads_started":1,"update_count":3000}
I20260812 06:18:32.477731 27251 maintenance_manager.cc:419] P e492fe812dfd45e8b3701e03fd864e18: Scheduling FlushDeltaMemStoresOp(aa6341a9648b4ea4b2d5d604b5f98b36): perf score=14.095187
I20260812 06:18:32.530831 27186 maintenance_manager.cc:643] P e492fe812dfd45e8b3701e03fd864e18: FlushDeltaMemStoresOp(aa6341a9648b4ea4b2d5d604b5f98b36) complete. Timing: real 0.053s	user 0.039s	sys 0.012s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":23471,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:18:32.531394 27251 maintenance_manager.cc:419] P e492fe812dfd45e8b3701e03fd864e18: Scheduling FlushDeltaMemStoresOp(aa6341a9648b4ea4b2d5d604b5f98b36): perf score=2.188937
I20260812 06:18:32.544123 27186 maintenance_manager.cc:643] P e492fe812dfd45e8b3701e03fd864e18: FlushDeltaMemStoresOp(aa6341a9648b4ea4b2d5d604b5f98b36) complete. Timing: real 0.013s	user 0.007s	sys 0.003s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4879,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:32.544596 27251 maintenance_manager.cc:419] P e492fe812dfd45e8b3701e03fd864e18: Scheduling MajorDeltaCompactionOp(aa6341a9648b4ea4b2d5d604b5f98b36): perf score=1.000000
I20260812 06:18:32.700649 27186 maintenance_manager.cc:643] P e492fe812dfd45e8b3701e03fd864e18: MajorDeltaCompactionOp(aa6341a9648b4ea4b2d5d604b5f98b36) complete. Timing: real 0.156s	user 0.123s	sys 0.031s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774689,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":1182,"lbm_read_time_us":9000,"lbm_reads_lt_1ms":572,"lbm_write_time_us":31851,"lbm_writes_lt_1ms":543,"mutex_wait_us":345,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":34816,"update_count":2500}
I20260812 06:18:32.701202 27251 maintenance_manager.cc:419] P e492fe812dfd45e8b3701e03fd864e18: Scheduling FlushDeltaMemStoresOp(aa6341a9648b4ea4b2d5d604b5f98b36): perf score=12.110812
I20260812 06:18:32.748844 27186 maintenance_manager.cc:643] P e492fe812dfd45e8b3701e03fd864e18: FlushDeltaMemStoresOp(aa6341a9648b4ea4b2d5d604b5f98b36) complete. Timing: real 0.047s	user 0.020s	sys 0.024s Metrics: {"bytes_written":13948450,"delete_count":0,"lbm_write_time_us":21565,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":342,"reinsert_count":0,"update_count":1700}
I20260812 06:18:32.749302 27251 maintenance_manager.cc:419] P e492fe812dfd45e8b3701e03fd864e18: Scheduling FlushDeltaMemStoresOp(aa6341a9648b4ea4b2d5d604b5f98b36): perf score=1.196750
I20260812 06:18:32.768736 27186 maintenance_manager.cc:643] P e492fe812dfd45e8b3701e03fd864e18: FlushDeltaMemStoresOp(aa6341a9648b4ea4b2d5d604b5f98b36) complete. Timing: real 0.019s	user 0.007s	sys 0.000s Metrics: {"bytes_written":2871909,"delete_count":0,"lbm_write_time_us":3111,"lbm_writes_lt_1ms":73,"reinsert_count":0,"update_count":350}
I20260812 06:18:32.769220 27251 maintenance_manager.cc:419] P e492fe812dfd45e8b3701e03fd864e18: Scheduling FlushDeltaMemStoresOp(aa6341a9648b4ea4b2d5d604b5f98b36): perf score=2.188937
I20260812 06:18:32.779269 27186 maintenance_manager.cc:643] P e492fe812dfd45e8b3701e03fd864e18: FlushDeltaMemStoresOp(aa6341a9648b4ea4b2d5d604b5f98b36) complete. Timing: real 0.010s	user 0.008s	sys 0.000s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3807,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:18:32.779770 27251 maintenance_manager.cc:419] P e492fe812dfd45e8b3701e03fd864e18: Scheduling MajorDeltaCompactionOp(aa6341a9648b4ea4b2d5d604b5f98b36): perf score=1.000000
I20260812 06:18:32.952999 27186 maintenance_manager.cc:643] P e492fe812dfd45e8b3701e03fd864e18: MajorDeltaCompactionOp(aa6341a9648b4ea4b2d5d604b5f98b36) complete. Timing: real 0.173s	user 0.125s	sys 0.048s Metrics: {"cfile_cache_miss":533,"cfile_cache_miss_bytes":24774764,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":985,"lbm_read_time_us":12406,"lbm_reads_lt_1ms":573,"lbm_write_time_us":29763,"lbm_writes_lt_1ms":543,"mutex_wait_us":24,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":11648,"update_count":2500}
I20260812 06:18:32.953727 27251 maintenance_manager.cc:419] P e492fe812dfd45e8b3701e03fd864e18: Scheduling FlushDeltaMemStoresOp(aa6341a9648b4ea4b2d5d604b5f98b36): perf score=14.095187
I20260812 06:18:33.013978 27186 maintenance_manager.cc:643] P e492fe812dfd45e8b3701e03fd864e18: FlushDeltaMemStoresOp(aa6341a9648b4ea4b2d5d604b5f98b36) complete. Timing: real 0.060s	user 0.031s	sys 0.020s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":22853,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:18:33.014634 27251 maintenance_manager.cc:419] P e492fe812dfd45e8b3701e03fd864e18: Scheduling FlushDeltaMemStoresOp(aa6341a9648b4ea4b2d5d604b5f98b36): perf score=2.188937
I20260812 06:18:33.025228 27186 maintenance_manager.cc:643] P e492fe812dfd45e8b3701e03fd864e18: FlushDeltaMemStoresOp(aa6341a9648b4ea4b2d5d604b5f98b36) complete. Timing: real 0.010s	user 0.008s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4074,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:33.025928 27251 maintenance_manager.cc:419] P e492fe812dfd45e8b3701e03fd864e18: Scheduling MajorDeltaCompactionOp(aa6341a9648b4ea4b2d5d604b5f98b36): perf score=1.000000
I20260812 06:18:33.201903 27186 maintenance_manager.cc:643] P e492fe812dfd45e8b3701e03fd864e18: MajorDeltaCompactionOp(aa6341a9648b4ea4b2d5d604b5f98b36) complete. Timing: real 0.176s	user 0.104s	sys 0.070s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774689,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":572,"lbm_read_time_us":14001,"lbm_reads_lt_1ms":572,"lbm_write_time_us":28737,"lbm_writes_lt_1ms":543,"mutex_wait_us":22,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":21248,"update_count":2500}
I20260812 06:18:33.202512 27251 maintenance_manager.cc:419] P e492fe812dfd45e8b3701e03fd864e18: Scheduling FlushDeltaMemStoresOp(aa6341a9648b4ea4b2d5d604b5f98b36): perf score=14.095187
I20260812 06:18:33.261473 27186 maintenance_manager.cc:643] P e492fe812dfd45e8b3701e03fd864e18: FlushDeltaMemStoresOp(aa6341a9648b4ea4b2d5d604b5f98b36) complete. Timing: real 0.059s	user 0.047s	sys 0.008s Metrics: {"bytes_written":16409903,"delete_count":0,"lbm_write_time_us":22213,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:18:33.262063 27251 maintenance_manager.cc:419] P e492fe812dfd45e8b3701e03fd864e18: Scheduling FlushDeltaMemStoresOp(aa6341a9648b4ea4b2d5d604b5f98b36): perf score=2.188937
I20260812 06:18:33.272789 27186 maintenance_manager.cc:643] P e492fe812dfd45e8b3701e03fd864e18: FlushDeltaMemStoresOp(aa6341a9648b4ea4b2d5d604b5f98b36) complete. Timing: real 0.011s	user 0.009s	sys 0.000s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":3981,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:33.273384 27251 maintenance_manager.cc:419] P e492fe812dfd45e8b3701e03fd864e18: Scheduling MajorDeltaCompactionOp(aa6341a9648b4ea4b2d5d604b5f98b36): perf score=1.000000
I20260812 06:18:33.456104 27186 maintenance_manager.cc:643] P e492fe812dfd45e8b3701e03fd864e18: MajorDeltaCompactionOp(aa6341a9648b4ea4b2d5d604b5f98b36) complete. Timing: real 0.182s	user 0.127s	sys 0.051s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774689,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":214,"lbm_read_time_us":12455,"lbm_reads_lt_1ms":572,"lbm_write_time_us":30513,"lbm_writes_lt_1ms":543,"mutex_wait_us":22,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":8064,"update_count":2500}
I20260812 06:18:33.456893 27251 maintenance_manager.cc:419] P e492fe812dfd45e8b3701e03fd864e18: Scheduling FlushDeltaMemStoresOp(aa6341a9648b4ea4b2d5d604b5f98b36): perf score=14.095187
I20260812 06:18:33.518762 27186 maintenance_manager.cc:643] P e492fe812dfd45e8b3701e03fd864e18: FlushDeltaMemStoresOp(aa6341a9648b4ea4b2d5d604b5f98b36) complete. Timing: real 0.062s	user 0.028s	sys 0.027s Metrics: {"bytes_written":16409903,"delete_count":0,"lbm_write_time_us":21469,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:18:33.519488 27251 maintenance_manager.cc:419] P e492fe812dfd45e8b3701e03fd864e18: Scheduling FlushDeltaMemStoresOp(aa6341a9648b4ea4b2d5d604b5f98b36): perf score=2.188937
I20260812 06:18:33.530766 27186 maintenance_manager.cc:643] P e492fe812dfd45e8b3701e03fd864e18: FlushDeltaMemStoresOp(aa6341a9648b4ea4b2d5d604b5f98b36) complete. Timing: real 0.011s	user 0.005s	sys 0.004s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4400,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:33.531414 27251 maintenance_manager.cc:419] P e492fe812dfd45e8b3701e03fd864e18: Scheduling MajorDeltaCompactionOp(aa6341a9648b4ea4b2d5d604b5f98b36): perf score=1.000000
I20260812 06:18:33.719048 27186 maintenance_manager.cc:643] P e492fe812dfd45e8b3701e03fd864e18: MajorDeltaCompactionOp(aa6341a9648b4ea4b2d5d604b5f98b36) complete. Timing: real 0.187s	user 0.124s	sys 0.052s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774689,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":555,"lbm_read_time_us":13401,"lbm_reads_lt_1ms":572,"lbm_write_time_us":29128,"lbm_writes_lt_1ms":543,"mutex_wait_us":47,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":22016,"update_count":2500}
I20260812 06:18:33.719856 27251 maintenance_manager.cc:419] P e492fe812dfd45e8b3701e03fd864e18: Scheduling FlushDeltaMemStoresOp(aa6341a9648b4ea4b2d5d604b5f98b36): perf score=14.095187
I20260812 06:18:33.770428 27186 maintenance_manager.cc:643] P e492fe812dfd45e8b3701e03fd864e18: FlushDeltaMemStoresOp(aa6341a9648b4ea4b2d5d604b5f98b36) complete. Timing: real 0.050s	user 0.030s	sys 0.015s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":20590,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:18:33.770942 27251 maintenance_manager.cc:419] P e492fe812dfd45e8b3701e03fd864e18: Scheduling FlushDeltaMemStoresOp(aa6341a9648b4ea4b2d5d604b5f98b36): perf score=2.188937
I20260812 06:18:33.793614 27186 maintenance_manager.cc:643] P e492fe812dfd45e8b3701e03fd864e18: FlushDeltaMemStoresOp(aa6341a9648b4ea4b2d5d604b5f98b36) complete. Timing: real 0.022s	user 0.007s	sys 0.012s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4635,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:33.794269 27251 maintenance_manager.cc:419] P e492fe812dfd45e8b3701e03fd864e18: Scheduling FlushMRSOp(aa6341a9648b4ea4b2d5d604b5f98b36): perf score=1.000000
I20260812 06:18:33.829798 27186 maintenance_manager.cc:643] P e492fe812dfd45e8b3701e03fd864e18: FlushMRSOp(aa6341a9648b4ea4b2d5d604b5f98b36) complete. Timing: real 0.035s	user 0.028s	sys 0.005s Metrics: {"bytes_written":1316419,"cfile_init":1,"dirs.queue_time_us":95,"dirs.run_cpu_time_us":270,"dirs.run_wall_time_us":1459,"drs_written":1,"lbm_read_time_us":40,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1865,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":32}
I20260812 06:18:33.830454 27251 maintenance_manager.cc:419] P e492fe812dfd45e8b3701e03fd864e18: Scheduling LogGCOp(aa6341a9648b4ea4b2d5d604b5f98b36): free 132571266 bytes of WAL
I20260812 06:18:33.830687 27186 log_reader.cc:385] T aa6341a9648b4ea4b2d5d604b5f98b36: removed 13 log segments from log reader
I20260812 06:18:33.830731 27186 log.cc:1079] T aa6341a9648b4ea4b2d5d604b5f98b36 P e492fe812dfd45e8b3701e03fd864e18: Deleting log segment in path: /tmp/dist-test-taskn9P66M/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515505003970-26863-0/minicluster-data/ts-0-root/wals/aa6341a9648b4ea4b2d5d604b5f98b36/wal-000000014 (ops 67-70)
I20260812 06:18:33.830761 27186 log.cc:1079] T aa6341a9648b4ea4b2d5d604b5f98b36 P e492fe812dfd45e8b3701e03fd864e18: Deleting log segment in path: /tmp/dist-test-taskn9P66M/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515505003970-26863-0/minicluster-data/ts-0-root/wals/aa6341a9648b4ea4b2d5d604b5f98b36/wal-000000015 (ops 71-75)
I20260812 06:18:33.830821 27186 log.cc:1079] T aa6341a9648b4ea4b2d5d604b5f98b36 P e492fe812dfd45e8b3701e03fd864e18: Deleting log segment in path: /tmp/dist-test-taskn9P66M/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515505003970-26863-0/minicluster-data/ts-0-root/wals/aa6341a9648b4ea4b2d5d604b5f98b36/wal-000000016 (ops 76-80)
I20260812 06:18:33.830865 27186 log.cc:1079] T aa6341a9648b4ea4b2d5d604b5f98b36 P e492fe812dfd45e8b3701e03fd864e18: Deleting log segment in path: /tmp/dist-test-taskn9P66M/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515505003970-26863-0/minicluster-data/ts-0-root/wals/aa6341a9648b4ea4b2d5d604b5f98b36/wal-000000017 (ops 81-85)
I20260812 06:18:33.830907 27186 log.cc:1079] T aa6341a9648b4ea4b2d5d604b5f98b36 P e492fe812dfd45e8b3701e03fd864e18: Deleting log segment in path: /tmp/dist-test-taskn9P66M/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515505003970-26863-0/minicluster-data/ts-0-root/wals/aa6341a9648b4ea4b2d5d604b5f98b36/wal-000000018 (ops 86-90)
I20260812 06:18:33.830972 27186 log.cc:1079] T aa6341a9648b4ea4b2d5d604b5f98b36 P e492fe812dfd45e8b3701e03fd864e18: Deleting log segment in path: /tmp/dist-test-taskn9P66M/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515505003970-26863-0/minicluster-data/ts-0-root/wals/aa6341a9648b4ea4b2d5d604b5f98b36/wal-000000019 (ops 91-94)
I20260812 06:18:33.831004 27186 log.cc:1079] T aa6341a9648b4ea4b2d5d604b5f98b36 P e492fe812dfd45e8b3701e03fd864e18: Deleting log segment in path: /tmp/dist-test-taskn9P66M/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515505003970-26863-0/minicluster-data/ts-0-root/wals/aa6341a9648b4ea4b2d5d604b5f98b36/wal-000000020 (ops 95-99)
I20260812 06:18:33.831039 27186 log.cc:1079] T aa6341a9648b4ea4b2d5d604b5f98b36 P e492fe812dfd45e8b3701e03fd864e18: Deleting log segment in path: /tmp/dist-test-taskn9P66M/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515505003970-26863-0/minicluster-data/ts-0-root/wals/aa6341a9648b4ea4b2d5d604b5f98b36/wal-000000021 (ops 100-104)
I20260812 06:18:33.831081 27186 log.cc:1079] T aa6341a9648b4ea4b2d5d604b5f98b36 P e492fe812dfd45e8b3701e03fd864e18: Deleting log segment in path: /tmp/dist-test-taskn9P66M/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515505003970-26863-0/minicluster-data/ts-0-root/wals/aa6341a9648b4ea4b2d5d604b5f98b36/wal-000000022 (ops 105-109)
I20260812 06:18:33.831118 27186 log.cc:1079] T aa6341a9648b4ea4b2d5d604b5f98b36 P e492fe812dfd45e8b3701e03fd864e18: Deleting log segment in path: /tmp/dist-test-taskn9P66M/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515505003970-26863-0/minicluster-data/ts-0-root/wals/aa6341a9648b4ea4b2d5d604b5f98b36/wal-000000023 (ops 110-114)
I20260812 06:18:33.831158 27186 log.cc:1079] T aa6341a9648b4ea4b2d5d604b5f98b36 P e492fe812dfd45e8b3701e03fd864e18: Deleting log segment in path: /tmp/dist-test-taskn9P66M/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515505003970-26863-0/minicluster-data/ts-0-root/wals/aa6341a9648b4ea4b2d5d604b5f98b36/wal-000000024 (ops 115-119)
I20260812 06:18:33.831197 27186 log.cc:1079] T aa6341a9648b4ea4b2d5d604b5f98b36 P e492fe812dfd45e8b3701e03fd864e18: Deleting log segment in path: /tmp/dist-test-taskn9P66M/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515505003970-26863-0/minicluster-data/ts-0-root/wals/aa6341a9648b4ea4b2d5d604b5f98b36/wal-000000025 (ops 120-124)
I20260812 06:18:33.831236 27186 log.cc:1079] T aa6341a9648b4ea4b2d5d604b5f98b36 P e492fe812dfd45e8b3701e03fd864e18: Deleting log segment in path: /tmp/dist-test-taskn9P66M/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515505003970-26863-0/minicluster-data/ts-0-root/wals/aa6341a9648b4ea4b2d5d604b5f98b36/wal-000000026 (ops 125-129)
I20260812 06:18:33.859067 27186 maintenance_manager.cc:643] P e492fe812dfd45e8b3701e03fd864e18: LogGCOp(aa6341a9648b4ea4b2d5d604b5f98b36) complete. Timing: real 0.028s	user 0.004s	sys 0.023s Metrics: {}
I20260812 06:18:33.859573 27251 maintenance_manager.cc:419] P e492fe812dfd45e8b3701e03fd864e18: Scheduling FlushDeltaMemStoresOp(aa6341a9648b4ea4b2d5d604b5f98b36): perf score=3.181125
I20260812 06:18:33.875147 27186 maintenance_manager.cc:643] P e492fe812dfd45e8b3701e03fd864e18: FlushDeltaMemStoresOp(aa6341a9648b4ea4b2d5d604b5f98b36) complete. Timing: real 0.015s	user 0.006s	sys 0.004s Metrics: {"bytes_written":4512903,"delete_count":0,"lbm_write_time_us":4486,"lbm_writes_lt_1ms":113,"reinsert_count":0,"update_count":550}
I20260812 06:18:33.875656 27251 maintenance_manager.cc:419] P e492fe812dfd45e8b3701e03fd864e18: Scheduling FlushDeltaMemStoresOp(aa6341a9648b4ea4b2d5d604b5f98b36): perf score=2.188937
I20260812 06:18:33.886097 27186 maintenance_manager.cc:643] P e492fe812dfd45e8b3701e03fd864e18: FlushDeltaMemStoresOp(aa6341a9648b4ea4b2d5d604b5f98b36) complete. Timing: real 0.010s	user 0.006s	sys 0.004s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":4032,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:18:33.886610 27251 maintenance_manager.cc:419] P e492fe812dfd45e8b3701e03fd864e18: Scheduling UndoDeltaBlockGCOp(aa6341a9648b4ea4b2d5d604b5f98b36): 493 bytes on disk
I20260812 06:18:33.887072 27186 maintenance_manager.cc:643] P e492fe812dfd45e8b3701e03fd864e18: UndoDeltaBlockGCOp(aa6341a9648b4ea4b2d5d604b5f98b36) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":60,"lbm_reads_lt_1ms":4}
I20260812 06:18:33.887759 27251 maintenance_manager.cc:419] P e492fe812dfd45e8b3701e03fd864e18: Scheduling MajorDeltaCompactionOp(aa6341a9648b4ea4b2d5d604b5f98b36): perf score=1.000000
I20260812 06:18:34.117157 27186 maintenance_manager.cc:643] P e492fe812dfd45e8b3701e03fd864e18: MajorDeltaCompactionOp(aa6341a9648b4ea4b2d5d604b5f98b36) complete. Timing: real 0.229s	user 0.156s	sys 0.071s Metrics: {"cfile_cache_miss":734,"cfile_cache_miss_bytes":32979740,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":1077,"lbm_read_time_us":14404,"lbm_reads_lt_1ms":774,"lbm_write_time_us":37556,"lbm_writes_lt_1ms":743,"mutex_wait_us":109,"peak_mem_usage":87969044,"reinsert_count":0,"spinlock_wait_cycles":5120,"thread_start_us":87,"threads_started":1,"update_count":3500}
I20260812 06:18:34.117821 27251 maintenance_manager.cc:419] P e492fe812dfd45e8b3701e03fd864e18: Scheduling FlushDeltaMemStoresOp(aa6341a9648b4ea4b2d5d604b5f98b36): perf score=18.063937
I20260812 06:18:34.194972 27186 maintenance_manager.cc:643] P e492fe812dfd45e8b3701e03fd864e18: FlushDeltaMemStoresOp(aa6341a9648b4ea4b2d5d604b5f98b36) complete. Timing: real 0.077s	user 0.028s	sys 0.032s Metrics: {"bytes_written":20512313,"delete_count":0,"lbm_write_time_us":28482,"lbm_writes_lt_1ms":503,"reinsert_count":0,"update_count":2500}
I20260812 06:18:34.195675 27251 maintenance_manager.cc:419] P e492fe812dfd45e8b3701e03fd864e18: Scheduling FlushDeltaMemStoresOp(aa6341a9648b4ea4b2d5d604b5f98b36): perf score=2.188937
I20260812 06:18:34.209082 27186 maintenance_manager.cc:643] P e492fe812dfd45e8b3701e03fd864e18: FlushDeltaMemStoresOp(aa6341a9648b4ea4b2d5d604b5f98b36) complete. Timing: real 0.013s	user 0.007s	sys 0.003s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4579,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:34.209784 27251 maintenance_manager.cc:419] P e492fe812dfd45e8b3701e03fd864e18: Scheduling MajorDeltaCompactionOp(aa6341a9648b4ea4b2d5d604b5f98b36): perf score=1.000000
I20260812 06:18:34.421273 27186 maintenance_manager.cc:643] P e492fe812dfd45e8b3701e03fd864e18: MajorDeltaCompactionOp(aa6341a9648b4ea4b2d5d604b5f98b36) complete. Timing: real 0.211s	user 0.139s	sys 0.069s Metrics: {"cfile_cache_miss":632,"cfile_cache_miss_bytes":28877100,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":406,"lbm_read_time_us":13928,"lbm_reads_lt_1ms":672,"lbm_write_time_us":36692,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":642,"mutex_wait_us":41,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":15360,"update_count":3000}
I20260812 06:18:34.422569 27251 maintenance_manager.cc:419] P e492fe812dfd45e8b3701e03fd864e18: Scheduling FlushDeltaMemStoresOp(aa6341a9648b4ea4b2d5d604b5f98b36): perf score=17.071750
I20260812 06:18:34.478981 27186 maintenance_manager.cc:643] P e492fe812dfd45e8b3701e03fd864e18: FlushDeltaMemStoresOp(aa6341a9648b4ea4b2d5d604b5f98b36) complete. Timing: real 0.056s	user 0.037s	sys 0.017s Metrics: {"bytes_written":18830326,"delete_count":0,"lbm_write_time_us":24499,"lbm_writes_lt_1ms":462,"reinsert_count":0,"update_count":2295}
I20260812 06:18:34.479511 27251 maintenance_manager.cc:419] P e492fe812dfd45e8b3701e03fd864e18: Scheduling FlushDeltaMemStoresOp(aa6341a9648b4ea4b2d5d604b5f98b36): perf score=1.000000
I20260812 06:18:34.493981 27186 maintenance_manager.cc:643] P e492fe812dfd45e8b3701e03fd864e18: FlushDeltaMemStoresOp(aa6341a9648b4ea4b2d5d604b5f98b36) complete. Timing: real 0.014s	user 0.006s	sys 0.004s Metrics: {"bytes_written":2092431,"delete_count":0,"lbm_write_time_us":3459,"lbm_writes_lt_1ms":54,"reinsert_count":0,"update_count":255}
I20260812 06:18:34.494449 27251 maintenance_manager.cc:419] P e492fe812dfd45e8b3701e03fd864e18: Scheduling FlushDeltaMemStoresOp(aa6341a9648b4ea4b2d5d604b5f98b36): perf score=2.188937
I20260812 06:18:34.504732 27186 maintenance_manager.cc:643] P e492fe812dfd45e8b3701e03fd864e18: FlushDeltaMemStoresOp(aa6341a9648b4ea4b2d5d604b5f98b36) complete. Timing: real 0.010s	user 0.005s	sys 0.004s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3863,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:18:34.505298 27251 maintenance_manager.cc:419] P e492fe812dfd45e8b3701e03fd864e18: Scheduling MajorDeltaCompactionOp(aa6341a9648b4ea4b2d5d604b5f98b36): perf score=1.000000
I20260812 06:18:34.726133 27186 maintenance_manager.cc:643] P e492fe812dfd45e8b3701e03fd864e18: MajorDeltaCompactionOp(aa6341a9648b4ea4b2d5d604b5f98b36) complete. Timing: real 0.221s	user 0.151s	sys 0.064s Metrics: {"cfile_cache_miss":633,"cfile_cache_miss_bytes":28877163,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":675,"lbm_read_time_us":13844,"lbm_reads_lt_1ms":673,"lbm_write_time_us":38805,"lbm_writes_lt_1ms":643,"mutex_wait_us":340,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":7808,"update_count":3000}
I20260812 06:18:34.726835 27251 maintenance_manager.cc:419] P e492fe812dfd45e8b3701e03fd864e18: Scheduling FlushDeltaMemStoresOp(aa6341a9648b4ea4b2d5d604b5f98b36): perf score=17.071750
I20260812 06:18:34.792425 27186 maintenance_manager.cc:643] P e492fe812dfd45e8b3701e03fd864e18: FlushDeltaMemStoresOp(aa6341a9648b4ea4b2d5d604b5f98b36) complete. Timing: real 0.065s	user 0.035s	sys 0.020s Metrics: {"bytes_written":19035451,"delete_count":0,"lbm_write_time_us":26023,"lbm_writes_lt_1ms":467,"reinsert_count":0,"update_count":2320}
I20260812 06:18:34.793099 27251 maintenance_manager.cc:419] P e492fe812dfd45e8b3701e03fd864e18: Scheduling FlushDeltaMemStoresOp(aa6341a9648b4ea4b2d5d604b5f98b36): perf score=4.173312
I20260812 06:18:34.814678 27186 maintenance_manager.cc:643] P e492fe812dfd45e8b3701e03fd864e18: FlushDeltaMemStoresOp(aa6341a9648b4ea4b2d5d604b5f98b36) complete. Timing: real 0.021s	user 0.017s	sys 0.003s Metrics: {"bytes_written":5579537,"delete_count":0,"lbm_write_time_us":8448,"lbm_writes_lt_1ms":139,"reinsert_count":0,"update_count":680}
I20260812 06:18:34.815318 27251 maintenance_manager.cc:419] P e492fe812dfd45e8b3701e03fd864e18: Scheduling MajorDeltaCompactionOp(aa6341a9648b4ea4b2d5d604b5f98b36): perf score=1.000000
I20260812 06:18:35.034228 27186 maintenance_manager.cc:643] P e492fe812dfd45e8b3701e03fd864e18: MajorDeltaCompactionOp(aa6341a9648b4ea4b2d5d604b5f98b36) complete. Timing: real 0.219s	user 0.149s	sys 0.063s Metrics: {"cfile_cache_miss":632,"cfile_cache_miss_bytes":28877110,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":1133,"lbm_read_time_us":17476,"lbm_reads_lt_1ms":672,"lbm_write_time_us":35467,"lbm_writes_lt_1ms":643,"mutex_wait_us":318,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":1920,"update_count":3000}
I20260812 06:18:35.035538 27251 maintenance_manager.cc:419] P e492fe812dfd45e8b3701e03fd864e18: Scheduling FlushDeltaMemStoresOp(aa6341a9648b4ea4b2d5d604b5f98b36): perf score=16.079562
I20260812 06:18:35.091322 27186 maintenance_manager.cc:643] P e492fe812dfd45e8b3701e03fd864e18: FlushDeltaMemStoresOp(aa6341a9648b4ea4b2d5d604b5f98b36) complete. Timing: real 0.056s	user 0.034s	sys 0.020s Metrics: {"bytes_written":17640627,"delete_count":0,"lbm_write_time_us":25627,"lbm_writes_lt_1ms":433,"reinsert_count":0,"update_count":2150}
I20260812 06:18:35.092003 27251 maintenance_manager.cc:419] P e492fe812dfd45e8b3701e03fd864e18: Scheduling FlushDeltaMemStoresOp(aa6341a9648b4ea4b2d5d604b5f98b36): perf score=1.196750
I20260812 06:18:35.115262 27186 maintenance_manager.cc:643] P e492fe812dfd45e8b3701e03fd864e18: FlushDeltaMemStoresOp(aa6341a9648b4ea4b2d5d604b5f98b36) complete. Timing: real 0.023s	user 0.008s	sys 0.004s Metrics: {"bytes_written":2871905,"delete_count":0,"lbm_write_time_us":4852,"lbm_writes_lt_1ms":73,"reinsert_count":0,"update_count":350}
I20260812 06:18:35.115768 27251 maintenance_manager.cc:419] P e492fe812dfd45e8b3701e03fd864e18: Scheduling FlushDeltaMemStoresOp(aa6341a9648b4ea4b2d5d604b5f98b36): perf score=2.188937
I20260812 06:18:35.127053 27186 maintenance_manager.cc:643] P e492fe812dfd45e8b3701e03fd864e18: FlushDeltaMemStoresOp(aa6341a9648b4ea4b2d5d604b5f98b36) complete. Timing: real 0.011s	user 0.010s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4427,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:35.127686 27251 maintenance_manager.cc:419] P e492fe812dfd45e8b3701e03fd864e18: Scheduling MajorDeltaCompactionOp(aa6341a9648b4ea4b2d5d604b5f98b36): perf score=1.000000
I20260812 06:18:35.340097 27186 maintenance_manager.cc:643] P e492fe812dfd45e8b3701e03fd864e18: MajorDeltaCompactionOp(aa6341a9648b4ea4b2d5d604b5f98b36) complete. Timing: real 0.212s	user 0.126s	sys 0.084s Metrics: {"cfile_cache_miss":633,"cfile_cache_miss_bytes":28877191,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":319,"lbm_read_time_us":14486,"lbm_reads_lt_1ms":673,"lbm_write_time_us":37981,"lbm_writes_lt_1ms":643,"mutex_wait_us":78,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":7808,"update_count":3000}
I20260812 06:18:35.341353 27251 maintenance_manager.cc:419] P e492fe812dfd45e8b3701e03fd864e18: Scheduling FlushDeltaMemStoresOp(aa6341a9648b4ea4b2d5d604b5f98b36): perf score=16.079562
I20260812 06:18:35.391830 27186 maintenance_manager.cc:643] P e492fe812dfd45e8b3701e03fd864e18: FlushDeltaMemStoresOp(aa6341a9648b4ea4b2d5d604b5f98b36) complete. Timing: real 0.050s	user 0.033s	sys 0.015s Metrics: {"bytes_written":17681648,"delete_count":0,"lbm_write_time_us":21911,"lbm_writes_lt_1ms":434,"reinsert_count":0,"update_count":2155}
I20260812 06:18:35.392738 27251 maintenance_manager.cc:419] P e492fe812dfd45e8b3701e03fd864e18: Scheduling FlushDeltaMemStoresOp(aa6341a9648b4ea4b2d5d604b5f98b36): perf score=1.196750
I20260812 06:18:35.412752 27186 maintenance_manager.cc:643] P e492fe812dfd45e8b3701e03fd864e18: FlushDeltaMemStoresOp(aa6341a9648b4ea4b2d5d604b5f98b36) complete. Timing: real 0.020s	user 0.007s	sys 0.003s Metrics: {"bytes_written":2830880,"delete_count":0,"lbm_write_time_us":4507,"lbm_writes_lt_1ms":72,"reinsert_count":0,"update_count":345}
I20260812 06:18:35.413321 27251 maintenance_manager.cc:419] P e492fe812dfd45e8b3701e03fd864e18: Scheduling FlushDeltaMemStoresOp(aa6341a9648b4ea4b2d5d604b5f98b36): perf score=2.188937
I20260812 06:18:35.425082 27186 maintenance_manager.cc:643] P e492fe812dfd45e8b3701e03fd864e18: FlushDeltaMemStoresOp(aa6341a9648b4ea4b2d5d604b5f98b36) complete. Timing: real 0.012s	user 0.006s	sys 0.003s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4757,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:35.425712 27251 maintenance_manager.cc:419] P e492fe812dfd45e8b3701e03fd864e18: Scheduling FlushMRSOp(aa6341a9648b4ea4b2d5d604b5f98b36): perf score=1.000000
I20260812 06:18:35.461651 27186 maintenance_manager.cc:643] P e492fe812dfd45e8b3701e03fd864e18: FlushMRSOp(aa6341a9648b4ea4b2d5d604b5f98b36) complete. Timing: real 0.036s	user 0.031s	sys 0.001s Metrics: {"bytes_written":1316417,"cfile_init":1,"dirs.queue_time_us":75,"dirs.run_cpu_time_us":252,"dirs.run_wall_time_us":1328,"drs_written":1,"lbm_read_time_us":48,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1849,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":32}
I20260812 06:18:35.462395 27251 maintenance_manager.cc:419] P e492fe812dfd45e8b3701e03fd864e18: Scheduling LogGCOp(aa6341a9648b4ea4b2d5d604b5f98b36): free 129320856 bytes of WAL
I20260812 06:18:35.462643 27186 log_reader.cc:385] T aa6341a9648b4ea4b2d5d604b5f98b36: removed 13 log segments from log reader
I20260812 06:18:35.462708 27186 log.cc:1079] T aa6341a9648b4ea4b2d5d604b5f98b36 P e492fe812dfd45e8b3701e03fd864e18: Deleting log segment in path: /tmp/dist-test-taskn9P66M/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515505003970-26863-0/minicluster-data/ts-0-root/wals/aa6341a9648b4ea4b2d5d604b5f98b36/wal-000000027 (ops 130-134)
I20260812 06:18:35.462765 27186 log.cc:1079] T aa6341a9648b4ea4b2d5d604b5f98b36 P e492fe812dfd45e8b3701e03fd864e18: Deleting log segment in path: /tmp/dist-test-taskn9P66M/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515505003970-26863-0/minicluster-data/ts-0-root/wals/aa6341a9648b4ea4b2d5d604b5f98b36/wal-000000028 (ops 135-138)
I20260812 06:18:35.462823 27186 log.cc:1079] T aa6341a9648b4ea4b2d5d604b5f98b36 P e492fe812dfd45e8b3701e03fd864e18: Deleting log segment in path: /tmp/dist-test-taskn9P66M/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515505003970-26863-0/minicluster-data/ts-0-root/wals/aa6341a9648b4ea4b2d5d604b5f98b36/wal-000000029 (ops 139-143)
I20260812 06:18:35.462867 27186 log.cc:1079] T aa6341a9648b4ea4b2d5d604b5f98b36 P e492fe812dfd45e8b3701e03fd864e18: Deleting log segment in path: /tmp/dist-test-taskn9P66M/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515505003970-26863-0/minicluster-data/ts-0-root/wals/aa6341a9648b4ea4b2d5d604b5f98b36/wal-000000030 (ops 144-148)
I20260812 06:18:35.462904 27186 log.cc:1079] T aa6341a9648b4ea4b2d5d604b5f98b36 P e492fe812dfd45e8b3701e03fd864e18: Deleting log segment in path: /tmp/dist-test-taskn9P66M/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515505003970-26863-0/minicluster-data/ts-0-root/wals/aa6341a9648b4ea4b2d5d604b5f98b36/wal-000000031 (ops 149-152)
I20260812 06:18:35.462942 27186 log.cc:1079] T aa6341a9648b4ea4b2d5d604b5f98b36 P e492fe812dfd45e8b3701e03fd864e18: Deleting log segment in path: /tmp/dist-test-taskn9P66M/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515505003970-26863-0/minicluster-data/ts-0-root/wals/aa6341a9648b4ea4b2d5d604b5f98b36/wal-000000032 (ops 153-157)
I20260812 06:18:35.462980 27186 log.cc:1079] T aa6341a9648b4ea4b2d5d604b5f98b36 P e492fe812dfd45e8b3701e03fd864e18: Deleting log segment in path: /tmp/dist-test-taskn9P66M/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515505003970-26863-0/minicluster-data/ts-0-root/wals/aa6341a9648b4ea4b2d5d604b5f98b36/wal-000000033 (ops 158-162)
I20260812 06:18:35.463018 27186 log.cc:1079] T aa6341a9648b4ea4b2d5d604b5f98b36 P e492fe812dfd45e8b3701e03fd864e18: Deleting log segment in path: /tmp/dist-test-taskn9P66M/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515505003970-26863-0/minicluster-data/ts-0-root/wals/aa6341a9648b4ea4b2d5d604b5f98b36/wal-000000034 (ops 163-167)
I20260812 06:18:35.463056 27186 log.cc:1079] T aa6341a9648b4ea4b2d5d604b5f98b36 P e492fe812dfd45e8b3701e03fd864e18: Deleting log segment in path: /tmp/dist-test-taskn9P66M/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515505003970-26863-0/minicluster-data/ts-0-root/wals/aa6341a9648b4ea4b2d5d604b5f98b36/wal-000000035 (ops 168-172)
I20260812 06:18:35.463095 27186 log.cc:1079] T aa6341a9648b4ea4b2d5d604b5f98b36 P e492fe812dfd45e8b3701e03fd864e18: Deleting log segment in path: /tmp/dist-test-taskn9P66M/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515505003970-26863-0/minicluster-data/ts-0-root/wals/aa6341a9648b4ea4b2d5d604b5f98b36/wal-000000036 (ops 173-177)
I20260812 06:18:35.463131 27186 log.cc:1079] T aa6341a9648b4ea4b2d5d604b5f98b36 P e492fe812dfd45e8b3701e03fd864e18: Deleting log segment in path: /tmp/dist-test-taskn9P66M/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515505003970-26863-0/minicluster-data/ts-0-root/wals/aa6341a9648b4ea4b2d5d604b5f98b36/wal-000000037 (ops 178-182)
I20260812 06:18:35.463172 27186 log.cc:1079] T aa6341a9648b4ea4b2d5d604b5f98b36 P e492fe812dfd45e8b3701e03fd864e18: Deleting log segment in path: /tmp/dist-test-taskn9P66M/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515505003970-26863-0/minicluster-data/ts-0-root/wals/aa6341a9648b4ea4b2d5d604b5f98b36/wal-000000038 (ops 183-187)
I20260812 06:18:35.463212 27186 log.cc:1079] T aa6341a9648b4ea4b2d5d604b5f98b36 P e492fe812dfd45e8b3701e03fd864e18: Deleting log segment in path: /tmp/dist-test-taskn9P66M/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515505003970-26863-0/minicluster-data/ts-0-root/wals/aa6341a9648b4ea4b2d5d604b5f98b36/wal-000000039 (ops 188-192)
I20260812 06:18:35.491832 27186 maintenance_manager.cc:643] P e492fe812dfd45e8b3701e03fd864e18: LogGCOp(aa6341a9648b4ea4b2d5d604b5f98b36) complete. Timing: real 0.029s	user 0.000s	sys 0.027s Metrics: {}
I20260812 06:18:35.492269 27251 maintenance_manager.cc:419] P e492fe812dfd45e8b3701e03fd864e18: Scheduling UndoDeltaBlockGCOp(aa6341a9648b4ea4b2d5d604b5f98b36): 492 bytes on disk
I20260812 06:18:35.492726 27186 maintenance_manager.cc:643] P e492fe812dfd45e8b3701e03fd864e18: UndoDeltaBlockGCOp(aa6341a9648b4ea4b2d5d604b5f98b36) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":61,"lbm_reads_lt_1ms":4}
I20260812 06:18:35.493408 27251 maintenance_manager.cc:419] P e492fe812dfd45e8b3701e03fd864e18: Scheduling FlushDeltaMemStoresOp(aa6341a9648b4ea4b2d5d604b5f98b36): perf score=3.181125
I20260812 06:18:35.514205 27186 maintenance_manager.cc:643] P e492fe812dfd45e8b3701e03fd864e18: FlushDeltaMemStoresOp(aa6341a9648b4ea4b2d5d604b5f98b36) complete. Timing: real 0.021s	user 0.013s	sys 0.004s Metrics: {"bytes_written":4512903,"delete_count":0,"lbm_write_time_us":7135,"lbm_writes_lt_1ms":113,"reinsert_count":0,"update_count":550}
I20260812 06:18:35.514742 27251 maintenance_manager.cc:419] P e492fe812dfd45e8b3701e03fd864e18: Scheduling FlushDeltaMemStoresOp(aa6341a9648b4ea4b2d5d604b5f98b36): perf score=2.188937
I20260812 06:18:35.524405 27186 maintenance_manager.cc:643] P e492fe812dfd45e8b3701e03fd864e18: FlushDeltaMemStoresOp(aa6341a9648b4ea4b2d5d604b5f98b36) complete. Timing: real 0.009s	user 0.004s	sys 0.003s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3544,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:18:35.524906 27251 maintenance_manager.cc:419] P e492fe812dfd45e8b3701e03fd864e18: Scheduling MajorDeltaCompactionOp(aa6341a9648b4ea4b2d5d604b5f98b36): perf score=1.000000
I20260812 06:18:35.617825 26863 heavy-update-compaction-itest.cc:229] Time spent updating: real 4.963s	user 1.840s	sys 0.172s
I20260812 06:18:35.729877 26863 heavy-update-compaction-itest.cc:265] Time spent scanning: real 0.112s	user 0.004s	sys 0.000s
I20260812 06:18:35.730479 26863 tablet_server.cc:179] TabletServer@127.26.59.193:0 shutting down...
I20260812 06:18:35.760098 27186 maintenance_manager.cc:643] P e492fe812dfd45e8b3701e03fd864e18: MajorDeltaCompactionOp(aa6341a9648b4ea4b2d5d604b5f98b36) complete. Timing: real 0.235s	user 0.187s	sys 0.048s Metrics: {"cfile_cache_miss":835,"cfile_cache_miss_bytes":37082239,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":5,"delta_iterators_relevant":5,"dirs.queue_time_us":817,"lbm_read_time_us":17782,"lbm_reads_lt_1ms":871,"lbm_write_time_us":40143,"lbm_writes_lt_1ms":843,"mutex_wait_us":106,"peak_mem_usage":100395616,"reinsert_count":0,"spinlock_wait_cycles":24960,"thread_start_us":93,"threads_started":1,"update_count":4000}
I20260812 06:18:35.760987 26863 ts_tablet_manager.cc:1507] Shutting down tablet manager...
I20260812 06:18:35.761459 26863 tablet_replica.cc:333] T aa6341a9648b4ea4b2d5d604b5f98b36 P e492fe812dfd45e8b3701e03fd864e18: stopping tablet replica
I20260812 06:18:35.761641 26863 raft_consensus.cc:2243] T aa6341a9648b4ea4b2d5d604b5f98b36 P e492fe812dfd45e8b3701e03fd864e18 [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:18:35.761824 26863 raft_consensus.cc:2272] T aa6341a9648b4ea4b2d5d604b5f98b36 P e492fe812dfd45e8b3701e03fd864e18 [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:18:35.777807 26863 tablet_server.cc:196] TabletServer@127.26.59.193:0 shutdown complete.
I20260812 06:18:35.832087 26863 master.cc:562] Master@127.26.59.254:45763 shutting down...
I20260812 06:18:35.835554 26863 raft_consensus.cc:2243] T 00000000000000000000000000000000 P 13ba9107224342c2a62b762433525e19 [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:18:35.835741 26863 raft_consensus.cc:2272] T 00000000000000000000000000000000 P 13ba9107224342c2a62b762433525e19 [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:18:35.835793 26863 tablet_replica.cc:333] T 00000000000000000000000000000000 P 13ba9107224342c2a62b762433525e19: stopping tablet replica
I20260812 06:18:35.848392 26863 master.cc:584] Master@127.26.59.254:45763 shutdown complete.
[       OK ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/1 (5495 ms)
[----------] 2 tests from EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy (10922 ms total)

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