[==========] Running 2 tests from 1 test suite.
[----------] Global test environment set-up.
[----------] 2 tests from EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy
[ RUN      ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/0
WARNING: Logging before InitGoogleLogging() is written to STDERR
I20260812 06:19:08.721998 21775 internal_mini_cluster.cc:156] Creating distributed mini masters. Addrs: 127.21.67.254:37759
I20260812 06:19:08.722976 21775 env_posix.cc:2285] Not raising this process' open files per process limit of 1048576; it is already as high as it can go
I20260812 06:19:08.723577 21775 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:19:08.729955 21786 instance_detector.cc:116] could not retrieve OpenStack instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:19:08.730041 21782 instance_detector.cc:116] could not retrieve AWS instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:19:08.730165 21775 server_base.cc:1061] running on GCE node
W20260812 06:19:08.730202 21784 instance_detector.cc:116] could not retrieve Azure instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:19:08.730733 21775 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:19:08.730854 21775 system_unsync_time.cc:38] NTP support is disabled. Clock error bounds will not be accurate. This configuration is not suitable for distributed clusters.
I20260812 06:19:08.730919 21775 hybrid_clock.cc:648] HybridClock initialized: now 1786515548730916 us; error 0 us; skew 500 ppm
I20260812 06:19:08.732746 21775 webserver.cc:533] Webserver started at http://127.21.67.254:42917/ using document root <none> and password file <none>
I20260812 06:19:08.733227 21775 fs_manager.cc:362] Metadata directory not provided
I20260812 06:19:08.733280 21775 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:19:08.733460 21775 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:19:08.734987 21775 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskw60Q2h/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515548711361-21775-0/minicluster-data/master-0-root/instance:
uuid: "10128bdf121b4e409400796840670ffc"
format_stamp: "Formatted at 2026-08-12 06:19:08 on dist-test-slave-cbbz"
I20260812 06:19:08.738262 21775 fs_manager.cc:696] Time spent creating directory manager: real 0.003s	user 0.005s	sys 0.000s
I20260812 06:19:08.740273 21791 log_block_manager.cc:4127] Time spent loading block containers with low live blocks: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:19:08.741374 21775 fs_manager.cc:730] Time spent opening block manager: real 0.002s	user 0.002s	sys 0.000s
I20260812 06:19:08.741468 21775 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskw60Q2h/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515548711361-21775-0/minicluster-data/master-0-root
uuid: "10128bdf121b4e409400796840670ffc"
format_stamp: "Formatted at 2026-08-12 06:19:08 on dist-test-slave-cbbz"
I20260812 06:19:08.741545 21775 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskw60Q2h/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515548711361-21775-0/minicluster-data/master-0-root
metadata directory: /tmp/dist-test-taskw60Q2h/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515548711361-21775-0/minicluster-data/master-0-root
1 data directories: /tmp/dist-test-taskw60Q2h/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515548711361-21775-0/minicluster-data/master-0-root/data
Total live blocks: 0
Total live bytes: 0
Total live bytes (after alignment): 0
Total number of LBM containers: 0 (0 full)
Did not check for missing blocks
Did not check for orphaned blocks
Total full LBM containers with extra space: 0 (0 repaired)
Total full LBM container extra space in bytes: 0 (0 repaired)
Total incomplete LBM containers: 0 (0 repaired)
Total LBM partial records: 0 (0 repaired)
Total corrupted LBM metadata records in RocksDB: 0 (0 repaired)
I20260812 06:19:08.751725 21775 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:19:08.752316 21775 env_posix.cc:2285] Not raising this process' running threads per effective uid limit of 18446744073709551615; it is already as high as it can go
I20260812 06:19:08.752440 21775 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:19:08.759559 21775 rpc_server.cc:307] RPC server started. Bound to: 127.21.67.254:37759
I20260812 06:19:08.759625 21853 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.21.67.254:37759 every 8 connection(s)
I20260812 06:19:08.761897 21854 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet 00000000000000000000000000000000. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:19:08.767197 21854 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P 10128bdf121b4e409400796840670ffc: Bootstrap starting.
I20260812 06:19:08.769574 21854 tablet_bootstrap.cc:654] T 00000000000000000000000000000000 P 10128bdf121b4e409400796840670ffc: Neither blocks nor log segments found. Creating new log.
I20260812 06:19:08.770453 21854 log.cc:826] T 00000000000000000000000000000000 P 10128bdf121b4e409400796840670ffc: Log is configured to *not* fsync() on all Append() calls
I20260812 06:19:08.772051 21854 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P 10128bdf121b4e409400796840670ffc: No bootstrap required, opened a new log
I20260812 06:19:08.774710 21854 raft_consensus.cc:359] T 00000000000000000000000000000000 P 10128bdf121b4e409400796840670ffc [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "10128bdf121b4e409400796840670ffc" member_type: VOTER }
I20260812 06:19:08.774861 21854 raft_consensus.cc:385] T 00000000000000000000000000000000 P 10128bdf121b4e409400796840670ffc [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:19:08.774930 21854 raft_consensus.cc:740] T 00000000000000000000000000000000 P 10128bdf121b4e409400796840670ffc [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: 10128bdf121b4e409400796840670ffc, State: Initialized, Role: FOLLOWER
I20260812 06:19:08.775555 21854 consensus_queue.cc:260] T 00000000000000000000000000000000 P 10128bdf121b4e409400796840670ffc [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: "10128bdf121b4e409400796840670ffc" member_type: VOTER }
I20260812 06:19:08.775723 21854 raft_consensus.cc:399] T 00000000000000000000000000000000 P 10128bdf121b4e409400796840670ffc [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:19:08.775790 21854 raft_consensus.cc:493] T 00000000000000000000000000000000 P 10128bdf121b4e409400796840670ffc [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:19:08.775949 21854 raft_consensus.cc:3060] T 00000000000000000000000000000000 P 10128bdf121b4e409400796840670ffc [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:19:08.776775 21854 raft_consensus.cc:515] T 00000000000000000000000000000000 P 10128bdf121b4e409400796840670ffc [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "10128bdf121b4e409400796840670ffc" member_type: VOTER }
I20260812 06:19:08.777206 21854 leader_election.cc:304] T 00000000000000000000000000000000 P 10128bdf121b4e409400796840670ffc [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: 10128bdf121b4e409400796840670ffc; no voters: 
I20260812 06:19:08.777529 21854 leader_election.cc:290] T 00000000000000000000000000000000 P 10128bdf121b4e409400796840670ffc [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:19:08.777670 21857 raft_consensus.cc:2804] T 00000000000000000000000000000000 P 10128bdf121b4e409400796840670ffc [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:19:08.777922 21857 raft_consensus.cc:697] T 00000000000000000000000000000000 P 10128bdf121b4e409400796840670ffc [term 1 LEADER]: Becoming Leader. State: Replica: 10128bdf121b4e409400796840670ffc, State: Running, Role: LEADER
I20260812 06:19:08.778316 21857 consensus_queue.cc:237] T 00000000000000000000000000000000 P 10128bdf121b4e409400796840670ffc [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: "10128bdf121b4e409400796840670ffc" member_type: VOTER }
I20260812 06:19:08.778471 21854 sys_catalog.cc:565] T 00000000000000000000000000000000 P 10128bdf121b4e409400796840670ffc [sys.catalog]: configured and running, proceeding with master startup.
I20260812 06:19:08.780182 21859 sys_catalog.cc:455] T 00000000000000000000000000000000 P 10128bdf121b4e409400796840670ffc [sys.catalog]: SysCatalogTable state changed. Reason: New leader 10128bdf121b4e409400796840670ffc. Latest consensus state: current_term: 1 leader_uuid: "10128bdf121b4e409400796840670ffc" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "10128bdf121b4e409400796840670ffc" member_type: VOTER } }
I20260812 06:19:08.780234 21858 sys_catalog.cc:455] T 00000000000000000000000000000000 P 10128bdf121b4e409400796840670ffc [sys.catalog]: SysCatalogTable state changed. Reason: RaftConsensus started. Latest consensus state: current_term: 1 leader_uuid: "10128bdf121b4e409400796840670ffc" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "10128bdf121b4e409400796840670ffc" member_type: VOTER } }
I20260812 06:19:08.780303 21859 sys_catalog.cc:458] T 00000000000000000000000000000000 P 10128bdf121b4e409400796840670ffc [sys.catalog]: This master's current role is: LEADER
I20260812 06:19:08.780318 21858 sys_catalog.cc:458] T 00000000000000000000000000000000 P 10128bdf121b4e409400796840670ffc [sys.catalog]: This master's current role is: LEADER
I20260812 06:19:08.780617 21869 catalog_manager.cc:1511] Loading table and tablet metadata into memory...
I20260812 06:19:08.780900 21775 internal_mini_cluster.cc:184] Waiting to initialize catalog manager on master 0
I20260812 06:19:08.782850 21869 catalog_manager.cc:1520] Initializing Kudu cluster ID...
I20260812 06:19:08.787047 21869 catalog_manager.cc:1383] Generated new cluster ID: b1ac14435dd04b61876eebadbb5a34f6
I20260812 06:19:08.787108 21869 catalog_manager.cc:1531] Initializing Kudu internal certificate authority...
I20260812 06:19:08.799983 21869 catalog_manager.cc:1406] Generated new certificate authority record
I20260812 06:19:08.801093 21869 catalog_manager.cc:1540] Loading token signing keys...
I20260812 06:19:08.816712 21869 catalog_manager.cc:6092] T 00000000000000000000000000000000 P 10128bdf121b4e409400796840670ffc: Generated new TSK 0
I20260812 06:19:08.817528 21869 catalog_manager.cc:1550] Initializing in-progress tserver states...
I20260812 06:19:08.845968 21775 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:19:08.848676 21878 instance_detector.cc:116] could not retrieve AWS instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:19:08.848928 21879 instance_detector.cc:116] could not retrieve Azure instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:19:08.848949 21881 instance_detector.cc:116] could not retrieve OpenStack instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:19:08.849222 21775 server_base.cc:1061] running on GCE node
I20260812 06:19:08.849427 21775 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:19:08.849484 21775 system_unsync_time.cc:38] NTP support is disabled. Clock error bounds will not be accurate. This configuration is not suitable for distributed clusters.
I20260812 06:19:08.849521 21775 hybrid_clock.cc:648] HybridClock initialized: now 1786515548849520 us; error 0 us; skew 500 ppm
I20260812 06:19:08.850523 21775 webserver.cc:533] Webserver started at http://127.21.67.193:42675/ using document root <none> and password file <none>
I20260812 06:19:08.850706 21775 fs_manager.cc:362] Metadata directory not provided
I20260812 06:19:08.850770 21775 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:19:08.850853 21775 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:19:08.851337 21775 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskw60Q2h/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515548711361-21775-0/minicluster-data/ts-0-root/instance:
uuid: "7430a51c2f334c1dae46b69b3ae5dbd9"
format_stamp: "Formatted at 2026-08-12 06:19:08 on dist-test-slave-cbbz"
I20260812 06:19:08.853396 21775 fs_manager.cc:696] Time spent creating directory manager: real 0.002s	user 0.003s	sys 0.000s
I20260812 06:19:08.854602 21887 log_block_manager.cc:4127] Time spent loading block containers with low live blocks: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:19:08.854914 21775 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.001s	sys 0.000s
I20260812 06:19:08.855006 21775 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskw60Q2h/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515548711361-21775-0/minicluster-data/ts-0-root
uuid: "7430a51c2f334c1dae46b69b3ae5dbd9"
format_stamp: "Formatted at 2026-08-12 06:19:08 on dist-test-slave-cbbz"
I20260812 06:19:08.855082 21775 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskw60Q2h/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515548711361-21775-0/minicluster-data/ts-0-root
metadata directory: /tmp/dist-test-taskw60Q2h/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515548711361-21775-0/minicluster-data/ts-0-root
1 data directories: /tmp/dist-test-taskw60Q2h/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515548711361-21775-0/minicluster-data/ts-0-root/data
Total live blocks: 0
Total live bytes: 0
Total live bytes (after alignment): 0
Total number of LBM containers: 0 (0 full)
Did not check for missing blocks
Did not check for orphaned blocks
Total full LBM containers with extra space: 0 (0 repaired)
Total full LBM container extra space in bytes: 0 (0 repaired)
Total incomplete LBM containers: 0 (0 repaired)
Total LBM partial records: 0 (0 repaired)
Total corrupted LBM metadata records in RocksDB: 0 (0 repaired)
I20260812 06:19:08.865103 21775 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:19:08.865530 21775 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:19:08.866032 21775 txn_system_client.cc:432] TxnSystemClient initialization is disabled...
I20260812 06:19:08.866882 21775 ts_tablet_manager.cc:585] Loaded tablet metadata (0 total tablets, 0 live tablets)
I20260812 06:19:08.866956 21775 ts_tablet_manager.cc:531] Time spent load tablet metadata: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:19:08.867033 21775 ts_tablet_manager.cc:616] Registered 0 tablets
I20260812 06:19:08.867089 21775 ts_tablet_manager.cc:595] Time spent register tablets: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:19:08.874030 21775 rpc_server.cc:307] RPC server started. Bound to: 127.21.67.193:46097
I20260812 06:19:08.874080 21960 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.21.67.193:46097 every 8 connection(s)
I20260812 06:19:08.884397 21961 heartbeater.cc:344] Connected to a master server at 127.21.67.254:37759
I20260812 06:19:08.884651 21961 heartbeater.cc:461] Registering TS with master...
I20260812 06:19:08.885115 21961 heartbeater.cc:507] Master 127.21.67.254:37759 requested a full tablet report, sending...
I20260812 06:19:08.886637 21812 ts_manager.cc:194] Registered new tserver with Master: 7430a51c2f334c1dae46b69b3ae5dbd9 (127.21.67.193:46097)
I20260812 06:19:08.887131 21775 internal_mini_cluster.cc:371] 1 TS(s) registered with all masters after 0.012409268s
I20260812 06:19:08.888190 21812 master_service.cc:502] Signed X509 certificate for tserver {username='slave'} at 127.0.0.1:44824
I20260812 06:19:08.896335 21812 catalog_manager.cc:2283] Servicing CreateTable request from {username='slave'} at 127.0.0.1:44840:
name: "heavy-update-compaction-test"
schema {
  columns {
    name: "key"
    type: INT64
    is_key: true
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_a"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_b"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_c"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_d"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_e"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
}
num_replicas: 1
split_rows_range_bounds {
}
partition_schema {
  range_schema {
  }
}
I20260812 06:19:08.910670 21920 tablet_service.cc:1511] Processing CreateTablet for tablet 99f7be6dfd45498d8a795fc80dff849e (DEFAULT_TABLE table=heavy-update-compaction-test [id=402f6472c8a747349e571e5c2e6ddc45]), partition=
I20260812 06:19:08.911186 21920 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet 99f7be6dfd45498d8a795fc80dff849e. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:19:08.913766 21975 tablet_bootstrap.cc:492] T 99f7be6dfd45498d8a795fc80dff849e P 7430a51c2f334c1dae46b69b3ae5dbd9: Bootstrap starting.
I20260812 06:19:08.915125 21975 tablet_bootstrap.cc:654] T 99f7be6dfd45498d8a795fc80dff849e P 7430a51c2f334c1dae46b69b3ae5dbd9: Neither blocks nor log segments found. Creating new log.
I20260812 06:19:08.916569 21975 tablet_bootstrap.cc:492] T 99f7be6dfd45498d8a795fc80dff849e P 7430a51c2f334c1dae46b69b3ae5dbd9: No bootstrap required, opened a new log
I20260812 06:19:08.916712 21975 ts_tablet_manager.cc:1403] T 99f7be6dfd45498d8a795fc80dff849e P 7430a51c2f334c1dae46b69b3ae5dbd9: Time spent bootstrapping tablet: real 0.003s	user 0.002s	sys 0.000s
I20260812 06:19:08.917289 21975 raft_consensus.cc:359] T 99f7be6dfd45498d8a795fc80dff849e P 7430a51c2f334c1dae46b69b3ae5dbd9 [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "7430a51c2f334c1dae46b69b3ae5dbd9" member_type: VOTER last_known_addr { host: "127.21.67.193" port: 46097 } }
I20260812 06:19:08.917421 21975 raft_consensus.cc:385] T 99f7be6dfd45498d8a795fc80dff849e P 7430a51c2f334c1dae46b69b3ae5dbd9 [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:19:08.917467 21975 raft_consensus.cc:740] T 99f7be6dfd45498d8a795fc80dff849e P 7430a51c2f334c1dae46b69b3ae5dbd9 [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: 7430a51c2f334c1dae46b69b3ae5dbd9, State: Initialized, Role: FOLLOWER
I20260812 06:19:08.917658 21975 consensus_queue.cc:260] T 99f7be6dfd45498d8a795fc80dff849e P 7430a51c2f334c1dae46b69b3ae5dbd9 [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: "7430a51c2f334c1dae46b69b3ae5dbd9" member_type: VOTER last_known_addr { host: "127.21.67.193" port: 46097 } }
I20260812 06:19:08.917829 21975 raft_consensus.cc:399] T 99f7be6dfd45498d8a795fc80dff849e P 7430a51c2f334c1dae46b69b3ae5dbd9 [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:19:08.917912 21975 raft_consensus.cc:493] T 99f7be6dfd45498d8a795fc80dff849e P 7430a51c2f334c1dae46b69b3ae5dbd9 [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:19:08.917977 21975 raft_consensus.cc:3060] T 99f7be6dfd45498d8a795fc80dff849e P 7430a51c2f334c1dae46b69b3ae5dbd9 [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:19:08.919059 21975 raft_consensus.cc:515] T 99f7be6dfd45498d8a795fc80dff849e P 7430a51c2f334c1dae46b69b3ae5dbd9 [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "7430a51c2f334c1dae46b69b3ae5dbd9" member_type: VOTER last_known_addr { host: "127.21.67.193" port: 46097 } }
I20260812 06:19:08.919225 21975 leader_election.cc:304] T 99f7be6dfd45498d8a795fc80dff849e P 7430a51c2f334c1dae46b69b3ae5dbd9 [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: 7430a51c2f334c1dae46b69b3ae5dbd9; no voters: 
I20260812 06:19:08.919450 21975 leader_election.cc:290] T 99f7be6dfd45498d8a795fc80dff849e P 7430a51c2f334c1dae46b69b3ae5dbd9 [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:19:08.919585 21977 raft_consensus.cc:2804] T 99f7be6dfd45498d8a795fc80dff849e P 7430a51c2f334c1dae46b69b3ae5dbd9 [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:19:08.919816 21975 ts_tablet_manager.cc:1434] T 99f7be6dfd45498d8a795fc80dff849e P 7430a51c2f334c1dae46b69b3ae5dbd9: Time spent starting tablet: real 0.003s	user 0.000s	sys 0.003s
I20260812 06:19:08.919886 21977 raft_consensus.cc:697] T 99f7be6dfd45498d8a795fc80dff849e P 7430a51c2f334c1dae46b69b3ae5dbd9 [term 1 LEADER]: Becoming Leader. State: Replica: 7430a51c2f334c1dae46b69b3ae5dbd9, State: Running, Role: LEADER
I20260812 06:19:08.920042 21961 heartbeater.cc:499] Master 127.21.67.254:37759 was elected leader, sending a full tablet report...
I20260812 06:19:08.920204 21977 consensus_queue.cc:237] T 99f7be6dfd45498d8a795fc80dff849e P 7430a51c2f334c1dae46b69b3ae5dbd9 [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: "7430a51c2f334c1dae46b69b3ae5dbd9" member_type: VOTER last_known_addr { host: "127.21.67.193" port: 46097 } }
I20260812 06:19:08.923164 21812 catalog_manager.cc:5719] T 99f7be6dfd45498d8a795fc80dff849e P 7430a51c2f334c1dae46b69b3ae5dbd9 reported cstate change: term changed from 0 to 1, leader changed from <none> to 7430a51c2f334c1dae46b69b3ae5dbd9 (127.21.67.193). New cstate: current_term: 1 leader_uuid: "7430a51c2f334c1dae46b69b3ae5dbd9" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "7430a51c2f334c1dae46b69b3ae5dbd9" member_type: VOTER last_known_addr { host: "127.21.67.193" port: 46097 } health_report { overall_health: HEALTHY } } }
I20260812 06:19:08.990339 21775 heavy-update-compaction-itest.cc:215] Time spent inserting: real 0.059s	user 0.019s	sys 0.011s
I20260812 06:19:09.125262 21962 maintenance_manager.cc:419] P 7430a51c2f334c1dae46b69b3ae5dbd9: Scheduling FlushMRSOp(99f7be6dfd45498d8a795fc80dff849e): perf score=19.054940
I20260812 06:19:09.311252 21893 maintenance_manager.cc:643] P 7430a51c2f334c1dae46b69b3ae5dbd9: FlushMRSOp(99f7be6dfd45498d8a795fc80dff849e) complete. Timing: real 0.186s	user 0.128s	sys 0.052s Metrics: {"bytes_written":13620265,"cfile_init":1,"compiler_manager_pool.queue_time_us":198,"delete_count":0,"dirs.queue_time_us":55,"dirs.run_cpu_time_us":242,"dirs.run_wall_time_us":969,"drs_written":1,"lbm_read_time_us":72,"lbm_reads_lt_1ms":4,"lbm_write_time_us":47372,"lbm_writes_lt_1ms":789,"mutex_wait_us":951,"peak_mem_usage":0,"reinsert_count":0,"rows_written":104,"spinlock_wait_cycles":122752,"thread_start_us":129,"threads_started":1,"update_count":1660}
I20260812 06:19:09.312533 21962 maintenance_manager.cc:419] P 7430a51c2f334c1dae46b69b3ae5dbd9: Scheduling LogGCOp(99f7be6dfd45498d8a795fc80dff849e): free 20743880 bytes of WAL
I20260812 06:19:09.312812 21893 log_reader.cc:385] T 99f7be6dfd45498d8a795fc80dff849e: removed 2 log segments from log reader
I20260812 06:19:09.312872 21893 log.cc:1079] T 99f7be6dfd45498d8a795fc80dff849e P 7430a51c2f334c1dae46b69b3ae5dbd9: Deleting log segment in path: /tmp/dist-test-taskw60Q2h/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515548711361-21775-0/minicluster-data/ts-0-root/wals/99f7be6dfd45498d8a795fc80dff849e/wal-000000001 (ops 1-6)
I20260812 06:19:09.312922 21893 log.cc:1079] T 99f7be6dfd45498d8a795fc80dff849e P 7430a51c2f334c1dae46b69b3ae5dbd9: Deleting log segment in path: /tmp/dist-test-taskw60Q2h/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515548711361-21775-0/minicluster-data/ts-0-root/wals/99f7be6dfd45498d8a795fc80dff849e/wal-000000002 (ops 7-11)
I20260812 06:19:09.318342 21893 maintenance_manager.cc:643] P 7430a51c2f334c1dae46b69b3ae5dbd9: LogGCOp(99f7be6dfd45498d8a795fc80dff849e) complete. Timing: real 0.006s	user 0.000s	sys 0.004s Metrics: {}
I20260812 06:19:09.318825 21962 maintenance_manager.cc:419] P 7430a51c2f334c1dae46b69b3ae5dbd9: Scheduling FlushDeltaMemStoresOp(99f7be6dfd45498d8a795fc80dff849e): perf score=4.173312
I20260812 06:19:09.344403 21893 maintenance_manager.cc:643] P 7430a51c2f334c1dae46b69b3ae5dbd9: FlushDeltaMemStoresOp(99f7be6dfd45498d8a795fc80dff849e) complete. Timing: real 0.025s	user 0.014s	sys 0.011s Metrics: {"bytes_written":5620558,"delete_count":0,"lbm_write_time_us":7657,"lbm_writes_lt_1ms":140,"reinsert_count":0,"update_count":685}
I20260812 06:19:09.345098 21962 maintenance_manager.cc:419] P 7430a51c2f334c1dae46b69b3ae5dbd9: Scheduling UndoDeltaBlockGCOp(99f7be6dfd45498d8a795fc80dff849e): 16411397 bytes on disk
I20260812 06:19:09.345908 21893 maintenance_manager.cc:643] P 7430a51c2f334c1dae46b69b3ae5dbd9: UndoDeltaBlockGCOp(99f7be6dfd45498d8a795fc80dff849e) complete. Timing: real 0.001s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":141,"lbm_reads_lt_1ms":4}
I20260812 06:19:09.346412 21962 maintenance_manager.cc:419] P 7430a51c2f334c1dae46b69b3ae5dbd9: Scheduling FlushDeltaMemStoresOp(99f7be6dfd45498d8a795fc80dff849e): perf score=1.000000
I20260812 06:19:09.353382 21893 maintenance_manager.cc:643] P 7430a51c2f334c1dae46b69b3ae5dbd9: FlushDeltaMemStoresOp(99f7be6dfd45498d8a795fc80dff849e) complete. Timing: real 0.007s	user 0.001s	sys 0.004s Metrics: {"bytes_written":1271927,"delete_count":0,"lbm_write_time_us":2079,"lbm_writes_lt_1ms":34,"reinsert_count":0,"update_count":155}
I20260812 06:19:09.353844 21962 maintenance_manager.cc:419] P 7430a51c2f334c1dae46b69b3ae5dbd9: Scheduling MajorDeltaCompactionOp(99f7be6dfd45498d8a795fc80dff849e): perf score=1.000000
I20260812 06:19:09.542488 21893 maintenance_manager.cc:643] P 7430a51c2f334c1dae46b69b3ae5dbd9: MajorDeltaCompactionOp(99f7be6dfd45498d8a795fc80dff849e) complete. Timing: real 0.188s	user 0.145s	sys 0.032s Metrics: {"cfile_cache_miss":533,"cfile_cache_miss_bytes":24774745,"cfile_init":7,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":539,"lbm_read_time_us":12247,"lbm_reads_lt_1ms":561,"lbm_write_time_us":30140,"lbm_writes_lt_1ms":543,"peak_mem_usage":63115900,"reinsert_count":0,"thread_start_us":340,"threads_started":5,"update_count":2500}
I20260812 06:19:09.543154 21962 maintenance_manager.cc:419] P 7430a51c2f334c1dae46b69b3ae5dbd9: Scheduling FlushDeltaMemStoresOp(99f7be6dfd45498d8a795fc80dff849e): perf score=14.095187
I20260812 06:19:09.595767 21893 maintenance_manager.cc:643] P 7430a51c2f334c1dae46b69b3ae5dbd9: FlushDeltaMemStoresOp(99f7be6dfd45498d8a795fc80dff849e) complete. Timing: real 0.052s	user 0.026s	sys 0.011s Metrics: {"bytes_written":16409903,"delete_count":0,"lbm_write_time_us":18313,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:09.596264 21962 maintenance_manager.cc:419] P 7430a51c2f334c1dae46b69b3ae5dbd9: Scheduling FlushDeltaMemStoresOp(99f7be6dfd45498d8a795fc80dff849e): perf score=2.188937
I20260812 06:19:09.606916 21893 maintenance_manager.cc:643] P 7430a51c2f334c1dae46b69b3ae5dbd9: FlushDeltaMemStoresOp(99f7be6dfd45498d8a795fc80dff849e) complete. Timing: real 0.010s	user 0.008s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3909,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:09.607474 21962 maintenance_manager.cc:419] P 7430a51c2f334c1dae46b69b3ae5dbd9: Scheduling MajorDeltaCompactionOp(99f7be6dfd45498d8a795fc80dff849e): perf score=1.000000
I20260812 06:19:09.781857 21893 maintenance_manager.cc:643] P 7430a51c2f334c1dae46b69b3ae5dbd9: MajorDeltaCompactionOp(99f7be6dfd45498d8a795fc80dff849e) complete. Timing: real 0.174s	user 0.108s	sys 0.061s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774690,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":314,"lbm_read_time_us":11793,"lbm_reads_lt_1ms":572,"lbm_write_time_us":31304,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":542,"mutex_wait_us":31,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":4608,"update_count":2500}
I20260812 06:19:09.782625 21962 maintenance_manager.cc:419] P 7430a51c2f334c1dae46b69b3ae5dbd9: Scheduling FlushDeltaMemStoresOp(99f7be6dfd45498d8a795fc80dff849e): perf score=11.118625
I20260812 06:19:09.814917 21893 maintenance_manager.cc:643] P 7430a51c2f334c1dae46b69b3ae5dbd9: FlushDeltaMemStoresOp(99f7be6dfd45498d8a795fc80dff849e) complete. Timing: real 0.032s	user 0.017s	sys 0.013s Metrics: {"bytes_written":12717735,"delete_count":0,"lbm_write_time_us":13690,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:19:09.815560 21962 maintenance_manager.cc:419] P 7430a51c2f334c1dae46b69b3ae5dbd9: Scheduling FlushDeltaMemStoresOp(99f7be6dfd45498d8a795fc80dff849e): perf score=2.188937
I20260812 06:19:09.829865 21893 maintenance_manager.cc:643] P 7430a51c2f334c1dae46b69b3ae5dbd9: FlushDeltaMemStoresOp(99f7be6dfd45498d8a795fc80dff849e) complete. Timing: real 0.014s	user 0.007s	sys 0.004s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":4773,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:19:09.830381 21962 maintenance_manager.cc:419] P 7430a51c2f334c1dae46b69b3ae5dbd9: Scheduling MajorDeltaCompactionOp(99f7be6dfd45498d8a795fc80dff849e): perf score=1.000000
I20260812 06:19:09.959662 21893 maintenance_manager.cc:643] P 7430a51c2f334c1dae46b69b3ae5dbd9: MajorDeltaCompactionOp(99f7be6dfd45498d8a795fc80dff849e) complete. Timing: real 0.129s	user 0.112s	sys 0.016s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672268,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":562,"lbm_read_time_us":8869,"lbm_reads_lt_1ms":464,"lbm_write_time_us":25047,"lbm_writes_lt_1ms":443,"mutex_wait_us":281,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":9856,"update_count":2000}
I20260812 06:19:09.960223 21962 maintenance_manager.cc:419] P 7430a51c2f334c1dae46b69b3ae5dbd9: Scheduling FlushDeltaMemStoresOp(99f7be6dfd45498d8a795fc80dff849e): perf score=11.118625
I20260812 06:19:09.992082 21893 maintenance_manager.cc:643] P 7430a51c2f334c1dae46b69b3ae5dbd9: FlushDeltaMemStoresOp(99f7be6dfd45498d8a795fc80dff849e) complete. Timing: real 0.032s	user 0.012s	sys 0.016s Metrics: {"bytes_written":12717735,"delete_count":0,"lbm_write_time_us":13978,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:19:09.992698 21962 maintenance_manager.cc:419] P 7430a51c2f334c1dae46b69b3ae5dbd9: Scheduling FlushDeltaMemStoresOp(99f7be6dfd45498d8a795fc80dff849e): perf score=2.188937
I20260812 06:19:10.009234 21893 maintenance_manager.cc:643] P 7430a51c2f334c1dae46b69b3ae5dbd9: FlushDeltaMemStoresOp(99f7be6dfd45498d8a795fc80dff849e) complete. Timing: real 0.016s	user 0.006s	sys 0.008s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":5900,"lbm_writes_lt_1ms":93,"mutex_wait_us":1,"reinsert_count":0,"update_count":450}
I20260812 06:19:10.009676 21962 maintenance_manager.cc:419] P 7430a51c2f334c1dae46b69b3ae5dbd9: Scheduling MajorDeltaCompactionOp(99f7be6dfd45498d8a795fc80dff849e): perf score=1.000000
I20260812 06:19:10.129441 21893 maintenance_manager.cc:643] P 7430a51c2f334c1dae46b69b3ae5dbd9: MajorDeltaCompactionOp(99f7be6dfd45498d8a795fc80dff849e) complete. Timing: real 0.120s	user 0.111s	sys 0.008s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672268,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":655,"lbm_read_time_us":9481,"lbm_reads_lt_1ms":468,"lbm_write_time_us":22137,"lbm_writes_lt_1ms":443,"mutex_wait_us":100,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":2944,"update_count":2000}
I20260812 06:19:10.130167 21962 maintenance_manager.cc:419] P 7430a51c2f334c1dae46b69b3ae5dbd9: Scheduling FlushDeltaMemStoresOp(99f7be6dfd45498d8a795fc80dff849e): perf score=10.126437
I20260812 06:19:10.170094 21893 maintenance_manager.cc:643] P 7430a51c2f334c1dae46b69b3ae5dbd9: FlushDeltaMemStoresOp(99f7be6dfd45498d8a795fc80dff849e) complete. Timing: real 0.040s	user 0.008s	sys 0.029s Metrics: {"bytes_written":12307489,"delete_count":0,"lbm_write_time_us":19673,"lbm_writes_1-10_ms":4,"lbm_writes_lt_1ms":299,"reinsert_count":0,"update_count":1500}
I20260812 06:19:10.170614 21962 maintenance_manager.cc:419] P 7430a51c2f334c1dae46b69b3ae5dbd9: Scheduling FlushDeltaMemStoresOp(99f7be6dfd45498d8a795fc80dff849e): perf score=2.188937
I20260812 06:19:10.181738 21893 maintenance_manager.cc:643] P 7430a51c2f334c1dae46b69b3ae5dbd9: FlushDeltaMemStoresOp(99f7be6dfd45498d8a795fc80dff849e) complete. Timing: real 0.011s	user 0.005s	sys 0.005s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4028,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:10.182235 21962 maintenance_manager.cc:419] P 7430a51c2f334c1dae46b69b3ae5dbd9: Scheduling MajorDeltaCompactionOp(99f7be6dfd45498d8a795fc80dff849e): perf score=1.000000
I20260812 06:19:10.311476 21893 maintenance_manager.cc:643] P 7430a51c2f334c1dae46b69b3ae5dbd9: MajorDeltaCompactionOp(99f7be6dfd45498d8a795fc80dff849e) complete. Timing: real 0.129s	user 0.099s	sys 0.029s 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":802,"lbm_read_time_us":9184,"lbm_reads_lt_1ms":472,"lbm_write_time_us":26279,"lbm_writes_lt_1ms":443,"mutex_wait_us":281,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":2304,"update_count":2000}
I20260812 06:19:10.312142 21962 maintenance_manager.cc:419] P 7430a51c2f334c1dae46b69b3ae5dbd9: Scheduling FlushDeltaMemStoresOp(99f7be6dfd45498d8a795fc80dff849e): perf score=11.118625
I20260812 06:19:10.351276 21893 maintenance_manager.cc:643] P 7430a51c2f334c1dae46b69b3ae5dbd9: FlushDeltaMemStoresOp(99f7be6dfd45498d8a795fc80dff849e) complete. Timing: real 0.039s	user 0.019s	sys 0.017s Metrics: {"bytes_written":12635683,"delete_count":0,"lbm_write_time_us":13705,"lbm_writes_lt_1ms":311,"reinsert_count":0,"update_count":1540}
I20260812 06:19:10.351835 21962 maintenance_manager.cc:419] P 7430a51c2f334c1dae46b69b3ae5dbd9: Scheduling FlushDeltaMemStoresOp(99f7be6dfd45498d8a795fc80dff849e): perf score=2.188937
I20260812 06:19:10.361706 21893 maintenance_manager.cc:643] P 7430a51c2f334c1dae46b69b3ae5dbd9: FlushDeltaMemStoresOp(99f7be6dfd45498d8a795fc80dff849e) complete. Timing: real 0.010s	user 0.008s	sys 0.000s Metrics: {"bytes_written":3774459,"delete_count":0,"lbm_write_time_us":3717,"lbm_writes_lt_1ms":95,"reinsert_count":0,"update_count":460}
I20260812 06:19:10.362164 21962 maintenance_manager.cc:419] P 7430a51c2f334c1dae46b69b3ae5dbd9: Scheduling MajorDeltaCompactionOp(99f7be6dfd45498d8a795fc80dff849e): perf score=1.000000
I20260812 06:19:10.518204 21893 maintenance_manager.cc:643] P 7430a51c2f334c1dae46b69b3ae5dbd9: MajorDeltaCompactionOp(99f7be6dfd45498d8a795fc80dff849e) complete. Timing: real 0.156s	user 0.113s	sys 0.042s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672270,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":1094,"lbm_read_time_us":13388,"lbm_reads_lt_1ms":472,"lbm_write_time_us":24309,"lbm_writes_lt_1ms":443,"mutex_wait_us":301,"peak_mem_usage":50689328,"reinsert_count":0,"update_count":2000}
I20260812 06:19:10.518662 21962 maintenance_manager.cc:419] P 7430a51c2f334c1dae46b69b3ae5dbd9: Scheduling FlushDeltaMemStoresOp(99f7be6dfd45498d8a795fc80dff849e): perf score=10.126437
I20260812 06:19:10.567289 21893 maintenance_manager.cc:643] P 7430a51c2f334c1dae46b69b3ae5dbd9: FlushDeltaMemStoresOp(99f7be6dfd45498d8a795fc80dff849e) complete. Timing: real 0.048s	user 0.018s	sys 0.016s Metrics: {"bytes_written":12307493,"delete_count":0,"lbm_write_time_us":16602,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:19:10.567878 21962 maintenance_manager.cc:419] P 7430a51c2f334c1dae46b69b3ae5dbd9: Scheduling FlushDeltaMemStoresOp(99f7be6dfd45498d8a795fc80dff849e): perf score=2.188937
I20260812 06:19:10.578802 21893 maintenance_manager.cc:643] P 7430a51c2f334c1dae46b69b3ae5dbd9: FlushDeltaMemStoresOp(99f7be6dfd45498d8a795fc80dff849e) complete. Timing: real 0.011s	user 0.005s	sys 0.003s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4050,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:10.579298 21962 maintenance_manager.cc:419] P 7430a51c2f334c1dae46b69b3ae5dbd9: Scheduling FlushMRSOp(99f7be6dfd45498d8a795fc80dff849e): perf score=1.000000
I20260812 06:19:10.610241 21893 maintenance_manager.cc:643] P 7430a51c2f334c1dae46b69b3ae5dbd9: FlushMRSOp(99f7be6dfd45498d8a795fc80dff849e) complete. Timing: real 0.031s	user 0.026s	sys 0.003s Metrics: {"bytes_written":1234473,"cfile_init":1,"dirs.queue_time_us":76,"dirs.run_cpu_time_us":231,"dirs.run_wall_time_us":1242,"drs_written":1,"lbm_read_time_us":44,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1566,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":30}
I20260812 06:19:10.611023 21962 maintenance_manager.cc:419] P 7430a51c2f334c1dae46b69b3ae5dbd9: Scheduling LogGCOp(99f7be6dfd45498d8a795fc80dff849e): free 124710259 bytes of WAL
I20260812 06:19:10.611244 21893 log_reader.cc:385] T 99f7be6dfd45498d8a795fc80dff849e: removed 12 log segments from log reader
I20260812 06:19:10.611306 21893 log.cc:1079] T 99f7be6dfd45498d8a795fc80dff849e P 7430a51c2f334c1dae46b69b3ae5dbd9: Deleting log segment in path: /tmp/dist-test-taskw60Q2h/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515548711361-21775-0/minicluster-data/ts-0-root/wals/99f7be6dfd45498d8a795fc80dff849e/wal-000000003 (ops 12-16)
I20260812 06:19:10.611358 21893 log.cc:1079] T 99f7be6dfd45498d8a795fc80dff849e P 7430a51c2f334c1dae46b69b3ae5dbd9: Deleting log segment in path: /tmp/dist-test-taskw60Q2h/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515548711361-21775-0/minicluster-data/ts-0-root/wals/99f7be6dfd45498d8a795fc80dff849e/wal-000000004 (ops 17-21)
I20260812 06:19:10.611415 21893 log.cc:1079] T 99f7be6dfd45498d8a795fc80dff849e P 7430a51c2f334c1dae46b69b3ae5dbd9: Deleting log segment in path: /tmp/dist-test-taskw60Q2h/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515548711361-21775-0/minicluster-data/ts-0-root/wals/99f7be6dfd45498d8a795fc80dff849e/wal-000000005 (ops 22-26)
I20260812 06:19:10.611456 21893 log.cc:1079] T 99f7be6dfd45498d8a795fc80dff849e P 7430a51c2f334c1dae46b69b3ae5dbd9: Deleting log segment in path: /tmp/dist-test-taskw60Q2h/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515548711361-21775-0/minicluster-data/ts-0-root/wals/99f7be6dfd45498d8a795fc80dff849e/wal-000000006 (ops 27-31)
I20260812 06:19:10.611491 21893 log.cc:1079] T 99f7be6dfd45498d8a795fc80dff849e P 7430a51c2f334c1dae46b69b3ae5dbd9: Deleting log segment in path: /tmp/dist-test-taskw60Q2h/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515548711361-21775-0/minicluster-data/ts-0-root/wals/99f7be6dfd45498d8a795fc80dff849e/wal-000000007 (ops 32-36)
I20260812 06:19:10.611526 21893 log.cc:1079] T 99f7be6dfd45498d8a795fc80dff849e P 7430a51c2f334c1dae46b69b3ae5dbd9: Deleting log segment in path: /tmp/dist-test-taskw60Q2h/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515548711361-21775-0/minicluster-data/ts-0-root/wals/99f7be6dfd45498d8a795fc80dff849e/wal-000000008 (ops 37-41)
I20260812 06:19:10.611567 21893 log.cc:1079] T 99f7be6dfd45498d8a795fc80dff849e P 7430a51c2f334c1dae46b69b3ae5dbd9: Deleting log segment in path: /tmp/dist-test-taskw60Q2h/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515548711361-21775-0/minicluster-data/ts-0-root/wals/99f7be6dfd45498d8a795fc80dff849e/wal-000000009 (ops 42-46)
I20260812 06:19:10.611605 21893 log.cc:1079] T 99f7be6dfd45498d8a795fc80dff849e P 7430a51c2f334c1dae46b69b3ae5dbd9: Deleting log segment in path: /tmp/dist-test-taskw60Q2h/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515548711361-21775-0/minicluster-data/ts-0-root/wals/99f7be6dfd45498d8a795fc80dff849e/wal-000000010 (ops 47-51)
I20260812 06:19:10.611642 21893 log.cc:1079] T 99f7be6dfd45498d8a795fc80dff849e P 7430a51c2f334c1dae46b69b3ae5dbd9: Deleting log segment in path: /tmp/dist-test-taskw60Q2h/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515548711361-21775-0/minicluster-data/ts-0-root/wals/99f7be6dfd45498d8a795fc80dff849e/wal-000000011 (ops 52-56)
I20260812 06:19:10.611680 21893 log.cc:1079] T 99f7be6dfd45498d8a795fc80dff849e P 7430a51c2f334c1dae46b69b3ae5dbd9: Deleting log segment in path: /tmp/dist-test-taskw60Q2h/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515548711361-21775-0/minicluster-data/ts-0-root/wals/99f7be6dfd45498d8a795fc80dff849e/wal-000000012 (ops 57-61)
I20260812 06:19:10.611716 21893 log.cc:1079] T 99f7be6dfd45498d8a795fc80dff849e P 7430a51c2f334c1dae46b69b3ae5dbd9: Deleting log segment in path: /tmp/dist-test-taskw60Q2h/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515548711361-21775-0/minicluster-data/ts-0-root/wals/99f7be6dfd45498d8a795fc80dff849e/wal-000000013 (ops 62-66)
I20260812 06:19:10.611750 21893 log.cc:1079] T 99f7be6dfd45498d8a795fc80dff849e P 7430a51c2f334c1dae46b69b3ae5dbd9: Deleting log segment in path: /tmp/dist-test-taskw60Q2h/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515548711361-21775-0/minicluster-data/ts-0-root/wals/99f7be6dfd45498d8a795fc80dff849e/wal-000000014 (ops 67-71)
I20260812 06:19:10.641057 21893 maintenance_manager.cc:643] P 7430a51c2f334c1dae46b69b3ae5dbd9: LogGCOp(99f7be6dfd45498d8a795fc80dff849e) complete. Timing: real 0.030s	user 0.000s	sys 0.029s Metrics: {}
I20260812 06:19:10.641441 21962 maintenance_manager.cc:419] P 7430a51c2f334c1dae46b69b3ae5dbd9: Scheduling UndoDeltaBlockGCOp(99f7be6dfd45498d8a795fc80dff849e): 472 bytes on disk
I20260812 06:19:10.641919 21893 maintenance_manager.cc:643] P 7430a51c2f334c1dae46b69b3ae5dbd9: UndoDeltaBlockGCOp(99f7be6dfd45498d8a795fc80dff849e) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":69,"lbm_reads_lt_1ms":4}
I20260812 06:19:10.642401 21962 maintenance_manager.cc:419] P 7430a51c2f334c1dae46b69b3ae5dbd9: Scheduling FlushDeltaMemStoresOp(99f7be6dfd45498d8a795fc80dff849e): perf score=3.181125
I20260812 06:19:10.667605 21893 maintenance_manager.cc:643] P 7430a51c2f334c1dae46b69b3ae5dbd9: FlushDeltaMemStoresOp(99f7be6dfd45498d8a795fc80dff849e) complete. Timing: real 0.025s	user 0.014s	sys 0.007s Metrics: {"bytes_written":4553930,"delete_count":0,"lbm_write_time_us":6969,"lbm_writes_lt_1ms":114,"reinsert_count":0,"update_count":555}
I20260812 06:19:10.668040 21962 maintenance_manager.cc:419] P 7430a51c2f334c1dae46b69b3ae5dbd9: Scheduling FlushDeltaMemStoresOp(99f7be6dfd45498d8a795fc80dff849e): perf score=2.188937
I20260812 06:19:10.677472 21893 maintenance_manager.cc:643] P 7430a51c2f334c1dae46b69b3ae5dbd9: FlushDeltaMemStoresOp(99f7be6dfd45498d8a795fc80dff849e) complete. Timing: real 0.009s	user 0.007s	sys 0.001s Metrics: {"bytes_written":3651380,"delete_count":0,"lbm_write_time_us":3523,"lbm_writes_lt_1ms":92,"reinsert_count":0,"update_count":445}
I20260812 06:19:10.677945 21962 maintenance_manager.cc:419] P 7430a51c2f334c1dae46b69b3ae5dbd9: Scheduling MajorDeltaCompactionOp(99f7be6dfd45498d8a795fc80dff849e): perf score=1.000000
I20260812 06:19:10.872411 21893 maintenance_manager.cc:643] P 7430a51c2f334c1dae46b69b3ae5dbd9: MajorDeltaCompactionOp(99f7be6dfd45498d8a795fc80dff849e) complete. Timing: real 0.194s	user 0.129s	sys 0.064s Metrics: {"cfile_cache_miss":634,"cfile_cache_miss_bytes":28877334,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":2648,"lbm_read_time_us":14923,"lbm_reads_lt_1ms":674,"lbm_write_time_us":33590,"lbm_writes_lt_1ms":643,"mutex_wait_us":1679,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":11520,"thread_start_us":78,"threads_started":1,"update_count":3000}
I20260812 06:19:10.873082 21962 maintenance_manager.cc:419] P 7430a51c2f334c1dae46b69b3ae5dbd9: Scheduling FlushDeltaMemStoresOp(99f7be6dfd45498d8a795fc80dff849e): perf score=11.118625
I20260812 06:19:10.914081 21893 maintenance_manager.cc:643] P 7430a51c2f334c1dae46b69b3ae5dbd9: FlushDeltaMemStoresOp(99f7be6dfd45498d8a795fc80dff849e) complete. Timing: real 0.041s	user 0.025s	sys 0.012s Metrics: {"bytes_written":12717736,"delete_count":0,"lbm_write_time_us":18322,"lbm_writes_1-10_ms":2,"lbm_writes_lt_1ms":311,"reinsert_count":0,"update_count":1550}
I20260812 06:19:10.914701 21962 maintenance_manager.cc:419] P 7430a51c2f334c1dae46b69b3ae5dbd9: Scheduling FlushDeltaMemStoresOp(99f7be6dfd45498d8a795fc80dff849e): perf score=2.188937
I20260812 06:19:10.935387 21893 maintenance_manager.cc:643] P 7430a51c2f334c1dae46b69b3ae5dbd9: FlushDeltaMemStoresOp(99f7be6dfd45498d8a795fc80dff849e) complete. Timing: real 0.021s	user 0.011s	sys 0.001s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4161,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:10.935966 21962 maintenance_manager.cc:419] P 7430a51c2f334c1dae46b69b3ae5dbd9: Scheduling FlushDeltaMemStoresOp(99f7be6dfd45498d8a795fc80dff849e): perf score=2.188937
I20260812 06:19:10.950289 21893 maintenance_manager.cc:643] P 7430a51c2f334c1dae46b69b3ae5dbd9: FlushDeltaMemStoresOp(99f7be6dfd45498d8a795fc80dff849e) complete. Timing: real 0.014s	user 0.007s	sys 0.005s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":5259,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:19:10.950927 21962 maintenance_manager.cc:419] P 7430a51c2f334c1dae46b69b3ae5dbd9: Scheduling MajorDeltaCompactionOp(99f7be6dfd45498d8a795fc80dff849e): perf score=1.000000
I20260812 06:19:11.126762 21893 maintenance_manager.cc:643] P 7430a51c2f334c1dae46b69b3ae5dbd9: MajorDeltaCompactionOp(99f7be6dfd45498d8a795fc80dff849e) complete. Timing: real 0.176s	user 0.086s	sys 0.087s 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":1114,"lbm_read_time_us":12738,"lbm_reads_lt_1ms":573,"lbm_write_time_us":30271,"lbm_writes_lt_1ms":543,"mutex_wait_us":304,"peak_mem_usage":63115900,"reinsert_count":0,"update_count":2500}
I20260812 06:19:11.130163 21962 maintenance_manager.cc:419] P 7430a51c2f334c1dae46b69b3ae5dbd9: Scheduling FlushDeltaMemStoresOp(99f7be6dfd45498d8a795fc80dff849e): perf score=11.118625
I20260812 06:19:11.169106 21893 maintenance_manager.cc:643] P 7430a51c2f334c1dae46b69b3ae5dbd9: FlushDeltaMemStoresOp(99f7be6dfd45498d8a795fc80dff849e) complete. Timing: real 0.039s	user 0.018s	sys 0.019s Metrics: {"bytes_written":13333097,"delete_count":0,"lbm_write_time_us":16881,"lbm_writes_lt_1ms":328,"reinsert_count":0,"update_count":1625}
I20260812 06:19:11.169615 21962 maintenance_manager.cc:419] P 7430a51c2f334c1dae46b69b3ae5dbd9: Scheduling FlushDeltaMemStoresOp(99f7be6dfd45498d8a795fc80dff849e): perf score=2.188937
I20260812 06:19:11.188072 21893 maintenance_manager.cc:643] P 7430a51c2f334c1dae46b69b3ae5dbd9: FlushDeltaMemStoresOp(99f7be6dfd45498d8a795fc80dff849e) complete. Timing: real 0.018s	user 0.000s	sys 0.008s Metrics: {"bytes_written":3487285,"delete_count":0,"lbm_write_time_us":3718,"lbm_writes_lt_1ms":88,"reinsert_count":0,"update_count":425}
I20260812 06:19:11.188587 21962 maintenance_manager.cc:419] P 7430a51c2f334c1dae46b69b3ae5dbd9: Scheduling FlushDeltaMemStoresOp(99f7be6dfd45498d8a795fc80dff849e): perf score=2.188937
I20260812 06:19:11.206157 21893 maintenance_manager.cc:643] P 7430a51c2f334c1dae46b69b3ae5dbd9: FlushDeltaMemStoresOp(99f7be6dfd45498d8a795fc80dff849e) complete. Timing: real 0.017s	user 0.007s	sys 0.009s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3463,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:19:11.206694 21962 maintenance_manager.cc:419] P 7430a51c2f334c1dae46b69b3ae5dbd9: Scheduling MajorDeltaCompactionOp(99f7be6dfd45498d8a795fc80dff849e): perf score=1.000000
I20260812 06:19:11.387616 21893 maintenance_manager.cc:643] P 7430a51c2f334c1dae46b69b3ae5dbd9: MajorDeltaCompactionOp(99f7be6dfd45498d8a795fc80dff849e) complete. Timing: real 0.181s	user 0.117s	sys 0.057s Metrics: {"cfile_cache_miss":533,"cfile_cache_miss_bytes":24774787,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":288,"lbm_read_time_us":12661,"lbm_reads_lt_1ms":573,"lbm_write_time_us":30185,"lbm_writes_lt_1ms":543,"mutex_wait_us":50,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":7936,"update_count":2500}
I20260812 06:19:11.388338 21962 maintenance_manager.cc:419] P 7430a51c2f334c1dae46b69b3ae5dbd9: Scheduling FlushDeltaMemStoresOp(99f7be6dfd45498d8a795fc80dff849e): perf score=14.095187
I20260812 06:19:11.438786 21893 maintenance_manager.cc:643] P 7430a51c2f334c1dae46b69b3ae5dbd9: FlushDeltaMemStoresOp(99f7be6dfd45498d8a795fc80dff849e) complete. Timing: real 0.050s	user 0.031s	sys 0.013s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":21026,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:11.439276 21962 maintenance_manager.cc:419] P 7430a51c2f334c1dae46b69b3ae5dbd9: Scheduling FlushDeltaMemStoresOp(99f7be6dfd45498d8a795fc80dff849e): perf score=2.188937
I20260812 06:19:11.451027 21893 maintenance_manager.cc:643] P 7430a51c2f334c1dae46b69b3ae5dbd9: FlushDeltaMemStoresOp(99f7be6dfd45498d8a795fc80dff849e) complete. Timing: real 0.012s	user 0.002s	sys 0.007s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4364,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:11.451476 21962 maintenance_manager.cc:419] P 7430a51c2f334c1dae46b69b3ae5dbd9: Scheduling MajorDeltaCompactionOp(99f7be6dfd45498d8a795fc80dff849e): perf score=1.000000
I20260812 06:19:11.660274 21893 maintenance_manager.cc:643] P 7430a51c2f334c1dae46b69b3ae5dbd9: MajorDeltaCompactionOp(99f7be6dfd45498d8a795fc80dff849e) complete. Timing: real 0.209s	user 0.140s	sys 0.051s 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":345,"lbm_read_time_us":10479,"lbm_reads_lt_1ms":572,"lbm_write_time_us":36959,"lbm_writes_lt_1ms":543,"mutex_wait_us":43,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":25216,"update_count":2500}
I20260812 06:19:11.660764 21962 maintenance_manager.cc:419] P 7430a51c2f334c1dae46b69b3ae5dbd9: Scheduling FlushDeltaMemStoresOp(99f7be6dfd45498d8a795fc80dff849e): perf score=14.095187
I20260812 06:19:11.712692 21893 maintenance_manager.cc:643] P 7430a51c2f334c1dae46b69b3ae5dbd9: FlushDeltaMemStoresOp(99f7be6dfd45498d8a795fc80dff849e) complete. Timing: real 0.052s	user 0.024s	sys 0.024s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":21770,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:11.713202 21962 maintenance_manager.cc:419] P 7430a51c2f334c1dae46b69b3ae5dbd9: Scheduling FlushDeltaMemStoresOp(99f7be6dfd45498d8a795fc80dff849e): perf score=2.188937
I20260812 06:19:11.728922 21893 maintenance_manager.cc:643] P 7430a51c2f334c1dae46b69b3ae5dbd9: FlushDeltaMemStoresOp(99f7be6dfd45498d8a795fc80dff849e) complete. Timing: real 0.016s	user 0.007s	sys 0.008s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":5876,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:11.729485 21962 maintenance_manager.cc:419] P 7430a51c2f334c1dae46b69b3ae5dbd9: Scheduling MajorDeltaCompactionOp(99f7be6dfd45498d8a795fc80dff849e): perf score=1.000000
I20260812 06:19:11.870030 21893 maintenance_manager.cc:643] P 7430a51c2f334c1dae46b69b3ae5dbd9: MajorDeltaCompactionOp(99f7be6dfd45498d8a795fc80dff849e) complete. Timing: real 0.139s	user 0.127s	sys 0.012s 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":324,"lbm_read_time_us":9268,"lbm_reads_lt_1ms":572,"lbm_write_time_us":29897,"lbm_writes_lt_1ms":543,"mutex_wait_us":67,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":20864,"update_count":2500}
I20260812 06:19:11.870601 21962 maintenance_manager.cc:419] P 7430a51c2f334c1dae46b69b3ae5dbd9: Scheduling FlushDeltaMemStoresOp(99f7be6dfd45498d8a795fc80dff849e): perf score=11.118625
I20260812 06:19:11.904430 21893 maintenance_manager.cc:643] P 7430a51c2f334c1dae46b69b3ae5dbd9: FlushDeltaMemStoresOp(99f7be6dfd45498d8a795fc80dff849e) complete. Timing: real 0.034s	user 0.010s	sys 0.023s Metrics: {"bytes_written":12717735,"delete_count":0,"lbm_write_time_us":15257,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:19:11.904969 21962 maintenance_manager.cc:419] P 7430a51c2f334c1dae46b69b3ae5dbd9: Scheduling FlushDeltaMemStoresOp(99f7be6dfd45498d8a795fc80dff849e): perf score=2.188937
I20260812 06:19:11.921237 21893 maintenance_manager.cc:643] P 7430a51c2f334c1dae46b69b3ae5dbd9: FlushDeltaMemStoresOp(99f7be6dfd45498d8a795fc80dff849e) complete. Timing: real 0.016s	user 0.005s	sys 0.008s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":5058,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:19:11.922250 21962 maintenance_manager.cc:419] P 7430a51c2f334c1dae46b69b3ae5dbd9: Scheduling MajorDeltaCompactionOp(99f7be6dfd45498d8a795fc80dff849e): perf score=1.000000
I20260812 06:19:12.042716 21893 maintenance_manager.cc:643] P 7430a51c2f334c1dae46b69b3ae5dbd9: MajorDeltaCompactionOp(99f7be6dfd45498d8a795fc80dff849e) complete. Timing: real 0.120s	user 0.105s	sys 0.015s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672268,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":165,"lbm_read_time_us":7665,"lbm_reads_lt_1ms":464,"lbm_write_time_us":23974,"lbm_writes_lt_1ms":443,"mutex_wait_us":23,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":7936,"update_count":2000}
I20260812 06:19:12.043507 21962 maintenance_manager.cc:419] P 7430a51c2f334c1dae46b69b3ae5dbd9: Scheduling FlushDeltaMemStoresOp(99f7be6dfd45498d8a795fc80dff849e): perf score=10.126437
I20260812 06:19:12.096781 21893 maintenance_manager.cc:643] P 7430a51c2f334c1dae46b69b3ae5dbd9: FlushDeltaMemStoresOp(99f7be6dfd45498d8a795fc80dff849e) complete. Timing: real 0.053s	user 0.038s	sys 0.008s Metrics: {"bytes_written":12307489,"delete_count":0,"lbm_write_time_us":23491,"lbm_writes_1-10_ms":2,"lbm_writes_lt_1ms":301,"reinsert_count":0,"update_count":1500}
I20260812 06:19:12.097497 21962 maintenance_manager.cc:419] P 7430a51c2f334c1dae46b69b3ae5dbd9: Scheduling FlushDeltaMemStoresOp(99f7be6dfd45498d8a795fc80dff849e): perf score=2.188937
I20260812 06:19:12.119342 21893 maintenance_manager.cc:643] P 7430a51c2f334c1dae46b69b3ae5dbd9: FlushDeltaMemStoresOp(99f7be6dfd45498d8a795fc80dff849e) complete. Timing: real 0.022s	user 0.012s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6683,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:12.119880 21962 maintenance_manager.cc:419] P 7430a51c2f334c1dae46b69b3ae5dbd9: Scheduling FlushMRSOp(99f7be6dfd45498d8a795fc80dff849e): perf score=1.000000
I20260812 06:19:12.152091 21893 maintenance_manager.cc:643] P 7430a51c2f334c1dae46b69b3ae5dbd9: FlushMRSOp(99f7be6dfd45498d8a795fc80dff849e) complete. Timing: real 0.032s	user 0.030s	sys 0.000s Metrics: {"bytes_written":1234479,"cfile_init":1,"dirs.queue_time_us":70,"dirs.run_cpu_time_us":205,"dirs.run_wall_time_us":1428,"drs_written":1,"lbm_read_time_us":46,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1462,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":30}
I20260812 06:19:12.152925 21962 maintenance_manager.cc:419] P 7430a51c2f334c1dae46b69b3ae5dbd9: Scheduling LogGCOp(99f7be6dfd45498d8a795fc80dff849e): free 124710373 bytes of WAL
I20260812 06:19:12.153178 21893 log_reader.cc:385] T 99f7be6dfd45498d8a795fc80dff849e: removed 12 log segments from log reader
I20260812 06:19:12.153227 21893 log.cc:1079] T 99f7be6dfd45498d8a795fc80dff849e P 7430a51c2f334c1dae46b69b3ae5dbd9: Deleting log segment in path: /tmp/dist-test-taskw60Q2h/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515548711361-21775-0/minicluster-data/ts-0-root/wals/99f7be6dfd45498d8a795fc80dff849e/wal-000000015 (ops 72-76)
I20260812 06:19:12.153257 21893 log.cc:1079] T 99f7be6dfd45498d8a795fc80dff849e P 7430a51c2f334c1dae46b69b3ae5dbd9: Deleting log segment in path: /tmp/dist-test-taskw60Q2h/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515548711361-21775-0/minicluster-data/ts-0-root/wals/99f7be6dfd45498d8a795fc80dff849e/wal-000000016 (ops 77-81)
I20260812 06:19:12.153296 21893 log.cc:1079] T 99f7be6dfd45498d8a795fc80dff849e P 7430a51c2f334c1dae46b69b3ae5dbd9: Deleting log segment in path: /tmp/dist-test-taskw60Q2h/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515548711361-21775-0/minicluster-data/ts-0-root/wals/99f7be6dfd45498d8a795fc80dff849e/wal-000000017 (ops 82-86)
I20260812 06:19:12.153342 21893 log.cc:1079] T 99f7be6dfd45498d8a795fc80dff849e P 7430a51c2f334c1dae46b69b3ae5dbd9: Deleting log segment in path: /tmp/dist-test-taskw60Q2h/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515548711361-21775-0/minicluster-data/ts-0-root/wals/99f7be6dfd45498d8a795fc80dff849e/wal-000000018 (ops 87-91)
I20260812 06:19:12.153369 21893 log.cc:1079] T 99f7be6dfd45498d8a795fc80dff849e P 7430a51c2f334c1dae46b69b3ae5dbd9: Deleting log segment in path: /tmp/dist-test-taskw60Q2h/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515548711361-21775-0/minicluster-data/ts-0-root/wals/99f7be6dfd45498d8a795fc80dff849e/wal-000000019 (ops 92-96)
I20260812 06:19:12.153422 21893 log.cc:1079] T 99f7be6dfd45498d8a795fc80dff849e P 7430a51c2f334c1dae46b69b3ae5dbd9: Deleting log segment in path: /tmp/dist-test-taskw60Q2h/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515548711361-21775-0/minicluster-data/ts-0-root/wals/99f7be6dfd45498d8a795fc80dff849e/wal-000000020 (ops 97-101)
I20260812 06:19:12.153460 21893 log.cc:1079] T 99f7be6dfd45498d8a795fc80dff849e P 7430a51c2f334c1dae46b69b3ae5dbd9: Deleting log segment in path: /tmp/dist-test-taskw60Q2h/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515548711361-21775-0/minicluster-data/ts-0-root/wals/99f7be6dfd45498d8a795fc80dff849e/wal-000000021 (ops 102-106)
I20260812 06:19:12.153515 21893 log.cc:1079] T 99f7be6dfd45498d8a795fc80dff849e P 7430a51c2f334c1dae46b69b3ae5dbd9: Deleting log segment in path: /tmp/dist-test-taskw60Q2h/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515548711361-21775-0/minicluster-data/ts-0-root/wals/99f7be6dfd45498d8a795fc80dff849e/wal-000000022 (ops 107-111)
I20260812 06:19:12.153560 21893 log.cc:1079] T 99f7be6dfd45498d8a795fc80dff849e P 7430a51c2f334c1dae46b69b3ae5dbd9: Deleting log segment in path: /tmp/dist-test-taskw60Q2h/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515548711361-21775-0/minicluster-data/ts-0-root/wals/99f7be6dfd45498d8a795fc80dff849e/wal-000000023 (ops 112-116)
I20260812 06:19:12.153607 21893 log.cc:1079] T 99f7be6dfd45498d8a795fc80dff849e P 7430a51c2f334c1dae46b69b3ae5dbd9: Deleting log segment in path: /tmp/dist-test-taskw60Q2h/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515548711361-21775-0/minicluster-data/ts-0-root/wals/99f7be6dfd45498d8a795fc80dff849e/wal-000000024 (ops 117-121)
I20260812 06:19:12.153648 21893 log.cc:1079] T 99f7be6dfd45498d8a795fc80dff849e P 7430a51c2f334c1dae46b69b3ae5dbd9: Deleting log segment in path: /tmp/dist-test-taskw60Q2h/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515548711361-21775-0/minicluster-data/ts-0-root/wals/99f7be6dfd45498d8a795fc80dff849e/wal-000000025 (ops 122-126)
I20260812 06:19:12.153692 21893 log.cc:1079] T 99f7be6dfd45498d8a795fc80dff849e P 7430a51c2f334c1dae46b69b3ae5dbd9: Deleting log segment in path: /tmp/dist-test-taskw60Q2h/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515548711361-21775-0/minicluster-data/ts-0-root/wals/99f7be6dfd45498d8a795fc80dff849e/wal-000000026 (ops 127-131)
I20260812 06:19:12.181553 21893 maintenance_manager.cc:643] P 7430a51c2f334c1dae46b69b3ae5dbd9: LogGCOp(99f7be6dfd45498d8a795fc80dff849e) complete. Timing: real 0.028s	user 0.001s	sys 0.027s Metrics: {}
I20260812 06:19:12.181975 21962 maintenance_manager.cc:419] P 7430a51c2f334c1dae46b69b3ae5dbd9: Scheduling UndoDeltaBlockGCOp(99f7be6dfd45498d8a795fc80dff849e): 472 bytes on disk
I20260812 06:19:12.182458 21893 maintenance_manager.cc:643] P 7430a51c2f334c1dae46b69b3ae5dbd9: UndoDeltaBlockGCOp(99f7be6dfd45498d8a795fc80dff849e) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":63,"lbm_reads_lt_1ms":4}
I20260812 06:19:12.182988 21962 maintenance_manager.cc:419] P 7430a51c2f334c1dae46b69b3ae5dbd9: Scheduling FlushDeltaMemStoresOp(99f7be6dfd45498d8a795fc80dff849e): perf score=6.157687
I20260812 06:19:12.210777 21893 maintenance_manager.cc:643] P 7430a51c2f334c1dae46b69b3ae5dbd9: FlushDeltaMemStoresOp(99f7be6dfd45498d8a795fc80dff849e) complete. Timing: real 0.028s	user 0.016s	sys 0.004s Metrics: {"bytes_written":8205078,"delete_count":0,"lbm_write_time_us":9789,"lbm_writes_lt_1ms":203,"reinsert_count":0,"update_count":1000}
I20260812 06:19:12.211349 21962 maintenance_manager.cc:419] P 7430a51c2f334c1dae46b69b3ae5dbd9: Scheduling MajorDeltaCompactionOp(99f7be6dfd45498d8a795fc80dff849e): perf score=1.000000
I20260812 06:19:12.389127 21893 maintenance_manager.cc:643] P 7430a51c2f334c1dae46b69b3ae5dbd9: MajorDeltaCompactionOp(99f7be6dfd45498d8a795fc80dff849e) complete. Timing: real 0.178s	user 0.122s	sys 0.056s Metrics: {"cfile_cache_miss":633,"cfile_cache_miss_bytes":28877220,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":503,"lbm_read_time_us":12685,"lbm_reads_lt_1ms":665,"lbm_write_time_us":37789,"lbm_writes_lt_1ms":643,"mutex_wait_us":51,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":12928,"thread_start_us":88,"threads_started":1,"update_count":3000}
I20260812 06:19:12.389814 21962 maintenance_manager.cc:419] P 7430a51c2f334c1dae46b69b3ae5dbd9: Scheduling FlushDeltaMemStoresOp(99f7be6dfd45498d8a795fc80dff849e): perf score=14.095187
I20260812 06:19:12.432519 21893 maintenance_manager.cc:643] P 7430a51c2f334c1dae46b69b3ae5dbd9: FlushDeltaMemStoresOp(99f7be6dfd45498d8a795fc80dff849e) complete. Timing: real 0.043s	user 0.019s	sys 0.023s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":19432,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:12.433032 21962 maintenance_manager.cc:419] P 7430a51c2f334c1dae46b69b3ae5dbd9: Scheduling FlushDeltaMemStoresOp(99f7be6dfd45498d8a795fc80dff849e): perf score=2.188937
I20260812 06:19:12.446854 21893 maintenance_manager.cc:643] P 7430a51c2f334c1dae46b69b3ae5dbd9: FlushDeltaMemStoresOp(99f7be6dfd45498d8a795fc80dff849e) complete. Timing: real 0.014s	user 0.001s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4031,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:12.447369 21962 maintenance_manager.cc:419] P 7430a51c2f334c1dae46b69b3ae5dbd9: Scheduling MajorDeltaCompactionOp(99f7be6dfd45498d8a795fc80dff849e): perf score=1.000000
I20260812 06:19:12.601954 21893 maintenance_manager.cc:643] P 7430a51c2f334c1dae46b69b3ae5dbd9: MajorDeltaCompactionOp(99f7be6dfd45498d8a795fc80dff849e) complete. Timing: real 0.154s	user 0.124s	sys 0.026s 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":911,"lbm_read_time_us":9634,"lbm_reads_lt_1ms":564,"lbm_write_time_us":29902,"lbm_writes_lt_1ms":543,"mutex_wait_us":107,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":44416,"update_count":2500}
I20260812 06:19:12.602540 21962 maintenance_manager.cc:419] P 7430a51c2f334c1dae46b69b3ae5dbd9: Scheduling FlushDeltaMemStoresOp(99f7be6dfd45498d8a795fc80dff849e): perf score=14.095187
I20260812 06:19:12.669359 21893 maintenance_manager.cc:643] P 7430a51c2f334c1dae46b69b3ae5dbd9: FlushDeltaMemStoresOp(99f7be6dfd45498d8a795fc80dff849e) complete. Timing: real 0.067s	user 0.022s	sys 0.028s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":24033,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:12.669938 21962 maintenance_manager.cc:419] P 7430a51c2f334c1dae46b69b3ae5dbd9: Scheduling FlushDeltaMemStoresOp(99f7be6dfd45498d8a795fc80dff849e): perf score=2.188937
I20260812 06:19:12.680840 21893 maintenance_manager.cc:643] P 7430a51c2f334c1dae46b69b3ae5dbd9: FlushDeltaMemStoresOp(99f7be6dfd45498d8a795fc80dff849e) complete. Timing: real 0.011s	user 0.006s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3903,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:12.681504 21962 maintenance_manager.cc:419] P 7430a51c2f334c1dae46b69b3ae5dbd9: Scheduling MajorDeltaCompactionOp(99f7be6dfd45498d8a795fc80dff849e): perf score=1.000000
I20260812 06:19:12.850808 21893 maintenance_manager.cc:643] P 7430a51c2f334c1dae46b69b3ae5dbd9: MajorDeltaCompactionOp(99f7be6dfd45498d8a795fc80dff849e) complete. Timing: real 0.169s	user 0.123s	sys 0.045s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774688,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":135,"lbm_read_time_us":12491,"lbm_reads_lt_1ms":572,"lbm_write_time_us":28176,"lbm_writes_lt_1ms":543,"mutex_wait_us":23,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":4864,"update_count":2500}
I20260812 06:19:12.851567 21962 maintenance_manager.cc:419] P 7430a51c2f334c1dae46b69b3ae5dbd9: Scheduling FlushDeltaMemStoresOp(99f7be6dfd45498d8a795fc80dff849e): perf score=14.095187
I20260812 06:19:12.910383 21893 maintenance_manager.cc:643] P 7430a51c2f334c1dae46b69b3ae5dbd9: FlushDeltaMemStoresOp(99f7be6dfd45498d8a795fc80dff849e) complete. Timing: real 0.058s	user 0.046s	sys 0.003s Metrics: {"bytes_written":16409900,"delete_count":0,"lbm_write_time_us":21965,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:12.910904 21962 maintenance_manager.cc:419] P 7430a51c2f334c1dae46b69b3ae5dbd9: Scheduling FlushDeltaMemStoresOp(99f7be6dfd45498d8a795fc80dff849e): perf score=2.188937
I20260812 06:19:12.922241 21893 maintenance_manager.cc:643] P 7430a51c2f334c1dae46b69b3ae5dbd9: FlushDeltaMemStoresOp(99f7be6dfd45498d8a795fc80dff849e) complete. Timing: real 0.011s	user 0.009s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4165,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:12.922830 21962 maintenance_manager.cc:419] P 7430a51c2f334c1dae46b69b3ae5dbd9: Scheduling MajorDeltaCompactionOp(99f7be6dfd45498d8a795fc80dff849e): perf score=1.000000
I20260812 06:19:13.103600 21893 maintenance_manager.cc:643] P 7430a51c2f334c1dae46b69b3ae5dbd9: MajorDeltaCompactionOp(99f7be6dfd45498d8a795fc80dff849e) complete. Timing: real 0.179s	user 0.128s	sys 0.046s 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":948,"lbm_read_time_us":13175,"lbm_reads_lt_1ms":572,"lbm_write_time_us":30186,"lbm_writes_lt_1ms":543,"mutex_wait_us":341,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":896,"update_count":2500}
I20260812 06:19:13.104364 21962 maintenance_manager.cc:419] P 7430a51c2f334c1dae46b69b3ae5dbd9: Scheduling FlushDeltaMemStoresOp(99f7be6dfd45498d8a795fc80dff849e): perf score=14.095187
I20260812 06:19:13.166414 21893 maintenance_manager.cc:643] P 7430a51c2f334c1dae46b69b3ae5dbd9: FlushDeltaMemStoresOp(99f7be6dfd45498d8a795fc80dff849e) complete. Timing: real 0.062s	user 0.029s	sys 0.031s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":23325,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":402,"reinsert_count":0,"update_count":2000}
I20260812 06:19:13.166981 21962 maintenance_manager.cc:419] P 7430a51c2f334c1dae46b69b3ae5dbd9: Scheduling FlushDeltaMemStoresOp(99f7be6dfd45498d8a795fc80dff849e): perf score=2.188937
I20260812 06:19:13.177927 21893 maintenance_manager.cc:643] P 7430a51c2f334c1dae46b69b3ae5dbd9: FlushDeltaMemStoresOp(99f7be6dfd45498d8a795fc80dff849e) complete. Timing: real 0.011s	user 0.001s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4058,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:13.178363 21962 maintenance_manager.cc:419] P 7430a51c2f334c1dae46b69b3ae5dbd9: Scheduling MajorDeltaCompactionOp(99f7be6dfd45498d8a795fc80dff849e): perf score=1.000000
I20260812 06:19:13.359658 21893 maintenance_manager.cc:643] P 7430a51c2f334c1dae46b69b3ae5dbd9: MajorDeltaCompactionOp(99f7be6dfd45498d8a795fc80dff849e) complete. Timing: real 0.181s	user 0.100s	sys 0.076s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774688,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":197,"lbm_read_time_us":12849,"lbm_reads_lt_1ms":572,"lbm_write_time_us":31791,"lbm_writes_lt_1ms":543,"mutex_wait_us":57,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":61952,"update_count":2500}
I20260812 06:19:13.360366 21962 maintenance_manager.cc:419] P 7430a51c2f334c1dae46b69b3ae5dbd9: Scheduling FlushDeltaMemStoresOp(99f7be6dfd45498d8a795fc80dff849e): perf score=14.095187
I20260812 06:19:13.422256 21893 maintenance_manager.cc:643] P 7430a51c2f334c1dae46b69b3ae5dbd9: FlushDeltaMemStoresOp(99f7be6dfd45498d8a795fc80dff849e) complete. Timing: real 0.062s	user 0.032s	sys 0.028s Metrics: {"bytes_written":16409905,"delete_count":0,"lbm_write_time_us":22431,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":402,"reinsert_count":0,"update_count":2000}
I20260812 06:19:13.422907 21962 maintenance_manager.cc:419] P 7430a51c2f334c1dae46b69b3ae5dbd9: Scheduling FlushDeltaMemStoresOp(99f7be6dfd45498d8a795fc80dff849e): perf score=2.188937
I20260812 06:19:13.440728 21893 maintenance_manager.cc:643] P 7430a51c2f334c1dae46b69b3ae5dbd9: FlushDeltaMemStoresOp(99f7be6dfd45498d8a795fc80dff849e) complete. Timing: real 0.018s	user 0.013s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6580,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:13.441331 21962 maintenance_manager.cc:419] P 7430a51c2f334c1dae46b69b3ae5dbd9: Scheduling MajorDeltaCompactionOp(99f7be6dfd45498d8a795fc80dff849e): perf score=1.000000
I20260812 06:19:13.613597 21893 maintenance_manager.cc:643] P 7430a51c2f334c1dae46b69b3ae5dbd9: MajorDeltaCompactionOp(99f7be6dfd45498d8a795fc80dff849e) complete. Timing: real 0.172s	user 0.094s	sys 0.068s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774692,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":858,"lbm_read_time_us":12188,"lbm_reads_lt_1ms":572,"lbm_write_time_us":28758,"lbm_writes_lt_1ms":543,"mutex_wait_us":276,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":5888,"update_count":2500}
I20260812 06:19:13.614192 21962 maintenance_manager.cc:419] P 7430a51c2f334c1dae46b69b3ae5dbd9: Scheduling FlushDeltaMemStoresOp(99f7be6dfd45498d8a795fc80dff849e): perf score=14.095187
I20260812 06:19:13.667769 21893 maintenance_manager.cc:643] P 7430a51c2f334c1dae46b69b3ae5dbd9: FlushDeltaMemStoresOp(99f7be6dfd45498d8a795fc80dff849e) complete. Timing: real 0.053s	user 0.019s	sys 0.031s Metrics: {"bytes_written":16409898,"delete_count":0,"lbm_write_time_us":23695,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":402,"reinsert_count":0,"update_count":2000}
I20260812 06:19:13.668351 21962 maintenance_manager.cc:419] P 7430a51c2f334c1dae46b69b3ae5dbd9: Scheduling FlushDeltaMemStoresOp(99f7be6dfd45498d8a795fc80dff849e): perf score=2.188937
I20260812 06:19:13.679177 21893 maintenance_manager.cc:643] P 7430a51c2f334c1dae46b69b3ae5dbd9: FlushDeltaMemStoresOp(99f7be6dfd45498d8a795fc80dff849e) complete. Timing: real 0.011s	user 0.009s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3998,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:13.679703 21962 maintenance_manager.cc:419] P 7430a51c2f334c1dae46b69b3ae5dbd9: Scheduling FlushMRSOp(99f7be6dfd45498d8a795fc80dff849e): perf score=1.000000
I20260812 06:19:13.718245 21893 maintenance_manager.cc:643] P 7430a51c2f334c1dae46b69b3ae5dbd9: FlushMRSOp(99f7be6dfd45498d8a795fc80dff849e) complete. Timing: real 0.038s	user 0.034s	sys 0.003s Metrics: {"bytes_written":1316417,"cfile_init":1,"dirs.queue_time_us":80,"dirs.run_cpu_time_us":232,"dirs.run_wall_time_us":1235,"drs_written":1,"lbm_read_time_us":38,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1938,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":32}
I20260812 06:19:13.718963 21962 maintenance_manager.cc:419] P 7430a51c2f334c1dae46b69b3ae5dbd9: Scheduling LogGCOp(99f7be6dfd45498d8a795fc80dff849e): free 128867720 bytes of WAL
I20260812 06:19:13.719223 21893 log_reader.cc:385] T 99f7be6dfd45498d8a795fc80dff849e: removed 13 log segments from log reader
I20260812 06:19:13.719288 21893 log.cc:1079] T 99f7be6dfd45498d8a795fc80dff849e P 7430a51c2f334c1dae46b69b3ae5dbd9: Deleting log segment in path: /tmp/dist-test-taskw60Q2h/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515548711361-21775-0/minicluster-data/ts-0-root/wals/99f7be6dfd45498d8a795fc80dff849e/wal-000000027 (ops 132-136)
I20260812 06:19:13.719339 21893 log.cc:1079] T 99f7be6dfd45498d8a795fc80dff849e P 7430a51c2f334c1dae46b69b3ae5dbd9: Deleting log segment in path: /tmp/dist-test-taskw60Q2h/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515548711361-21775-0/minicluster-data/ts-0-root/wals/99f7be6dfd45498d8a795fc80dff849e/wal-000000028 (ops 137-140)
I20260812 06:19:13.719398 21893 log.cc:1079] T 99f7be6dfd45498d8a795fc80dff849e P 7430a51c2f334c1dae46b69b3ae5dbd9: Deleting log segment in path: /tmp/dist-test-taskw60Q2h/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515548711361-21775-0/minicluster-data/ts-0-root/wals/99f7be6dfd45498d8a795fc80dff849e/wal-000000029 (ops 141-145)
I20260812 06:19:13.719442 21893 log.cc:1079] T 99f7be6dfd45498d8a795fc80dff849e P 7430a51c2f334c1dae46b69b3ae5dbd9: Deleting log segment in path: /tmp/dist-test-taskw60Q2h/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515548711361-21775-0/minicluster-data/ts-0-root/wals/99f7be6dfd45498d8a795fc80dff849e/wal-000000030 (ops 146-150)
I20260812 06:19:13.719478 21893 log.cc:1079] T 99f7be6dfd45498d8a795fc80dff849e P 7430a51c2f334c1dae46b69b3ae5dbd9: Deleting log segment in path: /tmp/dist-test-taskw60Q2h/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515548711361-21775-0/minicluster-data/ts-0-root/wals/99f7be6dfd45498d8a795fc80dff849e/wal-000000031 (ops 151-155)
I20260812 06:19:13.719518 21893 log.cc:1079] T 99f7be6dfd45498d8a795fc80dff849e P 7430a51c2f334c1dae46b69b3ae5dbd9: Deleting log segment in path: /tmp/dist-test-taskw60Q2h/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515548711361-21775-0/minicluster-data/ts-0-root/wals/99f7be6dfd45498d8a795fc80dff849e/wal-000000032 (ops 156-160)
I20260812 06:19:13.719558 21893 log.cc:1079] T 99f7be6dfd45498d8a795fc80dff849e P 7430a51c2f334c1dae46b69b3ae5dbd9: Deleting log segment in path: /tmp/dist-test-taskw60Q2h/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515548711361-21775-0/minicluster-data/ts-0-root/wals/99f7be6dfd45498d8a795fc80dff849e/wal-000000033 (ops 161-164)
I20260812 06:19:13.719596 21893 log.cc:1079] T 99f7be6dfd45498d8a795fc80dff849e P 7430a51c2f334c1dae46b69b3ae5dbd9: Deleting log segment in path: /tmp/dist-test-taskw60Q2h/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515548711361-21775-0/minicluster-data/ts-0-root/wals/99f7be6dfd45498d8a795fc80dff849e/wal-000000034 (ops 165-169)
I20260812 06:19:13.719633 21893 log.cc:1079] T 99f7be6dfd45498d8a795fc80dff849e P 7430a51c2f334c1dae46b69b3ae5dbd9: Deleting log segment in path: /tmp/dist-test-taskw60Q2h/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515548711361-21775-0/minicluster-data/ts-0-root/wals/99f7be6dfd45498d8a795fc80dff849e/wal-000000035 (ops 170-174)
I20260812 06:19:13.719673 21893 log.cc:1079] T 99f7be6dfd45498d8a795fc80dff849e P 7430a51c2f334c1dae46b69b3ae5dbd9: Deleting log segment in path: /tmp/dist-test-taskw60Q2h/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515548711361-21775-0/minicluster-data/ts-0-root/wals/99f7be6dfd45498d8a795fc80dff849e/wal-000000036 (ops 175-179)
I20260812 06:19:13.719712 21893 log.cc:1079] T 99f7be6dfd45498d8a795fc80dff849e P 7430a51c2f334c1dae46b69b3ae5dbd9: Deleting log segment in path: /tmp/dist-test-taskw60Q2h/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515548711361-21775-0/minicluster-data/ts-0-root/wals/99f7be6dfd45498d8a795fc80dff849e/wal-000000037 (ops 180-184)
I20260812 06:19:13.719750 21893 log.cc:1079] T 99f7be6dfd45498d8a795fc80dff849e P 7430a51c2f334c1dae46b69b3ae5dbd9: Deleting log segment in path: /tmp/dist-test-taskw60Q2h/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515548711361-21775-0/minicluster-data/ts-0-root/wals/99f7be6dfd45498d8a795fc80dff849e/wal-000000038 (ops 185-188)
I20260812 06:19:13.719789 21893 log.cc:1079] T 99f7be6dfd45498d8a795fc80dff849e P 7430a51c2f334c1dae46b69b3ae5dbd9: Deleting log segment in path: /tmp/dist-test-taskw60Q2h/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515548711361-21775-0/minicluster-data/ts-0-root/wals/99f7be6dfd45498d8a795fc80dff849e/wal-000000039 (ops 189-193)
I20260812 06:19:13.750880 21893 maintenance_manager.cc:643] P 7430a51c2f334c1dae46b69b3ae5dbd9: LogGCOp(99f7be6dfd45498d8a795fc80dff849e) complete. Timing: real 0.032s	user 0.000s	sys 0.029s Metrics: {}
I20260812 06:19:13.751426 21962 maintenance_manager.cc:419] P 7430a51c2f334c1dae46b69b3ae5dbd9: Scheduling FlushDeltaMemStoresOp(99f7be6dfd45498d8a795fc80dff849e): perf score=3.181125
I20260812 06:19:13.771095 21893 maintenance_manager.cc:643] P 7430a51c2f334c1dae46b69b3ae5dbd9: FlushDeltaMemStoresOp(99f7be6dfd45498d8a795fc80dff849e) complete. Timing: real 0.019s	user 0.007s	sys 0.003s Metrics: {"bytes_written":4512899,"delete_count":0,"lbm_write_time_us":4600,"lbm_writes_lt_1ms":113,"reinsert_count":0,"update_count":550}
I20260812 06:19:13.771606 21962 maintenance_manager.cc:419] P 7430a51c2f334c1dae46b69b3ae5dbd9: Scheduling UndoDeltaBlockGCOp(99f7be6dfd45498d8a795fc80dff849e): 493 bytes on disk
I20260812 06:19:13.772015 21893 maintenance_manager.cc:643] P 7430a51c2f334c1dae46b69b3ae5dbd9: UndoDeltaBlockGCOp(99f7be6dfd45498d8a795fc80dff849e) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":50,"lbm_reads_lt_1ms":4}
I20260812 06:19:13.772634 21962 maintenance_manager.cc:419] P 7430a51c2f334c1dae46b69b3ae5dbd9: Scheduling FlushDeltaMemStoresOp(99f7be6dfd45498d8a795fc80dff849e): perf score=2.188937
I20260812 06:19:13.782040 21893 maintenance_manager.cc:643] P 7430a51c2f334c1dae46b69b3ae5dbd9: FlushDeltaMemStoresOp(99f7be6dfd45498d8a795fc80dff849e) complete. Timing: real 0.009s	user 0.008s	sys 0.000s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3445,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:19:13.782418 21962 maintenance_manager.cc:419] P 7430a51c2f334c1dae46b69b3ae5dbd9: Scheduling MajorDeltaCompactionOp(99f7be6dfd45498d8a795fc80dff849e): perf score=1.000000
I20260812 06:19:13.874519 21775 heavy-update-compaction-itest.cc:229] Time spent updating: real 4.884s	user 1.776s	sys 0.159s
I20260812 06:19:13.972373 21775 heavy-update-compaction-itest.cc:265] Time spent scanning: real 0.097s	user 0.004s	sys 0.000s
I20260812 06:19:13.973140 21775 tablet_server.cc:179] TabletServer@127.21.67.193:0 shutting down...
I20260812 06:19:13.986562 21893 maintenance_manager.cc:643] P 7430a51c2f334c1dae46b69b3ae5dbd9: MajorDeltaCompactionOp(99f7be6dfd45498d8a795fc80dff849e) complete. Timing: real 0.204s	user 0.158s	sys 0.046s Metrics: {"cfile_cache_miss":734,"cfile_cache_miss_bytes":32979733,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":688,"lbm_read_time_us":14911,"lbm_reads_lt_1ms":770,"lbm_write_time_us":35081,"lbm_writes_lt_1ms":743,"mutex_wait_us":297,"peak_mem_usage":87969044,"reinsert_count":0,"spinlock_wait_cycles":17664,"thread_start_us":73,"threads_started":1,"update_count":3500}
I20260812 06:19:13.987128 21775 ts_tablet_manager.cc:1507] Shutting down tablet manager...
I20260812 06:19:13.987679 21775 tablet_replica.cc:333] T 99f7be6dfd45498d8a795fc80dff849e P 7430a51c2f334c1dae46b69b3ae5dbd9: stopping tablet replica
I20260812 06:19:13.987928 21775 raft_consensus.cc:2243] T 99f7be6dfd45498d8a795fc80dff849e P 7430a51c2f334c1dae46b69b3ae5dbd9 [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:19:13.988242 21775 raft_consensus.cc:2272] T 99f7be6dfd45498d8a795fc80dff849e P 7430a51c2f334c1dae46b69b3ae5dbd9 [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:19:14.015956 21775 tablet_server.cc:196] TabletServer@127.21.67.193:0 shutdown complete.
I20260812 06:19:14.045066 21775 master.cc:562] Master@127.21.67.254:37759 shutting down...
I20260812 06:19:14.049180 21775 raft_consensus.cc:2243] T 00000000000000000000000000000000 P 10128bdf121b4e409400796840670ffc [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:19:14.049398 21775 raft_consensus.cc:2272] T 00000000000000000000000000000000 P 10128bdf121b4e409400796840670ffc [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:19:14.049499 21775 tablet_replica.cc:333] T 00000000000000000000000000000000 P 10128bdf121b4e409400796840670ffc: stopping tablet replica
I20260812 06:19:14.061702 21775 master.cc:584] Master@127.21.67.254:37759 shutdown complete.
[       OK ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/0 (5429 ms)
[ RUN      ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/1
I20260812 06:19:14.151070 21775 internal_mini_cluster.cc:156] Creating distributed mini masters. Addrs: 127.21.67.254:33089
I20260812 06:19:14.151408 21775 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:19:14.153410 21999 instance_detector.cc:116] could not retrieve Azure instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:19:14.153431 21775 server_base.cc:1061] running on GCE node
W20260812 06:19:14.153610 22001 instance_detector.cc:116] could not retrieve OpenStack instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:19:14.153462 21998 instance_detector.cc:116] could not retrieve AWS instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:19:14.153867 21775 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:19:14.153913 21775 system_unsync_time.cc:38] NTP support is disabled. Clock error bounds will not be accurate. This configuration is not suitable for distributed clusters.
I20260812 06:19:14.153928 21775 hybrid_clock.cc:648] HybridClock initialized: now 1786515554153928 us; error 0 us; skew 500 ppm
I20260812 06:19:14.154692 21775 webserver.cc:533] Webserver started at http://127.21.67.254:36769/ using document root <none> and password file <none>
I20260812 06:19:14.154814 21775 fs_manager.cc:362] Metadata directory not provided
I20260812 06:19:14.154855 21775 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:19:14.154903 21775 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:19:14.155290 21775 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskw60Q2h/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515548711361-21775-0/minicluster-data/master-0-root/instance:
uuid: "a6a207e5dbae448b94361ff1da218560"
format_stamp: "Formatted at 2026-08-12 06:19:14 on dist-test-slave-cbbz"
I20260812 06:19:14.156879 21775 fs_manager.cc:696] Time spent creating directory manager: real 0.001s	user 0.002s	sys 0.000s
I20260812 06:19:14.157821 22006 log_block_manager.cc:4127] Time spent loading block containers with low live blocks: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:19:14.158073 21775 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.001s	sys 0.000s
I20260812 06:19:14.158174 21775 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskw60Q2h/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515548711361-21775-0/minicluster-data/master-0-root
uuid: "a6a207e5dbae448b94361ff1da218560"
format_stamp: "Formatted at 2026-08-12 06:19:14 on dist-test-slave-cbbz"
I20260812 06:19:14.158255 21775 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskw60Q2h/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515548711361-21775-0/minicluster-data/master-0-root
metadata directory: /tmp/dist-test-taskw60Q2h/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515548711361-21775-0/minicluster-data/master-0-root
1 data directories: /tmp/dist-test-taskw60Q2h/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515548711361-21775-0/minicluster-data/master-0-root/data
Total live blocks: 0
Total live bytes: 0
Total live bytes (after alignment): 0
Total number of LBM containers: 0 (0 full)
Did not check for missing blocks
Did not check for orphaned blocks
Total full LBM containers with extra space: 0 (0 repaired)
Total full LBM container extra space in bytes: 0 (0 repaired)
Total incomplete LBM containers: 0 (0 repaired)
Total LBM partial records: 0 (0 repaired)
Total corrupted LBM metadata records in RocksDB: 0 (0 repaired)
I20260812 06:19:14.175856 21775 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:19:14.176342 21775 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:19:14.180634 21775 rpc_server.cc:307] RPC server started. Bound to: 127.21.67.254:33089
I20260812 06:19:14.183699 22066 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.21.67.254:33089 every 8 connection(s)
I20260812 06:19:14.187335 22068 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet 00000000000000000000000000000000. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:19:14.190438 22068 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P a6a207e5dbae448b94361ff1da218560: Bootstrap starting.
I20260812 06:19:14.191181 22068 tablet_bootstrap.cc:654] T 00000000000000000000000000000000 P a6a207e5dbae448b94361ff1da218560: Neither blocks nor log segments found. Creating new log.
I20260812 06:19:14.192178 22068 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P a6a207e5dbae448b94361ff1da218560: No bootstrap required, opened a new log
I20260812 06:19:14.192514 22068 raft_consensus.cc:359] T 00000000000000000000000000000000 P a6a207e5dbae448b94361ff1da218560 [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "a6a207e5dbae448b94361ff1da218560" member_type: VOTER }
I20260812 06:19:14.192597 22068 raft_consensus.cc:385] T 00000000000000000000000000000000 P a6a207e5dbae448b94361ff1da218560 [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:19:14.192620 22068 raft_consensus.cc:740] T 00000000000000000000000000000000 P a6a207e5dbae448b94361ff1da218560 [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: a6a207e5dbae448b94361ff1da218560, State: Initialized, Role: FOLLOWER
I20260812 06:19:14.192760 22068 consensus_queue.cc:260] T 00000000000000000000000000000000 P a6a207e5dbae448b94361ff1da218560 [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: "a6a207e5dbae448b94361ff1da218560" member_type: VOTER }
I20260812 06:19:14.192845 22068 raft_consensus.cc:399] T 00000000000000000000000000000000 P a6a207e5dbae448b94361ff1da218560 [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:19:14.192869 22068 raft_consensus.cc:493] T 00000000000000000000000000000000 P a6a207e5dbae448b94361ff1da218560 [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:19:14.192899 22068 raft_consensus.cc:3060] T 00000000000000000000000000000000 P a6a207e5dbae448b94361ff1da218560 [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:19:14.193493 22068 raft_consensus.cc:515] T 00000000000000000000000000000000 P a6a207e5dbae448b94361ff1da218560 [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "a6a207e5dbae448b94361ff1da218560" member_type: VOTER }
I20260812 06:19:14.193600 22068 leader_election.cc:304] T 00000000000000000000000000000000 P a6a207e5dbae448b94361ff1da218560 [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: a6a207e5dbae448b94361ff1da218560; no voters: 
I20260812 06:19:14.193740 22068 leader_election.cc:290] T 00000000000000000000000000000000 P a6a207e5dbae448b94361ff1da218560 [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:19:14.193897 22071 raft_consensus.cc:2804] T 00000000000000000000000000000000 P a6a207e5dbae448b94361ff1da218560 [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:19:14.194105 22071 raft_consensus.cc:697] T 00000000000000000000000000000000 P a6a207e5dbae448b94361ff1da218560 [term 1 LEADER]: Becoming Leader. State: Replica: a6a207e5dbae448b94361ff1da218560, State: Running, Role: LEADER
I20260812 06:19:14.194228 22068 sys_catalog.cc:565] T 00000000000000000000000000000000 P a6a207e5dbae448b94361ff1da218560 [sys.catalog]: configured and running, proceeding with master startup.
I20260812 06:19:14.194316 22071 consensus_queue.cc:237] T 00000000000000000000000000000000 P a6a207e5dbae448b94361ff1da218560 [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: "a6a207e5dbae448b94361ff1da218560" member_type: VOTER }
I20260812 06:19:14.194802 22073 sys_catalog.cc:455] T 00000000000000000000000000000000 P a6a207e5dbae448b94361ff1da218560 [sys.catalog]: SysCatalogTable state changed. Reason: New leader a6a207e5dbae448b94361ff1da218560. Latest consensus state: current_term: 1 leader_uuid: "a6a207e5dbae448b94361ff1da218560" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "a6a207e5dbae448b94361ff1da218560" member_type: VOTER } }
I20260812 06:19:14.194909 22073 sys_catalog.cc:458] T 00000000000000000000000000000000 P a6a207e5dbae448b94361ff1da218560 [sys.catalog]: This master's current role is: LEADER
I20260812 06:19:14.194787 22072 sys_catalog.cc:455] T 00000000000000000000000000000000 P a6a207e5dbae448b94361ff1da218560 [sys.catalog]: SysCatalogTable state changed. Reason: RaftConsensus started. Latest consensus state: current_term: 1 leader_uuid: "a6a207e5dbae448b94361ff1da218560" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "a6a207e5dbae448b94361ff1da218560" member_type: VOTER } }
I20260812 06:19:14.194994 22072 sys_catalog.cc:458] T 00000000000000000000000000000000 P a6a207e5dbae448b94361ff1da218560 [sys.catalog]: This master's current role is: LEADER
I20260812 06:19:14.195556 22078 catalog_manager.cc:1511] Loading table and tablet metadata into memory...
I20260812 06:19:14.196501 22078 catalog_manager.cc:1520] Initializing Kudu cluster ID...
I20260812 06:19:14.196735 21775 internal_mini_cluster.cc:184] Waiting to initialize catalog manager on master 0
I20260812 06:19:14.198493 22078 catalog_manager.cc:1383] Generated new cluster ID: e02e0ca41ca7412db917ec535374d2b1
I20260812 06:19:14.198572 22078 catalog_manager.cc:1531] Initializing Kudu internal certificate authority...
I20260812 06:19:14.210196 22078 catalog_manager.cc:1406] Generated new certificate authority record
I20260812 06:19:14.210754 22078 catalog_manager.cc:1540] Loading token signing keys...
I20260812 06:19:14.224442 22078 catalog_manager.cc:6092] T 00000000000000000000000000000000 P a6a207e5dbae448b94361ff1da218560: Generated new TSK 0
I20260812 06:19:14.224671 22078 catalog_manager.cc:1550] Initializing in-progress tserver states...
I20260812 06:19:14.229031 21775 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:19:14.230847 22092 instance_detector.cc:116] could not retrieve OpenStack instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:19:14.230890 22089 instance_detector.cc:116] could not retrieve AWS instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:19:14.230974 21775 server_base.cc:1061] running on GCE node
W20260812 06:19:14.231017 22090 instance_detector.cc:116] could not retrieve Azure instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:19:14.231289 21775 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:19:14.231334 21775 system_unsync_time.cc:38] NTP support is disabled. Clock error bounds will not be accurate. This configuration is not suitable for distributed clusters.
I20260812 06:19:14.231349 21775 hybrid_clock.cc:648] HybridClock initialized: now 1786515554231350 us; error 0 us; skew 500 ppm
I20260812 06:19:14.232241 21775 webserver.cc:533] Webserver started at http://127.21.67.193:41497/ using document root <none> and password file <none>
I20260812 06:19:14.232424 21775 fs_manager.cc:362] Metadata directory not provided
I20260812 06:19:14.232487 21775 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:19:14.232570 21775 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:19:14.232944 21775 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskw60Q2h/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515548711361-21775-0/minicluster-data/ts-0-root/instance:
uuid: "854a308a6b1546819e960e724eab859c"
format_stamp: "Formatted at 2026-08-12 06:19:14 on dist-test-slave-cbbz"
I20260812 06:19:14.234354 21775 fs_manager.cc:696] Time spent creating directory manager: real 0.001s	user 0.000s	sys 0.002s
I20260812 06:19:14.235266 22101 log_block_manager.cc:4127] Time spent loading block containers with low live blocks: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:19:14.235513 21775 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.000s	sys 0.001s
I20260812 06:19:14.235577 21775 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskw60Q2h/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515548711361-21775-0/minicluster-data/ts-0-root
uuid: "854a308a6b1546819e960e724eab859c"
format_stamp: "Formatted at 2026-08-12 06:19:14 on dist-test-slave-cbbz"
I20260812 06:19:14.235663 21775 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskw60Q2h/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515548711361-21775-0/minicluster-data/ts-0-root
metadata directory: /tmp/dist-test-taskw60Q2h/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515548711361-21775-0/minicluster-data/ts-0-root
1 data directories: /tmp/dist-test-taskw60Q2h/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515548711361-21775-0/minicluster-data/ts-0-root/data
Total live blocks: 0
Total live bytes: 0
Total live bytes (after alignment): 0
Total number of LBM containers: 0 (0 full)
Did not check for missing blocks
Did not check for orphaned blocks
Total full LBM containers with extra space: 0 (0 repaired)
Total full LBM container extra space in bytes: 0 (0 repaired)
Total incomplete LBM containers: 0 (0 repaired)
Total LBM partial records: 0 (0 repaired)
Total corrupted LBM metadata records in RocksDB: 0 (0 repaired)
I20260812 06:19:14.254375 21775 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:19:14.254727 21775 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:19:14.255019 21775 txn_system_client.cc:432] TxnSystemClient initialization is disabled...
I20260812 06:19:14.255482 21775 ts_tablet_manager.cc:585] Loaded tablet metadata (0 total tablets, 0 live tablets)
I20260812 06:19:14.255542 21775 ts_tablet_manager.cc:531] Time spent load tablet metadata: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:19:14.255612 21775 ts_tablet_manager.cc:616] Registered 0 tablets
I20260812 06:19:14.255654 21775 ts_tablet_manager.cc:595] Time spent register tablets: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:19:14.260192 21775 rpc_server.cc:307] RPC server started. Bound to: 127.21.67.193:41821
I20260812 06:19:14.261293 22172 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.21.67.193:41821 every 8 connection(s)
I20260812 06:19:14.270363 22173 heartbeater.cc:344] Connected to a master server at 127.21.67.254:33089
I20260812 06:19:14.270457 22173 heartbeater.cc:461] Registering TS with master...
I20260812 06:19:14.270651 22173 heartbeater.cc:507] Master 127.21.67.254:33089 requested a full tablet report, sending...
I20260812 06:19:14.271248 22025 ts_manager.cc:194] Registered new tserver with Master: 854a308a6b1546819e960e724eab859c (127.21.67.193:41821)
I20260812 06:19:14.271974 22025 master_service.cc:502] Signed X509 certificate for tserver {username='slave'} at 127.0.0.1:34548
I20260812 06:19:14.272181 21775 internal_mini_cluster.cc:371] 1 TS(s) registered with all masters after 0.011000785s
I20260812 06:19:14.279174 22025 catalog_manager.cc:2283] Servicing CreateTable request from {username='slave'} at 127.0.0.1:34554:
name: "heavy-update-compaction-test"
schema {
  columns {
    name: "key"
    type: INT64
    is_key: true
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_a"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_b"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_c"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_d"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_e"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
}
num_replicas: 1
split_rows_range_bounds {
}
partition_schema {
  range_schema {
  }
}
I20260812 06:19:14.287820 22134 tablet_service.cc:1511] Processing CreateTablet for tablet 4f10fcf501c44a25a511800f3478698f (DEFAULT_TABLE table=heavy-update-compaction-test [id=2371987dfb1241b2b94346d38cb28813]), partition=
I20260812 06:19:14.288057 22134 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet 4f10fcf501c44a25a511800f3478698f. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:19:14.289963 22189 tablet_bootstrap.cc:492] T 4f10fcf501c44a25a511800f3478698f P 854a308a6b1546819e960e724eab859c: Bootstrap starting.
I20260812 06:19:14.290856 22189 tablet_bootstrap.cc:654] T 4f10fcf501c44a25a511800f3478698f P 854a308a6b1546819e960e724eab859c: Neither blocks nor log segments found. Creating new log.
I20260812 06:19:14.291904 22189 tablet_bootstrap.cc:492] T 4f10fcf501c44a25a511800f3478698f P 854a308a6b1546819e960e724eab859c: No bootstrap required, opened a new log
I20260812 06:19:14.292012 22189 ts_tablet_manager.cc:1403] T 4f10fcf501c44a25a511800f3478698f P 854a308a6b1546819e960e724eab859c: Time spent bootstrapping tablet: real 0.002s	user 0.001s	sys 0.000s
I20260812 06:19:14.292484 22189 raft_consensus.cc:359] T 4f10fcf501c44a25a511800f3478698f P 854a308a6b1546819e960e724eab859c [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "854a308a6b1546819e960e724eab859c" member_type: VOTER last_known_addr { host: "127.21.67.193" port: 41821 } }
I20260812 06:19:14.292595 22189 raft_consensus.cc:385] T 4f10fcf501c44a25a511800f3478698f P 854a308a6b1546819e960e724eab859c [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:19:14.292641 22189 raft_consensus.cc:740] T 4f10fcf501c44a25a511800f3478698f P 854a308a6b1546819e960e724eab859c [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: 854a308a6b1546819e960e724eab859c, State: Initialized, Role: FOLLOWER
I20260812 06:19:14.292791 22189 consensus_queue.cc:260] T 4f10fcf501c44a25a511800f3478698f P 854a308a6b1546819e960e724eab859c [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: "854a308a6b1546819e960e724eab859c" member_type: VOTER last_known_addr { host: "127.21.67.193" port: 41821 } }
I20260812 06:19:14.292893 22189 raft_consensus.cc:399] T 4f10fcf501c44a25a511800f3478698f P 854a308a6b1546819e960e724eab859c [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:19:14.292930 22189 raft_consensus.cc:493] T 4f10fcf501c44a25a511800f3478698f P 854a308a6b1546819e960e724eab859c [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:19:14.292989 22189 raft_consensus.cc:3060] T 4f10fcf501c44a25a511800f3478698f P 854a308a6b1546819e960e724eab859c [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:19:14.293774 22189 raft_consensus.cc:515] T 4f10fcf501c44a25a511800f3478698f P 854a308a6b1546819e960e724eab859c [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "854a308a6b1546819e960e724eab859c" member_type: VOTER last_known_addr { host: "127.21.67.193" port: 41821 } }
I20260812 06:19:14.293927 22189 leader_election.cc:304] T 4f10fcf501c44a25a511800f3478698f P 854a308a6b1546819e960e724eab859c [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: 854a308a6b1546819e960e724eab859c; no voters: 
I20260812 06:19:14.294112 22189 leader_election.cc:290] T 4f10fcf501c44a25a511800f3478698f P 854a308a6b1546819e960e724eab859c [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:19:14.294211 22191 raft_consensus.cc:2804] T 4f10fcf501c44a25a511800f3478698f P 854a308a6b1546819e960e724eab859c [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:19:14.294443 22191 raft_consensus.cc:697] T 4f10fcf501c44a25a511800f3478698f P 854a308a6b1546819e960e724eab859c [term 1 LEADER]: Becoming Leader. State: Replica: 854a308a6b1546819e960e724eab859c, State: Running, Role: LEADER
I20260812 06:19:14.294514 22173 heartbeater.cc:499] Master 127.21.67.254:33089 was elected leader, sending a full tablet report...
I20260812 06:19:14.294633 22191 consensus_queue.cc:237] T 4f10fcf501c44a25a511800f3478698f P 854a308a6b1546819e960e724eab859c [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: "854a308a6b1546819e960e724eab859c" member_type: VOTER last_known_addr { host: "127.21.67.193" port: 41821 } }
I20260812 06:19:14.294811 22189 ts_tablet_manager.cc:1434] T 4f10fcf501c44a25a511800f3478698f P 854a308a6b1546819e960e724eab859c: Time spent starting tablet: real 0.003s	user 0.003s	sys 0.000s
I20260812 06:19:14.296030 22025 catalog_manager.cc:5719] T 4f10fcf501c44a25a511800f3478698f P 854a308a6b1546819e960e724eab859c reported cstate change: term changed from 0 to 1, leader changed from <none> to 854a308a6b1546819e960e724eab859c (127.21.67.193). New cstate: current_term: 1 leader_uuid: "854a308a6b1546819e960e724eab859c" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "854a308a6b1546819e960e724eab859c" member_type: VOTER last_known_addr { host: "127.21.67.193" port: 41821 } health_report { overall_health: HEALTHY } } }
I20260812 06:19:14.355441 21775 heavy-update-compaction-itest.cc:215] Time spent inserting: real 0.052s	user 0.018s	sys 0.004s
I20260812 06:19:14.511827 22175 maintenance_manager.cc:419] P 854a308a6b1546819e960e724eab859c: Scheduling FlushMRSOp(4f10fcf501c44a25a511800f3478698f): perf score=19.054940
I20260812 06:19:14.654166 22109 maintenance_manager.cc:643] P 854a308a6b1546819e960e724eab859c: FlushMRSOp(4f10fcf501c44a25a511800f3478698f) complete. Timing: real 0.142s	user 0.090s	sys 0.051s Metrics: {"bytes_written":13169000,"cfile_init":1,"delete_count":0,"dirs.queue_time_us":92,"dirs.run_cpu_time_us":289,"dirs.run_wall_time_us":940,"drs_written":1,"lbm_read_time_us":40,"lbm_reads_lt_1ms":4,"lbm_write_time_us":41831,"lbm_writes_lt_1ms":788,"peak_mem_usage":0,"reinsert_count":0,"rows_written":105,"update_count":1605}
I20260812 06:19:14.654834 22175 maintenance_manager.cc:419] P 854a308a6b1546819e960e724eab859c: Scheduling LogGCOp(4f10fcf501c44a25a511800f3478698f): free 20743880 bytes of WAL
I20260812 06:19:14.655087 22109 log_reader.cc:385] T 4f10fcf501c44a25a511800f3478698f: removed 2 log segments from log reader
I20260812 06:19:14.655158 22109 log.cc:1079] T 4f10fcf501c44a25a511800f3478698f P 854a308a6b1546819e960e724eab859c: Deleting log segment in path: /tmp/dist-test-taskw60Q2h/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515548711361-21775-0/minicluster-data/ts-0-root/wals/4f10fcf501c44a25a511800f3478698f/wal-000000001 (ops 1-6)
I20260812 06:19:14.655200 22109 log.cc:1079] T 4f10fcf501c44a25a511800f3478698f P 854a308a6b1546819e960e724eab859c: Deleting log segment in path: /tmp/dist-test-taskw60Q2h/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515548711361-21775-0/minicluster-data/ts-0-root/wals/4f10fcf501c44a25a511800f3478698f/wal-000000002 (ops 7-11)
I20260812 06:19:14.661092 22109 maintenance_manager.cc:643] P 854a308a6b1546819e960e724eab859c: LogGCOp(4f10fcf501c44a25a511800f3478698f) complete. Timing: real 0.006s	user 0.000s	sys 0.005s Metrics: {}
I20260812 06:19:14.661484 22175 maintenance_manager.cc:419] P 854a308a6b1546819e960e724eab859c: Scheduling UndoDeltaBlockGCOp(4f10fcf501c44a25a511800f3478698f): 16821646 bytes on disk
I20260812 06:19:14.661955 22109 maintenance_manager.cc:643] P 854a308a6b1546819e960e724eab859c: UndoDeltaBlockGCOp(4f10fcf501c44a25a511800f3478698f) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":89,"lbm_reads_lt_1ms":4}
I20260812 06:19:14.662384 22175 maintenance_manager.cc:419] P 854a308a6b1546819e960e724eab859c: Scheduling FlushDeltaMemStoresOp(4f10fcf501c44a25a511800f3478698f): perf score=2.188937
I20260812 06:19:14.682539 22109 maintenance_manager.cc:643] P 854a308a6b1546819e960e724eab859c: FlushDeltaMemStoresOp(4f10fcf501c44a25a511800f3478698f) complete. Timing: real 0.020s	user 0.002s	sys 0.008s Metrics: {"bytes_written":3241134,"delete_count":0,"lbm_write_time_us":4640,"lbm_writes_lt_1ms":82,"reinsert_count":0,"update_count":395}
I20260812 06:19:14.682917 22175 maintenance_manager.cc:419] P 854a308a6b1546819e960e724eab859c: Scheduling FlushDeltaMemStoresOp(4f10fcf501c44a25a511800f3478698f): perf score=2.188937
I20260812 06:19:14.692662 22109 maintenance_manager.cc:643] P 854a308a6b1546819e960e724eab859c: FlushDeltaMemStoresOp(4f10fcf501c44a25a511800f3478698f) complete. Timing: real 0.010s	user 0.005s	sys 0.004s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3837,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:19:14.693013 22175 maintenance_manager.cc:419] P 854a308a6b1546819e960e724eab859c: Scheduling MajorDeltaCompactionOp(4f10fcf501c44a25a511800f3478698f): perf score=1.000000
I20260812 06:19:14.856405 22109 maintenance_manager.cc:643] P 854a308a6b1546819e960e724eab859c: MajorDeltaCompactionOp(4f10fcf501c44a25a511800f3478698f) complete. Timing: real 0.163s	user 0.115s	sys 0.045s Metrics: {"cfile_cache_miss":523,"cfile_cache_miss_bytes":24405534,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":680,"lbm_read_time_us":11651,"lbm_reads_lt_1ms":559,"lbm_write_time_us":30816,"lbm_writes_lt_1ms":533,"peak_mem_usage":61665166,"reinsert_count":0,"spinlock_wait_cycles":1536,"thread_start_us":343,"threads_started":5,"update_count":2450}
I20260812 06:19:14.857092 22175 maintenance_manager.cc:419] P 854a308a6b1546819e960e724eab859c: Scheduling FlushDeltaMemStoresOp(4f10fcf501c44a25a511800f3478698f): perf score=11.118625
I20260812 06:19:14.891976 22109 maintenance_manager.cc:643] P 854a308a6b1546819e960e724eab859c: FlushDeltaMemStoresOp(4f10fcf501c44a25a511800f3478698f) complete. Timing: real 0.035s	user 0.016s	sys 0.015s Metrics: {"bytes_written":12717735,"delete_count":0,"lbm_write_time_us":14915,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:19:14.892608 22175 maintenance_manager.cc:419] P 854a308a6b1546819e960e724eab859c: Scheduling FlushDeltaMemStoresOp(4f10fcf501c44a25a511800f3478698f): perf score=2.188937
I20260812 06:19:14.909982 22109 maintenance_manager.cc:643] P 854a308a6b1546819e960e724eab859c: FlushDeltaMemStoresOp(4f10fcf501c44a25a511800f3478698f) complete. Timing: real 0.017s	user 0.012s	sys 0.000s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":5241,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:19:14.910606 22175 maintenance_manager.cc:419] P 854a308a6b1546819e960e724eab859c: Scheduling MajorDeltaCompactionOp(4f10fcf501c44a25a511800f3478698f): perf score=1.000000
I20260812 06:19:15.031459 22109 maintenance_manager.cc:643] P 854a308a6b1546819e960e724eab859c: MajorDeltaCompactionOp(4f10fcf501c44a25a511800f3478698f) complete. Timing: real 0.121s	user 0.090s	sys 0.028s 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":419,"lbm_read_time_us":7494,"lbm_reads_lt_1ms":464,"lbm_write_time_us":23962,"lbm_writes_lt_1ms":443,"mutex_wait_us":44,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":6016,"update_count":2000}
I20260812 06:19:15.032177 22175 maintenance_manager.cc:419] P 854a308a6b1546819e960e724eab859c: Scheduling FlushDeltaMemStoresOp(4f10fcf501c44a25a511800f3478698f): perf score=11.118625
I20260812 06:19:15.076234 22109 maintenance_manager.cc:643] P 854a308a6b1546819e960e724eab859c: FlushDeltaMemStoresOp(4f10fcf501c44a25a511800f3478698f) complete. Timing: real 0.044s	user 0.032s	sys 0.008s Metrics: {"bytes_written":12717734,"delete_count":0,"lbm_write_time_us":16079,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:19:15.076759 22175 maintenance_manager.cc:419] P 854a308a6b1546819e960e724eab859c: Scheduling FlushDeltaMemStoresOp(4f10fcf501c44a25a511800f3478698f): perf score=2.188937
I20260812 06:19:15.096429 22109 maintenance_manager.cc:643] P 854a308a6b1546819e960e724eab859c: FlushDeltaMemStoresOp(4f10fcf501c44a25a511800f3478698f) complete. Timing: real 0.019s	user 0.006s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4106,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:15.096933 22175 maintenance_manager.cc:419] P 854a308a6b1546819e960e724eab859c: Scheduling FlushDeltaMemStoresOp(4f10fcf501c44a25a511800f3478698f): perf score=2.188937
I20260812 06:19:15.106168 22109 maintenance_manager.cc:643] P 854a308a6b1546819e960e724eab859c: FlushDeltaMemStoresOp(4f10fcf501c44a25a511800f3478698f) complete. Timing: real 0.009s	user 0.008s	sys 0.000s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3498,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:19:15.106611 22175 maintenance_manager.cc:419] P 854a308a6b1546819e960e724eab859c: Scheduling MajorDeltaCompactionOp(4f10fcf501c44a25a511800f3478698f): perf score=1.000000
I20260812 06:19:15.291013 22109 maintenance_manager.cc:643] P 854a308a6b1546819e960e724eab859c: MajorDeltaCompactionOp(4f10fcf501c44a25a511800f3478698f) complete. Timing: real 0.184s	user 0.090s	sys 0.085s Metrics: {"cfile_cache_miss":533,"cfile_cache_miss_bytes":24815793,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":196,"lbm_read_time_us":13302,"lbm_reads_lt_1ms":573,"lbm_write_time_us":29932,"lbm_writes_lt_1ms":543,"mutex_wait_us":29,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":60416,"update_count":2500}
I20260812 06:19:15.291692 22175 maintenance_manager.cc:419] P 854a308a6b1546819e960e724eab859c: Scheduling FlushDeltaMemStoresOp(4f10fcf501c44a25a511800f3478698f): perf score=14.095187
I20260812 06:19:15.350557 22109 maintenance_manager.cc:643] P 854a308a6b1546819e960e724eab859c: FlushDeltaMemStoresOp(4f10fcf501c44a25a511800f3478698f) complete. Timing: real 0.059s	user 0.022s	sys 0.027s Metrics: {"bytes_written":16409900,"delete_count":0,"lbm_write_time_us":19527,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:15.350989 22175 maintenance_manager.cc:419] P 854a308a6b1546819e960e724eab859c: Scheduling FlushDeltaMemStoresOp(4f10fcf501c44a25a511800f3478698f): perf score=2.188937
I20260812 06:19:15.361531 22109 maintenance_manager.cc:643] P 854a308a6b1546819e960e724eab859c: FlushDeltaMemStoresOp(4f10fcf501c44a25a511800f3478698f) complete. Timing: real 0.010s	user 0.001s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4215,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:15.361974 22175 maintenance_manager.cc:419] P 854a308a6b1546819e960e724eab859c: Scheduling MajorDeltaCompactionOp(4f10fcf501c44a25a511800f3478698f): perf score=1.000000
I20260812 06:19:15.549882 22109 maintenance_manager.cc:643] P 854a308a6b1546819e960e724eab859c: MajorDeltaCompactionOp(4f10fcf501c44a25a511800f3478698f) complete. Timing: real 0.188s	user 0.113s	sys 0.066s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24815682,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":179,"lbm_read_time_us":13487,"lbm_reads_lt_1ms":572,"lbm_write_time_us":29428,"lbm_writes_lt_1ms":543,"mutex_wait_us":42,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":6016,"update_count":2500}
I20260812 06:19:15.550563 22175 maintenance_manager.cc:419] P 854a308a6b1546819e960e724eab859c: Scheduling FlushDeltaMemStoresOp(4f10fcf501c44a25a511800f3478698f): perf score=14.095187
I20260812 06:19:15.608736 22109 maintenance_manager.cc:643] P 854a308a6b1546819e960e724eab859c: FlushDeltaMemStoresOp(4f10fcf501c44a25a511800f3478698f) complete. Timing: real 0.058s	user 0.031s	sys 0.024s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":19579,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:15.609360 22175 maintenance_manager.cc:419] P 854a308a6b1546819e960e724eab859c: Scheduling FlushDeltaMemStoresOp(4f10fcf501c44a25a511800f3478698f): perf score=2.188937
I20260812 06:19:15.620952 22109 maintenance_manager.cc:643] P 854a308a6b1546819e960e724eab859c: FlushDeltaMemStoresOp(4f10fcf501c44a25a511800f3478698f) complete. Timing: real 0.011s	user 0.005s	sys 0.006s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4529,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:15.621397 22175 maintenance_manager.cc:419] P 854a308a6b1546819e960e724eab859c: Scheduling MajorDeltaCompactionOp(4f10fcf501c44a25a511800f3478698f): perf score=1.000000
I20260812 06:19:15.807756 22109 maintenance_manager.cc:643] P 854a308a6b1546819e960e724eab859c: MajorDeltaCompactionOp(4f10fcf501c44a25a511800f3478698f) complete. Timing: real 0.186s	user 0.133s	sys 0.042s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24815683,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":244,"lbm_read_time_us":12409,"lbm_reads_lt_1ms":572,"lbm_write_time_us":29463,"lbm_writes_lt_1ms":543,"mutex_wait_us":56,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":7936,"update_count":2500}
I20260812 06:19:15.808508 22175 maintenance_manager.cc:419] P 854a308a6b1546819e960e724eab859c: Scheduling FlushDeltaMemStoresOp(4f10fcf501c44a25a511800f3478698f): perf score=14.095187
I20260812 06:19:15.859027 22109 maintenance_manager.cc:643] P 854a308a6b1546819e960e724eab859c: FlushDeltaMemStoresOp(4f10fcf501c44a25a511800f3478698f) complete. Timing: real 0.050s	user 0.033s	sys 0.007s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":19196,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:15.859504 22175 maintenance_manager.cc:419] P 854a308a6b1546819e960e724eab859c: Scheduling FlushDeltaMemStoresOp(4f10fcf501c44a25a511800f3478698f): perf score=2.188937
I20260812 06:19:15.880692 22109 maintenance_manager.cc:643] P 854a308a6b1546819e960e724eab859c: FlushDeltaMemStoresOp(4f10fcf501c44a25a511800f3478698f) complete. Timing: real 0.021s	user 0.006s	sys 0.015s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4039,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:15.881229 22175 maintenance_manager.cc:419] P 854a308a6b1546819e960e724eab859c: Scheduling FlushMRSOp(4f10fcf501c44a25a511800f3478698f): perf score=1.000000
I20260812 06:19:15.913796 22109 maintenance_manager.cc:643] P 854a308a6b1546819e960e724eab859c: FlushMRSOp(4f10fcf501c44a25a511800f3478698f) complete. Timing: real 0.032s	user 0.029s	sys 0.000s Metrics: {"bytes_written":1152508,"cfile_init":1,"dirs.queue_time_us":75,"dirs.run_cpu_time_us":211,"dirs.run_wall_time_us":1412,"drs_written":1,"lbm_read_time_us":38,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1330,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":28}
I20260812 06:19:15.914415 22175 maintenance_manager.cc:419] P 854a308a6b1546819e960e724eab859c: Scheduling LogGCOp(4f10fcf501c44a25a511800f3478698f): free 120100335 bytes of WAL
I20260812 06:19:15.914639 22109 log_reader.cc:385] T 4f10fcf501c44a25a511800f3478698f: removed 12 log segments from log reader
I20260812 06:19:15.914702 22109 log.cc:1079] T 4f10fcf501c44a25a511800f3478698f P 854a308a6b1546819e960e724eab859c: Deleting log segment in path: /tmp/dist-test-taskw60Q2h/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515548711361-21775-0/minicluster-data/ts-0-root/wals/4f10fcf501c44a25a511800f3478698f/wal-000000003 (ops 12-16)
I20260812 06:19:15.914755 22109 log.cc:1079] T 4f10fcf501c44a25a511800f3478698f P 854a308a6b1546819e960e724eab859c: Deleting log segment in path: /tmp/dist-test-taskw60Q2h/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515548711361-21775-0/minicluster-data/ts-0-root/wals/4f10fcf501c44a25a511800f3478698f/wal-000000004 (ops 17-21)
I20260812 06:19:15.914814 22109 log.cc:1079] T 4f10fcf501c44a25a511800f3478698f P 854a308a6b1546819e960e724eab859c: Deleting log segment in path: /tmp/dist-test-taskw60Q2h/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515548711361-21775-0/minicluster-data/ts-0-root/wals/4f10fcf501c44a25a511800f3478698f/wal-000000005 (ops 22-26)
I20260812 06:19:15.914858 22109 log.cc:1079] T 4f10fcf501c44a25a511800f3478698f P 854a308a6b1546819e960e724eab859c: Deleting log segment in path: /tmp/dist-test-taskw60Q2h/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515548711361-21775-0/minicluster-data/ts-0-root/wals/4f10fcf501c44a25a511800f3478698f/wal-000000006 (ops 27-31)
I20260812 06:19:15.914894 22109 log.cc:1079] T 4f10fcf501c44a25a511800f3478698f P 854a308a6b1546819e960e724eab859c: Deleting log segment in path: /tmp/dist-test-taskw60Q2h/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515548711361-21775-0/minicluster-data/ts-0-root/wals/4f10fcf501c44a25a511800f3478698f/wal-000000007 (ops 32-36)
I20260812 06:19:15.914935 22109 log.cc:1079] T 4f10fcf501c44a25a511800f3478698f P 854a308a6b1546819e960e724eab859c: Deleting log segment in path: /tmp/dist-test-taskw60Q2h/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515548711361-21775-0/minicluster-data/ts-0-root/wals/4f10fcf501c44a25a511800f3478698f/wal-000000008 (ops 37-40)
I20260812 06:19:15.914974 22109 log.cc:1079] T 4f10fcf501c44a25a511800f3478698f P 854a308a6b1546819e960e724eab859c: Deleting log segment in path: /tmp/dist-test-taskw60Q2h/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515548711361-21775-0/minicluster-data/ts-0-root/wals/4f10fcf501c44a25a511800f3478698f/wal-000000009 (ops 41-45)
I20260812 06:19:15.915014 22109 log.cc:1079] T 4f10fcf501c44a25a511800f3478698f P 854a308a6b1546819e960e724eab859c: Deleting log segment in path: /tmp/dist-test-taskw60Q2h/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515548711361-21775-0/minicluster-data/ts-0-root/wals/4f10fcf501c44a25a511800f3478698f/wal-000000010 (ops 46-50)
I20260812 06:19:15.915053 22109 log.cc:1079] T 4f10fcf501c44a25a511800f3478698f P 854a308a6b1546819e960e724eab859c: Deleting log segment in path: /tmp/dist-test-taskw60Q2h/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515548711361-21775-0/minicluster-data/ts-0-root/wals/4f10fcf501c44a25a511800f3478698f/wal-000000011 (ops 51-54)
I20260812 06:19:15.915099 22109 log.cc:1079] T 4f10fcf501c44a25a511800f3478698f P 854a308a6b1546819e960e724eab859c: Deleting log segment in path: /tmp/dist-test-taskw60Q2h/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515548711361-21775-0/minicluster-data/ts-0-root/wals/4f10fcf501c44a25a511800f3478698f/wal-000000012 (ops 55-59)
I20260812 06:19:15.915139 22109 log.cc:1079] T 4f10fcf501c44a25a511800f3478698f P 854a308a6b1546819e960e724eab859c: Deleting log segment in path: /tmp/dist-test-taskw60Q2h/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515548711361-21775-0/minicluster-data/ts-0-root/wals/4f10fcf501c44a25a511800f3478698f/wal-000000013 (ops 60-64)
I20260812 06:19:15.915176 22109 log.cc:1079] T 4f10fcf501c44a25a511800f3478698f P 854a308a6b1546819e960e724eab859c: Deleting log segment in path: /tmp/dist-test-taskw60Q2h/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515548711361-21775-0/minicluster-data/ts-0-root/wals/4f10fcf501c44a25a511800f3478698f/wal-000000014 (ops 65-68)
I20260812 06:19:15.942328 22109 maintenance_manager.cc:643] P 854a308a6b1546819e960e724eab859c: LogGCOp(4f10fcf501c44a25a511800f3478698f) complete. Timing: real 0.028s	user 0.000s	sys 0.026s Metrics: {}
I20260812 06:19:15.942829 22175 maintenance_manager.cc:419] P 854a308a6b1546819e960e724eab859c: Scheduling UndoDeltaBlockGCOp(4f10fcf501c44a25a511800f3478698f): 447 bytes on disk
I20260812 06:19:15.943356 22109 maintenance_manager.cc:643] P 854a308a6b1546819e960e724eab859c: UndoDeltaBlockGCOp(4f10fcf501c44a25a511800f3478698f) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":64,"lbm_reads_lt_1ms":4,"spinlock_wait_cycles":2816}
I20260812 06:19:15.943868 22175 maintenance_manager.cc:419] P 854a308a6b1546819e960e724eab859c: Scheduling FlushDeltaMemStoresOp(4f10fcf501c44a25a511800f3478698f): perf score=3.181125
I20260812 06:19:15.961199 22109 maintenance_manager.cc:643] P 854a308a6b1546819e960e724eab859c: FlushDeltaMemStoresOp(4f10fcf501c44a25a511800f3478698f) complete. Timing: real 0.017s	user 0.006s	sys 0.006s Metrics: {"bytes_written":4512900,"delete_count":0,"lbm_write_time_us":4967,"lbm_writes_lt_1ms":113,"reinsert_count":0,"update_count":550}
I20260812 06:19:15.961637 22175 maintenance_manager.cc:419] P 854a308a6b1546819e960e724eab859c: Scheduling FlushDeltaMemStoresOp(4f10fcf501c44a25a511800f3478698f): perf score=2.188937
I20260812 06:19:15.970853 22109 maintenance_manager.cc:643] P 854a308a6b1546819e960e724eab859c: FlushDeltaMemStoresOp(4f10fcf501c44a25a511800f3478698f) complete. Timing: real 0.009s	user 0.007s	sys 0.001s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3446,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:19:15.971226 22175 maintenance_manager.cc:419] P 854a308a6b1546819e960e724eab859c: Scheduling MajorDeltaCompactionOp(4f10fcf501c44a25a511800f3478698f): perf score=1.000000
I20260812 06:19:16.194344 22109 maintenance_manager.cc:643] P 854a308a6b1546819e960e724eab859c: MajorDeltaCompactionOp(4f10fcf501c44a25a511800f3478698f) complete. Timing: real 0.223s	user 0.130s	sys 0.091s Metrics: {"cfile_cache_miss":734,"cfile_cache_miss_bytes":33020731,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":696,"lbm_read_time_us":15120,"lbm_reads_lt_1ms":774,"lbm_write_time_us":36027,"lbm_writes_lt_1ms":743,"mutex_wait_us":20,"peak_mem_usage":87969044,"reinsert_count":0,"spinlock_wait_cycles":15360,"thread_start_us":111,"threads_started":1,"update_count":3500}
I20260812 06:19:16.195176 22175 maintenance_manager.cc:419] P 854a308a6b1546819e960e724eab859c: Scheduling FlushDeltaMemStoresOp(4f10fcf501c44a25a511800f3478698f): perf score=18.063937
I20260812 06:19:16.254151 22109 maintenance_manager.cc:643] P 854a308a6b1546819e960e724eab859c: FlushDeltaMemStoresOp(4f10fcf501c44a25a511800f3478698f) complete. Timing: real 0.059s	user 0.037s	sys 0.012s Metrics: {"bytes_written":20512317,"delete_count":0,"lbm_write_time_us":23043,"lbm_writes_lt_1ms":503,"reinsert_count":0,"update_count":2500}
I20260812 06:19:16.254657 22175 maintenance_manager.cc:419] P 854a308a6b1546819e960e724eab859c: Scheduling FlushDeltaMemStoresOp(4f10fcf501c44a25a511800f3478698f): perf score=2.188937
I20260812 06:19:16.265883 22109 maintenance_manager.cc:643] P 854a308a6b1546819e960e724eab859c: FlushDeltaMemStoresOp(4f10fcf501c44a25a511800f3478698f) complete. Timing: real 0.011s	user 0.009s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4131,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:16.266330 22175 maintenance_manager.cc:419] P 854a308a6b1546819e960e724eab859c: Scheduling MajorDeltaCompactionOp(4f10fcf501c44a25a511800f3478698f): perf score=1.000000
I20260812 06:19:16.477016 22109 maintenance_manager.cc:643] P 854a308a6b1546819e960e724eab859c: MajorDeltaCompactionOp(4f10fcf501c44a25a511800f3478698f) complete. Timing: real 0.211s	user 0.155s	sys 0.055s Metrics: {"cfile_cache_miss":632,"cfile_cache_miss_bytes":28918099,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":221,"lbm_read_time_us":14210,"lbm_reads_lt_1ms":672,"lbm_write_time_us":35183,"lbm_writes_lt_1ms":643,"mutex_wait_us":63,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":2688,"update_count":3000}
I20260812 06:19:16.477792 22175 maintenance_manager.cc:419] P 854a308a6b1546819e960e724eab859c: Scheduling FlushDeltaMemStoresOp(4f10fcf501c44a25a511800f3478698f): perf score=14.095187
I20260812 06:19:16.523809 22109 maintenance_manager.cc:643] P 854a308a6b1546819e960e724eab859c: FlushDeltaMemStoresOp(4f10fcf501c44a25a511800f3478698f) complete. Timing: real 0.046s	user 0.023s	sys 0.019s Metrics: {"bytes_written":16409903,"delete_count":0,"lbm_write_time_us":20421,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:16.524439 22175 maintenance_manager.cc:419] P 854a308a6b1546819e960e724eab859c: Scheduling FlushDeltaMemStoresOp(4f10fcf501c44a25a511800f3478698f): perf score=2.188937
I20260812 06:19:16.541604 22109 maintenance_manager.cc:643] P 854a308a6b1546819e960e724eab859c: FlushDeltaMemStoresOp(4f10fcf501c44a25a511800f3478698f) complete. Timing: real 0.017s	user 0.010s	sys 0.006s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6381,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:16.542066 22175 maintenance_manager.cc:419] P 854a308a6b1546819e960e724eab859c: Scheduling MajorDeltaCompactionOp(4f10fcf501c44a25a511800f3478698f): perf score=1.000000
I20260812 06:19:16.745173 22109 maintenance_manager.cc:643] P 854a308a6b1546819e960e724eab859c: MajorDeltaCompactionOp(4f10fcf501c44a25a511800f3478698f) complete. Timing: real 0.203s	user 0.105s	sys 0.084s 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":1054,"lbm_read_time_us":10908,"lbm_reads_lt_1ms":572,"lbm_write_time_us":31726,"lbm_writes_lt_1ms":543,"mutex_wait_us":339,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":4224,"update_count":2500}
I20260812 06:19:16.745668 22175 maintenance_manager.cc:419] P 854a308a6b1546819e960e724eab859c: Scheduling FlushDeltaMemStoresOp(4f10fcf501c44a25a511800f3478698f): perf score=18.063937
I20260812 06:19:16.816054 22109 maintenance_manager.cc:643] P 854a308a6b1546819e960e724eab859c: FlushDeltaMemStoresOp(4f10fcf501c44a25a511800f3478698f) complete. Timing: real 0.070s	user 0.032s	sys 0.024s Metrics: {"bytes_written":20512317,"delete_count":0,"lbm_write_time_us":26872,"lbm_writes_lt_1ms":503,"reinsert_count":0,"update_count":2500}
I20260812 06:19:16.816571 22175 maintenance_manager.cc:419] P 854a308a6b1546819e960e724eab859c: Scheduling FlushDeltaMemStoresOp(4f10fcf501c44a25a511800f3478698f): perf score=2.188937
I20260812 06:19:16.826917 22109 maintenance_manager.cc:643] P 854a308a6b1546819e960e724eab859c: FlushDeltaMemStoresOp(4f10fcf501c44a25a511800f3478698f) complete. Timing: real 0.010s	user 0.004s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3970,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:16.827553 22175 maintenance_manager.cc:419] P 854a308a6b1546819e960e724eab859c: Scheduling MajorDeltaCompactionOp(4f10fcf501c44a25a511800f3478698f): perf score=1.000000
I20260812 06:19:17.023614 22109 maintenance_manager.cc:643] P 854a308a6b1546819e960e724eab859c: MajorDeltaCompactionOp(4f10fcf501c44a25a511800f3478698f) complete. Timing: real 0.196s	user 0.129s	sys 0.065s Metrics: {"cfile_cache_miss":632,"cfile_cache_miss_bytes":28918099,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":859,"lbm_read_time_us":14441,"lbm_reads_lt_1ms":672,"lbm_write_time_us":33953,"lbm_writes_lt_1ms":643,"mutex_wait_us":344,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":768,"update_count":3000}
I20260812 06:19:17.024325 22175 maintenance_manager.cc:419] P 854a308a6b1546819e960e724eab859c: Scheduling FlushDeltaMemStoresOp(4f10fcf501c44a25a511800f3478698f): perf score=15.087375
I20260812 06:19:17.072300 22109 maintenance_manager.cc:643] P 854a308a6b1546819e960e724eab859c: FlushDeltaMemStoresOp(4f10fcf501c44a25a511800f3478698f) complete. Timing: real 0.048s	user 0.039s	sys 0.009s Metrics: {"bytes_written":16820143,"delete_count":0,"lbm_write_time_us":20217,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":412,"reinsert_count":0,"update_count":2050}
I20260812 06:19:17.072892 22175 maintenance_manager.cc:419] P 854a308a6b1546819e960e724eab859c: Scheduling FlushDeltaMemStoresOp(4f10fcf501c44a25a511800f3478698f): perf score=2.188937
I20260812 06:19:17.092938 22109 maintenance_manager.cc:643] P 854a308a6b1546819e960e724eab859c: FlushDeltaMemStoresOp(4f10fcf501c44a25a511800f3478698f) complete. Timing: real 0.020s	user 0.009s	sys 0.005s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":5946,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:19:17.093398 22175 maintenance_manager.cc:419] P 854a308a6b1546819e960e724eab859c: Scheduling FlushDeltaMemStoresOp(4f10fcf501c44a25a511800f3478698f): perf score=2.188937
I20260812 06:19:17.104185 22109 maintenance_manager.cc:643] P 854a308a6b1546819e960e724eab859c: FlushDeltaMemStoresOp(4f10fcf501c44a25a511800f3478698f) complete. Timing: real 0.011s	user 0.000s	sys 0.009s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4307,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:17.104619 22175 maintenance_manager.cc:419] P 854a308a6b1546819e960e724eab859c: Scheduling MajorDeltaCompactionOp(4f10fcf501c44a25a511800f3478698f): perf score=1.000000
I20260812 06:19:17.324200 22109 maintenance_manager.cc:643] P 854a308a6b1546819e960e724eab859c: MajorDeltaCompactionOp(4f10fcf501c44a25a511800f3478698f) complete. Timing: real 0.219s	user 0.140s	sys 0.076s Metrics: {"cfile_cache_miss":633,"cfile_cache_miss_bytes":28918201,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":534,"lbm_read_time_us":14948,"lbm_reads_lt_1ms":673,"lbm_write_time_us":35508,"lbm_writes_lt_1ms":643,"mutex_wait_us":55,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":26496,"update_count":3000}
I20260812 06:19:17.325038 22175 maintenance_manager.cc:419] P 854a308a6b1546819e960e724eab859c: Scheduling FlushDeltaMemStoresOp(4f10fcf501c44a25a511800f3478698f): perf score=16.079562
I20260812 06:19:17.391100 22109 maintenance_manager.cc:643] P 854a308a6b1546819e960e724eab859c: FlushDeltaMemStoresOp(4f10fcf501c44a25a511800f3478698f) complete. Timing: real 0.066s	user 0.033s	sys 0.020s Metrics: {"bytes_written":18584181,"delete_count":0,"lbm_write_time_us":24774,"lbm_writes_lt_1ms":456,"mutex_wait_us":800,"reinsert_count":0,"update_count":2265}
I20260812 06:19:17.391623 22175 maintenance_manager.cc:419] P 854a308a6b1546819e960e724eab859c: Scheduling FlushDeltaMemStoresOp(4f10fcf501c44a25a511800f3478698f): perf score=4.173312
I20260812 06:19:17.408954 22109 maintenance_manager.cc:643] P 854a308a6b1546819e960e724eab859c: FlushDeltaMemStoresOp(4f10fcf501c44a25a511800f3478698f) complete. Timing: real 0.017s	user 0.013s	sys 0.003s Metrics: {"bytes_written":6030804,"delete_count":0,"lbm_write_time_us":6714,"lbm_writes_lt_1ms":150,"reinsert_count":0,"update_count":735}
I20260812 06:19:17.409518 22175 maintenance_manager.cc:419] P 854a308a6b1546819e960e724eab859c: Scheduling FlushMRSOp(4f10fcf501c44a25a511800f3478698f): perf score=1.000000
I20260812 06:19:17.437983 22109 maintenance_manager.cc:643] P 854a308a6b1546819e960e724eab859c: FlushMRSOp(4f10fcf501c44a25a511800f3478698f) complete. Timing: real 0.028s	user 0.026s	sys 0.001s Metrics: {"bytes_written":1275449,"cfile_init":1,"dirs.queue_time_us":51,"dirs.run_cpu_time_us":137,"dirs.run_wall_time_us":1416,"drs_written":1,"lbm_read_time_us":57,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1977,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":31}
I20260812 06:19:17.438704 22175 maintenance_manager.cc:419] P 854a308a6b1546819e960e724eab859c: Scheduling LogGCOp(4f10fcf501c44a25a511800f3478698f): free 121006381 bytes of WAL
I20260812 06:19:17.438980 22109 log_reader.cc:385] T 4f10fcf501c44a25a511800f3478698f: removed 12 log segments from log reader
I20260812 06:19:17.439039 22109 log.cc:1079] T 4f10fcf501c44a25a511800f3478698f P 854a308a6b1546819e960e724eab859c: Deleting log segment in path: /tmp/dist-test-taskw60Q2h/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515548711361-21775-0/minicluster-data/ts-0-root/wals/4f10fcf501c44a25a511800f3478698f/wal-000000015 (ops 69-73)
I20260812 06:19:17.439078 22109 log.cc:1079] T 4f10fcf501c44a25a511800f3478698f P 854a308a6b1546819e960e724eab859c: Deleting log segment in path: /tmp/dist-test-taskw60Q2h/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515548711361-21775-0/minicluster-data/ts-0-root/wals/4f10fcf501c44a25a511800f3478698f/wal-000000016 (ops 74-78)
I20260812 06:19:17.439126 22109 log.cc:1079] T 4f10fcf501c44a25a511800f3478698f P 854a308a6b1546819e960e724eab859c: Deleting log segment in path: /tmp/dist-test-taskw60Q2h/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515548711361-21775-0/minicluster-data/ts-0-root/wals/4f10fcf501c44a25a511800f3478698f/wal-000000017 (ops 79-83)
I20260812 06:19:17.439152 22109 log.cc:1079] T 4f10fcf501c44a25a511800f3478698f P 854a308a6b1546819e960e724eab859c: Deleting log segment in path: /tmp/dist-test-taskw60Q2h/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515548711361-21775-0/minicluster-data/ts-0-root/wals/4f10fcf501c44a25a511800f3478698f/wal-000000018 (ops 84-88)
I20260812 06:19:17.439174 22109 log.cc:1079] T 4f10fcf501c44a25a511800f3478698f P 854a308a6b1546819e960e724eab859c: Deleting log segment in path: /tmp/dist-test-taskw60Q2h/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515548711361-21775-0/minicluster-data/ts-0-root/wals/4f10fcf501c44a25a511800f3478698f/wal-000000019 (ops 89-93)
I20260812 06:19:17.439203 22109 log.cc:1079] T 4f10fcf501c44a25a511800f3478698f P 854a308a6b1546819e960e724eab859c: Deleting log segment in path: /tmp/dist-test-taskw60Q2h/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515548711361-21775-0/minicluster-data/ts-0-root/wals/4f10fcf501c44a25a511800f3478698f/wal-000000020 (ops 94-98)
I20260812 06:19:17.439231 22109 log.cc:1079] T 4f10fcf501c44a25a511800f3478698f P 854a308a6b1546819e960e724eab859c: Deleting log segment in path: /tmp/dist-test-taskw60Q2h/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515548711361-21775-0/minicluster-data/ts-0-root/wals/4f10fcf501c44a25a511800f3478698f/wal-000000021 (ops 99-103)
I20260812 06:19:17.439261 22109 log.cc:1079] T 4f10fcf501c44a25a511800f3478698f P 854a308a6b1546819e960e724eab859c: Deleting log segment in path: /tmp/dist-test-taskw60Q2h/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515548711361-21775-0/minicluster-data/ts-0-root/wals/4f10fcf501c44a25a511800f3478698f/wal-000000022 (ops 104-108)
I20260812 06:19:17.439296 22109 log.cc:1079] T 4f10fcf501c44a25a511800f3478698f P 854a308a6b1546819e960e724eab859c: Deleting log segment in path: /tmp/dist-test-taskw60Q2h/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515548711361-21775-0/minicluster-data/ts-0-root/wals/4f10fcf501c44a25a511800f3478698f/wal-000000023 (ops 109-112)
I20260812 06:19:17.439327 22109 log.cc:1079] T 4f10fcf501c44a25a511800f3478698f P 854a308a6b1546819e960e724eab859c: Deleting log segment in path: /tmp/dist-test-taskw60Q2h/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515548711361-21775-0/minicluster-data/ts-0-root/wals/4f10fcf501c44a25a511800f3478698f/wal-000000024 (ops 113-117)
I20260812 06:19:17.439356 22109 log.cc:1079] T 4f10fcf501c44a25a511800f3478698f P 854a308a6b1546819e960e724eab859c: Deleting log segment in path: /tmp/dist-test-taskw60Q2h/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515548711361-21775-0/minicluster-data/ts-0-root/wals/4f10fcf501c44a25a511800f3478698f/wal-000000025 (ops 118-122)
I20260812 06:19:17.439384 22109 log.cc:1079] T 4f10fcf501c44a25a511800f3478698f P 854a308a6b1546819e960e724eab859c: Deleting log segment in path: /tmp/dist-test-taskw60Q2h/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515548711361-21775-0/minicluster-data/ts-0-root/wals/4f10fcf501c44a25a511800f3478698f/wal-000000026 (ops 123-127)
I20260812 06:19:17.469836 22109 maintenance_manager.cc:643] P 854a308a6b1546819e960e724eab859c: LogGCOp(4f10fcf501c44a25a511800f3478698f) complete. Timing: real 0.031s	user 0.000s	sys 0.029s Metrics: {}
I20260812 06:19:17.470209 22175 maintenance_manager.cc:419] P 854a308a6b1546819e960e724eab859c: Scheduling FlushDeltaMemStoresOp(4f10fcf501c44a25a511800f3478698f): perf score=3.181125
I20260812 06:19:17.482249 22109 maintenance_manager.cc:643] P 854a308a6b1546819e960e724eab859c: FlushDeltaMemStoresOp(4f10fcf501c44a25a511800f3478698f) complete. Timing: real 0.012s	user 0.003s	sys 0.006s Metrics: {"bytes_written":4512901,"delete_count":0,"lbm_write_time_us":4568,"lbm_writes_lt_1ms":113,"reinsert_count":0,"update_count":550}
I20260812 06:19:17.482681 22175 maintenance_manager.cc:419] P 854a308a6b1546819e960e724eab859c: Scheduling LogGCOp(4f10fcf501c44a25a511800f3478698f): free 12018008 bytes of WAL
I20260812 06:19:17.482906 22109 log_reader.cc:385] T 4f10fcf501c44a25a511800f3478698f: removed 1 log segments from log reader
I20260812 06:19:17.482980 22109 log.cc:1079] T 4f10fcf501c44a25a511800f3478698f P 854a308a6b1546819e960e724eab859c: Deleting log segment in path: /tmp/dist-test-taskw60Q2h/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515548711361-21775-0/minicluster-data/ts-0-root/wals/4f10fcf501c44a25a511800f3478698f/wal-000000027 (ops 128-132)
I20260812 06:19:17.485435 22109 maintenance_manager.cc:643] P 854a308a6b1546819e960e724eab859c: LogGCOp(4f10fcf501c44a25a511800f3478698f) complete. Timing: real 0.003s	user 0.000s	sys 0.001s Metrics: {}
I20260812 06:19:17.485723 22175 maintenance_manager.cc:419] P 854a308a6b1546819e960e724eab859c: Scheduling UndoDeltaBlockGCOp(4f10fcf501c44a25a511800f3478698f): 482 bytes on disk
I20260812 06:19:17.486084 22109 maintenance_manager.cc:643] P 854a308a6b1546819e960e724eab859c: UndoDeltaBlockGCOp(4f10fcf501c44a25a511800f3478698f) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":49,"lbm_reads_lt_1ms":4}
I20260812 06:19:17.486528 22175 maintenance_manager.cc:419] P 854a308a6b1546819e960e724eab859c: Scheduling FlushDeltaMemStoresOp(4f10fcf501c44a25a511800f3478698f): perf score=2.188937
I20260812 06:19:17.497555 22109 maintenance_manager.cc:643] P 854a308a6b1546819e960e724eab859c: FlushDeltaMemStoresOp(4f10fcf501c44a25a511800f3478698f) complete. Timing: real 0.011s	user 0.007s	sys 0.002s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3531,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:19:17.498164 22175 maintenance_manager.cc:419] P 854a308a6b1546819e960e724eab859c: Scheduling MajorDeltaCompactionOp(4f10fcf501c44a25a511800f3478698f): perf score=1.000000
I20260812 06:19:17.753744 22109 maintenance_manager.cc:643] P 854a308a6b1546819e960e724eab859c: MajorDeltaCompactionOp(4f10fcf501c44a25a511800f3478698f) complete. Timing: real 0.255s	user 0.156s	sys 0.087s Metrics: {"cfile_cache_miss":834,"cfile_cache_miss_bytes":37123152,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":488,"lbm_read_time_us":19096,"lbm_reads_lt_1ms":874,"lbm_write_time_us":43181,"lbm_writes_lt_1ms":843,"mutex_wait_us":320,"peak_mem_usage":100395616,"reinsert_count":0,"spinlock_wait_cycles":14848,"thread_start_us":84,"threads_started":1,"update_count":4000}
I20260812 06:19:17.754384 22175 maintenance_manager.cc:419] P 854a308a6b1546819e960e724eab859c: Scheduling FlushDeltaMemStoresOp(4f10fcf501c44a25a511800f3478698f): perf score=22.032687
I20260812 06:19:17.858616 22109 maintenance_manager.cc:643] P 854a308a6b1546819e960e724eab859c: FlushDeltaMemStoresOp(4f10fcf501c44a25a511800f3478698f) complete. Timing: real 0.104s	user 0.058s	sys 0.032s Metrics: {"bytes_written":24614719,"delete_count":0,"lbm_write_time_us":43974,"lbm_writes_1-10_ms":2,"lbm_writes_lt_1ms":601,"reinsert_count":0,"update_count":3000}
I20260812 06:19:17.859122 22175 maintenance_manager.cc:419] P 854a308a6b1546819e960e724eab859c: Scheduling FlushDeltaMemStoresOp(4f10fcf501c44a25a511800f3478698f): perf score=6.157687
I20260812 06:19:17.885340 22109 maintenance_manager.cc:643] P 854a308a6b1546819e960e724eab859c: FlushDeltaMemStoresOp(4f10fcf501c44a25a511800f3478698f) complete. Timing: real 0.026s	user 0.018s	sys 0.004s Metrics: {"bytes_written":8205078,"delete_count":0,"lbm_write_time_us":9882,"lbm_writes_lt_1ms":203,"reinsert_count":0,"update_count":1000}
I20260812 06:19:17.885905 22175 maintenance_manager.cc:419] P 854a308a6b1546819e960e724eab859c: Scheduling MajorDeltaCompactionOp(4f10fcf501c44a25a511800f3478698f): perf score=1.000000
I20260812 06:19:18.097694 22109 maintenance_manager.cc:643] P 854a308a6b1546819e960e724eab859c: MajorDeltaCompactionOp(4f10fcf501c44a25a511800f3478698f) complete. Timing: real 0.212s	user 0.142s	sys 0.068s Metrics: {"cfile_cache_miss":832,"cfile_cache_miss_bytes":37122914,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":170,"lbm_read_time_us":17582,"lbm_reads_lt_1ms":864,"lbm_write_time_us":44922,"lbm_writes_lt_1ms":843,"peak_mem_usage":100395616,"reinsert_count":0,"spinlock_wait_cycles":65024,"update_count":4000}
I20260812 06:19:18.098402 22175 maintenance_manager.cc:419] P 854a308a6b1546819e960e724eab859c: Scheduling FlushDeltaMemStoresOp(4f10fcf501c44a25a511800f3478698f): perf score=18.063937
I20260812 06:19:18.179307 22109 maintenance_manager.cc:643] P 854a308a6b1546819e960e724eab859c: FlushDeltaMemStoresOp(4f10fcf501c44a25a511800f3478698f) complete. Timing: real 0.081s	user 0.057s	sys 0.015s Metrics: {"bytes_written":20512315,"delete_count":0,"lbm_write_time_us":33662,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":502,"reinsert_count":0,"update_count":2500}
I20260812 06:19:18.179808 22175 maintenance_manager.cc:419] P 854a308a6b1546819e960e724eab859c: Scheduling FlushDeltaMemStoresOp(4f10fcf501c44a25a511800f3478698f): perf score=3.181125
I20260812 06:19:18.197439 22109 maintenance_manager.cc:643] P 854a308a6b1546819e960e724eab859c: FlushDeltaMemStoresOp(4f10fcf501c44a25a511800f3478698f) complete. Timing: real 0.017s	user 0.012s	sys 0.004s Metrics: {"bytes_written":4512912,"delete_count":0,"lbm_write_time_us":7197,"lbm_writes_lt_1ms":113,"reinsert_count":0,"update_count":550}
I20260812 06:19:18.197866 22175 maintenance_manager.cc:419] P 854a308a6b1546819e960e724eab859c: Scheduling FlushDeltaMemStoresOp(4f10fcf501c44a25a511800f3478698f): perf score=2.188937
I20260812 06:19:18.207165 22109 maintenance_manager.cc:643] P 854a308a6b1546819e960e724eab859c: FlushDeltaMemStoresOp(4f10fcf501c44a25a511800f3478698f) complete. Timing: real 0.009s	user 0.004s	sys 0.003s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3537,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:19:18.207580 22175 maintenance_manager.cc:419] P 854a308a6b1546819e960e724eab859c: Scheduling MajorDeltaCompactionOp(4f10fcf501c44a25a511800f3478698f): perf score=1.000000
I20260812 06:19:18.404261 22109 maintenance_manager.cc:643] P 854a308a6b1546819e960e724eab859c: MajorDeltaCompactionOp(4f10fcf501c44a25a511800f3478698f) complete. Timing: real 0.197s	user 0.161s	sys 0.031s Metrics: {"cfile_cache_miss":733,"cfile_cache_miss_bytes":33020627,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":788,"lbm_read_time_us":14035,"lbm_reads_lt_1ms":773,"lbm_write_time_us":40535,"lbm_writes_lt_1ms":743,"mutex_wait_us":358,"peak_mem_usage":87969044,"reinsert_count":0,"spinlock_wait_cycles":5504,"update_count":3500}
I20260812 06:19:18.405086 22175 maintenance_manager.cc:419] P 854a308a6b1546819e960e724eab859c: Scheduling FlushDeltaMemStoresOp(4f10fcf501c44a25a511800f3478698f): perf score=15.087375
I20260812 06:19:18.460484 22109 maintenance_manager.cc:643] P 854a308a6b1546819e960e724eab859c: FlushDeltaMemStoresOp(4f10fcf501c44a25a511800f3478698f) complete. Timing: real 0.055s	user 0.028s	sys 0.024s Metrics: {"bytes_written":16820148,"delete_count":0,"lbm_write_time_us":24668,"lbm_writes_1-10_ms":3,"lbm_writes_lt_1ms":410,"reinsert_count":0,"update_count":2050}
I20260812 06:19:18.462031 22175 maintenance_manager.cc:419] P 854a308a6b1546819e960e724eab859c: Scheduling FlushDeltaMemStoresOp(4f10fcf501c44a25a511800f3478698f): perf score=2.188937
I20260812 06:19:18.476711 22109 maintenance_manager.cc:643] P 854a308a6b1546819e960e724eab859c: FlushDeltaMemStoresOp(4f10fcf501c44a25a511800f3478698f) complete. Timing: real 0.015s	user 0.014s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5712,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:18.477193 22175 maintenance_manager.cc:419] P 854a308a6b1546819e960e724eab859c: Scheduling FlushDeltaMemStoresOp(4f10fcf501c44a25a511800f3478698f): perf score=2.188937
I20260812 06:19:18.489140 22109 maintenance_manager.cc:643] P 854a308a6b1546819e960e724eab859c: FlushDeltaMemStoresOp(4f10fcf501c44a25a511800f3478698f) complete. Timing: real 0.012s	user 0.011s	sys 0.000s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3911,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:19:18.489883 22175 maintenance_manager.cc:419] P 854a308a6b1546819e960e724eab859c: Scheduling MajorDeltaCompactionOp(4f10fcf501c44a25a511800f3478698f): perf score=1.000000
I20260812 06:19:18.672463 22109 maintenance_manager.cc:643] P 854a308a6b1546819e960e724eab859c: MajorDeltaCompactionOp(4f10fcf501c44a25a511800f3478698f) complete. Timing: real 0.182s	user 0.135s	sys 0.047s Metrics: {"cfile_cache_miss":633,"cfile_cache_miss_bytes":28918207,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":289,"lbm_read_time_us":14405,"lbm_reads_lt_1ms":673,"lbm_write_time_us":35408,"lbm_writes_lt_1ms":643,"mutex_wait_us":62,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":14080,"update_count":3000}
I20260812 06:19:18.673178 22175 maintenance_manager.cc:419] P 854a308a6b1546819e960e724eab859c: Scheduling FlushDeltaMemStoresOp(4f10fcf501c44a25a511800f3478698f): perf score=14.095187
I20260812 06:19:18.725199 22109 maintenance_manager.cc:643] P 854a308a6b1546819e960e724eab859c: FlushDeltaMemStoresOp(4f10fcf501c44a25a511800f3478698f) complete. Timing: real 0.052s	user 0.042s	sys 0.008s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":22243,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:18.725772 22175 maintenance_manager.cc:419] P 854a308a6b1546819e960e724eab859c: Scheduling FlushDeltaMemStoresOp(4f10fcf501c44a25a511800f3478698f): perf score=2.188937
I20260812 06:19:18.737970 22109 maintenance_manager.cc:643] P 854a308a6b1546819e960e724eab859c: FlushDeltaMemStoresOp(4f10fcf501c44a25a511800f3478698f) complete. Timing: real 0.012s	user 0.004s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4070,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:18.738440 22175 maintenance_manager.cc:419] P 854a308a6b1546819e960e724eab859c: Scheduling FlushMRSOp(4f10fcf501c44a25a511800f3478698f): perf score=1.000000
I20260812 06:19:18.765554 22109 maintenance_manager.cc:643] P 854a308a6b1546819e960e724eab859c: FlushMRSOp(4f10fcf501c44a25a511800f3478698f) complete. Timing: real 0.027s	user 0.025s	sys 0.000s Metrics: {"bytes_written":1152510,"cfile_init":1,"dirs.queue_time_us":64,"dirs.run_cpu_time_us":229,"dirs.run_wall_time_us":1262,"drs_written":1,"lbm_read_time_us":40,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1684,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":28}
I20260812 06:19:18.766186 22175 maintenance_manager.cc:419] P 854a308a6b1546819e960e724eab859c: Scheduling LogGCOp(4f10fcf501c44a25a511800f3478698f): free 108535632 bytes of WAL
I20260812 06:19:18.766415 22109 log_reader.cc:385] T 4f10fcf501c44a25a511800f3478698f: removed 11 log segments from log reader
I20260812 06:19:18.766461 22109 log.cc:1079] T 4f10fcf501c44a25a511800f3478698f P 854a308a6b1546819e960e724eab859c: Deleting log segment in path: /tmp/dist-test-taskw60Q2h/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515548711361-21775-0/minicluster-data/ts-0-root/wals/4f10fcf501c44a25a511800f3478698f/wal-000000028 (ops 133-137)
I20260812 06:19:18.766491 22109 log.cc:1079] T 4f10fcf501c44a25a511800f3478698f P 854a308a6b1546819e960e724eab859c: Deleting log segment in path: /tmp/dist-test-taskw60Q2h/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515548711361-21775-0/minicluster-data/ts-0-root/wals/4f10fcf501c44a25a511800f3478698f/wal-000000029 (ops 138-142)
I20260812 06:19:18.766561 22109 log.cc:1079] T 4f10fcf501c44a25a511800f3478698f P 854a308a6b1546819e960e724eab859c: Deleting log segment in path: /tmp/dist-test-taskw60Q2h/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515548711361-21775-0/minicluster-data/ts-0-root/wals/4f10fcf501c44a25a511800f3478698f/wal-000000030 (ops 143-147)
I20260812 06:19:18.766592 22109 log.cc:1079] T 4f10fcf501c44a25a511800f3478698f P 854a308a6b1546819e960e724eab859c: Deleting log segment in path: /tmp/dist-test-taskw60Q2h/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515548711361-21775-0/minicluster-data/ts-0-root/wals/4f10fcf501c44a25a511800f3478698f/wal-000000031 (ops 148-152)
I20260812 06:19:18.766633 22109 log.cc:1079] T 4f10fcf501c44a25a511800f3478698f P 854a308a6b1546819e960e724eab859c: Deleting log segment in path: /tmp/dist-test-taskw60Q2h/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515548711361-21775-0/minicluster-data/ts-0-root/wals/4f10fcf501c44a25a511800f3478698f/wal-000000032 (ops 153-157)
I20260812 06:19:18.766672 22109 log.cc:1079] T 4f10fcf501c44a25a511800f3478698f P 854a308a6b1546819e960e724eab859c: Deleting log segment in path: /tmp/dist-test-taskw60Q2h/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515548711361-21775-0/minicluster-data/ts-0-root/wals/4f10fcf501c44a25a511800f3478698f/wal-000000033 (ops 158-162)
I20260812 06:19:18.766721 22109 log.cc:1079] T 4f10fcf501c44a25a511800f3478698f P 854a308a6b1546819e960e724eab859c: Deleting log segment in path: /tmp/dist-test-taskw60Q2h/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515548711361-21775-0/minicluster-data/ts-0-root/wals/4f10fcf501c44a25a511800f3478698f/wal-000000034 (ops 163-166)
I20260812 06:19:18.766759 22109 log.cc:1079] T 4f10fcf501c44a25a511800f3478698f P 854a308a6b1546819e960e724eab859c: Deleting log segment in path: /tmp/dist-test-taskw60Q2h/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515548711361-21775-0/minicluster-data/ts-0-root/wals/4f10fcf501c44a25a511800f3478698f/wal-000000035 (ops 167-171)
I20260812 06:19:18.766799 22109 log.cc:1079] T 4f10fcf501c44a25a511800f3478698f P 854a308a6b1546819e960e724eab859c: Deleting log segment in path: /tmp/dist-test-taskw60Q2h/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515548711361-21775-0/minicluster-data/ts-0-root/wals/4f10fcf501c44a25a511800f3478698f/wal-000000036 (ops 172-176)
I20260812 06:19:18.766839 22109 log.cc:1079] T 4f10fcf501c44a25a511800f3478698f P 854a308a6b1546819e960e724eab859c: Deleting log segment in path: /tmp/dist-test-taskw60Q2h/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515548711361-21775-0/minicluster-data/ts-0-root/wals/4f10fcf501c44a25a511800f3478698f/wal-000000037 (ops 177-180)
I20260812 06:19:18.766880 22109 log.cc:1079] T 4f10fcf501c44a25a511800f3478698f P 854a308a6b1546819e960e724eab859c: Deleting log segment in path: /tmp/dist-test-taskw60Q2h/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515548711361-21775-0/minicluster-data/ts-0-root/wals/4f10fcf501c44a25a511800f3478698f/wal-000000038 (ops 181-185)
I20260812 06:19:18.791739 22109 maintenance_manager.cc:643] P 854a308a6b1546819e960e724eab859c: LogGCOp(4f10fcf501c44a25a511800f3478698f) complete. Timing: real 0.025s	user 0.000s	sys 0.022s Metrics: {}
I20260812 06:19:18.792250 22175 maintenance_manager.cc:419] P 854a308a6b1546819e960e724eab859c: Scheduling UndoDeltaBlockGCOp(4f10fcf501c44a25a511800f3478698f): 451 bytes on disk
I20260812 06:19:18.792877 22109 maintenance_manager.cc:643] P 854a308a6b1546819e960e724eab859c: UndoDeltaBlockGCOp(4f10fcf501c44a25a511800f3478698f) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":71,"lbm_reads_lt_1ms":4}
I20260812 06:19:18.793537 22175 maintenance_manager.cc:419] P 854a308a6b1546819e960e724eab859c: Scheduling FlushDeltaMemStoresOp(4f10fcf501c44a25a511800f3478698f): perf score=3.181125
I20260812 06:19:18.806660 22109 maintenance_manager.cc:643] P 854a308a6b1546819e960e724eab859c: FlushDeltaMemStoresOp(4f10fcf501c44a25a511800f3478698f) complete. Timing: real 0.013s	user 0.009s	sys 0.001s Metrics: {"bytes_written":4512900,"delete_count":0,"lbm_write_time_us":4529,"lbm_writes_lt_1ms":113,"reinsert_count":0,"update_count":550}
I20260812 06:19:18.807072 22175 maintenance_manager.cc:419] P 854a308a6b1546819e960e724eab859c: Scheduling FlushDeltaMemStoresOp(4f10fcf501c44a25a511800f3478698f): perf score=2.188937
I20260812 06:19:18.816439 22109 maintenance_manager.cc:643] P 854a308a6b1546819e960e724eab859c: FlushDeltaMemStoresOp(4f10fcf501c44a25a511800f3478698f) complete. Timing: real 0.009s	user 0.001s	sys 0.008s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3651,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:19:18.816833 22175 maintenance_manager.cc:419] P 854a308a6b1546819e960e724eab859c: Scheduling MajorDeltaCompactionOp(4f10fcf501c44a25a511800f3478698f): perf score=1.000000
I20260812 06:19:18.997834 22109 maintenance_manager.cc:643] P 854a308a6b1546819e960e724eab859c: MajorDeltaCompactionOp(4f10fcf501c44a25a511800f3478698f) complete. Timing: real 0.181s	user 0.133s	sys 0.048s Metrics: {"cfile_cache_miss":734,"cfile_cache_miss_bytes":33020733,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":158,"lbm_read_time_us":13674,"lbm_reads_lt_1ms":774,"lbm_write_time_us":36134,"lbm_writes_lt_1ms":743,"mutex_wait_us":21,"peak_mem_usage":87969044,"reinsert_count":0,"spinlock_wait_cycles":14080,"thread_start_us":75,"threads_started":1,"update_count":3500}
I20260812 06:19:18.998528 22175 maintenance_manager.cc:419] P 854a308a6b1546819e960e724eab859c: Scheduling FlushDeltaMemStoresOp(4f10fcf501c44a25a511800f3478698f): perf score=14.095187
I20260812 06:19:19.049256 22109 maintenance_manager.cc:643] P 854a308a6b1546819e960e724eab859c: FlushDeltaMemStoresOp(4f10fcf501c44a25a511800f3478698f) complete. Timing: real 0.050s	user 0.016s	sys 0.024s Metrics: {"bytes_written":16409900,"delete_count":0,"lbm_write_time_us":18160,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:19.049904 22175 maintenance_manager.cc:419] P 854a308a6b1546819e960e724eab859c: Scheduling FlushDeltaMemStoresOp(4f10fcf501c44a25a511800f3478698f): perf score=2.188937
I20260812 06:19:19.063256 22109 maintenance_manager.cc:643] P 854a308a6b1546819e960e724eab859c: FlushDeltaMemStoresOp(4f10fcf501c44a25a511800f3478698f) complete. Timing: real 0.013s	user 0.011s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5554,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:19.063810 22175 maintenance_manager.cc:419] P 854a308a6b1546819e960e724eab859c: Scheduling MajorDeltaCompactionOp(4f10fcf501c44a25a511800f3478698f): perf score=1.000000
I20260812 06:19:19.102943 21775 heavy-update-compaction-itest.cc:229] Time spent updating: real 4.747s	user 1.782s	sys 0.163s
I20260812 06:19:19.166878 21775 heavy-update-compaction-itest.cc:265] Time spent scanning: real 0.063s	user 0.001s	sys 0.000s
I20260812 06:19:19.167436 21775 tablet_server.cc:179] TabletServer@127.21.67.193:0 shutting down...
I20260812 06:19:19.209220 22109 maintenance_manager.cc:643] P 854a308a6b1546819e960e724eab859c: MajorDeltaCompactionOp(4f10fcf501c44a25a511800f3478698f) complete. Timing: real 0.145s	user 0.099s	sys 0.045s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24815682,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":215,"lbm_read_time_us":13763,"lbm_reads_lt_1ms":568,"lbm_write_time_us":28098,"lbm_writes_lt_1ms":543,"mutex_wait_us":23,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":9344,"update_count":2500}
I20260812 06:19:19.210175 21775 ts_tablet_manager.cc:1507] Shutting down tablet manager...
I20260812 06:19:19.210497 21775 tablet_replica.cc:333] T 4f10fcf501c44a25a511800f3478698f P 854a308a6b1546819e960e724eab859c: stopping tablet replica
I20260812 06:19:19.210680 21775 raft_consensus.cc:2243] T 4f10fcf501c44a25a511800f3478698f P 854a308a6b1546819e960e724eab859c [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:19:19.210879 21775 raft_consensus.cc:2272] T 4f10fcf501c44a25a511800f3478698f P 854a308a6b1546819e960e724eab859c [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:19:19.229099 21775 tablet_server.cc:196] TabletServer@127.21.67.193:0 shutdown complete.
I20260812 06:19:19.255556 21775 master.cc:562] Master@127.21.67.254:33089 shutting down...
I20260812 06:19:19.259580 21775 raft_consensus.cc:2243] T 00000000000000000000000000000000 P a6a207e5dbae448b94361ff1da218560 [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:19:19.259768 21775 raft_consensus.cc:2272] T 00000000000000000000000000000000 P a6a207e5dbae448b94361ff1da218560 [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:19:19.259859 21775 tablet_replica.cc:333] T 00000000000000000000000000000000 P a6a207e5dbae448b94361ff1da218560: stopping tablet replica
I20260812 06:19:19.272334 21775 master.cc:584] Master@127.21.67.254:33089 shutdown complete.
[       OK ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/1 (5213 ms)
[----------] 2 tests from EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy (10643 ms total)

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