[==========] Running 2 tests from 1 test suite.
[----------] Global test environment set-up.
[----------] 2 tests from EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy
[ RUN      ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/0
WARNING: Logging before InitGoogleLogging() is written to STDERR
I20260812 06:18:34.810678 24103 internal_mini_cluster.cc:156] Creating distributed mini masters. Addrs: 127.23.137.254:43951
I20260812 06:18:34.811672 24103 env_posix.cc:2285] Not raising this process' open files per process limit of 1048576; it is already as high as it can go
I20260812 06:18:34.812258 24103 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:18:34.818838 24111 instance_detector.cc:116] could not retrieve Azure instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:18:34.818938 24109 instance_detector.cc:116] could not retrieve AWS instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:18:34.819027 24103 server_base.cc:1061] running on GCE node
W20260812 06:18:34.819276 24114 instance_detector.cc:116] could not retrieve OpenStack instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:18:34.819818 24103 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:18:34.819932 24103 system_unsync_time.cc:38] NTP support is disabled. Clock error bounds will not be accurate. This configuration is not suitable for distributed clusters.
I20260812 06:18:34.820001 24103 hybrid_clock.cc:648] HybridClock initialized: now 1786515514819998 us; error 0 us; skew 500 ppm
I20260812 06:18:34.821841 24103 webserver.cc:533] Webserver started at http://127.23.137.254:40407/ using document root <none> and password file <none>
I20260812 06:18:34.822440 24103 fs_manager.cc:362] Metadata directory not provided
I20260812 06:18:34.822530 24103 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:18:34.822794 24103 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:18:34.824445 24103 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-task2jzYy2/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515514800191-24103-0/minicluster-data/master-0-root/instance:
uuid: "2b9143061bc54f6abc44fe2ba197a89e"
format_stamp: "Formatted at 2026-08-12 06:18:34 on dist-test-slave-jztv"
I20260812 06:18:34.827965 24103 fs_manager.cc:696] Time spent creating directory manager: real 0.003s	user 0.005s	sys 0.000s
I20260812 06:18:34.830009 24122 log_block_manager.cc:4127] Time spent loading block containers with low live blocks: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:18:34.831000 24103 fs_manager.cc:730] Time spent opening block manager: real 0.002s	user 0.002s	sys 0.000s
I20260812 06:18:34.831149 24103 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-task2jzYy2/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515514800191-24103-0/minicluster-data/master-0-root
uuid: "2b9143061bc54f6abc44fe2ba197a89e"
format_stamp: "Formatted at 2026-08-12 06:18:34 on dist-test-slave-jztv"
I20260812 06:18:34.831246 24103 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-task2jzYy2/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515514800191-24103-0/minicluster-data/master-0-root
metadata directory: /tmp/dist-test-task2jzYy2/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515514800191-24103-0/minicluster-data/master-0-root
1 data directories: /tmp/dist-test-task2jzYy2/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515514800191-24103-0/minicluster-data/master-0-root/data
Total live blocks: 0
Total live bytes: 0
Total live bytes (after alignment): 0
Total number of LBM containers: 0 (0 full)
Did not check for missing blocks
Did not check for orphaned blocks
Total full LBM containers with extra space: 0 (0 repaired)
Total full LBM container extra space in bytes: 0 (0 repaired)
Total incomplete LBM containers: 0 (0 repaired)
Total LBM partial records: 0 (0 repaired)
Total corrupted LBM metadata records in RocksDB: 0 (0 repaired)
I20260812 06:18:34.858489 24103 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:18:34.859160 24103 env_posix.cc:2285] Not raising this process' running threads per effective uid limit of 18446744073709551615; it is already as high as it can go
I20260812 06:18:34.859360 24103 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:18:34.867304 24103 rpc_server.cc:307] RPC server started. Bound to: 127.23.137.254:43951
I20260812 06:18:34.867313 24201 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.23.137.254:43951 every 8 connection(s)
I20260812 06:18:34.869714 24203 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet 00000000000000000000000000000000. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:18:34.875945 24203 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P 2b9143061bc54f6abc44fe2ba197a89e: Bootstrap starting.
I20260812 06:18:34.878489 24203 tablet_bootstrap.cc:654] T 00000000000000000000000000000000 P 2b9143061bc54f6abc44fe2ba197a89e: Neither blocks nor log segments found. Creating new log.
I20260812 06:18:34.879462 24203 log.cc:826] T 00000000000000000000000000000000 P 2b9143061bc54f6abc44fe2ba197a89e: Log is configured to *not* fsync() on all Append() calls
I20260812 06:18:34.881237 24203 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P 2b9143061bc54f6abc44fe2ba197a89e: No bootstrap required, opened a new log
I20260812 06:18:34.884147 24203 raft_consensus.cc:359] T 00000000000000000000000000000000 P 2b9143061bc54f6abc44fe2ba197a89e [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "2b9143061bc54f6abc44fe2ba197a89e" member_type: VOTER }
I20260812 06:18:34.884307 24203 raft_consensus.cc:385] T 00000000000000000000000000000000 P 2b9143061bc54f6abc44fe2ba197a89e [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:18:34.884383 24203 raft_consensus.cc:740] T 00000000000000000000000000000000 P 2b9143061bc54f6abc44fe2ba197a89e [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: 2b9143061bc54f6abc44fe2ba197a89e, State: Initialized, Role: FOLLOWER
I20260812 06:18:34.884990 24203 consensus_queue.cc:260] T 00000000000000000000000000000000 P 2b9143061bc54f6abc44fe2ba197a89e [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: "2b9143061bc54f6abc44fe2ba197a89e" member_type: VOTER }
I20260812 06:18:34.885164 24203 raft_consensus.cc:399] T 00000000000000000000000000000000 P 2b9143061bc54f6abc44fe2ba197a89e [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:18:34.885241 24203 raft_consensus.cc:493] T 00000000000000000000000000000000 P 2b9143061bc54f6abc44fe2ba197a89e [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:18:34.885403 24203 raft_consensus.cc:3060] T 00000000000000000000000000000000 P 2b9143061bc54f6abc44fe2ba197a89e [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:18:34.886237 24203 raft_consensus.cc:515] T 00000000000000000000000000000000 P 2b9143061bc54f6abc44fe2ba197a89e [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "2b9143061bc54f6abc44fe2ba197a89e" member_type: VOTER }
I20260812 06:18:34.886677 24203 leader_election.cc:304] T 00000000000000000000000000000000 P 2b9143061bc54f6abc44fe2ba197a89e [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: 2b9143061bc54f6abc44fe2ba197a89e; no voters: 
I20260812 06:18:34.886996 24203 leader_election.cc:290] T 00000000000000000000000000000000 P 2b9143061bc54f6abc44fe2ba197a89e [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:18:34.887174 24207 raft_consensus.cc:2804] T 00000000000000000000000000000000 P 2b9143061bc54f6abc44fe2ba197a89e [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:18:34.887466 24207 raft_consensus.cc:697] T 00000000000000000000000000000000 P 2b9143061bc54f6abc44fe2ba197a89e [term 1 LEADER]: Becoming Leader. State: Replica: 2b9143061bc54f6abc44fe2ba197a89e, State: Running, Role: LEADER
I20260812 06:18:34.887920 24207 consensus_queue.cc:237] T 00000000000000000000000000000000 P 2b9143061bc54f6abc44fe2ba197a89e [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: "2b9143061bc54f6abc44fe2ba197a89e" member_type: VOTER }
I20260812 06:18:34.888046 24203 sys_catalog.cc:565] T 00000000000000000000000000000000 P 2b9143061bc54f6abc44fe2ba197a89e [sys.catalog]: configured and running, proceeding with master startup.
I20260812 06:18:34.889999 24209 sys_catalog.cc:455] T 00000000000000000000000000000000 P 2b9143061bc54f6abc44fe2ba197a89e [sys.catalog]: SysCatalogTable state changed. Reason: New leader 2b9143061bc54f6abc44fe2ba197a89e. Latest consensus state: current_term: 1 leader_uuid: "2b9143061bc54f6abc44fe2ba197a89e" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "2b9143061bc54f6abc44fe2ba197a89e" member_type: VOTER } }
I20260812 06:18:34.890123 24209 sys_catalog.cc:458] T 00000000000000000000000000000000 P 2b9143061bc54f6abc44fe2ba197a89e [sys.catalog]: This master's current role is: LEADER
I20260812 06:18:34.890343 24103 internal_mini_cluster.cc:184] Waiting to initialize catalog manager on master 0
I20260812 06:18:34.890394 24208 sys_catalog.cc:455] T 00000000000000000000000000000000 P 2b9143061bc54f6abc44fe2ba197a89e [sys.catalog]: SysCatalogTable state changed. Reason: RaftConsensus started. Latest consensus state: current_term: 1 leader_uuid: "2b9143061bc54f6abc44fe2ba197a89e" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "2b9143061bc54f6abc44fe2ba197a89e" member_type: VOTER } }
I20260812 06:18:34.890470 24208 sys_catalog.cc:458] T 00000000000000000000000000000000 P 2b9143061bc54f6abc44fe2ba197a89e [sys.catalog]: This master's current role is: LEADER
W20260812 06:18:34.892246 24225 catalog_manager.cc:1594] T 00000000000000000000000000000000 P 2b9143061bc54f6abc44fe2ba197a89e: loading cluster ID for follower catalog manager: Not found: cluster ID entry not found
W20260812 06:18:34.892338 24225 catalog_manager.cc:883] Not found: cluster ID entry not found: failed to prepare follower catalog manager, will retry
I20260812 06:18:34.892414 24232 catalog_manager.cc:1511] Loading table and tablet metadata into memory...
I20260812 06:18:34.893112 24232 catalog_manager.cc:1520] Initializing Kudu cluster ID...
I20260812 06:18:34.897307 24232 catalog_manager.cc:1383] Generated new cluster ID: cbc78a6a734e49569bbe67e26ed8fab9
I20260812 06:18:34.897379 24232 catalog_manager.cc:1531] Initializing Kudu internal certificate authority...
I20260812 06:18:34.911247 24232 catalog_manager.cc:1406] Generated new certificate authority record
I20260812 06:18:34.912374 24232 catalog_manager.cc:1540] Loading token signing keys...
I20260812 06:18:34.922271 24232 catalog_manager.cc:6092] T 00000000000000000000000000000000 P 2b9143061bc54f6abc44fe2ba197a89e: Generated new TSK 0
I20260812 06:18:34.922967 24232 catalog_manager.cc:1550] Initializing in-progress tserver states...
I20260812 06:18:34.955303 24103 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:18:34.958521 24237 instance_detector.cc:116] could not retrieve Azure instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:18:34.958559 24236 instance_detector.cc:116] could not retrieve AWS instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:18:34.958709 24103 server_base.cc:1061] running on GCE node
W20260812 06:18:34.958612 24239 instance_detector.cc:116] could not retrieve OpenStack instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:18:34.959071 24103 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:18:34.959156 24103 system_unsync_time.cc:38] NTP support is disabled. Clock error bounds will not be accurate. This configuration is not suitable for distributed clusters.
I20260812 06:18:34.959199 24103 hybrid_clock.cc:648] HybridClock initialized: now 1786515514959198 us; error 0 us; skew 500 ppm
I20260812 06:18:34.960220 24103 webserver.cc:533] Webserver started at http://127.23.137.193:35673/ using document root <none> and password file <none>
I20260812 06:18:34.960427 24103 fs_manager.cc:362] Metadata directory not provided
I20260812 06:18:34.960505 24103 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:18:34.960602 24103 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:18:34.961030 24103 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-task2jzYy2/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515514800191-24103-0/minicluster-data/ts-0-root/instance:
uuid: "8dde46a745ca44f98b0568ba917a78e1"
format_stamp: "Formatted at 2026-08-12 06:18:34 on dist-test-slave-jztv"
I20260812 06:18:34.962707 24103 fs_manager.cc:696] Time spent creating directory manager: real 0.001s	user 0.002s	sys 0.000s
I20260812 06:18:34.963775 24247 log_block_manager.cc:4127] Time spent loading block containers with low live blocks: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:18:34.964020 24103 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.001s	sys 0.000s
I20260812 06:18:34.964097 24103 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-task2jzYy2/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515514800191-24103-0/minicluster-data/ts-0-root
uuid: "8dde46a745ca44f98b0568ba917a78e1"
format_stamp: "Formatted at 2026-08-12 06:18:34 on dist-test-slave-jztv"
I20260812 06:18:34.964191 24103 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-task2jzYy2/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515514800191-24103-0/minicluster-data/ts-0-root
metadata directory: /tmp/dist-test-task2jzYy2/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515514800191-24103-0/minicluster-data/ts-0-root
1 data directories: /tmp/dist-test-task2jzYy2/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515514800191-24103-0/minicluster-data/ts-0-root/data
Total live blocks: 0
Total live bytes: 0
Total live bytes (after alignment): 0
Total number of LBM containers: 0 (0 full)
Did not check for missing blocks
Did not check for orphaned blocks
Total full LBM containers with extra space: 0 (0 repaired)
Total full LBM container extra space in bytes: 0 (0 repaired)
Total incomplete LBM containers: 0 (0 repaired)
Total LBM partial records: 0 (0 repaired)
Total corrupted LBM metadata records in RocksDB: 0 (0 repaired)
I20260812 06:18:34.977701 24103 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:18:34.978307 24103 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:18:34.978832 24103 txn_system_client.cc:432] TxnSystemClient initialization is disabled...
I20260812 06:18:34.979734 24103 ts_tablet_manager.cc:585] Loaded tablet metadata (0 total tablets, 0 live tablets)
I20260812 06:18:34.979785 24103 ts_tablet_manager.cc:531] Time spent load tablet metadata: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:18:34.979848 24103 ts_tablet_manager.cc:616] Registered 0 tablets
I20260812 06:18:34.979889 24103 ts_tablet_manager.cc:595] Time spent register tablets: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:18:34.986946 24103 rpc_server.cc:307] RPC server started. Bound to: 127.23.137.193:46143
I20260812 06:18:34.986964 24347 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.23.137.193:46143 every 8 connection(s)
I20260812 06:18:34.999980 24348 heartbeater.cc:344] Connected to a master server at 127.23.137.254:43951
I20260812 06:18:35.000249 24348 heartbeater.cc:461] Registering TS with master...
I20260812 06:18:35.000679 24348 heartbeater.cc:507] Master 127.23.137.254:43951 requested a full tablet report, sending...
I20260812 06:18:35.002066 24145 ts_manager.cc:194] Registered new tserver with Master: 8dde46a745ca44f98b0568ba917a78e1 (127.23.137.193:46143)
I20260812 06:18:35.002207 24103 internal_mini_cluster.cc:371] 1 TS(s) registered with all masters after 0.014597204s
I20260812 06:18:35.003569 24145 master_service.cc:502] Signed X509 certificate for tserver {username='slave'} at 127.0.0.1:40530
I20260812 06:18:35.011981 24145 catalog_manager.cc:2283] Servicing CreateTable request from {username='slave'} at 127.0.0.1:40540:
name: "heavy-update-compaction-test"
schema {
  columns {
    name: "key"
    type: INT64
    is_key: true
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_a"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_b"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_c"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_d"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_e"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
}
num_replicas: 1
split_rows_range_bounds {
}
partition_schema {
  range_schema {
  }
}
I20260812 06:18:35.026786 24295 tablet_service.cc:1511] Processing CreateTablet for tablet 8b4e9da050794fc39cb361f0016d3485 (DEFAULT_TABLE table=heavy-update-compaction-test [id=42c7c465796d41f485a8e41f6ad4b7c6]), partition=
I20260812 06:18:35.027278 24295 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet 8b4e9da050794fc39cb361f0016d3485. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:18:35.029888 24366 tablet_bootstrap.cc:492] T 8b4e9da050794fc39cb361f0016d3485 P 8dde46a745ca44f98b0568ba917a78e1: Bootstrap starting.
I20260812 06:18:35.031034 24366 tablet_bootstrap.cc:654] T 8b4e9da050794fc39cb361f0016d3485 P 8dde46a745ca44f98b0568ba917a78e1: Neither blocks nor log segments found. Creating new log.
I20260812 06:18:35.032153 24366 tablet_bootstrap.cc:492] T 8b4e9da050794fc39cb361f0016d3485 P 8dde46a745ca44f98b0568ba917a78e1: No bootstrap required, opened a new log
I20260812 06:18:35.032239 24366 ts_tablet_manager.cc:1403] T 8b4e9da050794fc39cb361f0016d3485 P 8dde46a745ca44f98b0568ba917a78e1: Time spent bootstrapping tablet: real 0.002s	user 0.002s	sys 0.000s
I20260812 06:18:35.032903 24366 raft_consensus.cc:359] T 8b4e9da050794fc39cb361f0016d3485 P 8dde46a745ca44f98b0568ba917a78e1 [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "8dde46a745ca44f98b0568ba917a78e1" member_type: VOTER last_known_addr { host: "127.23.137.193" port: 46143 } }
I20260812 06:18:35.033004 24366 raft_consensus.cc:385] T 8b4e9da050794fc39cb361f0016d3485 P 8dde46a745ca44f98b0568ba917a78e1 [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:18:35.033037 24366 raft_consensus.cc:740] T 8b4e9da050794fc39cb361f0016d3485 P 8dde46a745ca44f98b0568ba917a78e1 [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: 8dde46a745ca44f98b0568ba917a78e1, State: Initialized, Role: FOLLOWER
I20260812 06:18:35.033228 24366 consensus_queue.cc:260] T 8b4e9da050794fc39cb361f0016d3485 P 8dde46a745ca44f98b0568ba917a78e1 [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: "8dde46a745ca44f98b0568ba917a78e1" member_type: VOTER last_known_addr { host: "127.23.137.193" port: 46143 } }
I20260812 06:18:35.033308 24366 raft_consensus.cc:399] T 8b4e9da050794fc39cb361f0016d3485 P 8dde46a745ca44f98b0568ba917a78e1 [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:18:35.033354 24366 raft_consensus.cc:493] T 8b4e9da050794fc39cb361f0016d3485 P 8dde46a745ca44f98b0568ba917a78e1 [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:18:35.033416 24366 raft_consensus.cc:3060] T 8b4e9da050794fc39cb361f0016d3485 P 8dde46a745ca44f98b0568ba917a78e1 [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:18:35.034482 24366 raft_consensus.cc:515] T 8b4e9da050794fc39cb361f0016d3485 P 8dde46a745ca44f98b0568ba917a78e1 [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "8dde46a745ca44f98b0568ba917a78e1" member_type: VOTER last_known_addr { host: "127.23.137.193" port: 46143 } }
I20260812 06:18:35.034642 24366 leader_election.cc:304] T 8b4e9da050794fc39cb361f0016d3485 P 8dde46a745ca44f98b0568ba917a78e1 [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: 8dde46a745ca44f98b0568ba917a78e1; no voters: 
I20260812 06:18:35.034889 24366 leader_election.cc:290] T 8b4e9da050794fc39cb361f0016d3485 P 8dde46a745ca44f98b0568ba917a78e1 [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:18:35.034986 24369 raft_consensus.cc:2804] T 8b4e9da050794fc39cb361f0016d3485 P 8dde46a745ca44f98b0568ba917a78e1 [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:18:35.035241 24366 ts_tablet_manager.cc:1434] T 8b4e9da050794fc39cb361f0016d3485 P 8dde46a745ca44f98b0568ba917a78e1: Time spent starting tablet: real 0.003s	user 0.003s	sys 0.000s
I20260812 06:18:35.035163 24369 raft_consensus.cc:697] T 8b4e9da050794fc39cb361f0016d3485 P 8dde46a745ca44f98b0568ba917a78e1 [term 1 LEADER]: Becoming Leader. State: Replica: 8dde46a745ca44f98b0568ba917a78e1, State: Running, Role: LEADER
I20260812 06:18:35.035652 24369 consensus_queue.cc:237] T 8b4e9da050794fc39cb361f0016d3485 P 8dde46a745ca44f98b0568ba917a78e1 [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: "8dde46a745ca44f98b0568ba917a78e1" member_type: VOTER last_known_addr { host: "127.23.137.193" port: 46143 } }
I20260812 06:18:35.035712 24348 heartbeater.cc:499] Master 127.23.137.254:43951 was elected leader, sending a full tablet report...
I20260812 06:18:35.038535 24145 catalog_manager.cc:5719] T 8b4e9da050794fc39cb361f0016d3485 P 8dde46a745ca44f98b0568ba917a78e1 reported cstate change: term changed from 0 to 1, leader changed from <none> to 8dde46a745ca44f98b0568ba917a78e1 (127.23.137.193). New cstate: current_term: 1 leader_uuid: "8dde46a745ca44f98b0568ba917a78e1" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "8dde46a745ca44f98b0568ba917a78e1" member_type: VOTER last_known_addr { host: "127.23.137.193" port: 46143 } health_report { overall_health: HEALTHY } } }
I20260812 06:18:35.100852 24103 heavy-update-compaction-itest.cc:215] Time spent inserting: real 0.054s	user 0.014s	sys 0.011s
I20260812 06:18:35.238118 24350 maintenance_manager.cc:419] P 8dde46a745ca44f98b0568ba917a78e1: Scheduling FlushMRSOp(8b4e9da050794fc39cb361f0016d3485): perf score=19.054940
I20260812 06:18:35.409886 24257 maintenance_manager.cc:643] P 8dde46a745ca44f98b0568ba917a78e1: FlushMRSOp(8b4e9da050794fc39cb361f0016d3485) complete. Timing: real 0.171s	user 0.126s	sys 0.041s Metrics: {"bytes_written":12717735,"cfile_init":1,"compiler_manager_pool.queue_time_us":228,"delete_count":0,"dirs.queue_time_us":74,"dirs.run_cpu_time_us":194,"dirs.run_wall_time_us":815,"drs_written":1,"lbm_read_time_us":53,"lbm_reads_lt_1ms":4,"lbm_write_time_us":40652,"lbm_writes_lt_1ms":767,"peak_mem_usage":0,"reinsert_count":0,"rows_written":104,"spinlock_wait_cycles":165248,"thread_start_us":157,"threads_started":1,"update_count":1550}
I20260812 06:18:35.411226 24350 maintenance_manager.cc:419] P 8dde46a745ca44f98b0568ba917a78e1: Scheduling LogGCOp(8b4e9da050794fc39cb361f0016d3485): free 20743880 bytes of WAL
I20260812 06:18:35.411553 24257 log_reader.cc:385] T 8b4e9da050794fc39cb361f0016d3485: removed 2 log segments from log reader
I20260812 06:18:35.411628 24257 log.cc:1079] T 8b4e9da050794fc39cb361f0016d3485 P 8dde46a745ca44f98b0568ba917a78e1: Deleting log segment in path: /tmp/dist-test-task2jzYy2/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515514800191-24103-0/minicluster-data/ts-0-root/wals/8b4e9da050794fc39cb361f0016d3485/wal-000000001 (ops 1-6)
I20260812 06:18:35.411684 24257 log.cc:1079] T 8b4e9da050794fc39cb361f0016d3485 P 8dde46a745ca44f98b0568ba917a78e1: Deleting log segment in path: /tmp/dist-test-task2jzYy2/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515514800191-24103-0/minicluster-data/ts-0-root/wals/8b4e9da050794fc39cb361f0016d3485/wal-000000002 (ops 7-11)
I20260812 06:18:35.417217 24257 maintenance_manager.cc:643] P 8dde46a745ca44f98b0568ba917a78e1: LogGCOp(8b4e9da050794fc39cb361f0016d3485) complete. Timing: real 0.006s	user 0.000s	sys 0.003s Metrics: {}
I20260812 06:18:35.417726 24350 maintenance_manager.cc:419] P 8dde46a745ca44f98b0568ba917a78e1: Scheduling UndoDeltaBlockGCOp(8b4e9da050794fc39cb361f0016d3485): 16411392 bytes on disk
I20260812 06:18:35.418457 24257 maintenance_manager.cc:643] P 8dde46a745ca44f98b0568ba917a78e1: UndoDeltaBlockGCOp(8b4e9da050794fc39cb361f0016d3485) complete. Timing: real 0.001s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":97,"lbm_reads_lt_1ms":4}
I20260812 06:18:35.418903 24350 maintenance_manager.cc:419] P 8dde46a745ca44f98b0568ba917a78e1: Scheduling FlushDeltaMemStoresOp(8b4e9da050794fc39cb361f0016d3485): perf score=2.188937
I20260812 06:18:35.453197 24257 maintenance_manager.cc:643] P 8dde46a745ca44f98b0568ba917a78e1: FlushDeltaMemStoresOp(8b4e9da050794fc39cb361f0016d3485) complete. Timing: real 0.034s	user 0.008s	sys 0.010s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":5203,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:18:35.453779 24350 maintenance_manager.cc:419] P 8dde46a745ca44f98b0568ba917a78e1: Scheduling FlushDeltaMemStoresOp(8b4e9da050794fc39cb361f0016d3485): perf score=2.188937
I20260812 06:18:35.465173 24257 maintenance_manager.cc:643] P 8dde46a745ca44f98b0568ba917a78e1: FlushDeltaMemStoresOp(8b4e9da050794fc39cb361f0016d3485) complete. Timing: real 0.011s	user 0.006s	sys 0.003s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4580,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:35.465721 24350 maintenance_manager.cc:419] P 8dde46a745ca44f98b0568ba917a78e1: Scheduling MajorDeltaCompactionOp(8b4e9da050794fc39cb361f0016d3485): perf score=1.000000
I20260812 06:18:35.630321 24257 maintenance_manager.cc:643] P 8dde46a745ca44f98b0568ba917a78e1: MajorDeltaCompactionOp(8b4e9da050794fc39cb361f0016d3485) complete. Timing: real 0.164s	user 0.112s	sys 0.052s Metrics: {"cfile_cache_miss":533,"cfile_cache_miss_bytes":24774799,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":667,"lbm_read_time_us":10276,"lbm_reads_lt_1ms":569,"lbm_write_time_us":28101,"lbm_writes_lt_1ms":543,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":896,"thread_start_us":356,"threads_started":5,"update_count":2500}
I20260812 06:18:35.630978 24350 maintenance_manager.cc:419] P 8dde46a745ca44f98b0568ba917a78e1: Scheduling FlushDeltaMemStoresOp(8b4e9da050794fc39cb361f0016d3485): perf score=10.126437
I20260812 06:18:35.662904 24257 maintenance_manager.cc:643] P 8dde46a745ca44f98b0568ba917a78e1: FlushDeltaMemStoresOp(8b4e9da050794fc39cb361f0016d3485) complete. Timing: real 0.032s	user 0.024s	sys 0.007s Metrics: {"bytes_written":12307492,"delete_count":0,"lbm_write_time_us":13882,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:18:35.663316 24350 maintenance_manager.cc:419] P 8dde46a745ca44f98b0568ba917a78e1: Scheduling FlushDeltaMemStoresOp(8b4e9da050794fc39cb361f0016d3485): perf score=2.188937
I20260812 06:18:35.673269 24257 maintenance_manager.cc:643] P 8dde46a745ca44f98b0568ba917a78e1: FlushDeltaMemStoresOp(8b4e9da050794fc39cb361f0016d3485) complete. Timing: real 0.010s	user 0.008s	sys 0.000s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":3827,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:35.673776 24350 maintenance_manager.cc:419] P 8dde46a745ca44f98b0568ba917a78e1: Scheduling MajorDeltaCompactionOp(8b4e9da050794fc39cb361f0016d3485): perf score=1.000000
I20260812 06:18:35.795480 24257 maintenance_manager.cc:643] P 8dde46a745ca44f98b0568ba917a78e1: MajorDeltaCompactionOp(8b4e9da050794fc39cb361f0016d3485) complete. Timing: real 0.121s	user 0.103s	sys 0.018s 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":237,"lbm_read_time_us":8234,"lbm_reads_lt_1ms":472,"lbm_write_time_us":21956,"lbm_writes_lt_1ms":443,"mutex_wait_us":27,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":9856,"update_count":2000}
I20260812 06:18:35.796082 24350 maintenance_manager.cc:419] P 8dde46a745ca44f98b0568ba917a78e1: Scheduling FlushDeltaMemStoresOp(8b4e9da050794fc39cb361f0016d3485): perf score=10.126437
I20260812 06:18:35.835434 24257 maintenance_manager.cc:643] P 8dde46a745ca44f98b0568ba917a78e1: FlushDeltaMemStoresOp(8b4e9da050794fc39cb361f0016d3485) complete. Timing: real 0.039s	user 0.022s	sys 0.010s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":14183,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:18:35.835979 24350 maintenance_manager.cc:419] P 8dde46a745ca44f98b0568ba917a78e1: Scheduling FlushDeltaMemStoresOp(8b4e9da050794fc39cb361f0016d3485): perf score=2.188937
I20260812 06:18:35.851233 24257 maintenance_manager.cc:643] P 8dde46a745ca44f98b0568ba917a78e1: FlushDeltaMemStoresOp(8b4e9da050794fc39cb361f0016d3485) complete. Timing: real 0.015s	user 0.014s	sys 0.000s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":5602,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:35.851788 24350 maintenance_manager.cc:419] P 8dde46a745ca44f98b0568ba917a78e1: Scheduling MajorDeltaCompactionOp(8b4e9da050794fc39cb361f0016d3485): perf score=1.000000
I20260812 06:18:35.997177 24257 maintenance_manager.cc:643] P 8dde46a745ca44f98b0568ba917a78e1: MajorDeltaCompactionOp(8b4e9da050794fc39cb361f0016d3485) complete. Timing: real 0.145s	user 0.109s	sys 0.032s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672276,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":1648,"lbm_read_time_us":9103,"lbm_reads_lt_1ms":472,"lbm_write_time_us":26924,"lbm_writes_lt_1ms":443,"mutex_wait_us":22,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":1664,"update_count":2000}
I20260812 06:18:35.997836 24350 maintenance_manager.cc:419] P 8dde46a745ca44f98b0568ba917a78e1: Scheduling FlushDeltaMemStoresOp(8b4e9da050794fc39cb361f0016d3485): perf score=10.126437
I20260812 06:18:36.045707 24257 maintenance_manager.cc:643] P 8dde46a745ca44f98b0568ba917a78e1: FlushDeltaMemStoresOp(8b4e9da050794fc39cb361f0016d3485) complete. Timing: real 0.047s	user 0.026s	sys 0.007s Metrics: {"bytes_written":12307489,"delete_count":0,"lbm_write_time_us":16200,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:18:36.046144 24350 maintenance_manager.cc:419] P 8dde46a745ca44f98b0568ba917a78e1: Scheduling FlushDeltaMemStoresOp(8b4e9da050794fc39cb361f0016d3485): perf score=2.188937
I20260812 06:18:36.060822 24257 maintenance_manager.cc:643] P 8dde46a745ca44f98b0568ba917a78e1: FlushDeltaMemStoresOp(8b4e9da050794fc39cb361f0016d3485) complete. Timing: real 0.014s	user 0.008s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5474,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:36.061395 24350 maintenance_manager.cc:419] P 8dde46a745ca44f98b0568ba917a78e1: Scheduling MajorDeltaCompactionOp(8b4e9da050794fc39cb361f0016d3485): perf score=1.000000
I20260812 06:18:36.174746 24257 maintenance_manager.cc:643] P 8dde46a745ca44f98b0568ba917a78e1: MajorDeltaCompactionOp(8b4e9da050794fc39cb361f0016d3485) complete. Timing: real 0.113s	user 0.107s	sys 0.006s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672276,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":623,"lbm_read_time_us":8267,"lbm_reads_lt_1ms":472,"lbm_write_time_us":21683,"lbm_writes_lt_1ms":443,"mutex_wait_us":57,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":896,"update_count":2000}
I20260812 06:18:36.175457 24350 maintenance_manager.cc:419] P 8dde46a745ca44f98b0568ba917a78e1: Scheduling FlushDeltaMemStoresOp(8b4e9da050794fc39cb361f0016d3485): perf score=10.126437
I20260812 06:18:36.222010 24257 maintenance_manager.cc:643] P 8dde46a745ca44f98b0568ba917a78e1: FlushDeltaMemStoresOp(8b4e9da050794fc39cb361f0016d3485) complete. Timing: real 0.046s	user 0.024s	sys 0.016s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":14801,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:18:36.222635 24350 maintenance_manager.cc:419] P 8dde46a745ca44f98b0568ba917a78e1: Scheduling FlushDeltaMemStoresOp(8b4e9da050794fc39cb361f0016d3485): perf score=2.188937
I20260812 06:18:36.239187 24257 maintenance_manager.cc:643] P 8dde46a745ca44f98b0568ba917a78e1: FlushDeltaMemStoresOp(8b4e9da050794fc39cb361f0016d3485) complete. Timing: real 0.016s	user 0.015s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6192,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:36.239815 24350 maintenance_manager.cc:419] P 8dde46a745ca44f98b0568ba917a78e1: Scheduling MajorDeltaCompactionOp(8b4e9da050794fc39cb361f0016d3485): perf score=1.000000
I20260812 06:18:36.391057 24257 maintenance_manager.cc:643] P 8dde46a745ca44f98b0568ba917a78e1: MajorDeltaCompactionOp(8b4e9da050794fc39cb361f0016d3485) complete. Timing: real 0.151s	user 0.107s	sys 0.040s 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":558,"lbm_read_time_us":9956,"lbm_reads_lt_1ms":472,"lbm_write_time_us":26764,"lbm_writes_lt_1ms":443,"mutex_wait_us":25,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":8576,"update_count":2000}
I20260812 06:18:36.391697 24350 maintenance_manager.cc:419] P 8dde46a745ca44f98b0568ba917a78e1: Scheduling FlushDeltaMemStoresOp(8b4e9da050794fc39cb361f0016d3485): perf score=10.126437
I20260812 06:18:36.439169 24257 maintenance_manager.cc:643] P 8dde46a745ca44f98b0568ba917a78e1: FlushDeltaMemStoresOp(8b4e9da050794fc39cb361f0016d3485) complete. Timing: real 0.047s	user 0.019s	sys 0.017s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":16198,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":302,"reinsert_count":0,"update_count":1500}
I20260812 06:18:36.439747 24350 maintenance_manager.cc:419] P 8dde46a745ca44f98b0568ba917a78e1: Scheduling FlushDeltaMemStoresOp(8b4e9da050794fc39cb361f0016d3485): perf score=2.188937
I20260812 06:18:36.455065 24257 maintenance_manager.cc:643] P 8dde46a745ca44f98b0568ba917a78e1: FlushDeltaMemStoresOp(8b4e9da050794fc39cb361f0016d3485) complete. Timing: real 0.015s	user 0.014s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5663,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:36.455665 24350 maintenance_manager.cc:419] P 8dde46a745ca44f98b0568ba917a78e1: Scheduling MajorDeltaCompactionOp(8b4e9da050794fc39cb361f0016d3485): perf score=1.000000
I20260812 06:18:36.583145 24257 maintenance_manager.cc:643] P 8dde46a745ca44f98b0568ba917a78e1: MajorDeltaCompactionOp(8b4e9da050794fc39cb361f0016d3485) complete. Timing: real 0.127s	user 0.111s	sys 0.016s 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":986,"lbm_read_time_us":9877,"lbm_reads_lt_1ms":472,"lbm_write_time_us":23843,"lbm_writes_lt_1ms":443,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":1280,"update_count":2000}
I20260812 06:18:36.583617 24350 maintenance_manager.cc:419] P 8dde46a745ca44f98b0568ba917a78e1: Scheduling FlushDeltaMemStoresOp(8b4e9da050794fc39cb361f0016d3485): perf score=10.126437
I20260812 06:18:36.630080 24257 maintenance_manager.cc:643] P 8dde46a745ca44f98b0568ba917a78e1: FlushDeltaMemStoresOp(8b4e9da050794fc39cb361f0016d3485) complete. Timing: real 0.046s	user 0.024s	sys 0.012s Metrics: {"bytes_written":12307492,"delete_count":0,"lbm_write_time_us":17151,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:18:36.630752 24350 maintenance_manager.cc:419] P 8dde46a745ca44f98b0568ba917a78e1: Scheduling FlushDeltaMemStoresOp(8b4e9da050794fc39cb361f0016d3485): perf score=2.188937
I20260812 06:18:36.642263 24257 maintenance_manager.cc:643] P 8dde46a745ca44f98b0568ba917a78e1: FlushDeltaMemStoresOp(8b4e9da050794fc39cb361f0016d3485) complete. Timing: real 0.011s	user 0.011s	sys 0.000s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4144,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:36.642797 24350 maintenance_manager.cc:419] P 8dde46a745ca44f98b0568ba917a78e1: Scheduling FlushMRSOp(8b4e9da050794fc39cb361f0016d3485): perf score=1.000000
I20260812 06:18:36.673200 24257 maintenance_manager.cc:643] P 8dde46a745ca44f98b0568ba917a78e1: FlushMRSOp(8b4e9da050794fc39cb361f0016d3485) complete. Timing: real 0.030s	user 0.029s	sys 0.000s Metrics: {"bytes_written":1193503,"cfile_init":1,"dirs.queue_time_us":42,"dirs.run_cpu_time_us":272,"dirs.run_wall_time_us":1582,"drs_written":1,"lbm_read_time_us":38,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1901,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":29,"spinlock_wait_cycles":896}
I20260812 06:18:36.673991 24350 maintenance_manager.cc:419] P 8dde46a745ca44f98b0568ba917a78e1: Scheduling LogGCOp(8b4e9da050794fc39cb361f0016d3485): free 112239308 bytes of WAL
I20260812 06:18:36.674292 24257 log_reader.cc:385] T 8b4e9da050794fc39cb361f0016d3485: removed 11 log segments from log reader
I20260812 06:18:36.674353 24257 log.cc:1079] T 8b4e9da050794fc39cb361f0016d3485 P 8dde46a745ca44f98b0568ba917a78e1: Deleting log segment in path: /tmp/dist-test-task2jzYy2/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515514800191-24103-0/minicluster-data/ts-0-root/wals/8b4e9da050794fc39cb361f0016d3485/wal-000000003 (ops 12-16)
I20260812 06:18:36.674407 24257 log.cc:1079] T 8b4e9da050794fc39cb361f0016d3485 P 8dde46a745ca44f98b0568ba917a78e1: Deleting log segment in path: /tmp/dist-test-task2jzYy2/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515514800191-24103-0/minicluster-data/ts-0-root/wals/8b4e9da050794fc39cb361f0016d3485/wal-000000004 (ops 17-20)
I20260812 06:18:36.674451 24257 log.cc:1079] T 8b4e9da050794fc39cb361f0016d3485 P 8dde46a745ca44f98b0568ba917a78e1: Deleting log segment in path: /tmp/dist-test-task2jzYy2/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515514800191-24103-0/minicluster-data/ts-0-root/wals/8b4e9da050794fc39cb361f0016d3485/wal-000000005 (ops 21-25)
I20260812 06:18:36.674479 24257 log.cc:1079] T 8b4e9da050794fc39cb361f0016d3485 P 8dde46a745ca44f98b0568ba917a78e1: Deleting log segment in path: /tmp/dist-test-task2jzYy2/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515514800191-24103-0/minicluster-data/ts-0-root/wals/8b4e9da050794fc39cb361f0016d3485/wal-000000006 (ops 26-30)
I20260812 06:18:36.674552 24257 log.cc:1079] T 8b4e9da050794fc39cb361f0016d3485 P 8dde46a745ca44f98b0568ba917a78e1: Deleting log segment in path: /tmp/dist-test-task2jzYy2/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515514800191-24103-0/minicluster-data/ts-0-root/wals/8b4e9da050794fc39cb361f0016d3485/wal-000000007 (ops 31-35)
I20260812 06:18:36.674588 24257 log.cc:1079] T 8b4e9da050794fc39cb361f0016d3485 P 8dde46a745ca44f98b0568ba917a78e1: Deleting log segment in path: /tmp/dist-test-task2jzYy2/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515514800191-24103-0/minicluster-data/ts-0-root/wals/8b4e9da050794fc39cb361f0016d3485/wal-000000008 (ops 36-40)
I20260812 06:18:36.674650 24257 log.cc:1079] T 8b4e9da050794fc39cb361f0016d3485 P 8dde46a745ca44f98b0568ba917a78e1: Deleting log segment in path: /tmp/dist-test-task2jzYy2/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515514800191-24103-0/minicluster-data/ts-0-root/wals/8b4e9da050794fc39cb361f0016d3485/wal-000000009 (ops 41-45)
I20260812 06:18:36.674686 24257 log.cc:1079] T 8b4e9da050794fc39cb361f0016d3485 P 8dde46a745ca44f98b0568ba917a78e1: Deleting log segment in path: /tmp/dist-test-task2jzYy2/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515514800191-24103-0/minicluster-data/ts-0-root/wals/8b4e9da050794fc39cb361f0016d3485/wal-000000010 (ops 46-50)
I20260812 06:18:36.674726 24257 log.cc:1079] T 8b4e9da050794fc39cb361f0016d3485 P 8dde46a745ca44f98b0568ba917a78e1: Deleting log segment in path: /tmp/dist-test-task2jzYy2/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515514800191-24103-0/minicluster-data/ts-0-root/wals/8b4e9da050794fc39cb361f0016d3485/wal-000000011 (ops 51-55)
I20260812 06:18:36.674764 24257 log.cc:1079] T 8b4e9da050794fc39cb361f0016d3485 P 8dde46a745ca44f98b0568ba917a78e1: Deleting log segment in path: /tmp/dist-test-task2jzYy2/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515514800191-24103-0/minicluster-data/ts-0-root/wals/8b4e9da050794fc39cb361f0016d3485/wal-000000012 (ops 56-60)
I20260812 06:18:36.674808 24257 log.cc:1079] T 8b4e9da050794fc39cb361f0016d3485 P 8dde46a745ca44f98b0568ba917a78e1: Deleting log segment in path: /tmp/dist-test-task2jzYy2/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515514800191-24103-0/minicluster-data/ts-0-root/wals/8b4e9da050794fc39cb361f0016d3485/wal-000000013 (ops 61-65)
I20260812 06:18:36.699185 24257 maintenance_manager.cc:643] P 8dde46a745ca44f98b0568ba917a78e1: LogGCOp(8b4e9da050794fc39cb361f0016d3485) complete. Timing: real 0.025s	user 0.001s	sys 0.023s Metrics: {}
I20260812 06:18:36.699592 24350 maintenance_manager.cc:419] P 8dde46a745ca44f98b0568ba917a78e1: Scheduling FlushDeltaMemStoresOp(8b4e9da050794fc39cb361f0016d3485): perf score=2.188937
I20260812 06:18:36.719797 24257 maintenance_manager.cc:643] P 8dde46a745ca44f98b0568ba917a78e1: FlushDeltaMemStoresOp(8b4e9da050794fc39cb361f0016d3485) complete. Timing: real 0.020s	user 0.010s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6202,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:36.720324 24350 maintenance_manager.cc:419] P 8dde46a745ca44f98b0568ba917a78e1: Scheduling LogGCOp(8b4e9da050794fc39cb361f0016d3485): free 12017932 bytes of WAL
I20260812 06:18:36.720566 24257 log_reader.cc:385] T 8b4e9da050794fc39cb361f0016d3485: removed 1 log segments from log reader
I20260812 06:18:36.720631 24257 log.cc:1079] T 8b4e9da050794fc39cb361f0016d3485 P 8dde46a745ca44f98b0568ba917a78e1: Deleting log segment in path: /tmp/dist-test-task2jzYy2/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515514800191-24103-0/minicluster-data/ts-0-root/wals/8b4e9da050794fc39cb361f0016d3485/wal-000000014 (ops 66-70)
I20260812 06:18:36.723114 24257 maintenance_manager.cc:643] P 8dde46a745ca44f98b0568ba917a78e1: LogGCOp(8b4e9da050794fc39cb361f0016d3485) complete. Timing: real 0.003s	user 0.000s	sys 0.002s Metrics: {}
I20260812 06:18:36.723456 24350 maintenance_manager.cc:419] P 8dde46a745ca44f98b0568ba917a78e1: Scheduling UndoDeltaBlockGCOp(8b4e9da050794fc39cb361f0016d3485): 463 bytes on disk
I20260812 06:18:36.723897 24257 maintenance_manager.cc:643] P 8dde46a745ca44f98b0568ba917a78e1: UndoDeltaBlockGCOp(8b4e9da050794fc39cb361f0016d3485) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":51,"lbm_reads_lt_1ms":4}
I20260812 06:18:36.724336 24350 maintenance_manager.cc:419] P 8dde46a745ca44f98b0568ba917a78e1: Scheduling FlushDeltaMemStoresOp(8b4e9da050794fc39cb361f0016d3485): perf score=2.188937
I20260812 06:18:36.735754 24257 maintenance_manager.cc:643] P 8dde46a745ca44f98b0568ba917a78e1: FlushDeltaMemStoresOp(8b4e9da050794fc39cb361f0016d3485) complete. Timing: real 0.011s	user 0.005s	sys 0.005s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4174,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:36.736269 24350 maintenance_manager.cc:419] P 8dde46a745ca44f98b0568ba917a78e1: Scheduling MajorDeltaCompactionOp(8b4e9da050794fc39cb361f0016d3485): perf score=1.000000
I20260812 06:18:36.902973 24257 maintenance_manager.cc:643] P 8dde46a745ca44f98b0568ba917a78e1: MajorDeltaCompactionOp(8b4e9da050794fc39cb361f0016d3485) complete. Timing: real 0.167s	user 0.127s	sys 0.040s Metrics: {"cfile_cache_miss":634,"cfile_cache_miss_bytes":28877340,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":532,"lbm_read_time_us":12414,"lbm_reads_lt_1ms":674,"lbm_write_time_us":31610,"lbm_writes_lt_1ms":643,"mutex_wait_us":264,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":9600,"thread_start_us":81,"threads_started":1,"update_count":3000}
I20260812 06:18:36.905787 24350 maintenance_manager.cc:419] P 8dde46a745ca44f98b0568ba917a78e1: Scheduling FlushDeltaMemStoresOp(8b4e9da050794fc39cb361f0016d3485): perf score=14.095187
I20260812 06:18:36.951493 24257 maintenance_manager.cc:643] P 8dde46a745ca44f98b0568ba917a78e1: FlushDeltaMemStoresOp(8b4e9da050794fc39cb361f0016d3485) complete. Timing: real 0.045s	user 0.017s	sys 0.027s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":20064,"lbm_writes_lt_1ms":403,"reinsert_count":0,"spinlock_wait_cycles":1280,"update_count":2000}
I20260812 06:18:36.952056 24350 maintenance_manager.cc:419] P 8dde46a745ca44f98b0568ba917a78e1: Scheduling FlushDeltaMemStoresOp(8b4e9da050794fc39cb361f0016d3485): perf score=2.188937
I20260812 06:18:36.967397 24257 maintenance_manager.cc:643] P 8dde46a745ca44f98b0568ba917a78e1: FlushDeltaMemStoresOp(8b4e9da050794fc39cb361f0016d3485) complete. Timing: real 0.015s	user 0.002s	sys 0.012s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5826,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:36.967993 24350 maintenance_manager.cc:419] P 8dde46a745ca44f98b0568ba917a78e1: Scheduling MajorDeltaCompactionOp(8b4e9da050794fc39cb361f0016d3485): perf score=1.000000
I20260812 06:18:37.130445 24257 maintenance_manager.cc:643] P 8dde46a745ca44f98b0568ba917a78e1: MajorDeltaCompactionOp(8b4e9da050794fc39cb361f0016d3485) complete. Timing: real 0.162s	user 0.110s	sys 0.044s 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":5607,"lbm_read_time_us":11540,"lbm_reads_lt_1ms":572,"lbm_write_time_us":28751,"lbm_writes_lt_1ms":543,"mutex_wait_us":4135,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":1664,"update_count":2500}
I20260812 06:18:37.131137 24350 maintenance_manager.cc:419] P 8dde46a745ca44f98b0568ba917a78e1: Scheduling FlushDeltaMemStoresOp(8b4e9da050794fc39cb361f0016d3485): perf score=13.103000
I20260812 06:18:37.177300 24257 maintenance_manager.cc:643] P 8dde46a745ca44f98b0568ba917a78e1: FlushDeltaMemStoresOp(8b4e9da050794fc39cb361f0016d3485) complete. Timing: real 0.046s	user 0.017s	sys 0.020s Metrics: {"bytes_written":14686886,"delete_count":0,"lbm_write_time_us":17902,"lbm_writes_lt_1ms":361,"reinsert_count":0,"update_count":1790}
I20260812 06:18:37.177785 24350 maintenance_manager.cc:419] P 8dde46a745ca44f98b0568ba917a78e1: Scheduling FlushDeltaMemStoresOp(8b4e9da050794fc39cb361f0016d3485): perf score=1.000000
I20260812 06:18:37.188102 24257 maintenance_manager.cc:643] P 8dde46a745ca44f98b0568ba917a78e1: FlushDeltaMemStoresOp(8b4e9da050794fc39cb361f0016d3485) complete. Timing: real 0.010s	user 0.005s	sys 0.000s Metrics: {"bytes_written":2133457,"delete_count":0,"lbm_write_time_us":2092,"lbm_writes_lt_1ms":55,"reinsert_count":0,"update_count":260}
I20260812 06:18:37.188498 24350 maintenance_manager.cc:419] P 8dde46a745ca44f98b0568ba917a78e1: Scheduling FlushDeltaMemStoresOp(8b4e9da050794fc39cb361f0016d3485): perf score=2.188937
I20260812 06:18:37.198009 24257 maintenance_manager.cc:643] P 8dde46a745ca44f98b0568ba917a78e1: FlushDeltaMemStoresOp(8b4e9da050794fc39cb361f0016d3485) complete. Timing: real 0.009s	user 0.004s	sys 0.004s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3668,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:18:37.198494 24350 maintenance_manager.cc:419] P 8dde46a745ca44f98b0568ba917a78e1: Scheduling MajorDeltaCompactionOp(8b4e9da050794fc39cb361f0016d3485): perf score=1.000000
I20260812 06:18:37.369807 24257 maintenance_manager.cc:643] P 8dde46a745ca44f98b0568ba917a78e1: MajorDeltaCompactionOp(8b4e9da050794fc39cb361f0016d3485) complete. Timing: real 0.171s	user 0.122s	sys 0.043s Metrics: {"cfile_cache_miss":533,"cfile_cache_miss_bytes":24774748,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":336,"lbm_read_time_us":11995,"lbm_reads_lt_1ms":573,"lbm_write_time_us":27776,"lbm_writes_lt_1ms":543,"mutex_wait_us":31,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":96000,"update_count":2500}
I20260812 06:18:37.370522 24350 maintenance_manager.cc:419] P 8dde46a745ca44f98b0568ba917a78e1: Scheduling FlushDeltaMemStoresOp(8b4e9da050794fc39cb361f0016d3485): perf score=14.095187
I20260812 06:18:37.428395 24257 maintenance_manager.cc:643] P 8dde46a745ca44f98b0568ba917a78e1: FlushDeltaMemStoresOp(8b4e9da050794fc39cb361f0016d3485) complete. Timing: real 0.058s	user 0.030s	sys 0.012s Metrics: {"bytes_written":16409903,"delete_count":0,"lbm_write_time_us":20114,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:18:37.428925 24350 maintenance_manager.cc:419] P 8dde46a745ca44f98b0568ba917a78e1: Scheduling FlushDeltaMemStoresOp(8b4e9da050794fc39cb361f0016d3485): perf score=2.188937
I20260812 06:18:37.439723 24257 maintenance_manager.cc:643] P 8dde46a745ca44f98b0568ba917a78e1: FlushDeltaMemStoresOp(8b4e9da050794fc39cb361f0016d3485) complete. Timing: real 0.011s	user 0.005s	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:18:37.440348 24350 maintenance_manager.cc:419] P 8dde46a745ca44f98b0568ba917a78e1: Scheduling MajorDeltaCompactionOp(8b4e9da050794fc39cb361f0016d3485): perf score=1.000000
I20260812 06:18:37.610379 24257 maintenance_manager.cc:643] P 8dde46a745ca44f98b0568ba917a78e1: MajorDeltaCompactionOp(8b4e9da050794fc39cb361f0016d3485) complete. Timing: real 0.170s	user 0.118s	sys 0.047s 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":179,"lbm_read_time_us":11454,"lbm_reads_lt_1ms":572,"lbm_write_time_us":30372,"lbm_writes_lt_1ms":543,"mutex_wait_us":24,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":14592,"update_count":2500}
I20260812 06:18:37.611093 24350 maintenance_manager.cc:419] P 8dde46a745ca44f98b0568ba917a78e1: Scheduling FlushDeltaMemStoresOp(8b4e9da050794fc39cb361f0016d3485): perf score=14.095187
I20260812 06:18:37.672020 24257 maintenance_manager.cc:643] P 8dde46a745ca44f98b0568ba917a78e1: FlushDeltaMemStoresOp(8b4e9da050794fc39cb361f0016d3485) complete. Timing: real 0.061s	user 0.046s	sys 0.011s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":22719,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:18:37.672683 24350 maintenance_manager.cc:419] P 8dde46a745ca44f98b0568ba917a78e1: Scheduling FlushDeltaMemStoresOp(8b4e9da050794fc39cb361f0016d3485): perf score=2.188937
I20260812 06:18:37.683168 24257 maintenance_manager.cc:643] P 8dde46a745ca44f98b0568ba917a78e1: FlushDeltaMemStoresOp(8b4e9da050794fc39cb361f0016d3485) complete. Timing: real 0.010s	user 0.005s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4070,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:37.683632 24350 maintenance_manager.cc:419] P 8dde46a745ca44f98b0568ba917a78e1: Scheduling MajorDeltaCompactionOp(8b4e9da050794fc39cb361f0016d3485): perf score=1.000000
I20260812 06:18:37.861799 24257 maintenance_manager.cc:643] P 8dde46a745ca44f98b0568ba917a78e1: MajorDeltaCompactionOp(8b4e9da050794fc39cb361f0016d3485) complete. Timing: real 0.178s	user 0.094s	sys 0.084s 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":173,"lbm_read_time_us":11988,"lbm_reads_lt_1ms":572,"lbm_write_time_us":31713,"lbm_writes_lt_1ms":543,"mutex_wait_us":42,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":7936,"update_count":2500}
I20260812 06:18:37.862892 24350 maintenance_manager.cc:419] P 8dde46a745ca44f98b0568ba917a78e1: Scheduling FlushDeltaMemStoresOp(8b4e9da050794fc39cb361f0016d3485): perf score=11.118625
I20260812 06:18:37.909382 24257 maintenance_manager.cc:643] P 8dde46a745ca44f98b0568ba917a78e1: FlushDeltaMemStoresOp(8b4e9da050794fc39cb361f0016d3485) complete. Timing: real 0.046s	user 0.018s	sys 0.024s Metrics: {"bytes_written":12717735,"delete_count":0,"lbm_write_time_us":20193,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:18:37.910050 24350 maintenance_manager.cc:419] P 8dde46a745ca44f98b0568ba917a78e1: Scheduling FlushDeltaMemStoresOp(8b4e9da050794fc39cb361f0016d3485): perf score=2.188937
I20260812 06:18:37.935142 24257 maintenance_manager.cc:643] P 8dde46a745ca44f98b0568ba917a78e1: FlushDeltaMemStoresOp(8b4e9da050794fc39cb361f0016d3485) complete. Timing: real 0.025s	user 0.014s	sys 0.007s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":6344,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:18:37.936103 24350 maintenance_manager.cc:419] P 8dde46a745ca44f98b0568ba917a78e1: Scheduling MajorDeltaCompactionOp(8b4e9da050794fc39cb361f0016d3485): perf score=1.000000
I20260812 06:18:38.080760 24257 maintenance_manager.cc:643] P 8dde46a745ca44f98b0568ba917a78e1: MajorDeltaCompactionOp(8b4e9da050794fc39cb361f0016d3485) complete. Timing: real 0.144s	user 0.087s	sys 0.050s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672268,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":1818,"lbm_read_time_us":9748,"lbm_reads_lt_1ms":464,"lbm_write_time_us":21775,"lbm_writes_lt_1ms":443,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":1280,"update_count":2000}
I20260812 06:18:38.081589 24350 maintenance_manager.cc:419] P 8dde46a745ca44f98b0568ba917a78e1: Scheduling FlushDeltaMemStoresOp(8b4e9da050794fc39cb361f0016d3485): perf score=11.118625
I20260812 06:18:38.124037 24257 maintenance_manager.cc:643] P 8dde46a745ca44f98b0568ba917a78e1: FlushDeltaMemStoresOp(8b4e9da050794fc39cb361f0016d3485) complete. Timing: real 0.042s	user 0.026s	sys 0.014s Metrics: {"bytes_written":12717737,"delete_count":0,"lbm_write_time_us":17548,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:18:38.124652 24350 maintenance_manager.cc:419] P 8dde46a745ca44f98b0568ba917a78e1: Scheduling FlushDeltaMemStoresOp(8b4e9da050794fc39cb361f0016d3485): perf score=2.188937
I20260812 06:18:38.148157 24257 maintenance_manager.cc:643] P 8dde46a745ca44f98b0568ba917a78e1: FlushDeltaMemStoresOp(8b4e9da050794fc39cb361f0016d3485) complete. Timing: real 0.023s	user 0.011s	sys 0.000s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":4994,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:18:38.148712 24350 maintenance_manager.cc:419] P 8dde46a745ca44f98b0568ba917a78e1: Scheduling FlushDeltaMemStoresOp(8b4e9da050794fc39cb361f0016d3485): perf score=2.188937
I20260812 06:18:38.159175 24257 maintenance_manager.cc:643] P 8dde46a745ca44f98b0568ba917a78e1: FlushDeltaMemStoresOp(8b4e9da050794fc39cb361f0016d3485) complete. Timing: real 0.010s	user 0.008s	sys 0.001s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":3849,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:38.159722 24350 maintenance_manager.cc:419] P 8dde46a745ca44f98b0568ba917a78e1: Scheduling FlushMRSOp(8b4e9da050794fc39cb361f0016d3485): perf score=1.000000
I20260812 06:18:38.194702 24257 maintenance_manager.cc:643] P 8dde46a745ca44f98b0568ba917a78e1: FlushMRSOp(8b4e9da050794fc39cb361f0016d3485) complete. Timing: real 0.035s	user 0.034s	sys 0.000s Metrics: {"bytes_written":1275449,"cfile_init":1,"dirs.queue_time_us":72,"dirs.run_cpu_time_us":239,"dirs.run_wall_time_us":1521,"drs_written":1,"lbm_read_time_us":36,"lbm_reads_lt_1ms":4,"lbm_write_time_us":2008,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":31}
I20260812 06:18:38.195403 24350 maintenance_manager.cc:419] P 8dde46a745ca44f98b0568ba917a78e1: Scheduling LogGCOp(8b4e9da050794fc39cb361f0016d3485): free 124710314 bytes of WAL
I20260812 06:18:38.195660 24257 log_reader.cc:385] T 8b4e9da050794fc39cb361f0016d3485: removed 12 log segments from log reader
I20260812 06:18:38.195703 24257 log.cc:1079] T 8b4e9da050794fc39cb361f0016d3485 P 8dde46a745ca44f98b0568ba917a78e1: Deleting log segment in path: /tmp/dist-test-task2jzYy2/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515514800191-24103-0/minicluster-data/ts-0-root/wals/8b4e9da050794fc39cb361f0016d3485/wal-000000015 (ops 71-75)
I20260812 06:18:38.195732 24257 log.cc:1079] T 8b4e9da050794fc39cb361f0016d3485 P 8dde46a745ca44f98b0568ba917a78e1: Deleting log segment in path: /tmp/dist-test-task2jzYy2/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515514800191-24103-0/minicluster-data/ts-0-root/wals/8b4e9da050794fc39cb361f0016d3485/wal-000000016 (ops 76-80)
I20260812 06:18:38.195791 24257 log.cc:1079] T 8b4e9da050794fc39cb361f0016d3485 P 8dde46a745ca44f98b0568ba917a78e1: Deleting log segment in path: /tmp/dist-test-task2jzYy2/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515514800191-24103-0/minicluster-data/ts-0-root/wals/8b4e9da050794fc39cb361f0016d3485/wal-000000017 (ops 81-85)
I20260812 06:18:38.195832 24257 log.cc:1079] T 8b4e9da050794fc39cb361f0016d3485 P 8dde46a745ca44f98b0568ba917a78e1: Deleting log segment in path: /tmp/dist-test-task2jzYy2/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515514800191-24103-0/minicluster-data/ts-0-root/wals/8b4e9da050794fc39cb361f0016d3485/wal-000000018 (ops 86-90)
I20260812 06:18:38.195873 24257 log.cc:1079] T 8b4e9da050794fc39cb361f0016d3485 P 8dde46a745ca44f98b0568ba917a78e1: Deleting log segment in path: /tmp/dist-test-task2jzYy2/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515514800191-24103-0/minicluster-data/ts-0-root/wals/8b4e9da050794fc39cb361f0016d3485/wal-000000019 (ops 91-95)
I20260812 06:18:38.195915 24257 log.cc:1079] T 8b4e9da050794fc39cb361f0016d3485 P 8dde46a745ca44f98b0568ba917a78e1: Deleting log segment in path: /tmp/dist-test-task2jzYy2/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515514800191-24103-0/minicluster-data/ts-0-root/wals/8b4e9da050794fc39cb361f0016d3485/wal-000000020 (ops 96-100)
I20260812 06:18:38.195955 24257 log.cc:1079] T 8b4e9da050794fc39cb361f0016d3485 P 8dde46a745ca44f98b0568ba917a78e1: Deleting log segment in path: /tmp/dist-test-task2jzYy2/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515514800191-24103-0/minicluster-data/ts-0-root/wals/8b4e9da050794fc39cb361f0016d3485/wal-000000021 (ops 101-105)
I20260812 06:18:38.195993 24257 log.cc:1079] T 8b4e9da050794fc39cb361f0016d3485 P 8dde46a745ca44f98b0568ba917a78e1: Deleting log segment in path: /tmp/dist-test-task2jzYy2/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515514800191-24103-0/minicluster-data/ts-0-root/wals/8b4e9da050794fc39cb361f0016d3485/wal-000000022 (ops 106-110)
I20260812 06:18:38.196039 24257 log.cc:1079] T 8b4e9da050794fc39cb361f0016d3485 P 8dde46a745ca44f98b0568ba917a78e1: Deleting log segment in path: /tmp/dist-test-task2jzYy2/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515514800191-24103-0/minicluster-data/ts-0-root/wals/8b4e9da050794fc39cb361f0016d3485/wal-000000023 (ops 111-115)
I20260812 06:18:38.196079 24257 log.cc:1079] T 8b4e9da050794fc39cb361f0016d3485 P 8dde46a745ca44f98b0568ba917a78e1: Deleting log segment in path: /tmp/dist-test-task2jzYy2/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515514800191-24103-0/minicluster-data/ts-0-root/wals/8b4e9da050794fc39cb361f0016d3485/wal-000000024 (ops 116-120)
I20260812 06:18:38.196121 24257 log.cc:1079] T 8b4e9da050794fc39cb361f0016d3485 P 8dde46a745ca44f98b0568ba917a78e1: Deleting log segment in path: /tmp/dist-test-task2jzYy2/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515514800191-24103-0/minicluster-data/ts-0-root/wals/8b4e9da050794fc39cb361f0016d3485/wal-000000025 (ops 121-125)
I20260812 06:18:38.196163 24257 log.cc:1079] T 8b4e9da050794fc39cb361f0016d3485 P 8dde46a745ca44f98b0568ba917a78e1: Deleting log segment in path: /tmp/dist-test-task2jzYy2/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515514800191-24103-0/minicluster-data/ts-0-root/wals/8b4e9da050794fc39cb361f0016d3485/wal-000000026 (ops 126-130)
I20260812 06:18:38.222424 24257 maintenance_manager.cc:643] P 8dde46a745ca44f98b0568ba917a78e1: LogGCOp(8b4e9da050794fc39cb361f0016d3485) complete. Timing: real 0.027s	user 0.000s	sys 0.027s Metrics: {}
I20260812 06:18:38.223729 24350 maintenance_manager.cc:419] P 8dde46a745ca44f98b0568ba917a78e1: Scheduling FlushDeltaMemStoresOp(8b4e9da050794fc39cb361f0016d3485): perf score=4.173312
I20260812 06:18:38.244382 24257 maintenance_manager.cc:643] P 8dde46a745ca44f98b0568ba917a78e1: FlushDeltaMemStoresOp(8b4e9da050794fc39cb361f0016d3485) complete. Timing: real 0.020s	user 0.008s	sys 0.011s Metrics: {"bytes_written":5333393,"delete_count":0,"lbm_write_time_us":5473,"lbm_writes_lt_1ms":133,"reinsert_count":0,"update_count":650}
I20260812 06:18:38.244865 24350 maintenance_manager.cc:419] P 8dde46a745ca44f98b0568ba917a78e1: Scheduling UndoDeltaBlockGCOp(8b4e9da050794fc39cb361f0016d3485): 482 bytes on disk
I20260812 06:18:38.245301 24257 maintenance_manager.cc:643] P 8dde46a745ca44f98b0568ba917a78e1: UndoDeltaBlockGCOp(8b4e9da050794fc39cb361f0016d3485) 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:18:38.245806 24350 maintenance_manager.cc:419] P 8dde46a745ca44f98b0568ba917a78e1: Scheduling FlushDeltaMemStoresOp(8b4e9da050794fc39cb361f0016d3485): perf score=1.196750
I20260812 06:18:38.253646 24257 maintenance_manager.cc:643] P 8dde46a745ca44f98b0568ba917a78e1: FlushDeltaMemStoresOp(8b4e9da050794fc39cb361f0016d3485) complete. Timing: real 0.008s	user 0.006s	sys 0.000s Metrics: {"bytes_written":2871905,"delete_count":0,"lbm_write_time_us":2759,"lbm_writes_lt_1ms":73,"reinsert_count":0,"update_count":350}
I20260812 06:18:38.254053 24350 maintenance_manager.cc:419] P 8dde46a745ca44f98b0568ba917a78e1: Scheduling MajorDeltaCompactionOp(8b4e9da050794fc39cb361f0016d3485): perf score=1.000000
I20260812 06:18:38.478746 24257 maintenance_manager.cc:643] P 8dde46a745ca44f98b0568ba917a78e1: MajorDeltaCompactionOp(8b4e9da050794fc39cb361f0016d3485) complete. Timing: real 0.224s	user 0.170s	sys 0.053s Metrics: {"cfile_cache_miss":735,"cfile_cache_miss_bytes":32979836,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":5,"delta_iterators_relevant":5,"dirs.queue_time_us":1515,"lbm_read_time_us":17661,"lbm_reads_lt_1ms":775,"lbm_write_time_us":36672,"lbm_writes_lt_1ms":743,"mutex_wait_us":534,"peak_mem_usage":87969044,"reinsert_count":0,"thread_start_us":83,"threads_started":1,"update_count":3500}
I20260812 06:18:38.482215 24350 maintenance_manager.cc:419] P 8dde46a745ca44f98b0568ba917a78e1: Scheduling FlushDeltaMemStoresOp(8b4e9da050794fc39cb361f0016d3485): perf score=14.095187
I20260812 06:18:38.550565 24257 maintenance_manager.cc:643] P 8dde46a745ca44f98b0568ba917a78e1: FlushDeltaMemStoresOp(8b4e9da050794fc39cb361f0016d3485) complete. Timing: real 0.067s	user 0.034s	sys 0.033s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":31128,"lbm_writes_1-10_ms":2,"lbm_writes_lt_1ms":401,"reinsert_count":0,"update_count":2000}
I20260812 06:18:38.551213 24350 maintenance_manager.cc:419] P 8dde46a745ca44f98b0568ba917a78e1: Scheduling FlushDeltaMemStoresOp(8b4e9da050794fc39cb361f0016d3485): perf score=2.188937
I20260812 06:18:38.567358 24257 maintenance_manager.cc:643] P 8dde46a745ca44f98b0568ba917a78e1: FlushDeltaMemStoresOp(8b4e9da050794fc39cb361f0016d3485) complete. Timing: real 0.016s	user 0.013s	sys 0.000s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":5441,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:38.567813 24350 maintenance_manager.cc:419] P 8dde46a745ca44f98b0568ba917a78e1: Scheduling MajorDeltaCompactionOp(8b4e9da050794fc39cb361f0016d3485): perf score=1.000000
I20260812 06:18:38.747790 24257 maintenance_manager.cc:643] P 8dde46a745ca44f98b0568ba917a78e1: MajorDeltaCompactionOp(8b4e9da050794fc39cb361f0016d3485) complete. Timing: real 0.180s	user 0.119s	sys 0.051s 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":554,"lbm_read_time_us":11338,"lbm_reads_lt_1ms":568,"lbm_write_time_us":29950,"lbm_writes_lt_1ms":543,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":3712,"update_count":2500}
I20260812 06:18:38.751327 24350 maintenance_manager.cc:419] P 8dde46a745ca44f98b0568ba917a78e1: Scheduling FlushDeltaMemStoresOp(8b4e9da050794fc39cb361f0016d3485): perf score=14.095187
I20260812 06:18:38.812093 24257 maintenance_manager.cc:643] P 8dde46a745ca44f98b0568ba917a78e1: FlushDeltaMemStoresOp(8b4e9da050794fc39cb361f0016d3485) complete. Timing: real 0.061s	user 0.027s	sys 0.031s Metrics: {"bytes_written":16409906,"delete_count":0,"lbm_write_time_us":22969,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":402,"reinsert_count":0,"update_count":2000}
I20260812 06:18:38.812695 24350 maintenance_manager.cc:419] P 8dde46a745ca44f98b0568ba917a78e1: Scheduling FlushDeltaMemStoresOp(8b4e9da050794fc39cb361f0016d3485): perf score=2.188937
I20260812 06:18:38.824316 24257 maintenance_manager.cc:643] P 8dde46a745ca44f98b0568ba917a78e1: FlushDeltaMemStoresOp(8b4e9da050794fc39cb361f0016d3485) complete. Timing: real 0.011s	user 0.006s	sys 0.003s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4475,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:38.824965 24350 maintenance_manager.cc:419] P 8dde46a745ca44f98b0568ba917a78e1: Scheduling MajorDeltaCompactionOp(8b4e9da050794fc39cb361f0016d3485): perf score=1.000000
I20260812 06:18:39.009553 24257 maintenance_manager.cc:643] P 8dde46a745ca44f98b0568ba917a78e1: MajorDeltaCompactionOp(8b4e9da050794fc39cb361f0016d3485) complete. Timing: real 0.184s	user 0.097s	sys 0.076s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774693,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":344,"lbm_read_time_us":13093,"lbm_reads_lt_1ms":572,"lbm_write_time_us":29935,"lbm_writes_lt_1ms":543,"mutex_wait_us":55,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":896,"update_count":2500}
I20260812 06:18:39.010071 24350 maintenance_manager.cc:419] P 8dde46a745ca44f98b0568ba917a78e1: Scheduling FlushDeltaMemStoresOp(8b4e9da050794fc39cb361f0016d3485): perf score=14.095187
I20260812 06:18:39.063798 24257 maintenance_manager.cc:643] P 8dde46a745ca44f98b0568ba917a78e1: FlushDeltaMemStoresOp(8b4e9da050794fc39cb361f0016d3485) complete. Timing: real 0.054s	user 0.021s	sys 0.024s Metrics: {"bytes_written":16409903,"delete_count":0,"lbm_write_time_us":20663,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:18:39.064399 24350 maintenance_manager.cc:419] P 8dde46a745ca44f98b0568ba917a78e1: Scheduling FlushDeltaMemStoresOp(8b4e9da050794fc39cb361f0016d3485): perf score=2.188937
I20260812 06:18:39.084555 24257 maintenance_manager.cc:643] P 8dde46a745ca44f98b0568ba917a78e1: FlushDeltaMemStoresOp(8b4e9da050794fc39cb361f0016d3485) complete. Timing: real 0.020s	user 0.010s	sys 0.007s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4542,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:39.085253 24350 maintenance_manager.cc:419] P 8dde46a745ca44f98b0568ba917a78e1: Scheduling MajorDeltaCompactionOp(8b4e9da050794fc39cb361f0016d3485): perf score=1.000000
I20260812 06:18:39.262912 24257 maintenance_manager.cc:643] P 8dde46a745ca44f98b0568ba917a78e1: MajorDeltaCompactionOp(8b4e9da050794fc39cb361f0016d3485) complete. Timing: real 0.177s	user 0.115s	sys 0.060s 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":829,"lbm_read_time_us":11852,"lbm_reads_lt_1ms":572,"lbm_write_time_us":31195,"lbm_writes_lt_1ms":543,"mutex_wait_us":21,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":2432,"update_count":2500}
I20260812 06:18:39.263537 24350 maintenance_manager.cc:419] P 8dde46a745ca44f98b0568ba917a78e1: Scheduling FlushDeltaMemStoresOp(8b4e9da050794fc39cb361f0016d3485): perf score=11.118625
I20260812 06:18:39.307576 24257 maintenance_manager.cc:643] P 8dde46a745ca44f98b0568ba917a78e1: FlushDeltaMemStoresOp(8b4e9da050794fc39cb361f0016d3485) complete. Timing: real 0.044s	user 0.021s	sys 0.020s Metrics: {"bytes_written":12717736,"delete_count":0,"lbm_write_time_us":20549,"lbm_writes_1-10_ms":2,"lbm_writes_lt_1ms":311,"reinsert_count":0,"update_count":1550}
I20260812 06:18:39.308051 24350 maintenance_manager.cc:419] P 8dde46a745ca44f98b0568ba917a78e1: Scheduling FlushDeltaMemStoresOp(8b4e9da050794fc39cb361f0016d3485): perf score=2.188937
I20260812 06:18:39.326655 24257 maintenance_manager.cc:643] P 8dde46a745ca44f98b0568ba917a78e1: FlushDeltaMemStoresOp(8b4e9da050794fc39cb361f0016d3485) complete. Timing: real 0.018s	user 0.006s	sys 0.004s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3862,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:18:39.327132 24350 maintenance_manager.cc:419] P 8dde46a745ca44f98b0568ba917a78e1: Scheduling FlushDeltaMemStoresOp(8b4e9da050794fc39cb361f0016d3485): perf score=2.188937
I20260812 06:18:39.337040 24257 maintenance_manager.cc:643] P 8dde46a745ca44f98b0568ba917a78e1: FlushDeltaMemStoresOp(8b4e9da050794fc39cb361f0016d3485) complete. Timing: real 0.010s	user 0.001s	sys 0.007s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":3847,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:39.337500 24350 maintenance_manager.cc:419] P 8dde46a745ca44f98b0568ba917a78e1: Scheduling MajorDeltaCompactionOp(8b4e9da050794fc39cb361f0016d3485): perf score=1.000000
I20260812 06:18:39.515125 24257 maintenance_manager.cc:643] P 8dde46a745ca44f98b0568ba917a78e1: MajorDeltaCompactionOp(8b4e9da050794fc39cb361f0016d3485) complete. Timing: real 0.177s	user 0.114s	sys 0.052s Metrics: {"cfile_cache_miss":533,"cfile_cache_miss_bytes":24774799,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":316,"lbm_read_time_us":12407,"lbm_reads_lt_1ms":573,"lbm_write_time_us":27722,"lbm_writes_lt_1ms":543,"mutex_wait_us":78,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":768,"update_count":2500}
I20260812 06:18:39.515867 24350 maintenance_manager.cc:419] P 8dde46a745ca44f98b0568ba917a78e1: Scheduling FlushDeltaMemStoresOp(8b4e9da050794fc39cb361f0016d3485): perf score=14.095187
I20260812 06:18:39.566066 24257 maintenance_manager.cc:643] P 8dde46a745ca44f98b0568ba917a78e1: FlushDeltaMemStoresOp(8b4e9da050794fc39cb361f0016d3485) complete. Timing: real 0.050s	user 0.020s	sys 0.019s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":18965,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:18:39.566669 24350 maintenance_manager.cc:419] P 8dde46a745ca44f98b0568ba917a78e1: Scheduling FlushDeltaMemStoresOp(8b4e9da050794fc39cb361f0016d3485): perf score=2.188937
I20260812 06:18:39.582106 24257 maintenance_manager.cc:643] P 8dde46a745ca44f98b0568ba917a78e1: FlushDeltaMemStoresOp(8b4e9da050794fc39cb361f0016d3485) complete. Timing: real 0.015s	user 0.008s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5652,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:39.582692 24350 maintenance_manager.cc:419] P 8dde46a745ca44f98b0568ba917a78e1: Scheduling MajorDeltaCompactionOp(8b4e9da050794fc39cb361f0016d3485): perf score=1.000000
I20260812 06:18:39.741484 24257 maintenance_manager.cc:643] P 8dde46a745ca44f98b0568ba917a78e1: MajorDeltaCompactionOp(8b4e9da050794fc39cb361f0016d3485) complete. Timing: real 0.159s	user 0.127s	sys 0.017s 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":1056,"lbm_read_time_us":9735,"lbm_reads_lt_1ms":572,"lbm_write_time_us":28785,"lbm_writes_lt_1ms":543,"mutex_wait_us":296,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":1152,"update_count":2500}
I20260812 06:18:39.742126 24350 maintenance_manager.cc:419] P 8dde46a745ca44f98b0568ba917a78e1: Scheduling FlushDeltaMemStoresOp(8b4e9da050794fc39cb361f0016d3485): perf score=14.095187
I20260812 06:18:39.792690 24257 maintenance_manager.cc:643] P 8dde46a745ca44f98b0568ba917a78e1: FlushDeltaMemStoresOp(8b4e9da050794fc39cb361f0016d3485) complete. Timing: real 0.050s	user 0.018s	sys 0.022s Metrics: {"bytes_written":16409904,"delete_count":0,"lbm_write_time_us":19220,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:18:39.793215 24350 maintenance_manager.cc:419] P 8dde46a745ca44f98b0568ba917a78e1: Scheduling FlushDeltaMemStoresOp(8b4e9da050794fc39cb361f0016d3485): perf score=2.188937
I20260812 06:18:39.804308 24257 maintenance_manager.cc:643] P 8dde46a745ca44f98b0568ba917a78e1: FlushDeltaMemStoresOp(8b4e9da050794fc39cb361f0016d3485) complete. Timing: real 0.011s	user 0.006s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4083,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:39.804821 24350 maintenance_manager.cc:419] P 8dde46a745ca44f98b0568ba917a78e1: Scheduling FlushMRSOp(8b4e9da050794fc39cb361f0016d3485): perf score=1.000000
I20260812 06:18:39.836691 24257 maintenance_manager.cc:643] P 8dde46a745ca44f98b0568ba917a78e1: FlushMRSOp(8b4e9da050794fc39cb361f0016d3485) complete. Timing: real 0.032s	user 0.030s	sys 0.000s Metrics: {"bytes_written":1316417,"cfile_init":1,"dirs.queue_time_us":75,"dirs.run_cpu_time_us":258,"dirs.run_wall_time_us":1567,"drs_written":1,"lbm_read_time_us":38,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1608,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":32}
I20260812 06:18:39.837366 24350 maintenance_manager.cc:419] P 8dde46a745ca44f98b0568ba917a78e1: Scheduling LogGCOp(8b4e9da050794fc39cb361f0016d3485): free 129773845 bytes of WAL
I20260812 06:18:39.837604 24257 log_reader.cc:385] T 8b4e9da050794fc39cb361f0016d3485: removed 13 log segments from log reader
I20260812 06:18:39.837668 24257 log.cc:1079] T 8b4e9da050794fc39cb361f0016d3485 P 8dde46a745ca44f98b0568ba917a78e1: Deleting log segment in path: /tmp/dist-test-task2jzYy2/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515514800191-24103-0/minicluster-data/ts-0-root/wals/8b4e9da050794fc39cb361f0016d3485/wal-000000027 (ops 131-135)
I20260812 06:18:39.837723 24257 log.cc:1079] T 8b4e9da050794fc39cb361f0016d3485 P 8dde46a745ca44f98b0568ba917a78e1: Deleting log segment in path: /tmp/dist-test-task2jzYy2/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515514800191-24103-0/minicluster-data/ts-0-root/wals/8b4e9da050794fc39cb361f0016d3485/wal-000000028 (ops 136-140)
I20260812 06:18:39.837781 24257 log.cc:1079] T 8b4e9da050794fc39cb361f0016d3485 P 8dde46a745ca44f98b0568ba917a78e1: Deleting log segment in path: /tmp/dist-test-task2jzYy2/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515514800191-24103-0/minicluster-data/ts-0-root/wals/8b4e9da050794fc39cb361f0016d3485/wal-000000029 (ops 141-145)
I20260812 06:18:39.837826 24257 log.cc:1079] T 8b4e9da050794fc39cb361f0016d3485 P 8dde46a745ca44f98b0568ba917a78e1: Deleting log segment in path: /tmp/dist-test-task2jzYy2/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515514800191-24103-0/minicluster-data/ts-0-root/wals/8b4e9da050794fc39cb361f0016d3485/wal-000000030 (ops 146-150)
I20260812 06:18:39.837864 24257 log.cc:1079] T 8b4e9da050794fc39cb361f0016d3485 P 8dde46a745ca44f98b0568ba917a78e1: Deleting log segment in path: /tmp/dist-test-task2jzYy2/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515514800191-24103-0/minicluster-data/ts-0-root/wals/8b4e9da050794fc39cb361f0016d3485/wal-000000031 (ops 151-155)
I20260812 06:18:39.837904 24257 log.cc:1079] T 8b4e9da050794fc39cb361f0016d3485 P 8dde46a745ca44f98b0568ba917a78e1: Deleting log segment in path: /tmp/dist-test-task2jzYy2/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515514800191-24103-0/minicluster-data/ts-0-root/wals/8b4e9da050794fc39cb361f0016d3485/wal-000000032 (ops 156-160)
I20260812 06:18:39.837944 24257 log.cc:1079] T 8b4e9da050794fc39cb361f0016d3485 P 8dde46a745ca44f98b0568ba917a78e1: Deleting log segment in path: /tmp/dist-test-task2jzYy2/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515514800191-24103-0/minicluster-data/ts-0-root/wals/8b4e9da050794fc39cb361f0016d3485/wal-000000033 (ops 161-164)
I20260812 06:18:39.837983 24257 log.cc:1079] T 8b4e9da050794fc39cb361f0016d3485 P 8dde46a745ca44f98b0568ba917a78e1: Deleting log segment in path: /tmp/dist-test-task2jzYy2/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515514800191-24103-0/minicluster-data/ts-0-root/wals/8b4e9da050794fc39cb361f0016d3485/wal-000000034 (ops 165-169)
I20260812 06:18:39.838022 24257 log.cc:1079] T 8b4e9da050794fc39cb361f0016d3485 P 8dde46a745ca44f98b0568ba917a78e1: Deleting log segment in path: /tmp/dist-test-task2jzYy2/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515514800191-24103-0/minicluster-data/ts-0-root/wals/8b4e9da050794fc39cb361f0016d3485/wal-000000035 (ops 170-174)
I20260812 06:18:39.838061 24257 log.cc:1079] T 8b4e9da050794fc39cb361f0016d3485 P 8dde46a745ca44f98b0568ba917a78e1: Deleting log segment in path: /tmp/dist-test-task2jzYy2/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515514800191-24103-0/minicluster-data/ts-0-root/wals/8b4e9da050794fc39cb361f0016d3485/wal-000000036 (ops 175-179)
I20260812 06:18:39.838102 24257 log.cc:1079] T 8b4e9da050794fc39cb361f0016d3485 P 8dde46a745ca44f98b0568ba917a78e1: Deleting log segment in path: /tmp/dist-test-task2jzYy2/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515514800191-24103-0/minicluster-data/ts-0-root/wals/8b4e9da050794fc39cb361f0016d3485/wal-000000037 (ops 180-184)
I20260812 06:18:39.838141 24257 log.cc:1079] T 8b4e9da050794fc39cb361f0016d3485 P 8dde46a745ca44f98b0568ba917a78e1: Deleting log segment in path: /tmp/dist-test-task2jzYy2/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515514800191-24103-0/minicluster-data/ts-0-root/wals/8b4e9da050794fc39cb361f0016d3485/wal-000000038 (ops 185-189)
I20260812 06:18:39.838179 24257 log.cc:1079] T 8b4e9da050794fc39cb361f0016d3485 P 8dde46a745ca44f98b0568ba917a78e1: Deleting log segment in path: /tmp/dist-test-task2jzYy2/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515514800191-24103-0/minicluster-data/ts-0-root/wals/8b4e9da050794fc39cb361f0016d3485/wal-000000039 (ops 190-194)
I20260812 06:18:39.867246 24257 maintenance_manager.cc:643] P 8dde46a745ca44f98b0568ba917a78e1: LogGCOp(8b4e9da050794fc39cb361f0016d3485) complete. Timing: real 0.030s	user 0.002s	sys 0.027s Metrics: {}
I20260812 06:18:39.867662 24350 maintenance_manager.cc:419] P 8dde46a745ca44f98b0568ba917a78e1: Scheduling FlushDeltaMemStoresOp(8b4e9da050794fc39cb361f0016d3485): perf score=3.181125
I20260812 06:18:39.895040 24257 maintenance_manager.cc:643] P 8dde46a745ca44f98b0568ba917a78e1: FlushDeltaMemStoresOp(8b4e9da050794fc39cb361f0016d3485) complete. Timing: real 0.027s	user 0.008s	sys 0.018s Metrics: {"bytes_written":4512903,"delete_count":0,"lbm_write_time_us":7373,"lbm_writes_lt_1ms":113,"reinsert_count":0,"update_count":550}
I20260812 06:18:39.895619 24350 maintenance_manager.cc:419] P 8dde46a745ca44f98b0568ba917a78e1: Scheduling UndoDeltaBlockGCOp(8b4e9da050794fc39cb361f0016d3485): 493 bytes on disk
I20260812 06:18:39.896075 24257 maintenance_manager.cc:643] P 8dde46a745ca44f98b0568ba917a78e1: UndoDeltaBlockGCOp(8b4e9da050794fc39cb361f0016d3485) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":64,"lbm_reads_lt_1ms":4}
I20260812 06:18:39.896601 24350 maintenance_manager.cc:419] P 8dde46a745ca44f98b0568ba917a78e1: Scheduling FlushDeltaMemStoresOp(8b4e9da050794fc39cb361f0016d3485): perf score=2.188937
I20260812 06:18:39.907754 24257 maintenance_manager.cc:643] P 8dde46a745ca44f98b0568ba917a78e1: FlushDeltaMemStoresOp(8b4e9da050794fc39cb361f0016d3485) complete. Timing: real 0.011s	user 0.005s	sys 0.004s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":4208,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:18:39.908316 24350 maintenance_manager.cc:419] P 8dde46a745ca44f98b0568ba917a78e1: Scheduling MajorDeltaCompactionOp(8b4e9da050794fc39cb361f0016d3485): perf score=1.000000
I20260812 06:18:40.003693 24103 heavy-update-compaction-itest.cc:229] Time spent updating: real 4.903s	user 1.811s	sys 0.170s
I20260812 06:18:40.105158 24103 heavy-update-compaction-itest.cc:265] Time spent scanning: real 0.101s	user 0.002s	sys 0.000s
I20260812 06:18:40.105783 24103 tablet_server.cc:179] TabletServer@127.23.137.193:0 shutting down...
I20260812 06:18:40.117280 24257 maintenance_manager.cc:643] P 8dde46a745ca44f98b0568ba917a78e1: MajorDeltaCompactionOp(8b4e9da050794fc39cb361f0016d3485) complete. Timing: real 0.209s	user 0.118s	sys 0.088s Metrics: {"cfile_cache_miss":734,"cfile_cache_miss_bytes":32979743,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":3426,"lbm_read_time_us":16400,"lbm_reads_lt_1ms":770,"lbm_write_time_us":33032,"lbm_writes_lt_1ms":743,"mutex_wait_us":2821,"peak_mem_usage":87969044,"reinsert_count":0,"spinlock_wait_cycles":3584,"thread_start_us":79,"threads_started":1,"update_count":3500}
I20260812 06:18:40.117862 24103 ts_tablet_manager.cc:1507] Shutting down tablet manager...
I20260812 06:18:40.118736 24103 tablet_replica.cc:333] T 8b4e9da050794fc39cb361f0016d3485 P 8dde46a745ca44f98b0568ba917a78e1: stopping tablet replica
I20260812 06:18:40.119015 24103 raft_consensus.cc:2243] T 8b4e9da050794fc39cb361f0016d3485 P 8dde46a745ca44f98b0568ba917a78e1 [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:18:40.119257 24103 raft_consensus.cc:2272] T 8b4e9da050794fc39cb361f0016d3485 P 8dde46a745ca44f98b0568ba917a78e1 [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:18:40.135602 24103 tablet_server.cc:196] TabletServer@127.23.137.193:0 shutdown complete.
I20260812 06:18:40.170894 24103 master.cc:562] Master@127.23.137.254:43951 shutting down...
I20260812 06:18:40.174605 24103 raft_consensus.cc:2243] T 00000000000000000000000000000000 P 2b9143061bc54f6abc44fe2ba197a89e [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:18:40.174774 24103 raft_consensus.cc:2272] T 00000000000000000000000000000000 P 2b9143061bc54f6abc44fe2ba197a89e [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:18:40.174829 24103 tablet_replica.cc:333] T 00000000000000000000000000000000 P 2b9143061bc54f6abc44fe2ba197a89e: stopping tablet replica
I20260812 06:18:40.187095 24103 master.cc:584] Master@127.23.137.254:43951 shutdown complete.
[       OK ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/0 (5460 ms)
[ RUN      ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/1
I20260812 06:18:40.285086 24103 internal_mini_cluster.cc:156] Creating distributed mini masters. Addrs: 127.23.137.254:42003
I20260812 06:18:40.285678 24103 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:18:40.287945 24403 instance_detector.cc:116] could not retrieve AWS instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:18:40.288029 24405 instance_detector.cc:116] could not retrieve Azure instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:18:40.288110 24408 instance_detector.cc:116] could not retrieve OpenStack instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:18:40.288129 24103 server_base.cc:1061] running on GCE node
I20260812 06:18:40.288362 24103 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:18:40.288403 24103 system_unsync_time.cc:38] NTP support is disabled. Clock error bounds will not be accurate. This configuration is not suitable for distributed clusters.
I20260812 06:18:40.288419 24103 hybrid_clock.cc:648] HybridClock initialized: now 1786515520288420 us; error 0 us; skew 500 ppm
I20260812 06:18:40.289326 24103 webserver.cc:533] Webserver started at http://127.23.137.254:40901/ using document root <none> and password file <none>
I20260812 06:18:40.289534 24103 fs_manager.cc:362] Metadata directory not provided
I20260812 06:18:40.289613 24103 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:18:40.289706 24103 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:18:40.290176 24103 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-task2jzYy2/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515514800191-24103-0/minicluster-data/master-0-root/instance:
uuid: "d09dbf1bfc724e4393b783a0b3643476"
format_stamp: "Formatted at 2026-08-12 06:18:40 on dist-test-slave-jztv"
I20260812 06:18:40.292074 24103 fs_manager.cc:696] Time spent creating directory manager: real 0.002s	user 0.002s	sys 0.000s
I20260812 06:18:40.293087 24417 log_block_manager.cc:4127] Time spent loading block containers with low live blocks: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:18:40.293351 24103 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.001s	sys 0.000s
I20260812 06:18:40.293430 24103 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-task2jzYy2/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515514800191-24103-0/minicluster-data/master-0-root
uuid: "d09dbf1bfc724e4393b783a0b3643476"
format_stamp: "Formatted at 2026-08-12 06:18:40 on dist-test-slave-jztv"
I20260812 06:18:40.293491 24103 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-task2jzYy2/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515514800191-24103-0/minicluster-data/master-0-root
metadata directory: /tmp/dist-test-task2jzYy2/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515514800191-24103-0/minicluster-data/master-0-root
1 data directories: /tmp/dist-test-task2jzYy2/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515514800191-24103-0/minicluster-data/master-0-root/data
Total live blocks: 0
Total live bytes: 0
Total live bytes (after alignment): 0
Total number of LBM containers: 0 (0 full)
Did not check for missing blocks
Did not check for orphaned blocks
Total full LBM containers with extra space: 0 (0 repaired)
Total full LBM container extra space in bytes: 0 (0 repaired)
Total incomplete LBM containers: 0 (0 repaired)
Total LBM partial records: 0 (0 repaired)
Total corrupted LBM metadata records in RocksDB: 0 (0 repaired)
I20260812 06:18:40.303418 24103 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:18:40.303767 24103 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:18:40.308159 24103 rpc_server.cc:307] RPC server started. Bound to: 127.23.137.254:42003
I20260812 06:18:40.311983 24502 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.23.137.254:42003 every 8 connection(s)
I20260812 06:18:40.314065 24503 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet 00000000000000000000000000000000. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:18:40.315891 24503 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P d09dbf1bfc724e4393b783a0b3643476: Bootstrap starting.
I20260812 06:18:40.316690 24503 tablet_bootstrap.cc:654] T 00000000000000000000000000000000 P d09dbf1bfc724e4393b783a0b3643476: Neither blocks nor log segments found. Creating new log.
I20260812 06:18:40.317714 24503 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P d09dbf1bfc724e4393b783a0b3643476: No bootstrap required, opened a new log
I20260812 06:18:40.318113 24503 raft_consensus.cc:359] T 00000000000000000000000000000000 P d09dbf1bfc724e4393b783a0b3643476 [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "d09dbf1bfc724e4393b783a0b3643476" member_type: VOTER }
I20260812 06:18:40.318220 24503 raft_consensus.cc:385] T 00000000000000000000000000000000 P d09dbf1bfc724e4393b783a0b3643476 [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:18:40.318310 24503 raft_consensus.cc:740] T 00000000000000000000000000000000 P d09dbf1bfc724e4393b783a0b3643476 [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: d09dbf1bfc724e4393b783a0b3643476, State: Initialized, Role: FOLLOWER
I20260812 06:18:40.318490 24503 consensus_queue.cc:260] T 00000000000000000000000000000000 P d09dbf1bfc724e4393b783a0b3643476 [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: "d09dbf1bfc724e4393b783a0b3643476" member_type: VOTER }
I20260812 06:18:40.318600 24503 raft_consensus.cc:399] T 00000000000000000000000000000000 P d09dbf1bfc724e4393b783a0b3643476 [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:18:40.318648 24503 raft_consensus.cc:493] T 00000000000000000000000000000000 P d09dbf1bfc724e4393b783a0b3643476 [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:18:40.318707 24503 raft_consensus.cc:3060] T 00000000000000000000000000000000 P d09dbf1bfc724e4393b783a0b3643476 [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:18:40.319396 24503 raft_consensus.cc:515] T 00000000000000000000000000000000 P d09dbf1bfc724e4393b783a0b3643476 [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "d09dbf1bfc724e4393b783a0b3643476" member_type: VOTER }
I20260812 06:18:40.319553 24503 leader_election.cc:304] T 00000000000000000000000000000000 P d09dbf1bfc724e4393b783a0b3643476 [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: d09dbf1bfc724e4393b783a0b3643476; no voters: 
I20260812 06:18:40.319752 24503 leader_election.cc:290] T 00000000000000000000000000000000 P d09dbf1bfc724e4393b783a0b3643476 [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:18:40.319881 24510 raft_consensus.cc:2804] T 00000000000000000000000000000000 P d09dbf1bfc724e4393b783a0b3643476 [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:18:40.320096 24510 raft_consensus.cc:697] T 00000000000000000000000000000000 P d09dbf1bfc724e4393b783a0b3643476 [term 1 LEADER]: Becoming Leader. State: Replica: d09dbf1bfc724e4393b783a0b3643476, State: Running, Role: LEADER
I20260812 06:18:40.320199 24503 sys_catalog.cc:565] T 00000000000000000000000000000000 P d09dbf1bfc724e4393b783a0b3643476 [sys.catalog]: configured and running, proceeding with master startup.
I20260812 06:18:40.320307 24510 consensus_queue.cc:237] T 00000000000000000000000000000000 P d09dbf1bfc724e4393b783a0b3643476 [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: "d09dbf1bfc724e4393b783a0b3643476" member_type: VOTER }
I20260812 06:18:40.320786 24511 sys_catalog.cc:455] T 00000000000000000000000000000000 P d09dbf1bfc724e4393b783a0b3643476 [sys.catalog]: SysCatalogTable state changed. Reason: RaftConsensus started. Latest consensus state: current_term: 1 leader_uuid: "d09dbf1bfc724e4393b783a0b3643476" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "d09dbf1bfc724e4393b783a0b3643476" member_type: VOTER } }
I20260812 06:18:40.320815 24512 sys_catalog.cc:455] T 00000000000000000000000000000000 P d09dbf1bfc724e4393b783a0b3643476 [sys.catalog]: SysCatalogTable state changed. Reason: New leader d09dbf1bfc724e4393b783a0b3643476. Latest consensus state: current_term: 1 leader_uuid: "d09dbf1bfc724e4393b783a0b3643476" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "d09dbf1bfc724e4393b783a0b3643476" member_type: VOTER } }
I20260812 06:18:40.320892 24511 sys_catalog.cc:458] T 00000000000000000000000000000000 P d09dbf1bfc724e4393b783a0b3643476 [sys.catalog]: This master's current role is: LEADER
I20260812 06:18:40.320905 24512 sys_catalog.cc:458] T 00000000000000000000000000000000 P d09dbf1bfc724e4393b783a0b3643476 [sys.catalog]: This master's current role is: LEADER
I20260812 06:18:40.321556 24519 catalog_manager.cc:1511] Loading table and tablet metadata into memory...
I20260812 06:18:40.322528 24519 catalog_manager.cc:1520] Initializing Kudu cluster ID...
I20260812 06:18:40.322760 24103 internal_mini_cluster.cc:184] Waiting to initialize catalog manager on master 0
I20260812 06:18:40.324461 24519 catalog_manager.cc:1383] Generated new cluster ID: 7975eaa09a444b46a24dd49e0b12406b
I20260812 06:18:40.324512 24519 catalog_manager.cc:1531] Initializing Kudu internal certificate authority...
I20260812 06:18:40.355451 24519 catalog_manager.cc:1406] Generated new certificate authority record
I20260812 06:18:40.356045 24519 catalog_manager.cc:1540] Loading token signing keys...
I20260812 06:18:40.363296 24519 catalog_manager.cc:6092] T 00000000000000000000000000000000 P d09dbf1bfc724e4393b783a0b3643476: Generated new TSK 0
I20260812 06:18:40.363472 24519 catalog_manager.cc:1550] Initializing in-progress tserver states...
I20260812 06:18:40.387388 24103 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:18:40.389523 24548 instance_detector.cc:116] could not retrieve Azure instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:18:40.389551 24550 instance_detector.cc:116] could not retrieve OpenStack instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:18:40.389604 24546 instance_detector.cc:116] could not retrieve AWS instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:18:40.389709 24103 server_base.cc:1061] running on GCE node
I20260812 06:18:40.389858 24103 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:18:40.389897 24103 system_unsync_time.cc:38] NTP support is disabled. Clock error bounds will not be accurate. This configuration is not suitable for distributed clusters.
I20260812 06:18:40.389914 24103 hybrid_clock.cc:648] HybridClock initialized: now 1786515520389914 us; error 0 us; skew 500 ppm
I20260812 06:18:40.390779 24103 webserver.cc:533] Webserver started at http://127.23.137.193:40895/ using document root <none> and password file <none>
I20260812 06:18:40.390920 24103 fs_manager.cc:362] Metadata directory not provided
I20260812 06:18:40.390966 24103 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:18:40.391036 24103 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:18:40.391386 24103 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-task2jzYy2/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515514800191-24103-0/minicluster-data/ts-0-root/instance:
uuid: "5973ac8c04d8457e980e80784abb5aa7"
format_stamp: "Formatted at 2026-08-12 06:18:40 on dist-test-slave-jztv"
I20260812 06:18:40.392877 24103 fs_manager.cc:696] Time spent creating directory manager: real 0.001s	user 0.002s	sys 0.000s
I20260812 06:18:40.393777 24558 log_block_manager.cc:4127] Time spent loading block containers with low live blocks: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:18:40.394050 24103 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.001s	sys 0.000s
I20260812 06:18:40.394119 24103 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-task2jzYy2/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515514800191-24103-0/minicluster-data/ts-0-root
uuid: "5973ac8c04d8457e980e80784abb5aa7"
format_stamp: "Formatted at 2026-08-12 06:18:40 on dist-test-slave-jztv"
I20260812 06:18:40.394253 24103 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-task2jzYy2/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515514800191-24103-0/minicluster-data/ts-0-root
metadata directory: /tmp/dist-test-task2jzYy2/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515514800191-24103-0/minicluster-data/ts-0-root
1 data directories: /tmp/dist-test-task2jzYy2/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515514800191-24103-0/minicluster-data/ts-0-root/data
Total live blocks: 0
Total live bytes: 0
Total live bytes (after alignment): 0
Total number of LBM containers: 0 (0 full)
Did not check for missing blocks
Did not check for orphaned blocks
Total full LBM containers with extra space: 0 (0 repaired)
Total full LBM container extra space in bytes: 0 (0 repaired)
Total incomplete LBM containers: 0 (0 repaired)
Total LBM partial records: 0 (0 repaired)
Total corrupted LBM metadata records in RocksDB: 0 (0 repaired)
I20260812 06:18:40.411434 24103 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:18:40.411857 24103 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:18:40.412217 24103 txn_system_client.cc:432] TxnSystemClient initialization is disabled...
I20260812 06:18:40.412725 24103 ts_tablet_manager.cc:585] Loaded tablet metadata (0 total tablets, 0 live tablets)
I20260812 06:18:40.412765 24103 ts_tablet_manager.cc:531] Time spent load tablet metadata: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:18:40.412829 24103 ts_tablet_manager.cc:616] Registered 0 tablets
I20260812 06:18:40.412869 24103 ts_tablet_manager.cc:595] Time spent register tablets: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:18:40.417332 24103 rpc_server.cc:307] RPC server started. Bound to: 127.23.137.193:39363
I20260812 06:18:40.418310 24662 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.23.137.193:39363 every 8 connection(s)
I20260812 06:18:40.430106 24663 heartbeater.cc:344] Connected to a master server at 127.23.137.254:42003
I20260812 06:18:40.430270 24663 heartbeater.cc:461] Registering TS with master...
I20260812 06:18:40.430514 24663 heartbeater.cc:507] Master 127.23.137.254:42003 requested a full tablet report, sending...
I20260812 06:18:40.431183 24441 ts_manager.cc:194] Registered new tserver with Master: 5973ac8c04d8457e980e80784abb5aa7 (127.23.137.193:39363)
I20260812 06:18:40.431401 24103 internal_mini_cluster.cc:371] 1 TS(s) registered with all masters after 0.013181149s
I20260812 06:18:40.432022 24441 master_service.cc:502] Signed X509 certificate for tserver {username='slave'} at 127.0.0.1:47568
I20260812 06:18:40.438745 24441 catalog_manager.cc:2283] Servicing CreateTable request from {username='slave'} at 127.0.0.1:47582:
name: "heavy-update-compaction-test"
schema {
  columns {
    name: "key"
    type: INT64
    is_key: true
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_a"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_b"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_c"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_d"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_e"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
}
num_replicas: 1
split_rows_range_bounds {
}
partition_schema {
  range_schema {
  }
}
I20260812 06:18:40.447006 24605 tablet_service.cc:1511] Processing CreateTablet for tablet 4ab1eaa54f904a649365473066f70724 (DEFAULT_TABLE table=heavy-update-compaction-test [id=53064c61826a4810af49b34bdc5fbbdb]), partition=
I20260812 06:18:40.447314 24605 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet 4ab1eaa54f904a649365473066f70724. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:18:40.449235 24684 tablet_bootstrap.cc:492] T 4ab1eaa54f904a649365473066f70724 P 5973ac8c04d8457e980e80784abb5aa7: Bootstrap starting.
I20260812 06:18:40.450405 24684 tablet_bootstrap.cc:654] T 4ab1eaa54f904a649365473066f70724 P 5973ac8c04d8457e980e80784abb5aa7: Neither blocks nor log segments found. Creating new log.
I20260812 06:18:40.451442 24684 tablet_bootstrap.cc:492] T 4ab1eaa54f904a649365473066f70724 P 5973ac8c04d8457e980e80784abb5aa7: No bootstrap required, opened a new log
I20260812 06:18:40.451552 24684 ts_tablet_manager.cc:1403] T 4ab1eaa54f904a649365473066f70724 P 5973ac8c04d8457e980e80784abb5aa7: Time spent bootstrapping tablet: real 0.002s	user 0.000s	sys 0.002s
I20260812 06:18:40.451947 24684 raft_consensus.cc:359] T 4ab1eaa54f904a649365473066f70724 P 5973ac8c04d8457e980e80784abb5aa7 [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "5973ac8c04d8457e980e80784abb5aa7" member_type: VOTER last_known_addr { host: "127.23.137.193" port: 39363 } }
I20260812 06:18:40.452069 24684 raft_consensus.cc:385] T 4ab1eaa54f904a649365473066f70724 P 5973ac8c04d8457e980e80784abb5aa7 [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:18:40.452119 24684 raft_consensus.cc:740] T 4ab1eaa54f904a649365473066f70724 P 5973ac8c04d8457e980e80784abb5aa7 [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: 5973ac8c04d8457e980e80784abb5aa7, State: Initialized, Role: FOLLOWER
I20260812 06:18:40.452256 24684 consensus_queue.cc:260] T 4ab1eaa54f904a649365473066f70724 P 5973ac8c04d8457e980e80784abb5aa7 [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: "5973ac8c04d8457e980e80784abb5aa7" member_type: VOTER last_known_addr { host: "127.23.137.193" port: 39363 } }
I20260812 06:18:40.452365 24684 raft_consensus.cc:399] T 4ab1eaa54f904a649365473066f70724 P 5973ac8c04d8457e980e80784abb5aa7 [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:18:40.452411 24684 raft_consensus.cc:493] T 4ab1eaa54f904a649365473066f70724 P 5973ac8c04d8457e980e80784abb5aa7 [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:18:40.452466 24684 raft_consensus.cc:3060] T 4ab1eaa54f904a649365473066f70724 P 5973ac8c04d8457e980e80784abb5aa7 [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:18:40.453472 24684 raft_consensus.cc:515] T 4ab1eaa54f904a649365473066f70724 P 5973ac8c04d8457e980e80784abb5aa7 [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "5973ac8c04d8457e980e80784abb5aa7" member_type: VOTER last_known_addr { host: "127.23.137.193" port: 39363 } }
I20260812 06:18:40.453624 24684 leader_election.cc:304] T 4ab1eaa54f904a649365473066f70724 P 5973ac8c04d8457e980e80784abb5aa7 [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: 5973ac8c04d8457e980e80784abb5aa7; no voters: 
I20260812 06:18:40.453835 24684 leader_election.cc:290] T 4ab1eaa54f904a649365473066f70724 P 5973ac8c04d8457e980e80784abb5aa7 [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:18:40.453961 24687 raft_consensus.cc:2804] T 4ab1eaa54f904a649365473066f70724 P 5973ac8c04d8457e980e80784abb5aa7 [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:18:40.454185 24687 raft_consensus.cc:697] T 4ab1eaa54f904a649365473066f70724 P 5973ac8c04d8457e980e80784abb5aa7 [term 1 LEADER]: Becoming Leader. State: Replica: 5973ac8c04d8457e980e80784abb5aa7, State: Running, Role: LEADER
I20260812 06:18:40.454190 24663 heartbeater.cc:499] Master 127.23.137.254:42003 was elected leader, sending a full tablet report...
I20260812 06:18:40.454196 24684 ts_tablet_manager.cc:1434] T 4ab1eaa54f904a649365473066f70724 P 5973ac8c04d8457e980e80784abb5aa7: Time spent starting tablet: real 0.003s	user 0.000s	sys 0.003s
I20260812 06:18:40.454375 24687 consensus_queue.cc:237] T 4ab1eaa54f904a649365473066f70724 P 5973ac8c04d8457e980e80784abb5aa7 [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: "5973ac8c04d8457e980e80784abb5aa7" member_type: VOTER last_known_addr { host: "127.23.137.193" port: 39363 } }
I20260812 06:18:40.455665 24441 catalog_manager.cc:5719] T 4ab1eaa54f904a649365473066f70724 P 5973ac8c04d8457e980e80784abb5aa7 reported cstate change: term changed from 0 to 1, leader changed from <none> to 5973ac8c04d8457e980e80784abb5aa7 (127.23.137.193). New cstate: current_term: 1 leader_uuid: "5973ac8c04d8457e980e80784abb5aa7" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "5973ac8c04d8457e980e80784abb5aa7" member_type: VOTER last_known_addr { host: "127.23.137.193" port: 39363 } health_report { overall_health: HEALTHY } } }
I20260812 06:18:40.514680 24103 heavy-update-compaction-itest.cc:215] Time spent inserting: real 0.052s	user 0.018s	sys 0.004s
I20260812 06:18:40.668747 24664 maintenance_manager.cc:419] P 5973ac8c04d8457e980e80784abb5aa7: Scheduling FlushMRSOp(4ab1eaa54f904a649365473066f70724): perf score=19.054940
I20260812 06:18:40.824945 24569 maintenance_manager.cc:643] P 5973ac8c04d8457e980e80784abb5aa7: FlushMRSOp(4ab1eaa54f904a649365473066f70724) complete. Timing: real 0.156s	user 0.094s	sys 0.059s Metrics: {"bytes_written":14276638,"cfile_init":1,"delete_count":0,"dirs.queue_time_us":79,"dirs.run_cpu_time_us":247,"dirs.run_wall_time_us":924,"drs_written":1,"lbm_read_time_us":38,"lbm_reads_lt_1ms":4,"lbm_write_time_us":40361,"lbm_writes_lt_1ms":805,"mutex_wait_us":169,"peak_mem_usage":0,"reinsert_count":0,"rows_written":104,"spinlock_wait_cycles":11264,"update_count":1740}
I20260812 06:18:40.825600 24664 maintenance_manager.cc:419] P 5973ac8c04d8457e980e80784abb5aa7: Scheduling LogGCOp(4ab1eaa54f904a649365473066f70724): free 20743880 bytes of WAL
I20260812 06:18:40.825866 24569 log_reader.cc:385] T 4ab1eaa54f904a649365473066f70724: removed 2 log segments from log reader
I20260812 06:18:40.825933 24569 log.cc:1079] T 4ab1eaa54f904a649365473066f70724 P 5973ac8c04d8457e980e80784abb5aa7: Deleting log segment in path: /tmp/dist-test-task2jzYy2/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515514800191-24103-0/minicluster-data/ts-0-root/wals/4ab1eaa54f904a649365473066f70724/wal-000000001 (ops 1-6)
I20260812 06:18:40.825989 24569 log.cc:1079] T 4ab1eaa54f904a649365473066f70724 P 5973ac8c04d8457e980e80784abb5aa7: Deleting log segment in path: /tmp/dist-test-task2jzYy2/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515514800191-24103-0/minicluster-data/ts-0-root/wals/4ab1eaa54f904a649365473066f70724/wal-000000002 (ops 7-11)
I20260812 06:18:40.830119 24569 maintenance_manager.cc:643] P 5973ac8c04d8457e980e80784abb5aa7: LogGCOp(4ab1eaa54f904a649365473066f70724) complete. Timing: real 0.004s	user 0.000s	sys 0.000s Metrics: {}
I20260812 06:18:40.830581 24664 maintenance_manager.cc:419] P 5973ac8c04d8457e980e80784abb5aa7: Scheduling FlushDeltaMemStoresOp(4ab1eaa54f904a649365473066f70724): perf score=1.196750
I20260812 06:18:40.841928 24569 maintenance_manager.cc:643] P 5973ac8c04d8457e980e80784abb5aa7: FlushDeltaMemStoresOp(4ab1eaa54f904a649365473066f70724) complete. Timing: real 0.011s	user 0.005s	sys 0.001s Metrics: {"bytes_written":2543708,"delete_count":0,"lbm_write_time_us":2474,"lbm_writes_lt_1ms":65,"reinsert_count":0,"update_count":310}
I20260812 06:18:40.842408 24664 maintenance_manager.cc:419] P 5973ac8c04d8457e980e80784abb5aa7: Scheduling FlushDeltaMemStoresOp(4ab1eaa54f904a649365473066f70724): perf score=2.188937
I20260812 06:18:40.855531 24569 maintenance_manager.cc:643] P 5973ac8c04d8457e980e80784abb5aa7: FlushDeltaMemStoresOp(4ab1eaa54f904a649365473066f70724) complete. Timing: real 0.013s	user 0.010s	sys 0.001s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":5022,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:18:40.856020 24664 maintenance_manager.cc:419] P 5973ac8c04d8457e980e80784abb5aa7: Scheduling MajorDeltaCompactionOp(4ab1eaa54f904a649365473066f70724): perf score=1.000000
I20260812 06:18:41.036654 24569 maintenance_manager.cc:643] P 5973ac8c04d8457e980e80784abb5aa7: MajorDeltaCompactionOp(4ab1eaa54f904a649365473066f70724) complete. Timing: real 0.180s	user 0.101s	sys 0.075s Metrics: {"cfile_cache_miss":533,"cfile_cache_miss_bytes":24774751,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":1046,"lbm_read_time_us":12028,"lbm_reads_lt_1ms":573,"lbm_write_time_us":29495,"lbm_writes_lt_1ms":543,"mutex_wait_us":145,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":3712,"thread_start_us":342,"threads_started":5,"update_count":2500}
I20260812 06:18:41.037438 24664 maintenance_manager.cc:419] P 5973ac8c04d8457e980e80784abb5aa7: Scheduling FlushDeltaMemStoresOp(4ab1eaa54f904a649365473066f70724): perf score=14.095187
I20260812 06:18:41.086194 24569 maintenance_manager.cc:643] P 5973ac8c04d8457e980e80784abb5aa7: FlushDeltaMemStoresOp(4ab1eaa54f904a649365473066f70724) complete. Timing: real 0.049s	user 0.031s	sys 0.012s Metrics: {"bytes_written":16409903,"delete_count":0,"lbm_write_time_us":20879,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:18:41.086767 24664 maintenance_manager.cc:419] P 5973ac8c04d8457e980e80784abb5aa7: Scheduling UndoDeltaBlockGCOp(4ab1eaa54f904a649365473066f70724): 16411395 bytes on disk
I20260812 06:18:41.087260 24569 maintenance_manager.cc:643] P 5973ac8c04d8457e980e80784abb5aa7: UndoDeltaBlockGCOp(4ab1eaa54f904a649365473066f70724) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":47,"lbm_reads_lt_1ms":4}
I20260812 06:18:41.087673 24664 maintenance_manager.cc:419] P 5973ac8c04d8457e980e80784abb5aa7: Scheduling MajorDeltaCompactionOp(4ab1eaa54f904a649365473066f70724): perf score=1.000000
I20260812 06:18:41.236483 24569 maintenance_manager.cc:643] P 5973ac8c04d8457e980e80784abb5aa7: MajorDeltaCompactionOp(4ab1eaa54f904a649365473066f70724) complete. Timing: real 0.149s	user 0.096s	sys 0.052s Metrics: {"cfile_cache_miss":431,"cfile_cache_miss_bytes":20672159,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":1,"delta_iterators_relevant":1,"dirs.queue_time_us":159,"lbm_read_time_us":10353,"lbm_reads_lt_1ms":463,"lbm_write_time_us":24338,"lbm_writes_lt_1ms":443,"mutex_wait_us":60,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":1920,"update_count":2000}
I20260812 06:18:41.237181 24664 maintenance_manager.cc:419] P 5973ac8c04d8457e980e80784abb5aa7: Scheduling FlushDeltaMemStoresOp(4ab1eaa54f904a649365473066f70724): perf score=14.095187
I20260812 06:18:41.287964 24569 maintenance_manager.cc:643] P 5973ac8c04d8457e980e80784abb5aa7: FlushDeltaMemStoresOp(4ab1eaa54f904a649365473066f70724) complete. Timing: real 0.051s	user 0.029s	sys 0.019s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":22550,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:18:41.288565 24664 maintenance_manager.cc:419] P 5973ac8c04d8457e980e80784abb5aa7: Scheduling FlushDeltaMemStoresOp(4ab1eaa54f904a649365473066f70724): perf score=2.188937
I20260812 06:18:41.304006 24569 maintenance_manager.cc:643] P 5973ac8c04d8457e980e80784abb5aa7: FlushDeltaMemStoresOp(4ab1eaa54f904a649365473066f70724) complete. Timing: real 0.015s	user 0.005s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5780,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:41.304683 24664 maintenance_manager.cc:419] P 5973ac8c04d8457e980e80784abb5aa7: Scheduling MajorDeltaCompactionOp(4ab1eaa54f904a649365473066f70724): perf score=1.000000
I20260812 06:18:41.489228 24569 maintenance_manager.cc:643] P 5973ac8c04d8457e980e80784abb5aa7: MajorDeltaCompactionOp(4ab1eaa54f904a649365473066f70724) complete. Timing: real 0.184s	user 0.112s	sys 0.068s 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":317,"lbm_read_time_us":12152,"lbm_reads_lt_1ms":572,"lbm_write_time_us":30672,"lbm_writes_lt_1ms":543,"mutex_wait_us":76,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":12544,"update_count":2500}
I20260812 06:18:41.489902 24664 maintenance_manager.cc:419] P 5973ac8c04d8457e980e80784abb5aa7: Scheduling FlushDeltaMemStoresOp(4ab1eaa54f904a649365473066f70724): perf score=14.095187
I20260812 06:18:41.542376 24569 maintenance_manager.cc:643] P 5973ac8c04d8457e980e80784abb5aa7: FlushDeltaMemStoresOp(4ab1eaa54f904a649365473066f70724) complete. Timing: real 0.052s	user 0.036s	sys 0.014s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":21711,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":402,"reinsert_count":0,"update_count":2000}
I20260812 06:18:41.542853 24664 maintenance_manager.cc:419] P 5973ac8c04d8457e980e80784abb5aa7: Scheduling FlushDeltaMemStoresOp(4ab1eaa54f904a649365473066f70724): perf score=2.188937
I20260812 06:18:41.558566 24569 maintenance_manager.cc:643] P 5973ac8c04d8457e980e80784abb5aa7: FlushDeltaMemStoresOp(4ab1eaa54f904a649365473066f70724) complete. Timing: real 0.015s	user 0.003s	sys 0.012s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6129,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:41.559190 24664 maintenance_manager.cc:419] P 5973ac8c04d8457e980e80784abb5aa7: Scheduling MajorDeltaCompactionOp(4ab1eaa54f904a649365473066f70724): perf score=1.000000
I20260812 06:18:41.711665 24569 maintenance_manager.cc:643] P 5973ac8c04d8457e980e80784abb5aa7: MajorDeltaCompactionOp(4ab1eaa54f904a649365473066f70724) complete. Timing: real 0.152s	user 0.109s	sys 0.038s 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":235,"lbm_read_time_us":9754,"lbm_reads_lt_1ms":572,"lbm_write_time_us":29063,"lbm_writes_lt_1ms":543,"mutex_wait_us":44,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":12288,"update_count":2500}
I20260812 06:18:41.712423 24664 maintenance_manager.cc:419] P 5973ac8c04d8457e980e80784abb5aa7: Scheduling FlushDeltaMemStoresOp(4ab1eaa54f904a649365473066f70724): perf score=11.118625
I20260812 06:18:41.754420 24569 maintenance_manager.cc:643] P 5973ac8c04d8457e980e80784abb5aa7: FlushDeltaMemStoresOp(4ab1eaa54f904a649365473066f70724) complete. Timing: real 0.042s	user 0.019s	sys 0.021s Metrics: {"bytes_written":12717735,"delete_count":0,"lbm_write_time_us":16219,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":312,"reinsert_count":0,"update_count":1550}
I20260812 06:18:41.754905 24664 maintenance_manager.cc:419] P 5973ac8c04d8457e980e80784abb5aa7: Scheduling FlushDeltaMemStoresOp(4ab1eaa54f904a649365473066f70724): perf score=2.188937
I20260812 06:18:41.768183 24569 maintenance_manager.cc:643] P 5973ac8c04d8457e980e80784abb5aa7: FlushDeltaMemStoresOp(4ab1eaa54f904a649365473066f70724) complete. Timing: real 0.013s	user 0.001s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4243,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:41.768627 24664 maintenance_manager.cc:419] P 5973ac8c04d8457e980e80784abb5aa7: Scheduling FlushDeltaMemStoresOp(4ab1eaa54f904a649365473066f70724): perf score=2.188937
I20260812 06:18:41.777750 24569 maintenance_manager.cc:643] P 5973ac8c04d8457e980e80784abb5aa7: FlushDeltaMemStoresOp(4ab1eaa54f904a649365473066f70724) complete. Timing: real 0.009s	user 0.004s	sys 0.004s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3428,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:18:41.778152 24664 maintenance_manager.cc:419] P 5973ac8c04d8457e980e80784abb5aa7: Scheduling MajorDeltaCompactionOp(4ab1eaa54f904a649365473066f70724): perf score=1.000000
I20260812 06:18:41.933756 24569 maintenance_manager.cc:643] P 5973ac8c04d8457e980e80784abb5aa7: MajorDeltaCompactionOp(4ab1eaa54f904a649365473066f70724) complete. Timing: real 0.155s	user 0.114s	sys 0.033s Metrics: {"cfile_cache_miss":533,"cfile_cache_miss_bytes":24774799,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":354,"lbm_read_time_us":10686,"lbm_reads_lt_1ms":573,"lbm_write_time_us":30723,"lbm_writes_lt_1ms":543,"mutex_wait_us":37,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":14592,"update_count":2500}
I20260812 06:18:41.934366 24664 maintenance_manager.cc:419] P 5973ac8c04d8457e980e80784abb5aa7: Scheduling FlushDeltaMemStoresOp(4ab1eaa54f904a649365473066f70724): perf score=14.095187
I20260812 06:18:41.980264 24569 maintenance_manager.cc:643] P 5973ac8c04d8457e980e80784abb5aa7: FlushDeltaMemStoresOp(4ab1eaa54f904a649365473066f70724) complete. Timing: real 0.046s	user 0.030s	sys 0.010s Metrics: {"bytes_written":16409903,"delete_count":0,"lbm_write_time_us":18326,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":402,"reinsert_count":0,"update_count":2000}
I20260812 06:18:41.980770 24664 maintenance_manager.cc:419] P 5973ac8c04d8457e980e80784abb5aa7: Scheduling FlushDeltaMemStoresOp(4ab1eaa54f904a649365473066f70724): perf score=2.188937
I20260812 06:18:41.991243 24569 maintenance_manager.cc:643] P 5973ac8c04d8457e980e80784abb5aa7: FlushDeltaMemStoresOp(4ab1eaa54f904a649365473066f70724) complete. Timing: real 0.010s	user 0.008s	sys 0.001s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4161,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:41.991683 24664 maintenance_manager.cc:419] P 5973ac8c04d8457e980e80784abb5aa7: Scheduling FlushMRSOp(4ab1eaa54f904a649365473066f70724): perf score=1.000000
I20260812 06:18:42.023988 24569 maintenance_manager.cc:643] P 5973ac8c04d8457e980e80784abb5aa7: FlushMRSOp(4ab1eaa54f904a649365473066f70724) complete. Timing: real 0.032s	user 0.024s	sys 0.006s Metrics: {"bytes_written":1193503,"cfile_init":1,"dirs.queue_time_us":49,"dirs.run_cpu_time_us":189,"dirs.run_wall_time_us":1346,"drs_written":1,"lbm_read_time_us":53,"lbm_reads_lt_1ms":4,"lbm_write_time_us":2040,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":29}
I20260812 06:18:42.024637 24664 maintenance_manager.cc:419] P 5973ac8c04d8457e980e80784abb5aa7: Scheduling LogGCOp(4ab1eaa54f904a649365473066f70724): free 115943189 bytes of WAL
I20260812 06:18:42.024844 24569 log_reader.cc:385] T 4ab1eaa54f904a649365473066f70724: removed 11 log segments from log reader
I20260812 06:18:42.024894 24569 log.cc:1079] T 4ab1eaa54f904a649365473066f70724 P 5973ac8c04d8457e980e80784abb5aa7: Deleting log segment in path: /tmp/dist-test-task2jzYy2/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515514800191-24103-0/minicluster-data/ts-0-root/wals/4ab1eaa54f904a649365473066f70724/wal-000000003 (ops 12-16)
I20260812 06:18:42.024933 24569 log.cc:1079] T 4ab1eaa54f904a649365473066f70724 P 5973ac8c04d8457e980e80784abb5aa7: Deleting log segment in path: /tmp/dist-test-task2jzYy2/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515514800191-24103-0/minicluster-data/ts-0-root/wals/4ab1eaa54f904a649365473066f70724/wal-000000004 (ops 17-21)
I20260812 06:18:42.024966 24569 log.cc:1079] T 4ab1eaa54f904a649365473066f70724 P 5973ac8c04d8457e980e80784abb5aa7: Deleting log segment in path: /tmp/dist-test-task2jzYy2/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515514800191-24103-0/minicluster-data/ts-0-root/wals/4ab1eaa54f904a649365473066f70724/wal-000000005 (ops 22-26)
I20260812 06:18:42.024988 24569 log.cc:1079] T 4ab1eaa54f904a649365473066f70724 P 5973ac8c04d8457e980e80784abb5aa7: Deleting log segment in path: /tmp/dist-test-task2jzYy2/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515514800191-24103-0/minicluster-data/ts-0-root/wals/4ab1eaa54f904a649365473066f70724/wal-000000006 (ops 27-31)
I20260812 06:18:42.025010 24569 log.cc:1079] T 4ab1eaa54f904a649365473066f70724 P 5973ac8c04d8457e980e80784abb5aa7: Deleting log segment in path: /tmp/dist-test-task2jzYy2/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515514800191-24103-0/minicluster-data/ts-0-root/wals/4ab1eaa54f904a649365473066f70724/wal-000000007 (ops 32-36)
I20260812 06:18:42.025058 24569 log.cc:1079] T 4ab1eaa54f904a649365473066f70724 P 5973ac8c04d8457e980e80784abb5aa7: Deleting log segment in path: /tmp/dist-test-task2jzYy2/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515514800191-24103-0/minicluster-data/ts-0-root/wals/4ab1eaa54f904a649365473066f70724/wal-000000008 (ops 37-41)
I20260812 06:18:42.025084 24569 log.cc:1079] T 4ab1eaa54f904a649365473066f70724 P 5973ac8c04d8457e980e80784abb5aa7: Deleting log segment in path: /tmp/dist-test-task2jzYy2/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515514800191-24103-0/minicluster-data/ts-0-root/wals/4ab1eaa54f904a649365473066f70724/wal-000000009 (ops 42-46)
I20260812 06:18:42.025115 24569 log.cc:1079] T 4ab1eaa54f904a649365473066f70724 P 5973ac8c04d8457e980e80784abb5aa7: Deleting log segment in path: /tmp/dist-test-task2jzYy2/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515514800191-24103-0/minicluster-data/ts-0-root/wals/4ab1eaa54f904a649365473066f70724/wal-000000010 (ops 47-51)
I20260812 06:18:42.025144 24569 log.cc:1079] T 4ab1eaa54f904a649365473066f70724 P 5973ac8c04d8457e980e80784abb5aa7: Deleting log segment in path: /tmp/dist-test-task2jzYy2/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515514800191-24103-0/minicluster-data/ts-0-root/wals/4ab1eaa54f904a649365473066f70724/wal-000000011 (ops 52-56)
I20260812 06:18:42.025172 24569 log.cc:1079] T 4ab1eaa54f904a649365473066f70724 P 5973ac8c04d8457e980e80784abb5aa7: Deleting log segment in path: /tmp/dist-test-task2jzYy2/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515514800191-24103-0/minicluster-data/ts-0-root/wals/4ab1eaa54f904a649365473066f70724/wal-000000012 (ops 57-61)
I20260812 06:18:42.025207 24569 log.cc:1079] T 4ab1eaa54f904a649365473066f70724 P 5973ac8c04d8457e980e80784abb5aa7: Deleting log segment in path: /tmp/dist-test-task2jzYy2/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515514800191-24103-0/minicluster-data/ts-0-root/wals/4ab1eaa54f904a649365473066f70724/wal-000000013 (ops 62-66)
I20260812 06:18:42.054490 24569 maintenance_manager.cc:643] P 5973ac8c04d8457e980e80784abb5aa7: LogGCOp(4ab1eaa54f904a649365473066f70724) complete. Timing: real 0.030s	user 0.000s	sys 0.029s Metrics: {}
I20260812 06:18:42.054986 24664 maintenance_manager.cc:419] P 5973ac8c04d8457e980e80784abb5aa7: Scheduling UndoDeltaBlockGCOp(4ab1eaa54f904a649365473066f70724): 463 bytes on disk
I20260812 06:18:42.055428 24569 maintenance_manager.cc:643] P 5973ac8c04d8457e980e80784abb5aa7: UndoDeltaBlockGCOp(4ab1eaa54f904a649365473066f70724) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":50,"lbm_reads_lt_1ms":4}
I20260812 06:18:42.055888 24664 maintenance_manager.cc:419] P 5973ac8c04d8457e980e80784abb5aa7: Scheduling FlushDeltaMemStoresOp(4ab1eaa54f904a649365473066f70724): perf score=2.188937
I20260812 06:18:42.073845 24569 maintenance_manager.cc:643] P 5973ac8c04d8457e980e80784abb5aa7: FlushDeltaMemStoresOp(4ab1eaa54f904a649365473066f70724) complete. Timing: real 0.018s	user 0.002s	sys 0.007s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4217,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:42.074412 24664 maintenance_manager.cc:419] P 5973ac8c04d8457e980e80784abb5aa7: Scheduling FlushDeltaMemStoresOp(4ab1eaa54f904a649365473066f70724): perf score=2.188937
I20260812 06:18:42.088850 24569 maintenance_manager.cc:643] P 5973ac8c04d8457e980e80784abb5aa7: FlushDeltaMemStoresOp(4ab1eaa54f904a649365473066f70724) complete. Timing: real 0.014s	user 0.012s	sys 0.000s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":5553,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:42.089437 24664 maintenance_manager.cc:419] P 5973ac8c04d8457e980e80784abb5aa7: Scheduling MajorDeltaCompactionOp(4ab1eaa54f904a649365473066f70724): perf score=1.000000
I20260812 06:18:42.326524 24569 maintenance_manager.cc:643] P 5973ac8c04d8457e980e80784abb5aa7: MajorDeltaCompactionOp(4ab1eaa54f904a649365473066f70724) complete. Timing: real 0.237s	user 0.171s	sys 0.060s Metrics: {"cfile_cache_miss":734,"cfile_cache_miss_bytes":32979749,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":969,"lbm_read_time_us":14779,"lbm_reads_lt_1ms":774,"lbm_write_time_us":39509,"lbm_writes_lt_1ms":743,"mutex_wait_us":307,"peak_mem_usage":87969044,"reinsert_count":0,"spinlock_wait_cycles":6016,"thread_start_us":100,"threads_started":1,"update_count":3500}
I20260812 06:18:42.327219 24664 maintenance_manager.cc:419] P 5973ac8c04d8457e980e80784abb5aa7: Scheduling FlushDeltaMemStoresOp(4ab1eaa54f904a649365473066f70724): perf score=15.087375
I20260812 06:18:42.380726 24569 maintenance_manager.cc:643] P 5973ac8c04d8457e980e80784abb5aa7: FlushDeltaMemStoresOp(4ab1eaa54f904a649365473066f70724) complete. Timing: real 0.053s	user 0.038s	sys 0.010s Metrics: {"bytes_written":16820142,"delete_count":0,"lbm_write_time_us":18934,"lbm_writes_lt_1ms":413,"reinsert_count":0,"update_count":2050}
I20260812 06:18:42.381265 24664 maintenance_manager.cc:419] P 5973ac8c04d8457e980e80784abb5aa7: Scheduling FlushDeltaMemStoresOp(4ab1eaa54f904a649365473066f70724): perf score=3.181125
I20260812 06:18:42.396603 24569 maintenance_manager.cc:643] P 5973ac8c04d8457e980e80784abb5aa7: FlushDeltaMemStoresOp(4ab1eaa54f904a649365473066f70724) complete. Timing: real 0.015s	user 0.014s	sys 0.000s Metrics: {"bytes_written":5046214,"delete_count":0,"lbm_write_time_us":6197,"lbm_writes_lt_1ms":126,"reinsert_count":0,"update_count":615}
I20260812 06:18:42.397017 24664 maintenance_manager.cc:419] P 5973ac8c04d8457e980e80784abb5aa7: Scheduling FlushDeltaMemStoresOp(4ab1eaa54f904a649365473066f70724): perf score=1.196750
I20260812 06:18:42.404819 24569 maintenance_manager.cc:643] P 5973ac8c04d8457e980e80784abb5aa7: FlushDeltaMemStoresOp(4ab1eaa54f904a649365473066f70724) complete. Timing: real 0.008s	user 0.003s	sys 0.003s Metrics: {"bytes_written":2748830,"delete_count":0,"lbm_write_time_us":2857,"lbm_writes_lt_1ms":70,"reinsert_count":0,"update_count":335}
I20260812 06:18:42.407617 24664 maintenance_manager.cc:419] P 5973ac8c04d8457e980e80784abb5aa7: Scheduling MajorDeltaCompactionOp(4ab1eaa54f904a649365473066f70724): perf score=1.000000
I20260812 06:18:42.628044 24569 maintenance_manager.cc:643] P 5973ac8c04d8457e980e80784abb5aa7: MajorDeltaCompactionOp(4ab1eaa54f904a649365473066f70724) complete. Timing: real 0.220s	user 0.141s	sys 0.066s Metrics: {"cfile_cache_miss":633,"cfile_cache_miss_bytes":28877186,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":313,"lbm_read_time_us":13833,"lbm_reads_lt_1ms":673,"lbm_write_time_us":33798,"lbm_writes_lt_1ms":643,"mutex_wait_us":3,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":16384,"update_count":3000}
I20260812 06:18:42.628664 24664 maintenance_manager.cc:419] P 5973ac8c04d8457e980e80784abb5aa7: Scheduling FlushDeltaMemStoresOp(4ab1eaa54f904a649365473066f70724): perf score=18.063937
I20260812 06:18:42.697214 24569 maintenance_manager.cc:643] P 5973ac8c04d8457e980e80784abb5aa7: FlushDeltaMemStoresOp(4ab1eaa54f904a649365473066f70724) complete. Timing: real 0.068s	user 0.034s	sys 0.024s Metrics: {"bytes_written":20512316,"delete_count":0,"lbm_write_time_us":27636,"lbm_writes_lt_1ms":503,"reinsert_count":0,"update_count":2500}
I20260812 06:18:42.697670 24664 maintenance_manager.cc:419] P 5973ac8c04d8457e980e80784abb5aa7: Scheduling FlushDeltaMemStoresOp(4ab1eaa54f904a649365473066f70724): perf score=2.188937
I20260812 06:18:42.708966 24569 maintenance_manager.cc:643] P 5973ac8c04d8457e980e80784abb5aa7: FlushDeltaMemStoresOp(4ab1eaa54f904a649365473066f70724) complete. Timing: real 0.011s	user 0.006s	sys 0.003s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4073,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:42.709463 24664 maintenance_manager.cc:419] P 5973ac8c04d8457e980e80784abb5aa7: Scheduling MajorDeltaCompactionOp(4ab1eaa54f904a649365473066f70724): perf score=1.000000
I20260812 06:18:42.905254 24569 maintenance_manager.cc:643] P 5973ac8c04d8457e980e80784abb5aa7: MajorDeltaCompactionOp(4ab1eaa54f904a649365473066f70724) complete. Timing: real 0.196s	user 0.121s	sys 0.072s Metrics: {"cfile_cache_miss":632,"cfile_cache_miss_bytes":28877103,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":955,"lbm_read_time_us":12556,"lbm_reads_lt_1ms":672,"lbm_write_time_us":33540,"lbm_writes_lt_1ms":643,"mutex_wait_us":56,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":4352,"update_count":3000}
I20260812 06:18:42.906047 24664 maintenance_manager.cc:419] P 5973ac8c04d8457e980e80784abb5aa7: Scheduling FlushDeltaMemStoresOp(4ab1eaa54f904a649365473066f70724): perf score=16.079562
I20260812 06:18:42.965317 24569 maintenance_manager.cc:643] P 5973ac8c04d8457e980e80784abb5aa7: FlushDeltaMemStoresOp(4ab1eaa54f904a649365473066f70724) complete. Timing: real 0.059s	user 0.035s	sys 0.019s Metrics: {"bytes_written":17886771,"delete_count":0,"lbm_write_time_us":25502,"lbm_writes_lt_1ms":439,"reinsert_count":0,"update_count":2180}
I20260812 06:18:42.965758 24664 maintenance_manager.cc:419] P 5973ac8c04d8457e980e80784abb5aa7: Scheduling FlushDeltaMemStoresOp(4ab1eaa54f904a649365473066f70724): perf score=1.196750
I20260812 06:18:42.976785 24569 maintenance_manager.cc:643] P 5973ac8c04d8457e980e80784abb5aa7: FlushDeltaMemStoresOp(4ab1eaa54f904a649365473066f70724) complete. Timing: real 0.011s	user 0.007s	sys 0.000s Metrics: {"bytes_written":3036009,"delete_count":0,"lbm_write_time_us":2934,"lbm_writes_lt_1ms":77,"reinsert_count":0,"update_count":370}
I20260812 06:18:42.977396 24664 maintenance_manager.cc:419] P 5973ac8c04d8457e980e80784abb5aa7: Scheduling FlushDeltaMemStoresOp(4ab1eaa54f904a649365473066f70724): perf score=2.188937
I20260812 06:18:42.987349 24569 maintenance_manager.cc:643] P 5973ac8c04d8457e980e80784abb5aa7: FlushDeltaMemStoresOp(4ab1eaa54f904a649365473066f70724) complete. Timing: real 0.010s	user 0.005s	sys 0.004s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3744,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:18:42.987774 24664 maintenance_manager.cc:419] P 5973ac8c04d8457e980e80784abb5aa7: Scheduling MajorDeltaCompactionOp(4ab1eaa54f904a649365473066f70724): perf score=1.000000
I20260812 06:18:43.185451 24569 maintenance_manager.cc:643] P 5973ac8c04d8457e980e80784abb5aa7: MajorDeltaCompactionOp(4ab1eaa54f904a649365473066f70724) complete. Timing: real 0.198s	user 0.117s	sys 0.080s Metrics: {"cfile_cache_miss":633,"cfile_cache_miss_bytes":28877185,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":1021,"lbm_read_time_us":13953,"lbm_reads_lt_1ms":673,"lbm_write_time_us":32034,"lbm_writes_lt_1ms":643,"mutex_wait_us":321,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":181888,"update_count":3000}
I20260812 06:18:43.186322 24664 maintenance_manager.cc:419] P 5973ac8c04d8457e980e80784abb5aa7: Scheduling FlushDeltaMemStoresOp(4ab1eaa54f904a649365473066f70724): perf score=16.079562
I20260812 06:18:43.254176 24569 maintenance_manager.cc:643] P 5973ac8c04d8457e980e80784abb5aa7: FlushDeltaMemStoresOp(4ab1eaa54f904a649365473066f70724) complete. Timing: real 0.068s	user 0.034s	sys 0.013s Metrics: {"bytes_written":17968822,"delete_count":0,"lbm_write_time_us":22674,"lbm_writes_lt_1ms":441,"reinsert_count":0,"update_count":2190}
I20260812 06:18:43.254745 24664 maintenance_manager.cc:419] P 5973ac8c04d8457e980e80784abb5aa7: Scheduling FlushDeltaMemStoresOp(4ab1eaa54f904a649365473066f70724): perf score=5.165500
I20260812 06:18:43.277851 24569 maintenance_manager.cc:643] P 5973ac8c04d8457e980e80784abb5aa7: FlushDeltaMemStoresOp(4ab1eaa54f904a649365473066f70724) complete. Timing: real 0.023s	user 0.013s	sys 0.004s Metrics: {"bytes_written":6646166,"delete_count":0,"lbm_write_time_us":8151,"lbm_writes_lt_1ms":165,"reinsert_count":0,"update_count":810}
I20260812 06:18:43.278367 24664 maintenance_manager.cc:419] P 5973ac8c04d8457e980e80784abb5aa7: Scheduling MajorDeltaCompactionOp(4ab1eaa54f904a649365473066f70724): perf score=1.000000
I20260812 06:18:43.488464 24569 maintenance_manager.cc:643] P 5973ac8c04d8457e980e80784abb5aa7: MajorDeltaCompactionOp(4ab1eaa54f904a649365473066f70724) complete. Timing: real 0.210s	user 0.139s	sys 0.068s Metrics: {"cfile_cache_miss":632,"cfile_cache_miss_bytes":28877110,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":827,"lbm_read_time_us":13605,"lbm_reads_lt_1ms":664,"lbm_write_time_us":32914,"lbm_writes_lt_1ms":643,"mutex_wait_us":308,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":9344,"update_count":3000}
I20260812 06:18:43.489056 24664 maintenance_manager.cc:419] P 5973ac8c04d8457e980e80784abb5aa7: Scheduling FlushDeltaMemStoresOp(4ab1eaa54f904a649365473066f70724): perf score=18.063937
I20260812 06:18:43.551285 24569 maintenance_manager.cc:643] P 5973ac8c04d8457e980e80784abb5aa7: FlushDeltaMemStoresOp(4ab1eaa54f904a649365473066f70724) complete. Timing: real 0.062s	user 0.028s	sys 0.032s Metrics: {"bytes_written":20512315,"delete_count":0,"lbm_write_time_us":28559,"lbm_writes_lt_1ms":503,"reinsert_count":0,"update_count":2500}
I20260812 06:18:43.551776 24664 maintenance_manager.cc:419] P 5973ac8c04d8457e980e80784abb5aa7: Scheduling FlushDeltaMemStoresOp(4ab1eaa54f904a649365473066f70724): perf score=2.188937
I20260812 06:18:43.563112 24569 maintenance_manager.cc:643] P 5973ac8c04d8457e980e80784abb5aa7: FlushDeltaMemStoresOp(4ab1eaa54f904a649365473066f70724) complete. Timing: real 0.011s	user 0.005s	sys 0.005s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4146,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:43.563846 24664 maintenance_manager.cc:419] P 5973ac8c04d8457e980e80784abb5aa7: Scheduling FlushMRSOp(4ab1eaa54f904a649365473066f70724): perf score=1.000000
I20260812 06:18:43.595585 24569 maintenance_manager.cc:643] P 5973ac8c04d8457e980e80784abb5aa7: FlushMRSOp(4ab1eaa54f904a649365473066f70724) complete. Timing: real 0.031s	user 0.026s	sys 0.005s Metrics: {"bytes_written":1316419,"cfile_init":1,"dirs.queue_time_us":72,"dirs.run_cpu_time_us":219,"dirs.run_wall_time_us":1709,"drs_written":1,"lbm_read_time_us":39,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1844,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":32}
I20260812 06:18:43.596207 24664 maintenance_manager.cc:419] P 5973ac8c04d8457e980e80784abb5aa7: Scheduling LogGCOp(4ab1eaa54f904a649365473066f70724): free 129320523 bytes of WAL
I20260812 06:18:43.596442 24569 log_reader.cc:385] T 4ab1eaa54f904a649365473066f70724: removed 13 log segments from log reader
I20260812 06:18:43.596485 24569 log.cc:1079] T 4ab1eaa54f904a649365473066f70724 P 5973ac8c04d8457e980e80784abb5aa7: Deleting log segment in path: /tmp/dist-test-task2jzYy2/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515514800191-24103-0/minicluster-data/ts-0-root/wals/4ab1eaa54f904a649365473066f70724/wal-000000014 (ops 67-71)
I20260812 06:18:43.596514 24569 log.cc:1079] T 4ab1eaa54f904a649365473066f70724 P 5973ac8c04d8457e980e80784abb5aa7: Deleting log segment in path: /tmp/dist-test-task2jzYy2/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515514800191-24103-0/minicluster-data/ts-0-root/wals/4ab1eaa54f904a649365473066f70724/wal-000000015 (ops 72-76)
I20260812 06:18:43.596590 24569 log.cc:1079] T 4ab1eaa54f904a649365473066f70724 P 5973ac8c04d8457e980e80784abb5aa7: Deleting log segment in path: /tmp/dist-test-task2jzYy2/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515514800191-24103-0/minicluster-data/ts-0-root/wals/4ab1eaa54f904a649365473066f70724/wal-000000016 (ops 77-81)
I20260812 06:18:43.596637 24569 log.cc:1079] T 4ab1eaa54f904a649365473066f70724 P 5973ac8c04d8457e980e80784abb5aa7: Deleting log segment in path: /tmp/dist-test-task2jzYy2/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515514800191-24103-0/minicluster-data/ts-0-root/wals/4ab1eaa54f904a649365473066f70724/wal-000000017 (ops 82-86)
I20260812 06:18:43.596678 24569 log.cc:1079] T 4ab1eaa54f904a649365473066f70724 P 5973ac8c04d8457e980e80784abb5aa7: Deleting log segment in path: /tmp/dist-test-task2jzYy2/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515514800191-24103-0/minicluster-data/ts-0-root/wals/4ab1eaa54f904a649365473066f70724/wal-000000018 (ops 87-91)
I20260812 06:18:43.596719 24569 log.cc:1079] T 4ab1eaa54f904a649365473066f70724 P 5973ac8c04d8457e980e80784abb5aa7: Deleting log segment in path: /tmp/dist-test-task2jzYy2/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515514800191-24103-0/minicluster-data/ts-0-root/wals/4ab1eaa54f904a649365473066f70724/wal-000000019 (ops 92-96)
I20260812 06:18:43.596760 24569 log.cc:1079] T 4ab1eaa54f904a649365473066f70724 P 5973ac8c04d8457e980e80784abb5aa7: Deleting log segment in path: /tmp/dist-test-task2jzYy2/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515514800191-24103-0/minicluster-data/ts-0-root/wals/4ab1eaa54f904a649365473066f70724/wal-000000020 (ops 97-100)
I20260812 06:18:43.596801 24569 log.cc:1079] T 4ab1eaa54f904a649365473066f70724 P 5973ac8c04d8457e980e80784abb5aa7: Deleting log segment in path: /tmp/dist-test-task2jzYy2/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515514800191-24103-0/minicluster-data/ts-0-root/wals/4ab1eaa54f904a649365473066f70724/wal-000000021 (ops 101-105)
I20260812 06:18:43.596841 24569 log.cc:1079] T 4ab1eaa54f904a649365473066f70724 P 5973ac8c04d8457e980e80784abb5aa7: Deleting log segment in path: /tmp/dist-test-task2jzYy2/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515514800191-24103-0/minicluster-data/ts-0-root/wals/4ab1eaa54f904a649365473066f70724/wal-000000022 (ops 106-110)
I20260812 06:18:43.596880 24569 log.cc:1079] T 4ab1eaa54f904a649365473066f70724 P 5973ac8c04d8457e980e80784abb5aa7: Deleting log segment in path: /tmp/dist-test-task2jzYy2/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515514800191-24103-0/minicluster-data/ts-0-root/wals/4ab1eaa54f904a649365473066f70724/wal-000000023 (ops 111-114)
I20260812 06:18:43.596920 24569 log.cc:1079] T 4ab1eaa54f904a649365473066f70724 P 5973ac8c04d8457e980e80784abb5aa7: Deleting log segment in path: /tmp/dist-test-task2jzYy2/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515514800191-24103-0/minicluster-data/ts-0-root/wals/4ab1eaa54f904a649365473066f70724/wal-000000024 (ops 115-119)
I20260812 06:18:43.596962 24569 log.cc:1079] T 4ab1eaa54f904a649365473066f70724 P 5973ac8c04d8457e980e80784abb5aa7: Deleting log segment in path: /tmp/dist-test-task2jzYy2/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515514800191-24103-0/minicluster-data/ts-0-root/wals/4ab1eaa54f904a649365473066f70724/wal-000000025 (ops 120-124)
I20260812 06:18:43.596999 24569 log.cc:1079] T 4ab1eaa54f904a649365473066f70724 P 5973ac8c04d8457e980e80784abb5aa7: Deleting log segment in path: /tmp/dist-test-task2jzYy2/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515514800191-24103-0/minicluster-data/ts-0-root/wals/4ab1eaa54f904a649365473066f70724/wal-000000026 (ops 125-129)
I20260812 06:18:43.625577 24569 maintenance_manager.cc:643] P 5973ac8c04d8457e980e80784abb5aa7: LogGCOp(4ab1eaa54f904a649365473066f70724) complete. Timing: real 0.029s	user 0.000s	sys 0.026s Metrics: {}
I20260812 06:18:43.626500 24664 maintenance_manager.cc:419] P 5973ac8c04d8457e980e80784abb5aa7: Scheduling FlushDeltaMemStoresOp(4ab1eaa54f904a649365473066f70724): perf score=5.165500
I20260812 06:18:43.642289 24569 maintenance_manager.cc:643] P 5973ac8c04d8457e980e80784abb5aa7: FlushDeltaMemStoresOp(4ab1eaa54f904a649365473066f70724) complete. Timing: real 0.016s	user 0.015s	sys 0.000s Metrics: {"bytes_written":6317966,"delete_count":0,"lbm_write_time_us":6201,"lbm_writes_lt_1ms":157,"reinsert_count":0,"update_count":770}
I20260812 06:18:43.642719 24664 maintenance_manager.cc:419] P 5973ac8c04d8457e980e80784abb5aa7: Scheduling FlushDeltaMemStoresOp(4ab1eaa54f904a649365473066f70724): perf score=1.000000
I20260812 06:18:43.651114 24569 maintenance_manager.cc:643] P 5973ac8c04d8457e980e80784abb5aa7: FlushDeltaMemStoresOp(4ab1eaa54f904a649365473066f70724) complete. Timing: real 0.008s	user 0.007s	sys 0.000s Metrics: {"bytes_written":1887302,"delete_count":0,"lbm_write_time_us":2612,"lbm_writes_lt_1ms":49,"reinsert_count":0,"update_count":230}
I20260812 06:18:43.651793 24664 maintenance_manager.cc:419] P 5973ac8c04d8457e980e80784abb5aa7: Scheduling MajorDeltaCompactionOp(4ab1eaa54f904a649365473066f70724): perf score=1.000000
I20260812 06:18:43.890009 24569 maintenance_manager.cc:643] P 5973ac8c04d8457e980e80784abb5aa7: MajorDeltaCompactionOp(4ab1eaa54f904a649365473066f70724) complete. Timing: real 0.238s	user 0.174s	sys 0.060s Metrics: {"cfile_cache_miss":834,"cfile_cache_miss_bytes":37082109,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":675,"lbm_read_time_us":16869,"lbm_reads_lt_1ms":866,"lbm_write_time_us":43285,"lbm_writes_lt_1ms":843,"mutex_wait_us":83,"peak_mem_usage":100395616,"reinsert_count":0,"spinlock_wait_cycles":9088,"thread_start_us":104,"threads_started":1,"update_count":4000}
I20260812 06:18:43.890779 24664 maintenance_manager.cc:419] P 5973ac8c04d8457e980e80784abb5aa7: Scheduling FlushDeltaMemStoresOp(4ab1eaa54f904a649365473066f70724): perf score=19.056125
I20260812 06:18:43.963896 24569 maintenance_manager.cc:643] P 5973ac8c04d8457e980e80784abb5aa7: FlushDeltaMemStoresOp(4ab1eaa54f904a649365473066f70724) complete. Timing: real 0.073s	user 0.051s	sys 0.008s Metrics: {"bytes_written":20922556,"delete_count":0,"lbm_write_time_us":26840,"lbm_writes_lt_1ms":513,"reinsert_count":0,"update_count":2550}
I20260812 06:18:43.964387 24664 maintenance_manager.cc:419] P 5973ac8c04d8457e980e80784abb5aa7: Scheduling FlushDeltaMemStoresOp(4ab1eaa54f904a649365473066f70724): perf score=6.157687
I20260812 06:18:43.989920 24569 maintenance_manager.cc:643] P 5973ac8c04d8457e980e80784abb5aa7: FlushDeltaMemStoresOp(4ab1eaa54f904a649365473066f70724) complete. Timing: real 0.025s	user 0.008s	sys 0.012s Metrics: {"bytes_written":7794838,"delete_count":0,"lbm_write_time_us":9737,"lbm_writes_lt_1ms":193,"reinsert_count":0,"update_count":950}
I20260812 06:18:43.990675 24664 maintenance_manager.cc:419] P 5973ac8c04d8457e980e80784abb5aa7: Scheduling UndoDeltaBlockGCOp(4ab1eaa54f904a649365473066f70724): 491 bytes on disk
I20260812 06:18:43.991171 24569 maintenance_manager.cc:643] P 5973ac8c04d8457e980e80784abb5aa7: UndoDeltaBlockGCOp(4ab1eaa54f904a649365473066f70724) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":75,"lbm_reads_lt_1ms":4}
I20260812 06:18:43.991839 24664 maintenance_manager.cc:419] P 5973ac8c04d8457e980e80784abb5aa7: Scheduling MajorDeltaCompactionOp(4ab1eaa54f904a649365473066f70724): perf score=1.000000
I20260812 06:18:44.200393 24569 maintenance_manager.cc:643] P 5973ac8c04d8457e980e80784abb5aa7: MajorDeltaCompactionOp(4ab1eaa54f904a649365473066f70724) complete. Timing: real 0.208s	user 0.150s	sys 0.056s Metrics: {"cfile_cache_miss":732,"cfile_cache_miss_bytes":32979516,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":229,"lbm_read_time_us":16577,"lbm_reads_lt_1ms":764,"lbm_write_time_us":42036,"lbm_writes_lt_1ms":743,"mutex_wait_us":44,"peak_mem_usage":87969044,"reinsert_count":0,"spinlock_wait_cycles":10368,"update_count":3500}
I20260812 06:18:44.200974 24664 maintenance_manager.cc:419] P 5973ac8c04d8457e980e80784abb5aa7: Scheduling FlushDeltaMemStoresOp(4ab1eaa54f904a649365473066f70724): perf score=18.063937
I20260812 06:18:44.256214 24569 maintenance_manager.cc:643] P 5973ac8c04d8457e980e80784abb5aa7: FlushDeltaMemStoresOp(4ab1eaa54f904a649365473066f70724) complete. Timing: real 0.055s	user 0.023s	sys 0.028s Metrics: {"bytes_written":20512315,"delete_count":0,"lbm_write_time_us":23838,"lbm_writes_lt_1ms":503,"reinsert_count":0,"update_count":2500}
I20260812 06:18:44.256686 24664 maintenance_manager.cc:419] P 5973ac8c04d8457e980e80784abb5aa7: Scheduling FlushDeltaMemStoresOp(4ab1eaa54f904a649365473066f70724): perf score=2.188937
I20260812 06:18:44.267340 24569 maintenance_manager.cc:643] P 5973ac8c04d8457e980e80784abb5aa7: FlushDeltaMemStoresOp(4ab1eaa54f904a649365473066f70724) complete. Timing: real 0.010s	user 0.005s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4240,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:44.267791 24664 maintenance_manager.cc:419] P 5973ac8c04d8457e980e80784abb5aa7: Scheduling MajorDeltaCompactionOp(4ab1eaa54f904a649365473066f70724): perf score=1.000000
I20260812 06:18:44.445458 24569 maintenance_manager.cc:643] P 5973ac8c04d8457e980e80784abb5aa7: MajorDeltaCompactionOp(4ab1eaa54f904a649365473066f70724) complete. Timing: real 0.177s	user 0.142s	sys 0.032s Metrics: {"cfile_cache_miss":632,"cfile_cache_miss_bytes":28877102,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":920,"lbm_read_time_us":14162,"lbm_reads_lt_1ms":672,"lbm_write_time_us":32938,"lbm_writes_lt_1ms":643,"mutex_wait_us":267,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":6528,"update_count":3000}
I20260812 06:18:44.446036 24664 maintenance_manager.cc:419] P 5973ac8c04d8457e980e80784abb5aa7: Scheduling FlushDeltaMemStoresOp(4ab1eaa54f904a649365473066f70724): perf score=14.095187
I20260812 06:18:44.498857 24569 maintenance_manager.cc:643] P 5973ac8c04d8457e980e80784abb5aa7: FlushDeltaMemStoresOp(4ab1eaa54f904a649365473066f70724) complete. Timing: real 0.053s	user 0.033s	sys 0.015s Metrics: {"bytes_written":16409900,"delete_count":0,"lbm_write_time_us":21506,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:18:44.499372 24664 maintenance_manager.cc:419] P 5973ac8c04d8457e980e80784abb5aa7: Scheduling FlushDeltaMemStoresOp(4ab1eaa54f904a649365473066f70724): perf score=2.188937
I20260812 06:18:44.510488 24569 maintenance_manager.cc:643] P 5973ac8c04d8457e980e80784abb5aa7: FlushDeltaMemStoresOp(4ab1eaa54f904a649365473066f70724) complete. Timing: real 0.011s	user 0.007s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4113,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:44.511210 24664 maintenance_manager.cc:419] P 5973ac8c04d8457e980e80784abb5aa7: Scheduling MajorDeltaCompactionOp(4ab1eaa54f904a649365473066f70724): perf score=1.000000
I20260812 06:18:44.666679 24569 maintenance_manager.cc:643] P 5973ac8c04d8457e980e80784abb5aa7: MajorDeltaCompactionOp(4ab1eaa54f904a649365473066f70724) complete. Timing: real 0.155s	user 0.119s	sys 0.035s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774687,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":118,"lbm_read_time_us":11923,"lbm_reads_lt_1ms":572,"lbm_write_time_us":30467,"lbm_writes_lt_1ms":543,"mutex_wait_us":26,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":52480,"update_count":2500}
I20260812 06:18:44.667448 24664 maintenance_manager.cc:419] P 5973ac8c04d8457e980e80784abb5aa7: Scheduling FlushDeltaMemStoresOp(4ab1eaa54f904a649365473066f70724): perf score=11.118625
I20260812 06:18:44.705793 24569 maintenance_manager.cc:643] P 5973ac8c04d8457e980e80784abb5aa7: FlushDeltaMemStoresOp(4ab1eaa54f904a649365473066f70724) complete. Timing: real 0.038s	user 0.022s	sys 0.012s Metrics: {"bytes_written":12717735,"delete_count":0,"lbm_write_time_us":15939,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:18:44.706476 24664 maintenance_manager.cc:419] P 5973ac8c04d8457e980e80784abb5aa7: Scheduling FlushDeltaMemStoresOp(4ab1eaa54f904a649365473066f70724): perf score=2.188937
I20260812 06:18:44.723094 24569 maintenance_manager.cc:643] P 5973ac8c04d8457e980e80784abb5aa7: FlushDeltaMemStoresOp(4ab1eaa54f904a649365473066f70724) complete. Timing: real 0.016s	user 0.007s	sys 0.005s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":4587,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:18:44.723616 24664 maintenance_manager.cc:419] P 5973ac8c04d8457e980e80784abb5aa7: Scheduling MajorDeltaCompactionOp(4ab1eaa54f904a649365473066f70724): perf score=1.000000
I20260812 06:18:44.880770 24569 maintenance_manager.cc:643] P 5973ac8c04d8457e980e80784abb5aa7: MajorDeltaCompactionOp(4ab1eaa54f904a649365473066f70724) complete. Timing: real 0.157s	user 0.119s	sys 0.033s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672268,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":147,"lbm_read_time_us":11098,"lbm_reads_lt_1ms":464,"lbm_write_time_us":24764,"lbm_writes_lt_1ms":443,"mutex_wait_us":50,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":15488,"update_count":2000}
I20260812 06:18:44.881433 24664 maintenance_manager.cc:419] P 5973ac8c04d8457e980e80784abb5aa7: Scheduling FlushDeltaMemStoresOp(4ab1eaa54f904a649365473066f70724): perf score=14.095187
I20260812 06:18:44.930428 24569 maintenance_manager.cc:643] P 5973ac8c04d8457e980e80784abb5aa7: FlushDeltaMemStoresOp(4ab1eaa54f904a649365473066f70724) complete. Timing: real 0.049s	user 0.033s	sys 0.015s Metrics: {"bytes_written":16409900,"delete_count":0,"lbm_write_time_us":20966,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:18:44.931021 24664 maintenance_manager.cc:419] P 5973ac8c04d8457e980e80784abb5aa7: Scheduling FlushDeltaMemStoresOp(4ab1eaa54f904a649365473066f70724): perf score=2.188937
I20260812 06:18:44.956384 24569 maintenance_manager.cc:643] P 5973ac8c04d8457e980e80784abb5aa7: FlushDeltaMemStoresOp(4ab1eaa54f904a649365473066f70724) complete. Timing: real 0.025s	user 0.015s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5812,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:44.957223 24664 maintenance_manager.cc:419] P 5973ac8c04d8457e980e80784abb5aa7: Scheduling FlushMRSOp(4ab1eaa54f904a649365473066f70724): perf score=1.000000
I20260812 06:18:44.988436 24569 maintenance_manager.cc:643] P 5973ac8c04d8457e980e80784abb5aa7: FlushMRSOp(4ab1eaa54f904a649365473066f70724) complete. Timing: real 0.031s	user 0.023s	sys 0.004s Metrics: {"bytes_written":1234477,"cfile_init":1,"dirs.queue_time_us":98,"dirs.run_cpu_time_us":201,"dirs.run_wall_time_us":1659,"drs_written":1,"lbm_read_time_us":51,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1751,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":30}
I20260812 06:18:44.989164 24664 maintenance_manager.cc:419] P 5973ac8c04d8457e980e80784abb5aa7: Scheduling LogGCOp(4ab1eaa54f904a649365473066f70724): free 124710570 bytes of WAL
I20260812 06:18:44.989418 24569 log_reader.cc:385] T 4ab1eaa54f904a649365473066f70724: removed 12 log segments from log reader
I20260812 06:18:44.989460 24569 log.cc:1079] T 4ab1eaa54f904a649365473066f70724 P 5973ac8c04d8457e980e80784abb5aa7: Deleting log segment in path: /tmp/dist-test-task2jzYy2/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515514800191-24103-0/minicluster-data/ts-0-root/wals/4ab1eaa54f904a649365473066f70724/wal-000000027 (ops 130-134)
I20260812 06:18:44.989488 24569 log.cc:1079] T 4ab1eaa54f904a649365473066f70724 P 5973ac8c04d8457e980e80784abb5aa7: Deleting log segment in path: /tmp/dist-test-task2jzYy2/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515514800191-24103-0/minicluster-data/ts-0-root/wals/4ab1eaa54f904a649365473066f70724/wal-000000028 (ops 135-139)
I20260812 06:18:44.989532 24569 log.cc:1079] T 4ab1eaa54f904a649365473066f70724 P 5973ac8c04d8457e980e80784abb5aa7: Deleting log segment in path: /tmp/dist-test-task2jzYy2/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515514800191-24103-0/minicluster-data/ts-0-root/wals/4ab1eaa54f904a649365473066f70724/wal-000000029 (ops 140-144)
I20260812 06:18:44.989574 24569 log.cc:1079] T 4ab1eaa54f904a649365473066f70724 P 5973ac8c04d8457e980e80784abb5aa7: Deleting log segment in path: /tmp/dist-test-task2jzYy2/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515514800191-24103-0/minicluster-data/ts-0-root/wals/4ab1eaa54f904a649365473066f70724/wal-000000030 (ops 145-149)
I20260812 06:18:44.989619 24569 log.cc:1079] T 4ab1eaa54f904a649365473066f70724 P 5973ac8c04d8457e980e80784abb5aa7: Deleting log segment in path: /tmp/dist-test-task2jzYy2/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515514800191-24103-0/minicluster-data/ts-0-root/wals/4ab1eaa54f904a649365473066f70724/wal-000000031 (ops 150-154)
I20260812 06:18:44.989677 24569 log.cc:1079] T 4ab1eaa54f904a649365473066f70724 P 5973ac8c04d8457e980e80784abb5aa7: Deleting log segment in path: /tmp/dist-test-task2jzYy2/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515514800191-24103-0/minicluster-data/ts-0-root/wals/4ab1eaa54f904a649365473066f70724/wal-000000032 (ops 155-159)
I20260812 06:18:44.989718 24569 log.cc:1079] T 4ab1eaa54f904a649365473066f70724 P 5973ac8c04d8457e980e80784abb5aa7: Deleting log segment in path: /tmp/dist-test-task2jzYy2/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515514800191-24103-0/minicluster-data/ts-0-root/wals/4ab1eaa54f904a649365473066f70724/wal-000000033 (ops 160-164)
I20260812 06:18:44.989758 24569 log.cc:1079] T 4ab1eaa54f904a649365473066f70724 P 5973ac8c04d8457e980e80784abb5aa7: Deleting log segment in path: /tmp/dist-test-task2jzYy2/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515514800191-24103-0/minicluster-data/ts-0-root/wals/4ab1eaa54f904a649365473066f70724/wal-000000034 (ops 165-169)
I20260812 06:18:44.989799 24569 log.cc:1079] T 4ab1eaa54f904a649365473066f70724 P 5973ac8c04d8457e980e80784abb5aa7: Deleting log segment in path: /tmp/dist-test-task2jzYy2/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515514800191-24103-0/minicluster-data/ts-0-root/wals/4ab1eaa54f904a649365473066f70724/wal-000000035 (ops 170-174)
I20260812 06:18:44.989837 24569 log.cc:1079] T 4ab1eaa54f904a649365473066f70724 P 5973ac8c04d8457e980e80784abb5aa7: Deleting log segment in path: /tmp/dist-test-task2jzYy2/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515514800191-24103-0/minicluster-data/ts-0-root/wals/4ab1eaa54f904a649365473066f70724/wal-000000036 (ops 175-179)
I20260812 06:18:44.989877 24569 log.cc:1079] T 4ab1eaa54f904a649365473066f70724 P 5973ac8c04d8457e980e80784abb5aa7: Deleting log segment in path: /tmp/dist-test-task2jzYy2/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515514800191-24103-0/minicluster-data/ts-0-root/wals/4ab1eaa54f904a649365473066f70724/wal-000000037 (ops 180-184)
I20260812 06:18:44.989915 24569 log.cc:1079] T 4ab1eaa54f904a649365473066f70724 P 5973ac8c04d8457e980e80784abb5aa7: Deleting log segment in path: /tmp/dist-test-task2jzYy2/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515514800191-24103-0/minicluster-data/ts-0-root/wals/4ab1eaa54f904a649365473066f70724/wal-000000038 (ops 185-189)
I20260812 06:18:45.015259 24569 maintenance_manager.cc:643] P 5973ac8c04d8457e980e80784abb5aa7: LogGCOp(4ab1eaa54f904a649365473066f70724) complete. Timing: real 0.026s	user 0.000s	sys 0.025s Metrics: {}
I20260812 06:18:45.015669 24664 maintenance_manager.cc:419] P 5973ac8c04d8457e980e80784abb5aa7: Scheduling FlushDeltaMemStoresOp(4ab1eaa54f904a649365473066f70724): perf score=2.188937
I20260812 06:18:45.035645 24569 maintenance_manager.cc:643] P 5973ac8c04d8457e980e80784abb5aa7: FlushDeltaMemStoresOp(4ab1eaa54f904a649365473066f70724) complete. Timing: real 0.020s	user 0.001s	sys 0.009s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4358,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:45.036159 24664 maintenance_manager.cc:419] P 5973ac8c04d8457e980e80784abb5aa7: Scheduling FlushDeltaMemStoresOp(4ab1eaa54f904a649365473066f70724): perf score=2.188937
I20260812 06:18:45.046263 24569 maintenance_manager.cc:643] P 5973ac8c04d8457e980e80784abb5aa7: FlushDeltaMemStoresOp(4ab1eaa54f904a649365473066f70724) complete. Timing: real 0.010s	user 0.004s	sys 0.004s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":3882,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:45.046717 24664 maintenance_manager.cc:419] P 5973ac8c04d8457e980e80784abb5aa7: Scheduling LogGCOp(4ab1eaa54f904a649365473066f70724): free 12017954 bytes of WAL
I20260812 06:18:45.047001 24569 log_reader.cc:385] T 4ab1eaa54f904a649365473066f70724: removed 1 log segments from log reader
I20260812 06:18:45.047070 24569 log.cc:1079] T 4ab1eaa54f904a649365473066f70724 P 5973ac8c04d8457e980e80784abb5aa7: Deleting log segment in path: /tmp/dist-test-task2jzYy2/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515514800191-24103-0/minicluster-data/ts-0-root/wals/4ab1eaa54f904a649365473066f70724/wal-000000039 (ops 190-194)
I20260812 06:18:45.050298 24569 maintenance_manager.cc:643] P 5973ac8c04d8457e980e80784abb5aa7: LogGCOp(4ab1eaa54f904a649365473066f70724) complete. Timing: real 0.003s	user 0.000s	sys 0.003s Metrics: {}
I20260812 06:18:45.051317 24664 maintenance_manager.cc:419] P 5973ac8c04d8457e980e80784abb5aa7: Scheduling MajorDeltaCompactionOp(4ab1eaa54f904a649365473066f70724): perf score=1.000000
I20260812 06:18:45.225095 24103 heavy-update-compaction-itest.cc:229] Time spent updating: real 4.710s	user 1.800s	sys 0.141s
I20260812 06:18:45.267568 24569 maintenance_manager.cc:643] P 5973ac8c04d8457e980e80784abb5aa7: MajorDeltaCompactionOp(4ab1eaa54f904a649365473066f70724) complete. Timing: real 0.216s	user 0.128s	sys 0.087s Metrics: {"cfile_cache_miss":734,"cfile_cache_miss_bytes":32979748,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"lbm_read_time_us":14144,"lbm_reads_lt_1ms":770,"lbm_write_time_us":37860,"lbm_writes_lt_1ms":743,"peak_mem_usage":87969044,"reinsert_count":0,"update_count":3500}
I20260812 06:18:45.268097 24664 maintenance_manager.cc:419] P 5973ac8c04d8457e980e80784abb5aa7: Scheduling UndoDeltaBlockGCOp(4ab1eaa54f904a649365473066f70724): 473 bytes on disk
I20260812 06:18:45.268520 24569 maintenance_manager.cc:643] P 5973ac8c04d8457e980e80784abb5aa7: UndoDeltaBlockGCOp(4ab1eaa54f904a649365473066f70724) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":50,"lbm_reads_lt_1ms":4}
I20260812 06:18:45.269063 24664 maintenance_manager.cc:419] P 5973ac8c04d8457e980e80784abb5aa7: Scheduling FlushDeltaMemStoresOp(4ab1eaa54f904a649365473066f70724): perf score=14.095187
I20260812 06:18:45.301599 24569 maintenance_manager.cc:643] P 5973ac8c04d8457e980e80784abb5aa7: FlushDeltaMemStoresOp(4ab1eaa54f904a649365473066f70724) complete. Timing: real 0.032s	user 0.024s	sys 0.008s Metrics: {"bytes_written":16409900,"delete_count":0,"lbm_write_time_us":15862,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:18:45.302076 24664 maintenance_manager.cc:419] P 5973ac8c04d8457e980e80784abb5aa7: Scheduling MajorDeltaCompactionOp(4ab1eaa54f904a649365473066f70724): perf score=1.000000
I20260812 06:18:45.322520 24103 heavy-update-compaction-itest.cc:265] Time spent scanning: real 0.097s	user 0.004s	sys 0.000s
I20260812 06:18:45.323118 24103 tablet_server.cc:179] TabletServer@127.23.137.193:0 shutting down...
I20260812 06:18:45.426502 24569 maintenance_manager.cc:643] P 5973ac8c04d8457e980e80784abb5aa7: MajorDeltaCompactionOp(4ab1eaa54f904a649365473066f70724) complete. Timing: real 0.124s	user 0.083s	sys 0.038s Metrics: {"cfile_cache_miss":431,"cfile_cache_miss_bytes":20672156,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":1,"delta_iterators_relevant":1,"dirs.queue_time_us":3199,"lbm_read_time_us":10469,"lbm_reads_lt_1ms":467,"lbm_write_time_us":22511,"lbm_writes_lt_1ms":443,"mutex_wait_us":2591,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":28416,"update_count":2000}
I20260812 06:18:45.427119 24103 ts_tablet_manager.cc:1507] Shutting down tablet manager...
I20260812 06:18:45.427342 24103 tablet_replica.cc:333] T 4ab1eaa54f904a649365473066f70724 P 5973ac8c04d8457e980e80784abb5aa7: stopping tablet replica
I20260812 06:18:45.427500 24103 raft_consensus.cc:2243] T 4ab1eaa54f904a649365473066f70724 P 5973ac8c04d8457e980e80784abb5aa7 [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:18:45.427680 24103 raft_consensus.cc:2272] T 4ab1eaa54f904a649365473066f70724 P 5973ac8c04d8457e980e80784abb5aa7 [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:18:45.432318 24103 tablet_server.cc:196] TabletServer@127.23.137.193:0 shutdown complete.
I20260812 06:18:45.460052 24103 master.cc:562] Master@127.23.137.254:42003 shutting down...
I20260812 06:18:45.463568 24103 raft_consensus.cc:2243] T 00000000000000000000000000000000 P d09dbf1bfc724e4393b783a0b3643476 [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:18:45.463737 24103 raft_consensus.cc:2272] T 00000000000000000000000000000000 P d09dbf1bfc724e4393b783a0b3643476 [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:18:45.463788 24103 tablet_replica.cc:333] T 00000000000000000000000000000000 P d09dbf1bfc724e4393b783a0b3643476: stopping tablet replica
I20260812 06:18:45.476114 24103 master.cc:584] Master@127.23.137.254:42003 shutdown complete.
[       OK ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/1 (5289 ms)
[----------] 2 tests from EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy (10750 ms total)

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