[==========] 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:18:20.141870 24480 internal_mini_cluster.cc:156] Creating distributed mini masters. Addrs: 127.23.232.62:36507
I20260812 06:18:20.143474 24480 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:18:20.144240 24480 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:18:20.151589 24487 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:18:20.151609 24485 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:18:20.151757 24480 server_base.cc:1061] running on GCE node
W20260812 06:18:20.151883 24491 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:18:20.152572 24480 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:18:20.152693 24480 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:18:20.152724 24480 hybrid_clock.cc:648] HybridClock initialized: now 1786515500152722 us; error 0 us; skew 500 ppm
I20260812 06:18:20.155254 24480 webserver.cc:533] Webserver started at http://127.23.232.62:40617/ using document root <none> and password file <none>
I20260812 06:18:20.155953 24480 fs_manager.cc:362] Metadata directory not provided
I20260812 06:18:20.156039 24480 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:18:20.156261 24480 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:18:20.158186 24480 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskBdY18o/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515500127844-24480-0/minicluster-data/master-0-root/instance:
uuid: "5d806f682f2e4d0f98b429a8bd59111b"
format_stamp: "Formatted at 2026-08-12 06:18:20 on dist-test-slave-t7g5"
I20260812 06:18:20.163625 24480 fs_manager.cc:696] Time spent creating directory manager: real 0.005s	user 0.004s	sys 0.000s
I20260812 06:18:20.166494 24496 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:18:20.168073 24480 fs_manager.cc:730] Time spent opening block manager: real 0.003s	user 0.003s	sys 0.000s
I20260812 06:18:20.168217 24480 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskBdY18o/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515500127844-24480-0/minicluster-data/master-0-root
uuid: "5d806f682f2e4d0f98b429a8bd59111b"
format_stamp: "Formatted at 2026-08-12 06:18:20 on dist-test-slave-t7g5"
I20260812 06:18:20.168336 24480 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskBdY18o/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515500127844-24480-0/minicluster-data/master-0-root
metadata directory: /tmp/dist-test-taskBdY18o/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515500127844-24480-0/minicluster-data/master-0-root
1 data directories: /tmp/dist-test-taskBdY18o/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515500127844-24480-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:18:20.181282 24480 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:18:20.182240 24480 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:18:20.182437 24480 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:18:20.192642 24480 rpc_server.cc:307] RPC server started. Bound to: 127.23.232.62:36507
I20260812 06:18:20.192747 24584 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.23.232.62:36507 every 8 connection(s)
I20260812 06:18:20.196408 24585 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:18:20.205010 24585 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P 5d806f682f2e4d0f98b429a8bd59111b: Bootstrap starting.
I20260812 06:18:20.208453 24585 tablet_bootstrap.cc:654] T 00000000000000000000000000000000 P 5d806f682f2e4d0f98b429a8bd59111b: Neither blocks nor log segments found. Creating new log.
I20260812 06:18:20.209714 24585 log.cc:826] T 00000000000000000000000000000000 P 5d806f682f2e4d0f98b429a8bd59111b: Log is configured to *not* fsync() on all Append() calls
I20260812 06:18:20.212111 24585 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P 5d806f682f2e4d0f98b429a8bd59111b: No bootstrap required, opened a new log
I20260812 06:18:20.215430 24585 raft_consensus.cc:359] T 00000000000000000000000000000000 P 5d806f682f2e4d0f98b429a8bd59111b [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "5d806f682f2e4d0f98b429a8bd59111b" member_type: VOTER }
I20260812 06:18:20.215678 24585 raft_consensus.cc:385] T 00000000000000000000000000000000 P 5d806f682f2e4d0f98b429a8bd59111b [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:18:20.215762 24585 raft_consensus.cc:740] T 00000000000000000000000000000000 P 5d806f682f2e4d0f98b429a8bd59111b [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: 5d806f682f2e4d0f98b429a8bd59111b, State: Initialized, Role: FOLLOWER
I20260812 06:18:20.216477 24585 consensus_queue.cc:260] T 00000000000000000000000000000000 P 5d806f682f2e4d0f98b429a8bd59111b [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: "5d806f682f2e4d0f98b429a8bd59111b" member_type: VOTER }
I20260812 06:18:20.216660 24585 raft_consensus.cc:399] T 00000000000000000000000000000000 P 5d806f682f2e4d0f98b429a8bd59111b [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:18:20.216735 24585 raft_consensus.cc:493] T 00000000000000000000000000000000 P 5d806f682f2e4d0f98b429a8bd59111b [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:18:20.216863 24585 raft_consensus.cc:3060] T 00000000000000000000000000000000 P 5d806f682f2e4d0f98b429a8bd59111b [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:18:20.217840 24585 raft_consensus.cc:515] T 00000000000000000000000000000000 P 5d806f682f2e4d0f98b429a8bd59111b [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "5d806f682f2e4d0f98b429a8bd59111b" member_type: VOTER }
I20260812 06:18:20.218333 24585 leader_election.cc:304] T 00000000000000000000000000000000 P 5d806f682f2e4d0f98b429a8bd59111b [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: 5d806f682f2e4d0f98b429a8bd59111b; no voters: 
I20260812 06:18:20.218689 24585 leader_election.cc:290] T 00000000000000000000000000000000 P 5d806f682f2e4d0f98b429a8bd59111b [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:18:20.218892 24588 raft_consensus.cc:2804] T 00000000000000000000000000000000 P 5d806f682f2e4d0f98b429a8bd59111b [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:18:20.219159 24588 raft_consensus.cc:697] T 00000000000000000000000000000000 P 5d806f682f2e4d0f98b429a8bd59111b [term 1 LEADER]: Becoming Leader. State: Replica: 5d806f682f2e4d0f98b429a8bd59111b, State: Running, Role: LEADER
I20260812 06:18:20.219592 24588 consensus_queue.cc:237] T 00000000000000000000000000000000 P 5d806f682f2e4d0f98b429a8bd59111b [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: "5d806f682f2e4d0f98b429a8bd59111b" member_type: VOTER }
I20260812 06:18:20.219877 24585 sys_catalog.cc:565] T 00000000000000000000000000000000 P 5d806f682f2e4d0f98b429a8bd59111b [sys.catalog]: configured and running, proceeding with master startup.
I20260812 06:18:20.221554 24592 sys_catalog.cc:455] T 00000000000000000000000000000000 P 5d806f682f2e4d0f98b429a8bd59111b [sys.catalog]: SysCatalogTable state changed. Reason: RaftConsensus started. Latest consensus state: current_term: 1 leader_uuid: "5d806f682f2e4d0f98b429a8bd59111b" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "5d806f682f2e4d0f98b429a8bd59111b" member_type: VOTER } }
I20260812 06:18:20.221590 24593 sys_catalog.cc:455] T 00000000000000000000000000000000 P 5d806f682f2e4d0f98b429a8bd59111b [sys.catalog]: SysCatalogTable state changed. Reason: New leader 5d806f682f2e4d0f98b429a8bd59111b. Latest consensus state: current_term: 1 leader_uuid: "5d806f682f2e4d0f98b429a8bd59111b" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "5d806f682f2e4d0f98b429a8bd59111b" member_type: VOTER } }
I20260812 06:18:20.221750 24592 sys_catalog.cc:458] T 00000000000000000000000000000000 P 5d806f682f2e4d0f98b429a8bd59111b [sys.catalog]: This master's current role is: LEADER
I20260812 06:18:20.221751 24593 sys_catalog.cc:458] T 00000000000000000000000000000000 P 5d806f682f2e4d0f98b429a8bd59111b [sys.catalog]: This master's current role is: LEADER
I20260812 06:18:20.222190 24607 catalog_manager.cc:1511] Loading table and tablet metadata into memory...
I20260812 06:18:20.222335 24480 internal_mini_cluster.cc:184] Waiting to initialize catalog manager on master 0
I20260812 06:18:20.224625 24607 catalog_manager.cc:1520] Initializing Kudu cluster ID...
I20260812 06:18:20.229890 24607 catalog_manager.cc:1383] Generated new cluster ID: 0675aa63b32f4e86988510ba7a4dd64a
I20260812 06:18:20.230041 24607 catalog_manager.cc:1531] Initializing Kudu internal certificate authority...
I20260812 06:18:20.243105 24607 catalog_manager.cc:1406] Generated new certificate authority record
I20260812 06:18:20.244117 24607 catalog_manager.cc:1540] Loading token signing keys...
I20260812 06:18:20.255110 24607 catalog_manager.cc:6092] T 00000000000000000000000000000000 P 5d806f682f2e4d0f98b429a8bd59111b: Generated new TSK 0
I20260812 06:18:20.256310 24607 catalog_manager.cc:1550] Initializing in-progress tserver states...
I20260812 06:18:20.287693 24480 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:18:20.291026 24617 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:18:20.291257 24619 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:18:20.291345 24621 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:18:20.291970 24480 server_base.cc:1061] running on GCE node
I20260812 06:18:20.292202 24480 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:18:20.292263 24480 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:18:20.292286 24480 hybrid_clock.cc:648] HybridClock initialized: now 1786515500292286 us; error 0 us; skew 500 ppm
I20260812 06:18:20.293507 24480 webserver.cc:533] Webserver started at http://127.23.232.1:38929/ using document root <none> and password file <none>
I20260812 06:18:20.293735 24480 fs_manager.cc:362] Metadata directory not provided
I20260812 06:18:20.293802 24480 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:18:20.293882 24480 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:18:20.294359 24480 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskBdY18o/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515500127844-24480-0/minicluster-data/ts-0-root/instance:
uuid: "c44a6e4741794afdaa18c491fbb97dae"
format_stamp: "Formatted at 2026-08-12 06:18:20 on dist-test-slave-t7g5"
I20260812 06:18:20.296432 24480 fs_manager.cc:696] Time spent creating directory manager: real 0.002s	user 0.000s	sys 0.002s
I20260812 06:18:20.297861 24627 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:18:20.298238 24480 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.000s	sys 0.001s
I20260812 06:18:20.298326 24480 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskBdY18o/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515500127844-24480-0/minicluster-data/ts-0-root
uuid: "c44a6e4741794afdaa18c491fbb97dae"
format_stamp: "Formatted at 2026-08-12 06:18:20 on dist-test-slave-t7g5"
I20260812 06:18:20.298435 24480 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskBdY18o/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515500127844-24480-0/minicluster-data/ts-0-root
metadata directory: /tmp/dist-test-taskBdY18o/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515500127844-24480-0/minicluster-data/ts-0-root
1 data directories: /tmp/dist-test-taskBdY18o/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515500127844-24480-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:18:20.317385 24480 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:18:20.318177 24480 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:18:20.318830 24480 txn_system_client.cc:432] TxnSystemClient initialization is disabled...
I20260812 06:18:20.319921 24480 ts_tablet_manager.cc:585] Loaded tablet metadata (0 total tablets, 0 live tablets)
I20260812 06:18:20.319983 24480 ts_tablet_manager.cc:531] Time spent load tablet metadata: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:18:20.320041 24480 ts_tablet_manager.cc:616] Registered 0 tablets
I20260812 06:18:20.320075 24480 ts_tablet_manager.cc:595] Time spent register tablets: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:18:20.327293 24480 rpc_server.cc:307] RPC server started. Bound to: 127.23.232.1:35921
I20260812 06:18:20.327334 24721 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.23.232.1:35921 every 8 connection(s)
I20260812 06:18:20.343940 24722 heartbeater.cc:344] Connected to a master server at 127.23.232.62:36507
I20260812 06:18:20.344314 24722 heartbeater.cc:461] Registering TS with master...
I20260812 06:18:20.344955 24722 heartbeater.cc:507] Master 127.23.232.62:36507 requested a full tablet report, sending...
I20260812 06:18:20.346870 24526 ts_manager.cc:194] Registered new tserver with Master: c44a6e4741794afdaa18c491fbb97dae (127.23.232.1:35921)
I20260812 06:18:20.347349 24480 internal_mini_cluster.cc:371] 1 TS(s) registered with all masters after 0.019428015s
I20260812 06:18:20.348367 24526 master_service.cc:502] Signed X509 certificate for tserver {username='slave'} at 127.0.0.1:42080
I20260812 06:18:20.360412 24526 catalog_manager.cc:2283] Servicing CreateTable request from {username='slave'} at 127.0.0.1:42096:
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:18:20.380082 24670 tablet_service.cc:1511] Processing CreateTablet for tablet 90ce218d0e1b4136bb506370aeda7b45 (DEFAULT_TABLE table=heavy-update-compaction-test [id=5b4f888931b647a8bea09a6bdce241b4]), partition=
I20260812 06:18:20.380756 24670 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet 90ce218d0e1b4136bb506370aeda7b45. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:18:20.384081 24736 tablet_bootstrap.cc:492] T 90ce218d0e1b4136bb506370aeda7b45 P c44a6e4741794afdaa18c491fbb97dae: Bootstrap starting.
I20260812 06:18:20.385798 24736 tablet_bootstrap.cc:654] T 90ce218d0e1b4136bb506370aeda7b45 P c44a6e4741794afdaa18c491fbb97dae: Neither blocks nor log segments found. Creating new log.
I20260812 06:18:20.387353 24736 tablet_bootstrap.cc:492] T 90ce218d0e1b4136bb506370aeda7b45 P c44a6e4741794afdaa18c491fbb97dae: No bootstrap required, opened a new log
I20260812 06:18:20.387496 24736 ts_tablet_manager.cc:1403] T 90ce218d0e1b4136bb506370aeda7b45 P c44a6e4741794afdaa18c491fbb97dae: Time spent bootstrapping tablet: real 0.004s	user 0.000s	sys 0.003s
I20260812 06:18:20.388065 24736 raft_consensus.cc:359] T 90ce218d0e1b4136bb506370aeda7b45 P c44a6e4741794afdaa18c491fbb97dae [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "c44a6e4741794afdaa18c491fbb97dae" member_type: VOTER last_known_addr { host: "127.23.232.1" port: 35921 } }
I20260812 06:18:20.388212 24736 raft_consensus.cc:385] T 90ce218d0e1b4136bb506370aeda7b45 P c44a6e4741794afdaa18c491fbb97dae [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:18:20.388247 24736 raft_consensus.cc:740] T 90ce218d0e1b4136bb506370aeda7b45 P c44a6e4741794afdaa18c491fbb97dae [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: c44a6e4741794afdaa18c491fbb97dae, State: Initialized, Role: FOLLOWER
I20260812 06:18:20.388492 24736 consensus_queue.cc:260] T 90ce218d0e1b4136bb506370aeda7b45 P c44a6e4741794afdaa18c491fbb97dae [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: "c44a6e4741794afdaa18c491fbb97dae" member_type: VOTER last_known_addr { host: "127.23.232.1" port: 35921 } }
I20260812 06:18:20.388651 24736 raft_consensus.cc:399] T 90ce218d0e1b4136bb506370aeda7b45 P c44a6e4741794afdaa18c491fbb97dae [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:18:20.388710 24736 raft_consensus.cc:493] T 90ce218d0e1b4136bb506370aeda7b45 P c44a6e4741794afdaa18c491fbb97dae [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:18:20.388768 24736 raft_consensus.cc:3060] T 90ce218d0e1b4136bb506370aeda7b45 P c44a6e4741794afdaa18c491fbb97dae [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:18:20.389940 24736 raft_consensus.cc:515] T 90ce218d0e1b4136bb506370aeda7b45 P c44a6e4741794afdaa18c491fbb97dae [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "c44a6e4741794afdaa18c491fbb97dae" member_type: VOTER last_known_addr { host: "127.23.232.1" port: 35921 } }
I20260812 06:18:20.390110 24736 leader_election.cc:304] T 90ce218d0e1b4136bb506370aeda7b45 P c44a6e4741794afdaa18c491fbb97dae [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: c44a6e4741794afdaa18c491fbb97dae; no voters: 
I20260812 06:18:20.390534 24736 leader_election.cc:290] T 90ce218d0e1b4136bb506370aeda7b45 P c44a6e4741794afdaa18c491fbb97dae [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:18:20.390679 24738 raft_consensus.cc:2804] T 90ce218d0e1b4136bb506370aeda7b45 P c44a6e4741794afdaa18c491fbb97dae [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:18:20.390902 24736 ts_tablet_manager.cc:1434] T 90ce218d0e1b4136bb506370aeda7b45 P c44a6e4741794afdaa18c491fbb97dae: Time spent starting tablet: real 0.003s	user 0.002s	sys 0.002s
I20260812 06:18:20.390923 24738 raft_consensus.cc:697] T 90ce218d0e1b4136bb506370aeda7b45 P c44a6e4741794afdaa18c491fbb97dae [term 1 LEADER]: Becoming Leader. State: Replica: c44a6e4741794afdaa18c491fbb97dae, State: Running, Role: LEADER
I20260812 06:18:20.391134 24738 consensus_queue.cc:237] T 90ce218d0e1b4136bb506370aeda7b45 P c44a6e4741794afdaa18c491fbb97dae [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: "c44a6e4741794afdaa18c491fbb97dae" member_type: VOTER last_known_addr { host: "127.23.232.1" port: 35921 } }
I20260812 06:18:20.391395 24722 heartbeater.cc:499] Master 127.23.232.62:36507 was elected leader, sending a full tablet report...
I20260812 06:18:20.394822 24526 catalog_manager.cc:5719] T 90ce218d0e1b4136bb506370aeda7b45 P c44a6e4741794afdaa18c491fbb97dae reported cstate change: term changed from 0 to 1, leader changed from <none> to c44a6e4741794afdaa18c491fbb97dae (127.23.232.1). New cstate: current_term: 1 leader_uuid: "c44a6e4741794afdaa18c491fbb97dae" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "c44a6e4741794afdaa18c491fbb97dae" member_type: VOTER last_known_addr { host: "127.23.232.1" port: 35921 } health_report { overall_health: HEALTHY } } }
I20260812 06:18:20.470206 24480 heavy-update-compaction-itest.cc:215] Time spent inserting: real 0.067s	user 0.020s	sys 0.010s
I20260812 06:18:20.578753 24723 maintenance_manager.cc:419] P c44a6e4741794afdaa18c491fbb97dae: Scheduling FlushMRSOp(90ce218d0e1b4136bb506370aeda7b45): perf score=11.117440
I20260812 06:18:20.704850 24633 maintenance_manager.cc:643] P c44a6e4741794afdaa18c491fbb97dae: FlushMRSOp(90ce218d0e1b4136bb506370aeda7b45) complete. Timing: real 0.126s	user 0.096s	sys 0.024s Metrics: {"bytes_written":8205078,"cfile_init":1,"compiler_manager_pool.queue_time_us":253,"delete_count":0,"dirs.queue_time_us":416,"dirs.run_cpu_time_us":209,"dirs.run_wall_time_us":802,"drs_written":1,"lbm_read_time_us":86,"lbm_reads_lt_1ms":4,"lbm_write_time_us":25033,"lbm_writes_lt_1ms":467,"peak_mem_usage":0,"reinsert_count":0,"rows_written":103,"thread_start_us":131,"threads_started":1,"update_count":1000}
I20260812 06:18:20.706300 24723 maintenance_manager.cc:419] P c44a6e4741794afdaa18c491fbb97dae: Scheduling LogGCOp(90ce218d0e1b4136bb506370aeda7b45): free 8725963 bytes of WAL
I20260812 06:18:20.706633 24633 log_reader.cc:385] T 90ce218d0e1b4136bb506370aeda7b45: removed 1 log segments from log reader
I20260812 06:18:20.706699 24633 log.cc:1079] T 90ce218d0e1b4136bb506370aeda7b45 P c44a6e4741794afdaa18c491fbb97dae: Deleting log segment in path: /tmp/dist-test-taskBdY18o/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515500127844-24480-0/minicluster-data/ts-0-root/wals/90ce218d0e1b4136bb506370aeda7b45/wal-000000001 (ops 1-6)
I20260812 06:18:20.709157 24633 maintenance_manager.cc:643] P c44a6e4741794afdaa18c491fbb97dae: LogGCOp(90ce218d0e1b4136bb506370aeda7b45) complete. Timing: real 0.003s	user 0.000s	sys 0.000s Metrics: {}
I20260812 06:18:20.709686 24723 maintenance_manager.cc:419] P c44a6e4741794afdaa18c491fbb97dae: Scheduling UndoDeltaBlockGCOp(90ce218d0e1b4136bb506370aeda7b45): 8616791 bytes on disk
I20260812 06:18:20.710503 24633 maintenance_manager.cc:643] P c44a6e4741794afdaa18c491fbb97dae: UndoDeltaBlockGCOp(90ce218d0e1b4136bb506370aeda7b45) complete. Timing: real 0.001s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":89,"lbm_reads_lt_1ms":4}
I20260812 06:18:20.710983 24723 maintenance_manager.cc:419] P c44a6e4741794afdaa18c491fbb97dae: Scheduling FlushDeltaMemStoresOp(90ce218d0e1b4136bb506370aeda7b45): perf score=2.188937
I20260812 06:18:20.731489 24633 maintenance_manager.cc:643] P c44a6e4741794afdaa18c491fbb97dae: FlushDeltaMemStoresOp(90ce218d0e1b4136bb506370aeda7b45) complete. Timing: real 0.020s	user 0.009s	sys 0.004s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":5621,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:18:20.732052 24723 maintenance_manager.cc:419] P c44a6e4741794afdaa18c491fbb97dae: Scheduling MajorDeltaCompactionOp(90ce218d0e1b4136bb506370aeda7b45): perf score=1.000000
I20260812 06:18:20.854650 24633 maintenance_manager.cc:643] P c44a6e4741794afdaa18c491fbb97dae: MajorDeltaCompactionOp(90ce218d0e1b4136bb506370aeda7b45) complete. Timing: real 0.122s	user 0.096s	sys 0.024s Metrics: {"cfile_cache_miss":322,"cfile_cache_miss_bytes":16118646,"cfile_init":7,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":493,"lbm_read_time_us":7226,"lbm_reads_lt_1ms":350,"lbm_write_time_us":21862,"lbm_writes_lt_1ms":333,"peak_mem_usage":36812022,"reinsert_count":0,"thread_start_us":247,"threads_started":5,"update_count":1450}
I20260812 06:18:20.855208 24723 maintenance_manager.cc:419] P c44a6e4741794afdaa18c491fbb97dae: Scheduling FlushDeltaMemStoresOp(90ce218d0e1b4136bb506370aeda7b45): perf score=10.126437
I20260812 06:18:20.903281 24633 maintenance_manager.cc:643] P c44a6e4741794afdaa18c491fbb97dae: FlushDeltaMemStoresOp(90ce218d0e1b4136bb506370aeda7b45) complete. Timing: real 0.048s	user 0.026s	sys 0.008s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":15802,"lbm_writes_lt_1ms":303,"reinsert_count":0,"spinlock_wait_cycles":1920,"update_count":1500}
I20260812 06:18:20.903771 24723 maintenance_manager.cc:419] P c44a6e4741794afdaa18c491fbb97dae: Scheduling FlushDeltaMemStoresOp(90ce218d0e1b4136bb506370aeda7b45): perf score=2.188937
I20260812 06:18:20.913991 24633 maintenance_manager.cc:643] P c44a6e4741794afdaa18c491fbb97dae: FlushDeltaMemStoresOp(90ce218d0e1b4136bb506370aeda7b45) complete. Timing: real 0.010s	user 0.002s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3743,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:20.914539 24723 maintenance_manager.cc:419] P c44a6e4741794afdaa18c491fbb97dae: Scheduling MajorDeltaCompactionOp(90ce218d0e1b4136bb506370aeda7b45): perf score=1.000000
I20260812 06:18:21.063550 24633 maintenance_manager.cc:643] P c44a6e4741794afdaa18c491fbb97dae: MajorDeltaCompactionOp(90ce218d0e1b4136bb506370aeda7b45) complete. Timing: real 0.149s	user 0.098s	sys 0.051s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20631312,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":261,"lbm_read_time_us":11967,"lbm_reads_lt_1ms":472,"lbm_write_time_us":27012,"lbm_writes_lt_1ms":443,"mutex_wait_us":103,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":3456,"update_count":2000}
I20260812 06:18:21.064105 24723 maintenance_manager.cc:419] P c44a6e4741794afdaa18c491fbb97dae: Scheduling FlushDeltaMemStoresOp(90ce218d0e1b4136bb506370aeda7b45): perf score=10.126437
I20260812 06:18:21.113214 24633 maintenance_manager.cc:643] P c44a6e4741794afdaa18c491fbb97dae: FlushDeltaMemStoresOp(90ce218d0e1b4136bb506370aeda7b45) complete. Timing: real 0.049s	user 0.016s	sys 0.020s Metrics: {"bytes_written":12307491,"delete_count":0,"lbm_write_time_us":16565,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:18:21.113911 24723 maintenance_manager.cc:419] P c44a6e4741794afdaa18c491fbb97dae: Scheduling FlushDeltaMemStoresOp(90ce218d0e1b4136bb506370aeda7b45): perf score=2.188937
I20260812 06:18:21.133342 24633 maintenance_manager.cc:643] P c44a6e4741794afdaa18c491fbb97dae: FlushDeltaMemStoresOp(90ce218d0e1b4136bb506370aeda7b45) complete. Timing: real 0.019s	user 0.012s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4882,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:21.133973 24723 maintenance_manager.cc:419] P c44a6e4741794afdaa18c491fbb97dae: Scheduling MajorDeltaCompactionOp(90ce218d0e1b4136bb506370aeda7b45): perf score=1.000000
I20260812 06:18:21.287043 24633 maintenance_manager.cc:643] P c44a6e4741794afdaa18c491fbb97dae: MajorDeltaCompactionOp(90ce218d0e1b4136bb506370aeda7b45) complete. Timing: real 0.153s	user 0.114s	sys 0.037s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20631313,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":292,"lbm_read_time_us":11745,"lbm_reads_lt_1ms":472,"lbm_write_time_us":24795,"lbm_writes_lt_1ms":443,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":768,"update_count":2000}
I20260812 06:18:21.287648 24723 maintenance_manager.cc:419] P c44a6e4741794afdaa18c491fbb97dae: Scheduling FlushDeltaMemStoresOp(90ce218d0e1b4136bb506370aeda7b45): perf score=10.126437
I20260812 06:18:21.321089 24633 maintenance_manager.cc:643] P c44a6e4741794afdaa18c491fbb97dae: FlushDeltaMemStoresOp(90ce218d0e1b4136bb506370aeda7b45) complete. Timing: real 0.033s	user 0.019s	sys 0.009s Metrics: {"bytes_written":12307493,"delete_count":0,"lbm_write_time_us":13645,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:18:21.321677 24723 maintenance_manager.cc:419] P c44a6e4741794afdaa18c491fbb97dae: Scheduling MajorDeltaCompactionOp(90ce218d0e1b4136bb506370aeda7b45): perf score=1.000000
I20260812 06:18:21.424078 24633 maintenance_manager.cc:643] P c44a6e4741794afdaa18c491fbb97dae: MajorDeltaCompactionOp(90ce218d0e1b4136bb506370aeda7b45) complete. Timing: real 0.102s	user 0.068s	sys 0.029s Metrics: {"cfile_cache_miss":331,"cfile_cache_miss_bytes":16528784,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":1,"delta_iterators_relevant":1,"dirs.queue_time_us":839,"lbm_read_time_us":5998,"lbm_reads_lt_1ms":363,"lbm_write_time_us":18879,"lbm_writes_lt_1ms":343,"mutex_wait_us":45,"peak_mem_usage":38262756,"reinsert_count":0,"spinlock_wait_cycles":50176,"update_count":1500}
I20260812 06:18:21.424583 24723 maintenance_manager.cc:419] P c44a6e4741794afdaa18c491fbb97dae: Scheduling FlushDeltaMemStoresOp(90ce218d0e1b4136bb506370aeda7b45): perf score=10.126437
I20260812 06:18:21.458489 24633 maintenance_manager.cc:643] P c44a6e4741794afdaa18c491fbb97dae: FlushDeltaMemStoresOp(90ce218d0e1b4136bb506370aeda7b45) complete. Timing: real 0.034s	user 0.026s	sys 0.007s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":14012,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:18:21.459215 24723 maintenance_manager.cc:419] P c44a6e4741794afdaa18c491fbb97dae: Scheduling MajorDeltaCompactionOp(90ce218d0e1b4136bb506370aeda7b45): perf score=1.000000
I20260812 06:18:21.584560 24633 maintenance_manager.cc:643] P c44a6e4741794afdaa18c491fbb97dae: MajorDeltaCompactionOp(90ce218d0e1b4136bb506370aeda7b45) complete. Timing: real 0.125s	user 0.088s	sys 0.036s Metrics: {"cfile_cache_miss":331,"cfile_cache_miss_bytes":16528781,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":1,"delta_iterators_relevant":1,"dirs.queue_time_us":885,"lbm_read_time_us":9434,"lbm_reads_lt_1ms":367,"lbm_write_time_us":22514,"lbm_writes_lt_1ms":343,"mutex_wait_us":299,"peak_mem_usage":38262756,"reinsert_count":0,"spinlock_wait_cycles":5632,"update_count":1500}
I20260812 06:18:21.585121 24723 maintenance_manager.cc:419] P c44a6e4741794afdaa18c491fbb97dae: Scheduling FlushDeltaMemStoresOp(90ce218d0e1b4136bb506370aeda7b45): perf score=10.126437
I20260812 06:18:21.635493 24633 maintenance_manager.cc:643] P c44a6e4741794afdaa18c491fbb97dae: FlushDeltaMemStoresOp(90ce218d0e1b4136bb506370aeda7b45) complete. Timing: real 0.050s	user 0.029s	sys 0.012s Metrics: {"bytes_written":12307489,"delete_count":0,"lbm_write_time_us":18662,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:18:21.635977 24723 maintenance_manager.cc:419] P c44a6e4741794afdaa18c491fbb97dae: Scheduling FlushDeltaMemStoresOp(90ce218d0e1b4136bb506370aeda7b45): perf score=2.188937
I20260812 06:18:21.648202 24633 maintenance_manager.cc:643] P c44a6e4741794afdaa18c491fbb97dae: FlushDeltaMemStoresOp(90ce218d0e1b4136bb506370aeda7b45) complete. Timing: real 0.012s	user 0.005s	sys 0.004s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4333,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:21.648983 24723 maintenance_manager.cc:419] P c44a6e4741794afdaa18c491fbb97dae: Scheduling MajorDeltaCompactionOp(90ce218d0e1b4136bb506370aeda7b45): perf score=1.000000
I20260812 06:18:21.792232 24633 maintenance_manager.cc:643] P c44a6e4741794afdaa18c491fbb97dae: MajorDeltaCompactionOp(90ce218d0e1b4136bb506370aeda7b45) complete. Timing: real 0.143s	user 0.105s	sys 0.027s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20631310,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":357,"lbm_read_time_us":8982,"lbm_reads_lt_1ms":472,"lbm_write_time_us":26769,"lbm_writes_lt_1ms":443,"mutex_wait_us":36,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":158976,"update_count":2000}
I20260812 06:18:21.792871 24723 maintenance_manager.cc:419] P c44a6e4741794afdaa18c491fbb97dae: Scheduling FlushDeltaMemStoresOp(90ce218d0e1b4136bb506370aeda7b45): perf score=10.126437
I20260812 06:18:21.842495 24633 maintenance_manager.cc:643] P c44a6e4741794afdaa18c491fbb97dae: FlushDeltaMemStoresOp(90ce218d0e1b4136bb506370aeda7b45) complete. Timing: real 0.049s	user 0.026s	sys 0.012s Metrics: {"bytes_written":12307489,"delete_count":0,"lbm_write_time_us":16655,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:18:21.843077 24723 maintenance_manager.cc:419] P c44a6e4741794afdaa18c491fbb97dae: Scheduling FlushDeltaMemStoresOp(90ce218d0e1b4136bb506370aeda7b45): perf score=2.188937
I20260812 06:18:21.853575 24633 maintenance_manager.cc:643] P c44a6e4741794afdaa18c491fbb97dae: FlushDeltaMemStoresOp(90ce218d0e1b4136bb506370aeda7b45) complete. Timing: real 0.010s	user 0.005s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3830,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:21.854218 24723 maintenance_manager.cc:419] P c44a6e4741794afdaa18c491fbb97dae: Scheduling MajorDeltaCompactionOp(90ce218d0e1b4136bb506370aeda7b45): perf score=1.000000
I20260812 06:18:21.977531 24633 maintenance_manager.cc:643] P c44a6e4741794afdaa18c491fbb97dae: MajorDeltaCompactionOp(90ce218d0e1b4136bb506370aeda7b45) complete. Timing: real 0.123s	user 0.090s	sys 0.032s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20631311,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":1500,"lbm_read_time_us":9534,"lbm_reads_lt_1ms":472,"lbm_write_time_us":23663,"lbm_writes_lt_1ms":443,"mutex_wait_us":460,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":3456,"update_count":2000}
I20260812 06:18:21.978446 24723 maintenance_manager.cc:419] P c44a6e4741794afdaa18c491fbb97dae: Scheduling FlushDeltaMemStoresOp(90ce218d0e1b4136bb506370aeda7b45): perf score=10.126437
I20260812 06:18:22.024472 24633 maintenance_manager.cc:643] P c44a6e4741794afdaa18c491fbb97dae: FlushDeltaMemStoresOp(90ce218d0e1b4136bb506370aeda7b45) complete. Timing: real 0.046s	user 0.022s	sys 0.011s Metrics: {"bytes_written":12307492,"delete_count":0,"lbm_write_time_us":15944,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:18:22.025154 24723 maintenance_manager.cc:419] P c44a6e4741794afdaa18c491fbb97dae: Scheduling FlushDeltaMemStoresOp(90ce218d0e1b4136bb506370aeda7b45): perf score=2.188937
I20260812 06:18:22.043221 24633 maintenance_manager.cc:643] P c44a6e4741794afdaa18c491fbb97dae: FlushDeltaMemStoresOp(90ce218d0e1b4136bb506370aeda7b45) complete. Timing: real 0.018s	user 0.010s	sys 0.005s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5838,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:22.044176 24723 maintenance_manager.cc:419] P c44a6e4741794afdaa18c491fbb97dae: Scheduling FlushMRSOp(90ce218d0e1b4136bb506370aeda7b45): perf score=1.000000
I20260812 06:18:22.073185 24633 maintenance_manager.cc:643] P c44a6e4741794afdaa18c491fbb97dae: FlushMRSOp(90ce218d0e1b4136bb506370aeda7b45) complete. Timing: real 0.029s	user 0.026s	sys 0.000s Metrics: {"bytes_written":1193504,"cfile_init":1,"dirs.queue_time_us":63,"dirs.run_cpu_time_us":228,"dirs.run_wall_time_us":1410,"drs_written":1,"lbm_read_time_us":44,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1394,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":29}
I20260812 06:18:22.074173 24723 maintenance_manager.cc:419] P c44a6e4741794afdaa18c491fbb97dae: Scheduling LogGCOp(90ce218d0e1b4136bb506370aeda7b45): free 124257231 bytes of WAL
I20260812 06:18:22.074434 24633 log_reader.cc:385] T 90ce218d0e1b4136bb506370aeda7b45: removed 12 log segments from log reader
I20260812 06:18:22.074487 24633 log.cc:1079] T 90ce218d0e1b4136bb506370aeda7b45 P c44a6e4741794afdaa18c491fbb97dae: Deleting log segment in path: /tmp/dist-test-taskBdY18o/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515500127844-24480-0/minicluster-data/ts-0-root/wals/90ce218d0e1b4136bb506370aeda7b45/wal-000000002 (ops 7-11)
I20260812 06:18:22.074530 24633 log.cc:1079] T 90ce218d0e1b4136bb506370aeda7b45 P c44a6e4741794afdaa18c491fbb97dae: Deleting log segment in path: /tmp/dist-test-taskBdY18o/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515500127844-24480-0/minicluster-data/ts-0-root/wals/90ce218d0e1b4136bb506370aeda7b45/wal-000000003 (ops 12-16)
I20260812 06:18:22.074564 24633 log.cc:1079] T 90ce218d0e1b4136bb506370aeda7b45 P c44a6e4741794afdaa18c491fbb97dae: Deleting log segment in path: /tmp/dist-test-taskBdY18o/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515500127844-24480-0/minicluster-data/ts-0-root/wals/90ce218d0e1b4136bb506370aeda7b45/wal-000000004 (ops 17-21)
I20260812 06:18:22.074597 24633 log.cc:1079] T 90ce218d0e1b4136bb506370aeda7b45 P c44a6e4741794afdaa18c491fbb97dae: Deleting log segment in path: /tmp/dist-test-taskBdY18o/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515500127844-24480-0/minicluster-data/ts-0-root/wals/90ce218d0e1b4136bb506370aeda7b45/wal-000000005 (ops 22-26)
I20260812 06:18:22.074628 24633 log.cc:1079] T 90ce218d0e1b4136bb506370aeda7b45 P c44a6e4741794afdaa18c491fbb97dae: Deleting log segment in path: /tmp/dist-test-taskBdY18o/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515500127844-24480-0/minicluster-data/ts-0-root/wals/90ce218d0e1b4136bb506370aeda7b45/wal-000000006 (ops 27-30)
I20260812 06:18:22.074659 24633 log.cc:1079] T 90ce218d0e1b4136bb506370aeda7b45 P c44a6e4741794afdaa18c491fbb97dae: Deleting log segment in path: /tmp/dist-test-taskBdY18o/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515500127844-24480-0/minicluster-data/ts-0-root/wals/90ce218d0e1b4136bb506370aeda7b45/wal-000000007 (ops 31-35)
I20260812 06:18:22.074893 24633 log.cc:1079] T 90ce218d0e1b4136bb506370aeda7b45 P c44a6e4741794afdaa18c491fbb97dae: Deleting log segment in path: /tmp/dist-test-taskBdY18o/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515500127844-24480-0/minicluster-data/ts-0-root/wals/90ce218d0e1b4136bb506370aeda7b45/wal-000000008 (ops 36-40)
I20260812 06:18:22.074975 24633 log.cc:1079] T 90ce218d0e1b4136bb506370aeda7b45 P c44a6e4741794afdaa18c491fbb97dae: Deleting log segment in path: /tmp/dist-test-taskBdY18o/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515500127844-24480-0/minicluster-data/ts-0-root/wals/90ce218d0e1b4136bb506370aeda7b45/wal-000000009 (ops 41-45)
I20260812 06:18:22.075006 24633 log.cc:1079] T 90ce218d0e1b4136bb506370aeda7b45 P c44a6e4741794afdaa18c491fbb97dae: Deleting log segment in path: /tmp/dist-test-taskBdY18o/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515500127844-24480-0/minicluster-data/ts-0-root/wals/90ce218d0e1b4136bb506370aeda7b45/wal-000000010 (ops 46-50)
I20260812 06:18:22.075038 24633 log.cc:1079] T 90ce218d0e1b4136bb506370aeda7b45 P c44a6e4741794afdaa18c491fbb97dae: Deleting log segment in path: /tmp/dist-test-taskBdY18o/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515500127844-24480-0/minicluster-data/ts-0-root/wals/90ce218d0e1b4136bb506370aeda7b45/wal-000000011 (ops 51-55)
I20260812 06:18:22.075069 24633 log.cc:1079] T 90ce218d0e1b4136bb506370aeda7b45 P c44a6e4741794afdaa18c491fbb97dae: Deleting log segment in path: /tmp/dist-test-taskBdY18o/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515500127844-24480-0/minicluster-data/ts-0-root/wals/90ce218d0e1b4136bb506370aeda7b45/wal-000000012 (ops 56-60)
I20260812 06:18:22.075102 24633 log.cc:1079] T 90ce218d0e1b4136bb506370aeda7b45 P c44a6e4741794afdaa18c491fbb97dae: Deleting log segment in path: /tmp/dist-test-taskBdY18o/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515500127844-24480-0/minicluster-data/ts-0-root/wals/90ce218d0e1b4136bb506370aeda7b45/wal-000000013 (ops 61-65)
I20260812 06:18:22.103469 24633 maintenance_manager.cc:643] P c44a6e4741794afdaa18c491fbb97dae: LogGCOp(90ce218d0e1b4136bb506370aeda7b45) complete. Timing: real 0.029s	user 0.003s	sys 0.024s Metrics: {}
I20260812 06:18:22.104028 24723 maintenance_manager.cc:419] P c44a6e4741794afdaa18c491fbb97dae: Scheduling FlushDeltaMemStoresOp(90ce218d0e1b4136bb506370aeda7b45): perf score=3.181125
I20260812 06:18:22.121479 24633 maintenance_manager.cc:643] P c44a6e4741794afdaa18c491fbb97dae: FlushDeltaMemStoresOp(90ce218d0e1b4136bb506370aeda7b45) complete. Timing: real 0.017s	user 0.008s	sys 0.008s Metrics: {"bytes_written":5169287,"delete_count":0,"lbm_write_time_us":7035,"lbm_writes_lt_1ms":129,"reinsert_count":0,"update_count":630}
I20260812 06:18:22.121974 24723 maintenance_manager.cc:419] P c44a6e4741794afdaa18c491fbb97dae: Scheduling FlushDeltaMemStoresOp(90ce218d0e1b4136bb506370aeda7b45): perf score=1.196750
I20260812 06:18:22.131209 24633 maintenance_manager.cc:643] P c44a6e4741794afdaa18c491fbb97dae: FlushDeltaMemStoresOp(90ce218d0e1b4136bb506370aeda7b45) complete. Timing: real 0.009s	user 0.001s	sys 0.006s Metrics: {"bytes_written":3036005,"delete_count":0,"lbm_write_time_us":2855,"lbm_writes_lt_1ms":77,"reinsert_count":0,"update_count":370}
I20260812 06:18:22.131780 24723 maintenance_manager.cc:419] P c44a6e4741794afdaa18c491fbb97dae: Scheduling UndoDeltaBlockGCOp(90ce218d0e1b4136bb506370aeda7b45): 463 bytes on disk
I20260812 06:18:22.132423 24633 maintenance_manager.cc:643] P c44a6e4741794afdaa18c491fbb97dae: UndoDeltaBlockGCOp(90ce218d0e1b4136bb506370aeda7b45) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":82,"lbm_reads_lt_1ms":4}
I20260812 06:18:22.132978 24723 maintenance_manager.cc:419] P c44a6e4741794afdaa18c491fbb97dae: Scheduling MajorDeltaCompactionOp(90ce218d0e1b4136bb506370aeda7b45): perf score=1.000000
I20260812 06:18:22.336369 24633 maintenance_manager.cc:643] P c44a6e4741794afdaa18c491fbb97dae: MajorDeltaCompactionOp(90ce218d0e1b4136bb506370aeda7b45) complete. Timing: real 0.203s	user 0.156s	sys 0.040s Metrics: {"cfile_cache_miss":634,"cfile_cache_miss_bytes":28836350,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":1588,"lbm_read_time_us":14328,"lbm_reads_lt_1ms":674,"lbm_write_time_us":36945,"lbm_writes_lt_1ms":643,"mutex_wait_us":69,"peak_mem_usage":75542472,"reinsert_count":0,"thread_start_us":115,"threads_started":1,"update_count":3000}
I20260812 06:18:22.337106 24723 maintenance_manager.cc:419] P c44a6e4741794afdaa18c491fbb97dae: Scheduling FlushDeltaMemStoresOp(90ce218d0e1b4136bb506370aeda7b45): perf score=14.095187
I20260812 06:18:22.396562 24633 maintenance_manager.cc:643] P c44a6e4741794afdaa18c491fbb97dae: FlushDeltaMemStoresOp(90ce218d0e1b4136bb506370aeda7b45) complete. Timing: real 0.059s	user 0.048s	sys 0.008s Metrics: {"bytes_written":16409897,"delete_count":0,"lbm_write_time_us":26645,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:18:22.397190 24723 maintenance_manager.cc:419] P c44a6e4741794afdaa18c491fbb97dae: Scheduling FlushDeltaMemStoresOp(90ce218d0e1b4136bb506370aeda7b45): perf score=2.188937
I20260812 06:18:22.410532 24633 maintenance_manager.cc:643] P c44a6e4741794afdaa18c491fbb97dae: FlushDeltaMemStoresOp(90ce218d0e1b4136bb506370aeda7b45) complete. Timing: real 0.013s	user 0.008s	sys 0.004s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":5029,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:22.411072 24723 maintenance_manager.cc:419] P c44a6e4741794afdaa18c491fbb97dae: Scheduling MajorDeltaCompactionOp(90ce218d0e1b4136bb506370aeda7b45): perf score=1.000000
I20260812 06:18:22.580665 24633 maintenance_manager.cc:643] P c44a6e4741794afdaa18c491fbb97dae: MajorDeltaCompactionOp(90ce218d0e1b4136bb506370aeda7b45) complete. Timing: real 0.169s	user 0.121s	sys 0.043s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24733718,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":1060,"lbm_read_time_us":10145,"lbm_reads_lt_1ms":572,"lbm_write_time_us":32587,"lbm_writes_lt_1ms":543,"peak_mem_usage":63115900,"reinsert_count":0,"update_count":2500}
I20260812 06:18:22.581333 24723 maintenance_manager.cc:419] P c44a6e4741794afdaa18c491fbb97dae: Scheduling FlushDeltaMemStoresOp(90ce218d0e1b4136bb506370aeda7b45): perf score=12.110812
I20260812 06:18:22.628397 24633 maintenance_manager.cc:643] P c44a6e4741794afdaa18c491fbb97dae: FlushDeltaMemStoresOp(90ce218d0e1b4136bb506370aeda7b45) complete. Timing: real 0.047s	user 0.020s	sys 0.024s Metrics: {"bytes_written":13866409,"delete_count":0,"lbm_write_time_us":22941,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":340,"reinsert_count":0,"update_count":1690}
I20260812 06:18:22.629055 24723 maintenance_manager.cc:419] P c44a6e4741794afdaa18c491fbb97dae: Scheduling FlushDeltaMemStoresOp(90ce218d0e1b4136bb506370aeda7b45): perf score=1.196750
I20260812 06:18:22.645924 24633 maintenance_manager.cc:643] P c44a6e4741794afdaa18c491fbb97dae: FlushDeltaMemStoresOp(90ce218d0e1b4136bb506370aeda7b45) complete. Timing: real 0.017s	user 0.009s	sys 0.000s Metrics: {"bytes_written":2953959,"delete_count":0,"lbm_write_time_us":2756,"lbm_writes_lt_1ms":75,"reinsert_count":0,"update_count":360}
I20260812 06:18:22.646562 24723 maintenance_manager.cc:419] P c44a6e4741794afdaa18c491fbb97dae: Scheduling FlushDeltaMemStoresOp(90ce218d0e1b4136bb506370aeda7b45): perf score=2.188937
I20260812 06:18:22.657430 24633 maintenance_manager.cc:643] P c44a6e4741794afdaa18c491fbb97dae: FlushDeltaMemStoresOp(90ce218d0e1b4136bb506370aeda7b45) complete. Timing: real 0.011s	user 0.005s	sys 0.003s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3569,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:18:22.658294 24723 maintenance_manager.cc:419] P c44a6e4741794afdaa18c491fbb97dae: Scheduling MajorDeltaCompactionOp(90ce218d0e1b4136bb506370aeda7b45): perf score=1.000000
I20260812 06:18:22.858902 24633 maintenance_manager.cc:643] P c44a6e4741794afdaa18c491fbb97dae: MajorDeltaCompactionOp(90ce218d0e1b4136bb506370aeda7b45) complete. Timing: real 0.200s	user 0.127s	sys 0.065s Metrics: {"cfile_cache_miss":533,"cfile_cache_miss_bytes":24733808,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":742,"lbm_read_time_us":14373,"lbm_reads_lt_1ms":573,"lbm_write_time_us":34043,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":542,"mutex_wait_us":43,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":4736,"update_count":2500}
I20260812 06:18:22.859539 24723 maintenance_manager.cc:419] P c44a6e4741794afdaa18c491fbb97dae: Scheduling FlushDeltaMemStoresOp(90ce218d0e1b4136bb506370aeda7b45): perf score=14.095187
I20260812 06:18:22.923568 24633 maintenance_manager.cc:643] P c44a6e4741794afdaa18c491fbb97dae: FlushDeltaMemStoresOp(90ce218d0e1b4136bb506370aeda7b45) complete. Timing: real 0.064s	user 0.030s	sys 0.020s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":23332,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":402,"reinsert_count":0,"update_count":2000}
I20260812 06:18:22.924178 24723 maintenance_manager.cc:419] P c44a6e4741794afdaa18c491fbb97dae: Scheduling FlushDeltaMemStoresOp(90ce218d0e1b4136bb506370aeda7b45): perf score=2.188937
I20260812 06:18:22.942332 24633 maintenance_manager.cc:643] P c44a6e4741794afdaa18c491fbb97dae: FlushDeltaMemStoresOp(90ce218d0e1b4136bb506370aeda7b45) complete. Timing: real 0.018s	user 0.017s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6243,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:22.943003 24723 maintenance_manager.cc:419] P c44a6e4741794afdaa18c491fbb97dae: Scheduling MajorDeltaCompactionOp(90ce218d0e1b4136bb506370aeda7b45): perf score=1.000000
I20260812 06:18:23.134071 24633 maintenance_manager.cc:643] P c44a6e4741794afdaa18c491fbb97dae: MajorDeltaCompactionOp(90ce218d0e1b4136bb506370aeda7b45) complete. Timing: real 0.191s	user 0.149s	sys 0.036s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24733723,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":1852,"lbm_read_time_us":14263,"lbm_reads_lt_1ms":572,"lbm_write_time_us":32673,"lbm_writes_lt_1ms":543,"mutex_wait_us":403,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":13440,"update_count":2500}
I20260812 06:18:23.134745 24723 maintenance_manager.cc:419] P c44a6e4741794afdaa18c491fbb97dae: Scheduling FlushDeltaMemStoresOp(90ce218d0e1b4136bb506370aeda7b45): perf score=11.118625
I20260812 06:18:23.193243 24633 maintenance_manager.cc:643] P c44a6e4741794afdaa18c491fbb97dae: FlushDeltaMemStoresOp(90ce218d0e1b4136bb506370aeda7b45) complete. Timing: real 0.058s	user 0.030s	sys 0.023s Metrics: {"bytes_written":12717736,"delete_count":0,"lbm_write_time_us":25047,"lbm_writes_1-10_ms":3,"lbm_writes_lt_1ms":310,"reinsert_count":0,"update_count":1550}
I20260812 06:18:23.193872 24723 maintenance_manager.cc:419] P c44a6e4741794afdaa18c491fbb97dae: Scheduling FlushDeltaMemStoresOp(90ce218d0e1b4136bb506370aeda7b45): perf score=3.181125
I20260812 06:18:23.207616 24633 maintenance_manager.cc:643] P c44a6e4741794afdaa18c491fbb97dae: FlushDeltaMemStoresOp(90ce218d0e1b4136bb506370aeda7b45) complete. Timing: real 0.014s	user 0.010s	sys 0.001s Metrics: {"bytes_written":4348809,"delete_count":0,"lbm_write_time_us":4998,"lbm_writes_lt_1ms":109,"reinsert_count":0,"update_count":530}
I20260812 06:18:23.208088 24723 maintenance_manager.cc:419] P c44a6e4741794afdaa18c491fbb97dae: Scheduling FlushDeltaMemStoresOp(90ce218d0e1b4136bb506370aeda7b45): perf score=2.188937
I20260812 06:18:23.219120 24633 maintenance_manager.cc:643] P c44a6e4741794afdaa18c491fbb97dae: FlushDeltaMemStoresOp(90ce218d0e1b4136bb506370aeda7b45) complete. Timing: real 0.011s	user 0.009s	sys 0.000s Metrics: {"bytes_written":3446255,"delete_count":0,"lbm_write_time_us":3685,"lbm_writes_lt_1ms":87,"reinsert_count":0,"update_count":420}
I20260812 06:18:23.219797 24723 maintenance_manager.cc:419] P c44a6e4741794afdaa18c491fbb97dae: Scheduling MajorDeltaCompactionOp(90ce218d0e1b4136bb506370aeda7b45): perf score=1.000000
I20260812 06:18:23.408325 24633 maintenance_manager.cc:643] P c44a6e4741794afdaa18c491fbb97dae: MajorDeltaCompactionOp(90ce218d0e1b4136bb506370aeda7b45) complete. Timing: real 0.188s	user 0.148s	sys 0.039s Metrics: {"cfile_cache_miss":533,"cfile_cache_miss_bytes":24733835,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":610,"lbm_read_time_us":13915,"lbm_reads_lt_1ms":573,"lbm_write_time_us":33883,"lbm_writes_lt_1ms":543,"mutex_wait_us":3,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":12032,"update_count":2500}
I20260812 06:18:23.409073 24723 maintenance_manager.cc:419] P c44a6e4741794afdaa18c491fbb97dae: Scheduling FlushDeltaMemStoresOp(90ce218d0e1b4136bb506370aeda7b45): perf score=11.118625
I20260812 06:18:23.441263 24633 maintenance_manager.cc:643] P c44a6e4741794afdaa18c491fbb97dae: FlushDeltaMemStoresOp(90ce218d0e1b4136bb506370aeda7b45) complete. Timing: real 0.032s	user 0.017s	sys 0.011s Metrics: {"bytes_written":12717735,"delete_count":0,"lbm_write_time_us":13278,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:18:23.441903 24723 maintenance_manager.cc:419] P c44a6e4741794afdaa18c491fbb97dae: Scheduling FlushDeltaMemStoresOp(90ce218d0e1b4136bb506370aeda7b45): perf score=2.188937
I20260812 06:18:23.460539 24633 maintenance_manager.cc:643] P c44a6e4741794afdaa18c491fbb97dae: FlushDeltaMemStoresOp(90ce218d0e1b4136bb506370aeda7b45) complete. Timing: real 0.018s	user 0.005s	sys 0.011s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3813,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:18:23.461414 24723 maintenance_manager.cc:419] P c44a6e4741794afdaa18c491fbb97dae: Scheduling MajorDeltaCompactionOp(90ce218d0e1b4136bb506370aeda7b45): perf score=1.000000
I20260812 06:18:23.627290 24633 maintenance_manager.cc:643] P c44a6e4741794afdaa18c491fbb97dae: MajorDeltaCompactionOp(90ce218d0e1b4136bb506370aeda7b45) complete. Timing: real 0.166s	user 0.115s	sys 0.048s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20631303,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":199,"lbm_read_time_us":12225,"lbm_reads_lt_1ms":472,"lbm_write_time_us":27265,"lbm_writes_lt_1ms":443,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":896,"update_count":2000}
I20260812 06:18:23.628111 24723 maintenance_manager.cc:419] P c44a6e4741794afdaa18c491fbb97dae: Scheduling FlushDeltaMemStoresOp(90ce218d0e1b4136bb506370aeda7b45): perf score=11.118625
I20260812 06:18:23.663225 24633 maintenance_manager.cc:643] P c44a6e4741794afdaa18c491fbb97dae: FlushDeltaMemStoresOp(90ce218d0e1b4136bb506370aeda7b45) complete. Timing: real 0.035s	user 0.010s	sys 0.021s Metrics: {"bytes_written":12717735,"delete_count":0,"lbm_write_time_us":13069,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:18:23.663838 24723 maintenance_manager.cc:419] P c44a6e4741794afdaa18c491fbb97dae: Scheduling FlushDeltaMemStoresOp(90ce218d0e1b4136bb506370aeda7b45): perf score=2.188937
I20260812 06:18:23.681151 24633 maintenance_manager.cc:643] P c44a6e4741794afdaa18c491fbb97dae: FlushDeltaMemStoresOp(90ce218d0e1b4136bb506370aeda7b45) complete. Timing: real 0.017s	user 0.010s	sys 0.003s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":6110,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:18:23.681751 24723 maintenance_manager.cc:419] P c44a6e4741794afdaa18c491fbb97dae: Scheduling FlushMRSOp(90ce218d0e1b4136bb506370aeda7b45): perf score=1.000000
I20260812 06:18:23.717046 24633 maintenance_manager.cc:643] P c44a6e4741794afdaa18c491fbb97dae: FlushMRSOp(90ce218d0e1b4136bb506370aeda7b45) complete. Timing: real 0.035s	user 0.029s	sys 0.004s Metrics: {"bytes_written":1193509,"cfile_init":1,"dirs.queue_time_us":115,"dirs.run_cpu_time_us":368,"dirs.run_wall_time_us":2458,"drs_written":1,"lbm_read_time_us":64,"lbm_reads_lt_1ms":4,"lbm_write_time_us":2766,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":29}
I20260812 06:18:23.718056 24723 maintenance_manager.cc:419] P c44a6e4741794afdaa18c491fbb97dae: Scheduling LogGCOp(90ce218d0e1b4136bb506370aeda7b45): free 121006460 bytes of WAL
I20260812 06:18:23.718418 24633 log_reader.cc:385] T 90ce218d0e1b4136bb506370aeda7b45: removed 12 log segments from log reader
I20260812 06:18:23.718515 24633 log.cc:1079] T 90ce218d0e1b4136bb506370aeda7b45 P c44a6e4741794afdaa18c491fbb97dae: Deleting log segment in path: /tmp/dist-test-taskBdY18o/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515500127844-24480-0/minicluster-data/ts-0-root/wals/90ce218d0e1b4136bb506370aeda7b45/wal-000000014 (ops 66-70)
I20260812 06:18:23.718565 24633 log.cc:1079] T 90ce218d0e1b4136bb506370aeda7b45 P c44a6e4741794afdaa18c491fbb97dae: Deleting log segment in path: /tmp/dist-test-taskBdY18o/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515500127844-24480-0/minicluster-data/ts-0-root/wals/90ce218d0e1b4136bb506370aeda7b45/wal-000000015 (ops 71-75)
I20260812 06:18:23.718600 24633 log.cc:1079] T 90ce218d0e1b4136bb506370aeda7b45 P c44a6e4741794afdaa18c491fbb97dae: Deleting log segment in path: /tmp/dist-test-taskBdY18o/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515500127844-24480-0/minicluster-data/ts-0-root/wals/90ce218d0e1b4136bb506370aeda7b45/wal-000000016 (ops 76-80)
I20260812 06:18:23.718626 24633 log.cc:1079] T 90ce218d0e1b4136bb506370aeda7b45 P c44a6e4741794afdaa18c491fbb97dae: Deleting log segment in path: /tmp/dist-test-taskBdY18o/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515500127844-24480-0/minicluster-data/ts-0-root/wals/90ce218d0e1b4136bb506370aeda7b45/wal-000000017 (ops 81-85)
I20260812 06:18:23.718658 24633 log.cc:1079] T 90ce218d0e1b4136bb506370aeda7b45 P c44a6e4741794afdaa18c491fbb97dae: Deleting log segment in path: /tmp/dist-test-taskBdY18o/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515500127844-24480-0/minicluster-data/ts-0-root/wals/90ce218d0e1b4136bb506370aeda7b45/wal-000000018 (ops 86-90)
I20260812 06:18:23.718693 24633 log.cc:1079] T 90ce218d0e1b4136bb506370aeda7b45 P c44a6e4741794afdaa18c491fbb97dae: Deleting log segment in path: /tmp/dist-test-taskBdY18o/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515500127844-24480-0/minicluster-data/ts-0-root/wals/90ce218d0e1b4136bb506370aeda7b45/wal-000000019 (ops 91-95)
I20260812 06:18:23.718725 24633 log.cc:1079] T 90ce218d0e1b4136bb506370aeda7b45 P c44a6e4741794afdaa18c491fbb97dae: Deleting log segment in path: /tmp/dist-test-taskBdY18o/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515500127844-24480-0/minicluster-data/ts-0-root/wals/90ce218d0e1b4136bb506370aeda7b45/wal-000000020 (ops 96-100)
I20260812 06:18:23.718756 24633 log.cc:1079] T 90ce218d0e1b4136bb506370aeda7b45 P c44a6e4741794afdaa18c491fbb97dae: Deleting log segment in path: /tmp/dist-test-taskBdY18o/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515500127844-24480-0/minicluster-data/ts-0-root/wals/90ce218d0e1b4136bb506370aeda7b45/wal-000000021 (ops 101-105)
I20260812 06:18:23.718787 24633 log.cc:1079] T 90ce218d0e1b4136bb506370aeda7b45 P c44a6e4741794afdaa18c491fbb97dae: Deleting log segment in path: /tmp/dist-test-taskBdY18o/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515500127844-24480-0/minicluster-data/ts-0-root/wals/90ce218d0e1b4136bb506370aeda7b45/wal-000000022 (ops 106-110)
I20260812 06:18:23.718818 24633 log.cc:1079] T 90ce218d0e1b4136bb506370aeda7b45 P c44a6e4741794afdaa18c491fbb97dae: Deleting log segment in path: /tmp/dist-test-taskBdY18o/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515500127844-24480-0/minicluster-data/ts-0-root/wals/90ce218d0e1b4136bb506370aeda7b45/wal-000000023 (ops 111-114)
I20260812 06:18:23.718849 24633 log.cc:1079] T 90ce218d0e1b4136bb506370aeda7b45 P c44a6e4741794afdaa18c491fbb97dae: Deleting log segment in path: /tmp/dist-test-taskBdY18o/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515500127844-24480-0/minicluster-data/ts-0-root/wals/90ce218d0e1b4136bb506370aeda7b45/wal-000000024 (ops 115-119)
I20260812 06:18:23.718880 24633 log.cc:1079] T 90ce218d0e1b4136bb506370aeda7b45 P c44a6e4741794afdaa18c491fbb97dae: Deleting log segment in path: /tmp/dist-test-taskBdY18o/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515500127844-24480-0/minicluster-data/ts-0-root/wals/90ce218d0e1b4136bb506370aeda7b45/wal-000000025 (ops 120-124)
I20260812 06:18:23.743227 24633 maintenance_manager.cc:643] P c44a6e4741794afdaa18c491fbb97dae: LogGCOp(90ce218d0e1b4136bb506370aeda7b45) complete. Timing: real 0.025s	user 0.000s	sys 0.023s Metrics: {}
I20260812 06:18:23.743772 24723 maintenance_manager.cc:419] P c44a6e4741794afdaa18c491fbb97dae: Scheduling FlushDeltaMemStoresOp(90ce218d0e1b4136bb506370aeda7b45): perf score=3.181125
I20260812 06:18:23.762743 24633 maintenance_manager.cc:643] P c44a6e4741794afdaa18c491fbb97dae: FlushDeltaMemStoresOp(90ce218d0e1b4136bb506370aeda7b45) complete. Timing: real 0.019s	user 0.009s	sys 0.008s Metrics: {"bytes_written":4471878,"delete_count":0,"lbm_write_time_us":7156,"lbm_writes_lt_1ms":112,"reinsert_count":0,"update_count":545}
I20260812 06:18:23.763434 24723 maintenance_manager.cc:419] P c44a6e4741794afdaa18c491fbb97dae: Scheduling UndoDeltaBlockGCOp(90ce218d0e1b4136bb506370aeda7b45): 462 bytes on disk
I20260812 06:18:23.764097 24633 maintenance_manager.cc:643] P c44a6e4741794afdaa18c491fbb97dae: UndoDeltaBlockGCOp(90ce218d0e1b4136bb506370aeda7b45) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":61,"lbm_reads_lt_1ms":4}
I20260812 06:18:23.764711 24723 maintenance_manager.cc:419] P c44a6e4741794afdaa18c491fbb97dae: Scheduling FlushDeltaMemStoresOp(90ce218d0e1b4136bb506370aeda7b45): perf score=2.188937
I20260812 06:18:23.777280 24633 maintenance_manager.cc:643] P c44a6e4741794afdaa18c491fbb97dae: FlushDeltaMemStoresOp(90ce218d0e1b4136bb506370aeda7b45) complete. Timing: real 0.012s	user 0.009s	sys 0.000s Metrics: {"bytes_written":3733433,"delete_count":0,"lbm_write_time_us":3900,"lbm_writes_lt_1ms":94,"reinsert_count":0,"update_count":455}
I20260812 06:18:23.778416 24723 maintenance_manager.cc:419] P c44a6e4741794afdaa18c491fbb97dae: Scheduling MajorDeltaCompactionOp(90ce218d0e1b4136bb506370aeda7b45): perf score=1.000000
I20260812 06:18:23.995626 24633 maintenance_manager.cc:643] P c44a6e4741794afdaa18c491fbb97dae: MajorDeltaCompactionOp(90ce218d0e1b4136bb506370aeda7b45) complete. Timing: real 0.217s	user 0.129s	sys 0.077s Metrics: {"cfile_cache_miss":634,"cfile_cache_miss_bytes":28836358,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":3225,"lbm_read_time_us":14649,"lbm_reads_lt_1ms":674,"lbm_write_time_us":32675,"lbm_writes_lt_1ms":643,"mutex_wait_us":2196,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":768,"thread_start_us":116,"threads_started":1,"update_count":3000}
I20260812 06:18:23.996511 24723 maintenance_manager.cc:419] P c44a6e4741794afdaa18c491fbb97dae: Scheduling FlushDeltaMemStoresOp(90ce218d0e1b4136bb506370aeda7b45): perf score=14.095187
I20260812 06:18:24.047492 24633 maintenance_manager.cc:643] P c44a6e4741794afdaa18c491fbb97dae: FlushDeltaMemStoresOp(90ce218d0e1b4136bb506370aeda7b45) complete. Timing: real 0.051s	user 0.037s	sys 0.011s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":23025,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:18:24.048370 24723 maintenance_manager.cc:419] P c44a6e4741794afdaa18c491fbb97dae: Scheduling FlushDeltaMemStoresOp(90ce218d0e1b4136bb506370aeda7b45): perf score=2.188937
I20260812 06:18:24.071997 24633 maintenance_manager.cc:643] P c44a6e4741794afdaa18c491fbb97dae: FlushDeltaMemStoresOp(90ce218d0e1b4136bb506370aeda7b45) complete. Timing: real 0.023s	user 0.010s	sys 0.011s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5451,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:24.072921 24723 maintenance_manager.cc:419] P c44a6e4741794afdaa18c491fbb97dae: Scheduling MajorDeltaCompactionOp(90ce218d0e1b4136bb506370aeda7b45): perf score=1.000000
I20260812 06:18:24.277797 24633 maintenance_manager.cc:643] P c44a6e4741794afdaa18c491fbb97dae: MajorDeltaCompactionOp(90ce218d0e1b4136bb506370aeda7b45) complete. Timing: real 0.205s	user 0.139s	sys 0.062s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24733723,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":352,"lbm_read_time_us":14092,"lbm_reads_lt_1ms":564,"lbm_write_time_us":31011,"lbm_writes_lt_1ms":543,"mutex_wait_us":69,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":7424,"update_count":2500}
I20260812 06:18:24.278386 24723 maintenance_manager.cc:419] P c44a6e4741794afdaa18c491fbb97dae: Scheduling FlushDeltaMemStoresOp(90ce218d0e1b4136bb506370aeda7b45): perf score=11.118625
I20260812 06:18:24.316373 24633 maintenance_manager.cc:643] P c44a6e4741794afdaa18c491fbb97dae: FlushDeltaMemStoresOp(90ce218d0e1b4136bb506370aeda7b45) complete. Timing: real 0.038s	user 0.022s	sys 0.013s Metrics: {"bytes_written":12717735,"delete_count":0,"lbm_write_time_us":16063,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:18:24.317126 24723 maintenance_manager.cc:419] P c44a6e4741794afdaa18c491fbb97dae: Scheduling FlushDeltaMemStoresOp(90ce218d0e1b4136bb506370aeda7b45): perf score=2.188937
I20260812 06:18:24.342568 24633 maintenance_manager.cc:643] P c44a6e4741794afdaa18c491fbb97dae: FlushDeltaMemStoresOp(90ce218d0e1b4136bb506370aeda7b45) complete. Timing: real 0.025s	user 0.013s	sys 0.004s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":6542,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:18:24.343178 24723 maintenance_manager.cc:419] P c44a6e4741794afdaa18c491fbb97dae: Scheduling MajorDeltaCompactionOp(90ce218d0e1b4136bb506370aeda7b45): perf score=1.000000
I20260812 06:18:24.480790 24633 maintenance_manager.cc:643] P c44a6e4741794afdaa18c491fbb97dae: MajorDeltaCompactionOp(90ce218d0e1b4136bb506370aeda7b45) complete. Timing: real 0.137s	user 0.117s	sys 0.020s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20631303,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":514,"lbm_read_time_us":8589,"lbm_reads_lt_1ms":464,"lbm_write_time_us":27511,"lbm_writes_lt_1ms":443,"mutex_wait_us":45,"peak_mem_usage":50689328,"reinsert_count":0,"update_count":2000}
I20260812 06:18:24.481381 24723 maintenance_manager.cc:419] P c44a6e4741794afdaa18c491fbb97dae: Scheduling FlushDeltaMemStoresOp(90ce218d0e1b4136bb506370aeda7b45): perf score=10.126437
I20260812 06:18:24.526383 24633 maintenance_manager.cc:643] P c44a6e4741794afdaa18c491fbb97dae: FlushDeltaMemStoresOp(90ce218d0e1b4136bb506370aeda7b45) complete. Timing: real 0.045s	user 0.029s	sys 0.011s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":17702,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:18:24.527176 24723 maintenance_manager.cc:419] P c44a6e4741794afdaa18c491fbb97dae: Scheduling FlushDeltaMemStoresOp(90ce218d0e1b4136bb506370aeda7b45): perf score=2.188937
I20260812 06:18:24.545055 24633 maintenance_manager.cc:643] P c44a6e4741794afdaa18c491fbb97dae: FlushDeltaMemStoresOp(90ce218d0e1b4136bb506370aeda7b45) complete. Timing: real 0.018s	user 0.010s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6040,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:24.545991 24723 maintenance_manager.cc:419] P c44a6e4741794afdaa18c491fbb97dae: Scheduling MajorDeltaCompactionOp(90ce218d0e1b4136bb506370aeda7b45): perf score=1.000000
I20260812 06:18:24.684645 24633 maintenance_manager.cc:643] P c44a6e4741794afdaa18c491fbb97dae: MajorDeltaCompactionOp(90ce218d0e1b4136bb506370aeda7b45) complete. Timing: real 0.138s	user 0.113s	sys 0.021s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20631312,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":891,"lbm_read_time_us":10192,"lbm_reads_lt_1ms":472,"lbm_write_time_us":26853,"lbm_writes_lt_1ms":443,"mutex_wait_us":368,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":10752,"update_count":2000}
I20260812 06:18:24.685369 24723 maintenance_manager.cc:419] P c44a6e4741794afdaa18c491fbb97dae: Scheduling FlushDeltaMemStoresOp(90ce218d0e1b4136bb506370aeda7b45): perf score=10.126437
I20260812 06:18:24.742929 24633 maintenance_manager.cc:643] P c44a6e4741794afdaa18c491fbb97dae: FlushDeltaMemStoresOp(90ce218d0e1b4136bb506370aeda7b45) complete. Timing: real 0.057s	user 0.034s	sys 0.007s Metrics: {"bytes_written":12307491,"delete_count":0,"lbm_write_time_us":18172,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:18:24.743925 24723 maintenance_manager.cc:419] P c44a6e4741794afdaa18c491fbb97dae: Scheduling FlushDeltaMemStoresOp(90ce218d0e1b4136bb506370aeda7b45): perf score=2.188937
I20260812 06:18:24.757846 24633 maintenance_manager.cc:643] P c44a6e4741794afdaa18c491fbb97dae: FlushDeltaMemStoresOp(90ce218d0e1b4136bb506370aeda7b45) complete. Timing: real 0.014s	user 0.010s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4815,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:24.758572 24723 maintenance_manager.cc:419] P c44a6e4741794afdaa18c491fbb97dae: Scheduling MajorDeltaCompactionOp(90ce218d0e1b4136bb506370aeda7b45): perf score=1.000000
I20260812 06:18:24.895206 24633 maintenance_manager.cc:643] P c44a6e4741794afdaa18c491fbb97dae: MajorDeltaCompactionOp(90ce218d0e1b4136bb506370aeda7b45) complete. Timing: real 0.136s	user 0.104s	sys 0.032s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20631313,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":1068,"lbm_read_time_us":8069,"lbm_reads_lt_1ms":472,"lbm_write_time_us":28133,"lbm_writes_lt_1ms":443,"mutex_wait_us":403,"peak_mem_usage":50689328,"reinsert_count":0,"update_count":2000}
I20260812 06:18:24.896139 24723 maintenance_manager.cc:419] P c44a6e4741794afdaa18c491fbb97dae: Scheduling FlushDeltaMemStoresOp(90ce218d0e1b4136bb506370aeda7b45): perf score=10.126437
I20260812 06:18:24.956372 24633 maintenance_manager.cc:643] P c44a6e4741794afdaa18c491fbb97dae: FlushDeltaMemStoresOp(90ce218d0e1b4136bb506370aeda7b45) complete. Timing: real 0.060s	user 0.039s	sys 0.013s Metrics: {"bytes_written":12307491,"delete_count":0,"lbm_write_time_us":20531,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:18:24.957263 24723 maintenance_manager.cc:419] P c44a6e4741794afdaa18c491fbb97dae: Scheduling FlushDeltaMemStoresOp(90ce218d0e1b4136bb506370aeda7b45): perf score=2.188937
I20260812 06:18:24.969017 24633 maintenance_manager.cc:643] P c44a6e4741794afdaa18c491fbb97dae: FlushDeltaMemStoresOp(90ce218d0e1b4136bb506370aeda7b45) complete. Timing: real 0.012s	user 0.006s	sys 0.003s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4377,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:24.969563 24723 maintenance_manager.cc:419] P c44a6e4741794afdaa18c491fbb97dae: Scheduling MajorDeltaCompactionOp(90ce218d0e1b4136bb506370aeda7b45): perf score=1.000000
I20260812 06:18:25.139209 24633 maintenance_manager.cc:643] P c44a6e4741794afdaa18c491fbb97dae: MajorDeltaCompactionOp(90ce218d0e1b4136bb506370aeda7b45) complete. Timing: real 0.169s	user 0.093s	sys 0.069s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20631313,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":950,"lbm_read_time_us":11481,"lbm_reads_lt_1ms":472,"lbm_write_time_us":28042,"lbm_writes_lt_1ms":443,"mutex_wait_us":49,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":7936,"update_count":2000}
I20260812 06:18:25.139937 24723 maintenance_manager.cc:419] P c44a6e4741794afdaa18c491fbb97dae: Scheduling FlushDeltaMemStoresOp(90ce218d0e1b4136bb506370aeda7b45): perf score=10.126437
I20260812 06:18:25.190729 24633 maintenance_manager.cc:643] P c44a6e4741794afdaa18c491fbb97dae: FlushDeltaMemStoresOp(90ce218d0e1b4136bb506370aeda7b45) complete. Timing: real 0.051s	user 0.026s	sys 0.012s Metrics: {"bytes_written":12307492,"delete_count":0,"lbm_write_time_us":16728,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:18:25.191891 24723 maintenance_manager.cc:419] P c44a6e4741794afdaa18c491fbb97dae: Scheduling FlushDeltaMemStoresOp(90ce218d0e1b4136bb506370aeda7b45): perf score=2.188937
I20260812 06:18:25.205781 24633 maintenance_manager.cc:643] P c44a6e4741794afdaa18c491fbb97dae: FlushDeltaMemStoresOp(90ce218d0e1b4136bb506370aeda7b45) complete. Timing: real 0.014s	user 0.010s	sys 0.004s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":5017,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:25.206326 24723 maintenance_manager.cc:419] P c44a6e4741794afdaa18c491fbb97dae: Scheduling MajorDeltaCompactionOp(90ce218d0e1b4136bb506370aeda7b45): perf score=1.000000
I20260812 06:18:25.342685 24633 maintenance_manager.cc:643] P c44a6e4741794afdaa18c491fbb97dae: MajorDeltaCompactionOp(90ce218d0e1b4136bb506370aeda7b45) complete. Timing: real 0.136s	user 0.108s	sys 0.028s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20631313,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":930,"lbm_read_time_us":8814,"lbm_reads_lt_1ms":472,"lbm_write_time_us":26369,"lbm_writes_lt_1ms":443,"mutex_wait_us":275,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":6144,"update_count":2000}
I20260812 06:18:25.343356 24723 maintenance_manager.cc:419] P c44a6e4741794afdaa18c491fbb97dae: Scheduling FlushDeltaMemStoresOp(90ce218d0e1b4136bb506370aeda7b45): perf score=10.126437
I20260812 06:18:25.389143 24633 maintenance_manager.cc:643] P c44a6e4741794afdaa18c491fbb97dae: FlushDeltaMemStoresOp(90ce218d0e1b4136bb506370aeda7b45) complete. Timing: real 0.046s	user 0.026s	sys 0.016s Metrics: {"bytes_written":12307493,"delete_count":0,"lbm_write_time_us":19430,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:18:25.389945 24723 maintenance_manager.cc:419] P c44a6e4741794afdaa18c491fbb97dae: Scheduling FlushDeltaMemStoresOp(90ce218d0e1b4136bb506370aeda7b45): perf score=2.188937
I20260812 06:18:25.406854 24633 maintenance_manager.cc:643] P c44a6e4741794afdaa18c491fbb97dae: FlushDeltaMemStoresOp(90ce218d0e1b4136bb506370aeda7b45) complete. Timing: real 0.017s	user 0.011s	sys 0.005s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":6651,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:25.407560 24723 maintenance_manager.cc:419] P c44a6e4741794afdaa18c491fbb97dae: Scheduling FlushMRSOp(90ce218d0e1b4136bb506370aeda7b45): perf score=1.000000
I20260812 06:18:25.438066 24633 maintenance_manager.cc:643] P c44a6e4741794afdaa18c491fbb97dae: FlushMRSOp(90ce218d0e1b4136bb506370aeda7b45) complete. Timing: real 0.030s	user 0.030s	sys 0.000s Metrics: {"bytes_written":1275445,"cfile_init":1,"dirs.queue_time_us":87,"dirs.run_cpu_time_us":380,"dirs.run_wall_time_us":1267,"drs_written":1,"lbm_read_time_us":41,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1616,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":31}
I20260812 06:18:25.438918 24723 maintenance_manager.cc:419] P c44a6e4741794afdaa18c491fbb97dae: Scheduling LogGCOp(90ce218d0e1b4136bb506370aeda7b45): free 128414645 bytes of WAL
I20260812 06:18:25.439189 24633 log_reader.cc:385] T 90ce218d0e1b4136bb506370aeda7b45: removed 13 log segments from log reader
I20260812 06:18:25.439240 24633 log.cc:1079] T 90ce218d0e1b4136bb506370aeda7b45 P c44a6e4741794afdaa18c491fbb97dae: Deleting log segment in path: /tmp/dist-test-taskBdY18o/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515500127844-24480-0/minicluster-data/ts-0-root/wals/90ce218d0e1b4136bb506370aeda7b45/wal-000000026 (ops 125-128)
I20260812 06:18:25.439282 24633 log.cc:1079] T 90ce218d0e1b4136bb506370aeda7b45 P c44a6e4741794afdaa18c491fbb97dae: Deleting log segment in path: /tmp/dist-test-taskBdY18o/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515500127844-24480-0/minicluster-data/ts-0-root/wals/90ce218d0e1b4136bb506370aeda7b45/wal-000000027 (ops 129-133)
I20260812 06:18:25.439316 24633 log.cc:1079] T 90ce218d0e1b4136bb506370aeda7b45 P c44a6e4741794afdaa18c491fbb97dae: Deleting log segment in path: /tmp/dist-test-taskBdY18o/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515500127844-24480-0/minicluster-data/ts-0-root/wals/90ce218d0e1b4136bb506370aeda7b45/wal-000000028 (ops 134-138)
I20260812 06:18:25.439440 24633 log.cc:1079] T 90ce218d0e1b4136bb506370aeda7b45 P c44a6e4741794afdaa18c491fbb97dae: Deleting log segment in path: /tmp/dist-test-taskBdY18o/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515500127844-24480-0/minicluster-data/ts-0-root/wals/90ce218d0e1b4136bb506370aeda7b45/wal-000000029 (ops 139-142)
I20260812 06:18:25.439497 24633 log.cc:1079] T 90ce218d0e1b4136bb506370aeda7b45 P c44a6e4741794afdaa18c491fbb97dae: Deleting log segment in path: /tmp/dist-test-taskBdY18o/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515500127844-24480-0/minicluster-data/ts-0-root/wals/90ce218d0e1b4136bb506370aeda7b45/wal-000000030 (ops 143-147)
I20260812 06:18:25.439530 24633 log.cc:1079] T 90ce218d0e1b4136bb506370aeda7b45 P c44a6e4741794afdaa18c491fbb97dae: Deleting log segment in path: /tmp/dist-test-taskBdY18o/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515500127844-24480-0/minicluster-data/ts-0-root/wals/90ce218d0e1b4136bb506370aeda7b45/wal-000000031 (ops 148-152)
I20260812 06:18:25.439564 24633 log.cc:1079] T 90ce218d0e1b4136bb506370aeda7b45 P c44a6e4741794afdaa18c491fbb97dae: Deleting log segment in path: /tmp/dist-test-taskBdY18o/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515500127844-24480-0/minicluster-data/ts-0-root/wals/90ce218d0e1b4136bb506370aeda7b45/wal-000000032 (ops 153-157)
I20260812 06:18:25.439592 24633 log.cc:1079] T 90ce218d0e1b4136bb506370aeda7b45 P c44a6e4741794afdaa18c491fbb97dae: Deleting log segment in path: /tmp/dist-test-taskBdY18o/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515500127844-24480-0/minicluster-data/ts-0-root/wals/90ce218d0e1b4136bb506370aeda7b45/wal-000000033 (ops 158-162)
I20260812 06:18:25.439616 24633 log.cc:1079] T 90ce218d0e1b4136bb506370aeda7b45 P c44a6e4741794afdaa18c491fbb97dae: Deleting log segment in path: /tmp/dist-test-taskBdY18o/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515500127844-24480-0/minicluster-data/ts-0-root/wals/90ce218d0e1b4136bb506370aeda7b45/wal-000000034 (ops 163-166)
I20260812 06:18:25.439657 24633 log.cc:1079] T 90ce218d0e1b4136bb506370aeda7b45 P c44a6e4741794afdaa18c491fbb97dae: Deleting log segment in path: /tmp/dist-test-taskBdY18o/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515500127844-24480-0/minicluster-data/ts-0-root/wals/90ce218d0e1b4136bb506370aeda7b45/wal-000000035 (ops 167-171)
I20260812 06:18:25.439682 24633 log.cc:1079] T 90ce218d0e1b4136bb506370aeda7b45 P c44a6e4741794afdaa18c491fbb97dae: Deleting log segment in path: /tmp/dist-test-taskBdY18o/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515500127844-24480-0/minicluster-data/ts-0-root/wals/90ce218d0e1b4136bb506370aeda7b45/wal-000000036 (ops 172-176)
I20260812 06:18:25.439713 24633 log.cc:1079] T 90ce218d0e1b4136bb506370aeda7b45 P c44a6e4741794afdaa18c491fbb97dae: Deleting log segment in path: /tmp/dist-test-taskBdY18o/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515500127844-24480-0/minicluster-data/ts-0-root/wals/90ce218d0e1b4136bb506370aeda7b45/wal-000000037 (ops 177-180)
I20260812 06:18:25.439742 24633 log.cc:1079] T 90ce218d0e1b4136bb506370aeda7b45 P c44a6e4741794afdaa18c491fbb97dae: Deleting log segment in path: /tmp/dist-test-taskBdY18o/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515500127844-24480-0/minicluster-data/ts-0-root/wals/90ce218d0e1b4136bb506370aeda7b45/wal-000000038 (ops 181-185)
I20260812 06:18:25.463928 24633 maintenance_manager.cc:643] P c44a6e4741794afdaa18c491fbb97dae: LogGCOp(90ce218d0e1b4136bb506370aeda7b45) complete. Timing: real 0.025s	user 0.000s	sys 0.023s Metrics: {}
I20260812 06:18:25.464568 24723 maintenance_manager.cc:419] P c44a6e4741794afdaa18c491fbb97dae: Scheduling FlushDeltaMemStoresOp(90ce218d0e1b4136bb506370aeda7b45): perf score=2.188937
I20260812 06:18:25.483868 24633 maintenance_manager.cc:643] P c44a6e4741794afdaa18c491fbb97dae: FlushDeltaMemStoresOp(90ce218d0e1b4136bb506370aeda7b45) complete. Timing: real 0.019s	user 0.002s	sys 0.007s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4267,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:25.484447 24723 maintenance_manager.cc:419] P c44a6e4741794afdaa18c491fbb97dae: Scheduling FlushDeltaMemStoresOp(90ce218d0e1b4136bb506370aeda7b45): perf score=2.188937
I20260812 06:18:25.498520 24633 maintenance_manager.cc:643] P c44a6e4741794afdaa18c491fbb97dae: FlushDeltaMemStoresOp(90ce218d0e1b4136bb506370aeda7b45) complete. Timing: real 0.014s	user 0.010s	sys 0.003s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5061,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:25.499049 24723 maintenance_manager.cc:419] P c44a6e4741794afdaa18c491fbb97dae: Scheduling UndoDeltaBlockGCOp(90ce218d0e1b4136bb506370aeda7b45): 483 bytes on disk
I20260812 06:18:25.499503 24633 maintenance_manager.cc:643] P c44a6e4741794afdaa18c491fbb97dae: UndoDeltaBlockGCOp(90ce218d0e1b4136bb506370aeda7b45) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":72,"lbm_reads_lt_1ms":4}
I20260812 06:18:25.500116 24723 maintenance_manager.cc:419] P c44a6e4741794afdaa18c491fbb97dae: Scheduling MajorDeltaCompactionOp(90ce218d0e1b4136bb506370aeda7b45): perf score=1.000000
I20260812 06:18:25.697892 24633 maintenance_manager.cc:643] P c44a6e4741794afdaa18c491fbb97dae: MajorDeltaCompactionOp(90ce218d0e1b4136bb506370aeda7b45) complete. Timing: real 0.198s	user 0.143s	sys 0.043s Metrics: {"cfile_cache_miss":634,"cfile_cache_miss_bytes":28836376,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":1161,"lbm_read_time_us":13241,"lbm_reads_lt_1ms":674,"lbm_write_time_us":37511,"lbm_writes_lt_1ms":643,"mutex_wait_us":108,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":14976,"thread_start_us":162,"threads_started":1,"update_count":3000}
I20260812 06:18:25.698724 24723 maintenance_manager.cc:419] P c44a6e4741794afdaa18c491fbb97dae: Scheduling FlushDeltaMemStoresOp(90ce218d0e1b4136bb506370aeda7b45): perf score=14.095187
I20260812 06:18:25.756649 24633 maintenance_manager.cc:643] P c44a6e4741794afdaa18c491fbb97dae: FlushDeltaMemStoresOp(90ce218d0e1b4136bb506370aeda7b45) complete. Timing: real 0.058s	user 0.019s	sys 0.035s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":24739,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:18:25.757332 24723 maintenance_manager.cc:419] P c44a6e4741794afdaa18c491fbb97dae: Scheduling FlushDeltaMemStoresOp(90ce218d0e1b4136bb506370aeda7b45): perf score=2.188937
I20260812 06:18:25.770444 24633 maintenance_manager.cc:643] P c44a6e4741794afdaa18c491fbb97dae: FlushDeltaMemStoresOp(90ce218d0e1b4136bb506370aeda7b45) complete. Timing: real 0.013s	user 0.004s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4688,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:25.770942 24723 maintenance_manager.cc:419] P c44a6e4741794afdaa18c491fbb97dae: Scheduling MajorDeltaCompactionOp(90ce218d0e1b4136bb506370aeda7b45): perf score=1.000000
I20260812 06:18:25.793547 24480 heavy-update-compaction-itest.cc:229] Time spent updating: real 5.323s	user 1.902s	sys 0.122s
I20260812 06:18:25.858059 24480 heavy-update-compaction-itest.cc:265] Time spent scanning: real 0.064s	user 0.001s	sys 0.003s
I20260812 06:18:25.859000 24480 tablet_server.cc:179] TabletServer@127.23.232.1:0 shutting down...
I20260812 06:18:25.909466 24633 maintenance_manager.cc:643] P c44a6e4741794afdaa18c491fbb97dae: MajorDeltaCompactionOp(90ce218d0e1b4136bb506370aeda7b45) complete. Timing: real 0.138s	user 0.118s	sys 0.020s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24733724,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":489,"lbm_read_time_us":10515,"lbm_reads_lt_1ms":568,"lbm_write_time_us":26573,"lbm_writes_lt_1ms":543,"mutex_wait_us":69,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":768,"update_count":2500}
I20260812 06:18:25.910272 24480 ts_tablet_manager.cc:1507] Shutting down tablet manager...
I20260812 06:18:25.910768 24480 tablet_replica.cc:333] T 90ce218d0e1b4136bb506370aeda7b45 P c44a6e4741794afdaa18c491fbb97dae: stopping tablet replica
I20260812 06:18:25.911053 24480 raft_consensus.cc:2243] T 90ce218d0e1b4136bb506370aeda7b45 P c44a6e4741794afdaa18c491fbb97dae [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:18:25.922683 24480 raft_consensus.cc:2272] T 90ce218d0e1b4136bb506370aeda7b45 P c44a6e4741794afdaa18c491fbb97dae [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:18:25.940047 24480 tablet_server.cc:196] TabletServer@127.23.232.1:0 shutdown complete.
I20260812 06:18:25.957744 24480 master.cc:562] Master@127.23.232.62:36507 shutting down...
I20260812 06:18:25.961880 24480 raft_consensus.cc:2243] T 00000000000000000000000000000000 P 5d806f682f2e4d0f98b429a8bd59111b [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:18:25.962179 24480 raft_consensus.cc:2272] T 00000000000000000000000000000000 P 5d806f682f2e4d0f98b429a8bd59111b [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:18:25.962280 24480 tablet_replica.cc:333] T 00000000000000000000000000000000 P 5d806f682f2e4d0f98b429a8bd59111b: stopping tablet replica
I20260812 06:18:25.975162 24480 master.cc:584] Master@127.23.232.62:36507 shutdown complete.
[       OK ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/0 (5918 ms)
[ RUN      ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/1
I20260812 06:18:26.058729 24480 internal_mini_cluster.cc:156] Creating distributed mini masters. Addrs: 127.23.232.62:35441
I20260812 06:18:26.059132 24480 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:18:26.062340 24776 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:18:26.062394 24777 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:18:26.062394 24780 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:18:26.062601 24480 server_base.cc:1061] running on GCE node
I20260812 06:18:26.062944 24480 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:18:26.062999 24480 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:18:26.063014 24480 hybrid_clock.cc:648] HybridClock initialized: now 1786515506063015 us; error 0 us; skew 500 ppm
I20260812 06:18:26.064078 24480 webserver.cc:533] Webserver started at http://127.23.232.62:33415/ using document root <none> and password file <none>
I20260812 06:18:26.064271 24480 fs_manager.cc:362] Metadata directory not provided
I20260812 06:18:26.064337 24480 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:18:26.064429 24480 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:18:26.064904 24480 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskBdY18o/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515500127844-24480-0/minicluster-data/master-0-root/instance:
uuid: "4b0da8073900484caee269dbbbc4522a"
format_stamp: "Formatted at 2026-08-12 06:18:26 on dist-test-slave-t7g5"
I20260812 06:18:26.066850 24480 fs_manager.cc:696] Time spent creating directory manager: real 0.002s	user 0.002s	sys 0.000s
I20260812 06:18:26.068288 24792 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:18:26.068600 24480 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.002s	sys 0.000s
I20260812 06:18:26.068681 24480 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskBdY18o/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515500127844-24480-0/minicluster-data/master-0-root
uuid: "4b0da8073900484caee269dbbbc4522a"
format_stamp: "Formatted at 2026-08-12 06:18:26 on dist-test-slave-t7g5"
I20260812 06:18:26.068765 24480 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskBdY18o/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515500127844-24480-0/minicluster-data/master-0-root
metadata directory: /tmp/dist-test-taskBdY18o/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515500127844-24480-0/minicluster-data/master-0-root
1 data directories: /tmp/dist-test-taskBdY18o/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515500127844-24480-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:18:26.075505 24480 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:18:26.075948 24480 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:18:26.080586 24480 rpc_server.cc:307] RPC server started. Bound to: 127.23.232.62:35441
I20260812 06:18:26.081552 24870 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.23.232.62:35441 every 8 connection(s)
I20260812 06:18:26.087541 24871 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:18:26.090714 24871 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P 4b0da8073900484caee269dbbbc4522a: Bootstrap starting.
I20260812 06:18:26.091636 24871 tablet_bootstrap.cc:654] T 00000000000000000000000000000000 P 4b0da8073900484caee269dbbbc4522a: Neither blocks nor log segments found. Creating new log.
I20260812 06:18:26.092761 24871 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P 4b0da8073900484caee269dbbbc4522a: No bootstrap required, opened a new log
I20260812 06:18:26.093189 24871 raft_consensus.cc:359] T 00000000000000000000000000000000 P 4b0da8073900484caee269dbbbc4522a [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "4b0da8073900484caee269dbbbc4522a" member_type: VOTER }
I20260812 06:18:26.093415 24871 raft_consensus.cc:385] T 00000000000000000000000000000000 P 4b0da8073900484caee269dbbbc4522a [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:18:26.093628 24871 raft_consensus.cc:740] T 00000000000000000000000000000000 P 4b0da8073900484caee269dbbbc4522a [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: 4b0da8073900484caee269dbbbc4522a, State: Initialized, Role: FOLLOWER
I20260812 06:18:26.094028 24871 consensus_queue.cc:260] T 00000000000000000000000000000000 P 4b0da8073900484caee269dbbbc4522a [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: "4b0da8073900484caee269dbbbc4522a" member_type: VOTER }
I20260812 06:18:26.094187 24871 raft_consensus.cc:399] T 00000000000000000000000000000000 P 4b0da8073900484caee269dbbbc4522a [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:18:26.094235 24871 raft_consensus.cc:493] T 00000000000000000000000000000000 P 4b0da8073900484caee269dbbbc4522a [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:18:26.094288 24871 raft_consensus.cc:3060] T 00000000000000000000000000000000 P 4b0da8073900484caee269dbbbc4522a [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:18:26.095253 24871 raft_consensus.cc:515] T 00000000000000000000000000000000 P 4b0da8073900484caee269dbbbc4522a [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "4b0da8073900484caee269dbbbc4522a" member_type: VOTER }
I20260812 06:18:26.095413 24871 leader_election.cc:304] T 00000000000000000000000000000000 P 4b0da8073900484caee269dbbbc4522a [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: 4b0da8073900484caee269dbbbc4522a; no voters: 
I20260812 06:18:26.095988 24871 leader_election.cc:290] T 00000000000000000000000000000000 P 4b0da8073900484caee269dbbbc4522a [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:18:26.096108 24874 raft_consensus.cc:2804] T 00000000000000000000000000000000 P 4b0da8073900484caee269dbbbc4522a [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:18:26.096323 24874 raft_consensus.cc:697] T 00000000000000000000000000000000 P 4b0da8073900484caee269dbbbc4522a [term 1 LEADER]: Becoming Leader. State: Replica: 4b0da8073900484caee269dbbbc4522a, State: Running, Role: LEADER
I20260812 06:18:26.096503 24874 consensus_queue.cc:237] T 00000000000000000000000000000000 P 4b0da8073900484caee269dbbbc4522a [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: "4b0da8073900484caee269dbbbc4522a" member_type: VOTER }
I20260812 06:18:26.096555 24871 sys_catalog.cc:565] T 00000000000000000000000000000000 P 4b0da8073900484caee269dbbbc4522a [sys.catalog]: configured and running, proceeding with master startup.
I20260812 06:18:26.096978 24875 sys_catalog.cc:455] T 00000000000000000000000000000000 P 4b0da8073900484caee269dbbbc4522a [sys.catalog]: SysCatalogTable state changed. Reason: RaftConsensus started. Latest consensus state: current_term: 1 leader_uuid: "4b0da8073900484caee269dbbbc4522a" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "4b0da8073900484caee269dbbbc4522a" member_type: VOTER } }
I20260812 06:18:26.097096 24875 sys_catalog.cc:458] T 00000000000000000000000000000000 P 4b0da8073900484caee269dbbbc4522a [sys.catalog]: This master's current role is: LEADER
I20260812 06:18:26.097000 24876 sys_catalog.cc:455] T 00000000000000000000000000000000 P 4b0da8073900484caee269dbbbc4522a [sys.catalog]: SysCatalogTable state changed. Reason: New leader 4b0da8073900484caee269dbbbc4522a. Latest consensus state: current_term: 1 leader_uuid: "4b0da8073900484caee269dbbbc4522a" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "4b0da8073900484caee269dbbbc4522a" member_type: VOTER } }
I20260812 06:18:26.097221 24876 sys_catalog.cc:458] T 00000000000000000000000000000000 P 4b0da8073900484caee269dbbbc4522a [sys.catalog]: This master's current role is: LEADER
I20260812 06:18:26.097469 24879 catalog_manager.cc:1511] Loading table and tablet metadata into memory...
I20260812 06:18:26.098312 24879 catalog_manager.cc:1520] Initializing Kudu cluster ID...
I20260812 06:18:26.098472 24480 internal_mini_cluster.cc:184] Waiting to initialize catalog manager on master 0
I20260812 06:18:26.100286 24879 catalog_manager.cc:1383] Generated new cluster ID: 9c543ec4f6284f13a04e106bbe1e491b
I20260812 06:18:26.100360 24879 catalog_manager.cc:1531] Initializing Kudu internal certificate authority...
I20260812 06:18:26.106643 24879 catalog_manager.cc:1406] Generated new certificate authority record
I20260812 06:18:26.107436 24879 catalog_manager.cc:1540] Loading token signing keys...
I20260812 06:18:26.121337 24879 catalog_manager.cc:6092] T 00000000000000000000000000000000 P 4b0da8073900484caee269dbbbc4522a: Generated new TSK 0
I20260812 06:18:26.121567 24879 catalog_manager.cc:1550] Initializing in-progress tserver states...
I20260812 06:18:26.131280 24480 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:18:26.133459 24902 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:18:26.133472 24898 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:18:26.133746 24896 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:18:26.133771 24480 server_base.cc:1061] running on GCE node
I20260812 06:18:26.134204 24480 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:18:26.134268 24480 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:18:26.134436 24480 hybrid_clock.cc:648] HybridClock initialized: now 1786515506134433 us; error 0 us; skew 500 ppm
I20260812 06:18:26.135556 24480 webserver.cc:533] Webserver started at http://127.23.232.1:35229/ using document root <none> and password file <none>
I20260812 06:18:26.135746 24480 fs_manager.cc:362] Metadata directory not provided
I20260812 06:18:26.135802 24480 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:18:26.135885 24480 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:18:26.136327 24480 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskBdY18o/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515500127844-24480-0/minicluster-data/ts-0-root/instance:
uuid: "f99df2b8e103490181e19544aeb9dcf3"
format_stamp: "Formatted at 2026-08-12 06:18:26 on dist-test-slave-t7g5"
I20260812 06:18:26.138758 24480 fs_manager.cc:696] Time spent creating directory manager: real 0.002s	user 0.000s	sys 0.003s
I20260812 06:18:26.139964 24910 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:18:26.140239 24480 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.000s	sys 0.001s
I20260812 06:18:26.140323 24480 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskBdY18o/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515500127844-24480-0/minicluster-data/ts-0-root
uuid: "f99df2b8e103490181e19544aeb9dcf3"
format_stamp: "Formatted at 2026-08-12 06:18:26 on dist-test-slave-t7g5"
I20260812 06:18:26.140405 24480 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskBdY18o/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515500127844-24480-0/minicluster-data/ts-0-root
metadata directory: /tmp/dist-test-taskBdY18o/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515500127844-24480-0/minicluster-data/ts-0-root
1 data directories: /tmp/dist-test-taskBdY18o/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515500127844-24480-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:18:26.154969 24480 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:18:26.155414 24480 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:18:26.155757 24480 txn_system_client.cc:432] TxnSystemClient initialization is disabled...
I20260812 06:18:26.156240 24480 ts_tablet_manager.cc:585] Loaded tablet metadata (0 total tablets, 0 live tablets)
I20260812 06:18:26.156279 24480 ts_tablet_manager.cc:531] Time spent load tablet metadata: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:18:26.156327 24480 ts_tablet_manager.cc:616] Registered 0 tablets
I20260812 06:18:26.156354 24480 ts_tablet_manager.cc:595] Time spent register tablets: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:18:26.162133 24480 rpc_server.cc:307] RPC server started. Bound to: 127.23.232.1:46493
I20260812 06:18:26.164151 25011 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.23.232.1:46493 every 8 connection(s)
I20260812 06:18:26.173209 25012 heartbeater.cc:344] Connected to a master server at 127.23.232.62:35441
I20260812 06:18:26.173380 25012 heartbeater.cc:461] Registering TS with master...
I20260812 06:18:26.173646 25012 heartbeater.cc:507] Master 127.23.232.62:35441 requested a full tablet report, sending...
I20260812 06:18:26.174667 24818 ts_manager.cc:194] Registered new tserver with Master: f99df2b8e103490181e19544aeb9dcf3 (127.23.232.1:46493)
I20260812 06:18:26.175285 24480 internal_mini_cluster.cc:371] 1 TS(s) registered with all masters after 0.012402044s
I20260812 06:18:26.175695 24818 master_service.cc:502] Signed X509 certificate for tserver {username='slave'} at 127.0.0.1:59930
I20260812 06:18:26.184942 24818 catalog_manager.cc:2283] Servicing CreateTable request from {username='slave'} at 127.0.0.1:59938:
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:18:26.197908 24954 tablet_service.cc:1511] Processing CreateTablet for tablet b7b6b07666c24201b70acb4abcf7fb8f (DEFAULT_TABLE table=heavy-update-compaction-test [id=98de17fbab584bdfaa182eea6a5b4ef7]), partition=
I20260812 06:18:26.198325 24954 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet b7b6b07666c24201b70acb4abcf7fb8f. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:18:26.201203 25026 tablet_bootstrap.cc:492] T b7b6b07666c24201b70acb4abcf7fb8f P f99df2b8e103490181e19544aeb9dcf3: Bootstrap starting.
I20260812 06:18:26.202201 25026 tablet_bootstrap.cc:654] T b7b6b07666c24201b70acb4abcf7fb8f P f99df2b8e103490181e19544aeb9dcf3: Neither blocks nor log segments found. Creating new log.
I20260812 06:18:26.203469 25026 tablet_bootstrap.cc:492] T b7b6b07666c24201b70acb4abcf7fb8f P f99df2b8e103490181e19544aeb9dcf3: No bootstrap required, opened a new log
I20260812 06:18:26.203555 25026 ts_tablet_manager.cc:1403] T b7b6b07666c24201b70acb4abcf7fb8f P f99df2b8e103490181e19544aeb9dcf3: Time spent bootstrapping tablet: real 0.002s	user 0.000s	sys 0.002s
I20260812 06:18:26.203982 25026 raft_consensus.cc:359] T b7b6b07666c24201b70acb4abcf7fb8f P f99df2b8e103490181e19544aeb9dcf3 [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "f99df2b8e103490181e19544aeb9dcf3" member_type: VOTER last_known_addr { host: "127.23.232.1" port: 46493 } }
I20260812 06:18:26.204077 25026 raft_consensus.cc:385] T b7b6b07666c24201b70acb4abcf7fb8f P f99df2b8e103490181e19544aeb9dcf3 [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:18:26.204099 25026 raft_consensus.cc:740] T b7b6b07666c24201b70acb4abcf7fb8f P f99df2b8e103490181e19544aeb9dcf3 [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: f99df2b8e103490181e19544aeb9dcf3, State: Initialized, Role: FOLLOWER
I20260812 06:18:26.204206 25026 consensus_queue.cc:260] T b7b6b07666c24201b70acb4abcf7fb8f P f99df2b8e103490181e19544aeb9dcf3 [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: "f99df2b8e103490181e19544aeb9dcf3" member_type: VOTER last_known_addr { host: "127.23.232.1" port: 46493 } }
I20260812 06:18:26.204286 25026 raft_consensus.cc:399] T b7b6b07666c24201b70acb4abcf7fb8f P f99df2b8e103490181e19544aeb9dcf3 [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:18:26.204316 25026 raft_consensus.cc:493] T b7b6b07666c24201b70acb4abcf7fb8f P f99df2b8e103490181e19544aeb9dcf3 [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:18:26.204350 25026 raft_consensus.cc:3060] T b7b6b07666c24201b70acb4abcf7fb8f P f99df2b8e103490181e19544aeb9dcf3 [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:18:26.205097 25026 raft_consensus.cc:515] T b7b6b07666c24201b70acb4abcf7fb8f P f99df2b8e103490181e19544aeb9dcf3 [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "f99df2b8e103490181e19544aeb9dcf3" member_type: VOTER last_known_addr { host: "127.23.232.1" port: 46493 } }
I20260812 06:18:26.205219 25026 leader_election.cc:304] T b7b6b07666c24201b70acb4abcf7fb8f P f99df2b8e103490181e19544aeb9dcf3 [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: f99df2b8e103490181e19544aeb9dcf3; no voters: 
I20260812 06:18:26.205397 25026 leader_election.cc:290] T b7b6b07666c24201b70acb4abcf7fb8f P f99df2b8e103490181e19544aeb9dcf3 [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:18:26.205585 25028 raft_consensus.cc:2804] T b7b6b07666c24201b70acb4abcf7fb8f P f99df2b8e103490181e19544aeb9dcf3 [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:18:26.205695 25026 ts_tablet_manager.cc:1434] T b7b6b07666c24201b70acb4abcf7fb8f P f99df2b8e103490181e19544aeb9dcf3: Time spent starting tablet: real 0.002s	user 0.000s	sys 0.002s
I20260812 06:18:26.205735 25012 heartbeater.cc:499] Master 127.23.232.62:35441 was elected leader, sending a full tablet report...
I20260812 06:18:26.205709 25028 raft_consensus.cc:697] T b7b6b07666c24201b70acb4abcf7fb8f P f99df2b8e103490181e19544aeb9dcf3 [term 1 LEADER]: Becoming Leader. State: Replica: f99df2b8e103490181e19544aeb9dcf3, State: Running, Role: LEADER
I20260812 06:18:26.205983 25028 consensus_queue.cc:237] T b7b6b07666c24201b70acb4abcf7fb8f P f99df2b8e103490181e19544aeb9dcf3 [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: "f99df2b8e103490181e19544aeb9dcf3" member_type: VOTER last_known_addr { host: "127.23.232.1" port: 46493 } }
I20260812 06:18:26.207644 24817 catalog_manager.cc:5719] T b7b6b07666c24201b70acb4abcf7fb8f P f99df2b8e103490181e19544aeb9dcf3 reported cstate change: term changed from 0 to 1, leader changed from <none> to f99df2b8e103490181e19544aeb9dcf3 (127.23.232.1). New cstate: current_term: 1 leader_uuid: "f99df2b8e103490181e19544aeb9dcf3" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "f99df2b8e103490181e19544aeb9dcf3" member_type: VOTER last_known_addr { host: "127.23.232.1" port: 46493 } health_report { overall_health: HEALTHY } } }
I20260812 06:18:26.274431 24480 heavy-update-compaction-itest.cc:215] Time spent inserting: real 0.060s	user 0.021s	sys 0.004s
I20260812 06:18:26.414573 25013 maintenance_manager.cc:419] P f99df2b8e103490181e19544aeb9dcf3: Scheduling FlushMRSOp(b7b6b07666c24201b70acb4abcf7fb8f): perf score=15.086190
I20260812 06:18:26.558735 24918 maintenance_manager.cc:643] P f99df2b8e103490181e19544aeb9dcf3: FlushMRSOp(b7b6b07666c24201b70acb4abcf7fb8f) complete. Timing: real 0.144s	user 0.112s	sys 0.020s Metrics: {"bytes_written":11897249,"cfile_init":1,"delete_count":0,"dirs.queue_time_us":57,"dirs.run_cpu_time_us":230,"dirs.run_wall_time_us":806,"drs_written":1,"lbm_read_time_us":42,"lbm_reads_lt_1ms":4,"lbm_write_time_us":33443,"lbm_writes_lt_1ms":657,"peak_mem_usage":0,"reinsert_count":0,"rows_written":104,"spinlock_wait_cycles":896,"update_count":1450}
I20260812 06:18:26.559684 25013 maintenance_manager.cc:419] P f99df2b8e103490181e19544aeb9dcf3: Scheduling LogGCOp(b7b6b07666c24201b70acb4abcf7fb8f): free 20743880 bytes of WAL
I20260812 06:18:26.560011 24918 log_reader.cc:385] T b7b6b07666c24201b70acb4abcf7fb8f: removed 2 log segments from log reader
I20260812 06:18:26.560068 24918 log.cc:1079] T b7b6b07666c24201b70acb4abcf7fb8f P f99df2b8e103490181e19544aeb9dcf3: Deleting log segment in path: /tmp/dist-test-taskBdY18o/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515500127844-24480-0/minicluster-data/ts-0-root/wals/b7b6b07666c24201b70acb4abcf7fb8f/wal-000000001 (ops 1-6)
I20260812 06:18:26.560111 24918 log.cc:1079] T b7b6b07666c24201b70acb4abcf7fb8f P f99df2b8e103490181e19544aeb9dcf3: Deleting log segment in path: /tmp/dist-test-taskBdY18o/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515500127844-24480-0/minicluster-data/ts-0-root/wals/b7b6b07666c24201b70acb4abcf7fb8f/wal-000000002 (ops 7-11)
I20260812 06:18:26.563804 24918 maintenance_manager.cc:643] P f99df2b8e103490181e19544aeb9dcf3: LogGCOp(b7b6b07666c24201b70acb4abcf7fb8f) complete. Timing: real 0.004s	user 0.000s	sys 0.002s Metrics: {}
I20260812 06:18:26.564548 25013 maintenance_manager.cc:419] P f99df2b8e103490181e19544aeb9dcf3: Scheduling UndoDeltaBlockGCOp(b7b6b07666c24201b70acb4abcf7fb8f): 12719214 bytes on disk
I20260812 06:18:26.565121 24918 maintenance_manager.cc:643] P f99df2b8e103490181e19544aeb9dcf3: UndoDeltaBlockGCOp(b7b6b07666c24201b70acb4abcf7fb8f) 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:18:26.565605 25013 maintenance_manager.cc:419] P f99df2b8e103490181e19544aeb9dcf3: Scheduling FlushDeltaMemStoresOp(b7b6b07666c24201b70acb4abcf7fb8f): perf score=2.188937
I20260812 06:18:26.582195 24918 maintenance_manager.cc:643] P f99df2b8e103490181e19544aeb9dcf3: FlushDeltaMemStoresOp(b7b6b07666c24201b70acb4abcf7fb8f) complete. Timing: real 0.016s	user 0.007s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6506,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:26.582770 25013 maintenance_manager.cc:419] P f99df2b8e103490181e19544aeb9dcf3: Scheduling MajorDeltaCompactionOp(b7b6b07666c24201b70acb4abcf7fb8f): perf score=1.000000
I20260812 06:18:26.732241 24918 maintenance_manager.cc:643] P f99df2b8e103490181e19544aeb9dcf3: MajorDeltaCompactionOp(b7b6b07666c24201b70acb4abcf7fb8f) complete. Timing: real 0.149s	user 0.092s	sys 0.052s Metrics: {"cfile_cache_miss":422,"cfile_cache_miss_bytes":20262036,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":1660,"lbm_read_time_us":11733,"lbm_reads_lt_1ms":454,"lbm_write_time_us":23444,"lbm_writes_lt_1ms":433,"mutex_wait_us":323,"peak_mem_usage":49238594,"reinsert_count":0,"thread_start_us":507,"threads_started":5,"update_count":1950}
I20260812 06:18:26.733028 25013 maintenance_manager.cc:419] P f99df2b8e103490181e19544aeb9dcf3: Scheduling FlushDeltaMemStoresOp(b7b6b07666c24201b70acb4abcf7fb8f): perf score=11.118625
I20260812 06:18:26.787854 24918 maintenance_manager.cc:643] P f99df2b8e103490181e19544aeb9dcf3: FlushDeltaMemStoresOp(b7b6b07666c24201b70acb4abcf7fb8f) complete. Timing: real 0.055s	user 0.016s	sys 0.036s Metrics: {"bytes_written":12717735,"delete_count":0,"lbm_write_time_us":17590,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:18:26.788511 25013 maintenance_manager.cc:419] P f99df2b8e103490181e19544aeb9dcf3: Scheduling FlushDeltaMemStoresOp(b7b6b07666c24201b70acb4abcf7fb8f): perf score=2.188937
I20260812 06:18:26.805163 24918 maintenance_manager.cc:643] P f99df2b8e103490181e19544aeb9dcf3: FlushDeltaMemStoresOp(b7b6b07666c24201b70acb4abcf7fb8f) complete. Timing: real 0.016s	user 0.012s	sys 0.000s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":5570,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:18:26.805929 25013 maintenance_manager.cc:419] P f99df2b8e103490181e19544aeb9dcf3: Scheduling MajorDeltaCompactionOp(b7b6b07666c24201b70acb4abcf7fb8f): perf score=1.000000
I20260812 06:18:26.981433 24918 maintenance_manager.cc:643] P f99df2b8e103490181e19544aeb9dcf3: MajorDeltaCompactionOp(b7b6b07666c24201b70acb4abcf7fb8f) complete. Timing: real 0.175s	user 0.107s	sys 0.065s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672268,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":2037,"lbm_read_time_us":11655,"lbm_reads_lt_1ms":468,"lbm_write_time_us":27760,"lbm_writes_lt_1ms":443,"mutex_wait_us":484,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":5248,"update_count":2000}
I20260812 06:18:26.981981 25013 maintenance_manager.cc:419] P f99df2b8e103490181e19544aeb9dcf3: Scheduling FlushDeltaMemStoresOp(b7b6b07666c24201b70acb4abcf7fb8f): perf score=11.118625
I20260812 06:18:27.026242 24918 maintenance_manager.cc:643] P f99df2b8e103490181e19544aeb9dcf3: FlushDeltaMemStoresOp(b7b6b07666c24201b70acb4abcf7fb8f) complete. Timing: real 0.044s	user 0.028s	sys 0.016s Metrics: {"bytes_written":12717735,"delete_count":0,"lbm_write_time_us":20408,"lbm_writes_1-10_ms":2,"lbm_writes_lt_1ms":311,"reinsert_count":0,"update_count":1550}
I20260812 06:18:27.027146 25013 maintenance_manager.cc:419] P f99df2b8e103490181e19544aeb9dcf3: Scheduling FlushDeltaMemStoresOp(b7b6b07666c24201b70acb4abcf7fb8f): perf score=2.188937
I20260812 06:18:27.042762 24918 maintenance_manager.cc:643] P f99df2b8e103490181e19544aeb9dcf3: FlushDeltaMemStoresOp(b7b6b07666c24201b70acb4abcf7fb8f) complete. Timing: real 0.015s	user 0.009s	sys 0.006s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":5766,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:18:27.043350 25013 maintenance_manager.cc:419] P f99df2b8e103490181e19544aeb9dcf3: Scheduling MajorDeltaCompactionOp(b7b6b07666c24201b70acb4abcf7fb8f): perf score=1.000000
I20260812 06:18:27.179953 24918 maintenance_manager.cc:643] P f99df2b8e103490181e19544aeb9dcf3: MajorDeltaCompactionOp(b7b6b07666c24201b70acb4abcf7fb8f) complete. Timing: real 0.136s	user 0.103s	sys 0.033s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672268,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":1762,"lbm_read_time_us":9913,"lbm_reads_lt_1ms":464,"lbm_write_time_us":27090,"lbm_writes_lt_1ms":443,"mutex_wait_us":610,"peak_mem_usage":50689328,"reinsert_count":0,"update_count":2000}
I20260812 06:18:27.181008 25013 maintenance_manager.cc:419] P f99df2b8e103490181e19544aeb9dcf3: Scheduling FlushDeltaMemStoresOp(b7b6b07666c24201b70acb4abcf7fb8f): perf score=10.126437
I20260812 06:18:27.228410 24918 maintenance_manager.cc:643] P f99df2b8e103490181e19544aeb9dcf3: FlushDeltaMemStoresOp(b7b6b07666c24201b70acb4abcf7fb8f) complete. Timing: real 0.047s	user 0.032s	sys 0.011s Metrics: {"bytes_written":12307492,"delete_count":0,"lbm_write_time_us":19441,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":302,"reinsert_count":0,"update_count":1500}
I20260812 06:18:27.229310 25013 maintenance_manager.cc:419] P f99df2b8e103490181e19544aeb9dcf3: Scheduling FlushDeltaMemStoresOp(b7b6b07666c24201b70acb4abcf7fb8f): perf score=2.188937
I20260812 06:18:27.245411 24918 maintenance_manager.cc:643] P f99df2b8e103490181e19544aeb9dcf3: FlushDeltaMemStoresOp(b7b6b07666c24201b70acb4abcf7fb8f) complete. Timing: real 0.016s	user 0.007s	sys 0.003s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4818,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:27.246117 25013 maintenance_manager.cc:419] P f99df2b8e103490181e19544aeb9dcf3: Scheduling MajorDeltaCompactionOp(b7b6b07666c24201b70acb4abcf7fb8f): perf score=1.000000
I20260812 06:18:27.381716 24918 maintenance_manager.cc:643] P f99df2b8e103490181e19544aeb9dcf3: MajorDeltaCompactionOp(b7b6b07666c24201b70acb4abcf7fb8f) complete. Timing: real 0.135s	user 0.115s	sys 0.020s 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":892,"lbm_read_time_us":10003,"lbm_reads_lt_1ms":464,"lbm_write_time_us":26447,"lbm_writes_lt_1ms":443,"mutex_wait_us":338,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":12672,"update_count":2000}
I20260812 06:18:27.382477 25013 maintenance_manager.cc:419] P f99df2b8e103490181e19544aeb9dcf3: Scheduling FlushDeltaMemStoresOp(b7b6b07666c24201b70acb4abcf7fb8f): perf score=10.126437
I20260812 06:18:27.438802 24918 maintenance_manager.cc:643] P f99df2b8e103490181e19544aeb9dcf3: FlushDeltaMemStoresOp(b7b6b07666c24201b70acb4abcf7fb8f) complete. Timing: real 0.056s	user 0.024s	sys 0.030s Metrics: {"bytes_written":12307489,"delete_count":0,"lbm_write_time_us":18477,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:18:27.439764 25013 maintenance_manager.cc:419] P f99df2b8e103490181e19544aeb9dcf3: Scheduling FlushDeltaMemStoresOp(b7b6b07666c24201b70acb4abcf7fb8f): perf score=2.188937
I20260812 06:18:27.457604 24918 maintenance_manager.cc:643] P f99df2b8e103490181e19544aeb9dcf3: FlushDeltaMemStoresOp(b7b6b07666c24201b70acb4abcf7fb8f) complete. Timing: real 0.018s	user 0.013s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5973,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:27.458544 25013 maintenance_manager.cc:419] P f99df2b8e103490181e19544aeb9dcf3: Scheduling MajorDeltaCompactionOp(b7b6b07666c24201b70acb4abcf7fb8f): perf score=1.000000
I20260812 06:18:27.617506 24918 maintenance_manager.cc:643] P f99df2b8e103490181e19544aeb9dcf3: MajorDeltaCompactionOp(b7b6b07666c24201b70acb4abcf7fb8f) complete. Timing: real 0.159s	user 0.088s	sys 0.068s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672276,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":318,"lbm_read_time_us":14004,"lbm_reads_lt_1ms":472,"lbm_write_time_us":23936,"lbm_writes_lt_1ms":443,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":14976,"update_count":2000}
I20260812 06:18:27.618216 25013 maintenance_manager.cc:419] P f99df2b8e103490181e19544aeb9dcf3: Scheduling FlushDeltaMemStoresOp(b7b6b07666c24201b70acb4abcf7fb8f): perf score=10.126437
I20260812 06:18:27.673036 24918 maintenance_manager.cc:643] P f99df2b8e103490181e19544aeb9dcf3: FlushDeltaMemStoresOp(b7b6b07666c24201b70acb4abcf7fb8f) complete. Timing: real 0.055s	user 0.030s	sys 0.016s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":22694,"lbm_writes_1-10_ms":2,"lbm_writes_lt_1ms":301,"reinsert_count":0,"update_count":1500}
I20260812 06:18:27.673915 25013 maintenance_manager.cc:419] P f99df2b8e103490181e19544aeb9dcf3: Scheduling FlushDeltaMemStoresOp(b7b6b07666c24201b70acb4abcf7fb8f): perf score=2.188937
I20260812 06:18:27.688652 24918 maintenance_manager.cc:643] P f99df2b8e103490181e19544aeb9dcf3: FlushDeltaMemStoresOp(b7b6b07666c24201b70acb4abcf7fb8f) complete. Timing: real 0.015s	user 0.010s	sys 0.001s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5087,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:27.689154 25013 maintenance_manager.cc:419] P f99df2b8e103490181e19544aeb9dcf3: Scheduling MajorDeltaCompactionOp(b7b6b07666c24201b70acb4abcf7fb8f): perf score=1.000000
I20260812 06:18:27.853847 24918 maintenance_manager.cc:643] P f99df2b8e103490181e19544aeb9dcf3: MajorDeltaCompactionOp(b7b6b07666c24201b70acb4abcf7fb8f) complete. Timing: real 0.165s	user 0.101s	sys 0.052s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672277,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":1203,"lbm_read_time_us":8970,"lbm_reads_lt_1ms":464,"lbm_write_time_us":39567,"lbm_writes_1-10_ms":2,"lbm_writes_lt_1ms":441,"mutex_wait_us":283,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":8448,"update_count":2000}
I20260812 06:18:27.854696 25013 maintenance_manager.cc:419] P f99df2b8e103490181e19544aeb9dcf3: Scheduling FlushDeltaMemStoresOp(b7b6b07666c24201b70acb4abcf7fb8f): perf score=11.118625
I20260812 06:18:27.902962 24918 maintenance_manager.cc:643] P f99df2b8e103490181e19544aeb9dcf3: FlushDeltaMemStoresOp(b7b6b07666c24201b70acb4abcf7fb8f) complete. Timing: real 0.048s	user 0.022s	sys 0.024s Metrics: {"bytes_written":12717736,"delete_count":0,"lbm_write_time_us":20093,"lbm_writes_1-10_ms":2,"lbm_writes_lt_1ms":311,"reinsert_count":0,"update_count":1550}
I20260812 06:18:27.903865 25013 maintenance_manager.cc:419] P f99df2b8e103490181e19544aeb9dcf3: Scheduling FlushDeltaMemStoresOp(b7b6b07666c24201b70acb4abcf7fb8f): perf score=2.188937
I20260812 06:18:27.929464 24918 maintenance_manager.cc:643] P f99df2b8e103490181e19544aeb9dcf3: FlushDeltaMemStoresOp(b7b6b07666c24201b70acb4abcf7fb8f) complete. Timing: real 0.025s	user 0.008s	sys 0.004s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":5017,"lbm_writes_lt_1ms":93,"reinsert_count":0,"spinlock_wait_cycles":1408,"update_count":450}
I20260812 06:18:27.930058 25013 maintenance_manager.cc:419] P f99df2b8e103490181e19544aeb9dcf3: Scheduling FlushDeltaMemStoresOp(b7b6b07666c24201b70acb4abcf7fb8f): perf score=2.188937
I20260812 06:18:27.948938 24918 maintenance_manager.cc:643] P f99df2b8e103490181e19544aeb9dcf3: FlushDeltaMemStoresOp(b7b6b07666c24201b70acb4abcf7fb8f) complete. Timing: real 0.019s	user 0.007s	sys 0.009s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":7080,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:27.949571 25013 maintenance_manager.cc:419] P f99df2b8e103490181e19544aeb9dcf3: Scheduling FlushMRSOp(b7b6b07666c24201b70acb4abcf7fb8f): perf score=1.000000
I20260812 06:18:27.986801 24918 maintenance_manager.cc:643] P f99df2b8e103490181e19544aeb9dcf3: FlushMRSOp(b7b6b07666c24201b70acb4abcf7fb8f) complete. Timing: real 0.037s	user 0.034s	sys 0.002s Metrics: {"bytes_written":1152508,"cfile_init":1,"dirs.queue_time_us":81,"dirs.run_cpu_time_us":256,"dirs.run_wall_time_us":1217,"drs_written":1,"lbm_read_time_us":65,"lbm_reads_lt_1ms":4,"lbm_write_time_us":2550,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":28,"spinlock_wait_cycles":1792}
I20260812 06:18:27.987434 25013 maintenance_manager.cc:419] P f99df2b8e103490181e19544aeb9dcf3: Scheduling LogGCOp(b7b6b07666c24201b70acb4abcf7fb8f): free 108535453 bytes of WAL
I20260812 06:18:27.987803 24918 log_reader.cc:385] T b7b6b07666c24201b70acb4abcf7fb8f: removed 11 log segments from log reader
I20260812 06:18:27.987955 24918 log.cc:1079] T b7b6b07666c24201b70acb4abcf7fb8f P f99df2b8e103490181e19544aeb9dcf3: Deleting log segment in path: /tmp/dist-test-taskBdY18o/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515500127844-24480-0/minicluster-data/ts-0-root/wals/b7b6b07666c24201b70acb4abcf7fb8f/wal-000000003 (ops 12-16)
I20260812 06:18:27.988023 24918 log.cc:1079] T b7b6b07666c24201b70acb4abcf7fb8f P f99df2b8e103490181e19544aeb9dcf3: Deleting log segment in path: /tmp/dist-test-taskBdY18o/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515500127844-24480-0/minicluster-data/ts-0-root/wals/b7b6b07666c24201b70acb4abcf7fb8f/wal-000000004 (ops 17-20)
I20260812 06:18:27.988081 24918 log.cc:1079] T b7b6b07666c24201b70acb4abcf7fb8f P f99df2b8e103490181e19544aeb9dcf3: Deleting log segment in path: /tmp/dist-test-taskBdY18o/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515500127844-24480-0/minicluster-data/ts-0-root/wals/b7b6b07666c24201b70acb4abcf7fb8f/wal-000000005 (ops 21-25)
I20260812 06:18:27.988112 24918 log.cc:1079] T b7b6b07666c24201b70acb4abcf7fb8f P f99df2b8e103490181e19544aeb9dcf3: Deleting log segment in path: /tmp/dist-test-taskBdY18o/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515500127844-24480-0/minicluster-data/ts-0-root/wals/b7b6b07666c24201b70acb4abcf7fb8f/wal-000000006 (ops 26-30)
I20260812 06:18:27.988174 24918 log.cc:1079] T b7b6b07666c24201b70acb4abcf7fb8f P f99df2b8e103490181e19544aeb9dcf3: Deleting log segment in path: /tmp/dist-test-taskBdY18o/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515500127844-24480-0/minicluster-data/ts-0-root/wals/b7b6b07666c24201b70acb4abcf7fb8f/wal-000000007 (ops 31-35)
I20260812 06:18:27.988234 24918 log.cc:1079] T b7b6b07666c24201b70acb4abcf7fb8f P f99df2b8e103490181e19544aeb9dcf3: Deleting log segment in path: /tmp/dist-test-taskBdY18o/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515500127844-24480-0/minicluster-data/ts-0-root/wals/b7b6b07666c24201b70acb4abcf7fb8f/wal-000000008 (ops 36-40)
I20260812 06:18:27.988276 24918 log.cc:1079] T b7b6b07666c24201b70acb4abcf7fb8f P f99df2b8e103490181e19544aeb9dcf3: Deleting log segment in path: /tmp/dist-test-taskBdY18o/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515500127844-24480-0/minicluster-data/ts-0-root/wals/b7b6b07666c24201b70acb4abcf7fb8f/wal-000000009 (ops 41-44)
I20260812 06:18:27.988336 24918 log.cc:1079] T b7b6b07666c24201b70acb4abcf7fb8f P f99df2b8e103490181e19544aeb9dcf3: Deleting log segment in path: /tmp/dist-test-taskBdY18o/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515500127844-24480-0/minicluster-data/ts-0-root/wals/b7b6b07666c24201b70acb4abcf7fb8f/wal-000000010 (ops 45-49)
I20260812 06:18:27.988372 24918 log.cc:1079] T b7b6b07666c24201b70acb4abcf7fb8f P f99df2b8e103490181e19544aeb9dcf3: Deleting log segment in path: /tmp/dist-test-taskBdY18o/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515500127844-24480-0/minicluster-data/ts-0-root/wals/b7b6b07666c24201b70acb4abcf7fb8f/wal-000000011 (ops 50-54)
I20260812 06:18:27.988399 24918 log.cc:1079] T b7b6b07666c24201b70acb4abcf7fb8f P f99df2b8e103490181e19544aeb9dcf3: Deleting log segment in path: /tmp/dist-test-taskBdY18o/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515500127844-24480-0/minicluster-data/ts-0-root/wals/b7b6b07666c24201b70acb4abcf7fb8f/wal-000000012 (ops 55-59)
I20260812 06:18:27.988458 24918 log.cc:1079] T b7b6b07666c24201b70acb4abcf7fb8f P f99df2b8e103490181e19544aeb9dcf3: Deleting log segment in path: /tmp/dist-test-taskBdY18o/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515500127844-24480-0/minicluster-data/ts-0-root/wals/b7b6b07666c24201b70acb4abcf7fb8f/wal-000000013 (ops 60-64)
I20260812 06:18:28.012995 24918 maintenance_manager.cc:643] P f99df2b8e103490181e19544aeb9dcf3: LogGCOp(b7b6b07666c24201b70acb4abcf7fb8f) complete. Timing: real 0.025s	user 0.000s	sys 0.022s Metrics: {}
I20260812 06:18:28.013675 25013 maintenance_manager.cc:419] P f99df2b8e103490181e19544aeb9dcf3: Scheduling UndoDeltaBlockGCOp(b7b6b07666c24201b70acb4abcf7fb8f): 447 bytes on disk
I20260812 06:18:28.014168 24918 maintenance_manager.cc:643] P f99df2b8e103490181e19544aeb9dcf3: UndoDeltaBlockGCOp(b7b6b07666c24201b70acb4abcf7fb8f) 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:18:28.014705 25013 maintenance_manager.cc:419] P f99df2b8e103490181e19544aeb9dcf3: Scheduling FlushDeltaMemStoresOp(b7b6b07666c24201b70acb4abcf7fb8f): perf score=3.181125
I20260812 06:18:28.041723 24918 maintenance_manager.cc:643] P f99df2b8e103490181e19544aeb9dcf3: FlushDeltaMemStoresOp(b7b6b07666c24201b70acb4abcf7fb8f) complete. Timing: real 0.027s	user 0.008s	sys 0.012s Metrics: {"bytes_written":4512903,"delete_count":0,"lbm_write_time_us":7905,"lbm_writes_lt_1ms":113,"reinsert_count":0,"update_count":550}
I20260812 06:18:28.042538 25013 maintenance_manager.cc:419] P f99df2b8e103490181e19544aeb9dcf3: Scheduling FlushDeltaMemStoresOp(b7b6b07666c24201b70acb4abcf7fb8f): perf score=2.188937
I20260812 06:18:28.058766 24918 maintenance_manager.cc:643] P f99df2b8e103490181e19544aeb9dcf3: FlushDeltaMemStoresOp(b7b6b07666c24201b70acb4abcf7fb8f) complete. Timing: real 0.016s	user 0.010s	sys 0.004s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":5804,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:18:28.059844 25013 maintenance_manager.cc:419] P f99df2b8e103490181e19544aeb9dcf3: Scheduling MajorDeltaCompactionOp(b7b6b07666c24201b70acb4abcf7fb8f): perf score=1.000000
I20260812 06:18:28.278860 24918 maintenance_manager.cc:643] P f99df2b8e103490181e19544aeb9dcf3: MajorDeltaCompactionOp(b7b6b07666c24201b70acb4abcf7fb8f) complete. Timing: real 0.219s	user 0.139s	sys 0.076s Metrics: {"cfile_cache_miss":735,"cfile_cache_miss_bytes":32979851,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":5,"delta_iterators_relevant":5,"dirs.queue_time_us":864,"lbm_read_time_us":16252,"lbm_reads_lt_1ms":775,"lbm_write_time_us":43494,"lbm_writes_lt_1ms":743,"mutex_wait_us":296,"peak_mem_usage":87969044,"reinsert_count":0,"spinlock_wait_cycles":36096,"thread_start_us":84,"threads_started":1,"update_count":3500}
I20260812 06:18:28.280223 25013 maintenance_manager.cc:419] P f99df2b8e103490181e19544aeb9dcf3: Scheduling FlushDeltaMemStoresOp(b7b6b07666c24201b70acb4abcf7fb8f): perf score=14.095187
I20260812 06:18:28.336345 24918 maintenance_manager.cc:643] P f99df2b8e103490181e19544aeb9dcf3: FlushDeltaMemStoresOp(b7b6b07666c24201b70acb4abcf7fb8f) complete. Timing: real 0.056s	user 0.025s	sys 0.019s Metrics: {"bytes_written":16409950,"delete_count":0,"lbm_write_time_us":20337,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:18:28.336997 25013 maintenance_manager.cc:419] P f99df2b8e103490181e19544aeb9dcf3: Scheduling FlushDeltaMemStoresOp(b7b6b07666c24201b70acb4abcf7fb8f): perf score=2.188937
I20260812 06:18:28.363904 24918 maintenance_manager.cc:643] P f99df2b8e103490181e19544aeb9dcf3: FlushDeltaMemStoresOp(b7b6b07666c24201b70acb4abcf7fb8f) complete. Timing: real 0.027s	user 0.007s	sys 0.018s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4762,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:28.364446 25013 maintenance_manager.cc:419] P f99df2b8e103490181e19544aeb9dcf3: Scheduling MajorDeltaCompactionOp(b7b6b07666c24201b70acb4abcf7fb8f): perf score=1.000000
I20260812 06:18:28.551945 24918 maintenance_manager.cc:643] P f99df2b8e103490181e19544aeb9dcf3: MajorDeltaCompactionOp(b7b6b07666c24201b70acb4abcf7fb8f) complete. Timing: real 0.187s	user 0.123s	sys 0.064s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774737,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":408,"lbm_read_time_us":14250,"lbm_reads_lt_1ms":572,"lbm_write_time_us":31732,"lbm_writes_lt_1ms":543,"mutex_wait_us":50,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":17792,"update_count":2500}
I20260812 06:18:28.552500 25013 maintenance_manager.cc:419] P f99df2b8e103490181e19544aeb9dcf3: Scheduling FlushDeltaMemStoresOp(b7b6b07666c24201b70acb4abcf7fb8f): perf score=11.118625
I20260812 06:18:28.588191 24918 maintenance_manager.cc:643] P f99df2b8e103490181e19544aeb9dcf3: FlushDeltaMemStoresOp(b7b6b07666c24201b70acb4abcf7fb8f) complete. Timing: real 0.036s	user 0.021s	sys 0.012s Metrics: {"bytes_written":12717735,"delete_count":0,"lbm_write_time_us":15278,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:18:28.588783 25013 maintenance_manager.cc:419] P f99df2b8e103490181e19544aeb9dcf3: Scheduling FlushDeltaMemStoresOp(b7b6b07666c24201b70acb4abcf7fb8f): perf score=2.188937
I20260812 06:18:28.603327 24918 maintenance_manager.cc:643] P f99df2b8e103490181e19544aeb9dcf3: FlushDeltaMemStoresOp(b7b6b07666c24201b70acb4abcf7fb8f) complete. Timing: real 0.014s	user 0.012s	sys 0.000s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":5800,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:18:28.603775 25013 maintenance_manager.cc:419] P f99df2b8e103490181e19544aeb9dcf3: Scheduling MajorDeltaCompactionOp(b7b6b07666c24201b70acb4abcf7fb8f): perf score=1.000000
I20260812 06:18:28.742527 24918 maintenance_manager.cc:643] P f99df2b8e103490181e19544aeb9dcf3: MajorDeltaCompactionOp(b7b6b07666c24201b70acb4abcf7fb8f) complete. Timing: real 0.139s	user 0.106s	sys 0.032s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672268,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":200,"lbm_read_time_us":8938,"lbm_reads_lt_1ms":464,"lbm_write_time_us":25902,"lbm_writes_lt_1ms":443,"mutex_wait_us":44,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":55680,"update_count":2000}
I20260812 06:18:28.743160 25013 maintenance_manager.cc:419] P f99df2b8e103490181e19544aeb9dcf3: Scheduling FlushDeltaMemStoresOp(b7b6b07666c24201b70acb4abcf7fb8f): perf score=10.126437
I20260812 06:18:28.791783 24918 maintenance_manager.cc:643] P f99df2b8e103490181e19544aeb9dcf3: FlushDeltaMemStoresOp(b7b6b07666c24201b70acb4abcf7fb8f) complete. Timing: real 0.048s	user 0.011s	sys 0.024s Metrics: {"bytes_written":12307491,"delete_count":0,"lbm_write_time_us":15841,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:18:28.792429 25013 maintenance_manager.cc:419] P f99df2b8e103490181e19544aeb9dcf3: Scheduling FlushDeltaMemStoresOp(b7b6b07666c24201b70acb4abcf7fb8f): perf score=2.188937
I20260812 06:18:28.804899 24918 maintenance_manager.cc:643] P f99df2b8e103490181e19544aeb9dcf3: FlushDeltaMemStoresOp(b7b6b07666c24201b70acb4abcf7fb8f) complete. Timing: real 0.012s	user 0.010s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4338,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:28.805469 25013 maintenance_manager.cc:419] P f99df2b8e103490181e19544aeb9dcf3: Scheduling MajorDeltaCompactionOp(b7b6b07666c24201b70acb4abcf7fb8f): perf score=1.000000
I20260812 06:18:28.940475 24918 maintenance_manager.cc:643] P f99df2b8e103490181e19544aeb9dcf3: MajorDeltaCompactionOp(b7b6b07666c24201b70acb4abcf7fb8f) complete. Timing: real 0.135s	user 0.104s	sys 0.030s 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":554,"lbm_read_time_us":10906,"lbm_reads_lt_1ms":472,"lbm_write_time_us":23809,"lbm_writes_lt_1ms":443,"mutex_wait_us":64,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":959616,"update_count":2000}
I20260812 06:18:28.941439 25013 maintenance_manager.cc:419] P f99df2b8e103490181e19544aeb9dcf3: Scheduling FlushDeltaMemStoresOp(b7b6b07666c24201b70acb4abcf7fb8f): perf score=10.126437
I20260812 06:18:28.987115 24918 maintenance_manager.cc:643] P f99df2b8e103490181e19544aeb9dcf3: FlushDeltaMemStoresOp(b7b6b07666c24201b70acb4abcf7fb8f) complete. Timing: real 0.045s	user 0.020s	sys 0.020s Metrics: {"bytes_written":12307491,"delete_count":0,"lbm_write_time_us":17735,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:18:28.987950 25013 maintenance_manager.cc:419] P f99df2b8e103490181e19544aeb9dcf3: Scheduling FlushDeltaMemStoresOp(b7b6b07666c24201b70acb4abcf7fb8f): perf score=2.188937
I20260812 06:18:29.001081 24918 maintenance_manager.cc:643] P f99df2b8e103490181e19544aeb9dcf3: FlushDeltaMemStoresOp(b7b6b07666c24201b70acb4abcf7fb8f) complete. Timing: real 0.013s	user 0.007s	sys 0.003s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4395,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:29.001729 25013 maintenance_manager.cc:419] P f99df2b8e103490181e19544aeb9dcf3: Scheduling MajorDeltaCompactionOp(b7b6b07666c24201b70acb4abcf7fb8f): perf score=1.000000
I20260812 06:18:29.132519 24918 maintenance_manager.cc:643] P f99df2b8e103490181e19544aeb9dcf3: MajorDeltaCompactionOp(b7b6b07666c24201b70acb4abcf7fb8f) complete. Timing: real 0.131s	user 0.101s	sys 0.029s 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":857,"lbm_read_time_us":11142,"lbm_reads_lt_1ms":472,"lbm_write_time_us":25096,"lbm_writes_lt_1ms":443,"mutex_wait_us":63,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":38144,"update_count":2000}
I20260812 06:18:29.133095 25013 maintenance_manager.cc:419] P f99df2b8e103490181e19544aeb9dcf3: Scheduling FlushDeltaMemStoresOp(b7b6b07666c24201b70acb4abcf7fb8f): perf score=10.126437
I20260812 06:18:29.187194 24918 maintenance_manager.cc:643] P f99df2b8e103490181e19544aeb9dcf3: FlushDeltaMemStoresOp(b7b6b07666c24201b70acb4abcf7fb8f) complete. Timing: real 0.054s	user 0.018s	sys 0.023s Metrics: {"bytes_written":12307489,"delete_count":0,"lbm_write_time_us":14294,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:18:29.187865 25013 maintenance_manager.cc:419] P f99df2b8e103490181e19544aeb9dcf3: Scheduling FlushDeltaMemStoresOp(b7b6b07666c24201b70acb4abcf7fb8f): perf score=2.188937
I20260812 06:18:29.200762 24918 maintenance_manager.cc:643] P f99df2b8e103490181e19544aeb9dcf3: FlushDeltaMemStoresOp(b7b6b07666c24201b70acb4abcf7fb8f) complete. Timing: real 0.013s	user 0.003s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5136,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:29.201330 25013 maintenance_manager.cc:419] P f99df2b8e103490181e19544aeb9dcf3: Scheduling MajorDeltaCompactionOp(b7b6b07666c24201b70acb4abcf7fb8f): perf score=1.000000
I20260812 06:18:29.356968 24918 maintenance_manager.cc:643] P f99df2b8e103490181e19544aeb9dcf3: MajorDeltaCompactionOp(b7b6b07666c24201b70acb4abcf7fb8f) complete. Timing: real 0.155s	user 0.115s	sys 0.040s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672276,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":761,"lbm_read_time_us":11602,"lbm_reads_lt_1ms":472,"lbm_write_time_us":25451,"lbm_writes_lt_1ms":443,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":1408,"update_count":2000}
I20260812 06:18:29.357888 25013 maintenance_manager.cc:419] P f99df2b8e103490181e19544aeb9dcf3: Scheduling FlushDeltaMemStoresOp(b7b6b07666c24201b70acb4abcf7fb8f): perf score=10.126437
I20260812 06:18:29.408211 24918 maintenance_manager.cc:643] P f99df2b8e103490181e19544aeb9dcf3: FlushDeltaMemStoresOp(b7b6b07666c24201b70acb4abcf7fb8f) complete. Timing: real 0.050s	user 0.026s	sys 0.020s Metrics: {"bytes_written":12307492,"delete_count":0,"lbm_write_time_us":22528,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":302,"reinsert_count":0,"update_count":1500}
I20260812 06:18:29.409125 25013 maintenance_manager.cc:419] P f99df2b8e103490181e19544aeb9dcf3: Scheduling FlushDeltaMemStoresOp(b7b6b07666c24201b70acb4abcf7fb8f): perf score=2.188937
I20260812 06:18:29.429870 24918 maintenance_manager.cc:643] P f99df2b8e103490181e19544aeb9dcf3: FlushDeltaMemStoresOp(b7b6b07666c24201b70acb4abcf7fb8f) complete. Timing: real 0.020s	user 0.013s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6398,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:29.430575 25013 maintenance_manager.cc:419] P f99df2b8e103490181e19544aeb9dcf3: Scheduling FlushMRSOp(b7b6b07666c24201b70acb4abcf7fb8f): perf score=1.000000
I20260812 06:18:29.471591 24918 maintenance_manager.cc:643] P f99df2b8e103490181e19544aeb9dcf3: FlushMRSOp(b7b6b07666c24201b70acb4abcf7fb8f) complete. Timing: real 0.041s	user 0.024s	sys 0.003s Metrics: {"bytes_written":1152508,"cfile_init":1,"dirs.queue_time_us":130,"dirs.run_cpu_time_us":283,"dirs.run_wall_time_us":1340,"drs_written":1,"lbm_read_time_us":53,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1894,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":28}
I20260812 06:18:29.472458 25013 maintenance_manager.cc:419] P f99df2b8e103490181e19544aeb9dcf3: Scheduling UndoDeltaBlockGCOp(b7b6b07666c24201b70acb4abcf7fb8f): 448 bytes on disk
I20260812 06:18:29.472967 24918 maintenance_manager.cc:643] P f99df2b8e103490181e19544aeb9dcf3: UndoDeltaBlockGCOp(b7b6b07666c24201b70acb4abcf7fb8f) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":80,"lbm_reads_lt_1ms":4}
I20260812 06:18:29.473773 25013 maintenance_manager.cc:419] P f99df2b8e103490181e19544aeb9dcf3: Scheduling FlushDeltaMemStoresOp(b7b6b07666c24201b70acb4abcf7fb8f): perf score=3.181125
I20260812 06:18:29.496362 24918 maintenance_manager.cc:643] P f99df2b8e103490181e19544aeb9dcf3: FlushDeltaMemStoresOp(b7b6b07666c24201b70acb4abcf7fb8f) complete. Timing: real 0.022s	user 0.012s	sys 0.008s Metrics: {"bytes_written":4512903,"delete_count":0,"lbm_write_time_us":4705,"lbm_writes_lt_1ms":113,"reinsert_count":0,"update_count":550}
I20260812 06:18:29.497135 25013 maintenance_manager.cc:419] P f99df2b8e103490181e19544aeb9dcf3: Scheduling LogGCOp(b7b6b07666c24201b70acb4abcf7fb8f): free 124257243 bytes of WAL
I20260812 06:18:29.497391 24918 log_reader.cc:385] T b7b6b07666c24201b70acb4abcf7fb8f: removed 12 log segments from log reader
I20260812 06:18:29.497439 24918 log.cc:1079] T b7b6b07666c24201b70acb4abcf7fb8f P f99df2b8e103490181e19544aeb9dcf3: Deleting log segment in path: /tmp/dist-test-taskBdY18o/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515500127844-24480-0/minicluster-data/ts-0-root/wals/b7b6b07666c24201b70acb4abcf7fb8f/wal-000000014 (ops 65-69)
I20260812 06:18:29.497475 24918 log.cc:1079] T b7b6b07666c24201b70acb4abcf7fb8f P f99df2b8e103490181e19544aeb9dcf3: Deleting log segment in path: /tmp/dist-test-taskBdY18o/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515500127844-24480-0/minicluster-data/ts-0-root/wals/b7b6b07666c24201b70acb4abcf7fb8f/wal-000000015 (ops 70-74)
I20260812 06:18:29.497514 24918 log.cc:1079] T b7b6b07666c24201b70acb4abcf7fb8f P f99df2b8e103490181e19544aeb9dcf3: Deleting log segment in path: /tmp/dist-test-taskBdY18o/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515500127844-24480-0/minicluster-data/ts-0-root/wals/b7b6b07666c24201b70acb4abcf7fb8f/wal-000000016 (ops 75-79)
I20260812 06:18:29.497550 24918 log.cc:1079] T b7b6b07666c24201b70acb4abcf7fb8f P f99df2b8e103490181e19544aeb9dcf3: Deleting log segment in path: /tmp/dist-test-taskBdY18o/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515500127844-24480-0/minicluster-data/ts-0-root/wals/b7b6b07666c24201b70acb4abcf7fb8f/wal-000000017 (ops 80-84)
I20260812 06:18:29.497575 24918 log.cc:1079] T b7b6b07666c24201b70acb4abcf7fb8f P f99df2b8e103490181e19544aeb9dcf3: Deleting log segment in path: /tmp/dist-test-taskBdY18o/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515500127844-24480-0/minicluster-data/ts-0-root/wals/b7b6b07666c24201b70acb4abcf7fb8f/wal-000000018 (ops 85-89)
I20260812 06:18:29.497809 24918 log.cc:1079] T b7b6b07666c24201b70acb4abcf7fb8f P f99df2b8e103490181e19544aeb9dcf3: Deleting log segment in path: /tmp/dist-test-taskBdY18o/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515500127844-24480-0/minicluster-data/ts-0-root/wals/b7b6b07666c24201b70acb4abcf7fb8f/wal-000000019 (ops 90-94)
I20260812 06:18:29.497996 24918 log.cc:1079] T b7b6b07666c24201b70acb4abcf7fb8f P f99df2b8e103490181e19544aeb9dcf3: Deleting log segment in path: /tmp/dist-test-taskBdY18o/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515500127844-24480-0/minicluster-data/ts-0-root/wals/b7b6b07666c24201b70acb4abcf7fb8f/wal-000000020 (ops 95-99)
I20260812 06:18:29.498023 24918 log.cc:1079] T b7b6b07666c24201b70acb4abcf7fb8f P f99df2b8e103490181e19544aeb9dcf3: Deleting log segment in path: /tmp/dist-test-taskBdY18o/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515500127844-24480-0/minicluster-data/ts-0-root/wals/b7b6b07666c24201b70acb4abcf7fb8f/wal-000000021 (ops 100-104)
I20260812 06:18:29.498061 24918 log.cc:1079] T b7b6b07666c24201b70acb4abcf7fb8f P f99df2b8e103490181e19544aeb9dcf3: Deleting log segment in path: /tmp/dist-test-taskBdY18o/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515500127844-24480-0/minicluster-data/ts-0-root/wals/b7b6b07666c24201b70acb4abcf7fb8f/wal-000000022 (ops 105-108)
I20260812 06:18:29.498106 24918 log.cc:1079] T b7b6b07666c24201b70acb4abcf7fb8f P f99df2b8e103490181e19544aeb9dcf3: Deleting log segment in path: /tmp/dist-test-taskBdY18o/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515500127844-24480-0/minicluster-data/ts-0-root/wals/b7b6b07666c24201b70acb4abcf7fb8f/wal-000000023 (ops 109-113)
I20260812 06:18:29.498157 24918 log.cc:1079] T b7b6b07666c24201b70acb4abcf7fb8f P f99df2b8e103490181e19544aeb9dcf3: Deleting log segment in path: /tmp/dist-test-taskBdY18o/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515500127844-24480-0/minicluster-data/ts-0-root/wals/b7b6b07666c24201b70acb4abcf7fb8f/wal-000000024 (ops 114-118)
I20260812 06:18:29.498200 24918 log.cc:1079] T b7b6b07666c24201b70acb4abcf7fb8f P f99df2b8e103490181e19544aeb9dcf3: Deleting log segment in path: /tmp/dist-test-taskBdY18o/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515500127844-24480-0/minicluster-data/ts-0-root/wals/b7b6b07666c24201b70acb4abcf7fb8f/wal-000000025 (ops 119-123)
I20260812 06:18:29.524603 24918 maintenance_manager.cc:643] P f99df2b8e103490181e19544aeb9dcf3: LogGCOp(b7b6b07666c24201b70acb4abcf7fb8f) complete. Timing: real 0.027s	user 0.000s	sys 0.024s Metrics: {}
I20260812 06:18:29.525610 25013 maintenance_manager.cc:419] P f99df2b8e103490181e19544aeb9dcf3: Scheduling FlushDeltaMemStoresOp(b7b6b07666c24201b70acb4abcf7fb8f): perf score=2.188937
I20260812 06:18:29.539942 24918 maintenance_manager.cc:643] P f99df2b8e103490181e19544aeb9dcf3: FlushDeltaMemStoresOp(b7b6b07666c24201b70acb4abcf7fb8f) complete. Timing: real 0.014s	user 0.006s	sys 0.006s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":5134,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:18:29.540653 25013 maintenance_manager.cc:419] P f99df2b8e103490181e19544aeb9dcf3: Scheduling MajorDeltaCompactionOp(b7b6b07666c24201b70acb4abcf7fb8f): perf score=1.000000
I20260812 06:18:29.733100 24918 maintenance_manager.cc:643] P f99df2b8e103490181e19544aeb9dcf3: MajorDeltaCompactionOp(b7b6b07666c24201b70acb4abcf7fb8f) complete. Timing: real 0.192s	user 0.135s	sys 0.057s Metrics: {"cfile_cache_miss":634,"cfile_cache_miss_bytes":28877331,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":348,"lbm_read_time_us":12452,"lbm_reads_lt_1ms":670,"lbm_write_time_us":32962,"lbm_writes_lt_1ms":643,"mutex_wait_us":309,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":3200,"thread_start_us":84,"threads_started":1,"update_count":3000}
I20260812 06:18:29.733891 25013 maintenance_manager.cc:419] P f99df2b8e103490181e19544aeb9dcf3: Scheduling FlushDeltaMemStoresOp(b7b6b07666c24201b70acb4abcf7fb8f): perf score=14.095187
I20260812 06:18:29.796985 24918 maintenance_manager.cc:643] P f99df2b8e103490181e19544aeb9dcf3: FlushDeltaMemStoresOp(b7b6b07666c24201b70acb4abcf7fb8f) complete. Timing: real 0.062s	user 0.048s	sys 0.008s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":22519,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:18:29.797578 25013 maintenance_manager.cc:419] P f99df2b8e103490181e19544aeb9dcf3: Scheduling FlushDeltaMemStoresOp(b7b6b07666c24201b70acb4abcf7fb8f): perf score=2.188937
I20260812 06:18:29.813612 24918 maintenance_manager.cc:643] P f99df2b8e103490181e19544aeb9dcf3: FlushDeltaMemStoresOp(b7b6b07666c24201b70acb4abcf7fb8f) complete. Timing: real 0.016s	user 0.005s	sys 0.005s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4413,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:29.814320 25013 maintenance_manager.cc:419] P f99df2b8e103490181e19544aeb9dcf3: Scheduling MajorDeltaCompactionOp(b7b6b07666c24201b70acb4abcf7fb8f): perf score=1.000000
I20260812 06:18:30.001928 24918 maintenance_manager.cc:643] P f99df2b8e103490181e19544aeb9dcf3: MajorDeltaCompactionOp(b7b6b07666c24201b70acb4abcf7fb8f) complete. Timing: real 0.187s	user 0.122s	sys 0.063s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774689,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":1618,"lbm_read_time_us":11309,"lbm_reads_lt_1ms":564,"lbm_write_time_us":30756,"lbm_writes_lt_1ms":543,"mutex_wait_us":549,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":58368,"update_count":2500}
I20260812 06:18:30.002763 25013 maintenance_manager.cc:419] P f99df2b8e103490181e19544aeb9dcf3: Scheduling FlushDeltaMemStoresOp(b7b6b07666c24201b70acb4abcf7fb8f): perf score=14.095187
I20260812 06:18:30.044034 24918 maintenance_manager.cc:643] P f99df2b8e103490181e19544aeb9dcf3: FlushDeltaMemStoresOp(b7b6b07666c24201b70acb4abcf7fb8f) complete. Timing: real 0.041s	user 0.022s	sys 0.017s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":18049,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:18:30.044523 25013 maintenance_manager.cc:419] P f99df2b8e103490181e19544aeb9dcf3: Scheduling FlushDeltaMemStoresOp(b7b6b07666c24201b70acb4abcf7fb8f): perf score=2.188937
I20260812 06:18:30.068667 24918 maintenance_manager.cc:643] P f99df2b8e103490181e19544aeb9dcf3: FlushDeltaMemStoresOp(b7b6b07666c24201b70acb4abcf7fb8f) complete. Timing: real 0.024s	user 0.009s	sys 0.009s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6120,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:30.069499 25013 maintenance_manager.cc:419] P f99df2b8e103490181e19544aeb9dcf3: Scheduling MajorDeltaCompactionOp(b7b6b07666c24201b70acb4abcf7fb8f): perf score=1.000000
I20260812 06:18:30.266074 24918 maintenance_manager.cc:643] P f99df2b8e103490181e19544aeb9dcf3: MajorDeltaCompactionOp(b7b6b07666c24201b70acb4abcf7fb8f) complete. Timing: real 0.196s	user 0.119s	sys 0.073s 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":1131,"lbm_read_time_us":13208,"lbm_reads_lt_1ms":572,"lbm_write_time_us":31994,"lbm_writes_lt_1ms":543,"mutex_wait_us":473,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":8320,"update_count":2500}
I20260812 06:18:30.266721 25013 maintenance_manager.cc:419] P f99df2b8e103490181e19544aeb9dcf3: Scheduling FlushDeltaMemStoresOp(b7b6b07666c24201b70acb4abcf7fb8f): perf score=14.095187
I20260812 06:18:30.321154 24918 maintenance_manager.cc:643] P f99df2b8e103490181e19544aeb9dcf3: FlushDeltaMemStoresOp(b7b6b07666c24201b70acb4abcf7fb8f) complete. Timing: real 0.054s	user 0.029s	sys 0.020s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":25166,"lbm_writes_1-10_ms":2,"lbm_writes_lt_1ms":401,"reinsert_count":0,"update_count":2000}
I20260812 06:18:30.321985 25013 maintenance_manager.cc:419] P f99df2b8e103490181e19544aeb9dcf3: Scheduling FlushDeltaMemStoresOp(b7b6b07666c24201b70acb4abcf7fb8f): perf score=2.188937
I20260812 06:18:30.333386 24918 maintenance_manager.cc:643] P f99df2b8e103490181e19544aeb9dcf3: FlushDeltaMemStoresOp(b7b6b07666c24201b70acb4abcf7fb8f) complete. Timing: real 0.011s	user 0.008s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3783,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:30.334432 25013 maintenance_manager.cc:419] P f99df2b8e103490181e19544aeb9dcf3: Scheduling MajorDeltaCompactionOp(b7b6b07666c24201b70acb4abcf7fb8f): perf score=1.000000
I20260812 06:18:30.497138 24918 maintenance_manager.cc:643] P f99df2b8e103490181e19544aeb9dcf3: MajorDeltaCompactionOp(b7b6b07666c24201b70acb4abcf7fb8f) complete. Timing: real 0.162s	user 0.114s	sys 0.048s 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":236,"lbm_read_time_us":12430,"lbm_reads_lt_1ms":572,"lbm_write_time_us":31675,"lbm_writes_lt_1ms":543,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":6912,"update_count":2500}
I20260812 06:18:30.497759 25013 maintenance_manager.cc:419] P f99df2b8e103490181e19544aeb9dcf3: Scheduling FlushDeltaMemStoresOp(b7b6b07666c24201b70acb4abcf7fb8f): perf score=11.118625
I20260812 06:18:30.540668 24918 maintenance_manager.cc:643] P f99df2b8e103490181e19544aeb9dcf3: FlushDeltaMemStoresOp(b7b6b07666c24201b70acb4abcf7fb8f) complete. Timing: real 0.043s	user 0.019s	sys 0.021s Metrics: {"bytes_written":12717735,"delete_count":0,"lbm_write_time_us":17362,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:18:30.541278 25013 maintenance_manager.cc:419] P f99df2b8e103490181e19544aeb9dcf3: Scheduling FlushDeltaMemStoresOp(b7b6b07666c24201b70acb4abcf7fb8f): perf score=2.188937
I20260812 06:18:30.559988 24918 maintenance_manager.cc:643] P f99df2b8e103490181e19544aeb9dcf3: FlushDeltaMemStoresOp(b7b6b07666c24201b70acb4abcf7fb8f) complete. Timing: real 0.018s	user 0.013s	sys 0.000s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":5363,"lbm_writes_lt_1ms":93,"reinsert_count":0,"spinlock_wait_cycles":2816,"update_count":450}
I20260812 06:18:30.560673 25013 maintenance_manager.cc:419] P f99df2b8e103490181e19544aeb9dcf3: Scheduling MajorDeltaCompactionOp(b7b6b07666c24201b70acb4abcf7fb8f): perf score=1.000000
I20260812 06:18:30.688818 24918 maintenance_manager.cc:643] P f99df2b8e103490181e19544aeb9dcf3: MajorDeltaCompactionOp(b7b6b07666c24201b70acb4abcf7fb8f) complete. Timing: real 0.128s	user 0.096s	sys 0.031s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672268,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":1210,"lbm_read_time_us":9116,"lbm_reads_lt_1ms":464,"lbm_write_time_us":22239,"lbm_writes_lt_1ms":443,"mutex_wait_us":286,"peak_mem_usage":50689328,"reinsert_count":0,"update_count":2000}
I20260812 06:18:30.689517 25013 maintenance_manager.cc:419] P f99df2b8e103490181e19544aeb9dcf3: Scheduling FlushDeltaMemStoresOp(b7b6b07666c24201b70acb4abcf7fb8f): perf score=10.126437
I20260812 06:18:30.734606 24918 maintenance_manager.cc:643] P f99df2b8e103490181e19544aeb9dcf3: FlushDeltaMemStoresOp(b7b6b07666c24201b70acb4abcf7fb8f) complete. Timing: real 0.045s	user 0.032s	sys 0.005s Metrics: {"bytes_written":12307491,"delete_count":0,"lbm_write_time_us":16775,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:18:30.735199 25013 maintenance_manager.cc:419] P f99df2b8e103490181e19544aeb9dcf3: Scheduling FlushDeltaMemStoresOp(b7b6b07666c24201b70acb4abcf7fb8f): perf score=2.188937
I20260812 06:18:30.747013 24918 maintenance_manager.cc:643] P f99df2b8e103490181e19544aeb9dcf3: FlushDeltaMemStoresOp(b7b6b07666c24201b70acb4abcf7fb8f) complete. Timing: real 0.012s	user 0.009s	sys 0.001s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4163,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:30.747570 25013 maintenance_manager.cc:419] P f99df2b8e103490181e19544aeb9dcf3: Scheduling MajorDeltaCompactionOp(b7b6b07666c24201b70acb4abcf7fb8f): perf score=1.000000
I20260812 06:18:30.875444 24918 maintenance_manager.cc:643] P f99df2b8e103490181e19544aeb9dcf3: MajorDeltaCompactionOp(b7b6b07666c24201b70acb4abcf7fb8f) complete. Timing: real 0.128s	user 0.110s	sys 0.017s 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":2131,"lbm_read_time_us":10441,"lbm_reads_lt_1ms":472,"lbm_write_time_us":22277,"lbm_writes_lt_1ms":443,"mutex_wait_us":542,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":5504,"update_count":2000}
I20260812 06:18:30.876119 25013 maintenance_manager.cc:419] P f99df2b8e103490181e19544aeb9dcf3: Scheduling FlushDeltaMemStoresOp(b7b6b07666c24201b70acb4abcf7fb8f): perf score=10.126437
I20260812 06:18:30.927971 24918 maintenance_manager.cc:643] P f99df2b8e103490181e19544aeb9dcf3: FlushDeltaMemStoresOp(b7b6b07666c24201b70acb4abcf7fb8f) complete. Timing: real 0.052s	user 0.018s	sys 0.019s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":13159,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:18:30.928617 25013 maintenance_manager.cc:419] P f99df2b8e103490181e19544aeb9dcf3: Scheduling FlushDeltaMemStoresOp(b7b6b07666c24201b70acb4abcf7fb8f): perf score=2.188937
I20260812 06:18:30.939826 24918 maintenance_manager.cc:643] P f99df2b8e103490181e19544aeb9dcf3: FlushDeltaMemStoresOp(b7b6b07666c24201b70acb4abcf7fb8f) complete. Timing: real 0.011s	user 0.002s	sys 0.007s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4225,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:30.940564 25013 maintenance_manager.cc:419] P f99df2b8e103490181e19544aeb9dcf3: Scheduling FlushMRSOp(b7b6b07666c24201b70acb4abcf7fb8f): perf score=1.000000
I20260812 06:18:30.983255 24918 maintenance_manager.cc:643] P f99df2b8e103490181e19544aeb9dcf3: FlushMRSOp(b7b6b07666c24201b70acb4abcf7fb8f) complete. Timing: real 0.043s	user 0.025s	sys 0.004s Metrics: {"bytes_written":1152510,"cfile_init":1,"dirs.queue_time_us":61,"dirs.run_cpu_time_us":229,"dirs.run_wall_time_us":1153,"drs_written":1,"lbm_read_time_us":47,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1980,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":28}
I20260812 06:18:30.984026 25013 maintenance_manager.cc:419] P f99df2b8e103490181e19544aeb9dcf3: Scheduling LogGCOp(b7b6b07666c24201b70acb4abcf7fb8f): free 112692591 bytes of WAL
I20260812 06:18:30.984242 24918 log_reader.cc:385] T b7b6b07666c24201b70acb4abcf7fb8f: removed 11 log segments from log reader
I20260812 06:18:30.984287 24918 log.cc:1079] T b7b6b07666c24201b70acb4abcf7fb8f P f99df2b8e103490181e19544aeb9dcf3: Deleting log segment in path: /tmp/dist-test-taskBdY18o/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515500127844-24480-0/minicluster-data/ts-0-root/wals/b7b6b07666c24201b70acb4abcf7fb8f/wal-000000026 (ops 124-128)
I20260812 06:18:30.984316 24918 log.cc:1079] T b7b6b07666c24201b70acb4abcf7fb8f P f99df2b8e103490181e19544aeb9dcf3: Deleting log segment in path: /tmp/dist-test-taskBdY18o/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515500127844-24480-0/minicluster-data/ts-0-root/wals/b7b6b07666c24201b70acb4abcf7fb8f/wal-000000027 (ops 129-133)
I20260812 06:18:30.984345 24918 log.cc:1079] T b7b6b07666c24201b70acb4abcf7fb8f P f99df2b8e103490181e19544aeb9dcf3: Deleting log segment in path: /tmp/dist-test-taskBdY18o/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515500127844-24480-0/minicluster-data/ts-0-root/wals/b7b6b07666c24201b70acb4abcf7fb8f/wal-000000028 (ops 134-138)
I20260812 06:18:30.984377 24918 log.cc:1079] T b7b6b07666c24201b70acb4abcf7fb8f P f99df2b8e103490181e19544aeb9dcf3: Deleting log segment in path: /tmp/dist-test-taskBdY18o/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515500127844-24480-0/minicluster-data/ts-0-root/wals/b7b6b07666c24201b70acb4abcf7fb8f/wal-000000029 (ops 139-143)
I20260812 06:18:30.984411 24918 log.cc:1079] T b7b6b07666c24201b70acb4abcf7fb8f P f99df2b8e103490181e19544aeb9dcf3: Deleting log segment in path: /tmp/dist-test-taskBdY18o/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515500127844-24480-0/minicluster-data/ts-0-root/wals/b7b6b07666c24201b70acb4abcf7fb8f/wal-000000030 (ops 144-148)
I20260812 06:18:30.984443 24918 log.cc:1079] T b7b6b07666c24201b70acb4abcf7fb8f P f99df2b8e103490181e19544aeb9dcf3: Deleting log segment in path: /tmp/dist-test-taskBdY18o/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515500127844-24480-0/minicluster-data/ts-0-root/wals/b7b6b07666c24201b70acb4abcf7fb8f/wal-000000031 (ops 149-153)
I20260812 06:18:30.984475 24918 log.cc:1079] T b7b6b07666c24201b70acb4abcf7fb8f P f99df2b8e103490181e19544aeb9dcf3: Deleting log segment in path: /tmp/dist-test-taskBdY18o/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515500127844-24480-0/minicluster-data/ts-0-root/wals/b7b6b07666c24201b70acb4abcf7fb8f/wal-000000032 (ops 154-158)
I20260812 06:18:30.984508 24918 log.cc:1079] T b7b6b07666c24201b70acb4abcf7fb8f P f99df2b8e103490181e19544aeb9dcf3: Deleting log segment in path: /tmp/dist-test-taskBdY18o/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515500127844-24480-0/minicluster-data/ts-0-root/wals/b7b6b07666c24201b70acb4abcf7fb8f/wal-000000033 (ops 159-163)
I20260812 06:18:30.984540 24918 log.cc:1079] T b7b6b07666c24201b70acb4abcf7fb8f P f99df2b8e103490181e19544aeb9dcf3: Deleting log segment in path: /tmp/dist-test-taskBdY18o/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515500127844-24480-0/minicluster-data/ts-0-root/wals/b7b6b07666c24201b70acb4abcf7fb8f/wal-000000034 (ops 164-168)
I20260812 06:18:30.984572 24918 log.cc:1079] T b7b6b07666c24201b70acb4abcf7fb8f P f99df2b8e103490181e19544aeb9dcf3: Deleting log segment in path: /tmp/dist-test-taskBdY18o/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515500127844-24480-0/minicluster-data/ts-0-root/wals/b7b6b07666c24201b70acb4abcf7fb8f/wal-000000035 (ops 169-173)
I20260812 06:18:30.984606 24918 log.cc:1079] T b7b6b07666c24201b70acb4abcf7fb8f P f99df2b8e103490181e19544aeb9dcf3: Deleting log segment in path: /tmp/dist-test-taskBdY18o/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515500127844-24480-0/minicluster-data/ts-0-root/wals/b7b6b07666c24201b70acb4abcf7fb8f/wal-000000036 (ops 174-178)
I20260812 06:18:31.007597 24918 maintenance_manager.cc:643] P f99df2b8e103490181e19544aeb9dcf3: LogGCOp(b7b6b07666c24201b70acb4abcf7fb8f) complete. Timing: real 0.023s	user 0.000s	sys 0.022s Metrics: {}
I20260812 06:18:31.008005 25013 maintenance_manager.cc:419] P f99df2b8e103490181e19544aeb9dcf3: Scheduling UndoDeltaBlockGCOp(b7b6b07666c24201b70acb4abcf7fb8f): 446 bytes on disk
I20260812 06:18:31.008698 24918 maintenance_manager.cc:643] P f99df2b8e103490181e19544aeb9dcf3: UndoDeltaBlockGCOp(b7b6b07666c24201b70acb4abcf7fb8f) complete. Timing: real 0.001s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":61,"lbm_reads_lt_1ms":4}
I20260812 06:18:31.010290 25013 maintenance_manager.cc:419] P f99df2b8e103490181e19544aeb9dcf3: Scheduling FlushDeltaMemStoresOp(b7b6b07666c24201b70acb4abcf7fb8f): perf score=3.181125
I20260812 06:18:31.043264 24918 maintenance_manager.cc:643] P f99df2b8e103490181e19544aeb9dcf3: FlushDeltaMemStoresOp(b7b6b07666c24201b70acb4abcf7fb8f) complete. Timing: real 0.033s	user 0.015s	sys 0.001s Metrics: {"bytes_written":4348807,"delete_count":0,"lbm_write_time_us":6397,"lbm_writes_lt_1ms":109,"reinsert_count":0,"update_count":530}
I20260812 06:18:31.043959 25013 maintenance_manager.cc:419] P f99df2b8e103490181e19544aeb9dcf3: Scheduling FlushDeltaMemStoresOp(b7b6b07666c24201b70acb4abcf7fb8f): perf score=2.188937
I20260812 06:18:31.060078 24918 maintenance_manager.cc:643] P f99df2b8e103490181e19544aeb9dcf3: FlushDeltaMemStoresOp(b7b6b07666c24201b70acb4abcf7fb8f) complete. Timing: real 0.016s	user 0.010s	sys 0.004s Metrics: {"bytes_written":3856509,"delete_count":0,"lbm_write_time_us":5601,"lbm_writes_lt_1ms":97,"reinsert_count":0,"update_count":470}
I20260812 06:18:31.060808 25013 maintenance_manager.cc:419] P f99df2b8e103490181e19544aeb9dcf3: Scheduling MajorDeltaCompactionOp(b7b6b07666c24201b70acb4abcf7fb8f): perf score=1.000000
I20260812 06:18:31.256443 24918 maintenance_manager.cc:643] P f99df2b8e103490181e19544aeb9dcf3: MajorDeltaCompactionOp(b7b6b07666c24201b70acb4abcf7fb8f) complete. Timing: real 0.195s	user 0.144s	sys 0.051s Metrics: {"cfile_cache_miss":634,"cfile_cache_miss_bytes":28877337,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":804,"lbm_read_time_us":13745,"lbm_reads_lt_1ms":674,"lbm_write_time_us":30790,"lbm_writes_lt_1ms":643,"mutex_wait_us":272,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":1792,"thread_start_us":85,"threads_started":1,"update_count":3000}
I20260812 06:18:31.257879 25013 maintenance_manager.cc:419] P f99df2b8e103490181e19544aeb9dcf3: Scheduling FlushDeltaMemStoresOp(b7b6b07666c24201b70acb4abcf7fb8f): perf score=14.095187
I20260812 06:18:31.320741 24918 maintenance_manager.cc:643] P f99df2b8e103490181e19544aeb9dcf3: FlushDeltaMemStoresOp(b7b6b07666c24201b70acb4abcf7fb8f) complete. Timing: real 0.063s	user 0.022s	sys 0.025s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":21611,"lbm_writes_1-10_ms":2,"lbm_writes_lt_1ms":401,"reinsert_count":0,"update_count":2000}
I20260812 06:18:31.321503 25013 maintenance_manager.cc:419] P f99df2b8e103490181e19544aeb9dcf3: Scheduling FlushDeltaMemStoresOp(b7b6b07666c24201b70acb4abcf7fb8f): perf score=2.188937
I20260812 06:18:31.332078 24918 maintenance_manager.cc:643] P f99df2b8e103490181e19544aeb9dcf3: FlushDeltaMemStoresOp(b7b6b07666c24201b70acb4abcf7fb8f) complete. Timing: real 0.010s	user 0.004s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3691,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:31.332705 25013 maintenance_manager.cc:419] P f99df2b8e103490181e19544aeb9dcf3: Scheduling MajorDeltaCompactionOp(b7b6b07666c24201b70acb4abcf7fb8f): perf score=1.000000
I20260812 06:18:31.528934 24918 maintenance_manager.cc:643] P f99df2b8e103490181e19544aeb9dcf3: MajorDeltaCompactionOp(b7b6b07666c24201b70acb4abcf7fb8f) complete. Timing: real 0.196s	user 0.145s	sys 0.038s 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":352,"lbm_read_time_us":12219,"lbm_reads_lt_1ms":572,"lbm_write_time_us":32490,"lbm_writes_lt_1ms":543,"mutex_wait_us":45,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":690560,"update_count":2500}
I20260812 06:18:31.529579 25013 maintenance_manager.cc:419] P f99df2b8e103490181e19544aeb9dcf3: Scheduling FlushDeltaMemStoresOp(b7b6b07666c24201b70acb4abcf7fb8f): perf score=14.095187
I20260812 06:18:31.582113 24480 heavy-update-compaction-itest.cc:229] Time spent updating: real 5.308s	user 1.886s	sys 0.152s
I20260812 06:18:31.596236 24918 maintenance_manager.cc:643] P f99df2b8e103490181e19544aeb9dcf3: FlushDeltaMemStoresOp(b7b6b07666c24201b70acb4abcf7fb8f) complete. Timing: real 0.066s	user 0.035s	sys 0.027s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":24243,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:18:31.597061 25013 maintenance_manager.cc:419] P f99df2b8e103490181e19544aeb9dcf3: Scheduling FlushDeltaMemStoresOp(b7b6b07666c24201b70acb4abcf7fb8f): perf score=2.188937
I20260812 06:18:31.613937 24918 maintenance_manager.cc:643] P f99df2b8e103490181e19544aeb9dcf3: FlushDeltaMemStoresOp(b7b6b07666c24201b70acb4abcf7fb8f) complete. Timing: real 0.017s	user 0.007s	sys 0.009s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6604,"lbm_writes_lt_1ms":103,"reinsert_count":0,"spinlock_wait_cycles":3072,"update_count":500}
I20260812 06:18:31.614833 25013 maintenance_manager.cc:419] P f99df2b8e103490181e19544aeb9dcf3: Scheduling MajorDeltaCompactionOp(b7b6b07666c24201b70acb4abcf7fb8f): perf score=1.000000
I20260812 06:18:31.687134 24480 heavy-update-compaction-itest.cc:265] Time spent scanning: real 0.104s	user 0.002s	sys 0.000s
I20260812 06:18:31.687660 24480 tablet_server.cc:179] TabletServer@127.23.232.1:0 shutting down...
I20260812 06:18:31.764217 24918 maintenance_manager.cc:643] P f99df2b8e103490181e19544aeb9dcf3: MajorDeltaCompactionOp(b7b6b07666c24201b70acb4abcf7fb8f) complete. Timing: real 0.149s	user 0.115s	sys 0.034s Metrics: {"cfile_cache_hit":267,"cfile_cache_hit_bytes":10914294,"cfile_cache_miss":265,"cfile_cache_miss_bytes":13860395,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":346,"lbm_read_time_us":10094,"lbm_reads_lt_1ms":297,"lbm_write_time_us":26396,"lbm_writes_lt_1ms":543,"mutex_wait_us":30,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":105088,"update_count":2500}
I20260812 06:18:31.764987 24480 ts_tablet_manager.cc:1507] Shutting down tablet manager...
I20260812 06:18:31.765225 24480 tablet_replica.cc:333] T b7b6b07666c24201b70acb4abcf7fb8f P f99df2b8e103490181e19544aeb9dcf3: stopping tablet replica
I20260812 06:18:31.765384 24480 raft_consensus.cc:2243] T b7b6b07666c24201b70acb4abcf7fb8f P f99df2b8e103490181e19544aeb9dcf3 [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:18:31.765545 24480 raft_consensus.cc:2272] T b7b6b07666c24201b70acb4abcf7fb8f P f99df2b8e103490181e19544aeb9dcf3 [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:18:31.781764 24480 tablet_server.cc:196] TabletServer@127.23.232.1:0 shutdown complete.
I20260812 06:18:31.810591 24480 master.cc:562] Master@127.23.232.62:35441 shutting down...
I20260812 06:18:31.815013 24480 raft_consensus.cc:2243] T 00000000000000000000000000000000 P 4b0da8073900484caee269dbbbc4522a [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:18:31.815269 24480 raft_consensus.cc:2272] T 00000000000000000000000000000000 P 4b0da8073900484caee269dbbbc4522a [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:18:31.815354 24480 tablet_replica.cc:333] T 00000000000000000000000000000000 P 4b0da8073900484caee269dbbbc4522a: stopping tablet replica
I20260812 06:18:31.828265 24480 master.cc:584] Master@127.23.232.62:35441 shutdown complete.
[       OK ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/1 (5853 ms)
[----------] 2 tests from EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy (11772 ms total)

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