[==========] Running 2 tests from 1 test suite.
[----------] Global test environment set-up.
[----------] 2 tests from EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy
[ RUN      ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/0
WARNING: Logging before InitGoogleLogging() is written to STDERR
I20260812 06:17:46.835614 27758 internal_mini_cluster.cc:156] Creating distributed mini masters. Addrs: 127.27.27.190:46031
I20260812 06:17:46.836483 27758 env_posix.cc:2285] Not raising this process' open files per process limit of 1048576; it is already as high as it can go
I20260812 06:17:46.837020 27758 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:17:46.842734 27769 instance_detector.cc:116] could not retrieve OpenStack instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:17:46.842872 27758 server_base.cc:1061] running on GCE node
W20260812 06:17:46.842815 27766 instance_detector.cc:116] could not retrieve AWS instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:17:46.842995 27767 instance_detector.cc:116] could not retrieve Azure instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:17:46.843479 27758 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:17:46.843572 27758 system_unsync_time.cc:38] NTP support is disabled. Clock error bounds will not be accurate. This configuration is not suitable for distributed clusters.
I20260812 06:17:46.843616 27758 hybrid_clock.cc:648] HybridClock initialized: now 1786515466843612 us; error 0 us; skew 500 ppm
I20260812 06:17:46.845098 27758 webserver.cc:533] Webserver started at http://127.27.27.190:36203/ using document root <none> and password file <none>
I20260812 06:17:46.845567 27758 fs_manager.cc:362] Metadata directory not provided
I20260812 06:17:46.845624 27758 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:17:46.845816 27758 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:17:46.847303 27758 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskdH4ppi/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515466825547-27758-0/minicluster-data/master-0-root/instance:
uuid: "782fb91a171c42e484c3444f9bb54fc7"
format_stamp: "Formatted at 2026-08-12 06:17:46 on dist-test-slave-tc2s"
I20260812 06:17:46.850415 27758 fs_manager.cc:696] Time spent creating directory manager: real 0.003s	user 0.004s	sys 0.000s
I20260812 06:17:46.852257 27774 log_block_manager.cc:4127] Time spent loading block containers with low live blocks: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:17:46.853143 27758 fs_manager.cc:730] Time spent opening block manager: real 0.002s	user 0.002s	sys 0.000s
I20260812 06:17:46.853241 27758 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskdH4ppi/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515466825547-27758-0/minicluster-data/master-0-root
uuid: "782fb91a171c42e484c3444f9bb54fc7"
format_stamp: "Formatted at 2026-08-12 06:17:46 on dist-test-slave-tc2s"
I20260812 06:17:46.853317 27758 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskdH4ppi/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515466825547-27758-0/minicluster-data/master-0-root
metadata directory: /tmp/dist-test-taskdH4ppi/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515466825547-27758-0/minicluster-data/master-0-root
1 data directories: /tmp/dist-test-taskdH4ppi/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515466825547-27758-0/minicluster-data/master-0-root/data
Total live blocks: 0
Total live bytes: 0
Total live bytes (after alignment): 0
Total number of LBM containers: 0 (0 full)
Did not check for missing blocks
Did not check for orphaned blocks
Total full LBM containers with extra space: 0 (0 repaired)
Total full LBM container extra space in bytes: 0 (0 repaired)
Total incomplete LBM containers: 0 (0 repaired)
Total LBM partial records: 0 (0 repaired)
Total corrupted LBM metadata records in RocksDB: 0 (0 repaired)
I20260812 06:17:46.865276 27758 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:17:46.865770 27758 env_posix.cc:2285] Not raising this process' running threads per effective uid limit of 18446744073709551615; it is already as high as it can go
I20260812 06:17:46.865942 27758 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:17:46.872694 27878 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.27.27.190:46031 every 8 connection(s)
I20260812 06:17:46.872697 27758 rpc_server.cc:307] RPC server started. Bound to: 127.27.27.190:46031
I20260812 06:17:46.874775 27883 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet 00000000000000000000000000000000. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:17:46.879769 27883 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P 782fb91a171c42e484c3444f9bb54fc7: Bootstrap starting.
I20260812 06:17:46.881932 27883 tablet_bootstrap.cc:654] T 00000000000000000000000000000000 P 782fb91a171c42e484c3444f9bb54fc7: Neither blocks nor log segments found. Creating new log.
I20260812 06:17:46.882731 27883 log.cc:826] T 00000000000000000000000000000000 P 782fb91a171c42e484c3444f9bb54fc7: Log is configured to *not* fsync() on all Append() calls
I20260812 06:17:46.884162 27883 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P 782fb91a171c42e484c3444f9bb54fc7: No bootstrap required, opened a new log
I20260812 06:17:46.886739 27883 raft_consensus.cc:359] T 00000000000000000000000000000000 P 782fb91a171c42e484c3444f9bb54fc7 [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "782fb91a171c42e484c3444f9bb54fc7" member_type: VOTER }
I20260812 06:17:46.886888 27883 raft_consensus.cc:385] T 00000000000000000000000000000000 P 782fb91a171c42e484c3444f9bb54fc7 [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:17:46.886932 27883 raft_consensus.cc:740] T 00000000000000000000000000000000 P 782fb91a171c42e484c3444f9bb54fc7 [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: 782fb91a171c42e484c3444f9bb54fc7, State: Initialized, Role: FOLLOWER
I20260812 06:17:46.887462 27883 consensus_queue.cc:260] T 00000000000000000000000000000000 P 782fb91a171c42e484c3444f9bb54fc7 [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: "782fb91a171c42e484c3444f9bb54fc7" member_type: VOTER }
I20260812 06:17:46.887598 27883 raft_consensus.cc:399] T 00000000000000000000000000000000 P 782fb91a171c42e484c3444f9bb54fc7 [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:17:46.887643 27883 raft_consensus.cc:493] T 00000000000000000000000000000000 P 782fb91a171c42e484c3444f9bb54fc7 [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:17:46.887727 27883 raft_consensus.cc:3060] T 00000000000000000000000000000000 P 782fb91a171c42e484c3444f9bb54fc7 [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:17:46.888368 27883 raft_consensus.cc:515] T 00000000000000000000000000000000 P 782fb91a171c42e484c3444f9bb54fc7 [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "782fb91a171c42e484c3444f9bb54fc7" member_type: VOTER }
I20260812 06:17:46.888734 27883 leader_election.cc:304] T 00000000000000000000000000000000 P 782fb91a171c42e484c3444f9bb54fc7 [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: 782fb91a171c42e484c3444f9bb54fc7; no voters: 
I20260812 06:17:46.888967 27883 leader_election.cc:290] T 00000000000000000000000000000000 P 782fb91a171c42e484c3444f9bb54fc7 [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:17:46.889074 27888 raft_consensus.cc:2804] T 00000000000000000000000000000000 P 782fb91a171c42e484c3444f9bb54fc7 [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:17:46.889274 27888 raft_consensus.cc:697] T 00000000000000000000000000000000 P 782fb91a171c42e484c3444f9bb54fc7 [term 1 LEADER]: Becoming Leader. State: Replica: 782fb91a171c42e484c3444f9bb54fc7, State: Running, Role: LEADER
I20260812 06:17:46.889639 27888 consensus_queue.cc:237] T 00000000000000000000000000000000 P 782fb91a171c42e484c3444f9bb54fc7 [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: "782fb91a171c42e484c3444f9bb54fc7" member_type: VOTER }
I20260812 06:17:46.889842 27883 sys_catalog.cc:565] T 00000000000000000000000000000000 P 782fb91a171c42e484c3444f9bb54fc7 [sys.catalog]: configured and running, proceeding with master startup.
I20260812 06:17:46.891438 27889 sys_catalog.cc:455] T 00000000000000000000000000000000 P 782fb91a171c42e484c3444f9bb54fc7 [sys.catalog]: SysCatalogTable state changed. Reason: RaftConsensus started. Latest consensus state: current_term: 1 leader_uuid: "782fb91a171c42e484c3444f9bb54fc7" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "782fb91a171c42e484c3444f9bb54fc7" member_type: VOTER } }
I20260812 06:17:46.891484 27890 sys_catalog.cc:455] T 00000000000000000000000000000000 P 782fb91a171c42e484c3444f9bb54fc7 [sys.catalog]: SysCatalogTable state changed. Reason: New leader 782fb91a171c42e484c3444f9bb54fc7. Latest consensus state: current_term: 1 leader_uuid: "782fb91a171c42e484c3444f9bb54fc7" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "782fb91a171c42e484c3444f9bb54fc7" member_type: VOTER } }
I20260812 06:17:46.891554 27889 sys_catalog.cc:458] T 00000000000000000000000000000000 P 782fb91a171c42e484c3444f9bb54fc7 [sys.catalog]: This master's current role is: LEADER
I20260812 06:17:46.891579 27890 sys_catalog.cc:458] T 00000000000000000000000000000000 P 782fb91a171c42e484c3444f9bb54fc7 [sys.catalog]: This master's current role is: LEADER
I20260812 06:17:46.892051 27758 internal_mini_cluster.cc:184] Waiting to initialize catalog manager on master 0
W20260812 06:17:46.893780 27915 catalog_manager.cc:1594] T 00000000000000000000000000000000 P 782fb91a171c42e484c3444f9bb54fc7: loading cluster ID for follower catalog manager: Not found: cluster ID entry not found
W20260812 06:17:46.893843 27915 catalog_manager.cc:883] Not found: cluster ID entry not found: failed to prepare follower catalog manager, will retry
I20260812 06:17:46.893949 27908 catalog_manager.cc:1511] Loading table and tablet metadata into memory...
I20260812 06:17:46.894840 27908 catalog_manager.cc:1520] Initializing Kudu cluster ID...
I20260812 06:17:46.899189 27908 catalog_manager.cc:1383] Generated new cluster ID: e8079bddbf3749f88283ad48be509efb
I20260812 06:17:46.899248 27908 catalog_manager.cc:1531] Initializing Kudu internal certificate authority...
I20260812 06:17:46.904158 27908 catalog_manager.cc:1406] Generated new certificate authority record
I20260812 06:17:46.904871 27908 catalog_manager.cc:1540] Loading token signing keys...
I20260812 06:17:46.915772 27908 catalog_manager.cc:6092] T 00000000000000000000000000000000 P 782fb91a171c42e484c3444f9bb54fc7: Generated new TSK 0
I20260812 06:17:46.916249 27908 catalog_manager.cc:1550] Initializing in-progress tserver states...
I20260812 06:17:46.924465 27758 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:17:46.927031 27922 instance_detector.cc:116] could not retrieve Azure instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:17:46.927083 27921 instance_detector.cc:116] could not retrieve AWS instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:17:46.927248 27758 server_base.cc:1061] running on GCE node
W20260812 06:17:46.927408 27924 instance_detector.cc:116] could not retrieve OpenStack instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:17:46.927604 27758 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:17:46.927649 27758 system_unsync_time.cc:38] NTP support is disabled. Clock error bounds will not be accurate. This configuration is not suitable for distributed clusters.
I20260812 06:17:46.927668 27758 hybrid_clock.cc:648] HybridClock initialized: now 1786515466927668 us; error 0 us; skew 500 ppm
I20260812 06:17:46.928498 27758 webserver.cc:533] Webserver started at http://127.27.27.129:43155/ using document root <none> and password file <none>
I20260812 06:17:46.928649 27758 fs_manager.cc:362] Metadata directory not provided
I20260812 06:17:46.928697 27758 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:17:46.928767 27758 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:17:46.929095 27758 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskdH4ppi/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515466825547-27758-0/minicluster-data/ts-0-root/instance:
uuid: "5e96228f5a1b4776a828e10faa8842e4"
format_stamp: "Formatted at 2026-08-12 06:17:46 on dist-test-slave-tc2s"
I20260812 06:17:46.930542 27758 fs_manager.cc:696] Time spent creating directory manager: real 0.001s	user 0.002s	sys 0.000s
I20260812 06:17:46.931443 27937 log_block_manager.cc:4127] Time spent loading block containers with low live blocks: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:17:46.931697 27758 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.001s	sys 0.000s
I20260812 06:17:46.931761 27758 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskdH4ppi/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515466825547-27758-0/minicluster-data/ts-0-root
uuid: "5e96228f5a1b4776a828e10faa8842e4"
format_stamp: "Formatted at 2026-08-12 06:17:46 on dist-test-slave-tc2s"
I20260812 06:17:46.931825 27758 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskdH4ppi/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515466825547-27758-0/minicluster-data/ts-0-root
metadata directory: /tmp/dist-test-taskdH4ppi/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515466825547-27758-0/minicluster-data/ts-0-root
1 data directories: /tmp/dist-test-taskdH4ppi/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515466825547-27758-0/minicluster-data/ts-0-root/data
Total live blocks: 0
Total live bytes: 0
Total live bytes (after alignment): 0
Total number of LBM containers: 0 (0 full)
Did not check for missing blocks
Did not check for orphaned blocks
Total full LBM containers with extra space: 0 (0 repaired)
Total full LBM container extra space in bytes: 0 (0 repaired)
Total incomplete LBM containers: 0 (0 repaired)
Total LBM partial records: 0 (0 repaired)
Total corrupted LBM metadata records in RocksDB: 0 (0 repaired)
I20260812 06:17:46.945766 27758 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:17:46.946123 27758 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:17:46.946497 27758 txn_system_client.cc:432] TxnSystemClient initialization is disabled...
I20260812 06:17:46.947227 27758 ts_tablet_manager.cc:585] Loaded tablet metadata (0 total tablets, 0 live tablets)
I20260812 06:17:46.947278 27758 ts_tablet_manager.cc:531] Time spent load tablet metadata: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:17:46.947319 27758 ts_tablet_manager.cc:616] Registered 0 tablets
I20260812 06:17:46.947350 27758 ts_tablet_manager.cc:595] Time spent register tablets: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:17:46.953299 27758 rpc_server.cc:307] RPC server started. Bound to: 127.27.27.129:35091
I20260812 06:17:46.953423 28053 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.27.27.129:35091 every 8 connection(s)
I20260812 06:17:46.963606 28056 heartbeater.cc:344] Connected to a master server at 127.27.27.190:46031
I20260812 06:17:46.963828 28056 heartbeater.cc:461] Registering TS with master...
I20260812 06:17:46.964259 28056 heartbeater.cc:507] Master 127.27.27.190:46031 requested a full tablet report, sending...
I20260812 06:17:46.965631 27806 ts_manager.cc:194] Registered new tserver with Master: 5e96228f5a1b4776a828e10faa8842e4 (127.27.27.129:35091)
I20260812 06:17:46.966212 27758 internal_mini_cluster.cc:371] 1 TS(s) registered with all masters after 0.012227038s
I20260812 06:17:46.967070 27806 master_service.cc:502] Signed X509 certificate for tserver {username='slave'} at 127.0.0.1:44612
I20260812 06:17:46.974722 27806 catalog_manager.cc:2283] Servicing CreateTable request from {username='slave'} at 127.0.0.1:44628:
name: "heavy-update-compaction-test"
schema {
  columns {
    name: "key"
    type: INT64
    is_key: true
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_a"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_b"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_c"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_d"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_e"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
}
num_replicas: 1
split_rows_range_bounds {
}
partition_schema {
  range_schema {
  }
}
I20260812 06:17:46.987092 27989 tablet_service.cc:1511] Processing CreateTablet for tablet 15d52d09c3864f4e847d842d4c500a9f (DEFAULT_TABLE table=heavy-update-compaction-test [id=9542dfe67ecd45b08d5423d34d7a3b56]), partition=
I20260812 06:17:46.987517 27989 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet 15d52d09c3864f4e847d842d4c500a9f. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:17:46.990077 28080 tablet_bootstrap.cc:492] T 15d52d09c3864f4e847d842d4c500a9f P 5e96228f5a1b4776a828e10faa8842e4: Bootstrap starting.
I20260812 06:17:46.990918 28080 tablet_bootstrap.cc:654] T 15d52d09c3864f4e847d842d4c500a9f P 5e96228f5a1b4776a828e10faa8842e4: Neither blocks nor log segments found. Creating new log.
I20260812 06:17:46.992169 28080 tablet_bootstrap.cc:492] T 15d52d09c3864f4e847d842d4c500a9f P 5e96228f5a1b4776a828e10faa8842e4: No bootstrap required, opened a new log
I20260812 06:17:46.992256 28080 ts_tablet_manager.cc:1403] T 15d52d09c3864f4e847d842d4c500a9f P 5e96228f5a1b4776a828e10faa8842e4: Time spent bootstrapping tablet: real 0.002s	user 0.001s	sys 0.000s
I20260812 06:17:46.992616 28080 raft_consensus.cc:359] T 15d52d09c3864f4e847d842d4c500a9f P 5e96228f5a1b4776a828e10faa8842e4 [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "5e96228f5a1b4776a828e10faa8842e4" member_type: VOTER last_known_addr { host: "127.27.27.129" port: 35091 } }
I20260812 06:17:46.992708 28080 raft_consensus.cc:385] T 15d52d09c3864f4e847d842d4c500a9f P 5e96228f5a1b4776a828e10faa8842e4 [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:17:46.992740 28080 raft_consensus.cc:740] T 15d52d09c3864f4e847d842d4c500a9f P 5e96228f5a1b4776a828e10faa8842e4 [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: 5e96228f5a1b4776a828e10faa8842e4, State: Initialized, Role: FOLLOWER
I20260812 06:17:46.992858 28080 consensus_queue.cc:260] T 15d52d09c3864f4e847d842d4c500a9f P 5e96228f5a1b4776a828e10faa8842e4 [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: "5e96228f5a1b4776a828e10faa8842e4" member_type: VOTER last_known_addr { host: "127.27.27.129" port: 35091 } }
I20260812 06:17:46.992951 28080 raft_consensus.cc:399] T 15d52d09c3864f4e847d842d4c500a9f P 5e96228f5a1b4776a828e10faa8842e4 [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:17:46.992995 28080 raft_consensus.cc:493] T 15d52d09c3864f4e847d842d4c500a9f P 5e96228f5a1b4776a828e10faa8842e4 [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:17:46.993044 28080 raft_consensus.cc:3060] T 15d52d09c3864f4e847d842d4c500a9f P 5e96228f5a1b4776a828e10faa8842e4 [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:17:46.993700 28080 raft_consensus.cc:515] T 15d52d09c3864f4e847d842d4c500a9f P 5e96228f5a1b4776a828e10faa8842e4 [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "5e96228f5a1b4776a828e10faa8842e4" member_type: VOTER last_known_addr { host: "127.27.27.129" port: 35091 } }
I20260812 06:17:46.993824 28080 leader_election.cc:304] T 15d52d09c3864f4e847d842d4c500a9f P 5e96228f5a1b4776a828e10faa8842e4 [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: 5e96228f5a1b4776a828e10faa8842e4; no voters: 
I20260812 06:17:46.994040 28080 leader_election.cc:290] T 15d52d09c3864f4e847d842d4c500a9f P 5e96228f5a1b4776a828e10faa8842e4 [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:17:46.994166 28084 raft_consensus.cc:2804] T 15d52d09c3864f4e847d842d4c500a9f P 5e96228f5a1b4776a828e10faa8842e4 [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:17:46.994359 28084 raft_consensus.cc:697] T 15d52d09c3864f4e847d842d4c500a9f P 5e96228f5a1b4776a828e10faa8842e4 [term 1 LEADER]: Becoming Leader. State: Replica: 5e96228f5a1b4776a828e10faa8842e4, State: Running, Role: LEADER
I20260812 06:17:46.994506 28084 consensus_queue.cc:237] T 15d52d09c3864f4e847d842d4c500a9f P 5e96228f5a1b4776a828e10faa8842e4 [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: "5e96228f5a1b4776a828e10faa8842e4" member_type: VOTER last_known_addr { host: "127.27.27.129" port: 35091 } }
I20260812 06:17:46.994633 28056 heartbeater.cc:499] Master 127.27.27.190:46031 was elected leader, sending a full tablet report...
I20260812 06:17:46.994349 28080 ts_tablet_manager.cc:1434] T 15d52d09c3864f4e847d842d4c500a9f P 5e96228f5a1b4776a828e10faa8842e4: Time spent starting tablet: real 0.002s	user 0.002s	sys 0.000s
I20260812 06:17:46.997152 27805 catalog_manager.cc:5719] T 15d52d09c3864f4e847d842d4c500a9f P 5e96228f5a1b4776a828e10faa8842e4 reported cstate change: term changed from 0 to 1, leader changed from <none> to 5e96228f5a1b4776a828e10faa8842e4 (127.27.27.129). New cstate: current_term: 1 leader_uuid: "5e96228f5a1b4776a828e10faa8842e4" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "5e96228f5a1b4776a828e10faa8842e4" member_type: VOTER last_known_addr { host: "127.27.27.129" port: 35091 } health_report { overall_health: HEALTHY } } }
I20260812 06:17:47.059235 27758 heavy-update-compaction-itest.cc:215] Time spent inserting: real 0.056s	user 0.017s	sys 0.008s
I20260812 06:17:47.205411 28058 maintenance_manager.cc:419] P 5e96228f5a1b4776a828e10faa8842e4: Scheduling FlushMRSOp(15d52d09c3864f4e847d842d4c500a9f): perf score=19.054940
I20260812 06:17:47.413363 27947 maintenance_manager.cc:643] P 5e96228f5a1b4776a828e10faa8842e4: FlushMRSOp(15d52d09c3864f4e847d842d4c500a9f) complete. Timing: real 0.208s	user 0.140s	sys 0.054s Metrics: {"bytes_written":16861170,"cfile_init":1,"compiler_manager_pool.queue_time_us":205,"delete_count":0,"dirs.queue_time_us":46,"dirs.run_cpu_time_us":193,"dirs.run_wall_time_us":1071,"drs_written":1,"lbm_read_time_us":72,"lbm_reads_lt_1ms":4,"lbm_write_time_us":47587,"lbm_writes_lt_1ms":878,"mutex_wait_us":244,"peak_mem_usage":0,"reinsert_count":0,"rows_written":105,"spinlock_wait_cycles":335616,"thread_start_us":110,"threads_started":1,"update_count":2055}
I20260812 06:17:47.414377 28058 maintenance_manager.cc:419] P 5e96228f5a1b4776a828e10faa8842e4: Scheduling LogGCOp(15d52d09c3864f4e847d842d4c500a9f): free 20743880 bytes of WAL
I20260812 06:17:47.414639 27947 log_reader.cc:385] T 15d52d09c3864f4e847d842d4c500a9f: removed 2 log segments from log reader
I20260812 06:17:47.414696 27947 log.cc:1079] T 15d52d09c3864f4e847d842d4c500a9f P 5e96228f5a1b4776a828e10faa8842e4: Deleting log segment in path: /tmp/dist-test-taskdH4ppi/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515466825547-27758-0/minicluster-data/ts-0-root/wals/15d52d09c3864f4e847d842d4c500a9f/wal-000000001 (ops 1-6)
I20260812 06:17:47.414757 27947 log.cc:1079] T 15d52d09c3864f4e847d842d4c500a9f P 5e96228f5a1b4776a828e10faa8842e4: Deleting log segment in path: /tmp/dist-test-taskdH4ppi/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515466825547-27758-0/minicluster-data/ts-0-root/wals/15d52d09c3864f4e847d842d4c500a9f/wal-000000002 (ops 7-11)
I20260812 06:17:47.418574 27947 maintenance_manager.cc:643] P 5e96228f5a1b4776a828e10faa8842e4: LogGCOp(15d52d09c3864f4e847d842d4c500a9f) complete. Timing: real 0.004s	user 0.000s	sys 0.003s Metrics: {}
I20260812 06:17:47.418895 28058 maintenance_manager.cc:419] P 5e96228f5a1b4776a828e10faa8842e4: Scheduling FlushDeltaMemStoresOp(15d52d09c3864f4e847d842d4c500a9f): perf score=6.157687
I20260812 06:17:47.438503 27947 maintenance_manager.cc:643] P 5e96228f5a1b4776a828e10faa8842e4: FlushDeltaMemStoresOp(15d52d09c3864f4e847d842d4c500a9f) complete. Timing: real 0.019s	user 0.015s	sys 0.004s Metrics: {"bytes_written":7343577,"delete_count":0,"lbm_write_time_us":8100,"lbm_writes_lt_1ms":182,"reinsert_count":0,"update_count":895}
I20260812 06:17:47.438920 28058 maintenance_manager.cc:419] P 5e96228f5a1b4776a828e10faa8842e4: Scheduling MajorDeltaCompactionOp(15d52d09c3864f4e847d842d4c500a9f): perf score=1.000000
I20260812 06:17:47.618544 27947 maintenance_manager.cc:643] P 5e96228f5a1b4776a828e10faa8842e4: MajorDeltaCompactionOp(15d52d09c3864f4e847d842d4c500a9f) complete. Timing: real 0.179s	user 0.149s	sys 0.028s Metrics: {"cfile_cache_miss":622,"cfile_cache_miss_bytes":28507864,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":827,"lbm_read_time_us":12087,"lbm_reads_lt_1ms":654,"lbm_write_time_us":31007,"lbm_writes_lt_1ms":633,"mutex_wait_us":107,"peak_mem_usage":74091738,"reinsert_count":0,"thread_start_us":316,"threads_started":5,"update_count":2950}
I20260812 06:17:47.618973 28058 maintenance_manager.cc:419] P 5e96228f5a1b4776a828e10faa8842e4: Scheduling FlushDeltaMemStoresOp(15d52d09c3864f4e847d842d4c500a9f): perf score=14.095187
I20260812 06:17:47.664479 27947 maintenance_manager.cc:643] P 5e96228f5a1b4776a828e10faa8842e4: FlushDeltaMemStoresOp(15d52d09c3864f4e847d842d4c500a9f) complete. Timing: real 0.045s	user 0.020s	sys 0.020s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":19281,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:17:47.664958 28058 maintenance_manager.cc:419] P 5e96228f5a1b4776a828e10faa8842e4: Scheduling MajorDeltaCompactionOp(15d52d09c3864f4e847d842d4c500a9f): perf score=1.000000
I20260812 06:17:47.800477 27947 maintenance_manager.cc:643] P 5e96228f5a1b4776a828e10faa8842e4: MajorDeltaCompactionOp(15d52d09c3864f4e847d842d4c500a9f) complete. Timing: real 0.135s	user 0.086s	sys 0.048s Metrics: {"cfile_cache_miss":431,"cfile_cache_miss_bytes":20713152,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":1,"delta_iterators_relevant":1,"dirs.queue_time_us":124,"lbm_read_time_us":9796,"lbm_reads_lt_1ms":463,"lbm_write_time_us":20681,"lbm_writes_lt_1ms":443,"mutex_wait_us":41,"peak_mem_usage":50689328,"reinsert_count":0,"update_count":2000}
I20260812 06:17:47.801010 28058 maintenance_manager.cc:419] P 5e96228f5a1b4776a828e10faa8842e4: Scheduling UndoDeltaBlockGCOp(15d52d09c3864f4e847d842d4c500a9f): 16821650 bytes on disk
I20260812 06:17:47.801501 27947 maintenance_manager.cc:643] P 5e96228f5a1b4776a828e10faa8842e4: UndoDeltaBlockGCOp(15d52d09c3864f4e847d842d4c500a9f) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":59,"lbm_reads_lt_1ms":4}
I20260812 06:17:47.801957 28058 maintenance_manager.cc:419] P 5e96228f5a1b4776a828e10faa8842e4: Scheduling FlushDeltaMemStoresOp(15d52d09c3864f4e847d842d4c500a9f): perf score=11.118625
I20260812 06:17:47.832065 27947 maintenance_manager.cc:643] P 5e96228f5a1b4776a828e10faa8842e4: FlushDeltaMemStoresOp(15d52d09c3864f4e847d842d4c500a9f) complete. Timing: real 0.030s	user 0.019s	sys 0.009s Metrics: {"bytes_written":12717735,"delete_count":0,"lbm_write_time_us":12712,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:17:47.832505 28058 maintenance_manager.cc:419] P 5e96228f5a1b4776a828e10faa8842e4: Scheduling FlushDeltaMemStoresOp(15d52d09c3864f4e847d842d4c500a9f): perf score=2.188937
I20260812 06:17:47.845935 27947 maintenance_manager.cc:643] P 5e96228f5a1b4776a828e10faa8842e4: FlushDeltaMemStoresOp(15d52d09c3864f4e847d842d4c500a9f) complete. Timing: real 0.013s	user 0.013s	sys 0.000s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":5425,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:17:47.846371 28058 maintenance_manager.cc:419] P 5e96228f5a1b4776a828e10faa8842e4: Scheduling MajorDeltaCompactionOp(15d52d09c3864f4e847d842d4c500a9f): perf score=1.000000
I20260812 06:17:47.965649 27947 maintenance_manager.cc:643] P 5e96228f5a1b4776a828e10faa8842e4: MajorDeltaCompactionOp(15d52d09c3864f4e847d842d4c500a9f) complete. Timing: real 0.119s	user 0.087s	sys 0.032s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20713263,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":494,"lbm_read_time_us":7518,"lbm_reads_lt_1ms":464,"lbm_write_time_us":23174,"lbm_writes_lt_1ms":443,"mutex_wait_us":301,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":16384,"update_count":2000}
I20260812 06:17:47.966126 28058 maintenance_manager.cc:419] P 5e96228f5a1b4776a828e10faa8842e4: Scheduling FlushDeltaMemStoresOp(15d52d09c3864f4e847d842d4c500a9f): perf score=10.126437
I20260812 06:17:48.008481 27947 maintenance_manager.cc:643] P 5e96228f5a1b4776a828e10faa8842e4: FlushDeltaMemStoresOp(15d52d09c3864f4e847d842d4c500a9f) complete. Timing: real 0.042s	user 0.023s	sys 0.009s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":14556,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:17:48.008970 28058 maintenance_manager.cc:419] P 5e96228f5a1b4776a828e10faa8842e4: Scheduling FlushDeltaMemStoresOp(15d52d09c3864f4e847d842d4c500a9f): perf score=2.188937
I20260812 06:17:48.018548 27947 maintenance_manager.cc:643] P 5e96228f5a1b4776a828e10faa8842e4: FlushDeltaMemStoresOp(15d52d09c3864f4e847d842d4c500a9f) complete. Timing: real 0.009s	user 0.005s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3694,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:48.018939 28058 maintenance_manager.cc:419] P 5e96228f5a1b4776a828e10faa8842e4: Scheduling MajorDeltaCompactionOp(15d52d09c3864f4e847d842d4c500a9f): perf score=1.000000
I20260812 06:17:48.139652 27947 maintenance_manager.cc:643] P 5e96228f5a1b4776a828e10faa8842e4: MajorDeltaCompactionOp(15d52d09c3864f4e847d842d4c500a9f) complete. Timing: real 0.121s	user 0.096s	sys 0.024s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20713272,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":173,"lbm_read_time_us":7785,"lbm_reads_lt_1ms":472,"lbm_write_time_us":23381,"lbm_writes_lt_1ms":443,"mutex_wait_us":34,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":6400,"update_count":2000}
I20260812 06:17:48.140316 28058 maintenance_manager.cc:419] P 5e96228f5a1b4776a828e10faa8842e4: Scheduling FlushDeltaMemStoresOp(15d52d09c3864f4e847d842d4c500a9f): perf score=10.126437
I20260812 06:17:48.182524 27947 maintenance_manager.cc:643] P 5e96228f5a1b4776a828e10faa8842e4: FlushDeltaMemStoresOp(15d52d09c3864f4e847d842d4c500a9f) complete. Timing: real 0.042s	user 0.027s	sys 0.007s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":15225,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:17:48.183007 28058 maintenance_manager.cc:419] P 5e96228f5a1b4776a828e10faa8842e4: Scheduling FlushDeltaMemStoresOp(15d52d09c3864f4e847d842d4c500a9f): perf score=2.188937
I20260812 06:17:48.192701 27947 maintenance_manager.cc:643] P 5e96228f5a1b4776a828e10faa8842e4: FlushDeltaMemStoresOp(15d52d09c3864f4e847d842d4c500a9f) complete. Timing: real 0.010s	user 0.008s	sys 0.000s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":3730,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:48.193233 28058 maintenance_manager.cc:419] P 5e96228f5a1b4776a828e10faa8842e4: Scheduling MajorDeltaCompactionOp(15d52d09c3864f4e847d842d4c500a9f): perf score=1.000000
I20260812 06:17:48.313627 27947 maintenance_manager.cc:643] P 5e96228f5a1b4776a828e10faa8842e4: MajorDeltaCompactionOp(15d52d09c3864f4e847d842d4c500a9f) complete. Timing: real 0.120s	user 0.104s	sys 0.016s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20713271,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":199,"lbm_read_time_us":9468,"lbm_reads_lt_1ms":472,"lbm_write_time_us":22333,"lbm_writes_lt_1ms":443,"mutex_wait_us":26,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":10496,"update_count":2000}
I20260812 06:17:48.314128 28058 maintenance_manager.cc:419] P 5e96228f5a1b4776a828e10faa8842e4: Scheduling FlushDeltaMemStoresOp(15d52d09c3864f4e847d842d4c500a9f): perf score=10.126437
I20260812 06:17:48.367890 27947 maintenance_manager.cc:643] P 5e96228f5a1b4776a828e10faa8842e4: FlushDeltaMemStoresOp(15d52d09c3864f4e847d842d4c500a9f) complete. Timing: real 0.054s	user 0.028s	sys 0.012s Metrics: {"bytes_written":12307489,"delete_count":0,"lbm_write_time_us":14916,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:17:48.368443 28058 maintenance_manager.cc:419] P 5e96228f5a1b4776a828e10faa8842e4: Scheduling FlushDeltaMemStoresOp(15d52d09c3864f4e847d842d4c500a9f): perf score=2.188937
I20260812 06:17:48.383597 27947 maintenance_manager.cc:643] P 5e96228f5a1b4776a828e10faa8842e4: FlushDeltaMemStoresOp(15d52d09c3864f4e847d842d4c500a9f) complete. Timing: real 0.015s	user 0.005s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5790,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:48.384095 28058 maintenance_manager.cc:419] P 5e96228f5a1b4776a828e10faa8842e4: Scheduling MajorDeltaCompactionOp(15d52d09c3864f4e847d842d4c500a9f): perf score=1.000000
I20260812 06:17:48.523383 27947 maintenance_manager.cc:643] P 5e96228f5a1b4776a828e10faa8842e4: MajorDeltaCompactionOp(15d52d09c3864f4e847d842d4c500a9f) complete. Timing: real 0.139s	user 0.070s	sys 0.068s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20713271,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":262,"lbm_read_time_us":12599,"lbm_reads_1-10_ms":1,"lbm_reads_lt_1ms":471,"lbm_write_time_us":21198,"lbm_writes_lt_1ms":443,"mutex_wait_us":29,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":5632,"update_count":2000}
I20260812 06:17:48.523913 28058 maintenance_manager.cc:419] P 5e96228f5a1b4776a828e10faa8842e4: Scheduling FlushDeltaMemStoresOp(15d52d09c3864f4e847d842d4c500a9f): perf score=10.126437
I20260812 06:17:48.567634 27947 maintenance_manager.cc:643] P 5e96228f5a1b4776a828e10faa8842e4: FlushDeltaMemStoresOp(15d52d09c3864f4e847d842d4c500a9f) complete. Timing: real 0.044s	user 0.025s	sys 0.011s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":16099,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:17:48.568143 28058 maintenance_manager.cc:419] P 5e96228f5a1b4776a828e10faa8842e4: Scheduling FlushDeltaMemStoresOp(15d52d09c3864f4e847d842d4c500a9f): perf score=2.188937
I20260812 06:17:48.583356 27947 maintenance_manager.cc:643] P 5e96228f5a1b4776a828e10faa8842e4: FlushDeltaMemStoresOp(15d52d09c3864f4e847d842d4c500a9f) complete. Timing: real 0.015s	user 0.013s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5858,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:48.583992 28058 maintenance_manager.cc:419] P 5e96228f5a1b4776a828e10faa8842e4: Scheduling FlushMRSOp(15d52d09c3864f4e847d842d4c500a9f): perf score=1.000000
I20260812 06:17:48.610249 27947 maintenance_manager.cc:643] P 5e96228f5a1b4776a828e10faa8842e4: FlushMRSOp(15d52d09c3864f4e847d842d4c500a9f) complete. Timing: real 0.026s	user 0.022s	sys 0.004s Metrics: {"bytes_written":1193503,"cfile_init":1,"dirs.queue_time_us":59,"dirs.run_cpu_time_us":245,"dirs.run_wall_time_us":1152,"drs_written":1,"lbm_read_time_us":50,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1374,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":29}
I20260812 06:17:48.611008 28058 maintenance_manager.cc:419] P 5e96228f5a1b4776a828e10faa8842e4: Scheduling LogGCOp(15d52d09c3864f4e847d842d4c500a9f): free 124710307 bytes of WAL
I20260812 06:17:48.611217 27947 log_reader.cc:385] T 15d52d09c3864f4e847d842d4c500a9f: removed 12 log segments from log reader
I20260812 06:17:48.611263 27947 log.cc:1079] T 15d52d09c3864f4e847d842d4c500a9f P 5e96228f5a1b4776a828e10faa8842e4: Deleting log segment in path: /tmp/dist-test-taskdH4ppi/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515466825547-27758-0/minicluster-data/ts-0-root/wals/15d52d09c3864f4e847d842d4c500a9f/wal-000000003 (ops 12-16)
I20260812 06:17:48.611291 27947 log.cc:1079] T 15d52d09c3864f4e847d842d4c500a9f P 5e96228f5a1b4776a828e10faa8842e4: Deleting log segment in path: /tmp/dist-test-taskdH4ppi/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515466825547-27758-0/minicluster-data/ts-0-root/wals/15d52d09c3864f4e847d842d4c500a9f/wal-000000004 (ops 17-21)
I20260812 06:17:48.611321 27947 log.cc:1079] T 15d52d09c3864f4e847d842d4c500a9f P 5e96228f5a1b4776a828e10faa8842e4: Deleting log segment in path: /tmp/dist-test-taskdH4ppi/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515466825547-27758-0/minicluster-data/ts-0-root/wals/15d52d09c3864f4e847d842d4c500a9f/wal-000000005 (ops 22-26)
I20260812 06:17:48.611352 27947 log.cc:1079] T 15d52d09c3864f4e847d842d4c500a9f P 5e96228f5a1b4776a828e10faa8842e4: Deleting log segment in path: /tmp/dist-test-taskdH4ppi/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515466825547-27758-0/minicluster-data/ts-0-root/wals/15d52d09c3864f4e847d842d4c500a9f/wal-000000006 (ops 27-31)
I20260812 06:17:48.611385 27947 log.cc:1079] T 15d52d09c3864f4e847d842d4c500a9f P 5e96228f5a1b4776a828e10faa8842e4: Deleting log segment in path: /tmp/dist-test-taskdH4ppi/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515466825547-27758-0/minicluster-data/ts-0-root/wals/15d52d09c3864f4e847d842d4c500a9f/wal-000000007 (ops 32-36)
I20260812 06:17:48.611428 27947 log.cc:1079] T 15d52d09c3864f4e847d842d4c500a9f P 5e96228f5a1b4776a828e10faa8842e4: Deleting log segment in path: /tmp/dist-test-taskdH4ppi/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515466825547-27758-0/minicluster-data/ts-0-root/wals/15d52d09c3864f4e847d842d4c500a9f/wal-000000008 (ops 37-41)
I20260812 06:17:48.611452 27947 log.cc:1079] T 15d52d09c3864f4e847d842d4c500a9f P 5e96228f5a1b4776a828e10faa8842e4: Deleting log segment in path: /tmp/dist-test-taskdH4ppi/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515466825547-27758-0/minicluster-data/ts-0-root/wals/15d52d09c3864f4e847d842d4c500a9f/wal-000000009 (ops 42-46)
I20260812 06:17:48.611483 27947 log.cc:1079] T 15d52d09c3864f4e847d842d4c500a9f P 5e96228f5a1b4776a828e10faa8842e4: Deleting log segment in path: /tmp/dist-test-taskdH4ppi/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515466825547-27758-0/minicluster-data/ts-0-root/wals/15d52d09c3864f4e847d842d4c500a9f/wal-000000010 (ops 47-51)
I20260812 06:17:48.611515 27947 log.cc:1079] T 15d52d09c3864f4e847d842d4c500a9f P 5e96228f5a1b4776a828e10faa8842e4: Deleting log segment in path: /tmp/dist-test-taskdH4ppi/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515466825547-27758-0/minicluster-data/ts-0-root/wals/15d52d09c3864f4e847d842d4c500a9f/wal-000000011 (ops 52-56)
I20260812 06:17:48.611547 27947 log.cc:1079] T 15d52d09c3864f4e847d842d4c500a9f P 5e96228f5a1b4776a828e10faa8842e4: Deleting log segment in path: /tmp/dist-test-taskdH4ppi/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515466825547-27758-0/minicluster-data/ts-0-root/wals/15d52d09c3864f4e847d842d4c500a9f/wal-000000012 (ops 57-61)
I20260812 06:17:48.611579 27947 log.cc:1079] T 15d52d09c3864f4e847d842d4c500a9f P 5e96228f5a1b4776a828e10faa8842e4: Deleting log segment in path: /tmp/dist-test-taskdH4ppi/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515466825547-27758-0/minicluster-data/ts-0-root/wals/15d52d09c3864f4e847d842d4c500a9f/wal-000000013 (ops 62-66)
I20260812 06:17:48.611610 27947 log.cc:1079] T 15d52d09c3864f4e847d842d4c500a9f P 5e96228f5a1b4776a828e10faa8842e4: Deleting log segment in path: /tmp/dist-test-taskdH4ppi/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515466825547-27758-0/minicluster-data/ts-0-root/wals/15d52d09c3864f4e847d842d4c500a9f/wal-000000014 (ops 67-71)
I20260812 06:17:48.634420 27947 maintenance_manager.cc:643] P 5e96228f5a1b4776a828e10faa8842e4: LogGCOp(15d52d09c3864f4e847d842d4c500a9f) complete. Timing: real 0.023s	user 0.000s	sys 0.023s Metrics: {}
I20260812 06:17:48.634797 28058 maintenance_manager.cc:419] P 5e96228f5a1b4776a828e10faa8842e4: Scheduling UndoDeltaBlockGCOp(15d52d09c3864f4e847d842d4c500a9f): 463 bytes on disk
I20260812 06:17:48.635227 27947 maintenance_manager.cc:643] P 5e96228f5a1b4776a828e10faa8842e4: UndoDeltaBlockGCOp(15d52d09c3864f4e847d842d4c500a9f) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":66,"lbm_reads_lt_1ms":4}
I20260812 06:17:48.635681 28058 maintenance_manager.cc:419] P 5e96228f5a1b4776a828e10faa8842e4: Scheduling FlushDeltaMemStoresOp(15d52d09c3864f4e847d842d4c500a9f): perf score=3.181125
I20260812 06:17:48.653751 27947 maintenance_manager.cc:643] P 5e96228f5a1b4776a828e10faa8842e4: FlushDeltaMemStoresOp(15d52d09c3864f4e847d842d4c500a9f) complete. Timing: real 0.018s	user 0.001s	sys 0.013s Metrics: {"bytes_written":4512903,"delete_count":0,"lbm_write_time_us":4415,"lbm_writes_lt_1ms":113,"reinsert_count":0,"update_count":550}
I20260812 06:17:48.654095 28058 maintenance_manager.cc:419] P 5e96228f5a1b4776a828e10faa8842e4: Scheduling FlushDeltaMemStoresOp(15d52d09c3864f4e847d842d4c500a9f): perf score=2.188937
I20260812 06:17:48.663139 27947 maintenance_manager.cc:643] P 5e96228f5a1b4776a828e10faa8842e4: FlushDeltaMemStoresOp(15d52d09c3864f4e847d842d4c500a9f) complete. Timing: real 0.009s	user 0.003s	sys 0.005s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3474,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:17:48.663518 28058 maintenance_manager.cc:419] P 5e96228f5a1b4776a828e10faa8842e4: Scheduling MajorDeltaCompactionOp(15d52d09c3864f4e847d842d4c500a9f): perf score=1.000000
I20260812 06:17:48.865151 27947 maintenance_manager.cc:643] P 5e96228f5a1b4776a828e10faa8842e4: MajorDeltaCompactionOp(15d52d09c3864f4e847d842d4c500a9f) complete. Timing: real 0.201s	user 0.122s	sys 0.072s Metrics: {"cfile_cache_miss":634,"cfile_cache_miss_bytes":28918324,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":164,"lbm_read_time_us":14401,"lbm_reads_lt_1ms":674,"lbm_write_time_us":34366,"lbm_writes_lt_1ms":643,"mutex_wait_us":56,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":3328,"thread_start_us":70,"threads_started":1,"update_count":3000}
I20260812 06:17:48.865993 28058 maintenance_manager.cc:419] P 5e96228f5a1b4776a828e10faa8842e4: Scheduling FlushDeltaMemStoresOp(15d52d09c3864f4e847d842d4c500a9f): perf score=14.095187
I20260812 06:17:48.927981 27947 maintenance_manager.cc:643] P 5e96228f5a1b4776a828e10faa8842e4: FlushDeltaMemStoresOp(15d52d09c3864f4e847d842d4c500a9f) complete. Timing: real 0.062s	user 0.024s	sys 0.028s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":20170,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:17:48.928507 28058 maintenance_manager.cc:419] P 5e96228f5a1b4776a828e10faa8842e4: Scheduling FlushDeltaMemStoresOp(15d52d09c3864f4e847d842d4c500a9f): perf score=2.188937
I20260812 06:17:48.938544 27947 maintenance_manager.cc:643] P 5e96228f5a1b4776a828e10faa8842e4: FlushDeltaMemStoresOp(15d52d09c3864f4e847d842d4c500a9f) complete. Timing: real 0.010s	user 0.005s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3901,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:48.938984 28058 maintenance_manager.cc:419] P 5e96228f5a1b4776a828e10faa8842e4: Scheduling MajorDeltaCompactionOp(15d52d09c3864f4e847d842d4c500a9f): perf score=1.000000
I20260812 06:17:49.106284 27947 maintenance_manager.cc:643] P 5e96228f5a1b4776a828e10faa8842e4: MajorDeltaCompactionOp(15d52d09c3864f4e847d842d4c500a9f) complete. Timing: real 0.167s	user 0.124s	sys 0.040s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24815683,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":655,"lbm_read_time_us":11404,"lbm_reads_lt_1ms":572,"lbm_write_time_us":27366,"lbm_writes_lt_1ms":543,"mutex_wait_us":301,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":1792,"update_count":2500}
I20260812 06:17:49.106834 28058 maintenance_manager.cc:419] P 5e96228f5a1b4776a828e10faa8842e4: Scheduling FlushDeltaMemStoresOp(15d52d09c3864f4e847d842d4c500a9f): perf score=11.118625
I20260812 06:17:49.142746 27947 maintenance_manager.cc:643] P 5e96228f5a1b4776a828e10faa8842e4: FlushDeltaMemStoresOp(15d52d09c3864f4e847d842d4c500a9f) complete. Timing: real 0.036s	user 0.023s	sys 0.012s Metrics: {"bytes_written":12717735,"delete_count":0,"lbm_write_time_us":15062,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:17:49.143230 28058 maintenance_manager.cc:419] P 5e96228f5a1b4776a828e10faa8842e4: Scheduling FlushDeltaMemStoresOp(15d52d09c3864f4e847d842d4c500a9f): perf score=2.188937
I20260812 06:17:49.166049 27947 maintenance_manager.cc:643] P 5e96228f5a1b4776a828e10faa8842e4: FlushDeltaMemStoresOp(15d52d09c3864f4e847d842d4c500a9f) complete. Timing: real 0.023s	user 0.009s	sys 0.004s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":4911,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:17:49.166529 28058 maintenance_manager.cc:419] P 5e96228f5a1b4776a828e10faa8842e4: Scheduling FlushDeltaMemStoresOp(15d52d09c3864f4e847d842d4c500a9f): perf score=2.188937
I20260812 06:17:49.188637 27947 maintenance_manager.cc:643] P 5e96228f5a1b4776a828e10faa8842e4: FlushDeltaMemStoresOp(15d52d09c3864f4e847d842d4c500a9f) complete. Timing: real 0.022s	user 0.004s	sys 0.015s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":5270,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:49.189070 28058 maintenance_manager.cc:419] P 5e96228f5a1b4776a828e10faa8842e4: Scheduling MajorDeltaCompactionOp(15d52d09c3864f4e847d842d4c500a9f): perf score=1.000000
I20260812 06:17:49.362115 27947 maintenance_manager.cc:643] P 5e96228f5a1b4776a828e10faa8842e4: MajorDeltaCompactionOp(15d52d09c3864f4e847d842d4c500a9f) complete. Timing: real 0.173s	user 0.115s	sys 0.056s Metrics: {"cfile_cache_miss":533,"cfile_cache_miss_bytes":24815793,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":550,"lbm_read_time_us":12176,"lbm_reads_lt_1ms":573,"lbm_write_time_us":29476,"lbm_writes_lt_1ms":543,"mutex_wait_us":296,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":4608,"update_count":2500}
I20260812 06:17:49.362671 28058 maintenance_manager.cc:419] P 5e96228f5a1b4776a828e10faa8842e4: Scheduling FlushDeltaMemStoresOp(15d52d09c3864f4e847d842d4c500a9f): perf score=11.118625
I20260812 06:17:49.397504 27947 maintenance_manager.cc:643] P 5e96228f5a1b4776a828e10faa8842e4: FlushDeltaMemStoresOp(15d52d09c3864f4e847d842d4c500a9f) complete. Timing: real 0.035s	user 0.022s	sys 0.008s Metrics: {"bytes_written":12717735,"delete_count":0,"lbm_write_time_us":14342,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:17:49.398108 28058 maintenance_manager.cc:419] P 5e96228f5a1b4776a828e10faa8842e4: Scheduling FlushDeltaMemStoresOp(15d52d09c3864f4e847d842d4c500a9f): perf score=2.188937
I20260812 06:17:49.422565 27947 maintenance_manager.cc:643] P 5e96228f5a1b4776a828e10faa8842e4: FlushDeltaMemStoresOp(15d52d09c3864f4e847d842d4c500a9f) complete. Timing: real 0.024s	user 0.012s	sys 0.001s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":5017,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:17:49.423039 28058 maintenance_manager.cc:419] P 5e96228f5a1b4776a828e10faa8842e4: Scheduling FlushDeltaMemStoresOp(15d52d09c3864f4e847d842d4c500a9f): perf score=2.188937
I20260812 06:17:49.437278 27947 maintenance_manager.cc:643] P 5e96228f5a1b4776a828e10faa8842e4: FlushDeltaMemStoresOp(15d52d09c3864f4e847d842d4c500a9f) complete. Timing: real 0.014s	user 0.008s	sys 0.003s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":5343,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:49.437703 28058 maintenance_manager.cc:419] P 5e96228f5a1b4776a828e10faa8842e4: Scheduling MajorDeltaCompactionOp(15d52d09c3864f4e847d842d4c500a9f): perf score=1.000000
I20260812 06:17:49.615890 27947 maintenance_manager.cc:643] P 5e96228f5a1b4776a828e10faa8842e4: MajorDeltaCompactionOp(15d52d09c3864f4e847d842d4c500a9f) complete. Timing: real 0.178s	user 0.124s	sys 0.051s Metrics: {"cfile_cache_miss":533,"cfile_cache_miss_bytes":24815793,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":604,"lbm_read_time_us":11859,"lbm_reads_lt_1ms":573,"lbm_write_time_us":28370,"lbm_writes_lt_1ms":543,"mutex_wait_us":287,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":17408,"update_count":2500}
I20260812 06:17:49.616441 28058 maintenance_manager.cc:419] P 5e96228f5a1b4776a828e10faa8842e4: Scheduling FlushDeltaMemStoresOp(15d52d09c3864f4e847d842d4c500a9f): perf score=11.118625
I20260812 06:17:49.655279 27947 maintenance_manager.cc:643] P 5e96228f5a1b4776a828e10faa8842e4: FlushDeltaMemStoresOp(15d52d09c3864f4e847d842d4c500a9f) complete. Timing: real 0.039s	user 0.022s	sys 0.015s Metrics: {"bytes_written":12717735,"delete_count":0,"lbm_write_time_us":15639,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:17:49.655799 28058 maintenance_manager.cc:419] P 5e96228f5a1b4776a828e10faa8842e4: Scheduling FlushDeltaMemStoresOp(15d52d09c3864f4e847d842d4c500a9f): perf score=2.188937
I20260812 06:17:49.671603 27947 maintenance_manager.cc:643] P 5e96228f5a1b4776a828e10faa8842e4: FlushDeltaMemStoresOp(15d52d09c3864f4e847d842d4c500a9f) complete. Timing: real 0.015s	user 0.004s	sys 0.004s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3762,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:17:49.672019 28058 maintenance_manager.cc:419] P 5e96228f5a1b4776a828e10faa8842e4: Scheduling FlushDeltaMemStoresOp(15d52d09c3864f4e847d842d4c500a9f): perf score=2.188937
I20260812 06:17:49.681720 27947 maintenance_manager.cc:643] P 5e96228f5a1b4776a828e10faa8842e4: FlushDeltaMemStoresOp(15d52d09c3864f4e847d842d4c500a9f) complete. Timing: real 0.010s	user 0.007s	sys 0.001s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3747,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:49.682114 28058 maintenance_manager.cc:419] P 5e96228f5a1b4776a828e10faa8842e4: Scheduling MajorDeltaCompactionOp(15d52d09c3864f4e847d842d4c500a9f): perf score=1.000000
I20260812 06:17:49.823093 27947 maintenance_manager.cc:643] P 5e96228f5a1b4776a828e10faa8842e4: MajorDeltaCompactionOp(15d52d09c3864f4e847d842d4c500a9f) complete. Timing: real 0.141s	user 0.121s	sys 0.017s Metrics: {"cfile_cache_miss":533,"cfile_cache_miss_bytes":24815794,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":223,"lbm_read_time_us":11329,"lbm_reads_lt_1ms":573,"lbm_write_time_us":26043,"lbm_writes_lt_1ms":543,"peak_mem_usage":63115900,"reinsert_count":0,"update_count":2500}
I20260812 06:17:49.823614 28058 maintenance_manager.cc:419] P 5e96228f5a1b4776a828e10faa8842e4: Scheduling FlushDeltaMemStoresOp(15d52d09c3864f4e847d842d4c500a9f): perf score=11.118625
I20260812 06:17:49.869004 27947 maintenance_manager.cc:643] P 5e96228f5a1b4776a828e10faa8842e4: FlushDeltaMemStoresOp(15d52d09c3864f4e847d842d4c500a9f) complete. Timing: real 0.045s	user 0.018s	sys 0.021s Metrics: {"bytes_written":12717735,"delete_count":0,"lbm_write_time_us":18852,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":312,"reinsert_count":0,"update_count":1550}
I20260812 06:17:49.869524 28058 maintenance_manager.cc:419] P 5e96228f5a1b4776a828e10faa8842e4: Scheduling FlushDeltaMemStoresOp(15d52d09c3864f4e847d842d4c500a9f): perf score=2.188937
I20260812 06:17:49.885676 27947 maintenance_manager.cc:643] P 5e96228f5a1b4776a828e10faa8842e4: FlushDeltaMemStoresOp(15d52d09c3864f4e847d842d4c500a9f) complete. Timing: real 0.016s	user 0.010s	sys 0.003s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6129,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:49.886085 28058 maintenance_manager.cc:419] P 5e96228f5a1b4776a828e10faa8842e4: Scheduling FlushDeltaMemStoresOp(15d52d09c3864f4e847d842d4c500a9f): perf score=2.188937
I20260812 06:17:49.894769 27947 maintenance_manager.cc:643] P 5e96228f5a1b4776a828e10faa8842e4: FlushDeltaMemStoresOp(15d52d09c3864f4e847d842d4c500a9f) complete. Timing: real 0.009s	user 0.003s	sys 0.005s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3315,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:17:49.895130 28058 maintenance_manager.cc:419] P 5e96228f5a1b4776a828e10faa8842e4: Scheduling MajorDeltaCompactionOp(15d52d09c3864f4e847d842d4c500a9f): perf score=1.000000
I20260812 06:17:50.037014 27947 maintenance_manager.cc:643] P 5e96228f5a1b4776a828e10faa8842e4: MajorDeltaCompactionOp(15d52d09c3864f4e847d842d4c500a9f) complete. Timing: real 0.142s	user 0.106s	sys 0.032s Metrics: {"cfile_cache_miss":533,"cfile_cache_miss_bytes":24815794,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":960,"lbm_read_time_us":10935,"lbm_reads_lt_1ms":573,"lbm_write_time_us":25306,"lbm_writes_lt_1ms":543,"mutex_wait_us":332,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":1664,"update_count":2500}
I20260812 06:17:50.037746 28058 maintenance_manager.cc:419] P 5e96228f5a1b4776a828e10faa8842e4: Scheduling FlushDeltaMemStoresOp(15d52d09c3864f4e847d842d4c500a9f): perf score=11.118625
I20260812 06:17:50.068670 27947 maintenance_manager.cc:643] P 5e96228f5a1b4776a828e10faa8842e4: FlushDeltaMemStoresOp(15d52d09c3864f4e847d842d4c500a9f) complete. Timing: real 0.031s	user 0.014s	sys 0.013s Metrics: {"bytes_written":12717735,"delete_count":0,"lbm_write_time_us":12655,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:17:50.069361 28058 maintenance_manager.cc:419] P 5e96228f5a1b4776a828e10faa8842e4: Scheduling FlushDeltaMemStoresOp(15d52d09c3864f4e847d842d4c500a9f): perf score=2.188937
I20260812 06:17:50.090512 27947 maintenance_manager.cc:643] P 5e96228f5a1b4776a828e10faa8842e4: FlushDeltaMemStoresOp(15d52d09c3864f4e847d842d4c500a9f) complete. Timing: real 0.021s	user 0.000s	sys 0.010s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":4237,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:17:50.091032 28058 maintenance_manager.cc:419] P 5e96228f5a1b4776a828e10faa8842e4: Scheduling FlushDeltaMemStoresOp(15d52d09c3864f4e847d842d4c500a9f): perf score=2.188937
I20260812 06:17:50.101311 27947 maintenance_manager.cc:643] P 5e96228f5a1b4776a828e10faa8842e4: FlushDeltaMemStoresOp(15d52d09c3864f4e847d842d4c500a9f) complete. Timing: real 0.010s	user 0.008s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4015,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:50.101717 28058 maintenance_manager.cc:419] P 5e96228f5a1b4776a828e10faa8842e4: Scheduling FlushMRSOp(15d52d09c3864f4e847d842d4c500a9f): perf score=1.000000
I20260812 06:17:50.135764 27947 maintenance_manager.cc:643] P 5e96228f5a1b4776a828e10faa8842e4: FlushMRSOp(15d52d09c3864f4e847d842d4c500a9f) complete. Timing: real 0.034s	user 0.030s	sys 0.003s Metrics: {"bytes_written":1316419,"cfile_init":1,"dirs.queue_time_us":77,"dirs.run_cpu_time_us":213,"dirs.run_wall_time_us":1158,"drs_written":1,"lbm_read_time_us":39,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1715,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":32}
I20260812 06:17:50.136426 28058 maintenance_manager.cc:419] P 5e96228f5a1b4776a828e10faa8842e4: Scheduling LogGCOp(15d52d09c3864f4e847d842d4c500a9f): free 124710258 bytes of WAL
I20260812 06:17:50.136641 27947 log_reader.cc:385] T 15d52d09c3864f4e847d842d4c500a9f: removed 12 log segments from log reader
I20260812 06:17:50.136687 27947 log.cc:1079] T 15d52d09c3864f4e847d842d4c500a9f P 5e96228f5a1b4776a828e10faa8842e4: Deleting log segment in path: /tmp/dist-test-taskdH4ppi/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515466825547-27758-0/minicluster-data/ts-0-root/wals/15d52d09c3864f4e847d842d4c500a9f/wal-000000015 (ops 72-76)
I20260812 06:17:50.136716 27947 log.cc:1079] T 15d52d09c3864f4e847d842d4c500a9f P 5e96228f5a1b4776a828e10faa8842e4: Deleting log segment in path: /tmp/dist-test-taskdH4ppi/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515466825547-27758-0/minicluster-data/ts-0-root/wals/15d52d09c3864f4e847d842d4c500a9f/wal-000000016 (ops 77-81)
I20260812 06:17:50.136749 27947 log.cc:1079] T 15d52d09c3864f4e847d842d4c500a9f P 5e96228f5a1b4776a828e10faa8842e4: Deleting log segment in path: /tmp/dist-test-taskdH4ppi/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515466825547-27758-0/minicluster-data/ts-0-root/wals/15d52d09c3864f4e847d842d4c500a9f/wal-000000017 (ops 82-86)
I20260812 06:17:50.136782 27947 log.cc:1079] T 15d52d09c3864f4e847d842d4c500a9f P 5e96228f5a1b4776a828e10faa8842e4: Deleting log segment in path: /tmp/dist-test-taskdH4ppi/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515466825547-27758-0/minicluster-data/ts-0-root/wals/15d52d09c3864f4e847d842d4c500a9f/wal-000000018 (ops 87-91)
I20260812 06:17:50.136816 27947 log.cc:1079] T 15d52d09c3864f4e847d842d4c500a9f P 5e96228f5a1b4776a828e10faa8842e4: Deleting log segment in path: /tmp/dist-test-taskdH4ppi/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515466825547-27758-0/minicluster-data/ts-0-root/wals/15d52d09c3864f4e847d842d4c500a9f/wal-000000019 (ops 92-96)
I20260812 06:17:50.136848 27947 log.cc:1079] T 15d52d09c3864f4e847d842d4c500a9f P 5e96228f5a1b4776a828e10faa8842e4: Deleting log segment in path: /tmp/dist-test-taskdH4ppi/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515466825547-27758-0/minicluster-data/ts-0-root/wals/15d52d09c3864f4e847d842d4c500a9f/wal-000000020 (ops 97-101)
I20260812 06:17:50.136880 27947 log.cc:1079] T 15d52d09c3864f4e847d842d4c500a9f P 5e96228f5a1b4776a828e10faa8842e4: Deleting log segment in path: /tmp/dist-test-taskdH4ppi/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515466825547-27758-0/minicluster-data/ts-0-root/wals/15d52d09c3864f4e847d842d4c500a9f/wal-000000021 (ops 102-106)
I20260812 06:17:50.136914 27947 log.cc:1079] T 15d52d09c3864f4e847d842d4c500a9f P 5e96228f5a1b4776a828e10faa8842e4: Deleting log segment in path: /tmp/dist-test-taskdH4ppi/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515466825547-27758-0/minicluster-data/ts-0-root/wals/15d52d09c3864f4e847d842d4c500a9f/wal-000000022 (ops 107-111)
I20260812 06:17:50.136945 27947 log.cc:1079] T 15d52d09c3864f4e847d842d4c500a9f P 5e96228f5a1b4776a828e10faa8842e4: Deleting log segment in path: /tmp/dist-test-taskdH4ppi/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515466825547-27758-0/minicluster-data/ts-0-root/wals/15d52d09c3864f4e847d842d4c500a9f/wal-000000023 (ops 112-116)
I20260812 06:17:50.136986 27947 log.cc:1079] T 15d52d09c3864f4e847d842d4c500a9f P 5e96228f5a1b4776a828e10faa8842e4: Deleting log segment in path: /tmp/dist-test-taskdH4ppi/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515466825547-27758-0/minicluster-data/ts-0-root/wals/15d52d09c3864f4e847d842d4c500a9f/wal-000000024 (ops 117-121)
I20260812 06:17:50.137017 27947 log.cc:1079] T 15d52d09c3864f4e847d842d4c500a9f P 5e96228f5a1b4776a828e10faa8842e4: Deleting log segment in path: /tmp/dist-test-taskdH4ppi/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515466825547-27758-0/minicluster-data/ts-0-root/wals/15d52d09c3864f4e847d842d4c500a9f/wal-000000025 (ops 122-126)
I20260812 06:17:50.137050 27947 log.cc:1079] T 15d52d09c3864f4e847d842d4c500a9f P 5e96228f5a1b4776a828e10faa8842e4: Deleting log segment in path: /tmp/dist-test-taskdH4ppi/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515466825547-27758-0/minicluster-data/ts-0-root/wals/15d52d09c3864f4e847d842d4c500a9f/wal-000000026 (ops 127-131)
I20260812 06:17:50.159760 27947 maintenance_manager.cc:643] P 5e96228f5a1b4776a828e10faa8842e4: LogGCOp(15d52d09c3864f4e847d842d4c500a9f) complete. Timing: real 0.023s	user 0.000s	sys 0.021s Metrics: {}
I20260812 06:17:50.160175 28058 maintenance_manager.cc:419] P 5e96228f5a1b4776a828e10faa8842e4: Scheduling UndoDeltaBlockGCOp(15d52d09c3864f4e847d842d4c500a9f): 492 bytes on disk
I20260812 06:17:50.160599 27947 maintenance_manager.cc:643] P 5e96228f5a1b4776a828e10faa8842e4: UndoDeltaBlockGCOp(15d52d09c3864f4e847d842d4c500a9f) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":51,"lbm_reads_lt_1ms":4}
I20260812 06:17:50.161176 28058 maintenance_manager.cc:419] P 5e96228f5a1b4776a828e10faa8842e4: Scheduling FlushDeltaMemStoresOp(15d52d09c3864f4e847d842d4c500a9f): perf score=3.181125
I20260812 06:17:50.173023 27947 maintenance_manager.cc:643] P 5e96228f5a1b4776a828e10faa8842e4: FlushDeltaMemStoresOp(15d52d09c3864f4e847d842d4c500a9f) complete. Timing: real 0.012s	user 0.003s	sys 0.007s Metrics: {"bytes_written":4635981,"delete_count":0,"lbm_write_time_us":4789,"lbm_writes_lt_1ms":116,"reinsert_count":0,"update_count":565}
I20260812 06:17:50.173413 28058 maintenance_manager.cc:419] P 5e96228f5a1b4776a828e10faa8842e4: Scheduling FlushDeltaMemStoresOp(15d52d09c3864f4e847d842d4c500a9f): perf score=2.188937
I20260812 06:17:50.190771 27947 maintenance_manager.cc:643] P 5e96228f5a1b4776a828e10faa8842e4: FlushDeltaMemStoresOp(15d52d09c3864f4e847d842d4c500a9f) complete. Timing: real 0.017s	user 0.006s	sys 0.011s Metrics: {"bytes_written":3569330,"delete_count":0,"lbm_write_time_us":3348,"lbm_writes_lt_1ms":90,"reinsert_count":0,"update_count":435}
I20260812 06:17:50.191202 28058 maintenance_manager.cc:419] P 5e96228f5a1b4776a828e10faa8842e4: Scheduling MajorDeltaCompactionOp(15d52d09c3864f4e847d842d4c500a9f): perf score=1.000000
I20260812 06:17:50.420480 27947 maintenance_manager.cc:643] P 5e96228f5a1b4776a828e10faa8842e4: MajorDeltaCompactionOp(15d52d09c3864f4e847d842d4c500a9f) complete. Timing: real 0.229s	user 0.172s	sys 0.056s Metrics: {"cfile_cache_miss":735,"cfile_cache_miss_bytes":33020849,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":5,"delta_iterators_relevant":5,"dirs.queue_time_us":308,"lbm_read_time_us":16387,"lbm_reads_lt_1ms":775,"lbm_write_time_us":40410,"lbm_writes_lt_1ms":743,"peak_mem_usage":87969044,"reinsert_count":0,"spinlock_wait_cycles":14464,"thread_start_us":107,"threads_started":1,"update_count":3500}
I20260812 06:17:50.421283 28058 maintenance_manager.cc:419] P 5e96228f5a1b4776a828e10faa8842e4: Scheduling FlushDeltaMemStoresOp(15d52d09c3864f4e847d842d4c500a9f): perf score=14.095187
I20260812 06:17:50.476534 27947 maintenance_manager.cc:643] P 5e96228f5a1b4776a828e10faa8842e4: FlushDeltaMemStoresOp(15d52d09c3864f4e847d842d4c500a9f) complete. Timing: real 0.055s	user 0.026s	sys 0.026s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":20256,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:17:50.477046 28058 maintenance_manager.cc:419] P 5e96228f5a1b4776a828e10faa8842e4: Scheduling FlushDeltaMemStoresOp(15d52d09c3864f4e847d842d4c500a9f): perf score=2.188937
I20260812 06:17:50.487128 27947 maintenance_manager.cc:643] P 5e96228f5a1b4776a828e10faa8842e4: FlushDeltaMemStoresOp(15d52d09c3864f4e847d842d4c500a9f) complete. Timing: real 0.010s	user 0.009s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3833,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:50.487506 28058 maintenance_manager.cc:419] P 5e96228f5a1b4776a828e10faa8842e4: Scheduling MajorDeltaCompactionOp(15d52d09c3864f4e847d842d4c500a9f): perf score=1.000000
I20260812 06:17:50.657655 27947 maintenance_manager.cc:643] P 5e96228f5a1b4776a828e10faa8842e4: MajorDeltaCompactionOp(15d52d09c3864f4e847d842d4c500a9f) complete. Timing: real 0.170s	user 0.106s	sys 0.056s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24815683,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":263,"lbm_read_time_us":13227,"lbm_reads_lt_1ms":572,"lbm_write_time_us":26001,"lbm_writes_lt_1ms":543,"mutex_wait_us":45,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":4864,"update_count":2500}
I20260812 06:17:50.658187 28058 maintenance_manager.cc:419] P 5e96228f5a1b4776a828e10faa8842e4: Scheduling FlushDeltaMemStoresOp(15d52d09c3864f4e847d842d4c500a9f): perf score=14.095187
I20260812 06:17:50.719596 27947 maintenance_manager.cc:643] P 5e96228f5a1b4776a828e10faa8842e4: FlushDeltaMemStoresOp(15d52d09c3864f4e847d842d4c500a9f) complete. Timing: real 0.061s	user 0.035s	sys 0.020s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":22476,"lbm_writes_lt_1ms":403,"mutex_wait_us":2,"reinsert_count":0,"update_count":2000}
I20260812 06:17:50.720036 28058 maintenance_manager.cc:419] P 5e96228f5a1b4776a828e10faa8842e4: Scheduling FlushDeltaMemStoresOp(15d52d09c3864f4e847d842d4c500a9f): perf score=2.188937
I20260812 06:17:50.729955 27947 maintenance_manager.cc:643] P 5e96228f5a1b4776a828e10faa8842e4: FlushDeltaMemStoresOp(15d52d09c3864f4e847d842d4c500a9f) complete. Timing: real 0.010s	user 0.005s	sys 0.005s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3930,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:50.730340 28058 maintenance_manager.cc:419] P 5e96228f5a1b4776a828e10faa8842e4: Scheduling MajorDeltaCompactionOp(15d52d09c3864f4e847d842d4c500a9f): perf score=1.000000
I20260812 06:17:50.888312 27947 maintenance_manager.cc:643] P 5e96228f5a1b4776a828e10faa8842e4: MajorDeltaCompactionOp(15d52d09c3864f4e847d842d4c500a9f) complete. Timing: real 0.158s	user 0.097s	sys 0.060s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24815684,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":482,"lbm_read_time_us":12670,"lbm_reads_lt_1ms":572,"lbm_write_time_us":28259,"lbm_writes_lt_1ms":543,"mutex_wait_us":53,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":12288,"update_count":2500}
I20260812 06:17:50.891117 28058 maintenance_manager.cc:419] P 5e96228f5a1b4776a828e10faa8842e4: Scheduling FlushDeltaMemStoresOp(15d52d09c3864f4e847d842d4c500a9f): perf score=10.126437
I20260812 06:17:50.926885 27947 maintenance_manager.cc:643] P 5e96228f5a1b4776a828e10faa8842e4: FlushDeltaMemStoresOp(15d52d09c3864f4e847d842d4c500a9f) complete. Timing: real 0.036s	user 0.011s	sys 0.024s Metrics: {"bytes_written":12307491,"delete_count":0,"lbm_write_time_us":15421,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:17:50.927429 28058 maintenance_manager.cc:419] P 5e96228f5a1b4776a828e10faa8842e4: Scheduling FlushDeltaMemStoresOp(15d52d09c3864f4e847d842d4c500a9f): perf score=2.188937
I20260812 06:17:50.951354 27947 maintenance_manager.cc:643] P 5e96228f5a1b4776a828e10faa8842e4: FlushDeltaMemStoresOp(15d52d09c3864f4e847d842d4c500a9f) complete. Timing: real 0.024s	user 0.008s	sys 0.004s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":5327,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:50.951817 28058 maintenance_manager.cc:419] P 5e96228f5a1b4776a828e10faa8842e4: Scheduling FlushDeltaMemStoresOp(15d52d09c3864f4e847d842d4c500a9f): perf score=2.188937
I20260812 06:17:50.969779 27947 maintenance_manager.cc:643] P 5e96228f5a1b4776a828e10faa8842e4: FlushDeltaMemStoresOp(15d52d09c3864f4e847d842d4c500a9f) complete. Timing: real 0.018s	user 0.005s	sys 0.009s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":3887,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:50.970253 28058 maintenance_manager.cc:419] P 5e96228f5a1b4776a828e10faa8842e4: Scheduling MajorDeltaCompactionOp(15d52d09c3864f4e847d842d4c500a9f): perf score=1.000000
I20260812 06:17:51.151525 27947 maintenance_manager.cc:643] P 5e96228f5a1b4776a828e10faa8842e4: MajorDeltaCompactionOp(15d52d09c3864f4e847d842d4c500a9f) complete. Timing: real 0.181s	user 0.119s	sys 0.060s Metrics: {"cfile_cache_miss":533,"cfile_cache_miss_bytes":24815802,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":278,"lbm_read_time_us":11625,"lbm_reads_lt_1ms":573,"lbm_write_time_us":32984,"lbm_writes_lt_1ms":543,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":41472,"update_count":2500}
I20260812 06:17:51.152081 28058 maintenance_manager.cc:419] P 5e96228f5a1b4776a828e10faa8842e4: Scheduling FlushDeltaMemStoresOp(15d52d09c3864f4e847d842d4c500a9f): perf score=11.118625
I20260812 06:17:51.194644 27947 maintenance_manager.cc:643] P 5e96228f5a1b4776a828e10faa8842e4: FlushDeltaMemStoresOp(15d52d09c3864f4e847d842d4c500a9f) complete. Timing: real 0.042s	user 0.033s	sys 0.000s Metrics: {"bytes_written":12717735,"delete_count":0,"lbm_write_time_us":14582,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:17:51.195281 28058 maintenance_manager.cc:419] P 5e96228f5a1b4776a828e10faa8842e4: Scheduling FlushDeltaMemStoresOp(15d52d09c3864f4e847d842d4c500a9f): perf score=2.188937
I20260812 06:17:51.212323 27947 maintenance_manager.cc:643] P 5e96228f5a1b4776a828e10faa8842e4: FlushDeltaMemStoresOp(15d52d09c3864f4e847d842d4c500a9f) complete. Timing: real 0.017s	user 0.005s	sys 0.003s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3820,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:51.212796 28058 maintenance_manager.cc:419] P 5e96228f5a1b4776a828e10faa8842e4: Scheduling FlushDeltaMemStoresOp(15d52d09c3864f4e847d842d4c500a9f): perf score=2.188937
I20260812 06:17:51.226081 27947 maintenance_manager.cc:643] P 5e96228f5a1b4776a828e10faa8842e4: FlushDeltaMemStoresOp(15d52d09c3864f4e847d842d4c500a9f) complete. Timing: real 0.013s	user 0.009s	sys 0.004s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":4952,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:17:51.226584 28058 maintenance_manager.cc:419] P 5e96228f5a1b4776a828e10faa8842e4: Scheduling MajorDeltaCompactionOp(15d52d09c3864f4e847d842d4c500a9f): perf score=1.000000
I20260812 06:17:51.403366 27947 maintenance_manager.cc:643] P 5e96228f5a1b4776a828e10faa8842e4: MajorDeltaCompactionOp(15d52d09c3864f4e847d842d4c500a9f) complete. Timing: real 0.177s	user 0.127s	sys 0.036s Metrics: {"cfile_cache_miss":533,"cfile_cache_miss_bytes":24815794,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":934,"lbm_read_time_us":9774,"lbm_reads_lt_1ms":573,"lbm_write_time_us":27967,"lbm_writes_lt_1ms":543,"mutex_wait_us":27,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":12288,"update_count":2500}
I20260812 06:17:51.403896 28058 maintenance_manager.cc:419] P 5e96228f5a1b4776a828e10faa8842e4: Scheduling FlushDeltaMemStoresOp(15d52d09c3864f4e847d842d4c500a9f): perf score=14.095187
I20260812 06:17:51.462529 27947 maintenance_manager.cc:643] P 5e96228f5a1b4776a828e10faa8842e4: FlushDeltaMemStoresOp(15d52d09c3864f4e847d842d4c500a9f) complete. Timing: real 0.058s	user 0.018s	sys 0.039s Metrics: {"bytes_written":16409898,"delete_count":0,"lbm_write_time_us":27713,"lbm_writes_1-10_ms":2,"lbm_writes_lt_1ms":401,"reinsert_count":0,"update_count":2000}
I20260812 06:17:51.463057 28058 maintenance_manager.cc:419] P 5e96228f5a1b4776a828e10faa8842e4: Scheduling FlushDeltaMemStoresOp(15d52d09c3864f4e847d842d4c500a9f): perf score=2.188937
I20260812 06:17:51.474578 27947 maintenance_manager.cc:643] P 5e96228f5a1b4776a828e10faa8842e4: FlushDeltaMemStoresOp(15d52d09c3864f4e847d842d4c500a9f) complete. Timing: real 0.011s	user 0.006s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4404,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:51.475287 28058 maintenance_manager.cc:419] P 5e96228f5a1b4776a828e10faa8842e4: Scheduling MajorDeltaCompactionOp(15d52d09c3864f4e847d842d4c500a9f): perf score=1.000000
I20260812 06:17:51.622825 27947 maintenance_manager.cc:643] P 5e96228f5a1b4776a828e10faa8842e4: MajorDeltaCompactionOp(15d52d09c3864f4e847d842d4c500a9f) complete. Timing: real 0.147s	user 0.123s	sys 0.023s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24815680,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":1081,"lbm_read_time_us":10499,"lbm_reads_lt_1ms":572,"lbm_write_time_us":28953,"lbm_writes_lt_1ms":543,"mutex_wait_us":245,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":896,"update_count":2500}
I20260812 06:17:51.623421 28058 maintenance_manager.cc:419] P 5e96228f5a1b4776a828e10faa8842e4: Scheduling FlushDeltaMemStoresOp(15d52d09c3864f4e847d842d4c500a9f): perf score=11.118625
I20260812 06:17:51.660439 27947 maintenance_manager.cc:643] P 5e96228f5a1b4776a828e10faa8842e4: FlushDeltaMemStoresOp(15d52d09c3864f4e847d842d4c500a9f) complete. Timing: real 0.037s	user 0.022s	sys 0.012s Metrics: {"bytes_written":12717735,"delete_count":0,"lbm_write_time_us":16137,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:17:51.660951 28058 maintenance_manager.cc:419] P 5e96228f5a1b4776a828e10faa8842e4: Scheduling FlushDeltaMemStoresOp(15d52d09c3864f4e847d842d4c500a9f): perf score=2.188937
I20260812 06:17:51.681394 27947 maintenance_manager.cc:643] P 5e96228f5a1b4776a828e10faa8842e4: FlushDeltaMemStoresOp(15d52d09c3864f4e847d842d4c500a9f) complete. Timing: real 0.020s	user 0.006s	sys 0.003s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":4278,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:17:51.681872 28058 maintenance_manager.cc:419] P 5e96228f5a1b4776a828e10faa8842e4: Scheduling FlushDeltaMemStoresOp(15d52d09c3864f4e847d842d4c500a9f): perf score=2.188937
I20260812 06:17:51.691314 27947 maintenance_manager.cc:643] P 5e96228f5a1b4776a828e10faa8842e4: FlushDeltaMemStoresOp(15d52d09c3864f4e847d842d4c500a9f) complete. Timing: real 0.009s	user 0.003s	sys 0.005s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3606,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:51.691776 28058 maintenance_manager.cc:419] P 5e96228f5a1b4776a828e10faa8842e4: Scheduling FlushMRSOp(15d52d09c3864f4e847d842d4c500a9f): perf score=1.000000
I20260812 06:17:51.726226 27947 maintenance_manager.cc:643] P 5e96228f5a1b4776a828e10faa8842e4: FlushMRSOp(15d52d09c3864f4e847d842d4c500a9f) complete. Timing: real 0.034s	user 0.030s	sys 0.004s Metrics: {"bytes_written":1316417,"cfile_init":1,"dirs.queue_time_us":56,"dirs.run_cpu_time_us":211,"dirs.run_wall_time_us":1045,"drs_written":1,"lbm_read_time_us":41,"lbm_reads_lt_1ms":4,"lbm_write_time_us":2232,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":32}
I20260812 06:17:51.727092 28058 maintenance_manager.cc:419] P 5e96228f5a1b4776a828e10faa8842e4: Scheduling LogGCOp(15d52d09c3864f4e847d842d4c500a9f): free 133024706 bytes of WAL
I20260812 06:17:51.727329 27947 log_reader.cc:385] T 15d52d09c3864f4e847d842d4c500a9f: removed 13 log segments from log reader
I20260812 06:17:51.727377 27947 log.cc:1079] T 15d52d09c3864f4e847d842d4c500a9f P 5e96228f5a1b4776a828e10faa8842e4: Deleting log segment in path: /tmp/dist-test-taskdH4ppi/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515466825547-27758-0/minicluster-data/ts-0-root/wals/15d52d09c3864f4e847d842d4c500a9f/wal-000000027 (ops 132-136)
I20260812 06:17:51.727406 27947 log.cc:1079] T 15d52d09c3864f4e847d842d4c500a9f P 5e96228f5a1b4776a828e10faa8842e4: Deleting log segment in path: /tmp/dist-test-taskdH4ppi/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515466825547-27758-0/minicluster-data/ts-0-root/wals/15d52d09c3864f4e847d842d4c500a9f/wal-000000028 (ops 137-141)
I20260812 06:17:51.727424 27947 log.cc:1079] T 15d52d09c3864f4e847d842d4c500a9f P 5e96228f5a1b4776a828e10faa8842e4: Deleting log segment in path: /tmp/dist-test-taskdH4ppi/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515466825547-27758-0/minicluster-data/ts-0-root/wals/15d52d09c3864f4e847d842d4c500a9f/wal-000000029 (ops 142-146)
I20260812 06:17:51.727456 27947 log.cc:1079] T 15d52d09c3864f4e847d842d4c500a9f P 5e96228f5a1b4776a828e10faa8842e4: Deleting log segment in path: /tmp/dist-test-taskdH4ppi/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515466825547-27758-0/minicluster-data/ts-0-root/wals/15d52d09c3864f4e847d842d4c500a9f/wal-000000030 (ops 147-151)
I20260812 06:17:51.727488 27947 log.cc:1079] T 15d52d09c3864f4e847d842d4c500a9f P 5e96228f5a1b4776a828e10faa8842e4: Deleting log segment in path: /tmp/dist-test-taskdH4ppi/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515466825547-27758-0/minicluster-data/ts-0-root/wals/15d52d09c3864f4e847d842d4c500a9f/wal-000000031 (ops 152-156)
I20260812 06:17:51.727533 27947 log.cc:1079] T 15d52d09c3864f4e847d842d4c500a9f P 5e96228f5a1b4776a828e10faa8842e4: Deleting log segment in path: /tmp/dist-test-taskdH4ppi/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515466825547-27758-0/minicluster-data/ts-0-root/wals/15d52d09c3864f4e847d842d4c500a9f/wal-000000032 (ops 157-161)
I20260812 06:17:51.727557 27947 log.cc:1079] T 15d52d09c3864f4e847d842d4c500a9f P 5e96228f5a1b4776a828e10faa8842e4: Deleting log segment in path: /tmp/dist-test-taskdH4ppi/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515466825547-27758-0/minicluster-data/ts-0-root/wals/15d52d09c3864f4e847d842d4c500a9f/wal-000000033 (ops 162-166)
I20260812 06:17:51.727588 27947 log.cc:1079] T 15d52d09c3864f4e847d842d4c500a9f P 5e96228f5a1b4776a828e10faa8842e4: Deleting log segment in path: /tmp/dist-test-taskdH4ppi/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515466825547-27758-0/minicluster-data/ts-0-root/wals/15d52d09c3864f4e847d842d4c500a9f/wal-000000034 (ops 167-171)
I20260812 06:17:51.727610 27947 log.cc:1079] T 15d52d09c3864f4e847d842d4c500a9f P 5e96228f5a1b4776a828e10faa8842e4: Deleting log segment in path: /tmp/dist-test-taskdH4ppi/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515466825547-27758-0/minicluster-data/ts-0-root/wals/15d52d09c3864f4e847d842d4c500a9f/wal-000000035 (ops 172-176)
I20260812 06:17:51.727640 27947 log.cc:1079] T 15d52d09c3864f4e847d842d4c500a9f P 5e96228f5a1b4776a828e10faa8842e4: Deleting log segment in path: /tmp/dist-test-taskdH4ppi/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515466825547-27758-0/minicluster-data/ts-0-root/wals/15d52d09c3864f4e847d842d4c500a9f/wal-000000036 (ops 177-180)
I20260812 06:17:51.727671 27947 log.cc:1079] T 15d52d09c3864f4e847d842d4c500a9f P 5e96228f5a1b4776a828e10faa8842e4: Deleting log segment in path: /tmp/dist-test-taskdH4ppi/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515466825547-27758-0/minicluster-data/ts-0-root/wals/15d52d09c3864f4e847d842d4c500a9f/wal-000000037 (ops 181-185)
I20260812 06:17:51.727703 27947 log.cc:1079] T 15d52d09c3864f4e847d842d4c500a9f P 5e96228f5a1b4776a828e10faa8842e4: Deleting log segment in path: /tmp/dist-test-taskdH4ppi/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515466825547-27758-0/minicluster-data/ts-0-root/wals/15d52d09c3864f4e847d842d4c500a9f/wal-000000038 (ops 186-190)
I20260812 06:17:51.727734 27947 log.cc:1079] T 15d52d09c3864f4e847d842d4c500a9f P 5e96228f5a1b4776a828e10faa8842e4: Deleting log segment in path: /tmp/dist-test-taskdH4ppi/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515466825547-27758-0/minicluster-data/ts-0-root/wals/15d52d09c3864f4e847d842d4c500a9f/wal-000000039 (ops 191-195)
I20260812 06:17:51.749337 27947 maintenance_manager.cc:643] P 5e96228f5a1b4776a828e10faa8842e4: LogGCOp(15d52d09c3864f4e847d842d4c500a9f) complete. Timing: real 0.022s	user 0.000s	sys 0.019s Metrics: {}
I20260812 06:17:51.749835 28058 maintenance_manager.cc:419] P 5e96228f5a1b4776a828e10faa8842e4: Scheduling UndoDeltaBlockGCOp(15d52d09c3864f4e847d842d4c500a9f): 492 bytes on disk
I20260812 06:17:51.750335 27947 maintenance_manager.cc:643] P 5e96228f5a1b4776a828e10faa8842e4: UndoDeltaBlockGCOp(15d52d09c3864f4e847d842d4c500a9f) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":67,"lbm_reads_lt_1ms":4}
I20260812 06:17:51.751091 28058 maintenance_manager.cc:419] P 5e96228f5a1b4776a828e10faa8842e4: Scheduling FlushDeltaMemStoresOp(15d52d09c3864f4e847d842d4c500a9f): perf score=2.188937
I20260812 06:17:51.768132 27758 heavy-update-compaction-itest.cc:229] Time spent updating: real 4.709s	user 1.659s	sys 0.185s
I20260812 06:17:51.778898 27947 maintenance_manager.cc:643] P 5e96228f5a1b4776a828e10faa8842e4: FlushDeltaMemStoresOp(15d52d09c3864f4e847d842d4c500a9f) complete. Timing: real 0.028s	user 0.011s	sys 0.014s Metrics: {"bytes_written":4225735,"delete_count":0,"lbm_write_time_us":6548,"lbm_writes_lt_1ms":106,"mutex_wait_us":83,"reinsert_count":0,"update_count":515}
I20260812 06:17:51.779402 28058 maintenance_manager.cc:419] P 5e96228f5a1b4776a828e10faa8842e4: Scheduling FlushDeltaMemStoresOp(15d52d09c3864f4e847d842d4c500a9f): perf score=2.188937
I20260812 06:17:51.793505 27947 maintenance_manager.cc:643] P 5e96228f5a1b4776a828e10faa8842e4: FlushDeltaMemStoresOp(15d52d09c3864f4e847d842d4c500a9f) complete. Timing: real 0.014s	user 0.012s	sys 0.001s Metrics: {"bytes_written":3979584,"delete_count":0,"lbm_write_time_us":5850,"lbm_writes_lt_1ms":100,"reinsert_count":0,"update_count":485}
I20260812 06:17:51.793958 28058 maintenance_manager.cc:419] P 5e96228f5a1b4776a828e10faa8842e4: Scheduling MajorDeltaCompactionOp(15d52d09c3864f4e847d842d4c500a9f): perf score=1.000000
I20260812 06:17:51.882882 27758 heavy-update-compaction-itest.cc:265] Time spent scanning: real 0.114s	user 0.004s	sys 0.000s
I20260812 06:17:51.883651 27758 tablet_server.cc:179] TabletServer@127.27.27.129:0 shutting down...
I20260812 06:17:51.973773 27947 maintenance_manager.cc:643] P 5e96228f5a1b4776a828e10faa8842e4: MajorDeltaCompactionOp(15d52d09c3864f4e847d842d4c500a9f) complete. Timing: real 0.180s	user 0.116s	sys 0.061s Metrics: {"cfile_cache_hit":226,"cfile_cache_hit_bytes":9112825,"cfile_cache_miss":509,"cfile_cache_miss_bytes":23908032,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":5,"delta_iterators_relevant":5,"dirs.queue_time_us":518,"lbm_read_time_us":10425,"lbm_reads_lt_1ms":541,"lbm_write_time_us":32719,"lbm_writes_lt_1ms":743,"mutex_wait_us":148,"peak_mem_usage":87969044,"reinsert_count":0,"spinlock_wait_cycles":4480,"thread_start_us":74,"threads_started":1,"update_count":3500}
I20260812 06:17:51.975046 27758 ts_tablet_manager.cc:1507] Shutting down tablet manager...
I20260812 06:17:51.975415 27758 tablet_replica.cc:333] T 15d52d09c3864f4e847d842d4c500a9f P 5e96228f5a1b4776a828e10faa8842e4: stopping tablet replica
I20260812 06:17:51.975636 27758 raft_consensus.cc:2243] T 15d52d09c3864f4e847d842d4c500a9f P 5e96228f5a1b4776a828e10faa8842e4 [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:17:51.975855 27758 raft_consensus.cc:2272] T 15d52d09c3864f4e847d842d4c500a9f P 5e96228f5a1b4776a828e10faa8842e4 [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:17:51.990010 27758 tablet_server.cc:196] TabletServer@127.27.27.129:0 shutdown complete.
I20260812 06:17:52.029946 27758 master.cc:562] Master@127.27.27.190:46031 shutting down...
I20260812 06:17:52.033610 27758 raft_consensus.cc:2243] T 00000000000000000000000000000000 P 782fb91a171c42e484c3444f9bb54fc7 [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:17:52.033774 27758 raft_consensus.cc:2272] T 00000000000000000000000000000000 P 782fb91a171c42e484c3444f9bb54fc7 [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:17:52.033846 27758 tablet_replica.cc:333] T 00000000000000000000000000000000 P 782fb91a171c42e484c3444f9bb54fc7: stopping tablet replica
I20260812 06:17:52.045876 27758 master.cc:584] Master@127.27.27.190:46031 shutdown complete.
[       OK ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/0 (5280 ms)
[ RUN      ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/1
I20260812 06:17:52.126371 27758 internal_mini_cluster.cc:156] Creating distributed mini masters. Addrs: 127.27.27.190:39811
I20260812 06:17:52.126783 27758 file_cache.cc:504] Constructed file cache file cache with capacity 419430
I20260812 06:17:52.128841 27758 server_base.cc:1061] running on GCE node
W20260812 06:17:52.128959 28124 instance_detector.cc:116] could not retrieve OpenStack instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:17:52.129040 28122 instance_detector.cc:116] could not retrieve Azure instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:17:52.128991 28121 instance_detector.cc:116] could not retrieve AWS instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:17:52.129311 27758 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:17:52.129352 27758 system_unsync_time.cc:38] NTP support is disabled. Clock error bounds will not be accurate. This configuration is not suitable for distributed clusters.
I20260812 06:17:52.129365 27758 hybrid_clock.cc:648] HybridClock initialized: now 1786515472129366 us; error 0 us; skew 500 ppm
I20260812 06:17:52.130895 27758 webserver.cc:533] Webserver started at http://127.27.27.190:38503/ using document root <none> and password file <none>
I20260812 06:17:52.131052 27758 fs_manager.cc:362] Metadata directory not provided
I20260812 06:17:52.131103 27758 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:17:52.131181 27758 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:17:52.131541 27758 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskdH4ppi/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515466825547-27758-0/minicluster-data/master-0-root/instance:
uuid: "c8170d81f0c343c3b30a48d66a53fe86"
format_stamp: "Formatted at 2026-08-12 06:17:52 on dist-test-slave-tc2s"
I20260812 06:17:52.132946 27758 fs_manager.cc:696] Time spent creating directory manager: real 0.001s	user 0.002s	sys 0.000s
I20260812 06:17:52.133771 28135 log_block_manager.cc:4127] Time spent loading block containers with low live blocks: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:17:52.133999 27758 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.001s	sys 0.000s
I20260812 06:17:52.134076 27758 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskdH4ppi/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515466825547-27758-0/minicluster-data/master-0-root
uuid: "c8170d81f0c343c3b30a48d66a53fe86"
format_stamp: "Formatted at 2026-08-12 06:17:52 on dist-test-slave-tc2s"
I20260812 06:17:52.134145 27758 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskdH4ppi/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515466825547-27758-0/minicluster-data/master-0-root
metadata directory: /tmp/dist-test-taskdH4ppi/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515466825547-27758-0/minicluster-data/master-0-root
1 data directories: /tmp/dist-test-taskdH4ppi/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515466825547-27758-0/minicluster-data/master-0-root/data
Total live blocks: 0
Total live bytes: 0
Total live bytes (after alignment): 0
Total number of LBM containers: 0 (0 full)
Did not check for missing blocks
Did not check for orphaned blocks
Total full LBM containers with extra space: 0 (0 repaired)
Total full LBM container extra space in bytes: 0 (0 repaired)
Total incomplete LBM containers: 0 (0 repaired)
Total LBM partial records: 0 (0 repaired)
Total corrupted LBM metadata records in RocksDB: 0 (0 repaired)
I20260812 06:17:52.154054 27758 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:17:52.154389 27758 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:17:52.158234 27758 rpc_server.cc:307] RPC server started. Bound to: 127.27.27.190:39811
I20260812 06:17:52.162171 28240 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.27.27.190:39811 every 8 connection(s)
I20260812 06:17:52.162580 28247 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet 00000000000000000000000000000000. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:17:52.164234 28247 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P c8170d81f0c343c3b30a48d66a53fe86: Bootstrap starting.
I20260812 06:17:52.164986 28247 tablet_bootstrap.cc:654] T 00000000000000000000000000000000 P c8170d81f0c343c3b30a48d66a53fe86: Neither blocks nor log segments found. Creating new log.
I20260812 06:17:52.165874 28247 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P c8170d81f0c343c3b30a48d66a53fe86: No bootstrap required, opened a new log
I20260812 06:17:52.166260 28247 raft_consensus.cc:359] T 00000000000000000000000000000000 P c8170d81f0c343c3b30a48d66a53fe86 [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "c8170d81f0c343c3b30a48d66a53fe86" member_type: VOTER }
I20260812 06:17:52.166342 28247 raft_consensus.cc:385] T 00000000000000000000000000000000 P c8170d81f0c343c3b30a48d66a53fe86 [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:17:52.166369 28247 raft_consensus.cc:740] T 00000000000000000000000000000000 P c8170d81f0c343c3b30a48d66a53fe86 [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: c8170d81f0c343c3b30a48d66a53fe86, State: Initialized, Role: FOLLOWER
I20260812 06:17:52.166478 28247 consensus_queue.cc:260] T 00000000000000000000000000000000 P c8170d81f0c343c3b30a48d66a53fe86 [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: "c8170d81f0c343c3b30a48d66a53fe86" member_type: VOTER }
I20260812 06:17:52.166569 28247 raft_consensus.cc:399] T 00000000000000000000000000000000 P c8170d81f0c343c3b30a48d66a53fe86 [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:17:52.166599 28247 raft_consensus.cc:493] T 00000000000000000000000000000000 P c8170d81f0c343c3b30a48d66a53fe86 [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:17:52.166633 28247 raft_consensus.cc:3060] T 00000000000000000000000000000000 P c8170d81f0c343c3b30a48d66a53fe86 [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:17:52.167233 28247 raft_consensus.cc:515] T 00000000000000000000000000000000 P c8170d81f0c343c3b30a48d66a53fe86 [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "c8170d81f0c343c3b30a48d66a53fe86" member_type: VOTER }
I20260812 06:17:52.167351 28247 leader_election.cc:304] T 00000000000000000000000000000000 P c8170d81f0c343c3b30a48d66a53fe86 [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: c8170d81f0c343c3b30a48d66a53fe86; no voters: 
I20260812 06:17:52.167488 28247 leader_election.cc:290] T 00000000000000000000000000000000 P c8170d81f0c343c3b30a48d66a53fe86 [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:17:52.167598 28253 raft_consensus.cc:2804] T 00000000000000000000000000000000 P c8170d81f0c343c3b30a48d66a53fe86 [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:17:52.167760 28253 raft_consensus.cc:697] T 00000000000000000000000000000000 P c8170d81f0c343c3b30a48d66a53fe86 [term 1 LEADER]: Becoming Leader. State: Replica: c8170d81f0c343c3b30a48d66a53fe86, State: Running, Role: LEADER
I20260812 06:17:52.167886 28253 consensus_queue.cc:237] T 00000000000000000000000000000000 P c8170d81f0c343c3b30a48d66a53fe86 [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: "c8170d81f0c343c3b30a48d66a53fe86" member_type: VOTER }
I20260812 06:17:52.167927 28247 sys_catalog.cc:565] T 00000000000000000000000000000000 P c8170d81f0c343c3b30a48d66a53fe86 [sys.catalog]: configured and running, proceeding with master startup.
I20260812 06:17:52.168381 28259 sys_catalog.cc:455] T 00000000000000000000000000000000 P c8170d81f0c343c3b30a48d66a53fe86 [sys.catalog]: SysCatalogTable state changed. Reason: New leader c8170d81f0c343c3b30a48d66a53fe86. Latest consensus state: current_term: 1 leader_uuid: "c8170d81f0c343c3b30a48d66a53fe86" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "c8170d81f0c343c3b30a48d66a53fe86" member_type: VOTER } }
I20260812 06:17:52.168511 28259 sys_catalog.cc:458] T 00000000000000000000000000000000 P c8170d81f0c343c3b30a48d66a53fe86 [sys.catalog]: This master's current role is: LEADER
I20260812 06:17:52.168527 28254 sys_catalog.cc:455] T 00000000000000000000000000000000 P c8170d81f0c343c3b30a48d66a53fe86 [sys.catalog]: SysCatalogTable state changed. Reason: RaftConsensus started. Latest consensus state: current_term: 1 leader_uuid: "c8170d81f0c343c3b30a48d66a53fe86" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "c8170d81f0c343c3b30a48d66a53fe86" member_type: VOTER } }
I20260812 06:17:52.168685 28254 sys_catalog.cc:458] T 00000000000000000000000000000000 P c8170d81f0c343c3b30a48d66a53fe86 [sys.catalog]: This master's current role is: LEADER
I20260812 06:17:52.169101 28264 catalog_manager.cc:1511] Loading table and tablet metadata into memory...
I20260812 06:17:52.169991 28264 catalog_manager.cc:1520] Initializing Kudu cluster ID...
I20260812 06:17:52.170205 27758 internal_mini_cluster.cc:184] Waiting to initialize catalog manager on master 0
I20260812 06:17:52.171687 28264 catalog_manager.cc:1383] Generated new cluster ID: 955aa45ff3e94527a63609910a360913
I20260812 06:17:52.171738 28264 catalog_manager.cc:1531] Initializing Kudu internal certificate authority...
I20260812 06:17:52.181051 28264 catalog_manager.cc:1406] Generated new certificate authority record
I20260812 06:17:52.181504 28264 catalog_manager.cc:1540] Loading token signing keys...
I20260812 06:17:52.189564 28264 catalog_manager.cc:6092] T 00000000000000000000000000000000 P c8170d81f0c343c3b30a48d66a53fe86: Generated new TSK 0
I20260812 06:17:52.189697 28264 catalog_manager.cc:1550] Initializing in-progress tserver states...
I20260812 06:17:52.202292 27758 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:17:52.204080 28296 instance_detector.cc:116] could not retrieve OpenStack instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:17:52.204105 28288 instance_detector.cc:116] could not retrieve AWS instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:17:52.204149 27758 server_base.cc:1061] running on GCE node
W20260812 06:17:52.204186 28290 instance_detector.cc:116] could not retrieve Azure instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:17:52.204418 27758 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:17:52.204466 27758 system_unsync_time.cc:38] NTP support is disabled. Clock error bounds will not be accurate. This configuration is not suitable for distributed clusters.
I20260812 06:17:52.204479 27758 hybrid_clock.cc:648] HybridClock initialized: now 1786515472204480 us; error 0 us; skew 500 ppm
I20260812 06:17:52.205298 27758 webserver.cc:533] Webserver started at http://127.27.27.129:33909/ using document root <none> and password file <none>
I20260812 06:17:52.205464 27758 fs_manager.cc:362] Metadata directory not provided
I20260812 06:17:52.205513 27758 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:17:52.205585 27758 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:17:52.205981 27758 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskdH4ppi/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515466825547-27758-0/minicluster-data/ts-0-root/instance:
uuid: "333690b6a8d84b799755210a3fb160eb"
format_stamp: "Formatted at 2026-08-12 06:17:52 on dist-test-slave-tc2s"
I20260812 06:17:52.207374 27758 fs_manager.cc:696] Time spent creating directory manager: real 0.001s	user 0.001s	sys 0.000s
I20260812 06:17:52.208282 28309 log_block_manager.cc:4127] Time spent loading block containers with low live blocks: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:17:52.208544 27758 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.001s	sys 0.000s
I20260812 06:17:52.208611 27758 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskdH4ppi/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515466825547-27758-0/minicluster-data/ts-0-root
uuid: "333690b6a8d84b799755210a3fb160eb"
format_stamp: "Formatted at 2026-08-12 06:17:52 on dist-test-slave-tc2s"
I20260812 06:17:52.208663 27758 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskdH4ppi/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515466825547-27758-0/minicluster-data/ts-0-root
metadata directory: /tmp/dist-test-taskdH4ppi/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515466825547-27758-0/minicluster-data/ts-0-root
1 data directories: /tmp/dist-test-taskdH4ppi/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515466825547-27758-0/minicluster-data/ts-0-root/data
Total live blocks: 0
Total live bytes: 0
Total live bytes (after alignment): 0
Total number of LBM containers: 0 (0 full)
Did not check for missing blocks
Did not check for orphaned blocks
Total full LBM containers with extra space: 0 (0 repaired)
Total full LBM container extra space in bytes: 0 (0 repaired)
Total incomplete LBM containers: 0 (0 repaired)
Total LBM partial records: 0 (0 repaired)
Total corrupted LBM metadata records in RocksDB: 0 (0 repaired)
I20260812 06:17:52.224558 27758 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:17:52.224882 27758 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:17:52.225122 27758 txn_system_client.cc:432] TxnSystemClient initialization is disabled...
I20260812 06:17:52.225521 27758 ts_tablet_manager.cc:585] Loaded tablet metadata (0 total tablets, 0 live tablets)
I20260812 06:17:52.225556 27758 ts_tablet_manager.cc:531] Time spent load tablet metadata: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:17:52.225586 27758 ts_tablet_manager.cc:616] Registered 0 tablets
I20260812 06:17:52.225606 27758 ts_tablet_manager.cc:595] Time spent register tablets: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:17:52.229573 27758 rpc_server.cc:307] RPC server started. Bound to: 127.27.27.129:35433
I20260812 06:17:52.229594 28430 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.27.27.129:35433 every 8 connection(s)
I20260812 06:17:52.237695 28434 heartbeater.cc:344] Connected to a master server at 127.27.27.190:39811
I20260812 06:17:52.237790 28434 heartbeater.cc:461] Registering TS with master...
I20260812 06:17:52.238005 28434 heartbeater.cc:507] Master 127.27.27.190:39811 requested a full tablet report, sending...
I20260812 06:17:52.238579 28171 ts_manager.cc:194] Registered new tserver with Master: 333690b6a8d84b799755210a3fb160eb (127.27.27.129:35433)
I20260812 06:17:52.238731 27758 internal_mini_cluster.cc:371] 1 TS(s) registered with all masters after 0.008770135s
I20260812 06:17:52.239348 28171 master_service.cc:502] Signed X509 certificate for tserver {username='slave'} at 127.0.0.1:36814
I20260812 06:17:52.245028 28171 catalog_manager.cc:2283] Servicing CreateTable request from {username='slave'} at 127.0.0.1:36824:
name: "heavy-update-compaction-test"
schema {
  columns {
    name: "key"
    type: INT64
    is_key: true
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_a"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_b"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_c"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_d"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_e"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
}
num_replicas: 1
split_rows_range_bounds {
}
partition_schema {
  range_schema {
  }
}
I20260812 06:17:52.252821 28352 tablet_service.cc:1511] Processing CreateTablet for tablet 317f884eb4a941df998110bf30c15aac (DEFAULT_TABLE table=heavy-update-compaction-test [id=5f75a2b339c749ce878225e40abfa842]), partition=
I20260812 06:17:52.253049 28352 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet 317f884eb4a941df998110bf30c15aac. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:17:52.254892 28461 tablet_bootstrap.cc:492] T 317f884eb4a941df998110bf30c15aac P 333690b6a8d84b799755210a3fb160eb: Bootstrap starting.
I20260812 06:17:52.255846 28461 tablet_bootstrap.cc:654] T 317f884eb4a941df998110bf30c15aac P 333690b6a8d84b799755210a3fb160eb: Neither blocks nor log segments found. Creating new log.
I20260812 06:17:52.256769 28461 tablet_bootstrap.cc:492] T 317f884eb4a941df998110bf30c15aac P 333690b6a8d84b799755210a3fb160eb: No bootstrap required, opened a new log
I20260812 06:17:52.256841 28461 ts_tablet_manager.cc:1403] T 317f884eb4a941df998110bf30c15aac P 333690b6a8d84b799755210a3fb160eb: Time spent bootstrapping tablet: real 0.002s	user 0.001s	sys 0.000s
I20260812 06:17:52.257211 28461 raft_consensus.cc:359] T 317f884eb4a941df998110bf30c15aac P 333690b6a8d84b799755210a3fb160eb [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "333690b6a8d84b799755210a3fb160eb" member_type: VOTER last_known_addr { host: "127.27.27.129" port: 35433 } }
I20260812 06:17:52.257294 28461 raft_consensus.cc:385] T 317f884eb4a941df998110bf30c15aac P 333690b6a8d84b799755210a3fb160eb [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:17:52.257320 28461 raft_consensus.cc:740] T 317f884eb4a941df998110bf30c15aac P 333690b6a8d84b799755210a3fb160eb [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: 333690b6a8d84b799755210a3fb160eb, State: Initialized, Role: FOLLOWER
I20260812 06:17:52.257419 28461 consensus_queue.cc:260] T 317f884eb4a941df998110bf30c15aac P 333690b6a8d84b799755210a3fb160eb [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: "333690b6a8d84b799755210a3fb160eb" member_type: VOTER last_known_addr { host: "127.27.27.129" port: 35433 } }
I20260812 06:17:52.257477 28461 raft_consensus.cc:399] T 317f884eb4a941df998110bf30c15aac P 333690b6a8d84b799755210a3fb160eb [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:17:52.257504 28461 raft_consensus.cc:493] T 317f884eb4a941df998110bf30c15aac P 333690b6a8d84b799755210a3fb160eb [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:17:52.257537 28461 raft_consensus.cc:3060] T 317f884eb4a941df998110bf30c15aac P 333690b6a8d84b799755210a3fb160eb [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:17:52.258353 28461 raft_consensus.cc:515] T 317f884eb4a941df998110bf30c15aac P 333690b6a8d84b799755210a3fb160eb [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "333690b6a8d84b799755210a3fb160eb" member_type: VOTER last_known_addr { host: "127.27.27.129" port: 35433 } }
I20260812 06:17:52.258497 28461 leader_election.cc:304] T 317f884eb4a941df998110bf30c15aac P 333690b6a8d84b799755210a3fb160eb [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: 333690b6a8d84b799755210a3fb160eb; no voters: 
I20260812 06:17:52.258685 28461 leader_election.cc:290] T 317f884eb4a941df998110bf30c15aac P 333690b6a8d84b799755210a3fb160eb [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:17:52.258783 28466 raft_consensus.cc:2804] T 317f884eb4a941df998110bf30c15aac P 333690b6a8d84b799755210a3fb160eb [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:17:52.258963 28466 raft_consensus.cc:697] T 317f884eb4a941df998110bf30c15aac P 333690b6a8d84b799755210a3fb160eb [term 1 LEADER]: Becoming Leader. State: Replica: 333690b6a8d84b799755210a3fb160eb, State: Running, Role: LEADER
I20260812 06:17:52.258984 28434 heartbeater.cc:499] Master 127.27.27.190:39811 was elected leader, sending a full tablet report...
I20260812 06:17:52.258980 28461 ts_tablet_manager.cc:1434] T 317f884eb4a941df998110bf30c15aac P 333690b6a8d84b799755210a3fb160eb: Time spent starting tablet: real 0.002s	user 0.002s	sys 0.000s
I20260812 06:17:52.259176 28466 consensus_queue.cc:237] T 317f884eb4a941df998110bf30c15aac P 333690b6a8d84b799755210a3fb160eb [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: "333690b6a8d84b799755210a3fb160eb" member_type: VOTER last_known_addr { host: "127.27.27.129" port: 35433 } }
I20260812 06:17:52.260407 28171 catalog_manager.cc:5719] T 317f884eb4a941df998110bf30c15aac P 333690b6a8d84b799755210a3fb160eb reported cstate change: term changed from 0 to 1, leader changed from <none> to 333690b6a8d84b799755210a3fb160eb (127.27.27.129). New cstate: current_term: 1 leader_uuid: "333690b6a8d84b799755210a3fb160eb" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "333690b6a8d84b799755210a3fb160eb" member_type: VOTER last_known_addr { host: "127.27.27.129" port: 35433 } health_report { overall_health: HEALTHY } } }
I20260812 06:17:52.315342 27758 heavy-update-compaction-itest.cc:215] Time spent inserting: real 0.051s	user 0.015s	sys 0.007s
I20260812 06:17:52.480456 28435 maintenance_manager.cc:419] P 333690b6a8d84b799755210a3fb160eb: Scheduling FlushMRSOp(317f884eb4a941df998110bf30c15aac): perf score=23.023690
I20260812 06:17:52.639580 28316 maintenance_manager.cc:643] P 333690b6a8d84b799755210a3fb160eb: FlushMRSOp(317f884eb4a941df998110bf30c15aac) complete. Timing: real 0.159s	user 0.125s	sys 0.032s Metrics: {"bytes_written":12717736,"cfile_init":1,"delete_count":0,"dirs.queue_time_us":62,"dirs.run_cpu_time_us":177,"dirs.run_wall_time_us":854,"drs_written":1,"lbm_read_time_us":64,"lbm_reads_lt_1ms":4,"lbm_write_time_us":41330,"lbm_writes_lt_1ms":867,"peak_mem_usage":0,"reinsert_count":0,"rows_written":105,"update_count":1550}
I20260812 06:17:52.640381 28435 maintenance_manager.cc:419] P 333690b6a8d84b799755210a3fb160eb: Scheduling LogGCOp(317f884eb4a941df998110bf30c15aac): free 20743880 bytes of WAL
I20260812 06:17:52.640615 28316 log_reader.cc:385] T 317f884eb4a941df998110bf30c15aac: removed 2 log segments from log reader
I20260812 06:17:52.640666 28316 log.cc:1079] T 317f884eb4a941df998110bf30c15aac P 333690b6a8d84b799755210a3fb160eb: Deleting log segment in path: /tmp/dist-test-taskdH4ppi/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515466825547-27758-0/minicluster-data/ts-0-root/wals/317f884eb4a941df998110bf30c15aac/wal-000000001 (ops 1-6)
I20260812 06:17:52.640705 28316 log.cc:1079] T 317f884eb4a941df998110bf30c15aac P 333690b6a8d84b799755210a3fb160eb: Deleting log segment in path: /tmp/dist-test-taskdH4ppi/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515466825547-27758-0/minicluster-data/ts-0-root/wals/317f884eb4a941df998110bf30c15aac/wal-000000002 (ops 7-11)
I20260812 06:17:52.644446 28316 maintenance_manager.cc:643] P 333690b6a8d84b799755210a3fb160eb: LogGCOp(317f884eb4a941df998110bf30c15aac) complete. Timing: real 0.004s	user 0.000s	sys 0.001s Metrics: {}
I20260812 06:17:52.644796 28435 maintenance_manager.cc:419] P 333690b6a8d84b799755210a3fb160eb: Scheduling FlushDeltaMemStoresOp(317f884eb4a941df998110bf30c15aac): perf score=2.188937
I20260812 06:17:52.657428 28316 maintenance_manager.cc:643] P 333690b6a8d84b799755210a3fb160eb: FlushDeltaMemStoresOp(317f884eb4a941df998110bf30c15aac) complete. Timing: real 0.012s	user 0.007s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5062,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:52.657799 28435 maintenance_manager.cc:419] P 333690b6a8d84b799755210a3fb160eb: Scheduling UndoDeltaBlockGCOp(317f884eb4a941df998110bf30c15aac): 20513813 bytes on disk
I20260812 06:17:52.658161 28316 maintenance_manager.cc:643] P 333690b6a8d84b799755210a3fb160eb: UndoDeltaBlockGCOp(317f884eb4a941df998110bf30c15aac) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":44,"lbm_reads_lt_1ms":4}
I20260812 06:17:52.658560 28435 maintenance_manager.cc:419] P 333690b6a8d84b799755210a3fb160eb: Scheduling MajorDeltaCompactionOp(317f884eb4a941df998110bf30c15aac): perf score=1.000000
I20260812 06:17:52.799589 28316 maintenance_manager.cc:643] P 333690b6a8d84b799755210a3fb160eb: MajorDeltaCompactionOp(317f884eb4a941df998110bf30c15aac) complete. Timing: real 0.141s	user 0.103s	sys 0.034s Metrics: {"cfile_cache_miss":442,"cfile_cache_miss_bytes":21123518,"cfile_init":7,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":422,"lbm_read_time_us":9522,"lbm_reads_lt_1ms":470,"lbm_write_time_us":20220,"lbm_writes_lt_1ms":453,"peak_mem_usage":51099678,"reinsert_count":0,"thread_start_us":293,"threads_started":5,"update_count":2050}
I20260812 06:17:52.800141 28435 maintenance_manager.cc:419] P 333690b6a8d84b799755210a3fb160eb: Scheduling FlushDeltaMemStoresOp(317f884eb4a941df998110bf30c15aac): perf score=14.095187
I20260812 06:17:52.847632 28316 maintenance_manager.cc:643] P 333690b6a8d84b799755210a3fb160eb: FlushDeltaMemStoresOp(317f884eb4a941df998110bf30c15aac) complete. Timing: real 0.047s	user 0.017s	sys 0.025s Metrics: {"bytes_written":15999661,"delete_count":0,"lbm_write_time_us":19324,"lbm_writes_lt_1ms":393,"reinsert_count":0,"update_count":1950}
I20260812 06:17:52.848075 28435 maintenance_manager.cc:419] P 333690b6a8d84b799755210a3fb160eb: Scheduling FlushDeltaMemStoresOp(317f884eb4a941df998110bf30c15aac): perf score=2.188937
I20260812 06:17:52.865860 28316 maintenance_manager.cc:643] P 333690b6a8d84b799755210a3fb160eb: FlushDeltaMemStoresOp(317f884eb4a941df998110bf30c15aac) complete. Timing: real 0.018s	user 0.000s	sys 0.014s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3628,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:52.866297 28435 maintenance_manager.cc:419] P 333690b6a8d84b799755210a3fb160eb: Scheduling MajorDeltaCompactionOp(317f884eb4a941df998110bf30c15aac): perf score=1.000000
I20260812 06:17:53.052712 28316 maintenance_manager.cc:643] P 333690b6a8d84b799755210a3fb160eb: MajorDeltaCompactionOp(317f884eb4a941df998110bf30c15aac) complete. Timing: real 0.186s	user 0.117s	sys 0.062s Metrics: {"cfile_cache_miss":522,"cfile_cache_miss_bytes":24405443,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":741,"lbm_read_time_us":13272,"lbm_reads_lt_1ms":562,"lbm_write_time_us":29152,"lbm_writes_lt_1ms":533,"mutex_wait_us":25,"peak_mem_usage":61665166,"reinsert_count":0,"spinlock_wait_cycles":4224,"update_count":2450}
I20260812 06:17:53.053205 28435 maintenance_manager.cc:419] P 333690b6a8d84b799755210a3fb160eb: Scheduling FlushDeltaMemStoresOp(317f884eb4a941df998110bf30c15aac): perf score=14.095187
I20260812 06:17:53.102223 28316 maintenance_manager.cc:643] P 333690b6a8d84b799755210a3fb160eb: FlushDeltaMemStoresOp(317f884eb4a941df998110bf30c15aac) complete. Timing: real 0.049s	user 0.013s	sys 0.035s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":20405,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":402,"reinsert_count":0,"update_count":2000}
I20260812 06:17:53.102772 28435 maintenance_manager.cc:419] P 333690b6a8d84b799755210a3fb160eb: Scheduling FlushDeltaMemStoresOp(317f884eb4a941df998110bf30c15aac): perf score=2.188937
I20260812 06:17:53.113807 28316 maintenance_manager.cc:643] P 333690b6a8d84b799755210a3fb160eb: FlushDeltaMemStoresOp(317f884eb4a941df998110bf30c15aac) complete. Timing: real 0.011s	user 0.009s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4048,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:53.114243 28435 maintenance_manager.cc:419] P 333690b6a8d84b799755210a3fb160eb: Scheduling MajorDeltaCompactionOp(317f884eb4a941df998110bf30c15aac): perf score=1.000000
I20260812 06:17:53.288233 28316 maintenance_manager.cc:643] P 333690b6a8d84b799755210a3fb160eb: MajorDeltaCompactionOp(317f884eb4a941df998110bf30c15aac) complete. Timing: real 0.174s	user 0.107s	sys 0.057s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24815684,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":153,"lbm_read_time_us":10012,"lbm_reads_lt_1ms":572,"lbm_write_time_us":25125,"lbm_writes_lt_1ms":543,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":7040,"update_count":2500}
I20260812 06:17:53.288761 28435 maintenance_manager.cc:419] P 333690b6a8d84b799755210a3fb160eb: Scheduling FlushDeltaMemStoresOp(317f884eb4a941df998110bf30c15aac): perf score=14.095187
I20260812 06:17:53.335500 28316 maintenance_manager.cc:643] P 333690b6a8d84b799755210a3fb160eb: FlushDeltaMemStoresOp(317f884eb4a941df998110bf30c15aac) complete. Timing: real 0.046s	user 0.021s	sys 0.016s Metrics: {"bytes_written":16409903,"delete_count":0,"lbm_write_time_us":16753,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:17:53.335970 28435 maintenance_manager.cc:419] P 333690b6a8d84b799755210a3fb160eb: Scheduling FlushDeltaMemStoresOp(317f884eb4a941df998110bf30c15aac): perf score=2.188937
I20260812 06:17:53.345567 28316 maintenance_manager.cc:643] P 333690b6a8d84b799755210a3fb160eb: FlushDeltaMemStoresOp(317f884eb4a941df998110bf30c15aac) complete. Timing: real 0.009s	user 0.000s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3698,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:53.346022 28435 maintenance_manager.cc:419] P 333690b6a8d84b799755210a3fb160eb: Scheduling MajorDeltaCompactionOp(317f884eb4a941df998110bf30c15aac): perf score=1.000000
I20260812 06:17:53.490168 28316 maintenance_manager.cc:643] P 333690b6a8d84b799755210a3fb160eb: MajorDeltaCompactionOp(317f884eb4a941df998110bf30c15aac) complete. Timing: real 0.144s	user 0.106s	sys 0.037s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24815685,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":607,"lbm_read_time_us":10756,"lbm_reads_lt_1ms":572,"lbm_write_time_us":28256,"lbm_writes_lt_1ms":543,"mutex_wait_us":289,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":41984,"update_count":2500}
I20260812 06:17:53.490694 28435 maintenance_manager.cc:419] P 333690b6a8d84b799755210a3fb160eb: Scheduling FlushDeltaMemStoresOp(317f884eb4a941df998110bf30c15aac): perf score=10.126437
I20260812 06:17:53.523587 28316 maintenance_manager.cc:643] P 333690b6a8d84b799755210a3fb160eb: FlushDeltaMemStoresOp(317f884eb4a941df998110bf30c15aac) complete. Timing: real 0.033s	user 0.031s	sys 0.000s Metrics: {"bytes_written":12307489,"delete_count":0,"lbm_write_time_us":14014,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:17:53.524055 28435 maintenance_manager.cc:419] P 333690b6a8d84b799755210a3fb160eb: Scheduling FlushDeltaMemStoresOp(317f884eb4a941df998110bf30c15aac): perf score=2.188937
I20260812 06:17:53.540970 28316 maintenance_manager.cc:643] P 333690b6a8d84b799755210a3fb160eb: FlushDeltaMemStoresOp(317f884eb4a941df998110bf30c15aac) complete. Timing: real 0.017s	user 0.009s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6112,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:53.541625 28435 maintenance_manager.cc:419] P 333690b6a8d84b799755210a3fb160eb: Scheduling MajorDeltaCompactionOp(317f884eb4a941df998110bf30c15aac): perf score=1.000000
I20260812 06:17:53.660717 28316 maintenance_manager.cc:643] P 333690b6a8d84b799755210a3fb160eb: MajorDeltaCompactionOp(317f884eb4a941df998110bf30c15aac) complete. Timing: real 0.119s	user 0.086s	sys 0.031s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20713271,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":275,"lbm_read_time_us":6828,"lbm_reads_lt_1ms":468,"lbm_write_time_us":23552,"lbm_writes_lt_1ms":443,"peak_mem_usage":50689328,"reinsert_count":0,"update_count":2000}
I20260812 06:17:53.661309 28435 maintenance_manager.cc:419] P 333690b6a8d84b799755210a3fb160eb: Scheduling FlushDeltaMemStoresOp(317f884eb4a941df998110bf30c15aac): perf score=10.126437
I20260812 06:17:53.706497 28316 maintenance_manager.cc:643] P 333690b6a8d84b799755210a3fb160eb: FlushDeltaMemStoresOp(317f884eb4a941df998110bf30c15aac) complete. Timing: real 0.045s	user 0.022s	sys 0.012s Metrics: {"bytes_written":12307493,"delete_count":0,"lbm_write_time_us":14799,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:17:53.706974 28435 maintenance_manager.cc:419] P 333690b6a8d84b799755210a3fb160eb: Scheduling FlushDeltaMemStoresOp(317f884eb4a941df998110bf30c15aac): perf score=2.188937
I20260812 06:17:53.718726 28316 maintenance_manager.cc:643] P 333690b6a8d84b799755210a3fb160eb: FlushDeltaMemStoresOp(317f884eb4a941df998110bf30c15aac) complete. Timing: real 0.012s	user 0.003s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4180,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:53.720764 28435 maintenance_manager.cc:419] P 333690b6a8d84b799755210a3fb160eb: Scheduling MajorDeltaCompactionOp(317f884eb4a941df998110bf30c15aac): perf score=1.000000
I20260812 06:17:53.841794 28316 maintenance_manager.cc:643] P 333690b6a8d84b799755210a3fb160eb: MajorDeltaCompactionOp(317f884eb4a941df998110bf30c15aac) complete. Timing: real 0.121s	user 0.113s	sys 0.008s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20713275,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":282,"lbm_read_time_us":9524,"lbm_reads_lt_1ms":472,"lbm_write_time_us":21629,"lbm_writes_lt_1ms":443,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":12672,"update_count":2000}
I20260812 06:17:53.842464 28435 maintenance_manager.cc:419] P 333690b6a8d84b799755210a3fb160eb: Scheduling FlushDeltaMemStoresOp(317f884eb4a941df998110bf30c15aac): perf score=10.126437
I20260812 06:17:53.895080 28316 maintenance_manager.cc:643] P 333690b6a8d84b799755210a3fb160eb: FlushDeltaMemStoresOp(317f884eb4a941df998110bf30c15aac) complete. Timing: real 0.052s	user 0.023s	sys 0.026s Metrics: {"bytes_written":12307491,"delete_count":0,"lbm_write_time_us":17618,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":302,"reinsert_count":0,"update_count":1500}
I20260812 06:17:53.895642 28435 maintenance_manager.cc:419] P 333690b6a8d84b799755210a3fb160eb: Scheduling FlushDeltaMemStoresOp(317f884eb4a941df998110bf30c15aac): perf score=2.188937
I20260812 06:17:53.910332 28316 maintenance_manager.cc:643] P 333690b6a8d84b799755210a3fb160eb: FlushDeltaMemStoresOp(317f884eb4a941df998110bf30c15aac) complete. Timing: real 0.015s	user 0.014s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5711,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:53.910774 28435 maintenance_manager.cc:419] P 333690b6a8d84b799755210a3fb160eb: Scheduling FlushMRSOp(317f884eb4a941df998110bf30c15aac): perf score=1.000000
I20260812 06:17:53.951226 28316 maintenance_manager.cc:643] P 333690b6a8d84b799755210a3fb160eb: FlushMRSOp(317f884eb4a941df998110bf30c15aac) complete. Timing: real 0.040s	user 0.029s	sys 0.000s Metrics: {"bytes_written":1275444,"cfile_init":1,"dirs.queue_time_us":48,"dirs.run_cpu_time_us":198,"dirs.run_wall_time_us":1209,"drs_written":1,"lbm_read_time_us":36,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1506,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":31}
I20260812 06:17:53.951938 28435 maintenance_manager.cc:419] P 333690b6a8d84b799755210a3fb160eb: Scheduling LogGCOp(317f884eb4a941df998110bf30c15aac): free 124710290 bytes of WAL
I20260812 06:17:53.952157 28316 log_reader.cc:385] T 317f884eb4a941df998110bf30c15aac: removed 12 log segments from log reader
I20260812 06:17:53.952204 28316 log.cc:1079] T 317f884eb4a941df998110bf30c15aac P 333690b6a8d84b799755210a3fb160eb: Deleting log segment in path: /tmp/dist-test-taskdH4ppi/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515466825547-27758-0/minicluster-data/ts-0-root/wals/317f884eb4a941df998110bf30c15aac/wal-000000003 (ops 12-16)
I20260812 06:17:53.952243 28316 log.cc:1079] T 317f884eb4a941df998110bf30c15aac P 333690b6a8d84b799755210a3fb160eb: Deleting log segment in path: /tmp/dist-test-taskdH4ppi/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515466825547-27758-0/minicluster-data/ts-0-root/wals/317f884eb4a941df998110bf30c15aac/wal-000000004 (ops 17-21)
I20260812 06:17:53.952277 28316 log.cc:1079] T 317f884eb4a941df998110bf30c15aac P 333690b6a8d84b799755210a3fb160eb: Deleting log segment in path: /tmp/dist-test-taskdH4ppi/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515466825547-27758-0/minicluster-data/ts-0-root/wals/317f884eb4a941df998110bf30c15aac/wal-000000005 (ops 22-26)
I20260812 06:17:53.952303 28316 log.cc:1079] T 317f884eb4a941df998110bf30c15aac P 333690b6a8d84b799755210a3fb160eb: Deleting log segment in path: /tmp/dist-test-taskdH4ppi/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515466825547-27758-0/minicluster-data/ts-0-root/wals/317f884eb4a941df998110bf30c15aac/wal-000000006 (ops 27-31)
I20260812 06:17:53.952334 28316 log.cc:1079] T 317f884eb4a941df998110bf30c15aac P 333690b6a8d84b799755210a3fb160eb: Deleting log segment in path: /tmp/dist-test-taskdH4ppi/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515466825547-27758-0/minicluster-data/ts-0-root/wals/317f884eb4a941df998110bf30c15aac/wal-000000007 (ops 32-36)
I20260812 06:17:53.952365 28316 log.cc:1079] T 317f884eb4a941df998110bf30c15aac P 333690b6a8d84b799755210a3fb160eb: Deleting log segment in path: /tmp/dist-test-taskdH4ppi/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515466825547-27758-0/minicluster-data/ts-0-root/wals/317f884eb4a941df998110bf30c15aac/wal-000000008 (ops 37-41)
I20260812 06:17:53.952397 28316 log.cc:1079] T 317f884eb4a941df998110bf30c15aac P 333690b6a8d84b799755210a3fb160eb: Deleting log segment in path: /tmp/dist-test-taskdH4ppi/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515466825547-27758-0/minicluster-data/ts-0-root/wals/317f884eb4a941df998110bf30c15aac/wal-000000009 (ops 42-46)
I20260812 06:17:53.952427 28316 log.cc:1079] T 317f884eb4a941df998110bf30c15aac P 333690b6a8d84b799755210a3fb160eb: Deleting log segment in path: /tmp/dist-test-taskdH4ppi/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515466825547-27758-0/minicluster-data/ts-0-root/wals/317f884eb4a941df998110bf30c15aac/wal-000000010 (ops 47-51)
I20260812 06:17:53.952458 28316 log.cc:1079] T 317f884eb4a941df998110bf30c15aac P 333690b6a8d84b799755210a3fb160eb: Deleting log segment in path: /tmp/dist-test-taskdH4ppi/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515466825547-27758-0/minicluster-data/ts-0-root/wals/317f884eb4a941df998110bf30c15aac/wal-000000011 (ops 52-56)
I20260812 06:17:53.952497 28316 log.cc:1079] T 317f884eb4a941df998110bf30c15aac P 333690b6a8d84b799755210a3fb160eb: Deleting log segment in path: /tmp/dist-test-taskdH4ppi/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515466825547-27758-0/minicluster-data/ts-0-root/wals/317f884eb4a941df998110bf30c15aac/wal-000000012 (ops 57-61)
I20260812 06:17:53.952528 28316 log.cc:1079] T 317f884eb4a941df998110bf30c15aac P 333690b6a8d84b799755210a3fb160eb: Deleting log segment in path: /tmp/dist-test-taskdH4ppi/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515466825547-27758-0/minicluster-data/ts-0-root/wals/317f884eb4a941df998110bf30c15aac/wal-000000013 (ops 62-66)
I20260812 06:17:53.952561 28316 log.cc:1079] T 317f884eb4a941df998110bf30c15aac P 333690b6a8d84b799755210a3fb160eb: Deleting log segment in path: /tmp/dist-test-taskdH4ppi/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515466825547-27758-0/minicluster-data/ts-0-root/wals/317f884eb4a941df998110bf30c15aac/wal-000000014 (ops 67-71)
I20260812 06:17:53.972680 28316 maintenance_manager.cc:643] P 333690b6a8d84b799755210a3fb160eb: LogGCOp(317f884eb4a941df998110bf30c15aac) complete. Timing: real 0.021s	user 0.000s	sys 0.018s Metrics: {}
I20260812 06:17:53.973065 28435 maintenance_manager.cc:419] P 333690b6a8d84b799755210a3fb160eb: Scheduling FlushDeltaMemStoresOp(317f884eb4a941df998110bf30c15aac): perf score=2.188937
I20260812 06:17:53.992887 28316 maintenance_manager.cc:643] P 333690b6a8d84b799755210a3fb160eb: FlushDeltaMemStoresOp(317f884eb4a941df998110bf30c15aac) complete. Timing: real 0.020s	user 0.007s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5101,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:53.993275 28435 maintenance_manager.cc:419] P 333690b6a8d84b799755210a3fb160eb: Scheduling UndoDeltaBlockGCOp(317f884eb4a941df998110bf30c15aac): 482 bytes on disk
I20260812 06:17:53.993623 28316 maintenance_manager.cc:643] P 333690b6a8d84b799755210a3fb160eb: UndoDeltaBlockGCOp(317f884eb4a941df998110bf30c15aac) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":47,"lbm_reads_lt_1ms":4}
I20260812 06:17:53.994100 28435 maintenance_manager.cc:419] P 333690b6a8d84b799755210a3fb160eb: Scheduling FlushDeltaMemStoresOp(317f884eb4a941df998110bf30c15aac): perf score=2.188937
I20260812 06:17:54.003511 28316 maintenance_manager.cc:643] P 333690b6a8d84b799755210a3fb160eb: FlushDeltaMemStoresOp(317f884eb4a941df998110bf30c15aac) complete. Timing: real 0.009s	user 0.008s	sys 0.000s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":3639,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:54.003898 28435 maintenance_manager.cc:419] P 333690b6a8d84b799755210a3fb160eb: Scheduling MajorDeltaCompactionOp(317f884eb4a941df998110bf30c15aac): perf score=1.000000
I20260812 06:17:54.208956 28316 maintenance_manager.cc:643] P 333690b6a8d84b799755210a3fb160eb: MajorDeltaCompactionOp(317f884eb4a941df998110bf30c15aac) complete. Timing: real 0.205s	user 0.125s	sys 0.080s Metrics: {"cfile_cache_miss":634,"cfile_cache_miss_bytes":28918334,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":88,"lbm_read_time_us":14223,"lbm_reads_lt_1ms":674,"lbm_write_time_us":33827,"lbm_writes_lt_1ms":643,"mutex_wait_us":24,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":17408,"thread_start_us":82,"threads_started":1,"update_count":3000}
I20260812 06:17:54.209587 28435 maintenance_manager.cc:419] P 333690b6a8d84b799755210a3fb160eb: Scheduling FlushDeltaMemStoresOp(317f884eb4a941df998110bf30c15aac): perf score=14.095187
I20260812 06:17:54.263562 28316 maintenance_manager.cc:643] P 333690b6a8d84b799755210a3fb160eb: FlushDeltaMemStoresOp(317f884eb4a941df998110bf30c15aac) complete. Timing: real 0.054s	user 0.033s	sys 0.019s Metrics: {"bytes_written":16409899,"delete_count":0,"lbm_write_time_us":24369,"lbm_writes_1-10_ms":3,"lbm_writes_lt_1ms":400,"reinsert_count":0,"update_count":2000}
I20260812 06:17:54.264011 28435 maintenance_manager.cc:419] P 333690b6a8d84b799755210a3fb160eb: Scheduling FlushDeltaMemStoresOp(317f884eb4a941df998110bf30c15aac): perf score=2.188937
I20260812 06:17:54.277695 28316 maintenance_manager.cc:643] P 333690b6a8d84b799755210a3fb160eb: FlushDeltaMemStoresOp(317f884eb4a941df998110bf30c15aac) complete. Timing: real 0.014s	user 0.012s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4953,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:54.278177 28435 maintenance_manager.cc:419] P 333690b6a8d84b799755210a3fb160eb: Scheduling MajorDeltaCompactionOp(317f884eb4a941df998110bf30c15aac): perf score=1.000000
I20260812 06:17:54.434288 28316 maintenance_manager.cc:643] P 333690b6a8d84b799755210a3fb160eb: MajorDeltaCompactionOp(317f884eb4a941df998110bf30c15aac) complete. Timing: real 0.156s	user 0.113s	sys 0.042s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24815681,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":460,"lbm_read_time_us":11602,"lbm_reads_lt_1ms":564,"lbm_write_time_us":25175,"lbm_writes_lt_1ms":543,"mutex_wait_us":256,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":6400,"update_count":2500}
I20260812 06:17:54.434837 28435 maintenance_manager.cc:419] P 333690b6a8d84b799755210a3fb160eb: Scheduling FlushDeltaMemStoresOp(317f884eb4a941df998110bf30c15aac): perf score=14.095187
I20260812 06:17:54.493362 28316 maintenance_manager.cc:643] P 333690b6a8d84b799755210a3fb160eb: FlushDeltaMemStoresOp(317f884eb4a941df998110bf30c15aac) complete. Timing: real 0.058s	user 0.025s	sys 0.029s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":21020,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:17:54.493944 28435 maintenance_manager.cc:419] P 333690b6a8d84b799755210a3fb160eb: Scheduling FlushDeltaMemStoresOp(317f884eb4a941df998110bf30c15aac): perf score=3.181125
I20260812 06:17:54.516496 28316 maintenance_manager.cc:643] P 333690b6a8d84b799755210a3fb160eb: FlushDeltaMemStoresOp(317f884eb4a941df998110bf30c15aac) complete. Timing: real 0.022s	user 0.008s	sys 0.004s Metrics: {"bytes_written":4512902,"delete_count":0,"lbm_write_time_us":5524,"lbm_writes_lt_1ms":113,"reinsert_count":0,"update_count":550}
I20260812 06:17:54.516990 28435 maintenance_manager.cc:419] P 333690b6a8d84b799755210a3fb160eb: Scheduling FlushDeltaMemStoresOp(317f884eb4a941df998110bf30c15aac): perf score=2.188937
I20260812 06:17:54.526160 28316 maintenance_manager.cc:643] P 333690b6a8d84b799755210a3fb160eb: FlushDeltaMemStoresOp(317f884eb4a941df998110bf30c15aac) complete. Timing: real 0.009s	user 0.009s	sys 0.000s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3609,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:17:54.526598 28435 maintenance_manager.cc:419] P 333690b6a8d84b799755210a3fb160eb: Scheduling MajorDeltaCompactionOp(317f884eb4a941df998110bf30c15aac): perf score=1.000000
I20260812 06:17:54.722007 28316 maintenance_manager.cc:643] P 333690b6a8d84b799755210a3fb160eb: MajorDeltaCompactionOp(317f884eb4a941df998110bf30c15aac) complete. Timing: real 0.195s	user 0.146s	sys 0.049s Metrics: {"cfile_cache_miss":633,"cfile_cache_miss_bytes":28918203,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":677,"lbm_read_time_us":15123,"lbm_reads_lt_1ms":673,"lbm_write_time_us":29167,"lbm_writes_lt_1ms":643,"mutex_wait_us":294,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":18048,"update_count":3000}
I20260812 06:17:54.722517 28435 maintenance_manager.cc:419] P 333690b6a8d84b799755210a3fb160eb: Scheduling FlushDeltaMemStoresOp(317f884eb4a941df998110bf30c15aac): perf score=14.095187
I20260812 06:17:54.766920 28316 maintenance_manager.cc:643] P 333690b6a8d84b799755210a3fb160eb: FlushDeltaMemStoresOp(317f884eb4a941df998110bf30c15aac) complete. Timing: real 0.044s	user 0.038s	sys 0.005s Metrics: {"bytes_written":16409903,"delete_count":0,"lbm_write_time_us":19429,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:17:54.767535 28435 maintenance_manager.cc:419] P 333690b6a8d84b799755210a3fb160eb: Scheduling FlushDeltaMemStoresOp(317f884eb4a941df998110bf30c15aac): perf score=2.188937
I20260812 06:17:54.779986 28316 maintenance_manager.cc:643] P 333690b6a8d84b799755210a3fb160eb: FlushDeltaMemStoresOp(317f884eb4a941df998110bf30c15aac) complete. Timing: real 0.012s	user 0.005s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4301,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:54.780491 28435 maintenance_manager.cc:419] P 333690b6a8d84b799755210a3fb160eb: Scheduling MajorDeltaCompactionOp(317f884eb4a941df998110bf30c15aac): perf score=1.000000
I20260812 06:17:54.944597 28316 maintenance_manager.cc:643] P 333690b6a8d84b799755210a3fb160eb: MajorDeltaCompactionOp(317f884eb4a941df998110bf30c15aac) complete. Timing: real 0.164s	user 0.118s	sys 0.045s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24815685,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":989,"lbm_read_time_us":11602,"lbm_reads_lt_1ms":564,"lbm_write_time_us":26436,"lbm_writes_lt_1ms":543,"mutex_wait_us":71,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":11648,"update_count":2500}
I20260812 06:17:54.945181 28435 maintenance_manager.cc:419] P 333690b6a8d84b799755210a3fb160eb: Scheduling FlushDeltaMemStoresOp(317f884eb4a941df998110bf30c15aac): perf score=14.095187
I20260812 06:17:55.000854 28316 maintenance_manager.cc:643] P 333690b6a8d84b799755210a3fb160eb: FlushDeltaMemStoresOp(317f884eb4a941df998110bf30c15aac) complete. Timing: real 0.055s	user 0.036s	sys 0.016s Metrics: {"bytes_written":16409904,"delete_count":0,"lbm_write_time_us":27717,"lbm_writes_1-10_ms":2,"lbm_writes_lt_1ms":401,"reinsert_count":0,"update_count":2000}
I20260812 06:17:55.001510 28435 maintenance_manager.cc:419] P 333690b6a8d84b799755210a3fb160eb: Scheduling FlushDeltaMemStoresOp(317f884eb4a941df998110bf30c15aac): perf score=2.188937
I20260812 06:17:55.014086 28316 maintenance_manager.cc:643] P 333690b6a8d84b799755210a3fb160eb: FlushDeltaMemStoresOp(317f884eb4a941df998110bf30c15aac) complete. Timing: real 0.012s	user 0.008s	sys 0.003s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4317,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:55.014613 28435 maintenance_manager.cc:419] P 333690b6a8d84b799755210a3fb160eb: Scheduling MajorDeltaCompactionOp(317f884eb4a941df998110bf30c15aac): perf score=1.000000
I20260812 06:17:55.178045 28316 maintenance_manager.cc:643] P 333690b6a8d84b799755210a3fb160eb: MajorDeltaCompactionOp(317f884eb4a941df998110bf30c15aac) complete. Timing: real 0.163s	user 0.094s	sys 0.068s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24815686,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":551,"lbm_read_time_us":12188,"lbm_reads_lt_1ms":568,"lbm_write_time_us":25323,"lbm_writes_lt_1ms":543,"mutex_wait_us":314,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":15872,"update_count":2500}
I20260812 06:17:55.178654 28435 maintenance_manager.cc:419] P 333690b6a8d84b799755210a3fb160eb: Scheduling FlushDeltaMemStoresOp(317f884eb4a941df998110bf30c15aac): perf score=15.087375
I20260812 06:17:55.224830 28316 maintenance_manager.cc:643] P 333690b6a8d84b799755210a3fb160eb: FlushDeltaMemStoresOp(317f884eb4a941df998110bf30c15aac) complete. Timing: real 0.046s	user 0.023s	sys 0.020s Metrics: {"bytes_written":16697070,"delete_count":0,"lbm_write_time_us":16466,"lbm_writes_lt_1ms":410,"reinsert_count":0,"update_count":2035}
I20260812 06:17:55.225509 28435 maintenance_manager.cc:419] P 333690b6a8d84b799755210a3fb160eb: Scheduling FlushDeltaMemStoresOp(317f884eb4a941df998110bf30c15aac): perf score=2.188937
I20260812 06:17:55.236234 28316 maintenance_manager.cc:643] P 333690b6a8d84b799755210a3fb160eb: FlushDeltaMemStoresOp(317f884eb4a941df998110bf30c15aac) complete. Timing: real 0.011s	user 0.005s	sys 0.003s Metrics: {"bytes_written":3815484,"delete_count":0,"lbm_write_time_us":3738,"lbm_writes_lt_1ms":96,"reinsert_count":0,"update_count":465}
I20260812 06:17:55.236671 28435 maintenance_manager.cc:419] P 333690b6a8d84b799755210a3fb160eb: Scheduling FlushMRSOp(317f884eb4a941df998110bf30c15aac): perf score=1.000000
I20260812 06:17:55.264557 28316 maintenance_manager.cc:643] P 333690b6a8d84b799755210a3fb160eb: FlushMRSOp(317f884eb4a941df998110bf30c15aac) complete. Timing: real 0.028s	user 0.026s	sys 0.000s Metrics: {"bytes_written":1152512,"cfile_init":1,"dirs.queue_time_us":61,"dirs.run_cpu_time_us":205,"dirs.run_wall_time_us":1018,"drs_written":1,"lbm_read_time_us":86,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1803,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":28}
I20260812 06:17:55.265180 28435 maintenance_manager.cc:419] P 333690b6a8d84b799755210a3fb160eb: Scheduling LogGCOp(317f884eb4a941df998110bf30c15aac): free 120553384 bytes of WAL
I20260812 06:17:55.265412 28316 log_reader.cc:385] T 317f884eb4a941df998110bf30c15aac: removed 12 log segments from log reader
I20260812 06:17:55.265471 28316 log.cc:1079] T 317f884eb4a941df998110bf30c15aac P 333690b6a8d84b799755210a3fb160eb: Deleting log segment in path: /tmp/dist-test-taskdH4ppi/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515466825547-27758-0/minicluster-data/ts-0-root/wals/317f884eb4a941df998110bf30c15aac/wal-000000015 (ops 72-76)
I20260812 06:17:55.265517 28316 log.cc:1079] T 317f884eb4a941df998110bf30c15aac P 333690b6a8d84b799755210a3fb160eb: Deleting log segment in path: /tmp/dist-test-taskdH4ppi/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515466825547-27758-0/minicluster-data/ts-0-root/wals/317f884eb4a941df998110bf30c15aac/wal-000000016 (ops 77-81)
I20260812 06:17:55.265550 28316 log.cc:1079] T 317f884eb4a941df998110bf30c15aac P 333690b6a8d84b799755210a3fb160eb: Deleting log segment in path: /tmp/dist-test-taskdH4ppi/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515466825547-27758-0/minicluster-data/ts-0-root/wals/317f884eb4a941df998110bf30c15aac/wal-000000017 (ops 82-86)
I20260812 06:17:55.265591 28316 log.cc:1079] T 317f884eb4a941df998110bf30c15aac P 333690b6a8d84b799755210a3fb160eb: Deleting log segment in path: /tmp/dist-test-taskdH4ppi/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515466825547-27758-0/minicluster-data/ts-0-root/wals/317f884eb4a941df998110bf30c15aac/wal-000000018 (ops 87-91)
I20260812 06:17:55.265630 28316 log.cc:1079] T 317f884eb4a941df998110bf30c15aac P 333690b6a8d84b799755210a3fb160eb: Deleting log segment in path: /tmp/dist-test-taskdH4ppi/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515466825547-27758-0/minicluster-data/ts-0-root/wals/317f884eb4a941df998110bf30c15aac/wal-000000019 (ops 92-96)
I20260812 06:17:55.265661 28316 log.cc:1079] T 317f884eb4a941df998110bf30c15aac P 333690b6a8d84b799755210a3fb160eb: Deleting log segment in path: /tmp/dist-test-taskdH4ppi/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515466825547-27758-0/minicluster-data/ts-0-root/wals/317f884eb4a941df998110bf30c15aac/wal-000000020 (ops 97-101)
I20260812 06:17:55.265693 28316 log.cc:1079] T 317f884eb4a941df998110bf30c15aac P 333690b6a8d84b799755210a3fb160eb: Deleting log segment in path: /tmp/dist-test-taskdH4ppi/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515466825547-27758-0/minicluster-data/ts-0-root/wals/317f884eb4a941df998110bf30c15aac/wal-000000021 (ops 102-106)
I20260812 06:17:55.265726 28316 log.cc:1079] T 317f884eb4a941df998110bf30c15aac P 333690b6a8d84b799755210a3fb160eb: Deleting log segment in path: /tmp/dist-test-taskdH4ppi/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515466825547-27758-0/minicluster-data/ts-0-root/wals/317f884eb4a941df998110bf30c15aac/wal-000000022 (ops 107-110)
I20260812 06:17:55.265759 28316 log.cc:1079] T 317f884eb4a941df998110bf30c15aac P 333690b6a8d84b799755210a3fb160eb: Deleting log segment in path: /tmp/dist-test-taskdH4ppi/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515466825547-27758-0/minicluster-data/ts-0-root/wals/317f884eb4a941df998110bf30c15aac/wal-000000023 (ops 111-115)
I20260812 06:17:55.265792 28316 log.cc:1079] T 317f884eb4a941df998110bf30c15aac P 333690b6a8d84b799755210a3fb160eb: Deleting log segment in path: /tmp/dist-test-taskdH4ppi/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515466825547-27758-0/minicluster-data/ts-0-root/wals/317f884eb4a941df998110bf30c15aac/wal-000000024 (ops 116-120)
I20260812 06:17:55.265825 28316 log.cc:1079] T 317f884eb4a941df998110bf30c15aac P 333690b6a8d84b799755210a3fb160eb: Deleting log segment in path: /tmp/dist-test-taskdH4ppi/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515466825547-27758-0/minicluster-data/ts-0-root/wals/317f884eb4a941df998110bf30c15aac/wal-000000025 (ops 121-124)
I20260812 06:17:55.265857 28316 log.cc:1079] T 317f884eb4a941df998110bf30c15aac P 333690b6a8d84b799755210a3fb160eb: Deleting log segment in path: /tmp/dist-test-taskdH4ppi/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515466825547-27758-0/minicluster-data/ts-0-root/wals/317f884eb4a941df998110bf30c15aac/wal-000000026 (ops 125-129)
I20260812 06:17:55.290020 28316 maintenance_manager.cc:643] P 333690b6a8d84b799755210a3fb160eb: LogGCOp(317f884eb4a941df998110bf30c15aac) complete. Timing: real 0.025s	user 0.002s	sys 0.023s Metrics: {}
I20260812 06:17:55.290417 28435 maintenance_manager.cc:419] P 333690b6a8d84b799755210a3fb160eb: Scheduling FlushDeltaMemStoresOp(317f884eb4a941df998110bf30c15aac): perf score=3.181125
I20260812 06:17:55.302206 28316 maintenance_manager.cc:643] P 333690b6a8d84b799755210a3fb160eb: FlushDeltaMemStoresOp(317f884eb4a941df998110bf30c15aac) complete. Timing: real 0.012s	user 0.011s	sys 0.000s Metrics: {"bytes_written":4677002,"delete_count":0,"lbm_write_time_us":4311,"lbm_writes_lt_1ms":117,"reinsert_count":0,"update_count":570}
I20260812 06:17:55.302608 28435 maintenance_manager.cc:419] P 333690b6a8d84b799755210a3fb160eb: Scheduling FlushDeltaMemStoresOp(317f884eb4a941df998110bf30c15aac): perf score=2.188937
I20260812 06:17:55.315138 28316 maintenance_manager.cc:643] P 333690b6a8d84b799755210a3fb160eb: FlushDeltaMemStoresOp(317f884eb4a941df998110bf30c15aac) complete. Timing: real 0.012s	user 0.011s	sys 0.000s Metrics: {"bytes_written":3528305,"delete_count":0,"lbm_write_time_us":4696,"lbm_writes_lt_1ms":89,"reinsert_count":0,"update_count":430}
I20260812 06:17:55.315500 28435 maintenance_manager.cc:419] P 333690b6a8d84b799755210a3fb160eb: Scheduling MajorDeltaCompactionOp(317f884eb4a941df998110bf30c15aac): perf score=1.000000
I20260812 06:17:55.520761 28316 maintenance_manager.cc:643] P 333690b6a8d84b799755210a3fb160eb: MajorDeltaCompactionOp(317f884eb4a941df998110bf30c15aac) complete. Timing: real 0.205s	user 0.151s	sys 0.052s Metrics: {"cfile_cache_miss":734,"cfile_cache_miss_bytes":33020728,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":2493,"lbm_read_time_us":14322,"lbm_reads_lt_1ms":774,"lbm_write_time_us":35826,"lbm_writes_lt_1ms":743,"mutex_wait_us":47,"peak_mem_usage":87969044,"reinsert_count":0,"spinlock_wait_cycles":3712,"thread_start_us":78,"threads_started":1,"update_count":3500}
I20260812 06:17:55.521391 28435 maintenance_manager.cc:419] P 333690b6a8d84b799755210a3fb160eb: Scheduling UndoDeltaBlockGCOp(317f884eb4a941df998110bf30c15aac): 447 bytes on disk
I20260812 06:17:55.521798 28316 maintenance_manager.cc:643] P 333690b6a8d84b799755210a3fb160eb: UndoDeltaBlockGCOp(317f884eb4a941df998110bf30c15aac) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":54,"lbm_reads_lt_1ms":4}
I20260812 06:17:55.522369 28435 maintenance_manager.cc:419] P 333690b6a8d84b799755210a3fb160eb: Scheduling FlushDeltaMemStoresOp(317f884eb4a941df998110bf30c15aac): perf score=15.087375
I20260812 06:17:55.563402 28316 maintenance_manager.cc:643] P 333690b6a8d84b799755210a3fb160eb: FlushDeltaMemStoresOp(317f884eb4a941df998110bf30c15aac) complete. Timing: real 0.041s	user 0.028s	sys 0.011s Metrics: {"bytes_written":16820139,"delete_count":0,"lbm_write_time_us":17734,"lbm_writes_lt_1ms":413,"reinsert_count":0,"update_count":2050}
I20260812 06:17:55.563880 28435 maintenance_manager.cc:419] P 333690b6a8d84b799755210a3fb160eb: Scheduling FlushDeltaMemStoresOp(317f884eb4a941df998110bf30c15aac): perf score=2.188937
I20260812 06:17:55.585690 28316 maintenance_manager.cc:643] P 333690b6a8d84b799755210a3fb160eb: FlushDeltaMemStoresOp(317f884eb4a941df998110bf30c15aac) complete. Timing: real 0.022s	user 0.008s	sys 0.008s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":7969,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":92,"reinsert_count":0,"update_count":450}
I20260812 06:17:55.586231 28435 maintenance_manager.cc:419] P 333690b6a8d84b799755210a3fb160eb: Scheduling FlushDeltaMemStoresOp(317f884eb4a941df998110bf30c15aac): perf score=2.188937
I20260812 06:17:55.595810 28316 maintenance_manager.cc:643] P 333690b6a8d84b799755210a3fb160eb: FlushDeltaMemStoresOp(317f884eb4a941df998110bf30c15aac) complete. Timing: real 0.009s	user 0.008s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3604,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:55.596280 28435 maintenance_manager.cc:419] P 333690b6a8d84b799755210a3fb160eb: Scheduling MajorDeltaCompactionOp(317f884eb4a941df998110bf30c15aac): perf score=1.000000
I20260812 06:17:55.778728 28316 maintenance_manager.cc:643] P 333690b6a8d84b799755210a3fb160eb: MajorDeltaCompactionOp(317f884eb4a941df998110bf30c15aac) complete. Timing: real 0.182s	user 0.140s	sys 0.027s Metrics: {"cfile_cache_miss":633,"cfile_cache_miss_bytes":28918198,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":603,"lbm_read_time_us":10481,"lbm_reads_lt_1ms":673,"lbm_write_time_us":39877,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":642,"peak_mem_usage":75542472,"reinsert_count":0,"update_count":3000}
I20260812 06:17:55.779291 28435 maintenance_manager.cc:419] P 333690b6a8d84b799755210a3fb160eb: Scheduling FlushDeltaMemStoresOp(317f884eb4a941df998110bf30c15aac): perf score=14.095187
I20260812 06:17:55.842041 28316 maintenance_manager.cc:643] P 333690b6a8d84b799755210a3fb160eb: FlushDeltaMemStoresOp(317f884eb4a941df998110bf30c15aac) complete. Timing: real 0.057s	user 0.034s	sys 0.023s Metrics: {"bytes_written":16409899,"delete_count":0,"lbm_write_time_us":27120,"lbm_writes_1-10_ms":2,"lbm_writes_lt_1ms":401,"reinsert_count":0,"update_count":2000}
I20260812 06:17:55.842578 28435 maintenance_manager.cc:419] P 333690b6a8d84b799755210a3fb160eb: Scheduling FlushDeltaMemStoresOp(317f884eb4a941df998110bf30c15aac): perf score=2.188937
I20260812 06:17:55.858544 28316 maintenance_manager.cc:643] P 333690b6a8d84b799755210a3fb160eb: FlushDeltaMemStoresOp(317f884eb4a941df998110bf30c15aac) complete. Timing: real 0.016s	user 0.015s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5930,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:55.859251 28435 maintenance_manager.cc:419] P 333690b6a8d84b799755210a3fb160eb: Scheduling MajorDeltaCompactionOp(317f884eb4a941df998110bf30c15aac): perf score=1.000000
I20260812 06:17:56.010849 28316 maintenance_manager.cc:643] P 333690b6a8d84b799755210a3fb160eb: MajorDeltaCompactionOp(317f884eb4a941df998110bf30c15aac) complete. Timing: real 0.151s	user 0.128s	sys 0.023s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24815681,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":686,"lbm_read_time_us":11803,"lbm_reads_lt_1ms":564,"lbm_write_time_us":25099,"lbm_writes_lt_1ms":543,"mutex_wait_us":341,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":7552,"update_count":2500}
I20260812 06:17:56.011477 28435 maintenance_manager.cc:419] P 333690b6a8d84b799755210a3fb160eb: Scheduling FlushDeltaMemStoresOp(317f884eb4a941df998110bf30c15aac): perf score=10.126437
I20260812 06:17:56.056499 28316 maintenance_manager.cc:643] P 333690b6a8d84b799755210a3fb160eb: FlushDeltaMemStoresOp(317f884eb4a941df998110bf30c15aac) complete. Timing: real 0.045s	user 0.023s	sys 0.012s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":17804,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":302,"reinsert_count":0,"update_count":1500}
I20260812 06:17:56.056934 28435 maintenance_manager.cc:419] P 333690b6a8d84b799755210a3fb160eb: Scheduling MajorDeltaCompactionOp(317f884eb4a941df998110bf30c15aac): perf score=1.000000
I20260812 06:17:56.174454 28316 maintenance_manager.cc:643] P 333690b6a8d84b799755210a3fb160eb: MajorDeltaCompactionOp(317f884eb4a941df998110bf30c15aac) complete. Timing: real 0.117s	user 0.094s	sys 0.022s Metrics: {"cfile_cache_miss":331,"cfile_cache_miss_bytes":16610741,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":1,"delta_iterators_relevant":1,"dirs.queue_time_us":1455,"lbm_read_time_us":8413,"lbm_reads_lt_1ms":363,"lbm_write_time_us":18516,"lbm_writes_lt_1ms":343,"mutex_wait_us":426,"peak_mem_usage":38262756,"reinsert_count":0,"update_count":1500}
I20260812 06:17:56.174961 28435 maintenance_manager.cc:419] P 333690b6a8d84b799755210a3fb160eb: Scheduling FlushDeltaMemStoresOp(317f884eb4a941df998110bf30c15aac): perf score=10.126437
I20260812 06:17:56.217116 28316 maintenance_manager.cc:643] P 333690b6a8d84b799755210a3fb160eb: FlushDeltaMemStoresOp(317f884eb4a941df998110bf30c15aac) complete. Timing: real 0.042s	user 0.024s	sys 0.014s Metrics: {"bytes_written":12307491,"delete_count":0,"lbm_write_time_us":19509,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":302,"reinsert_count":0,"update_count":1500}
I20260812 06:17:56.217743 28435 maintenance_manager.cc:419] P 333690b6a8d84b799755210a3fb160eb: Scheduling FlushDeltaMemStoresOp(317f884eb4a941df998110bf30c15aac): perf score=2.188937
I20260812 06:17:56.229131 28316 maintenance_manager.cc:643] P 333690b6a8d84b799755210a3fb160eb: FlushDeltaMemStoresOp(317f884eb4a941df998110bf30c15aac) complete. Timing: real 0.011s	user 0.004s	sys 0.005s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4439,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:56.229545 28435 maintenance_manager.cc:419] P 333690b6a8d84b799755210a3fb160eb: Scheduling MajorDeltaCompactionOp(317f884eb4a941df998110bf30c15aac): perf score=1.000000
I20260812 06:17:56.364281 28316 maintenance_manager.cc:643] P 333690b6a8d84b799755210a3fb160eb: MajorDeltaCompactionOp(317f884eb4a941df998110bf30c15aac) complete. Timing: real 0.135s	user 0.106s	sys 0.026s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20713273,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":1173,"lbm_read_time_us":7865,"lbm_reads_lt_1ms":472,"lbm_write_time_us":26222,"lbm_writes_lt_1ms":443,"mutex_wait_us":309,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":1792,"update_count":2000}
I20260812 06:17:56.364826 28435 maintenance_manager.cc:419] P 333690b6a8d84b799755210a3fb160eb: Scheduling FlushDeltaMemStoresOp(317f884eb4a941df998110bf30c15aac): perf score=11.118625
I20260812 06:17:56.392617 28316 maintenance_manager.cc:643] P 333690b6a8d84b799755210a3fb160eb: FlushDeltaMemStoresOp(317f884eb4a941df998110bf30c15aac) complete. Timing: real 0.028s	user 0.016s	sys 0.009s Metrics: {"bytes_written":12717735,"delete_count":0,"lbm_write_time_us":12139,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:17:56.393168 28435 maintenance_manager.cc:419] P 333690b6a8d84b799755210a3fb160eb: Scheduling FlushDeltaMemStoresOp(317f884eb4a941df998110bf30c15aac): perf score=2.188937
I20260812 06:17:56.402906 28316 maintenance_manager.cc:643] P 333690b6a8d84b799755210a3fb160eb: FlushDeltaMemStoresOp(317f884eb4a941df998110bf30c15aac) complete. Timing: real 0.010s	user 0.007s	sys 0.001s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3206,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:17:56.403594 28435 maintenance_manager.cc:419] P 333690b6a8d84b799755210a3fb160eb: Scheduling MajorDeltaCompactionOp(317f884eb4a941df998110bf30c15aac): perf score=1.000000
I20260812 06:17:56.526333 28316 maintenance_manager.cc:643] P 333690b6a8d84b799755210a3fb160eb: MajorDeltaCompactionOp(317f884eb4a941df998110bf30c15aac) complete. Timing: real 0.123s	user 0.093s	sys 0.029s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20713263,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":103,"lbm_read_time_us":7838,"lbm_reads_lt_1ms":472,"lbm_write_time_us":25071,"lbm_writes_lt_1ms":443,"mutex_wait_us":22,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":14208,"update_count":2000}
I20260812 06:17:56.527071 28435 maintenance_manager.cc:419] P 333690b6a8d84b799755210a3fb160eb: Scheduling FlushDeltaMemStoresOp(317f884eb4a941df998110bf30c15aac): perf score=10.126437
I20260812 06:17:56.571135 28316 maintenance_manager.cc:643] P 333690b6a8d84b799755210a3fb160eb: FlushDeltaMemStoresOp(317f884eb4a941df998110bf30c15aac) complete. Timing: real 0.044s	user 0.026s	sys 0.015s Metrics: {"bytes_written":12307492,"delete_count":0,"lbm_write_time_us":15368,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:17:56.571619 28435 maintenance_manager.cc:419] P 333690b6a8d84b799755210a3fb160eb: Scheduling FlushDeltaMemStoresOp(317f884eb4a941df998110bf30c15aac): perf score=2.188937
I20260812 06:17:56.581763 28316 maintenance_manager.cc:643] P 333690b6a8d84b799755210a3fb160eb: FlushDeltaMemStoresOp(317f884eb4a941df998110bf30c15aac) complete. Timing: real 0.010s	user 0.000s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4004,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:56.582278 28435 maintenance_manager.cc:419] P 333690b6a8d84b799755210a3fb160eb: Scheduling FlushMRSOp(317f884eb4a941df998110bf30c15aac): perf score=1.000000
I20260812 06:17:56.621333 28316 maintenance_manager.cc:643] P 333690b6a8d84b799755210a3fb160eb: FlushMRSOp(317f884eb4a941df998110bf30c15aac) complete. Timing: real 0.039s	user 0.026s	sys 0.000s Metrics: {"bytes_written":1152510,"cfile_init":1,"dirs.queue_time_us":60,"dirs.run_cpu_time_us":200,"dirs.run_wall_time_us":1124,"drs_written":1,"lbm_read_time_us":38,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1310,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":28}
I20260812 06:17:56.622112 28435 maintenance_manager.cc:419] P 333690b6a8d84b799755210a3fb160eb: Scheduling LogGCOp(317f884eb4a941df998110bf30c15aac): free 112239569 bytes of WAL
I20260812 06:17:56.622331 28316 log_reader.cc:385] T 317f884eb4a941df998110bf30c15aac: removed 11 log segments from log reader
I20260812 06:17:56.622392 28316 log.cc:1079] T 317f884eb4a941df998110bf30c15aac P 333690b6a8d84b799755210a3fb160eb: Deleting log segment in path: /tmp/dist-test-taskdH4ppi/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515466825547-27758-0/minicluster-data/ts-0-root/wals/317f884eb4a941df998110bf30c15aac/wal-000000027 (ops 130-134)
I20260812 06:17:56.622437 28316 log.cc:1079] T 317f884eb4a941df998110bf30c15aac P 333690b6a8d84b799755210a3fb160eb: Deleting log segment in path: /tmp/dist-test-taskdH4ppi/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515466825547-27758-0/minicluster-data/ts-0-root/wals/317f884eb4a941df998110bf30c15aac/wal-000000028 (ops 135-138)
I20260812 06:17:56.622471 28316 log.cc:1079] T 317f884eb4a941df998110bf30c15aac P 333690b6a8d84b799755210a3fb160eb: Deleting log segment in path: /tmp/dist-test-taskdH4ppi/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515466825547-27758-0/minicluster-data/ts-0-root/wals/317f884eb4a941df998110bf30c15aac/wal-000000029 (ops 139-143)
I20260812 06:17:56.622500 28316 log.cc:1079] T 317f884eb4a941df998110bf30c15aac P 333690b6a8d84b799755210a3fb160eb: Deleting log segment in path: /tmp/dist-test-taskdH4ppi/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515466825547-27758-0/minicluster-data/ts-0-root/wals/317f884eb4a941df998110bf30c15aac/wal-000000030 (ops 144-148)
I20260812 06:17:56.622529 28316 log.cc:1079] T 317f884eb4a941df998110bf30c15aac P 333690b6a8d84b799755210a3fb160eb: Deleting log segment in path: /tmp/dist-test-taskdH4ppi/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515466825547-27758-0/minicluster-data/ts-0-root/wals/317f884eb4a941df998110bf30c15aac/wal-000000031 (ops 149-153)
I20260812 06:17:56.622555 28316 log.cc:1079] T 317f884eb4a941df998110bf30c15aac P 333690b6a8d84b799755210a3fb160eb: Deleting log segment in path: /tmp/dist-test-taskdH4ppi/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515466825547-27758-0/minicluster-data/ts-0-root/wals/317f884eb4a941df998110bf30c15aac/wal-000000032 (ops 154-158)
I20260812 06:17:56.622578 28316 log.cc:1079] T 317f884eb4a941df998110bf30c15aac P 333690b6a8d84b799755210a3fb160eb: Deleting log segment in path: /tmp/dist-test-taskdH4ppi/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515466825547-27758-0/minicluster-data/ts-0-root/wals/317f884eb4a941df998110bf30c15aac/wal-000000033 (ops 159-163)
I20260812 06:17:56.622609 28316 log.cc:1079] T 317f884eb4a941df998110bf30c15aac P 333690b6a8d84b799755210a3fb160eb: Deleting log segment in path: /tmp/dist-test-taskdH4ppi/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515466825547-27758-0/minicluster-data/ts-0-root/wals/317f884eb4a941df998110bf30c15aac/wal-000000034 (ops 164-168)
I20260812 06:17:56.622641 28316 log.cc:1079] T 317f884eb4a941df998110bf30c15aac P 333690b6a8d84b799755210a3fb160eb: Deleting log segment in path: /tmp/dist-test-taskdH4ppi/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515466825547-27758-0/minicluster-data/ts-0-root/wals/317f884eb4a941df998110bf30c15aac/wal-000000035 (ops 169-173)
I20260812 06:17:56.622669 28316 log.cc:1079] T 317f884eb4a941df998110bf30c15aac P 333690b6a8d84b799755210a3fb160eb: Deleting log segment in path: /tmp/dist-test-taskdH4ppi/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515466825547-27758-0/minicluster-data/ts-0-root/wals/317f884eb4a941df998110bf30c15aac/wal-000000036 (ops 174-178)
I20260812 06:17:56.622697 28316 log.cc:1079] T 317f884eb4a941df998110bf30c15aac P 333690b6a8d84b799755210a3fb160eb: Deleting log segment in path: /tmp/dist-test-taskdH4ppi/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515466825547-27758-0/minicluster-data/ts-0-root/wals/317f884eb4a941df998110bf30c15aac/wal-000000037 (ops 179-183)
I20260812 06:17:56.647245 28316 maintenance_manager.cc:643] P 333690b6a8d84b799755210a3fb160eb: LogGCOp(317f884eb4a941df998110bf30c15aac) complete. Timing: real 0.025s	user 0.000s	sys 0.024s Metrics: {}
I20260812 06:17:56.647698 28435 maintenance_manager.cc:419] P 333690b6a8d84b799755210a3fb160eb: Scheduling FlushDeltaMemStoresOp(317f884eb4a941df998110bf30c15aac): perf score=3.181125
I20260812 06:17:56.669605 28316 maintenance_manager.cc:643] P 333690b6a8d84b799755210a3fb160eb: FlushDeltaMemStoresOp(317f884eb4a941df998110bf30c15aac) complete. Timing: real 0.022s	user 0.011s	sys 0.004s Metrics: {"bytes_written":4512900,"delete_count":0,"lbm_write_time_us":6886,"lbm_writes_lt_1ms":113,"reinsert_count":0,"update_count":550}
I20260812 06:17:56.670032 28435 maintenance_manager.cc:419] P 333690b6a8d84b799755210a3fb160eb: Scheduling FlushDeltaMemStoresOp(317f884eb4a941df998110bf30c15aac): perf score=2.188937
I20260812 06:17:56.679152 28316 maintenance_manager.cc:643] P 333690b6a8d84b799755210a3fb160eb: FlushDeltaMemStoresOp(317f884eb4a941df998110bf30c15aac) complete. Timing: real 0.009s	user 0.007s	sys 0.001s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3420,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:17:56.679576 28435 maintenance_manager.cc:419] P 333690b6a8d84b799755210a3fb160eb: Scheduling UndoDeltaBlockGCOp(317f884eb4a941df998110bf30c15aac): 447 bytes on disk
I20260812 06:17:56.679946 28316 maintenance_manager.cc:643] P 333690b6a8d84b799755210a3fb160eb: UndoDeltaBlockGCOp(317f884eb4a941df998110bf30c15aac) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":46,"lbm_reads_lt_1ms":4}
I20260812 06:17:56.680711 28435 maintenance_manager.cc:419] P 333690b6a8d84b799755210a3fb160eb: Scheduling MajorDeltaCompactionOp(317f884eb4a941df998110bf30c15aac): perf score=1.000000
I20260812 06:17:56.872323 28316 maintenance_manager.cc:643] P 333690b6a8d84b799755210a3fb160eb: MajorDeltaCompactionOp(317f884eb4a941df998110bf30c15aac) complete. Timing: real 0.191s	user 0.124s	sys 0.067s Metrics: {"cfile_cache_miss":634,"cfile_cache_miss_bytes":28918323,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":102,"lbm_read_time_us":14513,"lbm_reads_lt_1ms":674,"lbm_write_time_us":29679,"lbm_writes_lt_1ms":643,"mutex_wait_us":21,"peak_mem_usage":75542472,"reinsert_count":0,"thread_start_us":70,"threads_started":1,"update_count":3000}
I20260812 06:17:56.874400 28435 maintenance_manager.cc:419] P 333690b6a8d84b799755210a3fb160eb: Scheduling FlushDeltaMemStoresOp(317f884eb4a941df998110bf30c15aac): perf score=15.087375
I20260812 06:17:56.926885 28316 maintenance_manager.cc:643] P 333690b6a8d84b799755210a3fb160eb: FlushDeltaMemStoresOp(317f884eb4a941df998110bf30c15aac) complete. Timing: real 0.052s	user 0.027s	sys 0.020s Metrics: {"bytes_written":16574000,"delete_count":0,"lbm_write_time_us":21503,"lbm_writes_lt_1ms":407,"reinsert_count":0,"update_count":2020}
I20260812 06:17:56.927412 28435 maintenance_manager.cc:419] P 333690b6a8d84b799755210a3fb160eb: Scheduling FlushDeltaMemStoresOp(317f884eb4a941df998110bf30c15aac): perf score=2.188937
I20260812 06:17:56.936631 28316 maintenance_manager.cc:643] P 333690b6a8d84b799755210a3fb160eb: FlushDeltaMemStoresOp(317f884eb4a941df998110bf30c15aac) complete. Timing: real 0.009s	user 0.008s	sys 0.000s Metrics: {"bytes_written":3938559,"delete_count":0,"lbm_write_time_us":3534,"lbm_writes_lt_1ms":99,"reinsert_count":0,"update_count":480}
I20260812 06:17:56.937041 28435 maintenance_manager.cc:419] P 333690b6a8d84b799755210a3fb160eb: Scheduling MajorDeltaCompactionOp(317f884eb4a941df998110bf30c15aac): perf score=1.000000
I20260812 06:17:56.967677 27758 heavy-update-compaction-itest.cc:229] Time spent updating: real 4.652s	user 1.653s	sys 0.145s
I20260812 06:17:57.030197 27758 heavy-update-compaction-itest.cc:265] Time spent scanning: real 0.062s	user 0.003s	sys 0.000s
I20260812 06:17:57.030772 27758 tablet_server.cc:179] TabletServer@127.27.27.129:0 shutting down...
I20260812 06:17:57.081343 28316 maintenance_manager.cc:643] P 333690b6a8d84b799755210a3fb160eb: MajorDeltaCompactionOp(317f884eb4a941df998110bf30c15aac) complete. Timing: real 0.144s	user 0.095s	sys 0.047s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24815682,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":318,"lbm_read_time_us":12090,"lbm_reads_lt_1ms":568,"lbm_write_time_us":24124,"lbm_writes_lt_1ms":543,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":4608,"update_count":2500}
I20260812 06:17:57.082211 27758 ts_tablet_manager.cc:1507] Shutting down tablet manager...
I20260812 06:17:57.082418 27758 tablet_replica.cc:333] T 317f884eb4a941df998110bf30c15aac P 333690b6a8d84b799755210a3fb160eb: stopping tablet replica
I20260812 06:17:57.082544 27758 raft_consensus.cc:2243] T 317f884eb4a941df998110bf30c15aac P 333690b6a8d84b799755210a3fb160eb [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:17:57.082700 27758 raft_consensus.cc:2272] T 317f884eb4a941df998110bf30c15aac P 333690b6a8d84b799755210a3fb160eb [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:17:57.097311 27758 tablet_server.cc:196] TabletServer@127.27.27.129:0 shutdown complete.
I20260812 06:17:57.128372 27758 master.cc:562] Master@127.27.27.190:39811 shutting down...
I20260812 06:17:57.131775 27758 raft_consensus.cc:2243] T 00000000000000000000000000000000 P c8170d81f0c343c3b30a48d66a53fe86 [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:17:57.131953 27758 raft_consensus.cc:2272] T 00000000000000000000000000000000 P c8170d81f0c343c3b30a48d66a53fe86 [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:17:57.132018 27758 tablet_replica.cc:333] T 00000000000000000000000000000000 P c8170d81f0c343c3b30a48d66a53fe86: stopping tablet replica
I20260812 06:17:57.144994 27758 master.cc:584] Master@127.27.27.190:39811 shutdown complete.
[       OK ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/1 (5100 ms)
[----------] 2 tests from EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy (10382 ms total)

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