[==========] 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:17:26.117636 19121 internal_mini_cluster.cc:156] Creating distributed mini masters. Addrs: 127.18.172.126:46185
I20260812 06:17:26.118674 19121 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:17:26.119335 19121 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:17:26.126015 19136 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:17:26.126027 19132 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:17:26.126127 19121 server_base.cc:1061] running on GCE node
W20260812 06:17:26.126294 19139 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:17:26.126864 19121 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:17:26.126984 19121 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:17:26.127034 19121 hybrid_clock.cc:648] HybridClock initialized: now 1786515446127031 us; error 0 us; skew 500 ppm
I20260812 06:17:26.128787 19121 webserver.cc:533] Webserver started at http://127.18.172.126:46497/ using document root <none> and password file <none>
I20260812 06:17:26.129324 19121 fs_manager.cc:362] Metadata directory not provided
I20260812 06:17:26.129382 19121 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:17:26.129650 19121 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:17:26.131362 19121 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-task7hz9Df/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515446107064-19121-0/minicluster-data/master-0-root/instance:
uuid: "b195379ce520422899280e7ab035c0c0"
format_stamp: "Formatted at 2026-08-12 06:17:26 on dist-test-slave-znh6"
I20260812 06:17:26.134683 19121 fs_manager.cc:696] Time spent creating directory manager: real 0.003s	user 0.003s	sys 0.000s
I20260812 06:17:26.136917 19150 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:17:26.137923 19121 fs_manager.cc:730] Time spent opening block manager: real 0.002s	user 0.002s	sys 0.000s
I20260812 06:17:26.138062 19121 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-task7hz9Df/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515446107064-19121-0/minicluster-data/master-0-root
uuid: "b195379ce520422899280e7ab035c0c0"
format_stamp: "Formatted at 2026-08-12 06:17:26 on dist-test-slave-znh6"
I20260812 06:17:26.138157 19121 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-task7hz9Df/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515446107064-19121-0/minicluster-data/master-0-root
metadata directory: /tmp/dist-test-task7hz9Df/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515446107064-19121-0/minicluster-data/master-0-root
1 data directories: /tmp/dist-test-task7hz9Df/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515446107064-19121-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:17:26.195494 19121 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:17:26.196188 19121 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:17:26.196388 19121 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:17:26.204290 19121 rpc_server.cc:307] RPC server started. Bound to: 127.18.172.126:46185
I20260812 06:17:26.204305 19234 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.18.172.126:46185 every 8 connection(s)
I20260812 06:17:26.206511 19235 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:17:26.211781 19235 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P b195379ce520422899280e7ab035c0c0: Bootstrap starting.
I20260812 06:17:26.214011 19235 tablet_bootstrap.cc:654] T 00000000000000000000000000000000 P b195379ce520422899280e7ab035c0c0: Neither blocks nor log segments found. Creating new log.
I20260812 06:17:26.214898 19235 log.cc:826] T 00000000000000000000000000000000 P b195379ce520422899280e7ab035c0c0: Log is configured to *not* fsync() on all Append() calls
I20260812 06:17:26.216481 19235 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P b195379ce520422899280e7ab035c0c0: No bootstrap required, opened a new log
I20260812 06:17:26.219164 19235 raft_consensus.cc:359] T 00000000000000000000000000000000 P b195379ce520422899280e7ab035c0c0 [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "b195379ce520422899280e7ab035c0c0" member_type: VOTER }
I20260812 06:17:26.219321 19235 raft_consensus.cc:385] T 00000000000000000000000000000000 P b195379ce520422899280e7ab035c0c0 [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:17:26.219408 19235 raft_consensus.cc:740] T 00000000000000000000000000000000 P b195379ce520422899280e7ab035c0c0 [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: b195379ce520422899280e7ab035c0c0, State: Initialized, Role: FOLLOWER
I20260812 06:17:26.219998 19235 consensus_queue.cc:260] T 00000000000000000000000000000000 P b195379ce520422899280e7ab035c0c0 [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: "b195379ce520422899280e7ab035c0c0" member_type: VOTER }
I20260812 06:17:26.220165 19235 raft_consensus.cc:399] T 00000000000000000000000000000000 P b195379ce520422899280e7ab035c0c0 [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:17:26.220242 19235 raft_consensus.cc:493] T 00000000000000000000000000000000 P b195379ce520422899280e7ab035c0c0 [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:17:26.220410 19235 raft_consensus.cc:3060] T 00000000000000000000000000000000 P b195379ce520422899280e7ab035c0c0 [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:17:26.221164 19235 raft_consensus.cc:515] T 00000000000000000000000000000000 P b195379ce520422899280e7ab035c0c0 [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "b195379ce520422899280e7ab035c0c0" member_type: VOTER }
I20260812 06:17:26.221589 19235 leader_election.cc:304] T 00000000000000000000000000000000 P b195379ce520422899280e7ab035c0c0 [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: b195379ce520422899280e7ab035c0c0; no voters: 
I20260812 06:17:26.221901 19235 leader_election.cc:290] T 00000000000000000000000000000000 P b195379ce520422899280e7ab035c0c0 [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:17:26.222035 19242 raft_consensus.cc:2804] T 00000000000000000000000000000000 P b195379ce520422899280e7ab035c0c0 [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:17:26.222290 19242 raft_consensus.cc:697] T 00000000000000000000000000000000 P b195379ce520422899280e7ab035c0c0 [term 1 LEADER]: Becoming Leader. State: Replica: b195379ce520422899280e7ab035c0c0, State: Running, Role: LEADER
I20260812 06:17:26.222733 19242 consensus_queue.cc:237] T 00000000000000000000000000000000 P b195379ce520422899280e7ab035c0c0 [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: "b195379ce520422899280e7ab035c0c0" member_type: VOTER }
I20260812 06:17:26.222877 19235 sys_catalog.cc:565] T 00000000000000000000000000000000 P b195379ce520422899280e7ab035c0c0 [sys.catalog]: configured and running, proceeding with master startup.
I20260812 06:17:26.224529 19244 sys_catalog.cc:455] T 00000000000000000000000000000000 P b195379ce520422899280e7ab035c0c0 [sys.catalog]: SysCatalogTable state changed. Reason: New leader b195379ce520422899280e7ab035c0c0. Latest consensus state: current_term: 1 leader_uuid: "b195379ce520422899280e7ab035c0c0" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "b195379ce520422899280e7ab035c0c0" member_type: VOTER } }
I20260812 06:17:26.224594 19243 sys_catalog.cc:455] T 00000000000000000000000000000000 P b195379ce520422899280e7ab035c0c0 [sys.catalog]: SysCatalogTable state changed. Reason: RaftConsensus started. Latest consensus state: current_term: 1 leader_uuid: "b195379ce520422899280e7ab035c0c0" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "b195379ce520422899280e7ab035c0c0" member_type: VOTER } }
I20260812 06:17:26.224650 19244 sys_catalog.cc:458] T 00000000000000000000000000000000 P b195379ce520422899280e7ab035c0c0 [sys.catalog]: This master's current role is: LEADER
I20260812 06:17:26.224694 19243 sys_catalog.cc:458] T 00000000000000000000000000000000 P b195379ce520422899280e7ab035c0c0 [sys.catalog]: This master's current role is: LEADER
I20260812 06:17:26.225142 19261 catalog_manager.cc:1511] Loading table and tablet metadata into memory...
I20260812 06:17:26.225337 19121 internal_mini_cluster.cc:184] Waiting to initialize catalog manager on master 0
I20260812 06:17:26.227540 19261 catalog_manager.cc:1520] Initializing Kudu cluster ID...
I20260812 06:17:26.231956 19261 catalog_manager.cc:1383] Generated new cluster ID: 6d6bb9f6c65f4f60abea248d90b2f87e
I20260812 06:17:26.232019 19261 catalog_manager.cc:1531] Initializing Kudu internal certificate authority...
I20260812 06:17:26.254304 19261 catalog_manager.cc:1406] Generated new certificate authority record
I20260812 06:17:26.255172 19261 catalog_manager.cc:1540] Loading token signing keys...
I20260812 06:17:26.266198 19261 catalog_manager.cc:6092] T 00000000000000000000000000000000 P b195379ce520422899280e7ab035c0c0: Generated new TSK 0
I20260812 06:17:26.267148 19261 catalog_manager.cc:1550] Initializing in-progress tserver states...
I20260812 06:17:26.290494 19121 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:17:26.294327 19285 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:17:26.294613 19288 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:17:26.294843 19284 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:17:26.295985 19121 server_base.cc:1061] running on GCE node
I20260812 06:17:26.296311 19121 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:17:26.296409 19121 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:17:26.296501 19121 hybrid_clock.cc:648] HybridClock initialized: now 1786515446296500 us; error 0 us; skew 500 ppm
I20260812 06:17:26.298112 19121 webserver.cc:533] Webserver started at http://127.18.172.65:36219/ using document root <none> and password file <none>
I20260812 06:17:26.298394 19121 fs_manager.cc:362] Metadata directory not provided
I20260812 06:17:26.298538 19121 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:17:26.298705 19121 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:17:26.299464 19121 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-task7hz9Df/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515446107064-19121-0/minicluster-data/ts-0-root/instance:
uuid: "3e2b32be7c3b4a55b26f8bd7f401c66d"
format_stamp: "Formatted at 2026-08-12 06:17:26 on dist-test-slave-znh6"
I20260812 06:17:26.302196 19121 fs_manager.cc:696] Time spent creating directory manager: real 0.002s	user 0.003s	sys 0.000s
I20260812 06:17:26.303957 19297 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:17:26.304466 19121 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.001s	sys 0.000s
I20260812 06:17:26.304574 19121 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-task7hz9Df/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515446107064-19121-0/minicluster-data/ts-0-root
uuid: "3e2b32be7c3b4a55b26f8bd7f401c66d"
format_stamp: "Formatted at 2026-08-12 06:17:26 on dist-test-slave-znh6"
I20260812 06:17:26.304724 19121 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-task7hz9Df/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515446107064-19121-0/minicluster-data/ts-0-root
metadata directory: /tmp/dist-test-task7hz9Df/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515446107064-19121-0/minicluster-data/ts-0-root
1 data directories: /tmp/dist-test-task7hz9Df/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515446107064-19121-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:17:26.326977 19121 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:17:26.327716 19121 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:17:26.328510 19121 txn_system_client.cc:432] TxnSystemClient initialization is disabled...
I20260812 06:17:26.330183 19121 ts_tablet_manager.cc:585] Loaded tablet metadata (0 total tablets, 0 live tablets)
I20260812 06:17:26.330271 19121 ts_tablet_manager.cc:531] Time spent load tablet metadata: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:17:26.330370 19121 ts_tablet_manager.cc:616] Registered 0 tablets
I20260812 06:17:26.330452 19121 ts_tablet_manager.cc:595] Time spent register tablets: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:17:26.344153 19121 rpc_server.cc:307] RPC server started. Bound to: 127.18.172.65:32807
I20260812 06:17:26.344199 19404 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.18.172.65:32807 every 8 connection(s)
I20260812 06:17:26.361984 19406 heartbeater.cc:344] Connected to a master server at 127.18.172.126:46185
I20260812 06:17:26.362408 19406 heartbeater.cc:461] Registering TS with master...
I20260812 06:17:26.363335 19406 heartbeater.cc:507] Master 127.18.172.126:46185 requested a full tablet report, sending...
I20260812 06:17:26.365887 19179 ts_manager.cc:194] Registered new tserver with Master: 3e2b32be7c3b4a55b26f8bd7f401c66d (127.18.172.65:32807)
I20260812 06:17:26.366099 19121 internal_mini_cluster.cc:371] 1 TS(s) registered with all masters after 0.020792985s
I20260812 06:17:26.367789 19179 master_service.cc:502] Signed X509 certificate for tserver {username='slave'} at 127.0.0.1:34416
I20260812 06:17:26.381548 19179 catalog_manager.cc:2283] Servicing CreateTable request from {username='slave'} at 127.0.0.1:34418:
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:17:26.407156 19344 tablet_service.cc:1511] Processing CreateTablet for tablet e5d9eca0e0734adfb55539fa23802e30 (DEFAULT_TABLE table=heavy-update-compaction-test [id=fa299943662d4bb5b713b2f3b9500567]), partition=
I20260812 06:17:26.408048 19344 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet e5d9eca0e0734adfb55539fa23802e30. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:17:26.412703 19428 tablet_bootstrap.cc:492] T e5d9eca0e0734adfb55539fa23802e30 P 3e2b32be7c3b4a55b26f8bd7f401c66d: Bootstrap starting.
I20260812 06:17:26.414574 19428 tablet_bootstrap.cc:654] T e5d9eca0e0734adfb55539fa23802e30 P 3e2b32be7c3b4a55b26f8bd7f401c66d: Neither blocks nor log segments found. Creating new log.
I20260812 06:17:26.418339 19428 tablet_bootstrap.cc:492] T e5d9eca0e0734adfb55539fa23802e30 P 3e2b32be7c3b4a55b26f8bd7f401c66d: No bootstrap required, opened a new log
I20260812 06:17:26.418591 19428 ts_tablet_manager.cc:1403] T e5d9eca0e0734adfb55539fa23802e30 P 3e2b32be7c3b4a55b26f8bd7f401c66d: Time spent bootstrapping tablet: real 0.006s	user 0.003s	sys 0.000s
I20260812 06:17:26.419747 19428 raft_consensus.cc:359] T e5d9eca0e0734adfb55539fa23802e30 P 3e2b32be7c3b4a55b26f8bd7f401c66d [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "3e2b32be7c3b4a55b26f8bd7f401c66d" member_type: VOTER last_known_addr { host: "127.18.172.65" port: 32807 } }
I20260812 06:17:26.419997 19428 raft_consensus.cc:385] T e5d9eca0e0734adfb55539fa23802e30 P 3e2b32be7c3b4a55b26f8bd7f401c66d [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:17:26.420142 19428 raft_consensus.cc:740] T e5d9eca0e0734adfb55539fa23802e30 P 3e2b32be7c3b4a55b26f8bd7f401c66d [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: 3e2b32be7c3b4a55b26f8bd7f401c66d, State: Initialized, Role: FOLLOWER
I20260812 06:17:26.420523 19428 consensus_queue.cc:260] T e5d9eca0e0734adfb55539fa23802e30 P 3e2b32be7c3b4a55b26f8bd7f401c66d [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: "3e2b32be7c3b4a55b26f8bd7f401c66d" member_type: VOTER last_known_addr { host: "127.18.172.65" port: 32807 } }
I20260812 06:17:26.420708 19428 raft_consensus.cc:399] T e5d9eca0e0734adfb55539fa23802e30 P 3e2b32be7c3b4a55b26f8bd7f401c66d [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:17:26.420791 19428 raft_consensus.cc:493] T e5d9eca0e0734adfb55539fa23802e30 P 3e2b32be7c3b4a55b26f8bd7f401c66d [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:17:26.420881 19428 raft_consensus.cc:3060] T e5d9eca0e0734adfb55539fa23802e30 P 3e2b32be7c3b4a55b26f8bd7f401c66d [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:17:26.422623 19428 raft_consensus.cc:515] T e5d9eca0e0734adfb55539fa23802e30 P 3e2b32be7c3b4a55b26f8bd7f401c66d [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "3e2b32be7c3b4a55b26f8bd7f401c66d" member_type: VOTER last_known_addr { host: "127.18.172.65" port: 32807 } }
I20260812 06:17:26.422987 19428 leader_election.cc:304] T e5d9eca0e0734adfb55539fa23802e30 P 3e2b32be7c3b4a55b26f8bd7f401c66d [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: 3e2b32be7c3b4a55b26f8bd7f401c66d; no voters: 
I20260812 06:17:26.423432 19428 leader_election.cc:290] T e5d9eca0e0734adfb55539fa23802e30 P 3e2b32be7c3b4a55b26f8bd7f401c66d [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:17:26.423563 19430 raft_consensus.cc:2804] T e5d9eca0e0734adfb55539fa23802e30 P 3e2b32be7c3b4a55b26f8bd7f401c66d [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:17:26.424031 19430 raft_consensus.cc:697] T e5d9eca0e0734adfb55539fa23802e30 P 3e2b32be7c3b4a55b26f8bd7f401c66d [term 1 LEADER]: Becoming Leader. State: Replica: 3e2b32be7c3b4a55b26f8bd7f401c66d, State: Running, Role: LEADER
I20260812 06:17:26.424250 19428 ts_tablet_manager.cc:1434] T e5d9eca0e0734adfb55539fa23802e30 P 3e2b32be7c3b4a55b26f8bd7f401c66d: Time spent starting tablet: real 0.006s	user 0.000s	sys 0.006s
I20260812 06:17:26.424432 19430 consensus_queue.cc:237] T e5d9eca0e0734adfb55539fa23802e30 P 3e2b32be7c3b4a55b26f8bd7f401c66d [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: "3e2b32be7c3b4a55b26f8bd7f401c66d" member_type: VOTER last_known_addr { host: "127.18.172.65" port: 32807 } }
I20260812 06:17:26.424650 19406 heartbeater.cc:499] Master 127.18.172.126:46185 was elected leader, sending a full tablet report...
I20260812 06:17:26.429616 19179 catalog_manager.cc:5719] T e5d9eca0e0734adfb55539fa23802e30 P 3e2b32be7c3b4a55b26f8bd7f401c66d reported cstate change: term changed from 0 to 1, leader changed from <none> to 3e2b32be7c3b4a55b26f8bd7f401c66d (127.18.172.65). New cstate: current_term: 1 leader_uuid: "3e2b32be7c3b4a55b26f8bd7f401c66d" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "3e2b32be7c3b4a55b26f8bd7f401c66d" member_type: VOTER last_known_addr { host: "127.18.172.65" port: 32807 } health_report { overall_health: HEALTHY } } }
I20260812 06:17:26.542361 19121 heavy-update-compaction-itest.cc:215] Time spent inserting: real 0.103s	user 0.029s	sys 0.028s
I20260812 06:17:26.595968 19407 maintenance_manager.cc:419] P 3e2b32be7c3b4a55b26f8bd7f401c66d: Scheduling FlushMRSOp(e5d9eca0e0734adfb55539fa23802e30): perf score=3.179940
I20260812 06:17:26.797037 19307 maintenance_manager.cc:643] P 3e2b32be7c3b4a55b26f8bd7f401c66d: FlushMRSOp(e5d9eca0e0734adfb55539fa23802e30) complete. Timing: real 0.200s	user 0.149s	sys 0.044s Metrics: {"bytes_written":8123031,"cfile_init":1,"compiler_manager_pool.queue_time_us":78,"delete_count":0,"dirs.queue_time_us":103,"dirs.run_cpu_time_us":366,"dirs.run_wall_time_us":961,"drs_written":1,"lbm_read_time_us":164,"lbm_reads_lt_1ms":4,"lbm_write_time_us":41470,"lbm_writes_lt_1ms":265,"peak_mem_usage":0,"reinsert_count":0,"rows_written":101,"spinlock_wait_cycles":245632,"update_count":990}
I20260812 06:17:26.799749 19407 maintenance_manager.cc:419] P 3e2b32be7c3b4a55b26f8bd7f401c66d: Scheduling LogGCOp(e5d9eca0e0734adfb55539fa23802e30): free 11976772 bytes of WAL
I20260812 06:17:26.800487 19307 log_reader.cc:385] T e5d9eca0e0734adfb55539fa23802e30: removed 1 log segments from log reader
I20260812 06:17:26.800627 19307 log.cc:1079] T e5d9eca0e0734adfb55539fa23802e30 P 3e2b32be7c3b4a55b26f8bd7f401c66d: Deleting log segment in path: /tmp/dist-test-task7hz9Df/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515446107064-19121-0/minicluster-data/ts-0-root/wals/e5d9eca0e0734adfb55539fa23802e30/wal-000000001 (ops 1-6)
I20260812 06:17:26.807193 19307 maintenance_manager.cc:643] P 3e2b32be7c3b4a55b26f8bd7f401c66d: LogGCOp(e5d9eca0e0734adfb55539fa23802e30) complete. Timing: real 0.007s	user 0.000s	sys 0.007s Metrics: {}
I20260812 06:17:26.807948 19407 maintenance_manager.cc:419] P 3e2b32be7c3b4a55b26f8bd7f401c66d: Scheduling UndoDeltaBlockGCOp(e5d9eca0e0734adfb55539fa23802e30): 411733 bytes on disk
I20260812 06:17:26.809177 19307 maintenance_manager.cc:643] P 3e2b32be7c3b4a55b26f8bd7f401c66d: UndoDeltaBlockGCOp(e5d9eca0e0734adfb55539fa23802e30) complete. Timing: real 0.001s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":191,"lbm_reads_lt_1ms":4}
I20260812 06:17:26.810024 19407 maintenance_manager.cc:419] P 3e2b32be7c3b4a55b26f8bd7f401c66d: Scheduling FlushDeltaMemStoresOp(e5d9eca0e0734adfb55539fa23802e30): perf score=2.188937
I20260812 06:17:26.845046 19307 maintenance_manager.cc:643] P 3e2b32be7c3b4a55b26f8bd7f401c66d: FlushDeltaMemStoresOp(e5d9eca0e0734adfb55539fa23802e30) complete. Timing: real 0.035s	user 0.027s	sys 0.005s Metrics: {"bytes_written":4184707,"delete_count":0,"lbm_write_time_us":14548,"lbm_writes_lt_1ms":105,"reinsert_count":0,"update_count":510}
I20260812 06:17:26.846012 19407 maintenance_manager.cc:419] P 3e2b32be7c3b4a55b26f8bd7f401c66d: Scheduling FlushDeltaMemStoresOp(e5d9eca0e0734adfb55539fa23802e30): perf score=2.188937
I20260812 06:17:26.881321 19307 maintenance_manager.cc:643] P 3e2b32be7c3b4a55b26f8bd7f401c66d: FlushDeltaMemStoresOp(e5d9eca0e0734adfb55539fa23802e30) complete. Timing: real 0.035s	user 0.021s	sys 0.008s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":12296,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:17:26.882472 19407 maintenance_manager.cc:419] P 3e2b32be7c3b4a55b26f8bd7f401c66d: Scheduling MajorDeltaCompactionOp(e5d9eca0e0734adfb55539fa23802e30): perf score=1.000000
I20260812 06:17:27.245005 19307 maintenance_manager.cc:643] P 3e2b32be7c3b4a55b26f8bd7f401c66d: MajorDeltaCompactionOp(e5d9eca0e0734adfb55539fa23802e30) complete. Timing: real 0.362s	user 0.255s	sys 0.079s Metrics: {"cfile_cache_miss":423,"cfile_cache_miss_bytes":20139248,"cfile_init":7,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":1115,"lbm_read_time_us":22677,"lbm_reads_lt_1ms":451,"lbm_write_time_us":66185,"lbm_writes_lt_1ms":433,"peak_mem_usage":49238594,"reinsert_count":0,"thread_start_us":701,"threads_started":6,"update_count":1950}
I20260812 06:17:27.246047 19407 maintenance_manager.cc:419] P 3e2b32be7c3b4a55b26f8bd7f401c66d: Scheduling FlushDeltaMemStoresOp(e5d9eca0e0734adfb55539fa23802e30): perf score=18.063937
I20260812 06:17:27.364578 19307 maintenance_manager.cc:643] P 3e2b32be7c3b4a55b26f8bd7f401c66d: FlushDeltaMemStoresOp(e5d9eca0e0734adfb55539fa23802e30) complete. Timing: real 0.118s	user 0.081s	sys 0.035s Metrics: {"bytes_written":20512317,"delete_count":0,"lbm_write_time_us":54065,"lbm_writes_lt_1ms":503,"reinsert_count":0,"update_count":2500}
I20260812 06:17:27.365552 19407 maintenance_manager.cc:419] P 3e2b32be7c3b4a55b26f8bd7f401c66d: Scheduling FlushDeltaMemStoresOp(e5d9eca0e0734adfb55539fa23802e30): perf score=2.188937
I20260812 06:17:27.392690 19307 maintenance_manager.cc:643] P 3e2b32be7c3b4a55b26f8bd7f401c66d: FlushDeltaMemStoresOp(e5d9eca0e0734adfb55539fa23802e30) complete. Timing: real 0.027s	user 0.018s	sys 0.005s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":9660,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:27.395140 19407 maintenance_manager.cc:419] P 3e2b32be7c3b4a55b26f8bd7f401c66d: Scheduling MajorDeltaCompactionOp(e5d9eca0e0734adfb55539fa23802e30): perf score=1.000000
I20260812 06:17:27.594612 19307 maintenance_manager.cc:643] P 3e2b32be7c3b4a55b26f8bd7f401c66d: MajorDeltaCompactionOp(e5d9eca0e0734adfb55539fa23802e30) complete. Timing: real 0.199s	user 0.137s	sys 0.050s Metrics: {"cfile_cache_miss":632,"cfile_cache_miss_bytes":28754209,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":849,"lbm_read_time_us":12358,"lbm_reads_lt_1ms":664,"lbm_write_time_us":37481,"lbm_writes_lt_1ms":643,"mutex_wait_us":362,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":1664,"update_count":3000}
I20260812 06:17:27.595606 19407 maintenance_manager.cc:419] P 3e2b32be7c3b4a55b26f8bd7f401c66d: Scheduling FlushDeltaMemStoresOp(e5d9eca0e0734adfb55539fa23802e30): perf score=14.095187
I20260812 06:17:27.686055 19307 maintenance_manager.cc:643] P 3e2b32be7c3b4a55b26f8bd7f401c66d: FlushDeltaMemStoresOp(e5d9eca0e0734adfb55539fa23802e30) complete. Timing: real 0.090s	user 0.051s	sys 0.035s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":41806,"lbm_writes_1-10_ms":3,"lbm_writes_lt_1ms":400,"reinsert_count":0,"update_count":2000}
I20260812 06:17:27.686978 19407 maintenance_manager.cc:419] P 3e2b32be7c3b4a55b26f8bd7f401c66d: Scheduling FlushDeltaMemStoresOp(e5d9eca0e0734adfb55539fa23802e30): perf score=2.188937
I20260812 06:17:27.740854 19307 maintenance_manager.cc:643] P 3e2b32be7c3b4a55b26f8bd7f401c66d: FlushDeltaMemStoresOp(e5d9eca0e0734adfb55539fa23802e30) complete. Timing: real 0.054s	user 0.014s	sys 0.014s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":11975,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:27.741634 19407 maintenance_manager.cc:419] P 3e2b32be7c3b4a55b26f8bd7f401c66d: Scheduling FlushDeltaMemStoresOp(e5d9eca0e0734adfb55539fa23802e30): perf score=2.188937
I20260812 06:17:27.761206 19307 maintenance_manager.cc:643] P 3e2b32be7c3b4a55b26f8bd7f401c66d: FlushDeltaMemStoresOp(e5d9eca0e0734adfb55539fa23802e30) complete. Timing: real 0.019s	user 0.013s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":7699,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:27.762472 19407 maintenance_manager.cc:419] P 3e2b32be7c3b4a55b26f8bd7f401c66d: Scheduling MajorDeltaCompactionOp(e5d9eca0e0734adfb55539fa23802e30): perf score=1.000000
I20260812 06:17:28.066800 19307 maintenance_manager.cc:643] P 3e2b32be7c3b4a55b26f8bd7f401c66d: MajorDeltaCompactionOp(e5d9eca0e0734adfb55539fa23802e30) complete. Timing: real 0.304s	user 0.251s	sys 0.052s Metrics: {"cfile_cache_miss":633,"cfile_cache_miss_bytes":28754325,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":863,"lbm_read_time_us":26532,"lbm_reads_lt_1ms":673,"lbm_write_time_us":65398,"lbm_writes_lt_1ms":643,"mutex_wait_us":431,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":8704,"update_count":3000}
I20260812 06:17:28.067838 19407 maintenance_manager.cc:419] P 3e2b32be7c3b4a55b26f8bd7f401c66d: Scheduling FlushDeltaMemStoresOp(e5d9eca0e0734adfb55539fa23802e30): perf score=14.095187
I20260812 06:17:28.162292 19307 maintenance_manager.cc:643] P 3e2b32be7c3b4a55b26f8bd7f401c66d: FlushDeltaMemStoresOp(e5d9eca0e0734adfb55539fa23802e30) complete. Timing: real 0.094s	user 0.054s	sys 0.037s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":43256,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:17:28.163229 19407 maintenance_manager.cc:419] P 3e2b32be7c3b4a55b26f8bd7f401c66d: Scheduling FlushDeltaMemStoresOp(e5d9eca0e0734adfb55539fa23802e30): perf score=2.188937
I20260812 06:17:28.189898 19307 maintenance_manager.cc:643] P 3e2b32be7c3b4a55b26f8bd7f401c66d: FlushDeltaMemStoresOp(e5d9eca0e0734adfb55539fa23802e30) complete. Timing: real 0.026s	user 0.014s	sys 0.009s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":10185,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:28.191318 19407 maintenance_manager.cc:419] P 3e2b32be7c3b4a55b26f8bd7f401c66d: Scheduling MajorDeltaCompactionOp(e5d9eca0e0734adfb55539fa23802e30): perf score=1.000000
I20260812 06:17:28.486649 19307 maintenance_manager.cc:643] P 3e2b32be7c3b4a55b26f8bd7f401c66d: MajorDeltaCompactionOp(e5d9eca0e0734adfb55539fa23802e30) complete. Timing: real 0.295s	user 0.211s	sys 0.065s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24651793,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":250,"lbm_read_time_us":18381,"lbm_reads_lt_1ms":564,"lbm_write_time_us":59426,"lbm_writes_lt_1ms":543,"mutex_wait_us":37,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":19968,"update_count":2500}
I20260812 06:17:28.487886 19407 maintenance_manager.cc:419] P 3e2b32be7c3b4a55b26f8bd7f401c66d: Scheduling FlushDeltaMemStoresOp(e5d9eca0e0734adfb55539fa23802e30): perf score=14.095187
I20260812 06:17:28.600871 19307 maintenance_manager.cc:643] P 3e2b32be7c3b4a55b26f8bd7f401c66d: FlushDeltaMemStoresOp(e5d9eca0e0734adfb55539fa23802e30) complete. Timing: real 0.113s	user 0.034s	sys 0.048s Metrics: {"bytes_written":16409904,"delete_count":0,"lbm_write_time_us":38542,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:17:28.601613 19407 maintenance_manager.cc:419] P 3e2b32be7c3b4a55b26f8bd7f401c66d: Scheduling FlushDeltaMemStoresOp(e5d9eca0e0734adfb55539fa23802e30): perf score=2.188937
I20260812 06:17:28.622920 19307 maintenance_manager.cc:643] P 3e2b32be7c3b4a55b26f8bd7f401c66d: FlushDeltaMemStoresOp(e5d9eca0e0734adfb55539fa23802e30) complete. Timing: real 0.021s	user 0.017s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":7505,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:28.623881 19407 maintenance_manager.cc:419] P 3e2b32be7c3b4a55b26f8bd7f401c66d: Scheduling MajorDeltaCompactionOp(e5d9eca0e0734adfb55539fa23802e30): perf score=1.000000
I20260812 06:17:28.857151 19307 maintenance_manager.cc:643] P 3e2b32be7c3b4a55b26f8bd7f401c66d: MajorDeltaCompactionOp(e5d9eca0e0734adfb55539fa23802e30) complete. Timing: real 0.233s	user 0.168s	sys 0.064s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24651796,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":144,"lbm_read_time_us":24443,"lbm_reads_lt_1ms":572,"lbm_write_time_us":36160,"lbm_writes_lt_1ms":543,"mutex_wait_us":29,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":5120,"update_count":2500}
I20260812 06:17:28.857784 19407 maintenance_manager.cc:419] P 3e2b32be7c3b4a55b26f8bd7f401c66d: Scheduling FlushDeltaMemStoresOp(e5d9eca0e0734adfb55539fa23802e30): perf score=14.095187
I20260812 06:17:28.911958 19307 maintenance_manager.cc:643] P 3e2b32be7c3b4a55b26f8bd7f401c66d: FlushDeltaMemStoresOp(e5d9eca0e0734adfb55539fa23802e30) complete. Timing: real 0.054s	user 0.024s	sys 0.022s Metrics: {"bytes_written":16409904,"delete_count":0,"lbm_write_time_us":20210,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:17:28.912508 19407 maintenance_manager.cc:419] P 3e2b32be7c3b4a55b26f8bd7f401c66d: Scheduling FlushDeltaMemStoresOp(e5d9eca0e0734adfb55539fa23802e30): perf score=2.188937
I20260812 06:17:28.928851 19307 maintenance_manager.cc:643] P 3e2b32be7c3b4a55b26f8bd7f401c66d: FlushDeltaMemStoresOp(e5d9eca0e0734adfb55539fa23802e30) complete. Timing: real 0.016s	user 0.006s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6342,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:28.929320 19407 maintenance_manager.cc:419] P 3e2b32be7c3b4a55b26f8bd7f401c66d: Scheduling FlushMRSOp(e5d9eca0e0734adfb55539fa23802e30): perf score=1.000000
I20260812 06:17:28.970610 19307 maintenance_manager.cc:643] P 3e2b32be7c3b4a55b26f8bd7f401c66d: FlushMRSOp(e5d9eca0e0734adfb55539fa23802e30) complete. Timing: real 0.041s	user 0.035s	sys 0.000s Metrics: {"bytes_written":1234474,"cfile_init":1,"dirs.queue_time_us":141,"dirs.run_cpu_time_us":169,"dirs.run_wall_time_us":1079,"drs_written":1,"lbm_read_time_us":63,"lbm_reads_lt_1ms":4,"lbm_write_time_us":2095,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":30}
I20260812 06:17:28.971452 19407 maintenance_manager.cc:419] P 3e2b32be7c3b4a55b26f8bd7f401c66d: Scheduling LogGCOp(e5d9eca0e0734adfb55539fa23802e30): free 121006405 bytes of WAL
I20260812 06:17:28.971674 19307 log_reader.cc:385] T e5d9eca0e0734adfb55539fa23802e30: removed 12 log segments from log reader
I20260812 06:17:28.971717 19307 log.cc:1079] T e5d9eca0e0734adfb55539fa23802e30 P 3e2b32be7c3b4a55b26f8bd7f401c66d: Deleting log segment in path: /tmp/dist-test-task7hz9Df/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515446107064-19121-0/minicluster-data/ts-0-root/wals/e5d9eca0e0734adfb55539fa23802e30/wal-000000002 (ops 7-11)
I20260812 06:17:28.971745 19307 log.cc:1079] T e5d9eca0e0734adfb55539fa23802e30 P 3e2b32be7c3b4a55b26f8bd7f401c66d: Deleting log segment in path: /tmp/dist-test-task7hz9Df/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515446107064-19121-0/minicluster-data/ts-0-root/wals/e5d9eca0e0734adfb55539fa23802e30/wal-000000003 (ops 12-16)
I20260812 06:17:28.971817 19307 log.cc:1079] T e5d9eca0e0734adfb55539fa23802e30 P 3e2b32be7c3b4a55b26f8bd7f401c66d: Deleting log segment in path: /tmp/dist-test-task7hz9Df/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515446107064-19121-0/minicluster-data/ts-0-root/wals/e5d9eca0e0734adfb55539fa23802e30/wal-000000004 (ops 17-21)
I20260812 06:17:28.971860 19307 log.cc:1079] T e5d9eca0e0734adfb55539fa23802e30 P 3e2b32be7c3b4a55b26f8bd7f401c66d: Deleting log segment in path: /tmp/dist-test-task7hz9Df/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515446107064-19121-0/minicluster-data/ts-0-root/wals/e5d9eca0e0734adfb55539fa23802e30/wal-000000005 (ops 22-26)
I20260812 06:17:28.971912 19307 log.cc:1079] T e5d9eca0e0734adfb55539fa23802e30 P 3e2b32be7c3b4a55b26f8bd7f401c66d: Deleting log segment in path: /tmp/dist-test-task7hz9Df/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515446107064-19121-0/minicluster-data/ts-0-root/wals/e5d9eca0e0734adfb55539fa23802e30/wal-000000006 (ops 27-31)
I20260812 06:17:28.971975 19307 log.cc:1079] T e5d9eca0e0734adfb55539fa23802e30 P 3e2b32be7c3b4a55b26f8bd7f401c66d: Deleting log segment in path: /tmp/dist-test-task7hz9Df/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515446107064-19121-0/minicluster-data/ts-0-root/wals/e5d9eca0e0734adfb55539fa23802e30/wal-000000007 (ops 32-36)
I20260812 06:17:28.972015 19307 log.cc:1079] T e5d9eca0e0734adfb55539fa23802e30 P 3e2b32be7c3b4a55b26f8bd7f401c66d: Deleting log segment in path: /tmp/dist-test-task7hz9Df/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515446107064-19121-0/minicluster-data/ts-0-root/wals/e5d9eca0e0734adfb55539fa23802e30/wal-000000008 (ops 37-41)
I20260812 06:17:28.972054 19307 log.cc:1079] T e5d9eca0e0734adfb55539fa23802e30 P 3e2b32be7c3b4a55b26f8bd7f401c66d: Deleting log segment in path: /tmp/dist-test-task7hz9Df/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515446107064-19121-0/minicluster-data/ts-0-root/wals/e5d9eca0e0734adfb55539fa23802e30/wal-000000009 (ops 42-46)
I20260812 06:17:28.972095 19307 log.cc:1079] T e5d9eca0e0734adfb55539fa23802e30 P 3e2b32be7c3b4a55b26f8bd7f401c66d: Deleting log segment in path: /tmp/dist-test-task7hz9Df/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515446107064-19121-0/minicluster-data/ts-0-root/wals/e5d9eca0e0734adfb55539fa23802e30/wal-000000010 (ops 47-50)
I20260812 06:17:28.972136 19307 log.cc:1079] T e5d9eca0e0734adfb55539fa23802e30 P 3e2b32be7c3b4a55b26f8bd7f401c66d: Deleting log segment in path: /tmp/dist-test-task7hz9Df/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515446107064-19121-0/minicluster-data/ts-0-root/wals/e5d9eca0e0734adfb55539fa23802e30/wal-000000011 (ops 51-55)
I20260812 06:17:28.972175 19307 log.cc:1079] T e5d9eca0e0734adfb55539fa23802e30 P 3e2b32be7c3b4a55b26f8bd7f401c66d: Deleting log segment in path: /tmp/dist-test-task7hz9Df/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515446107064-19121-0/minicluster-data/ts-0-root/wals/e5d9eca0e0734adfb55539fa23802e30/wal-000000012 (ops 56-60)
I20260812 06:17:28.972214 19307 log.cc:1079] T e5d9eca0e0734adfb55539fa23802e30 P 3e2b32be7c3b4a55b26f8bd7f401c66d: Deleting log segment in path: /tmp/dist-test-task7hz9Df/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515446107064-19121-0/minicluster-data/ts-0-root/wals/e5d9eca0e0734adfb55539fa23802e30/wal-000000013 (ops 61-65)
I20260812 06:17:28.997380 19307 maintenance_manager.cc:643] P 3e2b32be7c3b4a55b26f8bd7f401c66d: LogGCOp(e5d9eca0e0734adfb55539fa23802e30) complete. Timing: real 0.026s	user 0.000s	sys 0.023s Metrics: {}
I20260812 06:17:28.997797 19407 maintenance_manager.cc:419] P 3e2b32be7c3b4a55b26f8bd7f401c66d: Scheduling UndoDeltaBlockGCOp(e5d9eca0e0734adfb55539fa23802e30): 473 bytes on disk
I20260812 06:17:28.998232 19307 maintenance_manager.cc:643] P 3e2b32be7c3b4a55b26f8bd7f401c66d: UndoDeltaBlockGCOp(e5d9eca0e0734adfb55539fa23802e30) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":52,"lbm_reads_lt_1ms":4}
I20260812 06:17:28.998688 19407 maintenance_manager.cc:419] P 3e2b32be7c3b4a55b26f8bd7f401c66d: Scheduling FlushDeltaMemStoresOp(e5d9eca0e0734adfb55539fa23802e30): perf score=3.181125
I20260812 06:17:29.010208 19307 maintenance_manager.cc:643] P 3e2b32be7c3b4a55b26f8bd7f401c66d: FlushDeltaMemStoresOp(e5d9eca0e0734adfb55539fa23802e30) complete. Timing: real 0.011s	user 0.009s	sys 0.000s Metrics: {"bytes_written":4512903,"delete_count":0,"lbm_write_time_us":4357,"lbm_writes_lt_1ms":113,"reinsert_count":0,"update_count":550}
I20260812 06:17:29.010601 19407 maintenance_manager.cc:419] P 3e2b32be7c3b4a55b26f8bd7f401c66d: Scheduling FlushDeltaMemStoresOp(e5d9eca0e0734adfb55539fa23802e30): perf score=2.188937
I20260812 06:17:29.020185 19307 maintenance_manager.cc:643] P 3e2b32be7c3b4a55b26f8bd7f401c66d: FlushDeltaMemStoresOp(e5d9eca0e0734adfb55539fa23802e30) complete. Timing: real 0.009s	user 0.008s	sys 0.000s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3674,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:17:29.020553 19407 maintenance_manager.cc:419] P 3e2b32be7c3b4a55b26f8bd7f401c66d: Scheduling MajorDeltaCompactionOp(e5d9eca0e0734adfb55539fa23802e30): perf score=1.000000
I20260812 06:17:29.238914 19307 maintenance_manager.cc:643] P 3e2b32be7c3b4a55b26f8bd7f401c66d: MajorDeltaCompactionOp(e5d9eca0e0734adfb55539fa23802e30) complete. Timing: real 0.218s	user 0.133s	sys 0.075s Metrics: {"cfile_cache_miss":734,"cfile_cache_miss_bytes":32856848,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":515,"lbm_read_time_us":13634,"lbm_reads_lt_1ms":774,"lbm_write_time_us":39733,"lbm_writes_lt_1ms":743,"mutex_wait_us":23,"peak_mem_usage":87969044,"reinsert_count":0,"spinlock_wait_cycles":13184,"thread_start_us":112,"threads_started":1,"update_count":3500}
I20260812 06:17:29.239621 19407 maintenance_manager.cc:419] P 3e2b32be7c3b4a55b26f8bd7f401c66d: Scheduling FlushDeltaMemStoresOp(e5d9eca0e0734adfb55539fa23802e30): perf score=18.063937
I20260812 06:17:29.299413 19307 maintenance_manager.cc:643] P 3e2b32be7c3b4a55b26f8bd7f401c66d: FlushDeltaMemStoresOp(e5d9eca0e0734adfb55539fa23802e30) complete. Timing: real 0.059s	user 0.016s	sys 0.041s Metrics: {"bytes_written":20512315,"delete_count":0,"lbm_write_time_us":24077,"lbm_writes_lt_1ms":503,"reinsert_count":0,"update_count":2500}
I20260812 06:17:29.299901 19407 maintenance_manager.cc:419] P 3e2b32be7c3b4a55b26f8bd7f401c66d: Scheduling FlushDeltaMemStoresOp(e5d9eca0e0734adfb55539fa23802e30): perf score=2.188937
I20260812 06:17:29.324371 19307 maintenance_manager.cc:643] P 3e2b32be7c3b4a55b26f8bd7f401c66d: FlushDeltaMemStoresOp(e5d9eca0e0734adfb55539fa23802e30) complete. Timing: real 0.024s	user 0.012s	sys 0.000s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":5518,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:29.324832 19407 maintenance_manager.cc:419] P 3e2b32be7c3b4a55b26f8bd7f401c66d: Scheduling FlushDeltaMemStoresOp(e5d9eca0e0734adfb55539fa23802e30): perf score=2.188937
I20260812 06:17:29.335031 19307 maintenance_manager.cc:643] P 3e2b32be7c3b4a55b26f8bd7f401c66d: FlushDeltaMemStoresOp(e5d9eca0e0734adfb55539fa23802e30) complete. Timing: real 0.010s	user 0.006s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4002,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:29.335412 19407 maintenance_manager.cc:419] P 3e2b32be7c3b4a55b26f8bd7f401c66d: Scheduling MajorDeltaCompactionOp(e5d9eca0e0734adfb55539fa23802e30): perf score=1.000000
I20260812 06:17:29.508975 19307 maintenance_manager.cc:643] P 3e2b32be7c3b4a55b26f8bd7f401c66d: MajorDeltaCompactionOp(e5d9eca0e0734adfb55539fa23802e30) complete. Timing: real 0.173s	user 0.153s	sys 0.020s Metrics: {"cfile_cache_miss":733,"cfile_cache_miss_bytes":32856737,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":1195,"lbm_read_time_us":11953,"lbm_reads_lt_1ms":773,"lbm_write_time_us":38206,"lbm_writes_lt_1ms":743,"mutex_wait_us":335,"peak_mem_usage":87969044,"reinsert_count":0,"update_count":3500}
I20260812 06:17:29.509677 19407 maintenance_manager.cc:419] P 3e2b32be7c3b4a55b26f8bd7f401c66d: Scheduling FlushDeltaMemStoresOp(e5d9eca0e0734adfb55539fa23802e30): perf score=15.087375
I20260812 06:17:29.576678 19307 maintenance_manager.cc:643] P 3e2b32be7c3b4a55b26f8bd7f401c66d: FlushDeltaMemStoresOp(e5d9eca0e0734adfb55539fa23802e30) complete. Timing: real 0.067s	user 0.023s	sys 0.028s Metrics: {"bytes_written":16820144,"delete_count":0,"lbm_write_time_us":23313,"lbm_writes_lt_1ms":413,"reinsert_count":0,"update_count":2050}
I20260812 06:17:29.577119 19407 maintenance_manager.cc:419] P 3e2b32be7c3b4a55b26f8bd7f401c66d: Scheduling FlushDeltaMemStoresOp(e5d9eca0e0734adfb55539fa23802e30): perf score=6.157687
I20260812 06:17:29.598424 19307 maintenance_manager.cc:643] P 3e2b32be7c3b4a55b26f8bd7f401c66d: FlushDeltaMemStoresOp(e5d9eca0e0734adfb55539fa23802e30) complete. Timing: real 0.021s	user 0.010s	sys 0.007s Metrics: {"bytes_written":7794836,"delete_count":0,"lbm_write_time_us":8605,"lbm_writes_lt_1ms":193,"reinsert_count":0,"update_count":950}
I20260812 06:17:29.599020 19407 maintenance_manager.cc:419] P 3e2b32be7c3b4a55b26f8bd7f401c66d: Scheduling MajorDeltaCompactionOp(e5d9eca0e0734adfb55539fa23802e30): perf score=1.000000
I20260812 06:17:29.766453 19307 maintenance_manager.cc:643] P 3e2b32be7c3b4a55b26f8bd7f401c66d: MajorDeltaCompactionOp(e5d9eca0e0734adfb55539fa23802e30) complete. Timing: real 0.167s	user 0.134s	sys 0.033s Metrics: {"cfile_cache_miss":632,"cfile_cache_miss_bytes":28754207,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":834,"lbm_read_time_us":12776,"lbm_reads_lt_1ms":672,"lbm_write_time_us":34484,"lbm_writes_lt_1ms":643,"mutex_wait_us":288,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":35584,"update_count":3000}
I20260812 06:17:29.767287 19407 maintenance_manager.cc:419] P 3e2b32be7c3b4a55b26f8bd7f401c66d: Scheduling FlushDeltaMemStoresOp(e5d9eca0e0734adfb55539fa23802e30): perf score=14.095187
I20260812 06:17:29.817375 19307 maintenance_manager.cc:643] P 3e2b32be7c3b4a55b26f8bd7f401c66d: FlushDeltaMemStoresOp(e5d9eca0e0734adfb55539fa23802e30) complete. Timing: real 0.050s	user 0.040s	sys 0.007s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":21364,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:17:29.817907 19407 maintenance_manager.cc:419] P 3e2b32be7c3b4a55b26f8bd7f401c66d: Scheduling FlushDeltaMemStoresOp(e5d9eca0e0734adfb55539fa23802e30): perf score=2.188937
I20260812 06:17:29.843611 19307 maintenance_manager.cc:643] P 3e2b32be7c3b4a55b26f8bd7f401c66d: FlushDeltaMemStoresOp(e5d9eca0e0734adfb55539fa23802e30) complete. Timing: real 0.025s	user 0.007s	sys 0.009s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":6672,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:29.844041 19407 maintenance_manager.cc:419] P 3e2b32be7c3b4a55b26f8bd7f401c66d: Scheduling FlushDeltaMemStoresOp(e5d9eca0e0734adfb55539fa23802e30): perf score=2.188937
I20260812 06:17:29.855082 19307 maintenance_manager.cc:643] P 3e2b32be7c3b4a55b26f8bd7f401c66d: FlushDeltaMemStoresOp(e5d9eca0e0734adfb55539fa23802e30) complete. Timing: real 0.011s	user 0.009s	sys 0.001s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4082,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:29.855549 19407 maintenance_manager.cc:419] P 3e2b32be7c3b4a55b26f8bd7f401c66d: Scheduling MajorDeltaCompactionOp(e5d9eca0e0734adfb55539fa23802e30): perf score=1.000000
I20260812 06:17:30.014753 19307 maintenance_manager.cc:643] P 3e2b32be7c3b4a55b26f8bd7f401c66d: MajorDeltaCompactionOp(e5d9eca0e0734adfb55539fa23802e30) complete. Timing: real 0.159s	user 0.122s	sys 0.036s Metrics: {"cfile_cache_miss":633,"cfile_cache_miss_bytes":28754323,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":326,"lbm_read_time_us":11725,"lbm_reads_lt_1ms":673,"lbm_write_time_us":32291,"lbm_writes_lt_1ms":643,"mutex_wait_us":38,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":6784,"update_count":3000}
I20260812 06:17:30.015597 19407 maintenance_manager.cc:419] P 3e2b32be7c3b4a55b26f8bd7f401c66d: Scheduling FlushDeltaMemStoresOp(e5d9eca0e0734adfb55539fa23802e30): perf score=14.095187
I20260812 06:17:30.063915 19307 maintenance_manager.cc:643] P 3e2b32be7c3b4a55b26f8bd7f401c66d: FlushDeltaMemStoresOp(e5d9eca0e0734adfb55539fa23802e30) complete. Timing: real 0.048s	user 0.032s	sys 0.015s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":21038,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:17:30.064846 19407 maintenance_manager.cc:419] P 3e2b32be7c3b4a55b26f8bd7f401c66d: Scheduling FlushDeltaMemStoresOp(e5d9eca0e0734adfb55539fa23802e30): perf score=2.188937
I20260812 06:17:30.093137 19307 maintenance_manager.cc:643] P 3e2b32be7c3b4a55b26f8bd7f401c66d: FlushDeltaMemStoresOp(e5d9eca0e0734adfb55539fa23802e30) complete. Timing: real 0.028s	user 0.011s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6206,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:30.093662 19407 maintenance_manager.cc:419] P 3e2b32be7c3b4a55b26f8bd7f401c66d: Scheduling FlushDeltaMemStoresOp(e5d9eca0e0734adfb55539fa23802e30): perf score=2.188937
I20260812 06:17:30.107950 19307 maintenance_manager.cc:643] P 3e2b32be7c3b4a55b26f8bd7f401c66d: FlushDeltaMemStoresOp(e5d9eca0e0734adfb55539fa23802e30) complete. Timing: real 0.014s	user 0.008s	sys 0.005s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":5557,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:30.108435 19407 maintenance_manager.cc:419] P 3e2b32be7c3b4a55b26f8bd7f401c66d: Scheduling MajorDeltaCompactionOp(e5d9eca0e0734adfb55539fa23802e30): perf score=1.000000
I20260812 06:17:30.275180 19307 maintenance_manager.cc:643] P 3e2b32be7c3b4a55b26f8bd7f401c66d: MajorDeltaCompactionOp(e5d9eca0e0734adfb55539fa23802e30) complete. Timing: real 0.167s	user 0.125s	sys 0.041s Metrics: {"cfile_cache_miss":633,"cfile_cache_miss_bytes":28754323,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":227,"lbm_read_time_us":12141,"lbm_reads_lt_1ms":673,"lbm_write_time_us":33858,"lbm_writes_lt_1ms":643,"mutex_wait_us":23,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":7424,"update_count":3000}
I20260812 06:17:30.275933 19407 maintenance_manager.cc:419] P 3e2b32be7c3b4a55b26f8bd7f401c66d: Scheduling FlushDeltaMemStoresOp(e5d9eca0e0734adfb55539fa23802e30): perf score=14.095187
I20260812 06:17:30.327162 19307 maintenance_manager.cc:643] P 3e2b32be7c3b4a55b26f8bd7f401c66d: FlushDeltaMemStoresOp(e5d9eca0e0734adfb55539fa23802e30) complete. Timing: real 0.051s	user 0.029s	sys 0.020s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":21931,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:17:30.327709 19407 maintenance_manager.cc:419] P 3e2b32be7c3b4a55b26f8bd7f401c66d: Scheduling FlushDeltaMemStoresOp(e5d9eca0e0734adfb55539fa23802e30): perf score=2.188937
I20260812 06:17:30.342543 19307 maintenance_manager.cc:643] P 3e2b32be7c3b4a55b26f8bd7f401c66d: FlushDeltaMemStoresOp(e5d9eca0e0734adfb55539fa23802e30) complete. Timing: real 0.015s	user 0.009s	sys 0.003s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5649,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:30.343130 19407 maintenance_manager.cc:419] P 3e2b32be7c3b4a55b26f8bd7f401c66d: Scheduling FlushMRSOp(e5d9eca0e0734adfb55539fa23802e30): perf score=1.000000
I20260812 06:17:30.374003 19307 maintenance_manager.cc:643] P 3e2b32be7c3b4a55b26f8bd7f401c66d: FlushMRSOp(e5d9eca0e0734adfb55539fa23802e30) complete. Timing: real 0.030s	user 0.023s	sys 0.005s Metrics: {"bytes_written":1316419,"cfile_init":1,"dirs.queue_time_us":64,"dirs.run_cpu_time_us":278,"dirs.run_wall_time_us":1175,"drs_written":1,"lbm_read_time_us":55,"lbm_reads_lt_1ms":4,"lbm_write_time_us":2194,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":32}
I20260812 06:17:30.374774 19407 maintenance_manager.cc:419] P 3e2b32be7c3b4a55b26f8bd7f401c66d: Scheduling LogGCOp(e5d9eca0e0734adfb55539fa23802e30): free 132571365 bytes of WAL
I20260812 06:17:30.375089 19307 log_reader.cc:385] T e5d9eca0e0734adfb55539fa23802e30: removed 13 log segments from log reader
I20260812 06:17:30.375152 19307 log.cc:1079] T e5d9eca0e0734adfb55539fa23802e30 P 3e2b32be7c3b4a55b26f8bd7f401c66d: Deleting log segment in path: /tmp/dist-test-task7hz9Df/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515446107064-19121-0/minicluster-data/ts-0-root/wals/e5d9eca0e0734adfb55539fa23802e30/wal-000000014 (ops 66-70)
I20260812 06:17:30.375191 19307 log.cc:1079] T e5d9eca0e0734adfb55539fa23802e30 P 3e2b32be7c3b4a55b26f8bd7f401c66d: Deleting log segment in path: /tmp/dist-test-task7hz9Df/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515446107064-19121-0/minicluster-data/ts-0-root/wals/e5d9eca0e0734adfb55539fa23802e30/wal-000000015 (ops 71-75)
I20260812 06:17:30.375222 19307 log.cc:1079] T e5d9eca0e0734adfb55539fa23802e30 P 3e2b32be7c3b4a55b26f8bd7f401c66d: Deleting log segment in path: /tmp/dist-test-task7hz9Df/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515446107064-19121-0/minicluster-data/ts-0-root/wals/e5d9eca0e0734adfb55539fa23802e30/wal-000000016 (ops 76-80)
I20260812 06:17:30.375250 19307 log.cc:1079] T e5d9eca0e0734adfb55539fa23802e30 P 3e2b32be7c3b4a55b26f8bd7f401c66d: Deleting log segment in path: /tmp/dist-test-task7hz9Df/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515446107064-19121-0/minicluster-data/ts-0-root/wals/e5d9eca0e0734adfb55539fa23802e30/wal-000000017 (ops 81-85)
I20260812 06:17:30.375286 19307 log.cc:1079] T e5d9eca0e0734adfb55539fa23802e30 P 3e2b32be7c3b4a55b26f8bd7f401c66d: Deleting log segment in path: /tmp/dist-test-task7hz9Df/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515446107064-19121-0/minicluster-data/ts-0-root/wals/e5d9eca0e0734adfb55539fa23802e30/wal-000000018 (ops 86-90)
I20260812 06:17:30.375319 19307 log.cc:1079] T e5d9eca0e0734adfb55539fa23802e30 P 3e2b32be7c3b4a55b26f8bd7f401c66d: Deleting log segment in path: /tmp/dist-test-task7hz9Df/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515446107064-19121-0/minicluster-data/ts-0-root/wals/e5d9eca0e0734adfb55539fa23802e30/wal-000000019 (ops 91-94)
I20260812 06:17:30.375357 19307 log.cc:1079] T e5d9eca0e0734adfb55539fa23802e30 P 3e2b32be7c3b4a55b26f8bd7f401c66d: Deleting log segment in path: /tmp/dist-test-task7hz9Df/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515446107064-19121-0/minicluster-data/ts-0-root/wals/e5d9eca0e0734adfb55539fa23802e30/wal-000000020 (ops 95-99)
I20260812 06:17:30.375383 19307 log.cc:1079] T e5d9eca0e0734adfb55539fa23802e30 P 3e2b32be7c3b4a55b26f8bd7f401c66d: Deleting log segment in path: /tmp/dist-test-task7hz9Df/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515446107064-19121-0/minicluster-data/ts-0-root/wals/e5d9eca0e0734adfb55539fa23802e30/wal-000000021 (ops 100-104)
I20260812 06:17:30.375415 19307 log.cc:1079] T e5d9eca0e0734adfb55539fa23802e30 P 3e2b32be7c3b4a55b26f8bd7f401c66d: Deleting log segment in path: /tmp/dist-test-task7hz9Df/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515446107064-19121-0/minicluster-data/ts-0-root/wals/e5d9eca0e0734adfb55539fa23802e30/wal-000000022 (ops 105-109)
I20260812 06:17:30.375451 19307 log.cc:1079] T e5d9eca0e0734adfb55539fa23802e30 P 3e2b32be7c3b4a55b26f8bd7f401c66d: Deleting log segment in path: /tmp/dist-test-task7hz9Df/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515446107064-19121-0/minicluster-data/ts-0-root/wals/e5d9eca0e0734adfb55539fa23802e30/wal-000000023 (ops 110-114)
I20260812 06:17:30.375483 19307 log.cc:1079] T e5d9eca0e0734adfb55539fa23802e30 P 3e2b32be7c3b4a55b26f8bd7f401c66d: Deleting log segment in path: /tmp/dist-test-task7hz9Df/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515446107064-19121-0/minicluster-data/ts-0-root/wals/e5d9eca0e0734adfb55539fa23802e30/wal-000000024 (ops 115-119)
I20260812 06:17:30.375511 19307 log.cc:1079] T e5d9eca0e0734adfb55539fa23802e30 P 3e2b32be7c3b4a55b26f8bd7f401c66d: Deleting log segment in path: /tmp/dist-test-task7hz9Df/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515446107064-19121-0/minicluster-data/ts-0-root/wals/e5d9eca0e0734adfb55539fa23802e30/wal-000000025 (ops 120-124)
I20260812 06:17:30.375537 19307 log.cc:1079] T e5d9eca0e0734adfb55539fa23802e30 P 3e2b32be7c3b4a55b26f8bd7f401c66d: Deleting log segment in path: /tmp/dist-test-task7hz9Df/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515446107064-19121-0/minicluster-data/ts-0-root/wals/e5d9eca0e0734adfb55539fa23802e30/wal-000000026 (ops 125-128)
I20260812 06:17:30.410766 19307 maintenance_manager.cc:643] P 3e2b32be7c3b4a55b26f8bd7f401c66d: LogGCOp(e5d9eca0e0734adfb55539fa23802e30) complete. Timing: real 0.036s	user 0.000s	sys 0.032s Metrics: {}
I20260812 06:17:30.411289 19407 maintenance_manager.cc:419] P 3e2b32be7c3b4a55b26f8bd7f401c66d: Scheduling FlushDeltaMemStoresOp(e5d9eca0e0734adfb55539fa23802e30): perf score=2.188937
I20260812 06:17:30.427361 19307 maintenance_manager.cc:643] P 3e2b32be7c3b4a55b26f8bd7f401c66d: FlushDeltaMemStoresOp(e5d9eca0e0734adfb55539fa23802e30) complete. Timing: real 0.016s	user 0.008s	sys 0.005s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":5193,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:30.427778 19407 maintenance_manager.cc:419] P 3e2b32be7c3b4a55b26f8bd7f401c66d: Scheduling FlushDeltaMemStoresOp(e5d9eca0e0734adfb55539fa23802e30): perf score=2.188937
I20260812 06:17:30.437604 19307 maintenance_manager.cc:643] P 3e2b32be7c3b4a55b26f8bd7f401c66d: FlushDeltaMemStoresOp(e5d9eca0e0734adfb55539fa23802e30) complete. Timing: real 0.010s	user 0.005s	sys 0.003s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":3940,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:30.437997 19407 maintenance_manager.cc:419] P 3e2b32be7c3b4a55b26f8bd7f401c66d: Scheduling UndoDeltaBlockGCOp(e5d9eca0e0734adfb55539fa23802e30): 492 bytes on disk
I20260812 06:17:30.438400 19307 maintenance_manager.cc:643] P 3e2b32be7c3b4a55b26f8bd7f401c66d: UndoDeltaBlockGCOp(e5d9eca0e0734adfb55539fa23802e30) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":48,"lbm_reads_lt_1ms":4}
I20260812 06:17:30.438952 19407 maintenance_manager.cc:419] P 3e2b32be7c3b4a55b26f8bd7f401c66d: Scheduling MajorDeltaCompactionOp(e5d9eca0e0734adfb55539fa23802e30): perf score=1.000000
I20260812 06:17:30.625394 19307 maintenance_manager.cc:643] P 3e2b32be7c3b4a55b26f8bd7f401c66d: MajorDeltaCompactionOp(e5d9eca0e0734adfb55539fa23802e30) complete. Timing: real 0.186s	user 0.147s	sys 0.028s Metrics: {"cfile_cache_miss":734,"cfile_cache_miss_bytes":32856854,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":736,"lbm_read_time_us":12660,"lbm_reads_lt_1ms":774,"lbm_write_time_us":36902,"lbm_writes_lt_1ms":743,"mutex_wait_us":374,"peak_mem_usage":87969044,"reinsert_count":0,"spinlock_wait_cycles":1280,"thread_start_us":75,"threads_started":1,"update_count":3500}
I20260812 06:17:30.627115 19407 maintenance_manager.cc:419] P 3e2b32be7c3b4a55b26f8bd7f401c66d: Scheduling FlushDeltaMemStoresOp(e5d9eca0e0734adfb55539fa23802e30): perf score=18.063937
I20260812 06:17:30.687047 19307 maintenance_manager.cc:643] P 3e2b32be7c3b4a55b26f8bd7f401c66d: FlushDeltaMemStoresOp(e5d9eca0e0734adfb55539fa23802e30) complete. Timing: real 0.060s	user 0.035s	sys 0.024s Metrics: {"bytes_written":20512319,"delete_count":0,"lbm_write_time_us":25998,"lbm_writes_lt_1ms":503,"reinsert_count":0,"update_count":2500}
I20260812 06:17:30.687572 19407 maintenance_manager.cc:419] P 3e2b32be7c3b4a55b26f8bd7f401c66d: Scheduling FlushDeltaMemStoresOp(e5d9eca0e0734adfb55539fa23802e30): perf score=2.188937
I20260812 06:17:30.709254 19307 maintenance_manager.cc:643] P 3e2b32be7c3b4a55b26f8bd7f401c66d: FlushDeltaMemStoresOp(e5d9eca0e0734adfb55539fa23802e30) complete. Timing: real 0.021s	user 0.010s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4733,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:30.709698 19407 maintenance_manager.cc:419] P 3e2b32be7c3b4a55b26f8bd7f401c66d: Scheduling FlushDeltaMemStoresOp(e5d9eca0e0734adfb55539fa23802e30): perf score=2.188937
I20260812 06:17:30.723872 19307 maintenance_manager.cc:643] P 3e2b32be7c3b4a55b26f8bd7f401c66d: FlushDeltaMemStoresOp(e5d9eca0e0734adfb55539fa23802e30) complete. Timing: real 0.014s	user 0.013s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5560,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:30.724323 19407 maintenance_manager.cc:419] P 3e2b32be7c3b4a55b26f8bd7f401c66d: Scheduling MajorDeltaCompactionOp(e5d9eca0e0734adfb55539fa23802e30): perf score=1.000000
I20260812 06:17:30.907017 19307 maintenance_manager.cc:643] P 3e2b32be7c3b4a55b26f8bd7f401c66d: MajorDeltaCompactionOp(e5d9eca0e0734adfb55539fa23802e30) complete. Timing: real 0.183s	user 0.142s	sys 0.040s Metrics: {"cfile_cache_miss":733,"cfile_cache_miss_bytes":32856742,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":726,"lbm_read_time_us":15243,"lbm_reads_lt_1ms":773,"lbm_write_time_us":37528,"lbm_writes_lt_1ms":743,"mutex_wait_us":70,"peak_mem_usage":87969044,"reinsert_count":0,"spinlock_wait_cycles":9600,"update_count":3500}
I20260812 06:17:30.907781 19407 maintenance_manager.cc:419] P 3e2b32be7c3b4a55b26f8bd7f401c66d: Scheduling FlushDeltaMemStoresOp(e5d9eca0e0734adfb55539fa23802e30): perf score=14.095187
I20260812 06:17:30.956538 19307 maintenance_manager.cc:643] P 3e2b32be7c3b4a55b26f8bd7f401c66d: FlushDeltaMemStoresOp(e5d9eca0e0734adfb55539fa23802e30) complete. Timing: real 0.049s	user 0.022s	sys 0.024s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":20981,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:17:30.957777 19407 maintenance_manager.cc:419] P 3e2b32be7c3b4a55b26f8bd7f401c66d: Scheduling FlushDeltaMemStoresOp(e5d9eca0e0734adfb55539fa23802e30): perf score=2.188937
I20260812 06:17:30.980588 19307 maintenance_manager.cc:643] P 3e2b32be7c3b4a55b26f8bd7f401c66d: FlushDeltaMemStoresOp(e5d9eca0e0734adfb55539fa23802e30) complete. Timing: real 0.023s	user 0.010s	sys 0.003s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5679,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:30.981040 19407 maintenance_manager.cc:419] P 3e2b32be7c3b4a55b26f8bd7f401c66d: Scheduling FlushDeltaMemStoresOp(e5d9eca0e0734adfb55539fa23802e30): perf score=2.188937
I20260812 06:17:30.991325 19307 maintenance_manager.cc:643] P 3e2b32be7c3b4a55b26f8bd7f401c66d: FlushDeltaMemStoresOp(e5d9eca0e0734adfb55539fa23802e30) complete. Timing: real 0.010s	user 0.010s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3964,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:30.991751 19407 maintenance_manager.cc:419] P 3e2b32be7c3b4a55b26f8bd7f401c66d: Scheduling MajorDeltaCompactionOp(e5d9eca0e0734adfb55539fa23802e30): perf score=1.000000
I20260812 06:17:31.160552 19307 maintenance_manager.cc:643] P 3e2b32be7c3b4a55b26f8bd7f401c66d: MajorDeltaCompactionOp(e5d9eca0e0734adfb55539fa23802e30) complete. Timing: real 0.168s	user 0.143s	sys 0.024s Metrics: {"cfile_cache_miss":633,"cfile_cache_miss_bytes":28754324,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":288,"lbm_read_time_us":13153,"lbm_reads_lt_1ms":673,"lbm_write_time_us":35139,"lbm_writes_lt_1ms":643,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":3584,"update_count":3000}
I20260812 06:17:31.161259 19407 maintenance_manager.cc:419] P 3e2b32be7c3b4a55b26f8bd7f401c66d: Scheduling FlushDeltaMemStoresOp(e5d9eca0e0734adfb55539fa23802e30): perf score=14.095187
I20260812 06:17:31.212282 19307 maintenance_manager.cc:643] P 3e2b32be7c3b4a55b26f8bd7f401c66d: FlushDeltaMemStoresOp(e5d9eca0e0734adfb55539fa23802e30) complete. Timing: real 0.051s	user 0.027s	sys 0.019s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":21152,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:17:31.212744 19407 maintenance_manager.cc:419] P 3e2b32be7c3b4a55b26f8bd7f401c66d: Scheduling FlushDeltaMemStoresOp(e5d9eca0e0734adfb55539fa23802e30): perf score=2.188937
I20260812 06:17:31.227326 19307 maintenance_manager.cc:643] P 3e2b32be7c3b4a55b26f8bd7f401c66d: FlushDeltaMemStoresOp(e5d9eca0e0734adfb55539fa23802e30) complete. Timing: real 0.014s	user 0.006s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5582,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:31.227797 19407 maintenance_manager.cc:419] P 3e2b32be7c3b4a55b26f8bd7f401c66d: Scheduling MajorDeltaCompactionOp(e5d9eca0e0734adfb55539fa23802e30): perf score=1.000000
I20260812 06:17:31.382994 19307 maintenance_manager.cc:643] P 3e2b32be7c3b4a55b26f8bd7f401c66d: MajorDeltaCompactionOp(e5d9eca0e0734adfb55539fa23802e30) complete. Timing: real 0.155s	user 0.107s	sys 0.047s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24651793,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":258,"lbm_read_time_us":10221,"lbm_reads_lt_1ms":572,"lbm_write_time_us":29373,"lbm_writes_lt_1ms":543,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":896,"update_count":2500}
I20260812 06:17:31.383635 19407 maintenance_manager.cc:419] P 3e2b32be7c3b4a55b26f8bd7f401c66d: Scheduling FlushDeltaMemStoresOp(e5d9eca0e0734adfb55539fa23802e30): perf score=12.110812
I20260812 06:17:31.420598 19307 maintenance_manager.cc:643] P 3e2b32be7c3b4a55b26f8bd7f401c66d: FlushDeltaMemStoresOp(e5d9eca0e0734adfb55539fa23802e30) complete. Timing: real 0.037s	user 0.023s	sys 0.012s Metrics: {"bytes_written":13743341,"delete_count":0,"lbm_write_time_us":15977,"lbm_writes_lt_1ms":338,"reinsert_count":0,"update_count":1675}
I20260812 06:17:31.421113 19407 maintenance_manager.cc:419] P 3e2b32be7c3b4a55b26f8bd7f401c66d: Scheduling FlushDeltaMemStoresOp(e5d9eca0e0734adfb55539fa23802e30): perf score=1.196750
I20260812 06:17:31.432138 19307 maintenance_manager.cc:643] P 3e2b32be7c3b4a55b26f8bd7f401c66d: FlushDeltaMemStoresOp(e5d9eca0e0734adfb55539fa23802e30) complete. Timing: real 0.011s	user 0.008s	sys 0.001s Metrics: {"bytes_written":2666779,"delete_count":0,"lbm_write_time_us":4286,"lbm_writes_lt_1ms":68,"reinsert_count":0,"update_count":325}
I20260812 06:17:31.432739 19407 maintenance_manager.cc:419] P 3e2b32be7c3b4a55b26f8bd7f401c66d: Scheduling MajorDeltaCompactionOp(e5d9eca0e0734adfb55539fa23802e30): perf score=1.000000
I20260812 06:17:31.581806 19307 maintenance_manager.cc:643] P 3e2b32be7c3b4a55b26f8bd7f401c66d: MajorDeltaCompactionOp(e5d9eca0e0734adfb55539fa23802e30) complete. Timing: real 0.149s	user 0.082s	sys 0.064s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20549353,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":165,"lbm_read_time_us":10605,"lbm_reads_lt_1ms":468,"lbm_write_time_us":25801,"lbm_writes_lt_1ms":443,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":2048,"update_count":2000}
I20260812 06:17:31.582393 19407 maintenance_manager.cc:419] P 3e2b32be7c3b4a55b26f8bd7f401c66d: Scheduling FlushDeltaMemStoresOp(e5d9eca0e0734adfb55539fa23802e30): perf score=10.126437
I20260812 06:17:31.611734 19307 maintenance_manager.cc:643] P 3e2b32be7c3b4a55b26f8bd7f401c66d: FlushDeltaMemStoresOp(e5d9eca0e0734adfb55539fa23802e30) complete. Timing: real 0.029s	user 0.024s	sys 0.004s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":12882,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:17:31.612290 19407 maintenance_manager.cc:419] P 3e2b32be7c3b4a55b26f8bd7f401c66d: Scheduling FlushDeltaMemStoresOp(e5d9eca0e0734adfb55539fa23802e30): perf score=2.188937
I20260812 06:17:31.625378 19307 maintenance_manager.cc:643] P 3e2b32be7c3b4a55b26f8bd7f401c66d: FlushDeltaMemStoresOp(e5d9eca0e0734adfb55539fa23802e30) complete. Timing: real 0.013s	user 0.008s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4846,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:31.625831 19407 maintenance_manager.cc:419] P 3e2b32be7c3b4a55b26f8bd7f401c66d: Scheduling FlushMRSOp(e5d9eca0e0734adfb55539fa23802e30): perf score=1.000000
I20260812 06:17:31.655297 19307 maintenance_manager.cc:643] P 3e2b32be7c3b4a55b26f8bd7f401c66d: FlushMRSOp(e5d9eca0e0734adfb55539fa23802e30) complete. Timing: real 0.029s	user 0.025s	sys 0.004s Metrics: {"bytes_written":1152510,"cfile_init":1,"dirs.queue_time_us":60,"dirs.run_cpu_time_us":171,"dirs.run_wall_time_us":1452,"drs_written":1,"lbm_read_time_us":46,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1462,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":28}
I20260812 06:17:31.655930 19407 maintenance_manager.cc:419] P 3e2b32be7c3b4a55b26f8bd7f401c66d: Scheduling LogGCOp(e5d9eca0e0734adfb55539fa23802e30): free 108535637 bytes of WAL
I20260812 06:17:31.656148 19307 log_reader.cc:385] T e5d9eca0e0734adfb55539fa23802e30: removed 11 log segments from log reader
I20260812 06:17:31.656213 19307 log.cc:1079] T e5d9eca0e0734adfb55539fa23802e30 P 3e2b32be7c3b4a55b26f8bd7f401c66d: Deleting log segment in path: /tmp/dist-test-task7hz9Df/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515446107064-19121-0/minicluster-data/ts-0-root/wals/e5d9eca0e0734adfb55539fa23802e30/wal-000000027 (ops 129-133)
I20260812 06:17:31.656270 19307 log.cc:1079] T e5d9eca0e0734adfb55539fa23802e30 P 3e2b32be7c3b4a55b26f8bd7f401c66d: Deleting log segment in path: /tmp/dist-test-task7hz9Df/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515446107064-19121-0/minicluster-data/ts-0-root/wals/e5d9eca0e0734adfb55539fa23802e30/wal-000000028 (ops 134-138)
I20260812 06:17:31.656311 19307 log.cc:1079] T e5d9eca0e0734adfb55539fa23802e30 P 3e2b32be7c3b4a55b26f8bd7f401c66d: Deleting log segment in path: /tmp/dist-test-task7hz9Df/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515446107064-19121-0/minicluster-data/ts-0-root/wals/e5d9eca0e0734adfb55539fa23802e30/wal-000000029 (ops 139-143)
I20260812 06:17:31.656371 19307 log.cc:1079] T e5d9eca0e0734adfb55539fa23802e30 P 3e2b32be7c3b4a55b26f8bd7f401c66d: Deleting log segment in path: /tmp/dist-test-task7hz9Df/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515446107064-19121-0/minicluster-data/ts-0-root/wals/e5d9eca0e0734adfb55539fa23802e30/wal-000000030 (ops 144-148)
I20260812 06:17:31.656411 19307 log.cc:1079] T e5d9eca0e0734adfb55539fa23802e30 P 3e2b32be7c3b4a55b26f8bd7f401c66d: Deleting log segment in path: /tmp/dist-test-task7hz9Df/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515446107064-19121-0/minicluster-data/ts-0-root/wals/e5d9eca0e0734adfb55539fa23802e30/wal-000000031 (ops 149-152)
I20260812 06:17:31.656452 19307 log.cc:1079] T e5d9eca0e0734adfb55539fa23802e30 P 3e2b32be7c3b4a55b26f8bd7f401c66d: Deleting log segment in path: /tmp/dist-test-task7hz9Df/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515446107064-19121-0/minicluster-data/ts-0-root/wals/e5d9eca0e0734adfb55539fa23802e30/wal-000000032 (ops 153-157)
I20260812 06:17:31.656488 19307 log.cc:1079] T e5d9eca0e0734adfb55539fa23802e30 P 3e2b32be7c3b4a55b26f8bd7f401c66d: Deleting log segment in path: /tmp/dist-test-task7hz9Df/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515446107064-19121-0/minicluster-data/ts-0-root/wals/e5d9eca0e0734adfb55539fa23802e30/wal-000000033 (ops 158-162)
I20260812 06:17:31.656528 19307 log.cc:1079] T e5d9eca0e0734adfb55539fa23802e30 P 3e2b32be7c3b4a55b26f8bd7f401c66d: Deleting log segment in path: /tmp/dist-test-task7hz9Df/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515446107064-19121-0/minicluster-data/ts-0-root/wals/e5d9eca0e0734adfb55539fa23802e30/wal-000000034 (ops 163-166)
I20260812 06:17:31.656569 19307 log.cc:1079] T e5d9eca0e0734adfb55539fa23802e30 P 3e2b32be7c3b4a55b26f8bd7f401c66d: Deleting log segment in path: /tmp/dist-test-task7hz9Df/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515446107064-19121-0/minicluster-data/ts-0-root/wals/e5d9eca0e0734adfb55539fa23802e30/wal-000000035 (ops 167-171)
I20260812 06:17:31.656610 19307 log.cc:1079] T e5d9eca0e0734adfb55539fa23802e30 P 3e2b32be7c3b4a55b26f8bd7f401c66d: Deleting log segment in path: /tmp/dist-test-task7hz9Df/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515446107064-19121-0/minicluster-data/ts-0-root/wals/e5d9eca0e0734adfb55539fa23802e30/wal-000000036 (ops 172-176)
I20260812 06:17:31.656651 19307 log.cc:1079] T e5d9eca0e0734adfb55539fa23802e30 P 3e2b32be7c3b4a55b26f8bd7f401c66d: Deleting log segment in path: /tmp/dist-test-task7hz9Df/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515446107064-19121-0/minicluster-data/ts-0-root/wals/e5d9eca0e0734adfb55539fa23802e30/wal-000000037 (ops 177-181)
I20260812 06:17:31.684082 19307 maintenance_manager.cc:643] P 3e2b32be7c3b4a55b26f8bd7f401c66d: LogGCOp(e5d9eca0e0734adfb55539fa23802e30) complete. Timing: real 0.028s	user 0.000s	sys 0.027s Metrics: {}
I20260812 06:17:31.684523 19407 maintenance_manager.cc:419] P 3e2b32be7c3b4a55b26f8bd7f401c66d: Scheduling UndoDeltaBlockGCOp(e5d9eca0e0734adfb55539fa23802e30): 448 bytes on disk
I20260812 06:17:31.685011 19307 maintenance_manager.cc:643] P 3e2b32be7c3b4a55b26f8bd7f401c66d: UndoDeltaBlockGCOp(e5d9eca0e0734adfb55539fa23802e30) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":69,"lbm_reads_lt_1ms":4}
I20260812 06:17:31.685521 19407 maintenance_manager.cc:419] P 3e2b32be7c3b4a55b26f8bd7f401c66d: Scheduling FlushDeltaMemStoresOp(e5d9eca0e0734adfb55539fa23802e30): perf score=3.181125
I20260812 06:17:31.705845 19307 maintenance_manager.cc:643] P 3e2b32be7c3b4a55b26f8bd7f401c66d: FlushDeltaMemStoresOp(e5d9eca0e0734adfb55539fa23802e30) complete. Timing: real 0.020s	user 0.003s	sys 0.007s Metrics: {"bytes_written":4512902,"delete_count":0,"lbm_write_time_us":4702,"lbm_writes_lt_1ms":113,"reinsert_count":0,"update_count":550}
I20260812 06:17:31.706373 19407 maintenance_manager.cc:419] P 3e2b32be7c3b4a55b26f8bd7f401c66d: Scheduling LogGCOp(e5d9eca0e0734adfb55539fa23802e30): free 12018006 bytes of WAL
I20260812 06:17:31.706566 19307 log_reader.cc:385] T e5d9eca0e0734adfb55539fa23802e30: removed 1 log segments from log reader
I20260812 06:17:31.706607 19307 log.cc:1079] T e5d9eca0e0734adfb55539fa23802e30 P 3e2b32be7c3b4a55b26f8bd7f401c66d: Deleting log segment in path: /tmp/dist-test-task7hz9Df/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515446107064-19121-0/minicluster-data/ts-0-root/wals/e5d9eca0e0734adfb55539fa23802e30/wal-000000038 (ops 182-186)
I20260812 06:17:31.709095 19307 maintenance_manager.cc:643] P 3e2b32be7c3b4a55b26f8bd7f401c66d: LogGCOp(e5d9eca0e0734adfb55539fa23802e30) complete. Timing: real 0.003s	user 0.000s	sys 0.000s Metrics: {}
I20260812 06:17:31.709370 19407 maintenance_manager.cc:419] P 3e2b32be7c3b4a55b26f8bd7f401c66d: Scheduling FlushDeltaMemStoresOp(e5d9eca0e0734adfb55539fa23802e30): perf score=2.188937
I20260812 06:17:31.718670 19307 maintenance_manager.cc:643] P 3e2b32be7c3b4a55b26f8bd7f401c66d: FlushDeltaMemStoresOp(e5d9eca0e0734adfb55539fa23802e30) complete. Timing: real 0.009s	user 0.003s	sys 0.005s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3589,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:17:31.719233 19407 maintenance_manager.cc:419] P 3e2b32be7c3b4a55b26f8bd7f401c66d: Scheduling MajorDeltaCompactionOp(e5d9eca0e0734adfb55539fa23802e30): perf score=1.000000
I20260812 06:17:31.936744 19307 maintenance_manager.cc:643] P 3e2b32be7c3b4a55b26f8bd7f401c66d: MajorDeltaCompactionOp(e5d9eca0e0734adfb55539fa23802e30) complete. Timing: real 0.217s	user 0.125s	sys 0.090s Metrics: {"cfile_cache_miss":634,"cfile_cache_miss_bytes":28754433,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":2374,"lbm_read_time_us":13862,"lbm_reads_lt_1ms":674,"lbm_write_time_us":39468,"lbm_writes_lt_1ms":643,"mutex_wait_us":1924,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":1536,"thread_start_us":94,"threads_started":1,"update_count":3000}
I20260812 06:17:31.937438 19407 maintenance_manager.cc:419] P 3e2b32be7c3b4a55b26f8bd7f401c66d: Scheduling FlushDeltaMemStoresOp(e5d9eca0e0734adfb55539fa23802e30): perf score=14.095187
I20260812 06:17:32.002959 19307 maintenance_manager.cc:643] P 3e2b32be7c3b4a55b26f8bd7f401c66d: FlushDeltaMemStoresOp(e5d9eca0e0734adfb55539fa23802e30) complete. Timing: real 0.065s	user 0.038s	sys 0.027s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":24652,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":402,"reinsert_count":0,"update_count":2000}
I20260812 06:17:32.003760 19407 maintenance_manager.cc:419] P 3e2b32be7c3b4a55b26f8bd7f401c66d: Scheduling FlushDeltaMemStoresOp(e5d9eca0e0734adfb55539fa23802e30): perf score=2.188937
I20260812 06:17:32.018682 19307 maintenance_manager.cc:643] P 3e2b32be7c3b4a55b26f8bd7f401c66d: FlushDeltaMemStoresOp(e5d9eca0e0734adfb55539fa23802e30) complete. Timing: real 0.015s	user 0.013s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5712,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:32.019170 19407 maintenance_manager.cc:419] P 3e2b32be7c3b4a55b26f8bd7f401c66d: Scheduling MajorDeltaCompactionOp(e5d9eca0e0734adfb55539fa23802e30): perf score=1.000000
I20260812 06:17:32.103801 19121 heavy-update-compaction-itest.cc:229] Time spent updating: real 5.561s	user 2.050s	sys 0.113s
I20260812 06:17:32.172398 19121 heavy-update-compaction-itest.cc:265] Time spent scanning: real 0.068s	user 0.002s	sys 0.000s
I20260812 06:17:32.173038 19121 tablet_server.cc:179] TabletServer@127.18.172.65:0 shutting down...
I20260812 06:17:32.179806 19307 maintenance_manager.cc:643] P 3e2b32be7c3b4a55b26f8bd7f401c66d: MajorDeltaCompactionOp(e5d9eca0e0734adfb55539fa23802e30) complete. Timing: real 0.160s	user 0.120s	sys 0.040s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24651794,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":413,"lbm_read_time_us":11627,"lbm_reads_lt_1ms":564,"lbm_write_time_us":25204,"lbm_writes_lt_1ms":543,"mutex_wait_us":37,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":3072,"update_count":2500}
I20260812 06:17:32.180398 19121 ts_tablet_manager.cc:1507] Shutting down tablet manager...
I20260812 06:17:32.180752 19121 tablet_replica.cc:333] T e5d9eca0e0734adfb55539fa23802e30 P 3e2b32be7c3b4a55b26f8bd7f401c66d: stopping tablet replica
I20260812 06:17:32.180996 19121 raft_consensus.cc:2243] T e5d9eca0e0734adfb55539fa23802e30 P 3e2b32be7c3b4a55b26f8bd7f401c66d [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:17:32.181213 19121 raft_consensus.cc:2272] T e5d9eca0e0734adfb55539fa23802e30 P 3e2b32be7c3b4a55b26f8bd7f401c66d [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:17:32.198297 19121 tablet_server.cc:196] TabletServer@127.18.172.65:0 shutdown complete.
I20260812 06:17:32.234165 19121 master.cc:562] Master@127.18.172.126:46185 shutting down...
I20260812 06:17:32.237780 19121 raft_consensus.cc:2243] T 00000000000000000000000000000000 P b195379ce520422899280e7ab035c0c0 [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:17:32.237941 19121 raft_consensus.cc:2272] T 00000000000000000000000000000000 P b195379ce520422899280e7ab035c0c0 [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:17:32.237996 19121 tablet_replica.cc:333] T 00000000000000000000000000000000 P b195379ce520422899280e7ab035c0c0: stopping tablet replica
I20260812 06:17:32.250216 19121 master.cc:584] Master@127.18.172.126:46185 shutdown complete.
[       OK ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/0 (6223 ms)
[ RUN      ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/1
I20260812 06:17:32.352479 19121 internal_mini_cluster.cc:156] Creating distributed mini masters. Addrs: 127.18.172.126:41751
I20260812 06:17:32.352891 19121 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:17:32.355201 19468 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:17:32.355347 19472 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:17:32.355428 19121 server_base.cc:1061] running on GCE node
W20260812 06:17:32.355230 19467 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:17:32.355674 19121 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:17:32.355721 19121 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:17:32.355736 19121 hybrid_clock.cc:648] HybridClock initialized: now 1786515452355736 us; error 0 us; skew 500 ppm
I20260812 06:17:32.356494 19121 webserver.cc:533] Webserver started at http://127.18.172.126:39749/ using document root <none> and password file <none>
I20260812 06:17:32.356627 19121 fs_manager.cc:362] Metadata directory not provided
I20260812 06:17:32.356670 19121 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:17:32.356724 19121 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:17:32.357065 19121 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-task7hz9Df/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515446107064-19121-0/minicluster-data/master-0-root/instance:
uuid: "f66ed132d9314fdabf92b5e694a5e6f9"
format_stamp: "Formatted at 2026-08-12 06:17:32 on dist-test-slave-znh6"
I20260812 06:17:32.358563 19121 fs_manager.cc:696] Time spent creating directory manager: real 0.001s	user 0.002s	sys 0.000s
I20260812 06:17:32.359500 19481 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:17:32.359725 19121 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.000s	sys 0.001s
I20260812 06:17:32.359788 19121 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-task7hz9Df/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515446107064-19121-0/minicluster-data/master-0-root
uuid: "f66ed132d9314fdabf92b5e694a5e6f9"
format_stamp: "Formatted at 2026-08-12 06:17:32 on dist-test-slave-znh6"
I20260812 06:17:32.359885 19121 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-task7hz9Df/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515446107064-19121-0/minicluster-data/master-0-root
metadata directory: /tmp/dist-test-task7hz9Df/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515446107064-19121-0/minicluster-data/master-0-root
1 data directories: /tmp/dist-test-task7hz9Df/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515446107064-19121-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:17:32.393071 19121 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:17:32.393582 19121 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:17:32.399755 19121 rpc_server.cc:307] RPC server started. Bound to: 127.18.172.126:41751
I20260812 06:17:32.399816 19566 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.18.172.126:41751 every 8 connection(s)
I20260812 06:17:32.401265 19567 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:17:32.405961 19567 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P f66ed132d9314fdabf92b5e694a5e6f9: Bootstrap starting.
I20260812 06:17:32.407562 19567 tablet_bootstrap.cc:654] T 00000000000000000000000000000000 P f66ed132d9314fdabf92b5e694a5e6f9: Neither blocks nor log segments found. Creating new log.
I20260812 06:17:32.408829 19567 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P f66ed132d9314fdabf92b5e694a5e6f9: No bootstrap required, opened a new log
I20260812 06:17:32.409330 19567 raft_consensus.cc:359] T 00000000000000000000000000000000 P f66ed132d9314fdabf92b5e694a5e6f9 [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "f66ed132d9314fdabf92b5e694a5e6f9" member_type: VOTER }
I20260812 06:17:32.409461 19567 raft_consensus.cc:385] T 00000000000000000000000000000000 P f66ed132d9314fdabf92b5e694a5e6f9 [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:17:32.409502 19567 raft_consensus.cc:740] T 00000000000000000000000000000000 P f66ed132d9314fdabf92b5e694a5e6f9 [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: f66ed132d9314fdabf92b5e694a5e6f9, State: Initialized, Role: FOLLOWER
I20260812 06:17:32.409672 19567 consensus_queue.cc:260] T 00000000000000000000000000000000 P f66ed132d9314fdabf92b5e694a5e6f9 [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: "f66ed132d9314fdabf92b5e694a5e6f9" member_type: VOTER }
I20260812 06:17:32.409760 19567 raft_consensus.cc:399] T 00000000000000000000000000000000 P f66ed132d9314fdabf92b5e694a5e6f9 [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:17:32.409808 19567 raft_consensus.cc:493] T 00000000000000000000000000000000 P f66ed132d9314fdabf92b5e694a5e6f9 [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:17:32.409865 19567 raft_consensus.cc:3060] T 00000000000000000000000000000000 P f66ed132d9314fdabf92b5e694a5e6f9 [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:17:32.410522 19567 raft_consensus.cc:515] T 00000000000000000000000000000000 P f66ed132d9314fdabf92b5e694a5e6f9 [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "f66ed132d9314fdabf92b5e694a5e6f9" member_type: VOTER }
I20260812 06:17:32.410676 19567 leader_election.cc:304] T 00000000000000000000000000000000 P f66ed132d9314fdabf92b5e694a5e6f9 [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: f66ed132d9314fdabf92b5e694a5e6f9; no voters: 
I20260812 06:17:32.410903 19567 leader_election.cc:290] T 00000000000000000000000000000000 P f66ed132d9314fdabf92b5e694a5e6f9 [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:17:32.411013 19571 raft_consensus.cc:2804] T 00000000000000000000000000000000 P f66ed132d9314fdabf92b5e694a5e6f9 [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:17:32.411216 19571 raft_consensus.cc:697] T 00000000000000000000000000000000 P f66ed132d9314fdabf92b5e694a5e6f9 [term 1 LEADER]: Becoming Leader. State: Replica: f66ed132d9314fdabf92b5e694a5e6f9, State: Running, Role: LEADER
I20260812 06:17:32.411384 19571 consensus_queue.cc:237] T 00000000000000000000000000000000 P f66ed132d9314fdabf92b5e694a5e6f9 [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: "f66ed132d9314fdabf92b5e694a5e6f9" member_type: VOTER }
I20260812 06:17:32.411393 19567 sys_catalog.cc:565] T 00000000000000000000000000000000 P f66ed132d9314fdabf92b5e694a5e6f9 [sys.catalog]: configured and running, proceeding with master startup.
I20260812 06:17:32.412129 19573 sys_catalog.cc:455] T 00000000000000000000000000000000 P f66ed132d9314fdabf92b5e694a5e6f9 [sys.catalog]: SysCatalogTable state changed. Reason: New leader f66ed132d9314fdabf92b5e694a5e6f9. Latest consensus state: current_term: 1 leader_uuid: "f66ed132d9314fdabf92b5e694a5e6f9" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "f66ed132d9314fdabf92b5e694a5e6f9" member_type: VOTER } }
I20260812 06:17:32.412281 19573 sys_catalog.cc:458] T 00000000000000000000000000000000 P f66ed132d9314fdabf92b5e694a5e6f9 [sys.catalog]: This master's current role is: LEADER
I20260812 06:17:32.412441 19572 sys_catalog.cc:455] T 00000000000000000000000000000000 P f66ed132d9314fdabf92b5e694a5e6f9 [sys.catalog]: SysCatalogTable state changed. Reason: RaftConsensus started. Latest consensus state: current_term: 1 leader_uuid: "f66ed132d9314fdabf92b5e694a5e6f9" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "f66ed132d9314fdabf92b5e694a5e6f9" member_type: VOTER } }
I20260812 06:17:32.412552 19572 sys_catalog.cc:458] T 00000000000000000000000000000000 P f66ed132d9314fdabf92b5e694a5e6f9 [sys.catalog]: This master's current role is: LEADER
I20260812 06:17:32.412621 19585 catalog_manager.cc:1511] Loading table and tablet metadata into memory...
I20260812 06:17:32.413511 19585 catalog_manager.cc:1520] Initializing Kudu cluster ID...
I20260812 06:17:32.413686 19121 internal_mini_cluster.cc:184] Waiting to initialize catalog manager on master 0
I20260812 06:17:32.415318 19585 catalog_manager.cc:1383] Generated new cluster ID: a0aa81ec3b814bcc92933fad64121c9d
I20260812 06:17:32.415374 19585 catalog_manager.cc:1531] Initializing Kudu internal certificate authority...
I20260812 06:17:32.428177 19585 catalog_manager.cc:1406] Generated new certificate authority record
I20260812 06:17:32.428705 19585 catalog_manager.cc:1540] Loading token signing keys...
I20260812 06:17:32.433617 19585 catalog_manager.cc:6092] T 00000000000000000000000000000000 P f66ed132d9314fdabf92b5e694a5e6f9: Generated new TSK 0
I20260812 06:17:32.433786 19585 catalog_manager.cc:1550] Initializing in-progress tserver states...
I20260812 06:17:32.446043 19121 file_cache.cc:504] Constructed file cache file cache with capacity 419430
I20260812 06:17:32.448266 19121 server_base.cc:1061] running on GCE node
W20260812 06:17:32.448266 19598 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:17:32.448329 19603 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:17:32.448329 19599 instance_detector.cc:116] could not retrieve Azure instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:17:32.448663 19121 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:17:32.448714 19121 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:17:32.448729 19121 hybrid_clock.cc:648] HybridClock initialized: now 1786515452448729 us; error 0 us; skew 500 ppm
I20260812 06:17:32.449589 19121 webserver.cc:533] Webserver started at http://127.18.172.65:41231/ using document root <none> and password file <none>
I20260812 06:17:32.449757 19121 fs_manager.cc:362] Metadata directory not provided
I20260812 06:17:32.449813 19121 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:17:32.449924 19121 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:17:32.450327 19121 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-task7hz9Df/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515446107064-19121-0/minicluster-data/ts-0-root/instance:
uuid: "b3b3a2f0924e41c4960d47ff0e9ba866"
format_stamp: "Formatted at 2026-08-12 06:17:32 on dist-test-slave-znh6"
I20260812 06:17:32.451925 19121 fs_manager.cc:696] Time spent creating directory manager: real 0.001s	user 0.000s	sys 0.002s
I20260812 06:17:32.452916 19616 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:17:32.453229 19121 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.000s	sys 0.001s
I20260812 06:17:32.453301 19121 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-task7hz9Df/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515446107064-19121-0/minicluster-data/ts-0-root
uuid: "b3b3a2f0924e41c4960d47ff0e9ba866"
format_stamp: "Formatted at 2026-08-12 06:17:32 on dist-test-slave-znh6"
I20260812 06:17:32.453399 19121 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-task7hz9Df/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515446107064-19121-0/minicluster-data/ts-0-root
metadata directory: /tmp/dist-test-task7hz9Df/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515446107064-19121-0/minicluster-data/ts-0-root
1 data directories: /tmp/dist-test-task7hz9Df/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515446107064-19121-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:17:32.481528 19121 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:17:32.481890 19121 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:17:32.482205 19121 txn_system_client.cc:432] TxnSystemClient initialization is disabled...
I20260812 06:17:32.482671 19121 ts_tablet_manager.cc:585] Loaded tablet metadata (0 total tablets, 0 live tablets)
I20260812 06:17:32.482708 19121 ts_tablet_manager.cc:531] Time spent load tablet metadata: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:17:32.482767 19121 ts_tablet_manager.cc:616] Registered 0 tablets
I20260812 06:17:32.482832 19121 ts_tablet_manager.cc:595] Time spent register tablets: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:17:32.487221 19121 rpc_server.cc:307] RPC server started. Bound to: 127.18.172.65:34531
I20260812 06:17:32.488365 19722 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.18.172.65:34531 every 8 connection(s)
I20260812 06:17:32.498159 19723 heartbeater.cc:344] Connected to a master server at 127.18.172.126:41751
I20260812 06:17:32.498279 19723 heartbeater.cc:461] Registering TS with master...
I20260812 06:17:32.498512 19723 heartbeater.cc:507] Master 127.18.172.126:41751 requested a full tablet report, sending...
I20260812 06:17:32.499193 19511 ts_manager.cc:194] Registered new tserver with Master: b3b3a2f0924e41c4960d47ff0e9ba866 (127.18.172.65:34531)
I20260812 06:17:32.499318 19121 internal_mini_cluster.cc:371] 1 TS(s) registered with all masters after 0.011169004s
I20260812 06:17:32.500172 19511 master_service.cc:502] Signed X509 certificate for tserver {username='slave'} at 127.0.0.1:34166
I20260812 06:17:32.506204 19511 catalog_manager.cc:2283] Servicing CreateTable request from {username='slave'} at 127.0.0.1:34182:
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:17:32.514556 19658 tablet_service.cc:1511] Processing CreateTablet for tablet 4808b56090a14f6082ad57f7fcd183bf (DEFAULT_TABLE table=heavy-update-compaction-test [id=1f29fd60c19641e4932f8af1d438f52d]), partition=
I20260812 06:17:32.514895 19658 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet 4808b56090a14f6082ad57f7fcd183bf. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:17:32.517026 19747 tablet_bootstrap.cc:492] T 4808b56090a14f6082ad57f7fcd183bf P b3b3a2f0924e41c4960d47ff0e9ba866: Bootstrap starting.
I20260812 06:17:32.517779 19747 tablet_bootstrap.cc:654] T 4808b56090a14f6082ad57f7fcd183bf P b3b3a2f0924e41c4960d47ff0e9ba866: Neither blocks nor log segments found. Creating new log.
I20260812 06:17:32.518756 19747 tablet_bootstrap.cc:492] T 4808b56090a14f6082ad57f7fcd183bf P b3b3a2f0924e41c4960d47ff0e9ba866: No bootstrap required, opened a new log
I20260812 06:17:32.518877 19747 ts_tablet_manager.cc:1403] T 4808b56090a14f6082ad57f7fcd183bf P b3b3a2f0924e41c4960d47ff0e9ba866: Time spent bootstrapping tablet: real 0.002s	user 0.002s	sys 0.000s
I20260812 06:17:32.519253 19747 raft_consensus.cc:359] T 4808b56090a14f6082ad57f7fcd183bf P b3b3a2f0924e41c4960d47ff0e9ba866 [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "b3b3a2f0924e41c4960d47ff0e9ba866" member_type: VOTER last_known_addr { host: "127.18.172.65" port: 34531 } }
I20260812 06:17:32.519337 19747 raft_consensus.cc:385] T 4808b56090a14f6082ad57f7fcd183bf P b3b3a2f0924e41c4960d47ff0e9ba866 [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:17:32.519359 19747 raft_consensus.cc:740] T 4808b56090a14f6082ad57f7fcd183bf P b3b3a2f0924e41c4960d47ff0e9ba866 [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: b3b3a2f0924e41c4960d47ff0e9ba866, State: Initialized, Role: FOLLOWER
I20260812 06:17:32.519477 19747 consensus_queue.cc:260] T 4808b56090a14f6082ad57f7fcd183bf P b3b3a2f0924e41c4960d47ff0e9ba866 [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: "b3b3a2f0924e41c4960d47ff0e9ba866" member_type: VOTER last_known_addr { host: "127.18.172.65" port: 34531 } }
I20260812 06:17:32.519567 19747 raft_consensus.cc:399] T 4808b56090a14f6082ad57f7fcd183bf P b3b3a2f0924e41c4960d47ff0e9ba866 [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:17:32.519622 19747 raft_consensus.cc:493] T 4808b56090a14f6082ad57f7fcd183bf P b3b3a2f0924e41c4960d47ff0e9ba866 [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:17:32.519695 19747 raft_consensus.cc:3060] T 4808b56090a14f6082ad57f7fcd183bf P b3b3a2f0924e41c4960d47ff0e9ba866 [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:17:32.520591 19747 raft_consensus.cc:515] T 4808b56090a14f6082ad57f7fcd183bf P b3b3a2f0924e41c4960d47ff0e9ba866 [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "b3b3a2f0924e41c4960d47ff0e9ba866" member_type: VOTER last_known_addr { host: "127.18.172.65" port: 34531 } }
I20260812 06:17:32.520742 19747 leader_election.cc:304] T 4808b56090a14f6082ad57f7fcd183bf P b3b3a2f0924e41c4960d47ff0e9ba866 [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: b3b3a2f0924e41c4960d47ff0e9ba866; no voters: 
I20260812 06:17:32.520952 19747 leader_election.cc:290] T 4808b56090a14f6082ad57f7fcd183bf P b3b3a2f0924e41c4960d47ff0e9ba866 [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:17:32.521086 19749 raft_consensus.cc:2804] T 4808b56090a14f6082ad57f7fcd183bf P b3b3a2f0924e41c4960d47ff0e9ba866 [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:17:32.521299 19747 ts_tablet_manager.cc:1434] T 4808b56090a14f6082ad57f7fcd183bf P b3b3a2f0924e41c4960d47ff0e9ba866: Time spent starting tablet: real 0.002s	user 0.002s	sys 0.000s
I20260812 06:17:32.521309 19723 heartbeater.cc:499] Master 127.18.172.126:41751 was elected leader, sending a full tablet report...
I20260812 06:17:32.521319 19749 raft_consensus.cc:697] T 4808b56090a14f6082ad57f7fcd183bf P b3b3a2f0924e41c4960d47ff0e9ba866 [term 1 LEADER]: Becoming Leader. State: Replica: b3b3a2f0924e41c4960d47ff0e9ba866, State: Running, Role: LEADER
I20260812 06:17:32.521493 19749 consensus_queue.cc:237] T 4808b56090a14f6082ad57f7fcd183bf P b3b3a2f0924e41c4960d47ff0e9ba866 [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: "b3b3a2f0924e41c4960d47ff0e9ba866" member_type: VOTER last_known_addr { host: "127.18.172.65" port: 34531 } }
I20260812 06:17:32.522687 19511 catalog_manager.cc:5719] T 4808b56090a14f6082ad57f7fcd183bf P b3b3a2f0924e41c4960d47ff0e9ba866 reported cstate change: term changed from 0 to 1, leader changed from <none> to b3b3a2f0924e41c4960d47ff0e9ba866 (127.18.172.65). New cstate: current_term: 1 leader_uuid: "b3b3a2f0924e41c4960d47ff0e9ba866" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "b3b3a2f0924e41c4960d47ff0e9ba866" member_type: VOTER last_known_addr { host: "127.18.172.65" port: 34531 } health_report { overall_health: HEALTHY } } }
I20260812 06:17:32.580986 19121 heavy-update-compaction-itest.cc:215] Time spent inserting: real 0.051s	user 0.018s	sys 0.004s
I20260812 06:17:32.738773 19725 maintenance_manager.cc:419] P b3b3a2f0924e41c4960d47ff0e9ba866: Scheduling FlushMRSOp(4808b56090a14f6082ad57f7fcd183bf): perf score=23.023690
I20260812 06:17:32.907402 19626 maintenance_manager.cc:643] P b3b3a2f0924e41c4960d47ff0e9ba866: FlushMRSOp(4808b56090a14f6082ad57f7fcd183bf) complete. Timing: real 0.168s	user 0.108s	sys 0.060s Metrics: {"bytes_written":12307490,"cfile_init":1,"delete_count":0,"dirs.queue_time_us":70,"dirs.run_cpu_time_us":193,"dirs.run_wall_time_us":736,"drs_written":1,"lbm_read_time_us":41,"lbm_reads_lt_1ms":4,"lbm_write_time_us":45999,"lbm_writes_lt_1ms":857,"peak_mem_usage":0,"reinsert_count":0,"rows_written":105,"update_count":1500}
I20260812 06:17:32.908098 19725 maintenance_manager.cc:419] P b3b3a2f0924e41c4960d47ff0e9ba866: Scheduling LogGCOp(4808b56090a14f6082ad57f7fcd183bf): free 20743880 bytes of WAL
I20260812 06:17:32.908370 19626 log_reader.cc:385] T 4808b56090a14f6082ad57f7fcd183bf: removed 2 log segments from log reader
I20260812 06:17:32.908468 19626 log.cc:1079] T 4808b56090a14f6082ad57f7fcd183bf P b3b3a2f0924e41c4960d47ff0e9ba866: Deleting log segment in path: /tmp/dist-test-task7hz9Df/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515446107064-19121-0/minicluster-data/ts-0-root/wals/4808b56090a14f6082ad57f7fcd183bf/wal-000000001 (ops 1-6)
I20260812 06:17:32.908545 19626 log.cc:1079] T 4808b56090a14f6082ad57f7fcd183bf P b3b3a2f0924e41c4960d47ff0e9ba866: Deleting log segment in path: /tmp/dist-test-task7hz9Df/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515446107064-19121-0/minicluster-data/ts-0-root/wals/4808b56090a14f6082ad57f7fcd183bf/wal-000000002 (ops 7-11)
I20260812 06:17:32.913792 19626 maintenance_manager.cc:643] P b3b3a2f0924e41c4960d47ff0e9ba866: LogGCOp(4808b56090a14f6082ad57f7fcd183bf) complete. Timing: real 0.005s	user 0.000s	sys 0.004s Metrics: {}
I20260812 06:17:32.915316 19725 maintenance_manager.cc:419] P b3b3a2f0924e41c4960d47ff0e9ba866: Scheduling FlushDeltaMemStoresOp(4808b56090a14f6082ad57f7fcd183bf): perf score=2.188937
I20260812 06:17:32.934310 19626 maintenance_manager.cc:643] P b3b3a2f0924e41c4960d47ff0e9ba866: FlushDeltaMemStoresOp(4808b56090a14f6082ad57f7fcd183bf) complete. Timing: real 0.019s	user 0.010s	sys 0.001s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5087,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:32.934755 19725 maintenance_manager.cc:419] P b3b3a2f0924e41c4960d47ff0e9ba866: Scheduling MajorDeltaCompactionOp(4808b56090a14f6082ad57f7fcd183bf): perf score=1.000000
I20260812 06:17:33.094000 19626 maintenance_manager.cc:643] P b3b3a2f0924e41c4960d47ff0e9ba866: MajorDeltaCompactionOp(4808b56090a14f6082ad57f7fcd183bf) complete. Timing: real 0.159s	user 0.115s	sys 0.037s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20713272,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":489,"lbm_read_time_us":11203,"lbm_reads_lt_1ms":464,"lbm_write_time_us":24519,"lbm_writes_lt_1ms":443,"mutex_wait_us":37,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":4224,"thread_start_us":325,"threads_started":5,"update_count":2000}
I20260812 06:17:33.094555 19725 maintenance_manager.cc:419] P b3b3a2f0924e41c4960d47ff0e9ba866: Scheduling FlushDeltaMemStoresOp(4808b56090a14f6082ad57f7fcd183bf): perf score=14.095187
I20260812 06:17:33.154744 19626 maintenance_manager.cc:643] P b3b3a2f0924e41c4960d47ff0e9ba866: FlushDeltaMemStoresOp(4808b56090a14f6082ad57f7fcd183bf) complete. Timing: real 0.060s	user 0.049s	sys 0.007s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":24511,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":402,"reinsert_count":0,"update_count":2000}
I20260812 06:17:33.155206 19725 maintenance_manager.cc:419] P b3b3a2f0924e41c4960d47ff0e9ba866: Scheduling UndoDeltaBlockGCOp(4808b56090a14f6082ad57f7fcd183bf): 20513813 bytes on disk
I20260812 06:17:33.155594 19626 maintenance_manager.cc:643] P b3b3a2f0924e41c4960d47ff0e9ba866: UndoDeltaBlockGCOp(4808b56090a14f6082ad57f7fcd183bf) 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:17:33.155972 19725 maintenance_manager.cc:419] P b3b3a2f0924e41c4960d47ff0e9ba866: Scheduling FlushDeltaMemStoresOp(4808b56090a14f6082ad57f7fcd183bf): perf score=2.188937
I20260812 06:17:33.168543 19626 maintenance_manager.cc:643] P b3b3a2f0924e41c4960d47ff0e9ba866: FlushDeltaMemStoresOp(4808b56090a14f6082ad57f7fcd183bf) complete. Timing: real 0.012s	user 0.010s	sys 0.001s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4677,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:33.169087 19725 maintenance_manager.cc:419] P b3b3a2f0924e41c4960d47ff0e9ba866: Scheduling MajorDeltaCompactionOp(4808b56090a14f6082ad57f7fcd183bf): perf score=1.000000
I20260812 06:17:33.343897 19626 maintenance_manager.cc:643] P b3b3a2f0924e41c4960d47ff0e9ba866: MajorDeltaCompactionOp(4808b56090a14f6082ad57f7fcd183bf) complete. Timing: real 0.175s	user 0.105s	sys 0.069s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24815682,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":164,"lbm_read_time_us":12237,"lbm_reads_lt_1ms":572,"lbm_write_time_us":27246,"lbm_writes_lt_1ms":543,"mutex_wait_us":34,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":2432,"update_count":2500}
I20260812 06:17:33.344571 19725 maintenance_manager.cc:419] P b3b3a2f0924e41c4960d47ff0e9ba866: Scheduling FlushDeltaMemStoresOp(4808b56090a14f6082ad57f7fcd183bf): perf score=14.095187
I20260812 06:17:33.399205 19626 maintenance_manager.cc:643] P b3b3a2f0924e41c4960d47ff0e9ba866: FlushDeltaMemStoresOp(4808b56090a14f6082ad57f7fcd183bf) complete. Timing: real 0.054s	user 0.039s	sys 0.015s Metrics: {"bytes_written":16409905,"delete_count":0,"lbm_write_time_us":24847,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:17:33.399634 19725 maintenance_manager.cc:419] P b3b3a2f0924e41c4960d47ff0e9ba866: Scheduling FlushDeltaMemStoresOp(4808b56090a14f6082ad57f7fcd183bf): perf score=2.188937
I20260812 06:17:33.419958 19626 maintenance_manager.cc:643] P b3b3a2f0924e41c4960d47ff0e9ba866: FlushDeltaMemStoresOp(4808b56090a14f6082ad57f7fcd183bf) complete. Timing: real 0.020s	user 0.009s	sys 0.011s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4034,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:33.420449 19725 maintenance_manager.cc:419] P b3b3a2f0924e41c4960d47ff0e9ba866: Scheduling MajorDeltaCompactionOp(4808b56090a14f6082ad57f7fcd183bf): perf score=1.000000
I20260812 06:17:33.598965 19626 maintenance_manager.cc:643] P b3b3a2f0924e41c4960d47ff0e9ba866: MajorDeltaCompactionOp(4808b56090a14f6082ad57f7fcd183bf) complete. Timing: real 0.178s	user 0.125s	sys 0.051s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24815687,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":699,"lbm_read_time_us":12392,"lbm_reads_lt_1ms":572,"lbm_write_time_us":29343,"lbm_writes_lt_1ms":543,"mutex_wait_us":69,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":3456,"update_count":2500}
I20260812 06:17:33.599594 19725 maintenance_manager.cc:419] P b3b3a2f0924e41c4960d47ff0e9ba866: Scheduling FlushDeltaMemStoresOp(4808b56090a14f6082ad57f7fcd183bf): perf score=14.095187
I20260812 06:17:33.661928 19626 maintenance_manager.cc:643] P b3b3a2f0924e41c4960d47ff0e9ba866: FlushDeltaMemStoresOp(4808b56090a14f6082ad57f7fcd183bf) complete. Timing: real 0.062s	user 0.037s	sys 0.022s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":29541,"lbm_writes_1-10_ms":2,"lbm_writes_lt_1ms":401,"reinsert_count":0,"update_count":2000}
I20260812 06:17:33.662390 19725 maintenance_manager.cc:419] P b3b3a2f0924e41c4960d47ff0e9ba866: Scheduling FlushDeltaMemStoresOp(4808b56090a14f6082ad57f7fcd183bf): perf score=2.188937
I20260812 06:17:33.674149 19626 maintenance_manager.cc:643] P b3b3a2f0924e41c4960d47ff0e9ba866: FlushDeltaMemStoresOp(4808b56090a14f6082ad57f7fcd183bf) complete. Timing: real 0.012s	user 0.007s	sys 0.003s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4428,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:33.674688 19725 maintenance_manager.cc:419] P b3b3a2f0924e41c4960d47ff0e9ba866: Scheduling MajorDeltaCompactionOp(4808b56090a14f6082ad57f7fcd183bf): perf score=1.000000
I20260812 06:17:33.857810 19626 maintenance_manager.cc:643] P b3b3a2f0924e41c4960d47ff0e9ba866: MajorDeltaCompactionOp(4808b56090a14f6082ad57f7fcd183bf) complete. Timing: real 0.183s	user 0.123s	sys 0.053s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24815683,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":252,"lbm_read_time_us":11689,"lbm_reads_lt_1ms":572,"lbm_write_time_us":31257,"lbm_writes_lt_1ms":543,"mutex_wait_us":38,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":10496,"update_count":2500}
I20260812 06:17:33.858584 19725 maintenance_manager.cc:419] P b3b3a2f0924e41c4960d47ff0e9ba866: Scheduling FlushDeltaMemStoresOp(4808b56090a14f6082ad57f7fcd183bf): perf score=14.095187
I20260812 06:17:33.914543 19626 maintenance_manager.cc:643] P b3b3a2f0924e41c4960d47ff0e9ba866: FlushDeltaMemStoresOp(4808b56090a14f6082ad57f7fcd183bf) complete. Timing: real 0.056s	user 0.032s	sys 0.012s Metrics: {"bytes_written":16409900,"delete_count":0,"lbm_write_time_us":21271,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:17:33.915069 19725 maintenance_manager.cc:419] P b3b3a2f0924e41c4960d47ff0e9ba866: Scheduling FlushDeltaMemStoresOp(4808b56090a14f6082ad57f7fcd183bf): perf score=2.188937
I20260812 06:17:33.925933 19626 maintenance_manager.cc:643] P b3b3a2f0924e41c4960d47ff0e9ba866: FlushDeltaMemStoresOp(4808b56090a14f6082ad57f7fcd183bf) complete. Timing: real 0.011s	user 0.000s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4095,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:33.926383 19725 maintenance_manager.cc:419] P b3b3a2f0924e41c4960d47ff0e9ba866: Scheduling MajorDeltaCompactionOp(4808b56090a14f6082ad57f7fcd183bf): perf score=1.000000
I20260812 06:17:34.088076 19626 maintenance_manager.cc:643] P b3b3a2f0924e41c4960d47ff0e9ba866: MajorDeltaCompactionOp(4808b56090a14f6082ad57f7fcd183bf) complete. Timing: real 0.162s	user 0.134s	sys 0.015s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24815682,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":931,"lbm_read_time_us":11075,"lbm_reads_lt_1ms":572,"lbm_write_time_us":29142,"lbm_writes_lt_1ms":543,"mutex_wait_us":323,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":3584,"update_count":2500}
I20260812 06:17:34.088726 19725 maintenance_manager.cc:419] P b3b3a2f0924e41c4960d47ff0e9ba866: Scheduling FlushDeltaMemStoresOp(4808b56090a14f6082ad57f7fcd183bf): perf score=14.095187
I20260812 06:17:34.142149 19626 maintenance_manager.cc:643] P b3b3a2f0924e41c4960d47ff0e9ba866: FlushDeltaMemStoresOp(4808b56090a14f6082ad57f7fcd183bf) complete. Timing: real 0.053s	user 0.039s	sys 0.003s Metrics: {"bytes_written":16409904,"delete_count":0,"lbm_write_time_us":20637,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:17:34.142590 19725 maintenance_manager.cc:419] P b3b3a2f0924e41c4960d47ff0e9ba866: Scheduling FlushDeltaMemStoresOp(4808b56090a14f6082ad57f7fcd183bf): perf score=2.188937
I20260812 06:17:34.153249 19626 maintenance_manager.cc:643] P b3b3a2f0924e41c4960d47ff0e9ba866: FlushDeltaMemStoresOp(4808b56090a14f6082ad57f7fcd183bf) complete. Timing: real 0.010s	user 0.006s	sys 0.003s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4141,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:34.153841 19725 maintenance_manager.cc:419] P b3b3a2f0924e41c4960d47ff0e9ba866: Scheduling FlushMRSOp(4808b56090a14f6082ad57f7fcd183bf): perf score=1.000000
I20260812 06:17:34.183374 19626 maintenance_manager.cc:643] P b3b3a2f0924e41c4960d47ff0e9ba866: FlushMRSOp(4808b56090a14f6082ad57f7fcd183bf) complete. Timing: real 0.029s	user 0.021s	sys 0.008s Metrics: {"bytes_written":1193503,"cfile_init":1,"dirs.queue_time_us":66,"dirs.run_cpu_time_us":278,"dirs.run_wall_time_us":1273,"drs_written":1,"lbm_read_time_us":59,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1671,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":29}
I20260812 06:17:34.183972 19725 maintenance_manager.cc:419] P b3b3a2f0924e41c4960d47ff0e9ba866: Scheduling LogGCOp(4808b56090a14f6082ad57f7fcd183bf): free 124257238 bytes of WAL
I20260812 06:17:34.184192 19626 log_reader.cc:385] T 4808b56090a14f6082ad57f7fcd183bf: removed 12 log segments from log reader
I20260812 06:17:34.184238 19626 log.cc:1079] T 4808b56090a14f6082ad57f7fcd183bf P b3b3a2f0924e41c4960d47ff0e9ba866: Deleting log segment in path: /tmp/dist-test-task7hz9Df/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515446107064-19121-0/minicluster-data/ts-0-root/wals/4808b56090a14f6082ad57f7fcd183bf/wal-000000003 (ops 12-16)
I20260812 06:17:34.184267 19626 log.cc:1079] T 4808b56090a14f6082ad57f7fcd183bf P b3b3a2f0924e41c4960d47ff0e9ba866: Deleting log segment in path: /tmp/dist-test-task7hz9Df/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515446107064-19121-0/minicluster-data/ts-0-root/wals/4808b56090a14f6082ad57f7fcd183bf/wal-000000004 (ops 17-21)
I20260812 06:17:34.184331 19626 log.cc:1079] T 4808b56090a14f6082ad57f7fcd183bf P b3b3a2f0924e41c4960d47ff0e9ba866: Deleting log segment in path: /tmp/dist-test-task7hz9Df/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515446107064-19121-0/minicluster-data/ts-0-root/wals/4808b56090a14f6082ad57f7fcd183bf/wal-000000005 (ops 22-26)
I20260812 06:17:34.184363 19626 log.cc:1079] T 4808b56090a14f6082ad57f7fcd183bf P b3b3a2f0924e41c4960d47ff0e9ba866: Deleting log segment in path: /tmp/dist-test-task7hz9Df/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515446107064-19121-0/minicluster-data/ts-0-root/wals/4808b56090a14f6082ad57f7fcd183bf/wal-000000006 (ops 27-31)
I20260812 06:17:34.184405 19626 log.cc:1079] T 4808b56090a14f6082ad57f7fcd183bf P b3b3a2f0924e41c4960d47ff0e9ba866: Deleting log segment in path: /tmp/dist-test-task7hz9Df/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515446107064-19121-0/minicluster-data/ts-0-root/wals/4808b56090a14f6082ad57f7fcd183bf/wal-000000007 (ops 32-36)
I20260812 06:17:34.184456 19626 log.cc:1079] T 4808b56090a14f6082ad57f7fcd183bf P b3b3a2f0924e41c4960d47ff0e9ba866: Deleting log segment in path: /tmp/dist-test-task7hz9Df/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515446107064-19121-0/minicluster-data/ts-0-root/wals/4808b56090a14f6082ad57f7fcd183bf/wal-000000008 (ops 37-41)
I20260812 06:17:34.184492 19626 log.cc:1079] T 4808b56090a14f6082ad57f7fcd183bf P b3b3a2f0924e41c4960d47ff0e9ba866: Deleting log segment in path: /tmp/dist-test-task7hz9Df/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515446107064-19121-0/minicluster-data/ts-0-root/wals/4808b56090a14f6082ad57f7fcd183bf/wal-000000009 (ops 42-46)
I20260812 06:17:34.184531 19626 log.cc:1079] T 4808b56090a14f6082ad57f7fcd183bf P b3b3a2f0924e41c4960d47ff0e9ba866: Deleting log segment in path: /tmp/dist-test-task7hz9Df/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515446107064-19121-0/minicluster-data/ts-0-root/wals/4808b56090a14f6082ad57f7fcd183bf/wal-000000010 (ops 47-50)
I20260812 06:17:34.184572 19626 log.cc:1079] T 4808b56090a14f6082ad57f7fcd183bf P b3b3a2f0924e41c4960d47ff0e9ba866: Deleting log segment in path: /tmp/dist-test-task7hz9Df/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515446107064-19121-0/minicluster-data/ts-0-root/wals/4808b56090a14f6082ad57f7fcd183bf/wal-000000011 (ops 51-55)
I20260812 06:17:34.184612 19626 log.cc:1079] T 4808b56090a14f6082ad57f7fcd183bf P b3b3a2f0924e41c4960d47ff0e9ba866: Deleting log segment in path: /tmp/dist-test-task7hz9Df/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515446107064-19121-0/minicluster-data/ts-0-root/wals/4808b56090a14f6082ad57f7fcd183bf/wal-000000012 (ops 56-60)
I20260812 06:17:34.184650 19626 log.cc:1079] T 4808b56090a14f6082ad57f7fcd183bf P b3b3a2f0924e41c4960d47ff0e9ba866: Deleting log segment in path: /tmp/dist-test-task7hz9Df/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515446107064-19121-0/minicluster-data/ts-0-root/wals/4808b56090a14f6082ad57f7fcd183bf/wal-000000013 (ops 61-65)
I20260812 06:17:34.184689 19626 log.cc:1079] T 4808b56090a14f6082ad57f7fcd183bf P b3b3a2f0924e41c4960d47ff0e9ba866: Deleting log segment in path: /tmp/dist-test-task7hz9Df/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515446107064-19121-0/minicluster-data/ts-0-root/wals/4808b56090a14f6082ad57f7fcd183bf/wal-000000014 (ops 66-70)
I20260812 06:17:34.214958 19626 maintenance_manager.cc:643] P b3b3a2f0924e41c4960d47ff0e9ba866: LogGCOp(4808b56090a14f6082ad57f7fcd183bf) complete. Timing: real 0.031s	user 0.000s	sys 0.031s Metrics: {}
I20260812 06:17:34.215368 19725 maintenance_manager.cc:419] P b3b3a2f0924e41c4960d47ff0e9ba866: Scheduling UndoDeltaBlockGCOp(4808b56090a14f6082ad57f7fcd183bf): 462 bytes on disk
I20260812 06:17:34.216099 19626 maintenance_manager.cc:643] P b3b3a2f0924e41c4960d47ff0e9ba866: UndoDeltaBlockGCOp(4808b56090a14f6082ad57f7fcd183bf) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":72,"lbm_reads_lt_1ms":4}
I20260812 06:17:34.216747 19725 maintenance_manager.cc:419] P b3b3a2f0924e41c4960d47ff0e9ba866: Scheduling FlushDeltaMemStoresOp(4808b56090a14f6082ad57f7fcd183bf): perf score=4.173312
I20260812 06:17:34.246879 19626 maintenance_manager.cc:643] P b3b3a2f0924e41c4960d47ff0e9ba866: FlushDeltaMemStoresOp(4808b56090a14f6082ad57f7fcd183bf) complete. Timing: real 0.030s	user 0.006s	sys 0.023s Metrics: {"bytes_written":6030800,"delete_count":0,"lbm_write_time_us":7260,"lbm_writes_lt_1ms":150,"reinsert_count":0,"update_count":735}
I20260812 06:17:34.247324 19725 maintenance_manager.cc:419] P b3b3a2f0924e41c4960d47ff0e9ba866: Scheduling FlushDeltaMemStoresOp(4808b56090a14f6082ad57f7fcd183bf): perf score=1.196750
I20260812 06:17:34.257226 19626 maintenance_manager.cc:643] P b3b3a2f0924e41c4960d47ff0e9ba866: FlushDeltaMemStoresOp(4808b56090a14f6082ad57f7fcd183bf) complete. Timing: real 0.010s	user 0.004s	sys 0.004s Metrics: {"bytes_written":2174479,"delete_count":0,"lbm_write_time_us":3243,"lbm_writes_lt_1ms":56,"reinsert_count":0,"update_count":265}
I20260812 06:17:34.257714 19725 maintenance_manager.cc:419] P b3b3a2f0924e41c4960d47ff0e9ba866: Scheduling MajorDeltaCompactionOp(4808b56090a14f6082ad57f7fcd183bf): perf score=1.000000
I20260812 06:17:34.477770 19626 maintenance_manager.cc:643] P b3b3a2f0924e41c4960d47ff0e9ba866: MajorDeltaCompactionOp(4808b56090a14f6082ad57f7fcd183bf) complete. Timing: real 0.220s	user 0.146s	sys 0.069s Metrics: {"cfile_cache_miss":734,"cfile_cache_miss_bytes":33020703,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":436,"lbm_read_time_us":15064,"lbm_reads_lt_1ms":774,"lbm_write_time_us":38438,"lbm_writes_lt_1ms":743,"mutex_wait_us":49,"peak_mem_usage":87969044,"reinsert_count":0,"spinlock_wait_cycles":2176,"thread_start_us":79,"threads_started":1,"update_count":3500}
I20260812 06:17:34.478493 19725 maintenance_manager.cc:419] P b3b3a2f0924e41c4960d47ff0e9ba866: Scheduling FlushDeltaMemStoresOp(4808b56090a14f6082ad57f7fcd183bf): perf score=15.087375
I20260812 06:17:34.531526 19626 maintenance_manager.cc:643] P b3b3a2f0924e41c4960d47ff0e9ba866: FlushDeltaMemStoresOp(4808b56090a14f6082ad57f7fcd183bf) complete. Timing: real 0.053s	user 0.022s	sys 0.019s Metrics: {"bytes_written":16820144,"delete_count":0,"lbm_write_time_us":18724,"lbm_writes_lt_1ms":413,"reinsert_count":0,"update_count":2050}
I20260812 06:17:34.532126 19725 maintenance_manager.cc:419] P b3b3a2f0924e41c4960d47ff0e9ba866: Scheduling FlushDeltaMemStoresOp(4808b56090a14f6082ad57f7fcd183bf): perf score=2.188937
I20260812 06:17:34.544688 19626 maintenance_manager.cc:643] P b3b3a2f0924e41c4960d47ff0e9ba866: FlushDeltaMemStoresOp(4808b56090a14f6082ad57f7fcd183bf) complete. Timing: real 0.012s	user 0.011s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4925,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:34.545111 19725 maintenance_manager.cc:419] P b3b3a2f0924e41c4960d47ff0e9ba866: Scheduling FlushDeltaMemStoresOp(4808b56090a14f6082ad57f7fcd183bf): perf score=2.188937
I20260812 06:17:34.554904 19626 maintenance_manager.cc:643] P b3b3a2f0924e41c4960d47ff0e9ba866: FlushDeltaMemStoresOp(4808b56090a14f6082ad57f7fcd183bf) complete. Timing: real 0.010s	user 0.006s	sys 0.004s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3908,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:17:34.555310 19725 maintenance_manager.cc:419] P b3b3a2f0924e41c4960d47ff0e9ba866: Scheduling MajorDeltaCompactionOp(4808b56090a14f6082ad57f7fcd183bf): perf score=1.000000
I20260812 06:17:34.767149 19626 maintenance_manager.cc:643] P b3b3a2f0924e41c4960d47ff0e9ba866: MajorDeltaCompactionOp(4808b56090a14f6082ad57f7fcd183bf) complete. Timing: real 0.212s	user 0.115s	sys 0.093s Metrics: {"cfile_cache_miss":633,"cfile_cache_miss_bytes":28918203,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":1091,"lbm_read_time_us":17125,"lbm_reads_lt_1ms":673,"lbm_write_time_us":32450,"lbm_writes_lt_1ms":643,"mutex_wait_us":55,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":13824,"update_count":3000}
I20260812 06:17:34.767889 19725 maintenance_manager.cc:419] P b3b3a2f0924e41c4960d47ff0e9ba866: Scheduling FlushDeltaMemStoresOp(4808b56090a14f6082ad57f7fcd183bf): perf score=16.079562
I20260812 06:17:34.833293 19626 maintenance_manager.cc:643] P b3b3a2f0924e41c4960d47ff0e9ba866: FlushDeltaMemStoresOp(4808b56090a14f6082ad57f7fcd183bf) complete. Timing: real 0.065s	user 0.037s	sys 0.012s Metrics: {"bytes_written":17968823,"delete_count":0,"lbm_write_time_us":22827,"lbm_writes_lt_1ms":441,"reinsert_count":0,"update_count":2190}
I20260812 06:17:34.833840 19725 maintenance_manager.cc:419] P b3b3a2f0924e41c4960d47ff0e9ba866: Scheduling FlushDeltaMemStoresOp(4808b56090a14f6082ad57f7fcd183bf): perf score=5.165500
I20260812 06:17:34.857551 19626 maintenance_manager.cc:643] P b3b3a2f0924e41c4960d47ff0e9ba866: FlushDeltaMemStoresOp(4808b56090a14f6082ad57f7fcd183bf) complete. Timing: real 0.024s	user 0.012s	sys 0.008s Metrics: {"bytes_written":6646165,"delete_count":0,"lbm_write_time_us":9784,"lbm_writes_lt_1ms":165,"reinsert_count":0,"update_count":810}
I20260812 06:17:34.858037 19725 maintenance_manager.cc:419] P b3b3a2f0924e41c4960d47ff0e9ba866: Scheduling MajorDeltaCompactionOp(4808b56090a14f6082ad57f7fcd183bf): perf score=1.000000
I20260812 06:17:35.055974 19626 maintenance_manager.cc:643] P b3b3a2f0924e41c4960d47ff0e9ba866: MajorDeltaCompactionOp(4808b56090a14f6082ad57f7fcd183bf) complete. Timing: real 0.198s	user 0.152s	sys 0.045s Metrics: {"cfile_cache_miss":632,"cfile_cache_miss_bytes":28918105,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":585,"lbm_read_time_us":14211,"lbm_reads_lt_1ms":664,"lbm_write_time_us":35086,"lbm_writes_lt_1ms":643,"mutex_wait_us":274,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":6528,"update_count":3000}
I20260812 06:17:35.056669 19725 maintenance_manager.cc:419] P b3b3a2f0924e41c4960d47ff0e9ba866: Scheduling FlushDeltaMemStoresOp(4808b56090a14f6082ad57f7fcd183bf): perf score=14.095187
I20260812 06:17:35.103976 19626 maintenance_manager.cc:643] P b3b3a2f0924e41c4960d47ff0e9ba866: FlushDeltaMemStoresOp(4808b56090a14f6082ad57f7fcd183bf) complete. Timing: real 0.047s	user 0.042s	sys 0.003s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":20634,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:17:35.104602 19725 maintenance_manager.cc:419] P b3b3a2f0924e41c4960d47ff0e9ba866: Scheduling FlushDeltaMemStoresOp(4808b56090a14f6082ad57f7fcd183bf): perf score=2.188937
I20260812 06:17:35.131224 19626 maintenance_manager.cc:643] P b3b3a2f0924e41c4960d47ff0e9ba866: FlushDeltaMemStoresOp(4808b56090a14f6082ad57f7fcd183bf) complete. Timing: real 0.026s	user 0.013s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5266,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:35.131701 19725 maintenance_manager.cc:419] P b3b3a2f0924e41c4960d47ff0e9ba866: Scheduling FlushDeltaMemStoresOp(4808b56090a14f6082ad57f7fcd183bf): perf score=2.188937
I20260812 06:17:35.141515 19626 maintenance_manager.cc:643] P b3b3a2f0924e41c4960d47ff0e9ba866: FlushDeltaMemStoresOp(4808b56090a14f6082ad57f7fcd183bf) complete. Timing: real 0.010s	user 0.005s	sys 0.003s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3987,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:35.141911 19725 maintenance_manager.cc:419] P b3b3a2f0924e41c4960d47ff0e9ba866: Scheduling MajorDeltaCompactionOp(4808b56090a14f6082ad57f7fcd183bf): perf score=1.000000
I20260812 06:17:35.352727 19626 maintenance_manager.cc:643] P b3b3a2f0924e41c4960d47ff0e9ba866: MajorDeltaCompactionOp(4808b56090a14f6082ad57f7fcd183bf) complete. Timing: real 0.211s	user 0.138s	sys 0.069s Metrics: {"cfile_cache_miss":633,"cfile_cache_miss_bytes":28918214,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":371,"lbm_read_time_us":15014,"lbm_reads_lt_1ms":673,"lbm_write_time_us":34534,"lbm_writes_lt_1ms":643,"mutex_wait_us":72,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":14336,"update_count":3000}
I20260812 06:17:35.353513 19725 maintenance_manager.cc:419] P b3b3a2f0924e41c4960d47ff0e9ba866: Scheduling FlushDeltaMemStoresOp(4808b56090a14f6082ad57f7fcd183bf): perf score=16.079562
I20260812 06:17:35.416011 19626 maintenance_manager.cc:643] P b3b3a2f0924e41c4960d47ff0e9ba866: FlushDeltaMemStoresOp(4808b56090a14f6082ad57f7fcd183bf) complete. Timing: real 0.062s	user 0.041s	sys 0.015s Metrics: {"bytes_written":17845748,"delete_count":0,"lbm_write_time_us":25494,"lbm_writes_lt_1ms":438,"reinsert_count":0,"update_count":2175}
I20260812 06:17:35.416589 19725 maintenance_manager.cc:419] P b3b3a2f0924e41c4960d47ff0e9ba866: Scheduling FlushDeltaMemStoresOp(4808b56090a14f6082ad57f7fcd183bf): perf score=1.196750
I20260812 06:17:35.436864 19626 maintenance_manager.cc:643] P b3b3a2f0924e41c4960d47ff0e9ba866: FlushDeltaMemStoresOp(4808b56090a14f6082ad57f7fcd183bf) complete. Timing: real 0.020s	user 0.004s	sys 0.008s Metrics: {"bytes_written":3077034,"delete_count":0,"lbm_write_time_us":4993,"lbm_writes_lt_1ms":78,"reinsert_count":0,"update_count":375}
I20260812 06:17:35.437391 19725 maintenance_manager.cc:419] P b3b3a2f0924e41c4960d47ff0e9ba866: Scheduling FlushDeltaMemStoresOp(4808b56090a14f6082ad57f7fcd183bf): perf score=2.188937
I20260812 06:17:35.446871 19626 maintenance_manager.cc:643] P b3b3a2f0924e41c4960d47ff0e9ba866: FlushDeltaMemStoresOp(4808b56090a14f6082ad57f7fcd183bf) complete. Timing: real 0.009s	user 0.008s	sys 0.000s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3596,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:17:35.447253 19725 maintenance_manager.cc:419] P b3b3a2f0924e41c4960d47ff0e9ba866: Scheduling MajorDeltaCompactionOp(4808b56090a14f6082ad57f7fcd183bf): perf score=1.000000
I20260812 06:17:35.675102 19626 maintenance_manager.cc:643] P b3b3a2f0924e41c4960d47ff0e9ba866: MajorDeltaCompactionOp(4808b56090a14f6082ad57f7fcd183bf) complete. Timing: real 0.228s	user 0.128s	sys 0.085s Metrics: {"cfile_cache_miss":633,"cfile_cache_miss_bytes":28918182,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":1066,"lbm_read_time_us":14167,"lbm_reads_lt_1ms":673,"lbm_write_time_us":35412,"lbm_writes_lt_1ms":643,"mutex_wait_us":71,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":6784,"update_count":3000}
I20260812 06:17:35.676014 19725 maintenance_manager.cc:419] P b3b3a2f0924e41c4960d47ff0e9ba866: Scheduling FlushDeltaMemStoresOp(4808b56090a14f6082ad57f7fcd183bf): perf score=18.063937
I20260812 06:17:35.741854 19626 maintenance_manager.cc:643] P b3b3a2f0924e41c4960d47ff0e9ba866: FlushDeltaMemStoresOp(4808b56090a14f6082ad57f7fcd183bf) complete. Timing: real 0.066s	user 0.022s	sys 0.030s Metrics: {"bytes_written":20512315,"delete_count":0,"lbm_write_time_us":24658,"lbm_writes_lt_1ms":503,"reinsert_count":0,"update_count":2500}
I20260812 06:17:35.742408 19725 maintenance_manager.cc:419] P b3b3a2f0924e41c4960d47ff0e9ba866: Scheduling FlushDeltaMemStoresOp(4808b56090a14f6082ad57f7fcd183bf): perf score=2.188937
I20260812 06:17:35.752895 19626 maintenance_manager.cc:643] P b3b3a2f0924e41c4960d47ff0e9ba866: FlushDeltaMemStoresOp(4808b56090a14f6082ad57f7fcd183bf) complete. Timing: real 0.010s	user 0.002s	sys 0.007s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3987,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:35.753476 19725 maintenance_manager.cc:419] P b3b3a2f0924e41c4960d47ff0e9ba866: Scheduling FlushMRSOp(4808b56090a14f6082ad57f7fcd183bf): perf score=1.000000
I20260812 06:17:35.785782 19626 maintenance_manager.cc:643] P b3b3a2f0924e41c4960d47ff0e9ba866: FlushMRSOp(4808b56090a14f6082ad57f7fcd183bf) complete. Timing: real 0.032s	user 0.030s	sys 0.000s Metrics: {"bytes_written":1316419,"cfile_init":1,"dirs.queue_time_us":144,"dirs.run_cpu_time_us":196,"dirs.run_wall_time_us":1053,"drs_written":1,"lbm_read_time_us":59,"lbm_reads_lt_1ms":4,"lbm_write_time_us":2025,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":32,"spinlock_wait_cycles":896}
I20260812 06:17:35.786448 19725 maintenance_manager.cc:419] P b3b3a2f0924e41c4960d47ff0e9ba866: Scheduling LogGCOp(4808b56090a14f6082ad57f7fcd183bf): free 128867486 bytes of WAL
I20260812 06:17:35.786720 19626 log_reader.cc:385] T 4808b56090a14f6082ad57f7fcd183bf: removed 13 log segments from log reader
I20260812 06:17:35.786782 19626 log.cc:1079] T 4808b56090a14f6082ad57f7fcd183bf P b3b3a2f0924e41c4960d47ff0e9ba866: Deleting log segment in path: /tmp/dist-test-task7hz9Df/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515446107064-19121-0/minicluster-data/ts-0-root/wals/4808b56090a14f6082ad57f7fcd183bf/wal-000000015 (ops 71-75)
I20260812 06:17:35.786847 19626 log.cc:1079] T 4808b56090a14f6082ad57f7fcd183bf P b3b3a2f0924e41c4960d47ff0e9ba866: Deleting log segment in path: /tmp/dist-test-task7hz9Df/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515446107064-19121-0/minicluster-data/ts-0-root/wals/4808b56090a14f6082ad57f7fcd183bf/wal-000000016 (ops 76-80)
I20260812 06:17:35.786890 19626 log.cc:1079] T 4808b56090a14f6082ad57f7fcd183bf P b3b3a2f0924e41c4960d47ff0e9ba866: Deleting log segment in path: /tmp/dist-test-task7hz9Df/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515446107064-19121-0/minicluster-data/ts-0-root/wals/4808b56090a14f6082ad57f7fcd183bf/wal-000000017 (ops 81-84)
I20260812 06:17:35.786918 19626 log.cc:1079] T 4808b56090a14f6082ad57f7fcd183bf P b3b3a2f0924e41c4960d47ff0e9ba866: Deleting log segment in path: /tmp/dist-test-task7hz9Df/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515446107064-19121-0/minicluster-data/ts-0-root/wals/4808b56090a14f6082ad57f7fcd183bf/wal-000000018 (ops 85-89)
I20260812 06:17:35.786942 19626 log.cc:1079] T 4808b56090a14f6082ad57f7fcd183bf P b3b3a2f0924e41c4960d47ff0e9ba866: Deleting log segment in path: /tmp/dist-test-task7hz9Df/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515446107064-19121-0/minicluster-data/ts-0-root/wals/4808b56090a14f6082ad57f7fcd183bf/wal-000000019 (ops 90-94)
I20260812 06:17:35.786964 19626 log.cc:1079] T 4808b56090a14f6082ad57f7fcd183bf P b3b3a2f0924e41c4960d47ff0e9ba866: Deleting log segment in path: /tmp/dist-test-task7hz9Df/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515446107064-19121-0/minicluster-data/ts-0-root/wals/4808b56090a14f6082ad57f7fcd183bf/wal-000000020 (ops 95-99)
I20260812 06:17:35.786995 19626 log.cc:1079] T 4808b56090a14f6082ad57f7fcd183bf P b3b3a2f0924e41c4960d47ff0e9ba866: Deleting log segment in path: /tmp/dist-test-task7hz9Df/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515446107064-19121-0/minicluster-data/ts-0-root/wals/4808b56090a14f6082ad57f7fcd183bf/wal-000000021 (ops 100-104)
I20260812 06:17:35.787031 19626 log.cc:1079] T 4808b56090a14f6082ad57f7fcd183bf P b3b3a2f0924e41c4960d47ff0e9ba866: Deleting log segment in path: /tmp/dist-test-task7hz9Df/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515446107064-19121-0/minicluster-data/ts-0-root/wals/4808b56090a14f6082ad57f7fcd183bf/wal-000000022 (ops 105-108)
I20260812 06:17:35.787065 19626 log.cc:1079] T 4808b56090a14f6082ad57f7fcd183bf P b3b3a2f0924e41c4960d47ff0e9ba866: Deleting log segment in path: /tmp/dist-test-task7hz9Df/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515446107064-19121-0/minicluster-data/ts-0-root/wals/4808b56090a14f6082ad57f7fcd183bf/wal-000000023 (ops 109-113)
I20260812 06:17:35.787096 19626 log.cc:1079] T 4808b56090a14f6082ad57f7fcd183bf P b3b3a2f0924e41c4960d47ff0e9ba866: Deleting log segment in path: /tmp/dist-test-task7hz9Df/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515446107064-19121-0/minicluster-data/ts-0-root/wals/4808b56090a14f6082ad57f7fcd183bf/wal-000000024 (ops 114-118)
I20260812 06:17:35.787124 19626 log.cc:1079] T 4808b56090a14f6082ad57f7fcd183bf P b3b3a2f0924e41c4960d47ff0e9ba866: Deleting log segment in path: /tmp/dist-test-task7hz9Df/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515446107064-19121-0/minicluster-data/ts-0-root/wals/4808b56090a14f6082ad57f7fcd183bf/wal-000000025 (ops 119-123)
I20260812 06:17:35.787154 19626 log.cc:1079] T 4808b56090a14f6082ad57f7fcd183bf P b3b3a2f0924e41c4960d47ff0e9ba866: Deleting log segment in path: /tmp/dist-test-task7hz9Df/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515446107064-19121-0/minicluster-data/ts-0-root/wals/4808b56090a14f6082ad57f7fcd183bf/wal-000000026 (ops 124-128)
I20260812 06:17:35.787187 19626 log.cc:1079] T 4808b56090a14f6082ad57f7fcd183bf P b3b3a2f0924e41c4960d47ff0e9ba866: Deleting log segment in path: /tmp/dist-test-task7hz9Df/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515446107064-19121-0/minicluster-data/ts-0-root/wals/4808b56090a14f6082ad57f7fcd183bf/wal-000000027 (ops 129-132)
I20260812 06:17:35.818924 19626 maintenance_manager.cc:643] P b3b3a2f0924e41c4960d47ff0e9ba866: LogGCOp(4808b56090a14f6082ad57f7fcd183bf) complete. Timing: real 0.032s	user 0.001s	sys 0.031s Metrics: {}
I20260812 06:17:35.819351 19725 maintenance_manager.cc:419] P b3b3a2f0924e41c4960d47ff0e9ba866: Scheduling UndoDeltaBlockGCOp(4808b56090a14f6082ad57f7fcd183bf): 492 bytes on disk
I20260812 06:17:35.819769 19626 maintenance_manager.cc:643] P b3b3a2f0924e41c4960d47ff0e9ba866: UndoDeltaBlockGCOp(4808b56090a14f6082ad57f7fcd183bf) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":48,"lbm_reads_lt_1ms":4}
I20260812 06:17:35.820369 19725 maintenance_manager.cc:419] P b3b3a2f0924e41c4960d47ff0e9ba866: Scheduling FlushDeltaMemStoresOp(4808b56090a14f6082ad57f7fcd183bf): perf score=3.181125
I20260812 06:17:35.832489 19626 maintenance_manager.cc:643] P b3b3a2f0924e41c4960d47ff0e9ba866: FlushDeltaMemStoresOp(4808b56090a14f6082ad57f7fcd183bf) complete. Timing: real 0.012s	user 0.009s	sys 0.000s Metrics: {"bytes_written":4512903,"delete_count":0,"lbm_write_time_us":4428,"lbm_writes_lt_1ms":113,"reinsert_count":0,"update_count":550}
I20260812 06:17:35.832873 19725 maintenance_manager.cc:419] P b3b3a2f0924e41c4960d47ff0e9ba866: Scheduling FlushDeltaMemStoresOp(4808b56090a14f6082ad57f7fcd183bf): perf score=2.188937
I20260812 06:17:35.842000 19626 maintenance_manager.cc:643] P b3b3a2f0924e41c4960d47ff0e9ba866: FlushDeltaMemStoresOp(4808b56090a14f6082ad57f7fcd183bf) complete. Timing: real 0.009s	user 0.008s	sys 0.000s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3563,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:17:35.842373 19725 maintenance_manager.cc:419] P b3b3a2f0924e41c4960d47ff0e9ba866: Scheduling MajorDeltaCompactionOp(4808b56090a14f6082ad57f7fcd183bf): perf score=1.000000
I20260812 06:17:36.100275 19626 maintenance_manager.cc:643] P b3b3a2f0924e41c4960d47ff0e9ba866: MajorDeltaCompactionOp(4808b56090a14f6082ad57f7fcd183bf) complete. Timing: real 0.258s	user 0.204s	sys 0.054s Metrics: {"cfile_cache_miss":834,"cfile_cache_miss_bytes":37123149,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":464,"lbm_read_time_us":19776,"lbm_reads_lt_1ms":874,"lbm_write_time_us":47562,"lbm_writes_lt_1ms":843,"mutex_wait_us":40,"peak_mem_usage":100395616,"reinsert_count":0,"spinlock_wait_cycles":14336,"thread_start_us":76,"threads_started":1,"update_count":4000}
I20260812 06:17:36.102730 19725 maintenance_manager.cc:419] P b3b3a2f0924e41c4960d47ff0e9ba866: Scheduling FlushDeltaMemStoresOp(4808b56090a14f6082ad57f7fcd183bf): perf score=18.063937
I20260812 06:17:36.162106 19626 maintenance_manager.cc:643] P b3b3a2f0924e41c4960d47ff0e9ba866: FlushDeltaMemStoresOp(4808b56090a14f6082ad57f7fcd183bf) complete. Timing: real 0.059s	user 0.033s	sys 0.023s Metrics: {"bytes_written":20512321,"delete_count":0,"lbm_write_time_us":26905,"lbm_writes_lt_1ms":503,"reinsert_count":0,"update_count":2500}
I20260812 06:17:36.162621 19725 maintenance_manager.cc:419] P b3b3a2f0924e41c4960d47ff0e9ba866: Scheduling FlushDeltaMemStoresOp(4808b56090a14f6082ad57f7fcd183bf): perf score=2.188937
I20260812 06:17:36.180271 19626 maintenance_manager.cc:643] P b3b3a2f0924e41c4960d47ff0e9ba866: FlushDeltaMemStoresOp(4808b56090a14f6082ad57f7fcd183bf) complete. Timing: real 0.017s	user 0.013s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5546,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:36.180825 19725 maintenance_manager.cc:419] P b3b3a2f0924e41c4960d47ff0e9ba866: Scheduling MajorDeltaCompactionOp(4808b56090a14f6082ad57f7fcd183bf): perf score=1.000000
I20260812 06:17:36.347713 19626 maintenance_manager.cc:643] P b3b3a2f0924e41c4960d47ff0e9ba866: MajorDeltaCompactionOp(4808b56090a14f6082ad57f7fcd183bf) complete. Timing: real 0.167s	user 0.132s	sys 0.034s Metrics: {"cfile_cache_miss":632,"cfile_cache_miss_bytes":28918103,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":202,"lbm_read_time_us":13112,"lbm_reads_lt_1ms":664,"lbm_write_time_us":33077,"lbm_writes_lt_1ms":643,"mutex_wait_us":30,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":768,"update_count":3000}
I20260812 06:17:36.348453 19725 maintenance_manager.cc:419] P b3b3a2f0924e41c4960d47ff0e9ba866: Scheduling FlushDeltaMemStoresOp(4808b56090a14f6082ad57f7fcd183bf): perf score=15.087375
I20260812 06:17:36.395480 19626 maintenance_manager.cc:643] P b3b3a2f0924e41c4960d47ff0e9ba866: FlushDeltaMemStoresOp(4808b56090a14f6082ad57f7fcd183bf) complete. Timing: real 0.047s	user 0.031s	sys 0.015s Metrics: {"bytes_written":16820142,"delete_count":0,"lbm_write_time_us":20715,"lbm_writes_lt_1ms":413,"reinsert_count":0,"update_count":2050}
I20260812 06:17:36.396138 19725 maintenance_manager.cc:419] P b3b3a2f0924e41c4960d47ff0e9ba866: Scheduling FlushDeltaMemStoresOp(4808b56090a14f6082ad57f7fcd183bf): perf score=2.188937
I20260812 06:17:36.415587 19626 maintenance_manager.cc:643] P b3b3a2f0924e41c4960d47ff0e9ba866: FlushDeltaMemStoresOp(4808b56090a14f6082ad57f7fcd183bf) complete. Timing: real 0.019s	user 0.012s	sys 0.004s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":6690,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:17:36.416582 19725 maintenance_manager.cc:419] P b3b3a2f0924e41c4960d47ff0e9ba866: Scheduling MajorDeltaCompactionOp(4808b56090a14f6082ad57f7fcd183bf): perf score=1.000000
I20260812 06:17:36.584667 19626 maintenance_manager.cc:643] P b3b3a2f0924e41c4960d47ff0e9ba866: MajorDeltaCompactionOp(4808b56090a14f6082ad57f7fcd183bf) complete. Timing: real 0.168s	user 0.092s	sys 0.071s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24815670,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":371,"lbm_read_time_us":13365,"lbm_reads_lt_1ms":564,"lbm_write_time_us":29919,"lbm_writes_lt_1ms":543,"mutex_wait_us":24,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":19200,"update_count":2500}
I20260812 06:17:36.585266 19725 maintenance_manager.cc:419] P b3b3a2f0924e41c4960d47ff0e9ba866: Scheduling FlushDeltaMemStoresOp(4808b56090a14f6082ad57f7fcd183bf): perf score=14.095187
I20260812 06:17:36.648586 19626 maintenance_manager.cc:643] P b3b3a2f0924e41c4960d47ff0e9ba866: FlushDeltaMemStoresOp(4808b56090a14f6082ad57f7fcd183bf) complete. Timing: real 0.063s	user 0.031s	sys 0.018s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":22176,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":402,"reinsert_count":0,"update_count":2000}
I20260812 06:17:36.649123 19725 maintenance_manager.cc:419] P b3b3a2f0924e41c4960d47ff0e9ba866: Scheduling FlushDeltaMemStoresOp(4808b56090a14f6082ad57f7fcd183bf): perf score=2.188937
I20260812 06:17:36.659688 19626 maintenance_manager.cc:643] P b3b3a2f0924e41c4960d47ff0e9ba866: FlushDeltaMemStoresOp(4808b56090a14f6082ad57f7fcd183bf) complete. Timing: real 0.010s	user 0.009s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3875,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:36.660539 19725 maintenance_manager.cc:419] P b3b3a2f0924e41c4960d47ff0e9ba866: Scheduling MajorDeltaCompactionOp(4808b56090a14f6082ad57f7fcd183bf): perf score=1.000000
I20260812 06:17:36.830924 19626 maintenance_manager.cc:643] P b3b3a2f0924e41c4960d47ff0e9ba866: MajorDeltaCompactionOp(4808b56090a14f6082ad57f7fcd183bf) complete. Timing: real 0.170s	user 0.111s	sys 0.055s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24815683,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":220,"lbm_read_time_us":12443,"lbm_reads_lt_1ms":572,"lbm_write_time_us":29500,"lbm_writes_lt_1ms":543,"mutex_wait_us":79,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":8064,"update_count":2500}
I20260812 06:17:36.831627 19725 maintenance_manager.cc:419] P b3b3a2f0924e41c4960d47ff0e9ba866: Scheduling FlushDeltaMemStoresOp(4808b56090a14f6082ad57f7fcd183bf): perf score=14.095187
I20260812 06:17:36.887794 19626 maintenance_manager.cc:643] P b3b3a2f0924e41c4960d47ff0e9ba866: FlushDeltaMemStoresOp(4808b56090a14f6082ad57f7fcd183bf) complete. Timing: real 0.056s	user 0.028s	sys 0.015s Metrics: {"bytes_written":16409903,"delete_count":0,"lbm_write_time_us":17531,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:17:36.888343 19725 maintenance_manager.cc:419] P b3b3a2f0924e41c4960d47ff0e9ba866: Scheduling FlushDeltaMemStoresOp(4808b56090a14f6082ad57f7fcd183bf): perf score=2.188937
I20260812 06:17:36.905212 19626 maintenance_manager.cc:643] P b3b3a2f0924e41c4960d47ff0e9ba866: FlushDeltaMemStoresOp(4808b56090a14f6082ad57f7fcd183bf) complete. Timing: real 0.017s	user 0.011s	sys 0.003s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6567,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:36.905732 19725 maintenance_manager.cc:419] P b3b3a2f0924e41c4960d47ff0e9ba866: Scheduling MajorDeltaCompactionOp(4808b56090a14f6082ad57f7fcd183bf): perf score=1.000000
I20260812 06:17:37.070561 19626 maintenance_manager.cc:643] P b3b3a2f0924e41c4960d47ff0e9ba866: MajorDeltaCompactionOp(4808b56090a14f6082ad57f7fcd183bf) complete. Timing: real 0.165s	user 0.100s	sys 0.064s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24815685,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":301,"lbm_read_time_us":10656,"lbm_reads_lt_1ms":572,"lbm_write_time_us":29923,"lbm_writes_lt_1ms":543,"mutex_wait_us":46,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":768,"update_count":2500}
I20260812 06:17:37.071331 19725 maintenance_manager.cc:419] P b3b3a2f0924e41c4960d47ff0e9ba866: Scheduling FlushDeltaMemStoresOp(4808b56090a14f6082ad57f7fcd183bf): perf score=14.095187
I20260812 06:17:37.127041 19626 maintenance_manager.cc:643] P b3b3a2f0924e41c4960d47ff0e9ba866: FlushDeltaMemStoresOp(4808b56090a14f6082ad57f7fcd183bf) complete. Timing: real 0.055s	user 0.031s	sys 0.022s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":18970,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:17:37.127535 19725 maintenance_manager.cc:419] P b3b3a2f0924e41c4960d47ff0e9ba866: Scheduling FlushDeltaMemStoresOp(4808b56090a14f6082ad57f7fcd183bf): perf score=2.188937
I20260812 06:17:37.137499 19626 maintenance_manager.cc:643] P b3b3a2f0924e41c4960d47ff0e9ba866: FlushDeltaMemStoresOp(4808b56090a14f6082ad57f7fcd183bf) complete. Timing: real 0.010s	user 0.008s	sys 0.000s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4052,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:37.137936 19725 maintenance_manager.cc:419] P b3b3a2f0924e41c4960d47ff0e9ba866: Scheduling FlushMRSOp(4808b56090a14f6082ad57f7fcd183bf): perf score=1.000000
I20260812 06:17:37.180199 19626 maintenance_manager.cc:643] P b3b3a2f0924e41c4960d47ff0e9ba866: FlushMRSOp(4808b56090a14f6082ad57f7fcd183bf) complete. Timing: real 0.042s	user 0.033s	sys 0.000s Metrics: {"bytes_written":1152512,"cfile_init":1,"dirs.queue_time_us":56,"dirs.run_cpu_time_us":220,"dirs.run_wall_time_us":1215,"drs_written":1,"lbm_read_time_us":43,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1319,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":28}
I20260812 06:17:37.180882 19725 maintenance_manager.cc:419] P b3b3a2f0924e41c4960d47ff0e9ba866: Scheduling LogGCOp(4808b56090a14f6082ad57f7fcd183bf): free 112692610 bytes of WAL
I20260812 06:17:37.181121 19626 log_reader.cc:385] T 4808b56090a14f6082ad57f7fcd183bf: removed 11 log segments from log reader
I20260812 06:17:37.181167 19626 log.cc:1079] T 4808b56090a14f6082ad57f7fcd183bf P b3b3a2f0924e41c4960d47ff0e9ba866: Deleting log segment in path: /tmp/dist-test-task7hz9Df/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515446107064-19121-0/minicluster-data/ts-0-root/wals/4808b56090a14f6082ad57f7fcd183bf/wal-000000028 (ops 133-137)
I20260812 06:17:37.181195 19626 log.cc:1079] T 4808b56090a14f6082ad57f7fcd183bf P b3b3a2f0924e41c4960d47ff0e9ba866: Deleting log segment in path: /tmp/dist-test-task7hz9Df/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515446107064-19121-0/minicluster-data/ts-0-root/wals/4808b56090a14f6082ad57f7fcd183bf/wal-000000029 (ops 138-142)
I20260812 06:17:37.181241 19626 log.cc:1079] T 4808b56090a14f6082ad57f7fcd183bf P b3b3a2f0924e41c4960d47ff0e9ba866: Deleting log segment in path: /tmp/dist-test-task7hz9Df/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515446107064-19121-0/minicluster-data/ts-0-root/wals/4808b56090a14f6082ad57f7fcd183bf/wal-000000030 (ops 143-147)
I20260812 06:17:37.181285 19626 log.cc:1079] T 4808b56090a14f6082ad57f7fcd183bf P b3b3a2f0924e41c4960d47ff0e9ba866: Deleting log segment in path: /tmp/dist-test-task7hz9Df/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515446107064-19121-0/minicluster-data/ts-0-root/wals/4808b56090a14f6082ad57f7fcd183bf/wal-000000031 (ops 148-152)
I20260812 06:17:37.181336 19626 log.cc:1079] T 4808b56090a14f6082ad57f7fcd183bf P b3b3a2f0924e41c4960d47ff0e9ba866: Deleting log segment in path: /tmp/dist-test-task7hz9Df/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515446107064-19121-0/minicluster-data/ts-0-root/wals/4808b56090a14f6082ad57f7fcd183bf/wal-000000032 (ops 153-157)
I20260812 06:17:37.181380 19626 log.cc:1079] T 4808b56090a14f6082ad57f7fcd183bf P b3b3a2f0924e41c4960d47ff0e9ba866: Deleting log segment in path: /tmp/dist-test-task7hz9Df/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515446107064-19121-0/minicluster-data/ts-0-root/wals/4808b56090a14f6082ad57f7fcd183bf/wal-000000033 (ops 158-162)
I20260812 06:17:37.181432 19626 log.cc:1079] T 4808b56090a14f6082ad57f7fcd183bf P b3b3a2f0924e41c4960d47ff0e9ba866: Deleting log segment in path: /tmp/dist-test-task7hz9Df/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515446107064-19121-0/minicluster-data/ts-0-root/wals/4808b56090a14f6082ad57f7fcd183bf/wal-000000034 (ops 163-167)
I20260812 06:17:37.181473 19626 log.cc:1079] T 4808b56090a14f6082ad57f7fcd183bf P b3b3a2f0924e41c4960d47ff0e9ba866: Deleting log segment in path: /tmp/dist-test-task7hz9Df/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515446107064-19121-0/minicluster-data/ts-0-root/wals/4808b56090a14f6082ad57f7fcd183bf/wal-000000035 (ops 168-172)
I20260812 06:17:37.181514 19626 log.cc:1079] T 4808b56090a14f6082ad57f7fcd183bf P b3b3a2f0924e41c4960d47ff0e9ba866: Deleting log segment in path: /tmp/dist-test-task7hz9Df/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515446107064-19121-0/minicluster-data/ts-0-root/wals/4808b56090a14f6082ad57f7fcd183bf/wal-000000036 (ops 173-177)
I20260812 06:17:37.181555 19626 log.cc:1079] T 4808b56090a14f6082ad57f7fcd183bf P b3b3a2f0924e41c4960d47ff0e9ba866: Deleting log segment in path: /tmp/dist-test-task7hz9Df/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515446107064-19121-0/minicluster-data/ts-0-root/wals/4808b56090a14f6082ad57f7fcd183bf/wal-000000037 (ops 178-182)
I20260812 06:17:37.181593 19626 log.cc:1079] T 4808b56090a14f6082ad57f7fcd183bf P b3b3a2f0924e41c4960d47ff0e9ba866: Deleting log segment in path: /tmp/dist-test-task7hz9Df/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515446107064-19121-0/minicluster-data/ts-0-root/wals/4808b56090a14f6082ad57f7fcd183bf/wal-000000038 (ops 183-187)
I20260812 06:17:37.206051 19626 maintenance_manager.cc:643] P b3b3a2f0924e41c4960d47ff0e9ba866: LogGCOp(4808b56090a14f6082ad57f7fcd183bf) complete. Timing: real 0.025s	user 0.000s	sys 0.022s Metrics: {}
I20260812 06:17:37.206534 19725 maintenance_manager.cc:419] P b3b3a2f0924e41c4960d47ff0e9ba866: Scheduling FlushDeltaMemStoresOp(4808b56090a14f6082ad57f7fcd183bf): perf score=2.188937
I20260812 06:17:37.226856 19626 maintenance_manager.cc:643] P b3b3a2f0924e41c4960d47ff0e9ba866: FlushDeltaMemStoresOp(4808b56090a14f6082ad57f7fcd183bf) complete. Timing: real 0.020s	user 0.013s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5173,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:37.227330 19725 maintenance_manager.cc:419] P b3b3a2f0924e41c4960d47ff0e9ba866: Scheduling FlushDeltaMemStoresOp(4808b56090a14f6082ad57f7fcd183bf): perf score=2.188937
I20260812 06:17:37.241528 19626 maintenance_manager.cc:643] P b3b3a2f0924e41c4960d47ff0e9ba866: FlushDeltaMemStoresOp(4808b56090a14f6082ad57f7fcd183bf) complete. Timing: real 0.014s	user 0.009s	sys 0.003s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":5673,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:37.241998 19725 maintenance_manager.cc:419] P b3b3a2f0924e41c4960d47ff0e9ba866: Scheduling MajorDeltaCompactionOp(4808b56090a14f6082ad57f7fcd183bf): perf score=1.000000
I20260812 06:17:37.434855 19121 heavy-update-compaction-itest.cc:229] Time spent updating: real 4.854s	user 1.787s	sys 0.174s
I20260812 06:17:37.473110 19626 maintenance_manager.cc:643] P b3b3a2f0924e41c4960d47ff0e9ba866: MajorDeltaCompactionOp(4808b56090a14f6082ad57f7fcd183bf) complete. Timing: real 0.231s	user 0.183s	sys 0.046s Metrics: {"cfile_cache_miss":734,"cfile_cache_miss_bytes":33020743,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"lbm_read_time_us":16560,"lbm_reads_lt_1ms":770,"lbm_write_time_us":41414,"lbm_writes_lt_1ms":743,"peak_mem_usage":87969044,"reinsert_count":0,"spinlock_wait_cycles":8704,"update_count":3500}
I20260812 06:17:37.473654 19725 maintenance_manager.cc:419] P b3b3a2f0924e41c4960d47ff0e9ba866: Scheduling FlushDeltaMemStoresOp(4808b56090a14f6082ad57f7fcd183bf): perf score=14.095187
I20260812 06:17:37.505205 19626 maintenance_manager.cc:643] P b3b3a2f0924e41c4960d47ff0e9ba866: FlushDeltaMemStoresOp(4808b56090a14f6082ad57f7fcd183bf) complete. Timing: real 0.031s	user 0.015s	sys 0.015s Metrics: {"bytes_written":16409900,"delete_count":0,"lbm_write_time_us":15416,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:17:37.505743 19725 maintenance_manager.cc:419] P b3b3a2f0924e41c4960d47ff0e9ba866: Scheduling MajorDeltaCompactionOp(4808b56090a14f6082ad57f7fcd183bf): perf score=1.000000
I20260812 06:17:37.538398 19121 heavy-update-compaction-itest.cc:265] Time spent scanning: real 0.103s	user 0.001s	sys 0.000s
I20260812 06:17:37.539098 19121 tablet_server.cc:179] TabletServer@127.18.172.65:0 shutting down...
I20260812 06:17:37.630793 19626 maintenance_manager.cc:643] P b3b3a2f0924e41c4960d47ff0e9ba866: MajorDeltaCompactionOp(4808b56090a14f6082ad57f7fcd183bf) complete. Timing: real 0.125s	user 0.080s	sys 0.044s Metrics: {"cfile_cache_miss":431,"cfile_cache_miss_bytes":20713151,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":1,"delta_iterators_relevant":1,"dirs.queue_time_us":413,"lbm_read_time_us":9864,"lbm_reads_lt_1ms":467,"lbm_write_time_us":22472,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":442,"mutex_wait_us":60,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":65152,"update_count":2000}
I20260812 06:17:37.631569 19121 ts_tablet_manager.cc:1507] Shutting down tablet manager...
I20260812 06:17:37.631882 19121 tablet_replica.cc:333] T 4808b56090a14f6082ad57f7fcd183bf P b3b3a2f0924e41c4960d47ff0e9ba866: stopping tablet replica
I20260812 06:17:37.632040 19121 raft_consensus.cc:2243] T 4808b56090a14f6082ad57f7fcd183bf P b3b3a2f0924e41c4960d47ff0e9ba866 [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:17:37.632222 19121 raft_consensus.cc:2272] T 4808b56090a14f6082ad57f7fcd183bf P b3b3a2f0924e41c4960d47ff0e9ba866 [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:17:37.635589 19121 tablet_server.cc:196] TabletServer@127.18.172.65:0 shutdown complete.
I20260812 06:17:37.672812 19121 master.cc:562] Master@127.18.172.126:41751 shutting down...
I20260812 06:17:37.676280 19121 raft_consensus.cc:2243] T 00000000000000000000000000000000 P f66ed132d9314fdabf92b5e694a5e6f9 [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:17:37.676479 19121 raft_consensus.cc:2272] T 00000000000000000000000000000000 P f66ed132d9314fdabf92b5e694a5e6f9 [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:17:37.676574 19121 tablet_replica.cc:333] T 00000000000000000000000000000000 P f66ed132d9314fdabf92b5e694a5e6f9: stopping tablet replica
I20260812 06:17:37.688799 19121 master.cc:584] Master@127.18.172.126:41751 shutdown complete.
[       OK ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/1 (5439 ms)
[----------] 2 tests from EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy (11663 ms total)

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