[==========] 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:20:13.172503  5236 internal_mini_cluster.cc:156] Creating distributed mini masters. Addrs: 127.5.29.62:35407
I20260812 06:20:13.173511  5236 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:20:13.174105  5236 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:20:13.180222  5245 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:20:13.180271  5249 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:20:13.180462  5236 server_base.cc:1061] running on GCE node
W20260812 06:20:13.180598  5246 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:20:13.181094  5236 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:20:13.181214  5236 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:20:13.181277  5236 hybrid_clock.cc:648] HybridClock initialized: now 1786515613181275 us; error 0 us; skew 500 ppm
I20260812 06:20:13.182976  5236 webserver.cc:533] Webserver started at http://127.5.29.62:36883/ using document root <none> and password file <none>
I20260812 06:20:13.183508  5236 fs_manager.cc:362] Metadata directory not provided
I20260812 06:20:13.183598  5236 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:20:13.183857  5236 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:20:13.185527  5236 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-task_bOXbU/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515613161794-5236-0/minicluster-data/master-0-root/instance:
uuid: "2fdd4ba5685d492c83d0d06a05a3081e"
format_stamp: "Formatted at 2026-08-12 06:20:13 on dist-test-slave-zpvx"
I20260812 06:20:13.188858  5236 fs_manager.cc:696] Time spent creating directory manager: real 0.003s	user 0.004s	sys 0.000s
I20260812 06:20:13.190907  5256 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:20:13.191895  5236 fs_manager.cc:730] Time spent opening block manager: real 0.002s	user 0.002s	sys 0.000s
I20260812 06:20:13.192026  5236 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-task_bOXbU/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515613161794-5236-0/minicluster-data/master-0-root
uuid: "2fdd4ba5685d492c83d0d06a05a3081e"
format_stamp: "Formatted at 2026-08-12 06:20:13 on dist-test-slave-zpvx"
I20260812 06:20:13.192132  5236 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-task_bOXbU/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515613161794-5236-0/minicluster-data/master-0-root
metadata directory: /tmp/dist-test-task_bOXbU/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515613161794-5236-0/minicluster-data/master-0-root
1 data directories: /tmp/dist-test-task_bOXbU/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515613161794-5236-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:20:13.213608  5236 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:20:13.214247  5236 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:20:13.214432  5236 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:20:13.222374  5236 rpc_server.cc:307] RPC server started. Bound to: 127.5.29.62:35407
I20260812 06:20:13.222391  5362 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.5.29.62:35407 every 8 connection(s)
I20260812 06:20:13.224721  5364 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:20:13.230010  5364 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P 2fdd4ba5685d492c83d0d06a05a3081e: Bootstrap starting.
I20260812 06:20:13.232309  5364 tablet_bootstrap.cc:654] T 00000000000000000000000000000000 P 2fdd4ba5685d492c83d0d06a05a3081e: Neither blocks nor log segments found. Creating new log.
I20260812 06:20:13.233261  5364 log.cc:826] T 00000000000000000000000000000000 P 2fdd4ba5685d492c83d0d06a05a3081e: Log is configured to *not* fsync() on all Append() calls
I20260812 06:20:13.234907  5364 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P 2fdd4ba5685d492c83d0d06a05a3081e: No bootstrap required, opened a new log
I20260812 06:20:13.237705  5364 raft_consensus.cc:359] T 00000000000000000000000000000000 P 2fdd4ba5685d492c83d0d06a05a3081e [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "2fdd4ba5685d492c83d0d06a05a3081e" member_type: VOTER }
I20260812 06:20:13.237869  5364 raft_consensus.cc:385] T 00000000000000000000000000000000 P 2fdd4ba5685d492c83d0d06a05a3081e [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:20:13.237973  5364 raft_consensus.cc:740] T 00000000000000000000000000000000 P 2fdd4ba5685d492c83d0d06a05a3081e [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: 2fdd4ba5685d492c83d0d06a05a3081e, State: Initialized, Role: FOLLOWER
I20260812 06:20:13.238566  5364 consensus_queue.cc:260] T 00000000000000000000000000000000 P 2fdd4ba5685d492c83d0d06a05a3081e [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: "2fdd4ba5685d492c83d0d06a05a3081e" member_type: VOTER }
I20260812 06:20:13.238727  5364 raft_consensus.cc:399] T 00000000000000000000000000000000 P 2fdd4ba5685d492c83d0d06a05a3081e [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:20:13.238806  5364 raft_consensus.cc:493] T 00000000000000000000000000000000 P 2fdd4ba5685d492c83d0d06a05a3081e [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:20:13.238967  5364 raft_consensus.cc:3060] T 00000000000000000000000000000000 P 2fdd4ba5685d492c83d0d06a05a3081e [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:20:13.239770  5364 raft_consensus.cc:515] T 00000000000000000000000000000000 P 2fdd4ba5685d492c83d0d06a05a3081e [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "2fdd4ba5685d492c83d0d06a05a3081e" member_type: VOTER }
I20260812 06:20:13.240216  5364 leader_election.cc:304] T 00000000000000000000000000000000 P 2fdd4ba5685d492c83d0d06a05a3081e [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: 2fdd4ba5685d492c83d0d06a05a3081e; no voters: 
I20260812 06:20:13.240556  5364 leader_election.cc:290] T 00000000000000000000000000000000 P 2fdd4ba5685d492c83d0d06a05a3081e [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:20:13.240706  5368 raft_consensus.cc:2804] T 00000000000000000000000000000000 P 2fdd4ba5685d492c83d0d06a05a3081e [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:20:13.240948  5368 raft_consensus.cc:697] T 00000000000000000000000000000000 P 2fdd4ba5685d492c83d0d06a05a3081e [term 1 LEADER]: Becoming Leader. State: Replica: 2fdd4ba5685d492c83d0d06a05a3081e, State: Running, Role: LEADER
I20260812 06:20:13.241380  5368 consensus_queue.cc:237] T 00000000000000000000000000000000 P 2fdd4ba5685d492c83d0d06a05a3081e [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: "2fdd4ba5685d492c83d0d06a05a3081e" member_type: VOTER }
I20260812 06:20:13.241588  5364 sys_catalog.cc:565] T 00000000000000000000000000000000 P 2fdd4ba5685d492c83d0d06a05a3081e [sys.catalog]: configured and running, proceeding with master startup.
I20260812 06:20:13.243322  5370 sys_catalog.cc:455] T 00000000000000000000000000000000 P 2fdd4ba5685d492c83d0d06a05a3081e [sys.catalog]: SysCatalogTable state changed. Reason: New leader 2fdd4ba5685d492c83d0d06a05a3081e. Latest consensus state: current_term: 1 leader_uuid: "2fdd4ba5685d492c83d0d06a05a3081e" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "2fdd4ba5685d492c83d0d06a05a3081e" member_type: VOTER } }
I20260812 06:20:13.243361  5369 sys_catalog.cc:455] T 00000000000000000000000000000000 P 2fdd4ba5685d492c83d0d06a05a3081e [sys.catalog]: SysCatalogTable state changed. Reason: RaftConsensus started. Latest consensus state: current_term: 1 leader_uuid: "2fdd4ba5685d492c83d0d06a05a3081e" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "2fdd4ba5685d492c83d0d06a05a3081e" member_type: VOTER } }
I20260812 06:20:13.243459  5370 sys_catalog.cc:458] T 00000000000000000000000000000000 P 2fdd4ba5685d492c83d0d06a05a3081e [sys.catalog]: This master's current role is: LEADER
I20260812 06:20:13.243460  5369 sys_catalog.cc:458] T 00000000000000000000000000000000 P 2fdd4ba5685d492c83d0d06a05a3081e [sys.catalog]: This master's current role is: LEADER
I20260812 06:20:13.243925  5385 catalog_manager.cc:1511] Loading table and tablet metadata into memory...
I20260812 06:20:13.244443  5236 internal_mini_cluster.cc:184] Waiting to initialize catalog manager on master 0
I20260812 06:20:13.246609  5385 catalog_manager.cc:1520] Initializing Kudu cluster ID...
I20260812 06:20:13.250864  5385 catalog_manager.cc:1383] Generated new cluster ID: 33f0b1652216428191cbc3c09c559dbb
I20260812 06:20:13.250927  5385 catalog_manager.cc:1531] Initializing Kudu internal certificate authority...
I20260812 06:20:13.284871  5385 catalog_manager.cc:1406] Generated new certificate authority record
I20260812 06:20:13.285804  5385 catalog_manager.cc:1540] Loading token signing keys...
I20260812 06:20:13.291137  5385 catalog_manager.cc:6092] T 00000000000000000000000000000000 P 2fdd4ba5685d492c83d0d06a05a3081e: Generated new TSK 0
I20260812 06:20:13.291766  5385 catalog_manager.cc:1550] Initializing in-progress tserver states...
I20260812 06:20:13.309460  5236 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:20:13.312463  5396 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:20:13.312541  5401 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:20:13.312556  5397 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:20:13.312726  5236 server_base.cc:1061] running on GCE node
I20260812 06:20:13.312976  5236 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:20:13.313026  5236 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:20:13.313050  5236 hybrid_clock.cc:648] HybridClock initialized: now 1786515613313049 us; error 0 us; skew 500 ppm
I20260812 06:20:13.314025  5236 webserver.cc:533] Webserver started at http://127.5.29.1:38561/ using document root <none> and password file <none>
I20260812 06:20:13.314198  5236 fs_manager.cc:362] Metadata directory not provided
I20260812 06:20:13.314256  5236 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:20:13.314324  5236 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:20:13.314766  5236 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-task_bOXbU/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515613161794-5236-0/minicluster-data/ts-0-root/instance:
uuid: "94b914dc65f548d29ab2172d8c20c7f7"
format_stamp: "Formatted at 2026-08-12 06:20:13 on dist-test-slave-zpvx"
I20260812 06:20:13.316650  5236 fs_manager.cc:696] Time spent creating directory manager: real 0.002s	user 0.002s	sys 0.000s
I20260812 06:20:13.317736  5415 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:20:13.318030  5236 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.001s	sys 0.000s
I20260812 06:20:13.318094  5236 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-task_bOXbU/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515613161794-5236-0/minicluster-data/ts-0-root
uuid: "94b914dc65f548d29ab2172d8c20c7f7"
format_stamp: "Formatted at 2026-08-12 06:20:13 on dist-test-slave-zpvx"
I20260812 06:20:13.318182  5236 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-task_bOXbU/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515613161794-5236-0/minicluster-data/ts-0-root
metadata directory: /tmp/dist-test-task_bOXbU/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515613161794-5236-0/minicluster-data/ts-0-root
1 data directories: /tmp/dist-test-task_bOXbU/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515613161794-5236-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:20:13.326783  5236 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:20:13.327190  5236 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:20:13.327679  5236 txn_system_client.cc:432] TxnSystemClient initialization is disabled...
I20260812 06:20:13.328540  5236 ts_tablet_manager.cc:585] Loaded tablet metadata (0 total tablets, 0 live tablets)
I20260812 06:20:13.328593  5236 ts_tablet_manager.cc:531] Time spent load tablet metadata: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:20:13.328658  5236 ts_tablet_manager.cc:616] Registered 0 tablets
I20260812 06:20:13.328704  5236 ts_tablet_manager.cc:595] Time spent register tablets: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:20:13.335270  5236 rpc_server.cc:307] RPC server started. Bound to: 127.5.29.1:40037
I20260812 06:20:13.335542  5535 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.5.29.1:40037 every 8 connection(s)
I20260812 06:20:13.348982  5536 heartbeater.cc:344] Connected to a master server at 127.5.29.62:35407
I20260812 06:20:13.349251  5536 heartbeater.cc:461] Registering TS with master...
I20260812 06:20:13.349753  5536 heartbeater.cc:507] Master 127.5.29.62:35407 requested a full tablet report, sending...
I20260812 06:20:13.351229  5292 ts_manager.cc:194] Registered new tserver with Master: 94b914dc65f548d29ab2172d8c20c7f7 (127.5.29.1:40037)
I20260812 06:20:13.351660  5236 internal_mini_cluster.cc:371] 1 TS(s) registered with all masters after 0.015702159s
I20260812 06:20:13.352732  5292 master_service.cc:502] Signed X509 certificate for tserver {username='slave'} at 127.0.0.1:56402
I20260812 06:20:13.361634  5292 catalog_manager.cc:2283] Servicing CreateTable request from {username='slave'} at 127.0.0.1:56404:
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:20:13.375312  5465 tablet_service.cc:1511] Processing CreateTablet for tablet 4d6991878cb445d8a9ed25942a28d84c (DEFAULT_TABLE table=heavy-update-compaction-test [id=a896a8f2047b4be2b1a1abd270a71aff]), partition=
I20260812 06:20:13.375800  5465 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet 4d6991878cb445d8a9ed25942a28d84c. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:20:13.378041  5559 tablet_bootstrap.cc:492] T 4d6991878cb445d8a9ed25942a28d84c P 94b914dc65f548d29ab2172d8c20c7f7: Bootstrap starting.
I20260812 06:20:13.379643  5559 tablet_bootstrap.cc:654] T 4d6991878cb445d8a9ed25942a28d84c P 94b914dc65f548d29ab2172d8c20c7f7: Neither blocks nor log segments found. Creating new log.
I20260812 06:20:13.380775  5559 tablet_bootstrap.cc:492] T 4d6991878cb445d8a9ed25942a28d84c P 94b914dc65f548d29ab2172d8c20c7f7: No bootstrap required, opened a new log
I20260812 06:20:13.380856  5559 ts_tablet_manager.cc:1403] T 4d6991878cb445d8a9ed25942a28d84c P 94b914dc65f548d29ab2172d8c20c7f7: Time spent bootstrapping tablet: real 0.003s	user 0.002s	sys 0.000s
I20260812 06:20:13.381317  5559 raft_consensus.cc:359] T 4d6991878cb445d8a9ed25942a28d84c P 94b914dc65f548d29ab2172d8c20c7f7 [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "94b914dc65f548d29ab2172d8c20c7f7" member_type: VOTER last_known_addr { host: "127.5.29.1" port: 40037 } }
I20260812 06:20:13.381417  5559 raft_consensus.cc:385] T 4d6991878cb445d8a9ed25942a28d84c P 94b914dc65f548d29ab2172d8c20c7f7 [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:20:13.381439  5559 raft_consensus.cc:740] T 4d6991878cb445d8a9ed25942a28d84c P 94b914dc65f548d29ab2172d8c20c7f7 [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: 94b914dc65f548d29ab2172d8c20c7f7, State: Initialized, Role: FOLLOWER
I20260812 06:20:13.381629  5559 consensus_queue.cc:260] T 4d6991878cb445d8a9ed25942a28d84c P 94b914dc65f548d29ab2172d8c20c7f7 [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: "94b914dc65f548d29ab2172d8c20c7f7" member_type: VOTER last_known_addr { host: "127.5.29.1" port: 40037 } }
I20260812 06:20:13.381722  5559 raft_consensus.cc:399] T 4d6991878cb445d8a9ed25942a28d84c P 94b914dc65f548d29ab2172d8c20c7f7 [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:20:13.381770  5559 raft_consensus.cc:493] T 4d6991878cb445d8a9ed25942a28d84c P 94b914dc65f548d29ab2172d8c20c7f7 [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:20:13.381829  5559 raft_consensus.cc:3060] T 4d6991878cb445d8a9ed25942a28d84c P 94b914dc65f548d29ab2172d8c20c7f7 [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:20:13.382686  5559 raft_consensus.cc:515] T 4d6991878cb445d8a9ed25942a28d84c P 94b914dc65f548d29ab2172d8c20c7f7 [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "94b914dc65f548d29ab2172d8c20c7f7" member_type: VOTER last_known_addr { host: "127.5.29.1" port: 40037 } }
I20260812 06:20:13.382844  5559 leader_election.cc:304] T 4d6991878cb445d8a9ed25942a28d84c P 94b914dc65f548d29ab2172d8c20c7f7 [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: 94b914dc65f548d29ab2172d8c20c7f7; no voters: 
I20260812 06:20:13.383100  5559 leader_election.cc:290] T 4d6991878cb445d8a9ed25942a28d84c P 94b914dc65f548d29ab2172d8c20c7f7 [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:20:13.383230  5561 raft_consensus.cc:2804] T 4d6991878cb445d8a9ed25942a28d84c P 94b914dc65f548d29ab2172d8c20c7f7 [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:20:13.383440  5559 ts_tablet_manager.cc:1434] T 4d6991878cb445d8a9ed25942a28d84c P 94b914dc65f548d29ab2172d8c20c7f7: Time spent starting tablet: real 0.002s	user 0.003s	sys 0.000s
I20260812 06:20:13.383513  5561 raft_consensus.cc:697] T 4d6991878cb445d8a9ed25942a28d84c P 94b914dc65f548d29ab2172d8c20c7f7 [term 1 LEADER]: Becoming Leader. State: Replica: 94b914dc65f548d29ab2172d8c20c7f7, State: Running, Role: LEADER
I20260812 06:20:13.383630  5536 heartbeater.cc:499] Master 127.5.29.62:35407 was elected leader, sending a full tablet report...
I20260812 06:20:13.383677  5561 consensus_queue.cc:237] T 4d6991878cb445d8a9ed25942a28d84c P 94b914dc65f548d29ab2172d8c20c7f7 [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: "94b914dc65f548d29ab2172d8c20c7f7" member_type: VOTER last_known_addr { host: "127.5.29.1" port: 40037 } }
I20260812 06:20:13.386564  5292 catalog_manager.cc:5719] T 4d6991878cb445d8a9ed25942a28d84c P 94b914dc65f548d29ab2172d8c20c7f7 reported cstate change: term changed from 0 to 1, leader changed from <none> to 94b914dc65f548d29ab2172d8c20c7f7 (127.5.29.1). New cstate: current_term: 1 leader_uuid: "94b914dc65f548d29ab2172d8c20c7f7" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "94b914dc65f548d29ab2172d8c20c7f7" member_type: VOTER last_known_addr { host: "127.5.29.1" port: 40037 } health_report { overall_health: HEALTHY } } }
I20260812 06:20:13.451730  5236 heavy-update-compaction-itest.cc:215] Time spent inserting: real 0.056s	user 0.014s	sys 0.013s
I20260812 06:20:13.586406  5537 maintenance_manager.cc:419] P 94b914dc65f548d29ab2172d8c20c7f7: Scheduling FlushMRSOp(4d6991878cb445d8a9ed25942a28d84c): perf score=19.054940
I20260812 06:20:13.773471  5422 maintenance_manager.cc:643] P 94b914dc65f548d29ab2172d8c20c7f7: FlushMRSOp(4d6991878cb445d8a9ed25942a28d84c) complete. Timing: real 0.187s	user 0.110s	sys 0.071s Metrics: {"bytes_written":12717736,"cfile_init":1,"compiler_manager_pool.queue_time_us":202,"delete_count":0,"dirs.queue_time_us":57,"dirs.run_cpu_time_us":178,"dirs.run_wall_time_us":747,"drs_written":1,"lbm_read_time_us":71,"lbm_reads_lt_1ms":4,"lbm_write_time_us":45222,"lbm_writes_lt_1ms":767,"peak_mem_usage":0,"reinsert_count":0,"rows_written":104,"spinlock_wait_cycles":447360,"thread_start_us":137,"threads_started":1,"update_count":1550}
I20260812 06:20:13.774840  5537 maintenance_manager.cc:419] P 94b914dc65f548d29ab2172d8c20c7f7: Scheduling LogGCOp(4d6991878cb445d8a9ed25942a28d84c): free 20743880 bytes of WAL
I20260812 06:20:13.775172  5422 log_reader.cc:385] T 4d6991878cb445d8a9ed25942a28d84c: removed 2 log segments from log reader
I20260812 06:20:13.775243  5422 log.cc:1079] T 4d6991878cb445d8a9ed25942a28d84c P 94b914dc65f548d29ab2172d8c20c7f7: Deleting log segment in path: /tmp/dist-test-task_bOXbU/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515613161794-5236-0/minicluster-data/ts-0-root/wals/4d6991878cb445d8a9ed25942a28d84c/wal-000000001 (ops 1-6)
I20260812 06:20:13.775300  5422 log.cc:1079] T 4d6991878cb445d8a9ed25942a28d84c P 94b914dc65f548d29ab2172d8c20c7f7: Deleting log segment in path: /tmp/dist-test-task_bOXbU/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515613161794-5236-0/minicluster-data/ts-0-root/wals/4d6991878cb445d8a9ed25942a28d84c/wal-000000002 (ops 7-11)
I20260812 06:20:13.781142  5422 maintenance_manager.cc:643] P 94b914dc65f548d29ab2172d8c20c7f7: LogGCOp(4d6991878cb445d8a9ed25942a28d84c) complete. Timing: real 0.006s	user 0.000s	sys 0.005s Metrics: {}
I20260812 06:20:13.781618  5537 maintenance_manager.cc:419] P 94b914dc65f548d29ab2172d8c20c7f7: Scheduling UndoDeltaBlockGCOp(4d6991878cb445d8a9ed25942a28d84c): 16411395 bytes on disk
I20260812 06:20:13.782291  5422 maintenance_manager.cc:643] P 94b914dc65f548d29ab2172d8c20c7f7: UndoDeltaBlockGCOp(4d6991878cb445d8a9ed25942a28d84c) complete. Timing: real 0.001s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":79,"lbm_reads_lt_1ms":4}
I20260812 06:20:13.782750  5537 maintenance_manager.cc:419] P 94b914dc65f548d29ab2172d8c20c7f7: Scheduling FlushDeltaMemStoresOp(4d6991878cb445d8a9ed25942a28d84c): perf score=2.188937
I20260812 06:20:13.817350  5422 maintenance_manager.cc:643] P 94b914dc65f548d29ab2172d8c20c7f7: FlushDeltaMemStoresOp(4d6991878cb445d8a9ed25942a28d84c) complete. Timing: real 0.034s	user 0.004s	sys 0.019s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":5909,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:20:13.817836  5537 maintenance_manager.cc:419] P 94b914dc65f548d29ab2172d8c20c7f7: Scheduling FlushDeltaMemStoresOp(4d6991878cb445d8a9ed25942a28d84c): perf score=2.188937
I20260812 06:20:13.834582  5422 maintenance_manager.cc:643] P 94b914dc65f548d29ab2172d8c20c7f7: FlushDeltaMemStoresOp(4d6991878cb445d8a9ed25942a28d84c) complete. Timing: real 0.017s	user 0.009s	sys 0.005s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6461,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:13.835230  5537 maintenance_manager.cc:419] P 94b914dc65f548d29ab2172d8c20c7f7: Scheduling MajorDeltaCompactionOp(4d6991878cb445d8a9ed25942a28d84c): perf score=1.000000
I20260812 06:20:14.017738  5422 maintenance_manager.cc:643] P 94b914dc65f548d29ab2172d8c20c7f7: MajorDeltaCompactionOp(4d6991878cb445d8a9ed25942a28d84c) complete. Timing: real 0.182s	user 0.123s	sys 0.059s Metrics: {"cfile_cache_miss":533,"cfile_cache_miss_bytes":24774800,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":1178,"lbm_read_time_us":13421,"lbm_reads_lt_1ms":569,"lbm_write_time_us":29645,"lbm_writes_lt_1ms":543,"mutex_wait_us":301,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":896,"thread_start_us":304,"threads_started":5,"update_count":2500}
I20260812 06:20:14.018294  5537 maintenance_manager.cc:419] P 94b914dc65f548d29ab2172d8c20c7f7: Scheduling FlushDeltaMemStoresOp(4d6991878cb445d8a9ed25942a28d84c): perf score=10.126437
I20260812 06:20:14.051177  5422 maintenance_manager.cc:643] P 94b914dc65f548d29ab2172d8c20c7f7: FlushDeltaMemStoresOp(4d6991878cb445d8a9ed25942a28d84c) complete. Timing: real 0.033s	user 0.021s	sys 0.009s Metrics: {"bytes_written":12307491,"delete_count":0,"lbm_write_time_us":14053,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:20:14.051899  5537 maintenance_manager.cc:419] P 94b914dc65f548d29ab2172d8c20c7f7: Scheduling FlushDeltaMemStoresOp(4d6991878cb445d8a9ed25942a28d84c): perf score=2.188937
I20260812 06:20:14.071759  5422 maintenance_manager.cc:643] P 94b914dc65f548d29ab2172d8c20c7f7: FlushDeltaMemStoresOp(4d6991878cb445d8a9ed25942a28d84c) complete. Timing: real 0.020s	user 0.011s	sys 0.003s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6707,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:14.072359  5537 maintenance_manager.cc:419] P 94b914dc65f548d29ab2172d8c20c7f7: Scheduling MajorDeltaCompactionOp(4d6991878cb445d8a9ed25942a28d84c): perf score=1.000000
I20260812 06:20:14.197691  5422 maintenance_manager.cc:643] P 94b914dc65f548d29ab2172d8c20c7f7: MajorDeltaCompactionOp(4d6991878cb445d8a9ed25942a28d84c) complete. Timing: real 0.125s	user 0.093s	sys 0.031s 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":166,"lbm_read_time_us":7397,"lbm_reads_lt_1ms":464,"lbm_write_time_us":24176,"lbm_writes_lt_1ms":443,"mutex_wait_us":82,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":13312,"update_count":2000}
I20260812 06:20:14.198307  5537 maintenance_manager.cc:419] P 94b914dc65f548d29ab2172d8c20c7f7: Scheduling FlushDeltaMemStoresOp(4d6991878cb445d8a9ed25942a28d84c): perf score=10.126437
I20260812 06:20:14.236189  5422 maintenance_manager.cc:643] P 94b914dc65f548d29ab2172d8c20c7f7: FlushDeltaMemStoresOp(4d6991878cb445d8a9ed25942a28d84c) complete. Timing: real 0.038s	user 0.018s	sys 0.017s Metrics: {"bytes_written":12307492,"delete_count":0,"lbm_write_time_us":16842,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:20:14.236663  5537 maintenance_manager.cc:419] P 94b914dc65f548d29ab2172d8c20c7f7: Scheduling FlushDeltaMemStoresOp(4d6991878cb445d8a9ed25942a28d84c): perf score=2.188937
I20260812 06:20:14.249938  5422 maintenance_manager.cc:643] P 94b914dc65f548d29ab2172d8c20c7f7: FlushDeltaMemStoresOp(4d6991878cb445d8a9ed25942a28d84c) complete. Timing: real 0.013s	user 0.007s	sys 0.005s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5003,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:14.250479  5537 maintenance_manager.cc:419] P 94b914dc65f548d29ab2172d8c20c7f7: Scheduling MajorDeltaCompactionOp(4d6991878cb445d8a9ed25942a28d84c): perf score=1.000000
I20260812 06:20:14.372344  5422 maintenance_manager.cc:643] P 94b914dc65f548d29ab2172d8c20c7f7: MajorDeltaCompactionOp(4d6991878cb445d8a9ed25942a28d84c) complete. Timing: real 0.122s	user 0.092s	sys 0.027s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672279,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":331,"lbm_read_time_us":8295,"lbm_reads_lt_1ms":464,"lbm_write_time_us":25373,"lbm_writes_lt_1ms":443,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":6016,"update_count":2000}
I20260812 06:20:14.372862  5537 maintenance_manager.cc:419] P 94b914dc65f548d29ab2172d8c20c7f7: Scheduling FlushDeltaMemStoresOp(4d6991878cb445d8a9ed25942a28d84c): perf score=10.126437
I20260812 06:20:14.423709  5422 maintenance_manager.cc:643] P 94b914dc65f548d29ab2172d8c20c7f7: FlushDeltaMemStoresOp(4d6991878cb445d8a9ed25942a28d84c) complete. Timing: real 0.051s	user 0.029s	sys 0.006s Metrics: {"bytes_written":12307491,"delete_count":0,"lbm_write_time_us":16481,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:20:14.424216  5537 maintenance_manager.cc:419] P 94b914dc65f548d29ab2172d8c20c7f7: Scheduling FlushDeltaMemStoresOp(4d6991878cb445d8a9ed25942a28d84c): perf score=2.188937
I20260812 06:20:14.434634  5422 maintenance_manager.cc:643] P 94b914dc65f548d29ab2172d8c20c7f7: FlushDeltaMemStoresOp(4d6991878cb445d8a9ed25942a28d84c) complete. Timing: real 0.010s	user 0.008s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3893,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:14.435161  5537 maintenance_manager.cc:419] P 94b914dc65f548d29ab2172d8c20c7f7: Scheduling MajorDeltaCompactionOp(4d6991878cb445d8a9ed25942a28d84c): perf score=1.000000
I20260812 06:20:14.560156  5422 maintenance_manager.cc:643] P 94b914dc65f548d29ab2172d8c20c7f7: MajorDeltaCompactionOp(4d6991878cb445d8a9ed25942a28d84c) complete. Timing: real 0.125s	user 0.099s	sys 0.024s 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":894,"lbm_read_time_us":8509,"lbm_reads_lt_1ms":472,"lbm_write_time_us":24520,"lbm_writes_lt_1ms":443,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":896,"update_count":2000}
I20260812 06:20:14.560916  5537 maintenance_manager.cc:419] P 94b914dc65f548d29ab2172d8c20c7f7: Scheduling FlushDeltaMemStoresOp(4d6991878cb445d8a9ed25942a28d84c): perf score=10.126437
I20260812 06:20:14.602984  5422 maintenance_manager.cc:643] P 94b914dc65f548d29ab2172d8c20c7f7: FlushDeltaMemStoresOp(4d6991878cb445d8a9ed25942a28d84c) complete. Timing: real 0.042s	user 0.033s	sys 0.006s Metrics: {"bytes_written":12307489,"delete_count":0,"lbm_write_time_us":14163,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:20:14.603518  5537 maintenance_manager.cc:419] P 94b914dc65f548d29ab2172d8c20c7f7: Scheduling FlushDeltaMemStoresOp(4d6991878cb445d8a9ed25942a28d84c): perf score=2.188937
I20260812 06:20:14.619822  5422 maintenance_manager.cc:643] P 94b914dc65f548d29ab2172d8c20c7f7: FlushDeltaMemStoresOp(4d6991878cb445d8a9ed25942a28d84c) complete. Timing: real 0.016s	user 0.014s	sys 0.000s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":6256,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:14.620481  5537 maintenance_manager.cc:419] P 94b914dc65f548d29ab2172d8c20c7f7: Scheduling MajorDeltaCompactionOp(4d6991878cb445d8a9ed25942a28d84c): perf score=1.000000
I20260812 06:20:14.776106  5422 maintenance_manager.cc:643] P 94b914dc65f548d29ab2172d8c20c7f7: MajorDeltaCompactionOp(4d6991878cb445d8a9ed25942a28d84c) complete. Timing: real 0.155s	user 0.122s	sys 0.033s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672275,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":170,"lbm_read_time_us":12490,"lbm_reads_lt_1ms":472,"lbm_write_time_us":24783,"lbm_writes_lt_1ms":443,"mutex_wait_us":40,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":896,"update_count":2000}
I20260812 06:20:14.776851  5537 maintenance_manager.cc:419] P 94b914dc65f548d29ab2172d8c20c7f7: Scheduling FlushDeltaMemStoresOp(4d6991878cb445d8a9ed25942a28d84c): perf score=10.126437
I20260812 06:20:14.828246  5422 maintenance_manager.cc:643] P 94b914dc65f548d29ab2172d8c20c7f7: FlushDeltaMemStoresOp(4d6991878cb445d8a9ed25942a28d84c) complete. Timing: real 0.051s	user 0.022s	sys 0.015s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":18441,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:20:14.828855  5537 maintenance_manager.cc:419] P 94b914dc65f548d29ab2172d8c20c7f7: Scheduling FlushDeltaMemStoresOp(4d6991878cb445d8a9ed25942a28d84c): perf score=2.188937
I20260812 06:20:14.839545  5422 maintenance_manager.cc:643] P 94b914dc65f548d29ab2172d8c20c7f7: FlushDeltaMemStoresOp(4d6991878cb445d8a9ed25942a28d84c) complete. Timing: real 0.010s	user 0.009s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3991,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:14.840082  5537 maintenance_manager.cc:419] P 94b914dc65f548d29ab2172d8c20c7f7: Scheduling MajorDeltaCompactionOp(4d6991878cb445d8a9ed25942a28d84c): perf score=1.000000
I20260812 06:20:14.990255  5422 maintenance_manager.cc:643] P 94b914dc65f548d29ab2172d8c20c7f7: MajorDeltaCompactionOp(4d6991878cb445d8a9ed25942a28d84c) complete. Timing: real 0.150s	user 0.137s	sys 0.011s 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":407,"lbm_read_time_us":11917,"lbm_reads_lt_1ms":472,"lbm_write_time_us":29133,"lbm_writes_lt_1ms":443,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":8320,"update_count":2000}
I20260812 06:20:14.990727  5537 maintenance_manager.cc:419] P 94b914dc65f548d29ab2172d8c20c7f7: Scheduling FlushDeltaMemStoresOp(4d6991878cb445d8a9ed25942a28d84c): perf score=10.126437
I20260812 06:20:15.033218  5422 maintenance_manager.cc:643] P 94b914dc65f548d29ab2172d8c20c7f7: FlushDeltaMemStoresOp(4d6991878cb445d8a9ed25942a28d84c) complete. Timing: real 0.042s	user 0.014s	sys 0.028s Metrics: {"bytes_written":12307489,"delete_count":0,"lbm_write_time_us":17705,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":302,"reinsert_count":0,"update_count":1500}
I20260812 06:20:15.033700  5537 maintenance_manager.cc:419] P 94b914dc65f548d29ab2172d8c20c7f7: Scheduling FlushDeltaMemStoresOp(4d6991878cb445d8a9ed25942a28d84c): perf score=2.188937
I20260812 06:20:15.043663  5422 maintenance_manager.cc:643] P 94b914dc65f548d29ab2172d8c20c7f7: FlushDeltaMemStoresOp(4d6991878cb445d8a9ed25942a28d84c) complete. Timing: real 0.010s	user 0.004s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3837,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:15.044191  5537 maintenance_manager.cc:419] P 94b914dc65f548d29ab2172d8c20c7f7: Scheduling FlushMRSOp(4d6991878cb445d8a9ed25942a28d84c): perf score=1.000000
I20260812 06:20:15.074200  5422 maintenance_manager.cc:643] P 94b914dc65f548d29ab2172d8c20c7f7: FlushMRSOp(4d6991878cb445d8a9ed25942a28d84c) complete. Timing: real 0.030s	user 0.024s	sys 0.005s Metrics: {"bytes_written":1193503,"cfile_init":1,"dirs.queue_time_us":59,"dirs.run_cpu_time_us":210,"dirs.run_wall_time_us":1172,"drs_written":1,"lbm_read_time_us":53,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1887,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":29}
I20260812 06:20:15.074965  5537 maintenance_manager.cc:419] P 94b914dc65f548d29ab2172d8c20c7f7: Scheduling LogGCOp(4d6991878cb445d8a9ed25942a28d84c): free 112239257 bytes of WAL
I20260812 06:20:15.075198  5422 log_reader.cc:385] T 4d6991878cb445d8a9ed25942a28d84c: removed 11 log segments from log reader
I20260812 06:20:15.075254  5422 log.cc:1079] T 4d6991878cb445d8a9ed25942a28d84c P 94b914dc65f548d29ab2172d8c20c7f7: Deleting log segment in path: /tmp/dist-test-task_bOXbU/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515613161794-5236-0/minicluster-data/ts-0-root/wals/4d6991878cb445d8a9ed25942a28d84c/wal-000000003 (ops 12-16)
I20260812 06:20:15.075290  5422 log.cc:1079] T 4d6991878cb445d8a9ed25942a28d84c P 94b914dc65f548d29ab2172d8c20c7f7: Deleting log segment in path: /tmp/dist-test-task_bOXbU/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515613161794-5236-0/minicluster-data/ts-0-root/wals/4d6991878cb445d8a9ed25942a28d84c/wal-000000004 (ops 17-21)
I20260812 06:20:15.075320  5422 log.cc:1079] T 4d6991878cb445d8a9ed25942a28d84c P 94b914dc65f548d29ab2172d8c20c7f7: Deleting log segment in path: /tmp/dist-test-task_bOXbU/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515613161794-5236-0/minicluster-data/ts-0-root/wals/4d6991878cb445d8a9ed25942a28d84c/wal-000000005 (ops 22-26)
I20260812 06:20:15.075351  5422 log.cc:1079] T 4d6991878cb445d8a9ed25942a28d84c P 94b914dc65f548d29ab2172d8c20c7f7: Deleting log segment in path: /tmp/dist-test-task_bOXbU/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515613161794-5236-0/minicluster-data/ts-0-root/wals/4d6991878cb445d8a9ed25942a28d84c/wal-000000006 (ops 27-30)
I20260812 06:20:15.075384  5422 log.cc:1079] T 4d6991878cb445d8a9ed25942a28d84c P 94b914dc65f548d29ab2172d8c20c7f7: Deleting log segment in path: /tmp/dist-test-task_bOXbU/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515613161794-5236-0/minicluster-data/ts-0-root/wals/4d6991878cb445d8a9ed25942a28d84c/wal-000000007 (ops 31-35)
I20260812 06:20:15.075415  5422 log.cc:1079] T 4d6991878cb445d8a9ed25942a28d84c P 94b914dc65f548d29ab2172d8c20c7f7: Deleting log segment in path: /tmp/dist-test-task_bOXbU/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515613161794-5236-0/minicluster-data/ts-0-root/wals/4d6991878cb445d8a9ed25942a28d84c/wal-000000008 (ops 36-40)
I20260812 06:20:15.075443  5422 log.cc:1079] T 4d6991878cb445d8a9ed25942a28d84c P 94b914dc65f548d29ab2172d8c20c7f7: Deleting log segment in path: /tmp/dist-test-task_bOXbU/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515613161794-5236-0/minicluster-data/ts-0-root/wals/4d6991878cb445d8a9ed25942a28d84c/wal-000000009 (ops 41-45)
I20260812 06:20:15.075469  5422 log.cc:1079] T 4d6991878cb445d8a9ed25942a28d84c P 94b914dc65f548d29ab2172d8c20c7f7: Deleting log segment in path: /tmp/dist-test-task_bOXbU/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515613161794-5236-0/minicluster-data/ts-0-root/wals/4d6991878cb445d8a9ed25942a28d84c/wal-000000010 (ops 46-50)
I20260812 06:20:15.075496  5422 log.cc:1079] T 4d6991878cb445d8a9ed25942a28d84c P 94b914dc65f548d29ab2172d8c20c7f7: Deleting log segment in path: /tmp/dist-test-task_bOXbU/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515613161794-5236-0/minicluster-data/ts-0-root/wals/4d6991878cb445d8a9ed25942a28d84c/wal-000000011 (ops 51-55)
I20260812 06:20:15.075531  5422 log.cc:1079] T 4d6991878cb445d8a9ed25942a28d84c P 94b914dc65f548d29ab2172d8c20c7f7: Deleting log segment in path: /tmp/dist-test-task_bOXbU/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515613161794-5236-0/minicluster-data/ts-0-root/wals/4d6991878cb445d8a9ed25942a28d84c/wal-000000012 (ops 56-60)
I20260812 06:20:15.075562  5422 log.cc:1079] T 4d6991878cb445d8a9ed25942a28d84c P 94b914dc65f548d29ab2172d8c20c7f7: Deleting log segment in path: /tmp/dist-test-task_bOXbU/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515613161794-5236-0/minicluster-data/ts-0-root/wals/4d6991878cb445d8a9ed25942a28d84c/wal-000000013 (ops 61-65)
I20260812 06:20:15.100883  5422 maintenance_manager.cc:643] P 94b914dc65f548d29ab2172d8c20c7f7: LogGCOp(4d6991878cb445d8a9ed25942a28d84c) complete. Timing: real 0.026s	user 0.000s	sys 0.025s Metrics: {}
I20260812 06:20:15.101289  5537 maintenance_manager.cc:419] P 94b914dc65f548d29ab2172d8c20c7f7: Scheduling UndoDeltaBlockGCOp(4d6991878cb445d8a9ed25942a28d84c): 461 bytes on disk
I20260812 06:20:15.101727  5422 maintenance_manager.cc:643] P 94b914dc65f548d29ab2172d8c20c7f7: UndoDeltaBlockGCOp(4d6991878cb445d8a9ed25942a28d84c) 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:20:15.102192  5537 maintenance_manager.cc:419] P 94b914dc65f548d29ab2172d8c20c7f7: Scheduling FlushDeltaMemStoresOp(4d6991878cb445d8a9ed25942a28d84c): perf score=2.188937
I20260812 06:20:15.120115  5422 maintenance_manager.cc:643] P 94b914dc65f548d29ab2172d8c20c7f7: FlushDeltaMemStoresOp(4d6991878cb445d8a9ed25942a28d84c) complete. Timing: real 0.018s	user 0.003s	sys 0.007s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4347,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:15.120555  5537 maintenance_manager.cc:419] P 94b914dc65f548d29ab2172d8c20c7f7: Scheduling FlushDeltaMemStoresOp(4d6991878cb445d8a9ed25942a28d84c): perf score=2.188937
I20260812 06:20:15.130348  5422 maintenance_manager.cc:643] P 94b914dc65f548d29ab2172d8c20c7f7: FlushDeltaMemStoresOp(4d6991878cb445d8a9ed25942a28d84c) complete. Timing: real 0.010s	user 0.004s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3962,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:15.130730  5537 maintenance_manager.cc:419] P 94b914dc65f548d29ab2172d8c20c7f7: Scheduling MajorDeltaCompactionOp(4d6991878cb445d8a9ed25942a28d84c): perf score=1.000000
I20260812 06:20:15.304343  5422 maintenance_manager.cc:643] P 94b914dc65f548d29ab2172d8c20c7f7: MajorDeltaCompactionOp(4d6991878cb445d8a9ed25942a28d84c) complete. Timing: real 0.173s	user 0.138s	sys 0.029s 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":694,"lbm_read_time_us":10745,"lbm_reads_lt_1ms":674,"lbm_write_time_us":37154,"lbm_writes_lt_1ms":643,"mutex_wait_us":41,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":3328,"thread_start_us":78,"threads_started":1,"update_count":3000}
I20260812 06:20:15.305614  5537 maintenance_manager.cc:419] P 94b914dc65f548d29ab2172d8c20c7f7: Scheduling FlushDeltaMemStoresOp(4d6991878cb445d8a9ed25942a28d84c): perf score=14.095187
I20260812 06:20:15.352792  5422 maintenance_manager.cc:643] P 94b914dc65f548d29ab2172d8c20c7f7: FlushDeltaMemStoresOp(4d6991878cb445d8a9ed25942a28d84c) complete. Timing: real 0.047s	user 0.024s	sys 0.022s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":21078,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:20:15.353482  5537 maintenance_manager.cc:419] P 94b914dc65f548d29ab2172d8c20c7f7: Scheduling FlushDeltaMemStoresOp(4d6991878cb445d8a9ed25942a28d84c): perf score=2.188937
I20260812 06:20:15.366248  5422 maintenance_manager.cc:643] P 94b914dc65f548d29ab2172d8c20c7f7: FlushDeltaMemStoresOp(4d6991878cb445d8a9ed25942a28d84c) complete. Timing: real 0.013s	user 0.010s	sys 0.001s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4820,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:15.366680  5537 maintenance_manager.cc:419] P 94b914dc65f548d29ab2172d8c20c7f7: Scheduling MajorDeltaCompactionOp(4d6991878cb445d8a9ed25942a28d84c): perf score=1.000000
I20260812 06:20:15.524328  5422 maintenance_manager.cc:643] P 94b914dc65f548d29ab2172d8c20c7f7: MajorDeltaCompactionOp(4d6991878cb445d8a9ed25942a28d84c) complete. Timing: real 0.157s	user 0.107s	sys 0.040s 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":199,"lbm_read_time_us":11203,"lbm_reads_lt_1ms":572,"lbm_write_time_us":30183,"lbm_writes_lt_1ms":543,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":2560,"update_count":2500}
I20260812 06:20:15.524962  5537 maintenance_manager.cc:419] P 94b914dc65f548d29ab2172d8c20c7f7: Scheduling FlushDeltaMemStoresOp(4d6991878cb445d8a9ed25942a28d84c): perf score=14.095187
I20260812 06:20:15.587142  5422 maintenance_manager.cc:643] P 94b914dc65f548d29ab2172d8c20c7f7: FlushDeltaMemStoresOp(4d6991878cb445d8a9ed25942a28d84c) complete. Timing: real 0.062s	user 0.032s	sys 0.019s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":22642,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":402,"reinsert_count":0,"update_count":2000}
I20260812 06:20:15.587639  5537 maintenance_manager.cc:419] P 94b914dc65f548d29ab2172d8c20c7f7: Scheduling FlushDeltaMemStoresOp(4d6991878cb445d8a9ed25942a28d84c): perf score=2.188937
I20260812 06:20:15.598229  5422 maintenance_manager.cc:643] P 94b914dc65f548d29ab2172d8c20c7f7: FlushDeltaMemStoresOp(4d6991878cb445d8a9ed25942a28d84c) complete. Timing: real 0.010s	user 0.008s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3902,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:15.598826  5537 maintenance_manager.cc:419] P 94b914dc65f548d29ab2172d8c20c7f7: Scheduling MajorDeltaCompactionOp(4d6991878cb445d8a9ed25942a28d84c): perf score=1.000000
I20260812 06:20:15.771893  5422 maintenance_manager.cc:643] P 94b914dc65f548d29ab2172d8c20c7f7: MajorDeltaCompactionOp(4d6991878cb445d8a9ed25942a28d84c) complete. Timing: real 0.173s	user 0.117s	sys 0.052s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774689,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":994,"lbm_read_time_us":11523,"lbm_reads_lt_1ms":572,"lbm_write_time_us":30869,"lbm_writes_lt_1ms":543,"mutex_wait_us":32,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":12928,"update_count":2500}
I20260812 06:20:15.772615  5537 maintenance_manager.cc:419] P 94b914dc65f548d29ab2172d8c20c7f7: Scheduling FlushDeltaMemStoresOp(4d6991878cb445d8a9ed25942a28d84c): perf score=14.095187
I20260812 06:20:15.814659  5422 maintenance_manager.cc:643] P 94b914dc65f548d29ab2172d8c20c7f7: FlushDeltaMemStoresOp(4d6991878cb445d8a9ed25942a28d84c) complete. Timing: real 0.042s	user 0.027s	sys 0.012s Metrics: {"bytes_written":16409903,"delete_count":0,"lbm_write_time_us":18483,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:20:15.816676  5537 maintenance_manager.cc:419] P 94b914dc65f548d29ab2172d8c20c7f7: Scheduling MajorDeltaCompactionOp(4d6991878cb445d8a9ed25942a28d84c): perf score=1.000000
I20260812 06:20:15.965487  5422 maintenance_manager.cc:643] P 94b914dc65f548d29ab2172d8c20c7f7: MajorDeltaCompactionOp(4d6991878cb445d8a9ed25942a28d84c) complete. Timing: real 0.149s	user 0.100s	sys 0.041s Metrics: {"cfile_cache_miss":431,"cfile_cache_miss_bytes":20672159,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":1,"delta_iterators_relevant":1,"dirs.queue_time_us":1260,"lbm_read_time_us":8229,"lbm_reads_lt_1ms":467,"lbm_write_time_us":24312,"lbm_writes_lt_1ms":443,"mutex_wait_us":269,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":8320,"update_count":2000}
I20260812 06:20:15.966295  5537 maintenance_manager.cc:419] P 94b914dc65f548d29ab2172d8c20c7f7: Scheduling FlushDeltaMemStoresOp(4d6991878cb445d8a9ed25942a28d84c): perf score=14.095187
I20260812 06:20:16.011986  5422 maintenance_manager.cc:643] P 94b914dc65f548d29ab2172d8c20c7f7: FlushDeltaMemStoresOp(4d6991878cb445d8a9ed25942a28d84c) complete. Timing: real 0.046s	user 0.028s	sys 0.012s Metrics: {"bytes_written":16409898,"delete_count":0,"lbm_write_time_us":19639,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:20:16.012575  5537 maintenance_manager.cc:419] P 94b914dc65f548d29ab2172d8c20c7f7: Scheduling FlushDeltaMemStoresOp(4d6991878cb445d8a9ed25942a28d84c): perf score=2.188937
I20260812 06:20:16.024430  5422 maintenance_manager.cc:643] P 94b914dc65f548d29ab2172d8c20c7f7: FlushDeltaMemStoresOp(4d6991878cb445d8a9ed25942a28d84c) complete. Timing: real 0.012s	user 0.009s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4203,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:16.024921  5537 maintenance_manager.cc:419] P 94b914dc65f548d29ab2172d8c20c7f7: Scheduling MajorDeltaCompactionOp(4d6991878cb445d8a9ed25942a28d84c): perf score=1.000000
I20260812 06:20:16.201462  5422 maintenance_manager.cc:643] P 94b914dc65f548d29ab2172d8c20c7f7: MajorDeltaCompactionOp(4d6991878cb445d8a9ed25942a28d84c) complete. Timing: real 0.176s	user 0.112s	sys 0.060s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774685,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":275,"lbm_read_time_us":10406,"lbm_reads_lt_1ms":572,"lbm_write_time_us":28584,"lbm_writes_lt_1ms":543,"mutex_wait_us":22,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":11008,"update_count":2500}
I20260812 06:20:16.202163  5537 maintenance_manager.cc:419] P 94b914dc65f548d29ab2172d8c20c7f7: Scheduling FlushDeltaMemStoresOp(4d6991878cb445d8a9ed25942a28d84c): perf score=14.095187
I20260812 06:20:16.257563  5422 maintenance_manager.cc:643] P 94b914dc65f548d29ab2172d8c20c7f7: FlushDeltaMemStoresOp(4d6991878cb445d8a9ed25942a28d84c) complete. Timing: real 0.055s	user 0.034s	sys 0.020s Metrics: {"bytes_written":16409903,"delete_count":0,"lbm_write_time_us":25565,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":402,"reinsert_count":0,"update_count":2000}
I20260812 06:20:16.258070  5537 maintenance_manager.cc:419] P 94b914dc65f548d29ab2172d8c20c7f7: Scheduling FlushDeltaMemStoresOp(4d6991878cb445d8a9ed25942a28d84c): perf score=2.188937
I20260812 06:20:16.271664  5422 maintenance_manager.cc:643] P 94b914dc65f548d29ab2172d8c20c7f7: FlushDeltaMemStoresOp(4d6991878cb445d8a9ed25942a28d84c) complete. Timing: real 0.013s	user 0.003s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5221,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:16.272320  5537 maintenance_manager.cc:419] P 94b914dc65f548d29ab2172d8c20c7f7: Scheduling MajorDeltaCompactionOp(4d6991878cb445d8a9ed25942a28d84c): perf score=1.000000
I20260812 06:20:16.432044  5422 maintenance_manager.cc:643] P 94b914dc65f548d29ab2172d8c20c7f7: MajorDeltaCompactionOp(4d6991878cb445d8a9ed25942a28d84c) complete. Timing: real 0.160s	user 0.114s	sys 0.038s 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":574,"lbm_read_time_us":10493,"lbm_reads_lt_1ms":572,"lbm_write_time_us":28995,"lbm_writes_lt_1ms":543,"mutex_wait_us":305,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":13440,"update_count":2500}
I20260812 06:20:16.432659  5537 maintenance_manager.cc:419] P 94b914dc65f548d29ab2172d8c20c7f7: Scheduling FlushDeltaMemStoresOp(4d6991878cb445d8a9ed25942a28d84c): perf score=14.095187
I20260812 06:20:16.489269  5422 maintenance_manager.cc:643] P 94b914dc65f548d29ab2172d8c20c7f7: FlushDeltaMemStoresOp(4d6991878cb445d8a9ed25942a28d84c) complete. Timing: real 0.056s	user 0.028s	sys 0.025s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":24053,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:20:16.489723  5537 maintenance_manager.cc:419] P 94b914dc65f548d29ab2172d8c20c7f7: Scheduling FlushDeltaMemStoresOp(4d6991878cb445d8a9ed25942a28d84c): perf score=2.188937
I20260812 06:20:16.501077  5422 maintenance_manager.cc:643] P 94b914dc65f548d29ab2172d8c20c7f7: FlushDeltaMemStoresOp(4d6991878cb445d8a9ed25942a28d84c) complete. Timing: real 0.011s	user 0.006s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4348,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:16.501574  5537 maintenance_manager.cc:419] P 94b914dc65f548d29ab2172d8c20c7f7: Scheduling FlushMRSOp(4d6991878cb445d8a9ed25942a28d84c): perf score=1.000000
I20260812 06:20:16.531205  5422 maintenance_manager.cc:643] P 94b914dc65f548d29ab2172d8c20c7f7: FlushMRSOp(4d6991878cb445d8a9ed25942a28d84c) complete. Timing: real 0.029s	user 0.028s	sys 0.000s Metrics: {"bytes_written":1275449,"cfile_init":1,"dirs.queue_time_us":62,"dirs.run_cpu_time_us":191,"dirs.run_wall_time_us":1215,"drs_written":1,"lbm_read_time_us":40,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1396,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":31}
I20260812 06:20:16.531912  5537 maintenance_manager.cc:419] P 94b914dc65f548d29ab2172d8c20c7f7: Scheduling LogGCOp(4d6991878cb445d8a9ed25942a28d84c): free 132571365 bytes of WAL
I20260812 06:20:16.532135  5422 log_reader.cc:385] T 4d6991878cb445d8a9ed25942a28d84c: removed 13 log segments from log reader
I20260812 06:20:16.532178  5422 log.cc:1079] T 4d6991878cb445d8a9ed25942a28d84c P 94b914dc65f548d29ab2172d8c20c7f7: Deleting log segment in path: /tmp/dist-test-task_bOXbU/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515613161794-5236-0/minicluster-data/ts-0-root/wals/4d6991878cb445d8a9ed25942a28d84c/wal-000000014 (ops 66-70)
I20260812 06:20:16.532207  5422 log.cc:1079] T 4d6991878cb445d8a9ed25942a28d84c P 94b914dc65f548d29ab2172d8c20c7f7: Deleting log segment in path: /tmp/dist-test-task_bOXbU/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515613161794-5236-0/minicluster-data/ts-0-root/wals/4d6991878cb445d8a9ed25942a28d84c/wal-000000015 (ops 71-74)
I20260812 06:20:16.532269  5422 log.cc:1079] T 4d6991878cb445d8a9ed25942a28d84c P 94b914dc65f548d29ab2172d8c20c7f7: Deleting log segment in path: /tmp/dist-test-task_bOXbU/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515613161794-5236-0/minicluster-data/ts-0-root/wals/4d6991878cb445d8a9ed25942a28d84c/wal-000000016 (ops 75-79)
I20260812 06:20:16.532318  5422 log.cc:1079] T 4d6991878cb445d8a9ed25942a28d84c P 94b914dc65f548d29ab2172d8c20c7f7: Deleting log segment in path: /tmp/dist-test-task_bOXbU/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515613161794-5236-0/minicluster-data/ts-0-root/wals/4d6991878cb445d8a9ed25942a28d84c/wal-000000017 (ops 80-84)
I20260812 06:20:16.532359  5422 log.cc:1079] T 4d6991878cb445d8a9ed25942a28d84c P 94b914dc65f548d29ab2172d8c20c7f7: Deleting log segment in path: /tmp/dist-test-task_bOXbU/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515613161794-5236-0/minicluster-data/ts-0-root/wals/4d6991878cb445d8a9ed25942a28d84c/wal-000000018 (ops 85-89)
I20260812 06:20:16.532447  5422 log.cc:1079] T 4d6991878cb445d8a9ed25942a28d84c P 94b914dc65f548d29ab2172d8c20c7f7: Deleting log segment in path: /tmp/dist-test-task_bOXbU/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515613161794-5236-0/minicluster-data/ts-0-root/wals/4d6991878cb445d8a9ed25942a28d84c/wal-000000019 (ops 90-94)
I20260812 06:20:16.532490  5422 log.cc:1079] T 4d6991878cb445d8a9ed25942a28d84c P 94b914dc65f548d29ab2172d8c20c7f7: Deleting log segment in path: /tmp/dist-test-task_bOXbU/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515613161794-5236-0/minicluster-data/ts-0-root/wals/4d6991878cb445d8a9ed25942a28d84c/wal-000000020 (ops 95-99)
I20260812 06:20:16.532531  5422 log.cc:1079] T 4d6991878cb445d8a9ed25942a28d84c P 94b914dc65f548d29ab2172d8c20c7f7: Deleting log segment in path: /tmp/dist-test-task_bOXbU/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515613161794-5236-0/minicluster-data/ts-0-root/wals/4d6991878cb445d8a9ed25942a28d84c/wal-000000021 (ops 100-104)
I20260812 06:20:16.532567  5422 log.cc:1079] T 4d6991878cb445d8a9ed25942a28d84c P 94b914dc65f548d29ab2172d8c20c7f7: Deleting log segment in path: /tmp/dist-test-task_bOXbU/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515613161794-5236-0/minicluster-data/ts-0-root/wals/4d6991878cb445d8a9ed25942a28d84c/wal-000000022 (ops 105-108)
I20260812 06:20:16.532608  5422 log.cc:1079] T 4d6991878cb445d8a9ed25942a28d84c P 94b914dc65f548d29ab2172d8c20c7f7: Deleting log segment in path: /tmp/dist-test-task_bOXbU/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515613161794-5236-0/minicluster-data/ts-0-root/wals/4d6991878cb445d8a9ed25942a28d84c/wal-000000023 (ops 109-113)
I20260812 06:20:16.532649  5422 log.cc:1079] T 4d6991878cb445d8a9ed25942a28d84c P 94b914dc65f548d29ab2172d8c20c7f7: Deleting log segment in path: /tmp/dist-test-task_bOXbU/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515613161794-5236-0/minicluster-data/ts-0-root/wals/4d6991878cb445d8a9ed25942a28d84c/wal-000000024 (ops 114-118)
I20260812 06:20:16.532689  5422 log.cc:1079] T 4d6991878cb445d8a9ed25942a28d84c P 94b914dc65f548d29ab2172d8c20c7f7: Deleting log segment in path: /tmp/dist-test-task_bOXbU/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515613161794-5236-0/minicluster-data/ts-0-root/wals/4d6991878cb445d8a9ed25942a28d84c/wal-000000025 (ops 119-123)
I20260812 06:20:16.532728  5422 log.cc:1079] T 4d6991878cb445d8a9ed25942a28d84c P 94b914dc65f548d29ab2172d8c20c7f7: Deleting log segment in path: /tmp/dist-test-task_bOXbU/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515613161794-5236-0/minicluster-data/ts-0-root/wals/4d6991878cb445d8a9ed25942a28d84c/wal-000000026 (ops 124-128)
I20260812 06:20:16.560684  5422 maintenance_manager.cc:643] P 94b914dc65f548d29ab2172d8c20c7f7: LogGCOp(4d6991878cb445d8a9ed25942a28d84c) complete. Timing: real 0.029s	user 0.000s	sys 0.028s Metrics: {}
I20260812 06:20:16.561071  5537 maintenance_manager.cc:419] P 94b914dc65f548d29ab2172d8c20c7f7: Scheduling FlushDeltaMemStoresOp(4d6991878cb445d8a9ed25942a28d84c): perf score=6.157687
I20260812 06:20:16.589673  5422 maintenance_manager.cc:643] P 94b914dc65f548d29ab2172d8c20c7f7: FlushDeltaMemStoresOp(4d6991878cb445d8a9ed25942a28d84c) complete. Timing: real 0.028s	user 0.017s	sys 0.003s Metrics: {"bytes_written":8082005,"delete_count":0,"lbm_write_time_us":9393,"lbm_writes_lt_1ms":200,"reinsert_count":0,"update_count":985}
I20260812 06:20:16.590166  5537 maintenance_manager.cc:419] P 94b914dc65f548d29ab2172d8c20c7f7: Scheduling UndoDeltaBlockGCOp(4d6991878cb445d8a9ed25942a28d84c): 483 bytes on disk
I20260812 06:20:16.590561  5422 maintenance_manager.cc:643] P 94b914dc65f548d29ab2172d8c20c7f7: UndoDeltaBlockGCOp(4d6991878cb445d8a9ed25942a28d84c) 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:20:16.591046  5537 maintenance_manager.cc:419] P 94b914dc65f548d29ab2172d8c20c7f7: Scheduling MajorDeltaCompactionOp(4d6991878cb445d8a9ed25942a28d84c): perf score=1.000000
I20260812 06:20:16.814699  5422 maintenance_manager.cc:643] P 94b914dc65f548d29ab2172d8c20c7f7: MajorDeltaCompactionOp(4d6991878cb445d8a9ed25942a28d84c) complete. Timing: real 0.223s	user 0.154s	sys 0.063s Metrics: {"cfile_cache_miss":730,"cfile_cache_miss_bytes":32856560,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":774,"lbm_read_time_us":15385,"lbm_reads_lt_1ms":762,"lbm_write_time_us":36646,"lbm_writes_lt_1ms":740,"mutex_wait_us":340,"peak_mem_usage":86805555,"reinsert_count":0,"spinlock_wait_cycles":2944,"thread_start_us":76,"threads_started":1,"update_count":3485}
I20260812 06:20:16.815462  5537 maintenance_manager.cc:419] P 94b914dc65f548d29ab2172d8c20c7f7: Scheduling FlushDeltaMemStoresOp(4d6991878cb445d8a9ed25942a28d84c): perf score=19.056125
I20260812 06:20:16.872958  5422 maintenance_manager.cc:643] P 94b914dc65f548d29ab2172d8c20c7f7: FlushDeltaMemStoresOp(4d6991878cb445d8a9ed25942a28d84c) complete. Timing: real 0.057s	user 0.031s	sys 0.020s Metrics: {"bytes_written":20635393,"delete_count":0,"lbm_write_time_us":23733,"lbm_writes_lt_1ms":506,"reinsert_count":0,"update_count":2515}
I20260812 06:20:16.873571  5537 maintenance_manager.cc:419] P 94b914dc65f548d29ab2172d8c20c7f7: Scheduling FlushDeltaMemStoresOp(4d6991878cb445d8a9ed25942a28d84c): perf score=2.188937
I20260812 06:20:16.886628  5422 maintenance_manager.cc:643] P 94b914dc65f548d29ab2172d8c20c7f7: FlushDeltaMemStoresOp(4d6991878cb445d8a9ed25942a28d84c) complete. Timing: real 0.013s	user 0.006s	sys 0.005s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4876,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:16.887188  5537 maintenance_manager.cc:419] P 94b914dc65f548d29ab2172d8c20c7f7: Scheduling MajorDeltaCompactionOp(4d6991878cb445d8a9ed25942a28d84c): perf score=1.000000
I20260812 06:20:17.085553  5422 maintenance_manager.cc:643] P 94b914dc65f548d29ab2172d8c20c7f7: MajorDeltaCompactionOp(4d6991878cb445d8a9ed25942a28d84c) complete. Timing: real 0.198s	user 0.147s	sys 0.051s Metrics: {"cfile_cache_miss":635,"cfile_cache_miss_bytes":29000180,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":182,"lbm_read_time_us":13279,"lbm_reads_lt_1ms":675,"lbm_write_time_us":31844,"lbm_writes_lt_1ms":646,"mutex_wait_us":20,"peak_mem_usage":75665577,"reinsert_count":0,"spinlock_wait_cycles":6016,"update_count":3015}
I20260812 06:20:17.086263  5537 maintenance_manager.cc:419] P 94b914dc65f548d29ab2172d8c20c7f7: Scheduling FlushDeltaMemStoresOp(4d6991878cb445d8a9ed25942a28d84c): perf score=14.095187
I20260812 06:20:17.147081  5422 maintenance_manager.cc:643] P 94b914dc65f548d29ab2172d8c20c7f7: FlushDeltaMemStoresOp(4d6991878cb445d8a9ed25942a28d84c) complete. Timing: real 0.061s	user 0.035s	sys 0.021s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":28694,"lbm_writes_1-10_ms":2,"lbm_writes_lt_1ms":401,"reinsert_count":0,"update_count":2000}
I20260812 06:20:17.147617  5537 maintenance_manager.cc:419] P 94b914dc65f548d29ab2172d8c20c7f7: Scheduling FlushDeltaMemStoresOp(4d6991878cb445d8a9ed25942a28d84c): perf score=3.181125
I20260812 06:20:17.159674  5422 maintenance_manager.cc:643] P 94b914dc65f548d29ab2172d8c20c7f7: FlushDeltaMemStoresOp(4d6991878cb445d8a9ed25942a28d84c) complete. Timing: real 0.012s	user 0.000s	sys 0.010s Metrics: {"bytes_written":4512900,"delete_count":0,"lbm_write_time_us":4575,"lbm_writes_lt_1ms":113,"reinsert_count":0,"update_count":550}
I20260812 06:20:17.160123  5537 maintenance_manager.cc:419] P 94b914dc65f548d29ab2172d8c20c7f7: Scheduling FlushDeltaMemStoresOp(4d6991878cb445d8a9ed25942a28d84c): perf score=2.188937
I20260812 06:20:17.172951  5422 maintenance_manager.cc:643] P 94b914dc65f548d29ab2172d8c20c7f7: FlushDeltaMemStoresOp(4d6991878cb445d8a9ed25942a28d84c) complete. Timing: real 0.013s	user 0.008s	sys 0.004s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":4945,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:20:17.173501  5537 maintenance_manager.cc:419] P 94b914dc65f548d29ab2172d8c20c7f7: Scheduling MajorDeltaCompactionOp(4d6991878cb445d8a9ed25942a28d84c): perf score=1.000000
I20260812 06:20:17.365597  5422 maintenance_manager.cc:643] P 94b914dc65f548d29ab2172d8c20c7f7: MajorDeltaCompactionOp(4d6991878cb445d8a9ed25942a28d84c) complete. Timing: real 0.192s	user 0.124s	sys 0.067s Metrics: {"cfile_cache_miss":633,"cfile_cache_miss_bytes":28877206,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":1018,"lbm_read_time_us":13760,"lbm_reads_lt_1ms":673,"lbm_write_time_us":33905,"lbm_writes_lt_1ms":643,"mutex_wait_us":264,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":6528,"update_count":3000}
I20260812 06:20:17.366204  5537 maintenance_manager.cc:419] P 94b914dc65f548d29ab2172d8c20c7f7: Scheduling FlushDeltaMemStoresOp(4d6991878cb445d8a9ed25942a28d84c): perf score=14.095187
I20260812 06:20:17.429104  5422 maintenance_manager.cc:643] P 94b914dc65f548d29ab2172d8c20c7f7: FlushDeltaMemStoresOp(4d6991878cb445d8a9ed25942a28d84c) complete. Timing: real 0.063s	user 0.034s	sys 0.028s Metrics: {"bytes_written":16409907,"delete_count":0,"lbm_write_time_us":25767,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":402,"reinsert_count":0,"update_count":2000}
I20260812 06:20:17.429719  5537 maintenance_manager.cc:419] P 94b914dc65f548d29ab2172d8c20c7f7: Scheduling FlushDeltaMemStoresOp(4d6991878cb445d8a9ed25942a28d84c): perf score=2.188937
I20260812 06:20:17.442421  5422 maintenance_manager.cc:643] P 94b914dc65f548d29ab2172d8c20c7f7: FlushDeltaMemStoresOp(4d6991878cb445d8a9ed25942a28d84c) complete. Timing: real 0.012s	user 0.002s	sys 0.009s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4816,"lbm_writes_lt_1ms":103,"reinsert_count":0,"spinlock_wait_cycles":768,"update_count":500}
I20260812 06:20:17.442993  5537 maintenance_manager.cc:419] P 94b914dc65f548d29ab2172d8c20c7f7: Scheduling MajorDeltaCompactionOp(4d6991878cb445d8a9ed25942a28d84c): perf score=1.000000
I20260812 06:20:17.609215  5422 maintenance_manager.cc:643] P 94b914dc65f548d29ab2172d8c20c7f7: MajorDeltaCompactionOp(4d6991878cb445d8a9ed25942a28d84c) complete. Timing: real 0.166s	user 0.119s	sys 0.047s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774694,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":1067,"lbm_read_time_us":12894,"lbm_reads_lt_1ms":572,"lbm_write_time_us":26244,"lbm_writes_lt_1ms":543,"mutex_wait_us":34,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":12032,"update_count":2500}
I20260812 06:20:17.609848  5537 maintenance_manager.cc:419] P 94b914dc65f548d29ab2172d8c20c7f7: Scheduling FlushDeltaMemStoresOp(4d6991878cb445d8a9ed25942a28d84c): perf score=14.095187
I20260812 06:20:17.661032  5422 maintenance_manager.cc:643] P 94b914dc65f548d29ab2172d8c20c7f7: FlushDeltaMemStoresOp(4d6991878cb445d8a9ed25942a28d84c) complete. Timing: real 0.051s	user 0.034s	sys 0.016s Metrics: {"bytes_written":16409900,"delete_count":0,"lbm_write_time_us":25102,"lbm_writes_1-10_ms":2,"lbm_writes_lt_1ms":401,"reinsert_count":0,"update_count":2000}
I20260812 06:20:17.661640  5537 maintenance_manager.cc:419] P 94b914dc65f548d29ab2172d8c20c7f7: Scheduling FlushDeltaMemStoresOp(4d6991878cb445d8a9ed25942a28d84c): perf score=2.188937
I20260812 06:20:17.674901  5422 maintenance_manager.cc:643] P 94b914dc65f548d29ab2172d8c20c7f7: FlushDeltaMemStoresOp(4d6991878cb445d8a9ed25942a28d84c) complete. Timing: real 0.013s	user 0.003s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5170,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:17.675365  5537 maintenance_manager.cc:419] P 94b914dc65f548d29ab2172d8c20c7f7: Scheduling MajorDeltaCompactionOp(4d6991878cb445d8a9ed25942a28d84c): perf score=1.000000
I20260812 06:20:17.846596  5422 maintenance_manager.cc:643] P 94b914dc65f548d29ab2172d8c20c7f7: MajorDeltaCompactionOp(4d6991878cb445d8a9ed25942a28d84c) complete. Timing: real 0.171s	user 0.131s	sys 0.040s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774687,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":227,"lbm_read_time_us":12530,"lbm_reads_lt_1ms":568,"lbm_write_time_us":28687,"lbm_writes_lt_1ms":543,"mutex_wait_us":22,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":14464,"update_count":2500}
I20260812 06:20:17.847332  5537 maintenance_manager.cc:419] P 94b914dc65f548d29ab2172d8c20c7f7: Scheduling FlushDeltaMemStoresOp(4d6991878cb445d8a9ed25942a28d84c): perf score=14.095187
I20260812 06:20:17.903716  5422 maintenance_manager.cc:643] P 94b914dc65f548d29ab2172d8c20c7f7: FlushDeltaMemStoresOp(4d6991878cb445d8a9ed25942a28d84c) complete. Timing: real 0.056s	user 0.034s	sys 0.019s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":20031,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:20:17.904258  5537 maintenance_manager.cc:419] P 94b914dc65f548d29ab2172d8c20c7f7: Scheduling FlushDeltaMemStoresOp(4d6991878cb445d8a9ed25942a28d84c): perf score=2.188937
I20260812 06:20:17.914503  5422 maintenance_manager.cc:643] P 94b914dc65f548d29ab2172d8c20c7f7: FlushDeltaMemStoresOp(4d6991878cb445d8a9ed25942a28d84c) complete. Timing: real 0.010s	user 0.009s	sys 0.000s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4111,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:17.914907  5537 maintenance_manager.cc:419] P 94b914dc65f548d29ab2172d8c20c7f7: Scheduling FlushMRSOp(4d6991878cb445d8a9ed25942a28d84c): perf score=1.000000
I20260812 06:20:17.954198  5422 maintenance_manager.cc:643] P 94b914dc65f548d29ab2172d8c20c7f7: FlushMRSOp(4d6991878cb445d8a9ed25942a28d84c) complete. Timing: real 0.039s	user 0.029s	sys 0.004s Metrics: {"bytes_written":1193507,"cfile_init":1,"dirs.queue_time_us":61,"dirs.run_cpu_time_us":255,"dirs.run_wall_time_us":1254,"drs_written":1,"lbm_read_time_us":43,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1448,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":29,"spinlock_wait_cycles":1792}
I20260812 06:20:17.954963  5537 maintenance_manager.cc:419] P 94b914dc65f548d29ab2172d8c20c7f7: Scheduling LogGCOp(4d6991878cb445d8a9ed25942a28d84c): free 120553644 bytes of WAL
I20260812 06:20:17.955238  5422 log_reader.cc:385] T 4d6991878cb445d8a9ed25942a28d84c: removed 12 log segments from log reader
I20260812 06:20:17.955312  5422 log.cc:1079] T 4d6991878cb445d8a9ed25942a28d84c P 94b914dc65f548d29ab2172d8c20c7f7: Deleting log segment in path: /tmp/dist-test-task_bOXbU/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515613161794-5236-0/minicluster-data/ts-0-root/wals/4d6991878cb445d8a9ed25942a28d84c/wal-000000027 (ops 129-133)
I20260812 06:20:17.955351  5422 log.cc:1079] T 4d6991878cb445d8a9ed25942a28d84c P 94b914dc65f548d29ab2172d8c20c7f7: Deleting log segment in path: /tmp/dist-test-task_bOXbU/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515613161794-5236-0/minicluster-data/ts-0-root/wals/4d6991878cb445d8a9ed25942a28d84c/wal-000000028 (ops 134-138)
I20260812 06:20:17.955381  5422 log.cc:1079] T 4d6991878cb445d8a9ed25942a28d84c P 94b914dc65f548d29ab2172d8c20c7f7: Deleting log segment in path: /tmp/dist-test-task_bOXbU/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515613161794-5236-0/minicluster-data/ts-0-root/wals/4d6991878cb445d8a9ed25942a28d84c/wal-000000029 (ops 139-143)
I20260812 06:20:17.955405  5422 log.cc:1079] T 4d6991878cb445d8a9ed25942a28d84c P 94b914dc65f548d29ab2172d8c20c7f7: Deleting log segment in path: /tmp/dist-test-task_bOXbU/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515613161794-5236-0/minicluster-data/ts-0-root/wals/4d6991878cb445d8a9ed25942a28d84c/wal-000000030 (ops 144-148)
I20260812 06:20:17.955433  5422 log.cc:1079] T 4d6991878cb445d8a9ed25942a28d84c P 94b914dc65f548d29ab2172d8c20c7f7: Deleting log segment in path: /tmp/dist-test-task_bOXbU/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515613161794-5236-0/minicluster-data/ts-0-root/wals/4d6991878cb445d8a9ed25942a28d84c/wal-000000031 (ops 149-152)
I20260812 06:20:17.955467  5422 log.cc:1079] T 4d6991878cb445d8a9ed25942a28d84c P 94b914dc65f548d29ab2172d8c20c7f7: Deleting log segment in path: /tmp/dist-test-task_bOXbU/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515613161794-5236-0/minicluster-data/ts-0-root/wals/4d6991878cb445d8a9ed25942a28d84c/wal-000000032 (ops 153-157)
I20260812 06:20:17.955502  5422 log.cc:1079] T 4d6991878cb445d8a9ed25942a28d84c P 94b914dc65f548d29ab2172d8c20c7f7: Deleting log segment in path: /tmp/dist-test-task_bOXbU/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515613161794-5236-0/minicluster-data/ts-0-root/wals/4d6991878cb445d8a9ed25942a28d84c/wal-000000033 (ops 158-162)
I20260812 06:20:17.955524  5422 log.cc:1079] T 4d6991878cb445d8a9ed25942a28d84c P 94b914dc65f548d29ab2172d8c20c7f7: Deleting log segment in path: /tmp/dist-test-task_bOXbU/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515613161794-5236-0/minicluster-data/ts-0-root/wals/4d6991878cb445d8a9ed25942a28d84c/wal-000000034 (ops 163-166)
I20260812 06:20:17.955552  5422 log.cc:1079] T 4d6991878cb445d8a9ed25942a28d84c P 94b914dc65f548d29ab2172d8c20c7f7: Deleting log segment in path: /tmp/dist-test-task_bOXbU/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515613161794-5236-0/minicluster-data/ts-0-root/wals/4d6991878cb445d8a9ed25942a28d84c/wal-000000035 (ops 167-171)
I20260812 06:20:17.955582  5422 log.cc:1079] T 4d6991878cb445d8a9ed25942a28d84c P 94b914dc65f548d29ab2172d8c20c7f7: Deleting log segment in path: /tmp/dist-test-task_bOXbU/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515613161794-5236-0/minicluster-data/ts-0-root/wals/4d6991878cb445d8a9ed25942a28d84c/wal-000000036 (ops 172-176)
I20260812 06:20:17.955612  5422 log.cc:1079] T 4d6991878cb445d8a9ed25942a28d84c P 94b914dc65f548d29ab2172d8c20c7f7: Deleting log segment in path: /tmp/dist-test-task_bOXbU/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515613161794-5236-0/minicluster-data/ts-0-root/wals/4d6991878cb445d8a9ed25942a28d84c/wal-000000037 (ops 177-181)
I20260812 06:20:17.955657  5422 log.cc:1079] T 4d6991878cb445d8a9ed25942a28d84c P 94b914dc65f548d29ab2172d8c20c7f7: Deleting log segment in path: /tmp/dist-test-task_bOXbU/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515613161794-5236-0/minicluster-data/ts-0-root/wals/4d6991878cb445d8a9ed25942a28d84c/wal-000000038 (ops 182-186)
I20260812 06:20:17.986024  5422 maintenance_manager.cc:643] P 94b914dc65f548d29ab2172d8c20c7f7: LogGCOp(4d6991878cb445d8a9ed25942a28d84c) complete. Timing: real 0.031s	user 0.000s	sys 0.029s Metrics: {}
I20260812 06:20:17.986419  5537 maintenance_manager.cc:419] P 94b914dc65f548d29ab2172d8c20c7f7: Scheduling UndoDeltaBlockGCOp(4d6991878cb445d8a9ed25942a28d84c): 462 bytes on disk
I20260812 06:20:17.986865  5422 maintenance_manager.cc:643] P 94b914dc65f548d29ab2172d8c20c7f7: UndoDeltaBlockGCOp(4d6991878cb445d8a9ed25942a28d84c) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":58,"lbm_reads_lt_1ms":4}
I20260812 06:20:17.987401  5537 maintenance_manager.cc:419] P 94b914dc65f548d29ab2172d8c20c7f7: Scheduling FlushDeltaMemStoresOp(4d6991878cb445d8a9ed25942a28d84c): perf score=2.188937
I20260812 06:20:18.009292  5422 maintenance_manager.cc:643] P 94b914dc65f548d29ab2172d8c20c7f7: FlushDeltaMemStoresOp(4d6991878cb445d8a9ed25942a28d84c) complete. Timing: real 0.022s	user 0.006s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4289,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:18.009804  5537 maintenance_manager.cc:419] P 94b914dc65f548d29ab2172d8c20c7f7: Scheduling FlushDeltaMemStoresOp(4d6991878cb445d8a9ed25942a28d84c): perf score=2.188937
I20260812 06:20:18.020088  5422 maintenance_manager.cc:643] P 94b914dc65f548d29ab2172d8c20c7f7: FlushDeltaMemStoresOp(4d6991878cb445d8a9ed25942a28d84c) complete. Timing: real 0.010s	user 0.003s	sys 0.005s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3992,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:18.020563  5537 maintenance_manager.cc:419] P 94b914dc65f548d29ab2172d8c20c7f7: Scheduling MajorDeltaCompactionOp(4d6991878cb445d8a9ed25942a28d84c): perf score=1.000000
I20260812 06:20:18.246536  5422 maintenance_manager.cc:643] P 94b914dc65f548d29ab2172d8c20c7f7: MajorDeltaCompactionOp(4d6991878cb445d8a9ed25942a28d84c) complete. Timing: real 0.226s	user 0.136s	sys 0.080s Metrics: {"cfile_cache_miss":734,"cfile_cache_miss_bytes":32979750,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":494,"lbm_read_time_us":14824,"lbm_reads_lt_1ms":774,"lbm_write_time_us":38985,"lbm_writes_lt_1ms":743,"mutex_wait_us":59,"peak_mem_usage":87969044,"reinsert_count":0,"thread_start_us":79,"threads_started":1,"update_count":3500}
I20260812 06:20:18.247288  5537 maintenance_manager.cc:419] P 94b914dc65f548d29ab2172d8c20c7f7: Scheduling FlushDeltaMemStoresOp(4d6991878cb445d8a9ed25942a28d84c): perf score=15.087375
I20260812 06:20:18.262735  5236 heavy-update-compaction-itest.cc:229] Time spent updating: real 4.811s	user 1.781s	sys 0.167s
I20260812 06:20:18.284837  5422 maintenance_manager.cc:643] P 94b914dc65f548d29ab2172d8c20c7f7: FlushDeltaMemStoresOp(4d6991878cb445d8a9ed25942a28d84c) complete. Timing: real 0.037s	user 0.020s	sys 0.016s Metrics: {"bytes_written":16820142,"delete_count":0,"lbm_write_time_us":18352,"lbm_writes_lt_1ms":413,"reinsert_count":0,"update_count":2050}
I20260812 06:20:18.285411  5537 maintenance_manager.cc:419] P 94b914dc65f548d29ab2172d8c20c7f7: Scheduling FlushDeltaMemStoresOp(4d6991878cb445d8a9ed25942a28d84c): perf score=2.188937
I20260812 06:20:18.299798  5422 maintenance_manager.cc:643] P 94b914dc65f548d29ab2172d8c20c7f7: FlushDeltaMemStoresOp(4d6991878cb445d8a9ed25942a28d84c) complete. Timing: real 0.014s	user 0.003s	sys 0.006s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3555,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:20:18.300405  5537 maintenance_manager.cc:419] P 94b914dc65f548d29ab2172d8c20c7f7: Scheduling MajorDeltaCompactionOp(4d6991878cb445d8a9ed25942a28d84c): perf score=1.000000
I20260812 06:20:18.307092  5236 heavy-update-compaction-itest.cc:265] Time spent scanning: real 0.044s	user 0.003s	sys 0.000s
I20260812 06:20:18.307669  5236 tablet_server.cc:179] TabletServer@127.5.29.1:0 shutting down...
I20260812 06:20:18.432358  5422 maintenance_manager.cc:643] P 94b914dc65f548d29ab2172d8c20c7f7: MajorDeltaCompactionOp(4d6991878cb445d8a9ed25942a28d84c) complete. Timing: real 0.132s	user 0.099s	sys 0.033s Metrics: {"cfile_cache_hit":30,"cfile_cache_hit_bytes":4262390,"cfile_cache_miss":502,"cfile_cache_miss_bytes":20512285,"cfile_init":4,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":512,"lbm_read_time_us":7871,"lbm_reads_lt_1ms":518,"lbm_write_time_us":24079,"lbm_writes_lt_1ms":543,"mutex_wait_us":61,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":14848,"update_count":2500}
I20260812 06:20:18.433218  5236 ts_tablet_manager.cc:1507] Shutting down tablet manager...
I20260812 06:20:18.433668  5236 tablet_replica.cc:333] T 4d6991878cb445d8a9ed25942a28d84c P 94b914dc65f548d29ab2172d8c20c7f7: stopping tablet replica
I20260812 06:20:18.433943  5236 raft_consensus.cc:2243] T 4d6991878cb445d8a9ed25942a28d84c P 94b914dc65f548d29ab2172d8c20c7f7 [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:20:18.434182  5236 raft_consensus.cc:2272] T 4d6991878cb445d8a9ed25942a28d84c P 94b914dc65f548d29ab2172d8c20c7f7 [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:20:18.450323  5236 tablet_server.cc:196] TabletServer@127.5.29.1:0 shutdown complete.
I20260812 06:20:18.479337  5236 master.cc:562] Master@127.5.29.62:35407 shutting down...
I20260812 06:20:18.483001  5236 raft_consensus.cc:2243] T 00000000000000000000000000000000 P 2fdd4ba5685d492c83d0d06a05a3081e [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:20:18.483191  5236 raft_consensus.cc:2272] T 00000000000000000000000000000000 P 2fdd4ba5685d492c83d0d06a05a3081e [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:20:18.483289  5236 tablet_replica.cc:333] T 00000000000000000000000000000000 P 2fdd4ba5685d492c83d0d06a05a3081e: stopping tablet replica
I20260812 06:20:18.495728  5236 master.cc:584] Master@127.5.29.62:35407 shutdown complete.
[       OK ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/0 (5412 ms)
[ RUN      ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/1
I20260812 06:20:18.596928  5236 internal_mini_cluster.cc:156] Creating distributed mini masters. Addrs: 127.5.29.62:41865
I20260812 06:20:18.597355  5236 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:20:18.599491  5596 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:20:18.599571  5236 server_base.cc:1061] running on GCE node
W20260812 06:20:18.599704  5601 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:20:18.600630  5595 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:20:18.600845  5236 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:20:18.600912  5236 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:20:18.600939  5236 hybrid_clock.cc:648] HybridClock initialized: now 1786515618600937 us; error 0 us; skew 500 ppm
I20260812 06:20:18.601727  5236 webserver.cc:533] Webserver started at http://127.5.29.62:41667/ using document root <none> and password file <none>
I20260812 06:20:18.601902  5236 fs_manager.cc:362] Metadata directory not provided
I20260812 06:20:18.601969  5236 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:20:18.602056  5236 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:20:18.602479  5236 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-task_bOXbU/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515613161794-5236-0/minicluster-data/master-0-root/instance:
uuid: "546fe77726b54eaea9ac58cf30fa34b8"
format_stamp: "Formatted at 2026-08-12 06:20:18 on dist-test-slave-zpvx"
I20260812 06:20:18.603992  5236 fs_manager.cc:696] Time spent creating directory manager: real 0.001s	user 0.002s	sys 0.000s
I20260812 06:20:18.604974  5609 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:20:18.605245  5236 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.000s	sys 0.000s
I20260812 06:20:18.605337  5236 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-task_bOXbU/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515613161794-5236-0/minicluster-data/master-0-root
uuid: "546fe77726b54eaea9ac58cf30fa34b8"
format_stamp: "Formatted at 2026-08-12 06:20:18 on dist-test-slave-zpvx"
I20260812 06:20:18.605428  5236 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-task_bOXbU/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515613161794-5236-0/minicluster-data/master-0-root
metadata directory: /tmp/dist-test-task_bOXbU/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515613161794-5236-0/minicluster-data/master-0-root
1 data directories: /tmp/dist-test-task_bOXbU/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515613161794-5236-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:20:18.622838  5236 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:20:18.623184  5236 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:20:18.628305  5236 rpc_server.cc:307] RPC server started. Bound to: 127.5.29.62:41865
I20260812 06:20:18.630721  5719 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.5.29.62:41865 every 8 connection(s)
I20260812 06:20:18.631225  5720 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:20:18.632911  5720 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P 546fe77726b54eaea9ac58cf30fa34b8: Bootstrap starting.
I20260812 06:20:18.633613  5720 tablet_bootstrap.cc:654] T 00000000000000000000000000000000 P 546fe77726b54eaea9ac58cf30fa34b8: Neither blocks nor log segments found. Creating new log.
I20260812 06:20:18.634577  5720 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P 546fe77726b54eaea9ac58cf30fa34b8: No bootstrap required, opened a new log
I20260812 06:20:18.634912  5720 raft_consensus.cc:359] T 00000000000000000000000000000000 P 546fe77726b54eaea9ac58cf30fa34b8 [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "546fe77726b54eaea9ac58cf30fa34b8" member_type: VOTER }
I20260812 06:20:18.634994  5720 raft_consensus.cc:385] T 00000000000000000000000000000000 P 546fe77726b54eaea9ac58cf30fa34b8 [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:20:18.635015  5720 raft_consensus.cc:740] T 00000000000000000000000000000000 P 546fe77726b54eaea9ac58cf30fa34b8 [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: 546fe77726b54eaea9ac58cf30fa34b8, State: Initialized, Role: FOLLOWER
I20260812 06:20:18.635154  5720 consensus_queue.cc:260] T 00000000000000000000000000000000 P 546fe77726b54eaea9ac58cf30fa34b8 [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: "546fe77726b54eaea9ac58cf30fa34b8" member_type: VOTER }
I20260812 06:20:18.635272  5720 raft_consensus.cc:399] T 00000000000000000000000000000000 P 546fe77726b54eaea9ac58cf30fa34b8 [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:20:18.635299  5720 raft_consensus.cc:493] T 00000000000000000000000000000000 P 546fe77726b54eaea9ac58cf30fa34b8 [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:20:18.635334  5720 raft_consensus.cc:3060] T 00000000000000000000000000000000 P 546fe77726b54eaea9ac58cf30fa34b8 [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:20:18.635950  5720 raft_consensus.cc:515] T 00000000000000000000000000000000 P 546fe77726b54eaea9ac58cf30fa34b8 [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "546fe77726b54eaea9ac58cf30fa34b8" member_type: VOTER }
I20260812 06:20:18.636061  5720 leader_election.cc:304] T 00000000000000000000000000000000 P 546fe77726b54eaea9ac58cf30fa34b8 [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: 546fe77726b54eaea9ac58cf30fa34b8; no voters: 
I20260812 06:20:18.636204  5720 leader_election.cc:290] T 00000000000000000000000000000000 P 546fe77726b54eaea9ac58cf30fa34b8 [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:20:18.636358  5724 raft_consensus.cc:2804] T 00000000000000000000000000000000 P 546fe77726b54eaea9ac58cf30fa34b8 [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:20:18.636610  5724 raft_consensus.cc:697] T 00000000000000000000000000000000 P 546fe77726b54eaea9ac58cf30fa34b8 [term 1 LEADER]: Becoming Leader. State: Replica: 546fe77726b54eaea9ac58cf30fa34b8, State: Running, Role: LEADER
I20260812 06:20:18.636644  5720 sys_catalog.cc:565] T 00000000000000000000000000000000 P 546fe77726b54eaea9ac58cf30fa34b8 [sys.catalog]: configured and running, proceeding with master startup.
I20260812 06:20:18.636741  5724 consensus_queue.cc:237] T 00000000000000000000000000000000 P 546fe77726b54eaea9ac58cf30fa34b8 [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: "546fe77726b54eaea9ac58cf30fa34b8" member_type: VOTER }
I20260812 06:20:18.637274  5727 sys_catalog.cc:455] T 00000000000000000000000000000000 P 546fe77726b54eaea9ac58cf30fa34b8 [sys.catalog]: SysCatalogTable state changed. Reason: RaftConsensus started. Latest consensus state: current_term: 1 leader_uuid: "546fe77726b54eaea9ac58cf30fa34b8" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "546fe77726b54eaea9ac58cf30fa34b8" member_type: VOTER } }
I20260812 06:20:18.637326  5728 sys_catalog.cc:455] T 00000000000000000000000000000000 P 546fe77726b54eaea9ac58cf30fa34b8 [sys.catalog]: SysCatalogTable state changed. Reason: New leader 546fe77726b54eaea9ac58cf30fa34b8. Latest consensus state: current_term: 1 leader_uuid: "546fe77726b54eaea9ac58cf30fa34b8" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "546fe77726b54eaea9ac58cf30fa34b8" member_type: VOTER } }
I20260812 06:20:18.637377  5727 sys_catalog.cc:458] T 00000000000000000000000000000000 P 546fe77726b54eaea9ac58cf30fa34b8 [sys.catalog]: This master's current role is: LEADER
I20260812 06:20:18.637414  5728 sys_catalog.cc:458] T 00000000000000000000000000000000 P 546fe77726b54eaea9ac58cf30fa34b8 [sys.catalog]: This master's current role is: LEADER
I20260812 06:20:18.638538  5236 internal_mini_cluster.cc:184] Waiting to initialize catalog manager on master 0
W20260812 06:20:18.638973  5750 catalog_manager.cc:1594] T 00000000000000000000000000000000 P 546fe77726b54eaea9ac58cf30fa34b8: loading cluster ID for follower catalog manager: Not found: cluster ID entry not found
W20260812 06:20:18.639065  5750 catalog_manager.cc:883] Not found: cluster ID entry not found: failed to prepare follower catalog manager, will retry
I20260812 06:20:18.639144  5738 catalog_manager.cc:1511] Loading table and tablet metadata into memory...
I20260812 06:20:18.639755  5738 catalog_manager.cc:1520] Initializing Kudu cluster ID...
I20260812 06:20:18.641417  5738 catalog_manager.cc:1383] Generated new cluster ID: 14f304eb5e3749888c7cd7af6d24136b
I20260812 06:20:18.641466  5738 catalog_manager.cc:1531] Initializing Kudu internal certificate authority...
I20260812 06:20:18.659962  5738 catalog_manager.cc:1406] Generated new certificate authority record
I20260812 06:20:18.660527  5738 catalog_manager.cc:1540] Loading token signing keys...
I20260812 06:20:18.672313  5738 catalog_manager.cc:6092] T 00000000000000000000000000000000 P 546fe77726b54eaea9ac58cf30fa34b8: Generated new TSK 0
I20260812 06:20:18.672509  5738 catalog_manager.cc:1550] Initializing in-progress tserver states...
I20260812 06:20:18.702980  5236 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:20:18.704901  5752 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:20:18.704942  5753 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:20:18.704942  5755 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:20:18.705260  5236 server_base.cc:1061] running on GCE node
I20260812 06:20:18.705397  5236 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:20:18.705432  5236 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:20:18.705448  5236 hybrid_clock.cc:648] HybridClock initialized: now 1786515618705448 us; error 0 us; skew 500 ppm
I20260812 06:20:18.706378  5236 webserver.cc:533] Webserver started at http://127.5.29.1:42105/ using document root <none> and password file <none>
I20260812 06:20:18.706602  5236 fs_manager.cc:362] Metadata directory not provided
I20260812 06:20:18.706664  5236 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:20:18.706734  5236 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:20:18.707095  5236 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-task_bOXbU/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515613161794-5236-0/minicluster-data/ts-0-root/instance:
uuid: "d7ed4198a4d24c99a1423ad12aa55761"
format_stamp: "Formatted at 2026-08-12 06:20:18 on dist-test-slave-zpvx"
I20260812 06:20:18.708626  5236 fs_manager.cc:696] Time spent creating directory manager: real 0.001s	user 0.002s	sys 0.000s
I20260812 06:20:18.709529  5765 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:20:18.709782  5236 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.001s	sys 0.000s
I20260812 06:20:18.709848  5236 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-task_bOXbU/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515613161794-5236-0/minicluster-data/ts-0-root
uuid: "d7ed4198a4d24c99a1423ad12aa55761"
format_stamp: "Formatted at 2026-08-12 06:20:18 on dist-test-slave-zpvx"
I20260812 06:20:18.709903  5236 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-task_bOXbU/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515613161794-5236-0/minicluster-data/ts-0-root
metadata directory: /tmp/dist-test-task_bOXbU/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515613161794-5236-0/minicluster-data/ts-0-root
1 data directories: /tmp/dist-test-task_bOXbU/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515613161794-5236-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:20:18.728894  5236 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:20:18.729271  5236 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:20:18.729544  5236 txn_system_client.cc:432] TxnSystemClient initialization is disabled...
I20260812 06:20:18.730038  5236 ts_tablet_manager.cc:585] Loaded tablet metadata (0 total tablets, 0 live tablets)
I20260812 06:20:18.730077  5236 ts_tablet_manager.cc:531] Time spent load tablet metadata: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:20:18.730137  5236 ts_tablet_manager.cc:616] Registered 0 tablets
I20260812 06:20:18.730177  5236 ts_tablet_manager.cc:595] Time spent register tablets: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:20:18.734651  5236 rpc_server.cc:307] RPC server started. Bound to: 127.5.29.1:37595
I20260812 06:20:18.735296  5883 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.5.29.1:37595 every 8 connection(s)
I20260812 06:20:18.744485  5885 heartbeater.cc:344] Connected to a master server at 127.5.29.62:41865
I20260812 06:20:18.744582  5885 heartbeater.cc:461] Registering TS with master...
I20260812 06:20:18.744772  5885 heartbeater.cc:507] Master 127.5.29.62:41865 requested a full tablet report, sending...
I20260812 06:20:18.745443  5644 ts_manager.cc:194] Registered new tserver with Master: d7ed4198a4d24c99a1423ad12aa55761 (127.5.29.1:37595)
I20260812 06:20:18.746106  5644 master_service.cc:502] Signed X509 certificate for tserver {username='slave'} at 127.0.0.1:60840
I20260812 06:20:18.746505  5236 internal_mini_cluster.cc:371] 1 TS(s) registered with all masters after 0.011135944s
I20260812 06:20:18.753602  5644 catalog_manager.cc:2283] Servicing CreateTable request from {username='slave'} at 127.0.0.1:60842:
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:20:18.762239  5818 tablet_service.cc:1511] Processing CreateTablet for tablet 0c01586a085546c6b85f6a2fd61f67da (DEFAULT_TABLE table=heavy-update-compaction-test [id=93259755023a489cbb3dc9099323943b]), partition=
I20260812 06:20:18.762516  5818 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet 0c01586a085546c6b85f6a2fd61f67da. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:20:18.764508  5905 tablet_bootstrap.cc:492] T 0c01586a085546c6b85f6a2fd61f67da P d7ed4198a4d24c99a1423ad12aa55761: Bootstrap starting.
I20260812 06:20:18.765312  5905 tablet_bootstrap.cc:654] T 0c01586a085546c6b85f6a2fd61f67da P d7ed4198a4d24c99a1423ad12aa55761: Neither blocks nor log segments found. Creating new log.
I20260812 06:20:18.766271  5905 tablet_bootstrap.cc:492] T 0c01586a085546c6b85f6a2fd61f67da P d7ed4198a4d24c99a1423ad12aa55761: No bootstrap required, opened a new log
I20260812 06:20:18.766342  5905 ts_tablet_manager.cc:1403] T 0c01586a085546c6b85f6a2fd61f67da P d7ed4198a4d24c99a1423ad12aa55761: Time spent bootstrapping tablet: real 0.002s	user 0.001s	sys 0.000s
I20260812 06:20:18.766695  5905 raft_consensus.cc:359] T 0c01586a085546c6b85f6a2fd61f67da P d7ed4198a4d24c99a1423ad12aa55761 [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "d7ed4198a4d24c99a1423ad12aa55761" member_type: VOTER last_known_addr { host: "127.5.29.1" port: 37595 } }
I20260812 06:20:18.766781  5905 raft_consensus.cc:385] T 0c01586a085546c6b85f6a2fd61f67da P d7ed4198a4d24c99a1423ad12aa55761 [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:20:18.766803  5905 raft_consensus.cc:740] T 0c01586a085546c6b85f6a2fd61f67da P d7ed4198a4d24c99a1423ad12aa55761 [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: d7ed4198a4d24c99a1423ad12aa55761, State: Initialized, Role: FOLLOWER
I20260812 06:20:18.766896  5905 consensus_queue.cc:260] T 0c01586a085546c6b85f6a2fd61f67da P d7ed4198a4d24c99a1423ad12aa55761 [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: "d7ed4198a4d24c99a1423ad12aa55761" member_type: VOTER last_known_addr { host: "127.5.29.1" port: 37595 } }
I20260812 06:20:18.766953  5905 raft_consensus.cc:399] T 0c01586a085546c6b85f6a2fd61f67da P d7ed4198a4d24c99a1423ad12aa55761 [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:20:18.766975  5905 raft_consensus.cc:493] T 0c01586a085546c6b85f6a2fd61f67da P d7ed4198a4d24c99a1423ad12aa55761 [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:20:18.767004  5905 raft_consensus.cc:3060] T 0c01586a085546c6b85f6a2fd61f67da P d7ed4198a4d24c99a1423ad12aa55761 [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:20:18.767884  5905 raft_consensus.cc:515] T 0c01586a085546c6b85f6a2fd61f67da P d7ed4198a4d24c99a1423ad12aa55761 [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "d7ed4198a4d24c99a1423ad12aa55761" member_type: VOTER last_known_addr { host: "127.5.29.1" port: 37595 } }
I20260812 06:20:18.768033  5905 leader_election.cc:304] T 0c01586a085546c6b85f6a2fd61f67da P d7ed4198a4d24c99a1423ad12aa55761 [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: d7ed4198a4d24c99a1423ad12aa55761; no voters: 
I20260812 06:20:18.768236  5905 leader_election.cc:290] T 0c01586a085546c6b85f6a2fd61f67da P d7ed4198a4d24c99a1423ad12aa55761 [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:20:18.768350  5908 raft_consensus.cc:2804] T 0c01586a085546c6b85f6a2fd61f67da P d7ed4198a4d24c99a1423ad12aa55761 [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:20:18.768582  5885 heartbeater.cc:499] Master 127.5.29.62:41865 was elected leader, sending a full tablet report...
I20260812 06:20:18.768579  5905 ts_tablet_manager.cc:1434] T 0c01586a085546c6b85f6a2fd61f67da P d7ed4198a4d24c99a1423ad12aa55761: Time spent starting tablet: real 0.002s	user 0.002s	sys 0.000s
I20260812 06:20:18.768648  5908 raft_consensus.cc:697] T 0c01586a085546c6b85f6a2fd61f67da P d7ed4198a4d24c99a1423ad12aa55761 [term 1 LEADER]: Becoming Leader. State: Replica: d7ed4198a4d24c99a1423ad12aa55761, State: Running, Role: LEADER
I20260812 06:20:18.768796  5908 consensus_queue.cc:237] T 0c01586a085546c6b85f6a2fd61f67da P d7ed4198a4d24c99a1423ad12aa55761 [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: "d7ed4198a4d24c99a1423ad12aa55761" member_type: VOTER last_known_addr { host: "127.5.29.1" port: 37595 } }
I20260812 06:20:18.770121  5644 catalog_manager.cc:5719] T 0c01586a085546c6b85f6a2fd61f67da P d7ed4198a4d24c99a1423ad12aa55761 reported cstate change: term changed from 0 to 1, leader changed from <none> to d7ed4198a4d24c99a1423ad12aa55761 (127.5.29.1). New cstate: current_term: 1 leader_uuid: "d7ed4198a4d24c99a1423ad12aa55761" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "d7ed4198a4d24c99a1423ad12aa55761" member_type: VOTER last_known_addr { host: "127.5.29.1" port: 37595 } health_report { overall_health: HEALTHY } } }
I20260812 06:20:18.831043  5236 heavy-update-compaction-itest.cc:215] Time spent inserting: real 0.052s	user 0.019s	sys 0.003s
I20260812 06:20:18.986006  5888 maintenance_manager.cc:419] P d7ed4198a4d24c99a1423ad12aa55761: Scheduling FlushMRSOp(0c01586a085546c6b85f6a2fd61f67da): perf score=19.054940
I20260812 06:20:19.152812  5775 maintenance_manager.cc:643] P d7ed4198a4d24c99a1423ad12aa55761: FlushMRSOp(0c01586a085546c6b85f6a2fd61f67da) complete. Timing: real 0.167s	user 0.122s	sys 0.043s Metrics: {"bytes_written":12840810,"cfile_init":1,"delete_count":0,"dirs.queue_time_us":33,"dirs.run_cpu_time_us":178,"dirs.run_wall_time_us":739,"drs_written":1,"lbm_read_time_us":40,"lbm_reads_lt_1ms":4,"lbm_write_time_us":40463,"lbm_writes_lt_1ms":780,"peak_mem_usage":0,"reinsert_count":0,"rows_written":105,"update_count":1565}
I20260812 06:20:19.153450  5888 maintenance_manager.cc:419] P d7ed4198a4d24c99a1423ad12aa55761: Scheduling LogGCOp(0c01586a085546c6b85f6a2fd61f67da): free 20743880 bytes of WAL
I20260812 06:20:19.153695  5775 log_reader.cc:385] T 0c01586a085546c6b85f6a2fd61f67da: removed 2 log segments from log reader
I20260812 06:20:19.153761  5775 log.cc:1079] T 0c01586a085546c6b85f6a2fd61f67da P d7ed4198a4d24c99a1423ad12aa55761: Deleting log segment in path: /tmp/dist-test-task_bOXbU/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515613161794-5236-0/minicluster-data/ts-0-root/wals/0c01586a085546c6b85f6a2fd61f67da/wal-000000001 (ops 1-6)
I20260812 06:20:19.153805  5775 log.cc:1079] T 0c01586a085546c6b85f6a2fd61f67da P d7ed4198a4d24c99a1423ad12aa55761: Deleting log segment in path: /tmp/dist-test-task_bOXbU/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515613161794-5236-0/minicluster-data/ts-0-root/wals/0c01586a085546c6b85f6a2fd61f67da/wal-000000002 (ops 7-11)
I20260812 06:20:19.159806  5775 maintenance_manager.cc:643] P d7ed4198a4d24c99a1423ad12aa55761: LogGCOp(0c01586a085546c6b85f6a2fd61f67da) complete. Timing: real 0.006s	user 0.000s	sys 0.003s Metrics: {}
I20260812 06:20:19.160174  5888 maintenance_manager.cc:419] P d7ed4198a4d24c99a1423ad12aa55761: Scheduling UndoDeltaBlockGCOp(0c01586a085546c6b85f6a2fd61f67da): 16821647 bytes on disk
I20260812 06:20:19.160619  5775 maintenance_manager.cc:643] P d7ed4198a4d24c99a1423ad12aa55761: UndoDeltaBlockGCOp(0c01586a085546c6b85f6a2fd61f67da) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":60,"lbm_reads_lt_1ms":4}
I20260812 06:20:19.160995  5888 maintenance_manager.cc:419] P d7ed4198a4d24c99a1423ad12aa55761: Scheduling FlushDeltaMemStoresOp(0c01586a085546c6b85f6a2fd61f67da): perf score=2.188937
I20260812 06:20:19.182771  5775 maintenance_manager.cc:643] P d7ed4198a4d24c99a1423ad12aa55761: FlushDeltaMemStoresOp(0c01586a085546c6b85f6a2fd61f67da) complete. Timing: real 0.022s	user 0.003s	sys 0.008s Metrics: {"bytes_written":3569334,"delete_count":0,"lbm_write_time_us":4870,"lbm_writes_lt_1ms":90,"reinsert_count":0,"update_count":435}
I20260812 06:20:19.183238  5888 maintenance_manager.cc:419] P d7ed4198a4d24c99a1423ad12aa55761: Scheduling FlushDeltaMemStoresOp(0c01586a085546c6b85f6a2fd61f67da): perf score=2.188937
I20260812 06:20:19.192824  5775 maintenance_manager.cc:643] P d7ed4198a4d24c99a1423ad12aa55761: FlushDeltaMemStoresOp(0c01586a085546c6b85f6a2fd61f67da) complete. Timing: real 0.009s	user 0.005s	sys 0.004s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3794,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:20:19.193367  5888 maintenance_manager.cc:419] P d7ed4198a4d24c99a1423ad12aa55761: Scheduling MajorDeltaCompactionOp(0c01586a085546c6b85f6a2fd61f67da): perf score=1.000000
I20260812 06:20:19.369985  5775 maintenance_manager.cc:643] P d7ed4198a4d24c99a1423ad12aa55761: MajorDeltaCompactionOp(0c01586a085546c6b85f6a2fd61f67da) complete. Timing: real 0.176s	user 0.107s	sys 0.067s Metrics: {"cfile_cache_miss":523,"cfile_cache_miss_bytes":24405544,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":62,"lbm_read_time_us":12570,"lbm_reads_lt_1ms":559,"lbm_write_time_us":26932,"lbm_writes_lt_1ms":533,"peak_mem_usage":61665166,"reinsert_count":0,"spinlock_wait_cycles":768,"thread_start_us":235,"threads_started":5,"update_count":2450}
I20260812 06:20:19.370446  5888 maintenance_manager.cc:419] P d7ed4198a4d24c99a1423ad12aa55761: Scheduling FlushDeltaMemStoresOp(0c01586a085546c6b85f6a2fd61f67da): perf score=14.095187
I20260812 06:20:19.429133  5775 maintenance_manager.cc:643] P d7ed4198a4d24c99a1423ad12aa55761: FlushDeltaMemStoresOp(0c01586a085546c6b85f6a2fd61f67da) complete. Timing: real 0.059s	user 0.039s	sys 0.011s Metrics: {"bytes_written":16409904,"delete_count":0,"lbm_write_time_us":17824,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:20:19.429626  5888 maintenance_manager.cc:419] P d7ed4198a4d24c99a1423ad12aa55761: Scheduling FlushDeltaMemStoresOp(0c01586a085546c6b85f6a2fd61f67da): perf score=2.188937
I20260812 06:20:19.440006  5775 maintenance_manager.cc:643] P d7ed4198a4d24c99a1423ad12aa55761: FlushDeltaMemStoresOp(0c01586a085546c6b85f6a2fd61f67da) complete. Timing: real 0.010s	user 0.004s	sys 0.004s 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:20:19.440440  5888 maintenance_manager.cc:419] P d7ed4198a4d24c99a1423ad12aa55761: Scheduling MajorDeltaCompactionOp(0c01586a085546c6b85f6a2fd61f67da): perf score=1.000000
I20260812 06:20:19.632560  5775 maintenance_manager.cc:643] P d7ed4198a4d24c99a1423ad12aa55761: MajorDeltaCompactionOp(0c01586a085546c6b85f6a2fd61f67da) complete. Timing: real 0.192s	user 0.130s	sys 0.061s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24815686,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":874,"lbm_read_time_us":13467,"lbm_reads_lt_1ms":572,"lbm_write_time_us":31504,"lbm_writes_lt_1ms":543,"mutex_wait_us":327,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":2816,"update_count":2500}
I20260812 06:20:19.633271  5888 maintenance_manager.cc:419] P d7ed4198a4d24c99a1423ad12aa55761: Scheduling FlushDeltaMemStoresOp(0c01586a085546c6b85f6a2fd61f67da): perf score=10.126437
I20260812 06:20:19.669552  5775 maintenance_manager.cc:643] P d7ed4198a4d24c99a1423ad12aa55761: FlushDeltaMemStoresOp(0c01586a085546c6b85f6a2fd61f67da) complete. Timing: real 0.036s	user 0.022s	sys 0.013s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":13357,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:20:19.670039  5888 maintenance_manager.cc:419] P d7ed4198a4d24c99a1423ad12aa55761: Scheduling FlushDeltaMemStoresOp(0c01586a085546c6b85f6a2fd61f67da): perf score=2.188937
I20260812 06:20:19.695008  5775 maintenance_manager.cc:643] P d7ed4198a4d24c99a1423ad12aa55761: FlushDeltaMemStoresOp(0c01586a085546c6b85f6a2fd61f67da) complete. Timing: real 0.025s	user 0.003s	sys 0.012s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6947,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:19.695442  5888 maintenance_manager.cc:419] P d7ed4198a4d24c99a1423ad12aa55761: Scheduling FlushDeltaMemStoresOp(0c01586a085546c6b85f6a2fd61f67da): perf score=2.188937
I20260812 06:20:19.715654  5775 maintenance_manager.cc:643] P d7ed4198a4d24c99a1423ad12aa55761: FlushDeltaMemStoresOp(0c01586a085546c6b85f6a2fd61f67da) complete. Timing: real 0.020s	user 0.004s	sys 0.013s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3838,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:19.716200  5888 maintenance_manager.cc:419] P d7ed4198a4d24c99a1423ad12aa55761: Scheduling MajorDeltaCompactionOp(0c01586a085546c6b85f6a2fd61f67da): perf score=1.000000
I20260812 06:20:19.904093  5775 maintenance_manager.cc:643] P d7ed4198a4d24c99a1423ad12aa55761: MajorDeltaCompactionOp(0c01586a085546c6b85f6a2fd61f67da) complete. Timing: real 0.188s	user 0.121s	sys 0.060s Metrics: {"cfile_cache_miss":533,"cfile_cache_miss_bytes":24815803,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":205,"lbm_read_time_us":11959,"lbm_reads_lt_1ms":573,"lbm_write_time_us":30323,"lbm_writes_lt_1ms":543,"mutex_wait_us":50,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":19968,"update_count":2500}
I20260812 06:20:19.904819  5888 maintenance_manager.cc:419] P d7ed4198a4d24c99a1423ad12aa55761: Scheduling FlushDeltaMemStoresOp(0c01586a085546c6b85f6a2fd61f67da): perf score=14.095187
I20260812 06:20:19.957412  5775 maintenance_manager.cc:643] P d7ed4198a4d24c99a1423ad12aa55761: FlushDeltaMemStoresOp(0c01586a085546c6b85f6a2fd61f67da) complete. Timing: real 0.052s	user 0.013s	sys 0.027s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":18488,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:20:19.957965  5888 maintenance_manager.cc:419] P d7ed4198a4d24c99a1423ad12aa55761: Scheduling FlushDeltaMemStoresOp(0c01586a085546c6b85f6a2fd61f67da): perf score=2.188937
I20260812 06:20:19.968705  5775 maintenance_manager.cc:643] P d7ed4198a4d24c99a1423ad12aa55761: FlushDeltaMemStoresOp(0c01586a085546c6b85f6a2fd61f67da) complete. Timing: real 0.011s	user 0.010s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3896,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:19.969184  5888 maintenance_manager.cc:419] P d7ed4198a4d24c99a1423ad12aa55761: Scheduling MajorDeltaCompactionOp(0c01586a085546c6b85f6a2fd61f67da): perf score=1.000000
I20260812 06:20:20.153194  5775 maintenance_manager.cc:643] P d7ed4198a4d24c99a1423ad12aa55761: MajorDeltaCompactionOp(0c01586a085546c6b85f6a2fd61f67da) complete. Timing: real 0.184s	user 0.119s	sys 0.055s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24815683,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":311,"lbm_read_time_us":11328,"lbm_reads_lt_1ms":572,"lbm_write_time_us":29755,"lbm_writes_lt_1ms":543,"mutex_wait_us":44,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":66432,"update_count":2500}
I20260812 06:20:20.153874  5888 maintenance_manager.cc:419] P d7ed4198a4d24c99a1423ad12aa55761: Scheduling FlushDeltaMemStoresOp(0c01586a085546c6b85f6a2fd61f67da): perf score=14.095187
I20260812 06:20:20.210739  5775 maintenance_manager.cc:643] P d7ed4198a4d24c99a1423ad12aa55761: FlushDeltaMemStoresOp(0c01586a085546c6b85f6a2fd61f67da) complete. Timing: real 0.057s	user 0.033s	sys 0.015s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":23001,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:20:20.211251  5888 maintenance_manager.cc:419] P d7ed4198a4d24c99a1423ad12aa55761: Scheduling FlushDeltaMemStoresOp(0c01586a085546c6b85f6a2fd61f67da): perf score=2.188937
I20260812 06:20:20.222219  5775 maintenance_manager.cc:643] P d7ed4198a4d24c99a1423ad12aa55761: FlushDeltaMemStoresOp(0c01586a085546c6b85f6a2fd61f67da) complete. Timing: real 0.011s	user 0.009s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3950,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:20.222828  5888 maintenance_manager.cc:419] P d7ed4198a4d24c99a1423ad12aa55761: Scheduling MajorDeltaCompactionOp(0c01586a085546c6b85f6a2fd61f67da): perf score=1.000000
I20260812 06:20:20.372592  5775 maintenance_manager.cc:643] P d7ed4198a4d24c99a1423ad12aa55761: MajorDeltaCompactionOp(0c01586a085546c6b85f6a2fd61f67da) complete. Timing: real 0.150s	user 0.121s	sys 0.022s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24815684,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":321,"lbm_read_time_us":10026,"lbm_reads_lt_1ms":572,"lbm_write_time_us":28845,"lbm_writes_lt_1ms":543,"mutex_wait_us":40,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":5760,"update_count":2500}
I20260812 06:20:20.373301  5888 maintenance_manager.cc:419] P d7ed4198a4d24c99a1423ad12aa55761: Scheduling FlushDeltaMemStoresOp(0c01586a085546c6b85f6a2fd61f67da): perf score=14.095187
I20260812 06:20:20.417814  5775 maintenance_manager.cc:643] P d7ed4198a4d24c99a1423ad12aa55761: FlushDeltaMemStoresOp(0c01586a085546c6b85f6a2fd61f67da) complete. Timing: real 0.044s	user 0.033s	sys 0.009s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":19173,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:20:20.418341  5888 maintenance_manager.cc:419] P d7ed4198a4d24c99a1423ad12aa55761: Scheduling FlushDeltaMemStoresOp(0c01586a085546c6b85f6a2fd61f67da): perf score=2.188937
I20260812 06:20:20.433342  5775 maintenance_manager.cc:643] P d7ed4198a4d24c99a1423ad12aa55761: FlushDeltaMemStoresOp(0c01586a085546c6b85f6a2fd61f67da) complete. Timing: real 0.015s	user 0.006s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5755,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:20.434333  5888 maintenance_manager.cc:419] P d7ed4198a4d24c99a1423ad12aa55761: Scheduling FlushMRSOp(0c01586a085546c6b85f6a2fd61f67da): perf score=1.000000
I20260812 06:20:20.464954  5775 maintenance_manager.cc:643] P d7ed4198a4d24c99a1423ad12aa55761: FlushMRSOp(0c01586a085546c6b85f6a2fd61f67da) complete. Timing: real 0.030s	user 0.030s	sys 0.000s Metrics: {"bytes_written":1193503,"cfile_init":1,"dirs.queue_time_us":85,"dirs.run_cpu_time_us":211,"dirs.run_wall_time_us":1170,"drs_written":1,"lbm_read_time_us":58,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1796,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":29}
I20260812 06:20:20.465596  5888 maintenance_manager.cc:419] P d7ed4198a4d24c99a1423ad12aa55761: Scheduling LogGCOp(0c01586a085546c6b85f6a2fd61f67da): free 124710299 bytes of WAL
I20260812 06:20:20.465865  5775 log_reader.cc:385] T 0c01586a085546c6b85f6a2fd61f67da: removed 12 log segments from log reader
I20260812 06:20:20.465932  5775 log.cc:1079] T 0c01586a085546c6b85f6a2fd61f67da P d7ed4198a4d24c99a1423ad12aa55761: Deleting log segment in path: /tmp/dist-test-task_bOXbU/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515613161794-5236-0/minicluster-data/ts-0-root/wals/0c01586a085546c6b85f6a2fd61f67da/wal-000000003 (ops 12-16)
I20260812 06:20:20.465970  5775 log.cc:1079] T 0c01586a085546c6b85f6a2fd61f67da P d7ed4198a4d24c99a1423ad12aa55761: Deleting log segment in path: /tmp/dist-test-task_bOXbU/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515613161794-5236-0/minicluster-data/ts-0-root/wals/0c01586a085546c6b85f6a2fd61f67da/wal-000000004 (ops 17-21)
I20260812 06:20:20.465993  5775 log.cc:1079] T 0c01586a085546c6b85f6a2fd61f67da P d7ed4198a4d24c99a1423ad12aa55761: Deleting log segment in path: /tmp/dist-test-task_bOXbU/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515613161794-5236-0/minicluster-data/ts-0-root/wals/0c01586a085546c6b85f6a2fd61f67da/wal-000000005 (ops 22-26)
I20260812 06:20:20.466023  5775 log.cc:1079] T 0c01586a085546c6b85f6a2fd61f67da P d7ed4198a4d24c99a1423ad12aa55761: Deleting log segment in path: /tmp/dist-test-task_bOXbU/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515613161794-5236-0/minicluster-data/ts-0-root/wals/0c01586a085546c6b85f6a2fd61f67da/wal-000000006 (ops 27-31)
I20260812 06:20:20.466049  5775 log.cc:1079] T 0c01586a085546c6b85f6a2fd61f67da P d7ed4198a4d24c99a1423ad12aa55761: Deleting log segment in path: /tmp/dist-test-task_bOXbU/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515613161794-5236-0/minicluster-data/ts-0-root/wals/0c01586a085546c6b85f6a2fd61f67da/wal-000000007 (ops 32-36)
I20260812 06:20:20.466084  5775 log.cc:1079] T 0c01586a085546c6b85f6a2fd61f67da P d7ed4198a4d24c99a1423ad12aa55761: Deleting log segment in path: /tmp/dist-test-task_bOXbU/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515613161794-5236-0/minicluster-data/ts-0-root/wals/0c01586a085546c6b85f6a2fd61f67da/wal-000000008 (ops 37-41)
I20260812 06:20:20.466115  5775 log.cc:1079] T 0c01586a085546c6b85f6a2fd61f67da P d7ed4198a4d24c99a1423ad12aa55761: Deleting log segment in path: /tmp/dist-test-task_bOXbU/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515613161794-5236-0/minicluster-data/ts-0-root/wals/0c01586a085546c6b85f6a2fd61f67da/wal-000000009 (ops 42-46)
I20260812 06:20:20.466142  5775 log.cc:1079] T 0c01586a085546c6b85f6a2fd61f67da P d7ed4198a4d24c99a1423ad12aa55761: Deleting log segment in path: /tmp/dist-test-task_bOXbU/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515613161794-5236-0/minicluster-data/ts-0-root/wals/0c01586a085546c6b85f6a2fd61f67da/wal-000000010 (ops 47-51)
I20260812 06:20:20.466169  5775 log.cc:1079] T 0c01586a085546c6b85f6a2fd61f67da P d7ed4198a4d24c99a1423ad12aa55761: Deleting log segment in path: /tmp/dist-test-task_bOXbU/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515613161794-5236-0/minicluster-data/ts-0-root/wals/0c01586a085546c6b85f6a2fd61f67da/wal-000000011 (ops 52-56)
I20260812 06:20:20.466197  5775 log.cc:1079] T 0c01586a085546c6b85f6a2fd61f67da P d7ed4198a4d24c99a1423ad12aa55761: Deleting log segment in path: /tmp/dist-test-task_bOXbU/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515613161794-5236-0/minicluster-data/ts-0-root/wals/0c01586a085546c6b85f6a2fd61f67da/wal-000000012 (ops 57-61)
I20260812 06:20:20.466226  5775 log.cc:1079] T 0c01586a085546c6b85f6a2fd61f67da P d7ed4198a4d24c99a1423ad12aa55761: Deleting log segment in path: /tmp/dist-test-task_bOXbU/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515613161794-5236-0/minicluster-data/ts-0-root/wals/0c01586a085546c6b85f6a2fd61f67da/wal-000000013 (ops 62-66)
I20260812 06:20:20.466259  5775 log.cc:1079] T 0c01586a085546c6b85f6a2fd61f67da P d7ed4198a4d24c99a1423ad12aa55761: Deleting log segment in path: /tmp/dist-test-task_bOXbU/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515613161794-5236-0/minicluster-data/ts-0-root/wals/0c01586a085546c6b85f6a2fd61f67da/wal-000000014 (ops 67-71)
I20260812 06:20:20.495713  5775 maintenance_manager.cc:643] P d7ed4198a4d24c99a1423ad12aa55761: LogGCOp(0c01586a085546c6b85f6a2fd61f67da) complete. Timing: real 0.030s	user 0.000s	sys 0.027s Metrics: {}
I20260812 06:20:20.496110  5888 maintenance_manager.cc:419] P d7ed4198a4d24c99a1423ad12aa55761: Scheduling UndoDeltaBlockGCOp(0c01586a085546c6b85f6a2fd61f67da): 463 bytes on disk
I20260812 06:20:20.496661  5775 maintenance_manager.cc:643] P d7ed4198a4d24c99a1423ad12aa55761: UndoDeltaBlockGCOp(0c01586a085546c6b85f6a2fd61f67da) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":115,"lbm_reads_lt_1ms":4}
I20260812 06:20:20.497123  5888 maintenance_manager.cc:419] P d7ed4198a4d24c99a1423ad12aa55761: Scheduling FlushDeltaMemStoresOp(0c01586a085546c6b85f6a2fd61f67da): perf score=2.188937
I20260812 06:20:20.517277  5775 maintenance_manager.cc:643] P d7ed4198a4d24c99a1423ad12aa55761: FlushDeltaMemStoresOp(0c01586a085546c6b85f6a2fd61f67da) complete. Timing: real 0.020s	user 0.015s	sys 0.000s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":6363,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:20.517655  5888 maintenance_manager.cc:419] P d7ed4198a4d24c99a1423ad12aa55761: Scheduling FlushDeltaMemStoresOp(0c01586a085546c6b85f6a2fd61f67da): perf score=2.188937
I20260812 06:20:20.538036  5775 maintenance_manager.cc:643] P d7ed4198a4d24c99a1423ad12aa55761: FlushDeltaMemStoresOp(0c01586a085546c6b85f6a2fd61f67da) complete. Timing: real 0.020s	user 0.004s	sys 0.014s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4148,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:20.538757  5888 maintenance_manager.cc:419] P d7ed4198a4d24c99a1423ad12aa55761: Scheduling MajorDeltaCompactionOp(0c01586a085546c6b85f6a2fd61f67da): perf score=1.000000
I20260812 06:20:20.795284  5775 maintenance_manager.cc:643] P d7ed4198a4d24c99a1423ad12aa55761: MajorDeltaCompactionOp(0c01586a085546c6b85f6a2fd61f67da) complete. Timing: real 0.256s	user 0.186s	sys 0.065s Metrics: {"cfile_cache_miss":734,"cfile_cache_miss_bytes":33020745,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":598,"lbm_read_time_us":14448,"lbm_reads_lt_1ms":774,"lbm_write_time_us":44942,"lbm_writes_lt_1ms":743,"mutex_wait_us":242,"peak_mem_usage":87969044,"reinsert_count":0,"spinlock_wait_cycles":10880,"thread_start_us":91,"threads_started":1,"update_count":3500}
I20260812 06:20:20.796216  5888 maintenance_manager.cc:419] P d7ed4198a4d24c99a1423ad12aa55761: Scheduling FlushDeltaMemStoresOp(0c01586a085546c6b85f6a2fd61f67da): perf score=18.063937
I20260812 06:20:20.855633  5775 maintenance_manager.cc:643] P d7ed4198a4d24c99a1423ad12aa55761: FlushDeltaMemStoresOp(0c01586a085546c6b85f6a2fd61f67da) complete. Timing: real 0.059s	user 0.034s	sys 0.020s Metrics: {"bytes_written":20512315,"delete_count":0,"lbm_write_time_us":26155,"lbm_writes_lt_1ms":503,"reinsert_count":0,"update_count":2500}
I20260812 06:20:20.856088  5888 maintenance_manager.cc:419] P d7ed4198a4d24c99a1423ad12aa55761: Scheduling FlushDeltaMemStoresOp(0c01586a085546c6b85f6a2fd61f67da): perf score=2.188937
I20260812 06:20:20.866355  5775 maintenance_manager.cc:643] P d7ed4198a4d24c99a1423ad12aa55761: FlushDeltaMemStoresOp(0c01586a085546c6b85f6a2fd61f67da) complete. Timing: real 0.010s	user 0.008s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3967,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:20.867110  5888 maintenance_manager.cc:419] P d7ed4198a4d24c99a1423ad12aa55761: Scheduling MajorDeltaCompactionOp(0c01586a085546c6b85f6a2fd61f67da): perf score=1.000000
I20260812 06:20:21.077080  5775 maintenance_manager.cc:643] P d7ed4198a4d24c99a1423ad12aa55761: MajorDeltaCompactionOp(0c01586a085546c6b85f6a2fd61f67da) complete. Timing: real 0.210s	user 0.135s	sys 0.071s Metrics: {"cfile_cache_miss":632,"cfile_cache_miss_bytes":28918097,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":1193,"lbm_read_time_us":15125,"lbm_reads_lt_1ms":672,"lbm_write_time_us":31455,"lbm_writes_lt_1ms":643,"mutex_wait_us":341,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":26752,"update_count":3000}
I20260812 06:20:21.077740  5888 maintenance_manager.cc:419] P d7ed4198a4d24c99a1423ad12aa55761: Scheduling FlushDeltaMemStoresOp(0c01586a085546c6b85f6a2fd61f67da): perf score=16.079562
I20260812 06:20:21.133903  5775 maintenance_manager.cc:643] P d7ed4198a4d24c99a1423ad12aa55761: FlushDeltaMemStoresOp(0c01586a085546c6b85f6a2fd61f67da) complete. Timing: real 0.056s	user 0.029s	sys 0.024s Metrics: {"bytes_written":17722675,"delete_count":0,"lbm_write_time_us":24963,"lbm_writes_lt_1ms":435,"reinsert_count":0,"update_count":2160}
I20260812 06:20:21.134444  5888 maintenance_manager.cc:419] P d7ed4198a4d24c99a1423ad12aa55761: Scheduling FlushDeltaMemStoresOp(0c01586a085546c6b85f6a2fd61f67da): perf score=2.188937
I20260812 06:20:21.145267  5775 maintenance_manager.cc:643] P d7ed4198a4d24c99a1423ad12aa55761: FlushDeltaMemStoresOp(0c01586a085546c6b85f6a2fd61f67da) complete. Timing: real 0.011s	user 0.004s	sys 0.005s Metrics: {"bytes_written":3200109,"delete_count":0,"lbm_write_time_us":3369,"lbm_writes_lt_1ms":81,"reinsert_count":0,"update_count":390}
I20260812 06:20:21.145684  5888 maintenance_manager.cc:419] P d7ed4198a4d24c99a1423ad12aa55761: Scheduling FlushDeltaMemStoresOp(0c01586a085546c6b85f6a2fd61f67da): perf score=2.188937
I20260812 06:20:21.154893  5775 maintenance_manager.cc:643] P d7ed4198a4d24c99a1423ad12aa55761: FlushDeltaMemStoresOp(0c01586a085546c6b85f6a2fd61f67da) complete. Timing: real 0.009s	user 0.003s	sys 0.005s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3685,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:20:21.155272  5888 maintenance_manager.cc:419] P d7ed4198a4d24c99a1423ad12aa55761: Scheduling MajorDeltaCompactionOp(0c01586a085546c6b85f6a2fd61f67da): perf score=1.000000
I20260812 06:20:21.357357  5775 maintenance_manager.cc:643] P d7ed4198a4d24c99a1423ad12aa55761: MajorDeltaCompactionOp(0c01586a085546c6b85f6a2fd61f67da) complete. Timing: real 0.202s	user 0.138s	sys 0.063s Metrics: {"cfile_cache_miss":633,"cfile_cache_miss_bytes":28918184,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":448,"lbm_read_time_us":12863,"lbm_reads_lt_1ms":673,"lbm_write_time_us":34468,"lbm_writes_lt_1ms":643,"mutex_wait_us":26,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":11008,"update_count":3000}
I20260812 06:20:21.358095  5888 maintenance_manager.cc:419] P d7ed4198a4d24c99a1423ad12aa55761: Scheduling FlushDeltaMemStoresOp(0c01586a085546c6b85f6a2fd61f67da): perf score=14.095187
I20260812 06:20:21.433238  5775 maintenance_manager.cc:643] P d7ed4198a4d24c99a1423ad12aa55761: FlushDeltaMemStoresOp(0c01586a085546c6b85f6a2fd61f67da) complete. Timing: real 0.075s	user 0.028s	sys 0.015s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":51070,"lbm_writes_10-100_ms":1,"lbm_writes_lt_1ms":402,"reinsert_count":0,"update_count":2000}
I20260812 06:20:21.433732  5888 maintenance_manager.cc:419] P d7ed4198a4d24c99a1423ad12aa55761: Scheduling FlushDeltaMemStoresOp(0c01586a085546c6b85f6a2fd61f67da): perf score=2.188937
I20260812 06:20:21.447413  5775 maintenance_manager.cc:643] P d7ed4198a4d24c99a1423ad12aa55761: FlushDeltaMemStoresOp(0c01586a085546c6b85f6a2fd61f67da) complete. Timing: real 0.013s	user 0.004s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5112,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:21.448069  5888 maintenance_manager.cc:419] P d7ed4198a4d24c99a1423ad12aa55761: Scheduling MajorDeltaCompactionOp(0c01586a085546c6b85f6a2fd61f67da): perf score=1.000000
I20260812 06:20:21.616005  5775 maintenance_manager.cc:643] P d7ed4198a4d24c99a1423ad12aa55761: MajorDeltaCompactionOp(0c01586a085546c6b85f6a2fd61f67da) complete. Timing: real 0.168s	user 0.096s	sys 0.072s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24815684,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":689,"lbm_read_time_us":10251,"lbm_reads_lt_1ms":564,"lbm_write_time_us":29756,"lbm_writes_lt_1ms":543,"mutex_wait_us":247,"peak_mem_usage":63115900,"reinsert_count":0,"update_count":2500}
I20260812 06:20:21.616752  5888 maintenance_manager.cc:419] P d7ed4198a4d24c99a1423ad12aa55761: Scheduling FlushDeltaMemStoresOp(0c01586a085546c6b85f6a2fd61f67da): perf score=14.095187
I20260812 06:20:21.667631  5775 maintenance_manager.cc:643] P d7ed4198a4d24c99a1423ad12aa55761: FlushDeltaMemStoresOp(0c01586a085546c6b85f6a2fd61f67da) complete. Timing: real 0.051s	user 0.037s	sys 0.011s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":23997,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":402,"reinsert_count":0,"update_count":2000}
I20260812 06:20:21.668129  5888 maintenance_manager.cc:419] P d7ed4198a4d24c99a1423ad12aa55761: Scheduling FlushDeltaMemStoresOp(0c01586a085546c6b85f6a2fd61f67da): perf score=2.188937
I20260812 06:20:21.681131  5775 maintenance_manager.cc:643] P d7ed4198a4d24c99a1423ad12aa55761: FlushDeltaMemStoresOp(0c01586a085546c6b85f6a2fd61f67da) complete. Timing: real 0.013s	user 0.004s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4981,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:21.681648  5888 maintenance_manager.cc:419] P d7ed4198a4d24c99a1423ad12aa55761: Scheduling MajorDeltaCompactionOp(0c01586a085546c6b85f6a2fd61f67da): perf score=1.000000
I20260812 06:20:21.856771  5775 maintenance_manager.cc:643] P d7ed4198a4d24c99a1423ad12aa55761: MajorDeltaCompactionOp(0c01586a085546c6b85f6a2fd61f67da) complete. Timing: real 0.175s	user 0.116s	sys 0.054s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24815684,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":469,"lbm_read_time_us":11996,"lbm_reads_lt_1ms":568,"lbm_write_time_us":29641,"lbm_writes_lt_1ms":543,"mutex_wait_us":103,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":896,"update_count":2500}
I20260812 06:20:21.857228  5888 maintenance_manager.cc:419] P d7ed4198a4d24c99a1423ad12aa55761: Scheduling FlushDeltaMemStoresOp(0c01586a085546c6b85f6a2fd61f67da): perf score=14.095187
I20260812 06:20:21.916008  5775 maintenance_manager.cc:643] P d7ed4198a4d24c99a1423ad12aa55761: FlushDeltaMemStoresOp(0c01586a085546c6b85f6a2fd61f67da) complete. Timing: real 0.059s	user 0.039s	sys 0.009s Metrics: {"bytes_written":16409906,"delete_count":0,"lbm_write_time_us":18426,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:20:21.916600  5888 maintenance_manager.cc:419] P d7ed4198a4d24c99a1423ad12aa55761: Scheduling FlushDeltaMemStoresOp(0c01586a085546c6b85f6a2fd61f67da): perf score=2.188937
I20260812 06:20:21.926911  5775 maintenance_manager.cc:643] P d7ed4198a4d24c99a1423ad12aa55761: FlushDeltaMemStoresOp(0c01586a085546c6b85f6a2fd61f67da) complete. Timing: real 0.010s	user 0.004s	sys 0.004s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4096,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:21.927531  5888 maintenance_manager.cc:419] P d7ed4198a4d24c99a1423ad12aa55761: Scheduling FlushMRSOp(0c01586a085546c6b85f6a2fd61f67da): perf score=1.000000
I20260812 06:20:21.959200  5775 maintenance_manager.cc:643] P d7ed4198a4d24c99a1423ad12aa55761: FlushMRSOp(0c01586a085546c6b85f6a2fd61f67da) complete. Timing: real 0.031s	user 0.030s	sys 0.000s Metrics: {"bytes_written":1193509,"cfile_init":1,"dirs.queue_time_us":53,"dirs.run_cpu_time_us":194,"dirs.run_wall_time_us":1351,"drs_written":1,"lbm_read_time_us":38,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1385,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":29}
I20260812 06:20:21.959818  5888 maintenance_manager.cc:419] P d7ed4198a4d24c99a1423ad12aa55761: Scheduling UndoDeltaBlockGCOp(0c01586a085546c6b85f6a2fd61f67da): 462 bytes on disk
I20260812 06:20:21.960196  5775 maintenance_manager.cc:643] P d7ed4198a4d24c99a1423ad12aa55761: UndoDeltaBlockGCOp(0c01586a085546c6b85f6a2fd61f67da) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":55,"lbm_reads_lt_1ms":4}
I20260812 06:20:21.960700  5888 maintenance_manager.cc:419] P d7ed4198a4d24c99a1423ad12aa55761: Scheduling MajorDeltaCompactionOp(0c01586a085546c6b85f6a2fd61f67da): perf score=1.000000
I20260812 06:20:22.144613  5775 maintenance_manager.cc:643] P d7ed4198a4d24c99a1423ad12aa55761: MajorDeltaCompactionOp(0c01586a085546c6b85f6a2fd61f67da) complete. Timing: real 0.184s	user 0.112s	sys 0.062s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24815687,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":288,"dirs.run_cpu_time_us":581,"dirs.run_wall_time_us":4356,"lbm_read_time_us":10773,"lbm_reads_lt_1ms":564,"lbm_write_time_us":29935,"lbm_writes_lt_1ms":543,"mutex_wait_us":2,"peak_mem_usage":63115900,"reinsert_count":0,"update_count":2500}
I20260812 06:20:22.145336  5888 maintenance_manager.cc:419] P d7ed4198a4d24c99a1423ad12aa55761: Scheduling LogGCOp(0c01586a085546c6b85f6a2fd61f67da): free 120553339 bytes of WAL
I20260812 06:20:22.145591  5775 log_reader.cc:385] T 0c01586a085546c6b85f6a2fd61f67da: removed 12 log segments from log reader
I20260812 06:20:22.145656  5775 log.cc:1079] T 0c01586a085546c6b85f6a2fd61f67da P d7ed4198a4d24c99a1423ad12aa55761: Deleting log segment in path: /tmp/dist-test-task_bOXbU/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515613161794-5236-0/minicluster-data/ts-0-root/wals/0c01586a085546c6b85f6a2fd61f67da/wal-000000015 (ops 72-76)
I20260812 06:20:22.145699  5775 log.cc:1079] T 0c01586a085546c6b85f6a2fd61f67da P d7ed4198a4d24c99a1423ad12aa55761: Deleting log segment in path: /tmp/dist-test-task_bOXbU/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515613161794-5236-0/minicluster-data/ts-0-root/wals/0c01586a085546c6b85f6a2fd61f67da/wal-000000016 (ops 77-80)
I20260812 06:20:22.145740  5775 log.cc:1079] T 0c01586a085546c6b85f6a2fd61f67da P d7ed4198a4d24c99a1423ad12aa55761: Deleting log segment in path: /tmp/dist-test-task_bOXbU/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515613161794-5236-0/minicluster-data/ts-0-root/wals/0c01586a085546c6b85f6a2fd61f67da/wal-000000017 (ops 81-85)
I20260812 06:20:22.145769  5775 log.cc:1079] T 0c01586a085546c6b85f6a2fd61f67da P d7ed4198a4d24c99a1423ad12aa55761: Deleting log segment in path: /tmp/dist-test-task_bOXbU/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515613161794-5236-0/minicluster-data/ts-0-root/wals/0c01586a085546c6b85f6a2fd61f67da/wal-000000018 (ops 86-90)
I20260812 06:20:22.145802  5775 log.cc:1079] T 0c01586a085546c6b85f6a2fd61f67da P d7ed4198a4d24c99a1423ad12aa55761: Deleting log segment in path: /tmp/dist-test-task_bOXbU/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515613161794-5236-0/minicluster-data/ts-0-root/wals/0c01586a085546c6b85f6a2fd61f67da/wal-000000019 (ops 91-95)
I20260812 06:20:22.145834  5775 log.cc:1079] T 0c01586a085546c6b85f6a2fd61f67da P d7ed4198a4d24c99a1423ad12aa55761: Deleting log segment in path: /tmp/dist-test-task_bOXbU/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515613161794-5236-0/minicluster-data/ts-0-root/wals/0c01586a085546c6b85f6a2fd61f67da/wal-000000020 (ops 96-100)
I20260812 06:20:22.145869  5775 log.cc:1079] T 0c01586a085546c6b85f6a2fd61f67da P d7ed4198a4d24c99a1423ad12aa55761: Deleting log segment in path: /tmp/dist-test-task_bOXbU/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515613161794-5236-0/minicluster-data/ts-0-root/wals/0c01586a085546c6b85f6a2fd61f67da/wal-000000021 (ops 101-105)
I20260812 06:20:22.145902  5775 log.cc:1079] T 0c01586a085546c6b85f6a2fd61f67da P d7ed4198a4d24c99a1423ad12aa55761: Deleting log segment in path: /tmp/dist-test-task_bOXbU/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515613161794-5236-0/minicluster-data/ts-0-root/wals/0c01586a085546c6b85f6a2fd61f67da/wal-000000022 (ops 106-110)
I20260812 06:20:22.145939  5775 log.cc:1079] T 0c01586a085546c6b85f6a2fd61f67da P d7ed4198a4d24c99a1423ad12aa55761: Deleting log segment in path: /tmp/dist-test-task_bOXbU/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515613161794-5236-0/minicluster-data/ts-0-root/wals/0c01586a085546c6b85f6a2fd61f67da/wal-000000023 (ops 111-114)
I20260812 06:20:22.145972  5775 log.cc:1079] T 0c01586a085546c6b85f6a2fd61f67da P d7ed4198a4d24c99a1423ad12aa55761: Deleting log segment in path: /tmp/dist-test-task_bOXbU/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515613161794-5236-0/minicluster-data/ts-0-root/wals/0c01586a085546c6b85f6a2fd61f67da/wal-000000024 (ops 115-119)
I20260812 06:20:22.146006  5775 log.cc:1079] T 0c01586a085546c6b85f6a2fd61f67da P d7ed4198a4d24c99a1423ad12aa55761: Deleting log segment in path: /tmp/dist-test-task_bOXbU/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515613161794-5236-0/minicluster-data/ts-0-root/wals/0c01586a085546c6b85f6a2fd61f67da/wal-000000025 (ops 120-124)
I20260812 06:20:22.146042  5775 log.cc:1079] T 0c01586a085546c6b85f6a2fd61f67da P d7ed4198a4d24c99a1423ad12aa55761: Deleting log segment in path: /tmp/dist-test-task_bOXbU/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515613161794-5236-0/minicluster-data/ts-0-root/wals/0c01586a085546c6b85f6a2fd61f67da/wal-000000026 (ops 125-129)
I20260812 06:20:22.173034  5775 maintenance_manager.cc:643] P d7ed4198a4d24c99a1423ad12aa55761: LogGCOp(0c01586a085546c6b85f6a2fd61f67da) complete. Timing: real 0.028s	user 0.000s	sys 0.027s Metrics: {}
I20260812 06:20:22.173461  5888 maintenance_manager.cc:419] P d7ed4198a4d24c99a1423ad12aa55761: Scheduling FlushDeltaMemStoresOp(0c01586a085546c6b85f6a2fd61f67da): perf score=18.063937
I20260812 06:20:22.230716  5775 maintenance_manager.cc:643] P d7ed4198a4d24c99a1423ad12aa55761: FlushDeltaMemStoresOp(0c01586a085546c6b85f6a2fd61f67da) complete. Timing: real 0.057s	user 0.035s	sys 0.020s Metrics: {"bytes_written":20512315,"delete_count":0,"lbm_write_time_us":22141,"lbm_writes_lt_1ms":503,"reinsert_count":0,"update_count":2500}
I20260812 06:20:22.231379  5888 maintenance_manager.cc:419] P d7ed4198a4d24c99a1423ad12aa55761: Scheduling FlushDeltaMemStoresOp(0c01586a085546c6b85f6a2fd61f67da): perf score=2.188937
I20260812 06:20:22.255757  5775 maintenance_manager.cc:643] P d7ed4198a4d24c99a1423ad12aa55761: FlushDeltaMemStoresOp(0c01586a085546c6b85f6a2fd61f67da) complete. Timing: real 0.024s	user 0.006s	sys 0.007s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5878,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:22.256206  5888 maintenance_manager.cc:419] P d7ed4198a4d24c99a1423ad12aa55761: Scheduling FlushDeltaMemStoresOp(0c01586a085546c6b85f6a2fd61f67da): perf score=2.188937
I20260812 06:20:22.270330  5775 maintenance_manager.cc:643] P d7ed4198a4d24c99a1423ad12aa55761: FlushDeltaMemStoresOp(0c01586a085546c6b85f6a2fd61f67da) complete. Timing: real 0.014s	user 0.011s	sys 0.001s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":5620,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:22.270774  5888 maintenance_manager.cc:419] P d7ed4198a4d24c99a1423ad12aa55761: Scheduling MajorDeltaCompactionOp(0c01586a085546c6b85f6a2fd61f67da): perf score=1.000000
I20260812 06:20:22.502741  5775 maintenance_manager.cc:643] P d7ed4198a4d24c99a1423ad12aa55761: MajorDeltaCompactionOp(0c01586a085546c6b85f6a2fd61f67da) complete. Timing: real 0.232s	user 0.156s	sys 0.072s Metrics: {"cfile_cache_miss":733,"cfile_cache_miss_bytes":33020627,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":314,"lbm_read_time_us":15853,"lbm_reads_lt_1ms":773,"lbm_write_time_us":38513,"lbm_writes_lt_1ms":743,"mutex_wait_us":21,"peak_mem_usage":87969044,"reinsert_count":0,"spinlock_wait_cycles":11776,"update_count":3500}
I20260812 06:20:22.503473  5888 maintenance_manager.cc:419] P d7ed4198a4d24c99a1423ad12aa55761: Scheduling FlushDeltaMemStoresOp(0c01586a085546c6b85f6a2fd61f67da): perf score=18.063937
I20260812 06:20:22.574658  5775 maintenance_manager.cc:643] P d7ed4198a4d24c99a1423ad12aa55761: FlushDeltaMemStoresOp(0c01586a085546c6b85f6a2fd61f67da) complete. Timing: real 0.071s	user 0.041s	sys 0.019s Metrics: {"bytes_written":20512318,"delete_count":0,"lbm_write_time_us":27003,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":502,"reinsert_count":0,"update_count":2500}
I20260812 06:20:22.575217  5888 maintenance_manager.cc:419] P d7ed4198a4d24c99a1423ad12aa55761: Scheduling FlushDeltaMemStoresOp(0c01586a085546c6b85f6a2fd61f67da): perf score=2.188937
I20260812 06:20:22.586760  5775 maintenance_manager.cc:643] P d7ed4198a4d24c99a1423ad12aa55761: FlushDeltaMemStoresOp(0c01586a085546c6b85f6a2fd61f67da) complete. Timing: real 0.011s	user 0.009s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4244,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:22.587397  5888 maintenance_manager.cc:419] P d7ed4198a4d24c99a1423ad12aa55761: Scheduling MajorDeltaCompactionOp(0c01586a085546c6b85f6a2fd61f67da): perf score=1.000000
I20260812 06:20:22.800865  5775 maintenance_manager.cc:643] P d7ed4198a4d24c99a1423ad12aa55761: MajorDeltaCompactionOp(0c01586a085546c6b85f6a2fd61f67da) complete. Timing: real 0.213s	user 0.140s	sys 0.070s Metrics: {"cfile_cache_miss":632,"cfile_cache_miss_bytes":28918100,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":319,"lbm_read_time_us":13789,"lbm_reads_lt_1ms":672,"lbm_write_time_us":36153,"lbm_writes_lt_1ms":643,"mutex_wait_us":47,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":94720,"update_count":3000}
I20260812 06:20:22.801802  5888 maintenance_manager.cc:419] P d7ed4198a4d24c99a1423ad12aa55761: Scheduling FlushDeltaMemStoresOp(0c01586a085546c6b85f6a2fd61f67da): perf score=16.079562
I20260812 06:20:22.869074  5775 maintenance_manager.cc:643] P d7ed4198a4d24c99a1423ad12aa55761: FlushDeltaMemStoresOp(0c01586a085546c6b85f6a2fd61f67da) complete. Timing: real 0.067s	user 0.036s	sys 0.020s Metrics: {"bytes_written":17722675,"delete_count":0,"lbm_write_time_us":25759,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":434,"reinsert_count":0,"update_count":2160}
I20260812 06:20:22.869554  5888 maintenance_manager.cc:419] P d7ed4198a4d24c99a1423ad12aa55761: Scheduling FlushDeltaMemStoresOp(0c01586a085546c6b85f6a2fd61f67da): perf score=5.165500
I20260812 06:20:22.887717  5775 maintenance_manager.cc:643] P d7ed4198a4d24c99a1423ad12aa55761: FlushDeltaMemStoresOp(0c01586a085546c6b85f6a2fd61f67da) complete. Timing: real 0.018s	user 0.012s	sys 0.004s Metrics: {"bytes_written":6892309,"delete_count":0,"lbm_write_time_us":7675,"lbm_writes_lt_1ms":171,"reinsert_count":0,"update_count":840}
I20260812 06:20:22.888222  5888 maintenance_manager.cc:419] P d7ed4198a4d24c99a1423ad12aa55761: Scheduling MajorDeltaCompactionOp(0c01586a085546c6b85f6a2fd61f67da): perf score=1.000000
I20260812 06:20:23.088783  5775 maintenance_manager.cc:643] P d7ed4198a4d24c99a1423ad12aa55761: MajorDeltaCompactionOp(0c01586a085546c6b85f6a2fd61f67da) complete. Timing: real 0.200s	user 0.133s	sys 0.068s Metrics: {"cfile_cache_miss":632,"cfile_cache_miss_bytes":28918101,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":278,"lbm_read_time_us":14327,"lbm_reads_lt_1ms":672,"lbm_write_time_us":32295,"lbm_writes_lt_1ms":643,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":21120,"update_count":3000}
I20260812 06:20:23.090061  5888 maintenance_manager.cc:419] P d7ed4198a4d24c99a1423ad12aa55761: Scheduling FlushDeltaMemStoresOp(0c01586a085546c6b85f6a2fd61f67da): perf score=18.063937
I20260812 06:20:23.161543  5775 maintenance_manager.cc:643] P d7ed4198a4d24c99a1423ad12aa55761: FlushDeltaMemStoresOp(0c01586a085546c6b85f6a2fd61f67da) complete. Timing: real 0.071s	user 0.031s	sys 0.032s Metrics: {"bytes_written":20512315,"delete_count":0,"lbm_write_time_us":29164,"lbm_writes_lt_1ms":503,"reinsert_count":0,"update_count":2500}
I20260812 06:20:23.162142  5888 maintenance_manager.cc:419] P d7ed4198a4d24c99a1423ad12aa55761: Scheduling FlushDeltaMemStoresOp(0c01586a085546c6b85f6a2fd61f67da): perf score=2.188937
I20260812 06:20:23.177351  5775 maintenance_manager.cc:643] P d7ed4198a4d24c99a1423ad12aa55761: FlushDeltaMemStoresOp(0c01586a085546c6b85f6a2fd61f67da) complete. Timing: real 0.015s	user 0.002s	sys 0.012s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5639,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:23.177935  5888 maintenance_manager.cc:419] P d7ed4198a4d24c99a1423ad12aa55761: Scheduling MajorDeltaCompactionOp(0c01586a085546c6b85f6a2fd61f67da): perf score=1.000000
I20260812 06:20:23.397020  5775 maintenance_manager.cc:643] P d7ed4198a4d24c99a1423ad12aa55761: MajorDeltaCompactionOp(0c01586a085546c6b85f6a2fd61f67da) complete. Timing: real 0.219s	user 0.119s	sys 0.091s Metrics: {"cfile_cache_miss":632,"cfile_cache_miss_bytes":28918097,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":381,"lbm_read_time_us":14654,"lbm_reads_lt_1ms":672,"lbm_write_time_us":35164,"lbm_writes_lt_1ms":643,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":3072,"update_count":3000}
I20260812 06:20:23.397735  5888 maintenance_manager.cc:419] P d7ed4198a4d24c99a1423ad12aa55761: Scheduling FlushDeltaMemStoresOp(0c01586a085546c6b85f6a2fd61f67da): perf score=18.063937
I20260812 06:20:23.458396  5775 maintenance_manager.cc:643] P d7ed4198a4d24c99a1423ad12aa55761: FlushDeltaMemStoresOp(0c01586a085546c6b85f6a2fd61f67da) complete. Timing: real 0.060s	user 0.034s	sys 0.024s Metrics: {"bytes_written":20512312,"delete_count":0,"lbm_write_time_us":27089,"lbm_writes_lt_1ms":503,"reinsert_count":0,"update_count":2500}
I20260812 06:20:23.458892  5888 maintenance_manager.cc:419] P d7ed4198a4d24c99a1423ad12aa55761: Scheduling FlushDeltaMemStoresOp(0c01586a085546c6b85f6a2fd61f67da): perf score=2.188937
I20260812 06:20:23.470965  5775 maintenance_manager.cc:643] P d7ed4198a4d24c99a1423ad12aa55761: FlushDeltaMemStoresOp(0c01586a085546c6b85f6a2fd61f67da) complete. Timing: real 0.012s	user 0.005s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4191,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:23.471499  5888 maintenance_manager.cc:419] P d7ed4198a4d24c99a1423ad12aa55761: Scheduling FlushMRSOp(0c01586a085546c6b85f6a2fd61f67da): perf score=1.000000
I20260812 06:20:23.504565  5775 maintenance_manager.cc:643] P d7ed4198a4d24c99a1423ad12aa55761: FlushMRSOp(0c01586a085546c6b85f6a2fd61f67da) complete. Timing: real 0.033s	user 0.029s	sys 0.003s Metrics: {"bytes_written":1275447,"cfile_init":1,"dirs.queue_time_us":71,"dirs.run_cpu_time_us":199,"dirs.run_wall_time_us":1403,"drs_written":1,"lbm_read_time_us":38,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1644,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":31}
I20260812 06:20:23.505245  5888 maintenance_manager.cc:419] P d7ed4198a4d24c99a1423ad12aa55761: Scheduling LogGCOp(0c01586a085546c6b85f6a2fd61f67da): free 120553697 bytes of WAL
I20260812 06:20:23.505494  5775 log_reader.cc:385] T 0c01586a085546c6b85f6a2fd61f67da: removed 12 log segments from log reader
I20260812 06:20:23.505542  5775 log.cc:1079] T 0c01586a085546c6b85f6a2fd61f67da P d7ed4198a4d24c99a1423ad12aa55761: Deleting log segment in path: /tmp/dist-test-task_bOXbU/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515613161794-5236-0/minicluster-data/ts-0-root/wals/0c01586a085546c6b85f6a2fd61f67da/wal-000000027 (ops 130-134)
I20260812 06:20:23.505571  5775 log.cc:1079] T 0c01586a085546c6b85f6a2fd61f67da P d7ed4198a4d24c99a1423ad12aa55761: Deleting log segment in path: /tmp/dist-test-task_bOXbU/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515613161794-5236-0/minicluster-data/ts-0-root/wals/0c01586a085546c6b85f6a2fd61f67da/wal-000000028 (ops 135-138)
I20260812 06:20:23.505642  5775 log.cc:1079] T 0c01586a085546c6b85f6a2fd61f67da P d7ed4198a4d24c99a1423ad12aa55761: Deleting log segment in path: /tmp/dist-test-task_bOXbU/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515613161794-5236-0/minicluster-data/ts-0-root/wals/0c01586a085546c6b85f6a2fd61f67da/wal-000000029 (ops 139-143)
I20260812 06:20:23.505684  5775 log.cc:1079] T 0c01586a085546c6b85f6a2fd61f67da P d7ed4198a4d24c99a1423ad12aa55761: Deleting log segment in path: /tmp/dist-test-task_bOXbU/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515613161794-5236-0/minicluster-data/ts-0-root/wals/0c01586a085546c6b85f6a2fd61f67da/wal-000000030 (ops 144-148)
I20260812 06:20:23.505722  5775 log.cc:1079] T 0c01586a085546c6b85f6a2fd61f67da P d7ed4198a4d24c99a1423ad12aa55761: Deleting log segment in path: /tmp/dist-test-task_bOXbU/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515613161794-5236-0/minicluster-data/ts-0-root/wals/0c01586a085546c6b85f6a2fd61f67da/wal-000000031 (ops 149-153)
I20260812 06:20:23.505764  5775 log.cc:1079] T 0c01586a085546c6b85f6a2fd61f67da P d7ed4198a4d24c99a1423ad12aa55761: Deleting log segment in path: /tmp/dist-test-task_bOXbU/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515613161794-5236-0/minicluster-data/ts-0-root/wals/0c01586a085546c6b85f6a2fd61f67da/wal-000000032 (ops 154-158)
I20260812 06:20:23.505800  5775 log.cc:1079] T 0c01586a085546c6b85f6a2fd61f67da P d7ed4198a4d24c99a1423ad12aa55761: Deleting log segment in path: /tmp/dist-test-task_bOXbU/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515613161794-5236-0/minicluster-data/ts-0-root/wals/0c01586a085546c6b85f6a2fd61f67da/wal-000000033 (ops 159-163)
I20260812 06:20:23.505851  5775 log.cc:1079] T 0c01586a085546c6b85f6a2fd61f67da P d7ed4198a4d24c99a1423ad12aa55761: Deleting log segment in path: /tmp/dist-test-task_bOXbU/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515613161794-5236-0/minicluster-data/ts-0-root/wals/0c01586a085546c6b85f6a2fd61f67da/wal-000000034 (ops 164-168)
I20260812 06:20:23.505897  5775 log.cc:1079] T 0c01586a085546c6b85f6a2fd61f67da P d7ed4198a4d24c99a1423ad12aa55761: Deleting log segment in path: /tmp/dist-test-task_bOXbU/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515613161794-5236-0/minicluster-data/ts-0-root/wals/0c01586a085546c6b85f6a2fd61f67da/wal-000000035 (ops 169-173)
I20260812 06:20:23.505934  5775 log.cc:1079] T 0c01586a085546c6b85f6a2fd61f67da P d7ed4198a4d24c99a1423ad12aa55761: Deleting log segment in path: /tmp/dist-test-task_bOXbU/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515613161794-5236-0/minicluster-data/ts-0-root/wals/0c01586a085546c6b85f6a2fd61f67da/wal-000000036 (ops 174-178)
I20260812 06:20:23.505970  5775 log.cc:1079] T 0c01586a085546c6b85f6a2fd61f67da P d7ed4198a4d24c99a1423ad12aa55761: Deleting log segment in path: /tmp/dist-test-task_bOXbU/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515613161794-5236-0/minicluster-data/ts-0-root/wals/0c01586a085546c6b85f6a2fd61f67da/wal-000000037 (ops 179-182)
I20260812 06:20:23.506007  5775 log.cc:1079] T 0c01586a085546c6b85f6a2fd61f67da P d7ed4198a4d24c99a1423ad12aa55761: Deleting log segment in path: /tmp/dist-test-task_bOXbU/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515613161794-5236-0/minicluster-data/ts-0-root/wals/0c01586a085546c6b85f6a2fd61f67da/wal-000000038 (ops 183-187)
I20260812 06:20:23.534337  5775 maintenance_manager.cc:643] P d7ed4198a4d24c99a1423ad12aa55761: LogGCOp(0c01586a085546c6b85f6a2fd61f67da) complete. Timing: real 0.029s	user 0.004s	sys 0.023s Metrics: {}
I20260812 06:20:23.534893  5888 maintenance_manager.cc:419] P d7ed4198a4d24c99a1423ad12aa55761: Scheduling UndoDeltaBlockGCOp(0c01586a085546c6b85f6a2fd61f67da): 482 bytes on disk
I20260812 06:20:23.535542  5775 maintenance_manager.cc:643] P d7ed4198a4d24c99a1423ad12aa55761: UndoDeltaBlockGCOp(0c01586a085546c6b85f6a2fd61f67da) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":69,"lbm_reads_lt_1ms":4}
I20260812 06:20:23.536245  5888 maintenance_manager.cc:419] P d7ed4198a4d24c99a1423ad12aa55761: Scheduling FlushDeltaMemStoresOp(0c01586a085546c6b85f6a2fd61f67da): perf score=3.181125
I20260812 06:20:23.548642  5775 maintenance_manager.cc:643] P d7ed4198a4d24c99a1423ad12aa55761: FlushDeltaMemStoresOp(0c01586a085546c6b85f6a2fd61f67da) complete. Timing: real 0.012s	user 0.012s	sys 0.000s Metrics: {"bytes_written":4718028,"delete_count":0,"lbm_write_time_us":4907,"lbm_writes_lt_1ms":118,"reinsert_count":0,"update_count":575}
I20260812 06:20:23.549125  5888 maintenance_manager.cc:419] P d7ed4198a4d24c99a1423ad12aa55761: Scheduling FlushDeltaMemStoresOp(0c01586a085546c6b85f6a2fd61f67da): perf score=2.188937
I20260812 06:20:23.557893  5775 maintenance_manager.cc:643] P d7ed4198a4d24c99a1423ad12aa55761: FlushDeltaMemStoresOp(0c01586a085546c6b85f6a2fd61f67da) complete. Timing: real 0.009s	user 0.007s	sys 0.000s Metrics: {"bytes_written":3487280,"delete_count":0,"lbm_write_time_us":3370,"lbm_writes_lt_1ms":88,"reinsert_count":0,"update_count":425}
I20260812 06:20:23.558435  5888 maintenance_manager.cc:419] P d7ed4198a4d24c99a1423ad12aa55761: Scheduling MajorDeltaCompactionOp(0c01586a085546c6b85f6a2fd61f67da): perf score=1.000000
I20260812 06:20:23.734366  5236 heavy-update-compaction-itest.cc:229] Time spent updating: real 4.903s	user 1.815s	sys 0.214s
I20260812 06:20:23.801658  5775 maintenance_manager.cc:643] P d7ed4198a4d24c99a1423ad12aa55761: MajorDeltaCompactionOp(0c01586a085546c6b85f6a2fd61f67da) complete. Timing: real 0.243s	user 0.177s	sys 0.064s Metrics: {"cfile_cache_miss":834,"cfile_cache_miss_bytes":37123146,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"lbm_read_time_us":19096,"lbm_reads_lt_1ms":870,"lbm_write_time_us":46566,"lbm_writes_lt_1ms":843,"peak_mem_usage":100395616,"reinsert_count":0,"spinlock_wait_cycles":1536,"update_count":4000}
I20260812 06:20:23.802146  5888 maintenance_manager.cc:419] P d7ed4198a4d24c99a1423ad12aa55761: Scheduling FlushDeltaMemStoresOp(0c01586a085546c6b85f6a2fd61f67da): perf score=14.095187
I20260812 06:20:23.835471  5236 heavy-update-compaction-itest.cc:265] Time spent scanning: real 0.101s	user 0.001s	sys 0.000s
I20260812 06:20:23.836020  5236 tablet_server.cc:179] TabletServer@127.5.29.1:0 shutting down...
I20260812 06:20:23.844288  5775 maintenance_manager.cc:643] P d7ed4198a4d24c99a1423ad12aa55761: FlushDeltaMemStoresOp(0c01586a085546c6b85f6a2fd61f67da) complete. Timing: real 0.042s	user 0.028s	sys 0.011s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":18301,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:20:23.844904  5236 ts_tablet_manager.cc:1507] Shutting down tablet manager...
I20260812 06:20:23.845166  5236 tablet_replica.cc:333] T 0c01586a085546c6b85f6a2fd61f67da P d7ed4198a4d24c99a1423ad12aa55761: stopping tablet replica
I20260812 06:20:23.845300  5236 raft_consensus.cc:2243] T 0c01586a085546c6b85f6a2fd61f67da P d7ed4198a4d24c99a1423ad12aa55761 [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:20:23.845505  5236 raft_consensus.cc:2272] T 0c01586a085546c6b85f6a2fd61f67da P d7ed4198a4d24c99a1423ad12aa55761 [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:20:23.848955  5236 tablet_server.cc:196] TabletServer@127.5.29.1:0 shutdown complete.
I20260812 06:20:23.891458  5236 master.cc:562] Master@127.5.29.62:41865 shutting down...
I20260812 06:20:23.895283  5236 raft_consensus.cc:2243] T 00000000000000000000000000000000 P 546fe77726b54eaea9ac58cf30fa34b8 [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:20:23.895498  5236 raft_consensus.cc:2272] T 00000000000000000000000000000000 P 546fe77726b54eaea9ac58cf30fa34b8 [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:20:23.895592  5236 tablet_replica.cc:333] T 00000000000000000000000000000000 P 546fe77726b54eaea9ac58cf30fa34b8: stopping tablet replica
I20260812 06:20:23.908007  5236 master.cc:584] Master@127.5.29.62:41865 shutdown complete.
[       OK ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/1 (5411 ms)
[----------] 2 tests from EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy (10825 ms total)

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