[==========] Running 2 tests from 1 test suite.
[----------] Global test environment set-up.
[----------] 2 tests from EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy
[ RUN      ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/0
WARNING: Logging before InitGoogleLogging() is written to STDERR
I20260812 06:17:46.915833  8794 internal_mini_cluster.cc:156] Creating distributed mini masters. Addrs: 127.8.150.190:46277
I20260812 06:17:46.916745  8794 env_posix.cc:2285] Not raising this process' open files per process limit of 1048576; it is already as high as it can go
I20260812 06:17:46.917323  8794 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:17:46.923017  8802 instance_detector.cc:116] could not retrieve Azure instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:17:46.923054  8801 instance_detector.cc:116] could not retrieve AWS instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:17:46.923302  8806 instance_detector.cc:116] could not retrieve OpenStack instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:17:46.923421  8794 server_base.cc:1061] running on GCE node
I20260812 06:17:46.923866  8794 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:17:46.923960  8794 system_unsync_time.cc:38] NTP support is disabled. Clock error bounds will not be accurate. This configuration is not suitable for distributed clusters.
I20260812 06:17:46.924002  8794 hybrid_clock.cc:648] HybridClock initialized: now 1786515466924000 us; error 0 us; skew 500 ppm
I20260812 06:17:46.925642  8794 webserver.cc:533] Webserver started at http://127.8.150.190:43115/ using document root <none> and password file <none>
I20260812 06:17:46.926127  8794 fs_manager.cc:362] Metadata directory not provided
I20260812 06:17:46.926186  8794 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:17:46.926400  8794 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:17:46.927934  8794 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskB0FmHn/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515466905639-8794-0/minicluster-data/master-0-root/instance:
uuid: "4310b703530d45f9980bc52cb117a3c5"
format_stamp: "Formatted at 2026-08-12 06:17:46 on dist-test-slave-k5rr"
I20260812 06:17:46.931234  8794 fs_manager.cc:696] Time spent creating directory manager: real 0.003s	user 0.001s	sys 0.003s
I20260812 06:17:46.933262  8814 log_block_manager.cc:4127] Time spent loading block containers with low live blocks: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:17:46.934257  8794 fs_manager.cc:730] Time spent opening block manager: real 0.002s	user 0.002s	sys 0.001s
I20260812 06:17:46.934371  8794 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskB0FmHn/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515466905639-8794-0/minicluster-data/master-0-root
uuid: "4310b703530d45f9980bc52cb117a3c5"
format_stamp: "Formatted at 2026-08-12 06:17:46 on dist-test-slave-k5rr"
I20260812 06:17:46.934461  8794 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskB0FmHn/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515466905639-8794-0/minicluster-data/master-0-root
metadata directory: /tmp/dist-test-taskB0FmHn/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515466905639-8794-0/minicluster-data/master-0-root
1 data directories: /tmp/dist-test-taskB0FmHn/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515466905639-8794-0/minicluster-data/master-0-root/data
Total live blocks: 0
Total live bytes: 0
Total live bytes (after alignment): 0
Total number of LBM containers: 0 (0 full)
Did not check for missing blocks
Did not check for orphaned blocks
Total full LBM containers with extra space: 0 (0 repaired)
Total full LBM container extra space in bytes: 0 (0 repaired)
Total incomplete LBM containers: 0 (0 repaired)
Total LBM partial records: 0 (0 repaired)
Total corrupted LBM metadata records in RocksDB: 0 (0 repaired)
I20260812 06:17:46.955956  8794 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:17:46.956548  8794 env_posix.cc:2285] Not raising this process' running threads per effective uid limit of 18446744073709551615; it is already as high as it can go
I20260812 06:17:46.956720  8794 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:17:46.964191  8893 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.8.150.190:46277 every 8 connection(s)
I20260812 06:17:46.964198  8794 rpc_server.cc:307] RPC server started. Bound to: 127.8.150.190:46277
I20260812 06:17:46.966421  8896 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet 00000000000000000000000000000000. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:17:46.971741  8896 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P 4310b703530d45f9980bc52cb117a3c5: Bootstrap starting.
I20260812 06:17:46.974067  8896 tablet_bootstrap.cc:654] T 00000000000000000000000000000000 P 4310b703530d45f9980bc52cb117a3c5: Neither blocks nor log segments found. Creating new log.
I20260812 06:17:46.974932  8896 log.cc:826] T 00000000000000000000000000000000 P 4310b703530d45f9980bc52cb117a3c5: Log is configured to *not* fsync() on all Append() calls
I20260812 06:17:46.976517  8896 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P 4310b703530d45f9980bc52cb117a3c5: No bootstrap required, opened a new log
I20260812 06:17:46.979262  8896 raft_consensus.cc:359] T 00000000000000000000000000000000 P 4310b703530d45f9980bc52cb117a3c5 [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "4310b703530d45f9980bc52cb117a3c5" member_type: VOTER }
I20260812 06:17:46.979431  8896 raft_consensus.cc:385] T 00000000000000000000000000000000 P 4310b703530d45f9980bc52cb117a3c5 [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:17:46.979476  8896 raft_consensus.cc:740] T 00000000000000000000000000000000 P 4310b703530d45f9980bc52cb117a3c5 [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: 4310b703530d45f9980bc52cb117a3c5, State: Initialized, Role: FOLLOWER
I20260812 06:17:46.980101  8896 consensus_queue.cc:260] T 00000000000000000000000000000000 P 4310b703530d45f9980bc52cb117a3c5 [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: "4310b703530d45f9980bc52cb117a3c5" member_type: VOTER }
I20260812 06:17:46.980259  8896 raft_consensus.cc:399] T 00000000000000000000000000000000 P 4310b703530d45f9980bc52cb117a3c5 [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:17:46.980324  8896 raft_consensus.cc:493] T 00000000000000000000000000000000 P 4310b703530d45f9980bc52cb117a3c5 [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:17:46.980444  8896 raft_consensus.cc:3060] T 00000000000000000000000000000000 P 4310b703530d45f9980bc52cb117a3c5 [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:17:46.981251  8896 raft_consensus.cc:515] T 00000000000000000000000000000000 P 4310b703530d45f9980bc52cb117a3c5 [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "4310b703530d45f9980bc52cb117a3c5" member_type: VOTER }
I20260812 06:17:46.981678  8896 leader_election.cc:304] T 00000000000000000000000000000000 P 4310b703530d45f9980bc52cb117a3c5 [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: 4310b703530d45f9980bc52cb117a3c5; no voters: 
I20260812 06:17:46.981979  8896 leader_election.cc:290] T 00000000000000000000000000000000 P 4310b703530d45f9980bc52cb117a3c5 [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:17:46.982124  8903 raft_consensus.cc:2804] T 00000000000000000000000000000000 P 4310b703530d45f9980bc52cb117a3c5 [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:17:46.982357  8903 raft_consensus.cc:697] T 00000000000000000000000000000000 P 4310b703530d45f9980bc52cb117a3c5 [term 1 LEADER]: Becoming Leader. State: Replica: 4310b703530d45f9980bc52cb117a3c5, State: Running, Role: LEADER
I20260812 06:17:46.982740  8903 consensus_queue.cc:237] T 00000000000000000000000000000000 P 4310b703530d45f9980bc52cb117a3c5 [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: "4310b703530d45f9980bc52cb117a3c5" member_type: VOTER }
I20260812 06:17:46.982932  8896 sys_catalog.cc:565] T 00000000000000000000000000000000 P 4310b703530d45f9980bc52cb117a3c5 [sys.catalog]: configured and running, proceeding with master startup.
I20260812 06:17:46.984490  8904 sys_catalog.cc:455] T 00000000000000000000000000000000 P 4310b703530d45f9980bc52cb117a3c5 [sys.catalog]: SysCatalogTable state changed. Reason: RaftConsensus started. Latest consensus state: current_term: 1 leader_uuid: "4310b703530d45f9980bc52cb117a3c5" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "4310b703530d45f9980bc52cb117a3c5" member_type: VOTER } }
I20260812 06:17:46.984469  8907 sys_catalog.cc:455] T 00000000000000000000000000000000 P 4310b703530d45f9980bc52cb117a3c5 [sys.catalog]: SysCatalogTable state changed. Reason: New leader 4310b703530d45f9980bc52cb117a3c5. Latest consensus state: current_term: 1 leader_uuid: "4310b703530d45f9980bc52cb117a3c5" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "4310b703530d45f9980bc52cb117a3c5" member_type: VOTER } }
I20260812 06:17:46.984612  8904 sys_catalog.cc:458] T 00000000000000000000000000000000 P 4310b703530d45f9980bc52cb117a3c5 [sys.catalog]: This master's current role is: LEADER
I20260812 06:17:46.984612  8907 sys_catalog.cc:458] T 00000000000000000000000000000000 P 4310b703530d45f9980bc52cb117a3c5 [sys.catalog]: This master's current role is: LEADER
I20260812 06:17:46.984963  8927 catalog_manager.cc:1511] Loading table and tablet metadata into memory...
I20260812 06:17:46.985136  8794 internal_mini_cluster.cc:184] Waiting to initialize catalog manager on master 0
I20260812 06:17:46.987167  8927 catalog_manager.cc:1520] Initializing Kudu cluster ID...
I20260812 06:17:46.991465  8927 catalog_manager.cc:1383] Generated new cluster ID: b1227540970e47adb89a32e5b66647b0
I20260812 06:17:46.991531  8927 catalog_manager.cc:1531] Initializing Kudu internal certificate authority...
I20260812 06:17:46.999609  8927 catalog_manager.cc:1406] Generated new certificate authority record
I20260812 06:17:47.000735  8927 catalog_manager.cc:1540] Loading token signing keys...
I20260812 06:17:47.018690  8927 catalog_manager.cc:6092] T 00000000000000000000000000000000 P 4310b703530d45f9980bc52cb117a3c5: Generated new TSK 0
I20260812 06:17:47.019462  8927 catalog_manager.cc:1550] Initializing in-progress tserver states...
I20260812 06:17:47.049939  8794 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:17:47.052683  8940 instance_detector.cc:116] could not retrieve Azure instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:17:47.052677  8938 instance_detector.cc:116] could not retrieve AWS instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:17:47.052814  8943 instance_detector.cc:116] could not retrieve OpenStack instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:17:47.052830  8794 server_base.cc:1061] running on GCE node
I20260812 06:17:47.053229  8794 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:17:47.053275  8794 system_unsync_time.cc:38] NTP support is disabled. Clock error bounds will not be accurate. This configuration is not suitable for distributed clusters.
I20260812 06:17:47.053292  8794 hybrid_clock.cc:648] HybridClock initialized: now 1786515467053291 us; error 0 us; skew 500 ppm
I20260812 06:17:47.054138  8794 webserver.cc:533] Webserver started at http://127.8.150.129:34713/ using document root <none> and password file <none>
I20260812 06:17:47.054315  8794 fs_manager.cc:362] Metadata directory not provided
I20260812 06:17:47.054364  8794 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:17:47.054440  8794 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:17:47.054831  8794 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskB0FmHn/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515466905639-8794-0/minicluster-data/ts-0-root/instance:
uuid: "7095a22e55a04de78a77e114367cab2f"
format_stamp: "Formatted at 2026-08-12 06:17:47 on dist-test-slave-k5rr"
I20260812 06:17:47.056298  8794 fs_manager.cc:696] Time spent creating directory manager: real 0.001s	user 0.002s	sys 0.000s
I20260812 06:17:47.057278  8951 log_block_manager.cc:4127] Time spent loading block containers with low live blocks: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:17:47.057492  8794 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.001s	sys 0.000s
I20260812 06:17:47.057564  8794 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskB0FmHn/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515466905639-8794-0/minicluster-data/ts-0-root
uuid: "7095a22e55a04de78a77e114367cab2f"
format_stamp: "Formatted at 2026-08-12 06:17:47 on dist-test-slave-k5rr"
I20260812 06:17:47.057637  8794 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskB0FmHn/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515466905639-8794-0/minicluster-data/ts-0-root
metadata directory: /tmp/dist-test-taskB0FmHn/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515466905639-8794-0/minicluster-data/ts-0-root
1 data directories: /tmp/dist-test-taskB0FmHn/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515466905639-8794-0/minicluster-data/ts-0-root/data
Total live blocks: 0
Total live bytes: 0
Total live bytes (after alignment): 0
Total number of LBM containers: 0 (0 full)
Did not check for missing blocks
Did not check for orphaned blocks
Total full LBM containers with extra space: 0 (0 repaired)
Total full LBM container extra space in bytes: 0 (0 repaired)
Total incomplete LBM containers: 0 (0 repaired)
Total LBM partial records: 0 (0 repaired)
Total corrupted LBM metadata records in RocksDB: 0 (0 repaired)
I20260812 06:17:47.090389  8794 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:17:47.090852  8794 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:17:47.091310  8794 txn_system_client.cc:432] TxnSystemClient initialization is disabled...
I20260812 06:17:47.092206  8794 ts_tablet_manager.cc:585] Loaded tablet metadata (0 total tablets, 0 live tablets)
I20260812 06:17:47.092263  8794 ts_tablet_manager.cc:531] Time spent load tablet metadata: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:17:47.092308  8794 ts_tablet_manager.cc:616] Registered 0 tablets
I20260812 06:17:47.092331  8794 ts_tablet_manager.cc:595] Time spent register tablets: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:17:47.098315  8794 rpc_server.cc:307] RPC server started. Bound to: 127.8.150.129:33481
I20260812 06:17:47.098356  9069 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.8.150.129:33481 every 8 connection(s)
I20260812 06:17:47.116954  9070 heartbeater.cc:344] Connected to a master server at 127.8.150.190:46277
I20260812 06:17:47.117233  9070 heartbeater.cc:461] Registering TS with master...
I20260812 06:17:47.117713  9070 heartbeater.cc:507] Master 127.8.150.190:46277 requested a full tablet report, sending...
I20260812 06:17:47.119127  8837 ts_manager.cc:194] Registered new tserver with Master: 7095a22e55a04de78a77e114367cab2f (127.8.150.129:33481)
I20260812 06:17:47.119717  8794 internal_mini_cluster.cc:371] 1 TS(s) registered with all masters after 0.020828549s
I20260812 06:17:47.120514  8837 master_service.cc:502] Signed X509 certificate for tserver {username='slave'} at 127.0.0.1:33886
I20260812 06:17:47.129282  8837 catalog_manager.cc:2283] Servicing CreateTable request from {username='slave'} at 127.0.0.1:33890:
name: "heavy-update-compaction-test"
schema {
  columns {
    name: "key"
    type: INT64
    is_key: true
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_a"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_b"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_c"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_d"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_e"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
}
num_replicas: 1
split_rows_range_bounds {
}
partition_schema {
  range_schema {
  }
}
I20260812 06:17:47.141882  9000 tablet_service.cc:1511] Processing CreateTablet for tablet 5e5ef4c2801e454cb784c9d74645915e (DEFAULT_TABLE table=heavy-update-compaction-test [id=c151dacce99d497eb4cc33ad27bdcb48]), partition=
I20260812 06:17:47.142298  9000 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet 5e5ef4c2801e454cb784c9d74645915e. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:17:47.144594  9091 tablet_bootstrap.cc:492] T 5e5ef4c2801e454cb784c9d74645915e P 7095a22e55a04de78a77e114367cab2f: Bootstrap starting.
I20260812 06:17:47.145480  9091 tablet_bootstrap.cc:654] T 5e5ef4c2801e454cb784c9d74645915e P 7095a22e55a04de78a77e114367cab2f: Neither blocks nor log segments found. Creating new log.
I20260812 06:17:47.146579  9091 tablet_bootstrap.cc:492] T 5e5ef4c2801e454cb784c9d74645915e P 7095a22e55a04de78a77e114367cab2f: No bootstrap required, opened a new log
I20260812 06:17:47.146692  9091 ts_tablet_manager.cc:1403] T 5e5ef4c2801e454cb784c9d74645915e P 7095a22e55a04de78a77e114367cab2f: Time spent bootstrapping tablet: real 0.002s	user 0.001s	sys 0.000s
I20260812 06:17:47.147137  9091 raft_consensus.cc:359] T 5e5ef4c2801e454cb784c9d74645915e P 7095a22e55a04de78a77e114367cab2f [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "7095a22e55a04de78a77e114367cab2f" member_type: VOTER last_known_addr { host: "127.8.150.129" port: 33481 } }
I20260812 06:17:47.147260  9091 raft_consensus.cc:385] T 5e5ef4c2801e454cb784c9d74645915e P 7095a22e55a04de78a77e114367cab2f [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:17:47.147298  9091 raft_consensus.cc:740] T 5e5ef4c2801e454cb784c9d74645915e P 7095a22e55a04de78a77e114367cab2f [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: 7095a22e55a04de78a77e114367cab2f, State: Initialized, Role: FOLLOWER
I20260812 06:17:47.147423  9091 consensus_queue.cc:260] T 5e5ef4c2801e454cb784c9d74645915e P 7095a22e55a04de78a77e114367cab2f [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: "7095a22e55a04de78a77e114367cab2f" member_type: VOTER last_known_addr { host: "127.8.150.129" port: 33481 } }
I20260812 06:17:47.147507  9091 raft_consensus.cc:399] T 5e5ef4c2801e454cb784c9d74645915e P 7095a22e55a04de78a77e114367cab2f [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:17:47.147548  9091 raft_consensus.cc:493] T 5e5ef4c2801e454cb784c9d74645915e P 7095a22e55a04de78a77e114367cab2f [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:17:47.147598  9091 raft_consensus.cc:3060] T 5e5ef4c2801e454cb784c9d74645915e P 7095a22e55a04de78a77e114367cab2f [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:17:47.148458  9091 raft_consensus.cc:515] T 5e5ef4c2801e454cb784c9d74645915e P 7095a22e55a04de78a77e114367cab2f [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "7095a22e55a04de78a77e114367cab2f" member_type: VOTER last_known_addr { host: "127.8.150.129" port: 33481 } }
I20260812 06:17:47.148603  9091 leader_election.cc:304] T 5e5ef4c2801e454cb784c9d74645915e P 7095a22e55a04de78a77e114367cab2f [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: 7095a22e55a04de78a77e114367cab2f; no voters: 
I20260812 06:17:47.148767  9091 leader_election.cc:290] T 5e5ef4c2801e454cb784c9d74645915e P 7095a22e55a04de78a77e114367cab2f [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:17:47.148903  9094 raft_consensus.cc:2804] T 5e5ef4c2801e454cb784c9d74645915e P 7095a22e55a04de78a77e114367cab2f [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:17:47.149128  9091 ts_tablet_manager.cc:1434] T 5e5ef4c2801e454cb784c9d74645915e P 7095a22e55a04de78a77e114367cab2f: Time spent starting tablet: real 0.002s	user 0.003s	sys 0.000s
I20260812 06:17:47.149190  9094 raft_consensus.cc:697] T 5e5ef4c2801e454cb784c9d74645915e P 7095a22e55a04de78a77e114367cab2f [term 1 LEADER]: Becoming Leader. State: Replica: 7095a22e55a04de78a77e114367cab2f, State: Running, Role: LEADER
I20260812 06:17:47.149394  9070 heartbeater.cc:499] Master 127.8.150.190:46277 was elected leader, sending a full tablet report...
I20260812 06:17:47.149386  9094 consensus_queue.cc:237] T 5e5ef4c2801e454cb784c9d74645915e P 7095a22e55a04de78a77e114367cab2f [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: "7095a22e55a04de78a77e114367cab2f" member_type: VOTER last_known_addr { host: "127.8.150.129" port: 33481 } }
I20260812 06:17:47.151950  8836 catalog_manager.cc:5719] T 5e5ef4c2801e454cb784c9d74645915e P 7095a22e55a04de78a77e114367cab2f reported cstate change: term changed from 0 to 1, leader changed from <none> to 7095a22e55a04de78a77e114367cab2f (127.8.150.129). New cstate: current_term: 1 leader_uuid: "7095a22e55a04de78a77e114367cab2f" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "7095a22e55a04de78a77e114367cab2f" member_type: VOTER last_known_addr { host: "127.8.150.129" port: 33481 } health_report { overall_health: HEALTHY } } }
I20260812 06:17:47.207397  8794 heavy-update-compaction-itest.cc:215] Time spent inserting: real 0.049s	user 0.015s	sys 0.009s
I20260812 06:17:47.349495  9071 maintenance_manager.cc:419] P 7095a22e55a04de78a77e114367cab2f: Scheduling FlushMRSOp(5e5ef4c2801e454cb784c9d74645915e): perf score=19.054940
I20260812 06:17:47.505178  8961 maintenance_manager.cc:643] P 7095a22e55a04de78a77e114367cab2f: FlushMRSOp(5e5ef4c2801e454cb784c9d74645915e) complete. Timing: real 0.155s	user 0.116s	sys 0.032s Metrics: {"bytes_written":11897247,"cfile_init":1,"compiler_manager_pool.queue_time_us":298,"delete_count":0,"dirs.queue_time_us":40,"dirs.run_cpu_time_us":196,"dirs.run_wall_time_us":742,"drs_written":1,"lbm_read_time_us":49,"lbm_reads_lt_1ms":4,"lbm_write_time_us":37318,"lbm_writes_lt_1ms":757,"peak_mem_usage":0,"reinsert_count":0,"rows_written":105,"thread_start_us":142,"threads_started":1,"update_count":1450}
I20260812 06:17:47.506125  9071 maintenance_manager.cc:419] P 7095a22e55a04de78a77e114367cab2f: Scheduling LogGCOp(5e5ef4c2801e454cb784c9d74645915e): free 20743880 bytes of WAL
I20260812 06:17:47.506399  8961 log_reader.cc:385] T 5e5ef4c2801e454cb784c9d74645915e: removed 2 log segments from log reader
I20260812 06:17:47.506456  8961 log.cc:1079] T 5e5ef4c2801e454cb784c9d74645915e P 7095a22e55a04de78a77e114367cab2f: Deleting log segment in path: /tmp/dist-test-taskB0FmHn/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515466905639-8794-0/minicluster-data/ts-0-root/wals/5e5ef4c2801e454cb784c9d74645915e/wal-000000001 (ops 1-6)
I20260812 06:17:47.506510  8961 log.cc:1079] T 5e5ef4c2801e454cb784c9d74645915e P 7095a22e55a04de78a77e114367cab2f: Deleting log segment in path: /tmp/dist-test-taskB0FmHn/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515466905639-8794-0/minicluster-data/ts-0-root/wals/5e5ef4c2801e454cb784c9d74645915e/wal-000000002 (ops 7-11)
I20260812 06:17:47.509971  8961 maintenance_manager.cc:643] P 7095a22e55a04de78a77e114367cab2f: LogGCOp(5e5ef4c2801e454cb784c9d74645915e) complete. Timing: real 0.004s	user 0.000s	sys 0.003s Metrics: {}
I20260812 06:17:47.510370  9071 maintenance_manager.cc:419] P 7095a22e55a04de78a77e114367cab2f: Scheduling UndoDeltaBlockGCOp(5e5ef4c2801e454cb784c9d74645915e): 16821650 bytes on disk
I20260812 06:17:47.510886  8961 maintenance_manager.cc:643] P 7095a22e55a04de78a77e114367cab2f: UndoDeltaBlockGCOp(5e5ef4c2801e454cb784c9d74645915e) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":54,"lbm_reads_lt_1ms":4}
I20260812 06:17:47.511233  9071 maintenance_manager.cc:419] P 7095a22e55a04de78a77e114367cab2f: Scheduling FlushDeltaMemStoresOp(5e5ef4c2801e454cb784c9d74645915e): perf score=2.188937
I20260812 06:17:47.526845  8961 maintenance_manager.cc:643] P 7095a22e55a04de78a77e114367cab2f: FlushDeltaMemStoresOp(5e5ef4c2801e454cb784c9d74645915e) complete. Timing: real 0.015s	user 0.009s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5250,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:47.527323  9071 maintenance_manager.cc:419] P 7095a22e55a04de78a77e114367cab2f: Scheduling MajorDeltaCompactionOp(5e5ef4c2801e454cb784c9d74645915e): perf score=1.000000
I20260812 06:17:47.670989  8961 maintenance_manager.cc:643] P 7095a22e55a04de78a77e114367cab2f: MajorDeltaCompactionOp(5e5ef4c2801e454cb784c9d74645915e) complete. Timing: real 0.144s	user 0.112s	sys 0.027s Metrics: {"cfile_cache_miss":422,"cfile_cache_miss_bytes":20303029,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":753,"lbm_read_time_us":9358,"lbm_reads_lt_1ms":454,"lbm_write_time_us":22873,"lbm_writes_lt_1ms":433,"mutex_wait_us":34,"peak_mem_usage":49238594,"reinsert_count":0,"spinlock_wait_cycles":1664,"thread_start_us":285,"threads_started":5,"update_count":1950}
I20260812 06:17:47.671484  9071 maintenance_manager.cc:419] P 7095a22e55a04de78a77e114367cab2f: Scheduling FlushDeltaMemStoresOp(5e5ef4c2801e454cb784c9d74645915e): perf score=10.126437
I20260812 06:17:47.708156  8961 maintenance_manager.cc:643] P 7095a22e55a04de78a77e114367cab2f: FlushDeltaMemStoresOp(5e5ef4c2801e454cb784c9d74645915e) complete. Timing: real 0.037s	user 0.020s	sys 0.012s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":15064,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:17:47.708623  9071 maintenance_manager.cc:419] P 7095a22e55a04de78a77e114367cab2f: Scheduling MajorDeltaCompactionOp(5e5ef4c2801e454cb784c9d74645915e): perf score=1.000000
I20260812 06:17:47.815222  8961 maintenance_manager.cc:643] P 7095a22e55a04de78a77e114367cab2f: MajorDeltaCompactionOp(5e5ef4c2801e454cb784c9d74645915e) complete. Timing: real 0.106s	user 0.094s	sys 0.012s Metrics: {"cfile_cache_miss":331,"cfile_cache_miss_bytes":16610741,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":1,"delta_iterators_relevant":1,"dirs.queue_time_us":646,"lbm_read_time_us":5925,"lbm_reads_lt_1ms":363,"lbm_write_time_us":19802,"lbm_writes_lt_1ms":343,"mutex_wait_us":336,"peak_mem_usage":38262756,"reinsert_count":0,"spinlock_wait_cycles":16000,"update_count":1500}
I20260812 06:17:47.815728  9071 maintenance_manager.cc:419] P 7095a22e55a04de78a77e114367cab2f: Scheduling FlushDeltaMemStoresOp(5e5ef4c2801e454cb784c9d74645915e): perf score=10.126437
I20260812 06:17:47.860821  8961 maintenance_manager.cc:643] P 7095a22e55a04de78a77e114367cab2f: FlushDeltaMemStoresOp(5e5ef4c2801e454cb784c9d74645915e) complete. Timing: real 0.045s	user 0.014s	sys 0.024s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":19496,"lbm_writes_1-10_ms":2,"lbm_writes_lt_1ms":301,"reinsert_count":0,"update_count":1500}
I20260812 06:17:47.861346  9071 maintenance_manager.cc:419] P 7095a22e55a04de78a77e114367cab2f: Scheduling MajorDeltaCompactionOp(5e5ef4c2801e454cb784c9d74645915e): perf score=1.000000
I20260812 06:17:47.973726  8961 maintenance_manager.cc:643] P 7095a22e55a04de78a77e114367cab2f: MajorDeltaCompactionOp(5e5ef4c2801e454cb784c9d74645915e) complete. Timing: real 0.112s	user 0.064s	sys 0.048s Metrics: {"cfile_cache_miss":331,"cfile_cache_miss_bytes":16610741,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":1,"delta_iterators_relevant":1,"dirs.queue_time_us":361,"lbm_read_time_us":8582,"lbm_reads_lt_1ms":363,"lbm_write_time_us":17101,"lbm_writes_lt_1ms":343,"peak_mem_usage":38262756,"reinsert_count":0,"update_count":1500}
I20260812 06:17:47.974172  9071 maintenance_manager.cc:419] P 7095a22e55a04de78a77e114367cab2f: Scheduling FlushDeltaMemStoresOp(5e5ef4c2801e454cb784c9d74645915e): perf score=10.126437
I20260812 06:17:48.025866  8961 maintenance_manager.cc:643] P 7095a22e55a04de78a77e114367cab2f: FlushDeltaMemStoresOp(5e5ef4c2801e454cb784c9d74645915e) complete. Timing: real 0.052s	user 0.027s	sys 0.016s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":20304,"lbm_writes_1-10_ms":2,"lbm_writes_lt_1ms":301,"reinsert_count":0,"update_count":1500}
I20260812 06:17:48.026428  9071 maintenance_manager.cc:419] P 7095a22e55a04de78a77e114367cab2f: Scheduling FlushDeltaMemStoresOp(5e5ef4c2801e454cb784c9d74645915e): perf score=2.188937
I20260812 06:17:48.044703  8961 maintenance_manager.cc:643] P 7095a22e55a04de78a77e114367cab2f: FlushDeltaMemStoresOp(5e5ef4c2801e454cb784c9d74645915e) complete. Timing: real 0.018s	user 0.014s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5733,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:48.045184  9071 maintenance_manager.cc:419] P 7095a22e55a04de78a77e114367cab2f: Scheduling MajorDeltaCompactionOp(5e5ef4c2801e454cb784c9d74645915e): perf score=1.000000
I20260812 06:17:48.163687  8961 maintenance_manager.cc:643] P 7095a22e55a04de78a77e114367cab2f: MajorDeltaCompactionOp(5e5ef4c2801e454cb784c9d74645915e) complete. Timing: real 0.118s	user 0.089s	sys 0.029s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20713272,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":511,"lbm_read_time_us":7362,"lbm_reads_lt_1ms":464,"lbm_write_time_us":24025,"lbm_writes_lt_1ms":443,"mutex_wait_us":334,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":5888,"update_count":2000}
I20260812 06:17:48.165459  9071 maintenance_manager.cc:419] P 7095a22e55a04de78a77e114367cab2f: Scheduling FlushDeltaMemStoresOp(5e5ef4c2801e454cb784c9d74645915e): perf score=10.126437
I20260812 06:17:48.205420  8961 maintenance_manager.cc:643] P 7095a22e55a04de78a77e114367cab2f: FlushDeltaMemStoresOp(5e5ef4c2801e454cb784c9d74645915e) complete. Timing: real 0.040s	user 0.027s	sys 0.012s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":17294,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:17:48.206019  9071 maintenance_manager.cc:419] P 7095a22e55a04de78a77e114367cab2f: Scheduling FlushDeltaMemStoresOp(5e5ef4c2801e454cb784c9d74645915e): perf score=2.188937
I20260812 06:17:48.217640  8961 maintenance_manager.cc:643] P 7095a22e55a04de78a77e114367cab2f: FlushDeltaMemStoresOp(5e5ef4c2801e454cb784c9d74645915e) complete. Timing: real 0.011s	user 0.011s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4187,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:48.218168  9071 maintenance_manager.cc:419] P 7095a22e55a04de78a77e114367cab2f: Scheduling MajorDeltaCompactionOp(5e5ef4c2801e454cb784c9d74645915e): perf score=1.000000
I20260812 06:17:48.339308  8961 maintenance_manager.cc:643] P 7095a22e55a04de78a77e114367cab2f: MajorDeltaCompactionOp(5e5ef4c2801e454cb784c9d74645915e) complete. Timing: real 0.121s	user 0.097s	sys 0.024s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20713272,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":128,"lbm_read_time_us":8412,"lbm_reads_lt_1ms":472,"lbm_write_time_us":22540,"lbm_writes_lt_1ms":443,"mutex_wait_us":35,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":17920,"update_count":2000}
I20260812 06:17:48.340027  9071 maintenance_manager.cc:419] P 7095a22e55a04de78a77e114367cab2f: Scheduling FlushDeltaMemStoresOp(5e5ef4c2801e454cb784c9d74645915e): perf score=11.118625
I20260812 06:17:48.383282  8961 maintenance_manager.cc:643] P 7095a22e55a04de78a77e114367cab2f: FlushDeltaMemStoresOp(5e5ef4c2801e454cb784c9d74645915e) complete. Timing: real 0.043s	user 0.022s	sys 0.018s Metrics: {"bytes_written":12717736,"delete_count":0,"lbm_write_time_us":15576,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:17:48.383915  9071 maintenance_manager.cc:419] P 7095a22e55a04de78a77e114367cab2f: Scheduling FlushDeltaMemStoresOp(5e5ef4c2801e454cb784c9d74645915e): perf score=2.188937
I20260812 06:17:48.394862  8961 maintenance_manager.cc:643] P 7095a22e55a04de78a77e114367cab2f: FlushDeltaMemStoresOp(5e5ef4c2801e454cb784c9d74645915e) complete. Timing: real 0.011s	user 0.005s	sys 0.004s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3873,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:17:48.395272  9071 maintenance_manager.cc:419] P 7095a22e55a04de78a77e114367cab2f: Scheduling MajorDeltaCompactionOp(5e5ef4c2801e454cb784c9d74645915e): perf score=1.000000
I20260812 06:17:48.549952  8961 maintenance_manager.cc:643] P 7095a22e55a04de78a77e114367cab2f: MajorDeltaCompactionOp(5e5ef4c2801e454cb784c9d74645915e) complete. Timing: real 0.155s	user 0.108s	sys 0.045s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20713264,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":309,"lbm_read_time_us":11465,"lbm_reads_lt_1ms":472,"lbm_write_time_us":26223,"lbm_writes_lt_1ms":443,"mutex_wait_us":3,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":768,"update_count":2000}
I20260812 06:17:48.550488  9071 maintenance_manager.cc:419] P 7095a22e55a04de78a77e114367cab2f: Scheduling FlushDeltaMemStoresOp(5e5ef4c2801e454cb784c9d74645915e): perf score=10.126437
I20260812 06:17:48.589659  8961 maintenance_manager.cc:643] P 7095a22e55a04de78a77e114367cab2f: FlushDeltaMemStoresOp(5e5ef4c2801e454cb784c9d74645915e) complete. Timing: real 0.039s	user 0.031s	sys 0.008s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":17194,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:17:48.590266  9071 maintenance_manager.cc:419] P 7095a22e55a04de78a77e114367cab2f: Scheduling FlushDeltaMemStoresOp(5e5ef4c2801e454cb784c9d74645915e): perf score=2.188937
I20260812 06:17:48.603567  8961 maintenance_manager.cc:643] P 7095a22e55a04de78a77e114367cab2f: FlushDeltaMemStoresOp(5e5ef4c2801e454cb784c9d74645915e) complete. Timing: real 0.013s	user 0.006s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4719,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:48.604075  9071 maintenance_manager.cc:419] P 7095a22e55a04de78a77e114367cab2f: Scheduling MajorDeltaCompactionOp(5e5ef4c2801e454cb784c9d74645915e): perf score=1.000000
I20260812 06:17:48.740857  8961 maintenance_manager.cc:643] P 7095a22e55a04de78a77e114367cab2f: MajorDeltaCompactionOp(5e5ef4c2801e454cb784c9d74645915e) complete. Timing: real 0.137s	user 0.096s	sys 0.039s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20713272,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":2018,"lbm_read_time_us":9753,"lbm_reads_lt_1ms":472,"lbm_write_time_us":27515,"lbm_writes_lt_1ms":443,"mutex_wait_us":843,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":896,"update_count":2000}
I20260812 06:17:48.741492  9071 maintenance_manager.cc:419] P 7095a22e55a04de78a77e114367cab2f: Scheduling FlushDeltaMemStoresOp(5e5ef4c2801e454cb784c9d74645915e): perf score=11.118625
I20260812 06:17:48.793203  8961 maintenance_manager.cc:643] P 7095a22e55a04de78a77e114367cab2f: FlushDeltaMemStoresOp(5e5ef4c2801e454cb784c9d74645915e) complete. Timing: real 0.052s	user 0.032s	sys 0.016s Metrics: {"bytes_written":12717734,"delete_count":0,"lbm_write_time_us":21851,"lbm_writes_1-10_ms":2,"lbm_writes_lt_1ms":311,"reinsert_count":0,"update_count":1550}
I20260812 06:17:48.794039  9071 maintenance_manager.cc:419] P 7095a22e55a04de78a77e114367cab2f: Scheduling FlushDeltaMemStoresOp(5e5ef4c2801e454cb784c9d74645915e): perf score=2.188937
I20260812 06:17:48.806552  8961 maintenance_manager.cc:643] P 7095a22e55a04de78a77e114367cab2f: FlushDeltaMemStoresOp(5e5ef4c2801e454cb784c9d74645915e) complete. Timing: real 0.012s	user 0.008s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3498,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:48.807053  9071 maintenance_manager.cc:419] P 7095a22e55a04de78a77e114367cab2f: Scheduling FlushDeltaMemStoresOp(5e5ef4c2801e454cb784c9d74645915e): perf score=2.188937
I20260812 06:17:48.820156  8961 maintenance_manager.cc:643] P 7095a22e55a04de78a77e114367cab2f: FlushDeltaMemStoresOp(5e5ef4c2801e454cb784c9d74645915e) complete. Timing: real 0.013s	user 0.008s	sys 0.003s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":4734,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:17:48.820740  9071 maintenance_manager.cc:419] P 7095a22e55a04de78a77e114367cab2f: Scheduling FlushMRSOp(5e5ef4c2801e454cb784c9d74645915e): perf score=1.000000
I20260812 06:17:48.849169  8961 maintenance_manager.cc:643] P 7095a22e55a04de78a77e114367cab2f: FlushMRSOp(5e5ef4c2801e454cb784c9d74645915e) complete. Timing: real 0.028s	user 0.027s	sys 0.000s Metrics: {"bytes_written":1234473,"cfile_init":1,"dirs.queue_time_us":46,"dirs.run_cpu_time_us":241,"dirs.run_wall_time_us":1237,"drs_written":1,"lbm_read_time_us":50,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1477,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":30}
I20260812 06:17:48.850132  9071 maintenance_manager.cc:419] P 7095a22e55a04de78a77e114367cab2f: Scheduling LogGCOp(5e5ef4c2801e454cb784c9d74645915e): free 121006433 bytes of WAL
I20260812 06:17:48.850419  8961 log_reader.cc:385] T 5e5ef4c2801e454cb784c9d74645915e: removed 12 log segments from log reader
I20260812 06:17:48.850481  8961 log.cc:1079] T 5e5ef4c2801e454cb784c9d74645915e P 7095a22e55a04de78a77e114367cab2f: Deleting log segment in path: /tmp/dist-test-taskB0FmHn/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515466905639-8794-0/minicluster-data/ts-0-root/wals/5e5ef4c2801e454cb784c9d74645915e/wal-000000003 (ops 12-16)
I20260812 06:17:48.850519  8961 log.cc:1079] T 5e5ef4c2801e454cb784c9d74645915e P 7095a22e55a04de78a77e114367cab2f: Deleting log segment in path: /tmp/dist-test-taskB0FmHn/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515466905639-8794-0/minicluster-data/ts-0-root/wals/5e5ef4c2801e454cb784c9d74645915e/wal-000000004 (ops 17-21)
I20260812 06:17:48.850553  8961 log.cc:1079] T 5e5ef4c2801e454cb784c9d74645915e P 7095a22e55a04de78a77e114367cab2f: Deleting log segment in path: /tmp/dist-test-taskB0FmHn/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515466905639-8794-0/minicluster-data/ts-0-root/wals/5e5ef4c2801e454cb784c9d74645915e/wal-000000005 (ops 22-26)
I20260812 06:17:48.850584  8961 log.cc:1079] T 5e5ef4c2801e454cb784c9d74645915e P 7095a22e55a04de78a77e114367cab2f: Deleting log segment in path: /tmp/dist-test-taskB0FmHn/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515466905639-8794-0/minicluster-data/ts-0-root/wals/5e5ef4c2801e454cb784c9d74645915e/wal-000000006 (ops 27-31)
I20260812 06:17:48.850615  8961 log.cc:1079] T 5e5ef4c2801e454cb784c9d74645915e P 7095a22e55a04de78a77e114367cab2f: Deleting log segment in path: /tmp/dist-test-taskB0FmHn/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515466905639-8794-0/minicluster-data/ts-0-root/wals/5e5ef4c2801e454cb784c9d74645915e/wal-000000007 (ops 32-36)
I20260812 06:17:48.850644  8961 log.cc:1079] T 5e5ef4c2801e454cb784c9d74645915e P 7095a22e55a04de78a77e114367cab2f: Deleting log segment in path: /tmp/dist-test-taskB0FmHn/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515466905639-8794-0/minicluster-data/ts-0-root/wals/5e5ef4c2801e454cb784c9d74645915e/wal-000000008 (ops 37-41)
I20260812 06:17:48.850675  8961 log.cc:1079] T 5e5ef4c2801e454cb784c9d74645915e P 7095a22e55a04de78a77e114367cab2f: Deleting log segment in path: /tmp/dist-test-taskB0FmHn/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515466905639-8794-0/minicluster-data/ts-0-root/wals/5e5ef4c2801e454cb784c9d74645915e/wal-000000009 (ops 42-46)
I20260812 06:17:48.850706  8961 log.cc:1079] T 5e5ef4c2801e454cb784c9d74645915e P 7095a22e55a04de78a77e114367cab2f: Deleting log segment in path: /tmp/dist-test-taskB0FmHn/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515466905639-8794-0/minicluster-data/ts-0-root/wals/5e5ef4c2801e454cb784c9d74645915e/wal-000000010 (ops 47-51)
I20260812 06:17:48.850736  8961 log.cc:1079] T 5e5ef4c2801e454cb784c9d74645915e P 7095a22e55a04de78a77e114367cab2f: Deleting log segment in path: /tmp/dist-test-taskB0FmHn/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515466905639-8794-0/minicluster-data/ts-0-root/wals/5e5ef4c2801e454cb784c9d74645915e/wal-000000011 (ops 52-56)
I20260812 06:17:48.850767  8961 log.cc:1079] T 5e5ef4c2801e454cb784c9d74645915e P 7095a22e55a04de78a77e114367cab2f: Deleting log segment in path: /tmp/dist-test-taskB0FmHn/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515466905639-8794-0/minicluster-data/ts-0-root/wals/5e5ef4c2801e454cb784c9d74645915e/wal-000000012 (ops 57-60)
I20260812 06:17:48.850796  8961 log.cc:1079] T 5e5ef4c2801e454cb784c9d74645915e P 7095a22e55a04de78a77e114367cab2f: Deleting log segment in path: /tmp/dist-test-taskB0FmHn/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515466905639-8794-0/minicluster-data/ts-0-root/wals/5e5ef4c2801e454cb784c9d74645915e/wal-000000013 (ops 61-65)
I20260812 06:17:48.850827  8961 log.cc:1079] T 5e5ef4c2801e454cb784c9d74645915e P 7095a22e55a04de78a77e114367cab2f: Deleting log segment in path: /tmp/dist-test-taskB0FmHn/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515466905639-8794-0/minicluster-data/ts-0-root/wals/5e5ef4c2801e454cb784c9d74645915e/wal-000000014 (ops 66-70)
I20260812 06:17:48.872516  8961 maintenance_manager.cc:643] P 7095a22e55a04de78a77e114367cab2f: LogGCOp(5e5ef4c2801e454cb784c9d74645915e) complete. Timing: real 0.022s	user 0.000s	sys 0.018s Metrics: {}
I20260812 06:17:48.872886  9071 maintenance_manager.cc:419] P 7095a22e55a04de78a77e114367cab2f: Scheduling FlushDeltaMemStoresOp(5e5ef4c2801e454cb784c9d74645915e): perf score=3.181125
I20260812 06:17:48.887281  8961 maintenance_manager.cc:643] P 7095a22e55a04de78a77e114367cab2f: FlushDeltaMemStoresOp(5e5ef4c2801e454cb784c9d74645915e) complete. Timing: real 0.014s	user 0.009s	sys 0.000s Metrics: {"bytes_written":4512903,"delete_count":0,"lbm_write_time_us":3847,"lbm_writes_lt_1ms":113,"reinsert_count":0,"update_count":550}
I20260812 06:17:48.887733  9071 maintenance_manager.cc:419] P 7095a22e55a04de78a77e114367cab2f: Scheduling UndoDeltaBlockGCOp(5e5ef4c2801e454cb784c9d74645915e): 472 bytes on disk
I20260812 06:17:48.888123  8961 maintenance_manager.cc:643] P 7095a22e55a04de78a77e114367cab2f: UndoDeltaBlockGCOp(5e5ef4c2801e454cb784c9d74645915e) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":48,"lbm_reads_lt_1ms":4}
I20260812 06:17:48.888604  9071 maintenance_manager.cc:419] P 7095a22e55a04de78a77e114367cab2f: Scheduling FlushDeltaMemStoresOp(5e5ef4c2801e454cb784c9d74645915e): perf score=2.188937
I20260812 06:17:48.897455  8961 maintenance_manager.cc:643] P 7095a22e55a04de78a77e114367cab2f: FlushDeltaMemStoresOp(5e5ef4c2801e454cb784c9d74645915e) complete. Timing: real 0.009s	user 0.008s	sys 0.000s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3145,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:17:48.897924  9071 maintenance_manager.cc:419] P 7095a22e55a04de78a77e114367cab2f: Scheduling MajorDeltaCompactionOp(5e5ef4c2801e454cb784c9d74645915e): perf score=1.000000
I20260812 06:17:49.076444  8961 maintenance_manager.cc:643] P 7095a22e55a04de78a77e114367cab2f: MajorDeltaCompactionOp(5e5ef4c2801e454cb784c9d74645915e) complete. Timing: real 0.178s	user 0.138s	sys 0.040s Metrics: {"cfile_cache_miss":735,"cfile_cache_miss_bytes":33020845,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":5,"delta_iterators_relevant":5,"dirs.queue_time_us":613,"lbm_read_time_us":14291,"lbm_reads_lt_1ms":775,"lbm_write_time_us":34247,"lbm_writes_lt_1ms":743,"mutex_wait_us":659,"peak_mem_usage":87969044,"reinsert_count":0,"spinlock_wait_cycles":8448,"thread_start_us":72,"threads_started":1,"update_count":3500}
I20260812 06:17:49.076977  9071 maintenance_manager.cc:419] P 7095a22e55a04de78a77e114367cab2f: Scheduling FlushDeltaMemStoresOp(5e5ef4c2801e454cb784c9d74645915e): perf score=14.095187
I20260812 06:17:49.121642  8961 maintenance_manager.cc:643] P 7095a22e55a04de78a77e114367cab2f: FlushDeltaMemStoresOp(5e5ef4c2801e454cb784c9d74645915e) complete. Timing: real 0.044s	user 0.032s	sys 0.012s Metrics: {"bytes_written":16409897,"delete_count":0,"lbm_write_time_us":19458,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:17:49.122236  9071 maintenance_manager.cc:419] P 7095a22e55a04de78a77e114367cab2f: Scheduling FlushDeltaMemStoresOp(5e5ef4c2801e454cb784c9d74645915e): perf score=2.188937
I20260812 06:17:49.144691  8961 maintenance_manager.cc:643] P 7095a22e55a04de78a77e114367cab2f: FlushDeltaMemStoresOp(5e5ef4c2801e454cb784c9d74645915e) complete. Timing: real 0.022s	user 0.007s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5211,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:49.145306  9071 maintenance_manager.cc:419] P 7095a22e55a04de78a77e114367cab2f: Scheduling MajorDeltaCompactionOp(5e5ef4c2801e454cb784c9d74645915e): perf score=1.000000
I20260812 06:17:49.306488  8961 maintenance_manager.cc:643] P 7095a22e55a04de78a77e114367cab2f: MajorDeltaCompactionOp(5e5ef4c2801e454cb784c9d74645915e) complete. Timing: real 0.161s	user 0.106s	sys 0.052s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24815679,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":972,"lbm_read_time_us":12741,"lbm_reads_lt_1ms":564,"lbm_write_time_us":24801,"lbm_writes_lt_1ms":543,"mutex_wait_us":80,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":2432,"update_count":2500}
I20260812 06:17:49.306977  9071 maintenance_manager.cc:419] P 7095a22e55a04de78a77e114367cab2f: Scheduling FlushDeltaMemStoresOp(5e5ef4c2801e454cb784c9d74645915e): perf score=14.095187
I20260812 06:17:49.353242  8961 maintenance_manager.cc:643] P 7095a22e55a04de78a77e114367cab2f: FlushDeltaMemStoresOp(5e5ef4c2801e454cb784c9d74645915e) complete. Timing: real 0.046s	user 0.027s	sys 0.019s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":21446,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":402,"reinsert_count":0,"update_count":2000}
I20260812 06:17:49.353811  9071 maintenance_manager.cc:419] P 7095a22e55a04de78a77e114367cab2f: Scheduling FlushDeltaMemStoresOp(5e5ef4c2801e454cb784c9d74645915e): perf score=2.188937
I20260812 06:17:49.369905  8961 maintenance_manager.cc:643] P 7095a22e55a04de78a77e114367cab2f: FlushDeltaMemStoresOp(5e5ef4c2801e454cb784c9d74645915e) complete. Timing: real 0.016s	user 0.015s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5861,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:49.370499  9071 maintenance_manager.cc:419] P 7095a22e55a04de78a77e114367cab2f: Scheduling MajorDeltaCompactionOp(5e5ef4c2801e454cb784c9d74645915e): perf score=1.000000
I20260812 06:17:49.534178  8961 maintenance_manager.cc:643] P 7095a22e55a04de78a77e114367cab2f: MajorDeltaCompactionOp(5e5ef4c2801e454cb784c9d74645915e) complete. Timing: real 0.164s	user 0.120s	sys 0.036s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24815683,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":294,"lbm_read_time_us":8641,"lbm_reads_lt_1ms":564,"lbm_write_time_us":28169,"lbm_writes_lt_1ms":543,"mutex_wait_us":62,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":3968,"update_count":2500}
I20260812 06:17:49.534718  9071 maintenance_manager.cc:419] P 7095a22e55a04de78a77e114367cab2f: Scheduling FlushDeltaMemStoresOp(5e5ef4c2801e454cb784c9d74645915e): perf score=14.095187
I20260812 06:17:49.588661  8961 maintenance_manager.cc:643] P 7095a22e55a04de78a77e114367cab2f: FlushDeltaMemStoresOp(5e5ef4c2801e454cb784c9d74645915e) complete. Timing: real 0.054s	user 0.012s	sys 0.027s Metrics: {"bytes_written":16409903,"delete_count":0,"lbm_write_time_us":18876,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:17:49.589294  9071 maintenance_manager.cc:419] P 7095a22e55a04de78a77e114367cab2f: Scheduling MajorDeltaCompactionOp(5e5ef4c2801e454cb784c9d74645915e): perf score=1.000000
I20260812 06:17:49.722164  8961 maintenance_manager.cc:643] P 7095a22e55a04de78a77e114367cab2f: MajorDeltaCompactionOp(5e5ef4c2801e454cb784c9d74645915e) complete. Timing: real 0.133s	user 0.100s	sys 0.032s Metrics: {"cfile_cache_miss":431,"cfile_cache_miss_bytes":20713154,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":1,"delta_iterators_relevant":1,"dirs.queue_time_us":608,"lbm_read_time_us":8663,"lbm_reads_lt_1ms":463,"lbm_write_time_us":26798,"lbm_writes_lt_1ms":443,"mutex_wait_us":275,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":2816,"update_count":2000}
I20260812 06:17:49.722813  9071 maintenance_manager.cc:419] P 7095a22e55a04de78a77e114367cab2f: Scheduling FlushDeltaMemStoresOp(5e5ef4c2801e454cb784c9d74645915e): perf score=10.126437
I20260812 06:17:49.761297  8961 maintenance_manager.cc:643] P 7095a22e55a04de78a77e114367cab2f: FlushDeltaMemStoresOp(5e5ef4c2801e454cb784c9d74645915e) complete. Timing: real 0.038s	user 0.026s	sys 0.011s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":16444,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:17:49.761862  9071 maintenance_manager.cc:419] P 7095a22e55a04de78a77e114367cab2f: Scheduling FlushDeltaMemStoresOp(5e5ef4c2801e454cb784c9d74645915e): perf score=2.188937
I20260812 06:17:49.771812  8961 maintenance_manager.cc:643] P 7095a22e55a04de78a77e114367cab2f: FlushDeltaMemStoresOp(5e5ef4c2801e454cb784c9d74645915e) complete. Timing: real 0.010s	user 0.000s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3541,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:49.772405  9071 maintenance_manager.cc:419] P 7095a22e55a04de78a77e114367cab2f: Scheduling MajorDeltaCompactionOp(5e5ef4c2801e454cb784c9d74645915e): perf score=1.000000
I20260812 06:17:49.896234  8961 maintenance_manager.cc:643] P 7095a22e55a04de78a77e114367cab2f: MajorDeltaCompactionOp(5e5ef4c2801e454cb784c9d74645915e) complete. Timing: real 0.124s	user 0.095s	sys 0.028s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20713272,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":827,"lbm_read_time_us":9703,"lbm_reads_lt_1ms":472,"lbm_write_time_us":22299,"lbm_writes_lt_1ms":443,"mutex_wait_us":19,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":2944,"update_count":2000}
I20260812 06:17:49.896782  9071 maintenance_manager.cc:419] P 7095a22e55a04de78a77e114367cab2f: Scheduling FlushDeltaMemStoresOp(5e5ef4c2801e454cb784c9d74645915e): perf score=10.126437
I20260812 06:17:49.944444  8961 maintenance_manager.cc:643] P 7095a22e55a04de78a77e114367cab2f: FlushDeltaMemStoresOp(5e5ef4c2801e454cb784c9d74645915e) complete. Timing: real 0.047s	user 0.026s	sys 0.015s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":16171,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":302,"reinsert_count":0,"update_count":1500}
I20260812 06:17:49.945118  9071 maintenance_manager.cc:419] P 7095a22e55a04de78a77e114367cab2f: Scheduling FlushDeltaMemStoresOp(5e5ef4c2801e454cb784c9d74645915e): perf score=2.188937
I20260812 06:17:49.955107  8961 maintenance_manager.cc:643] P 7095a22e55a04de78a77e114367cab2f: FlushDeltaMemStoresOp(5e5ef4c2801e454cb784c9d74645915e) complete. Timing: real 0.010s	user 0.004s	sys 0.004s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":3693,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:49.955631  9071 maintenance_manager.cc:419] P 7095a22e55a04de78a77e114367cab2f: Scheduling MajorDeltaCompactionOp(5e5ef4c2801e454cb784c9d74645915e): perf score=1.000000
I20260812 06:17:50.101202  8961 maintenance_manager.cc:643] P 7095a22e55a04de78a77e114367cab2f: MajorDeltaCompactionOp(5e5ef4c2801e454cb784c9d74645915e) complete. Timing: real 0.145s	user 0.095s	sys 0.050s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20713271,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":197,"lbm_read_time_us":10630,"lbm_reads_lt_1ms":472,"lbm_write_time_us":23739,"lbm_writes_lt_1ms":443,"mutex_wait_us":24,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":1920,"update_count":2000}
I20260812 06:17:50.101903  9071 maintenance_manager.cc:419] P 7095a22e55a04de78a77e114367cab2f: Scheduling FlushDeltaMemStoresOp(5e5ef4c2801e454cb784c9d74645915e): perf score=10.126437
I20260812 06:17:50.144762  8961 maintenance_manager.cc:643] P 7095a22e55a04de78a77e114367cab2f: FlushDeltaMemStoresOp(5e5ef4c2801e454cb784c9d74645915e) complete. Timing: real 0.043s	user 0.011s	sys 0.017s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":13721,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:17:50.145248  9071 maintenance_manager.cc:419] P 7095a22e55a04de78a77e114367cab2f: Scheduling FlushDeltaMemStoresOp(5e5ef4c2801e454cb784c9d74645915e): perf score=2.188937
I20260812 06:17:50.155794  8961 maintenance_manager.cc:643] P 7095a22e55a04de78a77e114367cab2f: FlushDeltaMemStoresOp(5e5ef4c2801e454cb784c9d74645915e) complete. Timing: real 0.010s	user 0.008s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3692,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:50.156440  9071 maintenance_manager.cc:419] P 7095a22e55a04de78a77e114367cab2f: Scheduling FlushMRSOp(5e5ef4c2801e454cb784c9d74645915e): perf score=1.000000
I20260812 06:17:50.182948  8961 maintenance_manager.cc:643] P 7095a22e55a04de78a77e114367cab2f: FlushMRSOp(5e5ef4c2801e454cb784c9d74645915e) complete. Timing: real 0.026s	user 0.024s	sys 0.000s Metrics: {"bytes_written":1152514,"cfile_init":1,"dirs.queue_time_us":55,"dirs.run_cpu_time_us":205,"dirs.run_wall_time_us":1277,"drs_written":1,"lbm_read_time_us":37,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1544,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":28}
I20260812 06:17:50.183768  9071 maintenance_manager.cc:419] P 7095a22e55a04de78a77e114367cab2f: Scheduling LogGCOp(5e5ef4c2801e454cb784c9d74645915e): free 115943124 bytes of WAL
I20260812 06:17:50.184051  8961 log_reader.cc:385] T 5e5ef4c2801e454cb784c9d74645915e: removed 11 log segments from log reader
I20260812 06:17:50.184104  8961 log.cc:1079] T 5e5ef4c2801e454cb784c9d74645915e P 7095a22e55a04de78a77e114367cab2f: Deleting log segment in path: /tmp/dist-test-taskB0FmHn/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515466905639-8794-0/minicluster-data/ts-0-root/wals/5e5ef4c2801e454cb784c9d74645915e/wal-000000015 (ops 71-75)
I20260812 06:17:50.184144  8961 log.cc:1079] T 5e5ef4c2801e454cb784c9d74645915e P 7095a22e55a04de78a77e114367cab2f: Deleting log segment in path: /tmp/dist-test-taskB0FmHn/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515466905639-8794-0/minicluster-data/ts-0-root/wals/5e5ef4c2801e454cb784c9d74645915e/wal-000000016 (ops 76-80)
I20260812 06:17:50.184175  8961 log.cc:1079] T 5e5ef4c2801e454cb784c9d74645915e P 7095a22e55a04de78a77e114367cab2f: Deleting log segment in path: /tmp/dist-test-taskB0FmHn/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515466905639-8794-0/minicluster-data/ts-0-root/wals/5e5ef4c2801e454cb784c9d74645915e/wal-000000017 (ops 81-85)
I20260812 06:17:50.184204  8961 log.cc:1079] T 5e5ef4c2801e454cb784c9d74645915e P 7095a22e55a04de78a77e114367cab2f: Deleting log segment in path: /tmp/dist-test-taskB0FmHn/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515466905639-8794-0/minicluster-data/ts-0-root/wals/5e5ef4c2801e454cb784c9d74645915e/wal-000000018 (ops 86-90)
I20260812 06:17:50.184263  8961 log.cc:1079] T 5e5ef4c2801e454cb784c9d74645915e P 7095a22e55a04de78a77e114367cab2f: Deleting log segment in path: /tmp/dist-test-taskB0FmHn/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515466905639-8794-0/minicluster-data/ts-0-root/wals/5e5ef4c2801e454cb784c9d74645915e/wal-000000019 (ops 91-95)
I20260812 06:17:50.184297  8961 log.cc:1079] T 5e5ef4c2801e454cb784c9d74645915e P 7095a22e55a04de78a77e114367cab2f: Deleting log segment in path: /tmp/dist-test-taskB0FmHn/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515466905639-8794-0/minicluster-data/ts-0-root/wals/5e5ef4c2801e454cb784c9d74645915e/wal-000000020 (ops 96-100)
I20260812 06:17:50.184326  8961 log.cc:1079] T 5e5ef4c2801e454cb784c9d74645915e P 7095a22e55a04de78a77e114367cab2f: Deleting log segment in path: /tmp/dist-test-taskB0FmHn/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515466905639-8794-0/minicluster-data/ts-0-root/wals/5e5ef4c2801e454cb784c9d74645915e/wal-000000021 (ops 101-105)
I20260812 06:17:50.184356  8961 log.cc:1079] T 5e5ef4c2801e454cb784c9d74645915e P 7095a22e55a04de78a77e114367cab2f: Deleting log segment in path: /tmp/dist-test-taskB0FmHn/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515466905639-8794-0/minicluster-data/ts-0-root/wals/5e5ef4c2801e454cb784c9d74645915e/wal-000000022 (ops 106-110)
I20260812 06:17:50.184386  8961 log.cc:1079] T 5e5ef4c2801e454cb784c9d74645915e P 7095a22e55a04de78a77e114367cab2f: Deleting log segment in path: /tmp/dist-test-taskB0FmHn/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515466905639-8794-0/minicluster-data/ts-0-root/wals/5e5ef4c2801e454cb784c9d74645915e/wal-000000023 (ops 111-115)
I20260812 06:17:50.184414  8961 log.cc:1079] T 5e5ef4c2801e454cb784c9d74645915e P 7095a22e55a04de78a77e114367cab2f: Deleting log segment in path: /tmp/dist-test-taskB0FmHn/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515466905639-8794-0/minicluster-data/ts-0-root/wals/5e5ef4c2801e454cb784c9d74645915e/wal-000000024 (ops 116-120)
I20260812 06:17:50.184444  8961 log.cc:1079] T 5e5ef4c2801e454cb784c9d74645915e P 7095a22e55a04de78a77e114367cab2f: Deleting log segment in path: /tmp/dist-test-taskB0FmHn/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515466905639-8794-0/minicluster-data/ts-0-root/wals/5e5ef4c2801e454cb784c9d74645915e/wal-000000025 (ops 121-125)
I20260812 06:17:50.205971  8961 maintenance_manager.cc:643] P 7095a22e55a04de78a77e114367cab2f: LogGCOp(5e5ef4c2801e454cb784c9d74645915e) complete. Timing: real 0.022s	user 0.000s	sys 0.021s Metrics: {}
I20260812 06:17:50.206386  9071 maintenance_manager.cc:419] P 7095a22e55a04de78a77e114367cab2f: Scheduling UndoDeltaBlockGCOp(5e5ef4c2801e454cb784c9d74645915e): 447 bytes on disk
I20260812 06:17:50.206868  8961 maintenance_manager.cc:643] P 7095a22e55a04de78a77e114367cab2f: UndoDeltaBlockGCOp(5e5ef4c2801e454cb784c9d74645915e) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":70,"lbm_reads_lt_1ms":4}
I20260812 06:17:50.207438  9071 maintenance_manager.cc:419] P 7095a22e55a04de78a77e114367cab2f: Scheduling FlushDeltaMemStoresOp(5e5ef4c2801e454cb784c9d74645915e): perf score=3.181125
I20260812 06:17:50.225512  8961 maintenance_manager.cc:643] P 7095a22e55a04de78a77e114367cab2f: FlushDeltaMemStoresOp(5e5ef4c2801e454cb784c9d74645915e) complete. Timing: real 0.018s	user 0.009s	sys 0.008s Metrics: {"bytes_written":4512903,"delete_count":0,"lbm_write_time_us":6579,"lbm_writes_lt_1ms":113,"reinsert_count":0,"update_count":550}
I20260812 06:17:50.225919  9071 maintenance_manager.cc:419] P 7095a22e55a04de78a77e114367cab2f: Scheduling FlushDeltaMemStoresOp(5e5ef4c2801e454cb784c9d74645915e): perf score=2.188937
I20260812 06:17:50.242144  8961 maintenance_manager.cc:643] P 7095a22e55a04de78a77e114367cab2f: FlushDeltaMemStoresOp(5e5ef4c2801e454cb784c9d74645915e) complete. Timing: real 0.016s	user 0.008s	sys 0.007s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3194,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:17:50.242681  9071 maintenance_manager.cc:419] P 7095a22e55a04de78a77e114367cab2f: Scheduling MajorDeltaCompactionOp(5e5ef4c2801e454cb784c9d74645915e): perf score=1.000000
I20260812 06:17:50.445369  8961 maintenance_manager.cc:643] P 7095a22e55a04de78a77e114367cab2f: MajorDeltaCompactionOp(5e5ef4c2801e454cb784c9d74645915e) complete. Timing: real 0.202s	user 0.147s	sys 0.048s Metrics: {"cfile_cache_miss":634,"cfile_cache_miss_bytes":28918324,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":2073,"lbm_read_time_us":15303,"lbm_reads_lt_1ms":674,"lbm_write_time_us":30971,"lbm_writes_lt_1ms":643,"mutex_wait_us":1816,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":16000,"thread_start_us":68,"threads_started":1,"update_count":3000}
I20260812 06:17:50.445886  9071 maintenance_manager.cc:419] P 7095a22e55a04de78a77e114367cab2f: Scheduling FlushDeltaMemStoresOp(5e5ef4c2801e454cb784c9d74645915e): perf score=14.095187
I20260812 06:17:50.500968  8961 maintenance_manager.cc:643] P 7095a22e55a04de78a77e114367cab2f: FlushDeltaMemStoresOp(5e5ef4c2801e454cb784c9d74645915e) complete. Timing: real 0.055s	user 0.024s	sys 0.020s Metrics: {"bytes_written":16409906,"delete_count":0,"lbm_write_time_us":16635,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:17:50.501538  9071 maintenance_manager.cc:419] P 7095a22e55a04de78a77e114367cab2f: Scheduling FlushDeltaMemStoresOp(5e5ef4c2801e454cb784c9d74645915e): perf score=2.188937
I20260812 06:17:50.511605  8961 maintenance_manager.cc:643] P 7095a22e55a04de78a77e114367cab2f: FlushDeltaMemStoresOp(5e5ef4c2801e454cb784c9d74645915e) complete. Timing: real 0.010s	user 0.004s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3753,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:50.512045  9071 maintenance_manager.cc:419] P 7095a22e55a04de78a77e114367cab2f: Scheduling MajorDeltaCompactionOp(5e5ef4c2801e454cb784c9d74645915e): perf score=1.000000
I20260812 06:17:50.672128  8961 maintenance_manager.cc:643] P 7095a22e55a04de78a77e114367cab2f: MajorDeltaCompactionOp(5e5ef4c2801e454cb784c9d74645915e) complete. Timing: real 0.160s	user 0.126s	sys 0.033s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24815688,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":659,"lbm_read_time_us":11492,"lbm_reads_lt_1ms":572,"lbm_write_time_us":26187,"lbm_writes_lt_1ms":543,"mutex_wait_us":382,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":279936,"update_count":2500}
I20260812 06:17:50.672747  9071 maintenance_manager.cc:419] P 7095a22e55a04de78a77e114367cab2f: Scheduling FlushDeltaMemStoresOp(5e5ef4c2801e454cb784c9d74645915e): perf score=10.126437
I20260812 06:17:50.704115  8961 maintenance_manager.cc:643] P 7095a22e55a04de78a77e114367cab2f: FlushDeltaMemStoresOp(5e5ef4c2801e454cb784c9d74645915e) complete. Timing: real 0.031s	user 0.024s	sys 0.004s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":13425,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:17:50.704634  9071 maintenance_manager.cc:419] P 7095a22e55a04de78a77e114367cab2f: Scheduling FlushDeltaMemStoresOp(5e5ef4c2801e454cb784c9d74645915e): perf score=2.188937
I20260812 06:17:50.718714  8961 maintenance_manager.cc:643] P 7095a22e55a04de78a77e114367cab2f: FlushDeltaMemStoresOp(5e5ef4c2801e454cb784c9d74645915e) complete. Timing: real 0.014s	user 0.008s	sys 0.004s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":5819,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:50.720718  9071 maintenance_manager.cc:419] P 7095a22e55a04de78a77e114367cab2f: Scheduling MajorDeltaCompactionOp(5e5ef4c2801e454cb784c9d74645915e): perf score=1.000000
I20260812 06:17:50.849083  8961 maintenance_manager.cc:643] P 7095a22e55a04de78a77e114367cab2f: MajorDeltaCompactionOp(5e5ef4c2801e454cb784c9d74645915e) complete. Timing: real 0.128s	user 0.093s	sys 0.035s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20713271,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":439,"lbm_read_time_us":7903,"lbm_reads_lt_1ms":472,"lbm_write_time_us":25534,"lbm_writes_lt_1ms":443,"mutex_wait_us":22,"peak_mem_usage":50689328,"reinsert_count":0,"update_count":2000}
I20260812 06:17:50.849913  9071 maintenance_manager.cc:419] P 7095a22e55a04de78a77e114367cab2f: Scheduling FlushDeltaMemStoresOp(5e5ef4c2801e454cb784c9d74645915e): perf score=11.118625
I20260812 06:17:50.880632  8961 maintenance_manager.cc:643] P 7095a22e55a04de78a77e114367cab2f: FlushDeltaMemStoresOp(5e5ef4c2801e454cb784c9d74645915e) complete. Timing: real 0.030s	user 0.020s	sys 0.008s Metrics: {"bytes_written":12594658,"delete_count":0,"lbm_write_time_us":13080,"lbm_writes_lt_1ms":310,"reinsert_count":0,"update_count":1535}
I20260812 06:17:50.881176  9071 maintenance_manager.cc:419] P 7095a22e55a04de78a77e114367cab2f: Scheduling FlushDeltaMemStoresOp(5e5ef4c2801e454cb784c9d74645915e): perf score=2.188937
I20260812 06:17:50.894945  8961 maintenance_manager.cc:643] P 7095a22e55a04de78a77e114367cab2f: FlushDeltaMemStoresOp(5e5ef4c2801e454cb784c9d74645915e) complete. Timing: real 0.014s	user 0.011s	sys 0.001s Metrics: {"bytes_written":3815484,"delete_count":0,"lbm_write_time_us":5385,"lbm_writes_lt_1ms":96,"reinsert_count":0,"update_count":465}
I20260812 06:17:50.895395  9071 maintenance_manager.cc:419] P 7095a22e55a04de78a77e114367cab2f: Scheduling MajorDeltaCompactionOp(5e5ef4c2801e454cb784c9d74645915e): perf score=1.000000
I20260812 06:17:51.017983  8961 maintenance_manager.cc:643] P 7095a22e55a04de78a77e114367cab2f: MajorDeltaCompactionOp(5e5ef4c2801e454cb784c9d74645915e) complete. Timing: real 0.122s	user 0.091s	sys 0.028s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20713265,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":706,"lbm_read_time_us":7149,"lbm_reads_lt_1ms":468,"lbm_write_time_us":23266,"lbm_writes_lt_1ms":443,"mutex_wait_us":322,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":3328,"update_count":2000}
I20260812 06:17:51.018646  9071 maintenance_manager.cc:419] P 7095a22e55a04de78a77e114367cab2f: Scheduling FlushDeltaMemStoresOp(5e5ef4c2801e454cb784c9d74645915e): perf score=10.126437
I20260812 06:17:51.065788  8961 maintenance_manager.cc:643] P 7095a22e55a04de78a77e114367cab2f: FlushDeltaMemStoresOp(5e5ef4c2801e454cb784c9d74645915e) complete. Timing: real 0.047s	user 0.023s	sys 0.012s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":15604,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:17:51.066309  9071 maintenance_manager.cc:419] P 7095a22e55a04de78a77e114367cab2f: Scheduling FlushDeltaMemStoresOp(5e5ef4c2801e454cb784c9d74645915e): perf score=2.188937
I20260812 06:17:51.076253  8961 maintenance_manager.cc:643] P 7095a22e55a04de78a77e114367cab2f: FlushDeltaMemStoresOp(5e5ef4c2801e454cb784c9d74645915e) complete. Timing: real 0.010s	user 0.008s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3506,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:51.076738  9071 maintenance_manager.cc:419] P 7095a22e55a04de78a77e114367cab2f: Scheduling MajorDeltaCompactionOp(5e5ef4c2801e454cb784c9d74645915e): perf score=1.000000
I20260812 06:17:51.198693  8961 maintenance_manager.cc:643] P 7095a22e55a04de78a77e114367cab2f: MajorDeltaCompactionOp(5e5ef4c2801e454cb784c9d74645915e) complete. Timing: real 0.122s	user 0.098s	sys 0.024s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20713272,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":277,"lbm_read_time_us":9265,"lbm_reads_lt_1ms":472,"lbm_write_time_us":22517,"lbm_writes_lt_1ms":443,"mutex_wait_us":63,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":4224,"update_count":2000}
I20260812 06:17:51.199229  9071 maintenance_manager.cc:419] P 7095a22e55a04de78a77e114367cab2f: Scheduling FlushDeltaMemStoresOp(5e5ef4c2801e454cb784c9d74645915e): perf score=10.126437
I20260812 06:17:51.246680  8961 maintenance_manager.cc:643] P 7095a22e55a04de78a77e114367cab2f: FlushDeltaMemStoresOp(5e5ef4c2801e454cb784c9d74645915e) complete. Timing: real 0.047s	user 0.014s	sys 0.023s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":13610,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:17:51.247237  9071 maintenance_manager.cc:419] P 7095a22e55a04de78a77e114367cab2f: Scheduling FlushDeltaMemStoresOp(5e5ef4c2801e454cb784c9d74645915e): perf score=2.188937
I20260812 06:17:51.257853  8961 maintenance_manager.cc:643] P 7095a22e55a04de78a77e114367cab2f: FlushDeltaMemStoresOp(5e5ef4c2801e454cb784c9d74645915e) complete. Timing: real 0.010s	user 0.005s	sys 0.005s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3914,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:51.258330  9071 maintenance_manager.cc:419] P 7095a22e55a04de78a77e114367cab2f: Scheduling MajorDeltaCompactionOp(5e5ef4c2801e454cb784c9d74645915e): perf score=1.000000
I20260812 06:17:51.397244  8961 maintenance_manager.cc:643] P 7095a22e55a04de78a77e114367cab2f: MajorDeltaCompactionOp(5e5ef4c2801e454cb784c9d74645915e) complete. Timing: real 0.139s	user 0.085s	sys 0.053s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20713272,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":291,"lbm_read_time_us":10393,"lbm_reads_lt_1ms":472,"lbm_write_time_us":21921,"lbm_writes_lt_1ms":443,"mutex_wait_us":75,"peak_mem_usage":50689328,"reinsert_count":0,"update_count":2000}
I20260812 06:17:51.397750  9071 maintenance_manager.cc:419] P 7095a22e55a04de78a77e114367cab2f: Scheduling FlushDeltaMemStoresOp(5e5ef4c2801e454cb784c9d74645915e): perf score=10.126437
I20260812 06:17:51.439613  8961 maintenance_manager.cc:643] P 7095a22e55a04de78a77e114367cab2f: FlushDeltaMemStoresOp(5e5ef4c2801e454cb784c9d74645915e) complete. Timing: real 0.042s	user 0.017s	sys 0.012s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":14058,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:17:51.440171  9071 maintenance_manager.cc:419] P 7095a22e55a04de78a77e114367cab2f: Scheduling FlushDeltaMemStoresOp(5e5ef4c2801e454cb784c9d74645915e): perf score=2.188937
I20260812 06:17:51.452334  8961 maintenance_manager.cc:643] P 7095a22e55a04de78a77e114367cab2f: FlushDeltaMemStoresOp(5e5ef4c2801e454cb784c9d74645915e) complete. Timing: real 0.012s	user 0.009s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4113,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:51.452945  9071 maintenance_manager.cc:419] P 7095a22e55a04de78a77e114367cab2f: Scheduling MajorDeltaCompactionOp(5e5ef4c2801e454cb784c9d74645915e): perf score=1.000000
I20260812 06:17:51.566090  8961 maintenance_manager.cc:643] P 7095a22e55a04de78a77e114367cab2f: MajorDeltaCompactionOp(5e5ef4c2801e454cb784c9d74645915e) complete. Timing: real 0.112s	user 0.087s	sys 0.025s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20713272,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":1415,"lbm_read_time_us":7971,"lbm_reads_lt_1ms":472,"lbm_write_time_us":21108,"lbm_writes_lt_1ms":443,"mutex_wait_us":526,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":2816,"update_count":2000}
I20260812 06:17:51.566695  9071 maintenance_manager.cc:419] P 7095a22e55a04de78a77e114367cab2f: Scheduling FlushDeltaMemStoresOp(5e5ef4c2801e454cb784c9d74645915e): perf score=10.126437
I20260812 06:17:51.602726  8961 maintenance_manager.cc:643] P 7095a22e55a04de78a77e114367cab2f: FlushDeltaMemStoresOp(5e5ef4c2801e454cb784c9d74645915e) complete. Timing: real 0.036s	user 0.026s	sys 0.003s Metrics: {"bytes_written":12307491,"delete_count":0,"lbm_write_time_us":13597,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:17:51.603307  9071 maintenance_manager.cc:419] P 7095a22e55a04de78a77e114367cab2f: Scheduling FlushDeltaMemStoresOp(5e5ef4c2801e454cb784c9d74645915e): perf score=2.188937
I20260812 06:17:51.618352  8961 maintenance_manager.cc:643] P 7095a22e55a04de78a77e114367cab2f: FlushDeltaMemStoresOp(5e5ef4c2801e454cb784c9d74645915e) complete. Timing: real 0.015s	user 0.014s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5432,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:51.618999  9071 maintenance_manager.cc:419] P 7095a22e55a04de78a77e114367cab2f: Scheduling FlushMRSOp(5e5ef4c2801e454cb784c9d74645915e): perf score=1.000000
I20260812 06:17:51.652238  8961 maintenance_manager.cc:643] P 7095a22e55a04de78a77e114367cab2f: FlushMRSOp(5e5ef4c2801e454cb784c9d74645915e) complete. Timing: real 0.033s	user 0.032s	sys 0.000s Metrics: {"bytes_written":1275447,"cfile_init":1,"dirs.queue_time_us":52,"dirs.run_cpu_time_us":199,"dirs.run_wall_time_us":1039,"drs_written":1,"lbm_read_time_us":37,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1465,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":31}
I20260812 06:17:51.652922  9071 maintenance_manager.cc:419] P 7095a22e55a04de78a77e114367cab2f: Scheduling LogGCOp(5e5ef4c2801e454cb784c9d74645915e): free 132571636 bytes of WAL
I20260812 06:17:51.653152  8961 log_reader.cc:385] T 5e5ef4c2801e454cb784c9d74645915e: removed 13 log segments from log reader
I20260812 06:17:51.653203  8961 log.cc:1079] T 5e5ef4c2801e454cb784c9d74645915e P 7095a22e55a04de78a77e114367cab2f: Deleting log segment in path: /tmp/dist-test-taskB0FmHn/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515466905639-8794-0/minicluster-data/ts-0-root/wals/5e5ef4c2801e454cb784c9d74645915e/wal-000000026 (ops 126-130)
I20260812 06:17:51.653229  8961 log.cc:1079] T 5e5ef4c2801e454cb784c9d74645915e P 7095a22e55a04de78a77e114367cab2f: Deleting log segment in path: /tmp/dist-test-taskB0FmHn/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515466905639-8794-0/minicluster-data/ts-0-root/wals/5e5ef4c2801e454cb784c9d74645915e/wal-000000027 (ops 131-135)
I20260812 06:17:51.653260  8961 log.cc:1079] T 5e5ef4c2801e454cb784c9d74645915e P 7095a22e55a04de78a77e114367cab2f: Deleting log segment in path: /tmp/dist-test-taskB0FmHn/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515466905639-8794-0/minicluster-data/ts-0-root/wals/5e5ef4c2801e454cb784c9d74645915e/wal-000000028 (ops 136-140)
I20260812 06:17:51.653290  8961 log.cc:1079] T 5e5ef4c2801e454cb784c9d74645915e P 7095a22e55a04de78a77e114367cab2f: Deleting log segment in path: /tmp/dist-test-taskB0FmHn/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515466905639-8794-0/minicluster-data/ts-0-root/wals/5e5ef4c2801e454cb784c9d74645915e/wal-000000029 (ops 141-145)
I20260812 06:17:51.653323  8961 log.cc:1079] T 5e5ef4c2801e454cb784c9d74645915e P 7095a22e55a04de78a77e114367cab2f: Deleting log segment in path: /tmp/dist-test-taskB0FmHn/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515466905639-8794-0/minicluster-data/ts-0-root/wals/5e5ef4c2801e454cb784c9d74645915e/wal-000000030 (ops 146-150)
I20260812 06:17:51.653358  8961 log.cc:1079] T 5e5ef4c2801e454cb784c9d74645915e P 7095a22e55a04de78a77e114367cab2f: Deleting log segment in path: /tmp/dist-test-taskB0FmHn/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515466905639-8794-0/minicluster-data/ts-0-root/wals/5e5ef4c2801e454cb784c9d74645915e/wal-000000031 (ops 151-155)
I20260812 06:17:51.653399  8961 log.cc:1079] T 5e5ef4c2801e454cb784c9d74645915e P 7095a22e55a04de78a77e114367cab2f: Deleting log segment in path: /tmp/dist-test-taskB0FmHn/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515466905639-8794-0/minicluster-data/ts-0-root/wals/5e5ef4c2801e454cb784c9d74645915e/wal-000000032 (ops 156-160)
I20260812 06:17:51.653434  8961 log.cc:1079] T 5e5ef4c2801e454cb784c9d74645915e P 7095a22e55a04de78a77e114367cab2f: Deleting log segment in path: /tmp/dist-test-taskB0FmHn/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515466905639-8794-0/minicluster-data/ts-0-root/wals/5e5ef4c2801e454cb784c9d74645915e/wal-000000033 (ops 161-164)
I20260812 06:17:51.653457  8961 log.cc:1079] T 5e5ef4c2801e454cb784c9d74645915e P 7095a22e55a04de78a77e114367cab2f: Deleting log segment in path: /tmp/dist-test-taskB0FmHn/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515466905639-8794-0/minicluster-data/ts-0-root/wals/5e5ef4c2801e454cb784c9d74645915e/wal-000000034 (ops 165-169)
I20260812 06:17:51.653488  8961 log.cc:1079] T 5e5ef4c2801e454cb784c9d74645915e P 7095a22e55a04de78a77e114367cab2f: Deleting log segment in path: /tmp/dist-test-taskB0FmHn/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515466905639-8794-0/minicluster-data/ts-0-root/wals/5e5ef4c2801e454cb784c9d74645915e/wal-000000035 (ops 170-174)
I20260812 06:17:51.653520  8961 log.cc:1079] T 5e5ef4c2801e454cb784c9d74645915e P 7095a22e55a04de78a77e114367cab2f: Deleting log segment in path: /tmp/dist-test-taskB0FmHn/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515466905639-8794-0/minicluster-data/ts-0-root/wals/5e5ef4c2801e454cb784c9d74645915e/wal-000000036 (ops 175-178)
I20260812 06:17:51.653553  8961 log.cc:1079] T 5e5ef4c2801e454cb784c9d74645915e P 7095a22e55a04de78a77e114367cab2f: Deleting log segment in path: /tmp/dist-test-taskB0FmHn/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515466905639-8794-0/minicluster-data/ts-0-root/wals/5e5ef4c2801e454cb784c9d74645915e/wal-000000037 (ops 179-183)
I20260812 06:17:51.653584  8961 log.cc:1079] T 5e5ef4c2801e454cb784c9d74645915e P 7095a22e55a04de78a77e114367cab2f: Deleting log segment in path: /tmp/dist-test-taskB0FmHn/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515466905639-8794-0/minicluster-data/ts-0-root/wals/5e5ef4c2801e454cb784c9d74645915e/wal-000000038 (ops 184-188)
I20260812 06:17:51.677876  8961 maintenance_manager.cc:643] P 7095a22e55a04de78a77e114367cab2f: LogGCOp(5e5ef4c2801e454cb784c9d74645915e) complete. Timing: real 0.025s	user 0.000s	sys 0.024s Metrics: {}
I20260812 06:17:51.678370  9071 maintenance_manager.cc:419] P 7095a22e55a04de78a77e114367cab2f: Scheduling UndoDeltaBlockGCOp(5e5ef4c2801e454cb784c9d74645915e): 483 bytes on disk
I20260812 06:17:51.678834  8961 maintenance_manager.cc:643] P 7095a22e55a04de78a77e114367cab2f: UndoDeltaBlockGCOp(5e5ef4c2801e454cb784c9d74645915e) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":53,"lbm_reads_lt_1ms":4}
I20260812 06:17:51.679613  9071 maintenance_manager.cc:419] P 7095a22e55a04de78a77e114367cab2f: Scheduling FlushDeltaMemStoresOp(5e5ef4c2801e454cb784c9d74645915e): perf score=3.181125
I20260812 06:17:51.691478  8961 maintenance_manager.cc:643] P 7095a22e55a04de78a77e114367cab2f: FlushDeltaMemStoresOp(5e5ef4c2801e454cb784c9d74645915e) complete. Timing: real 0.012s	user 0.010s	sys 0.000s Metrics: {"bytes_written":4800077,"delete_count":0,"lbm_write_time_us":4580,"lbm_writes_lt_1ms":120,"reinsert_count":0,"update_count":585}
I20260812 06:17:51.691953  9071 maintenance_manager.cc:419] P 7095a22e55a04de78a77e114367cab2f: Scheduling FlushDeltaMemStoresOp(5e5ef4c2801e454cb784c9d74645915e): perf score=2.188937
I20260812 06:17:51.700773  8961 maintenance_manager.cc:643] P 7095a22e55a04de78a77e114367cab2f: FlushDeltaMemStoresOp(5e5ef4c2801e454cb784c9d74645915e) complete. Timing: real 0.009s	user 0.007s	sys 0.000s Metrics: {"bytes_written":3405230,"delete_count":0,"lbm_write_time_us":3076,"lbm_writes_lt_1ms":86,"reinsert_count":0,"update_count":415}
I20260812 06:17:51.701453  9071 maintenance_manager.cc:419] P 7095a22e55a04de78a77e114367cab2f: Scheduling MajorDeltaCompactionOp(5e5ef4c2801e454cb784c9d74645915e): perf score=1.000000
I20260812 06:17:51.866978  8794 heavy-update-compaction-itest.cc:229] Time spent updating: real 4.659s	user 1.687s	sys 0.137s
I20260812 06:17:51.871253  8961 maintenance_manager.cc:643] P 7095a22e55a04de78a77e114367cab2f: MajorDeltaCompactionOp(5e5ef4c2801e454cb784c9d74645915e) complete. Timing: real 0.170s	user 0.121s	sys 0.037s Metrics: {"cfile_cache_miss":634,"cfile_cache_miss_bytes":28918324,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":335,"lbm_read_time_us":11548,"lbm_reads_lt_1ms":674,"lbm_write_time_us":31080,"lbm_writes_lt_1ms":643,"mutex_wait_us":38,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":9856,"thread_start_us":74,"threads_started":1,"update_count":3000}
I20260812 06:17:51.871822  9071 maintenance_manager.cc:419] P 7095a22e55a04de78a77e114367cab2f: Scheduling FlushDeltaMemStoresOp(5e5ef4c2801e454cb784c9d74645915e): perf score=14.095187
I20260812 06:17:51.895000  8794 heavy-update-compaction-itest.cc:265] Time spent scanning: real 0.027s	user 0.003s	sys 0.000s
I20260812 06:17:51.895773  8794 tablet_server.cc:179] TabletServer@127.8.150.129:0 shutting down...
I20260812 06:17:51.912055  8961 maintenance_manager.cc:643] P 7095a22e55a04de78a77e114367cab2f: FlushDeltaMemStoresOp(5e5ef4c2801e454cb784c9d74645915e) complete. Timing: real 0.040s	user 0.021s	sys 0.016s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":17789,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:17:51.912644  8794 ts_tablet_manager.cc:1507] Shutting down tablet manager...
I20260812 06:17:51.913095  8794 tablet_replica.cc:333] T 5e5ef4c2801e454cb784c9d74645915e P 7095a22e55a04de78a77e114367cab2f: stopping tablet replica
I20260812 06:17:51.913297  8794 raft_consensus.cc:2243] T 5e5ef4c2801e454cb784c9d74645915e P 7095a22e55a04de78a77e114367cab2f [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:17:51.913486  8794 raft_consensus.cc:2272] T 5e5ef4c2801e454cb784c9d74645915e P 7095a22e55a04de78a77e114367cab2f [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:17:51.928114  8794 tablet_server.cc:196] TabletServer@127.8.150.129:0 shutdown complete.
I20260812 06:17:51.932293  8794 master.cc:562] Master@127.8.150.190:46277 shutting down...
I20260812 06:17:51.935406  8794 raft_consensus.cc:2243] T 00000000000000000000000000000000 P 4310b703530d45f9980bc52cb117a3c5 [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:17:51.935549  8794 raft_consensus.cc:2272] T 00000000000000000000000000000000 P 4310b703530d45f9980bc52cb117a3c5 [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:17:51.935619  8794 tablet_replica.cc:333] T 00000000000000000000000000000000 P 4310b703530d45f9980bc52cb117a3c5: stopping tablet replica
I20260812 06:17:51.947469  8794 master.cc:584] Master@127.8.150.190:46277 shutdown complete.
[       OK ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/0 (5107 ms)
[ RUN      ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/1
I20260812 06:17:52.022436  8794 internal_mini_cluster.cc:156] Creating distributed mini masters. Addrs: 127.8.150.190:36265
I20260812 06:17:52.022828  8794 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:17:52.024732  9126 instance_detector.cc:116] could not retrieve OpenStack instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:17:52.024844  8794 server_base.cc:1061] running on GCE node
W20260812 06:17:52.024925  9120 instance_detector.cc:116] could not retrieve AWS instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:17:52.024857  9123 instance_detector.cc:116] could not retrieve Azure instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:17:52.025316  8794 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:17:52.025360  8794 system_unsync_time.cc:38] NTP support is disabled. Clock error bounds will not be accurate. This configuration is not suitable for distributed clusters.
I20260812 06:17:52.025374  8794 hybrid_clock.cc:648] HybridClock initialized: now 1786515472025374 us; error 0 us; skew 500 ppm
I20260812 06:17:52.026127  8794 webserver.cc:533] Webserver started at http://127.8.150.190:38407/ using document root <none> and password file <none>
I20260812 06:17:52.026269  8794 fs_manager.cc:362] Metadata directory not provided
I20260812 06:17:52.026314  8794 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:17:52.026371  8794 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:17:52.026711  8794 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskB0FmHn/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515466905639-8794-0/minicluster-data/master-0-root/instance:
uuid: "08700069e7fb4c06ad1a2c2cd88c90a7"
format_stamp: "Formatted at 2026-08-12 06:17:52 on dist-test-slave-k5rr"
I20260812 06:17:52.028139  8794 fs_manager.cc:696] Time spent creating directory manager: real 0.001s	user 0.002s	sys 0.000s
I20260812 06:17:52.029044  9136 log_block_manager.cc:4127] Time spent loading block containers with low live blocks: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:17:52.029270  8794 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.001s	sys 0.000s
I20260812 06:17:52.029336  8794 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskB0FmHn/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515466905639-8794-0/minicluster-data/master-0-root
uuid: "08700069e7fb4c06ad1a2c2cd88c90a7"
format_stamp: "Formatted at 2026-08-12 06:17:52 on dist-test-slave-k5rr"
I20260812 06:17:52.029405  8794 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskB0FmHn/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515466905639-8794-0/minicluster-data/master-0-root
metadata directory: /tmp/dist-test-taskB0FmHn/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515466905639-8794-0/minicluster-data/master-0-root
1 data directories: /tmp/dist-test-taskB0FmHn/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515466905639-8794-0/minicluster-data/master-0-root/data
Total live blocks: 0
Total live bytes: 0
Total live bytes (after alignment): 0
Total number of LBM containers: 0 (0 full)
Did not check for missing blocks
Did not check for orphaned blocks
Total full LBM containers with extra space: 0 (0 repaired)
Total full LBM container extra space in bytes: 0 (0 repaired)
Total incomplete LBM containers: 0 (0 repaired)
Total LBM partial records: 0 (0 repaired)
Total corrupted LBM metadata records in RocksDB: 0 (0 repaired)
I20260812 06:17:52.036813  8794 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:17:52.037196  8794 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:17:52.041395  8794 rpc_server.cc:307] RPC server started. Bound to: 127.8.150.190:36265
I20260812 06:17:52.058517  9224 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.8.150.190:36265 every 8 connection(s)
I20260812 06:17:52.059063  9225 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet 00000000000000000000000000000000. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:17:52.060858  9225 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P 08700069e7fb4c06ad1a2c2cd88c90a7: Bootstrap starting.
I20260812 06:17:52.061654  9225 tablet_bootstrap.cc:654] T 00000000000000000000000000000000 P 08700069e7fb4c06ad1a2c2cd88c90a7: Neither blocks nor log segments found. Creating new log.
I20260812 06:17:52.062626  9225 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P 08700069e7fb4c06ad1a2c2cd88c90a7: No bootstrap required, opened a new log
I20260812 06:17:52.063041  9225 raft_consensus.cc:359] T 00000000000000000000000000000000 P 08700069e7fb4c06ad1a2c2cd88c90a7 [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "08700069e7fb4c06ad1a2c2cd88c90a7" member_type: VOTER }
I20260812 06:17:52.063131  9225 raft_consensus.cc:385] T 00000000000000000000000000000000 P 08700069e7fb4c06ad1a2c2cd88c90a7 [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:17:52.063162  9225 raft_consensus.cc:740] T 00000000000000000000000000000000 P 08700069e7fb4c06ad1a2c2cd88c90a7 [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: 08700069e7fb4c06ad1a2c2cd88c90a7, State: Initialized, Role: FOLLOWER
I20260812 06:17:52.063302  9225 consensus_queue.cc:260] T 00000000000000000000000000000000 P 08700069e7fb4c06ad1a2c2cd88c90a7 [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: "08700069e7fb4c06ad1a2c2cd88c90a7" member_type: VOTER }
I20260812 06:17:52.063377  9225 raft_consensus.cc:399] T 00000000000000000000000000000000 P 08700069e7fb4c06ad1a2c2cd88c90a7 [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:17:52.063417  9225 raft_consensus.cc:493] T 00000000000000000000000000000000 P 08700069e7fb4c06ad1a2c2cd88c90a7 [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:17:52.063467  9225 raft_consensus.cc:3060] T 00000000000000000000000000000000 P 08700069e7fb4c06ad1a2c2cd88c90a7 [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:17:52.064136  9225 raft_consensus.cc:515] T 00000000000000000000000000000000 P 08700069e7fb4c06ad1a2c2cd88c90a7 [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "08700069e7fb4c06ad1a2c2cd88c90a7" member_type: VOTER }
I20260812 06:17:52.064268  9225 leader_election.cc:304] T 00000000000000000000000000000000 P 08700069e7fb4c06ad1a2c2cd88c90a7 [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: 08700069e7fb4c06ad1a2c2cd88c90a7; no voters: 
I20260812 06:17:52.064448  9225 leader_election.cc:290] T 00000000000000000000000000000000 P 08700069e7fb4c06ad1a2c2cd88c90a7 [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:17:52.064550  9230 raft_consensus.cc:2804] T 00000000000000000000000000000000 P 08700069e7fb4c06ad1a2c2cd88c90a7 [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:17:52.064735  9230 raft_consensus.cc:697] T 00000000000000000000000000000000 P 08700069e7fb4c06ad1a2c2cd88c90a7 [term 1 LEADER]: Becoming Leader. State: Replica: 08700069e7fb4c06ad1a2c2cd88c90a7, State: Running, Role: LEADER
I20260812 06:17:52.064868  9230 consensus_queue.cc:237] T 00000000000000000000000000000000 P 08700069e7fb4c06ad1a2c2cd88c90a7 [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: "08700069e7fb4c06ad1a2c2cd88c90a7" member_type: VOTER }
I20260812 06:17:52.064918  9225 sys_catalog.cc:565] T 00000000000000000000000000000000 P 08700069e7fb4c06ad1a2c2cd88c90a7 [sys.catalog]: configured and running, proceeding with master startup.
I20260812 06:17:52.065317  9231 sys_catalog.cc:455] T 00000000000000000000000000000000 P 08700069e7fb4c06ad1a2c2cd88c90a7 [sys.catalog]: SysCatalogTable state changed. Reason: RaftConsensus started. Latest consensus state: current_term: 1 leader_uuid: "08700069e7fb4c06ad1a2c2cd88c90a7" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "08700069e7fb4c06ad1a2c2cd88c90a7" member_type: VOTER } }
I20260812 06:17:52.065409  9231 sys_catalog.cc:458] T 00000000000000000000000000000000 P 08700069e7fb4c06ad1a2c2cd88c90a7 [sys.catalog]: This master's current role is: LEADER
I20260812 06:17:52.065356  9232 sys_catalog.cc:455] T 00000000000000000000000000000000 P 08700069e7fb4c06ad1a2c2cd88c90a7 [sys.catalog]: SysCatalogTable state changed. Reason: New leader 08700069e7fb4c06ad1a2c2cd88c90a7. Latest consensus state: current_term: 1 leader_uuid: "08700069e7fb4c06ad1a2c2cd88c90a7" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "08700069e7fb4c06ad1a2c2cd88c90a7" member_type: VOTER } }
I20260812 06:17:52.065454  9232 sys_catalog.cc:458] T 00000000000000000000000000000000 P 08700069e7fb4c06ad1a2c2cd88c90a7 [sys.catalog]: This master's current role is: LEADER
I20260812 06:17:52.065706  9234 catalog_manager.cc:1511] Loading table and tablet metadata into memory...
I20260812 06:17:52.066532  9234 catalog_manager.cc:1520] Initializing Kudu cluster ID...
I20260812 06:17:52.066675  8794 internal_mini_cluster.cc:184] Waiting to initialize catalog manager on master 0
I20260812 06:17:52.068295  9234 catalog_manager.cc:1383] Generated new cluster ID: 9b17055683474d90a3d2a53e2695d2bb
I20260812 06:17:52.068342  9234 catalog_manager.cc:1531] Initializing Kudu internal certificate authority...
I20260812 06:17:52.094228  9234 catalog_manager.cc:1406] Generated new certificate authority record
I20260812 06:17:52.094774  9234 catalog_manager.cc:1540] Loading token signing keys...
I20260812 06:17:52.101122  9234 catalog_manager.cc:6092] T 00000000000000000000000000000000 P 08700069e7fb4c06ad1a2c2cd88c90a7: Generated new TSK 0
I20260812 06:17:52.101279  9234 catalog_manager.cc:1550] Initializing in-progress tserver states...
I20260812 06:17:52.131181  8794 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:17:52.132988  9257 instance_detector.cc:116] could not retrieve AWS instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:17:52.133108  9258 instance_detector.cc:116] could not retrieve Azure instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:17:52.133129  9261 instance_detector.cc:116] could not retrieve OpenStack instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:17:52.133205  8794 server_base.cc:1061] running on GCE node
I20260812 06:17:52.133507  8794 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:17:52.133558  8794 system_unsync_time.cc:38] NTP support is disabled. Clock error bounds will not be accurate. This configuration is not suitable for distributed clusters.
I20260812 06:17:52.133572  8794 hybrid_clock.cc:648] HybridClock initialized: now 1786515472133573 us; error 0 us; skew 500 ppm
I20260812 06:17:52.134346  8794 webserver.cc:533] Webserver started at http://127.8.150.129:45237/ using document root <none> and password file <none>
I20260812 06:17:52.134510  8794 fs_manager.cc:362] Metadata directory not provided
I20260812 06:17:52.134560  8794 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:17:52.134634  8794 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:17:52.135002  8794 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskB0FmHn/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515466905639-8794-0/minicluster-data/ts-0-root/instance:
uuid: "2823bf5f2cac492a8fdfdbb4c44b23ee"
format_stamp: "Formatted at 2026-08-12 06:17:52 on dist-test-slave-k5rr"
I20260812 06:17:52.136449  8794 fs_manager.cc:696] Time spent creating directory manager: real 0.001s	user 0.002s	sys 0.000s
I20260812 06:17:52.137393  9274 log_block_manager.cc:4127] Time spent loading block containers with low live blocks: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:17:52.137622  8794 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.001s	sys 0.000s
I20260812 06:17:52.137688  8794 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskB0FmHn/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515466905639-8794-0/minicluster-data/ts-0-root
uuid: "2823bf5f2cac492a8fdfdbb4c44b23ee"
format_stamp: "Formatted at 2026-08-12 06:17:52 on dist-test-slave-k5rr"
I20260812 06:17:52.137755  8794 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskB0FmHn/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515466905639-8794-0/minicluster-data/ts-0-root
metadata directory: /tmp/dist-test-taskB0FmHn/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515466905639-8794-0/minicluster-data/ts-0-root
1 data directories: /tmp/dist-test-taskB0FmHn/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515466905639-8794-0/minicluster-data/ts-0-root/data
Total live blocks: 0
Total live bytes: 0
Total live bytes (after alignment): 0
Total number of LBM containers: 0 (0 full)
Did not check for missing blocks
Did not check for orphaned blocks
Total full LBM containers with extra space: 0 (0 repaired)
Total full LBM container extra space in bytes: 0 (0 repaired)
Total incomplete LBM containers: 0 (0 repaired)
Total LBM partial records: 0 (0 repaired)
Total corrupted LBM metadata records in RocksDB: 0 (0 repaired)
I20260812 06:17:52.146608  8794 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:17:52.146907  8794 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:17:52.147157  8794 txn_system_client.cc:432] TxnSystemClient initialization is disabled...
I20260812 06:17:52.147590  8794 ts_tablet_manager.cc:585] Loaded tablet metadata (0 total tablets, 0 live tablets)
I20260812 06:17:52.147629  8794 ts_tablet_manager.cc:531] Time spent load tablet metadata: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:17:52.147668  8794 ts_tablet_manager.cc:616] Registered 0 tablets
I20260812 06:17:52.147696  8794 ts_tablet_manager.cc:595] Time spent register tablets: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:17:52.151594  8794 rpc_server.cc:307] RPC server started. Bound to: 127.8.150.129:32867
I20260812 06:17:52.151638  9374 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.8.150.129:32867 every 8 connection(s)
I20260812 06:17:52.158905  9375 heartbeater.cc:344] Connected to a master server at 127.8.150.190:36265
I20260812 06:17:52.159009  9375 heartbeater.cc:461] Registering TS with master...
I20260812 06:17:52.159233  9375 heartbeater.cc:507] Master 127.8.150.190:36265 requested a full tablet report, sending...
I20260812 06:17:52.159845  9167 ts_manager.cc:194] Registered new tserver with Master: 2823bf5f2cac492a8fdfdbb4c44b23ee (127.8.150.129:32867)
I20260812 06:17:52.160543  9167 master_service.cc:502] Signed X509 certificate for tserver {username='slave'} at 127.0.0.1:41758
I20260812 06:17:52.160820  8794 internal_mini_cluster.cc:371] 1 TS(s) registered with all masters after 0.008832872s
I20260812 06:17:52.167047  9167 catalog_manager.cc:2283] Servicing CreateTable request from {username='slave'} at 127.0.0.1:41762:
name: "heavy-update-compaction-test"
schema {
  columns {
    name: "key"
    type: INT64
    is_key: true
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_a"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_b"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_c"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_d"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_e"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
}
num_replicas: 1
split_rows_range_bounds {
}
partition_schema {
  range_schema {
  }
}
I20260812 06:17:52.174875  9318 tablet_service.cc:1511] Processing CreateTablet for tablet 788cfd3762704a73b904631ef2ed017e (DEFAULT_TABLE table=heavy-update-compaction-test [id=2aee7248251242c6901a24e94fea7387]), partition=
I20260812 06:17:52.175135  9318 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet 788cfd3762704a73b904631ef2ed017e. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:17:52.176970  9393 tablet_bootstrap.cc:492] T 788cfd3762704a73b904631ef2ed017e P 2823bf5f2cac492a8fdfdbb4c44b23ee: Bootstrap starting.
I20260812 06:17:52.177933  9393 tablet_bootstrap.cc:654] T 788cfd3762704a73b904631ef2ed017e P 2823bf5f2cac492a8fdfdbb4c44b23ee: Neither blocks nor log segments found. Creating new log.
I20260812 06:17:52.178882  9393 tablet_bootstrap.cc:492] T 788cfd3762704a73b904631ef2ed017e P 2823bf5f2cac492a8fdfdbb4c44b23ee: No bootstrap required, opened a new log
I20260812 06:17:52.178964  9393 ts_tablet_manager.cc:1403] T 788cfd3762704a73b904631ef2ed017e P 2823bf5f2cac492a8fdfdbb4c44b23ee: Time spent bootstrapping tablet: real 0.002s	user 0.000s	sys 0.001s
I20260812 06:17:52.179332  9393 raft_consensus.cc:359] T 788cfd3762704a73b904631ef2ed017e P 2823bf5f2cac492a8fdfdbb4c44b23ee [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "2823bf5f2cac492a8fdfdbb4c44b23ee" member_type: VOTER last_known_addr { host: "127.8.150.129" port: 32867 } }
I20260812 06:17:52.179414  9393 raft_consensus.cc:385] T 788cfd3762704a73b904631ef2ed017e P 2823bf5f2cac492a8fdfdbb4c44b23ee [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:17:52.179441  9393 raft_consensus.cc:740] T 788cfd3762704a73b904631ef2ed017e P 2823bf5f2cac492a8fdfdbb4c44b23ee [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: 2823bf5f2cac492a8fdfdbb4c44b23ee, State: Initialized, Role: FOLLOWER
I20260812 06:17:52.179534  9393 consensus_queue.cc:260] T 788cfd3762704a73b904631ef2ed017e P 2823bf5f2cac492a8fdfdbb4c44b23ee [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: "2823bf5f2cac492a8fdfdbb4c44b23ee" member_type: VOTER last_known_addr { host: "127.8.150.129" port: 32867 } }
I20260812 06:17:52.179592  9393 raft_consensus.cc:399] T 788cfd3762704a73b904631ef2ed017e P 2823bf5f2cac492a8fdfdbb4c44b23ee [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:17:52.179620  9393 raft_consensus.cc:493] T 788cfd3762704a73b904631ef2ed017e P 2823bf5f2cac492a8fdfdbb4c44b23ee [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:17:52.179651  9393 raft_consensus.cc:3060] T 788cfd3762704a73b904631ef2ed017e P 2823bf5f2cac492a8fdfdbb4c44b23ee [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:17:52.180351  9393 raft_consensus.cc:515] T 788cfd3762704a73b904631ef2ed017e P 2823bf5f2cac492a8fdfdbb4c44b23ee [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "2823bf5f2cac492a8fdfdbb4c44b23ee" member_type: VOTER last_known_addr { host: "127.8.150.129" port: 32867 } }
I20260812 06:17:52.180491  9393 leader_election.cc:304] T 788cfd3762704a73b904631ef2ed017e P 2823bf5f2cac492a8fdfdbb4c44b23ee [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: 2823bf5f2cac492a8fdfdbb4c44b23ee; no voters: 
I20260812 06:17:52.180687  9393 leader_election.cc:290] T 788cfd3762704a73b904631ef2ed017e P 2823bf5f2cac492a8fdfdbb4c44b23ee [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:17:52.180853  9397 raft_consensus.cc:2804] T 788cfd3762704a73b904631ef2ed017e P 2823bf5f2cac492a8fdfdbb4c44b23ee [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:17:52.181052  9393 ts_tablet_manager.cc:1434] T 788cfd3762704a73b904631ef2ed017e P 2823bf5f2cac492a8fdfdbb4c44b23ee: Time spent starting tablet: real 0.002s	user 0.000s	sys 0.002s
I20260812 06:17:52.181074  9375 heartbeater.cc:499] Master 127.8.150.190:36265 was elected leader, sending a full tablet report...
I20260812 06:17:52.181242  9397 raft_consensus.cc:697] T 788cfd3762704a73b904631ef2ed017e P 2823bf5f2cac492a8fdfdbb4c44b23ee [term 1 LEADER]: Becoming Leader. State: Replica: 2823bf5f2cac492a8fdfdbb4c44b23ee, State: Running, Role: LEADER
I20260812 06:17:52.181356  9397 consensus_queue.cc:237] T 788cfd3762704a73b904631ef2ed017e P 2823bf5f2cac492a8fdfdbb4c44b23ee [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: "2823bf5f2cac492a8fdfdbb4c44b23ee" member_type: VOTER last_known_addr { host: "127.8.150.129" port: 32867 } }
I20260812 06:17:52.182561  9167 catalog_manager.cc:5719] T 788cfd3762704a73b904631ef2ed017e P 2823bf5f2cac492a8fdfdbb4c44b23ee reported cstate change: term changed from 0 to 1, leader changed from <none> to 2823bf5f2cac492a8fdfdbb4c44b23ee (127.8.150.129). New cstate: current_term: 1 leader_uuid: "2823bf5f2cac492a8fdfdbb4c44b23ee" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "2823bf5f2cac492a8fdfdbb4c44b23ee" member_type: VOTER last_known_addr { host: "127.8.150.129" port: 32867 } health_report { overall_health: HEALTHY } } }
I20260812 06:17:52.235270  8794 heavy-update-compaction-itest.cc:215] Time spent inserting: real 0.049s	user 0.009s	sys 0.012s
I20260812 06:17:52.402676  9376 maintenance_manager.cc:419] P 2823bf5f2cac492a8fdfdbb4c44b23ee: Scheduling FlushMRSOp(788cfd3762704a73b904631ef2ed017e): perf score=23.023690
I20260812 06:17:52.555742  9279 maintenance_manager.cc:643] P 2823bf5f2cac492a8fdfdbb4c44b23ee: FlushMRSOp(788cfd3762704a73b904631ef2ed017e) complete. Timing: real 0.153s	user 0.112s	sys 0.036s Metrics: {"bytes_written":13127976,"cfile_init":1,"delete_count":0,"dirs.queue_time_us":58,"dirs.run_cpu_time_us":177,"dirs.run_wall_time_us":793,"drs_written":1,"lbm_read_time_us":47,"lbm_reads_lt_1ms":4,"lbm_write_time_us":40242,"lbm_writes_lt_1ms":877,"mutex_wait_us":1608,"peak_mem_usage":0,"reinsert_count":0,"rows_written":105,"spinlock_wait_cycles":896,"update_count":1600}
I20260812 06:17:52.556478  9376 maintenance_manager.cc:419] P 2823bf5f2cac492a8fdfdbb4c44b23ee: Scheduling LogGCOp(788cfd3762704a73b904631ef2ed017e): free 20743880 bytes of WAL
I20260812 06:17:52.556752  9279 log_reader.cc:385] T 788cfd3762704a73b904631ef2ed017e: removed 2 log segments from log reader
I20260812 06:17:52.556806  9279 log.cc:1079] T 788cfd3762704a73b904631ef2ed017e P 2823bf5f2cac492a8fdfdbb4c44b23ee: Deleting log segment in path: /tmp/dist-test-taskB0FmHn/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515466905639-8794-0/minicluster-data/ts-0-root/wals/788cfd3762704a73b904631ef2ed017e/wal-000000001 (ops 1-6)
I20260812 06:17:52.556864  9279 log.cc:1079] T 788cfd3762704a73b904631ef2ed017e P 2823bf5f2cac492a8fdfdbb4c44b23ee: Deleting log segment in path: /tmp/dist-test-taskB0FmHn/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515466905639-8794-0/minicluster-data/ts-0-root/wals/788cfd3762704a73b904631ef2ed017e/wal-000000002 (ops 7-11)
I20260812 06:17:52.561087  9279 maintenance_manager.cc:643] P 2823bf5f2cac492a8fdfdbb4c44b23ee: LogGCOp(788cfd3762704a73b904631ef2ed017e) complete. Timing: real 0.004s	user 0.000s	sys 0.004s Metrics: {}
I20260812 06:17:52.561450  9376 maintenance_manager.cc:419] P 2823bf5f2cac492a8fdfdbb4c44b23ee: Scheduling UndoDeltaBlockGCOp(788cfd3762704a73b904631ef2ed017e): 20513810 bytes on disk
I20260812 06:17:52.561872  9279 maintenance_manager.cc:643] P 2823bf5f2cac492a8fdfdbb4c44b23ee: UndoDeltaBlockGCOp(788cfd3762704a73b904631ef2ed017e) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":62,"lbm_reads_lt_1ms":4,"spinlock_wait_cycles":768}
I20260812 06:17:52.562276  9376 maintenance_manager.cc:419] P 2823bf5f2cac492a8fdfdbb4c44b23ee: Scheduling FlushDeltaMemStoresOp(788cfd3762704a73b904631ef2ed017e): perf score=2.188937
I20260812 06:17:52.573695  9279 maintenance_manager.cc:643] P 2823bf5f2cac492a8fdfdbb4c44b23ee: FlushDeltaMemStoresOp(788cfd3762704a73b904631ef2ed017e) complete. Timing: real 0.011s	user 0.000s	sys 0.009s Metrics: {"bytes_written":3692410,"delete_count":0,"lbm_write_time_us":3258,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:17:52.574148  9376 maintenance_manager.cc:419] P 2823bf5f2cac492a8fdfdbb4c44b23ee: Scheduling FlushDeltaMemStoresOp(788cfd3762704a73b904631ef2ed017e): perf score=2.188937
I20260812 06:17:52.587229  9279 maintenance_manager.cc:643] P 2823bf5f2cac492a8fdfdbb4c44b23ee: FlushDeltaMemStoresOp(788cfd3762704a73b904631ef2ed017e) complete. Timing: real 0.013s	user 0.011s	sys 0.000s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":4728,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:17:52.587764  9376 maintenance_manager.cc:419] P 2823bf5f2cac492a8fdfdbb4c44b23ee: Scheduling MajorDeltaCompactionOp(788cfd3762704a73b904631ef2ed017e): perf score=1.000000
I20260812 06:17:52.746013  9279 maintenance_manager.cc:643] P 2823bf5f2cac492a8fdfdbb4c44b23ee: MajorDeltaCompactionOp(788cfd3762704a73b904631ef2ed017e) complete. Timing: real 0.158s	user 0.131s	sys 0.024s Metrics: {"cfile_cache_miss":533,"cfile_cache_miss_bytes":24815786,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":469,"lbm_read_time_us":12346,"lbm_reads_lt_1ms":569,"lbm_write_time_us":27348,"lbm_writes_lt_1ms":543,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":768,"thread_start_us":295,"threads_started":5,"update_count":2500}
I20260812 06:17:52.746599  9376 maintenance_manager.cc:419] P 2823bf5f2cac492a8fdfdbb4c44b23ee: Scheduling FlushDeltaMemStoresOp(788cfd3762704a73b904631ef2ed017e): perf score=11.118625
I20260812 06:17:52.790171  9279 maintenance_manager.cc:643] P 2823bf5f2cac492a8fdfdbb4c44b23ee: FlushDeltaMemStoresOp(788cfd3762704a73b904631ef2ed017e) complete. Timing: real 0.043s	user 0.025s	sys 0.015s Metrics: {"bytes_written":12717735,"delete_count":0,"lbm_write_time_us":19611,"lbm_writes_1-10_ms":2,"lbm_writes_lt_1ms":311,"reinsert_count":0,"update_count":1550}
I20260812 06:17:52.790657  9376 maintenance_manager.cc:419] P 2823bf5f2cac492a8fdfdbb4c44b23ee: Scheduling FlushDeltaMemStoresOp(788cfd3762704a73b904631ef2ed017e): perf score=2.188937
I20260812 06:17:52.805529  9279 maintenance_manager.cc:643] P 2823bf5f2cac492a8fdfdbb4c44b23ee: FlushDeltaMemStoresOp(788cfd3762704a73b904631ef2ed017e) complete. Timing: real 0.015s	user 0.006s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3600,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:52.806046  9376 maintenance_manager.cc:419] P 2823bf5f2cac492a8fdfdbb4c44b23ee: Scheduling FlushDeltaMemStoresOp(788cfd3762704a73b904631ef2ed017e): perf score=2.188937
I20260812 06:17:52.814977  9279 maintenance_manager.cc:643] P 2823bf5f2cac492a8fdfdbb4c44b23ee: FlushDeltaMemStoresOp(788cfd3762704a73b904631ef2ed017e) complete. Timing: real 0.009s	user 0.004s	sys 0.003s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3190,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:17:52.815402  9376 maintenance_manager.cc:419] P 2823bf5f2cac492a8fdfdbb4c44b23ee: Scheduling MajorDeltaCompactionOp(788cfd3762704a73b904631ef2ed017e): perf score=1.000000
I20260812 06:17:52.976593  9279 maintenance_manager.cc:643] P 2823bf5f2cac492a8fdfdbb4c44b23ee: MajorDeltaCompactionOp(788cfd3762704a73b904631ef2ed017e) complete. Timing: real 0.161s	user 0.103s	sys 0.041s Metrics: {"cfile_cache_miss":533,"cfile_cache_miss_bytes":24815794,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":570,"lbm_read_time_us":11900,"lbm_reads_lt_1ms":573,"lbm_write_time_us":25013,"lbm_writes_lt_1ms":543,"mutex_wait_us":46,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":15616,"update_count":2500}
I20260812 06:17:52.977299  9376 maintenance_manager.cc:419] P 2823bf5f2cac492a8fdfdbb4c44b23ee: Scheduling FlushDeltaMemStoresOp(788cfd3762704a73b904631ef2ed017e): perf score=14.095187
I20260812 06:17:53.030309  9279 maintenance_manager.cc:643] P 2823bf5f2cac492a8fdfdbb4c44b23ee: FlushDeltaMemStoresOp(788cfd3762704a73b904631ef2ed017e) complete. Timing: real 0.053s	user 0.033s	sys 0.017s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":22772,"lbm_writes_1-10_ms":2,"lbm_writes_lt_1ms":401,"reinsert_count":0,"update_count":2000}
I20260812 06:17:53.030818  9376 maintenance_manager.cc:419] P 2823bf5f2cac492a8fdfdbb4c44b23ee: Scheduling FlushDeltaMemStoresOp(788cfd3762704a73b904631ef2ed017e): perf score=2.188937
I20260812 06:17:53.040417  9279 maintenance_manager.cc:643] P 2823bf5f2cac492a8fdfdbb4c44b23ee: FlushDeltaMemStoresOp(788cfd3762704a73b904631ef2ed017e) complete. Timing: real 0.009s	user 0.008s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3505,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:53.041246  9376 maintenance_manager.cc:419] P 2823bf5f2cac492a8fdfdbb4c44b23ee: Scheduling MajorDeltaCompactionOp(788cfd3762704a73b904631ef2ed017e): perf score=1.000000
I20260812 06:17:53.204386  9279 maintenance_manager.cc:643] P 2823bf5f2cac492a8fdfdbb4c44b23ee: MajorDeltaCompactionOp(788cfd3762704a73b904631ef2ed017e) complete. Timing: real 0.163s	user 0.086s	sys 0.077s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24815683,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":887,"lbm_read_time_us":10916,"lbm_reads_lt_1ms":572,"lbm_write_time_us":25411,"lbm_writes_lt_1ms":543,"mutex_wait_us":25,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":10880,"update_count":2500}
I20260812 06:17:53.204998  9376 maintenance_manager.cc:419] P 2823bf5f2cac492a8fdfdbb4c44b23ee: Scheduling FlushDeltaMemStoresOp(788cfd3762704a73b904631ef2ed017e): perf score=14.095187
I20260812 06:17:53.255074  9279 maintenance_manager.cc:643] P 2823bf5f2cac492a8fdfdbb4c44b23ee: FlushDeltaMemStoresOp(788cfd3762704a73b904631ef2ed017e) complete. Timing: real 0.050s	user 0.044s	sys 0.001s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":20592,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:17:53.255693  9376 maintenance_manager.cc:419] P 2823bf5f2cac492a8fdfdbb4c44b23ee: Scheduling MajorDeltaCompactionOp(788cfd3762704a73b904631ef2ed017e): perf score=1.000000
I20260812 06:17:53.402415  9279 maintenance_manager.cc:643] P 2823bf5f2cac492a8fdfdbb4c44b23ee: MajorDeltaCompactionOp(788cfd3762704a73b904631ef2ed017e) complete. Timing: real 0.147s	user 0.092s	sys 0.048s Metrics: {"cfile_cache_miss":431,"cfile_cache_miss_bytes":20713152,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":1,"delta_iterators_relevant":1,"dirs.queue_time_us":201,"lbm_read_time_us":9138,"lbm_reads_lt_1ms":463,"lbm_write_time_us":22839,"lbm_writes_lt_1ms":443,"mutex_wait_us":3,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":1792,"update_count":2000}
I20260812 06:17:53.402905  9376 maintenance_manager.cc:419] P 2823bf5f2cac492a8fdfdbb4c44b23ee: Scheduling FlushDeltaMemStoresOp(788cfd3762704a73b904631ef2ed017e): perf score=14.095187
I20260812 06:17:53.451316  9279 maintenance_manager.cc:643] P 2823bf5f2cac492a8fdfdbb4c44b23ee: FlushDeltaMemStoresOp(788cfd3762704a73b904631ef2ed017e) complete. Timing: real 0.048s	user 0.026s	sys 0.012s Metrics: {"bytes_written":16409903,"delete_count":0,"lbm_write_time_us":17348,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:17:53.451857  9376 maintenance_manager.cc:419] P 2823bf5f2cac492a8fdfdbb4c44b23ee: Scheduling FlushDeltaMemStoresOp(788cfd3762704a73b904631ef2ed017e): perf score=2.188937
I20260812 06:17:53.467334  9279 maintenance_manager.cc:643] P 2823bf5f2cac492a8fdfdbb4c44b23ee: FlushDeltaMemStoresOp(788cfd3762704a73b904631ef2ed017e) complete. Timing: real 0.015s	user 0.011s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5857,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:53.467855  9376 maintenance_manager.cc:419] P 2823bf5f2cac492a8fdfdbb4c44b23ee: Scheduling MajorDeltaCompactionOp(788cfd3762704a73b904631ef2ed017e): perf score=1.000000
I20260812 06:17:53.655637  9279 maintenance_manager.cc:643] P 2823bf5f2cac492a8fdfdbb4c44b23ee: MajorDeltaCompactionOp(788cfd3762704a73b904631ef2ed017e) complete. Timing: real 0.188s	user 0.115s	sys 0.064s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24815685,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":256,"lbm_read_time_us":11617,"lbm_reads_lt_1ms":572,"lbm_write_time_us":29754,"lbm_writes_lt_1ms":543,"mutex_wait_us":23,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":11008,"update_count":2500}
I20260812 06:17:53.656214  9376 maintenance_manager.cc:419] P 2823bf5f2cac492a8fdfdbb4c44b23ee: Scheduling FlushDeltaMemStoresOp(788cfd3762704a73b904631ef2ed017e): perf score=14.095187
I20260812 06:17:53.709538  9279 maintenance_manager.cc:643] P 2823bf5f2cac492a8fdfdbb4c44b23ee: FlushDeltaMemStoresOp(788cfd3762704a73b904631ef2ed017e) complete. Timing: real 0.053s	user 0.029s	sys 0.023s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":25177,"lbm_writes_1-10_ms":3,"lbm_writes_lt_1ms":400,"reinsert_count":0,"update_count":2000}
I20260812 06:17:53.710057  9376 maintenance_manager.cc:419] P 2823bf5f2cac492a8fdfdbb4c44b23ee: Scheduling FlushDeltaMemStoresOp(788cfd3762704a73b904631ef2ed017e): perf score=2.188937
I20260812 06:17:53.722685  9279 maintenance_manager.cc:643] P 2823bf5f2cac492a8fdfdbb4c44b23ee: FlushDeltaMemStoresOp(788cfd3762704a73b904631ef2ed017e) complete. Timing: real 0.012s	user 0.006s	sys 0.004s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4327,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:53.723239  9376 maintenance_manager.cc:419] P 2823bf5f2cac492a8fdfdbb4c44b23ee: Scheduling FlushMRSOp(788cfd3762704a73b904631ef2ed017e): perf score=1.000000
I20260812 06:17:53.754856  9279 maintenance_manager.cc:643] P 2823bf5f2cac492a8fdfdbb4c44b23ee: FlushMRSOp(788cfd3762704a73b904631ef2ed017e) complete. Timing: real 0.031s	user 0.027s	sys 0.003s Metrics: {"bytes_written":1234473,"cfile_init":1,"dirs.queue_time_us":54,"dirs.run_cpu_time_us":205,"dirs.run_wall_time_us":1190,"drs_written":1,"lbm_read_time_us":36,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1620,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":30}
I20260812 06:17:53.755414  9376 maintenance_manager.cc:419] P 2823bf5f2cac492a8fdfdbb4c44b23ee: Scheduling LogGCOp(788cfd3762704a73b904631ef2ed017e): free 120100327 bytes of WAL
I20260812 06:17:53.755649  9279 log_reader.cc:385] T 788cfd3762704a73b904631ef2ed017e: removed 12 log segments from log reader
I20260812 06:17:53.755697  9279 log.cc:1079] T 788cfd3762704a73b904631ef2ed017e P 2823bf5f2cac492a8fdfdbb4c44b23ee: Deleting log segment in path: /tmp/dist-test-taskB0FmHn/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515466905639-8794-0/minicluster-data/ts-0-root/wals/788cfd3762704a73b904631ef2ed017e/wal-000000003 (ops 12-16)
I20260812 06:17:53.755728  9279 log.cc:1079] T 788cfd3762704a73b904631ef2ed017e P 2823bf5f2cac492a8fdfdbb4c44b23ee: Deleting log segment in path: /tmp/dist-test-taskB0FmHn/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515466905639-8794-0/minicluster-data/ts-0-root/wals/788cfd3762704a73b904631ef2ed017e/wal-000000004 (ops 17-20)
I20260812 06:17:53.755751  9279 log.cc:1079] T 788cfd3762704a73b904631ef2ed017e P 2823bf5f2cac492a8fdfdbb4c44b23ee: Deleting log segment in path: /tmp/dist-test-taskB0FmHn/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515466905639-8794-0/minicluster-data/ts-0-root/wals/788cfd3762704a73b904631ef2ed017e/wal-000000005 (ops 21-25)
I20260812 06:17:53.755789  9279 log.cc:1079] T 788cfd3762704a73b904631ef2ed017e P 2823bf5f2cac492a8fdfdbb4c44b23ee: Deleting log segment in path: /tmp/dist-test-taskB0FmHn/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515466905639-8794-0/minicluster-data/ts-0-root/wals/788cfd3762704a73b904631ef2ed017e/wal-000000006 (ops 26-30)
I20260812 06:17:53.755822  9279 log.cc:1079] T 788cfd3762704a73b904631ef2ed017e P 2823bf5f2cac492a8fdfdbb4c44b23ee: Deleting log segment in path: /tmp/dist-test-taskB0FmHn/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515466905639-8794-0/minicluster-data/ts-0-root/wals/788cfd3762704a73b904631ef2ed017e/wal-000000007 (ops 31-35)
I20260812 06:17:53.755857  9279 log.cc:1079] T 788cfd3762704a73b904631ef2ed017e P 2823bf5f2cac492a8fdfdbb4c44b23ee: Deleting log segment in path: /tmp/dist-test-taskB0FmHn/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515466905639-8794-0/minicluster-data/ts-0-root/wals/788cfd3762704a73b904631ef2ed017e/wal-000000008 (ops 36-40)
I20260812 06:17:53.755893  9279 log.cc:1079] T 788cfd3762704a73b904631ef2ed017e P 2823bf5f2cac492a8fdfdbb4c44b23ee: Deleting log segment in path: /tmp/dist-test-taskB0FmHn/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515466905639-8794-0/minicluster-data/ts-0-root/wals/788cfd3762704a73b904631ef2ed017e/wal-000000009 (ops 41-44)
I20260812 06:17:53.755918  9279 log.cc:1079] T 788cfd3762704a73b904631ef2ed017e P 2823bf5f2cac492a8fdfdbb4c44b23ee: Deleting log segment in path: /tmp/dist-test-taskB0FmHn/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515466905639-8794-0/minicluster-data/ts-0-root/wals/788cfd3762704a73b904631ef2ed017e/wal-000000010 (ops 45-49)
I20260812 06:17:53.755947  9279 log.cc:1079] T 788cfd3762704a73b904631ef2ed017e P 2823bf5f2cac492a8fdfdbb4c44b23ee: Deleting log segment in path: /tmp/dist-test-taskB0FmHn/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515466905639-8794-0/minicluster-data/ts-0-root/wals/788cfd3762704a73b904631ef2ed017e/wal-000000011 (ops 50-54)
I20260812 06:17:53.755971  9279 log.cc:1079] T 788cfd3762704a73b904631ef2ed017e P 2823bf5f2cac492a8fdfdbb4c44b23ee: Deleting log segment in path: /tmp/dist-test-taskB0FmHn/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515466905639-8794-0/minicluster-data/ts-0-root/wals/788cfd3762704a73b904631ef2ed017e/wal-000000012 (ops 55-59)
I20260812 06:17:53.756002  9279 log.cc:1079] T 788cfd3762704a73b904631ef2ed017e P 2823bf5f2cac492a8fdfdbb4c44b23ee: Deleting log segment in path: /tmp/dist-test-taskB0FmHn/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515466905639-8794-0/minicluster-data/ts-0-root/wals/788cfd3762704a73b904631ef2ed017e/wal-000000013 (ops 60-64)
I20260812 06:17:53.756026  9279 log.cc:1079] T 788cfd3762704a73b904631ef2ed017e P 2823bf5f2cac492a8fdfdbb4c44b23ee: Deleting log segment in path: /tmp/dist-test-taskB0FmHn/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515466905639-8794-0/minicluster-data/ts-0-root/wals/788cfd3762704a73b904631ef2ed017e/wal-000000014 (ops 65-68)
I20260812 06:17:53.782691  9279 maintenance_manager.cc:643] P 2823bf5f2cac492a8fdfdbb4c44b23ee: LogGCOp(788cfd3762704a73b904631ef2ed017e) complete. Timing: real 0.027s	user 0.000s	sys 0.025s Metrics: {}
I20260812 06:17:53.783309  9376 maintenance_manager.cc:419] P 2823bf5f2cac492a8fdfdbb4c44b23ee: Scheduling UndoDeltaBlockGCOp(788cfd3762704a73b904631ef2ed017e): 473 bytes on disk
I20260812 06:17:53.783852  9279 maintenance_manager.cc:643] P 2823bf5f2cac492a8fdfdbb4c44b23ee: UndoDeltaBlockGCOp(788cfd3762704a73b904631ef2ed017e) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":55,"lbm_reads_lt_1ms":4}
I20260812 06:17:53.784503  9376 maintenance_manager.cc:419] P 2823bf5f2cac492a8fdfdbb4c44b23ee: Scheduling FlushDeltaMemStoresOp(788cfd3762704a73b904631ef2ed017e): perf score=3.181125
I20260812 06:17:53.804561  9279 maintenance_manager.cc:643] P 2823bf5f2cac492a8fdfdbb4c44b23ee: FlushDeltaMemStoresOp(788cfd3762704a73b904631ef2ed017e) complete. Timing: real 0.020s	user 0.007s	sys 0.004s Metrics: {"bytes_written":4512903,"delete_count":0,"lbm_write_time_us":4971,"lbm_writes_lt_1ms":113,"reinsert_count":0,"update_count":550}
I20260812 06:17:53.805039  9376 maintenance_manager.cc:419] P 2823bf5f2cac492a8fdfdbb4c44b23ee: Scheduling LogGCOp(788cfd3762704a73b904631ef2ed017e): free 8767118 bytes of WAL
I20260812 06:17:53.805259  9279 log_reader.cc:385] T 788cfd3762704a73b904631ef2ed017e: removed 1 log segments from log reader
I20260812 06:17:53.805316  9279 log.cc:1079] T 788cfd3762704a73b904631ef2ed017e P 2823bf5f2cac492a8fdfdbb4c44b23ee: Deleting log segment in path: /tmp/dist-test-taskB0FmHn/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515466905639-8794-0/minicluster-data/ts-0-root/wals/788cfd3762704a73b904631ef2ed017e/wal-000000015 (ops 69-73)
I20260812 06:17:53.806779  9279 maintenance_manager.cc:643] P 2823bf5f2cac492a8fdfdbb4c44b23ee: LogGCOp(788cfd3762704a73b904631ef2ed017e) complete. Timing: real 0.002s	user 0.000s	sys 0.000s Metrics: {}
I20260812 06:17:53.807080  9376 maintenance_manager.cc:419] P 2823bf5f2cac492a8fdfdbb4c44b23ee: Scheduling FlushDeltaMemStoresOp(788cfd3762704a73b904631ef2ed017e): perf score=2.188937
I20260812 06:17:53.816867  9279 maintenance_manager.cc:643] P 2823bf5f2cac492a8fdfdbb4c44b23ee: FlushDeltaMemStoresOp(788cfd3762704a73b904631ef2ed017e) complete. Timing: real 0.010s	user 0.004s	sys 0.004s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3531,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:17:53.817525  9376 maintenance_manager.cc:419] P 2823bf5f2cac492a8fdfdbb4c44b23ee: Scheduling MajorDeltaCompactionOp(788cfd3762704a73b904631ef2ed017e): perf score=1.000000
I20260812 06:17:54.051303  9279 maintenance_manager.cc:643] P 2823bf5f2cac492a8fdfdbb4c44b23ee: MajorDeltaCompactionOp(788cfd3762704a73b904631ef2ed017e) complete. Timing: real 0.234s	user 0.147s	sys 0.085s Metrics: {"cfile_cache_miss":734,"cfile_cache_miss_bytes":33020735,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":577,"lbm_read_time_us":17099,"lbm_reads_lt_1ms":774,"lbm_write_time_us":39162,"lbm_writes_lt_1ms":743,"mutex_wait_us":371,"peak_mem_usage":87969044,"reinsert_count":0,"spinlock_wait_cycles":22016,"thread_start_us":132,"threads_started":1,"update_count":3500}
I20260812 06:17:54.052551  9376 maintenance_manager.cc:419] P 2823bf5f2cac492a8fdfdbb4c44b23ee: Scheduling FlushDeltaMemStoresOp(788cfd3762704a73b904631ef2ed017e): perf score=18.063937
I20260812 06:17:54.123409  9279 maintenance_manager.cc:643] P 2823bf5f2cac492a8fdfdbb4c44b23ee: FlushDeltaMemStoresOp(788cfd3762704a73b904631ef2ed017e) complete. Timing: real 0.070s	user 0.027s	sys 0.033s Metrics: {"bytes_written":20512316,"delete_count":0,"lbm_write_time_us":27016,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":502,"reinsert_count":0,"update_count":2500}
I20260812 06:17:54.123901  9376 maintenance_manager.cc:419] P 2823bf5f2cac492a8fdfdbb4c44b23ee: Scheduling FlushDeltaMemStoresOp(788cfd3762704a73b904631ef2ed017e): perf score=3.181125
I20260812 06:17:54.136956  9279 maintenance_manager.cc:643] P 2823bf5f2cac492a8fdfdbb4c44b23ee: FlushDeltaMemStoresOp(788cfd3762704a73b904631ef2ed017e) complete. Timing: real 0.013s	user 0.011s	sys 0.000s Metrics: {"bytes_written":4512903,"delete_count":0,"lbm_write_time_us":4707,"lbm_writes_lt_1ms":113,"reinsert_count":0,"update_count":550}
I20260812 06:17:54.137485  9376 maintenance_manager.cc:419] P 2823bf5f2cac492a8fdfdbb4c44b23ee: Scheduling FlushDeltaMemStoresOp(788cfd3762704a73b904631ef2ed017e): perf score=2.188937
I20260812 06:17:54.146355  9279 maintenance_manager.cc:643] P 2823bf5f2cac492a8fdfdbb4c44b23ee: FlushDeltaMemStoresOp(788cfd3762704a73b904631ef2ed017e) complete. Timing: real 0.009s	user 0.007s	sys 0.000s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3198,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:17:54.146740  9376 maintenance_manager.cc:419] P 2823bf5f2cac492a8fdfdbb4c44b23ee: Scheduling MajorDeltaCompactionOp(788cfd3762704a73b904631ef2ed017e): perf score=1.000000
I20260812 06:17:54.369468  9279 maintenance_manager.cc:643] P 2823bf5f2cac492a8fdfdbb4c44b23ee: MajorDeltaCompactionOp(788cfd3762704a73b904631ef2ed017e) complete. Timing: real 0.223s	user 0.151s	sys 0.064s Metrics: {"cfile_cache_miss":733,"cfile_cache_miss_bytes":33020619,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":523,"lbm_read_time_us":15956,"lbm_reads_lt_1ms":773,"lbm_write_time_us":35182,"lbm_writes_lt_1ms":743,"mutex_wait_us":52,"peak_mem_usage":87969044,"reinsert_count":0,"spinlock_wait_cycles":4736,"update_count":3500}
I20260812 06:17:54.369969  9376 maintenance_manager.cc:419] P 2823bf5f2cac492a8fdfdbb4c44b23ee: Scheduling FlushDeltaMemStoresOp(788cfd3762704a73b904631ef2ed017e): perf score=18.063937
I20260812 06:17:54.427104  9279 maintenance_manager.cc:643] P 2823bf5f2cac492a8fdfdbb4c44b23ee: FlushDeltaMemStoresOp(788cfd3762704a73b904631ef2ed017e) complete. Timing: real 0.057s	user 0.027s	sys 0.028s Metrics: {"bytes_written":20512314,"delete_count":0,"lbm_write_time_us":24871,"lbm_writes_lt_1ms":503,"reinsert_count":0,"update_count":2500}
I20260812 06:17:54.427642  9376 maintenance_manager.cc:419] P 2823bf5f2cac492a8fdfdbb4c44b23ee: Scheduling FlushDeltaMemStoresOp(788cfd3762704a73b904631ef2ed017e): perf score=2.188937
I20260812 06:17:54.445981  9279 maintenance_manager.cc:643] P 2823bf5f2cac492a8fdfdbb4c44b23ee: FlushDeltaMemStoresOp(788cfd3762704a73b904631ef2ed017e) complete. Timing: real 0.018s	user 0.011s	sys 0.001s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":5023,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:54.446493  9376 maintenance_manager.cc:419] P 2823bf5f2cac492a8fdfdbb4c44b23ee: Scheduling MajorDeltaCompactionOp(788cfd3762704a73b904631ef2ed017e): perf score=1.000000
I20260812 06:17:54.602847  9279 maintenance_manager.cc:643] P 2823bf5f2cac492a8fdfdbb4c44b23ee: MajorDeltaCompactionOp(788cfd3762704a73b904631ef2ed017e) complete. Timing: real 0.156s	user 0.102s	sys 0.053s Metrics: {"cfile_cache_miss":632,"cfile_cache_miss_bytes":28918095,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":1067,"lbm_read_time_us":12507,"lbm_reads_lt_1ms":664,"lbm_write_time_us":30155,"lbm_writes_lt_1ms":643,"mutex_wait_us":843,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":6016,"update_count":3000}
I20260812 06:17:54.603543  9376 maintenance_manager.cc:419] P 2823bf5f2cac492a8fdfdbb4c44b23ee: Scheduling FlushDeltaMemStoresOp(788cfd3762704a73b904631ef2ed017e): perf score=14.095187
I20260812 06:17:54.658565  9279 maintenance_manager.cc:643] P 2823bf5f2cac492a8fdfdbb4c44b23ee: FlushDeltaMemStoresOp(788cfd3762704a73b904631ef2ed017e) complete. Timing: real 0.055s	user 0.021s	sys 0.031s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":24115,"lbm_writes_1-10_ms":2,"lbm_writes_lt_1ms":401,"reinsert_count":0,"update_count":2000}
I20260812 06:17:54.659137  9376 maintenance_manager.cc:419] P 2823bf5f2cac492a8fdfdbb4c44b23ee: Scheduling FlushDeltaMemStoresOp(788cfd3762704a73b904631ef2ed017e): perf score=3.181125
I20260812 06:17:54.677410  9279 maintenance_manager.cc:643] P 2823bf5f2cac492a8fdfdbb4c44b23ee: FlushDeltaMemStoresOp(788cfd3762704a73b904631ef2ed017e) complete. Timing: real 0.018s	user 0.007s	sys 0.004s Metrics: {"bytes_written":4512902,"delete_count":0,"lbm_write_time_us":4202,"lbm_writes_lt_1ms":113,"reinsert_count":0,"update_count":550}
I20260812 06:17:54.677845  9376 maintenance_manager.cc:419] P 2823bf5f2cac492a8fdfdbb4c44b23ee: Scheduling FlushDeltaMemStoresOp(788cfd3762704a73b904631ef2ed017e): perf score=2.188937
I20260812 06:17:54.686647  9279 maintenance_manager.cc:643] P 2823bf5f2cac492a8fdfdbb4c44b23ee: FlushDeltaMemStoresOp(788cfd3762704a73b904631ef2ed017e) complete. Timing: real 0.009s	user 0.004s	sys 0.003s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3100,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:17:54.687059  9376 maintenance_manager.cc:419] P 2823bf5f2cac492a8fdfdbb4c44b23ee: Scheduling MajorDeltaCompactionOp(788cfd3762704a73b904631ef2ed017e): perf score=1.000000
I20260812 06:17:54.846303  9279 maintenance_manager.cc:643] P 2823bf5f2cac492a8fdfdbb4c44b23ee: MajorDeltaCompactionOp(788cfd3762704a73b904631ef2ed017e) complete. Timing: real 0.159s	user 0.115s	sys 0.044s Metrics: {"cfile_cache_miss":633,"cfile_cache_miss_bytes":28918204,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":255,"lbm_read_time_us":11297,"lbm_reads_lt_1ms":673,"lbm_write_time_us":31752,"lbm_writes_lt_1ms":643,"mutex_wait_us":25,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":13184,"update_count":3000}
I20260812 06:17:54.846987  9376 maintenance_manager.cc:419] P 2823bf5f2cac492a8fdfdbb4c44b23ee: Scheduling FlushDeltaMemStoresOp(788cfd3762704a73b904631ef2ed017e): perf score=14.095187
I20260812 06:17:54.890408  9279 maintenance_manager.cc:643] P 2823bf5f2cac492a8fdfdbb4c44b23ee: FlushDeltaMemStoresOp(788cfd3762704a73b904631ef2ed017e) complete. Timing: real 0.043s	user 0.029s	sys 0.013s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":18433,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:17:54.891152  9376 maintenance_manager.cc:419] P 2823bf5f2cac492a8fdfdbb4c44b23ee: Scheduling FlushDeltaMemStoresOp(788cfd3762704a73b904631ef2ed017e): perf score=2.188937
I20260812 06:17:54.904415  9279 maintenance_manager.cc:643] P 2823bf5f2cac492a8fdfdbb4c44b23ee: FlushDeltaMemStoresOp(788cfd3762704a73b904631ef2ed017e) complete. Timing: real 0.013s	user 0.010s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4268,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:54.904959  9376 maintenance_manager.cc:419] P 2823bf5f2cac492a8fdfdbb4c44b23ee: Scheduling MajorDeltaCompactionOp(788cfd3762704a73b904631ef2ed017e): perf score=1.000000
I20260812 06:17:55.048556  9279 maintenance_manager.cc:643] P 2823bf5f2cac492a8fdfdbb4c44b23ee: MajorDeltaCompactionOp(788cfd3762704a73b904631ef2ed017e) complete. Timing: real 0.143s	user 0.109s	sys 0.033s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24815684,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":407,"lbm_read_time_us":8611,"lbm_reads_lt_1ms":572,"lbm_write_time_us":28477,"lbm_writes_lt_1ms":543,"mutex_wait_us":51,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":9856,"update_count":2500}
I20260812 06:17:55.049129  9376 maintenance_manager.cc:419] P 2823bf5f2cac492a8fdfdbb4c44b23ee: Scheduling FlushDeltaMemStoresOp(788cfd3762704a73b904631ef2ed017e): perf score=12.110812
I20260812 06:17:55.084432  9279 maintenance_manager.cc:643] P 2823bf5f2cac492a8fdfdbb4c44b23ee: FlushDeltaMemStoresOp(788cfd3762704a73b904631ef2ed017e) complete. Timing: real 0.035s	user 0.023s	sys 0.009s Metrics: {"bytes_written":13784349,"delete_count":0,"lbm_write_time_us":15269,"lbm_writes_lt_1ms":339,"reinsert_count":0,"update_count":1680}
I20260812 06:17:55.084913  9376 maintenance_manager.cc:419] P 2823bf5f2cac492a8fdfdbb4c44b23ee: Scheduling FlushDeltaMemStoresOp(788cfd3762704a73b904631ef2ed017e): perf score=1.196750
I20260812 06:17:55.098572  9279 maintenance_manager.cc:643] P 2823bf5f2cac492a8fdfdbb4c44b23ee: FlushDeltaMemStoresOp(788cfd3762704a73b904631ef2ed017e) complete. Timing: real 0.013s	user 0.006s	sys 0.001s Metrics: {"bytes_written":2625754,"delete_count":0,"lbm_write_time_us":2767,"lbm_writes_lt_1ms":67,"reinsert_count":0,"update_count":320}
I20260812 06:17:55.099069  9376 maintenance_manager.cc:419] P 2823bf5f2cac492a8fdfdbb4c44b23ee: Scheduling FlushMRSOp(788cfd3762704a73b904631ef2ed017e): perf score=1.000000
I20260812 06:17:55.137972  9279 maintenance_manager.cc:643] P 2823bf5f2cac492a8fdfdbb4c44b23ee: FlushMRSOp(788cfd3762704a73b904631ef2ed017e) complete. Timing: real 0.039s	user 0.021s	sys 0.003s Metrics: {"bytes_written":1234479,"cfile_init":1,"dirs.queue_time_us":52,"dirs.run_cpu_time_us":232,"dirs.run_wall_time_us":1120,"drs_written":1,"lbm_read_time_us":45,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1473,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":30}
I20260812 06:17:55.138808  9376 maintenance_manager.cc:419] P 2823bf5f2cac492a8fdfdbb4c44b23ee: Scheduling FlushDeltaMemStoresOp(788cfd3762704a73b904631ef2ed017e): perf score=3.181125
I20260812 06:17:55.153762  9279 maintenance_manager.cc:643] P 2823bf5f2cac492a8fdfdbb4c44b23ee: FlushDeltaMemStoresOp(788cfd3762704a73b904631ef2ed017e) complete. Timing: real 0.015s	user 0.007s	sys 0.004s Metrics: {"bytes_written":4348807,"delete_count":0,"lbm_write_time_us":4469,"lbm_writes_lt_1ms":109,"reinsert_count":0,"update_count":530}
I20260812 06:17:55.154304  9376 maintenance_manager.cc:419] P 2823bf5f2cac492a8fdfdbb4c44b23ee: Scheduling LogGCOp(788cfd3762704a73b904631ef2ed017e): free 124257270 bytes of WAL
I20260812 06:17:55.154585  9279 log_reader.cc:385] T 788cfd3762704a73b904631ef2ed017e: removed 12 log segments from log reader
I20260812 06:17:55.154644  9279 log.cc:1079] T 788cfd3762704a73b904631ef2ed017e P 2823bf5f2cac492a8fdfdbb4c44b23ee: Deleting log segment in path: /tmp/dist-test-taskB0FmHn/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515466905639-8794-0/minicluster-data/ts-0-root/wals/788cfd3762704a73b904631ef2ed017e/wal-000000016 (ops 74-78)
I20260812 06:17:55.154685  9279 log.cc:1079] T 788cfd3762704a73b904631ef2ed017e P 2823bf5f2cac492a8fdfdbb4c44b23ee: Deleting log segment in path: /tmp/dist-test-taskB0FmHn/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515466905639-8794-0/minicluster-data/ts-0-root/wals/788cfd3762704a73b904631ef2ed017e/wal-000000017 (ops 79-83)
I20260812 06:17:55.154719  9279 log.cc:1079] T 788cfd3762704a73b904631ef2ed017e P 2823bf5f2cac492a8fdfdbb4c44b23ee: Deleting log segment in path: /tmp/dist-test-taskB0FmHn/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515466905639-8794-0/minicluster-data/ts-0-root/wals/788cfd3762704a73b904631ef2ed017e/wal-000000018 (ops 84-88)
I20260812 06:17:55.154752  9279 log.cc:1079] T 788cfd3762704a73b904631ef2ed017e P 2823bf5f2cac492a8fdfdbb4c44b23ee: Deleting log segment in path: /tmp/dist-test-taskB0FmHn/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515466905639-8794-0/minicluster-data/ts-0-root/wals/788cfd3762704a73b904631ef2ed017e/wal-000000019 (ops 89-92)
I20260812 06:17:55.154796  9279 log.cc:1079] T 788cfd3762704a73b904631ef2ed017e P 2823bf5f2cac492a8fdfdbb4c44b23ee: Deleting log segment in path: /tmp/dist-test-taskB0FmHn/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515466905639-8794-0/minicluster-data/ts-0-root/wals/788cfd3762704a73b904631ef2ed017e/wal-000000020 (ops 93-97)
I20260812 06:17:55.154821  9279 log.cc:1079] T 788cfd3762704a73b904631ef2ed017e P 2823bf5f2cac492a8fdfdbb4c44b23ee: Deleting log segment in path: /tmp/dist-test-taskB0FmHn/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515466905639-8794-0/minicluster-data/ts-0-root/wals/788cfd3762704a73b904631ef2ed017e/wal-000000021 (ops 98-102)
I20260812 06:17:55.154851  9279 log.cc:1079] T 788cfd3762704a73b904631ef2ed017e P 2823bf5f2cac492a8fdfdbb4c44b23ee: Deleting log segment in path: /tmp/dist-test-taskB0FmHn/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515466905639-8794-0/minicluster-data/ts-0-root/wals/788cfd3762704a73b904631ef2ed017e/wal-000000022 (ops 103-107)
I20260812 06:17:55.154878  9279 log.cc:1079] T 788cfd3762704a73b904631ef2ed017e P 2823bf5f2cac492a8fdfdbb4c44b23ee: Deleting log segment in path: /tmp/dist-test-taskB0FmHn/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515466905639-8794-0/minicluster-data/ts-0-root/wals/788cfd3762704a73b904631ef2ed017e/wal-000000023 (ops 108-112)
I20260812 06:17:55.154908  9279 log.cc:1079] T 788cfd3762704a73b904631ef2ed017e P 2823bf5f2cac492a8fdfdbb4c44b23ee: Deleting log segment in path: /tmp/dist-test-taskB0FmHn/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515466905639-8794-0/minicluster-data/ts-0-root/wals/788cfd3762704a73b904631ef2ed017e/wal-000000024 (ops 113-117)
I20260812 06:17:55.154939  9279 log.cc:1079] T 788cfd3762704a73b904631ef2ed017e P 2823bf5f2cac492a8fdfdbb4c44b23ee: Deleting log segment in path: /tmp/dist-test-taskB0FmHn/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515466905639-8794-0/minicluster-data/ts-0-root/wals/788cfd3762704a73b904631ef2ed017e/wal-000000025 (ops 118-122)
I20260812 06:17:55.154970  9279 log.cc:1079] T 788cfd3762704a73b904631ef2ed017e P 2823bf5f2cac492a8fdfdbb4c44b23ee: Deleting log segment in path: /tmp/dist-test-taskB0FmHn/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515466905639-8794-0/minicluster-data/ts-0-root/wals/788cfd3762704a73b904631ef2ed017e/wal-000000026 (ops 123-127)
I20260812 06:17:55.155000  9279 log.cc:1079] T 788cfd3762704a73b904631ef2ed017e P 2823bf5f2cac492a8fdfdbb4c44b23ee: Deleting log segment in path: /tmp/dist-test-taskB0FmHn/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515466905639-8794-0/minicluster-data/ts-0-root/wals/788cfd3762704a73b904631ef2ed017e/wal-000000027 (ops 128-132)
I20260812 06:17:55.178159  9279 maintenance_manager.cc:643] P 2823bf5f2cac492a8fdfdbb4c44b23ee: LogGCOp(788cfd3762704a73b904631ef2ed017e) complete. Timing: real 0.024s	user 0.000s	sys 0.023s Metrics: {}
I20260812 06:17:55.178680  9376 maintenance_manager.cc:419] P 2823bf5f2cac492a8fdfdbb4c44b23ee: Scheduling FlushDeltaMemStoresOp(788cfd3762704a73b904631ef2ed017e): perf score=3.181125
I20260812 06:17:55.199966  9279 maintenance_manager.cc:643] P 2823bf5f2cac492a8fdfdbb4c44b23ee: FlushDeltaMemStoresOp(788cfd3762704a73b904631ef2ed017e) complete. Timing: real 0.021s	user 0.009s	sys 0.005s Metrics: {"bytes_written":4266762,"delete_count":0,"lbm_write_time_us":6376,"lbm_writes_lt_1ms":107,"reinsert_count":0,"update_count":520}
I20260812 06:17:55.200456  9376 maintenance_manager.cc:419] P 2823bf5f2cac492a8fdfdbb4c44b23ee: Scheduling FlushDeltaMemStoresOp(788cfd3762704a73b904631ef2ed017e): perf score=2.188937
I20260812 06:17:55.209595  9279 maintenance_manager.cc:643] P 2823bf5f2cac492a8fdfdbb4c44b23ee: FlushDeltaMemStoresOp(788cfd3762704a73b904631ef2ed017e) complete. Timing: real 0.009s	user 0.008s	sys 0.000s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3199,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:17:55.210177  9376 maintenance_manager.cc:419] P 2823bf5f2cac492a8fdfdbb4c44b23ee: Scheduling MajorDeltaCompactionOp(788cfd3762704a73b904631ef2ed017e): perf score=1.000000
I20260812 06:17:55.424700  9279 maintenance_manager.cc:643] P 2823bf5f2cac492a8fdfdbb4c44b23ee: MajorDeltaCompactionOp(788cfd3762704a73b904631ef2ed017e) complete. Timing: real 0.214s	user 0.135s	sys 0.068s Metrics: {"cfile_cache_miss":735,"cfile_cache_miss_bytes":33020816,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":5,"delta_iterators_relevant":5,"dirs.queue_time_us":625,"lbm_read_time_us":15062,"lbm_reads_lt_1ms":775,"lbm_write_time_us":36003,"lbm_writes_lt_1ms":743,"mutex_wait_us":250,"peak_mem_usage":87969044,"reinsert_count":0,"spinlock_wait_cycles":6912,"thread_start_us":91,"threads_started":1,"update_count":3500}
I20260812 06:17:55.425235  9376 maintenance_manager.cc:419] P 2823bf5f2cac492a8fdfdbb4c44b23ee: Scheduling UndoDeltaBlockGCOp(788cfd3762704a73b904631ef2ed017e): 472 bytes on disk
I20260812 06:17:55.425645  9279 maintenance_manager.cc:643] P 2823bf5f2cac492a8fdfdbb4c44b23ee: UndoDeltaBlockGCOp(788cfd3762704a73b904631ef2ed017e) 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:17:55.426209  9376 maintenance_manager.cc:419] P 2823bf5f2cac492a8fdfdbb4c44b23ee: Scheduling FlushDeltaMemStoresOp(788cfd3762704a73b904631ef2ed017e): perf score=18.063937
I20260812 06:17:55.482828  9279 maintenance_manager.cc:643] P 2823bf5f2cac492a8fdfdbb4c44b23ee: FlushDeltaMemStoresOp(788cfd3762704a73b904631ef2ed017e) complete. Timing: real 0.056s	user 0.030s	sys 0.023s Metrics: {"bytes_written":20512316,"delete_count":0,"lbm_write_time_us":23687,"lbm_writes_lt_1ms":503,"reinsert_count":0,"update_count":2500}
I20260812 06:17:55.483546  9376 maintenance_manager.cc:419] P 2823bf5f2cac492a8fdfdbb4c44b23ee: Scheduling FlushDeltaMemStoresOp(788cfd3762704a73b904631ef2ed017e): perf score=2.188937
I20260812 06:17:55.507344  9279 maintenance_manager.cc:643] P 2823bf5f2cac492a8fdfdbb4c44b23ee: FlushDeltaMemStoresOp(788cfd3762704a73b904631ef2ed017e) complete. Timing: real 0.024s	user 0.003s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5123,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:55.507815  9376 maintenance_manager.cc:419] P 2823bf5f2cac492a8fdfdbb4c44b23ee: Scheduling FlushDeltaMemStoresOp(788cfd3762704a73b904631ef2ed017e): perf score=2.188937
I20260812 06:17:55.517724  9279 maintenance_manager.cc:643] P 2823bf5f2cac492a8fdfdbb4c44b23ee: FlushDeltaMemStoresOp(788cfd3762704a73b904631ef2ed017e) complete. Timing: real 0.010s	user 0.009s	sys 0.000s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":3629,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:55.518309  9376 maintenance_manager.cc:419] P 2823bf5f2cac492a8fdfdbb4c44b23ee: Scheduling MajorDeltaCompactionOp(788cfd3762704a73b904631ef2ed017e): perf score=1.000000
I20260812 06:17:55.695305  9279 maintenance_manager.cc:643] P 2823bf5f2cac492a8fdfdbb4c44b23ee: MajorDeltaCompactionOp(788cfd3762704a73b904631ef2ed017e) complete. Timing: real 0.177s	user 0.152s	sys 0.023s Metrics: {"cfile_cache_miss":733,"cfile_cache_miss_bytes":33020628,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":518,"lbm_read_time_us":12529,"lbm_reads_lt_1ms":773,"lbm_write_time_us":36018,"lbm_writes_lt_1ms":743,"peak_mem_usage":87969044,"reinsert_count":0,"spinlock_wait_cycles":6016,"update_count":3500}
I20260812 06:17:55.695880  9376 maintenance_manager.cc:419] P 2823bf5f2cac492a8fdfdbb4c44b23ee: Scheduling FlushDeltaMemStoresOp(788cfd3762704a73b904631ef2ed017e): perf score=14.095187
I20260812 06:17:55.738921  9279 maintenance_manager.cc:643] P 2823bf5f2cac492a8fdfdbb4c44b23ee: FlushDeltaMemStoresOp(788cfd3762704a73b904631ef2ed017e) complete. Timing: real 0.043s	user 0.026s	sys 0.015s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":17756,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:17:55.739521  9376 maintenance_manager.cc:419] P 2823bf5f2cac492a8fdfdbb4c44b23ee: Scheduling FlushDeltaMemStoresOp(788cfd3762704a73b904631ef2ed017e): perf score=2.188937
I20260812 06:17:55.755972  9279 maintenance_manager.cc:643] P 2823bf5f2cac492a8fdfdbb4c44b23ee: FlushDeltaMemStoresOp(788cfd3762704a73b904631ef2ed017e) complete. Timing: real 0.016s	user 0.003s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4965,"lbm_writes_lt_1ms":103,"reinsert_count":0,"spinlock_wait_cycles":3328,"update_count":500}
I20260812 06:17:55.756541  9376 maintenance_manager.cc:419] P 2823bf5f2cac492a8fdfdbb4c44b23ee: Scheduling MajorDeltaCompactionOp(788cfd3762704a73b904631ef2ed017e): perf score=1.000000
I20260812 06:17:55.910024  9279 maintenance_manager.cc:643] P 2823bf5f2cac492a8fdfdbb4c44b23ee: MajorDeltaCompactionOp(788cfd3762704a73b904631ef2ed017e) complete. Timing: real 0.153s	user 0.103s	sys 0.047s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24815683,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":615,"lbm_read_time_us":9000,"lbm_reads_lt_1ms":564,"lbm_write_time_us":27124,"lbm_writes_lt_1ms":543,"mutex_wait_us":335,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":34304,"update_count":2500}
I20260812 06:17:55.910559  9376 maintenance_manager.cc:419] P 2823bf5f2cac492a8fdfdbb4c44b23ee: Scheduling FlushDeltaMemStoresOp(788cfd3762704a73b904631ef2ed017e): perf score=14.095187
I20260812 06:17:55.948249  9279 maintenance_manager.cc:643] P 2823bf5f2cac492a8fdfdbb4c44b23ee: FlushDeltaMemStoresOp(788cfd3762704a73b904631ef2ed017e) complete. Timing: real 0.038s	user 0.013s	sys 0.021s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":16810,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:17:55.948693  9376 maintenance_manager.cc:419] P 2823bf5f2cac492a8fdfdbb4c44b23ee: Scheduling MajorDeltaCompactionOp(788cfd3762704a73b904631ef2ed017e): perf score=1.000000
I20260812 06:17:56.087648  9279 maintenance_manager.cc:643] P 2823bf5f2cac492a8fdfdbb4c44b23ee: MajorDeltaCompactionOp(788cfd3762704a73b904631ef2ed017e) complete. Timing: real 0.139s	user 0.097s	sys 0.039s Metrics: {"cfile_cache_miss":431,"cfile_cache_miss_bytes":20713152,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":1,"delta_iterators_relevant":1,"dirs.queue_time_us":931,"lbm_read_time_us":10039,"lbm_reads_lt_1ms":467,"lbm_write_time_us":21146,"lbm_writes_lt_1ms":443,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":896,"update_count":2000}
I20260812 06:17:56.088235  9376 maintenance_manager.cc:419] P 2823bf5f2cac492a8fdfdbb4c44b23ee: Scheduling FlushDeltaMemStoresOp(788cfd3762704a73b904631ef2ed017e): perf score=11.118625
I20260812 06:17:56.117949  9279 maintenance_manager.cc:643] P 2823bf5f2cac492a8fdfdbb4c44b23ee: FlushDeltaMemStoresOp(788cfd3762704a73b904631ef2ed017e) complete. Timing: real 0.029s	user 0.022s	sys 0.007s Metrics: {"bytes_written":12717737,"delete_count":0,"lbm_write_time_us":11851,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:17:56.118556  9376 maintenance_manager.cc:419] P 2823bf5f2cac492a8fdfdbb4c44b23ee: Scheduling FlushDeltaMemStoresOp(788cfd3762704a73b904631ef2ed017e): perf score=2.188937
I20260812 06:17:56.142860  9279 maintenance_manager.cc:643] P 2823bf5f2cac492a8fdfdbb4c44b23ee: FlushDeltaMemStoresOp(788cfd3762704a73b904631ef2ed017e) complete. Timing: real 0.024s	user 0.003s	sys 0.008s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":5261,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:17:56.143329  9376 maintenance_manager.cc:419] P 2823bf5f2cac492a8fdfdbb4c44b23ee: Scheduling FlushDeltaMemStoresOp(788cfd3762704a73b904631ef2ed017e): perf score=2.188937
I20260812 06:17:56.158144  9279 maintenance_manager.cc:643] P 2823bf5f2cac492a8fdfdbb4c44b23ee: FlushDeltaMemStoresOp(788cfd3762704a73b904631ef2ed017e) complete. Timing: real 0.015s	user 0.006s	sys 0.007s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5406,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:56.158699  9376 maintenance_manager.cc:419] P 2823bf5f2cac492a8fdfdbb4c44b23ee: Scheduling MajorDeltaCompactionOp(788cfd3762704a73b904631ef2ed017e): perf score=1.000000
I20260812 06:17:56.324700  9279 maintenance_manager.cc:643] P 2823bf5f2cac492a8fdfdbb4c44b23ee: MajorDeltaCompactionOp(788cfd3762704a73b904631ef2ed017e) complete. Timing: real 0.166s	user 0.117s	sys 0.048s Metrics: {"cfile_cache_miss":533,"cfile_cache_miss_bytes":24815796,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":149,"lbm_read_time_us":11048,"lbm_reads_lt_1ms":573,"lbm_write_time_us":26645,"lbm_writes_lt_1ms":543,"mutex_wait_us":23,"peak_mem_usage":63115900,"reinsert_count":0,"update_count":2500}
I20260812 06:17:56.325363  9376 maintenance_manager.cc:419] P 2823bf5f2cac492a8fdfdbb4c44b23ee: Scheduling FlushDeltaMemStoresOp(788cfd3762704a73b904631ef2ed017e): perf score=11.118625
I20260812 06:17:56.361763  9279 maintenance_manager.cc:643] P 2823bf5f2cac492a8fdfdbb4c44b23ee: FlushDeltaMemStoresOp(788cfd3762704a73b904631ef2ed017e) complete. Timing: real 0.036s	user 0.024s	sys 0.011s Metrics: {"bytes_written":12717735,"delete_count":0,"lbm_write_time_us":15277,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:17:56.362378  9376 maintenance_manager.cc:419] P 2823bf5f2cac492a8fdfdbb4c44b23ee: Scheduling FlushDeltaMemStoresOp(788cfd3762704a73b904631ef2ed017e): perf score=2.188937
I20260812 06:17:56.378495  9279 maintenance_manager.cc:643] P 2823bf5f2cac492a8fdfdbb4c44b23ee: FlushDeltaMemStoresOp(788cfd3762704a73b904631ef2ed017e) complete. Timing: real 0.016s	user 0.007s	sys 0.005s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":4490,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:17:56.379068  9376 maintenance_manager.cc:419] P 2823bf5f2cac492a8fdfdbb4c44b23ee: Scheduling MajorDeltaCompactionOp(788cfd3762704a73b904631ef2ed017e): perf score=1.000000
I20260812 06:17:56.495348  9279 maintenance_manager.cc:643] P 2823bf5f2cac492a8fdfdbb4c44b23ee: MajorDeltaCompactionOp(788cfd3762704a73b904631ef2ed017e) complete. Timing: real 0.116s	user 0.100s	sys 0.016s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20713263,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":369,"lbm_read_time_us":7233,"lbm_reads_lt_1ms":464,"lbm_write_time_us":23678,"lbm_writes_lt_1ms":443,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":768,"update_count":2000}
I20260812 06:17:56.495966  9376 maintenance_manager.cc:419] P 2823bf5f2cac492a8fdfdbb4c44b23ee: Scheduling FlushDeltaMemStoresOp(788cfd3762704a73b904631ef2ed017e): perf score=11.118625
I20260812 06:17:56.533488  9279 maintenance_manager.cc:643] P 2823bf5f2cac492a8fdfdbb4c44b23ee: FlushDeltaMemStoresOp(788cfd3762704a73b904631ef2ed017e) complete. Timing: real 0.037s	user 0.036s	sys 0.000s Metrics: {"bytes_written":12717735,"delete_count":0,"lbm_write_time_us":15923,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:17:56.534010  9376 maintenance_manager.cc:419] P 2823bf5f2cac492a8fdfdbb4c44b23ee: Scheduling FlushDeltaMemStoresOp(788cfd3762704a73b904631ef2ed017e): perf score=2.188937
I20260812 06:17:56.544793  9279 maintenance_manager.cc:643] P 2823bf5f2cac492a8fdfdbb4c44b23ee: FlushDeltaMemStoresOp(788cfd3762704a73b904631ef2ed017e) complete. Timing: real 0.011s	user 0.006s	sys 0.003s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":4013,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:17:56.545257  9376 maintenance_manager.cc:419] P 2823bf5f2cac492a8fdfdbb4c44b23ee: Scheduling FlushMRSOp(788cfd3762704a73b904631ef2ed017e): perf score=1.000000
I20260812 06:17:56.574412  9279 maintenance_manager.cc:643] P 2823bf5f2cac492a8fdfdbb4c44b23ee: FlushMRSOp(788cfd3762704a73b904631ef2ed017e) complete. Timing: real 0.029s	user 0.023s	sys 0.005s Metrics: {"bytes_written":1275447,"cfile_init":1,"dirs.queue_time_us":58,"dirs.run_cpu_time_us":207,"dirs.run_wall_time_us":1059,"drs_written":1,"lbm_read_time_us":46,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1522,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":31}
I20260812 06:17:56.575423  9376 maintenance_manager.cc:419] P 2823bf5f2cac492a8fdfdbb4c44b23ee: Scheduling LogGCOp(788cfd3762704a73b904631ef2ed017e): free 121459760 bytes of WAL
I20260812 06:17:56.575733  9279 log_reader.cc:385] T 788cfd3762704a73b904631ef2ed017e: removed 12 log segments from log reader
I20260812 06:17:56.575791  9279 log.cc:1079] T 788cfd3762704a73b904631ef2ed017e P 2823bf5f2cac492a8fdfdbb4c44b23ee: Deleting log segment in path: /tmp/dist-test-taskB0FmHn/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515466905639-8794-0/minicluster-data/ts-0-root/wals/788cfd3762704a73b904631ef2ed017e/wal-000000028 (ops 133-137)
I20260812 06:17:56.575829  9279 log.cc:1079] T 788cfd3762704a73b904631ef2ed017e P 2823bf5f2cac492a8fdfdbb4c44b23ee: Deleting log segment in path: /tmp/dist-test-taskB0FmHn/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515466905639-8794-0/minicluster-data/ts-0-root/wals/788cfd3762704a73b904631ef2ed017e/wal-000000029 (ops 138-142)
I20260812 06:17:56.575863  9279 log.cc:1079] T 788cfd3762704a73b904631ef2ed017e P 2823bf5f2cac492a8fdfdbb4c44b23ee: Deleting log segment in path: /tmp/dist-test-taskB0FmHn/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515466905639-8794-0/minicluster-data/ts-0-root/wals/788cfd3762704a73b904631ef2ed017e/wal-000000030 (ops 143-147)
I20260812 06:17:56.575894  9279 log.cc:1079] T 788cfd3762704a73b904631ef2ed017e P 2823bf5f2cac492a8fdfdbb4c44b23ee: Deleting log segment in path: /tmp/dist-test-taskB0FmHn/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515466905639-8794-0/minicluster-data/ts-0-root/wals/788cfd3762704a73b904631ef2ed017e/wal-000000031 (ops 148-152)
I20260812 06:17:56.575937  9279 log.cc:1079] T 788cfd3762704a73b904631ef2ed017e P 2823bf5f2cac492a8fdfdbb4c44b23ee: Deleting log segment in path: /tmp/dist-test-taskB0FmHn/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515466905639-8794-0/minicluster-data/ts-0-root/wals/788cfd3762704a73b904631ef2ed017e/wal-000000032 (ops 153-157)
I20260812 06:17:56.575968  9279 log.cc:1079] T 788cfd3762704a73b904631ef2ed017e P 2823bf5f2cac492a8fdfdbb4c44b23ee: Deleting log segment in path: /tmp/dist-test-taskB0FmHn/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515466905639-8794-0/minicluster-data/ts-0-root/wals/788cfd3762704a73b904631ef2ed017e/wal-000000033 (ops 158-162)
I20260812 06:17:56.575996  9279 log.cc:1079] T 788cfd3762704a73b904631ef2ed017e P 2823bf5f2cac492a8fdfdbb4c44b23ee: Deleting log segment in path: /tmp/dist-test-taskB0FmHn/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515466905639-8794-0/minicluster-data/ts-0-root/wals/788cfd3762704a73b904631ef2ed017e/wal-000000034 (ops 163-167)
I20260812 06:17:56.576026  9279 log.cc:1079] T 788cfd3762704a73b904631ef2ed017e P 2823bf5f2cac492a8fdfdbb4c44b23ee: Deleting log segment in path: /tmp/dist-test-taskB0FmHn/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515466905639-8794-0/minicluster-data/ts-0-root/wals/788cfd3762704a73b904631ef2ed017e/wal-000000035 (ops 168-172)
I20260812 06:17:56.576056  9279 log.cc:1079] T 788cfd3762704a73b904631ef2ed017e P 2823bf5f2cac492a8fdfdbb4c44b23ee: Deleting log segment in path: /tmp/dist-test-taskB0FmHn/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515466905639-8794-0/minicluster-data/ts-0-root/wals/788cfd3762704a73b904631ef2ed017e/wal-000000036 (ops 173-177)
I20260812 06:17:56.576084  9279 log.cc:1079] T 788cfd3762704a73b904631ef2ed017e P 2823bf5f2cac492a8fdfdbb4c44b23ee: Deleting log segment in path: /tmp/dist-test-taskB0FmHn/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515466905639-8794-0/minicluster-data/ts-0-root/wals/788cfd3762704a73b904631ef2ed017e/wal-000000037 (ops 178-182)
I20260812 06:17:56.576113  9279 log.cc:1079] T 788cfd3762704a73b904631ef2ed017e P 2823bf5f2cac492a8fdfdbb4c44b23ee: Deleting log segment in path: /tmp/dist-test-taskB0FmHn/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515466905639-8794-0/minicluster-data/ts-0-root/wals/788cfd3762704a73b904631ef2ed017e/wal-000000038 (ops 183-187)
I20260812 06:17:56.576143  9279 log.cc:1079] T 788cfd3762704a73b904631ef2ed017e P 2823bf5f2cac492a8fdfdbb4c44b23ee: Deleting log segment in path: /tmp/dist-test-taskB0FmHn/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515466905639-8794-0/minicluster-data/ts-0-root/wals/788cfd3762704a73b904631ef2ed017e/wal-000000039 (ops 188-192)
I20260812 06:17:56.603520  9279 maintenance_manager.cc:643] P 2823bf5f2cac492a8fdfdbb4c44b23ee: LogGCOp(788cfd3762704a73b904631ef2ed017e) complete. Timing: real 0.028s	user 0.000s	sys 0.025s Metrics: {}
I20260812 06:17:56.604038  9376 maintenance_manager.cc:419] P 2823bf5f2cac492a8fdfdbb4c44b23ee: Scheduling UndoDeltaBlockGCOp(788cfd3762704a73b904631ef2ed017e): 482 bytes on disk
I20260812 06:17:56.604534  9279 maintenance_manager.cc:643] P 2823bf5f2cac492a8fdfdbb4c44b23ee: UndoDeltaBlockGCOp(788cfd3762704a73b904631ef2ed017e) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":65,"lbm_reads_lt_1ms":4}
I20260812 06:17:56.605180  9376 maintenance_manager.cc:419] P 2823bf5f2cac492a8fdfdbb4c44b23ee: Scheduling FlushDeltaMemStoresOp(788cfd3762704a73b904631ef2ed017e): perf score=6.157687
I20260812 06:17:56.633580  9279 maintenance_manager.cc:643] P 2823bf5f2cac492a8fdfdbb4c44b23ee: FlushDeltaMemStoresOp(788cfd3762704a73b904631ef2ed017e) complete. Timing: real 0.028s	user 0.011s	sys 0.016s Metrics: {"bytes_written":8205078,"delete_count":0,"lbm_write_time_us":11511,"lbm_writes_lt_1ms":203,"reinsert_count":0,"update_count":1000}
I20260812 06:17:56.634073  9376 maintenance_manager.cc:419] P 2823bf5f2cac492a8fdfdbb4c44b23ee: Scheduling LogGCOp(788cfd3762704a73b904631ef2ed017e): free 11564893 bytes of WAL
I20260812 06:17:56.634305  9279 log_reader.cc:385] T 788cfd3762704a73b904631ef2ed017e: removed 1 log segments from log reader
I20260812 06:17:56.634377  9279 log.cc:1079] T 788cfd3762704a73b904631ef2ed017e P 2823bf5f2cac492a8fdfdbb4c44b23ee: Deleting log segment in path: /tmp/dist-test-taskB0FmHn/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515466905639-8794-0/minicluster-data/ts-0-root/wals/788cfd3762704a73b904631ef2ed017e/wal-000000040 (ops 193-196)
I20260812 06:17:56.636479  9279 maintenance_manager.cc:643] P 2823bf5f2cac492a8fdfdbb4c44b23ee: LogGCOp(788cfd3762704a73b904631ef2ed017e) complete. Timing: real 0.002s	user 0.000s	sys 0.000s Metrics: {}
I20260812 06:17:56.636793  9376 maintenance_manager.cc:419] P 2823bf5f2cac492a8fdfdbb4c44b23ee: Scheduling MajorDeltaCompactionOp(788cfd3762704a73b904631ef2ed017e): perf score=1.000000
I20260812 06:17:56.703877  8794 heavy-update-compaction-itest.cc:229] Time spent updating: real 4.469s	user 1.687s	sys 0.128s
I20260812 06:17:56.779292  8794 heavy-update-compaction-itest.cc:265] Time spent scanning: real 0.075s	user 0.002s	sys 0.000s
I20260812 06:17:56.779901  8794 tablet_server.cc:179] TabletServer@127.8.150.129:0 shutting down...
I20260812 06:17:56.794723  9279 maintenance_manager.cc:643] P 2823bf5f2cac492a8fdfdbb4c44b23ee: MajorDeltaCompactionOp(788cfd3762704a73b904631ef2ed017e) complete. Timing: real 0.158s	user 0.119s	sys 0.038s Metrics: {"cfile_cache_miss":633,"cfile_cache_miss_bytes":28918207,"cfile_init":7,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":554,"lbm_read_time_us":13611,"lbm_reads_lt_1ms":661,"lbm_write_time_us":28477,"lbm_writes_lt_1ms":643,"mutex_wait_us":262,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":43648,"thread_start_us":67,"threads_started":1,"update_count":3000}
I20260812 06:17:56.795392  8794 ts_tablet_manager.cc:1507] Shutting down tablet manager...
I20260812 06:17:56.795632  8794 tablet_replica.cc:333] T 788cfd3762704a73b904631ef2ed017e P 2823bf5f2cac492a8fdfdbb4c44b23ee: stopping tablet replica
I20260812 06:17:56.795821  8794 raft_consensus.cc:2243] T 788cfd3762704a73b904631ef2ed017e P 2823bf5f2cac492a8fdfdbb4c44b23ee [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:17:56.796090  8794 raft_consensus.cc:2272] T 788cfd3762704a73b904631ef2ed017e P 2823bf5f2cac492a8fdfdbb4c44b23ee [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:17:56.802042  8794 tablet_server.cc:196] TabletServer@127.8.150.129:0 shutdown complete.
I20260812 06:17:56.845249  8794 master.cc:562] Master@127.8.150.190:36265 shutting down...
I20260812 06:17:56.848201  8794 raft_consensus.cc:2243] T 00000000000000000000000000000000 P 08700069e7fb4c06ad1a2c2cd88c90a7 [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:17:56.848377  8794 raft_consensus.cc:2272] T 00000000000000000000000000000000 P 08700069e7fb4c06ad1a2c2cd88c90a7 [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:17:56.848448  8794 tablet_replica.cc:333] T 00000000000000000000000000000000 P 08700069e7fb4c06ad1a2c2cd88c90a7: stopping tablet replica
I20260812 06:17:56.860535  8794 master.cc:584] Master@127.8.150.190:36265 shutdown complete.
[       OK ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/1 (4909 ms)
[----------] 2 tests from EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy (10017 ms total)

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