[==========] 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:15.669322 24703 internal_mini_cluster.cc:156] Creating distributed mini masters. Addrs: 127.24.31.254:46441
I20260812 06:17:15.670269 24703 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:15.670814 24703 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:17:15.677464 24708 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:15.677552 24703 server_base.cc:1061] running on GCE node
W20260812 06:17:15.677500 24714 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:15.677786 24709 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:15.678416 24703 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:17:15.678517 24703 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:15.678579 24703 hybrid_clock.cc:648] HybridClock initialized: now 1786515435678576 us; error 0 us; skew 500 ppm
I20260812 06:17:15.680451 24703 webserver.cc:533] Webserver started at http://127.24.31.254:36667/ using document root <none> and password file <none>
I20260812 06:17:15.681013 24703 fs_manager.cc:362] Metadata directory not provided
I20260812 06:17:15.681082 24703 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:17:15.681324 24703 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:17:15.683190 24703 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskULGn6B/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515435658806-24703-0/minicluster-data/master-0-root/instance:
uuid: "f7aa4811d30d4863b06dc8d1bfbab979"
format_stamp: "Formatted at 2026-08-12 06:17:15 on dist-test-slave-7nm7"
I20260812 06:17:15.686820 24703 fs_manager.cc:696] Time spent creating directory manager: real 0.003s	user 0.004s	sys 0.000s
I20260812 06:17:15.688947 24722 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:15.689981 24703 fs_manager.cc:730] Time spent opening block manager: real 0.002s	user 0.002s	sys 0.000s
I20260812 06:17:15.690143 24703 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskULGn6B/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515435658806-24703-0/minicluster-data/master-0-root
uuid: "f7aa4811d30d4863b06dc8d1bfbab979"
format_stamp: "Formatted at 2026-08-12 06:17:15 on dist-test-slave-7nm7"
I20260812 06:17:15.690279 24703 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskULGn6B/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515435658806-24703-0/minicluster-data/master-0-root
metadata directory: /tmp/dist-test-taskULGn6B/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515435658806-24703-0/minicluster-data/master-0-root
1 data directories: /tmp/dist-test-taskULGn6B/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515435658806-24703-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:15.704341 24703 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:17:15.705015 24703 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:15.705262 24703 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:17:15.713050 24703 rpc_server.cc:307] RPC server started. Bound to: 127.24.31.254:46441
I20260812 06:17:15.713238 24814 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.24.31.254:46441 every 8 connection(s)
I20260812 06:17:15.715384 24817 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:15.721050 24817 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P f7aa4811d30d4863b06dc8d1bfbab979: Bootstrap starting.
I20260812 06:17:15.723598 24817 tablet_bootstrap.cc:654] T 00000000000000000000000000000000 P f7aa4811d30d4863b06dc8d1bfbab979: Neither blocks nor log segments found. Creating new log.
I20260812 06:17:15.724524 24817 log.cc:826] T 00000000000000000000000000000000 P f7aa4811d30d4863b06dc8d1bfbab979: Log is configured to *not* fsync() on all Append() calls
I20260812 06:17:15.726388 24817 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P f7aa4811d30d4863b06dc8d1bfbab979: No bootstrap required, opened a new log
I20260812 06:17:15.729142 24817 raft_consensus.cc:359] T 00000000000000000000000000000000 P f7aa4811d30d4863b06dc8d1bfbab979 [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "f7aa4811d30d4863b06dc8d1bfbab979" member_type: VOTER }
I20260812 06:17:15.729306 24817 raft_consensus.cc:385] T 00000000000000000000000000000000 P f7aa4811d30d4863b06dc8d1bfbab979 [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:17:15.729383 24817 raft_consensus.cc:740] T 00000000000000000000000000000000 P f7aa4811d30d4863b06dc8d1bfbab979 [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: f7aa4811d30d4863b06dc8d1bfbab979, State: Initialized, Role: FOLLOWER
I20260812 06:17:15.730002 24817 consensus_queue.cc:260] T 00000000000000000000000000000000 P f7aa4811d30d4863b06dc8d1bfbab979 [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: "f7aa4811d30d4863b06dc8d1bfbab979" member_type: VOTER }
I20260812 06:17:15.730141 24817 raft_consensus.cc:399] T 00000000000000000000000000000000 P f7aa4811d30d4863b06dc8d1bfbab979 [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:17:15.730261 24817 raft_consensus.cc:493] T 00000000000000000000000000000000 P f7aa4811d30d4863b06dc8d1bfbab979 [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:17:15.730422 24817 raft_consensus.cc:3060] T 00000000000000000000000000000000 P f7aa4811d30d4863b06dc8d1bfbab979 [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:17:15.731233 24817 raft_consensus.cc:515] T 00000000000000000000000000000000 P f7aa4811d30d4863b06dc8d1bfbab979 [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "f7aa4811d30d4863b06dc8d1bfbab979" member_type: VOTER }
I20260812 06:17:15.731669 24817 leader_election.cc:304] T 00000000000000000000000000000000 P f7aa4811d30d4863b06dc8d1bfbab979 [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: f7aa4811d30d4863b06dc8d1bfbab979; no voters: 
I20260812 06:17:15.732017 24817 leader_election.cc:290] T 00000000000000000000000000000000 P f7aa4811d30d4863b06dc8d1bfbab979 [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:17:15.732161 24822 raft_consensus.cc:2804] T 00000000000000000000000000000000 P f7aa4811d30d4863b06dc8d1bfbab979 [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:17:15.732412 24822 raft_consensus.cc:697] T 00000000000000000000000000000000 P f7aa4811d30d4863b06dc8d1bfbab979 [term 1 LEADER]: Becoming Leader. State: Replica: f7aa4811d30d4863b06dc8d1bfbab979, State: Running, Role: LEADER
I20260812 06:17:15.732827 24822 consensus_queue.cc:237] T 00000000000000000000000000000000 P f7aa4811d30d4863b06dc8d1bfbab979 [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: "f7aa4811d30d4863b06dc8d1bfbab979" member_type: VOTER }
I20260812 06:17:15.733083 24817 sys_catalog.cc:565] T 00000000000000000000000000000000 P f7aa4811d30d4863b06dc8d1bfbab979 [sys.catalog]: configured and running, proceeding with master startup.
I20260812 06:17:15.734705 24823 sys_catalog.cc:455] T 00000000000000000000000000000000 P f7aa4811d30d4863b06dc8d1bfbab979 [sys.catalog]: SysCatalogTable state changed. Reason: RaftConsensus started. Latest consensus state: current_term: 1 leader_uuid: "f7aa4811d30d4863b06dc8d1bfbab979" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "f7aa4811d30d4863b06dc8d1bfbab979" member_type: VOTER } }
I20260812 06:17:15.734753 24824 sys_catalog.cc:455] T 00000000000000000000000000000000 P f7aa4811d30d4863b06dc8d1bfbab979 [sys.catalog]: SysCatalogTable state changed. Reason: New leader f7aa4811d30d4863b06dc8d1bfbab979. Latest consensus state: current_term: 1 leader_uuid: "f7aa4811d30d4863b06dc8d1bfbab979" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "f7aa4811d30d4863b06dc8d1bfbab979" member_type: VOTER } }
I20260812 06:17:15.734831 24823 sys_catalog.cc:458] T 00000000000000000000000000000000 P f7aa4811d30d4863b06dc8d1bfbab979 [sys.catalog]: This master's current role is: LEADER
I20260812 06:17:15.734844 24824 sys_catalog.cc:458] T 00000000000000000000000000000000 P f7aa4811d30d4863b06dc8d1bfbab979 [sys.catalog]: This master's current role is: LEADER
I20260812 06:17:15.735165 24835 catalog_manager.cc:1511] Loading table and tablet metadata into memory...
I20260812 06:17:15.735523 24703 internal_mini_cluster.cc:184] Waiting to initialize catalog manager on master 0
I20260812 06:17:15.737351 24835 catalog_manager.cc:1520] Initializing Kudu cluster ID...
I20260812 06:17:15.742368 24835 catalog_manager.cc:1383] Generated new cluster ID: 4ed525db7805497ea9c1a3407fad31f6
I20260812 06:17:15.742456 24835 catalog_manager.cc:1531] Initializing Kudu internal certificate authority...
I20260812 06:17:15.757097 24835 catalog_manager.cc:1406] Generated new certificate authority record
I20260812 06:17:15.757963 24835 catalog_manager.cc:1540] Loading token signing keys...
I20260812 06:17:15.775847 24835 catalog_manager.cc:6092] T 00000000000000000000000000000000 P f7aa4811d30d4863b06dc8d1bfbab979: Generated new TSK 0
I20260812 06:17:15.776614 24835 catalog_manager.cc:1550] Initializing in-progress tserver states...
I20260812 06:17:15.800963 24703 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:17:15.803819 24849 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:15.803946 24854 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:15.804108 24851 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:15.804276 24703 server_base.cc:1061] running on GCE node
I20260812 06:17:15.804534 24703 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:17:15.804600 24703 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:15.804628 24703 hybrid_clock.cc:648] HybridClock initialized: now 1786515435804627 us; error 0 us; skew 500 ppm
I20260812 06:17:15.805648 24703 webserver.cc:533] Webserver started at http://127.24.31.193:43133/ using document root <none> and password file <none>
I20260812 06:17:15.805848 24703 fs_manager.cc:362] Metadata directory not provided
I20260812 06:17:15.805924 24703 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:17:15.806006 24703 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:17:15.806512 24703 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskULGn6B/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515435658806-24703-0/minicluster-data/ts-0-root/instance:
uuid: "9434c5b6d7f445b486a135481139f5c9"
format_stamp: "Formatted at 2026-08-12 06:17:15 on dist-test-slave-7nm7"
I20260812 06:17:15.808112 24703 fs_manager.cc:696] Time spent creating directory manager: real 0.001s	user 0.000s	sys 0.002s
I20260812 06:17:15.809167 24860 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:15.809422 24703 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.000s	sys 0.001s
I20260812 06:17:15.809497 24703 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskULGn6B/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515435658806-24703-0/minicluster-data/ts-0-root
uuid: "9434c5b6d7f445b486a135481139f5c9"
format_stamp: "Formatted at 2026-08-12 06:17:15 on dist-test-slave-7nm7"
I20260812 06:17:15.809590 24703 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskULGn6B/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515435658806-24703-0/minicluster-data/ts-0-root
metadata directory: /tmp/dist-test-taskULGn6B/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515435658806-24703-0/minicluster-data/ts-0-root
1 data directories: /tmp/dist-test-taskULGn6B/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515435658806-24703-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:15.823967 24703 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:17:15.824429 24703 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:17:15.824932 24703 txn_system_client.cc:432] TxnSystemClient initialization is disabled...
I20260812 06:17:15.826063 24703 ts_tablet_manager.cc:585] Loaded tablet metadata (0 total tablets, 0 live tablets)
I20260812 06:17:15.826115 24703 ts_tablet_manager.cc:531] Time spent load tablet metadata: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:17:15.826186 24703 ts_tablet_manager.cc:616] Registered 0 tablets
I20260812 06:17:15.826270 24703 ts_tablet_manager.cc:595] Time spent register tablets: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:17:15.833101 24703 rpc_server.cc:307] RPC server started. Bound to: 127.24.31.193:36819
I20260812 06:17:15.833137 24972 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.24.31.193:36819 every 8 connection(s)
I20260812 06:17:15.848662 24975 heartbeater.cc:344] Connected to a master server at 127.24.31.254:46441
I20260812 06:17:15.848954 24975 heartbeater.cc:461] Registering TS with master...
I20260812 06:17:15.849678 24975 heartbeater.cc:507] Master 127.24.31.254:46441 requested a full tablet report, sending...
I20260812 06:17:15.851361 24754 ts_manager.cc:194] Registered new tserver with Master: 9434c5b6d7f445b486a135481139f5c9 (127.24.31.193:36819)
I20260812 06:17:15.851701 24703 internal_mini_cluster.cc:371] 1 TS(s) registered with all masters after 0.017935843s
I20260812 06:17:15.852669 24754 master_service.cc:502] Signed X509 certificate for tserver {username='slave'} at 127.0.0.1:60074
I20260812 06:17:15.862188 24754 catalog_manager.cc:2283] Servicing CreateTable request from {username='slave'} at 127.0.0.1:60088:
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:15.877380 24903 tablet_service.cc:1511] Processing CreateTablet for tablet e13e0daac18e46eaa59be223431b0896 (DEFAULT_TABLE table=heavy-update-compaction-test [id=4ebbe976d25f4f7a8a331a656644e87c]), partition=
I20260812 06:17:15.877861 24903 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet e13e0daac18e46eaa59be223431b0896. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:17:15.880292 25000 tablet_bootstrap.cc:492] T e13e0daac18e46eaa59be223431b0896 P 9434c5b6d7f445b486a135481139f5c9: Bootstrap starting.
I20260812 06:17:15.881600 25000 tablet_bootstrap.cc:654] T e13e0daac18e46eaa59be223431b0896 P 9434c5b6d7f445b486a135481139f5c9: Neither blocks nor log segments found. Creating new log.
I20260812 06:17:15.882799 25000 tablet_bootstrap.cc:492] T e13e0daac18e46eaa59be223431b0896 P 9434c5b6d7f445b486a135481139f5c9: No bootstrap required, opened a new log
I20260812 06:17:15.882882 25000 ts_tablet_manager.cc:1403] T e13e0daac18e46eaa59be223431b0896 P 9434c5b6d7f445b486a135481139f5c9: Time spent bootstrapping tablet: real 0.003s	user 0.002s	sys 0.000s
I20260812 06:17:15.883373 25000 raft_consensus.cc:359] T e13e0daac18e46eaa59be223431b0896 P 9434c5b6d7f445b486a135481139f5c9 [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "9434c5b6d7f445b486a135481139f5c9" member_type: VOTER last_known_addr { host: "127.24.31.193" port: 36819 } }
I20260812 06:17:15.883472 25000 raft_consensus.cc:385] T e13e0daac18e46eaa59be223431b0896 P 9434c5b6d7f445b486a135481139f5c9 [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:17:15.883495 25000 raft_consensus.cc:740] T e13e0daac18e46eaa59be223431b0896 P 9434c5b6d7f445b486a135481139f5c9 [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: 9434c5b6d7f445b486a135481139f5c9, State: Initialized, Role: FOLLOWER
I20260812 06:17:15.883664 25000 consensus_queue.cc:260] T e13e0daac18e46eaa59be223431b0896 P 9434c5b6d7f445b486a135481139f5c9 [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: "9434c5b6d7f445b486a135481139f5c9" member_type: VOTER last_known_addr { host: "127.24.31.193" port: 36819 } }
I20260812 06:17:15.883751 25000 raft_consensus.cc:399] T e13e0daac18e46eaa59be223431b0896 P 9434c5b6d7f445b486a135481139f5c9 [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:17:15.883780 25000 raft_consensus.cc:493] T e13e0daac18e46eaa59be223431b0896 P 9434c5b6d7f445b486a135481139f5c9 [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:17:15.883854 25000 raft_consensus.cc:3060] T e13e0daac18e46eaa59be223431b0896 P 9434c5b6d7f445b486a135481139f5c9 [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:17:15.884760 25000 raft_consensus.cc:515] T e13e0daac18e46eaa59be223431b0896 P 9434c5b6d7f445b486a135481139f5c9 [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "9434c5b6d7f445b486a135481139f5c9" member_type: VOTER last_known_addr { host: "127.24.31.193" port: 36819 } }
I20260812 06:17:15.884899 25000 leader_election.cc:304] T e13e0daac18e46eaa59be223431b0896 P 9434c5b6d7f445b486a135481139f5c9 [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: 9434c5b6d7f445b486a135481139f5c9; no voters: 
I20260812 06:17:15.885170 25000 leader_election.cc:290] T e13e0daac18e46eaa59be223431b0896 P 9434c5b6d7f445b486a135481139f5c9 [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:17:15.885260 25007 raft_consensus.cc:2804] T e13e0daac18e46eaa59be223431b0896 P 9434c5b6d7f445b486a135481139f5c9 [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:17:15.885432 25007 raft_consensus.cc:697] T e13e0daac18e46eaa59be223431b0896 P 9434c5b6d7f445b486a135481139f5c9 [term 1 LEADER]: Becoming Leader. State: Replica: 9434c5b6d7f445b486a135481139f5c9, State: Running, Role: LEADER
I20260812 06:17:15.885547 25000 ts_tablet_manager.cc:1434] T e13e0daac18e46eaa59be223431b0896 P 9434c5b6d7f445b486a135481139f5c9: Time spent starting tablet: real 0.003s	user 0.003s	sys 0.000s
I20260812 06:17:15.885656 25007 consensus_queue.cc:237] T e13e0daac18e46eaa59be223431b0896 P 9434c5b6d7f445b486a135481139f5c9 [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: "9434c5b6d7f445b486a135481139f5c9" member_type: VOTER last_known_addr { host: "127.24.31.193" port: 36819 } }
I20260812 06:17:15.885844 24975 heartbeater.cc:499] Master 127.24.31.254:46441 was elected leader, sending a full tablet report...
I20260812 06:17:15.888454 24754 catalog_manager.cc:5719] T e13e0daac18e46eaa59be223431b0896 P 9434c5b6d7f445b486a135481139f5c9 reported cstate change: term changed from 0 to 1, leader changed from <none> to 9434c5b6d7f445b486a135481139f5c9 (127.24.31.193). New cstate: current_term: 1 leader_uuid: "9434c5b6d7f445b486a135481139f5c9" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "9434c5b6d7f445b486a135481139f5c9" member_type: VOTER last_known_addr { host: "127.24.31.193" port: 36819 } health_report { overall_health: HEALTHY } } }
I20260812 06:17:15.959499 24703 heavy-update-compaction-itest.cc:215] Time spent inserting: real 0.061s	user 0.023s	sys 0.008s
I20260812 06:17:16.084379 24977 maintenance_manager.cc:419] P 9434c5b6d7f445b486a135481139f5c9: Scheduling FlushMRSOp(e13e0daac18e46eaa59be223431b0896): perf score=15.086190
I20260812 06:17:16.252658 24865 maintenance_manager.cc:643] P 9434c5b6d7f445b486a135481139f5c9: FlushMRSOp(e13e0daac18e46eaa59be223431b0896) complete. Timing: real 0.168s	user 0.109s	sys 0.044s Metrics: {"bytes_written":12307491,"cfile_init":1,"compiler_manager_pool.queue_time_us":628,"delete_count":0,"dirs.queue_time_us":72,"dirs.run_cpu_time_us":214,"dirs.run_wall_time_us":745,"drs_written":1,"lbm_read_time_us":102,"lbm_reads_lt_1ms":4,"lbm_write_time_us":39150,"lbm_writes_lt_1ms":657,"peak_mem_usage":0,"reinsert_count":0,"rows_written":103,"thread_start_us":144,"threads_started":1,"update_count":1500}
I20260812 06:17:16.254105 24977 maintenance_manager.cc:419] P 9434c5b6d7f445b486a135481139f5c9: Scheduling LogGCOp(e13e0daac18e46eaa59be223431b0896): free 8725963 bytes of WAL
I20260812 06:17:16.254459 24865 log_reader.cc:385] T e13e0daac18e46eaa59be223431b0896: removed 1 log segments from log reader
I20260812 06:17:16.254539 24865 log.cc:1079] T e13e0daac18e46eaa59be223431b0896 P 9434c5b6d7f445b486a135481139f5c9: Deleting log segment in path: /tmp/dist-test-taskULGn6B/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515435658806-24703-0/minicluster-data/ts-0-root/wals/e13e0daac18e46eaa59be223431b0896/wal-000000001 (ops 1-6)
I20260812 06:17:16.257257 24865 maintenance_manager.cc:643] P 9434c5b6d7f445b486a135481139f5c9: LogGCOp(e13e0daac18e46eaa59be223431b0896) complete. Timing: real 0.003s	user 0.000s	sys 0.000s Metrics: {}
I20260812 06:17:16.257588 24977 maintenance_manager.cc:419] P 9434c5b6d7f445b486a135481139f5c9: Scheduling FlushDeltaMemStoresOp(e13e0daac18e46eaa59be223431b0896): perf score=2.188937
I20260812 06:17:16.276713 24865 maintenance_manager.cc:643] P 9434c5b6d7f445b486a135481139f5c9: FlushDeltaMemStoresOp(e13e0daac18e46eaa59be223431b0896) complete. Timing: real 0.019s	user 0.001s	sys 0.013s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5987,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:16.277351 24977 maintenance_manager.cc:419] P 9434c5b6d7f445b486a135481139f5c9: Scheduling UndoDeltaBlockGCOp(e13e0daac18e46eaa59be223431b0896): 12308958 bytes on disk
I20260812 06:17:16.277971 24865 maintenance_manager.cc:643] P 9434c5b6d7f445b486a135481139f5c9: UndoDeltaBlockGCOp(e13e0daac18e46eaa59be223431b0896) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":55,"lbm_reads_lt_1ms":4}
I20260812 06:17:16.278488 24977 maintenance_manager.cc:419] P 9434c5b6d7f445b486a135481139f5c9: Scheduling MajorDeltaCompactionOp(e13e0daac18e46eaa59be223431b0896): perf score=1.000000
I20260812 06:17:16.411072 24865 maintenance_manager.cc:643] P 9434c5b6d7f445b486a135481139f5c9: MajorDeltaCompactionOp(e13e0daac18e46eaa59be223431b0896) complete. Timing: real 0.132s	user 0.084s	sys 0.049s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20631313,"cfile_init":7,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":530,"lbm_read_time_us":10343,"lbm_reads_lt_1ms":460,"lbm_write_time_us":26930,"lbm_writes_lt_1ms":443,"mutex_wait_us":20,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":17664,"thread_start_us":320,"threads_started":5,"update_count":2000}
I20260812 06:17:16.411633 24977 maintenance_manager.cc:419] P 9434c5b6d7f445b486a135481139f5c9: Scheduling FlushDeltaMemStoresOp(e13e0daac18e46eaa59be223431b0896): perf score=10.126437
I20260812 06:17:16.450490 24865 maintenance_manager.cc:643] P 9434c5b6d7f445b486a135481139f5c9: FlushDeltaMemStoresOp(e13e0daac18e46eaa59be223431b0896) complete. Timing: real 0.039s	user 0.021s	sys 0.017s Metrics: {"bytes_written":12307491,"delete_count":0,"lbm_write_time_us":16921,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:17:16.450963 24977 maintenance_manager.cc:419] P 9434c5b6d7f445b486a135481139f5c9: Scheduling FlushDeltaMemStoresOp(e13e0daac18e46eaa59be223431b0896): perf score=2.188937
I20260812 06:17:16.468505 24865 maintenance_manager.cc:643] P 9434c5b6d7f445b486a135481139f5c9: FlushDeltaMemStoresOp(e13e0daac18e46eaa59be223431b0896) complete. Timing: real 0.017s	user 0.006s	sys 0.007s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6402,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:16.469110 24977 maintenance_manager.cc:419] P 9434c5b6d7f445b486a135481139f5c9: Scheduling MajorDeltaCompactionOp(e13e0daac18e46eaa59be223431b0896): perf score=1.000000
I20260812 06:17:16.595881 24865 maintenance_manager.cc:643] P 9434c5b6d7f445b486a135481139f5c9: MajorDeltaCompactionOp(e13e0daac18e46eaa59be223431b0896) complete. Timing: real 0.127s	user 0.088s	sys 0.038s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20631313,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":350,"lbm_read_time_us":9320,"lbm_reads_lt_1ms":468,"lbm_write_time_us":27013,"lbm_writes_lt_1ms":443,"mutex_wait_us":40,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":1792,"update_count":2000}
I20260812 06:17:16.596509 24977 maintenance_manager.cc:419] P 9434c5b6d7f445b486a135481139f5c9: Scheduling FlushDeltaMemStoresOp(e13e0daac18e46eaa59be223431b0896): perf score=10.126437
I20260812 06:17:16.644702 24865 maintenance_manager.cc:643] P 9434c5b6d7f445b486a135481139f5c9: FlushDeltaMemStoresOp(e13e0daac18e46eaa59be223431b0896) complete. Timing: real 0.048s	user 0.032s	sys 0.008s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":18691,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:17:16.645202 24977 maintenance_manager.cc:419] P 9434c5b6d7f445b486a135481139f5c9: Scheduling FlushDeltaMemStoresOp(e13e0daac18e46eaa59be223431b0896): perf score=2.188937
I20260812 06:17:16.656266 24865 maintenance_manager.cc:643] P 9434c5b6d7f445b486a135481139f5c9: FlushDeltaMemStoresOp(e13e0daac18e46eaa59be223431b0896) complete. Timing: real 0.011s	user 0.009s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4330,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:16.656775 24977 maintenance_manager.cc:419] P 9434c5b6d7f445b486a135481139f5c9: Scheduling MajorDeltaCompactionOp(e13e0daac18e46eaa59be223431b0896): perf score=1.000000
I20260812 06:17:16.790957 24865 maintenance_manager.cc:643] P 9434c5b6d7f445b486a135481139f5c9: MajorDeltaCompactionOp(e13e0daac18e46eaa59be223431b0896) complete. Timing: real 0.134s	user 0.114s	sys 0.019s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20631312,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":213,"lbm_read_time_us":10576,"lbm_reads_lt_1ms":472,"lbm_write_time_us":27748,"lbm_writes_lt_1ms":443,"mutex_wait_us":91,"peak_mem_usage":50689328,"reinsert_count":0,"update_count":2000}
I20260812 06:17:16.791730 24977 maintenance_manager.cc:419] P 9434c5b6d7f445b486a135481139f5c9: Scheduling FlushDeltaMemStoresOp(e13e0daac18e46eaa59be223431b0896): perf score=10.126437
I20260812 06:17:16.846216 24865 maintenance_manager.cc:643] P 9434c5b6d7f445b486a135481139f5c9: FlushDeltaMemStoresOp(e13e0daac18e46eaa59be223431b0896) complete. Timing: real 0.054s	user 0.030s	sys 0.019s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":19926,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:17:16.846766 24977 maintenance_manager.cc:419] P 9434c5b6d7f445b486a135481139f5c9: Scheduling FlushDeltaMemStoresOp(e13e0daac18e46eaa59be223431b0896): perf score=2.188937
I20260812 06:17:16.864207 24865 maintenance_manager.cc:643] P 9434c5b6d7f445b486a135481139f5c9: FlushDeltaMemStoresOp(e13e0daac18e46eaa59be223431b0896) complete. Timing: real 0.017s	user 0.006s	sys 0.009s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6545,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:16.864884 24977 maintenance_manager.cc:419] P 9434c5b6d7f445b486a135481139f5c9: Scheduling MajorDeltaCompactionOp(e13e0daac18e46eaa59be223431b0896): perf score=1.000000
I20260812 06:17:17.025962 24865 maintenance_manager.cc:643] P 9434c5b6d7f445b486a135481139f5c9: MajorDeltaCompactionOp(e13e0daac18e46eaa59be223431b0896) complete. Timing: real 0.161s	user 0.128s	sys 0.032s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20631312,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":2000,"lbm_read_time_us":14017,"lbm_reads_lt_1ms":472,"lbm_write_time_us":25304,"lbm_writes_lt_1ms":443,"mutex_wait_us":638,"peak_mem_usage":50689328,"reinsert_count":0,"update_count":2000}
I20260812 06:17:17.026870 24977 maintenance_manager.cc:419] P 9434c5b6d7f445b486a135481139f5c9: Scheduling FlushDeltaMemStoresOp(e13e0daac18e46eaa59be223431b0896): perf score=10.126437
I20260812 06:17:17.075223 24865 maintenance_manager.cc:643] P 9434c5b6d7f445b486a135481139f5c9: FlushDeltaMemStoresOp(e13e0daac18e46eaa59be223431b0896) complete. Timing: real 0.048s	user 0.014s	sys 0.030s Metrics: {"bytes_written":12307491,"delete_count":0,"lbm_write_time_us":21880,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":302,"reinsert_count":0,"update_count":1500}
I20260812 06:17:17.075702 24977 maintenance_manager.cc:419] P 9434c5b6d7f445b486a135481139f5c9: Scheduling FlushDeltaMemStoresOp(e13e0daac18e46eaa59be223431b0896): perf score=2.188937
I20260812 06:17:17.088086 24865 maintenance_manager.cc:643] P 9434c5b6d7f445b486a135481139f5c9: FlushDeltaMemStoresOp(e13e0daac18e46eaa59be223431b0896) complete. Timing: real 0.012s	user 0.006s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4854,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:17.088780 24977 maintenance_manager.cc:419] P 9434c5b6d7f445b486a135481139f5c9: Scheduling MajorDeltaCompactionOp(e13e0daac18e46eaa59be223431b0896): perf score=1.000000
I20260812 06:17:17.216781 24865 maintenance_manager.cc:643] P 9434c5b6d7f445b486a135481139f5c9: MajorDeltaCompactionOp(e13e0daac18e46eaa59be223431b0896) complete. Timing: real 0.128s	user 0.100s	sys 0.027s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20631313,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":201,"lbm_read_time_us":10382,"lbm_reads_lt_1ms":472,"lbm_write_time_us":26332,"lbm_writes_lt_1ms":443,"mutex_wait_us":102,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":12032,"update_count":2000}
I20260812 06:17:17.217391 24977 maintenance_manager.cc:419] P 9434c5b6d7f445b486a135481139f5c9: Scheduling FlushDeltaMemStoresOp(e13e0daac18e46eaa59be223431b0896): perf score=10.126437
I20260812 06:17:17.255637 24865 maintenance_manager.cc:643] P 9434c5b6d7f445b486a135481139f5c9: FlushDeltaMemStoresOp(e13e0daac18e46eaa59be223431b0896) complete. Timing: real 0.038s	user 0.017s	sys 0.019s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":16268,"lbm_writes_lt_1ms":303,"reinsert_count":0,"spinlock_wait_cycles":2432,"update_count":1500}
I20260812 06:17:17.256122 24977 maintenance_manager.cc:419] P 9434c5b6d7f445b486a135481139f5c9: Scheduling FlushDeltaMemStoresOp(e13e0daac18e46eaa59be223431b0896): perf score=2.188937
I20260812 06:17:17.267946 24865 maintenance_manager.cc:643] P 9434c5b6d7f445b486a135481139f5c9: FlushDeltaMemStoresOp(e13e0daac18e46eaa59be223431b0896) complete. Timing: real 0.012s	user 0.009s	sys 0.001s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4611,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:17.268452 24977 maintenance_manager.cc:419] P 9434c5b6d7f445b486a135481139f5c9: Scheduling MajorDeltaCompactionOp(e13e0daac18e46eaa59be223431b0896): perf score=1.000000
I20260812 06:17:17.401798 24865 maintenance_manager.cc:643] P 9434c5b6d7f445b486a135481139f5c9: MajorDeltaCompactionOp(e13e0daac18e46eaa59be223431b0896) complete. Timing: real 0.133s	user 0.103s	sys 0.030s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20631312,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":123,"lbm_read_time_us":9971,"lbm_reads_lt_1ms":472,"lbm_write_time_us":27852,"lbm_writes_lt_1ms":443,"mutex_wait_us":23,"peak_mem_usage":50689328,"reinsert_count":0,"update_count":2000}
I20260812 06:17:17.402402 24977 maintenance_manager.cc:419] P 9434c5b6d7f445b486a135481139f5c9: Scheduling FlushDeltaMemStoresOp(e13e0daac18e46eaa59be223431b0896): perf score=10.126437
I20260812 06:17:17.451134 24865 maintenance_manager.cc:643] P 9434c5b6d7f445b486a135481139f5c9: FlushDeltaMemStoresOp(e13e0daac18e46eaa59be223431b0896) complete. Timing: real 0.049s	user 0.028s	sys 0.020s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":17716,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:17:17.451742 24977 maintenance_manager.cc:419] P 9434c5b6d7f445b486a135481139f5c9: Scheduling FlushDeltaMemStoresOp(e13e0daac18e46eaa59be223431b0896): perf score=2.188937
I20260812 06:17:17.462798 24865 maintenance_manager.cc:643] P 9434c5b6d7f445b486a135481139f5c9: FlushDeltaMemStoresOp(e13e0daac18e46eaa59be223431b0896) complete. Timing: real 0.011s	user 0.002s	sys 0.008s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4387,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:17.463218 24977 maintenance_manager.cc:419] P 9434c5b6d7f445b486a135481139f5c9: Scheduling FlushMRSOp(e13e0daac18e46eaa59be223431b0896): perf score=1.000000
I20260812 06:17:17.504274 24865 maintenance_manager.cc:643] P 9434c5b6d7f445b486a135481139f5c9: FlushMRSOp(e13e0daac18e46eaa59be223431b0896) complete. Timing: real 0.041s	user 0.030s	sys 0.000s Metrics: {"bytes_written":1152509,"cfile_init":1,"dirs.queue_time_us":62,"dirs.run_cpu_time_us":314,"dirs.run_wall_time_us":1700,"drs_written":1,"lbm_read_time_us":38,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1578,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":28}
I20260812 06:17:17.505195 24977 maintenance_manager.cc:419] P 9434c5b6d7f445b486a135481139f5c9: Scheduling LogGCOp(e13e0daac18e46eaa59be223431b0896): free 120100313 bytes of WAL
I20260812 06:17:17.505442 24865 log_reader.cc:385] T e13e0daac18e46eaa59be223431b0896: removed 12 log segments from log reader
I20260812 06:17:17.505501 24865 log.cc:1079] T e13e0daac18e46eaa59be223431b0896 P 9434c5b6d7f445b486a135481139f5c9: Deleting log segment in path: /tmp/dist-test-taskULGn6B/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515435658806-24703-0/minicluster-data/ts-0-root/wals/e13e0daac18e46eaa59be223431b0896/wal-000000002 (ops 7-11)
I20260812 06:17:17.505559 24865 log.cc:1079] T e13e0daac18e46eaa59be223431b0896 P 9434c5b6d7f445b486a135481139f5c9: Deleting log segment in path: /tmp/dist-test-taskULGn6B/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515435658806-24703-0/minicluster-data/ts-0-root/wals/e13e0daac18e46eaa59be223431b0896/wal-000000003 (ops 12-16)
I20260812 06:17:17.505615 24865 log.cc:1079] T e13e0daac18e46eaa59be223431b0896 P 9434c5b6d7f445b486a135481139f5c9: Deleting log segment in path: /tmp/dist-test-taskULGn6B/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515435658806-24703-0/minicluster-data/ts-0-root/wals/e13e0daac18e46eaa59be223431b0896/wal-000000004 (ops 17-20)
I20260812 06:17:17.505677 24865 log.cc:1079] T e13e0daac18e46eaa59be223431b0896 P 9434c5b6d7f445b486a135481139f5c9: Deleting log segment in path: /tmp/dist-test-taskULGn6B/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515435658806-24703-0/minicluster-data/ts-0-root/wals/e13e0daac18e46eaa59be223431b0896/wal-000000005 (ops 21-25)
I20260812 06:17:17.505728 24865 log.cc:1079] T e13e0daac18e46eaa59be223431b0896 P 9434c5b6d7f445b486a135481139f5c9: Deleting log segment in path: /tmp/dist-test-taskULGn6B/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515435658806-24703-0/minicluster-data/ts-0-root/wals/e13e0daac18e46eaa59be223431b0896/wal-000000006 (ops 26-30)
I20260812 06:17:17.505786 24865 log.cc:1079] T e13e0daac18e46eaa59be223431b0896 P 9434c5b6d7f445b486a135481139f5c9: Deleting log segment in path: /tmp/dist-test-taskULGn6B/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515435658806-24703-0/minicluster-data/ts-0-root/wals/e13e0daac18e46eaa59be223431b0896/wal-000000007 (ops 31-35)
I20260812 06:17:17.505831 24865 log.cc:1079] T e13e0daac18e46eaa59be223431b0896 P 9434c5b6d7f445b486a135481139f5c9: Deleting log segment in path: /tmp/dist-test-taskULGn6B/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515435658806-24703-0/minicluster-data/ts-0-root/wals/e13e0daac18e46eaa59be223431b0896/wal-000000008 (ops 36-40)
I20260812 06:17:17.505877 24865 log.cc:1079] T e13e0daac18e46eaa59be223431b0896 P 9434c5b6d7f445b486a135481139f5c9: Deleting log segment in path: /tmp/dist-test-taskULGn6B/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515435658806-24703-0/minicluster-data/ts-0-root/wals/e13e0daac18e46eaa59be223431b0896/wal-000000009 (ops 41-44)
I20260812 06:17:17.505920 24865 log.cc:1079] T e13e0daac18e46eaa59be223431b0896 P 9434c5b6d7f445b486a135481139f5c9: Deleting log segment in path: /tmp/dist-test-taskULGn6B/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515435658806-24703-0/minicluster-data/ts-0-root/wals/e13e0daac18e46eaa59be223431b0896/wal-000000010 (ops 45-49)
I20260812 06:17:17.505963 24865 log.cc:1079] T e13e0daac18e46eaa59be223431b0896 P 9434c5b6d7f445b486a135481139f5c9: Deleting log segment in path: /tmp/dist-test-taskULGn6B/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515435658806-24703-0/minicluster-data/ts-0-root/wals/e13e0daac18e46eaa59be223431b0896/wal-000000011 (ops 50-54)
I20260812 06:17:17.506017 24865 log.cc:1079] T e13e0daac18e46eaa59be223431b0896 P 9434c5b6d7f445b486a135481139f5c9: Deleting log segment in path: /tmp/dist-test-taskULGn6B/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515435658806-24703-0/minicluster-data/ts-0-root/wals/e13e0daac18e46eaa59be223431b0896/wal-000000012 (ops 55-58)
I20260812 06:17:17.506062 24865 log.cc:1079] T e13e0daac18e46eaa59be223431b0896 P 9434c5b6d7f445b486a135481139f5c9: Deleting log segment in path: /tmp/dist-test-taskULGn6B/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515435658806-24703-0/minicluster-data/ts-0-root/wals/e13e0daac18e46eaa59be223431b0896/wal-000000013 (ops 59-63)
I20260812 06:17:17.538602 24865 maintenance_manager.cc:643] P 9434c5b6d7f445b486a135481139f5c9: LogGCOp(e13e0daac18e46eaa59be223431b0896) complete. Timing: real 0.033s	user 0.000s	sys 0.033s Metrics: {}
I20260812 06:17:17.539227 24977 maintenance_manager.cc:419] P 9434c5b6d7f445b486a135481139f5c9: Scheduling UndoDeltaBlockGCOp(e13e0daac18e46eaa59be223431b0896): 447 bytes on disk
I20260812 06:17:17.539690 24865 maintenance_manager.cc:643] P 9434c5b6d7f445b486a135481139f5c9: UndoDeltaBlockGCOp(e13e0daac18e46eaa59be223431b0896) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":53,"lbm_reads_lt_1ms":4}
I20260812 06:17:17.540201 24977 maintenance_manager.cc:419] P 9434c5b6d7f445b486a135481139f5c9: Scheduling FlushDeltaMemStoresOp(e13e0daac18e46eaa59be223431b0896): perf score=3.181125
I20260812 06:17:17.553354 24865 maintenance_manager.cc:643] P 9434c5b6d7f445b486a135481139f5c9: FlushDeltaMemStoresOp(e13e0daac18e46eaa59be223431b0896) complete. Timing: real 0.013s	user 0.010s	sys 0.001s Metrics: {"bytes_written":4800077,"delete_count":0,"lbm_write_time_us":5123,"lbm_writes_lt_1ms":120,"reinsert_count":0,"update_count":585}
I20260812 06:17:17.553843 24977 maintenance_manager.cc:419] P 9434c5b6d7f445b486a135481139f5c9: Scheduling FlushDeltaMemStoresOp(e13e0daac18e46eaa59be223431b0896): perf score=2.188937
I20260812 06:17:17.566512 24865 maintenance_manager.cc:643] P 9434c5b6d7f445b486a135481139f5c9: FlushDeltaMemStoresOp(e13e0daac18e46eaa59be223431b0896) complete. Timing: real 0.012s	user 0.007s	sys 0.005s Metrics: {"bytes_written":3405230,"delete_count":0,"lbm_write_time_us":4888,"lbm_writes_lt_1ms":86,"reinsert_count":0,"update_count":415}
I20260812 06:17:17.567056 24977 maintenance_manager.cc:419] P 9434c5b6d7f445b486a135481139f5c9: Scheduling MajorDeltaCompactionOp(e13e0daac18e46eaa59be223431b0896): perf score=1.000000
I20260812 06:17:17.778620 24865 maintenance_manager.cc:643] P 9434c5b6d7f445b486a135481139f5c9: MajorDeltaCompactionOp(e13e0daac18e46eaa59be223431b0896) complete. Timing: real 0.211s	user 0.119s	sys 0.091s Metrics: {"cfile_cache_miss":634,"cfile_cache_miss_bytes":28836362,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":180,"lbm_read_time_us":15893,"lbm_reads_lt_1ms":674,"lbm_write_time_us":36951,"lbm_writes_lt_1ms":643,"mutex_wait_us":47,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":16000,"thread_start_us":92,"threads_started":1,"update_count":3000}
I20260812 06:17:17.779445 24977 maintenance_manager.cc:419] P 9434c5b6d7f445b486a135481139f5c9: Scheduling FlushDeltaMemStoresOp(e13e0daac18e46eaa59be223431b0896): perf score=14.095187
I20260812 06:17:17.829849 24865 maintenance_manager.cc:643] P 9434c5b6d7f445b486a135481139f5c9: FlushDeltaMemStoresOp(e13e0daac18e46eaa59be223431b0896) complete. Timing: real 0.048s	user 0.031s	sys 0.013s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":21871,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:17:17.830482 24977 maintenance_manager.cc:419] P 9434c5b6d7f445b486a135481139f5c9: Scheduling FlushDeltaMemStoresOp(e13e0daac18e46eaa59be223431b0896): perf score=2.188937
I20260812 06:17:17.845799 24865 maintenance_manager.cc:643] P 9434c5b6d7f445b486a135481139f5c9: FlushDeltaMemStoresOp(e13e0daac18e46eaa59be223431b0896) complete. Timing: real 0.015s	user 0.012s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5836,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:17.846302 24977 maintenance_manager.cc:419] P 9434c5b6d7f445b486a135481139f5c9: Scheduling MajorDeltaCompactionOp(e13e0daac18e46eaa59be223431b0896): perf score=1.000000
I20260812 06:17:18.026117 24865 maintenance_manager.cc:643] P 9434c5b6d7f445b486a135481139f5c9: MajorDeltaCompactionOp(e13e0daac18e46eaa59be223431b0896) complete. Timing: real 0.180s	user 0.103s	sys 0.074s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24733724,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":400,"lbm_read_time_us":13712,"lbm_reads_lt_1ms":564,"lbm_write_time_us":30561,"lbm_writes_lt_1ms":543,"mutex_wait_us":40,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":14720,"update_count":2500}
I20260812 06:17:18.026821 24977 maintenance_manager.cc:419] P 9434c5b6d7f445b486a135481139f5c9: Scheduling FlushDeltaMemStoresOp(e13e0daac18e46eaa59be223431b0896): perf score=14.095187
I20260812 06:17:18.091271 24865 maintenance_manager.cc:643] P 9434c5b6d7f445b486a135481139f5c9: FlushDeltaMemStoresOp(e13e0daac18e46eaa59be223431b0896) complete. Timing: real 0.064s	user 0.037s	sys 0.027s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":22935,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:17:18.091949 24977 maintenance_manager.cc:419] P 9434c5b6d7f445b486a135481139f5c9: Scheduling FlushDeltaMemStoresOp(e13e0daac18e46eaa59be223431b0896): perf score=2.188937
I20260812 06:17:18.103878 24865 maintenance_manager.cc:643] P 9434c5b6d7f445b486a135481139f5c9: FlushDeltaMemStoresOp(e13e0daac18e46eaa59be223431b0896) complete. Timing: real 0.012s	user 0.005s	sys 0.005s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4919,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:18.104297 24977 maintenance_manager.cc:419] P 9434c5b6d7f445b486a135481139f5c9: Scheduling MajorDeltaCompactionOp(e13e0daac18e46eaa59be223431b0896): perf score=1.000000
I20260812 06:17:18.295352 24865 maintenance_manager.cc:643] P 9434c5b6d7f445b486a135481139f5c9: MajorDeltaCompactionOp(e13e0daac18e46eaa59be223431b0896) complete. Timing: real 0.191s	user 0.135s	sys 0.054s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24733723,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":233,"lbm_read_time_us":13331,"lbm_reads_lt_1ms":572,"lbm_write_time_us":34779,"lbm_writes_lt_1ms":543,"mutex_wait_us":60,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":2432,"update_count":2500}
I20260812 06:17:18.296037 24977 maintenance_manager.cc:419] P 9434c5b6d7f445b486a135481139f5c9: Scheduling FlushDeltaMemStoresOp(e13e0daac18e46eaa59be223431b0896): perf score=11.118625
I20260812 06:17:18.350360 24865 maintenance_manager.cc:643] P 9434c5b6d7f445b486a135481139f5c9: FlushDeltaMemStoresOp(e13e0daac18e46eaa59be223431b0896) complete. Timing: real 0.054s	user 0.028s	sys 0.023s Metrics: {"bytes_written":12717735,"delete_count":0,"lbm_write_time_us":19038,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:17:18.351344 24977 maintenance_manager.cc:419] P 9434c5b6d7f445b486a135481139f5c9: Scheduling FlushDeltaMemStoresOp(e13e0daac18e46eaa59be223431b0896): perf score=4.173312
I20260812 06:17:18.365873 24865 maintenance_manager.cc:643] P 9434c5b6d7f445b486a135481139f5c9: FlushDeltaMemStoresOp(e13e0daac18e46eaa59be223431b0896) complete. Timing: real 0.014s	user 0.008s	sys 0.004s Metrics: {"bytes_written":5415437,"delete_count":0,"lbm_write_time_us":6131,"lbm_writes_lt_1ms":135,"reinsert_count":0,"update_count":660}
I20260812 06:17:18.366406 24977 maintenance_manager.cc:419] P 9434c5b6d7f445b486a135481139f5c9: Scheduling FlushDeltaMemStoresOp(e13e0daac18e46eaa59be223431b0896): perf score=1.196750
I20260812 06:17:18.373713 24865 maintenance_manager.cc:643] P 9434c5b6d7f445b486a135481139f5c9: FlushDeltaMemStoresOp(e13e0daac18e46eaa59be223431b0896) complete. Timing: real 0.007s	user 0.005s	sys 0.001s Metrics: {"bytes_written":2379604,"delete_count":0,"lbm_write_time_us":2514,"lbm_writes_lt_1ms":61,"reinsert_count":0,"update_count":290}
I20260812 06:17:18.374312 24977 maintenance_manager.cc:419] P 9434c5b6d7f445b486a135481139f5c9: Scheduling MajorDeltaCompactionOp(e13e0daac18e46eaa59be223431b0896): perf score=1.000000
I20260812 06:17:18.562129 24865 maintenance_manager.cc:643] P 9434c5b6d7f445b486a135481139f5c9: MajorDeltaCompactionOp(e13e0daac18e46eaa59be223431b0896) complete. Timing: real 0.188s	user 0.109s	sys 0.068s Metrics: {"cfile_cache_miss":533,"cfile_cache_miss_bytes":24733805,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":215,"lbm_read_time_us":13485,"lbm_reads_lt_1ms":573,"lbm_write_time_us":32902,"lbm_writes_lt_1ms":543,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":14592,"update_count":2500}
I20260812 06:17:18.562714 24977 maintenance_manager.cc:419] P 9434c5b6d7f445b486a135481139f5c9: Scheduling FlushDeltaMemStoresOp(e13e0daac18e46eaa59be223431b0896): perf score=14.095187
I20260812 06:17:18.631136 24865 maintenance_manager.cc:643] P 9434c5b6d7f445b486a135481139f5c9: FlushDeltaMemStoresOp(e13e0daac18e46eaa59be223431b0896) complete. Timing: real 0.068s	user 0.028s	sys 0.039s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":26618,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":402,"reinsert_count":0,"spinlock_wait_cycles":1408,"update_count":2000}
I20260812 06:17:18.631675 24977 maintenance_manager.cc:419] P 9434c5b6d7f445b486a135481139f5c9: Scheduling FlushDeltaMemStoresOp(e13e0daac18e46eaa59be223431b0896): perf score=2.188937
I20260812 06:17:18.643116 24865 maintenance_manager.cc:643] P 9434c5b6d7f445b486a135481139f5c9: FlushDeltaMemStoresOp(e13e0daac18e46eaa59be223431b0896) complete. Timing: real 0.011s	user 0.010s	sys 0.000s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4334,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:18.643630 24977 maintenance_manager.cc:419] P 9434c5b6d7f445b486a135481139f5c9: Scheduling MajorDeltaCompactionOp(e13e0daac18e46eaa59be223431b0896): perf score=1.000000
I20260812 06:17:18.825385 24865 maintenance_manager.cc:643] P 9434c5b6d7f445b486a135481139f5c9: MajorDeltaCompactionOp(e13e0daac18e46eaa59be223431b0896) complete. Timing: real 0.182s	user 0.114s	sys 0.060s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24733723,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":155,"lbm_read_time_us":13759,"lbm_reads_lt_1ms":572,"lbm_write_time_us":31639,"lbm_writes_lt_1ms":543,"peak_mem_usage":63115900,"reinsert_count":0,"update_count":2500}
I20260812 06:17:18.826056 24977 maintenance_manager.cc:419] P 9434c5b6d7f445b486a135481139f5c9: Scheduling FlushDeltaMemStoresOp(e13e0daac18e46eaa59be223431b0896): perf score=11.118625
I20260812 06:17:18.868870 24865 maintenance_manager.cc:643] P 9434c5b6d7f445b486a135481139f5c9: FlushDeltaMemStoresOp(e13e0daac18e46eaa59be223431b0896) complete. Timing: real 0.043s	user 0.023s	sys 0.017s Metrics: {"bytes_written":12717736,"delete_count":0,"lbm_write_time_us":19234,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:17:18.869819 24977 maintenance_manager.cc:419] P 9434c5b6d7f445b486a135481139f5c9: Scheduling FlushDeltaMemStoresOp(e13e0daac18e46eaa59be223431b0896): perf score=2.188937
I20260812 06:17:18.884940 24865 maintenance_manager.cc:643] P 9434c5b6d7f445b486a135481139f5c9: FlushDeltaMemStoresOp(e13e0daac18e46eaa59be223431b0896) complete. Timing: real 0.015s	user 0.008s	sys 0.004s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":5371,"lbm_writes_lt_1ms":93,"reinsert_count":0,"spinlock_wait_cycles":768,"update_count":450}
I20260812 06:17:18.885416 24977 maintenance_manager.cc:419] P 9434c5b6d7f445b486a135481139f5c9: Scheduling MajorDeltaCompactionOp(e13e0daac18e46eaa59be223431b0896): perf score=1.000000
I20260812 06:17:19.015753 24865 maintenance_manager.cc:643] P 9434c5b6d7f445b486a135481139f5c9: MajorDeltaCompactionOp(e13e0daac18e46eaa59be223431b0896) complete. Timing: real 0.130s	user 0.124s	sys 0.006s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20631304,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":335,"lbm_read_time_us":8241,"lbm_reads_lt_1ms":464,"lbm_write_time_us":27106,"lbm_writes_lt_1ms":443,"mutex_wait_us":58,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":12672,"update_count":2000}
I20260812 06:17:19.016347 24977 maintenance_manager.cc:419] P 9434c5b6d7f445b486a135481139f5c9: Scheduling FlushDeltaMemStoresOp(e13e0daac18e46eaa59be223431b0896): perf score=10.126437
I20260812 06:17:19.060377 24865 maintenance_manager.cc:643] P 9434c5b6d7f445b486a135481139f5c9: FlushDeltaMemStoresOp(e13e0daac18e46eaa59be223431b0896) complete. Timing: real 0.044s	user 0.015s	sys 0.019s Metrics: {"bytes_written":12307492,"delete_count":0,"lbm_write_time_us":16463,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:17:19.060850 24977 maintenance_manager.cc:419] P 9434c5b6d7f445b486a135481139f5c9: Scheduling FlushDeltaMemStoresOp(e13e0daac18e46eaa59be223431b0896): perf score=2.188937
I20260812 06:17:19.071669 24865 maintenance_manager.cc:643] P 9434c5b6d7f445b486a135481139f5c9: FlushDeltaMemStoresOp(e13e0daac18e46eaa59be223431b0896) complete. Timing: real 0.011s	user 0.001s	sys 0.009s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4216,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:19.072269 24977 maintenance_manager.cc:419] P 9434c5b6d7f445b486a135481139f5c9: Scheduling FlushMRSOp(e13e0daac18e46eaa59be223431b0896): perf score=1.000000
I20260812 06:17:19.100845 24865 maintenance_manager.cc:643] P 9434c5b6d7f445b486a135481139f5c9: FlushMRSOp(e13e0daac18e46eaa59be223431b0896) complete. Timing: real 0.028s	user 0.027s	sys 0.000s Metrics: {"bytes_written":1234479,"cfile_init":1,"dirs.queue_time_us":70,"dirs.run_cpu_time_us":201,"dirs.run_wall_time_us":1444,"drs_written":1,"lbm_read_time_us":55,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1674,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":30}
I20260812 06:17:19.101650 24977 maintenance_manager.cc:419] P 9434c5b6d7f445b486a135481139f5c9: Scheduling LogGCOp(e13e0daac18e46eaa59be223431b0896): free 121006454 bytes of WAL
I20260812 06:17:19.101872 24865 log_reader.cc:385] T e13e0daac18e46eaa59be223431b0896: removed 12 log segments from log reader
I20260812 06:17:19.101915 24865 log.cc:1079] T e13e0daac18e46eaa59be223431b0896 P 9434c5b6d7f445b486a135481139f5c9: Deleting log segment in path: /tmp/dist-test-taskULGn6B/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515435658806-24703-0/minicluster-data/ts-0-root/wals/e13e0daac18e46eaa59be223431b0896/wal-000000014 (ops 64-68)
I20260812 06:17:19.101965 24865 log.cc:1079] T e13e0daac18e46eaa59be223431b0896 P 9434c5b6d7f445b486a135481139f5c9: Deleting log segment in path: /tmp/dist-test-taskULGn6B/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515435658806-24703-0/minicluster-data/ts-0-root/wals/e13e0daac18e46eaa59be223431b0896/wal-000000015 (ops 69-72)
I20260812 06:17:19.102018 24865 log.cc:1079] T e13e0daac18e46eaa59be223431b0896 P 9434c5b6d7f445b486a135481139f5c9: Deleting log segment in path: /tmp/dist-test-taskULGn6B/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515435658806-24703-0/minicluster-data/ts-0-root/wals/e13e0daac18e46eaa59be223431b0896/wal-000000016 (ops 73-77)
I20260812 06:17:19.102080 24865 log.cc:1079] T e13e0daac18e46eaa59be223431b0896 P 9434c5b6d7f445b486a135481139f5c9: Deleting log segment in path: /tmp/dist-test-taskULGn6B/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515435658806-24703-0/minicluster-data/ts-0-root/wals/e13e0daac18e46eaa59be223431b0896/wal-000000017 (ops 78-82)
I20260812 06:17:19.102121 24865 log.cc:1079] T e13e0daac18e46eaa59be223431b0896 P 9434c5b6d7f445b486a135481139f5c9: Deleting log segment in path: /tmp/dist-test-taskULGn6B/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515435658806-24703-0/minicluster-data/ts-0-root/wals/e13e0daac18e46eaa59be223431b0896/wal-000000018 (ops 83-87)
I20260812 06:17:19.102157 24865 log.cc:1079] T e13e0daac18e46eaa59be223431b0896 P 9434c5b6d7f445b486a135481139f5c9: Deleting log segment in path: /tmp/dist-test-taskULGn6B/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515435658806-24703-0/minicluster-data/ts-0-root/wals/e13e0daac18e46eaa59be223431b0896/wal-000000019 (ops 88-92)
I20260812 06:17:19.102200 24865 log.cc:1079] T e13e0daac18e46eaa59be223431b0896 P 9434c5b6d7f445b486a135481139f5c9: Deleting log segment in path: /tmp/dist-test-taskULGn6B/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515435658806-24703-0/minicluster-data/ts-0-root/wals/e13e0daac18e46eaa59be223431b0896/wal-000000020 (ops 93-97)
I20260812 06:17:19.102262 24865 log.cc:1079] T e13e0daac18e46eaa59be223431b0896 P 9434c5b6d7f445b486a135481139f5c9: Deleting log segment in path: /tmp/dist-test-taskULGn6B/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515435658806-24703-0/minicluster-data/ts-0-root/wals/e13e0daac18e46eaa59be223431b0896/wal-000000021 (ops 98-102)
I20260812 06:17:19.102309 24865 log.cc:1079] T e13e0daac18e46eaa59be223431b0896 P 9434c5b6d7f445b486a135481139f5c9: Deleting log segment in path: /tmp/dist-test-taskULGn6B/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515435658806-24703-0/minicluster-data/ts-0-root/wals/e13e0daac18e46eaa59be223431b0896/wal-000000022 (ops 103-107)
I20260812 06:17:19.102336 24865 log.cc:1079] T e13e0daac18e46eaa59be223431b0896 P 9434c5b6d7f445b486a135481139f5c9: Deleting log segment in path: /tmp/dist-test-taskULGn6B/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515435658806-24703-0/minicluster-data/ts-0-root/wals/e13e0daac18e46eaa59be223431b0896/wal-000000023 (ops 108-112)
I20260812 06:17:19.102360 24865 log.cc:1079] T e13e0daac18e46eaa59be223431b0896 P 9434c5b6d7f445b486a135481139f5c9: Deleting log segment in path: /tmp/dist-test-taskULGn6B/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515435658806-24703-0/minicluster-data/ts-0-root/wals/e13e0daac18e46eaa59be223431b0896/wal-000000024 (ops 113-117)
I20260812 06:17:19.102376 24865 log.cc:1079] T e13e0daac18e46eaa59be223431b0896 P 9434c5b6d7f445b486a135481139f5c9: Deleting log segment in path: /tmp/dist-test-taskULGn6B/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515435658806-24703-0/minicluster-data/ts-0-root/wals/e13e0daac18e46eaa59be223431b0896/wal-000000025 (ops 118-122)
I20260812 06:17:19.132884 24865 maintenance_manager.cc:643] P 9434c5b6d7f445b486a135481139f5c9: LogGCOp(e13e0daac18e46eaa59be223431b0896) complete. Timing: real 0.031s	user 0.000s	sys 0.028s Metrics: {}
I20260812 06:17:19.133412 24977 maintenance_manager.cc:419] P 9434c5b6d7f445b486a135481139f5c9: Scheduling UndoDeltaBlockGCOp(e13e0daac18e46eaa59be223431b0896): 472 bytes on disk
I20260812 06:17:19.134003 24865 maintenance_manager.cc:643] P 9434c5b6d7f445b486a135481139f5c9: UndoDeltaBlockGCOp(e13e0daac18e46eaa59be223431b0896) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":70,"lbm_reads_lt_1ms":4}
I20260812 06:17:19.134924 24977 maintenance_manager.cc:419] P 9434c5b6d7f445b486a135481139f5c9: Scheduling FlushDeltaMemStoresOp(e13e0daac18e46eaa59be223431b0896): perf score=3.181125
I20260812 06:17:19.153009 24865 maintenance_manager.cc:643] P 9434c5b6d7f445b486a135481139f5c9: FlushDeltaMemStoresOp(e13e0daac18e46eaa59be223431b0896) complete. Timing: real 0.018s	user 0.016s	sys 0.000s Metrics: {"bytes_written":4512903,"delete_count":0,"lbm_write_time_us":7455,"lbm_writes_lt_1ms":113,"reinsert_count":0,"update_count":550}
I20260812 06:17:19.153565 24977 maintenance_manager.cc:419] P 9434c5b6d7f445b486a135481139f5c9: Scheduling FlushDeltaMemStoresOp(e13e0daac18e46eaa59be223431b0896): perf score=2.188937
I20260812 06:17:19.163771 24865 maintenance_manager.cc:643] P 9434c5b6d7f445b486a135481139f5c9: FlushDeltaMemStoresOp(e13e0daac18e46eaa59be223431b0896) complete. Timing: real 0.010s	user 0.004s	sys 0.004s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3886,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:17:19.164775 24977 maintenance_manager.cc:419] P 9434c5b6d7f445b486a135481139f5c9: Scheduling MajorDeltaCompactionOp(e13e0daac18e46eaa59be223431b0896): perf score=1.000000
I20260812 06:17:19.342526 24865 maintenance_manager.cc:643] P 9434c5b6d7f445b486a135481139f5c9: MajorDeltaCompactionOp(e13e0daac18e46eaa59be223431b0896) complete. Timing: real 0.178s	user 0.144s	sys 0.032s Metrics: {"cfile_cache_miss":634,"cfile_cache_miss_bytes":28836366,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":2338,"lbm_read_time_us":13768,"lbm_reads_lt_1ms":674,"lbm_write_time_us":38596,"lbm_writes_lt_1ms":643,"mutex_wait_us":22,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":3456,"thread_start_us":84,"threads_started":1,"update_count":3000}
I20260812 06:17:19.343081 24977 maintenance_manager.cc:419] P 9434c5b6d7f445b486a135481139f5c9: Scheduling FlushDeltaMemStoresOp(e13e0daac18e46eaa59be223431b0896): perf score=14.095187
I20260812 06:17:19.402088 24865 maintenance_manager.cc:643] P 9434c5b6d7f445b486a135481139f5c9: FlushDeltaMemStoresOp(e13e0daac18e46eaa59be223431b0896) complete. Timing: real 0.059s	user 0.020s	sys 0.035s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":27204,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:17:19.402642 24977 maintenance_manager.cc:419] P 9434c5b6d7f445b486a135481139f5c9: Scheduling FlushDeltaMemStoresOp(e13e0daac18e46eaa59be223431b0896): perf score=2.188937
I20260812 06:17:19.422986 24865 maintenance_manager.cc:643] P 9434c5b6d7f445b486a135481139f5c9: FlushDeltaMemStoresOp(e13e0daac18e46eaa59be223431b0896) complete. Timing: real 0.020s	user 0.014s	sys 0.001s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5629,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:19.423533 24977 maintenance_manager.cc:419] P 9434c5b6d7f445b486a135481139f5c9: Scheduling MajorDeltaCompactionOp(e13e0daac18e46eaa59be223431b0896): perf score=1.000000
I20260812 06:17:19.586076 24865 maintenance_manager.cc:643] P 9434c5b6d7f445b486a135481139f5c9: MajorDeltaCompactionOp(e13e0daac18e46eaa59be223431b0896) complete. Timing: real 0.162s	user 0.127s	sys 0.032s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24733723,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":678,"lbm_read_time_us":11885,"lbm_reads_lt_1ms":564,"lbm_write_time_us":32803,"lbm_writes_lt_1ms":543,"mutex_wait_us":66,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":8320,"update_count":2500}
I20260812 06:17:19.586833 24977 maintenance_manager.cc:419] P 9434c5b6d7f445b486a135481139f5c9: Scheduling FlushDeltaMemStoresOp(e13e0daac18e46eaa59be223431b0896): perf score=14.095187
I20260812 06:17:19.642784 24865 maintenance_manager.cc:643] P 9434c5b6d7f445b486a135481139f5c9: FlushDeltaMemStoresOp(e13e0daac18e46eaa59be223431b0896) complete. Timing: real 0.056s	user 0.030s	sys 0.024s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":28188,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:17:19.643330 24977 maintenance_manager.cc:419] P 9434c5b6d7f445b486a135481139f5c9: Scheduling FlushDeltaMemStoresOp(e13e0daac18e46eaa59be223431b0896): perf score=2.188937
I20260812 06:17:19.662616 24865 maintenance_manager.cc:643] P 9434c5b6d7f445b486a135481139f5c9: FlushDeltaMemStoresOp(e13e0daac18e46eaa59be223431b0896) complete. Timing: real 0.019s	user 0.002s	sys 0.012s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5811,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:19.663048 24977 maintenance_manager.cc:419] P 9434c5b6d7f445b486a135481139f5c9: Scheduling MajorDeltaCompactionOp(e13e0daac18e46eaa59be223431b0896): perf score=1.000000
I20260812 06:17:19.821157 24865 maintenance_manager.cc:643] P 9434c5b6d7f445b486a135481139f5c9: MajorDeltaCompactionOp(e13e0daac18e46eaa59be223431b0896) complete. Timing: real 0.158s	user 0.109s	sys 0.044s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24733723,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":349,"lbm_read_time_us":10219,"lbm_reads_lt_1ms":564,"lbm_write_time_us":30759,"lbm_writes_lt_1ms":543,"mutex_wait_us":122,"peak_mem_usage":63115900,"reinsert_count":0,"update_count":2500}
I20260812 06:17:19.821834 24977 maintenance_manager.cc:419] P 9434c5b6d7f445b486a135481139f5c9: Scheduling FlushDeltaMemStoresOp(e13e0daac18e46eaa59be223431b0896): perf score=14.095187
I20260812 06:17:19.879338 24865 maintenance_manager.cc:643] P 9434c5b6d7f445b486a135481139f5c9: FlushDeltaMemStoresOp(e13e0daac18e46eaa59be223431b0896) complete. Timing: real 0.057s	user 0.034s	sys 0.015s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":23971,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:17:19.879832 24977 maintenance_manager.cc:419] P 9434c5b6d7f445b486a135481139f5c9: Scheduling FlushDeltaMemStoresOp(e13e0daac18e46eaa59be223431b0896): perf score=2.188937
I20260812 06:17:19.892266 24865 maintenance_manager.cc:643] P 9434c5b6d7f445b486a135481139f5c9: FlushDeltaMemStoresOp(e13e0daac18e46eaa59be223431b0896) complete. Timing: real 0.012s	user 0.006s	sys 0.004s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4398,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:19.892920 24977 maintenance_manager.cc:419] P 9434c5b6d7f445b486a135481139f5c9: Scheduling MajorDeltaCompactionOp(e13e0daac18e46eaa59be223431b0896): perf score=1.000000
I20260812 06:17:20.067759 24865 maintenance_manager.cc:643] P 9434c5b6d7f445b486a135481139f5c9: MajorDeltaCompactionOp(e13e0daac18e46eaa59be223431b0896) complete. Timing: real 0.175s	user 0.104s	sys 0.060s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24733722,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":288,"lbm_read_time_us":11927,"lbm_reads_lt_1ms":572,"lbm_write_time_us":30352,"lbm_writes_lt_1ms":543,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":2304,"update_count":2500}
I20260812 06:17:20.068778 24977 maintenance_manager.cc:419] P 9434c5b6d7f445b486a135481139f5c9: Scheduling FlushDeltaMemStoresOp(e13e0daac18e46eaa59be223431b0896): perf score=14.095187
I20260812 06:17:20.128221 24865 maintenance_manager.cc:643] P 9434c5b6d7f445b486a135481139f5c9: FlushDeltaMemStoresOp(e13e0daac18e46eaa59be223431b0896) complete. Timing: real 0.059s	user 0.027s	sys 0.024s Metrics: {"bytes_written":16409903,"delete_count":0,"lbm_write_time_us":24127,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:17:20.128840 24977 maintenance_manager.cc:419] P 9434c5b6d7f445b486a135481139f5c9: Scheduling MajorDeltaCompactionOp(e13e0daac18e46eaa59be223431b0896): perf score=1.000000
I20260812 06:17:20.278641 24865 maintenance_manager.cc:643] P 9434c5b6d7f445b486a135481139f5c9: MajorDeltaCompactionOp(e13e0daac18e46eaa59be223431b0896) complete. Timing: real 0.150s	user 0.085s	sys 0.064s Metrics: {"cfile_cache_miss":431,"cfile_cache_miss_bytes":20631194,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":1,"delta_iterators_relevant":1,"dirs.queue_time_us":261,"lbm_read_time_us":11918,"lbm_reads_lt_1ms":463,"lbm_write_time_us":25073,"lbm_writes_lt_1ms":443,"mutex_wait_us":75,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":1280,"update_count":2000}
I20260812 06:17:20.279347 24977 maintenance_manager.cc:419] P 9434c5b6d7f445b486a135481139f5c9: Scheduling FlushDeltaMemStoresOp(e13e0daac18e46eaa59be223431b0896): perf score=14.095187
I20260812 06:17:20.328398 24865 maintenance_manager.cc:643] P 9434c5b6d7f445b486a135481139f5c9: FlushDeltaMemStoresOp(e13e0daac18e46eaa59be223431b0896) complete. Timing: real 0.049s	user 0.019s	sys 0.028s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":21680,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:17:20.329025 24977 maintenance_manager.cc:419] P 9434c5b6d7f445b486a135481139f5c9: Scheduling FlushDeltaMemStoresOp(e13e0daac18e46eaa59be223431b0896): perf score=2.188937
I20260812 06:17:20.341952 24865 maintenance_manager.cc:643] P 9434c5b6d7f445b486a135481139f5c9: FlushDeltaMemStoresOp(e13e0daac18e46eaa59be223431b0896) complete. Timing: real 0.013s	user 0.007s	sys 0.004s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4897,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:20.342541 24977 maintenance_manager.cc:419] P 9434c5b6d7f445b486a135481139f5c9: Scheduling MajorDeltaCompactionOp(e13e0daac18e46eaa59be223431b0896): perf score=1.000000
I20260812 06:17:20.554991 24865 maintenance_manager.cc:643] P 9434c5b6d7f445b486a135481139f5c9: MajorDeltaCompactionOp(e13e0daac18e46eaa59be223431b0896) complete. Timing: real 0.212s	user 0.145s	sys 0.056s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24733722,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":423,"lbm_read_time_us":14541,"lbm_reads_lt_1ms":572,"lbm_write_time_us":35619,"lbm_writes_lt_1ms":543,"mutex_wait_us":69,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":19200,"update_count":2500}
I20260812 06:17:20.555538 24977 maintenance_manager.cc:419] P 9434c5b6d7f445b486a135481139f5c9: Scheduling FlushDeltaMemStoresOp(e13e0daac18e46eaa59be223431b0896): perf score=14.095187
I20260812 06:17:20.605505 24865 maintenance_manager.cc:643] P 9434c5b6d7f445b486a135481139f5c9: FlushDeltaMemStoresOp(e13e0daac18e46eaa59be223431b0896) complete. Timing: real 0.050s	user 0.031s	sys 0.011s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":21580,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:17:20.606045 24977 maintenance_manager.cc:419] P 9434c5b6d7f445b486a135481139f5c9: Scheduling FlushDeltaMemStoresOp(e13e0daac18e46eaa59be223431b0896): perf score=2.188937
I20260812 06:17:20.621783 24865 maintenance_manager.cc:643] P 9434c5b6d7f445b486a135481139f5c9: FlushDeltaMemStoresOp(e13e0daac18e46eaa59be223431b0896) complete. Timing: real 0.016s	user 0.006s	sys 0.007s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5968,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:20.622618 24977 maintenance_manager.cc:419] P 9434c5b6d7f445b486a135481139f5c9: Scheduling FlushMRSOp(e13e0daac18e46eaa59be223431b0896): perf score=1.000000
I20260812 06:17:20.652783 24865 maintenance_manager.cc:643] P 9434c5b6d7f445b486a135481139f5c9: FlushMRSOp(e13e0daac18e46eaa59be223431b0896) complete. Timing: real 0.030s	user 0.024s	sys 0.004s Metrics: {"bytes_written":1275445,"cfile_init":1,"dirs.queue_time_us":88,"dirs.run_cpu_time_us":245,"dirs.run_wall_time_us":1903,"drs_written":1,"lbm_read_time_us":56,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1782,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":31}
I20260812 06:17:20.653613 24977 maintenance_manager.cc:419] P 9434c5b6d7f445b486a135481139f5c9: Scheduling LogGCOp(e13e0daac18e46eaa59be223431b0896): free 133024619 bytes of WAL
I20260812 06:17:20.653870 24865 log_reader.cc:385] T e13e0daac18e46eaa59be223431b0896: removed 13 log segments from log reader
I20260812 06:17:20.653918 24865 log.cc:1079] T e13e0daac18e46eaa59be223431b0896 P 9434c5b6d7f445b486a135481139f5c9: Deleting log segment in path: /tmp/dist-test-taskULGn6B/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515435658806-24703-0/minicluster-data/ts-0-root/wals/e13e0daac18e46eaa59be223431b0896/wal-000000026 (ops 123-127)
I20260812 06:17:20.653947 24865 log.cc:1079] T e13e0daac18e46eaa59be223431b0896 P 9434c5b6d7f445b486a135481139f5c9: Deleting log segment in path: /tmp/dist-test-taskULGn6B/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515435658806-24703-0/minicluster-data/ts-0-root/wals/e13e0daac18e46eaa59be223431b0896/wal-000000027 (ops 128-132)
I20260812 06:17:20.654009 24865 log.cc:1079] T e13e0daac18e46eaa59be223431b0896 P 9434c5b6d7f445b486a135481139f5c9: Deleting log segment in path: /tmp/dist-test-taskULGn6B/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515435658806-24703-0/minicluster-data/ts-0-root/wals/e13e0daac18e46eaa59be223431b0896/wal-000000028 (ops 133-137)
I20260812 06:17:20.654052 24865 log.cc:1079] T e13e0daac18e46eaa59be223431b0896 P 9434c5b6d7f445b486a135481139f5c9: Deleting log segment in path: /tmp/dist-test-taskULGn6B/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515435658806-24703-0/minicluster-data/ts-0-root/wals/e13e0daac18e46eaa59be223431b0896/wal-000000029 (ops 138-142)
I20260812 06:17:20.654126 24865 log.cc:1079] T e13e0daac18e46eaa59be223431b0896 P 9434c5b6d7f445b486a135481139f5c9: Deleting log segment in path: /tmp/dist-test-taskULGn6B/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515435658806-24703-0/minicluster-data/ts-0-root/wals/e13e0daac18e46eaa59be223431b0896/wal-000000030 (ops 143-147)
I20260812 06:17:20.654179 24865 log.cc:1079] T e13e0daac18e46eaa59be223431b0896 P 9434c5b6d7f445b486a135481139f5c9: Deleting log segment in path: /tmp/dist-test-taskULGn6B/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515435658806-24703-0/minicluster-data/ts-0-root/wals/e13e0daac18e46eaa59be223431b0896/wal-000000031 (ops 148-152)
I20260812 06:17:20.654219 24865 log.cc:1079] T e13e0daac18e46eaa59be223431b0896 P 9434c5b6d7f445b486a135481139f5c9: Deleting log segment in path: /tmp/dist-test-taskULGn6B/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515435658806-24703-0/minicluster-data/ts-0-root/wals/e13e0daac18e46eaa59be223431b0896/wal-000000032 (ops 153-156)
I20260812 06:17:20.654280 24865 log.cc:1079] T e13e0daac18e46eaa59be223431b0896 P 9434c5b6d7f445b486a135481139f5c9: Deleting log segment in path: /tmp/dist-test-taskULGn6B/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515435658806-24703-0/minicluster-data/ts-0-root/wals/e13e0daac18e46eaa59be223431b0896/wal-000000033 (ops 157-161)
I20260812 06:17:20.654320 24865 log.cc:1079] T e13e0daac18e46eaa59be223431b0896 P 9434c5b6d7f445b486a135481139f5c9: Deleting log segment in path: /tmp/dist-test-taskULGn6B/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515435658806-24703-0/minicluster-data/ts-0-root/wals/e13e0daac18e46eaa59be223431b0896/wal-000000034 (ops 162-166)
I20260812 06:17:20.654361 24865 log.cc:1079] T e13e0daac18e46eaa59be223431b0896 P 9434c5b6d7f445b486a135481139f5c9: Deleting log segment in path: /tmp/dist-test-taskULGn6B/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515435658806-24703-0/minicluster-data/ts-0-root/wals/e13e0daac18e46eaa59be223431b0896/wal-000000035 (ops 167-171)
I20260812 06:17:20.654399 24865 log.cc:1079] T e13e0daac18e46eaa59be223431b0896 P 9434c5b6d7f445b486a135481139f5c9: Deleting log segment in path: /tmp/dist-test-taskULGn6B/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515435658806-24703-0/minicluster-data/ts-0-root/wals/e13e0daac18e46eaa59be223431b0896/wal-000000036 (ops 172-176)
I20260812 06:17:20.654443 24865 log.cc:1079] T e13e0daac18e46eaa59be223431b0896 P 9434c5b6d7f445b486a135481139f5c9: Deleting log segment in path: /tmp/dist-test-taskULGn6B/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515435658806-24703-0/minicluster-data/ts-0-root/wals/e13e0daac18e46eaa59be223431b0896/wal-000000037 (ops 177-181)
I20260812 06:17:20.654484 24865 log.cc:1079] T e13e0daac18e46eaa59be223431b0896 P 9434c5b6d7f445b486a135481139f5c9: Deleting log segment in path: /tmp/dist-test-taskULGn6B/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515435658806-24703-0/minicluster-data/ts-0-root/wals/e13e0daac18e46eaa59be223431b0896/wal-000000038 (ops 182-186)
I20260812 06:17:20.686412 24865 maintenance_manager.cc:643] P 9434c5b6d7f445b486a135481139f5c9: LogGCOp(e13e0daac18e46eaa59be223431b0896) complete. Timing: real 0.033s	user 0.000s	sys 0.032s Metrics: {}
I20260812 06:17:20.686869 24977 maintenance_manager.cc:419] P 9434c5b6d7f445b486a135481139f5c9: Scheduling UndoDeltaBlockGCOp(e13e0daac18e46eaa59be223431b0896): 481 bytes on disk
I20260812 06:17:20.687366 24865 maintenance_manager.cc:643] P 9434c5b6d7f445b486a135481139f5c9: UndoDeltaBlockGCOp(e13e0daac18e46eaa59be223431b0896) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":55,"lbm_reads_lt_1ms":4}
I20260812 06:17:20.687912 24977 maintenance_manager.cc:419] P 9434c5b6d7f445b486a135481139f5c9: Scheduling FlushDeltaMemStoresOp(e13e0daac18e46eaa59be223431b0896): perf score=3.181125
I20260812 06:17:20.715583 24865 maintenance_manager.cc:643] P 9434c5b6d7f445b486a135481139f5c9: FlushDeltaMemStoresOp(e13e0daac18e46eaa59be223431b0896) complete. Timing: real 0.027s	user 0.012s	sys 0.002s Metrics: {"bytes_written":4512903,"delete_count":0,"lbm_write_time_us":5976,"lbm_writes_lt_1ms":113,"reinsert_count":0,"update_count":550}
I20260812 06:17:20.716073 24977 maintenance_manager.cc:419] P 9434c5b6d7f445b486a135481139f5c9: Scheduling FlushDeltaMemStoresOp(e13e0daac18e46eaa59be223431b0896): perf score=2.188937
I20260812 06:17:20.730346 24865 maintenance_manager.cc:643] P 9434c5b6d7f445b486a135481139f5c9: FlushDeltaMemStoresOp(e13e0daac18e46eaa59be223431b0896) complete. Timing: real 0.014s	user 0.011s	sys 0.003s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":5590,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:17:20.730943 24977 maintenance_manager.cc:419] P 9434c5b6d7f445b486a135481139f5c9: Scheduling MajorDeltaCompactionOp(e13e0daac18e46eaa59be223431b0896): perf score=1.000000
I20260812 06:17:20.983249 24865 maintenance_manager.cc:643] P 9434c5b6d7f445b486a135481139f5c9: MajorDeltaCompactionOp(e13e0daac18e46eaa59be223431b0896) complete. Timing: real 0.252s	user 0.160s	sys 0.083s Metrics: {"cfile_cache_miss":734,"cfile_cache_miss_bytes":32938775,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":260,"lbm_read_time_us":17908,"lbm_reads_lt_1ms":774,"lbm_write_time_us":40841,"lbm_writes_lt_1ms":743,"mutex_wait_us":78,"peak_mem_usage":87969044,"reinsert_count":0,"thread_start_us":85,"threads_started":1,"update_count":3500}
I20260812 06:17:20.984061 24977 maintenance_manager.cc:419] P 9434c5b6d7f445b486a135481139f5c9: Scheduling FlushDeltaMemStoresOp(e13e0daac18e46eaa59be223431b0896): perf score=18.063937
I20260812 06:17:21.049175 24865 maintenance_manager.cc:643] P 9434c5b6d7f445b486a135481139f5c9: FlushDeltaMemStoresOp(e13e0daac18e46eaa59be223431b0896) complete. Timing: real 0.065s	user 0.030s	sys 0.032s Metrics: {"bytes_written":20512316,"delete_count":0,"lbm_write_time_us":30220,"lbm_writes_lt_1ms":503,"reinsert_count":0,"update_count":2500}
I20260812 06:17:21.049741 24977 maintenance_manager.cc:419] P 9434c5b6d7f445b486a135481139f5c9: Scheduling MajorDeltaCompactionOp(e13e0daac18e46eaa59be223431b0896): perf score=1.000000
I20260812 06:17:21.064672 24703 heavy-update-compaction-itest.cc:229] Time spent updating: real 5.105s	user 1.785s	sys 0.203s
I20260812 06:17:21.135356 24703 heavy-update-compaction-itest.cc:265] Time spent scanning: real 0.070s	user 0.005s	sys 0.000s
I20260812 06:17:21.136176 24703 tablet_server.cc:179] TabletServer@127.24.31.193:0 shutting down...
I20260812 06:17:21.204514 24865 maintenance_manager.cc:643] P 9434c5b6d7f445b486a135481139f5c9: MajorDeltaCompactionOp(e13e0daac18e46eaa59be223431b0896) complete. Timing: real 0.155s	user 0.108s	sys 0.046s Metrics: {"cfile_cache_miss":531,"cfile_cache_miss_bytes":24733607,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":1,"delta_iterators_relevant":1,"dirs.queue_time_us":452,"lbm_read_time_us":12427,"lbm_reads_lt_1ms":563,"lbm_write_time_us":28286,"lbm_writes_lt_1ms":543,"mutex_wait_us":42,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":9088,"update_count":2500}
I20260812 06:17:21.205291 24703 ts_tablet_manager.cc:1507] Shutting down tablet manager...
I20260812 06:17:21.205672 24703 tablet_replica.cc:333] T e13e0daac18e46eaa59be223431b0896 P 9434c5b6d7f445b486a135481139f5c9: stopping tablet replica
I20260812 06:17:21.205912 24703 raft_consensus.cc:2243] T e13e0daac18e46eaa59be223431b0896 P 9434c5b6d7f445b486a135481139f5c9 [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:17:21.206151 24703 raft_consensus.cc:2272] T e13e0daac18e46eaa59be223431b0896 P 9434c5b6d7f445b486a135481139f5c9 [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:17:21.223063 24703 tablet_server.cc:196] TabletServer@127.24.31.193:0 shutdown complete.
I20260812 06:17:21.250739 24703 master.cc:562] Master@127.24.31.254:46441 shutting down...
I20260812 06:17:21.254848 24703 raft_consensus.cc:2243] T 00000000000000000000000000000000 P f7aa4811d30d4863b06dc8d1bfbab979 [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:17:21.255050 24703 raft_consensus.cc:2272] T 00000000000000000000000000000000 P f7aa4811d30d4863b06dc8d1bfbab979 [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:17:21.255118 24703 tablet_replica.cc:333] T 00000000000000000000000000000000 P f7aa4811d30d4863b06dc8d1bfbab979: stopping tablet replica
I20260812 06:17:21.267556 24703 master.cc:584] Master@127.24.31.254:46441 shutdown complete.
[       OK ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/0 (5698 ms)
[ RUN      ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/1
I20260812 06:17:21.382851 24703 internal_mini_cluster.cc:156] Creating distributed mini masters. Addrs: 127.24.31.254:38507
I20260812 06:17:21.383212 24703 file_cache.cc:504] Constructed file cache file cache with capacity 419430
I20260812 06:17:21.385484 24703 server_base.cc:1061] running on GCE node
W20260812 06:17:21.385565 25041 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:21.385586 25039 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:21.385502 25037 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:21.385849 24703 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:17:21.385895 24703 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:21.385910 24703 hybrid_clock.cc:648] HybridClock initialized: now 1786515441385910 us; error 0 us; skew 500 ppm
I20260812 06:17:21.386761 24703 webserver.cc:533] Webserver started at http://127.24.31.254:39531/ using document root <none> and password file <none>
I20260812 06:17:21.386962 24703 fs_manager.cc:362] Metadata directory not provided
I20260812 06:17:21.387009 24703 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:17:21.387109 24703 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:17:21.387509 24703 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskULGn6B/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515435658806-24703-0/minicluster-data/master-0-root/instance:
uuid: "8ecb5599b57b4c1e8290a84f69890d18"
format_stamp: "Formatted at 2026-08-12 06:17:21 on dist-test-slave-7nm7"
I20260812 06:17:21.389096 24703 fs_manager.cc:696] Time spent creating directory manager: real 0.001s	user 0.002s	sys 0.000s
I20260812 06:17:21.390038 25047 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:21.390344 24703 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.001s	sys 0.000s
I20260812 06:17:21.390425 24703 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskULGn6B/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515435658806-24703-0/minicluster-data/master-0-root
uuid: "8ecb5599b57b4c1e8290a84f69890d18"
format_stamp: "Formatted at 2026-08-12 06:17:21 on dist-test-slave-7nm7"
I20260812 06:17:21.390488 24703 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskULGn6B/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515435658806-24703-0/minicluster-data/master-0-root
metadata directory: /tmp/dist-test-taskULGn6B/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515435658806-24703-0/minicluster-data/master-0-root
1 data directories: /tmp/dist-test-taskULGn6B/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515435658806-24703-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:21.408341 24703 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:17:21.408761 24703 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:17:21.413326 24703 rpc_server.cc:307] RPC server started. Bound to: 127.24.31.254:38507
I20260812 06:17:21.418788 25137 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.24.31.254:38507 every 8 connection(s)
I20260812 06:17:21.419268 25138 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:21.421131 25138 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P 8ecb5599b57b4c1e8290a84f69890d18: Bootstrap starting.
I20260812 06:17:21.421902 25138 tablet_bootstrap.cc:654] T 00000000000000000000000000000000 P 8ecb5599b57b4c1e8290a84f69890d18: Neither blocks nor log segments found. Creating new log.
I20260812 06:17:21.422928 25138 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P 8ecb5599b57b4c1e8290a84f69890d18: No bootstrap required, opened a new log
I20260812 06:17:21.423334 25138 raft_consensus.cc:359] T 00000000000000000000000000000000 P 8ecb5599b57b4c1e8290a84f69890d18 [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "8ecb5599b57b4c1e8290a84f69890d18" member_type: VOTER }
I20260812 06:17:21.423442 25138 raft_consensus.cc:385] T 00000000000000000000000000000000 P 8ecb5599b57b4c1e8290a84f69890d18 [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:17:21.423491 25138 raft_consensus.cc:740] T 00000000000000000000000000000000 P 8ecb5599b57b4c1e8290a84f69890d18 [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: 8ecb5599b57b4c1e8290a84f69890d18, State: Initialized, Role: FOLLOWER
I20260812 06:17:21.423641 25138 consensus_queue.cc:260] T 00000000000000000000000000000000 P 8ecb5599b57b4c1e8290a84f69890d18 [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: "8ecb5599b57b4c1e8290a84f69890d18" member_type: VOTER }
I20260812 06:17:21.423739 25138 raft_consensus.cc:399] T 00000000000000000000000000000000 P 8ecb5599b57b4c1e8290a84f69890d18 [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:17:21.423787 25138 raft_consensus.cc:493] T 00000000000000000000000000000000 P 8ecb5599b57b4c1e8290a84f69890d18 [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:17:21.423843 25138 raft_consensus.cc:3060] T 00000000000000000000000000000000 P 8ecb5599b57b4c1e8290a84f69890d18 [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:17:21.424515 25138 raft_consensus.cc:515] T 00000000000000000000000000000000 P 8ecb5599b57b4c1e8290a84f69890d18 [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "8ecb5599b57b4c1e8290a84f69890d18" member_type: VOTER }
I20260812 06:17:21.424672 25138 leader_election.cc:304] T 00000000000000000000000000000000 P 8ecb5599b57b4c1e8290a84f69890d18 [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: 8ecb5599b57b4c1e8290a84f69890d18; no voters: 
I20260812 06:17:21.424868 25138 leader_election.cc:290] T 00000000000000000000000000000000 P 8ecb5599b57b4c1e8290a84f69890d18 [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:17:21.425001 25143 raft_consensus.cc:2804] T 00000000000000000000000000000000 P 8ecb5599b57b4c1e8290a84f69890d18 [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:17:21.425256 25143 raft_consensus.cc:697] T 00000000000000000000000000000000 P 8ecb5599b57b4c1e8290a84f69890d18 [term 1 LEADER]: Becoming Leader. State: Replica: 8ecb5599b57b4c1e8290a84f69890d18, State: Running, Role: LEADER
I20260812 06:17:21.425360 25138 sys_catalog.cc:565] T 00000000000000000000000000000000 P 8ecb5599b57b4c1e8290a84f69890d18 [sys.catalog]: configured and running, proceeding with master startup.
I20260812 06:17:21.425436 25143 consensus_queue.cc:237] T 00000000000000000000000000000000 P 8ecb5599b57b4c1e8290a84f69890d18 [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: "8ecb5599b57b4c1e8290a84f69890d18" member_type: VOTER }
I20260812 06:17:21.426007 25145 sys_catalog.cc:455] T 00000000000000000000000000000000 P 8ecb5599b57b4c1e8290a84f69890d18 [sys.catalog]: SysCatalogTable state changed. Reason: New leader 8ecb5599b57b4c1e8290a84f69890d18. Latest consensus state: current_term: 1 leader_uuid: "8ecb5599b57b4c1e8290a84f69890d18" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "8ecb5599b57b4c1e8290a84f69890d18" member_type: VOTER } }
I20260812 06:17:21.425982 25144 sys_catalog.cc:455] T 00000000000000000000000000000000 P 8ecb5599b57b4c1e8290a84f69890d18 [sys.catalog]: SysCatalogTable state changed. Reason: RaftConsensus started. Latest consensus state: current_term: 1 leader_uuid: "8ecb5599b57b4c1e8290a84f69890d18" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "8ecb5599b57b4c1e8290a84f69890d18" member_type: VOTER } }
I20260812 06:17:21.426283 25144 sys_catalog.cc:458] T 00000000000000000000000000000000 P 8ecb5599b57b4c1e8290a84f69890d18 [sys.catalog]: This master's current role is: LEADER
I20260812 06:17:21.426599 25145 sys_catalog.cc:458] T 00000000000000000000000000000000 P 8ecb5599b57b4c1e8290a84f69890d18 [sys.catalog]: This master's current role is: LEADER
I20260812 06:17:21.426657 25156 catalog_manager.cc:1511] Loading table and tablet metadata into memory...
I20260812 06:17:21.427712 25156 catalog_manager.cc:1520] Initializing Kudu cluster ID...
I20260812 06:17:21.428023 24703 internal_mini_cluster.cc:184] Waiting to initialize catalog manager on master 0
I20260812 06:17:21.429647 25156 catalog_manager.cc:1383] Generated new cluster ID: 69784ea4a8e14070849176589da70eb8
I20260812 06:17:21.429714 25156 catalog_manager.cc:1531] Initializing Kudu internal certificate authority...
I20260812 06:17:21.447712 25156 catalog_manager.cc:1406] Generated new certificate authority record
I20260812 06:17:21.448352 25156 catalog_manager.cc:1540] Loading token signing keys...
I20260812 06:17:21.466956 25156 catalog_manager.cc:6092] T 00000000000000000000000000000000 P 8ecb5599b57b4c1e8290a84f69890d18: Generated new TSK 0
I20260812 06:17:21.467196 25156 catalog_manager.cc:1550] Initializing in-progress tserver states...
I20260812 06:17:21.492815 24703 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:17:21.494863 25176 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:21.494923 25189 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:21.494874 25179 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:21.495190 24703 server_base.cc:1061] running on GCE node
I20260812 06:17:21.495375 24703 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:17:21.495428 24703 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:21.495445 24703 hybrid_clock.cc:648] HybridClock initialized: now 1786515441495444 us; error 0 us; skew 500 ppm
I20260812 06:17:21.496351 24703 webserver.cc:533] Webserver started at http://127.24.31.193:45425/ using document root <none> and password file <none>
I20260812 06:17:21.496541 24703 fs_manager.cc:362] Metadata directory not provided
I20260812 06:17:21.496615 24703 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:17:21.496702 24703 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:17:21.497103 24703 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskULGn6B/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515435658806-24703-0/minicluster-data/ts-0-root/instance:
uuid: "a3b12bef41cd4902b875e8357c4dcedb"
format_stamp: "Formatted at 2026-08-12 06:17:21 on dist-test-slave-7nm7"
I20260812 06:17:21.498726 24703 fs_manager.cc:696] Time spent creating directory manager: real 0.001s	user 0.002s	sys 0.000s
I20260812 06:17:21.499754 25200 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:21.500053 24703 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.001s	sys 0.000s
I20260812 06:17:21.500125 24703 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskULGn6B/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515435658806-24703-0/minicluster-data/ts-0-root
uuid: "a3b12bef41cd4902b875e8357c4dcedb"
format_stamp: "Formatted at 2026-08-12 06:17:21 on dist-test-slave-7nm7"
I20260812 06:17:21.500219 24703 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskULGn6B/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515435658806-24703-0/minicluster-data/ts-0-root
metadata directory: /tmp/dist-test-taskULGn6B/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515435658806-24703-0/minicluster-data/ts-0-root
1 data directories: /tmp/dist-test-taskULGn6B/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515435658806-24703-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:21.515040 24703 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:17:21.515494 24703 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:17:21.515833 24703 txn_system_client.cc:432] TxnSystemClient initialization is disabled...
I20260812 06:17:21.516315 24703 ts_tablet_manager.cc:585] Loaded tablet metadata (0 total tablets, 0 live tablets)
I20260812 06:17:21.516355 24703 ts_tablet_manager.cc:531] Time spent load tablet metadata: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:17:21.516387 24703 ts_tablet_manager.cc:616] Registered 0 tablets
I20260812 06:17:21.516403 24703 ts_tablet_manager.cc:595] Time spent register tablets: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:17:21.521436 24703 rpc_server.cc:307] RPC server started. Bound to: 127.24.31.193:33725
I20260812 06:17:21.521471 25307 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.24.31.193:33725 every 8 connection(s)
I20260812 06:17:21.529935 25308 heartbeater.cc:344] Connected to a master server at 127.24.31.254:38507
I20260812 06:17:21.530067 25308 heartbeater.cc:461] Registering TS with master...
I20260812 06:17:21.530356 25308 heartbeater.cc:507] Master 127.24.31.254:38507 requested a full tablet report, sending...
I20260812 06:17:21.531140 25078 ts_manager.cc:194] Registered new tserver with Master: a3b12bef41cd4902b875e8357c4dcedb (127.24.31.193:33725)
I20260812 06:17:21.531937 25078 master_service.cc:502] Signed X509 certificate for tserver {username='slave'} at 127.0.0.1:32910
I20260812 06:17:21.532217 24703 internal_mini_cluster.cc:371] 1 TS(s) registered with all masters after 0.010346301s
I20260812 06:17:21.539978 25078 catalog_manager.cc:2283] Servicing CreateTable request from {username='slave'} at 127.0.0.1:32912:
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:21.549680 25248 tablet_service.cc:1511] Processing CreateTablet for tablet 84872f0dcd63457e8c9e1ee908cb00d9 (DEFAULT_TABLE table=heavy-update-compaction-test [id=d2b7425c80bf4c88badd75cd1cc7b3c1]), partition=
I20260812 06:17:21.549940 25248 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet 84872f0dcd63457e8c9e1ee908cb00d9. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:17:21.551945 25330 tablet_bootstrap.cc:492] T 84872f0dcd63457e8c9e1ee908cb00d9 P a3b12bef41cd4902b875e8357c4dcedb: Bootstrap starting.
I20260812 06:17:21.552726 25330 tablet_bootstrap.cc:654] T 84872f0dcd63457e8c9e1ee908cb00d9 P a3b12bef41cd4902b875e8357c4dcedb: Neither blocks nor log segments found. Creating new log.
I20260812 06:17:21.553872 25330 tablet_bootstrap.cc:492] T 84872f0dcd63457e8c9e1ee908cb00d9 P a3b12bef41cd4902b875e8357c4dcedb: No bootstrap required, opened a new log
I20260812 06:17:21.554004 25330 ts_tablet_manager.cc:1403] T 84872f0dcd63457e8c9e1ee908cb00d9 P a3b12bef41cd4902b875e8357c4dcedb: Time spent bootstrapping tablet: real 0.002s	user 0.001s	sys 0.000s
I20260812 06:17:21.554646 25330 raft_consensus.cc:359] T 84872f0dcd63457e8c9e1ee908cb00d9 P a3b12bef41cd4902b875e8357c4dcedb [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "a3b12bef41cd4902b875e8357c4dcedb" member_type: VOTER last_known_addr { host: "127.24.31.193" port: 33725 } }
I20260812 06:17:21.554762 25330 raft_consensus.cc:385] T 84872f0dcd63457e8c9e1ee908cb00d9 P a3b12bef41cd4902b875e8357c4dcedb [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:17:21.554809 25330 raft_consensus.cc:740] T 84872f0dcd63457e8c9e1ee908cb00d9 P a3b12bef41cd4902b875e8357c4dcedb [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: a3b12bef41cd4902b875e8357c4dcedb, State: Initialized, Role: FOLLOWER
I20260812 06:17:21.554984 25330 consensus_queue.cc:260] T 84872f0dcd63457e8c9e1ee908cb00d9 P a3b12bef41cd4902b875e8357c4dcedb [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: "a3b12bef41cd4902b875e8357c4dcedb" member_type: VOTER last_known_addr { host: "127.24.31.193" port: 33725 } }
I20260812 06:17:21.555142 25330 raft_consensus.cc:399] T 84872f0dcd63457e8c9e1ee908cb00d9 P a3b12bef41cd4902b875e8357c4dcedb [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:17:21.555213 25330 raft_consensus.cc:493] T 84872f0dcd63457e8c9e1ee908cb00d9 P a3b12bef41cd4902b875e8357c4dcedb [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:17:21.555274 25330 raft_consensus.cc:3060] T 84872f0dcd63457e8c9e1ee908cb00d9 P a3b12bef41cd4902b875e8357c4dcedb [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:17:21.556008 25330 raft_consensus.cc:515] T 84872f0dcd63457e8c9e1ee908cb00d9 P a3b12bef41cd4902b875e8357c4dcedb [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "a3b12bef41cd4902b875e8357c4dcedb" member_type: VOTER last_known_addr { host: "127.24.31.193" port: 33725 } }
I20260812 06:17:21.556175 25330 leader_election.cc:304] T 84872f0dcd63457e8c9e1ee908cb00d9 P a3b12bef41cd4902b875e8357c4dcedb [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: a3b12bef41cd4902b875e8357c4dcedb; no voters: 
I20260812 06:17:21.556394 25330 leader_election.cc:290] T 84872f0dcd63457e8c9e1ee908cb00d9 P a3b12bef41cd4902b875e8357c4dcedb [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:17:21.556541 25333 raft_consensus.cc:2804] T 84872f0dcd63457e8c9e1ee908cb00d9 P a3b12bef41cd4902b875e8357c4dcedb [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:17:21.556757 25330 ts_tablet_manager.cc:1434] T 84872f0dcd63457e8c9e1ee908cb00d9 P a3b12bef41cd4902b875e8357c4dcedb: Time spent starting tablet: real 0.003s	user 0.003s	sys 0.000s
I20260812 06:17:21.556770 25308 heartbeater.cc:499] Master 127.24.31.254:38507 was elected leader, sending a full tablet report...
I20260812 06:17:21.556772 25333 raft_consensus.cc:697] T 84872f0dcd63457e8c9e1ee908cb00d9 P a3b12bef41cd4902b875e8357c4dcedb [term 1 LEADER]: Becoming Leader. State: Replica: a3b12bef41cd4902b875e8357c4dcedb, State: Running, Role: LEADER
I20260812 06:17:21.557003 25333 consensus_queue.cc:237] T 84872f0dcd63457e8c9e1ee908cb00d9 P a3b12bef41cd4902b875e8357c4dcedb [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: "a3b12bef41cd4902b875e8357c4dcedb" member_type: VOTER last_known_addr { host: "127.24.31.193" port: 33725 } }
I20260812 06:17:21.558405 25078 catalog_manager.cc:5719] T 84872f0dcd63457e8c9e1ee908cb00d9 P a3b12bef41cd4902b875e8357c4dcedb reported cstate change: term changed from 0 to 1, leader changed from <none> to a3b12bef41cd4902b875e8357c4dcedb (127.24.31.193). New cstate: current_term: 1 leader_uuid: "a3b12bef41cd4902b875e8357c4dcedb" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "a3b12bef41cd4902b875e8357c4dcedb" member_type: VOTER last_known_addr { host: "127.24.31.193" port: 33725 } health_report { overall_health: HEALTHY } } }
I20260812 06:17:21.620464 24703 heavy-update-compaction-itest.cc:215] Time spent inserting: real 0.056s	user 0.014s	sys 0.010s
I20260812 06:17:21.772401 25312 maintenance_manager.cc:419] P a3b12bef41cd4902b875e8357c4dcedb: Scheduling FlushMRSOp(84872f0dcd63457e8c9e1ee908cb00d9): perf score=19.054940
I20260812 06:17:21.944151 25207 maintenance_manager.cc:643] P a3b12bef41cd4902b875e8357c4dcedb: FlushMRSOp(84872f0dcd63457e8c9e1ee908cb00d9) complete. Timing: real 0.171s	user 0.114s	sys 0.055s Metrics: {"bytes_written":12307490,"cfile_init":1,"delete_count":0,"dirs.queue_time_us":76,"dirs.run_cpu_time_us":204,"dirs.run_wall_time_us":741,"drs_written":1,"lbm_read_time_us":48,"lbm_reads_lt_1ms":4,"lbm_write_time_us":44706,"lbm_writes_lt_1ms":757,"peak_mem_usage":0,"reinsert_count":0,"rows_written":104,"update_count":1500}
I20260812 06:17:21.944871 25312 maintenance_manager.cc:419] P a3b12bef41cd4902b875e8357c4dcedb: Scheduling LogGCOp(84872f0dcd63457e8c9e1ee908cb00d9): free 20743831 bytes of WAL
I20260812 06:17:21.945109 25207 log_reader.cc:385] T 84872f0dcd63457e8c9e1ee908cb00d9: removed 2 log segments from log reader
I20260812 06:17:21.945154 25207 log.cc:1079] T 84872f0dcd63457e8c9e1ee908cb00d9 P a3b12bef41cd4902b875e8357c4dcedb: Deleting log segment in path: /tmp/dist-test-taskULGn6B/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515435658806-24703-0/minicluster-data/ts-0-root/wals/84872f0dcd63457e8c9e1ee908cb00d9/wal-000000001 (ops 1-6)
I20260812 06:17:21.945205 25207 log.cc:1079] T 84872f0dcd63457e8c9e1ee908cb00d9 P a3b12bef41cd4902b875e8357c4dcedb: Deleting log segment in path: /tmp/dist-test-taskULGn6B/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515435658806-24703-0/minicluster-data/ts-0-root/wals/84872f0dcd63457e8c9e1ee908cb00d9/wal-000000002 (ops 7-11)
I20260812 06:17:21.949796 25207 maintenance_manager.cc:643] P a3b12bef41cd4902b875e8357c4dcedb: LogGCOp(84872f0dcd63457e8c9e1ee908cb00d9) complete. Timing: real 0.005s	user 0.000s	sys 0.001s Metrics: {}
I20260812 06:17:21.950150 25312 maintenance_manager.cc:419] P a3b12bef41cd4902b875e8357c4dcedb: Scheduling UndoDeltaBlockGCOp(84872f0dcd63457e8c9e1ee908cb00d9): 16411395 bytes on disk
I20260812 06:17:21.950636 25207 maintenance_manager.cc:643] P a3b12bef41cd4902b875e8357c4dcedb: UndoDeltaBlockGCOp(84872f0dcd63457e8c9e1ee908cb00d9) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":58,"lbm_reads_lt_1ms":4}
I20260812 06:17:21.951032 25312 maintenance_manager.cc:419] P a3b12bef41cd4902b875e8357c4dcedb: Scheduling FlushDeltaMemStoresOp(84872f0dcd63457e8c9e1ee908cb00d9): perf score=2.188937
I20260812 06:17:21.963935 25207 maintenance_manager.cc:643] P a3b12bef41cd4902b875e8357c4dcedb: FlushDeltaMemStoresOp(84872f0dcd63457e8c9e1ee908cb00d9) complete. Timing: real 0.013s	user 0.006s	sys 0.005s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4741,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:21.964520 25312 maintenance_manager.cc:419] P a3b12bef41cd4902b875e8357c4dcedb: Scheduling MajorDeltaCompactionOp(84872f0dcd63457e8c9e1ee908cb00d9): perf score=1.000000
I20260812 06:17:22.119966 25207 maintenance_manager.cc:643] P a3b12bef41cd4902b875e8357c4dcedb: MajorDeltaCompactionOp(84872f0dcd63457e8c9e1ee908cb00d9) complete. Timing: real 0.155s	user 0.103s	sys 0.051s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672277,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":280,"lbm_read_time_us":12113,"lbm_reads_lt_1ms":464,"lbm_write_time_us":26352,"lbm_writes_lt_1ms":443,"mutex_wait_us":39,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":2944,"thread_start_us":355,"threads_started":5,"update_count":2000}
I20260812 06:17:22.120645 25312 maintenance_manager.cc:419] P a3b12bef41cd4902b875e8357c4dcedb: Scheduling FlushDeltaMemStoresOp(84872f0dcd63457e8c9e1ee908cb00d9): perf score=10.126437
I20260812 06:17:22.158269 25207 maintenance_manager.cc:643] P a3b12bef41cd4902b875e8357c4dcedb: FlushDeltaMemStoresOp(84872f0dcd63457e8c9e1ee908cb00d9) complete. Timing: real 0.037s	user 0.021s	sys 0.016s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":16439,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:17:22.158825 25312 maintenance_manager.cc:419] P a3b12bef41cd4902b875e8357c4dcedb: Scheduling FlushDeltaMemStoresOp(84872f0dcd63457e8c9e1ee908cb00d9): perf score=2.188937
I20260812 06:17:22.170771 25207 maintenance_manager.cc:643] P a3b12bef41cd4902b875e8357c4dcedb: FlushDeltaMemStoresOp(84872f0dcd63457e8c9e1ee908cb00d9) complete. Timing: real 0.012s	user 0.003s	sys 0.009s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4585,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:22.171407 25312 maintenance_manager.cc:419] P a3b12bef41cd4902b875e8357c4dcedb: Scheduling MajorDeltaCompactionOp(84872f0dcd63457e8c9e1ee908cb00d9): perf score=1.000000
I20260812 06:17:22.309752 25207 maintenance_manager.cc:643] P a3b12bef41cd4902b875e8357c4dcedb: MajorDeltaCompactionOp(84872f0dcd63457e8c9e1ee908cb00d9) complete. Timing: real 0.138s	user 0.117s	sys 0.020s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672277,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":2081,"lbm_read_time_us":10742,"lbm_reads_lt_1ms":472,"lbm_write_time_us":27566,"lbm_writes_lt_1ms":443,"mutex_wait_us":761,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":14720,"update_count":2000}
I20260812 06:17:22.310596 25312 maintenance_manager.cc:419] P a3b12bef41cd4902b875e8357c4dcedb: Scheduling FlushDeltaMemStoresOp(84872f0dcd63457e8c9e1ee908cb00d9): perf score=10.126437
I20260812 06:17:22.356796 25207 maintenance_manager.cc:643] P a3b12bef41cd4902b875e8357c4dcedb: FlushDeltaMemStoresOp(84872f0dcd63457e8c9e1ee908cb00d9) complete. Timing: real 0.046s	user 0.033s	sys 0.008s Metrics: {"bytes_written":12307489,"delete_count":0,"lbm_write_time_us":20788,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:17:22.357306 25312 maintenance_manager.cc:419] P a3b12bef41cd4902b875e8357c4dcedb: Scheduling FlushDeltaMemStoresOp(84872f0dcd63457e8c9e1ee908cb00d9): perf score=2.188937
I20260812 06:17:22.369585 25207 maintenance_manager.cc:643] P a3b12bef41cd4902b875e8357c4dcedb: FlushDeltaMemStoresOp(84872f0dcd63457e8c9e1ee908cb00d9) complete. Timing: real 0.012s	user 0.006s	sys 0.003s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4457,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:22.370291 25312 maintenance_manager.cc:419] P a3b12bef41cd4902b875e8357c4dcedb: Scheduling MajorDeltaCompactionOp(84872f0dcd63457e8c9e1ee908cb00d9): perf score=1.000000
I20260812 06:17:22.505369 25207 maintenance_manager.cc:643] P a3b12bef41cd4902b875e8357c4dcedb: MajorDeltaCompactionOp(84872f0dcd63457e8c9e1ee908cb00d9) complete. Timing: real 0.135s	user 0.098s	sys 0.037s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672276,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":670,"lbm_read_time_us":10815,"lbm_reads_lt_1ms":472,"lbm_write_time_us":28327,"lbm_writes_lt_1ms":443,"mutex_wait_us":109,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":14464,"update_count":2000}
I20260812 06:17:22.506085 25312 maintenance_manager.cc:419] P a3b12bef41cd4902b875e8357c4dcedb: Scheduling FlushDeltaMemStoresOp(84872f0dcd63457e8c9e1ee908cb00d9): perf score=10.126437
I20260812 06:17:22.564213 25207 maintenance_manager.cc:643] P a3b12bef41cd4902b875e8357c4dcedb: FlushDeltaMemStoresOp(84872f0dcd63457e8c9e1ee908cb00d9) complete. Timing: real 0.058s	user 0.021s	sys 0.031s Metrics: {"bytes_written":12307491,"delete_count":0,"lbm_write_time_us":19140,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:17:22.564793 25312 maintenance_manager.cc:419] P a3b12bef41cd4902b875e8357c4dcedb: Scheduling FlushDeltaMemStoresOp(84872f0dcd63457e8c9e1ee908cb00d9): perf score=2.188937
I20260812 06:17:22.581619 25207 maintenance_manager.cc:643] P a3b12bef41cd4902b875e8357c4dcedb: FlushDeltaMemStoresOp(84872f0dcd63457e8c9e1ee908cb00d9) complete. Timing: real 0.017s	user 0.007s	sys 0.007s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6457,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:22.582139 25312 maintenance_manager.cc:419] P a3b12bef41cd4902b875e8357c4dcedb: Scheduling MajorDeltaCompactionOp(84872f0dcd63457e8c9e1ee908cb00d9): perf score=1.000000
I20260812 06:17:22.743527 25207 maintenance_manager.cc:643] P a3b12bef41cd4902b875e8357c4dcedb: MajorDeltaCompactionOp(84872f0dcd63457e8c9e1ee908cb00d9) complete. Timing: real 0.161s	user 0.099s	sys 0.061s 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":222,"lbm_read_time_us":12759,"lbm_reads_lt_1ms":472,"lbm_write_time_us":27427,"lbm_writes_lt_1ms":443,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":18816,"update_count":2000}
I20260812 06:17:22.744226 25312 maintenance_manager.cc:419] P a3b12bef41cd4902b875e8357c4dcedb: Scheduling FlushDeltaMemStoresOp(84872f0dcd63457e8c9e1ee908cb00d9): perf score=10.126437
I20260812 06:17:22.784612 25207 maintenance_manager.cc:643] P a3b12bef41cd4902b875e8357c4dcedb: FlushDeltaMemStoresOp(84872f0dcd63457e8c9e1ee908cb00d9) complete. Timing: real 0.040s	user 0.033s	sys 0.004s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":17721,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:17:22.785130 25312 maintenance_manager.cc:419] P a3b12bef41cd4902b875e8357c4dcedb: Scheduling FlushDeltaMemStoresOp(84872f0dcd63457e8c9e1ee908cb00d9): perf score=2.188937
I20260812 06:17:22.798091 25207 maintenance_manager.cc:643] P a3b12bef41cd4902b875e8357c4dcedb: FlushDeltaMemStoresOp(84872f0dcd63457e8c9e1ee908cb00d9) complete. Timing: real 0.013s	user 0.003s	sys 0.007s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4916,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:22.798570 25312 maintenance_manager.cc:419] P a3b12bef41cd4902b875e8357c4dcedb: Scheduling MajorDeltaCompactionOp(84872f0dcd63457e8c9e1ee908cb00d9): perf score=1.000000
I20260812 06:17:22.928017 25207 maintenance_manager.cc:643] P a3b12bef41cd4902b875e8357c4dcedb: MajorDeltaCompactionOp(84872f0dcd63457e8c9e1ee908cb00d9) complete. Timing: real 0.129s	user 0.103s	sys 0.026s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672277,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":277,"lbm_read_time_us":9532,"lbm_reads_lt_1ms":468,"lbm_write_time_us":26354,"lbm_writes_lt_1ms":443,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":3072,"update_count":2000}
I20260812 06:17:22.928661 25312 maintenance_manager.cc:419] P a3b12bef41cd4902b875e8357c4dcedb: Scheduling FlushDeltaMemStoresOp(84872f0dcd63457e8c9e1ee908cb00d9): perf score=10.126437
I20260812 06:17:22.972091 25207 maintenance_manager.cc:643] P a3b12bef41cd4902b875e8357c4dcedb: FlushDeltaMemStoresOp(84872f0dcd63457e8c9e1ee908cb00d9) complete. Timing: real 0.043s	user 0.034s	sys 0.008s Metrics: {"bytes_written":12307491,"delete_count":0,"lbm_write_time_us":19771,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:17:22.972569 25312 maintenance_manager.cc:419] P a3b12bef41cd4902b875e8357c4dcedb: Scheduling FlushDeltaMemStoresOp(84872f0dcd63457e8c9e1ee908cb00d9): perf score=2.188937
I20260812 06:17:22.991907 25207 maintenance_manager.cc:643] P a3b12bef41cd4902b875e8357c4dcedb: FlushDeltaMemStoresOp(84872f0dcd63457e8c9e1ee908cb00d9) complete. Timing: real 0.019s	user 0.013s	sys 0.000s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":6105,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:22.992523 25312 maintenance_manager.cc:419] P a3b12bef41cd4902b875e8357c4dcedb: Scheduling MajorDeltaCompactionOp(84872f0dcd63457e8c9e1ee908cb00d9): perf score=1.000000
I20260812 06:17:23.130756 25207 maintenance_manager.cc:643] P a3b12bef41cd4902b875e8357c4dcedb: MajorDeltaCompactionOp(84872f0dcd63457e8c9e1ee908cb00d9) complete. Timing: real 0.138s	user 0.115s	sys 0.022s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672277,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":1002,"lbm_read_time_us":9853,"lbm_reads_lt_1ms":464,"lbm_write_time_us":27342,"lbm_writes_lt_1ms":443,"mutex_wait_us":539,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":3072,"update_count":2000}
I20260812 06:17:23.131460 25312 maintenance_manager.cc:419] P a3b12bef41cd4902b875e8357c4dcedb: Scheduling FlushDeltaMemStoresOp(84872f0dcd63457e8c9e1ee908cb00d9): perf score=11.118625
I20260812 06:17:23.169036 25207 maintenance_manager.cc:643] P a3b12bef41cd4902b875e8357c4dcedb: FlushDeltaMemStoresOp(84872f0dcd63457e8c9e1ee908cb00d9) complete. Timing: real 0.037s	user 0.019s	sys 0.014s Metrics: {"bytes_written":12717736,"delete_count":0,"lbm_write_time_us":15713,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:17:23.169513 25312 maintenance_manager.cc:419] P a3b12bef41cd4902b875e8357c4dcedb: Scheduling FlushDeltaMemStoresOp(84872f0dcd63457e8c9e1ee908cb00d9): perf score=2.188937
I20260812 06:17:23.183763 25207 maintenance_manager.cc:643] P a3b12bef41cd4902b875e8357c4dcedb: FlushDeltaMemStoresOp(84872f0dcd63457e8c9e1ee908cb00d9) complete. Timing: real 0.014s	user 0.012s	sys 0.000s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":5525,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:17:23.184355 25312 maintenance_manager.cc:419] P a3b12bef41cd4902b875e8357c4dcedb: Scheduling FlushMRSOp(84872f0dcd63457e8c9e1ee908cb00d9): perf score=1.000000
I20260812 06:17:23.219216 25207 maintenance_manager.cc:643] P a3b12bef41cd4902b875e8357c4dcedb: FlushMRSOp(84872f0dcd63457e8c9e1ee908cb00d9) complete. Timing: real 0.035s	user 0.029s	sys 0.003s Metrics: {"bytes_written":1152508,"cfile_init":1,"dirs.queue_time_us":89,"dirs.run_cpu_time_us":290,"dirs.run_wall_time_us":1429,"drs_written":1,"lbm_read_time_us":66,"lbm_reads_lt_1ms":4,"lbm_write_time_us":2078,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":28}
I20260812 06:17:23.219776 25312 maintenance_manager.cc:419] P a3b12bef41cd4902b875e8357c4dcedb: Scheduling LogGCOp(84872f0dcd63457e8c9e1ee908cb00d9): free 112239308 bytes of WAL
I20260812 06:17:23.219992 25207 log_reader.cc:385] T 84872f0dcd63457e8c9e1ee908cb00d9: removed 11 log segments from log reader
I20260812 06:17:23.220034 25207 log.cc:1079] T 84872f0dcd63457e8c9e1ee908cb00d9 P a3b12bef41cd4902b875e8357c4dcedb: Deleting log segment in path: /tmp/dist-test-taskULGn6B/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515435658806-24703-0/minicluster-data/ts-0-root/wals/84872f0dcd63457e8c9e1ee908cb00d9/wal-000000003 (ops 12-16)
I20260812 06:17:23.220062 25207 log.cc:1079] T 84872f0dcd63457e8c9e1ee908cb00d9 P a3b12bef41cd4902b875e8357c4dcedb: Deleting log segment in path: /tmp/dist-test-taskULGn6B/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515435658806-24703-0/minicluster-data/ts-0-root/wals/84872f0dcd63457e8c9e1ee908cb00d9/wal-000000004 (ops 17-21)
I20260812 06:17:23.220101 25207 log.cc:1079] T 84872f0dcd63457e8c9e1ee908cb00d9 P a3b12bef41cd4902b875e8357c4dcedb: Deleting log segment in path: /tmp/dist-test-taskULGn6B/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515435658806-24703-0/minicluster-data/ts-0-root/wals/84872f0dcd63457e8c9e1ee908cb00d9/wal-000000005 (ops 22-26)
I20260812 06:17:23.220145 25207 log.cc:1079] T 84872f0dcd63457e8c9e1ee908cb00d9 P a3b12bef41cd4902b875e8357c4dcedb: Deleting log segment in path: /tmp/dist-test-taskULGn6B/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515435658806-24703-0/minicluster-data/ts-0-root/wals/84872f0dcd63457e8c9e1ee908cb00d9/wal-000000006 (ops 27-30)
I20260812 06:17:23.220197 25207 log.cc:1079] T 84872f0dcd63457e8c9e1ee908cb00d9 P a3b12bef41cd4902b875e8357c4dcedb: Deleting log segment in path: /tmp/dist-test-taskULGn6B/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515435658806-24703-0/minicluster-data/ts-0-root/wals/84872f0dcd63457e8c9e1ee908cb00d9/wal-000000007 (ops 31-35)
I20260812 06:17:23.220237 25207 log.cc:1079] T 84872f0dcd63457e8c9e1ee908cb00d9 P a3b12bef41cd4902b875e8357c4dcedb: Deleting log segment in path: /tmp/dist-test-taskULGn6B/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515435658806-24703-0/minicluster-data/ts-0-root/wals/84872f0dcd63457e8c9e1ee908cb00d9/wal-000000008 (ops 36-40)
I20260812 06:17:23.220283 25207 log.cc:1079] T 84872f0dcd63457e8c9e1ee908cb00d9 P a3b12bef41cd4902b875e8357c4dcedb: Deleting log segment in path: /tmp/dist-test-taskULGn6B/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515435658806-24703-0/minicluster-data/ts-0-root/wals/84872f0dcd63457e8c9e1ee908cb00d9/wal-000000009 (ops 41-45)
I20260812 06:17:23.220327 25207 log.cc:1079] T 84872f0dcd63457e8c9e1ee908cb00d9 P a3b12bef41cd4902b875e8357c4dcedb: Deleting log segment in path: /tmp/dist-test-taskULGn6B/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515435658806-24703-0/minicluster-data/ts-0-root/wals/84872f0dcd63457e8c9e1ee908cb00d9/wal-000000010 (ops 46-50)
I20260812 06:17:23.220367 25207 log.cc:1079] T 84872f0dcd63457e8c9e1ee908cb00d9 P a3b12bef41cd4902b875e8357c4dcedb: Deleting log segment in path: /tmp/dist-test-taskULGn6B/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515435658806-24703-0/minicluster-data/ts-0-root/wals/84872f0dcd63457e8c9e1ee908cb00d9/wal-000000011 (ops 51-55)
I20260812 06:17:23.220407 25207 log.cc:1079] T 84872f0dcd63457e8c9e1ee908cb00d9 P a3b12bef41cd4902b875e8357c4dcedb: Deleting log segment in path: /tmp/dist-test-taskULGn6B/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515435658806-24703-0/minicluster-data/ts-0-root/wals/84872f0dcd63457e8c9e1ee908cb00d9/wal-000000012 (ops 56-60)
I20260812 06:17:23.220445 25207 log.cc:1079] T 84872f0dcd63457e8c9e1ee908cb00d9 P a3b12bef41cd4902b875e8357c4dcedb: Deleting log segment in path: /tmp/dist-test-taskULGn6B/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515435658806-24703-0/minicluster-data/ts-0-root/wals/84872f0dcd63457e8c9e1ee908cb00d9/wal-000000013 (ops 61-65)
I20260812 06:17:23.248114 25207 maintenance_manager.cc:643] P a3b12bef41cd4902b875e8357c4dcedb: LogGCOp(84872f0dcd63457e8c9e1ee908cb00d9) complete. Timing: real 0.028s	user 0.000s	sys 0.026s Metrics: {}
I20260812 06:17:23.248508 25312 maintenance_manager.cc:419] P a3b12bef41cd4902b875e8357c4dcedb: Scheduling UndoDeltaBlockGCOp(84872f0dcd63457e8c9e1ee908cb00d9): 447 bytes on disk
I20260812 06:17:23.248929 25207 maintenance_manager.cc:643] P a3b12bef41cd4902b875e8357c4dcedb: UndoDeltaBlockGCOp(84872f0dcd63457e8c9e1ee908cb00d9) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":53,"lbm_reads_lt_1ms":4}
I20260812 06:17:23.249460 25312 maintenance_manager.cc:419] P a3b12bef41cd4902b875e8357c4dcedb: Scheduling FlushDeltaMemStoresOp(84872f0dcd63457e8c9e1ee908cb00d9): perf score=2.188937
I20260812 06:17:23.270095 25207 maintenance_manager.cc:643] P a3b12bef41cd4902b875e8357c4dcedb: FlushDeltaMemStoresOp(84872f0dcd63457e8c9e1ee908cb00d9) complete. Timing: real 0.020s	user 0.014s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6523,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:23.270587 25312 maintenance_manager.cc:419] P a3b12bef41cd4902b875e8357c4dcedb: Scheduling FlushDeltaMemStoresOp(84872f0dcd63457e8c9e1ee908cb00d9): perf score=2.188937
I20260812 06:17:23.281229 25207 maintenance_manager.cc:643] P a3b12bef41cd4902b875e8357c4dcedb: FlushDeltaMemStoresOp(84872f0dcd63457e8c9e1ee908cb00d9) complete. Timing: real 0.010s	user 0.004s	sys 0.005s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4271,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:23.281855 25312 maintenance_manager.cc:419] P a3b12bef41cd4902b875e8357c4dcedb: Scheduling MajorDeltaCompactionOp(84872f0dcd63457e8c9e1ee908cb00d9): perf score=1.000000
I20260812 06:17:23.466488 25207 maintenance_manager.cc:643] P a3b12bef41cd4902b875e8357c4dcedb: MajorDeltaCompactionOp(84872f0dcd63457e8c9e1ee908cb00d9) complete. Timing: real 0.184s	user 0.147s	sys 0.036s Metrics: {"cfile_cache_miss":634,"cfile_cache_miss_bytes":28877330,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":274,"lbm_read_time_us":14454,"lbm_reads_lt_1ms":674,"lbm_write_time_us":36738,"lbm_writes_lt_1ms":643,"mutex_wait_us":40,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":2688,"thread_start_us":74,"threads_started":1,"update_count":3000}
I20260812 06:17:23.467082 25312 maintenance_manager.cc:419] P a3b12bef41cd4902b875e8357c4dcedb: Scheduling FlushDeltaMemStoresOp(84872f0dcd63457e8c9e1ee908cb00d9): perf score=14.095187
I20260812 06:17:23.515936 25207 maintenance_manager.cc:643] P a3b12bef41cd4902b875e8357c4dcedb: FlushDeltaMemStoresOp(84872f0dcd63457e8c9e1ee908cb00d9) complete. Timing: real 0.049s	user 0.039s	sys 0.008s Metrics: {"bytes_written":16409900,"delete_count":0,"lbm_write_time_us":21665,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:17:23.516436 25312 maintenance_manager.cc:419] P a3b12bef41cd4902b875e8357c4dcedb: Scheduling FlushDeltaMemStoresOp(84872f0dcd63457e8c9e1ee908cb00d9): perf score=2.188937
I20260812 06:17:23.533428 25207 maintenance_manager.cc:643] P a3b12bef41cd4902b875e8357c4dcedb: FlushDeltaMemStoresOp(84872f0dcd63457e8c9e1ee908cb00d9) complete. Timing: real 0.017s	user 0.012s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5508,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:23.533967 25312 maintenance_manager.cc:419] P a3b12bef41cd4902b875e8357c4dcedb: Scheduling MajorDeltaCompactionOp(84872f0dcd63457e8c9e1ee908cb00d9): perf score=1.000000
I20260812 06:17:23.699227 25207 maintenance_manager.cc:643] P a3b12bef41cd4902b875e8357c4dcedb: MajorDeltaCompactionOp(84872f0dcd63457e8c9e1ee908cb00d9) complete. Timing: real 0.165s	user 0.119s	sys 0.044s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774687,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":347,"lbm_read_time_us":11496,"lbm_reads_lt_1ms":568,"lbm_write_time_us":30225,"lbm_writes_lt_1ms":543,"mutex_wait_us":20,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":12800,"update_count":2500}
I20260812 06:17:23.699896 25312 maintenance_manager.cc:419] P a3b12bef41cd4902b875e8357c4dcedb: Scheduling FlushDeltaMemStoresOp(84872f0dcd63457e8c9e1ee908cb00d9): perf score=14.095187
I20260812 06:17:23.771185 25207 maintenance_manager.cc:643] P a3b12bef41cd4902b875e8357c4dcedb: FlushDeltaMemStoresOp(84872f0dcd63457e8c9e1ee908cb00d9) complete. Timing: real 0.071s	user 0.046s	sys 0.017s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":27532,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:17:23.771652 25312 maintenance_manager.cc:419] P a3b12bef41cd4902b875e8357c4dcedb: Scheduling FlushDeltaMemStoresOp(84872f0dcd63457e8c9e1ee908cb00d9): perf score=2.188937
I20260812 06:17:23.782418 25207 maintenance_manager.cc:643] P a3b12bef41cd4902b875e8357c4dcedb: FlushDeltaMemStoresOp(84872f0dcd63457e8c9e1ee908cb00d9) complete. Timing: real 0.011s	user 0.006s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4321,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:23.782907 25312 maintenance_manager.cc:419] P a3b12bef41cd4902b875e8357c4dcedb: Scheduling MajorDeltaCompactionOp(84872f0dcd63457e8c9e1ee908cb00d9): perf score=1.000000
I20260812 06:17:23.972797 25207 maintenance_manager.cc:643] P a3b12bef41cd4902b875e8357c4dcedb: MajorDeltaCompactionOp(84872f0dcd63457e8c9e1ee908cb00d9) complete. Timing: real 0.190s	user 0.114s	sys 0.072s 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":2131,"lbm_read_time_us":14656,"lbm_reads_lt_1ms":572,"lbm_write_time_us":32427,"lbm_writes_lt_1ms":543,"mutex_wait_us":682,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":3200,"update_count":2500}
I20260812 06:17:23.973327 25312 maintenance_manager.cc:419] P a3b12bef41cd4902b875e8357c4dcedb: Scheduling FlushDeltaMemStoresOp(84872f0dcd63457e8c9e1ee908cb00d9): perf score=14.095187
I20260812 06:17:24.043948 25207 maintenance_manager.cc:643] P a3b12bef41cd4902b875e8357c4dcedb: FlushDeltaMemStoresOp(84872f0dcd63457e8c9e1ee908cb00d9) complete. Timing: real 0.070s	user 0.034s	sys 0.035s Metrics: {"bytes_written":16409900,"delete_count":0,"lbm_write_time_us":29811,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:17:24.044629 25312 maintenance_manager.cc:419] P a3b12bef41cd4902b875e8357c4dcedb: Scheduling FlushDeltaMemStoresOp(84872f0dcd63457e8c9e1ee908cb00d9): perf score=2.188937
I20260812 06:17:24.063100 25207 maintenance_manager.cc:643] P a3b12bef41cd4902b875e8357c4dcedb: FlushDeltaMemStoresOp(84872f0dcd63457e8c9e1ee908cb00d9) complete. Timing: real 0.018s	user 0.013s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":7028,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:24.063634 25312 maintenance_manager.cc:419] P a3b12bef41cd4902b875e8357c4dcedb: Scheduling MajorDeltaCompactionOp(84872f0dcd63457e8c9e1ee908cb00d9): perf score=1.000000
I20260812 06:17:24.244185 25207 maintenance_manager.cc:643] P a3b12bef41cd4902b875e8357c4dcedb: MajorDeltaCompactionOp(84872f0dcd63457e8c9e1ee908cb00d9) complete. Timing: real 0.180s	user 0.111s	sys 0.068s 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":198,"lbm_read_time_us":14392,"lbm_reads_lt_1ms":572,"lbm_write_time_us":31352,"lbm_writes_lt_1ms":543,"mutex_wait_us":40,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":2176,"update_count":2500}
I20260812 06:17:24.244876 25312 maintenance_manager.cc:419] P a3b12bef41cd4902b875e8357c4dcedb: Scheduling FlushDeltaMemStoresOp(84872f0dcd63457e8c9e1ee908cb00d9): perf score=14.095187
I20260812 06:17:24.309163 25207 maintenance_manager.cc:643] P a3b12bef41cd4902b875e8357c4dcedb: FlushDeltaMemStoresOp(84872f0dcd63457e8c9e1ee908cb00d9) complete. Timing: real 0.064s	user 0.033s	sys 0.022s Metrics: {"bytes_written":16409904,"delete_count":0,"lbm_write_time_us":20447,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:17:24.309756 25312 maintenance_manager.cc:419] P a3b12bef41cd4902b875e8357c4dcedb: Scheduling FlushDeltaMemStoresOp(84872f0dcd63457e8c9e1ee908cb00d9): perf score=2.188937
I20260812 06:17:24.321234 25207 maintenance_manager.cc:643] P a3b12bef41cd4902b875e8357c4dcedb: FlushDeltaMemStoresOp(84872f0dcd63457e8c9e1ee908cb00d9) complete. Timing: real 0.011s	user 0.006s	sys 0.003s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4417,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:24.321677 25312 maintenance_manager.cc:419] P a3b12bef41cd4902b875e8357c4dcedb: Scheduling MajorDeltaCompactionOp(84872f0dcd63457e8c9e1ee908cb00d9): perf score=1.000000
I20260812 06:17:24.512166 25207 maintenance_manager.cc:643] P a3b12bef41cd4902b875e8357c4dcedb: MajorDeltaCompactionOp(84872f0dcd63457e8c9e1ee908cb00d9) complete. Timing: real 0.190s	user 0.117s	sys 0.067s 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":162,"lbm_read_time_us":13867,"lbm_reads_lt_1ms":572,"lbm_write_time_us":31809,"lbm_writes_lt_1ms":543,"mutex_wait_us":31,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":17280,"update_count":2500}
I20260812 06:17:24.512815 25312 maintenance_manager.cc:419] P a3b12bef41cd4902b875e8357c4dcedb: Scheduling FlushDeltaMemStoresOp(84872f0dcd63457e8c9e1ee908cb00d9): perf score=14.095187
I20260812 06:17:24.569554 25207 maintenance_manager.cc:643] P a3b12bef41cd4902b875e8357c4dcedb: FlushDeltaMemStoresOp(84872f0dcd63457e8c9e1ee908cb00d9) complete. Timing: real 0.057s	user 0.032s	sys 0.017s Metrics: {"bytes_written":16409915,"delete_count":0,"lbm_write_time_us":23590,"lbm_writes_lt_1ms":403,"reinsert_count":0,"spinlock_wait_cycles":2176,"update_count":2000}
I20260812 06:17:24.570070 25312 maintenance_manager.cc:419] P a3b12bef41cd4902b875e8357c4dcedb: Scheduling FlushDeltaMemStoresOp(84872f0dcd63457e8c9e1ee908cb00d9): perf score=2.188937
I20260812 06:17:24.600782 25207 maintenance_manager.cc:643] P a3b12bef41cd4902b875e8357c4dcedb: FlushDeltaMemStoresOp(84872f0dcd63457e8c9e1ee908cb00d9) complete. Timing: real 0.030s	user 0.007s	sys 0.021s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6293,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:24.601351 25312 maintenance_manager.cc:419] P a3b12bef41cd4902b875e8357c4dcedb: Scheduling MajorDeltaCompactionOp(84872f0dcd63457e8c9e1ee908cb00d9): perf score=1.000000
I20260812 06:17:24.778432 25207 maintenance_manager.cc:643] P a3b12bef41cd4902b875e8357c4dcedb: MajorDeltaCompactionOp(84872f0dcd63457e8c9e1ee908cb00d9) complete. Timing: real 0.177s	user 0.085s	sys 0.087s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774702,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":576,"lbm_read_time_us":15297,"lbm_reads_lt_1ms":572,"lbm_write_time_us":28331,"lbm_writes_lt_1ms":543,"mutex_wait_us":48,"peak_mem_usage":63115900,"reinsert_count":0,"update_count":2500}
I20260812 06:17:24.779208 25312 maintenance_manager.cc:419] P a3b12bef41cd4902b875e8357c4dcedb: Scheduling FlushDeltaMemStoresOp(84872f0dcd63457e8c9e1ee908cb00d9): perf score=14.095187
I20260812 06:17:24.829231 25207 maintenance_manager.cc:643] P a3b12bef41cd4902b875e8357c4dcedb: FlushDeltaMemStoresOp(84872f0dcd63457e8c9e1ee908cb00d9) complete. Timing: real 0.050s	user 0.034s	sys 0.012s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":21865,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:17:24.829783 25312 maintenance_manager.cc:419] P a3b12bef41cd4902b875e8357c4dcedb: Scheduling FlushDeltaMemStoresOp(84872f0dcd63457e8c9e1ee908cb00d9): perf score=2.188937
I20260812 06:17:24.841913 25207 maintenance_manager.cc:643] P a3b12bef41cd4902b875e8357c4dcedb: FlushDeltaMemStoresOp(84872f0dcd63457e8c9e1ee908cb00d9) complete. Timing: real 0.012s	user 0.002s	sys 0.007s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4473,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:24.842484 25312 maintenance_manager.cc:419] P a3b12bef41cd4902b875e8357c4dcedb: Scheduling FlushMRSOp(84872f0dcd63457e8c9e1ee908cb00d9): perf score=1.000000
I20260812 06:17:24.880218 25207 maintenance_manager.cc:643] P a3b12bef41cd4902b875e8357c4dcedb: FlushMRSOp(84872f0dcd63457e8c9e1ee908cb00d9) complete. Timing: real 0.037s	user 0.028s	sys 0.004s Metrics: {"bytes_written":1316419,"cfile_init":1,"dirs.queue_time_us":71,"dirs.run_cpu_time_us":237,"dirs.run_wall_time_us":1460,"drs_written":1,"lbm_read_time_us":76,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1862,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":32,"spinlock_wait_cycles":15104}
I20260812 06:17:24.880928 25312 maintenance_manager.cc:419] P a3b12bef41cd4902b875e8357c4dcedb: Scheduling LogGCOp(84872f0dcd63457e8c9e1ee908cb00d9): free 133024419 bytes of WAL
I20260812 06:17:24.881187 25207 log_reader.cc:385] T 84872f0dcd63457e8c9e1ee908cb00d9: removed 13 log segments from log reader
I20260812 06:17:24.881245 25207 log.cc:1079] T 84872f0dcd63457e8c9e1ee908cb00d9 P a3b12bef41cd4902b875e8357c4dcedb: Deleting log segment in path: /tmp/dist-test-taskULGn6B/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515435658806-24703-0/minicluster-data/ts-0-root/wals/84872f0dcd63457e8c9e1ee908cb00d9/wal-000000014 (ops 66-70)
I20260812 06:17:24.881284 25207 log.cc:1079] T 84872f0dcd63457e8c9e1ee908cb00d9 P a3b12bef41cd4902b875e8357c4dcedb: Deleting log segment in path: /tmp/dist-test-taskULGn6B/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515435658806-24703-0/minicluster-data/ts-0-root/wals/84872f0dcd63457e8c9e1ee908cb00d9/wal-000000015 (ops 71-75)
I20260812 06:17:24.881319 25207 log.cc:1079] T 84872f0dcd63457e8c9e1ee908cb00d9 P a3b12bef41cd4902b875e8357c4dcedb: Deleting log segment in path: /tmp/dist-test-taskULGn6B/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515435658806-24703-0/minicluster-data/ts-0-root/wals/84872f0dcd63457e8c9e1ee908cb00d9/wal-000000016 (ops 76-80)
I20260812 06:17:24.881348 25207 log.cc:1079] T 84872f0dcd63457e8c9e1ee908cb00d9 P a3b12bef41cd4902b875e8357c4dcedb: Deleting log segment in path: /tmp/dist-test-taskULGn6B/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515435658806-24703-0/minicluster-data/ts-0-root/wals/84872f0dcd63457e8c9e1ee908cb00d9/wal-000000017 (ops 81-85)
I20260812 06:17:24.881377 25207 log.cc:1079] T 84872f0dcd63457e8c9e1ee908cb00d9 P a3b12bef41cd4902b875e8357c4dcedb: Deleting log segment in path: /tmp/dist-test-taskULGn6B/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515435658806-24703-0/minicluster-data/ts-0-root/wals/84872f0dcd63457e8c9e1ee908cb00d9/wal-000000018 (ops 86-90)
I20260812 06:17:24.881399 25207 log.cc:1079] T 84872f0dcd63457e8c9e1ee908cb00d9 P a3b12bef41cd4902b875e8357c4dcedb: Deleting log segment in path: /tmp/dist-test-taskULGn6B/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515435658806-24703-0/minicluster-data/ts-0-root/wals/84872f0dcd63457e8c9e1ee908cb00d9/wal-000000019 (ops 91-94)
I20260812 06:17:24.881428 25207 log.cc:1079] T 84872f0dcd63457e8c9e1ee908cb00d9 P a3b12bef41cd4902b875e8357c4dcedb: Deleting log segment in path: /tmp/dist-test-taskULGn6B/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515435658806-24703-0/minicluster-data/ts-0-root/wals/84872f0dcd63457e8c9e1ee908cb00d9/wal-000000020 (ops 95-99)
I20260812 06:17:24.881464 25207 log.cc:1079] T 84872f0dcd63457e8c9e1ee908cb00d9 P a3b12bef41cd4902b875e8357c4dcedb: Deleting log segment in path: /tmp/dist-test-taskULGn6B/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515435658806-24703-0/minicluster-data/ts-0-root/wals/84872f0dcd63457e8c9e1ee908cb00d9/wal-000000021 (ops 100-104)
I20260812 06:17:24.881494 25207 log.cc:1079] T 84872f0dcd63457e8c9e1ee908cb00d9 P a3b12bef41cd4902b875e8357c4dcedb: Deleting log segment in path: /tmp/dist-test-taskULGn6B/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515435658806-24703-0/minicluster-data/ts-0-root/wals/84872f0dcd63457e8c9e1ee908cb00d9/wal-000000022 (ops 105-109)
I20260812 06:17:24.881522 25207 log.cc:1079] T 84872f0dcd63457e8c9e1ee908cb00d9 P a3b12bef41cd4902b875e8357c4dcedb: Deleting log segment in path: /tmp/dist-test-taskULGn6B/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515435658806-24703-0/minicluster-data/ts-0-root/wals/84872f0dcd63457e8c9e1ee908cb00d9/wal-000000023 (ops 110-114)
I20260812 06:17:24.881544 25207 log.cc:1079] T 84872f0dcd63457e8c9e1ee908cb00d9 P a3b12bef41cd4902b875e8357c4dcedb: Deleting log segment in path: /tmp/dist-test-taskULGn6B/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515435658806-24703-0/minicluster-data/ts-0-root/wals/84872f0dcd63457e8c9e1ee908cb00d9/wal-000000024 (ops 115-119)
I20260812 06:17:24.881572 25207 log.cc:1079] T 84872f0dcd63457e8c9e1ee908cb00d9 P a3b12bef41cd4902b875e8357c4dcedb: Deleting log segment in path: /tmp/dist-test-taskULGn6B/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515435658806-24703-0/minicluster-data/ts-0-root/wals/84872f0dcd63457e8c9e1ee908cb00d9/wal-000000025 (ops 120-124)
I20260812 06:17:24.881595 25207 log.cc:1079] T 84872f0dcd63457e8c9e1ee908cb00d9 P a3b12bef41cd4902b875e8357c4dcedb: Deleting log segment in path: /tmp/dist-test-taskULGn6B/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515435658806-24703-0/minicluster-data/ts-0-root/wals/84872f0dcd63457e8c9e1ee908cb00d9/wal-000000026 (ops 125-129)
I20260812 06:17:24.914911 25207 maintenance_manager.cc:643] P a3b12bef41cd4902b875e8357c4dcedb: LogGCOp(84872f0dcd63457e8c9e1ee908cb00d9) complete. Timing: real 0.034s	user 0.000s	sys 0.033s Metrics: {}
I20260812 06:17:24.915251 25312 maintenance_manager.cc:419] P a3b12bef41cd4902b875e8357c4dcedb: Scheduling UndoDeltaBlockGCOp(84872f0dcd63457e8c9e1ee908cb00d9): 492 bytes on disk
I20260812 06:17:24.915663 25207 maintenance_manager.cc:643] P a3b12bef41cd4902b875e8357c4dcedb: UndoDeltaBlockGCOp(84872f0dcd63457e8c9e1ee908cb00d9) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":72,"lbm_reads_lt_1ms":4}
I20260812 06:17:24.916134 25312 maintenance_manager.cc:419] P a3b12bef41cd4902b875e8357c4dcedb: Scheduling FlushDeltaMemStoresOp(84872f0dcd63457e8c9e1ee908cb00d9): perf score=2.188937
I20260812 06:17:24.945035 25207 maintenance_manager.cc:643] P a3b12bef41cd4902b875e8357c4dcedb: FlushDeltaMemStoresOp(84872f0dcd63457e8c9e1ee908cb00d9) complete. Timing: real 0.029s	user 0.008s	sys 0.006s Metrics: {"bytes_written":4225734,"delete_count":0,"lbm_write_time_us":6255,"lbm_writes_lt_1ms":106,"mutex_wait_us":255,"reinsert_count":0,"update_count":515}
I20260812 06:17:24.945618 25312 maintenance_manager.cc:419] P a3b12bef41cd4902b875e8357c4dcedb: Scheduling FlushDeltaMemStoresOp(84872f0dcd63457e8c9e1ee908cb00d9): perf score=2.188937
I20260812 06:17:24.956189 25207 maintenance_manager.cc:643] P a3b12bef41cd4902b875e8357c4dcedb: FlushDeltaMemStoresOp(84872f0dcd63457e8c9e1ee908cb00d9) complete. Timing: real 0.010s	user 0.006s	sys 0.003s Metrics: {"bytes_written":3979584,"delete_count":0,"lbm_write_time_us":4235,"lbm_writes_lt_1ms":100,"reinsert_count":0,"update_count":485}
I20260812 06:17:24.956634 25312 maintenance_manager.cc:419] P a3b12bef41cd4902b875e8357c4dcedb: Scheduling MajorDeltaCompactionOp(84872f0dcd63457e8c9e1ee908cb00d9): perf score=1.000000
I20260812 06:17:25.213869 25207 maintenance_manager.cc:643] P a3b12bef41cd4902b875e8357c4dcedb: MajorDeltaCompactionOp(84872f0dcd63457e8c9e1ee908cb00d9) complete. Timing: real 0.257s	user 0.162s	sys 0.093s Metrics: {"cfile_cache_miss":734,"cfile_cache_miss_bytes":32979750,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":386,"lbm_read_time_us":17497,"lbm_reads_lt_1ms":774,"lbm_write_time_us":43677,"lbm_writes_lt_1ms":743,"peak_mem_usage":87969044,"reinsert_count":0,"spinlock_wait_cycles":13952,"thread_start_us":81,"threads_started":1,"update_count":3500}
I20260812 06:17:25.214627 25312 maintenance_manager.cc:419] P a3b12bef41cd4902b875e8357c4dcedb: Scheduling FlushDeltaMemStoresOp(84872f0dcd63457e8c9e1ee908cb00d9): perf score=18.063937
I20260812 06:17:25.269611 25207 maintenance_manager.cc:643] P a3b12bef41cd4902b875e8357c4dcedb: FlushDeltaMemStoresOp(84872f0dcd63457e8c9e1ee908cb00d9) complete. Timing: real 0.055s	user 0.027s	sys 0.025s Metrics: {"bytes_written":20512317,"delete_count":0,"lbm_write_time_us":25357,"lbm_writes_lt_1ms":503,"reinsert_count":0,"update_count":2500}
I20260812 06:17:25.270318 25312 maintenance_manager.cc:419] P a3b12bef41cd4902b875e8357c4dcedb: Scheduling MajorDeltaCompactionOp(84872f0dcd63457e8c9e1ee908cb00d9): perf score=1.000000
I20260812 06:17:25.449378 25207 maintenance_manager.cc:643] P a3b12bef41cd4902b875e8357c4dcedb: MajorDeltaCompactionOp(84872f0dcd63457e8c9e1ee908cb00d9) complete. Timing: real 0.179s	user 0.120s	sys 0.056s Metrics: {"cfile_cache_miss":531,"cfile_cache_miss_bytes":24774573,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":1,"delta_iterators_relevant":1,"dirs.queue_time_us":241,"lbm_read_time_us":14369,"lbm_reads_lt_1ms":567,"lbm_write_time_us":29981,"lbm_writes_lt_1ms":543,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":20992,"update_count":2500}
I20260812 06:17:25.450129 25312 maintenance_manager.cc:419] P a3b12bef41cd4902b875e8357c4dcedb: Scheduling FlushDeltaMemStoresOp(84872f0dcd63457e8c9e1ee908cb00d9): perf score=14.095187
I20260812 06:17:25.519544 25207 maintenance_manager.cc:643] P a3b12bef41cd4902b875e8357c4dcedb: FlushDeltaMemStoresOp(84872f0dcd63457e8c9e1ee908cb00d9) complete. Timing: real 0.069s	user 0.030s	sys 0.031s Metrics: {"bytes_written":16409904,"delete_count":0,"lbm_write_time_us":22313,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:17:25.520280 25312 maintenance_manager.cc:419] P a3b12bef41cd4902b875e8357c4dcedb: Scheduling FlushDeltaMemStoresOp(84872f0dcd63457e8c9e1ee908cb00d9): perf score=2.188937
I20260812 06:17:25.531332 25207 maintenance_manager.cc:643] P a3b12bef41cd4902b875e8357c4dcedb: FlushDeltaMemStoresOp(84872f0dcd63457e8c9e1ee908cb00d9) complete. Timing: real 0.011s	user 0.009s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4321,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:25.531806 25312 maintenance_manager.cc:419] P a3b12bef41cd4902b875e8357c4dcedb: Scheduling MajorDeltaCompactionOp(84872f0dcd63457e8c9e1ee908cb00d9): perf score=1.000000
I20260812 06:17:25.717468 25207 maintenance_manager.cc:643] P a3b12bef41cd4902b875e8357c4dcedb: MajorDeltaCompactionOp(84872f0dcd63457e8c9e1ee908cb00d9) complete. Timing: real 0.185s	user 0.162s	sys 0.024s 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":215,"lbm_read_time_us":14178,"lbm_reads_lt_1ms":572,"lbm_write_time_us":31719,"lbm_writes_lt_1ms":543,"mutex_wait_us":2,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":16384,"update_count":2500}
I20260812 06:17:25.718150 25312 maintenance_manager.cc:419] P a3b12bef41cd4902b875e8357c4dcedb: Scheduling FlushDeltaMemStoresOp(84872f0dcd63457e8c9e1ee908cb00d9): perf score=11.118625
I20260812 06:17:25.753523 25207 maintenance_manager.cc:643] P a3b12bef41cd4902b875e8357c4dcedb: FlushDeltaMemStoresOp(84872f0dcd63457e8c9e1ee908cb00d9) complete. Timing: real 0.035s	user 0.019s	sys 0.013s Metrics: {"bytes_written":12717735,"delete_count":0,"lbm_write_time_us":15482,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:17:25.754091 25312 maintenance_manager.cc:419] P a3b12bef41cd4902b875e8357c4dcedb: Scheduling FlushDeltaMemStoresOp(84872f0dcd63457e8c9e1ee908cb00d9): perf score=2.188937
I20260812 06:17:25.771837 25207 maintenance_manager.cc:643] P a3b12bef41cd4902b875e8357c4dcedb: FlushDeltaMemStoresOp(84872f0dcd63457e8c9e1ee908cb00d9) complete. Timing: real 0.018s	user 0.014s	sys 0.001s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":6456,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:17:25.772275 25312 maintenance_manager.cc:419] P a3b12bef41cd4902b875e8357c4dcedb: Scheduling MajorDeltaCompactionOp(84872f0dcd63457e8c9e1ee908cb00d9): perf score=1.000000
I20260812 06:17:25.928026 25207 maintenance_manager.cc:643] P a3b12bef41cd4902b875e8357c4dcedb: MajorDeltaCompactionOp(84872f0dcd63457e8c9e1ee908cb00d9) complete. Timing: real 0.156s	user 0.104s	sys 0.040s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672268,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":160,"lbm_read_time_us":8220,"lbm_reads_lt_1ms":468,"lbm_write_time_us":24672,"lbm_writes_lt_1ms":443,"mutex_wait_us":46,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":9600,"update_count":2000}
I20260812 06:17:25.928777 25312 maintenance_manager.cc:419] P a3b12bef41cd4902b875e8357c4dcedb: Scheduling FlushDeltaMemStoresOp(84872f0dcd63457e8c9e1ee908cb00d9): perf score=11.118625
I20260812 06:17:25.966439 25207 maintenance_manager.cc:643] P a3b12bef41cd4902b875e8357c4dcedb: FlushDeltaMemStoresOp(84872f0dcd63457e8c9e1ee908cb00d9) complete. Timing: real 0.037s	user 0.025s	sys 0.012s Metrics: {"bytes_written":12717735,"delete_count":0,"lbm_write_time_us":16158,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:17:25.967082 25312 maintenance_manager.cc:419] P a3b12bef41cd4902b875e8357c4dcedb: Scheduling FlushDeltaMemStoresOp(84872f0dcd63457e8c9e1ee908cb00d9): perf score=2.188937
I20260812 06:17:25.983888 25207 maintenance_manager.cc:643] P a3b12bef41cd4902b875e8357c4dcedb: FlushDeltaMemStoresOp(84872f0dcd63457e8c9e1ee908cb00d9) complete. Timing: real 0.017s	user 0.012s	sys 0.000s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":5222,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:17:25.984462 25312 maintenance_manager.cc:419] P a3b12bef41cd4902b875e8357c4dcedb: Scheduling MajorDeltaCompactionOp(84872f0dcd63457e8c9e1ee908cb00d9): perf score=1.000000
I20260812 06:17:26.135035 25207 maintenance_manager.cc:643] P a3b12bef41cd4902b875e8357c4dcedb: MajorDeltaCompactionOp(84872f0dcd63457e8c9e1ee908cb00d9) complete. Timing: real 0.150s	user 0.111s	sys 0.030s 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":1128,"lbm_read_time_us":11481,"lbm_reads_lt_1ms":464,"lbm_write_time_us":26449,"lbm_writes_lt_1ms":443,"mutex_wait_us":299,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":2176,"update_count":2000}
I20260812 06:17:26.135809 25312 maintenance_manager.cc:419] P a3b12bef41cd4902b875e8357c4dcedb: Scheduling FlushDeltaMemStoresOp(84872f0dcd63457e8c9e1ee908cb00d9): perf score=14.095187
I20260812 06:17:26.187899 25207 maintenance_manager.cc:643] P a3b12bef41cd4902b875e8357c4dcedb: FlushDeltaMemStoresOp(84872f0dcd63457e8c9e1ee908cb00d9) complete. Timing: real 0.052s	user 0.030s	sys 0.011s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":19583,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:17:26.188402 25312 maintenance_manager.cc:419] P a3b12bef41cd4902b875e8357c4dcedb: Scheduling FlushDeltaMemStoresOp(84872f0dcd63457e8c9e1ee908cb00d9): perf score=2.188937
I20260812 06:17:26.200291 25207 maintenance_manager.cc:643] P a3b12bef41cd4902b875e8357c4dcedb: FlushDeltaMemStoresOp(84872f0dcd63457e8c9e1ee908cb00d9) complete. Timing: real 0.012s	user 0.009s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4274,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:26.200738 25312 maintenance_manager.cc:419] P a3b12bef41cd4902b875e8357c4dcedb: Scheduling MajorDeltaCompactionOp(84872f0dcd63457e8c9e1ee908cb00d9): perf score=1.000000
I20260812 06:17:26.370868 25207 maintenance_manager.cc:643] P a3b12bef41cd4902b875e8357c4dcedb: MajorDeltaCompactionOp(84872f0dcd63457e8c9e1ee908cb00d9) complete. Timing: real 0.170s	user 0.135s	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":130,"lbm_read_time_us":12919,"lbm_reads_lt_1ms":572,"lbm_write_time_us":29883,"lbm_writes_lt_1ms":543,"mutex_wait_us":42,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":15744,"update_count":2500}
I20260812 06:17:26.371933 25312 maintenance_manager.cc:419] P a3b12bef41cd4902b875e8357c4dcedb: Scheduling FlushDeltaMemStoresOp(84872f0dcd63457e8c9e1ee908cb00d9): perf score=14.095187
I20260812 06:17:26.432102 25207 maintenance_manager.cc:643] P a3b12bef41cd4902b875e8357c4dcedb: FlushDeltaMemStoresOp(84872f0dcd63457e8c9e1ee908cb00d9) complete. Timing: real 0.060s	user 0.035s	sys 0.016s Metrics: {"bytes_written":16409903,"delete_count":0,"lbm_write_time_us":26229,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":402,"reinsert_count":0,"update_count":2000}
I20260812 06:17:26.432754 25312 maintenance_manager.cc:419] P a3b12bef41cd4902b875e8357c4dcedb: Scheduling FlushMRSOp(84872f0dcd63457e8c9e1ee908cb00d9): perf score=1.000000
I20260812 06:17:26.475234 25207 maintenance_manager.cc:643] P a3b12bef41cd4902b875e8357c4dcedb: FlushMRSOp(84872f0dcd63457e8c9e1ee908cb00d9) complete. Timing: real 0.042s	user 0.028s	sys 0.000s Metrics: {"bytes_written":1234477,"cfile_init":1,"dirs.queue_time_us":58,"dirs.run_cpu_time_us":327,"dirs.run_wall_time_us":1505,"drs_written":1,"lbm_read_time_us":39,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1685,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":30}
I20260812 06:17:26.476090 25312 maintenance_manager.cc:419] P a3b12bef41cd4902b875e8357c4dcedb: Scheduling UndoDeltaBlockGCOp(84872f0dcd63457e8c9e1ee908cb00d9): 472 bytes on disk
I20260812 06:17:26.476574 25207 maintenance_manager.cc:643] P a3b12bef41cd4902b875e8357c4dcedb: UndoDeltaBlockGCOp(84872f0dcd63457e8c9e1ee908cb00d9) 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:26.477108 25312 maintenance_manager.cc:419] P a3b12bef41cd4902b875e8357c4dcedb: Scheduling FlushDeltaMemStoresOp(84872f0dcd63457e8c9e1ee908cb00d9): perf score=3.181125
I20260812 06:17:26.497246 25207 maintenance_manager.cc:643] P a3b12bef41cd4902b875e8357c4dcedb: FlushDeltaMemStoresOp(84872f0dcd63457e8c9e1ee908cb00d9) complete. Timing: real 0.020s	user 0.008s	sys 0.007s Metrics: {"bytes_written":4512903,"delete_count":0,"lbm_write_time_us":6915,"lbm_writes_lt_1ms":113,"reinsert_count":0,"update_count":550}
I20260812 06:17:26.497681 25312 maintenance_manager.cc:419] P a3b12bef41cd4902b875e8357c4dcedb: Scheduling LogGCOp(84872f0dcd63457e8c9e1ee908cb00d9): free 124257516 bytes of WAL
I20260812 06:17:26.497898 25207 log_reader.cc:385] T 84872f0dcd63457e8c9e1ee908cb00d9: removed 12 log segments from log reader
I20260812 06:17:26.497942 25207 log.cc:1079] T 84872f0dcd63457e8c9e1ee908cb00d9 P a3b12bef41cd4902b875e8357c4dcedb: Deleting log segment in path: /tmp/dist-test-taskULGn6B/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515435658806-24703-0/minicluster-data/ts-0-root/wals/84872f0dcd63457e8c9e1ee908cb00d9/wal-000000027 (ops 130-134)
I20260812 06:17:26.497970 25207 log.cc:1079] T 84872f0dcd63457e8c9e1ee908cb00d9 P a3b12bef41cd4902b875e8357c4dcedb: Deleting log segment in path: /tmp/dist-test-taskULGn6B/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515435658806-24703-0/minicluster-data/ts-0-root/wals/84872f0dcd63457e8c9e1ee908cb00d9/wal-000000028 (ops 135-138)
I20260812 06:17:26.498034 25207 log.cc:1079] T 84872f0dcd63457e8c9e1ee908cb00d9 P a3b12bef41cd4902b875e8357c4dcedb: Deleting log segment in path: /tmp/dist-test-taskULGn6B/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515435658806-24703-0/minicluster-data/ts-0-root/wals/84872f0dcd63457e8c9e1ee908cb00d9/wal-000000029 (ops 139-143)
I20260812 06:17:26.498066 25207 log.cc:1079] T 84872f0dcd63457e8c9e1ee908cb00d9 P a3b12bef41cd4902b875e8357c4dcedb: Deleting log segment in path: /tmp/dist-test-taskULGn6B/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515435658806-24703-0/minicluster-data/ts-0-root/wals/84872f0dcd63457e8c9e1ee908cb00d9/wal-000000030 (ops 144-148)
I20260812 06:17:26.498106 25207 log.cc:1079] T 84872f0dcd63457e8c9e1ee908cb00d9 P a3b12bef41cd4902b875e8357c4dcedb: Deleting log segment in path: /tmp/dist-test-taskULGn6B/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515435658806-24703-0/minicluster-data/ts-0-root/wals/84872f0dcd63457e8c9e1ee908cb00d9/wal-000000031 (ops 149-153)
I20260812 06:17:26.498167 25207 log.cc:1079] T 84872f0dcd63457e8c9e1ee908cb00d9 P a3b12bef41cd4902b875e8357c4dcedb: Deleting log segment in path: /tmp/dist-test-taskULGn6B/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515435658806-24703-0/minicluster-data/ts-0-root/wals/84872f0dcd63457e8c9e1ee908cb00d9/wal-000000032 (ops 154-158)
I20260812 06:17:26.498203 25207 log.cc:1079] T 84872f0dcd63457e8c9e1ee908cb00d9 P a3b12bef41cd4902b875e8357c4dcedb: Deleting log segment in path: /tmp/dist-test-taskULGn6B/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515435658806-24703-0/minicluster-data/ts-0-root/wals/84872f0dcd63457e8c9e1ee908cb00d9/wal-000000033 (ops 159-163)
I20260812 06:17:26.498263 25207 log.cc:1079] T 84872f0dcd63457e8c9e1ee908cb00d9 P a3b12bef41cd4902b875e8357c4dcedb: Deleting log segment in path: /tmp/dist-test-taskULGn6B/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515435658806-24703-0/minicluster-data/ts-0-root/wals/84872f0dcd63457e8c9e1ee908cb00d9/wal-000000034 (ops 164-168)
I20260812 06:17:26.498303 25207 log.cc:1079] T 84872f0dcd63457e8c9e1ee908cb00d9 P a3b12bef41cd4902b875e8357c4dcedb: Deleting log segment in path: /tmp/dist-test-taskULGn6B/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515435658806-24703-0/minicluster-data/ts-0-root/wals/84872f0dcd63457e8c9e1ee908cb00d9/wal-000000035 (ops 169-173)
I20260812 06:17:26.498339 25207 log.cc:1079] T 84872f0dcd63457e8c9e1ee908cb00d9 P a3b12bef41cd4902b875e8357c4dcedb: Deleting log segment in path: /tmp/dist-test-taskULGn6B/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515435658806-24703-0/minicluster-data/ts-0-root/wals/84872f0dcd63457e8c9e1ee908cb00d9/wal-000000036 (ops 174-178)
I20260812 06:17:26.498376 25207 log.cc:1079] T 84872f0dcd63457e8c9e1ee908cb00d9 P a3b12bef41cd4902b875e8357c4dcedb: Deleting log segment in path: /tmp/dist-test-taskULGn6B/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515435658806-24703-0/minicluster-data/ts-0-root/wals/84872f0dcd63457e8c9e1ee908cb00d9/wal-000000037 (ops 179-183)
I20260812 06:17:26.498412 25207 log.cc:1079] T 84872f0dcd63457e8c9e1ee908cb00d9 P a3b12bef41cd4902b875e8357c4dcedb: Deleting log segment in path: /tmp/dist-test-taskULGn6B/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515435658806-24703-0/minicluster-data/ts-0-root/wals/84872f0dcd63457e8c9e1ee908cb00d9/wal-000000038 (ops 184-188)
I20260812 06:17:26.528456 25207 maintenance_manager.cc:643] P a3b12bef41cd4902b875e8357c4dcedb: LogGCOp(84872f0dcd63457e8c9e1ee908cb00d9) complete. Timing: real 0.031s	user 0.002s	sys 0.027s Metrics: {}
I20260812 06:17:26.528846 25312 maintenance_manager.cc:419] P a3b12bef41cd4902b875e8357c4dcedb: Scheduling FlushDeltaMemStoresOp(84872f0dcd63457e8c9e1ee908cb00d9): perf score=2.188937
I20260812 06:17:26.548786 25207 maintenance_manager.cc:643] P a3b12bef41cd4902b875e8357c4dcedb: FlushDeltaMemStoresOp(84872f0dcd63457e8c9e1ee908cb00d9) complete. Timing: real 0.020s	user 0.007s	sys 0.007s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6977,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:26.549222 25312 maintenance_manager.cc:419] P a3b12bef41cd4902b875e8357c4dcedb: Scheduling FlushDeltaMemStoresOp(84872f0dcd63457e8c9e1ee908cb00d9): perf score=2.188937
I20260812 06:17:26.559005 25207 maintenance_manager.cc:643] P a3b12bef41cd4902b875e8357c4dcedb: FlushDeltaMemStoresOp(84872f0dcd63457e8c9e1ee908cb00d9) complete. Timing: real 0.010s	user 0.005s	sys 0.004s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3848,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:17:26.559435 25312 maintenance_manager.cc:419] P a3b12bef41cd4902b875e8357c4dcedb: Scheduling MajorDeltaCompactionOp(84872f0dcd63457e8c9e1ee908cb00d9): perf score=1.000000
I20260812 06:17:26.740860 24703 heavy-update-compaction-itest.cc:229] Time spent updating: real 5.120s	user 1.852s	sys 0.222s
I20260812 06:17:26.768105 25207 maintenance_manager.cc:643] P a3b12bef41cd4902b875e8357c4dcedb: MajorDeltaCompactionOp(84872f0dcd63457e8c9e1ee908cb00d9) complete. Timing: real 0.208s	user 0.139s	sys 0.068s Metrics: {"cfile_cache_miss":734,"cfile_cache_miss_bytes":32979742,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"lbm_read_time_us":16937,"lbm_reads_lt_1ms":770,"lbm_write_time_us":39049,"lbm_writes_lt_1ms":743,"peak_mem_usage":87969044,"reinsert_count":0,"spinlock_wait_cycles":3840,"update_count":3500}
I20260812 06:17:26.768668 25312 maintenance_manager.cc:419] P a3b12bef41cd4902b875e8357c4dcedb: Scheduling FlushDeltaMemStoresOp(84872f0dcd63457e8c9e1ee908cb00d9): perf score=14.095187
I20260812 06:17:26.828110 24703 heavy-update-compaction-itest.cc:265] Time spent scanning: real 0.087s	user 0.001s	sys 0.000s
I20260812 06:17:26.828637 24703 tablet_server.cc:179] TabletServer@127.24.31.193:0 shutting down...
I20260812 06:17:26.869225 25207 maintenance_manager.cc:643] P a3b12bef41cd4902b875e8357c4dcedb: FlushDeltaMemStoresOp(84872f0dcd63457e8c9e1ee908cb00d9) complete. Timing: real 0.100s	user 0.042s	sys 0.012s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":26063,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":402,"reinsert_count":0,"update_count":2000}
I20260812 06:17:26.869894 24703 ts_tablet_manager.cc:1507] Shutting down tablet manager...
I20260812 06:17:26.870103 24703 tablet_replica.cc:333] T 84872f0dcd63457e8c9e1ee908cb00d9 P a3b12bef41cd4902b875e8357c4dcedb: stopping tablet replica
I20260812 06:17:26.870287 24703 raft_consensus.cc:2243] T 84872f0dcd63457e8c9e1ee908cb00d9 P a3b12bef41cd4902b875e8357c4dcedb [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:17:26.870467 24703 raft_consensus.cc:2272] T 84872f0dcd63457e8c9e1ee908cb00d9 P a3b12bef41cd4902b875e8357c4dcedb [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:17:26.873771 24703 tablet_server.cc:196] TabletServer@127.24.31.193:0 shutdown complete.
I20260812 06:17:26.876521 24703 master.cc:562] Master@127.24.31.254:38507 shutting down...
I20260812 06:17:26.880349 24703 raft_consensus.cc:2243] T 00000000000000000000000000000000 P 8ecb5599b57b4c1e8290a84f69890d18 [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:17:26.880514 24703 raft_consensus.cc:2272] T 00000000000000000000000000000000 P 8ecb5599b57b4c1e8290a84f69890d18 [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:17:26.880609 24703 tablet_replica.cc:333] T 00000000000000000000000000000000 P 8ecb5599b57b4c1e8290a84f69890d18: stopping tablet replica
I20260812 06:17:26.892853 24703 master.cc:584] Master@127.24.31.254:38507 shutdown complete.
[       OK ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/1 (5623 ms)
[----------] 2 tests from EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy (11322 ms total)

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