[==========] 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:20:18.517025 12152 internal_mini_cluster.cc:156] Creating distributed mini masters. Addrs: 127.11.222.62:41993
I20260812 06:20:18.518224 12152 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:20:18.518977 12152 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:20:18.526867 12168 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:20:18.526867 12162 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:20:18.526922 12152 server_base.cc:1061] running on GCE node
W20260812 06:20:18.527330 12164 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:20:18.527992 12152 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:20:18.528092 12152 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:20:18.528158 12152 hybrid_clock.cc:648] HybridClock initialized: now 1786515618528154 us; error 0 us; skew 500 ppm
I20260812 06:20:18.530368 12152 webserver.cc:533] Webserver started at http://127.11.222.62:42517/ using document root <none> and password file <none>
I20260812 06:20:18.531111 12152 fs_manager.cc:362] Metadata directory not provided
I20260812 06:20:18.531188 12152 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:20:18.531466 12152 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:20:18.533388 12152 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskHG7JFS/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515618503783-12152-0/minicluster-data/master-0-root/instance:
uuid: "ff8b25039ca74d5c942d331e28c4de90"
format_stamp: "Formatted at 2026-08-12 06:20:18 on dist-test-slave-3kk6"
I20260812 06:20:18.537575 12152 fs_manager.cc:696] Time spent creating directory manager: real 0.004s	user 0.005s	sys 0.000s
I20260812 06:20:18.540511 12175 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:20:18.541855 12152 fs_manager.cc:730] Time spent opening block manager: real 0.003s	user 0.001s	sys 0.000s
I20260812 06:20:18.542030 12152 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskHG7JFS/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515618503783-12152-0/minicluster-data/master-0-root
uuid: "ff8b25039ca74d5c942d331e28c4de90"
format_stamp: "Formatted at 2026-08-12 06:20:18 on dist-test-slave-3kk6"
I20260812 06:20:18.542220 12152 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskHG7JFS/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515618503783-12152-0/minicluster-data/master-0-root
metadata directory: /tmp/dist-test-taskHG7JFS/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515618503783-12152-0/minicluster-data/master-0-root
1 data directories: /tmp/dist-test-taskHG7JFS/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515618503783-12152-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:20:18.584996 12152 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:20:18.585793 12152 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:20:18.586001 12152 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:20:18.594820 12152 rpc_server.cc:307] RPC server started. Bound to: 127.11.222.62:41993
I20260812 06:20:18.594887 12258 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.11.222.62:41993 every 8 connection(s)
I20260812 06:20:18.597481 12259 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:20:18.604099 12259 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P ff8b25039ca74d5c942d331e28c4de90: Bootstrap starting.
I20260812 06:20:18.607060 12259 tablet_bootstrap.cc:654] T 00000000000000000000000000000000 P ff8b25039ca74d5c942d331e28c4de90: Neither blocks nor log segments found. Creating new log.
I20260812 06:20:18.608213 12259 log.cc:826] T 00000000000000000000000000000000 P ff8b25039ca74d5c942d331e28c4de90: Log is configured to *not* fsync() on all Append() calls
I20260812 06:20:18.610913 12259 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P ff8b25039ca74d5c942d331e28c4de90: No bootstrap required, opened a new log
I20260812 06:20:18.614382 12259 raft_consensus.cc:359] T 00000000000000000000000000000000 P ff8b25039ca74d5c942d331e28c4de90 [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "ff8b25039ca74d5c942d331e28c4de90" member_type: VOTER }
I20260812 06:20:18.614605 12259 raft_consensus.cc:385] T 00000000000000000000000000000000 P ff8b25039ca74d5c942d331e28c4de90 [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:20:18.614727 12259 raft_consensus.cc:740] T 00000000000000000000000000000000 P ff8b25039ca74d5c942d331e28c4de90 [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: ff8b25039ca74d5c942d331e28c4de90, State: Initialized, Role: FOLLOWER
I20260812 06:20:18.615495 12259 consensus_queue.cc:260] T 00000000000000000000000000000000 P ff8b25039ca74d5c942d331e28c4de90 [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: "ff8b25039ca74d5c942d331e28c4de90" member_type: VOTER }
I20260812 06:20:18.615700 12259 raft_consensus.cc:399] T 00000000000000000000000000000000 P ff8b25039ca74d5c942d331e28c4de90 [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:20:18.615798 12259 raft_consensus.cc:493] T 00000000000000000000000000000000 P ff8b25039ca74d5c942d331e28c4de90 [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:20:18.616007 12259 raft_consensus.cc:3060] T 00000000000000000000000000000000 P ff8b25039ca74d5c942d331e28c4de90 [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:20:18.617167 12259 raft_consensus.cc:515] T 00000000000000000000000000000000 P ff8b25039ca74d5c942d331e28c4de90 [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "ff8b25039ca74d5c942d331e28c4de90" member_type: VOTER }
I20260812 06:20:18.617722 12259 leader_election.cc:304] T 00000000000000000000000000000000 P ff8b25039ca74d5c942d331e28c4de90 [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: ff8b25039ca74d5c942d331e28c4de90; no voters: 
I20260812 06:20:18.618152 12259 leader_election.cc:290] T 00000000000000000000000000000000 P ff8b25039ca74d5c942d331e28c4de90 [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:20:18.618376 12264 raft_consensus.cc:2804] T 00000000000000000000000000000000 P ff8b25039ca74d5c942d331e28c4de90 [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:20:18.618637 12264 raft_consensus.cc:697] T 00000000000000000000000000000000 P ff8b25039ca74d5c942d331e28c4de90 [term 1 LEADER]: Becoming Leader. State: Replica: ff8b25039ca74d5c942d331e28c4de90, State: Running, Role: LEADER
I20260812 06:20:18.619202 12264 consensus_queue.cc:237] T 00000000000000000000000000000000 P ff8b25039ca74d5c942d331e28c4de90 [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: "ff8b25039ca74d5c942d331e28c4de90" member_type: VOTER }
I20260812 06:20:18.619560 12259 sys_catalog.cc:565] T 00000000000000000000000000000000 P ff8b25039ca74d5c942d331e28c4de90 [sys.catalog]: configured and running, proceeding with master startup.
I20260812 06:20:18.621182 12268 sys_catalog.cc:455] T 00000000000000000000000000000000 P ff8b25039ca74d5c942d331e28c4de90 [sys.catalog]: SysCatalogTable state changed. Reason: New leader ff8b25039ca74d5c942d331e28c4de90. Latest consensus state: current_term: 1 leader_uuid: "ff8b25039ca74d5c942d331e28c4de90" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "ff8b25039ca74d5c942d331e28c4de90" member_type: VOTER } }
I20260812 06:20:18.621322 12268 sys_catalog.cc:458] T 00000000000000000000000000000000 P ff8b25039ca74d5c942d331e28c4de90 [sys.catalog]: This master's current role is: LEADER
I20260812 06:20:18.621632 12267 sys_catalog.cc:455] T 00000000000000000000000000000000 P ff8b25039ca74d5c942d331e28c4de90 [sys.catalog]: SysCatalogTable state changed. Reason: RaftConsensus started. Latest consensus state: current_term: 1 leader_uuid: "ff8b25039ca74d5c942d331e28c4de90" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "ff8b25039ca74d5c942d331e28c4de90" member_type: VOTER } }
I20260812 06:20:18.621737 12267 sys_catalog.cc:458] T 00000000000000000000000000000000 P ff8b25039ca74d5c942d331e28c4de90 [sys.catalog]: This master's current role is: LEADER
I20260812 06:20:18.621904 12280 catalog_manager.cc:1511] Loading table and tablet metadata into memory...
I20260812 06:20:18.622211 12152 internal_mini_cluster.cc:184] Waiting to initialize catalog manager on master 0
I20260812 06:20:18.624610 12280 catalog_manager.cc:1520] Initializing Kudu cluster ID...
I20260812 06:20:18.630242 12280 catalog_manager.cc:1383] Generated new cluster ID: f7403bc5dcf440f09f217d101ce8f748
I20260812 06:20:18.630332 12280 catalog_manager.cc:1531] Initializing Kudu internal certificate authority...
I20260812 06:20:18.644347 12280 catalog_manager.cc:1406] Generated new certificate authority record
I20260812 06:20:18.645793 12280 catalog_manager.cc:1540] Loading token signing keys...
I20260812 06:20:18.660457 12280 catalog_manager.cc:6092] T 00000000000000000000000000000000 P ff8b25039ca74d5c942d331e28c4de90: Generated new TSK 0
I20260812 06:20:18.661470 12280 catalog_manager.cc:1550] Initializing in-progress tserver states...
I20260812 06:20:18.687762 12152 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:20:18.691118 12298 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:20:18.691161 12297 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:20:18.691258 12300 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:20:18.691514 12152 server_base.cc:1061] running on GCE node
I20260812 06:20:18.691805 12152 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:20:18.691888 12152 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:20:18.691920 12152 hybrid_clock.cc:648] HybridClock initialized: now 1786515618691919 us; error 0 us; skew 500 ppm
I20260812 06:20:18.693079 12152 webserver.cc:533] Webserver started at http://127.11.222.1:39373/ using document root <none> and password file <none>
I20260812 06:20:18.693302 12152 fs_manager.cc:362] Metadata directory not provided
I20260812 06:20:18.693392 12152 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:20:18.693487 12152 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:20:18.693966 12152 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskHG7JFS/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515618503783-12152-0/minicluster-data/ts-0-root/instance:
uuid: "a3ad9850928e41aead46cec7b9db045f"
format_stamp: "Formatted at 2026-08-12 06:20:18 on dist-test-slave-3kk6"
I20260812 06:20:18.695968 12152 fs_manager.cc:696] Time spent creating directory manager: real 0.002s	user 0.003s	sys 0.000s
I20260812 06:20:18.697135 12308 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:20:18.697415 12152 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.001s	sys 0.000s
I20260812 06:20:18.697499 12152 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskHG7JFS/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515618503783-12152-0/minicluster-data/ts-0-root
uuid: "a3ad9850928e41aead46cec7b9db045f"
format_stamp: "Formatted at 2026-08-12 06:20:18 on dist-test-slave-3kk6"
I20260812 06:20:18.697602 12152 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskHG7JFS/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515618503783-12152-0/minicluster-data/ts-0-root
metadata directory: /tmp/dist-test-taskHG7JFS/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515618503783-12152-0/minicluster-data/ts-0-root
1 data directories: /tmp/dist-test-taskHG7JFS/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515618503783-12152-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:20:18.745141 12152 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:20:18.745688 12152 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:20:18.746305 12152 txn_system_client.cc:432] TxnSystemClient initialization is disabled...
I20260812 06:20:18.747514 12152 ts_tablet_manager.cc:585] Loaded tablet metadata (0 total tablets, 0 live tablets)
I20260812 06:20:18.747573 12152 ts_tablet_manager.cc:531] Time spent load tablet metadata: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:20:18.747649 12152 ts_tablet_manager.cc:616] Registered 0 tablets
I20260812 06:20:18.747699 12152 ts_tablet_manager.cc:595] Time spent register tablets: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:20:18.756191 12152 rpc_server.cc:307] RPC server started. Bound to: 127.11.222.1:37047
I20260812 06:20:18.756268 12399 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.11.222.1:37047 every 8 connection(s)
I20260812 06:20:18.767936 12400 heartbeater.cc:344] Connected to a master server at 127.11.222.62:41993
I20260812 06:20:18.768286 12400 heartbeater.cc:461] Registering TS with master...
I20260812 06:20:18.768816 12400 heartbeater.cc:507] Master 127.11.222.62:41993 requested a full tablet report, sending...
I20260812 06:20:18.770614 12200 ts_manager.cc:194] Registered new tserver with Master: a3ad9850928e41aead46cec7b9db045f (127.11.222.1:37047)
I20260812 06:20:18.770797 12152 internal_mini_cluster.cc:371] 1 TS(s) registered with all masters after 0.013805764s
I20260812 06:20:18.772364 12200 master_service.cc:502] Signed X509 certificate for tserver {username='slave'} at 127.0.0.1:38272
I20260812 06:20:18.782737 12200 catalog_manager.cc:2283] Servicing CreateTable request from {username='slave'} at 127.0.0.1:38288:
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:20:18.800107 12346 tablet_service.cc:1511] Processing CreateTablet for tablet edbfeddabe6c4a128a960ecdc25a4583 (DEFAULT_TABLE table=heavy-update-compaction-test [id=6a485810dea04462942c0f506d7e70e5]), partition=
I20260812 06:20:18.800697 12346 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet edbfeddabe6c4a128a960ecdc25a4583. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:20:18.803229 12415 tablet_bootstrap.cc:492] T edbfeddabe6c4a128a960ecdc25a4583 P a3ad9850928e41aead46cec7b9db045f: Bootstrap starting.
I20260812 06:20:18.804344 12415 tablet_bootstrap.cc:654] T edbfeddabe6c4a128a960ecdc25a4583 P a3ad9850928e41aead46cec7b9db045f: Neither blocks nor log segments found. Creating new log.
I20260812 06:20:18.805954 12415 tablet_bootstrap.cc:492] T edbfeddabe6c4a128a960ecdc25a4583 P a3ad9850928e41aead46cec7b9db045f: No bootstrap required, opened a new log
I20260812 06:20:18.806087 12415 ts_tablet_manager.cc:1403] T edbfeddabe6c4a128a960ecdc25a4583 P a3ad9850928e41aead46cec7b9db045f: Time spent bootstrapping tablet: real 0.003s	user 0.002s	sys 0.000s
I20260812 06:20:18.806541 12415 raft_consensus.cc:359] T edbfeddabe6c4a128a960ecdc25a4583 P a3ad9850928e41aead46cec7b9db045f [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "a3ad9850928e41aead46cec7b9db045f" member_type: VOTER last_known_addr { host: "127.11.222.1" port: 37047 } }
I20260812 06:20:18.806696 12415 raft_consensus.cc:385] T edbfeddabe6c4a128a960ecdc25a4583 P a3ad9850928e41aead46cec7b9db045f [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:20:18.806751 12415 raft_consensus.cc:740] T edbfeddabe6c4a128a960ecdc25a4583 P a3ad9850928e41aead46cec7b9db045f [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: a3ad9850928e41aead46cec7b9db045f, State: Initialized, Role: FOLLOWER
I20260812 06:20:18.806921 12415 consensus_queue.cc:260] T edbfeddabe6c4a128a960ecdc25a4583 P a3ad9850928e41aead46cec7b9db045f [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: "a3ad9850928e41aead46cec7b9db045f" member_type: VOTER last_known_addr { host: "127.11.222.1" port: 37047 } }
I20260812 06:20:18.807037 12415 raft_consensus.cc:399] T edbfeddabe6c4a128a960ecdc25a4583 P a3ad9850928e41aead46cec7b9db045f [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:20:18.807088 12415 raft_consensus.cc:493] T edbfeddabe6c4a128a960ecdc25a4583 P a3ad9850928e41aead46cec7b9db045f [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:20:18.807144 12415 raft_consensus.cc:3060] T edbfeddabe6c4a128a960ecdc25a4583 P a3ad9850928e41aead46cec7b9db045f [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:20:18.807894 12415 raft_consensus.cc:515] T edbfeddabe6c4a128a960ecdc25a4583 P a3ad9850928e41aead46cec7b9db045f [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "a3ad9850928e41aead46cec7b9db045f" member_type: VOTER last_known_addr { host: "127.11.222.1" port: 37047 } }
I20260812 06:20:18.808076 12415 leader_election.cc:304] T edbfeddabe6c4a128a960ecdc25a4583 P a3ad9850928e41aead46cec7b9db045f [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: a3ad9850928e41aead46cec7b9db045f; no voters: 
I20260812 06:20:18.808367 12415 leader_election.cc:290] T edbfeddabe6c4a128a960ecdc25a4583 P a3ad9850928e41aead46cec7b9db045f [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:20:18.808491 12417 raft_consensus.cc:2804] T edbfeddabe6c4a128a960ecdc25a4583 P a3ad9850928e41aead46cec7b9db045f [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:20:18.808811 12417 raft_consensus.cc:697] T edbfeddabe6c4a128a960ecdc25a4583 P a3ad9850928e41aead46cec7b9db045f [term 1 LEADER]: Becoming Leader. State: Replica: a3ad9850928e41aead46cec7b9db045f, State: Running, Role: LEADER
I20260812 06:20:18.808881 12415 ts_tablet_manager.cc:1434] T edbfeddabe6c4a128a960ecdc25a4583 P a3ad9850928e41aead46cec7b9db045f: Time spent starting tablet: real 0.003s	user 0.003s	sys 0.000s
I20260812 06:20:18.809074 12417 consensus_queue.cc:237] T edbfeddabe6c4a128a960ecdc25a4583 P a3ad9850928e41aead46cec7b9db045f [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: "a3ad9850928e41aead46cec7b9db045f" member_type: VOTER last_known_addr { host: "127.11.222.1" port: 37047 } }
I20260812 06:20:18.809195 12400 heartbeater.cc:499] Master 127.11.222.62:41993 was elected leader, sending a full tablet report...
I20260812 06:20:18.812302 12200 catalog_manager.cc:5719] T edbfeddabe6c4a128a960ecdc25a4583 P a3ad9850928e41aead46cec7b9db045f reported cstate change: term changed from 0 to 1, leader changed from <none> to a3ad9850928e41aead46cec7b9db045f (127.11.222.1). New cstate: current_term: 1 leader_uuid: "a3ad9850928e41aead46cec7b9db045f" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "a3ad9850928e41aead46cec7b9db045f" member_type: VOTER last_known_addr { host: "127.11.222.1" port: 37047 } health_report { overall_health: HEALTHY } } }
I20260812 06:20:18.882035 12152 heavy-update-compaction-itest.cc:215] Time spent inserting: real 0.060s	user 0.015s	sys 0.012s
I20260812 06:20:19.007714 12401 maintenance_manager.cc:419] P a3ad9850928e41aead46cec7b9db045f: Scheduling FlushMRSOp(edbfeddabe6c4a128a960ecdc25a4583): perf score=15.086190
I20260812 06:20:19.167608 12316 maintenance_manager.cc:643] P a3ad9850928e41aead46cec7b9db045f: FlushMRSOp(edbfeddabe6c4a128a960ecdc25a4583) complete. Timing: real 0.159s	user 0.133s	sys 0.024s Metrics: {"bytes_written":9353757,"cfile_init":1,"compiler_manager_pool.queue_time_us":411,"delete_count":0,"dirs.queue_time_us":75,"dirs.run_cpu_time_us":233,"dirs.run_wall_time_us":980,"drs_written":1,"lbm_read_time_us":127,"lbm_reads_lt_1ms":4,"lbm_write_time_us":36348,"lbm_writes_lt_1ms":585,"peak_mem_usage":0,"reinsert_count":0,"rows_written":103,"spinlock_wait_cycles":201088,"thread_start_us":203,"threads_started":1,"update_count":1140}
I20260812 06:20:19.169211 12401 maintenance_manager.cc:419] P a3ad9850928e41aead46cec7b9db045f: Scheduling LogGCOp(edbfeddabe6c4a128a960ecdc25a4583): free 11976772 bytes of WAL
I20260812 06:20:19.169890 12316 log_reader.cc:385] T edbfeddabe6c4a128a960ecdc25a4583: removed 1 log segments from log reader
I20260812 06:20:19.170109 12316 log.cc:1079] T edbfeddabe6c4a128a960ecdc25a4583 P a3ad9850928e41aead46cec7b9db045f: Deleting log segment in path: /tmp/dist-test-taskHG7JFS/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515618503783-12152-0/minicluster-data/ts-0-root/wals/edbfeddabe6c4a128a960ecdc25a4583/wal-000000001 (ops 1-6)
I20260812 06:20:19.174172 12316 maintenance_manager.cc:643] P a3ad9850928e41aead46cec7b9db045f: LogGCOp(edbfeddabe6c4a128a960ecdc25a4583) complete. Timing: real 0.005s	user 0.000s	sys 0.002s Metrics: {}
I20260812 06:20:19.174757 12401 maintenance_manager.cc:419] P a3ad9850928e41aead46cec7b9db045f: Scheduling FlushDeltaMemStoresOp(edbfeddabe6c4a128a960ecdc25a4583): perf score=1.196750
I20260812 06:20:19.199452 12316 maintenance_manager.cc:643] P a3ad9850928e41aead46cec7b9db045f: FlushDeltaMemStoresOp(edbfeddabe6c4a128a960ecdc25a4583) complete. Timing: real 0.024s	user 0.009s	sys 0.004s Metrics: {"bytes_written":3159084,"delete_count":0,"lbm_write_time_us":5132,"lbm_writes_lt_1ms":80,"reinsert_count":0,"update_count":385}
I20260812 06:20:19.199937 12401 maintenance_manager.cc:419] P a3ad9850928e41aead46cec7b9db045f: Scheduling UndoDeltaBlockGCOp(edbfeddabe6c4a128a960ecdc25a4583): 12308955 bytes on disk
I20260812 06:20:19.200533 12316 maintenance_manager.cc:643] P a3ad9850928e41aead46cec7b9db045f: UndoDeltaBlockGCOp(edbfeddabe6c4a128a960ecdc25a4583) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":56,"lbm_reads_lt_1ms":4}
I20260812 06:20:19.200954 12401 maintenance_manager.cc:419] P a3ad9850928e41aead46cec7b9db045f: Scheduling FlushDeltaMemStoresOp(edbfeddabe6c4a128a960ecdc25a4583): perf score=2.188937
I20260812 06:20:19.211544 12316 maintenance_manager.cc:643] P a3ad9850928e41aead46cec7b9db045f: FlushDeltaMemStoresOp(edbfeddabe6c4a128a960ecdc25a4583) complete. Timing: real 0.010s	user 0.010s	sys 0.000s Metrics: {"bytes_written":3897534,"delete_count":0,"lbm_write_time_us":3883,"lbm_writes_lt_1ms":98,"reinsert_count":0,"update_count":475}
I20260812 06:20:19.212256 12401 maintenance_manager.cc:419] P a3ad9850928e41aead46cec7b9db045f: Scheduling MajorDeltaCompactionOp(edbfeddabe6c4a128a960ecdc25a4583): perf score=1.000000
I20260812 06:20:19.371290 12316 maintenance_manager.cc:643] P a3ad9850928e41aead46cec7b9db045f: MajorDeltaCompactionOp(edbfeddabe6c4a128a960ecdc25a4583) complete. Timing: real 0.159s	user 0.112s	sys 0.040s Metrics: {"cfile_cache_miss":433,"cfile_cache_miss_bytes":20631410,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":663,"lbm_read_time_us":10251,"lbm_reads_lt_1ms":469,"lbm_write_time_us":28632,"lbm_writes_lt_1ms":443,"peak_mem_usage":50689328,"reinsert_count":0,"thread_start_us":358,"threads_started":5,"update_count":2000}
I20260812 06:20:19.371960 12401 maintenance_manager.cc:419] P a3ad9850928e41aead46cec7b9db045f: Scheduling FlushDeltaMemStoresOp(edbfeddabe6c4a128a960ecdc25a4583): perf score=10.126437
I20260812 06:20:19.425275 12316 maintenance_manager.cc:643] P a3ad9850928e41aead46cec7b9db045f: FlushDeltaMemStoresOp(edbfeddabe6c4a128a960ecdc25a4583) complete. Timing: real 0.053s	user 0.019s	sys 0.021s Metrics: {"bytes_written":12307492,"delete_count":0,"lbm_write_time_us":18850,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:20:19.425854 12401 maintenance_manager.cc:419] P a3ad9850928e41aead46cec7b9db045f: Scheduling FlushDeltaMemStoresOp(edbfeddabe6c4a128a960ecdc25a4583): perf score=2.188937
I20260812 06:20:19.438419 12316 maintenance_manager.cc:643] P a3ad9850928e41aead46cec7b9db045f: FlushDeltaMemStoresOp(edbfeddabe6c4a128a960ecdc25a4583) complete. Timing: real 0.012s	user 0.002s	sys 0.007s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4437,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:19.438952 12401 maintenance_manager.cc:419] P a3ad9850928e41aead46cec7b9db045f: Scheduling MajorDeltaCompactionOp(edbfeddabe6c4a128a960ecdc25a4583): perf score=1.000000
I20260812 06:20:19.574934 12316 maintenance_manager.cc:643] P a3ad9850928e41aead46cec7b9db045f: MajorDeltaCompactionOp(edbfeddabe6c4a128a960ecdc25a4583) complete. Timing: real 0.136s	user 0.100s	sys 0.035s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20631314,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":226,"lbm_read_time_us":10994,"lbm_reads_lt_1ms":472,"lbm_write_time_us":25298,"lbm_writes_lt_1ms":443,"mutex_wait_us":37,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":1920,"update_count":2000}
I20260812 06:20:19.575619 12401 maintenance_manager.cc:419] P a3ad9850928e41aead46cec7b9db045f: Scheduling FlushDeltaMemStoresOp(edbfeddabe6c4a128a960ecdc25a4583): perf score=10.126437
I20260812 06:20:19.628567 12316 maintenance_manager.cc:643] P a3ad9850928e41aead46cec7b9db045f: FlushDeltaMemStoresOp(edbfeddabe6c4a128a960ecdc25a4583) complete. Timing: real 0.053s	user 0.017s	sys 0.031s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":18104,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:20:19.629377 12401 maintenance_manager.cc:419] P a3ad9850928e41aead46cec7b9db045f: Scheduling FlushDeltaMemStoresOp(edbfeddabe6c4a128a960ecdc25a4583): perf score=2.188937
I20260812 06:20:19.641244 12316 maintenance_manager.cc:643] P a3ad9850928e41aead46cec7b9db045f: FlushDeltaMemStoresOp(edbfeddabe6c4a128a960ecdc25a4583) complete. Timing: real 0.012s	user 0.010s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4400,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:19.642030 12401 maintenance_manager.cc:419] P a3ad9850928e41aead46cec7b9db045f: Scheduling MajorDeltaCompactionOp(edbfeddabe6c4a128a960ecdc25a4583): perf score=1.000000
I20260812 06:20:19.814062 12316 maintenance_manager.cc:643] P a3ad9850928e41aead46cec7b9db045f: MajorDeltaCompactionOp(edbfeddabe6c4a128a960ecdc25a4583) complete. Timing: real 0.172s	user 0.120s	sys 0.052s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20631312,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":247,"lbm_read_time_us":13025,"lbm_reads_lt_1ms":472,"lbm_write_time_us":28335,"lbm_writes_lt_1ms":443,"mutex_wait_us":25,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":82304,"update_count":2000}
I20260812 06:20:19.814808 12401 maintenance_manager.cc:419] P a3ad9850928e41aead46cec7b9db045f: Scheduling FlushDeltaMemStoresOp(edbfeddabe6c4a128a960ecdc25a4583): perf score=10.126437
I20260812 06:20:19.864502 12316 maintenance_manager.cc:643] P a3ad9850928e41aead46cec7b9db045f: FlushDeltaMemStoresOp(edbfeddabe6c4a128a960ecdc25a4583) complete. Timing: real 0.049s	user 0.029s	sys 0.009s Metrics: {"bytes_written":12307491,"delete_count":0,"lbm_write_time_us":17612,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:20:19.865139 12401 maintenance_manager.cc:419] P a3ad9850928e41aead46cec7b9db045f: Scheduling FlushDeltaMemStoresOp(edbfeddabe6c4a128a960ecdc25a4583): perf score=2.188937
I20260812 06:20:19.879463 12316 maintenance_manager.cc:643] P a3ad9850928e41aead46cec7b9db045f: FlushDeltaMemStoresOp(edbfeddabe6c4a128a960ecdc25a4583) complete. Timing: real 0.014s	user 0.010s	sys 0.004s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4862,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:19.880146 12401 maintenance_manager.cc:419] P a3ad9850928e41aead46cec7b9db045f: Scheduling MajorDeltaCompactionOp(edbfeddabe6c4a128a960ecdc25a4583): perf score=1.000000
I20260812 06:20:20.032644 12316 maintenance_manager.cc:643] P a3ad9850928e41aead46cec7b9db045f: MajorDeltaCompactionOp(edbfeddabe6c4a128a960ecdc25a4583) complete. Timing: real 0.152s	user 0.120s	sys 0.032s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20631312,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":736,"lbm_read_time_us":11777,"lbm_reads_lt_1ms":472,"lbm_write_time_us":30325,"lbm_writes_lt_1ms":443,"mutex_wait_us":411,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":16768,"update_count":2000}
I20260812 06:20:20.033942 12401 maintenance_manager.cc:419] P a3ad9850928e41aead46cec7b9db045f: Scheduling FlushDeltaMemStoresOp(edbfeddabe6c4a128a960ecdc25a4583): perf score=10.126437
I20260812 06:20:20.078989 12316 maintenance_manager.cc:643] P a3ad9850928e41aead46cec7b9db045f: FlushDeltaMemStoresOp(edbfeddabe6c4a128a960ecdc25a4583) complete. Timing: real 0.045s	user 0.025s	sys 0.019s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":20407,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:20:20.079977 12401 maintenance_manager.cc:419] P a3ad9850928e41aead46cec7b9db045f: Scheduling FlushDeltaMemStoresOp(edbfeddabe6c4a128a960ecdc25a4583): perf score=2.188937
I20260812 06:20:20.096418 12316 maintenance_manager.cc:643] P a3ad9850928e41aead46cec7b9db045f: FlushDeltaMemStoresOp(edbfeddabe6c4a128a960ecdc25a4583) complete. Timing: real 0.016s	user 0.009s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5349,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:20.097357 12401 maintenance_manager.cc:419] P a3ad9850928e41aead46cec7b9db045f: Scheduling MajorDeltaCompactionOp(edbfeddabe6c4a128a960ecdc25a4583): perf score=1.000000
I20260812 06:20:20.235357 12316 maintenance_manager.cc:643] P a3ad9850928e41aead46cec7b9db045f: MajorDeltaCompactionOp(edbfeddabe6c4a128a960ecdc25a4583) complete. Timing: real 0.138s	user 0.110s	sys 0.021s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20631312,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":1116,"lbm_read_time_us":9712,"lbm_reads_lt_1ms":464,"lbm_write_time_us":26507,"lbm_writes_lt_1ms":443,"mutex_wait_us":350,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":1408,"update_count":2000}
I20260812 06:20:20.236167 12401 maintenance_manager.cc:419] P a3ad9850928e41aead46cec7b9db045f: Scheduling FlushDeltaMemStoresOp(edbfeddabe6c4a128a960ecdc25a4583): perf score=11.118625
I20260812 06:20:20.284866 12316 maintenance_manager.cc:643] P a3ad9850928e41aead46cec7b9db045f: FlushDeltaMemStoresOp(edbfeddabe6c4a128a960ecdc25a4583) complete. Timing: real 0.048s	user 0.021s	sys 0.025s Metrics: {"bytes_written":12717734,"delete_count":0,"lbm_write_time_us":20601,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:20:20.285602 12401 maintenance_manager.cc:419] P a3ad9850928e41aead46cec7b9db045f: Scheduling FlushDeltaMemStoresOp(edbfeddabe6c4a128a960ecdc25a4583): perf score=2.188937
I20260812 06:20:20.303177 12316 maintenance_manager.cc:643] P a3ad9850928e41aead46cec7b9db045f: FlushDeltaMemStoresOp(edbfeddabe6c4a128a960ecdc25a4583) complete. Timing: real 0.017s	user 0.012s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4620,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:20.303844 12401 maintenance_manager.cc:419] P a3ad9850928e41aead46cec7b9db045f: Scheduling FlushDeltaMemStoresOp(edbfeddabe6c4a128a960ecdc25a4583): perf score=2.188937
I20260812 06:20:20.315240 12316 maintenance_manager.cc:643] P a3ad9850928e41aead46cec7b9db045f: FlushDeltaMemStoresOp(edbfeddabe6c4a128a960ecdc25a4583) complete. Timing: real 0.011s	user 0.003s	sys 0.007s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":4154,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:20:20.315876 12401 maintenance_manager.cc:419] P a3ad9850928e41aead46cec7b9db045f: Scheduling MajorDeltaCompactionOp(edbfeddabe6c4a128a960ecdc25a4583): perf score=1.000000
I20260812 06:20:20.487314 12316 maintenance_manager.cc:643] P a3ad9850928e41aead46cec7b9db045f: MajorDeltaCompactionOp(edbfeddabe6c4a128a960ecdc25a4583) complete. Timing: real 0.171s	user 0.126s	sys 0.040s Metrics: {"cfile_cache_miss":533,"cfile_cache_miss_bytes":24733833,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":1531,"lbm_read_time_us":13607,"lbm_reads_lt_1ms":573,"lbm_write_time_us":31943,"lbm_writes_lt_1ms":543,"mutex_wait_us":468,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":3840,"update_count":2500}
I20260812 06:20:20.488188 12401 maintenance_manager.cc:419] P a3ad9850928e41aead46cec7b9db045f: Scheduling FlushDeltaMemStoresOp(edbfeddabe6c4a128a960ecdc25a4583): perf score=11.118625
I20260812 06:20:20.533696 12316 maintenance_manager.cc:643] P a3ad9850928e41aead46cec7b9db045f: FlushDeltaMemStoresOp(edbfeddabe6c4a128a960ecdc25a4583) complete. Timing: real 0.045s	user 0.034s	sys 0.008s Metrics: {"bytes_written":13456168,"delete_count":0,"lbm_write_time_us":19229,"lbm_writes_lt_1ms":331,"mutex_wait_us":714,"reinsert_count":0,"update_count":1640}
I20260812 06:20:20.534389 12401 maintenance_manager.cc:419] P a3ad9850928e41aead46cec7b9db045f: Scheduling FlushDeltaMemStoresOp(edbfeddabe6c4a128a960ecdc25a4583): perf score=1.196750
I20260812 06:20:20.551281 12316 maintenance_manager.cc:643] P a3ad9850928e41aead46cec7b9db045f: FlushDeltaMemStoresOp(edbfeddabe6c4a128a960ecdc25a4583) complete. Timing: real 0.017s	user 0.004s	sys 0.007s Metrics: {"bytes_written":2953955,"delete_count":0,"lbm_write_time_us":4181,"lbm_writes_lt_1ms":75,"reinsert_count":0,"update_count":360}
I20260812 06:20:20.552134 12401 maintenance_manager.cc:419] P a3ad9850928e41aead46cec7b9db045f: Scheduling FlushMRSOp(edbfeddabe6c4a128a960ecdc25a4583): perf score=1.000000
I20260812 06:20:20.594605 12316 maintenance_manager.cc:643] P a3ad9850928e41aead46cec7b9db045f: FlushMRSOp(edbfeddabe6c4a128a960ecdc25a4583) complete. Timing: real 0.042s	user 0.029s	sys 0.000s Metrics: {"bytes_written":1234474,"cfile_init":1,"dirs.queue_time_us":62,"dirs.run_cpu_time_us":241,"dirs.run_wall_time_us":1529,"drs_written":1,"lbm_read_time_us":106,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1787,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":30}
I20260812 06:20:20.595831 12401 maintenance_manager.cc:419] P a3ad9850928e41aead46cec7b9db045f: Scheduling UndoDeltaBlockGCOp(edbfeddabe6c4a128a960ecdc25a4583): 473 bytes on disk
I20260812 06:20:20.596372 12316 maintenance_manager.cc:643] P a3ad9850928e41aead46cec7b9db045f: UndoDeltaBlockGCOp(edbfeddabe6c4a128a960ecdc25a4583) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":66,"lbm_reads_lt_1ms":4}
I20260812 06:20:20.597090 12401 maintenance_manager.cc:419] P a3ad9850928e41aead46cec7b9db045f: Scheduling FlushDeltaMemStoresOp(edbfeddabe6c4a128a960ecdc25a4583): perf score=3.181125
I20260812 06:20:20.609552 12316 maintenance_manager.cc:643] P a3ad9850928e41aead46cec7b9db045f: FlushDeltaMemStoresOp(edbfeddabe6c4a128a960ecdc25a4583) complete. Timing: real 0.012s	user 0.007s	sys 0.003s Metrics: {"bytes_written":4512899,"delete_count":0,"lbm_write_time_us":4824,"lbm_writes_lt_1ms":113,"reinsert_count":0,"update_count":550}
I20260812 06:20:20.610177 12401 maintenance_manager.cc:419] P a3ad9850928e41aead46cec7b9db045f: Scheduling LogGCOp(edbfeddabe6c4a128a960ecdc25a4583): free 121459488 bytes of WAL
I20260812 06:20:20.610519 12316 log_reader.cc:385] T edbfeddabe6c4a128a960ecdc25a4583: removed 12 log segments from log reader
I20260812 06:20:20.610607 12316 log.cc:1079] T edbfeddabe6c4a128a960ecdc25a4583 P a3ad9850928e41aead46cec7b9db045f: Deleting log segment in path: /tmp/dist-test-taskHG7JFS/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515618503783-12152-0/minicluster-data/ts-0-root/wals/edbfeddabe6c4a128a960ecdc25a4583/wal-000000002 (ops 7-11)
I20260812 06:20:20.610692 12316 log.cc:1079] T edbfeddabe6c4a128a960ecdc25a4583 P a3ad9850928e41aead46cec7b9db045f: Deleting log segment in path: /tmp/dist-test-taskHG7JFS/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515618503783-12152-0/minicluster-data/ts-0-root/wals/edbfeddabe6c4a128a960ecdc25a4583/wal-000000003 (ops 12-16)
I20260812 06:20:20.610769 12316 log.cc:1079] T edbfeddabe6c4a128a960ecdc25a4583 P a3ad9850928e41aead46cec7b9db045f: Deleting log segment in path: /tmp/dist-test-taskHG7JFS/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515618503783-12152-0/minicluster-data/ts-0-root/wals/edbfeddabe6c4a128a960ecdc25a4583/wal-000000004 (ops 17-21)
I20260812 06:20:20.610821 12316 log.cc:1079] T edbfeddabe6c4a128a960ecdc25a4583 P a3ad9850928e41aead46cec7b9db045f: Deleting log segment in path: /tmp/dist-test-taskHG7JFS/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515618503783-12152-0/minicluster-data/ts-0-root/wals/edbfeddabe6c4a128a960ecdc25a4583/wal-000000005 (ops 22-26)
I20260812 06:20:20.610867 12316 log.cc:1079] T edbfeddabe6c4a128a960ecdc25a4583 P a3ad9850928e41aead46cec7b9db045f: Deleting log segment in path: /tmp/dist-test-taskHG7JFS/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515618503783-12152-0/minicluster-data/ts-0-root/wals/edbfeddabe6c4a128a960ecdc25a4583/wal-000000006 (ops 27-31)
I20260812 06:20:20.610910 12316 log.cc:1079] T edbfeddabe6c4a128a960ecdc25a4583 P a3ad9850928e41aead46cec7b9db045f: Deleting log segment in path: /tmp/dist-test-taskHG7JFS/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515618503783-12152-0/minicluster-data/ts-0-root/wals/edbfeddabe6c4a128a960ecdc25a4583/wal-000000007 (ops 32-36)
I20260812 06:20:20.610954 12316 log.cc:1079] T edbfeddabe6c4a128a960ecdc25a4583 P a3ad9850928e41aead46cec7b9db045f: Deleting log segment in path: /tmp/dist-test-taskHG7JFS/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515618503783-12152-0/minicluster-data/ts-0-root/wals/edbfeddabe6c4a128a960ecdc25a4583/wal-000000008 (ops 37-41)
I20260812 06:20:20.610998 12316 log.cc:1079] T edbfeddabe6c4a128a960ecdc25a4583 P a3ad9850928e41aead46cec7b9db045f: Deleting log segment in path: /tmp/dist-test-taskHG7JFS/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515618503783-12152-0/minicluster-data/ts-0-root/wals/edbfeddabe6c4a128a960ecdc25a4583/wal-000000009 (ops 42-46)
I20260812 06:20:20.611042 12316 log.cc:1079] T edbfeddabe6c4a128a960ecdc25a4583 P a3ad9850928e41aead46cec7b9db045f: Deleting log segment in path: /tmp/dist-test-taskHG7JFS/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515618503783-12152-0/minicluster-data/ts-0-root/wals/edbfeddabe6c4a128a960ecdc25a4583/wal-000000010 (ops 47-51)
I20260812 06:20:20.611088 12316 log.cc:1079] T edbfeddabe6c4a128a960ecdc25a4583 P a3ad9850928e41aead46cec7b9db045f: Deleting log segment in path: /tmp/dist-test-taskHG7JFS/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515618503783-12152-0/minicluster-data/ts-0-root/wals/edbfeddabe6c4a128a960ecdc25a4583/wal-000000011 (ops 52-56)
I20260812 06:20:20.611135 12316 log.cc:1079] T edbfeddabe6c4a128a960ecdc25a4583 P a3ad9850928e41aead46cec7b9db045f: Deleting log segment in path: /tmp/dist-test-taskHG7JFS/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515618503783-12152-0/minicluster-data/ts-0-root/wals/edbfeddabe6c4a128a960ecdc25a4583/wal-000000012 (ops 57-61)
I20260812 06:20:20.611179 12316 log.cc:1079] T edbfeddabe6c4a128a960ecdc25a4583 P a3ad9850928e41aead46cec7b9db045f: Deleting log segment in path: /tmp/dist-test-taskHG7JFS/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515618503783-12152-0/minicluster-data/ts-0-root/wals/edbfeddabe6c4a128a960ecdc25a4583/wal-000000013 (ops 62-66)
I20260812 06:20:20.643179 12316 maintenance_manager.cc:643] P a3ad9850928e41aead46cec7b9db045f: LogGCOp(edbfeddabe6c4a128a960ecdc25a4583) complete. Timing: real 0.033s	user 0.005s	sys 0.027s Metrics: {}
I20260812 06:20:20.643838 12401 maintenance_manager.cc:419] P a3ad9850928e41aead46cec7b9db045f: Scheduling FlushDeltaMemStoresOp(edbfeddabe6c4a128a960ecdc25a4583): perf score=4.173312
I20260812 06:20:20.662438 12316 maintenance_manager.cc:643] P a3ad9850928e41aead46cec7b9db045f: FlushDeltaMemStoresOp(edbfeddabe6c4a128a960ecdc25a4583) complete. Timing: real 0.018s	user 0.012s	sys 0.004s Metrics: {"bytes_written":5907725,"delete_count":0,"lbm_write_time_us":7535,"lbm_writes_lt_1ms":147,"reinsert_count":0,"update_count":720}
I20260812 06:20:20.663146 12401 maintenance_manager.cc:419] P a3ad9850928e41aead46cec7b9db045f: Scheduling LogGCOp(edbfeddabe6c4a128a960ecdc25a4583): free 11564883 bytes of WAL
I20260812 06:20:20.663522 12316 log_reader.cc:385] T edbfeddabe6c4a128a960ecdc25a4583: removed 1 log segments from log reader
I20260812 06:20:20.663602 12316 log.cc:1079] T edbfeddabe6c4a128a960ecdc25a4583 P a3ad9850928e41aead46cec7b9db045f: Deleting log segment in path: /tmp/dist-test-taskHG7JFS/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515618503783-12152-0/minicluster-data/ts-0-root/wals/edbfeddabe6c4a128a960ecdc25a4583/wal-000000014 (ops 67-70)
I20260812 06:20:20.666069 12316 maintenance_manager.cc:643] P a3ad9850928e41aead46cec7b9db045f: LogGCOp(edbfeddabe6c4a128a960ecdc25a4583) complete. Timing: real 0.003s	user 0.000s	sys 0.000s Metrics: {}
I20260812 06:20:20.666839 12401 maintenance_manager.cc:419] P a3ad9850928e41aead46cec7b9db045f: Scheduling FlushDeltaMemStoresOp(edbfeddabe6c4a128a960ecdc25a4583): perf score=1.000000
I20260812 06:20:20.676100 12316 maintenance_manager.cc:643] P a3ad9850928e41aead46cec7b9db045f: FlushDeltaMemStoresOp(edbfeddabe6c4a128a960ecdc25a4583) complete. Timing: real 0.009s	user 0.007s	sys 0.001s Metrics: {"bytes_written":1887302,"delete_count":0,"lbm_write_time_us":2590,"lbm_writes_lt_1ms":49,"reinsert_count":0,"update_count":230}
I20260812 06:20:20.676614 12401 maintenance_manager.cc:419] P a3ad9850928e41aead46cec7b9db045f: Scheduling MajorDeltaCompactionOp(edbfeddabe6c4a128a960ecdc25a4583): perf score=1.000000
I20260812 06:20:20.910229 12316 maintenance_manager.cc:643] P a3ad9850928e41aead46cec7b9db045f: MajorDeltaCompactionOp(edbfeddabe6c4a128a960ecdc25a4583) complete. Timing: real 0.233s	user 0.166s	sys 0.064s Metrics: {"cfile_cache_miss":735,"cfile_cache_miss_bytes":32938823,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":5,"delta_iterators_relevant":5,"dirs.queue_time_us":1095,"lbm_read_time_us":16247,"lbm_reads_lt_1ms":775,"lbm_write_time_us":41178,"lbm_writes_lt_1ms":743,"mutex_wait_us":266,"peak_mem_usage":87969044,"reinsert_count":0,"spinlock_wait_cycles":896,"thread_start_us":92,"threads_started":1,"update_count":3500}
I20260812 06:20:20.910923 12401 maintenance_manager.cc:419] P a3ad9850928e41aead46cec7b9db045f: Scheduling FlushDeltaMemStoresOp(edbfeddabe6c4a128a960ecdc25a4583): perf score=15.087375
I20260812 06:20:20.967098 12316 maintenance_manager.cc:643] P a3ad9850928e41aead46cec7b9db045f: FlushDeltaMemStoresOp(edbfeddabe6c4a128a960ecdc25a4583) complete. Timing: real 0.056s	user 0.028s	sys 0.028s Metrics: {"bytes_written":16820139,"delete_count":0,"lbm_write_time_us":25007,"lbm_writes_lt_1ms":413,"reinsert_count":0,"update_count":2050}
I20260812 06:20:20.967877 12401 maintenance_manager.cc:419] P a3ad9850928e41aead46cec7b9db045f: Scheduling FlushDeltaMemStoresOp(edbfeddabe6c4a128a960ecdc25a4583): perf score=2.188937
I20260812 06:20:20.986586 12316 maintenance_manager.cc:643] P a3ad9850928e41aead46cec7b9db045f: FlushDeltaMemStoresOp(edbfeddabe6c4a128a960ecdc25a4583) complete. Timing: real 0.019s	user 0.005s	sys 0.008s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":5669,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:20:20.987123 12401 maintenance_manager.cc:419] P a3ad9850928e41aead46cec7b9db045f: Scheduling FlushDeltaMemStoresOp(edbfeddabe6c4a128a960ecdc25a4583): perf score=2.188937
I20260812 06:20:20.998189 12316 maintenance_manager.cc:643] P a3ad9850928e41aead46cec7b9db045f: FlushDeltaMemStoresOp(edbfeddabe6c4a128a960ecdc25a4583) complete. Timing: real 0.011s	user 0.001s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4313,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:20.998723 12401 maintenance_manager.cc:419] P a3ad9850928e41aead46cec7b9db045f: Scheduling MajorDeltaCompactionOp(edbfeddabe6c4a128a960ecdc25a4583): perf score=1.000000
I20260812 06:20:21.177471 12316 maintenance_manager.cc:643] P a3ad9850928e41aead46cec7b9db045f: MajorDeltaCompactionOp(edbfeddabe6c4a128a960ecdc25a4583) complete. Timing: real 0.179s	user 0.146s	sys 0.031s Metrics: {"cfile_cache_miss":633,"cfile_cache_miss_bytes":28836238,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":1429,"lbm_read_time_us":13743,"lbm_reads_lt_1ms":673,"lbm_write_time_us":35084,"lbm_writes_lt_1ms":643,"mutex_wait_us":1155,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":19328,"update_count":3000}
I20260812 06:20:21.178166 12401 maintenance_manager.cc:419] P a3ad9850928e41aead46cec7b9db045f: Scheduling FlushDeltaMemStoresOp(edbfeddabe6c4a128a960ecdc25a4583): perf score=14.095187
I20260812 06:20:21.225665 12316 maintenance_manager.cc:643] P a3ad9850928e41aead46cec7b9db045f: FlushDeltaMemStoresOp(edbfeddabe6c4a128a960ecdc25a4583) complete. Timing: real 0.047s	user 0.034s	sys 0.010s Metrics: {"bytes_written":16409904,"delete_count":0,"lbm_write_time_us":20934,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:20:21.226284 12401 maintenance_manager.cc:419] P a3ad9850928e41aead46cec7b9db045f: Scheduling FlushDeltaMemStoresOp(edbfeddabe6c4a128a960ecdc25a4583): perf score=2.188937
I20260812 06:20:21.239096 12316 maintenance_manager.cc:643] P a3ad9850928e41aead46cec7b9db045f: FlushDeltaMemStoresOp(edbfeddabe6c4a128a960ecdc25a4583) complete. Timing: real 0.013s	user 0.012s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4792,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:21.239656 12401 maintenance_manager.cc:419] P a3ad9850928e41aead46cec7b9db045f: Scheduling MajorDeltaCompactionOp(edbfeddabe6c4a128a960ecdc25a4583): perf score=1.000000
I20260812 06:20:21.418177 12316 maintenance_manager.cc:643] P a3ad9850928e41aead46cec7b9db045f: MajorDeltaCompactionOp(edbfeddabe6c4a128a960ecdc25a4583) complete. Timing: real 0.178s	user 0.123s	sys 0.044s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24733726,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":200,"lbm_read_time_us":12840,"lbm_reads_lt_1ms":572,"lbm_write_time_us":30153,"lbm_writes_lt_1ms":543,"mutex_wait_us":24,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":16640,"update_count":2500}
I20260812 06:20:21.419078 12401 maintenance_manager.cc:419] P a3ad9850928e41aead46cec7b9db045f: Scheduling FlushDeltaMemStoresOp(edbfeddabe6c4a128a960ecdc25a4583): perf score=14.095187
I20260812 06:20:21.477674 12316 maintenance_manager.cc:643] P a3ad9850928e41aead46cec7b9db045f: FlushDeltaMemStoresOp(edbfeddabe6c4a128a960ecdc25a4583) complete. Timing: real 0.058s	user 0.022s	sys 0.025s Metrics: {"bytes_written":16409900,"delete_count":0,"lbm_write_time_us":22542,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":402,"reinsert_count":0,"update_count":2000}
I20260812 06:20:21.478269 12401 maintenance_manager.cc:419] P a3ad9850928e41aead46cec7b9db045f: Scheduling MajorDeltaCompactionOp(edbfeddabe6c4a128a960ecdc25a4583): perf score=1.000000
I20260812 06:20:21.644917 12316 maintenance_manager.cc:643] P a3ad9850928e41aead46cec7b9db045f: MajorDeltaCompactionOp(edbfeddabe6c4a128a960ecdc25a4583) complete. Timing: real 0.166s	user 0.121s	sys 0.039s Metrics: {"cfile_cache_miss":431,"cfile_cache_miss_bytes":20631191,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":1,"delta_iterators_relevant":1,"dirs.queue_time_us":355,"lbm_read_time_us":11684,"lbm_reads_lt_1ms":463,"lbm_write_time_us":27629,"lbm_writes_lt_1ms":443,"mutex_wait_us":67,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":1280,"update_count":2000}
I20260812 06:20:21.645702 12401 maintenance_manager.cc:419] P a3ad9850928e41aead46cec7b9db045f: Scheduling FlushDeltaMemStoresOp(edbfeddabe6c4a128a960ecdc25a4583): perf score=14.095187
I20260812 06:20:21.699294 12316 maintenance_manager.cc:643] P a3ad9850928e41aead46cec7b9db045f: FlushDeltaMemStoresOp(edbfeddabe6c4a128a960ecdc25a4583) complete. Timing: real 0.053s	user 0.024s	sys 0.020s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":20081,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:20:21.699821 12401 maintenance_manager.cc:419] P a3ad9850928e41aead46cec7b9db045f: Scheduling FlushDeltaMemStoresOp(edbfeddabe6c4a128a960ecdc25a4583): perf score=2.188937
I20260812 06:20:21.712024 12316 maintenance_manager.cc:643] P a3ad9850928e41aead46cec7b9db045f: FlushDeltaMemStoresOp(edbfeddabe6c4a128a960ecdc25a4583) complete. Timing: real 0.012s	user 0.005s	sys 0.006s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4343,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:21.712570 12401 maintenance_manager.cc:419] P a3ad9850928e41aead46cec7b9db045f: Scheduling MajorDeltaCompactionOp(edbfeddabe6c4a128a960ecdc25a4583): perf score=1.000000
I20260812 06:20:21.904482 12316 maintenance_manager.cc:643] P a3ad9850928e41aead46cec7b9db045f: MajorDeltaCompactionOp(edbfeddabe6c4a128a960ecdc25a4583) complete. Timing: real 0.192s	user 0.119s	sys 0.069s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24733723,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":237,"lbm_read_time_us":12060,"lbm_reads_lt_1ms":572,"lbm_write_time_us":31505,"lbm_writes_lt_1ms":543,"mutex_wait_us":39,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":19840,"update_count":2500}
I20260812 06:20:21.905153 12401 maintenance_manager.cc:419] P a3ad9850928e41aead46cec7b9db045f: Scheduling FlushDeltaMemStoresOp(edbfeddabe6c4a128a960ecdc25a4583): perf score=14.095187
I20260812 06:20:21.954128 12316 maintenance_manager.cc:643] P a3ad9850928e41aead46cec7b9db045f: FlushDeltaMemStoresOp(edbfeddabe6c4a128a960ecdc25a4583) complete. Timing: real 0.049s	user 0.033s	sys 0.012s Metrics: {"bytes_written":16409900,"delete_count":0,"lbm_write_time_us":21122,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:20:21.954918 12401 maintenance_manager.cc:419] P a3ad9850928e41aead46cec7b9db045f: Scheduling FlushDeltaMemStoresOp(edbfeddabe6c4a128a960ecdc25a4583): perf score=2.188937
I20260812 06:20:21.967407 12316 maintenance_manager.cc:643] P a3ad9850928e41aead46cec7b9db045f: FlushDeltaMemStoresOp(edbfeddabe6c4a128a960ecdc25a4583) complete. Timing: real 0.012s	user 0.007s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4540,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:21.969033 12401 maintenance_manager.cc:419] P a3ad9850928e41aead46cec7b9db045f: Scheduling MajorDeltaCompactionOp(edbfeddabe6c4a128a960ecdc25a4583): perf score=1.000000
I20260812 06:20:22.154786 12316 maintenance_manager.cc:643] P a3ad9850928e41aead46cec7b9db045f: MajorDeltaCompactionOp(edbfeddabe6c4a128a960ecdc25a4583) complete. Timing: real 0.186s	user 0.113s	sys 0.059s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24733722,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":649,"lbm_read_time_us":10577,"lbm_reads_lt_1ms":572,"lbm_write_time_us":34271,"lbm_writes_lt_1ms":543,"mutex_wait_us":42,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":12928,"update_count":2500}
I20260812 06:20:22.155418 12401 maintenance_manager.cc:419] P a3ad9850928e41aead46cec7b9db045f: Scheduling FlushDeltaMemStoresOp(edbfeddabe6c4a128a960ecdc25a4583): perf score=14.095187
I20260812 06:20:22.206555 12316 maintenance_manager.cc:643] P a3ad9850928e41aead46cec7b9db045f: FlushDeltaMemStoresOp(edbfeddabe6c4a128a960ecdc25a4583) complete. Timing: real 0.051s	user 0.028s	sys 0.012s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":19064,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:20:22.207283 12401 maintenance_manager.cc:419] P a3ad9850928e41aead46cec7b9db045f: Scheduling FlushDeltaMemStoresOp(edbfeddabe6c4a128a960ecdc25a4583): perf score=2.188937
I20260812 06:20:22.220067 12316 maintenance_manager.cc:643] P a3ad9850928e41aead46cec7b9db045f: FlushDeltaMemStoresOp(edbfeddabe6c4a128a960ecdc25a4583) complete. Timing: real 0.013s	user 0.011s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4518,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:22.220856 12401 maintenance_manager.cc:419] P a3ad9850928e41aead46cec7b9db045f: Scheduling FlushMRSOp(edbfeddabe6c4a128a960ecdc25a4583): perf score=1.000000
I20260812 06:20:22.254908 12316 maintenance_manager.cc:643] P a3ad9850928e41aead46cec7b9db045f: FlushMRSOp(edbfeddabe6c4a128a960ecdc25a4583) complete. Timing: real 0.034s	user 0.030s	sys 0.003s Metrics: {"bytes_written":1316419,"cfile_init":1,"dirs.queue_time_us":68,"dirs.run_cpu_time_us":271,"dirs.run_wall_time_us":1471,"drs_written":1,"lbm_read_time_us":39,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1942,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":32}
I20260812 06:20:22.255683 12401 maintenance_manager.cc:419] P a3ad9850928e41aead46cec7b9db045f: Scheduling LogGCOp(edbfeddabe6c4a128a960ecdc25a4583): free 121006392 bytes of WAL
I20260812 06:20:22.255959 12316 log_reader.cc:385] T edbfeddabe6c4a128a960ecdc25a4583: removed 12 log segments from log reader
I20260812 06:20:22.256006 12316 log.cc:1079] T edbfeddabe6c4a128a960ecdc25a4583 P a3ad9850928e41aead46cec7b9db045f: Deleting log segment in path: /tmp/dist-test-taskHG7JFS/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515618503783-12152-0/minicluster-data/ts-0-root/wals/edbfeddabe6c4a128a960ecdc25a4583/wal-000000015 (ops 71-75)
I20260812 06:20:22.256057 12316 log.cc:1079] T edbfeddabe6c4a128a960ecdc25a4583 P a3ad9850928e41aead46cec7b9db045f: Deleting log segment in path: /tmp/dist-test-taskHG7JFS/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515618503783-12152-0/minicluster-data/ts-0-root/wals/edbfeddabe6c4a128a960ecdc25a4583/wal-000000016 (ops 76-80)
I20260812 06:20:22.256101 12316 log.cc:1079] T edbfeddabe6c4a128a960ecdc25a4583 P a3ad9850928e41aead46cec7b9db045f: Deleting log segment in path: /tmp/dist-test-taskHG7JFS/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515618503783-12152-0/minicluster-data/ts-0-root/wals/edbfeddabe6c4a128a960ecdc25a4583/wal-000000017 (ops 81-84)
I20260812 06:20:22.256168 12316 log.cc:1079] T edbfeddabe6c4a128a960ecdc25a4583 P a3ad9850928e41aead46cec7b9db045f: Deleting log segment in path: /tmp/dist-test-taskHG7JFS/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515618503783-12152-0/minicluster-data/ts-0-root/wals/edbfeddabe6c4a128a960ecdc25a4583/wal-000000018 (ops 85-89)
I20260812 06:20:22.256232 12316 log.cc:1079] T edbfeddabe6c4a128a960ecdc25a4583 P a3ad9850928e41aead46cec7b9db045f: Deleting log segment in path: /tmp/dist-test-taskHG7JFS/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515618503783-12152-0/minicluster-data/ts-0-root/wals/edbfeddabe6c4a128a960ecdc25a4583/wal-000000019 (ops 90-94)
I20260812 06:20:22.256270 12316 log.cc:1079] T edbfeddabe6c4a128a960ecdc25a4583 P a3ad9850928e41aead46cec7b9db045f: Deleting log segment in path: /tmp/dist-test-taskHG7JFS/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515618503783-12152-0/minicluster-data/ts-0-root/wals/edbfeddabe6c4a128a960ecdc25a4583/wal-000000020 (ops 95-99)
I20260812 06:20:22.256314 12316 log.cc:1079] T edbfeddabe6c4a128a960ecdc25a4583 P a3ad9850928e41aead46cec7b9db045f: Deleting log segment in path: /tmp/dist-test-taskHG7JFS/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515618503783-12152-0/minicluster-data/ts-0-root/wals/edbfeddabe6c4a128a960ecdc25a4583/wal-000000021 (ops 100-104)
I20260812 06:20:22.256357 12316 log.cc:1079] T edbfeddabe6c4a128a960ecdc25a4583 P a3ad9850928e41aead46cec7b9db045f: Deleting log segment in path: /tmp/dist-test-taskHG7JFS/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515618503783-12152-0/minicluster-data/ts-0-root/wals/edbfeddabe6c4a128a960ecdc25a4583/wal-000000022 (ops 105-109)
I20260812 06:20:22.256397 12316 log.cc:1079] T edbfeddabe6c4a128a960ecdc25a4583 P a3ad9850928e41aead46cec7b9db045f: Deleting log segment in path: /tmp/dist-test-taskHG7JFS/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515618503783-12152-0/minicluster-data/ts-0-root/wals/edbfeddabe6c4a128a960ecdc25a4583/wal-000000023 (ops 110-114)
I20260812 06:20:22.256435 12316 log.cc:1079] T edbfeddabe6c4a128a960ecdc25a4583 P a3ad9850928e41aead46cec7b9db045f: Deleting log segment in path: /tmp/dist-test-taskHG7JFS/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515618503783-12152-0/minicluster-data/ts-0-root/wals/edbfeddabe6c4a128a960ecdc25a4583/wal-000000024 (ops 115-119)
I20260812 06:20:22.256474 12316 log.cc:1079] T edbfeddabe6c4a128a960ecdc25a4583 P a3ad9850928e41aead46cec7b9db045f: Deleting log segment in path: /tmp/dist-test-taskHG7JFS/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515618503783-12152-0/minicluster-data/ts-0-root/wals/edbfeddabe6c4a128a960ecdc25a4583/wal-000000025 (ops 120-124)
I20260812 06:20:22.256515 12316 log.cc:1079] T edbfeddabe6c4a128a960ecdc25a4583 P a3ad9850928e41aead46cec7b9db045f: Deleting log segment in path: /tmp/dist-test-taskHG7JFS/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515618503783-12152-0/minicluster-data/ts-0-root/wals/edbfeddabe6c4a128a960ecdc25a4583/wal-000000026 (ops 125-129)
I20260812 06:20:22.284970 12316 maintenance_manager.cc:643] P a3ad9850928e41aead46cec7b9db045f: LogGCOp(edbfeddabe6c4a128a960ecdc25a4583) complete. Timing: real 0.029s	user 0.000s	sys 0.027s Metrics: {}
I20260812 06:20:22.285485 12401 maintenance_manager.cc:419] P a3ad9850928e41aead46cec7b9db045f: Scheduling FlushDeltaMemStoresOp(edbfeddabe6c4a128a960ecdc25a4583): perf score=3.181125
I20260812 06:20:22.316980 12316 maintenance_manager.cc:643] P a3ad9850928e41aead46cec7b9db045f: FlushDeltaMemStoresOp(edbfeddabe6c4a128a960ecdc25a4583) complete. Timing: real 0.031s	user 0.010s	sys 0.019s Metrics: {"bytes_written":4882122,"delete_count":0,"lbm_write_time_us":7604,"lbm_writes_lt_1ms":122,"reinsert_count":0,"update_count":595}
I20260812 06:20:22.317749 12401 maintenance_manager.cc:419] P a3ad9850928e41aead46cec7b9db045f: Scheduling LogGCOp(edbfeddabe6c4a128a960ecdc25a4583): free 12018006 bytes of WAL
I20260812 06:20:22.318063 12316 log_reader.cc:385] T edbfeddabe6c4a128a960ecdc25a4583: removed 1 log segments from log reader
I20260812 06:20:22.318133 12316 log.cc:1079] T edbfeddabe6c4a128a960ecdc25a4583 P a3ad9850928e41aead46cec7b9db045f: Deleting log segment in path: /tmp/dist-test-taskHG7JFS/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515618503783-12152-0/minicluster-data/ts-0-root/wals/edbfeddabe6c4a128a960ecdc25a4583/wal-000000027 (ops 130-134)
I20260812 06:20:22.321362 12316 maintenance_manager.cc:643] P a3ad9850928e41aead46cec7b9db045f: LogGCOp(edbfeddabe6c4a128a960ecdc25a4583) complete. Timing: real 0.003s	user 0.000s	sys 0.001s Metrics: {}
I20260812 06:20:22.321834 12401 maintenance_manager.cc:419] P a3ad9850928e41aead46cec7b9db045f: Scheduling UndoDeltaBlockGCOp(edbfeddabe6c4a128a960ecdc25a4583): 491 bytes on disk
I20260812 06:20:22.322546 12316 maintenance_manager.cc:643] P a3ad9850928e41aead46cec7b9db045f: UndoDeltaBlockGCOp(edbfeddabe6c4a128a960ecdc25a4583) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":98,"lbm_reads_lt_1ms":4}
I20260812 06:20:22.323190 12401 maintenance_manager.cc:419] P a3ad9850928e41aead46cec7b9db045f: Scheduling FlushDeltaMemStoresOp(edbfeddabe6c4a128a960ecdc25a4583): perf score=2.188937
I20260812 06:20:22.333067 12316 maintenance_manager.cc:643] P a3ad9850928e41aead46cec7b9db045f: FlushDeltaMemStoresOp(edbfeddabe6c4a128a960ecdc25a4583) complete. Timing: real 0.010s	user 0.008s	sys 0.000s Metrics: {"bytes_written":3323180,"delete_count":0,"lbm_write_time_us":3624,"lbm_writes_lt_1ms":84,"reinsert_count":0,"update_count":405}
I20260812 06:20:22.333571 12401 maintenance_manager.cc:419] P a3ad9850928e41aead46cec7b9db045f: Scheduling MajorDeltaCompactionOp(edbfeddabe6c4a128a960ecdc25a4583): perf score=1.000000
I20260812 06:20:22.584179 12316 maintenance_manager.cc:643] P a3ad9850928e41aead46cec7b9db045f: MajorDeltaCompactionOp(edbfeddabe6c4a128a960ecdc25a4583) complete. Timing: real 0.250s	user 0.159s	sys 0.088s Metrics: {"cfile_cache_miss":734,"cfile_cache_miss_bytes":32938769,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":948,"lbm_read_time_us":18670,"lbm_reads_lt_1ms":774,"lbm_write_time_us":40810,"lbm_writes_lt_1ms":743,"mutex_wait_us":330,"peak_mem_usage":87969044,"reinsert_count":0,"spinlock_wait_cycles":18432,"thread_start_us":92,"threads_started":1,"update_count":3500}
I20260812 06:20:22.585089 12401 maintenance_manager.cc:419] P a3ad9850928e41aead46cec7b9db045f: Scheduling FlushDeltaMemStoresOp(edbfeddabe6c4a128a960ecdc25a4583): perf score=15.087375
I20260812 06:20:22.652163 12316 maintenance_manager.cc:643] P a3ad9850928e41aead46cec7b9db045f: FlushDeltaMemStoresOp(edbfeddabe6c4a128a960ecdc25a4583) complete. Timing: real 0.067s	user 0.027s	sys 0.036s Metrics: {"bytes_written":16820144,"delete_count":0,"lbm_write_time_us":29709,"lbm_writes_1-10_ms":2,"lbm_writes_lt_1ms":411,"reinsert_count":0,"update_count":2050}
I20260812 06:20:22.652734 12401 maintenance_manager.cc:419] P a3ad9850928e41aead46cec7b9db045f: Scheduling FlushDeltaMemStoresOp(edbfeddabe6c4a128a960ecdc25a4583): perf score=2.188937
I20260812 06:20:22.664146 12316 maintenance_manager.cc:643] P a3ad9850928e41aead46cec7b9db045f: FlushDeltaMemStoresOp(edbfeddabe6c4a128a960ecdc25a4583) complete. Timing: real 0.011s	user 0.005s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4212,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:22.664677 12401 maintenance_manager.cc:419] P a3ad9850928e41aead46cec7b9db045f: Scheduling FlushDeltaMemStoresOp(edbfeddabe6c4a128a960ecdc25a4583): perf score=2.188937
I20260812 06:20:22.675490 12316 maintenance_manager.cc:643] P a3ad9850928e41aead46cec7b9db045f: FlushDeltaMemStoresOp(edbfeddabe6c4a128a960ecdc25a4583) complete. Timing: real 0.011s	user 0.002s	sys 0.008s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":4118,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:20:22.676034 12401 maintenance_manager.cc:419] P a3ad9850928e41aead46cec7b9db045f: Scheduling MajorDeltaCompactionOp(edbfeddabe6c4a128a960ecdc25a4583): perf score=1.000000
I20260812 06:20:22.894141 12316 maintenance_manager.cc:643] P a3ad9850928e41aead46cec7b9db045f: MajorDeltaCompactionOp(edbfeddabe6c4a128a960ecdc25a4583) complete. Timing: real 0.218s	user 0.150s	sys 0.064s Metrics: {"cfile_cache_miss":633,"cfile_cache_miss_bytes":28836243,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":350,"lbm_read_time_us":15630,"lbm_reads_lt_1ms":673,"lbm_write_time_us":36464,"lbm_writes_lt_1ms":643,"mutex_wait_us":45,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":12416,"update_count":3000}
I20260812 06:20:22.894996 12401 maintenance_manager.cc:419] P a3ad9850928e41aead46cec7b9db045f: Scheduling FlushDeltaMemStoresOp(edbfeddabe6c4a128a960ecdc25a4583): perf score=16.079562
I20260812 06:20:22.943782 12316 maintenance_manager.cc:643] P a3ad9850928e41aead46cec7b9db045f: FlushDeltaMemStoresOp(edbfeddabe6c4a128a960ecdc25a4583) complete. Timing: real 0.048s	user 0.027s	sys 0.020s Metrics: {"bytes_written":17681651,"delete_count":0,"lbm_write_time_us":22356,"lbm_writes_lt_1ms":434,"reinsert_count":0,"update_count":2155}
I20260812 06:20:22.944610 12401 maintenance_manager.cc:419] P a3ad9850928e41aead46cec7b9db045f: Scheduling FlushDeltaMemStoresOp(edbfeddabe6c4a128a960ecdc25a4583): perf score=1.196750
I20260812 06:20:22.971673 12316 maintenance_manager.cc:643] P a3ad9850928e41aead46cec7b9db045f: FlushDeltaMemStoresOp(edbfeddabe6c4a128a960ecdc25a4583) complete. Timing: real 0.027s	user 0.002s	sys 0.012s Metrics: {"bytes_written":2830880,"delete_count":0,"lbm_write_time_us":5590,"lbm_writes_lt_1ms":72,"reinsert_count":0,"update_count":345}
I20260812 06:20:22.972235 12401 maintenance_manager.cc:419] P a3ad9850928e41aead46cec7b9db045f: Scheduling FlushDeltaMemStoresOp(edbfeddabe6c4a128a960ecdc25a4583): perf score=2.188937
I20260812 06:20:22.983558 12316 maintenance_manager.cc:643] P a3ad9850928e41aead46cec7b9db045f: FlushDeltaMemStoresOp(edbfeddabe6c4a128a960ecdc25a4583) complete. Timing: real 0.011s	user 0.009s	sys 0.001s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4234,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:22.984141 12401 maintenance_manager.cc:419] P a3ad9850928e41aead46cec7b9db045f: Scheduling MajorDeltaCompactionOp(edbfeddabe6c4a128a960ecdc25a4583): perf score=1.000000
I20260812 06:20:23.229218 12316 maintenance_manager.cc:643] P a3ad9850928e41aead46cec7b9db045f: MajorDeltaCompactionOp(edbfeddabe6c4a128a960ecdc25a4583) complete. Timing: real 0.245s	user 0.162s	sys 0.068s Metrics: {"cfile_cache_miss":633,"cfile_cache_miss_bytes":28836225,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":240,"lbm_read_time_us":14877,"lbm_reads_lt_1ms":673,"lbm_write_time_us":35950,"lbm_writes_lt_1ms":643,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":1280,"update_count":3000}
I20260812 06:20:23.230093 12401 maintenance_manager.cc:419] P a3ad9850928e41aead46cec7b9db045f: Scheduling FlushDeltaMemStoresOp(edbfeddabe6c4a128a960ecdc25a4583): perf score=18.063937
I20260812 06:20:23.315883 12316 maintenance_manager.cc:643] P a3ad9850928e41aead46cec7b9db045f: FlushDeltaMemStoresOp(edbfeddabe6c4a128a960ecdc25a4583) complete. Timing: real 0.085s	user 0.058s	sys 0.011s Metrics: {"bytes_written":20512320,"delete_count":0,"lbm_write_time_us":35997,"lbm_writes_1-10_ms":2,"lbm_writes_lt_1ms":501,"reinsert_count":0,"update_count":2500}
I20260812 06:20:23.316766 12401 maintenance_manager.cc:419] P a3ad9850928e41aead46cec7b9db045f: Scheduling FlushDeltaMemStoresOp(edbfeddabe6c4a128a960ecdc25a4583): perf score=2.188937
I20260812 06:20:23.328692 12316 maintenance_manager.cc:643] P a3ad9850928e41aead46cec7b9db045f: FlushDeltaMemStoresOp(edbfeddabe6c4a128a960ecdc25a4583) complete. Timing: real 0.012s	user 0.005s	sys 0.005s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4444,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:23.329279 12401 maintenance_manager.cc:419] P a3ad9850928e41aead46cec7b9db045f: Scheduling MajorDeltaCompactionOp(edbfeddabe6c4a128a960ecdc25a4583): perf score=1.000000
I20260812 06:20:23.547454 12316 maintenance_manager.cc:643] P a3ad9850928e41aead46cec7b9db045f: MajorDeltaCompactionOp(edbfeddabe6c4a128a960ecdc25a4583) complete. Timing: real 0.218s	user 0.154s	sys 0.063s Metrics: {"cfile_cache_miss":632,"cfile_cache_miss_bytes":28836142,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":336,"lbm_read_time_us":14755,"lbm_reads_lt_1ms":672,"lbm_write_time_us":35947,"lbm_writes_lt_1ms":643,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":2304,"update_count":3000}
I20260812 06:20:23.548738 12401 maintenance_manager.cc:419] P a3ad9850928e41aead46cec7b9db045f: Scheduling FlushDeltaMemStoresOp(edbfeddabe6c4a128a960ecdc25a4583): perf score=14.095187
I20260812 06:20:23.607631 12316 maintenance_manager.cc:643] P a3ad9850928e41aead46cec7b9db045f: FlushDeltaMemStoresOp(edbfeddabe6c4a128a960ecdc25a4583) complete. Timing: real 0.059s	user 0.043s	sys 0.012s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":25098,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:20:23.608242 12401 maintenance_manager.cc:419] P a3ad9850928e41aead46cec7b9db045f: Scheduling MajorDeltaCompactionOp(edbfeddabe6c4a128a960ecdc25a4583): perf score=1.000000
I20260812 06:20:23.761444 12316 maintenance_manager.cc:643] P a3ad9850928e41aead46cec7b9db045f: MajorDeltaCompactionOp(edbfeddabe6c4a128a960ecdc25a4583) complete. Timing: real 0.153s	user 0.092s	sys 0.057s Metrics: {"cfile_cache_miss":431,"cfile_cache_miss_bytes":20631192,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":1,"delta_iterators_relevant":1,"dirs.queue_time_us":646,"lbm_read_time_us":10824,"lbm_reads_lt_1ms":463,"lbm_write_time_us":25507,"lbm_writes_lt_1ms":443,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":768,"update_count":2000}
I20260812 06:20:23.762394 12401 maintenance_manager.cc:419] P a3ad9850928e41aead46cec7b9db045f: Scheduling FlushDeltaMemStoresOp(edbfeddabe6c4a128a960ecdc25a4583): perf score=11.118625
I20260812 06:20:23.796160 12316 maintenance_manager.cc:643] P a3ad9850928e41aead46cec7b9db045f: FlushDeltaMemStoresOp(edbfeddabe6c4a128a960ecdc25a4583) complete. Timing: real 0.034s	user 0.021s	sys 0.011s Metrics: {"bytes_written":12717737,"delete_count":0,"lbm_write_time_us":14160,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:20:23.796710 12401 maintenance_manager.cc:419] P a3ad9850928e41aead46cec7b9db045f: Scheduling FlushDeltaMemStoresOp(edbfeddabe6c4a128a960ecdc25a4583): perf score=2.188937
I20260812 06:20:23.815413 12316 maintenance_manager.cc:643] P a3ad9850928e41aead46cec7b9db045f: FlushDeltaMemStoresOp(edbfeddabe6c4a128a960ecdc25a4583) complete. Timing: real 0.018s	user 0.006s	sys 0.004s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":4251,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:20:23.816226 12401 maintenance_manager.cc:419] P a3ad9850928e41aead46cec7b9db045f: Scheduling FlushMRSOp(edbfeddabe6c4a128a960ecdc25a4583): perf score=1.000000
I20260812 06:20:23.860767 12316 maintenance_manager.cc:643] P a3ad9850928e41aead46cec7b9db045f: FlushMRSOp(edbfeddabe6c4a128a960ecdc25a4583) complete. Timing: real 0.044s	user 0.024s	sys 0.003s Metrics: {"bytes_written":1193507,"cfile_init":1,"dirs.queue_time_us":84,"dirs.run_cpu_time_us":315,"dirs.run_wall_time_us":1470,"drs_written":1,"lbm_read_time_us":68,"lbm_reads_lt_1ms":4,"lbm_write_time_us":2280,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":29}
I20260812 06:20:23.861727 12401 maintenance_manager.cc:419] P a3ad9850928e41aead46cec7b9db045f: Scheduling FlushDeltaMemStoresOp(edbfeddabe6c4a128a960ecdc25a4583): perf score=3.181125
I20260812 06:20:23.884941 12316 maintenance_manager.cc:643] P a3ad9850928e41aead46cec7b9db045f: FlushDeltaMemStoresOp(edbfeddabe6c4a128a960ecdc25a4583) complete. Timing: real 0.023s	user 0.008s	sys 0.004s Metrics: {"bytes_written":4512900,"delete_count":0,"lbm_write_time_us":4310,"lbm_writes_lt_1ms":113,"reinsert_count":0,"update_count":550}
I20260812 06:20:23.885674 12401 maintenance_manager.cc:419] P a3ad9850928e41aead46cec7b9db045f: Scheduling LogGCOp(edbfeddabe6c4a128a960ecdc25a4583): free 112239570 bytes of WAL
I20260812 06:20:23.885955 12316 log_reader.cc:385] T edbfeddabe6c4a128a960ecdc25a4583: removed 11 log segments from log reader
I20260812 06:20:23.886027 12316 log.cc:1079] T edbfeddabe6c4a128a960ecdc25a4583 P a3ad9850928e41aead46cec7b9db045f: Deleting log segment in path: /tmp/dist-test-taskHG7JFS/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515618503783-12152-0/minicluster-data/ts-0-root/wals/edbfeddabe6c4a128a960ecdc25a4583/wal-000000028 (ops 135-139)
I20260812 06:20:23.886082 12316 log.cc:1079] T edbfeddabe6c4a128a960ecdc25a4583 P a3ad9850928e41aead46cec7b9db045f: Deleting log segment in path: /tmp/dist-test-taskHG7JFS/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515618503783-12152-0/minicluster-data/ts-0-root/wals/edbfeddabe6c4a128a960ecdc25a4583/wal-000000029 (ops 140-144)
I20260812 06:20:23.886140 12316 log.cc:1079] T edbfeddabe6c4a128a960ecdc25a4583 P a3ad9850928e41aead46cec7b9db045f: Deleting log segment in path: /tmp/dist-test-taskHG7JFS/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515618503783-12152-0/minicluster-data/ts-0-root/wals/edbfeddabe6c4a128a960ecdc25a4583/wal-000000030 (ops 145-149)
I20260812 06:20:23.886184 12316 log.cc:1079] T edbfeddabe6c4a128a960ecdc25a4583 P a3ad9850928e41aead46cec7b9db045f: Deleting log segment in path: /tmp/dist-test-taskHG7JFS/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515618503783-12152-0/minicluster-data/ts-0-root/wals/edbfeddabe6c4a128a960ecdc25a4583/wal-000000031 (ops 150-154)
I20260812 06:20:23.886224 12316 log.cc:1079] T edbfeddabe6c4a128a960ecdc25a4583 P a3ad9850928e41aead46cec7b9db045f: Deleting log segment in path: /tmp/dist-test-taskHG7JFS/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515618503783-12152-0/minicluster-data/ts-0-root/wals/edbfeddabe6c4a128a960ecdc25a4583/wal-000000032 (ops 155-158)
I20260812 06:20:23.886263 12316 log.cc:1079] T edbfeddabe6c4a128a960ecdc25a4583 P a3ad9850928e41aead46cec7b9db045f: Deleting log segment in path: /tmp/dist-test-taskHG7JFS/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515618503783-12152-0/minicluster-data/ts-0-root/wals/edbfeddabe6c4a128a960ecdc25a4583/wal-000000033 (ops 159-163)
I20260812 06:20:23.886309 12316 log.cc:1079] T edbfeddabe6c4a128a960ecdc25a4583 P a3ad9850928e41aead46cec7b9db045f: Deleting log segment in path: /tmp/dist-test-taskHG7JFS/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515618503783-12152-0/minicluster-data/ts-0-root/wals/edbfeddabe6c4a128a960ecdc25a4583/wal-000000034 (ops 164-168)
I20260812 06:20:23.886353 12316 log.cc:1079] T edbfeddabe6c4a128a960ecdc25a4583 P a3ad9850928e41aead46cec7b9db045f: Deleting log segment in path: /tmp/dist-test-taskHG7JFS/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515618503783-12152-0/minicluster-data/ts-0-root/wals/edbfeddabe6c4a128a960ecdc25a4583/wal-000000035 (ops 169-173)
I20260812 06:20:23.886389 12316 log.cc:1079] T edbfeddabe6c4a128a960ecdc25a4583 P a3ad9850928e41aead46cec7b9db045f: Deleting log segment in path: /tmp/dist-test-taskHG7JFS/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515618503783-12152-0/minicluster-data/ts-0-root/wals/edbfeddabe6c4a128a960ecdc25a4583/wal-000000036 (ops 174-178)
I20260812 06:20:23.886426 12316 log.cc:1079] T edbfeddabe6c4a128a960ecdc25a4583 P a3ad9850928e41aead46cec7b9db045f: Deleting log segment in path: /tmp/dist-test-taskHG7JFS/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515618503783-12152-0/minicluster-data/ts-0-root/wals/edbfeddabe6c4a128a960ecdc25a4583/wal-000000037 (ops 179-183)
I20260812 06:20:23.886463 12316 log.cc:1079] T edbfeddabe6c4a128a960ecdc25a4583 P a3ad9850928e41aead46cec7b9db045f: Deleting log segment in path: /tmp/dist-test-taskHG7JFS/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515618503783-12152-0/minicluster-data/ts-0-root/wals/edbfeddabe6c4a128a960ecdc25a4583/wal-000000038 (ops 184-188)
I20260812 06:20:23.911945 12316 maintenance_manager.cc:643] P a3ad9850928e41aead46cec7b9db045f: LogGCOp(edbfeddabe6c4a128a960ecdc25a4583) complete. Timing: real 0.026s	user 0.000s	sys 0.025s Metrics: {}
I20260812 06:20:23.912523 12401 maintenance_manager.cc:419] P a3ad9850928e41aead46cec7b9db045f: Scheduling UndoDeltaBlockGCOp(edbfeddabe6c4a128a960ecdc25a4583): 463 bytes on disk
I20260812 06:20:23.913092 12316 maintenance_manager.cc:643] P a3ad9850928e41aead46cec7b9db045f: UndoDeltaBlockGCOp(edbfeddabe6c4a128a960ecdc25a4583) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":61,"lbm_reads_lt_1ms":4}
I20260812 06:20:23.913693 12401 maintenance_manager.cc:419] P a3ad9850928e41aead46cec7b9db045f: Scheduling FlushDeltaMemStoresOp(edbfeddabe6c4a128a960ecdc25a4583): perf score=2.188937
I20260812 06:20:23.935681 12316 maintenance_manager.cc:643] P a3ad9850928e41aead46cec7b9db045f: FlushDeltaMemStoresOp(edbfeddabe6c4a128a960ecdc25a4583) complete. Timing: real 0.022s	user 0.006s	sys 0.005s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4687,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:23.936304 12401 maintenance_manager.cc:419] P a3ad9850928e41aead46cec7b9db045f: Scheduling FlushDeltaMemStoresOp(edbfeddabe6c4a128a960ecdc25a4583): perf score=2.188937
I20260812 06:20:23.946727 12316 maintenance_manager.cc:643] P a3ad9850928e41aead46cec7b9db045f: FlushDeltaMemStoresOp(edbfeddabe6c4a128a960ecdc25a4583) complete. Timing: real 0.010s	user 0.009s	sys 0.001s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3818,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:20:23.947377 12401 maintenance_manager.cc:419] P a3ad9850928e41aead46cec7b9db045f: Scheduling MajorDeltaCompactionOp(edbfeddabe6c4a128a960ecdc25a4583): perf score=1.000000
I20260812 06:20:24.150461 12152 heavy-update-compaction-itest.cc:229] Time spent updating: real 5.268s	user 1.918s	sys 0.143s
I20260812 06:20:24.186096 12316 maintenance_manager.cc:643] P a3ad9850928e41aead46cec7b9db045f: MajorDeltaCompactionOp(edbfeddabe6c4a128a960ecdc25a4583) complete. Timing: real 0.239s	user 0.154s	sys 0.081s Metrics: {"cfile_cache_miss":735,"cfile_cache_miss_bytes":32938885,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":5,"delta_iterators_relevant":5,"lbm_read_time_us":17268,"lbm_reads_lt_1ms":771,"lbm_write_time_us":42721,"lbm_writes_lt_1ms":743,"peak_mem_usage":87969044,"reinsert_count":0,"update_count":3500}
I20260812 06:20:24.186779 12401 maintenance_manager.cc:419] P a3ad9850928e41aead46cec7b9db045f: Scheduling FlushDeltaMemStoresOp(edbfeddabe6c4a128a960ecdc25a4583): perf score=14.095187
I20260812 06:20:24.221402 12316 maintenance_manager.cc:643] P a3ad9850928e41aead46cec7b9db045f: FlushDeltaMemStoresOp(edbfeddabe6c4a128a960ecdc25a4583) complete. Timing: real 0.034s	user 0.022s	sys 0.013s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":16858,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:20:24.222023 12401 maintenance_manager.cc:419] P a3ad9850928e41aead46cec7b9db045f: Scheduling MajorDeltaCompactionOp(edbfeddabe6c4a128a960ecdc25a4583): perf score=1.000000
I20260812 06:20:24.260224 12152 heavy-update-compaction-itest.cc:265] Time spent scanning: real 0.109s	user 0.002s	sys 0.000s
I20260812 06:20:24.260977 12152 tablet_server.cc:179] TabletServer@127.11.222.1:0 shutting down...
I20260812 06:20:24.361367 12316 maintenance_manager.cc:643] P a3ad9850928e41aead46cec7b9db045f: MajorDeltaCompactionOp(edbfeddabe6c4a128a960ecdc25a4583) complete. Timing: real 0.139s	user 0.107s	sys 0.032s Metrics: {"cfile_cache_miss":431,"cfile_cache_miss_bytes":20631192,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":1,"delta_iterators_relevant":1,"dirs.queue_time_us":326,"lbm_read_time_us":12141,"lbm_reads_lt_1ms":467,"lbm_write_time_us":31073,"lbm_writes_1-10_ms":2,"lbm_writes_lt_1ms":441,"mutex_wait_us":26,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":102144,"update_count":2000}
I20260812 06:20:24.362254 12152 ts_tablet_manager.cc:1507] Shutting down tablet manager...
I20260812 06:20:24.362803 12152 tablet_replica.cc:333] T edbfeddabe6c4a128a960ecdc25a4583 P a3ad9850928e41aead46cec7b9db045f: stopping tablet replica
I20260812 06:20:24.363071 12152 raft_consensus.cc:2243] T edbfeddabe6c4a128a960ecdc25a4583 P a3ad9850928e41aead46cec7b9db045f [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:20:24.363335 12152 raft_consensus.cc:2272] T edbfeddabe6c4a128a960ecdc25a4583 P a3ad9850928e41aead46cec7b9db045f [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:20:24.380184 12152 tablet_server.cc:196] TabletServer@127.11.222.1:0 shutdown complete.
I20260812 06:20:24.402735 12152 master.cc:562] Master@127.11.222.62:41993 shutting down...
I20260812 06:20:24.406711 12152 raft_consensus.cc:2243] T 00000000000000000000000000000000 P ff8b25039ca74d5c942d331e28c4de90 [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:20:24.406926 12152 raft_consensus.cc:2272] T 00000000000000000000000000000000 P ff8b25039ca74d5c942d331e28c4de90 [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:20:24.406991 12152 tablet_replica.cc:333] T 00000000000000000000000000000000 P ff8b25039ca74d5c942d331e28c4de90: stopping tablet replica
I20260812 06:20:24.419849 12152 master.cc:584] Master@127.11.222.62:41993 shutdown complete.
[       OK ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/0 (6004 ms)
[ RUN      ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/1
I20260812 06:20:24.521220 12152 internal_mini_cluster.cc:156] Creating distributed mini masters. Addrs: 127.11.222.62:45921
I20260812 06:20:24.521631 12152 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:20:24.523757 12448 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:20:24.523914 12152 server_base.cc:1061] running on GCE node
W20260812 06:20:24.523871 12450 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:20:24.523842 12452 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:20:24.524331 12152 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:20:24.524417 12152 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:20:24.524446 12152 hybrid_clock.cc:648] HybridClock initialized: now 1786515624524445 us; error 0 us; skew 500 ppm
I20260812 06:20:24.525375 12152 webserver.cc:533] Webserver started at http://127.11.222.62:33649/ using document root <none> and password file <none>
I20260812 06:20:24.525523 12152 fs_manager.cc:362] Metadata directory not provided
I20260812 06:20:24.525568 12152 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:20:24.525624 12152 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:20:24.526002 12152 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskHG7JFS/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515618503783-12152-0/minicluster-data/master-0-root/instance:
uuid: "b67b75bb4312498d903b75559f7c8b57"
format_stamp: "Formatted at 2026-08-12 06:20:24 on dist-test-slave-3kk6"
I20260812 06:20:24.527863 12152 fs_manager.cc:696] Time spent creating directory manager: real 0.002s	user 0.000s	sys 0.002s
I20260812 06:20:24.528821 12460 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:20:24.529132 12152 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.001s	sys 0.000s
I20260812 06:20:24.529206 12152 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskHG7JFS/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515618503783-12152-0/minicluster-data/master-0-root
uuid: "b67b75bb4312498d903b75559f7c8b57"
format_stamp: "Formatted at 2026-08-12 06:20:24 on dist-test-slave-3kk6"
I20260812 06:20:24.529266 12152 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskHG7JFS/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515618503783-12152-0/minicluster-data/master-0-root
metadata directory: /tmp/dist-test-taskHG7JFS/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515618503783-12152-0/minicluster-data/master-0-root
1 data directories: /tmp/dist-test-taskHG7JFS/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515618503783-12152-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:20:24.537073 12152 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:20:24.537461 12152 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:20:24.541695 12152 rpc_server.cc:307] RPC server started. Bound to: 127.11.222.62:45921
I20260812 06:20:24.545418 12545 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.11.222.62:45921 every 8 connection(s)
I20260812 06:20:24.546911 12547 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:20:24.561318 12547 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P b67b75bb4312498d903b75559f7c8b57: Bootstrap starting.
I20260812 06:20:24.562351 12547 tablet_bootstrap.cc:654] T 00000000000000000000000000000000 P b67b75bb4312498d903b75559f7c8b57: Neither blocks nor log segments found. Creating new log.
I20260812 06:20:24.563791 12547 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P b67b75bb4312498d903b75559f7c8b57: No bootstrap required, opened a new log
I20260812 06:20:24.564337 12547 raft_consensus.cc:359] T 00000000000000000000000000000000 P b67b75bb4312498d903b75559f7c8b57 [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "b67b75bb4312498d903b75559f7c8b57" member_type: VOTER }
I20260812 06:20:24.564440 12547 raft_consensus.cc:385] T 00000000000000000000000000000000 P b67b75bb4312498d903b75559f7c8b57 [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:20:24.564464 12547 raft_consensus.cc:740] T 00000000000000000000000000000000 P b67b75bb4312498d903b75559f7c8b57 [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: b67b75bb4312498d903b75559f7c8b57, State: Initialized, Role: FOLLOWER
I20260812 06:20:24.564634 12547 consensus_queue.cc:260] T 00000000000000000000000000000000 P b67b75bb4312498d903b75559f7c8b57 [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: "b67b75bb4312498d903b75559f7c8b57" member_type: VOTER }
I20260812 06:20:24.564707 12547 raft_consensus.cc:399] T 00000000000000000000000000000000 P b67b75bb4312498d903b75559f7c8b57 [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:20:24.564754 12547 raft_consensus.cc:493] T 00000000000000000000000000000000 P b67b75bb4312498d903b75559f7c8b57 [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:20:24.564819 12547 raft_consensus.cc:3060] T 00000000000000000000000000000000 P b67b75bb4312498d903b75559f7c8b57 [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:20:24.565699 12547 raft_consensus.cc:515] T 00000000000000000000000000000000 P b67b75bb4312498d903b75559f7c8b57 [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "b67b75bb4312498d903b75559f7c8b57" member_type: VOTER }
I20260812 06:20:24.565872 12547 leader_election.cc:304] T 00000000000000000000000000000000 P b67b75bb4312498d903b75559f7c8b57 [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: b67b75bb4312498d903b75559f7c8b57; no voters: 
I20260812 06:20:24.566164 12547 leader_election.cc:290] T 00000000000000000000000000000000 P b67b75bb4312498d903b75559f7c8b57 [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:20:24.566357 12553 raft_consensus.cc:2804] T 00000000000000000000000000000000 P b67b75bb4312498d903b75559f7c8b57 [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:20:24.566617 12553 raft_consensus.cc:697] T 00000000000000000000000000000000 P b67b75bb4312498d903b75559f7c8b57 [term 1 LEADER]: Becoming Leader. State: Replica: b67b75bb4312498d903b75559f7c8b57, State: Running, Role: LEADER
I20260812 06:20:24.566768 12547 sys_catalog.cc:565] T 00000000000000000000000000000000 P b67b75bb4312498d903b75559f7c8b57 [sys.catalog]: configured and running, proceeding with master startup.
I20260812 06:20:24.566884 12553 consensus_queue.cc:237] T 00000000000000000000000000000000 P b67b75bb4312498d903b75559f7c8b57 [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: "b67b75bb4312498d903b75559f7c8b57" member_type: VOTER }
I20260812 06:20:24.567457 12556 sys_catalog.cc:455] T 00000000000000000000000000000000 P b67b75bb4312498d903b75559f7c8b57 [sys.catalog]: SysCatalogTable state changed. Reason: New leader b67b75bb4312498d903b75559f7c8b57. Latest consensus state: current_term: 1 leader_uuid: "b67b75bb4312498d903b75559f7c8b57" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "b67b75bb4312498d903b75559f7c8b57" member_type: VOTER } }
I20260812 06:20:24.567636 12556 sys_catalog.cc:458] T 00000000000000000000000000000000 P b67b75bb4312498d903b75559f7c8b57 [sys.catalog]: This master's current role is: LEADER
I20260812 06:20:24.567809 12554 sys_catalog.cc:455] T 00000000000000000000000000000000 P b67b75bb4312498d903b75559f7c8b57 [sys.catalog]: SysCatalogTable state changed. Reason: RaftConsensus started. Latest consensus state: current_term: 1 leader_uuid: "b67b75bb4312498d903b75559f7c8b57" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "b67b75bb4312498d903b75559f7c8b57" member_type: VOTER } }
I20260812 06:20:24.567952 12554 sys_catalog.cc:458] T 00000000000000000000000000000000 P b67b75bb4312498d903b75559f7c8b57 [sys.catalog]: This master's current role is: LEADER
I20260812 06:20:24.568586 12572 catalog_manager.cc:1511] Loading table and tablet metadata into memory...
I20260812 06:20:24.569687 12572 catalog_manager.cc:1520] Initializing Kudu cluster ID...
I20260812 06:20:24.569923 12152 internal_mini_cluster.cc:184] Waiting to initialize catalog manager on master 0
I20260812 06:20:24.572048 12572 catalog_manager.cc:1383] Generated new cluster ID: 38da3ebb58344898a7892cfca0d51558
I20260812 06:20:24.572129 12572 catalog_manager.cc:1531] Initializing Kudu internal certificate authority...
I20260812 06:20:24.581048 12572 catalog_manager.cc:1406] Generated new certificate authority record
I20260812 06:20:24.581661 12572 catalog_manager.cc:1540] Loading token signing keys...
I20260812 06:20:24.592393 12572 catalog_manager.cc:6092] T 00000000000000000000000000000000 P b67b75bb4312498d903b75559f7c8b57: Generated new TSK 0
I20260812 06:20:24.592629 12572 catalog_manager.cc:1550] Initializing in-progress tserver states...
I20260812 06:20:24.602533 12152 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:20:24.604936 12591 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:20:24.605113 12152 server_base.cc:1061] running on GCE node
W20260812 06:20:24.605118 12595 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:20:24.605219 12589 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:20:24.605506 12152 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:20:24.605553 12152 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:20:24.605571 12152 hybrid_clock.cc:648] HybridClock initialized: now 1786515624605571 us; error 0 us; skew 500 ppm
I20260812 06:20:24.606519 12152 webserver.cc:533] Webserver started at http://127.11.222.1:43263/ using document root <none> and password file <none>
I20260812 06:20:24.606732 12152 fs_manager.cc:362] Metadata directory not provided
I20260812 06:20:24.606789 12152 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:20:24.606848 12152 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:20:24.607277 12152 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskHG7JFS/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515618503783-12152-0/minicluster-data/ts-0-root/instance:
uuid: "1c76864c1a9945aa9ee4016cc79a06b9"
format_stamp: "Formatted at 2026-08-12 06:20:24 on dist-test-slave-3kk6"
I20260812 06:20:24.608943 12152 fs_manager.cc:696] Time spent creating directory manager: real 0.001s	user 0.002s	sys 0.000s
I20260812 06:20:24.609951 12602 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:20:24.610277 12152 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.001s	sys 0.000s
I20260812 06:20:24.610394 12152 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskHG7JFS/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515618503783-12152-0/minicluster-data/ts-0-root
uuid: "1c76864c1a9945aa9ee4016cc79a06b9"
format_stamp: "Formatted at 2026-08-12 06:20:24 on dist-test-slave-3kk6"
I20260812 06:20:24.610498 12152 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskHG7JFS/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515618503783-12152-0/minicluster-data/ts-0-root
metadata directory: /tmp/dist-test-taskHG7JFS/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515618503783-12152-0/minicluster-data/ts-0-root
1 data directories: /tmp/dist-test-taskHG7JFS/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515618503783-12152-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:20:24.624277 12152 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:20:24.624744 12152 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:20:24.625123 12152 txn_system_client.cc:432] TxnSystemClient initialization is disabled...
I20260812 06:20:24.625649 12152 ts_tablet_manager.cc:585] Loaded tablet metadata (0 total tablets, 0 live tablets)
I20260812 06:20:24.625712 12152 ts_tablet_manager.cc:531] Time spent load tablet metadata: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:20:24.625774 12152 ts_tablet_manager.cc:616] Registered 0 tablets
I20260812 06:20:24.625828 12152 ts_tablet_manager.cc:595] Time spent register tablets: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:20:24.630617 12152 rpc_server.cc:307] RPC server started. Bound to: 127.11.222.1:45293
I20260812 06:20:24.630805 12691 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.11.222.1:45293 every 8 connection(s)
I20260812 06:20:24.640420 12692 heartbeater.cc:344] Connected to a master server at 127.11.222.62:45921
I20260812 06:20:24.640590 12692 heartbeater.cc:461] Registering TS with master...
I20260812 06:20:24.640915 12692 heartbeater.cc:507] Master 127.11.222.62:45921 requested a full tablet report, sending...
I20260812 06:20:24.641757 12487 ts_manager.cc:194] Registered new tserver with Master: 1c76864c1a9945aa9ee4016cc79a06b9 (127.11.222.1:45293)
I20260812 06:20:24.642373 12152 internal_mini_cluster.cc:371] 1 TS(s) registered with all masters after 0.011198617s
I20260812 06:20:24.642835 12487 master_service.cc:502] Signed X509 certificate for tserver {username='slave'} at 127.0.0.1:45092
I20260812 06:20:24.651619 12487 catalog_manager.cc:2283] Servicing CreateTable request from {username='slave'} at 127.0.0.1:45104:
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:20:24.662223 12644 tablet_service.cc:1511] Processing CreateTablet for tablet 3c558229b1dd406398610d0e58ddd0f4 (DEFAULT_TABLE table=heavy-update-compaction-test [id=071d8d0d34654771b504700a84e939a9]), partition=
I20260812 06:20:24.662535 12644 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet 3c558229b1dd406398610d0e58ddd0f4. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:20:24.665165 12713 tablet_bootstrap.cc:492] T 3c558229b1dd406398610d0e58ddd0f4 P 1c76864c1a9945aa9ee4016cc79a06b9: Bootstrap starting.
I20260812 06:20:24.666332 12713 tablet_bootstrap.cc:654] T 3c558229b1dd406398610d0e58ddd0f4 P 1c76864c1a9945aa9ee4016cc79a06b9: Neither blocks nor log segments found. Creating new log.
I20260812 06:20:24.667949 12713 tablet_bootstrap.cc:492] T 3c558229b1dd406398610d0e58ddd0f4 P 1c76864c1a9945aa9ee4016cc79a06b9: No bootstrap required, opened a new log
I20260812 06:20:24.668054 12713 ts_tablet_manager.cc:1403] T 3c558229b1dd406398610d0e58ddd0f4 P 1c76864c1a9945aa9ee4016cc79a06b9: Time spent bootstrapping tablet: real 0.003s	user 0.002s	sys 0.000s
I20260812 06:20:24.668741 12713 raft_consensus.cc:359] T 3c558229b1dd406398610d0e58ddd0f4 P 1c76864c1a9945aa9ee4016cc79a06b9 [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "1c76864c1a9945aa9ee4016cc79a06b9" member_type: VOTER last_known_addr { host: "127.11.222.1" port: 45293 } }
I20260812 06:20:24.668905 12713 raft_consensus.cc:385] T 3c558229b1dd406398610d0e58ddd0f4 P 1c76864c1a9945aa9ee4016cc79a06b9 [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:20:24.668952 12713 raft_consensus.cc:740] T 3c558229b1dd406398610d0e58ddd0f4 P 1c76864c1a9945aa9ee4016cc79a06b9 [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: 1c76864c1a9945aa9ee4016cc79a06b9, State: Initialized, Role: FOLLOWER
I20260812 06:20:24.669108 12713 consensus_queue.cc:260] T 3c558229b1dd406398610d0e58ddd0f4 P 1c76864c1a9945aa9ee4016cc79a06b9 [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: "1c76864c1a9945aa9ee4016cc79a06b9" member_type: VOTER last_known_addr { host: "127.11.222.1" port: 45293 } }
I20260812 06:20:24.669176 12713 raft_consensus.cc:399] T 3c558229b1dd406398610d0e58ddd0f4 P 1c76864c1a9945aa9ee4016cc79a06b9 [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:20:24.669201 12713 raft_consensus.cc:493] T 3c558229b1dd406398610d0e58ddd0f4 P 1c76864c1a9945aa9ee4016cc79a06b9 [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:20:24.669230 12713 raft_consensus.cc:3060] T 3c558229b1dd406398610d0e58ddd0f4 P 1c76864c1a9945aa9ee4016cc79a06b9 [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:20:24.670106 12713 raft_consensus.cc:515] T 3c558229b1dd406398610d0e58ddd0f4 P 1c76864c1a9945aa9ee4016cc79a06b9 [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "1c76864c1a9945aa9ee4016cc79a06b9" member_type: VOTER last_known_addr { host: "127.11.222.1" port: 45293 } }
I20260812 06:20:24.670250 12713 leader_election.cc:304] T 3c558229b1dd406398610d0e58ddd0f4 P 1c76864c1a9945aa9ee4016cc79a06b9 [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: 1c76864c1a9945aa9ee4016cc79a06b9; no voters: 
I20260812 06:20:24.670454 12713 leader_election.cc:290] T 3c558229b1dd406398610d0e58ddd0f4 P 1c76864c1a9945aa9ee4016cc79a06b9 [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:20:24.670756 12716 raft_consensus.cc:2804] T 3c558229b1dd406398610d0e58ddd0f4 P 1c76864c1a9945aa9ee4016cc79a06b9 [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:20:24.671089 12692 heartbeater.cc:499] Master 127.11.222.62:45921 was elected leader, sending a full tablet report...
I20260812 06:20:24.671097 12716 raft_consensus.cc:697] T 3c558229b1dd406398610d0e58ddd0f4 P 1c76864c1a9945aa9ee4016cc79a06b9 [term 1 LEADER]: Becoming Leader. State: Replica: 1c76864c1a9945aa9ee4016cc79a06b9, State: Running, Role: LEADER
I20260812 06:20:24.671329 12716 consensus_queue.cc:237] T 3c558229b1dd406398610d0e58ddd0f4 P 1c76864c1a9945aa9ee4016cc79a06b9 [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: "1c76864c1a9945aa9ee4016cc79a06b9" member_type: VOTER last_known_addr { host: "127.11.222.1" port: 45293 } }
I20260812 06:20:24.671418 12713 ts_tablet_manager.cc:1434] T 3c558229b1dd406398610d0e58ddd0f4 P 1c76864c1a9945aa9ee4016cc79a06b9: Time spent starting tablet: real 0.003s	user 0.004s	sys 0.000s
I20260812 06:20:24.673139 12486 catalog_manager.cc:5719] T 3c558229b1dd406398610d0e58ddd0f4 P 1c76864c1a9945aa9ee4016cc79a06b9 reported cstate change: term changed from 0 to 1, leader changed from <none> to 1c76864c1a9945aa9ee4016cc79a06b9 (127.11.222.1). New cstate: current_term: 1 leader_uuid: "1c76864c1a9945aa9ee4016cc79a06b9" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "1c76864c1a9945aa9ee4016cc79a06b9" member_type: VOTER last_known_addr { host: "127.11.222.1" port: 45293 } health_report { overall_health: HEALTHY } } }
I20260812 06:20:24.740372 12152 heavy-update-compaction-itest.cc:215] Time spent inserting: real 0.061s	user 0.018s	sys 0.008s
I20260812 06:20:24.882194 12693 maintenance_manager.cc:419] P 1c76864c1a9945aa9ee4016cc79a06b9: Scheduling FlushMRSOp(3c558229b1dd406398610d0e58ddd0f4): perf score=16.078378
I20260812 06:20:25.052817 12608 maintenance_manager.cc:643] P 1c76864c1a9945aa9ee4016cc79a06b9: FlushMRSOp(3c558229b1dd406398610d0e58ddd0f4) complete. Timing: real 0.170s	user 0.095s	sys 0.069s Metrics: {"bytes_written":12307489,"cfile_init":1,"delete_count":0,"dirs.queue_time_us":76,"dirs.run_cpu_time_us":260,"dirs.run_wall_time_us":924,"drs_written":1,"lbm_read_time_us":72,"lbm_reads_lt_1ms":4,"lbm_write_time_us":44880,"lbm_writes_lt_1ms":757,"peak_mem_usage":0,"reinsert_count":0,"rows_written":104,"update_count":1500}
I20260812 06:20:25.053591 12693 maintenance_manager.cc:419] P 1c76864c1a9945aa9ee4016cc79a06b9: Scheduling LogGCOp(3c558229b1dd406398610d0e58ddd0f4): free 20290830 bytes of WAL
I20260812 06:20:25.053876 12608 log_reader.cc:385] T 3c558229b1dd406398610d0e58ddd0f4: removed 2 log segments from log reader
I20260812 06:20:25.053926 12608 log.cc:1079] T 3c558229b1dd406398610d0e58ddd0f4 P 1c76864c1a9945aa9ee4016cc79a06b9: Deleting log segment in path: /tmp/dist-test-taskHG7JFS/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515618503783-12152-0/minicluster-data/ts-0-root/wals/3c558229b1dd406398610d0e58ddd0f4/wal-000000001 (ops 1-6)
I20260812 06:20:25.053960 12608 log.cc:1079] T 3c558229b1dd406398610d0e58ddd0f4 P 1c76864c1a9945aa9ee4016cc79a06b9: Deleting log segment in path: /tmp/dist-test-taskHG7JFS/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515618503783-12152-0/minicluster-data/ts-0-root/wals/3c558229b1dd406398610d0e58ddd0f4/wal-000000002 (ops 7-10)
I20260812 06:20:25.059478 12608 maintenance_manager.cc:643] P 1c76864c1a9945aa9ee4016cc79a06b9: LogGCOp(3c558229b1dd406398610d0e58ddd0f4) complete. Timing: real 0.006s	user 0.000s	sys 0.005s Metrics: {}
I20260812 06:20:25.060048 12693 maintenance_manager.cc:419] P 1c76864c1a9945aa9ee4016cc79a06b9: Scheduling UndoDeltaBlockGCOp(3c558229b1dd406398610d0e58ddd0f4): 16411397 bytes on disk
I20260812 06:20:25.060691 12608 maintenance_manager.cc:643] P 1c76864c1a9945aa9ee4016cc79a06b9: UndoDeltaBlockGCOp(3c558229b1dd406398610d0e58ddd0f4) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":116,"lbm_reads_lt_1ms":4}
I20260812 06:20:25.061281 12693 maintenance_manager.cc:419] P 1c76864c1a9945aa9ee4016cc79a06b9: Scheduling FlushDeltaMemStoresOp(3c558229b1dd406398610d0e58ddd0f4): perf score=2.188937
I20260812 06:20:25.077592 12608 maintenance_manager.cc:643] P 1c76864c1a9945aa9ee4016cc79a06b9: FlushDeltaMemStoresOp(3c558229b1dd406398610d0e58ddd0f4) complete. Timing: real 0.016s	user 0.007s	sys 0.005s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5064,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:25.078179 12693 maintenance_manager.cc:419] P 1c76864c1a9945aa9ee4016cc79a06b9: Scheduling MajorDeltaCompactionOp(3c558229b1dd406398610d0e58ddd0f4): perf score=1.000000
I20260812 06:20:25.246443 12608 maintenance_manager.cc:643] P 1c76864c1a9945aa9ee4016cc79a06b9: MajorDeltaCompactionOp(3c558229b1dd406398610d0e58ddd0f4) complete. Timing: real 0.168s	user 0.105s	sys 0.049s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672276,"cfile_init":7,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":1068,"lbm_read_time_us":10752,"lbm_reads_lt_1ms":460,"lbm_write_time_us":25619,"lbm_writes_lt_1ms":443,"mutex_wait_us":54,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":11264,"thread_start_us":378,"threads_started":5,"update_count":2000}
I20260812 06:20:25.247262 12693 maintenance_manager.cc:419] P 1c76864c1a9945aa9ee4016cc79a06b9: Scheduling FlushDeltaMemStoresOp(3c558229b1dd406398610d0e58ddd0f4): perf score=14.095187
I20260812 06:20:25.298271 12608 maintenance_manager.cc:643] P 1c76864c1a9945aa9ee4016cc79a06b9: FlushDeltaMemStoresOp(3c558229b1dd406398610d0e58ddd0f4) complete. Timing: real 0.051s	user 0.014s	sys 0.031s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":22546,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:20:25.298846 12693 maintenance_manager.cc:419] P 1c76864c1a9945aa9ee4016cc79a06b9: Scheduling FlushDeltaMemStoresOp(3c558229b1dd406398610d0e58ddd0f4): perf score=2.188937
I20260812 06:20:25.311437 12608 maintenance_manager.cc:643] P 1c76864c1a9945aa9ee4016cc79a06b9: FlushDeltaMemStoresOp(3c558229b1dd406398610d0e58ddd0f4) complete. Timing: real 0.012s	user 0.007s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4337,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:25.312127 12693 maintenance_manager.cc:419] P 1c76864c1a9945aa9ee4016cc79a06b9: Scheduling MajorDeltaCompactionOp(3c558229b1dd406398610d0e58ddd0f4): perf score=1.000000
I20260812 06:20:25.480580 12608 maintenance_manager.cc:643] P 1c76864c1a9945aa9ee4016cc79a06b9: MajorDeltaCompactionOp(3c558229b1dd406398610d0e58ddd0f4) complete. Timing: real 0.168s	user 0.115s	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":86,"lbm_read_time_us":12567,"lbm_reads_lt_1ms":572,"lbm_write_time_us":35479,"lbm_writes_lt_1ms":543,"mutex_wait_us":29,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":25984,"update_count":2500}
I20260812 06:20:25.481252 12693 maintenance_manager.cc:419] P 1c76864c1a9945aa9ee4016cc79a06b9: Scheduling FlushDeltaMemStoresOp(3c558229b1dd406398610d0e58ddd0f4): perf score=11.118625
I20260812 06:20:25.515949 12608 maintenance_manager.cc:643] P 1c76864c1a9945aa9ee4016cc79a06b9: FlushDeltaMemStoresOp(3c558229b1dd406398610d0e58ddd0f4) complete. Timing: real 0.034s	user 0.017s	sys 0.015s Metrics: {"bytes_written":12717734,"delete_count":0,"lbm_write_time_us":15059,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:20:25.516487 12693 maintenance_manager.cc:419] P 1c76864c1a9945aa9ee4016cc79a06b9: Scheduling FlushDeltaMemStoresOp(3c558229b1dd406398610d0e58ddd0f4): perf score=2.188937
I20260812 06:20:25.526408 12608 maintenance_manager.cc:643] P 1c76864c1a9945aa9ee4016cc79a06b9: FlushDeltaMemStoresOp(3c558229b1dd406398610d0e58ddd0f4) complete. Timing: real 0.010s	user 0.004s	sys 0.004s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3753,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:20:25.526922 12693 maintenance_manager.cc:419] P 1c76864c1a9945aa9ee4016cc79a06b9: Scheduling MajorDeltaCompactionOp(3c558229b1dd406398610d0e58ddd0f4): perf score=1.000000
I20260812 06:20:25.668089 12608 maintenance_manager.cc:643] P 1c76864c1a9945aa9ee4016cc79a06b9: MajorDeltaCompactionOp(3c558229b1dd406398610d0e58ddd0f4) complete. Timing: real 0.141s	user 0.116s	sys 0.025s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672267,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":227,"lbm_read_time_us":10359,"lbm_reads_lt_1ms":472,"lbm_write_time_us":29694,"lbm_writes_lt_1ms":443,"mutex_wait_us":46,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":29184,"update_count":2000}
I20260812 06:20:25.668967 12693 maintenance_manager.cc:419] P 1c76864c1a9945aa9ee4016cc79a06b9: Scheduling FlushDeltaMemStoresOp(3c558229b1dd406398610d0e58ddd0f4): perf score=10.126437
I20260812 06:20:25.734539 12608 maintenance_manager.cc:643] P 1c76864c1a9945aa9ee4016cc79a06b9: FlushDeltaMemStoresOp(3c558229b1dd406398610d0e58ddd0f4) complete. Timing: real 0.065s	user 0.039s	sys 0.011s Metrics: {"bytes_written":12307493,"delete_count":0,"lbm_write_time_us":18789,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:20:25.735252 12693 maintenance_manager.cc:419] P 1c76864c1a9945aa9ee4016cc79a06b9: Scheduling FlushDeltaMemStoresOp(3c558229b1dd406398610d0e58ddd0f4): perf score=2.188937
I20260812 06:20:25.753536 12608 maintenance_manager.cc:643] P 1c76864c1a9945aa9ee4016cc79a06b9: FlushDeltaMemStoresOp(3c558229b1dd406398610d0e58ddd0f4) complete. Timing: real 0.018s	user 0.006s	sys 0.009s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6899,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:25.754202 12693 maintenance_manager.cc:419] P 1c76864c1a9945aa9ee4016cc79a06b9: Scheduling MajorDeltaCompactionOp(3c558229b1dd406398610d0e58ddd0f4): perf score=1.000000
I20260812 06:20:25.914108 12608 maintenance_manager.cc:643] P 1c76864c1a9945aa9ee4016cc79a06b9: MajorDeltaCompactionOp(3c558229b1dd406398610d0e58ddd0f4) complete. Timing: real 0.160s	user 0.103s	sys 0.056s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672280,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":713,"lbm_read_time_us":12735,"lbm_reads_lt_1ms":472,"lbm_write_time_us":26690,"lbm_writes_lt_1ms":443,"mutex_wait_us":60,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":14976,"update_count":2000}
I20260812 06:20:25.914904 12693 maintenance_manager.cc:419] P 1c76864c1a9945aa9ee4016cc79a06b9: Scheduling FlushDeltaMemStoresOp(3c558229b1dd406398610d0e58ddd0f4): perf score=10.126437
I20260812 06:20:25.964444 12608 maintenance_manager.cc:643] P 1c76864c1a9945aa9ee4016cc79a06b9: FlushDeltaMemStoresOp(3c558229b1dd406398610d0e58ddd0f4) complete. Timing: real 0.049s	user 0.014s	sys 0.032s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":21400,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:20:25.965023 12693 maintenance_manager.cc:419] P 1c76864c1a9945aa9ee4016cc79a06b9: Scheduling FlushDeltaMemStoresOp(3c558229b1dd406398610d0e58ddd0f4): perf score=2.188937
I20260812 06:20:25.977334 12608 maintenance_manager.cc:643] P 1c76864c1a9945aa9ee4016cc79a06b9: FlushDeltaMemStoresOp(3c558229b1dd406398610d0e58ddd0f4) complete. Timing: real 0.012s	user 0.009s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4357,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:25.978034 12693 maintenance_manager.cc:419] P 1c76864c1a9945aa9ee4016cc79a06b9: Scheduling MajorDeltaCompactionOp(3c558229b1dd406398610d0e58ddd0f4): perf score=1.000000
I20260812 06:20:26.120321 12608 maintenance_manager.cc:643] P 1c76864c1a9945aa9ee4016cc79a06b9: MajorDeltaCompactionOp(3c558229b1dd406398610d0e58ddd0f4) complete. Timing: real 0.142s	user 0.110s	sys 0.031s 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":1940,"lbm_read_time_us":9892,"lbm_reads_lt_1ms":472,"lbm_write_time_us":29522,"lbm_writes_lt_1ms":443,"mutex_wait_us":483,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":21632,"update_count":2000}
I20260812 06:20:26.120950 12693 maintenance_manager.cc:419] P 1c76864c1a9945aa9ee4016cc79a06b9: Scheduling FlushDeltaMemStoresOp(3c558229b1dd406398610d0e58ddd0f4): perf score=10.126437
I20260812 06:20:26.171221 12608 maintenance_manager.cc:643] P 1c76864c1a9945aa9ee4016cc79a06b9: FlushDeltaMemStoresOp(3c558229b1dd406398610d0e58ddd0f4) complete. Timing: real 0.050s	user 0.030s	sys 0.019s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":22258,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:20:26.171802 12693 maintenance_manager.cc:419] P 1c76864c1a9945aa9ee4016cc79a06b9: Scheduling FlushDeltaMemStoresOp(3c558229b1dd406398610d0e58ddd0f4): perf score=2.188937
I20260812 06:20:26.184576 12608 maintenance_manager.cc:643] P 1c76864c1a9945aa9ee4016cc79a06b9: FlushDeltaMemStoresOp(3c558229b1dd406398610d0e58ddd0f4) complete. Timing: real 0.013s	user 0.006s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4665,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:26.185163 12693 maintenance_manager.cc:419] P 1c76864c1a9945aa9ee4016cc79a06b9: Scheduling MajorDeltaCompactionOp(3c558229b1dd406398610d0e58ddd0f4): perf score=1.000000
I20260812 06:20:26.321491 12608 maintenance_manager.cc:643] P 1c76864c1a9945aa9ee4016cc79a06b9: MajorDeltaCompactionOp(3c558229b1dd406398610d0e58ddd0f4) complete. Timing: real 0.136s	user 0.109s	sys 0.024s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672277,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":254,"lbm_read_time_us":9269,"lbm_reads_lt_1ms":472,"lbm_write_time_us":25488,"lbm_writes_lt_1ms":443,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":768,"update_count":2000}
I20260812 06:20:26.322163 12693 maintenance_manager.cc:419] P 1c76864c1a9945aa9ee4016cc79a06b9: Scheduling FlushDeltaMemStoresOp(3c558229b1dd406398610d0e58ddd0f4): perf score=10.126437
I20260812 06:20:26.364683 12608 maintenance_manager.cc:643] P 1c76864c1a9945aa9ee4016cc79a06b9: FlushDeltaMemStoresOp(3c558229b1dd406398610d0e58ddd0f4) complete. Timing: real 0.042s	user 0.019s	sys 0.017s Metrics: {"bytes_written":12307494,"delete_count":0,"lbm_write_time_us":16941,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:20:26.365262 12693 maintenance_manager.cc:419] P 1c76864c1a9945aa9ee4016cc79a06b9: Scheduling FlushDeltaMemStoresOp(3c558229b1dd406398610d0e58ddd0f4): perf score=2.188937
I20260812 06:20:26.382352 12608 maintenance_manager.cc:643] P 1c76864c1a9945aa9ee4016cc79a06b9: FlushDeltaMemStoresOp(3c558229b1dd406398610d0e58ddd0f4) complete. Timing: real 0.017s	user 0.014s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6296,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:26.383067 12693 maintenance_manager.cc:419] P 1c76864c1a9945aa9ee4016cc79a06b9: Scheduling FlushMRSOp(3c558229b1dd406398610d0e58ddd0f4): perf score=1.000000
I20260812 06:20:26.411592 12608 maintenance_manager.cc:643] P 1c76864c1a9945aa9ee4016cc79a06b9: FlushMRSOp(3c558229b1dd406398610d0e58ddd0f4) complete. Timing: real 0.028s	user 0.025s	sys 0.002s Metrics: {"bytes_written":1193503,"cfile_init":1,"dirs.queue_time_us":75,"dirs.run_cpu_time_us":292,"dirs.run_wall_time_us":1506,"drs_written":1,"lbm_read_time_us":61,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1655,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":29}
I20260812 06:20:26.412351 12693 maintenance_manager.cc:419] P 1c76864c1a9945aa9ee4016cc79a06b9: Scheduling LogGCOp(3c558229b1dd406398610d0e58ddd0f4): free 117302565 bytes of WAL
I20260812 06:20:26.412650 12608 log_reader.cc:385] T 3c558229b1dd406398610d0e58ddd0f4: removed 12 log segments from log reader
I20260812 06:20:26.412715 12608 log.cc:1079] T 3c558229b1dd406398610d0e58ddd0f4 P 1c76864c1a9945aa9ee4016cc79a06b9: Deleting log segment in path: /tmp/dist-test-taskHG7JFS/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515618503783-12152-0/minicluster-data/ts-0-root/wals/3c558229b1dd406398610d0e58ddd0f4/wal-000000003 (ops 11-15)
I20260812 06:20:26.412755 12608 log.cc:1079] T 3c558229b1dd406398610d0e58ddd0f4 P 1c76864c1a9945aa9ee4016cc79a06b9: Deleting log segment in path: /tmp/dist-test-taskHG7JFS/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515618503783-12152-0/minicluster-data/ts-0-root/wals/3c558229b1dd406398610d0e58ddd0f4/wal-000000004 (ops 16-20)
I20260812 06:20:26.412783 12608 log.cc:1079] T 3c558229b1dd406398610d0e58ddd0f4 P 1c76864c1a9945aa9ee4016cc79a06b9: Deleting log segment in path: /tmp/dist-test-taskHG7JFS/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515618503783-12152-0/minicluster-data/ts-0-root/wals/3c558229b1dd406398610d0e58ddd0f4/wal-000000005 (ops 21-25)
I20260812 06:20:26.412809 12608 log.cc:1079] T 3c558229b1dd406398610d0e58ddd0f4 P 1c76864c1a9945aa9ee4016cc79a06b9: Deleting log segment in path: /tmp/dist-test-taskHG7JFS/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515618503783-12152-0/minicluster-data/ts-0-root/wals/3c558229b1dd406398610d0e58ddd0f4/wal-000000006 (ops 26-30)
I20260812 06:20:26.412833 12608 log.cc:1079] T 3c558229b1dd406398610d0e58ddd0f4 P 1c76864c1a9945aa9ee4016cc79a06b9: Deleting log segment in path: /tmp/dist-test-taskHG7JFS/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515618503783-12152-0/minicluster-data/ts-0-root/wals/3c558229b1dd406398610d0e58ddd0f4/wal-000000007 (ops 31-34)
I20260812 06:20:26.412855 12608 log.cc:1079] T 3c558229b1dd406398610d0e58ddd0f4 P 1c76864c1a9945aa9ee4016cc79a06b9: Deleting log segment in path: /tmp/dist-test-taskHG7JFS/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515618503783-12152-0/minicluster-data/ts-0-root/wals/3c558229b1dd406398610d0e58ddd0f4/wal-000000008 (ops 35-39)
I20260812 06:20:26.412886 12608 log.cc:1079] T 3c558229b1dd406398610d0e58ddd0f4 P 1c76864c1a9945aa9ee4016cc79a06b9: Deleting log segment in path: /tmp/dist-test-taskHG7JFS/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515618503783-12152-0/minicluster-data/ts-0-root/wals/3c558229b1dd406398610d0e58ddd0f4/wal-000000009 (ops 40-44)
I20260812 06:20:26.412915 12608 log.cc:1079] T 3c558229b1dd406398610d0e58ddd0f4 P 1c76864c1a9945aa9ee4016cc79a06b9: Deleting log segment in path: /tmp/dist-test-taskHG7JFS/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515618503783-12152-0/minicluster-data/ts-0-root/wals/3c558229b1dd406398610d0e58ddd0f4/wal-000000010 (ops 45-49)
I20260812 06:20:26.412949 12608 log.cc:1079] T 3c558229b1dd406398610d0e58ddd0f4 P 1c76864c1a9945aa9ee4016cc79a06b9: Deleting log segment in path: /tmp/dist-test-taskHG7JFS/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515618503783-12152-0/minicluster-data/ts-0-root/wals/3c558229b1dd406398610d0e58ddd0f4/wal-000000011 (ops 50-54)
I20260812 06:20:26.412983 12608 log.cc:1079] T 3c558229b1dd406398610d0e58ddd0f4 P 1c76864c1a9945aa9ee4016cc79a06b9: Deleting log segment in path: /tmp/dist-test-taskHG7JFS/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515618503783-12152-0/minicluster-data/ts-0-root/wals/3c558229b1dd406398610d0e58ddd0f4/wal-000000012 (ops 55-58)
I20260812 06:20:26.413014 12608 log.cc:1079] T 3c558229b1dd406398610d0e58ddd0f4 P 1c76864c1a9945aa9ee4016cc79a06b9: Deleting log segment in path: /tmp/dist-test-taskHG7JFS/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515618503783-12152-0/minicluster-data/ts-0-root/wals/3c558229b1dd406398610d0e58ddd0f4/wal-000000013 (ops 59-63)
I20260812 06:20:26.413043 12608 log.cc:1079] T 3c558229b1dd406398610d0e58ddd0f4 P 1c76864c1a9945aa9ee4016cc79a06b9: Deleting log segment in path: /tmp/dist-test-taskHG7JFS/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515618503783-12152-0/minicluster-data/ts-0-root/wals/3c558229b1dd406398610d0e58ddd0f4/wal-000000014 (ops 64-68)
I20260812 06:20:26.444625 12608 maintenance_manager.cc:643] P 1c76864c1a9945aa9ee4016cc79a06b9: LogGCOp(3c558229b1dd406398610d0e58ddd0f4) complete. Timing: real 0.032s	user 0.000s	sys 0.030s Metrics: {}
I20260812 06:20:26.445187 12693 maintenance_manager.cc:419] P 1c76864c1a9945aa9ee4016cc79a06b9: Scheduling FlushDeltaMemStoresOp(3c558229b1dd406398610d0e58ddd0f4): perf score=2.188937
I20260812 06:20:26.470031 12608 maintenance_manager.cc:643] P 1c76864c1a9945aa9ee4016cc79a06b9: FlushDeltaMemStoresOp(3c558229b1dd406398610d0e58ddd0f4) complete. Timing: real 0.025s	user 0.012s	sys 0.001s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5523,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:26.470530 12693 maintenance_manager.cc:419] P 1c76864c1a9945aa9ee4016cc79a06b9: Scheduling FlushDeltaMemStoresOp(3c558229b1dd406398610d0e58ddd0f4): perf score=2.188937
I20260812 06:20:26.481755 12608 maintenance_manager.cc:643] P 1c76864c1a9945aa9ee4016cc79a06b9: FlushDeltaMemStoresOp(3c558229b1dd406398610d0e58ddd0f4) complete. Timing: real 0.011s	user 0.006s	sys 0.004s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4192,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:26.482550 12693 maintenance_manager.cc:419] P 1c76864c1a9945aa9ee4016cc79a06b9: Scheduling MajorDeltaCompactionOp(3c558229b1dd406398610d0e58ddd0f4): perf score=1.000000
I20260812 06:20:26.660450 12608 maintenance_manager.cc:643] P 1c76864c1a9945aa9ee4016cc79a06b9: MajorDeltaCompactionOp(3c558229b1dd406398610d0e58ddd0f4) complete. Timing: real 0.178s	user 0.120s	sys 0.057s Metrics: {"cfile_cache_miss":634,"cfile_cache_miss_bytes":28877342,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":179,"lbm_read_time_us":13993,"lbm_reads_lt_1ms":674,"lbm_write_time_us":34201,"lbm_writes_lt_1ms":643,"mutex_wait_us":42,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":10880,"thread_start_us":97,"threads_started":1,"update_count":3000}
I20260812 06:20:26.661183 12693 maintenance_manager.cc:419] P 1c76864c1a9945aa9ee4016cc79a06b9: Scheduling UndoDeltaBlockGCOp(3c558229b1dd406398610d0e58ddd0f4): 461 bytes on disk
I20260812 06:20:26.661800 12608 maintenance_manager.cc:643] P 1c76864c1a9945aa9ee4016cc79a06b9: UndoDeltaBlockGCOp(3c558229b1dd406398610d0e58ddd0f4) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":96,"lbm_reads_lt_1ms":4}
I20260812 06:20:26.662573 12693 maintenance_manager.cc:419] P 1c76864c1a9945aa9ee4016cc79a06b9: Scheduling FlushDeltaMemStoresOp(3c558229b1dd406398610d0e58ddd0f4): perf score=14.095187
I20260812 06:20:26.710577 12608 maintenance_manager.cc:643] P 1c76864c1a9945aa9ee4016cc79a06b9: FlushDeltaMemStoresOp(3c558229b1dd406398610d0e58ddd0f4) complete. Timing: real 0.048s	user 0.026s	sys 0.017s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":20573,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:20:26.711308 12693 maintenance_manager.cc:419] P 1c76864c1a9945aa9ee4016cc79a06b9: Scheduling FlushDeltaMemStoresOp(3c558229b1dd406398610d0e58ddd0f4): perf score=2.188937
I20260812 06:20:26.724067 12608 maintenance_manager.cc:643] P 1c76864c1a9945aa9ee4016cc79a06b9: FlushDeltaMemStoresOp(3c558229b1dd406398610d0e58ddd0f4) complete. Timing: real 0.013s	user 0.008s	sys 0.003s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4588,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:26.724613 12693 maintenance_manager.cc:419] P 1c76864c1a9945aa9ee4016cc79a06b9: Scheduling MajorDeltaCompactionOp(3c558229b1dd406398610d0e58ddd0f4): perf score=1.000000
I20260812 06:20:26.910959 12608 maintenance_manager.cc:643] P 1c76864c1a9945aa9ee4016cc79a06b9: MajorDeltaCompactionOp(3c558229b1dd406398610d0e58ddd0f4) complete. Timing: real 0.186s	user 0.142s	sys 0.027s 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":401,"lbm_read_time_us":11604,"lbm_reads_lt_1ms":572,"lbm_write_time_us":34547,"lbm_writes_lt_1ms":543,"mutex_wait_us":24,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":36096,"update_count":2500}
I20260812 06:20:26.911836 12693 maintenance_manager.cc:419] P 1c76864c1a9945aa9ee4016cc79a06b9: Scheduling FlushDeltaMemStoresOp(3c558229b1dd406398610d0e58ddd0f4): perf score=14.095187
I20260812 06:20:26.963179 12608 maintenance_manager.cc:643] P 1c76864c1a9945aa9ee4016cc79a06b9: FlushDeltaMemStoresOp(3c558229b1dd406398610d0e58ddd0f4) complete. Timing: real 0.051s	user 0.027s	sys 0.020s Metrics: {"bytes_written":16409900,"delete_count":0,"lbm_write_time_us":21754,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:20:26.963706 12693 maintenance_manager.cc:419] P 1c76864c1a9945aa9ee4016cc79a06b9: Scheduling MajorDeltaCompactionOp(3c558229b1dd406398610d0e58ddd0f4): perf score=1.000000
I20260812 06:20:27.143785 12608 maintenance_manager.cc:643] P 1c76864c1a9945aa9ee4016cc79a06b9: MajorDeltaCompactionOp(3c558229b1dd406398610d0e58ddd0f4) complete. Timing: real 0.180s	user 0.112s	sys 0.057s Metrics: {"cfile_cache_miss":431,"cfile_cache_miss_bytes":20672156,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":1,"delta_iterators_relevant":1,"dirs.queue_time_us":1051,"lbm_read_time_us":11306,"lbm_reads_lt_1ms":463,"lbm_write_time_us":30725,"lbm_writes_lt_1ms":443,"mutex_wait_us":379,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":3200,"update_count":2000}
I20260812 06:20:27.144568 12693 maintenance_manager.cc:419] P 1c76864c1a9945aa9ee4016cc79a06b9: Scheduling FlushDeltaMemStoresOp(3c558229b1dd406398610d0e58ddd0f4): perf score=14.095187
I20260812 06:20:27.200752 12608 maintenance_manager.cc:643] P 1c76864c1a9945aa9ee4016cc79a06b9: FlushDeltaMemStoresOp(3c558229b1dd406398610d0e58ddd0f4) complete. Timing: real 0.056s	user 0.034s	sys 0.016s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":23661,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:20:27.201324 12693 maintenance_manager.cc:419] P 1c76864c1a9945aa9ee4016cc79a06b9: Scheduling FlushDeltaMemStoresOp(3c558229b1dd406398610d0e58ddd0f4): perf score=2.188937
I20260812 06:20:27.213627 12608 maintenance_manager.cc:643] P 1c76864c1a9945aa9ee4016cc79a06b9: FlushDeltaMemStoresOp(3c558229b1dd406398610d0e58ddd0f4) complete. Timing: real 0.012s	user 0.005s	sys 0.005s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4328,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:27.214226 12693 maintenance_manager.cc:419] P 1c76864c1a9945aa9ee4016cc79a06b9: Scheduling MajorDeltaCompactionOp(3c558229b1dd406398610d0e58ddd0f4): perf score=1.000000
I20260812 06:20:27.415903 12608 maintenance_manager.cc:643] P 1c76864c1a9945aa9ee4016cc79a06b9: MajorDeltaCompactionOp(3c558229b1dd406398610d0e58ddd0f4) complete. Timing: real 0.201s	user 0.125s	sys 0.073s 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":415,"lbm_read_time_us":12261,"lbm_reads_lt_1ms":572,"lbm_write_time_us":33343,"lbm_writes_lt_1ms":543,"mutex_wait_us":64,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":7936,"update_count":2500}
I20260812 06:20:27.416765 12693 maintenance_manager.cc:419] P 1c76864c1a9945aa9ee4016cc79a06b9: Scheduling FlushDeltaMemStoresOp(3c558229b1dd406398610d0e58ddd0f4): perf score=14.095187
I20260812 06:20:27.471423 12608 maintenance_manager.cc:643] P 1c76864c1a9945aa9ee4016cc79a06b9: FlushDeltaMemStoresOp(3c558229b1dd406398610d0e58ddd0f4) complete. Timing: real 0.054s	user 0.037s	sys 0.016s Metrics: {"bytes_written":16409900,"delete_count":0,"lbm_write_time_us":22988,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:20:27.472201 12693 maintenance_manager.cc:419] P 1c76864c1a9945aa9ee4016cc79a06b9: Scheduling FlushDeltaMemStoresOp(3c558229b1dd406398610d0e58ddd0f4): perf score=2.188937
I20260812 06:20:27.493024 12608 maintenance_manager.cc:643] P 1c76864c1a9945aa9ee4016cc79a06b9: FlushDeltaMemStoresOp(3c558229b1dd406398610d0e58ddd0f4) complete. Timing: real 0.021s	user 0.010s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":7754,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:27.493721 12693 maintenance_manager.cc:419] P 1c76864c1a9945aa9ee4016cc79a06b9: Scheduling MajorDeltaCompactionOp(3c558229b1dd406398610d0e58ddd0f4): perf score=1.000000
I20260812 06:20:27.687208 12608 maintenance_manager.cc:643] P 1c76864c1a9945aa9ee4016cc79a06b9: MajorDeltaCompactionOp(3c558229b1dd406398610d0e58ddd0f4) complete. Timing: real 0.193s	user 0.127s	sys 0.057s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774687,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":1147,"lbm_read_time_us":13200,"lbm_reads_lt_1ms":572,"lbm_write_time_us":36271,"lbm_writes_lt_1ms":543,"mutex_wait_us":312,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":14080,"update_count":2500}
I20260812 06:20:27.688021 12693 maintenance_manager.cc:419] P 1c76864c1a9945aa9ee4016cc79a06b9: Scheduling FlushDeltaMemStoresOp(3c558229b1dd406398610d0e58ddd0f4): perf score=14.095187
I20260812 06:20:27.738031 12608 maintenance_manager.cc:643] P 1c76864c1a9945aa9ee4016cc79a06b9: FlushDeltaMemStoresOp(3c558229b1dd406398610d0e58ddd0f4) complete. Timing: real 0.050s	user 0.024s	sys 0.021s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":23540,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":402,"reinsert_count":0,"update_count":2000}
I20260812 06:20:27.738617 12693 maintenance_manager.cc:419] P 1c76864c1a9945aa9ee4016cc79a06b9: Scheduling FlushDeltaMemStoresOp(3c558229b1dd406398610d0e58ddd0f4): perf score=2.188937
I20260812 06:20:27.751405 12608 maintenance_manager.cc:643] P 1c76864c1a9945aa9ee4016cc79a06b9: FlushDeltaMemStoresOp(3c558229b1dd406398610d0e58ddd0f4) complete. Timing: real 0.013s	user 0.003s	sys 0.009s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4941,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:27.751950 12693 maintenance_manager.cc:419] P 1c76864c1a9945aa9ee4016cc79a06b9: Scheduling MajorDeltaCompactionOp(3c558229b1dd406398610d0e58ddd0f4): perf score=1.000000
I20260812 06:20:27.952996 12608 maintenance_manager.cc:643] P 1c76864c1a9945aa9ee4016cc79a06b9: MajorDeltaCompactionOp(3c558229b1dd406398610d0e58ddd0f4) complete. Timing: real 0.201s	user 0.169s	sys 0.024s 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":329,"lbm_read_time_us":10627,"lbm_reads_lt_1ms":572,"lbm_write_time_us":45335,"lbm_writes_lt_1ms":543,"mutex_wait_us":111,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":20352,"update_count":2500}
I20260812 06:20:27.954433 12693 maintenance_manager.cc:419] P 1c76864c1a9945aa9ee4016cc79a06b9: Scheduling FlushDeltaMemStoresOp(3c558229b1dd406398610d0e58ddd0f4): perf score=11.118625
I20260812 06:20:28.041697 12608 maintenance_manager.cc:643] P 1c76864c1a9945aa9ee4016cc79a06b9: FlushDeltaMemStoresOp(3c558229b1dd406398610d0e58ddd0f4) complete. Timing: real 0.087s	user 0.030s	sys 0.042s Metrics: {"bytes_written":12717736,"delete_count":0,"lbm_write_time_us":37531,"lbm_writes_1-10_ms":3,"lbm_writes_lt_1ms":310,"reinsert_count":0,"update_count":1550}
I20260812 06:20:28.042610 12693 maintenance_manager.cc:419] P 1c76864c1a9945aa9ee4016cc79a06b9: Scheduling FlushDeltaMemStoresOp(3c558229b1dd406398610d0e58ddd0f4): perf score=2.188937
I20260812 06:20:28.070094 12608 maintenance_manager.cc:643] P 1c76864c1a9945aa9ee4016cc79a06b9: FlushDeltaMemStoresOp(3c558229b1dd406398610d0e58ddd0f4) complete. Timing: real 0.027s	user 0.006s	sys 0.013s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":8442,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:28.071146 12693 maintenance_manager.cc:419] P 1c76864c1a9945aa9ee4016cc79a06b9: Scheduling FlushDeltaMemStoresOp(3c558229b1dd406398610d0e58ddd0f4): perf score=2.188937
I20260812 06:20:28.090348 12608 maintenance_manager.cc:643] P 1c76864c1a9945aa9ee4016cc79a06b9: FlushDeltaMemStoresOp(3c558229b1dd406398610d0e58ddd0f4) complete. Timing: real 0.019s	user 0.012s	sys 0.004s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":7137,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:20:28.091275 12693 maintenance_manager.cc:419] P 1c76864c1a9945aa9ee4016cc79a06b9: Scheduling FlushMRSOp(3c558229b1dd406398610d0e58ddd0f4): perf score=1.000000
I20260812 06:20:28.154990 12608 maintenance_manager.cc:643] P 1c76864c1a9945aa9ee4016cc79a06b9: FlushMRSOp(3c558229b1dd406398610d0e58ddd0f4) complete. Timing: real 0.063s	user 0.051s	sys 0.008s Metrics: {"bytes_written":1275449,"cfile_init":1,"dirs.queue_time_us":134,"dirs.run_cpu_time_us":415,"dirs.run_wall_time_us":1742,"drs_written":1,"lbm_read_time_us":79,"lbm_reads_lt_1ms":4,"lbm_write_time_us":3575,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":31}
I20260812 06:20:28.156186 12693 maintenance_manager.cc:419] P 1c76864c1a9945aa9ee4016cc79a06b9: Scheduling LogGCOp(3c558229b1dd406398610d0e58ddd0f4): free 124257190 bytes of WAL
I20260812 06:20:28.156591 12608 log_reader.cc:385] T 3c558229b1dd406398610d0e58ddd0f4: removed 12 log segments from log reader
I20260812 06:20:28.156672 12608 log.cc:1079] T 3c558229b1dd406398610d0e58ddd0f4 P 1c76864c1a9945aa9ee4016cc79a06b9: Deleting log segment in path: /tmp/dist-test-taskHG7JFS/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515618503783-12152-0/minicluster-data/ts-0-root/wals/3c558229b1dd406398610d0e58ddd0f4/wal-000000015 (ops 69-72)
I20260812 06:20:28.156756 12608 log.cc:1079] T 3c558229b1dd406398610d0e58ddd0f4 P 1c76864c1a9945aa9ee4016cc79a06b9: Deleting log segment in path: /tmp/dist-test-taskHG7JFS/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515618503783-12152-0/minicluster-data/ts-0-root/wals/3c558229b1dd406398610d0e58ddd0f4/wal-000000016 (ops 73-77)
I20260812 06:20:28.156849 12608 log.cc:1079] T 3c558229b1dd406398610d0e58ddd0f4 P 1c76864c1a9945aa9ee4016cc79a06b9: Deleting log segment in path: /tmp/dist-test-taskHG7JFS/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515618503783-12152-0/minicluster-data/ts-0-root/wals/3c558229b1dd406398610d0e58ddd0f4/wal-000000017 (ops 78-82)
I20260812 06:20:28.156932 12608 log.cc:1079] T 3c558229b1dd406398610d0e58ddd0f4 P 1c76864c1a9945aa9ee4016cc79a06b9: Deleting log segment in path: /tmp/dist-test-taskHG7JFS/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515618503783-12152-0/minicluster-data/ts-0-root/wals/3c558229b1dd406398610d0e58ddd0f4/wal-000000018 (ops 83-87)
I20260812 06:20:28.157017 12608 log.cc:1079] T 3c558229b1dd406398610d0e58ddd0f4 P 1c76864c1a9945aa9ee4016cc79a06b9: Deleting log segment in path: /tmp/dist-test-taskHG7JFS/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515618503783-12152-0/minicluster-data/ts-0-root/wals/3c558229b1dd406398610d0e58ddd0f4/wal-000000019 (ops 88-92)
I20260812 06:20:28.157081 12608 log.cc:1079] T 3c558229b1dd406398610d0e58ddd0f4 P 1c76864c1a9945aa9ee4016cc79a06b9: Deleting log segment in path: /tmp/dist-test-taskHG7JFS/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515618503783-12152-0/minicluster-data/ts-0-root/wals/3c558229b1dd406398610d0e58ddd0f4/wal-000000020 (ops 93-97)
I20260812 06:20:28.157174 12608 log.cc:1079] T 3c558229b1dd406398610d0e58ddd0f4 P 1c76864c1a9945aa9ee4016cc79a06b9: Deleting log segment in path: /tmp/dist-test-taskHG7JFS/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515618503783-12152-0/minicluster-data/ts-0-root/wals/3c558229b1dd406398610d0e58ddd0f4/wal-000000021 (ops 98-102)
I20260812 06:20:28.157274 12608 log.cc:1079] T 3c558229b1dd406398610d0e58ddd0f4 P 1c76864c1a9945aa9ee4016cc79a06b9: Deleting log segment in path: /tmp/dist-test-taskHG7JFS/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515618503783-12152-0/minicluster-data/ts-0-root/wals/3c558229b1dd406398610d0e58ddd0f4/wal-000000022 (ops 103-107)
I20260812 06:20:28.157344 12608 log.cc:1079] T 3c558229b1dd406398610d0e58ddd0f4 P 1c76864c1a9945aa9ee4016cc79a06b9: Deleting log segment in path: /tmp/dist-test-taskHG7JFS/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515618503783-12152-0/minicluster-data/ts-0-root/wals/3c558229b1dd406398610d0e58ddd0f4/wal-000000023 (ops 108-112)
I20260812 06:20:28.157420 12608 log.cc:1079] T 3c558229b1dd406398610d0e58ddd0f4 P 1c76864c1a9945aa9ee4016cc79a06b9: Deleting log segment in path: /tmp/dist-test-taskHG7JFS/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515618503783-12152-0/minicluster-data/ts-0-root/wals/3c558229b1dd406398610d0e58ddd0f4/wal-000000024 (ops 113-117)
I20260812 06:20:28.157500 12608 log.cc:1079] T 3c558229b1dd406398610d0e58ddd0f4 P 1c76864c1a9945aa9ee4016cc79a06b9: Deleting log segment in path: /tmp/dist-test-taskHG7JFS/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515618503783-12152-0/minicluster-data/ts-0-root/wals/3c558229b1dd406398610d0e58ddd0f4/wal-000000025 (ops 118-122)
I20260812 06:20:28.157578 12608 log.cc:1079] T 3c558229b1dd406398610d0e58ddd0f4 P 1c76864c1a9945aa9ee4016cc79a06b9: Deleting log segment in path: /tmp/dist-test-taskHG7JFS/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515618503783-12152-0/minicluster-data/ts-0-root/wals/3c558229b1dd406398610d0e58ddd0f4/wal-000000026 (ops 123-127)
I20260812 06:20:28.203647 12608 maintenance_manager.cc:643] P 1c76864c1a9945aa9ee4016cc79a06b9: LogGCOp(3c558229b1dd406398610d0e58ddd0f4) complete. Timing: real 0.047s	user 0.000s	sys 0.046s Metrics: {}
I20260812 06:20:28.204430 12693 maintenance_manager.cc:419] P 1c76864c1a9945aa9ee4016cc79a06b9: Scheduling UndoDeltaBlockGCOp(3c558229b1dd406398610d0e58ddd0f4): 483 bytes on disk
I20260812 06:20:28.205214 12608 maintenance_manager.cc:643] P 1c76864c1a9945aa9ee4016cc79a06b9: UndoDeltaBlockGCOp(3c558229b1dd406398610d0e58ddd0f4) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":98,"lbm_reads_lt_1ms":4}
I20260812 06:20:28.206223 12693 maintenance_manager.cc:419] P 1c76864c1a9945aa9ee4016cc79a06b9: Scheduling FlushDeltaMemStoresOp(3c558229b1dd406398610d0e58ddd0f4): perf score=3.181125
I20260812 06:20:28.229161 12608 maintenance_manager.cc:643] P 1c76864c1a9945aa9ee4016cc79a06b9: FlushDeltaMemStoresOp(3c558229b1dd406398610d0e58ddd0f4) complete. Timing: real 0.023s	user 0.016s	sys 0.004s Metrics: {"bytes_written":4512900,"delete_count":0,"lbm_write_time_us":9257,"lbm_writes_lt_1ms":113,"reinsert_count":0,"update_count":550}
I20260812 06:20:28.230079 12693 maintenance_manager.cc:419] P 1c76864c1a9945aa9ee4016cc79a06b9: Scheduling LogGCOp(3c558229b1dd406398610d0e58ddd0f4): free 12018000 bytes of WAL
I20260812 06:20:28.230414 12608 log_reader.cc:385] T 3c558229b1dd406398610d0e58ddd0f4: removed 1 log segments from log reader
I20260812 06:20:28.230479 12608 log.cc:1079] T 3c558229b1dd406398610d0e58ddd0f4 P 1c76864c1a9945aa9ee4016cc79a06b9: Deleting log segment in path: /tmp/dist-test-taskHG7JFS/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515618503783-12152-0/minicluster-data/ts-0-root/wals/3c558229b1dd406398610d0e58ddd0f4/wal-000000027 (ops 128-132)
I20260812 06:20:28.234264 12608 maintenance_manager.cc:643] P 1c76864c1a9945aa9ee4016cc79a06b9: LogGCOp(3c558229b1dd406398610d0e58ddd0f4) complete. Timing: real 0.004s	user 0.000s	sys 0.000s Metrics: {}
I20260812 06:20:28.234898 12693 maintenance_manager.cc:419] P 1c76864c1a9945aa9ee4016cc79a06b9: Scheduling FlushDeltaMemStoresOp(3c558229b1dd406398610d0e58ddd0f4): perf score=2.188937
I20260812 06:20:28.280336 12608 maintenance_manager.cc:643] P 1c76864c1a9945aa9ee4016cc79a06b9: FlushDeltaMemStoresOp(3c558229b1dd406398610d0e58ddd0f4) complete. Timing: real 0.045s	user 0.015s	sys 0.028s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":9645,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:20:28.281351 12693 maintenance_manager.cc:419] P 1c76864c1a9945aa9ee4016cc79a06b9: Scheduling MajorDeltaCompactionOp(3c558229b1dd406398610d0e58ddd0f4): perf score=1.000000
I20260812 06:20:28.730383 12608 maintenance_manager.cc:643] P 1c76864c1a9945aa9ee4016cc79a06b9: MajorDeltaCompactionOp(3c558229b1dd406398610d0e58ddd0f4) complete. Timing: real 0.449s	user 0.295s	sys 0.144s Metrics: {"cfile_cache_miss":735,"cfile_cache_miss_bytes":32979849,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":5,"delta_iterators_relevant":5,"dirs.queue_time_us":2083,"lbm_read_time_us":36534,"lbm_reads_lt_1ms":767,"lbm_write_time_us":79324,"lbm_writes_lt_1ms":743,"peak_mem_usage":87969044,"reinsert_count":0,"spinlock_wait_cycles":46848,"thread_start_us":807,"threads_started":7,"update_count":3500}
I20260812 06:20:28.731921 12693 maintenance_manager.cc:419] P 1c76864c1a9945aa9ee4016cc79a06b9: Scheduling FlushDeltaMemStoresOp(3c558229b1dd406398610d0e58ddd0f4): perf score=18.063937
I20260812 06:20:28.867511 12608 maintenance_manager.cc:643] P 1c76864c1a9945aa9ee4016cc79a06b9: FlushDeltaMemStoresOp(3c558229b1dd406398610d0e58ddd0f4) complete. Timing: real 0.135s	user 0.064s	sys 0.070s Metrics: {"bytes_written":20512317,"delete_count":0,"lbm_write_time_us":55976,"lbm_writes_lt_1ms":503,"reinsert_count":0,"update_count":2500}
I20260812 06:20:28.868453 12693 maintenance_manager.cc:419] P 1c76864c1a9945aa9ee4016cc79a06b9: Scheduling FlushDeltaMemStoresOp(3c558229b1dd406398610d0e58ddd0f4): perf score=2.188937
I20260812 06:20:28.889079 12608 maintenance_manager.cc:643] P 1c76864c1a9945aa9ee4016cc79a06b9: FlushDeltaMemStoresOp(3c558229b1dd406398610d0e58ddd0f4) complete. Timing: real 0.020s	user 0.013s	sys 0.005s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":8434,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:28.889863 12693 maintenance_manager.cc:419] P 1c76864c1a9945aa9ee4016cc79a06b9: Scheduling MajorDeltaCompactionOp(3c558229b1dd406398610d0e58ddd0f4): perf score=1.000000
I20260812 06:20:29.268641 12608 maintenance_manager.cc:643] P 1c76864c1a9945aa9ee4016cc79a06b9: MajorDeltaCompactionOp(3c558229b1dd406398610d0e58ddd0f4) complete. Timing: real 0.378s	user 0.261s	sys 0.103s Metrics: {"cfile_cache_miss":632,"cfile_cache_miss_bytes":28877104,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":584,"lbm_read_time_us":28432,"lbm_reads_lt_1ms":672,"lbm_write_time_us":68708,"lbm_writes_lt_1ms":643,"mutex_wait_us":54,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":23936,"thread_start_us":661,"threads_started":5,"update_count":3000}
I20260812 06:20:29.269831 12693 maintenance_manager.cc:419] P 1c76864c1a9945aa9ee4016cc79a06b9: Scheduling FlushDeltaMemStoresOp(3c558229b1dd406398610d0e58ddd0f4): perf score=14.095187
I20260812 06:20:29.386168 12608 maintenance_manager.cc:643] P 1c76864c1a9945aa9ee4016cc79a06b9: FlushDeltaMemStoresOp(3c558229b1dd406398610d0e58ddd0f4) complete. Timing: real 0.116s	user 0.057s	sys 0.032s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":41883,"lbm_writes_lt_1ms":403,"mutex_wait_us":3,"reinsert_count":0,"update_count":2000}
I20260812 06:20:29.387329 12693 maintenance_manager.cc:419] P 1c76864c1a9945aa9ee4016cc79a06b9: Scheduling FlushDeltaMemStoresOp(3c558229b1dd406398610d0e58ddd0f4): perf score=2.188937
I20260812 06:20:29.407181 12608 maintenance_manager.cc:643] P 1c76864c1a9945aa9ee4016cc79a06b9: FlushDeltaMemStoresOp(3c558229b1dd406398610d0e58ddd0f4) complete. Timing: real 0.019s	user 0.016s	sys 0.003s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":7391,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:29.408236 12693 maintenance_manager.cc:419] P 1c76864c1a9945aa9ee4016cc79a06b9: Scheduling MajorDeltaCompactionOp(3c558229b1dd406398610d0e58ddd0f4): perf score=1.000000
I20260812 06:20:29.704605 12608 maintenance_manager.cc:643] P 1c76864c1a9945aa9ee4016cc79a06b9: MajorDeltaCompactionOp(3c558229b1dd406398610d0e58ddd0f4) complete. Timing: real 0.296s	user 0.181s	sys 0.112s 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":359,"lbm_read_time_us":44648,"lbm_reads_lt_1ms":572,"lbm_write_time_us":30382,"lbm_writes_lt_1ms":543,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":6528,"update_count":2500}
I20260812 06:20:29.705370 12693 maintenance_manager.cc:419] P 1c76864c1a9945aa9ee4016cc79a06b9: Scheduling FlushDeltaMemStoresOp(3c558229b1dd406398610d0e58ddd0f4): perf score=14.095187
I20260812 06:20:29.769039 12608 maintenance_manager.cc:643] P 1c76864c1a9945aa9ee4016cc79a06b9: FlushDeltaMemStoresOp(3c558229b1dd406398610d0e58ddd0f4) complete. Timing: real 0.063s	user 0.026s	sys 0.030s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":20864,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:20:29.769727 12693 maintenance_manager.cc:419] P 1c76864c1a9945aa9ee4016cc79a06b9: Scheduling FlushDeltaMemStoresOp(3c558229b1dd406398610d0e58ddd0f4): perf score=2.188937
I20260812 06:20:29.782083 12608 maintenance_manager.cc:643] P 1c76864c1a9945aa9ee4016cc79a06b9: FlushDeltaMemStoresOp(3c558229b1dd406398610d0e58ddd0f4) complete. Timing: real 0.012s	user 0.007s	sys 0.003s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4816,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:29.782624 12693 maintenance_manager.cc:419] P 1c76864c1a9945aa9ee4016cc79a06b9: Scheduling MajorDeltaCompactionOp(3c558229b1dd406398610d0e58ddd0f4): perf score=1.000000
I20260812 06:20:29.987461 12608 maintenance_manager.cc:643] P 1c76864c1a9945aa9ee4016cc79a06b9: MajorDeltaCompactionOp(3c558229b1dd406398610d0e58ddd0f4) complete. Timing: real 0.205s	user 0.124s	sys 0.069s 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":341,"lbm_read_time_us":14267,"lbm_reads_lt_1ms":572,"lbm_write_time_us":32361,"lbm_writes_lt_1ms":543,"mutex_wait_us":69,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":20736,"update_count":2500}
I20260812 06:20:29.988152 12693 maintenance_manager.cc:419] P 1c76864c1a9945aa9ee4016cc79a06b9: Scheduling FlushDeltaMemStoresOp(3c558229b1dd406398610d0e58ddd0f4): perf score=14.095187
I20260812 06:20:30.057610 12608 maintenance_manager.cc:643] P 1c76864c1a9945aa9ee4016cc79a06b9: FlushDeltaMemStoresOp(3c558229b1dd406398610d0e58ddd0f4) complete. Timing: real 0.069s	user 0.023s	sys 0.031s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":20078,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:20:30.058266 12693 maintenance_manager.cc:419] P 1c76864c1a9945aa9ee4016cc79a06b9: Scheduling FlushDeltaMemStoresOp(3c558229b1dd406398610d0e58ddd0f4): perf score=2.188937
I20260812 06:20:30.071014 12608 maintenance_manager.cc:643] P 1c76864c1a9945aa9ee4016cc79a06b9: FlushDeltaMemStoresOp(3c558229b1dd406398610d0e58ddd0f4) complete. Timing: real 0.012s	user 0.012s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4823,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:30.071642 12693 maintenance_manager.cc:419] P 1c76864c1a9945aa9ee4016cc79a06b9: Scheduling MajorDeltaCompactionOp(3c558229b1dd406398610d0e58ddd0f4): perf score=1.000000
I20260812 06:20:30.289976 12608 maintenance_manager.cc:643] P 1c76864c1a9945aa9ee4016cc79a06b9: MajorDeltaCompactionOp(3c558229b1dd406398610d0e58ddd0f4) complete. Timing: real 0.218s	user 0.136s	sys 0.075s 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":341,"lbm_read_time_us":15754,"lbm_reads_lt_1ms":572,"lbm_write_time_us":34951,"lbm_writes_lt_1ms":543,"mutex_wait_us":2,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":8320,"update_count":2500}
I20260812 06:20:30.290730 12693 maintenance_manager.cc:419] P 1c76864c1a9945aa9ee4016cc79a06b9: Scheduling FlushDeltaMemStoresOp(3c558229b1dd406398610d0e58ddd0f4): perf score=14.095187
I20260812 06:20:30.345517 12608 maintenance_manager.cc:643] P 1c76864c1a9945aa9ee4016cc79a06b9: FlushDeltaMemStoresOp(3c558229b1dd406398610d0e58ddd0f4) complete. Timing: real 0.054s	user 0.031s	sys 0.017s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":22739,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:20:30.346133 12693 maintenance_manager.cc:419] P 1c76864c1a9945aa9ee4016cc79a06b9: Scheduling FlushDeltaMemStoresOp(3c558229b1dd406398610d0e58ddd0f4): perf score=2.188937
I20260812 06:20:30.369306 12608 maintenance_manager.cc:643] P 1c76864c1a9945aa9ee4016cc79a06b9: FlushDeltaMemStoresOp(3c558229b1dd406398610d0e58ddd0f4) complete. Timing: real 0.023s	user 0.006s	sys 0.014s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4215,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:30.369985 12693 maintenance_manager.cc:419] P 1c76864c1a9945aa9ee4016cc79a06b9: Scheduling FlushMRSOp(3c558229b1dd406398610d0e58ddd0f4): perf score=1.000000
I20260812 06:20:30.407209 12608 maintenance_manager.cc:643] P 1c76864c1a9945aa9ee4016cc79a06b9: FlushMRSOp(3c558229b1dd406398610d0e58ddd0f4) complete. Timing: real 0.037s	user 0.027s	sys 0.000s Metrics: {"bytes_written":1152510,"cfile_init":1,"dirs.queue_time_us":72,"dirs.run_cpu_time_us":203,"dirs.run_wall_time_us":1354,"drs_written":1,"lbm_read_time_us":37,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1610,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":28}
I20260812 06:20:30.408156 12693 maintenance_manager.cc:419] P 1c76864c1a9945aa9ee4016cc79a06b9: Scheduling LogGCOp(3c558229b1dd406398610d0e58ddd0f4): free 108535632 bytes of WAL
I20260812 06:20:30.408461 12608 log_reader.cc:385] T 3c558229b1dd406398610d0e58ddd0f4: removed 11 log segments from log reader
I20260812 06:20:30.408540 12608 log.cc:1079] T 3c558229b1dd406398610d0e58ddd0f4 P 1c76864c1a9945aa9ee4016cc79a06b9: Deleting log segment in path: /tmp/dist-test-taskHG7JFS/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515618503783-12152-0/minicluster-data/ts-0-root/wals/3c558229b1dd406398610d0e58ddd0f4/wal-000000028 (ops 133-137)
I20260812 06:20:30.408596 12608 log.cc:1079] T 3c558229b1dd406398610d0e58ddd0f4 P 1c76864c1a9945aa9ee4016cc79a06b9: Deleting log segment in path: /tmp/dist-test-taskHG7JFS/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515618503783-12152-0/minicluster-data/ts-0-root/wals/3c558229b1dd406398610d0e58ddd0f4/wal-000000029 (ops 138-142)
I20260812 06:20:30.408654 12608 log.cc:1079] T 3c558229b1dd406398610d0e58ddd0f4 P 1c76864c1a9945aa9ee4016cc79a06b9: Deleting log segment in path: /tmp/dist-test-taskHG7JFS/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515618503783-12152-0/minicluster-data/ts-0-root/wals/3c558229b1dd406398610d0e58ddd0f4/wal-000000030 (ops 143-146)
I20260812 06:20:30.408696 12608 log.cc:1079] T 3c558229b1dd406398610d0e58ddd0f4 P 1c76864c1a9945aa9ee4016cc79a06b9: Deleting log segment in path: /tmp/dist-test-taskHG7JFS/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515618503783-12152-0/minicluster-data/ts-0-root/wals/3c558229b1dd406398610d0e58ddd0f4/wal-000000031 (ops 147-151)
I20260812 06:20:30.408733 12608 log.cc:1079] T 3c558229b1dd406398610d0e58ddd0f4 P 1c76864c1a9945aa9ee4016cc79a06b9: Deleting log segment in path: /tmp/dist-test-taskHG7JFS/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515618503783-12152-0/minicluster-data/ts-0-root/wals/3c558229b1dd406398610d0e58ddd0f4/wal-000000032 (ops 152-156)
I20260812 06:20:30.408777 12608 log.cc:1079] T 3c558229b1dd406398610d0e58ddd0f4 P 1c76864c1a9945aa9ee4016cc79a06b9: Deleting log segment in path: /tmp/dist-test-taskHG7JFS/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515618503783-12152-0/minicluster-data/ts-0-root/wals/3c558229b1dd406398610d0e58ddd0f4/wal-000000033 (ops 157-160)
I20260812 06:20:30.408816 12608 log.cc:1079] T 3c558229b1dd406398610d0e58ddd0f4 P 1c76864c1a9945aa9ee4016cc79a06b9: Deleting log segment in path: /tmp/dist-test-taskHG7JFS/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515618503783-12152-0/minicluster-data/ts-0-root/wals/3c558229b1dd406398610d0e58ddd0f4/wal-000000034 (ops 161-165)
I20260812 06:20:30.408854 12608 log.cc:1079] T 3c558229b1dd406398610d0e58ddd0f4 P 1c76864c1a9945aa9ee4016cc79a06b9: Deleting log segment in path: /tmp/dist-test-taskHG7JFS/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515618503783-12152-0/minicluster-data/ts-0-root/wals/3c558229b1dd406398610d0e58ddd0f4/wal-000000035 (ops 166-170)
I20260812 06:20:30.408892 12608 log.cc:1079] T 3c558229b1dd406398610d0e58ddd0f4 P 1c76864c1a9945aa9ee4016cc79a06b9: Deleting log segment in path: /tmp/dist-test-taskHG7JFS/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515618503783-12152-0/minicluster-data/ts-0-root/wals/3c558229b1dd406398610d0e58ddd0f4/wal-000000036 (ops 171-175)
I20260812 06:20:30.408938 12608 log.cc:1079] T 3c558229b1dd406398610d0e58ddd0f4 P 1c76864c1a9945aa9ee4016cc79a06b9: Deleting log segment in path: /tmp/dist-test-taskHG7JFS/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515618503783-12152-0/minicluster-data/ts-0-root/wals/3c558229b1dd406398610d0e58ddd0f4/wal-000000037 (ops 176-180)
I20260812 06:20:30.408977 12608 log.cc:1079] T 3c558229b1dd406398610d0e58ddd0f4 P 1c76864c1a9945aa9ee4016cc79a06b9: Deleting log segment in path: /tmp/dist-test-taskHG7JFS/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515618503783-12152-0/minicluster-data/ts-0-root/wals/3c558229b1dd406398610d0e58ddd0f4/wal-000000038 (ops 181-185)
I20260812 06:20:30.433293 12608 maintenance_manager.cc:643] P 1c76864c1a9945aa9ee4016cc79a06b9: LogGCOp(3c558229b1dd406398610d0e58ddd0f4) complete. Timing: real 0.025s	user 0.000s	sys 0.022s Metrics: {}
I20260812 06:20:30.433880 12693 maintenance_manager.cc:419] P 1c76864c1a9945aa9ee4016cc79a06b9: Scheduling UndoDeltaBlockGCOp(3c558229b1dd406398610d0e58ddd0f4): 448 bytes on disk
I20260812 06:20:30.434417 12608 maintenance_manager.cc:643] P 1c76864c1a9945aa9ee4016cc79a06b9: UndoDeltaBlockGCOp(3c558229b1dd406398610d0e58ddd0f4) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":57,"lbm_reads_lt_1ms":4}
I20260812 06:20:30.435438 12693 maintenance_manager.cc:419] P 1c76864c1a9945aa9ee4016cc79a06b9: Scheduling FlushDeltaMemStoresOp(3c558229b1dd406398610d0e58ddd0f4): perf score=2.188937
I20260812 06:20:30.457947 12608 maintenance_manager.cc:643] P 1c76864c1a9945aa9ee4016cc79a06b9: FlushDeltaMemStoresOp(3c558229b1dd406398610d0e58ddd0f4) complete. Timing: real 0.022s	user 0.005s	sys 0.005s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4669,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:30.458526 12693 maintenance_manager.cc:419] P 1c76864c1a9945aa9ee4016cc79a06b9: Scheduling FlushDeltaMemStoresOp(3c558229b1dd406398610d0e58ddd0f4): perf score=2.188937
I20260812 06:20:30.469872 12608 maintenance_manager.cc:643] P 1c76864c1a9945aa9ee4016cc79a06b9: FlushDeltaMemStoresOp(3c558229b1dd406398610d0e58ddd0f4) complete. Timing: real 0.011s	user 0.010s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4096,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:30.470785 12693 maintenance_manager.cc:419] P 1c76864c1a9945aa9ee4016cc79a06b9: Scheduling MajorDeltaCompactionOp(3c558229b1dd406398610d0e58ddd0f4): perf score=1.000000
I20260812 06:20:30.732014 12608 maintenance_manager.cc:643] P 1c76864c1a9945aa9ee4016cc79a06b9: MajorDeltaCompactionOp(3c558229b1dd406398610d0e58ddd0f4) complete. Timing: real 0.261s	user 0.175s	sys 0.084s Metrics: {"cfile_cache_miss":734,"cfile_cache_miss_bytes":32979750,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":1337,"lbm_read_time_us":16230,"lbm_reads_lt_1ms":774,"lbm_write_time_us":45180,"lbm_writes_lt_1ms":743,"mutex_wait_us":486,"peak_mem_usage":87969044,"reinsert_count":0,"spinlock_wait_cycles":16768,"thread_start_us":150,"threads_started":1,"update_count":3500}
I20260812 06:20:30.732980 12693 maintenance_manager.cc:419] P 1c76864c1a9945aa9ee4016cc79a06b9: Scheduling FlushDeltaMemStoresOp(3c558229b1dd406398610d0e58ddd0f4): perf score=18.063937
I20260812 06:20:30.807507 12152 heavy-update-compaction-itest.cc:229] Time spent updating: real 6.067s	user 2.156s	sys 0.192s
I20260812 06:20:30.811990 12608 maintenance_manager.cc:643] P 1c76864c1a9945aa9ee4016cc79a06b9: FlushDeltaMemStoresOp(3c558229b1dd406398610d0e58ddd0f4) complete. Timing: real 0.079s	user 0.038s	sys 0.027s Metrics: {"bytes_written":20512315,"delete_count":0,"lbm_write_time_us":33351,"lbm_writes_1-10_ms":3,"lbm_writes_lt_1ms":500,"reinsert_count":0,"spinlock_wait_cycles":1280,"update_count":2500}
I20260812 06:20:30.812603 12693 maintenance_manager.cc:419] P 1c76864c1a9945aa9ee4016cc79a06b9: Scheduling FlushDeltaMemStoresOp(3c558229b1dd406398610d0e58ddd0f4): perf score=2.188937
I20260812 06:20:30.823706 12608 maintenance_manager.cc:643] P 1c76864c1a9945aa9ee4016cc79a06b9: FlushDeltaMemStoresOp(3c558229b1dd406398610d0e58ddd0f4) complete. Timing: real 0.011s	user 0.005s	sys 0.005s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4471,"lbm_writes_lt_1ms":103,"reinsert_count":0,"spinlock_wait_cycles":1280,"update_count":500}
I20260812 06:20:30.824230 12693 maintenance_manager.cc:419] P 1c76864c1a9945aa9ee4016cc79a06b9: Scheduling MajorDeltaCompactionOp(3c558229b1dd406398610d0e58ddd0f4): perf score=1.000000
I20260812 06:20:30.887404 12152 heavy-update-compaction-itest.cc:265] Time spent scanning: real 0.079s	user 0.002s	sys 0.000s
I20260812 06:20:30.887986 12152 tablet_server.cc:179] TabletServer@127.11.222.1:0 shutting down...
I20260812 06:20:30.987452 12608 maintenance_manager.cc:643] P 1c76864c1a9945aa9ee4016cc79a06b9: MajorDeltaCompactionOp(3c558229b1dd406398610d0e58ddd0f4) complete. Timing: real 0.163s	user 0.139s	sys 0.023s Metrics: {"cfile_cache_hit":277,"cfile_cache_hit_bytes":11325717,"cfile_cache_miss":355,"cfile_cache_miss_bytes":17551385,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":979,"lbm_read_time_us":9535,"lbm_reads_lt_1ms":387,"lbm_write_time_us":32673,"lbm_writes_lt_1ms":643,"mutex_wait_us":114,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":112128,"update_count":3000}
I20260812 06:20:30.988137 12152 ts_tablet_manager.cc:1507] Shutting down tablet manager...
I20260812 06:20:30.988437 12152 tablet_replica.cc:333] T 3c558229b1dd406398610d0e58ddd0f4 P 1c76864c1a9945aa9ee4016cc79a06b9: stopping tablet replica
I20260812 06:20:30.988611 12152 raft_consensus.cc:2243] T 3c558229b1dd406398610d0e58ddd0f4 P 1c76864c1a9945aa9ee4016cc79a06b9 [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:20:30.988804 12152 raft_consensus.cc:2272] T 3c558229b1dd406398610d0e58ddd0f4 P 1c76864c1a9945aa9ee4016cc79a06b9 [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:20:31.005661 12152 tablet_server.cc:196] TabletServer@127.11.222.1:0 shutdown complete.
I20260812 06:20:31.040488 12152 master.cc:562] Master@127.11.222.62:45921 shutting down...
I20260812 06:20:31.044016 12152 raft_consensus.cc:2243] T 00000000000000000000000000000000 P b67b75bb4312498d903b75559f7c8b57 [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:20:31.044262 12152 raft_consensus.cc:2272] T 00000000000000000000000000000000 P b67b75bb4312498d903b75559f7c8b57 [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:20:31.044354 12152 tablet_replica.cc:333] T 00000000000000000000000000000000 P b67b75bb4312498d903b75559f7c8b57: stopping tablet replica
I20260812 06:20:31.057237 12152 master.cc:584] Master@127.11.222.62:45921 shutdown complete.
[       OK ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/1 (6633 ms)
[----------] 2 tests from EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy (12639 ms total)

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