[==========] 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:33.494693  6254 internal_mini_cluster.cc:156] Creating distributed mini masters. Addrs: 127.6.27.190:39693
I20260812 06:17:33.495739  6254 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:33.496351  6254 file_cache.cc:504] Constructed file cache file cache with capacity 419430
I20260812 06:17:33.502717  6254 server_base.cc:1061] running on GCE node
W20260812 06:17:33.502758  6259 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:33.503011  6260 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:33.503166  6262 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:33.503750  6254 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:17:33.503849  6254 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:33.503881  6254 hybrid_clock.cc:648] HybridClock initialized: now 1786515453503880 us; error 0 us; skew 500 ppm
I20260812 06:17:33.505641  6254 webserver.cc:533] Webserver started at http://127.6.27.190:41523/ using document root <none> and password file <none>
I20260812 06:17:33.506142  6254 fs_manager.cc:362] Metadata directory not provided
I20260812 06:17:33.506202  6254 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:17:33.506390  6254 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:17:33.508083  6254 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskeFMdIZ/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515453483730-6254-0/minicluster-data/master-0-root/instance:
uuid: "1a91d1ff3d5747539b524cfb747b88d3"
format_stamp: "Formatted at 2026-08-12 06:17:33 on dist-test-slave-bxbt"
I20260812 06:17:33.511467  6254 fs_manager.cc:696] Time spent creating directory manager: real 0.003s	user 0.003s	sys 0.000s
I20260812 06:17:33.513624  6267 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:33.514611  6254 fs_manager.cc:730] Time spent opening block manager: real 0.002s	user 0.000s	sys 0.002s
I20260812 06:17:33.514707  6254 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskeFMdIZ/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515453483730-6254-0/minicluster-data/master-0-root
uuid: "1a91d1ff3d5747539b524cfb747b88d3"
format_stamp: "Formatted at 2026-08-12 06:17:33 on dist-test-slave-bxbt"
I20260812 06:17:33.514830  6254 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskeFMdIZ/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515453483730-6254-0/minicluster-data/master-0-root
metadata directory: /tmp/dist-test-taskeFMdIZ/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515453483730-6254-0/minicluster-data/master-0-root
1 data directories: /tmp/dist-test-taskeFMdIZ/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515453483730-6254-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:33.526346  6254 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:17:33.526930  6254 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:33.527108  6254 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:17:33.534353  6254 rpc_server.cc:307] RPC server started. Bound to: 127.6.27.190:39693
I20260812 06:17:33.534382  6319 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.6.27.190:39693 every 8 connection(s)
I20260812 06:17:33.536521  6320 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:33.541744  6320 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P 1a91d1ff3d5747539b524cfb747b88d3: Bootstrap starting.
I20260812 06:17:33.544034  6320 tablet_bootstrap.cc:654] T 00000000000000000000000000000000 P 1a91d1ff3d5747539b524cfb747b88d3: Neither blocks nor log segments found. Creating new log.
I20260812 06:17:33.544924  6320 log.cc:826] T 00000000000000000000000000000000 P 1a91d1ff3d5747539b524cfb747b88d3: Log is configured to *not* fsync() on all Append() calls
I20260812 06:17:33.546566  6320 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P 1a91d1ff3d5747539b524cfb747b88d3: No bootstrap required, opened a new log
I20260812 06:17:33.549324  6320 raft_consensus.cc:359] T 00000000000000000000000000000000 P 1a91d1ff3d5747539b524cfb747b88d3 [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "1a91d1ff3d5747539b524cfb747b88d3" member_type: VOTER }
I20260812 06:17:33.549480  6320 raft_consensus.cc:385] T 00000000000000000000000000000000 P 1a91d1ff3d5747539b524cfb747b88d3 [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:17:33.549576  6320 raft_consensus.cc:740] T 00000000000000000000000000000000 P 1a91d1ff3d5747539b524cfb747b88d3 [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: 1a91d1ff3d5747539b524cfb747b88d3, State: Initialized, Role: FOLLOWER
I20260812 06:17:33.550218  6320 consensus_queue.cc:260] T 00000000000000000000000000000000 P 1a91d1ff3d5747539b524cfb747b88d3 [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: "1a91d1ff3d5747539b524cfb747b88d3" member_type: VOTER }
I20260812 06:17:33.550395  6320 raft_consensus.cc:399] T 00000000000000000000000000000000 P 1a91d1ff3d5747539b524cfb747b88d3 [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:17:33.550473  6320 raft_consensus.cc:493] T 00000000000000000000000000000000 P 1a91d1ff3d5747539b524cfb747b88d3 [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:17:33.550642  6320 raft_consensus.cc:3060] T 00000000000000000000000000000000 P 1a91d1ff3d5747539b524cfb747b88d3 [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:17:33.551422  6320 raft_consensus.cc:515] T 00000000000000000000000000000000 P 1a91d1ff3d5747539b524cfb747b88d3 [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "1a91d1ff3d5747539b524cfb747b88d3" member_type: VOTER }
I20260812 06:17:33.551893  6320 leader_election.cc:304] T 00000000000000000000000000000000 P 1a91d1ff3d5747539b524cfb747b88d3 [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: 1a91d1ff3d5747539b524cfb747b88d3; no voters: 
I20260812 06:17:33.552240  6320 leader_election.cc:290] T 00000000000000000000000000000000 P 1a91d1ff3d5747539b524cfb747b88d3 [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:17:33.552392  6323 raft_consensus.cc:2804] T 00000000000000000000000000000000 P 1a91d1ff3d5747539b524cfb747b88d3 [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:17:33.552668  6323 raft_consensus.cc:697] T 00000000000000000000000000000000 P 1a91d1ff3d5747539b524cfb747b88d3 [term 1 LEADER]: Becoming Leader. State: Replica: 1a91d1ff3d5747539b524cfb747b88d3, State: Running, Role: LEADER
I20260812 06:17:33.553056  6323 consensus_queue.cc:237] T 00000000000000000000000000000000 P 1a91d1ff3d5747539b524cfb747b88d3 [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: "1a91d1ff3d5747539b524cfb747b88d3" member_type: VOTER }
I20260812 06:17:33.553210  6320 sys_catalog.cc:565] T 00000000000000000000000000000000 P 1a91d1ff3d5747539b524cfb747b88d3 [sys.catalog]: configured and running, proceeding with master startup.
I20260812 06:17:33.555006  6324 sys_catalog.cc:455] T 00000000000000000000000000000000 P 1a91d1ff3d5747539b524cfb747b88d3 [sys.catalog]: SysCatalogTable state changed. Reason: RaftConsensus started. Latest consensus state: current_term: 1 leader_uuid: "1a91d1ff3d5747539b524cfb747b88d3" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "1a91d1ff3d5747539b524cfb747b88d3" member_type: VOTER } }
I20260812 06:17:33.555002  6325 sys_catalog.cc:455] T 00000000000000000000000000000000 P 1a91d1ff3d5747539b524cfb747b88d3 [sys.catalog]: SysCatalogTable state changed. Reason: New leader 1a91d1ff3d5747539b524cfb747b88d3. Latest consensus state: current_term: 1 leader_uuid: "1a91d1ff3d5747539b524cfb747b88d3" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "1a91d1ff3d5747539b524cfb747b88d3" member_type: VOTER } }
I20260812 06:17:33.555156  6324 sys_catalog.cc:458] T 00000000000000000000000000000000 P 1a91d1ff3d5747539b524cfb747b88d3 [sys.catalog]: This master's current role is: LEADER
I20260812 06:17:33.555156  6325 sys_catalog.cc:458] T 00000000000000000000000000000000 P 1a91d1ff3d5747539b524cfb747b88d3 [sys.catalog]: This master's current role is: LEADER
I20260812 06:17:33.555473  6254 internal_mini_cluster.cc:184] Waiting to initialize catalog manager on master 0
W20260812 06:17:33.557466  6338 catalog_manager.cc:1594] T 00000000000000000000000000000000 P 1a91d1ff3d5747539b524cfb747b88d3: loading cluster ID for follower catalog manager: Not found: cluster ID entry not found
W20260812 06:17:33.557531  6338 catalog_manager.cc:883] Not found: cluster ID entry not found: failed to prepare follower catalog manager, will retry
I20260812 06:17:33.557611  6337 catalog_manager.cc:1511] Loading table and tablet metadata into memory...
I20260812 06:17:33.558341  6337 catalog_manager.cc:1520] Initializing Kudu cluster ID...
I20260812 06:17:33.562884  6337 catalog_manager.cc:1383] Generated new cluster ID: 7e219ad3634d4f68bcfca78b937037b0
I20260812 06:17:33.562949  6337 catalog_manager.cc:1531] Initializing Kudu internal certificate authority...
I20260812 06:17:33.595163  6337 catalog_manager.cc:1406] Generated new certificate authority record
I20260812 06:17:33.596408  6337 catalog_manager.cc:1540] Loading token signing keys...
I20260812 06:17:33.608279  6337 catalog_manager.cc:6092] T 00000000000000000000000000000000 P 1a91d1ff3d5747539b524cfb747b88d3: Generated new TSK 0
I20260812 06:17:33.608903  6337 catalog_manager.cc:1550] Initializing in-progress tserver states...
I20260812 06:17:33.620326  6254 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:17:33.623090  6345 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:33.623128  6343 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:33.623159  6342 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:33.623306  6254 server_base.cc:1061] running on GCE node
I20260812 06:17:33.623629  6254 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:17:33.623714  6254 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:33.623752  6254 hybrid_clock.cc:648] HybridClock initialized: now 1786515453623751 us; error 0 us; skew 500 ppm
I20260812 06:17:33.624675  6254 webserver.cc:533] Webserver started at http://127.6.27.129:33883/ using document root <none> and password file <none>
I20260812 06:17:33.624855  6254 fs_manager.cc:362] Metadata directory not provided
I20260812 06:17:33.624909  6254 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:17:33.625032  6254 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:17:33.625433  6254 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskeFMdIZ/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515453483730-6254-0/minicluster-data/ts-0-root/instance:
uuid: "428cb329833f4e918859ecfb4fff3d27"
format_stamp: "Formatted at 2026-08-12 06:17:33 on dist-test-slave-bxbt"
I20260812 06:17:33.626920  6254 fs_manager.cc:696] Time spent creating directory manager: real 0.001s	user 0.000s	sys 0.002s
I20260812 06:17:33.627939  6350 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:33.628198  6254 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.001s	sys 0.000s
I20260812 06:17:33.628273  6254 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskeFMdIZ/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515453483730-6254-0/minicluster-data/ts-0-root
uuid: "428cb329833f4e918859ecfb4fff3d27"
format_stamp: "Formatted at 2026-08-12 06:17:33 on dist-test-slave-bxbt"
I20260812 06:17:33.628360  6254 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskeFMdIZ/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515453483730-6254-0/minicluster-data/ts-0-root
metadata directory: /tmp/dist-test-taskeFMdIZ/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515453483730-6254-0/minicluster-data/ts-0-root
1 data directories: /tmp/dist-test-taskeFMdIZ/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515453483730-6254-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:33.639351  6254 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:17:33.639822  6254 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:17:33.640331  6254 txn_system_client.cc:432] TxnSystemClient initialization is disabled...
I20260812 06:17:33.641124  6254 ts_tablet_manager.cc:585] Loaded tablet metadata (0 total tablets, 0 live tablets)
I20260812 06:17:33.641175  6254 ts_tablet_manager.cc:531] Time spent load tablet metadata: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:17:33.641252  6254 ts_tablet_manager.cc:616] Registered 0 tablets
I20260812 06:17:33.641286  6254 ts_tablet_manager.cc:595] Time spent register tablets: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:17:33.648046  6254 rpc_server.cc:307] RPC server started. Bound to: 127.6.27.129:39827
I20260812 06:17:33.648082  6413 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.6.27.129:39827 every 8 connection(s)
I20260812 06:17:33.657716  6414 heartbeater.cc:344] Connected to a master server at 127.6.27.190:39693
I20260812 06:17:33.657954  6414 heartbeater.cc:461] Registering TS with master...
I20260812 06:17:33.658370  6414 heartbeater.cc:507] Master 127.6.27.190:39693 requested a full tablet report, sending...
I20260812 06:17:33.659770  6284 ts_manager.cc:194] Registered new tserver with Master: 428cb329833f4e918859ecfb4fff3d27 (127.6.27.129:39827)
I20260812 06:17:33.659881  6254 internal_mini_cluster.cc:371] 1 TS(s) registered with all masters after 0.011178145s
I20260812 06:17:33.661223  6284 master_service.cc:502] Signed X509 certificate for tserver {username='slave'} at 127.0.0.1:39832
I20260812 06:17:33.668872  6284 catalog_manager.cc:2283] Servicing CreateTable request from {username='slave'} at 127.0.0.1:39842:
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:33.682562  6378 tablet_service.cc:1511] Processing CreateTablet for tablet f80e4931ac62410f81aef8e5fd6fa713 (DEFAULT_TABLE table=heavy-update-compaction-test [id=820666a78561478bb80b3f37a5c2869e]), partition=
I20260812 06:17:33.682996  6378 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet f80e4931ac62410f81aef8e5fd6fa713. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:17:33.685145  6426 tablet_bootstrap.cc:492] T f80e4931ac62410f81aef8e5fd6fa713 P 428cb329833f4e918859ecfb4fff3d27: Bootstrap starting.
I20260812 06:17:33.686196  6426 tablet_bootstrap.cc:654] T f80e4931ac62410f81aef8e5fd6fa713 P 428cb329833f4e918859ecfb4fff3d27: Neither blocks nor log segments found. Creating new log.
I20260812 06:17:33.687283  6426 tablet_bootstrap.cc:492] T f80e4931ac62410f81aef8e5fd6fa713 P 428cb329833f4e918859ecfb4fff3d27: No bootstrap required, opened a new log
I20260812 06:17:33.687374  6426 ts_tablet_manager.cc:1403] T f80e4931ac62410f81aef8e5fd6fa713 P 428cb329833f4e918859ecfb4fff3d27: Time spent bootstrapping tablet: real 0.002s	user 0.002s	sys 0.000s
I20260812 06:17:33.687865  6426 raft_consensus.cc:359] T f80e4931ac62410f81aef8e5fd6fa713 P 428cb329833f4e918859ecfb4fff3d27 [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "428cb329833f4e918859ecfb4fff3d27" member_type: VOTER last_known_addr { host: "127.6.27.129" port: 39827 } }
I20260812 06:17:33.687960  6426 raft_consensus.cc:385] T f80e4931ac62410f81aef8e5fd6fa713 P 428cb329833f4e918859ecfb4fff3d27 [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:17:33.687983  6426 raft_consensus.cc:740] T f80e4931ac62410f81aef8e5fd6fa713 P 428cb329833f4e918859ecfb4fff3d27 [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: 428cb329833f4e918859ecfb4fff3d27, State: Initialized, Role: FOLLOWER
I20260812 06:17:33.688148  6426 consensus_queue.cc:260] T f80e4931ac62410f81aef8e5fd6fa713 P 428cb329833f4e918859ecfb4fff3d27 [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: "428cb329833f4e918859ecfb4fff3d27" member_type: VOTER last_known_addr { host: "127.6.27.129" port: 39827 } }
I20260812 06:17:33.688231  6426 raft_consensus.cc:399] T f80e4931ac62410f81aef8e5fd6fa713 P 428cb329833f4e918859ecfb4fff3d27 [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:17:33.688278  6426 raft_consensus.cc:493] T f80e4931ac62410f81aef8e5fd6fa713 P 428cb329833f4e918859ecfb4fff3d27 [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:17:33.688341  6426 raft_consensus.cc:3060] T f80e4931ac62410f81aef8e5fd6fa713 P 428cb329833f4e918859ecfb4fff3d27 [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:17:33.689281  6426 raft_consensus.cc:515] T f80e4931ac62410f81aef8e5fd6fa713 P 428cb329833f4e918859ecfb4fff3d27 [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "428cb329833f4e918859ecfb4fff3d27" member_type: VOTER last_known_addr { host: "127.6.27.129" port: 39827 } }
I20260812 06:17:33.689404  6426 leader_election.cc:304] T f80e4931ac62410f81aef8e5fd6fa713 P 428cb329833f4e918859ecfb4fff3d27 [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: 428cb329833f4e918859ecfb4fff3d27; no voters: 
I20260812 06:17:33.689630  6426 leader_election.cc:290] T f80e4931ac62410f81aef8e5fd6fa713 P 428cb329833f4e918859ecfb4fff3d27 [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:17:33.689802  6428 raft_consensus.cc:2804] T f80e4931ac62410f81aef8e5fd6fa713 P 428cb329833f4e918859ecfb4fff3d27 [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:17:33.690045  6426 ts_tablet_manager.cc:1434] T f80e4931ac62410f81aef8e5fd6fa713 P 428cb329833f4e918859ecfb4fff3d27: Time spent starting tablet: real 0.003s	user 0.003s	sys 0.000s
I20260812 06:17:33.690230  6414 heartbeater.cc:499] Master 127.6.27.190:39693 was elected leader, sending a full tablet report...
I20260812 06:17:33.690079  6428 raft_consensus.cc:697] T f80e4931ac62410f81aef8e5fd6fa713 P 428cb329833f4e918859ecfb4fff3d27 [term 1 LEADER]: Becoming Leader. State: Replica: 428cb329833f4e918859ecfb4fff3d27, State: Running, Role: LEADER
I20260812 06:17:33.690639  6428 consensus_queue.cc:237] T f80e4931ac62410f81aef8e5fd6fa713 P 428cb329833f4e918859ecfb4fff3d27 [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: "428cb329833f4e918859ecfb4fff3d27" member_type: VOTER last_known_addr { host: "127.6.27.129" port: 39827 } }
I20260812 06:17:33.693414  6284 catalog_manager.cc:5719] T f80e4931ac62410f81aef8e5fd6fa713 P 428cb329833f4e918859ecfb4fff3d27 reported cstate change: term changed from 0 to 1, leader changed from <none> to 428cb329833f4e918859ecfb4fff3d27 (127.6.27.129). New cstate: current_term: 1 leader_uuid: "428cb329833f4e918859ecfb4fff3d27" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "428cb329833f4e918859ecfb4fff3d27" member_type: VOTER last_known_addr { host: "127.6.27.129" port: 39827 } health_report { overall_health: HEALTHY } } }
I20260812 06:17:33.753844  6254 heavy-update-compaction-itest.cc:215] Time spent inserting: real 0.054s	user 0.016s	sys 0.009s
I20260812 06:17:33.899189  6415 maintenance_manager.cc:419] P 428cb329833f4e918859ecfb4fff3d27: Scheduling FlushMRSOp(f80e4931ac62410f81aef8e5fd6fa713): perf score=19.054940
I20260812 06:17:34.095261  6355 maintenance_manager.cc:643] P 428cb329833f4e918859ecfb4fff3d27: FlushMRSOp(f80e4931ac62410f81aef8e5fd6fa713) complete. Timing: real 0.196s	user 0.147s	sys 0.043s Metrics: {"bytes_written":16409897,"cfile_init":1,"compiler_manager_pool.queue_time_us":218,"delete_count":0,"dirs.queue_time_us":64,"dirs.run_cpu_time_us":213,"dirs.run_wall_time_us":783,"drs_written":1,"lbm_read_time_us":69,"lbm_reads_lt_1ms":4,"lbm_write_time_us":49610,"lbm_writes_lt_1ms":857,"peak_mem_usage":0,"reinsert_count":0,"rows_written":104,"thread_start_us":154,"threads_started":1,"update_count":2000}
I20260812 06:17:34.096320  6415 maintenance_manager.cc:419] P 428cb329833f4e918859ecfb4fff3d27: Scheduling LogGCOp(f80e4931ac62410f81aef8e5fd6fa713): free 20743831 bytes of WAL
I20260812 06:17:34.096627  6355 log_reader.cc:385] T f80e4931ac62410f81aef8e5fd6fa713: removed 2 log segments from log reader
I20260812 06:17:34.096710  6355 log.cc:1079] T f80e4931ac62410f81aef8e5fd6fa713 P 428cb329833f4e918859ecfb4fff3d27: Deleting log segment in path: /tmp/dist-test-taskeFMdIZ/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515453483730-6254-0/minicluster-data/ts-0-root/wals/f80e4931ac62410f81aef8e5fd6fa713/wal-000000001 (ops 1-6)
I20260812 06:17:34.096783  6355 log.cc:1079] T f80e4931ac62410f81aef8e5fd6fa713 P 428cb329833f4e918859ecfb4fff3d27: Deleting log segment in path: /tmp/dist-test-taskeFMdIZ/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515453483730-6254-0/minicluster-data/ts-0-root/wals/f80e4931ac62410f81aef8e5fd6fa713/wal-000000002 (ops 7-11)
I20260812 06:17:34.101536  6355 maintenance_manager.cc:643] P 428cb329833f4e918859ecfb4fff3d27: LogGCOp(f80e4931ac62410f81aef8e5fd6fa713) complete. Timing: real 0.005s	user 0.000s	sys 0.003s Metrics: {}
I20260812 06:17:34.101971  6415 maintenance_manager.cc:419] P 428cb329833f4e918859ecfb4fff3d27: Scheduling FlushDeltaMemStoresOp(f80e4931ac62410f81aef8e5fd6fa713): perf score=2.188937
I20260812 06:17:34.127737  6355 maintenance_manager.cc:643] P 428cb329833f4e918859ecfb4fff3d27: FlushDeltaMemStoresOp(f80e4931ac62410f81aef8e5fd6fa713) complete. Timing: real 0.026s	user 0.009s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5624,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:34.128189  6415 maintenance_manager.cc:419] P 428cb329833f4e918859ecfb4fff3d27: Scheduling UndoDeltaBlockGCOp(f80e4931ac62410f81aef8e5fd6fa713): 16411394 bytes on disk
I20260812 06:17:34.128682  6355 maintenance_manager.cc:643] P 428cb329833f4e918859ecfb4fff3d27: UndoDeltaBlockGCOp(f80e4931ac62410f81aef8e5fd6fa713) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":45,"lbm_reads_lt_1ms":4}
I20260812 06:17:34.129148  6415 maintenance_manager.cc:419] P 428cb329833f4e918859ecfb4fff3d27: Scheduling FlushDeltaMemStoresOp(f80e4931ac62410f81aef8e5fd6fa713): perf score=2.188937
I20260812 06:17:34.139093  6355 maintenance_manager.cc:643] P 428cb329833f4e918859ecfb4fff3d27: FlushDeltaMemStoresOp(f80e4931ac62410f81aef8e5fd6fa713) complete. Timing: real 0.010s	user 0.008s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3888,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:34.139489  6415 maintenance_manager.cc:419] P 428cb329833f4e918859ecfb4fff3d27: Scheduling MajorDeltaCompactionOp(f80e4931ac62410f81aef8e5fd6fa713): perf score=1.000000
I20260812 06:17:34.345382  6355 maintenance_manager.cc:643] P 428cb329833f4e918859ecfb4fff3d27: MajorDeltaCompactionOp(f80e4931ac62410f81aef8e5fd6fa713) complete. Timing: real 0.206s	user 0.145s	sys 0.047s Metrics: {"cfile_cache_miss":633,"cfile_cache_miss_bytes":28877215,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":483,"lbm_read_time_us":12248,"lbm_reads_lt_1ms":669,"lbm_write_time_us":34943,"lbm_writes_lt_1ms":643,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":9088,"thread_start_us":326,"threads_started":5,"update_count":3000}
I20260812 06:17:34.346132  6415 maintenance_manager.cc:419] P 428cb329833f4e918859ecfb4fff3d27: Scheduling FlushDeltaMemStoresOp(f80e4931ac62410f81aef8e5fd6fa713): perf score=14.095187
I20260812 06:17:34.401883  6355 maintenance_manager.cc:643] P 428cb329833f4e918859ecfb4fff3d27: FlushDeltaMemStoresOp(f80e4931ac62410f81aef8e5fd6fa713) complete. Timing: real 0.056s	user 0.031s	sys 0.015s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":21431,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:17:34.402369  6415 maintenance_manager.cc:419] P 428cb329833f4e918859ecfb4fff3d27: Scheduling FlushDeltaMemStoresOp(f80e4931ac62410f81aef8e5fd6fa713): perf score=2.188937
I20260812 06:17:34.412132  6355 maintenance_manager.cc:643] P 428cb329833f4e918859ecfb4fff3d27: FlushDeltaMemStoresOp(f80e4931ac62410f81aef8e5fd6fa713) complete. Timing: real 0.010s	user 0.009s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3784,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:34.412528  6415 maintenance_manager.cc:419] P 428cb329833f4e918859ecfb4fff3d27: Scheduling MajorDeltaCompactionOp(f80e4931ac62410f81aef8e5fd6fa713): perf score=1.000000
I20260812 06:17:34.589805  6355 maintenance_manager.cc:643] P 428cb329833f4e918859ecfb4fff3d27: MajorDeltaCompactionOp(f80e4931ac62410f81aef8e5fd6fa713) complete. Timing: real 0.177s	user 0.099s	sys 0.067s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774688,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":652,"lbm_read_time_us":13258,"lbm_reads_lt_1ms":572,"lbm_write_time_us":29068,"lbm_writes_lt_1ms":543,"mutex_wait_us":22,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":7040,"update_count":2500}
I20260812 06:17:34.590497  6415 maintenance_manager.cc:419] P 428cb329833f4e918859ecfb4fff3d27: Scheduling FlushDeltaMemStoresOp(f80e4931ac62410f81aef8e5fd6fa713): perf score=14.095187
I20260812 06:17:34.646107  6355 maintenance_manager.cc:643] P 428cb329833f4e918859ecfb4fff3d27: FlushDeltaMemStoresOp(f80e4931ac62410f81aef8e5fd6fa713) complete. Timing: real 0.055s	user 0.029s	sys 0.018s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":18259,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:17:34.646687  6415 maintenance_manager.cc:419] P 428cb329833f4e918859ecfb4fff3d27: Scheduling FlushDeltaMemStoresOp(f80e4931ac62410f81aef8e5fd6fa713): perf score=2.188937
I20260812 06:17:34.663018  6355 maintenance_manager.cc:643] P 428cb329833f4e918859ecfb4fff3d27: FlushDeltaMemStoresOp(f80e4931ac62410f81aef8e5fd6fa713) complete. Timing: real 0.016s	user 0.014s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6080,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:34.663545  6415 maintenance_manager.cc:419] P 428cb329833f4e918859ecfb4fff3d27: Scheduling MajorDeltaCompactionOp(f80e4931ac62410f81aef8e5fd6fa713): perf score=1.000000
I20260812 06:17:34.840083  6355 maintenance_manager.cc:643] P 428cb329833f4e918859ecfb4fff3d27: MajorDeltaCompactionOp(f80e4931ac62410f81aef8e5fd6fa713) complete. Timing: real 0.176s	user 0.115s	sys 0.056s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774689,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":124,"lbm_read_time_us":12497,"lbm_reads_lt_1ms":572,"lbm_write_time_us":28849,"lbm_writes_lt_1ms":543,"mutex_wait_us":60,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":896,"update_count":2500}
I20260812 06:17:34.840735  6415 maintenance_manager.cc:419] P 428cb329833f4e918859ecfb4fff3d27: Scheduling FlushDeltaMemStoresOp(f80e4931ac62410f81aef8e5fd6fa713): perf score=14.095187
I20260812 06:17:34.905227  6355 maintenance_manager.cc:643] P 428cb329833f4e918859ecfb4fff3d27: FlushDeltaMemStoresOp(f80e4931ac62410f81aef8e5fd6fa713) complete. Timing: real 0.064s	user 0.034s	sys 0.029s Metrics: {"bytes_written":16409904,"delete_count":0,"lbm_write_time_us":24866,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":402,"reinsert_count":0,"update_count":2000}
I20260812 06:17:34.905726  6415 maintenance_manager.cc:419] P 428cb329833f4e918859ecfb4fff3d27: Scheduling FlushDeltaMemStoresOp(f80e4931ac62410f81aef8e5fd6fa713): perf score=2.188937
I20260812 06:17:34.915907  6355 maintenance_manager.cc:643] P 428cb329833f4e918859ecfb4fff3d27: FlushDeltaMemStoresOp(f80e4931ac62410f81aef8e5fd6fa713) complete. Timing: real 0.010s	user 0.005s	sys 0.005s 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:34.916352  6415 maintenance_manager.cc:419] P 428cb329833f4e918859ecfb4fff3d27: Scheduling MajorDeltaCompactionOp(f80e4931ac62410f81aef8e5fd6fa713): perf score=1.000000
I20260812 06:17:35.086444  6355 maintenance_manager.cc:643] P 428cb329833f4e918859ecfb4fff3d27: MajorDeltaCompactionOp(f80e4931ac62410f81aef8e5fd6fa713) complete. Timing: real 0.170s	user 0.115s	sys 0.052s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774691,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":182,"lbm_read_time_us":11844,"lbm_reads_lt_1ms":572,"lbm_write_time_us":30335,"lbm_writes_lt_1ms":543,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":2432,"update_count":2500}
I20260812 06:17:35.087060  6415 maintenance_manager.cc:419] P 428cb329833f4e918859ecfb4fff3d27: Scheduling FlushDeltaMemStoresOp(f80e4931ac62410f81aef8e5fd6fa713): perf score=10.126437
I20260812 06:17:35.132983  6355 maintenance_manager.cc:643] P 428cb329833f4e918859ecfb4fff3d27: FlushDeltaMemStoresOp(f80e4931ac62410f81aef8e5fd6fa713) complete. Timing: real 0.046s	user 0.021s	sys 0.023s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":20818,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":302,"reinsert_count":0,"update_count":1500}
I20260812 06:17:35.133488  6415 maintenance_manager.cc:419] P 428cb329833f4e918859ecfb4fff3d27: Scheduling FlushDeltaMemStoresOp(f80e4931ac62410f81aef8e5fd6fa713): perf score=2.188937
I20260812 06:17:35.149264  6355 maintenance_manager.cc:643] P 428cb329833f4e918859ecfb4fff3d27: FlushDeltaMemStoresOp(f80e4931ac62410f81aef8e5fd6fa713) complete. Timing: real 0.016s	user 0.010s	sys 0.000s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4632,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:35.149796  6415 maintenance_manager.cc:419] P 428cb329833f4e918859ecfb4fff3d27: Scheduling MajorDeltaCompactionOp(f80e4931ac62410f81aef8e5fd6fa713): perf score=1.000000
I20260812 06:17:35.282482  6355 maintenance_manager.cc:643] P 428cb329833f4e918859ecfb4fff3d27: MajorDeltaCompactionOp(f80e4931ac62410f81aef8e5fd6fa713) complete. Timing: real 0.132s	user 0.112s	sys 0.020s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672276,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":303,"lbm_read_time_us":7953,"lbm_reads_lt_1ms":464,"lbm_write_time_us":26406,"lbm_writes_lt_1ms":443,"peak_mem_usage":50689328,"reinsert_count":0,"update_count":2000}
I20260812 06:17:35.283229  6415 maintenance_manager.cc:419] P 428cb329833f4e918859ecfb4fff3d27: Scheduling FlushDeltaMemStoresOp(f80e4931ac62410f81aef8e5fd6fa713): perf score=10.126437
I20260812 06:17:35.320990  6355 maintenance_manager.cc:643] P 428cb329833f4e918859ecfb4fff3d27: FlushDeltaMemStoresOp(f80e4931ac62410f81aef8e5fd6fa713) complete. Timing: real 0.038s	user 0.021s	sys 0.015s Metrics: {"bytes_written":12307489,"delete_count":0,"lbm_write_time_us":15653,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:17:35.321424  6415 maintenance_manager.cc:419] P 428cb329833f4e918859ecfb4fff3d27: Scheduling FlushDeltaMemStoresOp(f80e4931ac62410f81aef8e5fd6fa713): perf score=2.188937
I20260812 06:17:35.335539  6355 maintenance_manager.cc:643] P 428cb329833f4e918859ecfb4fff3d27: FlushDeltaMemStoresOp(f80e4931ac62410f81aef8e5fd6fa713) complete. Timing: real 0.014s	user 0.004s	sys 0.008s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":5456,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:35.336269  6415 maintenance_manager.cc:419] P 428cb329833f4e918859ecfb4fff3d27: Scheduling FlushMRSOp(f80e4931ac62410f81aef8e5fd6fa713): perf score=1.000000
I20260812 06:17:35.365557  6355 maintenance_manager.cc:643] P 428cb329833f4e918859ecfb4fff3d27: FlushMRSOp(f80e4931ac62410f81aef8e5fd6fa713) complete. Timing: real 0.029s	user 0.026s	sys 0.001s Metrics: {"bytes_written":1234473,"cfile_init":1,"dirs.queue_time_us":64,"dirs.run_cpu_time_us":199,"dirs.run_wall_time_us":1261,"drs_written":1,"lbm_read_time_us":65,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1673,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":30}
I20260812 06:17:35.366405  6415 maintenance_manager.cc:419] P 428cb329833f4e918859ecfb4fff3d27: Scheduling LogGCOp(f80e4931ac62410f81aef8e5fd6fa713): free 120553367 bytes of WAL
I20260812 06:17:35.366717  6355 log_reader.cc:385] T f80e4931ac62410f81aef8e5fd6fa713: removed 12 log segments from log reader
I20260812 06:17:35.366797  6355 log.cc:1079] T f80e4931ac62410f81aef8e5fd6fa713 P 428cb329833f4e918859ecfb4fff3d27: Deleting log segment in path: /tmp/dist-test-taskeFMdIZ/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515453483730-6254-0/minicluster-data/ts-0-root/wals/f80e4931ac62410f81aef8e5fd6fa713/wal-000000003 (ops 12-16)
I20260812 06:17:35.366864  6355 log.cc:1079] T f80e4931ac62410f81aef8e5fd6fa713 P 428cb329833f4e918859ecfb4fff3d27: Deleting log segment in path: /tmp/dist-test-taskeFMdIZ/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515453483730-6254-0/minicluster-data/ts-0-root/wals/f80e4931ac62410f81aef8e5fd6fa713/wal-000000004 (ops 17-21)
I20260812 06:17:35.366909  6355 log.cc:1079] T f80e4931ac62410f81aef8e5fd6fa713 P 428cb329833f4e918859ecfb4fff3d27: Deleting log segment in path: /tmp/dist-test-taskeFMdIZ/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515453483730-6254-0/minicluster-data/ts-0-root/wals/f80e4931ac62410f81aef8e5fd6fa713/wal-000000005 (ops 22-26)
I20260812 06:17:35.366967  6355 log.cc:1079] T f80e4931ac62410f81aef8e5fd6fa713 P 428cb329833f4e918859ecfb4fff3d27: Deleting log segment in path: /tmp/dist-test-taskeFMdIZ/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515453483730-6254-0/minicluster-data/ts-0-root/wals/f80e4931ac62410f81aef8e5fd6fa713/wal-000000006 (ops 27-30)
I20260812 06:17:35.367018  6355 log.cc:1079] T f80e4931ac62410f81aef8e5fd6fa713 P 428cb329833f4e918859ecfb4fff3d27: Deleting log segment in path: /tmp/dist-test-taskeFMdIZ/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515453483730-6254-0/minicluster-data/ts-0-root/wals/f80e4931ac62410f81aef8e5fd6fa713/wal-000000007 (ops 31-35)
I20260812 06:17:35.367067  6355 log.cc:1079] T f80e4931ac62410f81aef8e5fd6fa713 P 428cb329833f4e918859ecfb4fff3d27: Deleting log segment in path: /tmp/dist-test-taskeFMdIZ/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515453483730-6254-0/minicluster-data/ts-0-root/wals/f80e4931ac62410f81aef8e5fd6fa713/wal-000000008 (ops 36-40)
I20260812 06:17:35.367105  6355 log.cc:1079] T f80e4931ac62410f81aef8e5fd6fa713 P 428cb329833f4e918859ecfb4fff3d27: Deleting log segment in path: /tmp/dist-test-taskeFMdIZ/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515453483730-6254-0/minicluster-data/ts-0-root/wals/f80e4931ac62410f81aef8e5fd6fa713/wal-000000009 (ops 41-45)
I20260812 06:17:35.367161  6355 log.cc:1079] T f80e4931ac62410f81aef8e5fd6fa713 P 428cb329833f4e918859ecfb4fff3d27: Deleting log segment in path: /tmp/dist-test-taskeFMdIZ/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515453483730-6254-0/minicluster-data/ts-0-root/wals/f80e4931ac62410f81aef8e5fd6fa713/wal-000000010 (ops 46-50)
I20260812 06:17:35.367213  6355 log.cc:1079] T f80e4931ac62410f81aef8e5fd6fa713 P 428cb329833f4e918859ecfb4fff3d27: Deleting log segment in path: /tmp/dist-test-taskeFMdIZ/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515453483730-6254-0/minicluster-data/ts-0-root/wals/f80e4931ac62410f81aef8e5fd6fa713/wal-000000011 (ops 51-54)
I20260812 06:17:35.367260  6355 log.cc:1079] T f80e4931ac62410f81aef8e5fd6fa713 P 428cb329833f4e918859ecfb4fff3d27: Deleting log segment in path: /tmp/dist-test-taskeFMdIZ/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515453483730-6254-0/minicluster-data/ts-0-root/wals/f80e4931ac62410f81aef8e5fd6fa713/wal-000000012 (ops 55-59)
I20260812 06:17:35.367305  6355 log.cc:1079] T f80e4931ac62410f81aef8e5fd6fa713 P 428cb329833f4e918859ecfb4fff3d27: Deleting log segment in path: /tmp/dist-test-taskeFMdIZ/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515453483730-6254-0/minicluster-data/ts-0-root/wals/f80e4931ac62410f81aef8e5fd6fa713/wal-000000013 (ops 60-64)
I20260812 06:17:35.367347  6355 log.cc:1079] T f80e4931ac62410f81aef8e5fd6fa713 P 428cb329833f4e918859ecfb4fff3d27: Deleting log segment in path: /tmp/dist-test-taskeFMdIZ/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515453483730-6254-0/minicluster-data/ts-0-root/wals/f80e4931ac62410f81aef8e5fd6fa713/wal-000000014 (ops 65-69)
I20260812 06:17:35.394560  6355 maintenance_manager.cc:643] P 428cb329833f4e918859ecfb4fff3d27: LogGCOp(f80e4931ac62410f81aef8e5fd6fa713) complete. Timing: real 0.028s	user 0.002s	sys 0.023s Metrics: {}
I20260812 06:17:35.395059  6415 maintenance_manager.cc:419] P 428cb329833f4e918859ecfb4fff3d27: Scheduling UndoDeltaBlockGCOp(f80e4931ac62410f81aef8e5fd6fa713): 472 bytes on disk
I20260812 06:17:35.395761  6355 maintenance_manager.cc:643] P 428cb329833f4e918859ecfb4fff3d27: UndoDeltaBlockGCOp(f80e4931ac62410f81aef8e5fd6fa713) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":74,"lbm_reads_lt_1ms":4}
I20260812 06:17:35.396317  6415 maintenance_manager.cc:419] P 428cb329833f4e918859ecfb4fff3d27: Scheduling FlushDeltaMemStoresOp(f80e4931ac62410f81aef8e5fd6fa713): perf score=5.165500
I20260812 06:17:35.418515  6355 maintenance_manager.cc:643] P 428cb329833f4e918859ecfb4fff3d27: FlushDeltaMemStoresOp(f80e4931ac62410f81aef8e5fd6fa713) complete. Timing: real 0.022s	user 0.010s	sys 0.009s Metrics: {"bytes_written":6933327,"delete_count":0,"lbm_write_time_us":9110,"lbm_writes_lt_1ms":172,"reinsert_count":0,"update_count":845}
I20260812 06:17:35.419035  6415 maintenance_manager.cc:419] P 428cb329833f4e918859ecfb4fff3d27: Scheduling FlushDeltaMemStoresOp(f80e4931ac62410f81aef8e5fd6fa713): perf score=1.000000
I20260812 06:17:35.426397  6355 maintenance_manager.cc:643] P 428cb329833f4e918859ecfb4fff3d27: FlushDeltaMemStoresOp(f80e4931ac62410f81aef8e5fd6fa713) complete. Timing: real 0.007s	user 0.006s	sys 0.000s Metrics: {"bytes_written":1271927,"delete_count":0,"lbm_write_time_us":2110,"lbm_writes_lt_1ms":34,"reinsert_count":0,"update_count":155}
I20260812 06:17:35.426882  6415 maintenance_manager.cc:419] P 428cb329833f4e918859ecfb4fff3d27: Scheduling MajorDeltaCompactionOp(f80e4931ac62410f81aef8e5fd6fa713): perf score=1.000000
I20260812 06:17:35.599982  6355 maintenance_manager.cc:643] P 428cb329833f4e918859ecfb4fff3d27: MajorDeltaCompactionOp(f80e4931ac62410f81aef8e5fd6fa713) complete. Timing: real 0.173s	user 0.137s	sys 0.031s Metrics: {"cfile_cache_miss":634,"cfile_cache_miss_bytes":28877268,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":619,"lbm_read_time_us":12098,"lbm_reads_lt_1ms":674,"lbm_write_time_us":34105,"lbm_writes_lt_1ms":643,"mutex_wait_us":160,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":9344,"thread_start_us":128,"threads_started":1,"update_count":3000}
I20260812 06:17:35.601014  6415 maintenance_manager.cc:419] P 428cb329833f4e918859ecfb4fff3d27: Scheduling FlushDeltaMemStoresOp(f80e4931ac62410f81aef8e5fd6fa713): perf score=14.095187
I20260812 06:17:35.650883  6355 maintenance_manager.cc:643] P 428cb329833f4e918859ecfb4fff3d27: FlushDeltaMemStoresOp(f80e4931ac62410f81aef8e5fd6fa713) complete. Timing: real 0.050s	user 0.027s	sys 0.019s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":23087,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":402,"reinsert_count":0,"update_count":2000}
I20260812 06:17:35.651459  6415 maintenance_manager.cc:419] P 428cb329833f4e918859ecfb4fff3d27: Scheduling FlushDeltaMemStoresOp(f80e4931ac62410f81aef8e5fd6fa713): perf score=2.188937
I20260812 06:17:35.664172  6355 maintenance_manager.cc:643] P 428cb329833f4e918859ecfb4fff3d27: FlushDeltaMemStoresOp(f80e4931ac62410f81aef8e5fd6fa713) complete. Timing: real 0.012s	user 0.007s	sys 0.004s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4580,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:35.664677  6415 maintenance_manager.cc:419] P 428cb329833f4e918859ecfb4fff3d27: Scheduling MajorDeltaCompactionOp(f80e4931ac62410f81aef8e5fd6fa713): perf score=1.000000
I20260812 06:17:35.818536  6355 maintenance_manager.cc:643] P 428cb329833f4e918859ecfb4fff3d27: MajorDeltaCompactionOp(f80e4931ac62410f81aef8e5fd6fa713) complete. Timing: real 0.154s	user 0.111s	sys 0.033s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774687,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":696,"lbm_read_time_us":10889,"lbm_reads_lt_1ms":572,"lbm_write_time_us":29281,"lbm_writes_lt_1ms":543,"mutex_wait_us":317,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":9984,"update_count":2500}
I20260812 06:17:35.819285  6415 maintenance_manager.cc:419] P 428cb329833f4e918859ecfb4fff3d27: Scheduling FlushDeltaMemStoresOp(f80e4931ac62410f81aef8e5fd6fa713): perf score=14.095187
I20260812 06:17:35.868928  6355 maintenance_manager.cc:643] P 428cb329833f4e918859ecfb4fff3d27: FlushDeltaMemStoresOp(f80e4931ac62410f81aef8e5fd6fa713) complete. Timing: real 0.049s	user 0.028s	sys 0.015s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":19767,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:17:35.869414  6415 maintenance_manager.cc:419] P 428cb329833f4e918859ecfb4fff3d27: Scheduling FlushDeltaMemStoresOp(f80e4931ac62410f81aef8e5fd6fa713): perf score=2.188937
I20260812 06:17:35.880520  6355 maintenance_manager.cc:643] P 428cb329833f4e918859ecfb4fff3d27: FlushDeltaMemStoresOp(f80e4931ac62410f81aef8e5fd6fa713) complete. Timing: real 0.011s	user 0.010s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4130,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:35.880970  6415 maintenance_manager.cc:419] P 428cb329833f4e918859ecfb4fff3d27: Scheduling MajorDeltaCompactionOp(f80e4931ac62410f81aef8e5fd6fa713): perf score=1.000000
I20260812 06:17:36.034811  6355 maintenance_manager.cc:643] P 428cb329833f4e918859ecfb4fff3d27: MajorDeltaCompactionOp(f80e4931ac62410f81aef8e5fd6fa713) complete. Timing: real 0.154s	user 0.109s	sys 0.040s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774689,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":175,"lbm_read_time_us":10609,"lbm_reads_lt_1ms":572,"lbm_write_time_us":28920,"lbm_writes_lt_1ms":543,"mutex_wait_us":37,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":2816,"update_count":2500}
I20260812 06:17:36.035420  6415 maintenance_manager.cc:419] P 428cb329833f4e918859ecfb4fff3d27: Scheduling FlushDeltaMemStoresOp(f80e4931ac62410f81aef8e5fd6fa713): perf score=11.118625
I20260812 06:17:36.067031  6355 maintenance_manager.cc:643] P 428cb329833f4e918859ecfb4fff3d27: FlushDeltaMemStoresOp(f80e4931ac62410f81aef8e5fd6fa713) complete. Timing: real 0.031s	user 0.020s	sys 0.008s Metrics: {"bytes_written":12717735,"delete_count":0,"lbm_write_time_us":12931,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:17:36.067631  6415 maintenance_manager.cc:419] P 428cb329833f4e918859ecfb4fff3d27: Scheduling FlushDeltaMemStoresOp(f80e4931ac62410f81aef8e5fd6fa713): perf score=2.188937
I20260812 06:17:36.084686  6355 maintenance_manager.cc:643] P 428cb329833f4e918859ecfb4fff3d27: FlushDeltaMemStoresOp(f80e4931ac62410f81aef8e5fd6fa713) complete. Timing: real 0.017s	user 0.011s	sys 0.001s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":4599,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:17:36.085283  6415 maintenance_manager.cc:419] P 428cb329833f4e918859ecfb4fff3d27: Scheduling MajorDeltaCompactionOp(f80e4931ac62410f81aef8e5fd6fa713): perf score=1.000000
I20260812 06:17:36.207315  6355 maintenance_manager.cc:643] P 428cb329833f4e918859ecfb4fff3d27: MajorDeltaCompactionOp(f80e4931ac62410f81aef8e5fd6fa713) complete. Timing: real 0.122s	user 0.087s	sys 0.033s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672268,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":539,"lbm_read_time_us":8697,"lbm_reads_lt_1ms":464,"lbm_write_time_us":23988,"lbm_writes_lt_1ms":443,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":2688,"update_count":2000}
I20260812 06:17:36.207944  6415 maintenance_manager.cc:419] P 428cb329833f4e918859ecfb4fff3d27: Scheduling FlushDeltaMemStoresOp(f80e4931ac62410f81aef8e5fd6fa713): perf score=11.118625
I20260812 06:17:36.253722  6355 maintenance_manager.cc:643] P 428cb329833f4e918859ecfb4fff3d27: FlushDeltaMemStoresOp(f80e4931ac62410f81aef8e5fd6fa713) complete. Timing: real 0.046s	user 0.027s	sys 0.016s Metrics: {"bytes_written":12717735,"delete_count":0,"lbm_write_time_us":17626,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":312,"reinsert_count":0,"update_count":1550}
I20260812 06:17:36.254365  6415 maintenance_manager.cc:419] P 428cb329833f4e918859ecfb4fff3d27: Scheduling FlushDeltaMemStoresOp(f80e4931ac62410f81aef8e5fd6fa713): perf score=2.188937
I20260812 06:17:36.274358  6355 maintenance_manager.cc:643] P 428cb329833f4e918859ecfb4fff3d27: FlushDeltaMemStoresOp(f80e4931ac62410f81aef8e5fd6fa713) complete. Timing: real 0.020s	user 0.004s	sys 0.008s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":5598,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:17:36.274821  6415 maintenance_manager.cc:419] P 428cb329833f4e918859ecfb4fff3d27: Scheduling FlushDeltaMemStoresOp(f80e4931ac62410f81aef8e5fd6fa713): perf score=2.188937
I20260812 06:17:36.285207  6355 maintenance_manager.cc:643] P 428cb329833f4e918859ecfb4fff3d27: FlushDeltaMemStoresOp(f80e4931ac62410f81aef8e5fd6fa713) complete. Timing: real 0.010s	user 0.006s	sys 0.003s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3956,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:36.285772  6415 maintenance_manager.cc:419] P 428cb329833f4e918859ecfb4fff3d27: Scheduling MajorDeltaCompactionOp(f80e4931ac62410f81aef8e5fd6fa713): perf score=1.000000
I20260812 06:17:36.455050  6355 maintenance_manager.cc:643] P 428cb329833f4e918859ecfb4fff3d27: MajorDeltaCompactionOp(f80e4931ac62410f81aef8e5fd6fa713) complete. Timing: real 0.169s	user 0.123s	sys 0.045s Metrics: {"cfile_cache_miss":533,"cfile_cache_miss_bytes":24774799,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":1432,"lbm_read_time_us":10995,"lbm_reads_lt_1ms":573,"lbm_write_time_us":31007,"lbm_writes_lt_1ms":543,"mutex_wait_us":93,"peak_mem_usage":63115900,"reinsert_count":0,"update_count":2500}
I20260812 06:17:36.455772  6415 maintenance_manager.cc:419] P 428cb329833f4e918859ecfb4fff3d27: Scheduling FlushDeltaMemStoresOp(f80e4931ac62410f81aef8e5fd6fa713): perf score=14.095187
I20260812 06:17:36.517096  6355 maintenance_manager.cc:643] P 428cb329833f4e918859ecfb4fff3d27: FlushDeltaMemStoresOp(f80e4931ac62410f81aef8e5fd6fa713) complete. Timing: real 0.061s	user 0.052s	sys 0.008s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":23371,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:17:36.517645  6415 maintenance_manager.cc:419] P 428cb329833f4e918859ecfb4fff3d27: Scheduling FlushDeltaMemStoresOp(f80e4931ac62410f81aef8e5fd6fa713): perf score=2.188937
I20260812 06:17:36.542286  6355 maintenance_manager.cc:643] P 428cb329833f4e918859ecfb4fff3d27: FlushDeltaMemStoresOp(f80e4931ac62410f81aef8e5fd6fa713) complete. Timing: real 0.024s	user 0.003s	sys 0.012s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":6681,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:36.542724  6415 maintenance_manager.cc:419] P 428cb329833f4e918859ecfb4fff3d27: Scheduling FlushDeltaMemStoresOp(f80e4931ac62410f81aef8e5fd6fa713): perf score=2.188937
I20260812 06:17:36.553215  6355 maintenance_manager.cc:643] P 428cb329833f4e918859ecfb4fff3d27: FlushDeltaMemStoresOp(f80e4931ac62410f81aef8e5fd6fa713) complete. Timing: real 0.010s	user 0.005s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4161,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:36.553632  6415 maintenance_manager.cc:419] P 428cb329833f4e918859ecfb4fff3d27: Scheduling MajorDeltaCompactionOp(f80e4931ac62410f81aef8e5fd6fa713): perf score=1.000000
I20260812 06:17:36.750717  6355 maintenance_manager.cc:643] P 428cb329833f4e918859ecfb4fff3d27: MajorDeltaCompactionOp(f80e4931ac62410f81aef8e5fd6fa713) complete. Timing: real 0.197s	user 0.131s	sys 0.062s Metrics: {"cfile_cache_miss":633,"cfile_cache_miss_bytes":28877219,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":201,"lbm_read_time_us":13986,"lbm_reads_lt_1ms":673,"lbm_write_time_us":31193,"lbm_writes_lt_1ms":643,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":20480,"update_count":3000}
I20260812 06:17:36.751353  6415 maintenance_manager.cc:419] P 428cb329833f4e918859ecfb4fff3d27: Scheduling FlushDeltaMemStoresOp(f80e4931ac62410f81aef8e5fd6fa713): perf score=14.095187
I20260812 06:17:36.806223  6355 maintenance_manager.cc:643] P 428cb329833f4e918859ecfb4fff3d27: FlushDeltaMemStoresOp(f80e4931ac62410f81aef8e5fd6fa713) complete. Timing: real 0.055s	user 0.043s	sys 0.003s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":20995,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:17:36.806860  6415 maintenance_manager.cc:419] P 428cb329833f4e918859ecfb4fff3d27: Scheduling FlushDeltaMemStoresOp(f80e4931ac62410f81aef8e5fd6fa713): perf score=2.188937
I20260812 06:17:36.822239  6355 maintenance_manager.cc:643] P 428cb329833f4e918859ecfb4fff3d27: FlushDeltaMemStoresOp(f80e4931ac62410f81aef8e5fd6fa713) complete. Timing: real 0.015s	user 0.010s	sys 0.003s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6119,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:36.822755  6415 maintenance_manager.cc:419] P 428cb329833f4e918859ecfb4fff3d27: Scheduling FlushMRSOp(f80e4931ac62410f81aef8e5fd6fa713): perf score=1.000000
I20260812 06:17:36.863116  6355 maintenance_manager.cc:643] P 428cb329833f4e918859ecfb4fff3d27: FlushMRSOp(f80e4931ac62410f81aef8e5fd6fa713) complete. Timing: real 0.040s	user 0.035s	sys 0.004s Metrics: {"bytes_written":1275449,"cfile_init":1,"dirs.queue_time_us":53,"dirs.run_cpu_time_us":176,"dirs.run_wall_time_us":1597,"drs_written":1,"lbm_read_time_us":64,"lbm_reads_lt_1ms":4,"lbm_write_time_us":2318,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":31}
I20260812 06:17:36.863984  6415 maintenance_manager.cc:419] P 428cb329833f4e918859ecfb4fff3d27: Scheduling LogGCOp(f80e4931ac62410f81aef8e5fd6fa713): free 124710308 bytes of WAL
I20260812 06:17:36.864279  6355 log_reader.cc:385] T f80e4931ac62410f81aef8e5fd6fa713: removed 12 log segments from log reader
I20260812 06:17:36.864369  6355 log.cc:1079] T f80e4931ac62410f81aef8e5fd6fa713 P 428cb329833f4e918859ecfb4fff3d27: Deleting log segment in path: /tmp/dist-test-taskeFMdIZ/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515453483730-6254-0/minicluster-data/ts-0-root/wals/f80e4931ac62410f81aef8e5fd6fa713/wal-000000015 (ops 70-74)
I20260812 06:17:36.864425  6355 log.cc:1079] T f80e4931ac62410f81aef8e5fd6fa713 P 428cb329833f4e918859ecfb4fff3d27: Deleting log segment in path: /tmp/dist-test-taskeFMdIZ/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515453483730-6254-0/minicluster-data/ts-0-root/wals/f80e4931ac62410f81aef8e5fd6fa713/wal-000000016 (ops 75-79)
I20260812 06:17:36.864512  6355 log.cc:1079] T f80e4931ac62410f81aef8e5fd6fa713 P 428cb329833f4e918859ecfb4fff3d27: Deleting log segment in path: /tmp/dist-test-taskeFMdIZ/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515453483730-6254-0/minicluster-data/ts-0-root/wals/f80e4931ac62410f81aef8e5fd6fa713/wal-000000017 (ops 80-84)
I20260812 06:17:36.864562  6355 log.cc:1079] T f80e4931ac62410f81aef8e5fd6fa713 P 428cb329833f4e918859ecfb4fff3d27: Deleting log segment in path: /tmp/dist-test-taskeFMdIZ/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515453483730-6254-0/minicluster-data/ts-0-root/wals/f80e4931ac62410f81aef8e5fd6fa713/wal-000000018 (ops 85-89)
I20260812 06:17:36.864605  6355 log.cc:1079] T f80e4931ac62410f81aef8e5fd6fa713 P 428cb329833f4e918859ecfb4fff3d27: Deleting log segment in path: /tmp/dist-test-taskeFMdIZ/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515453483730-6254-0/minicluster-data/ts-0-root/wals/f80e4931ac62410f81aef8e5fd6fa713/wal-000000019 (ops 90-94)
I20260812 06:17:36.864650  6355 log.cc:1079] T f80e4931ac62410f81aef8e5fd6fa713 P 428cb329833f4e918859ecfb4fff3d27: Deleting log segment in path: /tmp/dist-test-taskeFMdIZ/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515453483730-6254-0/minicluster-data/ts-0-root/wals/f80e4931ac62410f81aef8e5fd6fa713/wal-000000020 (ops 95-99)
I20260812 06:17:36.864696  6355 log.cc:1079] T f80e4931ac62410f81aef8e5fd6fa713 P 428cb329833f4e918859ecfb4fff3d27: Deleting log segment in path: /tmp/dist-test-taskeFMdIZ/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515453483730-6254-0/minicluster-data/ts-0-root/wals/f80e4931ac62410f81aef8e5fd6fa713/wal-000000021 (ops 100-104)
I20260812 06:17:36.864740  6355 log.cc:1079] T f80e4931ac62410f81aef8e5fd6fa713 P 428cb329833f4e918859ecfb4fff3d27: Deleting log segment in path: /tmp/dist-test-taskeFMdIZ/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515453483730-6254-0/minicluster-data/ts-0-root/wals/f80e4931ac62410f81aef8e5fd6fa713/wal-000000022 (ops 105-109)
I20260812 06:17:36.864785  6355 log.cc:1079] T f80e4931ac62410f81aef8e5fd6fa713 P 428cb329833f4e918859ecfb4fff3d27: Deleting log segment in path: /tmp/dist-test-taskeFMdIZ/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515453483730-6254-0/minicluster-data/ts-0-root/wals/f80e4931ac62410f81aef8e5fd6fa713/wal-000000023 (ops 110-114)
I20260812 06:17:36.864830  6355 log.cc:1079] T f80e4931ac62410f81aef8e5fd6fa713 P 428cb329833f4e918859ecfb4fff3d27: Deleting log segment in path: /tmp/dist-test-taskeFMdIZ/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515453483730-6254-0/minicluster-data/ts-0-root/wals/f80e4931ac62410f81aef8e5fd6fa713/wal-000000024 (ops 115-119)
I20260812 06:17:36.864882  6355 log.cc:1079] T f80e4931ac62410f81aef8e5fd6fa713 P 428cb329833f4e918859ecfb4fff3d27: Deleting log segment in path: /tmp/dist-test-taskeFMdIZ/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515453483730-6254-0/minicluster-data/ts-0-root/wals/f80e4931ac62410f81aef8e5fd6fa713/wal-000000025 (ops 120-124)
I20260812 06:17:36.864928  6355 log.cc:1079] T f80e4931ac62410f81aef8e5fd6fa713 P 428cb329833f4e918859ecfb4fff3d27: Deleting log segment in path: /tmp/dist-test-taskeFMdIZ/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515453483730-6254-0/minicluster-data/ts-0-root/wals/f80e4931ac62410f81aef8e5fd6fa713/wal-000000026 (ops 125-129)
I20260812 06:17:36.894248  6355 maintenance_manager.cc:643] P 428cb329833f4e918859ecfb4fff3d27: LogGCOp(f80e4931ac62410f81aef8e5fd6fa713) complete. Timing: real 0.030s	user 0.000s	sys 0.028s Metrics: {}
I20260812 06:17:36.894748  6415 maintenance_manager.cc:419] P 428cb329833f4e918859ecfb4fff3d27: Scheduling UndoDeltaBlockGCOp(f80e4931ac62410f81aef8e5fd6fa713): 482 bytes on disk
I20260812 06:17:36.895326  6355 maintenance_manager.cc:643] P 428cb329833f4e918859ecfb4fff3d27: UndoDeltaBlockGCOp(f80e4931ac62410f81aef8e5fd6fa713) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":77,"lbm_reads_lt_1ms":4}
I20260812 06:17:36.895895  6415 maintenance_manager.cc:419] P 428cb329833f4e918859ecfb4fff3d27: Scheduling FlushDeltaMemStoresOp(f80e4931ac62410f81aef8e5fd6fa713): perf score=3.181125
I20260812 06:17:36.917438  6355 maintenance_manager.cc:643] P 428cb329833f4e918859ecfb4fff3d27: FlushDeltaMemStoresOp(f80e4931ac62410f81aef8e5fd6fa713) complete. Timing: real 0.021s	user 0.009s	sys 0.008s Metrics: {"bytes_written":4512900,"delete_count":0,"lbm_write_time_us":7714,"lbm_writes_lt_1ms":113,"reinsert_count":0,"update_count":550}
I20260812 06:17:36.917878  6415 maintenance_manager.cc:419] P 428cb329833f4e918859ecfb4fff3d27: Scheduling FlushDeltaMemStoresOp(f80e4931ac62410f81aef8e5fd6fa713): perf score=2.188937
I20260812 06:17:36.928337  6355 maintenance_manager.cc:643] P 428cb329833f4e918859ecfb4fff3d27: FlushDeltaMemStoresOp(f80e4931ac62410f81aef8e5fd6fa713) complete. Timing: real 0.010s	user 0.010s	sys 0.000s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3949,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:17:36.928761  6415 maintenance_manager.cc:419] P 428cb329833f4e918859ecfb4fff3d27: Scheduling MajorDeltaCompactionOp(f80e4931ac62410f81aef8e5fd6fa713): perf score=1.000000
I20260812 06:17:37.167941  6355 maintenance_manager.cc:643] P 428cb329833f4e918859ecfb4fff3d27: MajorDeltaCompactionOp(f80e4931ac62410f81aef8e5fd6fa713) complete. Timing: real 0.239s	user 0.160s	sys 0.073s Metrics: {"cfile_cache_miss":734,"cfile_cache_miss_bytes":32979737,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":743,"lbm_read_time_us":15697,"lbm_reads_lt_1ms":774,"lbm_write_time_us":43583,"lbm_writes_lt_1ms":743,"mutex_wait_us":17,"peak_mem_usage":87969044,"reinsert_count":0,"spinlock_wait_cycles":7296,"thread_start_us":86,"threads_started":1,"update_count":3500}
I20260812 06:17:37.168620  6415 maintenance_manager.cc:419] P 428cb329833f4e918859ecfb4fff3d27: Scheduling FlushDeltaMemStoresOp(f80e4931ac62410f81aef8e5fd6fa713): perf score=15.087375
I20260812 06:17:37.232792  6355 maintenance_manager.cc:643] P 428cb329833f4e918859ecfb4fff3d27: FlushDeltaMemStoresOp(f80e4931ac62410f81aef8e5fd6fa713) complete. Timing: real 0.064s	user 0.027s	sys 0.029s Metrics: {"bytes_written":16820143,"delete_count":0,"lbm_write_time_us":24752,"lbm_writes_lt_1ms":413,"mutex_wait_us":3,"reinsert_count":0,"update_count":2050}
I20260812 06:17:37.233356  6415 maintenance_manager.cc:419] P 428cb329833f4e918859ecfb4fff3d27: Scheduling FlushDeltaMemStoresOp(f80e4931ac62410f81aef8e5fd6fa713): perf score=6.157687
I20260812 06:17:37.257848  6355 maintenance_manager.cc:643] P 428cb329833f4e918859ecfb4fff3d27: FlushDeltaMemStoresOp(f80e4931ac62410f81aef8e5fd6fa713) complete. Timing: real 0.024s	user 0.014s	sys 0.004s Metrics: {"bytes_written":7794836,"delete_count":0,"lbm_write_time_us":8327,"lbm_writes_lt_1ms":193,"reinsert_count":0,"update_count":950}
I20260812 06:17:37.258519  6415 maintenance_manager.cc:419] P 428cb329833f4e918859ecfb4fff3d27: Scheduling MajorDeltaCompactionOp(f80e4931ac62410f81aef8e5fd6fa713): perf score=1.000000
I20260812 06:17:37.430713  6355 maintenance_manager.cc:643] P 428cb329833f4e918859ecfb4fff3d27: MajorDeltaCompactionOp(f80e4931ac62410f81aef8e5fd6fa713) complete. Timing: real 0.172s	user 0.132s	sys 0.040s Metrics: {"cfile_cache_miss":632,"cfile_cache_miss_bytes":28877101,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":222,"lbm_read_time_us":11210,"lbm_reads_lt_1ms":664,"lbm_write_time_us":34203,"lbm_writes_lt_1ms":643,"mutex_wait_us":54,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":19968,"update_count":3000}
I20260812 06:17:37.431612  6415 maintenance_manager.cc:419] P 428cb329833f4e918859ecfb4fff3d27: Scheduling FlushDeltaMemStoresOp(f80e4931ac62410f81aef8e5fd6fa713): perf score=14.095187
I20260812 06:17:37.480446  6355 maintenance_manager.cc:643] P 428cb329833f4e918859ecfb4fff3d27: FlushDeltaMemStoresOp(f80e4931ac62410f81aef8e5fd6fa713) complete. Timing: real 0.049s	user 0.039s	sys 0.008s Metrics: {"bytes_written":16409900,"delete_count":0,"lbm_write_time_us":21637,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:17:37.480948  6415 maintenance_manager.cc:419] P 428cb329833f4e918859ecfb4fff3d27: Scheduling FlushDeltaMemStoresOp(f80e4931ac62410f81aef8e5fd6fa713): perf score=2.188937
I20260812 06:17:37.492151  6355 maintenance_manager.cc:643] P 428cb329833f4e918859ecfb4fff3d27: FlushDeltaMemStoresOp(f80e4931ac62410f81aef8e5fd6fa713) complete. Timing: real 0.011s	user 0.002s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4200,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:37.492667  6415 maintenance_manager.cc:419] P 428cb329833f4e918859ecfb4fff3d27: Scheduling MajorDeltaCompactionOp(f80e4931ac62410f81aef8e5fd6fa713): perf score=1.000000
I20260812 06:17:37.661192  6355 maintenance_manager.cc:643] P 428cb329833f4e918859ecfb4fff3d27: MajorDeltaCompactionOp(f80e4931ac62410f81aef8e5fd6fa713) complete. Timing: real 0.168s	user 0.106s	sys 0.055s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774687,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":743,"lbm_read_time_us":10387,"lbm_reads_lt_1ms":572,"lbm_write_time_us":30634,"lbm_writes_lt_1ms":543,"mutex_wait_us":28,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":54528,"update_count":2500}
I20260812 06:17:37.661823  6415 maintenance_manager.cc:419] P 428cb329833f4e918859ecfb4fff3d27: Scheduling FlushDeltaMemStoresOp(f80e4931ac62410f81aef8e5fd6fa713): perf score=14.095187
I20260812 06:17:37.710178  6355 maintenance_manager.cc:643] P 428cb329833f4e918859ecfb4fff3d27: FlushDeltaMemStoresOp(f80e4931ac62410f81aef8e5fd6fa713) complete. Timing: real 0.048s	user 0.025s	sys 0.017s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":19848,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:17:37.710652  6415 maintenance_manager.cc:419] P 428cb329833f4e918859ecfb4fff3d27: Scheduling MajorDeltaCompactionOp(f80e4931ac62410f81aef8e5fd6fa713): perf score=1.000000
I20260812 06:17:37.864928  6355 maintenance_manager.cc:643] P 428cb329833f4e918859ecfb4fff3d27: MajorDeltaCompactionOp(f80e4931ac62410f81aef8e5fd6fa713) complete. Timing: real 0.154s	user 0.109s	sys 0.040s Metrics: {"cfile_cache_miss":431,"cfile_cache_miss_bytes":20672157,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":1,"delta_iterators_relevant":1,"dirs.queue_time_us":835,"lbm_read_time_us":10355,"lbm_reads_lt_1ms":463,"lbm_write_time_us":22742,"lbm_writes_lt_1ms":443,"mutex_wait_us":252,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":4480,"update_count":2000}
I20260812 06:17:37.865630  6415 maintenance_manager.cc:419] P 428cb329833f4e918859ecfb4fff3d27: Scheduling FlushDeltaMemStoresOp(f80e4931ac62410f81aef8e5fd6fa713): perf score=14.095187
I20260812 06:17:37.918119  6355 maintenance_manager.cc:643] P 428cb329833f4e918859ecfb4fff3d27: FlushDeltaMemStoresOp(f80e4931ac62410f81aef8e5fd6fa713) complete. Timing: real 0.052s	user 0.037s	sys 0.009s Metrics: {"bytes_written":16409903,"delete_count":0,"lbm_write_time_us":21133,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:17:37.918615  6415 maintenance_manager.cc:419] P 428cb329833f4e918859ecfb4fff3d27: Scheduling FlushDeltaMemStoresOp(f80e4931ac62410f81aef8e5fd6fa713): perf score=2.188937
I20260812 06:17:37.929451  6355 maintenance_manager.cc:643] P 428cb329833f4e918859ecfb4fff3d27: FlushDeltaMemStoresOp(f80e4931ac62410f81aef8e5fd6fa713) complete. Timing: real 0.011s	user 0.008s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3994,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:37.929930  6415 maintenance_manager.cc:419] P 428cb329833f4e918859ecfb4fff3d27: Scheduling MajorDeltaCompactionOp(f80e4931ac62410f81aef8e5fd6fa713): perf score=1.000000
I20260812 06:17:38.110285  6355 maintenance_manager.cc:643] P 428cb329833f4e918859ecfb4fff3d27: MajorDeltaCompactionOp(f80e4931ac62410f81aef8e5fd6fa713) complete. Timing: real 0.180s	user 0.124s	sys 0.051s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774690,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":160,"lbm_read_time_us":10353,"lbm_reads_lt_1ms":572,"lbm_write_time_us":28702,"lbm_writes_lt_1ms":543,"mutex_wait_us":39,"peak_mem_usage":63115900,"reinsert_count":0,"update_count":2500}
I20260812 06:17:38.110948  6415 maintenance_manager.cc:419] P 428cb329833f4e918859ecfb4fff3d27: Scheduling FlushDeltaMemStoresOp(f80e4931ac62410f81aef8e5fd6fa713): perf score=14.095187
I20260812 06:17:38.160642  6355 maintenance_manager.cc:643] P 428cb329833f4e918859ecfb4fff3d27: FlushDeltaMemStoresOp(f80e4931ac62410f81aef8e5fd6fa713) complete. Timing: real 0.049s	user 0.033s	sys 0.011s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":20304,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:17:38.161190  6415 maintenance_manager.cc:419] P 428cb329833f4e918859ecfb4fff3d27: Scheduling FlushDeltaMemStoresOp(f80e4931ac62410f81aef8e5fd6fa713): perf score=2.188937
I20260812 06:17:38.172304  6355 maintenance_manager.cc:643] P 428cb329833f4e918859ecfb4fff3d27: FlushDeltaMemStoresOp(f80e4931ac62410f81aef8e5fd6fa713) complete. Timing: real 0.011s	user 0.006s	sys 0.004s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4176,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:38.172768  6415 maintenance_manager.cc:419] P 428cb329833f4e918859ecfb4fff3d27: Scheduling MajorDeltaCompactionOp(f80e4931ac62410f81aef8e5fd6fa713): perf score=1.000000
I20260812 06:17:38.322376  6355 maintenance_manager.cc:643] P 428cb329833f4e918859ecfb4fff3d27: MajorDeltaCompactionOp(f80e4931ac62410f81aef8e5fd6fa713) complete. Timing: real 0.149s	user 0.108s	sys 0.040s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774688,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":962,"lbm_read_time_us":9330,"lbm_reads_lt_1ms":572,"lbm_write_time_us":30334,"lbm_writes_lt_1ms":543,"mutex_wait_us":274,"peak_mem_usage":63115900,"reinsert_count":0,"update_count":2500}
I20260812 06:17:38.322847  6415 maintenance_manager.cc:419] P 428cb329833f4e918859ecfb4fff3d27: Scheduling FlushDeltaMemStoresOp(f80e4931ac62410f81aef8e5fd6fa713): perf score=11.118625
I20260812 06:17:38.358579  6355 maintenance_manager.cc:643] P 428cb329833f4e918859ecfb4fff3d27: FlushDeltaMemStoresOp(f80e4931ac62410f81aef8e5fd6fa713) complete. Timing: real 0.036s	user 0.021s	sys 0.012s Metrics: {"bytes_written":12717735,"delete_count":0,"lbm_write_time_us":15888,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:17:38.359099  6415 maintenance_manager.cc:419] P 428cb329833f4e918859ecfb4fff3d27: Scheduling FlushDeltaMemStoresOp(f80e4931ac62410f81aef8e5fd6fa713): perf score=2.188937
I20260812 06:17:38.376995  6355 maintenance_manager.cc:643] P 428cb329833f4e918859ecfb4fff3d27: FlushDeltaMemStoresOp(f80e4931ac62410f81aef8e5fd6fa713) complete. Timing: real 0.018s	user 0.004s	sys 0.011s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":6237,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:17:38.377663  6415 maintenance_manager.cc:419] P 428cb329833f4e918859ecfb4fff3d27: Scheduling FlushMRSOp(f80e4931ac62410f81aef8e5fd6fa713): perf score=1.000000
I20260812 06:17:38.432088  6355 maintenance_manager.cc:643] P 428cb329833f4e918859ecfb4fff3d27: FlushMRSOp(f80e4931ac62410f81aef8e5fd6fa713) complete. Timing: real 0.054s	user 0.038s	sys 0.000s Metrics: {"bytes_written":1316417,"cfile_init":1,"dirs.queue_time_us":71,"dirs.run_cpu_time_us":197,"dirs.run_wall_time_us":1213,"drs_written":1,"lbm_read_time_us":73,"lbm_reads_lt_1ms":4,"lbm_write_time_us":2069,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":32}
I20260812 06:17:38.432766  6415 maintenance_manager.cc:419] P 428cb329833f4e918859ecfb4fff3d27: Scheduling LogGCOp(f80e4931ac62410f81aef8e5fd6fa713): free 128867720 bytes of WAL
I20260812 06:17:38.432999  6355 log_reader.cc:385] T f80e4931ac62410f81aef8e5fd6fa713: removed 13 log segments from log reader
I20260812 06:17:38.433048  6355 log.cc:1079] T f80e4931ac62410f81aef8e5fd6fa713 P 428cb329833f4e918859ecfb4fff3d27: Deleting log segment in path: /tmp/dist-test-taskeFMdIZ/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515453483730-6254-0/minicluster-data/ts-0-root/wals/f80e4931ac62410f81aef8e5fd6fa713/wal-000000027 (ops 130-134)
I20260812 06:17:38.433075  6355 log.cc:1079] T f80e4931ac62410f81aef8e5fd6fa713 P 428cb329833f4e918859ecfb4fff3d27: Deleting log segment in path: /tmp/dist-test-taskeFMdIZ/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515453483730-6254-0/minicluster-data/ts-0-root/wals/f80e4931ac62410f81aef8e5fd6fa713/wal-000000028 (ops 135-138)
I20260812 06:17:38.433135  6355 log.cc:1079] T f80e4931ac62410f81aef8e5fd6fa713 P 428cb329833f4e918859ecfb4fff3d27: Deleting log segment in path: /tmp/dist-test-taskeFMdIZ/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515453483730-6254-0/minicluster-data/ts-0-root/wals/f80e4931ac62410f81aef8e5fd6fa713/wal-000000029 (ops 139-143)
I20260812 06:17:38.433178  6355 log.cc:1079] T f80e4931ac62410f81aef8e5fd6fa713 P 428cb329833f4e918859ecfb4fff3d27: Deleting log segment in path: /tmp/dist-test-taskeFMdIZ/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515453483730-6254-0/minicluster-data/ts-0-root/wals/f80e4931ac62410f81aef8e5fd6fa713/wal-000000030 (ops 144-148)
I20260812 06:17:38.433229  6355 log.cc:1079] T f80e4931ac62410f81aef8e5fd6fa713 P 428cb329833f4e918859ecfb4fff3d27: Deleting log segment in path: /tmp/dist-test-taskeFMdIZ/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515453483730-6254-0/minicluster-data/ts-0-root/wals/f80e4931ac62410f81aef8e5fd6fa713/wal-000000031 (ops 149-153)
I20260812 06:17:38.433269  6355 log.cc:1079] T f80e4931ac62410f81aef8e5fd6fa713 P 428cb329833f4e918859ecfb4fff3d27: Deleting log segment in path: /tmp/dist-test-taskeFMdIZ/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515453483730-6254-0/minicluster-data/ts-0-root/wals/f80e4931ac62410f81aef8e5fd6fa713/wal-000000032 (ops 154-158)
I20260812 06:17:38.433310  6355 log.cc:1079] T f80e4931ac62410f81aef8e5fd6fa713 P 428cb329833f4e918859ecfb4fff3d27: Deleting log segment in path: /tmp/dist-test-taskeFMdIZ/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515453483730-6254-0/minicluster-data/ts-0-root/wals/f80e4931ac62410f81aef8e5fd6fa713/wal-000000033 (ops 159-163)
I20260812 06:17:38.433349  6355 log.cc:1079] T f80e4931ac62410f81aef8e5fd6fa713 P 428cb329833f4e918859ecfb4fff3d27: Deleting log segment in path: /tmp/dist-test-taskeFMdIZ/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515453483730-6254-0/minicluster-data/ts-0-root/wals/f80e4931ac62410f81aef8e5fd6fa713/wal-000000034 (ops 164-168)
I20260812 06:17:38.433389  6355 log.cc:1079] T f80e4931ac62410f81aef8e5fd6fa713 P 428cb329833f4e918859ecfb4fff3d27: Deleting log segment in path: /tmp/dist-test-taskeFMdIZ/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515453483730-6254-0/minicluster-data/ts-0-root/wals/f80e4931ac62410f81aef8e5fd6fa713/wal-000000035 (ops 169-172)
I20260812 06:17:38.433437  6355 log.cc:1079] T f80e4931ac62410f81aef8e5fd6fa713 P 428cb329833f4e918859ecfb4fff3d27: Deleting log segment in path: /tmp/dist-test-taskeFMdIZ/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515453483730-6254-0/minicluster-data/ts-0-root/wals/f80e4931ac62410f81aef8e5fd6fa713/wal-000000036 (ops 173-177)
I20260812 06:17:38.433477  6355 log.cc:1079] T f80e4931ac62410f81aef8e5fd6fa713 P 428cb329833f4e918859ecfb4fff3d27: Deleting log segment in path: /tmp/dist-test-taskeFMdIZ/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515453483730-6254-0/minicluster-data/ts-0-root/wals/f80e4931ac62410f81aef8e5fd6fa713/wal-000000037 (ops 178-182)
I20260812 06:17:38.433521  6355 log.cc:1079] T f80e4931ac62410f81aef8e5fd6fa713 P 428cb329833f4e918859ecfb4fff3d27: Deleting log segment in path: /tmp/dist-test-taskeFMdIZ/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515453483730-6254-0/minicluster-data/ts-0-root/wals/f80e4931ac62410f81aef8e5fd6fa713/wal-000000038 (ops 183-186)
I20260812 06:17:38.433561  6355 log.cc:1079] T f80e4931ac62410f81aef8e5fd6fa713 P 428cb329833f4e918859ecfb4fff3d27: Deleting log segment in path: /tmp/dist-test-taskeFMdIZ/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515453483730-6254-0/minicluster-data/ts-0-root/wals/f80e4931ac62410f81aef8e5fd6fa713/wal-000000039 (ops 187-191)
I20260812 06:17:38.458879  6355 maintenance_manager.cc:643] P 428cb329833f4e918859ecfb4fff3d27: LogGCOp(f80e4931ac62410f81aef8e5fd6fa713) complete. Timing: real 0.026s	user 0.000s	sys 0.023s Metrics: {}
I20260812 06:17:38.459306  6415 maintenance_manager.cc:419] P 428cb329833f4e918859ecfb4fff3d27: Scheduling FlushDeltaMemStoresOp(f80e4931ac62410f81aef8e5fd6fa713): perf score=7.149875
I20260812 06:17:38.492177  6355 maintenance_manager.cc:643] P 428cb329833f4e918859ecfb4fff3d27: FlushDeltaMemStoresOp(f80e4931ac62410f81aef8e5fd6fa713) complete. Timing: real 0.033s	user 0.024s	sys 0.008s Metrics: {"bytes_written":8615322,"delete_count":0,"lbm_write_time_us":9625,"lbm_writes_lt_1ms":213,"reinsert_count":0,"update_count":1050}
I20260812 06:17:38.492811  6415 maintenance_manager.cc:419] P 428cb329833f4e918859ecfb4fff3d27: Scheduling LogGCOp(f80e4931ac62410f81aef8e5fd6fa713): free 12018006 bytes of WAL
I20260812 06:17:38.493073  6355 log_reader.cc:385] T f80e4931ac62410f81aef8e5fd6fa713: removed 1 log segments from log reader
I20260812 06:17:38.493140  6355 log.cc:1079] T f80e4931ac62410f81aef8e5fd6fa713 P 428cb329833f4e918859ecfb4fff3d27: Deleting log segment in path: /tmp/dist-test-taskeFMdIZ/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515453483730-6254-0/minicluster-data/ts-0-root/wals/f80e4931ac62410f81aef8e5fd6fa713/wal-000000040 (ops 192-196)
I20260812 06:17:38.495395  6355 maintenance_manager.cc:643] P 428cb329833f4e918859ecfb4fff3d27: LogGCOp(f80e4931ac62410f81aef8e5fd6fa713) complete. Timing: real 0.002s	user 0.000s	sys 0.000s Metrics: {}
I20260812 06:17:38.495813  6415 maintenance_manager.cc:419] P 428cb329833f4e918859ecfb4fff3d27: Scheduling FlushDeltaMemStoresOp(f80e4931ac62410f81aef8e5fd6fa713): perf score=2.188937
I20260812 06:17:38.506086  6355 maintenance_manager.cc:643] P 428cb329833f4e918859ecfb4fff3d27: FlushDeltaMemStoresOp(f80e4931ac62410f81aef8e5fd6fa713) complete. Timing: real 0.010s	user 0.000s	sys 0.008s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3963,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:17:38.506505  6415 maintenance_manager.cc:419] P 428cb329833f4e918859ecfb4fff3d27: Scheduling MajorDeltaCompactionOp(f80e4931ac62410f81aef8e5fd6fa713): perf score=1.000000
I20260812 06:17:38.550410  6254 heavy-update-compaction-itest.cc:229] Time spent updating: real 4.796s	user 1.802s	sys 0.133s
I20260812 06:17:38.653995  6254 heavy-update-compaction-itest.cc:265] Time spent scanning: real 0.103s	user 0.001s	sys 0.000s
I20260812 06:17:38.654773  6254 tablet_server.cc:179] TabletServer@127.6.27.129:0 shutting down...
I20260812 06:17:38.701118  6355 maintenance_manager.cc:643] P 428cb329833f4e918859ecfb4fff3d27: MajorDeltaCompactionOp(f80e4931ac62410f81aef8e5fd6fa713) complete. Timing: real 0.194s	user 0.114s	sys 0.080s Metrics: {"cfile_cache_miss":734,"cfile_cache_miss_bytes":32979733,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":1228,"lbm_read_time_us":15196,"lbm_reads_lt_1ms":770,"lbm_write_time_us":32753,"lbm_writes_lt_1ms":743,"mutex_wait_us":300,"peak_mem_usage":87969044,"reinsert_count":0,"spinlock_wait_cycles":2816,"thread_start_us":85,"threads_started":1,"update_count":3500}
I20260812 06:17:38.701869  6254 ts_tablet_manager.cc:1507] Shutting down tablet manager...
I20260812 06:17:38.702468  6254 tablet_replica.cc:333] T f80e4931ac62410f81aef8e5fd6fa713 P 428cb329833f4e918859ecfb4fff3d27: stopping tablet replica
I20260812 06:17:38.702718  6254 raft_consensus.cc:2243] T f80e4931ac62410f81aef8e5fd6fa713 P 428cb329833f4e918859ecfb4fff3d27 [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:17:38.702962  6254 raft_consensus.cc:2272] T f80e4931ac62410f81aef8e5fd6fa713 P 428cb329833f4e918859ecfb4fff3d27 [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:17:38.719238  6254 tablet_server.cc:196] TabletServer@127.6.27.129:0 shutdown complete.
I20260812 06:17:38.758221  6254 master.cc:562] Master@127.6.27.190:39693 shutting down...
I20260812 06:17:38.762089  6254 raft_consensus.cc:2243] T 00000000000000000000000000000000 P 1a91d1ff3d5747539b524cfb747b88d3 [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:17:38.762290  6254 raft_consensus.cc:2272] T 00000000000000000000000000000000 P 1a91d1ff3d5747539b524cfb747b88d3 [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:17:38.762390  6254 tablet_replica.cc:333] T 00000000000000000000000000000000 P 1a91d1ff3d5747539b524cfb747b88d3: stopping tablet replica
I20260812 06:17:38.774816  6254 master.cc:584] Master@127.6.27.190:39693 shutdown complete.
[       OK ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/0 (5363 ms)
[ RUN      ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/1
I20260812 06:17:38.869439  6254 internal_mini_cluster.cc:156] Creating distributed mini masters. Addrs: 127.6.27.190:37505
I20260812 06:17:38.869885  6254 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:17:38.872043  6446 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:38.871995  6445 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:38.872014  6254 server_base.cc:1061] running on GCE node
W20260812 06:17:38.871981  6448 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:38.872402  6254 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:17:38.872445  6254 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:38.872460  6254 hybrid_clock.cc:648] HybridClock initialized: now 1786515458872460 us; error 0 us; skew 500 ppm
I20260812 06:17:38.873266  6254 webserver.cc:533] Webserver started at http://127.6.27.190:37057/ using document root <none> and password file <none>
I20260812 06:17:38.873421  6254 fs_manager.cc:362] Metadata directory not provided
I20260812 06:17:38.873463  6254 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:17:38.873520  6254 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:17:38.873867  6254 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskeFMdIZ/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515453483730-6254-0/minicluster-data/master-0-root/instance:
uuid: "e11c6b1e0a1b41b5bd58750d5bad0e71"
format_stamp: "Formatted at 2026-08-12 06:17:38 on dist-test-slave-bxbt"
I20260812 06:17:38.875293  6254 fs_manager.cc:696] Time spent creating directory manager: real 0.001s	user 0.002s	sys 0.000s
I20260812 06:17:38.876669  6453 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:38.876938  6254 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.000s	sys 0.000s
I20260812 06:17:38.877038  6254 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskeFMdIZ/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515453483730-6254-0/minicluster-data/master-0-root
uuid: "e11c6b1e0a1b41b5bd58750d5bad0e71"
format_stamp: "Formatted at 2026-08-12 06:17:38 on dist-test-slave-bxbt"
I20260812 06:17:38.877125  6254 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskeFMdIZ/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515453483730-6254-0/minicluster-data/master-0-root
metadata directory: /tmp/dist-test-taskeFMdIZ/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515453483730-6254-0/minicluster-data/master-0-root
1 data directories: /tmp/dist-test-taskeFMdIZ/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515453483730-6254-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:38.892956  6254 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:17:38.893371  6254 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:17:38.897884  6254 rpc_server.cc:307] RPC server started. Bound to: 127.6.27.190:37505
I20260812 06:17:38.899139  6505 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.6.27.190:37505 every 8 connection(s)
I20260812 06:17:38.899664  6506 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:38.905062  6506 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P e11c6b1e0a1b41b5bd58750d5bad0e71: Bootstrap starting.
I20260812 06:17:38.905864  6506 tablet_bootstrap.cc:654] T 00000000000000000000000000000000 P e11c6b1e0a1b41b5bd58750d5bad0e71: Neither blocks nor log segments found. Creating new log.
I20260812 06:17:38.906880  6506 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P e11c6b1e0a1b41b5bd58750d5bad0e71: No bootstrap required, opened a new log
I20260812 06:17:38.907284  6506 raft_consensus.cc:359] T 00000000000000000000000000000000 P e11c6b1e0a1b41b5bd58750d5bad0e71 [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "e11c6b1e0a1b41b5bd58750d5bad0e71" member_type: VOTER }
I20260812 06:17:38.907399  6506 raft_consensus.cc:385] T 00000000000000000000000000000000 P e11c6b1e0a1b41b5bd58750d5bad0e71 [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:17:38.907423  6506 raft_consensus.cc:740] T 00000000000000000000000000000000 P e11c6b1e0a1b41b5bd58750d5bad0e71 [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: e11c6b1e0a1b41b5bd58750d5bad0e71, State: Initialized, Role: FOLLOWER
I20260812 06:17:38.907577  6506 consensus_queue.cc:260] T 00000000000000000000000000000000 P e11c6b1e0a1b41b5bd58750d5bad0e71 [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: "e11c6b1e0a1b41b5bd58750d5bad0e71" member_type: VOTER }
I20260812 06:17:38.907650  6506 raft_consensus.cc:399] T 00000000000000000000000000000000 P e11c6b1e0a1b41b5bd58750d5bad0e71 [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:17:38.907730  6506 raft_consensus.cc:493] T 00000000000000000000000000000000 P e11c6b1e0a1b41b5bd58750d5bad0e71 [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:17:38.907795  6506 raft_consensus.cc:3060] T 00000000000000000000000000000000 P e11c6b1e0a1b41b5bd58750d5bad0e71 [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:17:38.908478  6506 raft_consensus.cc:515] T 00000000000000000000000000000000 P e11c6b1e0a1b41b5bd58750d5bad0e71 [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "e11c6b1e0a1b41b5bd58750d5bad0e71" member_type: VOTER }
I20260812 06:17:38.908645  6506 leader_election.cc:304] T 00000000000000000000000000000000 P e11c6b1e0a1b41b5bd58750d5bad0e71 [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: e11c6b1e0a1b41b5bd58750d5bad0e71; no voters: 
I20260812 06:17:38.908864  6506 leader_election.cc:290] T 00000000000000000000000000000000 P e11c6b1e0a1b41b5bd58750d5bad0e71 [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:17:38.908949  6509 raft_consensus.cc:2804] T 00000000000000000000000000000000 P e11c6b1e0a1b41b5bd58750d5bad0e71 [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:17:38.909121  6509 raft_consensus.cc:697] T 00000000000000000000000000000000 P e11c6b1e0a1b41b5bd58750d5bad0e71 [term 1 LEADER]: Becoming Leader. State: Replica: e11c6b1e0a1b41b5bd58750d5bad0e71, State: Running, Role: LEADER
I20260812 06:17:38.909304  6509 consensus_queue.cc:237] T 00000000000000000000000000000000 P e11c6b1e0a1b41b5bd58750d5bad0e71 [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: "e11c6b1e0a1b41b5bd58750d5bad0e71" member_type: VOTER }
I20260812 06:17:38.909375  6506 sys_catalog.cc:565] T 00000000000000000000000000000000 P e11c6b1e0a1b41b5bd58750d5bad0e71 [sys.catalog]: configured and running, proceeding with master startup.
I20260812 06:17:38.909758  6510 sys_catalog.cc:455] T 00000000000000000000000000000000 P e11c6b1e0a1b41b5bd58750d5bad0e71 [sys.catalog]: SysCatalogTable state changed. Reason: RaftConsensus started. Latest consensus state: current_term: 1 leader_uuid: "e11c6b1e0a1b41b5bd58750d5bad0e71" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "e11c6b1e0a1b41b5bd58750d5bad0e71" member_type: VOTER } }
I20260812 06:17:38.909792  6511 sys_catalog.cc:455] T 00000000000000000000000000000000 P e11c6b1e0a1b41b5bd58750d5bad0e71 [sys.catalog]: SysCatalogTable state changed. Reason: New leader e11c6b1e0a1b41b5bd58750d5bad0e71. Latest consensus state: current_term: 1 leader_uuid: "e11c6b1e0a1b41b5bd58750d5bad0e71" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "e11c6b1e0a1b41b5bd58750d5bad0e71" member_type: VOTER } }
I20260812 06:17:38.909940  6511 sys_catalog.cc:458] T 00000000000000000000000000000000 P e11c6b1e0a1b41b5bd58750d5bad0e71 [sys.catalog]: This master's current role is: LEADER
I20260812 06:17:38.909929  6510 sys_catalog.cc:458] T 00000000000000000000000000000000 P e11c6b1e0a1b41b5bd58750d5bad0e71 [sys.catalog]: This master's current role is: LEADER
I20260812 06:17:38.910470  6514 catalog_manager.cc:1511] Loading table and tablet metadata into memory...
I20260812 06:17:38.911422  6514 catalog_manager.cc:1520] Initializing Kudu cluster ID...
I20260812 06:17:38.911628  6254 internal_mini_cluster.cc:184] Waiting to initialize catalog manager on master 0
I20260812 06:17:38.913275  6514 catalog_manager.cc:1383] Generated new cluster ID: 786496d33d144d3a963eb74d3c10aec7
I20260812 06:17:38.913333  6514 catalog_manager.cc:1531] Initializing Kudu internal certificate authority...
I20260812 06:17:38.939311  6514 catalog_manager.cc:1406] Generated new certificate authority record
I20260812 06:17:38.939934  6514 catalog_manager.cc:1540] Loading token signing keys...
I20260812 06:17:38.949316  6514 catalog_manager.cc:6092] T 00000000000000000000000000000000 P e11c6b1e0a1b41b5bd58750d5bad0e71: Generated new TSK 0
I20260812 06:17:38.949501  6514 catalog_manager.cc:1550] Initializing in-progress tserver states...
I20260812 06:17:38.976230  6254 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:17:38.978240  6527 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:38.978282  6528 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:38.978434  6254 server_base.cc:1061] running on GCE node
W20260812 06:17:38.978282  6530 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:38.978734  6254 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:17:38.978806  6254 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:38.978827  6254 hybrid_clock.cc:648] HybridClock initialized: now 1786515458978828 us; error 0 us; skew 500 ppm
I20260812 06:17:38.979647  6254 webserver.cc:533] Webserver started at http://127.6.27.129:46537/ using document root <none> and password file <none>
I20260812 06:17:38.979859  6254 fs_manager.cc:362] Metadata directory not provided
I20260812 06:17:38.979933  6254 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:17:38.980013  6254 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:17:38.980425  6254 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskeFMdIZ/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515453483730-6254-0/minicluster-data/ts-0-root/instance:
uuid: "36071023ed754f15a38af26ca86c8720"
format_stamp: "Formatted at 2026-08-12 06:17:38 on dist-test-slave-bxbt"
I20260812 06:17:38.981899  6254 fs_manager.cc:696] Time spent creating directory manager: real 0.001s	user 0.002s	sys 0.000s
I20260812 06:17:38.982803  6535 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:38.983048  6254 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.001s	sys 0.000s
I20260812 06:17:38.983142  6254 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskeFMdIZ/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515453483730-6254-0/minicluster-data/ts-0-root
uuid: "36071023ed754f15a38af26ca86c8720"
format_stamp: "Formatted at 2026-08-12 06:17:38 on dist-test-slave-bxbt"
I20260812 06:17:38.983232  6254 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskeFMdIZ/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515453483730-6254-0/minicluster-data/ts-0-root
metadata directory: /tmp/dist-test-taskeFMdIZ/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515453483730-6254-0/minicluster-data/ts-0-root
1 data directories: /tmp/dist-test-taskeFMdIZ/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515453483730-6254-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:38.999572  6254 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:17:38.999989  6254 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:17:39.000289  6254 txn_system_client.cc:432] TxnSystemClient initialization is disabled...
I20260812 06:17:39.000747  6254 ts_tablet_manager.cc:585] Loaded tablet metadata (0 total tablets, 0 live tablets)
I20260812 06:17:39.000808  6254 ts_tablet_manager.cc:531] Time spent load tablet metadata: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:17:39.000864  6254 ts_tablet_manager.cc:616] Registered 0 tablets
I20260812 06:17:39.000914  6254 ts_tablet_manager.cc:595] Time spent register tablets: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:17:39.005440  6254 rpc_server.cc:307] RPC server started. Bound to: 127.6.27.129:40035
I20260812 06:17:39.005950  6598 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.6.27.129:40035 every 8 connection(s)
I20260812 06:17:39.014663  6599 heartbeater.cc:344] Connected to a master server at 127.6.27.190:37505
I20260812 06:17:39.014761  6599 heartbeater.cc:461] Registering TS with master...
I20260812 06:17:39.015028  6599 heartbeater.cc:507] Master 127.6.27.190:37505 requested a full tablet report, sending...
I20260812 06:17:39.015625  6470 ts_manager.cc:194] Registered new tserver with Master: 36071023ed754f15a38af26ca86c8720 (127.6.27.129:40035)
I20260812 06:17:39.016024  6254 internal_mini_cluster.cc:371] 1 TS(s) registered with all masters after 0.009913352s
I20260812 06:17:39.016458  6470 master_service.cc:502] Signed X509 certificate for tserver {username='slave'} at 127.0.0.1:34578
I20260812 06:17:39.022734  6470 catalog_manager.cc:2283] Servicing CreateTable request from {username='slave'} at 127.0.0.1:34580:
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:39.031088  6563 tablet_service.cc:1511] Processing CreateTablet for tablet 3b8e688f01604204bbbbfc745c640423 (DEFAULT_TABLE table=heavy-update-compaction-test [id=e628f2c22477404ebf1f144167b0b9a6]), partition=
I20260812 06:17:39.031352  6563 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet 3b8e688f01604204bbbbfc745c640423. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:17:39.033412  6611 tablet_bootstrap.cc:492] T 3b8e688f01604204bbbbfc745c640423 P 36071023ed754f15a38af26ca86c8720: Bootstrap starting.
I20260812 06:17:39.034323  6611 tablet_bootstrap.cc:654] T 3b8e688f01604204bbbbfc745c640423 P 36071023ed754f15a38af26ca86c8720: Neither blocks nor log segments found. Creating new log.
I20260812 06:17:39.035346  6611 tablet_bootstrap.cc:492] T 3b8e688f01604204bbbbfc745c640423 P 36071023ed754f15a38af26ca86c8720: No bootstrap required, opened a new log
I20260812 06:17:39.035418  6611 ts_tablet_manager.cc:1403] T 3b8e688f01604204bbbbfc745c640423 P 36071023ed754f15a38af26ca86c8720: Time spent bootstrapping tablet: real 0.002s	user 0.001s	sys 0.000s
I20260812 06:17:39.035907  6611 raft_consensus.cc:359] T 3b8e688f01604204bbbbfc745c640423 P 36071023ed754f15a38af26ca86c8720 [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "36071023ed754f15a38af26ca86c8720" member_type: VOTER last_known_addr { host: "127.6.27.129" port: 40035 } }
I20260812 06:17:39.035992  6611 raft_consensus.cc:385] T 3b8e688f01604204bbbbfc745c640423 P 36071023ed754f15a38af26ca86c8720 [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:17:39.036015  6611 raft_consensus.cc:740] T 3b8e688f01604204bbbbfc745c640423 P 36071023ed754f15a38af26ca86c8720 [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: 36071023ed754f15a38af26ca86c8720, State: Initialized, Role: FOLLOWER
I20260812 06:17:39.036207  6611 consensus_queue.cc:260] T 3b8e688f01604204bbbbfc745c640423 P 36071023ed754f15a38af26ca86c8720 [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: "36071023ed754f15a38af26ca86c8720" member_type: VOTER last_known_addr { host: "127.6.27.129" port: 40035 } }
I20260812 06:17:39.036319  6611 raft_consensus.cc:399] T 3b8e688f01604204bbbbfc745c640423 P 36071023ed754f15a38af26ca86c8720 [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:17:39.036369  6611 raft_consensus.cc:493] T 3b8e688f01604204bbbbfc745c640423 P 36071023ed754f15a38af26ca86c8720 [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:17:39.036432  6611 raft_consensus.cc:3060] T 3b8e688f01604204bbbbfc745c640423 P 36071023ed754f15a38af26ca86c8720 [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:17:39.037304  6611 raft_consensus.cc:515] T 3b8e688f01604204bbbbfc745c640423 P 36071023ed754f15a38af26ca86c8720 [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "36071023ed754f15a38af26ca86c8720" member_type: VOTER last_known_addr { host: "127.6.27.129" port: 40035 } }
I20260812 06:17:39.037423  6611 leader_election.cc:304] T 3b8e688f01604204bbbbfc745c640423 P 36071023ed754f15a38af26ca86c8720 [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: 36071023ed754f15a38af26ca86c8720; no voters: 
I20260812 06:17:39.037564  6611 leader_election.cc:290] T 3b8e688f01604204bbbbfc745c640423 P 36071023ed754f15a38af26ca86c8720 [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:17:39.037703  6613 raft_consensus.cc:2804] T 3b8e688f01604204bbbbfc745c640423 P 36071023ed754f15a38af26ca86c8720 [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:17:39.037933  6613 raft_consensus.cc:697] T 3b8e688f01604204bbbbfc745c640423 P 36071023ed754f15a38af26ca86c8720 [term 1 LEADER]: Becoming Leader. State: Replica: 36071023ed754f15a38af26ca86c8720, State: Running, Role: LEADER
I20260812 06:17:39.037953  6611 ts_tablet_manager.cc:1434] T 3b8e688f01604204bbbbfc745c640423 P 36071023ed754f15a38af26ca86c8720: Time spent starting tablet: real 0.002s	user 0.003s	sys 0.000s
I20260812 06:17:39.038009  6599 heartbeater.cc:499] Master 127.6.27.190:37505 was elected leader, sending a full tablet report...
I20260812 06:17:39.038089  6613 consensus_queue.cc:237] T 3b8e688f01604204bbbbfc745c640423 P 36071023ed754f15a38af26ca86c8720 [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: "36071023ed754f15a38af26ca86c8720" member_type: VOTER last_known_addr { host: "127.6.27.129" port: 40035 } }
I20260812 06:17:39.039398  6470 catalog_manager.cc:5719] T 3b8e688f01604204bbbbfc745c640423 P 36071023ed754f15a38af26ca86c8720 reported cstate change: term changed from 0 to 1, leader changed from <none> to 36071023ed754f15a38af26ca86c8720 (127.6.27.129). New cstate: current_term: 1 leader_uuid: "36071023ed754f15a38af26ca86c8720" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "36071023ed754f15a38af26ca86c8720" member_type: VOTER last_known_addr { host: "127.6.27.129" port: 40035 } health_report { overall_health: HEALTHY } } }
I20260812 06:17:39.102964  6254 heavy-update-compaction-itest.cc:215] Time spent inserting: real 0.056s	user 0.017s	sys 0.004s
I20260812 06:17:39.256542  6600 maintenance_manager.cc:419] P 36071023ed754f15a38af26ca86c8720: Scheduling FlushMRSOp(3b8e688f01604204bbbbfc745c640423): perf score=19.054940
I20260812 06:17:39.409029  6540 maintenance_manager.cc:643] P 36071023ed754f15a38af26ca86c8720: FlushMRSOp(3b8e688f01604204bbbbfc745c640423) complete. Timing: real 0.152s	user 0.107s	sys 0.040s Metrics: {"bytes_written":13743339,"cfile_init":1,"delete_count":0,"dirs.queue_time_us":69,"dirs.run_cpu_time_us":226,"dirs.run_wall_time_us":913,"drs_written":1,"lbm_read_time_us":49,"lbm_reads_lt_1ms":4,"lbm_write_time_us":39394,"lbm_writes_lt_1ms":792,"mutex_wait_us":776,"peak_mem_usage":0,"reinsert_count":0,"rows_written":104,"spinlock_wait_cycles":1152,"update_count":1675}
I20260812 06:17:39.409659  6600 maintenance_manager.cc:419] P 36071023ed754f15a38af26ca86c8720: Scheduling FlushDeltaMemStoresOp(3b8e688f01604204bbbbfc745c640423): perf score=2.188937
I20260812 06:17:39.428793  6540 maintenance_manager.cc:643] P 36071023ed754f15a38af26ca86c8720: FlushDeltaMemStoresOp(3b8e688f01604204bbbbfc745c640423) complete. Timing: real 0.019s	user 0.008s	sys 0.006s Metrics: {"bytes_written":3282163,"delete_count":0,"lbm_write_time_us":5283,"lbm_writes_lt_1ms":83,"reinsert_count":0,"update_count":400}
I20260812 06:17:39.429255  6600 maintenance_manager.cc:419] P 36071023ed754f15a38af26ca86c8720: Scheduling LogGCOp(3b8e688f01604204bbbbfc745c640423): free 20743880 bytes of WAL
I20260812 06:17:39.429489  6540 log_reader.cc:385] T 3b8e688f01604204bbbbfc745c640423: removed 2 log segments from log reader
I20260812 06:17:39.429560  6540 log.cc:1079] T 3b8e688f01604204bbbbfc745c640423 P 36071023ed754f15a38af26ca86c8720: Deleting log segment in path: /tmp/dist-test-taskeFMdIZ/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515453483730-6254-0/minicluster-data/ts-0-root/wals/3b8e688f01604204bbbbfc745c640423/wal-000000001 (ops 1-6)
I20260812 06:17:39.429646  6540 log.cc:1079] T 3b8e688f01604204bbbbfc745c640423 P 36071023ed754f15a38af26ca86c8720: Deleting log segment in path: /tmp/dist-test-taskeFMdIZ/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515453483730-6254-0/minicluster-data/ts-0-root/wals/3b8e688f01604204bbbbfc745c640423/wal-000000002 (ops 7-11)
I20260812 06:17:39.433508  6540 maintenance_manager.cc:643] P 36071023ed754f15a38af26ca86c8720: LogGCOp(3b8e688f01604204bbbbfc745c640423) complete. Timing: real 0.004s	user 0.000s	sys 0.002s Metrics: {}
I20260812 06:17:39.433864  6600 maintenance_manager.cc:419] P 36071023ed754f15a38af26ca86c8720: Scheduling FlushDeltaMemStoresOp(3b8e688f01604204bbbbfc745c640423): perf score=2.188937
I20260812 06:17:39.442780  6540 maintenance_manager.cc:643] P 36071023ed754f15a38af26ca86c8720: FlushDeltaMemStoresOp(3b8e688f01604204bbbbfc745c640423) complete. Timing: real 0.009s	user 0.004s	sys 0.004s Metrics: {"bytes_written":3487280,"delete_count":0,"lbm_write_time_us":3383,"lbm_writes_lt_1ms":88,"reinsert_count":0,"update_count":425}
I20260812 06:17:39.443313  6600 maintenance_manager.cc:419] P 36071023ed754f15a38af26ca86c8720: Scheduling UndoDeltaBlockGCOp(3b8e688f01604204bbbbfc745c640423): 16411393 bytes on disk
I20260812 06:17:39.443781  6540 maintenance_manager.cc:643] P 36071023ed754f15a38af26ca86c8720: UndoDeltaBlockGCOp(3b8e688f01604204bbbbfc745c640423) 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:39.444317  6600 maintenance_manager.cc:419] P 36071023ed754f15a38af26ca86c8720: Scheduling MajorDeltaCompactionOp(3b8e688f01604204bbbbfc745c640423): perf score=1.000000
I20260812 06:17:39.616459  6540 maintenance_manager.cc:643] P 36071023ed754f15a38af26ca86c8720: MajorDeltaCompactionOp(3b8e688f01604204bbbbfc745c640423) complete. Timing: real 0.172s	user 0.137s	sys 0.031s Metrics: {"cfile_cache_miss":533,"cfile_cache_miss_bytes":24774782,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":536,"lbm_read_time_us":13050,"lbm_reads_lt_1ms":569,"lbm_write_time_us":28074,"lbm_writes_lt_1ms":543,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":5376,"thread_start_us":314,"threads_started":5,"update_count":2500}
I20260812 06:17:39.617142  6600 maintenance_manager.cc:419] P 36071023ed754f15a38af26ca86c8720: Scheduling FlushDeltaMemStoresOp(3b8e688f01604204bbbbfc745c640423): perf score=14.095187
I20260812 06:17:39.661895  6540 maintenance_manager.cc:643] P 36071023ed754f15a38af26ca86c8720: FlushDeltaMemStoresOp(3b8e688f01604204bbbbfc745c640423) complete. Timing: real 0.045s	user 0.030s	sys 0.012s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":19386,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:17:39.662415  6600 maintenance_manager.cc:419] P 36071023ed754f15a38af26ca86c8720: Scheduling MajorDeltaCompactionOp(3b8e688f01604204bbbbfc745c640423): perf score=1.000000
I20260812 06:17:39.824090  6540 maintenance_manager.cc:643] P 36071023ed754f15a38af26ca86c8720: MajorDeltaCompactionOp(3b8e688f01604204bbbbfc745c640423) complete. Timing: real 0.162s	user 0.100s	sys 0.062s Metrics: {"cfile_cache_miss":431,"cfile_cache_miss_bytes":20672158,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":1,"delta_iterators_relevant":1,"dirs.queue_time_us":1041,"lbm_read_time_us":10813,"lbm_reads_lt_1ms":463,"lbm_write_time_us":25755,"lbm_writes_lt_1ms":443,"mutex_wait_us":273,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":7552,"update_count":2000}
I20260812 06:17:39.824684  6600 maintenance_manager.cc:419] P 36071023ed754f15a38af26ca86c8720: Scheduling FlushDeltaMemStoresOp(3b8e688f01604204bbbbfc745c640423): perf score=14.095187
I20260812 06:17:39.870841  6540 maintenance_manager.cc:643] P 36071023ed754f15a38af26ca86c8720: FlushDeltaMemStoresOp(3b8e688f01604204bbbbfc745c640423) complete. Timing: real 0.046s	user 0.021s	sys 0.018s Metrics: {"bytes_written":16409903,"delete_count":0,"lbm_write_time_us":18708,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:17:39.871295  6600 maintenance_manager.cc:419] P 36071023ed754f15a38af26ca86c8720: Scheduling FlushDeltaMemStoresOp(3b8e688f01604204bbbbfc745c640423): perf score=2.188937
I20260812 06:17:39.882225  6540 maintenance_manager.cc:643] P 36071023ed754f15a38af26ca86c8720: FlushDeltaMemStoresOp(3b8e688f01604204bbbbfc745c640423) complete. Timing: real 0.011s	user 0.006s	sys 0.003s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3967,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:39.882663  6600 maintenance_manager.cc:419] P 36071023ed754f15a38af26ca86c8720: Scheduling MajorDeltaCompactionOp(3b8e688f01604204bbbbfc745c640423): perf score=1.000000
I20260812 06:17:40.063993  6540 maintenance_manager.cc:643] P 36071023ed754f15a38af26ca86c8720: MajorDeltaCompactionOp(3b8e688f01604204bbbbfc745c640423) complete. Timing: real 0.181s	user 0.139s	sys 0.040s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774690,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":329,"lbm_read_time_us":10666,"lbm_reads_lt_1ms":572,"lbm_write_time_us":28781,"lbm_writes_lt_1ms":543,"mutex_wait_us":40,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":15488,"update_count":2500}
I20260812 06:17:40.064563  6600 maintenance_manager.cc:419] P 36071023ed754f15a38af26ca86c8720: Scheduling FlushDeltaMemStoresOp(3b8e688f01604204bbbbfc745c640423): perf score=14.095187
I20260812 06:17:40.113517  6540 maintenance_manager.cc:643] P 36071023ed754f15a38af26ca86c8720: FlushDeltaMemStoresOp(3b8e688f01604204bbbbfc745c640423) complete. Timing: real 0.049s	user 0.031s	sys 0.013s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":20216,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:17:40.113978  6600 maintenance_manager.cc:419] P 36071023ed754f15a38af26ca86c8720: Scheduling FlushDeltaMemStoresOp(3b8e688f01604204bbbbfc745c640423): perf score=2.188937
I20260812 06:17:40.125072  6540 maintenance_manager.cc:643] P 36071023ed754f15a38af26ca86c8720: FlushDeltaMemStoresOp(3b8e688f01604204bbbbfc745c640423) complete. Timing: real 0.011s	user 0.005s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4231,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:40.125514  6600 maintenance_manager.cc:419] P 36071023ed754f15a38af26ca86c8720: Scheduling MajorDeltaCompactionOp(3b8e688f01604204bbbbfc745c640423): perf score=1.000000
I20260812 06:17:40.282950  6540 maintenance_manager.cc:643] P 36071023ed754f15a38af26ca86c8720: MajorDeltaCompactionOp(3b8e688f01604204bbbbfc745c640423) complete. Timing: real 0.157s	user 0.109s	sys 0.040s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774689,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":176,"lbm_read_time_us":10359,"lbm_reads_lt_1ms":572,"lbm_write_time_us":29534,"lbm_writes_lt_1ms":543,"mutex_wait_us":35,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":8960,"update_count":2500}
I20260812 06:17:40.283512  6600 maintenance_manager.cc:419] P 36071023ed754f15a38af26ca86c8720: Scheduling FlushDeltaMemStoresOp(3b8e688f01604204bbbbfc745c640423): perf score=14.095187
I20260812 06:17:40.339531  6540 maintenance_manager.cc:643] P 36071023ed754f15a38af26ca86c8720: FlushDeltaMemStoresOp(3b8e688f01604204bbbbfc745c640423) complete. Timing: real 0.056s	user 0.035s	sys 0.016s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":23334,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:17:40.340081  6600 maintenance_manager.cc:419] P 36071023ed754f15a38af26ca86c8720: Scheduling FlushDeltaMemStoresOp(3b8e688f01604204bbbbfc745c640423): perf score=2.188937
I20260812 06:17:40.354835  6540 maintenance_manager.cc:643] P 36071023ed754f15a38af26ca86c8720: FlushDeltaMemStoresOp(3b8e688f01604204bbbbfc745c640423) complete. Timing: real 0.015s	user 0.009s	sys 0.003s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5501,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:40.355425  6600 maintenance_manager.cc:419] P 36071023ed754f15a38af26ca86c8720: Scheduling MajorDeltaCompactionOp(3b8e688f01604204bbbbfc745c640423): perf score=1.000000
I20260812 06:17:40.497690  6540 maintenance_manager.cc:643] P 36071023ed754f15a38af26ca86c8720: MajorDeltaCompactionOp(3b8e688f01604204bbbbfc745c640423) complete. Timing: real 0.142s	user 0.112s	sys 0.027s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774688,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":732,"lbm_read_time_us":9409,"lbm_reads_lt_1ms":572,"lbm_write_time_us":31226,"lbm_writes_lt_1ms":543,"mutex_wait_us":81,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":2944,"update_count":2500}
I20260812 06:17:40.498476  6600 maintenance_manager.cc:419] P 36071023ed754f15a38af26ca86c8720: Scheduling FlushDeltaMemStoresOp(3b8e688f01604204bbbbfc745c640423): perf score=11.118625
I20260812 06:17:40.534408  6540 maintenance_manager.cc:643] P 36071023ed754f15a38af26ca86c8720: FlushDeltaMemStoresOp(3b8e688f01604204bbbbfc745c640423) complete. Timing: real 0.036s	user 0.029s	sys 0.004s Metrics: {"bytes_written":12717735,"delete_count":0,"lbm_write_time_us":14888,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:17:40.534984  6600 maintenance_manager.cc:419] P 36071023ed754f15a38af26ca86c8720: Scheduling FlushDeltaMemStoresOp(3b8e688f01604204bbbbfc745c640423): perf score=2.188937
I20260812 06:17:40.551514  6540 maintenance_manager.cc:643] P 36071023ed754f15a38af26ca86c8720: FlushDeltaMemStoresOp(3b8e688f01604204bbbbfc745c640423) complete. Timing: real 0.016s	user 0.011s	sys 0.000s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":4841,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:17:40.552153  6600 maintenance_manager.cc:419] P 36071023ed754f15a38af26ca86c8720: Scheduling FlushMRSOp(3b8e688f01604204bbbbfc745c640423): perf score=1.000000
I20260812 06:17:40.604707  6540 maintenance_manager.cc:643] P 36071023ed754f15a38af26ca86c8720: FlushMRSOp(3b8e688f01604204bbbbfc745c640423) complete. Timing: real 0.052s	user 0.032s	sys 0.000s Metrics: {"bytes_written":1193503,"cfile_init":1,"dirs.queue_time_us":63,"dirs.run_cpu_time_us":259,"dirs.run_wall_time_us":1274,"drs_written":1,"lbm_read_time_us":59,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1506,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":29}
I20260812 06:17:40.605471  6600 maintenance_manager.cc:419] P 36071023ed754f15a38af26ca86c8720: Scheduling LogGCOp(3b8e688f01604204bbbbfc745c640423): free 111786284 bytes of WAL
I20260812 06:17:40.605720  6540 log_reader.cc:385] T 3b8e688f01604204bbbbfc745c640423: removed 11 log segments from log reader
I20260812 06:17:40.605793  6540 log.cc:1079] T 3b8e688f01604204bbbbfc745c640423 P 36071023ed754f15a38af26ca86c8720: Deleting log segment in path: /tmp/dist-test-taskeFMdIZ/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515453483730-6254-0/minicluster-data/ts-0-root/wals/3b8e688f01604204bbbbfc745c640423/wal-000000003 (ops 12-16)
I20260812 06:17:40.605845  6540 log.cc:1079] T 3b8e688f01604204bbbbfc745c640423 P 36071023ed754f15a38af26ca86c8720: Deleting log segment in path: /tmp/dist-test-taskeFMdIZ/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515453483730-6254-0/minicluster-data/ts-0-root/wals/3b8e688f01604204bbbbfc745c640423/wal-000000004 (ops 17-21)
I20260812 06:17:40.605906  6540 log.cc:1079] T 3b8e688f01604204bbbbfc745c640423 P 36071023ed754f15a38af26ca86c8720: Deleting log segment in path: /tmp/dist-test-taskeFMdIZ/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515453483730-6254-0/minicluster-data/ts-0-root/wals/3b8e688f01604204bbbbfc745c640423/wal-000000005 (ops 22-26)
I20260812 06:17:40.605949  6540 log.cc:1079] T 3b8e688f01604204bbbbfc745c640423 P 36071023ed754f15a38af26ca86c8720: Deleting log segment in path: /tmp/dist-test-taskeFMdIZ/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515453483730-6254-0/minicluster-data/ts-0-root/wals/3b8e688f01604204bbbbfc745c640423/wal-000000006 (ops 27-31)
I20260812 06:17:40.605988  6540 log.cc:1079] T 3b8e688f01604204bbbbfc745c640423 P 36071023ed754f15a38af26ca86c8720: Deleting log segment in path: /tmp/dist-test-taskeFMdIZ/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515453483730-6254-0/minicluster-data/ts-0-root/wals/3b8e688f01604204bbbbfc745c640423/wal-000000007 (ops 32-36)
I20260812 06:17:40.606027  6540 log.cc:1079] T 3b8e688f01604204bbbbfc745c640423 P 36071023ed754f15a38af26ca86c8720: Deleting log segment in path: /tmp/dist-test-taskeFMdIZ/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515453483730-6254-0/minicluster-data/ts-0-root/wals/3b8e688f01604204bbbbfc745c640423/wal-000000008 (ops 37-40)
I20260812 06:17:40.606066  6540 log.cc:1079] T 3b8e688f01604204bbbbfc745c640423 P 36071023ed754f15a38af26ca86c8720: Deleting log segment in path: /tmp/dist-test-taskeFMdIZ/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515453483730-6254-0/minicluster-data/ts-0-root/wals/3b8e688f01604204bbbbfc745c640423/wal-000000009 (ops 41-45)
I20260812 06:17:40.606106  6540 log.cc:1079] T 3b8e688f01604204bbbbfc745c640423 P 36071023ed754f15a38af26ca86c8720: Deleting log segment in path: /tmp/dist-test-taskeFMdIZ/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515453483730-6254-0/minicluster-data/ts-0-root/wals/3b8e688f01604204bbbbfc745c640423/wal-000000010 (ops 46-50)
I20260812 06:17:40.606144  6540 log.cc:1079] T 3b8e688f01604204bbbbfc745c640423 P 36071023ed754f15a38af26ca86c8720: Deleting log segment in path: /tmp/dist-test-taskeFMdIZ/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515453483730-6254-0/minicluster-data/ts-0-root/wals/3b8e688f01604204bbbbfc745c640423/wal-000000011 (ops 51-55)
I20260812 06:17:40.606195  6540 log.cc:1079] T 3b8e688f01604204bbbbfc745c640423 P 36071023ed754f15a38af26ca86c8720: Deleting log segment in path: /tmp/dist-test-taskeFMdIZ/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515453483730-6254-0/minicluster-data/ts-0-root/wals/3b8e688f01604204bbbbfc745c640423/wal-000000012 (ops 56-60)
I20260812 06:17:40.606237  6540 log.cc:1079] T 3b8e688f01604204bbbbfc745c640423 P 36071023ed754f15a38af26ca86c8720: Deleting log segment in path: /tmp/dist-test-taskeFMdIZ/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515453483730-6254-0/minicluster-data/ts-0-root/wals/3b8e688f01604204bbbbfc745c640423/wal-000000013 (ops 61-64)
I20260812 06:17:40.627172  6540 maintenance_manager.cc:643] P 36071023ed754f15a38af26ca86c8720: LogGCOp(3b8e688f01604204bbbbfc745c640423) complete. Timing: real 0.022s	user 0.000s	sys 0.018s Metrics: {}
I20260812 06:17:40.627743  6600 maintenance_manager.cc:419] P 36071023ed754f15a38af26ca86c8720: Scheduling FlushDeltaMemStoresOp(3b8e688f01604204bbbbfc745c640423): perf score=6.157687
I20260812 06:17:40.647877  6540 maintenance_manager.cc:643] P 36071023ed754f15a38af26ca86c8720: FlushDeltaMemStoresOp(3b8e688f01604204bbbbfc745c640423) complete. Timing: real 0.020s	user 0.009s	sys 0.008s Metrics: {"bytes_written":8205079,"delete_count":0,"lbm_write_time_us":8263,"lbm_writes_lt_1ms":203,"reinsert_count":0,"update_count":1000}
I20260812 06:17:40.648298  6600 maintenance_manager.cc:419] P 36071023ed754f15a38af26ca86c8720: Scheduling LogGCOp(3b8e688f01604204bbbbfc745c640423): free 8767118 bytes of WAL
I20260812 06:17:40.648564  6540 log_reader.cc:385] T 3b8e688f01604204bbbbfc745c640423: removed 1 log segments from log reader
I20260812 06:17:40.648626  6540 log.cc:1079] T 3b8e688f01604204bbbbfc745c640423 P 36071023ed754f15a38af26ca86c8720: Deleting log segment in path: /tmp/dist-test-taskeFMdIZ/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515453483730-6254-0/minicluster-data/ts-0-root/wals/3b8e688f01604204bbbbfc745c640423/wal-000000014 (ops 65-69)
I20260812 06:17:40.650725  6540 maintenance_manager.cc:643] P 36071023ed754f15a38af26ca86c8720: LogGCOp(3b8e688f01604204bbbbfc745c640423) complete. Timing: real 0.002s	user 0.000s	sys 0.000s Metrics: {}
I20260812 06:17:40.651029  6600 maintenance_manager.cc:419] P 36071023ed754f15a38af26ca86c8720: Scheduling UndoDeltaBlockGCOp(3b8e688f01604204bbbbfc745c640423): 462 bytes on disk
I20260812 06:17:40.651465  6540 maintenance_manager.cc:643] P 36071023ed754f15a38af26ca86c8720: UndoDeltaBlockGCOp(3b8e688f01604204bbbbfc745c640423) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":62,"lbm_reads_lt_1ms":4}
I20260812 06:17:40.651965  6600 maintenance_manager.cc:419] P 36071023ed754f15a38af26ca86c8720: Scheduling FlushDeltaMemStoresOp(3b8e688f01604204bbbbfc745c640423): perf score=2.188937
I20260812 06:17:40.667390  6540 maintenance_manager.cc:643] P 36071023ed754f15a38af26ca86c8720: FlushDeltaMemStoresOp(3b8e688f01604204bbbbfc745c640423) complete. Timing: real 0.015s	user 0.013s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6020,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:40.667853  6600 maintenance_manager.cc:419] P 36071023ed754f15a38af26ca86c8720: Scheduling MajorDeltaCompactionOp(3b8e688f01604204bbbbfc745c640423): perf score=1.000000
I20260812 06:17:40.900209  6540 maintenance_manager.cc:643] P 36071023ed754f15a38af26ca86c8720: MajorDeltaCompactionOp(3b8e688f01604204bbbbfc745c640423) complete. Timing: real 0.231s	user 0.126s	sys 0.099s Metrics: {"cfile_cache_miss":734,"cfile_cache_miss_bytes":32979744,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":1816,"lbm_read_time_us":16722,"lbm_reads_lt_1ms":766,"lbm_write_time_us":36386,"lbm_writes_lt_1ms":743,"mutex_wait_us":67,"peak_mem_usage":87969044,"reinsert_count":0,"spinlock_wait_cycles":4224,"thread_start_us":76,"threads_started":1,"update_count":3500}
I20260812 06:17:40.900965  6600 maintenance_manager.cc:419] P 36071023ed754f15a38af26ca86c8720: Scheduling FlushDeltaMemStoresOp(3b8e688f01604204bbbbfc745c640423): perf score=18.063937
I20260812 06:17:40.973657  6540 maintenance_manager.cc:643] P 36071023ed754f15a38af26ca86c8720: FlushDeltaMemStoresOp(3b8e688f01604204bbbbfc745c640423) complete. Timing: real 0.072s	user 0.047s	sys 0.024s Metrics: {"bytes_written":20512315,"delete_count":0,"lbm_write_time_us":27330,"lbm_writes_lt_1ms":503,"reinsert_count":0,"update_count":2500}
I20260812 06:17:40.974319  6600 maintenance_manager.cc:419] P 36071023ed754f15a38af26ca86c8720: Scheduling FlushDeltaMemStoresOp(3b8e688f01604204bbbbfc745c640423): perf score=2.188937
I20260812 06:17:40.985060  6540 maintenance_manager.cc:643] P 36071023ed754f15a38af26ca86c8720: FlushDeltaMemStoresOp(3b8e688f01604204bbbbfc745c640423) complete. Timing: real 0.011s	user 0.001s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4026,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:40.985566  6600 maintenance_manager.cc:419] P 36071023ed754f15a38af26ca86c8720: Scheduling MajorDeltaCompactionOp(3b8e688f01604204bbbbfc745c640423): perf score=1.000000
I20260812 06:17:41.178711  6540 maintenance_manager.cc:643] P 36071023ed754f15a38af26ca86c8720: MajorDeltaCompactionOp(3b8e688f01604204bbbbfc745c640423) complete. Timing: real 0.193s	user 0.121s	sys 0.072s Metrics: {"cfile_cache_miss":632,"cfile_cache_miss_bytes":28877102,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":92,"lbm_read_time_us":12994,"lbm_reads_lt_1ms":672,"lbm_write_time_us":31886,"lbm_writes_lt_1ms":643,"mutex_wait_us":42,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":896,"update_count":3000}
I20260812 06:17:41.179433  6600 maintenance_manager.cc:419] P 36071023ed754f15a38af26ca86c8720: Scheduling FlushDeltaMemStoresOp(3b8e688f01604204bbbbfc745c640423): perf score=14.095187
I20260812 06:17:41.237347  6540 maintenance_manager.cc:643] P 36071023ed754f15a38af26ca86c8720: FlushDeltaMemStoresOp(3b8e688f01604204bbbbfc745c640423) complete. Timing: real 0.058s	user 0.024s	sys 0.031s Metrics: {"bytes_written":16409903,"delete_count":0,"lbm_write_time_us":29113,"lbm_writes_1-10_ms":2,"lbm_writes_lt_1ms":401,"reinsert_count":0,"update_count":2000}
I20260812 06:17:41.237928  6600 maintenance_manager.cc:419] P 36071023ed754f15a38af26ca86c8720: Scheduling FlushDeltaMemStoresOp(3b8e688f01604204bbbbfc745c640423): perf score=2.188937
I20260812 06:17:41.254181  6540 maintenance_manager.cc:643] P 36071023ed754f15a38af26ca86c8720: FlushDeltaMemStoresOp(3b8e688f01604204bbbbfc745c640423) complete. Timing: real 0.016s	user 0.007s	sys 0.007s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6333,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:41.254693  6600 maintenance_manager.cc:419] P 36071023ed754f15a38af26ca86c8720: Scheduling MajorDeltaCompactionOp(3b8e688f01604204bbbbfc745c640423): perf score=1.000000
I20260812 06:17:41.426337  6540 maintenance_manager.cc:643] P 36071023ed754f15a38af26ca86c8720: MajorDeltaCompactionOp(3b8e688f01604204bbbbfc745c640423) complete. Timing: real 0.171s	user 0.124s	sys 0.047s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774690,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":592,"lbm_read_time_us":12134,"lbm_reads_lt_1ms":572,"lbm_write_time_us":28752,"lbm_writes_lt_1ms":543,"mutex_wait_us":107,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":2304,"update_count":2500}
I20260812 06:17:41.426955  6600 maintenance_manager.cc:419] P 36071023ed754f15a38af26ca86c8720: Scheduling FlushDeltaMemStoresOp(3b8e688f01604204bbbbfc745c640423): perf score=14.095187
I20260812 06:17:41.483755  6540 maintenance_manager.cc:643] P 36071023ed754f15a38af26ca86c8720: FlushDeltaMemStoresOp(3b8e688f01604204bbbbfc745c640423) complete. Timing: real 0.057s	user 0.033s	sys 0.024s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":20734,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:17:41.484393  6600 maintenance_manager.cc:419] P 36071023ed754f15a38af26ca86c8720: Scheduling FlushDeltaMemStoresOp(3b8e688f01604204bbbbfc745c640423): perf score=2.188937
I20260812 06:17:41.501080  6540 maintenance_manager.cc:643] P 36071023ed754f15a38af26ca86c8720: FlushDeltaMemStoresOp(3b8e688f01604204bbbbfc745c640423) complete. Timing: real 0.016s	user 0.010s	sys 0.005s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6579,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:41.501531  6600 maintenance_manager.cc:419] P 36071023ed754f15a38af26ca86c8720: Scheduling MajorDeltaCompactionOp(3b8e688f01604204bbbbfc745c640423): perf score=1.000000
I20260812 06:17:41.691730  6540 maintenance_manager.cc:643] P 36071023ed754f15a38af26ca86c8720: MajorDeltaCompactionOp(3b8e688f01604204bbbbfc745c640423) complete. Timing: real 0.190s	user 0.118s	sys 0.063s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774688,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":555,"lbm_read_time_us":13801,"lbm_reads_lt_1ms":572,"lbm_write_time_us":30810,"lbm_writes_lt_1ms":543,"mutex_wait_us":270,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":17152,"update_count":2500}
I20260812 06:17:41.692379  6600 maintenance_manager.cc:419] P 36071023ed754f15a38af26ca86c8720: Scheduling FlushDeltaMemStoresOp(3b8e688f01604204bbbbfc745c640423): perf score=14.095187
I20260812 06:17:41.751211  6540 maintenance_manager.cc:643] P 36071023ed754f15a38af26ca86c8720: FlushDeltaMemStoresOp(3b8e688f01604204bbbbfc745c640423) complete. Timing: real 0.059s	user 0.024s	sys 0.031s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":20383,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:17:41.751961  6600 maintenance_manager.cc:419] P 36071023ed754f15a38af26ca86c8720: Scheduling FlushDeltaMemStoresOp(3b8e688f01604204bbbbfc745c640423): perf score=2.188937
I20260812 06:17:41.762200  6540 maintenance_manager.cc:643] P 36071023ed754f15a38af26ca86c8720: FlushDeltaMemStoresOp(3b8e688f01604204bbbbfc745c640423) complete. Timing: real 0.010s	user 0.008s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4065,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:41.762605  6600 maintenance_manager.cc:419] P 36071023ed754f15a38af26ca86c8720: Scheduling MajorDeltaCompactionOp(3b8e688f01604204bbbbfc745c640423): perf score=1.000000
I20260812 06:17:41.952052  6540 maintenance_manager.cc:643] P 36071023ed754f15a38af26ca86c8720: MajorDeltaCompactionOp(3b8e688f01604204bbbbfc745c640423) complete. Timing: real 0.189s	user 0.113s	sys 0.065s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774689,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":680,"lbm_read_time_us":12597,"lbm_reads_lt_1ms":572,"lbm_write_time_us":29464,"lbm_writes_lt_1ms":543,"mutex_wait_us":322,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":11520,"update_count":2500}
I20260812 06:17:41.952762  6600 maintenance_manager.cc:419] P 36071023ed754f15a38af26ca86c8720: Scheduling FlushDeltaMemStoresOp(3b8e688f01604204bbbbfc745c640423): perf score=14.095187
I20260812 06:17:42.000322  6540 maintenance_manager.cc:643] P 36071023ed754f15a38af26ca86c8720: FlushDeltaMemStoresOp(3b8e688f01604204bbbbfc745c640423) complete. Timing: real 0.047s	user 0.032s	sys 0.009s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":18476,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:17:42.000809  6600 maintenance_manager.cc:419] P 36071023ed754f15a38af26ca86c8720: Scheduling FlushDeltaMemStoresOp(3b8e688f01604204bbbbfc745c640423): perf score=2.188937
I20260812 06:17:42.012140  6540 maintenance_manager.cc:643] P 36071023ed754f15a38af26ca86c8720: FlushDeltaMemStoresOp(3b8e688f01604204bbbbfc745c640423) complete. Timing: real 0.011s	user 0.007s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4118,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:42.012790  6600 maintenance_manager.cc:419] P 36071023ed754f15a38af26ca86c8720: Scheduling FlushMRSOp(3b8e688f01604204bbbbfc745c640423): perf score=1.000000
I20260812 06:17:42.048991  6540 maintenance_manager.cc:643] P 36071023ed754f15a38af26ca86c8720: FlushMRSOp(3b8e688f01604204bbbbfc745c640423) complete. Timing: real 0.036s	user 0.022s	sys 0.009s Metrics: {"bytes_written":1152514,"cfile_init":1,"dirs.queue_time_us":70,"dirs.run_cpu_time_us":179,"dirs.run_wall_time_us":1063,"drs_written":1,"lbm_read_time_us":60,"lbm_reads_lt_1ms":4,"lbm_write_time_us":2131,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":28}
I20260812 06:17:42.049714  6600 maintenance_manager.cc:419] P 36071023ed754f15a38af26ca86c8720: Scheduling LogGCOp(3b8e688f01604204bbbbfc745c640423): free 112239265 bytes of WAL
I20260812 06:17:42.049961  6540 log_reader.cc:385] T 3b8e688f01604204bbbbfc745c640423: removed 11 log segments from log reader
I20260812 06:17:42.050032  6540 log.cc:1079] T 3b8e688f01604204bbbbfc745c640423 P 36071023ed754f15a38af26ca86c8720: Deleting log segment in path: /tmp/dist-test-taskeFMdIZ/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515453483730-6254-0/minicluster-data/ts-0-root/wals/3b8e688f01604204bbbbfc745c640423/wal-000000015 (ops 70-74)
I20260812 06:17:42.050088  6540 log.cc:1079] T 3b8e688f01604204bbbbfc745c640423 P 36071023ed754f15a38af26ca86c8720: Deleting log segment in path: /tmp/dist-test-taskeFMdIZ/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515453483730-6254-0/minicluster-data/ts-0-root/wals/3b8e688f01604204bbbbfc745c640423/wal-000000016 (ops 75-79)
I20260812 06:17:42.050146  6540 log.cc:1079] T 3b8e688f01604204bbbbfc745c640423 P 36071023ed754f15a38af26ca86c8720: Deleting log segment in path: /tmp/dist-test-taskeFMdIZ/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515453483730-6254-0/minicluster-data/ts-0-root/wals/3b8e688f01604204bbbbfc745c640423/wal-000000017 (ops 80-84)
I20260812 06:17:42.050191  6540 log.cc:1079] T 3b8e688f01604204bbbbfc745c640423 P 36071023ed754f15a38af26ca86c8720: Deleting log segment in path: /tmp/dist-test-taskeFMdIZ/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515453483730-6254-0/minicluster-data/ts-0-root/wals/3b8e688f01604204bbbbfc745c640423/wal-000000018 (ops 85-88)
I20260812 06:17:42.050232  6540 log.cc:1079] T 3b8e688f01604204bbbbfc745c640423 P 36071023ed754f15a38af26ca86c8720: Deleting log segment in path: /tmp/dist-test-taskeFMdIZ/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515453483730-6254-0/minicluster-data/ts-0-root/wals/3b8e688f01604204bbbbfc745c640423/wal-000000019 (ops 89-93)
I20260812 06:17:42.050271  6540 log.cc:1079] T 3b8e688f01604204bbbbfc745c640423 P 36071023ed754f15a38af26ca86c8720: Deleting log segment in path: /tmp/dist-test-taskeFMdIZ/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515453483730-6254-0/minicluster-data/ts-0-root/wals/3b8e688f01604204bbbbfc745c640423/wal-000000020 (ops 94-98)
I20260812 06:17:42.050310  6540 log.cc:1079] T 3b8e688f01604204bbbbfc745c640423 P 36071023ed754f15a38af26ca86c8720: Deleting log segment in path: /tmp/dist-test-taskeFMdIZ/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515453483730-6254-0/minicluster-data/ts-0-root/wals/3b8e688f01604204bbbbfc745c640423/wal-000000021 (ops 99-103)
I20260812 06:17:42.050349  6540 log.cc:1079] T 3b8e688f01604204bbbbfc745c640423 P 36071023ed754f15a38af26ca86c8720: Deleting log segment in path: /tmp/dist-test-taskeFMdIZ/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515453483730-6254-0/minicluster-data/ts-0-root/wals/3b8e688f01604204bbbbfc745c640423/wal-000000022 (ops 104-108)
I20260812 06:17:42.050388  6540 log.cc:1079] T 3b8e688f01604204bbbbfc745c640423 P 36071023ed754f15a38af26ca86c8720: Deleting log segment in path: /tmp/dist-test-taskeFMdIZ/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515453483730-6254-0/minicluster-data/ts-0-root/wals/3b8e688f01604204bbbbfc745c640423/wal-000000023 (ops 109-113)
I20260812 06:17:42.050426  6540 log.cc:1079] T 3b8e688f01604204bbbbfc745c640423 P 36071023ed754f15a38af26ca86c8720: Deleting log segment in path: /tmp/dist-test-taskeFMdIZ/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515453483730-6254-0/minicluster-data/ts-0-root/wals/3b8e688f01604204bbbbfc745c640423/wal-000000024 (ops 114-118)
I20260812 06:17:42.050468  6540 log.cc:1079] T 3b8e688f01604204bbbbfc745c640423 P 36071023ed754f15a38af26ca86c8720: Deleting log segment in path: /tmp/dist-test-taskeFMdIZ/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515453483730-6254-0/minicluster-data/ts-0-root/wals/3b8e688f01604204bbbbfc745c640423/wal-000000025 (ops 119-123)
I20260812 06:17:42.072084  6540 maintenance_manager.cc:643] P 36071023ed754f15a38af26ca86c8720: LogGCOp(3b8e688f01604204bbbbfc745c640423) complete. Timing: real 0.022s	user 0.000s	sys 0.022s Metrics: {}
I20260812 06:17:42.072525  6600 maintenance_manager.cc:419] P 36071023ed754f15a38af26ca86c8720: Scheduling UndoDeltaBlockGCOp(3b8e688f01604204bbbbfc745c640423): 447 bytes on disk
I20260812 06:17:42.073107  6540 maintenance_manager.cc:643] P 36071023ed754f15a38af26ca86c8720: UndoDeltaBlockGCOp(3b8e688f01604204bbbbfc745c640423) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":104,"lbm_reads_lt_1ms":4}
I20260812 06:17:42.073736  6600 maintenance_manager.cc:419] P 36071023ed754f15a38af26ca86c8720: Scheduling FlushDeltaMemStoresOp(3b8e688f01604204bbbbfc745c640423): perf score=2.188937
I20260812 06:17:42.096561  6540 maintenance_manager.cc:643] P 36071023ed754f15a38af26ca86c8720: FlushDeltaMemStoresOp(3b8e688f01604204bbbbfc745c640423) complete. Timing: real 0.023s	user 0.004s	sys 0.008s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":5224,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:42.096977  6600 maintenance_manager.cc:419] P 36071023ed754f15a38af26ca86c8720: Scheduling FlushDeltaMemStoresOp(3b8e688f01604204bbbbfc745c640423): perf score=2.188937
I20260812 06:17:42.106997  6540 maintenance_manager.cc:643] P 36071023ed754f15a38af26ca86c8720: FlushDeltaMemStoresOp(3b8e688f01604204bbbbfc745c640423) complete. Timing: real 0.010s	user 0.005s	sys 0.003s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3854,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:42.107432  6600 maintenance_manager.cc:419] P 36071023ed754f15a38af26ca86c8720: Scheduling MajorDeltaCompactionOp(3b8e688f01604204bbbbfc745c640423): perf score=1.000000
I20260812 06:17:42.346771  6540 maintenance_manager.cc:643] P 36071023ed754f15a38af26ca86c8720: MajorDeltaCompactionOp(3b8e688f01604204bbbbfc745c640423) complete. Timing: real 0.239s	user 0.169s	sys 0.063s Metrics: {"cfile_cache_miss":734,"cfile_cache_miss_bytes":32979749,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":1140,"lbm_read_time_us":15122,"lbm_reads_lt_1ms":774,"lbm_write_time_us":38167,"lbm_writes_lt_1ms":743,"mutex_wait_us":490,"peak_mem_usage":87969044,"reinsert_count":0,"spinlock_wait_cycles":12672,"thread_start_us":84,"threads_started":1,"update_count":3500}
I20260812 06:17:42.347517  6600 maintenance_manager.cc:419] P 36071023ed754f15a38af26ca86c8720: Scheduling FlushDeltaMemStoresOp(3b8e688f01604204bbbbfc745c640423): perf score=18.063937
I20260812 06:17:42.454651  6540 maintenance_manager.cc:643] P 36071023ed754f15a38af26ca86c8720: FlushDeltaMemStoresOp(3b8e688f01604204bbbbfc745c640423) complete. Timing: real 0.107s	user 0.038s	sys 0.015s Metrics: {"bytes_written":20512314,"delete_count":0,"lbm_write_time_us":74938,"lbm_writes_1-10_ms":1,"lbm_writes_10-100_ms":1,"lbm_writes_lt_1ms":501,"reinsert_count":0,"update_count":2500}
I20260812 06:17:42.455096  6600 maintenance_manager.cc:419] P 36071023ed754f15a38af26ca86c8720: Scheduling FlushDeltaMemStoresOp(3b8e688f01604204bbbbfc745c640423): perf score=3.181125
I20260812 06:17:42.477495  6540 maintenance_manager.cc:643] P 36071023ed754f15a38af26ca86c8720: FlushDeltaMemStoresOp(3b8e688f01604204bbbbfc745c640423) complete. Timing: real 0.022s	user 0.007s	sys 0.007s Metrics: {"bytes_written":4512903,"delete_count":0,"lbm_write_time_us":6264,"lbm_writes_lt_1ms":113,"reinsert_count":0,"update_count":550}
I20260812 06:17:42.477983  6600 maintenance_manager.cc:419] P 36071023ed754f15a38af26ca86c8720: Scheduling FlushDeltaMemStoresOp(3b8e688f01604204bbbbfc745c640423): perf score=2.188937
I20260812 06:17:42.491217  6540 maintenance_manager.cc:643] P 36071023ed754f15a38af26ca86c8720: FlushDeltaMemStoresOp(3b8e688f01604204bbbbfc745c640423) complete. Timing: real 0.013s	user 0.008s	sys 0.003s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":5059,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:17:42.491778  6600 maintenance_manager.cc:419] P 36071023ed754f15a38af26ca86c8720: Scheduling MajorDeltaCompactionOp(3b8e688f01604204bbbbfc745c640423): perf score=1.000000
I20260812 06:17:42.699800  6540 maintenance_manager.cc:643] P 36071023ed754f15a38af26ca86c8720: MajorDeltaCompactionOp(3b8e688f01604204bbbbfc745c640423) complete. Timing: real 0.208s	user 0.138s	sys 0.069s Metrics: {"cfile_cache_miss":733,"cfile_cache_miss_bytes":32979622,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":941,"lbm_read_time_us":14552,"lbm_reads_lt_1ms":773,"lbm_write_time_us":35861,"lbm_writes_lt_1ms":743,"mutex_wait_us":45,"peak_mem_usage":87969044,"reinsert_count":0,"spinlock_wait_cycles":1664,"update_count":3500}
I20260812 06:17:42.700465  6600 maintenance_manager.cc:419] P 36071023ed754f15a38af26ca86c8720: Scheduling FlushDeltaMemStoresOp(3b8e688f01604204bbbbfc745c640423): perf score=18.063937
I20260812 06:17:42.765089  6540 maintenance_manager.cc:643] P 36071023ed754f15a38af26ca86c8720: FlushDeltaMemStoresOp(3b8e688f01604204bbbbfc745c640423) complete. Timing: real 0.064s	user 0.047s	sys 0.016s Metrics: {"bytes_written":20512318,"delete_count":0,"lbm_write_time_us":28876,"lbm_writes_lt_1ms":503,"reinsert_count":0,"spinlock_wait_cycles":1792,"update_count":2500}
I20260812 06:17:42.765604  6600 maintenance_manager.cc:419] P 36071023ed754f15a38af26ca86c8720: Scheduling FlushDeltaMemStoresOp(3b8e688f01604204bbbbfc745c640423): perf score=2.188937
I20260812 06:17:42.782004  6540 maintenance_manager.cc:643] P 36071023ed754f15a38af26ca86c8720: FlushDeltaMemStoresOp(3b8e688f01604204bbbbfc745c640423) complete. Timing: real 0.016s	user 0.005s	sys 0.009s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6365,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:42.782541  6600 maintenance_manager.cc:419] P 36071023ed754f15a38af26ca86c8720: Scheduling MajorDeltaCompactionOp(3b8e688f01604204bbbbfc745c640423): perf score=1.000000
I20260812 06:17:42.948788  6540 maintenance_manager.cc:643] P 36071023ed754f15a38af26ca86c8720: MajorDeltaCompactionOp(3b8e688f01604204bbbbfc745c640423) complete. Timing: real 0.166s	user 0.133s	sys 0.033s Metrics: {"cfile_cache_miss":632,"cfile_cache_miss_bytes":28877105,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":150,"lbm_read_time_us":12891,"lbm_reads_lt_1ms":672,"lbm_write_time_us":35416,"lbm_writes_lt_1ms":643,"mutex_wait_us":24,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":17408,"update_count":3000}
I20260812 06:17:42.949525  6600 maintenance_manager.cc:419] P 36071023ed754f15a38af26ca86c8720: Scheduling FlushDeltaMemStoresOp(3b8e688f01604204bbbbfc745c640423): perf score=14.095187
I20260812 06:17:42.995584  6540 maintenance_manager.cc:643] P 36071023ed754f15a38af26ca86c8720: FlushDeltaMemStoresOp(3b8e688f01604204bbbbfc745c640423) complete. Timing: real 0.046s	user 0.025s	sys 0.016s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":19985,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:17:42.996150  6600 maintenance_manager.cc:419] P 36071023ed754f15a38af26ca86c8720: Scheduling FlushDeltaMemStoresOp(3b8e688f01604204bbbbfc745c640423): perf score=2.188937
I20260812 06:17:43.011896  6540 maintenance_manager.cc:643] P 36071023ed754f15a38af26ca86c8720: FlushDeltaMemStoresOp(3b8e688f01604204bbbbfc745c640423) complete. Timing: real 0.016s	user 0.003s	sys 0.012s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5787,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:43.012506  6600 maintenance_manager.cc:419] P 36071023ed754f15a38af26ca86c8720: Scheduling MajorDeltaCompactionOp(3b8e688f01604204bbbbfc745c640423): perf score=1.000000
I20260812 06:17:43.163362  6540 maintenance_manager.cc:643] P 36071023ed754f15a38af26ca86c8720: MajorDeltaCompactionOp(3b8e688f01604204bbbbfc745c640423) complete. Timing: real 0.151s	user 0.114s	sys 0.037s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774688,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":160,"lbm_read_time_us":10935,"lbm_reads_lt_1ms":572,"lbm_write_time_us":29235,"lbm_writes_lt_1ms":543,"mutex_wait_us":33,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":6016,"update_count":2500}
I20260812 06:17:43.164147  6600 maintenance_manager.cc:419] P 36071023ed754f15a38af26ca86c8720: Scheduling FlushDeltaMemStoresOp(3b8e688f01604204bbbbfc745c640423): perf score=10.126437
I20260812 06:17:43.197054  6540 maintenance_manager.cc:643] P 36071023ed754f15a38af26ca86c8720: FlushDeltaMemStoresOp(3b8e688f01604204bbbbfc745c640423) complete. Timing: real 0.033s	user 0.020s	sys 0.011s Metrics: {"bytes_written":12307492,"delete_count":0,"lbm_write_time_us":13945,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:17:43.197748  6600 maintenance_manager.cc:419] P 36071023ed754f15a38af26ca86c8720: Scheduling FlushDeltaMemStoresOp(3b8e688f01604204bbbbfc745c640423): perf score=2.188937
I20260812 06:17:43.216089  6540 maintenance_manager.cc:643] P 36071023ed754f15a38af26ca86c8720: FlushDeltaMemStoresOp(3b8e688f01604204bbbbfc745c640423) complete. Timing: real 0.018s	user 0.018s	sys 0.000s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":6959,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:43.216708  6600 maintenance_manager.cc:419] P 36071023ed754f15a38af26ca86c8720: Scheduling MajorDeltaCompactionOp(3b8e688f01604204bbbbfc745c640423): perf score=1.000000
I20260812 06:17:43.374262  6540 maintenance_manager.cc:643] P 36071023ed754f15a38af26ca86c8720: MajorDeltaCompactionOp(3b8e688f01604204bbbbfc745c640423) complete. Timing: real 0.157s	user 0.108s	sys 0.043s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672278,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":170,"lbm_read_time_us":10321,"lbm_reads_lt_1ms":472,"lbm_write_time_us":26283,"lbm_writes_lt_1ms":443,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":8576,"update_count":2000}
I20260812 06:17:43.374986  6600 maintenance_manager.cc:419] P 36071023ed754f15a38af26ca86c8720: Scheduling FlushDeltaMemStoresOp(3b8e688f01604204bbbbfc745c640423): perf score=11.118625
I20260812 06:17:43.412113  6540 maintenance_manager.cc:643] P 36071023ed754f15a38af26ca86c8720: FlushDeltaMemStoresOp(3b8e688f01604204bbbbfc745c640423) complete. Timing: real 0.037s	user 0.024s	sys 0.013s Metrics: {"bytes_written":12717736,"delete_count":0,"lbm_write_time_us":15156,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:17:43.412812  6600 maintenance_manager.cc:419] P 36071023ed754f15a38af26ca86c8720: Scheduling FlushDeltaMemStoresOp(3b8e688f01604204bbbbfc745c640423): perf score=2.188937
I20260812 06:17:43.427603  6540 maintenance_manager.cc:643] P 36071023ed754f15a38af26ca86c8720: FlushDeltaMemStoresOp(3b8e688f01604204bbbbfc745c640423) complete. Timing: real 0.015s	user 0.009s	sys 0.003s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":5598,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:17:43.428150  6600 maintenance_manager.cc:419] P 36071023ed754f15a38af26ca86c8720: Scheduling FlushMRSOp(3b8e688f01604204bbbbfc745c640423): perf score=1.000000
I20260812 06:17:43.479489  6540 maintenance_manager.cc:643] P 36071023ed754f15a38af26ca86c8720: FlushMRSOp(3b8e688f01604204bbbbfc745c640423) complete. Timing: real 0.051s	user 0.036s	sys 0.001s Metrics: {"bytes_written":1193505,"cfile_init":1,"dirs.queue_time_us":69,"dirs.run_cpu_time_us":233,"dirs.run_wall_time_us":1268,"drs_written":1,"lbm_read_time_us":45,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1561,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":29}
I20260812 06:17:43.480356  6600 maintenance_manager.cc:419] P 36071023ed754f15a38af26ca86c8720: Scheduling LogGCOp(3b8e688f01604204bbbbfc745c640423): free 112239581 bytes of WAL
I20260812 06:17:43.480605  6540 log_reader.cc:385] T 3b8e688f01604204bbbbfc745c640423: removed 11 log segments from log reader
I20260812 06:17:43.480656  6540 log.cc:1079] T 3b8e688f01604204bbbbfc745c640423 P 36071023ed754f15a38af26ca86c8720: Deleting log segment in path: /tmp/dist-test-taskeFMdIZ/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515453483730-6254-0/minicluster-data/ts-0-root/wals/3b8e688f01604204bbbbfc745c640423/wal-000000026 (ops 124-128)
I20260812 06:17:43.480685  6540 log.cc:1079] T 3b8e688f01604204bbbbfc745c640423 P 36071023ed754f15a38af26ca86c8720: Deleting log segment in path: /tmp/dist-test-taskeFMdIZ/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515453483730-6254-0/minicluster-data/ts-0-root/wals/3b8e688f01604204bbbbfc745c640423/wal-000000027 (ops 129-133)
I20260812 06:17:43.480806  6540 log.cc:1079] T 3b8e688f01604204bbbbfc745c640423 P 36071023ed754f15a38af26ca86c8720: Deleting log segment in path: /tmp/dist-test-taskeFMdIZ/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515453483730-6254-0/minicluster-data/ts-0-root/wals/3b8e688f01604204bbbbfc745c640423/wal-000000028 (ops 134-138)
I20260812 06:17:43.480854  6540 log.cc:1079] T 3b8e688f01604204bbbbfc745c640423 P 36071023ed754f15a38af26ca86c8720: Deleting log segment in path: /tmp/dist-test-taskeFMdIZ/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515453483730-6254-0/minicluster-data/ts-0-root/wals/3b8e688f01604204bbbbfc745c640423/wal-000000029 (ops 139-143)
I20260812 06:17:43.480873  6540 log.cc:1079] T 3b8e688f01604204bbbbfc745c640423 P 36071023ed754f15a38af26ca86c8720: Deleting log segment in path: /tmp/dist-test-taskeFMdIZ/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515453483730-6254-0/minicluster-data/ts-0-root/wals/3b8e688f01604204bbbbfc745c640423/wal-000000030 (ops 144-148)
I20260812 06:17:43.480929  6540 log.cc:1079] T 3b8e688f01604204bbbbfc745c640423 P 36071023ed754f15a38af26ca86c8720: Deleting log segment in path: /tmp/dist-test-taskeFMdIZ/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515453483730-6254-0/minicluster-data/ts-0-root/wals/3b8e688f01604204bbbbfc745c640423/wal-000000031 (ops 149-153)
I20260812 06:17:43.480970  6540 log.cc:1079] T 3b8e688f01604204bbbbfc745c640423 P 36071023ed754f15a38af26ca86c8720: Deleting log segment in path: /tmp/dist-test-taskeFMdIZ/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515453483730-6254-0/minicluster-data/ts-0-root/wals/3b8e688f01604204bbbbfc745c640423/wal-000000032 (ops 154-158)
I20260812 06:17:43.481009  6540 log.cc:1079] T 3b8e688f01604204bbbbfc745c640423 P 36071023ed754f15a38af26ca86c8720: Deleting log segment in path: /tmp/dist-test-taskeFMdIZ/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515453483730-6254-0/minicluster-data/ts-0-root/wals/3b8e688f01604204bbbbfc745c640423/wal-000000033 (ops 159-163)
I20260812 06:17:43.481096  6540 log.cc:1079] T 3b8e688f01604204bbbbfc745c640423 P 36071023ed754f15a38af26ca86c8720: Deleting log segment in path: /tmp/dist-test-taskeFMdIZ/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515453483730-6254-0/minicluster-data/ts-0-root/wals/3b8e688f01604204bbbbfc745c640423/wal-000000034 (ops 164-168)
I20260812 06:17:43.481159  6540 log.cc:1079] T 3b8e688f01604204bbbbfc745c640423 P 36071023ed754f15a38af26ca86c8720: Deleting log segment in path: /tmp/dist-test-taskeFMdIZ/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515453483730-6254-0/minicluster-data/ts-0-root/wals/3b8e688f01604204bbbbfc745c640423/wal-000000035 (ops 169-172)
I20260812 06:17:43.481199  6540 log.cc:1079] T 3b8e688f01604204bbbbfc745c640423 P 36071023ed754f15a38af26ca86c8720: Deleting log segment in path: /tmp/dist-test-taskeFMdIZ/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515453483730-6254-0/minicluster-data/ts-0-root/wals/3b8e688f01604204bbbbfc745c640423/wal-000000036 (ops 173-177)
I20260812 06:17:43.502018  6540 maintenance_manager.cc:643] P 36071023ed754f15a38af26ca86c8720: LogGCOp(3b8e688f01604204bbbbfc745c640423) complete. Timing: real 0.021s	user 0.000s	sys 0.019s Metrics: {}
I20260812 06:17:43.502430  6600 maintenance_manager.cc:419] P 36071023ed754f15a38af26ca86c8720: Scheduling UndoDeltaBlockGCOp(3b8e688f01604204bbbbfc745c640423): 463 bytes on disk
I20260812 06:17:43.502871  6540 maintenance_manager.cc:643] P 36071023ed754f15a38af26ca86c8720: UndoDeltaBlockGCOp(3b8e688f01604204bbbbfc745c640423) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":54,"lbm_reads_lt_1ms":4}
I20260812 06:17:43.503410  6600 maintenance_manager.cc:419] P 36071023ed754f15a38af26ca86c8720: Scheduling FlushDeltaMemStoresOp(3b8e688f01604204bbbbfc745c640423): perf score=6.157687
I20260812 06:17:43.529888  6540 maintenance_manager.cc:643] P 36071023ed754f15a38af26ca86c8720: FlushDeltaMemStoresOp(3b8e688f01604204bbbbfc745c640423) complete. Timing: real 0.026s	user 0.008s	sys 0.012s Metrics: {"bytes_written":8205078,"delete_count":0,"lbm_write_time_us":9917,"lbm_writes_lt_1ms":203,"reinsert_count":0,"update_count":1000}
I20260812 06:17:43.530622  6600 maintenance_manager.cc:419] P 36071023ed754f15a38af26ca86c8720: Scheduling LogGCOp(3b8e688f01604204bbbbfc745c640423): free 8767145 bytes of WAL
I20260812 06:17:43.530848  6540 log_reader.cc:385] T 3b8e688f01604204bbbbfc745c640423: removed 1 log segments from log reader
I20260812 06:17:43.530962  6540 log.cc:1079] T 3b8e688f01604204bbbbfc745c640423 P 36071023ed754f15a38af26ca86c8720: Deleting log segment in path: /tmp/dist-test-taskeFMdIZ/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515453483730-6254-0/minicluster-data/ts-0-root/wals/3b8e688f01604204bbbbfc745c640423/wal-000000037 (ops 178-182)
I20260812 06:17:43.533073  6540 maintenance_manager.cc:643] P 36071023ed754f15a38af26ca86c8720: LogGCOp(3b8e688f01604204bbbbfc745c640423) complete. Timing: real 0.002s	user 0.000s	sys 0.001s Metrics: {}
I20260812 06:17:43.533437  6600 maintenance_manager.cc:419] P 36071023ed754f15a38af26ca86c8720: Scheduling MajorDeltaCompactionOp(3b8e688f01604204bbbbfc745c640423): perf score=1.000000
I20260812 06:17:43.737326  6540 maintenance_manager.cc:643] P 36071023ed754f15a38af26ca86c8720: MajorDeltaCompactionOp(3b8e688f01604204bbbbfc745c640423) complete. Timing: real 0.204s	user 0.130s	sys 0.072s Metrics: {"cfile_cache_miss":633,"cfile_cache_miss_bytes":28877213,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":387,"lbm_read_time_us":14631,"lbm_reads_lt_1ms":665,"lbm_write_time_us":31971,"lbm_writes_lt_1ms":643,"mutex_wait_us":24,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":9344,"thread_start_us":80,"threads_started":1,"update_count":3000}
I20260812 06:17:43.738116  6600 maintenance_manager.cc:419] P 36071023ed754f15a38af26ca86c8720: Scheduling FlushDeltaMemStoresOp(3b8e688f01604204bbbbfc745c640423): perf score=18.063937
I20260812 06:17:43.806252  6540 maintenance_manager.cc:643] P 36071023ed754f15a38af26ca86c8720: FlushDeltaMemStoresOp(3b8e688f01604204bbbbfc745c640423) complete. Timing: real 0.068s	user 0.030s	sys 0.020s Metrics: {"bytes_written":20512315,"delete_count":0,"lbm_write_time_us":23990,"lbm_writes_lt_1ms":503,"reinsert_count":0,"update_count":2500}
I20260812 06:17:43.806792  6600 maintenance_manager.cc:419] P 36071023ed754f15a38af26ca86c8720: Scheduling FlushDeltaMemStoresOp(3b8e688f01604204bbbbfc745c640423): perf score=2.188937
I20260812 06:17:43.817225  6540 maintenance_manager.cc:643] P 36071023ed754f15a38af26ca86c8720: FlushDeltaMemStoresOp(3b8e688f01604204bbbbfc745c640423) complete. Timing: real 0.010s	user 0.008s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3881,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:43.817713  6600 maintenance_manager.cc:419] P 36071023ed754f15a38af26ca86c8720: Scheduling MajorDeltaCompactionOp(3b8e688f01604204bbbbfc745c640423): perf score=1.000000
I20260812 06:17:43.955744  6254 heavy-update-compaction-itest.cc:229] Time spent updating: real 4.853s	user 1.834s	sys 0.167s
I20260812 06:17:44.002768  6540 maintenance_manager.cc:643] P 36071023ed754f15a38af26ca86c8720: MajorDeltaCompactionOp(3b8e688f01604204bbbbfc745c640423) complete. Timing: real 0.185s	user 0.127s	sys 0.058s Metrics: {"cfile_cache_miss":632,"cfile_cache_miss_bytes":28877102,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":237,"lbm_read_time_us":13971,"lbm_reads_lt_1ms":668,"lbm_write_time_us":32346,"lbm_writes_lt_1ms":643,"mutex_wait_us":65,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":13824,"update_count":3000}
I20260812 06:17:44.003450  6600 maintenance_manager.cc:419] P 36071023ed754f15a38af26ca86c8720: Scheduling FlushDeltaMemStoresOp(3b8e688f01604204bbbbfc745c640423): perf score=10.126437
I20260812 06:17:44.013595  6254 heavy-update-compaction-itest.cc:265] Time spent scanning: real 0.057s	user 0.001s	sys 0.000s
I20260812 06:17:44.014096  6254 tablet_server.cc:179] TabletServer@127.6.27.129:0 shutting down...
I20260812 06:17:44.040969  6540 maintenance_manager.cc:643] P 36071023ed754f15a38af26ca86c8720: FlushDeltaMemStoresOp(3b8e688f01604204bbbbfc745c640423) complete. Timing: real 0.037s	user 0.025s	sys 0.011s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":13372,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:17:44.041563  6254 ts_tablet_manager.cc:1507] Shutting down tablet manager...
I20260812 06:17:44.041810  6254 tablet_replica.cc:333] T 3b8e688f01604204bbbbfc745c640423 P 36071023ed754f15a38af26ca86c8720: stopping tablet replica
I20260812 06:17:44.041973  6254 raft_consensus.cc:2243] T 3b8e688f01604204bbbbfc745c640423 P 36071023ed754f15a38af26ca86c8720 [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:17:44.042130  6254 raft_consensus.cc:2272] T 3b8e688f01604204bbbbfc745c640423 P 36071023ed754f15a38af26ca86c8720 [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:17:44.045586  6254 tablet_server.cc:196] TabletServer@127.6.27.129:0 shutdown complete.
I20260812 06:17:44.056635  6254 master.cc:562] Master@127.6.27.190:37505 shutting down...
I20260812 06:17:44.060352  6254 raft_consensus.cc:2243] T 00000000000000000000000000000000 P e11c6b1e0a1b41b5bd58750d5bad0e71 [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:17:44.060523  6254 raft_consensus.cc:2272] T 00000000000000000000000000000000 P e11c6b1e0a1b41b5bd58750d5bad0e71 [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:17:44.060565  6254 tablet_replica.cc:333] T 00000000000000000000000000000000 P e11c6b1e0a1b41b5bd58750d5bad0e71: stopping tablet replica
I20260812 06:17:44.072633  6254 master.cc:584] Master@127.6.27.190:37505 shutdown complete.
[       OK ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/1 (5301 ms)
[----------] 2 tests from EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy (10665 ms total)

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