[==========] Running 2 tests from 1 test suite.
[----------] Global test environment set-up.
[----------] 2 tests from EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy
[ RUN      ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/0
WARNING: Logging before InitGoogleLogging() is written to STDERR
I20260812 06:16:26.279074 14022 internal_mini_cluster.cc:156] Creating distributed mini masters. Addrs: 127.13.177.190:45661
I20260812 06:16:26.279997 14022 env_posix.cc:2285] Not raising this process' open files per process limit of 1048576; it is already as high as it can go
I20260812 06:16:26.280584 14022 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:16:26.286540 14045 instance_detector.cc:116] could not retrieve OpenStack instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:16:26.286540 14040 instance_detector.cc:116] could not retrieve AWS instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:16:26.286808 14042 instance_detector.cc:116] could not retrieve Azure instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:16:26.286942 14022 server_base.cc:1061] running on GCE node
I20260812 06:16:26.287338 14022 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:16:26.287449 14022 system_unsync_time.cc:38] NTP support is disabled. Clock error bounds will not be accurate. This configuration is not suitable for distributed clusters.
I20260812 06:16:26.287482 14022 hybrid_clock.cc:648] HybridClock initialized: now 1786515386287481 us; error 0 us; skew 500 ppm
I20260812 06:16:26.289233 14022 webserver.cc:533] Webserver started at http://127.13.177.190:36697/ using document root <none> and password file <none>
I20260812 06:16:26.289693 14022 fs_manager.cc:362] Metadata directory not provided
I20260812 06:16:26.289746 14022 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:16:26.289919 14022 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:16:26.291426 14022 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskBsNFja/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515386269012-14022-0/minicluster-data/master-0-root/instance:
uuid: "be1515567e1d4bf2811ab3407d2afc71"
format_stamp: "Formatted at 2026-08-12 06:16:26 on dist-test-slave-rwrg"
I20260812 06:16:26.294680 14022 fs_manager.cc:696] Time spent creating directory manager: real 0.003s	user 0.000s	sys 0.005s
I20260812 06:16:26.296433 14055 log_block_manager.cc:4127] Time spent loading block containers with low live blocks: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:16:26.297384 14022 fs_manager.cc:730] Time spent opening block manager: real 0.002s	user 0.000s	sys 0.002s
I20260812 06:16:26.297488 14022 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskBsNFja/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515386269012-14022-0/minicluster-data/master-0-root
uuid: "be1515567e1d4bf2811ab3407d2afc71"
format_stamp: "Formatted at 2026-08-12 06:16:26 on dist-test-slave-rwrg"
I20260812 06:16:26.297575 14022 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskBsNFja/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515386269012-14022-0/minicluster-data/master-0-root
metadata directory: /tmp/dist-test-taskBsNFja/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515386269012-14022-0/minicluster-data/master-0-root
1 data directories: /tmp/dist-test-taskBsNFja/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515386269012-14022-0/minicluster-data/master-0-root/data
Total live blocks: 0
Total live bytes: 0
Total live bytes (after alignment): 0
Total number of LBM containers: 0 (0 full)
Did not check for missing blocks
Did not check for orphaned blocks
Total full LBM containers with extra space: 0 (0 repaired)
Total full LBM container extra space in bytes: 0 (0 repaired)
Total incomplete LBM containers: 0 (0 repaired)
Total LBM partial records: 0 (0 repaired)
Total corrupted LBM metadata records in RocksDB: 0 (0 repaired)
I20260812 06:16:26.309899 14022 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:16:26.310393 14022 env_posix.cc:2285] Not raising this process' running threads per effective uid limit of 18446744073709551615; it is already as high as it can go
I20260812 06:16:26.310511 14022 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:16:26.317930 14022 rpc_server.cc:307] RPC server started. Bound to: 127.13.177.190:45661
I20260812 06:16:26.317940 14152 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.13.177.190:45661 every 8 connection(s)
I20260812 06:16:26.320011 14154 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet 00000000000000000000000000000000. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:16:26.325233 14154 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P be1515567e1d4bf2811ab3407d2afc71: Bootstrap starting.
I20260812 06:16:26.327425 14154 tablet_bootstrap.cc:654] T 00000000000000000000000000000000 P be1515567e1d4bf2811ab3407d2afc71: Neither blocks nor log segments found. Creating new log.
I20260812 06:16:26.328292 14154 log.cc:826] T 00000000000000000000000000000000 P be1515567e1d4bf2811ab3407d2afc71: Log is configured to *not* fsync() on all Append() calls
I20260812 06:16:26.329990 14154 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P be1515567e1d4bf2811ab3407d2afc71: No bootstrap required, opened a new log
I20260812 06:16:26.332762 14154 raft_consensus.cc:359] T 00000000000000000000000000000000 P be1515567e1d4bf2811ab3407d2afc71 [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "be1515567e1d4bf2811ab3407d2afc71" member_type: VOTER }
I20260812 06:16:26.332940 14154 raft_consensus.cc:385] T 00000000000000000000000000000000 P be1515567e1d4bf2811ab3407d2afc71 [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:16:26.333058 14154 raft_consensus.cc:740] T 00000000000000000000000000000000 P be1515567e1d4bf2811ab3407d2afc71 [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: be1515567e1d4bf2811ab3407d2afc71, State: Initialized, Role: FOLLOWER
I20260812 06:16:26.333704 14154 consensus_queue.cc:260] T 00000000000000000000000000000000 P be1515567e1d4bf2811ab3407d2afc71 [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: "be1515567e1d4bf2811ab3407d2afc71" member_type: VOTER }
I20260812 06:16:26.333870 14154 raft_consensus.cc:399] T 00000000000000000000000000000000 P be1515567e1d4bf2811ab3407d2afc71 [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:16:26.333946 14154 raft_consensus.cc:493] T 00000000000000000000000000000000 P be1515567e1d4bf2811ab3407d2afc71 [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:16:26.334117 14154 raft_consensus.cc:3060] T 00000000000000000000000000000000 P be1515567e1d4bf2811ab3407d2afc71 [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:16:26.334971 14154 raft_consensus.cc:515] T 00000000000000000000000000000000 P be1515567e1d4bf2811ab3407d2afc71 [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "be1515567e1d4bf2811ab3407d2afc71" member_type: VOTER }
I20260812 06:16:26.335386 14154 leader_election.cc:304] T 00000000000000000000000000000000 P be1515567e1d4bf2811ab3407d2afc71 [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: be1515567e1d4bf2811ab3407d2afc71; no voters: 
I20260812 06:16:26.335698 14154 leader_election.cc:290] T 00000000000000000000000000000000 P be1515567e1d4bf2811ab3407d2afc71 [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:16:26.335835 14159 raft_consensus.cc:2804] T 00000000000000000000000000000000 P be1515567e1d4bf2811ab3407d2afc71 [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:16:26.336117 14159 raft_consensus.cc:697] T 00000000000000000000000000000000 P be1515567e1d4bf2811ab3407d2afc71 [term 1 LEADER]: Becoming Leader. State: Replica: be1515567e1d4bf2811ab3407d2afc71, State: Running, Role: LEADER
I20260812 06:16:26.336635 14159 consensus_queue.cc:237] T 00000000000000000000000000000000 P be1515567e1d4bf2811ab3407d2afc71 [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: "be1515567e1d4bf2811ab3407d2afc71" member_type: VOTER }
I20260812 06:16:26.336746 14154 sys_catalog.cc:565] T 00000000000000000000000000000000 P be1515567e1d4bf2811ab3407d2afc71 [sys.catalog]: configured and running, proceeding with master startup.
I20260812 06:16:26.338476 14160 sys_catalog.cc:455] T 00000000000000000000000000000000 P be1515567e1d4bf2811ab3407d2afc71 [sys.catalog]: SysCatalogTable state changed. Reason: RaftConsensus started. Latest consensus state: current_term: 1 leader_uuid: "be1515567e1d4bf2811ab3407d2afc71" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "be1515567e1d4bf2811ab3407d2afc71" member_type: VOTER } }
I20260812 06:16:26.338587 14160 sys_catalog.cc:458] T 00000000000000000000000000000000 P be1515567e1d4bf2811ab3407d2afc71 [sys.catalog]: This master's current role is: LEADER
I20260812 06:16:26.338862 14163 sys_catalog.cc:455] T 00000000000000000000000000000000 P be1515567e1d4bf2811ab3407d2afc71 [sys.catalog]: SysCatalogTable state changed. Reason: New leader be1515567e1d4bf2811ab3407d2afc71. Latest consensus state: current_term: 1 leader_uuid: "be1515567e1d4bf2811ab3407d2afc71" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "be1515567e1d4bf2811ab3407d2afc71" member_type: VOTER } }
I20260812 06:16:26.338933 14163 sys_catalog.cc:458] T 00000000000000000000000000000000 P be1515567e1d4bf2811ab3407d2afc71 [sys.catalog]: This master's current role is: LEADER
I20260812 06:16:26.338939 14176 catalog_manager.cc:1511] Loading table and tablet metadata into memory...
I20260812 06:16:26.339758 14022 internal_mini_cluster.cc:184] Waiting to initialize catalog manager on master 0
I20260812 06:16:26.341482 14176 catalog_manager.cc:1520] Initializing Kudu cluster ID...
I20260812 06:16:26.345662 14176 catalog_manager.cc:1383] Generated new cluster ID: e53789caf62d41ea9656873b842c5bf4
I20260812 06:16:26.345726 14176 catalog_manager.cc:1531] Initializing Kudu internal certificate authority...
I20260812 06:16:26.364567 14176 catalog_manager.cc:1406] Generated new certificate authority record
I20260812 06:16:26.365738 14176 catalog_manager.cc:1540] Loading token signing keys...
I20260812 06:16:26.374622 14176 catalog_manager.cc:6092] T 00000000000000000000000000000000 P be1515567e1d4bf2811ab3407d2afc71: Generated new TSK 0
I20260812 06:16:26.375288 14176 catalog_manager.cc:1550] Initializing in-progress tserver states...
I20260812 06:16:26.404775 14022 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:16:26.407382 14187 instance_detector.cc:116] could not retrieve AWS instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:16:26.407488 14190 instance_detector.cc:116] could not retrieve OpenStack instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:16:26.407495 14188 instance_detector.cc:116] could not retrieve Azure instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:16:26.407819 14022 server_base.cc:1061] running on GCE node
I20260812 06:16:26.408002 14022 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:16:26.408043 14022 system_unsync_time.cc:38] NTP support is disabled. Clock error bounds will not be accurate. This configuration is not suitable for distributed clusters.
I20260812 06:16:26.408059 14022 hybrid_clock.cc:648] HybridClock initialized: now 1786515386408060 us; error 0 us; skew 500 ppm
I20260812 06:16:26.408973 14022 webserver.cc:533] Webserver started at http://127.13.177.129:44021/ using document root <none> and password file <none>
I20260812 06:16:26.409157 14022 fs_manager.cc:362] Metadata directory not provided
I20260812 06:16:26.409228 14022 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:16:26.409328 14022 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:16:26.409765 14022 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskBsNFja/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515386269012-14022-0/minicluster-data/ts-0-root/instance:
uuid: "210768fdb6d24d9f96c7ff800870e811"
format_stamp: "Formatted at 2026-08-12 06:16:26 on dist-test-slave-rwrg"
I20260812 06:16:26.411300 14022 fs_manager.cc:696] Time spent creating directory manager: real 0.001s	user 0.000s	sys 0.002s
I20260812 06:16:26.412261 14200 log_block_manager.cc:4127] Time spent loading block containers with low live blocks: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:16:26.412567 14022 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.001s	sys 0.000s
I20260812 06:16:26.412647 14022 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskBsNFja/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515386269012-14022-0/minicluster-data/ts-0-root
uuid: "210768fdb6d24d9f96c7ff800870e811"
format_stamp: "Formatted at 2026-08-12 06:16:26 on dist-test-slave-rwrg"
I20260812 06:16:26.412738 14022 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskBsNFja/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515386269012-14022-0/minicluster-data/ts-0-root
metadata directory: /tmp/dist-test-taskBsNFja/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515386269012-14022-0/minicluster-data/ts-0-root
1 data directories: /tmp/dist-test-taskBsNFja/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515386269012-14022-0/minicluster-data/ts-0-root/data
Total live blocks: 0
Total live bytes: 0
Total live bytes (after alignment): 0
Total number of LBM containers: 0 (0 full)
Did not check for missing blocks
Did not check for orphaned blocks
Total full LBM containers with extra space: 0 (0 repaired)
Total full LBM container extra space in bytes: 0 (0 repaired)
Total incomplete LBM containers: 0 (0 repaired)
Total LBM partial records: 0 (0 repaired)
Total corrupted LBM metadata records in RocksDB: 0 (0 repaired)
I20260812 06:16:26.419775 14022 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:16:26.420156 14022 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:16:26.420657 14022 txn_system_client.cc:432] TxnSystemClient initialization is disabled...
I20260812 06:16:26.421416 14022 ts_tablet_manager.cc:585] Loaded tablet metadata (0 total tablets, 0 live tablets)
I20260812 06:16:26.421463 14022 ts_tablet_manager.cc:531] Time spent load tablet metadata: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:16:26.421537 14022 ts_tablet_manager.cc:616] Registered 0 tablets
I20260812 06:16:26.421571 14022 ts_tablet_manager.cc:595] Time spent register tablets: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:16:26.428303 14022 rpc_server.cc:307] RPC server started. Bound to: 127.13.177.129:37785
I20260812 06:16:26.428517 14321 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.13.177.129:37785 every 8 connection(s)
I20260812 06:16:26.440948 14323 heartbeater.cc:344] Connected to a master server at 127.13.177.190:45661
I20260812 06:16:26.441211 14323 heartbeater.cc:461] Registering TS with master...
I20260812 06:16:26.441679 14323 heartbeater.cc:507] Master 127.13.177.190:45661 requested a full tablet report, sending...
I20260812 06:16:26.443169 14088 ts_manager.cc:194] Registered new tserver with Master: 210768fdb6d24d9f96c7ff800870e811 (127.13.177.129:37785)
I20260812 06:16:26.443588 14022 internal_mini_cluster.cc:371] 1 TS(s) registered with all masters after 0.014566474s
I20260812 06:16:26.444705 14088 master_service.cc:502] Signed X509 certificate for tserver {username='slave'} at 127.0.0.1:41696
I20260812 06:16:26.455515 14088 catalog_manager.cc:2283] Servicing CreateTable request from {username='slave'} at 127.0.0.1:41698:
name: "heavy-update-compaction-test"
schema {
  columns {
    name: "key"
    type: INT64
    is_key: true
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_a"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_b"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_c"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_d"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_e"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
}
num_replicas: 1
split_rows_range_bounds {
}
partition_schema {
  range_schema {
  }
}
I20260812 06:16:26.471194 14249 tablet_service.cc:1511] Processing CreateTablet for tablet a09e8349ab714633bf02db6f310b3411 (DEFAULT_TABLE table=heavy-update-compaction-test [id=0d79d8f8b35240618311e7fd8416e379]), partition=
I20260812 06:16:26.471622 14249 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet a09e8349ab714633bf02db6f310b3411. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:16:26.474535 14342 tablet_bootstrap.cc:492] T a09e8349ab714633bf02db6f310b3411 P 210768fdb6d24d9f96c7ff800870e811: Bootstrap starting.
I20260812 06:16:26.477013 14342 tablet_bootstrap.cc:654] T a09e8349ab714633bf02db6f310b3411 P 210768fdb6d24d9f96c7ff800870e811: Neither blocks nor log segments found. Creating new log.
I20260812 06:16:26.479069 14342 tablet_bootstrap.cc:492] T a09e8349ab714633bf02db6f310b3411 P 210768fdb6d24d9f96c7ff800870e811: No bootstrap required, opened a new log
I20260812 06:16:26.479223 14342 ts_tablet_manager.cc:1403] T a09e8349ab714633bf02db6f310b3411 P 210768fdb6d24d9f96c7ff800870e811: Time spent bootstrapping tablet: real 0.005s	user 0.004s	sys 0.000s
I20260812 06:16:26.480283 14342 raft_consensus.cc:359] T a09e8349ab714633bf02db6f310b3411 P 210768fdb6d24d9f96c7ff800870e811 [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "210768fdb6d24d9f96c7ff800870e811" member_type: VOTER last_known_addr { host: "127.13.177.129" port: 37785 } }
I20260812 06:16:26.480407 14342 raft_consensus.cc:385] T a09e8349ab714633bf02db6f310b3411 P 210768fdb6d24d9f96c7ff800870e811 [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:16:26.480443 14342 raft_consensus.cc:740] T a09e8349ab714633bf02db6f310b3411 P 210768fdb6d24d9f96c7ff800870e811 [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: 210768fdb6d24d9f96c7ff800870e811, State: Initialized, Role: FOLLOWER
I20260812 06:16:26.480594 14342 consensus_queue.cc:260] T a09e8349ab714633bf02db6f310b3411 P 210768fdb6d24d9f96c7ff800870e811 [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: "210768fdb6d24d9f96c7ff800870e811" member_type: VOTER last_known_addr { host: "127.13.177.129" port: 37785 } }
I20260812 06:16:26.480751 14342 raft_consensus.cc:399] T a09e8349ab714633bf02db6f310b3411 P 210768fdb6d24d9f96c7ff800870e811 [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:16:26.480832 14342 raft_consensus.cc:493] T a09e8349ab714633bf02db6f310b3411 P 210768fdb6d24d9f96c7ff800870e811 [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:16:26.480911 14342 raft_consensus.cc:3060] T a09e8349ab714633bf02db6f310b3411 P 210768fdb6d24d9f96c7ff800870e811 [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:16:26.482406 14342 raft_consensus.cc:515] T a09e8349ab714633bf02db6f310b3411 P 210768fdb6d24d9f96c7ff800870e811 [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "210768fdb6d24d9f96c7ff800870e811" member_type: VOTER last_known_addr { host: "127.13.177.129" port: 37785 } }
I20260812 06:16:26.482558 14342 leader_election.cc:304] T a09e8349ab714633bf02db6f310b3411 P 210768fdb6d24d9f96c7ff800870e811 [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: 210768fdb6d24d9f96c7ff800870e811; no voters: 
I20260812 06:16:26.482798 14342 leader_election.cc:290] T a09e8349ab714633bf02db6f310b3411 P 210768fdb6d24d9f96c7ff800870e811 [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:16:26.482977 14349 raft_consensus.cc:2804] T a09e8349ab714633bf02db6f310b3411 P 210768fdb6d24d9f96c7ff800870e811 [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:16:26.483224 14342 ts_tablet_manager.cc:1434] T a09e8349ab714633bf02db6f310b3411 P 210768fdb6d24d9f96c7ff800870e811: Time spent starting tablet: real 0.004s	user 0.004s	sys 0.000s
I20260812 06:16:26.483330 14349 raft_consensus.cc:697] T a09e8349ab714633bf02db6f310b3411 P 210768fdb6d24d9f96c7ff800870e811 [term 1 LEADER]: Becoming Leader. State: Replica: 210768fdb6d24d9f96c7ff800870e811, State: Running, Role: LEADER
I20260812 06:16:26.483544 14349 consensus_queue.cc:237] T a09e8349ab714633bf02db6f310b3411 P 210768fdb6d24d9f96c7ff800870e811 [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: "210768fdb6d24d9f96c7ff800870e811" member_type: VOTER last_known_addr { host: "127.13.177.129" port: 37785 } }
I20260812 06:16:26.483642 14323 heartbeater.cc:499] Master 127.13.177.190:45661 was elected leader, sending a full tablet report...
I20260812 06:16:26.486479 14088 catalog_manager.cc:5719] T a09e8349ab714633bf02db6f310b3411 P 210768fdb6d24d9f96c7ff800870e811 reported cstate change: term changed from 0 to 1, leader changed from <none> to 210768fdb6d24d9f96c7ff800870e811 (127.13.177.129). New cstate: current_term: 1 leader_uuid: "210768fdb6d24d9f96c7ff800870e811" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "210768fdb6d24d9f96c7ff800870e811" member_type: VOTER last_known_addr { host: "127.13.177.129" port: 37785 } health_report { overall_health: HEALTHY } } }
I20260812 06:16:26.608296 14022 heavy-update-compaction-itest.cc:215] Time spent inserting: real 0.116s	user 0.015s	sys 0.060s
I20260812 06:16:26.679567 14324 maintenance_manager.cc:419] P 210768fdb6d24d9f96c7ff800870e811: Scheduling FlushMRSOp(a09e8349ab714633bf02db6f310b3411): perf score=10.125253
I20260812 06:16:26.812031 14206 maintenance_manager.cc:643] P 210768fdb6d24d9f96c7ff800870e811: FlushMRSOp(a09e8349ab714633bf02db6f310b3411) complete. Timing: real 0.132s	user 0.109s	sys 0.016s Metrics: {"bytes_written":8205077,"cfile_init":1,"compiler_manager_pool.queue_time_us":275,"delete_count":0,"dirs.queue_time_us":62,"dirs.run_cpu_time_us":207,"dirs.run_wall_time_us":851,"drs_written":1,"lbm_read_time_us":64,"lbm_reads_lt_1ms":4,"lbm_write_time_us":33365,"lbm_writes_lt_1ms":457,"peak_mem_usage":0,"reinsert_count":0,"rows_written":102,"thread_start_us":161,"threads_started":1,"update_count":1000}
I20260812 06:16:26.813261 14324 maintenance_manager.cc:419] P 210768fdb6d24d9f96c7ff800870e811: Scheduling LogGCOp(a09e8349ab714633bf02db6f310b3411): free 8725963 bytes of WAL
I20260812 06:16:26.813557 14206 log_reader.cc:385] T a09e8349ab714633bf02db6f310b3411: removed 1 log segments from log reader
I20260812 06:16:26.813627 14206 log.cc:1079] T a09e8349ab714633bf02db6f310b3411 P 210768fdb6d24d9f96c7ff800870e811: Deleting log segment in path: /tmp/dist-test-taskBsNFja/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515386269012-14022-0/minicluster-data/ts-0-root/wals/a09e8349ab714633bf02db6f310b3411/wal-000000001 (ops 1-6)
I20260812 06:16:26.816089 14206 maintenance_manager.cc:643] P 210768fdb6d24d9f96c7ff800870e811: LogGCOp(a09e8349ab714633bf02db6f310b3411) complete. Timing: real 0.003s	user 0.001s	sys 0.000s Metrics: {}
I20260812 06:16:26.816413 14324 maintenance_manager.cc:419] P 210768fdb6d24d9f96c7ff800870e811: Scheduling MajorDeltaCompactionOp(a09e8349ab714633bf02db6f310b3411): perf score=1.000000
I20260812 06:16:26.919248 14206 maintenance_manager.cc:643] P 210768fdb6d24d9f96c7ff800870e811: MajorDeltaCompactionOp(a09e8349ab714633bf02db6f310b3411) complete. Timing: real 0.103s	user 0.090s	sys 0.012s Metrics: {"cfile_cache_miss":231,"cfile_cache_miss_bytes":12385403,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":1,"delta_iterators_relevant":1,"dirs.queue_time_us":493,"lbm_read_time_us":6349,"lbm_reads_lt_1ms":263,"lbm_write_time_us":19363,"lbm_writes_lt_1ms":243,"peak_mem_usage":25836184,"reinsert_count":0,"spinlock_wait_cycles":3200,"thread_start_us":427,"threads_started":5,"update_count":1000}
I20260812 06:16:26.919822 14324 maintenance_manager.cc:419] P 210768fdb6d24d9f96c7ff800870e811: Scheduling FlushDeltaMemStoresOp(a09e8349ab714633bf02db6f310b3411): perf score=6.157687
I20260812 06:16:26.950868 14206 maintenance_manager.cc:643] P 210768fdb6d24d9f96c7ff800870e811: FlushDeltaMemStoresOp(a09e8349ab714633bf02db6f310b3411) complete. Timing: real 0.031s	user 0.004s	sys 0.024s Metrics: {"bytes_written":8205078,"delete_count":0,"lbm_write_time_us":13660,"lbm_writes_lt_1ms":203,"reinsert_count":0,"update_count":1000}
I20260812 06:16:26.951327 14324 maintenance_manager.cc:419] P 210768fdb6d24d9f96c7ff800870e811: Scheduling FlushDeltaMemStoresOp(a09e8349ab714633bf02db6f310b3411): perf score=2.188937
I20260812 06:16:26.965233 14206 maintenance_manager.cc:643] P 210768fdb6d24d9f96c7ff800870e811: FlushDeltaMemStoresOp(a09e8349ab714633bf02db6f310b3411) complete. Timing: real 0.014s	user 0.008s	sys 0.005s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5431,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:26.965639 14324 maintenance_manager.cc:419] P 210768fdb6d24d9f96c7ff800870e811: Scheduling MajorDeltaCompactionOp(a09e8349ab714633bf02db6f310b3411): perf score=1.000000
I20260812 06:16:27.140009 14206 maintenance_manager.cc:643] P 210768fdb6d24d9f96c7ff800870e811: MajorDeltaCompactionOp(a09e8349ab714633bf02db6f310b3411) complete. Timing: real 0.174s	user 0.085s	sys 0.086s Metrics: {"cfile_cache_miss":332,"cfile_cache_miss_bytes":16487935,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":937,"lbm_read_time_us":7205,"lbm_reads_lt_1ms":372,"lbm_write_time_us":54822,"lbm_writes_1-10_ms":4,"lbm_writes_lt_1ms":339,"peak_mem_usage":38262756,"reinsert_count":0,"update_count":1500}
I20260812 06:16:27.140626 14324 maintenance_manager.cc:419] P 210768fdb6d24d9f96c7ff800870e811: Scheduling FlushDeltaMemStoresOp(a09e8349ab714633bf02db6f310b3411): perf score=6.157687
I20260812 06:16:27.186915 14206 maintenance_manager.cc:643] P 210768fdb6d24d9f96c7ff800870e811: FlushDeltaMemStoresOp(a09e8349ab714633bf02db6f310b3411) complete. Timing: real 0.046s	user 0.024s	sys 0.016s Metrics: {"bytes_written":8205078,"delete_count":0,"lbm_write_time_us":26291,"lbm_writes_lt_1ms":203,"reinsert_count":0,"update_count":1000}
I20260812 06:16:27.187399 14324 maintenance_manager.cc:419] P 210768fdb6d24d9f96c7ff800870e811: Scheduling UndoDeltaBlockGCOp(a09e8349ab714633bf02db6f310b3411): 8206538 bytes on disk
I20260812 06:16:27.187850 14206 maintenance_manager.cc:643] P 210768fdb6d24d9f96c7ff800870e811: UndoDeltaBlockGCOp(a09e8349ab714633bf02db6f310b3411) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":49,"lbm_reads_lt_1ms":4}
I20260812 06:16:27.188244 14324 maintenance_manager.cc:419] P 210768fdb6d24d9f96c7ff800870e811: Scheduling FlushDeltaMemStoresOp(a09e8349ab714633bf02db6f310b3411): perf score=2.188937
I20260812 06:16:27.200304 14206 maintenance_manager.cc:643] P 210768fdb6d24d9f96c7ff800870e811: FlushDeltaMemStoresOp(a09e8349ab714633bf02db6f310b3411) complete. Timing: real 0.012s	user 0.002s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4610,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:27.200865 14324 maintenance_manager.cc:419] P 210768fdb6d24d9f96c7ff800870e811: Scheduling MajorDeltaCompactionOp(a09e8349ab714633bf02db6f310b3411): perf score=1.000000
I20260812 06:16:27.364945 14206 maintenance_manager.cc:643] P 210768fdb6d24d9f96c7ff800870e811: MajorDeltaCompactionOp(a09e8349ab714633bf02db6f310b3411) complete. Timing: real 0.164s	user 0.087s	sys 0.077s Metrics: {"cfile_cache_miss":332,"cfile_cache_miss_bytes":16487935,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":891,"lbm_read_time_us":7778,"lbm_reads_lt_1ms":372,"lbm_write_time_us":63959,"lbm_writes_1-10_ms":8,"lbm_writes_lt_1ms":335,"mutex_wait_us":321,"peak_mem_usage":38262756,"reinsert_count":0,"spinlock_wait_cycles":2048,"update_count":1500}
I20260812 06:16:27.365537 14324 maintenance_manager.cc:419] P 210768fdb6d24d9f96c7ff800870e811: Scheduling FlushDeltaMemStoresOp(a09e8349ab714633bf02db6f310b3411): perf score=10.126437
I20260812 06:16:27.409566 14206 maintenance_manager.cc:643] P 210768fdb6d24d9f96c7ff800870e811: FlushDeltaMemStoresOp(a09e8349ab714633bf02db6f310b3411) complete. Timing: real 0.044s	user 0.014s	sys 0.024s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":19642,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":302,"reinsert_count":0,"update_count":1500}
I20260812 06:16:27.410095 14324 maintenance_manager.cc:419] P 210768fdb6d24d9f96c7ff800870e811: Scheduling MajorDeltaCompactionOp(a09e8349ab714633bf02db6f310b3411): perf score=1.000000
I20260812 06:16:27.598577 14206 maintenance_manager.cc:643] P 210768fdb6d24d9f96c7ff800870e811: MajorDeltaCompactionOp(a09e8349ab714633bf02db6f310b3411) complete. Timing: real 0.188s	user 0.109s	sys 0.071s Metrics: {"cfile_cache_miss":331,"cfile_cache_miss_bytes":16487816,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":1,"delta_iterators_relevant":1,"dirs.queue_time_us":177,"lbm_read_time_us":7035,"lbm_reads_lt_1ms":363,"lbm_write_time_us":62556,"lbm_writes_1-10_ms":12,"lbm_writes_lt_1ms":331,"mutex_wait_us":40,"peak_mem_usage":38262756,"reinsert_count":0,"spinlock_wait_cycles":1664,"update_count":1500}
I20260812 06:16:27.599365 14324 maintenance_manager.cc:419] P 210768fdb6d24d9f96c7ff800870e811: Scheduling FlushDeltaMemStoresOp(a09e8349ab714633bf02db6f310b3411): perf score=11.118625
I20260812 06:16:27.657910 14206 maintenance_manager.cc:643] P 210768fdb6d24d9f96c7ff800870e811: FlushDeltaMemStoresOp(a09e8349ab714633bf02db6f310b3411) complete. Timing: real 0.058s	user 0.025s	sys 0.031s Metrics: {"bytes_written":12717736,"delete_count":0,"lbm_write_time_us":32702,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":312,"reinsert_count":0,"update_count":1550}
I20260812 06:16:27.658381 14324 maintenance_manager.cc:419] P 210768fdb6d24d9f96c7ff800870e811: Scheduling FlushDeltaMemStoresOp(a09e8349ab714633bf02db6f310b3411): perf score=6.157687
I20260812 06:16:27.709533 14206 maintenance_manager.cc:643] P 210768fdb6d24d9f96c7ff800870e811: FlushDeltaMemStoresOp(a09e8349ab714633bf02db6f310b3411) complete. Timing: real 0.051s	user 0.019s	sys 0.028s Metrics: {"bytes_written":7794838,"delete_count":0,"lbm_write_time_us":33466,"lbm_writes_lt_1ms":193,"reinsert_count":0,"update_count":950}
I20260812 06:16:27.710407 14324 maintenance_manager.cc:419] P 210768fdb6d24d9f96c7ff800870e811: Scheduling FlushDeltaMemStoresOp(a09e8349ab714633bf02db6f310b3411): perf score=2.188937
I20260812 06:16:27.753970 14206 maintenance_manager.cc:643] P 210768fdb6d24d9f96c7ff800870e811: FlushDeltaMemStoresOp(a09e8349ab714633bf02db6f310b3411) complete. Timing: real 0.043s	user 0.024s	sys 0.009s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":22935,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:27.754447 14324 maintenance_manager.cc:419] P 210768fdb6d24d9f96c7ff800870e811: Scheduling MajorDeltaCompactionOp(a09e8349ab714633bf02db6f310b3411): perf score=1.000000
I20260812 06:16:28.111912 14206 maintenance_manager.cc:643] P 210768fdb6d24d9f96c7ff800870e811: MajorDeltaCompactionOp(a09e8349ab714633bf02db6f310b3411) complete. Timing: real 0.357s	user 0.144s	sys 0.209s Metrics: {"cfile_cache_miss":633,"cfile_cache_miss_bytes":28795297,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":819,"lbm_read_time_us":11336,"lbm_reads_lt_1ms":665,"lbm_write_time_us":140900,"lbm_writes_1-10_ms":12,"lbm_writes_lt_1ms":631,"mutex_wait_us":43,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":8320,"thread_start_us":300,"threads_started":5,"update_count":3000}
I20260812 06:16:28.112610 14324 maintenance_manager.cc:419] P 210768fdb6d24d9f96c7ff800870e811: Scheduling FlushDeltaMemStoresOp(a09e8349ab714633bf02db6f310b3411): perf score=18.063937
I20260812 06:16:28.207417 14206 maintenance_manager.cc:643] P 210768fdb6d24d9f96c7ff800870e811: FlushDeltaMemStoresOp(a09e8349ab714633bf02db6f310b3411) complete. Timing: real 0.095s	user 0.040s	sys 0.052s Metrics: {"bytes_written":20512318,"delete_count":0,"lbm_write_time_us":51443,"lbm_writes_lt_1ms":503,"reinsert_count":0,"update_count":2500}
I20260812 06:16:28.208045 14324 maintenance_manager.cc:419] P 210768fdb6d24d9f96c7ff800870e811: Scheduling FlushDeltaMemStoresOp(a09e8349ab714633bf02db6f310b3411): perf score=2.188937
I20260812 06:16:28.229812 14206 maintenance_manager.cc:643] P 210768fdb6d24d9f96c7ff800870e811: FlushDeltaMemStoresOp(a09e8349ab714633bf02db6f310b3411) complete. Timing: real 0.022s	user 0.008s	sys 0.007s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6804,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:28.230264 14324 maintenance_manager.cc:419] P 210768fdb6d24d9f96c7ff800870e811: Scheduling FlushDeltaMemStoresOp(a09e8349ab714633bf02db6f310b3411): perf score=2.188937
I20260812 06:16:28.242179 14206 maintenance_manager.cc:643] P 210768fdb6d24d9f96c7ff800870e811: FlushDeltaMemStoresOp(a09e8349ab714633bf02db6f310b3411) complete. Timing: real 0.012s	user 0.008s	sys 0.002s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5249,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:28.242594 14324 maintenance_manager.cc:419] P 210768fdb6d24d9f96c7ff800870e811: Scheduling MajorDeltaCompactionOp(a09e8349ab714633bf02db6f310b3411): perf score=1.000000
I20260812 06:16:28.645557 14206 maintenance_manager.cc:643] P 210768fdb6d24d9f96c7ff800870e811: MajorDeltaCompactionOp(a09e8349ab714633bf02db6f310b3411) complete. Timing: real 0.403s	user 0.175s	sys 0.221s Metrics: {"cfile_cache_miss":733,"cfile_cache_miss_bytes":32897706,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":2008,"lbm_read_time_us":15473,"lbm_reads_lt_1ms":773,"lbm_write_time_us":139721,"lbm_writes_1-10_ms":10,"lbm_writes_lt_1ms":733,"mutex_wait_us":58,"peak_mem_usage":87969044,"reinsert_count":0,"spinlock_wait_cycles":8064,"thread_start_us":1781,"threads_started":5,"update_count":3500}
I20260812 06:16:28.646265 14324 maintenance_manager.cc:419] P 210768fdb6d24d9f96c7ff800870e811: Scheduling FlushDeltaMemStoresOp(a09e8349ab714633bf02db6f310b3411): perf score=15.087375
I20260812 06:16:28.716986 14206 maintenance_manager.cc:643] P 210768fdb6d24d9f96c7ff800870e811: FlushDeltaMemStoresOp(a09e8349ab714633bf02db6f310b3411) complete. Timing: real 0.071s	user 0.046s	sys 0.016s Metrics: {"bytes_written":16902197,"delete_count":0,"lbm_write_time_us":30040,"lbm_writes_lt_1ms":415,"reinsert_count":0,"update_count":2060}
I20260812 06:16:28.717473 14324 maintenance_manager.cc:419] P 210768fdb6d24d9f96c7ff800870e811: Scheduling FlushDeltaMemStoresOp(a09e8349ab714633bf02db6f310b3411): perf score=2.188937
I20260812 06:16:28.728257 14206 maintenance_manager.cc:643] P 210768fdb6d24d9f96c7ff800870e811: FlushDeltaMemStoresOp(a09e8349ab714633bf02db6f310b3411) complete. Timing: real 0.011s	user 0.000s	sys 0.008s Metrics: {"bytes_written":4020610,"delete_count":0,"lbm_write_time_us":3994,"lbm_writes_lt_1ms":101,"reinsert_count":0,"update_count":490}
I20260812 06:16:28.728766 14324 maintenance_manager.cc:419] P 210768fdb6d24d9f96c7ff800870e811: Scheduling FlushDeltaMemStoresOp(a09e8349ab714633bf02db6f310b3411): perf score=2.188937
I20260812 06:16:28.741531 14206 maintenance_manager.cc:643] P 210768fdb6d24d9f96c7ff800870e811: FlushDeltaMemStoresOp(a09e8349ab714633bf02db6f310b3411) complete. Timing: real 0.013s	user 0.011s	sys 0.001s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":4854,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:16:28.742012 14324 maintenance_manager.cc:419] P 210768fdb6d24d9f96c7ff800870e811: Scheduling FlushMRSOp(a09e8349ab714633bf02db6f310b3411): perf score=1.000000
I20260812 06:16:28.780055 14206 maintenance_manager.cc:643] P 210768fdb6d24d9f96c7ff800870e811: FlushMRSOp(a09e8349ab714633bf02db6f310b3411) complete. Timing: real 0.038s	user 0.031s	sys 0.000s Metrics: {"bytes_written":1234474,"cfile_init":1,"dirs.queue_time_us":79,"dirs.run_cpu_time_us":319,"dirs.run_wall_time_us":1397,"drs_written":1,"lbm_read_time_us":47,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1436,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":30}
I20260812 06:16:28.780906 14324 maintenance_manager.cc:419] P 210768fdb6d24d9f96c7ff800870e811: Scheduling LogGCOp(a09e8349ab714633bf02db6f310b3411): free 124710295 bytes of WAL
I20260812 06:16:28.781126 14206 log_reader.cc:385] T a09e8349ab714633bf02db6f310b3411: removed 12 log segments from log reader
I20260812 06:16:28.781168 14206 log.cc:1079] T a09e8349ab714633bf02db6f310b3411 P 210768fdb6d24d9f96c7ff800870e811: Deleting log segment in path: /tmp/dist-test-taskBsNFja/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515386269012-14022-0/minicluster-data/ts-0-root/wals/a09e8349ab714633bf02db6f310b3411/wal-000000002 (ops 7-11)
I20260812 06:16:28.781198 14206 log.cc:1079] T a09e8349ab714633bf02db6f310b3411 P 210768fdb6d24d9f96c7ff800870e811: Deleting log segment in path: /tmp/dist-test-taskBsNFja/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515386269012-14022-0/minicluster-data/ts-0-root/wals/a09e8349ab714633bf02db6f310b3411/wal-000000003 (ops 12-16)
I20260812 06:16:28.781265 14206 log.cc:1079] T a09e8349ab714633bf02db6f310b3411 P 210768fdb6d24d9f96c7ff800870e811: Deleting log segment in path: /tmp/dist-test-taskBsNFja/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515386269012-14022-0/minicluster-data/ts-0-root/wals/a09e8349ab714633bf02db6f310b3411/wal-000000004 (ops 17-21)
I20260812 06:16:28.781307 14206 log.cc:1079] T a09e8349ab714633bf02db6f310b3411 P 210768fdb6d24d9f96c7ff800870e811: Deleting log segment in path: /tmp/dist-test-taskBsNFja/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515386269012-14022-0/minicluster-data/ts-0-root/wals/a09e8349ab714633bf02db6f310b3411/wal-000000005 (ops 22-26)
I20260812 06:16:28.781342 14206 log.cc:1079] T a09e8349ab714633bf02db6f310b3411 P 210768fdb6d24d9f96c7ff800870e811: Deleting log segment in path: /tmp/dist-test-taskBsNFja/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515386269012-14022-0/minicluster-data/ts-0-root/wals/a09e8349ab714633bf02db6f310b3411/wal-000000006 (ops 27-31)
I20260812 06:16:28.781381 14206 log.cc:1079] T a09e8349ab714633bf02db6f310b3411 P 210768fdb6d24d9f96c7ff800870e811: Deleting log segment in path: /tmp/dist-test-taskBsNFja/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515386269012-14022-0/minicluster-data/ts-0-root/wals/a09e8349ab714633bf02db6f310b3411/wal-000000007 (ops 32-36)
I20260812 06:16:28.781417 14206 log.cc:1079] T a09e8349ab714633bf02db6f310b3411 P 210768fdb6d24d9f96c7ff800870e811: Deleting log segment in path: /tmp/dist-test-taskBsNFja/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515386269012-14022-0/minicluster-data/ts-0-root/wals/a09e8349ab714633bf02db6f310b3411/wal-000000008 (ops 37-41)
I20260812 06:16:28.781456 14206 log.cc:1079] T a09e8349ab714633bf02db6f310b3411 P 210768fdb6d24d9f96c7ff800870e811: Deleting log segment in path: /tmp/dist-test-taskBsNFja/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515386269012-14022-0/minicluster-data/ts-0-root/wals/a09e8349ab714633bf02db6f310b3411/wal-000000009 (ops 42-46)
I20260812 06:16:28.781493 14206 log.cc:1079] T a09e8349ab714633bf02db6f310b3411 P 210768fdb6d24d9f96c7ff800870e811: Deleting log segment in path: /tmp/dist-test-taskBsNFja/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515386269012-14022-0/minicluster-data/ts-0-root/wals/a09e8349ab714633bf02db6f310b3411/wal-000000010 (ops 47-51)
I20260812 06:16:28.781533 14206 log.cc:1079] T a09e8349ab714633bf02db6f310b3411 P 210768fdb6d24d9f96c7ff800870e811: Deleting log segment in path: /tmp/dist-test-taskBsNFja/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515386269012-14022-0/minicluster-data/ts-0-root/wals/a09e8349ab714633bf02db6f310b3411/wal-000000011 (ops 52-56)
I20260812 06:16:28.781579 14206 log.cc:1079] T a09e8349ab714633bf02db6f310b3411 P 210768fdb6d24d9f96c7ff800870e811: Deleting log segment in path: /tmp/dist-test-taskBsNFja/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515386269012-14022-0/minicluster-data/ts-0-root/wals/a09e8349ab714633bf02db6f310b3411/wal-000000012 (ops 57-61)
I20260812 06:16:28.781620 14206 log.cc:1079] T a09e8349ab714633bf02db6f310b3411 P 210768fdb6d24d9f96c7ff800870e811: Deleting log segment in path: /tmp/dist-test-taskBsNFja/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515386269012-14022-0/minicluster-data/ts-0-root/wals/a09e8349ab714633bf02db6f310b3411/wal-000000013 (ops 62-66)
I20260812 06:16:28.806161 14206 maintenance_manager.cc:643] P 210768fdb6d24d9f96c7ff800870e811: LogGCOp(a09e8349ab714633bf02db6f310b3411) complete. Timing: real 0.025s	user 0.000s	sys 0.023s Metrics: {}
I20260812 06:16:28.806610 14324 maintenance_manager.cc:419] P 210768fdb6d24d9f96c7ff800870e811: Scheduling UndoDeltaBlockGCOp(a09e8349ab714633bf02db6f310b3411): 473 bytes on disk
I20260812 06:16:28.807253 14206 maintenance_manager.cc:643] P 210768fdb6d24d9f96c7ff800870e811: UndoDeltaBlockGCOp(a09e8349ab714633bf02db6f310b3411) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":182,"lbm_reads_lt_1ms":4}
I20260812 06:16:28.807767 14324 maintenance_manager.cc:419] P 210768fdb6d24d9f96c7ff800870e811: Scheduling FlushDeltaMemStoresOp(a09e8349ab714633bf02db6f310b3411): perf score=2.188937
I20260812 06:16:28.825042 14206 maintenance_manager.cc:643] P 210768fdb6d24d9f96c7ff800870e811: FlushDeltaMemStoresOp(a09e8349ab714633bf02db6f310b3411) complete. Timing: real 0.017s	user 0.008s	sys 0.003s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4360,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:28.825423 14324 maintenance_manager.cc:419] P 210768fdb6d24d9f96c7ff800870e811: Scheduling FlushDeltaMemStoresOp(a09e8349ab714633bf02db6f310b3411): perf score=2.188937
I20260812 06:16:28.835517 14206 maintenance_manager.cc:643] P 210768fdb6d24d9f96c7ff800870e811: FlushDeltaMemStoresOp(a09e8349ab714633bf02db6f310b3411) complete. Timing: real 0.010s	user 0.008s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3948,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:28.835889 14324 maintenance_manager.cc:419] P 210768fdb6d24d9f96c7ff800870e811: Scheduling MajorDeltaCompactionOp(a09e8349ab714633bf02db6f310b3411): perf score=1.000000
I20260812 06:16:29.056689 14206 maintenance_manager.cc:643] P 210768fdb6d24d9f96c7ff800870e811: MajorDeltaCompactionOp(a09e8349ab714633bf02db6f310b3411) complete. Timing: real 0.221s	user 0.177s	sys 0.043s Metrics: {"cfile_cache_miss":835,"cfile_cache_miss_bytes":37000344,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":5,"delta_iterators_relevant":5,"dirs.queue_time_us":379,"lbm_read_time_us":16803,"lbm_reads_lt_1ms":875,"lbm_write_time_us":42272,"lbm_writes_lt_1ms":843,"mutex_wait_us":40,"peak_mem_usage":100395616,"reinsert_count":0,"spinlock_wait_cycles":9984,"thread_start_us":113,"threads_started":1,"update_count":4000}
I20260812 06:16:29.057296 14324 maintenance_manager.cc:419] P 210768fdb6d24d9f96c7ff800870e811: Scheduling FlushDeltaMemStoresOp(a09e8349ab714633bf02db6f310b3411): perf score=18.063937
I20260812 06:16:29.165987 14206 maintenance_manager.cc:643] P 210768fdb6d24d9f96c7ff800870e811: FlushDeltaMemStoresOp(a09e8349ab714633bf02db6f310b3411) complete. Timing: real 0.109s	user 0.042s	sys 0.018s Metrics: {"bytes_written":20512314,"delete_count":0,"lbm_write_time_us":71142,"lbm_writes_10-100_ms":2,"lbm_writes_lt_1ms":501,"reinsert_count":0,"update_count":2500}
I20260812 06:16:29.166497 14324 maintenance_manager.cc:419] P 210768fdb6d24d9f96c7ff800870e811: Scheduling FlushDeltaMemStoresOp(a09e8349ab714633bf02db6f310b3411): perf score=6.157687
I20260812 06:16:29.192821 14206 maintenance_manager.cc:643] P 210768fdb6d24d9f96c7ff800870e811: FlushDeltaMemStoresOp(a09e8349ab714633bf02db6f310b3411) complete. Timing: real 0.026s	user 0.014s	sys 0.012s Metrics: {"bytes_written":8205078,"delete_count":0,"lbm_write_time_us":11308,"lbm_writes_lt_1ms":203,"reinsert_count":0,"update_count":1000}
I20260812 06:16:29.193387 14324 maintenance_manager.cc:419] P 210768fdb6d24d9f96c7ff800870e811: Scheduling MajorDeltaCompactionOp(a09e8349ab714633bf02db6f310b3411): perf score=1.000000
I20260812 06:16:29.450030 14206 maintenance_manager.cc:643] P 210768fdb6d24d9f96c7ff800870e811: MajorDeltaCompactionOp(a09e8349ab714633bf02db6f310b3411) complete. Timing: real 0.256s	user 0.137s	sys 0.119s Metrics: {"cfile_cache_miss":732,"cfile_cache_miss_bytes":32897584,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":451,"lbm_read_time_us":14752,"lbm_reads_lt_1ms":764,"lbm_write_time_us":96106,"lbm_writes_1-10_ms":7,"lbm_writes_lt_1ms":736,"mutex_wait_us":23,"peak_mem_usage":87969044,"reinsert_count":0,"spinlock_wait_cycles":5248,"update_count":3500}
I20260812 06:16:29.450726 14324 maintenance_manager.cc:419] P 210768fdb6d24d9f96c7ff800870e811: Scheduling FlushDeltaMemStoresOp(a09e8349ab714633bf02db6f310b3411): perf score=18.063937
I20260812 06:16:29.531463 14206 maintenance_manager.cc:643] P 210768fdb6d24d9f96c7ff800870e811: FlushDeltaMemStoresOp(a09e8349ab714633bf02db6f310b3411) complete. Timing: real 0.080s	user 0.026s	sys 0.040s Metrics: {"bytes_written":20635386,"delete_count":0,"lbm_write_time_us":37304,"lbm_writes_lt_1ms":506,"mutex_wait_us":251,"reinsert_count":0,"update_count":2515}
I20260812 06:16:29.531939 14324 maintenance_manager.cc:419] P 210768fdb6d24d9f96c7ff800870e811: Scheduling FlushDeltaMemStoresOp(a09e8349ab714633bf02db6f310b3411): perf score=6.157687
I20260812 06:16:29.557407 14206 maintenance_manager.cc:643] P 210768fdb6d24d9f96c7ff800870e811: FlushDeltaMemStoresOp(a09e8349ab714633bf02db6f310b3411) complete. Timing: real 0.025s	user 0.016s	sys 0.007s Metrics: {"bytes_written":8082009,"delete_count":0,"lbm_write_time_us":10230,"lbm_writes_lt_1ms":200,"reinsert_count":0,"update_count":985}
I20260812 06:16:29.558028 14324 maintenance_manager.cc:419] P 210768fdb6d24d9f96c7ff800870e811: Scheduling MajorDeltaCompactionOp(a09e8349ab714633bf02db6f310b3411): perf score=1.000000
I20260812 06:16:29.920557 14206 maintenance_manager.cc:643] P 210768fdb6d24d9f96c7ff800870e811: MajorDeltaCompactionOp(a09e8349ab714633bf02db6f310b3411) complete. Timing: real 0.362s	user 0.180s	sys 0.180s Metrics: {"cfile_cache_miss":732,"cfile_cache_miss_bytes":32897587,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":337,"lbm_read_time_us":12311,"lbm_reads_lt_1ms":764,"lbm_write_time_us":169590,"lbm_writes_1-10_ms":12,"lbm_writes_lt_1ms":731,"mutex_wait_us":88,"peak_mem_usage":87969044,"reinsert_count":0,"spinlock_wait_cycles":1408,"update_count":3500}
I20260812 06:16:29.921311 14324 maintenance_manager.cc:419] P 210768fdb6d24d9f96c7ff800870e811: Scheduling FlushDeltaMemStoresOp(a09e8349ab714633bf02db6f310b3411): perf score=23.024875
I20260812 06:16:30.021651 14206 maintenance_manager.cc:643] P 210768fdb6d24d9f96c7ff800870e811: FlushDeltaMemStoresOp(a09e8349ab714633bf02db6f310b3411) complete. Timing: real 0.100s	user 0.061s	sys 0.033s Metrics: {"bytes_written":25517256,"delete_count":0,"lbm_write_time_us":55285,"lbm_writes_lt_1ms":625,"reinsert_count":0,"update_count":3110}
I20260812 06:16:30.022158 14324 maintenance_manager.cc:419] P 210768fdb6d24d9f96c7ff800870e811: Scheduling FlushDeltaMemStoresOp(a09e8349ab714633bf02db6f310b3411): perf score=6.157687
I20260812 06:16:30.063089 14206 maintenance_manager.cc:643] P 210768fdb6d24d9f96c7ff800870e811: FlushDeltaMemStoresOp(a09e8349ab714633bf02db6f310b3411) complete. Timing: real 0.041s	user 0.014s	sys 0.025s Metrics: {"bytes_written":7712793,"delete_count":0,"lbm_write_time_us":24681,"lbm_writes_lt_1ms":191,"reinsert_count":0,"update_count":940}
I20260812 06:16:30.063859 14324 maintenance_manager.cc:419] P 210768fdb6d24d9f96c7ff800870e811: Scheduling FlushDeltaMemStoresOp(a09e8349ab714633bf02db6f310b3411): perf score=2.188937
I20260812 06:16:30.100661 14206 maintenance_manager.cc:643] P 210768fdb6d24d9f96c7ff800870e811: FlushDeltaMemStoresOp(a09e8349ab714633bf02db6f310b3411) complete. Timing: real 0.036s	user 0.005s	sys 0.019s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":16308,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:16:30.101136 14324 maintenance_manager.cc:419] P 210768fdb6d24d9f96c7ff800870e811: Scheduling FlushDeltaMemStoresOp(a09e8349ab714633bf02db6f310b3411): perf score=2.188937
I20260812 06:16:30.141784 14206 maintenance_manager.cc:643] P 210768fdb6d24d9f96c7ff800870e811: FlushDeltaMemStoresOp(a09e8349ab714633bf02db6f310b3411) complete. Timing: real 0.040s	user 0.014s	sys 0.015s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":20031,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:30.142266 14324 maintenance_manager.cc:419] P 210768fdb6d24d9f96c7ff800870e811: Scheduling MajorDeltaCompactionOp(a09e8349ab714633bf02db6f310b3411): perf score=1.000000
I20260812 06:16:30.612445 14206 maintenance_manager.cc:643] P 210768fdb6d24d9f96c7ff800870e811: MajorDeltaCompactionOp(a09e8349ab714633bf02db6f310b3411) complete. Timing: real 0.470s	user 0.202s	sys 0.268s Metrics: {"cfile_cache_miss":1034,"cfile_cache_miss_bytes":45205049,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":953,"lbm_read_time_us":20995,"lbm_reads_lt_1ms":1066,"lbm_write_time_us":217997,"lbm_writes_1-10_ms":4,"lbm_writes_lt_1ms":1039,"peak_mem_usage":125248760,"reinsert_count":0,"spinlock_wait_cycles":1792,"thread_start_us":472,"threads_started":6,"update_count":5000}
I20260812 06:16:30.613296 14324 maintenance_manager.cc:419] P 210768fdb6d24d9f96c7ff800870e811: Scheduling FlushDeltaMemStoresOp(a09e8349ab714633bf02db6f310b3411): perf score=26.001437
I20260812 06:16:30.691908 14206 maintenance_manager.cc:643] P 210768fdb6d24d9f96c7ff800870e811: FlushDeltaMemStoresOp(a09e8349ab714633bf02db6f310b3411) complete. Timing: real 0.078s	user 0.060s	sys 0.015s Metrics: {"bytes_written":28717136,"delete_count":0,"lbm_write_time_us":37723,"lbm_writes_lt_1ms":703,"reinsert_count":0,"update_count":3500}
I20260812 06:16:30.692451 14324 maintenance_manager.cc:419] P 210768fdb6d24d9f96c7ff800870e811: Scheduling FlushDeltaMemStoresOp(a09e8349ab714633bf02db6f310b3411): perf score=3.181125
I20260812 06:16:30.711334 14206 maintenance_manager.cc:643] P 210768fdb6d24d9f96c7ff800870e811: FlushDeltaMemStoresOp(a09e8349ab714633bf02db6f310b3411) complete. Timing: real 0.019s	user 0.007s	sys 0.005s Metrics: {"bytes_written":4512903,"delete_count":0,"lbm_write_time_us":5598,"lbm_writes_lt_1ms":113,"mutex_wait_us":1,"reinsert_count":0,"update_count":550}
I20260812 06:16:30.711827 14324 maintenance_manager.cc:419] P 210768fdb6d24d9f96c7ff800870e811: Scheduling FlushDeltaMemStoresOp(a09e8349ab714633bf02db6f310b3411): perf score=2.188937
I20260812 06:16:30.726104 14206 maintenance_manager.cc:643] P 210768fdb6d24d9f96c7ff800870e811: FlushDeltaMemStoresOp(a09e8349ab714633bf02db6f310b3411) complete. Timing: real 0.014s	user 0.013s	sys 0.000s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":5015,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:16:30.726802 14324 maintenance_manager.cc:419] P 210768fdb6d24d9f96c7ff800870e811: Scheduling FlushMRSOp(a09e8349ab714633bf02db6f310b3411): perf score=1.000000
I20260812 06:16:30.760953 14206 maintenance_manager.cc:643] P 210768fdb6d24d9f96c7ff800870e811: FlushMRSOp(a09e8349ab714633bf02db6f310b3411) complete. Timing: real 0.034s	user 0.031s	sys 0.003s Metrics: {"bytes_written":1439525,"cfile_init":1,"dirs.queue_time_us":66,"dirs.run_cpu_time_us":227,"dirs.run_wall_time_us":1428,"drs_written":1,"lbm_read_time_us":38,"lbm_reads_lt_1ms":4,"lbm_write_time_us":2030,"lbm_writes_lt_1ms":44,"peak_mem_usage":0,"rows_written":35}
I20260812 06:16:30.761672 14324 maintenance_manager.cc:419] P 210768fdb6d24d9f96c7ff800870e811: Scheduling LogGCOp(a09e8349ab714633bf02db6f310b3411): free 144589281 bytes of WAL
I20260812 06:16:30.761893 14206 log_reader.cc:385] T a09e8349ab714633bf02db6f310b3411: removed 14 log segments from log reader
I20260812 06:16:30.761955 14206 log.cc:1079] T a09e8349ab714633bf02db6f310b3411 P 210768fdb6d24d9f96c7ff800870e811: Deleting log segment in path: /tmp/dist-test-taskBsNFja/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515386269012-14022-0/minicluster-data/ts-0-root/wals/a09e8349ab714633bf02db6f310b3411/wal-000000014 (ops 67-70)
I20260812 06:16:30.762015 14206 log.cc:1079] T a09e8349ab714633bf02db6f310b3411 P 210768fdb6d24d9f96c7ff800870e811: Deleting log segment in path: /tmp/dist-test-taskBsNFja/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515386269012-14022-0/minicluster-data/ts-0-root/wals/a09e8349ab714633bf02db6f310b3411/wal-000000015 (ops 71-75)
I20260812 06:16:30.762069 14206 log.cc:1079] T a09e8349ab714633bf02db6f310b3411 P 210768fdb6d24d9f96c7ff800870e811: Deleting log segment in path: /tmp/dist-test-taskBsNFja/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515386269012-14022-0/minicluster-data/ts-0-root/wals/a09e8349ab714633bf02db6f310b3411/wal-000000016 (ops 76-80)
I20260812 06:16:30.762110 14206 log.cc:1079] T a09e8349ab714633bf02db6f310b3411 P 210768fdb6d24d9f96c7ff800870e811: Deleting log segment in path: /tmp/dist-test-taskBsNFja/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515386269012-14022-0/minicluster-data/ts-0-root/wals/a09e8349ab714633bf02db6f310b3411/wal-000000017 (ops 81-84)
I20260812 06:16:30.762144 14206 log.cc:1079] T a09e8349ab714633bf02db6f310b3411 P 210768fdb6d24d9f96c7ff800870e811: Deleting log segment in path: /tmp/dist-test-taskBsNFja/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515386269012-14022-0/minicluster-data/ts-0-root/wals/a09e8349ab714633bf02db6f310b3411/wal-000000018 (ops 85-89)
I20260812 06:16:30.762181 14206 log.cc:1079] T a09e8349ab714633bf02db6f310b3411 P 210768fdb6d24d9f96c7ff800870e811: Deleting log segment in path: /tmp/dist-test-taskBsNFja/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515386269012-14022-0/minicluster-data/ts-0-root/wals/a09e8349ab714633bf02db6f310b3411/wal-000000019 (ops 90-94)
I20260812 06:16:30.762217 14206 log.cc:1079] T a09e8349ab714633bf02db6f310b3411 P 210768fdb6d24d9f96c7ff800870e811: Deleting log segment in path: /tmp/dist-test-taskBsNFja/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515386269012-14022-0/minicluster-data/ts-0-root/wals/a09e8349ab714633bf02db6f310b3411/wal-000000020 (ops 95-99)
I20260812 06:16:30.762253 14206 log.cc:1079] T a09e8349ab714633bf02db6f310b3411 P 210768fdb6d24d9f96c7ff800870e811: Deleting log segment in path: /tmp/dist-test-taskBsNFja/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515386269012-14022-0/minicluster-data/ts-0-root/wals/a09e8349ab714633bf02db6f310b3411/wal-000000021 (ops 100-104)
I20260812 06:16:30.762288 14206 log.cc:1079] T a09e8349ab714633bf02db6f310b3411 P 210768fdb6d24d9f96c7ff800870e811: Deleting log segment in path: /tmp/dist-test-taskBsNFja/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515386269012-14022-0/minicluster-data/ts-0-root/wals/a09e8349ab714633bf02db6f310b3411/wal-000000022 (ops 105-109)
I20260812 06:16:30.762323 14206 log.cc:1079] T a09e8349ab714633bf02db6f310b3411 P 210768fdb6d24d9f96c7ff800870e811: Deleting log segment in path: /tmp/dist-test-taskBsNFja/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515386269012-14022-0/minicluster-data/ts-0-root/wals/a09e8349ab714633bf02db6f310b3411/wal-000000023 (ops 110-114)
I20260812 06:16:30.762359 14206 log.cc:1079] T a09e8349ab714633bf02db6f310b3411 P 210768fdb6d24d9f96c7ff800870e811: Deleting log segment in path: /tmp/dist-test-taskBsNFja/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515386269012-14022-0/minicluster-data/ts-0-root/wals/a09e8349ab714633bf02db6f310b3411/wal-000000024 (ops 115-119)
I20260812 06:16:30.762406 14206 log.cc:1079] T a09e8349ab714633bf02db6f310b3411 P 210768fdb6d24d9f96c7ff800870e811: Deleting log segment in path: /tmp/dist-test-taskBsNFja/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515386269012-14022-0/minicluster-data/ts-0-root/wals/a09e8349ab714633bf02db6f310b3411/wal-000000025 (ops 120-124)
I20260812 06:16:30.762439 14206 log.cc:1079] T a09e8349ab714633bf02db6f310b3411 P 210768fdb6d24d9f96c7ff800870e811: Deleting log segment in path: /tmp/dist-test-taskBsNFja/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515386269012-14022-0/minicluster-data/ts-0-root/wals/a09e8349ab714633bf02db6f310b3411/wal-000000026 (ops 125-129)
I20260812 06:16:30.762473 14206 log.cc:1079] T a09e8349ab714633bf02db6f310b3411 P 210768fdb6d24d9f96c7ff800870e811: Deleting log segment in path: /tmp/dist-test-taskBsNFja/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515386269012-14022-0/minicluster-data/ts-0-root/wals/a09e8349ab714633bf02db6f310b3411/wal-000000027 (ops 130-134)
I20260812 06:16:30.795138 14206 maintenance_manager.cc:643] P 210768fdb6d24d9f96c7ff800870e811: LogGCOp(a09e8349ab714633bf02db6f310b3411) complete. Timing: real 0.033s	user 0.004s	sys 0.026s Metrics: {}
I20260812 06:16:30.795639 14324 maintenance_manager.cc:419] P 210768fdb6d24d9f96c7ff800870e811: Scheduling FlushDeltaMemStoresOp(a09e8349ab714633bf02db6f310b3411): perf score=3.181125
I20260812 06:16:30.808143 14206 maintenance_manager.cc:643] P 210768fdb6d24d9f96c7ff800870e811: FlushDeltaMemStoresOp(a09e8349ab714633bf02db6f310b3411) complete. Timing: real 0.012s	user 0.010s	sys 0.000s Metrics: {"bytes_written":4512903,"delete_count":0,"lbm_write_time_us":4711,"lbm_writes_lt_1ms":113,"reinsert_count":0,"update_count":550}
I20260812 06:16:30.808857 14324 maintenance_manager.cc:419] P 210768fdb6d24d9f96c7ff800870e811: Scheduling FlushDeltaMemStoresOp(a09e8349ab714633bf02db6f310b3411): perf score=2.188937
I20260812 06:16:30.818514 14206 maintenance_manager.cc:643] P 210768fdb6d24d9f96c7ff800870e811: FlushDeltaMemStoresOp(a09e8349ab714633bf02db6f310b3411) complete. Timing: real 0.009s	user 0.000s	sys 0.008s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3796,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:16:30.818975 14324 maintenance_manager.cc:419] P 210768fdb6d24d9f96c7ff800870e811: Scheduling UndoDeltaBlockGCOp(a09e8349ab714633bf02db6f310b3411): 527 bytes on disk
I20260812 06:16:30.819418 14206 maintenance_manager.cc:643] P 210768fdb6d24d9f96c7ff800870e811: UndoDeltaBlockGCOp(a09e8349ab714633bf02db6f310b3411) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":50,"lbm_reads_lt_1ms":4}
I20260812 06:16:30.819901 14324 maintenance_manager.cc:419] P 210768fdb6d24d9f96c7ff800870e811: Scheduling MajorDeltaCompactionOp(a09e8349ab714633bf02db6f310b3411): perf score=1.000000
I20260812 06:16:31.124943 14206 maintenance_manager.cc:643] P 210768fdb6d24d9f96c7ff800870e811: MajorDeltaCompactionOp(a09e8349ab714633bf02db6f310b3411) complete. Timing: real 0.305s	user 0.190s	sys 0.112s Metrics: {"cfile_cache_miss":1135,"cfile_cache_miss_bytes":49307566,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":5,"delta_iterators_relevant":5,"dirs.queue_time_us":95,"lbm_read_time_us":20423,"lbm_reads_lt_1ms":1175,"lbm_write_time_us":57043,"lbm_writes_lt_1ms":1143,"peak_mem_usage":137675332,"reinsert_count":0,"spinlock_wait_cycles":2816,"thread_start_us":322,"threads_started":6,"update_count":5500}
I20260812 06:16:31.125504 14324 maintenance_manager.cc:419] P 210768fdb6d24d9f96c7ff800870e811: Scheduling FlushDeltaMemStoresOp(a09e8349ab714633bf02db6f310b3411): perf score=23.024875
I20260812 06:16:31.203536 14206 maintenance_manager.cc:643] P 210768fdb6d24d9f96c7ff800870e811: FlushDeltaMemStoresOp(a09e8349ab714633bf02db6f310b3411) complete. Timing: real 0.078s	user 0.035s	sys 0.040s Metrics: {"bytes_written":25024963,"delete_count":0,"lbm_write_time_us":32272,"lbm_writes_lt_1ms":613,"reinsert_count":0,"update_count":3050}
I20260812 06:16:31.204063 14324 maintenance_manager.cc:419] P 210768fdb6d24d9f96c7ff800870e811: Scheduling FlushDeltaMemStoresOp(a09e8349ab714633bf02db6f310b3411): perf score=6.157687
I20260812 06:16:31.243033 14206 maintenance_manager.cc:643] P 210768fdb6d24d9f96c7ff800870e811: FlushDeltaMemStoresOp(a09e8349ab714633bf02db6f310b3411) complete. Timing: real 0.039s	user 0.009s	sys 0.016s Metrics: {"bytes_written":7794836,"delete_count":0,"lbm_write_time_us":10782,"lbm_writes_lt_1ms":193,"reinsert_count":0,"update_count":950}
I20260812 06:16:31.243577 14324 maintenance_manager.cc:419] P 210768fdb6d24d9f96c7ff800870e811: Scheduling FlushDeltaMemStoresOp(a09e8349ab714633bf02db6f310b3411): perf score=2.188937
I20260812 06:16:31.257647 14206 maintenance_manager.cc:643] P 210768fdb6d24d9f96c7ff800870e811: FlushDeltaMemStoresOp(a09e8349ab714633bf02db6f310b3411) complete. Timing: real 0.014s	user 0.005s	sys 0.007s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":5663,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:31.258111 14324 maintenance_manager.cc:419] P 210768fdb6d24d9f96c7ff800870e811: Scheduling MajorDeltaCompactionOp(a09e8349ab714633bf02db6f310b3411): perf score=1.000000
I20260812 06:16:31.507910 14206 maintenance_manager.cc:643] P 210768fdb6d24d9f96c7ff800870e811: MajorDeltaCompactionOp(a09e8349ab714633bf02db6f310b3411) complete. Timing: real 0.250s	user 0.195s	sys 0.050s Metrics: {"cfile_cache_miss":933,"cfile_cache_miss_bytes":41102521,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":637,"lbm_read_time_us":15460,"lbm_reads_lt_1ms":973,"lbm_write_time_us":59856,"lbm_writes_1-10_ms":4,"lbm_writes_lt_1ms":939,"mutex_wait_us":321,"peak_mem_usage":112822188,"reinsert_count":0,"spinlock_wait_cycles":2432,"update_count":4500}
I20260812 06:16:31.508574 14324 maintenance_manager.cc:419] P 210768fdb6d24d9f96c7ff800870e811: Scheduling FlushDeltaMemStoresOp(a09e8349ab714633bf02db6f310b3411): perf score=18.063937
I20260812 06:16:31.620678 14206 maintenance_manager.cc:643] P 210768fdb6d24d9f96c7ff800870e811: FlushDeltaMemStoresOp(a09e8349ab714633bf02db6f310b3411) complete. Timing: real 0.112s	user 0.042s	sys 0.069s Metrics: {"bytes_written":20512314,"delete_count":0,"lbm_write_time_us":71082,"lbm_writes_1-10_ms":5,"lbm_writes_lt_1ms":498,"reinsert_count":0,"update_count":2500}
I20260812 06:16:31.621184 14324 maintenance_manager.cc:419] P 210768fdb6d24d9f96c7ff800870e811: Scheduling FlushDeltaMemStoresOp(a09e8349ab714633bf02db6f310b3411): perf score=2.188937
I20260812 06:16:31.639024 14206 maintenance_manager.cc:643] P 210768fdb6d24d9f96c7ff800870e811: FlushDeltaMemStoresOp(a09e8349ab714633bf02db6f310b3411) complete. Timing: real 0.018s	user 0.010s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6398,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:31.639518 14324 maintenance_manager.cc:419] P 210768fdb6d24d9f96c7ff800870e811: Scheduling MajorDeltaCompactionOp(a09e8349ab714633bf02db6f310b3411): perf score=1.000000
I20260812 06:16:31.858186 14206 maintenance_manager.cc:643] P 210768fdb6d24d9f96c7ff800870e811: MajorDeltaCompactionOp(a09e8349ab714633bf02db6f310b3411) complete. Timing: real 0.218s	user 0.135s	sys 0.083s Metrics: {"cfile_cache_miss":632,"cfile_cache_miss_bytes":28795171,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":804,"lbm_read_time_us":13703,"lbm_reads_lt_1ms":664,"lbm_write_time_us":41480,"lbm_writes_lt_1ms":643,"mutex_wait_us":53,"peak_mem_usage":75542472,"reinsert_count":0,"update_count":3000}
I20260812 06:16:31.858923 14324 maintenance_manager.cc:419] P 210768fdb6d24d9f96c7ff800870e811: Scheduling FlushDeltaMemStoresOp(a09e8349ab714633bf02db6f310b3411): perf score=16.079562
I20260812 06:16:31.935640 14206 maintenance_manager.cc:643] P 210768fdb6d24d9f96c7ff800870e811: FlushDeltaMemStoresOp(a09e8349ab714633bf02db6f310b3411) complete. Timing: real 0.076s	user 0.039s	sys 0.023s Metrics: {"bytes_written":17640629,"delete_count":0,"lbm_write_time_us":33358,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":432,"reinsert_count":0,"update_count":2150}
I20260812 06:16:31.936174 14324 maintenance_manager.cc:419] P 210768fdb6d24d9f96c7ff800870e811: Scheduling FlushDeltaMemStoresOp(a09e8349ab714633bf02db6f310b3411): perf score=5.165500
I20260812 06:16:31.957190 14206 maintenance_manager.cc:643] P 210768fdb6d24d9f96c7ff800870e811: FlushDeltaMemStoresOp(a09e8349ab714633bf02db6f310b3411) complete. Timing: real 0.021s	user 0.017s	sys 0.003s Metrics: {"bytes_written":6974360,"delete_count":0,"lbm_write_time_us":8614,"lbm_writes_lt_1ms":173,"reinsert_count":0,"update_count":850}
I20260812 06:16:31.957948 14324 maintenance_manager.cc:419] P 210768fdb6d24d9f96c7ff800870e811: Scheduling MajorDeltaCompactionOp(a09e8349ab714633bf02db6f310b3411): perf score=1.000000
I20260812 06:16:32.221918 14206 maintenance_manager.cc:643] P 210768fdb6d24d9f96c7ff800870e811: MajorDeltaCompactionOp(a09e8349ab714633bf02db6f310b3411) complete. Timing: real 0.264s	user 0.134s	sys 0.117s Metrics: {"cfile_cache_miss":632,"cfile_cache_miss_bytes":28795181,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":345,"lbm_read_time_us":13989,"lbm_reads_lt_1ms":672,"lbm_write_time_us":69168,"lbm_writes_1-10_ms":8,"lbm_writes_lt_1ms":635,"mutex_wait_us":26,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":28288,"update_count":3000}
I20260812 06:16:32.222703 14324 maintenance_manager.cc:419] P 210768fdb6d24d9f96c7ff800870e811: Scheduling FlushDeltaMemStoresOp(a09e8349ab714633bf02db6f310b3411): perf score=18.063937
I20260812 06:16:32.295948 14206 maintenance_manager.cc:643] P 210768fdb6d24d9f96c7ff800870e811: FlushDeltaMemStoresOp(a09e8349ab714633bf02db6f310b3411) complete. Timing: real 0.073s	user 0.037s	sys 0.024s Metrics: {"bytes_written":20512314,"delete_count":0,"lbm_write_time_us":30594,"lbm_writes_lt_1ms":503,"reinsert_count":0,"update_count":2500}
I20260812 06:16:32.296624 14324 maintenance_manager.cc:419] P 210768fdb6d24d9f96c7ff800870e811: Scheduling FlushDeltaMemStoresOp(a09e8349ab714633bf02db6f310b3411): perf score=2.188937
I20260812 06:16:32.309808 14206 maintenance_manager.cc:643] P 210768fdb6d24d9f96c7ff800870e811: FlushDeltaMemStoresOp(a09e8349ab714633bf02db6f310b3411) complete. Timing: real 0.013s	user 0.006s	sys 0.005s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5269,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:32.310336 14324 maintenance_manager.cc:419] P 210768fdb6d24d9f96c7ff800870e811: Scheduling FlushMRSOp(a09e8349ab714633bf02db6f310b3411): perf score=1.000000
I20260812 06:16:32.342546 14206 maintenance_manager.cc:643] P 210768fdb6d24d9f96c7ff800870e811: FlushMRSOp(a09e8349ab714633bf02db6f310b3411) complete. Timing: real 0.032s	user 0.028s	sys 0.003s Metrics: {"bytes_written":1193507,"cfile_init":1,"dirs.queue_time_us":52,"dirs.run_cpu_time_us":204,"dirs.run_wall_time_us":1272,"drs_written":1,"lbm_read_time_us":50,"lbm_reads_lt_1ms":4,"lbm_write_time_us":2701,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":29}
I20260812 06:16:32.343286 14324 maintenance_manager.cc:419] P 210768fdb6d24d9f96c7ff800870e811: Scheduling LogGCOp(a09e8349ab714633bf02db6f310b3411): free 121006648 bytes of WAL
I20260812 06:16:32.343536 14206 log_reader.cc:385] T a09e8349ab714633bf02db6f310b3411: removed 12 log segments from log reader
I20260812 06:16:32.343590 14206 log.cc:1079] T a09e8349ab714633bf02db6f310b3411 P 210768fdb6d24d9f96c7ff800870e811: Deleting log segment in path: /tmp/dist-test-taskBsNFja/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515386269012-14022-0/minicluster-data/ts-0-root/wals/a09e8349ab714633bf02db6f310b3411/wal-000000028 (ops 135-139)
I20260812 06:16:32.343648 14206 log.cc:1079] T a09e8349ab714633bf02db6f310b3411 P 210768fdb6d24d9f96c7ff800870e811: Deleting log segment in path: /tmp/dist-test-taskBsNFja/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515386269012-14022-0/minicluster-data/ts-0-root/wals/a09e8349ab714633bf02db6f310b3411/wal-000000029 (ops 140-144)
I20260812 06:16:32.343698 14206 log.cc:1079] T a09e8349ab714633bf02db6f310b3411 P 210768fdb6d24d9f96c7ff800870e811: Deleting log segment in path: /tmp/dist-test-taskBsNFja/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515386269012-14022-0/minicluster-data/ts-0-root/wals/a09e8349ab714633bf02db6f310b3411/wal-000000030 (ops 145-149)
I20260812 06:16:32.343750 14206 log.cc:1079] T a09e8349ab714633bf02db6f310b3411 P 210768fdb6d24d9f96c7ff800870e811: Deleting log segment in path: /tmp/dist-test-taskBsNFja/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515386269012-14022-0/minicluster-data/ts-0-root/wals/a09e8349ab714633bf02db6f310b3411/wal-000000031 (ops 150-154)
I20260812 06:16:32.343796 14206 log.cc:1079] T a09e8349ab714633bf02db6f310b3411 P 210768fdb6d24d9f96c7ff800870e811: Deleting log segment in path: /tmp/dist-test-taskBsNFja/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515386269012-14022-0/minicluster-data/ts-0-root/wals/a09e8349ab714633bf02db6f310b3411/wal-000000032 (ops 155-158)
I20260812 06:16:32.343864 14206 log.cc:1079] T a09e8349ab714633bf02db6f310b3411 P 210768fdb6d24d9f96c7ff800870e811: Deleting log segment in path: /tmp/dist-test-taskBsNFja/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515386269012-14022-0/minicluster-data/ts-0-root/wals/a09e8349ab714633bf02db6f310b3411/wal-000000033 (ops 159-163)
I20260812 06:16:32.343912 14206 log.cc:1079] T a09e8349ab714633bf02db6f310b3411 P 210768fdb6d24d9f96c7ff800870e811: Deleting log segment in path: /tmp/dist-test-taskBsNFja/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515386269012-14022-0/minicluster-data/ts-0-root/wals/a09e8349ab714633bf02db6f310b3411/wal-000000034 (ops 164-168)
I20260812 06:16:32.343971 14206 log.cc:1079] T a09e8349ab714633bf02db6f310b3411 P 210768fdb6d24d9f96c7ff800870e811: Deleting log segment in path: /tmp/dist-test-taskBsNFja/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515386269012-14022-0/minicluster-data/ts-0-root/wals/a09e8349ab714633bf02db6f310b3411/wal-000000035 (ops 169-173)
I20260812 06:16:32.344013 14206 log.cc:1079] T a09e8349ab714633bf02db6f310b3411 P 210768fdb6d24d9f96c7ff800870e811: Deleting log segment in path: /tmp/dist-test-taskBsNFja/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515386269012-14022-0/minicluster-data/ts-0-root/wals/a09e8349ab714633bf02db6f310b3411/wal-000000036 (ops 174-178)
I20260812 06:16:32.344062 14206 log.cc:1079] T a09e8349ab714633bf02db6f310b3411 P 210768fdb6d24d9f96c7ff800870e811: Deleting log segment in path: /tmp/dist-test-taskBsNFja/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515386269012-14022-0/minicluster-data/ts-0-root/wals/a09e8349ab714633bf02db6f310b3411/wal-000000037 (ops 179-183)
I20260812 06:16:32.344107 14206 log.cc:1079] T a09e8349ab714633bf02db6f310b3411 P 210768fdb6d24d9f96c7ff800870e811: Deleting log segment in path: /tmp/dist-test-taskBsNFja/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515386269012-14022-0/minicluster-data/ts-0-root/wals/a09e8349ab714633bf02db6f310b3411/wal-000000038 (ops 184-188)
I20260812 06:16:32.344152 14206 log.cc:1079] T a09e8349ab714633bf02db6f310b3411 P 210768fdb6d24d9f96c7ff800870e811: Deleting log segment in path: /tmp/dist-test-taskBsNFja/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515386269012-14022-0/minicluster-data/ts-0-root/wals/a09e8349ab714633bf02db6f310b3411/wal-000000039 (ops 189-193)
I20260812 06:16:32.368722 14206 maintenance_manager.cc:643] P 210768fdb6d24d9f96c7ff800870e811: LogGCOp(a09e8349ab714633bf02db6f310b3411) complete. Timing: real 0.025s	user 0.000s	sys 0.025s Metrics: {}
I20260812 06:16:32.369117 14324 maintenance_manager.cc:419] P 210768fdb6d24d9f96c7ff800870e811: Scheduling FlushDeltaMemStoresOp(a09e8349ab714633bf02db6f310b3411): perf score=3.181125
I20260812 06:16:32.390831 14206 maintenance_manager.cc:643] P 210768fdb6d24d9f96c7ff800870e811: FlushDeltaMemStoresOp(a09e8349ab714633bf02db6f310b3411) complete. Timing: real 0.021s	user 0.009s	sys 0.007s Metrics: {"bytes_written":4512903,"delete_count":0,"lbm_write_time_us":6954,"lbm_writes_lt_1ms":113,"reinsert_count":0,"update_count":550}
I20260812 06:16:32.391443 14324 maintenance_manager.cc:419] P 210768fdb6d24d9f96c7ff800870e811: Scheduling UndoDeltaBlockGCOp(a09e8349ab714633bf02db6f310b3411): 462 bytes on disk
I20260812 06:16:32.391964 14206 maintenance_manager.cc:643] P 210768fdb6d24d9f96c7ff800870e811: UndoDeltaBlockGCOp(a09e8349ab714633bf02db6f310b3411) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":73,"lbm_reads_lt_1ms":4}
I20260812 06:16:32.392467 14324 maintenance_manager.cc:419] P 210768fdb6d24d9f96c7ff800870e811: Scheduling FlushDeltaMemStoresOp(a09e8349ab714633bf02db6f310b3411): perf score=2.188937
I20260812 06:16:32.401763 14206 maintenance_manager.cc:643] P 210768fdb6d24d9f96c7ff800870e811: FlushDeltaMemStoresOp(a09e8349ab714633bf02db6f310b3411) complete. Timing: real 0.009s	user 0.003s	sys 0.005s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3479,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:16:32.402187 14324 maintenance_manager.cc:419] P 210768fdb6d24d9f96c7ff800870e811: Scheduling MajorDeltaCompactionOp(a09e8349ab714633bf02db6f310b3411): perf score=1.000000
I20260812 06:16:32.490698 14022 heavy-update-compaction-itest.cc:229] Time spent updating: real 5.882s	user 1.932s	sys 0.135s
I20260812 06:16:32.617084 14022 heavy-update-compaction-itest.cc:265] Time spent scanning: real 0.126s	user 0.003s	sys 0.000s
I20260812 06:16:32.617695 14022 tablet_server.cc:179] TabletServer@127.13.177.129:0 shutting down...
I20260812 06:16:32.649947 14206 maintenance_manager.cc:643] P 210768fdb6d24d9f96c7ff800870e811: MajorDeltaCompactionOp(a09e8349ab714633bf02db6f310b3411) complete. Timing: real 0.248s	user 0.170s	sys 0.076s Metrics: {"cfile_cache_miss":834,"cfile_cache_miss_bytes":37000223,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":2082,"lbm_read_time_us":17608,"lbm_reads_lt_1ms":870,"lbm_write_time_us":46994,"lbm_writes_lt_1ms":843,"mutex_wait_us":1486,"peak_mem_usage":100395616,"reinsert_count":0,"spinlock_wait_cycles":28032,"thread_start_us":77,"threads_started":1,"update_count":4000}
I20260812 06:16:32.650635 14022 ts_tablet_manager.cc:1507] Shutting down tablet manager...
I20260812 06:16:32.651113 14022 tablet_replica.cc:333] T a09e8349ab714633bf02db6f310b3411 P 210768fdb6d24d9f96c7ff800870e811: stopping tablet replica
I20260812 06:16:32.651350 14022 raft_consensus.cc:2243] T a09e8349ab714633bf02db6f310b3411 P 210768fdb6d24d9f96c7ff800870e811 [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:16:32.651643 14022 raft_consensus.cc:2272] T a09e8349ab714633bf02db6f310b3411 P 210768fdb6d24d9f96c7ff800870e811 [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:16:32.668329 14022 tablet_server.cc:196] TabletServer@127.13.177.129:0 shutdown complete.
I20260812 06:16:32.720610 14022 master.cc:562] Master@127.13.177.190:45661 shutting down...
I20260812 06:16:32.724237 14022 raft_consensus.cc:2243] T 00000000000000000000000000000000 P be1515567e1d4bf2811ab3407d2afc71 [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:16:32.724427 14022 raft_consensus.cc:2272] T 00000000000000000000000000000000 P be1515567e1d4bf2811ab3407d2afc71 [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:16:32.724583 14022 tablet_replica.cc:333] T 00000000000000000000000000000000 P be1515567e1d4bf2811ab3407d2afc71: stopping tablet replica
I20260812 06:16:32.737032 14022 master.cc:584] Master@127.13.177.190:45661 shutdown complete.
[       OK ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/0 (6541 ms)
[ RUN      ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/1
I20260812 06:16:32.820976 14022 internal_mini_cluster.cc:156] Creating distributed mini masters. Addrs: 127.13.177.190:36421
I20260812 06:16:32.821391 14022 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:16:32.823524 14424 instance_detector.cc:116] could not retrieve Azure instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:16:32.823601 14022 server_base.cc:1061] running on GCE node
W20260812 06:16:32.823621 14427 instance_detector.cc:116] could not retrieve OpenStack instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:16:32.823566 14423 instance_detector.cc:116] could not retrieve AWS instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:16:32.824002 14022 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:16:32.824064 14022 system_unsync_time.cc:38] NTP support is disabled. Clock error bounds will not be accurate. This configuration is not suitable for distributed clusters.
I20260812 06:16:32.824080 14022 hybrid_clock.cc:648] HybridClock initialized: now 1786515392824080 us; error 0 us; skew 500 ppm
I20260812 06:16:32.824972 14022 webserver.cc:533] Webserver started at http://127.13.177.190:34259/ using document root <none> and password file <none>
I20260812 06:16:32.825162 14022 fs_manager.cc:362] Metadata directory not provided
I20260812 06:16:32.825230 14022 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:16:32.825313 14022 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:16:32.825719 14022 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskBsNFja/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515386269012-14022-0/minicluster-data/master-0-root/instance:
uuid: "6654f7b70ce0435b97f7fefebff5ffff"
format_stamp: "Formatted at 2026-08-12 06:16:32 on dist-test-slave-rwrg"
I20260812 06:16:32.827216 14022 fs_manager.cc:696] Time spent creating directory manager: real 0.001s	user 0.002s	sys 0.000s
I20260812 06:16:32.828099 14437 log_block_manager.cc:4127] Time spent loading block containers with low live blocks: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:16:32.828361 14022 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.001s	sys 0.000s
I20260812 06:16:32.828424 14022 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskBsNFja/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515386269012-14022-0/minicluster-data/master-0-root
uuid: "6654f7b70ce0435b97f7fefebff5ffff"
format_stamp: "Formatted at 2026-08-12 06:16:32 on dist-test-slave-rwrg"
I20260812 06:16:32.828565 14022 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskBsNFja/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515386269012-14022-0/minicluster-data/master-0-root
metadata directory: /tmp/dist-test-taskBsNFja/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515386269012-14022-0/minicluster-data/master-0-root
1 data directories: /tmp/dist-test-taskBsNFja/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515386269012-14022-0/minicluster-data/master-0-root/data
Total live blocks: 0
Total live bytes: 0
Total live bytes (after alignment): 0
Total number of LBM containers: 0 (0 full)
Did not check for missing blocks
Did not check for orphaned blocks
Total full LBM containers with extra space: 0 (0 repaired)
Total full LBM container extra space in bytes: 0 (0 repaired)
Total incomplete LBM containers: 0 (0 repaired)
Total LBM partial records: 0 (0 repaired)
Total corrupted LBM metadata records in RocksDB: 0 (0 repaired)
I20260812 06:16:32.834339 14022 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:16:32.834714 14022 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:16:32.839067 14022 rpc_server.cc:307] RPC server started. Bound to: 127.13.177.190:36421
I20260812 06:16:32.842377 14560 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet 00000000000000000000000000000000. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:16:32.842764 14557 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.13.177.190:36421 every 8 connection(s)
I20260812 06:16:32.861486 14560 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P 6654f7b70ce0435b97f7fefebff5ffff: Bootstrap starting.
I20260812 06:16:32.862385 14560 tablet_bootstrap.cc:654] T 00000000000000000000000000000000 P 6654f7b70ce0435b97f7fefebff5ffff: Neither blocks nor log segments found. Creating new log.
I20260812 06:16:32.863517 14560 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P 6654f7b70ce0435b97f7fefebff5ffff: No bootstrap required, opened a new log
I20260812 06:16:32.863931 14560 raft_consensus.cc:359] T 00000000000000000000000000000000 P 6654f7b70ce0435b97f7fefebff5ffff [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "6654f7b70ce0435b97f7fefebff5ffff" member_type: VOTER }
I20260812 06:16:32.864020 14560 raft_consensus.cc:385] T 00000000000000000000000000000000 P 6654f7b70ce0435b97f7fefebff5ffff [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:16:32.864079 14560 raft_consensus.cc:740] T 00000000000000000000000000000000 P 6654f7b70ce0435b97f7fefebff5ffff [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: 6654f7b70ce0435b97f7fefebff5ffff, State: Initialized, Role: FOLLOWER
I20260812 06:16:32.864271 14560 consensus_queue.cc:260] T 00000000000000000000000000000000 P 6654f7b70ce0435b97f7fefebff5ffff [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: "6654f7b70ce0435b97f7fefebff5ffff" member_type: VOTER }
I20260812 06:16:32.864344 14560 raft_consensus.cc:399] T 00000000000000000000000000000000 P 6654f7b70ce0435b97f7fefebff5ffff [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:16:32.864411 14560 raft_consensus.cc:493] T 00000000000000000000000000000000 P 6654f7b70ce0435b97f7fefebff5ffff [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:16:32.864472 14560 raft_consensus.cc:3060] T 00000000000000000000000000000000 P 6654f7b70ce0435b97f7fefebff5ffff [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:16:32.865224 14560 raft_consensus.cc:515] T 00000000000000000000000000000000 P 6654f7b70ce0435b97f7fefebff5ffff [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "6654f7b70ce0435b97f7fefebff5ffff" member_type: VOTER }
I20260812 06:16:32.865372 14560 leader_election.cc:304] T 00000000000000000000000000000000 P 6654f7b70ce0435b97f7fefebff5ffff [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: 6654f7b70ce0435b97f7fefebff5ffff; no voters: 
I20260812 06:16:32.865600 14560 leader_election.cc:290] T 00000000000000000000000000000000 P 6654f7b70ce0435b97f7fefebff5ffff [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:16:32.865731 14565 raft_consensus.cc:2804] T 00000000000000000000000000000000 P 6654f7b70ce0435b97f7fefebff5ffff [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:16:32.865962 14565 raft_consensus.cc:697] T 00000000000000000000000000000000 P 6654f7b70ce0435b97f7fefebff5ffff [term 1 LEADER]: Becoming Leader. State: Replica: 6654f7b70ce0435b97f7fefebff5ffff, State: Running, Role: LEADER
I20260812 06:16:32.866065 14560 sys_catalog.cc:565] T 00000000000000000000000000000000 P 6654f7b70ce0435b97f7fefebff5ffff [sys.catalog]: configured and running, proceeding with master startup.
I20260812 06:16:32.866175 14565 consensus_queue.cc:237] T 00000000000000000000000000000000 P 6654f7b70ce0435b97f7fefebff5ffff [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: "6654f7b70ce0435b97f7fefebff5ffff" member_type: VOTER }
I20260812 06:16:32.866621 14567 sys_catalog.cc:455] T 00000000000000000000000000000000 P 6654f7b70ce0435b97f7fefebff5ffff [sys.catalog]: SysCatalogTable state changed. Reason: RaftConsensus started. Latest consensus state: current_term: 1 leader_uuid: "6654f7b70ce0435b97f7fefebff5ffff" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "6654f7b70ce0435b97f7fefebff5ffff" member_type: VOTER } }
I20260812 06:16:32.866748 14567 sys_catalog.cc:458] T 00000000000000000000000000000000 P 6654f7b70ce0435b97f7fefebff5ffff [sys.catalog]: This master's current role is: LEADER
I20260812 06:16:32.866637 14568 sys_catalog.cc:455] T 00000000000000000000000000000000 P 6654f7b70ce0435b97f7fefebff5ffff [sys.catalog]: SysCatalogTable state changed. Reason: New leader 6654f7b70ce0435b97f7fefebff5ffff. Latest consensus state: current_term: 1 leader_uuid: "6654f7b70ce0435b97f7fefebff5ffff" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "6654f7b70ce0435b97f7fefebff5ffff" member_type: VOTER } }
I20260812 06:16:32.866955 14568 sys_catalog.cc:458] T 00000000000000000000000000000000 P 6654f7b70ce0435b97f7fefebff5ffff [sys.catalog]: This master's current role is: LEADER
I20260812 06:16:32.867007 14576 catalog_manager.cc:1511] Loading table and tablet metadata into memory...
I20260812 06:16:32.867848 14576 catalog_manager.cc:1520] Initializing Kudu cluster ID...
I20260812 06:16:32.868076 14022 internal_mini_cluster.cc:184] Waiting to initialize catalog manager on master 0
I20260812 06:16:32.869681 14576 catalog_manager.cc:1383] Generated new cluster ID: a048aa7e10104153b14b3f5f58c02327
I20260812 06:16:32.869745 14576 catalog_manager.cc:1531] Initializing Kudu internal certificate authority...
I20260812 06:16:32.894069 14576 catalog_manager.cc:1406] Generated new certificate authority record
I20260812 06:16:32.894702 14576 catalog_manager.cc:1540] Loading token signing keys...
I20260812 06:16:32.903802 14576 catalog_manager.cc:6092] T 00000000000000000000000000000000 P 6654f7b70ce0435b97f7fefebff5ffff: Generated new TSK 0
I20260812 06:16:32.903952 14576 catalog_manager.cc:1550] Initializing in-progress tserver states...
I20260812 06:16:32.932721 14022 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:16:32.934607 14599 instance_detector.cc:116] could not retrieve AWS instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:16:32.934731 14601 instance_detector.cc:116] could not retrieve Azure instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:16:32.934731 14603 instance_detector.cc:116] could not retrieve OpenStack instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:16:32.934933 14022 server_base.cc:1061] running on GCE node
I20260812 06:16:32.935107 14022 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:16:32.935158 14022 system_unsync_time.cc:38] NTP support is disabled. Clock error bounds will not be accurate. This configuration is not suitable for distributed clusters.
I20260812 06:16:32.935173 14022 hybrid_clock.cc:648] HybridClock initialized: now 1786515392935174 us; error 0 us; skew 500 ppm
I20260812 06:16:32.936086 14022 webserver.cc:533] Webserver started at http://127.13.177.129:44221/ using document root <none> and password file <none>
I20260812 06:16:32.936267 14022 fs_manager.cc:362] Metadata directory not provided
I20260812 06:16:32.936327 14022 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:16:32.936429 14022 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:16:32.936897 14022 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskBsNFja/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515386269012-14022-0/minicluster-data/ts-0-root/instance:
uuid: "1c3f185fe7da4c38acee9da60c33f143"
format_stamp: "Formatted at 2026-08-12 06:16:32 on dist-test-slave-rwrg"
I20260812 06:16:32.938413 14022 fs_manager.cc:696] Time spent creating directory manager: real 0.001s	user 0.002s	sys 0.000s
I20260812 06:16:32.939318 14617 log_block_manager.cc:4127] Time spent loading block containers with low live blocks: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:16:32.939575 14022 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.001s	sys 0.000s
I20260812 06:16:32.939649 14022 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskBsNFja/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515386269012-14022-0/minicluster-data/ts-0-root
uuid: "1c3f185fe7da4c38acee9da60c33f143"
format_stamp: "Formatted at 2026-08-12 06:16:32 on dist-test-slave-rwrg"
I20260812 06:16:32.939702 14022 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskBsNFja/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515386269012-14022-0/minicluster-data/ts-0-root
metadata directory: /tmp/dist-test-taskBsNFja/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515386269012-14022-0/minicluster-data/ts-0-root
1 data directories: /tmp/dist-test-taskBsNFja/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515386269012-14022-0/minicluster-data/ts-0-root/data
Total live blocks: 0
Total live bytes: 0
Total live bytes (after alignment): 0
Total number of LBM containers: 0 (0 full)
Did not check for missing blocks
Did not check for orphaned blocks
Total full LBM containers with extra space: 0 (0 repaired)
Total full LBM container extra space in bytes: 0 (0 repaired)
Total incomplete LBM containers: 0 (0 repaired)
Total LBM partial records: 0 (0 repaired)
Total corrupted LBM metadata records in RocksDB: 0 (0 repaired)
I20260812 06:16:32.973946 14022 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:16:32.974291 14022 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:16:32.974555 14022 txn_system_client.cc:432] TxnSystemClient initialization is disabled...
I20260812 06:16:32.975067 14022 ts_tablet_manager.cc:585] Loaded tablet metadata (0 total tablets, 0 live tablets)
I20260812 06:16:32.975107 14022 ts_tablet_manager.cc:531] Time spent load tablet metadata: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:16:32.975140 14022 ts_tablet_manager.cc:616] Registered 0 tablets
I20260812 06:16:32.975199 14022 ts_tablet_manager.cc:595] Time spent register tablets: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:16:32.979754 14022 rpc_server.cc:307] RPC server started. Bound to: 127.13.177.129:45501
I20260812 06:16:32.979835 14735 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.13.177.129:45501 every 8 connection(s)
I20260812 06:16:32.986617 14737 heartbeater.cc:344] Connected to a master server at 127.13.177.190:36421
I20260812 06:16:32.986730 14737 heartbeater.cc:461] Registering TS with master...
I20260812 06:16:32.986903 14737 heartbeater.cc:507] Master 127.13.177.190:36421 requested a full tablet report, sending...
I20260812 06:16:32.987545 14469 ts_manager.cc:194] Registered new tserver with Master: 1c3f185fe7da4c38acee9da60c33f143 (127.13.177.129:45501)
I20260812 06:16:32.987991 14022 internal_mini_cluster.cc:371] 1 TS(s) registered with all masters after 0.007766s
I20260812 06:16:32.988287 14469 master_service.cc:502] Signed X509 certificate for tserver {username='slave'} at 127.0.0.1:56242
I20260812 06:16:32.994997 14469 catalog_manager.cc:2283] Servicing CreateTable request from {username='slave'} at 127.0.0.1:56254:
name: "heavy-update-compaction-test"
schema {
  columns {
    name: "key"
    type: INT64
    is_key: true
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_a"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_b"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_c"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_d"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_e"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
}
num_replicas: 1
split_rows_range_bounds {
}
partition_schema {
  range_schema {
  }
}
I20260812 06:16:33.003669 14661 tablet_service.cc:1511] Processing CreateTablet for tablet e4d13557f1e0463e846ffed5b9eb6ab5 (DEFAULT_TABLE table=heavy-update-compaction-test [id=4b3c75b980f444b9854acc09087429b7]), partition=
I20260812 06:16:33.003952 14661 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet e4d13557f1e0463e846ffed5b9eb6ab5. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:16:33.005942 14765 tablet_bootstrap.cc:492] T e4d13557f1e0463e846ffed5b9eb6ab5 P 1c3f185fe7da4c38acee9da60c33f143: Bootstrap starting.
I20260812 06:16:33.006863 14765 tablet_bootstrap.cc:654] T e4d13557f1e0463e846ffed5b9eb6ab5 P 1c3f185fe7da4c38acee9da60c33f143: Neither blocks nor log segments found. Creating new log.
I20260812 06:16:33.008430 14765 tablet_bootstrap.cc:492] T e4d13557f1e0463e846ffed5b9eb6ab5 P 1c3f185fe7da4c38acee9da60c33f143: No bootstrap required, opened a new log
I20260812 06:16:33.008548 14765 ts_tablet_manager.cc:1403] T e4d13557f1e0463e846ffed5b9eb6ab5 P 1c3f185fe7da4c38acee9da60c33f143: Time spent bootstrapping tablet: real 0.003s	user 0.002s	sys 0.000s
I20260812 06:16:33.008983 14765 raft_consensus.cc:359] T e4d13557f1e0463e846ffed5b9eb6ab5 P 1c3f185fe7da4c38acee9da60c33f143 [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "1c3f185fe7da4c38acee9da60c33f143" member_type: VOTER last_known_addr { host: "127.13.177.129" port: 45501 } }
I20260812 06:16:33.009109 14765 raft_consensus.cc:385] T e4d13557f1e0463e846ffed5b9eb6ab5 P 1c3f185fe7da4c38acee9da60c33f143 [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:16:33.009159 14765 raft_consensus.cc:740] T e4d13557f1e0463e846ffed5b9eb6ab5 P 1c3f185fe7da4c38acee9da60c33f143 [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: 1c3f185fe7da4c38acee9da60c33f143, State: Initialized, Role: FOLLOWER
I20260812 06:16:33.009315 14765 consensus_queue.cc:260] T e4d13557f1e0463e846ffed5b9eb6ab5 P 1c3f185fe7da4c38acee9da60c33f143 [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: "1c3f185fe7da4c38acee9da60c33f143" member_type: VOTER last_known_addr { host: "127.13.177.129" port: 45501 } }
I20260812 06:16:33.009416 14765 raft_consensus.cc:399] T e4d13557f1e0463e846ffed5b9eb6ab5 P 1c3f185fe7da4c38acee9da60c33f143 [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:16:33.009477 14765 raft_consensus.cc:493] T e4d13557f1e0463e846ffed5b9eb6ab5 P 1c3f185fe7da4c38acee9da60c33f143 [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:16:33.009537 14765 raft_consensus.cc:3060] T e4d13557f1e0463e846ffed5b9eb6ab5 P 1c3f185fe7da4c38acee9da60c33f143 [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:16:33.010267 14765 raft_consensus.cc:515] T e4d13557f1e0463e846ffed5b9eb6ab5 P 1c3f185fe7da4c38acee9da60c33f143 [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "1c3f185fe7da4c38acee9da60c33f143" member_type: VOTER last_known_addr { host: "127.13.177.129" port: 45501 } }
I20260812 06:16:33.010380 14765 leader_election.cc:304] T e4d13557f1e0463e846ffed5b9eb6ab5 P 1c3f185fe7da4c38acee9da60c33f143 [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: 1c3f185fe7da4c38acee9da60c33f143; no voters: 
I20260812 06:16:33.010526 14765 leader_election.cc:290] T e4d13557f1e0463e846ffed5b9eb6ab5 P 1c3f185fe7da4c38acee9da60c33f143 [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:16:33.010672 14769 raft_consensus.cc:2804] T e4d13557f1e0463e846ffed5b9eb6ab5 P 1c3f185fe7da4c38acee9da60c33f143 [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:16:33.010828 14765 ts_tablet_manager.cc:1434] T e4d13557f1e0463e846ffed5b9eb6ab5 P 1c3f185fe7da4c38acee9da60c33f143: Time spent starting tablet: real 0.002s	user 0.002s	sys 0.000s
I20260812 06:16:33.010838 14737 heartbeater.cc:499] Master 127.13.177.190:36421 was elected leader, sending a full tablet report...
I20260812 06:16:33.010910 14769 raft_consensus.cc:697] T e4d13557f1e0463e846ffed5b9eb6ab5 P 1c3f185fe7da4c38acee9da60c33f143 [term 1 LEADER]: Becoming Leader. State: Replica: 1c3f185fe7da4c38acee9da60c33f143, State: Running, Role: LEADER
I20260812 06:16:33.011029 14769 consensus_queue.cc:237] T e4d13557f1e0463e846ffed5b9eb6ab5 P 1c3f185fe7da4c38acee9da60c33f143 [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: "1c3f185fe7da4c38acee9da60c33f143" member_type: VOTER last_known_addr { host: "127.13.177.129" port: 45501 } }
I20260812 06:16:33.012323 14469 catalog_manager.cc:5719] T e4d13557f1e0463e846ffed5b9eb6ab5 P 1c3f185fe7da4c38acee9da60c33f143 reported cstate change: term changed from 0 to 1, leader changed from <none> to 1c3f185fe7da4c38acee9da60c33f143 (127.13.177.129). New cstate: current_term: 1 leader_uuid: "1c3f185fe7da4c38acee9da60c33f143" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "1c3f185fe7da4c38acee9da60c33f143" member_type: VOTER last_known_addr { host: "127.13.177.129" port: 45501 } health_report { overall_health: HEALTHY } } }
I20260812 06:16:33.074304 14022 heavy-update-compaction-itest.cc:215] Time spent inserting: real 0.055s	user 0.017s	sys 0.008s
I20260812 06:16:33.230726 14738 maintenance_manager.cc:419] P 1c3f185fe7da4c38acee9da60c33f143: Scheduling FlushMRSOp(e4d13557f1e0463e846ffed5b9eb6ab5): perf score=19.054940
I20260812 06:16:33.374897 14624 maintenance_manager.cc:643] P 1c3f185fe7da4c38acee9da60c33f143: FlushMRSOp(e4d13557f1e0463e846ffed5b9eb6ab5) complete. Timing: real 0.144s	user 0.114s	sys 0.028s Metrics: {"bytes_written":12635684,"cfile_init":1,"delete_count":0,"dirs.queue_time_us":76,"dirs.run_cpu_time_us":187,"dirs.run_wall_time_us":822,"drs_written":1,"lbm_read_time_us":92,"lbm_reads_lt_1ms":4,"lbm_write_time_us":35953,"lbm_writes_lt_1ms":765,"peak_mem_usage":0,"reinsert_count":0,"rows_written":104,"spinlock_wait_cycles":22656,"update_count":1540}
I20260812 06:16:33.375727 14738 maintenance_manager.cc:419] P 1c3f185fe7da4c38acee9da60c33f143: Scheduling LogGCOp(e4d13557f1e0463e846ffed5b9eb6ab5): free 20743880 bytes of WAL
I20260812 06:16:33.375955 14624 log_reader.cc:385] T e4d13557f1e0463e846ffed5b9eb6ab5: removed 2 log segments from log reader
I20260812 06:16:33.376011 14624 log.cc:1079] T e4d13557f1e0463e846ffed5b9eb6ab5 P 1c3f185fe7da4c38acee9da60c33f143: Deleting log segment in path: /tmp/dist-test-taskBsNFja/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515386269012-14022-0/minicluster-data/ts-0-root/wals/e4d13557f1e0463e846ffed5b9eb6ab5/wal-000000001 (ops 1-6)
I20260812 06:16:33.376066 14624 log.cc:1079] T e4d13557f1e0463e846ffed5b9eb6ab5 P 1c3f185fe7da4c38acee9da60c33f143: Deleting log segment in path: /tmp/dist-test-taskBsNFja/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515386269012-14022-0/minicluster-data/ts-0-root/wals/e4d13557f1e0463e846ffed5b9eb6ab5/wal-000000002 (ops 7-11)
I20260812 06:16:33.381531 14624 maintenance_manager.cc:643] P 1c3f185fe7da4c38acee9da60c33f143: LogGCOp(e4d13557f1e0463e846ffed5b9eb6ab5) complete. Timing: real 0.006s	user 0.000s	sys 0.005s Metrics: {}
I20260812 06:16:33.381964 14738 maintenance_manager.cc:419] P 1c3f185fe7da4c38acee9da60c33f143: Scheduling UndoDeltaBlockGCOp(e4d13557f1e0463e846ffed5b9eb6ab5): 16411391 bytes on disk
I20260812 06:16:33.382467 14624 maintenance_manager.cc:643] P 1c3f185fe7da4c38acee9da60c33f143: UndoDeltaBlockGCOp(e4d13557f1e0463e846ffed5b9eb6ab5) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":85,"lbm_reads_lt_1ms":4}
I20260812 06:16:33.383093 14738 maintenance_manager.cc:419] P 1c3f185fe7da4c38acee9da60c33f143: Scheduling FlushDeltaMemStoresOp(e4d13557f1e0463e846ffed5b9eb6ab5): perf score=2.188937
I20260812 06:16:33.396304 14624 maintenance_manager.cc:643] P 1c3f185fe7da4c38acee9da60c33f143: FlushDeltaMemStoresOp(e4d13557f1e0463e846ffed5b9eb6ab5) complete. Timing: real 0.013s	user 0.006s	sys 0.005s Metrics: {"bytes_written":3774459,"delete_count":0,"lbm_write_time_us":4974,"lbm_writes_lt_1ms":95,"reinsert_count":0,"update_count":460}
I20260812 06:16:33.396781 14738 maintenance_manager.cc:419] P 1c3f185fe7da4c38acee9da60c33f143: Scheduling MajorDeltaCompactionOp(e4d13557f1e0463e846ffed5b9eb6ab5): perf score=1.000000
I20260812 06:16:33.541004 14624 maintenance_manager.cc:643] P 1c3f185fe7da4c38acee9da60c33f143: MajorDeltaCompactionOp(e4d13557f1e0463e846ffed5b9eb6ab5) complete. Timing: real 0.144s	user 0.093s	sys 0.048s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672271,"cfile_init":7,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":729,"lbm_read_time_us":9846,"lbm_reads_lt_1ms":460,"lbm_write_time_us":24316,"lbm_writes_lt_1ms":443,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":2816,"thread_start_us":322,"threads_started":5,"update_count":2000}
I20260812 06:16:33.541632 14738 maintenance_manager.cc:419] P 1c3f185fe7da4c38acee9da60c33f143: Scheduling FlushDeltaMemStoresOp(e4d13557f1e0463e846ffed5b9eb6ab5): perf score=11.118625
I20260812 06:16:33.579818 14624 maintenance_manager.cc:643] P 1c3f185fe7da4c38acee9da60c33f143: FlushDeltaMemStoresOp(e4d13557f1e0463e846ffed5b9eb6ab5) complete. Timing: real 0.038s	user 0.012s	sys 0.023s Metrics: {"bytes_written":12717736,"delete_count":0,"lbm_write_time_us":15630,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":312,"reinsert_count":0,"update_count":1550}
I20260812 06:16:33.580660 14738 maintenance_manager.cc:419] P 1c3f185fe7da4c38acee9da60c33f143: Scheduling FlushDeltaMemStoresOp(e4d13557f1e0463e846ffed5b9eb6ab5): perf score=2.188937
I20260812 06:16:33.597472 14624 maintenance_manager.cc:643] P 1c3f185fe7da4c38acee9da60c33f143: FlushDeltaMemStoresOp(e4d13557f1e0463e846ffed5b9eb6ab5) complete. Timing: real 0.017s	user 0.012s	sys 0.001s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":5376,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:16:33.597980 14738 maintenance_manager.cc:419] P 1c3f185fe7da4c38acee9da60c33f143: Scheduling MajorDeltaCompactionOp(e4d13557f1e0463e846ffed5b9eb6ab5): perf score=1.000000
I20260812 06:16:33.723269 14624 maintenance_manager.cc:643] P 1c3f185fe7da4c38acee9da60c33f143: MajorDeltaCompactionOp(e4d13557f1e0463e846ffed5b9eb6ab5) complete. Timing: real 0.125s	user 0.096s	sys 0.028s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672269,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":438,"lbm_read_time_us":7060,"lbm_reads_lt_1ms":464,"lbm_write_time_us":25091,"lbm_writes_lt_1ms":443,"mutex_wait_us":189,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":2560,"update_count":2000}
I20260812 06:16:33.727692 14738 maintenance_manager.cc:419] P 1c3f185fe7da4c38acee9da60c33f143: Scheduling FlushDeltaMemStoresOp(e4d13557f1e0463e846ffed5b9eb6ab5): perf score=11.118625
I20260812 06:16:33.767151 14624 maintenance_manager.cc:643] P 1c3f185fe7da4c38acee9da60c33f143: FlushDeltaMemStoresOp(e4d13557f1e0463e846ffed5b9eb6ab5) complete. Timing: real 0.039s	user 0.014s	sys 0.023s Metrics: {"bytes_written":12717734,"delete_count":0,"lbm_write_time_us":12667,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:16:33.767710 14738 maintenance_manager.cc:419] P 1c3f185fe7da4c38acee9da60c33f143: Scheduling FlushDeltaMemStoresOp(e4d13557f1e0463e846ffed5b9eb6ab5): perf score=2.188937
I20260812 06:16:33.777753 14624 maintenance_manager.cc:643] P 1c3f185fe7da4c38acee9da60c33f143: FlushDeltaMemStoresOp(e4d13557f1e0463e846ffed5b9eb6ab5) complete. Timing: real 0.010s	user 0.001s	sys 0.008s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3933,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:16:33.778227 14738 maintenance_manager.cc:419] P 1c3f185fe7da4c38acee9da60c33f143: Scheduling MajorDeltaCompactionOp(e4d13557f1e0463e846ffed5b9eb6ab5): perf score=1.000000
I20260812 06:16:33.930423 14624 maintenance_manager.cc:643] P 1c3f185fe7da4c38acee9da60c33f143: MajorDeltaCompactionOp(e4d13557f1e0463e846ffed5b9eb6ab5) complete. Timing: real 0.152s	user 0.096s	sys 0.056s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672267,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":873,"lbm_read_time_us":11311,"lbm_reads_lt_1ms":472,"lbm_write_time_us":24474,"lbm_writes_lt_1ms":443,"mutex_wait_us":23,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":10112,"update_count":2000}
I20260812 06:16:33.931181 14738 maintenance_manager.cc:419] P 1c3f185fe7da4c38acee9da60c33f143: Scheduling FlushDeltaMemStoresOp(e4d13557f1e0463e846ffed5b9eb6ab5): perf score=10.126437
I20260812 06:16:33.971328 14624 maintenance_manager.cc:643] P 1c3f185fe7da4c38acee9da60c33f143: FlushDeltaMemStoresOp(e4d13557f1e0463e846ffed5b9eb6ab5) complete. Timing: real 0.040s	user 0.024s	sys 0.013s Metrics: {"bytes_written":12307492,"delete_count":0,"lbm_write_time_us":17038,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":302,"reinsert_count":0,"update_count":1500}
I20260812 06:16:33.971930 14738 maintenance_manager.cc:419] P 1c3f185fe7da4c38acee9da60c33f143: Scheduling FlushDeltaMemStoresOp(e4d13557f1e0463e846ffed5b9eb6ab5): perf score=2.188937
I20260812 06:16:33.989780 14624 maintenance_manager.cc:643] P 1c3f185fe7da4c38acee9da60c33f143: FlushDeltaMemStoresOp(e4d13557f1e0463e846ffed5b9eb6ab5) complete. Timing: real 0.018s	user 0.007s	sys 0.007s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":6453,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:33.990274 14738 maintenance_manager.cc:419] P 1c3f185fe7da4c38acee9da60c33f143: Scheduling MajorDeltaCompactionOp(e4d13557f1e0463e846ffed5b9eb6ab5): perf score=1.000000
I20260812 06:16:34.113281 14624 maintenance_manager.cc:643] P 1c3f185fe7da4c38acee9da60c33f143: MajorDeltaCompactionOp(e4d13557f1e0463e846ffed5b9eb6ab5) complete. Timing: real 0.123s	user 0.106s	sys 0.016s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672278,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":291,"lbm_read_time_us":7354,"lbm_reads_lt_1ms":464,"lbm_write_time_us":24107,"lbm_writes_lt_1ms":443,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":2560,"update_count":2000}
I20260812 06:16:34.113919 14738 maintenance_manager.cc:419] P 1c3f185fe7da4c38acee9da60c33f143: Scheduling FlushDeltaMemStoresOp(e4d13557f1e0463e846ffed5b9eb6ab5): perf score=10.126437
I20260812 06:16:34.157569 14624 maintenance_manager.cc:643] P 1c3f185fe7da4c38acee9da60c33f143: FlushDeltaMemStoresOp(e4d13557f1e0463e846ffed5b9eb6ab5) complete. Timing: real 0.043s	user 0.021s	sys 0.021s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":23068,"lbm_writes_1-10_ms":2,"lbm_writes_lt_1ms":301,"reinsert_count":0,"update_count":1500}
I20260812 06:16:34.158064 14738 maintenance_manager.cc:419] P 1c3f185fe7da4c38acee9da60c33f143: Scheduling FlushDeltaMemStoresOp(e4d13557f1e0463e846ffed5b9eb6ab5): perf score=2.188937
I20260812 06:16:34.170365 14624 maintenance_manager.cc:643] P 1c3f185fe7da4c38acee9da60c33f143: FlushDeltaMemStoresOp(e4d13557f1e0463e846ffed5b9eb6ab5) complete. Timing: real 0.012s	user 0.005s	sys 0.005s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4387,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:34.170845 14738 maintenance_manager.cc:419] P 1c3f185fe7da4c38acee9da60c33f143: Scheduling MajorDeltaCompactionOp(e4d13557f1e0463e846ffed5b9eb6ab5): perf score=1.000000
I20260812 06:16:34.297672 14624 maintenance_manager.cc:643] P 1c3f185fe7da4c38acee9da60c33f143: MajorDeltaCompactionOp(e4d13557f1e0463e846ffed5b9eb6ab5) complete. Timing: real 0.127s	user 0.107s	sys 0.020s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672277,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":263,"lbm_read_time_us":7356,"lbm_reads_lt_1ms":472,"lbm_write_time_us":26148,"lbm_writes_lt_1ms":443,"mutex_wait_us":43,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":8064,"update_count":2000}
I20260812 06:16:34.298389 14738 maintenance_manager.cc:419] P 1c3f185fe7da4c38acee9da60c33f143: Scheduling FlushDeltaMemStoresOp(e4d13557f1e0463e846ffed5b9eb6ab5): perf score=10.126437
I20260812 06:16:34.343261 14624 maintenance_manager.cc:643] P 1c3f185fe7da4c38acee9da60c33f143: FlushDeltaMemStoresOp(e4d13557f1e0463e846ffed5b9eb6ab5) complete. Timing: real 0.044s	user 0.017s	sys 0.016s Metrics: {"bytes_written":12307491,"delete_count":0,"lbm_write_time_us":15207,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:16:34.343725 14738 maintenance_manager.cc:419] P 1c3f185fe7da4c38acee9da60c33f143: Scheduling FlushDeltaMemStoresOp(e4d13557f1e0463e846ffed5b9eb6ab5): perf score=2.188937
I20260812 06:16:34.354239 14624 maintenance_manager.cc:643] P 1c3f185fe7da4c38acee9da60c33f143: FlushDeltaMemStoresOp(e4d13557f1e0463e846ffed5b9eb6ab5) complete. Timing: real 0.010s	user 0.009s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4133,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:34.354684 14738 maintenance_manager.cc:419] P 1c3f185fe7da4c38acee9da60c33f143: Scheduling MajorDeltaCompactionOp(e4d13557f1e0463e846ffed5b9eb6ab5): perf score=1.000000
I20260812 06:16:34.484743 14624 maintenance_manager.cc:643] P 1c3f185fe7da4c38acee9da60c33f143: MajorDeltaCompactionOp(e4d13557f1e0463e846ffed5b9eb6ab5) complete. Timing: real 0.130s	user 0.096s	sys 0.032s 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":989,"lbm_read_time_us":9411,"lbm_reads_lt_1ms":472,"lbm_write_time_us":23907,"lbm_writes_lt_1ms":443,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":2048,"update_count":2000}
I20260812 06:16:34.485324 14738 maintenance_manager.cc:419] P 1c3f185fe7da4c38acee9da60c33f143: Scheduling FlushDeltaMemStoresOp(e4d13557f1e0463e846ffed5b9eb6ab5): perf score=10.126437
I20260812 06:16:34.526196 14624 maintenance_manager.cc:643] P 1c3f185fe7da4c38acee9da60c33f143: FlushDeltaMemStoresOp(e4d13557f1e0463e846ffed5b9eb6ab5) complete. Timing: real 0.041s	user 0.024s	sys 0.015s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":14128,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:16:34.526710 14738 maintenance_manager.cc:419] P 1c3f185fe7da4c38acee9da60c33f143: Scheduling FlushDeltaMemStoresOp(e4d13557f1e0463e846ffed5b9eb6ab5): perf score=2.188937
I20260812 06:16:34.538362 14624 maintenance_manager.cc:643] P 1c3f185fe7da4c38acee9da60c33f143: FlushDeltaMemStoresOp(e4d13557f1e0463e846ffed5b9eb6ab5) complete. Timing: real 0.011s	user 0.005s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4462,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:34.538980 14738 maintenance_manager.cc:419] P 1c3f185fe7da4c38acee9da60c33f143: Scheduling FlushMRSOp(e4d13557f1e0463e846ffed5b9eb6ab5): perf score=1.000000
I20260812 06:16:34.577497 14624 maintenance_manager.cc:643] P 1c3f185fe7da4c38acee9da60c33f143: FlushMRSOp(e4d13557f1e0463e846ffed5b9eb6ab5) complete. Timing: real 0.038s	user 0.031s	sys 0.000s Metrics: {"bytes_written":1152508,"cfile_init":1,"dirs.queue_time_us":65,"dirs.run_cpu_time_us":218,"dirs.run_wall_time_us":1439,"drs_written":1,"lbm_read_time_us":46,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1386,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":28}
I20260812 06:16:34.578178 14738 maintenance_manager.cc:419] P 1c3f185fe7da4c38acee9da60c33f143: Scheduling LogGCOp(e4d13557f1e0463e846ffed5b9eb6ab5): free 112239265 bytes of WAL
I20260812 06:16:34.578444 14624 log_reader.cc:385] T e4d13557f1e0463e846ffed5b9eb6ab5: removed 11 log segments from log reader
I20260812 06:16:34.578505 14624 log.cc:1079] T e4d13557f1e0463e846ffed5b9eb6ab5 P 1c3f185fe7da4c38acee9da60c33f143: Deleting log segment in path: /tmp/dist-test-taskBsNFja/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515386269012-14022-0/minicluster-data/ts-0-root/wals/e4d13557f1e0463e846ffed5b9eb6ab5/wal-000000003 (ops 12-16)
I20260812 06:16:34.578545 14624 log.cc:1079] T e4d13557f1e0463e846ffed5b9eb6ab5 P 1c3f185fe7da4c38acee9da60c33f143: Deleting log segment in path: /tmp/dist-test-taskBsNFja/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515386269012-14022-0/minicluster-data/ts-0-root/wals/e4d13557f1e0463e846ffed5b9eb6ab5/wal-000000004 (ops 17-21)
I20260812 06:16:34.578567 14624 log.cc:1079] T e4d13557f1e0463e846ffed5b9eb6ab5 P 1c3f185fe7da4c38acee9da60c33f143: Deleting log segment in path: /tmp/dist-test-taskBsNFja/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515386269012-14022-0/minicluster-data/ts-0-root/wals/e4d13557f1e0463e846ffed5b9eb6ab5/wal-000000005 (ops 22-26)
I20260812 06:16:34.578598 14624 log.cc:1079] T e4d13557f1e0463e846ffed5b9eb6ab5 P 1c3f185fe7da4c38acee9da60c33f143: Deleting log segment in path: /tmp/dist-test-taskBsNFja/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515386269012-14022-0/minicluster-data/ts-0-root/wals/e4d13557f1e0463e846ffed5b9eb6ab5/wal-000000006 (ops 27-31)
I20260812 06:16:34.578626 14624 log.cc:1079] T e4d13557f1e0463e846ffed5b9eb6ab5 P 1c3f185fe7da4c38acee9da60c33f143: Deleting log segment in path: /tmp/dist-test-taskBsNFja/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515386269012-14022-0/minicluster-data/ts-0-root/wals/e4d13557f1e0463e846ffed5b9eb6ab5/wal-000000007 (ops 32-36)
I20260812 06:16:34.578660 14624 log.cc:1079] T e4d13557f1e0463e846ffed5b9eb6ab5 P 1c3f185fe7da4c38acee9da60c33f143: Deleting log segment in path: /tmp/dist-test-taskBsNFja/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515386269012-14022-0/minicluster-data/ts-0-root/wals/e4d13557f1e0463e846ffed5b9eb6ab5/wal-000000008 (ops 37-41)
I20260812 06:16:34.578691 14624 log.cc:1079] T e4d13557f1e0463e846ffed5b9eb6ab5 P 1c3f185fe7da4c38acee9da60c33f143: Deleting log segment in path: /tmp/dist-test-taskBsNFja/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515386269012-14022-0/minicluster-data/ts-0-root/wals/e4d13557f1e0463e846ffed5b9eb6ab5/wal-000000009 (ops 42-46)
I20260812 06:16:34.578716 14624 log.cc:1079] T e4d13557f1e0463e846ffed5b9eb6ab5 P 1c3f185fe7da4c38acee9da60c33f143: Deleting log segment in path: /tmp/dist-test-taskBsNFja/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515386269012-14022-0/minicluster-data/ts-0-root/wals/e4d13557f1e0463e846ffed5b9eb6ab5/wal-000000010 (ops 47-50)
I20260812 06:16:34.578743 14624 log.cc:1079] T e4d13557f1e0463e846ffed5b9eb6ab5 P 1c3f185fe7da4c38acee9da60c33f143: Deleting log segment in path: /tmp/dist-test-taskBsNFja/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515386269012-14022-0/minicluster-data/ts-0-root/wals/e4d13557f1e0463e846ffed5b9eb6ab5/wal-000000011 (ops 51-55)
I20260812 06:16:34.578770 14624 log.cc:1079] T e4d13557f1e0463e846ffed5b9eb6ab5 P 1c3f185fe7da4c38acee9da60c33f143: Deleting log segment in path: /tmp/dist-test-taskBsNFja/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515386269012-14022-0/minicluster-data/ts-0-root/wals/e4d13557f1e0463e846ffed5b9eb6ab5/wal-000000012 (ops 56-60)
I20260812 06:16:34.578802 14624 log.cc:1079] T e4d13557f1e0463e846ffed5b9eb6ab5 P 1c3f185fe7da4c38acee9da60c33f143: Deleting log segment in path: /tmp/dist-test-taskBsNFja/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515386269012-14022-0/minicluster-data/ts-0-root/wals/e4d13557f1e0463e846ffed5b9eb6ab5/wal-000000013 (ops 61-65)
I20260812 06:16:34.602763 14624 maintenance_manager.cc:643] P 1c3f185fe7da4c38acee9da60c33f143: LogGCOp(e4d13557f1e0463e846ffed5b9eb6ab5) complete. Timing: real 0.024s	user 0.000s	sys 0.022s Metrics: {}
I20260812 06:16:34.603206 14738 maintenance_manager.cc:419] P 1c3f185fe7da4c38acee9da60c33f143: Scheduling UndoDeltaBlockGCOp(e4d13557f1e0463e846ffed5b9eb6ab5): 447 bytes on disk
I20260812 06:16:34.603649 14624 maintenance_manager.cc:643] P 1c3f185fe7da4c38acee9da60c33f143: UndoDeltaBlockGCOp(e4d13557f1e0463e846ffed5b9eb6ab5) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":74,"lbm_reads_lt_1ms":4}
I20260812 06:16:34.604107 14738 maintenance_manager.cc:419] P 1c3f185fe7da4c38acee9da60c33f143: Scheduling FlushDeltaMemStoresOp(e4d13557f1e0463e846ffed5b9eb6ab5): perf score=2.188937
I20260812 06:16:34.630357 14624 maintenance_manager.cc:643] P 1c3f185fe7da4c38acee9da60c33f143: FlushDeltaMemStoresOp(e4d13557f1e0463e846ffed5b9eb6ab5) complete. Timing: real 0.026s	user 0.002s	sys 0.007s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4337,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:34.630911 14738 maintenance_manager.cc:419] P 1c3f185fe7da4c38acee9da60c33f143: Scheduling FlushDeltaMemStoresOp(e4d13557f1e0463e846ffed5b9eb6ab5): perf score=2.188937
I20260812 06:16:34.642038 14624 maintenance_manager.cc:643] P 1c3f185fe7da4c38acee9da60c33f143: FlushDeltaMemStoresOp(e4d13557f1e0463e846ffed5b9eb6ab5) complete. Timing: real 0.011s	user 0.004s	sys 0.005s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4285,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:34.642503 14738 maintenance_manager.cc:419] P 1c3f185fe7da4c38acee9da60c33f143: Scheduling MajorDeltaCompactionOp(e4d13557f1e0463e846ffed5b9eb6ab5): perf score=1.000000
I20260812 06:16:34.837426 14624 maintenance_manager.cc:643] P 1c3f185fe7da4c38acee9da60c33f143: MajorDeltaCompactionOp(e4d13557f1e0463e846ffed5b9eb6ab5) complete. Timing: real 0.195s	user 0.123s	sys 0.071s Metrics: {"cfile_cache_miss":634,"cfile_cache_miss_bytes":28877338,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":481,"lbm_read_time_us":13441,"lbm_reads_lt_1ms":674,"lbm_write_time_us":30341,"lbm_writes_lt_1ms":643,"mutex_wait_us":22,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":33664,"thread_start_us":80,"threads_started":1,"update_count":3000}
I20260812 06:16:34.838178 14738 maintenance_manager.cc:419] P 1c3f185fe7da4c38acee9da60c33f143: Scheduling FlushDeltaMemStoresOp(e4d13557f1e0463e846ffed5b9eb6ab5): perf score=14.095187
I20260812 06:16:34.897125 14624 maintenance_manager.cc:643] P 1c3f185fe7da4c38acee9da60c33f143: FlushDeltaMemStoresOp(e4d13557f1e0463e846ffed5b9eb6ab5) complete. Timing: real 0.059s	user 0.031s	sys 0.016s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":20018,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":402,"reinsert_count":0,"update_count":2000}
I20260812 06:16:34.897562 14738 maintenance_manager.cc:419] P 1c3f185fe7da4c38acee9da60c33f143: Scheduling FlushDeltaMemStoresOp(e4d13557f1e0463e846ffed5b9eb6ab5): perf score=2.188937
I20260812 06:16:34.907346 14624 maintenance_manager.cc:643] P 1c3f185fe7da4c38acee9da60c33f143: FlushDeltaMemStoresOp(e4d13557f1e0463e846ffed5b9eb6ab5) complete. Timing: real 0.010s	user 0.004s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3894,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:34.907758 14738 maintenance_manager.cc:419] P 1c3f185fe7da4c38acee9da60c33f143: Scheduling MajorDeltaCompactionOp(e4d13557f1e0463e846ffed5b9eb6ab5): perf score=1.000000
I20260812 06:16:35.083261 14624 maintenance_manager.cc:643] P 1c3f185fe7da4c38acee9da60c33f143: MajorDeltaCompactionOp(e4d13557f1e0463e846ffed5b9eb6ab5) complete. Timing: real 0.175s	user 0.094s	sys 0.080s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774688,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":233,"lbm_read_time_us":10710,"lbm_reads_lt_1ms":572,"lbm_write_time_us":30201,"lbm_writes_lt_1ms":543,"mutex_wait_us":33,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":14080,"update_count":2500}
I20260812 06:16:35.084172 14738 maintenance_manager.cc:419] P 1c3f185fe7da4c38acee9da60c33f143: Scheduling FlushDeltaMemStoresOp(e4d13557f1e0463e846ffed5b9eb6ab5): perf score=14.095187
I20260812 06:16:35.148187 14624 maintenance_manager.cc:643] P 1c3f185fe7da4c38acee9da60c33f143: FlushDeltaMemStoresOp(e4d13557f1e0463e846ffed5b9eb6ab5) complete. Timing: real 0.064s	user 0.045s	sys 0.015s Metrics: {"bytes_written":16409903,"delete_count":0,"lbm_write_time_us":24775,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:16:35.148821 14738 maintenance_manager.cc:419] P 1c3f185fe7da4c38acee9da60c33f143: Scheduling FlushDeltaMemStoresOp(e4d13557f1e0463e846ffed5b9eb6ab5): perf score=2.188937
I20260812 06:16:35.159188 14624 maintenance_manager.cc:643] P 1c3f185fe7da4c38acee9da60c33f143: FlushDeltaMemStoresOp(e4d13557f1e0463e846ffed5b9eb6ab5) complete. Timing: real 0.010s	user 0.008s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4158,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:35.159631 14738 maintenance_manager.cc:419] P 1c3f185fe7da4c38acee9da60c33f143: Scheduling MajorDeltaCompactionOp(e4d13557f1e0463e846ffed5b9eb6ab5): perf score=1.000000
I20260812 06:16:35.344710 14624 maintenance_manager.cc:643] P 1c3f185fe7da4c38acee9da60c33f143: MajorDeltaCompactionOp(e4d13557f1e0463e846ffed5b9eb6ab5) complete. Timing: real 0.185s	user 0.121s	sys 0.053s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774690,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":413,"lbm_read_time_us":13433,"lbm_reads_lt_1ms":572,"lbm_write_time_us":27825,"lbm_writes_lt_1ms":543,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":11904,"update_count":2500}
I20260812 06:16:35.345209 14738 maintenance_manager.cc:419] P 1c3f185fe7da4c38acee9da60c33f143: Scheduling FlushDeltaMemStoresOp(e4d13557f1e0463e846ffed5b9eb6ab5): perf score=14.095187
I20260812 06:16:35.411062 14624 maintenance_manager.cc:643] P 1c3f185fe7da4c38acee9da60c33f143: FlushDeltaMemStoresOp(e4d13557f1e0463e846ffed5b9eb6ab5) complete. Timing: real 0.066s	user 0.029s	sys 0.028s Metrics: {"bytes_written":16409882,"delete_count":0,"lbm_write_time_us":22336,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:16:35.411612 14738 maintenance_manager.cc:419] P 1c3f185fe7da4c38acee9da60c33f143: Scheduling FlushDeltaMemStoresOp(e4d13557f1e0463e846ffed5b9eb6ab5): perf score=2.188937
I20260812 06:16:35.422894 14624 maintenance_manager.cc:643] P 1c3f185fe7da4c38acee9da60c33f143: FlushDeltaMemStoresOp(e4d13557f1e0463e846ffed5b9eb6ab5) complete. Timing: real 0.011s	user 0.006s	sys 0.003s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4482,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:35.423393 14738 maintenance_manager.cc:419] P 1c3f185fe7da4c38acee9da60c33f143: Scheduling MajorDeltaCompactionOp(e4d13557f1e0463e846ffed5b9eb6ab5): perf score=1.000000
I20260812 06:16:35.607051 14624 maintenance_manager.cc:643] P 1c3f185fe7da4c38acee9da60c33f143: MajorDeltaCompactionOp(e4d13557f1e0463e846ffed5b9eb6ab5) complete. Timing: real 0.183s	user 0.106s	sys 0.075s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774668,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":676,"lbm_read_time_us":13069,"lbm_reads_lt_1ms":572,"lbm_write_time_us":30939,"lbm_writes_lt_1ms":543,"mutex_wait_us":207,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":15616,"update_count":2500}
I20260812 06:16:35.607851 14738 maintenance_manager.cc:419] P 1c3f185fe7da4c38acee9da60c33f143: Scheduling FlushDeltaMemStoresOp(e4d13557f1e0463e846ffed5b9eb6ab5): perf score=11.118625
I20260812 06:16:35.646412 14624 maintenance_manager.cc:643] P 1c3f185fe7da4c38acee9da60c33f143: FlushDeltaMemStoresOp(e4d13557f1e0463e846ffed5b9eb6ab5) complete. Timing: real 0.038s	user 0.021s	sys 0.015s Metrics: {"bytes_written":12717736,"delete_count":0,"lbm_write_time_us":13774,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:16:35.646921 14738 maintenance_manager.cc:419] P 1c3f185fe7da4c38acee9da60c33f143: Scheduling FlushDeltaMemStoresOp(e4d13557f1e0463e846ffed5b9eb6ab5): perf score=2.188937
I20260812 06:16:35.677986 14624 maintenance_manager.cc:643] P 1c3f185fe7da4c38acee9da60c33f143: FlushDeltaMemStoresOp(e4d13557f1e0463e846ffed5b9eb6ab5) complete. Timing: real 0.031s	user 0.008s	sys 0.014s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":5147,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:16:35.678442 14738 maintenance_manager.cc:419] P 1c3f185fe7da4c38acee9da60c33f143: Scheduling FlushDeltaMemStoresOp(e4d13557f1e0463e846ffed5b9eb6ab5): perf score=2.188937
I20260812 06:16:35.689024 14624 maintenance_manager.cc:643] P 1c3f185fe7da4c38acee9da60c33f143: FlushDeltaMemStoresOp(e4d13557f1e0463e846ffed5b9eb6ab5) complete. Timing: real 0.010s	user 0.006s	sys 0.004s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4157,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:35.689522 14738 maintenance_manager.cc:419] P 1c3f185fe7da4c38acee9da60c33f143: Scheduling MajorDeltaCompactionOp(e4d13557f1e0463e846ffed5b9eb6ab5): perf score=1.000000
I20260812 06:16:35.879092 14624 maintenance_manager.cc:643] P 1c3f185fe7da4c38acee9da60c33f143: MajorDeltaCompactionOp(e4d13557f1e0463e846ffed5b9eb6ab5) complete. Timing: real 0.189s	user 0.131s	sys 0.055s 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":202,"lbm_read_time_us":13823,"lbm_reads_lt_1ms":573,"lbm_write_time_us":29245,"lbm_writes_lt_1ms":543,"mutex_wait_us":62,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":7168,"update_count":2500}
I20260812 06:16:35.879655 14738 maintenance_manager.cc:419] P 1c3f185fe7da4c38acee9da60c33f143: Scheduling FlushDeltaMemStoresOp(e4d13557f1e0463e846ffed5b9eb6ab5): perf score=11.118625
I20260812 06:16:35.922328 14624 maintenance_manager.cc:643] P 1c3f185fe7da4c38acee9da60c33f143: FlushDeltaMemStoresOp(e4d13557f1e0463e846ffed5b9eb6ab5) complete. Timing: real 0.042s	user 0.021s	sys 0.019s Metrics: {"bytes_written":12717735,"delete_count":0,"lbm_write_time_us":16414,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:16:35.923053 14738 maintenance_manager.cc:419] P 1c3f185fe7da4c38acee9da60c33f143: Scheduling FlushDeltaMemStoresOp(e4d13557f1e0463e846ffed5b9eb6ab5): perf score=2.188937
I20260812 06:16:35.945333 14624 maintenance_manager.cc:643] P 1c3f185fe7da4c38acee9da60c33f143: FlushDeltaMemStoresOp(e4d13557f1e0463e846ffed5b9eb6ab5) complete. Timing: real 0.022s	user 0.003s	sys 0.008s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":4628,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:16:35.945782 14738 maintenance_manager.cc:419] P 1c3f185fe7da4c38acee9da60c33f143: Scheduling FlushDeltaMemStoresOp(e4d13557f1e0463e846ffed5b9eb6ab5): perf score=2.188937
I20260812 06:16:35.955791 14624 maintenance_manager.cc:643] P 1c3f185fe7da4c38acee9da60c33f143: FlushDeltaMemStoresOp(e4d13557f1e0463e846ffed5b9eb6ab5) complete. Timing: real 0.010s	user 0.007s	sys 0.001s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3880,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:35.956266 14738 maintenance_manager.cc:419] P 1c3f185fe7da4c38acee9da60c33f143: Scheduling MajorDeltaCompactionOp(e4d13557f1e0463e846ffed5b9eb6ab5): perf score=1.000000
I20260812 06:16:36.133179 14624 maintenance_manager.cc:643] P 1c3f185fe7da4c38acee9da60c33f143: MajorDeltaCompactionOp(e4d13557f1e0463e846ffed5b9eb6ab5) complete. Timing: real 0.177s	user 0.124s	sys 0.043s 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":592,"lbm_read_time_us":12335,"lbm_reads_lt_1ms":573,"lbm_write_time_us":26817,"lbm_writes_lt_1ms":543,"mutex_wait_us":263,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":1792,"update_count":2500}
I20260812 06:16:36.133734 14738 maintenance_manager.cc:419] P 1c3f185fe7da4c38acee9da60c33f143: Scheduling FlushDeltaMemStoresOp(e4d13557f1e0463e846ffed5b9eb6ab5): perf score=14.095187
I20260812 06:16:36.182855 14624 maintenance_manager.cc:643] P 1c3f185fe7da4c38acee9da60c33f143: FlushDeltaMemStoresOp(e4d13557f1e0463e846ffed5b9eb6ab5) complete. Timing: real 0.049s	user 0.037s	sys 0.005s Metrics: {"bytes_written":16409903,"delete_count":0,"lbm_write_time_us":19563,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:16:36.183333 14738 maintenance_manager.cc:419] P 1c3f185fe7da4c38acee9da60c33f143: Scheduling FlushDeltaMemStoresOp(e4d13557f1e0463e846ffed5b9eb6ab5): perf score=2.188937
I20260812 06:16:36.193801 14624 maintenance_manager.cc:643] P 1c3f185fe7da4c38acee9da60c33f143: FlushDeltaMemStoresOp(e4d13557f1e0463e846ffed5b9eb6ab5) complete. Timing: real 0.010s	user 0.005s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4180,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:36.194216 14738 maintenance_manager.cc:419] P 1c3f185fe7da4c38acee9da60c33f143: Scheduling FlushMRSOp(e4d13557f1e0463e846ffed5b9eb6ab5): perf score=1.000000
I20260812 06:16:36.228039 14624 maintenance_manager.cc:643] P 1c3f185fe7da4c38acee9da60c33f143: FlushMRSOp(e4d13557f1e0463e846ffed5b9eb6ab5) complete. Timing: real 0.034s	user 0.032s	sys 0.000s Metrics: {"bytes_written":1316419,"cfile_init":1,"dirs.queue_time_us":71,"dirs.run_cpu_time_us":162,"dirs.run_wall_time_us":1396,"drs_written":1,"lbm_read_time_us":50,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1881,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":32}
I20260812 06:16:36.228754 14738 maintenance_manager.cc:419] P 1c3f185fe7da4c38acee9da60c33f143: Scheduling LogGCOp(e4d13557f1e0463e846ffed5b9eb6ab5): free 133024367 bytes of WAL
I20260812 06:16:36.229043 14624 log_reader.cc:385] T e4d13557f1e0463e846ffed5b9eb6ab5: removed 13 log segments from log reader
I20260812 06:16:36.229100 14624 log.cc:1079] T e4d13557f1e0463e846ffed5b9eb6ab5 P 1c3f185fe7da4c38acee9da60c33f143: Deleting log segment in path: /tmp/dist-test-taskBsNFja/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515386269012-14022-0/minicluster-data/ts-0-root/wals/e4d13557f1e0463e846ffed5b9eb6ab5/wal-000000014 (ops 66-70)
I20260812 06:16:36.229137 14624 log.cc:1079] T e4d13557f1e0463e846ffed5b9eb6ab5 P 1c3f185fe7da4c38acee9da60c33f143: Deleting log segment in path: /tmp/dist-test-taskBsNFja/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515386269012-14022-0/minicluster-data/ts-0-root/wals/e4d13557f1e0463e846ffed5b9eb6ab5/wal-000000015 (ops 71-75)
I20260812 06:16:36.229169 14624 log.cc:1079] T e4d13557f1e0463e846ffed5b9eb6ab5 P 1c3f185fe7da4c38acee9da60c33f143: Deleting log segment in path: /tmp/dist-test-taskBsNFja/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515386269012-14022-0/minicluster-data/ts-0-root/wals/e4d13557f1e0463e846ffed5b9eb6ab5/wal-000000016 (ops 76-80)
I20260812 06:16:36.229199 14624 log.cc:1079] T e4d13557f1e0463e846ffed5b9eb6ab5 P 1c3f185fe7da4c38acee9da60c33f143: Deleting log segment in path: /tmp/dist-test-taskBsNFja/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515386269012-14022-0/minicluster-data/ts-0-root/wals/e4d13557f1e0463e846ffed5b9eb6ab5/wal-000000017 (ops 81-85)
I20260812 06:16:36.229267 14624 log.cc:1079] T e4d13557f1e0463e846ffed5b9eb6ab5 P 1c3f185fe7da4c38acee9da60c33f143: Deleting log segment in path: /tmp/dist-test-taskBsNFja/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515386269012-14022-0/minicluster-data/ts-0-root/wals/e4d13557f1e0463e846ffed5b9eb6ab5/wal-000000018 (ops 86-90)
I20260812 06:16:36.229367 14624 log.cc:1079] T e4d13557f1e0463e846ffed5b9eb6ab5 P 1c3f185fe7da4c38acee9da60c33f143: Deleting log segment in path: /tmp/dist-test-taskBsNFja/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515386269012-14022-0/minicluster-data/ts-0-root/wals/e4d13557f1e0463e846ffed5b9eb6ab5/wal-000000019 (ops 91-95)
I20260812 06:16:36.229404 14624 log.cc:1079] T e4d13557f1e0463e846ffed5b9eb6ab5 P 1c3f185fe7da4c38acee9da60c33f143: Deleting log segment in path: /tmp/dist-test-taskBsNFja/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515386269012-14022-0/minicluster-data/ts-0-root/wals/e4d13557f1e0463e846ffed5b9eb6ab5/wal-000000020 (ops 96-100)
I20260812 06:16:36.229427 14624 log.cc:1079] T e4d13557f1e0463e846ffed5b9eb6ab5 P 1c3f185fe7da4c38acee9da60c33f143: Deleting log segment in path: /tmp/dist-test-taskBsNFja/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515386269012-14022-0/minicluster-data/ts-0-root/wals/e4d13557f1e0463e846ffed5b9eb6ab5/wal-000000021 (ops 101-105)
I20260812 06:16:36.229458 14624 log.cc:1079] T e4d13557f1e0463e846ffed5b9eb6ab5 P 1c3f185fe7da4c38acee9da60c33f143: Deleting log segment in path: /tmp/dist-test-taskBsNFja/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515386269012-14022-0/minicluster-data/ts-0-root/wals/e4d13557f1e0463e846ffed5b9eb6ab5/wal-000000022 (ops 106-110)
I20260812 06:16:36.229493 14624 log.cc:1079] T e4d13557f1e0463e846ffed5b9eb6ab5 P 1c3f185fe7da4c38acee9da60c33f143: Deleting log segment in path: /tmp/dist-test-taskBsNFja/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515386269012-14022-0/minicluster-data/ts-0-root/wals/e4d13557f1e0463e846ffed5b9eb6ab5/wal-000000023 (ops 111-115)
I20260812 06:16:36.229519 14624 log.cc:1079] T e4d13557f1e0463e846ffed5b9eb6ab5 P 1c3f185fe7da4c38acee9da60c33f143: Deleting log segment in path: /tmp/dist-test-taskBsNFja/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515386269012-14022-0/minicluster-data/ts-0-root/wals/e4d13557f1e0463e846ffed5b9eb6ab5/wal-000000024 (ops 116-120)
I20260812 06:16:36.229542 14624 log.cc:1079] T e4d13557f1e0463e846ffed5b9eb6ab5 P 1c3f185fe7da4c38acee9da60c33f143: Deleting log segment in path: /tmp/dist-test-taskBsNFja/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515386269012-14022-0/minicluster-data/ts-0-root/wals/e4d13557f1e0463e846ffed5b9eb6ab5/wal-000000025 (ops 121-124)
I20260812 06:16:36.229588 14624 log.cc:1079] T e4d13557f1e0463e846ffed5b9eb6ab5 P 1c3f185fe7da4c38acee9da60c33f143: Deleting log segment in path: /tmp/dist-test-taskBsNFja/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515386269012-14022-0/minicluster-data/ts-0-root/wals/e4d13557f1e0463e846ffed5b9eb6ab5/wal-000000026 (ops 125-129)
I20260812 06:16:36.259934 14624 maintenance_manager.cc:643] P 1c3f185fe7da4c38acee9da60c33f143: LogGCOp(e4d13557f1e0463e846ffed5b9eb6ab5) complete. Timing: real 0.031s	user 0.000s	sys 0.028s Metrics: {}
I20260812 06:16:36.266333 14738 maintenance_manager.cc:419] P 1c3f185fe7da4c38acee9da60c33f143: Scheduling UndoDeltaBlockGCOp(e4d13557f1e0463e846ffed5b9eb6ab5): 493 bytes on disk
I20260812 06:16:36.266810 14624 maintenance_manager.cc:643] P 1c3f185fe7da4c38acee9da60c33f143: UndoDeltaBlockGCOp(e4d13557f1e0463e846ffed5b9eb6ab5) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":48,"lbm_reads_lt_1ms":4}
I20260812 06:16:36.267438 14738 maintenance_manager.cc:419] P 1c3f185fe7da4c38acee9da60c33f143: Scheduling FlushDeltaMemStoresOp(e4d13557f1e0463e846ffed5b9eb6ab5): perf score=2.188937
I20260812 06:16:36.285179 14624 maintenance_manager.cc:643] P 1c3f185fe7da4c38acee9da60c33f143: FlushDeltaMemStoresOp(e4d13557f1e0463e846ffed5b9eb6ab5) complete. Timing: real 0.018s	user 0.004s	sys 0.007s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4458,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:36.285624 14738 maintenance_manager.cc:419] P 1c3f185fe7da4c38acee9da60c33f143: Scheduling FlushDeltaMemStoresOp(e4d13557f1e0463e846ffed5b9eb6ab5): perf score=2.188937
I20260812 06:16:36.296022 14624 maintenance_manager.cc:643] P 1c3f185fe7da4c38acee9da60c33f143: FlushDeltaMemStoresOp(e4d13557f1e0463e846ffed5b9eb6ab5) complete. Timing: real 0.010s	user 0.005s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4174,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:36.296444 14738 maintenance_manager.cc:419] P 1c3f185fe7da4c38acee9da60c33f143: Scheduling MajorDeltaCompactionOp(e4d13557f1e0463e846ffed5b9eb6ab5): perf score=1.000000
I20260812 06:16:36.526729 14624 maintenance_manager.cc:643] P 1c3f185fe7da4c38acee9da60c33f143: MajorDeltaCompactionOp(e4d13557f1e0463e846ffed5b9eb6ab5) complete. Timing: real 0.230s	user 0.165s	sys 0.065s Metrics: {"cfile_cache_miss":734,"cfile_cache_miss_bytes":32979752,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":578,"lbm_read_time_us":14844,"lbm_reads_lt_1ms":774,"lbm_write_time_us":39179,"lbm_writes_lt_1ms":743,"mutex_wait_us":56,"peak_mem_usage":87969044,"reinsert_count":0,"spinlock_wait_cycles":12160,"thread_start_us":94,"threads_started":1,"update_count":3500}
I20260812 06:16:36.527520 14738 maintenance_manager.cc:419] P 1c3f185fe7da4c38acee9da60c33f143: Scheduling FlushDeltaMemStoresOp(e4d13557f1e0463e846ffed5b9eb6ab5): perf score=14.095187
I20260812 06:16:36.575726 14624 maintenance_manager.cc:643] P 1c3f185fe7da4c38acee9da60c33f143: FlushDeltaMemStoresOp(e4d13557f1e0463e846ffed5b9eb6ab5) complete. Timing: real 0.047s	user 0.027s	sys 0.017s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":21053,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:16:36.576424 14738 maintenance_manager.cc:419] P 1c3f185fe7da4c38acee9da60c33f143: Scheduling FlushDeltaMemStoresOp(e4d13557f1e0463e846ffed5b9eb6ab5): perf score=2.188937
I20260812 06:16:36.591610 14624 maintenance_manager.cc:643] P 1c3f185fe7da4c38acee9da60c33f143: FlushDeltaMemStoresOp(e4d13557f1e0463e846ffed5b9eb6ab5) complete. Timing: real 0.015s	user 0.009s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6199,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:36.592171 14738 maintenance_manager.cc:419] P 1c3f185fe7da4c38acee9da60c33f143: Scheduling MajorDeltaCompactionOp(e4d13557f1e0463e846ffed5b9eb6ab5): perf score=1.000000
I20260812 06:16:36.771196 14624 maintenance_manager.cc:643] P 1c3f185fe7da4c38acee9da60c33f143: MajorDeltaCompactionOp(e4d13557f1e0463e846ffed5b9eb6ab5) complete. Timing: real 0.179s	user 0.118s	sys 0.056s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774688,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":714,"lbm_read_time_us":11812,"lbm_reads_lt_1ms":572,"lbm_write_time_us":31950,"lbm_writes_lt_1ms":543,"mutex_wait_us":320,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":12160,"update_count":2500}
I20260812 06:16:36.771658 14738 maintenance_manager.cc:419] P 1c3f185fe7da4c38acee9da60c33f143: Scheduling FlushDeltaMemStoresOp(e4d13557f1e0463e846ffed5b9eb6ab5): perf score=14.095187
I20260812 06:16:36.829668 14624 maintenance_manager.cc:643] P 1c3f185fe7da4c38acee9da60c33f143: FlushDeltaMemStoresOp(e4d13557f1e0463e846ffed5b9eb6ab5) complete. Timing: real 0.058s	user 0.027s	sys 0.031s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":23511,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":402,"reinsert_count":0,"update_count":2000}
I20260812 06:16:36.830176 14738 maintenance_manager.cc:419] P 1c3f185fe7da4c38acee9da60c33f143: Scheduling FlushDeltaMemStoresOp(e4d13557f1e0463e846ffed5b9eb6ab5): perf score=2.188937
I20260812 06:16:36.840561 14624 maintenance_manager.cc:643] P 1c3f185fe7da4c38acee9da60c33f143: FlushDeltaMemStoresOp(e4d13557f1e0463e846ffed5b9eb6ab5) complete. Timing: real 0.010s	user 0.006s	sys 0.004s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4178,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:36.841022 14738 maintenance_manager.cc:419] P 1c3f185fe7da4c38acee9da60c33f143: Scheduling MajorDeltaCompactionOp(e4d13557f1e0463e846ffed5b9eb6ab5): perf score=1.000000
I20260812 06:16:37.020326 14624 maintenance_manager.cc:643] P 1c3f185fe7da4c38acee9da60c33f143: MajorDeltaCompactionOp(e4d13557f1e0463e846ffed5b9eb6ab5) complete. Timing: real 0.179s	user 0.123s	sys 0.051s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774688,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":3626,"lbm_read_time_us":12814,"lbm_reads_lt_1ms":572,"lbm_write_time_us":29605,"lbm_writes_lt_1ms":543,"mutex_wait_us":3011,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":2432,"update_count":2500}
I20260812 06:16:37.020952 14738 maintenance_manager.cc:419] P 1c3f185fe7da4c38acee9da60c33f143: Scheduling FlushDeltaMemStoresOp(e4d13557f1e0463e846ffed5b9eb6ab5): perf score=11.118625
I20260812 06:16:37.057439 14624 maintenance_manager.cc:643] P 1c3f185fe7da4c38acee9da60c33f143: FlushDeltaMemStoresOp(e4d13557f1e0463e846ffed5b9eb6ab5) complete. Timing: real 0.036s	user 0.029s	sys 0.006s Metrics: {"bytes_written":12717735,"delete_count":0,"lbm_write_time_us":15642,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:16:37.058101 14738 maintenance_manager.cc:419] P 1c3f185fe7da4c38acee9da60c33f143: Scheduling FlushDeltaMemStoresOp(e4d13557f1e0463e846ffed5b9eb6ab5): perf score=2.188937
I20260812 06:16:37.078387 14624 maintenance_manager.cc:643] P 1c3f185fe7da4c38acee9da60c33f143: FlushDeltaMemStoresOp(e4d13557f1e0463e846ffed5b9eb6ab5) complete. Timing: real 0.020s	user 0.005s	sys 0.004s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":4400,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:16:37.078912 14738 maintenance_manager.cc:419] P 1c3f185fe7da4c38acee9da60c33f143: Scheduling MajorDeltaCompactionOp(e4d13557f1e0463e846ffed5b9eb6ab5): perf score=1.000000
I20260812 06:16:37.236842 14624 maintenance_manager.cc:643] P 1c3f185fe7da4c38acee9da60c33f143: MajorDeltaCompactionOp(e4d13557f1e0463e846ffed5b9eb6ab5) complete. Timing: real 0.158s	user 0.095s	sys 0.061s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672268,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":1622,"lbm_read_time_us":10153,"lbm_reads_lt_1ms":464,"lbm_write_time_us":26191,"lbm_writes_lt_1ms":443,"mutex_wait_us":381,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":1792,"update_count":2000}
I20260812 06:16:37.237581 14738 maintenance_manager.cc:419] P 1c3f185fe7da4c38acee9da60c33f143: Scheduling FlushDeltaMemStoresOp(e4d13557f1e0463e846ffed5b9eb6ab5): perf score=11.118625
I20260812 06:16:37.273159 14624 maintenance_manager.cc:643] P 1c3f185fe7da4c38acee9da60c33f143: FlushDeltaMemStoresOp(e4d13557f1e0463e846ffed5b9eb6ab5) complete. Timing: real 0.035s	user 0.019s	sys 0.016s Metrics: {"bytes_written":12717735,"delete_count":0,"lbm_write_time_us":14988,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:16:37.273854 14738 maintenance_manager.cc:419] P 1c3f185fe7da4c38acee9da60c33f143: Scheduling FlushDeltaMemStoresOp(e4d13557f1e0463e846ffed5b9eb6ab5): perf score=2.188937
I20260812 06:16:37.296998 14624 maintenance_manager.cc:643] P 1c3f185fe7da4c38acee9da60c33f143: FlushDeltaMemStoresOp(e4d13557f1e0463e846ffed5b9eb6ab5) complete. Timing: real 0.023s	user 0.006s	sys 0.004s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3853,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:16:37.297508 14738 maintenance_manager.cc:419] P 1c3f185fe7da4c38acee9da60c33f143: Scheduling FlushDeltaMemStoresOp(e4d13557f1e0463e846ffed5b9eb6ab5): perf score=2.188937
I20260812 06:16:37.308729 14624 maintenance_manager.cc:643] P 1c3f185fe7da4c38acee9da60c33f143: FlushDeltaMemStoresOp(e4d13557f1e0463e846ffed5b9eb6ab5) complete. Timing: real 0.011s	user 0.011s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4155,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:37.309248 14738 maintenance_manager.cc:419] P 1c3f185fe7da4c38acee9da60c33f143: Scheduling MajorDeltaCompactionOp(e4d13557f1e0463e846ffed5b9eb6ab5): perf score=1.000000
I20260812 06:16:37.470758 14624 maintenance_manager.cc:643] P 1c3f185fe7da4c38acee9da60c33f143: MajorDeltaCompactionOp(e4d13557f1e0463e846ffed5b9eb6ab5) complete. Timing: real 0.161s	user 0.125s	sys 0.032s Metrics: {"cfile_cache_miss":533,"cfile_cache_miss_bytes":24774799,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":691,"lbm_read_time_us":12611,"lbm_reads_lt_1ms":573,"lbm_write_time_us":30159,"lbm_writes_lt_1ms":543,"mutex_wait_us":382,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":13184,"update_count":2500}
I20260812 06:16:37.471459 14738 maintenance_manager.cc:419] P 1c3f185fe7da4c38acee9da60c33f143: Scheduling FlushDeltaMemStoresOp(e4d13557f1e0463e846ffed5b9eb6ab5): perf score=11.118625
I20260812 06:16:37.507731 14624 maintenance_manager.cc:643] P 1c3f185fe7da4c38acee9da60c33f143: FlushDeltaMemStoresOp(e4d13557f1e0463e846ffed5b9eb6ab5) complete. Timing: real 0.036s	user 0.021s	sys 0.012s Metrics: {"bytes_written":12717734,"delete_count":0,"lbm_write_time_us":15315,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:16:37.508558 14738 maintenance_manager.cc:419] P 1c3f185fe7da4c38acee9da60c33f143: Scheduling FlushDeltaMemStoresOp(e4d13557f1e0463e846ffed5b9eb6ab5): perf score=2.188937
I20260812 06:16:37.521500 14624 maintenance_manager.cc:643] P 1c3f185fe7da4c38acee9da60c33f143: FlushDeltaMemStoresOp(e4d13557f1e0463e846ffed5b9eb6ab5) complete. Timing: real 0.013s	user 0.010s	sys 0.001s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":4544,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:16:37.522089 14738 maintenance_manager.cc:419] P 1c3f185fe7da4c38acee9da60c33f143: Scheduling MajorDeltaCompactionOp(e4d13557f1e0463e846ffed5b9eb6ab5): perf score=1.000000
I20260812 06:16:37.642827 14624 maintenance_manager.cc:643] P 1c3f185fe7da4c38acee9da60c33f143: MajorDeltaCompactionOp(e4d13557f1e0463e846ffed5b9eb6ab5) complete. Timing: real 0.121s	user 0.097s	sys 0.023s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672267,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":628,"lbm_read_time_us":7043,"lbm_reads_lt_1ms":464,"lbm_write_time_us":24036,"lbm_writes_lt_1ms":443,"mutex_wait_us":332,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":10624,"update_count":2000}
I20260812 06:16:37.644824 14738 maintenance_manager.cc:419] P 1c3f185fe7da4c38acee9da60c33f143: Scheduling FlushDeltaMemStoresOp(e4d13557f1e0463e846ffed5b9eb6ab5): perf score=10.126437
I20260812 06:16:37.684703 14624 maintenance_manager.cc:643] P 1c3f185fe7da4c38acee9da60c33f143: FlushDeltaMemStoresOp(e4d13557f1e0463e846ffed5b9eb6ab5) complete. Timing: real 0.040s	user 0.019s	sys 0.020s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":16607,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":302,"reinsert_count":0,"update_count":1500}
I20260812 06:16:37.685336 14738 maintenance_manager.cc:419] P 1c3f185fe7da4c38acee9da60c33f143: Scheduling FlushDeltaMemStoresOp(e4d13557f1e0463e846ffed5b9eb6ab5): perf score=2.188937
I20260812 06:16:37.697883 14624 maintenance_manager.cc:643] P 1c3f185fe7da4c38acee9da60c33f143: FlushDeltaMemStoresOp(e4d13557f1e0463e846ffed5b9eb6ab5) complete. Timing: real 0.012s	user 0.002s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4538,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:37.698385 14738 maintenance_manager.cc:419] P 1c3f185fe7da4c38acee9da60c33f143: Scheduling FlushMRSOp(e4d13557f1e0463e846ffed5b9eb6ab5): perf score=1.000000
I20260812 06:16:37.729034 14624 maintenance_manager.cc:643] P 1c3f185fe7da4c38acee9da60c33f143: FlushMRSOp(e4d13557f1e0463e846ffed5b9eb6ab5) complete. Timing: real 0.030s	user 0.026s	sys 0.004s Metrics: {"bytes_written":1193507,"cfile_init":1,"dirs.queue_time_us":71,"dirs.run_cpu_time_us":303,"dirs.run_wall_time_us":1447,"drs_written":1,"lbm_read_time_us":60,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1507,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":29}
I20260812 06:16:37.729800 14738 maintenance_manager.cc:419] P 1c3f185fe7da4c38acee9da60c33f143: Scheduling LogGCOp(e4d13557f1e0463e846ffed5b9eb6ab5): free 124710614 bytes of WAL
I20260812 06:16:37.730026 14624 log_reader.cc:385] T e4d13557f1e0463e846ffed5b9eb6ab5: removed 12 log segments from log reader
I20260812 06:16:37.730072 14624 log.cc:1079] T e4d13557f1e0463e846ffed5b9eb6ab5 P 1c3f185fe7da4c38acee9da60c33f143: Deleting log segment in path: /tmp/dist-test-taskBsNFja/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515386269012-14022-0/minicluster-data/ts-0-root/wals/e4d13557f1e0463e846ffed5b9eb6ab5/wal-000000027 (ops 130-134)
I20260812 06:16:37.730123 14624 log.cc:1079] T e4d13557f1e0463e846ffed5b9eb6ab5 P 1c3f185fe7da4c38acee9da60c33f143: Deleting log segment in path: /tmp/dist-test-taskBsNFja/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515386269012-14022-0/minicluster-data/ts-0-root/wals/e4d13557f1e0463e846ffed5b9eb6ab5/wal-000000028 (ops 135-139)
I20260812 06:16:37.730170 14624 log.cc:1079] T e4d13557f1e0463e846ffed5b9eb6ab5 P 1c3f185fe7da4c38acee9da60c33f143: Deleting log segment in path: /tmp/dist-test-taskBsNFja/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515386269012-14022-0/minicluster-data/ts-0-root/wals/e4d13557f1e0463e846ffed5b9eb6ab5/wal-000000029 (ops 140-144)
I20260812 06:16:37.730212 14624 log.cc:1079] T e4d13557f1e0463e846ffed5b9eb6ab5 P 1c3f185fe7da4c38acee9da60c33f143: Deleting log segment in path: /tmp/dist-test-taskBsNFja/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515386269012-14022-0/minicluster-data/ts-0-root/wals/e4d13557f1e0463e846ffed5b9eb6ab5/wal-000000030 (ops 145-149)
I20260812 06:16:37.730254 14624 log.cc:1079] T e4d13557f1e0463e846ffed5b9eb6ab5 P 1c3f185fe7da4c38acee9da60c33f143: Deleting log segment in path: /tmp/dist-test-taskBsNFja/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515386269012-14022-0/minicluster-data/ts-0-root/wals/e4d13557f1e0463e846ffed5b9eb6ab5/wal-000000031 (ops 150-154)
I20260812 06:16:37.730295 14624 log.cc:1079] T e4d13557f1e0463e846ffed5b9eb6ab5 P 1c3f185fe7da4c38acee9da60c33f143: Deleting log segment in path: /tmp/dist-test-taskBsNFja/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515386269012-14022-0/minicluster-data/ts-0-root/wals/e4d13557f1e0463e846ffed5b9eb6ab5/wal-000000032 (ops 155-159)
I20260812 06:16:37.730335 14624 log.cc:1079] T e4d13557f1e0463e846ffed5b9eb6ab5 P 1c3f185fe7da4c38acee9da60c33f143: Deleting log segment in path: /tmp/dist-test-taskBsNFja/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515386269012-14022-0/minicluster-data/ts-0-root/wals/e4d13557f1e0463e846ffed5b9eb6ab5/wal-000000033 (ops 160-164)
I20260812 06:16:37.730376 14624 log.cc:1079] T e4d13557f1e0463e846ffed5b9eb6ab5 P 1c3f185fe7da4c38acee9da60c33f143: Deleting log segment in path: /tmp/dist-test-taskBsNFja/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515386269012-14022-0/minicluster-data/ts-0-root/wals/e4d13557f1e0463e846ffed5b9eb6ab5/wal-000000034 (ops 165-169)
I20260812 06:16:37.730415 14624 log.cc:1079] T e4d13557f1e0463e846ffed5b9eb6ab5 P 1c3f185fe7da4c38acee9da60c33f143: Deleting log segment in path: /tmp/dist-test-taskBsNFja/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515386269012-14022-0/minicluster-data/ts-0-root/wals/e4d13557f1e0463e846ffed5b9eb6ab5/wal-000000035 (ops 170-174)
I20260812 06:16:37.730461 14624 log.cc:1079] T e4d13557f1e0463e846ffed5b9eb6ab5 P 1c3f185fe7da4c38acee9da60c33f143: Deleting log segment in path: /tmp/dist-test-taskBsNFja/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515386269012-14022-0/minicluster-data/ts-0-root/wals/e4d13557f1e0463e846ffed5b9eb6ab5/wal-000000036 (ops 175-179)
I20260812 06:16:37.730507 14624 log.cc:1079] T e4d13557f1e0463e846ffed5b9eb6ab5 P 1c3f185fe7da4c38acee9da60c33f143: Deleting log segment in path: /tmp/dist-test-taskBsNFja/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515386269012-14022-0/minicluster-data/ts-0-root/wals/e4d13557f1e0463e846ffed5b9eb6ab5/wal-000000037 (ops 180-184)
I20260812 06:16:37.730547 14624 log.cc:1079] T e4d13557f1e0463e846ffed5b9eb6ab5 P 1c3f185fe7da4c38acee9da60c33f143: Deleting log segment in path: /tmp/dist-test-taskBsNFja/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515386269012-14022-0/minicluster-data/ts-0-root/wals/e4d13557f1e0463e846ffed5b9eb6ab5/wal-000000038 (ops 185-189)
I20260812 06:16:37.758939 14624 maintenance_manager.cc:643] P 1c3f185fe7da4c38acee9da60c33f143: LogGCOp(e4d13557f1e0463e846ffed5b9eb6ab5) complete. Timing: real 0.029s	user 0.000s	sys 0.027s Metrics: {}
I20260812 06:16:37.759413 14738 maintenance_manager.cc:419] P 1c3f185fe7da4c38acee9da60c33f143: Scheduling FlushDeltaMemStoresOp(e4d13557f1e0463e846ffed5b9eb6ab5): perf score=3.181125
I20260812 06:16:37.772445 14624 maintenance_manager.cc:643] P 1c3f185fe7da4c38acee9da60c33f143: FlushDeltaMemStoresOp(e4d13557f1e0463e846ffed5b9eb6ab5) complete. Timing: real 0.013s	user 0.003s	sys 0.008s Metrics: {"bytes_written":4635980,"delete_count":0,"lbm_write_time_us":5121,"lbm_writes_lt_1ms":116,"reinsert_count":0,"update_count":565}
I20260812 06:16:37.773015 14738 maintenance_manager.cc:419] P 1c3f185fe7da4c38acee9da60c33f143: Scheduling FlushDeltaMemStoresOp(e4d13557f1e0463e846ffed5b9eb6ab5): perf score=2.188937
I20260812 06:16:37.783104 14624 maintenance_manager.cc:643] P 1c3f185fe7da4c38acee9da60c33f143: FlushDeltaMemStoresOp(e4d13557f1e0463e846ffed5b9eb6ab5) complete. Timing: real 0.010s	user 0.005s	sys 0.004s Metrics: {"bytes_written":3569330,"delete_count":0,"lbm_write_time_us":3854,"lbm_writes_lt_1ms":90,"reinsert_count":0,"update_count":435}
I20260812 06:16:37.783560 14738 maintenance_manager.cc:419] P 1c3f185fe7da4c38acee9da60c33f143: Scheduling UndoDeltaBlockGCOp(e4d13557f1e0463e846ffed5b9eb6ab5): 462 bytes on disk
I20260812 06:16:37.784094 14624 maintenance_manager.cc:643] P 1c3f185fe7da4c38acee9da60c33f143: UndoDeltaBlockGCOp(e4d13557f1e0463e846ffed5b9eb6ab5) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":73,"lbm_reads_lt_1ms":4}
I20260812 06:16:37.785390 14738 maintenance_manager.cc:419] P 1c3f185fe7da4c38acee9da60c33f143: Scheduling MajorDeltaCompactionOp(e4d13557f1e0463e846ffed5b9eb6ab5): perf score=1.000000
I20260812 06:16:37.963192 14624 maintenance_manager.cc:643] P 1c3f185fe7da4c38acee9da60c33f143: MajorDeltaCompactionOp(e4d13557f1e0463e846ffed5b9eb6ab5) complete. Timing: real 0.178s	user 0.132s	sys 0.041s Metrics: {"cfile_cache_miss":634,"cfile_cache_miss_bytes":28877331,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":670,"lbm_read_time_us":13953,"lbm_reads_lt_1ms":674,"lbm_write_time_us":33240,"lbm_writes_lt_1ms":643,"mutex_wait_us":32,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":242688,"thread_start_us":108,"threads_started":1,"update_count":3000}
I20260812 06:16:37.964107 14738 maintenance_manager.cc:419] P 1c3f185fe7da4c38acee9da60c33f143: Scheduling FlushDeltaMemStoresOp(e4d13557f1e0463e846ffed5b9eb6ab5): perf score=14.095187
I20260812 06:16:38.014549 14022 heavy-update-compaction-itest.cc:229] Time spent updating: real 4.940s	user 1.920s	sys 0.170s
I20260812 06:16:38.017493 14624 maintenance_manager.cc:643] P 1c3f185fe7da4c38acee9da60c33f143: FlushDeltaMemStoresOp(e4d13557f1e0463e846ffed5b9eb6ab5) complete. Timing: real 0.053s	user 0.023s	sys 0.024s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":21464,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:16:38.017959 14738 maintenance_manager.cc:419] P 1c3f185fe7da4c38acee9da60c33f143: Scheduling FlushDeltaMemStoresOp(e4d13557f1e0463e846ffed5b9eb6ab5): perf score=2.188937
I20260812 06:16:38.029062 14624 maintenance_manager.cc:643] P 1c3f185fe7da4c38acee9da60c33f143: FlushDeltaMemStoresOp(e4d13557f1e0463e846ffed5b9eb6ab5) complete. Timing: real 0.011s	user 0.010s	sys 0.001s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4645,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:38.029495 14738 maintenance_manager.cc:419] P 1c3f185fe7da4c38acee9da60c33f143: Scheduling MajorDeltaCompactionOp(e4d13557f1e0463e846ffed5b9eb6ab5): perf score=1.000000
I20260812 06:16:38.058225 14022 heavy-update-compaction-itest.cc:265] Time spent scanning: real 0.043s	user 0.001s	sys 0.000s
I20260812 06:16:38.058735 14022 tablet_server.cc:179] TabletServer@127.13.177.129:0 shutting down...
I20260812 06:16:38.138068 14624 maintenance_manager.cc:643] P 1c3f185fe7da4c38acee9da60c33f143: MajorDeltaCompactionOp(e4d13557f1e0463e846ffed5b9eb6ab5) complete. Timing: real 0.108s	user 0.082s	sys 0.026s Metrics: {"cfile_cache_hit":401,"cfile_cache_hit_bytes":16409767,"cfile_cache_miss":131,"cfile_cache_miss_bytes":8364921,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":368,"lbm_read_time_us":3210,"lbm_reads_lt_1ms":163,"lbm_write_time_us":24993,"lbm_writes_lt_1ms":543,"mutex_wait_us":68,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":17152,"update_count":2500}
I20260812 06:16:38.138845 14022 ts_tablet_manager.cc:1507] Shutting down tablet manager...
I20260812 06:16:38.139106 14022 tablet_replica.cc:333] T e4d13557f1e0463e846ffed5b9eb6ab5 P 1c3f185fe7da4c38acee9da60c33f143: stopping tablet replica
I20260812 06:16:38.139292 14022 raft_consensus.cc:2243] T e4d13557f1e0463e846ffed5b9eb6ab5 P 1c3f185fe7da4c38acee9da60c33f143 [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:16:38.139470 14022 raft_consensus.cc:2272] T e4d13557f1e0463e846ffed5b9eb6ab5 P 1c3f185fe7da4c38acee9da60c33f143 [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:16:38.144207 14022 tablet_server.cc:196] TabletServer@127.13.177.129:0 shutdown complete.
I20260812 06:16:38.184079 14022 master.cc:562] Master@127.13.177.190:36421 shutting down...
I20260812 06:16:38.187849 14022 raft_consensus.cc:2243] T 00000000000000000000000000000000 P 6654f7b70ce0435b97f7fefebff5ffff [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:16:38.188004 14022 raft_consensus.cc:2272] T 00000000000000000000000000000000 P 6654f7b70ce0435b97f7fefebff5ffff [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:16:38.188051 14022 tablet_replica.cc:333] T 00000000000000000000000000000000 P 6654f7b70ce0435b97f7fefebff5ffff: stopping tablet replica
I20260812 06:16:38.200448 14022 master.cc:584] Master@127.13.177.190:36421 shutdown complete.
[       OK ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/1 (5464 ms)
[----------] 2 tests from EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy (12006 ms total)

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