[==========] Running 2 tests from 1 test suite.
[----------] Global test environment set-up.
[----------] 2 tests from EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy
[ RUN      ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/0
WARNING: Logging before InitGoogleLogging() is written to STDERR
I20260812 06:19:27.144430  9529 internal_mini_cluster.cc:156] Creating distributed mini masters. Addrs: 127.9.78.126:34333
I20260812 06:19:27.145499  9529 env_posix.cc:2285] Not raising this process' open files per process limit of 1048576; it is already as high as it can go
I20260812 06:19:27.146098  9529 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:19:27.152499  9535 instance_detector.cc:116] could not retrieve AWS instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:19:27.152516  9539 instance_detector.cc:116] could not retrieve OpenStack instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:19:27.152745  9536 instance_detector.cc:116] could not retrieve Azure instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:19:27.152725  9529 server_base.cc:1061] running on GCE node
I20260812 06:19:27.153273  9529 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:19:27.153371  9529 system_unsync_time.cc:38] NTP support is disabled. Clock error bounds will not be accurate. This configuration is not suitable for distributed clusters.
I20260812 06:19:27.153421  9529 hybrid_clock.cc:648] HybridClock initialized: now 1786515567153419 us; error 0 us; skew 500 ppm
I20260812 06:19:27.155189  9529 webserver.cc:533] Webserver started at http://127.9.78.126:43689/ using document root <none> and password file <none>
I20260812 06:19:27.155742  9529 fs_manager.cc:362] Metadata directory not provided
I20260812 06:19:27.155802  9529 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:19:27.156042  9529 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:19:27.157826  9529 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskWwnqpJ/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515567133744-9529-0/minicluster-data/master-0-root/instance:
uuid: "1e76a7d00d214a98aa3dc6ff29aa78f9"
format_stamp: "Formatted at 2026-08-12 06:19:27 on dist-test-slave-s11t"
I20260812 06:19:27.161399  9529 fs_manager.cc:696] Time spent creating directory manager: real 0.003s	user 0.004s	sys 0.000s
I20260812 06:19:27.163589  9548 log_block_manager.cc:4127] Time spent loading block containers with low live blocks: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:19:27.164808  9529 fs_manager.cc:730] Time spent opening block manager: real 0.002s	user 0.003s	sys 0.000s
I20260812 06:19:27.164944  9529 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskWwnqpJ/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515567133744-9529-0/minicluster-data/master-0-root
uuid: "1e76a7d00d214a98aa3dc6ff29aa78f9"
format_stamp: "Formatted at 2026-08-12 06:19:27 on dist-test-slave-s11t"
I20260812 06:19:27.165061  9529 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskWwnqpJ/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515567133744-9529-0/minicluster-data/master-0-root
metadata directory: /tmp/dist-test-taskWwnqpJ/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515567133744-9529-0/minicluster-data/master-0-root
1 data directories: /tmp/dist-test-taskWwnqpJ/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515567133744-9529-0/minicluster-data/master-0-root/data
Total live blocks: 0
Total live bytes: 0
Total live bytes (after alignment): 0
Total number of LBM containers: 0 (0 full)
Did not check for missing blocks
Did not check for orphaned blocks
Total full LBM containers with extra space: 0 (0 repaired)
Total full LBM container extra space in bytes: 0 (0 repaired)
Total incomplete LBM containers: 0 (0 repaired)
Total LBM partial records: 0 (0 repaired)
Total corrupted LBM metadata records in RocksDB: 0 (0 repaired)
I20260812 06:19:27.173861  9529 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:19:27.174455  9529 env_posix.cc:2285] Not raising this process' running threads per effective uid limit of 18446744073709551615; it is already as high as it can go
I20260812 06:19:27.174631  9529 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:19:27.182361  9529 rpc_server.cc:307] RPC server started. Bound to: 127.9.78.126:34333
I20260812 06:19:27.182379  9638 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.9.78.126:34333 every 8 connection(s)
I20260812 06:19:27.184625  9639 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet 00000000000000000000000000000000. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:19:27.190023  9639 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P 1e76a7d00d214a98aa3dc6ff29aa78f9: Bootstrap starting.
I20260812 06:19:27.192298  9639 tablet_bootstrap.cc:654] T 00000000000000000000000000000000 P 1e76a7d00d214a98aa3dc6ff29aa78f9: Neither blocks nor log segments found. Creating new log.
I20260812 06:19:27.193244  9639 log.cc:826] T 00000000000000000000000000000000 P 1e76a7d00d214a98aa3dc6ff29aa78f9: Log is configured to *not* fsync() on all Append() calls
I20260812 06:19:27.194849  9639 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P 1e76a7d00d214a98aa3dc6ff29aa78f9: No bootstrap required, opened a new log
I20260812 06:19:27.197566  9639 raft_consensus.cc:359] T 00000000000000000000000000000000 P 1e76a7d00d214a98aa3dc6ff29aa78f9 [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "1e76a7d00d214a98aa3dc6ff29aa78f9" member_type: VOTER }
I20260812 06:19:27.197736  9639 raft_consensus.cc:385] T 00000000000000000000000000000000 P 1e76a7d00d214a98aa3dc6ff29aa78f9 [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:19:27.197788  9639 raft_consensus.cc:740] T 00000000000000000000000000000000 P 1e76a7d00d214a98aa3dc6ff29aa78f9 [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: 1e76a7d00d214a98aa3dc6ff29aa78f9, State: Initialized, Role: FOLLOWER
I20260812 06:19:27.198407  9639 consensus_queue.cc:260] T 00000000000000000000000000000000 P 1e76a7d00d214a98aa3dc6ff29aa78f9 [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: "1e76a7d00d214a98aa3dc6ff29aa78f9" member_type: VOTER }
I20260812 06:19:27.198549  9639 raft_consensus.cc:399] T 00000000000000000000000000000000 P 1e76a7d00d214a98aa3dc6ff29aa78f9 [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:19:27.198598  9639 raft_consensus.cc:493] T 00000000000000000000000000000000 P 1e76a7d00d214a98aa3dc6ff29aa78f9 [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:19:27.198681  9639 raft_consensus.cc:3060] T 00000000000000000000000000000000 P 1e76a7d00d214a98aa3dc6ff29aa78f9 [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:19:27.199411  9639 raft_consensus.cc:515] T 00000000000000000000000000000000 P 1e76a7d00d214a98aa3dc6ff29aa78f9 [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "1e76a7d00d214a98aa3dc6ff29aa78f9" member_type: VOTER }
I20260812 06:19:27.199784  9639 leader_election.cc:304] T 00000000000000000000000000000000 P 1e76a7d00d214a98aa3dc6ff29aa78f9 [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: 1e76a7d00d214a98aa3dc6ff29aa78f9; no voters: 
I20260812 06:19:27.200079  9639 leader_election.cc:290] T 00000000000000000000000000000000 P 1e76a7d00d214a98aa3dc6ff29aa78f9 [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:19:27.200242  9644 raft_consensus.cc:2804] T 00000000000000000000000000000000 P 1e76a7d00d214a98aa3dc6ff29aa78f9 [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:19:27.200524  9644 raft_consensus.cc:697] T 00000000000000000000000000000000 P 1e76a7d00d214a98aa3dc6ff29aa78f9 [term 1 LEADER]: Becoming Leader. State: Replica: 1e76a7d00d214a98aa3dc6ff29aa78f9, State: Running, Role: LEADER
I20260812 06:19:27.200963  9644 consensus_queue.cc:237] T 00000000000000000000000000000000 P 1e76a7d00d214a98aa3dc6ff29aa78f9 [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: "1e76a7d00d214a98aa3dc6ff29aa78f9" member_type: VOTER }
I20260812 06:19:27.201143  9639 sys_catalog.cc:565] T 00000000000000000000000000000000 P 1e76a7d00d214a98aa3dc6ff29aa78f9 [sys.catalog]: configured and running, proceeding with master startup.
I20260812 06:19:27.202936  9646 sys_catalog.cc:455] T 00000000000000000000000000000000 P 1e76a7d00d214a98aa3dc6ff29aa78f9 [sys.catalog]: SysCatalogTable state changed. Reason: New leader 1e76a7d00d214a98aa3dc6ff29aa78f9. Latest consensus state: current_term: 1 leader_uuid: "1e76a7d00d214a98aa3dc6ff29aa78f9" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "1e76a7d00d214a98aa3dc6ff29aa78f9" member_type: VOTER } }
I20260812 06:19:27.202967  9645 sys_catalog.cc:455] T 00000000000000000000000000000000 P 1e76a7d00d214a98aa3dc6ff29aa78f9 [sys.catalog]: SysCatalogTable state changed. Reason: RaftConsensus started. Latest consensus state: current_term: 1 leader_uuid: "1e76a7d00d214a98aa3dc6ff29aa78f9" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "1e76a7d00d214a98aa3dc6ff29aa78f9" member_type: VOTER } }
I20260812 06:19:27.203047  9646 sys_catalog.cc:458] T 00000000000000000000000000000000 P 1e76a7d00d214a98aa3dc6ff29aa78f9 [sys.catalog]: This master's current role is: LEADER
I20260812 06:19:27.203071  9645 sys_catalog.cc:458] T 00000000000000000000000000000000 P 1e76a7d00d214a98aa3dc6ff29aa78f9 [sys.catalog]: This master's current role is: LEADER
I20260812 06:19:27.203456  9667 catalog_manager.cc:1511] Loading table and tablet metadata into memory...
I20260812 06:19:27.203675  9529 internal_mini_cluster.cc:184] Waiting to initialize catalog manager on master 0
I20260812 06:19:27.206008  9667 catalog_manager.cc:1520] Initializing Kudu cluster ID...
I20260812 06:19:27.211167  9667 catalog_manager.cc:1383] Generated new cluster ID: 832c1a28584848dcac9e8a4572bb4d1d
I20260812 06:19:27.211314  9667 catalog_manager.cc:1531] Initializing Kudu internal certificate authority...
I20260812 06:19:27.227440  9667 catalog_manager.cc:1406] Generated new certificate authority record
I20260812 06:19:27.228978  9667 catalog_manager.cc:1540] Loading token signing keys...
I20260812 06:19:27.237926  9667 catalog_manager.cc:6092] T 00000000000000000000000000000000 P 1e76a7d00d214a98aa3dc6ff29aa78f9: Generated new TSK 0
I20260812 06:19:27.238665  9667 catalog_manager.cc:1550] Initializing in-progress tserver states...
I20260812 06:19:27.268882  9529 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:19:27.272426  9684 instance_detector.cc:116] could not retrieve AWS instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:19:27.272511  9685 instance_detector.cc:116] could not retrieve Azure instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:19:27.272706  9529 server_base.cc:1061] running on GCE node
W20260812 06:19:27.272776  9687 instance_detector.cc:116] could not retrieve OpenStack instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:19:27.273005  9529 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:19:27.273051  9529 system_unsync_time.cc:38] NTP support is disabled. Clock error bounds will not be accurate. This configuration is not suitable for distributed clusters.
I20260812 06:19:27.273067  9529 hybrid_clock.cc:648] HybridClock initialized: now 1786515567273067 us; error 0 us; skew 500 ppm
I20260812 06:19:27.274070  9529 webserver.cc:533] Webserver started at http://127.9.78.65:36119/ using document root <none> and password file <none>
I20260812 06:19:27.274268  9529 fs_manager.cc:362] Metadata directory not provided
I20260812 06:19:27.274336  9529 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:19:27.274423  9529 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:19:27.274844  9529 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskWwnqpJ/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515567133744-9529-0/minicluster-data/ts-0-root/instance:
uuid: "f3687e71354e4b22a0bd1bcf72e8f106"
format_stamp: "Formatted at 2026-08-12 06:19:27 on dist-test-slave-s11t"
I20260812 06:19:27.276407  9529 fs_manager.cc:696] Time spent creating directory manager: real 0.001s	user 0.002s	sys 0.000s
I20260812 06:19:27.277562  9693 log_block_manager.cc:4127] Time spent loading block containers with low live blocks: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:19:27.277813  9529 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.001s	sys 0.000s
I20260812 06:19:27.277895  9529 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskWwnqpJ/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515567133744-9529-0/minicluster-data/ts-0-root
uuid: "f3687e71354e4b22a0bd1bcf72e8f106"
format_stamp: "Formatted at 2026-08-12 06:19:27 on dist-test-slave-s11t"
I20260812 06:19:27.277995  9529 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskWwnqpJ/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515567133744-9529-0/minicluster-data/ts-0-root
metadata directory: /tmp/dist-test-taskWwnqpJ/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515567133744-9529-0/minicluster-data/ts-0-root
1 data directories: /tmp/dist-test-taskWwnqpJ/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515567133744-9529-0/minicluster-data/ts-0-root/data
Total live blocks: 0
Total live bytes: 0
Total live bytes (after alignment): 0
Total number of LBM containers: 0 (0 full)
Did not check for missing blocks
Did not check for orphaned blocks
Total full LBM containers with extra space: 0 (0 repaired)
Total full LBM container extra space in bytes: 0 (0 repaired)
Total incomplete LBM containers: 0 (0 repaired)
Total LBM partial records: 0 (0 repaired)
Total corrupted LBM metadata records in RocksDB: 0 (0 repaired)
I20260812 06:19:27.290321  9529 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:19:27.290781  9529 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:19:27.291309  9529 txn_system_client.cc:432] TxnSystemClient initialization is disabled...
I20260812 06:19:27.292234  9529 ts_tablet_manager.cc:585] Loaded tablet metadata (0 total tablets, 0 live tablets)
I20260812 06:19:27.292287  9529 ts_tablet_manager.cc:531] Time spent load tablet metadata: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:19:27.292359  9529 ts_tablet_manager.cc:616] Registered 0 tablets
I20260812 06:19:27.292399  9529 ts_tablet_manager.cc:595] Time spent register tablets: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:19:27.299607  9529 rpc_server.cc:307] RPC server started. Bound to: 127.9.78.65:33385
I20260812 06:19:27.299638  9789 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.9.78.65:33385 every 8 connection(s)
I20260812 06:19:27.314190  9792 heartbeater.cc:344] Connected to a master server at 127.9.78.126:34333
I20260812 06:19:27.314489  9792 heartbeater.cc:461] Registering TS with master...
I20260812 06:19:27.315037  9792 heartbeater.cc:507] Master 127.9.78.126:34333 requested a full tablet report, sending...
I20260812 06:19:27.316497  9580 ts_manager.cc:194] Registered new tserver with Master: f3687e71354e4b22a0bd1bcf72e8f106 (127.9.78.65:33385)
I20260812 06:19:27.317062  9529 internal_mini_cluster.cc:371] 1 TS(s) registered with all masters after 0.016728353s
I20260812 06:19:27.318029  9580 master_service.cc:502] Signed X509 certificate for tserver {username='slave'} at 127.0.0.1:55802
I20260812 06:19:27.327287  9580 catalog_manager.cc:2283] Servicing CreateTable request from {username='slave'} at 127.0.0.1:55806:
name: "heavy-update-compaction-test"
schema {
  columns {
    name: "key"
    type: INT64
    is_key: true
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_a"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_b"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_c"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_d"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_e"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
}
num_replicas: 1
split_rows_range_bounds {
}
partition_schema {
  range_schema {
  }
}
I20260812 06:19:27.342173  9738 tablet_service.cc:1511] Processing CreateTablet for tablet c6d550f876914b17b18d2976379663f2 (DEFAULT_TABLE table=heavy-update-compaction-test [id=56e9fe8a14a94f49a4ecba2be9246c1f]), partition=
I20260812 06:19:27.342685  9738 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet c6d550f876914b17b18d2976379663f2. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:19:27.344923  9807 tablet_bootstrap.cc:492] T c6d550f876914b17b18d2976379663f2 P f3687e71354e4b22a0bd1bcf72e8f106: Bootstrap starting.
I20260812 06:19:27.346102  9807 tablet_bootstrap.cc:654] T c6d550f876914b17b18d2976379663f2 P f3687e71354e4b22a0bd1bcf72e8f106: Neither blocks nor log segments found. Creating new log.
I20260812 06:19:27.347558  9807 tablet_bootstrap.cc:492] T c6d550f876914b17b18d2976379663f2 P f3687e71354e4b22a0bd1bcf72e8f106: No bootstrap required, opened a new log
I20260812 06:19:27.347645  9807 ts_tablet_manager.cc:1403] T c6d550f876914b17b18d2976379663f2 P f3687e71354e4b22a0bd1bcf72e8f106: Time spent bootstrapping tablet: real 0.003s	user 0.000s	sys 0.002s
I20260812 06:19:27.348179  9807 raft_consensus.cc:359] T c6d550f876914b17b18d2976379663f2 P f3687e71354e4b22a0bd1bcf72e8f106 [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "f3687e71354e4b22a0bd1bcf72e8f106" member_type: VOTER last_known_addr { host: "127.9.78.65" port: 33385 } }
I20260812 06:19:27.348286  9807 raft_consensus.cc:385] T c6d550f876914b17b18d2976379663f2 P f3687e71354e4b22a0bd1bcf72e8f106 [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:19:27.348310  9807 raft_consensus.cc:740] T c6d550f876914b17b18d2976379663f2 P f3687e71354e4b22a0bd1bcf72e8f106 [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: f3687e71354e4b22a0bd1bcf72e8f106, State: Initialized, Role: FOLLOWER
I20260812 06:19:27.348459  9807 consensus_queue.cc:260] T c6d550f876914b17b18d2976379663f2 P f3687e71354e4b22a0bd1bcf72e8f106 [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: "f3687e71354e4b22a0bd1bcf72e8f106" member_type: VOTER last_known_addr { host: "127.9.78.65" port: 33385 } }
I20260812 06:19:27.348549  9807 raft_consensus.cc:399] T c6d550f876914b17b18d2976379663f2 P f3687e71354e4b22a0bd1bcf72e8f106 [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:19:27.348578  9807 raft_consensus.cc:493] T c6d550f876914b17b18d2976379663f2 P f3687e71354e4b22a0bd1bcf72e8f106 [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:19:27.348659  9807 raft_consensus.cc:3060] T c6d550f876914b17b18d2976379663f2 P f3687e71354e4b22a0bd1bcf72e8f106 [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:19:27.349728  9807 raft_consensus.cc:515] T c6d550f876914b17b18d2976379663f2 P f3687e71354e4b22a0bd1bcf72e8f106 [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "f3687e71354e4b22a0bd1bcf72e8f106" member_type: VOTER last_known_addr { host: "127.9.78.65" port: 33385 } }
I20260812 06:19:27.349947  9807 leader_election.cc:304] T c6d550f876914b17b18d2976379663f2 P f3687e71354e4b22a0bd1bcf72e8f106 [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: f3687e71354e4b22a0bd1bcf72e8f106; no voters: 
I20260812 06:19:27.350165  9807 leader_election.cc:290] T c6d550f876914b17b18d2976379663f2 P f3687e71354e4b22a0bd1bcf72e8f106 [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:19:27.350261  9811 raft_consensus.cc:2804] T c6d550f876914b17b18d2976379663f2 P f3687e71354e4b22a0bd1bcf72e8f106 [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:19:27.350500  9811 raft_consensus.cc:697] T c6d550f876914b17b18d2976379663f2 P f3687e71354e4b22a0bd1bcf72e8f106 [term 1 LEADER]: Becoming Leader. State: Replica: f3687e71354e4b22a0bd1bcf72e8f106, State: Running, Role: LEADER
I20260812 06:19:27.350534  9807 ts_tablet_manager.cc:1434] T c6d550f876914b17b18d2976379663f2 P f3687e71354e4b22a0bd1bcf72e8f106: Time spent starting tablet: real 0.003s	user 0.003s	sys 0.000s
I20260812 06:19:27.350694  9811 consensus_queue.cc:237] T c6d550f876914b17b18d2976379663f2 P f3687e71354e4b22a0bd1bcf72e8f106 [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: "f3687e71354e4b22a0bd1bcf72e8f106" member_type: VOTER last_known_addr { host: "127.9.78.65" port: 33385 } }
I20260812 06:19:27.351050  9792 heartbeater.cc:499] Master 127.9.78.126:34333 was elected leader, sending a full tablet report...
I20260812 06:19:27.353597  9580 catalog_manager.cc:5719] T c6d550f876914b17b18d2976379663f2 P f3687e71354e4b22a0bd1bcf72e8f106 reported cstate change: term changed from 0 to 1, leader changed from <none> to f3687e71354e4b22a0bd1bcf72e8f106 (127.9.78.65). New cstate: current_term: 1 leader_uuid: "f3687e71354e4b22a0bd1bcf72e8f106" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "f3687e71354e4b22a0bd1bcf72e8f106" member_type: VOTER last_known_addr { host: "127.9.78.65" port: 33385 } health_report { overall_health: HEALTHY } } }
I20260812 06:19:27.425397  9529 heavy-update-compaction-itest.cc:215] Time spent inserting: real 0.063s	user 0.013s	sys 0.017s
I20260812 06:19:27.550845  9793 maintenance_manager.cc:419] P f3687e71354e4b22a0bd1bcf72e8f106: Scheduling FlushMRSOp(c6d550f876914b17b18d2976379663f2): perf score=15.086190
I20260812 06:19:27.709388  9702 maintenance_manager.cc:643] P f3687e71354e4b22a0bd1bcf72e8f106: FlushMRSOp(c6d550f876914b17b18d2976379663f2) complete. Timing: real 0.158s	user 0.115s	sys 0.032s Metrics: {"bytes_written":11897249,"cfile_init":1,"compiler_manager_pool.queue_time_us":297,"delete_count":0,"dirs.queue_time_us":52,"dirs.run_cpu_time_us":234,"dirs.run_wall_time_us":805,"drs_written":1,"lbm_read_time_us":73,"lbm_reads_lt_1ms":4,"lbm_write_time_us":36427,"lbm_writes_lt_1ms":657,"peak_mem_usage":0,"reinsert_count":0,"rows_written":104,"thread_start_us":137,"threads_started":1,"update_count":1450}
I20260812 06:19:27.710641  9793 maintenance_manager.cc:419] P f3687e71354e4b22a0bd1bcf72e8f106: Scheduling LogGCOp(c6d550f876914b17b18d2976379663f2): free 20743880 bytes of WAL
I20260812 06:19:27.711000  9702 log_reader.cc:385] T c6d550f876914b17b18d2976379663f2: removed 2 log segments from log reader
I20260812 06:19:27.711086  9702 log.cc:1079] T c6d550f876914b17b18d2976379663f2 P f3687e71354e4b22a0bd1bcf72e8f106: Deleting log segment in path: /tmp/dist-test-taskWwnqpJ/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515567133744-9529-0/minicluster-data/ts-0-root/wals/c6d550f876914b17b18d2976379663f2/wal-000000001 (ops 1-6)
I20260812 06:19:27.711195  9702 log.cc:1079] T c6d550f876914b17b18d2976379663f2 P f3687e71354e4b22a0bd1bcf72e8f106: Deleting log segment in path: /tmp/dist-test-taskWwnqpJ/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515567133744-9529-0/minicluster-data/ts-0-root/wals/c6d550f876914b17b18d2976379663f2/wal-000000002 (ops 7-11)
I20260812 06:19:27.715569  9702 maintenance_manager.cc:643] P f3687e71354e4b22a0bd1bcf72e8f106: LogGCOp(c6d550f876914b17b18d2976379663f2) complete. Timing: real 0.005s	user 0.000s	sys 0.002s Metrics: {}
I20260812 06:19:27.715991  9793 maintenance_manager.cc:419] P f3687e71354e4b22a0bd1bcf72e8f106: Scheduling UndoDeltaBlockGCOp(c6d550f876914b17b18d2976379663f2): 12719216 bytes on disk
I20260812 06:19:27.716611  9702 maintenance_manager.cc:643] P f3687e71354e4b22a0bd1bcf72e8f106: UndoDeltaBlockGCOp(c6d550f876914b17b18d2976379663f2) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":62,"lbm_reads_lt_1ms":4}
I20260812 06:19:27.717187  9793 maintenance_manager.cc:419] P f3687e71354e4b22a0bd1bcf72e8f106: Scheduling FlushDeltaMemStoresOp(c6d550f876914b17b18d2976379663f2): perf score=2.188937
I20260812 06:19:27.738113  9702 maintenance_manager.cc:643] P f3687e71354e4b22a0bd1bcf72e8f106: FlushDeltaMemStoresOp(c6d550f876914b17b18d2976379663f2) complete. Timing: real 0.021s	user 0.012s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6950,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:27.738705  9793 maintenance_manager.cc:419] P f3687e71354e4b22a0bd1bcf72e8f106: Scheduling MajorDeltaCompactionOp(c6d550f876914b17b18d2976379663f2): perf score=1.000000
I20260812 06:19:27.871513  9702 maintenance_manager.cc:643] P f3687e71354e4b22a0bd1bcf72e8f106: MajorDeltaCompactionOp(c6d550f876914b17b18d2976379663f2) complete. Timing: real 0.133s	user 0.113s	sys 0.019s Metrics: {"cfile_cache_miss":422,"cfile_cache_miss_bytes":20262036,"cfile_init":7,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":1038,"lbm_read_time_us":7467,"lbm_reads_lt_1ms":450,"lbm_write_time_us":25128,"lbm_writes_lt_1ms":433,"peak_mem_usage":49238594,"reinsert_count":0,"spinlock_wait_cycles":896,"thread_start_us":331,"threads_started":5,"update_count":1950}
I20260812 06:19:27.872131  9793 maintenance_manager.cc:419] P f3687e71354e4b22a0bd1bcf72e8f106: Scheduling FlushDeltaMemStoresOp(c6d550f876914b17b18d2976379663f2): perf score=10.126437
I20260812 06:19:27.917840  9702 maintenance_manager.cc:643] P f3687e71354e4b22a0bd1bcf72e8f106: FlushDeltaMemStoresOp(c6d550f876914b17b18d2976379663f2) complete. Timing: real 0.045s	user 0.024s	sys 0.011s Metrics: {"bytes_written":12307494,"delete_count":0,"lbm_write_time_us":15877,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:19:27.918416  9793 maintenance_manager.cc:419] P f3687e71354e4b22a0bd1bcf72e8f106: Scheduling FlushDeltaMemStoresOp(c6d550f876914b17b18d2976379663f2): perf score=2.188937
I20260812 06:19:27.929207  9702 maintenance_manager.cc:643] P f3687e71354e4b22a0bd1bcf72e8f106: FlushDeltaMemStoresOp(c6d550f876914b17b18d2976379663f2) complete. Timing: real 0.011s	user 0.006s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4114,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:27.929728  9793 maintenance_manager.cc:419] P f3687e71354e4b22a0bd1bcf72e8f106: Scheduling MajorDeltaCompactionOp(c6d550f876914b17b18d2976379663f2): perf score=1.000000
I20260812 06:19:28.059691  9702 maintenance_manager.cc:643] P f3687e71354e4b22a0bd1bcf72e8f106: MajorDeltaCompactionOp(c6d550f876914b17b18d2976379663f2) complete. Timing: real 0.130s	user 0.094s	sys 0.035s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672281,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":1353,"lbm_read_time_us":9885,"lbm_reads_lt_1ms":472,"lbm_write_time_us":24008,"lbm_writes_lt_1ms":443,"mutex_wait_us":312,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":6656,"update_count":2000}
I20260812 06:19:28.060405  9793 maintenance_manager.cc:419] P f3687e71354e4b22a0bd1bcf72e8f106: Scheduling FlushDeltaMemStoresOp(c6d550f876914b17b18d2976379663f2): perf score=10.126437
I20260812 06:19:28.098045  9702 maintenance_manager.cc:643] P f3687e71354e4b22a0bd1bcf72e8f106: FlushDeltaMemStoresOp(c6d550f876914b17b18d2976379663f2) complete. Timing: real 0.037s	user 0.020s	sys 0.016s Metrics: {"bytes_written":12307489,"delete_count":0,"lbm_write_time_us":17749,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":302,"reinsert_count":0,"update_count":1500}
I20260812 06:19:28.098538  9793 maintenance_manager.cc:419] P f3687e71354e4b22a0bd1bcf72e8f106: Scheduling FlushDeltaMemStoresOp(c6d550f876914b17b18d2976379663f2): perf score=2.188937
I20260812 06:19:28.115083  9702 maintenance_manager.cc:643] P f3687e71354e4b22a0bd1bcf72e8f106: FlushDeltaMemStoresOp(c6d550f876914b17b18d2976379663f2) complete. Timing: real 0.016s	user 0.012s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5263,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:28.115638  9793 maintenance_manager.cc:419] P f3687e71354e4b22a0bd1bcf72e8f106: Scheduling MajorDeltaCompactionOp(c6d550f876914b17b18d2976379663f2): perf score=1.000000
I20260812 06:19:28.244529  9702 maintenance_manager.cc:643] P f3687e71354e4b22a0bd1bcf72e8f106: MajorDeltaCompactionOp(c6d550f876914b17b18d2976379663f2) complete. Timing: real 0.129s	user 0.120s	sys 0.004s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672276,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":1338,"lbm_read_time_us":8008,"lbm_reads_lt_1ms":468,"lbm_write_time_us":24831,"lbm_writes_lt_1ms":443,"mutex_wait_us":421,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":13440,"update_count":2000}
I20260812 06:19:28.245388  9793 maintenance_manager.cc:419] P f3687e71354e4b22a0bd1bcf72e8f106: Scheduling FlushDeltaMemStoresOp(c6d550f876914b17b18d2976379663f2): perf score=11.118625
I20260812 06:19:28.298194  9702 maintenance_manager.cc:643] P f3687e71354e4b22a0bd1bcf72e8f106: FlushDeltaMemStoresOp(c6d550f876914b17b18d2976379663f2) complete. Timing: real 0.053s	user 0.020s	sys 0.030s Metrics: {"bytes_written":12717736,"delete_count":0,"lbm_write_time_us":19049,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:19:28.298884  9793 maintenance_manager.cc:419] P f3687e71354e4b22a0bd1bcf72e8f106: Scheduling FlushDeltaMemStoresOp(c6d550f876914b17b18d2976379663f2): perf score=2.188937
I20260812 06:19:28.319840  9702 maintenance_manager.cc:643] P f3687e71354e4b22a0bd1bcf72e8f106: FlushDeltaMemStoresOp(c6d550f876914b17b18d2976379663f2) complete. Timing: real 0.021s	user 0.004s	sys 0.008s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":4772,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:19:28.320518  9793 maintenance_manager.cc:419] P f3687e71354e4b22a0bd1bcf72e8f106: Scheduling MajorDeltaCompactionOp(c6d550f876914b17b18d2976379663f2): perf score=1.000000
I20260812 06:19:28.499142  9702 maintenance_manager.cc:643] P f3687e71354e4b22a0bd1bcf72e8f106: MajorDeltaCompactionOp(c6d550f876914b17b18d2976379663f2) complete. Timing: real 0.178s	user 0.108s	sys 0.059s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672269,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":287,"lbm_read_time_us":10518,"lbm_reads_lt_1ms":464,"lbm_write_time_us":27767,"lbm_writes_lt_1ms":443,"mutex_wait_us":72,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":13184,"update_count":2000}
I20260812 06:19:28.499683  9793 maintenance_manager.cc:419] P f3687e71354e4b22a0bd1bcf72e8f106: Scheduling FlushDeltaMemStoresOp(c6d550f876914b17b18d2976379663f2): perf score=14.095187
I20260812 06:19:28.551896  9702 maintenance_manager.cc:643] P f3687e71354e4b22a0bd1bcf72e8f106: FlushDeltaMemStoresOp(c6d550f876914b17b18d2976379663f2) complete. Timing: real 0.052s	user 0.023s	sys 0.020s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":20855,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:28.552410  9793 maintenance_manager.cc:419] P f3687e71354e4b22a0bd1bcf72e8f106: Scheduling FlushDeltaMemStoresOp(c6d550f876914b17b18d2976379663f2): perf score=2.188937
I20260812 06:19:28.564805  9702 maintenance_manager.cc:643] P f3687e71354e4b22a0bd1bcf72e8f106: FlushDeltaMemStoresOp(c6d550f876914b17b18d2976379663f2) complete. Timing: real 0.012s	user 0.012s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4594,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:28.565497  9793 maintenance_manager.cc:419] P f3687e71354e4b22a0bd1bcf72e8f106: Scheduling MajorDeltaCompactionOp(c6d550f876914b17b18d2976379663f2): perf score=1.000000
I20260812 06:19:28.711150  9702 maintenance_manager.cc:643] P f3687e71354e4b22a0bd1bcf72e8f106: MajorDeltaCompactionOp(c6d550f876914b17b18d2976379663f2) complete. Timing: real 0.145s	user 0.124s	sys 0.020s 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":249,"lbm_read_time_us":11935,"lbm_reads_lt_1ms":572,"lbm_write_time_us":27645,"lbm_writes_lt_1ms":543,"mutex_wait_us":1,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":2560,"update_count":2500}
I20260812 06:19:28.715224  9793 maintenance_manager.cc:419] P f3687e71354e4b22a0bd1bcf72e8f106: Scheduling FlushDeltaMemStoresOp(c6d550f876914b17b18d2976379663f2): perf score=11.118625
I20260812 06:19:28.760496  9702 maintenance_manager.cc:643] P f3687e71354e4b22a0bd1bcf72e8f106: FlushDeltaMemStoresOp(c6d550f876914b17b18d2976379663f2) complete. Timing: real 0.045s	user 0.020s	sys 0.020s Metrics: {"bytes_written":12840808,"delete_count":0,"lbm_write_time_us":19841,"lbm_writes_1-10_ms":2,"lbm_writes_lt_1ms":314,"reinsert_count":0,"update_count":1565}
I20260812 06:19:28.761117  9793 maintenance_manager.cc:419] P f3687e71354e4b22a0bd1bcf72e8f106: Scheduling FlushDeltaMemStoresOp(c6d550f876914b17b18d2976379663f2): perf score=2.188937
I20260812 06:19:28.772821  9702 maintenance_manager.cc:643] P f3687e71354e4b22a0bd1bcf72e8f106: FlushDeltaMemStoresOp(c6d550f876914b17b18d2976379663f2) complete. Timing: real 0.012s	user 0.006s	sys 0.004s Metrics: {"bytes_written":3979584,"delete_count":0,"lbm_write_time_us":3911,"lbm_writes_lt_1ms":100,"reinsert_count":0,"update_count":485}
I20260812 06:19:28.773309  9793 maintenance_manager.cc:419] P f3687e71354e4b22a0bd1bcf72e8f106: Scheduling FlushDeltaMemStoresOp(c6d550f876914b17b18d2976379663f2): perf score=2.188937
I20260812 06:19:28.783247  9702 maintenance_manager.cc:643] P f3687e71354e4b22a0bd1bcf72e8f106: FlushDeltaMemStoresOp(c6d550f876914b17b18d2976379663f2) complete. Timing: real 0.010s	user 0.008s	sys 0.000s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3601,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:19:28.783733  9793 maintenance_manager.cc:419] P f3687e71354e4b22a0bd1bcf72e8f106: Scheduling MajorDeltaCompactionOp(c6d550f876914b17b18d2976379663f2): perf score=1.000000
I20260812 06:19:28.972194  9702 maintenance_manager.cc:643] P f3687e71354e4b22a0bd1bcf72e8f106: MajorDeltaCompactionOp(c6d550f876914b17b18d2976379663f2) complete. Timing: real 0.188s	user 0.133s	sys 0.031s Metrics: {"cfile_cache_miss":533,"cfile_cache_miss_bytes":24774797,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":309,"lbm_read_time_us":10016,"lbm_reads_lt_1ms":573,"lbm_write_time_us":40138,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":542,"mutex_wait_us":49,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":5376,"update_count":2500}
I20260812 06:19:28.977696  9793 maintenance_manager.cc:419] P f3687e71354e4b22a0bd1bcf72e8f106: Scheduling FlushDeltaMemStoresOp(c6d550f876914b17b18d2976379663f2): perf score=14.095187
I20260812 06:19:29.031946  9702 maintenance_manager.cc:643] P f3687e71354e4b22a0bd1bcf72e8f106: FlushDeltaMemStoresOp(c6d550f876914b17b18d2976379663f2) complete. Timing: real 0.054s	user 0.028s	sys 0.020s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":22947,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:29.032469  9793 maintenance_manager.cc:419] P f3687e71354e4b22a0bd1bcf72e8f106: Scheduling FlushDeltaMemStoresOp(c6d550f876914b17b18d2976379663f2): perf score=2.188937
I20260812 06:19:29.044145  9702 maintenance_manager.cc:643] P f3687e71354e4b22a0bd1bcf72e8f106: FlushDeltaMemStoresOp(c6d550f876914b17b18d2976379663f2) complete. Timing: real 0.012s	user 0.009s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4003,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:29.044646  9793 maintenance_manager.cc:419] P f3687e71354e4b22a0bd1bcf72e8f106: Scheduling FlushMRSOp(c6d550f876914b17b18d2976379663f2): perf score=1.000000
I20260812 06:19:29.077190  9702 maintenance_manager.cc:643] P f3687e71354e4b22a0bd1bcf72e8f106: FlushMRSOp(c6d550f876914b17b18d2976379663f2) complete. Timing: real 0.032s	user 0.027s	sys 0.004s Metrics: {"bytes_written":1234473,"cfile_init":1,"dirs.queue_time_us":109,"dirs.run_cpu_time_us":329,"dirs.run_wall_time_us":1481,"drs_written":1,"lbm_read_time_us":65,"lbm_reads_lt_1ms":4,"lbm_write_time_us":2330,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":30}
I20260812 06:19:29.078065  9793 maintenance_manager.cc:419] P f3687e71354e4b22a0bd1bcf72e8f106: Scheduling LogGCOp(c6d550f876914b17b18d2976379663f2): free 124710306 bytes of WAL
I20260812 06:19:29.078328  9702 log_reader.cc:385] T c6d550f876914b17b18d2976379663f2: removed 12 log segments from log reader
I20260812 06:19:29.078397  9702 log.cc:1079] T c6d550f876914b17b18d2976379663f2 P f3687e71354e4b22a0bd1bcf72e8f106: Deleting log segment in path: /tmp/dist-test-taskWwnqpJ/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515567133744-9529-0/minicluster-data/ts-0-root/wals/c6d550f876914b17b18d2976379663f2/wal-000000003 (ops 12-16)
I20260812 06:19:29.078438  9702 log.cc:1079] T c6d550f876914b17b18d2976379663f2 P f3687e71354e4b22a0bd1bcf72e8f106: Deleting log segment in path: /tmp/dist-test-taskWwnqpJ/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515567133744-9529-0/minicluster-data/ts-0-root/wals/c6d550f876914b17b18d2976379663f2/wal-000000004 (ops 17-21)
I20260812 06:19:29.078478  9702 log.cc:1079] T c6d550f876914b17b18d2976379663f2 P f3687e71354e4b22a0bd1bcf72e8f106: Deleting log segment in path: /tmp/dist-test-taskWwnqpJ/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515567133744-9529-0/minicluster-data/ts-0-root/wals/c6d550f876914b17b18d2976379663f2/wal-000000005 (ops 22-26)
I20260812 06:19:29.078508  9702 log.cc:1079] T c6d550f876914b17b18d2976379663f2 P f3687e71354e4b22a0bd1bcf72e8f106: Deleting log segment in path: /tmp/dist-test-taskWwnqpJ/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515567133744-9529-0/minicluster-data/ts-0-root/wals/c6d550f876914b17b18d2976379663f2/wal-000000006 (ops 27-31)
I20260812 06:19:29.078549  9702 log.cc:1079] T c6d550f876914b17b18d2976379663f2 P f3687e71354e4b22a0bd1bcf72e8f106: Deleting log segment in path: /tmp/dist-test-taskWwnqpJ/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515567133744-9529-0/minicluster-data/ts-0-root/wals/c6d550f876914b17b18d2976379663f2/wal-000000007 (ops 32-36)
I20260812 06:19:29.078586  9702 log.cc:1079] T c6d550f876914b17b18d2976379663f2 P f3687e71354e4b22a0bd1bcf72e8f106: Deleting log segment in path: /tmp/dist-test-taskWwnqpJ/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515567133744-9529-0/minicluster-data/ts-0-root/wals/c6d550f876914b17b18d2976379663f2/wal-000000008 (ops 37-41)
I20260812 06:19:29.078610  9702 log.cc:1079] T c6d550f876914b17b18d2976379663f2 P f3687e71354e4b22a0bd1bcf72e8f106: Deleting log segment in path: /tmp/dist-test-taskWwnqpJ/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515567133744-9529-0/minicluster-data/ts-0-root/wals/c6d550f876914b17b18d2976379663f2/wal-000000009 (ops 42-46)
I20260812 06:19:29.078646  9702 log.cc:1079] T c6d550f876914b17b18d2976379663f2 P f3687e71354e4b22a0bd1bcf72e8f106: Deleting log segment in path: /tmp/dist-test-taskWwnqpJ/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515567133744-9529-0/minicluster-data/ts-0-root/wals/c6d550f876914b17b18d2976379663f2/wal-000000010 (ops 47-51)
I20260812 06:19:29.078683  9702 log.cc:1079] T c6d550f876914b17b18d2976379663f2 P f3687e71354e4b22a0bd1bcf72e8f106: Deleting log segment in path: /tmp/dist-test-taskWwnqpJ/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515567133744-9529-0/minicluster-data/ts-0-root/wals/c6d550f876914b17b18d2976379663f2/wal-000000011 (ops 52-56)
I20260812 06:19:29.078717  9702 log.cc:1079] T c6d550f876914b17b18d2976379663f2 P f3687e71354e4b22a0bd1bcf72e8f106: Deleting log segment in path: /tmp/dist-test-taskWwnqpJ/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515567133744-9529-0/minicluster-data/ts-0-root/wals/c6d550f876914b17b18d2976379663f2/wal-000000012 (ops 57-61)
I20260812 06:19:29.078744  9702 log.cc:1079] T c6d550f876914b17b18d2976379663f2 P f3687e71354e4b22a0bd1bcf72e8f106: Deleting log segment in path: /tmp/dist-test-taskWwnqpJ/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515567133744-9529-0/minicluster-data/ts-0-root/wals/c6d550f876914b17b18d2976379663f2/wal-000000013 (ops 62-66)
I20260812 06:19:29.078770  9702 log.cc:1079] T c6d550f876914b17b18d2976379663f2 P f3687e71354e4b22a0bd1bcf72e8f106: Deleting log segment in path: /tmp/dist-test-taskWwnqpJ/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515567133744-9529-0/minicluster-data/ts-0-root/wals/c6d550f876914b17b18d2976379663f2/wal-000000014 (ops 67-71)
I20260812 06:19:29.113080  9702 maintenance_manager.cc:643] P f3687e71354e4b22a0bd1bcf72e8f106: LogGCOp(c6d550f876914b17b18d2976379663f2) complete. Timing: real 0.035s	user 0.000s	sys 0.035s Metrics: {}
I20260812 06:19:29.113513  9793 maintenance_manager.cc:419] P f3687e71354e4b22a0bd1bcf72e8f106: Scheduling FlushDeltaMemStoresOp(c6d550f876914b17b18d2976379663f2): perf score=2.188937
I20260812 06:19:29.127589  9702 maintenance_manager.cc:643] P f3687e71354e4b22a0bd1bcf72e8f106: FlushDeltaMemStoresOp(c6d550f876914b17b18d2976379663f2) complete. Timing: real 0.014s	user 0.006s	sys 0.005s Metrics: {"bytes_written":4143683,"delete_count":0,"lbm_write_time_us":4701,"lbm_writes_lt_1ms":104,"reinsert_count":0,"update_count":505}
I20260812 06:19:29.128008  9793 maintenance_manager.cc:419] P f3687e71354e4b22a0bd1bcf72e8f106: Scheduling UndoDeltaBlockGCOp(c6d550f876914b17b18d2976379663f2): 473 bytes on disk
I20260812 06:19:29.128424  9702 maintenance_manager.cc:643] P f3687e71354e4b22a0bd1bcf72e8f106: UndoDeltaBlockGCOp(c6d550f876914b17b18d2976379663f2) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":52,"lbm_reads_lt_1ms":4}
I20260812 06:19:29.128942  9793 maintenance_manager.cc:419] P f3687e71354e4b22a0bd1bcf72e8f106: Scheduling FlushDeltaMemStoresOp(c6d550f876914b17b18d2976379663f2): perf score=2.188937
I20260812 06:19:29.139346  9702 maintenance_manager.cc:643] P f3687e71354e4b22a0bd1bcf72e8f106: FlushDeltaMemStoresOp(c6d550f876914b17b18d2976379663f2) complete. Timing: real 0.010s	user 0.004s	sys 0.004s Metrics: {"bytes_written":4061634,"delete_count":0,"lbm_write_time_us":3982,"lbm_writes_lt_1ms":102,"reinsert_count":0,"update_count":495}
I20260812 06:19:29.139791  9793 maintenance_manager.cc:419] P f3687e71354e4b22a0bd1bcf72e8f106: Scheduling MajorDeltaCompactionOp(c6d550f876914b17b18d2976379663f2): perf score=1.000000
I20260812 06:19:29.372661  9702 maintenance_manager.cc:643] P f3687e71354e4b22a0bd1bcf72e8f106: MajorDeltaCompactionOp(c6d550f876914b17b18d2976379663f2) complete. Timing: real 0.233s	user 0.178s	sys 0.051s Metrics: {"cfile_cache_miss":734,"cfile_cache_miss_bytes":32979750,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":567,"lbm_read_time_us":16018,"lbm_reads_lt_1ms":774,"lbm_write_time_us":41662,"lbm_writes_lt_1ms":743,"mutex_wait_us":49,"peak_mem_usage":87969044,"reinsert_count":0,"spinlock_wait_cycles":18944,"thread_start_us":79,"threads_started":1,"update_count":3500}
I20260812 06:19:29.376467  9793 maintenance_manager.cc:419] P f3687e71354e4b22a0bd1bcf72e8f106: Scheduling FlushDeltaMemStoresOp(c6d550f876914b17b18d2976379663f2): perf score=14.095187
I20260812 06:19:29.434958  9702 maintenance_manager.cc:643] P f3687e71354e4b22a0bd1bcf72e8f106: FlushDeltaMemStoresOp(c6d550f876914b17b18d2976379663f2) complete. Timing: real 0.058s	user 0.018s	sys 0.037s Metrics: {"bytes_written":16409900,"delete_count":0,"lbm_write_time_us":20746,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:29.435539  9793 maintenance_manager.cc:419] P f3687e71354e4b22a0bd1bcf72e8f106: Scheduling FlushDeltaMemStoresOp(c6d550f876914b17b18d2976379663f2): perf score=2.188937
I20260812 06:19:29.454473  9702 maintenance_manager.cc:643] P f3687e71354e4b22a0bd1bcf72e8f106: FlushDeltaMemStoresOp(c6d550f876914b17b18d2976379663f2) complete. Timing: real 0.019s	user 0.013s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":7027,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:29.455215  9793 maintenance_manager.cc:419] P f3687e71354e4b22a0bd1bcf72e8f106: Scheduling MajorDeltaCompactionOp(c6d550f876914b17b18d2976379663f2): perf score=1.000000
I20260812 06:19:29.664888  9702 maintenance_manager.cc:643] P f3687e71354e4b22a0bd1bcf72e8f106: MajorDeltaCompactionOp(c6d550f876914b17b18d2976379663f2) complete. Timing: real 0.209s	user 0.152s	sys 0.050s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774687,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":507,"lbm_read_time_us":12395,"lbm_reads_lt_1ms":572,"lbm_write_time_us":31122,"lbm_writes_lt_1ms":543,"mutex_wait_us":49,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":8704,"update_count":2500}
I20260812 06:19:29.665621  9793 maintenance_manager.cc:419] P f3687e71354e4b22a0bd1bcf72e8f106: Scheduling FlushDeltaMemStoresOp(c6d550f876914b17b18d2976379663f2): perf score=14.095187
I20260812 06:19:29.743140  9702 maintenance_manager.cc:643] P f3687e71354e4b22a0bd1bcf72e8f106: FlushDeltaMemStoresOp(c6d550f876914b17b18d2976379663f2) complete. Timing: real 0.077s	user 0.038s	sys 0.033s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":24857,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":402,"reinsert_count":0,"update_count":2000}
I20260812 06:19:29.743819  9793 maintenance_manager.cc:419] P f3687e71354e4b22a0bd1bcf72e8f106: Scheduling FlushDeltaMemStoresOp(c6d550f876914b17b18d2976379663f2): perf score=2.188937
I20260812 06:19:29.762957  9702 maintenance_manager.cc:643] P f3687e71354e4b22a0bd1bcf72e8f106: FlushDeltaMemStoresOp(c6d550f876914b17b18d2976379663f2) complete. Timing: real 0.019s	user 0.009s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":7142,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:29.763502  9793 maintenance_manager.cc:419] P f3687e71354e4b22a0bd1bcf72e8f106: Scheduling MajorDeltaCompactionOp(c6d550f876914b17b18d2976379663f2): perf score=1.000000
I20260812 06:19:30.056914  9702 maintenance_manager.cc:643] P f3687e71354e4b22a0bd1bcf72e8f106: MajorDeltaCompactionOp(c6d550f876914b17b18d2976379663f2) complete. Timing: real 0.293s	user 0.230s	sys 0.051s 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":668,"lbm_read_time_us":20351,"lbm_reads_lt_1ms":572,"lbm_write_time_us":42821,"lbm_writes_lt_1ms":543,"mutex_wait_us":67,"peak_mem_usage":63115900,"reinsert_count":0,"update_count":2500}
I20260812 06:19:30.057716  9793 maintenance_manager.cc:419] P f3687e71354e4b22a0bd1bcf72e8f106: Scheduling FlushDeltaMemStoresOp(c6d550f876914b17b18d2976379663f2): perf score=22.032687
I20260812 06:19:30.142742  9702 maintenance_manager.cc:643] P f3687e71354e4b22a0bd1bcf72e8f106: FlushDeltaMemStoresOp(c6d550f876914b17b18d2976379663f2) complete. Timing: real 0.085s	user 0.054s	sys 0.027s Metrics: {"bytes_written":24614721,"delete_count":0,"lbm_write_time_us":32439,"lbm_writes_lt_1ms":603,"reinsert_count":0,"update_count":3000}
I20260812 06:19:30.143289  9793 maintenance_manager.cc:419] P f3687e71354e4b22a0bd1bcf72e8f106: Scheduling FlushDeltaMemStoresOp(c6d550f876914b17b18d2976379663f2): perf score=2.188937
I20260812 06:19:30.155154  9702 maintenance_manager.cc:643] P f3687e71354e4b22a0bd1bcf72e8f106: FlushDeltaMemStoresOp(c6d550f876914b17b18d2976379663f2) complete. Timing: real 0.012s	user 0.003s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4282,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:30.155648  9793 maintenance_manager.cc:419] P f3687e71354e4b22a0bd1bcf72e8f106: Scheduling MajorDeltaCompactionOp(c6d550f876914b17b18d2976379663f2): perf score=1.000000
I20260812 06:19:30.407224  9702 maintenance_manager.cc:643] P f3687e71354e4b22a0bd1bcf72e8f106: MajorDeltaCompactionOp(c6d550f876914b17b18d2976379663f2) complete. Timing: real 0.251s	user 0.169s	sys 0.072s Metrics: {"cfile_cache_miss":732,"cfile_cache_miss_bytes":32979508,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":1123,"lbm_read_time_us":18096,"lbm_reads_lt_1ms":772,"lbm_write_time_us":39421,"lbm_writes_lt_1ms":743,"peak_mem_usage":87969044,"reinsert_count":0,"spinlock_wait_cycles":9472,"update_count":3500}
I20260812 06:19:30.407918  9793 maintenance_manager.cc:419] P f3687e71354e4b22a0bd1bcf72e8f106: Scheduling FlushDeltaMemStoresOp(c6d550f876914b17b18d2976379663f2): perf score=18.063937
I20260812 06:19:30.485455  9702 maintenance_manager.cc:643] P f3687e71354e4b22a0bd1bcf72e8f106: FlushDeltaMemStoresOp(c6d550f876914b17b18d2976379663f2) complete. Timing: real 0.077s	user 0.039s	sys 0.024s Metrics: {"bytes_written":20512315,"delete_count":0,"lbm_write_time_us":29082,"lbm_writes_lt_1ms":503,"reinsert_count":0,"update_count":2500}
I20260812 06:19:30.485991  9793 maintenance_manager.cc:419] P f3687e71354e4b22a0bd1bcf72e8f106: Scheduling FlushDeltaMemStoresOp(c6d550f876914b17b18d2976379663f2): perf score=2.188937
I20260812 06:19:30.498158  9702 maintenance_manager.cc:643] P f3687e71354e4b22a0bd1bcf72e8f106: FlushDeltaMemStoresOp(c6d550f876914b17b18d2976379663f2) complete. Timing: real 0.012s	user 0.009s	sys 0.002s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3975,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:30.498854  9793 maintenance_manager.cc:419] P f3687e71354e4b22a0bd1bcf72e8f106: Scheduling MajorDeltaCompactionOp(c6d550f876914b17b18d2976379663f2): perf score=1.000000
I20260812 06:19:30.714671  9702 maintenance_manager.cc:643] P f3687e71354e4b22a0bd1bcf72e8f106: MajorDeltaCompactionOp(c6d550f876914b17b18d2976379663f2) complete. Timing: real 0.216s	user 0.151s	sys 0.064s Metrics: {"cfile_cache_miss":632,"cfile_cache_miss_bytes":28877102,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":528,"lbm_read_time_us":14744,"lbm_reads_lt_1ms":672,"lbm_write_time_us":38432,"lbm_writes_lt_1ms":643,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":1280,"update_count":3000}
I20260812 06:19:30.715562  9793 maintenance_manager.cc:419] P f3687e71354e4b22a0bd1bcf72e8f106: Scheduling FlushDeltaMemStoresOp(c6d550f876914b17b18d2976379663f2): perf score=14.095187
I20260812 06:19:30.765914  9702 maintenance_manager.cc:643] P f3687e71354e4b22a0bd1bcf72e8f106: FlushDeltaMemStoresOp(c6d550f876914b17b18d2976379663f2) complete. Timing: real 0.050s	user 0.033s	sys 0.015s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":22165,"lbm_writes_lt_1ms":403,"reinsert_count":0,"spinlock_wait_cycles":2304,"update_count":2000}
I20260812 06:19:30.766553  9793 maintenance_manager.cc:419] P f3687e71354e4b22a0bd1bcf72e8f106: Scheduling FlushMRSOp(c6d550f876914b17b18d2976379663f2): perf score=1.000000
I20260812 06:19:30.827719  9702 maintenance_manager.cc:643] P f3687e71354e4b22a0bd1bcf72e8f106: FlushMRSOp(c6d550f876914b17b18d2976379663f2) complete. Timing: real 0.061s	user 0.036s	sys 0.000s Metrics: {"bytes_written":1234479,"cfile_init":1,"dirs.queue_time_us":82,"dirs.run_cpu_time_us":242,"dirs.run_wall_time_us":1607,"drs_written":1,"lbm_read_time_us":47,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1733,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":30}
I20260812 06:19:30.828560  9793 maintenance_manager.cc:419] P f3687e71354e4b22a0bd1bcf72e8f106: Scheduling LogGCOp(c6d550f876914b17b18d2976379663f2): free 115943184 bytes of WAL
I20260812 06:19:30.828822  9702 log_reader.cc:385] T c6d550f876914b17b18d2976379663f2: removed 11 log segments from log reader
I20260812 06:19:30.828871  9702 log.cc:1079] T c6d550f876914b17b18d2976379663f2 P f3687e71354e4b22a0bd1bcf72e8f106: Deleting log segment in path: /tmp/dist-test-taskWwnqpJ/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515567133744-9529-0/minicluster-data/ts-0-root/wals/c6d550f876914b17b18d2976379663f2/wal-000000015 (ops 72-76)
I20260812 06:19:30.828902  9702 log.cc:1079] T c6d550f876914b17b18d2976379663f2 P f3687e71354e4b22a0bd1bcf72e8f106: Deleting log segment in path: /tmp/dist-test-taskWwnqpJ/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515567133744-9529-0/minicluster-data/ts-0-root/wals/c6d550f876914b17b18d2976379663f2/wal-000000016 (ops 77-81)
I20260812 06:19:30.828966  9702 log.cc:1079] T c6d550f876914b17b18d2976379663f2 P f3687e71354e4b22a0bd1bcf72e8f106: Deleting log segment in path: /tmp/dist-test-taskWwnqpJ/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515567133744-9529-0/minicluster-data/ts-0-root/wals/c6d550f876914b17b18d2976379663f2/wal-000000017 (ops 82-86)
I20260812 06:19:30.829015  9702 log.cc:1079] T c6d550f876914b17b18d2976379663f2 P f3687e71354e4b22a0bd1bcf72e8f106: Deleting log segment in path: /tmp/dist-test-taskWwnqpJ/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515567133744-9529-0/minicluster-data/ts-0-root/wals/c6d550f876914b17b18d2976379663f2/wal-000000018 (ops 87-91)
I20260812 06:19:30.829051  9702 log.cc:1079] T c6d550f876914b17b18d2976379663f2 P f3687e71354e4b22a0bd1bcf72e8f106: Deleting log segment in path: /tmp/dist-test-taskWwnqpJ/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515567133744-9529-0/minicluster-data/ts-0-root/wals/c6d550f876914b17b18d2976379663f2/wal-000000019 (ops 92-96)
I20260812 06:19:30.829109  9702 log.cc:1079] T c6d550f876914b17b18d2976379663f2 P f3687e71354e4b22a0bd1bcf72e8f106: Deleting log segment in path: /tmp/dist-test-taskWwnqpJ/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515567133744-9529-0/minicluster-data/ts-0-root/wals/c6d550f876914b17b18d2976379663f2/wal-000000020 (ops 97-101)
I20260812 06:19:30.829136  9702 log.cc:1079] T c6d550f876914b17b18d2976379663f2 P f3687e71354e4b22a0bd1bcf72e8f106: Deleting log segment in path: /tmp/dist-test-taskWwnqpJ/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515567133744-9529-0/minicluster-data/ts-0-root/wals/c6d550f876914b17b18d2976379663f2/wal-000000021 (ops 102-106)
I20260812 06:19:30.829172  9702 log.cc:1079] T c6d550f876914b17b18d2976379663f2 P f3687e71354e4b22a0bd1bcf72e8f106: Deleting log segment in path: /tmp/dist-test-taskWwnqpJ/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515567133744-9529-0/minicluster-data/ts-0-root/wals/c6d550f876914b17b18d2976379663f2/wal-000000022 (ops 107-111)
I20260812 06:19:30.829218  9702 log.cc:1079] T c6d550f876914b17b18d2976379663f2 P f3687e71354e4b22a0bd1bcf72e8f106: Deleting log segment in path: /tmp/dist-test-taskWwnqpJ/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515567133744-9529-0/minicluster-data/ts-0-root/wals/c6d550f876914b17b18d2976379663f2/wal-000000023 (ops 112-116)
I20260812 06:19:30.829257  9702 log.cc:1079] T c6d550f876914b17b18d2976379663f2 P f3687e71354e4b22a0bd1bcf72e8f106: Deleting log segment in path: /tmp/dist-test-taskWwnqpJ/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515567133744-9529-0/minicluster-data/ts-0-root/wals/c6d550f876914b17b18d2976379663f2/wal-000000024 (ops 117-121)
I20260812 06:19:30.829298  9702 log.cc:1079] T c6d550f876914b17b18d2976379663f2 P f3687e71354e4b22a0bd1bcf72e8f106: Deleting log segment in path: /tmp/dist-test-taskWwnqpJ/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515567133744-9529-0/minicluster-data/ts-0-root/wals/c6d550f876914b17b18d2976379663f2/wal-000000025 (ops 122-126)
I20260812 06:19:30.857218  9702 maintenance_manager.cc:643] P f3687e71354e4b22a0bd1bcf72e8f106: LogGCOp(c6d550f876914b17b18d2976379663f2) complete. Timing: real 0.028s	user 0.001s	sys 0.027s Metrics: {}
I20260812 06:19:30.857645  9793 maintenance_manager.cc:419] P f3687e71354e4b22a0bd1bcf72e8f106: Scheduling UndoDeltaBlockGCOp(c6d550f876914b17b18d2976379663f2): 472 bytes on disk
I20260812 06:19:30.858103  9702 maintenance_manager.cc:643] P f3687e71354e4b22a0bd1bcf72e8f106: UndoDeltaBlockGCOp(c6d550f876914b17b18d2976379663f2) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":57,"lbm_reads_lt_1ms":4}
I20260812 06:19:30.858639  9793 maintenance_manager.cc:419] P f3687e71354e4b22a0bd1bcf72e8f106: Scheduling FlushDeltaMemStoresOp(c6d550f876914b17b18d2976379663f2): perf score=6.157687
I20260812 06:19:30.888111  9702 maintenance_manager.cc:643] P f3687e71354e4b22a0bd1bcf72e8f106: FlushDeltaMemStoresOp(c6d550f876914b17b18d2976379663f2) complete. Timing: real 0.029s	user 0.019s	sys 0.008s Metrics: {"bytes_written":8205078,"delete_count":0,"lbm_write_time_us":12722,"lbm_writes_lt_1ms":203,"reinsert_count":0,"update_count":1000}
I20260812 06:19:30.888756  9793 maintenance_manager.cc:419] P f3687e71354e4b22a0bd1bcf72e8f106: Scheduling LogGCOp(c6d550f876914b17b18d2976379663f2): free 8767130 bytes of WAL
I20260812 06:19:30.889002  9702 log_reader.cc:385] T c6d550f876914b17b18d2976379663f2: removed 1 log segments from log reader
I20260812 06:19:30.889075  9702 log.cc:1079] T c6d550f876914b17b18d2976379663f2 P f3687e71354e4b22a0bd1bcf72e8f106: Deleting log segment in path: /tmp/dist-test-taskWwnqpJ/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515567133744-9529-0/minicluster-data/ts-0-root/wals/c6d550f876914b17b18d2976379663f2/wal-000000026 (ops 127-131)
I20260812 06:19:30.890856  9702 maintenance_manager.cc:643] P f3687e71354e4b22a0bd1bcf72e8f106: LogGCOp(c6d550f876914b17b18d2976379663f2) complete. Timing: real 0.002s	user 0.000s	sys 0.000s Metrics: {}
I20260812 06:19:30.891208  9793 maintenance_manager.cc:419] P f3687e71354e4b22a0bd1bcf72e8f106: Scheduling FlushDeltaMemStoresOp(c6d550f876914b17b18d2976379663f2): perf score=2.188937
I20260812 06:19:30.903393  9702 maintenance_manager.cc:643] P f3687e71354e4b22a0bd1bcf72e8f106: FlushDeltaMemStoresOp(c6d550f876914b17b18d2976379663f2) complete. Timing: real 0.012s	user 0.006s	sys 0.003s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4411,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:30.903846  9793 maintenance_manager.cc:419] P f3687e71354e4b22a0bd1bcf72e8f106: Scheduling MajorDeltaCompactionOp(c6d550f876914b17b18d2976379663f2): perf score=1.000000
I20260812 06:19:31.120760  9702 maintenance_manager.cc:643] P f3687e71354e4b22a0bd1bcf72e8f106: MajorDeltaCompactionOp(c6d550f876914b17b18d2976379663f2) complete. Timing: real 0.217s	user 0.176s	sys 0.040s Metrics: {"cfile_cache_miss":733,"cfile_cache_miss_bytes":32979631,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":524,"lbm_read_time_us":17567,"lbm_reads_lt_1ms":773,"lbm_write_time_us":39743,"lbm_writes_lt_1ms":743,"mutex_wait_us":28,"peak_mem_usage":87969044,"reinsert_count":0,"spinlock_wait_cycles":24704,"thread_start_us":72,"threads_started":1,"update_count":3500}
I20260812 06:19:31.121410  9793 maintenance_manager.cc:419] P f3687e71354e4b22a0bd1bcf72e8f106: Scheduling FlushDeltaMemStoresOp(c6d550f876914b17b18d2976379663f2): perf score=18.063937
I20260812 06:19:31.180262  9702 maintenance_manager.cc:643] P f3687e71354e4b22a0bd1bcf72e8f106: FlushDeltaMemStoresOp(c6d550f876914b17b18d2976379663f2) complete. Timing: real 0.059s	user 0.046s	sys 0.009s Metrics: {"bytes_written":20512317,"delete_count":0,"lbm_write_time_us":26493,"lbm_writes_lt_1ms":503,"reinsert_count":0,"spinlock_wait_cycles":1408,"update_count":2500}
I20260812 06:19:31.180994  9793 maintenance_manager.cc:419] P f3687e71354e4b22a0bd1bcf72e8f106: Scheduling FlushDeltaMemStoresOp(c6d550f876914b17b18d2976379663f2): perf score=2.188937
I20260812 06:19:31.193925  9702 maintenance_manager.cc:643] P f3687e71354e4b22a0bd1bcf72e8f106: FlushDeltaMemStoresOp(c6d550f876914b17b18d2976379663f2) complete. Timing: real 0.013s	user 0.003s	sys 0.009s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4905,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:31.194386  9793 maintenance_manager.cc:419] P f3687e71354e4b22a0bd1bcf72e8f106: Scheduling MajorDeltaCompactionOp(c6d550f876914b17b18d2976379663f2): perf score=1.000000
I20260812 06:19:31.361425  9702 maintenance_manager.cc:643] P f3687e71354e4b22a0bd1bcf72e8f106: MajorDeltaCompactionOp(c6d550f876914b17b18d2976379663f2) complete. Timing: real 0.167s	user 0.135s	sys 0.032s Metrics: {"cfile_cache_miss":632,"cfile_cache_miss_bytes":28877104,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":321,"lbm_read_time_us":11959,"lbm_reads_lt_1ms":672,"lbm_write_time_us":35085,"lbm_writes_lt_1ms":643,"mutex_wait_us":26,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":2816,"update_count":3000}
I20260812 06:19:31.361989  9793 maintenance_manager.cc:419] P f3687e71354e4b22a0bd1bcf72e8f106: Scheduling FlushDeltaMemStoresOp(c6d550f876914b17b18d2976379663f2): perf score=14.095187
I20260812 06:19:31.415078  9702 maintenance_manager.cc:643] P f3687e71354e4b22a0bd1bcf72e8f106: FlushDeltaMemStoresOp(c6d550f876914b17b18d2976379663f2) complete. Timing: real 0.053s	user 0.029s	sys 0.011s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":19041,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:31.415632  9793 maintenance_manager.cc:419] P f3687e71354e4b22a0bd1bcf72e8f106: Scheduling FlushDeltaMemStoresOp(c6d550f876914b17b18d2976379663f2): perf score=2.188937
I20260812 06:19:31.431277  9702 maintenance_manager.cc:643] P f3687e71354e4b22a0bd1bcf72e8f106: FlushDeltaMemStoresOp(c6d550f876914b17b18d2976379663f2) complete. Timing: real 0.015s	user 0.005s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5925,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:31.431823  9793 maintenance_manager.cc:419] P f3687e71354e4b22a0bd1bcf72e8f106: Scheduling MajorDeltaCompactionOp(c6d550f876914b17b18d2976379663f2): perf score=1.000000
I20260812 06:19:31.604708  9702 maintenance_manager.cc:643] P f3687e71354e4b22a0bd1bcf72e8f106: MajorDeltaCompactionOp(c6d550f876914b17b18d2976379663f2) complete. Timing: real 0.173s	user 0.127s	sys 0.039s 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":168,"lbm_read_time_us":10506,"lbm_reads_lt_1ms":572,"lbm_write_time_us":33385,"lbm_writes_lt_1ms":543,"mutex_wait_us":81,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":39296,"update_count":2500}
I20260812 06:19:31.605320  9793 maintenance_manager.cc:419] P f3687e71354e4b22a0bd1bcf72e8f106: Scheduling FlushDeltaMemStoresOp(c6d550f876914b17b18d2976379663f2): perf score=14.095187
I20260812 06:19:31.651036  9702 maintenance_manager.cc:643] P f3687e71354e4b22a0bd1bcf72e8f106: FlushDeltaMemStoresOp(c6d550f876914b17b18d2976379663f2) complete. Timing: real 0.045s	user 0.023s	sys 0.019s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":20552,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:31.651583  9793 maintenance_manager.cc:419] P f3687e71354e4b22a0bd1bcf72e8f106: Scheduling MajorDeltaCompactionOp(c6d550f876914b17b18d2976379663f2): perf score=1.000000
I20260812 06:19:31.813400  9702 maintenance_manager.cc:643] P f3687e71354e4b22a0bd1bcf72e8f106: MajorDeltaCompactionOp(c6d550f876914b17b18d2976379663f2) complete. Timing: real 0.162s	user 0.121s	sys 0.039s Metrics: {"cfile_cache_miss":431,"cfile_cache_miss_bytes":20672158,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":1,"delta_iterators_relevant":1,"dirs.queue_time_us":552,"lbm_read_time_us":11315,"lbm_reads_lt_1ms":467,"lbm_write_time_us":27371,"lbm_writes_lt_1ms":443,"mutex_wait_us":329,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":6016,"update_count":2000}
I20260812 06:19:31.814265  9793 maintenance_manager.cc:419] P f3687e71354e4b22a0bd1bcf72e8f106: Scheduling FlushDeltaMemStoresOp(c6d550f876914b17b18d2976379663f2): perf score=11.118625
I20260812 06:19:31.853693  9702 maintenance_manager.cc:643] P f3687e71354e4b22a0bd1bcf72e8f106: FlushDeltaMemStoresOp(c6d550f876914b17b18d2976379663f2) complete. Timing: real 0.039s	user 0.025s	sys 0.011s Metrics: {"bytes_written":12717735,"delete_count":0,"lbm_write_time_us":16410,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:19:31.854262  9793 maintenance_manager.cc:419] P f3687e71354e4b22a0bd1bcf72e8f106: Scheduling FlushDeltaMemStoresOp(c6d550f876914b17b18d2976379663f2): perf score=2.188937
I20260812 06:19:31.873358  9702 maintenance_manager.cc:643] P f3687e71354e4b22a0bd1bcf72e8f106: FlushDeltaMemStoresOp(c6d550f876914b17b18d2976379663f2) complete. Timing: real 0.019s	user 0.006s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4345,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:31.873831  9793 maintenance_manager.cc:419] P f3687e71354e4b22a0bd1bcf72e8f106: Scheduling FlushDeltaMemStoresOp(c6d550f876914b17b18d2976379663f2): perf score=2.188937
I20260812 06:19:31.883890  9702 maintenance_manager.cc:643] P f3687e71354e4b22a0bd1bcf72e8f106: FlushDeltaMemStoresOp(c6d550f876914b17b18d2976379663f2) complete. Timing: real 0.010s	user 0.005s	sys 0.004s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3840,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:19:31.884428  9793 maintenance_manager.cc:419] P f3687e71354e4b22a0bd1bcf72e8f106: Scheduling MajorDeltaCompactionOp(c6d550f876914b17b18d2976379663f2): perf score=1.000000
I20260812 06:19:32.063606  9702 maintenance_manager.cc:643] P f3687e71354e4b22a0bd1bcf72e8f106: MajorDeltaCompactionOp(c6d550f876914b17b18d2976379663f2) complete. Timing: real 0.179s	user 0.099s	sys 0.072s Metrics: {"cfile_cache_miss":533,"cfile_cache_miss_bytes":24774799,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":739,"lbm_read_time_us":11696,"lbm_reads_lt_1ms":573,"lbm_write_time_us":30057,"lbm_writes_lt_1ms":543,"mutex_wait_us":283,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":11136,"update_count":2500}
I20260812 06:19:32.064376  9793 maintenance_manager.cc:419] P f3687e71354e4b22a0bd1bcf72e8f106: Scheduling FlushDeltaMemStoresOp(c6d550f876914b17b18d2976379663f2): perf score=14.095187
I20260812 06:19:32.121001  9702 maintenance_manager.cc:643] P f3687e71354e4b22a0bd1bcf72e8f106: FlushDeltaMemStoresOp(c6d550f876914b17b18d2976379663f2) complete. Timing: real 0.056s	user 0.027s	sys 0.015s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":18748,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:32.121526  9793 maintenance_manager.cc:419] P f3687e71354e4b22a0bd1bcf72e8f106: Scheduling FlushDeltaMemStoresOp(c6d550f876914b17b18d2976379663f2): perf score=2.188937
I20260812 06:19:32.134666  9702 maintenance_manager.cc:643] P f3687e71354e4b22a0bd1bcf72e8f106: FlushDeltaMemStoresOp(c6d550f876914b17b18d2976379663f2) complete. Timing: real 0.013s	user 0.006s	sys 0.005s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4590,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:32.135223  9793 maintenance_manager.cc:419] P f3687e71354e4b22a0bd1bcf72e8f106: Scheduling MajorDeltaCompactionOp(c6d550f876914b17b18d2976379663f2): perf score=1.000000
I20260812 06:19:32.307601  9702 maintenance_manager.cc:643] P f3687e71354e4b22a0bd1bcf72e8f106: MajorDeltaCompactionOp(c6d550f876914b17b18d2976379663f2) complete. Timing: real 0.172s	user 0.122s	sys 0.045s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774688,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":643,"lbm_read_time_us":11413,"lbm_reads_lt_1ms":572,"lbm_write_time_us":34452,"lbm_writes_lt_1ms":543,"mutex_wait_us":26,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":68736,"update_count":2500}
I20260812 06:19:32.308344  9793 maintenance_manager.cc:419] P f3687e71354e4b22a0bd1bcf72e8f106: Scheduling FlushDeltaMemStoresOp(c6d550f876914b17b18d2976379663f2): perf score=11.118625
I20260812 06:19:32.349186  9702 maintenance_manager.cc:643] P f3687e71354e4b22a0bd1bcf72e8f106: FlushDeltaMemStoresOp(c6d550f876914b17b18d2976379663f2) complete. Timing: real 0.041s	user 0.028s	sys 0.012s Metrics: {"bytes_written":13251052,"delete_count":0,"lbm_write_time_us":17754,"lbm_writes_lt_1ms":326,"reinsert_count":0,"update_count":1615}
I20260812 06:19:32.351480  9793 maintenance_manager.cc:419] P f3687e71354e4b22a0bd1bcf72e8f106: Scheduling FlushDeltaMemStoresOp(c6d550f876914b17b18d2976379663f2): perf score=1.196750
I20260812 06:19:32.364775  9702 maintenance_manager.cc:643] P f3687e71354e4b22a0bd1bcf72e8f106: FlushDeltaMemStoresOp(c6d550f876914b17b18d2976379663f2) complete. Timing: real 0.013s	user 0.012s	sys 0.000s Metrics: {"bytes_written":3159080,"delete_count":0,"lbm_write_time_us":4413,"lbm_writes_lt_1ms":80,"reinsert_count":0,"update_count":385}
I20260812 06:19:32.365324  9793 maintenance_manager.cc:419] P f3687e71354e4b22a0bd1bcf72e8f106: Scheduling FlushMRSOp(c6d550f876914b17b18d2976379663f2): perf score=1.000000
I20260812 06:19:32.417833  9702 maintenance_manager.cc:643] P f3687e71354e4b22a0bd1bcf72e8f106: FlushMRSOp(c6d550f876914b17b18d2976379663f2) complete. Timing: real 0.052s	user 0.028s	sys 0.003s Metrics: {"bytes_written":1316417,"cfile_init":1,"dirs.queue_time_us":56,"dirs.run_cpu_time_us":208,"dirs.run_wall_time_us":1451,"drs_written":1,"lbm_read_time_us":61,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1889,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":32}
I20260812 06:19:32.418632  9793 maintenance_manager.cc:419] P f3687e71354e4b22a0bd1bcf72e8f106: Scheduling LogGCOp(c6d550f876914b17b18d2976379663f2): free 121006697 bytes of WAL
I20260812 06:19:32.418897  9702 log_reader.cc:385] T c6d550f876914b17b18d2976379663f2: removed 12 log segments from log reader
I20260812 06:19:32.418947  9702 log.cc:1079] T c6d550f876914b17b18d2976379663f2 P f3687e71354e4b22a0bd1bcf72e8f106: Deleting log segment in path: /tmp/dist-test-taskWwnqpJ/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515567133744-9529-0/minicluster-data/ts-0-root/wals/c6d550f876914b17b18d2976379663f2/wal-000000027 (ops 132-136)
I20260812 06:19:32.418978  9702 log.cc:1079] T c6d550f876914b17b18d2976379663f2 P f3687e71354e4b22a0bd1bcf72e8f106: Deleting log segment in path: /tmp/dist-test-taskWwnqpJ/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515567133744-9529-0/minicluster-data/ts-0-root/wals/c6d550f876914b17b18d2976379663f2/wal-000000028 (ops 137-141)
I20260812 06:19:32.419044  9702 log.cc:1079] T c6d550f876914b17b18d2976379663f2 P f3687e71354e4b22a0bd1bcf72e8f106: Deleting log segment in path: /tmp/dist-test-taskWwnqpJ/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515567133744-9529-0/minicluster-data/ts-0-root/wals/c6d550f876914b17b18d2976379663f2/wal-000000029 (ops 142-146)
I20260812 06:19:32.419090  9702 log.cc:1079] T c6d550f876914b17b18d2976379663f2 P f3687e71354e4b22a0bd1bcf72e8f106: Deleting log segment in path: /tmp/dist-test-taskWwnqpJ/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515567133744-9529-0/minicluster-data/ts-0-root/wals/c6d550f876914b17b18d2976379663f2/wal-000000030 (ops 147-151)
I20260812 06:19:32.419133  9702 log.cc:1079] T c6d550f876914b17b18d2976379663f2 P f3687e71354e4b22a0bd1bcf72e8f106: Deleting log segment in path: /tmp/dist-test-taskWwnqpJ/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515567133744-9529-0/minicluster-data/ts-0-root/wals/c6d550f876914b17b18d2976379663f2/wal-000000031 (ops 152-156)
I20260812 06:19:32.419194  9702 log.cc:1079] T c6d550f876914b17b18d2976379663f2 P f3687e71354e4b22a0bd1bcf72e8f106: Deleting log segment in path: /tmp/dist-test-taskWwnqpJ/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515567133744-9529-0/minicluster-data/ts-0-root/wals/c6d550f876914b17b18d2976379663f2/wal-000000032 (ops 157-161)
I20260812 06:19:32.419232  9702 log.cc:1079] T c6d550f876914b17b18d2976379663f2 P f3687e71354e4b22a0bd1bcf72e8f106: Deleting log segment in path: /tmp/dist-test-taskWwnqpJ/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515567133744-9529-0/minicluster-data/ts-0-root/wals/c6d550f876914b17b18d2976379663f2/wal-000000033 (ops 162-166)
I20260812 06:19:32.419287  9702 log.cc:1079] T c6d550f876914b17b18d2976379663f2 P f3687e71354e4b22a0bd1bcf72e8f106: Deleting log segment in path: /tmp/dist-test-taskWwnqpJ/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515567133744-9529-0/minicluster-data/ts-0-root/wals/c6d550f876914b17b18d2976379663f2/wal-000000034 (ops 167-171)
I20260812 06:19:32.419328  9702 log.cc:1079] T c6d550f876914b17b18d2976379663f2 P f3687e71354e4b22a0bd1bcf72e8f106: Deleting log segment in path: /tmp/dist-test-taskWwnqpJ/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515567133744-9529-0/minicluster-data/ts-0-root/wals/c6d550f876914b17b18d2976379663f2/wal-000000035 (ops 172-176)
I20260812 06:19:32.419382  9702 log.cc:1079] T c6d550f876914b17b18d2976379663f2 P f3687e71354e4b22a0bd1bcf72e8f106: Deleting log segment in path: /tmp/dist-test-taskWwnqpJ/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515567133744-9529-0/minicluster-data/ts-0-root/wals/c6d550f876914b17b18d2976379663f2/wal-000000036 (ops 177-180)
I20260812 06:19:32.419421  9702 log.cc:1079] T c6d550f876914b17b18d2976379663f2 P f3687e71354e4b22a0bd1bcf72e8f106: Deleting log segment in path: /tmp/dist-test-taskWwnqpJ/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515567133744-9529-0/minicluster-data/ts-0-root/wals/c6d550f876914b17b18d2976379663f2/wal-000000037 (ops 181-185)
I20260812 06:19:32.419461  9702 log.cc:1079] T c6d550f876914b17b18d2976379663f2 P f3687e71354e4b22a0bd1bcf72e8f106: Deleting log segment in path: /tmp/dist-test-taskWwnqpJ/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515567133744-9529-0/minicluster-data/ts-0-root/wals/c6d550f876914b17b18d2976379663f2/wal-000000038 (ops 186-190)
I20260812 06:19:32.445178  9702 maintenance_manager.cc:643] P f3687e71354e4b22a0bd1bcf72e8f106: LogGCOp(c6d550f876914b17b18d2976379663f2) complete. Timing: real 0.026s	user 0.000s	sys 0.026s Metrics: {}
I20260812 06:19:32.445660  9793 maintenance_manager.cc:419] P f3687e71354e4b22a0bd1bcf72e8f106: Scheduling UndoDeltaBlockGCOp(c6d550f876914b17b18d2976379663f2): 492 bytes on disk
I20260812 06:19:32.446151  9702 maintenance_manager.cc:643] P f3687e71354e4b22a0bd1bcf72e8f106: UndoDeltaBlockGCOp(c6d550f876914b17b18d2976379663f2) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":54,"lbm_reads_lt_1ms":4}
I20260812 06:19:32.446887  9793 maintenance_manager.cc:419] P f3687e71354e4b22a0bd1bcf72e8f106: Scheduling FlushDeltaMemStoresOp(c6d550f876914b17b18d2976379663f2): perf score=7.149875
I20260812 06:19:32.477303  9702 maintenance_manager.cc:643] P f3687e71354e4b22a0bd1bcf72e8f106: FlushDeltaMemStoresOp(c6d550f876914b17b18d2976379663f2) complete. Timing: real 0.030s	user 0.007s	sys 0.023s Metrics: {"bytes_written":8615324,"delete_count":0,"lbm_write_time_us":9309,"lbm_writes_lt_1ms":213,"reinsert_count":0,"update_count":1050}
I20260812 06:19:32.477910  9793 maintenance_manager.cc:419] P f3687e71354e4b22a0bd1bcf72e8f106: Scheduling LogGCOp(c6d550f876914b17b18d2976379663f2): free 12017957 bytes of WAL
I20260812 06:19:32.478142  9702 log_reader.cc:385] T c6d550f876914b17b18d2976379663f2: removed 1 log segments from log reader
I20260812 06:19:32.478188  9702 log.cc:1079] T c6d550f876914b17b18d2976379663f2 P f3687e71354e4b22a0bd1bcf72e8f106: Deleting log segment in path: /tmp/dist-test-taskWwnqpJ/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515567133744-9529-0/minicluster-data/ts-0-root/wals/c6d550f876914b17b18d2976379663f2/wal-000000039 (ops 191-195)
I20260812 06:19:32.480629  9702 maintenance_manager.cc:643] P f3687e71354e4b22a0bd1bcf72e8f106: LogGCOp(c6d550f876914b17b18d2976379663f2) complete. Timing: real 0.003s	user 0.000s	sys 0.000s Metrics: {}
I20260812 06:19:32.481025  9793 maintenance_manager.cc:419] P f3687e71354e4b22a0bd1bcf72e8f106: Scheduling FlushDeltaMemStoresOp(c6d550f876914b17b18d2976379663f2): perf score=2.188937
I20260812 06:19:32.492518  9702 maintenance_manager.cc:643] P f3687e71354e4b22a0bd1bcf72e8f106: FlushDeltaMemStoresOp(c6d550f876914b17b18d2976379663f2) complete. Timing: real 0.011s	user 0.009s	sys 0.000s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":4254,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:19:32.493631  9793 maintenance_manager.cc:419] P f3687e71354e4b22a0bd1bcf72e8f106: Scheduling MajorDeltaCompactionOp(c6d550f876914b17b18d2976379663f2): perf score=1.000000
I20260812 06:19:32.590464  9529 heavy-update-compaction-itest.cc:229] Time spent updating: real 5.165s	user 1.922s	sys 0.150s
I20260812 06:19:32.698264  9529 heavy-update-compaction-itest.cc:265] Time spent scanning: real 0.107s	user 0.004s	sys 0.000s
I20260812 06:19:32.699105  9529 tablet_server.cc:179] TabletServer@127.9.78.65:0 shutting down...
I20260812 06:19:32.714977  9702 maintenance_manager.cc:643] P f3687e71354e4b22a0bd1bcf72e8f106: MajorDeltaCompactionOp(c6d550f876914b17b18d2976379663f2) complete. Timing: real 0.221s	user 0.129s	sys 0.092s Metrics: {"cfile_cache_miss":734,"cfile_cache_miss_bytes":32979727,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":637,"lbm_read_time_us":16991,"lbm_reads_lt_1ms":770,"lbm_write_time_us":33905,"lbm_writes_lt_1ms":743,"mutex_wait_us":27,"peak_mem_usage":87969044,"reinsert_count":0,"spinlock_wait_cycles":27136,"thread_start_us":105,"threads_started":1,"update_count":3500}
I20260812 06:19:32.716482  9529 ts_tablet_manager.cc:1507] Shutting down tablet manager...
I20260812 06:19:32.717051  9529 tablet_replica.cc:333] T c6d550f876914b17b18d2976379663f2 P f3687e71354e4b22a0bd1bcf72e8f106: stopping tablet replica
I20260812 06:19:32.717332  9529 raft_consensus.cc:2243] T c6d550f876914b17b18d2976379663f2 P f3687e71354e4b22a0bd1bcf72e8f106 [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:19:32.717600  9529 raft_consensus.cc:2272] T c6d550f876914b17b18d2976379663f2 P f3687e71354e4b22a0bd1bcf72e8f106 [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:19:32.734946  9529 tablet_server.cc:196] TabletServer@127.9.78.65:0 shutdown complete.
I20260812 06:19:32.773952  9529 master.cc:562] Master@127.9.78.126:34333 shutting down...
I20260812 06:19:32.777967  9529 raft_consensus.cc:2243] T 00000000000000000000000000000000 P 1e76a7d00d214a98aa3dc6ff29aa78f9 [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:19:32.778139  9529 raft_consensus.cc:2272] T 00000000000000000000000000000000 P 1e76a7d00d214a98aa3dc6ff29aa78f9 [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:19:32.778203  9529 tablet_replica.cc:333] T 00000000000000000000000000000000 P 1e76a7d00d214a98aa3dc6ff29aa78f9: stopping tablet replica
I20260812 06:19:32.791826  9529 master.cc:584] Master@127.9.78.126:34333 shutdown complete.
[       OK ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/0 (5740 ms)
[ RUN      ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/1
I20260812 06:19:32.899904  9529 internal_mini_cluster.cc:156] Creating distributed mini masters. Addrs: 127.9.78.126:33273
I20260812 06:19:32.900302  9529 file_cache.cc:504] Constructed file cache file cache with capacity 419430
I20260812 06:19:32.903086  9529 server_base.cc:1061] running on GCE node
W20260812 06:19:32.903160  9841 instance_detector.cc:116] could not retrieve Azure instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:19:32.903195  9840 instance_detector.cc:116] could not retrieve AWS instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:19:32.903170  9848 instance_detector.cc:116] could not retrieve OpenStack instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:19:32.903523  9529 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:19:32.903570  9529 system_unsync_time.cc:38] NTP support is disabled. Clock error bounds will not be accurate. This configuration is not suitable for distributed clusters.
I20260812 06:19:32.903586  9529 hybrid_clock.cc:648] HybridClock initialized: now 1786515572903586 us; error 0 us; skew 500 ppm
I20260812 06:19:32.904479  9529 webserver.cc:533] Webserver started at http://127.9.78.126:35165/ using document root <none> and password file <none>
I20260812 06:19:32.904663  9529 fs_manager.cc:362] Metadata directory not provided
I20260812 06:19:32.904765  9529 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:19:32.904847  9529 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:19:32.905262  9529 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskWwnqpJ/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515567133744-9529-0/minicluster-data/master-0-root/instance:
uuid: "9e0320a749c74345b05ee4a5bf839b3c"
format_stamp: "Formatted at 2026-08-12 06:19:32 on dist-test-slave-s11t"
I20260812 06:19:32.906875  9529 fs_manager.cc:696] Time spent creating directory manager: real 0.001s	user 0.000s	sys 0.002s
I20260812 06:19:32.907876  9857 log_block_manager.cc:4127] Time spent loading block containers with low live blocks: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:19:32.908186  9529 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.000s	sys 0.001s
I20260812 06:19:32.908278  9529 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskWwnqpJ/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515567133744-9529-0/minicluster-data/master-0-root
uuid: "9e0320a749c74345b05ee4a5bf839b3c"
format_stamp: "Formatted at 2026-08-12 06:19:32 on dist-test-slave-s11t"
I20260812 06:19:32.908386  9529 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskWwnqpJ/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515567133744-9529-0/minicluster-data/master-0-root
metadata directory: /tmp/dist-test-taskWwnqpJ/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515567133744-9529-0/minicluster-data/master-0-root
1 data directories: /tmp/dist-test-taskWwnqpJ/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515567133744-9529-0/minicluster-data/master-0-root/data
Total live blocks: 0
Total live bytes: 0
Total live bytes (after alignment): 0
Total number of LBM containers: 0 (0 full)
Did not check for missing blocks
Did not check for orphaned blocks
Total full LBM containers with extra space: 0 (0 repaired)
Total full LBM container extra space in bytes: 0 (0 repaired)
Total incomplete LBM containers: 0 (0 repaired)
Total LBM partial records: 0 (0 repaired)
Total corrupted LBM metadata records in RocksDB: 0 (0 repaired)
I20260812 06:19:32.955893  9529 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:19:32.956343  9529 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:19:32.960475  9529 rpc_server.cc:307] RPC server started. Bound to: 127.9.78.126:33273
I20260812 06:19:32.965842  9957 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.9.78.126:33273 every 8 connection(s)
I20260812 06:19:32.965878  9958 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet 00000000000000000000000000000000. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:19:32.967734  9958 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P 9e0320a749c74345b05ee4a5bf839b3c: Bootstrap starting.
I20260812 06:19:32.968575  9958 tablet_bootstrap.cc:654] T 00000000000000000000000000000000 P 9e0320a749c74345b05ee4a5bf839b3c: Neither blocks nor log segments found. Creating new log.
I20260812 06:19:32.969722  9958 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P 9e0320a749c74345b05ee4a5bf839b3c: No bootstrap required, opened a new log
I20260812 06:19:32.970170  9958 raft_consensus.cc:359] T 00000000000000000000000000000000 P 9e0320a749c74345b05ee4a5bf839b3c [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "9e0320a749c74345b05ee4a5bf839b3c" member_type: VOTER }
I20260812 06:19:32.970281  9958 raft_consensus.cc:385] T 00000000000000000000000000000000 P 9e0320a749c74345b05ee4a5bf839b3c [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:19:32.970332  9958 raft_consensus.cc:740] T 00000000000000000000000000000000 P 9e0320a749c74345b05ee4a5bf839b3c [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: 9e0320a749c74345b05ee4a5bf839b3c, State: Initialized, Role: FOLLOWER
I20260812 06:19:32.970525  9958 consensus_queue.cc:260] T 00000000000000000000000000000000 P 9e0320a749c74345b05ee4a5bf839b3c [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: "9e0320a749c74345b05ee4a5bf839b3c" member_type: VOTER }
I20260812 06:19:32.970619  9958 raft_consensus.cc:399] T 00000000000000000000000000000000 P 9e0320a749c74345b05ee4a5bf839b3c [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:19:32.970688  9958 raft_consensus.cc:493] T 00000000000000000000000000000000 P 9e0320a749c74345b05ee4a5bf839b3c [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:19:32.970748  9958 raft_consensus.cc:3060] T 00000000000000000000000000000000 P 9e0320a749c74345b05ee4a5bf839b3c [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:19:32.971506  9958 raft_consensus.cc:515] T 00000000000000000000000000000000 P 9e0320a749c74345b05ee4a5bf839b3c [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "9e0320a749c74345b05ee4a5bf839b3c" member_type: VOTER }
I20260812 06:19:32.971658  9958 leader_election.cc:304] T 00000000000000000000000000000000 P 9e0320a749c74345b05ee4a5bf839b3c [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: 9e0320a749c74345b05ee4a5bf839b3c; no voters: 
I20260812 06:19:32.971870  9958 leader_election.cc:290] T 00000000000000000000000000000000 P 9e0320a749c74345b05ee4a5bf839b3c [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:19:32.971998  9963 raft_consensus.cc:2804] T 00000000000000000000000000000000 P 9e0320a749c74345b05ee4a5bf839b3c [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:19:32.972241  9963 raft_consensus.cc:697] T 00000000000000000000000000000000 P 9e0320a749c74345b05ee4a5bf839b3c [term 1 LEADER]: Becoming Leader. State: Replica: 9e0320a749c74345b05ee4a5bf839b3c, State: Running, Role: LEADER
I20260812 06:19:32.972383  9963 consensus_queue.cc:237] T 00000000000000000000000000000000 P 9e0320a749c74345b05ee4a5bf839b3c [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: "9e0320a749c74345b05ee4a5bf839b3c" member_type: VOTER }
I20260812 06:19:32.972391  9958 sys_catalog.cc:565] T 00000000000000000000000000000000 P 9e0320a749c74345b05ee4a5bf839b3c [sys.catalog]: configured and running, proceeding with master startup.
I20260812 06:19:32.972901  9964 sys_catalog.cc:455] T 00000000000000000000000000000000 P 9e0320a749c74345b05ee4a5bf839b3c [sys.catalog]: SysCatalogTable state changed. Reason: RaftConsensus started. Latest consensus state: current_term: 1 leader_uuid: "9e0320a749c74345b05ee4a5bf839b3c" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "9e0320a749c74345b05ee4a5bf839b3c" member_type: VOTER } }
I20260812 06:19:32.972924  9965 sys_catalog.cc:455] T 00000000000000000000000000000000 P 9e0320a749c74345b05ee4a5bf839b3c [sys.catalog]: SysCatalogTable state changed. Reason: New leader 9e0320a749c74345b05ee4a5bf839b3c. Latest consensus state: current_term: 1 leader_uuid: "9e0320a749c74345b05ee4a5bf839b3c" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "9e0320a749c74345b05ee4a5bf839b3c" member_type: VOTER } }
I20260812 06:19:32.973070  9964 sys_catalog.cc:458] T 00000000000000000000000000000000 P 9e0320a749c74345b05ee4a5bf839b3c [sys.catalog]: This master's current role is: LEADER
I20260812 06:19:32.973152  9965 sys_catalog.cc:458] T 00000000000000000000000000000000 P 9e0320a749c74345b05ee4a5bf839b3c [sys.catalog]: This master's current role is: LEADER
I20260812 06:19:32.973640  9969 catalog_manager.cc:1511] Loading table and tablet metadata into memory...
I20260812 06:19:32.974444  9969 catalog_manager.cc:1520] Initializing Kudu cluster ID...
I20260812 06:19:32.974622  9529 internal_mini_cluster.cc:184] Waiting to initialize catalog manager on master 0
I20260812 06:19:32.976300  9969 catalog_manager.cc:1383] Generated new cluster ID: 0726d32c496148f8be877f2ace1a13c3
I20260812 06:19:32.976359  9969 catalog_manager.cc:1531] Initializing Kudu internal certificate authority...
I20260812 06:19:32.985308  9969 catalog_manager.cc:1406] Generated new certificate authority record
I20260812 06:19:32.985891  9969 catalog_manager.cc:1540] Loading token signing keys...
I20260812 06:19:32.997354  9969 catalog_manager.cc:6092] T 00000000000000000000000000000000 P 9e0320a749c74345b05ee4a5bf839b3c: Generated new TSK 0
I20260812 06:19:32.997565  9969 catalog_manager.cc:1550] Initializing in-progress tserver states...
I20260812 06:19:33.007398  9529 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:19:33.009645  9997 instance_detector.cc:116] could not retrieve OpenStack instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:19:33.009773  9995 instance_detector.cc:116] could not retrieve Azure instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:19:33.009781  9993 instance_detector.cc:116] could not retrieve AWS instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:19:33.010007  9529 server_base.cc:1061] running on GCE node
I20260812 06:19:33.010161  9529 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:19:33.010197  9529 system_unsync_time.cc:38] NTP support is disabled. Clock error bounds will not be accurate. This configuration is not suitable for distributed clusters.
I20260812 06:19:33.010212  9529 hybrid_clock.cc:648] HybridClock initialized: now 1786515573010213 us; error 0 us; skew 500 ppm
I20260812 06:19:33.011053  9529 webserver.cc:533] Webserver started at http://127.9.78.65:35127/ using document root <none> and password file <none>
I20260812 06:19:33.011189  9529 fs_manager.cc:362] Metadata directory not provided
I20260812 06:19:33.011233  9529 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:19:33.011291  9529 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:19:33.011716  9529 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskWwnqpJ/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515567133744-9529-0/minicluster-data/ts-0-root/instance:
uuid: "3a7f3c71c2e642f6b419e61ab2e00625"
format_stamp: "Formatted at 2026-08-12 06:19:33 on dist-test-slave-s11t"
I20260812 06:19:33.013294  9529 fs_manager.cc:696] Time spent creating directory manager: real 0.001s	user 0.002s	sys 0.000s
I20260812 06:19:33.014312 10005 log_block_manager.cc:4127] Time spent loading block containers with low live blocks: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:19:33.014642  9529 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.001s	sys 0.000s
I20260812 06:19:33.014760  9529 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskWwnqpJ/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515567133744-9529-0/minicluster-data/ts-0-root
uuid: "3a7f3c71c2e642f6b419e61ab2e00625"
format_stamp: "Formatted at 2026-08-12 06:19:33 on dist-test-slave-s11t"
I20260812 06:19:33.014871  9529 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskWwnqpJ/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515567133744-9529-0/minicluster-data/ts-0-root
metadata directory: /tmp/dist-test-taskWwnqpJ/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515567133744-9529-0/minicluster-data/ts-0-root
1 data directories: /tmp/dist-test-taskWwnqpJ/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515567133744-9529-0/minicluster-data/ts-0-root/data
Total live blocks: 0
Total live bytes: 0
Total live bytes (after alignment): 0
Total number of LBM containers: 0 (0 full)
Did not check for missing blocks
Did not check for orphaned blocks
Total full LBM containers with extra space: 0 (0 repaired)
Total full LBM container extra space in bytes: 0 (0 repaired)
Total incomplete LBM containers: 0 (0 repaired)
Total LBM partial records: 0 (0 repaired)
Total corrupted LBM metadata records in RocksDB: 0 (0 repaired)
I20260812 06:19:33.024839  9529 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:19:33.025235  9529 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:19:33.025557  9529 txn_system_client.cc:432] TxnSystemClient initialization is disabled...
I20260812 06:19:33.026113  9529 ts_tablet_manager.cc:585] Loaded tablet metadata (0 total tablets, 0 live tablets)
I20260812 06:19:33.026175  9529 ts_tablet_manager.cc:531] Time spent load tablet metadata: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:19:33.026234  9529 ts_tablet_manager.cc:616] Registered 0 tablets
I20260812 06:19:33.026291  9529 ts_tablet_manager.cc:595] Time spent register tablets: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:19:33.030880  9529 rpc_server.cc:307] RPC server started. Bound to: 127.9.78.65:33261
I20260812 06:19:33.033130 10119 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.9.78.65:33261 every 8 connection(s)
I20260812 06:19:33.041190 10120 heartbeater.cc:344] Connected to a master server at 127.9.78.126:33273
I20260812 06:19:33.041317 10120 heartbeater.cc:461] Registering TS with master...
I20260812 06:19:33.041594 10120 heartbeater.cc:507] Master 127.9.78.126:33273 requested a full tablet report, sending...
I20260812 06:19:33.042273  9885 ts_manager.cc:194] Registered new tserver with Master: 3a7f3c71c2e642f6b419e61ab2e00625 (127.9.78.65:33261)
I20260812 06:19:33.043094  9885 master_service.cc:502] Signed X509 certificate for tserver {username='slave'} at 127.0.0.1:58606
I20260812 06:19:33.043103  9529 internal_mini_cluster.cc:371] 1 TS(s) registered with all masters after 0.011175516s
I20260812 06:19:33.051091  9885 catalog_manager.cc:2283] Servicing CreateTable request from {username='slave'} at 127.0.0.1:58610:
name: "heavy-update-compaction-test"
schema {
  columns {
    name: "key"
    type: INT64
    is_key: true
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_a"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_b"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_c"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_d"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_e"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
}
num_replicas: 1
split_rows_range_bounds {
}
partition_schema {
  range_schema {
  }
}
I20260812 06:19:33.060465 10060 tablet_service.cc:1511] Processing CreateTablet for tablet 3513f4a5c07c45fd87231b0e93162473 (DEFAULT_TABLE table=heavy-update-compaction-test [id=d049a6830bfc405a8902068fed406f71]), partition=
I20260812 06:19:33.060833 10060 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet 3513f4a5c07c45fd87231b0e93162473. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:19:33.063201 10137 tablet_bootstrap.cc:492] T 3513f4a5c07c45fd87231b0e93162473 P 3a7f3c71c2e642f6b419e61ab2e00625: Bootstrap starting.
I20260812 06:19:33.064244 10137 tablet_bootstrap.cc:654] T 3513f4a5c07c45fd87231b0e93162473 P 3a7f3c71c2e642f6b419e61ab2e00625: Neither blocks nor log segments found. Creating new log.
I20260812 06:19:33.065645 10137 tablet_bootstrap.cc:492] T 3513f4a5c07c45fd87231b0e93162473 P 3a7f3c71c2e642f6b419e61ab2e00625: No bootstrap required, opened a new log
I20260812 06:19:33.065774 10137 ts_tablet_manager.cc:1403] T 3513f4a5c07c45fd87231b0e93162473 P 3a7f3c71c2e642f6b419e61ab2e00625: Time spent bootstrapping tablet: real 0.003s	user 0.000s	sys 0.002s
I20260812 06:19:33.066264 10137 raft_consensus.cc:359] T 3513f4a5c07c45fd87231b0e93162473 P 3a7f3c71c2e642f6b419e61ab2e00625 [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "3a7f3c71c2e642f6b419e61ab2e00625" member_type: VOTER last_known_addr { host: "127.9.78.65" port: 33261 } }
I20260812 06:19:33.066397 10137 raft_consensus.cc:385] T 3513f4a5c07c45fd87231b0e93162473 P 3a7f3c71c2e642f6b419e61ab2e00625 [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:19:33.066473 10137 raft_consensus.cc:740] T 3513f4a5c07c45fd87231b0e93162473 P 3a7f3c71c2e642f6b419e61ab2e00625 [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: 3a7f3c71c2e642f6b419e61ab2e00625, State: Initialized, Role: FOLLOWER
I20260812 06:19:33.066656 10137 consensus_queue.cc:260] T 3513f4a5c07c45fd87231b0e93162473 P 3a7f3c71c2e642f6b419e61ab2e00625 [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: "3a7f3c71c2e642f6b419e61ab2e00625" member_type: VOTER last_known_addr { host: "127.9.78.65" port: 33261 } }
I20260812 06:19:33.066763 10137 raft_consensus.cc:399] T 3513f4a5c07c45fd87231b0e93162473 P 3a7f3c71c2e642f6b419e61ab2e00625 [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:19:33.066815 10137 raft_consensus.cc:493] T 3513f4a5c07c45fd87231b0e93162473 P 3a7f3c71c2e642f6b419e61ab2e00625 [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:19:33.066874 10137 raft_consensus.cc:3060] T 3513f4a5c07c45fd87231b0e93162473 P 3a7f3c71c2e642f6b419e61ab2e00625 [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:19:33.067723 10137 raft_consensus.cc:515] T 3513f4a5c07c45fd87231b0e93162473 P 3a7f3c71c2e642f6b419e61ab2e00625 [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "3a7f3c71c2e642f6b419e61ab2e00625" member_type: VOTER last_known_addr { host: "127.9.78.65" port: 33261 } }
I20260812 06:19:33.067894 10137 leader_election.cc:304] T 3513f4a5c07c45fd87231b0e93162473 P 3a7f3c71c2e642f6b419e61ab2e00625 [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: 3a7f3c71c2e642f6b419e61ab2e00625; no voters: 
I20260812 06:19:33.068141 10137 leader_election.cc:290] T 3513f4a5c07c45fd87231b0e93162473 P 3a7f3c71c2e642f6b419e61ab2e00625 [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:19:33.068424 10144 raft_consensus.cc:2804] T 3513f4a5c07c45fd87231b0e93162473 P 3a7f3c71c2e642f6b419e61ab2e00625 [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:19:33.068543 10144 raft_consensus.cc:697] T 3513f4a5c07c45fd87231b0e93162473 P 3a7f3c71c2e642f6b419e61ab2e00625 [term 1 LEADER]: Becoming Leader. State: Replica: 3a7f3c71c2e642f6b419e61ab2e00625, State: Running, Role: LEADER
I20260812 06:19:33.068558 10137 ts_tablet_manager.cc:1434] T 3513f4a5c07c45fd87231b0e93162473 P 3a7f3c71c2e642f6b419e61ab2e00625: Time spent starting tablet: real 0.003s	user 0.000s	sys 0.003s
I20260812 06:19:33.068560 10120 heartbeater.cc:499] Master 127.9.78.126:33273 was elected leader, sending a full tablet report...
I20260812 06:19:33.068778 10144 consensus_queue.cc:237] T 3513f4a5c07c45fd87231b0e93162473 P 3a7f3c71c2e642f6b419e61ab2e00625 [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: "3a7f3c71c2e642f6b419e61ab2e00625" member_type: VOTER last_known_addr { host: "127.9.78.65" port: 33261 } }
I20260812 06:19:33.070308  9885 catalog_manager.cc:5719] T 3513f4a5c07c45fd87231b0e93162473 P 3a7f3c71c2e642f6b419e61ab2e00625 reported cstate change: term changed from 0 to 1, leader changed from <none> to 3a7f3c71c2e642f6b419e61ab2e00625 (127.9.78.65). New cstate: current_term: 1 leader_uuid: "3a7f3c71c2e642f6b419e61ab2e00625" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "3a7f3c71c2e642f6b419e61ab2e00625" member_type: VOTER last_known_addr { host: "127.9.78.65" port: 33261 } health_report { overall_health: HEALTHY } } }
I20260812 06:19:33.130075  9529 heavy-update-compaction-itest.cc:215] Time spent inserting: real 0.054s	user 0.019s	sys 0.004s
I20260812 06:19:33.283708 10121 maintenance_manager.cc:419] P 3a7f3c71c2e642f6b419e61ab2e00625: Scheduling FlushMRSOp(3513f4a5c07c45fd87231b0e93162473): perf score=19.054940
I20260812 06:19:33.447171 10016 maintenance_manager.cc:643] P 3a7f3c71c2e642f6b419e61ab2e00625: FlushMRSOp(3513f4a5c07c45fd87231b0e93162473) complete. Timing: real 0.163s	user 0.114s	sys 0.047s Metrics: {"bytes_written":12307490,"cfile_init":1,"delete_count":0,"dirs.queue_time_us":81,"dirs.run_cpu_time_us":173,"dirs.run_wall_time_us":736,"drs_written":1,"lbm_read_time_us":55,"lbm_reads_lt_1ms":4,"lbm_write_time_us":41395,"lbm_writes_lt_1ms":757,"peak_mem_usage":0,"reinsert_count":0,"rows_written":104,"spinlock_wait_cycles":896,"update_count":1500}
I20260812 06:19:33.447885 10121 maintenance_manager.cc:419] P 3a7f3c71c2e642f6b419e61ab2e00625: Scheduling LogGCOp(3513f4a5c07c45fd87231b0e93162473): free 20743880 bytes of WAL
I20260812 06:19:33.448120 10016 log_reader.cc:385] T 3513f4a5c07c45fd87231b0e93162473: removed 2 log segments from log reader
I20260812 06:19:33.448181 10016 log.cc:1079] T 3513f4a5c07c45fd87231b0e93162473 P 3a7f3c71c2e642f6b419e61ab2e00625: Deleting log segment in path: /tmp/dist-test-taskWwnqpJ/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515567133744-9529-0/minicluster-data/ts-0-root/wals/3513f4a5c07c45fd87231b0e93162473/wal-000000001 (ops 1-6)
I20260812 06:19:33.448243 10016 log.cc:1079] T 3513f4a5c07c45fd87231b0e93162473 P 3a7f3c71c2e642f6b419e61ab2e00625: Deleting log segment in path: /tmp/dist-test-taskWwnqpJ/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515567133744-9529-0/minicluster-data/ts-0-root/wals/3513f4a5c07c45fd87231b0e93162473/wal-000000002 (ops 7-11)
I20260812 06:19:33.452746 10016 maintenance_manager.cc:643] P 3a7f3c71c2e642f6b419e61ab2e00625: LogGCOp(3513f4a5c07c45fd87231b0e93162473) complete. Timing: real 0.005s	user 0.000s	sys 0.001s Metrics: {}
I20260812 06:19:33.453145 10121 maintenance_manager.cc:419] P 3a7f3c71c2e642f6b419e61ab2e00625: Scheduling FlushDeltaMemStoresOp(3513f4a5c07c45fd87231b0e93162473): perf score=2.188937
I20260812 06:19:33.467399 10016 maintenance_manager.cc:643] P 3a7f3c71c2e642f6b419e61ab2e00625: FlushDeltaMemStoresOp(3513f4a5c07c45fd87231b0e93162473) complete. Timing: real 0.014s	user 0.006s	sys 0.005s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5063,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:33.468075 10121 maintenance_manager.cc:419] P 3a7f3c71c2e642f6b419e61ab2e00625: Scheduling UndoDeltaBlockGCOp(3513f4a5c07c45fd87231b0e93162473): 16411394 bytes on disk
I20260812 06:19:33.468755 10016 maintenance_manager.cc:643] P 3a7f3c71c2e642f6b419e61ab2e00625: UndoDeltaBlockGCOp(3513f4a5c07c45fd87231b0e93162473) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":95,"lbm_reads_lt_1ms":4}
I20260812 06:19:33.469348 10121 maintenance_manager.cc:419] P 3a7f3c71c2e642f6b419e61ab2e00625: Scheduling MajorDeltaCompactionOp(3513f4a5c07c45fd87231b0e93162473): perf score=1.000000
I20260812 06:19:33.616930 10016 maintenance_manager.cc:643] P 3a7f3c71c2e642f6b419e61ab2e00625: MajorDeltaCompactionOp(3513f4a5c07c45fd87231b0e93162473) complete. Timing: real 0.147s	user 0.091s	sys 0.056s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672277,"cfile_init":7,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":567,"lbm_read_time_us":9949,"lbm_reads_lt_1ms":460,"lbm_write_time_us":25678,"lbm_writes_lt_1ms":443,"mutex_wait_us":23,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":10496,"thread_start_us":355,"threads_started":5,"update_count":2000}
I20260812 06:19:33.617579 10121 maintenance_manager.cc:419] P 3a7f3c71c2e642f6b419e61ab2e00625: Scheduling FlushDeltaMemStoresOp(3513f4a5c07c45fd87231b0e93162473): perf score=10.126437
I20260812 06:19:33.660265 10016 maintenance_manager.cc:643] P 3a7f3c71c2e642f6b419e61ab2e00625: FlushDeltaMemStoresOp(3513f4a5c07c45fd87231b0e93162473) complete. Timing: real 0.042s	user 0.017s	sys 0.022s Metrics: {"bytes_written":12307491,"delete_count":0,"lbm_write_time_us":13628,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:19:33.660936 10121 maintenance_manager.cc:419] P 3a7f3c71c2e642f6b419e61ab2e00625: Scheduling FlushDeltaMemStoresOp(3513f4a5c07c45fd87231b0e93162473): perf score=2.188937
I20260812 06:19:33.671672 10016 maintenance_manager.cc:643] P 3a7f3c71c2e642f6b419e61ab2e00625: FlushDeltaMemStoresOp(3513f4a5c07c45fd87231b0e93162473) complete. Timing: real 0.011s	user 0.005s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4240,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:33.672123 10121 maintenance_manager.cc:419] P 3a7f3c71c2e642f6b419e61ab2e00625: Scheduling MajorDeltaCompactionOp(3513f4a5c07c45fd87231b0e93162473): perf score=1.000000
I20260812 06:19:33.822624 10016 maintenance_manager.cc:643] P 3a7f3c71c2e642f6b419e61ab2e00625: MajorDeltaCompactionOp(3513f4a5c07c45fd87231b0e93162473) complete. Timing: real 0.150s	user 0.090s	sys 0.060s 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":211,"lbm_read_time_us":11436,"lbm_reads_lt_1ms":472,"lbm_write_time_us":22344,"lbm_writes_lt_1ms":443,"mutex_wait_us":21,"peak_mem_usage":50689328,"reinsert_count":0,"update_count":2000}
I20260812 06:19:33.823556 10121 maintenance_manager.cc:419] P 3a7f3c71c2e642f6b419e61ab2e00625: Scheduling FlushDeltaMemStoresOp(3513f4a5c07c45fd87231b0e93162473): perf score=10.126437
I20260812 06:19:33.862396 10016 maintenance_manager.cc:643] P 3a7f3c71c2e642f6b419e61ab2e00625: FlushDeltaMemStoresOp(3513f4a5c07c45fd87231b0e93162473) complete. Timing: real 0.038s	user 0.025s	sys 0.011s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":17762,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":302,"reinsert_count":0,"update_count":1500}
I20260812 06:19:33.862907 10121 maintenance_manager.cc:419] P 3a7f3c71c2e642f6b419e61ab2e00625: Scheduling FlushDeltaMemStoresOp(3513f4a5c07c45fd87231b0e93162473): perf score=2.188937
I20260812 06:19:33.883701 10016 maintenance_manager.cc:643] P 3a7f3c71c2e642f6b419e61ab2e00625: FlushDeltaMemStoresOp(3513f4a5c07c45fd87231b0e93162473) complete. Timing: real 0.021s	user 0.011s	sys 0.003s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6764,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:33.884248 10121 maintenance_manager.cc:419] P 3a7f3c71c2e642f6b419e61ab2e00625: Scheduling MajorDeltaCompactionOp(3513f4a5c07c45fd87231b0e93162473): perf score=1.000000
I20260812 06:19:34.011054 10016 maintenance_manager.cc:643] P 3a7f3c71c2e642f6b419e61ab2e00625: MajorDeltaCompactionOp(3513f4a5c07c45fd87231b0e93162473) complete. Timing: real 0.127s	user 0.110s	sys 0.017s 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":219,"lbm_read_time_us":9390,"lbm_reads_lt_1ms":464,"lbm_write_time_us":23273,"lbm_writes_lt_1ms":443,"mutex_wait_us":30,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":22784,"update_count":2000}
I20260812 06:19:34.011889 10121 maintenance_manager.cc:419] P 3a7f3c71c2e642f6b419e61ab2e00625: Scheduling FlushDeltaMemStoresOp(3513f4a5c07c45fd87231b0e93162473): perf score=10.126437
I20260812 06:19:34.056731 10016 maintenance_manager.cc:643] P 3a7f3c71c2e642f6b419e61ab2e00625: FlushDeltaMemStoresOp(3513f4a5c07c45fd87231b0e93162473) complete. Timing: real 0.045s	user 0.027s	sys 0.008s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":16378,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:19:34.057235 10121 maintenance_manager.cc:419] P 3a7f3c71c2e642f6b419e61ab2e00625: Scheduling FlushDeltaMemStoresOp(3513f4a5c07c45fd87231b0e93162473): perf score=2.188937
I20260812 06:19:34.068454 10016 maintenance_manager.cc:643] P 3a7f3c71c2e642f6b419e61ab2e00625: FlushDeltaMemStoresOp(3513f4a5c07c45fd87231b0e93162473) complete. Timing: real 0.011s	user 0.005s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4497,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:34.069072 10121 maintenance_manager.cc:419] P 3a7f3c71c2e642f6b419e61ab2e00625: Scheduling MajorDeltaCompactionOp(3513f4a5c07c45fd87231b0e93162473): perf score=1.000000
I20260812 06:19:34.195528 10016 maintenance_manager.cc:643] P 3a7f3c71c2e642f6b419e61ab2e00625: MajorDeltaCompactionOp(3513f4a5c07c45fd87231b0e93162473) complete. Timing: real 0.126s	user 0.098s	sys 0.028s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672277,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":659,"lbm_read_time_us":9834,"lbm_reads_lt_1ms":472,"lbm_write_time_us":22548,"lbm_writes_lt_1ms":443,"mutex_wait_us":345,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":4096,"update_count":2000}
I20260812 06:19:34.196097 10121 maintenance_manager.cc:419] P 3a7f3c71c2e642f6b419e61ab2e00625: Scheduling FlushDeltaMemStoresOp(3513f4a5c07c45fd87231b0e93162473): perf score=10.126437
I20260812 06:19:34.252731 10016 maintenance_manager.cc:643] P 3a7f3c71c2e642f6b419e61ab2e00625: FlushDeltaMemStoresOp(3513f4a5c07c45fd87231b0e93162473) complete. Timing: real 0.056s	user 0.033s	sys 0.023s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":18948,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":302,"reinsert_count":0,"update_count":1500}
I20260812 06:19:34.253588 10121 maintenance_manager.cc:419] P 3a7f3c71c2e642f6b419e61ab2e00625: Scheduling FlushDeltaMemStoresOp(3513f4a5c07c45fd87231b0e93162473): perf score=2.188937
I20260812 06:19:34.270459 10016 maintenance_manager.cc:643] P 3a7f3c71c2e642f6b419e61ab2e00625: FlushDeltaMemStoresOp(3513f4a5c07c45fd87231b0e93162473) complete. Timing: real 0.017s	user 0.007s	sys 0.008s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":6867,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:34.270905 10121 maintenance_manager.cc:419] P 3a7f3c71c2e642f6b419e61ab2e00625: Scheduling MajorDeltaCompactionOp(3513f4a5c07c45fd87231b0e93162473): perf score=1.000000
I20260812 06:19:34.437933 10016 maintenance_manager.cc:643] P 3a7f3c71c2e642f6b419e61ab2e00625: MajorDeltaCompactionOp(3513f4a5c07c45fd87231b0e93162473) complete. Timing: real 0.167s	user 0.094s	sys 0.072s 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":981,"lbm_read_time_us":12175,"lbm_reads_lt_1ms":472,"lbm_write_time_us":25889,"lbm_writes_lt_1ms":443,"mutex_wait_us":322,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":18432,"update_count":2000}
I20260812 06:19:34.438612 10121 maintenance_manager.cc:419] P 3a7f3c71c2e642f6b419e61ab2e00625: Scheduling FlushDeltaMemStoresOp(3513f4a5c07c45fd87231b0e93162473): perf score=10.126437
I20260812 06:19:34.482432 10016 maintenance_manager.cc:643] P 3a7f3c71c2e642f6b419e61ab2e00625: FlushDeltaMemStoresOp(3513f4a5c07c45fd87231b0e93162473) complete. Timing: real 0.044s	user 0.014s	sys 0.024s Metrics: {"bytes_written":12307493,"delete_count":0,"lbm_write_time_us":17678,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:19:34.482975 10121 maintenance_manager.cc:419] P 3a7f3c71c2e642f6b419e61ab2e00625: Scheduling MajorDeltaCompactionOp(3513f4a5c07c45fd87231b0e93162473): perf score=1.000000
I20260812 06:19:34.591252 10016 maintenance_manager.cc:643] P 3a7f3c71c2e642f6b419e61ab2e00625: MajorDeltaCompactionOp(3513f4a5c07c45fd87231b0e93162473) complete. Timing: real 0.108s	user 0.078s	sys 0.028s Metrics: {"cfile_cache_miss":331,"cfile_cache_miss_bytes":16569749,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":1,"delta_iterators_relevant":1,"dirs.queue_time_us":672,"lbm_read_time_us":6563,"lbm_reads_lt_1ms":363,"lbm_write_time_us":21378,"lbm_writes_lt_1ms":343,"mutex_wait_us":303,"peak_mem_usage":38262756,"reinsert_count":0,"spinlock_wait_cycles":3200,"update_count":1500}
I20260812 06:19:34.591989 10121 maintenance_manager.cc:419] P 3a7f3c71c2e642f6b419e61ab2e00625: Scheduling FlushDeltaMemStoresOp(3513f4a5c07c45fd87231b0e93162473): perf score=10.126437
I20260812 06:19:34.630642 10016 maintenance_manager.cc:643] P 3a7f3c71c2e642f6b419e61ab2e00625: FlushDeltaMemStoresOp(3513f4a5c07c45fd87231b0e93162473) complete. Timing: real 0.038s	user 0.019s	sys 0.015s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":15853,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:19:34.631152 10121 maintenance_manager.cc:419] P 3a7f3c71c2e642f6b419e61ab2e00625: Scheduling MajorDeltaCompactionOp(3513f4a5c07c45fd87231b0e93162473): perf score=1.000000
I20260812 06:19:34.749208 10016 maintenance_manager.cc:643] P 3a7f3c71c2e642f6b419e61ab2e00625: MajorDeltaCompactionOp(3513f4a5c07c45fd87231b0e93162473) complete. Timing: real 0.118s	user 0.086s	sys 0.032s Metrics: {"cfile_cache_miss":331,"cfile_cache_miss_bytes":16569746,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":1,"delta_iterators_relevant":1,"dirs.queue_time_us":248,"lbm_read_time_us":7638,"lbm_reads_lt_1ms":363,"lbm_write_time_us":23094,"lbm_writes_lt_1ms":343,"mutex_wait_us":80,"peak_mem_usage":38262756,"reinsert_count":0,"spinlock_wait_cycles":768,"update_count":1500}
I20260812 06:19:34.749951 10121 maintenance_manager.cc:419] P 3a7f3c71c2e642f6b419e61ab2e00625: Scheduling FlushDeltaMemStoresOp(3513f4a5c07c45fd87231b0e93162473): perf score=10.126437
I20260812 06:19:34.794667 10016 maintenance_manager.cc:643] P 3a7f3c71c2e642f6b419e61ab2e00625: FlushDeltaMemStoresOp(3513f4a5c07c45fd87231b0e93162473) complete. Timing: real 0.045s	user 0.013s	sys 0.021s Metrics: {"bytes_written":12307493,"delete_count":0,"lbm_write_time_us":15606,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:19:34.795222 10121 maintenance_manager.cc:419] P 3a7f3c71c2e642f6b419e61ab2e00625: Scheduling FlushDeltaMemStoresOp(3513f4a5c07c45fd87231b0e93162473): perf score=2.188937
I20260812 06:19:34.810967 10016 maintenance_manager.cc:643] P 3a7f3c71c2e642f6b419e61ab2e00625: FlushDeltaMemStoresOp(3513f4a5c07c45fd87231b0e93162473) complete. Timing: real 0.016s	user 0.010s	sys 0.004s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":6305,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:34.811599 10121 maintenance_manager.cc:419] P 3a7f3c71c2e642f6b419e61ab2e00625: Scheduling FlushMRSOp(3513f4a5c07c45fd87231b0e93162473): perf score=1.000000
I20260812 06:19:34.843241 10016 maintenance_manager.cc:643] P 3a7f3c71c2e642f6b419e61ab2e00625: FlushMRSOp(3513f4a5c07c45fd87231b0e93162473) complete. Timing: real 0.031s	user 0.030s	sys 0.000s Metrics: {"bytes_written":1234473,"cfile_init":1,"dirs.queue_time_us":79,"dirs.run_cpu_time_us":269,"dirs.run_wall_time_us":1620,"drs_written":1,"lbm_read_time_us":118,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1518,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":30}
I20260812 06:19:34.843986 10121 maintenance_manager.cc:419] P 3a7f3c71c2e642f6b419e61ab2e00625: Scheduling LogGCOp(3513f4a5c07c45fd87231b0e93162473): free 124257242 bytes of WAL
I20260812 06:19:34.844264 10016 log_reader.cc:385] T 3513f4a5c07c45fd87231b0e93162473: removed 12 log segments from log reader
I20260812 06:19:34.844332 10016 log.cc:1079] T 3513f4a5c07c45fd87231b0e93162473 P 3a7f3c71c2e642f6b419e61ab2e00625: Deleting log segment in path: /tmp/dist-test-taskWwnqpJ/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515567133744-9529-0/minicluster-data/ts-0-root/wals/3513f4a5c07c45fd87231b0e93162473/wal-000000003 (ops 12-16)
I20260812 06:19:34.844389 10016 log.cc:1079] T 3513f4a5c07c45fd87231b0e93162473 P 3a7f3c71c2e642f6b419e61ab2e00625: Deleting log segment in path: /tmp/dist-test-taskWwnqpJ/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515567133744-9529-0/minicluster-data/ts-0-root/wals/3513f4a5c07c45fd87231b0e93162473/wal-000000004 (ops 17-21)
I20260812 06:19:34.844450 10016 log.cc:1079] T 3513f4a5c07c45fd87231b0e93162473 P 3a7f3c71c2e642f6b419e61ab2e00625: Deleting log segment in path: /tmp/dist-test-taskWwnqpJ/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515567133744-9529-0/minicluster-data/ts-0-root/wals/3513f4a5c07c45fd87231b0e93162473/wal-000000005 (ops 22-26)
I20260812 06:19:34.844487 10016 log.cc:1079] T 3513f4a5c07c45fd87231b0e93162473 P 3a7f3c71c2e642f6b419e61ab2e00625: Deleting log segment in path: /tmp/dist-test-taskWwnqpJ/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515567133744-9529-0/minicluster-data/ts-0-root/wals/3513f4a5c07c45fd87231b0e93162473/wal-000000006 (ops 27-31)
I20260812 06:19:34.844566 10016 log.cc:1079] T 3513f4a5c07c45fd87231b0e93162473 P 3a7f3c71c2e642f6b419e61ab2e00625: Deleting log segment in path: /tmp/dist-test-taskWwnqpJ/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515567133744-9529-0/minicluster-data/ts-0-root/wals/3513f4a5c07c45fd87231b0e93162473/wal-000000007 (ops 32-36)
I20260812 06:19:34.844630 10016 log.cc:1079] T 3513f4a5c07c45fd87231b0e93162473 P 3a7f3c71c2e642f6b419e61ab2e00625: Deleting log segment in path: /tmp/dist-test-taskWwnqpJ/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515567133744-9529-0/minicluster-data/ts-0-root/wals/3513f4a5c07c45fd87231b0e93162473/wal-000000008 (ops 37-41)
I20260812 06:19:34.844676 10016 log.cc:1079] T 3513f4a5c07c45fd87231b0e93162473 P 3a7f3c71c2e642f6b419e61ab2e00625: Deleting log segment in path: /tmp/dist-test-taskWwnqpJ/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515567133744-9529-0/minicluster-data/ts-0-root/wals/3513f4a5c07c45fd87231b0e93162473/wal-000000009 (ops 42-46)
I20260812 06:19:34.844812 10016 log.cc:1079] T 3513f4a5c07c45fd87231b0e93162473 P 3a7f3c71c2e642f6b419e61ab2e00625: Deleting log segment in path: /tmp/dist-test-taskWwnqpJ/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515567133744-9529-0/minicluster-data/ts-0-root/wals/3513f4a5c07c45fd87231b0e93162473/wal-000000010 (ops 47-50)
I20260812 06:19:34.844868 10016 log.cc:1079] T 3513f4a5c07c45fd87231b0e93162473 P 3a7f3c71c2e642f6b419e61ab2e00625: Deleting log segment in path: /tmp/dist-test-taskWwnqpJ/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515567133744-9529-0/minicluster-data/ts-0-root/wals/3513f4a5c07c45fd87231b0e93162473/wal-000000011 (ops 51-55)
I20260812 06:19:34.844904 10016 log.cc:1079] T 3513f4a5c07c45fd87231b0e93162473 P 3a7f3c71c2e642f6b419e61ab2e00625: Deleting log segment in path: /tmp/dist-test-taskWwnqpJ/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515567133744-9529-0/minicluster-data/ts-0-root/wals/3513f4a5c07c45fd87231b0e93162473/wal-000000012 (ops 56-60)
I20260812 06:19:34.844949 10016 log.cc:1079] T 3513f4a5c07c45fd87231b0e93162473 P 3a7f3c71c2e642f6b419e61ab2e00625: Deleting log segment in path: /tmp/dist-test-taskWwnqpJ/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515567133744-9529-0/minicluster-data/ts-0-root/wals/3513f4a5c07c45fd87231b0e93162473/wal-000000013 (ops 61-65)
I20260812 06:19:34.844973 10016 log.cc:1079] T 3513f4a5c07c45fd87231b0e93162473 P 3a7f3c71c2e642f6b419e61ab2e00625: Deleting log segment in path: /tmp/dist-test-taskWwnqpJ/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515567133744-9529-0/minicluster-data/ts-0-root/wals/3513f4a5c07c45fd87231b0e93162473/wal-000000014 (ops 66-70)
I20260812 06:19:34.873201 10016 maintenance_manager.cc:643] P 3a7f3c71c2e642f6b419e61ab2e00625: LogGCOp(3513f4a5c07c45fd87231b0e93162473) complete. Timing: real 0.029s	user 0.000s	sys 0.028s Metrics: {}
I20260812 06:19:34.873708 10121 maintenance_manager.cc:419] P 3a7f3c71c2e642f6b419e61ab2e00625: Scheduling UndoDeltaBlockGCOp(3513f4a5c07c45fd87231b0e93162473): 472 bytes on disk
I20260812 06:19:34.874274 10016 maintenance_manager.cc:643] P 3a7f3c71c2e642f6b419e61ab2e00625: UndoDeltaBlockGCOp(3513f4a5c07c45fd87231b0e93162473) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":98,"lbm_reads_lt_1ms":4}
I20260812 06:19:34.874909 10121 maintenance_manager.cc:419] P 3a7f3c71c2e642f6b419e61ab2e00625: Scheduling FlushDeltaMemStoresOp(3513f4a5c07c45fd87231b0e93162473): perf score=2.188937
I20260812 06:19:34.901561 10016 maintenance_manager.cc:643] P 3a7f3c71c2e642f6b419e61ab2e00625: FlushDeltaMemStoresOp(3513f4a5c07c45fd87231b0e93162473) complete. Timing: real 0.026s	user 0.010s	sys 0.009s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":7176,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:34.902282 10121 maintenance_manager.cc:419] P 3a7f3c71c2e642f6b419e61ab2e00625: Scheduling FlushDeltaMemStoresOp(3513f4a5c07c45fd87231b0e93162473): perf score=2.188937
I20260812 06:19:34.916038 10016 maintenance_manager.cc:643] P 3a7f3c71c2e642f6b419e61ab2e00625: FlushDeltaMemStoresOp(3513f4a5c07c45fd87231b0e93162473) complete. Timing: real 0.014s	user 0.012s	sys 0.000s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":5453,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:34.916499 10121 maintenance_manager.cc:419] P 3a7f3c71c2e642f6b419e61ab2e00625: Scheduling MajorDeltaCompactionOp(3513f4a5c07c45fd87231b0e93162473): perf score=1.000000
I20260812 06:19:35.124468 10016 maintenance_manager.cc:643] P 3a7f3c71c2e642f6b419e61ab2e00625: MajorDeltaCompactionOp(3513f4a5c07c45fd87231b0e93162473) complete. Timing: real 0.208s	user 0.116s	sys 0.092s Metrics: {"cfile_cache_miss":634,"cfile_cache_miss_bytes":28877340,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":170,"lbm_read_time_us":17665,"lbm_reads_lt_1ms":674,"lbm_write_time_us":32190,"lbm_writes_lt_1ms":643,"mutex_wait_us":21,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":30208,"thread_start_us":106,"threads_started":1,"update_count":3000}
I20260812 06:19:35.125216 10121 maintenance_manager.cc:419] P 3a7f3c71c2e642f6b419e61ab2e00625: Scheduling FlushDeltaMemStoresOp(3513f4a5c07c45fd87231b0e93162473): perf score=14.095187
I20260812 06:19:35.197329 10016 maintenance_manager.cc:643] P 3a7f3c71c2e642f6b419e61ab2e00625: FlushDeltaMemStoresOp(3513f4a5c07c45fd87231b0e93162473) complete. Timing: real 0.072s	user 0.037s	sys 0.031s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":25496,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:35.197929 10121 maintenance_manager.cc:419] P 3a7f3c71c2e642f6b419e61ab2e00625: Scheduling FlushDeltaMemStoresOp(3513f4a5c07c45fd87231b0e93162473): perf score=2.188937
I20260812 06:19:35.209802 10016 maintenance_manager.cc:643] P 3a7f3c71c2e642f6b419e61ab2e00625: FlushDeltaMemStoresOp(3513f4a5c07c45fd87231b0e93162473) complete. Timing: real 0.012s	user 0.006s	sys 0.005s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4634,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:35.210301 10121 maintenance_manager.cc:419] P 3a7f3c71c2e642f6b419e61ab2e00625: Scheduling MajorDeltaCompactionOp(3513f4a5c07c45fd87231b0e93162473): perf score=1.000000
I20260812 06:19:35.401360 10016 maintenance_manager.cc:643] P 3a7f3c71c2e642f6b419e61ab2e00625: MajorDeltaCompactionOp(3513f4a5c07c45fd87231b0e93162473) complete. Timing: real 0.191s	user 0.112s	sys 0.072s 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":1013,"lbm_read_time_us":14488,"lbm_reads_lt_1ms":572,"lbm_write_time_us":29108,"lbm_writes_lt_1ms":543,"mutex_wait_us":285,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":11776,"update_count":2500}
I20260812 06:19:35.401924 10121 maintenance_manager.cc:419] P 3a7f3c71c2e642f6b419e61ab2e00625: Scheduling FlushDeltaMemStoresOp(3513f4a5c07c45fd87231b0e93162473): perf score=14.095187
I20260812 06:19:35.469668 10016 maintenance_manager.cc:643] P 3a7f3c71c2e642f6b419e61ab2e00625: FlushDeltaMemStoresOp(3513f4a5c07c45fd87231b0e93162473) complete. Timing: real 0.068s	user 0.024s	sys 0.035s Metrics: {"bytes_written":16409904,"delete_count":0,"lbm_write_time_us":22107,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:35.470238 10121 maintenance_manager.cc:419] P 3a7f3c71c2e642f6b419e61ab2e00625: Scheduling FlushDeltaMemStoresOp(3513f4a5c07c45fd87231b0e93162473): perf score=2.188937
I20260812 06:19:35.481756 10016 maintenance_manager.cc:643] P 3a7f3c71c2e642f6b419e61ab2e00625: FlushDeltaMemStoresOp(3513f4a5c07c45fd87231b0e93162473) complete. Timing: real 0.011s	user 0.010s	sys 0.001s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4391,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:35.482316 10121 maintenance_manager.cc:419] P 3a7f3c71c2e642f6b419e61ab2e00625: Scheduling MajorDeltaCompactionOp(3513f4a5c07c45fd87231b0e93162473): perf score=1.000000
I20260812 06:19:35.691365 10016 maintenance_manager.cc:643] P 3a7f3c71c2e642f6b419e61ab2e00625: MajorDeltaCompactionOp(3513f4a5c07c45fd87231b0e93162473) complete. Timing: real 0.209s	user 0.145s	sys 0.064s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774691,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":439,"lbm_read_time_us":17793,"lbm_reads_lt_1ms":572,"lbm_write_time_us":30932,"lbm_writes_lt_1ms":543,"mutex_wait_us":32,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":2816,"update_count":2500}
I20260812 06:19:35.692075 10121 maintenance_manager.cc:419] P 3a7f3c71c2e642f6b419e61ab2e00625: Scheduling FlushDeltaMemStoresOp(3513f4a5c07c45fd87231b0e93162473): perf score=10.126437
I20260812 06:19:35.757472 10016 maintenance_manager.cc:643] P 3a7f3c71c2e642f6b419e61ab2e00625: FlushDeltaMemStoresOp(3513f4a5c07c45fd87231b0e93162473) complete. Timing: real 0.065s	user 0.037s	sys 0.003s Metrics: {"bytes_written":12307491,"delete_count":0,"lbm_write_time_us":17563,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:19:35.758023 10121 maintenance_manager.cc:419] P 3a7f3c71c2e642f6b419e61ab2e00625: Scheduling FlushDeltaMemStoresOp(3513f4a5c07c45fd87231b0e93162473): perf score=2.188937
I20260812 06:19:35.773124 10016 maintenance_manager.cc:643] P 3a7f3c71c2e642f6b419e61ab2e00625: FlushDeltaMemStoresOp(3513f4a5c07c45fd87231b0e93162473) complete. Timing: real 0.015s	user 0.010s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5774,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:35.773732 10121 maintenance_manager.cc:419] P 3a7f3c71c2e642f6b419e61ab2e00625: Scheduling MajorDeltaCompactionOp(3513f4a5c07c45fd87231b0e93162473): perf score=1.000000
I20260812 06:19:35.906199 10016 maintenance_manager.cc:643] P 3a7f3c71c2e642f6b419e61ab2e00625: MajorDeltaCompactionOp(3513f4a5c07c45fd87231b0e93162473) complete. Timing: real 0.132s	user 0.095s	sys 0.036s 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":789,"lbm_read_time_us":8930,"lbm_reads_lt_1ms":472,"lbm_write_time_us":25952,"lbm_writes_lt_1ms":443,"mutex_wait_us":344,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":2304,"update_count":2000}
I20260812 06:19:35.906895 10121 maintenance_manager.cc:419] P 3a7f3c71c2e642f6b419e61ab2e00625: Scheduling FlushDeltaMemStoresOp(3513f4a5c07c45fd87231b0e93162473): perf score=7.149875
I20260812 06:19:35.932220 10016 maintenance_manager.cc:643] P 3a7f3c71c2e642f6b419e61ab2e00625: FlushDeltaMemStoresOp(3513f4a5c07c45fd87231b0e93162473) complete. Timing: real 0.025s	user 0.007s	sys 0.015s Metrics: {"bytes_written":8615323,"delete_count":0,"lbm_write_time_us":10710,"lbm_writes_lt_1ms":213,"reinsert_count":0,"update_count":1050}
I20260812 06:19:35.932948 10121 maintenance_manager.cc:419] P 3a7f3c71c2e642f6b419e61ab2e00625: Scheduling FlushDeltaMemStoresOp(3513f4a5c07c45fd87231b0e93162473): perf score=2.188937
I20260812 06:19:35.949115 10016 maintenance_manager.cc:643] P 3a7f3c71c2e642f6b419e61ab2e00625: FlushDeltaMemStoresOp(3513f4a5c07c45fd87231b0e93162473) complete. Timing: real 0.016s	user 0.011s	sys 0.005s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":5680,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:19:35.949716 10121 maintenance_manager.cc:419] P 3a7f3c71c2e642f6b419e61ab2e00625: Scheduling MajorDeltaCompactionOp(3513f4a5c07c45fd87231b0e93162473): perf score=1.000000
I20260812 06:19:36.077520 10016 maintenance_manager.cc:643] P 3a7f3c71c2e642f6b419e61ab2e00625: MajorDeltaCompactionOp(3513f4a5c07c45fd87231b0e93162473) complete. Timing: real 0.128s	user 0.105s	sys 0.020s Metrics: {"cfile_cache_miss":332,"cfile_cache_miss_bytes":16569856,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":272,"lbm_read_time_us":9973,"lbm_reads_lt_1ms":372,"lbm_write_time_us":22086,"lbm_writes_lt_1ms":343,"mutex_wait_us":42,"peak_mem_usage":38262756,"reinsert_count":0,"spinlock_wait_cycles":10496,"update_count":1500}
I20260812 06:19:36.078312 10121 maintenance_manager.cc:419] P 3a7f3c71c2e642f6b419e61ab2e00625: Scheduling FlushDeltaMemStoresOp(3513f4a5c07c45fd87231b0e93162473): perf score=10.126437
I20260812 06:19:36.121040 10016 maintenance_manager.cc:643] P 3a7f3c71c2e642f6b419e61ab2e00625: FlushDeltaMemStoresOp(3513f4a5c07c45fd87231b0e93162473) complete. Timing: real 0.043s	user 0.027s	sys 0.016s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":18102,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":302,"reinsert_count":0,"update_count":1500}
I20260812 06:19:36.121574 10121 maintenance_manager.cc:419] P 3a7f3c71c2e642f6b419e61ab2e00625: Scheduling MajorDeltaCompactionOp(3513f4a5c07c45fd87231b0e93162473): perf score=1.000000
I20260812 06:19:36.249531 10016 maintenance_manager.cc:643] P 3a7f3c71c2e642f6b419e61ab2e00625: MajorDeltaCompactionOp(3513f4a5c07c45fd87231b0e93162473) complete. Timing: real 0.128s	user 0.099s	sys 0.028s Metrics: {"cfile_cache_miss":331,"cfile_cache_miss_bytes":16569746,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":1,"delta_iterators_relevant":1,"lbm_read_time_us":7140,"lbm_reads_lt_1ms":367,"lbm_write_time_us":22071,"lbm_writes_lt_1ms":343,"mutex_wait_us":21,"peak_mem_usage":38262756,"reinsert_count":0,"update_count":1500}
I20260812 06:19:36.250223 10121 maintenance_manager.cc:419] P 3a7f3c71c2e642f6b419e61ab2e00625: Scheduling FlushDeltaMemStoresOp(3513f4a5c07c45fd87231b0e93162473): perf score=10.126437
I20260812 06:19:36.297971 10016 maintenance_manager.cc:643] P 3a7f3c71c2e642f6b419e61ab2e00625: FlushDeltaMemStoresOp(3513f4a5c07c45fd87231b0e93162473) complete. Timing: real 0.048s	user 0.034s	sys 0.012s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":21506,"lbm_writes_lt_1ms":303,"reinsert_count":0,"spinlock_wait_cycles":3456,"update_count":1500}
I20260812 06:19:36.298537 10121 maintenance_manager.cc:419] P 3a7f3c71c2e642f6b419e61ab2e00625: Scheduling FlushDeltaMemStoresOp(3513f4a5c07c45fd87231b0e93162473): perf score=2.188937
I20260812 06:19:36.310925 10016 maintenance_manager.cc:643] P 3a7f3c71c2e642f6b419e61ab2e00625: FlushDeltaMemStoresOp(3513f4a5c07c45fd87231b0e93162473) complete. Timing: real 0.012s	user 0.007s	sys 0.003s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4877,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:36.311398 10121 maintenance_manager.cc:419] P 3a7f3c71c2e642f6b419e61ab2e00625: Scheduling MajorDeltaCompactionOp(3513f4a5c07c45fd87231b0e93162473): perf score=1.000000
I20260812 06:19:36.441404 10016 maintenance_manager.cc:643] P 3a7f3c71c2e642f6b419e61ab2e00625: MajorDeltaCompactionOp(3513f4a5c07c45fd87231b0e93162473) complete. Timing: real 0.130s	user 0.098s	sys 0.032s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672277,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":184,"lbm_read_time_us":8608,"lbm_reads_lt_1ms":472,"lbm_write_time_us":24681,"lbm_writes_lt_1ms":443,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":3968,"update_count":2000}
I20260812 06:19:36.442315 10121 maintenance_manager.cc:419] P 3a7f3c71c2e642f6b419e61ab2e00625: Scheduling FlushDeltaMemStoresOp(3513f4a5c07c45fd87231b0e93162473): perf score=10.126437
I20260812 06:19:36.487532 10016 maintenance_manager.cc:643] P 3a7f3c71c2e642f6b419e61ab2e00625: FlushDeltaMemStoresOp(3513f4a5c07c45fd87231b0e93162473) complete. Timing: real 0.045s	user 0.033s	sys 0.004s Metrics: {"bytes_written":12307492,"delete_count":0,"lbm_write_time_us":17680,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:19:36.488051 10121 maintenance_manager.cc:419] P 3a7f3c71c2e642f6b419e61ab2e00625: Scheduling FlushDeltaMemStoresOp(3513f4a5c07c45fd87231b0e93162473): perf score=2.188937
I20260812 06:19:36.498785 10016 maintenance_manager.cc:643] P 3a7f3c71c2e642f6b419e61ab2e00625: FlushDeltaMemStoresOp(3513f4a5c07c45fd87231b0e93162473) complete. Timing: real 0.011s	user 0.002s	sys 0.007s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4298,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:36.499248 10121 maintenance_manager.cc:419] P 3a7f3c71c2e642f6b419e61ab2e00625: Scheduling FlushMRSOp(3513f4a5c07c45fd87231b0e93162473): perf score=1.000000
I20260812 06:19:36.532550 10016 maintenance_manager.cc:643] P 3a7f3c71c2e642f6b419e61ab2e00625: FlushMRSOp(3513f4a5c07c45fd87231b0e93162473) complete. Timing: real 0.033s	user 0.032s	sys 0.000s Metrics: {"bytes_written":1234479,"cfile_init":1,"dirs.queue_time_us":68,"dirs.run_cpu_time_us":201,"dirs.run_wall_time_us":1258,"drs_written":1,"lbm_read_time_us":37,"lbm_reads_lt_1ms":4,"lbm_write_time_us":2173,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":30}
I20260812 06:19:36.533420 10121 maintenance_manager.cc:419] P 3a7f3c71c2e642f6b419e61ab2e00625: Scheduling LogGCOp(3513f4a5c07c45fd87231b0e93162473): free 124710306 bytes of WAL
I20260812 06:19:36.533627 10016 log_reader.cc:385] T 3513f4a5c07c45fd87231b0e93162473: removed 12 log segments from log reader
I20260812 06:19:36.533684 10016 log.cc:1079] T 3513f4a5c07c45fd87231b0e93162473 P 3a7f3c71c2e642f6b419e61ab2e00625: Deleting log segment in path: /tmp/dist-test-taskWwnqpJ/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515567133744-9529-0/minicluster-data/ts-0-root/wals/3513f4a5c07c45fd87231b0e93162473/wal-000000015 (ops 71-75)
I20260812 06:19:36.533733 10016 log.cc:1079] T 3513f4a5c07c45fd87231b0e93162473 P 3a7f3c71c2e642f6b419e61ab2e00625: Deleting log segment in path: /tmp/dist-test-taskWwnqpJ/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515567133744-9529-0/minicluster-data/ts-0-root/wals/3513f4a5c07c45fd87231b0e93162473/wal-000000016 (ops 76-80)
I20260812 06:19:36.533771 10016 log.cc:1079] T 3513f4a5c07c45fd87231b0e93162473 P 3a7f3c71c2e642f6b419e61ab2e00625: Deleting log segment in path: /tmp/dist-test-taskWwnqpJ/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515567133744-9529-0/minicluster-data/ts-0-root/wals/3513f4a5c07c45fd87231b0e93162473/wal-000000017 (ops 81-85)
I20260812 06:19:36.533818 10016 log.cc:1079] T 3513f4a5c07c45fd87231b0e93162473 P 3a7f3c71c2e642f6b419e61ab2e00625: Deleting log segment in path: /tmp/dist-test-taskWwnqpJ/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515567133744-9529-0/minicluster-data/ts-0-root/wals/3513f4a5c07c45fd87231b0e93162473/wal-000000018 (ops 86-90)
I20260812 06:19:36.533856 10016 log.cc:1079] T 3513f4a5c07c45fd87231b0e93162473 P 3a7f3c71c2e642f6b419e61ab2e00625: Deleting log segment in path: /tmp/dist-test-taskWwnqpJ/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515567133744-9529-0/minicluster-data/ts-0-root/wals/3513f4a5c07c45fd87231b0e93162473/wal-000000019 (ops 91-95)
I20260812 06:19:36.533895 10016 log.cc:1079] T 3513f4a5c07c45fd87231b0e93162473 P 3a7f3c71c2e642f6b419e61ab2e00625: Deleting log segment in path: /tmp/dist-test-taskWwnqpJ/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515567133744-9529-0/minicluster-data/ts-0-root/wals/3513f4a5c07c45fd87231b0e93162473/wal-000000020 (ops 96-100)
I20260812 06:19:36.533936 10016 log.cc:1079] T 3513f4a5c07c45fd87231b0e93162473 P 3a7f3c71c2e642f6b419e61ab2e00625: Deleting log segment in path: /tmp/dist-test-taskWwnqpJ/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515567133744-9529-0/minicluster-data/ts-0-root/wals/3513f4a5c07c45fd87231b0e93162473/wal-000000021 (ops 101-105)
I20260812 06:19:36.533975 10016 log.cc:1079] T 3513f4a5c07c45fd87231b0e93162473 P 3a7f3c71c2e642f6b419e61ab2e00625: Deleting log segment in path: /tmp/dist-test-taskWwnqpJ/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515567133744-9529-0/minicluster-data/ts-0-root/wals/3513f4a5c07c45fd87231b0e93162473/wal-000000022 (ops 106-110)
I20260812 06:19:36.534013 10016 log.cc:1079] T 3513f4a5c07c45fd87231b0e93162473 P 3a7f3c71c2e642f6b419e61ab2e00625: Deleting log segment in path: /tmp/dist-test-taskWwnqpJ/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515567133744-9529-0/minicluster-data/ts-0-root/wals/3513f4a5c07c45fd87231b0e93162473/wal-000000023 (ops 111-115)
I20260812 06:19:36.534053 10016 log.cc:1079] T 3513f4a5c07c45fd87231b0e93162473 P 3a7f3c71c2e642f6b419e61ab2e00625: Deleting log segment in path: /tmp/dist-test-taskWwnqpJ/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515567133744-9529-0/minicluster-data/ts-0-root/wals/3513f4a5c07c45fd87231b0e93162473/wal-000000024 (ops 116-120)
I20260812 06:19:36.534092 10016 log.cc:1079] T 3513f4a5c07c45fd87231b0e93162473 P 3a7f3c71c2e642f6b419e61ab2e00625: Deleting log segment in path: /tmp/dist-test-taskWwnqpJ/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515567133744-9529-0/minicluster-data/ts-0-root/wals/3513f4a5c07c45fd87231b0e93162473/wal-000000025 (ops 121-125)
I20260812 06:19:36.534132 10016 log.cc:1079] T 3513f4a5c07c45fd87231b0e93162473 P 3a7f3c71c2e642f6b419e61ab2e00625: Deleting log segment in path: /tmp/dist-test-taskWwnqpJ/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515567133744-9529-0/minicluster-data/ts-0-root/wals/3513f4a5c07c45fd87231b0e93162473/wal-000000026 (ops 126-130)
I20260812 06:19:36.563088 10016 maintenance_manager.cc:643] P 3a7f3c71c2e642f6b419e61ab2e00625: LogGCOp(3513f4a5c07c45fd87231b0e93162473) complete. Timing: real 0.030s	user 0.000s	sys 0.027s Metrics: {}
I20260812 06:19:36.563539 10121 maintenance_manager.cc:419] P 3a7f3c71c2e642f6b419e61ab2e00625: Scheduling FlushDeltaMemStoresOp(3513f4a5c07c45fd87231b0e93162473): perf score=3.181125
I20260812 06:19:36.576370 10016 maintenance_manager.cc:643] P 3a7f3c71c2e642f6b419e61ab2e00625: FlushDeltaMemStoresOp(3513f4a5c07c45fd87231b0e93162473) complete. Timing: real 0.013s	user 0.003s	sys 0.007s Metrics: {"bytes_written":4512900,"delete_count":0,"lbm_write_time_us":4643,"lbm_writes_lt_1ms":113,"reinsert_count":0,"update_count":550}
I20260812 06:19:36.576930 10121 maintenance_manager.cc:419] P 3a7f3c71c2e642f6b419e61ab2e00625: Scheduling UndoDeltaBlockGCOp(3513f4a5c07c45fd87231b0e93162473): 473 bytes on disk
I20260812 06:19:36.577420 10016 maintenance_manager.cc:643] P 3a7f3c71c2e642f6b419e61ab2e00625: UndoDeltaBlockGCOp(3513f4a5c07c45fd87231b0e93162473) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":71,"lbm_reads_lt_1ms":4}
I20260812 06:19:36.577929 10121 maintenance_manager.cc:419] P 3a7f3c71c2e642f6b419e61ab2e00625: Scheduling FlushDeltaMemStoresOp(3513f4a5c07c45fd87231b0e93162473): perf score=2.188937
I20260812 06:19:36.591343 10016 maintenance_manager.cc:643] P 3a7f3c71c2e642f6b419e61ab2e00625: FlushDeltaMemStoresOp(3513f4a5c07c45fd87231b0e93162473) complete. Timing: real 0.013s	user 0.003s	sys 0.008s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":5046,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:19:36.591948 10121 maintenance_manager.cc:419] P 3a7f3c71c2e642f6b419e61ab2e00625: Scheduling MajorDeltaCompactionOp(3513f4a5c07c45fd87231b0e93162473): perf score=1.000000
I20260812 06:19:36.764402 10016 maintenance_manager.cc:643] P 3a7f3c71c2e642f6b419e61ab2e00625: MajorDeltaCompactionOp(3513f4a5c07c45fd87231b0e93162473) complete. Timing: real 0.172s	user 0.136s	sys 0.032s Metrics: {"cfile_cache_miss":634,"cfile_cache_miss_bytes":28877328,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":568,"lbm_read_time_us":12684,"lbm_reads_lt_1ms":674,"lbm_write_time_us":33633,"lbm_writes_lt_1ms":643,"mutex_wait_us":46,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":17792,"thread_start_us":82,"threads_started":1,"update_count":3000}
I20260812 06:19:36.765197 10121 maintenance_manager.cc:419] P 3a7f3c71c2e642f6b419e61ab2e00625: Scheduling FlushDeltaMemStoresOp(3513f4a5c07c45fd87231b0e93162473): perf score=14.095187
I20260812 06:19:36.819581 10016 maintenance_manager.cc:643] P 3a7f3c71c2e642f6b419e61ab2e00625: FlushDeltaMemStoresOp(3513f4a5c07c45fd87231b0e93162473) complete. Timing: real 0.054s	user 0.026s	sys 0.015s Metrics: {"bytes_written":16409900,"delete_count":0,"lbm_write_time_us":19420,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:36.820084 10121 maintenance_manager.cc:419] P 3a7f3c71c2e642f6b419e61ab2e00625: Scheduling FlushDeltaMemStoresOp(3513f4a5c07c45fd87231b0e93162473): perf score=2.188937
I20260812 06:19:36.831509 10016 maintenance_manager.cc:643] P 3a7f3c71c2e642f6b419e61ab2e00625: FlushDeltaMemStoresOp(3513f4a5c07c45fd87231b0e93162473) complete. Timing: real 0.011s	user 0.009s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4171,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:36.831996 10121 maintenance_manager.cc:419] P 3a7f3c71c2e642f6b419e61ab2e00625: Scheduling MajorDeltaCompactionOp(3513f4a5c07c45fd87231b0e93162473): perf score=1.000000
I20260812 06:19:37.002079 10016 maintenance_manager.cc:643] P 3a7f3c71c2e642f6b419e61ab2e00625: MajorDeltaCompactionOp(3513f4a5c07c45fd87231b0e93162473) complete. Timing: real 0.170s	user 0.124s	sys 0.024s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774687,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":636,"lbm_read_time_us":10768,"lbm_reads_lt_1ms":572,"lbm_write_time_us":30120,"lbm_writes_lt_1ms":543,"mutex_wait_us":27,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":4992,"update_count":2500}
I20260812 06:19:37.002929 10121 maintenance_manager.cc:419] P 3a7f3c71c2e642f6b419e61ab2e00625: Scheduling FlushDeltaMemStoresOp(3513f4a5c07c45fd87231b0e93162473): perf score=14.095187
I20260812 06:19:37.069025 10016 maintenance_manager.cc:643] P 3a7f3c71c2e642f6b419e61ab2e00625: FlushDeltaMemStoresOp(3513f4a5c07c45fd87231b0e93162473) complete. Timing: real 0.066s	user 0.024s	sys 0.032s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":25122,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:37.069541 10121 maintenance_manager.cc:419] P 3a7f3c71c2e642f6b419e61ab2e00625: Scheduling FlushDeltaMemStoresOp(3513f4a5c07c45fd87231b0e93162473): perf score=2.188937
I20260812 06:19:37.081568 10016 maintenance_manager.cc:643] P 3a7f3c71c2e642f6b419e61ab2e00625: FlushDeltaMemStoresOp(3513f4a5c07c45fd87231b0e93162473) complete. Timing: real 0.012s	user 0.011s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4009,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:37.082119 10121 maintenance_manager.cc:419] P 3a7f3c71c2e642f6b419e61ab2e00625: Scheduling MajorDeltaCompactionOp(3513f4a5c07c45fd87231b0e93162473): perf score=1.000000
I20260812 06:19:37.281883 10016 maintenance_manager.cc:643] P 3a7f3c71c2e642f6b419e61ab2e00625: MajorDeltaCompactionOp(3513f4a5c07c45fd87231b0e93162473) complete. Timing: real 0.200s	user 0.132s	sys 0.059s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774688,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":584,"lbm_read_time_us":13484,"lbm_reads_lt_1ms":572,"lbm_write_time_us":30026,"lbm_writes_lt_1ms":543,"mutex_wait_us":60,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":16256,"update_count":2500}
I20260812 06:19:37.282580 10121 maintenance_manager.cc:419] P 3a7f3c71c2e642f6b419e61ab2e00625: Scheduling FlushDeltaMemStoresOp(3513f4a5c07c45fd87231b0e93162473): perf score=14.095187
I20260812 06:19:37.335933 10016 maintenance_manager.cc:643] P 3a7f3c71c2e642f6b419e61ab2e00625: FlushDeltaMemStoresOp(3513f4a5c07c45fd87231b0e93162473) complete. Timing: real 0.053s	user 0.028s	sys 0.019s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":22902,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:37.336561 10121 maintenance_manager.cc:419] P 3a7f3c71c2e642f6b419e61ab2e00625: Scheduling MajorDeltaCompactionOp(3513f4a5c07c45fd87231b0e93162473): perf score=1.000000
I20260812 06:19:37.493537 10016 maintenance_manager.cc:643] P 3a7f3c71c2e642f6b419e61ab2e00625: MajorDeltaCompactionOp(3513f4a5c07c45fd87231b0e93162473) complete. Timing: real 0.157s	user 0.103s	sys 0.053s Metrics: {"cfile_cache_miss":431,"cfile_cache_miss_bytes":20672157,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":1,"delta_iterators_relevant":1,"dirs.queue_time_us":866,"lbm_read_time_us":10954,"lbm_reads_lt_1ms":463,"lbm_write_time_us":25971,"lbm_writes_lt_1ms":443,"mutex_wait_us":298,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":4736,"update_count":2000}
I20260812 06:19:37.494069 10121 maintenance_manager.cc:419] P 3a7f3c71c2e642f6b419e61ab2e00625: Scheduling FlushDeltaMemStoresOp(3513f4a5c07c45fd87231b0e93162473): perf score=14.095187
I20260812 06:19:37.542861 10016 maintenance_manager.cc:643] P 3a7f3c71c2e642f6b419e61ab2e00625: FlushDeltaMemStoresOp(3513f4a5c07c45fd87231b0e93162473) complete. Timing: real 0.049s	user 0.028s	sys 0.016s Metrics: {"bytes_written":16409903,"delete_count":0,"lbm_write_time_us":20863,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:37.543408 10121 maintenance_manager.cc:419] P 3a7f3c71c2e642f6b419e61ab2e00625: Scheduling FlushDeltaMemStoresOp(3513f4a5c07c45fd87231b0e93162473): perf score=2.188937
I20260812 06:19:37.557422 10016 maintenance_manager.cc:643] P 3a7f3c71c2e642f6b419e61ab2e00625: FlushDeltaMemStoresOp(3513f4a5c07c45fd87231b0e93162473) complete. Timing: real 0.014s	user 0.002s	sys 0.011s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":5120,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:37.557883 10121 maintenance_manager.cc:419] P 3a7f3c71c2e642f6b419e61ab2e00625: Scheduling MajorDeltaCompactionOp(3513f4a5c07c45fd87231b0e93162473): perf score=1.000000
I20260812 06:19:37.737144 10016 maintenance_manager.cc:643] P 3a7f3c71c2e642f6b419e61ab2e00625: MajorDeltaCompactionOp(3513f4a5c07c45fd87231b0e93162473) complete. Timing: real 0.179s	user 0.100s	sys 0.075s 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":326,"lbm_read_time_us":12067,"lbm_reads_lt_1ms":564,"lbm_write_time_us":27643,"lbm_writes_lt_1ms":543,"mutex_wait_us":27,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":20352,"update_count":2500}
I20260812 06:19:37.737898 10121 maintenance_manager.cc:419] P 3a7f3c71c2e642f6b419e61ab2e00625: Scheduling FlushDeltaMemStoresOp(3513f4a5c07c45fd87231b0e93162473): perf score=14.095187
I20260812 06:19:37.789659 10016 maintenance_manager.cc:643] P 3a7f3c71c2e642f6b419e61ab2e00625: FlushDeltaMemStoresOp(3513f4a5c07c45fd87231b0e93162473) complete. Timing: real 0.052s	user 0.035s	sys 0.015s Metrics: {"bytes_written":16409903,"delete_count":0,"lbm_write_time_us":22899,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:37.790273 10121 maintenance_manager.cc:419] P 3a7f3c71c2e642f6b419e61ab2e00625: Scheduling FlushDeltaMemStoresOp(3513f4a5c07c45fd87231b0e93162473): perf score=2.188937
I20260812 06:19:37.808987 10016 maintenance_manager.cc:643] P 3a7f3c71c2e642f6b419e61ab2e00625: FlushDeltaMemStoresOp(3513f4a5c07c45fd87231b0e93162473) complete. Timing: real 0.019s	user 0.011s	sys 0.005s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":6264,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:37.809562 10121 maintenance_manager.cc:419] P 3a7f3c71c2e642f6b419e61ab2e00625: Scheduling MajorDeltaCompactionOp(3513f4a5c07c45fd87231b0e93162473): perf score=1.000000
I20260812 06:19:37.982630 10016 maintenance_manager.cc:643] P 3a7f3c71c2e642f6b419e61ab2e00625: MajorDeltaCompactionOp(3513f4a5c07c45fd87231b0e93162473) complete. Timing: real 0.173s	user 0.127s	sys 0.040s 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":200,"lbm_read_time_us":9514,"lbm_reads_lt_1ms":564,"lbm_write_time_us":34671,"lbm_writes_lt_1ms":543,"mutex_wait_us":22,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":3200,"update_count":2500}
I20260812 06:19:37.983402 10121 maintenance_manager.cc:419] P 3a7f3c71c2e642f6b419e61ab2e00625: Scheduling FlushDeltaMemStoresOp(3513f4a5c07c45fd87231b0e93162473): perf score=14.095187
I20260812 06:19:38.039660 10016 maintenance_manager.cc:643] P 3a7f3c71c2e642f6b419e61ab2e00625: FlushDeltaMemStoresOp(3513f4a5c07c45fd87231b0e93162473) complete. Timing: real 0.056s	user 0.032s	sys 0.015s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":23218,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:38.040205 10121 maintenance_manager.cc:419] P 3a7f3c71c2e642f6b419e61ab2e00625: Scheduling FlushDeltaMemStoresOp(3513f4a5c07c45fd87231b0e93162473): perf score=2.188937
I20260812 06:19:38.051695 10016 maintenance_manager.cc:643] P 3a7f3c71c2e642f6b419e61ab2e00625: FlushDeltaMemStoresOp(3513f4a5c07c45fd87231b0e93162473) complete. Timing: real 0.011s	user 0.006s	sys 0.003s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4183,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:38.052181 10121 maintenance_manager.cc:419] P 3a7f3c71c2e642f6b419e61ab2e00625: Scheduling FlushMRSOp(3513f4a5c07c45fd87231b0e93162473): perf score=1.000000
I20260812 06:19:38.086318 10016 maintenance_manager.cc:643] P 3a7f3c71c2e642f6b419e61ab2e00625: FlushMRSOp(3513f4a5c07c45fd87231b0e93162473) complete. Timing: real 0.034s	user 0.032s	sys 0.000s Metrics: {"bytes_written":1275447,"cfile_init":1,"dirs.queue_time_us":65,"dirs.run_cpu_time_us":188,"dirs.run_wall_time_us":1278,"drs_written":1,"lbm_read_time_us":60,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1733,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":31}
I20260812 06:19:38.087095 10121 maintenance_manager.cc:419] P 3a7f3c71c2e642f6b419e61ab2e00625: Scheduling LogGCOp(3513f4a5c07c45fd87231b0e93162473): free 129320724 bytes of WAL
I20260812 06:19:38.087352 10016 log_reader.cc:385] T 3513f4a5c07c45fd87231b0e93162473: removed 13 log segments from log reader
I20260812 06:19:38.087419 10016 log.cc:1079] T 3513f4a5c07c45fd87231b0e93162473 P 3a7f3c71c2e642f6b419e61ab2e00625: Deleting log segment in path: /tmp/dist-test-taskWwnqpJ/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515567133744-9529-0/minicluster-data/ts-0-root/wals/3513f4a5c07c45fd87231b0e93162473/wal-000000027 (ops 131-135)
I20260812 06:19:38.087469 10016 log.cc:1079] T 3513f4a5c07c45fd87231b0e93162473 P 3a7f3c71c2e642f6b419e61ab2e00625: Deleting log segment in path: /tmp/dist-test-taskWwnqpJ/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515567133744-9529-0/minicluster-data/ts-0-root/wals/3513f4a5c07c45fd87231b0e93162473/wal-000000028 (ops 136-140)
I20260812 06:19:38.087528 10016 log.cc:1079] T 3513f4a5c07c45fd87231b0e93162473 P 3a7f3c71c2e642f6b419e61ab2e00625: Deleting log segment in path: /tmp/dist-test-taskWwnqpJ/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515567133744-9529-0/minicluster-data/ts-0-root/wals/3513f4a5c07c45fd87231b0e93162473/wal-000000029 (ops 141-144)
I20260812 06:19:38.087571 10016 log.cc:1079] T 3513f4a5c07c45fd87231b0e93162473 P 3a7f3c71c2e642f6b419e61ab2e00625: Deleting log segment in path: /tmp/dist-test-taskWwnqpJ/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515567133744-9529-0/minicluster-data/ts-0-root/wals/3513f4a5c07c45fd87231b0e93162473/wal-000000030 (ops 145-149)
I20260812 06:19:38.087610 10016 log.cc:1079] T 3513f4a5c07c45fd87231b0e93162473 P 3a7f3c71c2e642f6b419e61ab2e00625: Deleting log segment in path: /tmp/dist-test-taskWwnqpJ/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515567133744-9529-0/minicluster-data/ts-0-root/wals/3513f4a5c07c45fd87231b0e93162473/wal-000000031 (ops 150-154)
I20260812 06:19:38.087648 10016 log.cc:1079] T 3513f4a5c07c45fd87231b0e93162473 P 3a7f3c71c2e642f6b419e61ab2e00625: Deleting log segment in path: /tmp/dist-test-taskWwnqpJ/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515567133744-9529-0/minicluster-data/ts-0-root/wals/3513f4a5c07c45fd87231b0e93162473/wal-000000032 (ops 155-158)
I20260812 06:19:38.087685 10016 log.cc:1079] T 3513f4a5c07c45fd87231b0e93162473 P 3a7f3c71c2e642f6b419e61ab2e00625: Deleting log segment in path: /tmp/dist-test-taskWwnqpJ/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515567133744-9529-0/minicluster-data/ts-0-root/wals/3513f4a5c07c45fd87231b0e93162473/wal-000000033 (ops 159-163)
I20260812 06:19:38.087724 10016 log.cc:1079] T 3513f4a5c07c45fd87231b0e93162473 P 3a7f3c71c2e642f6b419e61ab2e00625: Deleting log segment in path: /tmp/dist-test-taskWwnqpJ/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515567133744-9529-0/minicluster-data/ts-0-root/wals/3513f4a5c07c45fd87231b0e93162473/wal-000000034 (ops 164-168)
I20260812 06:19:38.087761 10016 log.cc:1079] T 3513f4a5c07c45fd87231b0e93162473 P 3a7f3c71c2e642f6b419e61ab2e00625: Deleting log segment in path: /tmp/dist-test-taskWwnqpJ/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515567133744-9529-0/minicluster-data/ts-0-root/wals/3513f4a5c07c45fd87231b0e93162473/wal-000000035 (ops 169-173)
I20260812 06:19:38.087803 10016 log.cc:1079] T 3513f4a5c07c45fd87231b0e93162473 P 3a7f3c71c2e642f6b419e61ab2e00625: Deleting log segment in path: /tmp/dist-test-taskWwnqpJ/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515567133744-9529-0/minicluster-data/ts-0-root/wals/3513f4a5c07c45fd87231b0e93162473/wal-000000036 (ops 174-178)
I20260812 06:19:38.087842 10016 log.cc:1079] T 3513f4a5c07c45fd87231b0e93162473 P 3a7f3c71c2e642f6b419e61ab2e00625: Deleting log segment in path: /tmp/dist-test-taskWwnqpJ/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515567133744-9529-0/minicluster-data/ts-0-root/wals/3513f4a5c07c45fd87231b0e93162473/wal-000000037 (ops 179-183)
I20260812 06:19:38.087881 10016 log.cc:1079] T 3513f4a5c07c45fd87231b0e93162473 P 3a7f3c71c2e642f6b419e61ab2e00625: Deleting log segment in path: /tmp/dist-test-taskWwnqpJ/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515567133744-9529-0/minicluster-data/ts-0-root/wals/3513f4a5c07c45fd87231b0e93162473/wal-000000038 (ops 184-188)
I20260812 06:19:38.087921 10016 log.cc:1079] T 3513f4a5c07c45fd87231b0e93162473 P 3a7f3c71c2e642f6b419e61ab2e00625: Deleting log segment in path: /tmp/dist-test-taskWwnqpJ/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515567133744-9529-0/minicluster-data/ts-0-root/wals/3513f4a5c07c45fd87231b0e93162473/wal-000000039 (ops 189-193)
I20260812 06:19:38.118573 10016 maintenance_manager.cc:643] P 3a7f3c71c2e642f6b419e61ab2e00625: LogGCOp(3513f4a5c07c45fd87231b0e93162473) complete. Timing: real 0.031s	user 0.000s	sys 0.029s Metrics: {}
I20260812 06:19:38.119024 10121 maintenance_manager.cc:419] P 3a7f3c71c2e642f6b419e61ab2e00625: Scheduling FlushDeltaMemStoresOp(3513f4a5c07c45fd87231b0e93162473): perf score=3.181125
I20260812 06:19:38.147527 10016 maintenance_manager.cc:643] P 3a7f3c71c2e642f6b419e61ab2e00625: FlushDeltaMemStoresOp(3513f4a5c07c45fd87231b0e93162473) complete. Timing: real 0.028s	user 0.008s	sys 0.018s Metrics: {"bytes_written":4841094,"delete_count":0,"lbm_write_time_us":7438,"lbm_writes_lt_1ms":121,"reinsert_count":0,"update_count":590}
I20260812 06:19:38.148185 10121 maintenance_manager.cc:419] P 3a7f3c71c2e642f6b419e61ab2e00625: Scheduling FlushDeltaMemStoresOp(3513f4a5c07c45fd87231b0e93162473): perf score=2.188937
I20260812 06:19:38.157495 10016 maintenance_manager.cc:643] P 3a7f3c71c2e642f6b419e61ab2e00625: FlushDeltaMemStoresOp(3513f4a5c07c45fd87231b0e93162473) complete. Timing: real 0.009s	user 0.004s	sys 0.004s Metrics: {"bytes_written":3364205,"delete_count":0,"lbm_write_time_us":3349,"lbm_writes_lt_1ms":85,"reinsert_count":0,"update_count":410}
I20260812 06:19:38.158084 10121 maintenance_manager.cc:419] P 3a7f3c71c2e642f6b419e61ab2e00625: Scheduling MajorDeltaCompactionOp(3513f4a5c07c45fd87231b0e93162473): perf score=1.000000
I20260812 06:19:38.327612  9529 heavy-update-compaction-itest.cc:229] Time spent updating: real 5.197s	user 1.852s	sys 0.225s
I20260812 06:19:38.381731 10016 maintenance_manager.cc:643] P 3a7f3c71c2e642f6b419e61ab2e00625: MajorDeltaCompactionOp(3513f4a5c07c45fd87231b0e93162473) complete. Timing: real 0.223s	user 0.127s	sys 0.096s Metrics: {"cfile_cache_miss":734,"cfile_cache_miss_bytes":32979731,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"lbm_read_time_us":16719,"lbm_reads_lt_1ms":770,"lbm_write_time_us":39708,"lbm_writes_lt_1ms":743,"peak_mem_usage":87969044,"reinsert_count":0,"spinlock_wait_cycles":2816,"update_count":3500}
I20260812 06:19:38.382244 10121 maintenance_manager.cc:419] P 3a7f3c71c2e642f6b419e61ab2e00625: Scheduling FlushDeltaMemStoresOp(3513f4a5c07c45fd87231b0e93162473): perf score=10.126437
I20260812 06:19:38.404119  9529 heavy-update-compaction-itest.cc:265] Time spent scanning: real 0.076s	user 0.001s	sys 0.000s
I20260812 06:19:38.404620  9529 tablet_server.cc:179] TabletServer@127.9.78.65:0 shutting down...
I20260812 06:19:38.416968 10016 maintenance_manager.cc:643] P 3a7f3c71c2e642f6b419e61ab2e00625: FlushDeltaMemStoresOp(3513f4a5c07c45fd87231b0e93162473) complete. Timing: real 0.035s	user 0.011s	sys 0.023s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":14921,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:19:38.417587  9529 ts_tablet_manager.cc:1507] Shutting down tablet manager...
I20260812 06:19:38.417872  9529 tablet_replica.cc:333] T 3513f4a5c07c45fd87231b0e93162473 P 3a7f3c71c2e642f6b419e61ab2e00625: stopping tablet replica
I20260812 06:19:38.417996  9529 raft_consensus.cc:2243] T 3513f4a5c07c45fd87231b0e93162473 P 3a7f3c71c2e642f6b419e61ab2e00625 [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:19:38.431295  9529 raft_consensus.cc:2272] T 3513f4a5c07c45fd87231b0e93162473 P 3a7f3c71c2e642f6b419e61ab2e00625 [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:19:38.437099  9529 tablet_server.cc:196] TabletServer@127.9.78.65:0 shutdown complete.
I20260812 06:19:38.449687  9529 master.cc:562] Master@127.9.78.126:33273 shutting down...
I20260812 06:19:38.453547  9529 raft_consensus.cc:2243] T 00000000000000000000000000000000 P 9e0320a749c74345b05ee4a5bf839b3c [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:19:38.453765  9529 raft_consensus.cc:2272] T 00000000000000000000000000000000 P 9e0320a749c74345b05ee4a5bf839b3c [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:19:38.453855  9529 tablet_replica.cc:333] T 00000000000000000000000000000000 P 9e0320a749c74345b05ee4a5bf839b3c: stopping tablet replica
I20260812 06:19:38.466434  9529 master.cc:584] Master@127.9.78.126:33273 shutdown complete.
[       OK ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/1 (5672 ms)
[----------] 2 tests from EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy (11414 ms total)

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