[==========] 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:38.782142 20007 internal_mini_cluster.cc:156] Creating distributed mini masters. Addrs: 127.19.137.254:41271
I20260812 06:19:38.783124 20007 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:38.783731 20007 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:19:38.789764 20013 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:38.789764 20012 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:38.789809 20007 server_base.cc:1061] running on GCE node
W20260812 06:19:38.790057 20015 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:38.790560 20007 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:19:38.790652 20007 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:38.790692 20007 hybrid_clock.cc:648] HybridClock initialized: now 1786515578790690 us; error 0 us; skew 500 ppm
I20260812 06:19:38.792433 20007 webserver.cc:533] Webserver started at http://127.19.137.254:46457/ using document root <none> and password file <none>
I20260812 06:19:38.792944 20007 fs_manager.cc:362] Metadata directory not provided
I20260812 06:19:38.793000 20007 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:19:38.793205 20007 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:19:38.794831 20007 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskztgv1X/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515578771685-20007-0/minicluster-data/master-0-root/instance:
uuid: "14faa334333c484b97c2975938943d97"
format_stamp: "Formatted at 2026-08-12 06:19:38 on dist-test-slave-f7th"
I20260812 06:19:38.798513 20007 fs_manager.cc:696] Time spent creating directory manager: real 0.003s	user 0.005s	sys 0.000s
I20260812 06:19:38.800642 20020 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:38.801704 20007 fs_manager.cc:730] Time spent opening block manager: real 0.002s	user 0.001s	sys 0.000s
I20260812 06:19:38.801815 20007 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskztgv1X/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515578771685-20007-0/minicluster-data/master-0-root
uuid: "14faa334333c484b97c2975938943d97"
format_stamp: "Formatted at 2026-08-12 06:19:38 on dist-test-slave-f7th"
I20260812 06:19:38.801903 20007 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskztgv1X/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515578771685-20007-0/minicluster-data/master-0-root
metadata directory: /tmp/dist-test-taskztgv1X/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515578771685-20007-0/minicluster-data/master-0-root
1 data directories: /tmp/dist-test-taskztgv1X/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515578771685-20007-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:38.813129 20007 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:19:38.813706 20007 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:38.813846 20007 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:19:38.821353 20007 rpc_server.cc:307] RPC server started. Bound to: 127.19.137.254:41271
I20260812 06:19:38.821362 20072 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.19.137.254:41271 every 8 connection(s)
I20260812 06:19:38.823536 20073 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:38.828825 20073 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P 14faa334333c484b97c2975938943d97: Bootstrap starting.
I20260812 06:19:38.831058 20073 tablet_bootstrap.cc:654] T 00000000000000000000000000000000 P 14faa334333c484b97c2975938943d97: Neither blocks nor log segments found. Creating new log.
I20260812 06:19:38.831984 20073 log.cc:826] T 00000000000000000000000000000000 P 14faa334333c484b97c2975938943d97: Log is configured to *not* fsync() on all Append() calls
I20260812 06:19:38.833636 20073 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P 14faa334333c484b97c2975938943d97: No bootstrap required, opened a new log
I20260812 06:19:38.836483 20073 raft_consensus.cc:359] T 00000000000000000000000000000000 P 14faa334333c484b97c2975938943d97 [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "14faa334333c484b97c2975938943d97" member_type: VOTER }
I20260812 06:19:38.836659 20073 raft_consensus.cc:385] T 00000000000000000000000000000000 P 14faa334333c484b97c2975938943d97 [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:19:38.836727 20073 raft_consensus.cc:740] T 00000000000000000000000000000000 P 14faa334333c484b97c2975938943d97 [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: 14faa334333c484b97c2975938943d97, State: Initialized, Role: FOLLOWER
I20260812 06:19:38.837298 20073 consensus_queue.cc:260] T 00000000000000000000000000000000 P 14faa334333c484b97c2975938943d97 [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: "14faa334333c484b97c2975938943d97" member_type: VOTER }
I20260812 06:19:38.837450 20073 raft_consensus.cc:399] T 00000000000000000000000000000000 P 14faa334333c484b97c2975938943d97 [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:19:38.837513 20073 raft_consensus.cc:493] T 00000000000000000000000000000000 P 14faa334333c484b97c2975938943d97 [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:19:38.837635 20073 raft_consensus.cc:3060] T 00000000000000000000000000000000 P 14faa334333c484b97c2975938943d97 [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:19:38.838438 20073 raft_consensus.cc:515] T 00000000000000000000000000000000 P 14faa334333c484b97c2975938943d97 [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "14faa334333c484b97c2975938943d97" member_type: VOTER }
I20260812 06:19:38.838857 20073 leader_election.cc:304] T 00000000000000000000000000000000 P 14faa334333c484b97c2975938943d97 [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: 14faa334333c484b97c2975938943d97; no voters: 
I20260812 06:19:38.839162 20073 leader_election.cc:290] T 00000000000000000000000000000000 P 14faa334333c484b97c2975938943d97 [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:19:38.839287 20076 raft_consensus.cc:2804] T 00000000000000000000000000000000 P 14faa334333c484b97c2975938943d97 [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:19:38.839550 20076 raft_consensus.cc:697] T 00000000000000000000000000000000 P 14faa334333c484b97c2975938943d97 [term 1 LEADER]: Becoming Leader. State: Replica: 14faa334333c484b97c2975938943d97, State: Running, Role: LEADER
I20260812 06:19:38.839978 20076 consensus_queue.cc:237] T 00000000000000000000000000000000 P 14faa334333c484b97c2975938943d97 [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: "14faa334333c484b97c2975938943d97" member_type: VOTER }
I20260812 06:19:38.840150 20073 sys_catalog.cc:565] T 00000000000000000000000000000000 P 14faa334333c484b97c2975938943d97 [sys.catalog]: configured and running, proceeding with master startup.
I20260812 06:19:38.842051 20078 sys_catalog.cc:455] T 00000000000000000000000000000000 P 14faa334333c484b97c2975938943d97 [sys.catalog]: SysCatalogTable state changed. Reason: New leader 14faa334333c484b97c2975938943d97. Latest consensus state: current_term: 1 leader_uuid: "14faa334333c484b97c2975938943d97" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "14faa334333c484b97c2975938943d97" member_type: VOTER } }
I20260812 06:19:38.842033 20077 sys_catalog.cc:455] T 00000000000000000000000000000000 P 14faa334333c484b97c2975938943d97 [sys.catalog]: SysCatalogTable state changed. Reason: RaftConsensus started. Latest consensus state: current_term: 1 leader_uuid: "14faa334333c484b97c2975938943d97" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "14faa334333c484b97c2975938943d97" member_type: VOTER } }
I20260812 06:19:38.842185 20078 sys_catalog.cc:458] T 00000000000000000000000000000000 P 14faa334333c484b97c2975938943d97 [sys.catalog]: This master's current role is: LEADER
I20260812 06:19:38.842188 20077 sys_catalog.cc:458] T 00000000000000000000000000000000 P 14faa334333c484b97c2975938943d97 [sys.catalog]: This master's current role is: LEADER
I20260812 06:19:38.842409 20007 internal_mini_cluster.cc:184] Waiting to initialize catalog manager on master 0
I20260812 06:19:38.842492 20091 catalog_manager.cc:1511] Loading table and tablet metadata into memory...
I20260812 06:19:38.844918 20091 catalog_manager.cc:1520] Initializing Kudu cluster ID...
I20260812 06:19:38.849997 20091 catalog_manager.cc:1383] Generated new cluster ID: 4940c23778064e1cbb9fcd328ad0334a
I20260812 06:19:38.850066 20091 catalog_manager.cc:1531] Initializing Kudu internal certificate authority...
I20260812 06:19:38.870800 20091 catalog_manager.cc:1406] Generated new certificate authority record
I20260812 06:19:38.872020 20091 catalog_manager.cc:1540] Loading token signing keys...
I20260812 06:19:38.880899 20091 catalog_manager.cc:6092] T 00000000000000000000000000000000 P 14faa334333c484b97c2975938943d97: Generated new TSK 0
I20260812 06:19:38.881652 20091 catalog_manager.cc:1550] Initializing in-progress tserver states...
I20260812 06:19:38.907264 20007 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:19:38.910414 20098 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:38.910568 20096 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:38.910586 20095 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:38.910823 20007 server_base.cc:1061] running on GCE node
I20260812 06:19:38.911268 20007 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:19:38.911326 20007 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:38.911347 20007 hybrid_clock.cc:648] HybridClock initialized: now 1786515578911347 us; error 0 us; skew 500 ppm
I20260812 06:19:38.912251 20007 webserver.cc:533] Webserver started at http://127.19.137.193:37571/ using document root <none> and password file <none>
I20260812 06:19:38.912410 20007 fs_manager.cc:362] Metadata directory not provided
I20260812 06:19:38.912467 20007 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:19:38.912541 20007 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:19:38.912963 20007 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskztgv1X/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515578771685-20007-0/minicluster-data/ts-0-root/instance:
uuid: "b4bb78f1ffaa467784fba932c2322957"
format_stamp: "Formatted at 2026-08-12 06:19:38 on dist-test-slave-f7th"
I20260812 06:19:38.914728 20007 fs_manager.cc:696] Time spent creating directory manager: real 0.002s	user 0.000s	sys 0.002s
I20260812 06:19:38.915843 20103 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:38.916136 20007 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.001s	sys 0.000s
I20260812 06:19:38.916253 20007 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskztgv1X/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515578771685-20007-0/minicluster-data/ts-0-root
uuid: "b4bb78f1ffaa467784fba932c2322957"
format_stamp: "Formatted at 2026-08-12 06:19:38 on dist-test-slave-f7th"
I20260812 06:19:38.916365 20007 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskztgv1X/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515578771685-20007-0/minicluster-data/ts-0-root
metadata directory: /tmp/dist-test-taskztgv1X/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515578771685-20007-0/minicluster-data/ts-0-root
1 data directories: /tmp/dist-test-taskztgv1X/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515578771685-20007-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:38.927259 20007 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:19:38.927853 20007 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:19:38.928432 20007 txn_system_client.cc:432] TxnSystemClient initialization is disabled...
I20260812 06:19:38.929498 20007 ts_tablet_manager.cc:585] Loaded tablet metadata (0 total tablets, 0 live tablets)
I20260812 06:19:38.929611 20007 ts_tablet_manager.cc:531] Time spent load tablet metadata: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:19:38.929711 20007 ts_tablet_manager.cc:616] Registered 0 tablets
I20260812 06:19:38.929776 20007 ts_tablet_manager.cc:595] Time spent register tablets: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:19:38.936278 20007 rpc_server.cc:307] RPC server started. Bound to: 127.19.137.193:33711
I20260812 06:19:38.936316 20166 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.19.137.193:33711 every 8 connection(s)
I20260812 06:19:38.947862 20167 heartbeater.cc:344] Connected to a master server at 127.19.137.254:41271
I20260812 06:19:38.948132 20167 heartbeater.cc:461] Registering TS with master...
I20260812 06:19:38.948617 20167 heartbeater.cc:507] Master 127.19.137.254:41271 requested a full tablet report, sending...
I20260812 06:19:38.950196 20037 ts_manager.cc:194] Registered new tserver with Master: b4bb78f1ffaa467784fba932c2322957 (127.19.137.193:33711)
I20260812 06:19:38.950443 20007 internal_mini_cluster.cc:371] 1 TS(s) registered with all masters after 0.013426163s
I20260812 06:19:38.951802 20037 master_service.cc:502] Signed X509 certificate for tserver {username='slave'} at 127.0.0.1:40584
I20260812 06:19:38.964439 20037 catalog_manager.cc:2283] Servicing CreateTable request from {username='slave'} at 127.0.0.1:40588:
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:38.982299 20131 tablet_service.cc:1511] Processing CreateTablet for tablet 5c0bfdd2cc5b4000b4d3561b1db76e0d (DEFAULT_TABLE table=heavy-update-compaction-test [id=eb0f558072c340089b88d63e1242ae7d]), partition=
I20260812 06:19:38.982791 20131 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet 5c0bfdd2cc5b4000b4d3561b1db76e0d. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:19:38.985764 20179 tablet_bootstrap.cc:492] T 5c0bfdd2cc5b4000b4d3561b1db76e0d P b4bb78f1ffaa467784fba932c2322957: Bootstrap starting.
I20260812 06:19:38.986832 20179 tablet_bootstrap.cc:654] T 5c0bfdd2cc5b4000b4d3561b1db76e0d P b4bb78f1ffaa467784fba932c2322957: Neither blocks nor log segments found. Creating new log.
I20260812 06:19:38.988119 20179 tablet_bootstrap.cc:492] T 5c0bfdd2cc5b4000b4d3561b1db76e0d P b4bb78f1ffaa467784fba932c2322957: No bootstrap required, opened a new log
I20260812 06:19:38.988300 20179 ts_tablet_manager.cc:1403] T 5c0bfdd2cc5b4000b4d3561b1db76e0d P b4bb78f1ffaa467784fba932c2322957: Time spent bootstrapping tablet: real 0.003s	user 0.002s	sys 0.000s
I20260812 06:19:38.988863 20179 raft_consensus.cc:359] T 5c0bfdd2cc5b4000b4d3561b1db76e0d P b4bb78f1ffaa467784fba932c2322957 [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "b4bb78f1ffaa467784fba932c2322957" member_type: VOTER last_known_addr { host: "127.19.137.193" port: 33711 } }
I20260812 06:19:38.989038 20179 raft_consensus.cc:385] T 5c0bfdd2cc5b4000b4d3561b1db76e0d P b4bb78f1ffaa467784fba932c2322957 [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:19:38.989107 20179 raft_consensus.cc:740] T 5c0bfdd2cc5b4000b4d3561b1db76e0d P b4bb78f1ffaa467784fba932c2322957 [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: b4bb78f1ffaa467784fba932c2322957, State: Initialized, Role: FOLLOWER
I20260812 06:19:38.989265 20179 consensus_queue.cc:260] T 5c0bfdd2cc5b4000b4d3561b1db76e0d P b4bb78f1ffaa467784fba932c2322957 [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: "b4bb78f1ffaa467784fba932c2322957" member_type: VOTER last_known_addr { host: "127.19.137.193" port: 33711 } }
I20260812 06:19:38.989390 20179 raft_consensus.cc:399] T 5c0bfdd2cc5b4000b4d3561b1db76e0d P b4bb78f1ffaa467784fba932c2322957 [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:19:38.989454 20179 raft_consensus.cc:493] T 5c0bfdd2cc5b4000b4d3561b1db76e0d P b4bb78f1ffaa467784fba932c2322957 [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:19:38.989530 20179 raft_consensus.cc:3060] T 5c0bfdd2cc5b4000b4d3561b1db76e0d P b4bb78f1ffaa467784fba932c2322957 [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:19:38.990509 20179 raft_consensus.cc:515] T 5c0bfdd2cc5b4000b4d3561b1db76e0d P b4bb78f1ffaa467784fba932c2322957 [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "b4bb78f1ffaa467784fba932c2322957" member_type: VOTER last_known_addr { host: "127.19.137.193" port: 33711 } }
I20260812 06:19:38.990710 20179 leader_election.cc:304] T 5c0bfdd2cc5b4000b4d3561b1db76e0d P b4bb78f1ffaa467784fba932c2322957 [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: b4bb78f1ffaa467784fba932c2322957; no voters: 
I20260812 06:19:38.990947 20179 leader_election.cc:290] T 5c0bfdd2cc5b4000b4d3561b1db76e0d P b4bb78f1ffaa467784fba932c2322957 [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:19:38.991050 20181 raft_consensus.cc:2804] T 5c0bfdd2cc5b4000b4d3561b1db76e0d P b4bb78f1ffaa467784fba932c2322957 [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:19:38.991338 20181 raft_consensus.cc:697] T 5c0bfdd2cc5b4000b4d3561b1db76e0d P b4bb78f1ffaa467784fba932c2322957 [term 1 LEADER]: Becoming Leader. State: Replica: b4bb78f1ffaa467784fba932c2322957, State: Running, Role: LEADER
I20260812 06:19:38.991346 20179 ts_tablet_manager.cc:1434] T 5c0bfdd2cc5b4000b4d3561b1db76e0d P b4bb78f1ffaa467784fba932c2322957: Time spent starting tablet: real 0.003s	user 0.002s	sys 0.000s
I20260812 06:19:38.991581 20181 consensus_queue.cc:237] T 5c0bfdd2cc5b4000b4d3561b1db76e0d P b4bb78f1ffaa467784fba932c2322957 [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: "b4bb78f1ffaa467784fba932c2322957" member_type: VOTER last_known_addr { host: "127.19.137.193" port: 33711 } }
I20260812 06:19:38.991931 20167 heartbeater.cc:499] Master 127.19.137.254:41271 was elected leader, sending a full tablet report...
I20260812 06:19:38.995129 20037 catalog_manager.cc:5719] T 5c0bfdd2cc5b4000b4d3561b1db76e0d P b4bb78f1ffaa467784fba932c2322957 reported cstate change: term changed from 0 to 1, leader changed from <none> to b4bb78f1ffaa467784fba932c2322957 (127.19.137.193). New cstate: current_term: 1 leader_uuid: "b4bb78f1ffaa467784fba932c2322957" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "b4bb78f1ffaa467784fba932c2322957" member_type: VOTER last_known_addr { host: "127.19.137.193" port: 33711 } health_report { overall_health: HEALTHY } } }
I20260812 06:19:39.068269 20007 heavy-update-compaction-itest.cc:215] Time spent inserting: real 0.067s	user 0.022s	sys 0.011s
I20260812 06:19:39.187755 20168 maintenance_manager.cc:419] P b4bb78f1ffaa467784fba932c2322957: Scheduling FlushMRSOp(5c0bfdd2cc5b4000b4d3561b1db76e0d): perf score=15.086190
I20260812 06:19:39.356515 20108 maintenance_manager.cc:643] P b4bb78f1ffaa467784fba932c2322957: FlushMRSOp(5c0bfdd2cc5b4000b4d3561b1db76e0d) complete. Timing: real 0.168s	user 0.117s	sys 0.034s Metrics: {"bytes_written":11897250,"cfile_init":1,"compiler_manager_pool.queue_time_us":214,"delete_count":0,"dirs.queue_time_us":42,"dirs.run_cpu_time_us":201,"dirs.run_wall_time_us":927,"drs_written":1,"lbm_read_time_us":70,"lbm_reads_lt_1ms":4,"lbm_write_time_us":39984,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":656,"peak_mem_usage":0,"reinsert_count":0,"rows_written":104,"thread_start_us":101,"threads_started":1,"update_count":1450}
I20260812 06:19:39.357647 20168 maintenance_manager.cc:419] P b4bb78f1ffaa467784fba932c2322957: Scheduling FlushDeltaMemStoresOp(5c0bfdd2cc5b4000b4d3561b1db76e0d): perf score=2.188937
I20260812 06:19:39.370869 20108 maintenance_manager.cc:643] P b4bb78f1ffaa467784fba932c2322957: FlushDeltaMemStoresOp(5c0bfdd2cc5b4000b4d3561b1db76e0d) complete. Timing: real 0.013s	user 0.006s	sys 0.005s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4873,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:39.371423 20168 maintenance_manager.cc:419] P b4bb78f1ffaa467784fba932c2322957: Scheduling LogGCOp(5c0bfdd2cc5b4000b4d3561b1db76e0d): free 20743880 bytes of WAL
I20260812 06:19:39.371800 20108 log_reader.cc:385] T 5c0bfdd2cc5b4000b4d3561b1db76e0d: removed 2 log segments from log reader
I20260812 06:19:39.371899 20108 log.cc:1079] T 5c0bfdd2cc5b4000b4d3561b1db76e0d P b4bb78f1ffaa467784fba932c2322957: Deleting log segment in path: /tmp/dist-test-taskztgv1X/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515578771685-20007-0/minicluster-data/ts-0-root/wals/5c0bfdd2cc5b4000b4d3561b1db76e0d/wal-000000001 (ops 1-6)
I20260812 06:19:39.371991 20108 log.cc:1079] T 5c0bfdd2cc5b4000b4d3561b1db76e0d P b4bb78f1ffaa467784fba932c2322957: Deleting log segment in path: /tmp/dist-test-taskztgv1X/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515578771685-20007-0/minicluster-data/ts-0-root/wals/5c0bfdd2cc5b4000b4d3561b1db76e0d/wal-000000002 (ops 7-11)
I20260812 06:19:39.376981 20108 maintenance_manager.cc:643] P b4bb78f1ffaa467784fba932c2322957: LogGCOp(5c0bfdd2cc5b4000b4d3561b1db76e0d) complete. Timing: real 0.005s	user 0.000s	sys 0.004s Metrics: {}
I20260812 06:19:39.377467 20168 maintenance_manager.cc:419] P b4bb78f1ffaa467784fba932c2322957: Scheduling UndoDeltaBlockGCOp(5c0bfdd2cc5b4000b4d3561b1db76e0d): 12719217 bytes on disk
I20260812 06:19:39.378191 20108 maintenance_manager.cc:643] P b4bb78f1ffaa467784fba932c2322957: UndoDeltaBlockGCOp(5c0bfdd2cc5b4000b4d3561b1db76e0d) complete. Timing: real 0.001s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":80,"lbm_reads_lt_1ms":4}
I20260812 06:19:39.378672 20168 maintenance_manager.cc:419] P b4bb78f1ffaa467784fba932c2322957: Scheduling MajorDeltaCompactionOp(5c0bfdd2cc5b4000b4d3561b1db76e0d): perf score=1.000000
I20260812 06:19:39.515993 20108 maintenance_manager.cc:643] P b4bb78f1ffaa467784fba932c2322957: MajorDeltaCompactionOp(5c0bfdd2cc5b4000b4d3561b1db76e0d) complete. Timing: real 0.137s	user 0.099s	sys 0.031s Metrics: {"cfile_cache_miss":422,"cfile_cache_miss_bytes":20262037,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":382,"lbm_read_time_us":8524,"lbm_reads_lt_1ms":454,"lbm_write_time_us":25403,"lbm_writes_lt_1ms":433,"peak_mem_usage":49238594,"reinsert_count":0,"spinlock_wait_cycles":896,"thread_start_us":292,"threads_started":5,"update_count":1950}
I20260812 06:19:39.516508 20168 maintenance_manager.cc:419] P b4bb78f1ffaa467784fba932c2322957: Scheduling FlushDeltaMemStoresOp(5c0bfdd2cc5b4000b4d3561b1db76e0d): perf score=7.149875
I20260812 06:19:39.542833 20108 maintenance_manager.cc:643] P b4bb78f1ffaa467784fba932c2322957: FlushDeltaMemStoresOp(5c0bfdd2cc5b4000b4d3561b1db76e0d) complete. Timing: real 0.026s	user 0.020s	sys 0.004s Metrics: {"bytes_written":8615324,"delete_count":0,"lbm_write_time_us":10643,"lbm_writes_lt_1ms":213,"reinsert_count":0,"update_count":1050}
I20260812 06:19:39.543378 20168 maintenance_manager.cc:419] P b4bb78f1ffaa467784fba932c2322957: Scheduling FlushDeltaMemStoresOp(5c0bfdd2cc5b4000b4d3561b1db76e0d): perf score=2.188937
I20260812 06:19:39.561429 20108 maintenance_manager.cc:643] P b4bb78f1ffaa467784fba932c2322957: FlushDeltaMemStoresOp(5c0bfdd2cc5b4000b4d3561b1db76e0d) complete. Timing: real 0.018s	user 0.011s	sys 0.000s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":4547,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:19:39.562026 20168 maintenance_manager.cc:419] P b4bb78f1ffaa467784fba932c2322957: Scheduling MajorDeltaCompactionOp(5c0bfdd2cc5b4000b4d3561b1db76e0d): perf score=1.000000
I20260812 06:19:39.681000 20108 maintenance_manager.cc:643] P b4bb78f1ffaa467784fba932c2322957: MajorDeltaCompactionOp(5c0bfdd2cc5b4000b4d3561b1db76e0d) complete. Timing: real 0.119s	user 0.098s	sys 0.019s Metrics: {"cfile_cache_miss":332,"cfile_cache_miss_bytes":16569857,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":787,"lbm_read_time_us":7471,"lbm_reads_lt_1ms":364,"lbm_write_time_us":20937,"lbm_writes_lt_1ms":343,"mutex_wait_us":511,"peak_mem_usage":38262756,"reinsert_count":0,"update_count":1500}
I20260812 06:19:39.681600 20168 maintenance_manager.cc:419] P b4bb78f1ffaa467784fba932c2322957: Scheduling FlushDeltaMemStoresOp(5c0bfdd2cc5b4000b4d3561b1db76e0d): perf score=11.118625
I20260812 06:19:39.717401 20108 maintenance_manager.cc:643] P b4bb78f1ffaa467784fba932c2322957: FlushDeltaMemStoresOp(5c0bfdd2cc5b4000b4d3561b1db76e0d) complete. Timing: real 0.036s	user 0.026s	sys 0.008s Metrics: {"bytes_written":12717735,"delete_count":0,"lbm_write_time_us":14349,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:19:39.717980 20168 maintenance_manager.cc:419] P b4bb78f1ffaa467784fba932c2322957: Scheduling FlushDeltaMemStoresOp(5c0bfdd2cc5b4000b4d3561b1db76e0d): perf score=2.188937
I20260812 06:19:39.752028 20108 maintenance_manager.cc:643] P b4bb78f1ffaa467784fba932c2322957: FlushDeltaMemStoresOp(5c0bfdd2cc5b4000b4d3561b1db76e0d) complete. Timing: real 0.034s	user 0.007s	sys 0.013s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":4898,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:19:39.752477 20168 maintenance_manager.cc:419] P b4bb78f1ffaa467784fba932c2322957: Scheduling FlushDeltaMemStoresOp(5c0bfdd2cc5b4000b4d3561b1db76e0d): perf score=2.188937
I20260812 06:19:39.764846 20108 maintenance_manager.cc:643] P b4bb78f1ffaa467784fba932c2322957: FlushDeltaMemStoresOp(5c0bfdd2cc5b4000b4d3561b1db76e0d) complete. Timing: real 0.012s	user 0.005s	sys 0.006s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4666,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:39.765270 20168 maintenance_manager.cc:419] P b4bb78f1ffaa467784fba932c2322957: Scheduling MajorDeltaCompactionOp(5c0bfdd2cc5b4000b4d3561b1db76e0d): perf score=1.000000
I20260812 06:19:39.950506 20108 maintenance_manager.cc:643] P b4bb78f1ffaa467784fba932c2322957: MajorDeltaCompactionOp(5c0bfdd2cc5b4000b4d3561b1db76e0d) complete. Timing: real 0.185s	user 0.105s	sys 0.064s Metrics: {"cfile_cache_miss":533,"cfile_cache_miss_bytes":24774799,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":1949,"dirs.run_cpu_time_us":382,"dirs.run_wall_time_us":3197,"lbm_read_time_us":12133,"lbm_reads_lt_1ms":573,"lbm_write_time_us":28498,"lbm_writes_lt_1ms":543,"mutex_wait_us":724,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":4864,"update_count":2500}
I20260812 06:19:39.951674 20168 maintenance_manager.cc:419] P b4bb78f1ffaa467784fba932c2322957: Scheduling FlushDeltaMemStoresOp(5c0bfdd2cc5b4000b4d3561b1db76e0d): perf score=14.095187
I20260812 06:19:39.998865 20108 maintenance_manager.cc:643] P b4bb78f1ffaa467784fba932c2322957: FlushDeltaMemStoresOp(5c0bfdd2cc5b4000b4d3561b1db76e0d) complete. Timing: real 0.047s	user 0.020s	sys 0.024s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":21081,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":402,"reinsert_count":0,"update_count":2000}
I20260812 06:19:39.999341 20168 maintenance_manager.cc:419] P b4bb78f1ffaa467784fba932c2322957: Scheduling FlushDeltaMemStoresOp(5c0bfdd2cc5b4000b4d3561b1db76e0d): perf score=2.188937
I20260812 06:19:40.010309 20108 maintenance_manager.cc:643] P b4bb78f1ffaa467784fba932c2322957: FlushDeltaMemStoresOp(5c0bfdd2cc5b4000b4d3561b1db76e0d) complete. Timing: real 0.011s	user 0.009s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3793,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:40.010842 20168 maintenance_manager.cc:419] P b4bb78f1ffaa467784fba932c2322957: Scheduling MajorDeltaCompactionOp(5c0bfdd2cc5b4000b4d3561b1db76e0d): perf score=1.000000
I20260812 06:19:40.204187 20108 maintenance_manager.cc:643] P b4bb78f1ffaa467784fba932c2322957: MajorDeltaCompactionOp(5c0bfdd2cc5b4000b4d3561b1db76e0d) complete. Timing: real 0.193s	user 0.139s	sys 0.049s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774689,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":849,"lbm_read_time_us":12115,"lbm_reads_lt_1ms":572,"lbm_write_time_us":32173,"lbm_writes_lt_1ms":543,"mutex_wait_us":306,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":1280,"thread_start_us":86,"threads_started":1,"update_count":2500}
I20260812 06:19:40.204689 20168 maintenance_manager.cc:419] P b4bb78f1ffaa467784fba932c2322957: Scheduling FlushDeltaMemStoresOp(5c0bfdd2cc5b4000b4d3561b1db76e0d): perf score=11.118625
I20260812 06:19:40.241580 20108 maintenance_manager.cc:643] P b4bb78f1ffaa467784fba932c2322957: FlushDeltaMemStoresOp(5c0bfdd2cc5b4000b4d3561b1db76e0d) complete. Timing: real 0.037s	user 0.011s	sys 0.024s Metrics: {"bytes_written":12717735,"delete_count":0,"lbm_write_time_us":15159,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:19:40.242169 20168 maintenance_manager.cc:419] P b4bb78f1ffaa467784fba932c2322957: Scheduling FlushDeltaMemStoresOp(5c0bfdd2cc5b4000b4d3561b1db76e0d): perf score=2.188937
I20260812 06:19:40.253108 20108 maintenance_manager.cc:643] P b4bb78f1ffaa467784fba932c2322957: FlushDeltaMemStoresOp(5c0bfdd2cc5b4000b4d3561b1db76e0d) complete. Timing: real 0.011s	user 0.005s	sys 0.004s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3852,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:19:40.253598 20168 maintenance_manager.cc:419] P b4bb78f1ffaa467784fba932c2322957: Scheduling MajorDeltaCompactionOp(5c0bfdd2cc5b4000b4d3561b1db76e0d): perf score=1.000000
I20260812 06:19:40.380492 20108 maintenance_manager.cc:643] P b4bb78f1ffaa467784fba932c2322957: MajorDeltaCompactionOp(5c0bfdd2cc5b4000b4d3561b1db76e0d) complete. Timing: real 0.127s	user 0.110s	sys 0.015s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672268,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":316,"lbm_read_time_us":8548,"lbm_reads_lt_1ms":472,"lbm_write_time_us":24023,"lbm_writes_lt_1ms":443,"mutex_wait_us":114,"peak_mem_usage":50689328,"reinsert_count":0,"update_count":2000}
I20260812 06:19:40.381081 20168 maintenance_manager.cc:419] P b4bb78f1ffaa467784fba932c2322957: Scheduling FlushDeltaMemStoresOp(5c0bfdd2cc5b4000b4d3561b1db76e0d): perf score=10.126437
I20260812 06:19:40.419063 20108 maintenance_manager.cc:643] P b4bb78f1ffaa467784fba932c2322957: FlushDeltaMemStoresOp(5c0bfdd2cc5b4000b4d3561b1db76e0d) complete. Timing: real 0.038s	user 0.027s	sys 0.004s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":13554,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:19:40.419766 20168 maintenance_manager.cc:419] P b4bb78f1ffaa467784fba932c2322957: Scheduling FlushDeltaMemStoresOp(5c0bfdd2cc5b4000b4d3561b1db76e0d): perf score=2.188937
I20260812 06:19:40.430419 20108 maintenance_manager.cc:643] P b4bb78f1ffaa467784fba932c2322957: FlushDeltaMemStoresOp(5c0bfdd2cc5b4000b4d3561b1db76e0d) complete. Timing: real 0.010s	user 0.004s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3753,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:40.431026 20168 maintenance_manager.cc:419] P b4bb78f1ffaa467784fba932c2322957: Scheduling MajorDeltaCompactionOp(5c0bfdd2cc5b4000b4d3561b1db76e0d): perf score=1.000000
I20260812 06:19:40.566669 20108 maintenance_manager.cc:643] P b4bb78f1ffaa467784fba932c2322957: MajorDeltaCompactionOp(5c0bfdd2cc5b4000b4d3561b1db76e0d) complete. Timing: real 0.135s	user 0.099s	sys 0.032s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672277,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":625,"lbm_read_time_us":7670,"lbm_reads_lt_1ms":472,"lbm_write_time_us":25612,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":442,"mutex_wait_us":219,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":1664,"update_count":2000}
I20260812 06:19:40.567188 20168 maintenance_manager.cc:419] P b4bb78f1ffaa467784fba932c2322957: Scheduling FlushDeltaMemStoresOp(5c0bfdd2cc5b4000b4d3561b1db76e0d): perf score=10.126437
I20260812 06:19:40.611071 20108 maintenance_manager.cc:643] P b4bb78f1ffaa467784fba932c2322957: FlushDeltaMemStoresOp(5c0bfdd2cc5b4000b4d3561b1db76e0d) complete. Timing: real 0.044s	user 0.029s	sys 0.011s Metrics: {"bytes_written":12307496,"delete_count":0,"lbm_write_time_us":15114,"lbm_writes_lt_1ms":303,"reinsert_count":0,"spinlock_wait_cycles":1280,"update_count":1500}
I20260812 06:19:40.611709 20168 maintenance_manager.cc:419] P b4bb78f1ffaa467784fba932c2322957: Scheduling FlushDeltaMemStoresOp(5c0bfdd2cc5b4000b4d3561b1db76e0d): perf score=2.188937
I20260812 06:19:40.625056 20108 maintenance_manager.cc:643] P b4bb78f1ffaa467784fba932c2322957: FlushDeltaMemStoresOp(5c0bfdd2cc5b4000b4d3561b1db76e0d) complete. Timing: real 0.013s	user 0.007s	sys 0.005s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":5035,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:40.625648 20168 maintenance_manager.cc:419] P b4bb78f1ffaa467784fba932c2322957: Scheduling FlushMRSOp(5c0bfdd2cc5b4000b4d3561b1db76e0d): perf score=1.000000
I20260812 06:19:40.664304 20108 maintenance_manager.cc:643] P b4bb78f1ffaa467784fba932c2322957: FlushMRSOp(5c0bfdd2cc5b4000b4d3561b1db76e0d) complete. Timing: real 0.038s	user 0.035s	sys 0.000s Metrics: {"bytes_written":1152508,"cfile_init":1,"dirs.queue_time_us":66,"dirs.run_cpu_time_us":243,"dirs.run_wall_time_us":1391,"drs_written":1,"lbm_read_time_us":52,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1680,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":28,"spinlock_wait_cycles":896}
I20260812 06:19:40.665274 20168 maintenance_manager.cc:419] P b4bb78f1ffaa467784fba932c2322957: Scheduling LogGCOp(5c0bfdd2cc5b4000b4d3561b1db76e0d): free 115943180 bytes of WAL
I20260812 06:19:40.665488 20108 log_reader.cc:385] T 5c0bfdd2cc5b4000b4d3561b1db76e0d: removed 11 log segments from log reader
I20260812 06:19:40.665537 20108 log.cc:1079] T 5c0bfdd2cc5b4000b4d3561b1db76e0d P b4bb78f1ffaa467784fba932c2322957: Deleting log segment in path: /tmp/dist-test-taskztgv1X/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515578771685-20007-0/minicluster-data/ts-0-root/wals/5c0bfdd2cc5b4000b4d3561b1db76e0d/wal-000000003 (ops 12-16)
I20260812 06:19:40.665575 20108 log.cc:1079] T 5c0bfdd2cc5b4000b4d3561b1db76e0d P b4bb78f1ffaa467784fba932c2322957: Deleting log segment in path: /tmp/dist-test-taskztgv1X/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515578771685-20007-0/minicluster-data/ts-0-root/wals/5c0bfdd2cc5b4000b4d3561b1db76e0d/wal-000000004 (ops 17-21)
I20260812 06:19:40.665604 20108 log.cc:1079] T 5c0bfdd2cc5b4000b4d3561b1db76e0d P b4bb78f1ffaa467784fba932c2322957: Deleting log segment in path: /tmp/dist-test-taskztgv1X/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515578771685-20007-0/minicluster-data/ts-0-root/wals/5c0bfdd2cc5b4000b4d3561b1db76e0d/wal-000000005 (ops 22-26)
I20260812 06:19:40.665632 20108 log.cc:1079] T 5c0bfdd2cc5b4000b4d3561b1db76e0d P b4bb78f1ffaa467784fba932c2322957: Deleting log segment in path: /tmp/dist-test-taskztgv1X/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515578771685-20007-0/minicluster-data/ts-0-root/wals/5c0bfdd2cc5b4000b4d3561b1db76e0d/wal-000000006 (ops 27-31)
I20260812 06:19:40.665658 20108 log.cc:1079] T 5c0bfdd2cc5b4000b4d3561b1db76e0d P b4bb78f1ffaa467784fba932c2322957: Deleting log segment in path: /tmp/dist-test-taskztgv1X/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515578771685-20007-0/minicluster-data/ts-0-root/wals/5c0bfdd2cc5b4000b4d3561b1db76e0d/wal-000000007 (ops 32-36)
I20260812 06:19:40.665688 20108 log.cc:1079] T 5c0bfdd2cc5b4000b4d3561b1db76e0d P b4bb78f1ffaa467784fba932c2322957: Deleting log segment in path: /tmp/dist-test-taskztgv1X/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515578771685-20007-0/minicluster-data/ts-0-root/wals/5c0bfdd2cc5b4000b4d3561b1db76e0d/wal-000000008 (ops 37-41)
I20260812 06:19:40.665719 20108 log.cc:1079] T 5c0bfdd2cc5b4000b4d3561b1db76e0d P b4bb78f1ffaa467784fba932c2322957: Deleting log segment in path: /tmp/dist-test-taskztgv1X/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515578771685-20007-0/minicluster-data/ts-0-root/wals/5c0bfdd2cc5b4000b4d3561b1db76e0d/wal-000000009 (ops 42-46)
I20260812 06:19:40.665745 20108 log.cc:1079] T 5c0bfdd2cc5b4000b4d3561b1db76e0d P b4bb78f1ffaa467784fba932c2322957: Deleting log segment in path: /tmp/dist-test-taskztgv1X/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515578771685-20007-0/minicluster-data/ts-0-root/wals/5c0bfdd2cc5b4000b4d3561b1db76e0d/wal-000000010 (ops 47-51)
I20260812 06:19:40.665769 20108 log.cc:1079] T 5c0bfdd2cc5b4000b4d3561b1db76e0d P b4bb78f1ffaa467784fba932c2322957: Deleting log segment in path: /tmp/dist-test-taskztgv1X/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515578771685-20007-0/minicluster-data/ts-0-root/wals/5c0bfdd2cc5b4000b4d3561b1db76e0d/wal-000000011 (ops 52-56)
I20260812 06:19:40.665797 20108 log.cc:1079] T 5c0bfdd2cc5b4000b4d3561b1db76e0d P b4bb78f1ffaa467784fba932c2322957: Deleting log segment in path: /tmp/dist-test-taskztgv1X/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515578771685-20007-0/minicluster-data/ts-0-root/wals/5c0bfdd2cc5b4000b4d3561b1db76e0d/wal-000000012 (ops 57-61)
I20260812 06:19:40.665827 20108 log.cc:1079] T 5c0bfdd2cc5b4000b4d3561b1db76e0d P b4bb78f1ffaa467784fba932c2322957: Deleting log segment in path: /tmp/dist-test-taskztgv1X/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515578771685-20007-0/minicluster-data/ts-0-root/wals/5c0bfdd2cc5b4000b4d3561b1db76e0d/wal-000000013 (ops 62-66)
I20260812 06:19:40.692129 20108 maintenance_manager.cc:643] P b4bb78f1ffaa467784fba932c2322957: LogGCOp(5c0bfdd2cc5b4000b4d3561b1db76e0d) complete. Timing: real 0.027s	user 0.000s	sys 0.024s Metrics: {}
I20260812 06:19:40.692498 20168 maintenance_manager.cc:419] P b4bb78f1ffaa467784fba932c2322957: Scheduling UndoDeltaBlockGCOp(5c0bfdd2cc5b4000b4d3561b1db76e0d): 448 bytes on disk
I20260812 06:19:40.692970 20108 maintenance_manager.cc:643] P b4bb78f1ffaa467784fba932c2322957: UndoDeltaBlockGCOp(5c0bfdd2cc5b4000b4d3561b1db76e0d) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":65,"lbm_reads_lt_1ms":4}
I20260812 06:19:40.693424 20168 maintenance_manager.cc:419] P b4bb78f1ffaa467784fba932c2322957: Scheduling FlushDeltaMemStoresOp(5c0bfdd2cc5b4000b4d3561b1db76e0d): perf score=3.181125
I20260812 06:19:40.715993 20108 maintenance_manager.cc:643] P b4bb78f1ffaa467784fba932c2322957: FlushDeltaMemStoresOp(5c0bfdd2cc5b4000b4d3561b1db76e0d) complete. Timing: real 0.022s	user 0.010s	sys 0.006s Metrics: {"bytes_written":4512900,"delete_count":0,"lbm_write_time_us":6113,"lbm_writes_lt_1ms":113,"reinsert_count":0,"update_count":550}
I20260812 06:19:40.716492 20168 maintenance_manager.cc:419] P b4bb78f1ffaa467784fba932c2322957: Scheduling FlushDeltaMemStoresOp(5c0bfdd2cc5b4000b4d3561b1db76e0d): perf score=2.188937
I20260812 06:19:40.727435 20108 maintenance_manager.cc:643] P b4bb78f1ffaa467784fba932c2322957: FlushDeltaMemStoresOp(5c0bfdd2cc5b4000b4d3561b1db76e0d) complete. Timing: real 0.011s	user 0.001s	sys 0.008s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":4054,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:19:40.727864 20168 maintenance_manager.cc:419] P b4bb78f1ffaa467784fba932c2322957: Scheduling MajorDeltaCompactionOp(5c0bfdd2cc5b4000b4d3561b1db76e0d): perf score=1.000000
I20260812 06:19:40.938614 20108 maintenance_manager.cc:643] P b4bb78f1ffaa467784fba932c2322957: MajorDeltaCompactionOp(5c0bfdd2cc5b4000b4d3561b1db76e0d) complete. Timing: real 0.211s	user 0.128s	sys 0.071s Metrics: {"cfile_cache_miss":634,"cfile_cache_miss_bytes":28877331,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":797,"lbm_read_time_us":12450,"lbm_reads_lt_1ms":674,"lbm_write_time_us":43125,"lbm_writes_10-100_ms":1,"lbm_writes_lt_1ms":642,"mutex_wait_us":298,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":3584,"thread_start_us":68,"threads_started":1,"update_count":3000}
I20260812 06:19:40.940505 20168 maintenance_manager.cc:419] P b4bb78f1ffaa467784fba932c2322957: Scheduling FlushDeltaMemStoresOp(5c0bfdd2cc5b4000b4d3561b1db76e0d): perf score=14.095187
I20260812 06:19:40.991294 20108 maintenance_manager.cc:643] P b4bb78f1ffaa467784fba932c2322957: FlushDeltaMemStoresOp(5c0bfdd2cc5b4000b4d3561b1db76e0d) complete. Timing: real 0.051s	user 0.040s	sys 0.004s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":20716,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:40.991873 20168 maintenance_manager.cc:419] P b4bb78f1ffaa467784fba932c2322957: Scheduling MajorDeltaCompactionOp(5c0bfdd2cc5b4000b4d3561b1db76e0d): perf score=1.000000
I20260812 06:19:41.148672 20108 maintenance_manager.cc:643] P b4bb78f1ffaa467784fba932c2322957: MajorDeltaCompactionOp(5c0bfdd2cc5b4000b4d3561b1db76e0d) complete. Timing: real 0.157s	user 0.119s	sys 0.032s Metrics: {"cfile_cache_miss":431,"cfile_cache_miss_bytes":20672157,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":1,"delta_iterators_relevant":1,"dirs.queue_time_us":111,"lbm_read_time_us":10547,"lbm_reads_lt_1ms":463,"lbm_write_time_us":25477,"lbm_writes_lt_1ms":443,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":5376,"update_count":2000}
I20260812 06:19:41.151365 20168 maintenance_manager.cc:419] P b4bb78f1ffaa467784fba932c2322957: Scheduling FlushDeltaMemStoresOp(5c0bfdd2cc5b4000b4d3561b1db76e0d): perf score=11.118625
I20260812 06:19:41.190493 20108 maintenance_manager.cc:643] P b4bb78f1ffaa467784fba932c2322957: FlushDeltaMemStoresOp(5c0bfdd2cc5b4000b4d3561b1db76e0d) complete. Timing: real 0.039s	user 0.023s	sys 0.007s Metrics: {"bytes_written":12717737,"delete_count":0,"lbm_write_time_us":13437,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:19:41.191048 20168 maintenance_manager.cc:419] P b4bb78f1ffaa467784fba932c2322957: Scheduling FlushDeltaMemStoresOp(5c0bfdd2cc5b4000b4d3561b1db76e0d): perf score=2.188937
I20260812 06:19:41.211403 20108 maintenance_manager.cc:643] P b4bb78f1ffaa467784fba932c2322957: FlushDeltaMemStoresOp(5c0bfdd2cc5b4000b4d3561b1db76e0d) complete. Timing: real 0.020s	user 0.010s	sys 0.001s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5878,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":102,"reinsert_count":0,"update_count":500}
I20260812 06:19:41.211977 20168 maintenance_manager.cc:419] P b4bb78f1ffaa467784fba932c2322957: Scheduling FlushDeltaMemStoresOp(5c0bfdd2cc5b4000b4d3561b1db76e0d): perf score=2.188937
I20260812 06:19:41.222615 20108 maintenance_manager.cc:643] P b4bb78f1ffaa467784fba932c2322957: FlushDeltaMemStoresOp(5c0bfdd2cc5b4000b4d3561b1db76e0d) complete. Timing: real 0.010s	user 0.003s	sys 0.006s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3875,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:19:41.223942 20168 maintenance_manager.cc:419] P b4bb78f1ffaa467784fba932c2322957: Scheduling MajorDeltaCompactionOp(5c0bfdd2cc5b4000b4d3561b1db76e0d): perf score=1.000000
I20260812 06:19:41.403430 20108 maintenance_manager.cc:643] P b4bb78f1ffaa467784fba932c2322957: MajorDeltaCompactionOp(5c0bfdd2cc5b4000b4d3561b1db76e0d) complete. Timing: real 0.179s	user 0.098s	sys 0.077s Metrics: {"cfile_cache_miss":533,"cfile_cache_miss_bytes":24774801,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":166,"lbm_read_time_us":11074,"lbm_reads_lt_1ms":573,"lbm_write_time_us":30608,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":542,"mutex_wait_us":26,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":11136,"update_count":2500}
I20260812 06:19:41.404043 20168 maintenance_manager.cc:419] P b4bb78f1ffaa467784fba932c2322957: Scheduling FlushDeltaMemStoresOp(5c0bfdd2cc5b4000b4d3561b1db76e0d): perf score=11.118625
I20260812 06:19:41.436421 20108 maintenance_manager.cc:643] P b4bb78f1ffaa467784fba932c2322957: FlushDeltaMemStoresOp(5c0bfdd2cc5b4000b4d3561b1db76e0d) complete. Timing: real 0.032s	user 0.020s	sys 0.011s Metrics: {"bytes_written":12717735,"delete_count":0,"lbm_write_time_us":13480,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":312,"reinsert_count":0,"update_count":1550}
I20260812 06:19:41.436879 20168 maintenance_manager.cc:419] P b4bb78f1ffaa467784fba932c2322957: Scheduling FlushDeltaMemStoresOp(5c0bfdd2cc5b4000b4d3561b1db76e0d): perf score=2.188937
I20260812 06:19:41.458192 20108 maintenance_manager.cc:643] P b4bb78f1ffaa467784fba932c2322957: FlushDeltaMemStoresOp(5c0bfdd2cc5b4000b4d3561b1db76e0d) complete. Timing: real 0.021s	user 0.006s	sys 0.005s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":8036,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":92,"reinsert_count":0,"update_count":450}
I20260812 06:19:41.458662 20168 maintenance_manager.cc:419] P b4bb78f1ffaa467784fba932c2322957: Scheduling FlushDeltaMemStoresOp(5c0bfdd2cc5b4000b4d3561b1db76e0d): perf score=2.188937
I20260812 06:19:41.472841 20108 maintenance_manager.cc:643] P b4bb78f1ffaa467784fba932c2322957: FlushDeltaMemStoresOp(5c0bfdd2cc5b4000b4d3561b1db76e0d) complete. Timing: real 0.014s	user 0.012s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4908,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:41.473389 20168 maintenance_manager.cc:419] P b4bb78f1ffaa467784fba932c2322957: Scheduling MajorDeltaCompactionOp(5c0bfdd2cc5b4000b4d3561b1db76e0d): perf score=1.000000
I20260812 06:19:41.657788 20108 maintenance_manager.cc:643] P b4bb78f1ffaa467784fba932c2322957: MajorDeltaCompactionOp(5c0bfdd2cc5b4000b4d3561b1db76e0d) complete. Timing: real 0.184s	user 0.132s	sys 0.039s Metrics: {"cfile_cache_miss":533,"cfile_cache_miss_bytes":24774799,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":834,"lbm_read_time_us":10602,"lbm_reads_lt_1ms":573,"lbm_write_time_us":34279,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":542,"mutex_wait_us":252,"peak_mem_usage":63115900,"reinsert_count":0,"update_count":2500}
I20260812 06:19:41.658329 20168 maintenance_manager.cc:419] P b4bb78f1ffaa467784fba932c2322957: Scheduling FlushDeltaMemStoresOp(5c0bfdd2cc5b4000b4d3561b1db76e0d): perf score=14.095187
I20260812 06:19:41.708010 20108 maintenance_manager.cc:643] P b4bb78f1ffaa467784fba932c2322957: FlushDeltaMemStoresOp(5c0bfdd2cc5b4000b4d3561b1db76e0d) complete. Timing: real 0.049s	user 0.040s	sys 0.008s Metrics: {"bytes_written":16409903,"delete_count":0,"lbm_write_time_us":21033,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:41.708470 20168 maintenance_manager.cc:419] P b4bb78f1ffaa467784fba932c2322957: Scheduling FlushDeltaMemStoresOp(5c0bfdd2cc5b4000b4d3561b1db76e0d): perf score=2.188937
I20260812 06:19:41.721509 20108 maintenance_manager.cc:643] P b4bb78f1ffaa467784fba932c2322957: FlushDeltaMemStoresOp(5c0bfdd2cc5b4000b4d3561b1db76e0d) complete. Timing: real 0.013s	user 0.005s	sys 0.006s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5091,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:41.721943 20168 maintenance_manager.cc:419] P b4bb78f1ffaa467784fba932c2322957: Scheduling MajorDeltaCompactionOp(5c0bfdd2cc5b4000b4d3561b1db76e0d): perf score=1.000000
I20260812 06:19:41.884095 20108 maintenance_manager.cc:643] P b4bb78f1ffaa467784fba932c2322957: MajorDeltaCompactionOp(5c0bfdd2cc5b4000b4d3561b1db76e0d) complete. Timing: real 0.162s	user 0.125s	sys 0.031s 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":38,"lbm_read_time_us":10940,"lbm_reads_lt_1ms":572,"lbm_write_time_us":29924,"lbm_writes_lt_1ms":543,"mutex_wait_us":22,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":2176,"update_count":2500}
I20260812 06:19:41.884657 20168 maintenance_manager.cc:419] P b4bb78f1ffaa467784fba932c2322957: Scheduling FlushDeltaMemStoresOp(5c0bfdd2cc5b4000b4d3561b1db76e0d): perf score=10.126437
I20260812 06:19:41.926545 20108 maintenance_manager.cc:643] P b4bb78f1ffaa467784fba932c2322957: FlushDeltaMemStoresOp(5c0bfdd2cc5b4000b4d3561b1db76e0d) complete. Timing: real 0.042s	user 0.018s	sys 0.008s Metrics: {"bytes_written":12307491,"delete_count":0,"lbm_write_time_us":11643,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:19:41.927098 20168 maintenance_manager.cc:419] P b4bb78f1ffaa467784fba932c2322957: Scheduling FlushDeltaMemStoresOp(5c0bfdd2cc5b4000b4d3561b1db76e0d): perf score=3.181125
I20260812 06:19:41.941706 20108 maintenance_manager.cc:643] P b4bb78f1ffaa467784fba932c2322957: FlushDeltaMemStoresOp(5c0bfdd2cc5b4000b4d3561b1db76e0d) complete. Timing: real 0.014s	user 0.004s	sys 0.008s Metrics: {"bytes_written":4512900,"delete_count":0,"lbm_write_time_us":5034,"lbm_writes_lt_1ms":113,"reinsert_count":0,"update_count":550}
I20260812 06:19:41.942229 20168 maintenance_manager.cc:419] P b4bb78f1ffaa467784fba932c2322957: Scheduling FlushDeltaMemStoresOp(5c0bfdd2cc5b4000b4d3561b1db76e0d): perf score=2.188937
I20260812 06:19:41.953657 20108 maintenance_manager.cc:643] P b4bb78f1ffaa467784fba932c2322957: FlushDeltaMemStoresOp(5c0bfdd2cc5b4000b4d3561b1db76e0d) complete. Timing: real 0.011s	user 0.006s	sys 0.003s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":4165,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:19:41.954118 20168 maintenance_manager.cc:419] P b4bb78f1ffaa467784fba932c2322957: Scheduling MajorDeltaCompactionOp(5c0bfdd2cc5b4000b4d3561b1db76e0d): perf score=1.000000
I20260812 06:19:42.110741 20108 maintenance_manager.cc:643] P b4bb78f1ffaa467784fba932c2322957: MajorDeltaCompactionOp(5c0bfdd2cc5b4000b4d3561b1db76e0d) complete. Timing: real 0.156s	user 0.138s	sys 0.016s Metrics: {"cfile_cache_miss":533,"cfile_cache_miss_bytes":24774796,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":96,"lbm_read_time_us":9915,"lbm_reads_lt_1ms":573,"lbm_write_time_us":30223,"lbm_writes_lt_1ms":543,"mutex_wait_us":26,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":896,"update_count":2500}
I20260812 06:19:42.111578 20168 maintenance_manager.cc:419] P b4bb78f1ffaa467784fba932c2322957: Scheduling FlushDeltaMemStoresOp(5c0bfdd2cc5b4000b4d3561b1db76e0d): perf score=11.118625
I20260812 06:19:42.154737 20108 maintenance_manager.cc:643] P b4bb78f1ffaa467784fba932c2322957: FlushDeltaMemStoresOp(5c0bfdd2cc5b4000b4d3561b1db76e0d) complete. Timing: real 0.043s	user 0.021s	sys 0.013s Metrics: {"bytes_written":12717735,"delete_count":0,"lbm_write_time_us":14602,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:19:42.155324 20168 maintenance_manager.cc:419] P b4bb78f1ffaa467784fba932c2322957: Scheduling FlushDeltaMemStoresOp(5c0bfdd2cc5b4000b4d3561b1db76e0d): perf score=2.188937
I20260812 06:19:42.176416 20108 maintenance_manager.cc:643] P b4bb78f1ffaa467784fba932c2322957: FlushDeltaMemStoresOp(5c0bfdd2cc5b4000b4d3561b1db76e0d) complete. Timing: real 0.020s	user 0.007s	sys 0.005s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":4945,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:19:42.176990 20168 maintenance_manager.cc:419] P b4bb78f1ffaa467784fba932c2322957: Scheduling FlushDeltaMemStoresOp(5c0bfdd2cc5b4000b4d3561b1db76e0d): perf score=2.188937
I20260812 06:19:42.191309 20108 maintenance_manager.cc:643] P b4bb78f1ffaa467784fba932c2322957: FlushDeltaMemStoresOp(5c0bfdd2cc5b4000b4d3561b1db76e0d) complete. Timing: real 0.014s	user 0.008s	sys 0.003s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5064,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:42.192080 20168 maintenance_manager.cc:419] P b4bb78f1ffaa467784fba932c2322957: Scheduling FlushMRSOp(5c0bfdd2cc5b4000b4d3561b1db76e0d): perf score=1.000000
I20260812 06:19:42.233132 20108 maintenance_manager.cc:643] P b4bb78f1ffaa467784fba932c2322957: FlushMRSOp(5c0bfdd2cc5b4000b4d3561b1db76e0d) complete. Timing: real 0.041s	user 0.031s	sys 0.005s Metrics: {"bytes_written":1275449,"cfile_init":1,"dirs.queue_time_us":35,"dirs.run_cpu_time_us":148,"dirs.run_wall_time_us":1171,"drs_written":1,"lbm_read_time_us":40,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1812,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":31}
I20260812 06:19:42.233930 20168 maintenance_manager.cc:419] P b4bb78f1ffaa467784fba932c2322957: Scheduling LogGCOp(5c0bfdd2cc5b4000b4d3561b1db76e0d): free 121459489 bytes of WAL
I20260812 06:19:42.234170 20108 log_reader.cc:385] T 5c0bfdd2cc5b4000b4d3561b1db76e0d: removed 12 log segments from log reader
I20260812 06:19:42.234216 20108 log.cc:1079] T 5c0bfdd2cc5b4000b4d3561b1db76e0d P b4bb78f1ffaa467784fba932c2322957: Deleting log segment in path: /tmp/dist-test-taskztgv1X/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515578771685-20007-0/minicluster-data/ts-0-root/wals/5c0bfdd2cc5b4000b4d3561b1db76e0d/wal-000000014 (ops 67-71)
I20260812 06:19:42.234282 20108 log.cc:1079] T 5c0bfdd2cc5b4000b4d3561b1db76e0d P b4bb78f1ffaa467784fba932c2322957: Deleting log segment in path: /tmp/dist-test-taskztgv1X/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515578771685-20007-0/minicluster-data/ts-0-root/wals/5c0bfdd2cc5b4000b4d3561b1db76e0d/wal-000000015 (ops 72-76)
I20260812 06:19:42.234318 20108 log.cc:1079] T 5c0bfdd2cc5b4000b4d3561b1db76e0d P b4bb78f1ffaa467784fba932c2322957: Deleting log segment in path: /tmp/dist-test-taskztgv1X/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515578771685-20007-0/minicluster-data/ts-0-root/wals/5c0bfdd2cc5b4000b4d3561b1db76e0d/wal-000000016 (ops 77-81)
I20260812 06:19:42.234376 20108 log.cc:1079] T 5c0bfdd2cc5b4000b4d3561b1db76e0d P b4bb78f1ffaa467784fba932c2322957: Deleting log segment in path: /tmp/dist-test-taskztgv1X/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515578771685-20007-0/minicluster-data/ts-0-root/wals/5c0bfdd2cc5b4000b4d3561b1db76e0d/wal-000000017 (ops 82-86)
I20260812 06:19:42.234418 20108 log.cc:1079] T 5c0bfdd2cc5b4000b4d3561b1db76e0d P b4bb78f1ffaa467784fba932c2322957: Deleting log segment in path: /tmp/dist-test-taskztgv1X/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515578771685-20007-0/minicluster-data/ts-0-root/wals/5c0bfdd2cc5b4000b4d3561b1db76e0d/wal-000000018 (ops 87-91)
I20260812 06:19:42.234472 20108 log.cc:1079] T 5c0bfdd2cc5b4000b4d3561b1db76e0d P b4bb78f1ffaa467784fba932c2322957: Deleting log segment in path: /tmp/dist-test-taskztgv1X/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515578771685-20007-0/minicluster-data/ts-0-root/wals/5c0bfdd2cc5b4000b4d3561b1db76e0d/wal-000000019 (ops 92-96)
I20260812 06:19:42.234506 20108 log.cc:1079] T 5c0bfdd2cc5b4000b4d3561b1db76e0d P b4bb78f1ffaa467784fba932c2322957: Deleting log segment in path: /tmp/dist-test-taskztgv1X/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515578771685-20007-0/minicluster-data/ts-0-root/wals/5c0bfdd2cc5b4000b4d3561b1db76e0d/wal-000000020 (ops 97-101)
I20260812 06:19:42.234560 20108 log.cc:1079] T 5c0bfdd2cc5b4000b4d3561b1db76e0d P b4bb78f1ffaa467784fba932c2322957: Deleting log segment in path: /tmp/dist-test-taskztgv1X/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515578771685-20007-0/minicluster-data/ts-0-root/wals/5c0bfdd2cc5b4000b4d3561b1db76e0d/wal-000000021 (ops 102-106)
I20260812 06:19:42.234614 20108 log.cc:1079] T 5c0bfdd2cc5b4000b4d3561b1db76e0d P b4bb78f1ffaa467784fba932c2322957: Deleting log segment in path: /tmp/dist-test-taskztgv1X/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515578771685-20007-0/minicluster-data/ts-0-root/wals/5c0bfdd2cc5b4000b4d3561b1db76e0d/wal-000000022 (ops 107-111)
I20260812 06:19:42.234651 20108 log.cc:1079] T 5c0bfdd2cc5b4000b4d3561b1db76e0d P b4bb78f1ffaa467784fba932c2322957: Deleting log segment in path: /tmp/dist-test-taskztgv1X/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515578771685-20007-0/minicluster-data/ts-0-root/wals/5c0bfdd2cc5b4000b4d3561b1db76e0d/wal-000000023 (ops 112-116)
I20260812 06:19:42.234705 20108 log.cc:1079] T 5c0bfdd2cc5b4000b4d3561b1db76e0d P b4bb78f1ffaa467784fba932c2322957: Deleting log segment in path: /tmp/dist-test-taskztgv1X/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515578771685-20007-0/minicluster-data/ts-0-root/wals/5c0bfdd2cc5b4000b4d3561b1db76e0d/wal-000000024 (ops 117-121)
I20260812 06:19:42.234740 20108 log.cc:1079] T 5c0bfdd2cc5b4000b4d3561b1db76e0d P b4bb78f1ffaa467784fba932c2322957: Deleting log segment in path: /tmp/dist-test-taskztgv1X/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515578771685-20007-0/minicluster-data/ts-0-root/wals/5c0bfdd2cc5b4000b4d3561b1db76e0d/wal-000000025 (ops 122-126)
I20260812 06:19:42.259680 20108 maintenance_manager.cc:643] P b4bb78f1ffaa467784fba932c2322957: LogGCOp(5c0bfdd2cc5b4000b4d3561b1db76e0d) complete. Timing: real 0.026s	user 0.000s	sys 0.025s Metrics: {}
I20260812 06:19:42.260260 20168 maintenance_manager.cc:419] P b4bb78f1ffaa467784fba932c2322957: Scheduling UndoDeltaBlockGCOp(5c0bfdd2cc5b4000b4d3561b1db76e0d): 482 bytes on disk
I20260812 06:19:42.260860 20108 maintenance_manager.cc:643] P b4bb78f1ffaa467784fba932c2322957: UndoDeltaBlockGCOp(5c0bfdd2cc5b4000b4d3561b1db76e0d) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":66,"lbm_reads_lt_1ms":4}
I20260812 06:19:42.261456 20168 maintenance_manager.cc:419] P b4bb78f1ffaa467784fba932c2322957: Scheduling FlushDeltaMemStoresOp(5c0bfdd2cc5b4000b4d3561b1db76e0d): perf score=3.181125
I20260812 06:19:42.278327 20108 maintenance_manager.cc:643] P b4bb78f1ffaa467784fba932c2322957: FlushDeltaMemStoresOp(5c0bfdd2cc5b4000b4d3561b1db76e0d) complete. Timing: real 0.017s	user 0.002s	sys 0.013s Metrics: {"bytes_written":4800074,"delete_count":0,"lbm_write_time_us":6723,"lbm_writes_lt_1ms":120,"reinsert_count":0,"update_count":585}
I20260812 06:19:42.278867 20168 maintenance_manager.cc:419] P b4bb78f1ffaa467784fba932c2322957: Scheduling LogGCOp(5c0bfdd2cc5b4000b4d3561b1db76e0d): free 11564883 bytes of WAL
I20260812 06:19:42.279080 20108 log_reader.cc:385] T 5c0bfdd2cc5b4000b4d3561b1db76e0d: removed 1 log segments from log reader
I20260812 06:19:42.279150 20108 log.cc:1079] T 5c0bfdd2cc5b4000b4d3561b1db76e0d P b4bb78f1ffaa467784fba932c2322957: Deleting log segment in path: /tmp/dist-test-taskztgv1X/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515578771685-20007-0/minicluster-data/ts-0-root/wals/5c0bfdd2cc5b4000b4d3561b1db76e0d/wal-000000026 (ops 127-130)
I20260812 06:19:42.281749 20108 maintenance_manager.cc:643] P b4bb78f1ffaa467784fba932c2322957: LogGCOp(5c0bfdd2cc5b4000b4d3561b1db76e0d) complete. Timing: real 0.003s	user 0.000s	sys 0.001s Metrics: {}
I20260812 06:19:42.282104 20168 maintenance_manager.cc:419] P b4bb78f1ffaa467784fba932c2322957: Scheduling FlushDeltaMemStoresOp(5c0bfdd2cc5b4000b4d3561b1db76e0d): perf score=2.188937
I20260812 06:19:42.292938 20108 maintenance_manager.cc:643] P b4bb78f1ffaa467784fba932c2322957: FlushDeltaMemStoresOp(5c0bfdd2cc5b4000b4d3561b1db76e0d) complete. Timing: real 0.011s	user 0.004s	sys 0.005s Metrics: {"bytes_written":3405230,"delete_count":0,"lbm_write_time_us":3875,"lbm_writes_lt_1ms":86,"reinsert_count":0,"update_count":415}
I20260812 06:19:42.293468 20168 maintenance_manager.cc:419] P b4bb78f1ffaa467784fba932c2322957: Scheduling MajorDeltaCompactionOp(5c0bfdd2cc5b4000b4d3561b1db76e0d): perf score=1.000000
I20260812 06:19:42.499394 20108 maintenance_manager.cc:643] P b4bb78f1ffaa467784fba932c2322957: MajorDeltaCompactionOp(5c0bfdd2cc5b4000b4d3561b1db76e0d) complete. Timing: real 0.206s	user 0.162s	sys 0.040s Metrics: {"cfile_cache_miss":735,"cfile_cache_miss_bytes":32979847,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":5,"delta_iterators_relevant":5,"dirs.queue_time_us":938,"lbm_read_time_us":13419,"lbm_reads_lt_1ms":775,"lbm_write_time_us":40892,"lbm_writes_lt_1ms":743,"mutex_wait_us":46,"peak_mem_usage":87969044,"reinsert_count":0,"spinlock_wait_cycles":46464,"thread_start_us":86,"threads_started":1,"update_count":3500}
I20260812 06:19:42.499979 20168 maintenance_manager.cc:419] P b4bb78f1ffaa467784fba932c2322957: Scheduling FlushDeltaMemStoresOp(5c0bfdd2cc5b4000b4d3561b1db76e0d): perf score=14.095187
I20260812 06:19:42.550266 20108 maintenance_manager.cc:643] P b4bb78f1ffaa467784fba932c2322957: FlushDeltaMemStoresOp(5c0bfdd2cc5b4000b4d3561b1db76e0d) complete. Timing: real 0.050s	user 0.040s	sys 0.004s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":19758,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:42.552033 20168 maintenance_manager.cc:419] P b4bb78f1ffaa467784fba932c2322957: Scheduling FlushDeltaMemStoresOp(5c0bfdd2cc5b4000b4d3561b1db76e0d): perf score=2.188937
I20260812 06:19:42.565320 20108 maintenance_manager.cc:643] P b4bb78f1ffaa467784fba932c2322957: FlushDeltaMemStoresOp(5c0bfdd2cc5b4000b4d3561b1db76e0d) complete. Timing: real 0.013s	user 0.002s	sys 0.009s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5070,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:42.565795 20168 maintenance_manager.cc:419] P b4bb78f1ffaa467784fba932c2322957: Scheduling MajorDeltaCompactionOp(5c0bfdd2cc5b4000b4d3561b1db76e0d): perf score=1.000000
I20260812 06:19:42.750049 20108 maintenance_manager.cc:643] P b4bb78f1ffaa467784fba932c2322957: MajorDeltaCompactionOp(5c0bfdd2cc5b4000b4d3561b1db76e0d) complete. Timing: real 0.184s	user 0.128s	sys 0.033s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774689,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":83,"lbm_read_time_us":11266,"lbm_reads_lt_1ms":572,"lbm_write_time_us":36170,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":542,"mutex_wait_us":25,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":128768,"update_count":2500}
I20260812 06:19:42.750582 20168 maintenance_manager.cc:419] P b4bb78f1ffaa467784fba932c2322957: Scheduling FlushDeltaMemStoresOp(5c0bfdd2cc5b4000b4d3561b1db76e0d): perf score=14.095187
I20260812 06:19:42.788458 20108 maintenance_manager.cc:643] P b4bb78f1ffaa467784fba932c2322957: FlushDeltaMemStoresOp(5c0bfdd2cc5b4000b4d3561b1db76e0d) complete. Timing: real 0.038s	user 0.030s	sys 0.007s Metrics: {"bytes_written":16409903,"delete_count":0,"lbm_write_time_us":16354,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:42.789027 20168 maintenance_manager.cc:419] P b4bb78f1ffaa467784fba932c2322957: Scheduling MajorDeltaCompactionOp(5c0bfdd2cc5b4000b4d3561b1db76e0d): perf score=1.000000
I20260812 06:19:42.954319 20108 maintenance_manager.cc:643] P b4bb78f1ffaa467784fba932c2322957: MajorDeltaCompactionOp(5c0bfdd2cc5b4000b4d3561b1db76e0d) complete. Timing: real 0.165s	user 0.114s	sys 0.033s Metrics: {"cfile_cache_miss":431,"cfile_cache_miss_bytes":20672159,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":1,"delta_iterators_relevant":1,"dirs.queue_time_us":147,"lbm_read_time_us":9977,"lbm_reads_lt_1ms":467,"lbm_write_time_us":39826,"lbm_writes_10-100_ms":1,"lbm_writes_lt_1ms":442,"mutex_wait_us":36,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":12160,"update_count":2000}
I20260812 06:19:42.955945 20168 maintenance_manager.cc:419] P b4bb78f1ffaa467784fba932c2322957: Scheduling FlushDeltaMemStoresOp(5c0bfdd2cc5b4000b4d3561b1db76e0d): perf score=10.126437
I20260812 06:19:42.999780 20108 maintenance_manager.cc:643] P b4bb78f1ffaa467784fba932c2322957: FlushDeltaMemStoresOp(5c0bfdd2cc5b4000b4d3561b1db76e0d) complete. Timing: real 0.044s	user 0.026s	sys 0.015s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":14935,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:19:43.000372 20168 maintenance_manager.cc:419] P b4bb78f1ffaa467784fba932c2322957: Scheduling FlushDeltaMemStoresOp(5c0bfdd2cc5b4000b4d3561b1db76e0d): perf score=2.188937
I20260812 06:19:43.015383 20108 maintenance_manager.cc:643] P b4bb78f1ffaa467784fba932c2322957: FlushDeltaMemStoresOp(5c0bfdd2cc5b4000b4d3561b1db76e0d) complete. Timing: real 0.015s	user 0.012s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5802,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:43.015933 20168 maintenance_manager.cc:419] P b4bb78f1ffaa467784fba932c2322957: Scheduling MajorDeltaCompactionOp(5c0bfdd2cc5b4000b4d3561b1db76e0d): perf score=1.000000
I20260812 06:19:43.179909 20108 maintenance_manager.cc:643] P b4bb78f1ffaa467784fba932c2322957: MajorDeltaCompactionOp(5c0bfdd2cc5b4000b4d3561b1db76e0d) complete. Timing: real 0.164s	user 0.103s	sys 0.056s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672277,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":798,"lbm_read_time_us":10660,"lbm_reads_lt_1ms":472,"lbm_write_time_us":26159,"lbm_writes_lt_1ms":443,"mutex_wait_us":256,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":768,"update_count":2000}
I20260812 06:19:43.180507 20168 maintenance_manager.cc:419] P b4bb78f1ffaa467784fba932c2322957: Scheduling FlushDeltaMemStoresOp(5c0bfdd2cc5b4000b4d3561b1db76e0d): perf score=10.126437
I20260812 06:19:43.218120 20108 maintenance_manager.cc:643] P b4bb78f1ffaa467784fba932c2322957: FlushDeltaMemStoresOp(5c0bfdd2cc5b4000b4d3561b1db76e0d) complete. Timing: real 0.037s	user 0.018s	sys 0.017s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":16808,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:19:43.218613 20168 maintenance_manager.cc:419] P b4bb78f1ffaa467784fba932c2322957: Scheduling FlushDeltaMemStoresOp(5c0bfdd2cc5b4000b4d3561b1db76e0d): perf score=2.188937
I20260812 06:19:43.228497 20108 maintenance_manager.cc:643] P b4bb78f1ffaa467784fba932c2322957: FlushDeltaMemStoresOp(5c0bfdd2cc5b4000b4d3561b1db76e0d) complete. Timing: real 0.010s	user 0.009s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3516,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:43.229005 20168 maintenance_manager.cc:419] P b4bb78f1ffaa467784fba932c2322957: Scheduling MajorDeltaCompactionOp(5c0bfdd2cc5b4000b4d3561b1db76e0d): perf score=1.000000
I20260812 06:19:43.362558 20108 maintenance_manager.cc:643] P b4bb78f1ffaa467784fba932c2322957: MajorDeltaCompactionOp(5c0bfdd2cc5b4000b4d3561b1db76e0d) complete. Timing: real 0.133s	user 0.101s	sys 0.026s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672277,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":217,"lbm_read_time_us":11816,"lbm_reads_lt_1ms":472,"lbm_write_time_us":27327,"lbm_writes_1-10_ms":3,"lbm_writes_lt_1ms":440,"mutex_wait_us":25,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":2432,"update_count":2000}
I20260812 06:19:43.363131 20168 maintenance_manager.cc:419] P b4bb78f1ffaa467784fba932c2322957: Scheduling FlushDeltaMemStoresOp(5c0bfdd2cc5b4000b4d3561b1db76e0d): perf score=10.126437
I20260812 06:19:43.413216 20108 maintenance_manager.cc:643] P b4bb78f1ffaa467784fba932c2322957: FlushDeltaMemStoresOp(5c0bfdd2cc5b4000b4d3561b1db76e0d) complete. Timing: real 0.050s	user 0.017s	sys 0.016s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":15292,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:19:43.413743 20168 maintenance_manager.cc:419] P b4bb78f1ffaa467784fba932c2322957: Scheduling FlushDeltaMemStoresOp(5c0bfdd2cc5b4000b4d3561b1db76e0d): perf score=2.188937
I20260812 06:19:43.430655 20108 maintenance_manager.cc:643] P b4bb78f1ffaa467784fba932c2322957: FlushDeltaMemStoresOp(5c0bfdd2cc5b4000b4d3561b1db76e0d) complete. Timing: real 0.017s	user 0.008s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5462,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:43.431275 20168 maintenance_manager.cc:419] P b4bb78f1ffaa467784fba932c2322957: Scheduling MajorDeltaCompactionOp(5c0bfdd2cc5b4000b4d3561b1db76e0d): perf score=1.000000
I20260812 06:19:43.565469 20108 maintenance_manager.cc:643] P b4bb78f1ffaa467784fba932c2322957: MajorDeltaCompactionOp(5c0bfdd2cc5b4000b4d3561b1db76e0d) complete. Timing: real 0.134s	user 0.102s	sys 0.032s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672277,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":55,"lbm_read_time_us":9844,"lbm_reads_lt_1ms":468,"lbm_write_time_us":26429,"lbm_writes_lt_1ms":443,"mutex_wait_us":50,"peak_mem_usage":50689328,"reinsert_count":0,"update_count":2000}
I20260812 06:19:43.566084 20168 maintenance_manager.cc:419] P b4bb78f1ffaa467784fba932c2322957: Scheduling FlushDeltaMemStoresOp(5c0bfdd2cc5b4000b4d3561b1db76e0d): perf score=10.126437
I20260812 06:19:43.611459 20108 maintenance_manager.cc:643] P b4bb78f1ffaa467784fba932c2322957: FlushDeltaMemStoresOp(5c0bfdd2cc5b4000b4d3561b1db76e0d) complete. Timing: real 0.045s	user 0.031s	sys 0.003s Metrics: {"bytes_written":12307491,"delete_count":0,"lbm_write_time_us":13656,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:19:43.612146 20168 maintenance_manager.cc:419] P b4bb78f1ffaa467784fba932c2322957: Scheduling FlushDeltaMemStoresOp(5c0bfdd2cc5b4000b4d3561b1db76e0d): perf score=2.188937
I20260812 06:19:43.623869 20108 maintenance_manager.cc:643] P b4bb78f1ffaa467784fba932c2322957: FlushDeltaMemStoresOp(5c0bfdd2cc5b4000b4d3561b1db76e0d) complete. Timing: real 0.012s	user 0.007s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4273,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:43.624367 20168 maintenance_manager.cc:419] P b4bb78f1ffaa467784fba932c2322957: Scheduling MajorDeltaCompactionOp(5c0bfdd2cc5b4000b4d3561b1db76e0d): perf score=1.000000
I20260812 06:19:43.787742 20108 maintenance_manager.cc:643] P b4bb78f1ffaa467784fba932c2322957: MajorDeltaCompactionOp(5c0bfdd2cc5b4000b4d3561b1db76e0d) complete. Timing: real 0.163s	user 0.093s	sys 0.056s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672278,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":941,"lbm_read_time_us":11273,"lbm_reads_lt_1ms":472,"lbm_write_time_us":25020,"lbm_writes_lt_1ms":443,"mutex_wait_us":39,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":5376,"update_count":2000}
I20260812 06:19:43.788291 20168 maintenance_manager.cc:419] P b4bb78f1ffaa467784fba932c2322957: Scheduling FlushDeltaMemStoresOp(5c0bfdd2cc5b4000b4d3561b1db76e0d): perf score=10.126437
I20260812 06:19:43.837872 20108 maintenance_manager.cc:643] P b4bb78f1ffaa467784fba932c2322957: FlushDeltaMemStoresOp(5c0bfdd2cc5b4000b4d3561b1db76e0d) complete. Timing: real 0.049s	user 0.020s	sys 0.009s Metrics: {"bytes_written":12307492,"delete_count":0,"lbm_write_time_us":31807,"lbm_writes_10-100_ms":1,"lbm_writes_lt_1ms":302,"reinsert_count":0,"update_count":1500}
I20260812 06:19:43.838572 20168 maintenance_manager.cc:419] P b4bb78f1ffaa467784fba932c2322957: Scheduling FlushDeltaMemStoresOp(5c0bfdd2cc5b4000b4d3561b1db76e0d): perf score=2.188937
I20260812 06:19:43.852653 20108 maintenance_manager.cc:643] P b4bb78f1ffaa467784fba932c2322957: FlushDeltaMemStoresOp(5c0bfdd2cc5b4000b4d3561b1db76e0d) complete. Timing: real 0.014s	user 0.003s	sys 0.009s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5030,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:43.853425 20168 maintenance_manager.cc:419] P b4bb78f1ffaa467784fba932c2322957: Scheduling FlushMRSOp(5c0bfdd2cc5b4000b4d3561b1db76e0d): perf score=1.000000
I20260812 06:19:43.887959 20108 maintenance_manager.cc:643] P b4bb78f1ffaa467784fba932c2322957: FlushMRSOp(5c0bfdd2cc5b4000b4d3561b1db76e0d) complete. Timing: real 0.034s	user 0.032s	sys 0.001s Metrics: {"bytes_written":1275447,"cfile_init":1,"dirs.queue_time_us":58,"dirs.run_cpu_time_us":213,"dirs.run_wall_time_us":1345,"drs_written":1,"lbm_read_time_us":37,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1501,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":31}
I20260812 06:19:43.888756 20168 maintenance_manager.cc:419] P b4bb78f1ffaa467784fba932c2322957: Scheduling LogGCOp(5c0bfdd2cc5b4000b4d3561b1db76e0d): free 117302835 bytes of WAL
I20260812 06:19:43.888988 20108 log_reader.cc:385] T 5c0bfdd2cc5b4000b4d3561b1db76e0d: removed 12 log segments from log reader
I20260812 06:19:43.889035 20108 log.cc:1079] T 5c0bfdd2cc5b4000b4d3561b1db76e0d P b4bb78f1ffaa467784fba932c2322957: Deleting log segment in path: /tmp/dist-test-taskztgv1X/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515578771685-20007-0/minicluster-data/ts-0-root/wals/5c0bfdd2cc5b4000b4d3561b1db76e0d/wal-000000027 (ops 131-135)
I20260812 06:19:43.889070 20108 log.cc:1079] T 5c0bfdd2cc5b4000b4d3561b1db76e0d P b4bb78f1ffaa467784fba932c2322957: Deleting log segment in path: /tmp/dist-test-taskztgv1X/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515578771685-20007-0/minicluster-data/ts-0-root/wals/5c0bfdd2cc5b4000b4d3561b1db76e0d/wal-000000028 (ops 136-140)
I20260812 06:19:43.889161 20108 log.cc:1079] T 5c0bfdd2cc5b4000b4d3561b1db76e0d P b4bb78f1ffaa467784fba932c2322957: Deleting log segment in path: /tmp/dist-test-taskztgv1X/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515578771685-20007-0/minicluster-data/ts-0-root/wals/5c0bfdd2cc5b4000b4d3561b1db76e0d/wal-000000029 (ops 141-144)
I20260812 06:19:43.889200 20108 log.cc:1079] T 5c0bfdd2cc5b4000b4d3561b1db76e0d P b4bb78f1ffaa467784fba932c2322957: Deleting log segment in path: /tmp/dist-test-taskztgv1X/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515578771685-20007-0/minicluster-data/ts-0-root/wals/5c0bfdd2cc5b4000b4d3561b1db76e0d/wal-000000030 (ops 145-149)
I20260812 06:19:43.889222 20108 log.cc:1079] T 5c0bfdd2cc5b4000b4d3561b1db76e0d P b4bb78f1ffaa467784fba932c2322957: Deleting log segment in path: /tmp/dist-test-taskztgv1X/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515578771685-20007-0/minicluster-data/ts-0-root/wals/5c0bfdd2cc5b4000b4d3561b1db76e0d/wal-000000031 (ops 150-154)
I20260812 06:19:43.889278 20108 log.cc:1079] T 5c0bfdd2cc5b4000b4d3561b1db76e0d P b4bb78f1ffaa467784fba932c2322957: Deleting log segment in path: /tmp/dist-test-taskztgv1X/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515578771685-20007-0/minicluster-data/ts-0-root/wals/5c0bfdd2cc5b4000b4d3561b1db76e0d/wal-000000032 (ops 155-158)
I20260812 06:19:43.889331 20108 log.cc:1079] T 5c0bfdd2cc5b4000b4d3561b1db76e0d P b4bb78f1ffaa467784fba932c2322957: Deleting log segment in path: /tmp/dist-test-taskztgv1X/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515578771685-20007-0/minicluster-data/ts-0-root/wals/5c0bfdd2cc5b4000b4d3561b1db76e0d/wal-000000033 (ops 159-163)
I20260812 06:19:43.889381 20108 log.cc:1079] T 5c0bfdd2cc5b4000b4d3561b1db76e0d P b4bb78f1ffaa467784fba932c2322957: Deleting log segment in path: /tmp/dist-test-taskztgv1X/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515578771685-20007-0/minicluster-data/ts-0-root/wals/5c0bfdd2cc5b4000b4d3561b1db76e0d/wal-000000034 (ops 164-168)
I20260812 06:19:43.889432 20108 log.cc:1079] T 5c0bfdd2cc5b4000b4d3561b1db76e0d P b4bb78f1ffaa467784fba932c2322957: Deleting log segment in path: /tmp/dist-test-taskztgv1X/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515578771685-20007-0/minicluster-data/ts-0-root/wals/5c0bfdd2cc5b4000b4d3561b1db76e0d/wal-000000035 (ops 169-173)
I20260812 06:19:43.889465 20108 log.cc:1079] T 5c0bfdd2cc5b4000b4d3561b1db76e0d P b4bb78f1ffaa467784fba932c2322957: Deleting log segment in path: /tmp/dist-test-taskztgv1X/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515578771685-20007-0/minicluster-data/ts-0-root/wals/5c0bfdd2cc5b4000b4d3561b1db76e0d/wal-000000036 (ops 174-178)
I20260812 06:19:43.889508 20108 log.cc:1079] T 5c0bfdd2cc5b4000b4d3561b1db76e0d P b4bb78f1ffaa467784fba932c2322957: Deleting log segment in path: /tmp/dist-test-taskztgv1X/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515578771685-20007-0/minicluster-data/ts-0-root/wals/5c0bfdd2cc5b4000b4d3561b1db76e0d/wal-000000037 (ops 179-183)
I20260812 06:19:43.889542 20108 log.cc:1079] T 5c0bfdd2cc5b4000b4d3561b1db76e0d P b4bb78f1ffaa467784fba932c2322957: Deleting log segment in path: /tmp/dist-test-taskztgv1X/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515578771685-20007-0/minicluster-data/ts-0-root/wals/5c0bfdd2cc5b4000b4d3561b1db76e0d/wal-000000038 (ops 184-188)
I20260812 06:19:43.911141 20108 maintenance_manager.cc:643] P b4bb78f1ffaa467784fba932c2322957: LogGCOp(5c0bfdd2cc5b4000b4d3561b1db76e0d) complete. Timing: real 0.022s	user 0.004s	sys 0.015s Metrics: {}
I20260812 06:19:43.911530 20168 maintenance_manager.cc:419] P b4bb78f1ffaa467784fba932c2322957: Scheduling FlushDeltaMemStoresOp(5c0bfdd2cc5b4000b4d3561b1db76e0d): perf score=2.188937
I20260812 06:19:43.938391 20108 maintenance_manager.cc:643] P b4bb78f1ffaa467784fba932c2322957: FlushDeltaMemStoresOp(5c0bfdd2cc5b4000b4d3561b1db76e0d) complete. Timing: real 0.027s	user 0.015s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5797,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:43.939006 20168 maintenance_manager.cc:419] P b4bb78f1ffaa467784fba932c2322957: Scheduling FlushDeltaMemStoresOp(5c0bfdd2cc5b4000b4d3561b1db76e0d): perf score=2.188937
I20260812 06:19:43.955233 20108 maintenance_manager.cc:643] P b4bb78f1ffaa467784fba932c2322957: FlushDeltaMemStoresOp(5c0bfdd2cc5b4000b4d3561b1db76e0d) complete. Timing: real 0.016s	user 0.006s	sys 0.007s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":5850,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:43.955772 20168 maintenance_manager.cc:419] P b4bb78f1ffaa467784fba932c2322957: Scheduling UndoDeltaBlockGCOp(5c0bfdd2cc5b4000b4d3561b1db76e0d): 482 bytes on disk
I20260812 06:19:43.956269 20108 maintenance_manager.cc:643] P b4bb78f1ffaa467784fba932c2322957: UndoDeltaBlockGCOp(5c0bfdd2cc5b4000b4d3561b1db76e0d) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":67,"lbm_reads_lt_1ms":4}
I20260812 06:19:43.956804 20168 maintenance_manager.cc:419] P b4bb78f1ffaa467784fba932c2322957: Scheduling MajorDeltaCompactionOp(5c0bfdd2cc5b4000b4d3561b1db76e0d): perf score=1.000000
I20260812 06:19:44.168114 20108 maintenance_manager.cc:643] P b4bb78f1ffaa467784fba932c2322957: MajorDeltaCompactionOp(5c0bfdd2cc5b4000b4d3561b1db76e0d) complete. Timing: real 0.211s	user 0.147s	sys 0.059s Metrics: {"cfile_cache_miss":634,"cfile_cache_miss_bytes":28877340,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":661,"lbm_read_time_us":15267,"lbm_reads_lt_1ms":674,"lbm_write_time_us":33826,"lbm_writes_lt_1ms":643,"mutex_wait_us":58,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":768,"thread_start_us":76,"threads_started":1,"update_count":3000}
I20260812 06:19:44.168700 20168 maintenance_manager.cc:419] P b4bb78f1ffaa467784fba932c2322957: Scheduling FlushDeltaMemStoresOp(5c0bfdd2cc5b4000b4d3561b1db76e0d): perf score=11.118625
I20260812 06:19:44.186909 20007 heavy-update-compaction-itest.cc:229] Time spent updating: real 5.119s	user 1.784s	sys 0.179s
I20260812 06:19:44.210031 20108 maintenance_manager.cc:643] P b4bb78f1ffaa467784fba932c2322957: FlushDeltaMemStoresOp(5c0bfdd2cc5b4000b4d3561b1db76e0d) complete. Timing: real 0.041s	user 0.023s	sys 0.013s Metrics: {"bytes_written":12717735,"delete_count":0,"lbm_write_time_us":16458,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:19:44.210892 20168 maintenance_manager.cc:419] P b4bb78f1ffaa467784fba932c2322957: Scheduling FlushDeltaMemStoresOp(5c0bfdd2cc5b4000b4d3561b1db76e0d): perf score=2.188937
I20260812 06:19:44.215629 20007 heavy-update-compaction-itest.cc:265] Time spent scanning: real 0.028s	user 0.002s	sys 0.002s
I20260812 06:19:44.216355 20007 tablet_server.cc:179] TabletServer@127.19.137.193:0 shutting down...
I20260812 06:19:44.226152 20108 maintenance_manager.cc:643] P b4bb78f1ffaa467784fba932c2322957: FlushDeltaMemStoresOp(5c0bfdd2cc5b4000b4d3561b1db76e0d) complete. Timing: real 0.015s	user 0.007s	sys 0.004s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":6020,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:19:44.226678 20007 ts_tablet_manager.cc:1507] Shutting down tablet manager...
I20260812 06:19:44.227000 20007 tablet_replica.cc:333] T 5c0bfdd2cc5b4000b4d3561b1db76e0d P b4bb78f1ffaa467784fba932c2322957: stopping tablet replica
I20260812 06:19:44.227213 20007 raft_consensus.cc:2243] T 5c0bfdd2cc5b4000b4d3561b1db76e0d P b4bb78f1ffaa467784fba932c2322957 [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:19:44.237227 20007 raft_consensus.cc:2272] T 5c0bfdd2cc5b4000b4d3561b1db76e0d P b4bb78f1ffaa467784fba932c2322957 [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:19:44.253497 20007 tablet_server.cc:196] TabletServer@127.19.137.193:0 shutdown complete.
I20260812 06:19:44.259004 20007 master.cc:562] Master@127.19.137.254:41271 shutting down...
I20260812 06:19:44.262864 20007 raft_consensus.cc:2243] T 00000000000000000000000000000000 P 14faa334333c484b97c2975938943d97 [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:19:44.263039 20007 raft_consensus.cc:2272] T 00000000000000000000000000000000 P 14faa334333c484b97c2975938943d97 [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:19:44.263114 20007 tablet_replica.cc:333] T 00000000000000000000000000000000 P 14faa334333c484b97c2975938943d97: stopping tablet replica
I20260812 06:19:44.275271 20007 master.cc:584] Master@127.19.137.254:41271 shutdown complete.
[       OK ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/0 (5570 ms)
[ RUN      ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/1
I20260812 06:19:44.351408 20007 internal_mini_cluster.cc:156] Creating distributed mini masters. Addrs: 127.19.137.254:44035
I20260812 06:19:44.351819 20007 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:19:44.353808 20202 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:44.353789 20204 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:44.353951 20201 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:44.354192 20007 server_base.cc:1061] running on GCE node
I20260812 06:19:44.354346 20007 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:19:44.354383 20007 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:44.354398 20007 hybrid_clock.cc:648] HybridClock initialized: now 1786515584354398 us; error 0 us; skew 500 ppm
I20260812 06:19:44.355201 20007 webserver.cc:533] Webserver started at http://127.19.137.254:43955/ using document root <none> and password file <none>
I20260812 06:19:44.355342 20007 fs_manager.cc:362] Metadata directory not provided
I20260812 06:19:44.355388 20007 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:19:44.355449 20007 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:19:44.355847 20007 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskztgv1X/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515578771685-20007-0/minicluster-data/master-0-root/instance:
uuid: "6f3d7f90ba8547a9bcccd584fec59f79"
format_stamp: "Formatted at 2026-08-12 06:19:44 on dist-test-slave-f7th"
I20260812 06:19:44.357347 20007 fs_manager.cc:696] Time spent creating directory manager: real 0.001s	user 0.000s	sys 0.001s
I20260812 06:19:44.358249 20209 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:44.358487 20007 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.000s	sys 0.001s
I20260812 06:19:44.358557 20007 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskztgv1X/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515578771685-20007-0/minicluster-data/master-0-root
uuid: "6f3d7f90ba8547a9bcccd584fec59f79"
format_stamp: "Formatted at 2026-08-12 06:19:44 on dist-test-slave-f7th"
I20260812 06:19:44.358623 20007 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskztgv1X/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515578771685-20007-0/minicluster-data/master-0-root
metadata directory: /tmp/dist-test-taskztgv1X/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515578771685-20007-0/minicluster-data/master-0-root
1 data directories: /tmp/dist-test-taskztgv1X/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515578771685-20007-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:44.373312 20007 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:19:44.373672 20007 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:19:44.377564 20007 rpc_server.cc:307] RPC server started. Bound to: 127.19.137.254:44035
I20260812 06:19:44.382366 20261 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.19.137.254:44035 every 8 connection(s)
I20260812 06:19:44.382931 20262 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:44.385396 20262 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P 6f3d7f90ba8547a9bcccd584fec59f79: Bootstrap starting.
I20260812 06:19:44.386385 20262 tablet_bootstrap.cc:654] T 00000000000000000000000000000000 P 6f3d7f90ba8547a9bcccd584fec59f79: Neither blocks nor log segments found. Creating new log.
I20260812 06:19:44.387511 20262 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P 6f3d7f90ba8547a9bcccd584fec59f79: No bootstrap required, opened a new log
I20260812 06:19:44.388019 20262 raft_consensus.cc:359] T 00000000000000000000000000000000 P 6f3d7f90ba8547a9bcccd584fec59f79 [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "6f3d7f90ba8547a9bcccd584fec59f79" member_type: VOTER }
I20260812 06:19:44.388130 20262 raft_consensus.cc:385] T 00000000000000000000000000000000 P 6f3d7f90ba8547a9bcccd584fec59f79 [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:19:44.388170 20262 raft_consensus.cc:740] T 00000000000000000000000000000000 P 6f3d7f90ba8547a9bcccd584fec59f79 [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: 6f3d7f90ba8547a9bcccd584fec59f79, State: Initialized, Role: FOLLOWER
I20260812 06:19:44.388314 20262 consensus_queue.cc:260] T 00000000000000000000000000000000 P 6f3d7f90ba8547a9bcccd584fec59f79 [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: "6f3d7f90ba8547a9bcccd584fec59f79" member_type: VOTER }
I20260812 06:19:44.388411 20262 raft_consensus.cc:399] T 00000000000000000000000000000000 P 6f3d7f90ba8547a9bcccd584fec59f79 [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:19:44.388453 20262 raft_consensus.cc:493] T 00000000000000000000000000000000 P 6f3d7f90ba8547a9bcccd584fec59f79 [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:19:44.388502 20262 raft_consensus.cc:3060] T 00000000000000000000000000000000 P 6f3d7f90ba8547a9bcccd584fec59f79 [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:19:44.389410 20262 raft_consensus.cc:515] T 00000000000000000000000000000000 P 6f3d7f90ba8547a9bcccd584fec59f79 [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "6f3d7f90ba8547a9bcccd584fec59f79" member_type: VOTER }
I20260812 06:19:44.389560 20262 leader_election.cc:304] T 00000000000000000000000000000000 P 6f3d7f90ba8547a9bcccd584fec59f79 [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: 6f3d7f90ba8547a9bcccd584fec59f79; no voters: 
I20260812 06:19:44.389767 20262 leader_election.cc:290] T 00000000000000000000000000000000 P 6f3d7f90ba8547a9bcccd584fec59f79 [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:19:44.389861 20265 raft_consensus.cc:2804] T 00000000000000000000000000000000 P 6f3d7f90ba8547a9bcccd584fec59f79 [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:19:44.390046 20265 raft_consensus.cc:697] T 00000000000000000000000000000000 P 6f3d7f90ba8547a9bcccd584fec59f79 [term 1 LEADER]: Becoming Leader. State: Replica: 6f3d7f90ba8547a9bcccd584fec59f79, State: Running, Role: LEADER
I20260812 06:19:44.390221 20262 sys_catalog.cc:565] T 00000000000000000000000000000000 P 6f3d7f90ba8547a9bcccd584fec59f79 [sys.catalog]: configured and running, proceeding with master startup.
I20260812 06:19:44.390245 20265 consensus_queue.cc:237] T 00000000000000000000000000000000 P 6f3d7f90ba8547a9bcccd584fec59f79 [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: "6f3d7f90ba8547a9bcccd584fec59f79" member_type: VOTER }
I20260812 06:19:44.390664 20266 sys_catalog.cc:455] T 00000000000000000000000000000000 P 6f3d7f90ba8547a9bcccd584fec59f79 [sys.catalog]: SysCatalogTable state changed. Reason: RaftConsensus started. Latest consensus state: current_term: 1 leader_uuid: "6f3d7f90ba8547a9bcccd584fec59f79" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "6f3d7f90ba8547a9bcccd584fec59f79" member_type: VOTER } }
I20260812 06:19:44.390743 20266 sys_catalog.cc:458] T 00000000000000000000000000000000 P 6f3d7f90ba8547a9bcccd584fec59f79 [sys.catalog]: This master's current role is: LEADER
I20260812 06:19:44.391000 20267 sys_catalog.cc:455] T 00000000000000000000000000000000 P 6f3d7f90ba8547a9bcccd584fec59f79 [sys.catalog]: SysCatalogTable state changed. Reason: New leader 6f3d7f90ba8547a9bcccd584fec59f79. Latest consensus state: current_term: 1 leader_uuid: "6f3d7f90ba8547a9bcccd584fec59f79" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "6f3d7f90ba8547a9bcccd584fec59f79" member_type: VOTER } }
I20260812 06:19:44.391119 20267 sys_catalog.cc:458] T 00000000000000000000000000000000 P 6f3d7f90ba8547a9bcccd584fec59f79 [sys.catalog]: This master's current role is: LEADER
I20260812 06:19:44.391324 20269 catalog_manager.cc:1511] Loading table and tablet metadata into memory...
I20260812 06:19:44.392198 20269 catalog_manager.cc:1520] Initializing Kudu cluster ID...
I20260812 06:19:44.392411 20007 internal_mini_cluster.cc:184] Waiting to initialize catalog manager on master 0
I20260812 06:19:44.394100 20269 catalog_manager.cc:1383] Generated new cluster ID: efed95e8c95f4052bf0e31488d7e81d0
I20260812 06:19:44.394160 20269 catalog_manager.cc:1531] Initializing Kudu internal certificate authority...
I20260812 06:19:44.399299 20269 catalog_manager.cc:1406] Generated new certificate authority record
I20260812 06:19:44.400113 20269 catalog_manager.cc:1540] Loading token signing keys...
I20260812 06:19:44.412263 20269 catalog_manager.cc:6092] T 00000000000000000000000000000000 P 6f3d7f90ba8547a9bcccd584fec59f79: Generated new TSK 0
I20260812 06:19:44.412458 20269 catalog_manager.cc:1550] Initializing in-progress tserver states...
I20260812 06:19:44.424909 20007 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:19:44.426823 20283 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:44.426898 20286 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:44.426944 20284 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:44.427160 20007 server_base.cc:1061] running on GCE node
I20260812 06:19:44.427384 20007 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:19:44.427428 20007 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:44.427441 20007 hybrid_clock.cc:648] HybridClock initialized: now 1786515584427442 us; error 0 us; skew 500 ppm
I20260812 06:19:44.428275 20007 webserver.cc:533] Webserver started at http://127.19.137.193:42533/ using document root <none> and password file <none>
I20260812 06:19:44.428431 20007 fs_manager.cc:362] Metadata directory not provided
I20260812 06:19:44.428480 20007 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:19:44.428555 20007 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:19:44.428925 20007 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskztgv1X/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515578771685-20007-0/minicluster-data/ts-0-root/instance:
uuid: "0cda5a9e75eb46e3bfa99f51db835acd"
format_stamp: "Formatted at 2026-08-12 06:19:44 on dist-test-slave-f7th"
I20260812 06:19:44.430322 20007 fs_manager.cc:696] Time spent creating directory manager: real 0.001s	user 0.000s	sys 0.002s
I20260812 06:19:44.431264 20291 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:44.431545 20007 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.000s	sys 0.001s
I20260812 06:19:44.431634 20007 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskztgv1X/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515578771685-20007-0/minicluster-data/ts-0-root
uuid: "0cda5a9e75eb46e3bfa99f51db835acd"
format_stamp: "Formatted at 2026-08-12 06:19:44 on dist-test-slave-f7th"
I20260812 06:19:44.431704 20007 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskztgv1X/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515578771685-20007-0/minicluster-data/ts-0-root
metadata directory: /tmp/dist-test-taskztgv1X/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515578771685-20007-0/minicluster-data/ts-0-root
1 data directories: /tmp/dist-test-taskztgv1X/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515578771685-20007-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:44.437808 20007 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:19:44.438118 20007 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:19:44.438364 20007 txn_system_client.cc:432] TxnSystemClient initialization is disabled...
I20260812 06:19:44.438781 20007 ts_tablet_manager.cc:585] Loaded tablet metadata (0 total tablets, 0 live tablets)
I20260812 06:19:44.438817 20007 ts_tablet_manager.cc:531] Time spent load tablet metadata: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:19:44.438855 20007 ts_tablet_manager.cc:616] Registered 0 tablets
I20260812 06:19:44.438882 20007 ts_tablet_manager.cc:595] Time spent register tablets: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:19:44.443516 20007 rpc_server.cc:307] RPC server started. Bound to: 127.19.137.193:33699
I20260812 06:19:44.444231 20354 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.19.137.193:33699 every 8 connection(s)
I20260812 06:19:44.451579 20355 heartbeater.cc:344] Connected to a master server at 127.19.137.254:44035
I20260812 06:19:44.451723 20355 heartbeater.cc:461] Registering TS with master...
I20260812 06:19:44.451962 20355 heartbeater.cc:507] Master 127.19.137.254:44035 requested a full tablet report, sending...
I20260812 06:19:44.452590 20226 ts_manager.cc:194] Registered new tserver with Master: 0cda5a9e75eb46e3bfa99f51db835acd (127.19.137.193:33699)
I20260812 06:19:44.453179 20007 internal_mini_cluster.cc:371] 1 TS(s) registered with all masters after 0.008951657s
I20260812 06:19:44.453342 20226 master_service.cc:502] Signed X509 certificate for tserver {username='slave'} at 127.0.0.1:52176
I20260812 06:19:44.460601 20226 catalog_manager.cc:2283] Servicing CreateTable request from {username='slave'} at 127.0.0.1:52192:
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:44.469539 20319 tablet_service.cc:1511] Processing CreateTablet for tablet 405917d820fb4f5080cc9a5128c3150d (DEFAULT_TABLE table=heavy-update-compaction-test [id=291ffb77c35a407e8603ba3d626cc33c]), partition=
I20260812 06:19:44.469779 20319 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet 405917d820fb4f5080cc9a5128c3150d. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:19:44.471791 20367 tablet_bootstrap.cc:492] T 405917d820fb4f5080cc9a5128c3150d P 0cda5a9e75eb46e3bfa99f51db835acd: Bootstrap starting.
I20260812 06:19:44.472810 20367 tablet_bootstrap.cc:654] T 405917d820fb4f5080cc9a5128c3150d P 0cda5a9e75eb46e3bfa99f51db835acd: Neither blocks nor log segments found. Creating new log.
I20260812 06:19:44.474004 20367 tablet_bootstrap.cc:492] T 405917d820fb4f5080cc9a5128c3150d P 0cda5a9e75eb46e3bfa99f51db835acd: No bootstrap required, opened a new log
I20260812 06:19:44.474095 20367 ts_tablet_manager.cc:1403] T 405917d820fb4f5080cc9a5128c3150d P 0cda5a9e75eb46e3bfa99f51db835acd: Time spent bootstrapping tablet: real 0.002s	user 0.002s	sys 0.000s
I20260812 06:19:44.474548 20367 raft_consensus.cc:359] T 405917d820fb4f5080cc9a5128c3150d P 0cda5a9e75eb46e3bfa99f51db835acd [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "0cda5a9e75eb46e3bfa99f51db835acd" member_type: VOTER last_known_addr { host: "127.19.137.193" port: 33699 } }
I20260812 06:19:44.474659 20367 raft_consensus.cc:385] T 405917d820fb4f5080cc9a5128c3150d P 0cda5a9e75eb46e3bfa99f51db835acd [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:19:44.474696 20367 raft_consensus.cc:740] T 405917d820fb4f5080cc9a5128c3150d P 0cda5a9e75eb46e3bfa99f51db835acd [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: 0cda5a9e75eb46e3bfa99f51db835acd, State: Initialized, Role: FOLLOWER
I20260812 06:19:44.474813 20367 consensus_queue.cc:260] T 405917d820fb4f5080cc9a5128c3150d P 0cda5a9e75eb46e3bfa99f51db835acd [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: "0cda5a9e75eb46e3bfa99f51db835acd" member_type: VOTER last_known_addr { host: "127.19.137.193" port: 33699 } }
I20260812 06:19:44.474888 20367 raft_consensus.cc:399] T 405917d820fb4f5080cc9a5128c3150d P 0cda5a9e75eb46e3bfa99f51db835acd [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:19:44.474924 20367 raft_consensus.cc:493] T 405917d820fb4f5080cc9a5128c3150d P 0cda5a9e75eb46e3bfa99f51db835acd [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:19:44.474968 20367 raft_consensus.cc:3060] T 405917d820fb4f5080cc9a5128c3150d P 0cda5a9e75eb46e3bfa99f51db835acd [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:19:44.475867 20367 raft_consensus.cc:515] T 405917d820fb4f5080cc9a5128c3150d P 0cda5a9e75eb46e3bfa99f51db835acd [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "0cda5a9e75eb46e3bfa99f51db835acd" member_type: VOTER last_known_addr { host: "127.19.137.193" port: 33699 } }
I20260812 06:19:44.476013 20367 leader_election.cc:304] T 405917d820fb4f5080cc9a5128c3150d P 0cda5a9e75eb46e3bfa99f51db835acd [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: 0cda5a9e75eb46e3bfa99f51db835acd; no voters: 
I20260812 06:19:44.476209 20367 leader_election.cc:290] T 405917d820fb4f5080cc9a5128c3150d P 0cda5a9e75eb46e3bfa99f51db835acd [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:19:44.476310 20369 raft_consensus.cc:2804] T 405917d820fb4f5080cc9a5128c3150d P 0cda5a9e75eb46e3bfa99f51db835acd [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:19:44.476512 20367 ts_tablet_manager.cc:1434] T 405917d820fb4f5080cc9a5128c3150d P 0cda5a9e75eb46e3bfa99f51db835acd: Time spent starting tablet: real 0.002s	user 0.003s	sys 0.000s
I20260812 06:19:44.476609 20355 heartbeater.cc:499] Master 127.19.137.254:44035 was elected leader, sending a full tablet report...
I20260812 06:19:44.476522 20369 raft_consensus.cc:697] T 405917d820fb4f5080cc9a5128c3150d P 0cda5a9e75eb46e3bfa99f51db835acd [term 1 LEADER]: Becoming Leader. State: Replica: 0cda5a9e75eb46e3bfa99f51db835acd, State: Running, Role: LEADER
I20260812 06:19:44.476754 20369 consensus_queue.cc:237] T 405917d820fb4f5080cc9a5128c3150d P 0cda5a9e75eb46e3bfa99f51db835acd [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: "0cda5a9e75eb46e3bfa99f51db835acd" member_type: VOTER last_known_addr { host: "127.19.137.193" port: 33699 } }
I20260812 06:19:44.477984 20226 catalog_manager.cc:5719] T 405917d820fb4f5080cc9a5128c3150d P 0cda5a9e75eb46e3bfa99f51db835acd reported cstate change: term changed from 0 to 1, leader changed from <none> to 0cda5a9e75eb46e3bfa99f51db835acd (127.19.137.193). New cstate: current_term: 1 leader_uuid: "0cda5a9e75eb46e3bfa99f51db835acd" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "0cda5a9e75eb46e3bfa99f51db835acd" member_type: VOTER last_known_addr { host: "127.19.137.193" port: 33699 } health_report { overall_health: HEALTHY } } }
I20260812 06:19:44.535821 20007 heavy-update-compaction-itest.cc:215] Time spent inserting: real 0.052s	user 0.015s	sys 0.006s
I20260812 06:19:44.694680 20356 maintenance_manager.cc:419] P 0cda5a9e75eb46e3bfa99f51db835acd: Scheduling FlushMRSOp(405917d820fb4f5080cc9a5128c3150d): perf score=19.054940
I20260812 06:19:44.846979 20296 maintenance_manager.cc:643] P 0cda5a9e75eb46e3bfa99f51db835acd: FlushMRSOp(405917d820fb4f5080cc9a5128c3150d) complete. Timing: real 0.152s	user 0.103s	sys 0.040s Metrics: {"bytes_written":12307492,"cfile_init":1,"delete_count":0,"dirs.queue_time_us":57,"dirs.run_cpu_time_us":193,"dirs.run_wall_time_us":905,"drs_written":1,"lbm_read_time_us":36,"lbm_reads_lt_1ms":4,"lbm_write_time_us":35445,"lbm_writes_lt_1ms":757,"mutex_wait_us":2,"peak_mem_usage":0,"reinsert_count":0,"rows_written":104,"update_count":1500}
I20260812 06:19:44.847671 20356 maintenance_manager.cc:419] P 0cda5a9e75eb46e3bfa99f51db835acd: Scheduling LogGCOp(405917d820fb4f5080cc9a5128c3150d): free 20743880 bytes of WAL
I20260812 06:19:44.847896 20296 log_reader.cc:385] T 405917d820fb4f5080cc9a5128c3150d: removed 2 log segments from log reader
I20260812 06:19:44.847951 20296 log.cc:1079] T 405917d820fb4f5080cc9a5128c3150d P 0cda5a9e75eb46e3bfa99f51db835acd: Deleting log segment in path: /tmp/dist-test-taskztgv1X/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515578771685-20007-0/minicluster-data/ts-0-root/wals/405917d820fb4f5080cc9a5128c3150d/wal-000000001 (ops 1-6)
I20260812 06:19:44.847988 20296 log.cc:1079] T 405917d820fb4f5080cc9a5128c3150d P 0cda5a9e75eb46e3bfa99f51db835acd: Deleting log segment in path: /tmp/dist-test-taskztgv1X/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515578771685-20007-0/minicluster-data/ts-0-root/wals/405917d820fb4f5080cc9a5128c3150d/wal-000000002 (ops 7-11)
I20260812 06:19:44.852732 20296 maintenance_manager.cc:643] P 0cda5a9e75eb46e3bfa99f51db835acd: LogGCOp(405917d820fb4f5080cc9a5128c3150d) complete. Timing: real 0.005s	user 0.000s	sys 0.004s Metrics: {}
I20260812 06:19:44.853080 20356 maintenance_manager.cc:419] P 0cda5a9e75eb46e3bfa99f51db835acd: Scheduling UndoDeltaBlockGCOp(405917d820fb4f5080cc9a5128c3150d): 16411396 bytes on disk
I20260812 06:19:44.853564 20296 maintenance_manager.cc:643] P 0cda5a9e75eb46e3bfa99f51db835acd: UndoDeltaBlockGCOp(405917d820fb4f5080cc9a5128c3150d) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":73,"lbm_reads_lt_1ms":4}
I20260812 06:19:44.854040 20356 maintenance_manager.cc:419] P 0cda5a9e75eb46e3bfa99f51db835acd: Scheduling FlushDeltaMemStoresOp(405917d820fb4f5080cc9a5128c3150d): perf score=2.188937
I20260812 06:19:44.869417 20296 maintenance_manager.cc:643] P 0cda5a9e75eb46e3bfa99f51db835acd: FlushDeltaMemStoresOp(405917d820fb4f5080cc9a5128c3150d) complete. Timing: real 0.015s	user 0.009s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5780,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:44.869921 20356 maintenance_manager.cc:419] P 0cda5a9e75eb46e3bfa99f51db835acd: Scheduling MajorDeltaCompactionOp(405917d820fb4f5080cc9a5128c3150d): perf score=1.000000
I20260812 06:19:45.044384 20296 maintenance_manager.cc:643] P 0cda5a9e75eb46e3bfa99f51db835acd: MajorDeltaCompactionOp(405917d820fb4f5080cc9a5128c3150d) complete. Timing: real 0.174s	user 0.123s	sys 0.039s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672279,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":462,"lbm_read_time_us":10633,"lbm_reads_lt_1ms":464,"lbm_write_time_us":26250,"lbm_writes_lt_1ms":443,"peak_mem_usage":50689328,"reinsert_count":0,"thread_start_us":288,"threads_started":5,"update_count":2000}
I20260812 06:19:45.044909 20356 maintenance_manager.cc:419] P 0cda5a9e75eb46e3bfa99f51db835acd: Scheduling FlushDeltaMemStoresOp(405917d820fb4f5080cc9a5128c3150d): perf score=14.095187
I20260812 06:19:45.090857 20296 maintenance_manager.cc:643] P 0cda5a9e75eb46e3bfa99f51db835acd: FlushDeltaMemStoresOp(405917d820fb4f5080cc9a5128c3150d) complete. Timing: real 0.046s	user 0.025s	sys 0.016s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":19720,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:45.091462 20356 maintenance_manager.cc:419] P 0cda5a9e75eb46e3bfa99f51db835acd: Scheduling FlushDeltaMemStoresOp(405917d820fb4f5080cc9a5128c3150d): perf score=2.188937
I20260812 06:19:45.113408 20296 maintenance_manager.cc:643] P 0cda5a9e75eb46e3bfa99f51db835acd: FlushDeltaMemStoresOp(405917d820fb4f5080cc9a5128c3150d) complete. Timing: real 0.022s	user 0.008s	sys 0.012s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5076,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:45.114028 20356 maintenance_manager.cc:419] P 0cda5a9e75eb46e3bfa99f51db835acd: Scheduling MajorDeltaCompactionOp(405917d820fb4f5080cc9a5128c3150d): perf score=1.000000
I20260812 06:19:45.304944 20296 maintenance_manager.cc:643] P 0cda5a9e75eb46e3bfa99f51db835acd: MajorDeltaCompactionOp(405917d820fb4f5080cc9a5128c3150d) complete. Timing: real 0.191s	user 0.132s	sys 0.059s 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":71,"lbm_read_time_us":13515,"lbm_reads_lt_1ms":572,"lbm_write_time_us":29695,"lbm_writes_lt_1ms":543,"mutex_wait_us":71,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":4480,"update_count":2500}
I20260812 06:19:45.305761 20356 maintenance_manager.cc:419] P 0cda5a9e75eb46e3bfa99f51db835acd: Scheduling FlushDeltaMemStoresOp(405917d820fb4f5080cc9a5128c3150d): perf score=14.095187
I20260812 06:19:45.344468 20296 maintenance_manager.cc:643] P 0cda5a9e75eb46e3bfa99f51db835acd: FlushDeltaMemStoresOp(405917d820fb4f5080cc9a5128c3150d) complete. Timing: real 0.039s	user 0.025s	sys 0.012s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":16626,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:45.344983 20356 maintenance_manager.cc:419] P 0cda5a9e75eb46e3bfa99f51db835acd: Scheduling FlushDeltaMemStoresOp(405917d820fb4f5080cc9a5128c3150d): perf score=2.188937
I20260812 06:19:45.360728 20296 maintenance_manager.cc:643] P 0cda5a9e75eb46e3bfa99f51db835acd: FlushDeltaMemStoresOp(405917d820fb4f5080cc9a5128c3150d) complete. Timing: real 0.016s	user 0.005s	sys 0.010s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5977,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:45.361119 20356 maintenance_manager.cc:419] P 0cda5a9e75eb46e3bfa99f51db835acd: Scheduling MajorDeltaCompactionOp(405917d820fb4f5080cc9a5128c3150d): perf score=1.000000
I20260812 06:19:45.552282 20296 maintenance_manager.cc:643] P 0cda5a9e75eb46e3bfa99f51db835acd: MajorDeltaCompactionOp(405917d820fb4f5080cc9a5128c3150d) complete. Timing: real 0.191s	user 0.138s	sys 0.046s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774689,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":126,"lbm_read_time_us":11533,"lbm_reads_lt_1ms":572,"lbm_write_time_us":29562,"lbm_writes_lt_1ms":543,"mutex_wait_us":19,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":7040,"update_count":2500}
I20260812 06:19:45.552897 20356 maintenance_manager.cc:419] P 0cda5a9e75eb46e3bfa99f51db835acd: Scheduling FlushDeltaMemStoresOp(405917d820fb4f5080cc9a5128c3150d): perf score=14.095187
I20260812 06:19:45.599205 20296 maintenance_manager.cc:643] P 0cda5a9e75eb46e3bfa99f51db835acd: FlushDeltaMemStoresOp(405917d820fb4f5080cc9a5128c3150d) complete. Timing: real 0.045s	user 0.033s	sys 0.008s Metrics: {"bytes_written":16409903,"delete_count":0,"lbm_write_time_us":19189,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:45.599766 20356 maintenance_manager.cc:419] P 0cda5a9e75eb46e3bfa99f51db835acd: Scheduling FlushDeltaMemStoresOp(405917d820fb4f5080cc9a5128c3150d): perf score=2.188937
I20260812 06:19:45.619433 20296 maintenance_manager.cc:643] P 0cda5a9e75eb46e3bfa99f51db835acd: FlushDeltaMemStoresOp(405917d820fb4f5080cc9a5128c3150d) complete. Timing: real 0.020s	user 0.010s	sys 0.005s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6319,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:45.619901 20356 maintenance_manager.cc:419] P 0cda5a9e75eb46e3bfa99f51db835acd: Scheduling MajorDeltaCompactionOp(405917d820fb4f5080cc9a5128c3150d): perf score=1.000000
I20260812 06:19:45.773346 20296 maintenance_manager.cc:643] P 0cda5a9e75eb46e3bfa99f51db835acd: MajorDeltaCompactionOp(405917d820fb4f5080cc9a5128c3150d) complete. Timing: real 0.153s	user 0.128s	sys 0.023s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774690,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":335,"lbm_read_time_us":8363,"lbm_reads_lt_1ms":564,"lbm_write_time_us":29016,"lbm_writes_lt_1ms":543,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":3712,"update_count":2500}
I20260812 06:19:45.773993 20356 maintenance_manager.cc:419] P 0cda5a9e75eb46e3bfa99f51db835acd: Scheduling FlushDeltaMemStoresOp(405917d820fb4f5080cc9a5128c3150d): perf score=11.118625
I20260812 06:19:45.810619 20296 maintenance_manager.cc:643] P 0cda5a9e75eb46e3bfa99f51db835acd: FlushDeltaMemStoresOp(405917d820fb4f5080cc9a5128c3150d) complete. Timing: real 0.036s	user 0.026s	sys 0.007s Metrics: {"bytes_written":12717736,"delete_count":0,"lbm_write_time_us":15559,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:19:45.811172 20356 maintenance_manager.cc:419] P 0cda5a9e75eb46e3bfa99f51db835acd: Scheduling FlushDeltaMemStoresOp(405917d820fb4f5080cc9a5128c3150d): perf score=2.188937
I20260812 06:19:45.824525 20296 maintenance_manager.cc:643] P 0cda5a9e75eb46e3bfa99f51db835acd: FlushDeltaMemStoresOp(405917d820fb4f5080cc9a5128c3150d) complete. Timing: real 0.013s	user 0.011s	sys 0.001s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":4810,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:19:45.825017 20356 maintenance_manager.cc:419] P 0cda5a9e75eb46e3bfa99f51db835acd: Scheduling MajorDeltaCompactionOp(405917d820fb4f5080cc9a5128c3150d): perf score=1.000000
I20260812 06:19:45.959839 20296 maintenance_manager.cc:643] P 0cda5a9e75eb46e3bfa99f51db835acd: MajorDeltaCompactionOp(405917d820fb4f5080cc9a5128c3150d) complete. Timing: real 0.135s	user 0.110s	sys 0.021s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672269,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":390,"lbm_read_time_us":8432,"lbm_reads_lt_1ms":472,"lbm_write_time_us":25126,"lbm_writes_lt_1ms":443,"mutex_wait_us":68,"peak_mem_usage":50689328,"reinsert_count":0,"update_count":2000}
I20260812 06:19:45.963343 20356 maintenance_manager.cc:419] P 0cda5a9e75eb46e3bfa99f51db835acd: Scheduling FlushDeltaMemStoresOp(405917d820fb4f5080cc9a5128c3150d): perf score=11.118625
I20260812 06:19:46.007107 20296 maintenance_manager.cc:643] P 0cda5a9e75eb46e3bfa99f51db835acd: FlushDeltaMemStoresOp(405917d820fb4f5080cc9a5128c3150d) complete. Timing: real 0.044s	user 0.030s	sys 0.003s Metrics: {"bytes_written":13045918,"delete_count":0,"lbm_write_time_us":16054,"lbm_writes_lt_1ms":321,"reinsert_count":0,"update_count":1590}
I20260812 06:19:46.007745 20356 maintenance_manager.cc:419] P 0cda5a9e75eb46e3bfa99f51db835acd: Scheduling FlushDeltaMemStoresOp(405917d820fb4f5080cc9a5128c3150d): perf score=2.188937
I20260812 06:19:46.020264 20296 maintenance_manager.cc:643] P 0cda5a9e75eb46e3bfa99f51db835acd: FlushDeltaMemStoresOp(405917d820fb4f5080cc9a5128c3150d) complete. Timing: real 0.012s	user 0.011s	sys 0.001s Metrics: {"bytes_written":3774459,"delete_count":0,"lbm_write_time_us":4632,"lbm_writes_lt_1ms":95,"reinsert_count":0,"update_count":460}
I20260812 06:19:46.020785 20356 maintenance_manager.cc:419] P 0cda5a9e75eb46e3bfa99f51db835acd: Scheduling FlushDeltaMemStoresOp(405917d820fb4f5080cc9a5128c3150d): perf score=2.188937
I20260812 06:19:46.033548 20296 maintenance_manager.cc:643] P 0cda5a9e75eb46e3bfa99f51db835acd: FlushDeltaMemStoresOp(405917d820fb4f5080cc9a5128c3150d) complete. Timing: real 0.013s	user 0.006s	sys 0.004s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":4491,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:19:46.034307 20356 maintenance_manager.cc:419] P 0cda5a9e75eb46e3bfa99f51db835acd: Scheduling FlushMRSOp(405917d820fb4f5080cc9a5128c3150d): perf score=1.000000
I20260812 06:19:46.070490 20296 maintenance_manager.cc:643] P 0cda5a9e75eb46e3bfa99f51db835acd: FlushMRSOp(405917d820fb4f5080cc9a5128c3150d) complete. Timing: real 0.036s	user 0.029s	sys 0.005s Metrics: {"bytes_written":1152508,"cfile_init":1,"dirs.queue_time_us":65,"dirs.run_cpu_time_us":304,"dirs.run_wall_time_us":1283,"drs_written":1,"lbm_read_time_us":58,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1733,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":28}
I20260812 06:19:46.071306 20356 maintenance_manager.cc:419] P 0cda5a9e75eb46e3bfa99f51db835acd: Scheduling LogGCOp(405917d820fb4f5080cc9a5128c3150d): free 112239310 bytes of WAL
I20260812 06:19:46.071794 20296 log_reader.cc:385] T 405917d820fb4f5080cc9a5128c3150d: removed 11 log segments from log reader
I20260812 06:19:46.071888 20296 log.cc:1079] T 405917d820fb4f5080cc9a5128c3150d P 0cda5a9e75eb46e3bfa99f51db835acd: Deleting log segment in path: /tmp/dist-test-taskztgv1X/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515578771685-20007-0/minicluster-data/ts-0-root/wals/405917d820fb4f5080cc9a5128c3150d/wal-000000003 (ops 12-16)
I20260812 06:19:46.071965 20296 log.cc:1079] T 405917d820fb4f5080cc9a5128c3150d P 0cda5a9e75eb46e3bfa99f51db835acd: Deleting log segment in path: /tmp/dist-test-taskztgv1X/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515578771685-20007-0/minicluster-data/ts-0-root/wals/405917d820fb4f5080cc9a5128c3150d/wal-000000004 (ops 17-21)
I20260812 06:19:46.072026 20296 log.cc:1079] T 405917d820fb4f5080cc9a5128c3150d P 0cda5a9e75eb46e3bfa99f51db835acd: Deleting log segment in path: /tmp/dist-test-taskztgv1X/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515578771685-20007-0/minicluster-data/ts-0-root/wals/405917d820fb4f5080cc9a5128c3150d/wal-000000005 (ops 22-26)
I20260812 06:19:46.072077 20296 log.cc:1079] T 405917d820fb4f5080cc9a5128c3150d P 0cda5a9e75eb46e3bfa99f51db835acd: Deleting log segment in path: /tmp/dist-test-taskztgv1X/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515578771685-20007-0/minicluster-data/ts-0-root/wals/405917d820fb4f5080cc9a5128c3150d/wal-000000006 (ops 27-31)
I20260812 06:19:46.072134 20296 log.cc:1079] T 405917d820fb4f5080cc9a5128c3150d P 0cda5a9e75eb46e3bfa99f51db835acd: Deleting log segment in path: /tmp/dist-test-taskztgv1X/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515578771685-20007-0/minicluster-data/ts-0-root/wals/405917d820fb4f5080cc9a5128c3150d/wal-000000007 (ops 32-36)
I20260812 06:19:46.072196 20296 log.cc:1079] T 405917d820fb4f5080cc9a5128c3150d P 0cda5a9e75eb46e3bfa99f51db835acd: Deleting log segment in path: /tmp/dist-test-taskztgv1X/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515578771685-20007-0/minicluster-data/ts-0-root/wals/405917d820fb4f5080cc9a5128c3150d/wal-000000008 (ops 37-40)
I20260812 06:19:46.072254 20296 log.cc:1079] T 405917d820fb4f5080cc9a5128c3150d P 0cda5a9e75eb46e3bfa99f51db835acd: Deleting log segment in path: /tmp/dist-test-taskztgv1X/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515578771685-20007-0/minicluster-data/ts-0-root/wals/405917d820fb4f5080cc9a5128c3150d/wal-000000009 (ops 41-45)
I20260812 06:19:46.072309 20296 log.cc:1079] T 405917d820fb4f5080cc9a5128c3150d P 0cda5a9e75eb46e3bfa99f51db835acd: Deleting log segment in path: /tmp/dist-test-taskztgv1X/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515578771685-20007-0/minicluster-data/ts-0-root/wals/405917d820fb4f5080cc9a5128c3150d/wal-000000010 (ops 46-50)
I20260812 06:19:46.072377 20296 log.cc:1079] T 405917d820fb4f5080cc9a5128c3150d P 0cda5a9e75eb46e3bfa99f51db835acd: Deleting log segment in path: /tmp/dist-test-taskztgv1X/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515578771685-20007-0/minicluster-data/ts-0-root/wals/405917d820fb4f5080cc9a5128c3150d/wal-000000011 (ops 51-55)
I20260812 06:19:46.072448 20296 log.cc:1079] T 405917d820fb4f5080cc9a5128c3150d P 0cda5a9e75eb46e3bfa99f51db835acd: Deleting log segment in path: /tmp/dist-test-taskztgv1X/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515578771685-20007-0/minicluster-data/ts-0-root/wals/405917d820fb4f5080cc9a5128c3150d/wal-000000012 (ops 56-60)
I20260812 06:19:46.072513 20296 log.cc:1079] T 405917d820fb4f5080cc9a5128c3150d P 0cda5a9e75eb46e3bfa99f51db835acd: Deleting log segment in path: /tmp/dist-test-taskztgv1X/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515578771685-20007-0/minicluster-data/ts-0-root/wals/405917d820fb4f5080cc9a5128c3150d/wal-000000013 (ops 61-65)
I20260812 06:19:46.093731 20296 maintenance_manager.cc:643] P 0cda5a9e75eb46e3bfa99f51db835acd: LogGCOp(405917d820fb4f5080cc9a5128c3150d) complete. Timing: real 0.022s	user 0.000s	sys 0.020s Metrics: {}
I20260812 06:19:46.094108 20356 maintenance_manager.cc:419] P 0cda5a9e75eb46e3bfa99f51db835acd: Scheduling FlushDeltaMemStoresOp(405917d820fb4f5080cc9a5128c3150d): perf score=4.173312
I20260812 06:19:46.112524 20296 maintenance_manager.cc:643] P 0cda5a9e75eb46e3bfa99f51db835acd: FlushDeltaMemStoresOp(405917d820fb4f5080cc9a5128c3150d) complete. Timing: real 0.018s	user 0.005s	sys 0.012s Metrics: {"bytes_written":6276942,"delete_count":0,"lbm_write_time_us":7189,"lbm_writes_lt_1ms":156,"mutex_wait_us":45,"reinsert_count":0,"update_count":765}
I20260812 06:19:46.113019 20356 maintenance_manager.cc:419] P 0cda5a9e75eb46e3bfa99f51db835acd: Scheduling FlushDeltaMemStoresOp(405917d820fb4f5080cc9a5128c3150d): perf score=1.000000
I20260812 06:19:46.123844 20296 maintenance_manager.cc:643] P 0cda5a9e75eb46e3bfa99f51db835acd: FlushDeltaMemStoresOp(405917d820fb4f5080cc9a5128c3150d) complete. Timing: real 0.011s	user 0.010s	sys 0.000s Metrics: {"bytes_written":1928327,"delete_count":0,"lbm_write_time_us":3127,"lbm_writes_lt_1ms":50,"reinsert_count":0,"update_count":235}
I20260812 06:19:46.124354 20356 maintenance_manager.cc:419] P 0cda5a9e75eb46e3bfa99f51db835acd: Scheduling MajorDeltaCompactionOp(405917d820fb4f5080cc9a5128c3150d): perf score=1.000000
I20260812 06:19:46.325176 20296 maintenance_manager.cc:643] P 0cda5a9e75eb46e3bfa99f51db835acd: MajorDeltaCompactionOp(405917d820fb4f5080cc9a5128c3150d) complete. Timing: real 0.201s	user 0.138s	sys 0.060s Metrics: {"cfile_cache_miss":735,"cfile_cache_miss_bytes":32979790,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":5,"delta_iterators_relevant":5,"dirs.queue_time_us":802,"lbm_read_time_us":11409,"lbm_reads_lt_1ms":767,"lbm_write_time_us":40196,"lbm_writes_lt_1ms":743,"mutex_wait_us":253,"peak_mem_usage":87969044,"reinsert_count":0,"spinlock_wait_cycles":7936,"thread_start_us":72,"threads_started":1,"update_count":3500}
I20260812 06:19:46.325640 20356 maintenance_manager.cc:419] P 0cda5a9e75eb46e3bfa99f51db835acd: Scheduling UndoDeltaBlockGCOp(405917d820fb4f5080cc9a5128c3150d): 448 bytes on disk
I20260812 06:19:46.326339 20296 maintenance_manager.cc:643] P 0cda5a9e75eb46e3bfa99f51db835acd: UndoDeltaBlockGCOp(405917d820fb4f5080cc9a5128c3150d) complete. Timing: real 0.001s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":42,"lbm_reads_lt_1ms":4}
I20260812 06:19:46.326820 20356 maintenance_manager.cc:419] P 0cda5a9e75eb46e3bfa99f51db835acd: Scheduling FlushDeltaMemStoresOp(405917d820fb4f5080cc9a5128c3150d): perf score=14.095187
I20260812 06:19:46.367957 20296 maintenance_manager.cc:643] P 0cda5a9e75eb46e3bfa99f51db835acd: FlushDeltaMemStoresOp(405917d820fb4f5080cc9a5128c3150d) complete. Timing: real 0.041s	user 0.017s	sys 0.023s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":17652,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:46.368445 20356 maintenance_manager.cc:419] P 0cda5a9e75eb46e3bfa99f51db835acd: Scheduling FlushDeltaMemStoresOp(405917d820fb4f5080cc9a5128c3150d): perf score=2.188937
I20260812 06:19:46.384546 20296 maintenance_manager.cc:643] P 0cda5a9e75eb46e3bfa99f51db835acd: FlushDeltaMemStoresOp(405917d820fb4f5080cc9a5128c3150d) complete. Timing: real 0.016s	user 0.013s	sys 0.000s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":5364,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:46.385038 20356 maintenance_manager.cc:419] P 0cda5a9e75eb46e3bfa99f51db835acd: Scheduling MajorDeltaCompactionOp(405917d820fb4f5080cc9a5128c3150d): perf score=1.000000
I20260812 06:19:46.537096 20296 maintenance_manager.cc:643] P 0cda5a9e75eb46e3bfa99f51db835acd: MajorDeltaCompactionOp(405917d820fb4f5080cc9a5128c3150d) complete. Timing: real 0.152s	user 0.111s	sys 0.039s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774687,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":219,"lbm_read_time_us":11111,"lbm_reads_lt_1ms":568,"lbm_write_time_us":28983,"lbm_writes_lt_1ms":543,"mutex_wait_us":52,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":896,"update_count":2500}
I20260812 06:19:46.537690 20356 maintenance_manager.cc:419] P 0cda5a9e75eb46e3bfa99f51db835acd: Scheduling FlushDeltaMemStoresOp(405917d820fb4f5080cc9a5128c3150d): perf score=11.118625
I20260812 06:19:46.574842 20296 maintenance_manager.cc:643] P 0cda5a9e75eb46e3bfa99f51db835acd: FlushDeltaMemStoresOp(405917d820fb4f5080cc9a5128c3150d) complete. Timing: real 0.037s	user 0.021s	sys 0.008s Metrics: {"bytes_written":12717735,"delete_count":0,"lbm_write_time_us":13635,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:19:46.575287 20356 maintenance_manager.cc:419] P 0cda5a9e75eb46e3bfa99f51db835acd: Scheduling FlushDeltaMemStoresOp(405917d820fb4f5080cc9a5128c3150d): perf score=2.188937
I20260812 06:19:46.590281 20296 maintenance_manager.cc:643] P 0cda5a9e75eb46e3bfa99f51db835acd: FlushDeltaMemStoresOp(405917d820fb4f5080cc9a5128c3150d) complete. Timing: real 0.015s	user 0.009s	sys 0.003s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":6087,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":92,"reinsert_count":0,"update_count":450}
I20260812 06:19:46.590796 20356 maintenance_manager.cc:419] P 0cda5a9e75eb46e3bfa99f51db835acd: Scheduling MajorDeltaCompactionOp(405917d820fb4f5080cc9a5128c3150d): perf score=1.000000
I20260812 06:19:46.735913 20296 maintenance_manager.cc:643] P 0cda5a9e75eb46e3bfa99f51db835acd: MajorDeltaCompactionOp(405917d820fb4f5080cc9a5128c3150d) complete. Timing: real 0.145s	user 0.116s	sys 0.028s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672268,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":604,"lbm_read_time_us":9314,"lbm_reads_lt_1ms":472,"lbm_write_time_us":22214,"lbm_writes_lt_1ms":443,"peak_mem_usage":50689328,"reinsert_count":0,"update_count":2000}
I20260812 06:19:46.736416 20356 maintenance_manager.cc:419] P 0cda5a9e75eb46e3bfa99f51db835acd: Scheduling FlushDeltaMemStoresOp(405917d820fb4f5080cc9a5128c3150d): perf score=10.126437
I20260812 06:19:46.783236 20296 maintenance_manager.cc:643] P 0cda5a9e75eb46e3bfa99f51db835acd: FlushDeltaMemStoresOp(405917d820fb4f5080cc9a5128c3150d) complete. Timing: real 0.047s	user 0.023s	sys 0.013s Metrics: {"bytes_written":12307494,"delete_count":0,"lbm_write_time_us":17332,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:19:46.783735 20356 maintenance_manager.cc:419] P 0cda5a9e75eb46e3bfa99f51db835acd: Scheduling FlushDeltaMemStoresOp(405917d820fb4f5080cc9a5128c3150d): perf score=2.188937
I20260812 06:19:46.798527 20296 maintenance_manager.cc:643] P 0cda5a9e75eb46e3bfa99f51db835acd: FlushDeltaMemStoresOp(405917d820fb4f5080cc9a5128c3150d) complete. Timing: real 0.015s	user 0.007s	sys 0.005s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5288,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:46.799007 20356 maintenance_manager.cc:419] P 0cda5a9e75eb46e3bfa99f51db835acd: Scheduling MajorDeltaCompactionOp(405917d820fb4f5080cc9a5128c3150d): perf score=1.000000
I20260812 06:19:46.931805 20296 maintenance_manager.cc:643] P 0cda5a9e75eb46e3bfa99f51db835acd: MajorDeltaCompactionOp(405917d820fb4f5080cc9a5128c3150d) complete. Timing: real 0.133s	user 0.102s	sys 0.028s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672281,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"lbm_read_time_us":8400,"lbm_reads_lt_1ms":472,"lbm_write_time_us":24092,"lbm_writes_lt_1ms":443,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":1536,"update_count":2000}
I20260812 06:19:46.932317 20356 maintenance_manager.cc:419] P 0cda5a9e75eb46e3bfa99f51db835acd: Scheduling FlushDeltaMemStoresOp(405917d820fb4f5080cc9a5128c3150d): perf score=10.126437
I20260812 06:19:46.987872 20296 maintenance_manager.cc:643] P 0cda5a9e75eb46e3bfa99f51db835acd: FlushDeltaMemStoresOp(405917d820fb4f5080cc9a5128c3150d) complete. Timing: real 0.055s	user 0.019s	sys 0.024s Metrics: {"bytes_written":12307492,"delete_count":0,"lbm_write_time_us":18091,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:19:46.988406 20356 maintenance_manager.cc:419] P 0cda5a9e75eb46e3bfa99f51db835acd: Scheduling FlushDeltaMemStoresOp(405917d820fb4f5080cc9a5128c3150d): perf score=2.188937
I20260812 06:19:47.002916 20296 maintenance_manager.cc:643] P 0cda5a9e75eb46e3bfa99f51db835acd: FlushDeltaMemStoresOp(405917d820fb4f5080cc9a5128c3150d) complete. Timing: real 0.014s	user 0.012s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5199,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:47.003473 20356 maintenance_manager.cc:419] P 0cda5a9e75eb46e3bfa99f51db835acd: Scheduling MajorDeltaCompactionOp(405917d820fb4f5080cc9a5128c3150d): perf score=1.000000
I20260812 06:19:47.151031 20296 maintenance_manager.cc:643] P 0cda5a9e75eb46e3bfa99f51db835acd: MajorDeltaCompactionOp(405917d820fb4f5080cc9a5128c3150d) complete. Timing: real 0.147s	user 0.120s	sys 0.025s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672279,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":263,"lbm_read_time_us":8591,"lbm_reads_lt_1ms":472,"lbm_write_time_us":27445,"lbm_writes_lt_1ms":443,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":3200,"update_count":2000}
I20260812 06:19:47.151660 20356 maintenance_manager.cc:419] P 0cda5a9e75eb46e3bfa99f51db835acd: Scheduling FlushDeltaMemStoresOp(405917d820fb4f5080cc9a5128c3150d): perf score=11.118625
I20260812 06:19:47.191440 20296 maintenance_manager.cc:643] P 0cda5a9e75eb46e3bfa99f51db835acd: FlushDeltaMemStoresOp(405917d820fb4f5080cc9a5128c3150d) complete. Timing: real 0.040s	user 0.022s	sys 0.017s Metrics: {"bytes_written":12717735,"delete_count":0,"lbm_write_time_us":17262,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:19:47.192023 20356 maintenance_manager.cc:419] P 0cda5a9e75eb46e3bfa99f51db835acd: Scheduling FlushDeltaMemStoresOp(405917d820fb4f5080cc9a5128c3150d): perf score=2.188937
I20260812 06:19:47.202452 20296 maintenance_manager.cc:643] P 0cda5a9e75eb46e3bfa99f51db835acd: FlushDeltaMemStoresOp(405917d820fb4f5080cc9a5128c3150d) complete. Timing: real 0.010s	user 0.008s	sys 0.000s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3380,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:19:47.203069 20356 maintenance_manager.cc:419] P 0cda5a9e75eb46e3bfa99f51db835acd: Scheduling MajorDeltaCompactionOp(405917d820fb4f5080cc9a5128c3150d): perf score=1.000000
I20260812 06:19:47.331333 20296 maintenance_manager.cc:643] P 0cda5a9e75eb46e3bfa99f51db835acd: MajorDeltaCompactionOp(405917d820fb4f5080cc9a5128c3150d) complete. Timing: real 0.128s	user 0.093s	sys 0.020s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672268,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":1513,"lbm_read_time_us":8685,"lbm_reads_lt_1ms":472,"lbm_write_time_us":20948,"lbm_writes_lt_1ms":443,"mutex_wait_us":561,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":12800,"update_count":2000}
I20260812 06:19:47.331955 20356 maintenance_manager.cc:419] P 0cda5a9e75eb46e3bfa99f51db835acd: Scheduling FlushDeltaMemStoresOp(405917d820fb4f5080cc9a5128c3150d): perf score=10.126437
I20260812 06:19:47.388060 20296 maintenance_manager.cc:643] P 0cda5a9e75eb46e3bfa99f51db835acd: FlushDeltaMemStoresOp(405917d820fb4f5080cc9a5128c3150d) complete. Timing: real 0.056s	user 0.038s	sys 0.007s Metrics: {"bytes_written":12307493,"delete_count":0,"lbm_write_time_us":15968,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:19:47.388556 20356 maintenance_manager.cc:419] P 0cda5a9e75eb46e3bfa99f51db835acd: Scheduling FlushDeltaMemStoresOp(405917d820fb4f5080cc9a5128c3150d): perf score=2.188937
I20260812 06:19:47.398834 20296 maintenance_manager.cc:643] P 0cda5a9e75eb46e3bfa99f51db835acd: FlushDeltaMemStoresOp(405917d820fb4f5080cc9a5128c3150d) complete. Timing: real 0.010s	user 0.004s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3843,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:47.399250 20356 maintenance_manager.cc:419] P 0cda5a9e75eb46e3bfa99f51db835acd: Scheduling MajorDeltaCompactionOp(405917d820fb4f5080cc9a5128c3150d): perf score=1.000000
I20260812 06:19:47.566509 20296 maintenance_manager.cc:643] P 0cda5a9e75eb46e3bfa99f51db835acd: MajorDeltaCompactionOp(405917d820fb4f5080cc9a5128c3150d) complete. Timing: real 0.167s	user 0.101s	sys 0.053s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672280,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":304,"lbm_read_time_us":10450,"lbm_reads_lt_1ms":472,"lbm_write_time_us":24168,"lbm_writes_lt_1ms":443,"peak_mem_usage":50689328,"reinsert_count":0,"update_count":2000}
I20260812 06:19:47.567036 20356 maintenance_manager.cc:419] P 0cda5a9e75eb46e3bfa99f51db835acd: Scheduling FlushDeltaMemStoresOp(405917d820fb4f5080cc9a5128c3150d): perf score=10.126437
I20260812 06:19:47.608403 20296 maintenance_manager.cc:643] P 0cda5a9e75eb46e3bfa99f51db835acd: FlushDeltaMemStoresOp(405917d820fb4f5080cc9a5128c3150d) complete. Timing: real 0.041s	user 0.032s	sys 0.004s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":14956,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:19:47.608987 20356 maintenance_manager.cc:419] P 0cda5a9e75eb46e3bfa99f51db835acd: Scheduling FlushDeltaMemStoresOp(405917d820fb4f5080cc9a5128c3150d): perf score=2.188937
I20260812 06:19:47.621507 20296 maintenance_manager.cc:643] P 0cda5a9e75eb46e3bfa99f51db835acd: FlushDeltaMemStoresOp(405917d820fb4f5080cc9a5128c3150d) complete. Timing: real 0.012s	user 0.010s	sys 0.001s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4797,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:47.622062 20356 maintenance_manager.cc:419] P 0cda5a9e75eb46e3bfa99f51db835acd: Scheduling FlushMRSOp(405917d820fb4f5080cc9a5128c3150d): perf score=1.000000
I20260812 06:19:47.657737 20296 maintenance_manager.cc:643] P 0cda5a9e75eb46e3bfa99f51db835acd: FlushMRSOp(405917d820fb4f5080cc9a5128c3150d) complete. Timing: real 0.035s	user 0.027s	sys 0.006s Metrics: {"bytes_written":1275449,"cfile_init":1,"dirs.queue_time_us":51,"dirs.run_cpu_time_us":208,"dirs.run_wall_time_us":1390,"drs_written":1,"lbm_read_time_us":51,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1686,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":31}
I20260812 06:19:47.658428 20356 maintenance_manager.cc:419] P 0cda5a9e75eb46e3bfa99f51db835acd: Scheduling LogGCOp(405917d820fb4f5080cc9a5128c3150d): free 124710314 bytes of WAL
I20260812 06:19:47.658638 20296 log_reader.cc:385] T 405917d820fb4f5080cc9a5128c3150d: removed 12 log segments from log reader
I20260812 06:19:47.658680 20296 log.cc:1079] T 405917d820fb4f5080cc9a5128c3150d P 0cda5a9e75eb46e3bfa99f51db835acd: Deleting log segment in path: /tmp/dist-test-taskztgv1X/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515578771685-20007-0/minicluster-data/ts-0-root/wals/405917d820fb4f5080cc9a5128c3150d/wal-000000014 (ops 66-70)
I20260812 06:19:47.658712 20296 log.cc:1079] T 405917d820fb4f5080cc9a5128c3150d P 0cda5a9e75eb46e3bfa99f51db835acd: Deleting log segment in path: /tmp/dist-test-taskztgv1X/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515578771685-20007-0/minicluster-data/ts-0-root/wals/405917d820fb4f5080cc9a5128c3150d/wal-000000015 (ops 71-75)
I20260812 06:19:47.658732 20296 log.cc:1079] T 405917d820fb4f5080cc9a5128c3150d P 0cda5a9e75eb46e3bfa99f51db835acd: Deleting log segment in path: /tmp/dist-test-taskztgv1X/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515578771685-20007-0/minicluster-data/ts-0-root/wals/405917d820fb4f5080cc9a5128c3150d/wal-000000016 (ops 76-80)
I20260812 06:19:47.658752 20296 log.cc:1079] T 405917d820fb4f5080cc9a5128c3150d P 0cda5a9e75eb46e3bfa99f51db835acd: Deleting log segment in path: /tmp/dist-test-taskztgv1X/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515578771685-20007-0/minicluster-data/ts-0-root/wals/405917d820fb4f5080cc9a5128c3150d/wal-000000017 (ops 81-85)
I20260812 06:19:47.658771 20296 log.cc:1079] T 405917d820fb4f5080cc9a5128c3150d P 0cda5a9e75eb46e3bfa99f51db835acd: Deleting log segment in path: /tmp/dist-test-taskztgv1X/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515578771685-20007-0/minicluster-data/ts-0-root/wals/405917d820fb4f5080cc9a5128c3150d/wal-000000018 (ops 86-90)
I20260812 06:19:47.658842 20296 log.cc:1079] T 405917d820fb4f5080cc9a5128c3150d P 0cda5a9e75eb46e3bfa99f51db835acd: Deleting log segment in path: /tmp/dist-test-taskztgv1X/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515578771685-20007-0/minicluster-data/ts-0-root/wals/405917d820fb4f5080cc9a5128c3150d/wal-000000019 (ops 91-95)
I20260812 06:19:47.658892 20296 log.cc:1079] T 405917d820fb4f5080cc9a5128c3150d P 0cda5a9e75eb46e3bfa99f51db835acd: Deleting log segment in path: /tmp/dist-test-taskztgv1X/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515578771685-20007-0/minicluster-data/ts-0-root/wals/405917d820fb4f5080cc9a5128c3150d/wal-000000020 (ops 96-100)
I20260812 06:19:47.658923 20296 log.cc:1079] T 405917d820fb4f5080cc9a5128c3150d P 0cda5a9e75eb46e3bfa99f51db835acd: Deleting log segment in path: /tmp/dist-test-taskztgv1X/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515578771685-20007-0/minicluster-data/ts-0-root/wals/405917d820fb4f5080cc9a5128c3150d/wal-000000021 (ops 101-105)
I20260812 06:19:47.658943 20296 log.cc:1079] T 405917d820fb4f5080cc9a5128c3150d P 0cda5a9e75eb46e3bfa99f51db835acd: Deleting log segment in path: /tmp/dist-test-taskztgv1X/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515578771685-20007-0/minicluster-data/ts-0-root/wals/405917d820fb4f5080cc9a5128c3150d/wal-000000022 (ops 106-110)
I20260812 06:19:47.658963 20296 log.cc:1079] T 405917d820fb4f5080cc9a5128c3150d P 0cda5a9e75eb46e3bfa99f51db835acd: Deleting log segment in path: /tmp/dist-test-taskztgv1X/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515578771685-20007-0/minicluster-data/ts-0-root/wals/405917d820fb4f5080cc9a5128c3150d/wal-000000023 (ops 111-115)
I20260812 06:19:47.659005 20296 log.cc:1079] T 405917d820fb4f5080cc9a5128c3150d P 0cda5a9e75eb46e3bfa99f51db835acd: Deleting log segment in path: /tmp/dist-test-taskztgv1X/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515578771685-20007-0/minicluster-data/ts-0-root/wals/405917d820fb4f5080cc9a5128c3150d/wal-000000024 (ops 116-120)
I20260812 06:19:47.659040 20296 log.cc:1079] T 405917d820fb4f5080cc9a5128c3150d P 0cda5a9e75eb46e3bfa99f51db835acd: Deleting log segment in path: /tmp/dist-test-taskztgv1X/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515578771685-20007-0/minicluster-data/ts-0-root/wals/405917d820fb4f5080cc9a5128c3150d/wal-000000025 (ops 121-125)
I20260812 06:19:47.686262 20296 maintenance_manager.cc:643] P 0cda5a9e75eb46e3bfa99f51db835acd: LogGCOp(405917d820fb4f5080cc9a5128c3150d) complete. Timing: real 0.028s	user 0.000s	sys 0.025s Metrics: {}
I20260812 06:19:47.686766 20356 maintenance_manager.cc:419] P 0cda5a9e75eb46e3bfa99f51db835acd: Scheduling UndoDeltaBlockGCOp(405917d820fb4f5080cc9a5128c3150d): 482 bytes on disk
I20260812 06:19:47.687206 20296 maintenance_manager.cc:643] P 0cda5a9e75eb46e3bfa99f51db835acd: UndoDeltaBlockGCOp(405917d820fb4f5080cc9a5128c3150d) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":64,"lbm_reads_lt_1ms":4}
I20260812 06:19:47.687804 20356 maintenance_manager.cc:419] P 0cda5a9e75eb46e3bfa99f51db835acd: Scheduling FlushDeltaMemStoresOp(405917d820fb4f5080cc9a5128c3150d): perf score=6.157687
I20260812 06:19:47.717761 20296 maintenance_manager.cc:643] P 0cda5a9e75eb46e3bfa99f51db835acd: FlushDeltaMemStoresOp(405917d820fb4f5080cc9a5128c3150d) complete. Timing: real 0.030s	user 0.017s	sys 0.010s Metrics: {"bytes_written":8205077,"delete_count":0,"lbm_write_time_us":10088,"lbm_writes_lt_1ms":203,"reinsert_count":0,"update_count":1000}
I20260812 06:19:47.718525 20356 maintenance_manager.cc:419] P 0cda5a9e75eb46e3bfa99f51db835acd: Scheduling MajorDeltaCompactionOp(405917d820fb4f5080cc9a5128c3150d): perf score=1.000000
I20260812 06:19:47.939114 20296 maintenance_manager.cc:643] P 0cda5a9e75eb46e3bfa99f51db835acd: MajorDeltaCompactionOp(405917d820fb4f5080cc9a5128c3150d) complete. Timing: real 0.220s	user 0.141s	sys 0.076s 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":1801,"lbm_read_time_us":11996,"lbm_reads_lt_1ms":665,"lbm_write_time_us":38610,"lbm_writes_lt_1ms":643,"mutex_wait_us":651,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":7936,"thread_start_us":70,"threads_started":1,"update_count":3000}
I20260812 06:19:47.939736 20356 maintenance_manager.cc:419] P 0cda5a9e75eb46e3bfa99f51db835acd: Scheduling FlushDeltaMemStoresOp(405917d820fb4f5080cc9a5128c3150d): perf score=15.087375
I20260812 06:19:48.015901 20296 maintenance_manager.cc:643] P 0cda5a9e75eb46e3bfa99f51db835acd: FlushDeltaMemStoresOp(405917d820fb4f5080cc9a5128c3150d) complete. Timing: real 0.075s	user 0.044s	sys 0.020s Metrics: {"bytes_written":16820144,"delete_count":0,"lbm_write_time_us":24503,"lbm_writes_lt_1ms":413,"reinsert_count":0,"update_count":2050}
I20260812 06:19:48.016433 20356 maintenance_manager.cc:419] P 0cda5a9e75eb46e3bfa99f51db835acd: Scheduling FlushDeltaMemStoresOp(405917d820fb4f5080cc9a5128c3150d): perf score=6.157687
I20260812 06:19:48.042358 20296 maintenance_manager.cc:643] P 0cda5a9e75eb46e3bfa99f51db835acd: FlushDeltaMemStoresOp(405917d820fb4f5080cc9a5128c3150d) complete. Timing: real 0.026s	user 0.014s	sys 0.009s Metrics: {"bytes_written":7794836,"delete_count":0,"lbm_write_time_us":10543,"lbm_writes_lt_1ms":193,"reinsert_count":0,"update_count":950}
I20260812 06:19:48.043035 20356 maintenance_manager.cc:419] P 0cda5a9e75eb46e3bfa99f51db835acd: Scheduling MajorDeltaCompactionOp(405917d820fb4f5080cc9a5128c3150d): perf score=1.000000
I20260812 06:19:48.252063 20296 maintenance_manager.cc:643] P 0cda5a9e75eb46e3bfa99f51db835acd: MajorDeltaCompactionOp(405917d820fb4f5080cc9a5128c3150d) complete. Timing: real 0.209s	user 0.144s	sys 0.064s Metrics: {"cfile_cache_miss":632,"cfile_cache_miss_bytes":28877102,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":1483,"lbm_read_time_us":12855,"lbm_reads_lt_1ms":672,"lbm_write_time_us":35774,"lbm_writes_lt_1ms":643,"mutex_wait_us":530,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":19200,"update_count":3000}
I20260812 06:19:48.252770 20356 maintenance_manager.cc:419] P 0cda5a9e75eb46e3bfa99f51db835acd: Scheduling FlushDeltaMemStoresOp(405917d820fb4f5080cc9a5128c3150d): perf score=14.095187
I20260812 06:19:48.312707 20296 maintenance_manager.cc:643] P 0cda5a9e75eb46e3bfa99f51db835acd: FlushDeltaMemStoresOp(405917d820fb4f5080cc9a5128c3150d) complete. Timing: real 0.060s	user 0.019s	sys 0.032s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":22564,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:48.313397 20356 maintenance_manager.cc:419] P 0cda5a9e75eb46e3bfa99f51db835acd: Scheduling FlushDeltaMemStoresOp(405917d820fb4f5080cc9a5128c3150d): perf score=3.181125
I20260812 06:19:48.338861 20296 maintenance_manager.cc:643] P 0cda5a9e75eb46e3bfa99f51db835acd: FlushDeltaMemStoresOp(405917d820fb4f5080cc9a5128c3150d) complete. Timing: real 0.021s	user 0.009s	sys 0.003s Metrics: {"bytes_written":4512900,"delete_count":0,"lbm_write_time_us":7296,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":112,"reinsert_count":0,"update_count":550}
I20260812 06:19:48.339310 20356 maintenance_manager.cc:419] P 0cda5a9e75eb46e3bfa99f51db835acd: Scheduling FlushDeltaMemStoresOp(405917d820fb4f5080cc9a5128c3150d): perf score=2.188937
I20260812 06:19:48.351760 20296 maintenance_manager.cc:643] P 0cda5a9e75eb46e3bfa99f51db835acd: FlushDeltaMemStoresOp(405917d820fb4f5080cc9a5128c3150d) complete. Timing: real 0.012s	user 0.005s	sys 0.008s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":4640,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:19:48.352418 20356 maintenance_manager.cc:419] P 0cda5a9e75eb46e3bfa99f51db835acd: Scheduling MajorDeltaCompactionOp(405917d820fb4f5080cc9a5128c3150d): perf score=1.000000
I20260812 06:19:48.545910 20296 maintenance_manager.cc:643] P 0cda5a9e75eb46e3bfa99f51db835acd: MajorDeltaCompactionOp(405917d820fb4f5080cc9a5128c3150d) complete. Timing: real 0.193s	user 0.136s	sys 0.056s Metrics: {"cfile_cache_miss":633,"cfile_cache_miss_bytes":28877207,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":145,"lbm_read_time_us":13078,"lbm_reads_lt_1ms":673,"lbm_write_time_us":29649,"lbm_writes_lt_1ms":643,"mutex_wait_us":30,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":2304,"update_count":3000}
I20260812 06:19:48.546502 20356 maintenance_manager.cc:419] P 0cda5a9e75eb46e3bfa99f51db835acd: Scheduling FlushDeltaMemStoresOp(405917d820fb4f5080cc9a5128c3150d): perf score=14.095187
I20260812 06:19:48.614450 20296 maintenance_manager.cc:643] P 0cda5a9e75eb46e3bfa99f51db835acd: FlushDeltaMemStoresOp(405917d820fb4f5080cc9a5128c3150d) complete. Timing: real 0.067s	user 0.032s	sys 0.016s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":25513,"lbm_writes_1-10_ms":2,"lbm_writes_lt_1ms":401,"reinsert_count":0,"update_count":2000}
I20260812 06:19:48.614910 20356 maintenance_manager.cc:419] P 0cda5a9e75eb46e3bfa99f51db835acd: Scheduling FlushDeltaMemStoresOp(405917d820fb4f5080cc9a5128c3150d): perf score=2.188937
I20260812 06:19:48.630807 20296 maintenance_manager.cc:643] P 0cda5a9e75eb46e3bfa99f51db835acd: FlushDeltaMemStoresOp(405917d820fb4f5080cc9a5128c3150d) complete. Timing: real 0.016s	user 0.010s	sys 0.003s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6004,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:48.631965 20356 maintenance_manager.cc:419] P 0cda5a9e75eb46e3bfa99f51db835acd: Scheduling MajorDeltaCompactionOp(405917d820fb4f5080cc9a5128c3150d): perf score=1.000000
I20260812 06:19:48.824236 20296 maintenance_manager.cc:643] P 0cda5a9e75eb46e3bfa99f51db835acd: MajorDeltaCompactionOp(405917d820fb4f5080cc9a5128c3150d) complete. Timing: real 0.192s	user 0.122s	sys 0.064s 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":283,"lbm_read_time_us":12610,"lbm_reads_lt_1ms":572,"lbm_write_time_us":31404,"lbm_writes_lt_1ms":543,"mutex_wait_us":40,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":7168,"update_count":2500}
I20260812 06:19:48.824813 20356 maintenance_manager.cc:419] P 0cda5a9e75eb46e3bfa99f51db835acd: Scheduling FlushDeltaMemStoresOp(405917d820fb4f5080cc9a5128c3150d): perf score=14.095187
I20260812 06:19:48.893154 20296 maintenance_manager.cc:643] P 0cda5a9e75eb46e3bfa99f51db835acd: FlushDeltaMemStoresOp(405917d820fb4f5080cc9a5128c3150d) complete. Timing: real 0.068s	user 0.027s	sys 0.020s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":20635,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:48.893688 20356 maintenance_manager.cc:419] P 0cda5a9e75eb46e3bfa99f51db835acd: Scheduling FlushDeltaMemStoresOp(405917d820fb4f5080cc9a5128c3150d): perf score=2.188937
I20260812 06:19:48.913689 20296 maintenance_manager.cc:643] P 0cda5a9e75eb46e3bfa99f51db835acd: FlushDeltaMemStoresOp(405917d820fb4f5080cc9a5128c3150d) complete. Timing: real 0.020s	user 0.010s	sys 0.007s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":6821,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:48.914147 20356 maintenance_manager.cc:419] P 0cda5a9e75eb46e3bfa99f51db835acd: Scheduling MajorDeltaCompactionOp(405917d820fb4f5080cc9a5128c3150d): perf score=1.000000
I20260812 06:19:49.103569 20296 maintenance_manager.cc:643] P 0cda5a9e75eb46e3bfa99f51db835acd: MajorDeltaCompactionOp(405917d820fb4f5080cc9a5128c3150d) complete. Timing: real 0.189s	user 0.129s	sys 0.056s 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":805,"lbm_read_time_us":14018,"lbm_reads_lt_1ms":572,"lbm_write_time_us":32295,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":542,"mutex_wait_us":324,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":3712,"update_count":2500}
I20260812 06:19:49.104110 20356 maintenance_manager.cc:419] P 0cda5a9e75eb46e3bfa99f51db835acd: Scheduling FlushDeltaMemStoresOp(405917d820fb4f5080cc9a5128c3150d): perf score=14.095187
I20260812 06:19:49.178647 20296 maintenance_manager.cc:643] P 0cda5a9e75eb46e3bfa99f51db835acd: FlushDeltaMemStoresOp(405917d820fb4f5080cc9a5128c3150d) complete. Timing: real 0.071s	user 0.027s	sys 0.021s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":37161,"lbm_writes_10-100_ms":1,"lbm_writes_lt_1ms":402,"reinsert_count":0,"update_count":2000}
I20260812 06:19:49.179378 20356 maintenance_manager.cc:419] P 0cda5a9e75eb46e3bfa99f51db835acd: Scheduling FlushDeltaMemStoresOp(405917d820fb4f5080cc9a5128c3150d): perf score=2.188937
I20260812 06:19:49.194922 20296 maintenance_manager.cc:643] P 0cda5a9e75eb46e3bfa99f51db835acd: FlushDeltaMemStoresOp(405917d820fb4f5080cc9a5128c3150d) complete. Timing: real 0.015s	user 0.009s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6020,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:49.195473 20356 maintenance_manager.cc:419] P 0cda5a9e75eb46e3bfa99f51db835acd: Scheduling FlushMRSOp(405917d820fb4f5080cc9a5128c3150d): perf score=1.000000
I20260812 06:19:49.235737 20296 maintenance_manager.cc:643] P 0cda5a9e75eb46e3bfa99f51db835acd: FlushMRSOp(405917d820fb4f5080cc9a5128c3150d) complete. Timing: real 0.040s	user 0.031s	sys 0.001s Metrics: {"bytes_written":1193505,"cfile_init":1,"dirs.queue_time_us":51,"dirs.run_cpu_time_us":200,"dirs.run_wall_time_us":1284,"drs_written":1,"lbm_read_time_us":58,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1914,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":29}
I20260812 06:19:49.236429 20356 maintenance_manager.cc:419] P 0cda5a9e75eb46e3bfa99f51db835acd: Scheduling LogGCOp(405917d820fb4f5080cc9a5128c3150d): free 121006685 bytes of WAL
I20260812 06:19:49.236618 20296 log_reader.cc:385] T 405917d820fb4f5080cc9a5128c3150d: removed 12 log segments from log reader
I20260812 06:19:49.236656 20296 log.cc:1079] T 405917d820fb4f5080cc9a5128c3150d P 0cda5a9e75eb46e3bfa99f51db835acd: Deleting log segment in path: /tmp/dist-test-taskztgv1X/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515578771685-20007-0/minicluster-data/ts-0-root/wals/405917d820fb4f5080cc9a5128c3150d/wal-000000026 (ops 126-130)
I20260812 06:19:49.236692 20296 log.cc:1079] T 405917d820fb4f5080cc9a5128c3150d P 0cda5a9e75eb46e3bfa99f51db835acd: Deleting log segment in path: /tmp/dist-test-taskztgv1X/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515578771685-20007-0/minicluster-data/ts-0-root/wals/405917d820fb4f5080cc9a5128c3150d/wal-000000027 (ops 131-135)
I20260812 06:19:49.236755 20296 log.cc:1079] T 405917d820fb4f5080cc9a5128c3150d P 0cda5a9e75eb46e3bfa99f51db835acd: Deleting log segment in path: /tmp/dist-test-taskztgv1X/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515578771685-20007-0/minicluster-data/ts-0-root/wals/405917d820fb4f5080cc9a5128c3150d/wal-000000028 (ops 136-140)
I20260812 06:19:49.236788 20296 log.cc:1079] T 405917d820fb4f5080cc9a5128c3150d P 0cda5a9e75eb46e3bfa99f51db835acd: Deleting log segment in path: /tmp/dist-test-taskztgv1X/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515578771685-20007-0/minicluster-data/ts-0-root/wals/405917d820fb4f5080cc9a5128c3150d/wal-000000029 (ops 141-144)
I20260812 06:19:49.236814 20296 log.cc:1079] T 405917d820fb4f5080cc9a5128c3150d P 0cda5a9e75eb46e3bfa99f51db835acd: Deleting log segment in path: /tmp/dist-test-taskztgv1X/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515578771685-20007-0/minicluster-data/ts-0-root/wals/405917d820fb4f5080cc9a5128c3150d/wal-000000030 (ops 145-149)
I20260812 06:19:49.236843 20296 log.cc:1079] T 405917d820fb4f5080cc9a5128c3150d P 0cda5a9e75eb46e3bfa99f51db835acd: Deleting log segment in path: /tmp/dist-test-taskztgv1X/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515578771685-20007-0/minicluster-data/ts-0-root/wals/405917d820fb4f5080cc9a5128c3150d/wal-000000031 (ops 150-154)
I20260812 06:19:49.236899 20296 log.cc:1079] T 405917d820fb4f5080cc9a5128c3150d P 0cda5a9e75eb46e3bfa99f51db835acd: Deleting log segment in path: /tmp/dist-test-taskztgv1X/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515578771685-20007-0/minicluster-data/ts-0-root/wals/405917d820fb4f5080cc9a5128c3150d/wal-000000032 (ops 155-159)
I20260812 06:19:49.236934 20296 log.cc:1079] T 405917d820fb4f5080cc9a5128c3150d P 0cda5a9e75eb46e3bfa99f51db835acd: Deleting log segment in path: /tmp/dist-test-taskztgv1X/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515578771685-20007-0/minicluster-data/ts-0-root/wals/405917d820fb4f5080cc9a5128c3150d/wal-000000033 (ops 160-164)
I20260812 06:19:49.236992 20296 log.cc:1079] T 405917d820fb4f5080cc9a5128c3150d P 0cda5a9e75eb46e3bfa99f51db835acd: Deleting log segment in path: /tmp/dist-test-taskztgv1X/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515578771685-20007-0/minicluster-data/ts-0-root/wals/405917d820fb4f5080cc9a5128c3150d/wal-000000034 (ops 165-169)
I20260812 06:19:49.237027 20296 log.cc:1079] T 405917d820fb4f5080cc9a5128c3150d P 0cda5a9e75eb46e3bfa99f51db835acd: Deleting log segment in path: /tmp/dist-test-taskztgv1X/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515578771685-20007-0/minicluster-data/ts-0-root/wals/405917d820fb4f5080cc9a5128c3150d/wal-000000035 (ops 170-174)
I20260812 06:19:49.237080 20296 log.cc:1079] T 405917d820fb4f5080cc9a5128c3150d P 0cda5a9e75eb46e3bfa99f51db835acd: Deleting log segment in path: /tmp/dist-test-taskztgv1X/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515578771685-20007-0/minicluster-data/ts-0-root/wals/405917d820fb4f5080cc9a5128c3150d/wal-000000036 (ops 175-179)
I20260812 06:19:49.237113 20296 log.cc:1079] T 405917d820fb4f5080cc9a5128c3150d P 0cda5a9e75eb46e3bfa99f51db835acd: Deleting log segment in path: /tmp/dist-test-taskztgv1X/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515578771685-20007-0/minicluster-data/ts-0-root/wals/405917d820fb4f5080cc9a5128c3150d/wal-000000037 (ops 180-184)
I20260812 06:19:49.267200 20296 maintenance_manager.cc:643] P 0cda5a9e75eb46e3bfa99f51db835acd: LogGCOp(405917d820fb4f5080cc9a5128c3150d) complete. Timing: real 0.031s	user 0.002s	sys 0.020s Metrics: {}
I20260812 06:19:49.267700 20356 maintenance_manager.cc:419] P 0cda5a9e75eb46e3bfa99f51db835acd: Scheduling UndoDeltaBlockGCOp(405917d820fb4f5080cc9a5128c3150d): 463 bytes on disk
I20260812 06:19:49.268224 20296 maintenance_manager.cc:643] P 0cda5a9e75eb46e3bfa99f51db835acd: UndoDeltaBlockGCOp(405917d820fb4f5080cc9a5128c3150d) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":65,"lbm_reads_lt_1ms":4}
I20260812 06:19:49.272101 20356 maintenance_manager.cc:419] P 0cda5a9e75eb46e3bfa99f51db835acd: Scheduling FlushDeltaMemStoresOp(405917d820fb4f5080cc9a5128c3150d): perf score=3.181125
I20260812 06:19:49.289474 20296 maintenance_manager.cc:643] P 0cda5a9e75eb46e3bfa99f51db835acd: FlushDeltaMemStoresOp(405917d820fb4f5080cc9a5128c3150d) complete. Timing: real 0.017s	user 0.005s	sys 0.008s Metrics: {"bytes_written":4512900,"delete_count":0,"lbm_write_time_us":5708,"lbm_writes_lt_1ms":113,"reinsert_count":0,"update_count":550}
I20260812 06:19:49.290132 20356 maintenance_manager.cc:419] P 0cda5a9e75eb46e3bfa99f51db835acd: Scheduling FlushDeltaMemStoresOp(405917d820fb4f5080cc9a5128c3150d): perf score=2.188937
I20260812 06:19:49.304450 20296 maintenance_manager.cc:643] P 0cda5a9e75eb46e3bfa99f51db835acd: FlushDeltaMemStoresOp(405917d820fb4f5080cc9a5128c3150d) complete. Timing: real 0.014s	user 0.006s	sys 0.007s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":4617,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:19:49.304979 20356 maintenance_manager.cc:419] P 0cda5a9e75eb46e3bfa99f51db835acd: Scheduling MajorDeltaCompactionOp(405917d820fb4f5080cc9a5128c3150d): perf score=1.000000
I20260812 06:19:49.548338 20296 maintenance_manager.cc:643] P 0cda5a9e75eb46e3bfa99f51db835acd: MajorDeltaCompactionOp(405917d820fb4f5080cc9a5128c3150d) complete. Timing: real 0.243s	user 0.154s	sys 0.072s Metrics: {"cfile_cache_miss":734,"cfile_cache_miss_bytes":32979737,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":661,"lbm_read_time_us":19488,"lbm_reads_1-10_ms":1,"lbm_reads_lt_1ms":773,"lbm_write_time_us":41284,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":742,"mutex_wait_us":263,"peak_mem_usage":87969044,"reinsert_count":0,"spinlock_wait_cycles":2201856,"thread_start_us":75,"threads_started":1,"update_count":3500}
I20260812 06:19:49.548915 20356 maintenance_manager.cc:419] P 0cda5a9e75eb46e3bfa99f51db835acd: Scheduling FlushDeltaMemStoresOp(405917d820fb4f5080cc9a5128c3150d): perf score=18.063937
I20260812 06:19:49.604696 20007 heavy-update-compaction-itest.cc:229] Time spent updating: real 5.069s	user 1.803s	sys 0.143s
I20260812 06:19:49.609011 20296 maintenance_manager.cc:643] P 0cda5a9e75eb46e3bfa99f51db835acd: FlushDeltaMemStoresOp(405917d820fb4f5080cc9a5128c3150d) complete. Timing: real 0.060s	user 0.043s	sys 0.016s Metrics: {"bytes_written":20512320,"delete_count":0,"lbm_write_time_us":26568,"lbm_writes_lt_1ms":503,"reinsert_count":0,"update_count":2500}
I20260812 06:19:49.609525 20356 maintenance_manager.cc:419] P 0cda5a9e75eb46e3bfa99f51db835acd: Scheduling FlushDeltaMemStoresOp(405917d820fb4f5080cc9a5128c3150d): perf score=2.188937
I20260812 06:19:49.629794 20296 maintenance_manager.cc:643] P 0cda5a9e75eb46e3bfa99f51db835acd: FlushDeltaMemStoresOp(405917d820fb4f5080cc9a5128c3150d) complete. Timing: real 0.018s	user 0.007s	sys 0.008s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":8566,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":102,"reinsert_count":0,"spinlock_wait_cycles":3584,"update_count":500}
I20260812 06:19:49.630426 20356 maintenance_manager.cc:419] P 0cda5a9e75eb46e3bfa99f51db835acd: Scheduling MajorDeltaCompactionOp(405917d820fb4f5080cc9a5128c3150d): perf score=1.000000
I20260812 06:19:49.665341 20007 heavy-update-compaction-itest.cc:265] Time spent scanning: real 0.060s	user 0.001s	sys 0.000s
I20260812 06:19:49.665889 20007 tablet_server.cc:179] TabletServer@127.19.137.193:0 shutting down...
I20260812 06:19:49.777884 20296 maintenance_manager.cc:643] P 0cda5a9e75eb46e3bfa99f51db835acd: MajorDeltaCompactionOp(405917d820fb4f5080cc9a5128c3150d) complete. Timing: real 0.147s	user 0.098s	sys 0.043s Metrics: {"cfile_cache_hit":474,"cfile_cache_hit_bytes":19404889,"cfile_cache_miss":158,"cfile_cache_miss_bytes":9472217,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":627,"lbm_read_time_us":6577,"lbm_reads_1-10_ms":1,"lbm_reads_lt_1ms":189,"lbm_write_time_us":33730,"lbm_writes_1-10_ms":2,"lbm_writes_lt_1ms":641,"mutex_wait_us":43,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":32384,"update_count":3000}
I20260812 06:19:49.778504 20007 ts_tablet_manager.cc:1507] Shutting down tablet manager...
I20260812 06:19:49.778861 20007 tablet_replica.cc:333] T 405917d820fb4f5080cc9a5128c3150d P 0cda5a9e75eb46e3bfa99f51db835acd: stopping tablet replica
I20260812 06:19:49.778988 20007 raft_consensus.cc:2243] T 405917d820fb4f5080cc9a5128c3150d P 0cda5a9e75eb46e3bfa99f51db835acd [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:19:49.779152 20007 raft_consensus.cc:2272] T 405917d820fb4f5080cc9a5128c3150d P 0cda5a9e75eb46e3bfa99f51db835acd [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:19:49.782877 20007 tablet_server.cc:196] TabletServer@127.19.137.193:0 shutdown complete.
I20260812 06:19:49.830672 20007 master.cc:562] Master@127.19.137.254:44035 shutting down...
I20260812 06:19:49.834676 20007 raft_consensus.cc:2243] T 00000000000000000000000000000000 P 6f3d7f90ba8547a9bcccd584fec59f79 [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:19:49.834851 20007 raft_consensus.cc:2272] T 00000000000000000000000000000000 P 6f3d7f90ba8547a9bcccd584fec59f79 [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:19:49.834916 20007 tablet_replica.cc:333] T 00000000000000000000000000000000 P 6f3d7f90ba8547a9bcccd584fec59f79: stopping tablet replica
I20260812 06:19:49.847304 20007 master.cc:584] Master@127.19.137.254:44035 shutdown complete.
[       OK ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/1 (5572 ms)
[----------] 2 tests from EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy (11143 ms total)

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