[==========] 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:18:11.072489 31228 internal_mini_cluster.cc:156] Creating distributed mini masters. Addrs: 127.30.127.62:42777
I20260812 06:18:11.073451 31228 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:18:11.074064 31228 file_cache.cc:504] Constructed file cache file cache with capacity 419430
I20260812 06:18:11.080281 31228 server_base.cc:1061] running on GCE node
W20260812 06:18:11.080259 31234 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:18:11.080426 31235 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:18:11.080478 31237 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:18:11.080964 31228 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:18:11.081072 31228 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:18:11.081118 31228 hybrid_clock.cc:648] HybridClock initialized: now 1786515491081116 us; error 0 us; skew 500 ppm
I20260812 06:18:11.082762 31228 webserver.cc:533] Webserver started at http://127.30.127.62:42959/ using document root <none> and password file <none>
I20260812 06:18:11.083279 31228 fs_manager.cc:362] Metadata directory not provided
I20260812 06:18:11.083376 31228 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:18:11.083632 31228 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:18:11.085233 31228 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskyLMvui/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515491061751-31228-0/minicluster-data/master-0-root/instance:
uuid: "22d743a7a2d14f8a9eceefe0247693a3"
format_stamp: "Formatted at 2026-08-12 06:18:11 on dist-test-slave-zkpd"
I20260812 06:18:11.088593 31228 fs_manager.cc:696] Time spent creating directory manager: real 0.003s	user 0.003s	sys 0.000s
I20260812 06:18:11.090525 31243 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:18:11.091424 31228 fs_manager.cc:730] Time spent opening block manager: real 0.002s	user 0.002s	sys 0.000s
I20260812 06:18:11.091552 31228 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskyLMvui/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515491061751-31228-0/minicluster-data/master-0-root
uuid: "22d743a7a2d14f8a9eceefe0247693a3"
format_stamp: "Formatted at 2026-08-12 06:18:11 on dist-test-slave-zkpd"
I20260812 06:18:11.091648 31228 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskyLMvui/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515491061751-31228-0/minicluster-data/master-0-root
metadata directory: /tmp/dist-test-taskyLMvui/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515491061751-31228-0/minicluster-data/master-0-root
1 data directories: /tmp/dist-test-taskyLMvui/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515491061751-31228-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:18:11.109652 31228 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:18:11.110260 31228 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:18:11.110448 31228 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:18:11.118258 31228 rpc_server.cc:307] RPC server started. Bound to: 127.30.127.62:42777
I20260812 06:18:11.118286 31302 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.30.127.62:42777 every 8 connection(s)
I20260812 06:18:11.120550 31303 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:18:11.125808 31303 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P 22d743a7a2d14f8a9eceefe0247693a3: Bootstrap starting.
I20260812 06:18:11.128181 31303 tablet_bootstrap.cc:654] T 00000000000000000000000000000000 P 22d743a7a2d14f8a9eceefe0247693a3: Neither blocks nor log segments found. Creating new log.
I20260812 06:18:11.129055 31303 log.cc:826] T 00000000000000000000000000000000 P 22d743a7a2d14f8a9eceefe0247693a3: Log is configured to *not* fsync() on all Append() calls
I20260812 06:18:11.130623 31303 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P 22d743a7a2d14f8a9eceefe0247693a3: No bootstrap required, opened a new log
I20260812 06:18:11.133347 31303 raft_consensus.cc:359] T 00000000000000000000000000000000 P 22d743a7a2d14f8a9eceefe0247693a3 [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "22d743a7a2d14f8a9eceefe0247693a3" member_type: VOTER }
I20260812 06:18:11.133502 31303 raft_consensus.cc:385] T 00000000000000000000000000000000 P 22d743a7a2d14f8a9eceefe0247693a3 [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:18:11.133610 31303 raft_consensus.cc:740] T 00000000000000000000000000000000 P 22d743a7a2d14f8a9eceefe0247693a3 [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: 22d743a7a2d14f8a9eceefe0247693a3, State: Initialized, Role: FOLLOWER
I20260812 06:18:11.134262 31303 consensus_queue.cc:260] T 00000000000000000000000000000000 P 22d743a7a2d14f8a9eceefe0247693a3 [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: "22d743a7a2d14f8a9eceefe0247693a3" member_type: VOTER }
I20260812 06:18:11.134434 31303 raft_consensus.cc:399] T 00000000000000000000000000000000 P 22d743a7a2d14f8a9eceefe0247693a3 [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:18:11.134526 31303 raft_consensus.cc:493] T 00000000000000000000000000000000 P 22d743a7a2d14f8a9eceefe0247693a3 [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:18:11.134660 31303 raft_consensus.cc:3060] T 00000000000000000000000000000000 P 22d743a7a2d14f8a9eceefe0247693a3 [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:18:11.135408 31303 raft_consensus.cc:515] T 00000000000000000000000000000000 P 22d743a7a2d14f8a9eceefe0247693a3 [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "22d743a7a2d14f8a9eceefe0247693a3" member_type: VOTER }
I20260812 06:18:11.135838 31303 leader_election.cc:304] T 00000000000000000000000000000000 P 22d743a7a2d14f8a9eceefe0247693a3 [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: 22d743a7a2d14f8a9eceefe0247693a3; no voters: 
I20260812 06:18:11.136164 31303 leader_election.cc:290] T 00000000000000000000000000000000 P 22d743a7a2d14f8a9eceefe0247693a3 [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:18:11.136328 31306 raft_consensus.cc:2804] T 00000000000000000000000000000000 P 22d743a7a2d14f8a9eceefe0247693a3 [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:18:11.136584 31306 raft_consensus.cc:697] T 00000000000000000000000000000000 P 22d743a7a2d14f8a9eceefe0247693a3 [term 1 LEADER]: Becoming Leader. State: Replica: 22d743a7a2d14f8a9eceefe0247693a3, State: Running, Role: LEADER
I20260812 06:18:11.136934 31306 consensus_queue.cc:237] T 00000000000000000000000000000000 P 22d743a7a2d14f8a9eceefe0247693a3 [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: "22d743a7a2d14f8a9eceefe0247693a3" member_type: VOTER }
I20260812 06:18:11.137135 31303 sys_catalog.cc:565] T 00000000000000000000000000000000 P 22d743a7a2d14f8a9eceefe0247693a3 [sys.catalog]: configured and running, proceeding with master startup.
I20260812 06:18:11.138738 31307 sys_catalog.cc:455] T 00000000000000000000000000000000 P 22d743a7a2d14f8a9eceefe0247693a3 [sys.catalog]: SysCatalogTable state changed. Reason: RaftConsensus started. Latest consensus state: current_term: 1 leader_uuid: "22d743a7a2d14f8a9eceefe0247693a3" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "22d743a7a2d14f8a9eceefe0247693a3" member_type: VOTER } }
I20260812 06:18:11.138792 31308 sys_catalog.cc:455] T 00000000000000000000000000000000 P 22d743a7a2d14f8a9eceefe0247693a3 [sys.catalog]: SysCatalogTable state changed. Reason: New leader 22d743a7a2d14f8a9eceefe0247693a3. Latest consensus state: current_term: 1 leader_uuid: "22d743a7a2d14f8a9eceefe0247693a3" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "22d743a7a2d14f8a9eceefe0247693a3" member_type: VOTER } }
I20260812 06:18:11.138866 31307 sys_catalog.cc:458] T 00000000000000000000000000000000 P 22d743a7a2d14f8a9eceefe0247693a3 [sys.catalog]: This master's current role is: LEADER
I20260812 06:18:11.138906 31308 sys_catalog.cc:458] T 00000000000000000000000000000000 P 22d743a7a2d14f8a9eceefe0247693a3 [sys.catalog]: This master's current role is: LEADER
I20260812 06:18:11.139324 31318 catalog_manager.cc:1511] Loading table and tablet metadata into memory...
I20260812 06:18:11.139504 31228 internal_mini_cluster.cc:184] Waiting to initialize catalog manager on master 0
I20260812 06:18:11.141902 31318 catalog_manager.cc:1520] Initializing Kudu cluster ID...
I20260812 06:18:11.146759 31318 catalog_manager.cc:1383] Generated new cluster ID: eefc450528dc40c5a7cfc1f054a565af
I20260812 06:18:11.146834 31318 catalog_manager.cc:1531] Initializing Kudu internal certificate authority...
I20260812 06:18:11.156302 31318 catalog_manager.cc:1406] Generated new certificate authority record
I20260812 06:18:11.157063 31318 catalog_manager.cc:1540] Loading token signing keys...
I20260812 06:18:11.175014 31318 catalog_manager.cc:6092] T 00000000000000000000000000000000 P 22d743a7a2d14f8a9eceefe0247693a3: Generated new TSK 0
I20260812 06:18:11.175643 31318 catalog_manager.cc:1550] Initializing in-progress tserver states...
I20260812 06:18:11.204319 31228 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:18:11.206977 31326 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:18:11.207043 31330 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:18:11.207052 31328 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:18:11.207470 31228 server_base.cc:1061] running on GCE node
I20260812 06:18:11.207661 31228 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:18:11.207717 31228 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:18:11.207774 31228 hybrid_clock.cc:648] HybridClock initialized: now 1786515491207750 us; error 0 us; skew 500 ppm
I20260812 06:18:11.208781 31228 webserver.cc:533] Webserver started at http://127.30.127.1:39151/ using document root <none> and password file <none>
I20260812 06:18:11.208958 31228 fs_manager.cc:362] Metadata directory not provided
I20260812 06:18:11.209029 31228 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:18:11.209110 31228 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:18:11.209527 31228 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskyLMvui/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515491061751-31228-0/minicluster-data/ts-0-root/instance:
uuid: "0330a6b87754415c9cc9e65efcbbc869"
format_stamp: "Formatted at 2026-08-12 06:18:11 on dist-test-slave-zkpd"
I20260812 06:18:11.211086 31228 fs_manager.cc:696] Time spent creating directory manager: real 0.001s	user 0.002s	sys 0.000s
I20260812 06:18:11.212153 31335 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:18:11.212414 31228 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.001s	sys 0.000s
I20260812 06:18:11.212491 31228 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskyLMvui/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515491061751-31228-0/minicluster-data/ts-0-root
uuid: "0330a6b87754415c9cc9e65efcbbc869"
format_stamp: "Formatted at 2026-08-12 06:18:11 on dist-test-slave-zkpd"
I20260812 06:18:11.212589 31228 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskyLMvui/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515491061751-31228-0/minicluster-data/ts-0-root
metadata directory: /tmp/dist-test-taskyLMvui/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515491061751-31228-0/minicluster-data/ts-0-root
1 data directories: /tmp/dist-test-taskyLMvui/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515491061751-31228-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:18:11.220947 31228 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:18:11.221395 31228 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:18:11.221916 31228 txn_system_client.cc:432] TxnSystemClient initialization is disabled...
I20260812 06:18:11.222827 31228 ts_tablet_manager.cc:585] Loaded tablet metadata (0 total tablets, 0 live tablets)
I20260812 06:18:11.222878 31228 ts_tablet_manager.cc:531] Time spent load tablet metadata: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:18:11.222968 31228 ts_tablet_manager.cc:616] Registered 0 tablets
I20260812 06:18:11.223009 31228 ts_tablet_manager.cc:595] Time spent register tablets: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:18:11.230204 31228 rpc_server.cc:307] RPC server started. Bound to: 127.30.127.1:36607
I20260812 06:18:11.230286 31404 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.30.127.1:36607 every 8 connection(s)
I20260812 06:18:11.245407 31405 heartbeater.cc:344] Connected to a master server at 127.30.127.62:42777
I20260812 06:18:11.245657 31405 heartbeater.cc:461] Registering TS with master...
I20260812 06:18:11.246096 31405 heartbeater.cc:507] Master 127.30.127.62:42777 requested a full tablet report, sending...
I20260812 06:18:11.247666 31261 ts_manager.cc:194] Registered new tserver with Master: 0330a6b87754415c9cc9e65efcbbc869 (127.30.127.1:36607)
I20260812 06:18:11.247732 31228 internal_mini_cluster.cc:371] 1 TS(s) registered with all masters after 0.016877197s
I20260812 06:18:11.249267 31261 master_service.cc:502] Signed X509 certificate for tserver {username='slave'} at 127.0.0.1:44042
I20260812 06:18:11.257230 31261 catalog_manager.cc:2283] Servicing CreateTable request from {username='slave'} at 127.0.0.1:44052:
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:18:11.272524 31366 tablet_service.cc:1511] Processing CreateTablet for tablet 10ab8ed74bc2446fa6d552395a99143e (DEFAULT_TABLE table=heavy-update-compaction-test [id=317d254d93d64c50b6540b8d138eae27]), partition=
I20260812 06:18:11.273000 31366 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet 10ab8ed74bc2446fa6d552395a99143e. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:18:11.276154 31417 tablet_bootstrap.cc:492] T 10ab8ed74bc2446fa6d552395a99143e P 0330a6b87754415c9cc9e65efcbbc869: Bootstrap starting.
I20260812 06:18:11.277024 31417 tablet_bootstrap.cc:654] T 10ab8ed74bc2446fa6d552395a99143e P 0330a6b87754415c9cc9e65efcbbc869: Neither blocks nor log segments found. Creating new log.
I20260812 06:18:11.278340 31417 tablet_bootstrap.cc:492] T 10ab8ed74bc2446fa6d552395a99143e P 0330a6b87754415c9cc9e65efcbbc869: No bootstrap required, opened a new log
I20260812 06:18:11.278481 31417 ts_tablet_manager.cc:1403] T 10ab8ed74bc2446fa6d552395a99143e P 0330a6b87754415c9cc9e65efcbbc869: Time spent bootstrapping tablet: real 0.002s	user 0.002s	sys 0.000s
I20260812 06:18:11.278939 31417 raft_consensus.cc:359] T 10ab8ed74bc2446fa6d552395a99143e P 0330a6b87754415c9cc9e65efcbbc869 [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "0330a6b87754415c9cc9e65efcbbc869" member_type: VOTER last_known_addr { host: "127.30.127.1" port: 36607 } }
I20260812 06:18:11.279062 31417 raft_consensus.cc:385] T 10ab8ed74bc2446fa6d552395a99143e P 0330a6b87754415c9cc9e65efcbbc869 [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:18:11.279129 31417 raft_consensus.cc:740] T 10ab8ed74bc2446fa6d552395a99143e P 0330a6b87754415c9cc9e65efcbbc869 [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: 0330a6b87754415c9cc9e65efcbbc869, State: Initialized, Role: FOLLOWER
I20260812 06:18:11.279321 31417 consensus_queue.cc:260] T 10ab8ed74bc2446fa6d552395a99143e P 0330a6b87754415c9cc9e65efcbbc869 [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: "0330a6b87754415c9cc9e65efcbbc869" member_type: VOTER last_known_addr { host: "127.30.127.1" port: 36607 } }
I20260812 06:18:11.279433 31417 raft_consensus.cc:399] T 10ab8ed74bc2446fa6d552395a99143e P 0330a6b87754415c9cc9e65efcbbc869 [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:18:11.279495 31417 raft_consensus.cc:493] T 10ab8ed74bc2446fa6d552395a99143e P 0330a6b87754415c9cc9e65efcbbc869 [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:18:11.279556 31417 raft_consensus.cc:3060] T 10ab8ed74bc2446fa6d552395a99143e P 0330a6b87754415c9cc9e65efcbbc869 [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:18:11.280491 31417 raft_consensus.cc:515] T 10ab8ed74bc2446fa6d552395a99143e P 0330a6b87754415c9cc9e65efcbbc869 [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "0330a6b87754415c9cc9e65efcbbc869" member_type: VOTER last_known_addr { host: "127.30.127.1" port: 36607 } }
I20260812 06:18:11.280606 31417 leader_election.cc:304] T 10ab8ed74bc2446fa6d552395a99143e P 0330a6b87754415c9cc9e65efcbbc869 [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: 0330a6b87754415c9cc9e65efcbbc869; no voters: 
I20260812 06:18:11.280833 31417 leader_election.cc:290] T 10ab8ed74bc2446fa6d552395a99143e P 0330a6b87754415c9cc9e65efcbbc869 [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:18:11.280927 31419 raft_consensus.cc:2804] T 10ab8ed74bc2446fa6d552395a99143e P 0330a6b87754415c9cc9e65efcbbc869 [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:18:11.281140 31419 raft_consensus.cc:697] T 10ab8ed74bc2446fa6d552395a99143e P 0330a6b87754415c9cc9e65efcbbc869 [term 1 LEADER]: Becoming Leader. State: Replica: 0330a6b87754415c9cc9e65efcbbc869, State: Running, Role: LEADER
I20260812 06:18:11.281198 31417 ts_tablet_manager.cc:1434] T 10ab8ed74bc2446fa6d552395a99143e P 0330a6b87754415c9cc9e65efcbbc869: Time spent starting tablet: real 0.003s	user 0.003s	sys 0.000s
I20260812 06:18:11.281431 31405 heartbeater.cc:499] Master 127.30.127.62:42777 was elected leader, sending a full tablet report...
I20260812 06:18:11.281535 31419 consensus_queue.cc:237] T 10ab8ed74bc2446fa6d552395a99143e P 0330a6b87754415c9cc9e65efcbbc869 [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: "0330a6b87754415c9cc9e65efcbbc869" member_type: VOTER last_known_addr { host: "127.30.127.1" port: 36607 } }
I20260812 06:18:11.284158 31261 catalog_manager.cc:5719] T 10ab8ed74bc2446fa6d552395a99143e P 0330a6b87754415c9cc9e65efcbbc869 reported cstate change: term changed from 0 to 1, leader changed from <none> to 0330a6b87754415c9cc9e65efcbbc869 (127.30.127.1). New cstate: current_term: 1 leader_uuid: "0330a6b87754415c9cc9e65efcbbc869" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "0330a6b87754415c9cc9e65efcbbc869" member_type: VOTER last_known_addr { host: "127.30.127.1" port: 36607 } health_report { overall_health: HEALTHY } } }
I20260812 06:18:11.360917 31228 heavy-update-compaction-itest.cc:215] Time spent inserting: real 0.068s	user 0.027s	sys 0.003s
I20260812 06:18:11.481590 31406 maintenance_manager.cc:419] P 0330a6b87754415c9cc9e65efcbbc869: Scheduling FlushMRSOp(10ab8ed74bc2446fa6d552395a99143e): perf score=15.086190
I20260812 06:18:11.636264 31341 maintenance_manager.cc:643] P 0330a6b87754415c9cc9e65efcbbc869: FlushMRSOp(10ab8ed74bc2446fa6d552395a99143e) complete. Timing: real 0.154s	user 0.101s	sys 0.050s Metrics: {"bytes_written":12307491,"cfile_init":1,"compiler_manager_pool.queue_time_us":275,"delete_count":0,"dirs.queue_time_us":70,"dirs.run_cpu_time_us":233,"dirs.run_wall_time_us":885,"drs_written":1,"lbm_read_time_us":78,"lbm_reads_lt_1ms":4,"lbm_write_time_us":37394,"lbm_writes_lt_1ms":657,"peak_mem_usage":0,"reinsert_count":0,"rows_written":103,"thread_start_us":165,"threads_started":1,"update_count":1500}
I20260812 06:18:11.637419 31406 maintenance_manager.cc:419] P 0330a6b87754415c9cc9e65efcbbc869: Scheduling LogGCOp(10ab8ed74bc2446fa6d552395a99143e): free 8725963 bytes of WAL
I20260812 06:18:11.637709 31341 log_reader.cc:385] T 10ab8ed74bc2446fa6d552395a99143e: removed 1 log segments from log reader
I20260812 06:18:11.637786 31341 log.cc:1079] T 10ab8ed74bc2446fa6d552395a99143e P 0330a6b87754415c9cc9e65efcbbc869: Deleting log segment in path: /tmp/dist-test-taskyLMvui/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515491061751-31228-0/minicluster-data/ts-0-root/wals/10ab8ed74bc2446fa6d552395a99143e/wal-000000001 (ops 1-6)
I20260812 06:18:11.640190 31341 maintenance_manager.cc:643] P 0330a6b87754415c9cc9e65efcbbc869: LogGCOp(10ab8ed74bc2446fa6d552395a99143e) complete. Timing: real 0.003s	user 0.000s	sys 0.002s Metrics: {}
I20260812 06:18:11.640503 31406 maintenance_manager.cc:419] P 0330a6b87754415c9cc9e65efcbbc869: Scheduling FlushDeltaMemStoresOp(10ab8ed74bc2446fa6d552395a99143e): perf score=2.188937
I20260812 06:18:11.658804 31341 maintenance_manager.cc:643] P 0330a6b87754415c9cc9e65efcbbc869: FlushDeltaMemStoresOp(10ab8ed74bc2446fa6d552395a99143e) complete. Timing: real 0.018s	user 0.004s	sys 0.009s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5844,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:11.659341 31406 maintenance_manager.cc:419] P 0330a6b87754415c9cc9e65efcbbc869: Scheduling UndoDeltaBlockGCOp(10ab8ed74bc2446fa6d552395a99143e): 12308959 bytes on disk
I20260812 06:18:11.660152 31341 maintenance_manager.cc:643] P 0330a6b87754415c9cc9e65efcbbc869: UndoDeltaBlockGCOp(10ab8ed74bc2446fa6d552395a99143e) complete. Timing: real 0.001s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":115,"lbm_reads_lt_1ms":4}
I20260812 06:18:11.660635 31406 maintenance_manager.cc:419] P 0330a6b87754415c9cc9e65efcbbc869: Scheduling MajorDeltaCompactionOp(10ab8ed74bc2446fa6d552395a99143e): perf score=1.000000
I20260812 06:18:11.790035 31341 maintenance_manager.cc:643] P 0330a6b87754415c9cc9e65efcbbc869: MajorDeltaCompactionOp(10ab8ed74bc2446fa6d552395a99143e) complete. Timing: real 0.129s	user 0.086s	sys 0.043s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20631313,"cfile_init":7,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":518,"lbm_read_time_us":9520,"lbm_reads_lt_1ms":460,"lbm_write_time_us":23313,"lbm_writes_lt_1ms":443,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":2560,"thread_start_us":269,"threads_started":5,"update_count":2000}
I20260812 06:18:11.790532 31406 maintenance_manager.cc:419] P 0330a6b87754415c9cc9e65efcbbc869: Scheduling FlushDeltaMemStoresOp(10ab8ed74bc2446fa6d552395a99143e): perf score=10.126437
I20260812 06:18:11.833266 31341 maintenance_manager.cc:643] P 0330a6b87754415c9cc9e65efcbbc869: FlushDeltaMemStoresOp(10ab8ed74bc2446fa6d552395a99143e) complete. Timing: real 0.043s	user 0.032s	sys 0.008s Metrics: {"bytes_written":12307489,"delete_count":0,"lbm_write_time_us":17749,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:18:11.833680 31406 maintenance_manager.cc:419] P 0330a6b87754415c9cc9e65efcbbc869: Scheduling FlushDeltaMemStoresOp(10ab8ed74bc2446fa6d552395a99143e): perf score=2.188937
I20260812 06:18:11.844568 31341 maintenance_manager.cc:643] P 0330a6b87754415c9cc9e65efcbbc869: FlushDeltaMemStoresOp(10ab8ed74bc2446fa6d552395a99143e) complete. Timing: real 0.011s	user 0.002s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4184,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:11.845211 31406 maintenance_manager.cc:419] P 0330a6b87754415c9cc9e65efcbbc869: Scheduling MajorDeltaCompactionOp(10ab8ed74bc2446fa6d552395a99143e): perf score=1.000000
I20260812 06:18:11.966708 31341 maintenance_manager.cc:643] P 0330a6b87754415c9cc9e65efcbbc869: MajorDeltaCompactionOp(10ab8ed74bc2446fa6d552395a99143e) complete. Timing: real 0.121s	user 0.097s	sys 0.024s 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":687,"lbm_read_time_us":7976,"lbm_reads_lt_1ms":472,"lbm_write_time_us":24978,"lbm_writes_lt_1ms":443,"mutex_wait_us":289,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":1536,"update_count":2000}
I20260812 06:18:11.967303 31406 maintenance_manager.cc:419] P 0330a6b87754415c9cc9e65efcbbc869: Scheduling FlushDeltaMemStoresOp(10ab8ed74bc2446fa6d552395a99143e): perf score=10.126437
I20260812 06:18:12.010564 31341 maintenance_manager.cc:643] P 0330a6b87754415c9cc9e65efcbbc869: FlushDeltaMemStoresOp(10ab8ed74bc2446fa6d552395a99143e) complete. Timing: real 0.043s	user 0.019s	sys 0.012s Metrics: {"bytes_written":12307489,"delete_count":0,"lbm_write_time_us":14681,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:18:12.010986 31406 maintenance_manager.cc:419] P 0330a6b87754415c9cc9e65efcbbc869: Scheduling FlushDeltaMemStoresOp(10ab8ed74bc2446fa6d552395a99143e): perf score=2.188937
I20260812 06:18:12.021356 31341 maintenance_manager.cc:643] P 0330a6b87754415c9cc9e65efcbbc869: FlushDeltaMemStoresOp(10ab8ed74bc2446fa6d552395a99143e) complete. Timing: real 0.010s	user 0.001s	sys 0.008s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4210,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:12.021790 31406 maintenance_manager.cc:419] P 0330a6b87754415c9cc9e65efcbbc869: Scheduling MajorDeltaCompactionOp(10ab8ed74bc2446fa6d552395a99143e): perf score=1.000000
I20260812 06:18:12.143761 31341 maintenance_manager.cc:643] P 0330a6b87754415c9cc9e65efcbbc869: MajorDeltaCompactionOp(10ab8ed74bc2446fa6d552395a99143e) complete. Timing: real 0.122s	user 0.106s	sys 0.016s 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":301,"lbm_read_time_us":9327,"lbm_reads_lt_1ms":472,"lbm_write_time_us":23562,"lbm_writes_lt_1ms":443,"mutex_wait_us":43,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":7296,"update_count":2000}
I20260812 06:18:12.144527 31406 maintenance_manager.cc:419] P 0330a6b87754415c9cc9e65efcbbc869: Scheduling FlushDeltaMemStoresOp(10ab8ed74bc2446fa6d552395a99143e): perf score=10.126437
I20260812 06:18:12.196929 31341 maintenance_manager.cc:643] P 0330a6b87754415c9cc9e65efcbbc869: FlushDeltaMemStoresOp(10ab8ed74bc2446fa6d552395a99143e) complete. Timing: real 0.051s	user 0.026s	sys 0.022s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":16434,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:18:12.197459 31406 maintenance_manager.cc:419] P 0330a6b87754415c9cc9e65efcbbc869: Scheduling FlushDeltaMemStoresOp(10ab8ed74bc2446fa6d552395a99143e): perf score=2.188937
I20260812 06:18:12.213560 31341 maintenance_manager.cc:643] P 0330a6b87754415c9cc9e65efcbbc869: FlushDeltaMemStoresOp(10ab8ed74bc2446fa6d552395a99143e) complete. Timing: real 0.016s	user 0.010s	sys 0.004s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":6039,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:12.214049 31406 maintenance_manager.cc:419] P 0330a6b87754415c9cc9e65efcbbc869: Scheduling MajorDeltaCompactionOp(10ab8ed74bc2446fa6d552395a99143e): perf score=1.000000
I20260812 06:18:12.358156 31341 maintenance_manager.cc:643] P 0330a6b87754415c9cc9e65efcbbc869: MajorDeltaCompactionOp(10ab8ed74bc2446fa6d552395a99143e) complete. Timing: real 0.144s	user 0.104s	sys 0.040s 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":974,"lbm_read_time_us":11394,"lbm_reads_lt_1ms":472,"lbm_write_time_us":22341,"lbm_writes_lt_1ms":443,"mutex_wait_us":264,"peak_mem_usage":50689328,"reinsert_count":0,"update_count":2000}
I20260812 06:18:12.358606 31406 maintenance_manager.cc:419] P 0330a6b87754415c9cc9e65efcbbc869: Scheduling FlushDeltaMemStoresOp(10ab8ed74bc2446fa6d552395a99143e): perf score=10.126437
I20260812 06:18:12.403688 31341 maintenance_manager.cc:643] P 0330a6b87754415c9cc9e65efcbbc869: FlushDeltaMemStoresOp(10ab8ed74bc2446fa6d552395a99143e) complete. Timing: real 0.045s	user 0.012s	sys 0.019s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":14785,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:18:12.404253 31406 maintenance_manager.cc:419] P 0330a6b87754415c9cc9e65efcbbc869: Scheduling FlushDeltaMemStoresOp(10ab8ed74bc2446fa6d552395a99143e): perf score=2.188937
I20260812 06:18:12.414959 31341 maintenance_manager.cc:643] P 0330a6b87754415c9cc9e65efcbbc869: FlushDeltaMemStoresOp(10ab8ed74bc2446fa6d552395a99143e) complete. Timing: real 0.011s	user 0.000s	sys 0.009s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4111,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:12.415686 31406 maintenance_manager.cc:419] P 0330a6b87754415c9cc9e65efcbbc869: Scheduling MajorDeltaCompactionOp(10ab8ed74bc2446fa6d552395a99143e): perf score=1.000000
I20260812 06:18:12.546902 31341 maintenance_manager.cc:643] P 0330a6b87754415c9cc9e65efcbbc869: MajorDeltaCompactionOp(10ab8ed74bc2446fa6d552395a99143e) complete. Timing: real 0.131s	user 0.103s	sys 0.024s 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":360,"lbm_read_time_us":8743,"lbm_reads_lt_1ms":472,"lbm_write_time_us":24457,"lbm_writes_lt_1ms":443,"mutex_wait_us":21,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":3200,"update_count":2000}
I20260812 06:18:12.547436 31406 maintenance_manager.cc:419] P 0330a6b87754415c9cc9e65efcbbc869: Scheduling FlushDeltaMemStoresOp(10ab8ed74bc2446fa6d552395a99143e): perf score=10.126437
I20260812 06:18:12.597013 31341 maintenance_manager.cc:643] P 0330a6b87754415c9cc9e65efcbbc869: FlushDeltaMemStoresOp(10ab8ed74bc2446fa6d552395a99143e) complete. Timing: real 0.049s	user 0.029s	sys 0.011s Metrics: {"bytes_written":12307492,"delete_count":0,"lbm_write_time_us":17816,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:18:12.597606 31406 maintenance_manager.cc:419] P 0330a6b87754415c9cc9e65efcbbc869: Scheduling FlushDeltaMemStoresOp(10ab8ed74bc2446fa6d552395a99143e): perf score=2.188937
I20260812 06:18:12.612968 31341 maintenance_manager.cc:643] P 0330a6b87754415c9cc9e65efcbbc869: FlushDeltaMemStoresOp(10ab8ed74bc2446fa6d552395a99143e) complete. Timing: real 0.015s	user 0.009s	sys 0.006s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5601,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:12.613416 31406 maintenance_manager.cc:419] P 0330a6b87754415c9cc9e65efcbbc869: Scheduling MajorDeltaCompactionOp(10ab8ed74bc2446fa6d552395a99143e): perf score=1.000000
I20260812 06:18:12.746368 31341 maintenance_manager.cc:643] P 0330a6b87754415c9cc9e65efcbbc869: MajorDeltaCompactionOp(10ab8ed74bc2446fa6d552395a99143e) complete. Timing: real 0.133s	user 0.102s	sys 0.030s 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":593,"lbm_read_time_us":10054,"lbm_reads_lt_1ms":472,"lbm_write_time_us":25275,"lbm_writes_lt_1ms":443,"mutex_wait_us":23,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":13056,"update_count":2000}
I20260812 06:18:12.746999 31406 maintenance_manager.cc:419] P 0330a6b87754415c9cc9e65efcbbc869: Scheduling FlushDeltaMemStoresOp(10ab8ed74bc2446fa6d552395a99143e): perf score=10.126437
I20260812 06:18:12.803575 31341 maintenance_manager.cc:643] P 0330a6b87754415c9cc9e65efcbbc869: FlushDeltaMemStoresOp(10ab8ed74bc2446fa6d552395a99143e) complete. Timing: real 0.056s	user 0.027s	sys 0.015s Metrics: {"bytes_written":12307489,"delete_count":0,"lbm_write_time_us":16196,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:18:12.804338 31406 maintenance_manager.cc:419] P 0330a6b87754415c9cc9e65efcbbc869: Scheduling FlushDeltaMemStoresOp(10ab8ed74bc2446fa6d552395a99143e): perf score=2.188937
I20260812 06:18:12.818799 31341 maintenance_manager.cc:643] P 0330a6b87754415c9cc9e65efcbbc869: FlushDeltaMemStoresOp(10ab8ed74bc2446fa6d552395a99143e) complete. Timing: real 0.014s	user 0.006s	sys 0.005s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4801,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:12.819244 31406 maintenance_manager.cc:419] P 0330a6b87754415c9cc9e65efcbbc869: Scheduling FlushMRSOp(10ab8ed74bc2446fa6d552395a99143e): perf score=1.000000
I20260812 06:18:12.846866 31341 maintenance_manager.cc:643] P 0330a6b87754415c9cc9e65efcbbc869: FlushMRSOp(10ab8ed74bc2446fa6d552395a99143e) complete. Timing: real 0.027s	user 0.026s	sys 0.000s Metrics: {"bytes_written":1193504,"cfile_init":1,"dirs.queue_time_us":66,"dirs.run_cpu_time_us":244,"dirs.run_wall_time_us":1381,"drs_written":1,"lbm_read_time_us":42,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1780,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":29}
I20260812 06:18:12.847605 31406 maintenance_manager.cc:419] P 0330a6b87754415c9cc9e65efcbbc869: Scheduling LogGCOp(10ab8ed74bc2446fa6d552395a99143e): free 123804179 bytes of WAL
I20260812 06:18:12.847831 31341 log_reader.cc:385] T 10ab8ed74bc2446fa6d552395a99143e: removed 12 log segments from log reader
I20260812 06:18:12.847877 31341 log.cc:1079] T 10ab8ed74bc2446fa6d552395a99143e P 0330a6b87754415c9cc9e65efcbbc869: Deleting log segment in path: /tmp/dist-test-taskyLMvui/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515491061751-31228-0/minicluster-data/ts-0-root/wals/10ab8ed74bc2446fa6d552395a99143e/wal-000000002 (ops 7-11)
I20260812 06:18:12.847970 31341 log.cc:1079] T 10ab8ed74bc2446fa6d552395a99143e P 0330a6b87754415c9cc9e65efcbbc869: Deleting log segment in path: /tmp/dist-test-taskyLMvui/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515491061751-31228-0/minicluster-data/ts-0-root/wals/10ab8ed74bc2446fa6d552395a99143e/wal-000000003 (ops 12-16)
I20260812 06:18:12.848014 31341 log.cc:1079] T 10ab8ed74bc2446fa6d552395a99143e P 0330a6b87754415c9cc9e65efcbbc869: Deleting log segment in path: /tmp/dist-test-taskyLMvui/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515491061751-31228-0/minicluster-data/ts-0-root/wals/10ab8ed74bc2446fa6d552395a99143e/wal-000000004 (ops 17-21)
I20260812 06:18:12.848047 31341 log.cc:1079] T 10ab8ed74bc2446fa6d552395a99143e P 0330a6b87754415c9cc9e65efcbbc869: Deleting log segment in path: /tmp/dist-test-taskyLMvui/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515491061751-31228-0/minicluster-data/ts-0-root/wals/10ab8ed74bc2446fa6d552395a99143e/wal-000000005 (ops 22-26)
I20260812 06:18:12.848083 31341 log.cc:1079] T 10ab8ed74bc2446fa6d552395a99143e P 0330a6b87754415c9cc9e65efcbbc869: Deleting log segment in path: /tmp/dist-test-taskyLMvui/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515491061751-31228-0/minicluster-data/ts-0-root/wals/10ab8ed74bc2446fa6d552395a99143e/wal-000000006 (ops 27-30)
I20260812 06:18:12.848126 31341 log.cc:1079] T 10ab8ed74bc2446fa6d552395a99143e P 0330a6b87754415c9cc9e65efcbbc869: Deleting log segment in path: /tmp/dist-test-taskyLMvui/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515491061751-31228-0/minicluster-data/ts-0-root/wals/10ab8ed74bc2446fa6d552395a99143e/wal-000000007 (ops 31-35)
I20260812 06:18:12.848163 31341 log.cc:1079] T 10ab8ed74bc2446fa6d552395a99143e P 0330a6b87754415c9cc9e65efcbbc869: Deleting log segment in path: /tmp/dist-test-taskyLMvui/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515491061751-31228-0/minicluster-data/ts-0-root/wals/10ab8ed74bc2446fa6d552395a99143e/wal-000000008 (ops 36-40)
I20260812 06:18:12.848199 31341 log.cc:1079] T 10ab8ed74bc2446fa6d552395a99143e P 0330a6b87754415c9cc9e65efcbbc869: Deleting log segment in path: /tmp/dist-test-taskyLMvui/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515491061751-31228-0/minicluster-data/ts-0-root/wals/10ab8ed74bc2446fa6d552395a99143e/wal-000000009 (ops 41-45)
I20260812 06:18:12.848237 31341 log.cc:1079] T 10ab8ed74bc2446fa6d552395a99143e P 0330a6b87754415c9cc9e65efcbbc869: Deleting log segment in path: /tmp/dist-test-taskyLMvui/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515491061751-31228-0/minicluster-data/ts-0-root/wals/10ab8ed74bc2446fa6d552395a99143e/wal-000000010 (ops 46-50)
I20260812 06:18:12.848282 31341 log.cc:1079] T 10ab8ed74bc2446fa6d552395a99143e P 0330a6b87754415c9cc9e65efcbbc869: Deleting log segment in path: /tmp/dist-test-taskyLMvui/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515491061751-31228-0/minicluster-data/ts-0-root/wals/10ab8ed74bc2446fa6d552395a99143e/wal-000000011 (ops 51-55)
I20260812 06:18:12.848318 31341 log.cc:1079] T 10ab8ed74bc2446fa6d552395a99143e P 0330a6b87754415c9cc9e65efcbbc869: Deleting log segment in path: /tmp/dist-test-taskyLMvui/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515491061751-31228-0/minicluster-data/ts-0-root/wals/10ab8ed74bc2446fa6d552395a99143e/wal-000000012 (ops 56-60)
I20260812 06:18:12.848356 31341 log.cc:1079] T 10ab8ed74bc2446fa6d552395a99143e P 0330a6b87754415c9cc9e65efcbbc869: Deleting log segment in path: /tmp/dist-test-taskyLMvui/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515491061751-31228-0/minicluster-data/ts-0-root/wals/10ab8ed74bc2446fa6d552395a99143e/wal-000000013 (ops 61-64)
I20260812 06:18:12.877002 31341 maintenance_manager.cc:643] P 0330a6b87754415c9cc9e65efcbbc869: LogGCOp(10ab8ed74bc2446fa6d552395a99143e) complete. Timing: real 0.029s	user 0.000s	sys 0.028s Metrics: {}
I20260812 06:18:12.877526 31406 maintenance_manager.cc:419] P 0330a6b87754415c9cc9e65efcbbc869: Scheduling FlushDeltaMemStoresOp(10ab8ed74bc2446fa6d552395a99143e): perf score=3.181125
I20260812 06:18:12.898042 31341 maintenance_manager.cc:643] P 0330a6b87754415c9cc9e65efcbbc869: FlushDeltaMemStoresOp(10ab8ed74bc2446fa6d552395a99143e) complete. Timing: real 0.020s	user 0.010s	sys 0.006s Metrics: {"bytes_written":4512903,"delete_count":0,"lbm_write_time_us":7080,"lbm_writes_lt_1ms":113,"reinsert_count":0,"update_count":550}
I20260812 06:18:12.898442 31406 maintenance_manager.cc:419] P 0330a6b87754415c9cc9e65efcbbc869: Scheduling FlushDeltaMemStoresOp(10ab8ed74bc2446fa6d552395a99143e): perf score=2.188937
I20260812 06:18:12.908077 31341 maintenance_manager.cc:643] P 0330a6b87754415c9cc9e65efcbbc869: FlushDeltaMemStoresOp(10ab8ed74bc2446fa6d552395a99143e) complete. Timing: real 0.009s	user 0.009s	sys 0.000s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3822,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:18:12.908454 31406 maintenance_manager.cc:419] P 0330a6b87754415c9cc9e65efcbbc869: Scheduling UndoDeltaBlockGCOp(10ab8ed74bc2446fa6d552395a99143e): 462 bytes on disk
I20260812 06:18:12.908874 31341 maintenance_manager.cc:643] P 0330a6b87754415c9cc9e65efcbbc869: UndoDeltaBlockGCOp(10ab8ed74bc2446fa6d552395a99143e) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":49,"lbm_reads_lt_1ms":4}
I20260812 06:18:12.909327 31406 maintenance_manager.cc:419] P 0330a6b87754415c9cc9e65efcbbc869: Scheduling MajorDeltaCompactionOp(10ab8ed74bc2446fa6d552395a99143e): perf score=1.000000
I20260812 06:18:13.108175 31341 maintenance_manager.cc:643] P 0330a6b87754415c9cc9e65efcbbc869: MajorDeltaCompactionOp(10ab8ed74bc2446fa6d552395a99143e) complete. Timing: real 0.199s	user 0.110s	sys 0.088s Metrics: {"cfile_cache_miss":634,"cfile_cache_miss_bytes":28836362,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":915,"lbm_read_time_us":13057,"lbm_reads_lt_1ms":674,"lbm_write_time_us":33469,"lbm_writes_lt_1ms":643,"mutex_wait_us":326,"peak_mem_usage":75542472,"reinsert_count":0,"thread_start_us":83,"threads_started":1,"update_count":3000}
I20260812 06:18:13.108973 31406 maintenance_manager.cc:419] P 0330a6b87754415c9cc9e65efcbbc869: Scheduling FlushDeltaMemStoresOp(10ab8ed74bc2446fa6d552395a99143e): perf score=14.095187
I20260812 06:18:13.153820 31341 maintenance_manager.cc:643] P 0330a6b87754415c9cc9e65efcbbc869: FlushDeltaMemStoresOp(10ab8ed74bc2446fa6d552395a99143e) complete. Timing: real 0.045s	user 0.034s	sys 0.008s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":20137,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:18:13.154388 31406 maintenance_manager.cc:419] P 0330a6b87754415c9cc9e65efcbbc869: Scheduling MajorDeltaCompactionOp(10ab8ed74bc2446fa6d552395a99143e): perf score=1.000000
I20260812 06:18:13.309866 31341 maintenance_manager.cc:643] P 0330a6b87754415c9cc9e65efcbbc869: MajorDeltaCompactionOp(10ab8ed74bc2446fa6d552395a99143e) complete. Timing: real 0.154s	user 0.117s	sys 0.034s Metrics: {"cfile_cache_miss":431,"cfile_cache_miss_bytes":20631192,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":1,"delta_iterators_relevant":1,"dirs.queue_time_us":90,"lbm_read_time_us":10511,"lbm_reads_lt_1ms":467,"lbm_write_time_us":25741,"lbm_writes_lt_1ms":443,"mutex_wait_us":23,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":8192,"update_count":2000}
I20260812 06:18:13.310542 31406 maintenance_manager.cc:419] P 0330a6b87754415c9cc9e65efcbbc869: Scheduling FlushDeltaMemStoresOp(10ab8ed74bc2446fa6d552395a99143e): perf score=11.118625
I20260812 06:18:13.346041 31341 maintenance_manager.cc:643] P 0330a6b87754415c9cc9e65efcbbc869: FlushDeltaMemStoresOp(10ab8ed74bc2446fa6d552395a99143e) complete. Timing: real 0.035s	user 0.019s	sys 0.014s Metrics: {"bytes_written":12717735,"delete_count":0,"lbm_write_time_us":15260,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:18:13.346725 31406 maintenance_manager.cc:419] P 0330a6b87754415c9cc9e65efcbbc869: Scheduling FlushDeltaMemStoresOp(10ab8ed74bc2446fa6d552395a99143e): perf score=2.188937
I20260812 06:18:13.362855 31341 maintenance_manager.cc:643] P 0330a6b87754415c9cc9e65efcbbc869: FlushDeltaMemStoresOp(10ab8ed74bc2446fa6d552395a99143e) complete. Timing: real 0.016s	user 0.006s	sys 0.004s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":4708,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:18:13.363399 31406 maintenance_manager.cc:419] P 0330a6b87754415c9cc9e65efcbbc869: Scheduling MajorDeltaCompactionOp(10ab8ed74bc2446fa6d552395a99143e): perf score=1.000000
I20260812 06:18:13.489512 31341 maintenance_manager.cc:643] P 0330a6b87754415c9cc9e65efcbbc869: MajorDeltaCompactionOp(10ab8ed74bc2446fa6d552395a99143e) complete. Timing: real 0.126s	user 0.086s	sys 0.040s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20631303,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":742,"lbm_read_time_us":7096,"lbm_reads_lt_1ms":464,"lbm_write_time_us":25869,"lbm_writes_lt_1ms":443,"mutex_wait_us":48,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":2304,"update_count":2000}
I20260812 06:18:13.490187 31406 maintenance_manager.cc:419] P 0330a6b87754415c9cc9e65efcbbc869: Scheduling FlushDeltaMemStoresOp(10ab8ed74bc2446fa6d552395a99143e): perf score=10.126437
I20260812 06:18:13.528909 31341 maintenance_manager.cc:643] P 0330a6b87754415c9cc9e65efcbbc869: FlushDeltaMemStoresOp(10ab8ed74bc2446fa6d552395a99143e) complete. Timing: real 0.039s	user 0.030s	sys 0.007s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":15827,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:18:13.529467 31406 maintenance_manager.cc:419] P 0330a6b87754415c9cc9e65efcbbc869: Scheduling FlushDeltaMemStoresOp(10ab8ed74bc2446fa6d552395a99143e): perf score=2.188937
I20260812 06:18:13.539816 31341 maintenance_manager.cc:643] P 0330a6b87754415c9cc9e65efcbbc869: FlushDeltaMemStoresOp(10ab8ed74bc2446fa6d552395a99143e) complete. Timing: real 0.010s	user 0.001s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4070,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:13.541433 31406 maintenance_manager.cc:419] P 0330a6b87754415c9cc9e65efcbbc869: Scheduling MajorDeltaCompactionOp(10ab8ed74bc2446fa6d552395a99143e): perf score=1.000000
I20260812 06:18:13.663689 31341 maintenance_manager.cc:643] P 0330a6b87754415c9cc9e65efcbbc869: MajorDeltaCompactionOp(10ab8ed74bc2446fa6d552395a99143e) complete. Timing: real 0.122s	user 0.106s	sys 0.016s 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":963,"lbm_read_time_us":8966,"lbm_reads_lt_1ms":472,"lbm_write_time_us":23085,"lbm_writes_lt_1ms":443,"mutex_wait_us":238,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":768,"update_count":2000}
I20260812 06:18:13.664312 31406 maintenance_manager.cc:419] P 0330a6b87754415c9cc9e65efcbbc869: Scheduling FlushDeltaMemStoresOp(10ab8ed74bc2446fa6d552395a99143e): perf score=10.126437
I20260812 06:18:13.703588 31341 maintenance_manager.cc:643] P 0330a6b87754415c9cc9e65efcbbc869: FlushDeltaMemStoresOp(10ab8ed74bc2446fa6d552395a99143e) complete. Timing: real 0.039s	user 0.026s	sys 0.007s Metrics: {"bytes_written":12307491,"delete_count":0,"lbm_write_time_us":15556,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:18:13.704130 31406 maintenance_manager.cc:419] P 0330a6b87754415c9cc9e65efcbbc869: Scheduling FlushDeltaMemStoresOp(10ab8ed74bc2446fa6d552395a99143e): perf score=2.188937
I20260812 06:18:13.714967 31341 maintenance_manager.cc:643] P 0330a6b87754415c9cc9e65efcbbc869: FlushDeltaMemStoresOp(10ab8ed74bc2446fa6d552395a99143e) complete. Timing: real 0.011s	user 0.000s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4092,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:13.715694 31406 maintenance_manager.cc:419] P 0330a6b87754415c9cc9e65efcbbc869: Scheduling MajorDeltaCompactionOp(10ab8ed74bc2446fa6d552395a99143e): perf score=1.000000
I20260812 06:18:13.835518 31341 maintenance_manager.cc:643] P 0330a6b87754415c9cc9e65efcbbc869: MajorDeltaCompactionOp(10ab8ed74bc2446fa6d552395a99143e) complete. Timing: real 0.120s	user 0.096s	sys 0.020s 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":78,"lbm_read_time_us":8189,"lbm_reads_lt_1ms":472,"lbm_write_time_us":22625,"lbm_writes_lt_1ms":443,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":768,"update_count":2000}
I20260812 06:18:13.836166 31406 maintenance_manager.cc:419] P 0330a6b87754415c9cc9e65efcbbc869: Scheduling FlushDeltaMemStoresOp(10ab8ed74bc2446fa6d552395a99143e): perf score=10.126437
I20260812 06:18:13.882316 31341 maintenance_manager.cc:643] P 0330a6b87754415c9cc9e65efcbbc869: FlushDeltaMemStoresOp(10ab8ed74bc2446fa6d552395a99143e) complete. Timing: real 0.046s	user 0.024s	sys 0.020s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":15959,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:18:13.882836 31406 maintenance_manager.cc:419] P 0330a6b87754415c9cc9e65efcbbc869: Scheduling FlushDeltaMemStoresOp(10ab8ed74bc2446fa6d552395a99143e): perf score=2.188937
I20260812 06:18:13.893972 31341 maintenance_manager.cc:643] P 0330a6b87754415c9cc9e65efcbbc869: FlushDeltaMemStoresOp(10ab8ed74bc2446fa6d552395a99143e) complete. Timing: real 0.011s	user 0.005s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4173,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:13.894412 31406 maintenance_manager.cc:419] P 0330a6b87754415c9cc9e65efcbbc869: Scheduling MajorDeltaCompactionOp(10ab8ed74bc2446fa6d552395a99143e): perf score=1.000000
I20260812 06:18:14.036320 31341 maintenance_manager.cc:643] P 0330a6b87754415c9cc9e65efcbbc869: MajorDeltaCompactionOp(10ab8ed74bc2446fa6d552395a99143e) complete. Timing: real 0.142s	user 0.097s	sys 0.044s 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":394,"lbm_read_time_us":11573,"lbm_reads_lt_1ms":472,"lbm_write_time_us":22721,"lbm_writes_lt_1ms":443,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":10240,"update_count":2000}
I20260812 06:18:14.037106 31406 maintenance_manager.cc:419] P 0330a6b87754415c9cc9e65efcbbc869: Scheduling FlushDeltaMemStoresOp(10ab8ed74bc2446fa6d552395a99143e): perf score=10.126437
I20260812 06:18:14.074523 31341 maintenance_manager.cc:643] P 0330a6b87754415c9cc9e65efcbbc869: FlushDeltaMemStoresOp(10ab8ed74bc2446fa6d552395a99143e) complete. Timing: real 0.037s	user 0.027s	sys 0.008s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":15694,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:18:14.075023 31406 maintenance_manager.cc:419] P 0330a6b87754415c9cc9e65efcbbc869: Scheduling FlushDeltaMemStoresOp(10ab8ed74bc2446fa6d552395a99143e): perf score=2.188937
I20260812 06:18:14.088593 31341 maintenance_manager.cc:643] P 0330a6b87754415c9cc9e65efcbbc869: FlushDeltaMemStoresOp(10ab8ed74bc2446fa6d552395a99143e) complete. Timing: real 0.013s	user 0.008s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5014,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:14.089079 31406 maintenance_manager.cc:419] P 0330a6b87754415c9cc9e65efcbbc869: Scheduling MajorDeltaCompactionOp(10ab8ed74bc2446fa6d552395a99143e): perf score=1.000000
I20260812 06:18:14.219008 31341 maintenance_manager.cc:643] P 0330a6b87754415c9cc9e65efcbbc869: MajorDeltaCompactionOp(10ab8ed74bc2446fa6d552395a99143e) complete. Timing: real 0.130s	user 0.091s	sys 0.037s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20631312,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":513,"lbm_read_time_us":8518,"lbm_reads_lt_1ms":464,"lbm_write_time_us":25240,"lbm_writes_lt_1ms":443,"mutex_wait_us":47,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":4224,"update_count":2000}
I20260812 06:18:14.219736 31406 maintenance_manager.cc:419] P 0330a6b87754415c9cc9e65efcbbc869: Scheduling FlushDeltaMemStoresOp(10ab8ed74bc2446fa6d552395a99143e): perf score=11.118625
I20260812 06:18:14.253114 31341 maintenance_manager.cc:643] P 0330a6b87754415c9cc9e65efcbbc869: FlushDeltaMemStoresOp(10ab8ed74bc2446fa6d552395a99143e) complete. Timing: real 0.033s	user 0.021s	sys 0.011s Metrics: {"bytes_written":12717735,"delete_count":0,"lbm_write_time_us":14189,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:18:14.253676 31406 maintenance_manager.cc:419] P 0330a6b87754415c9cc9e65efcbbc869: Scheduling FlushDeltaMemStoresOp(10ab8ed74bc2446fa6d552395a99143e): perf score=2.188937
I20260812 06:18:14.269214 31341 maintenance_manager.cc:643] P 0330a6b87754415c9cc9e65efcbbc869: FlushDeltaMemStoresOp(10ab8ed74bc2446fa6d552395a99143e) complete. Timing: real 0.015s	user 0.010s	sys 0.004s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":5994,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:18:14.269775 31406 maintenance_manager.cc:419] P 0330a6b87754415c9cc9e65efcbbc869: Scheduling FlushMRSOp(10ab8ed74bc2446fa6d552395a99143e): perf score=1.000000
I20260812 06:18:14.303081 31341 maintenance_manager.cc:643] P 0330a6b87754415c9cc9e65efcbbc869: FlushMRSOp(10ab8ed74bc2446fa6d552395a99143e) complete. Timing: real 0.031s	user 0.025s	sys 0.004s Metrics: {"bytes_written":1234479,"cfile_init":1,"dirs.queue_time_us":89,"dirs.run_cpu_time_us":196,"dirs.run_wall_time_us":1260,"drs_written":1,"lbm_read_time_us":58,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1855,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":30}
I20260812 06:18:14.304018 31406 maintenance_manager.cc:419] P 0330a6b87754415c9cc9e65efcbbc869: Scheduling LogGCOp(10ab8ed74bc2446fa6d552395a99143e): free 121459489 bytes of WAL
I20260812 06:18:14.304279 31341 log_reader.cc:385] T 10ab8ed74bc2446fa6d552395a99143e: removed 12 log segments from log reader
I20260812 06:18:14.304342 31341 log.cc:1079] T 10ab8ed74bc2446fa6d552395a99143e P 0330a6b87754415c9cc9e65efcbbc869: Deleting log segment in path: /tmp/dist-test-taskyLMvui/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515491061751-31228-0/minicluster-data/ts-0-root/wals/10ab8ed74bc2446fa6d552395a99143e/wal-000000014 (ops 65-69)
I20260812 06:18:14.304392 31341 log.cc:1079] T 10ab8ed74bc2446fa6d552395a99143e P 0330a6b87754415c9cc9e65efcbbc869: Deleting log segment in path: /tmp/dist-test-taskyLMvui/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515491061751-31228-0/minicluster-data/ts-0-root/wals/10ab8ed74bc2446fa6d552395a99143e/wal-000000015 (ops 70-74)
I20260812 06:18:14.304414 31341 log.cc:1079] T 10ab8ed74bc2446fa6d552395a99143e P 0330a6b87754415c9cc9e65efcbbc869: Deleting log segment in path: /tmp/dist-test-taskyLMvui/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515491061751-31228-0/minicluster-data/ts-0-root/wals/10ab8ed74bc2446fa6d552395a99143e/wal-000000016 (ops 75-79)
I20260812 06:18:14.304436 31341 log.cc:1079] T 10ab8ed74bc2446fa6d552395a99143e P 0330a6b87754415c9cc9e65efcbbc869: Deleting log segment in path: /tmp/dist-test-taskyLMvui/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515491061751-31228-0/minicluster-data/ts-0-root/wals/10ab8ed74bc2446fa6d552395a99143e/wal-000000017 (ops 80-84)
I20260812 06:18:14.304466 31341 log.cc:1079] T 10ab8ed74bc2446fa6d552395a99143e P 0330a6b87754415c9cc9e65efcbbc869: Deleting log segment in path: /tmp/dist-test-taskyLMvui/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515491061751-31228-0/minicluster-data/ts-0-root/wals/10ab8ed74bc2446fa6d552395a99143e/wal-000000018 (ops 85-89)
I20260812 06:18:14.304498 31341 log.cc:1079] T 10ab8ed74bc2446fa6d552395a99143e P 0330a6b87754415c9cc9e65efcbbc869: Deleting log segment in path: /tmp/dist-test-taskyLMvui/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515491061751-31228-0/minicluster-data/ts-0-root/wals/10ab8ed74bc2446fa6d552395a99143e/wal-000000019 (ops 90-94)
I20260812 06:18:14.304531 31341 log.cc:1079] T 10ab8ed74bc2446fa6d552395a99143e P 0330a6b87754415c9cc9e65efcbbc869: Deleting log segment in path: /tmp/dist-test-taskyLMvui/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515491061751-31228-0/minicluster-data/ts-0-root/wals/10ab8ed74bc2446fa6d552395a99143e/wal-000000020 (ops 95-99)
I20260812 06:18:14.304561 31341 log.cc:1079] T 10ab8ed74bc2446fa6d552395a99143e P 0330a6b87754415c9cc9e65efcbbc869: Deleting log segment in path: /tmp/dist-test-taskyLMvui/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515491061751-31228-0/minicluster-data/ts-0-root/wals/10ab8ed74bc2446fa6d552395a99143e/wal-000000021 (ops 100-104)
I20260812 06:18:14.304582 31341 log.cc:1079] T 10ab8ed74bc2446fa6d552395a99143e P 0330a6b87754415c9cc9e65efcbbc869: Deleting log segment in path: /tmp/dist-test-taskyLMvui/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515491061751-31228-0/minicluster-data/ts-0-root/wals/10ab8ed74bc2446fa6d552395a99143e/wal-000000022 (ops 105-109)
I20260812 06:18:14.304610 31341 log.cc:1079] T 10ab8ed74bc2446fa6d552395a99143e P 0330a6b87754415c9cc9e65efcbbc869: Deleting log segment in path: /tmp/dist-test-taskyLMvui/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515491061751-31228-0/minicluster-data/ts-0-root/wals/10ab8ed74bc2446fa6d552395a99143e/wal-000000023 (ops 110-114)
I20260812 06:18:14.304637 31341 log.cc:1079] T 10ab8ed74bc2446fa6d552395a99143e P 0330a6b87754415c9cc9e65efcbbc869: Deleting log segment in path: /tmp/dist-test-taskyLMvui/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515491061751-31228-0/minicluster-data/ts-0-root/wals/10ab8ed74bc2446fa6d552395a99143e/wal-000000024 (ops 115-119)
I20260812 06:18:14.304670 31341 log.cc:1079] T 10ab8ed74bc2446fa6d552395a99143e P 0330a6b87754415c9cc9e65efcbbc869: Deleting log segment in path: /tmp/dist-test-taskyLMvui/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515491061751-31228-0/minicluster-data/ts-0-root/wals/10ab8ed74bc2446fa6d552395a99143e/wal-000000025 (ops 120-124)
I20260812 06:18:14.334369 31341 maintenance_manager.cc:643] P 0330a6b87754415c9cc9e65efcbbc869: LogGCOp(10ab8ed74bc2446fa6d552395a99143e) complete. Timing: real 0.030s	user 0.000s	sys 0.028s Metrics: {}
I20260812 06:18:14.334893 31406 maintenance_manager.cc:419] P 0330a6b87754415c9cc9e65efcbbc869: Scheduling FlushDeltaMemStoresOp(10ab8ed74bc2446fa6d552395a99143e): perf score=3.181125
I20260812 06:18:14.347330 31341 maintenance_manager.cc:643] P 0330a6b87754415c9cc9e65efcbbc869: FlushDeltaMemStoresOp(10ab8ed74bc2446fa6d552395a99143e) complete. Timing: real 0.012s	user 0.007s	sys 0.004s Metrics: {"bytes_written":4718029,"delete_count":0,"lbm_write_time_us":5049,"lbm_writes_lt_1ms":118,"reinsert_count":0,"update_count":575}
I20260812 06:18:14.347760 31406 maintenance_manager.cc:419] P 0330a6b87754415c9cc9e65efcbbc869: Scheduling UndoDeltaBlockGCOp(10ab8ed74bc2446fa6d552395a99143e): 472 bytes on disk
I20260812 06:18:14.348179 31341 maintenance_manager.cc:643] P 0330a6b87754415c9cc9e65efcbbc869: UndoDeltaBlockGCOp(10ab8ed74bc2446fa6d552395a99143e) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":48,"lbm_reads_lt_1ms":4}
I20260812 06:18:14.348726 31406 maintenance_manager.cc:419] P 0330a6b87754415c9cc9e65efcbbc869: Scheduling FlushDeltaMemStoresOp(10ab8ed74bc2446fa6d552395a99143e): perf score=2.188937
I20260812 06:18:14.359700 31341 maintenance_manager.cc:643] P 0330a6b87754415c9cc9e65efcbbc869: FlushDeltaMemStoresOp(10ab8ed74bc2446fa6d552395a99143e) complete. Timing: real 0.011s	user 0.004s	sys 0.003s Metrics: {"bytes_written":3487280,"delete_count":0,"lbm_write_time_us":3749,"lbm_writes_lt_1ms":88,"reinsert_count":0,"update_count":425}
I20260812 06:18:14.360313 31406 maintenance_manager.cc:419] P 0330a6b87754415c9cc9e65efcbbc869: Scheduling LogGCOp(10ab8ed74bc2446fa6d552395a99143e): free 11564877 bytes of WAL
I20260812 06:18:14.360626 31341 log_reader.cc:385] T 10ab8ed74bc2446fa6d552395a99143e: removed 1 log segments from log reader
I20260812 06:18:14.360699 31341 log.cc:1079] T 10ab8ed74bc2446fa6d552395a99143e P 0330a6b87754415c9cc9e65efcbbc869: Deleting log segment in path: /tmp/dist-test-taskyLMvui/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515491061751-31228-0/minicluster-data/ts-0-root/wals/10ab8ed74bc2446fa6d552395a99143e/wal-000000026 (ops 125-128)
I20260812 06:18:14.363142 31341 maintenance_manager.cc:643] P 0330a6b87754415c9cc9e65efcbbc869: LogGCOp(10ab8ed74bc2446fa6d552395a99143e) complete. Timing: real 0.003s	user 0.000s	sys 0.000s Metrics: {}
I20260812 06:18:14.363445 31406 maintenance_manager.cc:419] P 0330a6b87754415c9cc9e65efcbbc869: Scheduling MajorDeltaCompactionOp(10ab8ed74bc2446fa6d552395a99143e): perf score=1.000000
I20260812 06:18:14.522094 31341 maintenance_manager.cc:643] P 0330a6b87754415c9cc9e65efcbbc869: MajorDeltaCompactionOp(10ab8ed74bc2446fa6d552395a99143e) complete. Timing: real 0.158s	user 0.142s	sys 0.016s Metrics: {"cfile_cache_miss":634,"cfile_cache_miss_bytes":28836356,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":914,"lbm_read_time_us":10045,"lbm_reads_lt_1ms":666,"lbm_write_time_us":32801,"lbm_writes_lt_1ms":643,"mutex_wait_us":106,"peak_mem_usage":75542472,"reinsert_count":0,"thread_start_us":76,"threads_started":1,"update_count":3000}
I20260812 06:18:14.522773 31406 maintenance_manager.cc:419] P 0330a6b87754415c9cc9e65efcbbc869: Scheduling FlushDeltaMemStoresOp(10ab8ed74bc2446fa6d552395a99143e): perf score=14.095187
I20260812 06:18:14.570467 31341 maintenance_manager.cc:643] P 0330a6b87754415c9cc9e65efcbbc869: FlushDeltaMemStoresOp(10ab8ed74bc2446fa6d552395a99143e) complete. Timing: real 0.048s	user 0.024s	sys 0.021s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":20616,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:18:14.570971 31406 maintenance_manager.cc:419] P 0330a6b87754415c9cc9e65efcbbc869: Scheduling FlushDeltaMemStoresOp(10ab8ed74bc2446fa6d552395a99143e): perf score=2.188937
I20260812 06:18:14.583822 31341 maintenance_manager.cc:643] P 0330a6b87754415c9cc9e65efcbbc869: FlushDeltaMemStoresOp(10ab8ed74bc2446fa6d552395a99143e) complete. Timing: real 0.013s	user 0.007s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5188,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:14.584344 31406 maintenance_manager.cc:419] P 0330a6b87754415c9cc9e65efcbbc869: Scheduling MajorDeltaCompactionOp(10ab8ed74bc2446fa6d552395a99143e): perf score=1.000000
I20260812 06:18:14.745695 31341 maintenance_manager.cc:643] P 0330a6b87754415c9cc9e65efcbbc869: MajorDeltaCompactionOp(10ab8ed74bc2446fa6d552395a99143e) complete. Timing: real 0.161s	user 0.130s	sys 0.020s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24733723,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":914,"lbm_read_time_us":10098,"lbm_reads_lt_1ms":572,"lbm_write_time_us":29407,"lbm_writes_lt_1ms":543,"mutex_wait_us":267,"peak_mem_usage":63115900,"reinsert_count":0,"update_count":2500}
I20260812 06:18:14.746402 31406 maintenance_manager.cc:419] P 0330a6b87754415c9cc9e65efcbbc869: Scheduling FlushDeltaMemStoresOp(10ab8ed74bc2446fa6d552395a99143e): perf score=14.095187
I20260812 06:18:14.799417 31341 maintenance_manager.cc:643] P 0330a6b87754415c9cc9e65efcbbc869: FlushDeltaMemStoresOp(10ab8ed74bc2446fa6d552395a99143e) complete. Timing: real 0.053s	user 0.023s	sys 0.015s Metrics: {"bytes_written":16409905,"delete_count":0,"lbm_write_time_us":18520,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:18:14.800071 31406 maintenance_manager.cc:419] P 0330a6b87754415c9cc9e65efcbbc869: Scheduling FlushDeltaMemStoresOp(10ab8ed74bc2446fa6d552395a99143e): perf score=2.188937
I20260812 06:18:14.811918 31341 maintenance_manager.cc:643] P 0330a6b87754415c9cc9e65efcbbc869: FlushDeltaMemStoresOp(10ab8ed74bc2446fa6d552395a99143e) complete. Timing: real 0.012s	user 0.005s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4753,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:14.812491 31406 maintenance_manager.cc:419] P 0330a6b87754415c9cc9e65efcbbc869: Scheduling MajorDeltaCompactionOp(10ab8ed74bc2446fa6d552395a99143e): perf score=1.000000
I20260812 06:18:14.960750 31341 maintenance_manager.cc:643] P 0330a6b87754415c9cc9e65efcbbc869: MajorDeltaCompactionOp(10ab8ed74bc2446fa6d552395a99143e) complete. Timing: real 0.148s	user 0.100s	sys 0.044s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24733727,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":219,"lbm_read_time_us":10594,"lbm_reads_lt_1ms":572,"lbm_write_time_us":29350,"lbm_writes_lt_1ms":543,"mutex_wait_us":82,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":12672,"update_count":2500}
I20260812 06:18:14.961517 31406 maintenance_manager.cc:419] P 0330a6b87754415c9cc9e65efcbbc869: Scheduling FlushDeltaMemStoresOp(10ab8ed74bc2446fa6d552395a99143e): perf score=14.095187
I20260812 06:18:15.014674 31341 maintenance_manager.cc:643] P 0330a6b87754415c9cc9e65efcbbc869: FlushDeltaMemStoresOp(10ab8ed74bc2446fa6d552395a99143e) complete. Timing: real 0.053s	user 0.033s	sys 0.011s Metrics: {"bytes_written":16409903,"delete_count":0,"lbm_write_time_us":20695,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:18:15.015197 31406 maintenance_manager.cc:419] P 0330a6b87754415c9cc9e65efcbbc869: Scheduling FlushDeltaMemStoresOp(10ab8ed74bc2446fa6d552395a99143e): perf score=2.188937
I20260812 06:18:15.026289 31341 maintenance_manager.cc:643] P 0330a6b87754415c9cc9e65efcbbc869: FlushDeltaMemStoresOp(10ab8ed74bc2446fa6d552395a99143e) complete. Timing: real 0.011s	user 0.000s	sys 0.009s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4116,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:15.026757 31406 maintenance_manager.cc:419] P 0330a6b87754415c9cc9e65efcbbc869: Scheduling MajorDeltaCompactionOp(10ab8ed74bc2446fa6d552395a99143e): perf score=1.000000
I20260812 06:18:15.176082 31341 maintenance_manager.cc:643] P 0330a6b87754415c9cc9e65efcbbc869: MajorDeltaCompactionOp(10ab8ed74bc2446fa6d552395a99143e) complete. Timing: real 0.149s	user 0.101s	sys 0.037s 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":1004,"lbm_read_time_us":8938,"lbm_reads_lt_1ms":572,"lbm_write_time_us":27020,"lbm_writes_lt_1ms":543,"mutex_wait_us":366,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":9856,"update_count":2500}
I20260812 06:18:15.176798 31406 maintenance_manager.cc:419] P 0330a6b87754415c9cc9e65efcbbc869: Scheduling FlushDeltaMemStoresOp(10ab8ed74bc2446fa6d552395a99143e): perf score=14.095187
I20260812 06:18:15.219713 31341 maintenance_manager.cc:643] P 0330a6b87754415c9cc9e65efcbbc869: FlushDeltaMemStoresOp(10ab8ed74bc2446fa6d552395a99143e) complete. Timing: real 0.043s	user 0.031s	sys 0.007s Metrics: {"bytes_written":16409904,"delete_count":0,"lbm_write_time_us":19091,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:18:15.220201 31406 maintenance_manager.cc:419] P 0330a6b87754415c9cc9e65efcbbc869: Scheduling MajorDeltaCompactionOp(10ab8ed74bc2446fa6d552395a99143e): perf score=1.000000
I20260812 06:18:15.376883 31341 maintenance_manager.cc:643] P 0330a6b87754415c9cc9e65efcbbc869: MajorDeltaCompactionOp(10ab8ed74bc2446fa6d552395a99143e) complete. Timing: real 0.157s	user 0.120s	sys 0.032s Metrics: {"cfile_cache_miss":431,"cfile_cache_miss_bytes":20631195,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":1,"delta_iterators_relevant":1,"dirs.queue_time_us":731,"lbm_read_time_us":11616,"lbm_reads_lt_1ms":467,"lbm_write_time_us":26445,"lbm_writes_lt_1ms":443,"mutex_wait_us":320,"peak_mem_usage":50689328,"reinsert_count":0,"update_count":2000}
I20260812 06:18:15.377492 31406 maintenance_manager.cc:419] P 0330a6b87754415c9cc9e65efcbbc869: Scheduling FlushDeltaMemStoresOp(10ab8ed74bc2446fa6d552395a99143e): perf score=11.118625
I20260812 06:18:15.416917 31341 maintenance_manager.cc:643] P 0330a6b87754415c9cc9e65efcbbc869: FlushDeltaMemStoresOp(10ab8ed74bc2446fa6d552395a99143e) complete. Timing: real 0.039s	user 0.023s	sys 0.015s Metrics: {"bytes_written":12717735,"delete_count":0,"lbm_write_time_us":16282,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:18:15.417548 31406 maintenance_manager.cc:419] P 0330a6b87754415c9cc9e65efcbbc869: Scheduling FlushDeltaMemStoresOp(10ab8ed74bc2446fa6d552395a99143e): perf score=2.188937
I20260812 06:18:15.441474 31341 maintenance_manager.cc:643] P 0330a6b87754415c9cc9e65efcbbc869: FlushDeltaMemStoresOp(10ab8ed74bc2446fa6d552395a99143e) complete. Timing: real 0.024s	user 0.010s	sys 0.001s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":4691,"lbm_writes_lt_1ms":93,"reinsert_count":0,"spinlock_wait_cycles":768,"update_count":450}
I20260812 06:18:15.441939 31406 maintenance_manager.cc:419] P 0330a6b87754415c9cc9e65efcbbc869: Scheduling FlushDeltaMemStoresOp(10ab8ed74bc2446fa6d552395a99143e): perf score=2.188937
I20260812 06:18:15.452931 31341 maintenance_manager.cc:643] P 0330a6b87754415c9cc9e65efcbbc869: FlushDeltaMemStoresOp(10ab8ed74bc2446fa6d552395a99143e) complete. Timing: real 0.011s	user 0.010s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4383,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:15.453565 31406 maintenance_manager.cc:419] P 0330a6b87754415c9cc9e65efcbbc869: Scheduling MajorDeltaCompactionOp(10ab8ed74bc2446fa6d552395a99143e): perf score=1.000000
I20260812 06:18:15.646507 31341 maintenance_manager.cc:643] P 0330a6b87754415c9cc9e65efcbbc869: MajorDeltaCompactionOp(10ab8ed74bc2446fa6d552395a99143e) complete. Timing: real 0.193s	user 0.119s	sys 0.057s Metrics: {"cfile_cache_miss":533,"cfile_cache_miss_bytes":24733834,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":602,"lbm_read_time_us":14085,"lbm_reads_lt_1ms":573,"lbm_write_time_us":29960,"lbm_writes_lt_1ms":543,"mutex_wait_us":63,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":5248,"update_count":2500}
I20260812 06:18:15.647284 31406 maintenance_manager.cc:419] P 0330a6b87754415c9cc9e65efcbbc869: Scheduling FlushDeltaMemStoresOp(10ab8ed74bc2446fa6d552395a99143e): perf score=14.095187
I20260812 06:18:15.701067 31341 maintenance_manager.cc:643] P 0330a6b87754415c9cc9e65efcbbc869: FlushDeltaMemStoresOp(10ab8ed74bc2446fa6d552395a99143e) complete. Timing: real 0.054s	user 0.025s	sys 0.021s Metrics: {"bytes_written":16409903,"delete_count":0,"lbm_write_time_us":20903,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:18:15.701613 31406 maintenance_manager.cc:419] P 0330a6b87754415c9cc9e65efcbbc869: Scheduling FlushDeltaMemStoresOp(10ab8ed74bc2446fa6d552395a99143e): perf score=2.188937
I20260812 06:18:15.712710 31341 maintenance_manager.cc:643] P 0330a6b87754415c9cc9e65efcbbc869: FlushDeltaMemStoresOp(10ab8ed74bc2446fa6d552395a99143e) complete. Timing: real 0.011s	user 0.010s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4154,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:15.713173 31406 maintenance_manager.cc:419] P 0330a6b87754415c9cc9e65efcbbc869: Scheduling FlushMRSOp(10ab8ed74bc2446fa6d552395a99143e): perf score=1.000000
I20260812 06:18:15.743304 31341 maintenance_manager.cc:643] P 0330a6b87754415c9cc9e65efcbbc869: FlushMRSOp(10ab8ed74bc2446fa6d552395a99143e) complete. Timing: real 0.030s	user 0.028s	sys 0.000s Metrics: {"bytes_written":1234475,"cfile_init":1,"dirs.queue_time_us":56,"dirs.run_cpu_time_us":217,"dirs.run_wall_time_us":1470,"drs_written":1,"lbm_read_time_us":38,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1793,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":30}
I20260812 06:18:15.743973 31406 maintenance_manager.cc:419] P 0330a6b87754415c9cc9e65efcbbc869: Scheduling LogGCOp(10ab8ed74bc2446fa6d552395a99143e): free 121006648 bytes of WAL
I20260812 06:18:15.744189 31341 log_reader.cc:385] T 10ab8ed74bc2446fa6d552395a99143e: removed 12 log segments from log reader
I20260812 06:18:15.744248 31341 log.cc:1079] T 10ab8ed74bc2446fa6d552395a99143e P 0330a6b87754415c9cc9e65efcbbc869: Deleting log segment in path: /tmp/dist-test-taskyLMvui/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515491061751-31228-0/minicluster-data/ts-0-root/wals/10ab8ed74bc2446fa6d552395a99143e/wal-000000027 (ops 129-133)
I20260812 06:18:15.744303 31341 log.cc:1079] T 10ab8ed74bc2446fa6d552395a99143e P 0330a6b87754415c9cc9e65efcbbc869: Deleting log segment in path: /tmp/dist-test-taskyLMvui/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515491061751-31228-0/minicluster-data/ts-0-root/wals/10ab8ed74bc2446fa6d552395a99143e/wal-000000028 (ops 134-138)
I20260812 06:18:15.744339 31341 log.cc:1079] T 10ab8ed74bc2446fa6d552395a99143e P 0330a6b87754415c9cc9e65efcbbc869: Deleting log segment in path: /tmp/dist-test-taskyLMvui/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515491061751-31228-0/minicluster-data/ts-0-root/wals/10ab8ed74bc2446fa6d552395a99143e/wal-000000029 (ops 139-143)
I20260812 06:18:15.744390 31341 log.cc:1079] T 10ab8ed74bc2446fa6d552395a99143e P 0330a6b87754415c9cc9e65efcbbc869: Deleting log segment in path: /tmp/dist-test-taskyLMvui/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515491061751-31228-0/minicluster-data/ts-0-root/wals/10ab8ed74bc2446fa6d552395a99143e/wal-000000030 (ops 144-148)
I20260812 06:18:15.744426 31341 log.cc:1079] T 10ab8ed74bc2446fa6d552395a99143e P 0330a6b87754415c9cc9e65efcbbc869: Deleting log segment in path: /tmp/dist-test-taskyLMvui/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515491061751-31228-0/minicluster-data/ts-0-root/wals/10ab8ed74bc2446fa6d552395a99143e/wal-000000031 (ops 149-152)
I20260812 06:18:15.744467 31341 log.cc:1079] T 10ab8ed74bc2446fa6d552395a99143e P 0330a6b87754415c9cc9e65efcbbc869: Deleting log segment in path: /tmp/dist-test-taskyLMvui/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515491061751-31228-0/minicluster-data/ts-0-root/wals/10ab8ed74bc2446fa6d552395a99143e/wal-000000032 (ops 153-157)
I20260812 06:18:15.744505 31341 log.cc:1079] T 10ab8ed74bc2446fa6d552395a99143e P 0330a6b87754415c9cc9e65efcbbc869: Deleting log segment in path: /tmp/dist-test-taskyLMvui/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515491061751-31228-0/minicluster-data/ts-0-root/wals/10ab8ed74bc2446fa6d552395a99143e/wal-000000033 (ops 158-162)
I20260812 06:18:15.744544 31341 log.cc:1079] T 10ab8ed74bc2446fa6d552395a99143e P 0330a6b87754415c9cc9e65efcbbc869: Deleting log segment in path: /tmp/dist-test-taskyLMvui/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515491061751-31228-0/minicluster-data/ts-0-root/wals/10ab8ed74bc2446fa6d552395a99143e/wal-000000034 (ops 163-167)
I20260812 06:18:15.744580 31341 log.cc:1079] T 10ab8ed74bc2446fa6d552395a99143e P 0330a6b87754415c9cc9e65efcbbc869: Deleting log segment in path: /tmp/dist-test-taskyLMvui/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515491061751-31228-0/minicluster-data/ts-0-root/wals/10ab8ed74bc2446fa6d552395a99143e/wal-000000035 (ops 168-172)
I20260812 06:18:15.744617 31341 log.cc:1079] T 10ab8ed74bc2446fa6d552395a99143e P 0330a6b87754415c9cc9e65efcbbc869: Deleting log segment in path: /tmp/dist-test-taskyLMvui/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515491061751-31228-0/minicluster-data/ts-0-root/wals/10ab8ed74bc2446fa6d552395a99143e/wal-000000036 (ops 173-177)
I20260812 06:18:15.744656 31341 log.cc:1079] T 10ab8ed74bc2446fa6d552395a99143e P 0330a6b87754415c9cc9e65efcbbc869: Deleting log segment in path: /tmp/dist-test-taskyLMvui/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515491061751-31228-0/minicluster-data/ts-0-root/wals/10ab8ed74bc2446fa6d552395a99143e/wal-000000037 (ops 178-182)
I20260812 06:18:15.744693 31341 log.cc:1079] T 10ab8ed74bc2446fa6d552395a99143e P 0330a6b87754415c9cc9e65efcbbc869: Deleting log segment in path: /tmp/dist-test-taskyLMvui/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515491061751-31228-0/minicluster-data/ts-0-root/wals/10ab8ed74bc2446fa6d552395a99143e/wal-000000038 (ops 183-187)
I20260812 06:18:15.773087 31341 maintenance_manager.cc:643] P 0330a6b87754415c9cc9e65efcbbc869: LogGCOp(10ab8ed74bc2446fa6d552395a99143e) complete. Timing: real 0.029s	user 0.000s	sys 0.028s Metrics: {}
I20260812 06:18:15.773548 31406 maintenance_manager.cc:419] P 0330a6b87754415c9cc9e65efcbbc869: Scheduling UndoDeltaBlockGCOp(10ab8ed74bc2446fa6d552395a99143e): 473 bytes on disk
I20260812 06:18:15.774065 31341 maintenance_manager.cc:643] P 0330a6b87754415c9cc9e65efcbbc869: UndoDeltaBlockGCOp(10ab8ed74bc2446fa6d552395a99143e) 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:18:15.774614 31406 maintenance_manager.cc:419] P 0330a6b87754415c9cc9e65efcbbc869: Scheduling FlushDeltaMemStoresOp(10ab8ed74bc2446fa6d552395a99143e): perf score=3.181125
I20260812 06:18:15.796838 31341 maintenance_manager.cc:643] P 0330a6b87754415c9cc9e65efcbbc869: FlushDeltaMemStoresOp(10ab8ed74bc2446fa6d552395a99143e) complete. Timing: real 0.022s	user 0.016s	sys 0.001s Metrics: {"bytes_written":4512903,"delete_count":0,"lbm_write_time_us":7277,"lbm_writes_lt_1ms":113,"reinsert_count":0,"update_count":550}
I20260812 06:18:15.797254 31406 maintenance_manager.cc:419] P 0330a6b87754415c9cc9e65efcbbc869: Scheduling FlushDeltaMemStoresOp(10ab8ed74bc2446fa6d552395a99143e): perf score=2.188937
I20260812 06:18:15.806561 31341 maintenance_manager.cc:643] P 0330a6b87754415c9cc9e65efcbbc869: FlushDeltaMemStoresOp(10ab8ed74bc2446fa6d552395a99143e) complete. Timing: real 0.009s	user 0.003s	sys 0.005s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3784,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:18:15.807125 31406 maintenance_manager.cc:419] P 0330a6b87754415c9cc9e65efcbbc869: Scheduling MajorDeltaCompactionOp(10ab8ed74bc2446fa6d552395a99143e): perf score=1.000000
I20260812 06:18:16.019641 31341 maintenance_manager.cc:643] P 0330a6b87754415c9cc9e65efcbbc869: MajorDeltaCompactionOp(10ab8ed74bc2446fa6d552395a99143e) complete. Timing: real 0.212s	user 0.156s	sys 0.052s 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":203,"lbm_read_time_us":15424,"lbm_reads_lt_1ms":774,"lbm_write_time_us":36036,"lbm_writes_lt_1ms":743,"mutex_wait_us":21,"peak_mem_usage":87969044,"reinsert_count":0,"spinlock_wait_cycles":10112,"thread_start_us":102,"threads_started":1,"update_count":3500}
I20260812 06:18:16.021416 31406 maintenance_manager.cc:419] P 0330a6b87754415c9cc9e65efcbbc869: Scheduling FlushDeltaMemStoresOp(10ab8ed74bc2446fa6d552395a99143e): perf score=17.071750
I20260812 06:18:16.080098 31341 maintenance_manager.cc:643] P 0330a6b87754415c9cc9e65efcbbc869: FlushDeltaMemStoresOp(10ab8ed74bc2446fa6d552395a99143e) complete. Timing: real 0.058s	user 0.018s	sys 0.036s Metrics: {"bytes_written":18748277,"delete_count":0,"lbm_write_time_us":23638,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":459,"reinsert_count":0,"update_count":2285}
I20260812 06:18:16.080582 31406 maintenance_manager.cc:419] P 0330a6b87754415c9cc9e65efcbbc869: Scheduling FlushDeltaMemStoresOp(10ab8ed74bc2446fa6d552395a99143e): perf score=1.196750
I20260812 06:18:16.089743 31228 heavy-update-compaction-itest.cc:229] Time spent updating: real 4.729s	user 1.747s	sys 0.138s
I20260812 06:18:16.090871 31341 maintenance_manager.cc:643] P 0330a6b87754415c9cc9e65efcbbc869: FlushDeltaMemStoresOp(10ab8ed74bc2446fa6d552395a99143e) complete. Timing: real 0.010s	user 0.005s	sys 0.000s Metrics: {"bytes_written":2174483,"delete_count":0,"lbm_write_time_us":2205,"lbm_writes_lt_1ms":56,"reinsert_count":0,"update_count":265}
I20260812 06:18:16.091260 31406 maintenance_manager.cc:419] P 0330a6b87754415c9cc9e65efcbbc869: Scheduling FlushDeltaMemStoresOp(10ab8ed74bc2446fa6d552395a99143e): perf score=2.188937
I20260812 06:18:16.104997 31341 maintenance_manager.cc:643] P 0330a6b87754415c9cc9e65efcbbc869: FlushDeltaMemStoresOp(10ab8ed74bc2446fa6d552395a99143e) complete. Timing: real 0.014s	user 0.006s	sys 0.007s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":5604,"lbm_writes_lt_1ms":93,"reinsert_count":0,"spinlock_wait_cycles":1792,"update_count":450}
I20260812 06:18:16.105381 31406 maintenance_manager.cc:419] P 0330a6b87754415c9cc9e65efcbbc869: Scheduling MajorDeltaCompactionOp(10ab8ed74bc2446fa6d552395a99143e): perf score=1.000000
I20260812 06:18:16.164326 31228 heavy-update-compaction-itest.cc:265] Time spent scanning: real 0.074s	user 0.003s	sys 0.000s
I20260812 06:18:16.164974 31228 tablet_server.cc:179] TabletServer@127.30.127.1:0 shutting down...
I20260812 06:18:16.252084 31341 maintenance_manager.cc:643] P 0330a6b87754415c9cc9e65efcbbc869: MajorDeltaCompactionOp(10ab8ed74bc2446fa6d552395a99143e) complete. Timing: real 0.147s	user 0.101s	sys 0.044s Metrics: {"cfile_cache_hit":172,"cfile_cache_hit_bytes":6978758,"cfile_cache_miss":461,"cfile_cache_miss_bytes":21857442,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":1165,"lbm_read_time_us":9457,"lbm_reads_lt_1ms":493,"lbm_write_time_us":27422,"lbm_writes_lt_1ms":643,"mutex_wait_us":153,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":48384,"update_count":3000}
I20260812 06:18:16.256735 31228 ts_tablet_manager.cc:1507] Shutting down tablet manager...
I20260812 06:18:16.257206 31228 tablet_replica.cc:333] T 10ab8ed74bc2446fa6d552395a99143e P 0330a6b87754415c9cc9e65efcbbc869: stopping tablet replica
I20260812 06:18:16.257449 31228 raft_consensus.cc:2243] T 10ab8ed74bc2446fa6d552395a99143e P 0330a6b87754415c9cc9e65efcbbc869 [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:18:16.257647 31228 raft_consensus.cc:2272] T 10ab8ed74bc2446fa6d552395a99143e P 0330a6b87754415c9cc9e65efcbbc869 [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:18:16.272502 31228 tablet_server.cc:196] TabletServer@127.30.127.1:0 shutdown complete.
I20260812 06:18:16.305009 31228 master.cc:562] Master@127.30.127.62:42777 shutting down...
I20260812 06:18:16.308883 31228 raft_consensus.cc:2243] T 00000000000000000000000000000000 P 22d743a7a2d14f8a9eceefe0247693a3 [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:18:16.309038 31228 raft_consensus.cc:2272] T 00000000000000000000000000000000 P 22d743a7a2d14f8a9eceefe0247693a3 [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:18:16.309091 31228 tablet_replica.cc:333] T 00000000000000000000000000000000 P 22d743a7a2d14f8a9eceefe0247693a3: stopping tablet replica
I20260812 06:18:16.321234 31228 master.cc:584] Master@127.30.127.62:42777 shutdown complete.
[       OK ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/0 (5338 ms)
[ RUN      ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/1
I20260812 06:18:16.422326 31228 internal_mini_cluster.cc:156] Creating distributed mini masters. Addrs: 127.30.127.62:43203
I20260812 06:18:16.422725 31228 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:18:16.424772 31439 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:18:16.424795 31443 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:18:16.424896 31441 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:18:16.424928 31228 server_base.cc:1061] running on GCE node
I20260812 06:18:16.425273 31228 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:18:16.425324 31228 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:18:16.425346 31228 hybrid_clock.cc:648] HybridClock initialized: now 1786515496425346 us; error 0 us; skew 500 ppm
I20260812 06:18:16.426093 31228 webserver.cc:533] Webserver started at http://127.30.127.62:35347/ using document root <none> and password file <none>
I20260812 06:18:16.426219 31228 fs_manager.cc:362] Metadata directory not provided
I20260812 06:18:16.426258 31228 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:18:16.426316 31228 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:18:16.426646 31228 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskyLMvui/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515491061751-31228-0/minicluster-data/master-0-root/instance:
uuid: "3c2f4c01c3cb4756a4e5ee25e8a3fb7d"
format_stamp: "Formatted at 2026-08-12 06:18:16 on dist-test-slave-zkpd"
I20260812 06:18:16.428685 31228 fs_manager.cc:696] Time spent creating directory manager: real 0.002s	user 0.002s	sys 0.000s
I20260812 06:18:16.429586 31449 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:18:16.429824 31228 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.001s	sys 0.000s
I20260812 06:18:16.429895 31228 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskyLMvui/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515491061751-31228-0/minicluster-data/master-0-root
uuid: "3c2f4c01c3cb4756a4e5ee25e8a3fb7d"
format_stamp: "Formatted at 2026-08-12 06:18:16 on dist-test-slave-zkpd"
I20260812 06:18:16.429991 31228 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskyLMvui/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515491061751-31228-0/minicluster-data/master-0-root
metadata directory: /tmp/dist-test-taskyLMvui/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515491061751-31228-0/minicluster-data/master-0-root
1 data directories: /tmp/dist-test-taskyLMvui/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515491061751-31228-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:18:16.449637 31228 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:18:16.450044 31228 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:18:16.454276 31228 rpc_server.cc:307] RPC server started. Bound to: 127.30.127.62:43203
I20260812 06:18:16.456693 31513 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:18:16.462334 31512 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.30.127.62:43203 every 8 connection(s)
I20260812 06:18:16.462800 31513 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P 3c2f4c01c3cb4756a4e5ee25e8a3fb7d: Bootstrap starting.
I20260812 06:18:16.463512 31513 tablet_bootstrap.cc:654] T 00000000000000000000000000000000 P 3c2f4c01c3cb4756a4e5ee25e8a3fb7d: Neither blocks nor log segments found. Creating new log.
I20260812 06:18:16.464461 31513 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P 3c2f4c01c3cb4756a4e5ee25e8a3fb7d: No bootstrap required, opened a new log
I20260812 06:18:16.464818 31513 raft_consensus.cc:359] T 00000000000000000000000000000000 P 3c2f4c01c3cb4756a4e5ee25e8a3fb7d [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "3c2f4c01c3cb4756a4e5ee25e8a3fb7d" member_type: VOTER }
I20260812 06:18:16.464910 31513 raft_consensus.cc:385] T 00000000000000000000000000000000 P 3c2f4c01c3cb4756a4e5ee25e8a3fb7d [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:18:16.464932 31513 raft_consensus.cc:740] T 00000000000000000000000000000000 P 3c2f4c01c3cb4756a4e5ee25e8a3fb7d [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: 3c2f4c01c3cb4756a4e5ee25e8a3fb7d, State: Initialized, Role: FOLLOWER
I20260812 06:18:16.465073 31513 consensus_queue.cc:260] T 00000000000000000000000000000000 P 3c2f4c01c3cb4756a4e5ee25e8a3fb7d [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: "3c2f4c01c3cb4756a4e5ee25e8a3fb7d" member_type: VOTER }
I20260812 06:18:16.465161 31513 raft_consensus.cc:399] T 00000000000000000000000000000000 P 3c2f4c01c3cb4756a4e5ee25e8a3fb7d [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:18:16.465186 31513 raft_consensus.cc:493] T 00000000000000000000000000000000 P 3c2f4c01c3cb4756a4e5ee25e8a3fb7d [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:18:16.465221 31513 raft_consensus.cc:3060] T 00000000000000000000000000000000 P 3c2f4c01c3cb4756a4e5ee25e8a3fb7d [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:18:16.465844 31513 raft_consensus.cc:515] T 00000000000000000000000000000000 P 3c2f4c01c3cb4756a4e5ee25e8a3fb7d [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "3c2f4c01c3cb4756a4e5ee25e8a3fb7d" member_type: VOTER }
I20260812 06:18:16.465963 31513 leader_election.cc:304] T 00000000000000000000000000000000 P 3c2f4c01c3cb4756a4e5ee25e8a3fb7d [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: 3c2f4c01c3cb4756a4e5ee25e8a3fb7d; no voters: 
I20260812 06:18:16.466104 31513 leader_election.cc:290] T 00000000000000000000000000000000 P 3c2f4c01c3cb4756a4e5ee25e8a3fb7d [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:18:16.466277 31516 raft_consensus.cc:2804] T 00000000000000000000000000000000 P 3c2f4c01c3cb4756a4e5ee25e8a3fb7d [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:18:16.466464 31516 raft_consensus.cc:697] T 00000000000000000000000000000000 P 3c2f4c01c3cb4756a4e5ee25e8a3fb7d [term 1 LEADER]: Becoming Leader. State: Replica: 3c2f4c01c3cb4756a4e5ee25e8a3fb7d, State: Running, Role: LEADER
I20260812 06:18:16.466614 31513 sys_catalog.cc:565] T 00000000000000000000000000000000 P 3c2f4c01c3cb4756a4e5ee25e8a3fb7d [sys.catalog]: configured and running, proceeding with master startup.
I20260812 06:18:16.466624 31516 consensus_queue.cc:237] T 00000000000000000000000000000000 P 3c2f4c01c3cb4756a4e5ee25e8a3fb7d [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: "3c2f4c01c3cb4756a4e5ee25e8a3fb7d" member_type: VOTER }
I20260812 06:18:16.467123 31518 sys_catalog.cc:455] T 00000000000000000000000000000000 P 3c2f4c01c3cb4756a4e5ee25e8a3fb7d [sys.catalog]: SysCatalogTable state changed. Reason: New leader 3c2f4c01c3cb4756a4e5ee25e8a3fb7d. Latest consensus state: current_term: 1 leader_uuid: "3c2f4c01c3cb4756a4e5ee25e8a3fb7d" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "3c2f4c01c3cb4756a4e5ee25e8a3fb7d" member_type: VOTER } }
I20260812 06:18:16.467104 31517 sys_catalog.cc:455] T 00000000000000000000000000000000 P 3c2f4c01c3cb4756a4e5ee25e8a3fb7d [sys.catalog]: SysCatalogTable state changed. Reason: RaftConsensus started. Latest consensus state: current_term: 1 leader_uuid: "3c2f4c01c3cb4756a4e5ee25e8a3fb7d" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "3c2f4c01c3cb4756a4e5ee25e8a3fb7d" member_type: VOTER } }
I20260812 06:18:16.467214 31518 sys_catalog.cc:458] T 00000000000000000000000000000000 P 3c2f4c01c3cb4756a4e5ee25e8a3fb7d [sys.catalog]: This master's current role is: LEADER
I20260812 06:18:16.467224 31517 sys_catalog.cc:458] T 00000000000000000000000000000000 P 3c2f4c01c3cb4756a4e5ee25e8a3fb7d [sys.catalog]: This master's current role is: LEADER
I20260812 06:18:16.467496 31521 catalog_manager.cc:1511] Loading table and tablet metadata into memory...
I20260812 06:18:16.468351 31521 catalog_manager.cc:1520] Initializing Kudu cluster ID...
I20260812 06:18:16.468636 31228 internal_mini_cluster.cc:184] Waiting to initialize catalog manager on master 0
I20260812 06:18:16.470386 31521 catalog_manager.cc:1383] Generated new cluster ID: 47957c1e7cdb476a8697222028070e71
I20260812 06:18:16.470456 31521 catalog_manager.cc:1531] Initializing Kudu internal certificate authority...
I20260812 06:18:16.485126 31521 catalog_manager.cc:1406] Generated new certificate authority record
I20260812 06:18:16.485630 31521 catalog_manager.cc:1540] Loading token signing keys...
I20260812 06:18:16.493889 31521 catalog_manager.cc:6092] T 00000000000000000000000000000000 P 3c2f4c01c3cb4756a4e5ee25e8a3fb7d: Generated new TSK 0
I20260812 06:18:16.494035 31521 catalog_manager.cc:1550] Initializing in-progress tserver states...
I20260812 06:18:16.500897 31228 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:18:16.502652 31537 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:18:16.502761 31228 server_base.cc:1061] running on GCE node
W20260812 06:18:16.502734 31540 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:18:16.502720 31538 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:18:16.503024 31228 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:18:16.503067 31228 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:18:16.503082 31228 hybrid_clock.cc:648] HybridClock initialized: now 1786515496503082 us; error 0 us; skew 500 ppm
I20260812 06:18:16.504047 31228 webserver.cc:533] Webserver started at http://127.30.127.1:34263/ using document root <none> and password file <none>
I20260812 06:18:16.504213 31228 fs_manager.cc:362] Metadata directory not provided
I20260812 06:18:16.504297 31228 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:18:16.504374 31228 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:18:16.504733 31228 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskyLMvui/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515491061751-31228-0/minicluster-data/ts-0-root/instance:
uuid: "70f5518003144bec918e906a727c8e72"
format_stamp: "Formatted at 2026-08-12 06:18:16 on dist-test-slave-zkpd"
I20260812 06:18:16.506165 31228 fs_manager.cc:696] Time spent creating directory manager: real 0.001s	user 0.000s	sys 0.002s
I20260812 06:18:16.507059 31547 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:18:16.507303 31228 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.000s	sys 0.001s
I20260812 06:18:16.507401 31228 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskyLMvui/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515491061751-31228-0/minicluster-data/ts-0-root
uuid: "70f5518003144bec918e906a727c8e72"
format_stamp: "Formatted at 2026-08-12 06:18:16 on dist-test-slave-zkpd"
I20260812 06:18:16.507489 31228 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskyLMvui/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515491061751-31228-0/minicluster-data/ts-0-root
metadata directory: /tmp/dist-test-taskyLMvui/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515491061751-31228-0/minicluster-data/ts-0-root
1 data directories: /tmp/dist-test-taskyLMvui/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515491061751-31228-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:18:16.521690 31228 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:18:16.522069 31228 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:18:16.522364 31228 txn_system_client.cc:432] TxnSystemClient initialization is disabled...
I20260812 06:18:16.522817 31228 ts_tablet_manager.cc:585] Loaded tablet metadata (0 total tablets, 0 live tablets)
I20260812 06:18:16.522877 31228 ts_tablet_manager.cc:531] Time spent load tablet metadata: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:18:16.522938 31228 ts_tablet_manager.cc:616] Registered 0 tablets
I20260812 06:18:16.522972 31228 ts_tablet_manager.cc:595] Time spent register tablets: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:18:16.527360 31228 rpc_server.cc:307] RPC server started. Bound to: 127.30.127.1:46433
I20260812 06:18:16.527393 31620 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.30.127.1:46433 every 8 connection(s)
I20260812 06:18:16.536159 31621 heartbeater.cc:344] Connected to a master server at 127.30.127.62:43203
I20260812 06:18:16.536268 31621 heartbeater.cc:461] Registering TS with master...
I20260812 06:18:16.536440 31621 heartbeater.cc:507] Master 127.30.127.62:43203 requested a full tablet report, sending...
I20260812 06:18:16.537072 31468 ts_manager.cc:194] Registered new tserver with Master: 70f5518003144bec918e906a727c8e72 (127.30.127.1:46433)
I20260812 06:18:16.537726 31228 internal_mini_cluster.cc:371] 1 TS(s) registered with all masters after 0.009933939s
I20260812 06:18:16.537796 31468 master_service.cc:502] Signed X509 certificate for tserver {username='slave'} at 127.0.0.1:56676
I20260812 06:18:16.544504 31468 catalog_manager.cc:2283] Servicing CreateTable request from {username='slave'} at 127.0.0.1:56692:
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:18:16.552708 31577 tablet_service.cc:1511] Processing CreateTablet for tablet de648fb27aff431f9a062605235ca67e (DEFAULT_TABLE table=heavy-update-compaction-test [id=ad2ba0f71c2b4fbbb8d83f59328f17e2]), partition=
I20260812 06:18:16.552930 31577 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet de648fb27aff431f9a062605235ca67e. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:18:16.554729 31633 tablet_bootstrap.cc:492] T de648fb27aff431f9a062605235ca67e P 70f5518003144bec918e906a727c8e72: Bootstrap starting.
I20260812 06:18:16.555601 31633 tablet_bootstrap.cc:654] T de648fb27aff431f9a062605235ca67e P 70f5518003144bec918e906a727c8e72: Neither blocks nor log segments found. Creating new log.
I20260812 06:18:16.556710 31633 tablet_bootstrap.cc:492] T de648fb27aff431f9a062605235ca67e P 70f5518003144bec918e906a727c8e72: No bootstrap required, opened a new log
I20260812 06:18:16.556782 31633 ts_tablet_manager.cc:1403] T de648fb27aff431f9a062605235ca67e P 70f5518003144bec918e906a727c8e72: Time spent bootstrapping tablet: real 0.002s	user 0.000s	sys 0.001s
I20260812 06:18:16.557199 31633 raft_consensus.cc:359] T de648fb27aff431f9a062605235ca67e P 70f5518003144bec918e906a727c8e72 [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "70f5518003144bec918e906a727c8e72" member_type: VOTER last_known_addr { host: "127.30.127.1" port: 46433 } }
I20260812 06:18:16.557282 31633 raft_consensus.cc:385] T de648fb27aff431f9a062605235ca67e P 70f5518003144bec918e906a727c8e72 [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:18:16.557327 31633 raft_consensus.cc:740] T de648fb27aff431f9a062605235ca67e P 70f5518003144bec918e906a727c8e72 [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: 70f5518003144bec918e906a727c8e72, State: Initialized, Role: FOLLOWER
I20260812 06:18:16.557507 31633 consensus_queue.cc:260] T de648fb27aff431f9a062605235ca67e P 70f5518003144bec918e906a727c8e72 [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: "70f5518003144bec918e906a727c8e72" member_type: VOTER last_known_addr { host: "127.30.127.1" port: 46433 } }
I20260812 06:18:16.557585 31633 raft_consensus.cc:399] T de648fb27aff431f9a062605235ca67e P 70f5518003144bec918e906a727c8e72 [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:18:16.557642 31633 raft_consensus.cc:493] T de648fb27aff431f9a062605235ca67e P 70f5518003144bec918e906a727c8e72 [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:18:16.557701 31633 raft_consensus.cc:3060] T de648fb27aff431f9a062605235ca67e P 70f5518003144bec918e906a727c8e72 [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:18:16.558459 31633 raft_consensus.cc:515] T de648fb27aff431f9a062605235ca67e P 70f5518003144bec918e906a727c8e72 [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "70f5518003144bec918e906a727c8e72" member_type: VOTER last_known_addr { host: "127.30.127.1" port: 46433 } }
I20260812 06:18:16.558612 31633 leader_election.cc:304] T de648fb27aff431f9a062605235ca67e P 70f5518003144bec918e906a727c8e72 [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: 70f5518003144bec918e906a727c8e72; no voters: 
I20260812 06:18:16.558776 31633 leader_election.cc:290] T de648fb27aff431f9a062605235ca67e P 70f5518003144bec918e906a727c8e72 [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:18:16.558913 31636 raft_consensus.cc:2804] T de648fb27aff431f9a062605235ca67e P 70f5518003144bec918e906a727c8e72 [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:18:16.559105 31633 ts_tablet_manager.cc:1434] T de648fb27aff431f9a062605235ca67e P 70f5518003144bec918e906a727c8e72: Time spent starting tablet: real 0.002s	user 0.000s	sys 0.003s
I20260812 06:18:16.559125 31636 raft_consensus.cc:697] T de648fb27aff431f9a062605235ca67e P 70f5518003144bec918e906a727c8e72 [term 1 LEADER]: Becoming Leader. State: Replica: 70f5518003144bec918e906a727c8e72, State: Running, Role: LEADER
I20260812 06:18:16.559131 31621 heartbeater.cc:499] Master 127.30.127.62:43203 was elected leader, sending a full tablet report...
I20260812 06:18:16.559310 31636 consensus_queue.cc:237] T de648fb27aff431f9a062605235ca67e P 70f5518003144bec918e906a727c8e72 [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: "70f5518003144bec918e906a727c8e72" member_type: VOTER last_known_addr { host: "127.30.127.1" port: 46433 } }
I20260812 06:18:16.560736 31468 catalog_manager.cc:5719] T de648fb27aff431f9a062605235ca67e P 70f5518003144bec918e906a727c8e72 reported cstate change: term changed from 0 to 1, leader changed from <none> to 70f5518003144bec918e906a727c8e72 (127.30.127.1). New cstate: current_term: 1 leader_uuid: "70f5518003144bec918e906a727c8e72" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "70f5518003144bec918e906a727c8e72" member_type: VOTER last_known_addr { host: "127.30.127.1" port: 46433 } health_report { overall_health: HEALTHY } } }
I20260812 06:18:16.617167 31228 heavy-update-compaction-itest.cc:215] Time spent inserting: real 0.053s	user 0.022s	sys 0.000s
I20260812 06:18:16.778407 31622 maintenance_manager.cc:419] P 70f5518003144bec918e906a727c8e72: Scheduling FlushMRSOp(de648fb27aff431f9a062605235ca67e): perf score=19.054940
I20260812 06:18:16.958617 31553 maintenance_manager.cc:643] P 70f5518003144bec918e906a727c8e72: FlushMRSOp(de648fb27aff431f9a062605235ca67e) complete. Timing: real 0.180s	user 0.116s	sys 0.060s Metrics: {"bytes_written":12307489,"cfile_init":1,"delete_count":0,"dirs.queue_time_us":66,"dirs.run_cpu_time_us":211,"dirs.run_wall_time_us":845,"drs_written":1,"lbm_read_time_us":56,"lbm_reads_lt_1ms":4,"lbm_write_time_us":48365,"lbm_writes_lt_1ms":857,"peak_mem_usage":0,"reinsert_count":0,"rows_written":104,"spinlock_wait_cycles":1792,"update_count":1500}
I20260812 06:18:16.959281 31622 maintenance_manager.cc:419] P 70f5518003144bec918e906a727c8e72: Scheduling LogGCOp(de648fb27aff431f9a062605235ca67e): free 20743880 bytes of WAL
I20260812 06:18:16.959525 31553 log_reader.cc:385] T de648fb27aff431f9a062605235ca67e: removed 2 log segments from log reader
I20260812 06:18:16.959574 31553 log.cc:1079] T de648fb27aff431f9a062605235ca67e P 70f5518003144bec918e906a727c8e72: Deleting log segment in path: /tmp/dist-test-taskyLMvui/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515491061751-31228-0/minicluster-data/ts-0-root/wals/de648fb27aff431f9a062605235ca67e/wal-000000001 (ops 1-6)
I20260812 06:18:16.959605 31553 log.cc:1079] T de648fb27aff431f9a062605235ca67e P 70f5518003144bec918e906a727c8e72: Deleting log segment in path: /tmp/dist-test-taskyLMvui/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515491061751-31228-0/minicluster-data/ts-0-root/wals/de648fb27aff431f9a062605235ca67e/wal-000000002 (ops 7-11)
I20260812 06:18:16.964241 31553 maintenance_manager.cc:643] P 70f5518003144bec918e906a727c8e72: LogGCOp(de648fb27aff431f9a062605235ca67e) complete. Timing: real 0.005s	user 0.000s	sys 0.004s Metrics: {}
I20260812 06:18:16.964591 31622 maintenance_manager.cc:419] P 70f5518003144bec918e906a727c8e72: Scheduling FlushDeltaMemStoresOp(de648fb27aff431f9a062605235ca67e): perf score=2.188937
I20260812 06:18:16.981647 31553 maintenance_manager.cc:643] P 70f5518003144bec918e906a727c8e72: FlushDeltaMemStoresOp(de648fb27aff431f9a062605235ca67e) complete. Timing: real 0.017s	user 0.011s	sys 0.002s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6208,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:16.982108 31622 maintenance_manager.cc:419] P 70f5518003144bec918e906a727c8e72: Scheduling MajorDeltaCompactionOp(de648fb27aff431f9a062605235ca67e): perf score=1.000000
I20260812 06:18:17.134363 31553 maintenance_manager.cc:643] P 70f5518003144bec918e906a727c8e72: MajorDeltaCompactionOp(de648fb27aff431f9a062605235ca67e) complete. Timing: real 0.152s	user 0.085s	sys 0.067s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672276,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":86,"lbm_read_time_us":11682,"lbm_reads_lt_1ms":468,"lbm_write_time_us":25681,"lbm_writes_lt_1ms":443,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":9472,"thread_start_us":319,"threads_started":5,"update_count":2000}
I20260812 06:18:17.135198 31622 maintenance_manager.cc:419] P 70f5518003144bec918e906a727c8e72: Scheduling UndoDeltaBlockGCOp(de648fb27aff431f9a062605235ca67e): 20513805 bytes on disk
I20260812 06:18:17.135732 31553 maintenance_manager.cc:643] P 70f5518003144bec918e906a727c8e72: UndoDeltaBlockGCOp(de648fb27aff431f9a062605235ca67e) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":96,"lbm_reads_lt_1ms":4}
I20260812 06:18:17.136382 31622 maintenance_manager.cc:419] P 70f5518003144bec918e906a727c8e72: Scheduling FlushDeltaMemStoresOp(de648fb27aff431f9a062605235ca67e): perf score=10.126437
I20260812 06:18:17.183583 31553 maintenance_manager.cc:643] P 70f5518003144bec918e906a727c8e72: FlushDeltaMemStoresOp(de648fb27aff431f9a062605235ca67e) complete. Timing: real 0.047s	user 0.029s	sys 0.015s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":14691,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:18:17.184233 31622 maintenance_manager.cc:419] P 70f5518003144bec918e906a727c8e72: Scheduling FlushDeltaMemStoresOp(de648fb27aff431f9a062605235ca67e): perf score=2.188937
I20260812 06:18:17.194941 31553 maintenance_manager.cc:643] P 70f5518003144bec918e906a727c8e72: FlushDeltaMemStoresOp(de648fb27aff431f9a062605235ca67e) complete. Timing: real 0.010s	user 0.009s	sys 0.000s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4106,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:17.195478 31622 maintenance_manager.cc:419] P 70f5518003144bec918e906a727c8e72: Scheduling MajorDeltaCompactionOp(de648fb27aff431f9a062605235ca67e): perf score=1.000000
I20260812 06:18:17.359289 31553 maintenance_manager.cc:643] P 70f5518003144bec918e906a727c8e72: MajorDeltaCompactionOp(de648fb27aff431f9a062605235ca67e) complete. Timing: real 0.164s	user 0.123s	sys 0.040s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672276,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":1267,"lbm_read_time_us":10951,"lbm_reads_lt_1ms":472,"lbm_write_time_us":27108,"lbm_writes_lt_1ms":443,"mutex_wait_us":400,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":15104,"update_count":2000}
I20260812 06:18:17.360100 31622 maintenance_manager.cc:419] P 70f5518003144bec918e906a727c8e72: Scheduling FlushDeltaMemStoresOp(de648fb27aff431f9a062605235ca67e): perf score=10.126437
I20260812 06:18:17.397511 31553 maintenance_manager.cc:643] P 70f5518003144bec918e906a727c8e72: FlushDeltaMemStoresOp(de648fb27aff431f9a062605235ca67e) complete. Timing: real 0.037s	user 0.026s	sys 0.008s Metrics: {"bytes_written":12307492,"delete_count":0,"lbm_write_time_us":13728,"lbm_writes_lt_1ms":303,"reinsert_count":0,"spinlock_wait_cycles":1792,"update_count":1500}
I20260812 06:18:17.398012 31622 maintenance_manager.cc:419] P 70f5518003144bec918e906a727c8e72: Scheduling FlushDeltaMemStoresOp(de648fb27aff431f9a062605235ca67e): perf score=2.188937
I20260812 06:18:17.412880 31553 maintenance_manager.cc:643] P 70f5518003144bec918e906a727c8e72: FlushDeltaMemStoresOp(de648fb27aff431f9a062605235ca67e) complete. Timing: real 0.015s	user 0.008s	sys 0.005s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5819,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:17.413425 31622 maintenance_manager.cc:419] P 70f5518003144bec918e906a727c8e72: Scheduling MajorDeltaCompactionOp(de648fb27aff431f9a062605235ca67e): perf score=1.000000
I20260812 06:18:17.544447 31553 maintenance_manager.cc:643] P 70f5518003144bec918e906a727c8e72: MajorDeltaCompactionOp(de648fb27aff431f9a062605235ca67e) complete. Timing: real 0.131s	user 0.101s	sys 0.029s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672279,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":898,"lbm_read_time_us":8307,"lbm_reads_lt_1ms":472,"lbm_write_time_us":25732,"lbm_writes_lt_1ms":443,"mutex_wait_us":27,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":6784,"update_count":2000}
I20260812 06:18:17.544935 31622 maintenance_manager.cc:419] P 70f5518003144bec918e906a727c8e72: Scheduling FlushDeltaMemStoresOp(de648fb27aff431f9a062605235ca67e): perf score=10.126437
I20260812 06:18:17.588841 31553 maintenance_manager.cc:643] P 70f5518003144bec918e906a727c8e72: FlushDeltaMemStoresOp(de648fb27aff431f9a062605235ca67e) complete. Timing: real 0.044s	user 0.032s	sys 0.004s Metrics: {"bytes_written":12307491,"delete_count":0,"lbm_write_time_us":16475,"lbm_writes_1-10_ms":2,"lbm_writes_lt_1ms":301,"reinsert_count":0,"update_count":1500}
I20260812 06:18:17.589373 31622 maintenance_manager.cc:419] P 70f5518003144bec918e906a727c8e72: Scheduling FlushDeltaMemStoresOp(de648fb27aff431f9a062605235ca67e): perf score=2.188937
I20260812 06:18:17.600178 31553 maintenance_manager.cc:643] P 70f5518003144bec918e906a727c8e72: FlushDeltaMemStoresOp(de648fb27aff431f9a062605235ca67e) complete. Timing: real 0.011s	user 0.010s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4167,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:17.600685 31622 maintenance_manager.cc:419] P 70f5518003144bec918e906a727c8e72: Scheduling MajorDeltaCompactionOp(de648fb27aff431f9a062605235ca67e): perf score=1.000000
I20260812 06:18:17.748400 31553 maintenance_manager.cc:643] P 70f5518003144bec918e906a727c8e72: MajorDeltaCompactionOp(de648fb27aff431f9a062605235ca67e) complete. Timing: real 0.148s	user 0.120s	sys 0.028s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672278,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":222,"lbm_read_time_us":9925,"lbm_reads_lt_1ms":472,"lbm_write_time_us":28861,"lbm_writes_lt_1ms":443,"mutex_wait_us":58,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":35840,"update_count":2000}
I20260812 06:18:17.749155 31622 maintenance_manager.cc:419] P 70f5518003144bec918e906a727c8e72: Scheduling FlushDeltaMemStoresOp(de648fb27aff431f9a062605235ca67e): perf score=10.126437
I20260812 06:18:17.800053 31553 maintenance_manager.cc:643] P 70f5518003144bec918e906a727c8e72: FlushDeltaMemStoresOp(de648fb27aff431f9a062605235ca67e) complete. Timing: real 0.050s	user 0.015s	sys 0.027s Metrics: {"bytes_written":12307492,"delete_count":0,"lbm_write_time_us":13872,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:18:17.800580 31622 maintenance_manager.cc:419] P 70f5518003144bec918e906a727c8e72: Scheduling FlushDeltaMemStoresOp(de648fb27aff431f9a062605235ca67e): perf score=2.188937
I20260812 06:18:17.811277 31553 maintenance_manager.cc:643] P 70f5518003144bec918e906a727c8e72: FlushDeltaMemStoresOp(de648fb27aff431f9a062605235ca67e) complete. Timing: real 0.010s	user 0.005s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4276,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:17.811681 31622 maintenance_manager.cc:419] P 70f5518003144bec918e906a727c8e72: Scheduling MajorDeltaCompactionOp(de648fb27aff431f9a062605235ca67e): perf score=1.000000
I20260812 06:18:17.967708 31553 maintenance_manager.cc:643] P 70f5518003144bec918e906a727c8e72: MajorDeltaCompactionOp(de648fb27aff431f9a062605235ca67e) complete. Timing: real 0.156s	user 0.096s	sys 0.060s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672279,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":115,"lbm_read_time_us":11465,"lbm_reads_lt_1ms":472,"lbm_write_time_us":24132,"lbm_writes_lt_1ms":443,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":896,"update_count":2000}
I20260812 06:18:17.968413 31622 maintenance_manager.cc:419] P 70f5518003144bec918e906a727c8e72: Scheduling FlushDeltaMemStoresOp(de648fb27aff431f9a062605235ca67e): perf score=10.126437
I20260812 06:18:18.007781 31553 maintenance_manager.cc:643] P 70f5518003144bec918e906a727c8e72: FlushDeltaMemStoresOp(de648fb27aff431f9a062605235ca67e) complete. Timing: real 0.038s	user 0.021s	sys 0.015s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":16907,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:18:18.008358 31622 maintenance_manager.cc:419] P 70f5518003144bec918e906a727c8e72: Scheduling FlushDeltaMemStoresOp(de648fb27aff431f9a062605235ca67e): perf score=2.188937
I20260812 06:18:18.020725 31553 maintenance_manager.cc:643] P 70f5518003144bec918e906a727c8e72: FlushDeltaMemStoresOp(de648fb27aff431f9a062605235ca67e) complete. Timing: real 0.012s	user 0.003s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4360,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:18.021167 31622 maintenance_manager.cc:419] P 70f5518003144bec918e906a727c8e72: Scheduling MajorDeltaCompactionOp(de648fb27aff431f9a062605235ca67e): perf score=1.000000
I20260812 06:18:18.150396 31553 maintenance_manager.cc:643] P 70f5518003144bec918e906a727c8e72: MajorDeltaCompactionOp(de648fb27aff431f9a062605235ca67e) complete. Timing: real 0.129s	user 0.105s	sys 0.024s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672277,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":486,"lbm_read_time_us":7897,"lbm_reads_lt_1ms":472,"lbm_write_time_us":24992,"lbm_writes_lt_1ms":443,"mutex_wait_us":21,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":11392,"update_count":2000}
I20260812 06:18:18.154579 31622 maintenance_manager.cc:419] P 70f5518003144bec918e906a727c8e72: Scheduling FlushDeltaMemStoresOp(de648fb27aff431f9a062605235ca67e): perf score=11.118625
I20260812 06:18:18.185585 31553 maintenance_manager.cc:643] P 70f5518003144bec918e906a727c8e72: FlushDeltaMemStoresOp(de648fb27aff431f9a062605235ca67e) complete. Timing: real 0.031s	user 0.017s	sys 0.012s Metrics: {"bytes_written":12635685,"delete_count":0,"lbm_write_time_us":13166,"lbm_writes_lt_1ms":311,"reinsert_count":0,"update_count":1540}
I20260812 06:18:18.186151 31622 maintenance_manager.cc:419] P 70f5518003144bec918e906a727c8e72: Scheduling FlushDeltaMemStoresOp(de648fb27aff431f9a062605235ca67e): perf score=2.188937
I20260812 06:18:18.199723 31553 maintenance_manager.cc:643] P 70f5518003144bec918e906a727c8e72: FlushDeltaMemStoresOp(de648fb27aff431f9a062605235ca67e) complete. Timing: real 0.013s	user 0.000s	sys 0.011s Metrics: {"bytes_written":3774459,"delete_count":0,"lbm_write_time_us":4971,"lbm_writes_lt_1ms":95,"reinsert_count":0,"update_count":460}
I20260812 06:18:18.200229 31622 maintenance_manager.cc:419] P 70f5518003144bec918e906a727c8e72: Scheduling FlushMRSOp(de648fb27aff431f9a062605235ca67e): perf score=1.000000
I20260812 06:18:18.230240 31553 maintenance_manager.cc:643] P 70f5518003144bec918e906a727c8e72: FlushMRSOp(de648fb27aff431f9a062605235ca67e) complete. Timing: real 0.030s	user 0.026s	sys 0.002s Metrics: {"bytes_written":1234473,"cfile_init":1,"dirs.queue_time_us":67,"dirs.run_cpu_time_us":240,"dirs.run_wall_time_us":1237,"drs_written":1,"lbm_read_time_us":37,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1430,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":30}
I20260812 06:18:18.230912 31622 maintenance_manager.cc:419] P 70f5518003144bec918e906a727c8e72: Scheduling LogGCOp(de648fb27aff431f9a062605235ca67e): free 112239306 bytes of WAL
I20260812 06:18:18.231127 31553 log_reader.cc:385] T de648fb27aff431f9a062605235ca67e: removed 11 log segments from log reader
I20260812 06:18:18.231170 31553 log.cc:1079] T de648fb27aff431f9a062605235ca67e P 70f5518003144bec918e906a727c8e72: Deleting log segment in path: /tmp/dist-test-taskyLMvui/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515491061751-31228-0/minicluster-data/ts-0-root/wals/de648fb27aff431f9a062605235ca67e/wal-000000003 (ops 12-16)
I20260812 06:18:18.231199 31553 log.cc:1079] T de648fb27aff431f9a062605235ca67e P 70f5518003144bec918e906a727c8e72: Deleting log segment in path: /tmp/dist-test-taskyLMvui/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515491061751-31228-0/minicluster-data/ts-0-root/wals/de648fb27aff431f9a062605235ca67e/wal-000000004 (ops 17-21)
I20260812 06:18:18.231268 31553 log.cc:1079] T de648fb27aff431f9a062605235ca67e P 70f5518003144bec918e906a727c8e72: Deleting log segment in path: /tmp/dist-test-taskyLMvui/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515491061751-31228-0/minicluster-data/ts-0-root/wals/de648fb27aff431f9a062605235ca67e/wal-000000005 (ops 22-26)
I20260812 06:18:18.231307 31553 log.cc:1079] T de648fb27aff431f9a062605235ca67e P 70f5518003144bec918e906a727c8e72: Deleting log segment in path: /tmp/dist-test-taskyLMvui/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515491061751-31228-0/minicluster-data/ts-0-root/wals/de648fb27aff431f9a062605235ca67e/wal-000000006 (ops 27-31)
I20260812 06:18:18.231350 31553 log.cc:1079] T de648fb27aff431f9a062605235ca67e P 70f5518003144bec918e906a727c8e72: Deleting log segment in path: /tmp/dist-test-taskyLMvui/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515491061751-31228-0/minicluster-data/ts-0-root/wals/de648fb27aff431f9a062605235ca67e/wal-000000007 (ops 32-36)
I20260812 06:18:18.231390 31553 log.cc:1079] T de648fb27aff431f9a062605235ca67e P 70f5518003144bec918e906a727c8e72: Deleting log segment in path: /tmp/dist-test-taskyLMvui/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515491061751-31228-0/minicluster-data/ts-0-root/wals/de648fb27aff431f9a062605235ca67e/wal-000000008 (ops 37-41)
I20260812 06:18:18.231431 31553 log.cc:1079] T de648fb27aff431f9a062605235ca67e P 70f5518003144bec918e906a727c8e72: Deleting log segment in path: /tmp/dist-test-taskyLMvui/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515491061751-31228-0/minicluster-data/ts-0-root/wals/de648fb27aff431f9a062605235ca67e/wal-000000009 (ops 42-46)
I20260812 06:18:18.231470 31553 log.cc:1079] T de648fb27aff431f9a062605235ca67e P 70f5518003144bec918e906a727c8e72: Deleting log segment in path: /tmp/dist-test-taskyLMvui/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515491061751-31228-0/minicluster-data/ts-0-root/wals/de648fb27aff431f9a062605235ca67e/wal-000000010 (ops 47-50)
I20260812 06:18:18.231509 31553 log.cc:1079] T de648fb27aff431f9a062605235ca67e P 70f5518003144bec918e906a727c8e72: Deleting log segment in path: /tmp/dist-test-taskyLMvui/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515491061751-31228-0/minicluster-data/ts-0-root/wals/de648fb27aff431f9a062605235ca67e/wal-000000011 (ops 51-55)
I20260812 06:18:18.231549 31553 log.cc:1079] T de648fb27aff431f9a062605235ca67e P 70f5518003144bec918e906a727c8e72: Deleting log segment in path: /tmp/dist-test-taskyLMvui/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515491061751-31228-0/minicluster-data/ts-0-root/wals/de648fb27aff431f9a062605235ca67e/wal-000000012 (ops 56-60)
I20260812 06:18:18.231590 31553 log.cc:1079] T de648fb27aff431f9a062605235ca67e P 70f5518003144bec918e906a727c8e72: Deleting log segment in path: /tmp/dist-test-taskyLMvui/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515491061751-31228-0/minicluster-data/ts-0-root/wals/de648fb27aff431f9a062605235ca67e/wal-000000013 (ops 61-65)
I20260812 06:18:18.257524 31553 maintenance_manager.cc:643] P 70f5518003144bec918e906a727c8e72: LogGCOp(de648fb27aff431f9a062605235ca67e) complete. Timing: real 0.026s	user 0.000s	sys 0.025s Metrics: {}
I20260812 06:18:18.257925 31622 maintenance_manager.cc:419] P 70f5518003144bec918e906a727c8e72: Scheduling FlushDeltaMemStoresOp(de648fb27aff431f9a062605235ca67e): perf score=4.173312
I20260812 06:18:18.272845 31553 maintenance_manager.cc:643] P 70f5518003144bec918e906a727c8e72: FlushDeltaMemStoresOp(de648fb27aff431f9a062605235ca67e) complete. Timing: real 0.015s	user 0.001s	sys 0.013s Metrics: {"bytes_written":5948753,"delete_count":0,"lbm_write_time_us":6286,"lbm_writes_lt_1ms":148,"reinsert_count":0,"update_count":725}
I20260812 06:18:18.273263 31622 maintenance_manager.cc:419] P 70f5518003144bec918e906a727c8e72: Scheduling LogGCOp(de648fb27aff431f9a062605235ca67e): free 8767129 bytes of WAL
I20260812 06:18:18.273469 31553 log_reader.cc:385] T de648fb27aff431f9a062605235ca67e: removed 1 log segments from log reader
I20260812 06:18:18.273512 31553 log.cc:1079] T de648fb27aff431f9a062605235ca67e P 70f5518003144bec918e906a727c8e72: Deleting log segment in path: /tmp/dist-test-taskyLMvui/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515491061751-31228-0/minicluster-data/ts-0-root/wals/de648fb27aff431f9a062605235ca67e/wal-000000014 (ops 66-70)
I20260812 06:18:18.275161 31553 maintenance_manager.cc:643] P 70f5518003144bec918e906a727c8e72: LogGCOp(de648fb27aff431f9a062605235ca67e) complete. Timing: real 0.002s	user 0.000s	sys 0.000s Metrics: {}
I20260812 06:18:18.275456 31622 maintenance_manager.cc:419] P 70f5518003144bec918e906a727c8e72: Scheduling UndoDeltaBlockGCOp(de648fb27aff431f9a062605235ca67e): 472 bytes on disk
I20260812 06:18:18.275839 31553 maintenance_manager.cc:643] P 70f5518003144bec918e906a727c8e72: UndoDeltaBlockGCOp(de648fb27aff431f9a062605235ca67e) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":50,"lbm_reads_lt_1ms":4}
I20260812 06:18:18.276502 31622 maintenance_manager.cc:419] P 70f5518003144bec918e906a727c8e72: Scheduling FlushDeltaMemStoresOp(de648fb27aff431f9a062605235ca67e): perf score=1.196750
I20260812 06:18:18.287922 31553 maintenance_manager.cc:643] P 70f5518003144bec918e906a727c8e72: FlushDeltaMemStoresOp(de648fb27aff431f9a062605235ca67e) complete. Timing: real 0.011s	user 0.005s	sys 0.003s Metrics: {"bytes_written":2256529,"delete_count":0,"lbm_write_time_us":3431,"lbm_writes_lt_1ms":58,"reinsert_count":0,"update_count":275}
I20260812 06:18:18.288515 31622 maintenance_manager.cc:419] P 70f5518003144bec918e906a727c8e72: Scheduling MajorDeltaCompactionOp(de648fb27aff431f9a062605235ca67e): perf score=1.000000
I20260812 06:18:18.463508 31553 maintenance_manager.cc:643] P 70f5518003144bec918e906a727c8e72: MajorDeltaCompactionOp(de648fb27aff431f9a062605235ca67e) complete. Timing: real 0.175s	user 0.154s	sys 0.020s Metrics: {"cfile_cache_miss":634,"cfile_cache_miss_bytes":28877292,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":764,"lbm_read_time_us":13331,"lbm_reads_lt_1ms":670,"lbm_write_time_us":34080,"lbm_writes_lt_1ms":643,"mutex_wait_us":283,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":12288,"thread_start_us":94,"threads_started":1,"update_count":3000}
I20260812 06:18:18.464311 31622 maintenance_manager.cc:419] P 70f5518003144bec918e906a727c8e72: Scheduling FlushDeltaMemStoresOp(de648fb27aff431f9a062605235ca67e): perf score=14.095187
I20260812 06:18:18.513899 31553 maintenance_manager.cc:643] P 70f5518003144bec918e906a727c8e72: FlushDeltaMemStoresOp(de648fb27aff431f9a062605235ca67e) complete. Timing: real 0.049s	user 0.038s	sys 0.009s Metrics: {"bytes_written":16409904,"delete_count":0,"lbm_write_time_us":20713,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:18:18.514705 31622 maintenance_manager.cc:419] P 70f5518003144bec918e906a727c8e72: Scheduling FlushDeltaMemStoresOp(de648fb27aff431f9a062605235ca67e): perf score=2.188937
I20260812 06:18:18.543396 31553 maintenance_manager.cc:643] P 70f5518003144bec918e906a727c8e72: FlushDeltaMemStoresOp(de648fb27aff431f9a062605235ca67e) complete. Timing: real 0.028s	user 0.013s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5974,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:18.543856 31622 maintenance_manager.cc:419] P 70f5518003144bec918e906a727c8e72: Scheduling FlushDeltaMemStoresOp(de648fb27aff431f9a062605235ca67e): perf score=2.188937
I20260812 06:18:18.554098 31553 maintenance_manager.cc:643] P 70f5518003144bec918e906a727c8e72: FlushDeltaMemStoresOp(de648fb27aff431f9a062605235ca67e) complete. Timing: real 0.010s	user 0.004s	sys 0.004s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":3770,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:18.554566 31622 maintenance_manager.cc:419] P 70f5518003144bec918e906a727c8e72: Scheduling MajorDeltaCompactionOp(de648fb27aff431f9a062605235ca67e): perf score=1.000000
I20260812 06:18:18.731642 31553 maintenance_manager.cc:643] P 70f5518003144bec918e906a727c8e72: MajorDeltaCompactionOp(de648fb27aff431f9a062605235ca67e) complete. Timing: real 0.177s	user 0.123s	sys 0.052s Metrics: {"cfile_cache_miss":633,"cfile_cache_miss_bytes":28877221,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":373,"lbm_read_time_us":11601,"lbm_reads_lt_1ms":673,"lbm_write_time_us":35223,"lbm_writes_lt_1ms":643,"mutex_wait_us":44,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":13440,"update_count":3000}
I20260812 06:18:18.732295 31622 maintenance_manager.cc:419] P 70f5518003144bec918e906a727c8e72: Scheduling FlushDeltaMemStoresOp(de648fb27aff431f9a062605235ca67e): perf score=14.095187
I20260812 06:18:18.777549 31553 maintenance_manager.cc:643] P 70f5518003144bec918e906a727c8e72: FlushDeltaMemStoresOp(de648fb27aff431f9a062605235ca67e) complete. Timing: real 0.045s	user 0.032s	sys 0.011s Metrics: {"bytes_written":16409900,"delete_count":0,"lbm_write_time_us":19787,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:18:18.778121 31622 maintenance_manager.cc:419] P 70f5518003144bec918e906a727c8e72: Scheduling FlushDeltaMemStoresOp(de648fb27aff431f9a062605235ca67e): perf score=2.188937
I20260812 06:18:18.792939 31553 maintenance_manager.cc:643] P 70f5518003144bec918e906a727c8e72: FlushDeltaMemStoresOp(de648fb27aff431f9a062605235ca67e) complete. Timing: real 0.015s	user 0.005s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5717,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:18.793380 31622 maintenance_manager.cc:419] P 70f5518003144bec918e906a727c8e72: Scheduling MajorDeltaCompactionOp(de648fb27aff431f9a062605235ca67e): perf score=1.000000
I20260812 06:18:18.971256 31553 maintenance_manager.cc:643] P 70f5518003144bec918e906a727c8e72: MajorDeltaCompactionOp(de648fb27aff431f9a062605235ca67e) complete. Timing: real 0.178s	user 0.106s	sys 0.064s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774687,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":209,"lbm_read_time_us":10996,"lbm_reads_lt_1ms":572,"lbm_write_time_us":28250,"lbm_writes_lt_1ms":543,"mutex_wait_us":20,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":8832,"update_count":2500}
I20260812 06:18:18.971932 31622 maintenance_manager.cc:419] P 70f5518003144bec918e906a727c8e72: Scheduling FlushDeltaMemStoresOp(de648fb27aff431f9a062605235ca67e): perf score=14.095187
I20260812 06:18:19.021502 31553 maintenance_manager.cc:643] P 70f5518003144bec918e906a727c8e72: FlushDeltaMemStoresOp(de648fb27aff431f9a062605235ca67e) complete. Timing: real 0.049s	user 0.046s	sys 0.000s Metrics: {"bytes_written":16409903,"delete_count":0,"lbm_write_time_us":20565,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:18:19.022087 31622 maintenance_manager.cc:419] P 70f5518003144bec918e906a727c8e72: Scheduling FlushDeltaMemStoresOp(de648fb27aff431f9a062605235ca67e): perf score=2.188937
I20260812 06:18:19.033264 31553 maintenance_manager.cc:643] P 70f5518003144bec918e906a727c8e72: FlushDeltaMemStoresOp(de648fb27aff431f9a062605235ca67e) complete. Timing: real 0.011s	user 0.004s	sys 0.005s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3961,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:19.033865 31622 maintenance_manager.cc:419] P 70f5518003144bec918e906a727c8e72: Scheduling MajorDeltaCompactionOp(de648fb27aff431f9a062605235ca67e): perf score=1.000000
I20260812 06:18:19.185125 31553 maintenance_manager.cc:643] P 70f5518003144bec918e906a727c8e72: MajorDeltaCompactionOp(de648fb27aff431f9a062605235ca67e) complete. Timing: real 0.151s	user 0.134s	sys 0.013s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774690,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":867,"lbm_read_time_us":9488,"lbm_reads_lt_1ms":572,"lbm_write_time_us":29549,"lbm_writes_lt_1ms":543,"mutex_wait_us":318,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":1920,"update_count":2500}
I20260812 06:18:19.188223 31622 maintenance_manager.cc:419] P 70f5518003144bec918e906a727c8e72: Scheduling FlushDeltaMemStoresOp(de648fb27aff431f9a062605235ca67e): perf score=14.095187
I20260812 06:18:19.237880 31553 maintenance_manager.cc:643] P 70f5518003144bec918e906a727c8e72: FlushDeltaMemStoresOp(de648fb27aff431f9a062605235ca67e) complete. Timing: real 0.049s	user 0.019s	sys 0.024s Metrics: {"bytes_written":16409903,"delete_count":0,"lbm_write_time_us":19286,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:18:19.238413 31622 maintenance_manager.cc:419] P 70f5518003144bec918e906a727c8e72: Scheduling FlushDeltaMemStoresOp(de648fb27aff431f9a062605235ca67e): perf score=2.188937
I20260812 06:18:19.253968 31553 maintenance_manager.cc:643] P 70f5518003144bec918e906a727c8e72: FlushDeltaMemStoresOp(de648fb27aff431f9a062605235ca67e) complete. Timing: real 0.015s	user 0.013s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5692,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:19.254473 31622 maintenance_manager.cc:419] P 70f5518003144bec918e906a727c8e72: Scheduling MajorDeltaCompactionOp(de648fb27aff431f9a062605235ca67e): perf score=1.000000
I20260812 06:18:19.407671 31553 maintenance_manager.cc:643] P 70f5518003144bec918e906a727c8e72: MajorDeltaCompactionOp(de648fb27aff431f9a062605235ca67e) complete. Timing: real 0.153s	user 0.120s	sys 0.032s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774690,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":1565,"lbm_read_time_us":11237,"lbm_reads_lt_1ms":572,"lbm_write_time_us":31455,"lbm_writes_lt_1ms":543,"mutex_wait_us":1061,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":14080,"update_count":2500}
I20260812 06:18:19.408437 31622 maintenance_manager.cc:419] P 70f5518003144bec918e906a727c8e72: Scheduling FlushDeltaMemStoresOp(de648fb27aff431f9a062605235ca67e): perf score=10.126437
I20260812 06:18:19.442134 31553 maintenance_manager.cc:643] P 70f5518003144bec918e906a727c8e72: FlushDeltaMemStoresOp(de648fb27aff431f9a062605235ca67e) complete. Timing: real 0.033s	user 0.015s	sys 0.015s Metrics: {"bytes_written":12307491,"delete_count":0,"lbm_write_time_us":13927,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:18:19.442649 31622 maintenance_manager.cc:419] P 70f5518003144bec918e906a727c8e72: Scheduling FlushDeltaMemStoresOp(de648fb27aff431f9a062605235ca67e): perf score=2.188937
I20260812 06:18:19.453068 31553 maintenance_manager.cc:643] P 70f5518003144bec918e906a727c8e72: FlushDeltaMemStoresOp(de648fb27aff431f9a062605235ca67e) complete. Timing: real 0.010s	user 0.009s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3863,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:19.453531 31622 maintenance_manager.cc:419] P 70f5518003144bec918e906a727c8e72: Scheduling MajorDeltaCompactionOp(de648fb27aff431f9a062605235ca67e): perf score=1.000000
I20260812 06:18:19.574692 31553 maintenance_manager.cc:643] P 70f5518003144bec918e906a727c8e72: MajorDeltaCompactionOp(de648fb27aff431f9a062605235ca67e) complete. Timing: real 0.121s	user 0.073s	sys 0.047s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672278,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":334,"lbm_read_time_us":9112,"lbm_reads_lt_1ms":472,"lbm_write_time_us":21795,"lbm_writes_lt_1ms":443,"mutex_wait_us":45,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":6528,"update_count":2000}
I20260812 06:18:19.575402 31622 maintenance_manager.cc:419] P 70f5518003144bec918e906a727c8e72: Scheduling FlushDeltaMemStoresOp(de648fb27aff431f9a062605235ca67e): perf score=10.126437
I20260812 06:18:19.619789 31553 maintenance_manager.cc:643] P 70f5518003144bec918e906a727c8e72: FlushDeltaMemStoresOp(de648fb27aff431f9a062605235ca67e) complete. Timing: real 0.044s	user 0.023s	sys 0.018s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":14340,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:18:19.620375 31622 maintenance_manager.cc:419] P 70f5518003144bec918e906a727c8e72: Scheduling FlushDeltaMemStoresOp(de648fb27aff431f9a062605235ca67e): perf score=2.188937
I20260812 06:18:19.630982 31553 maintenance_manager.cc:643] P 70f5518003144bec918e906a727c8e72: FlushDeltaMemStoresOp(de648fb27aff431f9a062605235ca67e) complete. Timing: real 0.010s	user 0.005s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4189,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:19.631445 31622 maintenance_manager.cc:419] P 70f5518003144bec918e906a727c8e72: Scheduling FlushMRSOp(de648fb27aff431f9a062605235ca67e): perf score=1.000000
I20260812 06:18:19.677523 31553 maintenance_manager.cc:643] P 70f5518003144bec918e906a727c8e72: FlushMRSOp(de648fb27aff431f9a062605235ca67e) complete. Timing: real 0.046s	user 0.034s	sys 0.000s Metrics: {"bytes_written":1234479,"cfile_init":1,"dirs.queue_time_us":65,"dirs.run_cpu_time_us":231,"dirs.run_wall_time_us":1492,"drs_written":1,"lbm_read_time_us":78,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1486,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":30}
I20260812 06:18:19.678288 31622 maintenance_manager.cc:419] P 70f5518003144bec918e906a727c8e72: Scheduling LogGCOp(de648fb27aff431f9a062605235ca67e): free 123804199 bytes of WAL
I20260812 06:18:19.678503 31553 log_reader.cc:385] T de648fb27aff431f9a062605235ca67e: removed 12 log segments from log reader
I20260812 06:18:19.678546 31553 log.cc:1079] T de648fb27aff431f9a062605235ca67e P 70f5518003144bec918e906a727c8e72: Deleting log segment in path: /tmp/dist-test-taskyLMvui/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515491061751-31228-0/minicluster-data/ts-0-root/wals/de648fb27aff431f9a062605235ca67e/wal-000000015 (ops 71-75)
I20260812 06:18:19.678574 31553 log.cc:1079] T de648fb27aff431f9a062605235ca67e P 70f5518003144bec918e906a727c8e72: Deleting log segment in path: /tmp/dist-test-taskyLMvui/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515491061751-31228-0/minicluster-data/ts-0-root/wals/de648fb27aff431f9a062605235ca67e/wal-000000016 (ops 76-80)
I20260812 06:18:19.678643 31553 log.cc:1079] T de648fb27aff431f9a062605235ca67e P 70f5518003144bec918e906a727c8e72: Deleting log segment in path: /tmp/dist-test-taskyLMvui/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515491061751-31228-0/minicluster-data/ts-0-root/wals/de648fb27aff431f9a062605235ca67e/wal-000000017 (ops 81-84)
I20260812 06:18:19.678684 31553 log.cc:1079] T de648fb27aff431f9a062605235ca67e P 70f5518003144bec918e906a727c8e72: Deleting log segment in path: /tmp/dist-test-taskyLMvui/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515491061751-31228-0/minicluster-data/ts-0-root/wals/de648fb27aff431f9a062605235ca67e/wal-000000018 (ops 85-89)
I20260812 06:18:19.678751 31553 log.cc:1079] T de648fb27aff431f9a062605235ca67e P 70f5518003144bec918e906a727c8e72: Deleting log segment in path: /tmp/dist-test-taskyLMvui/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515491061751-31228-0/minicluster-data/ts-0-root/wals/de648fb27aff431f9a062605235ca67e/wal-000000019 (ops 90-94)
I20260812 06:18:19.678792 31553 log.cc:1079] T de648fb27aff431f9a062605235ca67e P 70f5518003144bec918e906a727c8e72: Deleting log segment in path: /tmp/dist-test-taskyLMvui/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515491061751-31228-0/minicluster-data/ts-0-root/wals/de648fb27aff431f9a062605235ca67e/wal-000000020 (ops 95-99)
I20260812 06:18:19.678841 31553 log.cc:1079] T de648fb27aff431f9a062605235ca67e P 70f5518003144bec918e906a727c8e72: Deleting log segment in path: /tmp/dist-test-taskyLMvui/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515491061751-31228-0/minicluster-data/ts-0-root/wals/de648fb27aff431f9a062605235ca67e/wal-000000021 (ops 100-104)
I20260812 06:18:19.678875 31553 log.cc:1079] T de648fb27aff431f9a062605235ca67e P 70f5518003144bec918e906a727c8e72: Deleting log segment in path: /tmp/dist-test-taskyLMvui/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515491061751-31228-0/minicluster-data/ts-0-root/wals/de648fb27aff431f9a062605235ca67e/wal-000000022 (ops 105-108)
I20260812 06:18:19.678912 31553 log.cc:1079] T de648fb27aff431f9a062605235ca67e P 70f5518003144bec918e906a727c8e72: Deleting log segment in path: /tmp/dist-test-taskyLMvui/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515491061751-31228-0/minicluster-data/ts-0-root/wals/de648fb27aff431f9a062605235ca67e/wal-000000023 (ops 109-113)
I20260812 06:18:19.678951 31553 log.cc:1079] T de648fb27aff431f9a062605235ca67e P 70f5518003144bec918e906a727c8e72: Deleting log segment in path: /tmp/dist-test-taskyLMvui/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515491061751-31228-0/minicluster-data/ts-0-root/wals/de648fb27aff431f9a062605235ca67e/wal-000000024 (ops 114-118)
I20260812 06:18:19.678988 31553 log.cc:1079] T de648fb27aff431f9a062605235ca67e P 70f5518003144bec918e906a727c8e72: Deleting log segment in path: /tmp/dist-test-taskyLMvui/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515491061751-31228-0/minicluster-data/ts-0-root/wals/de648fb27aff431f9a062605235ca67e/wal-000000025 (ops 119-123)
I20260812 06:18:19.679028 31553 log.cc:1079] T de648fb27aff431f9a062605235ca67e P 70f5518003144bec918e906a727c8e72: Deleting log segment in path: /tmp/dist-test-taskyLMvui/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515491061751-31228-0/minicluster-data/ts-0-root/wals/de648fb27aff431f9a062605235ca67e/wal-000000026 (ops 124-128)
I20260812 06:18:19.707043 31553 maintenance_manager.cc:643] P 70f5518003144bec918e906a727c8e72: LogGCOp(de648fb27aff431f9a062605235ca67e) complete. Timing: real 0.029s	user 0.004s	sys 0.022s Metrics: {}
I20260812 06:18:19.707424 31622 maintenance_manager.cc:419] P 70f5518003144bec918e906a727c8e72: Scheduling UndoDeltaBlockGCOp(de648fb27aff431f9a062605235ca67e): 472 bytes on disk
I20260812 06:18:19.708096 31553 maintenance_manager.cc:643] P 70f5518003144bec918e906a727c8e72: UndoDeltaBlockGCOp(de648fb27aff431f9a062605235ca67e) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":117,"lbm_reads_lt_1ms":4}
I20260812 06:18:19.708637 31622 maintenance_manager.cc:419] P 70f5518003144bec918e906a727c8e72: Scheduling FlushDeltaMemStoresOp(de648fb27aff431f9a062605235ca67e): perf score=3.181125
I20260812 06:18:19.722538 31553 maintenance_manager.cc:643] P 70f5518003144bec918e906a727c8e72: FlushDeltaMemStoresOp(de648fb27aff431f9a062605235ca67e) complete. Timing: real 0.014s	user 0.007s	sys 0.003s Metrics: {"bytes_written":4512903,"delete_count":0,"lbm_write_time_us":4580,"lbm_writes_lt_1ms":113,"reinsert_count":0,"update_count":550}
I20260812 06:18:19.722901 31622 maintenance_manager.cc:419] P 70f5518003144bec918e906a727c8e72: Scheduling FlushDeltaMemStoresOp(de648fb27aff431f9a062605235ca67e): perf score=2.188937
I20260812 06:18:19.733666 31553 maintenance_manager.cc:643] P 70f5518003144bec918e906a727c8e72: FlushDeltaMemStoresOp(de648fb27aff431f9a062605235ca67e) complete. Timing: real 0.011s	user 0.008s	sys 0.001s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3807,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:18:19.734244 31622 maintenance_manager.cc:419] P 70f5518003144bec918e906a727c8e72: Scheduling MajorDeltaCompactionOp(de648fb27aff431f9a062605235ca67e): perf score=1.000000
I20260812 06:18:19.943822 31553 maintenance_manager.cc:643] P 70f5518003144bec918e906a727c8e72: MajorDeltaCompactionOp(de648fb27aff431f9a062605235ca67e) complete. Timing: real 0.209s	user 0.152s	sys 0.057s Metrics: {"cfile_cache_miss":634,"cfile_cache_miss_bytes":28877329,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":1530,"lbm_read_time_us":15195,"lbm_reads_lt_1ms":674,"lbm_write_time_us":33987,"lbm_writes_lt_1ms":643,"mutex_wait_us":495,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":8064,"thread_start_us":78,"threads_started":1,"update_count":3000}
I20260812 06:18:19.944619 31622 maintenance_manager.cc:419] P 70f5518003144bec918e906a727c8e72: Scheduling FlushDeltaMemStoresOp(de648fb27aff431f9a062605235ca67e): perf score=14.095187
I20260812 06:18:20.001132 31553 maintenance_manager.cc:643] P 70f5518003144bec918e906a727c8e72: FlushDeltaMemStoresOp(de648fb27aff431f9a062605235ca67e) complete. Timing: real 0.056s	user 0.035s	sys 0.019s Metrics: {"bytes_written":16409904,"delete_count":0,"lbm_write_time_us":28086,"lbm_writes_1-10_ms":2,"lbm_writes_lt_1ms":401,"reinsert_count":0,"update_count":2000}
I20260812 06:18:20.001567 31622 maintenance_manager.cc:419] P 70f5518003144bec918e906a727c8e72: Scheduling FlushDeltaMemStoresOp(de648fb27aff431f9a062605235ca67e): perf score=2.188937
I20260812 06:18:20.012681 31553 maintenance_manager.cc:643] P 70f5518003144bec918e906a727c8e72: FlushDeltaMemStoresOp(de648fb27aff431f9a062605235ca67e) complete. Timing: real 0.011s	user 0.010s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4070,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:20.013188 31622 maintenance_manager.cc:419] P 70f5518003144bec918e906a727c8e72: Scheduling MajorDeltaCompactionOp(de648fb27aff431f9a062605235ca67e): perf score=1.000000
I20260812 06:18:20.185899 31553 maintenance_manager.cc:643] P 70f5518003144bec918e906a727c8e72: MajorDeltaCompactionOp(de648fb27aff431f9a062605235ca67e) complete. Timing: real 0.173s	user 0.088s	sys 0.084s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774691,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":212,"lbm_read_time_us":13016,"lbm_reads_lt_1ms":572,"lbm_write_time_us":28277,"lbm_writes_lt_1ms":543,"mutex_wait_us":22,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":8448,"update_count":2500}
I20260812 06:18:20.186360 31622 maintenance_manager.cc:419] P 70f5518003144bec918e906a727c8e72: Scheduling FlushDeltaMemStoresOp(de648fb27aff431f9a062605235ca67e): perf score=14.095187
I20260812 06:18:20.240564 31553 maintenance_manager.cc:643] P 70f5518003144bec918e906a727c8e72: FlushDeltaMemStoresOp(de648fb27aff431f9a062605235ca67e) complete. Timing: real 0.054s	user 0.022s	sys 0.031s Metrics: {"bytes_written":16409900,"delete_count":0,"lbm_write_time_us":24393,"lbm_writes_lt_1ms":403,"reinsert_count":0,"spinlock_wait_cycles":896,"update_count":2000}
I20260812 06:18:20.241080 31622 maintenance_manager.cc:419] P 70f5518003144bec918e906a727c8e72: Scheduling FlushDeltaMemStoresOp(de648fb27aff431f9a062605235ca67e): perf score=2.188937
I20260812 06:18:20.254061 31553 maintenance_manager.cc:643] P 70f5518003144bec918e906a727c8e72: FlushDeltaMemStoresOp(de648fb27aff431f9a062605235ca67e) complete. Timing: real 0.013s	user 0.006s	sys 0.005s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4731,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:20.254568 31622 maintenance_manager.cc:419] P 70f5518003144bec918e906a727c8e72: Scheduling MajorDeltaCompactionOp(de648fb27aff431f9a062605235ca67e): perf score=1.000000
I20260812 06:18:20.431727 31553 maintenance_manager.cc:643] P 70f5518003144bec918e906a727c8e72: MajorDeltaCompactionOp(de648fb27aff431f9a062605235ca67e) complete. Timing: real 0.177s	user 0.112s	sys 0.060s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774687,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":456,"lbm_read_time_us":13369,"lbm_reads_lt_1ms":572,"lbm_write_time_us":29330,"lbm_writes_lt_1ms":543,"mutex_wait_us":267,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":2816,"update_count":2500}
I20260812 06:18:20.432513 31622 maintenance_manager.cc:419] P 70f5518003144bec918e906a727c8e72: Scheduling FlushDeltaMemStoresOp(de648fb27aff431f9a062605235ca67e): perf score=14.095187
I20260812 06:18:20.495200 31553 maintenance_manager.cc:643] P 70f5518003144bec918e906a727c8e72: FlushDeltaMemStoresOp(de648fb27aff431f9a062605235ca67e) complete. Timing: real 0.063s	user 0.041s	sys 0.015s Metrics: {"bytes_written":16409899,"delete_count":0,"lbm_write_time_us":21205,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:18:20.495739 31622 maintenance_manager.cc:419] P 70f5518003144bec918e906a727c8e72: Scheduling FlushDeltaMemStoresOp(de648fb27aff431f9a062605235ca67e): perf score=2.188937
I20260812 06:18:20.512393 31553 maintenance_manager.cc:643] P 70f5518003144bec918e906a727c8e72: FlushDeltaMemStoresOp(de648fb27aff431f9a062605235ca67e) complete. Timing: real 0.016s	user 0.015s	sys 0.001s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6370,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:20.512918 31622 maintenance_manager.cc:419] P 70f5518003144bec918e906a727c8e72: Scheduling MajorDeltaCompactionOp(de648fb27aff431f9a062605235ca67e): perf score=1.000000
I20260812 06:18:20.697041 31553 maintenance_manager.cc:643] P 70f5518003144bec918e906a727c8e72: MajorDeltaCompactionOp(de648fb27aff431f9a062605235ca67e) complete. Timing: real 0.184s	user 0.094s	sys 0.079s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774686,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":147,"lbm_read_time_us":13196,"lbm_reads_lt_1ms":572,"lbm_write_time_us":30656,"lbm_writes_lt_1ms":543,"mutex_wait_us":21,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":19968,"update_count":2500}
I20260812 06:18:20.697737 31622 maintenance_manager.cc:419] P 70f5518003144bec918e906a727c8e72: Scheduling FlushDeltaMemStoresOp(de648fb27aff431f9a062605235ca67e): perf score=14.095187
I20260812 06:18:20.748163 31553 maintenance_manager.cc:643] P 70f5518003144bec918e906a727c8e72: FlushDeltaMemStoresOp(de648fb27aff431f9a062605235ca67e) complete. Timing: real 0.050s	user 0.027s	sys 0.015s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":18699,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:18:20.748744 31622 maintenance_manager.cc:419] P 70f5518003144bec918e906a727c8e72: Scheduling FlushDeltaMemStoresOp(de648fb27aff431f9a062605235ca67e): perf score=2.188937
I20260812 06:18:20.769865 31553 maintenance_manager.cc:643] P 70f5518003144bec918e906a727c8e72: FlushDeltaMemStoresOp(de648fb27aff431f9a062605235ca67e) complete. Timing: real 0.021s	user 0.005s	sys 0.014s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4291,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:20.770403 31622 maintenance_manager.cc:419] P 70f5518003144bec918e906a727c8e72: Scheduling MajorDeltaCompactionOp(de648fb27aff431f9a062605235ca67e): perf score=1.000000
I20260812 06:18:20.948791 31553 maintenance_manager.cc:643] P 70f5518003144bec918e906a727c8e72: MajorDeltaCompactionOp(de648fb27aff431f9a062605235ca67e) complete. Timing: real 0.178s	user 0.128s	sys 0.050s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774689,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":246,"lbm_read_time_us":12063,"lbm_reads_lt_1ms":572,"lbm_write_time_us":28919,"lbm_writes_lt_1ms":543,"mutex_wait_us":20,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":4608,"update_count":2500}
I20260812 06:18:20.949597 31622 maintenance_manager.cc:419] P 70f5518003144bec918e906a727c8e72: Scheduling FlushDeltaMemStoresOp(de648fb27aff431f9a062605235ca67e): perf score=14.095187
I20260812 06:18:20.999348 31553 maintenance_manager.cc:643] P 70f5518003144bec918e906a727c8e72: FlushDeltaMemStoresOp(de648fb27aff431f9a062605235ca67e) complete. Timing: real 0.050s	user 0.024s	sys 0.021s Metrics: {"bytes_written":16409900,"delete_count":0,"lbm_write_time_us":21633,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:18:20.999946 31622 maintenance_manager.cc:419] P 70f5518003144bec918e906a727c8e72: Scheduling FlushDeltaMemStoresOp(de648fb27aff431f9a062605235ca67e): perf score=2.188937
I20260812 06:18:21.011447 31553 maintenance_manager.cc:643] P 70f5518003144bec918e906a727c8e72: FlushDeltaMemStoresOp(de648fb27aff431f9a062605235ca67e) complete. Timing: real 0.011s	user 0.005s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4089,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:21.011984 31622 maintenance_manager.cc:419] P 70f5518003144bec918e906a727c8e72: Scheduling MajorDeltaCompactionOp(de648fb27aff431f9a062605235ca67e): perf score=1.000000
I20260812 06:18:21.211335 31553 maintenance_manager.cc:643] P 70f5518003144bec918e906a727c8e72: MajorDeltaCompactionOp(de648fb27aff431f9a062605235ca67e) complete. Timing: real 0.199s	user 0.110s	sys 0.081s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774687,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":539,"lbm_read_time_us":10556,"lbm_reads_lt_1ms":572,"lbm_write_time_us":31256,"lbm_writes_lt_1ms":543,"mutex_wait_us":21,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":16256,"update_count":2500}
I20260812 06:18:21.212146 31622 maintenance_manager.cc:419] P 70f5518003144bec918e906a727c8e72: Scheduling FlushDeltaMemStoresOp(de648fb27aff431f9a062605235ca67e): perf score=14.095187
I20260812 06:18:21.257802 31553 maintenance_manager.cc:643] P 70f5518003144bec918e906a727c8e72: FlushDeltaMemStoresOp(de648fb27aff431f9a062605235ca67e) complete. Timing: real 0.045s	user 0.027s	sys 0.016s Metrics: {"bytes_written":16409904,"delete_count":0,"lbm_write_time_us":19493,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:18:21.258332 31622 maintenance_manager.cc:419] P 70f5518003144bec918e906a727c8e72: Scheduling FlushDeltaMemStoresOp(de648fb27aff431f9a062605235ca67e): perf score=2.188937
I20260812 06:18:21.269326 31553 maintenance_manager.cc:643] P 70f5518003144bec918e906a727c8e72: FlushDeltaMemStoresOp(de648fb27aff431f9a062605235ca67e) complete. Timing: real 0.011s	user 0.005s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4061,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:21.269810 31622 maintenance_manager.cc:419] P 70f5518003144bec918e906a727c8e72: Scheduling FlushMRSOp(de648fb27aff431f9a062605235ca67e): perf score=1.000000
I20260812 06:18:21.302980 31553 maintenance_manager.cc:643] P 70f5518003144bec918e906a727c8e72: FlushMRSOp(de648fb27aff431f9a062605235ca67e) complete. Timing: real 0.033s	user 0.031s	sys 0.000s Metrics: {"bytes_written":1316417,"cfile_init":1,"dirs.queue_time_us":78,"dirs.run_cpu_time_us":274,"dirs.run_wall_time_us":1415,"drs_written":1,"lbm_read_time_us":48,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1687,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":32}
I20260812 06:18:21.303773 31622 maintenance_manager.cc:419] P 70f5518003144bec918e906a727c8e72: Scheduling LogGCOp(de648fb27aff431f9a062605235ca67e): free 133024644 bytes of WAL
I20260812 06:18:21.304068 31553 log_reader.cc:385] T de648fb27aff431f9a062605235ca67e: removed 13 log segments from log reader
I20260812 06:18:21.304143 31553 log.cc:1079] T de648fb27aff431f9a062605235ca67e P 70f5518003144bec918e906a727c8e72: Deleting log segment in path: /tmp/dist-test-taskyLMvui/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515491061751-31228-0/minicluster-data/ts-0-root/wals/de648fb27aff431f9a062605235ca67e/wal-000000027 (ops 129-133)
I20260812 06:18:21.304196 31553 log.cc:1079] T de648fb27aff431f9a062605235ca67e P 70f5518003144bec918e906a727c8e72: Deleting log segment in path: /tmp/dist-test-taskyLMvui/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515491061751-31228-0/minicluster-data/ts-0-root/wals/de648fb27aff431f9a062605235ca67e/wal-000000028 (ops 134-138)
I20260812 06:18:21.304257 31553 log.cc:1079] T de648fb27aff431f9a062605235ca67e P 70f5518003144bec918e906a727c8e72: Deleting log segment in path: /tmp/dist-test-taskyLMvui/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515491061751-31228-0/minicluster-data/ts-0-root/wals/de648fb27aff431f9a062605235ca67e/wal-000000029 (ops 139-143)
I20260812 06:18:21.304301 31553 log.cc:1079] T de648fb27aff431f9a062605235ca67e P 70f5518003144bec918e906a727c8e72: Deleting log segment in path: /tmp/dist-test-taskyLMvui/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515491061751-31228-0/minicluster-data/ts-0-root/wals/de648fb27aff431f9a062605235ca67e/wal-000000030 (ops 144-148)
I20260812 06:18:21.304342 31553 log.cc:1079] T de648fb27aff431f9a062605235ca67e P 70f5518003144bec918e906a727c8e72: Deleting log segment in path: /tmp/dist-test-taskyLMvui/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515491061751-31228-0/minicluster-data/ts-0-root/wals/de648fb27aff431f9a062605235ca67e/wal-000000031 (ops 149-153)
I20260812 06:18:21.304381 31553 log.cc:1079] T de648fb27aff431f9a062605235ca67e P 70f5518003144bec918e906a727c8e72: Deleting log segment in path: /tmp/dist-test-taskyLMvui/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515491061751-31228-0/minicluster-data/ts-0-root/wals/de648fb27aff431f9a062605235ca67e/wal-000000032 (ops 154-158)
I20260812 06:18:21.304421 31553 log.cc:1079] T de648fb27aff431f9a062605235ca67e P 70f5518003144bec918e906a727c8e72: Deleting log segment in path: /tmp/dist-test-taskyLMvui/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515491061751-31228-0/minicluster-data/ts-0-root/wals/de648fb27aff431f9a062605235ca67e/wal-000000033 (ops 159-163)
I20260812 06:18:21.304461 31553 log.cc:1079] T de648fb27aff431f9a062605235ca67e P 70f5518003144bec918e906a727c8e72: Deleting log segment in path: /tmp/dist-test-taskyLMvui/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515491061751-31228-0/minicluster-data/ts-0-root/wals/de648fb27aff431f9a062605235ca67e/wal-000000034 (ops 164-168)
I20260812 06:18:21.304499 31553 log.cc:1079] T de648fb27aff431f9a062605235ca67e P 70f5518003144bec918e906a727c8e72: Deleting log segment in path: /tmp/dist-test-taskyLMvui/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515491061751-31228-0/minicluster-data/ts-0-root/wals/de648fb27aff431f9a062605235ca67e/wal-000000035 (ops 169-173)
I20260812 06:18:21.304538 31553 log.cc:1079] T de648fb27aff431f9a062605235ca67e P 70f5518003144bec918e906a727c8e72: Deleting log segment in path: /tmp/dist-test-taskyLMvui/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515491061751-31228-0/minicluster-data/ts-0-root/wals/de648fb27aff431f9a062605235ca67e/wal-000000036 (ops 174-178)
I20260812 06:18:21.304577 31553 log.cc:1079] T de648fb27aff431f9a062605235ca67e P 70f5518003144bec918e906a727c8e72: Deleting log segment in path: /tmp/dist-test-taskyLMvui/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515491061751-31228-0/minicluster-data/ts-0-root/wals/de648fb27aff431f9a062605235ca67e/wal-000000037 (ops 179-182)
I20260812 06:18:21.304617 31553 log.cc:1079] T de648fb27aff431f9a062605235ca67e P 70f5518003144bec918e906a727c8e72: Deleting log segment in path: /tmp/dist-test-taskyLMvui/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515491061751-31228-0/minicluster-data/ts-0-root/wals/de648fb27aff431f9a062605235ca67e/wal-000000038 (ops 183-187)
I20260812 06:18:21.304656 31553 log.cc:1079] T de648fb27aff431f9a062605235ca67e P 70f5518003144bec918e906a727c8e72: Deleting log segment in path: /tmp/dist-test-taskyLMvui/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515491061751-31228-0/minicluster-data/ts-0-root/wals/de648fb27aff431f9a062605235ca67e/wal-000000039 (ops 188-192)
I20260812 06:18:21.333175 31553 maintenance_manager.cc:643] P 70f5518003144bec918e906a727c8e72: LogGCOp(de648fb27aff431f9a062605235ca67e) complete. Timing: real 0.029s	user 0.008s	sys 0.020s Metrics: {}
I20260812 06:18:21.333695 31622 maintenance_manager.cc:419] P 70f5518003144bec918e906a727c8e72: Scheduling FlushDeltaMemStoresOp(de648fb27aff431f9a062605235ca67e): perf score=3.181125
I20260812 06:18:21.355593 31553 maintenance_manager.cc:643] P 70f5518003144bec918e906a727c8e72: FlushDeltaMemStoresOp(de648fb27aff431f9a062605235ca67e) complete. Timing: real 0.022s	user 0.012s	sys 0.004s Metrics: {"bytes_written":4512902,"delete_count":0,"lbm_write_time_us":7437,"lbm_writes_lt_1ms":113,"reinsert_count":0,"update_count":550}
I20260812 06:18:21.356112 31622 maintenance_manager.cc:419] P 70f5518003144bec918e906a727c8e72: Scheduling FlushDeltaMemStoresOp(de648fb27aff431f9a062605235ca67e): perf score=2.188937
I20260812 06:18:21.369475 31553 maintenance_manager.cc:643] P 70f5518003144bec918e906a727c8e72: FlushDeltaMemStoresOp(de648fb27aff431f9a062605235ca67e) complete. Timing: real 0.013s	user 0.007s	sys 0.005s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":5263,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:18:21.370003 31622 maintenance_manager.cc:419] P 70f5518003144bec918e906a727c8e72: Scheduling MajorDeltaCompactionOp(de648fb27aff431f9a062605235ca67e): perf score=1.000000
I20260812 06:18:21.454561 31228 heavy-update-compaction-itest.cc:229] Time spent updating: real 4.837s	user 1.828s	sys 0.173s
I20260812 06:18:21.546900 31228 heavy-update-compaction-itest.cc:265] Time spent scanning: real 0.092s	user 0.001s	sys 0.000s
I20260812 06:18:21.547430 31228 tablet_server.cc:179] TabletServer@127.30.127.1:0 shutting down...
I20260812 06:18:21.584195 31553 maintenance_manager.cc:643] P 70f5518003144bec918e906a727c8e72: MajorDeltaCompactionOp(de648fb27aff431f9a062605235ca67e) complete. Timing: real 0.214s	user 0.134s	sys 0.079s Metrics: {"cfile_cache_miss":734,"cfile_cache_miss_bytes":32979742,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":618,"lbm_read_time_us":14782,"lbm_reads_lt_1ms":770,"lbm_write_time_us":33970,"lbm_writes_lt_1ms":743,"mutex_wait_us":2,"peak_mem_usage":87969044,"reinsert_count":0,"spinlock_wait_cycles":3456,"thread_start_us":84,"threads_started":1,"update_count":3500}
I20260812 06:18:21.584784 31228 ts_tablet_manager.cc:1507] Shutting down tablet manager...
I20260812 06:18:21.585131 31228 tablet_replica.cc:333] T de648fb27aff431f9a062605235ca67e P 70f5518003144bec918e906a727c8e72: stopping tablet replica
I20260812 06:18:21.585310 31228 raft_consensus.cc:2243] T de648fb27aff431f9a062605235ca67e P 70f5518003144bec918e906a727c8e72 [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:18:21.585498 31228 raft_consensus.cc:2272] T de648fb27aff431f9a062605235ca67e P 70f5518003144bec918e906a727c8e72 [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:18:21.590889 31228 tablet_server.cc:196] TabletServer@127.30.127.1:0 shutdown complete.
I20260812 06:18:21.641798 31228 master.cc:562] Master@127.30.127.62:43203 shutting down...
I20260812 06:18:21.645622 31228 raft_consensus.cc:2243] T 00000000000000000000000000000000 P 3c2f4c01c3cb4756a4e5ee25e8a3fb7d [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:18:21.645820 31228 raft_consensus.cc:2272] T 00000000000000000000000000000000 P 3c2f4c01c3cb4756a4e5ee25e8a3fb7d [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:18:21.645915 31228 tablet_replica.cc:333] T 00000000000000000000000000000000 P 3c2f4c01c3cb4756a4e5ee25e8a3fb7d: stopping tablet replica
I20260812 06:18:21.658161 31228 master.cc:584] Master@127.30.127.62:43203 shutdown complete.
[       OK ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/1 (5330 ms)
[----------] 2 tests from EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy (10670 ms total)

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