[==========] 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:16:51.985942 24417 internal_mini_cluster.cc:156] Creating distributed mini masters. Addrs: 127.23.216.126:46165
I20260812 06:16:51.987001 24417 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:16:51.987563 24417 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:16:51.994179 24424 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:16:51.994251 24427 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:16:51.994285 24417 server_base.cc:1061] running on GCE node
W20260812 06:16:51.994531 24425 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:16:51.995116 24417 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:16:51.995244 24417 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:16:51.995296 24417 hybrid_clock.cc:648] HybridClock initialized: now 1786515411995292 us; error 0 us; skew 500 ppm
I20260812 06:16:51.997172 24417 webserver.cc:533] Webserver started at http://127.23.216.126:35057/ using document root <none> and password file <none>
I20260812 06:16:51.997781 24417 fs_manager.cc:362] Metadata directory not provided
I20260812 06:16:51.997879 24417 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:16:51.998126 24417 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:16:51.999918 24417 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskg6QwMH/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515411975274-24417-0/minicluster-data/master-0-root/instance:
uuid: "37deffac47d340c8a49bb462d5ec79c3"
format_stamp: "Formatted at 2026-08-12 06:16:51 on dist-test-slave-pgkr"
I20260812 06:16:52.003710 24417 fs_manager.cc:696] Time spent creating directory manager: real 0.003s	user 0.003s	sys 0.001s
I20260812 06:16:52.005950 24433 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:16:52.007066 24417 fs_manager.cc:730] Time spent opening block manager: real 0.002s	user 0.003s	sys 0.000s
I20260812 06:16:52.007216 24417 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskg6QwMH/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515411975274-24417-0/minicluster-data/master-0-root
uuid: "37deffac47d340c8a49bb462d5ec79c3"
format_stamp: "Formatted at 2026-08-12 06:16:51 on dist-test-slave-pgkr"
I20260812 06:16:52.007334 24417 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskg6QwMH/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515411975274-24417-0/minicluster-data/master-0-root
metadata directory: /tmp/dist-test-taskg6QwMH/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515411975274-24417-0/minicluster-data/master-0-root
1 data directories: /tmp/dist-test-taskg6QwMH/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515411975274-24417-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:16:52.036315 24417 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:16:52.037066 24417 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:16:52.037271 24417 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:16:52.046005 24417 rpc_server.cc:307] RPC server started. Bound to: 127.23.216.126:46165
I20260812 06:16:52.046023 24491 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.23.216.126:46165 every 8 connection(s)
I20260812 06:16:52.048548 24492 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:16:52.054811 24492 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P 37deffac47d340c8a49bb462d5ec79c3: Bootstrap starting.
I20260812 06:16:52.057561 24492 tablet_bootstrap.cc:654] T 00000000000000000000000000000000 P 37deffac47d340c8a49bb462d5ec79c3: Neither blocks nor log segments found. Creating new log.
I20260812 06:16:52.058719 24492 log.cc:826] T 00000000000000000000000000000000 P 37deffac47d340c8a49bb462d5ec79c3: Log is configured to *not* fsync() on all Append() calls
I20260812 06:16:52.060787 24492 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P 37deffac47d340c8a49bb462d5ec79c3: No bootstrap required, opened a new log
I20260812 06:16:52.063882 24492 raft_consensus.cc:359] T 00000000000000000000000000000000 P 37deffac47d340c8a49bb462d5ec79c3 [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "37deffac47d340c8a49bb462d5ec79c3" member_type: VOTER }
I20260812 06:16:52.064079 24492 raft_consensus.cc:385] T 00000000000000000000000000000000 P 37deffac47d340c8a49bb462d5ec79c3 [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:16:52.064168 24492 raft_consensus.cc:740] T 00000000000000000000000000000000 P 37deffac47d340c8a49bb462d5ec79c3 [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: 37deffac47d340c8a49bb462d5ec79c3, State: Initialized, Role: FOLLOWER
I20260812 06:16:52.064852 24492 consensus_queue.cc:260] T 00000000000000000000000000000000 P 37deffac47d340c8a49bb462d5ec79c3 [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: "37deffac47d340c8a49bb462d5ec79c3" member_type: VOTER }
I20260812 06:16:52.065042 24492 raft_consensus.cc:399] T 00000000000000000000000000000000 P 37deffac47d340c8a49bb462d5ec79c3 [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:16:52.065117 24492 raft_consensus.cc:493] T 00000000000000000000000000000000 P 37deffac47d340c8a49bb462d5ec79c3 [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:16:52.065315 24492 raft_consensus.cc:3060] T 00000000000000000000000000000000 P 37deffac47d340c8a49bb462d5ec79c3 [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:16:52.066232 24492 raft_consensus.cc:515] T 00000000000000000000000000000000 P 37deffac47d340c8a49bb462d5ec79c3 [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "37deffac47d340c8a49bb462d5ec79c3" member_type: VOTER }
I20260812 06:16:52.066814 24492 leader_election.cc:304] T 00000000000000000000000000000000 P 37deffac47d340c8a49bb462d5ec79c3 [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: 37deffac47d340c8a49bb462d5ec79c3; no voters: 
I20260812 06:16:52.067198 24492 leader_election.cc:290] T 00000000000000000000000000000000 P 37deffac47d340c8a49bb462d5ec79c3 [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:16:52.067404 24495 raft_consensus.cc:2804] T 00000000000000000000000000000000 P 37deffac47d340c8a49bb462d5ec79c3 [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:16:52.067691 24495 raft_consensus.cc:697] T 00000000000000000000000000000000 P 37deffac47d340c8a49bb462d5ec79c3 [term 1 LEADER]: Becoming Leader. State: Replica: 37deffac47d340c8a49bb462d5ec79c3, State: Running, Role: LEADER
I20260812 06:16:52.068164 24495 consensus_queue.cc:237] T 00000000000000000000000000000000 P 37deffac47d340c8a49bb462d5ec79c3 [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: "37deffac47d340c8a49bb462d5ec79c3" member_type: VOTER }
I20260812 06:16:52.068584 24492 sys_catalog.cc:565] T 00000000000000000000000000000000 P 37deffac47d340c8a49bb462d5ec79c3 [sys.catalog]: configured and running, proceeding with master startup.
I20260812 06:16:52.070179 24497 sys_catalog.cc:455] T 00000000000000000000000000000000 P 37deffac47d340c8a49bb462d5ec79c3 [sys.catalog]: SysCatalogTable state changed. Reason: New leader 37deffac47d340c8a49bb462d5ec79c3. Latest consensus state: current_term: 1 leader_uuid: "37deffac47d340c8a49bb462d5ec79c3" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "37deffac47d340c8a49bb462d5ec79c3" member_type: VOTER } }
I20260812 06:16:52.070240 24496 sys_catalog.cc:455] T 00000000000000000000000000000000 P 37deffac47d340c8a49bb462d5ec79c3 [sys.catalog]: SysCatalogTable state changed. Reason: RaftConsensus started. Latest consensus state: current_term: 1 leader_uuid: "37deffac47d340c8a49bb462d5ec79c3" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "37deffac47d340c8a49bb462d5ec79c3" member_type: VOTER } }
I20260812 06:16:52.070338 24496 sys_catalog.cc:458] T 00000000000000000000000000000000 P 37deffac47d340c8a49bb462d5ec79c3 [sys.catalog]: This master's current role is: LEADER
I20260812 06:16:52.070338 24497 sys_catalog.cc:458] T 00000000000000000000000000000000 P 37deffac47d340c8a49bb462d5ec79c3 [sys.catalog]: This master's current role is: LEADER
I20260812 06:16:52.070837 24506 catalog_manager.cc:1511] Loading table and tablet metadata into memory...
I20260812 06:16:52.070967 24417 internal_mini_cluster.cc:184] Waiting to initialize catalog manager on master 0
I20260812 06:16:52.073354 24506 catalog_manager.cc:1520] Initializing Kudu cluster ID...
I20260812 06:16:52.078454 24506 catalog_manager.cc:1383] Generated new cluster ID: cbcd27685e9a43df98fbb600528e26f3
I20260812 06:16:52.078538 24506 catalog_manager.cc:1531] Initializing Kudu internal certificate authority...
I20260812 06:16:52.086761 24506 catalog_manager.cc:1406] Generated new certificate authority record
I20260812 06:16:52.087637 24506 catalog_manager.cc:1540] Loading token signing keys...
I20260812 06:16:52.095521 24506 catalog_manager.cc:6092] T 00000000000000000000000000000000 P 37deffac47d340c8a49bb462d5ec79c3: Generated new TSK 0
I20260812 06:16:52.096220 24506 catalog_manager.cc:1550] Initializing in-progress tserver states...
I20260812 06:16:52.103719 24417 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:16:52.106588 24514 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:16:52.106760 24517 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:16:52.106814 24515 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:16:52.107034 24417 server_base.cc:1061] running on GCE node
I20260812 06:16:52.107264 24417 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:16:52.107307 24417 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:16:52.107323 24417 hybrid_clock.cc:648] HybridClock initialized: now 1786515412107323 us; error 0 us; skew 500 ppm
I20260812 06:16:52.108433 24417 webserver.cc:533] Webserver started at http://127.23.216.65:43727/ using document root <none> and password file <none>
I20260812 06:16:52.108646 24417 fs_manager.cc:362] Metadata directory not provided
I20260812 06:16:52.108705 24417 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:16:52.108814 24417 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:16:52.109418 24417 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskg6QwMH/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515411975274-24417-0/minicluster-data/ts-0-root/instance:
uuid: "813824f78dfa45fcb29184e4c6e98ece"
format_stamp: "Formatted at 2026-08-12 06:16:52 on dist-test-slave-pgkr"
I20260812 06:16:52.111220 24417 fs_manager.cc:696] Time spent creating directory manager: real 0.001s	user 0.003s	sys 0.000s
I20260812 06:16:52.112452 24522 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:16:52.112761 24417 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.001s	sys 0.000s
I20260812 06:16:52.112856 24417 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskg6QwMH/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515411975274-24417-0/minicluster-data/ts-0-root
uuid: "813824f78dfa45fcb29184e4c6e98ece"
format_stamp: "Formatted at 2026-08-12 06:16:52 on dist-test-slave-pgkr"
I20260812 06:16:52.112950 24417 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskg6QwMH/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515411975274-24417-0/minicluster-data/ts-0-root
metadata directory: /tmp/dist-test-taskg6QwMH/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515411975274-24417-0/minicluster-data/ts-0-root
1 data directories: /tmp/dist-test-taskg6QwMH/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515411975274-24417-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:16:52.118539 24417 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:16:52.119076 24417 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:16:52.119588 24417 txn_system_client.cc:432] TxnSystemClient initialization is disabled...
I20260812 06:16:52.120644 24417 ts_tablet_manager.cc:585] Loaded tablet metadata (0 total tablets, 0 live tablets)
I20260812 06:16:52.120762 24417 ts_tablet_manager.cc:531] Time spent load tablet metadata: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:16:52.120899 24417 ts_tablet_manager.cc:616] Registered 0 tablets
I20260812 06:16:52.120945 24417 ts_tablet_manager.cc:595] Time spent register tablets: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:16:52.127923 24417 rpc_server.cc:307] RPC server started. Bound to: 127.23.216.65:34309
I20260812 06:16:52.127981 24597 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.23.216.65:34309 every 8 connection(s)
I20260812 06:16:52.138482 24598 heartbeater.cc:344] Connected to a master server at 127.23.216.126:46165
I20260812 06:16:52.138808 24598 heartbeater.cc:461] Registering TS with master...
I20260812 06:16:52.139292 24598 heartbeater.cc:507] Master 127.23.216.126:46165 requested a full tablet report, sending...
I20260812 06:16:52.140914 24455 ts_manager.cc:194] Registered new tserver with Master: 813824f78dfa45fcb29184e4c6e98ece (127.23.216.65:34309)
I20260812 06:16:52.141240 24417 internal_mini_cluster.cc:371] 1 TS(s) registered with all masters after 0.012558371s
I20260812 06:16:52.142318 24455 master_service.cc:502] Signed X509 certificate for tserver {username='slave'} at 127.0.0.1:40310
I20260812 06:16:52.153127 24455 catalog_manager.cc:2283] Servicing CreateTable request from {username='slave'} at 127.0.0.1:40312:
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:16:52.169353 24555 tablet_service.cc:1511] Processing CreateTablet for tablet c6555552ba2640d68e9debc3930289a1 (DEFAULT_TABLE table=heavy-update-compaction-test [id=ac04a87d11474a00ad3e353184e23b20]), partition=
I20260812 06:16:52.169927 24555 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet c6555552ba2640d68e9debc3930289a1. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:16:52.172986 24610 tablet_bootstrap.cc:492] T c6555552ba2640d68e9debc3930289a1 P 813824f78dfa45fcb29184e4c6e98ece: Bootstrap starting.
I20260812 06:16:52.174031 24610 tablet_bootstrap.cc:654] T c6555552ba2640d68e9debc3930289a1 P 813824f78dfa45fcb29184e4c6e98ece: Neither blocks nor log segments found. Creating new log.
I20260812 06:16:52.175297 24610 tablet_bootstrap.cc:492] T c6555552ba2640d68e9debc3930289a1 P 813824f78dfa45fcb29184e4c6e98ece: No bootstrap required, opened a new log
I20260812 06:16:52.175464 24610 ts_tablet_manager.cc:1403] T c6555552ba2640d68e9debc3930289a1 P 813824f78dfa45fcb29184e4c6e98ece: Time spent bootstrapping tablet: real 0.003s	user 0.000s	sys 0.002s
I20260812 06:16:52.176085 24610 raft_consensus.cc:359] T c6555552ba2640d68e9debc3930289a1 P 813824f78dfa45fcb29184e4c6e98ece [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "813824f78dfa45fcb29184e4c6e98ece" member_type: VOTER last_known_addr { host: "127.23.216.65" port: 34309 } }
I20260812 06:16:52.176240 24610 raft_consensus.cc:385] T c6555552ba2640d68e9debc3930289a1 P 813824f78dfa45fcb29184e4c6e98ece [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:16:52.176329 24610 raft_consensus.cc:740] T c6555552ba2640d68e9debc3930289a1 P 813824f78dfa45fcb29184e4c6e98ece [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: 813824f78dfa45fcb29184e4c6e98ece, State: Initialized, Role: FOLLOWER
I20260812 06:16:52.176488 24610 consensus_queue.cc:260] T c6555552ba2640d68e9debc3930289a1 P 813824f78dfa45fcb29184e4c6e98ece [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: "813824f78dfa45fcb29184e4c6e98ece" member_type: VOTER last_known_addr { host: "127.23.216.65" port: 34309 } }
I20260812 06:16:52.176623 24610 raft_consensus.cc:399] T c6555552ba2640d68e9debc3930289a1 P 813824f78dfa45fcb29184e4c6e98ece [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:16:52.176687 24610 raft_consensus.cc:493] T c6555552ba2640d68e9debc3930289a1 P 813824f78dfa45fcb29184e4c6e98ece [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:16:52.176751 24610 raft_consensus.cc:3060] T c6555552ba2640d68e9debc3930289a1 P 813824f78dfa45fcb29184e4c6e98ece [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:16:52.177556 24610 raft_consensus.cc:515] T c6555552ba2640d68e9debc3930289a1 P 813824f78dfa45fcb29184e4c6e98ece [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "813824f78dfa45fcb29184e4c6e98ece" member_type: VOTER last_known_addr { host: "127.23.216.65" port: 34309 } }
I20260812 06:16:52.177743 24610 leader_election.cc:304] T c6555552ba2640d68e9debc3930289a1 P 813824f78dfa45fcb29184e4c6e98ece [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: 813824f78dfa45fcb29184e4c6e98ece; no voters: 
I20260812 06:16:52.178015 24610 leader_election.cc:290] T c6555552ba2640d68e9debc3930289a1 P 813824f78dfa45fcb29184e4c6e98ece [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:16:52.178133 24612 raft_consensus.cc:2804] T c6555552ba2640d68e9debc3930289a1 P 813824f78dfa45fcb29184e4c6e98ece [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:16:52.178408 24610 ts_tablet_manager.cc:1434] T c6555552ba2640d68e9debc3930289a1 P 813824f78dfa45fcb29184e4c6e98ece: Time spent starting tablet: real 0.003s	user 0.000s	sys 0.003s
I20260812 06:16:52.178702 24598 heartbeater.cc:499] Master 127.23.216.126:46165 was elected leader, sending a full tablet report...
I20260812 06:16:52.178408 24612 raft_consensus.cc:697] T c6555552ba2640d68e9debc3930289a1 P 813824f78dfa45fcb29184e4c6e98ece [term 1 LEADER]: Becoming Leader. State: Replica: 813824f78dfa45fcb29184e4c6e98ece, State: Running, Role: LEADER
I20260812 06:16:52.179162 24612 consensus_queue.cc:237] T c6555552ba2640d68e9debc3930289a1 P 813824f78dfa45fcb29184e4c6e98ece [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: "813824f78dfa45fcb29184e4c6e98ece" member_type: VOTER last_known_addr { host: "127.23.216.65" port: 34309 } }
I20260812 06:16:52.182255 24454 catalog_manager.cc:5719] T c6555552ba2640d68e9debc3930289a1 P 813824f78dfa45fcb29184e4c6e98ece reported cstate change: term changed from 0 to 1, leader changed from <none> to 813824f78dfa45fcb29184e4c6e98ece (127.23.216.65). New cstate: current_term: 1 leader_uuid: "813824f78dfa45fcb29184e4c6e98ece" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "813824f78dfa45fcb29184e4c6e98ece" member_type: VOTER last_known_addr { host: "127.23.216.65" port: 34309 } health_report { overall_health: HEALTHY } } }
I20260812 06:16:52.253314 24417 heavy-update-compaction-itest.cc:215] Time spent inserting: real 0.064s	user 0.011s	sys 0.020s
I20260812 06:16:52.379321 24599 maintenance_manager.cc:419] P 813824f78dfa45fcb29184e4c6e98ece: Scheduling FlushMRSOp(c6555552ba2640d68e9debc3930289a1): perf score=15.086190
I20260812 06:16:52.531427 24528 maintenance_manager.cc:643] P 813824f78dfa45fcb29184e4c6e98ece: FlushMRSOp(c6555552ba2640d68e9debc3930289a1) complete. Timing: real 0.152s	user 0.090s	sys 0.048s Metrics: {"bytes_written":11897249,"cfile_init":1,"compiler_manager_pool.queue_time_us":261,"delete_count":0,"dirs.queue_time_us":64,"dirs.run_cpu_time_us":228,"dirs.run_wall_time_us":871,"drs_written":1,"lbm_read_time_us":76,"lbm_reads_lt_1ms":4,"lbm_write_time_us":34230,"lbm_writes_lt_1ms":657,"peak_mem_usage":0,"reinsert_count":0,"rows_written":104,"thread_start_us":160,"threads_started":1,"update_count":1450}
I20260812 06:16:52.532508 24599 maintenance_manager.cc:419] P 813824f78dfa45fcb29184e4c6e98ece: Scheduling LogGCOp(c6555552ba2640d68e9debc3930289a1): free 20743880 bytes of WAL
I20260812 06:16:52.532825 24528 log_reader.cc:385] T c6555552ba2640d68e9debc3930289a1: removed 2 log segments from log reader
I20260812 06:16:52.532907 24528 log.cc:1079] T c6555552ba2640d68e9debc3930289a1 P 813824f78dfa45fcb29184e4c6e98ece: Deleting log segment in path: /tmp/dist-test-taskg6QwMH/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515411975274-24417-0/minicluster-data/ts-0-root/wals/c6555552ba2640d68e9debc3930289a1/wal-000000001 (ops 1-6)
I20260812 06:16:52.532984 24528 log.cc:1079] T c6555552ba2640d68e9debc3930289a1 P 813824f78dfa45fcb29184e4c6e98ece: Deleting log segment in path: /tmp/dist-test-taskg6QwMH/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515411975274-24417-0/minicluster-data/ts-0-root/wals/c6555552ba2640d68e9debc3930289a1/wal-000000002 (ops 7-11)
I20260812 06:16:52.537252 24528 maintenance_manager.cc:643] P 813824f78dfa45fcb29184e4c6e98ece: LogGCOp(c6555552ba2640d68e9debc3930289a1) complete. Timing: real 0.005s	user 0.000s	sys 0.002s Metrics: {}
I20260812 06:16:52.537606 24599 maintenance_manager.cc:419] P 813824f78dfa45fcb29184e4c6e98ece: Scheduling FlushDeltaMemStoresOp(c6555552ba2640d68e9debc3930289a1): perf score=2.188937
I20260812 06:16:52.555128 24528 maintenance_manager.cc:643] P 813824f78dfa45fcb29184e4c6e98ece: FlushDeltaMemStoresOp(c6555552ba2640d68e9debc3930289a1) complete. Timing: real 0.017s	user 0.012s	sys 0.003s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5880,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:52.555617 24599 maintenance_manager.cc:419] P 813824f78dfa45fcb29184e4c6e98ece: Scheduling UndoDeltaBlockGCOp(c6555552ba2640d68e9debc3930289a1): 12719214 bytes on disk
I20260812 06:16:52.556193 24528 maintenance_manager.cc:643] P 813824f78dfa45fcb29184e4c6e98ece: UndoDeltaBlockGCOp(c6555552ba2640d68e9debc3930289a1) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":50,"lbm_reads_lt_1ms":4}
I20260812 06:16:52.556612 24599 maintenance_manager.cc:419] P 813824f78dfa45fcb29184e4c6e98ece: Scheduling MajorDeltaCompactionOp(c6555552ba2640d68e9debc3930289a1): perf score=1.000000
I20260812 06:16:52.699977 24528 maintenance_manager.cc:643] P 813824f78dfa45fcb29184e4c6e98ece: MajorDeltaCompactionOp(c6555552ba2640d68e9debc3930289a1) complete. Timing: real 0.143s	user 0.115s	sys 0.028s Metrics: {"cfile_cache_miss":422,"cfile_cache_miss_bytes":20262036,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":907,"lbm_read_time_us":7564,"lbm_reads_lt_1ms":454,"lbm_write_time_us":28910,"lbm_writes_lt_1ms":433,"mutex_wait_us":23,"peak_mem_usage":49238594,"reinsert_count":0,"spinlock_wait_cycles":9472,"thread_start_us":314,"threads_started":5,"update_count":1950}
I20260812 06:16:52.700557 24599 maintenance_manager.cc:419] P 813824f78dfa45fcb29184e4c6e98ece: Scheduling FlushDeltaMemStoresOp(c6555552ba2640d68e9debc3930289a1): perf score=10.126437
I20260812 06:16:52.746908 24528 maintenance_manager.cc:643] P 813824f78dfa45fcb29184e4c6e98ece: FlushDeltaMemStoresOp(c6555552ba2640d68e9debc3930289a1) complete. Timing: real 0.046s	user 0.029s	sys 0.008s Metrics: {"bytes_written":12307492,"delete_count":0,"lbm_write_time_us":17195,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":302,"reinsert_count":0,"update_count":1500}
I20260812 06:16:52.747366 24599 maintenance_manager.cc:419] P 813824f78dfa45fcb29184e4c6e98ece: Scheduling FlushDeltaMemStoresOp(c6555552ba2640d68e9debc3930289a1): perf score=2.188937
I20260812 06:16:52.757959 24528 maintenance_manager.cc:643] P 813824f78dfa45fcb29184e4c6e98ece: FlushDeltaMemStoresOp(c6555552ba2640d68e9debc3930289a1) complete. Timing: real 0.010s	user 0.009s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4146,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:52.758729 24599 maintenance_manager.cc:419] P 813824f78dfa45fcb29184e4c6e98ece: Scheduling MajorDeltaCompactionOp(c6555552ba2640d68e9debc3930289a1): perf score=1.000000
I20260812 06:16:52.887820 24528 maintenance_manager.cc:643] P 813824f78dfa45fcb29184e4c6e98ece: MajorDeltaCompactionOp(c6555552ba2640d68e9debc3930289a1) complete. Timing: real 0.129s	user 0.108s	sys 0.021s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672279,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":315,"lbm_read_time_us":9445,"lbm_reads_lt_1ms":472,"lbm_write_time_us":25980,"lbm_writes_lt_1ms":443,"mutex_wait_us":44,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":583552,"update_count":2000}
I20260812 06:16:52.888523 24599 maintenance_manager.cc:419] P 813824f78dfa45fcb29184e4c6e98ece: Scheduling FlushDeltaMemStoresOp(c6555552ba2640d68e9debc3930289a1): perf score=10.126437
I20260812 06:16:52.935876 24528 maintenance_manager.cc:643] P 813824f78dfa45fcb29184e4c6e98ece: FlushDeltaMemStoresOp(c6555552ba2640d68e9debc3930289a1) complete. Timing: real 0.047s	user 0.034s	sys 0.008s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":19285,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:16:52.936410 24599 maintenance_manager.cc:419] P 813824f78dfa45fcb29184e4c6e98ece: Scheduling FlushDeltaMemStoresOp(c6555552ba2640d68e9debc3930289a1): perf score=2.188937
I20260812 06:16:52.949558 24528 maintenance_manager.cc:643] P 813824f78dfa45fcb29184e4c6e98ece: FlushDeltaMemStoresOp(c6555552ba2640d68e9debc3930289a1) complete. Timing: real 0.013s	user 0.010s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4685,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:52.950028 24599 maintenance_manager.cc:419] P 813824f78dfa45fcb29184e4c6e98ece: Scheduling MajorDeltaCompactionOp(c6555552ba2640d68e9debc3930289a1): perf score=1.000000
I20260812 06:16:53.072485 24528 maintenance_manager.cc:643] P 813824f78dfa45fcb29184e4c6e98ece: MajorDeltaCompactionOp(c6555552ba2640d68e9debc3930289a1) complete. Timing: real 0.122s	user 0.096s	sys 0.026s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672277,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":1027,"lbm_read_time_us":7981,"lbm_reads_lt_1ms":472,"lbm_write_time_us":25673,"lbm_writes_lt_1ms":443,"mutex_wait_us":326,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":2176,"update_count":2000}
I20260812 06:16:53.073107 24599 maintenance_manager.cc:419] P 813824f78dfa45fcb29184e4c6e98ece: Scheduling FlushDeltaMemStoresOp(c6555552ba2640d68e9debc3930289a1): perf score=10.126437
I20260812 06:16:53.122828 24528 maintenance_manager.cc:643] P 813824f78dfa45fcb29184e4c6e98ece: FlushDeltaMemStoresOp(c6555552ba2640d68e9debc3930289a1) complete. Timing: real 0.050s	user 0.031s	sys 0.013s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":15699,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:16:53.123423 24599 maintenance_manager.cc:419] P 813824f78dfa45fcb29184e4c6e98ece: Scheduling FlushDeltaMemStoresOp(c6555552ba2640d68e9debc3930289a1): perf score=2.188937
I20260812 06:16:53.134279 24528 maintenance_manager.cc:643] P 813824f78dfa45fcb29184e4c6e98ece: FlushDeltaMemStoresOp(c6555552ba2640d68e9debc3930289a1) complete. Timing: real 0.011s	user 0.009s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4182,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:53.134811 24599 maintenance_manager.cc:419] P 813824f78dfa45fcb29184e4c6e98ece: Scheduling MajorDeltaCompactionOp(c6555552ba2640d68e9debc3930289a1): perf score=1.000000
I20260812 06:16:53.276055 24528 maintenance_manager.cc:643] P 813824f78dfa45fcb29184e4c6e98ece: MajorDeltaCompactionOp(c6555552ba2640d68e9debc3930289a1) complete. Timing: real 0.141s	user 0.098s	sys 0.043s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672277,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":177,"lbm_read_time_us":11178,"lbm_reads_lt_1ms":472,"lbm_write_time_us":23454,"lbm_writes_lt_1ms":443,"mutex_wait_us":28,"peak_mem_usage":50689328,"reinsert_count":0,"update_count":2000}
I20260812 06:16:53.279434 24599 maintenance_manager.cc:419] P 813824f78dfa45fcb29184e4c6e98ece: Scheduling FlushDeltaMemStoresOp(c6555552ba2640d68e9debc3930289a1): perf score=10.126437
I20260812 06:16:53.320958 24528 maintenance_manager.cc:643] P 813824f78dfa45fcb29184e4c6e98ece: FlushDeltaMemStoresOp(c6555552ba2640d68e9debc3930289a1) complete. Timing: real 0.041s	user 0.012s	sys 0.025s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":16318,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:16:53.321446 24599 maintenance_manager.cc:419] P 813824f78dfa45fcb29184e4c6e98ece: Scheduling FlushDeltaMemStoresOp(c6555552ba2640d68e9debc3930289a1): perf score=2.188937
I20260812 06:16:53.334075 24528 maintenance_manager.cc:643] P 813824f78dfa45fcb29184e4c6e98ece: FlushDeltaMemStoresOp(c6555552ba2640d68e9debc3930289a1) complete. Timing: real 0.012s	user 0.007s	sys 0.003s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4572,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:53.334861 24599 maintenance_manager.cc:419] P 813824f78dfa45fcb29184e4c6e98ece: Scheduling MajorDeltaCompactionOp(c6555552ba2640d68e9debc3930289a1): perf score=1.000000
I20260812 06:16:53.462822 24528 maintenance_manager.cc:643] P 813824f78dfa45fcb29184e4c6e98ece: MajorDeltaCompactionOp(c6555552ba2640d68e9debc3930289a1) complete. Timing: real 0.128s	user 0.086s	sys 0.039s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672277,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":531,"lbm_read_time_us":8328,"lbm_reads_lt_1ms":472,"lbm_write_time_us":25668,"lbm_writes_lt_1ms":443,"mutex_wait_us":160,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":14592,"update_count":2000}
I20260812 06:16:53.463641 24599 maintenance_manager.cc:419] P 813824f78dfa45fcb29184e4c6e98ece: Scheduling FlushDeltaMemStoresOp(c6555552ba2640d68e9debc3930289a1): perf score=10.126437
I20260812 06:16:53.505088 24528 maintenance_manager.cc:643] P 813824f78dfa45fcb29184e4c6e98ece: FlushDeltaMemStoresOp(c6555552ba2640d68e9debc3930289a1) complete. Timing: real 0.041s	user 0.005s	sys 0.033s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":18972,"lbm_writes_1-10_ms":2,"lbm_writes_lt_1ms":301,"reinsert_count":0,"update_count":1500}
I20260812 06:16:53.506047 24599 maintenance_manager.cc:419] P 813824f78dfa45fcb29184e4c6e98ece: Scheduling FlushDeltaMemStoresOp(c6555552ba2640d68e9debc3930289a1): perf score=2.188937
I20260812 06:16:53.521605 24528 maintenance_manager.cc:643] P 813824f78dfa45fcb29184e4c6e98ece: FlushDeltaMemStoresOp(c6555552ba2640d68e9debc3930289a1) complete. Timing: real 0.015s	user 0.011s	sys 0.003s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5830,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:53.522142 24599 maintenance_manager.cc:419] P 813824f78dfa45fcb29184e4c6e98ece: Scheduling MajorDeltaCompactionOp(c6555552ba2640d68e9debc3930289a1): perf score=1.000000
I20260812 06:16:53.645421 24528 maintenance_manager.cc:643] P 813824f78dfa45fcb29184e4c6e98ece: MajorDeltaCompactionOp(c6555552ba2640d68e9debc3930289a1) complete. Timing: real 0.123s	user 0.107s	sys 0.016s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672277,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":368,"lbm_read_time_us":8483,"lbm_reads_lt_1ms":464,"lbm_write_time_us":23415,"lbm_writes_lt_1ms":443,"peak_mem_usage":50689328,"reinsert_count":0,"update_count":2000}
I20260812 06:16:53.646142 24599 maintenance_manager.cc:419] P 813824f78dfa45fcb29184e4c6e98ece: Scheduling FlushDeltaMemStoresOp(c6555552ba2640d68e9debc3930289a1): perf score=10.126437
I20260812 06:16:53.688898 24528 maintenance_manager.cc:643] P 813824f78dfa45fcb29184e4c6e98ece: FlushDeltaMemStoresOp(c6555552ba2640d68e9debc3930289a1) complete. Timing: real 0.043s	user 0.021s	sys 0.016s Metrics: {"bytes_written":12307491,"delete_count":0,"lbm_write_time_us":17339,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:16:53.689527 24599 maintenance_manager.cc:419] P 813824f78dfa45fcb29184e4c6e98ece: Scheduling FlushDeltaMemStoresOp(c6555552ba2640d68e9debc3930289a1): perf score=2.188937
I20260812 06:16:53.700613 24528 maintenance_manager.cc:643] P 813824f78dfa45fcb29184e4c6e98ece: FlushDeltaMemStoresOp(c6555552ba2640d68e9debc3930289a1) complete. Timing: real 0.011s	user 0.001s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4186,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:53.701197 24599 maintenance_manager.cc:419] P 813824f78dfa45fcb29184e4c6e98ece: Scheduling MajorDeltaCompactionOp(c6555552ba2640d68e9debc3930289a1): perf score=1.000000
I20260812 06:16:53.827323 24528 maintenance_manager.cc:643] P 813824f78dfa45fcb29184e4c6e98ece: MajorDeltaCompactionOp(c6555552ba2640d68e9debc3930289a1) complete. Timing: real 0.125s	user 0.092s	sys 0.032s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672278,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":621,"lbm_read_time_us":9349,"lbm_reads_lt_1ms":472,"lbm_write_time_us":24425,"lbm_writes_lt_1ms":443,"mutex_wait_us":28,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":2304,"update_count":2000}
I20260812 06:16:53.827843 24599 maintenance_manager.cc:419] P 813824f78dfa45fcb29184e4c6e98ece: Scheduling FlushDeltaMemStoresOp(c6555552ba2640d68e9debc3930289a1): perf score=10.126437
I20260812 06:16:53.864641 24528 maintenance_manager.cc:643] P 813824f78dfa45fcb29184e4c6e98ece: FlushDeltaMemStoresOp(c6555552ba2640d68e9debc3930289a1) complete. Timing: real 0.037s	user 0.019s	sys 0.015s Metrics: {"bytes_written":12307489,"delete_count":0,"lbm_write_time_us":12679,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:16:53.865217 24599 maintenance_manager.cc:419] P 813824f78dfa45fcb29184e4c6e98ece: Scheduling FlushDeltaMemStoresOp(c6555552ba2640d68e9debc3930289a1): perf score=2.188937
I20260812 06:16:53.876339 24528 maintenance_manager.cc:643] P 813824f78dfa45fcb29184e4c6e98ece: FlushDeltaMemStoresOp(c6555552ba2640d68e9debc3930289a1) complete. Timing: real 0.011s	user 0.009s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4479,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:53.876787 24599 maintenance_manager.cc:419] P 813824f78dfa45fcb29184e4c6e98ece: Scheduling FlushMRSOp(c6555552ba2640d68e9debc3930289a1): perf score=1.000000
I20260812 06:16:53.921476 24528 maintenance_manager.cc:643] P 813824f78dfa45fcb29184e4c6e98ece: FlushMRSOp(c6555552ba2640d68e9debc3930289a1) complete. Timing: real 0.044s	user 0.031s	sys 0.000s Metrics: {"bytes_written":1275443,"cfile_init":1,"dirs.queue_time_us":74,"dirs.run_cpu_time_us":250,"dirs.run_wall_time_us":1467,"drs_written":1,"lbm_read_time_us":60,"lbm_reads_lt_1ms":4,"lbm_write_time_us":2355,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":31}
I20260812 06:16:53.922313 24599 maintenance_manager.cc:419] P 813824f78dfa45fcb29184e4c6e98ece: Scheduling LogGCOp(c6555552ba2640d68e9debc3930289a1): free 124710298 bytes of WAL
I20260812 06:16:53.922544 24528 log_reader.cc:385] T c6555552ba2640d68e9debc3930289a1: removed 12 log segments from log reader
I20260812 06:16:53.922608 24528 log.cc:1079] T c6555552ba2640d68e9debc3930289a1 P 813824f78dfa45fcb29184e4c6e98ece: Deleting log segment in path: /tmp/dist-test-taskg6QwMH/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515411975274-24417-0/minicluster-data/ts-0-root/wals/c6555552ba2640d68e9debc3930289a1/wal-000000003 (ops 12-16)
I20260812 06:16:53.922683 24528 log.cc:1079] T c6555552ba2640d68e9debc3930289a1 P 813824f78dfa45fcb29184e4c6e98ece: Deleting log segment in path: /tmp/dist-test-taskg6QwMH/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515411975274-24417-0/minicluster-data/ts-0-root/wals/c6555552ba2640d68e9debc3930289a1/wal-000000004 (ops 17-21)
I20260812 06:16:53.922751 24528 log.cc:1079] T c6555552ba2640d68e9debc3930289a1 P 813824f78dfa45fcb29184e4c6e98ece: Deleting log segment in path: /tmp/dist-test-taskg6QwMH/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515411975274-24417-0/minicluster-data/ts-0-root/wals/c6555552ba2640d68e9debc3930289a1/wal-000000005 (ops 22-26)
I20260812 06:16:53.922791 24528 log.cc:1079] T c6555552ba2640d68e9debc3930289a1 P 813824f78dfa45fcb29184e4c6e98ece: Deleting log segment in path: /tmp/dist-test-taskg6QwMH/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515411975274-24417-0/minicluster-data/ts-0-root/wals/c6555552ba2640d68e9debc3930289a1/wal-000000006 (ops 27-31)
I20260812 06:16:53.922827 24528 log.cc:1079] T c6555552ba2640d68e9debc3930289a1 P 813824f78dfa45fcb29184e4c6e98ece: Deleting log segment in path: /tmp/dist-test-taskg6QwMH/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515411975274-24417-0/minicluster-data/ts-0-root/wals/c6555552ba2640d68e9debc3930289a1/wal-000000007 (ops 32-36)
I20260812 06:16:53.922863 24528 log.cc:1079] T c6555552ba2640d68e9debc3930289a1 P 813824f78dfa45fcb29184e4c6e98ece: Deleting log segment in path: /tmp/dist-test-taskg6QwMH/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515411975274-24417-0/minicluster-data/ts-0-root/wals/c6555552ba2640d68e9debc3930289a1/wal-000000008 (ops 37-41)
I20260812 06:16:53.922899 24528 log.cc:1079] T c6555552ba2640d68e9debc3930289a1 P 813824f78dfa45fcb29184e4c6e98ece: Deleting log segment in path: /tmp/dist-test-taskg6QwMH/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515411975274-24417-0/minicluster-data/ts-0-root/wals/c6555552ba2640d68e9debc3930289a1/wal-000000009 (ops 42-46)
I20260812 06:16:53.922935 24528 log.cc:1079] T c6555552ba2640d68e9debc3930289a1 P 813824f78dfa45fcb29184e4c6e98ece: Deleting log segment in path: /tmp/dist-test-taskg6QwMH/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515411975274-24417-0/minicluster-data/ts-0-root/wals/c6555552ba2640d68e9debc3930289a1/wal-000000010 (ops 47-51)
I20260812 06:16:53.922971 24528 log.cc:1079] T c6555552ba2640d68e9debc3930289a1 P 813824f78dfa45fcb29184e4c6e98ece: Deleting log segment in path: /tmp/dist-test-taskg6QwMH/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515411975274-24417-0/minicluster-data/ts-0-root/wals/c6555552ba2640d68e9debc3930289a1/wal-000000011 (ops 52-56)
I20260812 06:16:53.923004 24528 log.cc:1079] T c6555552ba2640d68e9debc3930289a1 P 813824f78dfa45fcb29184e4c6e98ece: Deleting log segment in path: /tmp/dist-test-taskg6QwMH/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515411975274-24417-0/minicluster-data/ts-0-root/wals/c6555552ba2640d68e9debc3930289a1/wal-000000012 (ops 57-61)
I20260812 06:16:53.923040 24528 log.cc:1079] T c6555552ba2640d68e9debc3930289a1 P 813824f78dfa45fcb29184e4c6e98ece: Deleting log segment in path: /tmp/dist-test-taskg6QwMH/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515411975274-24417-0/minicluster-data/ts-0-root/wals/c6555552ba2640d68e9debc3930289a1/wal-000000013 (ops 62-66)
I20260812 06:16:53.923074 24528 log.cc:1079] T c6555552ba2640d68e9debc3930289a1 P 813824f78dfa45fcb29184e4c6e98ece: Deleting log segment in path: /tmp/dist-test-taskg6QwMH/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515411975274-24417-0/minicluster-data/ts-0-root/wals/c6555552ba2640d68e9debc3930289a1/wal-000000014 (ops 67-71)
I20260812 06:16:53.950196 24528 maintenance_manager.cc:643] P 813824f78dfa45fcb29184e4c6e98ece: LogGCOp(c6555552ba2640d68e9debc3930289a1) complete. Timing: real 0.028s	user 0.001s	sys 0.023s Metrics: {}
I20260812 06:16:53.950682 24599 maintenance_manager.cc:419] P 813824f78dfa45fcb29184e4c6e98ece: Scheduling FlushDeltaMemStoresOp(c6555552ba2640d68e9debc3930289a1): perf score=2.188937
I20260812 06:16:53.971539 24528 maintenance_manager.cc:643] P 813824f78dfa45fcb29184e4c6e98ece: FlushDeltaMemStoresOp(c6555552ba2640d68e9debc3930289a1) complete. Timing: real 0.021s	user 0.009s	sys 0.006s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6116,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:53.971982 24599 maintenance_manager.cc:419] P 813824f78dfa45fcb29184e4c6e98ece: Scheduling FlushDeltaMemStoresOp(c6555552ba2640d68e9debc3930289a1): perf score=2.188937
I20260812 06:16:53.982299 24528 maintenance_manager.cc:643] P 813824f78dfa45fcb29184e4c6e98ece: FlushDeltaMemStoresOp(c6555552ba2640d68e9debc3930289a1) complete. Timing: real 0.010s	user 0.003s	sys 0.005s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3919,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:53.982856 24599 maintenance_manager.cc:419] P 813824f78dfa45fcb29184e4c6e98ece: Scheduling MajorDeltaCompactionOp(c6555552ba2640d68e9debc3930289a1): perf score=1.000000
I20260812 06:16:54.185328 24528 maintenance_manager.cc:643] P 813824f78dfa45fcb29184e4c6e98ece: MajorDeltaCompactionOp(c6555552ba2640d68e9debc3930289a1) complete. Timing: real 0.202s	user 0.140s	sys 0.062s Metrics: {"cfile_cache_miss":634,"cfile_cache_miss_bytes":28877338,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":1161,"lbm_read_time_us":13658,"lbm_reads_lt_1ms":674,"lbm_write_time_us":35741,"lbm_writes_lt_1ms":643,"mutex_wait_us":2,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":1152,"thread_start_us":89,"threads_started":1,"update_count":3000}
I20260812 06:16:54.187033 24599 maintenance_manager.cc:419] P 813824f78dfa45fcb29184e4c6e98ece: Scheduling UndoDeltaBlockGCOp(c6555552ba2640d68e9debc3930289a1): 483 bytes on disk
I20260812 06:16:54.187680 24528 maintenance_manager.cc:643] P 813824f78dfa45fcb29184e4c6e98ece: UndoDeltaBlockGCOp(c6555552ba2640d68e9debc3930289a1) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":102,"lbm_reads_lt_1ms":4}
I20260812 06:16:54.188431 24599 maintenance_manager.cc:419] P 813824f78dfa45fcb29184e4c6e98ece: Scheduling FlushDeltaMemStoresOp(c6555552ba2640d68e9debc3930289a1): perf score=14.095187
I20260812 06:16:54.252945 24528 maintenance_manager.cc:643] P 813824f78dfa45fcb29184e4c6e98ece: FlushDeltaMemStoresOp(c6555552ba2640d68e9debc3930289a1) complete. Timing: real 0.064s	user 0.042s	sys 0.008s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":23472,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:16:54.253485 24599 maintenance_manager.cc:419] P 813824f78dfa45fcb29184e4c6e98ece: Scheduling FlushDeltaMemStoresOp(c6555552ba2640d68e9debc3930289a1): perf score=2.188937
I20260812 06:16:54.265313 24528 maintenance_manager.cc:643] P 813824f78dfa45fcb29184e4c6e98ece: FlushDeltaMemStoresOp(c6555552ba2640d68e9debc3930289a1) complete. Timing: real 0.012s	user 0.006s	sys 0.003s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4179,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:54.266021 24599 maintenance_manager.cc:419] P 813824f78dfa45fcb29184e4c6e98ece: Scheduling MajorDeltaCompactionOp(c6555552ba2640d68e9debc3930289a1): perf score=1.000000
I20260812 06:16:54.427059 24528 maintenance_manager.cc:643] P 813824f78dfa45fcb29184e4c6e98ece: MajorDeltaCompactionOp(c6555552ba2640d68e9debc3930289a1) complete. Timing: real 0.161s	user 0.109s	sys 0.052s 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":311,"lbm_read_time_us":11505,"lbm_reads_lt_1ms":572,"lbm_write_time_us":26975,"lbm_writes_lt_1ms":543,"mutex_wait_us":42,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":110848,"update_count":2500}
I20260812 06:16:54.427834 24599 maintenance_manager.cc:419] P 813824f78dfa45fcb29184e4c6e98ece: Scheduling FlushDeltaMemStoresOp(c6555552ba2640d68e9debc3930289a1): perf score=14.095187
I20260812 06:16:54.484277 24528 maintenance_manager.cc:643] P 813824f78dfa45fcb29184e4c6e98ece: FlushDeltaMemStoresOp(c6555552ba2640d68e9debc3930289a1) complete. Timing: real 0.056s	user 0.019s	sys 0.027s Metrics: {"bytes_written":16409900,"delete_count":0,"lbm_write_time_us":17914,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:16:54.484881 24599 maintenance_manager.cc:419] P 813824f78dfa45fcb29184e4c6e98ece: Scheduling FlushDeltaMemStoresOp(c6555552ba2640d68e9debc3930289a1): perf score=2.188937
I20260812 06:16:54.495813 24528 maintenance_manager.cc:643] P 813824f78dfa45fcb29184e4c6e98ece: FlushDeltaMemStoresOp(c6555552ba2640d68e9debc3930289a1) complete. Timing: real 0.011s	user 0.001s	sys 0.008s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4175,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:54.496321 24599 maintenance_manager.cc:419] P 813824f78dfa45fcb29184e4c6e98ece: Scheduling MajorDeltaCompactionOp(c6555552ba2640d68e9debc3930289a1): perf score=1.000000
I20260812 06:16:54.672791 24528 maintenance_manager.cc:643] P 813824f78dfa45fcb29184e4c6e98ece: MajorDeltaCompactionOp(c6555552ba2640d68e9debc3930289a1) complete. Timing: real 0.176s	user 0.122s	sys 0.054s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774686,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":418,"lbm_read_time_us":12153,"lbm_reads_lt_1ms":572,"lbm_write_time_us":32336,"lbm_writes_lt_1ms":543,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":2176,"update_count":2500}
I20260812 06:16:54.673449 24599 maintenance_manager.cc:419] P 813824f78dfa45fcb29184e4c6e98ece: Scheduling FlushDeltaMemStoresOp(c6555552ba2640d68e9debc3930289a1): perf score=10.126437
I20260812 06:16:54.708377 24528 maintenance_manager.cc:643] P 813824f78dfa45fcb29184e4c6e98ece: FlushDeltaMemStoresOp(c6555552ba2640d68e9debc3930289a1) complete. Timing: real 0.035s	user 0.016s	sys 0.017s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":15178,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:16:54.708967 24599 maintenance_manager.cc:419] P 813824f78dfa45fcb29184e4c6e98ece: Scheduling FlushDeltaMemStoresOp(c6555552ba2640d68e9debc3930289a1): perf score=2.188937
I20260812 06:16:54.725615 24528 maintenance_manager.cc:643] P 813824f78dfa45fcb29184e4c6e98ece: FlushDeltaMemStoresOp(c6555552ba2640d68e9debc3930289a1) complete. Timing: real 0.016s	user 0.010s	sys 0.003s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":6315,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:54.726109 24599 maintenance_manager.cc:419] P 813824f78dfa45fcb29184e4c6e98ece: Scheduling MajorDeltaCompactionOp(c6555552ba2640d68e9debc3930289a1): perf score=1.000000
I20260812 06:16:54.924190 24528 maintenance_manager.cc:643] P 813824f78dfa45fcb29184e4c6e98ece: MajorDeltaCompactionOp(c6555552ba2640d68e9debc3930289a1) complete. Timing: real 0.198s	user 0.120s	sys 0.072s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672276,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":409,"lbm_read_time_us":10108,"lbm_reads_lt_1ms":472,"lbm_write_time_us":32178,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":442,"mutex_wait_us":85,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":7424,"update_count":2000}
I20260812 06:16:54.925262 24599 maintenance_manager.cc:419] P 813824f78dfa45fcb29184e4c6e98ece: Scheduling FlushDeltaMemStoresOp(c6555552ba2640d68e9debc3930289a1): perf score=10.126437
I20260812 06:16:54.989149 24528 maintenance_manager.cc:643] P 813824f78dfa45fcb29184e4c6e98ece: FlushDeltaMemStoresOp(c6555552ba2640d68e9debc3930289a1) complete. Timing: real 0.064s	user 0.050s	sys 0.012s Metrics: {"bytes_written":12307493,"delete_count":0,"lbm_write_time_us":27867,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:16:54.990221 24599 maintenance_manager.cc:419] P 813824f78dfa45fcb29184e4c6e98ece: Scheduling FlushDeltaMemStoresOp(c6555552ba2640d68e9debc3930289a1): perf score=2.188937
I20260812 06:16:55.022667 24528 maintenance_manager.cc:643] P 813824f78dfa45fcb29184e4c6e98ece: FlushDeltaMemStoresOp(c6555552ba2640d68e9debc3930289a1) complete. Timing: real 0.032s	user 0.016s	sys 0.015s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":12104,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:55.024681 24599 maintenance_manager.cc:419] P 813824f78dfa45fcb29184e4c6e98ece: Scheduling MajorDeltaCompactionOp(c6555552ba2640d68e9debc3930289a1): perf score=1.000000
I20260812 06:16:55.254060 24528 maintenance_manager.cc:643] P 813824f78dfa45fcb29184e4c6e98ece: MajorDeltaCompactionOp(c6555552ba2640d68e9debc3930289a1) complete. Timing: real 0.229s	user 0.165s	sys 0.064s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672280,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":95,"lbm_read_time_us":18707,"lbm_reads_lt_1ms":464,"lbm_write_time_us":47117,"lbm_writes_1-10_ms":2,"lbm_writes_lt_1ms":441,"mutex_wait_us":30,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":10240,"update_count":2000}
I20260812 06:16:55.255394 24599 maintenance_manager.cc:419] P 813824f78dfa45fcb29184e4c6e98ece: Scheduling FlushDeltaMemStoresOp(c6555552ba2640d68e9debc3930289a1): perf score=10.126437
I20260812 06:16:55.355649 24528 maintenance_manager.cc:643] P 813824f78dfa45fcb29184e4c6e98ece: FlushDeltaMemStoresOp(c6555552ba2640d68e9debc3930289a1) complete. Timing: real 0.100s	user 0.055s	sys 0.028s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":38979,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:16:55.356884 24599 maintenance_manager.cc:419] P 813824f78dfa45fcb29184e4c6e98ece: Scheduling FlushDeltaMemStoresOp(c6555552ba2640d68e9debc3930289a1): perf score=2.188937
I20260812 06:16:55.373569 24528 maintenance_manager.cc:643] P 813824f78dfa45fcb29184e4c6e98ece: FlushDeltaMemStoresOp(c6555552ba2640d68e9debc3930289a1) complete. Timing: real 0.016s	user 0.014s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6281,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:55.375429 24599 maintenance_manager.cc:419] P 813824f78dfa45fcb29184e4c6e98ece: Scheduling MajorDeltaCompactionOp(c6555552ba2640d68e9debc3930289a1): perf score=1.000000
I20260812 06:16:55.618152 24528 maintenance_manager.cc:643] P 813824f78dfa45fcb29184e4c6e98ece: MajorDeltaCompactionOp(c6555552ba2640d68e9debc3930289a1) complete. Timing: real 0.242s	user 0.193s	sys 0.048s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672277,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":522,"lbm_read_time_us":16405,"lbm_reads_lt_1ms":472,"lbm_write_time_us":52949,"lbm_writes_1-10_ms":2,"lbm_writes_lt_1ms":441,"mutex_wait_us":10,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":23424,"update_count":2000}
I20260812 06:16:55.619150 24599 maintenance_manager.cc:419] P 813824f78dfa45fcb29184e4c6e98ece: Scheduling FlushDeltaMemStoresOp(c6555552ba2640d68e9debc3930289a1): perf score=10.126437
I20260812 06:16:55.712807 24528 maintenance_manager.cc:643] P 813824f78dfa45fcb29184e4c6e98ece: FlushDeltaMemStoresOp(c6555552ba2640d68e9debc3930289a1) complete. Timing: real 0.093s	user 0.032s	sys 0.044s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":29040,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:16:55.713744 24599 maintenance_manager.cc:419] P 813824f78dfa45fcb29184e4c6e98ece: Scheduling FlushDeltaMemStoresOp(c6555552ba2640d68e9debc3930289a1): perf score=2.188937
I20260812 06:16:55.731542 24528 maintenance_manager.cc:643] P 813824f78dfa45fcb29184e4c6e98ece: FlushDeltaMemStoresOp(c6555552ba2640d68e9debc3930289a1) complete. Timing: real 0.017s	user 0.013s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6912,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:55.732511 24599 maintenance_manager.cc:419] P 813824f78dfa45fcb29184e4c6e98ece: Scheduling FlushMRSOp(c6555552ba2640d68e9debc3930289a1): perf score=1.000000
I20260812 06:16:55.781973 24528 maintenance_manager.cc:643] P 813824f78dfa45fcb29184e4c6e98ece: FlushMRSOp(c6555552ba2640d68e9debc3930289a1) complete. Timing: real 0.049s	user 0.044s	sys 0.004s Metrics: {"bytes_written":1152514,"cfile_init":1,"dirs.queue_time_us":73,"dirs.run_cpu_time_us":327,"dirs.run_wall_time_us":1680,"drs_written":1,"lbm_read_time_us":143,"lbm_reads_lt_1ms":4,"lbm_write_time_us":3880,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":28}
I20260812 06:16:55.782896 24599 maintenance_manager.cc:419] P 813824f78dfa45fcb29184e4c6e98ece: Scheduling MajorDeltaCompactionOp(c6555552ba2640d68e9debc3930289a1): perf score=1.000000
I20260812 06:16:55.948352 24528 maintenance_manager.cc:643] P 813824f78dfa45fcb29184e4c6e98ece: MajorDeltaCompactionOp(c6555552ba2640d68e9debc3930289a1) complete. Timing: real 0.165s	user 0.111s	sys 0.044s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672277,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":889,"lbm_read_time_us":9669,"lbm_reads_lt_1ms":464,"lbm_write_time_us":27609,"lbm_writes_lt_1ms":443,"mutex_wait_us":331,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":27264,"update_count":2000}
I20260812 06:16:55.948961 24599 maintenance_manager.cc:419] P 813824f78dfa45fcb29184e4c6e98ece: Scheduling LogGCOp(c6555552ba2640d68e9debc3930289a1): free 112692371 bytes of WAL
I20260812 06:16:55.949282 24528 log_reader.cc:385] T c6555552ba2640d68e9debc3930289a1: removed 11 log segments from log reader
I20260812 06:16:55.949358 24528 log.cc:1079] T c6555552ba2640d68e9debc3930289a1 P 813824f78dfa45fcb29184e4c6e98ece: Deleting log segment in path: /tmp/dist-test-taskg6QwMH/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515411975274-24417-0/minicluster-data/ts-0-root/wals/c6555552ba2640d68e9debc3930289a1/wal-000000015 (ops 72-76)
I20260812 06:16:55.949466 24528 log.cc:1079] T c6555552ba2640d68e9debc3930289a1 P 813824f78dfa45fcb29184e4c6e98ece: Deleting log segment in path: /tmp/dist-test-taskg6QwMH/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515411975274-24417-0/minicluster-data/ts-0-root/wals/c6555552ba2640d68e9debc3930289a1/wal-000000016 (ops 77-81)
I20260812 06:16:55.949517 24528 log.cc:1079] T c6555552ba2640d68e9debc3930289a1 P 813824f78dfa45fcb29184e4c6e98ece: Deleting log segment in path: /tmp/dist-test-taskg6QwMH/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515411975274-24417-0/minicluster-data/ts-0-root/wals/c6555552ba2640d68e9debc3930289a1/wal-000000017 (ops 82-86)
I20260812 06:16:55.949601 24528 log.cc:1079] T c6555552ba2640d68e9debc3930289a1 P 813824f78dfa45fcb29184e4c6e98ece: Deleting log segment in path: /tmp/dist-test-taskg6QwMH/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515411975274-24417-0/minicluster-data/ts-0-root/wals/c6555552ba2640d68e9debc3930289a1/wal-000000018 (ops 87-91)
I20260812 06:16:55.949651 24528 log.cc:1079] T c6555552ba2640d68e9debc3930289a1 P 813824f78dfa45fcb29184e4c6e98ece: Deleting log segment in path: /tmp/dist-test-taskg6QwMH/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515411975274-24417-0/minicluster-data/ts-0-root/wals/c6555552ba2640d68e9debc3930289a1/wal-000000019 (ops 92-96)
I20260812 06:16:55.949718 24528 log.cc:1079] T c6555552ba2640d68e9debc3930289a1 P 813824f78dfa45fcb29184e4c6e98ece: Deleting log segment in path: /tmp/dist-test-taskg6QwMH/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515411975274-24417-0/minicluster-data/ts-0-root/wals/c6555552ba2640d68e9debc3930289a1/wal-000000020 (ops 97-101)
I20260812 06:16:55.949774 24528 log.cc:1079] T c6555552ba2640d68e9debc3930289a1 P 813824f78dfa45fcb29184e4c6e98ece: Deleting log segment in path: /tmp/dist-test-taskg6QwMH/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515411975274-24417-0/minicluster-data/ts-0-root/wals/c6555552ba2640d68e9debc3930289a1/wal-000000021 (ops 102-106)
I20260812 06:16:55.949841 24528 log.cc:1079] T c6555552ba2640d68e9debc3930289a1 P 813824f78dfa45fcb29184e4c6e98ece: Deleting log segment in path: /tmp/dist-test-taskg6QwMH/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515411975274-24417-0/minicluster-data/ts-0-root/wals/c6555552ba2640d68e9debc3930289a1/wal-000000022 (ops 107-111)
I20260812 06:16:55.949887 24528 log.cc:1079] T c6555552ba2640d68e9debc3930289a1 P 813824f78dfa45fcb29184e4c6e98ece: Deleting log segment in path: /tmp/dist-test-taskg6QwMH/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515411975274-24417-0/minicluster-data/ts-0-root/wals/c6555552ba2640d68e9debc3930289a1/wal-000000023 (ops 112-116)
I20260812 06:16:55.949954 24528 log.cc:1079] T c6555552ba2640d68e9debc3930289a1 P 813824f78dfa45fcb29184e4c6e98ece: Deleting log segment in path: /tmp/dist-test-taskg6QwMH/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515411975274-24417-0/minicluster-data/ts-0-root/wals/c6555552ba2640d68e9debc3930289a1/wal-000000024 (ops 117-121)
I20260812 06:16:55.949999 24528 log.cc:1079] T c6555552ba2640d68e9debc3930289a1 P 813824f78dfa45fcb29184e4c6e98ece: Deleting log segment in path: /tmp/dist-test-taskg6QwMH/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515411975274-24417-0/minicluster-data/ts-0-root/wals/c6555552ba2640d68e9debc3930289a1/wal-000000025 (ops 122-126)
I20260812 06:16:55.975112 24528 maintenance_manager.cc:643] P 813824f78dfa45fcb29184e4c6e98ece: LogGCOp(c6555552ba2640d68e9debc3930289a1) complete. Timing: real 0.026s	user 0.000s	sys 0.025s Metrics: {}
I20260812 06:16:55.975678 24599 maintenance_manager.cc:419] P 813824f78dfa45fcb29184e4c6e98ece: Scheduling FlushDeltaMemStoresOp(c6555552ba2640d68e9debc3930289a1): perf score=14.095187
I20260812 06:16:56.023907 24528 maintenance_manager.cc:643] P 813824f78dfa45fcb29184e4c6e98ece: FlushDeltaMemStoresOp(c6555552ba2640d68e9debc3930289a1) complete. Timing: real 0.048s	user 0.026s	sys 0.021s Metrics: {"bytes_written":16409903,"delete_count":0,"lbm_write_time_us":21314,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:16:56.024570 24599 maintenance_manager.cc:419] P 813824f78dfa45fcb29184e4c6e98ece: Scheduling FlushDeltaMemStoresOp(c6555552ba2640d68e9debc3930289a1): perf score=2.188937
I20260812 06:16:56.043752 24528 maintenance_manager.cc:643] P 813824f78dfa45fcb29184e4c6e98ece: FlushDeltaMemStoresOp(c6555552ba2640d68e9debc3930289a1) complete. Timing: real 0.019s	user 0.005s	sys 0.006s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4501,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:56.044262 24599 maintenance_manager.cc:419] P 813824f78dfa45fcb29184e4c6e98ece: Scheduling UndoDeltaBlockGCOp(c6555552ba2640d68e9debc3930289a1): 447 bytes on disk
I20260812 06:16:56.044785 24528 maintenance_manager.cc:643] P 813824f78dfa45fcb29184e4c6e98ece: UndoDeltaBlockGCOp(c6555552ba2640d68e9debc3930289a1) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":70,"lbm_reads_lt_1ms":4}
I20260812 06:16:56.045328 24599 maintenance_manager.cc:419] P 813824f78dfa45fcb29184e4c6e98ece: Scheduling FlushDeltaMemStoresOp(c6555552ba2640d68e9debc3930289a1): perf score=2.188937
I20260812 06:16:56.064621 24528 maintenance_manager.cc:643] P 813824f78dfa45fcb29184e4c6e98ece: FlushDeltaMemStoresOp(c6555552ba2640d68e9debc3930289a1) complete. Timing: real 0.019s	user 0.005s	sys 0.012s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4110,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:56.065200 24599 maintenance_manager.cc:419] P 813824f78dfa45fcb29184e4c6e98ece: Scheduling MajorDeltaCompactionOp(c6555552ba2640d68e9debc3930289a1): perf score=1.000000
I20260812 06:16:56.272054 24528 maintenance_manager.cc:643] P 813824f78dfa45fcb29184e4c6e98ece: MajorDeltaCompactionOp(c6555552ba2640d68e9debc3930289a1) complete. Timing: real 0.207s	user 0.134s	sys 0.072s Metrics: {"cfile_cache_miss":633,"cfile_cache_miss_bytes":28877220,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":1313,"lbm_read_time_us":14272,"lbm_reads_lt_1ms":673,"lbm_write_time_us":38329,"lbm_writes_lt_1ms":643,"mutex_wait_us":359,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":3968,"update_count":3000}
I20260812 06:16:56.273759 24599 maintenance_manager.cc:419] P 813824f78dfa45fcb29184e4c6e98ece: Scheduling FlushDeltaMemStoresOp(c6555552ba2640d68e9debc3930289a1): perf score=14.095187
I20260812 06:16:56.344628 24528 maintenance_manager.cc:643] P 813824f78dfa45fcb29184e4c6e98ece: FlushDeltaMemStoresOp(c6555552ba2640d68e9debc3930289a1) complete. Timing: real 0.071s	user 0.030s	sys 0.038s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":28499,"lbm_writes_1-10_ms":2,"lbm_writes_lt_1ms":401,"reinsert_count":0,"update_count":2000}
I20260812 06:16:56.345278 24599 maintenance_manager.cc:419] P 813824f78dfa45fcb29184e4c6e98ece: Scheduling FlushDeltaMemStoresOp(c6555552ba2640d68e9debc3930289a1): perf score=2.188937
I20260812 06:16:56.362274 24528 maintenance_manager.cc:643] P 813824f78dfa45fcb29184e4c6e98ece: FlushDeltaMemStoresOp(c6555552ba2640d68e9debc3930289a1) complete. Timing: real 0.017s	user 0.003s	sys 0.011s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6607,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:56.362886 24599 maintenance_manager.cc:419] P 813824f78dfa45fcb29184e4c6e98ece: Scheduling MajorDeltaCompactionOp(c6555552ba2640d68e9debc3930289a1): perf score=1.000000
I20260812 06:16:56.554889 24528 maintenance_manager.cc:643] P 813824f78dfa45fcb29184e4c6e98ece: MajorDeltaCompactionOp(c6555552ba2640d68e9debc3930289a1) complete. Timing: real 0.192s	user 0.136s	sys 0.045s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774688,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":817,"lbm_read_time_us":13049,"lbm_reads_lt_1ms":568,"lbm_write_time_us":30795,"lbm_writes_lt_1ms":543,"mutex_wait_us":66,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":2048,"update_count":2500}
I20260812 06:16:56.555490 24599 maintenance_manager.cc:419] P 813824f78dfa45fcb29184e4c6e98ece: Scheduling FlushDeltaMemStoresOp(c6555552ba2640d68e9debc3930289a1): perf score=14.095187
I20260812 06:16:56.601775 24528 maintenance_manager.cc:643] P 813824f78dfa45fcb29184e4c6e98ece: FlushDeltaMemStoresOp(c6555552ba2640d68e9debc3930289a1) complete. Timing: real 0.046s	user 0.027s	sys 0.013s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":19447,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:16:56.602252 24599 maintenance_manager.cc:419] P 813824f78dfa45fcb29184e4c6e98ece: Scheduling FlushDeltaMemStoresOp(c6555552ba2640d68e9debc3930289a1): perf score=2.188937
I20260812 06:16:56.613582 24528 maintenance_manager.cc:643] P 813824f78dfa45fcb29184e4c6e98ece: FlushDeltaMemStoresOp(c6555552ba2640d68e9debc3930289a1) complete. Timing: real 0.011s	user 0.009s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4111,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:56.614223 24599 maintenance_manager.cc:419] P 813824f78dfa45fcb29184e4c6e98ece: Scheduling MajorDeltaCompactionOp(c6555552ba2640d68e9debc3930289a1): perf score=1.000000
I20260812 06:16:56.791651 24528 maintenance_manager.cc:643] P 813824f78dfa45fcb29184e4c6e98ece: MajorDeltaCompactionOp(c6555552ba2640d68e9debc3930289a1) complete. Timing: real 0.177s	user 0.125s	sys 0.047s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774689,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":982,"lbm_read_time_us":10057,"lbm_reads_lt_1ms":572,"lbm_write_time_us":28986,"lbm_writes_lt_1ms":543,"mutex_wait_us":290,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":896,"update_count":2500}
I20260812 06:16:56.792500 24599 maintenance_manager.cc:419] P 813824f78dfa45fcb29184e4c6e98ece: Scheduling FlushDeltaMemStoresOp(c6555552ba2640d68e9debc3930289a1): perf score=14.095187
I20260812 06:16:56.849222 24528 maintenance_manager.cc:643] P 813824f78dfa45fcb29184e4c6e98ece: FlushDeltaMemStoresOp(c6555552ba2640d68e9debc3930289a1) complete. Timing: real 0.056s	user 0.025s	sys 0.029s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":28793,"lbm_writes_1-10_ms":2,"lbm_writes_lt_1ms":401,"reinsert_count":0,"update_count":2000}
I20260812 06:16:56.849787 24599 maintenance_manager.cc:419] P 813824f78dfa45fcb29184e4c6e98ece: Scheduling FlushDeltaMemStoresOp(c6555552ba2640d68e9debc3930289a1): perf score=2.188937
I20260812 06:16:56.862950 24528 maintenance_manager.cc:643] P 813824f78dfa45fcb29184e4c6e98ece: FlushDeltaMemStoresOp(c6555552ba2640d68e9debc3930289a1) complete. Timing: real 0.013s	user 0.005s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4714,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:56.863564 24599 maintenance_manager.cc:419] P 813824f78dfa45fcb29184e4c6e98ece: Scheduling MajorDeltaCompactionOp(c6555552ba2640d68e9debc3930289a1): perf score=1.000000
I20260812 06:16:57.027163 24528 maintenance_manager.cc:643] P 813824f78dfa45fcb29184e4c6e98ece: MajorDeltaCompactionOp(c6555552ba2640d68e9debc3930289a1) complete. Timing: real 0.163s	user 0.099s	sys 0.052s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774689,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":2749,"lbm_read_time_us":11442,"lbm_reads_lt_1ms":572,"lbm_write_time_us":29781,"lbm_writes_lt_1ms":543,"mutex_wait_us":2450,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":2944,"update_count":2500}
I20260812 06:16:57.027940 24599 maintenance_manager.cc:419] P 813824f78dfa45fcb29184e4c6e98ece: Scheduling FlushDeltaMemStoresOp(c6555552ba2640d68e9debc3930289a1): perf score=14.095187
I20260812 06:16:57.076886 24528 maintenance_manager.cc:643] P 813824f78dfa45fcb29184e4c6e98ece: FlushDeltaMemStoresOp(c6555552ba2640d68e9debc3930289a1) complete. Timing: real 0.049s	user 0.025s	sys 0.016s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":19470,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:16:57.077395 24599 maintenance_manager.cc:419] P 813824f78dfa45fcb29184e4c6e98ece: Scheduling FlushDeltaMemStoresOp(c6555552ba2640d68e9debc3930289a1): perf score=2.188937
I20260812 06:16:57.088636 24528 maintenance_manager.cc:643] P 813824f78dfa45fcb29184e4c6e98ece: FlushDeltaMemStoresOp(c6555552ba2640d68e9debc3930289a1) complete. Timing: real 0.011s	user 0.005s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4136,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:57.089330 24599 maintenance_manager.cc:419] P 813824f78dfa45fcb29184e4c6e98ece: Scheduling MajorDeltaCompactionOp(c6555552ba2640d68e9debc3930289a1): perf score=1.000000
I20260812 06:16:57.269596 24528 maintenance_manager.cc:643] P 813824f78dfa45fcb29184e4c6e98ece: MajorDeltaCompactionOp(c6555552ba2640d68e9debc3930289a1) complete. Timing: real 0.180s	user 0.135s	sys 0.037s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774689,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":740,"lbm_read_time_us":10880,"lbm_reads_lt_1ms":572,"lbm_write_time_us":35241,"lbm_writes_lt_1ms":543,"mutex_wait_us":314,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":3200,"update_count":2500}
I20260812 06:16:57.270324 24599 maintenance_manager.cc:419] P 813824f78dfa45fcb29184e4c6e98ece: Scheduling FlushDeltaMemStoresOp(c6555552ba2640d68e9debc3930289a1): perf score=14.095187
I20260812 06:16:57.331513 24528 maintenance_manager.cc:643] P 813824f78dfa45fcb29184e4c6e98ece: FlushDeltaMemStoresOp(c6555552ba2640d68e9debc3930289a1) complete. Timing: real 0.061s	user 0.029s	sys 0.031s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":34245,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:16:57.332031 24599 maintenance_manager.cc:419] P 813824f78dfa45fcb29184e4c6e98ece: Scheduling FlushDeltaMemStoresOp(c6555552ba2640d68e9debc3930289a1): perf score=2.188937
I20260812 06:16:57.351976 24528 maintenance_manager.cc:643] P 813824f78dfa45fcb29184e4c6e98ece: FlushDeltaMemStoresOp(c6555552ba2640d68e9debc3930289a1) complete. Timing: real 0.020s	user 0.001s	sys 0.012s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5580,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:57.352622 24599 maintenance_manager.cc:419] P 813824f78dfa45fcb29184e4c6e98ece: Scheduling FlushMRSOp(c6555552ba2640d68e9debc3930289a1): perf score=1.000000
I20260812 06:16:57.405862 24528 maintenance_manager.cc:643] P 813824f78dfa45fcb29184e4c6e98ece: FlushMRSOp(c6555552ba2640d68e9debc3930289a1) complete. Timing: real 0.053s	user 0.029s	sys 0.004s Metrics: {"bytes_written":1316417,"cfile_init":1,"dirs.queue_time_us":96,"dirs.run_cpu_time_us":379,"dirs.run_wall_time_us":1747,"drs_written":1,"lbm_read_time_us":39,"lbm_reads_lt_1ms":4,"lbm_write_time_us":4063,"lbm_writes_1-10_ms":2,"lbm_writes_lt_1ms":37,"peak_mem_usage":0,"rows_written":32}
I20260812 06:16:57.407013 24599 maintenance_manager.cc:419] P 813824f78dfa45fcb29184e4c6e98ece: Scheduling FlushDeltaMemStoresOp(c6555552ba2640d68e9debc3930289a1): perf score=3.181125
I20260812 06:16:57.426225 24528 maintenance_manager.cc:643] P 813824f78dfa45fcb29184e4c6e98ece: FlushDeltaMemStoresOp(c6555552ba2640d68e9debc3930289a1) complete. Timing: real 0.019s	user 0.009s	sys 0.008s Metrics: {"bytes_written":4635981,"delete_count":0,"lbm_write_time_us":10737,"lbm_writes_lt_1ms":116,"reinsert_count":0,"update_count":565}
I20260812 06:16:57.427105 24599 maintenance_manager.cc:419] P 813824f78dfa45fcb29184e4c6e98ece: Scheduling LogGCOp(c6555552ba2640d68e9debc3930289a1): free 133024636 bytes of WAL
I20260812 06:16:57.427405 24528 log_reader.cc:385] T c6555552ba2640d68e9debc3930289a1: removed 13 log segments from log reader
I20260812 06:16:57.427453 24528 log.cc:1079] T c6555552ba2640d68e9debc3930289a1 P 813824f78dfa45fcb29184e4c6e98ece: Deleting log segment in path: /tmp/dist-test-taskg6QwMH/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515411975274-24417-0/minicluster-data/ts-0-root/wals/c6555552ba2640d68e9debc3930289a1/wal-000000026 (ops 127-131)
I20260812 06:16:57.427484 24528 log.cc:1079] T c6555552ba2640d68e9debc3930289a1 P 813824f78dfa45fcb29184e4c6e98ece: Deleting log segment in path: /tmp/dist-test-taskg6QwMH/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515411975274-24417-0/minicluster-data/ts-0-root/wals/c6555552ba2640d68e9debc3930289a1/wal-000000027 (ops 132-136)
I20260812 06:16:57.427525 24528 log.cc:1079] T c6555552ba2640d68e9debc3930289a1 P 813824f78dfa45fcb29184e4c6e98ece: Deleting log segment in path: /tmp/dist-test-taskg6QwMH/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515411975274-24417-0/minicluster-data/ts-0-root/wals/c6555552ba2640d68e9debc3930289a1/wal-000000028 (ops 137-141)
I20260812 06:16:57.427570 24528 log.cc:1079] T c6555552ba2640d68e9debc3930289a1 P 813824f78dfa45fcb29184e4c6e98ece: Deleting log segment in path: /tmp/dist-test-taskg6QwMH/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515411975274-24417-0/minicluster-data/ts-0-root/wals/c6555552ba2640d68e9debc3930289a1/wal-000000029 (ops 142-146)
I20260812 06:16:57.427603 24528 log.cc:1079] T c6555552ba2640d68e9debc3930289a1 P 813824f78dfa45fcb29184e4c6e98ece: Deleting log segment in path: /tmp/dist-test-taskg6QwMH/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515411975274-24417-0/minicluster-data/ts-0-root/wals/c6555552ba2640d68e9debc3930289a1/wal-000000030 (ops 147-150)
I20260812 06:16:57.427661 24528 log.cc:1079] T c6555552ba2640d68e9debc3930289a1 P 813824f78dfa45fcb29184e4c6e98ece: Deleting log segment in path: /tmp/dist-test-taskg6QwMH/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515411975274-24417-0/minicluster-data/ts-0-root/wals/c6555552ba2640d68e9debc3930289a1/wal-000000031 (ops 151-155)
I20260812 06:16:57.427690 24528 log.cc:1079] T c6555552ba2640d68e9debc3930289a1 P 813824f78dfa45fcb29184e4c6e98ece: Deleting log segment in path: /tmp/dist-test-taskg6QwMH/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515411975274-24417-0/minicluster-data/ts-0-root/wals/c6555552ba2640d68e9debc3930289a1/wal-000000032 (ops 156-160)
I20260812 06:16:57.427752 24528 log.cc:1079] T c6555552ba2640d68e9debc3930289a1 P 813824f78dfa45fcb29184e4c6e98ece: Deleting log segment in path: /tmp/dist-test-taskg6QwMH/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515411975274-24417-0/minicluster-data/ts-0-root/wals/c6555552ba2640d68e9debc3930289a1/wal-000000033 (ops 161-165)
I20260812 06:16:57.427801 24528 log.cc:1079] T c6555552ba2640d68e9debc3930289a1 P 813824f78dfa45fcb29184e4c6e98ece: Deleting log segment in path: /tmp/dist-test-taskg6QwMH/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515411975274-24417-0/minicluster-data/ts-0-root/wals/c6555552ba2640d68e9debc3930289a1/wal-000000034 (ops 166-170)
I20260812 06:16:57.427845 24528 log.cc:1079] T c6555552ba2640d68e9debc3930289a1 P 813824f78dfa45fcb29184e4c6e98ece: Deleting log segment in path: /tmp/dist-test-taskg6QwMH/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515411975274-24417-0/minicluster-data/ts-0-root/wals/c6555552ba2640d68e9debc3930289a1/wal-000000035 (ops 171-175)
I20260812 06:16:57.427881 24528 log.cc:1079] T c6555552ba2640d68e9debc3930289a1 P 813824f78dfa45fcb29184e4c6e98ece: Deleting log segment in path: /tmp/dist-test-taskg6QwMH/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515411975274-24417-0/minicluster-data/ts-0-root/wals/c6555552ba2640d68e9debc3930289a1/wal-000000036 (ops 176-180)
I20260812 06:16:57.427910 24528 log.cc:1079] T c6555552ba2640d68e9debc3930289a1 P 813824f78dfa45fcb29184e4c6e98ece: Deleting log segment in path: /tmp/dist-test-taskg6QwMH/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515411975274-24417-0/minicluster-data/ts-0-root/wals/c6555552ba2640d68e9debc3930289a1/wal-000000037 (ops 181-185)
I20260812 06:16:57.427948 24528 log.cc:1079] T c6555552ba2640d68e9debc3930289a1 P 813824f78dfa45fcb29184e4c6e98ece: Deleting log segment in path: /tmp/dist-test-taskg6QwMH/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515411975274-24417-0/minicluster-data/ts-0-root/wals/c6555552ba2640d68e9debc3930289a1/wal-000000038 (ops 186-190)
I20260812 06:16:57.457696 24528 maintenance_manager.cc:643] P 813824f78dfa45fcb29184e4c6e98ece: LogGCOp(c6555552ba2640d68e9debc3930289a1) complete. Timing: real 0.030s	user 0.000s	sys 0.027s Metrics: {}
I20260812 06:16:57.458171 24599 maintenance_manager.cc:419] P 813824f78dfa45fcb29184e4c6e98ece: Scheduling FlushDeltaMemStoresOp(c6555552ba2640d68e9debc3930289a1): perf score=6.157687
I20260812 06:16:57.487253 24528 maintenance_manager.cc:643] P 813824f78dfa45fcb29184e4c6e98ece: FlushDeltaMemStoresOp(c6555552ba2640d68e9debc3930289a1) complete. Timing: real 0.029s	user 0.018s	sys 0.007s Metrics: {"bytes_written":7671768,"delete_count":0,"lbm_write_time_us":10700,"lbm_writes_lt_1ms":190,"reinsert_count":0,"update_count":935}
I20260812 06:16:57.487753 24599 maintenance_manager.cc:419] P 813824f78dfa45fcb29184e4c6e98ece: Scheduling LogGCOp(c6555552ba2640d68e9debc3930289a1): free 11564893 bytes of WAL
I20260812 06:16:57.488039 24528 log_reader.cc:385] T c6555552ba2640d68e9debc3930289a1: removed 1 log segments from log reader
I20260812 06:16:57.488111 24528 log.cc:1079] T c6555552ba2640d68e9debc3930289a1 P 813824f78dfa45fcb29184e4c6e98ece: Deleting log segment in path: /tmp/dist-test-taskg6QwMH/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515411975274-24417-0/minicluster-data/ts-0-root/wals/c6555552ba2640d68e9debc3930289a1/wal-000000039 (ops 191-194)
I20260812 06:16:57.491392 24528 maintenance_manager.cc:643] P 813824f78dfa45fcb29184e4c6e98ece: LogGCOp(c6555552ba2640d68e9debc3930289a1) complete. Timing: real 0.003s	user 0.000s	sys 0.003s Metrics: {}
I20260812 06:16:57.491750 24599 maintenance_manager.cc:419] P 813824f78dfa45fcb29184e4c6e98ece: Scheduling MajorDeltaCompactionOp(c6555552ba2640d68e9debc3930289a1): perf score=1.000000
I20260812 06:16:57.625908 24417 heavy-update-compaction-itest.cc:229] Time spent updating: real 5.372s	user 1.963s	sys 0.145s
I20260812 06:16:57.728960 24528 maintenance_manager.cc:643] P 813824f78dfa45fcb29184e4c6e98ece: MajorDeltaCompactionOp(c6555552ba2640d68e9debc3930289a1) complete. Timing: real 0.234s	user 0.153s	sys 0.081s Metrics: {"cfile_cache_miss":834,"cfile_cache_miss_bytes":37082176,"cfile_init":7,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":1161,"lbm_read_time_us":17121,"lbm_reads_lt_1ms":862,"lbm_write_time_us":39554,"lbm_writes_lt_1ms":843,"mutex_wait_us":69,"peak_mem_usage":100395616,"reinsert_count":0,"spinlock_wait_cycles":1536,"thread_start_us":126,"threads_started":1,"update_count":4000}
I20260812 06:16:57.729702 24599 maintenance_manager.cc:419] P 813824f78dfa45fcb29184e4c6e98ece: Scheduling UndoDeltaBlockGCOp(c6555552ba2640d68e9debc3930289a1): 493 bytes on disk
I20260812 06:16:57.730458 24528 maintenance_manager.cc:643] P 813824f78dfa45fcb29184e4c6e98ece: UndoDeltaBlockGCOp(c6555552ba2640d68e9debc3930289a1) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":110,"lbm_reads_lt_1ms":4}
I20260812 06:16:57.731487 24599 maintenance_manager.cc:419] P 813824f78dfa45fcb29184e4c6e98ece: Scheduling FlushDeltaMemStoresOp(c6555552ba2640d68e9debc3930289a1): perf score=10.126437
I20260812 06:16:57.737664 24417 heavy-update-compaction-itest.cc:265] Time spent scanning: real 0.111s	user 0.002s	sys 0.000s
I20260812 06:16:57.738459 24417 tablet_server.cc:179] TabletServer@127.23.216.65:0 shutting down...
I20260812 06:16:57.776150 24528 maintenance_manager.cc:643] P 813824f78dfa45fcb29184e4c6e98ece: FlushDeltaMemStoresOp(c6555552ba2640d68e9debc3930289a1) complete. Timing: real 0.044s	user 0.014s	sys 0.029s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":14998,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:16:57.776919 24417 ts_tablet_manager.cc:1507] Shutting down tablet manager...
I20260812 06:16:57.777416 24417 tablet_replica.cc:333] T c6555552ba2640d68e9debc3930289a1 P 813824f78dfa45fcb29184e4c6e98ece: stopping tablet replica
I20260812 06:16:57.777635 24417 raft_consensus.cc:2243] T c6555552ba2640d68e9debc3930289a1 P 813824f78dfa45fcb29184e4c6e98ece [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:16:57.777849 24417 raft_consensus.cc:2272] T c6555552ba2640d68e9debc3930289a1 P 813824f78dfa45fcb29184e4c6e98ece [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:16:57.793497 24417 tablet_server.cc:196] TabletServer@127.23.216.65:0 shutdown complete.
I20260812 06:16:57.801666 24417 master.cc:562] Master@127.23.216.126:46165 shutting down...
I20260812 06:16:57.806177 24417 raft_consensus.cc:2243] T 00000000000000000000000000000000 P 37deffac47d340c8a49bb462d5ec79c3 [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:16:57.806380 24417 raft_consensus.cc:2272] T 00000000000000000000000000000000 P 37deffac47d340c8a49bb462d5ec79c3 [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:16:57.806483 24417 tablet_replica.cc:333] T 00000000000000000000000000000000 P 37deffac47d340c8a49bb462d5ec79c3: stopping tablet replica
I20260812 06:16:57.818971 24417 master.cc:584] Master@127.23.216.126:46165 shutdown complete.
[       OK ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/0 (5923 ms)
[ RUN      ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/1
I20260812 06:16:57.909672 24417 internal_mini_cluster.cc:156] Creating distributed mini masters. Addrs: 127.23.216.126:37433
I20260812 06:16:57.910106 24417 file_cache.cc:504] Constructed file cache file cache with capacity 419430
I20260812 06:16:57.912926 24417 server_base.cc:1061] running on GCE node
W20260812 06:16:57.912992 24629 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:16:57.913004 24630 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:16:57.913125 24633 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:16:57.913374 24417 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:16:57.913419 24417 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:16:57.913434 24417 hybrid_clock.cc:648] HybridClock initialized: now 1786515417913434 us; error 0 us; skew 500 ppm
I20260812 06:16:57.914354 24417 webserver.cc:533] Webserver started at http://127.23.216.126:35659/ using document root <none> and password file <none>
I20260812 06:16:57.914563 24417 fs_manager.cc:362] Metadata directory not provided
I20260812 06:16:57.915349 24417 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:16:57.915495 24417 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:16:57.915908 24417 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskg6QwMH/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515411975274-24417-0/minicluster-data/master-0-root/instance:
uuid: "041c3a0741f641b5a9d181852e111cc5"
format_stamp: "Formatted at 2026-08-12 06:16:57 on dist-test-slave-pgkr"
I20260812 06:16:57.917472 24417 fs_manager.cc:696] Time spent creating directory manager: real 0.001s	user 0.000s	sys 0.002s
I20260812 06:16:57.918555 24638 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:16:57.919025 24417 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.000s	sys 0.001s
I20260812 06:16:57.919097 24417 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskg6QwMH/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515411975274-24417-0/minicluster-data/master-0-root
uuid: "041c3a0741f641b5a9d181852e111cc5"
format_stamp: "Formatted at 2026-08-12 06:16:57 on dist-test-slave-pgkr"
I20260812 06:16:57.919195 24417 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskg6QwMH/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515411975274-24417-0/minicluster-data/master-0-root
metadata directory: /tmp/dist-test-taskg6QwMH/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515411975274-24417-0/minicluster-data/master-0-root
1 data directories: /tmp/dist-test-taskg6QwMH/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515411975274-24417-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:16:57.937456 24417 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:16:57.937949 24417 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:16:57.942888 24417 rpc_server.cc:307] RPC server started. Bound to: 127.23.216.126:37433
I20260812 06:16:57.948647 24697 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.23.216.126:37433 every 8 connection(s)
I20260812 06:16:57.949348 24698 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:16:57.956161 24698 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P 041c3a0741f641b5a9d181852e111cc5: Bootstrap starting.
I20260812 06:16:57.957082 24698 tablet_bootstrap.cc:654] T 00000000000000000000000000000000 P 041c3a0741f641b5a9d181852e111cc5: Neither blocks nor log segments found. Creating new log.
I20260812 06:16:57.958302 24698 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P 041c3a0741f641b5a9d181852e111cc5: No bootstrap required, opened a new log
I20260812 06:16:57.958760 24698 raft_consensus.cc:359] T 00000000000000000000000000000000 P 041c3a0741f641b5a9d181852e111cc5 [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "041c3a0741f641b5a9d181852e111cc5" member_type: VOTER }
I20260812 06:16:57.958885 24698 raft_consensus.cc:385] T 00000000000000000000000000000000 P 041c3a0741f641b5a9d181852e111cc5 [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:16:57.958938 24698 raft_consensus.cc:740] T 00000000000000000000000000000000 P 041c3a0741f641b5a9d181852e111cc5 [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: 041c3a0741f641b5a9d181852e111cc5, State: Initialized, Role: FOLLOWER
I20260812 06:16:57.959124 24698 consensus_queue.cc:260] T 00000000000000000000000000000000 P 041c3a0741f641b5a9d181852e111cc5 [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: "041c3a0741f641b5a9d181852e111cc5" member_type: VOTER }
I20260812 06:16:57.959240 24698 raft_consensus.cc:399] T 00000000000000000000000000000000 P 041c3a0741f641b5a9d181852e111cc5 [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:16:57.959286 24698 raft_consensus.cc:493] T 00000000000000000000000000000000 P 041c3a0741f641b5a9d181852e111cc5 [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:16:57.959347 24698 raft_consensus.cc:3060] T 00000000000000000000000000000000 P 041c3a0741f641b5a9d181852e111cc5 [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:16:57.960103 24698 raft_consensus.cc:515] T 00000000000000000000000000000000 P 041c3a0741f641b5a9d181852e111cc5 [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "041c3a0741f641b5a9d181852e111cc5" member_type: VOTER }
I20260812 06:16:57.960263 24698 leader_election.cc:304] T 00000000000000000000000000000000 P 041c3a0741f641b5a9d181852e111cc5 [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: 041c3a0741f641b5a9d181852e111cc5; no voters: 
I20260812 06:16:57.960481 24698 leader_election.cc:290] T 00000000000000000000000000000000 P 041c3a0741f641b5a9d181852e111cc5 [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:16:57.960659 24702 raft_consensus.cc:2804] T 00000000000000000000000000000000 P 041c3a0741f641b5a9d181852e111cc5 [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:16:57.960892 24702 raft_consensus.cc:697] T 00000000000000000000000000000000 P 041c3a0741f641b5a9d181852e111cc5 [term 1 LEADER]: Becoming Leader. State: Replica: 041c3a0741f641b5a9d181852e111cc5, State: Running, Role: LEADER
I20260812 06:16:57.961068 24702 consensus_queue.cc:237] T 00000000000000000000000000000000 P 041c3a0741f641b5a9d181852e111cc5 [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: "041c3a0741f641b5a9d181852e111cc5" member_type: VOTER }
I20260812 06:16:57.961171 24698 sys_catalog.cc:565] T 00000000000000000000000000000000 P 041c3a0741f641b5a9d181852e111cc5 [sys.catalog]: configured and running, proceeding with master startup.
I20260812 06:16:57.961489 24703 sys_catalog.cc:455] T 00000000000000000000000000000000 P 041c3a0741f641b5a9d181852e111cc5 [sys.catalog]: SysCatalogTable state changed. Reason: New leader 041c3a0741f641b5a9d181852e111cc5. Latest consensus state: current_term: 1 leader_uuid: "041c3a0741f641b5a9d181852e111cc5" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "041c3a0741f641b5a9d181852e111cc5" member_type: VOTER } }
I20260812 06:16:57.961521 24705 sys_catalog.cc:455] T 00000000000000000000000000000000 P 041c3a0741f641b5a9d181852e111cc5 [sys.catalog]: SysCatalogTable state changed. Reason: RaftConsensus started. Latest consensus state: current_term: 1 leader_uuid: "041c3a0741f641b5a9d181852e111cc5" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "041c3a0741f641b5a9d181852e111cc5" member_type: VOTER } }
I20260812 06:16:57.961621 24705 sys_catalog.cc:458] T 00000000000000000000000000000000 P 041c3a0741f641b5a9d181852e111cc5 [sys.catalog]: This master's current role is: LEADER
I20260812 06:16:57.961613 24703 sys_catalog.cc:458] T 00000000000000000000000000000000 P 041c3a0741f641b5a9d181852e111cc5 [sys.catalog]: This master's current role is: LEADER
I20260812 06:16:57.961997 24708 catalog_manager.cc:1511] Loading table and tablet metadata into memory...
I20260812 06:16:57.962958 24708 catalog_manager.cc:1520] Initializing Kudu cluster ID...
I20260812 06:16:57.963363 24417 internal_mini_cluster.cc:184] Waiting to initialize catalog manager on master 0
I20260812 06:16:57.964986 24708 catalog_manager.cc:1383] Generated new cluster ID: b51188234a544840859fc059fdb75016
I20260812 06:16:57.965077 24708 catalog_manager.cc:1531] Initializing Kudu internal certificate authority...
I20260812 06:16:57.988891 24708 catalog_manager.cc:1406] Generated new certificate authority record
I20260812 06:16:57.989501 24708 catalog_manager.cc:1540] Loading token signing keys...
I20260812 06:16:58.004518 24708 catalog_manager.cc:6092] T 00000000000000000000000000000000 P 041c3a0741f641b5a9d181852e111cc5: Generated new TSK 0
I20260812 06:16:58.004760 24708 catalog_manager.cc:1550] Initializing in-progress tserver states...
I20260812 06:16:58.028294 24417 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:16:58.030748 24725 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:16:58.030929 24724 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:16:58.031025 24417 server_base.cc:1061] running on GCE node
W20260812 06:16:58.030730 24727 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:16:58.031447 24417 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:16:58.031543 24417 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:16:58.031571 24417 hybrid_clock.cc:648] HybridClock initialized: now 1786515418031570 us; error 0 us; skew 500 ppm
I20260812 06:16:58.032522 24417 webserver.cc:533] Webserver started at http://127.23.216.65:43443/ using document root <none> and password file <none>
I20260812 06:16:58.032766 24417 fs_manager.cc:362] Metadata directory not provided
I20260812 06:16:58.032861 24417 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:16:58.032969 24417 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:16:58.033421 24417 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskg6QwMH/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515411975274-24417-0/minicluster-data/ts-0-root/instance:
uuid: "875d28fe3fa54e14bcc1ae88410f2b71"
format_stamp: "Formatted at 2026-08-12 06:16:58 on dist-test-slave-pgkr"
I20260812 06:16:58.035099 24417 fs_manager.cc:696] Time spent creating directory manager: real 0.001s	user 0.002s	sys 0.000s
I20260812 06:16:58.036118 24733 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:16:58.036401 24417 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.001s	sys 0.000s
I20260812 06:16:58.036504 24417 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskg6QwMH/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515411975274-24417-0/minicluster-data/ts-0-root
uuid: "875d28fe3fa54e14bcc1ae88410f2b71"
format_stamp: "Formatted at 2026-08-12 06:16:58 on dist-test-slave-pgkr"
I20260812 06:16:58.036602 24417 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskg6QwMH/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515411975274-24417-0/minicluster-data/ts-0-root
metadata directory: /tmp/dist-test-taskg6QwMH/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515411975274-24417-0/minicluster-data/ts-0-root
1 data directories: /tmp/dist-test-taskg6QwMH/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515411975274-24417-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:16:58.051020 24417 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:16:58.051460 24417 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:16:58.051823 24417 txn_system_client.cc:432] TxnSystemClient initialization is disabled...
I20260812 06:16:58.052343 24417 ts_tablet_manager.cc:585] Loaded tablet metadata (0 total tablets, 0 live tablets)
I20260812 06:16:58.052412 24417 ts_tablet_manager.cc:531] Time spent load tablet metadata: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:16:58.052481 24417 ts_tablet_manager.cc:616] Registered 0 tablets
I20260812 06:16:58.052515 24417 ts_tablet_manager.cc:595] Time spent register tablets: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:16:58.057467 24417 rpc_server.cc:307] RPC server started. Bound to: 127.23.216.65:45683
I20260812 06:16:58.057685 24799 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.23.216.65:45683 every 8 connection(s)
I20260812 06:16:58.063242 24800 heartbeater.cc:344] Connected to a master server at 127.23.216.126:37433
I20260812 06:16:58.063352 24800 heartbeater.cc:461] Registering TS with master...
I20260812 06:16:58.063560 24800 heartbeater.cc:507] Master 127.23.216.126:37433 requested a full tablet report, sending...
I20260812 06:16:58.064236 24655 ts_manager.cc:194] Registered new tserver with Master: 875d28fe3fa54e14bcc1ae88410f2b71 (127.23.216.65:45683)
I20260812 06:16:58.064935 24417 internal_mini_cluster.cc:371] 1 TS(s) registered with all masters after 0.006943886s
I20260812 06:16:58.065062 24655 master_service.cc:502] Signed X509 certificate for tserver {username='slave'} at 127.0.0.1:52246
I20260812 06:16:58.072839 24655 catalog_manager.cc:2283] Servicing CreateTable request from {username='slave'} at 127.0.0.1:52256:
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:16:58.082484 24761 tablet_service.cc:1511] Processing CreateTablet for tablet da8e99a02d16409a9b44b91b98b5f136 (DEFAULT_TABLE table=heavy-update-compaction-test [id=b656bd87f00f4ec9aa1021c15f49ee6f]), partition=
I20260812 06:16:58.082866 24761 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet da8e99a02d16409a9b44b91b98b5f136. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:16:58.084887 24813 tablet_bootstrap.cc:492] T da8e99a02d16409a9b44b91b98b5f136 P 875d28fe3fa54e14bcc1ae88410f2b71: Bootstrap starting.
I20260812 06:16:58.085819 24813 tablet_bootstrap.cc:654] T da8e99a02d16409a9b44b91b98b5f136 P 875d28fe3fa54e14bcc1ae88410f2b71: Neither blocks nor log segments found. Creating new log.
I20260812 06:16:58.087122 24813 tablet_bootstrap.cc:492] T da8e99a02d16409a9b44b91b98b5f136 P 875d28fe3fa54e14bcc1ae88410f2b71: No bootstrap required, opened a new log
I20260812 06:16:58.087208 24813 ts_tablet_manager.cc:1403] T da8e99a02d16409a9b44b91b98b5f136 P 875d28fe3fa54e14bcc1ae88410f2b71: Time spent bootstrapping tablet: real 0.002s	user 0.002s	sys 0.000s
I20260812 06:16:58.087687 24813 raft_consensus.cc:359] T da8e99a02d16409a9b44b91b98b5f136 P 875d28fe3fa54e14bcc1ae88410f2b71 [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "875d28fe3fa54e14bcc1ae88410f2b71" member_type: VOTER last_known_addr { host: "127.23.216.65" port: 45683 } }
I20260812 06:16:58.087792 24813 raft_consensus.cc:385] T da8e99a02d16409a9b44b91b98b5f136 P 875d28fe3fa54e14bcc1ae88410f2b71 [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:16:58.087816 24813 raft_consensus.cc:740] T da8e99a02d16409a9b44b91b98b5f136 P 875d28fe3fa54e14bcc1ae88410f2b71 [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: 875d28fe3fa54e14bcc1ae88410f2b71, State: Initialized, Role: FOLLOWER
I20260812 06:16:58.088007 24813 consensus_queue.cc:260] T da8e99a02d16409a9b44b91b98b5f136 P 875d28fe3fa54e14bcc1ae88410f2b71 [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: "875d28fe3fa54e14bcc1ae88410f2b71" member_type: VOTER last_known_addr { host: "127.23.216.65" port: 45683 } }
I20260812 06:16:58.088117 24813 raft_consensus.cc:399] T da8e99a02d16409a9b44b91b98b5f136 P 875d28fe3fa54e14bcc1ae88410f2b71 [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:16:58.088172 24813 raft_consensus.cc:493] T da8e99a02d16409a9b44b91b98b5f136 P 875d28fe3fa54e14bcc1ae88410f2b71 [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:16:58.088264 24813 raft_consensus.cc:3060] T da8e99a02d16409a9b44b91b98b5f136 P 875d28fe3fa54e14bcc1ae88410f2b71 [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:16:58.089053 24813 raft_consensus.cc:515] T da8e99a02d16409a9b44b91b98b5f136 P 875d28fe3fa54e14bcc1ae88410f2b71 [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "875d28fe3fa54e14bcc1ae88410f2b71" member_type: VOTER last_known_addr { host: "127.23.216.65" port: 45683 } }
I20260812 06:16:58.089176 24813 leader_election.cc:304] T da8e99a02d16409a9b44b91b98b5f136 P 875d28fe3fa54e14bcc1ae88410f2b71 [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: 875d28fe3fa54e14bcc1ae88410f2b71; no voters: 
I20260812 06:16:58.089366 24813 leader_election.cc:290] T da8e99a02d16409a9b44b91b98b5f136 P 875d28fe3fa54e14bcc1ae88410f2b71 [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:16:58.089536 24815 raft_consensus.cc:2804] T da8e99a02d16409a9b44b91b98b5f136 P 875d28fe3fa54e14bcc1ae88410f2b71 [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:16:58.089780 24813 ts_tablet_manager.cc:1434] T da8e99a02d16409a9b44b91b98b5f136 P 875d28fe3fa54e14bcc1ae88410f2b71: Time spent starting tablet: real 0.002s	user 0.003s	sys 0.000s
I20260812 06:16:58.089795 24800 heartbeater.cc:499] Master 127.23.216.126:37433 was elected leader, sending a full tablet report...
I20260812 06:16:58.089795 24815 raft_consensus.cc:697] T da8e99a02d16409a9b44b91b98b5f136 P 875d28fe3fa54e14bcc1ae88410f2b71 [term 1 LEADER]: Becoming Leader. State: Replica: 875d28fe3fa54e14bcc1ae88410f2b71, State: Running, Role: LEADER
I20260812 06:16:58.090310 24815 consensus_queue.cc:237] T da8e99a02d16409a9b44b91b98b5f136 P 875d28fe3fa54e14bcc1ae88410f2b71 [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: "875d28fe3fa54e14bcc1ae88410f2b71" member_type: VOTER last_known_addr { host: "127.23.216.65" port: 45683 } }
I20260812 06:16:58.092092 24655 catalog_manager.cc:5719] T da8e99a02d16409a9b44b91b98b5f136 P 875d28fe3fa54e14bcc1ae88410f2b71 reported cstate change: term changed from 0 to 1, leader changed from <none> to 875d28fe3fa54e14bcc1ae88410f2b71 (127.23.216.65). New cstate: current_term: 1 leader_uuid: "875d28fe3fa54e14bcc1ae88410f2b71" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "875d28fe3fa54e14bcc1ae88410f2b71" member_type: VOTER last_known_addr { host: "127.23.216.65" port: 45683 } health_report { overall_health: HEALTHY } } }
I20260812 06:16:58.154445 24417 heavy-update-compaction-itest.cc:215] Time spent inserting: real 0.055s	user 0.018s	sys 0.006s
I20260812 06:16:58.308562 24801 maintenance_manager.cc:419] P 875d28fe3fa54e14bcc1ae88410f2b71: Scheduling FlushMRSOp(da8e99a02d16409a9b44b91b98b5f136): perf score=19.054940
I20260812 06:16:58.463209 24738 maintenance_manager.cc:643] P 875d28fe3fa54e14bcc1ae88410f2b71: FlushMRSOp(da8e99a02d16409a9b44b91b98b5f136) complete. Timing: real 0.154s	user 0.094s	sys 0.059s Metrics: {"bytes_written":11897251,"cfile_init":1,"delete_count":0,"dirs.queue_time_us":60,"dirs.run_cpu_time_us":202,"dirs.run_wall_time_us":933,"drs_written":1,"lbm_read_time_us":44,"lbm_reads_lt_1ms":4,"lbm_write_time_us":40879,"lbm_writes_lt_1ms":757,"peak_mem_usage":0,"reinsert_count":0,"rows_written":105,"update_count":1450}
I20260812 06:16:58.464036 24801 maintenance_manager.cc:419] P 875d28fe3fa54e14bcc1ae88410f2b71: Scheduling LogGCOp(da8e99a02d16409a9b44b91b98b5f136): free 20743880 bytes of WAL
I20260812 06:16:58.464301 24738 log_reader.cc:385] T da8e99a02d16409a9b44b91b98b5f136: removed 2 log segments from log reader
I20260812 06:16:58.464414 24738 log.cc:1079] T da8e99a02d16409a9b44b91b98b5f136 P 875d28fe3fa54e14bcc1ae88410f2b71: Deleting log segment in path: /tmp/dist-test-taskg6QwMH/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515411975274-24417-0/minicluster-data/ts-0-root/wals/da8e99a02d16409a9b44b91b98b5f136/wal-000000001 (ops 1-6)
I20260812 06:16:58.464471 24738 log.cc:1079] T da8e99a02d16409a9b44b91b98b5f136 P 875d28fe3fa54e14bcc1ae88410f2b71: Deleting log segment in path: /tmp/dist-test-taskg6QwMH/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515411975274-24417-0/minicluster-data/ts-0-root/wals/da8e99a02d16409a9b44b91b98b5f136/wal-000000002 (ops 7-11)
I20260812 06:16:58.470372 24738 maintenance_manager.cc:643] P 875d28fe3fa54e14bcc1ae88410f2b71: LogGCOp(da8e99a02d16409a9b44b91b98b5f136) complete. Timing: real 0.006s	user 0.000s	sys 0.002s Metrics: {}
I20260812 06:16:58.470860 24801 maintenance_manager.cc:419] P 875d28fe3fa54e14bcc1ae88410f2b71: Scheduling UndoDeltaBlockGCOp(da8e99a02d16409a9b44b91b98b5f136): 16821650 bytes on disk
I20260812 06:16:58.471357 24738 maintenance_manager.cc:643] P 875d28fe3fa54e14bcc1ae88410f2b71: UndoDeltaBlockGCOp(da8e99a02d16409a9b44b91b98b5f136) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":74,"lbm_reads_lt_1ms":4}
I20260812 06:16:58.471864 24801 maintenance_manager.cc:419] P 875d28fe3fa54e14bcc1ae88410f2b71: Scheduling FlushDeltaMemStoresOp(da8e99a02d16409a9b44b91b98b5f136): perf score=2.188937
I20260812 06:16:58.494143 24738 maintenance_manager.cc:643] P 875d28fe3fa54e14bcc1ae88410f2b71: FlushDeltaMemStoresOp(da8e99a02d16409a9b44b91b98b5f136) complete. Timing: real 0.022s	user 0.013s	sys 0.001s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":5970,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:58.494750 24801 maintenance_manager.cc:419] P 875d28fe3fa54e14bcc1ae88410f2b71: Scheduling FlushDeltaMemStoresOp(da8e99a02d16409a9b44b91b98b5f136): perf score=2.188937
I20260812 06:16:58.505009 24738 maintenance_manager.cc:643] P 875d28fe3fa54e14bcc1ae88410f2b71: FlushDeltaMemStoresOp(da8e99a02d16409a9b44b91b98b5f136) complete. Timing: real 0.010s	user 0.004s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3964,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:58.505584 24801 maintenance_manager.cc:419] P 875d28fe3fa54e14bcc1ae88410f2b71: Scheduling MajorDeltaCompactionOp(da8e99a02d16409a9b44b91b98b5f136): perf score=1.000000
I20260812 06:16:58.677330 24738 maintenance_manager.cc:643] P 875d28fe3fa54e14bcc1ae88410f2b71: MajorDeltaCompactionOp(da8e99a02d16409a9b44b91b98b5f136) complete. Timing: real 0.172s	user 0.135s	sys 0.031s Metrics: {"cfile_cache_miss":523,"cfile_cache_miss_bytes":24405563,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":1036,"lbm_read_time_us":13286,"lbm_reads_lt_1ms":559,"lbm_write_time_us":28428,"lbm_writes_lt_1ms":533,"peak_mem_usage":61665166,"reinsert_count":0,"spinlock_wait_cycles":3072,"thread_start_us":440,"threads_started":5,"update_count":2450}
I20260812 06:16:58.677995 24801 maintenance_manager.cc:419] P 875d28fe3fa54e14bcc1ae88410f2b71: Scheduling FlushDeltaMemStoresOp(da8e99a02d16409a9b44b91b98b5f136): perf score=14.095187
I20260812 06:16:58.739883 24738 maintenance_manager.cc:643] P 875d28fe3fa54e14bcc1ae88410f2b71: FlushDeltaMemStoresOp(da8e99a02d16409a9b44b91b98b5f136) complete. Timing: real 0.062s	user 0.041s	sys 0.011s Metrics: {"bytes_written":16409903,"delete_count":0,"lbm_write_time_us":24104,"lbm_writes_lt_1ms":403,"mutex_wait_us":2,"reinsert_count":0,"spinlock_wait_cycles":1408,"update_count":2000}
I20260812 06:16:58.740403 24801 maintenance_manager.cc:419] P 875d28fe3fa54e14bcc1ae88410f2b71: Scheduling FlushDeltaMemStoresOp(da8e99a02d16409a9b44b91b98b5f136): perf score=2.188937
I20260812 06:16:58.752470 24738 maintenance_manager.cc:643] P 875d28fe3fa54e14bcc1ae88410f2b71: FlushDeltaMemStoresOp(da8e99a02d16409a9b44b91b98b5f136) complete. Timing: real 0.012s	user 0.010s	sys 0.000s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4284,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:58.753165 24801 maintenance_manager.cc:419] P 875d28fe3fa54e14bcc1ae88410f2b71: Scheduling MajorDeltaCompactionOp(da8e99a02d16409a9b44b91b98b5f136): perf score=1.000000
I20260812 06:16:58.917060 24738 maintenance_manager.cc:643] P 875d28fe3fa54e14bcc1ae88410f2b71: MajorDeltaCompactionOp(da8e99a02d16409a9b44b91b98b5f136) complete. Timing: real 0.164s	user 0.113s	sys 0.039s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24815684,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":370,"lbm_read_time_us":11643,"lbm_reads_lt_1ms":572,"lbm_write_time_us":28699,"lbm_writes_lt_1ms":543,"mutex_wait_us":67,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":37888,"update_count":2500}
I20260812 06:16:58.917737 24801 maintenance_manager.cc:419] P 875d28fe3fa54e14bcc1ae88410f2b71: Scheduling FlushDeltaMemStoresOp(da8e99a02d16409a9b44b91b98b5f136): perf score=14.095187
I20260812 06:16:58.975435 24738 maintenance_manager.cc:643] P 875d28fe3fa54e14bcc1ae88410f2b71: FlushDeltaMemStoresOp(da8e99a02d16409a9b44b91b98b5f136) complete. Timing: real 0.058s	user 0.038s	sys 0.016s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":25049,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:16:58.975986 24801 maintenance_manager.cc:419] P 875d28fe3fa54e14bcc1ae88410f2b71: Scheduling MajorDeltaCompactionOp(da8e99a02d16409a9b44b91b98b5f136): perf score=1.000000
I20260812 06:16:59.130131 24738 maintenance_manager.cc:643] P 875d28fe3fa54e14bcc1ae88410f2b71: MajorDeltaCompactionOp(da8e99a02d16409a9b44b91b98b5f136) complete. Timing: real 0.154s	user 0.099s	sys 0.053s Metrics: {"cfile_cache_miss":431,"cfile_cache_miss_bytes":20713152,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":1,"delta_iterators_relevant":1,"dirs.queue_time_us":60,"lbm_read_time_us":11803,"lbm_reads_lt_1ms":463,"lbm_write_time_us":24110,"lbm_writes_lt_1ms":443,"mutex_wait_us":21,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":6528,"update_count":2000}
I20260812 06:16:59.130802 24801 maintenance_manager.cc:419] P 875d28fe3fa54e14bcc1ae88410f2b71: Scheduling FlushDeltaMemStoresOp(da8e99a02d16409a9b44b91b98b5f136): perf score=11.118625
I20260812 06:16:59.167910 24738 maintenance_manager.cc:643] P 875d28fe3fa54e14bcc1ae88410f2b71: FlushDeltaMemStoresOp(da8e99a02d16409a9b44b91b98b5f136) complete. Timing: real 0.037s	user 0.023s	sys 0.012s Metrics: {"bytes_written":12717738,"delete_count":0,"lbm_write_time_us":15989,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:16:59.168509 24801 maintenance_manager.cc:419] P 875d28fe3fa54e14bcc1ae88410f2b71: Scheduling FlushDeltaMemStoresOp(da8e99a02d16409a9b44b91b98b5f136): perf score=2.188937
I20260812 06:16:59.185983 24738 maintenance_manager.cc:643] P 875d28fe3fa54e14bcc1ae88410f2b71: FlushDeltaMemStoresOp(da8e99a02d16409a9b44b91b98b5f136) complete. Timing: real 0.017s	user 0.005s	sys 0.008s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":6172,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:16:59.186481 24801 maintenance_manager.cc:419] P 875d28fe3fa54e14bcc1ae88410f2b71: Scheduling MajorDeltaCompactionOp(da8e99a02d16409a9b44b91b98b5f136): perf score=1.000000
I20260812 06:16:59.323208 24738 maintenance_manager.cc:643] P 875d28fe3fa54e14bcc1ae88410f2b71: MajorDeltaCompactionOp(da8e99a02d16409a9b44b91b98b5f136) complete. Timing: real 0.137s	user 0.116s	sys 0.020s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20713266,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":95,"lbm_read_time_us":8868,"lbm_reads_lt_1ms":464,"lbm_write_time_us":27279,"lbm_writes_lt_1ms":443,"mutex_wait_us":32,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":12416,"update_count":2000}
I20260812 06:16:59.323895 24801 maintenance_manager.cc:419] P 875d28fe3fa54e14bcc1ae88410f2b71: Scheduling FlushDeltaMemStoresOp(da8e99a02d16409a9b44b91b98b5f136): perf score=10.126437
I20260812 06:16:59.362844 24738 maintenance_manager.cc:643] P 875d28fe3fa54e14bcc1ae88410f2b71: FlushDeltaMemStoresOp(da8e99a02d16409a9b44b91b98b5f136) complete. Timing: real 0.039s	user 0.019s	sys 0.019s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":19522,"lbm_writes_1-10_ms":2,"lbm_writes_lt_1ms":301,"reinsert_count":0,"update_count":1500}
I20260812 06:16:59.363387 24801 maintenance_manager.cc:419] P 875d28fe3fa54e14bcc1ae88410f2b71: Scheduling FlushDeltaMemStoresOp(da8e99a02d16409a9b44b91b98b5f136): perf score=2.188937
I20260812 06:16:59.380439 24738 maintenance_manager.cc:643] P 875d28fe3fa54e14bcc1ae88410f2b71: FlushDeltaMemStoresOp(da8e99a02d16409a9b44b91b98b5f136) complete. Timing: real 0.017s	user 0.010s	sys 0.005s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6729,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:59.380931 24801 maintenance_manager.cc:419] P 875d28fe3fa54e14bcc1ae88410f2b71: Scheduling MajorDeltaCompactionOp(da8e99a02d16409a9b44b91b98b5f136): perf score=1.000000
I20260812 06:16:59.511624 24738 maintenance_manager.cc:643] P 875d28fe3fa54e14bcc1ae88410f2b71: MajorDeltaCompactionOp(da8e99a02d16409a9b44b91b98b5f136) complete. Timing: real 0.130s	user 0.109s	sys 0.021s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20713272,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":1137,"lbm_read_time_us":7922,"lbm_reads_lt_1ms":472,"lbm_write_time_us":26446,"lbm_writes_lt_1ms":443,"mutex_wait_us":326,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":12928,"update_count":2000}
I20260812 06:16:59.512418 24801 maintenance_manager.cc:419] P 875d28fe3fa54e14bcc1ae88410f2b71: Scheduling FlushDeltaMemStoresOp(da8e99a02d16409a9b44b91b98b5f136): perf score=10.126437
I20260812 06:16:59.558018 24738 maintenance_manager.cc:643] P 875d28fe3fa54e14bcc1ae88410f2b71: FlushDeltaMemStoresOp(da8e99a02d16409a9b44b91b98b5f136) complete. Timing: real 0.045s	user 0.024s	sys 0.012s Metrics: {"bytes_written":12307491,"delete_count":0,"lbm_write_time_us":18976,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":302,"reinsert_count":0,"update_count":1500}
I20260812 06:16:59.558560 24801 maintenance_manager.cc:419] P 875d28fe3fa54e14bcc1ae88410f2b71: Scheduling FlushDeltaMemStoresOp(da8e99a02d16409a9b44b91b98b5f136): perf score=2.188937
I20260812 06:16:59.570765 24738 maintenance_manager.cc:643] P 875d28fe3fa54e14bcc1ae88410f2b71: FlushDeltaMemStoresOp(da8e99a02d16409a9b44b91b98b5f136) complete. Timing: real 0.012s	user 0.007s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4722,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:59.571236 24801 maintenance_manager.cc:419] P 875d28fe3fa54e14bcc1ae88410f2b71: Scheduling MajorDeltaCompactionOp(da8e99a02d16409a9b44b91b98b5f136): perf score=1.000000
I20260812 06:16:59.709705 24738 maintenance_manager.cc:643] P 875d28fe3fa54e14bcc1ae88410f2b71: MajorDeltaCompactionOp(da8e99a02d16409a9b44b91b98b5f136) complete. Timing: real 0.138s	user 0.094s	sys 0.044s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20713273,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":226,"lbm_read_time_us":8850,"lbm_reads_lt_1ms":472,"lbm_write_time_us":29678,"lbm_writes_lt_1ms":443,"mutex_wait_us":42,"peak_mem_usage":50689328,"reinsert_count":0,"update_count":2000}
I20260812 06:16:59.710427 24801 maintenance_manager.cc:419] P 875d28fe3fa54e14bcc1ae88410f2b71: Scheduling FlushDeltaMemStoresOp(da8e99a02d16409a9b44b91b98b5f136): perf score=10.126437
I20260812 06:16:59.763702 24738 maintenance_manager.cc:643] P 875d28fe3fa54e14bcc1ae88410f2b71: FlushDeltaMemStoresOp(da8e99a02d16409a9b44b91b98b5f136) complete. Timing: real 0.053s	user 0.027s	sys 0.018s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":16289,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:16:59.764284 24801 maintenance_manager.cc:419] P 875d28fe3fa54e14bcc1ae88410f2b71: Scheduling FlushDeltaMemStoresOp(da8e99a02d16409a9b44b91b98b5f136): perf score=2.188937
I20260812 06:16:59.774989 24738 maintenance_manager.cc:643] P 875d28fe3fa54e14bcc1ae88410f2b71: FlushDeltaMemStoresOp(da8e99a02d16409a9b44b91b98b5f136) complete. Timing: real 0.011s	user 0.006s	sys 0.004s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4232,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:59.775420 24801 maintenance_manager.cc:419] P 875d28fe3fa54e14bcc1ae88410f2b71: Scheduling FlushMRSOp(da8e99a02d16409a9b44b91b98b5f136): perf score=1.000000
I20260812 06:16:59.820137 24738 maintenance_manager.cc:643] P 875d28fe3fa54e14bcc1ae88410f2b71: FlushMRSOp(da8e99a02d16409a9b44b91b98b5f136) complete. Timing: real 0.045s	user 0.031s	sys 0.000s Metrics: {"bytes_written":1193503,"cfile_init":1,"dirs.queue_time_us":67,"dirs.run_cpu_time_us":248,"dirs.run_wall_time_us":1315,"drs_written":1,"lbm_read_time_us":49,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1440,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":29}
I20260812 06:16:59.820861 24801 maintenance_manager.cc:419] P 875d28fe3fa54e14bcc1ae88410f2b71: Scheduling LogGCOp(da8e99a02d16409a9b44b91b98b5f136): free 124257239 bytes of WAL
I20260812 06:16:59.821141 24738 log_reader.cc:385] T da8e99a02d16409a9b44b91b98b5f136: removed 12 log segments from log reader
I20260812 06:16:59.821205 24738 log.cc:1079] T da8e99a02d16409a9b44b91b98b5f136 P 875d28fe3fa54e14bcc1ae88410f2b71: Deleting log segment in path: /tmp/dist-test-taskg6QwMH/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515411975274-24417-0/minicluster-data/ts-0-root/wals/da8e99a02d16409a9b44b91b98b5f136/wal-000000003 (ops 12-16)
I20260812 06:16:59.821244 24738 log.cc:1079] T da8e99a02d16409a9b44b91b98b5f136 P 875d28fe3fa54e14bcc1ae88410f2b71: Deleting log segment in path: /tmp/dist-test-taskg6QwMH/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515411975274-24417-0/minicluster-data/ts-0-root/wals/da8e99a02d16409a9b44b91b98b5f136/wal-000000004 (ops 17-20)
I20260812 06:16:59.821269 24738 log.cc:1079] T da8e99a02d16409a9b44b91b98b5f136 P 875d28fe3fa54e14bcc1ae88410f2b71: Deleting log segment in path: /tmp/dist-test-taskg6QwMH/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515411975274-24417-0/minicluster-data/ts-0-root/wals/da8e99a02d16409a9b44b91b98b5f136/wal-000000005 (ops 21-25)
I20260812 06:16:59.821291 24738 log.cc:1079] T da8e99a02d16409a9b44b91b98b5f136 P 875d28fe3fa54e14bcc1ae88410f2b71: Deleting log segment in path: /tmp/dist-test-taskg6QwMH/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515411975274-24417-0/minicluster-data/ts-0-root/wals/da8e99a02d16409a9b44b91b98b5f136/wal-000000006 (ops 26-30)
I20260812 06:16:59.821317 24738 log.cc:1079] T da8e99a02d16409a9b44b91b98b5f136 P 875d28fe3fa54e14bcc1ae88410f2b71: Deleting log segment in path: /tmp/dist-test-taskg6QwMH/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515411975274-24417-0/minicluster-data/ts-0-root/wals/da8e99a02d16409a9b44b91b98b5f136/wal-000000007 (ops 31-35)
I20260812 06:16:59.821352 24738 log.cc:1079] T da8e99a02d16409a9b44b91b98b5f136 P 875d28fe3fa54e14bcc1ae88410f2b71: Deleting log segment in path: /tmp/dist-test-taskg6QwMH/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515411975274-24417-0/minicluster-data/ts-0-root/wals/da8e99a02d16409a9b44b91b98b5f136/wal-000000008 (ops 36-40)
I20260812 06:16:59.821374 24738 log.cc:1079] T da8e99a02d16409a9b44b91b98b5f136 P 875d28fe3fa54e14bcc1ae88410f2b71: Deleting log segment in path: /tmp/dist-test-taskg6QwMH/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515411975274-24417-0/minicluster-data/ts-0-root/wals/da8e99a02d16409a9b44b91b98b5f136/wal-000000009 (ops 41-45)
I20260812 06:16:59.821396 24738 log.cc:1079] T da8e99a02d16409a9b44b91b98b5f136 P 875d28fe3fa54e14bcc1ae88410f2b71: Deleting log segment in path: /tmp/dist-test-taskg6QwMH/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515411975274-24417-0/minicluster-data/ts-0-root/wals/da8e99a02d16409a9b44b91b98b5f136/wal-000000010 (ops 46-50)
I20260812 06:16:59.821425 24738 log.cc:1079] T da8e99a02d16409a9b44b91b98b5f136 P 875d28fe3fa54e14bcc1ae88410f2b71: Deleting log segment in path: /tmp/dist-test-taskg6QwMH/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515411975274-24417-0/minicluster-data/ts-0-root/wals/da8e99a02d16409a9b44b91b98b5f136/wal-000000011 (ops 51-55)
I20260812 06:16:59.821452 24738 log.cc:1079] T da8e99a02d16409a9b44b91b98b5f136 P 875d28fe3fa54e14bcc1ae88410f2b71: Deleting log segment in path: /tmp/dist-test-taskg6QwMH/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515411975274-24417-0/minicluster-data/ts-0-root/wals/da8e99a02d16409a9b44b91b98b5f136/wal-000000012 (ops 56-60)
I20260812 06:16:59.821485 24738 log.cc:1079] T da8e99a02d16409a9b44b91b98b5f136 P 875d28fe3fa54e14bcc1ae88410f2b71: Deleting log segment in path: /tmp/dist-test-taskg6QwMH/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515411975274-24417-0/minicluster-data/ts-0-root/wals/da8e99a02d16409a9b44b91b98b5f136/wal-000000013 (ops 61-65)
I20260812 06:16:59.821517 24738 log.cc:1079] T da8e99a02d16409a9b44b91b98b5f136 P 875d28fe3fa54e14bcc1ae88410f2b71: Deleting log segment in path: /tmp/dist-test-taskg6QwMH/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515411975274-24417-0/minicluster-data/ts-0-root/wals/da8e99a02d16409a9b44b91b98b5f136/wal-000000014 (ops 66-70)
I20260812 06:16:59.850806 24738 maintenance_manager.cc:643] P 875d28fe3fa54e14bcc1ae88410f2b71: LogGCOp(da8e99a02d16409a9b44b91b98b5f136) complete. Timing: real 0.030s	user 0.000s	sys 0.030s Metrics: {}
I20260812 06:16:59.851194 24801 maintenance_manager.cc:419] P 875d28fe3fa54e14bcc1ae88410f2b71: Scheduling FlushDeltaMemStoresOp(da8e99a02d16409a9b44b91b98b5f136): perf score=3.181125
I20260812 06:16:59.874869 24738 maintenance_manager.cc:643] P 875d28fe3fa54e14bcc1ae88410f2b71: FlushDeltaMemStoresOp(da8e99a02d16409a9b44b91b98b5f136) complete. Timing: real 0.024s	user 0.009s	sys 0.005s Metrics: {"bytes_written":4512903,"delete_count":0,"lbm_write_time_us":5795,"lbm_writes_lt_1ms":113,"reinsert_count":0,"update_count":550}
I20260812 06:16:59.875385 24801 maintenance_manager.cc:419] P 875d28fe3fa54e14bcc1ae88410f2b71: Scheduling FlushDeltaMemStoresOp(da8e99a02d16409a9b44b91b98b5f136): perf score=2.188937
I20260812 06:16:59.884820 24738 maintenance_manager.cc:643] P 875d28fe3fa54e14bcc1ae88410f2b71: FlushDeltaMemStoresOp(da8e99a02d16409a9b44b91b98b5f136) complete. Timing: real 0.009s	user 0.008s	sys 0.000s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3480,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:16:59.885270 24801 maintenance_manager.cc:419] P 875d28fe3fa54e14bcc1ae88410f2b71: Scheduling UndoDeltaBlockGCOp(da8e99a02d16409a9b44b91b98b5f136): 462 bytes on disk
I20260812 06:16:59.885680 24738 maintenance_manager.cc:643] P 875d28fe3fa54e14bcc1ae88410f2b71: UndoDeltaBlockGCOp(da8e99a02d16409a9b44b91b98b5f136) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":54,"lbm_reads_lt_1ms":4}
I20260812 06:16:59.886132 24801 maintenance_manager.cc:419] P 875d28fe3fa54e14bcc1ae88410f2b71: Scheduling MajorDeltaCompactionOp(da8e99a02d16409a9b44b91b98b5f136): perf score=1.000000
I20260812 06:17:00.099745 24738 maintenance_manager.cc:643] P 875d28fe3fa54e14bcc1ae88410f2b71: MajorDeltaCompactionOp(da8e99a02d16409a9b44b91b98b5f136) complete. Timing: real 0.213s	user 0.150s	sys 0.063s Metrics: {"cfile_cache_miss":634,"cfile_cache_miss_bytes":28918323,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":835,"lbm_read_time_us":15325,"lbm_reads_lt_1ms":674,"lbm_write_time_us":33777,"lbm_writes_lt_1ms":643,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":13440,"thread_start_us":82,"threads_started":1,"update_count":3000}
I20260812 06:17:00.100559 24801 maintenance_manager.cc:419] P 875d28fe3fa54e14bcc1ae88410f2b71: Scheduling FlushDeltaMemStoresOp(da8e99a02d16409a9b44b91b98b5f136): perf score=14.095187
I20260812 06:17:00.156672 24738 maintenance_manager.cc:643] P 875d28fe3fa54e14bcc1ae88410f2b71: FlushDeltaMemStoresOp(da8e99a02d16409a9b44b91b98b5f136) complete. Timing: real 0.056s	user 0.040s	sys 0.011s Metrics: {"bytes_written":16409900,"delete_count":0,"lbm_write_time_us":22453,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:17:00.157189 24801 maintenance_manager.cc:419] P 875d28fe3fa54e14bcc1ae88410f2b71: Scheduling FlushDeltaMemStoresOp(da8e99a02d16409a9b44b91b98b5f136): perf score=2.188937
I20260812 06:17:00.168365 24738 maintenance_manager.cc:643] P 875d28fe3fa54e14bcc1ae88410f2b71: FlushDeltaMemStoresOp(da8e99a02d16409a9b44b91b98b5f136) complete. Timing: real 0.011s	user 0.005s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3913,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:00.169013 24801 maintenance_manager.cc:419] P 875d28fe3fa54e14bcc1ae88410f2b71: Scheduling MajorDeltaCompactionOp(da8e99a02d16409a9b44b91b98b5f136): perf score=1.000000
I20260812 06:17:00.339385 24738 maintenance_manager.cc:643] P 875d28fe3fa54e14bcc1ae88410f2b71: MajorDeltaCompactionOp(da8e99a02d16409a9b44b91b98b5f136) complete. Timing: real 0.170s	user 0.114s	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":381,"lbm_read_time_us":13339,"lbm_reads_lt_1ms":572,"lbm_write_time_us":28613,"lbm_writes_lt_1ms":543,"mutex_wait_us":82,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":13312,"update_count":2500}
I20260812 06:17:00.339942 24801 maintenance_manager.cc:419] P 875d28fe3fa54e14bcc1ae88410f2b71: Scheduling FlushDeltaMemStoresOp(da8e99a02d16409a9b44b91b98b5f136): perf score=14.095187
I20260812 06:17:00.400624 24738 maintenance_manager.cc:643] P 875d28fe3fa54e14bcc1ae88410f2b71: FlushDeltaMemStoresOp(da8e99a02d16409a9b44b91b98b5f136) complete. Timing: real 0.060s	user 0.018s	sys 0.032s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":21591,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:17:00.401180 24801 maintenance_manager.cc:419] P 875d28fe3fa54e14bcc1ae88410f2b71: Scheduling FlushDeltaMemStoresOp(da8e99a02d16409a9b44b91b98b5f136): perf score=2.188937
I20260812 06:17:00.412669 24738 maintenance_manager.cc:643] P 875d28fe3fa54e14bcc1ae88410f2b71: FlushDeltaMemStoresOp(da8e99a02d16409a9b44b91b98b5f136) complete. Timing: real 0.011s	user 0.006s	sys 0.003s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4384,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:00.413141 24801 maintenance_manager.cc:419] P 875d28fe3fa54e14bcc1ae88410f2b71: Scheduling MajorDeltaCompactionOp(da8e99a02d16409a9b44b91b98b5f136): perf score=1.000000
I20260812 06:17:00.585012 24738 maintenance_manager.cc:643] P 875d28fe3fa54e14bcc1ae88410f2b71: MajorDeltaCompactionOp(da8e99a02d16409a9b44b91b98b5f136) complete. Timing: real 0.172s	user 0.096s	sys 0.076s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24815684,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":172,"lbm_read_time_us":11738,"lbm_reads_lt_1ms":572,"lbm_write_time_us":29410,"lbm_writes_lt_1ms":543,"mutex_wait_us":23,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":7936,"update_count":2500}
I20260812 06:17:00.585708 24801 maintenance_manager.cc:419] P 875d28fe3fa54e14bcc1ae88410f2b71: Scheduling FlushDeltaMemStoresOp(da8e99a02d16409a9b44b91b98b5f136): perf score=14.095187
I20260812 06:17:00.646953 24738 maintenance_manager.cc:643] P 875d28fe3fa54e14bcc1ae88410f2b71: FlushDeltaMemStoresOp(da8e99a02d16409a9b44b91b98b5f136) complete. Timing: real 0.061s	user 0.034s	sys 0.027s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":22655,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:17:00.647578 24801 maintenance_manager.cc:419] P 875d28fe3fa54e14bcc1ae88410f2b71: Scheduling FlushDeltaMemStoresOp(da8e99a02d16409a9b44b91b98b5f136): perf score=2.188937
I20260812 06:17:00.658190 24738 maintenance_manager.cc:643] P 875d28fe3fa54e14bcc1ae88410f2b71: FlushDeltaMemStoresOp(da8e99a02d16409a9b44b91b98b5f136) complete. Timing: real 0.010s	user 0.004s	sys 0.004s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4100,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:00.658905 24801 maintenance_manager.cc:419] P 875d28fe3fa54e14bcc1ae88410f2b71: Scheduling MajorDeltaCompactionOp(da8e99a02d16409a9b44b91b98b5f136): perf score=1.000000
I20260812 06:17:00.849707 24738 maintenance_manager.cc:643] P 875d28fe3fa54e14bcc1ae88410f2b71: MajorDeltaCompactionOp(da8e99a02d16409a9b44b91b98b5f136) complete. Timing: real 0.191s	user 0.100s	sys 0.086s 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":230,"lbm_read_time_us":12307,"lbm_reads_lt_1ms":572,"lbm_write_time_us":33969,"lbm_writes_lt_1ms":543,"mutex_wait_us":23,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":9600,"update_count":2500}
I20260812 06:17:00.850559 24801 maintenance_manager.cc:419] P 875d28fe3fa54e14bcc1ae88410f2b71: Scheduling FlushDeltaMemStoresOp(da8e99a02d16409a9b44b91b98b5f136): perf score=14.095187
I20260812 06:17:00.897603 24738 maintenance_manager.cc:643] P 875d28fe3fa54e14bcc1ae88410f2b71: FlushDeltaMemStoresOp(da8e99a02d16409a9b44b91b98b5f136) complete. Timing: real 0.047s	user 0.010s	sys 0.030s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":19173,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:17:00.898191 24801 maintenance_manager.cc:419] P 875d28fe3fa54e14bcc1ae88410f2b71: Scheduling FlushDeltaMemStoresOp(da8e99a02d16409a9b44b91b98b5f136): perf score=2.188937
I20260812 06:17:00.920379 24738 maintenance_manager.cc:643] P 875d28fe3fa54e14bcc1ae88410f2b71: FlushDeltaMemStoresOp(da8e99a02d16409a9b44b91b98b5f136) complete. Timing: real 0.022s	user 0.006s	sys 0.014s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4244,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:00.921057 24801 maintenance_manager.cc:419] P 875d28fe3fa54e14bcc1ae88410f2b71: Scheduling MajorDeltaCompactionOp(da8e99a02d16409a9b44b91b98b5f136): perf score=1.000000
I20260812 06:17:01.111593 24738 maintenance_manager.cc:643] P 875d28fe3fa54e14bcc1ae88410f2b71: MajorDeltaCompactionOp(da8e99a02d16409a9b44b91b98b5f136) complete. Timing: real 0.190s	user 0.113s	sys 0.070s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24815684,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":206,"lbm_read_time_us":12534,"lbm_reads_lt_1ms":572,"lbm_write_time_us":32011,"lbm_writes_lt_1ms":543,"mutex_wait_us":79,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":6400,"update_count":2500}
I20260812 06:17:01.112377 24801 maintenance_manager.cc:419] P 875d28fe3fa54e14bcc1ae88410f2b71: Scheduling FlushDeltaMemStoresOp(da8e99a02d16409a9b44b91b98b5f136): perf score=14.095187
I20260812 06:17:01.162753 24738 maintenance_manager.cc:643] P 875d28fe3fa54e14bcc1ae88410f2b71: FlushDeltaMemStoresOp(da8e99a02d16409a9b44b91b98b5f136) complete. Timing: real 0.050s	user 0.039s	sys 0.011s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":22081,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:17:01.163338 24801 maintenance_manager.cc:419] P 875d28fe3fa54e14bcc1ae88410f2b71: Scheduling FlushDeltaMemStoresOp(da8e99a02d16409a9b44b91b98b5f136): perf score=2.188937
I20260812 06:17:01.175904 24738 maintenance_manager.cc:643] P 875d28fe3fa54e14bcc1ae88410f2b71: FlushDeltaMemStoresOp(da8e99a02d16409a9b44b91b98b5f136) complete. Timing: real 0.012s	user 0.009s	sys 0.002s Metrics: {"bytes_written":4102660,"delete_count":0,"lbm_write_time_us":4444,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:01.176409 24801 maintenance_manager.cc:419] P 875d28fe3fa54e14bcc1ae88410f2b71: Scheduling MajorDeltaCompactionOp(da8e99a02d16409a9b44b91b98b5f136): perf score=1.000000
I20260812 06:17:01.356863 24738 maintenance_manager.cc:643] P 875d28fe3fa54e14bcc1ae88410f2b71: MajorDeltaCompactionOp(da8e99a02d16409a9b44b91b98b5f136) complete. Timing: real 0.180s	user 0.140s	sys 0.035s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24815684,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":213,"lbm_read_time_us":10567,"lbm_reads_lt_1ms":572,"lbm_write_time_us":31787,"lbm_writes_lt_1ms":543,"mutex_wait_us":20,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":6144,"update_count":2500}
I20260812 06:17:01.357550 24801 maintenance_manager.cc:419] P 875d28fe3fa54e14bcc1ae88410f2b71: Scheduling FlushDeltaMemStoresOp(da8e99a02d16409a9b44b91b98b5f136): perf score=14.095187
I20260812 06:17:01.405035 24738 maintenance_manager.cc:643] P 875d28fe3fa54e14bcc1ae88410f2b71: FlushDeltaMemStoresOp(da8e99a02d16409a9b44b91b98b5f136) complete. Timing: real 0.047s	user 0.021s	sys 0.024s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":20794,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:17:01.405622 24801 maintenance_manager.cc:419] P 875d28fe3fa54e14bcc1ae88410f2b71: Scheduling FlushDeltaMemStoresOp(da8e99a02d16409a9b44b91b98b5f136): perf score=2.188937
I20260812 06:17:01.420895 24738 maintenance_manager.cc:643] P 875d28fe3fa54e14bcc1ae88410f2b71: FlushDeltaMemStoresOp(da8e99a02d16409a9b44b91b98b5f136) complete. Timing: real 0.015s	user 0.006s	sys 0.007s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6134,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:01.421411 24801 maintenance_manager.cc:419] P 875d28fe3fa54e14bcc1ae88410f2b71: Scheduling FlushMRSOp(da8e99a02d16409a9b44b91b98b5f136): perf score=1.000000
I20260812 06:17:01.455394 24738 maintenance_manager.cc:643] P 875d28fe3fa54e14bcc1ae88410f2b71: FlushMRSOp(da8e99a02d16409a9b44b91b98b5f136) complete. Timing: real 0.034s	user 0.033s	sys 0.000s Metrics: {"bytes_written":1316419,"cfile_init":1,"dirs.queue_time_us":74,"dirs.run_cpu_time_us":254,"dirs.run_wall_time_us":1544,"drs_written":1,"lbm_read_time_us":61,"lbm_reads_lt_1ms":4,"lbm_write_time_us":2219,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":32,"spinlock_wait_cycles":1280}
I20260812 06:17:01.456192 24801 maintenance_manager.cc:419] P 875d28fe3fa54e14bcc1ae88410f2b71: Scheduling LogGCOp(da8e99a02d16409a9b44b91b98b5f136): free 129773581 bytes of WAL
I20260812 06:17:01.456478 24738 log_reader.cc:385] T da8e99a02d16409a9b44b91b98b5f136: removed 13 log segments from log reader
I20260812 06:17:01.456557 24738 log.cc:1079] T da8e99a02d16409a9b44b91b98b5f136 P 875d28fe3fa54e14bcc1ae88410f2b71: Deleting log segment in path: /tmp/dist-test-taskg6QwMH/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515411975274-24417-0/minicluster-data/ts-0-root/wals/da8e99a02d16409a9b44b91b98b5f136/wal-000000015 (ops 71-75)
I20260812 06:17:01.456612 24738 log.cc:1079] T da8e99a02d16409a9b44b91b98b5f136 P 875d28fe3fa54e14bcc1ae88410f2b71: Deleting log segment in path: /tmp/dist-test-taskg6QwMH/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515411975274-24417-0/minicluster-data/ts-0-root/wals/da8e99a02d16409a9b44b91b98b5f136/wal-000000016 (ops 76-80)
I20260812 06:17:01.456671 24738 log.cc:1079] T da8e99a02d16409a9b44b91b98b5f136 P 875d28fe3fa54e14bcc1ae88410f2b71: Deleting log segment in path: /tmp/dist-test-taskg6QwMH/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515411975274-24417-0/minicluster-data/ts-0-root/wals/da8e99a02d16409a9b44b91b98b5f136/wal-000000017 (ops 81-85)
I20260812 06:17:01.456712 24738 log.cc:1079] T da8e99a02d16409a9b44b91b98b5f136 P 875d28fe3fa54e14bcc1ae88410f2b71: Deleting log segment in path: /tmp/dist-test-taskg6QwMH/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515411975274-24417-0/minicluster-data/ts-0-root/wals/da8e99a02d16409a9b44b91b98b5f136/wal-000000018 (ops 86-90)
I20260812 06:17:01.456766 24738 log.cc:1079] T da8e99a02d16409a9b44b91b98b5f136 P 875d28fe3fa54e14bcc1ae88410f2b71: Deleting log segment in path: /tmp/dist-test-taskg6QwMH/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515411975274-24417-0/minicluster-data/ts-0-root/wals/da8e99a02d16409a9b44b91b98b5f136/wal-000000019 (ops 91-95)
I20260812 06:17:01.456806 24738 log.cc:1079] T da8e99a02d16409a9b44b91b98b5f136 P 875d28fe3fa54e14bcc1ae88410f2b71: Deleting log segment in path: /tmp/dist-test-taskg6QwMH/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515411975274-24417-0/minicluster-data/ts-0-root/wals/da8e99a02d16409a9b44b91b98b5f136/wal-000000020 (ops 96-100)
I20260812 06:17:01.456843 24738 log.cc:1079] T da8e99a02d16409a9b44b91b98b5f136 P 875d28fe3fa54e14bcc1ae88410f2b71: Deleting log segment in path: /tmp/dist-test-taskg6QwMH/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515411975274-24417-0/minicluster-data/ts-0-root/wals/da8e99a02d16409a9b44b91b98b5f136/wal-000000021 (ops 101-104)
I20260812 06:17:01.456879 24738 log.cc:1079] T da8e99a02d16409a9b44b91b98b5f136 P 875d28fe3fa54e14bcc1ae88410f2b71: Deleting log segment in path: /tmp/dist-test-taskg6QwMH/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515411975274-24417-0/minicluster-data/ts-0-root/wals/da8e99a02d16409a9b44b91b98b5f136/wal-000000022 (ops 105-109)
I20260812 06:17:01.456918 24738 log.cc:1079] T da8e99a02d16409a9b44b91b98b5f136 P 875d28fe3fa54e14bcc1ae88410f2b71: Deleting log segment in path: /tmp/dist-test-taskg6QwMH/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515411975274-24417-0/minicluster-data/ts-0-root/wals/da8e99a02d16409a9b44b91b98b5f136/wal-000000023 (ops 110-114)
I20260812 06:17:01.456954 24738 log.cc:1079] T da8e99a02d16409a9b44b91b98b5f136 P 875d28fe3fa54e14bcc1ae88410f2b71: Deleting log segment in path: /tmp/dist-test-taskg6QwMH/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515411975274-24417-0/minicluster-data/ts-0-root/wals/da8e99a02d16409a9b44b91b98b5f136/wal-000000024 (ops 115-119)
I20260812 06:17:01.456990 24738 log.cc:1079] T da8e99a02d16409a9b44b91b98b5f136 P 875d28fe3fa54e14bcc1ae88410f2b71: Deleting log segment in path: /tmp/dist-test-taskg6QwMH/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515411975274-24417-0/minicluster-data/ts-0-root/wals/da8e99a02d16409a9b44b91b98b5f136/wal-000000025 (ops 120-124)
I20260812 06:17:01.457036 24738 log.cc:1079] T da8e99a02d16409a9b44b91b98b5f136 P 875d28fe3fa54e14bcc1ae88410f2b71: Deleting log segment in path: /tmp/dist-test-taskg6QwMH/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515411975274-24417-0/minicluster-data/ts-0-root/wals/da8e99a02d16409a9b44b91b98b5f136/wal-000000026 (ops 125-129)
I20260812 06:17:01.457072 24738 log.cc:1079] T da8e99a02d16409a9b44b91b98b5f136 P 875d28fe3fa54e14bcc1ae88410f2b71: Deleting log segment in path: /tmp/dist-test-taskg6QwMH/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515411975274-24417-0/minicluster-data/ts-0-root/wals/da8e99a02d16409a9b44b91b98b5f136/wal-000000027 (ops 130-134)
I20260812 06:17:01.487986 24738 maintenance_manager.cc:643] P 875d28fe3fa54e14bcc1ae88410f2b71: LogGCOp(da8e99a02d16409a9b44b91b98b5f136) complete. Timing: real 0.032s	user 0.000s	sys 0.030s Metrics: {}
I20260812 06:17:01.488466 24801 maintenance_manager.cc:419] P 875d28fe3fa54e14bcc1ae88410f2b71: Scheduling FlushDeltaMemStoresOp(da8e99a02d16409a9b44b91b98b5f136): perf score=3.181125
I20260812 06:17:01.515377 24738 maintenance_manager.cc:643] P 875d28fe3fa54e14bcc1ae88410f2b71: FlushDeltaMemStoresOp(da8e99a02d16409a9b44b91b98b5f136) complete. Timing: real 0.027s	user 0.012s	sys 0.008s Metrics: {"bytes_written":4512903,"delete_count":0,"lbm_write_time_us":7526,"lbm_writes_lt_1ms":113,"reinsert_count":0,"update_count":550}
I20260812 06:17:01.516124 24801 maintenance_manager.cc:419] P 875d28fe3fa54e14bcc1ae88410f2b71: Scheduling UndoDeltaBlockGCOp(da8e99a02d16409a9b44b91b98b5f136): 493 bytes on disk
I20260812 06:17:01.516597 24738 maintenance_manager.cc:643] P 875d28fe3fa54e14bcc1ae88410f2b71: UndoDeltaBlockGCOp(da8e99a02d16409a9b44b91b98b5f136) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":64,"lbm_reads_lt_1ms":4}
I20260812 06:17:01.517108 24801 maintenance_manager.cc:419] P 875d28fe3fa54e14bcc1ae88410f2b71: Scheduling FlushDeltaMemStoresOp(da8e99a02d16409a9b44b91b98b5f136): perf score=2.188937
I20260812 06:17:01.527467 24738 maintenance_manager.cc:643] P 875d28fe3fa54e14bcc1ae88410f2b71: FlushDeltaMemStoresOp(da8e99a02d16409a9b44b91b98b5f136) complete. Timing: real 0.010s	user 0.000s	sys 0.009s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3882,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:17:01.528309 24801 maintenance_manager.cc:419] P 875d28fe3fa54e14bcc1ae88410f2b71: Scheduling MajorDeltaCompactionOp(da8e99a02d16409a9b44b91b98b5f136): perf score=1.000000
I20260812 06:17:01.774360 24738 maintenance_manager.cc:643] P 875d28fe3fa54e14bcc1ae88410f2b71: MajorDeltaCompactionOp(da8e99a02d16409a9b44b91b98b5f136) complete. Timing: real 0.246s	user 0.167s	sys 0.069s Metrics: {"cfile_cache_miss":734,"cfile_cache_miss_bytes":33020735,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":276,"lbm_read_time_us":15655,"lbm_reads_lt_1ms":774,"lbm_write_time_us":38496,"lbm_writes_lt_1ms":743,"mutex_wait_us":74,"peak_mem_usage":87969044,"reinsert_count":0,"spinlock_wait_cycles":1664,"thread_start_us":79,"threads_started":1,"update_count":3500}
I20260812 06:17:01.775198 24801 maintenance_manager.cc:419] P 875d28fe3fa54e14bcc1ae88410f2b71: Scheduling FlushDeltaMemStoresOp(da8e99a02d16409a9b44b91b98b5f136): perf score=18.063937
I20260812 06:17:01.833191 24738 maintenance_manager.cc:643] P 875d28fe3fa54e14bcc1ae88410f2b71: FlushDeltaMemStoresOp(da8e99a02d16409a9b44b91b98b5f136) complete. Timing: real 0.058s	user 0.023s	sys 0.031s Metrics: {"bytes_written":20512316,"delete_count":0,"lbm_write_time_us":25486,"lbm_writes_lt_1ms":503,"reinsert_count":0,"spinlock_wait_cycles":1920,"update_count":2500}
I20260812 06:17:01.833899 24801 maintenance_manager.cc:419] P 875d28fe3fa54e14bcc1ae88410f2b71: Scheduling MajorDeltaCompactionOp(da8e99a02d16409a9b44b91b98b5f136): perf score=1.000000
I20260812 06:17:02.033185 24738 maintenance_manager.cc:643] P 875d28fe3fa54e14bcc1ae88410f2b71: MajorDeltaCompactionOp(da8e99a02d16409a9b44b91b98b5f136) complete. Timing: real 0.199s	user 0.110s	sys 0.058s Metrics: {"cfile_cache_miss":531,"cfile_cache_miss_bytes":24815567,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":1,"delta_iterators_relevant":1,"dirs.queue_time_us":858,"lbm_read_time_us":12896,"lbm_reads_lt_1ms":563,"lbm_write_time_us":27727,"lbm_writes_lt_1ms":543,"mutex_wait_us":278,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":7936,"update_count":2500}
I20260812 06:17:02.033944 24801 maintenance_manager.cc:419] P 875d28fe3fa54e14bcc1ae88410f2b71: Scheduling FlushDeltaMemStoresOp(da8e99a02d16409a9b44b91b98b5f136): perf score=15.087375
I20260812 06:17:02.129858 24738 maintenance_manager.cc:643] P 875d28fe3fa54e14bcc1ae88410f2b71: FlushDeltaMemStoresOp(da8e99a02d16409a9b44b91b98b5f136) complete. Timing: real 0.096s	user 0.029s	sys 0.012s Metrics: {"bytes_written":17312435,"delete_count":0,"lbm_write_time_us":18825,"lbm_writes_lt_1ms":425,"reinsert_count":0,"update_count":2110}
I20260812 06:17:02.130434 24801 maintenance_manager.cc:419] P 875d28fe3fa54e14bcc1ae88410f2b71: Scheduling FlushDeltaMemStoresOp(da8e99a02d16409a9b44b91b98b5f136): perf score=6.157687
I20260812 06:17:02.241495 24738 maintenance_manager.cc:643] P 875d28fe3fa54e14bcc1ae88410f2b71: FlushDeltaMemStoresOp(da8e99a02d16409a9b44b91b98b5f136) complete. Timing: real 0.111s	user 0.018s	sys 0.003s Metrics: {"bytes_written":7712790,"delete_count":0,"lbm_write_time_us":9272,"lbm_writes_lt_1ms":191,"reinsert_count":0,"update_count":940}
I20260812 06:17:02.242053 24801 maintenance_manager.cc:419] P 875d28fe3fa54e14bcc1ae88410f2b71: Scheduling FlushDeltaMemStoresOp(da8e99a02d16409a9b44b91b98b5f136): perf score=10.126437
I20260812 06:17:02.344172 24738 maintenance_manager.cc:643] P 875d28fe3fa54e14bcc1ae88410f2b71: FlushDeltaMemStoresOp(da8e99a02d16409a9b44b91b98b5f136) complete. Timing: real 0.102s	user 0.019s	sys 0.016s Metrics: {"bytes_written":11897251,"delete_count":0,"lbm_write_time_us":15497,"lbm_writes_lt_1ms":293,"reinsert_count":0,"update_count":1450}
I20260812 06:17:02.344784 24801 maintenance_manager.cc:419] P 875d28fe3fa54e14bcc1ae88410f2b71: Scheduling FlushDeltaMemStoresOp(da8e99a02d16409a9b44b91b98b5f136): perf score=6.157687
W20260812 06:17:02.444448 24819 log.cc:927] Time spent T da8e99a02d16409a9b44b91b98b5f136 P 875d28fe3fa54e14bcc1ae88410f2b71: Append to log took a long time: real 0.065s	user 0.000s	sys 0.000s
I20260812 06:17:02.468638 24738 maintenance_manager.cc:643] P 875d28fe3fa54e14bcc1ae88410f2b71: FlushDeltaMemStoresOp(da8e99a02d16409a9b44b91b98b5f136) complete. Timing: real 0.124s	user 0.008s	sys 0.012s Metrics: {"bytes_written":8205078,"delete_count":0,"lbm_write_time_us":9079,"lbm_writes_lt_1ms":203,"reinsert_count":0,"update_count":1000}
I20260812 06:17:02.469161 24801 maintenance_manager.cc:419] P 875d28fe3fa54e14bcc1ae88410f2b71: Scheduling FlushDeltaMemStoresOp(da8e99a02d16409a9b44b91b98b5f136): perf score=6.157687
I20260812 06:17:02.568976 24738 maintenance_manager.cc:643] P 875d28fe3fa54e14bcc1ae88410f2b71: FlushDeltaMemStoresOp(da8e99a02d16409a9b44b91b98b5f136) complete. Timing: real 0.100s	user 0.021s	sys 0.000s Metrics: {"bytes_written":8205077,"delete_count":0,"lbm_write_time_us":9273,"lbm_writes_lt_1ms":203,"reinsert_count":0,"update_count":1000}
I20260812 06:17:02.569813 24801 maintenance_manager.cc:419] P 875d28fe3fa54e14bcc1ae88410f2b71: Scheduling FlushDeltaMemStoresOp(da8e99a02d16409a9b44b91b98b5f136): perf score=7.149875
I20260812 06:17:02.674425 24738 maintenance_manager.cc:643] P 875d28fe3fa54e14bcc1ae88410f2b71: FlushDeltaMemStoresOp(da8e99a02d16409a9b44b91b98b5f136) complete. Timing: real 0.104s	user 0.017s	sys 0.007s Metrics: {"bytes_written":8410199,"delete_count":0,"lbm_write_time_us":10267,"lbm_writes_lt_1ms":208,"reinsert_count":0,"update_count":1025}
I20260812 06:17:02.675138 24801 maintenance_manager.cc:419] P 875d28fe3fa54e14bcc1ae88410f2b71: Scheduling FlushDeltaMemStoresOp(da8e99a02d16409a9b44b91b98b5f136): perf score=8.142062
I20260812 06:17:02.776300 24738 maintenance_manager.cc:643] P 875d28fe3fa54e14bcc1ae88410f2b71: FlushDeltaMemStoresOp(da8e99a02d16409a9b44b91b98b5f136) complete. Timing: real 0.101s	user 0.018s	sys 0.009s Metrics: {"bytes_written":10092191,"delete_count":0,"lbm_write_time_us":11806,"lbm_writes_lt_1ms":249,"reinsert_count":0,"update_count":1230}
I20260812 06:17:02.777071 24801 maintenance_manager.cc:419] P 875d28fe3fa54e14bcc1ae88410f2b71: Scheduling FlushDeltaMemStoresOp(da8e99a02d16409a9b44b91b98b5f136): perf score=8.142062
I20260812 06:17:02.878567 24738 maintenance_manager.cc:643] P 875d28fe3fa54e14bcc1ae88410f2b71: FlushDeltaMemStoresOp(da8e99a02d16409a9b44b91b98b5f136) complete. Timing: real 0.101s	user 0.014s	sys 0.017s Metrics: {"bytes_written":10215269,"delete_count":0,"lbm_write_time_us":13639,"lbm_writes_lt_1ms":252,"reinsert_count":0,"update_count":1245}
I20260812 06:17:02.879897 24801 maintenance_manager.cc:419] P 875d28fe3fa54e14bcc1ae88410f2b71: Scheduling FlushDeltaMemStoresOp(da8e99a02d16409a9b44b91b98b5f136): perf score=6.157687
I20260812 06:17:02.979426 24738 maintenance_manager.cc:643] P 875d28fe3fa54e14bcc1ae88410f2b71: FlushDeltaMemStoresOp(da8e99a02d16409a9b44b91b98b5f136) complete. Timing: real 0.099s	user 0.014s	sys 0.008s Metrics: {"bytes_written":8205078,"delete_count":0,"lbm_write_time_us":9819,"lbm_writes_lt_1ms":203,"reinsert_count":0,"update_count":1000}
I20260812 06:17:02.979941 24801 maintenance_manager.cc:419] P 875d28fe3fa54e14bcc1ae88410f2b71: Scheduling FlushDeltaMemStoresOp(da8e99a02d16409a9b44b91b98b5f136): perf score=10.126437
I20260812 06:17:03.073346 24417 heavy-update-compaction-itest.cc:229] Time spent updating: real 4.919s	user 1.811s	sys 0.159s
I20260812 06:17:03.075769 24738 maintenance_manager.cc:643] P 875d28fe3fa54e14bcc1ae88410f2b71: FlushDeltaMemStoresOp(da8e99a02d16409a9b44b91b98b5f136) complete. Timing: real 0.096s	user 0.021s	sys 0.016s Metrics: {"bytes_written":12307489,"delete_count":0,"lbm_write_time_us":17436,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:17:03.076488 24801 maintenance_manager.cc:419] P 875d28fe3fa54e14bcc1ae88410f2b71: Scheduling FlushDeltaMemStoresOp(da8e99a02d16409a9b44b91b98b5f136): perf score=6.157687
I20260812 06:17:03.175347 24738 maintenance_manager.cc:643] P 875d28fe3fa54e14bcc1ae88410f2b71: FlushDeltaMemStoresOp(da8e99a02d16409a9b44b91b98b5f136) complete. Timing: real 0.099s	user 0.012s	sys 0.008s Metrics: {"bytes_written":8205079,"delete_count":0,"lbm_write_time_us":8795,"lbm_writes_lt_1ms":203,"reinsert_count":0,"spinlock_wait_cycles":1792,"update_count":1000}
I20260812 06:17:03.176103 24801 maintenance_manager.cc:419] P 875d28fe3fa54e14bcc1ae88410f2b71: Scheduling FlushMRSOp(da8e99a02d16409a9b44b91b98b5f136): perf score=1.000000
I20260812 06:17:03.274101 24738 maintenance_manager.cc:643] P 875d28fe3fa54e14bcc1ae88410f2b71: FlushMRSOp(da8e99a02d16409a9b44b91b98b5f136) complete. Timing: real 0.098s	user 0.028s	sys 0.012s Metrics: {"bytes_written":1398558,"cfile_init":1,"dirs.queue_time_us":216,"dirs.run_cpu_time_us":221,"dirs.run_wall_time_us":59668,"drs_written":1,"lbm_read_time_us":34,"lbm_reads_lt_1ms":4,"lbm_write_time_us":6758,"lbm_writes_1-10_ms":4,"lbm_writes_lt_1ms":40,"peak_mem_usage":0,"rows_written":34,"thread_start_us":120,"threads_started":1}
I20260812 06:17:03.275561 24801 maintenance_manager.cc:419] P 875d28fe3fa54e14bcc1ae88410f2b71: Scheduling LogGCOp(da8e99a02d16409a9b44b91b98b5f136): free 119647311 bytes of WAL
I20260812 06:17:03.275941 24738 log_reader.cc:385] T da8e99a02d16409a9b44b91b98b5f136: removed 11 log segments from log reader
I20260812 06:17:03.276012 24738 log.cc:1079] T da8e99a02d16409a9b44b91b98b5f136 P 875d28fe3fa54e14bcc1ae88410f2b71: Deleting log segment in path: /tmp/dist-test-taskg6QwMH/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515411975274-24417-0/minicluster-data/ts-0-root/wals/da8e99a02d16409a9b44b91b98b5f136/wal-000000028 (ops 135-139)
I20260812 06:17:03.276098 24738 log.cc:1079] T da8e99a02d16409a9b44b91b98b5f136 P 875d28fe3fa54e14bcc1ae88410f2b71: Deleting log segment in path: /tmp/dist-test-taskg6QwMH/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515411975274-24417-0/minicluster-data/ts-0-root/wals/da8e99a02d16409a9b44b91b98b5f136/wal-000000029 (ops 140-144)
I20260812 06:17:03.276149 24738 log.cc:1079] T da8e99a02d16409a9b44b91b98b5f136 P 875d28fe3fa54e14bcc1ae88410f2b71: Deleting log segment in path: /tmp/dist-test-taskg6QwMH/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515411975274-24417-0/minicluster-data/ts-0-root/wals/da8e99a02d16409a9b44b91b98b5f136/wal-000000030 (ops 145-149)
I20260812 06:17:03.276201 24738 log.cc:1079] T da8e99a02d16409a9b44b91b98b5f136 P 875d28fe3fa54e14bcc1ae88410f2b71: Deleting log segment in path: /tmp/dist-test-taskg6QwMH/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515411975274-24417-0/minicluster-data/ts-0-root/wals/da8e99a02d16409a9b44b91b98b5f136/wal-000000031 (ops 150-154)
I20260812 06:17:03.276252 24738 log.cc:1079] T da8e99a02d16409a9b44b91b98b5f136 P 875d28fe3fa54e14bcc1ae88410f2b71: Deleting log segment in path: /tmp/dist-test-taskg6QwMH/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515411975274-24417-0/minicluster-data/ts-0-root/wals/da8e99a02d16409a9b44b91b98b5f136/wal-000000032 (ops 155-159)
I20260812 06:17:03.276309 24738 log.cc:1079] T da8e99a02d16409a9b44b91b98b5f136 P 875d28fe3fa54e14bcc1ae88410f2b71: Deleting log segment in path: /tmp/dist-test-taskg6QwMH/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515411975274-24417-0/minicluster-data/ts-0-root/wals/da8e99a02d16409a9b44b91b98b5f136/wal-000000033 (ops 160-164)
I20260812 06:17:03.276351 24738 log.cc:1079] T da8e99a02d16409a9b44b91b98b5f136 P 875d28fe3fa54e14bcc1ae88410f2b71: Deleting log segment in path: /tmp/dist-test-taskg6QwMH/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515411975274-24417-0/minicluster-data/ts-0-root/wals/da8e99a02d16409a9b44b91b98b5f136/wal-000000034 (ops 165-169)
I20260812 06:17:03.276417 24738 log.cc:1079] T da8e99a02d16409a9b44b91b98b5f136 P 875d28fe3fa54e14bcc1ae88410f2b71: Deleting log segment in path: /tmp/dist-test-taskg6QwMH/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515411975274-24417-0/minicluster-data/ts-0-root/wals/da8e99a02d16409a9b44b91b98b5f136/wal-000000035 (ops 170-175)
I20260812 06:17:03.276491 24738 log.cc:1079] T da8e99a02d16409a9b44b91b98b5f136 P 875d28fe3fa54e14bcc1ae88410f2b71: Deleting log segment in path: /tmp/dist-test-taskg6QwMH/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515411975274-24417-0/minicluster-data/ts-0-root/wals/da8e99a02d16409a9b44b91b98b5f136/wal-000000036 (ops 176-180)
I20260812 06:17:03.276537 24738 log.cc:1079] T da8e99a02d16409a9b44b91b98b5f136 P 875d28fe3fa54e14bcc1ae88410f2b71: Deleting log segment in path: /tmp/dist-test-taskg6QwMH/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515411975274-24417-0/minicluster-data/ts-0-root/wals/da8e99a02d16409a9b44b91b98b5f136/wal-000000037 (ops 181-185)
I20260812 06:17:03.276677 24738 log.cc:1079] T da8e99a02d16409a9b44b91b98b5f136 P 875d28fe3fa54e14bcc1ae88410f2b71: Deleting log segment in path: /tmp/dist-test-taskg6QwMH/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515411975274-24417-0/minicluster-data/ts-0-root/wals/da8e99a02d16409a9b44b91b98b5f136/wal-000000038 (ops 186-190)
I20260812 06:17:03.310007 24738 maintenance_manager.cc:643] P 875d28fe3fa54e14bcc1ae88410f2b71: LogGCOp(da8e99a02d16409a9b44b91b98b5f136) complete. Timing: real 0.034s	user 0.000s	sys 0.031s Metrics: {}
I20260812 06:17:03.310720 24801 maintenance_manager.cc:419] P 875d28fe3fa54e14bcc1ae88410f2b71: Scheduling MajorDeltaCompactionOp(da8e99a02d16409a9b44b91b98b5f136): perf score=1.000000
I20260812 06:17:03.373390 24417 heavy-update-compaction-itest.cc:265] Time spent scanning: real 0.300s	user 0.003s	sys 0.000s
I20260812 06:17:03.374095 24417 tablet_server.cc:179] TabletServer@127.23.216.65:0 shutting down...
I20260812 06:17:04.583509 24738 maintenance_manager.cc:643] P 875d28fe3fa54e14bcc1ae88410f2b71: MajorDeltaCompactionOp(da8e99a02d16409a9b44b91b98b5f136) complete. Timing: real 1.273s	user 0.363s	sys 0.906s Metrics: {"cfile_cache_hit":2109,"cfile_cache_hit_bytes":88469884,"cfile_cache_miss":632,"cfile_cache_miss_bytes":26599963,"cfile_init":5,"delete_count":0,"delta_blocks_compacted":11,"delta_iterators_relevant":11,"dirs.queue_time_us":1160,"lbm_read_time_us":10068,"lbm_reads_lt_1ms":652,"lbm_write_time_us":473418,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":2744,"peak_mem_usage":336500484,"reinsert_count":0,"thread_start_us":493,"threads_started":7,"update_count":13500,"wal-append.queue_time_us":194}
I20260812 06:17:04.584223 24417 ts_tablet_manager.cc:1507] Shutting down tablet manager...
I20260812 06:17:04.584420 24417 tablet_replica.cc:333] T da8e99a02d16409a9b44b91b98b5f136 P 875d28fe3fa54e14bcc1ae88410f2b71: stopping tablet replica
I20260812 06:17:04.584607 24417 raft_consensus.cc:2243] T da8e99a02d16409a9b44b91b98b5f136 P 875d28fe3fa54e14bcc1ae88410f2b71 [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:17:04.584849 24417 raft_consensus.cc:2272] T da8e99a02d16409a9b44b91b98b5f136 P 875d28fe3fa54e14bcc1ae88410f2b71 [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:17:04.598892 24417 tablet_server.cc:196] TabletServer@127.23.216.65:0 shutdown complete.
I20260812 06:17:05.185330 24417 master.cc:562] Master@127.23.216.126:37433 shutting down...
I20260812 06:17:05.189045 24417 raft_consensus.cc:2243] T 00000000000000000000000000000000 P 041c3a0741f641b5a9d181852e111cc5 [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:17:05.189244 24417 raft_consensus.cc:2272] T 00000000000000000000000000000000 P 041c3a0741f641b5a9d181852e111cc5 [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:17:05.189292 24417 tablet_replica.cc:333] T 00000000000000000000000000000000 P 041c3a0741f641b5a9d181852e111cc5: stopping tablet replica
I20260812 06:17:05.202071 24417 master.cc:584] Master@127.23.216.126:37433 shutdown complete.
[       OK ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/1 (7387 ms)
[----------] 2 tests from EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy (13312 ms total)

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