[==========] Running 2 tests from 1 test suite.
[----------] Global test environment set-up.
[----------] 2 tests from EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy
[ RUN      ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/0
WARNING: Logging before InitGoogleLogging() is written to STDERR
I20260812 06:19:48.362833  6621 internal_mini_cluster.cc:156] Creating distributed mini masters. Addrs: 127.6.119.126:44237
I20260812 06:19:48.363834  6621 env_posix.cc:2285] Not raising this process' open files per process limit of 1048576; it is already as high as it can go
I20260812 06:19:48.364456  6621 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:19:48.370736  6628 instance_detector.cc:116] could not retrieve AWS instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:19:48.370899  6629 instance_detector.cc:116] could not retrieve Azure instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:19:48.371004  6631 instance_detector.cc:116] could not retrieve OpenStack instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:19:48.370947  6621 server_base.cc:1061] running on GCE node
I20260812 06:19:48.371649  6621 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:19:48.371757  6621 system_unsync_time.cc:38] NTP support is disabled. Clock error bounds will not be accurate. This configuration is not suitable for distributed clusters.
I20260812 06:19:48.371804  6621 hybrid_clock.cc:648] HybridClock initialized: now 1786515588371801 us; error 0 us; skew 500 ppm
I20260812 06:19:48.373524  6621 webserver.cc:533] Webserver started at http://127.6.119.126:34551/ using document root <none> and password file <none>
I20260812 06:19:48.374070  6621 fs_manager.cc:362] Metadata directory not provided
I20260812 06:19:48.374152  6621 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:19:48.374392  6621 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:19:48.376633  6621 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskTJlGYB/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515588352133-6621-0/minicluster-data/master-0-root/instance:
uuid: "dbfb40d8d29f41798c423e936f3d5d5d"
format_stamp: "Formatted at 2026-08-12 06:19:48 on dist-test-slave-gp6n"
I20260812 06:19:48.380610  6621 fs_manager.cc:696] Time spent creating directory manager: real 0.003s	user 0.000s	sys 0.005s
I20260812 06:19:48.382678  6636 log_block_manager.cc:4127] Time spent loading block containers with low live blocks: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:19:48.383653  6621 fs_manager.cc:730] Time spent opening block manager: real 0.002s	user 0.001s	sys 0.001s
I20260812 06:19:48.383785  6621 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskTJlGYB/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515588352133-6621-0/minicluster-data/master-0-root
uuid: "dbfb40d8d29f41798c423e936f3d5d5d"
format_stamp: "Formatted at 2026-08-12 06:19:48 on dist-test-slave-gp6n"
I20260812 06:19:48.383889  6621 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskTJlGYB/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515588352133-6621-0/minicluster-data/master-0-root
metadata directory: /tmp/dist-test-taskTJlGYB/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515588352133-6621-0/minicluster-data/master-0-root
1 data directories: /tmp/dist-test-taskTJlGYB/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515588352133-6621-0/minicluster-data/master-0-root/data
Total live blocks: 0
Total live bytes: 0
Total live bytes (after alignment): 0
Total number of LBM containers: 0 (0 full)
Did not check for missing blocks
Did not check for orphaned blocks
Total full LBM containers with extra space: 0 (0 repaired)
Total full LBM container extra space in bytes: 0 (0 repaired)
Total incomplete LBM containers: 0 (0 repaired)
Total LBM partial records: 0 (0 repaired)
Total corrupted LBM metadata records in RocksDB: 0 (0 repaired)
I20260812 06:19:48.404683  6621 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:19:48.405334  6621 env_posix.cc:2285] Not raising this process' running threads per effective uid limit of 18446744073709551615; it is already as high as it can go
I20260812 06:19:48.405531  6621 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:19:48.413368  6621 rpc_server.cc:307] RPC server started. Bound to: 127.6.119.126:44237
I20260812 06:19:48.413379  6701 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.6.119.126:44237 every 8 connection(s)
I20260812 06:19:48.415565  6702 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet 00000000000000000000000000000000. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:19:48.420729  6702 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P dbfb40d8d29f41798c423e936f3d5d5d: Bootstrap starting.
I20260812 06:19:48.422952  6702 tablet_bootstrap.cc:654] T 00000000000000000000000000000000 P dbfb40d8d29f41798c423e936f3d5d5d: Neither blocks nor log segments found. Creating new log.
I20260812 06:19:48.423765  6702 log.cc:826] T 00000000000000000000000000000000 P dbfb40d8d29f41798c423e936f3d5d5d: Log is configured to *not* fsync() on all Append() calls
I20260812 06:19:48.425318  6702 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P dbfb40d8d29f41798c423e936f3d5d5d: No bootstrap required, opened a new log
I20260812 06:19:48.428030  6702 raft_consensus.cc:359] T 00000000000000000000000000000000 P dbfb40d8d29f41798c423e936f3d5d5d [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "dbfb40d8d29f41798c423e936f3d5d5d" member_type: VOTER }
I20260812 06:19:48.428184  6702 raft_consensus.cc:385] T 00000000000000000000000000000000 P dbfb40d8d29f41798c423e936f3d5d5d [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:19:48.428223  6702 raft_consensus.cc:740] T 00000000000000000000000000000000 P dbfb40d8d29f41798c423e936f3d5d5d [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: dbfb40d8d29f41798c423e936f3d5d5d, State: Initialized, Role: FOLLOWER
I20260812 06:19:48.428704  6702 consensus_queue.cc:260] T 00000000000000000000000000000000 P dbfb40d8d29f41798c423e936f3d5d5d [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: "dbfb40d8d29f41798c423e936f3d5d5d" member_type: VOTER }
I20260812 06:19:48.428826  6702 raft_consensus.cc:399] T 00000000000000000000000000000000 P dbfb40d8d29f41798c423e936f3d5d5d [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:19:48.428869  6702 raft_consensus.cc:493] T 00000000000000000000000000000000 P dbfb40d8d29f41798c423e936f3d5d5d [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:19:48.428956  6702 raft_consensus.cc:3060] T 00000000000000000000000000000000 P dbfb40d8d29f41798c423e936f3d5d5d [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:19:48.429670  6702 raft_consensus.cc:515] T 00000000000000000000000000000000 P dbfb40d8d29f41798c423e936f3d5d5d [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "dbfb40d8d29f41798c423e936f3d5d5d" member_type: VOTER }
I20260812 06:19:48.430037  6702 leader_election.cc:304] T 00000000000000000000000000000000 P dbfb40d8d29f41798c423e936f3d5d5d [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: dbfb40d8d29f41798c423e936f3d5d5d; no voters: 
I20260812 06:19:48.430279  6702 leader_election.cc:290] T 00000000000000000000000000000000 P dbfb40d8d29f41798c423e936f3d5d5d [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:19:48.430431  6708 raft_consensus.cc:2804] T 00000000000000000000000000000000 P dbfb40d8d29f41798c423e936f3d5d5d [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:19:48.430689  6708 raft_consensus.cc:697] T 00000000000000000000000000000000 P dbfb40d8d29f41798c423e936f3d5d5d [term 1 LEADER]: Becoming Leader. State: Replica: dbfb40d8d29f41798c423e936f3d5d5d, State: Running, Role: LEADER
I20260812 06:19:48.431133  6708 consensus_queue.cc:237] T 00000000000000000000000000000000 P dbfb40d8d29f41798c423e936f3d5d5d [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: "dbfb40d8d29f41798c423e936f3d5d5d" member_type: VOTER }
I20260812 06:19:48.431221  6702 sys_catalog.cc:565] T 00000000000000000000000000000000 P dbfb40d8d29f41798c423e936f3d5d5d [sys.catalog]: configured and running, proceeding with master startup.
I20260812 06:19:48.432924  6709 sys_catalog.cc:455] T 00000000000000000000000000000000 P dbfb40d8d29f41798c423e936f3d5d5d [sys.catalog]: SysCatalogTable state changed. Reason: RaftConsensus started. Latest consensus state: current_term: 1 leader_uuid: "dbfb40d8d29f41798c423e936f3d5d5d" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "dbfb40d8d29f41798c423e936f3d5d5d" member_type: VOTER } }
I20260812 06:19:48.432962  6710 sys_catalog.cc:455] T 00000000000000000000000000000000 P dbfb40d8d29f41798c423e936f3d5d5d [sys.catalog]: SysCatalogTable state changed. Reason: New leader dbfb40d8d29f41798c423e936f3d5d5d. Latest consensus state: current_term: 1 leader_uuid: "dbfb40d8d29f41798c423e936f3d5d5d" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "dbfb40d8d29f41798c423e936f3d5d5d" member_type: VOTER } }
I20260812 06:19:48.433066  6710 sys_catalog.cc:458] T 00000000000000000000000000000000 P dbfb40d8d29f41798c423e936f3d5d5d [sys.catalog]: This master's current role is: LEADER
I20260812 06:19:48.433050  6709 sys_catalog.cc:458] T 00000000000000000000000000000000 P dbfb40d8d29f41798c423e936f3d5d5d [sys.catalog]: This master's current role is: LEADER
I20260812 06:19:48.433601  6621 internal_mini_cluster.cc:184] Waiting to initialize catalog manager on master 0
W20260812 06:19:48.435477  6725 catalog_manager.cc:1594] T 00000000000000000000000000000000 P dbfb40d8d29f41798c423e936f3d5d5d: loading cluster ID for follower catalog manager: Not found: cluster ID entry not found
W20260812 06:19:48.435539  6725 catalog_manager.cc:883] Not found: cluster ID entry not found: failed to prepare follower catalog manager, will retry
I20260812 06:19:48.435616  6722 catalog_manager.cc:1511] Loading table and tablet metadata into memory...
I20260812 06:19:48.436318  6722 catalog_manager.cc:1520] Initializing Kudu cluster ID...
I20260812 06:19:48.440659  6722 catalog_manager.cc:1383] Generated new cluster ID: a90a88a0ed97443db9c6b34edf542773
I20260812 06:19:48.440721  6722 catalog_manager.cc:1531] Initializing Kudu internal certificate authority...
I20260812 06:19:48.457377  6722 catalog_manager.cc:1406] Generated new certificate authority record
I20260812 06:19:48.458232  6722 catalog_manager.cc:1540] Loading token signing keys...
I20260812 06:19:48.465341  6722 catalog_manager.cc:6092] T 00000000000000000000000000000000 P dbfb40d8d29f41798c423e936f3d5d5d: Generated new TSK 0
I20260812 06:19:48.465912  6722 catalog_manager.cc:1550] Initializing in-progress tserver states...
I20260812 06:19:48.498566  6621 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:19:48.501902  6734 instance_detector.cc:116] could not retrieve OpenStack instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:19:48.501917  6730 instance_detector.cc:116] could not retrieve Azure instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:19:48.501917  6729 instance_detector.cc:116] could not retrieve AWS instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:19:48.502121  6621 server_base.cc:1061] running on GCE node
I20260812 06:19:48.502345  6621 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:19:48.502386  6621 system_unsync_time.cc:38] NTP support is disabled. Clock error bounds will not be accurate. This configuration is not suitable for distributed clusters.
I20260812 06:19:48.502449  6621 hybrid_clock.cc:648] HybridClock initialized: now 1786515588502448 us; error 0 us; skew 500 ppm
I20260812 06:19:48.503414  6621 webserver.cc:533] Webserver started at http://127.6.119.65:46231/ using document root <none> and password file <none>
I20260812 06:19:48.503607  6621 fs_manager.cc:362] Metadata directory not provided
I20260812 06:19:48.503671  6621 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:19:48.503772  6621 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:19:48.504189  6621 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskTJlGYB/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515588352133-6621-0/minicluster-data/ts-0-root/instance:
uuid: "cd35e2b62ca0493fbaaeda698df4b49b"
format_stamp: "Formatted at 2026-08-12 06:19:48 on dist-test-slave-gp6n"
I20260812 06:19:48.505769  6621 fs_manager.cc:696] Time spent creating directory manager: real 0.001s	user 0.000s	sys 0.002s
I20260812 06:19:48.506845  6739 log_block_manager.cc:4127] Time spent loading block containers with low live blocks: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:19:48.507082  6621 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.000s	sys 0.001s
I20260812 06:19:48.507159  6621 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskTJlGYB/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515588352133-6621-0/minicluster-data/ts-0-root
uuid: "cd35e2b62ca0493fbaaeda698df4b49b"
format_stamp: "Formatted at 2026-08-12 06:19:48 on dist-test-slave-gp6n"
I20260812 06:19:48.507254  6621 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskTJlGYB/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515588352133-6621-0/minicluster-data/ts-0-root
metadata directory: /tmp/dist-test-taskTJlGYB/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515588352133-6621-0/minicluster-data/ts-0-root
1 data directories: /tmp/dist-test-taskTJlGYB/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515588352133-6621-0/minicluster-data/ts-0-root/data
Total live blocks: 0
Total live bytes: 0
Total live bytes (after alignment): 0
Total number of LBM containers: 0 (0 full)
Did not check for missing blocks
Did not check for orphaned blocks
Total full LBM containers with extra space: 0 (0 repaired)
Total full LBM container extra space in bytes: 0 (0 repaired)
Total incomplete LBM containers: 0 (0 repaired)
Total LBM partial records: 0 (0 repaired)
Total corrupted LBM metadata records in RocksDB: 0 (0 repaired)
I20260812 06:19:48.511461  6621 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:19:48.511883  6621 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:19:48.512382  6621 txn_system_client.cc:432] TxnSystemClient initialization is disabled...
I20260812 06:19:48.513214  6621 ts_tablet_manager.cc:585] Loaded tablet metadata (0 total tablets, 0 live tablets)
I20260812 06:19:48.513264  6621 ts_tablet_manager.cc:531] Time spent load tablet metadata: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:19:48.513332  6621 ts_tablet_manager.cc:616] Registered 0 tablets
I20260812 06:19:48.513370  6621 ts_tablet_manager.cc:595] Time spent register tablets: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:19:48.520187  6621 rpc_server.cc:307] RPC server started. Bound to: 127.6.119.65:45637
I20260812 06:19:48.520222  6815 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.6.119.65:45637 every 8 connection(s)
I20260812 06:19:48.534042  6816 heartbeater.cc:344] Connected to a master server at 127.6.119.126:44237
I20260812 06:19:48.534301  6816 heartbeater.cc:461] Registering TS with master...
I20260812 06:19:48.534754  6816 heartbeater.cc:507] Master 127.6.119.126:44237 requested a full tablet report, sending...
I20260812 06:19:48.536144  6658 ts_manager.cc:194] Registered new tserver with Master: cd35e2b62ca0493fbaaeda698df4b49b (127.6.119.65:45637)
I20260812 06:19:48.536250  6621 internal_mini_cluster.cc:371] 1 TS(s) registered with all masters after 0.015422685s
I20260812 06:19:48.537319  6658 master_service.cc:502] Signed X509 certificate for tserver {username='slave'} at 127.0.0.1:56574
I20260812 06:19:48.545675  6658 catalog_manager.cc:2283] Servicing CreateTable request from {username='slave'} at 127.0.0.1:56580:
name: "heavy-update-compaction-test"
schema {
  columns {
    name: "key"
    type: INT64
    is_key: true
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_a"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_b"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_c"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_d"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_e"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
}
num_replicas: 1
split_rows_range_bounds {
}
partition_schema {
  range_schema {
  }
}
I20260812 06:19:48.560118  6771 tablet_service.cc:1511] Processing CreateTablet for tablet cd52d03fc5fd479b921e4730520f01ad (DEFAULT_TABLE table=heavy-update-compaction-test [id=7b7216ef8ba441b59e82d28a1ed796c7]), partition=
I20260812 06:19:48.560602  6771 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet cd52d03fc5fd479b921e4730520f01ad. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:19:48.563094  6833 tablet_bootstrap.cc:492] T cd52d03fc5fd479b921e4730520f01ad P cd35e2b62ca0493fbaaeda698df4b49b: Bootstrap starting.
I20260812 06:19:48.564225  6833 tablet_bootstrap.cc:654] T cd52d03fc5fd479b921e4730520f01ad P cd35e2b62ca0493fbaaeda698df4b49b: Neither blocks nor log segments found. Creating new log.
I20260812 06:19:48.565632  6833 tablet_bootstrap.cc:492] T cd52d03fc5fd479b921e4730520f01ad P cd35e2b62ca0493fbaaeda698df4b49b: No bootstrap required, opened a new log
I20260812 06:19:48.565716  6833 ts_tablet_manager.cc:1403] T cd52d03fc5fd479b921e4730520f01ad P cd35e2b62ca0493fbaaeda698df4b49b: Time spent bootstrapping tablet: real 0.003s	user 0.002s	sys 0.000s
I20260812 06:19:48.566190  6833 raft_consensus.cc:359] T cd52d03fc5fd479b921e4730520f01ad P cd35e2b62ca0493fbaaeda698df4b49b [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "cd35e2b62ca0493fbaaeda698df4b49b" member_type: VOTER last_known_addr { host: "127.6.119.65" port: 45637 } }
I20260812 06:19:48.566289  6833 raft_consensus.cc:385] T cd52d03fc5fd479b921e4730520f01ad P cd35e2b62ca0493fbaaeda698df4b49b [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:19:48.566313  6833 raft_consensus.cc:740] T cd52d03fc5fd479b921e4730520f01ad P cd35e2b62ca0493fbaaeda698df4b49b [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: cd35e2b62ca0493fbaaeda698df4b49b, State: Initialized, Role: FOLLOWER
I20260812 06:19:48.566501  6833 consensus_queue.cc:260] T cd52d03fc5fd479b921e4730520f01ad P cd35e2b62ca0493fbaaeda698df4b49b [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: "cd35e2b62ca0493fbaaeda698df4b49b" member_type: VOTER last_known_addr { host: "127.6.119.65" port: 45637 } }
I20260812 06:19:48.566586  6833 raft_consensus.cc:399] T cd52d03fc5fd479b921e4730520f01ad P cd35e2b62ca0493fbaaeda698df4b49b [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:19:48.566634  6833 raft_consensus.cc:493] T cd52d03fc5fd479b921e4730520f01ad P cd35e2b62ca0493fbaaeda698df4b49b [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:19:48.566700  6833 raft_consensus.cc:3060] T cd52d03fc5fd479b921e4730520f01ad P cd35e2b62ca0493fbaaeda698df4b49b [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:19:48.567615  6833 raft_consensus.cc:515] T cd52d03fc5fd479b921e4730520f01ad P cd35e2b62ca0493fbaaeda698df4b49b [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "cd35e2b62ca0493fbaaeda698df4b49b" member_type: VOTER last_known_addr { host: "127.6.119.65" port: 45637 } }
I20260812 06:19:48.567786  6833 leader_election.cc:304] T cd52d03fc5fd479b921e4730520f01ad P cd35e2b62ca0493fbaaeda698df4b49b [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: cd35e2b62ca0493fbaaeda698df4b49b; no voters: 
I20260812 06:19:48.568085  6833 leader_election.cc:290] T cd52d03fc5fd479b921e4730520f01ad P cd35e2b62ca0493fbaaeda698df4b49b [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:19:48.568213  6835 raft_consensus.cc:2804] T cd52d03fc5fd479b921e4730520f01ad P cd35e2b62ca0493fbaaeda698df4b49b [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:19:48.568450  6835 raft_consensus.cc:697] T cd52d03fc5fd479b921e4730520f01ad P cd35e2b62ca0493fbaaeda698df4b49b [term 1 LEADER]: Becoming Leader. State: Replica: cd35e2b62ca0493fbaaeda698df4b49b, State: Running, Role: LEADER
I20260812 06:19:48.568522  6833 ts_tablet_manager.cc:1434] T cd52d03fc5fd479b921e4730520f01ad P cd35e2b62ca0493fbaaeda698df4b49b: Time spent starting tablet: real 0.003s	user 0.003s	sys 0.000s
I20260812 06:19:48.568688  6835 consensus_queue.cc:237] T cd52d03fc5fd479b921e4730520f01ad P cd35e2b62ca0493fbaaeda698df4b49b [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: "cd35e2b62ca0493fbaaeda698df4b49b" member_type: VOTER last_known_addr { host: "127.6.119.65" port: 45637 } }
I20260812 06:19:48.568817  6816 heartbeater.cc:499] Master 127.6.119.126:44237 was elected leader, sending a full tablet report...
I20260812 06:19:48.571606  6658 catalog_manager.cc:5719] T cd52d03fc5fd479b921e4730520f01ad P cd35e2b62ca0493fbaaeda698df4b49b reported cstate change: term changed from 0 to 1, leader changed from <none> to cd35e2b62ca0493fbaaeda698df4b49b (127.6.119.65). New cstate: current_term: 1 leader_uuid: "cd35e2b62ca0493fbaaeda698df4b49b" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "cd35e2b62ca0493fbaaeda698df4b49b" member_type: VOTER last_known_addr { host: "127.6.119.65" port: 45637 } health_report { overall_health: HEALTHY } } }
I20260812 06:19:48.633736  6621 heavy-update-compaction-itest.cc:215] Time spent inserting: real 0.054s	user 0.018s	sys 0.009s
I20260812 06:19:48.771315  6817 maintenance_manager.cc:419] P cd35e2b62ca0493fbaaeda698df4b49b: Scheduling FlushMRSOp(cd52d03fc5fd479b921e4730520f01ad): perf score=19.054940
I20260812 06:19:48.970839  6747 maintenance_manager.cc:643] P cd35e2b62ca0493fbaaeda698df4b49b: FlushMRSOp(cd52d03fc5fd479b921e4730520f01ad) complete. Timing: real 0.199s	user 0.148s	sys 0.047s Metrics: {"bytes_written":16409899,"cfile_init":1,"compiler_manager_pool.queue_time_us":203,"delete_count":0,"dirs.queue_time_us":78,"dirs.run_cpu_time_us":243,"dirs.run_wall_time_us":937,"drs_written":1,"lbm_read_time_us":72,"lbm_reads_lt_1ms":4,"lbm_write_time_us":49471,"lbm_writes_lt_1ms":857,"peak_mem_usage":0,"reinsert_count":0,"rows_written":104,"thread_start_us":136,"threads_started":1,"update_count":2000}
I20260812 06:19:48.972312  6817 maintenance_manager.cc:419] P cd35e2b62ca0493fbaaeda698df4b49b: Scheduling LogGCOp(cd52d03fc5fd479b921e4730520f01ad): free 20743880 bytes of WAL
I20260812 06:19:48.972733  6747 log_reader.cc:385] T cd52d03fc5fd479b921e4730520f01ad: removed 2 log segments from log reader
I20260812 06:19:48.972851  6747 log.cc:1079] T cd52d03fc5fd479b921e4730520f01ad P cd35e2b62ca0493fbaaeda698df4b49b: Deleting log segment in path: /tmp/dist-test-taskTJlGYB/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515588352133-6621-0/minicluster-data/ts-0-root/wals/cd52d03fc5fd479b921e4730520f01ad/wal-000000001 (ops 1-6)
I20260812 06:19:48.972954  6747 log.cc:1079] T cd52d03fc5fd479b921e4730520f01ad P cd35e2b62ca0493fbaaeda698df4b49b: Deleting log segment in path: /tmp/dist-test-taskTJlGYB/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515588352133-6621-0/minicluster-data/ts-0-root/wals/cd52d03fc5fd479b921e4730520f01ad/wal-000000002 (ops 7-11)
I20260812 06:19:48.978500  6747 maintenance_manager.cc:643] P cd35e2b62ca0493fbaaeda698df4b49b: LogGCOp(cd52d03fc5fd479b921e4730520f01ad) complete. Timing: real 0.006s	user 0.000s	sys 0.006s Metrics: {}
I20260812 06:19:48.979070  6817 maintenance_manager.cc:419] P cd35e2b62ca0493fbaaeda698df4b49b: Scheduling FlushDeltaMemStoresOp(cd52d03fc5fd479b921e4730520f01ad): perf score=2.188937
I20260812 06:19:48.994207  6747 maintenance_manager.cc:643] P cd35e2b62ca0493fbaaeda698df4b49b: FlushDeltaMemStoresOp(cd52d03fc5fd479b921e4730520f01ad) complete. Timing: real 0.015s	user 0.006s	sys 0.005s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5024,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:48.994805  6817 maintenance_manager.cc:419] P cd35e2b62ca0493fbaaeda698df4b49b: Scheduling MajorDeltaCompactionOp(cd52d03fc5fd479b921e4730520f01ad): perf score=1.000000
I20260812 06:19:49.162840  6747 maintenance_manager.cc:643] P cd35e2b62ca0493fbaaeda698df4b49b: MajorDeltaCompactionOp(cd52d03fc5fd479b921e4730520f01ad) complete. Timing: real 0.168s	user 0.105s	sys 0.062s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774686,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":893,"lbm_read_time_us":9493,"lbm_reads_lt_1ms":564,"lbm_write_time_us":30185,"lbm_writes_lt_1ms":543,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":1792,"thread_start_us":367,"threads_started":5,"update_count":2500}
I20260812 06:19:49.163460  6817 maintenance_manager.cc:419] P cd35e2b62ca0493fbaaeda698df4b49b: Scheduling UndoDeltaBlockGCOp(cd52d03fc5fd479b921e4730520f01ad): 16411393 bytes on disk
I20260812 06:19:49.163895  6747 maintenance_manager.cc:643] P cd35e2b62ca0493fbaaeda698df4b49b: UndoDeltaBlockGCOp(cd52d03fc5fd479b921e4730520f01ad) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":42,"lbm_reads_lt_1ms":4}
I20260812 06:19:49.164288  6817 maintenance_manager.cc:419] P cd35e2b62ca0493fbaaeda698df4b49b: Scheduling FlushDeltaMemStoresOp(cd52d03fc5fd479b921e4730520f01ad): perf score=11.118625
I20260812 06:19:49.207139  6747 maintenance_manager.cc:643] P cd35e2b62ca0493fbaaeda698df4b49b: FlushDeltaMemStoresOp(cd52d03fc5fd479b921e4730520f01ad) complete. Timing: real 0.043s	user 0.023s	sys 0.019s Metrics: {"bytes_written":12717735,"delete_count":0,"lbm_write_time_us":18463,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":312,"reinsert_count":0,"update_count":1550}
I20260812 06:19:49.207654  6817 maintenance_manager.cc:419] P cd35e2b62ca0493fbaaeda698df4b49b: Scheduling FlushDeltaMemStoresOp(cd52d03fc5fd479b921e4730520f01ad): perf score=2.188937
I20260812 06:19:49.231992  6747 maintenance_manager.cc:643] P cd35e2b62ca0493fbaaeda698df4b49b: FlushDeltaMemStoresOp(cd52d03fc5fd479b921e4730520f01ad) complete. Timing: real 0.024s	user 0.005s	sys 0.008s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":5608,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:19:49.232470  6817 maintenance_manager.cc:419] P cd35e2b62ca0493fbaaeda698df4b49b: Scheduling FlushDeltaMemStoresOp(cd52d03fc5fd479b921e4730520f01ad): perf score=2.188937
I20260812 06:19:49.251185  6747 maintenance_manager.cc:643] P cd35e2b62ca0493fbaaeda698df4b49b: FlushDeltaMemStoresOp(cd52d03fc5fd479b921e4730520f01ad) complete. Timing: real 0.019s	user 0.011s	sys 0.007s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4006,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:49.251699  6817 maintenance_manager.cc:419] P cd35e2b62ca0493fbaaeda698df4b49b: Scheduling MajorDeltaCompactionOp(cd52d03fc5fd479b921e4730520f01ad): perf score=1.000000
I20260812 06:19:49.410564  6747 maintenance_manager.cc:643] P cd35e2b62ca0493fbaaeda698df4b49b: MajorDeltaCompactionOp(cd52d03fc5fd479b921e4730520f01ad) complete. Timing: real 0.159s	user 0.117s	sys 0.041s 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":454,"lbm_read_time_us":11872,"lbm_reads_lt_1ms":573,"lbm_write_time_us":25966,"lbm_writes_lt_1ms":543,"mutex_wait_us":102,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":768,"update_count":2500}
I20260812 06:19:49.411239  6817 maintenance_manager.cc:419] P cd35e2b62ca0493fbaaeda698df4b49b: Scheduling FlushDeltaMemStoresOp(cd52d03fc5fd479b921e4730520f01ad): perf score=10.126437
I20260812 06:19:49.454764  6747 maintenance_manager.cc:643] P cd35e2b62ca0493fbaaeda698df4b49b: FlushDeltaMemStoresOp(cd52d03fc5fd479b921e4730520f01ad) complete. Timing: real 0.043s	user 0.011s	sys 0.031s Metrics: {"bytes_written":12307492,"delete_count":0,"lbm_write_time_us":20533,"lbm_writes_1-10_ms":3,"lbm_writes_lt_1ms":300,"reinsert_count":0,"update_count":1500}
I20260812 06:19:49.455354  6817 maintenance_manager.cc:419] P cd35e2b62ca0493fbaaeda698df4b49b: Scheduling FlushDeltaMemStoresOp(cd52d03fc5fd479b921e4730520f01ad): perf score=2.188937
I20260812 06:19:49.472100  6747 maintenance_manager.cc:643] P cd35e2b62ca0493fbaaeda698df4b49b: FlushDeltaMemStoresOp(cd52d03fc5fd479b921e4730520f01ad) complete. Timing: real 0.017s	user 0.014s	sys 0.001s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6314,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:49.472556  6817 maintenance_manager.cc:419] P cd35e2b62ca0493fbaaeda698df4b49b: Scheduling MajorDeltaCompactionOp(cd52d03fc5fd479b921e4730520f01ad): perf score=1.000000
I20260812 06:19:49.593065  6747 maintenance_manager.cc:643] P cd35e2b62ca0493fbaaeda698df4b49b: MajorDeltaCompactionOp(cd52d03fc5fd479b921e4730520f01ad) complete. Timing: real 0.120s	user 0.084s	sys 0.036s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672279,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":40,"lbm_read_time_us":8092,"lbm_reads_lt_1ms":468,"lbm_write_time_us":23916,"lbm_writes_lt_1ms":443,"mutex_wait_us":20,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":8320,"update_count":2000}
I20260812 06:19:49.593729  6817 maintenance_manager.cc:419] P cd35e2b62ca0493fbaaeda698df4b49b: Scheduling FlushDeltaMemStoresOp(cd52d03fc5fd479b921e4730520f01ad): perf score=10.126437
I20260812 06:19:49.636829  6747 maintenance_manager.cc:643] P cd35e2b62ca0493fbaaeda698df4b49b: FlushDeltaMemStoresOp(cd52d03fc5fd479b921e4730520f01ad) complete. Timing: real 0.042s	user 0.016s	sys 0.023s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":18027,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":302,"reinsert_count":0,"update_count":1500}
I20260812 06:19:49.637382  6817 maintenance_manager.cc:419] P cd35e2b62ca0493fbaaeda698df4b49b: Scheduling FlushDeltaMemStoresOp(cd52d03fc5fd479b921e4730520f01ad): perf score=2.188937
I20260812 06:19:49.650941  6747 maintenance_manager.cc:643] P cd35e2b62ca0493fbaaeda698df4b49b: FlushDeltaMemStoresOp(cd52d03fc5fd479b921e4730520f01ad) complete. Timing: real 0.013s	user 0.010s	sys 0.003s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4795,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:49.651522  6817 maintenance_manager.cc:419] P cd35e2b62ca0493fbaaeda698df4b49b: Scheduling MajorDeltaCompactionOp(cd52d03fc5fd479b921e4730520f01ad): perf score=1.000000
I20260812 06:19:49.774731  6747 maintenance_manager.cc:643] P cd35e2b62ca0493fbaaeda698df4b49b: MajorDeltaCompactionOp(cd52d03fc5fd479b921e4730520f01ad) complete. Timing: real 0.123s	user 0.090s	sys 0.033s 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":631,"lbm_read_time_us":8188,"lbm_reads_lt_1ms":464,"lbm_write_time_us":23349,"lbm_writes_lt_1ms":443,"mutex_wait_us":27,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":38912,"update_count":2000}
I20260812 06:19:49.779980  6817 maintenance_manager.cc:419] P cd35e2b62ca0493fbaaeda698df4b49b: Scheduling FlushDeltaMemStoresOp(cd52d03fc5fd479b921e4730520f01ad): perf score=10.126437
I20260812 06:19:49.814062  6747 maintenance_manager.cc:643] P cd35e2b62ca0493fbaaeda698df4b49b: FlushDeltaMemStoresOp(cd52d03fc5fd479b921e4730520f01ad) complete. Timing: real 0.034s	user 0.015s	sys 0.015s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":14714,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:19:49.814627  6817 maintenance_manager.cc:419] P cd35e2b62ca0493fbaaeda698df4b49b: Scheduling FlushDeltaMemStoresOp(cd52d03fc5fd479b921e4730520f01ad): perf score=2.188937
I20260812 06:19:49.830288  6747 maintenance_manager.cc:643] P cd35e2b62ca0493fbaaeda698df4b49b: FlushDeltaMemStoresOp(cd52d03fc5fd479b921e4730520f01ad) complete. Timing: real 0.015s	user 0.006s	sys 0.005s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5219,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:49.830791  6817 maintenance_manager.cc:419] P cd35e2b62ca0493fbaaeda698df4b49b: Scheduling MajorDeltaCompactionOp(cd52d03fc5fd479b921e4730520f01ad): perf score=1.000000
I20260812 06:19:49.959815  6747 maintenance_manager.cc:643] P cd35e2b62ca0493fbaaeda698df4b49b: MajorDeltaCompactionOp(cd52d03fc5fd479b921e4730520f01ad) complete. Timing: real 0.129s	user 0.118s	sys 0.010s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672277,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":259,"lbm_read_time_us":8226,"lbm_reads_lt_1ms":468,"lbm_write_time_us":24651,"lbm_writes_lt_1ms":443,"mutex_wait_us":45,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":39424,"update_count":2000}
I20260812 06:19:49.960546  6817 maintenance_manager.cc:419] P cd35e2b62ca0493fbaaeda698df4b49b: Scheduling FlushDeltaMemStoresOp(cd52d03fc5fd479b921e4730520f01ad): perf score=10.126437
I20260812 06:19:49.999378  6747 maintenance_manager.cc:643] P cd35e2b62ca0493fbaaeda698df4b49b: FlushDeltaMemStoresOp(cd52d03fc5fd479b921e4730520f01ad) complete. Timing: real 0.039s	user 0.021s	sys 0.016s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":13800,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:19:49.999912  6817 maintenance_manager.cc:419] P cd35e2b62ca0493fbaaeda698df4b49b: Scheduling FlushDeltaMemStoresOp(cd52d03fc5fd479b921e4730520f01ad): perf score=2.188937
I20260812 06:19:50.010658  6747 maintenance_manager.cc:643] P cd35e2b62ca0493fbaaeda698df4b49b: FlushDeltaMemStoresOp(cd52d03fc5fd479b921e4730520f01ad) complete. Timing: real 0.011s	user 0.002s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4298,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:50.011106  6817 maintenance_manager.cc:419] P cd35e2b62ca0493fbaaeda698df4b49b: Scheduling MajorDeltaCompactionOp(cd52d03fc5fd479b921e4730520f01ad): perf score=1.000000
I20260812 06:19:50.152647  6747 maintenance_manager.cc:643] P cd35e2b62ca0493fbaaeda698df4b49b: MajorDeltaCompactionOp(cd52d03fc5fd479b921e4730520f01ad) complete. Timing: real 0.141s	user 0.100s	sys 0.041s 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":416,"lbm_read_time_us":10783,"lbm_reads_lt_1ms":472,"lbm_write_time_us":23006,"lbm_writes_lt_1ms":443,"mutex_wait_us":88,"peak_mem_usage":50689328,"reinsert_count":0,"update_count":2000}
I20260812 06:19:50.153477  6817 maintenance_manager.cc:419] P cd35e2b62ca0493fbaaeda698df4b49b: Scheduling FlushDeltaMemStoresOp(cd52d03fc5fd479b921e4730520f01ad): perf score=10.126437
I20260812 06:19:50.192977  6747 maintenance_manager.cc:643] P cd35e2b62ca0493fbaaeda698df4b49b: FlushDeltaMemStoresOp(cd52d03fc5fd479b921e4730520f01ad) complete. Timing: real 0.039s	user 0.025s	sys 0.008s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":15470,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:19:50.193498  6817 maintenance_manager.cc:419] P cd35e2b62ca0493fbaaeda698df4b49b: Scheduling FlushDeltaMemStoresOp(cd52d03fc5fd479b921e4730520f01ad): perf score=2.188937
I20260812 06:19:50.207917  6747 maintenance_manager.cc:643] P cd35e2b62ca0493fbaaeda698df4b49b: FlushDeltaMemStoresOp(cd52d03fc5fd479b921e4730520f01ad) complete. Timing: real 0.014s	user 0.009s	sys 0.004s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":5729,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:50.208674  6817 maintenance_manager.cc:419] P cd35e2b62ca0493fbaaeda698df4b49b: Scheduling FlushMRSOp(cd52d03fc5fd479b921e4730520f01ad): perf score=1.000000
I20260812 06:19:50.244875  6747 maintenance_manager.cc:643] P cd35e2b62ca0493fbaaeda698df4b49b: FlushMRSOp(cd52d03fc5fd479b921e4730520f01ad) complete. Timing: real 0.036s	user 0.034s	sys 0.000s Metrics: {"bytes_written":1234473,"cfile_init":1,"dirs.queue_time_us":68,"dirs.run_cpu_time_us":250,"dirs.run_wall_time_us":1408,"drs_written":1,"lbm_read_time_us":81,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1512,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":30,"spinlock_wait_cycles":1792}
I20260812 06:19:50.245692  6817 maintenance_manager.cc:419] P cd35e2b62ca0493fbaaeda698df4b49b: Scheduling LogGCOp(cd52d03fc5fd479b921e4730520f01ad): free 120553370 bytes of WAL
I20260812 06:19:50.245940  6747 log_reader.cc:385] T cd52d03fc5fd479b921e4730520f01ad: removed 12 log segments from log reader
I20260812 06:19:50.246011  6747 log.cc:1079] T cd52d03fc5fd479b921e4730520f01ad P cd35e2b62ca0493fbaaeda698df4b49b: Deleting log segment in path: /tmp/dist-test-taskTJlGYB/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515588352133-6621-0/minicluster-data/ts-0-root/wals/cd52d03fc5fd479b921e4730520f01ad/wal-000000003 (ops 12-16)
I20260812 06:19:50.246065  6747 log.cc:1079] T cd52d03fc5fd479b921e4730520f01ad P cd35e2b62ca0493fbaaeda698df4b49b: Deleting log segment in path: /tmp/dist-test-taskTJlGYB/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515588352133-6621-0/minicluster-data/ts-0-root/wals/cd52d03fc5fd479b921e4730520f01ad/wal-000000004 (ops 17-21)
I20260812 06:19:50.246122  6747 log.cc:1079] T cd52d03fc5fd479b921e4730520f01ad P cd35e2b62ca0493fbaaeda698df4b49b: Deleting log segment in path: /tmp/dist-test-taskTJlGYB/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515588352133-6621-0/minicluster-data/ts-0-root/wals/cd52d03fc5fd479b921e4730520f01ad/wal-000000005 (ops 22-26)
I20260812 06:19:50.246163  6747 log.cc:1079] T cd52d03fc5fd479b921e4730520f01ad P cd35e2b62ca0493fbaaeda698df4b49b: Deleting log segment in path: /tmp/dist-test-taskTJlGYB/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515588352133-6621-0/minicluster-data/ts-0-root/wals/cd52d03fc5fd479b921e4730520f01ad/wal-000000006 (ops 27-30)
I20260812 06:19:50.246201  6747 log.cc:1079] T cd52d03fc5fd479b921e4730520f01ad P cd35e2b62ca0493fbaaeda698df4b49b: Deleting log segment in path: /tmp/dist-test-taskTJlGYB/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515588352133-6621-0/minicluster-data/ts-0-root/wals/cd52d03fc5fd479b921e4730520f01ad/wal-000000007 (ops 31-35)
I20260812 06:19:50.246237  6747 log.cc:1079] T cd52d03fc5fd479b921e4730520f01ad P cd35e2b62ca0493fbaaeda698df4b49b: Deleting log segment in path: /tmp/dist-test-taskTJlGYB/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515588352133-6621-0/minicluster-data/ts-0-root/wals/cd52d03fc5fd479b921e4730520f01ad/wal-000000008 (ops 36-40)
I20260812 06:19:50.246274  6747 log.cc:1079] T cd52d03fc5fd479b921e4730520f01ad P cd35e2b62ca0493fbaaeda698df4b49b: Deleting log segment in path: /tmp/dist-test-taskTJlGYB/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515588352133-6621-0/minicluster-data/ts-0-root/wals/cd52d03fc5fd479b921e4730520f01ad/wal-000000009 (ops 41-44)
I20260812 06:19:50.246311  6747 log.cc:1079] T cd52d03fc5fd479b921e4730520f01ad P cd35e2b62ca0493fbaaeda698df4b49b: Deleting log segment in path: /tmp/dist-test-taskTJlGYB/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515588352133-6621-0/minicluster-data/ts-0-root/wals/cd52d03fc5fd479b921e4730520f01ad/wal-000000010 (ops 45-49)
I20260812 06:19:50.246356  6747 log.cc:1079] T cd52d03fc5fd479b921e4730520f01ad P cd35e2b62ca0493fbaaeda698df4b49b: Deleting log segment in path: /tmp/dist-test-taskTJlGYB/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515588352133-6621-0/minicluster-data/ts-0-root/wals/cd52d03fc5fd479b921e4730520f01ad/wal-000000011 (ops 50-54)
I20260812 06:19:50.246393  6747 log.cc:1079] T cd52d03fc5fd479b921e4730520f01ad P cd35e2b62ca0493fbaaeda698df4b49b: Deleting log segment in path: /tmp/dist-test-taskTJlGYB/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515588352133-6621-0/minicluster-data/ts-0-root/wals/cd52d03fc5fd479b921e4730520f01ad/wal-000000012 (ops 55-59)
I20260812 06:19:50.246459  6747 log.cc:1079] T cd52d03fc5fd479b921e4730520f01ad P cd35e2b62ca0493fbaaeda698df4b49b: Deleting log segment in path: /tmp/dist-test-taskTJlGYB/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515588352133-6621-0/minicluster-data/ts-0-root/wals/cd52d03fc5fd479b921e4730520f01ad/wal-000000013 (ops 60-64)
I20260812 06:19:50.246497  6747 log.cc:1079] T cd52d03fc5fd479b921e4730520f01ad P cd35e2b62ca0493fbaaeda698df4b49b: Deleting log segment in path: /tmp/dist-test-taskTJlGYB/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515588352133-6621-0/minicluster-data/ts-0-root/wals/cd52d03fc5fd479b921e4730520f01ad/wal-000000014 (ops 65-69)
I20260812 06:19:50.273450  6747 maintenance_manager.cc:643] P cd35e2b62ca0493fbaaeda698df4b49b: LogGCOp(cd52d03fc5fd479b921e4730520f01ad) complete. Timing: real 0.028s	user 0.000s	sys 0.025s Metrics: {}
I20260812 06:19:50.273963  6817 maintenance_manager.cc:419] P cd35e2b62ca0493fbaaeda698df4b49b: Scheduling FlushDeltaMemStoresOp(cd52d03fc5fd479b921e4730520f01ad): perf score=4.173312
I20260812 06:19:50.296339  6747 maintenance_manager.cc:643] P cd35e2b62ca0493fbaaeda698df4b49b: FlushDeltaMemStoresOp(cd52d03fc5fd479b921e4730520f01ad) complete. Timing: real 0.022s	user 0.013s	sys 0.007s Metrics: {"bytes_written":5620561,"delete_count":0,"lbm_write_time_us":5452,"lbm_writes_lt_1ms":140,"reinsert_count":0,"update_count":685}
I20260812 06:19:50.296888  6817 maintenance_manager.cc:419] P cd35e2b62ca0493fbaaeda698df4b49b: Scheduling UndoDeltaBlockGCOp(cd52d03fc5fd479b921e4730520f01ad): 473 bytes on disk
I20260812 06:19:50.297367  6747 maintenance_manager.cc:643] P cd35e2b62ca0493fbaaeda698df4b49b: UndoDeltaBlockGCOp(cd52d03fc5fd479b921e4730520f01ad) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":56,"lbm_reads_lt_1ms":4}
I20260812 06:19:50.297904  6817 maintenance_manager.cc:419] P cd35e2b62ca0493fbaaeda698df4b49b: Scheduling FlushDeltaMemStoresOp(cd52d03fc5fd479b921e4730520f01ad): perf score=1.196750
I20260812 06:19:50.305493  6747 maintenance_manager.cc:643] P cd35e2b62ca0493fbaaeda698df4b49b: FlushDeltaMemStoresOp(cd52d03fc5fd479b921e4730520f01ad) complete. Timing: real 0.007s	user 0.006s	sys 0.000s Metrics: {"bytes_written":2584729,"delete_count":0,"lbm_write_time_us":2623,"lbm_writes_lt_1ms":66,"reinsert_count":0,"update_count":315}
I20260812 06:19:50.306048  6817 maintenance_manager.cc:419] P cd35e2b62ca0493fbaaeda698df4b49b: Scheduling MajorDeltaCompactionOp(cd52d03fc5fd479b921e4730520f01ad): perf score=1.000000
I20260812 06:19:50.505328  6747 maintenance_manager.cc:643] P cd35e2b62ca0493fbaaeda698df4b49b: MajorDeltaCompactionOp(cd52d03fc5fd479b921e4730520f01ad) complete. Timing: real 0.199s	user 0.123s	sys 0.064s Metrics: {"cfile_cache_miss":634,"cfile_cache_miss_bytes":28877304,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":782,"lbm_read_time_us":14577,"lbm_reads_lt_1ms":674,"lbm_write_time_us":31406,"lbm_writes_lt_1ms":643,"mutex_wait_us":65,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":5504,"thread_start_us":104,"threads_started":1,"update_count":3000}
I20260812 06:19:50.505936  6817 maintenance_manager.cc:419] P cd35e2b62ca0493fbaaeda698df4b49b: Scheduling FlushDeltaMemStoresOp(cd52d03fc5fd479b921e4730520f01ad): perf score=14.095187
I20260812 06:19:50.566219  6747 maintenance_manager.cc:643] P cd35e2b62ca0493fbaaeda698df4b49b: FlushDeltaMemStoresOp(cd52d03fc5fd479b921e4730520f01ad) complete. Timing: real 0.060s	user 0.034s	sys 0.019s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":21353,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:50.566896  6817 maintenance_manager.cc:419] P cd35e2b62ca0493fbaaeda698df4b49b: Scheduling FlushDeltaMemStoresOp(cd52d03fc5fd479b921e4730520f01ad): perf score=2.188937
I20260812 06:19:50.577802  6747 maintenance_manager.cc:643] P cd35e2b62ca0493fbaaeda698df4b49b: FlushDeltaMemStoresOp(cd52d03fc5fd479b921e4730520f01ad) complete. Timing: real 0.011s	user 0.005s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4272,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:50.578366  6817 maintenance_manager.cc:419] P cd35e2b62ca0493fbaaeda698df4b49b: Scheduling MajorDeltaCompactionOp(cd52d03fc5fd479b921e4730520f01ad): perf score=1.000000
I20260812 06:19:50.750759  6747 maintenance_manager.cc:643] P cd35e2b62ca0493fbaaeda698df4b49b: MajorDeltaCompactionOp(cd52d03fc5fd479b921e4730520f01ad) complete. Timing: real 0.172s	user 0.116s	sys 0.056s 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":187,"lbm_read_time_us":13264,"lbm_reads_lt_1ms":572,"lbm_write_time_us":26997,"lbm_writes_lt_1ms":543,"mutex_wait_us":45,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":44288,"update_count":2500}
I20260812 06:19:50.751348  6817 maintenance_manager.cc:419] P cd35e2b62ca0493fbaaeda698df4b49b: Scheduling FlushDeltaMemStoresOp(cd52d03fc5fd479b921e4730520f01ad): perf score=10.126437
I20260812 06:19:50.787592  6747 maintenance_manager.cc:643] P cd35e2b62ca0493fbaaeda698df4b49b: FlushDeltaMemStoresOp(cd52d03fc5fd479b921e4730520f01ad) complete. Timing: real 0.036s	user 0.018s	sys 0.014s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":14228,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:19:50.788110  6817 maintenance_manager.cc:419] P cd35e2b62ca0493fbaaeda698df4b49b: Scheduling FlushDeltaMemStoresOp(cd52d03fc5fd479b921e4730520f01ad): perf score=2.188937
I20260812 06:19:50.802860  6747 maintenance_manager.cc:643] P cd35e2b62ca0493fbaaeda698df4b49b: FlushDeltaMemStoresOp(cd52d03fc5fd479b921e4730520f01ad) complete. Timing: real 0.015s	user 0.014s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5101,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:50.803529  6817 maintenance_manager.cc:419] P cd35e2b62ca0493fbaaeda698df4b49b: Scheduling MajorDeltaCompactionOp(cd52d03fc5fd479b921e4730520f01ad): perf score=1.000000
I20260812 06:19:50.925482  6747 maintenance_manager.cc:643] P cd35e2b62ca0493fbaaeda698df4b49b: MajorDeltaCompactionOp(cd52d03fc5fd479b921e4730520f01ad) complete. Timing: real 0.122s	user 0.094s	sys 0.028s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672277,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":250,"lbm_read_time_us":10017,"lbm_reads_lt_1ms":472,"lbm_write_time_us":21118,"lbm_writes_lt_1ms":443,"mutex_wait_us":42,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":3328,"update_count":2000}
I20260812 06:19:50.926070  6817 maintenance_manager.cc:419] P cd35e2b62ca0493fbaaeda698df4b49b: Scheduling FlushDeltaMemStoresOp(cd52d03fc5fd479b921e4730520f01ad): perf score=10.126437
I20260812 06:19:50.965327  6747 maintenance_manager.cc:643] P cd35e2b62ca0493fbaaeda698df4b49b: FlushDeltaMemStoresOp(cd52d03fc5fd479b921e4730520f01ad) complete. Timing: real 0.039s	user 0.032s	sys 0.000s Metrics: {"bytes_written":12307489,"delete_count":0,"lbm_write_time_us":14925,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:19:50.965852  6817 maintenance_manager.cc:419] P cd35e2b62ca0493fbaaeda698df4b49b: Scheduling FlushDeltaMemStoresOp(cd52d03fc5fd479b921e4730520f01ad): perf score=2.188937
I20260812 06:19:50.980813  6747 maintenance_manager.cc:643] P cd35e2b62ca0493fbaaeda698df4b49b: FlushDeltaMemStoresOp(cd52d03fc5fd479b921e4730520f01ad) complete. Timing: real 0.015s	user 0.012s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5544,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:50.981364  6817 maintenance_manager.cc:419] P cd35e2b62ca0493fbaaeda698df4b49b: Scheduling MajorDeltaCompactionOp(cd52d03fc5fd479b921e4730520f01ad): perf score=1.000000
I20260812 06:19:51.108011  6747 maintenance_manager.cc:643] P cd35e2b62ca0493fbaaeda698df4b49b: MajorDeltaCompactionOp(cd52d03fc5fd479b921e4730520f01ad) complete. Timing: real 0.126s	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":240,"lbm_read_time_us":8562,"lbm_reads_lt_1ms":472,"lbm_write_time_us":24259,"lbm_writes_lt_1ms":443,"mutex_wait_us":26,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":10624,"update_count":2000}
I20260812 06:19:51.108767  6817 maintenance_manager.cc:419] P cd35e2b62ca0493fbaaeda698df4b49b: Scheduling FlushDeltaMemStoresOp(cd52d03fc5fd479b921e4730520f01ad): perf score=10.126437
I20260812 06:19:51.148819  6747 maintenance_manager.cc:643] P cd35e2b62ca0493fbaaeda698df4b49b: FlushDeltaMemStoresOp(cd52d03fc5fd479b921e4730520f01ad) complete. Timing: real 0.040s	user 0.027s	sys 0.007s Metrics: {"bytes_written":12307492,"delete_count":0,"lbm_write_time_us":15780,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:19:51.149349  6817 maintenance_manager.cc:419] P cd35e2b62ca0493fbaaeda698df4b49b: Scheduling FlushDeltaMemStoresOp(cd52d03fc5fd479b921e4730520f01ad): perf score=2.188937
I20260812 06:19:51.159950  6747 maintenance_manager.cc:643] P cd35e2b62ca0493fbaaeda698df4b49b: FlushDeltaMemStoresOp(cd52d03fc5fd479b921e4730520f01ad) complete. Timing: real 0.010s	user 0.005s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3992,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:51.160620  6817 maintenance_manager.cc:419] P cd35e2b62ca0493fbaaeda698df4b49b: Scheduling MajorDeltaCompactionOp(cd52d03fc5fd479b921e4730520f01ad): perf score=1.000000
I20260812 06:19:51.293427  6747 maintenance_manager.cc:643] P cd35e2b62ca0493fbaaeda698df4b49b: MajorDeltaCompactionOp(cd52d03fc5fd479b921e4730520f01ad) complete. Timing: real 0.133s	user 0.108s	sys 0.023s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672279,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":1025,"lbm_read_time_us":9866,"lbm_reads_lt_1ms":472,"lbm_write_time_us":27457,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":442,"mutex_wait_us":263,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":3712,"update_count":2000}
I20260812 06:19:51.294100  6817 maintenance_manager.cc:419] P cd35e2b62ca0493fbaaeda698df4b49b: Scheduling FlushDeltaMemStoresOp(cd52d03fc5fd479b921e4730520f01ad): perf score=10.126437
I20260812 06:19:51.352183  6747 maintenance_manager.cc:643] P cd35e2b62ca0493fbaaeda698df4b49b: FlushDeltaMemStoresOp(cd52d03fc5fd479b921e4730520f01ad) complete. Timing: real 0.058s	user 0.018s	sys 0.029s Metrics: {"bytes_written":12307491,"delete_count":0,"lbm_write_time_us":17818,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:19:51.352725  6817 maintenance_manager.cc:419] P cd35e2b62ca0493fbaaeda698df4b49b: Scheduling FlushDeltaMemStoresOp(cd52d03fc5fd479b921e4730520f01ad): perf score=2.188937
I20260812 06:19:51.364181  6747 maintenance_manager.cc:643] P cd35e2b62ca0493fbaaeda698df4b49b: FlushDeltaMemStoresOp(cd52d03fc5fd479b921e4730520f01ad) complete. Timing: real 0.011s	user 0.006s	sys 0.003s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4575,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:51.364728  6817 maintenance_manager.cc:419] P cd35e2b62ca0493fbaaeda698df4b49b: Scheduling MajorDeltaCompactionOp(cd52d03fc5fd479b921e4730520f01ad): perf score=1.000000
I20260812 06:19:51.521888  6747 maintenance_manager.cc:643] P cd35e2b62ca0493fbaaeda698df4b49b: MajorDeltaCompactionOp(cd52d03fc5fd479b921e4730520f01ad) complete. Timing: real 0.157s	user 0.117s	sys 0.040s 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":346,"lbm_read_time_us":12234,"lbm_reads_lt_1ms":472,"lbm_write_time_us":24442,"lbm_writes_lt_1ms":443,"mutex_wait_us":41,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":8704,"update_count":2000}
I20260812 06:19:51.522714  6817 maintenance_manager.cc:419] P cd35e2b62ca0493fbaaeda698df4b49b: Scheduling FlushDeltaMemStoresOp(cd52d03fc5fd479b921e4730520f01ad): perf score=10.126437
I20260812 06:19:51.563778  6747 maintenance_manager.cc:643] P cd35e2b62ca0493fbaaeda698df4b49b: FlushDeltaMemStoresOp(cd52d03fc5fd479b921e4730520f01ad) complete. Timing: real 0.041s	user 0.026s	sys 0.008s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":15323,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:19:51.564313  6817 maintenance_manager.cc:419] P cd35e2b62ca0493fbaaeda698df4b49b: Scheduling FlushDeltaMemStoresOp(cd52d03fc5fd479b921e4730520f01ad): perf score=2.188937
I20260812 06:19:51.574832  6747 maintenance_manager.cc:643] P cd35e2b62ca0493fbaaeda698df4b49b: FlushDeltaMemStoresOp(cd52d03fc5fd479b921e4730520f01ad) complete. Timing: real 0.010s	user 0.006s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4075,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:51.575546  6817 maintenance_manager.cc:419] P cd35e2b62ca0493fbaaeda698df4b49b: Scheduling MajorDeltaCompactionOp(cd52d03fc5fd479b921e4730520f01ad): perf score=1.000000
I20260812 06:19:51.704784  6747 maintenance_manager.cc:643] P cd35e2b62ca0493fbaaeda698df4b49b: MajorDeltaCompactionOp(cd52d03fc5fd479b921e4730520f01ad) complete. Timing: real 0.129s	user 0.093s	sys 0.035s 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":235,"lbm_read_time_us":8714,"lbm_reads_lt_1ms":472,"lbm_write_time_us":26159,"lbm_writes_lt_1ms":443,"mutex_wait_us":26,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":11136,"update_count":2000}
I20260812 06:19:51.705515  6817 maintenance_manager.cc:419] P cd35e2b62ca0493fbaaeda698df4b49b: Scheduling FlushDeltaMemStoresOp(cd52d03fc5fd479b921e4730520f01ad): perf score=10.126437
I20260812 06:19:51.749361  6747 maintenance_manager.cc:643] P cd35e2b62ca0493fbaaeda698df4b49b: FlushDeltaMemStoresOp(cd52d03fc5fd479b921e4730520f01ad) complete. Timing: real 0.044s	user 0.027s	sys 0.008s Metrics: {"bytes_written":12307489,"delete_count":0,"lbm_write_time_us":16341,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:19:51.749889  6817 maintenance_manager.cc:419] P cd35e2b62ca0493fbaaeda698df4b49b: Scheduling FlushDeltaMemStoresOp(cd52d03fc5fd479b921e4730520f01ad): perf score=2.188937
I20260812 06:19:51.761158  6747 maintenance_manager.cc:643] P cd35e2b62ca0493fbaaeda698df4b49b: FlushDeltaMemStoresOp(cd52d03fc5fd479b921e4730520f01ad) complete. Timing: real 0.011s	user 0.005s	sys 0.003s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4271,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:51.761766  6817 maintenance_manager.cc:419] P cd35e2b62ca0493fbaaeda698df4b49b: Scheduling FlushMRSOp(cd52d03fc5fd479b921e4730520f01ad): perf score=1.000000
I20260812 06:19:51.792579  6747 maintenance_manager.cc:643] P cd35e2b62ca0493fbaaeda698df4b49b: FlushMRSOp(cd52d03fc5fd479b921e4730520f01ad) complete. Timing: real 0.031s	user 0.029s	sys 0.000s Metrics: {"bytes_written":1275449,"cfile_init":1,"dirs.queue_time_us":50,"dirs.run_cpu_time_us":260,"dirs.run_wall_time_us":1461,"drs_written":1,"lbm_read_time_us":35,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1547,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":31}
I20260812 06:19:51.793257  6817 maintenance_manager.cc:419] P cd35e2b62ca0493fbaaeda698df4b49b: Scheduling LogGCOp(cd52d03fc5fd479b921e4730520f01ad): free 132571336 bytes of WAL
I20260812 06:19:51.793481  6747 log_reader.cc:385] T cd52d03fc5fd479b921e4730520f01ad: removed 13 log segments from log reader
I20260812 06:19:51.793533  6747 log.cc:1079] T cd52d03fc5fd479b921e4730520f01ad P cd35e2b62ca0493fbaaeda698df4b49b: Deleting log segment in path: /tmp/dist-test-taskTJlGYB/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515588352133-6621-0/minicluster-data/ts-0-root/wals/cd52d03fc5fd479b921e4730520f01ad/wal-000000015 (ops 70-74)
I20260812 06:19:51.793561  6747 log.cc:1079] T cd52d03fc5fd479b921e4730520f01ad P cd35e2b62ca0493fbaaeda698df4b49b: Deleting log segment in path: /tmp/dist-test-taskTJlGYB/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515588352133-6621-0/minicluster-data/ts-0-root/wals/cd52d03fc5fd479b921e4730520f01ad/wal-000000016 (ops 75-79)
I20260812 06:19:51.793613  6747 log.cc:1079] T cd52d03fc5fd479b921e4730520f01ad P cd35e2b62ca0493fbaaeda698df4b49b: Deleting log segment in path: /tmp/dist-test-taskTJlGYB/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515588352133-6621-0/minicluster-data/ts-0-root/wals/cd52d03fc5fd479b921e4730520f01ad/wal-000000017 (ops 80-84)
I20260812 06:19:51.793658  6747 log.cc:1079] T cd52d03fc5fd479b921e4730520f01ad P cd35e2b62ca0493fbaaeda698df4b49b: Deleting log segment in path: /tmp/dist-test-taskTJlGYB/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515588352133-6621-0/minicluster-data/ts-0-root/wals/cd52d03fc5fd479b921e4730520f01ad/wal-000000018 (ops 85-89)
I20260812 06:19:51.793720  6747 log.cc:1079] T cd52d03fc5fd479b921e4730520f01ad P cd35e2b62ca0493fbaaeda698df4b49b: Deleting log segment in path: /tmp/dist-test-taskTJlGYB/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515588352133-6621-0/minicluster-data/ts-0-root/wals/cd52d03fc5fd479b921e4730520f01ad/wal-000000019 (ops 90-94)
I20260812 06:19:51.793761  6747 log.cc:1079] T cd52d03fc5fd479b921e4730520f01ad P cd35e2b62ca0493fbaaeda698df4b49b: Deleting log segment in path: /tmp/dist-test-taskTJlGYB/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515588352133-6621-0/minicluster-data/ts-0-root/wals/cd52d03fc5fd479b921e4730520f01ad/wal-000000020 (ops 95-98)
I20260812 06:19:51.793802  6747 log.cc:1079] T cd52d03fc5fd479b921e4730520f01ad P cd35e2b62ca0493fbaaeda698df4b49b: Deleting log segment in path: /tmp/dist-test-taskTJlGYB/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515588352133-6621-0/minicluster-data/ts-0-root/wals/cd52d03fc5fd479b921e4730520f01ad/wal-000000021 (ops 99-103)
I20260812 06:19:51.793843  6747 log.cc:1079] T cd52d03fc5fd479b921e4730520f01ad P cd35e2b62ca0493fbaaeda698df4b49b: Deleting log segment in path: /tmp/dist-test-taskTJlGYB/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515588352133-6621-0/minicluster-data/ts-0-root/wals/cd52d03fc5fd479b921e4730520f01ad/wal-000000022 (ops 104-108)
I20260812 06:19:51.793882  6747 log.cc:1079] T cd52d03fc5fd479b921e4730520f01ad P cd35e2b62ca0493fbaaeda698df4b49b: Deleting log segment in path: /tmp/dist-test-taskTJlGYB/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515588352133-6621-0/minicluster-data/ts-0-root/wals/cd52d03fc5fd479b921e4730520f01ad/wal-000000023 (ops 109-112)
I20260812 06:19:51.793926  6747 log.cc:1079] T cd52d03fc5fd479b921e4730520f01ad P cd35e2b62ca0493fbaaeda698df4b49b: Deleting log segment in path: /tmp/dist-test-taskTJlGYB/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515588352133-6621-0/minicluster-data/ts-0-root/wals/cd52d03fc5fd479b921e4730520f01ad/wal-000000024 (ops 113-117)
I20260812 06:19:51.793967  6747 log.cc:1079] T cd52d03fc5fd479b921e4730520f01ad P cd35e2b62ca0493fbaaeda698df4b49b: Deleting log segment in path: /tmp/dist-test-taskTJlGYB/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515588352133-6621-0/minicluster-data/ts-0-root/wals/cd52d03fc5fd479b921e4730520f01ad/wal-000000025 (ops 118-122)
I20260812 06:19:51.794006  6747 log.cc:1079] T cd52d03fc5fd479b921e4730520f01ad P cd35e2b62ca0493fbaaeda698df4b49b: Deleting log segment in path: /tmp/dist-test-taskTJlGYB/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515588352133-6621-0/minicluster-data/ts-0-root/wals/cd52d03fc5fd479b921e4730520f01ad/wal-000000026 (ops 123-127)
I20260812 06:19:51.794047  6747 log.cc:1079] T cd52d03fc5fd479b921e4730520f01ad P cd35e2b62ca0493fbaaeda698df4b49b: Deleting log segment in path: /tmp/dist-test-taskTJlGYB/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515588352133-6621-0/minicluster-data/ts-0-root/wals/cd52d03fc5fd479b921e4730520f01ad/wal-000000027 (ops 128-132)
I20260812 06:19:51.822587  6747 maintenance_manager.cc:643] P cd35e2b62ca0493fbaaeda698df4b49b: LogGCOp(cd52d03fc5fd479b921e4730520f01ad) complete. Timing: real 0.029s	user 0.000s	sys 0.029s Metrics: {}
I20260812 06:19:51.822965  6817 maintenance_manager.cc:419] P cd35e2b62ca0493fbaaeda698df4b49b: Scheduling UndoDeltaBlockGCOp(cd52d03fc5fd479b921e4730520f01ad): 482 bytes on disk
I20260812 06:19:51.823559  6747 maintenance_manager.cc:643] P cd35e2b62ca0493fbaaeda698df4b49b: UndoDeltaBlockGCOp(cd52d03fc5fd479b921e4730520f01ad) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":52,"lbm_reads_lt_1ms":4}
I20260812 06:19:51.824059  6817 maintenance_manager.cc:419] P cd35e2b62ca0493fbaaeda698df4b49b: Scheduling FlushDeltaMemStoresOp(cd52d03fc5fd479b921e4730520f01ad): perf score=6.157687
I20260812 06:19:51.850353  6747 maintenance_manager.cc:643] P cd35e2b62ca0493fbaaeda698df4b49b: FlushDeltaMemStoresOp(cd52d03fc5fd479b921e4730520f01ad) complete. Timing: real 0.026s	user 0.010s	sys 0.013s Metrics: {"bytes_written":7876884,"delete_count":0,"lbm_write_time_us":10985,"lbm_writes_lt_1ms":195,"reinsert_count":0,"update_count":960}
I20260812 06:19:51.850965  6817 maintenance_manager.cc:419] P cd35e2b62ca0493fbaaeda698df4b49b: Scheduling MajorDeltaCompactionOp(cd52d03fc5fd479b921e4730520f01ad): perf score=1.000000
I20260812 06:19:52.021608  6747 maintenance_manager.cc:643] P cd35e2b62ca0493fbaaeda698df4b49b: MajorDeltaCompactionOp(cd52d03fc5fd479b921e4730520f01ad) complete. Timing: real 0.170s	user 0.142s	sys 0.029s Metrics: {"cfile_cache_miss":625,"cfile_cache_miss_bytes":28549025,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":169,"lbm_read_time_us":11362,"lbm_reads_lt_1ms":661,"lbm_write_time_us":35312,"lbm_writes_lt_1ms":635,"mutex_wait_us":32,"peak_mem_usage":74173808,"reinsert_count":0,"spinlock_wait_cycles":16256,"thread_start_us":77,"threads_started":1,"update_count":2960}
I20260812 06:19:52.022922  6817 maintenance_manager.cc:419] P cd35e2b62ca0493fbaaeda698df4b49b: Scheduling FlushDeltaMemStoresOp(cd52d03fc5fd479b921e4730520f01ad): perf score=15.087375
I20260812 06:19:52.069187  6747 maintenance_manager.cc:643] P cd35e2b62ca0493fbaaeda698df4b49b: FlushDeltaMemStoresOp(cd52d03fc5fd479b921e4730520f01ad) complete. Timing: real 0.046s	user 0.029s	sys 0.012s Metrics: {"bytes_written":16738098,"delete_count":0,"lbm_write_time_us":20016,"lbm_writes_lt_1ms":411,"reinsert_count":0,"update_count":2040}
I20260812 06:19:52.069685  6817 maintenance_manager.cc:419] P cd35e2b62ca0493fbaaeda698df4b49b: Scheduling FlushDeltaMemStoresOp(cd52d03fc5fd479b921e4730520f01ad): perf score=2.188937
I20260812 06:19:52.079980  6747 maintenance_manager.cc:643] P cd35e2b62ca0493fbaaeda698df4b49b: FlushDeltaMemStoresOp(cd52d03fc5fd479b921e4730520f01ad) complete. Timing: real 0.010s	user 0.006s	sys 0.003s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4180,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:52.080387  6817 maintenance_manager.cc:419] P cd35e2b62ca0493fbaaeda698df4b49b: Scheduling MajorDeltaCompactionOp(cd52d03fc5fd479b921e4730520f01ad): perf score=1.000000
I20260812 06:19:52.250708  6747 maintenance_manager.cc:643] P cd35e2b62ca0493fbaaeda698df4b49b: MajorDeltaCompactionOp(cd52d03fc5fd479b921e4730520f01ad) complete. Timing: real 0.170s	user 0.104s	sys 0.054s Metrics: {"cfile_cache_miss":540,"cfile_cache_miss_bytes":25102884,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":217,"lbm_read_time_us":10629,"lbm_reads_lt_1ms":580,"lbm_write_time_us":32750,"lbm_writes_lt_1ms":551,"mutex_wait_us":38,"peak_mem_usage":63444180,"reinsert_count":0,"spinlock_wait_cycles":768,"update_count":2540}
I20260812 06:19:52.251305  6817 maintenance_manager.cc:419] P cd35e2b62ca0493fbaaeda698df4b49b: Scheduling FlushDeltaMemStoresOp(cd52d03fc5fd479b921e4730520f01ad): perf score=14.095187
I20260812 06:19:52.295629  6747 maintenance_manager.cc:643] P cd35e2b62ca0493fbaaeda698df4b49b: FlushDeltaMemStoresOp(cd52d03fc5fd479b921e4730520f01ad) complete. Timing: real 0.044s	user 0.032s	sys 0.009s Metrics: {"bytes_written":16409904,"delete_count":0,"lbm_write_time_us":20186,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":402,"reinsert_count":0,"update_count":2000}
I20260812 06:19:52.296303  6817 maintenance_manager.cc:419] P cd35e2b62ca0493fbaaeda698df4b49b: Scheduling MajorDeltaCompactionOp(cd52d03fc5fd479b921e4730520f01ad): perf score=1.000000
I20260812 06:19:52.436885  6747 maintenance_manager.cc:643] P cd35e2b62ca0493fbaaeda698df4b49b: MajorDeltaCompactionOp(cd52d03fc5fd479b921e4730520f01ad) complete. Timing: real 0.140s	user 0.104s	sys 0.036s Metrics: {"cfile_cache_miss":431,"cfile_cache_miss_bytes":20672160,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":1,"delta_iterators_relevant":1,"dirs.queue_time_us":965,"lbm_read_time_us":9957,"lbm_reads_lt_1ms":467,"lbm_write_time_us":22831,"lbm_writes_lt_1ms":443,"mutex_wait_us":62,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":12032,"update_count":2000}
I20260812 06:19:52.437590  6817 maintenance_manager.cc:419] P cd35e2b62ca0493fbaaeda698df4b49b: Scheduling FlushDeltaMemStoresOp(cd52d03fc5fd479b921e4730520f01ad): perf score=10.126437
I20260812 06:19:52.474336  6747 maintenance_manager.cc:643] P cd35e2b62ca0493fbaaeda698df4b49b: FlushDeltaMemStoresOp(cd52d03fc5fd479b921e4730520f01ad) complete. Timing: real 0.037s	user 0.023s	sys 0.011s Metrics: {"bytes_written":12307491,"delete_count":0,"lbm_write_time_us":16386,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:19:52.474849  6817 maintenance_manager.cc:419] P cd35e2b62ca0493fbaaeda698df4b49b: Scheduling FlushDeltaMemStoresOp(cd52d03fc5fd479b921e4730520f01ad): perf score=2.188937
I20260812 06:19:52.486881  6747 maintenance_manager.cc:643] P cd35e2b62ca0493fbaaeda698df4b49b: FlushDeltaMemStoresOp(cd52d03fc5fd479b921e4730520f01ad) complete. Timing: real 0.012s	user 0.011s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4825,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:52.487341  6817 maintenance_manager.cc:419] P cd35e2b62ca0493fbaaeda698df4b49b: Scheduling MajorDeltaCompactionOp(cd52d03fc5fd479b921e4730520f01ad): perf score=1.000000
I20260812 06:19:52.615271  6747 maintenance_manager.cc:643] P cd35e2b62ca0493fbaaeda698df4b49b: MajorDeltaCompactionOp(cd52d03fc5fd479b921e4730520f01ad) complete. Timing: real 0.128s	user 0.108s	sys 0.020s 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":647,"lbm_read_time_us":9475,"lbm_reads_lt_1ms":472,"lbm_write_time_us":26121,"lbm_writes_lt_1ms":443,"mutex_wait_us":254,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":6528,"update_count":2000}
I20260812 06:19:52.615981  6817 maintenance_manager.cc:419] P cd35e2b62ca0493fbaaeda698df4b49b: Scheduling FlushDeltaMemStoresOp(cd52d03fc5fd479b921e4730520f01ad): perf score=10.126437
I20260812 06:19:52.658131  6747 maintenance_manager.cc:643] P cd35e2b62ca0493fbaaeda698df4b49b: FlushDeltaMemStoresOp(cd52d03fc5fd479b921e4730520f01ad) complete. Timing: real 0.042s	user 0.027s	sys 0.011s Metrics: {"bytes_written":12307489,"delete_count":0,"lbm_write_time_us":18448,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:19:52.658680  6817 maintenance_manager.cc:419] P cd35e2b62ca0493fbaaeda698df4b49b: Scheduling FlushDeltaMemStoresOp(cd52d03fc5fd479b921e4730520f01ad): perf score=2.188937
I20260812 06:19:52.669737  6747 maintenance_manager.cc:643] P cd35e2b62ca0493fbaaeda698df4b49b: FlushDeltaMemStoresOp(cd52d03fc5fd479b921e4730520f01ad) complete. Timing: real 0.011s	user 0.005s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4101,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:52.670535  6817 maintenance_manager.cc:419] P cd35e2b62ca0493fbaaeda698df4b49b: Scheduling MajorDeltaCompactionOp(cd52d03fc5fd479b921e4730520f01ad): perf score=1.000000
I20260812 06:19:52.783991  6747 maintenance_manager.cc:643] P cd35e2b62ca0493fbaaeda698df4b49b: MajorDeltaCompactionOp(cd52d03fc5fd479b921e4730520f01ad) complete. Timing: real 0.113s	user 0.090s	sys 0.023s 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":522,"lbm_read_time_us":8212,"lbm_reads_lt_1ms":472,"lbm_write_time_us":21655,"lbm_writes_lt_1ms":443,"mutex_wait_us":21,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":16512,"update_count":2000}
I20260812 06:19:52.784459  6817 maintenance_manager.cc:419] P cd35e2b62ca0493fbaaeda698df4b49b: Scheduling FlushDeltaMemStoresOp(cd52d03fc5fd479b921e4730520f01ad): perf score=10.126437
I20260812 06:19:52.826826  6747 maintenance_manager.cc:643] P cd35e2b62ca0493fbaaeda698df4b49b: FlushDeltaMemStoresOp(cd52d03fc5fd479b921e4730520f01ad) complete. Timing: real 0.042s	user 0.017s	sys 0.021s Metrics: {"bytes_written":12307489,"delete_count":0,"lbm_write_time_us":17006,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:19:52.827443  6817 maintenance_manager.cc:419] P cd35e2b62ca0493fbaaeda698df4b49b: Scheduling FlushDeltaMemStoresOp(cd52d03fc5fd479b921e4730520f01ad): perf score=2.188937
I20260812 06:19:52.838472  6747 maintenance_manager.cc:643] P cd35e2b62ca0493fbaaeda698df4b49b: FlushDeltaMemStoresOp(cd52d03fc5fd479b921e4730520f01ad) complete. Timing: real 0.011s	user 0.006s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4211,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:52.839221  6817 maintenance_manager.cc:419] P cd35e2b62ca0493fbaaeda698df4b49b: Scheduling MajorDeltaCompactionOp(cd52d03fc5fd479b921e4730520f01ad): perf score=1.000000
I20260812 06:19:52.963852  6747 maintenance_manager.cc:643] P cd35e2b62ca0493fbaaeda698df4b49b: MajorDeltaCompactionOp(cd52d03fc5fd479b921e4730520f01ad) complete. Timing: real 0.124s	user 0.095s	sys 0.029s 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":220,"lbm_read_time_us":10206,"lbm_reads_lt_1ms":472,"lbm_write_time_us":23174,"lbm_writes_lt_1ms":443,"mutex_wait_us":60,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":2432,"update_count":2000}
I20260812 06:19:52.964483  6817 maintenance_manager.cc:419] P cd35e2b62ca0493fbaaeda698df4b49b: Scheduling FlushDeltaMemStoresOp(cd52d03fc5fd479b921e4730520f01ad): perf score=10.126437
I20260812 06:19:53.007587  6747 maintenance_manager.cc:643] P cd35e2b62ca0493fbaaeda698df4b49b: FlushDeltaMemStoresOp(cd52d03fc5fd479b921e4730520f01ad) complete. Timing: real 0.043s	user 0.021s	sys 0.020s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":14272,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:19:53.008183  6817 maintenance_manager.cc:419] P cd35e2b62ca0493fbaaeda698df4b49b: Scheduling FlushDeltaMemStoresOp(cd52d03fc5fd479b921e4730520f01ad): perf score=2.188937
I20260812 06:19:53.018993  6747 maintenance_manager.cc:643] P cd35e2b62ca0493fbaaeda698df4b49b: FlushDeltaMemStoresOp(cd52d03fc5fd479b921e4730520f01ad) complete. Timing: real 0.011s	user 0.006s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4156,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:53.019465  6817 maintenance_manager.cc:419] P cd35e2b62ca0493fbaaeda698df4b49b: Scheduling MajorDeltaCompactionOp(cd52d03fc5fd479b921e4730520f01ad): perf score=1.000000
I20260812 06:19:53.161638  6747 maintenance_manager.cc:643] P cd35e2b62ca0493fbaaeda698df4b49b: MajorDeltaCompactionOp(cd52d03fc5fd479b921e4730520f01ad) complete. Timing: real 0.142s	user 0.086s	sys 0.056s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672277,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":294,"lbm_read_time_us":9772,"lbm_reads_lt_1ms":472,"lbm_write_time_us":24527,"lbm_writes_lt_1ms":443,"mutex_wait_us":29,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":18944,"update_count":2000}
I20260812 06:19:53.162271  6817 maintenance_manager.cc:419] P cd35e2b62ca0493fbaaeda698df4b49b: Scheduling FlushDeltaMemStoresOp(cd52d03fc5fd479b921e4730520f01ad): perf score=10.126437
I20260812 06:19:53.209546  6747 maintenance_manager.cc:643] P cd35e2b62ca0493fbaaeda698df4b49b: FlushDeltaMemStoresOp(cd52d03fc5fd479b921e4730520f01ad) complete. Timing: real 0.047s	user 0.026s	sys 0.011s Metrics: {"bytes_written":12307492,"delete_count":0,"lbm_write_time_us":18008,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:19:53.210011  6817 maintenance_manager.cc:419] P cd35e2b62ca0493fbaaeda698df4b49b: Scheduling FlushDeltaMemStoresOp(cd52d03fc5fd479b921e4730520f01ad): perf score=2.188937
I20260812 06:19:53.221442  6747 maintenance_manager.cc:643] P cd35e2b62ca0493fbaaeda698df4b49b: FlushDeltaMemStoresOp(cd52d03fc5fd479b921e4730520f01ad) complete. Timing: real 0.011s	user 0.006s	sys 0.003s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4230,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:53.222029  6817 maintenance_manager.cc:419] P cd35e2b62ca0493fbaaeda698df4b49b: Scheduling FlushMRSOp(cd52d03fc5fd479b921e4730520f01ad): perf score=1.000000
I20260812 06:19:53.250118  6747 maintenance_manager.cc:643] P cd35e2b62ca0493fbaaeda698df4b49b: FlushMRSOp(cd52d03fc5fd479b921e4730520f01ad) complete. Timing: real 0.028s	user 0.026s	sys 0.000s Metrics: {"bytes_written":1275447,"cfile_init":1,"dirs.queue_time_us":61,"dirs.run_cpu_time_us":188,"dirs.run_wall_time_us":1438,"drs_written":1,"lbm_read_time_us":43,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1742,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":31}
I20260812 06:19:53.250929  6817 maintenance_manager.cc:419] P cd35e2b62ca0493fbaaeda698df4b49b: Scheduling LogGCOp(cd52d03fc5fd479b921e4730520f01ad): free 129320732 bytes of WAL
I20260812 06:19:53.251166  6747 log_reader.cc:385] T cd52d03fc5fd479b921e4730520f01ad: removed 13 log segments from log reader
I20260812 06:19:53.251214  6747 log.cc:1079] T cd52d03fc5fd479b921e4730520f01ad P cd35e2b62ca0493fbaaeda698df4b49b: Deleting log segment in path: /tmp/dist-test-taskTJlGYB/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515588352133-6621-0/minicluster-data/ts-0-root/wals/cd52d03fc5fd479b921e4730520f01ad/wal-000000028 (ops 133-137)
I20260812 06:19:53.251246  6747 log.cc:1079] T cd52d03fc5fd479b921e4730520f01ad P cd35e2b62ca0493fbaaeda698df4b49b: Deleting log segment in path: /tmp/dist-test-taskTJlGYB/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515588352133-6621-0/minicluster-data/ts-0-root/wals/cd52d03fc5fd479b921e4730520f01ad/wal-000000029 (ops 138-142)
I20260812 06:19:53.251314  6747 log.cc:1079] T cd52d03fc5fd479b921e4730520f01ad P cd35e2b62ca0493fbaaeda698df4b49b: Deleting log segment in path: /tmp/dist-test-taskTJlGYB/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515588352133-6621-0/minicluster-data/ts-0-root/wals/cd52d03fc5fd479b921e4730520f01ad/wal-000000030 (ops 143-146)
I20260812 06:19:53.251359  6747 log.cc:1079] T cd52d03fc5fd479b921e4730520f01ad P cd35e2b62ca0493fbaaeda698df4b49b: Deleting log segment in path: /tmp/dist-test-taskTJlGYB/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515588352133-6621-0/minicluster-data/ts-0-root/wals/cd52d03fc5fd479b921e4730520f01ad/wal-000000031 (ops 147-151)
I20260812 06:19:53.251418  6747 log.cc:1079] T cd52d03fc5fd479b921e4730520f01ad P cd35e2b62ca0493fbaaeda698df4b49b: Deleting log segment in path: /tmp/dist-test-taskTJlGYB/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515588352133-6621-0/minicluster-data/ts-0-root/wals/cd52d03fc5fd479b921e4730520f01ad/wal-000000032 (ops 152-156)
I20260812 06:19:53.251439  6747 log.cc:1079] T cd52d03fc5fd479b921e4730520f01ad P cd35e2b62ca0493fbaaeda698df4b49b: Deleting log segment in path: /tmp/dist-test-taskTJlGYB/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515588352133-6621-0/minicluster-data/ts-0-root/wals/cd52d03fc5fd479b921e4730520f01ad/wal-000000033 (ops 157-161)
I20260812 06:19:53.251502  6747 log.cc:1079] T cd52d03fc5fd479b921e4730520f01ad P cd35e2b62ca0493fbaaeda698df4b49b: Deleting log segment in path: /tmp/dist-test-taskTJlGYB/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515588352133-6621-0/minicluster-data/ts-0-root/wals/cd52d03fc5fd479b921e4730520f01ad/wal-000000034 (ops 162-166)
I20260812 06:19:53.251549  6747 log.cc:1079] T cd52d03fc5fd479b921e4730520f01ad P cd35e2b62ca0493fbaaeda698df4b49b: Deleting log segment in path: /tmp/dist-test-taskTJlGYB/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515588352133-6621-0/minicluster-data/ts-0-root/wals/cd52d03fc5fd479b921e4730520f01ad/wal-000000035 (ops 167-171)
I20260812 06:19:53.251593  6747 log.cc:1079] T cd52d03fc5fd479b921e4730520f01ad P cd35e2b62ca0493fbaaeda698df4b49b: Deleting log segment in path: /tmp/dist-test-taskTJlGYB/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515588352133-6621-0/minicluster-data/ts-0-root/wals/cd52d03fc5fd479b921e4730520f01ad/wal-000000036 (ops 172-176)
I20260812 06:19:53.251637  6747 log.cc:1079] T cd52d03fc5fd479b921e4730520f01ad P cd35e2b62ca0493fbaaeda698df4b49b: Deleting log segment in path: /tmp/dist-test-taskTJlGYB/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515588352133-6621-0/minicluster-data/ts-0-root/wals/cd52d03fc5fd479b921e4730520f01ad/wal-000000037 (ops 177-181)
I20260812 06:19:53.251685  6747 log.cc:1079] T cd52d03fc5fd479b921e4730520f01ad P cd35e2b62ca0493fbaaeda698df4b49b: Deleting log segment in path: /tmp/dist-test-taskTJlGYB/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515588352133-6621-0/minicluster-data/ts-0-root/wals/cd52d03fc5fd479b921e4730520f01ad/wal-000000038 (ops 182-186)
I20260812 06:19:53.251730  6747 log.cc:1079] T cd52d03fc5fd479b921e4730520f01ad P cd35e2b62ca0493fbaaeda698df4b49b: Deleting log segment in path: /tmp/dist-test-taskTJlGYB/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515588352133-6621-0/minicluster-data/ts-0-root/wals/cd52d03fc5fd479b921e4730520f01ad/wal-000000039 (ops 187-190)
I20260812 06:19:53.251775  6747 log.cc:1079] T cd52d03fc5fd479b921e4730520f01ad P cd35e2b62ca0493fbaaeda698df4b49b: Deleting log segment in path: /tmp/dist-test-taskTJlGYB/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515588352133-6621-0/minicluster-data/ts-0-root/wals/cd52d03fc5fd479b921e4730520f01ad/wal-000000040 (ops 191-195)
I20260812 06:19:53.287812  6747 maintenance_manager.cc:643] P cd35e2b62ca0493fbaaeda698df4b49b: LogGCOp(cd52d03fc5fd479b921e4730520f01ad) complete. Timing: real 0.037s	user 0.001s	sys 0.035s Metrics: {}
I20260812 06:19:53.288420  6817 maintenance_manager.cc:419] P cd35e2b62ca0493fbaaeda698df4b49b: Scheduling FlushDeltaMemStoresOp(cd52d03fc5fd479b921e4730520f01ad): perf score=3.181125
I20260812 06:19:53.323160  6747 maintenance_manager.cc:643] P cd35e2b62ca0493fbaaeda698df4b49b: FlushDeltaMemStoresOp(cd52d03fc5fd479b921e4730520f01ad) complete. Timing: real 0.033s	user 0.013s	sys 0.019s Metrics: {"bytes_written":4512900,"delete_count":0,"lbm_write_time_us":8199,"lbm_writes_lt_1ms":113,"reinsert_count":0,"update_count":550}
I20260812 06:19:53.323777  6817 maintenance_manager.cc:419] P cd35e2b62ca0493fbaaeda698df4b49b: Scheduling FlushDeltaMemStoresOp(cd52d03fc5fd479b921e4730520f01ad): perf score=2.188937
I20260812 06:19:53.335114  6747 maintenance_manager.cc:643] P cd35e2b62ca0493fbaaeda698df4b49b: FlushDeltaMemStoresOp(cd52d03fc5fd479b921e4730520f01ad) complete. Timing: real 0.011s	user 0.009s	sys 0.001s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":4290,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:19:53.335603  6817 maintenance_manager.cc:419] P cd35e2b62ca0493fbaaeda698df4b49b: Scheduling MajorDeltaCompactionOp(cd52d03fc5fd479b921e4730520f01ad): perf score=1.000000
I20260812 06:19:53.436501  6621 heavy-update-compaction-itest.cc:229] Time spent updating: real 4.803s	user 1.782s	sys 0.155s
I20260812 06:19:53.526757  6621 heavy-update-compaction-itest.cc:265] Time spent scanning: real 0.090s	user 0.003s	sys 0.000s
I20260812 06:19:53.527416  6621 tablet_server.cc:179] TabletServer@127.6.119.65:0 shutting down...
I20260812 06:19:53.533327  6747 maintenance_manager.cc:643] P cd35e2b62ca0493fbaaeda698df4b49b: MajorDeltaCompactionOp(cd52d03fc5fd479b921e4730520f01ad) complete. Timing: real 0.198s	user 0.117s	sys 0.077s Metrics: {"cfile_cache_miss":634,"cfile_cache_miss_bytes":28877328,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":364,"dirs.run_cpu_time_us":597,"dirs.run_wall_time_us":2858,"lbm_read_time_us":14925,"lbm_reads_lt_1ms":670,"lbm_write_time_us":33257,"lbm_writes_lt_1ms":643,"mutex_wait_us":37,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":5888,"update_count":3000}
I20260812 06:19:53.534000  6817 maintenance_manager.cc:419] P cd35e2b62ca0493fbaaeda698df4b49b: Scheduling UndoDeltaBlockGCOp(cd52d03fc5fd479b921e4730520f01ad): 483 bytes on disk
I20260812 06:19:53.534590  6747 maintenance_manager.cc:643] P cd35e2b62ca0493fbaaeda698df4b49b: UndoDeltaBlockGCOp(cd52d03fc5fd479b921e4730520f01ad) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":113,"lbm_reads_lt_1ms":4}
I20260812 06:19:53.535279  6817 maintenance_manager.cc:419] P cd35e2b62ca0493fbaaeda698df4b49b: Scheduling FlushDeltaMemStoresOp(cd52d03fc5fd479b921e4730520f01ad): perf score=6.157687
I20260812 06:19:53.556774  6747 maintenance_manager.cc:643] P cd35e2b62ca0493fbaaeda698df4b49b: FlushDeltaMemStoresOp(cd52d03fc5fd479b921e4730520f01ad) complete. Timing: real 0.021s	user 0.009s	sys 0.010s Metrics: {"bytes_written":8205078,"delete_count":0,"lbm_write_time_us":10004,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":202,"reinsert_count":0,"update_count":1000}
I20260812 06:19:53.557924  6621 ts_tablet_manager.cc:1507] Shutting down tablet manager...
I20260812 06:19:53.558377  6621 tablet_replica.cc:333] T cd52d03fc5fd479b921e4730520f01ad P cd35e2b62ca0493fbaaeda698df4b49b: stopping tablet replica
I20260812 06:19:53.558692  6621 raft_consensus.cc:2243] T cd52d03fc5fd479b921e4730520f01ad P cd35e2b62ca0493fbaaeda698df4b49b [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:19:53.558959  6621 raft_consensus.cc:2272] T cd52d03fc5fd479b921e4730520f01ad P cd35e2b62ca0493fbaaeda698df4b49b [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:19:53.573987  6621 tablet_server.cc:196] TabletServer@127.6.119.65:0 shutdown complete.
I20260812 06:19:53.579005  6621 master.cc:562] Master@127.6.119.126:44237 shutting down...
I20260812 06:19:53.582531  6621 raft_consensus.cc:2243] T 00000000000000000000000000000000 P dbfb40d8d29f41798c423e936f3d5d5d [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:19:53.582713  6621 raft_consensus.cc:2272] T 00000000000000000000000000000000 P dbfb40d8d29f41798c423e936f3d5d5d [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:19:53.582810  6621 tablet_replica.cc:333] T 00000000000000000000000000000000 P dbfb40d8d29f41798c423e936f3d5d5d: stopping tablet replica
I20260812 06:19:53.595139  6621 master.cc:584] Master@127.6.119.126:44237 shutdown complete.
[       OK ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/0 (5319 ms)
[ RUN      ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/1
I20260812 06:19:53.694796  6621 internal_mini_cluster.cc:156] Creating distributed mini masters. Addrs: 127.6.119.126:37017
I20260812 06:19:53.695230  6621 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:19:53.697300  6855 instance_detector.cc:116] could not retrieve OpenStack instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:19:53.697394  6621 server_base.cc:1061] running on GCE node
W20260812 06:19:53.697341  6853 instance_detector.cc:116] could not retrieve Azure instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:19:53.697365  6852 instance_detector.cc:116] could not retrieve AWS instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:19:53.697713  6621 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:19:53.697757  6621 system_unsync_time.cc:38] NTP support is disabled. Clock error bounds will not be accurate. This configuration is not suitable for distributed clusters.
I20260812 06:19:53.697772  6621 hybrid_clock.cc:648] HybridClock initialized: now 1786515593697772 us; error 0 us; skew 500 ppm
I20260812 06:19:53.698704  6621 webserver.cc:533] Webserver started at http://127.6.119.126:37051/ using document root <none> and password file <none>
I20260812 06:19:53.698902  6621 fs_manager.cc:362] Metadata directory not provided
I20260812 06:19:53.698982  6621 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:19:53.699085  6621 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:19:53.699503  6621 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskTJlGYB/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515588352133-6621-0/minicluster-data/master-0-root/instance:
uuid: "3ef297e27c7446c5bd72d26e7ac9840d"
format_stamp: "Formatted at 2026-08-12 06:19:53 on dist-test-slave-gp6n"
I20260812 06:19:53.701027  6621 fs_manager.cc:696] Time spent creating directory manager: real 0.001s	user 0.000s	sys 0.002s
I20260812 06:19:53.701987  6863 log_block_manager.cc:4127] Time spent loading block containers with low live blocks: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:19:53.702219  6621 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.000s	sys 0.001s
I20260812 06:19:53.702311  6621 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskTJlGYB/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515588352133-6621-0/minicluster-data/master-0-root
uuid: "3ef297e27c7446c5bd72d26e7ac9840d"
format_stamp: "Formatted at 2026-08-12 06:19:53 on dist-test-slave-gp6n"
I20260812 06:19:53.702382  6621 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskTJlGYB/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515588352133-6621-0/minicluster-data/master-0-root
metadata directory: /tmp/dist-test-taskTJlGYB/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515588352133-6621-0/minicluster-data/master-0-root
1 data directories: /tmp/dist-test-taskTJlGYB/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515588352133-6621-0/minicluster-data/master-0-root/data
Total live blocks: 0
Total live bytes: 0
Total live bytes (after alignment): 0
Total number of LBM containers: 0 (0 full)
Did not check for missing blocks
Did not check for orphaned blocks
Total full LBM containers with extra space: 0 (0 repaired)
Total full LBM container extra space in bytes: 0 (0 repaired)
Total incomplete LBM containers: 0 (0 repaired)
Total LBM partial records: 0 (0 repaired)
Total corrupted LBM metadata records in RocksDB: 0 (0 repaired)
I20260812 06:19:53.711287  6621 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:19:53.711617  6621 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:19:53.715981  6621 rpc_server.cc:307] RPC server started. Bound to: 127.6.119.126:37017
I20260812 06:19:53.718148  6926 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.6.119.126:37017 every 8 connection(s)
I20260812 06:19:53.720649  6927 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet 00000000000000000000000000000000. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:19:53.722499  6927 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P 3ef297e27c7446c5bd72d26e7ac9840d: Bootstrap starting.
I20260812 06:19:53.723274  6927 tablet_bootstrap.cc:654] T 00000000000000000000000000000000 P 3ef297e27c7446c5bd72d26e7ac9840d: Neither blocks nor log segments found. Creating new log.
I20260812 06:19:53.724238  6927 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P 3ef297e27c7446c5bd72d26e7ac9840d: No bootstrap required, opened a new log
I20260812 06:19:53.724639  6927 raft_consensus.cc:359] T 00000000000000000000000000000000 P 3ef297e27c7446c5bd72d26e7ac9840d [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "3ef297e27c7446c5bd72d26e7ac9840d" member_type: VOTER }
I20260812 06:19:53.724722  6927 raft_consensus.cc:385] T 00000000000000000000000000000000 P 3ef297e27c7446c5bd72d26e7ac9840d [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:19:53.724779  6927 raft_consensus.cc:740] T 00000000000000000000000000000000 P 3ef297e27c7446c5bd72d26e7ac9840d [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: 3ef297e27c7446c5bd72d26e7ac9840d, State: Initialized, Role: FOLLOWER
I20260812 06:19:53.725005  6927 consensus_queue.cc:260] T 00000000000000000000000000000000 P 3ef297e27c7446c5bd72d26e7ac9840d [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: "3ef297e27c7446c5bd72d26e7ac9840d" member_type: VOTER }
I20260812 06:19:53.725101  6927 raft_consensus.cc:399] T 00000000000000000000000000000000 P 3ef297e27c7446c5bd72d26e7ac9840d [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:19:53.725171  6927 raft_consensus.cc:493] T 00000000000000000000000000000000 P 3ef297e27c7446c5bd72d26e7ac9840d [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:19:53.725234  6927 raft_consensus.cc:3060] T 00000000000000000000000000000000 P 3ef297e27c7446c5bd72d26e7ac9840d [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:19:53.725924  6927 raft_consensus.cc:515] T 00000000000000000000000000000000 P 3ef297e27c7446c5bd72d26e7ac9840d [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "3ef297e27c7446c5bd72d26e7ac9840d" member_type: VOTER }
I20260812 06:19:53.726078  6927 leader_election.cc:304] T 00000000000000000000000000000000 P 3ef297e27c7446c5bd72d26e7ac9840d [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: 3ef297e27c7446c5bd72d26e7ac9840d; no voters: 
I20260812 06:19:53.726284  6927 leader_election.cc:290] T 00000000000000000000000000000000 P 3ef297e27c7446c5bd72d26e7ac9840d [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:19:53.726404  6933 raft_consensus.cc:2804] T 00000000000000000000000000000000 P 3ef297e27c7446c5bd72d26e7ac9840d [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:19:53.726670  6933 raft_consensus.cc:697] T 00000000000000000000000000000000 P 3ef297e27c7446c5bd72d26e7ac9840d [term 1 LEADER]: Becoming Leader. State: Replica: 3ef297e27c7446c5bd72d26e7ac9840d, State: Running, Role: LEADER
I20260812 06:19:53.726802  6927 sys_catalog.cc:565] T 00000000000000000000000000000000 P 3ef297e27c7446c5bd72d26e7ac9840d [sys.catalog]: configured and running, proceeding with master startup.
I20260812 06:19:53.726811  6933 consensus_queue.cc:237] T 00000000000000000000000000000000 P 3ef297e27c7446c5bd72d26e7ac9840d [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: "3ef297e27c7446c5bd72d26e7ac9840d" member_type: VOTER }
I20260812 06:19:53.727308  6934 sys_catalog.cc:455] T 00000000000000000000000000000000 P 3ef297e27c7446c5bd72d26e7ac9840d [sys.catalog]: SysCatalogTable state changed. Reason: RaftConsensus started. Latest consensus state: current_term: 1 leader_uuid: "3ef297e27c7446c5bd72d26e7ac9840d" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "3ef297e27c7446c5bd72d26e7ac9840d" member_type: VOTER } }
I20260812 06:19:53.727340  6935 sys_catalog.cc:455] T 00000000000000000000000000000000 P 3ef297e27c7446c5bd72d26e7ac9840d [sys.catalog]: SysCatalogTable state changed. Reason: New leader 3ef297e27c7446c5bd72d26e7ac9840d. Latest consensus state: current_term: 1 leader_uuid: "3ef297e27c7446c5bd72d26e7ac9840d" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "3ef297e27c7446c5bd72d26e7ac9840d" member_type: VOTER } }
I20260812 06:19:53.727507  6935 sys_catalog.cc:458] T 00000000000000000000000000000000 P 3ef297e27c7446c5bd72d26e7ac9840d [sys.catalog]: This master's current role is: LEADER
I20260812 06:19:53.727763  6934 sys_catalog.cc:458] T 00000000000000000000000000000000 P 3ef297e27c7446c5bd72d26e7ac9840d [sys.catalog]: This master's current role is: LEADER
I20260812 06:19:53.728070  6941 catalog_manager.cc:1511] Loading table and tablet metadata into memory...
I20260812 06:19:53.729029  6941 catalog_manager.cc:1520] Initializing Kudu cluster ID...
I20260812 06:19:53.729233  6621 internal_mini_cluster.cc:184] Waiting to initialize catalog manager on master 0
I20260812 06:19:53.730938  6941 catalog_manager.cc:1383] Generated new cluster ID: 177ec4e447b449b2b8a67d28d0bd1f0b
I20260812 06:19:53.730996  6941 catalog_manager.cc:1531] Initializing Kudu internal certificate authority...
I20260812 06:19:53.741326  6941 catalog_manager.cc:1406] Generated new certificate authority record
I20260812 06:19:53.741945  6941 catalog_manager.cc:1540] Loading token signing keys...
I20260812 06:19:53.748252  6941 catalog_manager.cc:6092] T 00000000000000000000000000000000 P 3ef297e27c7446c5bd72d26e7ac9840d: Generated new TSK 0
I20260812 06:19:53.748454  6941 catalog_manager.cc:1550] Initializing in-progress tserver states...
I20260812 06:19:53.761782  6621 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:19:53.763803  6955 instance_detector.cc:116] could not retrieve Azure instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:19:53.763865  6958 instance_detector.cc:116] could not retrieve OpenStack instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:19:53.763868  6954 instance_detector.cc:116] could not retrieve AWS instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:19:53.764117  6621 server_base.cc:1061] running on GCE node
I20260812 06:19:53.764304  6621 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:19:53.764343  6621 system_unsync_time.cc:38] NTP support is disabled. Clock error bounds will not be accurate. This configuration is not suitable for distributed clusters.
I20260812 06:19:53.764359  6621 hybrid_clock.cc:648] HybridClock initialized: now 1786515593764359 us; error 0 us; skew 500 ppm
I20260812 06:19:53.765268  6621 webserver.cc:533] Webserver started at http://127.6.119.65:43807/ using document root <none> and password file <none>
I20260812 06:19:53.765445  6621 fs_manager.cc:362] Metadata directory not provided
I20260812 06:19:53.765496  6621 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:19:53.765578  6621 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:19:53.765980  6621 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskTJlGYB/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515588352133-6621-0/minicluster-data/ts-0-root/instance:
uuid: "87eb638e65b24b22a36d13a4e52c50ef"
format_stamp: "Formatted at 2026-08-12 06:19:53 on dist-test-slave-gp6n"
I20260812 06:19:53.767645  6621 fs_manager.cc:696] Time spent creating directory manager: real 0.001s	user 0.002s	sys 0.000s
I20260812 06:19:53.768572  6964 log_block_manager.cc:4127] Time spent loading block containers with low live blocks: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:19:53.768790  6621 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.001s	sys 0.000s
I20260812 06:19:53.768878  6621 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskTJlGYB/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515588352133-6621-0/minicluster-data/ts-0-root
uuid: "87eb638e65b24b22a36d13a4e52c50ef"
format_stamp: "Formatted at 2026-08-12 06:19:53 on dist-test-slave-gp6n"
I20260812 06:19:53.768965  6621 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskTJlGYB/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515588352133-6621-0/minicluster-data/ts-0-root
metadata directory: /tmp/dist-test-taskTJlGYB/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515588352133-6621-0/minicluster-data/ts-0-root
1 data directories: /tmp/dist-test-taskTJlGYB/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515588352133-6621-0/minicluster-data/ts-0-root/data
Total live blocks: 0
Total live bytes: 0
Total live bytes (after alignment): 0
Total number of LBM containers: 0 (0 full)
Did not check for missing blocks
Did not check for orphaned blocks
Total full LBM containers with extra space: 0 (0 repaired)
Total full LBM container extra space in bytes: 0 (0 repaired)
Total incomplete LBM containers: 0 (0 repaired)
Total LBM partial records: 0 (0 repaired)
Total corrupted LBM metadata records in RocksDB: 0 (0 repaired)
I20260812 06:19:53.777714  6621 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:19:53.778066  6621 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:19:53.778352  6621 txn_system_client.cc:432] TxnSystemClient initialization is disabled...
I20260812 06:19:53.778817  6621 ts_tablet_manager.cc:585] Loaded tablet metadata (0 total tablets, 0 live tablets)
I20260812 06:19:53.778877  6621 ts_tablet_manager.cc:531] Time spent load tablet metadata: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:19:53.778939  6621 ts_tablet_manager.cc:616] Registered 0 tablets
I20260812 06:19:53.778985  6621 ts_tablet_manager.cc:595] Time spent register tablets: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:19:53.783231  6621 rpc_server.cc:307] RPC server started. Bound to: 127.6.119.65:38087
I20260812 06:19:53.784409  7039 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.6.119.65:38087 every 8 connection(s)
I20260812 06:19:53.793529  7040 heartbeater.cc:344] Connected to a master server at 127.6.119.126:37017
I20260812 06:19:53.793632  7040 heartbeater.cc:461] Registering TS with master...
I20260812 06:19:53.793815  7040 heartbeater.cc:507] Master 127.6.119.126:37017 requested a full tablet report, sending...
I20260812 06:19:53.794545  6883 ts_manager.cc:194] Registered new tserver with Master: 87eb638e65b24b22a36d13a4e52c50ef (127.6.119.65:38087)
I20260812 06:19:53.795203  6621 internal_mini_cluster.cc:371] 1 TS(s) registered with all masters after 0.011032439s
I20260812 06:19:53.795291  6883 master_service.cc:502] Signed X509 certificate for tserver {username='slave'} at 127.0.0.1:58318
I20260812 06:19:53.802063  6883 catalog_manager.cc:2283] Servicing CreateTable request from {username='slave'} at 127.0.0.1:58320:
name: "heavy-update-compaction-test"
schema {
  columns {
    name: "key"
    type: INT64
    is_key: true
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_a"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_b"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_c"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_d"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_e"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
}
num_replicas: 1
split_rows_range_bounds {
}
partition_schema {
  range_schema {
  }
}
I20260812 06:19:53.810815  6997 tablet_service.cc:1511] Processing CreateTablet for tablet e584ae22fe034071a40543c9556cc34c (DEFAULT_TABLE table=heavy-update-compaction-test [id=5c48daabfa284b7db3bfb8433e483a64]), partition=
I20260812 06:19:53.811102  6997 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet e584ae22fe034071a40543c9556cc34c. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:19:53.813019  7055 tablet_bootstrap.cc:492] T e584ae22fe034071a40543c9556cc34c P 87eb638e65b24b22a36d13a4e52c50ef: Bootstrap starting.
I20260812 06:19:53.813961  7055 tablet_bootstrap.cc:654] T e584ae22fe034071a40543c9556cc34c P 87eb638e65b24b22a36d13a4e52c50ef: Neither blocks nor log segments found. Creating new log.
I20260812 06:19:53.814997  7055 tablet_bootstrap.cc:492] T e584ae22fe034071a40543c9556cc34c P 87eb638e65b24b22a36d13a4e52c50ef: No bootstrap required, opened a new log
I20260812 06:19:53.815069  7055 ts_tablet_manager.cc:1403] T e584ae22fe034071a40543c9556cc34c P 87eb638e65b24b22a36d13a4e52c50ef: Time spent bootstrapping tablet: real 0.002s	user 0.000s	sys 0.002s
I20260812 06:19:53.815411  7055 raft_consensus.cc:359] T e584ae22fe034071a40543c9556cc34c P 87eb638e65b24b22a36d13a4e52c50ef [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "87eb638e65b24b22a36d13a4e52c50ef" member_type: VOTER last_known_addr { host: "127.6.119.65" port: 38087 } }
I20260812 06:19:53.815493  7055 raft_consensus.cc:385] T e584ae22fe034071a40543c9556cc34c P 87eb638e65b24b22a36d13a4e52c50ef [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:19:53.815515  7055 raft_consensus.cc:740] T e584ae22fe034071a40543c9556cc34c P 87eb638e65b24b22a36d13a4e52c50ef [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: 87eb638e65b24b22a36d13a4e52c50ef, State: Initialized, Role: FOLLOWER
I20260812 06:19:53.815604  7055 consensus_queue.cc:260] T e584ae22fe034071a40543c9556cc34c P 87eb638e65b24b22a36d13a4e52c50ef [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: "87eb638e65b24b22a36d13a4e52c50ef" member_type: VOTER last_known_addr { host: "127.6.119.65" port: 38087 } }
I20260812 06:19:53.815661  7055 raft_consensus.cc:399] T e584ae22fe034071a40543c9556cc34c P 87eb638e65b24b22a36d13a4e52c50ef [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:19:53.815685  7055 raft_consensus.cc:493] T e584ae22fe034071a40543c9556cc34c P 87eb638e65b24b22a36d13a4e52c50ef [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:19:53.815718  7055 raft_consensus.cc:3060] T e584ae22fe034071a40543c9556cc34c P 87eb638e65b24b22a36d13a4e52c50ef [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:19:53.816565  7055 raft_consensus.cc:515] T e584ae22fe034071a40543c9556cc34c P 87eb638e65b24b22a36d13a4e52c50ef [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "87eb638e65b24b22a36d13a4e52c50ef" member_type: VOTER last_known_addr { host: "127.6.119.65" port: 38087 } }
I20260812 06:19:53.816744  7055 leader_election.cc:304] T e584ae22fe034071a40543c9556cc34c P 87eb638e65b24b22a36d13a4e52c50ef [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: 87eb638e65b24b22a36d13a4e52c50ef; no voters: 
I20260812 06:19:53.816972  7055 leader_election.cc:290] T e584ae22fe034071a40543c9556cc34c P 87eb638e65b24b22a36d13a4e52c50ef [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:19:53.817095  7057 raft_consensus.cc:2804] T e584ae22fe034071a40543c9556cc34c P 87eb638e65b24b22a36d13a4e52c50ef [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:19:53.817329  7057 raft_consensus.cc:697] T e584ae22fe034071a40543c9556cc34c P 87eb638e65b24b22a36d13a4e52c50ef [term 1 LEADER]: Becoming Leader. State: Replica: 87eb638e65b24b22a36d13a4e52c50ef, State: Running, Role: LEADER
I20260812 06:19:53.817338  7055 ts_tablet_manager.cc:1434] T e584ae22fe034071a40543c9556cc34c P 87eb638e65b24b22a36d13a4e52c50ef: Time spent starting tablet: real 0.002s	user 0.000s	sys 0.002s
I20260812 06:19:53.817363  7040 heartbeater.cc:499] Master 127.6.119.126:37017 was elected leader, sending a full tablet report...
I20260812 06:19:53.817487  7057 consensus_queue.cc:237] T e584ae22fe034071a40543c9556cc34c P 87eb638e65b24b22a36d13a4e52c50ef [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: "87eb638e65b24b22a36d13a4e52c50ef" member_type: VOTER last_known_addr { host: "127.6.119.65" port: 38087 } }
I20260812 06:19:53.818827  6883 catalog_manager.cc:5719] T e584ae22fe034071a40543c9556cc34c P 87eb638e65b24b22a36d13a4e52c50ef reported cstate change: term changed from 0 to 1, leader changed from <none> to 87eb638e65b24b22a36d13a4e52c50ef (127.6.119.65). New cstate: current_term: 1 leader_uuid: "87eb638e65b24b22a36d13a4e52c50ef" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "87eb638e65b24b22a36d13a4e52c50ef" member_type: VOTER last_known_addr { host: "127.6.119.65" port: 38087 } health_report { overall_health: HEALTHY } } }
I20260812 06:19:53.874310  6621 heavy-update-compaction-itest.cc:215] Time spent inserting: real 0.052s	user 0.016s	sys 0.008s
I20260812 06:19:54.034818  7041 maintenance_manager.cc:419] P 87eb638e65b24b22a36d13a4e52c50ef: Scheduling FlushMRSOp(e584ae22fe034071a40543c9556cc34c): perf score=23.023690
I20260812 06:19:54.192893  6969 maintenance_manager.cc:643] P 87eb638e65b24b22a36d13a4e52c50ef: FlushMRSOp(e584ae22fe034071a40543c9556cc34c) complete. Timing: real 0.158s	user 0.113s	sys 0.036s Metrics: {"bytes_written":12307489,"cfile_init":1,"delete_count":0,"dirs.queue_time_us":61,"dirs.run_cpu_time_us":209,"dirs.run_wall_time_us":975,"drs_written":1,"lbm_read_time_us":41,"lbm_reads_lt_1ms":4,"lbm_write_time_us":40965,"lbm_writes_lt_1ms":857,"peak_mem_usage":0,"reinsert_count":0,"rows_written":105,"spinlock_wait_cycles":1408,"update_count":1500}
I20260812 06:19:54.193778  7041 maintenance_manager.cc:419] P 87eb638e65b24b22a36d13a4e52c50ef: Scheduling LogGCOp(e584ae22fe034071a40543c9556cc34c): free 20743880 bytes of WAL
I20260812 06:19:54.194092  6969 log_reader.cc:385] T e584ae22fe034071a40543c9556cc34c: removed 2 log segments from log reader
I20260812 06:19:54.194165  6969 log.cc:1079] T e584ae22fe034071a40543c9556cc34c P 87eb638e65b24b22a36d13a4e52c50ef: Deleting log segment in path: /tmp/dist-test-taskTJlGYB/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515588352133-6621-0/minicluster-data/ts-0-root/wals/e584ae22fe034071a40543c9556cc34c/wal-000000001 (ops 1-6)
I20260812 06:19:54.194223  6969 log.cc:1079] T e584ae22fe034071a40543c9556cc34c P 87eb638e65b24b22a36d13a4e52c50ef: Deleting log segment in path: /tmp/dist-test-taskTJlGYB/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515588352133-6621-0/minicluster-data/ts-0-root/wals/e584ae22fe034071a40543c9556cc34c/wal-000000002 (ops 7-11)
I20260812 06:19:54.198664  6969 maintenance_manager.cc:643] P 87eb638e65b24b22a36d13a4e52c50ef: LogGCOp(e584ae22fe034071a40543c9556cc34c) complete. Timing: real 0.005s	user 0.000s	sys 0.004s Metrics: {}
I20260812 06:19:54.198992  7041 maintenance_manager.cc:419] P 87eb638e65b24b22a36d13a4e52c50ef: Scheduling UndoDeltaBlockGCOp(e584ae22fe034071a40543c9556cc34c): 20513813 bytes on disk
I20260812 06:19:54.199401  6969 maintenance_manager.cc:643] P 87eb638e65b24b22a36d13a4e52c50ef: UndoDeltaBlockGCOp(e584ae22fe034071a40543c9556cc34c) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":55,"lbm_reads_lt_1ms":4}
I20260812 06:19:54.199777  7041 maintenance_manager.cc:419] P 87eb638e65b24b22a36d13a4e52c50ef: Scheduling FlushDeltaMemStoresOp(e584ae22fe034071a40543c9556cc34c): perf score=2.188937
I20260812 06:19:54.211846  6969 maintenance_manager.cc:643] P 87eb638e65b24b22a36d13a4e52c50ef: FlushDeltaMemStoresOp(e584ae22fe034071a40543c9556cc34c) complete. Timing: real 0.012s	user 0.000s	sys 0.010s Metrics: {"bytes_written":4102660,"delete_count":0,"lbm_write_time_us":4633,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:54.212393  7041 maintenance_manager.cc:419] P 87eb638e65b24b22a36d13a4e52c50ef: Scheduling MajorDeltaCompactionOp(e584ae22fe034071a40543c9556cc34c): perf score=1.000000
I20260812 06:19:54.363240  6969 maintenance_manager.cc:643] P 87eb638e65b24b22a36d13a4e52c50ef: MajorDeltaCompactionOp(e584ae22fe034071a40543c9556cc34c) complete. Timing: real 0.151s	user 0.114s	sys 0.032s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20713272,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":463,"lbm_read_time_us":12396,"lbm_reads_lt_1ms":464,"lbm_write_time_us":23425,"lbm_writes_lt_1ms":443,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":5504,"thread_start_us":326,"threads_started":5,"update_count":2000}
I20260812 06:19:54.363957  7041 maintenance_manager.cc:419] P 87eb638e65b24b22a36d13a4e52c50ef: Scheduling FlushDeltaMemStoresOp(e584ae22fe034071a40543c9556cc34c): perf score=11.118625
I20260812 06:19:54.408944  6969 maintenance_manager.cc:643] P 87eb638e65b24b22a36d13a4e52c50ef: FlushDeltaMemStoresOp(e584ae22fe034071a40543c9556cc34c) complete. Timing: real 0.045s	user 0.021s	sys 0.020s Metrics: {"bytes_written":12717735,"delete_count":0,"lbm_write_time_us":15775,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:19:54.409562  7041 maintenance_manager.cc:419] P 87eb638e65b24b22a36d13a4e52c50ef: Scheduling FlushDeltaMemStoresOp(e584ae22fe034071a40543c9556cc34c): perf score=2.188937
I20260812 06:19:54.437090  6969 maintenance_manager.cc:643] P 87eb638e65b24b22a36d13a4e52c50ef: FlushDeltaMemStoresOp(e584ae22fe034071a40543c9556cc34c) complete. Timing: real 0.027s	user 0.008s	sys 0.004s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":5133,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:19:54.437605  7041 maintenance_manager.cc:419] P 87eb638e65b24b22a36d13a4e52c50ef: Scheduling FlushDeltaMemStoresOp(e584ae22fe034071a40543c9556cc34c): perf score=2.188937
I20260812 06:19:54.447247  6969 maintenance_manager.cc:643] P 87eb638e65b24b22a36d13a4e52c50ef: FlushDeltaMemStoresOp(e584ae22fe034071a40543c9556cc34c) complete. Timing: real 0.009s	user 0.005s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3822,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:54.447680  7041 maintenance_manager.cc:419] P 87eb638e65b24b22a36d13a4e52c50ef: Scheduling MajorDeltaCompactionOp(e584ae22fe034071a40543c9556cc34c): perf score=1.000000
I20260812 06:19:54.619062  6969 maintenance_manager.cc:643] P 87eb638e65b24b22a36d13a4e52c50ef: MajorDeltaCompactionOp(e584ae22fe034071a40543c9556cc34c) complete. Timing: real 0.171s	user 0.116s	sys 0.048s Metrics: {"cfile_cache_miss":533,"cfile_cache_miss_bytes":24815794,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":343,"lbm_read_time_us":10916,"lbm_reads_lt_1ms":573,"lbm_write_time_us":27628,"lbm_writes_lt_1ms":543,"mutex_wait_us":23,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":12928,"update_count":2500}
I20260812 06:19:54.619609  7041 maintenance_manager.cc:419] P 87eb638e65b24b22a36d13a4e52c50ef: Scheduling FlushDeltaMemStoresOp(e584ae22fe034071a40543c9556cc34c): perf score=14.095187
I20260812 06:19:54.678932  6969 maintenance_manager.cc:643] P 87eb638e65b24b22a36d13a4e52c50ef: FlushDeltaMemStoresOp(e584ae22fe034071a40543c9556cc34c) complete. Timing: real 0.059s	user 0.026s	sys 0.023s Metrics: {"bytes_written":16409900,"delete_count":0,"lbm_write_time_us":17554,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:54.679467  7041 maintenance_manager.cc:419] P 87eb638e65b24b22a36d13a4e52c50ef: Scheduling FlushDeltaMemStoresOp(e584ae22fe034071a40543c9556cc34c): perf score=2.188937
I20260812 06:19:54.690044  6969 maintenance_manager.cc:643] P 87eb638e65b24b22a36d13a4e52c50ef: FlushDeltaMemStoresOp(e584ae22fe034071a40543c9556cc34c) complete. Timing: real 0.010s	user 0.009s	sys 0.000s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4134,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:54.690515  7041 maintenance_manager.cc:419] P 87eb638e65b24b22a36d13a4e52c50ef: Scheduling MajorDeltaCompactionOp(e584ae22fe034071a40543c9556cc34c): perf score=1.000000
I20260812 06:19:54.881474  6969 maintenance_manager.cc:643] P 87eb638e65b24b22a36d13a4e52c50ef: MajorDeltaCompactionOp(e584ae22fe034071a40543c9556cc34c) complete. Timing: real 0.191s	user 0.127s	sys 0.055s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24815681,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":163,"lbm_read_time_us":13209,"lbm_reads_lt_1ms":572,"lbm_write_time_us":31515,"lbm_writes_lt_1ms":543,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":4352,"update_count":2500}
I20260812 06:19:54.881999  7041 maintenance_manager.cc:419] P 87eb638e65b24b22a36d13a4e52c50ef: Scheduling FlushDeltaMemStoresOp(e584ae22fe034071a40543c9556cc34c): perf score=14.095187
I20260812 06:19:54.939566  6969 maintenance_manager.cc:643] P 87eb638e65b24b22a36d13a4e52c50ef: FlushDeltaMemStoresOp(e584ae22fe034071a40543c9556cc34c) complete. Timing: real 0.057s	user 0.026s	sys 0.023s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":17823,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:54.940100  7041 maintenance_manager.cc:419] P 87eb638e65b24b22a36d13a4e52c50ef: Scheduling FlushDeltaMemStoresOp(e584ae22fe034071a40543c9556cc34c): perf score=2.188937
I20260812 06:19:54.950284  6969 maintenance_manager.cc:643] P 87eb638e65b24b22a36d13a4e52c50ef: FlushDeltaMemStoresOp(e584ae22fe034071a40543c9556cc34c) complete. Timing: real 0.010s	user 0.000s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4117,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:54.950848  7041 maintenance_manager.cc:419] P 87eb638e65b24b22a36d13a4e52c50ef: Scheduling MajorDeltaCompactionOp(e584ae22fe034071a40543c9556cc34c): perf score=1.000000
I20260812 06:19:55.154261  6969 maintenance_manager.cc:643] P 87eb638e65b24b22a36d13a4e52c50ef: MajorDeltaCompactionOp(e584ae22fe034071a40543c9556cc34c) complete. Timing: real 0.203s	user 0.103s	sys 0.087s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24815683,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":936,"lbm_read_time_us":13470,"lbm_reads_lt_1ms":572,"lbm_write_time_us":31821,"lbm_writes_lt_1ms":543,"mutex_wait_us":255,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":9984,"update_count":2500}
I20260812 06:19:55.154935  7041 maintenance_manager.cc:419] P 87eb638e65b24b22a36d13a4e52c50ef: Scheduling FlushDeltaMemStoresOp(e584ae22fe034071a40543c9556cc34c): perf score=14.095187
I20260812 06:19:55.204911  6969 maintenance_manager.cc:643] P 87eb638e65b24b22a36d13a4e52c50ef: FlushDeltaMemStoresOp(e584ae22fe034071a40543c9556cc34c) complete. Timing: real 0.050s	user 0.029s	sys 0.019s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":22284,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:55.205387  7041 maintenance_manager.cc:419] P 87eb638e65b24b22a36d13a4e52c50ef: Scheduling FlushDeltaMemStoresOp(e584ae22fe034071a40543c9556cc34c): perf score=2.188937
I20260812 06:19:55.218309  6969 maintenance_manager.cc:643] P 87eb638e65b24b22a36d13a4e52c50ef: FlushDeltaMemStoresOp(e584ae22fe034071a40543c9556cc34c) complete. Timing: real 0.013s	user 0.003s	sys 0.007s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4564,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:55.218828  7041 maintenance_manager.cc:419] P 87eb638e65b24b22a36d13a4e52c50ef: Scheduling MajorDeltaCompactionOp(e584ae22fe034071a40543c9556cc34c): perf score=1.000000
I20260812 06:19:55.421090  6969 maintenance_manager.cc:643] P 87eb638e65b24b22a36d13a4e52c50ef: MajorDeltaCompactionOp(e584ae22fe034071a40543c9556cc34c) complete. Timing: real 0.202s	user 0.139s	sys 0.053s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24815683,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":567,"dirs.run_cpu_time_us":680,"dirs.run_wall_time_us":2878,"lbm_read_time_us":11372,"lbm_reads_lt_1ms":572,"lbm_write_time_us":29742,"lbm_writes_lt_1ms":543,"mutex_wait_us":65,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":768,"update_count":2500}
I20260812 06:19:55.421792  7041 maintenance_manager.cc:419] P 87eb638e65b24b22a36d13a4e52c50ef: Scheduling FlushDeltaMemStoresOp(e584ae22fe034071a40543c9556cc34c): perf score=14.095187
I20260812 06:19:55.474092  6969 maintenance_manager.cc:643] P 87eb638e65b24b22a36d13a4e52c50ef: FlushDeltaMemStoresOp(e584ae22fe034071a40543c9556cc34c) complete. Timing: real 0.052s	user 0.026s	sys 0.023s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":23428,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:55.474609  7041 maintenance_manager.cc:419] P 87eb638e65b24b22a36d13a4e52c50ef: Scheduling FlushDeltaMemStoresOp(e584ae22fe034071a40543c9556cc34c): perf score=2.188937
I20260812 06:19:55.484663  6969 maintenance_manager.cc:643] P 87eb638e65b24b22a36d13a4e52c50ef: FlushDeltaMemStoresOp(e584ae22fe034071a40543c9556cc34c) complete. Timing: real 0.010s	user 0.008s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3875,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:55.485229  7041 maintenance_manager.cc:419] P 87eb638e65b24b22a36d13a4e52c50ef: Scheduling FlushMRSOp(e584ae22fe034071a40543c9556cc34c): perf score=1.000000
I20260812 06:19:55.516857  6969 maintenance_manager.cc:643] P 87eb638e65b24b22a36d13a4e52c50ef: FlushMRSOp(e584ae22fe034071a40543c9556cc34c) complete. Timing: real 0.031s	user 0.023s	sys 0.007s Metrics: {"bytes_written":1193503,"cfile_init":1,"dirs.queue_time_us":479,"dirs.run_cpu_time_us":207,"dirs.run_wall_time_us":1347,"drs_written":1,"lbm_read_time_us":39,"lbm_reads_lt_1ms":4,"lbm_write_time_us":2219,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":29}
I20260812 06:19:55.517495  7041 maintenance_manager.cc:419] P 87eb638e65b24b22a36d13a4e52c50ef: Scheduling LogGCOp(e584ae22fe034071a40543c9556cc34c): free 124257235 bytes of WAL
I20260812 06:19:55.517712  6969 log_reader.cc:385] T e584ae22fe034071a40543c9556cc34c: removed 12 log segments from log reader
I20260812 06:19:55.517773  6969 log.cc:1079] T e584ae22fe034071a40543c9556cc34c P 87eb638e65b24b22a36d13a4e52c50ef: Deleting log segment in path: /tmp/dist-test-taskTJlGYB/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515588352133-6621-0/minicluster-data/ts-0-root/wals/e584ae22fe034071a40543c9556cc34c/wal-000000003 (ops 12-16)
I20260812 06:19:55.517827  6969 log.cc:1079] T e584ae22fe034071a40543c9556cc34c P 87eb638e65b24b22a36d13a4e52c50ef: Deleting log segment in path: /tmp/dist-test-taskTJlGYB/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515588352133-6621-0/minicluster-data/ts-0-root/wals/e584ae22fe034071a40543c9556cc34c/wal-000000004 (ops 17-21)
I20260812 06:19:55.517884  6969 log.cc:1079] T e584ae22fe034071a40543c9556cc34c P 87eb638e65b24b22a36d13a4e52c50ef: Deleting log segment in path: /tmp/dist-test-taskTJlGYB/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515588352133-6621-0/minicluster-data/ts-0-root/wals/e584ae22fe034071a40543c9556cc34c/wal-000000005 (ops 22-26)
I20260812 06:19:55.517925  6969 log.cc:1079] T e584ae22fe034071a40543c9556cc34c P 87eb638e65b24b22a36d13a4e52c50ef: Deleting log segment in path: /tmp/dist-test-taskTJlGYB/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515588352133-6621-0/minicluster-data/ts-0-root/wals/e584ae22fe034071a40543c9556cc34c/wal-000000006 (ops 27-31)
I20260812 06:19:55.517961  6969 log.cc:1079] T e584ae22fe034071a40543c9556cc34c P 87eb638e65b24b22a36d13a4e52c50ef: Deleting log segment in path: /tmp/dist-test-taskTJlGYB/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515588352133-6621-0/minicluster-data/ts-0-root/wals/e584ae22fe034071a40543c9556cc34c/wal-000000007 (ops 32-36)
I20260812 06:19:55.517997  6969 log.cc:1079] T e584ae22fe034071a40543c9556cc34c P 87eb638e65b24b22a36d13a4e52c50ef: Deleting log segment in path: /tmp/dist-test-taskTJlGYB/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515588352133-6621-0/minicluster-data/ts-0-root/wals/e584ae22fe034071a40543c9556cc34c/wal-000000008 (ops 37-40)
I20260812 06:19:55.518041  6969 log.cc:1079] T e584ae22fe034071a40543c9556cc34c P 87eb638e65b24b22a36d13a4e52c50ef: Deleting log segment in path: /tmp/dist-test-taskTJlGYB/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515588352133-6621-0/minicluster-data/ts-0-root/wals/e584ae22fe034071a40543c9556cc34c/wal-000000009 (ops 41-45)
I20260812 06:19:55.518079  6969 log.cc:1079] T e584ae22fe034071a40543c9556cc34c P 87eb638e65b24b22a36d13a4e52c50ef: Deleting log segment in path: /tmp/dist-test-taskTJlGYB/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515588352133-6621-0/minicluster-data/ts-0-root/wals/e584ae22fe034071a40543c9556cc34c/wal-000000010 (ops 46-50)
I20260812 06:19:55.518115  6969 log.cc:1079] T e584ae22fe034071a40543c9556cc34c P 87eb638e65b24b22a36d13a4e52c50ef: Deleting log segment in path: /tmp/dist-test-taskTJlGYB/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515588352133-6621-0/minicluster-data/ts-0-root/wals/e584ae22fe034071a40543c9556cc34c/wal-000000011 (ops 51-55)
I20260812 06:19:55.518151  6969 log.cc:1079] T e584ae22fe034071a40543c9556cc34c P 87eb638e65b24b22a36d13a4e52c50ef: Deleting log segment in path: /tmp/dist-test-taskTJlGYB/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515588352133-6621-0/minicluster-data/ts-0-root/wals/e584ae22fe034071a40543c9556cc34c/wal-000000012 (ops 56-60)
I20260812 06:19:55.518189  6969 log.cc:1079] T e584ae22fe034071a40543c9556cc34c P 87eb638e65b24b22a36d13a4e52c50ef: Deleting log segment in path: /tmp/dist-test-taskTJlGYB/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515588352133-6621-0/minicluster-data/ts-0-root/wals/e584ae22fe034071a40543c9556cc34c/wal-000000013 (ops 61-65)
I20260812 06:19:55.518227  6969 log.cc:1079] T e584ae22fe034071a40543c9556cc34c P 87eb638e65b24b22a36d13a4e52c50ef: Deleting log segment in path: /tmp/dist-test-taskTJlGYB/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515588352133-6621-0/minicluster-data/ts-0-root/wals/e584ae22fe034071a40543c9556cc34c/wal-000000014 (ops 66-70)
I20260812 06:19:55.543633  6969 maintenance_manager.cc:643] P 87eb638e65b24b22a36d13a4e52c50ef: LogGCOp(e584ae22fe034071a40543c9556cc34c) complete. Timing: real 0.026s	user 0.000s	sys 0.025s Metrics: {}
I20260812 06:19:55.546285  7041 maintenance_manager.cc:419] P 87eb638e65b24b22a36d13a4e52c50ef: Scheduling UndoDeltaBlockGCOp(e584ae22fe034071a40543c9556cc34c): 463 bytes on disk
I20260812 06:19:55.546834  6969 maintenance_manager.cc:643] P 87eb638e65b24b22a36d13a4e52c50ef: UndoDeltaBlockGCOp(e584ae22fe034071a40543c9556cc34c) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":67,"lbm_reads_lt_1ms":4}
I20260812 06:19:55.547435  7041 maintenance_manager.cc:419] P 87eb638e65b24b22a36d13a4e52c50ef: Scheduling FlushDeltaMemStoresOp(e584ae22fe034071a40543c9556cc34c): perf score=2.188937
I20260812 06:19:55.569669  6969 maintenance_manager.cc:643] P 87eb638e65b24b22a36d13a4e52c50ef: FlushDeltaMemStoresOp(e584ae22fe034071a40543c9556cc34c) complete. Timing: real 0.022s	user 0.006s	sys 0.009s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6518,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:55.570113  7041 maintenance_manager.cc:419] P 87eb638e65b24b22a36d13a4e52c50ef: Scheduling FlushDeltaMemStoresOp(e584ae22fe034071a40543c9556cc34c): perf score=2.188937
I20260812 06:19:55.580235  6969 maintenance_manager.cc:643] P 87eb638e65b24b22a36d13a4e52c50ef: FlushDeltaMemStoresOp(e584ae22fe034071a40543c9556cc34c) complete. Timing: real 0.010s	user 0.008s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3909,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:55.580603  7041 maintenance_manager.cc:419] P 87eb638e65b24b22a36d13a4e52c50ef: Scheduling MajorDeltaCompactionOp(e584ae22fe034071a40543c9556cc34c): perf score=1.000000
I20260812 06:19:55.810679  6969 maintenance_manager.cc:643] P 87eb638e65b24b22a36d13a4e52c50ef: MajorDeltaCompactionOp(e584ae22fe034071a40543c9556cc34c) complete. Timing: real 0.230s	user 0.176s	sys 0.050s Metrics: {"cfile_cache_miss":734,"cfile_cache_miss_bytes":33020745,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":507,"lbm_read_time_us":15291,"lbm_reads_lt_1ms":774,"lbm_write_time_us":36228,"lbm_writes_lt_1ms":743,"mutex_wait_us":60,"peak_mem_usage":87969044,"reinsert_count":0,"spinlock_wait_cycles":15232,"thread_start_us":80,"threads_started":1,"update_count":3500}
I20260812 06:19:55.813688  7041 maintenance_manager.cc:419] P 87eb638e65b24b22a36d13a4e52c50ef: Scheduling FlushDeltaMemStoresOp(e584ae22fe034071a40543c9556cc34c): perf score=17.071750
I20260812 06:19:55.879776  6969 maintenance_manager.cc:643] P 87eb638e65b24b22a36d13a4e52c50ef: FlushDeltaMemStoresOp(e584ae22fe034071a40543c9556cc34c) complete. Timing: real 0.066s	user 0.026s	sys 0.023s Metrics: {"bytes_written":19281592,"delete_count":0,"lbm_write_time_us":22682,"lbm_writes_lt_1ms":473,"reinsert_count":0,"update_count":2350}
I20260812 06:19:55.880277  7041 maintenance_manager.cc:419] P 87eb638e65b24b22a36d13a4e52c50ef: Scheduling FlushDeltaMemStoresOp(e584ae22fe034071a40543c9556cc34c): perf score=4.173312
I20260812 06:19:55.900017  6969 maintenance_manager.cc:643] P 87eb638e65b24b22a36d13a4e52c50ef: FlushDeltaMemStoresOp(e584ae22fe034071a40543c9556cc34c) complete. Timing: real 0.020s	user 0.010s	sys 0.008s Metrics: {"bytes_written":5333390,"delete_count":0,"lbm_write_time_us":7900,"lbm_writes_lt_1ms":133,"reinsert_count":0,"update_count":650}
I20260812 06:19:55.900590  7041 maintenance_manager.cc:419] P 87eb638e65b24b22a36d13a4e52c50ef: Scheduling MajorDeltaCompactionOp(e584ae22fe034071a40543c9556cc34c): perf score=1.000000
I20260812 06:19:56.113878  6969 maintenance_manager.cc:643] P 87eb638e65b24b22a36d13a4e52c50ef: MajorDeltaCompactionOp(e584ae22fe034071a40543c9556cc34c) complete. Timing: real 0.213s	user 0.105s	sys 0.094s Metrics: {"cfile_cache_miss":632,"cfile_cache_miss_bytes":28918099,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":235,"lbm_read_time_us":13773,"lbm_reads_lt_1ms":672,"lbm_write_time_us":32539,"lbm_writes_lt_1ms":643,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":21376,"update_count":3000}
I20260812 06:19:56.114697  7041 maintenance_manager.cc:419] P 87eb638e65b24b22a36d13a4e52c50ef: Scheduling FlushDeltaMemStoresOp(e584ae22fe034071a40543c9556cc34c): perf score=18.063937
I20260812 06:19:56.182504  6969 maintenance_manager.cc:643] P 87eb638e65b24b22a36d13a4e52c50ef: FlushDeltaMemStoresOp(e584ae22fe034071a40543c9556cc34c) complete. Timing: real 0.068s	user 0.025s	sys 0.033s Metrics: {"bytes_written":20512315,"delete_count":0,"lbm_write_time_us":26505,"lbm_writes_lt_1ms":503,"reinsert_count":0,"update_count":2500}
I20260812 06:19:56.182932  7041 maintenance_manager.cc:419] P 87eb638e65b24b22a36d13a4e52c50ef: Scheduling FlushDeltaMemStoresOp(e584ae22fe034071a40543c9556cc34c): perf score=2.188937
I20260812 06:19:56.194957  6969 maintenance_manager.cc:643] P 87eb638e65b24b22a36d13a4e52c50ef: FlushDeltaMemStoresOp(e584ae22fe034071a40543c9556cc34c) complete. Timing: real 0.012s	user 0.004s	sys 0.007s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4271,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:56.195626  7041 maintenance_manager.cc:419] P 87eb638e65b24b22a36d13a4e52c50ef: Scheduling MajorDeltaCompactionOp(e584ae22fe034071a40543c9556cc34c): perf score=1.000000
I20260812 06:19:56.404006  6969 maintenance_manager.cc:643] P 87eb638e65b24b22a36d13a4e52c50ef: MajorDeltaCompactionOp(e584ae22fe034071a40543c9556cc34c) complete. Timing: real 0.208s	user 0.128s	sys 0.080s Metrics: {"cfile_cache_miss":632,"cfile_cache_miss_bytes":28918097,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":939,"lbm_read_time_us":15146,"lbm_reads_lt_1ms":672,"lbm_write_time_us":33178,"lbm_writes_lt_1ms":643,"mutex_wait_us":476,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":4480,"update_count":3000}
I20260812 06:19:56.404754  7041 maintenance_manager.cc:419] P 87eb638e65b24b22a36d13a4e52c50ef: Scheduling FlushDeltaMemStoresOp(e584ae22fe034071a40543c9556cc34c): perf score=14.095187
I20260812 06:19:56.453454  6969 maintenance_manager.cc:643] P 87eb638e65b24b22a36d13a4e52c50ef: FlushDeltaMemStoresOp(e584ae22fe034071a40543c9556cc34c) complete. Timing: real 0.049s	user 0.033s	sys 0.012s Metrics: {"bytes_written":16409905,"delete_count":0,"lbm_write_time_us":21359,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:56.453958  7041 maintenance_manager.cc:419] P 87eb638e65b24b22a36d13a4e52c50ef: Scheduling FlushDeltaMemStoresOp(e584ae22fe034071a40543c9556cc34c): perf score=2.188937
I20260812 06:19:56.468920  6969 maintenance_manager.cc:643] P 87eb638e65b24b22a36d13a4e52c50ef: FlushDeltaMemStoresOp(e584ae22fe034071a40543c9556cc34c) complete. Timing: real 0.015s	user 0.010s	sys 0.003s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6004,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:56.469375  7041 maintenance_manager.cc:419] P 87eb638e65b24b22a36d13a4e52c50ef: Scheduling MajorDeltaCompactionOp(e584ae22fe034071a40543c9556cc34c): perf score=1.000000
I20260812 06:19:56.644945  6969 maintenance_manager.cc:643] P 87eb638e65b24b22a36d13a4e52c50ef: MajorDeltaCompactionOp(e584ae22fe034071a40543c9556cc34c) complete. Timing: real 0.175s	user 0.098s	sys 0.075s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24815687,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":173,"lbm_read_time_us":12347,"lbm_reads_lt_1ms":572,"lbm_write_time_us":29991,"lbm_writes_lt_1ms":543,"mutex_wait_us":1,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":2944,"update_count":2500}
I20260812 06:19:56.645635  7041 maintenance_manager.cc:419] P 87eb638e65b24b22a36d13a4e52c50ef: Scheduling FlushDeltaMemStoresOp(e584ae22fe034071a40543c9556cc34c): perf score=14.095187
I20260812 06:19:56.696291  6969 maintenance_manager.cc:643] P 87eb638e65b24b22a36d13a4e52c50ef: FlushDeltaMemStoresOp(e584ae22fe034071a40543c9556cc34c) complete. Timing: real 0.050s	user 0.033s	sys 0.015s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":22019,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:56.696812  7041 maintenance_manager.cc:419] P 87eb638e65b24b22a36d13a4e52c50ef: Scheduling FlushDeltaMemStoresOp(e584ae22fe034071a40543c9556cc34c): perf score=2.188937
I20260812 06:19:56.714026  6969 maintenance_manager.cc:643] P 87eb638e65b24b22a36d13a4e52c50ef: FlushDeltaMemStoresOp(e584ae22fe034071a40543c9556cc34c) complete. Timing: real 0.017s	user 0.007s	sys 0.007s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6705,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:56.714665  7041 maintenance_manager.cc:419] P 87eb638e65b24b22a36d13a4e52c50ef: Scheduling MajorDeltaCompactionOp(e584ae22fe034071a40543c9556cc34c): perf score=1.000000
I20260812 06:19:56.884315  6969 maintenance_manager.cc:643] P 87eb638e65b24b22a36d13a4e52c50ef: MajorDeltaCompactionOp(e584ae22fe034071a40543c9556cc34c) complete. Timing: real 0.169s	user 0.116s	sys 0.053s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24815684,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":273,"lbm_read_time_us":11665,"lbm_reads_lt_1ms":572,"lbm_write_time_us":28934,"lbm_writes_lt_1ms":543,"mutex_wait_us":66,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":7808,"update_count":2500}
I20260812 06:19:56.884946  7041 maintenance_manager.cc:419] P 87eb638e65b24b22a36d13a4e52c50ef: Scheduling FlushDeltaMemStoresOp(e584ae22fe034071a40543c9556cc34c): perf score=14.095187
I20260812 06:19:56.941958  6969 maintenance_manager.cc:643] P 87eb638e65b24b22a36d13a4e52c50ef: FlushDeltaMemStoresOp(e584ae22fe034071a40543c9556cc34c) complete. Timing: real 0.057s	user 0.027s	sys 0.026s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":20303,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:56.942646  7041 maintenance_manager.cc:419] P 87eb638e65b24b22a36d13a4e52c50ef: Scheduling FlushDeltaMemStoresOp(e584ae22fe034071a40543c9556cc34c): perf score=2.188937
I20260812 06:19:56.959781  6969 maintenance_manager.cc:643] P 87eb638e65b24b22a36d13a4e52c50ef: FlushDeltaMemStoresOp(e584ae22fe034071a40543c9556cc34c) complete. Timing: real 0.017s	user 0.011s	sys 0.005s 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:19:56.960333  7041 maintenance_manager.cc:419] P 87eb638e65b24b22a36d13a4e52c50ef: Scheduling FlushMRSOp(e584ae22fe034071a40543c9556cc34c): perf score=1.000000
I20260812 06:19:57.001380  6969 maintenance_manager.cc:643] P 87eb638e65b24b22a36d13a4e52c50ef: FlushMRSOp(e584ae22fe034071a40543c9556cc34c) complete. Timing: real 0.041s	user 0.025s	sys 0.004s Metrics: {"bytes_written":1193509,"cfile_init":1,"dirs.queue_time_us":61,"dirs.run_cpu_time_us":226,"dirs.run_wall_time_us":1341,"drs_written":1,"lbm_read_time_us":36,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1540,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":29}
I20260812 06:19:57.002063  7041 maintenance_manager.cc:419] P 87eb638e65b24b22a36d13a4e52c50ef: Scheduling LogGCOp(e584ae22fe034071a40543c9556cc34c): free 121006391 bytes of WAL
I20260812 06:19:57.002291  6969 log_reader.cc:385] T e584ae22fe034071a40543c9556cc34c: removed 12 log segments from log reader
I20260812 06:19:57.002358  6969 log.cc:1079] T e584ae22fe034071a40543c9556cc34c P 87eb638e65b24b22a36d13a4e52c50ef: Deleting log segment in path: /tmp/dist-test-taskTJlGYB/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515588352133-6621-0/minicluster-data/ts-0-root/wals/e584ae22fe034071a40543c9556cc34c/wal-000000015 (ops 71-75)
I20260812 06:19:57.002445  6969 log.cc:1079] T e584ae22fe034071a40543c9556cc34c P 87eb638e65b24b22a36d13a4e52c50ef: Deleting log segment in path: /tmp/dist-test-taskTJlGYB/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515588352133-6621-0/minicluster-data/ts-0-root/wals/e584ae22fe034071a40543c9556cc34c/wal-000000016 (ops 76-80)
I20260812 06:19:57.002506  6969 log.cc:1079] T e584ae22fe034071a40543c9556cc34c P 87eb638e65b24b22a36d13a4e52c50ef: Deleting log segment in path: /tmp/dist-test-taskTJlGYB/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515588352133-6621-0/minicluster-data/ts-0-root/wals/e584ae22fe034071a40543c9556cc34c/wal-000000017 (ops 81-85)
I20260812 06:19:57.002547  6969 log.cc:1079] T e584ae22fe034071a40543c9556cc34c P 87eb638e65b24b22a36d13a4e52c50ef: Deleting log segment in path: /tmp/dist-test-taskTJlGYB/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515588352133-6621-0/minicluster-data/ts-0-root/wals/e584ae22fe034071a40543c9556cc34c/wal-000000018 (ops 86-90)
I20260812 06:19:57.002584  6969 log.cc:1079] T e584ae22fe034071a40543c9556cc34c P 87eb638e65b24b22a36d13a4e52c50ef: Deleting log segment in path: /tmp/dist-test-taskTJlGYB/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515588352133-6621-0/minicluster-data/ts-0-root/wals/e584ae22fe034071a40543c9556cc34c/wal-000000019 (ops 91-95)
I20260812 06:19:57.002619  6969 log.cc:1079] T e584ae22fe034071a40543c9556cc34c P 87eb638e65b24b22a36d13a4e52c50ef: Deleting log segment in path: /tmp/dist-test-taskTJlGYB/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515588352133-6621-0/minicluster-data/ts-0-root/wals/e584ae22fe034071a40543c9556cc34c/wal-000000020 (ops 96-100)
I20260812 06:19:57.002655  6969 log.cc:1079] T e584ae22fe034071a40543c9556cc34c P 87eb638e65b24b22a36d13a4e52c50ef: Deleting log segment in path: /tmp/dist-test-taskTJlGYB/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515588352133-6621-0/minicluster-data/ts-0-root/wals/e584ae22fe034071a40543c9556cc34c/wal-000000021 (ops 101-104)
I20260812 06:19:57.002692  6969 log.cc:1079] T e584ae22fe034071a40543c9556cc34c P 87eb638e65b24b22a36d13a4e52c50ef: Deleting log segment in path: /tmp/dist-test-taskTJlGYB/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515588352133-6621-0/minicluster-data/ts-0-root/wals/e584ae22fe034071a40543c9556cc34c/wal-000000022 (ops 105-109)
I20260812 06:19:57.002729  6969 log.cc:1079] T e584ae22fe034071a40543c9556cc34c P 87eb638e65b24b22a36d13a4e52c50ef: Deleting log segment in path: /tmp/dist-test-taskTJlGYB/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515588352133-6621-0/minicluster-data/ts-0-root/wals/e584ae22fe034071a40543c9556cc34c/wal-000000023 (ops 110-114)
I20260812 06:19:57.002765  6969 log.cc:1079] T e584ae22fe034071a40543c9556cc34c P 87eb638e65b24b22a36d13a4e52c50ef: Deleting log segment in path: /tmp/dist-test-taskTJlGYB/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515588352133-6621-0/minicluster-data/ts-0-root/wals/e584ae22fe034071a40543c9556cc34c/wal-000000024 (ops 115-119)
I20260812 06:19:57.002802  6969 log.cc:1079] T e584ae22fe034071a40543c9556cc34c P 87eb638e65b24b22a36d13a4e52c50ef: Deleting log segment in path: /tmp/dist-test-taskTJlGYB/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515588352133-6621-0/minicluster-data/ts-0-root/wals/e584ae22fe034071a40543c9556cc34c/wal-000000025 (ops 120-124)
I20260812 06:19:57.002840  6969 log.cc:1079] T e584ae22fe034071a40543c9556cc34c P 87eb638e65b24b22a36d13a4e52c50ef: Deleting log segment in path: /tmp/dist-test-taskTJlGYB/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515588352133-6621-0/minicluster-data/ts-0-root/wals/e584ae22fe034071a40543c9556cc34c/wal-000000026 (ops 125-129)
I20260812 06:19:57.026918  6969 maintenance_manager.cc:643] P 87eb638e65b24b22a36d13a4e52c50ef: LogGCOp(e584ae22fe034071a40543c9556cc34c) complete. Timing: real 0.025s	user 0.002s	sys 0.023s Metrics: {}
I20260812 06:19:57.027298  7041 maintenance_manager.cc:419] P 87eb638e65b24b22a36d13a4e52c50ef: Scheduling FlushDeltaMemStoresOp(e584ae22fe034071a40543c9556cc34c): perf score=2.188937
I20260812 06:19:57.046270  6969 maintenance_manager.cc:643] P 87eb638e65b24b22a36d13a4e52c50ef: FlushDeltaMemStoresOp(e584ae22fe034071a40543c9556cc34c) complete. Timing: real 0.019s	user 0.005s	sys 0.005s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4343,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:57.046770  7041 maintenance_manager.cc:419] P 87eb638e65b24b22a36d13a4e52c50ef: Scheduling UndoDeltaBlockGCOp(e584ae22fe034071a40543c9556cc34c): 462 bytes on disk
I20260812 06:19:57.047181  6969 maintenance_manager.cc:643] P 87eb638e65b24b22a36d13a4e52c50ef: UndoDeltaBlockGCOp(e584ae22fe034071a40543c9556cc34c) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":50,"lbm_reads_lt_1ms":4}
I20260812 06:19:57.047646  7041 maintenance_manager.cc:419] P 87eb638e65b24b22a36d13a4e52c50ef: Scheduling FlushDeltaMemStoresOp(e584ae22fe034071a40543c9556cc34c): perf score=2.188937
I20260812 06:19:57.057781  6969 maintenance_manager.cc:643] P 87eb638e65b24b22a36d13a4e52c50ef: FlushDeltaMemStoresOp(e584ae22fe034071a40543c9556cc34c) complete. Timing: real 0.010s	user 0.005s	sys 0.004s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":3903,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:57.058346  7041 maintenance_manager.cc:419] P 87eb638e65b24b22a36d13a4e52c50ef: Scheduling MajorDeltaCompactionOp(e584ae22fe034071a40543c9556cc34c): perf score=1.000000
I20260812 06:19:57.277741  6969 maintenance_manager.cc:643] P 87eb638e65b24b22a36d13a4e52c50ef: MajorDeltaCompactionOp(e584ae22fe034071a40543c9556cc34c) complete. Timing: real 0.219s	user 0.176s	sys 0.040s Metrics: {"cfile_cache_miss":734,"cfile_cache_miss_bytes":33020744,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":520,"lbm_read_time_us":15492,"lbm_reads_lt_1ms":774,"lbm_write_time_us":38394,"lbm_writes_lt_1ms":743,"mutex_wait_us":61,"peak_mem_usage":87969044,"reinsert_count":0,"spinlock_wait_cycles":8704,"thread_start_us":133,"threads_started":1,"update_count":3500}
I20260812 06:19:57.278492  7041 maintenance_manager.cc:419] P 87eb638e65b24b22a36d13a4e52c50ef: Scheduling FlushDeltaMemStoresOp(e584ae22fe034071a40543c9556cc34c): perf score=14.095187
I20260812 06:19:57.338191  6969 maintenance_manager.cc:643] P 87eb638e65b24b22a36d13a4e52c50ef: FlushDeltaMemStoresOp(e584ae22fe034071a40543c9556cc34c) complete. Timing: real 0.059s	user 0.033s	sys 0.016s Metrics: {"bytes_written":16409899,"delete_count":0,"lbm_write_time_us":23461,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:57.338665  7041 maintenance_manager.cc:419] P 87eb638e65b24b22a36d13a4e52c50ef: Scheduling FlushDeltaMemStoresOp(e584ae22fe034071a40543c9556cc34c): perf score=3.181125
I20260812 06:19:57.350750  6969 maintenance_manager.cc:643] P 87eb638e65b24b22a36d13a4e52c50ef: FlushDeltaMemStoresOp(e584ae22fe034071a40543c9556cc34c) complete. Timing: real 0.012s	user 0.007s	sys 0.004s Metrics: {"bytes_written":4512901,"delete_count":0,"lbm_write_time_us":4261,"lbm_writes_lt_1ms":113,"reinsert_count":0,"update_count":550}
I20260812 06:19:57.351159  7041 maintenance_manager.cc:419] P 87eb638e65b24b22a36d13a4e52c50ef: Scheduling FlushDeltaMemStoresOp(e584ae22fe034071a40543c9556cc34c): perf score=2.188937
I20260812 06:19:57.360379  6969 maintenance_manager.cc:643] P 87eb638e65b24b22a36d13a4e52c50ef: FlushDeltaMemStoresOp(e584ae22fe034071a40543c9556cc34c) complete. Timing: real 0.009s	user 0.008s	sys 0.000s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3452,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:19:57.360788  7041 maintenance_manager.cc:419] P 87eb638e65b24b22a36d13a4e52c50ef: Scheduling MajorDeltaCompactionOp(e584ae22fe034071a40543c9556cc34c): perf score=1.000000
I20260812 06:19:57.560300  6969 maintenance_manager.cc:643] P 87eb638e65b24b22a36d13a4e52c50ef: MajorDeltaCompactionOp(e584ae22fe034071a40543c9556cc34c) complete. Timing: real 0.199s	user 0.121s	sys 0.078s Metrics: {"cfile_cache_miss":633,"cfile_cache_miss_bytes":28918200,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":907,"lbm_read_time_us":13395,"lbm_reads_lt_1ms":673,"lbm_write_time_us":36414,"lbm_writes_lt_1ms":643,"mutex_wait_us":43,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":9600,"update_count":3000}
I20260812 06:19:57.561033  7041 maintenance_manager.cc:419] P 87eb638e65b24b22a36d13a4e52c50ef: Scheduling FlushDeltaMemStoresOp(e584ae22fe034071a40543c9556cc34c): perf score=14.095187
I20260812 06:19:57.604205  6969 maintenance_manager.cc:643] P 87eb638e65b24b22a36d13a4e52c50ef: FlushDeltaMemStoresOp(e584ae22fe034071a40543c9556cc34c) complete. Timing: real 0.043s	user 0.020s	sys 0.021s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":19355,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:57.604663  7041 maintenance_manager.cc:419] P 87eb638e65b24b22a36d13a4e52c50ef: Scheduling FlushDeltaMemStoresOp(e584ae22fe034071a40543c9556cc34c): perf score=2.188937
I20260812 06:19:57.621021  6969 maintenance_manager.cc:643] P 87eb638e65b24b22a36d13a4e52c50ef: FlushDeltaMemStoresOp(e584ae22fe034071a40543c9556cc34c) complete. Timing: real 0.016s	user 0.007s	sys 0.007s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6207,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:57.621493  7041 maintenance_manager.cc:419] P 87eb638e65b24b22a36d13a4e52c50ef: Scheduling MajorDeltaCompactionOp(e584ae22fe034071a40543c9556cc34c): perf score=1.000000
I20260812 06:19:57.775364  6969 maintenance_manager.cc:643] P 87eb638e65b24b22a36d13a4e52c50ef: MajorDeltaCompactionOp(e584ae22fe034071a40543c9556cc34c) complete. Timing: real 0.154s	user 0.111s	sys 0.035s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24815684,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":227,"lbm_read_time_us":10323,"lbm_reads_lt_1ms":564,"lbm_write_time_us":27199,"lbm_writes_lt_1ms":543,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":2048,"update_count":2500}
I20260812 06:19:57.776059  7041 maintenance_manager.cc:419] P 87eb638e65b24b22a36d13a4e52c50ef: Scheduling FlushDeltaMemStoresOp(e584ae22fe034071a40543c9556cc34c): perf score=14.095187
I20260812 06:19:57.841029  6969 maintenance_manager.cc:643] P 87eb638e65b24b22a36d13a4e52c50ef: FlushDeltaMemStoresOp(e584ae22fe034071a40543c9556cc34c) complete. Timing: real 0.065s	user 0.028s	sys 0.020s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":23101,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":402,"reinsert_count":0,"update_count":2000}
I20260812 06:19:57.841508  7041 maintenance_manager.cc:419] P 87eb638e65b24b22a36d13a4e52c50ef: Scheduling FlushDeltaMemStoresOp(e584ae22fe034071a40543c9556cc34c): perf score=2.188937
I20260812 06:19:57.851825  6969 maintenance_manager.cc:643] P 87eb638e65b24b22a36d13a4e52c50ef: FlushDeltaMemStoresOp(e584ae22fe034071a40543c9556cc34c) complete. Timing: real 0.010s	user 0.005s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3975,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:57.852344  7041 maintenance_manager.cc:419] P 87eb638e65b24b22a36d13a4e52c50ef: Scheduling MajorDeltaCompactionOp(e584ae22fe034071a40543c9556cc34c): perf score=1.000000
I20260812 06:19:58.022984  6969 maintenance_manager.cc:643] P 87eb638e65b24b22a36d13a4e52c50ef: MajorDeltaCompactionOp(e584ae22fe034071a40543c9556cc34c) complete. Timing: real 0.170s	user 0.095s	sys 0.075s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24815684,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":193,"lbm_read_time_us":11738,"lbm_reads_lt_1ms":572,"lbm_write_time_us":29104,"lbm_writes_lt_1ms":543,"mutex_wait_us":11,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":2816,"update_count":2500}
I20260812 06:19:58.023692  7041 maintenance_manager.cc:419] P 87eb638e65b24b22a36d13a4e52c50ef: Scheduling FlushDeltaMemStoresOp(e584ae22fe034071a40543c9556cc34c): perf score=14.095187
I20260812 06:19:58.078593  6969 maintenance_manager.cc:643] P 87eb638e65b24b22a36d13a4e52c50ef: FlushDeltaMemStoresOp(e584ae22fe034071a40543c9556cc34c) complete. Timing: real 0.055s	user 0.030s	sys 0.022s Metrics: {"bytes_written":16409909,"delete_count":0,"lbm_write_time_us":19214,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:58.079118  7041 maintenance_manager.cc:419] P 87eb638e65b24b22a36d13a4e52c50ef: Scheduling FlushDeltaMemStoresOp(e584ae22fe034071a40543c9556cc34c): perf score=2.188937
I20260812 06:19:58.089880  6969 maintenance_manager.cc:643] P 87eb638e65b24b22a36d13a4e52c50ef: FlushDeltaMemStoresOp(e584ae22fe034071a40543c9556cc34c) complete. Timing: real 0.011s	user 0.001s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4292,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:58.090323  7041 maintenance_manager.cc:419] P 87eb638e65b24b22a36d13a4e52c50ef: Scheduling MajorDeltaCompactionOp(e584ae22fe034071a40543c9556cc34c): perf score=1.000000
I20260812 06:19:58.269479  6969 maintenance_manager.cc:643] P 87eb638e65b24b22a36d13a4e52c50ef: MajorDeltaCompactionOp(e584ae22fe034071a40543c9556cc34c) complete. Timing: real 0.179s	user 0.118s	sys 0.061s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24815691,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":683,"lbm_read_time_us":12920,"lbm_reads_lt_1ms":572,"lbm_write_time_us":29194,"lbm_writes_lt_1ms":543,"mutex_wait_us":309,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":13952,"update_count":2500}
I20260812 06:19:58.270169  7041 maintenance_manager.cc:419] P 87eb638e65b24b22a36d13a4e52c50ef: Scheduling FlushDeltaMemStoresOp(e584ae22fe034071a40543c9556cc34c): perf score=14.095187
I20260812 06:19:58.329744  6969 maintenance_manager.cc:643] P 87eb638e65b24b22a36d13a4e52c50ef: FlushDeltaMemStoresOp(e584ae22fe034071a40543c9556cc34c) complete. Timing: real 0.059s	user 0.026s	sys 0.028s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":21320,"lbm_writes_lt_1ms":403,"reinsert_count":0,"spinlock_wait_cycles":896,"update_count":2000}
I20260812 06:19:58.330312  7041 maintenance_manager.cc:419] P 87eb638e65b24b22a36d13a4e52c50ef: Scheduling FlushDeltaMemStoresOp(e584ae22fe034071a40543c9556cc34c): perf score=2.188937
I20260812 06:19:58.341073  6969 maintenance_manager.cc:643] P 87eb638e65b24b22a36d13a4e52c50ef: FlushDeltaMemStoresOp(e584ae22fe034071a40543c9556cc34c) complete. Timing: real 0.011s	user 0.001s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4293,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:58.341580  7041 maintenance_manager.cc:419] P 87eb638e65b24b22a36d13a4e52c50ef: Scheduling FlushMRSOp(e584ae22fe034071a40543c9556cc34c): perf score=1.000000
I20260812 06:19:58.386629  6969 maintenance_manager.cc:643] P 87eb638e65b24b22a36d13a4e52c50ef: FlushMRSOp(e584ae22fe034071a40543c9556cc34c) complete. Timing: real 0.045s	user 0.025s	sys 0.008s Metrics: {"bytes_written":1152510,"cfile_init":1,"dirs.queue_time_us":66,"dirs.run_cpu_time_us":242,"dirs.run_wall_time_us":1452,"drs_written":1,"lbm_read_time_us":63,"lbm_reads_lt_1ms":4,"lbm_write_time_us":2219,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":28}
I20260812 06:19:58.387269  7041 maintenance_manager.cc:419] P 87eb638e65b24b22a36d13a4e52c50ef: Scheduling LogGCOp(e584ae22fe034071a40543c9556cc34c): free 108535741 bytes of WAL
I20260812 06:19:58.387516  6969 log_reader.cc:385] T e584ae22fe034071a40543c9556cc34c: removed 11 log segments from log reader
I20260812 06:19:58.387559  6969 log.cc:1079] T e584ae22fe034071a40543c9556cc34c P 87eb638e65b24b22a36d13a4e52c50ef: Deleting log segment in path: /tmp/dist-test-taskTJlGYB/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515588352133-6621-0/minicluster-data/ts-0-root/wals/e584ae22fe034071a40543c9556cc34c/wal-000000027 (ops 130-134)
I20260812 06:19:58.387586  6969 log.cc:1079] T e584ae22fe034071a40543c9556cc34c P 87eb638e65b24b22a36d13a4e52c50ef: Deleting log segment in path: /tmp/dist-test-taskTJlGYB/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515588352133-6621-0/minicluster-data/ts-0-root/wals/e584ae22fe034071a40543c9556cc34c/wal-000000028 (ops 135-139)
I20260812 06:19:58.387651  6969 log.cc:1079] T e584ae22fe034071a40543c9556cc34c P 87eb638e65b24b22a36d13a4e52c50ef: Deleting log segment in path: /tmp/dist-test-taskTJlGYB/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515588352133-6621-0/minicluster-data/ts-0-root/wals/e584ae22fe034071a40543c9556cc34c/wal-000000029 (ops 140-144)
I20260812 06:19:58.387692  6969 log.cc:1079] T e584ae22fe034071a40543c9556cc34c P 87eb638e65b24b22a36d13a4e52c50ef: Deleting log segment in path: /tmp/dist-test-taskTJlGYB/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515588352133-6621-0/minicluster-data/ts-0-root/wals/e584ae22fe034071a40543c9556cc34c/wal-000000030 (ops 145-148)
I20260812 06:19:58.387748  6969 log.cc:1079] T e584ae22fe034071a40543c9556cc34c P 87eb638e65b24b22a36d13a4e52c50ef: Deleting log segment in path: /tmp/dist-test-taskTJlGYB/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515588352133-6621-0/minicluster-data/ts-0-root/wals/e584ae22fe034071a40543c9556cc34c/wal-000000031 (ops 149-153)
I20260812 06:19:58.387791  6969 log.cc:1079] T e584ae22fe034071a40543c9556cc34c P 87eb638e65b24b22a36d13a4e52c50ef: Deleting log segment in path: /tmp/dist-test-taskTJlGYB/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515588352133-6621-0/minicluster-data/ts-0-root/wals/e584ae22fe034071a40543c9556cc34c/wal-000000032 (ops 154-158)
I20260812 06:19:58.387832  6969 log.cc:1079] T e584ae22fe034071a40543c9556cc34c P 87eb638e65b24b22a36d13a4e52c50ef: Deleting log segment in path: /tmp/dist-test-taskTJlGYB/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515588352133-6621-0/minicluster-data/ts-0-root/wals/e584ae22fe034071a40543c9556cc34c/wal-000000033 (ops 159-163)
I20260812 06:19:58.387873  6969 log.cc:1079] T e584ae22fe034071a40543c9556cc34c P 87eb638e65b24b22a36d13a4e52c50ef: Deleting log segment in path: /tmp/dist-test-taskTJlGYB/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515588352133-6621-0/minicluster-data/ts-0-root/wals/e584ae22fe034071a40543c9556cc34c/wal-000000034 (ops 164-168)
I20260812 06:19:58.387912  6969 log.cc:1079] T e584ae22fe034071a40543c9556cc34c P 87eb638e65b24b22a36d13a4e52c50ef: Deleting log segment in path: /tmp/dist-test-taskTJlGYB/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515588352133-6621-0/minicluster-data/ts-0-root/wals/e584ae22fe034071a40543c9556cc34c/wal-000000035 (ops 169-172)
I20260812 06:19:58.387948  6969 log.cc:1079] T e584ae22fe034071a40543c9556cc34c P 87eb638e65b24b22a36d13a4e52c50ef: Deleting log segment in path: /tmp/dist-test-taskTJlGYB/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515588352133-6621-0/minicluster-data/ts-0-root/wals/e584ae22fe034071a40543c9556cc34c/wal-000000036 (ops 173-177)
I20260812 06:19:58.387986  6969 log.cc:1079] T e584ae22fe034071a40543c9556cc34c P 87eb638e65b24b22a36d13a4e52c50ef: Deleting log segment in path: /tmp/dist-test-taskTJlGYB/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515588352133-6621-0/minicluster-data/ts-0-root/wals/e584ae22fe034071a40543c9556cc34c/wal-000000037 (ops 178-182)
I20260812 06:19:58.412132  6969 maintenance_manager.cc:643] P 87eb638e65b24b22a36d13a4e52c50ef: LogGCOp(e584ae22fe034071a40543c9556cc34c) complete. Timing: real 0.025s	user 0.000s	sys 0.023s Metrics: {}
I20260812 06:19:58.412684  7041 maintenance_manager.cc:419] P 87eb638e65b24b22a36d13a4e52c50ef: Scheduling FlushDeltaMemStoresOp(e584ae22fe034071a40543c9556cc34c): perf score=2.188937
I20260812 06:19:58.429276  6969 maintenance_manager.cc:643] P 87eb638e65b24b22a36d13a4e52c50ef: FlushDeltaMemStoresOp(e584ae22fe034071a40543c9556cc34c) complete. Timing: real 0.016s	user 0.003s	sys 0.007s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4721,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:58.429721  7041 maintenance_manager.cc:419] P 87eb638e65b24b22a36d13a4e52c50ef: Scheduling FlushDeltaMemStoresOp(e584ae22fe034071a40543c9556cc34c): perf score=2.188937
I20260812 06:19:58.440232  6969 maintenance_manager.cc:643] P 87eb638e65b24b22a36d13a4e52c50ef: FlushDeltaMemStoresOp(e584ae22fe034071a40543c9556cc34c) complete. Timing: real 0.010s	user 0.002s	sys 0.007s 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:19:58.440649  7041 maintenance_manager.cc:419] P 87eb638e65b24b22a36d13a4e52c50ef: Scheduling MajorDeltaCompactionOp(e584ae22fe034071a40543c9556cc34c): perf score=1.000000
I20260812 06:19:58.667773  6969 maintenance_manager.cc:643] P 87eb638e65b24b22a36d13a4e52c50ef: MajorDeltaCompactionOp(e584ae22fe034071a40543c9556cc34c) complete. Timing: real 0.227s	user 0.144s	sys 0.081s Metrics: {"cfile_cache_miss":734,"cfile_cache_miss_bytes":33020746,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":514,"lbm_read_time_us":16352,"lbm_reads_lt_1ms":774,"lbm_write_time_us":39537,"lbm_writes_lt_1ms":743,"peak_mem_usage":87969044,"reinsert_count":0,"spinlock_wait_cycles":4992,"thread_start_us":85,"threads_started":1,"update_count":3500}
I20260812 06:19:58.668494  7041 maintenance_manager.cc:419] P 87eb638e65b24b22a36d13a4e52c50ef: Scheduling FlushDeltaMemStoresOp(e584ae22fe034071a40543c9556cc34c): perf score=15.087375
I20260812 06:19:58.725417  6969 maintenance_manager.cc:643] P 87eb638e65b24b22a36d13a4e52c50ef: FlushDeltaMemStoresOp(e584ae22fe034071a40543c9556cc34c) complete. Timing: real 0.057s	user 0.042s	sys 0.012s Metrics: {"bytes_written":16820143,"delete_count":0,"lbm_write_time_us":24893,"lbm_writes_lt_1ms":413,"reinsert_count":0,"update_count":2050}
I20260812 06:19:58.726199  7041 maintenance_manager.cc:419] P 87eb638e65b24b22a36d13a4e52c50ef: Scheduling UndoDeltaBlockGCOp(e584ae22fe034071a40543c9556cc34c): 446 bytes on disk
I20260812 06:19:58.726892  6969 maintenance_manager.cc:643] P 87eb638e65b24b22a36d13a4e52c50ef: UndoDeltaBlockGCOp(e584ae22fe034071a40543c9556cc34c) 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:19:58.727694  7041 maintenance_manager.cc:419] P 87eb638e65b24b22a36d13a4e52c50ef: Scheduling FlushDeltaMemStoresOp(e584ae22fe034071a40543c9556cc34c): perf score=2.188937
I20260812 06:19:58.752341  6969 maintenance_manager.cc:643] P 87eb638e65b24b22a36d13a4e52c50ef: FlushDeltaMemStoresOp(e584ae22fe034071a40543c9556cc34c) complete. Timing: real 0.024s	user 0.011s	sys 0.000s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":4902,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:19:58.752796  7041 maintenance_manager.cc:419] P 87eb638e65b24b22a36d13a4e52c50ef: Scheduling FlushDeltaMemStoresOp(e584ae22fe034071a40543c9556cc34c): perf score=2.188937
I20260812 06:19:58.762917  6969 maintenance_manager.cc:643] P 87eb638e65b24b22a36d13a4e52c50ef: FlushDeltaMemStoresOp(e584ae22fe034071a40543c9556cc34c) complete. Timing: real 0.010s	user 0.006s	sys 0.003s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3944,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:58.763316  7041 maintenance_manager.cc:419] P 87eb638e65b24b22a36d13a4e52c50ef: Scheduling MajorDeltaCompactionOp(e584ae22fe034071a40543c9556cc34c): perf score=1.000000
I20260812 06:19:58.794862  6621 heavy-update-compaction-itest.cc:229] Time spent updating: real 4.920s	user 1.824s	sys 0.183s
I20260812 06:19:58.868182  6621 heavy-update-compaction-itest.cc:265] Time spent scanning: real 0.073s	user 0.001s	sys 0.000s
I20260812 06:19:58.868729  6621 tablet_server.cc:179] TabletServer@127.6.119.65:0 shutting down...
I20260812 06:19:58.936691  6969 maintenance_manager.cc:643] P 87eb638e65b24b22a36d13a4e52c50ef: MajorDeltaCompactionOp(e584ae22fe034071a40543c9556cc34c) complete. Timing: real 0.173s	user 0.109s	sys 0.064s Metrics: {"cfile_cache_miss":633,"cfile_cache_miss_bytes":28918202,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":420,"lbm_read_time_us":13777,"lbm_reads_lt_1ms":669,"lbm_write_time_us":29516,"lbm_writes_lt_1ms":643,"mutex_wait_us":73,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":4864,"update_count":3000}
I20260812 06:19:58.937501  6621 ts_tablet_manager.cc:1507] Shutting down tablet manager...
I20260812 06:19:58.937801  6621 tablet_replica.cc:333] T e584ae22fe034071a40543c9556cc34c P 87eb638e65b24b22a36d13a4e52c50ef: stopping tablet replica
I20260812 06:19:58.937940  6621 raft_consensus.cc:2243] T e584ae22fe034071a40543c9556cc34c P 87eb638e65b24b22a36d13a4e52c50ef [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:19:58.938126  6621 raft_consensus.cc:2272] T e584ae22fe034071a40543c9556cc34c P 87eb638e65b24b22a36d13a4e52c50ef [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:19:58.953383  6621 tablet_server.cc:196] TabletServer@127.6.119.65:0 shutdown complete.
I20260812 06:19:58.990499  6621 master.cc:562] Master@127.6.119.126:37017 shutting down...
I20260812 06:19:58.994136  6621 raft_consensus.cc:2243] T 00000000000000000000000000000000 P 3ef297e27c7446c5bd72d26e7ac9840d [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:19:58.994331  6621 raft_consensus.cc:2272] T 00000000000000000000000000000000 P 3ef297e27c7446c5bd72d26e7ac9840d [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:19:58.994449  6621 tablet_replica.cc:333] T 00000000000000000000000000000000 P 3ef297e27c7446c5bd72d26e7ac9840d: stopping tablet replica
I20260812 06:19:59.006862  6621 master.cc:584] Master@127.6.119.126:37017 shutdown complete.
[       OK ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/1 (5415 ms)
[----------] 2 tests from EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy (10735 ms total)

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