[==========] 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:25.515122 25086 internal_mini_cluster.cc:156] Creating distributed mini masters. Addrs: 127.24.127.190:45463
I20260812 06:17:25.516170 25086 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:25.516870 25086 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:17:25.523267 25094 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:25.523268 25095 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:25.523571 25086 server_base.cc:1061] running on GCE node
W20260812 06:17:25.523576 25099 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:25.524276 25086 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:17:25.524398 25086 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:25.524462 25086 hybrid_clock.cc:648] HybridClock initialized: now 1786515445524459 us; error 0 us; skew 500 ppm
I20260812 06:17:25.526232 25086 webserver.cc:533] Webserver started at http://127.24.127.190:39543/ using document root <none> and password file <none>
I20260812 06:17:25.526796 25086 fs_manager.cc:362] Metadata directory not provided
I20260812 06:17:25.526889 25086 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:17:25.527158 25086 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:17:25.528923 25086 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskQFXsto/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515445504383-25086-0/minicluster-data/master-0-root/instance:
uuid: "e50fd6b907a94ddea10be5e38edfdbf4"
format_stamp: "Formatted at 2026-08-12 06:17:25 on dist-test-slave-t3q3"
I20260812 06:17:25.532653 25086 fs_manager.cc:696] Time spent creating directory manager: real 0.003s	user 0.003s	sys 0.001s
I20260812 06:17:25.534756 25105 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:25.535763 25086 fs_manager.cc:730] Time spent opening block manager: real 0.002s	user 0.002s	sys 0.000s
I20260812 06:17:25.535897 25086 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskQFXsto/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515445504383-25086-0/minicluster-data/master-0-root
uuid: "e50fd6b907a94ddea10be5e38edfdbf4"
format_stamp: "Formatted at 2026-08-12 06:17:25 on dist-test-slave-t3q3"
I20260812 06:17:25.536007 25086 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskQFXsto/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515445504383-25086-0/minicluster-data/master-0-root
metadata directory: /tmp/dist-test-taskQFXsto/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515445504383-25086-0/minicluster-data/master-0-root
1 data directories: /tmp/dist-test-taskQFXsto/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515445504383-25086-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:25.547533 25086 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:17:25.548249 25086 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:25.548421 25086 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:17:25.555965 25086 rpc_server.cc:307] RPC server started. Bound to: 127.24.127.190:45463
I20260812 06:17:25.555989 25189 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.24.127.190:45463 every 8 connection(s)
I20260812 06:17:25.558283 25193 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:25.563705 25193 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P e50fd6b907a94ddea10be5e38edfdbf4: Bootstrap starting.
I20260812 06:17:25.566126 25193 tablet_bootstrap.cc:654] T 00000000000000000000000000000000 P e50fd6b907a94ddea10be5e38edfdbf4: Neither blocks nor log segments found. Creating new log.
I20260812 06:17:25.566970 25193 log.cc:826] T 00000000000000000000000000000000 P e50fd6b907a94ddea10be5e38edfdbf4: Log is configured to *not* fsync() on all Append() calls
I20260812 06:17:25.568778 25193 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P e50fd6b907a94ddea10be5e38edfdbf4: No bootstrap required, opened a new log
I20260812 06:17:25.571548 25193 raft_consensus.cc:359] T 00000000000000000000000000000000 P e50fd6b907a94ddea10be5e38edfdbf4 [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "e50fd6b907a94ddea10be5e38edfdbf4" member_type: VOTER }
I20260812 06:17:25.571717 25193 raft_consensus.cc:385] T 00000000000000000000000000000000 P e50fd6b907a94ddea10be5e38edfdbf4 [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:17:25.571758 25193 raft_consensus.cc:740] T 00000000000000000000000000000000 P e50fd6b907a94ddea10be5e38edfdbf4 [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: e50fd6b907a94ddea10be5e38edfdbf4, State: Initialized, Role: FOLLOWER
I20260812 06:17:25.572369 25193 consensus_queue.cc:260] T 00000000000000000000000000000000 P e50fd6b907a94ddea10be5e38edfdbf4 [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: "e50fd6b907a94ddea10be5e38edfdbf4" member_type: VOTER }
I20260812 06:17:25.572510 25193 raft_consensus.cc:399] T 00000000000000000000000000000000 P e50fd6b907a94ddea10be5e38edfdbf4 [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:17:25.572556 25193 raft_consensus.cc:493] T 00000000000000000000000000000000 P e50fd6b907a94ddea10be5e38edfdbf4 [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:17:25.572650 25193 raft_consensus.cc:3060] T 00000000000000000000000000000000 P e50fd6b907a94ddea10be5e38edfdbf4 [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:17:25.573428 25193 raft_consensus.cc:515] T 00000000000000000000000000000000 P e50fd6b907a94ddea10be5e38edfdbf4 [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "e50fd6b907a94ddea10be5e38edfdbf4" member_type: VOTER }
I20260812 06:17:25.573817 25193 leader_election.cc:304] T 00000000000000000000000000000000 P e50fd6b907a94ddea10be5e38edfdbf4 [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: e50fd6b907a94ddea10be5e38edfdbf4; no voters: 
I20260812 06:17:25.574090 25193 leader_election.cc:290] T 00000000000000000000000000000000 P e50fd6b907a94ddea10be5e38edfdbf4 [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:17:25.574265 25196 raft_consensus.cc:2804] T 00000000000000000000000000000000 P e50fd6b907a94ddea10be5e38edfdbf4 [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:17:25.574546 25196 raft_consensus.cc:697] T 00000000000000000000000000000000 P e50fd6b907a94ddea10be5e38edfdbf4 [term 1 LEADER]: Becoming Leader. State: Replica: e50fd6b907a94ddea10be5e38edfdbf4, State: Running, Role: LEADER
I20260812 06:17:25.574944 25196 consensus_queue.cc:237] T 00000000000000000000000000000000 P e50fd6b907a94ddea10be5e38edfdbf4 [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: "e50fd6b907a94ddea10be5e38edfdbf4" member_type: VOTER }
I20260812 06:17:25.575120 25193 sys_catalog.cc:565] T 00000000000000000000000000000000 P e50fd6b907a94ddea10be5e38edfdbf4 [sys.catalog]: configured and running, proceeding with master startup.
I20260812 06:17:25.577024 25200 sys_catalog.cc:455] T 00000000000000000000000000000000 P e50fd6b907a94ddea10be5e38edfdbf4 [sys.catalog]: SysCatalogTable state changed. Reason: New leader e50fd6b907a94ddea10be5e38edfdbf4. Latest consensus state: current_term: 1 leader_uuid: "e50fd6b907a94ddea10be5e38edfdbf4" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "e50fd6b907a94ddea10be5e38edfdbf4" member_type: VOTER } }
I20260812 06:17:25.577020 25197 sys_catalog.cc:455] T 00000000000000000000000000000000 P e50fd6b907a94ddea10be5e38edfdbf4 [sys.catalog]: SysCatalogTable state changed. Reason: RaftConsensus started. Latest consensus state: current_term: 1 leader_uuid: "e50fd6b907a94ddea10be5e38edfdbf4" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "e50fd6b907a94ddea10be5e38edfdbf4" member_type: VOTER } }
I20260812 06:17:25.577183 25200 sys_catalog.cc:458] T 00000000000000000000000000000000 P e50fd6b907a94ddea10be5e38edfdbf4 [sys.catalog]: This master's current role is: LEADER
I20260812 06:17:25.577183 25197 sys_catalog.cc:458] T 00000000000000000000000000000000 P e50fd6b907a94ddea10be5e38edfdbf4 [sys.catalog]: This master's current role is: LEADER
I20260812 06:17:25.577474 25086 internal_mini_cluster.cc:184] Waiting to initialize catalog manager on master 0
I20260812 06:17:25.577570 25220 catalog_manager.cc:1511] Loading table and tablet metadata into memory...
I20260812 06:17:25.580226 25220 catalog_manager.cc:1520] Initializing Kudu cluster ID...
I20260812 06:17:25.585120 25220 catalog_manager.cc:1383] Generated new cluster ID: 04a168d6ffb94bcdabd220c784377040
I20260812 06:17:25.585201 25220 catalog_manager.cc:1531] Initializing Kudu internal certificate authority...
I20260812 06:17:25.597859 25220 catalog_manager.cc:1406] Generated new certificate authority record
I20260812 06:17:25.598743 25220 catalog_manager.cc:1540] Loading token signing keys...
I20260812 06:17:25.606319 25220 catalog_manager.cc:6092] T 00000000000000000000000000000000 P e50fd6b907a94ddea10be5e38edfdbf4: Generated new TSK 0
I20260812 06:17:25.606971 25220 catalog_manager.cc:1550] Initializing in-progress tserver states...
I20260812 06:17:25.609913 25086 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:17:25.612694 25226 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:25.612823 25231 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:25.612710 25229 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:25.613121 25086 server_base.cc:1061] running on GCE node
I20260812 06:17:25.613296 25086 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:17:25.613344 25086 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:25.613368 25086 hybrid_clock.cc:648] HybridClock initialized: now 1786515445613366 us; error 0 us; skew 500 ppm
I20260812 06:17:25.614355 25086 webserver.cc:533] Webserver started at http://127.24.127.129:35749/ using document root <none> and password file <none>
I20260812 06:17:25.614531 25086 fs_manager.cc:362] Metadata directory not provided
I20260812 06:17:25.614593 25086 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:17:25.614673 25086 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:17:25.615123 25086 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskQFXsto/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515445504383-25086-0/minicluster-data/ts-0-root/instance:
uuid: "dd4f23643a31400496a29615ad83678d"
format_stamp: "Formatted at 2026-08-12 06:17:25 on dist-test-slave-t3q3"
I20260812 06:17:25.617125 25086 fs_manager.cc:696] Time spent creating directory manager: real 0.002s	user 0.000s	sys 0.002s
I20260812 06:17:25.618460 25237 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:25.618772 25086 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.000s	sys 0.001s
I20260812 06:17:25.618856 25086 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskQFXsto/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515445504383-25086-0/minicluster-data/ts-0-root
uuid: "dd4f23643a31400496a29615ad83678d"
format_stamp: "Formatted at 2026-08-12 06:17:25 on dist-test-slave-t3q3"
I20260812 06:17:25.618923 25086 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskQFXsto/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515445504383-25086-0/minicluster-data/ts-0-root
metadata directory: /tmp/dist-test-taskQFXsto/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515445504383-25086-0/minicluster-data/ts-0-root
1 data directories: /tmp/dist-test-taskQFXsto/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515445504383-25086-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:25.631834 25086 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:17:25.632371 25086 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:17:25.632911 25086 txn_system_client.cc:432] TxnSystemClient initialization is disabled...
I20260812 06:17:25.633978 25086 ts_tablet_manager.cc:585] Loaded tablet metadata (0 total tablets, 0 live tablets)
I20260812 06:17:25.634044 25086 ts_tablet_manager.cc:531] Time spent load tablet metadata: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:17:25.634100 25086 ts_tablet_manager.cc:616] Registered 0 tablets
I20260812 06:17:25.634131 25086 ts_tablet_manager.cc:595] Time spent register tablets: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:17:25.641551 25086 rpc_server.cc:307] RPC server started. Bound to: 127.24.127.129:34881
I20260812 06:17:25.641644 25328 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.24.127.129:34881 every 8 connection(s)
I20260812 06:17:25.655308 25334 heartbeater.cc:344] Connected to a master server at 127.24.127.190:45463
I20260812 06:17:25.655586 25334 heartbeater.cc:461] Registering TS with master...
I20260812 06:17:25.656104 25334 heartbeater.cc:507] Master 127.24.127.190:45463 requested a full tablet report, sending...
I20260812 06:17:25.657532 25126 ts_manager.cc:194] Registered new tserver with Master: dd4f23643a31400496a29615ad83678d (127.24.127.129:34881)
I20260812 06:17:25.657912 25086 internal_mini_cluster.cc:371] 1 TS(s) registered with all masters after 0.015680102s
I20260812 06:17:25.658795 25126 master_service.cc:502] Signed X509 certificate for tserver {username='slave'} at 127.0.0.1:42314
I20260812 06:17:25.667799 25126 catalog_manager.cc:2283] Servicing CreateTable request from {username='slave'} at 127.0.0.1:42324:
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:25.684815 25271 tablet_service.cc:1511] Processing CreateTablet for tablet 13c3836bf0214c5cbe44fbdefce90bfd (DEFAULT_TABLE table=heavy-update-compaction-test [id=d207e14d81a4430d91f375e2ecb2b472]), partition=
I20260812 06:17:25.685339 25271 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet 13c3836bf0214c5cbe44fbdefce90bfd. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:17:25.687618 25357 tablet_bootstrap.cc:492] T 13c3836bf0214c5cbe44fbdefce90bfd P dd4f23643a31400496a29615ad83678d: Bootstrap starting.
I20260812 06:17:25.688601 25357 tablet_bootstrap.cc:654] T 13c3836bf0214c5cbe44fbdefce90bfd P dd4f23643a31400496a29615ad83678d: Neither blocks nor log segments found. Creating new log.
I20260812 06:17:25.689958 25357 tablet_bootstrap.cc:492] T 13c3836bf0214c5cbe44fbdefce90bfd P dd4f23643a31400496a29615ad83678d: No bootstrap required, opened a new log
I20260812 06:17:25.690066 25357 ts_tablet_manager.cc:1403] T 13c3836bf0214c5cbe44fbdefce90bfd P dd4f23643a31400496a29615ad83678d: Time spent bootstrapping tablet: real 0.003s	user 0.000s	sys 0.002s
I20260812 06:17:25.690572 25357 raft_consensus.cc:359] T 13c3836bf0214c5cbe44fbdefce90bfd P dd4f23643a31400496a29615ad83678d [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "dd4f23643a31400496a29615ad83678d" member_type: VOTER last_known_addr { host: "127.24.127.129" port: 34881 } }
I20260812 06:17:25.690703 25357 raft_consensus.cc:385] T 13c3836bf0214c5cbe44fbdefce90bfd P dd4f23643a31400496a29615ad83678d [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:17:25.690752 25357 raft_consensus.cc:740] T 13c3836bf0214c5cbe44fbdefce90bfd P dd4f23643a31400496a29615ad83678d [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: dd4f23643a31400496a29615ad83678d, State: Initialized, Role: FOLLOWER
I20260812 06:17:25.690886 25357 consensus_queue.cc:260] T 13c3836bf0214c5cbe44fbdefce90bfd P dd4f23643a31400496a29615ad83678d [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: "dd4f23643a31400496a29615ad83678d" member_type: VOTER last_known_addr { host: "127.24.127.129" port: 34881 } }
I20260812 06:17:25.690982 25357 raft_consensus.cc:399] T 13c3836bf0214c5cbe44fbdefce90bfd P dd4f23643a31400496a29615ad83678d [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:17:25.691020 25357 raft_consensus.cc:493] T 13c3836bf0214c5cbe44fbdefce90bfd P dd4f23643a31400496a29615ad83678d [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:17:25.691068 25357 raft_consensus.cc:3060] T 13c3836bf0214c5cbe44fbdefce90bfd P dd4f23643a31400496a29615ad83678d [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:17:25.692203 25357 raft_consensus.cc:515] T 13c3836bf0214c5cbe44fbdefce90bfd P dd4f23643a31400496a29615ad83678d [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "dd4f23643a31400496a29615ad83678d" member_type: VOTER last_known_addr { host: "127.24.127.129" port: 34881 } }
I20260812 06:17:25.692358 25357 leader_election.cc:304] T 13c3836bf0214c5cbe44fbdefce90bfd P dd4f23643a31400496a29615ad83678d [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: dd4f23643a31400496a29615ad83678d; no voters: 
I20260812 06:17:25.692574 25357 leader_election.cc:290] T 13c3836bf0214c5cbe44fbdefce90bfd P dd4f23643a31400496a29615ad83678d [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:17:25.692736 25359 raft_consensus.cc:2804] T 13c3836bf0214c5cbe44fbdefce90bfd P dd4f23643a31400496a29615ad83678d [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:17:25.692896 25357 ts_tablet_manager.cc:1434] T 13c3836bf0214c5cbe44fbdefce90bfd P dd4f23643a31400496a29615ad83678d: Time spent starting tablet: real 0.003s	user 0.000s	sys 0.003s
I20260812 06:17:25.693012 25359 raft_consensus.cc:697] T 13c3836bf0214c5cbe44fbdefce90bfd P dd4f23643a31400496a29615ad83678d [term 1 LEADER]: Becoming Leader. State: Replica: dd4f23643a31400496a29615ad83678d, State: Running, Role: LEADER
I20260812 06:17:25.693159 25334 heartbeater.cc:499] Master 127.24.127.190:45463 was elected leader, sending a full tablet report...
I20260812 06:17:25.693229 25359 consensus_queue.cc:237] T 13c3836bf0214c5cbe44fbdefce90bfd P dd4f23643a31400496a29615ad83678d [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: "dd4f23643a31400496a29615ad83678d" member_type: VOTER last_known_addr { host: "127.24.127.129" port: 34881 } }
I20260812 06:17:25.695988 25126 catalog_manager.cc:5719] T 13c3836bf0214c5cbe44fbdefce90bfd P dd4f23643a31400496a29615ad83678d reported cstate change: term changed from 0 to 1, leader changed from <none> to dd4f23643a31400496a29615ad83678d (127.24.127.129). New cstate: current_term: 1 leader_uuid: "dd4f23643a31400496a29615ad83678d" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "dd4f23643a31400496a29615ad83678d" member_type: VOTER last_known_addr { host: "127.24.127.129" port: 34881 } health_report { overall_health: HEALTHY } } }
I20260812 06:17:25.773217 25086 heavy-update-compaction-itest.cc:215] Time spent inserting: real 0.071s	user 0.024s	sys 0.003s
I20260812 06:17:25.892736 25338 maintenance_manager.cc:419] P dd4f23643a31400496a29615ad83678d: Scheduling FlushMRSOp(13c3836bf0214c5cbe44fbdefce90bfd): perf score=15.086190
I20260812 06:17:26.053022 25245 maintenance_manager.cc:643] P dd4f23643a31400496a29615ad83678d: FlushMRSOp(13c3836bf0214c5cbe44fbdefce90bfd) complete. Timing: real 0.160s	user 0.107s	sys 0.045s Metrics: {"bytes_written":12307490,"cfile_init":1,"compiler_manager_pool.queue_time_us":83,"delete_count":0,"dirs.queue_time_us":78,"dirs.run_cpu_time_us":241,"dirs.run_wall_time_us":913,"drs_written":1,"lbm_read_time_us":78,"lbm_reads_lt_1ms":4,"lbm_write_time_us":36915,"lbm_writes_lt_1ms":657,"peak_mem_usage":0,"reinsert_count":0,"rows_written":103,"update_count":1500}
I20260812 06:17:26.054193 25338 maintenance_manager.cc:419] P dd4f23643a31400496a29615ad83678d: Scheduling LogGCOp(13c3836bf0214c5cbe44fbdefce90bfd): free 11976772 bytes of WAL
I20260812 06:17:26.054493 25245 log_reader.cc:385] T 13c3836bf0214c5cbe44fbdefce90bfd: removed 1 log segments from log reader
I20260812 06:17:26.054564 25245 log.cc:1079] T 13c3836bf0214c5cbe44fbdefce90bfd P dd4f23643a31400496a29615ad83678d: Deleting log segment in path: /tmp/dist-test-taskQFXsto/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515445504383-25086-0/minicluster-data/ts-0-root/wals/13c3836bf0214c5cbe44fbdefce90bfd/wal-000000001 (ops 1-6)
I20260812 06:17:26.057776 25245 maintenance_manager.cc:643] P dd4f23643a31400496a29615ad83678d: LogGCOp(13c3836bf0214c5cbe44fbdefce90bfd) complete. Timing: real 0.003s	user 0.000s	sys 0.002s Metrics: {}
I20260812 06:17:26.058112 25338 maintenance_manager.cc:419] P dd4f23643a31400496a29615ad83678d: Scheduling UndoDeltaBlockGCOp(13c3836bf0214c5cbe44fbdefce90bfd): 12308958 bytes on disk
I20260812 06:17:26.058732 25245 maintenance_manager.cc:643] P dd4f23643a31400496a29615ad83678d: UndoDeltaBlockGCOp(13c3836bf0214c5cbe44fbdefce90bfd) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":72,"lbm_reads_lt_1ms":4}
I20260812 06:17:26.059142 25338 maintenance_manager.cc:419] P dd4f23643a31400496a29615ad83678d: Scheduling FlushDeltaMemStoresOp(13c3836bf0214c5cbe44fbdefce90bfd): perf score=2.188937
I20260812 06:17:26.079430 25245 maintenance_manager.cc:643] P dd4f23643a31400496a29615ad83678d: FlushDeltaMemStoresOp(13c3836bf0214c5cbe44fbdefce90bfd) complete. Timing: real 0.020s	user 0.008s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6811,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:26.079977 25338 maintenance_manager.cc:419] P dd4f23643a31400496a29615ad83678d: Scheduling MajorDeltaCompactionOp(13c3836bf0214c5cbe44fbdefce90bfd): perf score=1.000000
I20260812 06:17:26.211925 25245 maintenance_manager.cc:643] P dd4f23643a31400496a29615ad83678d: MajorDeltaCompactionOp(13c3836bf0214c5cbe44fbdefce90bfd) complete. Timing: real 0.132s	user 0.090s	sys 0.041s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20631312,"cfile_init":7,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":619,"lbm_read_time_us":8918,"lbm_reads_lt_1ms":460,"lbm_write_time_us":25710,"lbm_writes_lt_1ms":443,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":1280,"thread_start_us":331,"threads_started":5,"update_count":2000}
I20260812 06:17:26.212473 25338 maintenance_manager.cc:419] P dd4f23643a31400496a29615ad83678d: Scheduling FlushDeltaMemStoresOp(13c3836bf0214c5cbe44fbdefce90bfd): perf score=10.126437
I20260812 06:17:26.254887 25245 maintenance_manager.cc:643] P dd4f23643a31400496a29615ad83678d: FlushDeltaMemStoresOp(13c3836bf0214c5cbe44fbdefce90bfd) complete. Timing: real 0.042s	user 0.022s	sys 0.015s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":17554,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:17:26.255366 25338 maintenance_manager.cc:419] P dd4f23643a31400496a29615ad83678d: Scheduling FlushDeltaMemStoresOp(13c3836bf0214c5cbe44fbdefce90bfd): perf score=2.188937
I20260812 06:17:26.265784 25245 maintenance_manager.cc:643] P dd4f23643a31400496a29615ad83678d: FlushDeltaMemStoresOp(13c3836bf0214c5cbe44fbdefce90bfd) complete. Timing: real 0.010s	user 0.005s	sys 0.004s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":3943,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:26.266364 25338 maintenance_manager.cc:419] P dd4f23643a31400496a29615ad83678d: Scheduling MajorDeltaCompactionOp(13c3836bf0214c5cbe44fbdefce90bfd): perf score=1.000000
I20260812 06:17:26.389605 25245 maintenance_manager.cc:643] P dd4f23643a31400496a29615ad83678d: MajorDeltaCompactionOp(13c3836bf0214c5cbe44fbdefce90bfd) complete. Timing: real 0.123s	user 0.095s	sys 0.028s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20631311,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":331,"lbm_read_time_us":9688,"lbm_reads_lt_1ms":472,"lbm_write_time_us":21471,"lbm_writes_lt_1ms":443,"mutex_wait_us":66,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":13952,"update_count":2000}
I20260812 06:17:26.390231 25338 maintenance_manager.cc:419] P dd4f23643a31400496a29615ad83678d: Scheduling FlushDeltaMemStoresOp(13c3836bf0214c5cbe44fbdefce90bfd): perf score=10.126437
I20260812 06:17:26.431443 25245 maintenance_manager.cc:643] P dd4f23643a31400496a29615ad83678d: FlushDeltaMemStoresOp(13c3836bf0214c5cbe44fbdefce90bfd) complete. Timing: real 0.041s	user 0.025s	sys 0.008s Metrics: {"bytes_written":12307492,"delete_count":0,"lbm_write_time_us":15397,"lbm_writes_lt_1ms":303,"reinsert_count":0,"spinlock_wait_cycles":3328,"update_count":1500}
I20260812 06:17:26.431959 25338 maintenance_manager.cc:419] P dd4f23643a31400496a29615ad83678d: Scheduling FlushDeltaMemStoresOp(13c3836bf0214c5cbe44fbdefce90bfd): perf score=2.188937
I20260812 06:17:26.442193 25245 maintenance_manager.cc:643] P dd4f23643a31400496a29615ad83678d: FlushDeltaMemStoresOp(13c3836bf0214c5cbe44fbdefce90bfd) complete. Timing: real 0.010s	user 0.008s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3922,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:26.442693 25338 maintenance_manager.cc:419] P dd4f23643a31400496a29615ad83678d: Scheduling MajorDeltaCompactionOp(13c3836bf0214c5cbe44fbdefce90bfd): perf score=1.000000
I20260812 06:17:26.574683 25245 maintenance_manager.cc:643] P dd4f23643a31400496a29615ad83678d: MajorDeltaCompactionOp(13c3836bf0214c5cbe44fbdefce90bfd) complete. Timing: real 0.132s	user 0.108s	sys 0.024s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20631314,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":253,"lbm_read_time_us":8046,"lbm_reads_lt_1ms":472,"lbm_write_time_us":27407,"lbm_writes_lt_1ms":443,"mutex_wait_us":56,"peak_mem_usage":50689328,"reinsert_count":0,"update_count":2000}
I20260812 06:17:26.575376 25338 maintenance_manager.cc:419] P dd4f23643a31400496a29615ad83678d: Scheduling FlushDeltaMemStoresOp(13c3836bf0214c5cbe44fbdefce90bfd): perf score=10.126437
I20260812 06:17:26.625272 25245 maintenance_manager.cc:643] P dd4f23643a31400496a29615ad83678d: FlushDeltaMemStoresOp(13c3836bf0214c5cbe44fbdefce90bfd) complete. Timing: real 0.049s	user 0.036s	sys 0.010s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":18500,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":302,"reinsert_count":0,"update_count":1500}
I20260812 06:17:26.625799 25338 maintenance_manager.cc:419] P dd4f23643a31400496a29615ad83678d: Scheduling FlushDeltaMemStoresOp(13c3836bf0214c5cbe44fbdefce90bfd): perf score=2.188937
I20260812 06:17:26.636642 25245 maintenance_manager.cc:643] P dd4f23643a31400496a29615ad83678d: FlushDeltaMemStoresOp(13c3836bf0214c5cbe44fbdefce90bfd) complete. Timing: real 0.011s	user 0.010s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4183,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:26.637074 25338 maintenance_manager.cc:419] P dd4f23643a31400496a29615ad83678d: Scheduling MajorDeltaCompactionOp(13c3836bf0214c5cbe44fbdefce90bfd): perf score=1.000000
I20260812 06:17:26.786504 25245 maintenance_manager.cc:643] P dd4f23643a31400496a29615ad83678d: MajorDeltaCompactionOp(13c3836bf0214c5cbe44fbdefce90bfd) complete. Timing: real 0.149s	user 0.116s	sys 0.032s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20631312,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":669,"lbm_read_time_us":10995,"lbm_reads_lt_1ms":472,"lbm_write_time_us":25525,"lbm_writes_lt_1ms":443,"mutex_wait_us":332,"peak_mem_usage":50689328,"reinsert_count":0,"update_count":2000}
I20260812 06:17:26.787016 25338 maintenance_manager.cc:419] P dd4f23643a31400496a29615ad83678d: Scheduling FlushDeltaMemStoresOp(13c3836bf0214c5cbe44fbdefce90bfd): perf score=10.126437
I20260812 06:17:26.835391 25245 maintenance_manager.cc:643] P dd4f23643a31400496a29615ad83678d: FlushDeltaMemStoresOp(13c3836bf0214c5cbe44fbdefce90bfd) complete. Timing: real 0.048s	user 0.023s	sys 0.015s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":19077,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:17:26.835822 25338 maintenance_manager.cc:419] P dd4f23643a31400496a29615ad83678d: Scheduling FlushDeltaMemStoresOp(13c3836bf0214c5cbe44fbdefce90bfd): perf score=2.188937
I20260812 06:17:26.846256 25245 maintenance_manager.cc:643] P dd4f23643a31400496a29615ad83678d: FlushDeltaMemStoresOp(13c3836bf0214c5cbe44fbdefce90bfd) complete. Timing: real 0.010s	user 0.005s	sys 0.003s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4023,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:26.846874 25338 maintenance_manager.cc:419] P dd4f23643a31400496a29615ad83678d: Scheduling MajorDeltaCompactionOp(13c3836bf0214c5cbe44fbdefce90bfd): perf score=1.000000
I20260812 06:17:26.970432 25245 maintenance_manager.cc:643] P dd4f23643a31400496a29615ad83678d: MajorDeltaCompactionOp(13c3836bf0214c5cbe44fbdefce90bfd) complete. Timing: real 0.123s	user 0.090s	sys 0.032s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20631311,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":1508,"lbm_read_time_us":10117,"lbm_reads_lt_1ms":472,"lbm_write_time_us":21491,"lbm_writes_lt_1ms":443,"mutex_wait_us":671,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":4736,"update_count":2000}
I20260812 06:17:26.971148 25338 maintenance_manager.cc:419] P dd4f23643a31400496a29615ad83678d: Scheduling FlushDeltaMemStoresOp(13c3836bf0214c5cbe44fbdefce90bfd): perf score=10.126437
I20260812 06:17:27.013721 25245 maintenance_manager.cc:643] P dd4f23643a31400496a29615ad83678d: FlushDeltaMemStoresOp(13c3836bf0214c5cbe44fbdefce90bfd) complete. Timing: real 0.042s	user 0.021s	sys 0.015s Metrics: {"bytes_written":12307489,"delete_count":0,"lbm_write_time_us":16588,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:17:27.014185 25338 maintenance_manager.cc:419] P dd4f23643a31400496a29615ad83678d: Scheduling FlushDeltaMemStoresOp(13c3836bf0214c5cbe44fbdefce90bfd): perf score=2.188937
I20260812 06:17:27.024993 25245 maintenance_manager.cc:643] P dd4f23643a31400496a29615ad83678d: FlushDeltaMemStoresOp(13c3836bf0214c5cbe44fbdefce90bfd) complete. Timing: real 0.011s	user 0.009s	sys 0.001s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4139,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:27.025429 25338 maintenance_manager.cc:419] P dd4f23643a31400496a29615ad83678d: Scheduling MajorDeltaCompactionOp(13c3836bf0214c5cbe44fbdefce90bfd): perf score=1.000000
I20260812 06:17:27.148561 25245 maintenance_manager.cc:643] P dd4f23643a31400496a29615ad83678d: MajorDeltaCompactionOp(13c3836bf0214c5cbe44fbdefce90bfd) complete. Timing: real 0.123s	user 0.095s	sys 0.027s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20631310,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":1418,"lbm_read_time_us":7853,"lbm_reads_lt_1ms":472,"lbm_write_time_us":25171,"lbm_writes_lt_1ms":443,"mutex_wait_us":456,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":5888,"update_count":2000}
I20260812 06:17:27.149277 25338 maintenance_manager.cc:419] P dd4f23643a31400496a29615ad83678d: Scheduling FlushDeltaMemStoresOp(13c3836bf0214c5cbe44fbdefce90bfd): perf score=10.126437
I20260812 06:17:27.192570 25245 maintenance_manager.cc:643] P dd4f23643a31400496a29615ad83678d: FlushDeltaMemStoresOp(13c3836bf0214c5cbe44fbdefce90bfd) complete. Timing: real 0.043s	user 0.027s	sys 0.012s Metrics: {"bytes_written":12307491,"delete_count":0,"lbm_write_time_us":16838,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:17:27.193130 25338 maintenance_manager.cc:419] P dd4f23643a31400496a29615ad83678d: Scheduling FlushDeltaMemStoresOp(13c3836bf0214c5cbe44fbdefce90bfd): perf score=2.188937
I20260812 06:17:27.204542 25245 maintenance_manager.cc:643] P dd4f23643a31400496a29615ad83678d: FlushDeltaMemStoresOp(13c3836bf0214c5cbe44fbdefce90bfd) complete. Timing: real 0.011s	user 0.007s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4172,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:27.205232 25338 maintenance_manager.cc:419] P dd4f23643a31400496a29615ad83678d: Scheduling FlushMRSOp(13c3836bf0214c5cbe44fbdefce90bfd): perf score=1.000000
I20260812 06:17:27.236534 25245 maintenance_manager.cc:643] P dd4f23643a31400496a29615ad83678d: FlushMRSOp(13c3836bf0214c5cbe44fbdefce90bfd) complete. Timing: real 0.031s	user 0.031s	sys 0.000s Metrics: {"bytes_written":1152509,"cfile_init":1,"dirs.queue_time_us":68,"dirs.run_cpu_time_us":275,"dirs.run_wall_time_us":1484,"drs_written":1,"lbm_read_time_us":54,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1526,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":28}
I20260812 06:17:27.237457 25338 maintenance_manager.cc:419] P dd4f23643a31400496a29615ad83678d: Scheduling LogGCOp(13c3836bf0214c5cbe44fbdefce90bfd): free 116849504 bytes of WAL
I20260812 06:17:27.237735 25245 log_reader.cc:385] T 13c3836bf0214c5cbe44fbdefce90bfd: removed 12 log segments from log reader
I20260812 06:17:27.237804 25245 log.cc:1079] T 13c3836bf0214c5cbe44fbdefce90bfd P dd4f23643a31400496a29615ad83678d: Deleting log segment in path: /tmp/dist-test-taskQFXsto/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515445504383-25086-0/minicluster-data/ts-0-root/wals/13c3836bf0214c5cbe44fbdefce90bfd/wal-000000002 (ops 7-11)
I20260812 06:17:27.237859 25245 log.cc:1079] T 13c3836bf0214c5cbe44fbdefce90bfd P dd4f23643a31400496a29615ad83678d: Deleting log segment in path: /tmp/dist-test-taskQFXsto/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515445504383-25086-0/minicluster-data/ts-0-root/wals/13c3836bf0214c5cbe44fbdefce90bfd/wal-000000003 (ops 12-16)
I20260812 06:17:27.237918 25245 log.cc:1079] T 13c3836bf0214c5cbe44fbdefce90bfd P dd4f23643a31400496a29615ad83678d: Deleting log segment in path: /tmp/dist-test-taskQFXsto/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515445504383-25086-0/minicluster-data/ts-0-root/wals/13c3836bf0214c5cbe44fbdefce90bfd/wal-000000004 (ops 17-20)
I20260812 06:17:27.237960 25245 log.cc:1079] T 13c3836bf0214c5cbe44fbdefce90bfd P dd4f23643a31400496a29615ad83678d: Deleting log segment in path: /tmp/dist-test-taskQFXsto/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515445504383-25086-0/minicluster-data/ts-0-root/wals/13c3836bf0214c5cbe44fbdefce90bfd/wal-000000005 (ops 21-25)
I20260812 06:17:27.237995 25245 log.cc:1079] T 13c3836bf0214c5cbe44fbdefce90bfd P dd4f23643a31400496a29615ad83678d: Deleting log segment in path: /tmp/dist-test-taskQFXsto/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515445504383-25086-0/minicluster-data/ts-0-root/wals/13c3836bf0214c5cbe44fbdefce90bfd/wal-000000006 (ops 26-30)
I20260812 06:17:27.238034 25245 log.cc:1079] T 13c3836bf0214c5cbe44fbdefce90bfd P dd4f23643a31400496a29615ad83678d: Deleting log segment in path: /tmp/dist-test-taskQFXsto/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515445504383-25086-0/minicluster-data/ts-0-root/wals/13c3836bf0214c5cbe44fbdefce90bfd/wal-000000007 (ops 31-35)
I20260812 06:17:27.238065 25245 log.cc:1079] T 13c3836bf0214c5cbe44fbdefce90bfd P dd4f23643a31400496a29615ad83678d: Deleting log segment in path: /tmp/dist-test-taskQFXsto/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515445504383-25086-0/minicluster-data/ts-0-root/wals/13c3836bf0214c5cbe44fbdefce90bfd/wal-000000008 (ops 36-40)
I20260812 06:17:27.238091 25245 log.cc:1079] T 13c3836bf0214c5cbe44fbdefce90bfd P dd4f23643a31400496a29615ad83678d: Deleting log segment in path: /tmp/dist-test-taskQFXsto/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515445504383-25086-0/minicluster-data/ts-0-root/wals/13c3836bf0214c5cbe44fbdefce90bfd/wal-000000009 (ops 41-44)
I20260812 06:17:27.238131 25245 log.cc:1079] T 13c3836bf0214c5cbe44fbdefce90bfd P dd4f23643a31400496a29615ad83678d: Deleting log segment in path: /tmp/dist-test-taskQFXsto/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515445504383-25086-0/minicluster-data/ts-0-root/wals/13c3836bf0214c5cbe44fbdefce90bfd/wal-000000010 (ops 45-49)
I20260812 06:17:27.238170 25245 log.cc:1079] T 13c3836bf0214c5cbe44fbdefce90bfd P dd4f23643a31400496a29615ad83678d: Deleting log segment in path: /tmp/dist-test-taskQFXsto/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515445504383-25086-0/minicluster-data/ts-0-root/wals/13c3836bf0214c5cbe44fbdefce90bfd/wal-000000011 (ops 50-54)
I20260812 06:17:27.238207 25245 log.cc:1079] T 13c3836bf0214c5cbe44fbdefce90bfd P dd4f23643a31400496a29615ad83678d: Deleting log segment in path: /tmp/dist-test-taskQFXsto/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515445504383-25086-0/minicluster-data/ts-0-root/wals/13c3836bf0214c5cbe44fbdefce90bfd/wal-000000012 (ops 55-58)
I20260812 06:17:27.238245 25245 log.cc:1079] T 13c3836bf0214c5cbe44fbdefce90bfd P dd4f23643a31400496a29615ad83678d: Deleting log segment in path: /tmp/dist-test-taskQFXsto/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515445504383-25086-0/minicluster-data/ts-0-root/wals/13c3836bf0214c5cbe44fbdefce90bfd/wal-000000013 (ops 59-63)
I20260812 06:17:27.265455 25245 maintenance_manager.cc:643] P dd4f23643a31400496a29615ad83678d: LogGCOp(13c3836bf0214c5cbe44fbdefce90bfd) complete. Timing: real 0.028s	user 0.003s	sys 0.023s Metrics: {}
I20260812 06:17:27.265892 25338 maintenance_manager.cc:419] P dd4f23643a31400496a29615ad83678d: Scheduling FlushDeltaMemStoresOp(13c3836bf0214c5cbe44fbdefce90bfd): perf score=4.173312
I20260812 06:17:27.280401 25245 maintenance_manager.cc:643] P dd4f23643a31400496a29615ad83678d: FlushDeltaMemStoresOp(13c3836bf0214c5cbe44fbdefce90bfd) complete. Timing: real 0.014s	user 0.010s	sys 0.004s Metrics: {"bytes_written":5825681,"delete_count":0,"lbm_write_time_us":5878,"lbm_writes_lt_1ms":145,"reinsert_count":0,"update_count":710}
I20260812 06:17:27.280846 25338 maintenance_manager.cc:419] P dd4f23643a31400496a29615ad83678d: Scheduling FlushDeltaMemStoresOp(13c3836bf0214c5cbe44fbdefce90bfd): perf score=1.196750
I20260812 06:17:27.289666 25245 maintenance_manager.cc:643] P dd4f23643a31400496a29615ad83678d: FlushDeltaMemStoresOp(13c3836bf0214c5cbe44fbdefce90bfd) complete. Timing: real 0.009s	user 0.003s	sys 0.004s Metrics: {"bytes_written":2379604,"delete_count":0,"lbm_write_time_us":2951,"lbm_writes_lt_1ms":61,"reinsert_count":0,"update_count":290}
I20260812 06:17:27.290552 25338 maintenance_manager.cc:419] P dd4f23643a31400496a29615ad83678d: Scheduling MajorDeltaCompactionOp(13c3836bf0214c5cbe44fbdefce90bfd): perf score=1.000000
I20260812 06:17:27.464445 25245 maintenance_manager.cc:643] P dd4f23643a31400496a29615ad83678d: MajorDeltaCompactionOp(13c3836bf0214c5cbe44fbdefce90bfd) complete. Timing: real 0.174s	user 0.135s	sys 0.034s Metrics: {"cfile_cache_miss":634,"cfile_cache_miss_bytes":28836336,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":1333,"lbm_read_time_us":11255,"lbm_reads_lt_1ms":666,"lbm_write_time_us":35851,"lbm_writes_lt_1ms":643,"mutex_wait_us":714,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":3200,"thread_start_us":95,"threads_started":1,"update_count":3000}
I20260812 06:17:27.465286 25338 maintenance_manager.cc:419] P dd4f23643a31400496a29615ad83678d: Scheduling FlushDeltaMemStoresOp(13c3836bf0214c5cbe44fbdefce90bfd): perf score=14.095187
I20260812 06:17:27.515977 25245 maintenance_manager.cc:643] P dd4f23643a31400496a29615ad83678d: FlushDeltaMemStoresOp(13c3836bf0214c5cbe44fbdefce90bfd) complete. Timing: real 0.050s	user 0.027s	sys 0.016s Metrics: {"bytes_written":16409903,"delete_count":0,"lbm_write_time_us":20595,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:17:27.516537 25338 maintenance_manager.cc:419] P dd4f23643a31400496a29615ad83678d: Scheduling UndoDeltaBlockGCOp(13c3836bf0214c5cbe44fbdefce90bfd): 447 bytes on disk
I20260812 06:17:27.516970 25245 maintenance_manager.cc:643] P dd4f23643a31400496a29615ad83678d: UndoDeltaBlockGCOp(13c3836bf0214c5cbe44fbdefce90bfd) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":62,"lbm_reads_lt_1ms":4}
I20260812 06:17:27.517390 25338 maintenance_manager.cc:419] P dd4f23643a31400496a29615ad83678d: Scheduling FlushDeltaMemStoresOp(13c3836bf0214c5cbe44fbdefce90bfd): perf score=2.188937
I20260812 06:17:27.529284 25245 maintenance_manager.cc:643] P dd4f23643a31400496a29615ad83678d: FlushDeltaMemStoresOp(13c3836bf0214c5cbe44fbdefce90bfd) complete. Timing: real 0.012s	user 0.010s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4231,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:27.529712 25338 maintenance_manager.cc:419] P dd4f23643a31400496a29615ad83678d: Scheduling MajorDeltaCompactionOp(13c3836bf0214c5cbe44fbdefce90bfd): perf score=1.000000
I20260812 06:17:27.690359 25245 maintenance_manager.cc:643] P dd4f23643a31400496a29615ad83678d: MajorDeltaCompactionOp(13c3836bf0214c5cbe44fbdefce90bfd) complete. Timing: real 0.160s	user 0.128s	sys 0.027s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24733725,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":303,"lbm_read_time_us":10524,"lbm_reads_lt_1ms":572,"lbm_write_time_us":31070,"lbm_writes_lt_1ms":543,"mutex_wait_us":31,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":78592,"update_count":2500}
I20260812 06:17:27.690977 25338 maintenance_manager.cc:419] P dd4f23643a31400496a29615ad83678d: Scheduling FlushDeltaMemStoresOp(13c3836bf0214c5cbe44fbdefce90bfd): perf score=14.095187
I20260812 06:17:27.734318 25245 maintenance_manager.cc:643] P dd4f23643a31400496a29615ad83678d: FlushDeltaMemStoresOp(13c3836bf0214c5cbe44fbdefce90bfd) complete. Timing: real 0.043s	user 0.033s	sys 0.008s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":19621,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:17:27.734864 25338 maintenance_manager.cc:419] P dd4f23643a31400496a29615ad83678d: Scheduling MajorDeltaCompactionOp(13c3836bf0214c5cbe44fbdefce90bfd): perf score=1.000000
I20260812 06:17:27.891530 25245 maintenance_manager.cc:643] P dd4f23643a31400496a29615ad83678d: MajorDeltaCompactionOp(13c3836bf0214c5cbe44fbdefce90bfd) complete. Timing: real 0.156s	user 0.120s	sys 0.036s Metrics: {"cfile_cache_miss":431,"cfile_cache_miss_bytes":20631193,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":1,"delta_iterators_relevant":1,"dirs.queue_time_us":212,"lbm_read_time_us":11314,"lbm_reads_lt_1ms":467,"lbm_write_time_us":27380,"lbm_writes_lt_1ms":443,"mutex_wait_us":28,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":22656,"update_count":2000}
I20260812 06:17:27.892153 25338 maintenance_manager.cc:419] P dd4f23643a31400496a29615ad83678d: Scheduling FlushDeltaMemStoresOp(13c3836bf0214c5cbe44fbdefce90bfd): perf score=10.126437
I20260812 06:17:27.925119 25245 maintenance_manager.cc:643] P dd4f23643a31400496a29615ad83678d: FlushDeltaMemStoresOp(13c3836bf0214c5cbe44fbdefce90bfd) complete. Timing: real 0.033s	user 0.019s	sys 0.012s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":14400,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:17:27.925575 25338 maintenance_manager.cc:419] P dd4f23643a31400496a29615ad83678d: Scheduling FlushDeltaMemStoresOp(13c3836bf0214c5cbe44fbdefce90bfd): perf score=2.188937
I20260812 06:17:27.939966 25245 maintenance_manager.cc:643] P dd4f23643a31400496a29615ad83678d: FlushDeltaMemStoresOp(13c3836bf0214c5cbe44fbdefce90bfd) complete. Timing: real 0.014s	user 0.004s	sys 0.008s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":5628,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:27.940511 25338 maintenance_manager.cc:419] P dd4f23643a31400496a29615ad83678d: Scheduling MajorDeltaCompactionOp(13c3836bf0214c5cbe44fbdefce90bfd): perf score=1.000000
I20260812 06:17:28.082198 25245 maintenance_manager.cc:643] P dd4f23643a31400496a29615ad83678d: MajorDeltaCompactionOp(13c3836bf0214c5cbe44fbdefce90bfd) complete. Timing: real 0.141s	user 0.128s	sys 0.012s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20631311,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":553,"lbm_read_time_us":9517,"lbm_reads_lt_1ms":472,"lbm_write_time_us":29847,"lbm_writes_lt_1ms":443,"mutex_wait_us":42,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":896,"update_count":2000}
I20260812 06:17:28.082831 25338 maintenance_manager.cc:419] P dd4f23643a31400496a29615ad83678d: Scheduling FlushDeltaMemStoresOp(13c3836bf0214c5cbe44fbdefce90bfd): perf score=10.126437
I20260812 06:17:28.130788 25245 maintenance_manager.cc:643] P dd4f23643a31400496a29615ad83678d: FlushDeltaMemStoresOp(13c3836bf0214c5cbe44fbdefce90bfd) complete. Timing: real 0.048s	user 0.028s	sys 0.007s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":16309,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:17:28.131279 25338 maintenance_manager.cc:419] P dd4f23643a31400496a29615ad83678d: Scheduling FlushDeltaMemStoresOp(13c3836bf0214c5cbe44fbdefce90bfd): perf score=2.188937
I20260812 06:17:28.142015 25245 maintenance_manager.cc:643] P dd4f23643a31400496a29615ad83678d: FlushDeltaMemStoresOp(13c3836bf0214c5cbe44fbdefce90bfd) complete. Timing: real 0.011s	user 0.006s	sys 0.003s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4010,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:28.142755 25338 maintenance_manager.cc:419] P dd4f23643a31400496a29615ad83678d: Scheduling MajorDeltaCompactionOp(13c3836bf0214c5cbe44fbdefce90bfd): perf score=1.000000
I20260812 06:17:28.265702 25245 maintenance_manager.cc:643] P dd4f23643a31400496a29615ad83678d: MajorDeltaCompactionOp(13c3836bf0214c5cbe44fbdefce90bfd) complete. Timing: real 0.123s	user 0.092s	sys 0.030s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20631311,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":1542,"lbm_read_time_us":9295,"lbm_reads_lt_1ms":472,"lbm_write_time_us":22945,"lbm_writes_lt_1ms":443,"mutex_wait_us":462,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":768,"update_count":2000}
I20260812 06:17:28.266393 25338 maintenance_manager.cc:419] P dd4f23643a31400496a29615ad83678d: Scheduling FlushDeltaMemStoresOp(13c3836bf0214c5cbe44fbdefce90bfd): perf score=10.126437
I20260812 06:17:28.313457 25245 maintenance_manager.cc:643] P dd4f23643a31400496a29615ad83678d: FlushDeltaMemStoresOp(13c3836bf0214c5cbe44fbdefce90bfd) complete. Timing: real 0.047s	user 0.020s	sys 0.025s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":20854,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":302,"reinsert_count":0,"update_count":1500}
I20260812 06:17:28.314101 25338 maintenance_manager.cc:419] P dd4f23643a31400496a29615ad83678d: Scheduling FlushDeltaMemStoresOp(13c3836bf0214c5cbe44fbdefce90bfd): perf score=2.188937
I20260812 06:17:28.325049 25245 maintenance_manager.cc:643] P dd4f23643a31400496a29615ad83678d: FlushDeltaMemStoresOp(13c3836bf0214c5cbe44fbdefce90bfd) complete. Timing: real 0.011s	user 0.001s	sys 0.009s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4122,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:28.325697 25338 maintenance_manager.cc:419] P dd4f23643a31400496a29615ad83678d: Scheduling MajorDeltaCompactionOp(13c3836bf0214c5cbe44fbdefce90bfd): perf score=1.000000
I20260812 06:17:28.457368 25245 maintenance_manager.cc:643] P dd4f23643a31400496a29615ad83678d: MajorDeltaCompactionOp(13c3836bf0214c5cbe44fbdefce90bfd) complete. Timing: real 0.131s	user 0.091s	sys 0.040s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20631312,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":280,"lbm_read_time_us":9656,"lbm_reads_lt_1ms":472,"lbm_write_time_us":26015,"lbm_writes_lt_1ms":443,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":11648,"update_count":2000}
I20260812 06:17:28.458083 25338 maintenance_manager.cc:419] P dd4f23643a31400496a29615ad83678d: Scheduling FlushDeltaMemStoresOp(13c3836bf0214c5cbe44fbdefce90bfd): perf score=10.126437
I20260812 06:17:28.507138 25245 maintenance_manager.cc:643] P dd4f23643a31400496a29615ad83678d: FlushDeltaMemStoresOp(13c3836bf0214c5cbe44fbdefce90bfd) complete. Timing: real 0.049s	user 0.030s	sys 0.012s Metrics: {"bytes_written":12307491,"delete_count":0,"lbm_write_time_us":15947,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:17:28.507710 25338 maintenance_manager.cc:419] P dd4f23643a31400496a29615ad83678d: Scheduling FlushDeltaMemStoresOp(13c3836bf0214c5cbe44fbdefce90bfd): perf score=2.188937
I20260812 06:17:28.518905 25245 maintenance_manager.cc:643] P dd4f23643a31400496a29615ad83678d: FlushDeltaMemStoresOp(13c3836bf0214c5cbe44fbdefce90bfd) complete. Timing: real 0.011s	user 0.009s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4241,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:28.519511 25338 maintenance_manager.cc:419] P dd4f23643a31400496a29615ad83678d: Scheduling MajorDeltaCompactionOp(13c3836bf0214c5cbe44fbdefce90bfd): perf score=1.000000
I20260812 06:17:28.667237 25245 maintenance_manager.cc:643] P dd4f23643a31400496a29615ad83678d: MajorDeltaCompactionOp(13c3836bf0214c5cbe44fbdefce90bfd) complete. Timing: real 0.148s	user 0.086s	sys 0.059s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20631313,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":173,"lbm_read_time_us":12378,"lbm_reads_lt_1ms":472,"lbm_write_time_us":22498,"lbm_writes_lt_1ms":443,"peak_mem_usage":50689328,"reinsert_count":0,"update_count":2000}
I20260812 06:17:28.667881 25338 maintenance_manager.cc:419] P dd4f23643a31400496a29615ad83678d: Scheduling FlushDeltaMemStoresOp(13c3836bf0214c5cbe44fbdefce90bfd): perf score=10.126437
I20260812 06:17:28.716883 25245 maintenance_manager.cc:643] P dd4f23643a31400496a29615ad83678d: FlushDeltaMemStoresOp(13c3836bf0214c5cbe44fbdefce90bfd) complete. Timing: real 0.049s	user 0.012s	sys 0.028s Metrics: {"bytes_written":12307492,"delete_count":0,"lbm_write_time_us":20283,"lbm_writes_1-10_ms":3,"lbm_writes_lt_1ms":300,"reinsert_count":0,"update_count":1500}
I20260812 06:17:28.717350 25338 maintenance_manager.cc:419] P dd4f23643a31400496a29615ad83678d: Scheduling FlushDeltaMemStoresOp(13c3836bf0214c5cbe44fbdefce90bfd): perf score=2.188937
I20260812 06:17:28.728682 25245 maintenance_manager.cc:643] P dd4f23643a31400496a29615ad83678d: FlushDeltaMemStoresOp(13c3836bf0214c5cbe44fbdefce90bfd) complete. Timing: real 0.011s	user 0.003s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4290,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:28.729346 25338 maintenance_manager.cc:419] P dd4f23643a31400496a29615ad83678d: Scheduling FlushMRSOp(13c3836bf0214c5cbe44fbdefce90bfd): perf score=1.000000
I20260812 06:17:28.762977 25245 maintenance_manager.cc:643] P dd4f23643a31400496a29615ad83678d: FlushMRSOp(13c3836bf0214c5cbe44fbdefce90bfd) complete. Timing: real 0.032s	user 0.031s	sys 0.000s Metrics: {"bytes_written":1275449,"cfile_init":1,"dirs.queue_time_us":60,"dirs.run_cpu_time_us":240,"dirs.run_wall_time_us":1350,"drs_written":1,"lbm_read_time_us":45,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1573,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":31}
I20260812 06:17:28.763741 25338 maintenance_manager.cc:419] P dd4f23643a31400496a29615ad83678d: Scheduling LogGCOp(13c3836bf0214c5cbe44fbdefce90bfd): free 133024371 bytes of WAL
I20260812 06:17:28.763978 25245 log_reader.cc:385] T 13c3836bf0214c5cbe44fbdefce90bfd: removed 13 log segments from log reader
I20260812 06:17:28.764025 25245 log.cc:1079] T 13c3836bf0214c5cbe44fbdefce90bfd P dd4f23643a31400496a29615ad83678d: Deleting log segment in path: /tmp/dist-test-taskQFXsto/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515445504383-25086-0/minicluster-data/ts-0-root/wals/13c3836bf0214c5cbe44fbdefce90bfd/wal-000000014 (ops 64-68)
I20260812 06:17:28.764093 25245 log.cc:1079] T 13c3836bf0214c5cbe44fbdefce90bfd P dd4f23643a31400496a29615ad83678d: Deleting log segment in path: /tmp/dist-test-taskQFXsto/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515445504383-25086-0/minicluster-data/ts-0-root/wals/13c3836bf0214c5cbe44fbdefce90bfd/wal-000000015 (ops 69-73)
I20260812 06:17:28.764150 25245 log.cc:1079] T 13c3836bf0214c5cbe44fbdefce90bfd P dd4f23643a31400496a29615ad83678d: Deleting log segment in path: /tmp/dist-test-taskQFXsto/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515445504383-25086-0/minicluster-data/ts-0-root/wals/13c3836bf0214c5cbe44fbdefce90bfd/wal-000000016 (ops 74-78)
I20260812 06:17:28.764195 25245 log.cc:1079] T 13c3836bf0214c5cbe44fbdefce90bfd P dd4f23643a31400496a29615ad83678d: Deleting log segment in path: /tmp/dist-test-taskQFXsto/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515445504383-25086-0/minicluster-data/ts-0-root/wals/13c3836bf0214c5cbe44fbdefce90bfd/wal-000000017 (ops 79-83)
I20260812 06:17:28.764240 25245 log.cc:1079] T 13c3836bf0214c5cbe44fbdefce90bfd P dd4f23643a31400496a29615ad83678d: Deleting log segment in path: /tmp/dist-test-taskQFXsto/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515445504383-25086-0/minicluster-data/ts-0-root/wals/13c3836bf0214c5cbe44fbdefce90bfd/wal-000000018 (ops 84-88)
I20260812 06:17:28.764278 25245 log.cc:1079] T 13c3836bf0214c5cbe44fbdefce90bfd P dd4f23643a31400496a29615ad83678d: Deleting log segment in path: /tmp/dist-test-taskQFXsto/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515445504383-25086-0/minicluster-data/ts-0-root/wals/13c3836bf0214c5cbe44fbdefce90bfd/wal-000000019 (ops 89-92)
I20260812 06:17:28.764317 25245 log.cc:1079] T 13c3836bf0214c5cbe44fbdefce90bfd P dd4f23643a31400496a29615ad83678d: Deleting log segment in path: /tmp/dist-test-taskQFXsto/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515445504383-25086-0/minicluster-data/ts-0-root/wals/13c3836bf0214c5cbe44fbdefce90bfd/wal-000000020 (ops 93-97)
I20260812 06:17:28.764354 25245 log.cc:1079] T 13c3836bf0214c5cbe44fbdefce90bfd P dd4f23643a31400496a29615ad83678d: Deleting log segment in path: /tmp/dist-test-taskQFXsto/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515445504383-25086-0/minicluster-data/ts-0-root/wals/13c3836bf0214c5cbe44fbdefce90bfd/wal-000000021 (ops 98-102)
I20260812 06:17:28.764393 25245 log.cc:1079] T 13c3836bf0214c5cbe44fbdefce90bfd P dd4f23643a31400496a29615ad83678d: Deleting log segment in path: /tmp/dist-test-taskQFXsto/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515445504383-25086-0/minicluster-data/ts-0-root/wals/13c3836bf0214c5cbe44fbdefce90bfd/wal-000000022 (ops 103-107)
I20260812 06:17:28.764430 25245 log.cc:1079] T 13c3836bf0214c5cbe44fbdefce90bfd P dd4f23643a31400496a29615ad83678d: Deleting log segment in path: /tmp/dist-test-taskQFXsto/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515445504383-25086-0/minicluster-data/ts-0-root/wals/13c3836bf0214c5cbe44fbdefce90bfd/wal-000000023 (ops 108-112)
I20260812 06:17:28.764469 25245 log.cc:1079] T 13c3836bf0214c5cbe44fbdefce90bfd P dd4f23643a31400496a29615ad83678d: Deleting log segment in path: /tmp/dist-test-taskQFXsto/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515445504383-25086-0/minicluster-data/ts-0-root/wals/13c3836bf0214c5cbe44fbdefce90bfd/wal-000000024 (ops 113-117)
I20260812 06:17:28.764508 25245 log.cc:1079] T 13c3836bf0214c5cbe44fbdefce90bfd P dd4f23643a31400496a29615ad83678d: Deleting log segment in path: /tmp/dist-test-taskQFXsto/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515445504383-25086-0/minicluster-data/ts-0-root/wals/13c3836bf0214c5cbe44fbdefce90bfd/wal-000000025 (ops 118-122)
I20260812 06:17:28.764544 25245 log.cc:1079] T 13c3836bf0214c5cbe44fbdefce90bfd P dd4f23643a31400496a29615ad83678d: Deleting log segment in path: /tmp/dist-test-taskQFXsto/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515445504383-25086-0/minicluster-data/ts-0-root/wals/13c3836bf0214c5cbe44fbdefce90bfd/wal-000000026 (ops 123-127)
I20260812 06:17:28.794521 25245 maintenance_manager.cc:643] P dd4f23643a31400496a29615ad83678d: LogGCOp(13c3836bf0214c5cbe44fbdefce90bfd) complete. Timing: real 0.031s	user 0.002s	sys 0.027s Metrics: {}
I20260812 06:17:28.794935 25338 maintenance_manager.cc:419] P dd4f23643a31400496a29615ad83678d: Scheduling UndoDeltaBlockGCOp(13c3836bf0214c5cbe44fbdefce90bfd): 483 bytes on disk
I20260812 06:17:28.795369 25245 maintenance_manager.cc:643] P dd4f23643a31400496a29615ad83678d: UndoDeltaBlockGCOp(13c3836bf0214c5cbe44fbdefce90bfd) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":53,"lbm_reads_lt_1ms":4}
I20260812 06:17:28.795976 25338 maintenance_manager.cc:419] P dd4f23643a31400496a29615ad83678d: Scheduling FlushDeltaMemStoresOp(13c3836bf0214c5cbe44fbdefce90bfd): perf score=6.157687
I20260812 06:17:28.826962 25245 maintenance_manager.cc:643] P dd4f23643a31400496a29615ad83678d: FlushDeltaMemStoresOp(13c3836bf0214c5cbe44fbdefce90bfd) complete. Timing: real 0.031s	user 0.016s	sys 0.008s Metrics: {"bytes_written":8205078,"delete_count":0,"lbm_write_time_us":9386,"lbm_writes_lt_1ms":203,"reinsert_count":0,"update_count":1000}
I20260812 06:17:28.827544 25338 maintenance_manager.cc:419] P dd4f23643a31400496a29615ad83678d: Scheduling MajorDeltaCompactionOp(13c3836bf0214c5cbe44fbdefce90bfd): perf score=1.000000
I20260812 06:17:29.016413 25245 maintenance_manager.cc:643] P dd4f23643a31400496a29615ad83678d: MajorDeltaCompactionOp(13c3836bf0214c5cbe44fbdefce90bfd) complete. Timing: real 0.189s	user 0.128s	sys 0.058s Metrics: {"cfile_cache_miss":633,"cfile_cache_miss_bytes":28836258,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":251,"lbm_read_time_us":13985,"lbm_reads_lt_1ms":665,"lbm_write_time_us":33966,"lbm_writes_lt_1ms":643,"mutex_wait_us":20,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":12416,"thread_start_us":82,"threads_started":1,"update_count":3000}
I20260812 06:17:29.017144 25338 maintenance_manager.cc:419] P dd4f23643a31400496a29615ad83678d: Scheduling FlushDeltaMemStoresOp(13c3836bf0214c5cbe44fbdefce90bfd): perf score=15.087375
I20260812 06:17:29.079504 25245 maintenance_manager.cc:643] P dd4f23643a31400496a29615ad83678d: FlushDeltaMemStoresOp(13c3836bf0214c5cbe44fbdefce90bfd) complete. Timing: real 0.062s	user 0.026s	sys 0.032s Metrics: {"bytes_written":16820142,"delete_count":0,"lbm_write_time_us":22488,"lbm_writes_lt_1ms":413,"reinsert_count":0,"update_count":2050}
I20260812 06:17:29.084585 25338 maintenance_manager.cc:419] P dd4f23643a31400496a29615ad83678d: Scheduling FlushDeltaMemStoresOp(13c3836bf0214c5cbe44fbdefce90bfd): perf score=2.188937
I20260812 06:17:29.101774 25245 maintenance_manager.cc:643] P dd4f23643a31400496a29615ad83678d: FlushDeltaMemStoresOp(13c3836bf0214c5cbe44fbdefce90bfd) complete. Timing: real 0.017s	user 0.009s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3943,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:29.102321 25338 maintenance_manager.cc:419] P dd4f23643a31400496a29615ad83678d: Scheduling FlushDeltaMemStoresOp(13c3836bf0214c5cbe44fbdefce90bfd): perf score=2.188937
I20260812 06:17:29.111611 25245 maintenance_manager.cc:643] P dd4f23643a31400496a29615ad83678d: FlushDeltaMemStoresOp(13c3836bf0214c5cbe44fbdefce90bfd) complete. Timing: real 0.009s	user 0.004s	sys 0.003s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3494,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:17:29.112146 25338 maintenance_manager.cc:419] P dd4f23643a31400496a29615ad83678d: Scheduling MajorDeltaCompactionOp(13c3836bf0214c5cbe44fbdefce90bfd): perf score=1.000000
I20260812 06:17:29.319072 25245 maintenance_manager.cc:643] P dd4f23643a31400496a29615ad83678d: MajorDeltaCompactionOp(13c3836bf0214c5cbe44fbdefce90bfd) complete. Timing: real 0.207s	user 0.130s	sys 0.077s Metrics: {"cfile_cache_miss":633,"cfile_cache_miss_bytes":28836241,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":259,"lbm_read_time_us":15524,"lbm_reads_lt_1ms":673,"lbm_write_time_us":34590,"lbm_writes_lt_1ms":643,"mutex_wait_us":41,"peak_mem_usage":75542472,"reinsert_count":0,"update_count":3000}
I20260812 06:17:29.319654 25338 maintenance_manager.cc:419] P dd4f23643a31400496a29615ad83678d: Scheduling FlushDeltaMemStoresOp(13c3836bf0214c5cbe44fbdefce90bfd): perf score=14.095187
I20260812 06:17:29.370484 25245 maintenance_manager.cc:643] P dd4f23643a31400496a29615ad83678d: FlushDeltaMemStoresOp(13c3836bf0214c5cbe44fbdefce90bfd) complete. Timing: real 0.051s	user 0.034s	sys 0.011s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":20831,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:17:29.371066 25338 maintenance_manager.cc:419] P dd4f23643a31400496a29615ad83678d: Scheduling FlushDeltaMemStoresOp(13c3836bf0214c5cbe44fbdefce90bfd): perf score=2.188937
I20260812 06:17:29.384269 25245 maintenance_manager.cc:643] P dd4f23643a31400496a29615ad83678d: FlushDeltaMemStoresOp(13c3836bf0214c5cbe44fbdefce90bfd) complete. Timing: real 0.013s	user 0.009s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5001,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:29.386215 25338 maintenance_manager.cc:419] P dd4f23643a31400496a29615ad83678d: Scheduling MajorDeltaCompactionOp(13c3836bf0214c5cbe44fbdefce90bfd): perf score=1.000000
I20260812 06:17:29.570570 25245 maintenance_manager.cc:643] P dd4f23643a31400496a29615ad83678d: MajorDeltaCompactionOp(13c3836bf0214c5cbe44fbdefce90bfd) complete. Timing: real 0.184s	user 0.154s	sys 0.023s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24733724,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":839,"lbm_read_time_us":13437,"lbm_reads_lt_1ms":572,"lbm_write_time_us":31191,"lbm_writes_lt_1ms":543,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":2688,"update_count":2500}
I20260812 06:17:29.571174 25338 maintenance_manager.cc:419] P dd4f23643a31400496a29615ad83678d: Scheduling FlushDeltaMemStoresOp(13c3836bf0214c5cbe44fbdefce90bfd): perf score=14.095187
I20260812 06:17:29.634650 25245 maintenance_manager.cc:643] P dd4f23643a31400496a29615ad83678d: FlushDeltaMemStoresOp(13c3836bf0214c5cbe44fbdefce90bfd) complete. Timing: real 0.063s	user 0.014s	sys 0.046s Metrics: {"bytes_written":16409903,"delete_count":0,"lbm_write_time_us":23735,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:17:29.635331 25338 maintenance_manager.cc:419] P dd4f23643a31400496a29615ad83678d: Scheduling FlushDeltaMemStoresOp(13c3836bf0214c5cbe44fbdefce90bfd): perf score=2.188937
I20260812 06:17:29.646214 25245 maintenance_manager.cc:643] P dd4f23643a31400496a29615ad83678d: FlushDeltaMemStoresOp(13c3836bf0214c5cbe44fbdefce90bfd) complete. Timing: real 0.011s	user 0.006s	sys 0.003s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4245,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:29.646682 25338 maintenance_manager.cc:419] P dd4f23643a31400496a29615ad83678d: Scheduling MajorDeltaCompactionOp(13c3836bf0214c5cbe44fbdefce90bfd): perf score=1.000000
I20260812 06:17:29.820785 25245 maintenance_manager.cc:643] P dd4f23643a31400496a29615ad83678d: MajorDeltaCompactionOp(13c3836bf0214c5cbe44fbdefce90bfd) complete. Timing: real 0.174s	user 0.110s	sys 0.064s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24733725,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":276,"lbm_read_time_us":13034,"lbm_reads_lt_1ms":572,"lbm_write_time_us":29674,"lbm_writes_lt_1ms":543,"mutex_wait_us":76,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":896,"update_count":2500}
I20260812 06:17:29.821605 25338 maintenance_manager.cc:419] P dd4f23643a31400496a29615ad83678d: Scheduling FlushDeltaMemStoresOp(13c3836bf0214c5cbe44fbdefce90bfd): perf score=14.095187
I20260812 06:17:29.874666 25245 maintenance_manager.cc:643] P dd4f23643a31400496a29615ad83678d: FlushDeltaMemStoresOp(13c3836bf0214c5cbe44fbdefce90bfd) complete. Timing: real 0.053s	user 0.025s	sys 0.025s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":26334,"lbm_writes_1-10_ms":2,"lbm_writes_lt_1ms":401,"reinsert_count":0,"update_count":2000}
I20260812 06:17:29.875236 25338 maintenance_manager.cc:419] P dd4f23643a31400496a29615ad83678d: Scheduling FlushDeltaMemStoresOp(13c3836bf0214c5cbe44fbdefce90bfd): perf score=2.188937
I20260812 06:17:29.894800 25245 maintenance_manager.cc:643] P dd4f23643a31400496a29615ad83678d: FlushDeltaMemStoresOp(13c3836bf0214c5cbe44fbdefce90bfd) complete. Timing: real 0.019s	user 0.006s	sys 0.011s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4143,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:29.895385 25338 maintenance_manager.cc:419] P dd4f23643a31400496a29615ad83678d: Scheduling MajorDeltaCompactionOp(13c3836bf0214c5cbe44fbdefce90bfd): perf score=1.000000
I20260812 06:17:30.091499 25245 maintenance_manager.cc:643] P dd4f23643a31400496a29615ad83678d: MajorDeltaCompactionOp(13c3836bf0214c5cbe44fbdefce90bfd) complete. Timing: real 0.196s	user 0.113s	sys 0.072s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24733724,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":834,"lbm_read_time_us":13746,"lbm_reads_lt_1ms":572,"lbm_write_time_us":31514,"lbm_writes_lt_1ms":543,"mutex_wait_us":36,"peak_mem_usage":63115900,"reinsert_count":0,"update_count":2500}
I20260812 06:17:30.092298 25338 maintenance_manager.cc:419] P dd4f23643a31400496a29615ad83678d: Scheduling FlushDeltaMemStoresOp(13c3836bf0214c5cbe44fbdefce90bfd): perf score=14.095187
I20260812 06:17:30.143674 25245 maintenance_manager.cc:643] P dd4f23643a31400496a29615ad83678d: FlushDeltaMemStoresOp(13c3836bf0214c5cbe44fbdefce90bfd) complete. Timing: real 0.051s	user 0.013s	sys 0.028s Metrics: {"bytes_written":16409903,"delete_count":0,"lbm_write_time_us":20108,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:17:30.144280 25338 maintenance_manager.cc:419] P dd4f23643a31400496a29615ad83678d: Scheduling FlushDeltaMemStoresOp(13c3836bf0214c5cbe44fbdefce90bfd): perf score=2.188937
I20260812 06:17:30.156526 25245 maintenance_manager.cc:643] P dd4f23643a31400496a29615ad83678d: FlushDeltaMemStoresOp(13c3836bf0214c5cbe44fbdefce90bfd) complete. Timing: real 0.012s	user 0.003s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4604,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:30.156993 25338 maintenance_manager.cc:419] P dd4f23643a31400496a29615ad83678d: Scheduling FlushMRSOp(13c3836bf0214c5cbe44fbdefce90bfd): perf score=1.000000
I20260812 06:17:30.194990 25245 maintenance_manager.cc:643] P dd4f23643a31400496a29615ad83678d: FlushMRSOp(13c3836bf0214c5cbe44fbdefce90bfd) complete. Timing: real 0.038s	user 0.028s	sys 0.004s Metrics: {"bytes_written":1152510,"cfile_init":1,"dirs.queue_time_us":51,"dirs.run_cpu_time_us":316,"dirs.run_wall_time_us":1321,"drs_written":1,"lbm_read_time_us":39,"lbm_reads_lt_1ms":4,"lbm_write_time_us":2549,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":28}
I20260812 06:17:30.195727 25338 maintenance_manager.cc:419] P dd4f23643a31400496a29615ad83678d: Scheduling LogGCOp(13c3836bf0214c5cbe44fbdefce90bfd): free 112239497 bytes of WAL
I20260812 06:17:30.195963 25245 log_reader.cc:385] T 13c3836bf0214c5cbe44fbdefce90bfd: removed 11 log segments from log reader
I20260812 06:17:30.196027 25245 log.cc:1079] T 13c3836bf0214c5cbe44fbdefce90bfd P dd4f23643a31400496a29615ad83678d: Deleting log segment in path: /tmp/dist-test-taskQFXsto/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515445504383-25086-0/minicluster-data/ts-0-root/wals/13c3836bf0214c5cbe44fbdefce90bfd/wal-000000027 (ops 128-132)
I20260812 06:17:30.196115 25245 log.cc:1079] T 13c3836bf0214c5cbe44fbdefce90bfd P dd4f23643a31400496a29615ad83678d: Deleting log segment in path: /tmp/dist-test-taskQFXsto/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515445504383-25086-0/minicluster-data/ts-0-root/wals/13c3836bf0214c5cbe44fbdefce90bfd/wal-000000028 (ops 133-137)
I20260812 06:17:30.196173 25245 log.cc:1079] T 13c3836bf0214c5cbe44fbdefce90bfd P dd4f23643a31400496a29615ad83678d: Deleting log segment in path: /tmp/dist-test-taskQFXsto/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515445504383-25086-0/minicluster-data/ts-0-root/wals/13c3836bf0214c5cbe44fbdefce90bfd/wal-000000029 (ops 138-142)
I20260812 06:17:30.196218 25245 log.cc:1079] T 13c3836bf0214c5cbe44fbdefce90bfd P dd4f23643a31400496a29615ad83678d: Deleting log segment in path: /tmp/dist-test-taskQFXsto/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515445504383-25086-0/minicluster-data/ts-0-root/wals/13c3836bf0214c5cbe44fbdefce90bfd/wal-000000030 (ops 143-146)
I20260812 06:17:30.196255 25245 log.cc:1079] T 13c3836bf0214c5cbe44fbdefce90bfd P dd4f23643a31400496a29615ad83678d: Deleting log segment in path: /tmp/dist-test-taskQFXsto/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515445504383-25086-0/minicluster-data/ts-0-root/wals/13c3836bf0214c5cbe44fbdefce90bfd/wal-000000031 (ops 147-151)
I20260812 06:17:30.196295 25245 log.cc:1079] T 13c3836bf0214c5cbe44fbdefce90bfd P dd4f23643a31400496a29615ad83678d: Deleting log segment in path: /tmp/dist-test-taskQFXsto/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515445504383-25086-0/minicluster-data/ts-0-root/wals/13c3836bf0214c5cbe44fbdefce90bfd/wal-000000032 (ops 152-156)
I20260812 06:17:30.196333 25245 log.cc:1079] T 13c3836bf0214c5cbe44fbdefce90bfd P dd4f23643a31400496a29615ad83678d: Deleting log segment in path: /tmp/dist-test-taskQFXsto/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515445504383-25086-0/minicluster-data/ts-0-root/wals/13c3836bf0214c5cbe44fbdefce90bfd/wal-000000033 (ops 157-161)
I20260812 06:17:30.196372 25245 log.cc:1079] T 13c3836bf0214c5cbe44fbdefce90bfd P dd4f23643a31400496a29615ad83678d: Deleting log segment in path: /tmp/dist-test-taskQFXsto/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515445504383-25086-0/minicluster-data/ts-0-root/wals/13c3836bf0214c5cbe44fbdefce90bfd/wal-000000034 (ops 162-166)
I20260812 06:17:30.196411 25245 log.cc:1079] T 13c3836bf0214c5cbe44fbdefce90bfd P dd4f23643a31400496a29615ad83678d: Deleting log segment in path: /tmp/dist-test-taskQFXsto/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515445504383-25086-0/minicluster-data/ts-0-root/wals/13c3836bf0214c5cbe44fbdefce90bfd/wal-000000035 (ops 167-171)
I20260812 06:17:30.196450 25245 log.cc:1079] T 13c3836bf0214c5cbe44fbdefce90bfd P dd4f23643a31400496a29615ad83678d: Deleting log segment in path: /tmp/dist-test-taskQFXsto/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515445504383-25086-0/minicluster-data/ts-0-root/wals/13c3836bf0214c5cbe44fbdefce90bfd/wal-000000036 (ops 172-176)
I20260812 06:17:30.196489 25245 log.cc:1079] T 13c3836bf0214c5cbe44fbdefce90bfd P dd4f23643a31400496a29615ad83678d: Deleting log segment in path: /tmp/dist-test-taskQFXsto/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515445504383-25086-0/minicluster-data/ts-0-root/wals/13c3836bf0214c5cbe44fbdefce90bfd/wal-000000037 (ops 177-181)
I20260812 06:17:30.221469 25245 maintenance_manager.cc:643] P dd4f23643a31400496a29615ad83678d: LogGCOp(13c3836bf0214c5cbe44fbdefce90bfd) complete. Timing: real 0.026s	user 0.000s	sys 0.024s Metrics: {}
I20260812 06:17:30.221937 25338 maintenance_manager.cc:419] P dd4f23643a31400496a29615ad83678d: Scheduling FlushDeltaMemStoresOp(13c3836bf0214c5cbe44fbdefce90bfd): perf score=3.181125
I20260812 06:17:30.249431 25245 maintenance_manager.cc:643] P dd4f23643a31400496a29615ad83678d: FlushDeltaMemStoresOp(13c3836bf0214c5cbe44fbdefce90bfd) complete. Timing: real 0.027s	user 0.011s	sys 0.005s Metrics: {"bytes_written":4512903,"delete_count":0,"lbm_write_time_us":7091,"lbm_writes_lt_1ms":113,"reinsert_count":0,"update_count":550}
I20260812 06:17:30.249940 25338 maintenance_manager.cc:419] P dd4f23643a31400496a29615ad83678d: Scheduling FlushDeltaMemStoresOp(13c3836bf0214c5cbe44fbdefce90bfd): perf score=2.188937
I20260812 06:17:30.259093 25245 maintenance_manager.cc:643] P dd4f23643a31400496a29615ad83678d: FlushDeltaMemStoresOp(13c3836bf0214c5cbe44fbdefce90bfd) complete. Timing: real 0.009s	user 0.007s	sys 0.000s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3437,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:17:30.259529 25338 maintenance_manager.cc:419] P dd4f23643a31400496a29615ad83678d: Scheduling UndoDeltaBlockGCOp(13c3836bf0214c5cbe44fbdefce90bfd): 447 bytes on disk
I20260812 06:17:30.259954 25245 maintenance_manager.cc:643] P dd4f23643a31400496a29615ad83678d: UndoDeltaBlockGCOp(13c3836bf0214c5cbe44fbdefce90bfd) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":55,"lbm_reads_lt_1ms":4}
I20260812 06:17:30.260488 25338 maintenance_manager.cc:419] P dd4f23643a31400496a29615ad83678d: Scheduling MajorDeltaCompactionOp(13c3836bf0214c5cbe44fbdefce90bfd): perf score=1.000000
I20260812 06:17:30.493026 25245 maintenance_manager.cc:643] P dd4f23643a31400496a29615ad83678d: MajorDeltaCompactionOp(13c3836bf0214c5cbe44fbdefce90bfd) complete. Timing: real 0.232s	user 0.163s	sys 0.067s Metrics: {"cfile_cache_miss":734,"cfile_cache_miss_bytes":32938777,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":223,"lbm_read_time_us":16151,"lbm_reads_lt_1ms":774,"lbm_write_time_us":37385,"lbm_writes_lt_1ms":743,"mutex_wait_us":29,"peak_mem_usage":87969044,"reinsert_count":0,"spinlock_wait_cycles":129536,"thread_start_us":81,"threads_started":1,"update_count":3500}
I20260812 06:17:30.493848 25338 maintenance_manager.cc:419] P dd4f23643a31400496a29615ad83678d: Scheduling FlushDeltaMemStoresOp(13c3836bf0214c5cbe44fbdefce90bfd): perf score=18.063937
I20260812 06:17:30.561206 25245 maintenance_manager.cc:643] P dd4f23643a31400496a29615ad83678d: FlushDeltaMemStoresOp(13c3836bf0214c5cbe44fbdefce90bfd) complete. Timing: real 0.067s	user 0.048s	sys 0.004s Metrics: {"bytes_written":20512315,"delete_count":0,"lbm_write_time_us":24154,"lbm_writes_lt_1ms":503,"reinsert_count":0,"update_count":2500}
I20260812 06:17:30.561676 25338 maintenance_manager.cc:419] P dd4f23643a31400496a29615ad83678d: Scheduling FlushDeltaMemStoresOp(13c3836bf0214c5cbe44fbdefce90bfd): perf score=2.188937
I20260812 06:17:30.572677 25245 maintenance_manager.cc:643] P dd4f23643a31400496a29615ad83678d: FlushDeltaMemStoresOp(13c3836bf0214c5cbe44fbdefce90bfd) complete. Timing: real 0.011s	user 0.010s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4170,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:30.573133 25338 maintenance_manager.cc:419] P dd4f23643a31400496a29615ad83678d: Scheduling MajorDeltaCompactionOp(13c3836bf0214c5cbe44fbdefce90bfd): perf score=1.000000
I20260812 06:17:30.668429 25086 heavy-update-compaction-itest.cc:229] Time spent updating: real 4.895s	user 1.834s	sys 0.102s
I20260812 06:17:30.740178 25086 heavy-update-compaction-itest.cc:265] Time spent scanning: real 0.071s	user 0.005s	sys 0.000s
I20260812 06:17:30.740854 25086 tablet_server.cc:179] TabletServer@127.24.127.129:0 shutting down...
I20260812 06:17:30.764292 25245 maintenance_manager.cc:643] P dd4f23643a31400496a29615ad83678d: MajorDeltaCompactionOp(13c3836bf0214c5cbe44fbdefce90bfd) complete. Timing: real 0.191s	user 0.129s	sys 0.060s Metrics: {"cfile_cache_miss":632,"cfile_cache_miss_bytes":28836137,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":698,"lbm_read_time_us":14938,"lbm_reads_lt_1ms":668,"lbm_write_time_us":31428,"lbm_writes_lt_1ms":643,"mutex_wait_us":63,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":12032,"update_count":3000}
I20260812 06:17:30.765094 25086 ts_tablet_manager.cc:1507] Shutting down tablet manager...
I20260812 06:17:30.765511 25086 tablet_replica.cc:333] T 13c3836bf0214c5cbe44fbdefce90bfd P dd4f23643a31400496a29615ad83678d: stopping tablet replica
I20260812 06:17:30.765753 25086 raft_consensus.cc:2243] T 13c3836bf0214c5cbe44fbdefce90bfd P dd4f23643a31400496a29615ad83678d [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:17:30.765996 25086 raft_consensus.cc:2272] T 13c3836bf0214c5cbe44fbdefce90bfd P dd4f23643a31400496a29615ad83678d [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:17:30.798836 25086 tablet_server.cc:196] TabletServer@127.24.127.129:0 shutdown complete.
I20260812 06:17:30.817035 25086 master.cc:562] Master@127.24.127.190:45463 shutting down...
I20260812 06:17:30.820847 25086 raft_consensus.cc:2243] T 00000000000000000000000000000000 P e50fd6b907a94ddea10be5e38edfdbf4 [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:17:30.821045 25086 raft_consensus.cc:2272] T 00000000000000000000000000000000 P e50fd6b907a94ddea10be5e38edfdbf4 [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:17:30.821153 25086 tablet_replica.cc:333] T 00000000000000000000000000000000 P e50fd6b907a94ddea10be5e38edfdbf4: stopping tablet replica
I20260812 06:17:30.833554 25086 master.cc:584] Master@127.24.127.190:45463 shutdown complete.
[       OK ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/0 (5413 ms)
[ RUN      ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/1
I20260812 06:17:30.928896 25086 internal_mini_cluster.cc:156] Creating distributed mini masters. Addrs: 127.24.127.190:44805
I20260812 06:17:30.929425 25086 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:17:30.931501 25389 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:30.931934 25388 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:30.932051 25392 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:30.932256 25086 server_base.cc:1061] running on GCE node
I20260812 06:17:30.932452 25086 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:17:30.932492 25086 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:30.932533 25086 hybrid_clock.cc:648] HybridClock initialized: now 1786515450932515 us; error 0 us; skew 500 ppm
I20260812 06:17:30.933418 25086 webserver.cc:533] Webserver started at http://127.24.127.190:46581/ using document root <none> and password file <none>
I20260812 06:17:30.933607 25086 fs_manager.cc:362] Metadata directory not provided
I20260812 06:17:30.933667 25086 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:17:30.933772 25086 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:17:30.934195 25086 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskQFXsto/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515445504383-25086-0/minicluster-data/master-0-root/instance:
uuid: "8197fbc32dd446fb860e1fbdf1d532aa"
format_stamp: "Formatted at 2026-08-12 06:17:30 on dist-test-slave-t3q3"
I20260812 06:17:30.935701 25086 fs_manager.cc:696] Time spent creating directory manager: real 0.001s	user 0.002s	sys 0.000s
I20260812 06:17:30.936805 25398 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:30.937093 25086 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.000s	sys 0.001s
I20260812 06:17:30.937189 25086 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskQFXsto/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515445504383-25086-0/minicluster-data/master-0-root
uuid: "8197fbc32dd446fb860e1fbdf1d532aa"
format_stamp: "Formatted at 2026-08-12 06:17:30 on dist-test-slave-t3q3"
I20260812 06:17:30.937279 25086 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskQFXsto/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515445504383-25086-0/minicluster-data/master-0-root
metadata directory: /tmp/dist-test-taskQFXsto/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515445504383-25086-0/minicluster-data/master-0-root
1 data directories: /tmp/dist-test-taskQFXsto/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515445504383-25086-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:30.961516 25086 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:17:30.961985 25086 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:17:30.966289 25086 rpc_server.cc:307] RPC server started. Bound to: 127.24.127.190:44805
I20260812 06:17:30.968875 25478 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:30.975338 25477 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.24.127.190:44805 every 8 connection(s)
I20260812 06:17:30.975955 25478 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P 8197fbc32dd446fb860e1fbdf1d532aa: Bootstrap starting.
I20260812 06:17:30.976877 25478 tablet_bootstrap.cc:654] T 00000000000000000000000000000000 P 8197fbc32dd446fb860e1fbdf1d532aa: Neither blocks nor log segments found. Creating new log.
I20260812 06:17:30.978051 25478 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P 8197fbc32dd446fb860e1fbdf1d532aa: No bootstrap required, opened a new log
I20260812 06:17:30.978488 25478 raft_consensus.cc:359] T 00000000000000000000000000000000 P 8197fbc32dd446fb860e1fbdf1d532aa [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "8197fbc32dd446fb860e1fbdf1d532aa" member_type: VOTER }
I20260812 06:17:30.978608 25478 raft_consensus.cc:385] T 00000000000000000000000000000000 P 8197fbc32dd446fb860e1fbdf1d532aa [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:17:30.978659 25478 raft_consensus.cc:740] T 00000000000000000000000000000000 P 8197fbc32dd446fb860e1fbdf1d532aa [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: 8197fbc32dd446fb860e1fbdf1d532aa, State: Initialized, Role: FOLLOWER
I20260812 06:17:30.978824 25478 consensus_queue.cc:260] T 00000000000000000000000000000000 P 8197fbc32dd446fb860e1fbdf1d532aa [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: "8197fbc32dd446fb860e1fbdf1d532aa" member_type: VOTER }
I20260812 06:17:30.978920 25478 raft_consensus.cc:399] T 00000000000000000000000000000000 P 8197fbc32dd446fb860e1fbdf1d532aa [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:17:30.978971 25478 raft_consensus.cc:493] T 00000000000000000000000000000000 P 8197fbc32dd446fb860e1fbdf1d532aa [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:17:30.979038 25478 raft_consensus.cc:3060] T 00000000000000000000000000000000 P 8197fbc32dd446fb860e1fbdf1d532aa [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:17:30.979741 25478 raft_consensus.cc:515] T 00000000000000000000000000000000 P 8197fbc32dd446fb860e1fbdf1d532aa [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "8197fbc32dd446fb860e1fbdf1d532aa" member_type: VOTER }
I20260812 06:17:30.979902 25478 leader_election.cc:304] T 00000000000000000000000000000000 P 8197fbc32dd446fb860e1fbdf1d532aa [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: 8197fbc32dd446fb860e1fbdf1d532aa; no voters: 
I20260812 06:17:30.980165 25478 leader_election.cc:290] T 00000000000000000000000000000000 P 8197fbc32dd446fb860e1fbdf1d532aa [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:17:30.980315 25481 raft_consensus.cc:2804] T 00000000000000000000000000000000 P 8197fbc32dd446fb860e1fbdf1d532aa [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:17:30.980557 25481 raft_consensus.cc:697] T 00000000000000000000000000000000 P 8197fbc32dd446fb860e1fbdf1d532aa [term 1 LEADER]: Becoming Leader. State: Replica: 8197fbc32dd446fb860e1fbdf1d532aa, State: Running, Role: LEADER
I20260812 06:17:30.980669 25478 sys_catalog.cc:565] T 00000000000000000000000000000000 P 8197fbc32dd446fb860e1fbdf1d532aa [sys.catalog]: configured and running, proceeding with master startup.
I20260812 06:17:30.980722 25481 consensus_queue.cc:237] T 00000000000000000000000000000000 P 8197fbc32dd446fb860e1fbdf1d532aa [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: "8197fbc32dd446fb860e1fbdf1d532aa" member_type: VOTER }
I20260812 06:17:30.981194 25482 sys_catalog.cc:455] T 00000000000000000000000000000000 P 8197fbc32dd446fb860e1fbdf1d532aa [sys.catalog]: SysCatalogTable state changed. Reason: RaftConsensus started. Latest consensus state: current_term: 1 leader_uuid: "8197fbc32dd446fb860e1fbdf1d532aa" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "8197fbc32dd446fb860e1fbdf1d532aa" member_type: VOTER } }
I20260812 06:17:30.981248 25484 sys_catalog.cc:455] T 00000000000000000000000000000000 P 8197fbc32dd446fb860e1fbdf1d532aa [sys.catalog]: SysCatalogTable state changed. Reason: New leader 8197fbc32dd446fb860e1fbdf1d532aa. Latest consensus state: current_term: 1 leader_uuid: "8197fbc32dd446fb860e1fbdf1d532aa" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "8197fbc32dd446fb860e1fbdf1d532aa" member_type: VOTER } }
I20260812 06:17:30.981294 25482 sys_catalog.cc:458] T 00000000000000000000000000000000 P 8197fbc32dd446fb860e1fbdf1d532aa [sys.catalog]: This master's current role is: LEADER
I20260812 06:17:30.981352 25484 sys_catalog.cc:458] T 00000000000000000000000000000000 P 8197fbc32dd446fb860e1fbdf1d532aa [sys.catalog]: This master's current role is: LEADER
I20260812 06:17:30.981590 25489 catalog_manager.cc:1511] Loading table and tablet metadata into memory...
I20260812 06:17:30.982605 25489 catalog_manager.cc:1520] Initializing Kudu cluster ID...
I20260812 06:17:30.982813 25086 internal_mini_cluster.cc:184] Waiting to initialize catalog manager on master 0
I20260812 06:17:30.984643 25489 catalog_manager.cc:1383] Generated new cluster ID: 0f52b1a1bb924891af95e0d36177a02a
I20260812 06:17:30.984719 25489 catalog_manager.cc:1531] Initializing Kudu internal certificate authority...
I20260812 06:17:31.001740 25489 catalog_manager.cc:1406] Generated new certificate authority record
I20260812 06:17:31.002357 25489 catalog_manager.cc:1540] Loading token signing keys...
I20260812 06:17:31.008594 25489 catalog_manager.cc:6092] T 00000000000000000000000000000000 P 8197fbc32dd446fb860e1fbdf1d532aa: Generated new TSK 0
I20260812 06:17:31.008826 25489 catalog_manager.cc:1550] Initializing in-progress tserver states...
I20260812 06:17:31.015583 25086 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:17:31.017997 25514 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:31.018002 25509 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:31.018199 25086 server_base.cc:1061] running on GCE node
W20260812 06:17:31.018011 25511 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:31.018477 25086 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:17:31.018522 25086 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:31.018541 25086 hybrid_clock.cc:648] HybridClock initialized: now 1786515451018542 us; error 0 us; skew 500 ppm
I20260812 06:17:31.019383 25086 webserver.cc:533] Webserver started at http://127.24.127.129:35791/ using document root <none> and password file <none>
I20260812 06:17:31.019526 25086 fs_manager.cc:362] Metadata directory not provided
I20260812 06:17:31.019578 25086 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:17:31.019640 25086 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:17:31.020015 25086 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskQFXsto/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515445504383-25086-0/minicluster-data/ts-0-root/instance:
uuid: "cd5ca3a0ba6547428c859e06eb320059"
format_stamp: "Formatted at 2026-08-12 06:17:31 on dist-test-slave-t3q3"
I20260812 06:17:31.021616 25086 fs_manager.cc:696] Time spent creating directory manager: real 0.001s	user 0.001s	sys 0.000s
I20260812 06:17:31.022533 25525 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:31.022768 25086 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.001s	sys 0.000s
I20260812 06:17:31.022832 25086 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskQFXsto/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515445504383-25086-0/minicluster-data/ts-0-root
uuid: "cd5ca3a0ba6547428c859e06eb320059"
format_stamp: "Formatted at 2026-08-12 06:17:31 on dist-test-slave-t3q3"
I20260812 06:17:31.022936 25086 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskQFXsto/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515445504383-25086-0/minicluster-data/ts-0-root
metadata directory: /tmp/dist-test-taskQFXsto/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515445504383-25086-0/minicluster-data/ts-0-root
1 data directories: /tmp/dist-test-taskQFXsto/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515445504383-25086-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:31.043056 25086 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:17:31.043503 25086 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:17:31.043851 25086 txn_system_client.cc:432] TxnSystemClient initialization is disabled...
I20260812 06:17:31.044394 25086 ts_tablet_manager.cc:585] Loaded tablet metadata (0 total tablets, 0 live tablets)
I20260812 06:17:31.044458 25086 ts_tablet_manager.cc:531] Time spent load tablet metadata: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:17:31.044524 25086 ts_tablet_manager.cc:616] Registered 0 tablets
I20260812 06:17:31.044562 25086 ts_tablet_manager.cc:595] Time spent register tablets: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:17:31.049549 25086 rpc_server.cc:307] RPC server started. Bound to: 127.24.127.129:42419
I20260812 06:17:31.050729 25620 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.24.127.129:42419 every 8 connection(s)
I20260812 06:17:31.059904 25622 heartbeater.cc:344] Connected to a master server at 127.24.127.190:44805
I20260812 06:17:31.060016 25622 heartbeater.cc:461] Registering TS with master...
I20260812 06:17:31.060318 25622 heartbeater.cc:507] Master 127.24.127.190:44805 requested a full tablet report, sending...
I20260812 06:17:31.061000 25421 ts_manager.cc:194] Registered new tserver with Master: cd5ca3a0ba6547428c859e06eb320059 (127.24.127.129:42419)
I20260812 06:17:31.061335 25086 internal_mini_cluster.cc:371] 1 TS(s) registered with all masters after 0.011113315s
I20260812 06:17:31.062045 25421 master_service.cc:502] Signed X509 certificate for tserver {username='slave'} at 127.0.0.1:46130
I20260812 06:17:31.068552 25421 catalog_manager.cc:2283] Servicing CreateTable request from {username='slave'} at 127.0.0.1:46138:
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:31.077245 25564 tablet_service.cc:1511] Processing CreateTablet for tablet d1b6bab0be754ae99b308edc42262ae0 (DEFAULT_TABLE table=heavy-update-compaction-test [id=4683aa92b26d48a992cdc02d89fbe674]), partition=
I20260812 06:17:31.077538 25564 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet d1b6bab0be754ae99b308edc42262ae0. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:17:31.079386 25636 tablet_bootstrap.cc:492] T d1b6bab0be754ae99b308edc42262ae0 P cd5ca3a0ba6547428c859e06eb320059: Bootstrap starting.
I20260812 06:17:31.080334 25636 tablet_bootstrap.cc:654] T d1b6bab0be754ae99b308edc42262ae0 P cd5ca3a0ba6547428c859e06eb320059: Neither blocks nor log segments found. Creating new log.
I20260812 06:17:31.081383 25636 tablet_bootstrap.cc:492] T d1b6bab0be754ae99b308edc42262ae0 P cd5ca3a0ba6547428c859e06eb320059: No bootstrap required, opened a new log
I20260812 06:17:31.081483 25636 ts_tablet_manager.cc:1403] T d1b6bab0be754ae99b308edc42262ae0 P cd5ca3a0ba6547428c859e06eb320059: Time spent bootstrapping tablet: real 0.002s	user 0.001s	sys 0.000s
I20260812 06:17:31.081877 25636 raft_consensus.cc:359] T d1b6bab0be754ae99b308edc42262ae0 P cd5ca3a0ba6547428c859e06eb320059 [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "cd5ca3a0ba6547428c859e06eb320059" member_type: VOTER last_known_addr { host: "127.24.127.129" port: 42419 } }
I20260812 06:17:31.081964 25636 raft_consensus.cc:385] T d1b6bab0be754ae99b308edc42262ae0 P cd5ca3a0ba6547428c859e06eb320059 [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:17:31.081986 25636 raft_consensus.cc:740] T d1b6bab0be754ae99b308edc42262ae0 P cd5ca3a0ba6547428c859e06eb320059 [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: cd5ca3a0ba6547428c859e06eb320059, State: Initialized, Role: FOLLOWER
I20260812 06:17:31.082115 25636 consensus_queue.cc:260] T d1b6bab0be754ae99b308edc42262ae0 P cd5ca3a0ba6547428c859e06eb320059 [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: "cd5ca3a0ba6547428c859e06eb320059" member_type: VOTER last_known_addr { host: "127.24.127.129" port: 42419 } }
I20260812 06:17:31.082212 25636 raft_consensus.cc:399] T d1b6bab0be754ae99b308edc42262ae0 P cd5ca3a0ba6547428c859e06eb320059 [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:17:31.082290 25636 raft_consensus.cc:493] T d1b6bab0be754ae99b308edc42262ae0 P cd5ca3a0ba6547428c859e06eb320059 [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:17:31.082355 25636 raft_consensus.cc:3060] T d1b6bab0be754ae99b308edc42262ae0 P cd5ca3a0ba6547428c859e06eb320059 [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:17:31.083262 25636 raft_consensus.cc:515] T d1b6bab0be754ae99b308edc42262ae0 P cd5ca3a0ba6547428c859e06eb320059 [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "cd5ca3a0ba6547428c859e06eb320059" member_type: VOTER last_known_addr { host: "127.24.127.129" port: 42419 } }
I20260812 06:17:31.083416 25636 leader_election.cc:304] T d1b6bab0be754ae99b308edc42262ae0 P cd5ca3a0ba6547428c859e06eb320059 [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: cd5ca3a0ba6547428c859e06eb320059; no voters: 
I20260812 06:17:31.083636 25636 leader_election.cc:290] T d1b6bab0be754ae99b308edc42262ae0 P cd5ca3a0ba6547428c859e06eb320059 [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:17:31.083765 25638 raft_consensus.cc:2804] T d1b6bab0be754ae99b308edc42262ae0 P cd5ca3a0ba6547428c859e06eb320059 [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:17:31.083997 25638 raft_consensus.cc:697] T d1b6bab0be754ae99b308edc42262ae0 P cd5ca3a0ba6547428c859e06eb320059 [term 1 LEADER]: Becoming Leader. State: Replica: cd5ca3a0ba6547428c859e06eb320059, State: Running, Role: LEADER
I20260812 06:17:31.083994 25622 heartbeater.cc:499] Master 127.24.127.190:44805 was elected leader, sending a full tablet report...
I20260812 06:17:31.083979 25636 ts_tablet_manager.cc:1434] T d1b6bab0be754ae99b308edc42262ae0 P cd5ca3a0ba6547428c859e06eb320059: Time spent starting tablet: real 0.002s	user 0.003s	sys 0.000s
I20260812 06:17:31.084272 25638 consensus_queue.cc:237] T d1b6bab0be754ae99b308edc42262ae0 P cd5ca3a0ba6547428c859e06eb320059 [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: "cd5ca3a0ba6547428c859e06eb320059" member_type: VOTER last_known_addr { host: "127.24.127.129" port: 42419 } }
I20260812 06:17:31.085629 25421 catalog_manager.cc:5719] T d1b6bab0be754ae99b308edc42262ae0 P cd5ca3a0ba6547428c859e06eb320059 reported cstate change: term changed from 0 to 1, leader changed from <none> to cd5ca3a0ba6547428c859e06eb320059 (127.24.127.129). New cstate: current_term: 1 leader_uuid: "cd5ca3a0ba6547428c859e06eb320059" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "cd5ca3a0ba6547428c859e06eb320059" member_type: VOTER last_known_addr { host: "127.24.127.129" port: 42419 } health_report { overall_health: HEALTHY } } }
I20260812 06:17:31.146552 25086 heavy-update-compaction-itest.cc:215] Time spent inserting: real 0.054s	user 0.010s	sys 0.012s
I20260812 06:17:31.301261 25624 maintenance_manager.cc:419] P cd5ca3a0ba6547428c859e06eb320059: Scheduling FlushMRSOp(d1b6bab0be754ae99b308edc42262ae0): perf score=19.054940
I20260812 06:17:31.456382 25532 maintenance_manager.cc:643] P cd5ca3a0ba6547428c859e06eb320059: FlushMRSOp(d1b6bab0be754ae99b308edc42262ae0) complete. Timing: real 0.155s	user 0.119s	sys 0.036s Metrics: {"bytes_written":12717738,"cfile_init":1,"delete_count":0,"dirs.queue_time_us":62,"dirs.run_cpu_time_us":231,"dirs.run_wall_time_us":859,"drs_written":1,"lbm_read_time_us":61,"lbm_reads_lt_1ms":4,"lbm_write_time_us":38547,"lbm_writes_lt_1ms":777,"peak_mem_usage":0,"reinsert_count":0,"rows_written":105,"spinlock_wait_cycles":1536,"update_count":1550}
I20260812 06:17:31.457114 25624 maintenance_manager.cc:419] P cd5ca3a0ba6547428c859e06eb320059: Scheduling LogGCOp(d1b6bab0be754ae99b308edc42262ae0): free 20743880 bytes of WAL
I20260812 06:17:31.457382 25532 log_reader.cc:385] T d1b6bab0be754ae99b308edc42262ae0: removed 2 log segments from log reader
I20260812 06:17:31.457465 25532 log.cc:1079] T d1b6bab0be754ae99b308edc42262ae0 P cd5ca3a0ba6547428c859e06eb320059: Deleting log segment in path: /tmp/dist-test-taskQFXsto/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515445504383-25086-0/minicluster-data/ts-0-root/wals/d1b6bab0be754ae99b308edc42262ae0/wal-000000001 (ops 1-6)
I20260812 06:17:31.457595 25532 log.cc:1079] T d1b6bab0be754ae99b308edc42262ae0 P cd5ca3a0ba6547428c859e06eb320059: Deleting log segment in path: /tmp/dist-test-taskQFXsto/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515445504383-25086-0/minicluster-data/ts-0-root/wals/d1b6bab0be754ae99b308edc42262ae0/wal-000000002 (ops 7-11)
I20260812 06:17:31.463526 25532 maintenance_manager.cc:643] P cd5ca3a0ba6547428c859e06eb320059: LogGCOp(d1b6bab0be754ae99b308edc42262ae0) complete. Timing: real 0.006s	user 0.000s	sys 0.003s Metrics: {}
I20260812 06:17:31.463937 25624 maintenance_manager.cc:419] P cd5ca3a0ba6547428c859e06eb320059: Scheduling FlushDeltaMemStoresOp(d1b6bab0be754ae99b308edc42262ae0): perf score=2.188937
I20260812 06:17:31.489039 25532 maintenance_manager.cc:643] P cd5ca3a0ba6547428c859e06eb320059: FlushDeltaMemStoresOp(d1b6bab0be754ae99b308edc42262ae0) complete. Timing: real 0.025s	user 0.011s	sys 0.001s Metrics: {"bytes_written":3692409,"delete_count":0,"lbm_write_time_us":4598,"lbm_writes_lt_1ms":93,"reinsert_count":0,"spinlock_wait_cycles":1408,"update_count":450}
I20260812 06:17:31.489557 25624 maintenance_manager.cc:419] P cd5ca3a0ba6547428c859e06eb320059: Scheduling FlushDeltaMemStoresOp(d1b6bab0be754ae99b308edc42262ae0): perf score=2.188937
I20260812 06:17:31.499074 25532 maintenance_manager.cc:643] P cd5ca3a0ba6547428c859e06eb320059: FlushDeltaMemStoresOp(d1b6bab0be754ae99b308edc42262ae0) complete. Timing: real 0.009s	user 0.000s	sys 0.008s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3650,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:17:31.499677 25624 maintenance_manager.cc:419] P cd5ca3a0ba6547428c859e06eb320059: Scheduling UndoDeltaBlockGCOp(d1b6bab0be754ae99b308edc42262ae0): 16821646 bytes on disk
I20260812 06:17:31.500262 25532 maintenance_manager.cc:643] P cd5ca3a0ba6547428c859e06eb320059: UndoDeltaBlockGCOp(d1b6bab0be754ae99b308edc42262ae0) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":69,"lbm_reads_lt_1ms":4}
I20260812 06:17:31.500846 25624 maintenance_manager.cc:419] P cd5ca3a0ba6547428c859e06eb320059: Scheduling MajorDeltaCompactionOp(d1b6bab0be754ae99b308edc42262ae0): perf score=1.000000
I20260812 06:17:31.666294 25532 maintenance_manager.cc:643] P cd5ca3a0ba6547428c859e06eb320059: MajorDeltaCompactionOp(d1b6bab0be754ae99b308edc42262ae0) complete. Timing: real 0.165s	user 0.117s	sys 0.048s Metrics: {"cfile_cache_miss":523,"cfile_cache_miss_bytes":24405547,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":564,"lbm_read_time_us":13175,"lbm_reads_lt_1ms":559,"lbm_write_time_us":29246,"lbm_writes_lt_1ms":533,"mutex_wait_us":58,"peak_mem_usage":61665166,"reinsert_count":0,"spinlock_wait_cycles":10624,"thread_start_us":369,"threads_started":5,"update_count":2450}
I20260812 06:17:31.666818 25624 maintenance_manager.cc:419] P cd5ca3a0ba6547428c859e06eb320059: Scheduling FlushDeltaMemStoresOp(d1b6bab0be754ae99b308edc42262ae0): perf score=14.095187
I20260812 06:17:31.719326 25532 maintenance_manager.cc:643] P cd5ca3a0ba6547428c859e06eb320059: FlushDeltaMemStoresOp(d1b6bab0be754ae99b308edc42262ae0) complete. Timing: real 0.052s	user 0.029s	sys 0.020s Metrics: {"bytes_written":16409903,"delete_count":0,"lbm_write_time_us":22945,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:17:31.719763 25624 maintenance_manager.cc:419] P cd5ca3a0ba6547428c859e06eb320059: Scheduling FlushDeltaMemStoresOp(d1b6bab0be754ae99b308edc42262ae0): perf score=2.188937
I20260812 06:17:31.730214 25532 maintenance_manager.cc:643] P cd5ca3a0ba6547428c859e06eb320059: FlushDeltaMemStoresOp(d1b6bab0be754ae99b308edc42262ae0) complete. Timing: real 0.010s	user 0.008s	sys 0.000s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":3864,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:31.730806 25624 maintenance_manager.cc:419] P cd5ca3a0ba6547428c859e06eb320059: Scheduling MajorDeltaCompactionOp(d1b6bab0be754ae99b308edc42262ae0): perf score=1.000000
I20260812 06:17:31.910368 25532 maintenance_manager.cc:643] P cd5ca3a0ba6547428c859e06eb320059: MajorDeltaCompactionOp(d1b6bab0be754ae99b308edc42262ae0) complete. Timing: real 0.179s	user 0.132s	sys 0.039s 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":805,"lbm_read_time_us":11581,"lbm_reads_lt_1ms":572,"lbm_write_time_us":32252,"lbm_writes_lt_1ms":543,"mutex_wait_us":386,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":14592,"update_count":2500}
I20260812 06:17:31.911130 25624 maintenance_manager.cc:419] P cd5ca3a0ba6547428c859e06eb320059: Scheduling FlushDeltaMemStoresOp(d1b6bab0be754ae99b308edc42262ae0): perf score=14.095187
I20260812 06:17:31.959064 25532 maintenance_manager.cc:643] P cd5ca3a0ba6547428c859e06eb320059: FlushDeltaMemStoresOp(d1b6bab0be754ae99b308edc42262ae0) complete. Timing: real 0.048s	user 0.041s	sys 0.004s Metrics: {"bytes_written":16409948,"delete_count":0,"lbm_write_time_us":21028,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:17:31.959692 25624 maintenance_manager.cc:419] P cd5ca3a0ba6547428c859e06eb320059: Scheduling MajorDeltaCompactionOp(d1b6bab0be754ae99b308edc42262ae0): perf score=1.000000
I20260812 06:17:32.122135 25532 maintenance_manager.cc:643] P cd5ca3a0ba6547428c859e06eb320059: MajorDeltaCompactionOp(d1b6bab0be754ae99b308edc42262ae0) complete. Timing: real 0.162s	user 0.097s	sys 0.056s Metrics: {"cfile_cache_miss":431,"cfile_cache_miss_bytes":20713199,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":1,"delta_iterators_relevant":1,"dirs.queue_time_us":107,"lbm_read_time_us":11787,"lbm_reads_lt_1ms":467,"lbm_write_time_us":25571,"lbm_writes_lt_1ms":443,"mutex_wait_us":22,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":24576,"update_count":2000}
I20260812 06:17:32.122786 25624 maintenance_manager.cc:419] P cd5ca3a0ba6547428c859e06eb320059: Scheduling FlushDeltaMemStoresOp(d1b6bab0be754ae99b308edc42262ae0): perf score=14.095187
I20260812 06:17:32.179718 25532 maintenance_manager.cc:643] P cd5ca3a0ba6547428c859e06eb320059: FlushDeltaMemStoresOp(d1b6bab0be754ae99b308edc42262ae0) complete. Timing: real 0.057s	user 0.028s	sys 0.020s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":23328,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:17:32.180310 25624 maintenance_manager.cc:419] P cd5ca3a0ba6547428c859e06eb320059: Scheduling FlushDeltaMemStoresOp(d1b6bab0be754ae99b308edc42262ae0): perf score=2.188937
I20260812 06:17:32.191743 25532 maintenance_manager.cc:643] P cd5ca3a0ba6547428c859e06eb320059: FlushDeltaMemStoresOp(d1b6bab0be754ae99b308edc42262ae0) complete. Timing: real 0.011s	user 0.005s	sys 0.004s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4207,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:32.192271 25624 maintenance_manager.cc:419] P cd5ca3a0ba6547428c859e06eb320059: Scheduling MajorDeltaCompactionOp(d1b6bab0be754ae99b308edc42262ae0): perf score=1.000000
I20260812 06:17:32.392866 25532 maintenance_manager.cc:643] P cd5ca3a0ba6547428c859e06eb320059: MajorDeltaCompactionOp(d1b6bab0be754ae99b308edc42262ae0) complete. Timing: real 0.200s	user 0.132s	sys 0.061s 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":707,"lbm_read_time_us":12563,"lbm_reads_lt_1ms":572,"lbm_write_time_us":32508,"lbm_writes_lt_1ms":543,"mutex_wait_us":331,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":20736,"update_count":2500}
I20260812 06:17:32.393646 25624 maintenance_manager.cc:419] P cd5ca3a0ba6547428c859e06eb320059: Scheduling FlushDeltaMemStoresOp(d1b6bab0be754ae99b308edc42262ae0): perf score=14.095187
I20260812 06:17:32.444000 25532 maintenance_manager.cc:643] P cd5ca3a0ba6547428c859e06eb320059: FlushDeltaMemStoresOp(d1b6bab0be754ae99b308edc42262ae0) complete. Timing: real 0.050s	user 0.025s	sys 0.020s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":21913,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:17:32.444566 25624 maintenance_manager.cc:419] P cd5ca3a0ba6547428c859e06eb320059: Scheduling FlushDeltaMemStoresOp(d1b6bab0be754ae99b308edc42262ae0): perf score=2.188937
I20260812 06:17:32.456449 25532 maintenance_manager.cc:643] P cd5ca3a0ba6547428c859e06eb320059: FlushDeltaMemStoresOp(d1b6bab0be754ae99b308edc42262ae0) complete. Timing: real 0.012s	user 0.011s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4220,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:32.457157 25624 maintenance_manager.cc:419] P cd5ca3a0ba6547428c859e06eb320059: Scheduling MajorDeltaCompactionOp(d1b6bab0be754ae99b308edc42262ae0): perf score=1.000000
I20260812 06:17:32.606340 25532 maintenance_manager.cc:643] P cd5ca3a0ba6547428c859e06eb320059: MajorDeltaCompactionOp(d1b6bab0be754ae99b308edc42262ae0) complete. Timing: real 0.149s	user 0.102s	sys 0.040s 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":140,"lbm_read_time_us":11525,"lbm_reads_lt_1ms":572,"lbm_write_time_us":28018,"lbm_writes_lt_1ms":543,"mutex_wait_us":3,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":5760,"update_count":2500}
I20260812 06:17:32.607021 25624 maintenance_manager.cc:419] P cd5ca3a0ba6547428c859e06eb320059: Scheduling FlushDeltaMemStoresOp(d1b6bab0be754ae99b308edc42262ae0): perf score=11.118625
I20260812 06:17:32.640465 25532 maintenance_manager.cc:643] P cd5ca3a0ba6547428c859e06eb320059: FlushDeltaMemStoresOp(d1b6bab0be754ae99b308edc42262ae0) complete. Timing: real 0.033s	user 0.020s	sys 0.012s Metrics: {"bytes_written":12717737,"delete_count":0,"lbm_write_time_us":13749,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:17:32.641556 25624 maintenance_manager.cc:419] P cd5ca3a0ba6547428c859e06eb320059: Scheduling FlushDeltaMemStoresOp(d1b6bab0be754ae99b308edc42262ae0): perf score=2.188937
I20260812 06:17:32.667009 25532 maintenance_manager.cc:643] P cd5ca3a0ba6547428c859e06eb320059: FlushDeltaMemStoresOp(d1b6bab0be754ae99b308edc42262ae0) complete. Timing: real 0.025s	user 0.010s	sys 0.003s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":5676,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:17:32.667534 25624 maintenance_manager.cc:419] P cd5ca3a0ba6547428c859e06eb320059: Scheduling FlushDeltaMemStoresOp(d1b6bab0be754ae99b308edc42262ae0): perf score=2.188937
I20260812 06:17:32.677889 25532 maintenance_manager.cc:643] P cd5ca3a0ba6547428c859e06eb320059: FlushDeltaMemStoresOp(d1b6bab0be754ae99b308edc42262ae0) complete. Timing: real 0.010s	user 0.006s	sys 0.003s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4101,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:32.678349 25624 maintenance_manager.cc:419] P cd5ca3a0ba6547428c859e06eb320059: Scheduling FlushMRSOp(d1b6bab0be754ae99b308edc42262ae0): perf score=1.000000
I20260812 06:17:32.711625 25532 maintenance_manager.cc:643] P cd5ca3a0ba6547428c859e06eb320059: FlushMRSOp(d1b6bab0be754ae99b308edc42262ae0) complete. Timing: real 0.033s	user 0.028s	sys 0.004s Metrics: {"bytes_written":1152508,"cfile_init":1,"dirs.queue_time_us":45,"dirs.run_cpu_time_us":243,"dirs.run_wall_time_us":1439,"drs_written":1,"lbm_read_time_us":41,"lbm_reads_lt_1ms":4,"lbm_write_time_us":2168,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":28}
I20260812 06:17:32.712287 25624 maintenance_manager.cc:419] P cd5ca3a0ba6547428c859e06eb320059: Scheduling LogGCOp(d1b6bab0be754ae99b308edc42262ae0): free 112239314 bytes of WAL
I20260812 06:17:32.712512 25532 log_reader.cc:385] T d1b6bab0be754ae99b308edc42262ae0: removed 11 log segments from log reader
I20260812 06:17:32.712558 25532 log.cc:1079] T d1b6bab0be754ae99b308edc42262ae0 P cd5ca3a0ba6547428c859e06eb320059: Deleting log segment in path: /tmp/dist-test-taskQFXsto/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515445504383-25086-0/minicluster-data/ts-0-root/wals/d1b6bab0be754ae99b308edc42262ae0/wal-000000003 (ops 12-16)
I20260812 06:17:32.712586 25532 log.cc:1079] T d1b6bab0be754ae99b308edc42262ae0 P cd5ca3a0ba6547428c859e06eb320059: Deleting log segment in path: /tmp/dist-test-taskQFXsto/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515445504383-25086-0/minicluster-data/ts-0-root/wals/d1b6bab0be754ae99b308edc42262ae0/wal-000000004 (ops 17-21)
I20260812 06:17:32.712654 25532 log.cc:1079] T d1b6bab0be754ae99b308edc42262ae0 P cd5ca3a0ba6547428c859e06eb320059: Deleting log segment in path: /tmp/dist-test-taskQFXsto/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515445504383-25086-0/minicluster-data/ts-0-root/wals/d1b6bab0be754ae99b308edc42262ae0/wal-000000005 (ops 22-26)
I20260812 06:17:32.712698 25532 log.cc:1079] T d1b6bab0be754ae99b308edc42262ae0 P cd5ca3a0ba6547428c859e06eb320059: Deleting log segment in path: /tmp/dist-test-taskQFXsto/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515445504383-25086-0/minicluster-data/ts-0-root/wals/d1b6bab0be754ae99b308edc42262ae0/wal-000000006 (ops 27-30)
I20260812 06:17:32.712741 25532 log.cc:1079] T d1b6bab0be754ae99b308edc42262ae0 P cd5ca3a0ba6547428c859e06eb320059: Deleting log segment in path: /tmp/dist-test-taskQFXsto/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515445504383-25086-0/minicluster-data/ts-0-root/wals/d1b6bab0be754ae99b308edc42262ae0/wal-000000007 (ops 31-35)
I20260812 06:17:32.712801 25532 log.cc:1079] T d1b6bab0be754ae99b308edc42262ae0 P cd5ca3a0ba6547428c859e06eb320059: Deleting log segment in path: /tmp/dist-test-taskQFXsto/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515445504383-25086-0/minicluster-data/ts-0-root/wals/d1b6bab0be754ae99b308edc42262ae0/wal-000000008 (ops 36-40)
I20260812 06:17:32.712841 25532 log.cc:1079] T d1b6bab0be754ae99b308edc42262ae0 P cd5ca3a0ba6547428c859e06eb320059: Deleting log segment in path: /tmp/dist-test-taskQFXsto/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515445504383-25086-0/minicluster-data/ts-0-root/wals/d1b6bab0be754ae99b308edc42262ae0/wal-000000009 (ops 41-45)
I20260812 06:17:32.712881 25532 log.cc:1079] T d1b6bab0be754ae99b308edc42262ae0 P cd5ca3a0ba6547428c859e06eb320059: Deleting log segment in path: /tmp/dist-test-taskQFXsto/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515445504383-25086-0/minicluster-data/ts-0-root/wals/d1b6bab0be754ae99b308edc42262ae0/wal-000000010 (ops 46-50)
I20260812 06:17:32.712921 25532 log.cc:1079] T d1b6bab0be754ae99b308edc42262ae0 P cd5ca3a0ba6547428c859e06eb320059: Deleting log segment in path: /tmp/dist-test-taskQFXsto/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515445504383-25086-0/minicluster-data/ts-0-root/wals/d1b6bab0be754ae99b308edc42262ae0/wal-000000011 (ops 51-55)
I20260812 06:17:32.712971 25532 log.cc:1079] T d1b6bab0be754ae99b308edc42262ae0 P cd5ca3a0ba6547428c859e06eb320059: Deleting log segment in path: /tmp/dist-test-taskQFXsto/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515445504383-25086-0/minicluster-data/ts-0-root/wals/d1b6bab0be754ae99b308edc42262ae0/wal-000000012 (ops 56-60)
I20260812 06:17:32.713013 25532 log.cc:1079] T d1b6bab0be754ae99b308edc42262ae0 P cd5ca3a0ba6547428c859e06eb320059: Deleting log segment in path: /tmp/dist-test-taskQFXsto/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515445504383-25086-0/minicluster-data/ts-0-root/wals/d1b6bab0be754ae99b308edc42262ae0/wal-000000013 (ops 61-65)
I20260812 06:17:32.739390 25532 maintenance_manager.cc:643] P cd5ca3a0ba6547428c859e06eb320059: LogGCOp(d1b6bab0be754ae99b308edc42262ae0) complete. Timing: real 0.027s	user 0.001s	sys 0.025s Metrics: {}
I20260812 06:17:32.739799 25624 maintenance_manager.cc:419] P cd5ca3a0ba6547428c859e06eb320059: Scheduling FlushDeltaMemStoresOp(d1b6bab0be754ae99b308edc42262ae0): perf score=3.181125
I20260812 06:17:32.770952 25532 maintenance_manager.cc:643] P cd5ca3a0ba6547428c859e06eb320059: FlushDeltaMemStoresOp(d1b6bab0be754ae99b308edc42262ae0) complete. Timing: real 0.031s	user 0.008s	sys 0.018s Metrics: {"bytes_written":4512900,"delete_count":0,"lbm_write_time_us":7333,"lbm_writes_lt_1ms":113,"reinsert_count":0,"update_count":550}
I20260812 06:17:32.771448 25624 maintenance_manager.cc:419] P cd5ca3a0ba6547428c859e06eb320059: Scheduling LogGCOp(d1b6bab0be754ae99b308edc42262ae0): free 12017932 bytes of WAL
I20260812 06:17:32.771684 25532 log_reader.cc:385] T d1b6bab0be754ae99b308edc42262ae0: removed 1 log segments from log reader
I20260812 06:17:32.771732 25532 log.cc:1079] T d1b6bab0be754ae99b308edc42262ae0 P cd5ca3a0ba6547428c859e06eb320059: Deleting log segment in path: /tmp/dist-test-taskQFXsto/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515445504383-25086-0/minicluster-data/ts-0-root/wals/d1b6bab0be754ae99b308edc42262ae0/wal-000000014 (ops 66-70)
I20260812 06:17:32.774226 25532 maintenance_manager.cc:643] P cd5ca3a0ba6547428c859e06eb320059: LogGCOp(d1b6bab0be754ae99b308edc42262ae0) complete. Timing: real 0.003s	user 0.000s	sys 0.000s Metrics: {}
I20260812 06:17:32.774592 25624 maintenance_manager.cc:419] P cd5ca3a0ba6547428c859e06eb320059: Scheduling FlushDeltaMemStoresOp(d1b6bab0be754ae99b308edc42262ae0): perf score=2.188937
I20260812 06:17:32.784605 25532 maintenance_manager.cc:643] P cd5ca3a0ba6547428c859e06eb320059: FlushDeltaMemStoresOp(d1b6bab0be754ae99b308edc42262ae0) complete. Timing: real 0.010s	user 0.004s	sys 0.005s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3835,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:17:32.785006 25624 maintenance_manager.cc:419] P cd5ca3a0ba6547428c859e06eb320059: Scheduling MajorDeltaCompactionOp(d1b6bab0be754ae99b308edc42262ae0): perf score=1.000000
I20260812 06:17:33.034685 25532 maintenance_manager.cc:643] P cd5ca3a0ba6547428c859e06eb320059: MajorDeltaCompactionOp(d1b6bab0be754ae99b308edc42262ae0) complete. Timing: real 0.249s	user 0.142s	sys 0.096s Metrics: {"cfile_cache_miss":735,"cfile_cache_miss_bytes":33020844,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":5,"delta_iterators_relevant":5,"dirs.queue_time_us":381,"lbm_read_time_us":17424,"lbm_reads_lt_1ms":775,"lbm_write_time_us":36907,"lbm_writes_lt_1ms":743,"mutex_wait_us":65,"peak_mem_usage":87969044,"reinsert_count":0,"spinlock_wait_cycles":13952,"thread_start_us":93,"threads_started":1,"update_count":3500}
I20260812 06:17:33.035619 25624 maintenance_manager.cc:419] P cd5ca3a0ba6547428c859e06eb320059: Scheduling UndoDeltaBlockGCOp(d1b6bab0be754ae99b308edc42262ae0): 448 bytes on disk
I20260812 06:17:33.036265 25532 maintenance_manager.cc:643] P cd5ca3a0ba6547428c859e06eb320059: UndoDeltaBlockGCOp(d1b6bab0be754ae99b308edc42262ae0) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":133,"lbm_reads_lt_1ms":4}
I20260812 06:17:33.036755 25624 maintenance_manager.cc:419] P cd5ca3a0ba6547428c859e06eb320059: Scheduling FlushDeltaMemStoresOp(d1b6bab0be754ae99b308edc42262ae0): perf score=18.063937
I20260812 06:17:33.112246 25532 maintenance_manager.cc:643] P cd5ca3a0ba6547428c859e06eb320059: FlushDeltaMemStoresOp(d1b6bab0be754ae99b308edc42262ae0) complete. Timing: real 0.075s	user 0.028s	sys 0.039s Metrics: {"bytes_written":20512315,"delete_count":0,"lbm_write_time_us":32832,"lbm_writes_1-10_ms":2,"lbm_writes_lt_1ms":501,"reinsert_count":0,"update_count":2500}
I20260812 06:17:33.112809 25624 maintenance_manager.cc:419] P cd5ca3a0ba6547428c859e06eb320059: Scheduling FlushDeltaMemStoresOp(d1b6bab0be754ae99b308edc42262ae0): perf score=2.188937
I20260812 06:17:33.123178 25532 maintenance_manager.cc:643] P cd5ca3a0ba6547428c859e06eb320059: FlushDeltaMemStoresOp(d1b6bab0be754ae99b308edc42262ae0) complete. Timing: real 0.010s	user 0.000s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4041,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:33.123730 25624 maintenance_manager.cc:419] P cd5ca3a0ba6547428c859e06eb320059: Scheduling MajorDeltaCompactionOp(d1b6bab0be754ae99b308edc42262ae0): perf score=1.000000
I20260812 06:17:33.372225 25532 maintenance_manager.cc:643] P cd5ca3a0ba6547428c859e06eb320059: MajorDeltaCompactionOp(d1b6bab0be754ae99b308edc42262ae0) complete. Timing: real 0.248s	user 0.135s	sys 0.100s Metrics: {"cfile_cache_miss":632,"cfile_cache_miss_bytes":28918097,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":649,"lbm_read_time_us":17163,"lbm_reads_lt_1ms":672,"lbm_write_time_us":34361,"lbm_writes_lt_1ms":643,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":1664,"update_count":3000}
I20260812 06:17:33.373075 25624 maintenance_manager.cc:419] P cd5ca3a0ba6547428c859e06eb320059: Scheduling FlushDeltaMemStoresOp(d1b6bab0be754ae99b308edc42262ae0): perf score=14.095187
I20260812 06:17:33.460134 25532 maintenance_manager.cc:643] P cd5ca3a0ba6547428c859e06eb320059: FlushDeltaMemStoresOp(d1b6bab0be754ae99b308edc42262ae0) complete. Timing: real 0.087s	user 0.049s	sys 0.016s Metrics: {"bytes_written":16409905,"delete_count":0,"lbm_write_time_us":27969,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":402,"reinsert_count":0,"update_count":2000}
I20260812 06:17:33.460722 25624 maintenance_manager.cc:419] P cd5ca3a0ba6547428c859e06eb320059: Scheduling FlushDeltaMemStoresOp(d1b6bab0be754ae99b308edc42262ae0): perf score=2.188937
I20260812 06:17:33.476025 25532 maintenance_manager.cc:643] P cd5ca3a0ba6547428c859e06eb320059: FlushDeltaMemStoresOp(d1b6bab0be754ae99b308edc42262ae0) complete. Timing: real 0.015s	user 0.006s	sys 0.007s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5734,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:33.476636 25624 maintenance_manager.cc:419] P cd5ca3a0ba6547428c859e06eb320059: Scheduling MajorDeltaCompactionOp(d1b6bab0be754ae99b308edc42262ae0): perf score=1.000000
I20260812 06:17:33.675261 25532 maintenance_manager.cc:643] P cd5ca3a0ba6547428c859e06eb320059: MajorDeltaCompactionOp(d1b6bab0be754ae99b308edc42262ae0) complete. Timing: real 0.198s	user 0.122s	sys 0.070s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24815687,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":1008,"lbm_read_time_us":14878,"lbm_reads_lt_1ms":572,"lbm_write_time_us":33704,"lbm_writes_lt_1ms":543,"mutex_wait_us":262,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":5632,"update_count":2500}
I20260812 06:17:33.675917 25624 maintenance_manager.cc:419] P cd5ca3a0ba6547428c859e06eb320059: Scheduling FlushDeltaMemStoresOp(d1b6bab0be754ae99b308edc42262ae0): perf score=14.095187
I20260812 06:17:33.733306 25532 maintenance_manager.cc:643] P cd5ca3a0ba6547428c859e06eb320059: FlushDeltaMemStoresOp(d1b6bab0be754ae99b308edc42262ae0) complete. Timing: real 0.057s	user 0.035s	sys 0.014s Metrics: {"bytes_written":16409903,"delete_count":0,"lbm_write_time_us":21057,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:17:33.733819 25624 maintenance_manager.cc:419] P cd5ca3a0ba6547428c859e06eb320059: Scheduling FlushDeltaMemStoresOp(d1b6bab0be754ae99b308edc42262ae0): perf score=2.188937
I20260812 06:17:33.746248 25532 maintenance_manager.cc:643] P cd5ca3a0ba6547428c859e06eb320059: FlushDeltaMemStoresOp(d1b6bab0be754ae99b308edc42262ae0) complete. Timing: real 0.012s	user 0.002s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4642,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:33.746762 25624 maintenance_manager.cc:419] P cd5ca3a0ba6547428c859e06eb320059: Scheduling MajorDeltaCompactionOp(d1b6bab0be754ae99b308edc42262ae0): perf score=1.000000
I20260812 06:17:33.908490 25532 maintenance_manager.cc:643] P cd5ca3a0ba6547428c859e06eb320059: MajorDeltaCompactionOp(d1b6bab0be754ae99b308edc42262ae0) complete. Timing: real 0.162s	user 0.105s	sys 0.056s 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":1531,"lbm_read_time_us":11339,"lbm_reads_lt_1ms":572,"lbm_write_time_us":27631,"lbm_writes_lt_1ms":543,"mutex_wait_us":361,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":115328,"update_count":2500}
I20260812 06:17:33.909126 25624 maintenance_manager.cc:419] P cd5ca3a0ba6547428c859e06eb320059: Scheduling FlushDeltaMemStoresOp(d1b6bab0be754ae99b308edc42262ae0): perf score=14.095187
I20260812 06:17:33.970301 25532 maintenance_manager.cc:643] P cd5ca3a0ba6547428c859e06eb320059: FlushDeltaMemStoresOp(d1b6bab0be754ae99b308edc42262ae0) complete. Timing: real 0.061s	user 0.036s	sys 0.020s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":21760,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:17:33.970793 25624 maintenance_manager.cc:419] P cd5ca3a0ba6547428c859e06eb320059: Scheduling FlushDeltaMemStoresOp(d1b6bab0be754ae99b308edc42262ae0): perf score=2.188937
I20260812 06:17:33.981630 25532 maintenance_manager.cc:643] P cd5ca3a0ba6547428c859e06eb320059: FlushDeltaMemStoresOp(d1b6bab0be754ae99b308edc42262ae0) complete. Timing: real 0.011s	user 0.005s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4238,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:33.982185 25624 maintenance_manager.cc:419] P cd5ca3a0ba6547428c859e06eb320059: Scheduling MajorDeltaCompactionOp(d1b6bab0be754ae99b308edc42262ae0): perf score=1.000000
I20260812 06:17:34.159700 25532 maintenance_manager.cc:643] P cd5ca3a0ba6547428c859e06eb320059: MajorDeltaCompactionOp(d1b6bab0be754ae99b308edc42262ae0) complete. Timing: real 0.177s	user 0.111s	sys 0.063s 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":632,"lbm_read_time_us":12390,"lbm_reads_lt_1ms":572,"lbm_write_time_us":30307,"lbm_writes_lt_1ms":543,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":23424,"update_count":2500}
I20260812 06:17:34.160427 25624 maintenance_manager.cc:419] P cd5ca3a0ba6547428c859e06eb320059: Scheduling FlushDeltaMemStoresOp(d1b6bab0be754ae99b308edc42262ae0): perf score=10.126437
I20260812 06:17:34.208819 25532 maintenance_manager.cc:643] P cd5ca3a0ba6547428c859e06eb320059: FlushDeltaMemStoresOp(d1b6bab0be754ae99b308edc42262ae0) complete. Timing: real 0.048s	user 0.028s	sys 0.017s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":22023,"lbm_writes_1-10_ms":3,"lbm_writes_lt_1ms":300,"reinsert_count":0,"update_count":1500}
I20260812 06:17:34.209424 25624 maintenance_manager.cc:419] P cd5ca3a0ba6547428c859e06eb320059: Scheduling FlushDeltaMemStoresOp(d1b6bab0be754ae99b308edc42262ae0): perf score=2.188937
I20260812 06:17:34.222407 25532 maintenance_manager.cc:643] P cd5ca3a0ba6547428c859e06eb320059: FlushDeltaMemStoresOp(d1b6bab0be754ae99b308edc42262ae0) complete. Timing: real 0.013s	user 0.008s	sys 0.003s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5145,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:34.223071 25624 maintenance_manager.cc:419] P cd5ca3a0ba6547428c859e06eb320059: Scheduling MajorDeltaCompactionOp(d1b6bab0be754ae99b308edc42262ae0): perf score=1.000000
I20260812 06:17:34.378603 25532 maintenance_manager.cc:643] P cd5ca3a0ba6547428c859e06eb320059: MajorDeltaCompactionOp(d1b6bab0be754ae99b308edc42262ae0) complete. Timing: real 0.155s	user 0.095s	sys 0.049s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20713272,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":818,"lbm_read_time_us":8740,"lbm_reads_lt_1ms":464,"lbm_write_time_us":22851,"lbm_writes_lt_1ms":443,"mutex_wait_us":71,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":768,"update_count":2000}
I20260812 06:17:34.379490 25624 maintenance_manager.cc:419] P cd5ca3a0ba6547428c859e06eb320059: Scheduling FlushDeltaMemStoresOp(d1b6bab0be754ae99b308edc42262ae0): perf score=11.118625
I20260812 06:17:34.414873 25532 maintenance_manager.cc:643] P cd5ca3a0ba6547428c859e06eb320059: FlushDeltaMemStoresOp(d1b6bab0be754ae99b308edc42262ae0) complete. Timing: real 0.035s	user 0.016s	sys 0.016s Metrics: {"bytes_written":12717735,"delete_count":0,"lbm_write_time_us":15806,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:17:34.415421 25624 maintenance_manager.cc:419] P cd5ca3a0ba6547428c859e06eb320059: Scheduling FlushDeltaMemStoresOp(d1b6bab0be754ae99b308edc42262ae0): perf score=2.188937
I20260812 06:17:34.433070 25532 maintenance_manager.cc:643] P cd5ca3a0ba6547428c859e06eb320059: FlushDeltaMemStoresOp(d1b6bab0be754ae99b308edc42262ae0) complete. Timing: real 0.017s	user 0.012s	sys 0.001s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":5464,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:17:34.433835 25624 maintenance_manager.cc:419] P cd5ca3a0ba6547428c859e06eb320059: Scheduling FlushMRSOp(d1b6bab0be754ae99b308edc42262ae0): perf score=1.000000
I20260812 06:17:34.485371 25532 maintenance_manager.cc:643] P cd5ca3a0ba6547428c859e06eb320059: FlushMRSOp(d1b6bab0be754ae99b308edc42262ae0) complete. Timing: real 0.051s	user 0.030s	sys 0.004s Metrics: {"bytes_written":1316419,"cfile_init":1,"dirs.queue_time_us":36,"dirs.run_cpu_time_us":195,"dirs.run_wall_time_us":1147,"drs_written":1,"lbm_read_time_us":118,"lbm_reads_lt_1ms":4,"lbm_write_time_us":3380,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":38,"peak_mem_usage":0,"rows_written":32}
I20260812 06:17:34.486176 25624 maintenance_manager.cc:419] P cd5ca3a0ba6547428c859e06eb320059: Scheduling LogGCOp(d1b6bab0be754ae99b308edc42262ae0): free 121459497 bytes of WAL
I20260812 06:17:34.486459 25532 log_reader.cc:385] T d1b6bab0be754ae99b308edc42262ae0: removed 12 log segments from log reader
I20260812 06:17:34.486531 25532 log.cc:1079] T d1b6bab0be754ae99b308edc42262ae0 P cd5ca3a0ba6547428c859e06eb320059: Deleting log segment in path: /tmp/dist-test-taskQFXsto/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515445504383-25086-0/minicluster-data/ts-0-root/wals/d1b6bab0be754ae99b308edc42262ae0/wal-000000015 (ops 71-75)
I20260812 06:17:34.486572 25532 log.cc:1079] T d1b6bab0be754ae99b308edc42262ae0 P cd5ca3a0ba6547428c859e06eb320059: Deleting log segment in path: /tmp/dist-test-taskQFXsto/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515445504383-25086-0/minicluster-data/ts-0-root/wals/d1b6bab0be754ae99b308edc42262ae0/wal-000000016 (ops 76-80)
I20260812 06:17:34.486609 25532 log.cc:1079] T d1b6bab0be754ae99b308edc42262ae0 P cd5ca3a0ba6547428c859e06eb320059: Deleting log segment in path: /tmp/dist-test-taskQFXsto/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515445504383-25086-0/minicluster-data/ts-0-root/wals/d1b6bab0be754ae99b308edc42262ae0/wal-000000017 (ops 81-85)
I20260812 06:17:34.486644 25532 log.cc:1079] T d1b6bab0be754ae99b308edc42262ae0 P cd5ca3a0ba6547428c859e06eb320059: Deleting log segment in path: /tmp/dist-test-taskQFXsto/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515445504383-25086-0/minicluster-data/ts-0-root/wals/d1b6bab0be754ae99b308edc42262ae0/wal-000000018 (ops 86-90)
I20260812 06:17:34.486673 25532 log.cc:1079] T d1b6bab0be754ae99b308edc42262ae0 P cd5ca3a0ba6547428c859e06eb320059: Deleting log segment in path: /tmp/dist-test-taskQFXsto/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515445504383-25086-0/minicluster-data/ts-0-root/wals/d1b6bab0be754ae99b308edc42262ae0/wal-000000019 (ops 91-95)
I20260812 06:17:34.486702 25532 log.cc:1079] T d1b6bab0be754ae99b308edc42262ae0 P cd5ca3a0ba6547428c859e06eb320059: Deleting log segment in path: /tmp/dist-test-taskQFXsto/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515445504383-25086-0/minicluster-data/ts-0-root/wals/d1b6bab0be754ae99b308edc42262ae0/wal-000000020 (ops 96-100)
I20260812 06:17:34.486734 25532 log.cc:1079] T d1b6bab0be754ae99b308edc42262ae0 P cd5ca3a0ba6547428c859e06eb320059: Deleting log segment in path: /tmp/dist-test-taskQFXsto/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515445504383-25086-0/minicluster-data/ts-0-root/wals/d1b6bab0be754ae99b308edc42262ae0/wal-000000021 (ops 101-105)
I20260812 06:17:34.486769 25532 log.cc:1079] T d1b6bab0be754ae99b308edc42262ae0 P cd5ca3a0ba6547428c859e06eb320059: Deleting log segment in path: /tmp/dist-test-taskQFXsto/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515445504383-25086-0/minicluster-data/ts-0-root/wals/d1b6bab0be754ae99b308edc42262ae0/wal-000000022 (ops 106-110)
I20260812 06:17:34.486799 25532 log.cc:1079] T d1b6bab0be754ae99b308edc42262ae0 P cd5ca3a0ba6547428c859e06eb320059: Deleting log segment in path: /tmp/dist-test-taskQFXsto/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515445504383-25086-0/minicluster-data/ts-0-root/wals/d1b6bab0be754ae99b308edc42262ae0/wal-000000023 (ops 111-115)
I20260812 06:17:34.486828 25532 log.cc:1079] T d1b6bab0be754ae99b308edc42262ae0 P cd5ca3a0ba6547428c859e06eb320059: Deleting log segment in path: /tmp/dist-test-taskQFXsto/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515445504383-25086-0/minicluster-data/ts-0-root/wals/d1b6bab0be754ae99b308edc42262ae0/wal-000000024 (ops 116-120)
I20260812 06:17:34.486857 25532 log.cc:1079] T d1b6bab0be754ae99b308edc42262ae0 P cd5ca3a0ba6547428c859e06eb320059: Deleting log segment in path: /tmp/dist-test-taskQFXsto/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515445504383-25086-0/minicluster-data/ts-0-root/wals/d1b6bab0be754ae99b308edc42262ae0/wal-000000025 (ops 121-125)
I20260812 06:17:34.486887 25532 log.cc:1079] T d1b6bab0be754ae99b308edc42262ae0 P cd5ca3a0ba6547428c859e06eb320059: Deleting log segment in path: /tmp/dist-test-taskQFXsto/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515445504383-25086-0/minicluster-data/ts-0-root/wals/d1b6bab0be754ae99b308edc42262ae0/wal-000000026 (ops 126-130)
I20260812 06:17:34.517983 25532 maintenance_manager.cc:643] P cd5ca3a0ba6547428c859e06eb320059: LogGCOp(d1b6bab0be754ae99b308edc42262ae0) complete. Timing: real 0.032s	user 0.000s	sys 0.030s Metrics: {}
I20260812 06:17:34.518440 25624 maintenance_manager.cc:419] P cd5ca3a0ba6547428c859e06eb320059: Scheduling FlushDeltaMemStoresOp(d1b6bab0be754ae99b308edc42262ae0): perf score=6.157687
I20260812 06:17:34.540904 25532 maintenance_manager.cc:643] P cd5ca3a0ba6547428c859e06eb320059: FlushDeltaMemStoresOp(d1b6bab0be754ae99b308edc42262ae0) complete. Timing: real 0.022s	user 0.012s	sys 0.007s Metrics: {"bytes_written":8205078,"delete_count":0,"lbm_write_time_us":8725,"lbm_writes_lt_1ms":203,"reinsert_count":0,"update_count":1000}
I20260812 06:17:34.541527 25624 maintenance_manager.cc:419] P cd5ca3a0ba6547428c859e06eb320059: Scheduling LogGCOp(d1b6bab0be754ae99b308edc42262ae0): free 11564893 bytes of WAL
I20260812 06:17:34.541767 25532 log_reader.cc:385] T d1b6bab0be754ae99b308edc42262ae0: removed 1 log segments from log reader
I20260812 06:17:34.541834 25532 log.cc:1079] T d1b6bab0be754ae99b308edc42262ae0 P cd5ca3a0ba6547428c859e06eb320059: Deleting log segment in path: /tmp/dist-test-taskQFXsto/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515445504383-25086-0/minicluster-data/ts-0-root/wals/d1b6bab0be754ae99b308edc42262ae0/wal-000000027 (ops 131-134)
I20260812 06:17:34.544201 25532 maintenance_manager.cc:643] P cd5ca3a0ba6547428c859e06eb320059: LogGCOp(d1b6bab0be754ae99b308edc42262ae0) complete. Timing: real 0.002s	user 0.000s	sys 0.002s Metrics: {}
I20260812 06:17:34.544502 25624 maintenance_manager.cc:419] P cd5ca3a0ba6547428c859e06eb320059: Scheduling UndoDeltaBlockGCOp(d1b6bab0be754ae99b308edc42262ae0): 492 bytes on disk
I20260812 06:17:34.544891 25532 maintenance_manager.cc:643] P cd5ca3a0ba6547428c859e06eb320059: UndoDeltaBlockGCOp(d1b6bab0be754ae99b308edc42262ae0) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":53,"lbm_reads_lt_1ms":4}
I20260812 06:17:34.545339 25624 maintenance_manager.cc:419] P cd5ca3a0ba6547428c859e06eb320059: Scheduling FlushDeltaMemStoresOp(d1b6bab0be754ae99b308edc42262ae0): perf score=2.188937
I20260812 06:17:34.557758 25532 maintenance_manager.cc:643] P cd5ca3a0ba6547428c859e06eb320059: FlushDeltaMemStoresOp(d1b6bab0be754ae99b308edc42262ae0) complete. Timing: real 0.012s	user 0.006s	sys 0.005s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4524,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:34.566799 25624 maintenance_manager.cc:419] P cd5ca3a0ba6547428c859e06eb320059: Scheduling MajorDeltaCompactionOp(d1b6bab0be754ae99b308edc42262ae0): perf score=1.000000
I20260812 06:17:34.804391 25532 maintenance_manager.cc:643] P cd5ca3a0ba6547428c859e06eb320059: MajorDeltaCompactionOp(d1b6bab0be754ae99b308edc42262ae0) complete. Timing: real 0.237s	user 0.133s	sys 0.098s Metrics: {"cfile_cache_miss":734,"cfile_cache_miss_bytes":33020737,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":6041,"lbm_read_time_us":16280,"lbm_reads_lt_1ms":766,"lbm_write_time_us":40831,"lbm_writes_lt_1ms":743,"mutex_wait_us":2754,"peak_mem_usage":87969044,"reinsert_count":0,"spinlock_wait_cycles":4224,"thread_start_us":83,"threads_started":1,"update_count":3500}
I20260812 06:17:34.805123 25624 maintenance_manager.cc:419] P cd5ca3a0ba6547428c859e06eb320059: Scheduling FlushDeltaMemStoresOp(d1b6bab0be754ae99b308edc42262ae0): perf score=18.063937
I20260812 06:17:34.881670 25532 maintenance_manager.cc:643] P cd5ca3a0ba6547428c859e06eb320059: FlushDeltaMemStoresOp(d1b6bab0be754ae99b308edc42262ae0) complete. Timing: real 0.076s	user 0.058s	sys 0.018s Metrics: {"bytes_written":20512317,"delete_count":0,"lbm_write_time_us":33513,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":502,"reinsert_count":0,"update_count":2500}
I20260812 06:17:34.882256 25624 maintenance_manager.cc:419] P cd5ca3a0ba6547428c859e06eb320059: Scheduling FlushDeltaMemStoresOp(d1b6bab0be754ae99b308edc42262ae0): perf score=2.188937
I20260812 06:17:34.895941 25532 maintenance_manager.cc:643] P cd5ca3a0ba6547428c859e06eb320059: FlushDeltaMemStoresOp(d1b6bab0be754ae99b308edc42262ae0) complete. Timing: real 0.013s	user 0.003s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4926,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:34.896487 25624 maintenance_manager.cc:419] P cd5ca3a0ba6547428c859e06eb320059: Scheduling MajorDeltaCompactionOp(d1b6bab0be754ae99b308edc42262ae0): perf score=1.000000
I20260812 06:17:35.114420 25532 maintenance_manager.cc:643] P cd5ca3a0ba6547428c859e06eb320059: MajorDeltaCompactionOp(d1b6bab0be754ae99b308edc42262ae0) complete. Timing: real 0.218s	user 0.159s	sys 0.057s Metrics: {"cfile_cache_miss":632,"cfile_cache_miss_bytes":28918099,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":252,"lbm_read_time_us":15352,"lbm_reads_lt_1ms":672,"lbm_write_time_us":36977,"lbm_writes_lt_1ms":643,"mutex_wait_us":41,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":26624,"update_count":3000}
I20260812 06:17:35.115252 25624 maintenance_manager.cc:419] P cd5ca3a0ba6547428c859e06eb320059: Scheduling FlushDeltaMemStoresOp(d1b6bab0be754ae99b308edc42262ae0): perf score=18.063937
I20260812 06:17:35.183871 25532 maintenance_manager.cc:643] P cd5ca3a0ba6547428c859e06eb320059: FlushDeltaMemStoresOp(d1b6bab0be754ae99b308edc42262ae0) complete. Timing: real 0.068s	user 0.033s	sys 0.028s Metrics: {"bytes_written":19691832,"delete_count":0,"lbm_write_time_us":28047,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":482,"reinsert_count":0,"update_count":2400}
I20260812 06:17:35.184355 25624 maintenance_manager.cc:419] P cd5ca3a0ba6547428c859e06eb320059: Scheduling FlushDeltaMemStoresOp(d1b6bab0be754ae99b308edc42262ae0): perf score=3.181125
I20260812 06:17:35.196310 25532 maintenance_manager.cc:643] P cd5ca3a0ba6547428c859e06eb320059: FlushDeltaMemStoresOp(d1b6bab0be754ae99b308edc42262ae0) complete. Timing: real 0.012s	user 0.011s	sys 0.001s Metrics: {"bytes_written":4923146,"delete_count":0,"lbm_write_time_us":4732,"lbm_writes_lt_1ms":123,"reinsert_count":0,"update_count":600}
I20260812 06:17:35.196798 25624 maintenance_manager.cc:419] P cd5ca3a0ba6547428c859e06eb320059: Scheduling MajorDeltaCompactionOp(d1b6bab0be754ae99b308edc42262ae0): perf score=1.000000
I20260812 06:17:35.404299 25532 maintenance_manager.cc:643] P cd5ca3a0ba6547428c859e06eb320059: MajorDeltaCompactionOp(d1b6bab0be754ae99b308edc42262ae0) complete. Timing: real 0.207s	user 0.109s	sys 0.096s Metrics: {"cfile_cache_miss":632,"cfile_cache_miss_bytes":28918101,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":572,"lbm_read_time_us":13965,"lbm_reads_lt_1ms":672,"lbm_write_time_us":35613,"lbm_writes_lt_1ms":643,"mutex_wait_us":114,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":10368,"update_count":3000}
I20260812 06:17:35.405138 25624 maintenance_manager.cc:419] P cd5ca3a0ba6547428c859e06eb320059: Scheduling FlushDeltaMemStoresOp(d1b6bab0be754ae99b308edc42262ae0): perf score=14.095187
I20260812 06:17:35.459789 25532 maintenance_manager.cc:643] P cd5ca3a0ba6547428c859e06eb320059: FlushDeltaMemStoresOp(d1b6bab0be754ae99b308edc42262ae0) complete. Timing: real 0.054s	user 0.026s	sys 0.025s Metrics: {"bytes_written":16409900,"delete_count":0,"lbm_write_time_us":24290,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:17:35.460407 25624 maintenance_manager.cc:419] P cd5ca3a0ba6547428c859e06eb320059: Scheduling FlushDeltaMemStoresOp(d1b6bab0be754ae99b308edc42262ae0): perf score=2.188937
I20260812 06:17:35.486621 25532 maintenance_manager.cc:643] P cd5ca3a0ba6547428c859e06eb320059: FlushDeltaMemStoresOp(d1b6bab0be754ae99b308edc42262ae0) complete. Timing: real 0.026s	user 0.008s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5354,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:35.487054 25624 maintenance_manager.cc:419] P cd5ca3a0ba6547428c859e06eb320059: Scheduling FlushDeltaMemStoresOp(d1b6bab0be754ae99b308edc42262ae0): perf score=2.188937
I20260812 06:17:35.497253 25532 maintenance_manager.cc:643] P cd5ca3a0ba6547428c859e06eb320059: FlushDeltaMemStoresOp(d1b6bab0be754ae99b308edc42262ae0) complete. Timing: real 0.010s	user 0.001s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4077,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:35.497653 25624 maintenance_manager.cc:419] P cd5ca3a0ba6547428c859e06eb320059: Scheduling MajorDeltaCompactionOp(d1b6bab0be754ae99b308edc42262ae0): perf score=1.000000
I20260812 06:17:35.698053 25532 maintenance_manager.cc:643] P cd5ca3a0ba6547428c859e06eb320059: MajorDeltaCompactionOp(d1b6bab0be754ae99b308edc42262ae0) complete. Timing: real 0.200s	user 0.121s	sys 0.079s Metrics: {"cfile_cache_miss":633,"cfile_cache_miss_bytes":28918213,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":203,"lbm_read_time_us":13657,"lbm_reads_lt_1ms":673,"lbm_write_time_us":34001,"lbm_writes_lt_1ms":643,"mutex_wait_us":24,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":9088,"update_count":3000}
I20260812 06:17:35.698863 25624 maintenance_manager.cc:419] P cd5ca3a0ba6547428c859e06eb320059: Scheduling FlushDeltaMemStoresOp(d1b6bab0be754ae99b308edc42262ae0): perf score=14.095187
I20260812 06:17:35.756378 25532 maintenance_manager.cc:643] P cd5ca3a0ba6547428c859e06eb320059: FlushDeltaMemStoresOp(d1b6bab0be754ae99b308edc42262ae0) complete. Timing: real 0.057s	user 0.033s	sys 0.023s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":25008,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:17:35.756919 25624 maintenance_manager.cc:419] P cd5ca3a0ba6547428c859e06eb320059: Scheduling FlushDeltaMemStoresOp(d1b6bab0be754ae99b308edc42262ae0): perf score=3.181125
I20260812 06:17:35.772842 25532 maintenance_manager.cc:643] P cd5ca3a0ba6547428c859e06eb320059: FlushDeltaMemStoresOp(d1b6bab0be754ae99b308edc42262ae0) complete. Timing: real 0.016s	user 0.011s	sys 0.000s Metrics: {"bytes_written":4512904,"delete_count":0,"lbm_write_time_us":4540,"lbm_writes_lt_1ms":113,"reinsert_count":0,"update_count":550}
I20260812 06:17:35.773353 25624 maintenance_manager.cc:419] P cd5ca3a0ba6547428c859e06eb320059: Scheduling FlushDeltaMemStoresOp(d1b6bab0be754ae99b308edc42262ae0): perf score=2.188937
I20260812 06:17:35.786849 25532 maintenance_manager.cc:643] P cd5ca3a0ba6547428c859e06eb320059: FlushDeltaMemStoresOp(d1b6bab0be754ae99b308edc42262ae0) complete. Timing: real 0.013s	user 0.011s	sys 0.000s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":5187,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:17:35.787350 25624 maintenance_manager.cc:419] P cd5ca3a0ba6547428c859e06eb320059: Scheduling MajorDeltaCompactionOp(d1b6bab0be754ae99b308edc42262ae0): perf score=1.000000
I20260812 06:17:35.999789 25532 maintenance_manager.cc:643] P cd5ca3a0ba6547428c859e06eb320059: MajorDeltaCompactionOp(d1b6bab0be754ae99b308edc42262ae0) complete. Timing: real 0.212s	user 0.160s	sys 0.052s Metrics: {"cfile_cache_miss":633,"cfile_cache_miss_bytes":28918205,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":1018,"lbm_read_time_us":13850,"lbm_reads_lt_1ms":673,"lbm_write_time_us":36975,"lbm_writes_lt_1ms":643,"mutex_wait_us":290,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":20480,"update_count":3000}
I20260812 06:17:36.000588 25624 maintenance_manager.cc:419] P cd5ca3a0ba6547428c859e06eb320059: Scheduling FlushDeltaMemStoresOp(d1b6bab0be754ae99b308edc42262ae0): perf score=14.095187
I20260812 06:17:36.054720 25532 maintenance_manager.cc:643] P cd5ca3a0ba6547428c859e06eb320059: FlushDeltaMemStoresOp(d1b6bab0be754ae99b308edc42262ae0) complete. Timing: real 0.054s	user 0.017s	sys 0.032s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":21891,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:17:36.055299 25624 maintenance_manager.cc:419] P cd5ca3a0ba6547428c859e06eb320059: Scheduling FlushDeltaMemStoresOp(d1b6bab0be754ae99b308edc42262ae0): perf score=3.181125
I20260812 06:17:36.075765 25532 maintenance_manager.cc:643] P cd5ca3a0ba6547428c859e06eb320059: FlushDeltaMemStoresOp(d1b6bab0be754ae99b308edc42262ae0) complete. Timing: real 0.020s	user 0.003s	sys 0.007s Metrics: {"bytes_written":4512903,"delete_count":0,"lbm_write_time_us":4984,"lbm_writes_lt_1ms":113,"reinsert_count":0,"update_count":550}
I20260812 06:17:36.076328 25624 maintenance_manager.cc:419] P cd5ca3a0ba6547428c859e06eb320059: Scheduling FlushDeltaMemStoresOp(d1b6bab0be754ae99b308edc42262ae0): perf score=2.188937
I20260812 06:17:36.090147 25532 maintenance_manager.cc:643] P cd5ca3a0ba6547428c859e06eb320059: FlushDeltaMemStoresOp(d1b6bab0be754ae99b308edc42262ae0) complete. Timing: real 0.014s	user 0.002s	sys 0.009s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":5282,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:17:36.090659 25624 maintenance_manager.cc:419] P cd5ca3a0ba6547428c859e06eb320059: Scheduling FlushMRSOp(d1b6bab0be754ae99b308edc42262ae0): perf score=1.000000
I20260812 06:17:36.123238 25532 maintenance_manager.cc:643] P cd5ca3a0ba6547428c859e06eb320059: FlushMRSOp(d1b6bab0be754ae99b308edc42262ae0) complete. Timing: real 0.032s	user 0.027s	sys 0.004s Metrics: {"bytes_written":1316417,"cfile_init":1,"dirs.queue_time_us":81,"dirs.run_cpu_time_us":211,"dirs.run_wall_time_us":1253,"drs_written":1,"lbm_read_time_us":69,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1739,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":32}
I20260812 06:17:36.124022 25624 maintenance_manager.cc:419] P cd5ca3a0ba6547428c859e06eb320059: Scheduling LogGCOp(d1b6bab0be754ae99b308edc42262ae0): free 124710570 bytes of WAL
I20260812 06:17:36.124351 25532 log_reader.cc:385] T d1b6bab0be754ae99b308edc42262ae0: removed 12 log segments from log reader
I20260812 06:17:36.124405 25532 log.cc:1079] T d1b6bab0be754ae99b308edc42262ae0 P cd5ca3a0ba6547428c859e06eb320059: Deleting log segment in path: /tmp/dist-test-taskQFXsto/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515445504383-25086-0/minicluster-data/ts-0-root/wals/d1b6bab0be754ae99b308edc42262ae0/wal-000000028 (ops 135-139)
I20260812 06:17:36.124435 25532 log.cc:1079] T d1b6bab0be754ae99b308edc42262ae0 P cd5ca3a0ba6547428c859e06eb320059: Deleting log segment in path: /tmp/dist-test-taskQFXsto/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515445504383-25086-0/minicluster-data/ts-0-root/wals/d1b6bab0be754ae99b308edc42262ae0/wal-000000029 (ops 140-144)
I20260812 06:17:36.124495 25532 log.cc:1079] T d1b6bab0be754ae99b308edc42262ae0 P cd5ca3a0ba6547428c859e06eb320059: Deleting log segment in path: /tmp/dist-test-taskQFXsto/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515445504383-25086-0/minicluster-data/ts-0-root/wals/d1b6bab0be754ae99b308edc42262ae0/wal-000000030 (ops 145-149)
I20260812 06:17:36.124534 25532 log.cc:1079] T d1b6bab0be754ae99b308edc42262ae0 P cd5ca3a0ba6547428c859e06eb320059: Deleting log segment in path: /tmp/dist-test-taskQFXsto/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515445504383-25086-0/minicluster-data/ts-0-root/wals/d1b6bab0be754ae99b308edc42262ae0/wal-000000031 (ops 150-154)
I20260812 06:17:36.124576 25532 log.cc:1079] T d1b6bab0be754ae99b308edc42262ae0 P cd5ca3a0ba6547428c859e06eb320059: Deleting log segment in path: /tmp/dist-test-taskQFXsto/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515445504383-25086-0/minicluster-data/ts-0-root/wals/d1b6bab0be754ae99b308edc42262ae0/wal-000000032 (ops 155-159)
I20260812 06:17:36.124616 25532 log.cc:1079] T d1b6bab0be754ae99b308edc42262ae0 P cd5ca3a0ba6547428c859e06eb320059: Deleting log segment in path: /tmp/dist-test-taskQFXsto/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515445504383-25086-0/minicluster-data/ts-0-root/wals/d1b6bab0be754ae99b308edc42262ae0/wal-000000033 (ops 160-164)
I20260812 06:17:36.124657 25532 log.cc:1079] T d1b6bab0be754ae99b308edc42262ae0 P cd5ca3a0ba6547428c859e06eb320059: Deleting log segment in path: /tmp/dist-test-taskQFXsto/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515445504383-25086-0/minicluster-data/ts-0-root/wals/d1b6bab0be754ae99b308edc42262ae0/wal-000000034 (ops 165-169)
I20260812 06:17:36.124696 25532 log.cc:1079] T d1b6bab0be754ae99b308edc42262ae0 P cd5ca3a0ba6547428c859e06eb320059: Deleting log segment in path: /tmp/dist-test-taskQFXsto/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515445504383-25086-0/minicluster-data/ts-0-root/wals/d1b6bab0be754ae99b308edc42262ae0/wal-000000035 (ops 170-174)
I20260812 06:17:36.124737 25532 log.cc:1079] T d1b6bab0be754ae99b308edc42262ae0 P cd5ca3a0ba6547428c859e06eb320059: Deleting log segment in path: /tmp/dist-test-taskQFXsto/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515445504383-25086-0/minicluster-data/ts-0-root/wals/d1b6bab0be754ae99b308edc42262ae0/wal-000000036 (ops 175-179)
I20260812 06:17:36.124774 25532 log.cc:1079] T d1b6bab0be754ae99b308edc42262ae0 P cd5ca3a0ba6547428c859e06eb320059: Deleting log segment in path: /tmp/dist-test-taskQFXsto/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515445504383-25086-0/minicluster-data/ts-0-root/wals/d1b6bab0be754ae99b308edc42262ae0/wal-000000037 (ops 180-184)
I20260812 06:17:36.124812 25532 log.cc:1079] T d1b6bab0be754ae99b308edc42262ae0 P cd5ca3a0ba6547428c859e06eb320059: Deleting log segment in path: /tmp/dist-test-taskQFXsto/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515445504383-25086-0/minicluster-data/ts-0-root/wals/d1b6bab0be754ae99b308edc42262ae0/wal-000000038 (ops 185-189)
I20260812 06:17:36.124850 25532 log.cc:1079] T d1b6bab0be754ae99b308edc42262ae0 P cd5ca3a0ba6547428c859e06eb320059: Deleting log segment in path: /tmp/dist-test-taskQFXsto/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515445504383-25086-0/minicluster-data/ts-0-root/wals/d1b6bab0be754ae99b308edc42262ae0/wal-000000039 (ops 190-194)
I20260812 06:17:36.151183 25532 maintenance_manager.cc:643] P cd5ca3a0ba6547428c859e06eb320059: LogGCOp(d1b6bab0be754ae99b308edc42262ae0) complete. Timing: real 0.027s	user 0.000s	sys 0.024s Metrics: {}
I20260812 06:17:36.151831 25624 maintenance_manager.cc:419] P cd5ca3a0ba6547428c859e06eb320059: Scheduling UndoDeltaBlockGCOp(d1b6bab0be754ae99b308edc42262ae0): 493 bytes on disk
I20260812 06:17:36.152484 25532 maintenance_manager.cc:643] P cd5ca3a0ba6547428c859e06eb320059: UndoDeltaBlockGCOp(d1b6bab0be754ae99b308edc42262ae0) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":97,"lbm_reads_lt_1ms":4}
I20260812 06:17:36.153245 25624 maintenance_manager.cc:419] P cd5ca3a0ba6547428c859e06eb320059: Scheduling FlushDeltaMemStoresOp(d1b6bab0be754ae99b308edc42262ae0): perf score=3.181125
I20260812 06:17:36.167903 25532 maintenance_manager.cc:643] P cd5ca3a0ba6547428c859e06eb320059: FlushDeltaMemStoresOp(d1b6bab0be754ae99b308edc42262ae0) complete. Timing: real 0.014s	user 0.002s	sys 0.009s Metrics: {"bytes_written":4512903,"delete_count":0,"lbm_write_time_us":5118,"lbm_writes_lt_1ms":113,"reinsert_count":0,"update_count":550}
I20260812 06:17:36.168385 25624 maintenance_manager.cc:419] P cd5ca3a0ba6547428c859e06eb320059: Scheduling FlushDeltaMemStoresOp(d1b6bab0be754ae99b308edc42262ae0): perf score=2.188937
I20260812 06:17:36.178146 25532 maintenance_manager.cc:643] P cd5ca3a0ba6547428c859e06eb320059: FlushDeltaMemStoresOp(d1b6bab0be754ae99b308edc42262ae0) complete. Timing: real 0.010s	user 0.008s	sys 0.000s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3580,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:17:36.178664 25624 maintenance_manager.cc:419] P cd5ca3a0ba6547428c859e06eb320059: Scheduling MajorDeltaCompactionOp(d1b6bab0be754ae99b308edc42262ae0): perf score=1.000000
I20260812 06:17:36.219933 25086 heavy-update-compaction-itest.cc:229] Time spent updating: real 5.073s	user 1.817s	sys 0.214s
I20260812 06:17:36.322459 25086 heavy-update-compaction-itest.cc:265] Time spent scanning: real 0.102s	user 0.001s	sys 0.000s
I20260812 06:17:36.323009 25086 tablet_server.cc:179] TabletServer@127.24.127.129:0 shutting down...
I20260812 06:17:36.393296 25532 maintenance_manager.cc:643] P cd5ca3a0ba6547428c859e06eb320059: MajorDeltaCompactionOp(d1b6bab0be754ae99b308edc42262ae0) complete. Timing: real 0.214s	user 0.150s	sys 0.064s Metrics: {"cfile_cache_miss":835,"cfile_cache_miss_bytes":37123256,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":5,"delta_iterators_relevant":5,"dirs.queue_time_us":948,"lbm_read_time_us":17521,"lbm_reads_lt_1ms":871,"lbm_write_time_us":37850,"lbm_writes_lt_1ms":843,"mutex_wait_us":30,"peak_mem_usage":100395616,"reinsert_count":0,"spinlock_wait_cycles":25856,"thread_start_us":77,"threads_started":1,"update_count":4000}
I20260812 06:17:36.394183 25086 ts_tablet_manager.cc:1507] Shutting down tablet manager...
I20260812 06:17:36.394610 25086 tablet_replica.cc:333] T d1b6bab0be754ae99b308edc42262ae0 P cd5ca3a0ba6547428c859e06eb320059: stopping tablet replica
I20260812 06:17:36.394781 25086 raft_consensus.cc:2243] T d1b6bab0be754ae99b308edc42262ae0 P cd5ca3a0ba6547428c859e06eb320059 [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:17:36.394968 25086 raft_consensus.cc:2272] T d1b6bab0be754ae99b308edc42262ae0 P cd5ca3a0ba6547428c859e06eb320059 [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:17:36.414497 25086 tablet_server.cc:196] TabletServer@127.24.127.129:0 shutdown complete.
I20260812 06:17:36.466917 25086 master.cc:562] Master@127.24.127.190:44805 shutting down...
I20260812 06:17:36.471017 25086 raft_consensus.cc:2243] T 00000000000000000000000000000000 P 8197fbc32dd446fb860e1fbdf1d532aa [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:17:36.471225 25086 raft_consensus.cc:2272] T 00000000000000000000000000000000 P 8197fbc32dd446fb860e1fbdf1d532aa [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:17:36.471311 25086 tablet_replica.cc:333] T 00000000000000000000000000000000 P 8197fbc32dd446fb860e1fbdf1d532aa: stopping tablet replica
I20260812 06:17:36.483853 25086 master.cc:584] Master@127.24.127.190:44805 shutdown complete.
[       OK ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/1 (5643 ms)
[----------] 2 tests from EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy (11058 ms total)

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