[==========] Running 2 tests from 1 test suite.
[----------] Global test environment set-up.
[----------] 2 tests from EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy
[ RUN      ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/0
WARNING: Logging before InitGoogleLogging() is written to STDERR
I20260812 06:19:23.736191 31713 internal_mini_cluster.cc:156] Creating distributed mini masters. Addrs: 127.30.248.126:41555
I20260812 06:19:23.737203 31713 env_posix.cc:2285] Not raising this process' open files per process limit of 1048576; it is already as high as it can go
I20260812 06:19:23.737782 31713 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:19:23.744215 31722 instance_detector.cc:116] could not retrieve AWS instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:19:23.744223 31725 instance_detector.cc:116] could not retrieve OpenStack instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:19:23.744263 31713 server_base.cc:1061] running on GCE node
W20260812 06:19:23.744509 31723 instance_detector.cc:116] could not retrieve Azure instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:19:23.744978 31713 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:19:23.745095 31713 system_unsync_time.cc:38] NTP support is disabled. Clock error bounds will not be accurate. This configuration is not suitable for distributed clusters.
I20260812 06:19:23.745138 31713 hybrid_clock.cc:648] HybridClock initialized: now 1786515563745135 us; error 0 us; skew 500 ppm
I20260812 06:19:23.746767 31713 webserver.cc:533] Webserver started at http://127.30.248.126:46645/ using document root <none> and password file <none>
I20260812 06:19:23.747283 31713 fs_manager.cc:362] Metadata directory not provided
I20260812 06:19:23.747366 31713 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:19:23.747597 31713 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:19:23.749213 31713 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskxHIKYo/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515563725526-31713-0/minicluster-data/master-0-root/instance:
uuid: "35494638c05e4bba86f27cefed98d86b"
format_stamp: "Formatted at 2026-08-12 06:19:23 on dist-test-slave-gmjp"
I20260812 06:19:23.752517 31713 fs_manager.cc:696] Time spent creating directory manager: real 0.003s	user 0.003s	sys 0.000s
I20260812 06:19:23.754488 31731 log_block_manager.cc:4127] Time spent loading block containers with low live blocks: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:19:23.755411 31713 fs_manager.cc:730] Time spent opening block manager: real 0.002s	user 0.002s	sys 0.000s
I20260812 06:19:23.755553 31713 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskxHIKYo/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515563725526-31713-0/minicluster-data/master-0-root
uuid: "35494638c05e4bba86f27cefed98d86b"
format_stamp: "Formatted at 2026-08-12 06:19:23 on dist-test-slave-gmjp"
I20260812 06:19:23.755650 31713 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskxHIKYo/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515563725526-31713-0/minicluster-data/master-0-root
metadata directory: /tmp/dist-test-taskxHIKYo/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515563725526-31713-0/minicluster-data/master-0-root
1 data directories: /tmp/dist-test-taskxHIKYo/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515563725526-31713-0/minicluster-data/master-0-root/data
Total live blocks: 0
Total live bytes: 0
Total live bytes (after alignment): 0
Total number of LBM containers: 0 (0 full)
Did not check for missing blocks
Did not check for orphaned blocks
Total full LBM containers with extra space: 0 (0 repaired)
Total full LBM container extra space in bytes: 0 (0 repaired)
Total incomplete LBM containers: 0 (0 repaired)
Total LBM partial records: 0 (0 repaired)
Total corrupted LBM metadata records in RocksDB: 0 (0 repaired)
I20260812 06:19:23.793125 31713 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:19:23.793828 31713 env_posix.cc:2285] Not raising this process' running threads per effective uid limit of 18446744073709551615; it is already as high as it can go
I20260812 06:19:23.794028 31713 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:19:23.801786 31713 rpc_server.cc:307] RPC server started. Bound to: 127.30.248.126:41555
I20260812 06:19:23.801784 31822 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.30.248.126:41555 every 8 connection(s)
I20260812 06:19:23.803997 31823 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet 00000000000000000000000000000000. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:19:23.809430 31823 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P 35494638c05e4bba86f27cefed98d86b: Bootstrap starting.
I20260812 06:19:23.811717 31823 tablet_bootstrap.cc:654] T 00000000000000000000000000000000 P 35494638c05e4bba86f27cefed98d86b: Neither blocks nor log segments found. Creating new log.
I20260812 06:19:23.812613 31823 log.cc:826] T 00000000000000000000000000000000 P 35494638c05e4bba86f27cefed98d86b: Log is configured to *not* fsync() on all Append() calls
I20260812 06:19:23.814240 31823 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P 35494638c05e4bba86f27cefed98d86b: No bootstrap required, opened a new log
I20260812 06:19:23.817034 31823 raft_consensus.cc:359] T 00000000000000000000000000000000 P 35494638c05e4bba86f27cefed98d86b [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "35494638c05e4bba86f27cefed98d86b" member_type: VOTER }
I20260812 06:19:23.817191 31823 raft_consensus.cc:385] T 00000000000000000000000000000000 P 35494638c05e4bba86f27cefed98d86b [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:19:23.817292 31823 raft_consensus.cc:740] T 00000000000000000000000000000000 P 35494638c05e4bba86f27cefed98d86b [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: 35494638c05e4bba86f27cefed98d86b, State: Initialized, Role: FOLLOWER
I20260812 06:19:23.817929 31823 consensus_queue.cc:260] T 00000000000000000000000000000000 P 35494638c05e4bba86f27cefed98d86b [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: "35494638c05e4bba86f27cefed98d86b" member_type: VOTER }
I20260812 06:19:23.818102 31823 raft_consensus.cc:399] T 00000000000000000000000000000000 P 35494638c05e4bba86f27cefed98d86b [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:19:23.818171 31823 raft_consensus.cc:493] T 00000000000000000000000000000000 P 35494638c05e4bba86f27cefed98d86b [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:19:23.818322 31823 raft_consensus.cc:3060] T 00000000000000000000000000000000 P 35494638c05e4bba86f27cefed98d86b [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:19:23.819111 31823 raft_consensus.cc:515] T 00000000000000000000000000000000 P 35494638c05e4bba86f27cefed98d86b [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "35494638c05e4bba86f27cefed98d86b" member_type: VOTER }
I20260812 06:19:23.819538 31823 leader_election.cc:304] T 00000000000000000000000000000000 P 35494638c05e4bba86f27cefed98d86b [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: 35494638c05e4bba86f27cefed98d86b; no voters: 
I20260812 06:19:23.819847 31823 leader_election.cc:290] T 00000000000000000000000000000000 P 35494638c05e4bba86f27cefed98d86b [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:19:23.819991 31829 raft_consensus.cc:2804] T 00000000000000000000000000000000 P 35494638c05e4bba86f27cefed98d86b [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:19:23.820271 31829 raft_consensus.cc:697] T 00000000000000000000000000000000 P 35494638c05e4bba86f27cefed98d86b [term 1 LEADER]: Becoming Leader. State: Replica: 35494638c05e4bba86f27cefed98d86b, State: Running, Role: LEADER
I20260812 06:19:23.820703 31829 consensus_queue.cc:237] T 00000000000000000000000000000000 P 35494638c05e4bba86f27cefed98d86b [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: "35494638c05e4bba86f27cefed98d86b" member_type: VOTER }
I20260812 06:19:23.820871 31823 sys_catalog.cc:565] T 00000000000000000000000000000000 P 35494638c05e4bba86f27cefed98d86b [sys.catalog]: configured and running, proceeding with master startup.
I20260812 06:19:23.822639 31831 sys_catalog.cc:455] T 00000000000000000000000000000000 P 35494638c05e4bba86f27cefed98d86b [sys.catalog]: SysCatalogTable state changed. Reason: New leader 35494638c05e4bba86f27cefed98d86b. Latest consensus state: current_term: 1 leader_uuid: "35494638c05e4bba86f27cefed98d86b" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "35494638c05e4bba86f27cefed98d86b" member_type: VOTER } }
I20260812 06:19:23.822681 31830 sys_catalog.cc:455] T 00000000000000000000000000000000 P 35494638c05e4bba86f27cefed98d86b [sys.catalog]: SysCatalogTable state changed. Reason: RaftConsensus started. Latest consensus state: current_term: 1 leader_uuid: "35494638c05e4bba86f27cefed98d86b" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "35494638c05e4bba86f27cefed98d86b" member_type: VOTER } }
I20260812 06:19:23.822746 31831 sys_catalog.cc:458] T 00000000000000000000000000000000 P 35494638c05e4bba86f27cefed98d86b [sys.catalog]: This master's current role is: LEADER
I20260812 06:19:23.822796 31830 sys_catalog.cc:458] T 00000000000000000000000000000000 P 35494638c05e4bba86f27cefed98d86b [sys.catalog]: This master's current role is: LEADER
I20260812 06:19:23.823146 31854 catalog_manager.cc:1511] Loading table and tablet metadata into memory...
I20260812 06:19:23.823179 31713 internal_mini_cluster.cc:184] Waiting to initialize catalog manager on master 0
I20260812 06:19:23.825506 31854 catalog_manager.cc:1520] Initializing Kudu cluster ID...
I20260812 06:19:23.829907 31854 catalog_manager.cc:1383] Generated new cluster ID: aa7cc3119d9341cc8b8899782f540fcb
I20260812 06:19:23.829982 31854 catalog_manager.cc:1531] Initializing Kudu internal certificate authority...
I20260812 06:19:23.842365 31854 catalog_manager.cc:1406] Generated new certificate authority record
I20260812 06:19:23.843204 31854 catalog_manager.cc:1540] Loading token signing keys...
I20260812 06:19:23.855909 31854 catalog_manager.cc:6092] T 00000000000000000000000000000000 P 35494638c05e4bba86f27cefed98d86b: Generated new TSK 0
I20260812 06:19:23.856714 31854 catalog_manager.cc:1550] Initializing in-progress tserver states...
I20260812 06:19:23.888401 31713 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:19:23.891381 31863 instance_detector.cc:116] could not retrieve AWS instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:19:23.891474 31864 instance_detector.cc:116] could not retrieve Azure instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:19:23.891578 31713 server_base.cc:1061] running on GCE node
W20260812 06:19:23.891641 31872 instance_detector.cc:116] could not retrieve OpenStack instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:19:23.891961 31713 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:19:23.892007 31713 system_unsync_time.cc:38] NTP support is disabled. Clock error bounds will not be accurate. This configuration is not suitable for distributed clusters.
I20260812 06:19:23.892023 31713 hybrid_clock.cc:648] HybridClock initialized: now 1786515563892023 us; error 0 us; skew 500 ppm
I20260812 06:19:23.892980 31713 webserver.cc:533] Webserver started at http://127.30.248.65:36843/ using document root <none> and password file <none>
I20260812 06:19:23.893162 31713 fs_manager.cc:362] Metadata directory not provided
I20260812 06:19:23.893216 31713 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:19:23.893312 31713 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:19:23.893712 31713 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskxHIKYo/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515563725526-31713-0/minicluster-data/ts-0-root/instance:
uuid: "7f5b3a28cb1e413d9865c25ed19ec248"
format_stamp: "Formatted at 2026-08-12 06:19:23 on dist-test-slave-gmjp"
I20260812 06:19:23.895200 31713 fs_manager.cc:696] Time spent creating directory manager: real 0.001s	user 0.002s	sys 0.000s
I20260812 06:19:23.896196 31881 log_block_manager.cc:4127] Time spent loading block containers with low live blocks: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:19:23.896478 31713 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.001s	sys 0.000s
I20260812 06:19:23.896559 31713 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskxHIKYo/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515563725526-31713-0/minicluster-data/ts-0-root
uuid: "7f5b3a28cb1e413d9865c25ed19ec248"
format_stamp: "Formatted at 2026-08-12 06:19:23 on dist-test-slave-gmjp"
I20260812 06:19:23.896625 31713 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskxHIKYo/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515563725526-31713-0/minicluster-data/ts-0-root
metadata directory: /tmp/dist-test-taskxHIKYo/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515563725526-31713-0/minicluster-data/ts-0-root
1 data directories: /tmp/dist-test-taskxHIKYo/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515563725526-31713-0/minicluster-data/ts-0-root/data
Total live blocks: 0
Total live bytes: 0
Total live bytes (after alignment): 0
Total number of LBM containers: 0 (0 full)
Did not check for missing blocks
Did not check for orphaned blocks
Total full LBM containers with extra space: 0 (0 repaired)
Total full LBM container extra space in bytes: 0 (0 repaired)
Total incomplete LBM containers: 0 (0 repaired)
Total LBM partial records: 0 (0 repaired)
Total corrupted LBM metadata records in RocksDB: 0 (0 repaired)
I20260812 06:19:23.909755 31713 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:19:23.910221 31713 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:19:23.910761 31713 txn_system_client.cc:432] TxnSystemClient initialization is disabled...
I20260812 06:19:23.911806 31713 ts_tablet_manager.cc:585] Loaded tablet metadata (0 total tablets, 0 live tablets)
I20260812 06:19:23.911873 31713 ts_tablet_manager.cc:531] Time spent load tablet metadata: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:19:23.911931 31713 ts_tablet_manager.cc:616] Registered 0 tablets
I20260812 06:19:23.911972 31713 ts_tablet_manager.cc:595] Time spent register tablets: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:19:23.918705 31713 rpc_server.cc:307] RPC server started. Bound to: 127.30.248.65:38831
I20260812 06:19:23.918726 31989 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.30.248.65:38831 every 8 connection(s)
I20260812 06:19:23.928323 31992 heartbeater.cc:344] Connected to a master server at 127.30.248.126:41555
I20260812 06:19:23.928558 31992 heartbeater.cc:461] Registering TS with master...
I20260812 06:19:23.929020 31992 heartbeater.cc:507] Master 127.30.248.126:41555 requested a full tablet report, sending...
I20260812 06:19:23.930446 31767 ts_manager.cc:194] Registered new tserver with Master: 7f5b3a28cb1e413d9865c25ed19ec248 (127.30.248.65:38831)
I20260812 06:19:23.930547 31713 internal_mini_cluster.cc:371] 1 TS(s) registered with all masters after 0.01119758s
I20260812 06:19:23.931593 31767 master_service.cc:502] Signed X509 certificate for tserver {username='slave'} at 127.0.0.1:49058
I20260812 06:19:23.939760 31767 catalog_manager.cc:2283] Servicing CreateTable request from {username='slave'} at 127.0.0.1:49068:
name: "heavy-update-compaction-test"
schema {
  columns {
    name: "key"
    type: INT64
    is_key: true
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_a"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_b"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_c"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_d"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_e"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
}
num_replicas: 1
split_rows_range_bounds {
}
partition_schema {
  range_schema {
  }
}
I20260812 06:19:23.954046 31935 tablet_service.cc:1511] Processing CreateTablet for tablet 6d45f86d36f5456aa24f014a1997e1fd (DEFAULT_TABLE table=heavy-update-compaction-test [id=b1a9f2d9bef14b8880a272b5bae0fd09]), partition=
I20260812 06:19:23.954519 31935 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet 6d45f86d36f5456aa24f014a1997e1fd. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:19:23.957393 32010 tablet_bootstrap.cc:492] T 6d45f86d36f5456aa24f014a1997e1fd P 7f5b3a28cb1e413d9865c25ed19ec248: Bootstrap starting.
I20260812 06:19:23.958259 32010 tablet_bootstrap.cc:654] T 6d45f86d36f5456aa24f014a1997e1fd P 7f5b3a28cb1e413d9865c25ed19ec248: Neither blocks nor log segments found. Creating new log.
I20260812 06:19:23.959478 32010 tablet_bootstrap.cc:492] T 6d45f86d36f5456aa24f014a1997e1fd P 7f5b3a28cb1e413d9865c25ed19ec248: No bootstrap required, opened a new log
I20260812 06:19:23.959596 32010 ts_tablet_manager.cc:1403] T 6d45f86d36f5456aa24f014a1997e1fd P 7f5b3a28cb1e413d9865c25ed19ec248: Time spent bootstrapping tablet: real 0.002s	user 0.002s	sys 0.000s
I20260812 06:19:23.960400 32010 raft_consensus.cc:359] T 6d45f86d36f5456aa24f014a1997e1fd P 7f5b3a28cb1e413d9865c25ed19ec248 [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "7f5b3a28cb1e413d9865c25ed19ec248" member_type: VOTER last_known_addr { host: "127.30.248.65" port: 38831 } }
I20260812 06:19:23.960510 32010 raft_consensus.cc:385] T 6d45f86d36f5456aa24f014a1997e1fd P 7f5b3a28cb1e413d9865c25ed19ec248 [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:19:23.960536 32010 raft_consensus.cc:740] T 6d45f86d36f5456aa24f014a1997e1fd P 7f5b3a28cb1e413d9865c25ed19ec248 [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: 7f5b3a28cb1e413d9865c25ed19ec248, State: Initialized, Role: FOLLOWER
I20260812 06:19:23.960701 32010 consensus_queue.cc:260] T 6d45f86d36f5456aa24f014a1997e1fd P 7f5b3a28cb1e413d9865c25ed19ec248 [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: "7f5b3a28cb1e413d9865c25ed19ec248" member_type: VOTER last_known_addr { host: "127.30.248.65" port: 38831 } }
I20260812 06:19:23.960783 32010 raft_consensus.cc:399] T 6d45f86d36f5456aa24f014a1997e1fd P 7f5b3a28cb1e413d9865c25ed19ec248 [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:19:23.960829 32010 raft_consensus.cc:493] T 6d45f86d36f5456aa24f014a1997e1fd P 7f5b3a28cb1e413d9865c25ed19ec248 [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:19:23.960884 32010 raft_consensus.cc:3060] T 6d45f86d36f5456aa24f014a1997e1fd P 7f5b3a28cb1e413d9865c25ed19ec248 [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:19:23.961608 32010 raft_consensus.cc:515] T 6d45f86d36f5456aa24f014a1997e1fd P 7f5b3a28cb1e413d9865c25ed19ec248 [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "7f5b3a28cb1e413d9865c25ed19ec248" member_type: VOTER last_known_addr { host: "127.30.248.65" port: 38831 } }
I20260812 06:19:23.961755 32010 leader_election.cc:304] T 6d45f86d36f5456aa24f014a1997e1fd P 7f5b3a28cb1e413d9865c25ed19ec248 [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: 7f5b3a28cb1e413d9865c25ed19ec248; no voters: 
I20260812 06:19:23.961989 32010 leader_election.cc:290] T 6d45f86d36f5456aa24f014a1997e1fd P 7f5b3a28cb1e413d9865c25ed19ec248 [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:19:23.962085 32012 raft_consensus.cc:2804] T 6d45f86d36f5456aa24f014a1997e1fd P 7f5b3a28cb1e413d9865c25ed19ec248 [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:19:23.962292 32012 raft_consensus.cc:697] T 6d45f86d36f5456aa24f014a1997e1fd P 7f5b3a28cb1e413d9865c25ed19ec248 [term 1 LEADER]: Becoming Leader. State: Replica: 7f5b3a28cb1e413d9865c25ed19ec248, State: Running, Role: LEADER
I20260812 06:19:23.962407 32010 ts_tablet_manager.cc:1434] T 6d45f86d36f5456aa24f014a1997e1fd P 7f5b3a28cb1e413d9865c25ed19ec248: Time spent starting tablet: real 0.003s	user 0.003s	sys 0.000s
I20260812 06:19:23.962499 32012 consensus_queue.cc:237] T 6d45f86d36f5456aa24f014a1997e1fd P 7f5b3a28cb1e413d9865c25ed19ec248 [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: "7f5b3a28cb1e413d9865c25ed19ec248" member_type: VOTER last_known_addr { host: "127.30.248.65" port: 38831 } }
I20260812 06:19:23.962713 31992 heartbeater.cc:499] Master 127.30.248.126:41555 was elected leader, sending a full tablet report...
I20260812 06:19:23.965246 31767 catalog_manager.cc:5719] T 6d45f86d36f5456aa24f014a1997e1fd P 7f5b3a28cb1e413d9865c25ed19ec248 reported cstate change: term changed from 0 to 1, leader changed from <none> to 7f5b3a28cb1e413d9865c25ed19ec248 (127.30.248.65). New cstate: current_term: 1 leader_uuid: "7f5b3a28cb1e413d9865c25ed19ec248" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "7f5b3a28cb1e413d9865c25ed19ec248" member_type: VOTER last_known_addr { host: "127.30.248.65" port: 38831 } health_report { overall_health: HEALTHY } } }
I20260812 06:19:24.024928 31713 heavy-update-compaction-itest.cc:215] Time spent inserting: real 0.054s	user 0.015s	sys 0.012s
I20260812 06:19:24.169782 31993 maintenance_manager.cc:419] P 7f5b3a28cb1e413d9865c25ed19ec248: Scheduling FlushMRSOp(6d45f86d36f5456aa24f014a1997e1fd): perf score=19.054940
I20260812 06:19:24.362061 31889 maintenance_manager.cc:643] P 7f5b3a28cb1e413d9865c25ed19ec248: FlushMRSOp(6d45f86d36f5456aa24f014a1997e1fd) complete. Timing: real 0.192s	user 0.135s	sys 0.048s Metrics: {"bytes_written":16409901,"cfile_init":1,"compiler_manager_pool.queue_time_us":182,"delete_count":0,"dirs.queue_time_us":85,"dirs.run_cpu_time_us":181,"dirs.run_wall_time_us":765,"drs_written":1,"lbm_read_time_us":178,"lbm_reads_lt_1ms":4,"lbm_write_time_us":45443,"lbm_writes_lt_1ms":857,"peak_mem_usage":0,"reinsert_count":0,"rows_written":104,"thread_start_us":112,"threads_started":1,"update_count":2000}
I20260812 06:19:24.363283 31993 maintenance_manager.cc:419] P 7f5b3a28cb1e413d9865c25ed19ec248: Scheduling LogGCOp(6d45f86d36f5456aa24f014a1997e1fd): free 20743880 bytes of WAL
I20260812 06:19:24.363636 31889 log_reader.cc:385] T 6d45f86d36f5456aa24f014a1997e1fd: removed 2 log segments from log reader
I20260812 06:19:24.363713 31889 log.cc:1079] T 6d45f86d36f5456aa24f014a1997e1fd P 7f5b3a28cb1e413d9865c25ed19ec248: Deleting log segment in path: /tmp/dist-test-taskxHIKYo/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515563725526-31713-0/minicluster-data/ts-0-root/wals/6d45f86d36f5456aa24f014a1997e1fd/wal-000000001 (ops 1-6)
I20260812 06:19:24.363823 31889 log.cc:1079] T 6d45f86d36f5456aa24f014a1997e1fd P 7f5b3a28cb1e413d9865c25ed19ec248: Deleting log segment in path: /tmp/dist-test-taskxHIKYo/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515563725526-31713-0/minicluster-data/ts-0-root/wals/6d45f86d36f5456aa24f014a1997e1fd/wal-000000002 (ops 7-11)
I20260812 06:19:24.369572 31889 maintenance_manager.cc:643] P 7f5b3a28cb1e413d9865c25ed19ec248: LogGCOp(6d45f86d36f5456aa24f014a1997e1fd) complete. Timing: real 0.006s	user 0.000s	sys 0.005s Metrics: {}
I20260812 06:19:24.369925 31993 maintenance_manager.cc:419] P 7f5b3a28cb1e413d9865c25ed19ec248: Scheduling UndoDeltaBlockGCOp(6d45f86d36f5456aa24f014a1997e1fd): 16411393 bytes on disk
I20260812 06:19:24.370599 31889 maintenance_manager.cc:643] P 7f5b3a28cb1e413d9865c25ed19ec248: UndoDeltaBlockGCOp(6d45f86d36f5456aa24f014a1997e1fd) complete. Timing: real 0.001s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":77,"lbm_reads_lt_1ms":4}
I20260812 06:19:24.371021 31993 maintenance_manager.cc:419] P 7f5b3a28cb1e413d9865c25ed19ec248: Scheduling FlushDeltaMemStoresOp(6d45f86d36f5456aa24f014a1997e1fd): perf score=2.188937
I20260812 06:19:24.386354 31889 maintenance_manager.cc:643] P 7f5b3a28cb1e413d9865c25ed19ec248: FlushDeltaMemStoresOp(6d45f86d36f5456aa24f014a1997e1fd) complete. Timing: real 0.015s	user 0.009s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5952,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:24.386979 31993 maintenance_manager.cc:419] P 7f5b3a28cb1e413d9865c25ed19ec248: Scheduling MajorDeltaCompactionOp(6d45f86d36f5456aa24f014a1997e1fd): perf score=1.000000
I20260812 06:19:24.563048 31889 maintenance_manager.cc:643] P 7f5b3a28cb1e413d9865c25ed19ec248: MajorDeltaCompactionOp(6d45f86d36f5456aa24f014a1997e1fd) complete. Timing: real 0.176s	user 0.097s	sys 0.071s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774688,"cfile_init":7,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":819,"lbm_read_time_us":11778,"lbm_reads_lt_1ms":560,"lbm_write_time_us":26838,"lbm_writes_lt_1ms":543,"mutex_wait_us":1,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":1664,"thread_start_us":339,"threads_started":5,"update_count":2500}
I20260812 06:19:24.563612 31993 maintenance_manager.cc:419] P 7f5b3a28cb1e413d9865c25ed19ec248: Scheduling FlushDeltaMemStoresOp(6d45f86d36f5456aa24f014a1997e1fd): perf score=14.095187
I20260812 06:19:24.613255 31889 maintenance_manager.cc:643] P 7f5b3a28cb1e413d9865c25ed19ec248: FlushDeltaMemStoresOp(6d45f86d36f5456aa24f014a1997e1fd) complete. Timing: real 0.049s	user 0.037s	sys 0.012s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":23844,"lbm_writes_1-10_ms":3,"lbm_writes_lt_1ms":400,"reinsert_count":0,"update_count":2000}
I20260812 06:19:24.613821 31993 maintenance_manager.cc:419] P 7f5b3a28cb1e413d9865c25ed19ec248: Scheduling FlushDeltaMemStoresOp(6d45f86d36f5456aa24f014a1997e1fd): perf score=2.188937
I20260812 06:19:24.636606 31889 maintenance_manager.cc:643] P 7f5b3a28cb1e413d9865c25ed19ec248: FlushDeltaMemStoresOp(6d45f86d36f5456aa24f014a1997e1fd) complete. Timing: real 0.023s	user 0.013s	sys 0.003s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6433,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:24.637085 31993 maintenance_manager.cc:419] P 7f5b3a28cb1e413d9865c25ed19ec248: Scheduling MajorDeltaCompactionOp(6d45f86d36f5456aa24f014a1997e1fd): perf score=1.000000
I20260812 06:19:24.831771 31889 maintenance_manager.cc:643] P 7f5b3a28cb1e413d9865c25ed19ec248: MajorDeltaCompactionOp(6d45f86d36f5456aa24f014a1997e1fd) complete. Timing: real 0.195s	user 0.138s	sys 0.045s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774689,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":726,"lbm_read_time_us":12118,"lbm_reads_lt_1ms":568,"lbm_write_time_us":33119,"lbm_writes_lt_1ms":543,"mutex_wait_us":81,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":10496,"update_count":2500}
I20260812 06:19:24.832442 31993 maintenance_manager.cc:419] P 7f5b3a28cb1e413d9865c25ed19ec248: Scheduling FlushDeltaMemStoresOp(6d45f86d36f5456aa24f014a1997e1fd): perf score=14.095187
I20260812 06:19:24.881315 31889 maintenance_manager.cc:643] P 7f5b3a28cb1e413d9865c25ed19ec248: FlushDeltaMemStoresOp(6d45f86d36f5456aa24f014a1997e1fd) complete. Timing: real 0.049s	user 0.032s	sys 0.013s Metrics: {"bytes_written":16409904,"delete_count":0,"lbm_write_time_us":20154,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:24.881803 31993 maintenance_manager.cc:419] P 7f5b3a28cb1e413d9865c25ed19ec248: Scheduling FlushDeltaMemStoresOp(6d45f86d36f5456aa24f014a1997e1fd): perf score=2.188937
I20260812 06:19:24.893217 31889 maintenance_manager.cc:643] P 7f5b3a28cb1e413d9865c25ed19ec248: FlushDeltaMemStoresOp(6d45f86d36f5456aa24f014a1997e1fd) complete. Timing: real 0.011s	user 0.006s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3983,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:24.893900 31993 maintenance_manager.cc:419] P 7f5b3a28cb1e413d9865c25ed19ec248: Scheduling MajorDeltaCompactionOp(6d45f86d36f5456aa24f014a1997e1fd): perf score=1.000000
I20260812 06:19:25.058754 31889 maintenance_manager.cc:643] P 7f5b3a28cb1e413d9865c25ed19ec248: MajorDeltaCompactionOp(6d45f86d36f5456aa24f014a1997e1fd) complete. Timing: real 0.165s	user 0.107s	sys 0.053s 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":136,"lbm_read_time_us":9317,"lbm_reads_lt_1ms":572,"lbm_write_time_us":30034,"lbm_writes_lt_1ms":543,"mutex_wait_us":35,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":23680,"update_count":2500}
I20260812 06:19:25.059554 31993 maintenance_manager.cc:419] P 7f5b3a28cb1e413d9865c25ed19ec248: Scheduling FlushDeltaMemStoresOp(6d45f86d36f5456aa24f014a1997e1fd): perf score=11.118625
I20260812 06:19:25.100744 31889 maintenance_manager.cc:643] P 7f5b3a28cb1e413d9865c25ed19ec248: FlushDeltaMemStoresOp(6d45f86d36f5456aa24f014a1997e1fd) complete. Timing: real 0.041s	user 0.021s	sys 0.019s Metrics: {"bytes_written":12717735,"delete_count":0,"lbm_write_time_us":17576,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:19:25.101361 31993 maintenance_manager.cc:419] P 7f5b3a28cb1e413d9865c25ed19ec248: Scheduling FlushDeltaMemStoresOp(6d45f86d36f5456aa24f014a1997e1fd): perf score=2.188937
I20260812 06:19:25.124671 31889 maintenance_manager.cc:643] P 7f5b3a28cb1e413d9865c25ed19ec248: FlushDeltaMemStoresOp(6d45f86d36f5456aa24f014a1997e1fd) complete. Timing: real 0.023s	user 0.011s	sys 0.001s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":4837,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:19:25.125097 31993 maintenance_manager.cc:419] P 7f5b3a28cb1e413d9865c25ed19ec248: Scheduling FlushDeltaMemStoresOp(6d45f86d36f5456aa24f014a1997e1fd): perf score=2.188937
I20260812 06:19:25.135138 31889 maintenance_manager.cc:643] P 7f5b3a28cb1e413d9865c25ed19ec248: FlushDeltaMemStoresOp(6d45f86d36f5456aa24f014a1997e1fd) complete. Timing: real 0.010s	user 0.008s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3934,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:25.135560 31993 maintenance_manager.cc:419] P 7f5b3a28cb1e413d9865c25ed19ec248: Scheduling MajorDeltaCompactionOp(6d45f86d36f5456aa24f014a1997e1fd): perf score=1.000000
I20260812 06:19:25.292610 31889 maintenance_manager.cc:643] P 7f5b3a28cb1e413d9865c25ed19ec248: MajorDeltaCompactionOp(6d45f86d36f5456aa24f014a1997e1fd) complete. Timing: real 0.157s	user 0.109s	sys 0.039s Metrics: {"cfile_cache_miss":533,"cfile_cache_miss_bytes":24774799,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":192,"lbm_read_time_us":10627,"lbm_reads_lt_1ms":573,"lbm_write_time_us":30012,"lbm_writes_lt_1ms":543,"mutex_wait_us":45,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":9216,"update_count":2500}
I20260812 06:19:25.293200 31993 maintenance_manager.cc:419] P 7f5b3a28cb1e413d9865c25ed19ec248: Scheduling FlushDeltaMemStoresOp(6d45f86d36f5456aa24f014a1997e1fd): perf score=14.095187
I20260812 06:19:25.345512 31889 maintenance_manager.cc:643] P 7f5b3a28cb1e413d9865c25ed19ec248: FlushDeltaMemStoresOp(6d45f86d36f5456aa24f014a1997e1fd) complete. Timing: real 0.052s	user 0.036s	sys 0.008s Metrics: {"bytes_written":16409900,"delete_count":0,"lbm_write_time_us":20300,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:25.346060 31993 maintenance_manager.cc:419] P 7f5b3a28cb1e413d9865c25ed19ec248: Scheduling FlushDeltaMemStoresOp(6d45f86d36f5456aa24f014a1997e1fd): perf score=2.188937
I20260812 06:19:25.357352 31889 maintenance_manager.cc:643] P 7f5b3a28cb1e413d9865c25ed19ec248: FlushDeltaMemStoresOp(6d45f86d36f5456aa24f014a1997e1fd) complete. Timing: real 0.011s	user 0.000s	sys 0.009s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4053,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:25.357965 31993 maintenance_manager.cc:419] P 7f5b3a28cb1e413d9865c25ed19ec248: Scheduling MajorDeltaCompactionOp(6d45f86d36f5456aa24f014a1997e1fd): perf score=1.000000
I20260812 06:19:25.511339 31889 maintenance_manager.cc:643] P 7f5b3a28cb1e413d9865c25ed19ec248: MajorDeltaCompactionOp(6d45f86d36f5456aa24f014a1997e1fd) complete. Timing: real 0.153s	user 0.112s	sys 0.033s 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":174,"lbm_read_time_us":10113,"lbm_reads_lt_1ms":572,"lbm_write_time_us":30764,"lbm_writes_lt_1ms":543,"mutex_wait_us":45,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":7424,"update_count":2500}
I20260812 06:19:25.511904 31993 maintenance_manager.cc:419] P 7f5b3a28cb1e413d9865c25ed19ec248: Scheduling FlushDeltaMemStoresOp(6d45f86d36f5456aa24f014a1997e1fd): perf score=14.095187
I20260812 06:19:25.566191 31889 maintenance_manager.cc:643] P 7f5b3a28cb1e413d9865c25ed19ec248: FlushDeltaMemStoresOp(6d45f86d36f5456aa24f014a1997e1fd) complete. Timing: real 0.054s	user 0.023s	sys 0.023s Metrics: {"bytes_written":16409903,"delete_count":0,"lbm_write_time_us":21464,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:25.566666 31993 maintenance_manager.cc:419] P 7f5b3a28cb1e413d9865c25ed19ec248: Scheduling FlushDeltaMemStoresOp(6d45f86d36f5456aa24f014a1997e1fd): perf score=2.188937
I20260812 06:19:25.577612 31889 maintenance_manager.cc:643] P 7f5b3a28cb1e413d9865c25ed19ec248: FlushDeltaMemStoresOp(6d45f86d36f5456aa24f014a1997e1fd) complete. Timing: real 0.011s	user 0.005s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3939,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:25.578254 31993 maintenance_manager.cc:419] P 7f5b3a28cb1e413d9865c25ed19ec248: Scheduling FlushMRSOp(6d45f86d36f5456aa24f014a1997e1fd): perf score=1.000000
I20260812 06:19:25.609823 31889 maintenance_manager.cc:643] P 7f5b3a28cb1e413d9865c25ed19ec248: FlushMRSOp(6d45f86d36f5456aa24f014a1997e1fd) complete. Timing: real 0.031s	user 0.030s	sys 0.000s Metrics: {"bytes_written":1234473,"cfile_init":1,"dirs.queue_time_us":122,"dirs.run_cpu_time_us":201,"dirs.run_wall_time_us":1083,"drs_written":1,"lbm_read_time_us":41,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1377,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":30}
I20260812 06:19:25.610587 31993 maintenance_manager.cc:419] P 7f5b3a28cb1e413d9865c25ed19ec248: Scheduling LogGCOp(6d45f86d36f5456aa24f014a1997e1fd): free 124257238 bytes of WAL
I20260812 06:19:25.610802 31889 log_reader.cc:385] T 6d45f86d36f5456aa24f014a1997e1fd: removed 12 log segments from log reader
I20260812 06:19:25.610846 31889 log.cc:1079] T 6d45f86d36f5456aa24f014a1997e1fd P 7f5b3a28cb1e413d9865c25ed19ec248: Deleting log segment in path: /tmp/dist-test-taskxHIKYo/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515563725526-31713-0/minicluster-data/ts-0-root/wals/6d45f86d36f5456aa24f014a1997e1fd/wal-000000003 (ops 12-16)
I20260812 06:19:25.610873 31889 log.cc:1079] T 6d45f86d36f5456aa24f014a1997e1fd P 7f5b3a28cb1e413d9865c25ed19ec248: Deleting log segment in path: /tmp/dist-test-taskxHIKYo/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515563725526-31713-0/minicluster-data/ts-0-root/wals/6d45f86d36f5456aa24f014a1997e1fd/wal-000000004 (ops 17-21)
I20260812 06:19:25.610932 31889 log.cc:1079] T 6d45f86d36f5456aa24f014a1997e1fd P 7f5b3a28cb1e413d9865c25ed19ec248: Deleting log segment in path: /tmp/dist-test-taskxHIKYo/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515563725526-31713-0/minicluster-data/ts-0-root/wals/6d45f86d36f5456aa24f014a1997e1fd/wal-000000005 (ops 22-26)
I20260812 06:19:25.610980 31889 log.cc:1079] T 6d45f86d36f5456aa24f014a1997e1fd P 7f5b3a28cb1e413d9865c25ed19ec248: Deleting log segment in path: /tmp/dist-test-taskxHIKYo/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515563725526-31713-0/minicluster-data/ts-0-root/wals/6d45f86d36f5456aa24f014a1997e1fd/wal-000000006 (ops 27-31)
I20260812 06:19:25.611019 31889 log.cc:1079] T 6d45f86d36f5456aa24f014a1997e1fd P 7f5b3a28cb1e413d9865c25ed19ec248: Deleting log segment in path: /tmp/dist-test-taskxHIKYo/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515563725526-31713-0/minicluster-data/ts-0-root/wals/6d45f86d36f5456aa24f014a1997e1fd/wal-000000007 (ops 32-36)
I20260812 06:19:25.611061 31889 log.cc:1079] T 6d45f86d36f5456aa24f014a1997e1fd P 7f5b3a28cb1e413d9865c25ed19ec248: Deleting log segment in path: /tmp/dist-test-taskxHIKYo/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515563725526-31713-0/minicluster-data/ts-0-root/wals/6d45f86d36f5456aa24f014a1997e1fd/wal-000000008 (ops 37-41)
I20260812 06:19:25.611100 31889 log.cc:1079] T 6d45f86d36f5456aa24f014a1997e1fd P 7f5b3a28cb1e413d9865c25ed19ec248: Deleting log segment in path: /tmp/dist-test-taskxHIKYo/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515563725526-31713-0/minicluster-data/ts-0-root/wals/6d45f86d36f5456aa24f014a1997e1fd/wal-000000009 (ops 42-46)
I20260812 06:19:25.611140 31889 log.cc:1079] T 6d45f86d36f5456aa24f014a1997e1fd P 7f5b3a28cb1e413d9865c25ed19ec248: Deleting log segment in path: /tmp/dist-test-taskxHIKYo/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515563725526-31713-0/minicluster-data/ts-0-root/wals/6d45f86d36f5456aa24f014a1997e1fd/wal-000000010 (ops 47-51)
I20260812 06:19:25.611176 31889 log.cc:1079] T 6d45f86d36f5456aa24f014a1997e1fd P 7f5b3a28cb1e413d9865c25ed19ec248: Deleting log segment in path: /tmp/dist-test-taskxHIKYo/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515563725526-31713-0/minicluster-data/ts-0-root/wals/6d45f86d36f5456aa24f014a1997e1fd/wal-000000011 (ops 52-56)
I20260812 06:19:25.611213 31889 log.cc:1079] T 6d45f86d36f5456aa24f014a1997e1fd P 7f5b3a28cb1e413d9865c25ed19ec248: Deleting log segment in path: /tmp/dist-test-taskxHIKYo/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515563725526-31713-0/minicluster-data/ts-0-root/wals/6d45f86d36f5456aa24f014a1997e1fd/wal-000000012 (ops 57-61)
I20260812 06:19:25.611250 31889 log.cc:1079] T 6d45f86d36f5456aa24f014a1997e1fd P 7f5b3a28cb1e413d9865c25ed19ec248: Deleting log segment in path: /tmp/dist-test-taskxHIKYo/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515563725526-31713-0/minicluster-data/ts-0-root/wals/6d45f86d36f5456aa24f014a1997e1fd/wal-000000013 (ops 62-66)
I20260812 06:19:25.611289 31889 log.cc:1079] T 6d45f86d36f5456aa24f014a1997e1fd P 7f5b3a28cb1e413d9865c25ed19ec248: Deleting log segment in path: /tmp/dist-test-taskxHIKYo/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515563725526-31713-0/minicluster-data/ts-0-root/wals/6d45f86d36f5456aa24f014a1997e1fd/wal-000000014 (ops 67-70)
I20260812 06:19:25.640408 31889 maintenance_manager.cc:643] P 7f5b3a28cb1e413d9865c25ed19ec248: LogGCOp(6d45f86d36f5456aa24f014a1997e1fd) complete. Timing: real 0.030s	user 0.000s	sys 0.029s Metrics: {}
I20260812 06:19:25.640789 31993 maintenance_manager.cc:419] P 7f5b3a28cb1e413d9865c25ed19ec248: Scheduling FlushDeltaMemStoresOp(6d45f86d36f5456aa24f014a1997e1fd): perf score=3.181125
I20260812 06:19:25.657655 31889 maintenance_manager.cc:643] P 7f5b3a28cb1e413d9865c25ed19ec248: FlushDeltaMemStoresOp(6d45f86d36f5456aa24f014a1997e1fd) complete. Timing: real 0.017s	user 0.013s	sys 0.002s Metrics: {"bytes_written":4512900,"delete_count":0,"lbm_write_time_us":6817,"lbm_writes_lt_1ms":113,"reinsert_count":0,"update_count":550}
I20260812 06:19:25.658052 31993 maintenance_manager.cc:419] P 7f5b3a28cb1e413d9865c25ed19ec248: Scheduling UndoDeltaBlockGCOp(6d45f86d36f5456aa24f014a1997e1fd): 472 bytes on disk
I20260812 06:19:25.658416 31889 maintenance_manager.cc:643] P 7f5b3a28cb1e413d9865c25ed19ec248: UndoDeltaBlockGCOp(6d45f86d36f5456aa24f014a1997e1fd) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":46,"lbm_reads_lt_1ms":4}
I20260812 06:19:25.658872 31993 maintenance_manager.cc:419] P 7f5b3a28cb1e413d9865c25ed19ec248: Scheduling FlushDeltaMemStoresOp(6d45f86d36f5456aa24f014a1997e1fd): perf score=2.188937
I20260812 06:19:25.668358 31889 maintenance_manager.cc:643] P 7f5b3a28cb1e413d9865c25ed19ec248: FlushDeltaMemStoresOp(6d45f86d36f5456aa24f014a1997e1fd) complete. Timing: real 0.009s	user 0.006s	sys 0.003s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3527,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:19:25.669018 31993 maintenance_manager.cc:419] P 7f5b3a28cb1e413d9865c25ed19ec248: Scheduling MajorDeltaCompactionOp(6d45f86d36f5456aa24f014a1997e1fd): perf score=1.000000
I20260812 06:19:25.877354 31889 maintenance_manager.cc:643] P 7f5b3a28cb1e413d9865c25ed19ec248: MajorDeltaCompactionOp(6d45f86d36f5456aa24f014a1997e1fd) complete. Timing: real 0.208s	user 0.164s	sys 0.036s Metrics: {"cfile_cache_miss":734,"cfile_cache_miss_bytes":32979739,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":457,"lbm_read_time_us":12295,"lbm_reads_lt_1ms":774,"lbm_write_time_us":36111,"lbm_writes_lt_1ms":743,"mutex_wait_us":25,"peak_mem_usage":87969044,"reinsert_count":0,"spinlock_wait_cycles":10240,"thread_start_us":79,"threads_started":1,"update_count":3500}
I20260812 06:19:25.878037 31993 maintenance_manager.cc:419] P 7f5b3a28cb1e413d9865c25ed19ec248: Scheduling FlushDeltaMemStoresOp(6d45f86d36f5456aa24f014a1997e1fd): perf score=15.087375
I20260812 06:19:25.937086 31889 maintenance_manager.cc:643] P 7f5b3a28cb1e413d9865c25ed19ec248: FlushDeltaMemStoresOp(6d45f86d36f5456aa24f014a1997e1fd) complete. Timing: real 0.059s	user 0.040s	sys 0.017s Metrics: {"bytes_written":16820145,"delete_count":0,"lbm_write_time_us":21713,"lbm_writes_lt_1ms":413,"reinsert_count":0,"update_count":2050}
I20260812 06:19:25.937592 31993 maintenance_manager.cc:419] P 7f5b3a28cb1e413d9865c25ed19ec248: Scheduling FlushDeltaMemStoresOp(6d45f86d36f5456aa24f014a1997e1fd): perf score=2.188937
I20260812 06:19:25.951924 31889 maintenance_manager.cc:643] P 7f5b3a28cb1e413d9865c25ed19ec248: FlushDeltaMemStoresOp(6d45f86d36f5456aa24f014a1997e1fd) complete. Timing: real 0.014s	user 0.010s	sys 0.001s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":4850,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:19:25.952425 31993 maintenance_manager.cc:419] P 7f5b3a28cb1e413d9865c25ed19ec248: Scheduling MajorDeltaCompactionOp(6d45f86d36f5456aa24f014a1997e1fd): perf score=1.000000
I20260812 06:19:26.118081 31889 maintenance_manager.cc:643] P 7f5b3a28cb1e413d9865c25ed19ec248: MajorDeltaCompactionOp(6d45f86d36f5456aa24f014a1997e1fd) complete. Timing: real 0.165s	user 0.120s	sys 0.045s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774678,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":233,"lbm_read_time_us":11101,"lbm_reads_lt_1ms":564,"lbm_write_time_us":28809,"lbm_writes_lt_1ms":543,"mutex_wait_us":45,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":4992,"update_count":2500}
I20260812 06:19:26.118717 31993 maintenance_manager.cc:419] P 7f5b3a28cb1e413d9865c25ed19ec248: Scheduling FlushDeltaMemStoresOp(6d45f86d36f5456aa24f014a1997e1fd): perf score=14.095187
I20260812 06:19:26.177290 31889 maintenance_manager.cc:643] P 7f5b3a28cb1e413d9865c25ed19ec248: FlushDeltaMemStoresOp(6d45f86d36f5456aa24f014a1997e1fd) complete. Timing: real 0.058s	user 0.035s	sys 0.019s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":24086,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:26.177889 31993 maintenance_manager.cc:419] P 7f5b3a28cb1e413d9865c25ed19ec248: Scheduling FlushDeltaMemStoresOp(6d45f86d36f5456aa24f014a1997e1fd): perf score=2.188937
I20260812 06:19:26.202473 31889 maintenance_manager.cc:643] P 7f5b3a28cb1e413d9865c25ed19ec248: FlushDeltaMemStoresOp(6d45f86d36f5456aa24f014a1997e1fd) complete. Timing: real 0.024s	user 0.011s	sys 0.011s 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:19:26.203141 31993 maintenance_manager.cc:419] P 7f5b3a28cb1e413d9865c25ed19ec248: Scheduling MajorDeltaCompactionOp(6d45f86d36f5456aa24f014a1997e1fd): perf score=1.000000
I20260812 06:19:26.381978 31889 maintenance_manager.cc:643] P 7f5b3a28cb1e413d9865c25ed19ec248: MajorDeltaCompactionOp(6d45f86d36f5456aa24f014a1997e1fd) complete. Timing: real 0.179s	user 0.133s	sys 0.035s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774688,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":804,"lbm_read_time_us":12833,"lbm_reads_lt_1ms":572,"lbm_write_time_us":28280,"lbm_writes_lt_1ms":543,"mutex_wait_us":260,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":162944,"update_count":2500}
I20260812 06:19:26.382529 31993 maintenance_manager.cc:419] P 7f5b3a28cb1e413d9865c25ed19ec248: Scheduling FlushDeltaMemStoresOp(6d45f86d36f5456aa24f014a1997e1fd): perf score=14.095187
I20260812 06:19:26.434458 31889 maintenance_manager.cc:643] P 7f5b3a28cb1e413d9865c25ed19ec248: FlushDeltaMemStoresOp(6d45f86d36f5456aa24f014a1997e1fd) complete. Timing: real 0.052s	user 0.044s	sys 0.003s Metrics: {"bytes_written":16409903,"delete_count":0,"lbm_write_time_us":22191,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:26.434883 31993 maintenance_manager.cc:419] P 7f5b3a28cb1e413d9865c25ed19ec248: Scheduling FlushDeltaMemStoresOp(6d45f86d36f5456aa24f014a1997e1fd): perf score=2.188937
I20260812 06:19:26.445993 31889 maintenance_manager.cc:643] P 7f5b3a28cb1e413d9865c25ed19ec248: FlushDeltaMemStoresOp(6d45f86d36f5456aa24f014a1997e1fd) complete. Timing: real 0.011s	user 0.009s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3955,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:26.446476 31993 maintenance_manager.cc:419] P 7f5b3a28cb1e413d9865c25ed19ec248: Scheduling MajorDeltaCompactionOp(6d45f86d36f5456aa24f014a1997e1fd): perf score=1.000000
I20260812 06:19:26.605806 31889 maintenance_manager.cc:643] P 7f5b3a28cb1e413d9865c25ed19ec248: MajorDeltaCompactionOp(6d45f86d36f5456aa24f014a1997e1fd) complete. Timing: real 0.159s	user 0.109s	sys 0.043s 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":227,"lbm_read_time_us":9143,"lbm_reads_lt_1ms":572,"lbm_write_time_us":27169,"lbm_writes_lt_1ms":543,"mutex_wait_us":25,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":21632,"update_count":2500}
I20260812 06:19:26.606432 31993 maintenance_manager.cc:419] P 7f5b3a28cb1e413d9865c25ed19ec248: Scheduling FlushDeltaMemStoresOp(6d45f86d36f5456aa24f014a1997e1fd): perf score=11.118625
I20260812 06:19:26.643456 31889 maintenance_manager.cc:643] P 7f5b3a28cb1e413d9865c25ed19ec248: FlushDeltaMemStoresOp(6d45f86d36f5456aa24f014a1997e1fd) complete. Timing: real 0.035s	user 0.027s	sys 0.004s Metrics: {"bytes_written":12717735,"delete_count":0,"lbm_write_time_us":15061,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:19:26.644048 31993 maintenance_manager.cc:419] P 7f5b3a28cb1e413d9865c25ed19ec248: Scheduling FlushDeltaMemStoresOp(6d45f86d36f5456aa24f014a1997e1fd): perf score=2.188937
I20260812 06:19:26.659889 31889 maintenance_manager.cc:643] P 7f5b3a28cb1e413d9865c25ed19ec248: FlushDeltaMemStoresOp(6d45f86d36f5456aa24f014a1997e1fd) complete. Timing: real 0.016s	user 0.009s	sys 0.004s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":5821,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:19:26.660373 31993 maintenance_manager.cc:419] P 7f5b3a28cb1e413d9865c25ed19ec248: Scheduling MajorDeltaCompactionOp(6d45f86d36f5456aa24f014a1997e1fd): perf score=1.000000
I20260812 06:19:26.785411 31889 maintenance_manager.cc:643] P 7f5b3a28cb1e413d9865c25ed19ec248: MajorDeltaCompactionOp(6d45f86d36f5456aa24f014a1997e1fd) complete. Timing: real 0.125s	user 0.102s	sys 0.020s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672268,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":373,"lbm_read_time_us":8286,"lbm_reads_lt_1ms":464,"lbm_write_time_us":24254,"lbm_writes_lt_1ms":443,"mutex_wait_us":3,"peak_mem_usage":50689328,"reinsert_count":0,"update_count":2000}
I20260812 06:19:26.785961 31993 maintenance_manager.cc:419] P 7f5b3a28cb1e413d9865c25ed19ec248: Scheduling FlushDeltaMemStoresOp(6d45f86d36f5456aa24f014a1997e1fd): perf score=11.118625
I20260812 06:19:26.826201 31889 maintenance_manager.cc:643] P 7f5b3a28cb1e413d9865c25ed19ec248: FlushDeltaMemStoresOp(6d45f86d36f5456aa24f014a1997e1fd) complete. Timing: real 0.040s	user 0.025s	sys 0.013s Metrics: {"bytes_written":12717735,"delete_count":0,"lbm_write_time_us":17767,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:19:26.826719 31993 maintenance_manager.cc:419] P 7f5b3a28cb1e413d9865c25ed19ec248: Scheduling FlushDeltaMemStoresOp(6d45f86d36f5456aa24f014a1997e1fd): perf score=2.188937
I20260812 06:19:26.843871 31889 maintenance_manager.cc:643] P 7f5b3a28cb1e413d9865c25ed19ec248: FlushDeltaMemStoresOp(6d45f86d36f5456aa24f014a1997e1fd) complete. Timing: real 0.017s	user 0.008s	sys 0.005s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":6011,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:19:26.844468 31993 maintenance_manager.cc:419] P 7f5b3a28cb1e413d9865c25ed19ec248: Scheduling MajorDeltaCompactionOp(6d45f86d36f5456aa24f014a1997e1fd): perf score=1.000000
I20260812 06:19:26.968883 31889 maintenance_manager.cc:643] P 7f5b3a28cb1e413d9865c25ed19ec248: MajorDeltaCompactionOp(6d45f86d36f5456aa24f014a1997e1fd) complete. Timing: real 0.124s	user 0.080s	sys 0.044s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672268,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":149,"lbm_read_time_us":8636,"lbm_reads_lt_1ms":472,"lbm_write_time_us":23913,"lbm_writes_lt_1ms":443,"mutex_wait_us":31,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":7936,"update_count":2000}
I20260812 06:19:26.970170 31993 maintenance_manager.cc:419] P 7f5b3a28cb1e413d9865c25ed19ec248: Scheduling FlushDeltaMemStoresOp(6d45f86d36f5456aa24f014a1997e1fd): perf score=11.118625
I20260812 06:19:27.014539 31889 maintenance_manager.cc:643] P 7f5b3a28cb1e413d9865c25ed19ec248: FlushDeltaMemStoresOp(6d45f86d36f5456aa24f014a1997e1fd) complete. Timing: real 0.044s	user 0.009s	sys 0.033s Metrics: {"bytes_written":12594661,"delete_count":0,"lbm_write_time_us":14048,"lbm_writes_lt_1ms":310,"reinsert_count":0,"update_count":1535}
I20260812 06:19:27.015143 31993 maintenance_manager.cc:419] P 7f5b3a28cb1e413d9865c25ed19ec248: Scheduling FlushDeltaMemStoresOp(6d45f86d36f5456aa24f014a1997e1fd): perf score=2.188937
I20260812 06:19:27.030741 31889 maintenance_manager.cc:643] P 7f5b3a28cb1e413d9865c25ed19ec248: FlushDeltaMemStoresOp(6d45f86d36f5456aa24f014a1997e1fd) complete. Timing: real 0.015s	user 0.012s	sys 0.000s Metrics: {"bytes_written":3815484,"delete_count":0,"lbm_write_time_us":5686,"lbm_writes_lt_1ms":96,"reinsert_count":0,"update_count":465}
I20260812 06:19:27.031355 31993 maintenance_manager.cc:419] P 7f5b3a28cb1e413d9865c25ed19ec248: Scheduling FlushMRSOp(6d45f86d36f5456aa24f014a1997e1fd): perf score=1.000000
I20260812 06:19:27.078527 31889 maintenance_manager.cc:643] P 7f5b3a28cb1e413d9865c25ed19ec248: FlushMRSOp(6d45f86d36f5456aa24f014a1997e1fd) complete. Timing: real 0.047s	user 0.035s	sys 0.003s Metrics: {"bytes_written":1193509,"cfile_init":1,"dirs.queue_time_us":149,"dirs.run_cpu_time_us":193,"dirs.run_wall_time_us":1239,"drs_written":1,"lbm_read_time_us":85,"lbm_reads_lt_1ms":4,"lbm_write_time_us":2079,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":29}
I20260812 06:19:27.079629 31993 maintenance_manager.cc:419] P 7f5b3a28cb1e413d9865c25ed19ec248: Scheduling LogGCOp(6d45f86d36f5456aa24f014a1997e1fd): free 112692315 bytes of WAL
I20260812 06:19:27.079871 31889 log_reader.cc:385] T 6d45f86d36f5456aa24f014a1997e1fd: removed 11 log segments from log reader
I20260812 06:19:27.079914 31889 log.cc:1079] T 6d45f86d36f5456aa24f014a1997e1fd P 7f5b3a28cb1e413d9865c25ed19ec248: Deleting log segment in path: /tmp/dist-test-taskxHIKYo/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515563725526-31713-0/minicluster-data/ts-0-root/wals/6d45f86d36f5456aa24f014a1997e1fd/wal-000000015 (ops 71-75)
I20260812 06:19:27.079943 31889 log.cc:1079] T 6d45f86d36f5456aa24f014a1997e1fd P 7f5b3a28cb1e413d9865c25ed19ec248: Deleting log segment in path: /tmp/dist-test-taskxHIKYo/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515563725526-31713-0/minicluster-data/ts-0-root/wals/6d45f86d36f5456aa24f014a1997e1fd/wal-000000016 (ops 76-80)
I20260812 06:19:27.079994 31889 log.cc:1079] T 6d45f86d36f5456aa24f014a1997e1fd P 7f5b3a28cb1e413d9865c25ed19ec248: Deleting log segment in path: /tmp/dist-test-taskxHIKYo/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515563725526-31713-0/minicluster-data/ts-0-root/wals/6d45f86d36f5456aa24f014a1997e1fd/wal-000000017 (ops 81-85)
I20260812 06:19:27.080036 31889 log.cc:1079] T 6d45f86d36f5456aa24f014a1997e1fd P 7f5b3a28cb1e413d9865c25ed19ec248: Deleting log segment in path: /tmp/dist-test-taskxHIKYo/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515563725526-31713-0/minicluster-data/ts-0-root/wals/6d45f86d36f5456aa24f014a1997e1fd/wal-000000018 (ops 86-90)
I20260812 06:19:27.080075 31889 log.cc:1079] T 6d45f86d36f5456aa24f014a1997e1fd P 7f5b3a28cb1e413d9865c25ed19ec248: Deleting log segment in path: /tmp/dist-test-taskxHIKYo/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515563725526-31713-0/minicluster-data/ts-0-root/wals/6d45f86d36f5456aa24f014a1997e1fd/wal-000000019 (ops 91-95)
I20260812 06:19:27.080114 31889 log.cc:1079] T 6d45f86d36f5456aa24f014a1997e1fd P 7f5b3a28cb1e413d9865c25ed19ec248: Deleting log segment in path: /tmp/dist-test-taskxHIKYo/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515563725526-31713-0/minicluster-data/ts-0-root/wals/6d45f86d36f5456aa24f014a1997e1fd/wal-000000020 (ops 96-100)
I20260812 06:19:27.080180 31889 log.cc:1079] T 6d45f86d36f5456aa24f014a1997e1fd P 7f5b3a28cb1e413d9865c25ed19ec248: Deleting log segment in path: /tmp/dist-test-taskxHIKYo/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515563725526-31713-0/minicluster-data/ts-0-root/wals/6d45f86d36f5456aa24f014a1997e1fd/wal-000000021 (ops 101-105)
I20260812 06:19:27.080219 31889 log.cc:1079] T 6d45f86d36f5456aa24f014a1997e1fd P 7f5b3a28cb1e413d9865c25ed19ec248: Deleting log segment in path: /tmp/dist-test-taskxHIKYo/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515563725526-31713-0/minicluster-data/ts-0-root/wals/6d45f86d36f5456aa24f014a1997e1fd/wal-000000022 (ops 106-110)
I20260812 06:19:27.080269 31889 log.cc:1079] T 6d45f86d36f5456aa24f014a1997e1fd P 7f5b3a28cb1e413d9865c25ed19ec248: Deleting log segment in path: /tmp/dist-test-taskxHIKYo/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515563725526-31713-0/minicluster-data/ts-0-root/wals/6d45f86d36f5456aa24f014a1997e1fd/wal-000000023 (ops 111-115)
I20260812 06:19:27.080307 31889 log.cc:1079] T 6d45f86d36f5456aa24f014a1997e1fd P 7f5b3a28cb1e413d9865c25ed19ec248: Deleting log segment in path: /tmp/dist-test-taskxHIKYo/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515563725526-31713-0/minicluster-data/ts-0-root/wals/6d45f86d36f5456aa24f014a1997e1fd/wal-000000024 (ops 116-120)
I20260812 06:19:27.080343 31889 log.cc:1079] T 6d45f86d36f5456aa24f014a1997e1fd P 7f5b3a28cb1e413d9865c25ed19ec248: Deleting log segment in path: /tmp/dist-test-taskxHIKYo/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515563725526-31713-0/minicluster-data/ts-0-root/wals/6d45f86d36f5456aa24f014a1997e1fd/wal-000000025 (ops 121-125)
I20260812 06:19:27.106038 31889 maintenance_manager.cc:643] P 7f5b3a28cb1e413d9865c25ed19ec248: LogGCOp(6d45f86d36f5456aa24f014a1997e1fd) complete. Timing: real 0.026s	user 0.002s	sys 0.023s Metrics: {}
I20260812 06:19:27.106540 31993 maintenance_manager.cc:419] P 7f5b3a28cb1e413d9865c25ed19ec248: Scheduling UndoDeltaBlockGCOp(6d45f86d36f5456aa24f014a1997e1fd): 463 bytes on disk
I20260812 06:19:27.107184 31889 maintenance_manager.cc:643] P 7f5b3a28cb1e413d9865c25ed19ec248: UndoDeltaBlockGCOp(6d45f86d36f5456aa24f014a1997e1fd) 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:19:27.107789 31993 maintenance_manager.cc:419] P 7f5b3a28cb1e413d9865c25ed19ec248: Scheduling FlushDeltaMemStoresOp(6d45f86d36f5456aa24f014a1997e1fd): perf score=3.181125
I20260812 06:19:27.130666 31889 maintenance_manager.cc:643] P 7f5b3a28cb1e413d9865c25ed19ec248: FlushDeltaMemStoresOp(6d45f86d36f5456aa24f014a1997e1fd) complete. Timing: real 0.023s	user 0.010s	sys 0.003s Metrics: {"bytes_written":4512900,"delete_count":0,"lbm_write_time_us":5852,"lbm_writes_lt_1ms":113,"reinsert_count":0,"update_count":550}
I20260812 06:19:27.131166 31993 maintenance_manager.cc:419] P 7f5b3a28cb1e413d9865c25ed19ec248: Scheduling FlushDeltaMemStoresOp(6d45f86d36f5456aa24f014a1997e1fd): perf score=2.188937
I20260812 06:19:27.140844 31889 maintenance_manager.cc:643] P 7f5b3a28cb1e413d9865c25ed19ec248: FlushDeltaMemStoresOp(6d45f86d36f5456aa24f014a1997e1fd) complete. Timing: real 0.009s	user 0.009s	sys 0.000s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3575,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:19:27.141291 31993 maintenance_manager.cc:419] P 7f5b3a28cb1e413d9865c25ed19ec248: Scheduling MajorDeltaCompactionOp(6d45f86d36f5456aa24f014a1997e1fd): perf score=1.000000
I20260812 06:19:27.340301 31889 maintenance_manager.cc:643] P 7f5b3a28cb1e413d9865c25ed19ec248: MajorDeltaCompactionOp(6d45f86d36f5456aa24f014a1997e1fd) complete. Timing: real 0.199s	user 0.138s	sys 0.060s Metrics: {"cfile_cache_miss":634,"cfile_cache_miss_bytes":28877322,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":563,"lbm_read_time_us":13085,"lbm_reads_lt_1ms":674,"lbm_write_time_us":33543,"lbm_writes_lt_1ms":643,"mutex_wait_us":291,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":14592,"thread_start_us":101,"threads_started":1,"update_count":3000}
I20260812 06:19:27.341185 31993 maintenance_manager.cc:419] P 7f5b3a28cb1e413d9865c25ed19ec248: Scheduling FlushDeltaMemStoresOp(6d45f86d36f5456aa24f014a1997e1fd): perf score=14.095187
I20260812 06:19:27.394130 31889 maintenance_manager.cc:643] P 7f5b3a28cb1e413d9865c25ed19ec248: FlushDeltaMemStoresOp(6d45f86d36f5456aa24f014a1997e1fd) complete. Timing: real 0.053s	user 0.027s	sys 0.015s Metrics: {"bytes_written":16409900,"delete_count":0,"lbm_write_time_us":19640,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:27.394629 31993 maintenance_manager.cc:419] P 7f5b3a28cb1e413d9865c25ed19ec248: Scheduling FlushDeltaMemStoresOp(6d45f86d36f5456aa24f014a1997e1fd): perf score=2.188937
I20260812 06:19:27.406112 31889 maintenance_manager.cc:643] P 7f5b3a28cb1e413d9865c25ed19ec248: FlushDeltaMemStoresOp(6d45f86d36f5456aa24f014a1997e1fd) complete. Timing: real 0.011s	user 0.005s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4035,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:27.406775 31993 maintenance_manager.cc:419] P 7f5b3a28cb1e413d9865c25ed19ec248: Scheduling MajorDeltaCompactionOp(6d45f86d36f5456aa24f014a1997e1fd): perf score=1.000000
I20260812 06:19:27.589901 31889 maintenance_manager.cc:643] P 7f5b3a28cb1e413d9865c25ed19ec248: MajorDeltaCompactionOp(6d45f86d36f5456aa24f014a1997e1fd) complete. Timing: real 0.183s	user 0.154s	sys 0.028s 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":282,"lbm_read_time_us":11651,"lbm_reads_lt_1ms":572,"lbm_write_time_us":35554,"lbm_writes_lt_1ms":543,"mutex_wait_us":42,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":4864,"update_count":2500}
I20260812 06:19:27.590583 31993 maintenance_manager.cc:419] P 7f5b3a28cb1e413d9865c25ed19ec248: Scheduling FlushDeltaMemStoresOp(6d45f86d36f5456aa24f014a1997e1fd): perf score=14.095187
I20260812 06:19:27.651218 31889 maintenance_manager.cc:643] P 7f5b3a28cb1e413d9865c25ed19ec248: FlushDeltaMemStoresOp(6d45f86d36f5456aa24f014a1997e1fd) complete. Timing: real 0.060s	user 0.033s	sys 0.024s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":27151,"lbm_writes_1-10_ms":3,"lbm_writes_lt_1ms":400,"reinsert_count":0,"update_count":2000}
I20260812 06:19:27.651787 31993 maintenance_manager.cc:419] P 7f5b3a28cb1e413d9865c25ed19ec248: Scheduling FlushDeltaMemStoresOp(6d45f86d36f5456aa24f014a1997e1fd): perf score=2.188937
I20260812 06:19:27.662319 31889 maintenance_manager.cc:643] P 7f5b3a28cb1e413d9865c25ed19ec248: FlushDeltaMemStoresOp(6d45f86d36f5456aa24f014a1997e1fd) complete. Timing: real 0.010s	user 0.006s	sys 0.003s 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:19:27.662817 31993 maintenance_manager.cc:419] P 7f5b3a28cb1e413d9865c25ed19ec248: Scheduling MajorDeltaCompactionOp(6d45f86d36f5456aa24f014a1997e1fd): perf score=1.000000
I20260812 06:19:27.832509 31889 maintenance_manager.cc:643] P 7f5b3a28cb1e413d9865c25ed19ec248: MajorDeltaCompactionOp(6d45f86d36f5456aa24f014a1997e1fd) complete. Timing: real 0.170s	user 0.121s	sys 0.047s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774688,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":857,"lbm_read_time_us":13603,"lbm_reads_lt_1ms":572,"lbm_write_time_us":29269,"lbm_writes_lt_1ms":543,"mutex_wait_us":255,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":896,"update_count":2500}
I20260812 06:19:27.833086 31993 maintenance_manager.cc:419] P 7f5b3a28cb1e413d9865c25ed19ec248: Scheduling FlushDeltaMemStoresOp(6d45f86d36f5456aa24f014a1997e1fd): perf score=14.095187
I20260812 06:19:27.890436 31889 maintenance_manager.cc:643] P 7f5b3a28cb1e413d9865c25ed19ec248: FlushDeltaMemStoresOp(6d45f86d36f5456aa24f014a1997e1fd) complete. Timing: real 0.057s	user 0.023s	sys 0.031s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":20512,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:27.891096 31993 maintenance_manager.cc:419] P 7f5b3a28cb1e413d9865c25ed19ec248: Scheduling FlushDeltaMemStoresOp(6d45f86d36f5456aa24f014a1997e1fd): perf score=2.188937
I20260812 06:19:27.902632 31889 maintenance_manager.cc:643] P 7f5b3a28cb1e413d9865c25ed19ec248: FlushDeltaMemStoresOp(6d45f86d36f5456aa24f014a1997e1fd) complete. Timing: real 0.011s	user 0.006s	sys 0.003s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4539,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:27.903087 31993 maintenance_manager.cc:419] P 7f5b3a28cb1e413d9865c25ed19ec248: Scheduling MajorDeltaCompactionOp(6d45f86d36f5456aa24f014a1997e1fd): perf score=1.000000
I20260812 06:19:28.083549 31889 maintenance_manager.cc:643] P 7f5b3a28cb1e413d9865c25ed19ec248: MajorDeltaCompactionOp(6d45f86d36f5456aa24f014a1997e1fd) complete. Timing: real 0.180s	user 0.116s	sys 0.055s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774688,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":563,"lbm_read_time_us":12265,"lbm_reads_lt_1ms":572,"lbm_write_time_us":29099,"lbm_writes_lt_1ms":543,"mutex_wait_us":26,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":28416,"update_count":2500}
I20260812 06:19:28.084214 31993 maintenance_manager.cc:419] P 7f5b3a28cb1e413d9865c25ed19ec248: Scheduling FlushDeltaMemStoresOp(6d45f86d36f5456aa24f014a1997e1fd): perf score=14.095187
I20260812 06:19:28.126149 31889 maintenance_manager.cc:643] P 7f5b3a28cb1e413d9865c25ed19ec248: FlushDeltaMemStoresOp(6d45f86d36f5456aa24f014a1997e1fd) complete. Timing: real 0.042s	user 0.028s	sys 0.012s Metrics: {"bytes_written":16409903,"delete_count":0,"lbm_write_time_us":17962,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:28.126688 31993 maintenance_manager.cc:419] P 7f5b3a28cb1e413d9865c25ed19ec248: Scheduling FlushDeltaMemStoresOp(6d45f86d36f5456aa24f014a1997e1fd): perf score=2.188937
I20260812 06:19:28.145747 31889 maintenance_manager.cc:643] P 7f5b3a28cb1e413d9865c25ed19ec248: FlushDeltaMemStoresOp(6d45f86d36f5456aa24f014a1997e1fd) complete. Timing: real 0.019s	user 0.002s	sys 0.015s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4117,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:28.146503 31993 maintenance_manager.cc:419] P 7f5b3a28cb1e413d9865c25ed19ec248: Scheduling MajorDeltaCompactionOp(6d45f86d36f5456aa24f014a1997e1fd): perf score=1.000000
I20260812 06:19:28.326488 31889 maintenance_manager.cc:643] P 7f5b3a28cb1e413d9865c25ed19ec248: MajorDeltaCompactionOp(6d45f86d36f5456aa24f014a1997e1fd) complete. Timing: real 0.180s	user 0.112s	sys 0.060s 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":314,"lbm_read_time_us":12413,"lbm_reads_lt_1ms":572,"lbm_write_time_us":30253,"lbm_writes_lt_1ms":543,"mutex_wait_us":2,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":6272,"update_count":2500}
I20260812 06:19:28.327145 31993 maintenance_manager.cc:419] P 7f5b3a28cb1e413d9865c25ed19ec248: Scheduling FlushDeltaMemStoresOp(6d45f86d36f5456aa24f014a1997e1fd): perf score=14.095187
I20260812 06:19:28.373629 31889 maintenance_manager.cc:643] P 7f5b3a28cb1e413d9865c25ed19ec248: FlushDeltaMemStoresOp(6d45f86d36f5456aa24f014a1997e1fd) complete. Timing: real 0.046s	user 0.028s	sys 0.016s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":19821,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:28.374155 31993 maintenance_manager.cc:419] P 7f5b3a28cb1e413d9865c25ed19ec248: Scheduling FlushDeltaMemStoresOp(6d45f86d36f5456aa24f014a1997e1fd): perf score=2.188937
I20260812 06:19:28.385344 31889 maintenance_manager.cc:643] P 7f5b3a28cb1e413d9865c25ed19ec248: FlushDeltaMemStoresOp(6d45f86d36f5456aa24f014a1997e1fd) complete. Timing: real 0.011s	user 0.010s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4065,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:28.385849 31993 maintenance_manager.cc:419] P 7f5b3a28cb1e413d9865c25ed19ec248: Scheduling MajorDeltaCompactionOp(6d45f86d36f5456aa24f014a1997e1fd): perf score=1.000000
I20260812 06:19:28.578253 31889 maintenance_manager.cc:643] P 7f5b3a28cb1e413d9865c25ed19ec248: MajorDeltaCompactionOp(6d45f86d36f5456aa24f014a1997e1fd) complete. Timing: real 0.192s	user 0.157s	sys 0.028s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774688,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":589,"lbm_read_time_us":11570,"lbm_reads_lt_1ms":572,"lbm_write_time_us":31942,"lbm_writes_lt_1ms":543,"mutex_wait_us":26,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":12288,"update_count":2500}
I20260812 06:19:28.579010 31993 maintenance_manager.cc:419] P 7f5b3a28cb1e413d9865c25ed19ec248: Scheduling FlushDeltaMemStoresOp(6d45f86d36f5456aa24f014a1997e1fd): perf score=11.118625
I20260812 06:19:28.616443 31889 maintenance_manager.cc:643] P 7f5b3a28cb1e413d9865c25ed19ec248: FlushDeltaMemStoresOp(6d45f86d36f5456aa24f014a1997e1fd) complete. Timing: real 0.037s	user 0.025s	sys 0.012s Metrics: {"bytes_written":12717735,"delete_count":0,"lbm_write_time_us":15698,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:19:28.616974 31993 maintenance_manager.cc:419] P 7f5b3a28cb1e413d9865c25ed19ec248: Scheduling FlushDeltaMemStoresOp(6d45f86d36f5456aa24f014a1997e1fd): perf score=2.188937
I20260812 06:19:28.640857 31889 maintenance_manager.cc:643] P 7f5b3a28cb1e413d9865c25ed19ec248: FlushDeltaMemStoresOp(6d45f86d36f5456aa24f014a1997e1fd) complete. Timing: real 0.024s	user 0.010s	sys 0.003s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":5018,"lbm_writes_lt_1ms":93,"reinsert_count":0,"spinlock_wait_cycles":1792,"update_count":450}
I20260812 06:19:28.641314 31993 maintenance_manager.cc:419] P 7f5b3a28cb1e413d9865c25ed19ec248: Scheduling FlushDeltaMemStoresOp(6d45f86d36f5456aa24f014a1997e1fd): perf score=2.188937
I20260812 06:19:28.651402 31889 maintenance_manager.cc:643] P 7f5b3a28cb1e413d9865c25ed19ec248: FlushDeltaMemStoresOp(6d45f86d36f5456aa24f014a1997e1fd) complete. Timing: real 0.010s	user 0.005s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3915,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:28.651836 31993 maintenance_manager.cc:419] P 7f5b3a28cb1e413d9865c25ed19ec248: Scheduling FlushMRSOp(6d45f86d36f5456aa24f014a1997e1fd): perf score=1.000000
I20260812 06:19:28.683328 31889 maintenance_manager.cc:643] P 7f5b3a28cb1e413d9865c25ed19ec248: FlushMRSOp(6d45f86d36f5456aa24f014a1997e1fd) complete. Timing: real 0.031s	user 0.026s	sys 0.003s Metrics: {"bytes_written":1316417,"cfile_init":1,"dirs.queue_time_us":64,"dirs.run_cpu_time_us":156,"dirs.run_wall_time_us":1183,"drs_written":1,"lbm_read_time_us":58,"lbm_reads_lt_1ms":4,"lbm_write_time_us":2175,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":32}
I20260812 06:19:28.684118 31993 maintenance_manager.cc:419] P 7f5b3a28cb1e413d9865c25ed19ec248: Scheduling LogGCOp(6d45f86d36f5456aa24f014a1997e1fd): free 133024690 bytes of WAL
I20260812 06:19:28.684412 31889 log_reader.cc:385] T 6d45f86d36f5456aa24f014a1997e1fd: removed 13 log segments from log reader
I20260812 06:19:28.684484 31889 log.cc:1079] T 6d45f86d36f5456aa24f014a1997e1fd P 7f5b3a28cb1e413d9865c25ed19ec248: Deleting log segment in path: /tmp/dist-test-taskxHIKYo/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515563725526-31713-0/minicluster-data/ts-0-root/wals/6d45f86d36f5456aa24f014a1997e1fd/wal-000000026 (ops 126-130)
I20260812 06:19:28.684522 31889 log.cc:1079] T 6d45f86d36f5456aa24f014a1997e1fd P 7f5b3a28cb1e413d9865c25ed19ec248: Deleting log segment in path: /tmp/dist-test-taskxHIKYo/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515563725526-31713-0/minicluster-data/ts-0-root/wals/6d45f86d36f5456aa24f014a1997e1fd/wal-000000027 (ops 131-134)
I20260812 06:19:28.684559 31889 log.cc:1079] T 6d45f86d36f5456aa24f014a1997e1fd P 7f5b3a28cb1e413d9865c25ed19ec248: Deleting log segment in path: /tmp/dist-test-taskxHIKYo/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515563725526-31713-0/minicluster-data/ts-0-root/wals/6d45f86d36f5456aa24f014a1997e1fd/wal-000000028 (ops 135-139)
I20260812 06:19:28.684585 31889 log.cc:1079] T 6d45f86d36f5456aa24f014a1997e1fd P 7f5b3a28cb1e413d9865c25ed19ec248: Deleting log segment in path: /tmp/dist-test-taskxHIKYo/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515563725526-31713-0/minicluster-data/ts-0-root/wals/6d45f86d36f5456aa24f014a1997e1fd/wal-000000029 (ops 140-144)
I20260812 06:19:28.684617 31889 log.cc:1079] T 6d45f86d36f5456aa24f014a1997e1fd P 7f5b3a28cb1e413d9865c25ed19ec248: Deleting log segment in path: /tmp/dist-test-taskxHIKYo/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515563725526-31713-0/minicluster-data/ts-0-root/wals/6d45f86d36f5456aa24f014a1997e1fd/wal-000000030 (ops 145-149)
I20260812 06:19:28.684640 31889 log.cc:1079] T 6d45f86d36f5456aa24f014a1997e1fd P 7f5b3a28cb1e413d9865c25ed19ec248: Deleting log segment in path: /tmp/dist-test-taskxHIKYo/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515563725526-31713-0/minicluster-data/ts-0-root/wals/6d45f86d36f5456aa24f014a1997e1fd/wal-000000031 (ops 150-154)
I20260812 06:19:28.684662 31889 log.cc:1079] T 6d45f86d36f5456aa24f014a1997e1fd P 7f5b3a28cb1e413d9865c25ed19ec248: Deleting log segment in path: /tmp/dist-test-taskxHIKYo/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515563725526-31713-0/minicluster-data/ts-0-root/wals/6d45f86d36f5456aa24f014a1997e1fd/wal-000000032 (ops 155-159)
I20260812 06:19:28.684692 31889 log.cc:1079] T 6d45f86d36f5456aa24f014a1997e1fd P 7f5b3a28cb1e413d9865c25ed19ec248: Deleting log segment in path: /tmp/dist-test-taskxHIKYo/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515563725526-31713-0/minicluster-data/ts-0-root/wals/6d45f86d36f5456aa24f014a1997e1fd/wal-000000033 (ops 160-164)
I20260812 06:19:28.684727 31889 log.cc:1079] T 6d45f86d36f5456aa24f014a1997e1fd P 7f5b3a28cb1e413d9865c25ed19ec248: Deleting log segment in path: /tmp/dist-test-taskxHIKYo/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515563725526-31713-0/minicluster-data/ts-0-root/wals/6d45f86d36f5456aa24f014a1997e1fd/wal-000000034 (ops 165-169)
I20260812 06:19:28.684760 31889 log.cc:1079] T 6d45f86d36f5456aa24f014a1997e1fd P 7f5b3a28cb1e413d9865c25ed19ec248: Deleting log segment in path: /tmp/dist-test-taskxHIKYo/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515563725526-31713-0/minicluster-data/ts-0-root/wals/6d45f86d36f5456aa24f014a1997e1fd/wal-000000035 (ops 170-174)
I20260812 06:19:28.684789 31889 log.cc:1079] T 6d45f86d36f5456aa24f014a1997e1fd P 7f5b3a28cb1e413d9865c25ed19ec248: Deleting log segment in path: /tmp/dist-test-taskxHIKYo/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515563725526-31713-0/minicluster-data/ts-0-root/wals/6d45f86d36f5456aa24f014a1997e1fd/wal-000000036 (ops 175-179)
I20260812 06:19:28.684818 31889 log.cc:1079] T 6d45f86d36f5456aa24f014a1997e1fd P 7f5b3a28cb1e413d9865c25ed19ec248: Deleting log segment in path: /tmp/dist-test-taskxHIKYo/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515563725526-31713-0/minicluster-data/ts-0-root/wals/6d45f86d36f5456aa24f014a1997e1fd/wal-000000037 (ops 180-184)
I20260812 06:19:28.684845 31889 log.cc:1079] T 6d45f86d36f5456aa24f014a1997e1fd P 7f5b3a28cb1e413d9865c25ed19ec248: Deleting log segment in path: /tmp/dist-test-taskxHIKYo/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515563725526-31713-0/minicluster-data/ts-0-root/wals/6d45f86d36f5456aa24f014a1997e1fd/wal-000000038 (ops 185-189)
I20260812 06:19:28.715842 31889 maintenance_manager.cc:643] P 7f5b3a28cb1e413d9865c25ed19ec248: LogGCOp(6d45f86d36f5456aa24f014a1997e1fd) complete. Timing: real 0.031s	user 0.000s	sys 0.028s Metrics: {}
I20260812 06:19:28.719703 31993 maintenance_manager.cc:419] P 7f5b3a28cb1e413d9865c25ed19ec248: Scheduling UndoDeltaBlockGCOp(6d45f86d36f5456aa24f014a1997e1fd): 492 bytes on disk
I20260812 06:19:28.720329 31889 maintenance_manager.cc:643] P 7f5b3a28cb1e413d9865c25ed19ec248: UndoDeltaBlockGCOp(6d45f86d36f5456aa24f014a1997e1fd) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":68,"lbm_reads_lt_1ms":4}
I20260812 06:19:28.720983 31993 maintenance_manager.cc:419] P 7f5b3a28cb1e413d9865c25ed19ec248: Scheduling FlushDeltaMemStoresOp(6d45f86d36f5456aa24f014a1997e1fd): perf score=2.188937
I20260812 06:19:28.743034 31889 maintenance_manager.cc:643] P 7f5b3a28cb1e413d9865c25ed19ec248: FlushDeltaMemStoresOp(6d45f86d36f5456aa24f014a1997e1fd) complete. Timing: real 0.022s	user 0.011s	sys 0.004s Metrics: {"bytes_written":4143683,"delete_count":0,"lbm_write_time_us":6652,"lbm_writes_lt_1ms":104,"reinsert_count":0,"update_count":505}
I20260812 06:19:28.743506 31993 maintenance_manager.cc:419] P 7f5b3a28cb1e413d9865c25ed19ec248: Scheduling FlushDeltaMemStoresOp(6d45f86d36f5456aa24f014a1997e1fd): perf score=2.188937
I20260812 06:19:28.753423 31889 maintenance_manager.cc:643] P 7f5b3a28cb1e413d9865c25ed19ec248: FlushDeltaMemStoresOp(6d45f86d36f5456aa24f014a1997e1fd) complete. Timing: real 0.010s	user 0.000s	sys 0.008s Metrics: {"bytes_written":4061634,"delete_count":0,"lbm_write_time_us":3960,"lbm_writes_lt_1ms":102,"reinsert_count":0,"update_count":495}
I20260812 06:19:28.753907 31993 maintenance_manager.cc:419] P 7f5b3a28cb1e413d9865c25ed19ec248: Scheduling MajorDeltaCompactionOp(6d45f86d36f5456aa24f014a1997e1fd): perf score=1.000000
I20260812 06:19:28.877082 31713 heavy-update-compaction-itest.cc:229] Time spent updating: real 4.852s	user 1.755s	sys 0.159s
I20260812 06:19:28.950515 31889 maintenance_manager.cc:643] P 7f5b3a28cb1e413d9865c25ed19ec248: MajorDeltaCompactionOp(6d45f86d36f5456aa24f014a1997e1fd) complete. Timing: real 0.196s	user 0.152s	sys 0.043s Metrics: {"cfile_cache_miss":735,"cfile_cache_miss_bytes":32979860,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":5,"delta_iterators_relevant":5,"lbm_read_time_us":14937,"lbm_reads_lt_1ms":771,"lbm_write_time_us":34674,"lbm_writes_lt_1ms":743,"peak_mem_usage":87969044,"reinsert_count":0,"spinlock_wait_cycles":768,"update_count":3500}
I20260812 06:19:28.951058 31993 maintenance_manager.cc:419] P 7f5b3a28cb1e413d9865c25ed19ec248: Scheduling FlushDeltaMemStoresOp(6d45f86d36f5456aa24f014a1997e1fd): perf score=10.126437
I20260812 06:19:28.965991 31713 heavy-update-compaction-itest.cc:265] Time spent scanning: real 0.088s	user 0.002s	sys 0.000s
I20260812 06:19:28.966614 31713 tablet_server.cc:179] TabletServer@127.30.248.65:0 shutting down...
I20260812 06:19:28.994760 31889 maintenance_manager.cc:643] P 7f5b3a28cb1e413d9865c25ed19ec248: FlushDeltaMemStoresOp(6d45f86d36f5456aa24f014a1997e1fd) complete. Timing: real 0.044s	user 0.016s	sys 0.025s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":15384,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:19:28.995368 31713 ts_tablet_manager.cc:1507] Shutting down tablet manager...
I20260812 06:19:28.995798 31713 tablet_replica.cc:333] T 6d45f86d36f5456aa24f014a1997e1fd P 7f5b3a28cb1e413d9865c25ed19ec248: stopping tablet replica
I20260812 06:19:28.995996 31713 raft_consensus.cc:2243] T 6d45f86d36f5456aa24f014a1997e1fd P 7f5b3a28cb1e413d9865c25ed19ec248 [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:19:28.996243 31713 raft_consensus.cc:2272] T 6d45f86d36f5456aa24f014a1997e1fd P 7f5b3a28cb1e413d9865c25ed19ec248 [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:19:29.010803 31713 tablet_server.cc:196] TabletServer@127.30.248.65:0 shutdown complete.
I20260812 06:19:29.015446 31713 master.cc:562] Master@127.30.248.126:41555 shutting down...
I20260812 06:19:29.019291 31713 raft_consensus.cc:2243] T 00000000000000000000000000000000 P 35494638c05e4bba86f27cefed98d86b [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:19:29.019439 31713 raft_consensus.cc:2272] T 00000000000000000000000000000000 P 35494638c05e4bba86f27cefed98d86b [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:19:29.019500 31713 tablet_replica.cc:333] T 00000000000000000000000000000000 P 35494638c05e4bba86f27cefed98d86b: stopping tablet replica
I20260812 06:19:29.031924 31713 master.cc:584] Master@127.30.248.126:41555 shutdown complete.
[       OK ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/0 (5385 ms)
[ RUN      ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/1
I20260812 06:19:29.121541 31713 internal_mini_cluster.cc:156] Creating distributed mini masters. Addrs: 127.30.248.126:44711
I20260812 06:19:29.121909 31713 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:19:29.123965 32041 instance_detector.cc:116] could not retrieve Azure instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:19:29.124053 31713 server_base.cc:1061] running on GCE node
W20260812 06:19:29.123997 32040 instance_detector.cc:116] could not retrieve AWS instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:19:29.123986 32043 instance_detector.cc:116] could not retrieve OpenStack instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:19:29.124409 31713 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:19:29.124469 31713 system_unsync_time.cc:38] NTP support is disabled. Clock error bounds will not be accurate. This configuration is not suitable for distributed clusters.
I20260812 06:19:29.124514 31713 hybrid_clock.cc:648] HybridClock initialized: now 1786515569124513 us; error 0 us; skew 500 ppm
I20260812 06:19:29.125336 31713 webserver.cc:533] Webserver started at http://127.30.248.126:34415/ using document root <none> and password file <none>
I20260812 06:19:29.125510 31713 fs_manager.cc:362] Metadata directory not provided
I20260812 06:19:29.125578 31713 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:19:29.125658 31713 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:19:29.126048 31713 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskxHIKYo/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515563725526-31713-0/minicluster-data/master-0-root/instance:
uuid: "78c07787eee742259ac385c8a94fcf01"
format_stamp: "Formatted at 2026-08-12 06:19:29 on dist-test-slave-gmjp"
I20260812 06:19:29.127594 31713 fs_manager.cc:696] Time spent creating directory manager: real 0.001s	user 0.000s	sys 0.002s
I20260812 06:19:29.128611 32054 log_block_manager.cc:4127] Time spent loading block containers with low live blocks: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:19:29.128830 31713 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.000s	sys 0.000s
I20260812 06:19:29.128916 31713 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskxHIKYo/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515563725526-31713-0/minicluster-data/master-0-root
uuid: "78c07787eee742259ac385c8a94fcf01"
format_stamp: "Formatted at 2026-08-12 06:19:29 on dist-test-slave-gmjp"
I20260812 06:19:29.129009 31713 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskxHIKYo/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515563725526-31713-0/minicluster-data/master-0-root
metadata directory: /tmp/dist-test-taskxHIKYo/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515563725526-31713-0/minicluster-data/master-0-root
1 data directories: /tmp/dist-test-taskxHIKYo/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515563725526-31713-0/minicluster-data/master-0-root/data
Total live blocks: 0
Total live bytes: 0
Total live bytes (after alignment): 0
Total number of LBM containers: 0 (0 full)
Did not check for missing blocks
Did not check for orphaned blocks
Total full LBM containers with extra space: 0 (0 repaired)
Total full LBM container extra space in bytes: 0 (0 repaired)
Total incomplete LBM containers: 0 (0 repaired)
Total LBM partial records: 0 (0 repaired)
Total corrupted LBM metadata records in RocksDB: 0 (0 repaired)
I20260812 06:19:29.141582 31713 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:19:29.141939 31713 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:19:29.146299 31713 rpc_server.cc:307] RPC server started. Bound to: 127.30.248.126:44711
I20260812 06:19:29.152737 32145 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.30.248.126:44711 every 8 connection(s)
I20260812 06:19:29.156107 32147 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet 00000000000000000000000000000000. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:19:29.157994 32147 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P 78c07787eee742259ac385c8a94fcf01: Bootstrap starting.
I20260812 06:19:29.158792 32147 tablet_bootstrap.cc:654] T 00000000000000000000000000000000 P 78c07787eee742259ac385c8a94fcf01: Neither blocks nor log segments found. Creating new log.
I20260812 06:19:29.159793 32147 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P 78c07787eee742259ac385c8a94fcf01: No bootstrap required, opened a new log
I20260812 06:19:29.160244 32147 raft_consensus.cc:359] T 00000000000000000000000000000000 P 78c07787eee742259ac385c8a94fcf01 [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "78c07787eee742259ac385c8a94fcf01" member_type: VOTER }
I20260812 06:19:29.160331 32147 raft_consensus.cc:385] T 00000000000000000000000000000000 P 78c07787eee742259ac385c8a94fcf01 [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:19:29.160389 32147 raft_consensus.cc:740] T 00000000000000000000000000000000 P 78c07787eee742259ac385c8a94fcf01 [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: 78c07787eee742259ac385c8a94fcf01, State: Initialized, Role: FOLLOWER
I20260812 06:19:29.160557 32147 consensus_queue.cc:260] T 00000000000000000000000000000000 P 78c07787eee742259ac385c8a94fcf01 [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: "78c07787eee742259ac385c8a94fcf01" member_type: VOTER }
I20260812 06:19:29.160630 32147 raft_consensus.cc:399] T 00000000000000000000000000000000 P 78c07787eee742259ac385c8a94fcf01 [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:19:29.160696 32147 raft_consensus.cc:493] T 00000000000000000000000000000000 P 78c07787eee742259ac385c8a94fcf01 [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:19:29.160765 32147 raft_consensus.cc:3060] T 00000000000000000000000000000000 P 78c07787eee742259ac385c8a94fcf01 [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:19:29.161440 32147 raft_consensus.cc:515] T 00000000000000000000000000000000 P 78c07787eee742259ac385c8a94fcf01 [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "78c07787eee742259ac385c8a94fcf01" member_type: VOTER }
I20260812 06:19:29.161584 32147 leader_election.cc:304] T 00000000000000000000000000000000 P 78c07787eee742259ac385c8a94fcf01 [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: 78c07787eee742259ac385c8a94fcf01; no voters: 
I20260812 06:19:29.161784 32147 leader_election.cc:290] T 00000000000000000000000000000000 P 78c07787eee742259ac385c8a94fcf01 [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:19:29.161988 32152 raft_consensus.cc:2804] T 00000000000000000000000000000000 P 78c07787eee742259ac385c8a94fcf01 [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:19:29.162245 32152 raft_consensus.cc:697] T 00000000000000000000000000000000 P 78c07787eee742259ac385c8a94fcf01 [term 1 LEADER]: Becoming Leader. State: Replica: 78c07787eee742259ac385c8a94fcf01, State: Running, Role: LEADER
I20260812 06:19:29.162328 32147 sys_catalog.cc:565] T 00000000000000000000000000000000 P 78c07787eee742259ac385c8a94fcf01 [sys.catalog]: configured and running, proceeding with master startup.
I20260812 06:19:29.162392 32152 consensus_queue.cc:237] T 00000000000000000000000000000000 P 78c07787eee742259ac385c8a94fcf01 [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: "78c07787eee742259ac385c8a94fcf01" member_type: VOTER }
I20260812 06:19:29.162918 32155 sys_catalog.cc:455] T 00000000000000000000000000000000 P 78c07787eee742259ac385c8a94fcf01 [sys.catalog]: SysCatalogTable state changed. Reason: New leader 78c07787eee742259ac385c8a94fcf01. Latest consensus state: current_term: 1 leader_uuid: "78c07787eee742259ac385c8a94fcf01" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "78c07787eee742259ac385c8a94fcf01" member_type: VOTER } }
I20260812 06:19:29.163010 32155 sys_catalog.cc:458] T 00000000000000000000000000000000 P 78c07787eee742259ac385c8a94fcf01 [sys.catalog]: This master's current role is: LEADER
I20260812 06:19:29.162899 32154 sys_catalog.cc:455] T 00000000000000000000000000000000 P 78c07787eee742259ac385c8a94fcf01 [sys.catalog]: SysCatalogTable state changed. Reason: RaftConsensus started. Latest consensus state: current_term: 1 leader_uuid: "78c07787eee742259ac385c8a94fcf01" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "78c07787eee742259ac385c8a94fcf01" member_type: VOTER } }
I20260812 06:19:29.163132 32154 sys_catalog.cc:458] T 00000000000000000000000000000000 P 78c07787eee742259ac385c8a94fcf01 [sys.catalog]: This master's current role is: LEADER
I20260812 06:19:29.163590 32161 catalog_manager.cc:1511] Loading table and tablet metadata into memory...
I20260812 06:19:29.164664 32161 catalog_manager.cc:1520] Initializing Kudu cluster ID...
I20260812 06:19:29.164862 31713 internal_mini_cluster.cc:184] Waiting to initialize catalog manager on master 0
I20260812 06:19:29.166455 32161 catalog_manager.cc:1383] Generated new cluster ID: 53d9b39135c14f0d9c8ad3cc8c82843e
I20260812 06:19:29.166513 32161 catalog_manager.cc:1531] Initializing Kudu internal certificate authority...
I20260812 06:19:29.192529 32161 catalog_manager.cc:1406] Generated new certificate authority record
I20260812 06:19:29.193128 32161 catalog_manager.cc:1540] Loading token signing keys...
I20260812 06:19:29.202241 32161 catalog_manager.cc:6092] T 00000000000000000000000000000000 P 78c07787eee742259ac385c8a94fcf01: Generated new TSK 0
I20260812 06:19:29.202419 32161 catalog_manager.cc:1550] Initializing in-progress tserver states...
I20260812 06:19:29.229481 31713 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:19:29.231460 32182 instance_detector.cc:116] could not retrieve Azure instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:19:29.231567 32192 instance_detector.cc:116] could not retrieve OpenStack instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:19:29.231567 32179 instance_detector.cc:116] could not retrieve AWS instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:19:29.231642 31713 server_base.cc:1061] running on GCE node
I20260812 06:19:29.231904 31713 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:19:29.231976 31713 system_unsync_time.cc:38] NTP support is disabled. Clock error bounds will not be accurate. This configuration is not suitable for distributed clusters.
I20260812 06:19:29.232012 31713 hybrid_clock.cc:648] HybridClock initialized: now 1786515569232010 us; error 0 us; skew 500 ppm
I20260812 06:19:29.232973 31713 webserver.cc:533] Webserver started at http://127.30.248.65:34809/ using document root <none> and password file <none>
I20260812 06:19:29.233167 31713 fs_manager.cc:362] Metadata directory not provided
I20260812 06:19:29.233244 31713 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:19:29.233327 31713 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:19:29.233743 31713 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskxHIKYo/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515563725526-31713-0/minicluster-data/ts-0-root/instance:
uuid: "3ef58559e19d47278ac2732524ec1e1d"
format_stamp: "Formatted at 2026-08-12 06:19:29 on dist-test-slave-gmjp"
I20260812 06:19:29.235265 31713 fs_manager.cc:696] Time spent creating directory manager: real 0.001s	user 0.000s	sys 0.002s
I20260812 06:19:29.236128 32203 log_block_manager.cc:4127] Time spent loading block containers with low live blocks: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:19:29.236433 31713 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.000s	sys 0.001s
I20260812 06:19:29.236521 31713 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskxHIKYo/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515563725526-31713-0/minicluster-data/ts-0-root
uuid: "3ef58559e19d47278ac2732524ec1e1d"
format_stamp: "Formatted at 2026-08-12 06:19:29 on dist-test-slave-gmjp"
I20260812 06:19:29.236605 31713 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskxHIKYo/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515563725526-31713-0/minicluster-data/ts-0-root
metadata directory: /tmp/dist-test-taskxHIKYo/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515563725526-31713-0/minicluster-data/ts-0-root
1 data directories: /tmp/dist-test-taskxHIKYo/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515563725526-31713-0/minicluster-data/ts-0-root/data
Total live blocks: 0
Total live bytes: 0
Total live bytes (after alignment): 0
Total number of LBM containers: 0 (0 full)
Did not check for missing blocks
Did not check for orphaned blocks
Total full LBM containers with extra space: 0 (0 repaired)
Total full LBM container extra space in bytes: 0 (0 repaired)
Total incomplete LBM containers: 0 (0 repaired)
Total LBM partial records: 0 (0 repaired)
Total corrupted LBM metadata records in RocksDB: 0 (0 repaired)
I20260812 06:19:29.246062 31713 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:19:29.246404 31713 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:19:29.246685 31713 txn_system_client.cc:432] TxnSystemClient initialization is disabled...
I20260812 06:19:29.247159 31713 ts_tablet_manager.cc:585] Loaded tablet metadata (0 total tablets, 0 live tablets)
I20260812 06:19:29.247217 31713 ts_tablet_manager.cc:531] Time spent load tablet metadata: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:19:29.247284 31713 ts_tablet_manager.cc:616] Registered 0 tablets
I20260812 06:19:29.247323 31713 ts_tablet_manager.cc:595] Time spent register tablets: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:19:29.251556 31713 rpc_server.cc:307] RPC server started. Bound to: 127.30.248.65:39383
I20260812 06:19:29.251848 32307 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.30.248.65:39383 every 8 connection(s)
I20260812 06:19:29.259441 32308 heartbeater.cc:344] Connected to a master server at 127.30.248.126:44711
I20260812 06:19:29.259559 32308 heartbeater.cc:461] Registering TS with master...
I20260812 06:19:29.259791 32308 heartbeater.cc:507] Master 127.30.248.126:44711 requested a full tablet report, sending...
I20260812 06:19:29.260471 32084 ts_manager.cc:194] Registered new tserver with Master: 3ef58559e19d47278ac2732524ec1e1d (127.30.248.65:39383)
I20260812 06:19:29.260993 31713 internal_mini_cluster.cc:371] 1 TS(s) registered with all masters after 0.00885525s
I20260812 06:19:29.261219 32084 master_service.cc:502] Signed X509 certificate for tserver {username='slave'} at 127.0.0.1:58166
I20260812 06:19:29.267705 32084 catalog_manager.cc:2283] Servicing CreateTable request from {username='slave'} at 127.0.0.1:58176:
name: "heavy-update-compaction-test"
schema {
  columns {
    name: "key"
    type: INT64
    is_key: true
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_a"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_b"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_c"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_d"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_e"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
}
num_replicas: 1
split_rows_range_bounds {
}
partition_schema {
  range_schema {
  }
}
I20260812 06:19:29.276008 32254 tablet_service.cc:1511] Processing CreateTablet for tablet c2199a23569a4f65be07587196ce5df1 (DEFAULT_TABLE table=heavy-update-compaction-test [id=f024d68929594c7c937a5bed7bae04cb]), partition=
I20260812 06:19:29.276317 32254 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet c2199a23569a4f65be07587196ce5df1. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:19:29.278268 32329 tablet_bootstrap.cc:492] T c2199a23569a4f65be07587196ce5df1 P 3ef58559e19d47278ac2732524ec1e1d: Bootstrap starting.
I20260812 06:19:29.279191 32329 tablet_bootstrap.cc:654] T c2199a23569a4f65be07587196ce5df1 P 3ef58559e19d47278ac2732524ec1e1d: Neither blocks nor log segments found. Creating new log.
I20260812 06:19:29.280292 32329 tablet_bootstrap.cc:492] T c2199a23569a4f65be07587196ce5df1 P 3ef58559e19d47278ac2732524ec1e1d: No bootstrap required, opened a new log
I20260812 06:19:29.280411 32329 ts_tablet_manager.cc:1403] T c2199a23569a4f65be07587196ce5df1 P 3ef58559e19d47278ac2732524ec1e1d: Time spent bootstrapping tablet: real 0.002s	user 0.002s	sys 0.000s
I20260812 06:19:29.280833 32329 raft_consensus.cc:359] T c2199a23569a4f65be07587196ce5df1 P 3ef58559e19d47278ac2732524ec1e1d [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "3ef58559e19d47278ac2732524ec1e1d" member_type: VOTER last_known_addr { host: "127.30.248.65" port: 39383 } }
I20260812 06:19:29.280920 32329 raft_consensus.cc:385] T c2199a23569a4f65be07587196ce5df1 P 3ef58559e19d47278ac2732524ec1e1d [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:19:29.280982 32329 raft_consensus.cc:740] T c2199a23569a4f65be07587196ce5df1 P 3ef58559e19d47278ac2732524ec1e1d [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: 3ef58559e19d47278ac2732524ec1e1d, State: Initialized, Role: FOLLOWER
I20260812 06:19:29.281142 32329 consensus_queue.cc:260] T c2199a23569a4f65be07587196ce5df1 P 3ef58559e19d47278ac2732524ec1e1d [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: "3ef58559e19d47278ac2732524ec1e1d" member_type: VOTER last_known_addr { host: "127.30.248.65" port: 39383 } }
I20260812 06:19:29.281240 32329 raft_consensus.cc:399] T c2199a23569a4f65be07587196ce5df1 P 3ef58559e19d47278ac2732524ec1e1d [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:19:29.281291 32329 raft_consensus.cc:493] T c2199a23569a4f65be07587196ce5df1 P 3ef58559e19d47278ac2732524ec1e1d [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:19:29.281353 32329 raft_consensus.cc:3060] T c2199a23569a4f65be07587196ce5df1 P 3ef58559e19d47278ac2732524ec1e1d [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:19:29.282199 32329 raft_consensus.cc:515] T c2199a23569a4f65be07587196ce5df1 P 3ef58559e19d47278ac2732524ec1e1d [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "3ef58559e19d47278ac2732524ec1e1d" member_type: VOTER last_known_addr { host: "127.30.248.65" port: 39383 } }
I20260812 06:19:29.282346 32329 leader_election.cc:304] T c2199a23569a4f65be07587196ce5df1 P 3ef58559e19d47278ac2732524ec1e1d [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: 3ef58559e19d47278ac2732524ec1e1d; no voters: 
I20260812 06:19:29.282572 32329 leader_election.cc:290] T c2199a23569a4f65be07587196ce5df1 P 3ef58559e19d47278ac2732524ec1e1d [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:19:29.282680 32331 raft_consensus.cc:2804] T c2199a23569a4f65be07587196ce5df1 P 3ef58559e19d47278ac2732524ec1e1d [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:19:29.282902 32329 ts_tablet_manager.cc:1434] T c2199a23569a4f65be07587196ce5df1 P 3ef58559e19d47278ac2732524ec1e1d: Time spent starting tablet: real 0.002s	user 0.003s	sys 0.000s
I20260812 06:19:29.282899 32308 heartbeater.cc:499] Master 127.30.248.126:44711 was elected leader, sending a full tablet report...
I20260812 06:19:29.282898 32331 raft_consensus.cc:697] T c2199a23569a4f65be07587196ce5df1 P 3ef58559e19d47278ac2732524ec1e1d [term 1 LEADER]: Becoming Leader. State: Replica: 3ef58559e19d47278ac2732524ec1e1d, State: Running, Role: LEADER
I20260812 06:19:29.283298 32331 consensus_queue.cc:237] T c2199a23569a4f65be07587196ce5df1 P 3ef58559e19d47278ac2732524ec1e1d [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: "3ef58559e19d47278ac2732524ec1e1d" member_type: VOTER last_known_addr { host: "127.30.248.65" port: 39383 } }
I20260812 06:19:29.284593 32084 catalog_manager.cc:5719] T c2199a23569a4f65be07587196ce5df1 P 3ef58559e19d47278ac2732524ec1e1d reported cstate change: term changed from 0 to 1, leader changed from <none> to 3ef58559e19d47278ac2732524ec1e1d (127.30.248.65). New cstate: current_term: 1 leader_uuid: "3ef58559e19d47278ac2732524ec1e1d" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "3ef58559e19d47278ac2732524ec1e1d" member_type: VOTER last_known_addr { host: "127.30.248.65" port: 39383 } health_report { overall_health: HEALTHY } } }
I20260812 06:19:29.341581 31713 heavy-update-compaction-itest.cc:215] Time spent inserting: real 0.050s	user 0.011s	sys 0.010s
I20260812 06:19:29.502600 32310 maintenance_manager.cc:419] P 3ef58559e19d47278ac2732524ec1e1d: Scheduling FlushMRSOp(c2199a23569a4f65be07587196ce5df1): perf score=23.023690
I20260812 06:19:29.666812 32210 maintenance_manager.cc:643] P 3ef58559e19d47278ac2732524ec1e1d: FlushMRSOp(c2199a23569a4f65be07587196ce5df1) complete. Timing: real 0.164s	user 0.119s	sys 0.040s Metrics: {"bytes_written":12307491,"cfile_init":1,"delete_count":0,"dirs.queue_time_us":78,"dirs.run_cpu_time_us":210,"dirs.run_wall_time_us":766,"drs_written":1,"lbm_read_time_us":38,"lbm_reads_lt_1ms":4,"lbm_write_time_us":45641,"lbm_writes_lt_1ms":857,"peak_mem_usage":0,"reinsert_count":0,"rows_written":105,"update_count":1500}
I20260812 06:19:29.667390 32310 maintenance_manager.cc:419] P 3ef58559e19d47278ac2732524ec1e1d: Scheduling LogGCOp(c2199a23569a4f65be07587196ce5df1): free 20743831 bytes of WAL
I20260812 06:19:29.667609 32210 log_reader.cc:385] T c2199a23569a4f65be07587196ce5df1: removed 2 log segments from log reader
I20260812 06:19:29.667654 32210 log.cc:1079] T c2199a23569a4f65be07587196ce5df1 P 3ef58559e19d47278ac2732524ec1e1d: Deleting log segment in path: /tmp/dist-test-taskxHIKYo/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515563725526-31713-0/minicluster-data/ts-0-root/wals/c2199a23569a4f65be07587196ce5df1/wal-000000001 (ops 1-6)
I20260812 06:19:29.667701 32210 log.cc:1079] T c2199a23569a4f65be07587196ce5df1 P 3ef58559e19d47278ac2732524ec1e1d: Deleting log segment in path: /tmp/dist-test-taskxHIKYo/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515563725526-31713-0/minicluster-data/ts-0-root/wals/c2199a23569a4f65be07587196ce5df1/wal-000000002 (ops 7-11)
I20260812 06:19:29.671998 32210 maintenance_manager.cc:643] P 3ef58559e19d47278ac2732524ec1e1d: LogGCOp(c2199a23569a4f65be07587196ce5df1) complete. Timing: real 0.004s	user 0.000s	sys 0.001s Metrics: {}
I20260812 06:19:29.672371 32310 maintenance_manager.cc:419] P 3ef58559e19d47278ac2732524ec1e1d: Scheduling FlushDeltaMemStoresOp(c2199a23569a4f65be07587196ce5df1): perf score=2.188937
I20260812 06:19:29.689853 32210 maintenance_manager.cc:643] P 3ef58559e19d47278ac2732524ec1e1d: FlushDeltaMemStoresOp(c2199a23569a4f65be07587196ce5df1) complete. Timing: real 0.017s	user 0.009s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6016,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:29.690331 32310 maintenance_manager.cc:419] P 3ef58559e19d47278ac2732524ec1e1d: Scheduling UndoDeltaBlockGCOp(c2199a23569a4f65be07587196ce5df1): 20513815 bytes on disk
I20260812 06:19:29.690703 32210 maintenance_manager.cc:643] P 3ef58559e19d47278ac2732524ec1e1d: UndoDeltaBlockGCOp(c2199a23569a4f65be07587196ce5df1) 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:19:29.691092 32310 maintenance_manager.cc:419] P 3ef58559e19d47278ac2732524ec1e1d: Scheduling MajorDeltaCompactionOp(c2199a23569a4f65be07587196ce5df1): perf score=1.000000
I20260812 06:19:29.832196 32210 maintenance_manager.cc:643] P 3ef58559e19d47278ac2732524ec1e1d: MajorDeltaCompactionOp(c2199a23569a4f65be07587196ce5df1) complete. Timing: real 0.141s	user 0.097s	sys 0.034s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20713273,"cfile_init":7,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":886,"lbm_read_time_us":9247,"lbm_reads_lt_1ms":460,"lbm_write_time_us":22679,"lbm_writes_lt_1ms":443,"mutex_wait_us":38,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":2688,"thread_start_us":339,"threads_started":5,"update_count":2000}
I20260812 06:19:29.832732 32310 maintenance_manager.cc:419] P 3ef58559e19d47278ac2732524ec1e1d: Scheduling FlushDeltaMemStoresOp(c2199a23569a4f65be07587196ce5df1): perf score=14.095187
I20260812 06:19:29.889645 32210 maintenance_manager.cc:643] P 3ef58559e19d47278ac2732524ec1e1d: FlushDeltaMemStoresOp(c2199a23569a4f65be07587196ce5df1) complete. Timing: real 0.057s	user 0.028s	sys 0.016s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":20008,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:29.890164 32310 maintenance_manager.cc:419] P 3ef58559e19d47278ac2732524ec1e1d: Scheduling FlushDeltaMemStoresOp(c2199a23569a4f65be07587196ce5df1): perf score=2.188937
I20260812 06:19:29.901301 32210 maintenance_manager.cc:643] P 3ef58559e19d47278ac2732524ec1e1d: FlushDeltaMemStoresOp(c2199a23569a4f65be07587196ce5df1) complete. Timing: real 0.011s	user 0.000s	sys 0.009s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3999,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:29.901943 32310 maintenance_manager.cc:419] P 3ef58559e19d47278ac2732524ec1e1d: Scheduling MajorDeltaCompactionOp(c2199a23569a4f65be07587196ce5df1): perf score=1.000000
I20260812 06:19:30.076277 32210 maintenance_manager.cc:643] P 3ef58559e19d47278ac2732524ec1e1d: MajorDeltaCompactionOp(c2199a23569a4f65be07587196ce5df1) complete. Timing: real 0.174s	user 0.103s	sys 0.071s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24815683,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":1054,"lbm_read_time_us":12175,"lbm_reads_lt_1ms":572,"lbm_write_time_us":28562,"lbm_writes_lt_1ms":543,"mutex_wait_us":278,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":8320,"update_count":2500}
I20260812 06:19:30.076989 32310 maintenance_manager.cc:419] P 3ef58559e19d47278ac2732524ec1e1d: Scheduling FlushDeltaMemStoresOp(c2199a23569a4f65be07587196ce5df1): perf score=14.095187
I20260812 06:19:30.134296 32210 maintenance_manager.cc:643] P 3ef58559e19d47278ac2732524ec1e1d: FlushDeltaMemStoresOp(c2199a23569a4f65be07587196ce5df1) complete. Timing: real 0.057s	user 0.041s	sys 0.006s Metrics: {"bytes_written":16409903,"delete_count":0,"lbm_write_time_us":21670,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:30.134859 32310 maintenance_manager.cc:419] P 3ef58559e19d47278ac2732524ec1e1d: Scheduling FlushDeltaMemStoresOp(c2199a23569a4f65be07587196ce5df1): perf score=2.188937
I20260812 06:19:30.146848 32210 maintenance_manager.cc:643] P 3ef58559e19d47278ac2732524ec1e1d: FlushDeltaMemStoresOp(c2199a23569a4f65be07587196ce5df1) complete. Timing: real 0.012s	user 0.005s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4145,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:30.147480 32310 maintenance_manager.cc:419] P 3ef58559e19d47278ac2732524ec1e1d: Scheduling MajorDeltaCompactionOp(c2199a23569a4f65be07587196ce5df1): perf score=1.000000
I20260812 06:19:30.316562 32210 maintenance_manager.cc:643] P 3ef58559e19d47278ac2732524ec1e1d: MajorDeltaCompactionOp(c2199a23569a4f65be07587196ce5df1) complete. Timing: real 0.169s	user 0.096s	sys 0.072s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24815685,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":1275,"lbm_read_time_us":11474,"lbm_reads_lt_1ms":572,"lbm_write_time_us":30133,"lbm_writes_lt_1ms":543,"mutex_wait_us":489,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":14336,"update_count":2500}
I20260812 06:19:30.317215 32310 maintenance_manager.cc:419] P 3ef58559e19d47278ac2732524ec1e1d: Scheduling FlushDeltaMemStoresOp(c2199a23569a4f65be07587196ce5df1): perf score=14.095187
I20260812 06:19:30.374998 32210 maintenance_manager.cc:643] P 3ef58559e19d47278ac2732524ec1e1d: FlushDeltaMemStoresOp(c2199a23569a4f65be07587196ce5df1) complete. Timing: real 0.058s	user 0.039s	sys 0.004s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":18723,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:30.375594 32310 maintenance_manager.cc:419] P 3ef58559e19d47278ac2732524ec1e1d: Scheduling FlushDeltaMemStoresOp(c2199a23569a4f65be07587196ce5df1): perf score=2.188937
I20260812 06:19:30.386226 32210 maintenance_manager.cc:643] P 3ef58559e19d47278ac2732524ec1e1d: FlushDeltaMemStoresOp(c2199a23569a4f65be07587196ce5df1) complete. Timing: real 0.010s	user 0.009s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4056,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:30.386646 32310 maintenance_manager.cc:419] P 3ef58559e19d47278ac2732524ec1e1d: Scheduling MajorDeltaCompactionOp(c2199a23569a4f65be07587196ce5df1): perf score=1.000000
I20260812 06:19:30.578472 32210 maintenance_manager.cc:643] P 3ef58559e19d47278ac2732524ec1e1d: MajorDeltaCompactionOp(c2199a23569a4f65be07587196ce5df1) complete. Timing: real 0.192s	user 0.132s	sys 0.056s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24815683,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":556,"lbm_read_time_us":11206,"lbm_reads_lt_1ms":572,"lbm_write_time_us":30893,"lbm_writes_lt_1ms":543,"mutex_wait_us":243,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":896,"update_count":2500}
I20260812 06:19:30.578984 32310 maintenance_manager.cc:419] P 3ef58559e19d47278ac2732524ec1e1d: Scheduling FlushDeltaMemStoresOp(c2199a23569a4f65be07587196ce5df1): perf score=14.095187
I20260812 06:19:30.633543 32210 maintenance_manager.cc:643] P 3ef58559e19d47278ac2732524ec1e1d: FlushDeltaMemStoresOp(c2199a23569a4f65be07587196ce5df1) complete. Timing: real 0.054s	user 0.027s	sys 0.023s Metrics: {"bytes_written":16409898,"delete_count":0,"lbm_write_time_us":18100,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:30.633989 32310 maintenance_manager.cc:419] P 3ef58559e19d47278ac2732524ec1e1d: Scheduling FlushDeltaMemStoresOp(c2199a23569a4f65be07587196ce5df1): perf score=2.188937
I20260812 06:19:30.644531 32210 maintenance_manager.cc:643] P 3ef58559e19d47278ac2732524ec1e1d: FlushDeltaMemStoresOp(c2199a23569a4f65be07587196ce5df1) complete. Timing: real 0.010s	user 0.006s	sys 0.004s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4180,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:30.644887 32310 maintenance_manager.cc:419] P 3ef58559e19d47278ac2732524ec1e1d: Scheduling MajorDeltaCompactionOp(c2199a23569a4f65be07587196ce5df1): perf score=1.000000
I20260812 06:19:30.816991 32210 maintenance_manager.cc:643] P 3ef58559e19d47278ac2732524ec1e1d: MajorDeltaCompactionOp(c2199a23569a4f65be07587196ce5df1) complete. Timing: real 0.172s	user 0.136s	sys 0.035s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24815679,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":888,"lbm_read_time_us":11926,"lbm_reads_lt_1ms":572,"lbm_write_time_us":28579,"lbm_writes_lt_1ms":543,"mutex_wait_us":325,"peak_mem_usage":63115900,"reinsert_count":0,"update_count":2500}
I20260812 06:19:30.817735 32310 maintenance_manager.cc:419] P 3ef58559e19d47278ac2732524ec1e1d: Scheduling FlushDeltaMemStoresOp(c2199a23569a4f65be07587196ce5df1): perf score=11.118625
I20260812 06:19:30.849370 32210 maintenance_manager.cc:643] P 3ef58559e19d47278ac2732524ec1e1d: FlushDeltaMemStoresOp(c2199a23569a4f65be07587196ce5df1) complete. Timing: real 0.031s	user 0.027s	sys 0.003s Metrics: {"bytes_written":12717735,"delete_count":0,"lbm_write_time_us":12949,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:19:30.849858 32310 maintenance_manager.cc:419] P 3ef58559e19d47278ac2732524ec1e1d: Scheduling FlushDeltaMemStoresOp(c2199a23569a4f65be07587196ce5df1): perf score=2.188937
I20260812 06:19:30.884414 32210 maintenance_manager.cc:643] P 3ef58559e19d47278ac2732524ec1e1d: FlushDeltaMemStoresOp(c2199a23569a4f65be07587196ce5df1) complete. Timing: real 0.034s	user 0.012s	sys 0.011s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":5393,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:19:30.884903 32310 maintenance_manager.cc:419] P 3ef58559e19d47278ac2732524ec1e1d: Scheduling FlushDeltaMemStoresOp(c2199a23569a4f65be07587196ce5df1): perf score=2.188937
I20260812 06:19:30.895417 32210 maintenance_manager.cc:643] P 3ef58559e19d47278ac2732524ec1e1d: FlushDeltaMemStoresOp(c2199a23569a4f65be07587196ce5df1) complete. Timing: real 0.010s	user 0.008s	sys 0.001s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4035,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:30.895803 32310 maintenance_manager.cc:419] P 3ef58559e19d47278ac2732524ec1e1d: Scheduling FlushMRSOp(c2199a23569a4f65be07587196ce5df1): perf score=1.000000
I20260812 06:19:30.925545 32210 maintenance_manager.cc:643] P 3ef58559e19d47278ac2732524ec1e1d: FlushMRSOp(c2199a23569a4f65be07587196ce5df1) complete. Timing: real 0.030s	user 0.028s	sys 0.000s Metrics: {"bytes_written":1193503,"cfile_init":1,"dirs.queue_time_us":69,"dirs.run_cpu_time_us":180,"dirs.run_wall_time_us":1184,"drs_written":1,"lbm_read_time_us":97,"lbm_reads_lt_1ms":4,"lbm_write_time_us":2065,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":29}
I20260812 06:19:30.926450 32310 maintenance_manager.cc:419] P 3ef58559e19d47278ac2732524ec1e1d: Scheduling MajorDeltaCompactionOp(c2199a23569a4f65be07587196ce5df1): perf score=1.000000
I20260812 06:19:31.101277 32210 maintenance_manager.cc:643] P 3ef58559e19d47278ac2732524ec1e1d: MajorDeltaCompactionOp(c2199a23569a4f65be07587196ce5df1) complete. Timing: real 0.175s	user 0.122s	sys 0.052s Metrics: {"cfile_cache_miss":533,"cfile_cache_miss_bytes":24815793,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":795,"lbm_read_time_us":11340,"lbm_reads_lt_1ms":565,"lbm_write_time_us":31436,"lbm_writes_lt_1ms":543,"mutex_wait_us":24,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":7936,"update_count":2500}
I20260812 06:19:31.102082 32310 maintenance_manager.cc:419] P 3ef58559e19d47278ac2732524ec1e1d: Scheduling LogGCOp(c2199a23569a4f65be07587196ce5df1): free 124257287 bytes of WAL
I20260812 06:19:31.102344 32210 log_reader.cc:385] T c2199a23569a4f65be07587196ce5df1: removed 12 log segments from log reader
I20260812 06:19:31.102396 32210 log.cc:1079] T c2199a23569a4f65be07587196ce5df1 P 3ef58559e19d47278ac2732524ec1e1d: Deleting log segment in path: /tmp/dist-test-taskxHIKYo/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515563725526-31713-0/minicluster-data/ts-0-root/wals/c2199a23569a4f65be07587196ce5df1/wal-000000003 (ops 12-16)
I20260812 06:19:31.102442 32210 log.cc:1079] T c2199a23569a4f65be07587196ce5df1 P 3ef58559e19d47278ac2732524ec1e1d: Deleting log segment in path: /tmp/dist-test-taskxHIKYo/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515563725526-31713-0/minicluster-data/ts-0-root/wals/c2199a23569a4f65be07587196ce5df1/wal-000000004 (ops 17-21)
I20260812 06:19:31.102520 32210 log.cc:1079] T c2199a23569a4f65be07587196ce5df1 P 3ef58559e19d47278ac2732524ec1e1d: Deleting log segment in path: /tmp/dist-test-taskxHIKYo/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515563725526-31713-0/minicluster-data/ts-0-root/wals/c2199a23569a4f65be07587196ce5df1/wal-000000005 (ops 22-26)
I20260812 06:19:31.102566 32210 log.cc:1079] T c2199a23569a4f65be07587196ce5df1 P 3ef58559e19d47278ac2732524ec1e1d: Deleting log segment in path: /tmp/dist-test-taskxHIKYo/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515563725526-31713-0/minicluster-data/ts-0-root/wals/c2199a23569a4f65be07587196ce5df1/wal-000000006 (ops 27-31)
I20260812 06:19:31.102603 32210 log.cc:1079] T c2199a23569a4f65be07587196ce5df1 P 3ef58559e19d47278ac2732524ec1e1d: Deleting log segment in path: /tmp/dist-test-taskxHIKYo/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515563725526-31713-0/minicluster-data/ts-0-root/wals/c2199a23569a4f65be07587196ce5df1/wal-000000007 (ops 32-36)
I20260812 06:19:31.102676 32210 log.cc:1079] T c2199a23569a4f65be07587196ce5df1 P 3ef58559e19d47278ac2732524ec1e1d: Deleting log segment in path: /tmp/dist-test-taskxHIKYo/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515563725526-31713-0/minicluster-data/ts-0-root/wals/c2199a23569a4f65be07587196ce5df1/wal-000000008 (ops 37-41)
I20260812 06:19:31.102727 32210 log.cc:1079] T c2199a23569a4f65be07587196ce5df1 P 3ef58559e19d47278ac2732524ec1e1d: Deleting log segment in path: /tmp/dist-test-taskxHIKYo/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515563725526-31713-0/minicluster-data/ts-0-root/wals/c2199a23569a4f65be07587196ce5df1/wal-000000009 (ops 42-46)
I20260812 06:19:31.102764 32210 log.cc:1079] T c2199a23569a4f65be07587196ce5df1 P 3ef58559e19d47278ac2732524ec1e1d: Deleting log segment in path: /tmp/dist-test-taskxHIKYo/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515563725526-31713-0/minicluster-data/ts-0-root/wals/c2199a23569a4f65be07587196ce5df1/wal-000000010 (ops 47-51)
I20260812 06:19:31.102826 32210 log.cc:1079] T c2199a23569a4f65be07587196ce5df1 P 3ef58559e19d47278ac2732524ec1e1d: Deleting log segment in path: /tmp/dist-test-taskxHIKYo/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515563725526-31713-0/minicluster-data/ts-0-root/wals/c2199a23569a4f65be07587196ce5df1/wal-000000011 (ops 52-56)
I20260812 06:19:31.102908 32210 log.cc:1079] T c2199a23569a4f65be07587196ce5df1 P 3ef58559e19d47278ac2732524ec1e1d: Deleting log segment in path: /tmp/dist-test-taskxHIKYo/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515563725526-31713-0/minicluster-data/ts-0-root/wals/c2199a23569a4f65be07587196ce5df1/wal-000000012 (ops 57-60)
I20260812 06:19:31.102957 32210 log.cc:1079] T c2199a23569a4f65be07587196ce5df1 P 3ef58559e19d47278ac2732524ec1e1d: Deleting log segment in path: /tmp/dist-test-taskxHIKYo/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515563725526-31713-0/minicluster-data/ts-0-root/wals/c2199a23569a4f65be07587196ce5df1/wal-000000013 (ops 61-65)
I20260812 06:19:31.102991 32210 log.cc:1079] T c2199a23569a4f65be07587196ce5df1 P 3ef58559e19d47278ac2732524ec1e1d: Deleting log segment in path: /tmp/dist-test-taskxHIKYo/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515563725526-31713-0/minicluster-data/ts-0-root/wals/c2199a23569a4f65be07587196ce5df1/wal-000000014 (ops 66-70)
I20260812 06:19:31.133435 32210 maintenance_manager.cc:643] P 3ef58559e19d47278ac2732524ec1e1d: LogGCOp(c2199a23569a4f65be07587196ce5df1) complete. Timing: real 0.031s	user 0.000s	sys 0.030s Metrics: {}
I20260812 06:19:31.134027 32310 maintenance_manager.cc:419] P 3ef58559e19d47278ac2732524ec1e1d: Scheduling FlushDeltaMemStoresOp(c2199a23569a4f65be07587196ce5df1): perf score=18.063937
I20260812 06:19:31.204322 32210 maintenance_manager.cc:643] P 3ef58559e19d47278ac2732524ec1e1d: FlushDeltaMemStoresOp(c2199a23569a4f65be07587196ce5df1) complete. Timing: real 0.070s	user 0.034s	sys 0.035s Metrics: {"bytes_written":20512316,"delete_count":0,"lbm_write_time_us":27693,"lbm_writes_lt_1ms":503,"reinsert_count":0,"update_count":2500}
I20260812 06:19:31.204916 32310 maintenance_manager.cc:419] P 3ef58559e19d47278ac2732524ec1e1d: Scheduling UndoDeltaBlockGCOp(c2199a23569a4f65be07587196ce5df1): 462 bytes on disk
I20260812 06:19:31.205377 32210 maintenance_manager.cc:643] P 3ef58559e19d47278ac2732524ec1e1d: UndoDeltaBlockGCOp(c2199a23569a4f65be07587196ce5df1) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":63,"lbm_reads_lt_1ms":4}
I20260812 06:19:31.205834 32310 maintenance_manager.cc:419] P 3ef58559e19d47278ac2732524ec1e1d: Scheduling FlushDeltaMemStoresOp(c2199a23569a4f65be07587196ce5df1): perf score=2.188937
I20260812 06:19:31.221506 32210 maintenance_manager.cc:643] P 3ef58559e19d47278ac2732524ec1e1d: FlushDeltaMemStoresOp(c2199a23569a4f65be07587196ce5df1) complete. Timing: real 0.016s	user 0.010s	sys 0.005s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6173,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:31.221943 32310 maintenance_manager.cc:419] P 3ef58559e19d47278ac2732524ec1e1d: Scheduling MajorDeltaCompactionOp(c2199a23569a4f65be07587196ce5df1): perf score=1.000000
I20260812 06:19:31.436326 32210 maintenance_manager.cc:643] P 3ef58559e19d47278ac2732524ec1e1d: MajorDeltaCompactionOp(c2199a23569a4f65be07587196ce5df1) complete. Timing: real 0.214s	user 0.141s	sys 0.061s Metrics: {"cfile_cache_miss":632,"cfile_cache_miss_bytes":28918098,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":592,"lbm_read_time_us":14063,"lbm_reads_lt_1ms":668,"lbm_write_time_us":34108,"lbm_writes_lt_1ms":643,"mutex_wait_us":306,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":6656,"update_count":3000}
I20260812 06:19:31.436877 32310 maintenance_manager.cc:419] P 3ef58559e19d47278ac2732524ec1e1d: Scheduling FlushDeltaMemStoresOp(c2199a23569a4f65be07587196ce5df1): perf score=18.063937
I20260812 06:19:31.493551 32210 maintenance_manager.cc:643] P 3ef58559e19d47278ac2732524ec1e1d: FlushDeltaMemStoresOp(c2199a23569a4f65be07587196ce5df1) complete. Timing: real 0.057s	user 0.027s	sys 0.028s Metrics: {"bytes_written":20512349,"delete_count":0,"lbm_write_time_us":25311,"lbm_writes_lt_1ms":503,"reinsert_count":0,"update_count":2500}
I20260812 06:19:31.494175 32310 maintenance_manager.cc:419] P 3ef58559e19d47278ac2732524ec1e1d: Scheduling FlushDeltaMemStoresOp(c2199a23569a4f65be07587196ce5df1): perf score=2.188937
I20260812 06:19:31.505939 32210 maintenance_manager.cc:643] P 3ef58559e19d47278ac2732524ec1e1d: FlushDeltaMemStoresOp(c2199a23569a4f65be07587196ce5df1) complete. Timing: real 0.012s	user 0.007s	sys 0.003s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4541,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:31.506542 32310 maintenance_manager.cc:419] P 3ef58559e19d47278ac2732524ec1e1d: Scheduling MajorDeltaCompactionOp(c2199a23569a4f65be07587196ce5df1): perf score=1.000000
I20260812 06:19:31.727703 32210 maintenance_manager.cc:643] P 3ef58559e19d47278ac2732524ec1e1d: MajorDeltaCompactionOp(c2199a23569a4f65be07587196ce5df1) complete. Timing: real 0.221s	user 0.141s	sys 0.076s Metrics: {"cfile_cache_miss":632,"cfile_cache_miss_bytes":28918130,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":287,"lbm_read_time_us":14117,"lbm_reads_lt_1ms":672,"lbm_write_time_us":37035,"lbm_writes_lt_1ms":643,"mutex_wait_us":42,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":1664,"update_count":3000}
I20260812 06:19:31.728488 32310 maintenance_manager.cc:419] P 3ef58559e19d47278ac2732524ec1e1d: Scheduling FlushDeltaMemStoresOp(c2199a23569a4f65be07587196ce5df1): perf score=16.079562
I20260812 06:19:31.799934 32210 maintenance_manager.cc:643] P 3ef58559e19d47278ac2732524ec1e1d: FlushDeltaMemStoresOp(c2199a23569a4f65be07587196ce5df1) complete. Timing: real 0.071s	user 0.033s	sys 0.021s Metrics: {"bytes_written":18050868,"delete_count":0,"lbm_write_time_us":28508,"lbm_writes_1-10_ms":2,"lbm_writes_lt_1ms":441,"reinsert_count":0,"update_count":2200}
I20260812 06:19:31.800486 32310 maintenance_manager.cc:419] P 3ef58559e19d47278ac2732524ec1e1d: Scheduling FlushDeltaMemStoresOp(c2199a23569a4f65be07587196ce5df1): perf score=5.165500
I20260812 06:19:31.817982 32210 maintenance_manager.cc:643] P 3ef58559e19d47278ac2732524ec1e1d: FlushDeltaMemStoresOp(c2199a23569a4f65be07587196ce5df1) complete. Timing: real 0.017s	user 0.008s	sys 0.008s Metrics: {"bytes_written":6564114,"delete_count":0,"lbm_write_time_us":7029,"lbm_writes_lt_1ms":163,"reinsert_count":0,"update_count":800}
I20260812 06:19:31.818701 32310 maintenance_manager.cc:419] P 3ef58559e19d47278ac2732524ec1e1d: Scheduling MajorDeltaCompactionOp(c2199a23569a4f65be07587196ce5df1): perf score=1.000000
I20260812 06:19:32.032913 32210 maintenance_manager.cc:643] P 3ef58559e19d47278ac2732524ec1e1d: MajorDeltaCompactionOp(c2199a23569a4f65be07587196ce5df1) complete. Timing: real 0.214s	user 0.132s	sys 0.075s Metrics: {"cfile_cache_miss":632,"cfile_cache_miss_bytes":28918099,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":1136,"lbm_read_time_us":13764,"lbm_reads_lt_1ms":664,"lbm_write_time_us":34115,"lbm_writes_lt_1ms":643,"mutex_wait_us":617,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":6656,"update_count":3000}
I20260812 06:19:32.033635 32310 maintenance_manager.cc:419] P 3ef58559e19d47278ac2732524ec1e1d: Scheduling FlushDeltaMemStoresOp(c2199a23569a4f65be07587196ce5df1): perf score=18.063937
I20260812 06:19:32.104696 32210 maintenance_manager.cc:643] P 3ef58559e19d47278ac2732524ec1e1d: FlushDeltaMemStoresOp(c2199a23569a4f65be07587196ce5df1) complete. Timing: real 0.071s	user 0.039s	sys 0.020s Metrics: {"bytes_written":20512317,"delete_count":0,"lbm_write_time_us":27341,"lbm_writes_lt_1ms":503,"reinsert_count":0,"update_count":2500}
I20260812 06:19:32.105180 32310 maintenance_manager.cc:419] P 3ef58559e19d47278ac2732524ec1e1d: Scheduling FlushDeltaMemStoresOp(c2199a23569a4f65be07587196ce5df1): perf score=2.188937
I20260812 06:19:32.115734 32210 maintenance_manager.cc:643] P 3ef58559e19d47278ac2732524ec1e1d: FlushDeltaMemStoresOp(c2199a23569a4f65be07587196ce5df1) complete. Timing: real 0.010s	user 0.004s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3999,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:32.116645 32310 maintenance_manager.cc:419] P 3ef58559e19d47278ac2732524ec1e1d: Scheduling MajorDeltaCompactionOp(c2199a23569a4f65be07587196ce5df1): perf score=1.000000
I20260812 06:19:32.323108 32210 maintenance_manager.cc:643] P 3ef58559e19d47278ac2732524ec1e1d: MajorDeltaCompactionOp(c2199a23569a4f65be07587196ce5df1) complete. Timing: real 0.206s	user 0.132s	sys 0.072s Metrics: {"cfile_cache_miss":632,"cfile_cache_miss_bytes":28918099,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":2559,"lbm_read_time_us":12982,"lbm_reads_lt_1ms":672,"lbm_write_time_us":34182,"lbm_writes_lt_1ms":643,"mutex_wait_us":1626,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":9984,"update_count":3000}
I20260812 06:19:32.323854 32310 maintenance_manager.cc:419] P 3ef58559e19d47278ac2732524ec1e1d: Scheduling FlushDeltaMemStoresOp(c2199a23569a4f65be07587196ce5df1): perf score=14.095187
I20260812 06:19:32.377558 32210 maintenance_manager.cc:643] P 3ef58559e19d47278ac2732524ec1e1d: FlushDeltaMemStoresOp(c2199a23569a4f65be07587196ce5df1) complete. Timing: real 0.053s	user 0.024s	sys 0.027s Metrics: {"bytes_written":16409899,"delete_count":0,"lbm_write_time_us":23191,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":402,"reinsert_count":0,"update_count":2000}
I20260812 06:19:32.378163 32310 maintenance_manager.cc:419] P 3ef58559e19d47278ac2732524ec1e1d: Scheduling FlushDeltaMemStoresOp(c2199a23569a4f65be07587196ce5df1): perf score=2.188937
I20260812 06:19:32.397255 32210 maintenance_manager.cc:643] P 3ef58559e19d47278ac2732524ec1e1d: FlushDeltaMemStoresOp(c2199a23569a4f65be07587196ce5df1) complete. Timing: real 0.019s	user 0.008s	sys 0.006s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5768,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:32.397907 32310 maintenance_manager.cc:419] P 3ef58559e19d47278ac2732524ec1e1d: Scheduling FlushMRSOp(c2199a23569a4f65be07587196ce5df1): perf score=1.000000
I20260812 06:19:32.451764 32210 maintenance_manager.cc:643] P 3ef58559e19d47278ac2732524ec1e1d: FlushMRSOp(c2199a23569a4f65be07587196ce5df1) complete. Timing: real 0.054s	user 0.027s	sys 0.001s Metrics: {"bytes_written":1234479,"cfile_init":1,"dirs.queue_time_us":93,"dirs.run_cpu_time_us":209,"dirs.run_wall_time_us":1377,"drs_written":1,"lbm_read_time_us":70,"lbm_reads_lt_1ms":4,"lbm_write_time_us":2460,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":30}
I20260812 06:19:32.452523 32310 maintenance_manager.cc:419] P 3ef58559e19d47278ac2732524ec1e1d: Scheduling LogGCOp(c2199a23569a4f65be07587196ce5df1): free 120553389 bytes of WAL
I20260812 06:19:32.452801 32210 log_reader.cc:385] T c2199a23569a4f65be07587196ce5df1: removed 12 log segments from log reader
I20260812 06:19:32.452878 32210 log.cc:1079] T c2199a23569a4f65be07587196ce5df1 P 3ef58559e19d47278ac2732524ec1e1d: Deleting log segment in path: /tmp/dist-test-taskxHIKYo/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515563725526-31713-0/minicluster-data/ts-0-root/wals/c2199a23569a4f65be07587196ce5df1/wal-000000015 (ops 71-75)
I20260812 06:19:32.452917 32210 log.cc:1079] T c2199a23569a4f65be07587196ce5df1 P 3ef58559e19d47278ac2732524ec1e1d: Deleting log segment in path: /tmp/dist-test-taskxHIKYo/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515563725526-31713-0/minicluster-data/ts-0-root/wals/c2199a23569a4f65be07587196ce5df1/wal-000000016 (ops 76-80)
I20260812 06:19:32.452955 32210 log.cc:1079] T c2199a23569a4f65be07587196ce5df1 P 3ef58559e19d47278ac2732524ec1e1d: Deleting log segment in path: /tmp/dist-test-taskxHIKYo/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515563725526-31713-0/minicluster-data/ts-0-root/wals/c2199a23569a4f65be07587196ce5df1/wal-000000017 (ops 81-85)
I20260812 06:19:32.452979 32210 log.cc:1079] T c2199a23569a4f65be07587196ce5df1 P 3ef58559e19d47278ac2732524ec1e1d: Deleting log segment in path: /tmp/dist-test-taskxHIKYo/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515563725526-31713-0/minicluster-data/ts-0-root/wals/c2199a23569a4f65be07587196ce5df1/wal-000000018 (ops 86-90)
I20260812 06:19:32.453002 32210 log.cc:1079] T c2199a23569a4f65be07587196ce5df1 P 3ef58559e19d47278ac2732524ec1e1d: Deleting log segment in path: /tmp/dist-test-taskxHIKYo/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515563725526-31713-0/minicluster-data/ts-0-root/wals/c2199a23569a4f65be07587196ce5df1/wal-000000019 (ops 91-94)
I20260812 06:19:32.453032 32210 log.cc:1079] T c2199a23569a4f65be07587196ce5df1 P 3ef58559e19d47278ac2732524ec1e1d: Deleting log segment in path: /tmp/dist-test-taskxHIKYo/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515563725526-31713-0/minicluster-data/ts-0-root/wals/c2199a23569a4f65be07587196ce5df1/wal-000000020 (ops 95-99)
I20260812 06:19:32.453061 32210 log.cc:1079] T c2199a23569a4f65be07587196ce5df1 P 3ef58559e19d47278ac2732524ec1e1d: Deleting log segment in path: /tmp/dist-test-taskxHIKYo/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515563725526-31713-0/minicluster-data/ts-0-root/wals/c2199a23569a4f65be07587196ce5df1/wal-000000021 (ops 100-104)
I20260812 06:19:32.453096 32210 log.cc:1079] T c2199a23569a4f65be07587196ce5df1 P 3ef58559e19d47278ac2732524ec1e1d: Deleting log segment in path: /tmp/dist-test-taskxHIKYo/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515563725526-31713-0/minicluster-data/ts-0-root/wals/c2199a23569a4f65be07587196ce5df1/wal-000000022 (ops 105-109)
I20260812 06:19:32.453130 32210 log.cc:1079] T c2199a23569a4f65be07587196ce5df1 P 3ef58559e19d47278ac2732524ec1e1d: Deleting log segment in path: /tmp/dist-test-taskxHIKYo/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515563725526-31713-0/minicluster-data/ts-0-root/wals/c2199a23569a4f65be07587196ce5df1/wal-000000023 (ops 110-114)
I20260812 06:19:32.453158 32210 log.cc:1079] T c2199a23569a4f65be07587196ce5df1 P 3ef58559e19d47278ac2732524ec1e1d: Deleting log segment in path: /tmp/dist-test-taskxHIKYo/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515563725526-31713-0/minicluster-data/ts-0-root/wals/c2199a23569a4f65be07587196ce5df1/wal-000000024 (ops 115-119)
I20260812 06:19:32.453187 32210 log.cc:1079] T c2199a23569a4f65be07587196ce5df1 P 3ef58559e19d47278ac2732524ec1e1d: Deleting log segment in path: /tmp/dist-test-taskxHIKYo/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515563725526-31713-0/minicluster-data/ts-0-root/wals/c2199a23569a4f65be07587196ce5df1/wal-000000025 (ops 120-124)
I20260812 06:19:32.453217 32210 log.cc:1079] T c2199a23569a4f65be07587196ce5df1 P 3ef58559e19d47278ac2732524ec1e1d: Deleting log segment in path: /tmp/dist-test-taskxHIKYo/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515563725526-31713-0/minicluster-data/ts-0-root/wals/c2199a23569a4f65be07587196ce5df1/wal-000000026 (ops 125-128)
I20260812 06:19:32.481734 32210 maintenance_manager.cc:643] P 3ef58559e19d47278ac2732524ec1e1d: LogGCOp(c2199a23569a4f65be07587196ce5df1) complete. Timing: real 0.029s	user 0.000s	sys 0.027s Metrics: {}
I20260812 06:19:32.482152 32310 maintenance_manager.cc:419] P 3ef58559e19d47278ac2732524ec1e1d: Scheduling UndoDeltaBlockGCOp(c2199a23569a4f65be07587196ce5df1): 473 bytes on disk
I20260812 06:19:32.482702 32210 maintenance_manager.cc:643] P 3ef58559e19d47278ac2732524ec1e1d: UndoDeltaBlockGCOp(c2199a23569a4f65be07587196ce5df1) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":106,"lbm_reads_lt_1ms":4,"spinlock_wait_cycles":6528}
I20260812 06:19:32.483217 32310 maintenance_manager.cc:419] P 3ef58559e19d47278ac2732524ec1e1d: Scheduling FlushDeltaMemStoresOp(c2199a23569a4f65be07587196ce5df1): perf score=6.157687
I20260812 06:19:32.512406 32210 maintenance_manager.cc:643] P 3ef58559e19d47278ac2732524ec1e1d: FlushDeltaMemStoresOp(c2199a23569a4f65be07587196ce5df1) complete. Timing: real 0.029s	user 0.017s	sys 0.011s Metrics: {"bytes_written":8205078,"delete_count":0,"lbm_write_time_us":12309,"lbm_writes_lt_1ms":203,"reinsert_count":0,"update_count":1000}
I20260812 06:19:32.512959 32310 maintenance_manager.cc:419] P 3ef58559e19d47278ac2732524ec1e1d: Scheduling FlushDeltaMemStoresOp(c2199a23569a4f65be07587196ce5df1): perf score=2.188937
I20260812 06:19:32.528096 32210 maintenance_manager.cc:643] P 3ef58559e19d47278ac2732524ec1e1d: FlushDeltaMemStoresOp(c2199a23569a4f65be07587196ce5df1) complete. Timing: real 0.015s	user 0.005s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5731,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:32.528685 32310 maintenance_manager.cc:419] P 3ef58559e19d47278ac2732524ec1e1d: Scheduling MajorDeltaCompactionOp(c2199a23569a4f65be07587196ce5df1): perf score=1.000000
I20260812 06:19:32.760928 32210 maintenance_manager.cc:643] P 3ef58559e19d47278ac2732524ec1e1d: MajorDeltaCompactionOp(c2199a23569a4f65be07587196ce5df1) complete. Timing: real 0.232s	user 0.182s	sys 0.049s Metrics: {"cfile_cache_miss":834,"cfile_cache_miss_bytes":37123156,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":2471,"lbm_read_time_us":17346,"lbm_reads_lt_1ms":874,"lbm_write_time_us":41484,"lbm_writes_lt_1ms":843,"mutex_wait_us":962,"peak_mem_usage":100395616,"reinsert_count":0,"spinlock_wait_cycles":10496,"thread_start_us":98,"threads_started":1,"update_count":4000}
I20260812 06:19:32.761585 32310 maintenance_manager.cc:419] P 3ef58559e19d47278ac2732524ec1e1d: Scheduling FlushDeltaMemStoresOp(c2199a23569a4f65be07587196ce5df1): perf score=18.063937
I20260812 06:19:32.832113 32210 maintenance_manager.cc:643] P 3ef58559e19d47278ac2732524ec1e1d: FlushDeltaMemStoresOp(c2199a23569a4f65be07587196ce5df1) complete. Timing: real 0.070s	user 0.031s	sys 0.032s Metrics: {"bytes_written":20512318,"delete_count":0,"lbm_write_time_us":30966,"lbm_writes_1-10_ms":3,"lbm_writes_lt_1ms":500,"reinsert_count":0,"update_count":2500}
I20260812 06:19:32.832603 32310 maintenance_manager.cc:419] P 3ef58559e19d47278ac2732524ec1e1d: Scheduling FlushDeltaMemStoresOp(c2199a23569a4f65be07587196ce5df1): perf score=3.181125
I20260812 06:19:32.845207 32210 maintenance_manager.cc:643] P 3ef58559e19d47278ac2732524ec1e1d: FlushDeltaMemStoresOp(c2199a23569a4f65be07587196ce5df1) complete. Timing: real 0.012s	user 0.006s	sys 0.005s Metrics: {"bytes_written":5005191,"delete_count":0,"lbm_write_time_us":5265,"lbm_writes_lt_1ms":125,"reinsert_count":0,"update_count":610}
I20260812 06:19:32.845606 32310 maintenance_manager.cc:419] P 3ef58559e19d47278ac2732524ec1e1d: Scheduling FlushDeltaMemStoresOp(c2199a23569a4f65be07587196ce5df1): perf score=2.188937
I20260812 06:19:32.855747 32210 maintenance_manager.cc:643] P 3ef58559e19d47278ac2732524ec1e1d: FlushDeltaMemStoresOp(c2199a23569a4f65be07587196ce5df1) complete. Timing: real 0.010s	user 0.002s	sys 0.005s Metrics: {"bytes_written":3200105,"delete_count":0,"lbm_write_time_us":3151,"lbm_writes_lt_1ms":81,"reinsert_count":0,"update_count":390}
I20260812 06:19:32.856434 32310 maintenance_manager.cc:419] P 3ef58559e19d47278ac2732524ec1e1d: Scheduling MajorDeltaCompactionOp(c2199a23569a4f65be07587196ce5df1): perf score=1.000000
I20260812 06:19:33.044834 32210 maintenance_manager.cc:643] P 3ef58559e19d47278ac2732524ec1e1d: MajorDeltaCompactionOp(c2199a23569a4f65be07587196ce5df1) complete. Timing: real 0.188s	user 0.139s	sys 0.048s Metrics: {"cfile_cache_miss":733,"cfile_cache_miss_bytes":33020609,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":470,"lbm_read_time_us":12244,"lbm_reads_lt_1ms":773,"lbm_write_time_us":39676,"lbm_writes_lt_1ms":743,"mutex_wait_us":21,"peak_mem_usage":87969044,"reinsert_count":0,"spinlock_wait_cycles":8192,"update_count":3500}
I20260812 06:19:33.045552 32310 maintenance_manager.cc:419] P 3ef58559e19d47278ac2732524ec1e1d: Scheduling FlushDeltaMemStoresOp(c2199a23569a4f65be07587196ce5df1): perf score=14.095187
I20260812 06:19:33.085793 32210 maintenance_manager.cc:643] P 3ef58559e19d47278ac2732524ec1e1d: FlushDeltaMemStoresOp(c2199a23569a4f65be07587196ce5df1) complete. Timing: real 0.039s	user 0.021s	sys 0.015s Metrics: {"bytes_written":16409903,"delete_count":0,"lbm_write_time_us":17454,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:33.086279 32310 maintenance_manager.cc:419] P 3ef58559e19d47278ac2732524ec1e1d: Scheduling FlushDeltaMemStoresOp(c2199a23569a4f65be07587196ce5df1): perf score=2.188937
I20260812 06:19:33.099201 32210 maintenance_manager.cc:643] P 3ef58559e19d47278ac2732524ec1e1d: FlushDeltaMemStoresOp(c2199a23569a4f65be07587196ce5df1) complete. Timing: real 0.013s	user 0.008s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4939,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:33.099656 32310 maintenance_manager.cc:419] P 3ef58559e19d47278ac2732524ec1e1d: Scheduling MajorDeltaCompactionOp(c2199a23569a4f65be07587196ce5df1): perf score=1.000000
I20260812 06:19:33.263046 32210 maintenance_manager.cc:643] P 3ef58559e19d47278ac2732524ec1e1d: MajorDeltaCompactionOp(c2199a23569a4f65be07587196ce5df1) complete. Timing: real 0.163s	user 0.083s	sys 0.075s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24815685,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":823,"lbm_read_time_us":9855,"lbm_reads_lt_1ms":572,"lbm_write_time_us":30587,"lbm_writes_lt_1ms":543,"mutex_wait_us":41,"peak_mem_usage":63115900,"reinsert_count":0,"update_count":2500}
I20260812 06:19:33.263728 32310 maintenance_manager.cc:419] P 3ef58559e19d47278ac2732524ec1e1d: Scheduling FlushDeltaMemStoresOp(c2199a23569a4f65be07587196ce5df1): perf score=14.095187
I20260812 06:19:33.311779 32210 maintenance_manager.cc:643] P 3ef58559e19d47278ac2732524ec1e1d: FlushDeltaMemStoresOp(c2199a23569a4f65be07587196ce5df1) complete. Timing: real 0.048s	user 0.019s	sys 0.019s Metrics: {"bytes_written":16409903,"delete_count":0,"lbm_write_time_us":18992,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:33.312431 32310 maintenance_manager.cc:419] P 3ef58559e19d47278ac2732524ec1e1d: Scheduling MajorDeltaCompactionOp(c2199a23569a4f65be07587196ce5df1): perf score=1.000000
I20260812 06:19:33.456621 32210 maintenance_manager.cc:643] P 3ef58559e19d47278ac2732524ec1e1d: MajorDeltaCompactionOp(c2199a23569a4f65be07587196ce5df1) complete. Timing: real 0.144s	user 0.102s	sys 0.041s Metrics: {"cfile_cache_miss":431,"cfile_cache_miss_bytes":20713154,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":1,"delta_iterators_relevant":1,"dirs.queue_time_us":1430,"lbm_read_time_us":9301,"lbm_reads_lt_1ms":463,"lbm_write_time_us":24984,"lbm_writes_lt_1ms":443,"mutex_wait_us":342,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":24192,"update_count":2000}
I20260812 06:19:33.457108 32310 maintenance_manager.cc:419] P 3ef58559e19d47278ac2732524ec1e1d: Scheduling FlushDeltaMemStoresOp(c2199a23569a4f65be07587196ce5df1): perf score=14.095187
I20260812 06:19:33.507544 32210 maintenance_manager.cc:643] P 3ef58559e19d47278ac2732524ec1e1d: FlushDeltaMemStoresOp(c2199a23569a4f65be07587196ce5df1) complete. Timing: real 0.050s	user 0.033s	sys 0.008s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":19826,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:33.508024 32310 maintenance_manager.cc:419] P 3ef58559e19d47278ac2732524ec1e1d: Scheduling FlushDeltaMemStoresOp(c2199a23569a4f65be07587196ce5df1): perf score=2.188937
I20260812 06:19:33.519222 32210 maintenance_manager.cc:643] P 3ef58559e19d47278ac2732524ec1e1d: FlushDeltaMemStoresOp(c2199a23569a4f65be07587196ce5df1) complete. Timing: real 0.011s	user 0.004s	sys 0.004s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4200,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:33.519726 32310 maintenance_manager.cc:419] P 3ef58559e19d47278ac2732524ec1e1d: Scheduling MajorDeltaCompactionOp(c2199a23569a4f65be07587196ce5df1): perf score=1.000000
I20260812 06:19:33.706419 32210 maintenance_manager.cc:643] P 3ef58559e19d47278ac2732524ec1e1d: MajorDeltaCompactionOp(c2199a23569a4f65be07587196ce5df1) complete. Timing: real 0.187s	user 0.121s	sys 0.055s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24815682,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":320,"lbm_read_time_us":11393,"lbm_reads_lt_1ms":572,"lbm_write_time_us":28863,"lbm_writes_lt_1ms":543,"mutex_wait_us":67,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":3712,"update_count":2500}
I20260812 06:19:33.707125 32310 maintenance_manager.cc:419] P 3ef58559e19d47278ac2732524ec1e1d: Scheduling FlushDeltaMemStoresOp(c2199a23569a4f65be07587196ce5df1): perf score=14.095187
I20260812 06:19:33.754063 32210 maintenance_manager.cc:643] P 3ef58559e19d47278ac2732524ec1e1d: FlushDeltaMemStoresOp(c2199a23569a4f65be07587196ce5df1) complete. Timing: real 0.047s	user 0.021s	sys 0.017s Metrics: {"bytes_written":16409897,"delete_count":0,"lbm_write_time_us":17727,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:33.754567 32310 maintenance_manager.cc:419] P 3ef58559e19d47278ac2732524ec1e1d: Scheduling FlushDeltaMemStoresOp(c2199a23569a4f65be07587196ce5df1): perf score=2.188937
I20260812 06:19:33.767247 32210 maintenance_manager.cc:643] P 3ef58559e19d47278ac2732524ec1e1d: FlushDeltaMemStoresOp(c2199a23569a4f65be07587196ce5df1) complete. Timing: real 0.013s	user 0.009s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4333,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:33.767867 32310 maintenance_manager.cc:419] P 3ef58559e19d47278ac2732524ec1e1d: Scheduling FlushMRSOp(c2199a23569a4f65be07587196ce5df1): perf score=1.000000
I20260812 06:19:33.795373 32210 maintenance_manager.cc:643] P 3ef58559e19d47278ac2732524ec1e1d: FlushMRSOp(c2199a23569a4f65be07587196ce5df1) complete. Timing: real 0.027s	user 0.026s	sys 0.000s Metrics: {"bytes_written":1152510,"cfile_init":1,"dirs.queue_time_us":96,"dirs.run_cpu_time_us":235,"dirs.run_wall_time_us":1236,"drs_written":1,"lbm_read_time_us":42,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1684,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":28}
I20260812 06:19:33.796046 32310 maintenance_manager.cc:419] P 3ef58559e19d47278ac2732524ec1e1d: Scheduling LogGCOp(c2199a23569a4f65be07587196ce5df1): free 112692616 bytes of WAL
I20260812 06:19:33.796305 32210 log_reader.cc:385] T c2199a23569a4f65be07587196ce5df1: removed 11 log segments from log reader
I20260812 06:19:33.796355 32210 log.cc:1079] T c2199a23569a4f65be07587196ce5df1 P 3ef58559e19d47278ac2732524ec1e1d: Deleting log segment in path: /tmp/dist-test-taskxHIKYo/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515563725526-31713-0/minicluster-data/ts-0-root/wals/c2199a23569a4f65be07587196ce5df1/wal-000000027 (ops 129-133)
I20260812 06:19:33.796384 32210 log.cc:1079] T c2199a23569a4f65be07587196ce5df1 P 3ef58559e19d47278ac2732524ec1e1d: Deleting log segment in path: /tmp/dist-test-taskxHIKYo/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515563725526-31713-0/minicluster-data/ts-0-root/wals/c2199a23569a4f65be07587196ce5df1/wal-000000028 (ops 134-138)
I20260812 06:19:33.796453 32210 log.cc:1079] T c2199a23569a4f65be07587196ce5df1 P 3ef58559e19d47278ac2732524ec1e1d: Deleting log segment in path: /tmp/dist-test-taskxHIKYo/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515563725526-31713-0/minicluster-data/ts-0-root/wals/c2199a23569a4f65be07587196ce5df1/wal-000000029 (ops 139-143)
I20260812 06:19:33.796499 32210 log.cc:1079] T c2199a23569a4f65be07587196ce5df1 P 3ef58559e19d47278ac2732524ec1e1d: Deleting log segment in path: /tmp/dist-test-taskxHIKYo/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515563725526-31713-0/minicluster-data/ts-0-root/wals/c2199a23569a4f65be07587196ce5df1/wal-000000030 (ops 144-148)
I20260812 06:19:33.796550 32210 log.cc:1079] T c2199a23569a4f65be07587196ce5df1 P 3ef58559e19d47278ac2732524ec1e1d: Deleting log segment in path: /tmp/dist-test-taskxHIKYo/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515563725526-31713-0/minicluster-data/ts-0-root/wals/c2199a23569a4f65be07587196ce5df1/wal-000000031 (ops 149-153)
I20260812 06:19:33.796591 32210 log.cc:1079] T c2199a23569a4f65be07587196ce5df1 P 3ef58559e19d47278ac2732524ec1e1d: Deleting log segment in path: /tmp/dist-test-taskxHIKYo/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515563725526-31713-0/minicluster-data/ts-0-root/wals/c2199a23569a4f65be07587196ce5df1/wal-000000032 (ops 154-158)
I20260812 06:19:33.796631 32210 log.cc:1079] T c2199a23569a4f65be07587196ce5df1 P 3ef58559e19d47278ac2732524ec1e1d: Deleting log segment in path: /tmp/dist-test-taskxHIKYo/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515563725526-31713-0/minicluster-data/ts-0-root/wals/c2199a23569a4f65be07587196ce5df1/wal-000000033 (ops 159-163)
I20260812 06:19:33.796672 32210 log.cc:1079] T c2199a23569a4f65be07587196ce5df1 P 3ef58559e19d47278ac2732524ec1e1d: Deleting log segment in path: /tmp/dist-test-taskxHIKYo/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515563725526-31713-0/minicluster-data/ts-0-root/wals/c2199a23569a4f65be07587196ce5df1/wal-000000034 (ops 164-168)
I20260812 06:19:33.796712 32210 log.cc:1079] T c2199a23569a4f65be07587196ce5df1 P 3ef58559e19d47278ac2732524ec1e1d: Deleting log segment in path: /tmp/dist-test-taskxHIKYo/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515563725526-31713-0/minicluster-data/ts-0-root/wals/c2199a23569a4f65be07587196ce5df1/wal-000000035 (ops 169-173)
I20260812 06:19:33.796752 32210 log.cc:1079] T c2199a23569a4f65be07587196ce5df1 P 3ef58559e19d47278ac2732524ec1e1d: Deleting log segment in path: /tmp/dist-test-taskxHIKYo/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515563725526-31713-0/minicluster-data/ts-0-root/wals/c2199a23569a4f65be07587196ce5df1/wal-000000036 (ops 174-178)
I20260812 06:19:33.796792 32210 log.cc:1079] T c2199a23569a4f65be07587196ce5df1 P 3ef58559e19d47278ac2732524ec1e1d: Deleting log segment in path: /tmp/dist-test-taskxHIKYo/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515563725526-31713-0/minicluster-data/ts-0-root/wals/c2199a23569a4f65be07587196ce5df1/wal-000000037 (ops 179-183)
I20260812 06:19:33.823587 32210 maintenance_manager.cc:643] P 3ef58559e19d47278ac2732524ec1e1d: LogGCOp(c2199a23569a4f65be07587196ce5df1) complete. Timing: real 0.027s	user 0.000s	sys 0.024s Metrics: {}
I20260812 06:19:33.824625 32310 maintenance_manager.cc:419] P 3ef58559e19d47278ac2732524ec1e1d: Scheduling FlushDeltaMemStoresOp(c2199a23569a4f65be07587196ce5df1): perf score=2.188937
I20260812 06:19:33.847813 32210 maintenance_manager.cc:643] P 3ef58559e19d47278ac2732524ec1e1d: FlushDeltaMemStoresOp(c2199a23569a4f65be07587196ce5df1) complete. Timing: real 0.023s	user 0.010s	sys 0.005s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6603,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:33.848336 32310 maintenance_manager.cc:419] P 3ef58559e19d47278ac2732524ec1e1d: Scheduling FlushDeltaMemStoresOp(c2199a23569a4f65be07587196ce5df1): perf score=2.188937
I20260812 06:19:33.858729 32210 maintenance_manager.cc:643] P 3ef58559e19d47278ac2732524ec1e1d: FlushDeltaMemStoresOp(c2199a23569a4f65be07587196ce5df1) complete. Timing: real 0.010s	user 0.000s	sys 0.008s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4126,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:33.859176 32310 maintenance_manager.cc:419] P 3ef58559e19d47278ac2732524ec1e1d: Scheduling UndoDeltaBlockGCOp(c2199a23569a4f65be07587196ce5df1): 447 bytes on disk
I20260812 06:19:33.859584 32210 maintenance_manager.cc:643] P 3ef58559e19d47278ac2732524ec1e1d: UndoDeltaBlockGCOp(c2199a23569a4f65be07587196ce5df1) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":52,"lbm_reads_lt_1ms":4}
I20260812 06:19:33.860059 32310 maintenance_manager.cc:419] P 3ef58559e19d47278ac2732524ec1e1d: Scheduling MajorDeltaCompactionOp(c2199a23569a4f65be07587196ce5df1): perf score=1.000000
I20260812 06:19:34.088527 32210 maintenance_manager.cc:643] P 3ef58559e19d47278ac2732524ec1e1d: MajorDeltaCompactionOp(c2199a23569a4f65be07587196ce5df1) complete. Timing: real 0.228s	user 0.155s	sys 0.071s Metrics: {"cfile_cache_miss":734,"cfile_cache_miss_bytes":33020740,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":778,"lbm_read_time_us":16938,"lbm_reads_lt_1ms":774,"lbm_write_time_us":37943,"lbm_writes_lt_1ms":743,"mutex_wait_us":58,"peak_mem_usage":87969044,"reinsert_count":0,"spinlock_wait_cycles":14848,"thread_start_us":111,"threads_started":1,"update_count":3500}
I20260812 06:19:34.089340 32310 maintenance_manager.cc:419] P 3ef58559e19d47278ac2732524ec1e1d: Scheduling FlushDeltaMemStoresOp(c2199a23569a4f65be07587196ce5df1): perf score=18.063937
I20260812 06:19:34.153489 31713 heavy-update-compaction-itest.cc:229] Time spent updating: real 4.812s	user 1.774s	sys 0.199s
I20260812 06:19:34.157770 32210 maintenance_manager.cc:643] P 3ef58559e19d47278ac2732524ec1e1d: FlushDeltaMemStoresOp(c2199a23569a4f65be07587196ce5df1) complete. Timing: real 0.068s	user 0.040s	sys 0.021s Metrics: {"bytes_written":20512316,"delete_count":0,"lbm_write_time_us":31121,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":502,"reinsert_count":0,"update_count":2500}
I20260812 06:19:34.158229 32310 maintenance_manager.cc:419] P 3ef58559e19d47278ac2732524ec1e1d: Scheduling FlushDeltaMemStoresOp(c2199a23569a4f65be07587196ce5df1): perf score=2.188937
I20260812 06:19:34.168395 32210 maintenance_manager.cc:643] P 3ef58559e19d47278ac2732524ec1e1d: FlushDeltaMemStoresOp(c2199a23569a4f65be07587196ce5df1) complete. Timing: real 0.010s	user 0.009s	sys 0.001s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4102,"lbm_writes_lt_1ms":103,"reinsert_count":0,"spinlock_wait_cycles":768,"update_count":500}
I20260812 06:19:34.168823 32310 maintenance_manager.cc:419] P 3ef58559e19d47278ac2732524ec1e1d: Scheduling MajorDeltaCompactionOp(c2199a23569a4f65be07587196ce5df1): perf score=1.000000
I20260812 06:19:34.223011 31713 heavy-update-compaction-itest.cc:265] Time spent scanning: real 0.069s	user 0.001s	sys 0.000s
I20260812 06:19:34.223634 31713 tablet_server.cc:179] TabletServer@127.30.248.65:0 shutting down...
I20260812 06:19:34.320876 32210 maintenance_manager.cc:643] P 3ef58559e19d47278ac2732524ec1e1d: MajorDeltaCompactionOp(c2199a23569a4f65be07587196ce5df1) complete. Timing: real 0.152s	user 0.105s	sys 0.046s Metrics: {"cfile_cache_hit":255,"cfile_cache_hit_bytes":10423476,"cfile_cache_miss":377,"cfile_cache_miss_bytes":18494622,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":1376,"lbm_read_time_us":7789,"lbm_reads_lt_1ms":409,"lbm_write_time_us":29894,"lbm_writes_lt_1ms":643,"mutex_wait_us":315,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":127104,"update_count":3000}
I20260812 06:19:34.321676 31713 ts_tablet_manager.cc:1507] Shutting down tablet manager...
I20260812 06:19:34.321944 31713 tablet_replica.cc:333] T c2199a23569a4f65be07587196ce5df1 P 3ef58559e19d47278ac2732524ec1e1d: stopping tablet replica
I20260812 06:19:34.322078 31713 raft_consensus.cc:2243] T c2199a23569a4f65be07587196ce5df1 P 3ef58559e19d47278ac2732524ec1e1d [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:19:34.322259 31713 raft_consensus.cc:2272] T c2199a23569a4f65be07587196ce5df1 P 3ef58559e19d47278ac2732524ec1e1d [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:19:34.326020 31713 tablet_server.cc:196] TabletServer@127.30.248.65:0 shutdown complete.
I20260812 06:19:34.373199 31713 master.cc:562] Master@127.30.248.126:44711 shutting down...
I20260812 06:19:34.376590 31713 raft_consensus.cc:2243] T 00000000000000000000000000000000 P 78c07787eee742259ac385c8a94fcf01 [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:19:34.376791 31713 raft_consensus.cc:2272] T 00000000000000000000000000000000 P 78c07787eee742259ac385c8a94fcf01 [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:19:34.376880 31713 tablet_replica.cc:333] T 00000000000000000000000000000000 P 78c07787eee742259ac385c8a94fcf01: stopping tablet replica
I20260812 06:19:34.389163 31713 master.cc:584] Master@127.30.248.126:44711 shutdown complete.
[       OK ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/1 (5358 ms)
[----------] 2 tests from EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy (10744 ms total)

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