[==========] 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:19:31.505889 29067 internal_mini_cluster.cc:156] Creating distributed mini masters. Addrs: 127.28.98.254:44569
I20260812 06:19:31.507351 29067 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:19:31.508229 29067 file_cache.cc:504] Constructed file cache file cache with capacity 419430
I20260812 06:19:31.517196 29067 server_base.cc:1061] running on GCE node
W20260812 06:19:31.517243 29073 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:19:31.517210 29077 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:19:31.517750 29072 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:19:31.518532 29067 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:19:31.518711 29067 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:19:31.518759 29067 hybrid_clock.cc:648] HybridClock initialized: now 1786515571518756 us; error 0 us; skew 500 ppm
I20260812 06:19:31.521106 29067 webserver.cc:533] Webserver started at http://127.28.98.254:34209/ using document root <none> and password file <none>
I20260812 06:19:31.521785 29067 fs_manager.cc:362] Metadata directory not provided
I20260812 06:19:31.521869 29067 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:19:31.522213 29067 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:19:31.524587 29067 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-tasklNF8fM/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515571494869-29067-0/minicluster-data/master-0-root/instance:
uuid: "466489bda773402ba69d1ff65a300df7"
format_stamp: "Formatted at 2026-08-12 06:19:31 on dist-test-slave-1zqn"
I20260812 06:19:31.530145 29067 fs_manager.cc:696] Time spent creating directory manager: real 0.005s	user 0.004s	sys 0.000s
I20260812 06:19:31.533182 29083 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:19:31.534590 29067 fs_manager.cc:730] Time spent opening block manager: real 0.003s	user 0.002s	sys 0.000s
I20260812 06:19:31.534724 29067 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-tasklNF8fM/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515571494869-29067-0/minicluster-data/master-0-root
uuid: "466489bda773402ba69d1ff65a300df7"
format_stamp: "Formatted at 2026-08-12 06:19:31 on dist-test-slave-1zqn"
I20260812 06:19:31.534845 29067 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-tasklNF8fM/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515571494869-29067-0/minicluster-data/master-0-root
metadata directory: /tmp/dist-test-tasklNF8fM/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515571494869-29067-0/minicluster-data/master-0-root
1 data directories: /tmp/dist-test-tasklNF8fM/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515571494869-29067-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:19:31.556957 29067 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:19:31.557718 29067 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:19:31.557909 29067 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:19:31.566620 29067 rpc_server.cc:307] RPC server started. Bound to: 127.28.98.254:44569
I20260812 06:19:31.566620 29146 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.28.98.254:44569 every 8 connection(s)
I20260812 06:19:31.569131 29147 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:19:31.574661 29147 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P 466489bda773402ba69d1ff65a300df7: Bootstrap starting.
I20260812 06:19:31.577136 29147 tablet_bootstrap.cc:654] T 00000000000000000000000000000000 P 466489bda773402ba69d1ff65a300df7: Neither blocks nor log segments found. Creating new log.
I20260812 06:19:31.578075 29147 log.cc:826] T 00000000000000000000000000000000 P 466489bda773402ba69d1ff65a300df7: Log is configured to *not* fsync() on all Append() calls
I20260812 06:19:31.579871 29147 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P 466489bda773402ba69d1ff65a300df7: No bootstrap required, opened a new log
I20260812 06:19:31.582722 29147 raft_consensus.cc:359] T 00000000000000000000000000000000 P 466489bda773402ba69d1ff65a300df7 [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "466489bda773402ba69d1ff65a300df7" member_type: VOTER }
I20260812 06:19:31.582886 29147 raft_consensus.cc:385] T 00000000000000000000000000000000 P 466489bda773402ba69d1ff65a300df7 [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:19:31.582991 29147 raft_consensus.cc:740] T 00000000000000000000000000000000 P 466489bda773402ba69d1ff65a300df7 [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: 466489bda773402ba69d1ff65a300df7, State: Initialized, Role: FOLLOWER
I20260812 06:19:31.583665 29147 consensus_queue.cc:260] T 00000000000000000000000000000000 P 466489bda773402ba69d1ff65a300df7 [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: "466489bda773402ba69d1ff65a300df7" member_type: VOTER }
I20260812 06:19:31.583835 29147 raft_consensus.cc:399] T 00000000000000000000000000000000 P 466489bda773402ba69d1ff65a300df7 [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:19:31.583910 29147 raft_consensus.cc:493] T 00000000000000000000000000000000 P 466489bda773402ba69d1ff65a300df7 [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:19:31.584100 29147 raft_consensus.cc:3060] T 00000000000000000000000000000000 P 466489bda773402ba69d1ff65a300df7 [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:19:31.585098 29147 raft_consensus.cc:515] T 00000000000000000000000000000000 P 466489bda773402ba69d1ff65a300df7 [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "466489bda773402ba69d1ff65a300df7" member_type: VOTER }
I20260812 06:19:31.585546 29147 leader_election.cc:304] T 00000000000000000000000000000000 P 466489bda773402ba69d1ff65a300df7 [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: 466489bda773402ba69d1ff65a300df7; no voters: 
I20260812 06:19:31.585873 29147 leader_election.cc:290] T 00000000000000000000000000000000 P 466489bda773402ba69d1ff65a300df7 [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:19:31.585991 29150 raft_consensus.cc:2804] T 00000000000000000000000000000000 P 466489bda773402ba69d1ff65a300df7 [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:19:31.586282 29150 raft_consensus.cc:697] T 00000000000000000000000000000000 P 466489bda773402ba69d1ff65a300df7 [term 1 LEADER]: Becoming Leader. State: Replica: 466489bda773402ba69d1ff65a300df7, State: Running, Role: LEADER
I20260812 06:19:31.586700 29150 consensus_queue.cc:237] T 00000000000000000000000000000000 P 466489bda773402ba69d1ff65a300df7 [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: "466489bda773402ba69d1ff65a300df7" member_type: VOTER }
I20260812 06:19:31.586970 29147 sys_catalog.cc:565] T 00000000000000000000000000000000 P 466489bda773402ba69d1ff65a300df7 [sys.catalog]: configured and running, proceeding with master startup.
I20260812 06:19:31.588829 29152 sys_catalog.cc:455] T 00000000000000000000000000000000 P 466489bda773402ba69d1ff65a300df7 [sys.catalog]: SysCatalogTable state changed. Reason: New leader 466489bda773402ba69d1ff65a300df7. Latest consensus state: current_term: 1 leader_uuid: "466489bda773402ba69d1ff65a300df7" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "466489bda773402ba69d1ff65a300df7" member_type: VOTER } }
I20260812 06:19:31.589043 29152 sys_catalog.cc:458] T 00000000000000000000000000000000 P 466489bda773402ba69d1ff65a300df7 [sys.catalog]: This master's current role is: LEADER
I20260812 06:19:31.589361 29151 sys_catalog.cc:455] T 00000000000000000000000000000000 P 466489bda773402ba69d1ff65a300df7 [sys.catalog]: SysCatalogTable state changed. Reason: RaftConsensus started. Latest consensus state: current_term: 1 leader_uuid: "466489bda773402ba69d1ff65a300df7" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "466489bda773402ba69d1ff65a300df7" member_type: VOTER } }
I20260812 06:19:31.589468 29151 sys_catalog.cc:458] T 00000000000000000000000000000000 P 466489bda773402ba69d1ff65a300df7 [sys.catalog]: This master's current role is: LEADER
I20260812 06:19:31.589704 29160 catalog_manager.cc:1511] Loading table and tablet metadata into memory...
I20260812 06:19:31.592113 29160 catalog_manager.cc:1520] Initializing Kudu cluster ID...
I20260812 06:19:31.592415 29067 internal_mini_cluster.cc:184] Waiting to initialize catalog manager on master 0
I20260812 06:19:31.597357 29160 catalog_manager.cc:1383] Generated new cluster ID: cb34d248d3ca46ebb993d6ec2ab55334
I20260812 06:19:31.597433 29160 catalog_manager.cc:1531] Initializing Kudu internal certificate authority...
I20260812 06:19:31.609244 29160 catalog_manager.cc:1406] Generated new certificate authority record
I20260812 06:19:31.610462 29160 catalog_manager.cc:1540] Loading token signing keys...
I20260812 06:19:31.625142 29160 catalog_manager.cc:6092] T 00000000000000000000000000000000 P 466489bda773402ba69d1ff65a300df7: Generated new TSK 0
I20260812 06:19:31.625964 29160 catalog_manager.cc:1550] Initializing in-progress tserver states...
I20260812 06:19:31.657649 29067 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:19:31.660890 29171 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:19:31.661175 29172 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:19:31.661242 29174 instance_detector.cc:116] could not retrieve OpenStack instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:19:31.661422 29067 server_base.cc:1061] running on GCE node
I20260812 06:19:31.661638 29067 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:19:31.661681 29067 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:19:31.661705 29067 hybrid_clock.cc:648] HybridClock initialized: now 1786515571661703 us; error 0 us; skew 500 ppm
I20260812 06:19:31.662766 29067 webserver.cc:533] Webserver started at http://127.28.98.193:38215/ using document root <none> and password file <none>
I20260812 06:19:31.663060 29067 fs_manager.cc:362] Metadata directory not provided
I20260812 06:19:31.663143 29067 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:19:31.663239 29067 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:19:31.663726 29067 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-tasklNF8fM/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515571494869-29067-0/minicluster-data/ts-0-root/instance:
uuid: "1608363c15464f61a61d23583a523e3e"
format_stamp: "Formatted at 2026-08-12 06:19:31 on dist-test-slave-1zqn"
I20260812 06:19:31.665580 29067 fs_manager.cc:696] Time spent creating directory manager: real 0.002s	user 0.003s	sys 0.000s
I20260812 06:19:31.666725 29179 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:19:31.667061 29067 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.001s	sys 0.000s
I20260812 06:19:31.667161 29067 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-tasklNF8fM/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515571494869-29067-0/minicluster-data/ts-0-root
uuid: "1608363c15464f61a61d23583a523e3e"
format_stamp: "Formatted at 2026-08-12 06:19:31 on dist-test-slave-1zqn"
I20260812 06:19:31.667268 29067 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-tasklNF8fM/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515571494869-29067-0/minicluster-data/ts-0-root
metadata directory: /tmp/dist-test-tasklNF8fM/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515571494869-29067-0/minicluster-data/ts-0-root
1 data directories: /tmp/dist-test-tasklNF8fM/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515571494869-29067-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:19:31.688616 29067 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:19:31.689630 29067 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:19:31.690371 29067 txn_system_client.cc:432] TxnSystemClient initialization is disabled...
I20260812 06:19:31.691359 29067 ts_tablet_manager.cc:585] Loaded tablet metadata (0 total tablets, 0 live tablets)
I20260812 06:19:31.691425 29067 ts_tablet_manager.cc:531] Time spent load tablet metadata: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:19:31.691504 29067 ts_tablet_manager.cc:616] Registered 0 tablets
I20260812 06:19:31.691550 29067 ts_tablet_manager.cc:595] Time spent register tablets: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:19:31.699783 29067 rpc_server.cc:307] RPC server started. Bound to: 127.28.98.193:45771
I20260812 06:19:31.699837 29256 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.28.98.193:45771 every 8 connection(s)
I20260812 06:19:31.710954 29257 heartbeater.cc:344] Connected to a master server at 127.28.98.254:44569
I20260812 06:19:31.711223 29257 heartbeater.cc:461] Registering TS with master...
I20260812 06:19:31.711731 29257 heartbeater.cc:507] Master 127.28.98.254:44569 requested a full tablet report, sending...
I20260812 06:19:31.713414 29104 ts_manager.cc:194] Registered new tserver with Master: 1608363c15464f61a61d23583a523e3e (127.28.98.193:45771)
I20260812 06:19:31.714197 29067 internal_mini_cluster.cc:371] 1 TS(s) registered with all masters after 0.01364801s
I20260812 06:19:31.714984 29104 master_service.cc:502] Signed X509 certificate for tserver {username='slave'} at 127.0.0.1:49916
I20260812 06:19:31.724565 29104 catalog_manager.cc:2283] Servicing CreateTable request from {username='slave'} at 127.0.0.1:49928:
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:19:31.739395 29215 tablet_service.cc:1511] Processing CreateTablet for tablet 759f20969e5f4bc8b5d02de7a708ce88 (DEFAULT_TABLE table=heavy-update-compaction-test [id=ab1703162c6840dc94547c623288f5d3]), partition=
I20260812 06:19:31.739935 29215 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet 759f20969e5f4bc8b5d02de7a708ce88. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:19:31.742652 29273 tablet_bootstrap.cc:492] T 759f20969e5f4bc8b5d02de7a708ce88 P 1608363c15464f61a61d23583a523e3e: Bootstrap starting.
I20260812 06:19:31.744475 29273 tablet_bootstrap.cc:654] T 759f20969e5f4bc8b5d02de7a708ce88 P 1608363c15464f61a61d23583a523e3e: Neither blocks nor log segments found. Creating new log.
I20260812 06:19:31.746058 29273 tablet_bootstrap.cc:492] T 759f20969e5f4bc8b5d02de7a708ce88 P 1608363c15464f61a61d23583a523e3e: No bootstrap required, opened a new log
I20260812 06:19:31.746371 29273 ts_tablet_manager.cc:1403] T 759f20969e5f4bc8b5d02de7a708ce88 P 1608363c15464f61a61d23583a523e3e: Time spent bootstrapping tablet: real 0.004s	user 0.003s	sys 0.000s
I20260812 06:19:31.746984 29273 raft_consensus.cc:359] T 759f20969e5f4bc8b5d02de7a708ce88 P 1608363c15464f61a61d23583a523e3e [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "1608363c15464f61a61d23583a523e3e" member_type: VOTER last_known_addr { host: "127.28.98.193" port: 45771 } }
I20260812 06:19:31.747160 29273 raft_consensus.cc:385] T 759f20969e5f4bc8b5d02de7a708ce88 P 1608363c15464f61a61d23583a523e3e [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:19:31.747215 29273 raft_consensus.cc:740] T 759f20969e5f4bc8b5d02de7a708ce88 P 1608363c15464f61a61d23583a523e3e [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: 1608363c15464f61a61d23583a523e3e, State: Initialized, Role: FOLLOWER
I20260812 06:19:31.747350 29273 consensus_queue.cc:260] T 759f20969e5f4bc8b5d02de7a708ce88 P 1608363c15464f61a61d23583a523e3e [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: "1608363c15464f61a61d23583a523e3e" member_type: VOTER last_known_addr { host: "127.28.98.193" port: 45771 } }
I20260812 06:19:31.747452 29273 raft_consensus.cc:399] T 759f20969e5f4bc8b5d02de7a708ce88 P 1608363c15464f61a61d23583a523e3e [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:19:31.747494 29273 raft_consensus.cc:493] T 759f20969e5f4bc8b5d02de7a708ce88 P 1608363c15464f61a61d23583a523e3e [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:19:31.747546 29273 raft_consensus.cc:3060] T 759f20969e5f4bc8b5d02de7a708ce88 P 1608363c15464f61a61d23583a523e3e [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:19:31.748639 29273 raft_consensus.cc:515] T 759f20969e5f4bc8b5d02de7a708ce88 P 1608363c15464f61a61d23583a523e3e [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "1608363c15464f61a61d23583a523e3e" member_type: VOTER last_known_addr { host: "127.28.98.193" port: 45771 } }
I20260812 06:19:31.748798 29273 leader_election.cc:304] T 759f20969e5f4bc8b5d02de7a708ce88 P 1608363c15464f61a61d23583a523e3e [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: 1608363c15464f61a61d23583a523e3e; no voters: 
I20260812 06:19:31.749058 29273 leader_election.cc:290] T 759f20969e5f4bc8b5d02de7a708ce88 P 1608363c15464f61a61d23583a523e3e [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:19:31.749253 29275 raft_consensus.cc:2804] T 759f20969e5f4bc8b5d02de7a708ce88 P 1608363c15464f61a61d23583a523e3e [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:19:31.749423 29273 ts_tablet_manager.cc:1434] T 759f20969e5f4bc8b5d02de7a708ce88 P 1608363c15464f61a61d23583a523e3e: Time spent starting tablet: real 0.003s	user 0.001s	sys 0.002s
I20260812 06:19:31.749604 29275 raft_consensus.cc:697] T 759f20969e5f4bc8b5d02de7a708ce88 P 1608363c15464f61a61d23583a523e3e [term 1 LEADER]: Becoming Leader. State: Replica: 1608363c15464f61a61d23583a523e3e, State: Running, Role: LEADER
I20260812 06:19:31.749692 29257 heartbeater.cc:499] Master 127.28.98.254:44569 was elected leader, sending a full tablet report...
I20260812 06:19:31.749763 29275 consensus_queue.cc:237] T 759f20969e5f4bc8b5d02de7a708ce88 P 1608363c15464f61a61d23583a523e3e [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: "1608363c15464f61a61d23583a523e3e" member_type: VOTER last_known_addr { host: "127.28.98.193" port: 45771 } }
I20260812 06:19:31.753038 29103 catalog_manager.cc:5719] T 759f20969e5f4bc8b5d02de7a708ce88 P 1608363c15464f61a61d23583a523e3e reported cstate change: term changed from 0 to 1, leader changed from <none> to 1608363c15464f61a61d23583a523e3e (127.28.98.193). New cstate: current_term: 1 leader_uuid: "1608363c15464f61a61d23583a523e3e" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "1608363c15464f61a61d23583a523e3e" member_type: VOTER last_known_addr { host: "127.28.98.193" port: 45771 } health_report { overall_health: HEALTHY } } }
I20260812 06:19:31.821597 29067 heavy-update-compaction-itest.cc:215] Time spent inserting: real 0.061s	user 0.022s	sys 0.007s
I20260812 06:19:31.951282 29258 maintenance_manager.cc:419] P 1608363c15464f61a61d23583a523e3e: Scheduling FlushMRSOp(759f20969e5f4bc8b5d02de7a708ce88): perf score=15.086190
I20260812 06:19:32.120452 29187 maintenance_manager.cc:643] P 1608363c15464f61a61d23583a523e3e: FlushMRSOp(759f20969e5f4bc8b5d02de7a708ce88) complete. Timing: real 0.169s	user 0.119s	sys 0.046s Metrics: {"bytes_written":12307490,"cfile_init":1,"compiler_manager_pool.queue_time_us":277,"delete_count":0,"dirs.queue_time_us":55,"dirs.run_cpu_time_us":193,"dirs.run_wall_time_us":1107,"drs_written":1,"lbm_read_time_us":79,"lbm_reads_lt_1ms":4,"lbm_write_time_us":37981,"lbm_writes_lt_1ms":667,"mutex_wait_us":1574,"peak_mem_usage":0,"reinsert_count":0,"rows_written":104,"spinlock_wait_cycles":288512,"thread_start_us":164,"threads_started":1,"update_count":1500}
I20260812 06:19:32.122159 29258 maintenance_manager.cc:419] P 1608363c15464f61a61d23583a523e3e: Scheduling LogGCOp(759f20969e5f4bc8b5d02de7a708ce88): free 20743880 bytes of WAL
I20260812 06:19:32.122567 29187 log_reader.cc:385] T 759f20969e5f4bc8b5d02de7a708ce88: removed 2 log segments from log reader
I20260812 06:19:32.122635 29187 log.cc:1079] T 759f20969e5f4bc8b5d02de7a708ce88 P 1608363c15464f61a61d23583a523e3e: Deleting log segment in path: /tmp/dist-test-tasklNF8fM/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515571494869-29067-0/minicluster-data/ts-0-root/wals/759f20969e5f4bc8b5d02de7a708ce88/wal-000000001 (ops 1-6)
I20260812 06:19:32.122696 29187 log.cc:1079] T 759f20969e5f4bc8b5d02de7a708ce88 P 1608363c15464f61a61d23583a523e3e: Deleting log segment in path: /tmp/dist-test-tasklNF8fM/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515571494869-29067-0/minicluster-data/ts-0-root/wals/759f20969e5f4bc8b5d02de7a708ce88/wal-000000002 (ops 7-11)
I20260812 06:19:32.129315 29187 maintenance_manager.cc:643] P 1608363c15464f61a61d23583a523e3e: LogGCOp(759f20969e5f4bc8b5d02de7a708ce88) complete. Timing: real 0.007s	user 0.000s	sys 0.006s Metrics: {}
I20260812 06:19:32.129756 29258 maintenance_manager.cc:419] P 1608363c15464f61a61d23583a523e3e: Scheduling FlushDeltaMemStoresOp(759f20969e5f4bc8b5d02de7a708ce88): perf score=2.188937
I20260812 06:19:32.151859 29187 maintenance_manager.cc:643] P 1608363c15464f61a61d23583a523e3e: FlushDeltaMemStoresOp(759f20969e5f4bc8b5d02de7a708ce88) complete. Timing: real 0.022s	user 0.005s	sys 0.005s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4647,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:32.152348 29258 maintenance_manager.cc:419] P 1608363c15464f61a61d23583a523e3e: Scheduling FlushDeltaMemStoresOp(759f20969e5f4bc8b5d02de7a708ce88): perf score=2.188937
I20260812 06:19:32.166172 29187 maintenance_manager.cc:643] P 1608363c15464f61a61d23583a523e3e: FlushDeltaMemStoresOp(759f20969e5f4bc8b5d02de7a708ce88) complete. Timing: real 0.014s	user 0.011s	sys 0.000s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":5240,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:19:32.166648 29258 maintenance_manager.cc:419] P 1608363c15464f61a61d23583a523e3e: Scheduling UndoDeltaBlockGCOp(759f20969e5f4bc8b5d02de7a708ce88): 12719216 bytes on disk
I20260812 06:19:32.167325 29187 maintenance_manager.cc:643] P 1608363c15464f61a61d23583a523e3e: UndoDeltaBlockGCOp(759f20969e5f4bc8b5d02de7a708ce88) 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:19:32.167742 29258 maintenance_manager.cc:419] P 1608363c15464f61a61d23583a523e3e: Scheduling MajorDeltaCompactionOp(759f20969e5f4bc8b5d02de7a708ce88): perf score=1.000000
I20260812 06:19:32.332507 29187 maintenance_manager.cc:643] P 1608363c15464f61a61d23583a523e3e: MajorDeltaCompactionOp(759f20969e5f4bc8b5d02de7a708ce88) complete. Timing: real 0.165s	user 0.132s	sys 0.031s Metrics: {"cfile_cache_miss":523,"cfile_cache_miss_bytes":24364554,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":113,"lbm_read_time_us":12166,"lbm_reads_lt_1ms":559,"lbm_write_time_us":30309,"lbm_writes_lt_1ms":533,"peak_mem_usage":61665166,"reinsert_count":0,"spinlock_wait_cycles":1664,"thread_start_us":280,"threads_started":5,"update_count":2450}
I20260812 06:19:32.333153 29258 maintenance_manager.cc:419] P 1608363c15464f61a61d23583a523e3e: Scheduling FlushDeltaMemStoresOp(759f20969e5f4bc8b5d02de7a708ce88): perf score=10.126437
I20260812 06:19:32.390694 29187 maintenance_manager.cc:643] P 1608363c15464f61a61d23583a523e3e: FlushDeltaMemStoresOp(759f20969e5f4bc8b5d02de7a708ce88) complete. Timing: real 0.055s	user 0.037s	sys 0.010s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":20821,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:19:32.391384 29258 maintenance_manager.cc:419] P 1608363c15464f61a61d23583a523e3e: Scheduling FlushDeltaMemStoresOp(759f20969e5f4bc8b5d02de7a708ce88): perf score=2.188937
I20260812 06:19:32.411370 29187 maintenance_manager.cc:643] P 1608363c15464f61a61d23583a523e3e: FlushDeltaMemStoresOp(759f20969e5f4bc8b5d02de7a708ce88) complete. Timing: real 0.020s	user 0.010s	sys 0.007s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":7464,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:32.411975 29258 maintenance_manager.cc:419] P 1608363c15464f61a61d23583a523e3e: Scheduling MajorDeltaCompactionOp(759f20969e5f4bc8b5d02de7a708ce88): perf score=1.000000
I20260812 06:19:32.624142 29187 maintenance_manager.cc:643] P 1608363c15464f61a61d23583a523e3e: MajorDeltaCompactionOp(759f20969e5f4bc8b5d02de7a708ce88) complete. Timing: real 0.212s	user 0.171s	sys 0.041s 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":237,"lbm_read_time_us":14391,"lbm_reads_lt_1ms":472,"lbm_write_time_us":34930,"lbm_writes_lt_1ms":443,"peak_mem_usage":50689328,"reinsert_count":0,"update_count":2000}
I20260812 06:19:32.624842 29258 maintenance_manager.cc:419] P 1608363c15464f61a61d23583a523e3e: Scheduling FlushDeltaMemStoresOp(759f20969e5f4bc8b5d02de7a708ce88): perf score=18.063937
I20260812 06:19:32.716717 29187 maintenance_manager.cc:643] P 1608363c15464f61a61d23583a523e3e: FlushDeltaMemStoresOp(759f20969e5f4bc8b5d02de7a708ce88) complete. Timing: real 0.092s	user 0.054s	sys 0.029s Metrics: {"bytes_written":20512315,"delete_count":0,"lbm_write_time_us":36257,"lbm_writes_lt_1ms":503,"reinsert_count":0,"update_count":2500}
I20260812 06:19:32.717270 29258 maintenance_manager.cc:419] P 1608363c15464f61a61d23583a523e3e: Scheduling FlushDeltaMemStoresOp(759f20969e5f4bc8b5d02de7a708ce88): perf score=6.157687
I20260812 06:19:32.748507 29187 maintenance_manager.cc:643] P 1608363c15464f61a61d23583a523e3e: FlushDeltaMemStoresOp(759f20969e5f4bc8b5d02de7a708ce88) complete. Timing: real 0.031s	user 0.022s	sys 0.008s Metrics: {"bytes_written":8205078,"delete_count":0,"lbm_write_time_us":12506,"lbm_writes_lt_1ms":203,"reinsert_count":0,"update_count":1000}
I20260812 06:19:32.749198 29258 maintenance_manager.cc:419] P 1608363c15464f61a61d23583a523e3e: Scheduling MajorDeltaCompactionOp(759f20969e5f4bc8b5d02de7a708ce88): perf score=1.000000
I20260812 06:19:32.953083 29187 maintenance_manager.cc:643] P 1608363c15464f61a61d23583a523e3e: MajorDeltaCompactionOp(759f20969e5f4bc8b5d02de7a708ce88) complete. Timing: real 0.204s	user 0.163s	sys 0.040s Metrics: {"cfile_cache_miss":732,"cfile_cache_miss_bytes":32979515,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":716,"lbm_read_time_us":15774,"lbm_reads_lt_1ms":764,"lbm_write_time_us":41306,"lbm_writes_lt_1ms":743,"mutex_wait_us":380,"peak_mem_usage":87969044,"reinsert_count":0,"spinlock_wait_cycles":5632,"update_count":3500}
I20260812 06:19:32.953903 29258 maintenance_manager.cc:419] P 1608363c15464f61a61d23583a523e3e: Scheduling FlushDeltaMemStoresOp(759f20969e5f4bc8b5d02de7a708ce88): perf score=14.095187
I20260812 06:19:33.010959 29187 maintenance_manager.cc:643] P 1608363c15464f61a61d23583a523e3e: FlushDeltaMemStoresOp(759f20969e5f4bc8b5d02de7a708ce88) complete. Timing: real 0.057s	user 0.034s	sys 0.020s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":25360,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:33.011600 29258 maintenance_manager.cc:419] P 1608363c15464f61a61d23583a523e3e: Scheduling FlushDeltaMemStoresOp(759f20969e5f4bc8b5d02de7a708ce88): perf score=2.188937
I20260812 06:19:33.025774 29187 maintenance_manager.cc:643] P 1608363c15464f61a61d23583a523e3e: FlushDeltaMemStoresOp(759f20969e5f4bc8b5d02de7a708ce88) complete. Timing: real 0.014s	user 0.008s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5185,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:33.026280 29258 maintenance_manager.cc:419] P 1608363c15464f61a61d23583a523e3e: Scheduling MajorDeltaCompactionOp(759f20969e5f4bc8b5d02de7a708ce88): perf score=1.000000
I20260812 06:19:33.184506 29187 maintenance_manager.cc:643] P 1608363c15464f61a61d23583a523e3e: MajorDeltaCompactionOp(759f20969e5f4bc8b5d02de7a708ce88) complete. Timing: real 0.158s	user 0.115s	sys 0.041s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774689,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":295,"lbm_read_time_us":11821,"lbm_reads_lt_1ms":572,"lbm_write_time_us":33121,"lbm_writes_lt_1ms":543,"mutex_wait_us":66,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":643968,"update_count":2500}
I20260812 06:19:33.185206 29258 maintenance_manager.cc:419] P 1608363c15464f61a61d23583a523e3e: Scheduling FlushDeltaMemStoresOp(759f20969e5f4bc8b5d02de7a708ce88): perf score=11.118625
I20260812 06:19:33.219370 29187 maintenance_manager.cc:643] P 1608363c15464f61a61d23583a523e3e: FlushDeltaMemStoresOp(759f20969e5f4bc8b5d02de7a708ce88) complete. Timing: real 0.034s	user 0.018s	sys 0.013s Metrics: {"bytes_written":12717735,"delete_count":0,"lbm_write_time_us":14806,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:19:33.219859 29258 maintenance_manager.cc:419] P 1608363c15464f61a61d23583a523e3e: Scheduling FlushDeltaMemStoresOp(759f20969e5f4bc8b5d02de7a708ce88): perf score=2.188937
I20260812 06:19:33.245813 29187 maintenance_manager.cc:643] P 1608363c15464f61a61d23583a523e3e: FlushDeltaMemStoresOp(759f20969e5f4bc8b5d02de7a708ce88) complete. Timing: real 0.026s	user 0.008s	sys 0.004s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":4784,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:19:33.246344 29258 maintenance_manager.cc:419] P 1608363c15464f61a61d23583a523e3e: Scheduling FlushDeltaMemStoresOp(759f20969e5f4bc8b5d02de7a708ce88): perf score=2.188937
I20260812 06:19:33.257470 29187 maintenance_manager.cc:643] P 1608363c15464f61a61d23583a523e3e: FlushDeltaMemStoresOp(759f20969e5f4bc8b5d02de7a708ce88) complete. Timing: real 0.011s	user 0.006s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4168,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:33.257982 29258 maintenance_manager.cc:419] P 1608363c15464f61a61d23583a523e3e: Scheduling MajorDeltaCompactionOp(759f20969e5f4bc8b5d02de7a708ce88): perf score=1.000000
I20260812 06:19:33.406716 29187 maintenance_manager.cc:643] P 1608363c15464f61a61d23583a523e3e: MajorDeltaCompactionOp(759f20969e5f4bc8b5d02de7a708ce88) complete. Timing: real 0.149s	user 0.113s	sys 0.035s Metrics: {"cfile_cache_miss":533,"cfile_cache_miss_bytes":24774799,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":358,"lbm_read_time_us":10296,"lbm_reads_lt_1ms":573,"lbm_write_time_us":30366,"lbm_writes_lt_1ms":543,"mutex_wait_us":87,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":768,"update_count":2500}
I20260812 06:19:33.407563 29258 maintenance_manager.cc:419] P 1608363c15464f61a61d23583a523e3e: Scheduling FlushDeltaMemStoresOp(759f20969e5f4bc8b5d02de7a708ce88): perf score=11.118625
I20260812 06:19:33.464396 29187 maintenance_manager.cc:643] P 1608363c15464f61a61d23583a523e3e: FlushDeltaMemStoresOp(759f20969e5f4bc8b5d02de7a708ce88) complete. Timing: real 0.057s	user 0.032s	sys 0.023s Metrics: {"bytes_written":12717734,"delete_count":0,"lbm_write_time_us":25691,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":312,"reinsert_count":0,"update_count":1550}
I20260812 06:19:33.464988 29258 maintenance_manager.cc:419] P 1608363c15464f61a61d23583a523e3e: Scheduling FlushDeltaMemStoresOp(759f20969e5f4bc8b5d02de7a708ce88): perf score=2.188937
I20260812 06:19:33.490033 29187 maintenance_manager.cc:643] P 1608363c15464f61a61d23583a523e3e: FlushDeltaMemStoresOp(759f20969e5f4bc8b5d02de7a708ce88) complete. Timing: real 0.025s	user 0.008s	sys 0.004s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":5235,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:19:33.490531 29258 maintenance_manager.cc:419] P 1608363c15464f61a61d23583a523e3e: Scheduling FlushDeltaMemStoresOp(759f20969e5f4bc8b5d02de7a708ce88): perf score=2.188937
I20260812 06:19:33.502226 29187 maintenance_manager.cc:643] P 1608363c15464f61a61d23583a523e3e: FlushDeltaMemStoresOp(759f20969e5f4bc8b5d02de7a708ce88) complete. Timing: real 0.012s	user 0.006s	sys 0.003s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4260,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:33.502741 29258 maintenance_manager.cc:419] P 1608363c15464f61a61d23583a523e3e: Scheduling FlushMRSOp(759f20969e5f4bc8b5d02de7a708ce88): perf score=1.000000
I20260812 06:19:33.539291 29187 maintenance_manager.cc:643] P 1608363c15464f61a61d23583a523e3e: FlushMRSOp(759f20969e5f4bc8b5d02de7a708ce88) complete. Timing: real 0.036s	user 0.033s	sys 0.000s Metrics: {"bytes_written":1234473,"cfile_init":1,"dirs.queue_time_us":106,"dirs.run_cpu_time_us":299,"dirs.run_wall_time_us":1592,"drs_written":1,"lbm_read_time_us":64,"lbm_reads_lt_1ms":4,"lbm_write_time_us":2382,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":30}
I20260812 06:19:33.540292 29258 maintenance_manager.cc:419] P 1608363c15464f61a61d23583a523e3e: Scheduling LogGCOp(759f20969e5f4bc8b5d02de7a708ce88): free 121006433 bytes of WAL
I20260812 06:19:33.540527 29187 log_reader.cc:385] T 759f20969e5f4bc8b5d02de7a708ce88: removed 12 log segments from log reader
I20260812 06:19:33.540573 29187 log.cc:1079] T 759f20969e5f4bc8b5d02de7a708ce88 P 1608363c15464f61a61d23583a523e3e: Deleting log segment in path: /tmp/dist-test-tasklNF8fM/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515571494869-29067-0/minicluster-data/ts-0-root/wals/759f20969e5f4bc8b5d02de7a708ce88/wal-000000003 (ops 12-16)
I20260812 06:19:33.540629 29187 log.cc:1079] T 759f20969e5f4bc8b5d02de7a708ce88 P 1608363c15464f61a61d23583a523e3e: Deleting log segment in path: /tmp/dist-test-tasklNF8fM/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515571494869-29067-0/minicluster-data/ts-0-root/wals/759f20969e5f4bc8b5d02de7a708ce88/wal-000000004 (ops 17-21)
I20260812 06:19:33.540678 29187 log.cc:1079] T 759f20969e5f4bc8b5d02de7a708ce88 P 1608363c15464f61a61d23583a523e3e: Deleting log segment in path: /tmp/dist-test-tasklNF8fM/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515571494869-29067-0/minicluster-data/ts-0-root/wals/759f20969e5f4bc8b5d02de7a708ce88/wal-000000005 (ops 22-26)
I20260812 06:19:33.540709 29187 log.cc:1079] T 759f20969e5f4bc8b5d02de7a708ce88 P 1608363c15464f61a61d23583a523e3e: Deleting log segment in path: /tmp/dist-test-tasklNF8fM/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515571494869-29067-0/minicluster-data/ts-0-root/wals/759f20969e5f4bc8b5d02de7a708ce88/wal-000000006 (ops 27-31)
I20260812 06:19:33.540757 29187 log.cc:1079] T 759f20969e5f4bc8b5d02de7a708ce88 P 1608363c15464f61a61d23583a523e3e: Deleting log segment in path: /tmp/dist-test-tasklNF8fM/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515571494869-29067-0/minicluster-data/ts-0-root/wals/759f20969e5f4bc8b5d02de7a708ce88/wal-000000007 (ops 32-36)
I20260812 06:19:33.540791 29187 log.cc:1079] T 759f20969e5f4bc8b5d02de7a708ce88 P 1608363c15464f61a61d23583a523e3e: Deleting log segment in path: /tmp/dist-test-tasklNF8fM/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515571494869-29067-0/minicluster-data/ts-0-root/wals/759f20969e5f4bc8b5d02de7a708ce88/wal-000000008 (ops 37-41)
I20260812 06:19:33.540836 29187 log.cc:1079] T 759f20969e5f4bc8b5d02de7a708ce88 P 1608363c15464f61a61d23583a523e3e: Deleting log segment in path: /tmp/dist-test-tasklNF8fM/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515571494869-29067-0/minicluster-data/ts-0-root/wals/759f20969e5f4bc8b5d02de7a708ce88/wal-000000009 (ops 42-46)
I20260812 06:19:33.540881 29187 log.cc:1079] T 759f20969e5f4bc8b5d02de7a708ce88 P 1608363c15464f61a61d23583a523e3e: Deleting log segment in path: /tmp/dist-test-tasklNF8fM/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515571494869-29067-0/minicluster-data/ts-0-root/wals/759f20969e5f4bc8b5d02de7a708ce88/wal-000000010 (ops 47-50)
I20260812 06:19:33.540937 29187 log.cc:1079] T 759f20969e5f4bc8b5d02de7a708ce88 P 1608363c15464f61a61d23583a523e3e: Deleting log segment in path: /tmp/dist-test-tasklNF8fM/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515571494869-29067-0/minicluster-data/ts-0-root/wals/759f20969e5f4bc8b5d02de7a708ce88/wal-000000011 (ops 51-55)
I20260812 06:19:33.540977 29187 log.cc:1079] T 759f20969e5f4bc8b5d02de7a708ce88 P 1608363c15464f61a61d23583a523e3e: Deleting log segment in path: /tmp/dist-test-tasklNF8fM/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515571494869-29067-0/minicluster-data/ts-0-root/wals/759f20969e5f4bc8b5d02de7a708ce88/wal-000000012 (ops 56-60)
I20260812 06:19:33.541015 29187 log.cc:1079] T 759f20969e5f4bc8b5d02de7a708ce88 P 1608363c15464f61a61d23583a523e3e: Deleting log segment in path: /tmp/dist-test-tasklNF8fM/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515571494869-29067-0/minicluster-data/ts-0-root/wals/759f20969e5f4bc8b5d02de7a708ce88/wal-000000013 (ops 61-65)
I20260812 06:19:33.541055 29187 log.cc:1079] T 759f20969e5f4bc8b5d02de7a708ce88 P 1608363c15464f61a61d23583a523e3e: Deleting log segment in path: /tmp/dist-test-tasklNF8fM/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515571494869-29067-0/minicluster-data/ts-0-root/wals/759f20969e5f4bc8b5d02de7a708ce88/wal-000000014 (ops 66-70)
I20260812 06:19:33.571817 29187 maintenance_manager.cc:643] P 1608363c15464f61a61d23583a523e3e: LogGCOp(759f20969e5f4bc8b5d02de7a708ce88) complete. Timing: real 0.031s	user 0.000s	sys 0.028s Metrics: {}
I20260812 06:19:33.572467 29258 maintenance_manager.cc:419] P 1608363c15464f61a61d23583a523e3e: Scheduling FlushDeltaMemStoresOp(759f20969e5f4bc8b5d02de7a708ce88): perf score=2.188937
I20260812 06:19:33.586427 29187 maintenance_manager.cc:643] P 1608363c15464f61a61d23583a523e3e: FlushDeltaMemStoresOp(759f20969e5f4bc8b5d02de7a708ce88) complete. Timing: real 0.014s	user 0.006s	sys 0.005s Metrics: {"bytes_written":4225732,"delete_count":0,"lbm_write_time_us":4821,"lbm_writes_lt_1ms":106,"mutex_wait_us":150,"reinsert_count":0,"update_count":515}
I20260812 06:19:33.586867 29258 maintenance_manager.cc:419] P 1608363c15464f61a61d23583a523e3e: Scheduling UndoDeltaBlockGCOp(759f20969e5f4bc8b5d02de7a708ce88): 473 bytes on disk
I20260812 06:19:33.587342 29187 maintenance_manager.cc:643] P 1608363c15464f61a61d23583a523e3e: UndoDeltaBlockGCOp(759f20969e5f4bc8b5d02de7a708ce88) 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:19:33.587877 29258 maintenance_manager.cc:419] P 1608363c15464f61a61d23583a523e3e: Scheduling FlushDeltaMemStoresOp(759f20969e5f4bc8b5d02de7a708ce88): perf score=2.188937
I20260812 06:19:33.600478 29187 maintenance_manager.cc:643] P 1608363c15464f61a61d23583a523e3e: FlushDeltaMemStoresOp(759f20969e5f4bc8b5d02de7a708ce88) complete. Timing: real 0.012s	user 0.004s	sys 0.007s Metrics: {"bytes_written":3979583,"delete_count":0,"lbm_write_time_us":4450,"lbm_writes_lt_1ms":100,"reinsert_count":0,"update_count":485}
I20260812 06:19:33.601730 29258 maintenance_manager.cc:419] P 1608363c15464f61a61d23583a523e3e: Scheduling MajorDeltaCompactionOp(759f20969e5f4bc8b5d02de7a708ce88): perf score=1.000000
I20260812 06:19:33.837399 29187 maintenance_manager.cc:643] P 1608363c15464f61a61d23583a523e3e: MajorDeltaCompactionOp(759f20969e5f4bc8b5d02de7a708ce88) complete. Timing: real 0.235s	user 0.134s	sys 0.089s Metrics: {"cfile_cache_miss":735,"cfile_cache_miss_bytes":32979857,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":5,"delta_iterators_relevant":5,"dirs.queue_time_us":1032,"lbm_read_time_us":15461,"lbm_reads_lt_1ms":775,"lbm_write_time_us":37825,"lbm_writes_lt_1ms":743,"mutex_wait_us":36,"peak_mem_usage":87969044,"reinsert_count":0,"spinlock_wait_cycles":768,"thread_start_us":89,"threads_started":1,"update_count":3500}
I20260812 06:19:33.838158 29258 maintenance_manager.cc:419] P 1608363c15464f61a61d23583a523e3e: Scheduling FlushDeltaMemStoresOp(759f20969e5f4bc8b5d02de7a708ce88): perf score=15.087375
I20260812 06:19:33.913251 29187 maintenance_manager.cc:643] P 1608363c15464f61a61d23583a523e3e: FlushDeltaMemStoresOp(759f20969e5f4bc8b5d02de7a708ce88) complete. Timing: real 0.075s	user 0.024s	sys 0.036s Metrics: {"bytes_written":16820143,"delete_count":0,"lbm_write_time_us":27701,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":412,"reinsert_count":0,"update_count":2050}
I20260812 06:19:33.913789 29258 maintenance_manager.cc:419] P 1608363c15464f61a61d23583a523e3e: Scheduling FlushDeltaMemStoresOp(759f20969e5f4bc8b5d02de7a708ce88): perf score=6.157687
I20260812 06:19:33.943739 29187 maintenance_manager.cc:643] P 1608363c15464f61a61d23583a523e3e: FlushDeltaMemStoresOp(759f20969e5f4bc8b5d02de7a708ce88) complete. Timing: real 0.030s	user 0.007s	sys 0.019s Metrics: {"bytes_written":7794836,"delete_count":0,"lbm_write_time_us":12422,"lbm_writes_lt_1ms":193,"reinsert_count":0,"update_count":950}
I20260812 06:19:33.944423 29258 maintenance_manager.cc:419] P 1608363c15464f61a61d23583a523e3e: Scheduling MajorDeltaCompactionOp(759f20969e5f4bc8b5d02de7a708ce88): perf score=1.000000
I20260812 06:19:34.145960 29187 maintenance_manager.cc:643] P 1608363c15464f61a61d23583a523e3e: MajorDeltaCompactionOp(759f20969e5f4bc8b5d02de7a708ce88) complete. Timing: real 0.201s	user 0.156s	sys 0.044s Metrics: {"cfile_cache_miss":632,"cfile_cache_miss_bytes":28877101,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":438,"lbm_read_time_us":14215,"lbm_reads_lt_1ms":672,"lbm_write_time_us":34396,"lbm_writes_lt_1ms":643,"mutex_wait_us":70,"peak_mem_usage":75542472,"reinsert_count":0,"update_count":3000}
I20260812 06:19:34.146561 29258 maintenance_manager.cc:419] P 1608363c15464f61a61d23583a523e3e: Scheduling FlushDeltaMemStoresOp(759f20969e5f4bc8b5d02de7a708ce88): perf score=17.071750
I20260812 06:19:34.206875 29187 maintenance_manager.cc:643] P 1608363c15464f61a61d23583a523e3e: FlushDeltaMemStoresOp(759f20969e5f4bc8b5d02de7a708ce88) complete. Timing: real 0.060s	user 0.037s	sys 0.020s Metrics: {"bytes_written":18707249,"delete_count":0,"lbm_write_time_us":26430,"lbm_writes_lt_1ms":459,"reinsert_count":0,"update_count":2280}
I20260812 06:19:34.207540 29258 maintenance_manager.cc:419] P 1608363c15464f61a61d23583a523e3e: Scheduling FlushDeltaMemStoresOp(759f20969e5f4bc8b5d02de7a708ce88): perf score=1.196750
I20260812 06:19:34.228363 29187 maintenance_manager.cc:643] P 1608363c15464f61a61d23583a523e3e: FlushDeltaMemStoresOp(759f20969e5f4bc8b5d02de7a708ce88) complete. Timing: real 0.021s	user 0.006s	sys 0.004s Metrics: {"bytes_written":2215508,"delete_count":0,"lbm_write_time_us":3335,"lbm_writes_lt_1ms":57,"reinsert_count":0,"update_count":270}
I20260812 06:19:34.228819 29258 maintenance_manager.cc:419] P 1608363c15464f61a61d23583a523e3e: Scheduling FlushDeltaMemStoresOp(759f20969e5f4bc8b5d02de7a708ce88): perf score=2.188937
I20260812 06:19:34.238302 29187 maintenance_manager.cc:643] P 1608363c15464f61a61d23583a523e3e: FlushDeltaMemStoresOp(759f20969e5f4bc8b5d02de7a708ce88) complete. Timing: real 0.009s	user 0.008s	sys 0.000s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3508,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:19:34.238762 29258 maintenance_manager.cc:419] P 1608363c15464f61a61d23583a523e3e: Scheduling MajorDeltaCompactionOp(759f20969e5f4bc8b5d02de7a708ce88): perf score=1.000000
I20260812 06:19:34.445729 29187 maintenance_manager.cc:643] P 1608363c15464f61a61d23583a523e3e: MajorDeltaCompactionOp(759f20969e5f4bc8b5d02de7a708ce88) complete. Timing: real 0.207s	user 0.151s	sys 0.055s Metrics: {"cfile_cache_miss":633,"cfile_cache_miss_bytes":28877162,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":783,"lbm_read_time_us":14858,"lbm_reads_lt_1ms":673,"lbm_write_time_us":34498,"lbm_writes_lt_1ms":643,"mutex_wait_us":371,"peak_mem_usage":75542472,"reinsert_count":0,"update_count":3000}
I20260812 06:19:34.446460 29258 maintenance_manager.cc:419] P 1608363c15464f61a61d23583a523e3e: Scheduling FlushDeltaMemStoresOp(759f20969e5f4bc8b5d02de7a708ce88): perf score=14.095187
I20260812 06:19:34.503361 29187 maintenance_manager.cc:643] P 1608363c15464f61a61d23583a523e3e: FlushDeltaMemStoresOp(759f20969e5f4bc8b5d02de7a708ce88) complete. Timing: real 0.057s	user 0.026s	sys 0.020s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":21884,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:34.503928 29258 maintenance_manager.cc:419] P 1608363c15464f61a61d23583a523e3e: Scheduling MajorDeltaCompactionOp(759f20969e5f4bc8b5d02de7a708ce88): perf score=1.000000
I20260812 06:19:34.666340 29187 maintenance_manager.cc:643] P 1608363c15464f61a61d23583a523e3e: MajorDeltaCompactionOp(759f20969e5f4bc8b5d02de7a708ce88) complete. Timing: real 0.162s	user 0.135s	sys 0.027s Metrics: {"cfile_cache_miss":431,"cfile_cache_miss_bytes":20672157,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":1,"delta_iterators_relevant":1,"dirs.queue_time_us":220,"lbm_read_time_us":10705,"lbm_reads_lt_1ms":463,"lbm_write_time_us":26172,"lbm_writes_lt_1ms":443,"mutex_wait_us":51,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":19968,"update_count":2000}
I20260812 06:19:34.667110 29258 maintenance_manager.cc:419] P 1608363c15464f61a61d23583a523e3e: Scheduling FlushDeltaMemStoresOp(759f20969e5f4bc8b5d02de7a708ce88): perf score=14.095187
I20260812 06:19:34.722266 29187 maintenance_manager.cc:643] P 1608363c15464f61a61d23583a523e3e: FlushDeltaMemStoresOp(759f20969e5f4bc8b5d02de7a708ce88) complete. Timing: real 0.055s	user 0.044s	sys 0.007s Metrics: {"bytes_written":16409898,"delete_count":0,"lbm_write_time_us":23726,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:34.722745 29258 maintenance_manager.cc:419] P 1608363c15464f61a61d23583a523e3e: Scheduling FlushDeltaMemStoresOp(759f20969e5f4bc8b5d02de7a708ce88): perf score=2.188937
I20260812 06:19:34.733644 29187 maintenance_manager.cc:643] P 1608363c15464f61a61d23583a523e3e: FlushDeltaMemStoresOp(759f20969e5f4bc8b5d02de7a708ce88) complete. Timing: real 0.011s	user 0.005s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4042,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:34.734468 29258 maintenance_manager.cc:419] P 1608363c15464f61a61d23583a523e3e: Scheduling MajorDeltaCompactionOp(759f20969e5f4bc8b5d02de7a708ce88): perf score=1.000000
I20260812 06:19:34.937815 29187 maintenance_manager.cc:643] P 1608363c15464f61a61d23583a523e3e: MajorDeltaCompactionOp(759f20969e5f4bc8b5d02de7a708ce88) complete. Timing: real 0.203s	user 0.119s	sys 0.070s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774685,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":705,"lbm_read_time_us":12573,"lbm_reads_lt_1ms":572,"lbm_write_time_us":31478,"lbm_writes_lt_1ms":543,"mutex_wait_us":70,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":9984,"update_count":2500}
I20260812 06:19:34.938396 29258 maintenance_manager.cc:419] P 1608363c15464f61a61d23583a523e3e: Scheduling FlushDeltaMemStoresOp(759f20969e5f4bc8b5d02de7a708ce88): perf score=14.095187
I20260812 06:19:34.989622 29187 maintenance_manager.cc:643] P 1608363c15464f61a61d23583a523e3e: FlushDeltaMemStoresOp(759f20969e5f4bc8b5d02de7a708ce88) complete. Timing: real 0.051s	user 0.022s	sys 0.017s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":17464,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:34.990113 29258 maintenance_manager.cc:419] P 1608363c15464f61a61d23583a523e3e: Scheduling FlushDeltaMemStoresOp(759f20969e5f4bc8b5d02de7a708ce88): perf score=2.188937
I20260812 06:19:35.002127 29187 maintenance_manager.cc:643] P 1608363c15464f61a61d23583a523e3e: FlushDeltaMemStoresOp(759f20969e5f4bc8b5d02de7a708ce88) complete. Timing: real 0.012s	user 0.005s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4402,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:35.002630 29258 maintenance_manager.cc:419] P 1608363c15464f61a61d23583a523e3e: Scheduling FlushMRSOp(759f20969e5f4bc8b5d02de7a708ce88): perf score=1.000000
I20260812 06:19:35.032451 29187 maintenance_manager.cc:643] P 1608363c15464f61a61d23583a523e3e: FlushMRSOp(759f20969e5f4bc8b5d02de7a708ce88) complete. Timing: real 0.030s	user 0.022s	sys 0.008s Metrics: {"bytes_written":1152514,"cfile_init":1,"dirs.queue_time_us":66,"dirs.run_cpu_time_us":252,"dirs.run_wall_time_us":1446,"drs_written":1,"lbm_read_time_us":35,"lbm_reads_lt_1ms":4,"lbm_write_time_us":2099,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":28,"spinlock_wait_cycles":23296}
I20260812 06:19:35.033201 29258 maintenance_manager.cc:419] P 1608363c15464f61a61d23583a523e3e: Scheduling LogGCOp(759f20969e5f4bc8b5d02de7a708ce88): free 119647287 bytes of WAL
I20260812 06:19:35.033423 29187 log_reader.cc:385] T 759f20969e5f4bc8b5d02de7a708ce88: removed 12 log segments from log reader
I20260812 06:19:35.033483 29187 log.cc:1079] T 759f20969e5f4bc8b5d02de7a708ce88 P 1608363c15464f61a61d23583a523e3e: Deleting log segment in path: /tmp/dist-test-tasklNF8fM/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515571494869-29067-0/minicluster-data/ts-0-root/wals/759f20969e5f4bc8b5d02de7a708ce88/wal-000000015 (ops 71-74)
I20260812 06:19:35.033543 29187 log.cc:1079] T 759f20969e5f4bc8b5d02de7a708ce88 P 1608363c15464f61a61d23583a523e3e: Deleting log segment in path: /tmp/dist-test-tasklNF8fM/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515571494869-29067-0/minicluster-data/ts-0-root/wals/759f20969e5f4bc8b5d02de7a708ce88/wal-000000016 (ops 75-79)
I20260812 06:19:35.033596 29187 log.cc:1079] T 759f20969e5f4bc8b5d02de7a708ce88 P 1608363c15464f61a61d23583a523e3e: Deleting log segment in path: /tmp/dist-test-tasklNF8fM/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515571494869-29067-0/minicluster-data/ts-0-root/wals/759f20969e5f4bc8b5d02de7a708ce88/wal-000000017 (ops 80-84)
I20260812 06:19:35.033640 29187 log.cc:1079] T 759f20969e5f4bc8b5d02de7a708ce88 P 1608363c15464f61a61d23583a523e3e: Deleting log segment in path: /tmp/dist-test-tasklNF8fM/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515571494869-29067-0/minicluster-data/ts-0-root/wals/759f20969e5f4bc8b5d02de7a708ce88/wal-000000018 (ops 85-88)
I20260812 06:19:35.033679 29187 log.cc:1079] T 759f20969e5f4bc8b5d02de7a708ce88 P 1608363c15464f61a61d23583a523e3e: Deleting log segment in path: /tmp/dist-test-tasklNF8fM/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515571494869-29067-0/minicluster-data/ts-0-root/wals/759f20969e5f4bc8b5d02de7a708ce88/wal-000000019 (ops 89-93)
I20260812 06:19:35.033717 29187 log.cc:1079] T 759f20969e5f4bc8b5d02de7a708ce88 P 1608363c15464f61a61d23583a523e3e: Deleting log segment in path: /tmp/dist-test-tasklNF8fM/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515571494869-29067-0/minicluster-data/ts-0-root/wals/759f20969e5f4bc8b5d02de7a708ce88/wal-000000020 (ops 94-98)
I20260812 06:19:35.033757 29187 log.cc:1079] T 759f20969e5f4bc8b5d02de7a708ce88 P 1608363c15464f61a61d23583a523e3e: Deleting log segment in path: /tmp/dist-test-tasklNF8fM/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515571494869-29067-0/minicluster-data/ts-0-root/wals/759f20969e5f4bc8b5d02de7a708ce88/wal-000000021 (ops 99-102)
I20260812 06:19:35.033797 29187 log.cc:1079] T 759f20969e5f4bc8b5d02de7a708ce88 P 1608363c15464f61a61d23583a523e3e: Deleting log segment in path: /tmp/dist-test-tasklNF8fM/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515571494869-29067-0/minicluster-data/ts-0-root/wals/759f20969e5f4bc8b5d02de7a708ce88/wal-000000022 (ops 103-107)
I20260812 06:19:35.033834 29187 log.cc:1079] T 759f20969e5f4bc8b5d02de7a708ce88 P 1608363c15464f61a61d23583a523e3e: Deleting log segment in path: /tmp/dist-test-tasklNF8fM/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515571494869-29067-0/minicluster-data/ts-0-root/wals/759f20969e5f4bc8b5d02de7a708ce88/wal-000000023 (ops 108-112)
I20260812 06:19:35.033872 29187 log.cc:1079] T 759f20969e5f4bc8b5d02de7a708ce88 P 1608363c15464f61a61d23583a523e3e: Deleting log segment in path: /tmp/dist-test-tasklNF8fM/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515571494869-29067-0/minicluster-data/ts-0-root/wals/759f20969e5f4bc8b5d02de7a708ce88/wal-000000024 (ops 113-117)
I20260812 06:19:35.033910 29187 log.cc:1079] T 759f20969e5f4bc8b5d02de7a708ce88 P 1608363c15464f61a61d23583a523e3e: Deleting log segment in path: /tmp/dist-test-tasklNF8fM/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515571494869-29067-0/minicluster-data/ts-0-root/wals/759f20969e5f4bc8b5d02de7a708ce88/wal-000000025 (ops 118-122)
I20260812 06:19:35.033947 29187 log.cc:1079] T 759f20969e5f4bc8b5d02de7a708ce88 P 1608363c15464f61a61d23583a523e3e: Deleting log segment in path: /tmp/dist-test-tasklNF8fM/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515571494869-29067-0/minicluster-data/ts-0-root/wals/759f20969e5f4bc8b5d02de7a708ce88/wal-000000026 (ops 123-126)
I20260812 06:19:35.059931 29187 maintenance_manager.cc:643] P 1608363c15464f61a61d23583a523e3e: LogGCOp(759f20969e5f4bc8b5d02de7a708ce88) complete. Timing: real 0.027s	user 0.000s	sys 0.023s Metrics: {}
I20260812 06:19:35.060559 29258 maintenance_manager.cc:419] P 1608363c15464f61a61d23583a523e3e: Scheduling FlushDeltaMemStoresOp(759f20969e5f4bc8b5d02de7a708ce88): perf score=2.188937
I20260812 06:19:35.087170 29187 maintenance_manager.cc:643] P 1608363c15464f61a61d23583a523e3e: FlushDeltaMemStoresOp(759f20969e5f4bc8b5d02de7a708ce88) complete. Timing: real 0.026s	user 0.006s	sys 0.005s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4940,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:35.087742 29258 maintenance_manager.cc:419] P 1608363c15464f61a61d23583a523e3e: Scheduling UndoDeltaBlockGCOp(759f20969e5f4bc8b5d02de7a708ce88): 447 bytes on disk
I20260812 06:19:35.088222 29187 maintenance_manager.cc:643] P 1608363c15464f61a61d23583a523e3e: UndoDeltaBlockGCOp(759f20969e5f4bc8b5d02de7a708ce88) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":68,"lbm_reads_lt_1ms":4}
I20260812 06:19:35.088739 29258 maintenance_manager.cc:419] P 1608363c15464f61a61d23583a523e3e: Scheduling FlushDeltaMemStoresOp(759f20969e5f4bc8b5d02de7a708ce88): perf score=2.188937
I20260812 06:19:35.099619 29187 maintenance_manager.cc:643] P 1608363c15464f61a61d23583a523e3e: FlushDeltaMemStoresOp(759f20969e5f4bc8b5d02de7a708ce88) complete. Timing: real 0.011s	user 0.006s	sys 0.003s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4160,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:35.100103 29258 maintenance_manager.cc:419] P 1608363c15464f61a61d23583a523e3e: Scheduling MajorDeltaCompactionOp(759f20969e5f4bc8b5d02de7a708ce88): perf score=1.000000
I20260812 06:19:35.334403 29187 maintenance_manager.cc:643] P 1608363c15464f61a61d23583a523e3e: MajorDeltaCompactionOp(759f20969e5f4bc8b5d02de7a708ce88) complete. Timing: real 0.234s	user 0.153s	sys 0.081s 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":575,"lbm_read_time_us":15152,"lbm_reads_lt_1ms":774,"lbm_write_time_us":40719,"lbm_writes_lt_1ms":743,"mutex_wait_us":63,"peak_mem_usage":87969044,"reinsert_count":0,"spinlock_wait_cycles":14080,"thread_start_us":87,"threads_started":1,"update_count":3500}
I20260812 06:19:35.336690 29258 maintenance_manager.cc:419] P 1608363c15464f61a61d23583a523e3e: Scheduling FlushDeltaMemStoresOp(759f20969e5f4bc8b5d02de7a708ce88): perf score=14.095187
I20260812 06:19:35.392596 29187 maintenance_manager.cc:643] P 1608363c15464f61a61d23583a523e3e: FlushDeltaMemStoresOp(759f20969e5f4bc8b5d02de7a708ce88) complete. Timing: real 0.056s	user 0.031s	sys 0.024s Metrics: {"bytes_written":16409903,"delete_count":0,"lbm_write_time_us":23016,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":402,"reinsert_count":0,"update_count":2000}
I20260812 06:19:35.393251 29258 maintenance_manager.cc:419] P 1608363c15464f61a61d23583a523e3e: Scheduling FlushDeltaMemStoresOp(759f20969e5f4bc8b5d02de7a708ce88): perf score=2.188937
I20260812 06:19:35.414911 29187 maintenance_manager.cc:643] P 1608363c15464f61a61d23583a523e3e: FlushDeltaMemStoresOp(759f20969e5f4bc8b5d02de7a708ce88) complete. Timing: real 0.021s	user 0.014s	sys 0.000s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":6284,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:35.415347 29258 maintenance_manager.cc:419] P 1608363c15464f61a61d23583a523e3e: Scheduling FlushDeltaMemStoresOp(759f20969e5f4bc8b5d02de7a708ce88): perf score=2.188937
I20260812 06:19:35.425813 29187 maintenance_manager.cc:643] P 1608363c15464f61a61d23583a523e3e: FlushDeltaMemStoresOp(759f20969e5f4bc8b5d02de7a708ce88) complete. Timing: real 0.010s	user 0.004s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3943,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:35.426270 29258 maintenance_manager.cc:419] P 1608363c15464f61a61d23583a523e3e: Scheduling MajorDeltaCompactionOp(759f20969e5f4bc8b5d02de7a708ce88): perf score=1.000000
I20260812 06:19:35.638439 29187 maintenance_manager.cc:643] P 1608363c15464f61a61d23583a523e3e: MajorDeltaCompactionOp(759f20969e5f4bc8b5d02de7a708ce88) complete. Timing: real 0.212s	user 0.128s	sys 0.080s Metrics: {"cfile_cache_miss":633,"cfile_cache_miss_bytes":28877220,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":1027,"lbm_read_time_us":15648,"lbm_reads_lt_1ms":673,"lbm_write_time_us":33559,"lbm_writes_lt_1ms":643,"mutex_wait_us":269,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":12672,"update_count":3000}
I20260812 06:19:35.639256 29258 maintenance_manager.cc:419] P 1608363c15464f61a61d23583a523e3e: Scheduling FlushDeltaMemStoresOp(759f20969e5f4bc8b5d02de7a708ce88): perf score=17.071750
I20260812 06:19:35.693269 29187 maintenance_manager.cc:643] P 1608363c15464f61a61d23583a523e3e: FlushDeltaMemStoresOp(759f20969e5f4bc8b5d02de7a708ce88) complete. Timing: real 0.054s	user 0.034s	sys 0.015s Metrics: {"bytes_written":19404660,"delete_count":0,"lbm_write_time_us":22340,"lbm_writes_lt_1ms":476,"reinsert_count":0,"update_count":2365}
I20260812 06:19:35.693998 29258 maintenance_manager.cc:419] P 1608363c15464f61a61d23583a523e3e: Scheduling FlushDeltaMemStoresOp(759f20969e5f4bc8b5d02de7a708ce88): perf score=1.000000
I20260812 06:19:35.703943 29187 maintenance_manager.cc:643] P 1608363c15464f61a61d23583a523e3e: FlushDeltaMemStoresOp(759f20969e5f4bc8b5d02de7a708ce88) complete. Timing: real 0.010s	user 0.004s	sys 0.000s Metrics: {"bytes_written":1518081,"delete_count":0,"lbm_write_time_us":1750,"lbm_writes_lt_1ms":40,"reinsert_count":0,"update_count":185}
I20260812 06:19:35.704449 29258 maintenance_manager.cc:419] P 1608363c15464f61a61d23583a523e3e: Scheduling FlushDeltaMemStoresOp(759f20969e5f4bc8b5d02de7a708ce88): perf score=2.188937
I20260812 06:19:35.714412 29187 maintenance_manager.cc:643] P 1608363c15464f61a61d23583a523e3e: FlushDeltaMemStoresOp(759f20969e5f4bc8b5d02de7a708ce88) complete. Timing: real 0.010s	user 0.008s	sys 0.000s 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:19:35.714890 29258 maintenance_manager.cc:419] P 1608363c15464f61a61d23583a523e3e: Scheduling MajorDeltaCompactionOp(759f20969e5f4bc8b5d02de7a708ce88): perf score=1.000000
I20260812 06:19:35.919299 29187 maintenance_manager.cc:643] P 1608363c15464f61a61d23583a523e3e: MajorDeltaCompactionOp(759f20969e5f4bc8b5d02de7a708ce88) complete. Timing: real 0.204s	user 0.119s	sys 0.080s Metrics: {"cfile_cache_miss":633,"cfile_cache_miss_bytes":28877147,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":841,"lbm_read_time_us":19536,"lbm_reads_1-10_ms":1,"lbm_reads_lt_1ms":672,"lbm_write_time_us":35118,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":642,"mutex_wait_us":347,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":7424,"update_count":3000}
I20260812 06:19:35.919978 29258 maintenance_manager.cc:419] P 1608363c15464f61a61d23583a523e3e: Scheduling FlushDeltaMemStoresOp(759f20969e5f4bc8b5d02de7a708ce88): perf score=14.095187
I20260812 06:19:35.983433 29187 maintenance_manager.cc:643] P 1608363c15464f61a61d23583a523e3e: FlushDeltaMemStoresOp(759f20969e5f4bc8b5d02de7a708ce88) complete. Timing: real 0.063s	user 0.041s	sys 0.013s Metrics: {"bytes_written":16409905,"delete_count":0,"lbm_write_time_us":24676,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:35.983942 29258 maintenance_manager.cc:419] P 1608363c15464f61a61d23583a523e3e: Scheduling FlushDeltaMemStoresOp(759f20969e5f4bc8b5d02de7a708ce88): perf score=2.188937
I20260812 06:19:35.996121 29187 maintenance_manager.cc:643] P 1608363c15464f61a61d23583a523e3e: FlushDeltaMemStoresOp(759f20969e5f4bc8b5d02de7a708ce88) complete. Timing: real 0.012s	user 0.001s	sys 0.009s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4377,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:35.996572 29258 maintenance_manager.cc:419] P 1608363c15464f61a61d23583a523e3e: Scheduling MajorDeltaCompactionOp(759f20969e5f4bc8b5d02de7a708ce88): perf score=1.000000
I20260812 06:19:36.164543 29187 maintenance_manager.cc:643] P 1608363c15464f61a61d23583a523e3e: MajorDeltaCompactionOp(759f20969e5f4bc8b5d02de7a708ce88) complete. Timing: real 0.168s	user 0.114s	sys 0.052s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774692,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":754,"lbm_read_time_us":12555,"lbm_reads_lt_1ms":572,"lbm_write_time_us":29411,"lbm_writes_lt_1ms":543,"mutex_wait_us":357,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":1536,"update_count":2500}
I20260812 06:19:36.165252 29258 maintenance_manager.cc:419] P 1608363c15464f61a61d23583a523e3e: Scheduling FlushDeltaMemStoresOp(759f20969e5f4bc8b5d02de7a708ce88): perf score=14.095187
I20260812 06:19:36.217636 29187 maintenance_manager.cc:643] P 1608363c15464f61a61d23583a523e3e: FlushDeltaMemStoresOp(759f20969e5f4bc8b5d02de7a708ce88) complete. Timing: real 0.052s	user 0.022s	sys 0.028s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":24432,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":402,"reinsert_count":0,"update_count":2000}
I20260812 06:19:36.218173 29258 maintenance_manager.cc:419] P 1608363c15464f61a61d23583a523e3e: Scheduling FlushDeltaMemStoresOp(759f20969e5f4bc8b5d02de7a708ce88): perf score=2.188937
I20260812 06:19:36.229101 29187 maintenance_manager.cc:643] P 1608363c15464f61a61d23583a523e3e: FlushDeltaMemStoresOp(759f20969e5f4bc8b5d02de7a708ce88) complete. Timing: real 0.011s	user 0.009s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4201,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:36.229593 29258 maintenance_manager.cc:419] P 1608363c15464f61a61d23583a523e3e: Scheduling MajorDeltaCompactionOp(759f20969e5f4bc8b5d02de7a708ce88): perf score=1.000000
I20260812 06:19:36.412154 29187 maintenance_manager.cc:643] P 1608363c15464f61a61d23583a523e3e: MajorDeltaCompactionOp(759f20969e5f4bc8b5d02de7a708ce88) complete. Timing: real 0.182s	user 0.137s	sys 0.034s 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":316,"lbm_read_time_us":13499,"lbm_reads_lt_1ms":572,"lbm_write_time_us":29642,"lbm_writes_lt_1ms":543,"mutex_wait_us":38,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":768,"update_count":2500}
I20260812 06:19:36.412714 29258 maintenance_manager.cc:419] P 1608363c15464f61a61d23583a523e3e: Scheduling FlushDeltaMemStoresOp(759f20969e5f4bc8b5d02de7a708ce88): perf score=14.095187
I20260812 06:19:36.477592 29187 maintenance_manager.cc:643] P 1608363c15464f61a61d23583a523e3e: FlushDeltaMemStoresOp(759f20969e5f4bc8b5d02de7a708ce88) complete. Timing: real 0.065s	user 0.026s	sys 0.036s Metrics: {"bytes_written":16409903,"delete_count":0,"lbm_write_time_us":25214,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":402,"reinsert_count":0,"update_count":2000}
I20260812 06:19:36.478189 29258 maintenance_manager.cc:419] P 1608363c15464f61a61d23583a523e3e: Scheduling FlushDeltaMemStoresOp(759f20969e5f4bc8b5d02de7a708ce88): perf score=2.188937
I20260812 06:19:36.489094 29187 maintenance_manager.cc:643] P 1608363c15464f61a61d23583a523e3e: FlushDeltaMemStoresOp(759f20969e5f4bc8b5d02de7a708ce88) complete. Timing: real 0.011s	user 0.001s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4272,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:36.489670 29258 maintenance_manager.cc:419] P 1608363c15464f61a61d23583a523e3e: Scheduling FlushMRSOp(759f20969e5f4bc8b5d02de7a708ce88): perf score=1.000000
I20260812 06:19:36.522442 29187 maintenance_manager.cc:643] P 1608363c15464f61a61d23583a523e3e: FlushMRSOp(759f20969e5f4bc8b5d02de7a708ce88) complete. Timing: real 0.033s	user 0.027s	sys 0.003s Metrics: {"bytes_written":1193505,"cfile_init":1,"dirs.queue_time_us":77,"dirs.run_cpu_time_us":250,"dirs.run_wall_time_us":1503,"drs_written":1,"lbm_read_time_us":39,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1375,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":29}
I20260812 06:19:36.523141 29258 maintenance_manager.cc:419] P 1608363c15464f61a61d23583a523e3e: Scheduling MajorDeltaCompactionOp(759f20969e5f4bc8b5d02de7a708ce88): perf score=1.000000
I20260812 06:19:36.684991 29187 maintenance_manager.cc:643] P 1608363c15464f61a61d23583a523e3e: MajorDeltaCompactionOp(759f20969e5f4bc8b5d02de7a708ce88) complete. Timing: real 0.162s	user 0.118s	sys 0.044s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774690,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":1290,"lbm_read_time_us":11121,"lbm_reads_lt_1ms":564,"lbm_write_time_us":27574,"lbm_writes_lt_1ms":543,"mutex_wait_us":335,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":9344,"update_count":2500}
I20260812 06:19:36.685801 29258 maintenance_manager.cc:419] P 1608363c15464f61a61d23583a523e3e: Scheduling LogGCOp(759f20969e5f4bc8b5d02de7a708ce88): free 121006639 bytes of WAL
I20260812 06:19:36.686074 29187 log_reader.cc:385] T 759f20969e5f4bc8b5d02de7a708ce88: removed 12 log segments from log reader
I20260812 06:19:36.686126 29187 log.cc:1079] T 759f20969e5f4bc8b5d02de7a708ce88 P 1608363c15464f61a61d23583a523e3e: Deleting log segment in path: /tmp/dist-test-tasklNF8fM/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515571494869-29067-0/minicluster-data/ts-0-root/wals/759f20969e5f4bc8b5d02de7a708ce88/wal-000000027 (ops 127-131)
I20260812 06:19:36.686174 29187 log.cc:1079] T 759f20969e5f4bc8b5d02de7a708ce88 P 1608363c15464f61a61d23583a523e3e: Deleting log segment in path: /tmp/dist-test-tasklNF8fM/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515571494869-29067-0/minicluster-data/ts-0-root/wals/759f20969e5f4bc8b5d02de7a708ce88/wal-000000028 (ops 132-136)
I20260812 06:19:36.686218 29187 log.cc:1079] T 759f20969e5f4bc8b5d02de7a708ce88 P 1608363c15464f61a61d23583a523e3e: Deleting log segment in path: /tmp/dist-test-tasklNF8fM/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515571494869-29067-0/minicluster-data/ts-0-root/wals/759f20969e5f4bc8b5d02de7a708ce88/wal-000000029 (ops 137-140)
I20260812 06:19:36.686261 29187 log.cc:1079] T 759f20969e5f4bc8b5d02de7a708ce88 P 1608363c15464f61a61d23583a523e3e: Deleting log segment in path: /tmp/dist-test-tasklNF8fM/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515571494869-29067-0/minicluster-data/ts-0-root/wals/759f20969e5f4bc8b5d02de7a708ce88/wal-000000030 (ops 141-145)
I20260812 06:19:36.686304 29187 log.cc:1079] T 759f20969e5f4bc8b5d02de7a708ce88 P 1608363c15464f61a61d23583a523e3e: Deleting log segment in path: /tmp/dist-test-tasklNF8fM/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515571494869-29067-0/minicluster-data/ts-0-root/wals/759f20969e5f4bc8b5d02de7a708ce88/wal-000000031 (ops 146-150)
I20260812 06:19:36.686398 29187 log.cc:1079] T 759f20969e5f4bc8b5d02de7a708ce88 P 1608363c15464f61a61d23583a523e3e: Deleting log segment in path: /tmp/dist-test-tasklNF8fM/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515571494869-29067-0/minicluster-data/ts-0-root/wals/759f20969e5f4bc8b5d02de7a708ce88/wal-000000032 (ops 151-155)
I20260812 06:19:36.686466 29187 log.cc:1079] T 759f20969e5f4bc8b5d02de7a708ce88 P 1608363c15464f61a61d23583a523e3e: Deleting log segment in path: /tmp/dist-test-tasklNF8fM/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515571494869-29067-0/minicluster-data/ts-0-root/wals/759f20969e5f4bc8b5d02de7a708ce88/wal-000000033 (ops 156-160)
I20260812 06:19:36.686504 29187 log.cc:1079] T 759f20969e5f4bc8b5d02de7a708ce88 P 1608363c15464f61a61d23583a523e3e: Deleting log segment in path: /tmp/dist-test-tasklNF8fM/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515571494869-29067-0/minicluster-data/ts-0-root/wals/759f20969e5f4bc8b5d02de7a708ce88/wal-000000034 (ops 161-165)
I20260812 06:19:36.686587 29187 log.cc:1079] T 759f20969e5f4bc8b5d02de7a708ce88 P 1608363c15464f61a61d23583a523e3e: Deleting log segment in path: /tmp/dist-test-tasklNF8fM/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515571494869-29067-0/minicluster-data/ts-0-root/wals/759f20969e5f4bc8b5d02de7a708ce88/wal-000000035 (ops 166-170)
I20260812 06:19:36.686635 29187 log.cc:1079] T 759f20969e5f4bc8b5d02de7a708ce88 P 1608363c15464f61a61d23583a523e3e: Deleting log segment in path: /tmp/dist-test-tasklNF8fM/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515571494869-29067-0/minicluster-data/ts-0-root/wals/759f20969e5f4bc8b5d02de7a708ce88/wal-000000036 (ops 171-175)
I20260812 06:19:36.686704 29187 log.cc:1079] T 759f20969e5f4bc8b5d02de7a708ce88 P 1608363c15464f61a61d23583a523e3e: Deleting log segment in path: /tmp/dist-test-tasklNF8fM/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515571494869-29067-0/minicluster-data/ts-0-root/wals/759f20969e5f4bc8b5d02de7a708ce88/wal-000000037 (ops 176-180)
I20260812 06:19:36.686749 29187 log.cc:1079] T 759f20969e5f4bc8b5d02de7a708ce88 P 1608363c15464f61a61d23583a523e3e: Deleting log segment in path: /tmp/dist-test-tasklNF8fM/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515571494869-29067-0/minicluster-data/ts-0-root/wals/759f20969e5f4bc8b5d02de7a708ce88/wal-000000038 (ops 181-185)
I20260812 06:19:36.718325 29187 maintenance_manager.cc:643] P 1608363c15464f61a61d23583a523e3e: LogGCOp(759f20969e5f4bc8b5d02de7a708ce88) complete. Timing: real 0.032s	user 0.001s	sys 0.028s Metrics: {}
I20260812 06:19:36.718868 29258 maintenance_manager.cc:419] P 1608363c15464f61a61d23583a523e3e: Scheduling UndoDeltaBlockGCOp(759f20969e5f4bc8b5d02de7a708ce88): 463 bytes on disk
I20260812 06:19:36.719674 29187 maintenance_manager.cc:643] P 1608363c15464f61a61d23583a523e3e: UndoDeltaBlockGCOp(759f20969e5f4bc8b5d02de7a708ce88) complete. Timing: real 0.001s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":70,"lbm_reads_lt_1ms":4}
I20260812 06:19:36.720359 29258 maintenance_manager.cc:419] P 1608363c15464f61a61d23583a523e3e: Scheduling FlushDeltaMemStoresOp(759f20969e5f4bc8b5d02de7a708ce88): perf score=18.063937
I20260812 06:19:36.787269 29187 maintenance_manager.cc:643] P 1608363c15464f61a61d23583a523e3e: FlushDeltaMemStoresOp(759f20969e5f4bc8b5d02de7a708ce88) complete. Timing: real 0.067s	user 0.041s	sys 0.022s Metrics: {"bytes_written":20102075,"delete_count":0,"lbm_write_time_us":26553,"lbm_writes_lt_1ms":493,"reinsert_count":0,"update_count":2450}
I20260812 06:19:36.787901 29258 maintenance_manager.cc:419] P 1608363c15464f61a61d23583a523e3e: Scheduling FlushDeltaMemStoresOp(759f20969e5f4bc8b5d02de7a708ce88): perf score=3.181125
I20260812 06:19:36.800251 29187 maintenance_manager.cc:643] P 1608363c15464f61a61d23583a523e3e: FlushDeltaMemStoresOp(759f20969e5f4bc8b5d02de7a708ce88) complete. Timing: real 0.012s	user 0.011s	sys 0.001s Metrics: {"bytes_written":4512903,"delete_count":0,"lbm_write_time_us":4637,"lbm_writes_lt_1ms":113,"reinsert_count":0,"update_count":550}
I20260812 06:19:36.800719 29258 maintenance_manager.cc:419] P 1608363c15464f61a61d23583a523e3e: Scheduling MajorDeltaCompactionOp(759f20969e5f4bc8b5d02de7a708ce88): perf score=1.000000
I20260812 06:19:36.951246 29067 heavy-update-compaction-itest.cc:229] Time spent updating: real 5.130s	user 1.857s	sys 0.179s
I20260812 06:19:36.992384 29187 maintenance_manager.cc:643] P 1608363c15464f61a61d23583a523e3e: MajorDeltaCompactionOp(759f20969e5f4bc8b5d02de7a708ce88) complete. Timing: real 0.191s	user 0.143s	sys 0.048s Metrics: {"cfile_cache_miss":632,"cfile_cache_miss_bytes":28877106,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"lbm_read_time_us":15448,"lbm_reads_lt_1ms":668,"lbm_write_time_us":35064,"lbm_writes_lt_1ms":643,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":1408,"update_count":3000}
I20260812 06:19:36.992926 29258 maintenance_manager.cc:419] P 1608363c15464f61a61d23583a523e3e: Scheduling FlushDeltaMemStoresOp(759f20969e5f4bc8b5d02de7a708ce88): perf score=10.126437
I20260812 06:19:37.020416 29067 heavy-update-compaction-itest.cc:265] Time spent scanning: real 0.069s	user 0.005s	sys 0.000s
I20260812 06:19:37.021235 29067 tablet_server.cc:179] TabletServer@127.28.98.193:0 shutting down...
I20260812 06:19:37.039388 29187 maintenance_manager.cc:643] P 1608363c15464f61a61d23583a523e3e: FlushDeltaMemStoresOp(759f20969e5f4bc8b5d02de7a708ce88) complete. Timing: real 0.046s	user 0.010s	sys 0.032s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":18588,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:19:37.040105 29067 ts_tablet_manager.cc:1507] Shutting down tablet manager...
I20260812 06:19:37.040571 29067 tablet_replica.cc:333] T 759f20969e5f4bc8b5d02de7a708ce88 P 1608363c15464f61a61d23583a523e3e: stopping tablet replica
I20260812 06:19:37.041020 29067 raft_consensus.cc:2243] T 759f20969e5f4bc8b5d02de7a708ce88 P 1608363c15464f61a61d23583a523e3e [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:19:37.051781 29067 raft_consensus.cc:2272] T 759f20969e5f4bc8b5d02de7a708ce88 P 1608363c15464f61a61d23583a523e3e [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:19:37.067888 29067 tablet_server.cc:196] TabletServer@127.28.98.193:0 shutdown complete.
I20260812 06:19:37.073267 29067 master.cc:562] Master@127.28.98.254:44569 shutting down...
I20260812 06:19:37.078224 29067 raft_consensus.cc:2243] T 00000000000000000000000000000000 P 466489bda773402ba69d1ff65a300df7 [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:19:37.078397 29067 raft_consensus.cc:2272] T 00000000000000000000000000000000 P 466489bda773402ba69d1ff65a300df7 [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:19:37.078464 29067 tablet_replica.cc:333] T 00000000000000000000000000000000 P 466489bda773402ba69d1ff65a300df7: stopping tablet replica
I20260812 06:19:37.091954 29067 master.cc:584] Master@127.28.98.254:44569 shutdown complete.
[       OK ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/0 (5680 ms)
[ RUN      ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/1
I20260812 06:19:37.185869 29067 internal_mini_cluster.cc:156] Creating distributed mini masters. Addrs: 127.28.98.254:40745
I20260812 06:19:37.186254 29067 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:19:37.188773 29295 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:19:37.188807 29294 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:19:37.188773 29298 instance_detector.cc:116] could not retrieve OpenStack instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:19:37.188987 29067 server_base.cc:1061] running on GCE node
I20260812 06:19:37.189273 29067 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:19:37.189311 29067 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:19:37.189327 29067 hybrid_clock.cc:648] HybridClock initialized: now 1786515577189327 us; error 0 us; skew 500 ppm
I20260812 06:19:37.190254 29067 webserver.cc:533] Webserver started at http://127.28.98.254:37901/ using document root <none> and password file <none>
I20260812 06:19:37.190430 29067 fs_manager.cc:362] Metadata directory not provided
I20260812 06:19:37.190479 29067 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:19:37.190574 29067 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:19:37.190979 29067 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-tasklNF8fM/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515571494869-29067-0/minicluster-data/master-0-root/instance:
uuid: "f2e25696e2f84f73880e0bdc616a70df"
format_stamp: "Formatted at 2026-08-12 06:19:37 on dist-test-slave-1zqn"
I20260812 06:19:37.192592 29067 fs_manager.cc:696] Time spent creating directory manager: real 0.001s	user 0.002s	sys 0.000s
I20260812 06:19:37.193645 29305 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:19:37.193951 29067 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.001s	sys 0.000s
I20260812 06:19:37.194049 29067 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-tasklNF8fM/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515571494869-29067-0/minicluster-data/master-0-root
uuid: "f2e25696e2f84f73880e0bdc616a70df"
format_stamp: "Formatted at 2026-08-12 06:19:37 on dist-test-slave-1zqn"
I20260812 06:19:37.194150 29067 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-tasklNF8fM/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515571494869-29067-0/minicluster-data/master-0-root
metadata directory: /tmp/dist-test-tasklNF8fM/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515571494869-29067-0/minicluster-data/master-0-root
1 data directories: /tmp/dist-test-tasklNF8fM/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515571494869-29067-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:19:37.202056 29067 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:19:37.202433 29067 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:19:37.206708 29067 rpc_server.cc:307] RPC server started. Bound to: 127.28.98.254:40745
I20260812 06:19:37.208771 29369 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:19:37.209298 29368 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.28.98.254:40745 every 8 connection(s)
I20260812 06:19:37.214175 29369 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P f2e25696e2f84f73880e0bdc616a70df: Bootstrap starting.
I20260812 06:19:37.215003 29369 tablet_bootstrap.cc:654] T 00000000000000000000000000000000 P f2e25696e2f84f73880e0bdc616a70df: Neither blocks nor log segments found. Creating new log.
I20260812 06:19:37.216137 29369 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P f2e25696e2f84f73880e0bdc616a70df: No bootstrap required, opened a new log
I20260812 06:19:37.216552 29369 raft_consensus.cc:359] T 00000000000000000000000000000000 P f2e25696e2f84f73880e0bdc616a70df [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "f2e25696e2f84f73880e0bdc616a70df" member_type: VOTER }
I20260812 06:19:37.216641 29369 raft_consensus.cc:385] T 00000000000000000000000000000000 P f2e25696e2f84f73880e0bdc616a70df [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:19:37.216665 29369 raft_consensus.cc:740] T 00000000000000000000000000000000 P f2e25696e2f84f73880e0bdc616a70df [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: f2e25696e2f84f73880e0bdc616a70df, State: Initialized, Role: FOLLOWER
I20260812 06:19:37.216822 29369 consensus_queue.cc:260] T 00000000000000000000000000000000 P f2e25696e2f84f73880e0bdc616a70df [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: "f2e25696e2f84f73880e0bdc616a70df" member_type: VOTER }
I20260812 06:19:37.216928 29369 raft_consensus.cc:399] T 00000000000000000000000000000000 P f2e25696e2f84f73880e0bdc616a70df [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:19:37.216966 29369 raft_consensus.cc:493] T 00000000000000000000000000000000 P f2e25696e2f84f73880e0bdc616a70df [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:19:37.217000 29369 raft_consensus.cc:3060] T 00000000000000000000000000000000 P f2e25696e2f84f73880e0bdc616a70df [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:19:37.217692 29369 raft_consensus.cc:515] T 00000000000000000000000000000000 P f2e25696e2f84f73880e0bdc616a70df [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "f2e25696e2f84f73880e0bdc616a70df" member_type: VOTER }
I20260812 06:19:37.217808 29369 leader_election.cc:304] T 00000000000000000000000000000000 P f2e25696e2f84f73880e0bdc616a70df [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: f2e25696e2f84f73880e0bdc616a70df; no voters: 
I20260812 06:19:37.217963 29369 leader_election.cc:290] T 00000000000000000000000000000000 P f2e25696e2f84f73880e0bdc616a70df [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:19:37.218109 29373 raft_consensus.cc:2804] T 00000000000000000000000000000000 P f2e25696e2f84f73880e0bdc616a70df [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:19:37.218328 29373 raft_consensus.cc:697] T 00000000000000000000000000000000 P f2e25696e2f84f73880e0bdc616a70df [term 1 LEADER]: Becoming Leader. State: Replica: f2e25696e2f84f73880e0bdc616a70df, State: Running, Role: LEADER
I20260812 06:19:37.218475 29373 consensus_queue.cc:237] T 00000000000000000000000000000000 P f2e25696e2f84f73880e0bdc616a70df [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: "f2e25696e2f84f73880e0bdc616a70df" member_type: VOTER }
I20260812 06:19:37.218475 29369 sys_catalog.cc:565] T 00000000000000000000000000000000 P f2e25696e2f84f73880e0bdc616a70df [sys.catalog]: configured and running, proceeding with master startup.
I20260812 06:19:37.219049 29374 sys_catalog.cc:455] T 00000000000000000000000000000000 P f2e25696e2f84f73880e0bdc616a70df [sys.catalog]: SysCatalogTable state changed. Reason: RaftConsensus started. Latest consensus state: current_term: 1 leader_uuid: "f2e25696e2f84f73880e0bdc616a70df" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "f2e25696e2f84f73880e0bdc616a70df" member_type: VOTER } }
I20260812 06:19:37.219058 29375 sys_catalog.cc:455] T 00000000000000000000000000000000 P f2e25696e2f84f73880e0bdc616a70df [sys.catalog]: SysCatalogTable state changed. Reason: New leader f2e25696e2f84f73880e0bdc616a70df. Latest consensus state: current_term: 1 leader_uuid: "f2e25696e2f84f73880e0bdc616a70df" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "f2e25696e2f84f73880e0bdc616a70df" member_type: VOTER } }
I20260812 06:19:37.219211 29375 sys_catalog.cc:458] T 00000000000000000000000000000000 P f2e25696e2f84f73880e0bdc616a70df [sys.catalog]: This master's current role is: LEADER
I20260812 06:19:37.219290 29374 sys_catalog.cc:458] T 00000000000000000000000000000000 P f2e25696e2f84f73880e0bdc616a70df [sys.catalog]: This master's current role is: LEADER
I20260812 06:19:37.219944 29377 catalog_manager.cc:1511] Loading table and tablet metadata into memory...
I20260812 06:19:37.220942 29377 catalog_manager.cc:1520] Initializing Kudu cluster ID...
I20260812 06:19:37.221194 29067 internal_mini_cluster.cc:184] Waiting to initialize catalog manager on master 0
I20260812 06:19:37.222942 29377 catalog_manager.cc:1383] Generated new cluster ID: a2a9bce2fc45458b888db23ec5a3627c
I20260812 06:19:37.223007 29377 catalog_manager.cc:1531] Initializing Kudu internal certificate authority...
I20260812 06:19:37.235523 29377 catalog_manager.cc:1406] Generated new certificate authority record
I20260812 06:19:37.236187 29377 catalog_manager.cc:1540] Loading token signing keys...
I20260812 06:19:37.242250 29377 catalog_manager.cc:6092] T 00000000000000000000000000000000 P f2e25696e2f84f73880e0bdc616a70df: Generated new TSK 0
I20260812 06:19:37.242456 29377 catalog_manager.cc:1550] Initializing in-progress tserver states...
I20260812 06:19:37.253808 29067 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:19:37.256126 29393 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:19:37.256233 29394 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:19:37.256206 29067 server_base.cc:1061] running on GCE node
W20260812 06:19:37.256136 29396 instance_detector.cc:116] could not retrieve OpenStack instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:19:37.256554 29067 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:19:37.256628 29067 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:19:37.256645 29067 hybrid_clock.cc:648] HybridClock initialized: now 1786515577256646 us; error 0 us; skew 500 ppm
I20260812 06:19:37.257439 29067 webserver.cc:533] Webserver started at http://127.28.98.193:37987/ using document root <none> and password file <none>
I20260812 06:19:37.257586 29067 fs_manager.cc:362] Metadata directory not provided
I20260812 06:19:37.257661 29067 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:19:37.257728 29067 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:19:37.258131 29067 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-tasklNF8fM/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515571494869-29067-0/minicluster-data/ts-0-root/instance:
uuid: "74618a9db2da473a9aa3a1560ea503db"
format_stamp: "Formatted at 2026-08-12 06:19:37 on dist-test-slave-1zqn"
I20260812 06:19:37.259622 29067 fs_manager.cc:696] Time spent creating directory manager: real 0.001s	user 0.002s	sys 0.000s
I20260812 06:19:37.260573 29401 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:19:37.260823 29067 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.000s	sys 0.000s
I20260812 06:19:37.260910 29067 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-tasklNF8fM/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515571494869-29067-0/minicluster-data/ts-0-root
uuid: "74618a9db2da473a9aa3a1560ea503db"
format_stamp: "Formatted at 2026-08-12 06:19:37 on dist-test-slave-1zqn"
I20260812 06:19:37.260993 29067 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-tasklNF8fM/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515571494869-29067-0/minicluster-data/ts-0-root
metadata directory: /tmp/dist-test-tasklNF8fM/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515571494869-29067-0/minicluster-data/ts-0-root
1 data directories: /tmp/dist-test-tasklNF8fM/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515571494869-29067-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:19:37.295058 29067 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:19:37.295536 29067 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:19:37.295881 29067 txn_system_client.cc:432] TxnSystemClient initialization is disabled...
I20260812 06:19:37.296435 29067 ts_tablet_manager.cc:585] Loaded tablet metadata (0 total tablets, 0 live tablets)
I20260812 06:19:37.296494 29067 ts_tablet_manager.cc:531] Time spent load tablet metadata: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:19:37.296554 29067 ts_tablet_manager.cc:616] Registered 0 tablets
I20260812 06:19:37.296607 29067 ts_tablet_manager.cc:595] Time spent register tablets: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:19:37.301448 29067 rpc_server.cc:307] RPC server started. Bound to: 127.28.98.193:34033
I20260812 06:19:37.303776 29474 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.28.98.193:34033 every 8 connection(s)
I20260812 06:19:37.313532 29475 heartbeater.cc:344] Connected to a master server at 127.28.98.254:40745
I20260812 06:19:37.313642 29475 heartbeater.cc:461] Registering TS with master...
I20260812 06:19:37.313897 29475 heartbeater.cc:507] Master 127.28.98.254:40745 requested a full tablet report, sending...
I20260812 06:19:37.314620 29326 ts_manager.cc:194] Registered new tserver with Master: 74618a9db2da473a9aa3a1560ea503db (127.28.98.193:34033)
I20260812 06:19:37.314800 29067 internal_mini_cluster.cc:371] 1 TS(s) registered with all masters after 0.012282017s
I20260812 06:19:37.315562 29326 master_service.cc:502] Signed X509 certificate for tserver {username='slave'} at 127.0.0.1:47502
I20260812 06:19:37.322769 29326 catalog_manager.cc:2283] Servicing CreateTable request from {username='slave'} at 127.0.0.1:47516:
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:19:37.332357 29432 tablet_service.cc:1511] Processing CreateTablet for tablet f033abff6faa4575bf15a0f48ebf2954 (DEFAULT_TABLE table=heavy-update-compaction-test [id=2155a3b6821a4cacbe23287c7ea190d5]), partition=
I20260812 06:19:37.332631 29432 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet f033abff6faa4575bf15a0f48ebf2954. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:19:37.334830 29488 tablet_bootstrap.cc:492] T f033abff6faa4575bf15a0f48ebf2954 P 74618a9db2da473a9aa3a1560ea503db: Bootstrap starting.
I20260812 06:19:37.335784 29488 tablet_bootstrap.cc:654] T f033abff6faa4575bf15a0f48ebf2954 P 74618a9db2da473a9aa3a1560ea503db: Neither blocks nor log segments found. Creating new log.
I20260812 06:19:37.337162 29488 tablet_bootstrap.cc:492] T f033abff6faa4575bf15a0f48ebf2954 P 74618a9db2da473a9aa3a1560ea503db: No bootstrap required, opened a new log
I20260812 06:19:37.337265 29488 ts_tablet_manager.cc:1403] T f033abff6faa4575bf15a0f48ebf2954 P 74618a9db2da473a9aa3a1560ea503db: Time spent bootstrapping tablet: real 0.002s	user 0.002s	sys 0.000s
I20260812 06:19:37.337798 29488 raft_consensus.cc:359] T f033abff6faa4575bf15a0f48ebf2954 P 74618a9db2da473a9aa3a1560ea503db [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "74618a9db2da473a9aa3a1560ea503db" member_type: VOTER last_known_addr { host: "127.28.98.193" port: 34033 } }
I20260812 06:19:37.337888 29488 raft_consensus.cc:385] T f033abff6faa4575bf15a0f48ebf2954 P 74618a9db2da473a9aa3a1560ea503db [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:19:37.337911 29488 raft_consensus.cc:740] T f033abff6faa4575bf15a0f48ebf2954 P 74618a9db2da473a9aa3a1560ea503db [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: 74618a9db2da473a9aa3a1560ea503db, State: Initialized, Role: FOLLOWER
I20260812 06:19:37.338100 29488 consensus_queue.cc:260] T f033abff6faa4575bf15a0f48ebf2954 P 74618a9db2da473a9aa3a1560ea503db [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: "74618a9db2da473a9aa3a1560ea503db" member_type: VOTER last_known_addr { host: "127.28.98.193" port: 34033 } }
I20260812 06:19:37.338191 29488 raft_consensus.cc:399] T f033abff6faa4575bf15a0f48ebf2954 P 74618a9db2da473a9aa3a1560ea503db [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:19:37.338255 29488 raft_consensus.cc:493] T f033abff6faa4575bf15a0f48ebf2954 P 74618a9db2da473a9aa3a1560ea503db [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:19:37.338313 29488 raft_consensus.cc:3060] T f033abff6faa4575bf15a0f48ebf2954 P 74618a9db2da473a9aa3a1560ea503db [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:19:37.339043 29488 raft_consensus.cc:515] T f033abff6faa4575bf15a0f48ebf2954 P 74618a9db2da473a9aa3a1560ea503db [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "74618a9db2da473a9aa3a1560ea503db" member_type: VOTER last_known_addr { host: "127.28.98.193" port: 34033 } }
I20260812 06:19:37.339162 29488 leader_election.cc:304] T f033abff6faa4575bf15a0f48ebf2954 P 74618a9db2da473a9aa3a1560ea503db [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: 74618a9db2da473a9aa3a1560ea503db; no voters: 
I20260812 06:19:37.339388 29488 leader_election.cc:290] T f033abff6faa4575bf15a0f48ebf2954 P 74618a9db2da473a9aa3a1560ea503db [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:19:37.339533 29490 raft_consensus.cc:2804] T f033abff6faa4575bf15a0f48ebf2954 P 74618a9db2da473a9aa3a1560ea503db [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:19:37.339731 29488 ts_tablet_manager.cc:1434] T f033abff6faa4575bf15a0f48ebf2954 P 74618a9db2da473a9aa3a1560ea503db: Time spent starting tablet: real 0.002s	user 0.003s	sys 0.000s
I20260812 06:19:37.339785 29475 heartbeater.cc:499] Master 127.28.98.254:40745 was elected leader, sending a full tablet report...
I20260812 06:19:37.339763 29490 raft_consensus.cc:697] T f033abff6faa4575bf15a0f48ebf2954 P 74618a9db2da473a9aa3a1560ea503db [term 1 LEADER]: Becoming Leader. State: Replica: 74618a9db2da473a9aa3a1560ea503db, State: Running, Role: LEADER
I20260812 06:19:37.340023 29490 consensus_queue.cc:237] T f033abff6faa4575bf15a0f48ebf2954 P 74618a9db2da473a9aa3a1560ea503db [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: "74618a9db2da473a9aa3a1560ea503db" member_type: VOTER last_known_addr { host: "127.28.98.193" port: 34033 } }
I20260812 06:19:37.341519 29326 catalog_manager.cc:5719] T f033abff6faa4575bf15a0f48ebf2954 P 74618a9db2da473a9aa3a1560ea503db reported cstate change: term changed from 0 to 1, leader changed from <none> to 74618a9db2da473a9aa3a1560ea503db (127.28.98.193). New cstate: current_term: 1 leader_uuid: "74618a9db2da473a9aa3a1560ea503db" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "74618a9db2da473a9aa3a1560ea503db" member_type: VOTER last_known_addr { host: "127.28.98.193" port: 34033 } health_report { overall_health: HEALTHY } } }
I20260812 06:19:37.402488 29067 heavy-update-compaction-itest.cc:215] Time spent inserting: real 0.055s	user 0.019s	sys 0.004s
I20260812 06:19:37.554453 29476 maintenance_manager.cc:419] P 74618a9db2da473a9aa3a1560ea503db: Scheduling FlushMRSOp(f033abff6faa4575bf15a0f48ebf2954): perf score=19.054940
I20260812 06:19:37.716209 29408 maintenance_manager.cc:643] P 74618a9db2da473a9aa3a1560ea503db: FlushMRSOp(f033abff6faa4575bf15a0f48ebf2954) complete. Timing: real 0.161s	user 0.114s	sys 0.048s Metrics: {"bytes_written":12307491,"cfile_init":1,"delete_count":0,"dirs.queue_time_us":83,"dirs.run_cpu_time_us":215,"dirs.run_wall_time_us":772,"drs_written":1,"lbm_read_time_us":43,"lbm_reads_lt_1ms":4,"lbm_write_time_us":41309,"lbm_writes_lt_1ms":757,"peak_mem_usage":0,"reinsert_count":0,"rows_written":104,"update_count":1500}
I20260812 06:19:37.716950 29476 maintenance_manager.cc:419] P 74618a9db2da473a9aa3a1560ea503db: Scheduling LogGCOp(f033abff6faa4575bf15a0f48ebf2954): free 20743880 bytes of WAL
I20260812 06:19:37.717180 29408 log_reader.cc:385] T f033abff6faa4575bf15a0f48ebf2954: removed 2 log segments from log reader
I20260812 06:19:37.717226 29408 log.cc:1079] T f033abff6faa4575bf15a0f48ebf2954 P 74618a9db2da473a9aa3a1560ea503db: Deleting log segment in path: /tmp/dist-test-tasklNF8fM/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515571494869-29067-0/minicluster-data/ts-0-root/wals/f033abff6faa4575bf15a0f48ebf2954/wal-000000001 (ops 1-6)
I20260812 06:19:37.717278 29408 log.cc:1079] T f033abff6faa4575bf15a0f48ebf2954 P 74618a9db2da473a9aa3a1560ea503db: Deleting log segment in path: /tmp/dist-test-tasklNF8fM/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515571494869-29067-0/minicluster-data/ts-0-root/wals/f033abff6faa4575bf15a0f48ebf2954/wal-000000002 (ops 7-11)
I20260812 06:19:37.721952 29408 maintenance_manager.cc:643] P 74618a9db2da473a9aa3a1560ea503db: LogGCOp(f033abff6faa4575bf15a0f48ebf2954) complete. Timing: real 0.005s	user 0.000s	sys 0.003s Metrics: {}
I20260812 06:19:37.722290 29476 maintenance_manager.cc:419] P 74618a9db2da473a9aa3a1560ea503db: Scheduling FlushDeltaMemStoresOp(f033abff6faa4575bf15a0f48ebf2954): perf score=2.188937
I20260812 06:19:37.736860 29408 maintenance_manager.cc:643] P 74618a9db2da473a9aa3a1560ea503db: FlushDeltaMemStoresOp(f033abff6faa4575bf15a0f48ebf2954) complete. Timing: real 0.014s	user 0.013s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5175,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:37.737329 29476 maintenance_manager.cc:419] P 74618a9db2da473a9aa3a1560ea503db: Scheduling UndoDeltaBlockGCOp(f033abff6faa4575bf15a0f48ebf2954): 16411396 bytes on disk
I20260812 06:19:37.738983 29408 maintenance_manager.cc:643] P 74618a9db2da473a9aa3a1560ea503db: UndoDeltaBlockGCOp(f033abff6faa4575bf15a0f48ebf2954) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":63,"lbm_reads_lt_1ms":4}
I20260812 06:19:37.739553 29476 maintenance_manager.cc:419] P 74618a9db2da473a9aa3a1560ea503db: Scheduling MajorDeltaCompactionOp(f033abff6faa4575bf15a0f48ebf2954): perf score=1.000000
I20260812 06:19:37.892107 29408 maintenance_manager.cc:643] P 74618a9db2da473a9aa3a1560ea503db: MajorDeltaCompactionOp(f033abff6faa4575bf15a0f48ebf2954) complete. Timing: real 0.152s	user 0.108s	sys 0.039s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672278,"cfile_init":7,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":471,"lbm_read_time_us":10033,"lbm_reads_lt_1ms":460,"lbm_write_time_us":27305,"lbm_writes_lt_1ms":443,"mutex_wait_us":23,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":5888,"thread_start_us":367,"threads_started":5,"update_count":2000}
I20260812 06:19:37.893451 29476 maintenance_manager.cc:419] P 74618a9db2da473a9aa3a1560ea503db: Scheduling FlushDeltaMemStoresOp(f033abff6faa4575bf15a0f48ebf2954): perf score=11.118625
I20260812 06:19:37.941887 29408 maintenance_manager.cc:643] P 74618a9db2da473a9aa3a1560ea503db: FlushDeltaMemStoresOp(f033abff6faa4575bf15a0f48ebf2954) complete. Timing: real 0.048s	user 0.025s	sys 0.022s Metrics: {"bytes_written":12717735,"delete_count":0,"lbm_write_time_us":17624,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:19:37.942521 29476 maintenance_manager.cc:419] P 74618a9db2da473a9aa3a1560ea503db: Scheduling FlushDeltaMemStoresOp(f033abff6faa4575bf15a0f48ebf2954): perf score=2.188937
I20260812 06:19:37.954826 29408 maintenance_manager.cc:643] P 74618a9db2da473a9aa3a1560ea503db: FlushDeltaMemStoresOp(f033abff6faa4575bf15a0f48ebf2954) complete. Timing: real 0.012s	user 0.003s	sys 0.007s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":4489,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:19:37.955322 29476 maintenance_manager.cc:419] P 74618a9db2da473a9aa3a1560ea503db: Scheduling MajorDeltaCompactionOp(f033abff6faa4575bf15a0f48ebf2954): perf score=1.000000
I20260812 06:19:38.111536 29408 maintenance_manager.cc:643] P 74618a9db2da473a9aa3a1560ea503db: MajorDeltaCompactionOp(f033abff6faa4575bf15a0f48ebf2954) complete. Timing: real 0.156s	user 0.116s	sys 0.040s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672268,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":806,"lbm_read_time_us":11153,"lbm_reads_lt_1ms":472,"lbm_write_time_us":25720,"lbm_writes_lt_1ms":443,"mutex_wait_us":58,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":22144,"update_count":2000}
I20260812 06:19:38.112308 29476 maintenance_manager.cc:419] P 74618a9db2da473a9aa3a1560ea503db: Scheduling FlushDeltaMemStoresOp(f033abff6faa4575bf15a0f48ebf2954): perf score=10.126437
I20260812 06:19:38.156622 29408 maintenance_manager.cc:643] P 74618a9db2da473a9aa3a1560ea503db: FlushDeltaMemStoresOp(f033abff6faa4575bf15a0f48ebf2954) complete. Timing: real 0.044s	user 0.022s	sys 0.020s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":19123,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":302,"reinsert_count":0,"update_count":1500}
I20260812 06:19:38.157150 29476 maintenance_manager.cc:419] P 74618a9db2da473a9aa3a1560ea503db: Scheduling FlushDeltaMemStoresOp(f033abff6faa4575bf15a0f48ebf2954): perf score=2.188937
I20260812 06:19:38.169044 29408 maintenance_manager.cc:643] P 74618a9db2da473a9aa3a1560ea503db: FlushDeltaMemStoresOp(f033abff6faa4575bf15a0f48ebf2954) complete. Timing: real 0.012s	user 0.006s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4508,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:38.169482 29476 maintenance_manager.cc:419] P 74618a9db2da473a9aa3a1560ea503db: Scheduling MajorDeltaCompactionOp(f033abff6faa4575bf15a0f48ebf2954): perf score=1.000000
I20260812 06:19:38.303162 29408 maintenance_manager.cc:643] P 74618a9db2da473a9aa3a1560ea503db: MajorDeltaCompactionOp(f033abff6faa4575bf15a0f48ebf2954) complete. Timing: real 0.134s	user 0.109s	sys 0.024s 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":270,"lbm_read_time_us":9710,"lbm_reads_lt_1ms":472,"lbm_write_time_us":25636,"lbm_writes_lt_1ms":443,"mutex_wait_us":1,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":5120,"update_count":2000}
I20260812 06:19:38.303701 29476 maintenance_manager.cc:419] P 74618a9db2da473a9aa3a1560ea503db: Scheduling FlushDeltaMemStoresOp(f033abff6faa4575bf15a0f48ebf2954): perf score=10.126437
I20260812 06:19:38.352192 29408 maintenance_manager.cc:643] P 74618a9db2da473a9aa3a1560ea503db: FlushDeltaMemStoresOp(f033abff6faa4575bf15a0f48ebf2954) complete. Timing: real 0.048s	user 0.021s	sys 0.027s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":19792,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":302,"reinsert_count":0,"update_count":1500}
I20260812 06:19:38.352681 29476 maintenance_manager.cc:419] P 74618a9db2da473a9aa3a1560ea503db: Scheduling FlushDeltaMemStoresOp(f033abff6faa4575bf15a0f48ebf2954): perf score=2.188937
I20260812 06:19:38.364320 29408 maintenance_manager.cc:643] P 74618a9db2da473a9aa3a1560ea503db: FlushDeltaMemStoresOp(f033abff6faa4575bf15a0f48ebf2954) complete. Timing: real 0.011s	user 0.011s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4049,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:38.364811 29476 maintenance_manager.cc:419] P 74618a9db2da473a9aa3a1560ea503db: Scheduling MajorDeltaCompactionOp(f033abff6faa4575bf15a0f48ebf2954): perf score=1.000000
I20260812 06:19:38.498980 29408 maintenance_manager.cc:643] P 74618a9db2da473a9aa3a1560ea503db: MajorDeltaCompactionOp(f033abff6faa4575bf15a0f48ebf2954) complete. Timing: real 0.134s	user 0.112s	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":446,"lbm_read_time_us":9800,"lbm_reads_lt_1ms":472,"lbm_write_time_us":25565,"lbm_writes_lt_1ms":443,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":6016,"update_count":2000}
I20260812 06:19:38.499682 29476 maintenance_manager.cc:419] P 74618a9db2da473a9aa3a1560ea503db: Scheduling FlushDeltaMemStoresOp(f033abff6faa4575bf15a0f48ebf2954): perf score=10.126437
I20260812 06:19:38.548257 29408 maintenance_manager.cc:643] P 74618a9db2da473a9aa3a1560ea503db: FlushDeltaMemStoresOp(f033abff6faa4575bf15a0f48ebf2954) complete. Timing: real 0.048s	user 0.035s	sys 0.004s Metrics: {"bytes_written":12307491,"delete_count":0,"lbm_write_time_us":16536,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:19:38.548758 29476 maintenance_manager.cc:419] P 74618a9db2da473a9aa3a1560ea503db: Scheduling FlushDeltaMemStoresOp(f033abff6faa4575bf15a0f48ebf2954): perf score=2.188937
I20260812 06:19:38.560047 29408 maintenance_manager.cc:643] P 74618a9db2da473a9aa3a1560ea503db: FlushDeltaMemStoresOp(f033abff6faa4575bf15a0f48ebf2954) complete. Timing: real 0.011s	user 0.005s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4179,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:38.560794 29476 maintenance_manager.cc:419] P 74618a9db2da473a9aa3a1560ea503db: Scheduling MajorDeltaCompactionOp(f033abff6faa4575bf15a0f48ebf2954): perf score=1.000000
I20260812 06:19:38.688417 29408 maintenance_manager.cc:643] P 74618a9db2da473a9aa3a1560ea503db: MajorDeltaCompactionOp(f033abff6faa4575bf15a0f48ebf2954) complete. Timing: real 0.127s	user 0.107s	sys 0.020s 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":186,"lbm_read_time_us":10659,"lbm_reads_lt_1ms":472,"lbm_write_time_us":22584,"lbm_writes_lt_1ms":443,"mutex_wait_us":22,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":15488,"update_count":2000}
I20260812 06:19:38.689105 29476 maintenance_manager.cc:419] P 74618a9db2da473a9aa3a1560ea503db: Scheduling FlushDeltaMemStoresOp(f033abff6faa4575bf15a0f48ebf2954): perf score=10.126437
I20260812 06:19:38.740396 29408 maintenance_manager.cc:643] P 74618a9db2da473a9aa3a1560ea503db: FlushDeltaMemStoresOp(f033abff6faa4575bf15a0f48ebf2954) complete. Timing: real 0.051s	user 0.024s	sys 0.023s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":16848,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:19:38.740867 29476 maintenance_manager.cc:419] P 74618a9db2da473a9aa3a1560ea503db: Scheduling FlushDeltaMemStoresOp(f033abff6faa4575bf15a0f48ebf2954): perf score=2.188937
I20260812 06:19:38.751385 29408 maintenance_manager.cc:643] P 74618a9db2da473a9aa3a1560ea503db: FlushDeltaMemStoresOp(f033abff6faa4575bf15a0f48ebf2954) complete. Timing: real 0.010s	user 0.009s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4125,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:38.751840 29476 maintenance_manager.cc:419] P 74618a9db2da473a9aa3a1560ea503db: Scheduling MajorDeltaCompactionOp(f033abff6faa4575bf15a0f48ebf2954): perf score=1.000000
I20260812 06:19:38.915154 29408 maintenance_manager.cc:643] P 74618a9db2da473a9aa3a1560ea503db: MajorDeltaCompactionOp(f033abff6faa4575bf15a0f48ebf2954) complete. Timing: real 0.163s	user 0.110s	sys 0.051s 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":179,"lbm_read_time_us":12283,"lbm_reads_lt_1ms":472,"lbm_write_time_us":25005,"lbm_writes_lt_1ms":443,"peak_mem_usage":50689328,"reinsert_count":0,"update_count":2000}
I20260812 06:19:38.915820 29476 maintenance_manager.cc:419] P 74618a9db2da473a9aa3a1560ea503db: Scheduling FlushDeltaMemStoresOp(f033abff6faa4575bf15a0f48ebf2954): perf score=10.126437
I20260812 06:19:38.966482 29408 maintenance_manager.cc:643] P 74618a9db2da473a9aa3a1560ea503db: FlushDeltaMemStoresOp(f033abff6faa4575bf15a0f48ebf2954) complete. Timing: real 0.050s	user 0.020s	sys 0.015s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":16302,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:19:38.967015 29476 maintenance_manager.cc:419] P 74618a9db2da473a9aa3a1560ea503db: Scheduling FlushDeltaMemStoresOp(f033abff6faa4575bf15a0f48ebf2954): perf score=2.188937
I20260812 06:19:38.978790 29408 maintenance_manager.cc:643] P 74618a9db2da473a9aa3a1560ea503db: FlushDeltaMemStoresOp(f033abff6faa4575bf15a0f48ebf2954) complete. Timing: real 0.012s	user 0.006s	sys 0.003s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4248,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:38.979343 29476 maintenance_manager.cc:419] P 74618a9db2da473a9aa3a1560ea503db: Scheduling FlushMRSOp(f033abff6faa4575bf15a0f48ebf2954): perf score=1.000000
I20260812 06:19:39.012138 29408 maintenance_manager.cc:643] P 74618a9db2da473a9aa3a1560ea503db: FlushMRSOp(f033abff6faa4575bf15a0f48ebf2954) complete. Timing: real 0.033s	user 0.032s	sys 0.000s Metrics: {"bytes_written":1152508,"cfile_init":1,"dirs.queue_time_us":75,"dirs.run_cpu_time_us":241,"dirs.run_wall_time_us":1706,"drs_written":1,"lbm_read_time_us":39,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1671,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":28}
I20260812 06:19:39.012758 29476 maintenance_manager.cc:419] P 74618a9db2da473a9aa3a1560ea503db: Scheduling LogGCOp(f033abff6faa4575bf15a0f48ebf2954): free 115943176 bytes of WAL
I20260812 06:19:39.012979 29408 log_reader.cc:385] T f033abff6faa4575bf15a0f48ebf2954: removed 11 log segments from log reader
I20260812 06:19:39.013036 29408 log.cc:1079] T f033abff6faa4575bf15a0f48ebf2954 P 74618a9db2da473a9aa3a1560ea503db: Deleting log segment in path: /tmp/dist-test-tasklNF8fM/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515571494869-29067-0/minicluster-data/ts-0-root/wals/f033abff6faa4575bf15a0f48ebf2954/wal-000000003 (ops 12-16)
I20260812 06:19:39.013099 29408 log.cc:1079] T f033abff6faa4575bf15a0f48ebf2954 P 74618a9db2da473a9aa3a1560ea503db: Deleting log segment in path: /tmp/dist-test-tasklNF8fM/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515571494869-29067-0/minicluster-data/ts-0-root/wals/f033abff6faa4575bf15a0f48ebf2954/wal-000000004 (ops 17-21)
I20260812 06:19:39.013132 29408 log.cc:1079] T f033abff6faa4575bf15a0f48ebf2954 P 74618a9db2da473a9aa3a1560ea503db: Deleting log segment in path: /tmp/dist-test-tasklNF8fM/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515571494869-29067-0/minicluster-data/ts-0-root/wals/f033abff6faa4575bf15a0f48ebf2954/wal-000000005 (ops 22-26)
I20260812 06:19:39.013175 29408 log.cc:1079] T f033abff6faa4575bf15a0f48ebf2954 P 74618a9db2da473a9aa3a1560ea503db: Deleting log segment in path: /tmp/dist-test-tasklNF8fM/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515571494869-29067-0/minicluster-data/ts-0-root/wals/f033abff6faa4575bf15a0f48ebf2954/wal-000000006 (ops 27-31)
I20260812 06:19:39.013211 29408 log.cc:1079] T f033abff6faa4575bf15a0f48ebf2954 P 74618a9db2da473a9aa3a1560ea503db: Deleting log segment in path: /tmp/dist-test-tasklNF8fM/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515571494869-29067-0/minicluster-data/ts-0-root/wals/f033abff6faa4575bf15a0f48ebf2954/wal-000000007 (ops 32-36)
I20260812 06:19:39.013258 29408 log.cc:1079] T f033abff6faa4575bf15a0f48ebf2954 P 74618a9db2da473a9aa3a1560ea503db: Deleting log segment in path: /tmp/dist-test-tasklNF8fM/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515571494869-29067-0/minicluster-data/ts-0-root/wals/f033abff6faa4575bf15a0f48ebf2954/wal-000000008 (ops 37-41)
I20260812 06:19:39.013296 29408 log.cc:1079] T f033abff6faa4575bf15a0f48ebf2954 P 74618a9db2da473a9aa3a1560ea503db: Deleting log segment in path: /tmp/dist-test-tasklNF8fM/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515571494869-29067-0/minicluster-data/ts-0-root/wals/f033abff6faa4575bf15a0f48ebf2954/wal-000000009 (ops 42-46)
I20260812 06:19:39.013334 29408 log.cc:1079] T f033abff6faa4575bf15a0f48ebf2954 P 74618a9db2da473a9aa3a1560ea503db: Deleting log segment in path: /tmp/dist-test-tasklNF8fM/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515571494869-29067-0/minicluster-data/ts-0-root/wals/f033abff6faa4575bf15a0f48ebf2954/wal-000000010 (ops 47-51)
I20260812 06:19:39.013370 29408 log.cc:1079] T f033abff6faa4575bf15a0f48ebf2954 P 74618a9db2da473a9aa3a1560ea503db: Deleting log segment in path: /tmp/dist-test-tasklNF8fM/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515571494869-29067-0/minicluster-data/ts-0-root/wals/f033abff6faa4575bf15a0f48ebf2954/wal-000000011 (ops 52-56)
I20260812 06:19:39.013404 29408 log.cc:1079] T f033abff6faa4575bf15a0f48ebf2954 P 74618a9db2da473a9aa3a1560ea503db: Deleting log segment in path: /tmp/dist-test-tasklNF8fM/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515571494869-29067-0/minicluster-data/ts-0-root/wals/f033abff6faa4575bf15a0f48ebf2954/wal-000000012 (ops 57-61)
I20260812 06:19:39.013448 29408 log.cc:1079] T f033abff6faa4575bf15a0f48ebf2954 P 74618a9db2da473a9aa3a1560ea503db: Deleting log segment in path: /tmp/dist-test-tasklNF8fM/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515571494869-29067-0/minicluster-data/ts-0-root/wals/f033abff6faa4575bf15a0f48ebf2954/wal-000000013 (ops 62-66)
I20260812 06:19:39.039536 29408 maintenance_manager.cc:643] P 74618a9db2da473a9aa3a1560ea503db: LogGCOp(f033abff6faa4575bf15a0f48ebf2954) complete. Timing: real 0.027s	user 0.000s	sys 0.023s Metrics: {}
I20260812 06:19:39.040020 29476 maintenance_manager.cc:419] P 74618a9db2da473a9aa3a1560ea503db: Scheduling UndoDeltaBlockGCOp(f033abff6faa4575bf15a0f48ebf2954): 447 bytes on disk
I20260812 06:19:39.040555 29408 maintenance_manager.cc:643] P 74618a9db2da473a9aa3a1560ea503db: UndoDeltaBlockGCOp(f033abff6faa4575bf15a0f48ebf2954) 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:19:39.041087 29476 maintenance_manager.cc:419] P 74618a9db2da473a9aa3a1560ea503db: Scheduling FlushDeltaMemStoresOp(f033abff6faa4575bf15a0f48ebf2954): perf score=3.181125
I20260812 06:19:39.069268 29408 maintenance_manager.cc:643] P 74618a9db2da473a9aa3a1560ea503db: FlushDeltaMemStoresOp(f033abff6faa4575bf15a0f48ebf2954) complete. Timing: real 0.028s	user 0.008s	sys 0.019s Metrics: {"bytes_written":4512900,"delete_count":0,"lbm_write_time_us":7025,"lbm_writes_lt_1ms":113,"reinsert_count":0,"update_count":550}
I20260812 06:19:39.069788 29476 maintenance_manager.cc:419] P 74618a9db2da473a9aa3a1560ea503db: Scheduling FlushDeltaMemStoresOp(f033abff6faa4575bf15a0f48ebf2954): perf score=2.188937
I20260812 06:19:39.079900 29408 maintenance_manager.cc:643] P 74618a9db2da473a9aa3a1560ea503db: FlushDeltaMemStoresOp(f033abff6faa4575bf15a0f48ebf2954) complete. Timing: real 0.010s	user 0.000s	sys 0.008s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3869,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:19:39.080504 29476 maintenance_manager.cc:419] P 74618a9db2da473a9aa3a1560ea503db: Scheduling MajorDeltaCompactionOp(f033abff6faa4575bf15a0f48ebf2954): perf score=1.000000
I20260812 06:19:39.305639 29408 maintenance_manager.cc:643] P 74618a9db2da473a9aa3a1560ea503db: MajorDeltaCompactionOp(f033abff6faa4575bf15a0f48ebf2954) complete. Timing: real 0.225s	user 0.164s	sys 0.060s Metrics: {"cfile_cache_miss":634,"cfile_cache_miss_bytes":28877326,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":693,"lbm_read_time_us":17449,"lbm_reads_lt_1ms":674,"lbm_write_time_us":37000,"lbm_writes_lt_1ms":643,"mutex_wait_us":285,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":14848,"thread_start_us":89,"threads_started":1,"update_count":3000}
I20260812 06:19:39.306483 29476 maintenance_manager.cc:419] P 74618a9db2da473a9aa3a1560ea503db: Scheduling FlushDeltaMemStoresOp(f033abff6faa4575bf15a0f48ebf2954): perf score=14.095187
I20260812 06:19:39.377763 29408 maintenance_manager.cc:643] P 74618a9db2da473a9aa3a1560ea503db: FlushDeltaMemStoresOp(f033abff6faa4575bf15a0f48ebf2954) complete. Timing: real 0.071s	user 0.030s	sys 0.039s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":29970,"lbm_writes_1-10_ms":2,"lbm_writes_lt_1ms":401,"reinsert_count":0,"update_count":2000}
I20260812 06:19:39.378429 29476 maintenance_manager.cc:419] P 74618a9db2da473a9aa3a1560ea503db: Scheduling FlushDeltaMemStoresOp(f033abff6faa4575bf15a0f48ebf2954): perf score=3.181125
I20260812 06:19:39.405833 29408 maintenance_manager.cc:643] P 74618a9db2da473a9aa3a1560ea503db: FlushDeltaMemStoresOp(f033abff6faa4575bf15a0f48ebf2954) complete. Timing: real 0.027s	user 0.013s	sys 0.000s Metrics: {"bytes_written":4512900,"delete_count":0,"lbm_write_time_us":5788,"lbm_writes_lt_1ms":113,"reinsert_count":0,"update_count":550}
I20260812 06:19:39.406275 29476 maintenance_manager.cc:419] P 74618a9db2da473a9aa3a1560ea503db: Scheduling FlushDeltaMemStoresOp(f033abff6faa4575bf15a0f48ebf2954): perf score=2.188937
I20260812 06:19:39.416780 29408 maintenance_manager.cc:643] P 74618a9db2da473a9aa3a1560ea503db: FlushDeltaMemStoresOp(f033abff6faa4575bf15a0f48ebf2954) complete. Timing: real 0.010s	user 0.006s	sys 0.004s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3861,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:19:39.417265 29476 maintenance_manager.cc:419] P 74618a9db2da473a9aa3a1560ea503db: Scheduling MajorDeltaCompactionOp(f033abff6faa4575bf15a0f48ebf2954): perf score=1.000000
I20260812 06:19:39.628753 29408 maintenance_manager.cc:643] P 74618a9db2da473a9aa3a1560ea503db: MajorDeltaCompactionOp(f033abff6faa4575bf15a0f48ebf2954) complete. Timing: real 0.211s	user 0.155s	sys 0.055s Metrics: {"cfile_cache_miss":633,"cfile_cache_miss_bytes":28877207,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":1034,"lbm_read_time_us":15251,"lbm_reads_lt_1ms":673,"lbm_write_time_us":34557,"lbm_writes_lt_1ms":643,"mutex_wait_us":68,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":3072,"update_count":3000}
I20260812 06:19:39.629384 29476 maintenance_manager.cc:419] P 74618a9db2da473a9aa3a1560ea503db: Scheduling FlushDeltaMemStoresOp(f033abff6faa4575bf15a0f48ebf2954): perf score=14.095187
I20260812 06:19:39.681310 29408 maintenance_manager.cc:643] P 74618a9db2da473a9aa3a1560ea503db: FlushDeltaMemStoresOp(f033abff6faa4575bf15a0f48ebf2954) complete. Timing: real 0.052s	user 0.038s	sys 0.012s Metrics: {"bytes_written":16409903,"delete_count":0,"lbm_write_time_us":23802,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:39.681838 29476 maintenance_manager.cc:419] P 74618a9db2da473a9aa3a1560ea503db: Scheduling FlushDeltaMemStoresOp(f033abff6faa4575bf15a0f48ebf2954): perf score=2.188937
I20260812 06:19:39.692819 29408 maintenance_manager.cc:643] P 74618a9db2da473a9aa3a1560ea503db: FlushDeltaMemStoresOp(f033abff6faa4575bf15a0f48ebf2954) complete. Timing: real 0.011s	user 0.010s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4206,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:39.693320 29476 maintenance_manager.cc:419] P 74618a9db2da473a9aa3a1560ea503db: Scheduling MajorDeltaCompactionOp(f033abff6faa4575bf15a0f48ebf2954): perf score=1.000000
I20260812 06:19:39.885721 29408 maintenance_manager.cc:643] P 74618a9db2da473a9aa3a1560ea503db: MajorDeltaCompactionOp(f033abff6faa4575bf15a0f48ebf2954) complete. Timing: real 0.192s	user 0.126s	sys 0.066s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774690,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":299,"lbm_read_time_us":14528,"lbm_reads_lt_1ms":572,"lbm_write_time_us":32757,"lbm_writes_lt_1ms":543,"mutex_wait_us":41,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":26496,"update_count":2500}
I20260812 06:19:39.886431 29476 maintenance_manager.cc:419] P 74618a9db2da473a9aa3a1560ea503db: Scheduling FlushDeltaMemStoresOp(f033abff6faa4575bf15a0f48ebf2954): perf score=14.095187
I20260812 06:19:39.949005 29408 maintenance_manager.cc:643] P 74618a9db2da473a9aa3a1560ea503db: FlushDeltaMemStoresOp(f033abff6faa4575bf15a0f48ebf2954) complete. Timing: real 0.062s	user 0.041s	sys 0.020s Metrics: {"bytes_written":16409903,"delete_count":0,"lbm_write_time_us":23577,"lbm_writes_lt_1ms":403,"reinsert_count":0,"spinlock_wait_cycles":26496,"update_count":2000}
I20260812 06:19:39.949584 29476 maintenance_manager.cc:419] P 74618a9db2da473a9aa3a1560ea503db: Scheduling FlushDeltaMemStoresOp(f033abff6faa4575bf15a0f48ebf2954): perf score=2.188937
I20260812 06:19:39.960403 29408 maintenance_manager.cc:643] P 74618a9db2da473a9aa3a1560ea503db: FlushDeltaMemStoresOp(f033abff6faa4575bf15a0f48ebf2954) complete. Timing: real 0.011s	user 0.002s	sys 0.008s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4291,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:39.960832 29476 maintenance_manager.cc:419] P 74618a9db2da473a9aa3a1560ea503db: Scheduling MajorDeltaCompactionOp(f033abff6faa4575bf15a0f48ebf2954): perf score=1.000000
I20260812 06:19:40.155159 29408 maintenance_manager.cc:643] P 74618a9db2da473a9aa3a1560ea503db: MajorDeltaCompactionOp(f033abff6faa4575bf15a0f48ebf2954) complete. Timing: real 0.194s	user 0.114s	sys 0.076s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774689,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":1004,"lbm_read_time_us":13352,"lbm_reads_lt_1ms":572,"lbm_write_time_us":32037,"lbm_writes_lt_1ms":543,"mutex_wait_us":44,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":6016,"update_count":2500}
I20260812 06:19:40.155968 29476 maintenance_manager.cc:419] P 74618a9db2da473a9aa3a1560ea503db: Scheduling FlushDeltaMemStoresOp(f033abff6faa4575bf15a0f48ebf2954): perf score=11.118625
I20260812 06:19:40.198218 29408 maintenance_manager.cc:643] P 74618a9db2da473a9aa3a1560ea503db: FlushDeltaMemStoresOp(f033abff6faa4575bf15a0f48ebf2954) complete. Timing: real 0.042s	user 0.032s	sys 0.008s Metrics: {"bytes_written":12717736,"delete_count":0,"lbm_write_time_us":17834,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:19:40.199034 29476 maintenance_manager.cc:419] P 74618a9db2da473a9aa3a1560ea503db: Scheduling FlushDeltaMemStoresOp(f033abff6faa4575bf15a0f48ebf2954): perf score=2.188937
I20260812 06:19:40.221434 29408 maintenance_manager.cc:643] P 74618a9db2da473a9aa3a1560ea503db: FlushDeltaMemStoresOp(f033abff6faa4575bf15a0f48ebf2954) complete. Timing: real 0.022s	user 0.010s	sys 0.011s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":5529,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:19:40.222093 29476 maintenance_manager.cc:419] P 74618a9db2da473a9aa3a1560ea503db: Scheduling FlushDeltaMemStoresOp(f033abff6faa4575bf15a0f48ebf2954): perf score=1.000000
I20260812 06:19:40.234386 29408 maintenance_manager.cc:643] P 74618a9db2da473a9aa3a1560ea503db: FlushDeltaMemStoresOp(f033abff6faa4575bf15a0f48ebf2954) complete. Timing: real 0.012s	user 0.006s	sys 0.000s Metrics: {"bytes_written":1353981,"delete_count":0,"lbm_write_time_us":2476,"lbm_writes_lt_1ms":36,"reinsert_count":0,"update_count":165}
I20260812 06:19:40.234913 29476 maintenance_manager.cc:419] P 74618a9db2da473a9aa3a1560ea503db: Scheduling FlushDeltaMemStoresOp(f033abff6faa4575bf15a0f48ebf2954): perf score=1.196750
I20260812 06:19:40.244827 29408 maintenance_manager.cc:643] P 74618a9db2da473a9aa3a1560ea503db: FlushDeltaMemStoresOp(f033abff6faa4575bf15a0f48ebf2954) complete. Timing: real 0.010s	user 0.005s	sys 0.004s Metrics: {"bytes_written":2748830,"delete_count":0,"lbm_write_time_us":3262,"lbm_writes_lt_1ms":70,"reinsert_count":0,"update_count":335}
I20260812 06:19:40.245460 29476 maintenance_manager.cc:419] P 74618a9db2da473a9aa3a1560ea503db: Scheduling MajorDeltaCompactionOp(f033abff6faa4575bf15a0f48ebf2954): perf score=1.000000
I20260812 06:19:40.445186 29408 maintenance_manager.cc:643] P 74618a9db2da473a9aa3a1560ea503db: MajorDeltaCompactionOp(f033abff6faa4575bf15a0f48ebf2954) complete. Timing: real 0.200s	user 0.139s	sys 0.060s Metrics: {"cfile_cache_miss":534,"cfile_cache_miss_bytes":24774825,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":1063,"lbm_read_time_us":14149,"lbm_reads_lt_1ms":574,"lbm_write_time_us":31707,"lbm_writes_lt_1ms":543,"mutex_wait_us":304,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":2688,"update_count":2500}
I20260812 06:19:40.445712 29476 maintenance_manager.cc:419] P 74618a9db2da473a9aa3a1560ea503db: Scheduling FlushDeltaMemStoresOp(f033abff6faa4575bf15a0f48ebf2954): perf score=14.095187
I20260812 06:19:40.500043 29408 maintenance_manager.cc:643] P 74618a9db2da473a9aa3a1560ea503db: FlushDeltaMemStoresOp(f033abff6faa4575bf15a0f48ebf2954) complete. Timing: real 0.054s	user 0.039s	sys 0.011s Metrics: {"bytes_written":16409900,"delete_count":0,"lbm_write_time_us":26645,"lbm_writes_1-10_ms":2,"lbm_writes_lt_1ms":401,"reinsert_count":0,"update_count":2000}
I20260812 06:19:40.500598 29476 maintenance_manager.cc:419] P 74618a9db2da473a9aa3a1560ea503db: Scheduling FlushDeltaMemStoresOp(f033abff6faa4575bf15a0f48ebf2954): perf score=2.188937
I20260812 06:19:40.521797 29408 maintenance_manager.cc:643] P 74618a9db2da473a9aa3a1560ea503db: FlushDeltaMemStoresOp(f033abff6faa4575bf15a0f48ebf2954) complete. Timing: real 0.021s	user 0.012s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5270,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:40.522392 29476 maintenance_manager.cc:419] P 74618a9db2da473a9aa3a1560ea503db: Scheduling FlushMRSOp(f033abff6faa4575bf15a0f48ebf2954): perf score=1.000000
I20260812 06:19:40.553189 29408 maintenance_manager.cc:643] P 74618a9db2da473a9aa3a1560ea503db: FlushMRSOp(f033abff6faa4575bf15a0f48ebf2954) complete. Timing: real 0.031s	user 0.021s	sys 0.008s Metrics: {"bytes_written":1193509,"cfile_init":1,"dirs.queue_time_us":75,"dirs.run_cpu_time_us":247,"dirs.run_wall_time_us":1763,"drs_written":1,"lbm_read_time_us":41,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1498,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":29}
I20260812 06:19:40.554168 29476 maintenance_manager.cc:419] P 74618a9db2da473a9aa3a1560ea503db: Scheduling LogGCOp(f033abff6faa4575bf15a0f48ebf2954): free 112692324 bytes of WAL
I20260812 06:19:40.554448 29408 log_reader.cc:385] T f033abff6faa4575bf15a0f48ebf2954: removed 11 log segments from log reader
I20260812 06:19:40.554505 29408 log.cc:1079] T f033abff6faa4575bf15a0f48ebf2954 P 74618a9db2da473a9aa3a1560ea503db: Deleting log segment in path: /tmp/dist-test-tasklNF8fM/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515571494869-29067-0/minicluster-data/ts-0-root/wals/f033abff6faa4575bf15a0f48ebf2954/wal-000000014 (ops 67-71)
I20260812 06:19:40.554570 29408 log.cc:1079] T f033abff6faa4575bf15a0f48ebf2954 P 74618a9db2da473a9aa3a1560ea503db: Deleting log segment in path: /tmp/dist-test-tasklNF8fM/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515571494869-29067-0/minicluster-data/ts-0-root/wals/f033abff6faa4575bf15a0f48ebf2954/wal-000000015 (ops 72-76)
I20260812 06:19:40.554625 29408 log.cc:1079] T f033abff6faa4575bf15a0f48ebf2954 P 74618a9db2da473a9aa3a1560ea503db: Deleting log segment in path: /tmp/dist-test-tasklNF8fM/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515571494869-29067-0/minicluster-data/ts-0-root/wals/f033abff6faa4575bf15a0f48ebf2954/wal-000000016 (ops 77-81)
I20260812 06:19:40.554664 29408 log.cc:1079] T f033abff6faa4575bf15a0f48ebf2954 P 74618a9db2da473a9aa3a1560ea503db: Deleting log segment in path: /tmp/dist-test-tasklNF8fM/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515571494869-29067-0/minicluster-data/ts-0-root/wals/f033abff6faa4575bf15a0f48ebf2954/wal-000000017 (ops 82-86)
I20260812 06:19:40.554702 29408 log.cc:1079] T f033abff6faa4575bf15a0f48ebf2954 P 74618a9db2da473a9aa3a1560ea503db: Deleting log segment in path: /tmp/dist-test-tasklNF8fM/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515571494869-29067-0/minicluster-data/ts-0-root/wals/f033abff6faa4575bf15a0f48ebf2954/wal-000000018 (ops 87-91)
I20260812 06:19:40.554738 29408 log.cc:1079] T f033abff6faa4575bf15a0f48ebf2954 P 74618a9db2da473a9aa3a1560ea503db: Deleting log segment in path: /tmp/dist-test-tasklNF8fM/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515571494869-29067-0/minicluster-data/ts-0-root/wals/f033abff6faa4575bf15a0f48ebf2954/wal-000000019 (ops 92-96)
I20260812 06:19:40.554775 29408 log.cc:1079] T f033abff6faa4575bf15a0f48ebf2954 P 74618a9db2da473a9aa3a1560ea503db: Deleting log segment in path: /tmp/dist-test-tasklNF8fM/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515571494869-29067-0/minicluster-data/ts-0-root/wals/f033abff6faa4575bf15a0f48ebf2954/wal-000000020 (ops 97-101)
I20260812 06:19:40.554811 29408 log.cc:1079] T f033abff6faa4575bf15a0f48ebf2954 P 74618a9db2da473a9aa3a1560ea503db: Deleting log segment in path: /tmp/dist-test-tasklNF8fM/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515571494869-29067-0/minicluster-data/ts-0-root/wals/f033abff6faa4575bf15a0f48ebf2954/wal-000000021 (ops 102-106)
I20260812 06:19:40.554848 29408 log.cc:1079] T f033abff6faa4575bf15a0f48ebf2954 P 74618a9db2da473a9aa3a1560ea503db: Deleting log segment in path: /tmp/dist-test-tasklNF8fM/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515571494869-29067-0/minicluster-data/ts-0-root/wals/f033abff6faa4575bf15a0f48ebf2954/wal-000000022 (ops 107-111)
I20260812 06:19:40.554885 29408 log.cc:1079] T f033abff6faa4575bf15a0f48ebf2954 P 74618a9db2da473a9aa3a1560ea503db: Deleting log segment in path: /tmp/dist-test-tasklNF8fM/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515571494869-29067-0/minicluster-data/ts-0-root/wals/f033abff6faa4575bf15a0f48ebf2954/wal-000000023 (ops 112-116)
I20260812 06:19:40.554920 29408 log.cc:1079] T f033abff6faa4575bf15a0f48ebf2954 P 74618a9db2da473a9aa3a1560ea503db: Deleting log segment in path: /tmp/dist-test-tasklNF8fM/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515571494869-29067-0/minicluster-data/ts-0-root/wals/f033abff6faa4575bf15a0f48ebf2954/wal-000000024 (ops 117-121)
I20260812 06:19:40.581384 29408 maintenance_manager.cc:643] P 74618a9db2da473a9aa3a1560ea503db: LogGCOp(f033abff6faa4575bf15a0f48ebf2954) complete. Timing: real 0.027s	user 0.000s	sys 0.026s Metrics: {}
I20260812 06:19:40.581921 29476 maintenance_manager.cc:419] P 74618a9db2da473a9aa3a1560ea503db: Scheduling UndoDeltaBlockGCOp(f033abff6faa4575bf15a0f48ebf2954): 462 bytes on disk
I20260812 06:19:40.583418 29408 maintenance_manager.cc:643] P 74618a9db2da473a9aa3a1560ea503db: UndoDeltaBlockGCOp(f033abff6faa4575bf15a0f48ebf2954) complete. Timing: real 0.001s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":78,"lbm_reads_lt_1ms":4}
I20260812 06:19:40.584220 29476 maintenance_manager.cc:419] P 74618a9db2da473a9aa3a1560ea503db: Scheduling FlushDeltaMemStoresOp(f033abff6faa4575bf15a0f48ebf2954): perf score=4.173312
I20260812 06:19:40.600466 29408 maintenance_manager.cc:643] P 74618a9db2da473a9aa3a1560ea503db: FlushDeltaMemStoresOp(f033abff6faa4575bf15a0f48ebf2954) complete. Timing: real 0.016s	user 0.005s	sys 0.010s Metrics: {"bytes_written":5784659,"delete_count":0,"lbm_write_time_us":6879,"lbm_writes_lt_1ms":144,"reinsert_count":0,"update_count":705}
I20260812 06:19:40.600936 29476 maintenance_manager.cc:419] P 74618a9db2da473a9aa3a1560ea503db: Scheduling FlushDeltaMemStoresOp(f033abff6faa4575bf15a0f48ebf2954): perf score=1.196750
I20260812 06:19:40.609406 29408 maintenance_manager.cc:643] P 74618a9db2da473a9aa3a1560ea503db: FlushDeltaMemStoresOp(f033abff6faa4575bf15a0f48ebf2954) complete. Timing: real 0.008s	user 0.000s	sys 0.007s Metrics: {"bytes_written":2420629,"delete_count":0,"lbm_write_time_us":2512,"lbm_writes_lt_1ms":62,"reinsert_count":0,"update_count":295}
I20260812 06:19:40.609884 29476 maintenance_manager.cc:419] P 74618a9db2da473a9aa3a1560ea503db: Scheduling LogGCOp(f033abff6faa4575bf15a0f48ebf2954): free 12017981 bytes of WAL
I20260812 06:19:40.610109 29408 log_reader.cc:385] T f033abff6faa4575bf15a0f48ebf2954: removed 1 log segments from log reader
I20260812 06:19:40.610169 29408 log.cc:1079] T f033abff6faa4575bf15a0f48ebf2954 P 74618a9db2da473a9aa3a1560ea503db: Deleting log segment in path: /tmp/dist-test-tasklNF8fM/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515571494869-29067-0/minicluster-data/ts-0-root/wals/f033abff6faa4575bf15a0f48ebf2954/wal-000000025 (ops 122-126)
I20260812 06:19:40.613358 29408 maintenance_manager.cc:643] P 74618a9db2da473a9aa3a1560ea503db: LogGCOp(f033abff6faa4575bf15a0f48ebf2954) complete. Timing: real 0.003s	user 0.000s	sys 0.002s Metrics: {}
I20260812 06:19:40.613798 29476 maintenance_manager.cc:419] P 74618a9db2da473a9aa3a1560ea503db: Scheduling MajorDeltaCompactionOp(f033abff6faa4575bf15a0f48ebf2954): perf score=1.000000
I20260812 06:19:40.872617 29408 maintenance_manager.cc:643] P 74618a9db2da473a9aa3a1560ea503db: MajorDeltaCompactionOp(f033abff6faa4575bf15a0f48ebf2954) complete. Timing: real 0.259s	user 0.170s	sys 0.078s Metrics: {"cfile_cache_miss":734,"cfile_cache_miss_bytes":32979713,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":1779,"lbm_read_time_us":17552,"lbm_reads_lt_1ms":774,"lbm_write_time_us":40750,"lbm_writes_lt_1ms":743,"mutex_wait_us":480,"peak_mem_usage":87969044,"reinsert_count":0,"spinlock_wait_cycles":17408,"thread_start_us":121,"threads_started":1,"update_count":3500}
I20260812 06:19:40.873426 29476 maintenance_manager.cc:419] P 74618a9db2da473a9aa3a1560ea503db: Scheduling FlushDeltaMemStoresOp(f033abff6faa4575bf15a0f48ebf2954): perf score=18.063937
I20260812 06:19:41.001127 29408 maintenance_manager.cc:643] P 74618a9db2da473a9aa3a1560ea503db: FlushDeltaMemStoresOp(f033abff6faa4575bf15a0f48ebf2954) complete. Timing: real 0.127s	user 0.048s	sys 0.024s Metrics: {"bytes_written":20512315,"delete_count":0,"lbm_write_time_us":74625,"lbm_writes_10-100_ms":1,"lbm_writes_lt_1ms":502,"reinsert_count":0,"update_count":2500}
I20260812 06:19:41.001724 29476 maintenance_manager.cc:419] P 74618a9db2da473a9aa3a1560ea503db: Scheduling FlushDeltaMemStoresOp(f033abff6faa4575bf15a0f48ebf2954): perf score=3.181125
I20260812 06:19:41.021353 29408 maintenance_manager.cc:643] P 74618a9db2da473a9aa3a1560ea503db: FlushDeltaMemStoresOp(f033abff6faa4575bf15a0f48ebf2954) complete. Timing: real 0.019s	user 0.013s	sys 0.006s Metrics: {"bytes_written":4512900,"delete_count":0,"lbm_write_time_us":7404,"lbm_writes_lt_1ms":113,"reinsert_count":0,"update_count":550}
I20260812 06:19:41.022023 29476 maintenance_manager.cc:419] P 74618a9db2da473a9aa3a1560ea503db: Scheduling FlushDeltaMemStoresOp(f033abff6faa4575bf15a0f48ebf2954): perf score=2.188937
I20260812 06:19:41.038771 29408 maintenance_manager.cc:643] P 74618a9db2da473a9aa3a1560ea503db: FlushDeltaMemStoresOp(f033abff6faa4575bf15a0f48ebf2954) complete. Timing: real 0.017s	user 0.009s	sys 0.005s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":6150,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:19:41.039520 29476 maintenance_manager.cc:419] P 74618a9db2da473a9aa3a1560ea503db: Scheduling MajorDeltaCompactionOp(f033abff6faa4575bf15a0f48ebf2954): perf score=1.000000
I20260812 06:19:41.288125 29408 maintenance_manager.cc:643] P 74618a9db2da473a9aa3a1560ea503db: MajorDeltaCompactionOp(f033abff6faa4575bf15a0f48ebf2954) complete. Timing: real 0.248s	user 0.161s	sys 0.079s Metrics: {"cfile_cache_miss":733,"cfile_cache_miss_bytes":32979620,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":787,"lbm_read_time_us":20780,"lbm_reads_lt_1ms":773,"lbm_write_time_us":40757,"lbm_writes_lt_1ms":743,"mutex_wait_us":310,"peak_mem_usage":87969044,"reinsert_count":0,"spinlock_wait_cycles":11392,"update_count":3500}
I20260812 06:19:41.288813 29476 maintenance_manager.cc:419] P 74618a9db2da473a9aa3a1560ea503db: Scheduling FlushDeltaMemStoresOp(f033abff6faa4575bf15a0f48ebf2954): perf score=19.056125
I20260812 06:19:41.377416 29408 maintenance_manager.cc:643] P 74618a9db2da473a9aa3a1560ea503db: FlushDeltaMemStoresOp(f033abff6faa4575bf15a0f48ebf2954) complete. Timing: real 0.088s	user 0.048s	sys 0.039s Metrics: {"bytes_written":20922553,"delete_count":0,"lbm_write_time_us":39574,"lbm_writes_1-10_ms":2,"lbm_writes_lt_1ms":511,"reinsert_count":0,"update_count":2550}
I20260812 06:19:41.378229 29476 maintenance_manager.cc:419] P 74618a9db2da473a9aa3a1560ea503db: Scheduling FlushDeltaMemStoresOp(f033abff6faa4575bf15a0f48ebf2954): perf score=6.157687
I20260812 06:19:41.407112 29408 maintenance_manager.cc:643] P 74618a9db2da473a9aa3a1560ea503db: FlushDeltaMemStoresOp(f033abff6faa4575bf15a0f48ebf2954) complete. Timing: real 0.029s	user 0.011s	sys 0.011s Metrics: {"bytes_written":7794837,"delete_count":0,"lbm_write_time_us":10565,"lbm_writes_lt_1ms":193,"reinsert_count":0,"update_count":950}
I20260812 06:19:41.407577 29476 maintenance_manager.cc:419] P 74618a9db2da473a9aa3a1560ea503db: Scheduling FlushDeltaMemStoresOp(f033abff6faa4575bf15a0f48ebf2954): perf score=2.188937
I20260812 06:19:41.418473 29408 maintenance_manager.cc:643] P 74618a9db2da473a9aa3a1560ea503db: FlushDeltaMemStoresOp(f033abff6faa4575bf15a0f48ebf2954) complete. Timing: real 0.011s	user 0.006s	sys 0.003s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4022,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:41.418938 29476 maintenance_manager.cc:419] P 74618a9db2da473a9aa3a1560ea503db: Scheduling MajorDeltaCompactionOp(f033abff6faa4575bf15a0f48ebf2954): perf score=1.000000
I20260812 06:19:41.647171 29408 maintenance_manager.cc:643] P 74618a9db2da473a9aa3a1560ea503db: MajorDeltaCompactionOp(f033abff6faa4575bf15a0f48ebf2954) complete. Timing: real 0.228s	user 0.180s	sys 0.047s Metrics: {"cfile_cache_miss":833,"cfile_cache_miss_bytes":37082042,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":441,"lbm_read_time_us":15632,"lbm_reads_lt_1ms":873,"lbm_write_time_us":45902,"lbm_writes_lt_1ms":843,"mutex_wait_us":18,"peak_mem_usage":100395616,"reinsert_count":0,"spinlock_wait_cycles":10112,"update_count":4000}
I20260812 06:19:41.647933 29476 maintenance_manager.cc:419] P 74618a9db2da473a9aa3a1560ea503db: Scheduling FlushDeltaMemStoresOp(f033abff6faa4575bf15a0f48ebf2954): perf score=18.063937
I20260812 06:19:41.711876 29408 maintenance_manager.cc:643] P 74618a9db2da473a9aa3a1560ea503db: FlushDeltaMemStoresOp(f033abff6faa4575bf15a0f48ebf2954) complete. Timing: real 0.064s	user 0.038s	sys 0.021s Metrics: {"bytes_written":20512322,"delete_count":0,"lbm_write_time_us":28316,"lbm_writes_lt_1ms":503,"reinsert_count":0,"update_count":2500}
I20260812 06:19:41.712414 29476 maintenance_manager.cc:419] P 74618a9db2da473a9aa3a1560ea503db: Scheduling FlushDeltaMemStoresOp(f033abff6faa4575bf15a0f48ebf2954): perf score=2.188937
I20260812 06:19:41.730425 29408 maintenance_manager.cc:643] P 74618a9db2da473a9aa3a1560ea503db: FlushDeltaMemStoresOp(f033abff6faa4575bf15a0f48ebf2954) complete. Timing: real 0.018s	user 0.010s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6282,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:41.730871 29476 maintenance_manager.cc:419] P 74618a9db2da473a9aa3a1560ea503db: Scheduling MajorDeltaCompactionOp(f033abff6faa4575bf15a0f48ebf2954): perf score=1.000000
I20260812 06:19:41.899020 29408 maintenance_manager.cc:643] P 74618a9db2da473a9aa3a1560ea503db: MajorDeltaCompactionOp(f033abff6faa4575bf15a0f48ebf2954) complete. Timing: real 0.168s	user 0.124s	sys 0.044s Metrics: {"cfile_cache_miss":632,"cfile_cache_miss_bytes":28877109,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":949,"lbm_read_time_us":10962,"lbm_reads_lt_1ms":664,"lbm_write_time_us":35386,"lbm_writes_lt_1ms":643,"mutex_wait_us":34,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":46080,"update_count":3000}
I20260812 06:19:41.899663 29476 maintenance_manager.cc:419] P 74618a9db2da473a9aa3a1560ea503db: Scheduling FlushDeltaMemStoresOp(f033abff6faa4575bf15a0f48ebf2954): perf score=14.095187
I20260812 06:19:41.950763 29408 maintenance_manager.cc:643] P 74618a9db2da473a9aa3a1560ea503db: FlushDeltaMemStoresOp(f033abff6faa4575bf15a0f48ebf2954) complete. Timing: real 0.051s	user 0.027s	sys 0.020s Metrics: {"bytes_written":16409903,"delete_count":0,"lbm_write_time_us":22651,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:41.951378 29476 maintenance_manager.cc:419] P 74618a9db2da473a9aa3a1560ea503db: Scheduling FlushDeltaMemStoresOp(f033abff6faa4575bf15a0f48ebf2954): perf score=2.188937
I20260812 06:19:41.967159 29408 maintenance_manager.cc:643] P 74618a9db2da473a9aa3a1560ea503db: FlushDeltaMemStoresOp(f033abff6faa4575bf15a0f48ebf2954) complete. Timing: real 0.016s	user 0.012s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5630,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:41.967730 29476 maintenance_manager.cc:419] P 74618a9db2da473a9aa3a1560ea503db: Scheduling MajorDeltaCompactionOp(f033abff6faa4575bf15a0f48ebf2954): perf score=1.000000
I20260812 06:19:42.137151 29408 maintenance_manager.cc:643] P 74618a9db2da473a9aa3a1560ea503db: MajorDeltaCompactionOp(f033abff6faa4575bf15a0f48ebf2954) complete. Timing: real 0.169s	user 0.119s	sys 0.048s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774690,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":548,"lbm_read_time_us":12409,"lbm_reads_lt_1ms":564,"lbm_write_time_us":32196,"lbm_writes_lt_1ms":543,"mutex_wait_us":27,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":28672,"update_count":2500}
I20260812 06:19:42.137940 29476 maintenance_manager.cc:419] P 74618a9db2da473a9aa3a1560ea503db: Scheduling FlushDeltaMemStoresOp(f033abff6faa4575bf15a0f48ebf2954): perf score=14.095187
I20260812 06:19:42.200551 29408 maintenance_manager.cc:643] P 74618a9db2da473a9aa3a1560ea503db: FlushDeltaMemStoresOp(f033abff6faa4575bf15a0f48ebf2954) complete. Timing: real 0.062s	user 0.031s	sys 0.016s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":21485,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:42.201041 29476 maintenance_manager.cc:419] P 74618a9db2da473a9aa3a1560ea503db: Scheduling FlushDeltaMemStoresOp(f033abff6faa4575bf15a0f48ebf2954): perf score=2.188937
I20260812 06:19:42.212227 29408 maintenance_manager.cc:643] P 74618a9db2da473a9aa3a1560ea503db: FlushDeltaMemStoresOp(f033abff6faa4575bf15a0f48ebf2954) complete. Timing: real 0.011s	user 0.003s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4142,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:42.212785 29476 maintenance_manager.cc:419] P 74618a9db2da473a9aa3a1560ea503db: Scheduling FlushMRSOp(f033abff6faa4575bf15a0f48ebf2954): perf score=1.000000
I20260812 06:19:42.248543 29408 maintenance_manager.cc:643] P 74618a9db2da473a9aa3a1560ea503db: FlushMRSOp(f033abff6faa4575bf15a0f48ebf2954) complete. Timing: real 0.036s	user 0.035s	sys 0.000s Metrics: {"bytes_written":1316417,"cfile_init":1,"dirs.queue_time_us":67,"dirs.run_cpu_time_us":176,"dirs.run_wall_time_us":1515,"drs_written":1,"lbm_read_time_us":62,"lbm_reads_lt_1ms":4,"lbm_write_time_us":2119,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":32}
I20260812 06:19:42.249333 29476 maintenance_manager.cc:419] P 74618a9db2da473a9aa3a1560ea503db: Scheduling LogGCOp(f033abff6faa4575bf15a0f48ebf2954): free 129320773 bytes of WAL
I20260812 06:19:42.249789 29408 log_reader.cc:385] T f033abff6faa4575bf15a0f48ebf2954: removed 13 log segments from log reader
I20260812 06:19:42.249888 29408 log.cc:1079] T f033abff6faa4575bf15a0f48ebf2954 P 74618a9db2da473a9aa3a1560ea503db: Deleting log segment in path: /tmp/dist-test-tasklNF8fM/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515571494869-29067-0/minicluster-data/ts-0-root/wals/f033abff6faa4575bf15a0f48ebf2954/wal-000000026 (ops 127-131)
I20260812 06:19:42.249965 29408 log.cc:1079] T f033abff6faa4575bf15a0f48ebf2954 P 74618a9db2da473a9aa3a1560ea503db: Deleting log segment in path: /tmp/dist-test-tasklNF8fM/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515571494869-29067-0/minicluster-data/ts-0-root/wals/f033abff6faa4575bf15a0f48ebf2954/wal-000000027 (ops 132-136)
I20260812 06:19:42.250039 29408 log.cc:1079] T f033abff6faa4575bf15a0f48ebf2954 P 74618a9db2da473a9aa3a1560ea503db: Deleting log segment in path: /tmp/dist-test-tasklNF8fM/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515571494869-29067-0/minicluster-data/ts-0-root/wals/f033abff6faa4575bf15a0f48ebf2954/wal-000000028 (ops 137-140)
I20260812 06:19:42.250103 29408 log.cc:1079] T f033abff6faa4575bf15a0f48ebf2954 P 74618a9db2da473a9aa3a1560ea503db: Deleting log segment in path: /tmp/dist-test-tasklNF8fM/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515571494869-29067-0/minicluster-data/ts-0-root/wals/f033abff6faa4575bf15a0f48ebf2954/wal-000000029 (ops 141-145)
I20260812 06:19:42.250175 29408 log.cc:1079] T f033abff6faa4575bf15a0f48ebf2954 P 74618a9db2da473a9aa3a1560ea503db: Deleting log segment in path: /tmp/dist-test-tasklNF8fM/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515571494869-29067-0/minicluster-data/ts-0-root/wals/f033abff6faa4575bf15a0f48ebf2954/wal-000000030 (ops 146-150)
I20260812 06:19:42.250213 29408 log.cc:1079] T f033abff6faa4575bf15a0f48ebf2954 P 74618a9db2da473a9aa3a1560ea503db: Deleting log segment in path: /tmp/dist-test-tasklNF8fM/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515571494869-29067-0/minicluster-data/ts-0-root/wals/f033abff6faa4575bf15a0f48ebf2954/wal-000000031 (ops 151-155)
I20260812 06:19:42.250257 29408 log.cc:1079] T f033abff6faa4575bf15a0f48ebf2954 P 74618a9db2da473a9aa3a1560ea503db: Deleting log segment in path: /tmp/dist-test-tasklNF8fM/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515571494869-29067-0/minicluster-data/ts-0-root/wals/f033abff6faa4575bf15a0f48ebf2954/wal-000000032 (ops 156-160)
I20260812 06:19:42.250299 29408 log.cc:1079] T f033abff6faa4575bf15a0f48ebf2954 P 74618a9db2da473a9aa3a1560ea503db: Deleting log segment in path: /tmp/dist-test-tasklNF8fM/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515571494869-29067-0/minicluster-data/ts-0-root/wals/f033abff6faa4575bf15a0f48ebf2954/wal-000000033 (ops 161-164)
I20260812 06:19:42.250340 29408 log.cc:1079] T f033abff6faa4575bf15a0f48ebf2954 P 74618a9db2da473a9aa3a1560ea503db: Deleting log segment in path: /tmp/dist-test-tasklNF8fM/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515571494869-29067-0/minicluster-data/ts-0-root/wals/f033abff6faa4575bf15a0f48ebf2954/wal-000000034 (ops 165-169)
I20260812 06:19:42.250388 29408 log.cc:1079] T f033abff6faa4575bf15a0f48ebf2954 P 74618a9db2da473a9aa3a1560ea503db: Deleting log segment in path: /tmp/dist-test-tasklNF8fM/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515571494869-29067-0/minicluster-data/ts-0-root/wals/f033abff6faa4575bf15a0f48ebf2954/wal-000000035 (ops 170-174)
I20260812 06:19:42.250430 29408 log.cc:1079] T f033abff6faa4575bf15a0f48ebf2954 P 74618a9db2da473a9aa3a1560ea503db: Deleting log segment in path: /tmp/dist-test-tasklNF8fM/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515571494869-29067-0/minicluster-data/ts-0-root/wals/f033abff6faa4575bf15a0f48ebf2954/wal-000000036 (ops 175-179)
I20260812 06:19:42.250478 29408 log.cc:1079] T f033abff6faa4575bf15a0f48ebf2954 P 74618a9db2da473a9aa3a1560ea503db: Deleting log segment in path: /tmp/dist-test-tasklNF8fM/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515571494869-29067-0/minicluster-data/ts-0-root/wals/f033abff6faa4575bf15a0f48ebf2954/wal-000000037 (ops 180-184)
I20260812 06:19:42.250519 29408 log.cc:1079] T f033abff6faa4575bf15a0f48ebf2954 P 74618a9db2da473a9aa3a1560ea503db: Deleting log segment in path: /tmp/dist-test-tasklNF8fM/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515571494869-29067-0/minicluster-data/ts-0-root/wals/f033abff6faa4575bf15a0f48ebf2954/wal-000000038 (ops 185-189)
I20260812 06:19:42.279994 29408 maintenance_manager.cc:643] P 74618a9db2da473a9aa3a1560ea503db: LogGCOp(f033abff6faa4575bf15a0f48ebf2954) complete. Timing: real 0.030s	user 0.000s	sys 0.026s Metrics: {}
I20260812 06:19:42.280726 29476 maintenance_manager.cc:419] P 74618a9db2da473a9aa3a1560ea503db: Scheduling FlushDeltaMemStoresOp(f033abff6faa4575bf15a0f48ebf2954): perf score=5.165500
I20260812 06:19:42.296592 29408 maintenance_manager.cc:643] P 74618a9db2da473a9aa3a1560ea503db: FlushDeltaMemStoresOp(f033abff6faa4575bf15a0f48ebf2954) complete. Timing: real 0.016s	user 0.007s	sys 0.008s Metrics: {"bytes_written":6317966,"delete_count":0,"lbm_write_time_us":6418,"lbm_writes_lt_1ms":157,"reinsert_count":0,"update_count":770}
I20260812 06:19:42.297087 29476 maintenance_manager.cc:419] P 74618a9db2da473a9aa3a1560ea503db: Scheduling UndoDeltaBlockGCOp(f033abff6faa4575bf15a0f48ebf2954): 492 bytes on disk
I20260812 06:19:42.297494 29408 maintenance_manager.cc:643] P 74618a9db2da473a9aa3a1560ea503db: UndoDeltaBlockGCOp(f033abff6faa4575bf15a0f48ebf2954) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":54,"lbm_reads_lt_1ms":4}
I20260812 06:19:42.298009 29476 maintenance_manager.cc:419] P 74618a9db2da473a9aa3a1560ea503db: Scheduling FlushDeltaMemStoresOp(f033abff6faa4575bf15a0f48ebf2954): perf score=1.000000
I20260812 06:19:42.306588 29408 maintenance_manager.cc:643] P 74618a9db2da473a9aa3a1560ea503db: FlushDeltaMemStoresOp(f033abff6faa4575bf15a0f48ebf2954) complete. Timing: real 0.008s	user 0.004s	sys 0.003s Metrics: {"bytes_written":1887302,"delete_count":0,"lbm_write_time_us":2888,"lbm_writes_lt_1ms":49,"reinsert_count":0,"update_count":230}
I20260812 06:19:42.307153 29476 maintenance_manager.cc:419] P 74618a9db2da473a9aa3a1560ea503db: Scheduling MajorDeltaCompactionOp(f033abff6faa4575bf15a0f48ebf2954): perf score=1.000000
I20260812 06:19:42.537920 29067 heavy-update-compaction-itest.cc:229] Time spent updating: real 5.135s	user 1.855s	sys 0.166s
I20260812 06:19:42.540959 29408 maintenance_manager.cc:643] P 74618a9db2da473a9aa3a1560ea503db: MajorDeltaCompactionOp(f033abff6faa4575bf15a0f48ebf2954) complete. Timing: real 0.234s	user 0.123s	sys 0.100s Metrics: {"cfile_cache_miss":734,"cfile_cache_miss_bytes":32979696,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":620,"lbm_read_time_us":16920,"lbm_reads_lt_1ms":766,"lbm_write_time_us":39357,"lbm_writes_lt_1ms":743,"mutex_wait_us":284,"peak_mem_usage":87969044,"reinsert_count":0,"spinlock_wait_cycles":16768,"thread_start_us":77,"threads_started":1,"update_count":3500}
I20260812 06:19:42.541680 29476 maintenance_manager.cc:419] P 74618a9db2da473a9aa3a1560ea503db: Scheduling FlushDeltaMemStoresOp(f033abff6faa4575bf15a0f48ebf2954): perf score=18.063937
I20260812 06:19:42.568842 29067 heavy-update-compaction-itest.cc:265] Time spent scanning: real 0.031s	user 0.002s	sys 0.000s
I20260812 06:19:42.569391 29067 tablet_server.cc:179] TabletServer@127.28.98.193:0 shutting down...
I20260812 06:19:42.600291 29408 maintenance_manager.cc:643] P 74618a9db2da473a9aa3a1560ea503db: FlushDeltaMemStoresOp(f033abff6faa4575bf15a0f48ebf2954) complete. Timing: real 0.057s	user 0.045s	sys 0.012s Metrics: {"bytes_written":20512317,"delete_count":0,"lbm_write_time_us":24748,"lbm_writes_lt_1ms":503,"reinsert_count":0,"update_count":2500}
I20260812 06:19:42.600973 29067 ts_tablet_manager.cc:1507] Shutting down tablet manager...
I20260812 06:19:42.601212 29067 tablet_replica.cc:333] T f033abff6faa4575bf15a0f48ebf2954 P 74618a9db2da473a9aa3a1560ea503db: stopping tablet replica
I20260812 06:19:42.601364 29067 raft_consensus.cc:2243] T f033abff6faa4575bf15a0f48ebf2954 P 74618a9db2da473a9aa3a1560ea503db [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:19:42.601519 29067 raft_consensus.cc:2272] T f033abff6faa4575bf15a0f48ebf2954 P 74618a9db2da473a9aa3a1560ea503db [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:19:42.604830 29067 tablet_server.cc:196] TabletServer@127.28.98.193:0 shutdown complete.
I20260812 06:19:42.607674 29067 master.cc:562] Master@127.28.98.254:40745 shutting down...
I20260812 06:19:42.611153 29067 raft_consensus.cc:2243] T 00000000000000000000000000000000 P f2e25696e2f84f73880e0bdc616a70df [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:19:42.611300 29067 raft_consensus.cc:2272] T 00000000000000000000000000000000 P f2e25696e2f84f73880e0bdc616a70df [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:19:42.611348 29067 tablet_replica.cc:333] T 00000000000000000000000000000000 P f2e25696e2f84f73880e0bdc616a70df: stopping tablet replica
I20260812 06:19:42.623762 29067 master.cc:584] Master@127.28.98.254:40745 shutdown complete.
[       OK ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/1 (5531 ms)
[----------] 2 tests from EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy (11213 ms total)

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