[==========] Running 2 tests from 1 test suite.
[----------] Global test environment set-up.
[----------] 2 tests from EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy
[ RUN      ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/0
WARNING: Logging before InitGoogleLogging() is written to STDERR
I20260812 06:20:28.667690  8997 internal_mini_cluster.cc:156] Creating distributed mini masters. Addrs: 127.8.201.126:42307
I20260812 06:20:28.668676  8997 env_posix.cc:2285] Not raising this process' open files per process limit of 1048576; it is already as high as it can go
I20260812 06:20:28.669260  8997 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:20:28.676338  9005 instance_detector.cc:116] could not retrieve OpenStack instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:20:28.676398  8997 server_base.cc:1061] running on GCE node
W20260812 06:20:28.676467  9003 instance_detector.cc:116] could not retrieve Azure instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:20:28.676586  9002 instance_detector.cc:116] could not retrieve AWS instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:20:28.677152  8997 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:20:28.677276  8997 system_unsync_time.cc:38] NTP support is disabled. Clock error bounds will not be accurate. This configuration is not suitable for distributed clusters.
I20260812 06:20:28.677304  8997 hybrid_clock.cc:648] HybridClock initialized: now 1786515628677302 us; error 0 us; skew 500 ppm
I20260812 06:20:28.679088  8997 webserver.cc:533] Webserver started at http://127.8.201.126:46655/ using document root <none> and password file <none>
I20260812 06:20:28.679577  8997 fs_manager.cc:362] Metadata directory not provided
I20260812 06:20:28.679630  8997 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:20:28.679808  8997 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:20:28.681460  8997 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskJpMpSi/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515628656676-8997-0/minicluster-data/master-0-root/instance:
uuid: "2793652cd1ed48aa81de8b4230664bd5"
format_stamp: "Formatted at 2026-08-12 06:20:28 on dist-test-slave-w206"
I20260812 06:20:28.684887  8997 fs_manager.cc:696] Time spent creating directory manager: real 0.003s	user 0.005s	sys 0.000s
I20260812 06:20:28.686906  9010 log_block_manager.cc:4127] Time spent loading block containers with low live blocks: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:20:28.688081  8997 fs_manager.cc:730] Time spent opening block manager: real 0.002s	user 0.002s	sys 0.000s
I20260812 06:20:28.688220  8997 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskJpMpSi/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515628656676-8997-0/minicluster-data/master-0-root
uuid: "2793652cd1ed48aa81de8b4230664bd5"
format_stamp: "Formatted at 2026-08-12 06:20:28 on dist-test-slave-w206"
I20260812 06:20:28.688329  8997 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskJpMpSi/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515628656676-8997-0/minicluster-data/master-0-root
metadata directory: /tmp/dist-test-taskJpMpSi/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515628656676-8997-0/minicluster-data/master-0-root
1 data directories: /tmp/dist-test-taskJpMpSi/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515628656676-8997-0/minicluster-data/master-0-root/data
Total live blocks: 0
Total live bytes: 0
Total live bytes (after alignment): 0
Total number of LBM containers: 0 (0 full)
Did not check for missing blocks
Did not check for orphaned blocks
Total full LBM containers with extra space: 0 (0 repaired)
Total full LBM container extra space in bytes: 0 (0 repaired)
Total incomplete LBM containers: 0 (0 repaired)
Total LBM partial records: 0 (0 repaired)
Total corrupted LBM metadata records in RocksDB: 0 (0 repaired)
I20260812 06:20:28.701620  8997 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:20:28.702279  8997 env_posix.cc:2285] Not raising this process' running threads per effective uid limit of 18446744073709551615; it is already as high as it can go
I20260812 06:20:28.702474  8997 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:20:28.710366  8997 rpc_server.cc:307] RPC server started. Bound to: 127.8.201.126:42307
I20260812 06:20:28.710371  9071 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.8.201.126:42307 every 8 connection(s)
I20260812 06:20:28.712781  9072 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet 00000000000000000000000000000000. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:20:28.718194  9072 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P 2793652cd1ed48aa81de8b4230664bd5: Bootstrap starting.
I20260812 06:20:28.720650  9072 tablet_bootstrap.cc:654] T 00000000000000000000000000000000 P 2793652cd1ed48aa81de8b4230664bd5: Neither blocks nor log segments found. Creating new log.
I20260812 06:20:28.721565  9072 log.cc:826] T 00000000000000000000000000000000 P 2793652cd1ed48aa81de8b4230664bd5: Log is configured to *not* fsync() on all Append() calls
I20260812 06:20:28.723325  9072 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P 2793652cd1ed48aa81de8b4230664bd5: No bootstrap required, opened a new log
I20260812 06:20:28.726135  9072 raft_consensus.cc:359] T 00000000000000000000000000000000 P 2793652cd1ed48aa81de8b4230664bd5 [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "2793652cd1ed48aa81de8b4230664bd5" member_type: VOTER }
I20260812 06:20:28.726311  9072 raft_consensus.cc:385] T 00000000000000000000000000000000 P 2793652cd1ed48aa81de8b4230664bd5 [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:20:28.726444  9072 raft_consensus.cc:740] T 00000000000000000000000000000000 P 2793652cd1ed48aa81de8b4230664bd5 [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: 2793652cd1ed48aa81de8b4230664bd5, State: Initialized, Role: FOLLOWER
I20260812 06:20:28.727113  9072 consensus_queue.cc:260] T 00000000000000000000000000000000 P 2793652cd1ed48aa81de8b4230664bd5 [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: "2793652cd1ed48aa81de8b4230664bd5" member_type: VOTER }
I20260812 06:20:28.727293  9072 raft_consensus.cc:399] T 00000000000000000000000000000000 P 2793652cd1ed48aa81de8b4230664bd5 [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:20:28.727365  9072 raft_consensus.cc:493] T 00000000000000000000000000000000 P 2793652cd1ed48aa81de8b4230664bd5 [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:20:28.727541  9072 raft_consensus.cc:3060] T 00000000000000000000000000000000 P 2793652cd1ed48aa81de8b4230664bd5 [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:20:28.728377  9072 raft_consensus.cc:515] T 00000000000000000000000000000000 P 2793652cd1ed48aa81de8b4230664bd5 [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "2793652cd1ed48aa81de8b4230664bd5" member_type: VOTER }
I20260812 06:20:28.728824  9072 leader_election.cc:304] T 00000000000000000000000000000000 P 2793652cd1ed48aa81de8b4230664bd5 [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: 2793652cd1ed48aa81de8b4230664bd5; no voters: 
I20260812 06:20:28.729207  9072 leader_election.cc:290] T 00000000000000000000000000000000 P 2793652cd1ed48aa81de8b4230664bd5 [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:20:28.729362  9075 raft_consensus.cc:2804] T 00000000000000000000000000000000 P 2793652cd1ed48aa81de8b4230664bd5 [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:20:28.729633  9075 raft_consensus.cc:697] T 00000000000000000000000000000000 P 2793652cd1ed48aa81de8b4230664bd5 [term 1 LEADER]: Becoming Leader. State: Replica: 2793652cd1ed48aa81de8b4230664bd5, State: Running, Role: LEADER
I20260812 06:20:28.730023  9075 consensus_queue.cc:237] T 00000000000000000000000000000000 P 2793652cd1ed48aa81de8b4230664bd5 [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: "2793652cd1ed48aa81de8b4230664bd5" member_type: VOTER }
I20260812 06:20:28.730252  9072 sys_catalog.cc:565] T 00000000000000000000000000000000 P 2793652cd1ed48aa81de8b4230664bd5 [sys.catalog]: configured and running, proceeding with master startup.
I20260812 06:20:28.732025  9077 sys_catalog.cc:455] T 00000000000000000000000000000000 P 2793652cd1ed48aa81de8b4230664bd5 [sys.catalog]: SysCatalogTable state changed. Reason: New leader 2793652cd1ed48aa81de8b4230664bd5. Latest consensus state: current_term: 1 leader_uuid: "2793652cd1ed48aa81de8b4230664bd5" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "2793652cd1ed48aa81de8b4230664bd5" member_type: VOTER } }
I20260812 06:20:28.732039  9076 sys_catalog.cc:455] T 00000000000000000000000000000000 P 2793652cd1ed48aa81de8b4230664bd5 [sys.catalog]: SysCatalogTable state changed. Reason: RaftConsensus started. Latest consensus state: current_term: 1 leader_uuid: "2793652cd1ed48aa81de8b4230664bd5" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "2793652cd1ed48aa81de8b4230664bd5" member_type: VOTER } }
I20260812 06:20:28.732182  9077 sys_catalog.cc:458] T 00000000000000000000000000000000 P 2793652cd1ed48aa81de8b4230664bd5 [sys.catalog]: This master's current role is: LEADER
I20260812 06:20:28.732180  9076 sys_catalog.cc:458] T 00000000000000000000000000000000 P 2793652cd1ed48aa81de8b4230664bd5 [sys.catalog]: This master's current role is: LEADER
I20260812 06:20:28.732525  9088 catalog_manager.cc:1511] Loading table and tablet metadata into memory...
I20260812 06:20:28.732731  8997 internal_mini_cluster.cc:184] Waiting to initialize catalog manager on master 0
I20260812 06:20:28.734903  9088 catalog_manager.cc:1520] Initializing Kudu cluster ID...
I20260812 06:20:28.739337  9088 catalog_manager.cc:1383] Generated new cluster ID: a1187563128d47aa94d7f95286df405b
I20260812 06:20:28.739400  9088 catalog_manager.cc:1531] Initializing Kudu internal certificate authority...
I20260812 06:20:28.754001  9088 catalog_manager.cc:1406] Generated new certificate authority record
I20260812 06:20:28.754834  9088 catalog_manager.cc:1540] Loading token signing keys...
I20260812 06:20:28.761700  9088 catalog_manager.cc:6092] T 00000000000000000000000000000000 P 2793652cd1ed48aa81de8b4230664bd5: Generated new TSK 0
I20260812 06:20:28.762312  9088 catalog_manager.cc:1550] Initializing in-progress tserver states...
I20260812 06:20:28.765314  8997 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:20:28.768013  9097 instance_detector.cc:116] could not retrieve Azure instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:20:28.768124  9099 instance_detector.cc:116] could not retrieve OpenStack instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:20:28.768105  9096 instance_detector.cc:116] could not retrieve AWS instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:20:28.768414  8997 server_base.cc:1061] running on GCE node
I20260812 06:20:28.768605  8997 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:20:28.768652  8997 system_unsync_time.cc:38] NTP support is disabled. Clock error bounds will not be accurate. This configuration is not suitable for distributed clusters.
I20260812 06:20:28.768674  8997 hybrid_clock.cc:648] HybridClock initialized: now 1786515628768674 us; error 0 us; skew 500 ppm
I20260812 06:20:28.769582  8997 webserver.cc:533] Webserver started at http://127.8.201.65:45303/ using document root <none> and password file <none>
I20260812 06:20:28.769739  8997 fs_manager.cc:362] Metadata directory not provided
I20260812 06:20:28.769806  8997 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:20:28.769879  8997 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:20:28.770283  8997 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskJpMpSi/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515628656676-8997-0/minicluster-data/ts-0-root/instance:
uuid: "ccfaeb148adf4e22af00fd968a98712c"
format_stamp: "Formatted at 2026-08-12 06:20:28 on dist-test-slave-w206"
I20260812 06:20:28.772105  8997 fs_manager.cc:696] Time spent creating directory manager: real 0.002s	user 0.000s	sys 0.002s
I20260812 06:20:28.773206  9105 log_block_manager.cc:4127] Time spent loading block containers with low live blocks: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:20:28.773518  8997 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.000s	sys 0.001s
I20260812 06:20:28.773581  8997 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskJpMpSi/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515628656676-8997-0/minicluster-data/ts-0-root
uuid: "ccfaeb148adf4e22af00fd968a98712c"
format_stamp: "Formatted at 2026-08-12 06:20:28 on dist-test-slave-w206"
I20260812 06:20:28.773665  8997 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskJpMpSi/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515628656676-8997-0/minicluster-data/ts-0-root
metadata directory: /tmp/dist-test-taskJpMpSi/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515628656676-8997-0/minicluster-data/ts-0-root
1 data directories: /tmp/dist-test-taskJpMpSi/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515628656676-8997-0/minicluster-data/ts-0-root/data
Total live blocks: 0
Total live bytes: 0
Total live bytes (after alignment): 0
Total number of LBM containers: 0 (0 full)
Did not check for missing blocks
Did not check for orphaned blocks
Total full LBM containers with extra space: 0 (0 repaired)
Total full LBM container extra space in bytes: 0 (0 repaired)
Total incomplete LBM containers: 0 (0 repaired)
Total LBM partial records: 0 (0 repaired)
Total corrupted LBM metadata records in RocksDB: 0 (0 repaired)
I20260812 06:20:28.785264  8997 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:20:28.785723  8997 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:20:28.786237  8997 txn_system_client.cc:432] TxnSystemClient initialization is disabled...
I20260812 06:20:28.787142  8997 ts_tablet_manager.cc:585] Loaded tablet metadata (0 total tablets, 0 live tablets)
I20260812 06:20:28.787196  8997 ts_tablet_manager.cc:531] Time spent load tablet metadata: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:20:28.787263  8997 ts_tablet_manager.cc:616] Registered 0 tablets
I20260812 06:20:28.787309  8997 ts_tablet_manager.cc:595] Time spent register tablets: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:20:28.793834  8997 rpc_server.cc:307] RPC server started. Bound to: 127.8.201.65:37643
I20260812 06:20:28.793879  9171 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.8.201.65:37643 every 8 connection(s)
I20260812 06:20:28.803702  9172 heartbeater.cc:344] Connected to a master server at 127.8.201.126:42307
I20260812 06:20:28.803966  9172 heartbeater.cc:461] Registering TS with master...
I20260812 06:20:28.804390  9172 heartbeater.cc:507] Master 127.8.201.126:42307 requested a full tablet report, sending...
I20260812 06:20:28.805738  9029 ts_manager.cc:194] Registered new tserver with Master: ccfaeb148adf4e22af00fd968a98712c (127.8.201.65:37643)
I20260812 06:20:28.806047  8997 internal_mini_cluster.cc:371] 1 TS(s) registered with all masters after 0.011546035s
I20260812 06:20:28.807080  9029 master_service.cc:502] Signed X509 certificate for tserver {username='slave'} at 127.0.0.1:34804
I20260812 06:20:28.815642  9029 catalog_manager.cc:2283] Servicing CreateTable request from {username='slave'} at 127.0.0.1:34820:
name: "heavy-update-compaction-test"
schema {
  columns {
    name: "key"
    type: INT64
    is_key: true
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_a"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_b"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_c"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_d"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_e"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
}
num_replicas: 1
split_rows_range_bounds {
}
partition_schema {
  range_schema {
  }
}
I20260812 06:20:28.829820  9135 tablet_service.cc:1511] Processing CreateTablet for tablet 55a6bbbf78f04ba08e9690432dc562f4 (DEFAULT_TABLE table=heavy-update-compaction-test [id=297a41fa3078439884a62d0cc2f72a32]), partition=
I20260812 06:20:28.830348  9135 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet 55a6bbbf78f04ba08e9690432dc562f4. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:20:28.832844  9184 tablet_bootstrap.cc:492] T 55a6bbbf78f04ba08e9690432dc562f4 P ccfaeb148adf4e22af00fd968a98712c: Bootstrap starting.
I20260812 06:20:28.833920  9184 tablet_bootstrap.cc:654] T 55a6bbbf78f04ba08e9690432dc562f4 P ccfaeb148adf4e22af00fd968a98712c: Neither blocks nor log segments found. Creating new log.
I20260812 06:20:28.835119  9184 tablet_bootstrap.cc:492] T 55a6bbbf78f04ba08e9690432dc562f4 P ccfaeb148adf4e22af00fd968a98712c: No bootstrap required, opened a new log
I20260812 06:20:28.835220  9184 ts_tablet_manager.cc:1403] T 55a6bbbf78f04ba08e9690432dc562f4 P ccfaeb148adf4e22af00fd968a98712c: Time spent bootstrapping tablet: real 0.002s	user 0.002s	sys 0.000s
I20260812 06:20:28.835668  9184 raft_consensus.cc:359] T 55a6bbbf78f04ba08e9690432dc562f4 P ccfaeb148adf4e22af00fd968a98712c [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "ccfaeb148adf4e22af00fd968a98712c" member_type: VOTER last_known_addr { host: "127.8.201.65" port: 37643 } }
I20260812 06:20:28.835765  9184 raft_consensus.cc:385] T 55a6bbbf78f04ba08e9690432dc562f4 P ccfaeb148adf4e22af00fd968a98712c [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:20:28.835816  9184 raft_consensus.cc:740] T 55a6bbbf78f04ba08e9690432dc562f4 P ccfaeb148adf4e22af00fd968a98712c [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: ccfaeb148adf4e22af00fd968a98712c, State: Initialized, Role: FOLLOWER
I20260812 06:20:28.835963  9184 consensus_queue.cc:260] T 55a6bbbf78f04ba08e9690432dc562f4 P ccfaeb148adf4e22af00fd968a98712c [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: "ccfaeb148adf4e22af00fd968a98712c" member_type: VOTER last_known_addr { host: "127.8.201.65" port: 37643 } }
I20260812 06:20:28.836053  9184 raft_consensus.cc:399] T 55a6bbbf78f04ba08e9690432dc562f4 P ccfaeb148adf4e22af00fd968a98712c [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:20:28.836109  9184 raft_consensus.cc:493] T 55a6bbbf78f04ba08e9690432dc562f4 P ccfaeb148adf4e22af00fd968a98712c [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:20:28.836163  9184 raft_consensus.cc:3060] T 55a6bbbf78f04ba08e9690432dc562f4 P ccfaeb148adf4e22af00fd968a98712c [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:20:28.837074  9184 raft_consensus.cc:515] T 55a6bbbf78f04ba08e9690432dc562f4 P ccfaeb148adf4e22af00fd968a98712c [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "ccfaeb148adf4e22af00fd968a98712c" member_type: VOTER last_known_addr { host: "127.8.201.65" port: 37643 } }
I20260812 06:20:28.837234  9184 leader_election.cc:304] T 55a6bbbf78f04ba08e9690432dc562f4 P ccfaeb148adf4e22af00fd968a98712c [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: ccfaeb148adf4e22af00fd968a98712c; no voters: 
I20260812 06:20:28.837527  9184 leader_election.cc:290] T 55a6bbbf78f04ba08e9690432dc562f4 P ccfaeb148adf4e22af00fd968a98712c [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:20:28.837613  9186 raft_consensus.cc:2804] T 55a6bbbf78f04ba08e9690432dc562f4 P ccfaeb148adf4e22af00fd968a98712c [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:20:28.837793  9186 raft_consensus.cc:697] T 55a6bbbf78f04ba08e9690432dc562f4 P ccfaeb148adf4e22af00fd968a98712c [term 1 LEADER]: Becoming Leader. State: Replica: ccfaeb148adf4e22af00fd968a98712c, State: Running, Role: LEADER
I20260812 06:20:28.837888  9184 ts_tablet_manager.cc:1434] T 55a6bbbf78f04ba08e9690432dc562f4 P ccfaeb148adf4e22af00fd968a98712c: Time spent starting tablet: real 0.003s	user 0.003s	sys 0.000s
I20260812 06:20:28.837991  9186 consensus_queue.cc:237] T 55a6bbbf78f04ba08e9690432dc562f4 P ccfaeb148adf4e22af00fd968a98712c [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: "ccfaeb148adf4e22af00fd968a98712c" member_type: VOTER last_known_addr { host: "127.8.201.65" port: 37643 } }
I20260812 06:20:28.838227  9172 heartbeater.cc:499] Master 127.8.201.126:42307 was elected leader, sending a full tablet report...
I20260812 06:20:28.840879  9029 catalog_manager.cc:5719] T 55a6bbbf78f04ba08e9690432dc562f4 P ccfaeb148adf4e22af00fd968a98712c reported cstate change: term changed from 0 to 1, leader changed from <none> to ccfaeb148adf4e22af00fd968a98712c (127.8.201.65). New cstate: current_term: 1 leader_uuid: "ccfaeb148adf4e22af00fd968a98712c" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "ccfaeb148adf4e22af00fd968a98712c" member_type: VOTER last_known_addr { host: "127.8.201.65" port: 37643 } health_report { overall_health: HEALTHY } } }
I20260812 06:20:28.906328  8997 heavy-update-compaction-itest.cc:215] Time spent inserting: real 0.056s	user 0.023s	sys 0.003s
I20260812 06:20:29.044960  9173 maintenance_manager.cc:419] P ccfaeb148adf4e22af00fd968a98712c: Scheduling FlushMRSOp(55a6bbbf78f04ba08e9690432dc562f4): perf score=19.054940
I20260812 06:20:29.267489  9110 maintenance_manager.cc:643] P ccfaeb148adf4e22af00fd968a98712c: FlushMRSOp(55a6bbbf78f04ba08e9690432dc562f4) complete. Timing: real 0.222s	user 0.147s	sys 0.062s Metrics: {"bytes_written":14440742,"cfile_init":1,"compiler_manager_pool.queue_time_us":199,"delete_count":0,"dirs.queue_time_us":88,"dirs.run_cpu_time_us":293,"dirs.run_wall_time_us":1080,"drs_written":1,"lbm_read_time_us":79,"lbm_reads_lt_1ms":4,"lbm_write_time_us":55592,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":808,"mutex_wait_us":1694,"peak_mem_usage":0,"reinsert_count":0,"rows_written":104,"spinlock_wait_cycles":42752,"thread_start_us":133,"threads_started":1,"update_count":1760}
I20260812 06:20:29.268573  9173 maintenance_manager.cc:419] P ccfaeb148adf4e22af00fd968a98712c: Scheduling LogGCOp(55a6bbbf78f04ba08e9690432dc562f4): free 20743880 bytes of WAL
I20260812 06:20:29.268911  9110 log_reader.cc:385] T 55a6bbbf78f04ba08e9690432dc562f4: removed 2 log segments from log reader
I20260812 06:20:29.269004  9110 log.cc:1079] T 55a6bbbf78f04ba08e9690432dc562f4 P ccfaeb148adf4e22af00fd968a98712c: Deleting log segment in path: /tmp/dist-test-taskJpMpSi/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515628656676-8997-0/minicluster-data/ts-0-root/wals/55a6bbbf78f04ba08e9690432dc562f4/wal-000000001 (ops 1-6)
I20260812 06:20:29.269085  9110 log.cc:1079] T 55a6bbbf78f04ba08e9690432dc562f4 P ccfaeb148adf4e22af00fd968a98712c: Deleting log segment in path: /tmp/dist-test-taskJpMpSi/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515628656676-8997-0/minicluster-data/ts-0-root/wals/55a6bbbf78f04ba08e9690432dc562f4/wal-000000002 (ops 7-11)
I20260812 06:20:29.273581  9110 maintenance_manager.cc:643] P ccfaeb148adf4e22af00fd968a98712c: LogGCOp(55a6bbbf78f04ba08e9690432dc562f4) complete. Timing: real 0.005s	user 0.000s	sys 0.002s Metrics: {}
I20260812 06:20:29.273965  9173 maintenance_manager.cc:419] P ccfaeb148adf4e22af00fd968a98712c: Scheduling UndoDeltaBlockGCOp(55a6bbbf78f04ba08e9690432dc562f4): 16411393 bytes on disk
I20260812 06:20:29.274641  9110 maintenance_manager.cc:643] P ccfaeb148adf4e22af00fd968a98712c: UndoDeltaBlockGCOp(55a6bbbf78f04ba08e9690432dc562f4) complete. Timing: real 0.001s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":74,"lbm_reads_lt_1ms":4}
I20260812 06:20:29.275118  9173 maintenance_manager.cc:419] P ccfaeb148adf4e22af00fd968a98712c: Scheduling FlushDeltaMemStoresOp(55a6bbbf78f04ba08e9690432dc562f4): perf score=4.173312
I20260812 06:20:29.298547  9110 maintenance_manager.cc:643] P ccfaeb148adf4e22af00fd968a98712c: FlushDeltaMemStoresOp(55a6bbbf78f04ba08e9690432dc562f4) complete. Timing: real 0.023s	user 0.014s	sys 0.005s Metrics: {"bytes_written":6071825,"delete_count":0,"lbm_write_time_us":7949,"lbm_writes_lt_1ms":151,"reinsert_count":0,"update_count":740}
I20260812 06:20:29.299170  9173 maintenance_manager.cc:419] P ccfaeb148adf4e22af00fd968a98712c: Scheduling MajorDeltaCompactionOp(55a6bbbf78f04ba08e9690432dc562f4): perf score=1.000000
I20260812 06:20:29.473616  9110 maintenance_manager.cc:643] P ccfaeb148adf4e22af00fd968a98712c: MajorDeltaCompactionOp(55a6bbbf78f04ba08e9690432dc562f4) complete. Timing: real 0.174s	user 0.102s	sys 0.068s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774689,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":1836,"lbm_read_time_us":13765,"lbm_reads_lt_1ms":564,"lbm_write_time_us":28445,"lbm_writes_lt_1ms":543,"mutex_wait_us":500,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":768,"thread_start_us":333,"threads_started":5,"update_count":2500}
I20260812 06:20:29.474263  9173 maintenance_manager.cc:419] P ccfaeb148adf4e22af00fd968a98712c: Scheduling FlushDeltaMemStoresOp(55a6bbbf78f04ba08e9690432dc562f4): perf score=11.118625
I20260812 06:20:29.518872  9110 maintenance_manager.cc:643] P ccfaeb148adf4e22af00fd968a98712c: FlushDeltaMemStoresOp(55a6bbbf78f04ba08e9690432dc562f4) complete. Timing: real 0.044s	user 0.023s	sys 0.016s Metrics: {"bytes_written":12717736,"delete_count":0,"lbm_write_time_us":16831,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:20:29.519397  9173 maintenance_manager.cc:419] P ccfaeb148adf4e22af00fd968a98712c: Scheduling FlushDeltaMemStoresOp(55a6bbbf78f04ba08e9690432dc562f4): perf score=2.188937
I20260812 06:20:29.537025  9110 maintenance_manager.cc:643] P ccfaeb148adf4e22af00fd968a98712c: FlushDeltaMemStoresOp(55a6bbbf78f04ba08e9690432dc562f4) complete. Timing: real 0.017s	user 0.013s	sys 0.001s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6236,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:29.537444  9173 maintenance_manager.cc:419] P ccfaeb148adf4e22af00fd968a98712c: Scheduling FlushDeltaMemStoresOp(55a6bbbf78f04ba08e9690432dc562f4): perf score=2.188937
I20260812 06:20:29.557003  9110 maintenance_manager.cc:643] P ccfaeb148adf4e22af00fd968a98712c: FlushDeltaMemStoresOp(55a6bbbf78f04ba08e9690432dc562f4) complete. Timing: real 0.019s	user 0.008s	sys 0.010s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3646,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:20:29.557593  9173 maintenance_manager.cc:419] P ccfaeb148adf4e22af00fd968a98712c: Scheduling MajorDeltaCompactionOp(55a6bbbf78f04ba08e9690432dc562f4): perf score=1.000000
I20260812 06:20:29.735780  9110 maintenance_manager.cc:643] P ccfaeb148adf4e22af00fd968a98712c: MajorDeltaCompactionOp(55a6bbbf78f04ba08e9690432dc562f4) complete. Timing: real 0.178s	user 0.134s	sys 0.043s Metrics: {"cfile_cache_miss":533,"cfile_cache_miss_bytes":24774800,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":732,"lbm_read_time_us":13087,"lbm_reads_lt_1ms":573,"lbm_write_time_us":32021,"lbm_writes_lt_1ms":543,"mutex_wait_us":57,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":10624,"update_count":2500}
I20260812 06:20:29.736443  9173 maintenance_manager.cc:419] P ccfaeb148adf4e22af00fd968a98712c: Scheduling FlushDeltaMemStoresOp(55a6bbbf78f04ba08e9690432dc562f4): perf score=10.126437
I20260812 06:20:29.772285  9110 maintenance_manager.cc:643] P ccfaeb148adf4e22af00fd968a98712c: FlushDeltaMemStoresOp(55a6bbbf78f04ba08e9690432dc562f4) complete. Timing: real 0.036s	user 0.022s	sys 0.012s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":15773,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:20:29.772898  9173 maintenance_manager.cc:419] P ccfaeb148adf4e22af00fd968a98712c: Scheduling FlushDeltaMemStoresOp(55a6bbbf78f04ba08e9690432dc562f4): perf score=2.188937
I20260812 06:20:29.792433  9110 maintenance_manager.cc:643] P ccfaeb148adf4e22af00fd968a98712c: FlushDeltaMemStoresOp(55a6bbbf78f04ba08e9690432dc562f4) complete. Timing: real 0.019s	user 0.015s	sys 0.001s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":6640,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:29.793049  9173 maintenance_manager.cc:419] P ccfaeb148adf4e22af00fd968a98712c: Scheduling MajorDeltaCompactionOp(55a6bbbf78f04ba08e9690432dc562f4): perf score=1.000000
I20260812 06:20:29.920845  9110 maintenance_manager.cc:643] P ccfaeb148adf4e22af00fd968a98712c: MajorDeltaCompactionOp(55a6bbbf78f04ba08e9690432dc562f4) complete. Timing: real 0.128s	user 0.087s	sys 0.041s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672276,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":366,"lbm_read_time_us":8117,"lbm_reads_lt_1ms":468,"lbm_write_time_us":26940,"lbm_writes_lt_1ms":443,"mutex_wait_us":68,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":12544,"update_count":2000}
I20260812 06:20:29.921536  9173 maintenance_manager.cc:419] P ccfaeb148adf4e22af00fd968a98712c: Scheduling FlushDeltaMemStoresOp(55a6bbbf78f04ba08e9690432dc562f4): perf score=10.126437
I20260812 06:20:29.961506  9110 maintenance_manager.cc:643] P ccfaeb148adf4e22af00fd968a98712c: FlushDeltaMemStoresOp(55a6bbbf78f04ba08e9690432dc562f4) complete. Timing: real 0.040s	user 0.022s	sys 0.012s Metrics: {"bytes_written":12307492,"delete_count":0,"lbm_write_time_us":17991,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":302,"reinsert_count":0,"update_count":1500}
I20260812 06:20:29.961992  9173 maintenance_manager.cc:419] P ccfaeb148adf4e22af00fd968a98712c: Scheduling FlushDeltaMemStoresOp(55a6bbbf78f04ba08e9690432dc562f4): perf score=2.188937
I20260812 06:20:29.972401  9110 maintenance_manager.cc:643] P ccfaeb148adf4e22af00fd968a98712c: FlushDeltaMemStoresOp(55a6bbbf78f04ba08e9690432dc562f4) complete. Timing: real 0.010s	user 0.001s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4048,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:29.972842  9173 maintenance_manager.cc:419] P ccfaeb148adf4e22af00fd968a98712c: Scheduling MajorDeltaCompactionOp(55a6bbbf78f04ba08e9690432dc562f4): perf score=1.000000
I20260812 06:20:30.099992  9110 maintenance_manager.cc:643] P ccfaeb148adf4e22af00fd968a98712c: MajorDeltaCompactionOp(55a6bbbf78f04ba08e9690432dc562f4) complete. Timing: real 0.127s	user 0.115s	sys 0.011s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672279,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":675,"lbm_read_time_us":8497,"lbm_reads_lt_1ms":472,"lbm_write_time_us":24273,"lbm_writes_lt_1ms":443,"mutex_wait_us":333,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":11904,"update_count":2000}
I20260812 06:20:30.100736  9173 maintenance_manager.cc:419] P ccfaeb148adf4e22af00fd968a98712c: Scheduling FlushDeltaMemStoresOp(55a6bbbf78f04ba08e9690432dc562f4): perf score=10.126437
I20260812 06:20:30.149672  9110 maintenance_manager.cc:643] P ccfaeb148adf4e22af00fd968a98712c: FlushDeltaMemStoresOp(55a6bbbf78f04ba08e9690432dc562f4) complete. Timing: real 0.049s	user 0.033s	sys 0.004s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":17033,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:20:30.150280  9173 maintenance_manager.cc:419] P ccfaeb148adf4e22af00fd968a98712c: Scheduling FlushDeltaMemStoresOp(55a6bbbf78f04ba08e9690432dc562f4): perf score=2.188937
I20260812 06:20:30.163673  9110 maintenance_manager.cc:643] P ccfaeb148adf4e22af00fd968a98712c: FlushDeltaMemStoresOp(55a6bbbf78f04ba08e9690432dc562f4) complete. Timing: real 0.013s	user 0.012s	sys 0.000s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4922,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:30.164289  9173 maintenance_manager.cc:419] P ccfaeb148adf4e22af00fd968a98712c: Scheduling MajorDeltaCompactionOp(55a6bbbf78f04ba08e9690432dc562f4): perf score=1.000000
I20260812 06:20:30.298589  9110 maintenance_manager.cc:643] P ccfaeb148adf4e22af00fd968a98712c: MajorDeltaCompactionOp(55a6bbbf78f04ba08e9690432dc562f4) complete. Timing: real 0.134s	user 0.116s	sys 0.017s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672276,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":1453,"lbm_read_time_us":10101,"lbm_reads_lt_1ms":472,"lbm_write_time_us":27509,"lbm_writes_lt_1ms":443,"mutex_wait_us":49,"peak_mem_usage":50689328,"reinsert_count":0,"update_count":2000}
I20260812 06:20:30.299485  9173 maintenance_manager.cc:419] P ccfaeb148adf4e22af00fd968a98712c: Scheduling FlushDeltaMemStoresOp(55a6bbbf78f04ba08e9690432dc562f4): perf score=10.126437
I20260812 06:20:30.351828  9110 maintenance_manager.cc:643] P ccfaeb148adf4e22af00fd968a98712c: FlushDeltaMemStoresOp(55a6bbbf78f04ba08e9690432dc562f4) complete. Timing: real 0.052s	user 0.030s	sys 0.015s Metrics: {"bytes_written":12307489,"delete_count":0,"lbm_write_time_us":17108,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:20:30.352371  9173 maintenance_manager.cc:419] P ccfaeb148adf4e22af00fd968a98712c: Scheduling FlushDeltaMemStoresOp(55a6bbbf78f04ba08e9690432dc562f4): perf score=2.188937
I20260812 06:20:30.362722  9110 maintenance_manager.cc:643] P ccfaeb148adf4e22af00fd968a98712c: FlushDeltaMemStoresOp(55a6bbbf78f04ba08e9690432dc562f4) complete. Timing: real 0.010s	user 0.004s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4013,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:30.363327  9173 maintenance_manager.cc:419] P ccfaeb148adf4e22af00fd968a98712c: Scheduling MajorDeltaCompactionOp(55a6bbbf78f04ba08e9690432dc562f4): perf score=1.000000
I20260812 06:20:30.519234  9110 maintenance_manager.cc:643] P ccfaeb148adf4e22af00fd968a98712c: MajorDeltaCompactionOp(55a6bbbf78f04ba08e9690432dc562f4) complete. Timing: real 0.156s	user 0.094s	sys 0.061s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672276,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":227,"lbm_read_time_us":11521,"lbm_reads_lt_1ms":472,"lbm_write_time_us":25780,"lbm_writes_lt_1ms":443,"mutex_wait_us":25,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":2944,"update_count":2000}
I20260812 06:20:30.520061  9173 maintenance_manager.cc:419] P ccfaeb148adf4e22af00fd968a98712c: Scheduling FlushDeltaMemStoresOp(55a6bbbf78f04ba08e9690432dc562f4): perf score=10.126437
I20260812 06:20:30.555197  9110 maintenance_manager.cc:643] P ccfaeb148adf4e22af00fd968a98712c: FlushDeltaMemStoresOp(55a6bbbf78f04ba08e9690432dc562f4) complete. Timing: real 0.035s	user 0.022s	sys 0.013s Metrics: {"bytes_written":12307491,"delete_count":0,"lbm_write_time_us":14749,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:20:30.555905  9173 maintenance_manager.cc:419] P ccfaeb148adf4e22af00fd968a98712c: Scheduling FlushDeltaMemStoresOp(55a6bbbf78f04ba08e9690432dc562f4): perf score=2.188937
I20260812 06:20:30.578895  9110 maintenance_manager.cc:643] P ccfaeb148adf4e22af00fd968a98712c: FlushDeltaMemStoresOp(55a6bbbf78f04ba08e9690432dc562f4) complete. Timing: real 0.023s	user 0.011s	sys 0.000s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4878,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:30.579459  9173 maintenance_manager.cc:419] P ccfaeb148adf4e22af00fd968a98712c: Scheduling FlushDeltaMemStoresOp(55a6bbbf78f04ba08e9690432dc562f4): perf score=2.188937
I20260812 06:20:30.594455  9110 maintenance_manager.cc:643] P ccfaeb148adf4e22af00fd968a98712c: FlushDeltaMemStoresOp(55a6bbbf78f04ba08e9690432dc562f4) complete. Timing: real 0.015s	user 0.009s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5899,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:30.595073  9173 maintenance_manager.cc:419] P ccfaeb148adf4e22af00fd968a98712c: Scheduling FlushMRSOp(55a6bbbf78f04ba08e9690432dc562f4): perf score=1.000000
I20260812 06:20:30.627779  9110 maintenance_manager.cc:643] P ccfaeb148adf4e22af00fd968a98712c: FlushMRSOp(55a6bbbf78f04ba08e9690432dc562f4) complete. Timing: real 0.033s	user 0.031s	sys 0.001s Metrics: {"bytes_written":1275443,"cfile_init":1,"dirs.queue_time_us":78,"dirs.run_cpu_time_us":284,"dirs.run_wall_time_us":1580,"drs_written":1,"lbm_read_time_us":82,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1502,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":31}
I20260812 06:20:30.628733  9173 maintenance_manager.cc:419] P ccfaeb148adf4e22af00fd968a98712c: Scheduling FlushDeltaMemStoresOp(55a6bbbf78f04ba08e9690432dc562f4): perf score=2.188937
I20260812 06:20:30.640897  9110 maintenance_manager.cc:643] P ccfaeb148adf4e22af00fd968a98712c: FlushDeltaMemStoresOp(55a6bbbf78f04ba08e9690432dc562f4) complete. Timing: real 0.012s	user 0.007s	sys 0.003s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4848,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:30.641352  9173 maintenance_manager.cc:419] P ccfaeb148adf4e22af00fd968a98712c: Scheduling LogGCOp(55a6bbbf78f04ba08e9690432dc562f4): free 124710252 bytes of WAL
I20260812 06:20:30.641582  9110 log_reader.cc:385] T 55a6bbbf78f04ba08e9690432dc562f4: removed 12 log segments from log reader
I20260812 06:20:30.641628  9110 log.cc:1079] T 55a6bbbf78f04ba08e9690432dc562f4 P ccfaeb148adf4e22af00fd968a98712c: Deleting log segment in path: /tmp/dist-test-taskJpMpSi/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515628656676-8997-0/minicluster-data/ts-0-root/wals/55a6bbbf78f04ba08e9690432dc562f4/wal-000000003 (ops 12-16)
I20260812 06:20:30.641656  9110 log.cc:1079] T 55a6bbbf78f04ba08e9690432dc562f4 P ccfaeb148adf4e22af00fd968a98712c: Deleting log segment in path: /tmp/dist-test-taskJpMpSi/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515628656676-8997-0/minicluster-data/ts-0-root/wals/55a6bbbf78f04ba08e9690432dc562f4/wal-000000004 (ops 17-21)
I20260812 06:20:30.641718  9110 log.cc:1079] T 55a6bbbf78f04ba08e9690432dc562f4 P ccfaeb148adf4e22af00fd968a98712c: Deleting log segment in path: /tmp/dist-test-taskJpMpSi/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515628656676-8997-0/minicluster-data/ts-0-root/wals/55a6bbbf78f04ba08e9690432dc562f4/wal-000000005 (ops 22-26)
I20260812 06:20:30.641752  9110 log.cc:1079] T 55a6bbbf78f04ba08e9690432dc562f4 P ccfaeb148adf4e22af00fd968a98712c: Deleting log segment in path: /tmp/dist-test-taskJpMpSi/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515628656676-8997-0/minicluster-data/ts-0-root/wals/55a6bbbf78f04ba08e9690432dc562f4/wal-000000006 (ops 27-31)
I20260812 06:20:30.641788  9110 log.cc:1079] T 55a6bbbf78f04ba08e9690432dc562f4 P ccfaeb148adf4e22af00fd968a98712c: Deleting log segment in path: /tmp/dist-test-taskJpMpSi/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515628656676-8997-0/minicluster-data/ts-0-root/wals/55a6bbbf78f04ba08e9690432dc562f4/wal-000000007 (ops 32-36)
I20260812 06:20:30.641826  9110 log.cc:1079] T 55a6bbbf78f04ba08e9690432dc562f4 P ccfaeb148adf4e22af00fd968a98712c: Deleting log segment in path: /tmp/dist-test-taskJpMpSi/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515628656676-8997-0/minicluster-data/ts-0-root/wals/55a6bbbf78f04ba08e9690432dc562f4/wal-000000008 (ops 37-41)
I20260812 06:20:30.641865  9110 log.cc:1079] T 55a6bbbf78f04ba08e9690432dc562f4 P ccfaeb148adf4e22af00fd968a98712c: Deleting log segment in path: /tmp/dist-test-taskJpMpSi/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515628656676-8997-0/minicluster-data/ts-0-root/wals/55a6bbbf78f04ba08e9690432dc562f4/wal-000000009 (ops 42-46)
I20260812 06:20:30.641906  9110 log.cc:1079] T 55a6bbbf78f04ba08e9690432dc562f4 P ccfaeb148adf4e22af00fd968a98712c: Deleting log segment in path: /tmp/dist-test-taskJpMpSi/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515628656676-8997-0/minicluster-data/ts-0-root/wals/55a6bbbf78f04ba08e9690432dc562f4/wal-000000010 (ops 47-51)
I20260812 06:20:30.641947  9110 log.cc:1079] T 55a6bbbf78f04ba08e9690432dc562f4 P ccfaeb148adf4e22af00fd968a98712c: Deleting log segment in path: /tmp/dist-test-taskJpMpSi/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515628656676-8997-0/minicluster-data/ts-0-root/wals/55a6bbbf78f04ba08e9690432dc562f4/wal-000000011 (ops 52-56)
I20260812 06:20:30.641984  9110 log.cc:1079] T 55a6bbbf78f04ba08e9690432dc562f4 P ccfaeb148adf4e22af00fd968a98712c: Deleting log segment in path: /tmp/dist-test-taskJpMpSi/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515628656676-8997-0/minicluster-data/ts-0-root/wals/55a6bbbf78f04ba08e9690432dc562f4/wal-000000012 (ops 57-61)
I20260812 06:20:30.642023  9110 log.cc:1079] T 55a6bbbf78f04ba08e9690432dc562f4 P ccfaeb148adf4e22af00fd968a98712c: Deleting log segment in path: /tmp/dist-test-taskJpMpSi/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515628656676-8997-0/minicluster-data/ts-0-root/wals/55a6bbbf78f04ba08e9690432dc562f4/wal-000000013 (ops 62-66)
I20260812 06:20:30.642061  9110 log.cc:1079] T 55a6bbbf78f04ba08e9690432dc562f4 P ccfaeb148adf4e22af00fd968a98712c: Deleting log segment in path: /tmp/dist-test-taskJpMpSi/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515628656676-8997-0/minicluster-data/ts-0-root/wals/55a6bbbf78f04ba08e9690432dc562f4/wal-000000014 (ops 67-71)
I20260812 06:20:30.671367  9110 maintenance_manager.cc:643] P ccfaeb148adf4e22af00fd968a98712c: LogGCOp(55a6bbbf78f04ba08e9690432dc562f4) complete. Timing: real 0.030s	user 0.000s	sys 0.029s Metrics: {}
I20260812 06:20:30.671772  9173 maintenance_manager.cc:419] P ccfaeb148adf4e22af00fd968a98712c: Scheduling MajorDeltaCompactionOp(55a6bbbf78f04ba08e9690432dc562f4): perf score=1.000000
I20260812 06:20:30.867703  9110 maintenance_manager.cc:643] P ccfaeb148adf4e22af00fd968a98712c: MajorDeltaCompactionOp(55a6bbbf78f04ba08e9690432dc562f4) complete. Timing: real 0.196s	user 0.118s	sys 0.078s Metrics: {"cfile_cache_miss":634,"cfile_cache_miss_bytes":28877339,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":371,"lbm_read_time_us":12654,"lbm_reads_lt_1ms":666,"lbm_write_time_us":35847,"lbm_writes_lt_1ms":643,"mutex_wait_us":27,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":9600,"thread_start_us":94,"threads_started":1,"update_count":3000}
I20260812 06:20:30.868238  9173 maintenance_manager.cc:419] P ccfaeb148adf4e22af00fd968a98712c: Scheduling FlushDeltaMemStoresOp(55a6bbbf78f04ba08e9690432dc562f4): perf score=14.095187
I20260812 06:20:30.918663  9110 maintenance_manager.cc:643] P ccfaeb148adf4e22af00fd968a98712c: FlushDeltaMemStoresOp(55a6bbbf78f04ba08e9690432dc562f4) complete. Timing: real 0.050s	user 0.027s	sys 0.019s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":18258,"lbm_writes_lt_1ms":403,"reinsert_count":0,"spinlock_wait_cycles":1408,"update_count":2000}
I20260812 06:20:30.919409  9173 maintenance_manager.cc:419] P ccfaeb148adf4e22af00fd968a98712c: Scheduling UndoDeltaBlockGCOp(55a6bbbf78f04ba08e9690432dc562f4): 482 bytes on disk
I20260812 06:20:30.920120  9110 maintenance_manager.cc:643] P ccfaeb148adf4e22af00fd968a98712c: UndoDeltaBlockGCOp(55a6bbbf78f04ba08e9690432dc562f4) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":107,"lbm_reads_lt_1ms":4}
I20260812 06:20:30.920655  9173 maintenance_manager.cc:419] P ccfaeb148adf4e22af00fd968a98712c: Scheduling FlushDeltaMemStoresOp(55a6bbbf78f04ba08e9690432dc562f4): perf score=2.188937
I20260812 06:20:30.936956  9110 maintenance_manager.cc:643] P ccfaeb148adf4e22af00fd968a98712c: FlushDeltaMemStoresOp(55a6bbbf78f04ba08e9690432dc562f4) complete. Timing: real 0.016s	user 0.005s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6082,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:30.937399  9173 maintenance_manager.cc:419] P ccfaeb148adf4e22af00fd968a98712c: Scheduling MajorDeltaCompactionOp(55a6bbbf78f04ba08e9690432dc562f4): perf score=1.000000
I20260812 06:20:31.149052  9110 maintenance_manager.cc:643] P ccfaeb148adf4e22af00fd968a98712c: MajorDeltaCompactionOp(55a6bbbf78f04ba08e9690432dc562f4) complete. Timing: real 0.211s	user 0.136s	sys 0.060s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774688,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":918,"lbm_read_time_us":12519,"lbm_reads_lt_1ms":568,"lbm_write_time_us":32187,"lbm_writes_1-10_ms":2,"lbm_writes_lt_1ms":541,"mutex_wait_us":485,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":2688,"update_count":2500}
I20260812 06:20:31.150430  9173 maintenance_manager.cc:419] P ccfaeb148adf4e22af00fd968a98712c: Scheduling FlushDeltaMemStoresOp(55a6bbbf78f04ba08e9690432dc562f4): perf score=14.095187
I20260812 06:20:31.249182  9110 maintenance_manager.cc:643] P ccfaeb148adf4e22af00fd968a98712c: FlushDeltaMemStoresOp(55a6bbbf78f04ba08e9690432dc562f4) complete. Timing: real 0.098s	user 0.073s	sys 0.023s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":44513,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":402,"reinsert_count":0,"update_count":2000}
I20260812 06:20:31.249938  9173 maintenance_manager.cc:419] P ccfaeb148adf4e22af00fd968a98712c: Scheduling FlushDeltaMemStoresOp(55a6bbbf78f04ba08e9690432dc562f4): perf score=2.188937
I20260812 06:20:31.290766  9110 maintenance_manager.cc:643] P ccfaeb148adf4e22af00fd968a98712c: FlushDeltaMemStoresOp(55a6bbbf78f04ba08e9690432dc562f4) complete. Timing: real 0.040s	user 0.028s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":14007,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:31.291941  9173 maintenance_manager.cc:419] P ccfaeb148adf4e22af00fd968a98712c: Scheduling MajorDeltaCompactionOp(55a6bbbf78f04ba08e9690432dc562f4): perf score=1.000000
I20260812 06:20:31.649349  9110 maintenance_manager.cc:643] P ccfaeb148adf4e22af00fd968a98712c: MajorDeltaCompactionOp(55a6bbbf78f04ba08e9690432dc562f4) complete. Timing: real 0.357s	user 0.242s	sys 0.105s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774688,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":89,"lbm_read_time_us":25262,"lbm_reads_lt_1ms":564,"lbm_write_time_us":62441,"lbm_writes_lt_1ms":543,"mutex_wait_us":39,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":11136,"update_count":2500}
I20260812 06:20:31.650574  9173 maintenance_manager.cc:419] P ccfaeb148adf4e22af00fd968a98712c: Scheduling FlushDeltaMemStoresOp(55a6bbbf78f04ba08e9690432dc562f4): perf score=14.095187
I20260812 06:20:31.742731  9110 maintenance_manager.cc:643] P ccfaeb148adf4e22af00fd968a98712c: FlushDeltaMemStoresOp(55a6bbbf78f04ba08e9690432dc562f4) complete. Timing: real 0.092s	user 0.061s	sys 0.027s Metrics: {"bytes_written":16409903,"delete_count":0,"lbm_write_time_us":42194,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:20:31.743566  9173 maintenance_manager.cc:419] P ccfaeb148adf4e22af00fd968a98712c: Scheduling FlushDeltaMemStoresOp(55a6bbbf78f04ba08e9690432dc562f4): perf score=2.188937
I20260812 06:20:31.774032  9110 maintenance_manager.cc:643] P ccfaeb148adf4e22af00fd968a98712c: FlushDeltaMemStoresOp(55a6bbbf78f04ba08e9690432dc562f4) complete. Timing: real 0.030s	user 0.018s	sys 0.009s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":12790,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:31.774693  9173 maintenance_manager.cc:419] P ccfaeb148adf4e22af00fd968a98712c: Scheduling MajorDeltaCompactionOp(55a6bbbf78f04ba08e9690432dc562f4): perf score=1.000000
I20260812 06:20:32.025044  9110 maintenance_manager.cc:643] P ccfaeb148adf4e22af00fd968a98712c: MajorDeltaCompactionOp(55a6bbbf78f04ba08e9690432dc562f4) complete. Timing: real 0.250s	user 0.150s	sys 0.089s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774690,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":200,"lbm_read_time_us":17201,"lbm_reads_lt_1ms":572,"lbm_write_time_us":47052,"lbm_writes_lt_1ms":543,"mutex_wait_us":20,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":11776,"update_count":2500}
I20260812 06:20:32.025700  9173 maintenance_manager.cc:419] P ccfaeb148adf4e22af00fd968a98712c: Scheduling FlushDeltaMemStoresOp(55a6bbbf78f04ba08e9690432dc562f4): perf score=14.095187
I20260812 06:20:32.072490  9110 maintenance_manager.cc:643] P ccfaeb148adf4e22af00fd968a98712c: FlushDeltaMemStoresOp(55a6bbbf78f04ba08e9690432dc562f4) complete. Timing: real 0.047s	user 0.022s	sys 0.023s Metrics: {"bytes_written":16409903,"delete_count":0,"lbm_write_time_us":20914,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:20:32.073102  9173 maintenance_manager.cc:419] P ccfaeb148adf4e22af00fd968a98712c: Scheduling FlushDeltaMemStoresOp(55a6bbbf78f04ba08e9690432dc562f4): perf score=2.188937
I20260812 06:20:32.085526  9110 maintenance_manager.cc:643] P ccfaeb148adf4e22af00fd968a98712c: FlushDeltaMemStoresOp(55a6bbbf78f04ba08e9690432dc562f4) complete. Timing: real 0.012s	user 0.007s	sys 0.003s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4764,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:32.086135  9173 maintenance_manager.cc:419] P ccfaeb148adf4e22af00fd968a98712c: Scheduling MajorDeltaCompactionOp(55a6bbbf78f04ba08e9690432dc562f4): perf score=1.000000
I20260812 06:20:32.255131  9110 maintenance_manager.cc:643] P ccfaeb148adf4e22af00fd968a98712c: MajorDeltaCompactionOp(55a6bbbf78f04ba08e9690432dc562f4) complete. Timing: real 0.169s	user 0.145s	sys 0.021s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774689,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":513,"lbm_read_time_us":10908,"lbm_reads_lt_1ms":572,"lbm_write_time_us":35775,"lbm_writes_lt_1ms":543,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":1792,"update_count":2500}
I20260812 06:20:32.255838  9173 maintenance_manager.cc:419] P ccfaeb148adf4e22af00fd968a98712c: Scheduling FlushDeltaMemStoresOp(55a6bbbf78f04ba08e9690432dc562f4): perf score=11.118625
I20260812 06:20:32.296327  9110 maintenance_manager.cc:643] P ccfaeb148adf4e22af00fd968a98712c: FlushDeltaMemStoresOp(55a6bbbf78f04ba08e9690432dc562f4) complete. Timing: real 0.040s	user 0.020s	sys 0.017s Metrics: {"bytes_written":12717734,"delete_count":0,"lbm_write_time_us":16759,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:20:32.296856  9173 maintenance_manager.cc:419] P ccfaeb148adf4e22af00fd968a98712c: Scheduling FlushDeltaMemStoresOp(55a6bbbf78f04ba08e9690432dc562f4): perf score=2.188937
I20260812 06:20:32.311335  9110 maintenance_manager.cc:643] P ccfaeb148adf4e22af00fd968a98712c: FlushDeltaMemStoresOp(55a6bbbf78f04ba08e9690432dc562f4) complete. Timing: real 0.014s	user 0.010s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5419,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:32.311861  9173 maintenance_manager.cc:419] P ccfaeb148adf4e22af00fd968a98712c: Scheduling FlushDeltaMemStoresOp(55a6bbbf78f04ba08e9690432dc562f4): perf score=2.188937
I20260812 06:20:32.323218  9110 maintenance_manager.cc:643] P ccfaeb148adf4e22af00fd968a98712c: FlushDeltaMemStoresOp(55a6bbbf78f04ba08e9690432dc562f4) complete. Timing: real 0.011s	user 0.007s	sys 0.004s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3677,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:20:32.323834  9173 maintenance_manager.cc:419] P ccfaeb148adf4e22af00fd968a98712c: Scheduling MajorDeltaCompactionOp(55a6bbbf78f04ba08e9690432dc562f4): perf score=1.000000
I20260812 06:20:32.489459  9110 maintenance_manager.cc:643] P ccfaeb148adf4e22af00fd968a98712c: MajorDeltaCompactionOp(55a6bbbf78f04ba08e9690432dc562f4) complete. Timing: real 0.165s	user 0.115s	sys 0.040s Metrics: {"cfile_cache_miss":533,"cfile_cache_miss_bytes":24774798,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":278,"lbm_read_time_us":11243,"lbm_reads_lt_1ms":573,"lbm_write_time_us":33169,"lbm_writes_lt_1ms":543,"mutex_wait_us":25,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":8704,"update_count":2500}
I20260812 06:20:32.490043  9173 maintenance_manager.cc:419] P ccfaeb148adf4e22af00fd968a98712c: Scheduling FlushDeltaMemStoresOp(55a6bbbf78f04ba08e9690432dc562f4): perf score=14.095187
I20260812 06:20:32.541050  9110 maintenance_manager.cc:643] P ccfaeb148adf4e22af00fd968a98712c: FlushDeltaMemStoresOp(55a6bbbf78f04ba08e9690432dc562f4) complete. Timing: real 0.051s	user 0.037s	sys 0.012s Metrics: {"bytes_written":16409900,"delete_count":0,"lbm_write_time_us":22970,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:20:32.541556  9173 maintenance_manager.cc:419] P ccfaeb148adf4e22af00fd968a98712c: Scheduling FlushDeltaMemStoresOp(55a6bbbf78f04ba08e9690432dc562f4): perf score=2.188937
I20260812 06:20:32.562914  9110 maintenance_manager.cc:643] P ccfaeb148adf4e22af00fd968a98712c: FlushDeltaMemStoresOp(55a6bbbf78f04ba08e9690432dc562f4) complete. Timing: real 0.021s	user 0.003s	sys 0.011s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6583,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:32.563668  9173 maintenance_manager.cc:419] P ccfaeb148adf4e22af00fd968a98712c: Scheduling FlushMRSOp(55a6bbbf78f04ba08e9690432dc562f4): perf score=1.000000
I20260812 06:20:32.614488  9110 maintenance_manager.cc:643] P ccfaeb148adf4e22af00fd968a98712c: FlushMRSOp(55a6bbbf78f04ba08e9690432dc562f4) complete. Timing: real 0.051s	user 0.025s	sys 0.004s Metrics: {"bytes_written":1316419,"cfile_init":1,"dirs.queue_time_us":87,"dirs.run_cpu_time_us":165,"dirs.run_wall_time_us":1388,"drs_written":1,"lbm_read_time_us":65,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1883,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":32}
I20260812 06:20:32.615342  9173 maintenance_manager.cc:419] P ccfaeb148adf4e22af00fd968a98712c: Scheduling LogGCOp(55a6bbbf78f04ba08e9690432dc562f4): free 124710309 bytes of WAL
I20260812 06:20:32.615581  9110 log_reader.cc:385] T 55a6bbbf78f04ba08e9690432dc562f4: removed 12 log segments from log reader
I20260812 06:20:32.615628  9110 log.cc:1079] T 55a6bbbf78f04ba08e9690432dc562f4 P ccfaeb148adf4e22af00fd968a98712c: Deleting log segment in path: /tmp/dist-test-taskJpMpSi/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515628656676-8997-0/minicluster-data/ts-0-root/wals/55a6bbbf78f04ba08e9690432dc562f4/wal-000000015 (ops 72-76)
I20260812 06:20:32.615656  9110 log.cc:1079] T 55a6bbbf78f04ba08e9690432dc562f4 P ccfaeb148adf4e22af00fd968a98712c: Deleting log segment in path: /tmp/dist-test-taskJpMpSi/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515628656676-8997-0/minicluster-data/ts-0-root/wals/55a6bbbf78f04ba08e9690432dc562f4/wal-000000016 (ops 77-81)
I20260812 06:20:32.615725  9110 log.cc:1079] T 55a6bbbf78f04ba08e9690432dc562f4 P ccfaeb148adf4e22af00fd968a98712c: Deleting log segment in path: /tmp/dist-test-taskJpMpSi/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515628656676-8997-0/minicluster-data/ts-0-root/wals/55a6bbbf78f04ba08e9690432dc562f4/wal-000000017 (ops 82-86)
I20260812 06:20:32.615759  9110 log.cc:1079] T 55a6bbbf78f04ba08e9690432dc562f4 P ccfaeb148adf4e22af00fd968a98712c: Deleting log segment in path: /tmp/dist-test-taskJpMpSi/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515628656676-8997-0/minicluster-data/ts-0-root/wals/55a6bbbf78f04ba08e9690432dc562f4/wal-000000018 (ops 87-91)
I20260812 06:20:32.615800  9110 log.cc:1079] T 55a6bbbf78f04ba08e9690432dc562f4 P ccfaeb148adf4e22af00fd968a98712c: Deleting log segment in path: /tmp/dist-test-taskJpMpSi/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515628656676-8997-0/minicluster-data/ts-0-root/wals/55a6bbbf78f04ba08e9690432dc562f4/wal-000000019 (ops 92-96)
I20260812 06:20:32.615865  9110 log.cc:1079] T 55a6bbbf78f04ba08e9690432dc562f4 P ccfaeb148adf4e22af00fd968a98712c: Deleting log segment in path: /tmp/dist-test-taskJpMpSi/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515628656676-8997-0/minicluster-data/ts-0-root/wals/55a6bbbf78f04ba08e9690432dc562f4/wal-000000020 (ops 97-101)
I20260812 06:20:32.615913  9110 log.cc:1079] T 55a6bbbf78f04ba08e9690432dc562f4 P ccfaeb148adf4e22af00fd968a98712c: Deleting log segment in path: /tmp/dist-test-taskJpMpSi/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515628656676-8997-0/minicluster-data/ts-0-root/wals/55a6bbbf78f04ba08e9690432dc562f4/wal-000000021 (ops 102-106)
I20260812 06:20:32.615957  9110 log.cc:1079] T 55a6bbbf78f04ba08e9690432dc562f4 P ccfaeb148adf4e22af00fd968a98712c: Deleting log segment in path: /tmp/dist-test-taskJpMpSi/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515628656676-8997-0/minicluster-data/ts-0-root/wals/55a6bbbf78f04ba08e9690432dc562f4/wal-000000022 (ops 107-111)
I20260812 06:20:32.615993  9110 log.cc:1079] T 55a6bbbf78f04ba08e9690432dc562f4 P ccfaeb148adf4e22af00fd968a98712c: Deleting log segment in path: /tmp/dist-test-taskJpMpSi/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515628656676-8997-0/minicluster-data/ts-0-root/wals/55a6bbbf78f04ba08e9690432dc562f4/wal-000000023 (ops 112-116)
I20260812 06:20:32.616029  9110 log.cc:1079] T 55a6bbbf78f04ba08e9690432dc562f4 P ccfaeb148adf4e22af00fd968a98712c: Deleting log segment in path: /tmp/dist-test-taskJpMpSi/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515628656676-8997-0/minicluster-data/ts-0-root/wals/55a6bbbf78f04ba08e9690432dc562f4/wal-000000024 (ops 117-121)
I20260812 06:20:32.616070  9110 log.cc:1079] T 55a6bbbf78f04ba08e9690432dc562f4 P ccfaeb148adf4e22af00fd968a98712c: Deleting log segment in path: /tmp/dist-test-taskJpMpSi/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515628656676-8997-0/minicluster-data/ts-0-root/wals/55a6bbbf78f04ba08e9690432dc562f4/wal-000000025 (ops 122-126)
I20260812 06:20:32.616110  9110 log.cc:1079] T 55a6bbbf78f04ba08e9690432dc562f4 P ccfaeb148adf4e22af00fd968a98712c: Deleting log segment in path: /tmp/dist-test-taskJpMpSi/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515628656676-8997-0/minicluster-data/ts-0-root/wals/55a6bbbf78f04ba08e9690432dc562f4/wal-000000026 (ops 127-131)
I20260812 06:20:32.644336  9110 maintenance_manager.cc:643] P ccfaeb148adf4e22af00fd968a98712c: LogGCOp(55a6bbbf78f04ba08e9690432dc562f4) complete. Timing: real 0.029s	user 0.000s	sys 0.028s Metrics: {}
I20260812 06:20:32.645172  9173 maintenance_manager.cc:419] P ccfaeb148adf4e22af00fd968a98712c: Scheduling UndoDeltaBlockGCOp(55a6bbbf78f04ba08e9690432dc562f4): 493 bytes on disk
I20260812 06:20:32.645712  9110 maintenance_manager.cc:643] P ccfaeb148adf4e22af00fd968a98712c: UndoDeltaBlockGCOp(55a6bbbf78f04ba08e9690432dc562f4) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":52,"lbm_reads_lt_1ms":4}
I20260812 06:20:32.646209  9173 maintenance_manager.cc:419] P ccfaeb148adf4e22af00fd968a98712c: Scheduling FlushDeltaMemStoresOp(55a6bbbf78f04ba08e9690432dc562f4): perf score=7.149875
I20260812 06:20:32.666199  9110 maintenance_manager.cc:643] P ccfaeb148adf4e22af00fd968a98712c: FlushDeltaMemStoresOp(55a6bbbf78f04ba08e9690432dc562f4) complete. Timing: real 0.020s	user 0.006s	sys 0.011s Metrics: {"bytes_written":8615323,"delete_count":0,"lbm_write_time_us":8805,"lbm_writes_lt_1ms":213,"reinsert_count":0,"update_count":1050}
I20260812 06:20:32.666688  9173 maintenance_manager.cc:419] P ccfaeb148adf4e22af00fd968a98712c: Scheduling LogGCOp(55a6bbbf78f04ba08e9690432dc562f4): free 12018006 bytes of WAL
I20260812 06:20:32.666885  9110 log_reader.cc:385] T 55a6bbbf78f04ba08e9690432dc562f4: removed 1 log segments from log reader
I20260812 06:20:32.666931  9110 log.cc:1079] T 55a6bbbf78f04ba08e9690432dc562f4 P ccfaeb148adf4e22af00fd968a98712c: Deleting log segment in path: /tmp/dist-test-taskJpMpSi/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515628656676-8997-0/minicluster-data/ts-0-root/wals/55a6bbbf78f04ba08e9690432dc562f4/wal-000000027 (ops 132-136)
I20260812 06:20:32.669690  9110 maintenance_manager.cc:643] P ccfaeb148adf4e22af00fd968a98712c: LogGCOp(55a6bbbf78f04ba08e9690432dc562f4) complete. Timing: real 0.003s	user 0.000s	sys 0.000s Metrics: {}
I20260812 06:20:32.670419  9173 maintenance_manager.cc:419] P ccfaeb148adf4e22af00fd968a98712c: Scheduling FlushDeltaMemStoresOp(55a6bbbf78f04ba08e9690432dc562f4): perf score=2.188937
I20260812 06:20:32.682941  9110 maintenance_manager.cc:643] P ccfaeb148adf4e22af00fd968a98712c: FlushDeltaMemStoresOp(55a6bbbf78f04ba08e9690432dc562f4) complete. Timing: real 0.012s	user 0.002s	sys 0.007s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":4155,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:20:32.683413  9173 maintenance_manager.cc:419] P ccfaeb148adf4e22af00fd968a98712c: Scheduling MajorDeltaCompactionOp(55a6bbbf78f04ba08e9690432dc562f4): perf score=1.000000
I20260812 06:20:32.889009  9110 maintenance_manager.cc:643] P ccfaeb148adf4e22af00fd968a98712c: MajorDeltaCompactionOp(55a6bbbf78f04ba08e9690432dc562f4) complete. Timing: real 0.205s	user 0.155s	sys 0.050s Metrics: {"cfile_cache_miss":834,"cfile_cache_miss_bytes":37082153,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":559,"lbm_read_time_us":14980,"lbm_reads_lt_1ms":866,"lbm_write_time_us":43750,"lbm_writes_lt_1ms":843,"mutex_wait_us":84,"peak_mem_usage":100395616,"reinsert_count":0,"spinlock_wait_cycles":11008,"thread_start_us":86,"threads_started":1,"update_count":4000}
I20260812 06:20:32.889710  9173 maintenance_manager.cc:419] P ccfaeb148adf4e22af00fd968a98712c: Scheduling FlushDeltaMemStoresOp(55a6bbbf78f04ba08e9690432dc562f4): perf score=18.063937
I20260812 06:20:32.980654  9110 maintenance_manager.cc:643] P ccfaeb148adf4e22af00fd968a98712c: FlushDeltaMemStoresOp(55a6bbbf78f04ba08e9690432dc562f4) complete. Timing: real 0.091s	user 0.028s	sys 0.039s Metrics: {"bytes_written":20512316,"delete_count":0,"lbm_write_time_us":25312,"lbm_writes_lt_1ms":503,"reinsert_count":0,"update_count":2500}
I20260812 06:20:32.981141  9173 maintenance_manager.cc:419] P ccfaeb148adf4e22af00fd968a98712c: Scheduling FlushDeltaMemStoresOp(55a6bbbf78f04ba08e9690432dc562f4): perf score=2.188937
I20260812 06:20:32.991840  9110 maintenance_manager.cc:643] P ccfaeb148adf4e22af00fd968a98712c: FlushDeltaMemStoresOp(55a6bbbf78f04ba08e9690432dc562f4) complete. Timing: real 0.011s	user 0.005s	sys 0.005s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4083,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:32.992285  9173 maintenance_manager.cc:419] P ccfaeb148adf4e22af00fd968a98712c: Scheduling MajorDeltaCompactionOp(55a6bbbf78f04ba08e9690432dc562f4): perf score=1.000000
I20260812 06:20:33.198859  9110 maintenance_manager.cc:643] P ccfaeb148adf4e22af00fd968a98712c: MajorDeltaCompactionOp(55a6bbbf78f04ba08e9690432dc562f4) complete. Timing: real 0.206s	user 0.152s	sys 0.046s Metrics: {"cfile_cache_miss":632,"cfile_cache_miss_bytes":28877103,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":1274,"lbm_read_time_us":14588,"lbm_reads_lt_1ms":672,"lbm_write_time_us":35289,"lbm_writes_lt_1ms":643,"mutex_wait_us":314,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":20224,"update_count":3000}
I20260812 06:20:33.199415  9173 maintenance_manager.cc:419] P ccfaeb148adf4e22af00fd968a98712c: Scheduling FlushDeltaMemStoresOp(55a6bbbf78f04ba08e9690432dc562f4): perf score=14.095187
I20260812 06:20:33.264062  9110 maintenance_manager.cc:643] P ccfaeb148adf4e22af00fd968a98712c: FlushDeltaMemStoresOp(55a6bbbf78f04ba08e9690432dc562f4) complete. Timing: real 0.064s	user 0.027s	sys 0.028s Metrics: {"bytes_written":16409900,"delete_count":0,"lbm_write_time_us":21050,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:20:33.264634  9173 maintenance_manager.cc:419] P ccfaeb148adf4e22af00fd968a98712c: Scheduling FlushDeltaMemStoresOp(55a6bbbf78f04ba08e9690432dc562f4): perf score=2.188937
I20260812 06:20:33.275725  9110 maintenance_manager.cc:643] P ccfaeb148adf4e22af00fd968a98712c: FlushDeltaMemStoresOp(55a6bbbf78f04ba08e9690432dc562f4) complete. Timing: real 0.011s	user 0.006s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4169,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:33.276208  9173 maintenance_manager.cc:419] P ccfaeb148adf4e22af00fd968a98712c: Scheduling MajorDeltaCompactionOp(55a6bbbf78f04ba08e9690432dc562f4): perf score=1.000000
I20260812 06:20:33.452351  9110 maintenance_manager.cc:643] P ccfaeb148adf4e22af00fd968a98712c: MajorDeltaCompactionOp(55a6bbbf78f04ba08e9690432dc562f4) complete. Timing: real 0.176s	user 0.131s	sys 0.044s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774687,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":168,"lbm_read_time_us":13343,"lbm_reads_lt_1ms":572,"lbm_write_time_us":29504,"lbm_writes_lt_1ms":543,"mutex_wait_us":23,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":48000,"update_count":2500}
I20260812 06:20:33.452847  9173 maintenance_manager.cc:419] P ccfaeb148adf4e22af00fd968a98712c: Scheduling FlushDeltaMemStoresOp(55a6bbbf78f04ba08e9690432dc562f4): perf score=14.095187
I20260812 06:20:33.508204  9110 maintenance_manager.cc:643] P ccfaeb148adf4e22af00fd968a98712c: FlushDeltaMemStoresOp(55a6bbbf78f04ba08e9690432dc562f4) complete. Timing: real 0.055s	user 0.036s	sys 0.012s Metrics: {"bytes_written":16409903,"delete_count":0,"lbm_write_time_us":22240,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:20:33.508703  9173 maintenance_manager.cc:419] P ccfaeb148adf4e22af00fd968a98712c: Scheduling FlushDeltaMemStoresOp(55a6bbbf78f04ba08e9690432dc562f4): perf score=2.188937
I20260812 06:20:33.520234  9110 maintenance_manager.cc:643] P ccfaeb148adf4e22af00fd968a98712c: FlushDeltaMemStoresOp(55a6bbbf78f04ba08e9690432dc562f4) complete. Timing: real 0.011s	user 0.010s	sys 0.000s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4104,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:33.520735  9173 maintenance_manager.cc:419] P ccfaeb148adf4e22af00fd968a98712c: Scheduling MajorDeltaCompactionOp(55a6bbbf78f04ba08e9690432dc562f4): perf score=1.000000
I20260812 06:20:33.723342  9110 maintenance_manager.cc:643] P ccfaeb148adf4e22af00fd968a98712c: MajorDeltaCompactionOp(55a6bbbf78f04ba08e9690432dc562f4) complete. Timing: real 0.202s	user 0.135s	sys 0.052s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774689,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":274,"lbm_read_time_us":10913,"lbm_reads_lt_1ms":572,"lbm_write_time_us":33560,"lbm_writes_lt_1ms":543,"mutex_wait_us":57,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":896,"update_count":2500}
I20260812 06:20:33.724136  9173 maintenance_manager.cc:419] P ccfaeb148adf4e22af00fd968a98712c: Scheduling FlushDeltaMemStoresOp(55a6bbbf78f04ba08e9690432dc562f4): perf score=14.095187
I20260812 06:20:33.773602  9110 maintenance_manager.cc:643] P ccfaeb148adf4e22af00fd968a98712c: FlushDeltaMemStoresOp(55a6bbbf78f04ba08e9690432dc562f4) complete. Timing: real 0.049s	user 0.021s	sys 0.023s Metrics: {"bytes_written":16409900,"delete_count":0,"lbm_write_time_us":20656,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:20:33.774097  9173 maintenance_manager.cc:419] P ccfaeb148adf4e22af00fd968a98712c: Scheduling FlushDeltaMemStoresOp(55a6bbbf78f04ba08e9690432dc562f4): perf score=2.188937
I20260812 06:20:33.785740  9110 maintenance_manager.cc:643] P ccfaeb148adf4e22af00fd968a98712c: FlushDeltaMemStoresOp(55a6bbbf78f04ba08e9690432dc562f4) complete. Timing: real 0.011s	user 0.002s	sys 0.007s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4373,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:33.786405  9173 maintenance_manager.cc:419] P ccfaeb148adf4e22af00fd968a98712c: Scheduling MajorDeltaCompactionOp(55a6bbbf78f04ba08e9690432dc562f4): perf score=1.000000
I20260812 06:20:33.942569  9110 maintenance_manager.cc:643] P ccfaeb148adf4e22af00fd968a98712c: MajorDeltaCompactionOp(55a6bbbf78f04ba08e9690432dc562f4) complete. Timing: real 0.156s	user 0.108s	sys 0.044s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774687,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":341,"lbm_read_time_us":10020,"lbm_reads_lt_1ms":572,"lbm_write_time_us":32605,"lbm_writes_lt_1ms":543,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":24960,"update_count":2500}
I20260812 06:20:33.943359  9173 maintenance_manager.cc:419] P ccfaeb148adf4e22af00fd968a98712c: Scheduling FlushDeltaMemStoresOp(55a6bbbf78f04ba08e9690432dc562f4): perf score=11.118625
I20260812 06:20:33.981839  9110 maintenance_manager.cc:643] P ccfaeb148adf4e22af00fd968a98712c: FlushDeltaMemStoresOp(55a6bbbf78f04ba08e9690432dc562f4) complete. Timing: real 0.038s	user 0.022s	sys 0.013s Metrics: {"bytes_written":12717734,"delete_count":0,"lbm_write_time_us":17004,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:20:33.982430  9173 maintenance_manager.cc:419] P ccfaeb148adf4e22af00fd968a98712c: Scheduling FlushDeltaMemStoresOp(55a6bbbf78f04ba08e9690432dc562f4): perf score=2.188937
I20260812 06:20:34.001323  9110 maintenance_manager.cc:643] P ccfaeb148adf4e22af00fd968a98712c: FlushDeltaMemStoresOp(55a6bbbf78f04ba08e9690432dc562f4) complete. Timing: real 0.019s	user 0.010s	sys 0.003s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":5715,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:20:34.001955  9173 maintenance_manager.cc:419] P ccfaeb148adf4e22af00fd968a98712c: Scheduling MajorDeltaCompactionOp(55a6bbbf78f04ba08e9690432dc562f4): perf score=1.000000
I20260812 06:20:34.125226  9110 maintenance_manager.cc:643] P ccfaeb148adf4e22af00fd968a98712c: MajorDeltaCompactionOp(55a6bbbf78f04ba08e9690432dc562f4) complete. Timing: real 0.123s	user 0.090s	sys 0.031s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672267,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":477,"lbm_read_time_us":7819,"lbm_reads_lt_1ms":464,"lbm_write_time_us":24061,"lbm_writes_lt_1ms":443,"mutex_wait_us":2,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":5760,"update_count":2000}
I20260812 06:20:34.126017  9173 maintenance_manager.cc:419] P ccfaeb148adf4e22af00fd968a98712c: Scheduling FlushDeltaMemStoresOp(55a6bbbf78f04ba08e9690432dc562f4): perf score=10.126437
I20260812 06:20:34.165146  9110 maintenance_manager.cc:643] P ccfaeb148adf4e22af00fd968a98712c: FlushDeltaMemStoresOp(55a6bbbf78f04ba08e9690432dc562f4) complete. Timing: real 0.039s	user 0.035s	sys 0.000s Metrics: {"bytes_written":12307492,"delete_count":0,"lbm_write_time_us":15735,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:20:34.165724  9173 maintenance_manager.cc:419] P ccfaeb148adf4e22af00fd968a98712c: Scheduling FlushDeltaMemStoresOp(55a6bbbf78f04ba08e9690432dc562f4): perf score=2.188937
I20260812 06:20:34.176630  9110 maintenance_manager.cc:643] P ccfaeb148adf4e22af00fd968a98712c: FlushDeltaMemStoresOp(55a6bbbf78f04ba08e9690432dc562f4) complete. Timing: real 0.011s	user 0.006s	sys 0.003s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4100,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:34.177382  9173 maintenance_manager.cc:419] P ccfaeb148adf4e22af00fd968a98712c: Scheduling FlushMRSOp(55a6bbbf78f04ba08e9690432dc562f4): perf score=1.000000
I20260812 06:20:34.210837  9110 maintenance_manager.cc:643] P ccfaeb148adf4e22af00fd968a98712c: FlushMRSOp(55a6bbbf78f04ba08e9690432dc562f4) complete. Timing: real 0.033s	user 0.028s	sys 0.003s Metrics: {"bytes_written":1275447,"cfile_init":1,"dirs.queue_time_us":68,"dirs.run_cpu_time_us":224,"dirs.run_wall_time_us":1403,"drs_written":1,"lbm_read_time_us":69,"lbm_reads_lt_1ms":4,"lbm_write_time_us":2154,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":31}
I20260812 06:20:34.211580  9173 maintenance_manager.cc:419] P ccfaeb148adf4e22af00fd968a98712c: Scheduling LogGCOp(55a6bbbf78f04ba08e9690432dc562f4): free 124710562 bytes of WAL
I20260812 06:20:34.211820  9110 log_reader.cc:385] T 55a6bbbf78f04ba08e9690432dc562f4: removed 12 log segments from log reader
I20260812 06:20:34.211891  9110 log.cc:1079] T 55a6bbbf78f04ba08e9690432dc562f4 P ccfaeb148adf4e22af00fd968a98712c: Deleting log segment in path: /tmp/dist-test-taskJpMpSi/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515628656676-8997-0/minicluster-data/ts-0-root/wals/55a6bbbf78f04ba08e9690432dc562f4/wal-000000028 (ops 137-141)
I20260812 06:20:34.211951  9110 log.cc:1079] T 55a6bbbf78f04ba08e9690432dc562f4 P ccfaeb148adf4e22af00fd968a98712c: Deleting log segment in path: /tmp/dist-test-taskJpMpSi/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515628656676-8997-0/minicluster-data/ts-0-root/wals/55a6bbbf78f04ba08e9690432dc562f4/wal-000000029 (ops 142-146)
I20260812 06:20:34.212005  9110 log.cc:1079] T 55a6bbbf78f04ba08e9690432dc562f4 P ccfaeb148adf4e22af00fd968a98712c: Deleting log segment in path: /tmp/dist-test-taskJpMpSi/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515628656676-8997-0/minicluster-data/ts-0-root/wals/55a6bbbf78f04ba08e9690432dc562f4/wal-000000030 (ops 147-151)
I20260812 06:20:34.212049  9110 log.cc:1079] T 55a6bbbf78f04ba08e9690432dc562f4 P ccfaeb148adf4e22af00fd968a98712c: Deleting log segment in path: /tmp/dist-test-taskJpMpSi/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515628656676-8997-0/minicluster-data/ts-0-root/wals/55a6bbbf78f04ba08e9690432dc562f4/wal-000000031 (ops 152-156)
I20260812 06:20:34.212090  9110 log.cc:1079] T 55a6bbbf78f04ba08e9690432dc562f4 P ccfaeb148adf4e22af00fd968a98712c: Deleting log segment in path: /tmp/dist-test-taskJpMpSi/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515628656676-8997-0/minicluster-data/ts-0-root/wals/55a6bbbf78f04ba08e9690432dc562f4/wal-000000032 (ops 157-161)
I20260812 06:20:34.212131  9110 log.cc:1079] T 55a6bbbf78f04ba08e9690432dc562f4 P ccfaeb148adf4e22af00fd968a98712c: Deleting log segment in path: /tmp/dist-test-taskJpMpSi/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515628656676-8997-0/minicluster-data/ts-0-root/wals/55a6bbbf78f04ba08e9690432dc562f4/wal-000000033 (ops 162-166)
I20260812 06:20:34.212170  9110 log.cc:1079] T 55a6bbbf78f04ba08e9690432dc562f4 P ccfaeb148adf4e22af00fd968a98712c: Deleting log segment in path: /tmp/dist-test-taskJpMpSi/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515628656676-8997-0/minicluster-data/ts-0-root/wals/55a6bbbf78f04ba08e9690432dc562f4/wal-000000034 (ops 167-171)
I20260812 06:20:34.212209  9110 log.cc:1079] T 55a6bbbf78f04ba08e9690432dc562f4 P ccfaeb148adf4e22af00fd968a98712c: Deleting log segment in path: /tmp/dist-test-taskJpMpSi/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515628656676-8997-0/minicluster-data/ts-0-root/wals/55a6bbbf78f04ba08e9690432dc562f4/wal-000000035 (ops 172-176)
I20260812 06:20:34.212250  9110 log.cc:1079] T 55a6bbbf78f04ba08e9690432dc562f4 P ccfaeb148adf4e22af00fd968a98712c: Deleting log segment in path: /tmp/dist-test-taskJpMpSi/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515628656676-8997-0/minicluster-data/ts-0-root/wals/55a6bbbf78f04ba08e9690432dc562f4/wal-000000036 (ops 177-181)
I20260812 06:20:34.212291  9110 log.cc:1079] T 55a6bbbf78f04ba08e9690432dc562f4 P ccfaeb148adf4e22af00fd968a98712c: Deleting log segment in path: /tmp/dist-test-taskJpMpSi/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515628656676-8997-0/minicluster-data/ts-0-root/wals/55a6bbbf78f04ba08e9690432dc562f4/wal-000000037 (ops 182-186)
I20260812 06:20:34.212330  9110 log.cc:1079] T 55a6bbbf78f04ba08e9690432dc562f4 P ccfaeb148adf4e22af00fd968a98712c: Deleting log segment in path: /tmp/dist-test-taskJpMpSi/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515628656676-8997-0/minicluster-data/ts-0-root/wals/55a6bbbf78f04ba08e9690432dc562f4/wal-000000038 (ops 187-191)
I20260812 06:20:34.212370  9110 log.cc:1079] T 55a6bbbf78f04ba08e9690432dc562f4 P ccfaeb148adf4e22af00fd968a98712c: Deleting log segment in path: /tmp/dist-test-taskJpMpSi/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515628656676-8997-0/minicluster-data/ts-0-root/wals/55a6bbbf78f04ba08e9690432dc562f4/wal-000000039 (ops 192-196)
I20260812 06:20:34.240366  9110 maintenance_manager.cc:643] P ccfaeb148adf4e22af00fd968a98712c: LogGCOp(55a6bbbf78f04ba08e9690432dc562f4) complete. Timing: real 0.029s	user 0.000s	sys 0.027s Metrics: {}
I20260812 06:20:34.240839  9173 maintenance_manager.cc:419] P ccfaeb148adf4e22af00fd968a98712c: Scheduling UndoDeltaBlockGCOp(55a6bbbf78f04ba08e9690432dc562f4): 483 bytes on disk
I20260812 06:20:34.241312  9110 maintenance_manager.cc:643] P ccfaeb148adf4e22af00fd968a98712c: UndoDeltaBlockGCOp(55a6bbbf78f04ba08e9690432dc562f4) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":67,"lbm_reads_lt_1ms":4}
I20260812 06:20:34.241953  9173 maintenance_manager.cc:419] P ccfaeb148adf4e22af00fd968a98712c: Scheduling FlushDeltaMemStoresOp(55a6bbbf78f04ba08e9690432dc562f4): perf score=3.181125
I20260812 06:20:34.258215  8997 heavy-update-compaction-itest.cc:229] Time spent updating: real 5.352s	user 1.906s	sys 0.131s
I20260812 06:20:34.259876  9110 maintenance_manager.cc:643] P ccfaeb148adf4e22af00fd968a98712c: FlushDeltaMemStoresOp(55a6bbbf78f04ba08e9690432dc562f4) complete. Timing: real 0.018s	user 0.012s	sys 0.005s Metrics: {"bytes_written":4512900,"delete_count":0,"lbm_write_time_us":7330,"lbm_writes_lt_1ms":113,"reinsert_count":0,"update_count":550}
I20260812 06:20:34.260290  9173 maintenance_manager.cc:419] P ccfaeb148adf4e22af00fd968a98712c: Scheduling FlushDeltaMemStoresOp(55a6bbbf78f04ba08e9690432dc562f4): perf score=2.188937
I20260812 06:20:34.269263  9110 maintenance_manager.cc:643] P ccfaeb148adf4e22af00fd968a98712c: FlushDeltaMemStoresOp(55a6bbbf78f04ba08e9690432dc562f4) complete. Timing: real 0.009s	user 0.007s	sys 0.001s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3819,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:20:34.269637  9173 maintenance_manager.cc:419] P ccfaeb148adf4e22af00fd968a98712c: Scheduling MajorDeltaCompactionOp(55a6bbbf78f04ba08e9690432dc562f4): perf score=1.000000
I20260812 06:20:34.322899  8997 heavy-update-compaction-itest.cc:265] Time spent scanning: real 0.064s	user 0.001s	sys 0.001s
I20260812 06:20:34.323724  8997 tablet_server.cc:179] TabletServer@127.8.201.65:0 shutting down...
I20260812 06:20:34.409116  9110 maintenance_manager.cc:643] P ccfaeb148adf4e22af00fd968a98712c: MajorDeltaCompactionOp(55a6bbbf78f04ba08e9690432dc562f4) complete. Timing: real 0.139s	user 0.088s	sys 0.052s Metrics: {"cfile_cache_hit":297,"cfile_cache_hit_bytes":12064285,"cfile_cache_miss":337,"cfile_cache_miss_bytes":16813043,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":280,"lbm_read_time_us":6460,"lbm_reads_lt_1ms":369,"lbm_write_time_us":30904,"lbm_writes_lt_1ms":643,"mutex_wait_us":79,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":88320,"thread_start_us":79,"threads_started":1,"update_count":3000}
I20260812 06:20:34.410751  8997 ts_tablet_manager.cc:1507] Shutting down tablet manager...
I20260812 06:20:34.411280  8997 tablet_replica.cc:333] T 55a6bbbf78f04ba08e9690432dc562f4 P ccfaeb148adf4e22af00fd968a98712c: stopping tablet replica
I20260812 06:20:34.411588  8997 raft_consensus.cc:2243] T 55a6bbbf78f04ba08e9690432dc562f4 P ccfaeb148adf4e22af00fd968a98712c [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:20:34.411886  8997 raft_consensus.cc:2272] T 55a6bbbf78f04ba08e9690432dc562f4 P ccfaeb148adf4e22af00fd968a98712c [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:20:34.427505  8997 tablet_server.cc:196] TabletServer@127.8.201.65:0 shutdown complete.
I20260812 06:20:34.466270  8997 master.cc:562] Master@127.8.201.126:42307 shutting down...
I20260812 06:20:34.469863  8997 raft_consensus.cc:2243] T 00000000000000000000000000000000 P 2793652cd1ed48aa81de8b4230664bd5 [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:20:34.470024  8997 raft_consensus.cc:2272] T 00000000000000000000000000000000 P 2793652cd1ed48aa81de8b4230664bd5 [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:20:34.470077  8997 tablet_replica.cc:333] T 00000000000000000000000000000000 P 2793652cd1ed48aa81de8b4230664bd5: stopping tablet replica
I20260812 06:20:34.482371  8997 master.cc:584] Master@127.8.201.126:42307 shutdown complete.
[       OK ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/0 (5902 ms)
[ RUN      ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/1
I20260812 06:20:34.569944  8997 internal_mini_cluster.cc:156] Creating distributed mini masters. Addrs: 127.8.201.126:35057
I20260812 06:20:34.570304  8997 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:20:34.572736  9209 instance_detector.cc:116] could not retrieve OpenStack instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:20:34.572839  8997 server_base.cc:1061] running on GCE node
W20260812 06:20:34.572880  9206 instance_detector.cc:116] could not retrieve AWS instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:20:34.573033  9207 instance_detector.cc:116] could not retrieve Azure instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:20:34.573247  8997 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:20:34.573307  8997 system_unsync_time.cc:38] NTP support is disabled. Clock error bounds will not be accurate. This configuration is not suitable for distributed clusters.
I20260812 06:20:34.573339  8997 hybrid_clock.cc:648] HybridClock initialized: now 1786515634573339 us; error 0 us; skew 500 ppm
I20260812 06:20:34.574856  8997 webserver.cc:533] Webserver started at http://127.8.201.126:38385/ using document root <none> and password file <none>
I20260812 06:20:34.575073  8997 fs_manager.cc:362] Metadata directory not provided
I20260812 06:20:34.575141  8997 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:20:34.575220  8997 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:20:34.575610  8997 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskJpMpSi/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515628656676-8997-0/minicluster-data/master-0-root/instance:
uuid: "414b0d2348ce449697ac4b4854d282e4"
format_stamp: "Formatted at 2026-08-12 06:20:34 on dist-test-slave-w206"
I20260812 06:20:34.577122  8997 fs_manager.cc:696] Time spent creating directory manager: real 0.001s	user 0.000s	sys 0.002s
I20260812 06:20:34.578071  9215 log_block_manager.cc:4127] Time spent loading block containers with low live blocks: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:20:34.578341  8997 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.000s	sys 0.001s
I20260812 06:20:34.578446  8997 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskJpMpSi/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515628656676-8997-0/minicluster-data/master-0-root
uuid: "414b0d2348ce449697ac4b4854d282e4"
format_stamp: "Formatted at 2026-08-12 06:20:34 on dist-test-slave-w206"
I20260812 06:20:34.578524  8997 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskJpMpSi/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515628656676-8997-0/minicluster-data/master-0-root
metadata directory: /tmp/dist-test-taskJpMpSi/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515628656676-8997-0/minicluster-data/master-0-root
1 data directories: /tmp/dist-test-taskJpMpSi/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515628656676-8997-0/minicluster-data/master-0-root/data
Total live blocks: 0
Total live bytes: 0
Total live bytes (after alignment): 0
Total number of LBM containers: 0 (0 full)
Did not check for missing blocks
Did not check for orphaned blocks
Total full LBM containers with extra space: 0 (0 repaired)
Total full LBM container extra space in bytes: 0 (0 repaired)
Total incomplete LBM containers: 0 (0 repaired)
Total LBM partial records: 0 (0 repaired)
Total corrupted LBM metadata records in RocksDB: 0 (0 repaired)
I20260812 06:20:34.587705  8997 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:20:34.588061  8997 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:20:34.592509  8997 rpc_server.cc:307] RPC server started. Bound to: 127.8.201.126:35057
I20260812 06:20:34.598197  9272 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet 00000000000000000000000000000000. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:20:34.599815  9271 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.8.201.126:35057 every 8 connection(s)
I20260812 06:20:34.604836  9272 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P 414b0d2348ce449697ac4b4854d282e4: Bootstrap starting.
I20260812 06:20:34.605659  9272 tablet_bootstrap.cc:654] T 00000000000000000000000000000000 P 414b0d2348ce449697ac4b4854d282e4: Neither blocks nor log segments found. Creating new log.
I20260812 06:20:34.606695  9272 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P 414b0d2348ce449697ac4b4854d282e4: No bootstrap required, opened a new log
I20260812 06:20:34.607146  9272 raft_consensus.cc:359] T 00000000000000000000000000000000 P 414b0d2348ce449697ac4b4854d282e4 [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "414b0d2348ce449697ac4b4854d282e4" member_type: VOTER }
I20260812 06:20:34.607231  9272 raft_consensus.cc:385] T 00000000000000000000000000000000 P 414b0d2348ce449697ac4b4854d282e4 [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:20:34.607254  9272 raft_consensus.cc:740] T 00000000000000000000000000000000 P 414b0d2348ce449697ac4b4854d282e4 [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: 414b0d2348ce449697ac4b4854d282e4, State: Initialized, Role: FOLLOWER
I20260812 06:20:34.607404  9272 consensus_queue.cc:260] T 00000000000000000000000000000000 P 414b0d2348ce449697ac4b4854d282e4 [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: "414b0d2348ce449697ac4b4854d282e4" member_type: VOTER }
I20260812 06:20:34.607489  9272 raft_consensus.cc:399] T 00000000000000000000000000000000 P 414b0d2348ce449697ac4b4854d282e4 [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:20:34.607542  9272 raft_consensus.cc:493] T 00000000000000000000000000000000 P 414b0d2348ce449697ac4b4854d282e4 [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:20:34.607604  9272 raft_consensus.cc:3060] T 00000000000000000000000000000000 P 414b0d2348ce449697ac4b4854d282e4 [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:20:34.608296  9272 raft_consensus.cc:515] T 00000000000000000000000000000000 P 414b0d2348ce449697ac4b4854d282e4 [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "414b0d2348ce449697ac4b4854d282e4" member_type: VOTER }
I20260812 06:20:34.608449  9272 leader_election.cc:304] T 00000000000000000000000000000000 P 414b0d2348ce449697ac4b4854d282e4 [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: 414b0d2348ce449697ac4b4854d282e4; no voters: 
I20260812 06:20:34.608649  9272 leader_election.cc:290] T 00000000000000000000000000000000 P 414b0d2348ce449697ac4b4854d282e4 [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:20:34.608786  9276 raft_consensus.cc:2804] T 00000000000000000000000000000000 P 414b0d2348ce449697ac4b4854d282e4 [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:20:34.608986  9276 raft_consensus.cc:697] T 00000000000000000000000000000000 P 414b0d2348ce449697ac4b4854d282e4 [term 1 LEADER]: Becoming Leader. State: Replica: 414b0d2348ce449697ac4b4854d282e4, State: Running, Role: LEADER
I20260812 06:20:34.609068  9272 sys_catalog.cc:565] T 00000000000000000000000000000000 P 414b0d2348ce449697ac4b4854d282e4 [sys.catalog]: configured and running, proceeding with master startup.
I20260812 06:20:34.609128  9276 consensus_queue.cc:237] T 00000000000000000000000000000000 P 414b0d2348ce449697ac4b4854d282e4 [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: "414b0d2348ce449697ac4b4854d282e4" member_type: VOTER }
I20260812 06:20:34.609511  9277 sys_catalog.cc:455] T 00000000000000000000000000000000 P 414b0d2348ce449697ac4b4854d282e4 [sys.catalog]: SysCatalogTable state changed. Reason: RaftConsensus started. Latest consensus state: current_term: 1 leader_uuid: "414b0d2348ce449697ac4b4854d282e4" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "414b0d2348ce449697ac4b4854d282e4" member_type: VOTER } }
I20260812 06:20:34.609529  9278 sys_catalog.cc:455] T 00000000000000000000000000000000 P 414b0d2348ce449697ac4b4854d282e4 [sys.catalog]: SysCatalogTable state changed. Reason: New leader 414b0d2348ce449697ac4b4854d282e4. Latest consensus state: current_term: 1 leader_uuid: "414b0d2348ce449697ac4b4854d282e4" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "414b0d2348ce449697ac4b4854d282e4" member_type: VOTER } }
I20260812 06:20:34.609611  9277 sys_catalog.cc:458] T 00000000000000000000000000000000 P 414b0d2348ce449697ac4b4854d282e4 [sys.catalog]: This master's current role is: LEADER
I20260812 06:20:34.609632  9278 sys_catalog.cc:458] T 00000000000000000000000000000000 P 414b0d2348ce449697ac4b4854d282e4 [sys.catalog]: This master's current role is: LEADER
I20260812 06:20:34.609871  9280 catalog_manager.cc:1511] Loading table and tablet metadata into memory...
I20260812 06:20:34.610805  9280 catalog_manager.cc:1520] Initializing Kudu cluster ID...
I20260812 06:20:34.611043  8997 internal_mini_cluster.cc:184] Waiting to initialize catalog manager on master 0
I20260812 06:20:34.612602  9280 catalog_manager.cc:1383] Generated new cluster ID: f2a8a6b4b3a042e8894bd86a702773c2
I20260812 06:20:34.612670  9280 catalog_manager.cc:1531] Initializing Kudu internal certificate authority...
I20260812 06:20:34.624040  9280 catalog_manager.cc:1406] Generated new certificate authority record
I20260812 06:20:34.624641  9280 catalog_manager.cc:1540] Loading token signing keys...
I20260812 06:20:34.636929  9280 catalog_manager.cc:6092] T 00000000000000000000000000000000 P 414b0d2348ce449697ac4b4854d282e4: Generated new TSK 0
I20260812 06:20:34.637123  9280 catalog_manager.cc:1550] Initializing in-progress tserver states...
I20260812 06:20:34.643344  8997 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:20:34.645246  9295 instance_detector.cc:116] could not retrieve Azure instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:20:34.645311  9294 instance_detector.cc:116] could not retrieve AWS instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:20:34.645414  9298 instance_detector.cc:116] could not retrieve OpenStack instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:20:34.645661  8997 server_base.cc:1061] running on GCE node
I20260812 06:20:34.645814  8997 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:20:34.645859  8997 system_unsync_time.cc:38] NTP support is disabled. Clock error bounds will not be accurate. This configuration is not suitable for distributed clusters.
I20260812 06:20:34.645875  8997 hybrid_clock.cc:648] HybridClock initialized: now 1786515634645875 us; error 0 us; skew 500 ppm
I20260812 06:20:34.646787  8997 webserver.cc:533] Webserver started at http://127.8.201.65:40513/ using document root <none> and password file <none>
I20260812 06:20:34.646962  8997 fs_manager.cc:362] Metadata directory not provided
I20260812 06:20:34.647060  8997 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:20:34.647140  8997 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:20:34.647547  8997 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskJpMpSi/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515628656676-8997-0/minicluster-data/ts-0-root/instance:
uuid: "76337248a092430683274fa9f98a4b00"
format_stamp: "Formatted at 2026-08-12 06:20:34 on dist-test-slave-w206"
I20260812 06:20:34.649084  8997 fs_manager.cc:696] Time spent creating directory manager: real 0.001s	user 0.000s	sys 0.002s
I20260812 06:20:34.650167  9303 log_block_manager.cc:4127] Time spent loading block containers with low live blocks: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:20:34.650449  8997 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.000s	sys 0.001s
I20260812 06:20:34.650554  8997 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskJpMpSi/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515628656676-8997-0/minicluster-data/ts-0-root
uuid: "76337248a092430683274fa9f98a4b00"
format_stamp: "Formatted at 2026-08-12 06:20:34 on dist-test-slave-w206"
I20260812 06:20:34.650648  8997 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskJpMpSi/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515628656676-8997-0/minicluster-data/ts-0-root
metadata directory: /tmp/dist-test-taskJpMpSi/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515628656676-8997-0/minicluster-data/ts-0-root
1 data directories: /tmp/dist-test-taskJpMpSi/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515628656676-8997-0/minicluster-data/ts-0-root/data
Total live blocks: 0
Total live bytes: 0
Total live bytes (after alignment): 0
Total number of LBM containers: 0 (0 full)
Did not check for missing blocks
Did not check for orphaned blocks
Total full LBM containers with extra space: 0 (0 repaired)
Total full LBM container extra space in bytes: 0 (0 repaired)
Total incomplete LBM containers: 0 (0 repaired)
Total LBM partial records: 0 (0 repaired)
Total corrupted LBM metadata records in RocksDB: 0 (0 repaired)
I20260812 06:20:34.663375  8997 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:20:34.663763  8997 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:20:34.664086  8997 txn_system_client.cc:432] TxnSystemClient initialization is disabled...
I20260812 06:20:34.664665  8997 ts_tablet_manager.cc:585] Loaded tablet metadata (0 total tablets, 0 live tablets)
I20260812 06:20:34.664728  8997 ts_tablet_manager.cc:531] Time spent load tablet metadata: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:20:34.664791  8997 ts_tablet_manager.cc:616] Registered 0 tablets
I20260812 06:20:34.664842  8997 ts_tablet_manager.cc:595] Time spent register tablets: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:20:34.669689  8997 rpc_server.cc:307] RPC server started. Bound to: 127.8.201.65:35689
I20260812 06:20:34.671595  9371 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.8.201.65:35689 every 8 connection(s)
I20260812 06:20:34.679395  9372 heartbeater.cc:344] Connected to a master server at 127.8.201.126:35057
I20260812 06:20:34.679512  9372 heartbeater.cc:461] Registering TS with master...
I20260812 06:20:34.679776  9372 heartbeater.cc:507] Master 127.8.201.126:35057 requested a full tablet report, sending...
I20260812 06:20:34.680423  9234 ts_manager.cc:194] Registered new tserver with Master: 76337248a092430683274fa9f98a4b00 (127.8.201.65:35689)
I20260812 06:20:34.680866  8997 internal_mini_cluster.cc:371] 1 TS(s) registered with all masters after 0.009875996s
I20260812 06:20:34.681187  9234 master_service.cc:502] Signed X509 certificate for tserver {username='slave'} at 127.0.0.1:41288
I20260812 06:20:34.687940  9234 catalog_manager.cc:2283] Servicing CreateTable request from {username='slave'} at 127.0.0.1:41294:
name: "heavy-update-compaction-test"
schema {
  columns {
    name: "key"
    type: INT64
    is_key: true
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_a"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_b"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_c"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_d"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_e"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
}
num_replicas: 1
split_rows_range_bounds {
}
partition_schema {
  range_schema {
  }
}
I20260812 06:20:34.697530  9334 tablet_service.cc:1511] Processing CreateTablet for tablet f64082c406204b158310f4238f926047 (DEFAULT_TABLE table=heavy-update-compaction-test [id=d5483427388f47d3b2d7407a022019f3]), partition=
I20260812 06:20:34.697841  9334 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet f64082c406204b158310f4238f926047. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:20:34.699985  9386 tablet_bootstrap.cc:492] T f64082c406204b158310f4238f926047 P 76337248a092430683274fa9f98a4b00: Bootstrap starting.
I20260812 06:20:34.700824  9386 tablet_bootstrap.cc:654] T f64082c406204b158310f4238f926047 P 76337248a092430683274fa9f98a4b00: Neither blocks nor log segments found. Creating new log.
I20260812 06:20:34.701870  9386 tablet_bootstrap.cc:492] T f64082c406204b158310f4238f926047 P 76337248a092430683274fa9f98a4b00: No bootstrap required, opened a new log
I20260812 06:20:34.701954  9386 ts_tablet_manager.cc:1403] T f64082c406204b158310f4238f926047 P 76337248a092430683274fa9f98a4b00: Time spent bootstrapping tablet: real 0.002s	user 0.001s	sys 0.000s
I20260812 06:20:34.702375  9386 raft_consensus.cc:359] T f64082c406204b158310f4238f926047 P 76337248a092430683274fa9f98a4b00 [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "76337248a092430683274fa9f98a4b00" member_type: VOTER last_known_addr { host: "127.8.201.65" port: 35689 } }
I20260812 06:20:34.702497  9386 raft_consensus.cc:385] T f64082c406204b158310f4238f926047 P 76337248a092430683274fa9f98a4b00 [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:20:34.702538  9386 raft_consensus.cc:740] T f64082c406204b158310f4238f926047 P 76337248a092430683274fa9f98a4b00 [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: 76337248a092430683274fa9f98a4b00, State: Initialized, Role: FOLLOWER
I20260812 06:20:34.702703  9386 consensus_queue.cc:260] T f64082c406204b158310f4238f926047 P 76337248a092430683274fa9f98a4b00 [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: "76337248a092430683274fa9f98a4b00" member_type: VOTER last_known_addr { host: "127.8.201.65" port: 35689 } }
I20260812 06:20:34.702833  9386 raft_consensus.cc:399] T f64082c406204b158310f4238f926047 P 76337248a092430683274fa9f98a4b00 [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:20:34.702883  9386 raft_consensus.cc:493] T f64082c406204b158310f4238f926047 P 76337248a092430683274fa9f98a4b00 [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:20:34.702934  9386 raft_consensus.cc:3060] T f64082c406204b158310f4238f926047 P 76337248a092430683274fa9f98a4b00 [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:20:34.703676  9386 raft_consensus.cc:515] T f64082c406204b158310f4238f926047 P 76337248a092430683274fa9f98a4b00 [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "76337248a092430683274fa9f98a4b00" member_type: VOTER last_known_addr { host: "127.8.201.65" port: 35689 } }
I20260812 06:20:34.703791  9386 leader_election.cc:304] T f64082c406204b158310f4238f926047 P 76337248a092430683274fa9f98a4b00 [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: 76337248a092430683274fa9f98a4b00; no voters: 
I20260812 06:20:34.703941  9386 leader_election.cc:290] T f64082c406204b158310f4238f926047 P 76337248a092430683274fa9f98a4b00 [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:20:34.704105  9389 raft_consensus.cc:2804] T f64082c406204b158310f4238f926047 P 76337248a092430683274fa9f98a4b00 [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:20:34.704257  9386 ts_tablet_manager.cc:1434] T f64082c406204b158310f4238f926047 P 76337248a092430683274fa9f98a4b00: Time spent starting tablet: real 0.002s	user 0.003s	sys 0.000s
I20260812 06:20:34.704358  9372 heartbeater.cc:499] Master 127.8.201.126:35057 was elected leader, sending a full tablet report...
I20260812 06:20:34.704335  9389 raft_consensus.cc:697] T f64082c406204b158310f4238f926047 P 76337248a092430683274fa9f98a4b00 [term 1 LEADER]: Becoming Leader. State: Replica: 76337248a092430683274fa9f98a4b00, State: Running, Role: LEADER
I20260812 06:20:34.704547  9389 consensus_queue.cc:237] T f64082c406204b158310f4238f926047 P 76337248a092430683274fa9f98a4b00 [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: "76337248a092430683274fa9f98a4b00" member_type: VOTER last_known_addr { host: "127.8.201.65" port: 35689 } }
I20260812 06:20:34.705876  9234 catalog_manager.cc:5719] T f64082c406204b158310f4238f926047 P 76337248a092430683274fa9f98a4b00 reported cstate change: term changed from 0 to 1, leader changed from <none> to 76337248a092430683274fa9f98a4b00 (127.8.201.65). New cstate: current_term: 1 leader_uuid: "76337248a092430683274fa9f98a4b00" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "76337248a092430683274fa9f98a4b00" member_type: VOTER last_known_addr { host: "127.8.201.65" port: 35689 } health_report { overall_health: HEALTHY } } }
I20260812 06:20:34.765218  8997 heavy-update-compaction-itest.cc:215] Time spent inserting: real 0.052s	user 0.016s	sys 0.005s
I20260812 06:20:34.922089  9373 maintenance_manager.cc:419] P 76337248a092430683274fa9f98a4b00: Scheduling FlushMRSOp(f64082c406204b158310f4238f926047): perf score=19.054940
I20260812 06:20:35.075260  9308 maintenance_manager.cc:643] P 76337248a092430683274fa9f98a4b00: FlushMRSOp(f64082c406204b158310f4238f926047) complete. Timing: real 0.153s	user 0.102s	sys 0.051s Metrics: {"bytes_written":11897250,"cfile_init":1,"delete_count":0,"dirs.queue_time_us":54,"dirs.run_cpu_time_us":213,"dirs.run_wall_time_us":880,"drs_written":1,"lbm_read_time_us":36,"lbm_reads_lt_1ms":4,"lbm_write_time_us":38289,"lbm_writes_lt_1ms":757,"peak_mem_usage":0,"reinsert_count":0,"rows_written":105,"update_count":1450}
I20260812 06:20:35.076323  9373 maintenance_manager.cc:419] P 76337248a092430683274fa9f98a4b00: Scheduling LogGCOp(f64082c406204b158310f4238f926047): free 20743880 bytes of WAL
I20260812 06:20:35.076634  9308 log_reader.cc:385] T f64082c406204b158310f4238f926047: removed 2 log segments from log reader
I20260812 06:20:35.076727  9308 log.cc:1079] T f64082c406204b158310f4238f926047 P 76337248a092430683274fa9f98a4b00: Deleting log segment in path: /tmp/dist-test-taskJpMpSi/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515628656676-8997-0/minicluster-data/ts-0-root/wals/f64082c406204b158310f4238f926047/wal-000000001 (ops 1-6)
I20260812 06:20:35.076797  9308 log.cc:1079] T f64082c406204b158310f4238f926047 P 76337248a092430683274fa9f98a4b00: Deleting log segment in path: /tmp/dist-test-taskJpMpSi/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515628656676-8997-0/minicluster-data/ts-0-root/wals/f64082c406204b158310f4238f926047/wal-000000002 (ops 7-11)
I20260812 06:20:35.083443  9308 maintenance_manager.cc:643] P 76337248a092430683274fa9f98a4b00: LogGCOp(f64082c406204b158310f4238f926047) complete. Timing: real 0.007s	user 0.000s	sys 0.006s Metrics: {}
I20260812 06:20:35.083999  9373 maintenance_manager.cc:419] P 76337248a092430683274fa9f98a4b00: Scheduling FlushDeltaMemStoresOp(f64082c406204b158310f4238f926047): perf score=2.188937
I20260812 06:20:35.101959  9308 maintenance_manager.cc:643] P 76337248a092430683274fa9f98a4b00: FlushDeltaMemStoresOp(f64082c406204b158310f4238f926047) complete. Timing: real 0.018s	user 0.008s	sys 0.005s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6230,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:35.102370  9373 maintenance_manager.cc:419] P 76337248a092430683274fa9f98a4b00: Scheduling UndoDeltaBlockGCOp(f64082c406204b158310f4238f926047): 16821646 bytes on disk
I20260812 06:20:35.102749  9308 maintenance_manager.cc:643] P 76337248a092430683274fa9f98a4b00: UndoDeltaBlockGCOp(f64082c406204b158310f4238f926047) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":51,"lbm_reads_lt_1ms":4}
I20260812 06:20:35.103183  9373 maintenance_manager.cc:419] P 76337248a092430683274fa9f98a4b00: Scheduling MajorDeltaCompactionOp(f64082c406204b158310f4238f926047): perf score=1.000000
I20260812 06:20:35.248831  9308 maintenance_manager.cc:643] P 76337248a092430683274fa9f98a4b00: MajorDeltaCompactionOp(f64082c406204b158310f4238f926047) complete. Timing: real 0.145s	user 0.113s	sys 0.028s Metrics: {"cfile_cache_miss":422,"cfile_cache_miss_bytes":20303032,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":635,"lbm_read_time_us":12304,"lbm_reads_lt_1ms":454,"lbm_write_time_us":24458,"lbm_writes_lt_1ms":433,"mutex_wait_us":19,"peak_mem_usage":49238594,"reinsert_count":0,"spinlock_wait_cycles":6400,"thread_start_us":367,"threads_started":5,"update_count":1950}
I20260812 06:20:35.249579  9373 maintenance_manager.cc:419] P 76337248a092430683274fa9f98a4b00: Scheduling FlushDeltaMemStoresOp(f64082c406204b158310f4238f926047): perf score=11.118625
I20260812 06:20:35.293550  9308 maintenance_manager.cc:643] P 76337248a092430683274fa9f98a4b00: FlushDeltaMemStoresOp(f64082c406204b158310f4238f926047) complete. Timing: real 0.044s	user 0.017s	sys 0.024s Metrics: {"bytes_written":12717735,"delete_count":0,"lbm_write_time_us":13959,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:20:35.294147  9373 maintenance_manager.cc:419] P 76337248a092430683274fa9f98a4b00: Scheduling FlushDeltaMemStoresOp(f64082c406204b158310f4238f926047): perf score=2.188937
I20260812 06:20:35.312008  9308 maintenance_manager.cc:643] P 76337248a092430683274fa9f98a4b00: FlushDeltaMemStoresOp(f64082c406204b158310f4238f926047) complete. Timing: real 0.018s	user 0.002s	sys 0.009s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":4444,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:20:35.312551  9373 maintenance_manager.cc:419] P 76337248a092430683274fa9f98a4b00: Scheduling MajorDeltaCompactionOp(f64082c406204b158310f4238f926047): perf score=1.000000
I20260812 06:20:35.477703  9308 maintenance_manager.cc:643] P 76337248a092430683274fa9f98a4b00: MajorDeltaCompactionOp(f64082c406204b158310f4238f926047) complete. Timing: real 0.165s	user 0.099s	sys 0.065s 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":1213,"lbm_read_time_us":12548,"lbm_reads_lt_1ms":464,"lbm_write_time_us":25244,"lbm_writes_lt_1ms":443,"mutex_wait_us":40,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":3456,"update_count":2000}
I20260812 06:20:35.478652  9373 maintenance_manager.cc:419] P 76337248a092430683274fa9f98a4b00: Scheduling FlushDeltaMemStoresOp(f64082c406204b158310f4238f926047): perf score=14.095187
I20260812 06:20:35.531138  9308 maintenance_manager.cc:643] P 76337248a092430683274fa9f98a4b00: FlushDeltaMemStoresOp(f64082c406204b158310f4238f926047) complete. Timing: real 0.052s	user 0.041s	sys 0.011s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":23518,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:20:35.531652  9373 maintenance_manager.cc:419] P 76337248a092430683274fa9f98a4b00: Scheduling FlushDeltaMemStoresOp(f64082c406204b158310f4238f926047): perf score=2.188937
I20260812 06:20:35.572072  9308 maintenance_manager.cc:643] P 76337248a092430683274fa9f98a4b00: FlushDeltaMemStoresOp(f64082c406204b158310f4238f926047) complete. Timing: real 0.040s	user 0.006s	sys 0.020s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":6764,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:35.572628  9373 maintenance_manager.cc:419] P 76337248a092430683274fa9f98a4b00: Scheduling FlushDeltaMemStoresOp(f64082c406204b158310f4238f926047): perf score=2.188937
I20260812 06:20:35.584535  9308 maintenance_manager.cc:643] P 76337248a092430683274fa9f98a4b00: FlushDeltaMemStoresOp(f64082c406204b158310f4238f926047) complete. Timing: real 0.012s	user 0.009s	sys 0.001s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4624,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:35.585062  9373 maintenance_manager.cc:419] P 76337248a092430683274fa9f98a4b00: Scheduling MajorDeltaCompactionOp(f64082c406204b158310f4238f926047): perf score=1.000000
I20260812 06:20:35.807361  9308 maintenance_manager.cc:643] P 76337248a092430683274fa9f98a4b00: MajorDeltaCompactionOp(f64082c406204b158310f4238f926047) complete. Timing: real 0.222s	user 0.149s	sys 0.072s Metrics: {"cfile_cache_miss":633,"cfile_cache_miss_bytes":28918213,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":2565,"lbm_read_time_us":15019,"lbm_reads_lt_1ms":673,"lbm_write_time_us":40835,"lbm_writes_lt_1ms":643,"mutex_wait_us":939,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":7424,"update_count":3000}
I20260812 06:20:35.808295  9373 maintenance_manager.cc:419] P 76337248a092430683274fa9f98a4b00: Scheduling FlushDeltaMemStoresOp(f64082c406204b158310f4238f926047): perf score=14.095187
I20260812 06:20:35.863888  9308 maintenance_manager.cc:643] P 76337248a092430683274fa9f98a4b00: FlushDeltaMemStoresOp(f64082c406204b158310f4238f926047) complete. Timing: real 0.055s	user 0.027s	sys 0.027s Metrics: {"bytes_written":16409906,"delete_count":0,"lbm_write_time_us":19814,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:20:35.864727  9373 maintenance_manager.cc:419] P 76337248a092430683274fa9f98a4b00: Scheduling FlushDeltaMemStoresOp(f64082c406204b158310f4238f926047): perf score=2.188937
I20260812 06:20:35.879669  9308 maintenance_manager.cc:643] P 76337248a092430683274fa9f98a4b00: FlushDeltaMemStoresOp(f64082c406204b158310f4238f926047) complete. Timing: real 0.015s	user 0.010s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5869,"lbm_writes_lt_1ms":103,"reinsert_count":0,"spinlock_wait_cycles":1408,"update_count":500}
I20260812 06:20:35.880136  9373 maintenance_manager.cc:419] P 76337248a092430683274fa9f98a4b00: Scheduling MajorDeltaCompactionOp(f64082c406204b158310f4238f926047): perf score=1.000000
I20260812 06:20:36.085060  9308 maintenance_manager.cc:643] P 76337248a092430683274fa9f98a4b00: MajorDeltaCompactionOp(f64082c406204b158310f4238f926047) complete. Timing: real 0.205s	user 0.137s	sys 0.068s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24815688,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":362,"lbm_read_time_us":15290,"lbm_reads_lt_1ms":568,"lbm_write_time_us":36013,"lbm_writes_lt_1ms":543,"mutex_wait_us":61,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":1408,"update_count":2500}
I20260812 06:20:36.085726  9373 maintenance_manager.cc:419] P 76337248a092430683274fa9f98a4b00: Scheduling FlushDeltaMemStoresOp(f64082c406204b158310f4238f926047): perf score=14.095187
I20260812 06:20:36.138150  9308 maintenance_manager.cc:643] P 76337248a092430683274fa9f98a4b00: FlushDeltaMemStoresOp(f64082c406204b158310f4238f926047) complete. Timing: real 0.052s	user 0.029s	sys 0.008s Metrics: {"bytes_written":16409903,"delete_count":0,"lbm_write_time_us":18044,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:20:36.138664  9373 maintenance_manager.cc:419] P 76337248a092430683274fa9f98a4b00: Scheduling FlushDeltaMemStoresOp(f64082c406204b158310f4238f926047): perf score=2.188937
I20260812 06:20:36.150480  9308 maintenance_manager.cc:643] P 76337248a092430683274fa9f98a4b00: FlushDeltaMemStoresOp(f64082c406204b158310f4238f926047) complete. Timing: real 0.012s	user 0.006s	sys 0.003s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4308,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:36.150923  9373 maintenance_manager.cc:419] P 76337248a092430683274fa9f98a4b00: Scheduling MajorDeltaCompactionOp(f64082c406204b158310f4238f926047): perf score=1.000000
I20260812 06:20:36.341786  9308 maintenance_manager.cc:643] P 76337248a092430683274fa9f98a4b00: MajorDeltaCompactionOp(f64082c406204b158310f4238f926047) complete. Timing: real 0.191s	user 0.147s	sys 0.039s 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":166,"lbm_read_time_us":10547,"lbm_reads_lt_1ms":572,"lbm_write_time_us":30373,"lbm_writes_lt_1ms":543,"mutex_wait_us":44,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":4096,"update_count":2500}
I20260812 06:20:36.342325  9373 maintenance_manager.cc:419] P 76337248a092430683274fa9f98a4b00: Scheduling FlushDeltaMemStoresOp(f64082c406204b158310f4238f926047): perf score=14.095187
I20260812 06:20:36.399240  9308 maintenance_manager.cc:643] P 76337248a092430683274fa9f98a4b00: FlushDeltaMemStoresOp(f64082c406204b158310f4238f926047) complete. Timing: real 0.057s	user 0.034s	sys 0.011s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":20521,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:20:36.399682  9373 maintenance_manager.cc:419] P 76337248a092430683274fa9f98a4b00: Scheduling FlushDeltaMemStoresOp(f64082c406204b158310f4238f926047): perf score=2.188937
I20260812 06:20:36.410313  9308 maintenance_manager.cc:643] P 76337248a092430683274fa9f98a4b00: FlushDeltaMemStoresOp(f64082c406204b158310f4238f926047) complete. Timing: real 0.010s	user 0.005s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4096,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:36.411098  9373 maintenance_manager.cc:419] P 76337248a092430683274fa9f98a4b00: Scheduling FlushMRSOp(f64082c406204b158310f4238f926047): perf score=1.000000
I20260812 06:20:36.442198  9308 maintenance_manager.cc:643] P 76337248a092430683274fa9f98a4b00: FlushMRSOp(f64082c406204b158310f4238f926047) complete. Timing: real 0.031s	user 0.025s	sys 0.004s Metrics: {"bytes_written":1152508,"cfile_init":1,"dirs.queue_time_us":79,"dirs.run_cpu_time_us":266,"dirs.run_wall_time_us":1464,"drs_written":1,"lbm_read_time_us":63,"lbm_reads_lt_1ms":4,"lbm_write_time_us":2219,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":28}
I20260812 06:20:36.442763  9373 maintenance_manager.cc:419] P 76337248a092430683274fa9f98a4b00: Scheduling LogGCOp(f64082c406204b158310f4238f926047): free 112692367 bytes of WAL
I20260812 06:20:36.442967  9308 log_reader.cc:385] T f64082c406204b158310f4238f926047: removed 11 log segments from log reader
I20260812 06:20:36.443065  9308 log.cc:1079] T f64082c406204b158310f4238f926047 P 76337248a092430683274fa9f98a4b00: Deleting log segment in path: /tmp/dist-test-taskJpMpSi/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515628656676-8997-0/minicluster-data/ts-0-root/wals/f64082c406204b158310f4238f926047/wal-000000003 (ops 12-16)
I20260812 06:20:36.443120  9308 log.cc:1079] T f64082c406204b158310f4238f926047 P 76337248a092430683274fa9f98a4b00: Deleting log segment in path: /tmp/dist-test-taskJpMpSi/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515628656676-8997-0/minicluster-data/ts-0-root/wals/f64082c406204b158310f4238f926047/wal-000000004 (ops 17-21)
I20260812 06:20:36.443171  9308 log.cc:1079] T f64082c406204b158310f4238f926047 P 76337248a092430683274fa9f98a4b00: Deleting log segment in path: /tmp/dist-test-taskJpMpSi/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515628656676-8997-0/minicluster-data/ts-0-root/wals/f64082c406204b158310f4238f926047/wal-000000005 (ops 22-26)
I20260812 06:20:36.443219  9308 log.cc:1079] T f64082c406204b158310f4238f926047 P 76337248a092430683274fa9f98a4b00: Deleting log segment in path: /tmp/dist-test-taskJpMpSi/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515628656676-8997-0/minicluster-data/ts-0-root/wals/f64082c406204b158310f4238f926047/wal-000000006 (ops 27-31)
I20260812 06:20:36.443256  9308 log.cc:1079] T f64082c406204b158310f4238f926047 P 76337248a092430683274fa9f98a4b00: Deleting log segment in path: /tmp/dist-test-taskJpMpSi/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515628656676-8997-0/minicluster-data/ts-0-root/wals/f64082c406204b158310f4238f926047/wal-000000007 (ops 32-36)
I20260812 06:20:36.443295  9308 log.cc:1079] T f64082c406204b158310f4238f926047 P 76337248a092430683274fa9f98a4b00: Deleting log segment in path: /tmp/dist-test-taskJpMpSi/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515628656676-8997-0/minicluster-data/ts-0-root/wals/f64082c406204b158310f4238f926047/wal-000000008 (ops 37-41)
I20260812 06:20:36.443331  9308 log.cc:1079] T f64082c406204b158310f4238f926047 P 76337248a092430683274fa9f98a4b00: Deleting log segment in path: /tmp/dist-test-taskJpMpSi/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515628656676-8997-0/minicluster-data/ts-0-root/wals/f64082c406204b158310f4238f926047/wal-000000009 (ops 42-46)
I20260812 06:20:36.443369  9308 log.cc:1079] T f64082c406204b158310f4238f926047 P 76337248a092430683274fa9f98a4b00: Deleting log segment in path: /tmp/dist-test-taskJpMpSi/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515628656676-8997-0/minicluster-data/ts-0-root/wals/f64082c406204b158310f4238f926047/wal-000000010 (ops 47-51)
I20260812 06:20:36.443406  9308 log.cc:1079] T f64082c406204b158310f4238f926047 P 76337248a092430683274fa9f98a4b00: Deleting log segment in path: /tmp/dist-test-taskJpMpSi/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515628656676-8997-0/minicluster-data/ts-0-root/wals/f64082c406204b158310f4238f926047/wal-000000011 (ops 52-56)
I20260812 06:20:36.443441  9308 log.cc:1079] T f64082c406204b158310f4238f926047 P 76337248a092430683274fa9f98a4b00: Deleting log segment in path: /tmp/dist-test-taskJpMpSi/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515628656676-8997-0/minicluster-data/ts-0-root/wals/f64082c406204b158310f4238f926047/wal-000000012 (ops 57-61)
I20260812 06:20:36.443478  9308 log.cc:1079] T f64082c406204b158310f4238f926047 P 76337248a092430683274fa9f98a4b00: Deleting log segment in path: /tmp/dist-test-taskJpMpSi/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515628656676-8997-0/minicluster-data/ts-0-root/wals/f64082c406204b158310f4238f926047/wal-000000013 (ops 62-66)
I20260812 06:20:36.471240  9308 maintenance_manager.cc:643] P 76337248a092430683274fa9f98a4b00: LogGCOp(f64082c406204b158310f4238f926047) complete. Timing: real 0.028s	user 0.001s	sys 0.027s Metrics: {}
I20260812 06:20:36.472357  9373 maintenance_manager.cc:419] P 76337248a092430683274fa9f98a4b00: Scheduling FlushDeltaMemStoresOp(f64082c406204b158310f4238f926047): perf score=2.188937
I20260812 06:20:36.485486  9308 maintenance_manager.cc:643] P 76337248a092430683274fa9f98a4b00: FlushDeltaMemStoresOp(f64082c406204b158310f4238f926047) complete. Timing: real 0.013s	user 0.010s	sys 0.001s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4151,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:36.486114  9373 maintenance_manager.cc:419] P 76337248a092430683274fa9f98a4b00: Scheduling LogGCOp(f64082c406204b158310f4238f926047): free 11564875 bytes of WAL
I20260812 06:20:36.486342  9308 log_reader.cc:385] T f64082c406204b158310f4238f926047: removed 1 log segments from log reader
I20260812 06:20:36.486406  9308 log.cc:1079] T f64082c406204b158310f4238f926047 P 76337248a092430683274fa9f98a4b00: Deleting log segment in path: /tmp/dist-test-taskJpMpSi/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515628656676-8997-0/minicluster-data/ts-0-root/wals/f64082c406204b158310f4238f926047/wal-000000014 (ops 67-70)
I20260812 06:20:36.488766  9308 maintenance_manager.cc:643] P 76337248a092430683274fa9f98a4b00: LogGCOp(f64082c406204b158310f4238f926047) complete. Timing: real 0.002s	user 0.000s	sys 0.001s Metrics: {}
I20260812 06:20:36.489069  9373 maintenance_manager.cc:419] P 76337248a092430683274fa9f98a4b00: Scheduling MajorDeltaCompactionOp(f64082c406204b158310f4238f926047): perf score=1.000000
I20260812 06:20:36.700914  9308 maintenance_manager.cc:643] P 76337248a092430683274fa9f98a4b00: MajorDeltaCompactionOp(f64082c406204b158310f4238f926047) complete. Timing: real 0.212s	user 0.138s	sys 0.069s Metrics: {"cfile_cache_miss":633,"cfile_cache_miss_bytes":28918213,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":409,"lbm_read_time_us":14498,"lbm_reads_lt_1ms":665,"lbm_write_time_us":35422,"lbm_writes_lt_1ms":643,"mutex_wait_us":23,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":11904,"thread_start_us":84,"threads_started":1,"update_count":3000}
I20260812 06:20:36.701659  9373 maintenance_manager.cc:419] P 76337248a092430683274fa9f98a4b00: Scheduling UndoDeltaBlockGCOp(f64082c406204b158310f4238f926047): 448 bytes on disk
I20260812 06:20:36.702196  9308 maintenance_manager.cc:643] P 76337248a092430683274fa9f98a4b00: UndoDeltaBlockGCOp(f64082c406204b158310f4238f926047) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":100,"lbm_reads_lt_1ms":4}
I20260812 06:20:36.702863  9373 maintenance_manager.cc:419] P 76337248a092430683274fa9f98a4b00: Scheduling FlushDeltaMemStoresOp(f64082c406204b158310f4238f926047): perf score=18.063937
I20260812 06:20:36.775456  9308 maintenance_manager.cc:643] P 76337248a092430683274fa9f98a4b00: FlushDeltaMemStoresOp(f64082c406204b158310f4238f926047) complete. Timing: real 0.072s	user 0.050s	sys 0.022s Metrics: {"bytes_written":20512316,"delete_count":0,"lbm_write_time_us":28074,"lbm_writes_lt_1ms":503,"reinsert_count":0,"update_count":2500}
I20260812 06:20:36.775956  9373 maintenance_manager.cc:419] P 76337248a092430683274fa9f98a4b00: Scheduling FlushDeltaMemStoresOp(f64082c406204b158310f4238f926047): perf score=2.188937
I20260812 06:20:36.801594  9308 maintenance_manager.cc:643] P 76337248a092430683274fa9f98a4b00: FlushDeltaMemStoresOp(f64082c406204b158310f4238f926047) complete. Timing: real 0.025s	user 0.005s	sys 0.005s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4628,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:36.802045  9373 maintenance_manager.cc:419] P 76337248a092430683274fa9f98a4b00: Scheduling FlushDeltaMemStoresOp(f64082c406204b158310f4238f926047): perf score=2.188937
I20260812 06:20:36.812611  9308 maintenance_manager.cc:643] P 76337248a092430683274fa9f98a4b00: FlushDeltaMemStoresOp(f64082c406204b158310f4238f926047) complete. Timing: real 0.010s	user 0.002s	sys 0.007s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4302,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:36.813046  9373 maintenance_manager.cc:419] P 76337248a092430683274fa9f98a4b00: Scheduling MajorDeltaCompactionOp(f64082c406204b158310f4238f926047): perf score=1.000000
I20260812 06:20:37.067183  9308 maintenance_manager.cc:643] P 76337248a092430683274fa9f98a4b00: MajorDeltaCompactionOp(f64082c406204b158310f4238f926047) complete. Timing: real 0.254s	user 0.163s	sys 0.082s Metrics: {"cfile_cache_miss":733,"cfile_cache_miss_bytes":33020629,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":296,"lbm_read_time_us":15484,"lbm_reads_lt_1ms":773,"lbm_write_time_us":41533,"lbm_writes_lt_1ms":743,"mutex_wait_us":195,"peak_mem_usage":87969044,"reinsert_count":0,"spinlock_wait_cycles":61184,"update_count":3500}
I20260812 06:20:37.068065  9373 maintenance_manager.cc:419] P 76337248a092430683274fa9f98a4b00: Scheduling FlushDeltaMemStoresOp(f64082c406204b158310f4238f926047): perf score=18.063937
I20260812 06:20:37.140082  9308 maintenance_manager.cc:643] P 76337248a092430683274fa9f98a4b00: FlushDeltaMemStoresOp(f64082c406204b158310f4238f926047) complete. Timing: real 0.072s	user 0.039s	sys 0.020s Metrics: {"bytes_written":20512316,"delete_count":0,"lbm_write_time_us":27376,"lbm_writes_lt_1ms":503,"reinsert_count":0,"update_count":2500}
I20260812 06:20:37.140558  9373 maintenance_manager.cc:419] P 76337248a092430683274fa9f98a4b00: Scheduling FlushDeltaMemStoresOp(f64082c406204b158310f4238f926047): perf score=2.188937
I20260812 06:20:37.152235  9308 maintenance_manager.cc:643] P 76337248a092430683274fa9f98a4b00: FlushDeltaMemStoresOp(f64082c406204b158310f4238f926047) complete. Timing: real 0.011s	user 0.011s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4177,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:37.153090  9373 maintenance_manager.cc:419] P 76337248a092430683274fa9f98a4b00: Scheduling MajorDeltaCompactionOp(f64082c406204b158310f4238f926047): perf score=1.000000
I20260812 06:20:37.381745  9308 maintenance_manager.cc:643] P 76337248a092430683274fa9f98a4b00: MajorDeltaCompactionOp(f64082c406204b158310f4238f926047) complete. Timing: real 0.228s	user 0.157s	sys 0.060s Metrics: {"cfile_cache_miss":632,"cfile_cache_miss_bytes":28918098,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":169,"lbm_read_time_us":14767,"lbm_reads_lt_1ms":672,"lbm_write_time_us":35374,"lbm_writes_lt_1ms":643,"mutex_wait_us":36,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":100864,"update_count":3000}
I20260812 06:20:37.382320  9373 maintenance_manager.cc:419] P 76337248a092430683274fa9f98a4b00: Scheduling FlushDeltaMemStoresOp(f64082c406204b158310f4238f926047): perf score=18.063937
I20260812 06:20:37.459839  9308 maintenance_manager.cc:643] P 76337248a092430683274fa9f98a4b00: FlushDeltaMemStoresOp(f64082c406204b158310f4238f926047) complete. Timing: real 0.077s	user 0.038s	sys 0.027s Metrics: {"bytes_written":20512316,"delete_count":0,"lbm_write_time_us":30097,"lbm_writes_lt_1ms":503,"reinsert_count":0,"update_count":2500}
I20260812 06:20:37.460321  9373 maintenance_manager.cc:419] P 76337248a092430683274fa9f98a4b00: Scheduling FlushDeltaMemStoresOp(f64082c406204b158310f4238f926047): perf score=2.188937
I20260812 06:20:37.471314  9308 maintenance_manager.cc:643] P 76337248a092430683274fa9f98a4b00: FlushDeltaMemStoresOp(f64082c406204b158310f4238f926047) complete. Timing: real 0.011s	user 0.010s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4272,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:37.471797  9373 maintenance_manager.cc:419] P 76337248a092430683274fa9f98a4b00: Scheduling MajorDeltaCompactionOp(f64082c406204b158310f4238f926047): perf score=1.000000
I20260812 06:20:37.679539  9308 maintenance_manager.cc:643] P 76337248a092430683274fa9f98a4b00: MajorDeltaCompactionOp(f64082c406204b158310f4238f926047) complete. Timing: real 0.208s	user 0.159s	sys 0.048s Metrics: {"cfile_cache_miss":632,"cfile_cache_miss_bytes":28918098,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":924,"lbm_read_time_us":14185,"lbm_reads_lt_1ms":672,"lbm_write_time_us":32942,"lbm_writes_lt_1ms":643,"mutex_wait_us":156,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":1670784,"update_count":3000}
I20260812 06:20:37.680125  9373 maintenance_manager.cc:419] P 76337248a092430683274fa9f98a4b00: Scheduling FlushDeltaMemStoresOp(f64082c406204b158310f4238f926047): perf score=14.095187
I20260812 06:20:37.747305  9308 maintenance_manager.cc:643] P 76337248a092430683274fa9f98a4b00: FlushDeltaMemStoresOp(f64082c406204b158310f4238f926047) complete. Timing: real 0.067s	user 0.041s	sys 0.016s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":25316,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:20:37.747843  9373 maintenance_manager.cc:419] P 76337248a092430683274fa9f98a4b00: Scheduling FlushDeltaMemStoresOp(f64082c406204b158310f4238f926047): perf score=2.188937
I20260812 06:20:37.760915  9308 maintenance_manager.cc:643] P 76337248a092430683274fa9f98a4b00: FlushDeltaMemStoresOp(f64082c406204b158310f4238f926047) complete. Timing: real 0.013s	user 0.010s	sys 0.001s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4857,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:37.761439  9373 maintenance_manager.cc:419] P 76337248a092430683274fa9f98a4b00: Scheduling MajorDeltaCompactionOp(f64082c406204b158310f4238f926047): perf score=1.000000
I20260812 06:20:37.947227  9308 maintenance_manager.cc:643] P 76337248a092430683274fa9f98a4b00: MajorDeltaCompactionOp(f64082c406204b158310f4238f926047) complete. Timing: real 0.186s	user 0.120s	sys 0.064s 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":1372,"lbm_read_time_us":13851,"lbm_reads_lt_1ms":572,"lbm_write_time_us":31667,"lbm_writes_lt_1ms":543,"mutex_wait_us":486,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":52480,"update_count":2500}
I20260812 06:20:37.947968  9373 maintenance_manager.cc:419] P 76337248a092430683274fa9f98a4b00: Scheduling FlushDeltaMemStoresOp(f64082c406204b158310f4238f926047): perf score=14.095187
I20260812 06:20:38.006176  9308 maintenance_manager.cc:643] P 76337248a092430683274fa9f98a4b00: FlushDeltaMemStoresOp(f64082c406204b158310f4238f926047) complete. Timing: real 0.058s	user 0.042s	sys 0.013s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":26035,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:20:38.006743  9373 maintenance_manager.cc:419] P 76337248a092430683274fa9f98a4b00: Scheduling FlushDeltaMemStoresOp(f64082c406204b158310f4238f926047): perf score=2.188937
I20260812 06:20:38.023197  9308 maintenance_manager.cc:643] P 76337248a092430683274fa9f98a4b00: FlushDeltaMemStoresOp(f64082c406204b158310f4238f926047) complete. Timing: real 0.016s	user 0.012s	sys 0.003s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6786,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:38.023674  9373 maintenance_manager.cc:419] P 76337248a092430683274fa9f98a4b00: Scheduling FlushMRSOp(f64082c406204b158310f4238f926047): perf score=1.000000
I20260812 06:20:38.054770  9308 maintenance_manager.cc:643] P 76337248a092430683274fa9f98a4b00: FlushMRSOp(f64082c406204b158310f4238f926047) complete. Timing: real 0.031s	user 0.028s	sys 0.000s Metrics: {"bytes_written":1275449,"cfile_init":1,"dirs.queue_time_us":86,"dirs.run_cpu_time_us":232,"dirs.run_wall_time_us":1463,"drs_written":1,"lbm_read_time_us":49,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1899,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":31}
I20260812 06:20:38.055636  9373 maintenance_manager.cc:419] P 76337248a092430683274fa9f98a4b00: Scheduling LogGCOp(f64082c406204b158310f4238f926047): free 112692315 bytes of WAL
I20260812 06:20:38.055861  9308 log_reader.cc:385] T f64082c406204b158310f4238f926047: removed 11 log segments from log reader
I20260812 06:20:38.055910  9308 log.cc:1079] T f64082c406204b158310f4238f926047 P 76337248a092430683274fa9f98a4b00: Deleting log segment in path: /tmp/dist-test-taskJpMpSi/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515628656676-8997-0/minicluster-data/ts-0-root/wals/f64082c406204b158310f4238f926047/wal-000000015 (ops 71-75)
I20260812 06:20:38.055949  9308 log.cc:1079] T f64082c406204b158310f4238f926047 P 76337248a092430683274fa9f98a4b00: Deleting log segment in path: /tmp/dist-test-taskJpMpSi/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515628656676-8997-0/minicluster-data/ts-0-root/wals/f64082c406204b158310f4238f926047/wal-000000016 (ops 76-80)
I20260812 06:20:38.055974  9308 log.cc:1079] T f64082c406204b158310f4238f926047 P 76337248a092430683274fa9f98a4b00: Deleting log segment in path: /tmp/dist-test-taskJpMpSi/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515628656676-8997-0/minicluster-data/ts-0-root/wals/f64082c406204b158310f4238f926047/wal-000000017 (ops 81-85)
I20260812 06:20:38.055995  9308 log.cc:1079] T f64082c406204b158310f4238f926047 P 76337248a092430683274fa9f98a4b00: Deleting log segment in path: /tmp/dist-test-taskJpMpSi/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515628656676-8997-0/minicluster-data/ts-0-root/wals/f64082c406204b158310f4238f926047/wal-000000018 (ops 86-90)
I20260812 06:20:38.056018  9308 log.cc:1079] T f64082c406204b158310f4238f926047 P 76337248a092430683274fa9f98a4b00: Deleting log segment in path: /tmp/dist-test-taskJpMpSi/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515628656676-8997-0/minicluster-data/ts-0-root/wals/f64082c406204b158310f4238f926047/wal-000000019 (ops 91-95)
I20260812 06:20:38.056044  9308 log.cc:1079] T f64082c406204b158310f4238f926047 P 76337248a092430683274fa9f98a4b00: Deleting log segment in path: /tmp/dist-test-taskJpMpSi/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515628656676-8997-0/minicluster-data/ts-0-root/wals/f64082c406204b158310f4238f926047/wal-000000020 (ops 96-100)
I20260812 06:20:38.056069  9308 log.cc:1079] T f64082c406204b158310f4238f926047 P 76337248a092430683274fa9f98a4b00: Deleting log segment in path: /tmp/dist-test-taskJpMpSi/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515628656676-8997-0/minicluster-data/ts-0-root/wals/f64082c406204b158310f4238f926047/wal-000000021 (ops 101-105)
I20260812 06:20:38.056092  9308 log.cc:1079] T f64082c406204b158310f4238f926047 P 76337248a092430683274fa9f98a4b00: Deleting log segment in path: /tmp/dist-test-taskJpMpSi/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515628656676-8997-0/minicluster-data/ts-0-root/wals/f64082c406204b158310f4238f926047/wal-000000022 (ops 106-110)
I20260812 06:20:38.056113  9308 log.cc:1079] T f64082c406204b158310f4238f926047 P 76337248a092430683274fa9f98a4b00: Deleting log segment in path: /tmp/dist-test-taskJpMpSi/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515628656676-8997-0/minicluster-data/ts-0-root/wals/f64082c406204b158310f4238f926047/wal-000000023 (ops 111-115)
I20260812 06:20:38.056140  9308 log.cc:1079] T f64082c406204b158310f4238f926047 P 76337248a092430683274fa9f98a4b00: Deleting log segment in path: /tmp/dist-test-taskJpMpSi/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515628656676-8997-0/minicluster-data/ts-0-root/wals/f64082c406204b158310f4238f926047/wal-000000024 (ops 116-120)
I20260812 06:20:38.056169  9308 log.cc:1079] T f64082c406204b158310f4238f926047 P 76337248a092430683274fa9f98a4b00: Deleting log segment in path: /tmp/dist-test-taskJpMpSi/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515628656676-8997-0/minicluster-data/ts-0-root/wals/f64082c406204b158310f4238f926047/wal-000000025 (ops 121-125)
I20260812 06:20:38.083091  9308 maintenance_manager.cc:643] P 76337248a092430683274fa9f98a4b00: LogGCOp(f64082c406204b158310f4238f926047) complete. Timing: real 0.027s	user 0.000s	sys 0.027s Metrics: {}
I20260812 06:20:38.084069  9373 maintenance_manager.cc:419] P 76337248a092430683274fa9f98a4b00: Scheduling UndoDeltaBlockGCOp(f64082c406204b158310f4238f926047): 482 bytes on disk
I20260812 06:20:38.084492  9308 maintenance_manager.cc:643] P 76337248a092430683274fa9f98a4b00: UndoDeltaBlockGCOp(f64082c406204b158310f4238f926047) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":57,"lbm_reads_lt_1ms":4}
I20260812 06:20:38.085114  9373 maintenance_manager.cc:419] P 76337248a092430683274fa9f98a4b00: Scheduling FlushDeltaMemStoresOp(f64082c406204b158310f4238f926047): perf score=5.165500
I20260812 06:20:38.106892  9308 maintenance_manager.cc:643] P 76337248a092430683274fa9f98a4b00: FlushDeltaMemStoresOp(f64082c406204b158310f4238f926047) complete. Timing: real 0.022s	user 0.007s	sys 0.012s Metrics: {"bytes_written":6769231,"delete_count":0,"lbm_write_time_us":8963,"lbm_writes_lt_1ms":168,"reinsert_count":0,"update_count":825}
I20260812 06:20:38.107395  9373 maintenance_manager.cc:419] P 76337248a092430683274fa9f98a4b00: Scheduling LogGCOp(f64082c406204b158310f4238f926047): free 8767182 bytes of WAL
I20260812 06:20:38.107620  9308 log_reader.cc:385] T f64082c406204b158310f4238f926047: removed 1 log segments from log reader
I20260812 06:20:38.107673  9308 log.cc:1079] T f64082c406204b158310f4238f926047 P 76337248a092430683274fa9f98a4b00: Deleting log segment in path: /tmp/dist-test-taskJpMpSi/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515628656676-8997-0/minicluster-data/ts-0-root/wals/f64082c406204b158310f4238f926047/wal-000000026 (ops 126-130)
I20260812 06:20:38.110148  9308 maintenance_manager.cc:643] P 76337248a092430683274fa9f98a4b00: LogGCOp(f64082c406204b158310f4238f926047) complete. Timing: real 0.003s	user 0.000s	sys 0.000s Metrics: {}
I20260812 06:20:38.110633  9373 maintenance_manager.cc:419] P 76337248a092430683274fa9f98a4b00: Scheduling FlushDeltaMemStoresOp(f64082c406204b158310f4238f926047): perf score=1.000000
I20260812 06:20:38.118408  9308 maintenance_manager.cc:643] P 76337248a092430683274fa9f98a4b00: FlushDeltaMemStoresOp(f64082c406204b158310f4238f926047) complete. Timing: real 0.008s	user 0.006s	sys 0.000s Metrics: {"bytes_written":1436027,"delete_count":0,"lbm_write_time_us":2383,"lbm_writes_lt_1ms":38,"reinsert_count":0,"update_count":175}
I20260812 06:20:38.118891  9373 maintenance_manager.cc:419] P 76337248a092430683274fa9f98a4b00: Scheduling MajorDeltaCompactionOp(f64082c406204b158310f4238f926047): perf score=1.000000
I20260812 06:20:38.355633  9308 maintenance_manager.cc:643] P 76337248a092430683274fa9f98a4b00: MajorDeltaCompactionOp(f64082c406204b158310f4238f926047) complete. Timing: real 0.237s	user 0.151s	sys 0.085s Metrics: {"cfile_cache_miss":734,"cfile_cache_miss_bytes":33020681,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":610,"lbm_read_time_us":17731,"lbm_reads_lt_1ms":774,"lbm_write_time_us":41855,"lbm_writes_lt_1ms":743,"peak_mem_usage":87969044,"reinsert_count":0,"spinlock_wait_cycles":7936,"thread_start_us":79,"threads_started":1,"update_count":3500}
I20260812 06:20:38.356205  9373 maintenance_manager.cc:419] P 76337248a092430683274fa9f98a4b00: Scheduling FlushDeltaMemStoresOp(f64082c406204b158310f4238f926047): perf score=19.056125
I20260812 06:20:38.434198  9308 maintenance_manager.cc:643] P 76337248a092430683274fa9f98a4b00: FlushDeltaMemStoresOp(f64082c406204b158310f4238f926047) complete. Timing: real 0.078s	user 0.037s	sys 0.032s Metrics: {"bytes_written":20922556,"delete_count":0,"lbm_write_time_us":32664,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":512,"reinsert_count":0,"update_count":2550}
I20260812 06:20:38.434701  9373 maintenance_manager.cc:419] P 76337248a092430683274fa9f98a4b00: Scheduling FlushDeltaMemStoresOp(f64082c406204b158310f4238f926047): perf score=6.157687
I20260812 06:20:38.461346  9308 maintenance_manager.cc:643] P 76337248a092430683274fa9f98a4b00: FlushDeltaMemStoresOp(f64082c406204b158310f4238f926047) complete. Timing: real 0.026s	user 0.014s	sys 0.007s Metrics: {"bytes_written":7794836,"delete_count":0,"lbm_write_time_us":10170,"lbm_writes_lt_1ms":193,"reinsert_count":0,"update_count":950}
I20260812 06:20:38.461850  9373 maintenance_manager.cc:419] P 76337248a092430683274fa9f98a4b00: Scheduling MajorDeltaCompactionOp(f64082c406204b158310f4238f926047): perf score=1.000000
I20260812 06:20:38.663312  9308 maintenance_manager.cc:643] P 76337248a092430683274fa9f98a4b00: MajorDeltaCompactionOp(f64082c406204b158310f4238f926047) complete. Timing: real 0.201s	user 0.168s	sys 0.032s Metrics: {"cfile_cache_miss":732,"cfile_cache_miss_bytes":33020509,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":668,"lbm_read_time_us":15150,"lbm_reads_lt_1ms":764,"lbm_write_time_us":44071,"lbm_writes_lt_1ms":743,"mutex_wait_us":331,"peak_mem_usage":87969044,"reinsert_count":0,"spinlock_wait_cycles":32384,"update_count":3500}
I20260812 06:20:38.663863  9373 maintenance_manager.cc:419] P 76337248a092430683274fa9f98a4b00: Scheduling FlushDeltaMemStoresOp(f64082c406204b158310f4238f926047): perf score=18.063937
I20260812 06:20:38.738411  9308 maintenance_manager.cc:643] P 76337248a092430683274fa9f98a4b00: FlushDeltaMemStoresOp(f64082c406204b158310f4238f926047) complete. Timing: real 0.074s	user 0.034s	sys 0.036s Metrics: {"bytes_written":20512313,"delete_count":0,"lbm_write_time_us":31523,"lbm_writes_lt_1ms":503,"reinsert_count":0,"update_count":2500}
I20260812 06:20:38.739060  9373 maintenance_manager.cc:419] P 76337248a092430683274fa9f98a4b00: Scheduling FlushDeltaMemStoresOp(f64082c406204b158310f4238f926047): perf score=2.188937
I20260812 06:20:38.758025  9308 maintenance_manager.cc:643] P 76337248a092430683274fa9f98a4b00: FlushDeltaMemStoresOp(f64082c406204b158310f4238f926047) complete. Timing: real 0.019s	user 0.006s	sys 0.005s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5132,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:38.758592  9373 maintenance_manager.cc:419] P 76337248a092430683274fa9f98a4b00: Scheduling FlushDeltaMemStoresOp(f64082c406204b158310f4238f926047): perf score=2.188937
I20260812 06:20:38.769070  9308 maintenance_manager.cc:643] P 76337248a092430683274fa9f98a4b00: FlushDeltaMemStoresOp(f64082c406204b158310f4238f926047) complete. Timing: real 0.010s	user 0.006s	sys 0.003s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4078,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:38.769702  9373 maintenance_manager.cc:419] P 76337248a092430683274fa9f98a4b00: Scheduling MajorDeltaCompactionOp(f64082c406204b158310f4238f926047): perf score=1.000000
I20260812 06:20:38.961573  9308 maintenance_manager.cc:643] P 76337248a092430683274fa9f98a4b00: MajorDeltaCompactionOp(f64082c406204b158310f4238f926047) complete. Timing: real 0.192s	user 0.135s	sys 0.056s Metrics: {"cfile_cache_miss":733,"cfile_cache_miss_bytes":33020625,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":1663,"lbm_read_time_us":14493,"lbm_reads_lt_1ms":773,"lbm_write_time_us":40601,"lbm_writes_lt_1ms":743,"mutex_wait_us":585,"peak_mem_usage":87969044,"reinsert_count":0,"spinlock_wait_cycles":2304,"update_count":3500}
I20260812 06:20:38.962522  9373 maintenance_manager.cc:419] P 76337248a092430683274fa9f98a4b00: Scheduling FlushDeltaMemStoresOp(f64082c406204b158310f4238f926047): perf score=14.095187
I20260812 06:20:39.015359  9308 maintenance_manager.cc:643] P 76337248a092430683274fa9f98a4b00: FlushDeltaMemStoresOp(f64082c406204b158310f4238f926047) complete. Timing: real 0.053s	user 0.040s	sys 0.011s Metrics: {"bytes_written":16615024,"delete_count":0,"lbm_write_time_us":22540,"lbm_writes_lt_1ms":408,"reinsert_count":0,"update_count":2025}
I20260812 06:20:39.015823  9373 maintenance_manager.cc:419] P 76337248a092430683274fa9f98a4b00: Scheduling FlushDeltaMemStoresOp(f64082c406204b158310f4238f926047): perf score=3.181125
I20260812 06:20:39.036700  9308 maintenance_manager.cc:643] P 76337248a092430683274fa9f98a4b00: FlushDeltaMemStoresOp(f64082c406204b158310f4238f926047) complete. Timing: real 0.021s	user 0.003s	sys 0.008s Metrics: {"bytes_written":4307786,"delete_count":0,"lbm_write_time_us":4661,"lbm_writes_lt_1ms":108,"reinsert_count":0,"update_count":525}
I20260812 06:20:39.037148  9373 maintenance_manager.cc:419] P 76337248a092430683274fa9f98a4b00: Scheduling FlushDeltaMemStoresOp(f64082c406204b158310f4238f926047): perf score=2.188937
I20260812 06:20:39.048671  9308 maintenance_manager.cc:643] P 76337248a092430683274fa9f98a4b00: FlushDeltaMemStoresOp(f64082c406204b158310f4238f926047) complete. Timing: real 0.011s	user 0.006s	sys 0.004s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":4130,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:20:39.049232  9373 maintenance_manager.cc:419] P 76337248a092430683274fa9f98a4b00: Scheduling MajorDeltaCompactionOp(f64082c406204b158310f4238f926047): perf score=1.000000
I20260812 06:20:39.221583  9308 maintenance_manager.cc:643] P 76337248a092430683274fa9f98a4b00: MajorDeltaCompactionOp(f64082c406204b158310f4238f926047) complete. Timing: real 0.172s	user 0.149s	sys 0.023s Metrics: {"cfile_cache_miss":633,"cfile_cache_miss_bytes":28918210,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":198,"lbm_read_time_us":11671,"lbm_reads_lt_1ms":673,"lbm_write_time_us":35597,"lbm_writes_lt_1ms":643,"mutex_wait_us":22,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":16512,"update_count":3000}
I20260812 06:20:39.222158  9373 maintenance_manager.cc:419] P 76337248a092430683274fa9f98a4b00: Scheduling FlushDeltaMemStoresOp(f64082c406204b158310f4238f926047): perf score=14.095187
I20260812 06:20:39.273881  9308 maintenance_manager.cc:643] P 76337248a092430683274fa9f98a4b00: FlushDeltaMemStoresOp(f64082c406204b158310f4238f926047) complete. Timing: real 0.052s	user 0.020s	sys 0.021s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":19140,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:20:39.274457  9373 maintenance_manager.cc:419] P 76337248a092430683274fa9f98a4b00: Scheduling FlushDeltaMemStoresOp(f64082c406204b158310f4238f926047): perf score=2.188937
I20260812 06:20:39.290242  9308 maintenance_manager.cc:643] P 76337248a092430683274fa9f98a4b00: FlushDeltaMemStoresOp(f64082c406204b158310f4238f926047) complete. Timing: real 0.016s	user 0.010s	sys 0.003s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5837,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:39.290843  9373 maintenance_manager.cc:419] P 76337248a092430683274fa9f98a4b00: Scheduling MajorDeltaCompactionOp(f64082c406204b158310f4238f926047): perf score=1.000000
I20260812 06:20:39.458953  9308 maintenance_manager.cc:643] P 76337248a092430683274fa9f98a4b00: MajorDeltaCompactionOp(f64082c406204b158310f4238f926047) complete. Timing: real 0.168s	user 0.123s	sys 0.025s 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":207,"lbm_read_time_us":10164,"lbm_reads_lt_1ms":572,"lbm_write_time_us":32057,"lbm_writes_lt_1ms":543,"mutex_wait_us":53,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":2688,"update_count":2500}
I20260812 06:20:39.459827  9373 maintenance_manager.cc:419] P 76337248a092430683274fa9f98a4b00: Scheduling FlushDeltaMemStoresOp(f64082c406204b158310f4238f926047): perf score=14.095187
I20260812 06:20:39.519186  9308 maintenance_manager.cc:643] P 76337248a092430683274fa9f98a4b00: FlushDeltaMemStoresOp(f64082c406204b158310f4238f926047) complete. Timing: real 0.059s	user 0.038s	sys 0.011s Metrics: {"bytes_written":16409905,"delete_count":0,"lbm_write_time_us":22868,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":402,"reinsert_count":0,"update_count":2000}
I20260812 06:20:39.519678  9373 maintenance_manager.cc:419] P 76337248a092430683274fa9f98a4b00: Scheduling FlushDeltaMemStoresOp(f64082c406204b158310f4238f926047): perf score=2.188937
I20260812 06:20:39.530191  9308 maintenance_manager.cc:643] P 76337248a092430683274fa9f98a4b00: FlushDeltaMemStoresOp(f64082c406204b158310f4238f926047) complete. Timing: real 0.010s	user 0.008s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3994,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:39.530812  9373 maintenance_manager.cc:419] P 76337248a092430683274fa9f98a4b00: Scheduling FlushMRSOp(f64082c406204b158310f4238f926047): perf score=1.000000
I20260812 06:20:39.563764  9308 maintenance_manager.cc:643] P 76337248a092430683274fa9f98a4b00: FlushMRSOp(f64082c406204b158310f4238f926047) complete. Timing: real 0.033s	user 0.032s	sys 0.000s Metrics: {"bytes_written":1275447,"cfile_init":1,"dirs.queue_time_us":67,"dirs.run_cpu_time_us":256,"dirs.run_wall_time_us":1611,"drs_written":1,"lbm_read_time_us":57,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1696,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":31}
I20260812 06:20:39.564554  9373 maintenance_manager.cc:419] P 76337248a092430683274fa9f98a4b00: Scheduling LogGCOp(f64082c406204b158310f4238f926047): free 124257516 bytes of WAL
I20260812 06:20:39.564824  9308 log_reader.cc:385] T f64082c406204b158310f4238f926047: removed 12 log segments from log reader
I20260812 06:20:39.564885  9308 log.cc:1079] T f64082c406204b158310f4238f926047 P 76337248a092430683274fa9f98a4b00: Deleting log segment in path: /tmp/dist-test-taskJpMpSi/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515628656676-8997-0/minicluster-data/ts-0-root/wals/f64082c406204b158310f4238f926047/wal-000000027 (ops 131-134)
I20260812 06:20:39.564924  9308 log.cc:1079] T f64082c406204b158310f4238f926047 P 76337248a092430683274fa9f98a4b00: Deleting log segment in path: /tmp/dist-test-taskJpMpSi/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515628656676-8997-0/minicluster-data/ts-0-root/wals/f64082c406204b158310f4238f926047/wal-000000028 (ops 135-139)
I20260812 06:20:39.564947  9308 log.cc:1079] T f64082c406204b158310f4238f926047 P 76337248a092430683274fa9f98a4b00: Deleting log segment in path: /tmp/dist-test-taskJpMpSi/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515628656676-8997-0/minicluster-data/ts-0-root/wals/f64082c406204b158310f4238f926047/wal-000000029 (ops 140-144)
I20260812 06:20:39.564977  9308 log.cc:1079] T f64082c406204b158310f4238f926047 P 76337248a092430683274fa9f98a4b00: Deleting log segment in path: /tmp/dist-test-taskJpMpSi/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515628656676-8997-0/minicluster-data/ts-0-root/wals/f64082c406204b158310f4238f926047/wal-000000030 (ops 145-149)
I20260812 06:20:39.565001  9308 log.cc:1079] T f64082c406204b158310f4238f926047 P 76337248a092430683274fa9f98a4b00: Deleting log segment in path: /tmp/dist-test-taskJpMpSi/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515628656676-8997-0/minicluster-data/ts-0-root/wals/f64082c406204b158310f4238f926047/wal-000000031 (ops 150-154)
I20260812 06:20:39.565028  9308 log.cc:1079] T f64082c406204b158310f4238f926047 P 76337248a092430683274fa9f98a4b00: Deleting log segment in path: /tmp/dist-test-taskJpMpSi/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515628656676-8997-0/minicluster-data/ts-0-root/wals/f64082c406204b158310f4238f926047/wal-000000032 (ops 155-159)
I20260812 06:20:39.565061  9308 log.cc:1079] T f64082c406204b158310f4238f926047 P 76337248a092430683274fa9f98a4b00: Deleting log segment in path: /tmp/dist-test-taskJpMpSi/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515628656676-8997-0/minicluster-data/ts-0-root/wals/f64082c406204b158310f4238f926047/wal-000000033 (ops 160-164)
I20260812 06:20:39.565088  9308 log.cc:1079] T f64082c406204b158310f4238f926047 P 76337248a092430683274fa9f98a4b00: Deleting log segment in path: /tmp/dist-test-taskJpMpSi/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515628656676-8997-0/minicluster-data/ts-0-root/wals/f64082c406204b158310f4238f926047/wal-000000034 (ops 165-169)
I20260812 06:20:39.565114  9308 log.cc:1079] T f64082c406204b158310f4238f926047 P 76337248a092430683274fa9f98a4b00: Deleting log segment in path: /tmp/dist-test-taskJpMpSi/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515628656676-8997-0/minicluster-data/ts-0-root/wals/f64082c406204b158310f4238f926047/wal-000000035 (ops 170-174)
I20260812 06:20:39.565135  9308 log.cc:1079] T f64082c406204b158310f4238f926047 P 76337248a092430683274fa9f98a4b00: Deleting log segment in path: /tmp/dist-test-taskJpMpSi/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515628656676-8997-0/minicluster-data/ts-0-root/wals/f64082c406204b158310f4238f926047/wal-000000036 (ops 175-179)
I20260812 06:20:39.565163  9308 log.cc:1079] T f64082c406204b158310f4238f926047 P 76337248a092430683274fa9f98a4b00: Deleting log segment in path: /tmp/dist-test-taskJpMpSi/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515628656676-8997-0/minicluster-data/ts-0-root/wals/f64082c406204b158310f4238f926047/wal-000000037 (ops 180-184)
I20260812 06:20:39.565194  9308 log.cc:1079] T f64082c406204b158310f4238f926047 P 76337248a092430683274fa9f98a4b00: Deleting log segment in path: /tmp/dist-test-taskJpMpSi/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515628656676-8997-0/minicluster-data/ts-0-root/wals/f64082c406204b158310f4238f926047/wal-000000038 (ops 185-189)
I20260812 06:20:39.596565  9308 maintenance_manager.cc:643] P 76337248a092430683274fa9f98a4b00: LogGCOp(f64082c406204b158310f4238f926047) complete. Timing: real 0.032s	user 0.000s	sys 0.030s Metrics: {}
I20260812 06:20:39.597090  9373 maintenance_manager.cc:419] P 76337248a092430683274fa9f98a4b00: Scheduling UndoDeltaBlockGCOp(f64082c406204b158310f4238f926047): 483 bytes on disk
I20260812 06:20:39.597575  9308 maintenance_manager.cc:643] P 76337248a092430683274fa9f98a4b00: UndoDeltaBlockGCOp(f64082c406204b158310f4238f926047) 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:20:39.598136  9373 maintenance_manager.cc:419] P 76337248a092430683274fa9f98a4b00: Scheduling FlushDeltaMemStoresOp(f64082c406204b158310f4238f926047): perf score=2.188937
I20260812 06:20:39.617748  9308 maintenance_manager.cc:643] P 76337248a092430683274fa9f98a4b00: FlushDeltaMemStoresOp(f64082c406204b158310f4238f926047) complete. Timing: real 0.019s	user 0.006s	sys 0.003s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4474,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:39.618229  9373 maintenance_manager.cc:419] P 76337248a092430683274fa9f98a4b00: Scheduling FlushDeltaMemStoresOp(f64082c406204b158310f4238f926047): perf score=2.188937
I20260812 06:20:39.628496  9308 maintenance_manager.cc:643] P 76337248a092430683274fa9f98a4b00: FlushDeltaMemStoresOp(f64082c406204b158310f4238f926047) complete. Timing: real 0.010s	user 0.004s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4007,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:39.628976  9373 maintenance_manager.cc:419] P 76337248a092430683274fa9f98a4b00: Scheduling MajorDeltaCompactionOp(f64082c406204b158310f4238f926047): perf score=1.000000
I20260812 06:20:39.748159  8997 heavy-update-compaction-itest.cc:229] Time spent updating: real 4.983s	user 1.858s	sys 0.153s
I20260812 06:20:39.826534  9308 maintenance_manager.cc:643] P 76337248a092430683274fa9f98a4b00: MajorDeltaCompactionOp(f64082c406204b158310f4238f926047) complete. Timing: real 0.197s	user 0.113s	sys 0.082s Metrics: {"cfile_cache_miss":734,"cfile_cache_miss_bytes":33020749,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":7115,"lbm_read_time_us":14579,"lbm_reads_lt_1ms":770,"lbm_write_time_us":35386,"lbm_writes_lt_1ms":743,"mutex_wait_us":1624,"peak_mem_usage":87969044,"reinsert_count":0,"spinlock_wait_cycles":2816,"thread_start_us":102,"threads_started":1,"update_count":3500}
I20260812 06:20:39.827383  9373 maintenance_manager.cc:419] P 76337248a092430683274fa9f98a4b00: Scheduling FlushDeltaMemStoresOp(f64082c406204b158310f4238f926047): perf score=10.126437
I20260812 06:20:39.829280  8997 heavy-update-compaction-itest.cc:265] Time spent scanning: real 0.081s	user 0.001s	sys 0.000s
I20260812 06:20:39.829759  8997 tablet_server.cc:179] TabletServer@127.8.201.65:0 shutting down...
I20260812 06:20:39.864672  9308 maintenance_manager.cc:643] P 76337248a092430683274fa9f98a4b00: FlushDeltaMemStoresOp(f64082c406204b158310f4238f926047) complete. Timing: real 0.037s	user 0.019s	sys 0.016s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":14872,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:20:39.865713  8997 ts_tablet_manager.cc:1507] Shutting down tablet manager...
I20260812 06:20:39.865932  8997 tablet_replica.cc:333] T f64082c406204b158310f4238f926047 P 76337248a092430683274fa9f98a4b00: stopping tablet replica
I20260812 06:20:39.866091  8997 raft_consensus.cc:2243] T f64082c406204b158310f4238f926047 P 76337248a092430683274fa9f98a4b00 [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:20:39.866272  8997 raft_consensus.cc:2272] T f64082c406204b158310f4238f926047 P 76337248a092430683274fa9f98a4b00 [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:20:39.869354  8997 tablet_server.cc:196] TabletServer@127.8.201.65:0 shutdown complete.
I20260812 06:20:39.882311  8997 master.cc:562] Master@127.8.201.126:35057 shutting down...
I20260812 06:20:39.885623  8997 raft_consensus.cc:2243] T 00000000000000000000000000000000 P 414b0d2348ce449697ac4b4854d282e4 [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:20:39.885802  8997 raft_consensus.cc:2272] T 00000000000000000000000000000000 P 414b0d2348ce449697ac4b4854d282e4 [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:20:39.885883  8997 tablet_replica.cc:333] T 00000000000000000000000000000000 P 414b0d2348ce449697ac4b4854d282e4: stopping tablet replica
I20260812 06:20:39.898006  8997 master.cc:584] Master@127.8.201.126:35057 shutdown complete.
[       OK ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/1 (5418 ms)
[----------] 2 tests from EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy (11321 ms total)

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