[==========] 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:17:09.520656 26595 internal_mini_cluster.cc:156] Creating distributed mini masters. Addrs: 127.25.248.254:45537
I20260812 06:17:09.521616 26595 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:17:09.522204 26595 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:17:09.528584 26602 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:17:09.528650 26595 server_base.cc:1061] running on GCE node
W20260812 06:17:09.528602 26604 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:17:09.528920 26601 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:17:09.529426 26595 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:17:09.529582 26595 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:17:09.529640 26595 hybrid_clock.cc:648] HybridClock initialized: now 1786515429529637 us; error 0 us; skew 500 ppm
I20260812 06:17:09.531417 26595 webserver.cc:533] Webserver started at http://127.25.248.254:34747/ using document root <none> and password file <none>
I20260812 06:17:09.531982 26595 fs_manager.cc:362] Metadata directory not provided
I20260812 06:17:09.532074 26595 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:17:09.532330 26595 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:17:09.534032 26595 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskdBxro6/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515429510153-26595-0/minicluster-data/master-0-root/instance:
uuid: "89f4295528e048f193944e5c532f1eb0"
format_stamp: "Formatted at 2026-08-12 06:17:09 on dist-test-slave-10pc"
I20260812 06:17:09.537583 26595 fs_manager.cc:696] Time spent creating directory manager: real 0.003s	user 0.004s	sys 0.000s
I20260812 06:17:09.539664 26610 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:17:09.540663 26595 fs_manager.cc:730] Time spent opening block manager: real 0.002s	user 0.003s	sys 0.000s
I20260812 06:17:09.540799 26595 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskdBxro6/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515429510153-26595-0/minicluster-data/master-0-root
uuid: "89f4295528e048f193944e5c532f1eb0"
format_stamp: "Formatted at 2026-08-12 06:17:09 on dist-test-slave-10pc"
I20260812 06:17:09.540905 26595 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskdBxro6/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515429510153-26595-0/minicluster-data/master-0-root
metadata directory: /tmp/dist-test-taskdBxro6/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515429510153-26595-0/minicluster-data/master-0-root
1 data directories: /tmp/dist-test-taskdBxro6/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515429510153-26595-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:17:09.566896 26595 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:17:09.567591 26595 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:17:09.567775 26595 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:17:09.575407 26595 rpc_server.cc:307] RPC server started. Bound to: 127.25.248.254:45537
I20260812 06:17:09.575429 26668 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.25.248.254:45537 every 8 connection(s)
I20260812 06:17:09.577656 26669 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:17:09.582921 26669 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P 89f4295528e048f193944e5c532f1eb0: Bootstrap starting.
I20260812 06:17:09.585271 26669 tablet_bootstrap.cc:654] T 00000000000000000000000000000000 P 89f4295528e048f193944e5c532f1eb0: Neither blocks nor log segments found. Creating new log.
I20260812 06:17:09.586196 26669 log.cc:826] T 00000000000000000000000000000000 P 89f4295528e048f193944e5c532f1eb0: Log is configured to *not* fsync() on all Append() calls
I20260812 06:17:09.587822 26669 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P 89f4295528e048f193944e5c532f1eb0: No bootstrap required, opened a new log
I20260812 06:17:09.591356 26669 raft_consensus.cc:359] T 00000000000000000000000000000000 P 89f4295528e048f193944e5c532f1eb0 [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "89f4295528e048f193944e5c532f1eb0" member_type: VOTER }
I20260812 06:17:09.591614 26669 raft_consensus.cc:385] T 00000000000000000000000000000000 P 89f4295528e048f193944e5c532f1eb0 [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:17:09.591719 26669 raft_consensus.cc:740] T 00000000000000000000000000000000 P 89f4295528e048f193944e5c532f1eb0 [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: 89f4295528e048f193944e5c532f1eb0, State: Initialized, Role: FOLLOWER
I20260812 06:17:09.592352 26669 consensus_queue.cc:260] T 00000000000000000000000000000000 P 89f4295528e048f193944e5c532f1eb0 [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: "89f4295528e048f193944e5c532f1eb0" member_type: VOTER }
I20260812 06:17:09.592562 26669 raft_consensus.cc:399] T 00000000000000000000000000000000 P 89f4295528e048f193944e5c532f1eb0 [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:17:09.592649 26669 raft_consensus.cc:493] T 00000000000000000000000000000000 P 89f4295528e048f193944e5c532f1eb0 [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:17:09.592779 26669 raft_consensus.cc:3060] T 00000000000000000000000000000000 P 89f4295528e048f193944e5c532f1eb0 [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:17:09.593571 26669 raft_consensus.cc:515] T 00000000000000000000000000000000 P 89f4295528e048f193944e5c532f1eb0 [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "89f4295528e048f193944e5c532f1eb0" member_type: VOTER }
I20260812 06:17:09.594007 26669 leader_election.cc:304] T 00000000000000000000000000000000 P 89f4295528e048f193944e5c532f1eb0 [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: 89f4295528e048f193944e5c532f1eb0; no voters: 
I20260812 06:17:09.594332 26669 leader_election.cc:290] T 00000000000000000000000000000000 P 89f4295528e048f193944e5c532f1eb0 [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:17:09.594488 26672 raft_consensus.cc:2804] T 00000000000000000000000000000000 P 89f4295528e048f193944e5c532f1eb0 [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:17:09.594732 26672 raft_consensus.cc:697] T 00000000000000000000000000000000 P 89f4295528e048f193944e5c532f1eb0 [term 1 LEADER]: Becoming Leader. State: Replica: 89f4295528e048f193944e5c532f1eb0, State: Running, Role: LEADER
I20260812 06:17:09.595127 26672 consensus_queue.cc:237] T 00000000000000000000000000000000 P 89f4295528e048f193944e5c532f1eb0 [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: "89f4295528e048f193944e5c532f1eb0" member_type: VOTER }
I20260812 06:17:09.595377 26669 sys_catalog.cc:565] T 00000000000000000000000000000000 P 89f4295528e048f193944e5c532f1eb0 [sys.catalog]: configured and running, proceeding with master startup.
I20260812 06:17:09.596948 26673 sys_catalog.cc:455] T 00000000000000000000000000000000 P 89f4295528e048f193944e5c532f1eb0 [sys.catalog]: SysCatalogTable state changed. Reason: RaftConsensus started. Latest consensus state: current_term: 1 leader_uuid: "89f4295528e048f193944e5c532f1eb0" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "89f4295528e048f193944e5c532f1eb0" member_type: VOTER } }
I20260812 06:17:09.597069 26673 sys_catalog.cc:458] T 00000000000000000000000000000000 P 89f4295528e048f193944e5c532f1eb0 [sys.catalog]: This master's current role is: LEADER
I20260812 06:17:09.597379 26675 sys_catalog.cc:455] T 00000000000000000000000000000000 P 89f4295528e048f193944e5c532f1eb0 [sys.catalog]: SysCatalogTable state changed. Reason: New leader 89f4295528e048f193944e5c532f1eb0. Latest consensus state: current_term: 1 leader_uuid: "89f4295528e048f193944e5c532f1eb0" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "89f4295528e048f193944e5c532f1eb0" member_type: VOTER } }
I20260812 06:17:09.597463 26675 sys_catalog.cc:458] T 00000000000000000000000000000000 P 89f4295528e048f193944e5c532f1eb0 [sys.catalog]: This master's current role is: LEADER
I20260812 06:17:09.597790 26595 internal_mini_cluster.cc:184] Waiting to initialize catalog manager on master 0
W20260812 06:17:09.599785 26689 catalog_manager.cc:1594] T 00000000000000000000000000000000 P 89f4295528e048f193944e5c532f1eb0: loading cluster ID for follower catalog manager: Not found: cluster ID entry not found
W20260812 06:17:09.599845 26689 catalog_manager.cc:883] Not found: cluster ID entry not found: failed to prepare follower catalog manager, will retry
I20260812 06:17:09.599915 26684 catalog_manager.cc:1511] Loading table and tablet metadata into memory...
I20260812 06:17:09.600718 26684 catalog_manager.cc:1520] Initializing Kudu cluster ID...
I20260812 06:17:09.605556 26684 catalog_manager.cc:1383] Generated new cluster ID: b0bafc76d4f14267a12c6ce176f9c7a0
I20260812 06:17:09.605630 26684 catalog_manager.cc:1531] Initializing Kudu internal certificate authority...
I20260812 06:17:09.617542 26684 catalog_manager.cc:1406] Generated new certificate authority record
I20260812 06:17:09.618358 26684 catalog_manager.cc:1540] Loading token signing keys...
I20260812 06:17:09.625250 26684 catalog_manager.cc:6092] T 00000000000000000000000000000000 P 89f4295528e048f193944e5c532f1eb0: Generated new TSK 0
I20260812 06:17:09.625813 26684 catalog_manager.cc:1550] Initializing in-progress tserver states...
I20260812 06:17:09.630343 26595 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:17:09.632845 26693 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:17:09.632872 26694 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:17:09.632961 26595 server_base.cc:1061] running on GCE node
W20260812 06:17:09.633116 26696 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:17:09.633371 26595 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:17:09.633419 26595 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:17:09.633433 26595 hybrid_clock.cc:648] HybridClock initialized: now 1786515429633434 us; error 0 us; skew 500 ppm
I20260812 06:17:09.634387 26595 webserver.cc:533] Webserver started at http://127.25.248.193:45605/ using document root <none> and password file <none>
I20260812 06:17:09.634569 26595 fs_manager.cc:362] Metadata directory not provided
I20260812 06:17:09.634618 26595 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:17:09.634716 26595 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:17:09.635093 26595 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskdBxro6/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515429510153-26595-0/minicluster-data/ts-0-root/instance:
uuid: "e78892971ebf49c2bdf20115712ae7bd"
format_stamp: "Formatted at 2026-08-12 06:17:09 on dist-test-slave-10pc"
I20260812 06:17:09.636598 26595 fs_manager.cc:696] Time spent creating directory manager: real 0.001s	user 0.002s	sys 0.000s
I20260812 06:17:09.637614 26702 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:17:09.637852 26595 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.001s	sys 0.000s
I20260812 06:17:09.637943 26595 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskdBxro6/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515429510153-26595-0/minicluster-data/ts-0-root
uuid: "e78892971ebf49c2bdf20115712ae7bd"
format_stamp: "Formatted at 2026-08-12 06:17:09 on dist-test-slave-10pc"
I20260812 06:17:09.638021 26595 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskdBxro6/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515429510153-26595-0/minicluster-data/ts-0-root
metadata directory: /tmp/dist-test-taskdBxro6/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515429510153-26595-0/minicluster-data/ts-0-root
1 data directories: /tmp/dist-test-taskdBxro6/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515429510153-26595-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:17:09.642204 26595 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:17:09.642603 26595 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:17:09.643060 26595 txn_system_client.cc:432] TxnSystemClient initialization is disabled...
I20260812 06:17:09.643817 26595 ts_tablet_manager.cc:585] Loaded tablet metadata (0 total tablets, 0 live tablets)
I20260812 06:17:09.643867 26595 ts_tablet_manager.cc:531] Time spent load tablet metadata: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:17:09.643931 26595 ts_tablet_manager.cc:616] Registered 0 tablets
I20260812 06:17:09.643973 26595 ts_tablet_manager.cc:595] Time spent register tablets: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:17:09.650870 26595 rpc_server.cc:307] RPC server started. Bound to: 127.25.248.193:34377
I20260812 06:17:09.650904 26768 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.25.248.193:34377 every 8 connection(s)
I20260812 06:17:09.665226 26770 heartbeater.cc:344] Connected to a master server at 127.25.248.254:45537
I20260812 06:17:09.665480 26770 heartbeater.cc:461] Registering TS with master...
I20260812 06:17:09.665946 26770 heartbeater.cc:507] Master 127.25.248.254:45537 requested a full tablet report, sending...
I20260812 06:17:09.667491 26630 ts_manager.cc:194] Registered new tserver with Master: e78892971ebf49c2bdf20115712ae7bd (127.25.248.193:34377)
I20260812 06:17:09.668187 26595 internal_mini_cluster.cc:371] 1 TS(s) registered with all masters after 0.016668555s
I20260812 06:17:09.669080 26630 master_service.cc:502] Signed X509 certificate for tserver {username='slave'} at 127.0.0.1:34454
I20260812 06:17:09.678552 26630 catalog_manager.cc:2283] Servicing CreateTable request from {username='slave'} at 127.0.0.1:34462:
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:17:09.694020 26732 tablet_service.cc:1511] Processing CreateTablet for tablet d609d3ecd5a74d16b31521f4951e3187 (DEFAULT_TABLE table=heavy-update-compaction-test [id=e69a59b088e94617ac67d82dd5611758]), partition=
I20260812 06:17:09.694491 26732 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet d609d3ecd5a74d16b31521f4951e3187. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:17:09.696597 26786 tablet_bootstrap.cc:492] T d609d3ecd5a74d16b31521f4951e3187 P e78892971ebf49c2bdf20115712ae7bd: Bootstrap starting.
I20260812 06:17:09.697912 26786 tablet_bootstrap.cc:654] T d609d3ecd5a74d16b31521f4951e3187 P e78892971ebf49c2bdf20115712ae7bd: Neither blocks nor log segments found. Creating new log.
I20260812 06:17:09.698966 26786 tablet_bootstrap.cc:492] T d609d3ecd5a74d16b31521f4951e3187 P e78892971ebf49c2bdf20115712ae7bd: No bootstrap required, opened a new log
I20260812 06:17:09.699090 26786 ts_tablet_manager.cc:1403] T d609d3ecd5a74d16b31521f4951e3187 P e78892971ebf49c2bdf20115712ae7bd: Time spent bootstrapping tablet: real 0.003s	user 0.002s	sys 0.000s
I20260812 06:17:09.699482 26786 raft_consensus.cc:359] T d609d3ecd5a74d16b31521f4951e3187 P e78892971ebf49c2bdf20115712ae7bd [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "e78892971ebf49c2bdf20115712ae7bd" member_type: VOTER last_known_addr { host: "127.25.248.193" port: 34377 } }
I20260812 06:17:09.699600 26786 raft_consensus.cc:385] T d609d3ecd5a74d16b31521f4951e3187 P e78892971ebf49c2bdf20115712ae7bd [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:17:09.699646 26786 raft_consensus.cc:740] T d609d3ecd5a74d16b31521f4951e3187 P e78892971ebf49c2bdf20115712ae7bd [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: e78892971ebf49c2bdf20115712ae7bd, State: Initialized, Role: FOLLOWER
I20260812 06:17:09.699810 26786 consensus_queue.cc:260] T d609d3ecd5a74d16b31521f4951e3187 P e78892971ebf49c2bdf20115712ae7bd [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: "e78892971ebf49c2bdf20115712ae7bd" member_type: VOTER last_known_addr { host: "127.25.248.193" port: 34377 } }
I20260812 06:17:09.699935 26786 raft_consensus.cc:399] T d609d3ecd5a74d16b31521f4951e3187 P e78892971ebf49c2bdf20115712ae7bd [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:17:09.699993 26786 raft_consensus.cc:493] T d609d3ecd5a74d16b31521f4951e3187 P e78892971ebf49c2bdf20115712ae7bd [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:17:09.700054 26786 raft_consensus.cc:3060] T d609d3ecd5a74d16b31521f4951e3187 P e78892971ebf49c2bdf20115712ae7bd [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:17:09.700867 26786 raft_consensus.cc:515] T d609d3ecd5a74d16b31521f4951e3187 P e78892971ebf49c2bdf20115712ae7bd [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "e78892971ebf49c2bdf20115712ae7bd" member_type: VOTER last_known_addr { host: "127.25.248.193" port: 34377 } }
I20260812 06:17:09.701023 26786 leader_election.cc:304] T d609d3ecd5a74d16b31521f4951e3187 P e78892971ebf49c2bdf20115712ae7bd [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: e78892971ebf49c2bdf20115712ae7bd; no voters: 
I20260812 06:17:09.701242 26786 leader_election.cc:290] T d609d3ecd5a74d16b31521f4951e3187 P e78892971ebf49c2bdf20115712ae7bd [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:17:09.701337 26788 raft_consensus.cc:2804] T d609d3ecd5a74d16b31521f4951e3187 P e78892971ebf49c2bdf20115712ae7bd [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:17:09.701582 26788 raft_consensus.cc:697] T d609d3ecd5a74d16b31521f4951e3187 P e78892971ebf49c2bdf20115712ae7bd [term 1 LEADER]: Becoming Leader. State: Replica: e78892971ebf49c2bdf20115712ae7bd, State: Running, Role: LEADER
I20260812 06:17:09.701653 26786 ts_tablet_manager.cc:1434] T d609d3ecd5a74d16b31521f4951e3187 P e78892971ebf49c2bdf20115712ae7bd: Time spent starting tablet: real 0.002s	user 0.000s	sys 0.002s
I20260812 06:17:09.701854 26770 heartbeater.cc:499] Master 127.25.248.254:45537 was elected leader, sending a full tablet report...
I20260812 06:17:09.702165 26788 consensus_queue.cc:237] T d609d3ecd5a74d16b31521f4951e3187 P e78892971ebf49c2bdf20115712ae7bd [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: "e78892971ebf49c2bdf20115712ae7bd" member_type: VOTER last_known_addr { host: "127.25.248.193" port: 34377 } }
I20260812 06:17:09.704772 26630 catalog_manager.cc:5719] T d609d3ecd5a74d16b31521f4951e3187 P e78892971ebf49c2bdf20115712ae7bd reported cstate change: term changed from 0 to 1, leader changed from <none> to e78892971ebf49c2bdf20115712ae7bd (127.25.248.193). New cstate: current_term: 1 leader_uuid: "e78892971ebf49c2bdf20115712ae7bd" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "e78892971ebf49c2bdf20115712ae7bd" member_type: VOTER last_known_addr { host: "127.25.248.193" port: 34377 } health_report { overall_health: HEALTHY } } }
I20260812 06:17:09.777539 26595 heavy-update-compaction-itest.cc:215] Time spent inserting: real 0.063s	user 0.025s	sys 0.008s
I20260812 06:17:09.902001 26772 maintenance_manager.cc:419] P e78892971ebf49c2bdf20115712ae7bd: Scheduling FlushMRSOp(d609d3ecd5a74d16b31521f4951e3187): perf score=15.086190
I20260812 06:17:10.057227 26707 maintenance_manager.cc:643] P e78892971ebf49c2bdf20115712ae7bd: FlushMRSOp(d609d3ecd5a74d16b31521f4951e3187) complete. Timing: real 0.155s	user 0.107s	sys 0.041s Metrics: {"bytes_written":11897249,"cfile_init":1,"compiler_manager_pool.queue_time_us":244,"delete_count":0,"dirs.queue_time_us":78,"dirs.run_cpu_time_us":221,"dirs.run_wall_time_us":991,"drs_written":1,"lbm_read_time_us":52,"lbm_reads_lt_1ms":4,"lbm_write_time_us":37623,"lbm_writes_lt_1ms":657,"peak_mem_usage":0,"reinsert_count":0,"rows_written":104,"thread_start_us":118,"threads_started":1,"update_count":1450}
I20260812 06:17:10.058302 26772 maintenance_manager.cc:419] P e78892971ebf49c2bdf20115712ae7bd: Scheduling LogGCOp(d609d3ecd5a74d16b31521f4951e3187): free 20743880 bytes of WAL
I20260812 06:17:10.058609 26707 log_reader.cc:385] T d609d3ecd5a74d16b31521f4951e3187: removed 2 log segments from log reader
I20260812 06:17:10.058701 26707 log.cc:1079] T d609d3ecd5a74d16b31521f4951e3187 P e78892971ebf49c2bdf20115712ae7bd: Deleting log segment in path: /tmp/dist-test-taskdBxro6/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515429510153-26595-0/minicluster-data/ts-0-root/wals/d609d3ecd5a74d16b31521f4951e3187/wal-000000001 (ops 1-6)
I20260812 06:17:10.058779 26707 log.cc:1079] T d609d3ecd5a74d16b31521f4951e3187 P e78892971ebf49c2bdf20115712ae7bd: Deleting log segment in path: /tmp/dist-test-taskdBxro6/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515429510153-26595-0/minicluster-data/ts-0-root/wals/d609d3ecd5a74d16b31521f4951e3187/wal-000000002 (ops 7-11)
I20260812 06:17:10.063205 26707 maintenance_manager.cc:643] P e78892971ebf49c2bdf20115712ae7bd: LogGCOp(d609d3ecd5a74d16b31521f4951e3187) complete. Timing: real 0.005s	user 0.000s	sys 0.002s Metrics: {}
I20260812 06:17:10.063535 26772 maintenance_manager.cc:419] P e78892971ebf49c2bdf20115712ae7bd: Scheduling UndoDeltaBlockGCOp(d609d3ecd5a74d16b31521f4951e3187): 12719216 bytes on disk
I20260812 06:17:10.064142 26707 maintenance_manager.cc:643] P e78892971ebf49c2bdf20115712ae7bd: UndoDeltaBlockGCOp(d609d3ecd5a74d16b31521f4951e3187) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":55,"lbm_reads_lt_1ms":4}
I20260812 06:17:10.064574 26772 maintenance_manager.cc:419] P e78892971ebf49c2bdf20115712ae7bd: Scheduling FlushDeltaMemStoresOp(d609d3ecd5a74d16b31521f4951e3187): perf score=2.188937
I20260812 06:17:10.085193 26707 maintenance_manager.cc:643] P e78892971ebf49c2bdf20115712ae7bd: FlushDeltaMemStoresOp(d609d3ecd5a74d16b31521f4951e3187) complete. Timing: real 0.020s	user 0.015s	sys 0.001s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6306,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:10.085690 26772 maintenance_manager.cc:419] P e78892971ebf49c2bdf20115712ae7bd: Scheduling MajorDeltaCompactionOp(d609d3ecd5a74d16b31521f4951e3187): perf score=1.000000
I20260812 06:17:10.221930 26707 maintenance_manager.cc:643] P e78892971ebf49c2bdf20115712ae7bd: MajorDeltaCompactionOp(d609d3ecd5a74d16b31521f4951e3187) complete. Timing: real 0.136s	user 0.100s	sys 0.036s 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":578,"lbm_read_time_us":7957,"lbm_reads_lt_1ms":450,"lbm_write_time_us":24726,"lbm_writes_lt_1ms":433,"mutex_wait_us":23,"peak_mem_usage":49238594,"reinsert_count":0,"spinlock_wait_cycles":11520,"thread_start_us":335,"threads_started":5,"update_count":1950}
I20260812 06:17:10.222553 26772 maintenance_manager.cc:419] P e78892971ebf49c2bdf20115712ae7bd: Scheduling FlushDeltaMemStoresOp(d609d3ecd5a74d16b31521f4951e3187): perf score=10.126437
I20260812 06:17:10.266790 26707 maintenance_manager.cc:643] P e78892971ebf49c2bdf20115712ae7bd: FlushDeltaMemStoresOp(d609d3ecd5a74d16b31521f4951e3187) complete. Timing: real 0.044s	user 0.017s	sys 0.024s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":18450,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:17:10.267307 26772 maintenance_manager.cc:419] P e78892971ebf49c2bdf20115712ae7bd: Scheduling FlushDeltaMemStoresOp(d609d3ecd5a74d16b31521f4951e3187): perf score=2.188937
I20260812 06:17:10.282071 26707 maintenance_manager.cc:643] P e78892971ebf49c2bdf20115712ae7bd: FlushDeltaMemStoresOp(d609d3ecd5a74d16b31521f4951e3187) complete. Timing: real 0.015s	user 0.005s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5558,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:10.282519 26772 maintenance_manager.cc:419] P e78892971ebf49c2bdf20115712ae7bd: Scheduling MajorDeltaCompactionOp(d609d3ecd5a74d16b31521f4951e3187): perf score=1.000000
I20260812 06:17:10.425802 26707 maintenance_manager.cc:643] P e78892971ebf49c2bdf20115712ae7bd: MajorDeltaCompactionOp(d609d3ecd5a74d16b31521f4951e3187) complete. Timing: real 0.143s	user 0.118s	sys 0.024s 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":1874,"lbm_read_time_us":7732,"lbm_reads_lt_1ms":472,"lbm_write_time_us":29143,"lbm_writes_lt_1ms":443,"mutex_wait_us":486,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":768,"update_count":2000}
I20260812 06:17:10.426851 26772 maintenance_manager.cc:419] P e78892971ebf49c2bdf20115712ae7bd: Scheduling FlushDeltaMemStoresOp(d609d3ecd5a74d16b31521f4951e3187): perf score=10.126437
I20260812 06:17:10.498049 26707 maintenance_manager.cc:643] P e78892971ebf49c2bdf20115712ae7bd: FlushDeltaMemStoresOp(d609d3ecd5a74d16b31521f4951e3187) complete. Timing: real 0.071s	user 0.047s	sys 0.020s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":30118,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:17:10.498757 26772 maintenance_manager.cc:419] P e78892971ebf49c2bdf20115712ae7bd: Scheduling FlushDeltaMemStoresOp(d609d3ecd5a74d16b31521f4951e3187): perf score=2.188937
I20260812 06:17:10.519356 26707 maintenance_manager.cc:643] P e78892971ebf49c2bdf20115712ae7bd: FlushDeltaMemStoresOp(d609d3ecd5a74d16b31521f4951e3187) complete. Timing: real 0.020s	user 0.017s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":7105,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:10.520474 26772 maintenance_manager.cc:419] P e78892971ebf49c2bdf20115712ae7bd: Scheduling MajorDeltaCompactionOp(d609d3ecd5a74d16b31521f4951e3187): perf score=1.000000
I20260812 06:17:10.711720 26707 maintenance_manager.cc:643] P e78892971ebf49c2bdf20115712ae7bd: MajorDeltaCompactionOp(d609d3ecd5a74d16b31521f4951e3187) complete. Timing: real 0.191s	user 0.146s	sys 0.045s 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":190,"lbm_read_time_us":14695,"lbm_reads_lt_1ms":472,"lbm_write_time_us":39999,"lbm_writes_lt_1ms":443,"mutex_wait_us":28,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":6784,"update_count":2000}
I20260812 06:17:10.712775 26772 maintenance_manager.cc:419] P e78892971ebf49c2bdf20115712ae7bd: Scheduling FlushDeltaMemStoresOp(d609d3ecd5a74d16b31521f4951e3187): perf score=10.126437
I20260812 06:17:10.800158 26707 maintenance_manager.cc:643] P e78892971ebf49c2bdf20115712ae7bd: FlushDeltaMemStoresOp(d609d3ecd5a74d16b31521f4951e3187) complete. Timing: real 0.087s	user 0.052s	sys 0.028s Metrics: {"bytes_written":12307492,"delete_count":0,"lbm_write_time_us":35306,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":302,"reinsert_count":0,"update_count":1500}
I20260812 06:17:10.801060 26772 maintenance_manager.cc:419] P e78892971ebf49c2bdf20115712ae7bd: Scheduling FlushDeltaMemStoresOp(d609d3ecd5a74d16b31521f4951e3187): perf score=2.188937
I20260812 06:17:10.820078 26707 maintenance_manager.cc:643] P e78892971ebf49c2bdf20115712ae7bd: FlushDeltaMemStoresOp(d609d3ecd5a74d16b31521f4951e3187) complete. Timing: real 0.019s	user 0.012s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":7651,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:10.820950 26772 maintenance_manager.cc:419] P e78892971ebf49c2bdf20115712ae7bd: Scheduling MajorDeltaCompactionOp(d609d3ecd5a74d16b31521f4951e3187): perf score=1.000000
I20260812 06:17:11.055773 26707 maintenance_manager.cc:643] P e78892971ebf49c2bdf20115712ae7bd: MajorDeltaCompactionOp(d609d3ecd5a74d16b31521f4951e3187) complete. Timing: real 0.235s	user 0.148s	sys 0.086s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672279,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":927,"lbm_read_time_us":19831,"lbm_reads_lt_1ms":472,"lbm_write_time_us":43220,"lbm_writes_lt_1ms":443,"mutex_wait_us":2,"peak_mem_usage":50689328,"reinsert_count":0,"update_count":2000}
I20260812 06:17:11.059592 26772 maintenance_manager.cc:419] P e78892971ebf49c2bdf20115712ae7bd: Scheduling FlushDeltaMemStoresOp(d609d3ecd5a74d16b31521f4951e3187): perf score=10.126437
I20260812 06:17:11.128376 26707 maintenance_manager.cc:643] P e78892971ebf49c2bdf20115712ae7bd: FlushDeltaMemStoresOp(d609d3ecd5a74d16b31521f4951e3187) complete. Timing: real 0.068s	user 0.039s	sys 0.019s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":27462,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:17:11.129256 26772 maintenance_manager.cc:419] P e78892971ebf49c2bdf20115712ae7bd: Scheduling FlushDeltaMemStoresOp(d609d3ecd5a74d16b31521f4951e3187): perf score=2.188937
I20260812 06:17:11.149461 26707 maintenance_manager.cc:643] P e78892971ebf49c2bdf20115712ae7bd: FlushDeltaMemStoresOp(d609d3ecd5a74d16b31521f4951e3187) complete. Timing: real 0.020s	user 0.019s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6986,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:11.150635 26772 maintenance_manager.cc:419] P e78892971ebf49c2bdf20115712ae7bd: Scheduling MajorDeltaCompactionOp(d609d3ecd5a74d16b31521f4951e3187): perf score=1.000000
I20260812 06:17:11.362720 26707 maintenance_manager.cc:643] P e78892971ebf49c2bdf20115712ae7bd: MajorDeltaCompactionOp(d609d3ecd5a74d16b31521f4951e3187) complete. Timing: real 0.212s	user 0.173s	sys 0.039s 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":479,"lbm_read_time_us":14475,"lbm_reads_lt_1ms":472,"lbm_write_time_us":47096,"lbm_writes_lt_1ms":443,"mutex_wait_us":43,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":4864,"update_count":2000}
I20260812 06:17:11.363519 26772 maintenance_manager.cc:419] P e78892971ebf49c2bdf20115712ae7bd: Scheduling FlushDeltaMemStoresOp(d609d3ecd5a74d16b31521f4951e3187): perf score=10.126437
I20260812 06:17:11.430281 26707 maintenance_manager.cc:643] P e78892971ebf49c2bdf20115712ae7bd: FlushDeltaMemStoresOp(d609d3ecd5a74d16b31521f4951e3187) complete. Timing: real 0.066s	user 0.049s	sys 0.015s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":28756,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:17:11.431034 26772 maintenance_manager.cc:419] P e78892971ebf49c2bdf20115712ae7bd: Scheduling FlushDeltaMemStoresOp(d609d3ecd5a74d16b31521f4951e3187): perf score=2.188937
I20260812 06:17:11.449896 26707 maintenance_manager.cc:643] P e78892971ebf49c2bdf20115712ae7bd: FlushDeltaMemStoresOp(d609d3ecd5a74d16b31521f4951e3187) complete. Timing: real 0.019s	user 0.013s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":7502,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:11.450827 26772 maintenance_manager.cc:419] P e78892971ebf49c2bdf20115712ae7bd: Scheduling MajorDeltaCompactionOp(d609d3ecd5a74d16b31521f4951e3187): perf score=1.000000
I20260812 06:17:11.693931 26707 maintenance_manager.cc:643] P e78892971ebf49c2bdf20115712ae7bd: MajorDeltaCompactionOp(d609d3ecd5a74d16b31521f4951e3187) complete. Timing: real 0.243s	user 0.184s	sys 0.052s 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":829,"lbm_read_time_us":16930,"lbm_reads_lt_1ms":472,"lbm_write_time_us":49935,"lbm_writes_lt_1ms":443,"mutex_wait_us":3,"peak_mem_usage":50689328,"reinsert_count":0,"update_count":2000}
I20260812 06:17:11.695071 26772 maintenance_manager.cc:419] P e78892971ebf49c2bdf20115712ae7bd: Scheduling FlushDeltaMemStoresOp(d609d3ecd5a74d16b31521f4951e3187): perf score=11.118625
I20260812 06:17:11.758634 26707 maintenance_manager.cc:643] P e78892971ebf49c2bdf20115712ae7bd: FlushDeltaMemStoresOp(d609d3ecd5a74d16b31521f4951e3187) complete. Timing: real 0.063s	user 0.026s	sys 0.035s Metrics: {"bytes_written":12717737,"delete_count":0,"lbm_write_time_us":24562,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:17:11.759573 26772 maintenance_manager.cc:419] P e78892971ebf49c2bdf20115712ae7bd: Scheduling FlushDeltaMemStoresOp(d609d3ecd5a74d16b31521f4951e3187): perf score=2.188937
I20260812 06:17:11.787663 26707 maintenance_manager.cc:643] P e78892971ebf49c2bdf20115712ae7bd: FlushDeltaMemStoresOp(d609d3ecd5a74d16b31521f4951e3187) complete. Timing: real 0.028s	user 0.020s	sys 0.000s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":8959,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:17:11.788326 26772 maintenance_manager.cc:419] P e78892971ebf49c2bdf20115712ae7bd: Scheduling FlushMRSOp(d609d3ecd5a74d16b31521f4951e3187): perf score=1.000000
I20260812 06:17:11.846984 26707 maintenance_manager.cc:643] P e78892971ebf49c2bdf20115712ae7bd: FlushMRSOp(d609d3ecd5a74d16b31521f4951e3187) complete. Timing: real 0.058s	user 0.046s	sys 0.010s Metrics: {"bytes_written":1152508,"cfile_init":1,"dirs.queue_time_us":136,"dirs.run_cpu_time_us":441,"dirs.run_wall_time_us":1689,"drs_written":1,"lbm_read_time_us":98,"lbm_reads_lt_1ms":4,"lbm_write_time_us":3839,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":28}
I20260812 06:17:11.848286 26772 maintenance_manager.cc:419] P e78892971ebf49c2bdf20115712ae7bd: Scheduling LogGCOp(d609d3ecd5a74d16b31521f4951e3187): free 103925197 bytes of WAL
I20260812 06:17:11.848663 26707 log_reader.cc:385] T d609d3ecd5a74d16b31521f4951e3187: removed 10 log segments from log reader
I20260812 06:17:11.848747 26707 log.cc:1079] T d609d3ecd5a74d16b31521f4951e3187 P e78892971ebf49c2bdf20115712ae7bd: Deleting log segment in path: /tmp/dist-test-taskdBxro6/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515429510153-26595-0/minicluster-data/ts-0-root/wals/d609d3ecd5a74d16b31521f4951e3187/wal-000000003 (ops 12-16)
I20260812 06:17:11.848843 26707 log.cc:1079] T d609d3ecd5a74d16b31521f4951e3187 P e78892971ebf49c2bdf20115712ae7bd: Deleting log segment in path: /tmp/dist-test-taskdBxro6/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515429510153-26595-0/minicluster-data/ts-0-root/wals/d609d3ecd5a74d16b31521f4951e3187/wal-000000004 (ops 17-21)
I20260812 06:17:11.849100 26707 log.cc:1079] T d609d3ecd5a74d16b31521f4951e3187 P e78892971ebf49c2bdf20115712ae7bd: Deleting log segment in path: /tmp/dist-test-taskdBxro6/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515429510153-26595-0/minicluster-data/ts-0-root/wals/d609d3ecd5a74d16b31521f4951e3187/wal-000000005 (ops 22-26)
I20260812 06:17:11.849186 26707 log.cc:1079] T d609d3ecd5a74d16b31521f4951e3187 P e78892971ebf49c2bdf20115712ae7bd: Deleting log segment in path: /tmp/dist-test-taskdBxro6/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515429510153-26595-0/minicluster-data/ts-0-root/wals/d609d3ecd5a74d16b31521f4951e3187/wal-000000006 (ops 27-31)
I20260812 06:17:11.849244 26707 log.cc:1079] T d609d3ecd5a74d16b31521f4951e3187 P e78892971ebf49c2bdf20115712ae7bd: Deleting log segment in path: /tmp/dist-test-taskdBxro6/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515429510153-26595-0/minicluster-data/ts-0-root/wals/d609d3ecd5a74d16b31521f4951e3187/wal-000000007 (ops 32-36)
I20260812 06:17:11.849347 26707 log.cc:1079] T d609d3ecd5a74d16b31521f4951e3187 P e78892971ebf49c2bdf20115712ae7bd: Deleting log segment in path: /tmp/dist-test-taskdBxro6/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515429510153-26595-0/minicluster-data/ts-0-root/wals/d609d3ecd5a74d16b31521f4951e3187/wal-000000008 (ops 37-41)
I20260812 06:17:11.849463 26707 log.cc:1079] T d609d3ecd5a74d16b31521f4951e3187 P e78892971ebf49c2bdf20115712ae7bd: Deleting log segment in path: /tmp/dist-test-taskdBxro6/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515429510153-26595-0/minicluster-data/ts-0-root/wals/d609d3ecd5a74d16b31521f4951e3187/wal-000000009 (ops 42-46)
I20260812 06:17:11.849560 26707 log.cc:1079] T d609d3ecd5a74d16b31521f4951e3187 P e78892971ebf49c2bdf20115712ae7bd: Deleting log segment in path: /tmp/dist-test-taskdBxro6/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515429510153-26595-0/minicluster-data/ts-0-root/wals/d609d3ecd5a74d16b31521f4951e3187/wal-000000010 (ops 47-51)
I20260812 06:17:11.849680 26707 log.cc:1079] T d609d3ecd5a74d16b31521f4951e3187 P e78892971ebf49c2bdf20115712ae7bd: Deleting log segment in path: /tmp/dist-test-taskdBxro6/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515429510153-26595-0/minicluster-data/ts-0-root/wals/d609d3ecd5a74d16b31521f4951e3187/wal-000000011 (ops 52-56)
I20260812 06:17:11.849812 26707 log.cc:1079] T d609d3ecd5a74d16b31521f4951e3187 P e78892971ebf49c2bdf20115712ae7bd: Deleting log segment in path: /tmp/dist-test-taskdBxro6/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515429510153-26595-0/minicluster-data/ts-0-root/wals/d609d3ecd5a74d16b31521f4951e3187/wal-000000012 (ops 57-61)
I20260812 06:17:11.893314 26707 maintenance_manager.cc:643] P e78892971ebf49c2bdf20115712ae7bd: LogGCOp(d609d3ecd5a74d16b31521f4951e3187) complete. Timing: real 0.045s	user 0.000s	sys 0.044s Metrics: {}
I20260812 06:17:11.895393 26772 maintenance_manager.cc:419] P e78892971ebf49c2bdf20115712ae7bd: Scheduling UndoDeltaBlockGCOp(d609d3ecd5a74d16b31521f4951e3187): 448 bytes on disk
I20260812 06:17:11.896354 26707 maintenance_manager.cc:643] P e78892971ebf49c2bdf20115712ae7bd: UndoDeltaBlockGCOp(d609d3ecd5a74d16b31521f4951e3187) complete. Timing: real 0.001s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":160,"lbm_reads_lt_1ms":4}
I20260812 06:17:11.897673 26772 maintenance_manager.cc:419] P e78892971ebf49c2bdf20115712ae7bd: Scheduling FlushDeltaMemStoresOp(d609d3ecd5a74d16b31521f4951e3187): perf score=3.181125
I20260812 06:17:11.924678 26707 maintenance_manager.cc:643] P e78892971ebf49c2bdf20115712ae7bd: FlushDeltaMemStoresOp(d609d3ecd5a74d16b31521f4951e3187) complete. Timing: real 0.027s	user 0.013s	sys 0.011s Metrics: {"bytes_written":4512903,"delete_count":0,"lbm_write_time_us":9655,"lbm_writes_lt_1ms":113,"reinsert_count":0,"update_count":550}
I20260812 06:17:11.925590 26772 maintenance_manager.cc:419] P e78892971ebf49c2bdf20115712ae7bd: Scheduling LogGCOp(d609d3ecd5a74d16b31521f4951e3187): free 8767174 bytes of WAL
I20260812 06:17:11.926044 26707 log_reader.cc:385] T d609d3ecd5a74d16b31521f4951e3187: removed 1 log segments from log reader
I20260812 06:17:11.926127 26707 log.cc:1079] T d609d3ecd5a74d16b31521f4951e3187 P e78892971ebf49c2bdf20115712ae7bd: Deleting log segment in path: /tmp/dist-test-taskdBxro6/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515429510153-26595-0/minicluster-data/ts-0-root/wals/d609d3ecd5a74d16b31521f4951e3187/wal-000000013 (ops 62-66)
I20260812 06:17:11.929224 26707 maintenance_manager.cc:643] P e78892971ebf49c2bdf20115712ae7bd: LogGCOp(d609d3ecd5a74d16b31521f4951e3187) complete. Timing: real 0.003s	user 0.000s	sys 0.003s Metrics: {}
I20260812 06:17:11.929790 26772 maintenance_manager.cc:419] P e78892971ebf49c2bdf20115712ae7bd: Scheduling FlushDeltaMemStoresOp(d609d3ecd5a74d16b31521f4951e3187): perf score=2.188937
I20260812 06:17:11.953452 26707 maintenance_manager.cc:643] P e78892971ebf49c2bdf20115712ae7bd: FlushDeltaMemStoresOp(d609d3ecd5a74d16b31521f4951e3187) complete. Timing: real 0.023s	user 0.015s	sys 0.008s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":7768,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:17:11.954605 26772 maintenance_manager.cc:419] P e78892971ebf49c2bdf20115712ae7bd: Scheduling MajorDeltaCompactionOp(d609d3ecd5a74d16b31521f4951e3187): perf score=1.000000
I20260812 06:17:12.290688 26707 maintenance_manager.cc:643] P e78892971ebf49c2bdf20115712ae7bd: MajorDeltaCompactionOp(d609d3ecd5a74d16b31521f4951e3187) complete. Timing: real 0.336s	user 0.201s	sys 0.132s Metrics: {"cfile_cache_miss":634,"cfile_cache_miss_bytes":28877322,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":917,"lbm_read_time_us":27627,"lbm_reads_lt_1ms":674,"lbm_write_time_us":63784,"lbm_writes_lt_1ms":643,"mutex_wait_us":20,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":896,"thread_start_us":371,"threads_started":6,"update_count":3000}
I20260812 06:17:12.291595 26772 maintenance_manager.cc:419] P e78892971ebf49c2bdf20115712ae7bd: Scheduling FlushDeltaMemStoresOp(d609d3ecd5a74d16b31521f4951e3187): perf score=16.079562
I20260812 06:17:12.353065 26707 maintenance_manager.cc:643] P e78892971ebf49c2bdf20115712ae7bd: FlushDeltaMemStoresOp(d609d3ecd5a74d16b31521f4951e3187) complete. Timing: real 0.061s	user 0.026s	sys 0.032s Metrics: {"bytes_written":17599603,"delete_count":0,"lbm_write_time_us":29797,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":431,"reinsert_count":0,"update_count":2145}
I20260812 06:17:12.353524 26772 maintenance_manager.cc:419] P e78892971ebf49c2bdf20115712ae7bd: Scheduling FlushDeltaMemStoresOp(d609d3ecd5a74d16b31521f4951e3187): perf score=2.188937
I20260812 06:17:12.364790 26707 maintenance_manager.cc:643] P e78892971ebf49c2bdf20115712ae7bd: FlushDeltaMemStoresOp(d609d3ecd5a74d16b31521f4951e3187) complete. Timing: real 0.011s	user 0.009s	sys 0.000s Metrics: {"bytes_written":3323184,"delete_count":0,"lbm_write_time_us":3337,"lbm_writes_lt_1ms":84,"reinsert_count":0,"update_count":405}
I20260812 06:17:12.365228 26772 maintenance_manager.cc:419] P e78892971ebf49c2bdf20115712ae7bd: Scheduling FlushDeltaMemStoresOp(d609d3ecd5a74d16b31521f4951e3187): perf score=2.188937
I20260812 06:17:12.374919 26707 maintenance_manager.cc:643] P e78892971ebf49c2bdf20115712ae7bd: FlushDeltaMemStoresOp(d609d3ecd5a74d16b31521f4951e3187) complete. Timing: real 0.010s	user 0.005s	sys 0.003s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3704,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:17:12.375396 26772 maintenance_manager.cc:419] P e78892971ebf49c2bdf20115712ae7bd: Scheduling MajorDeltaCompactionOp(d609d3ecd5a74d16b31521f4951e3187): perf score=1.000000
I20260812 06:17:12.575790 26707 maintenance_manager.cc:643] P e78892971ebf49c2bdf20115712ae7bd: MajorDeltaCompactionOp(d609d3ecd5a74d16b31521f4951e3187) complete. Timing: real 0.200s	user 0.128s	sys 0.072s Metrics: {"cfile_cache_miss":633,"cfile_cache_miss_bytes":28877192,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":220,"lbm_read_time_us":14793,"lbm_reads_lt_1ms":673,"lbm_write_time_us":35370,"lbm_writes_lt_1ms":643,"mutex_wait_us":21,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":13312,"update_count":3000}
I20260812 06:17:12.576707 26772 maintenance_manager.cc:419] P e78892971ebf49c2bdf20115712ae7bd: Scheduling FlushDeltaMemStoresOp(d609d3ecd5a74d16b31521f4951e3187): perf score=14.095187
I20260812 06:17:12.642937 26707 maintenance_manager.cc:643] P e78892971ebf49c2bdf20115712ae7bd: FlushDeltaMemStoresOp(d609d3ecd5a74d16b31521f4951e3187) complete. Timing: real 0.066s	user 0.015s	sys 0.037s Metrics: {"bytes_written":16409899,"delete_count":0,"lbm_write_time_us":25324,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:17:12.643517 26772 maintenance_manager.cc:419] P e78892971ebf49c2bdf20115712ae7bd: Scheduling FlushDeltaMemStoresOp(d609d3ecd5a74d16b31521f4951e3187): perf score=2.188937
I20260812 06:17:12.656569 26707 maintenance_manager.cc:643] P e78892971ebf49c2bdf20115712ae7bd: FlushDeltaMemStoresOp(d609d3ecd5a74d16b31521f4951e3187) complete. Timing: real 0.013s	user 0.005s	sys 0.007s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4809,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:12.657243 26772 maintenance_manager.cc:419] P e78892971ebf49c2bdf20115712ae7bd: Scheduling MajorDeltaCompactionOp(d609d3ecd5a74d16b31521f4951e3187): perf score=1.000000
I20260812 06:17:12.830879 26707 maintenance_manager.cc:643] P e78892971ebf49c2bdf20115712ae7bd: MajorDeltaCompactionOp(d609d3ecd5a74d16b31521f4951e3187) complete. Timing: real 0.173s	user 0.120s	sys 0.053s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774686,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":220,"lbm_read_time_us":12482,"lbm_reads_lt_1ms":572,"lbm_write_time_us":30410,"lbm_writes_lt_1ms":543,"mutex_wait_us":105,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":8704,"update_count":2500}
I20260812 06:17:12.831664 26772 maintenance_manager.cc:419] P e78892971ebf49c2bdf20115712ae7bd: Scheduling FlushDeltaMemStoresOp(d609d3ecd5a74d16b31521f4951e3187): perf score=14.095187
I20260812 06:17:12.885653 26707 maintenance_manager.cc:643] P e78892971ebf49c2bdf20115712ae7bd: FlushDeltaMemStoresOp(d609d3ecd5a74d16b31521f4951e3187) complete. Timing: real 0.054s	user 0.042s	sys 0.011s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":19573,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:17:12.886209 26772 maintenance_manager.cc:419] P e78892971ebf49c2bdf20115712ae7bd: Scheduling FlushDeltaMemStoresOp(d609d3ecd5a74d16b31521f4951e3187): perf score=2.188937
I20260812 06:17:12.897356 26707 maintenance_manager.cc:643] P e78892971ebf49c2bdf20115712ae7bd: FlushDeltaMemStoresOp(d609d3ecd5a74d16b31521f4951e3187) complete. Timing: real 0.011s	user 0.006s	sys 0.004s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4264,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:12.897804 26772 maintenance_manager.cc:419] P e78892971ebf49c2bdf20115712ae7bd: Scheduling MajorDeltaCompactionOp(d609d3ecd5a74d16b31521f4951e3187): perf score=1.000000
I20260812 06:17:13.079502 26707 maintenance_manager.cc:643] P e78892971ebf49c2bdf20115712ae7bd: MajorDeltaCompactionOp(d609d3ecd5a74d16b31521f4951e3187) complete. Timing: real 0.182s	user 0.126s	sys 0.052s 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":1148,"lbm_read_time_us":13222,"lbm_reads_lt_1ms":572,"lbm_write_time_us":31137,"lbm_writes_lt_1ms":543,"mutex_wait_us":342,"peak_mem_usage":63115900,"reinsert_count":0,"update_count":2500}
I20260812 06:17:13.079991 26772 maintenance_manager.cc:419] P e78892971ebf49c2bdf20115712ae7bd: Scheduling FlushDeltaMemStoresOp(d609d3ecd5a74d16b31521f4951e3187): perf score=11.118625
I20260812 06:17:13.127635 26707 maintenance_manager.cc:643] P e78892971ebf49c2bdf20115712ae7bd: FlushDeltaMemStoresOp(d609d3ecd5a74d16b31521f4951e3187) complete. Timing: real 0.047s	user 0.020s	sys 0.024s Metrics: {"bytes_written":12717735,"delete_count":0,"lbm_write_time_us":25720,"lbm_writes_1-10_ms":3,"lbm_writes_lt_1ms":310,"reinsert_count":0,"update_count":1550}
I20260812 06:17:13.128118 26772 maintenance_manager.cc:419] P e78892971ebf49c2bdf20115712ae7bd: Scheduling FlushDeltaMemStoresOp(d609d3ecd5a74d16b31521f4951e3187): perf score=2.188937
I20260812 06:17:13.140641 26707 maintenance_manager.cc:643] P e78892971ebf49c2bdf20115712ae7bd: FlushDeltaMemStoresOp(d609d3ecd5a74d16b31521f4951e3187) complete. Timing: real 0.012s	user 0.008s	sys 0.003s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":4375,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:17:13.141263 26772 maintenance_manager.cc:419] P e78892971ebf49c2bdf20115712ae7bd: Scheduling MajorDeltaCompactionOp(d609d3ecd5a74d16b31521f4951e3187): perf score=1.000000
I20260812 06:17:13.303309 26707 maintenance_manager.cc:643] P e78892971ebf49c2bdf20115712ae7bd: MajorDeltaCompactionOp(d609d3ecd5a74d16b31521f4951e3187) complete. Timing: real 0.162s	user 0.110s	sys 0.044s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672268,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":194,"lbm_read_time_us":11032,"lbm_reads_lt_1ms":464,"lbm_write_time_us":25382,"lbm_writes_lt_1ms":443,"mutex_wait_us":49,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":71040,"update_count":2000}
I20260812 06:17:13.303954 26772 maintenance_manager.cc:419] P e78892971ebf49c2bdf20115712ae7bd: Scheduling FlushDeltaMemStoresOp(d609d3ecd5a74d16b31521f4951e3187): perf score=14.095187
I20260812 06:17:13.355049 26707 maintenance_manager.cc:643] P e78892971ebf49c2bdf20115712ae7bd: FlushDeltaMemStoresOp(d609d3ecd5a74d16b31521f4951e3187) complete. Timing: real 0.051s	user 0.033s	sys 0.016s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":24187,"lbm_writes_1-10_ms":2,"lbm_writes_lt_1ms":401,"reinsert_count":0,"update_count":2000}
I20260812 06:17:13.355618 26772 maintenance_manager.cc:419] P e78892971ebf49c2bdf20115712ae7bd: Scheduling FlushDeltaMemStoresOp(d609d3ecd5a74d16b31521f4951e3187): perf score=2.188937
I20260812 06:17:13.370990 26707 maintenance_manager.cc:643] P e78892971ebf49c2bdf20115712ae7bd: FlushDeltaMemStoresOp(d609d3ecd5a74d16b31521f4951e3187) complete. Timing: real 0.015s	user 0.009s	sys 0.004s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":5588,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:13.371729 26772 maintenance_manager.cc:419] P e78892971ebf49c2bdf20115712ae7bd: Scheduling MajorDeltaCompactionOp(d609d3ecd5a74d16b31521f4951e3187): perf score=1.000000
I20260812 06:17:13.514948 26707 maintenance_manager.cc:643] P e78892971ebf49c2bdf20115712ae7bd: MajorDeltaCompactionOp(d609d3ecd5a74d16b31521f4951e3187) complete. Timing: real 0.143s	user 0.090s	sys 0.052s 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":140,"lbm_read_time_us":10131,"lbm_reads_lt_1ms":572,"lbm_write_time_us":29481,"lbm_writes_lt_1ms":543,"mutex_wait_us":50,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":1792,"update_count":2500}
I20260812 06:17:13.518304 26772 maintenance_manager.cc:419] P e78892971ebf49c2bdf20115712ae7bd: Scheduling FlushDeltaMemStoresOp(d609d3ecd5a74d16b31521f4951e3187): perf score=11.118625
I20260812 06:17:13.557920 26707 maintenance_manager.cc:643] P e78892971ebf49c2bdf20115712ae7bd: FlushDeltaMemStoresOp(d609d3ecd5a74d16b31521f4951e3187) complete. Timing: real 0.039s	user 0.022s	sys 0.016s Metrics: {"bytes_written":13045919,"delete_count":0,"lbm_write_time_us":17405,"lbm_writes_lt_1ms":321,"reinsert_count":0,"update_count":1590}
I20260812 06:17:13.558656 26772 maintenance_manager.cc:419] P e78892971ebf49c2bdf20115712ae7bd: Scheduling FlushDeltaMemStoresOp(d609d3ecd5a74d16b31521f4951e3187): perf score=2.188937
I20260812 06:17:13.579401 26707 maintenance_manager.cc:643] P e78892971ebf49c2bdf20115712ae7bd: FlushDeltaMemStoresOp(d609d3ecd5a74d16b31521f4951e3187) complete. Timing: real 0.021s	user 0.005s	sys 0.004s Metrics: {"bytes_written":3774459,"delete_count":0,"lbm_write_time_us":4210,"lbm_writes_lt_1ms":95,"reinsert_count":0,"update_count":460}
I20260812 06:17:13.579852 26772 maintenance_manager.cc:419] P e78892971ebf49c2bdf20115712ae7bd: Scheduling FlushDeltaMemStoresOp(d609d3ecd5a74d16b31521f4951e3187): perf score=2.188937
I20260812 06:17:13.589336 26707 maintenance_manager.cc:643] P e78892971ebf49c2bdf20115712ae7bd: FlushDeltaMemStoresOp(d609d3ecd5a74d16b31521f4951e3187) complete. Timing: real 0.009s	user 0.004s	sys 0.005s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3491,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:17:13.589800 26772 maintenance_manager.cc:419] P e78892971ebf49c2bdf20115712ae7bd: Scheduling FlushMRSOp(d609d3ecd5a74d16b31521f4951e3187): perf score=1.000000
I20260812 06:17:13.624291 26707 maintenance_manager.cc:643] P e78892971ebf49c2bdf20115712ae7bd: FlushMRSOp(d609d3ecd5a74d16b31521f4951e3187) complete. Timing: real 0.034s	user 0.031s	sys 0.002s Metrics: {"bytes_written":1275449,"cfile_init":1,"dirs.queue_time_us":71,"dirs.run_cpu_time_us":249,"dirs.run_wall_time_us":1399,"drs_written":1,"lbm_read_time_us":83,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1733,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":31}
I20260812 06:17:13.625228 26772 maintenance_manager.cc:419] P e78892971ebf49c2bdf20115712ae7bd: Scheduling LogGCOp(d609d3ecd5a74d16b31521f4951e3187): free 132571327 bytes of WAL
I20260812 06:17:13.625520 26707 log_reader.cc:385] T d609d3ecd5a74d16b31521f4951e3187: removed 13 log segments from log reader
I20260812 06:17:13.625597 26707 log.cc:1079] T d609d3ecd5a74d16b31521f4951e3187 P e78892971ebf49c2bdf20115712ae7bd: Deleting log segment in path: /tmp/dist-test-taskdBxro6/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515429510153-26595-0/minicluster-data/ts-0-root/wals/d609d3ecd5a74d16b31521f4951e3187/wal-000000014 (ops 67-70)
I20260812 06:17:13.625650 26707 log.cc:1079] T d609d3ecd5a74d16b31521f4951e3187 P e78892971ebf49c2bdf20115712ae7bd: Deleting log segment in path: /tmp/dist-test-taskdBxro6/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515429510153-26595-0/minicluster-data/ts-0-root/wals/d609d3ecd5a74d16b31521f4951e3187/wal-000000015 (ops 71-75)
I20260812 06:17:13.625710 26707 log.cc:1079] T d609d3ecd5a74d16b31521f4951e3187 P e78892971ebf49c2bdf20115712ae7bd: Deleting log segment in path: /tmp/dist-test-taskdBxro6/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515429510153-26595-0/minicluster-data/ts-0-root/wals/d609d3ecd5a74d16b31521f4951e3187/wal-000000016 (ops 76-80)
I20260812 06:17:13.625754 26707 log.cc:1079] T d609d3ecd5a74d16b31521f4951e3187 P e78892971ebf49c2bdf20115712ae7bd: Deleting log segment in path: /tmp/dist-test-taskdBxro6/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515429510153-26595-0/minicluster-data/ts-0-root/wals/d609d3ecd5a74d16b31521f4951e3187/wal-000000017 (ops 81-84)
I20260812 06:17:13.625793 26707 log.cc:1079] T d609d3ecd5a74d16b31521f4951e3187 P e78892971ebf49c2bdf20115712ae7bd: Deleting log segment in path: /tmp/dist-test-taskdBxro6/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515429510153-26595-0/minicluster-data/ts-0-root/wals/d609d3ecd5a74d16b31521f4951e3187/wal-000000018 (ops 85-89)
I20260812 06:17:13.625833 26707 log.cc:1079] T d609d3ecd5a74d16b31521f4951e3187 P e78892971ebf49c2bdf20115712ae7bd: Deleting log segment in path: /tmp/dist-test-taskdBxro6/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515429510153-26595-0/minicluster-data/ts-0-root/wals/d609d3ecd5a74d16b31521f4951e3187/wal-000000019 (ops 90-94)
I20260812 06:17:13.625874 26707 log.cc:1079] T d609d3ecd5a74d16b31521f4951e3187 P e78892971ebf49c2bdf20115712ae7bd: Deleting log segment in path: /tmp/dist-test-taskdBxro6/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515429510153-26595-0/minicluster-data/ts-0-root/wals/d609d3ecd5a74d16b31521f4951e3187/wal-000000020 (ops 95-99)
I20260812 06:17:13.625914 26707 log.cc:1079] T d609d3ecd5a74d16b31521f4951e3187 P e78892971ebf49c2bdf20115712ae7bd: Deleting log segment in path: /tmp/dist-test-taskdBxro6/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515429510153-26595-0/minicluster-data/ts-0-root/wals/d609d3ecd5a74d16b31521f4951e3187/wal-000000021 (ops 100-104)
I20260812 06:17:13.625954 26707 log.cc:1079] T d609d3ecd5a74d16b31521f4951e3187 P e78892971ebf49c2bdf20115712ae7bd: Deleting log segment in path: /tmp/dist-test-taskdBxro6/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515429510153-26595-0/minicluster-data/ts-0-root/wals/d609d3ecd5a74d16b31521f4951e3187/wal-000000022 (ops 105-109)
I20260812 06:17:13.625995 26707 log.cc:1079] T d609d3ecd5a74d16b31521f4951e3187 P e78892971ebf49c2bdf20115712ae7bd: Deleting log segment in path: /tmp/dist-test-taskdBxro6/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515429510153-26595-0/minicluster-data/ts-0-root/wals/d609d3ecd5a74d16b31521f4951e3187/wal-000000023 (ops 110-114)
I20260812 06:17:13.626041 26707 log.cc:1079] T d609d3ecd5a74d16b31521f4951e3187 P e78892971ebf49c2bdf20115712ae7bd: Deleting log segment in path: /tmp/dist-test-taskdBxro6/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515429510153-26595-0/minicluster-data/ts-0-root/wals/d609d3ecd5a74d16b31521f4951e3187/wal-000000024 (ops 115-119)
I20260812 06:17:13.626082 26707 log.cc:1079] T d609d3ecd5a74d16b31521f4951e3187 P e78892971ebf49c2bdf20115712ae7bd: Deleting log segment in path: /tmp/dist-test-taskdBxro6/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515429510153-26595-0/minicluster-data/ts-0-root/wals/d609d3ecd5a74d16b31521f4951e3187/wal-000000025 (ops 120-124)
I20260812 06:17:13.626122 26707 log.cc:1079] T d609d3ecd5a74d16b31521f4951e3187 P e78892971ebf49c2bdf20115712ae7bd: Deleting log segment in path: /tmp/dist-test-taskdBxro6/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515429510153-26595-0/minicluster-data/ts-0-root/wals/d609d3ecd5a74d16b31521f4951e3187/wal-000000026 (ops 125-129)
I20260812 06:17:13.656673 26707 maintenance_manager.cc:643] P e78892971ebf49c2bdf20115712ae7bd: LogGCOp(d609d3ecd5a74d16b31521f4951e3187) complete. Timing: real 0.031s	user 0.000s	sys 0.031s Metrics: {}
I20260812 06:17:13.657074 26772 maintenance_manager.cc:419] P e78892971ebf49c2bdf20115712ae7bd: Scheduling UndoDeltaBlockGCOp(d609d3ecd5a74d16b31521f4951e3187): 481 bytes on disk
I20260812 06:17:13.657820 26707 maintenance_manager.cc:643] P e78892971ebf49c2bdf20115712ae7bd: UndoDeltaBlockGCOp(d609d3ecd5a74d16b31521f4951e3187) complete. Timing: real 0.001s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":66,"lbm_reads_lt_1ms":4}
I20260812 06:17:13.658483 26772 maintenance_manager.cc:419] P e78892971ebf49c2bdf20115712ae7bd: Scheduling FlushDeltaMemStoresOp(d609d3ecd5a74d16b31521f4951e3187): perf score=3.181125
I20260812 06:17:13.672955 26707 maintenance_manager.cc:643] P e78892971ebf49c2bdf20115712ae7bd: FlushDeltaMemStoresOp(d609d3ecd5a74d16b31521f4951e3187) complete. Timing: real 0.014s	user 0.012s	sys 0.001s Metrics: {"bytes_written":4677001,"delete_count":0,"lbm_write_time_us":5767,"lbm_writes_lt_1ms":117,"reinsert_count":0,"update_count":570}
I20260812 06:17:13.673370 26772 maintenance_manager.cc:419] P e78892971ebf49c2bdf20115712ae7bd: Scheduling FlushDeltaMemStoresOp(d609d3ecd5a74d16b31521f4951e3187): perf score=2.188937
I20260812 06:17:13.693032 26707 maintenance_manager.cc:643] P e78892971ebf49c2bdf20115712ae7bd: FlushDeltaMemStoresOp(d609d3ecd5a74d16b31521f4951e3187) complete. Timing: real 0.019s	user 0.004s	sys 0.015s Metrics: {"bytes_written":3528305,"delete_count":0,"lbm_write_time_us":3449,"lbm_writes_lt_1ms":89,"reinsert_count":0,"update_count":430}
I20260812 06:17:13.693497 26772 maintenance_manager.cc:419] P e78892971ebf49c2bdf20115712ae7bd: Scheduling MajorDeltaCompactionOp(d609d3ecd5a74d16b31521f4951e3187): perf score=1.000000
I20260812 06:17:13.931851 26707 maintenance_manager.cc:643] P e78892971ebf49c2bdf20115712ae7bd: MajorDeltaCompactionOp(d609d3ecd5a74d16b31521f4951e3187) complete. Timing: real 0.238s	user 0.155s	sys 0.077s Metrics: {"cfile_cache_miss":735,"cfile_cache_miss_bytes":32979833,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":5,"delta_iterators_relevant":5,"dirs.queue_time_us":492,"lbm_read_time_us":15591,"lbm_reads_lt_1ms":775,"lbm_write_time_us":41119,"lbm_writes_lt_1ms":743,"mutex_wait_us":19,"peak_mem_usage":87969044,"reinsert_count":0,"spinlock_wait_cycles":9728,"thread_start_us":76,"threads_started":1,"update_count":3500}
I20260812 06:17:13.934628 26772 maintenance_manager.cc:419] P e78892971ebf49c2bdf20115712ae7bd: Scheduling FlushDeltaMemStoresOp(d609d3ecd5a74d16b31521f4951e3187): perf score=15.087375
I20260812 06:17:13.985466 26707 maintenance_manager.cc:643] P e78892971ebf49c2bdf20115712ae7bd: FlushDeltaMemStoresOp(d609d3ecd5a74d16b31521f4951e3187) complete. Timing: real 0.051s	user 0.023s	sys 0.016s Metrics: {"bytes_written":16820148,"delete_count":0,"lbm_write_time_us":17663,"lbm_writes_lt_1ms":413,"reinsert_count":0,"update_count":2050}
I20260812 06:17:13.986011 26772 maintenance_manager.cc:419] P e78892971ebf49c2bdf20115712ae7bd: Scheduling FlushDeltaMemStoresOp(d609d3ecd5a74d16b31521f4951e3187): perf score=2.188937
I20260812 06:17:14.006255 26707 maintenance_manager.cc:643] P e78892971ebf49c2bdf20115712ae7bd: FlushDeltaMemStoresOp(d609d3ecd5a74d16b31521f4951e3187) complete. Timing: real 0.020s	user 0.011s	sys 0.003s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6721,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:14.006716 26772 maintenance_manager.cc:419] P e78892971ebf49c2bdf20115712ae7bd: Scheduling FlushDeltaMemStoresOp(d609d3ecd5a74d16b31521f4951e3187): perf score=2.188937
I20260812 06:17:14.016670 26707 maintenance_manager.cc:643] P e78892971ebf49c2bdf20115712ae7bd: FlushDeltaMemStoresOp(d609d3ecd5a74d16b31521f4951e3187) complete. Timing: real 0.010s	user 0.006s	sys 0.003s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3932,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:17:14.017184 26772 maintenance_manager.cc:419] P e78892971ebf49c2bdf20115712ae7bd: Scheduling MajorDeltaCompactionOp(d609d3ecd5a74d16b31521f4951e3187): perf score=1.000000
I20260812 06:17:14.218046 26707 maintenance_manager.cc:643] P e78892971ebf49c2bdf20115712ae7bd: MajorDeltaCompactionOp(d609d3ecd5a74d16b31521f4951e3187) complete. Timing: real 0.201s	user 0.125s	sys 0.076s Metrics: {"cfile_cache_miss":633,"cfile_cache_miss_bytes":28877212,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":217,"lbm_read_time_us":14533,"lbm_reads_lt_1ms":673,"lbm_write_time_us":32595,"lbm_writes_lt_1ms":643,"mutex_wait_us":85,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":3456,"update_count":3000}
I20260812 06:17:14.220914 26772 maintenance_manager.cc:419] P e78892971ebf49c2bdf20115712ae7bd: Scheduling FlushDeltaMemStoresOp(d609d3ecd5a74d16b31521f4951e3187): perf score=14.095187
I20260812 06:17:14.297631 26707 maintenance_manager.cc:643] P e78892971ebf49c2bdf20115712ae7bd: FlushDeltaMemStoresOp(d609d3ecd5a74d16b31521f4951e3187) complete. Timing: real 0.065s	user 0.040s	sys 0.013s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":23776,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:17:14.298247 26772 maintenance_manager.cc:419] P e78892971ebf49c2bdf20115712ae7bd: Scheduling FlushDeltaMemStoresOp(d609d3ecd5a74d16b31521f4951e3187): perf score=2.188937
I20260812 06:17:14.313695 26707 maintenance_manager.cc:643] P e78892971ebf49c2bdf20115712ae7bd: FlushDeltaMemStoresOp(d609d3ecd5a74d16b31521f4951e3187) complete. Timing: real 0.015s	user 0.014s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5704,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:14.314214 26772 maintenance_manager.cc:419] P e78892971ebf49c2bdf20115712ae7bd: Scheduling MajorDeltaCompactionOp(d609d3ecd5a74d16b31521f4951e3187): perf score=1.000000
I20260812 06:17:14.502898 26707 maintenance_manager.cc:643] P e78892971ebf49c2bdf20115712ae7bd: MajorDeltaCompactionOp(d609d3ecd5a74d16b31521f4951e3187) complete. Timing: real 0.188s	user 0.112s	sys 0.066s 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":171,"lbm_read_time_us":13589,"lbm_reads_lt_1ms":572,"lbm_write_time_us":32018,"lbm_writes_lt_1ms":543,"mutex_wait_us":82,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":13312,"update_count":2500}
I20260812 06:17:14.503580 26772 maintenance_manager.cc:419] P e78892971ebf49c2bdf20115712ae7bd: Scheduling FlushDeltaMemStoresOp(d609d3ecd5a74d16b31521f4951e3187): perf score=14.095187
I20260812 06:17:14.558234 26707 maintenance_manager.cc:643] P e78892971ebf49c2bdf20115712ae7bd: FlushDeltaMemStoresOp(d609d3ecd5a74d16b31521f4951e3187) complete. Timing: real 0.054s	user 0.021s	sys 0.031s Metrics: {"bytes_written":16409904,"delete_count":0,"lbm_write_time_us":26347,"lbm_writes_1-10_ms":2,"lbm_writes_lt_1ms":401,"reinsert_count":0,"update_count":2000}
I20260812 06:17:14.558792 26772 maintenance_manager.cc:419] P e78892971ebf49c2bdf20115712ae7bd: Scheduling FlushDeltaMemStoresOp(d609d3ecd5a74d16b31521f4951e3187): perf score=2.188937
I20260812 06:17:14.572122 26707 maintenance_manager.cc:643] P e78892971ebf49c2bdf20115712ae7bd: FlushDeltaMemStoresOp(d609d3ecd5a74d16b31521f4951e3187) complete. Timing: real 0.013s	user 0.011s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4760,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:14.572716 26772 maintenance_manager.cc:419] P e78892971ebf49c2bdf20115712ae7bd: Scheduling MajorDeltaCompactionOp(d609d3ecd5a74d16b31521f4951e3187): perf score=1.000000
I20260812 06:17:14.763790 26707 maintenance_manager.cc:643] P e78892971ebf49c2bdf20115712ae7bd: MajorDeltaCompactionOp(d609d3ecd5a74d16b31521f4951e3187) complete. Timing: real 0.191s	user 0.150s	sys 0.029s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774691,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":523,"lbm_read_time_us":12605,"lbm_reads_lt_1ms":564,"lbm_write_time_us":29978,"lbm_writes_lt_1ms":543,"mutex_wait_us":53,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":8960,"update_count":2500}
I20260812 06:17:14.764586 26772 maintenance_manager.cc:419] P e78892971ebf49c2bdf20115712ae7bd: Scheduling FlushDeltaMemStoresOp(d609d3ecd5a74d16b31521f4951e3187): perf score=11.118625
I20260812 06:17:14.833832 26707 maintenance_manager.cc:643] P e78892971ebf49c2bdf20115712ae7bd: FlushDeltaMemStoresOp(d609d3ecd5a74d16b31521f4951e3187) complete. Timing: real 0.069s	user 0.030s	sys 0.036s Metrics: {"bytes_written":12717735,"delete_count":0,"lbm_write_time_us":27162,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":312,"reinsert_count":0,"update_count":1550}
I20260812 06:17:14.834494 26772 maintenance_manager.cc:419] P e78892971ebf49c2bdf20115712ae7bd: Scheduling FlushDeltaMemStoresOp(d609d3ecd5a74d16b31521f4951e3187): perf score=6.157687
I20260812 06:17:14.853011 26707 maintenance_manager.cc:643] P e78892971ebf49c2bdf20115712ae7bd: FlushDeltaMemStoresOp(d609d3ecd5a74d16b31521f4951e3187) complete. Timing: real 0.018s	user 0.010s	sys 0.008s Metrics: {"bytes_written":7794838,"delete_count":0,"lbm_write_time_us":8132,"lbm_writes_lt_1ms":193,"reinsert_count":0,"update_count":950}
I20260812 06:17:14.853695 26772 maintenance_manager.cc:419] P e78892971ebf49c2bdf20115712ae7bd: Scheduling MajorDeltaCompactionOp(d609d3ecd5a74d16b31521f4951e3187): perf score=1.000000
I20260812 06:17:15.047068 26707 maintenance_manager.cc:643] P e78892971ebf49c2bdf20115712ae7bd: MajorDeltaCompactionOp(d609d3ecd5a74d16b31521f4951e3187) complete. Timing: real 0.193s	user 0.122s	sys 0.067s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774695,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":196,"lbm_read_time_us":12680,"lbm_reads_lt_1ms":572,"lbm_write_time_us":34209,"lbm_writes_lt_1ms":543,"mutex_wait_us":46,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":2816,"update_count":2500}
I20260812 06:17:15.047787 26772 maintenance_manager.cc:419] P e78892971ebf49c2bdf20115712ae7bd: Scheduling FlushDeltaMemStoresOp(d609d3ecd5a74d16b31521f4951e3187): perf score=10.126437
I20260812 06:17:15.082816 26707 maintenance_manager.cc:643] P e78892971ebf49c2bdf20115712ae7bd: FlushDeltaMemStoresOp(d609d3ecd5a74d16b31521f4951e3187) complete. Timing: real 0.035s	user 0.019s	sys 0.011s Metrics: {"bytes_written":12307491,"delete_count":0,"lbm_write_time_us":14174,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:17:15.083360 26772 maintenance_manager.cc:419] P e78892971ebf49c2bdf20115712ae7bd: Scheduling MajorDeltaCompactionOp(d609d3ecd5a74d16b31521f4951e3187): perf score=1.000000
I20260812 06:17:15.192276 26707 maintenance_manager.cc:643] P e78892971ebf49c2bdf20115712ae7bd: MajorDeltaCompactionOp(d609d3ecd5a74d16b31521f4951e3187) complete. Timing: real 0.109s	user 0.090s	sys 0.017s Metrics: {"cfile_cache_miss":331,"cfile_cache_miss_bytes":16569747,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":1,"delta_iterators_relevant":1,"dirs.queue_time_us":1163,"lbm_read_time_us":7240,"lbm_reads_lt_1ms":363,"lbm_write_time_us":19453,"lbm_writes_lt_1ms":343,"mutex_wait_us":300,"peak_mem_usage":38262756,"reinsert_count":0,"spinlock_wait_cycles":768,"update_count":1500}
I20260812 06:17:15.192953 26772 maintenance_manager.cc:419] P e78892971ebf49c2bdf20115712ae7bd: Scheduling FlushDeltaMemStoresOp(d609d3ecd5a74d16b31521f4951e3187): perf score=10.126437
I20260812 06:17:15.238627 26707 maintenance_manager.cc:643] P e78892971ebf49c2bdf20115712ae7bd: FlushDeltaMemStoresOp(d609d3ecd5a74d16b31521f4951e3187) complete. Timing: real 0.045s	user 0.020s	sys 0.012s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":14654,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:17:15.239214 26772 maintenance_manager.cc:419] P e78892971ebf49c2bdf20115712ae7bd: Scheduling FlushDeltaMemStoresOp(d609d3ecd5a74d16b31521f4951e3187): perf score=2.188937
I20260812 06:17:15.249898 26707 maintenance_manager.cc:643] P e78892971ebf49c2bdf20115712ae7bd: FlushDeltaMemStoresOp(d609d3ecd5a74d16b31521f4951e3187) complete. Timing: real 0.010s	user 0.005s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3876,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:15.250765 26772 maintenance_manager.cc:419] P e78892971ebf49c2bdf20115712ae7bd: Scheduling FlushMRSOp(d609d3ecd5a74d16b31521f4951e3187): perf score=1.000000
I20260812 06:17:15.281030 26707 maintenance_manager.cc:643] P e78892971ebf49c2bdf20115712ae7bd: FlushMRSOp(d609d3ecd5a74d16b31521f4951e3187) complete. Timing: real 0.030s	user 0.029s	sys 0.000s Metrics: {"bytes_written":1234477,"cfile_init":1,"dirs.queue_time_us":64,"dirs.run_cpu_time_us":222,"dirs.run_wall_time_us":1536,"drs_written":1,"lbm_read_time_us":39,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1949,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":30}
I20260812 06:17:15.281680 26772 maintenance_manager.cc:419] P e78892971ebf49c2bdf20115712ae7bd: Scheduling LogGCOp(d609d3ecd5a74d16b31521f4951e3187): free 120553646 bytes of WAL
I20260812 06:17:15.281910 26707 log_reader.cc:385] T d609d3ecd5a74d16b31521f4951e3187: removed 12 log segments from log reader
I20260812 06:17:15.281960 26707 log.cc:1079] T d609d3ecd5a74d16b31521f4951e3187 P e78892971ebf49c2bdf20115712ae7bd: Deleting log segment in path: /tmp/dist-test-taskdBxro6/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515429510153-26595-0/minicluster-data/ts-0-root/wals/d609d3ecd5a74d16b31521f4951e3187/wal-000000027 (ops 130-134)
I20260812 06:17:15.281989 26707 log.cc:1079] T d609d3ecd5a74d16b31521f4951e3187 P e78892971ebf49c2bdf20115712ae7bd: Deleting log segment in path: /tmp/dist-test-taskdBxro6/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515429510153-26595-0/minicluster-data/ts-0-root/wals/d609d3ecd5a74d16b31521f4951e3187/wal-000000028 (ops 135-139)
I20260812 06:17:15.282049 26707 log.cc:1079] T d609d3ecd5a74d16b31521f4951e3187 P e78892971ebf49c2bdf20115712ae7bd: Deleting log segment in path: /tmp/dist-test-taskdBxro6/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515429510153-26595-0/minicluster-data/ts-0-root/wals/d609d3ecd5a74d16b31521f4951e3187/wal-000000029 (ops 140-144)
I20260812 06:17:15.282115 26707 log.cc:1079] T d609d3ecd5a74d16b31521f4951e3187 P e78892971ebf49c2bdf20115712ae7bd: Deleting log segment in path: /tmp/dist-test-taskdBxro6/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515429510153-26595-0/minicluster-data/ts-0-root/wals/d609d3ecd5a74d16b31521f4951e3187/wal-000000030 (ops 145-148)
I20260812 06:17:15.282178 26707 log.cc:1079] T d609d3ecd5a74d16b31521f4951e3187 P e78892971ebf49c2bdf20115712ae7bd: Deleting log segment in path: /tmp/dist-test-taskdBxro6/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515429510153-26595-0/minicluster-data/ts-0-root/wals/d609d3ecd5a74d16b31521f4951e3187/wal-000000031 (ops 149-153)
I20260812 06:17:15.282222 26707 log.cc:1079] T d609d3ecd5a74d16b31521f4951e3187 P e78892971ebf49c2bdf20115712ae7bd: Deleting log segment in path: /tmp/dist-test-taskdBxro6/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515429510153-26595-0/minicluster-data/ts-0-root/wals/d609d3ecd5a74d16b31521f4951e3187/wal-000000032 (ops 154-158)
I20260812 06:17:15.282262 26707 log.cc:1079] T d609d3ecd5a74d16b31521f4951e3187 P e78892971ebf49c2bdf20115712ae7bd: Deleting log segment in path: /tmp/dist-test-taskdBxro6/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515429510153-26595-0/minicluster-data/ts-0-root/wals/d609d3ecd5a74d16b31521f4951e3187/wal-000000033 (ops 159-163)
I20260812 06:17:15.282301 26707 log.cc:1079] T d609d3ecd5a74d16b31521f4951e3187 P e78892971ebf49c2bdf20115712ae7bd: Deleting log segment in path: /tmp/dist-test-taskdBxro6/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515429510153-26595-0/minicluster-data/ts-0-root/wals/d609d3ecd5a74d16b31521f4951e3187/wal-000000034 (ops 164-168)
I20260812 06:17:15.282341 26707 log.cc:1079] T d609d3ecd5a74d16b31521f4951e3187 P e78892971ebf49c2bdf20115712ae7bd: Deleting log segment in path: /tmp/dist-test-taskdBxro6/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515429510153-26595-0/minicluster-data/ts-0-root/wals/d609d3ecd5a74d16b31521f4951e3187/wal-000000035 (ops 169-172)
I20260812 06:17:15.282377 26707 log.cc:1079] T d609d3ecd5a74d16b31521f4951e3187 P e78892971ebf49c2bdf20115712ae7bd: Deleting log segment in path: /tmp/dist-test-taskdBxro6/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515429510153-26595-0/minicluster-data/ts-0-root/wals/d609d3ecd5a74d16b31521f4951e3187/wal-000000036 (ops 173-177)
I20260812 06:17:15.282415 26707 log.cc:1079] T d609d3ecd5a74d16b31521f4951e3187 P e78892971ebf49c2bdf20115712ae7bd: Deleting log segment in path: /tmp/dist-test-taskdBxro6/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515429510153-26595-0/minicluster-data/ts-0-root/wals/d609d3ecd5a74d16b31521f4951e3187/wal-000000037 (ops 178-182)
I20260812 06:17:15.282460 26707 log.cc:1079] T d609d3ecd5a74d16b31521f4951e3187 P e78892971ebf49c2bdf20115712ae7bd: Deleting log segment in path: /tmp/dist-test-taskdBxro6/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515429510153-26595-0/minicluster-data/ts-0-root/wals/d609d3ecd5a74d16b31521f4951e3187/wal-000000038 (ops 183-187)
I20260812 06:17:15.308627 26707 maintenance_manager.cc:643] P e78892971ebf49c2bdf20115712ae7bd: LogGCOp(d609d3ecd5a74d16b31521f4951e3187) complete. Timing: real 0.027s	user 0.004s	sys 0.022s Metrics: {}
I20260812 06:17:15.309127 26772 maintenance_manager.cc:419] P e78892971ebf49c2bdf20115712ae7bd: Scheduling UndoDeltaBlockGCOp(d609d3ecd5a74d16b31521f4951e3187): 472 bytes on disk
I20260812 06:17:15.309689 26707 maintenance_manager.cc:643] P e78892971ebf49c2bdf20115712ae7bd: UndoDeltaBlockGCOp(d609d3ecd5a74d16b31521f4951e3187) 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:17:15.310352 26772 maintenance_manager.cc:419] P e78892971ebf49c2bdf20115712ae7bd: Scheduling FlushDeltaMemStoresOp(d609d3ecd5a74d16b31521f4951e3187): perf score=3.181125
I20260812 06:17:15.323917 26707 maintenance_manager.cc:643] P e78892971ebf49c2bdf20115712ae7bd: FlushDeltaMemStoresOp(d609d3ecd5a74d16b31521f4951e3187) complete. Timing: real 0.013s	user 0.008s	sys 0.004s Metrics: {"bytes_written":5251342,"delete_count":0,"lbm_write_time_us":5530,"lbm_writes_lt_1ms":131,"mutex_wait_us":54,"reinsert_count":0,"update_count":640}
I20260812 06:17:15.324420 26772 maintenance_manager.cc:419] P e78892971ebf49c2bdf20115712ae7bd: Scheduling FlushDeltaMemStoresOp(d609d3ecd5a74d16b31521f4951e3187): perf score=1.196750
I20260812 06:17:15.334731 26707 maintenance_manager.cc:643] P e78892971ebf49c2bdf20115712ae7bd: FlushDeltaMemStoresOp(d609d3ecd5a74d16b31521f4951e3187) complete. Timing: real 0.010s	user 0.007s	sys 0.001s Metrics: {"bytes_written":2953955,"delete_count":0,"lbm_write_time_us":3218,"lbm_writes_lt_1ms":75,"reinsert_count":0,"update_count":360}
I20260812 06:17:15.335255 26772 maintenance_manager.cc:419] P e78892971ebf49c2bdf20115712ae7bd: Scheduling MajorDeltaCompactionOp(d609d3ecd5a74d16b31521f4951e3187): perf score=1.000000
I20260812 06:17:15.514532 26707 maintenance_manager.cc:643] P e78892971ebf49c2bdf20115712ae7bd: MajorDeltaCompactionOp(d609d3ecd5a74d16b31521f4951e3187) complete. Timing: real 0.179s	user 0.143s	sys 0.036s Metrics: {"cfile_cache_miss":634,"cfile_cache_miss_bytes":28877312,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":239,"lbm_read_time_us":13138,"lbm_reads_lt_1ms":666,"lbm_write_time_us":37059,"lbm_writes_lt_1ms":643,"mutex_wait_us":20,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":8576,"thread_start_us":78,"threads_started":1,"update_count":3000}
I20260812 06:17:15.515268 26772 maintenance_manager.cc:419] P e78892971ebf49c2bdf20115712ae7bd: Scheduling FlushDeltaMemStoresOp(d609d3ecd5a74d16b31521f4951e3187): perf score=14.095187
I20260812 06:17:15.564071 26595 heavy-update-compaction-itest.cc:229] Time spent updating: real 5.786s	user 2.047s	sys 0.166s
I20260812 06:17:15.567408 26707 maintenance_manager.cc:643] P e78892971ebf49c2bdf20115712ae7bd: FlushDeltaMemStoresOp(d609d3ecd5a74d16b31521f4951e3187) complete. Timing: real 0.052s	user 0.034s	sys 0.008s Metrics: {"bytes_written":16409903,"delete_count":0,"lbm_write_time_us":19198,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:17:15.567873 26772 maintenance_manager.cc:419] P e78892971ebf49c2bdf20115712ae7bd: Scheduling FlushDeltaMemStoresOp(d609d3ecd5a74d16b31521f4951e3187): perf score=2.188937
I20260812 06:17:15.578500 26707 maintenance_manager.cc:643] P e78892971ebf49c2bdf20115712ae7bd: FlushDeltaMemStoresOp(d609d3ecd5a74d16b31521f4951e3187) complete. Timing: real 0.010s	user 0.006s	sys 0.003s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4440,"lbm_writes_lt_1ms":103,"reinsert_count":0,"spinlock_wait_cycles":768,"update_count":500}
I20260812 06:17:15.578940 26772 maintenance_manager.cc:419] P e78892971ebf49c2bdf20115712ae7bd: Scheduling MajorDeltaCompactionOp(d609d3ecd5a74d16b31521f4951e3187): perf score=1.000000
I20260812 06:17:15.608634 26595 heavy-update-compaction-itest.cc:265] Time spent scanning: real 0.044s	user 0.003s	sys 0.000s
I20260812 06:17:15.609269 26595 tablet_server.cc:179] TabletServer@127.25.248.193:0 shutting down...
I20260812 06:17:15.696357 26707 maintenance_manager.cc:643] P e78892971ebf49c2bdf20115712ae7bd: MajorDeltaCompactionOp(d609d3ecd5a74d16b31521f4951e3187) complete. Timing: real 0.117s	user 0.088s	sys 0.028s Metrics: {"cfile_cache_hit":400,"cfile_cache_hit_bytes":16368758,"cfile_cache_miss":132,"cfile_cache_miss_bytes":8405932,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":944,"lbm_read_time_us":3427,"lbm_reads_lt_1ms":164,"lbm_write_time_us":26842,"lbm_writes_lt_1ms":543,"mutex_wait_us":86,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":20864,"update_count":2500}
I20260812 06:17:15.697160 26595 ts_tablet_manager.cc:1507] Shutting down tablet manager...
I20260812 06:17:15.697665 26595 tablet_replica.cc:333] T d609d3ecd5a74d16b31521f4951e3187 P e78892971ebf49c2bdf20115712ae7bd: stopping tablet replica
I20260812 06:17:15.697923 26595 raft_consensus.cc:2243] T d609d3ecd5a74d16b31521f4951e3187 P e78892971ebf49c2bdf20115712ae7bd [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:17:15.698181 26595 raft_consensus.cc:2272] T d609d3ecd5a74d16b31521f4951e3187 P e78892971ebf49c2bdf20115712ae7bd [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:17:15.714704 26595 tablet_server.cc:196] TabletServer@127.25.248.193:0 shutdown complete.
I20260812 06:17:15.743644 26595 master.cc:562] Master@127.25.248.254:45537 shutting down...
I20260812 06:17:15.747823 26595 raft_consensus.cc:2243] T 00000000000000000000000000000000 P 89f4295528e048f193944e5c532f1eb0 [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:17:15.747982 26595 raft_consensus.cc:2272] T 00000000000000000000000000000000 P 89f4295528e048f193944e5c532f1eb0 [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:17:15.748042 26595 tablet_replica.cc:333] T 00000000000000000000000000000000 P 89f4295528e048f193944e5c532f1eb0: stopping tablet replica
I20260812 06:17:15.760625 26595 master.cc:584] Master@127.25.248.254:45537 shutdown complete.
[       OK ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/0 (6330 ms)
[ RUN      ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/1
I20260812 06:17:15.861382 26595 internal_mini_cluster.cc:156] Creating distributed mini masters. Addrs: 127.25.248.254:37567
I20260812 06:17:15.861832 26595 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:17:15.864243 26813 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:17:15.864243 26816 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:17:15.864349 26595 server_base.cc:1061] running on GCE node
W20260812 06:17:15.864511 26814 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:17:15.864751 26595 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:17:15.864820 26595 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:17:15.864845 26595 hybrid_clock.cc:648] HybridClock initialized: now 1786515435864845 us; error 0 us; skew 500 ppm
I20260812 06:17:15.865757 26595 webserver.cc:533] Webserver started at http://127.25.248.254:45327/ using document root <none> and password file <none>
I20260812 06:17:15.865970 26595 fs_manager.cc:362] Metadata directory not provided
I20260812 06:17:15.866050 26595 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:17:15.866135 26595 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:17:15.866577 26595 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskdBxro6/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515429510153-26595-0/minicluster-data/master-0-root/instance:
uuid: "b047e9968d9249bb8dcab814b541180f"
format_stamp: "Formatted at 2026-08-12 06:17:15 on dist-test-slave-10pc"
I20260812 06:17:15.868147 26595 fs_manager.cc:696] Time spent creating directory manager: real 0.001s	user 0.000s	sys 0.002s
I20260812 06:17:15.869218 26822 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:17:15.869472 26595 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.000s	sys 0.001s
I20260812 06:17:15.869565 26595 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskdBxro6/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515429510153-26595-0/minicluster-data/master-0-root
uuid: "b047e9968d9249bb8dcab814b541180f"
format_stamp: "Formatted at 2026-08-12 06:17:15 on dist-test-slave-10pc"
I20260812 06:17:15.869655 26595 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskdBxro6/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515429510153-26595-0/minicluster-data/master-0-root
metadata directory: /tmp/dist-test-taskdBxro6/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515429510153-26595-0/minicluster-data/master-0-root
1 data directories: /tmp/dist-test-taskdBxro6/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515429510153-26595-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:17:15.880976 26595 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:17:15.881364 26595 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:17:15.885812 26595 rpc_server.cc:307] RPC server started. Bound to: 127.25.248.254:37567
I20260812 06:17:15.887384 26881 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.25.248.254:37567 every 8 connection(s)
I20260812 06:17:15.892757 26882 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:17:15.894737 26882 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P b047e9968d9249bb8dcab814b541180f: Bootstrap starting.
I20260812 06:17:15.895541 26882 tablet_bootstrap.cc:654] T 00000000000000000000000000000000 P b047e9968d9249bb8dcab814b541180f: Neither blocks nor log segments found. Creating new log.
I20260812 06:17:15.896605 26882 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P b047e9968d9249bb8dcab814b541180f: No bootstrap required, opened a new log
I20260812 06:17:15.897001 26882 raft_consensus.cc:359] T 00000000000000000000000000000000 P b047e9968d9249bb8dcab814b541180f [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "b047e9968d9249bb8dcab814b541180f" member_type: VOTER }
I20260812 06:17:15.897094 26882 raft_consensus.cc:385] T 00000000000000000000000000000000 P b047e9968d9249bb8dcab814b541180f [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:17:15.897162 26882 raft_consensus.cc:740] T 00000000000000000000000000000000 P b047e9968d9249bb8dcab814b541180f [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: b047e9968d9249bb8dcab814b541180f, State: Initialized, Role: FOLLOWER
I20260812 06:17:15.897327 26882 consensus_queue.cc:260] T 00000000000000000000000000000000 P b047e9968d9249bb8dcab814b541180f [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: "b047e9968d9249bb8dcab814b541180f" member_type: VOTER }
I20260812 06:17:15.897397 26882 raft_consensus.cc:399] T 00000000000000000000000000000000 P b047e9968d9249bb8dcab814b541180f [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:17:15.897469 26882 raft_consensus.cc:493] T 00000000000000000000000000000000 P b047e9968d9249bb8dcab814b541180f [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:17:15.897531 26882 raft_consensus.cc:3060] T 00000000000000000000000000000000 P b047e9968d9249bb8dcab814b541180f [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:17:15.898200 26882 raft_consensus.cc:515] T 00000000000000000000000000000000 P b047e9968d9249bb8dcab814b541180f [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "b047e9968d9249bb8dcab814b541180f" member_type: VOTER }
I20260812 06:17:15.898344 26882 leader_election.cc:304] T 00000000000000000000000000000000 P b047e9968d9249bb8dcab814b541180f [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: b047e9968d9249bb8dcab814b541180f; no voters: 
I20260812 06:17:15.898561 26882 leader_election.cc:290] T 00000000000000000000000000000000 P b047e9968d9249bb8dcab814b541180f [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:17:15.898675 26885 raft_consensus.cc:2804] T 00000000000000000000000000000000 P b047e9968d9249bb8dcab814b541180f [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:17:15.898931 26885 raft_consensus.cc:697] T 00000000000000000000000000000000 P b047e9968d9249bb8dcab814b541180f [term 1 LEADER]: Becoming Leader. State: Replica: b047e9968d9249bb8dcab814b541180f, State: Running, Role: LEADER
I20260812 06:17:15.899001 26882 sys_catalog.cc:565] T 00000000000000000000000000000000 P b047e9968d9249bb8dcab814b541180f [sys.catalog]: configured and running, proceeding with master startup.
I20260812 06:17:15.899098 26885 consensus_queue.cc:237] T 00000000000000000000000000000000 P b047e9968d9249bb8dcab814b541180f [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: "b047e9968d9249bb8dcab814b541180f" member_type: VOTER }
I20260812 06:17:15.899550 26886 sys_catalog.cc:455] T 00000000000000000000000000000000 P b047e9968d9249bb8dcab814b541180f [sys.catalog]: SysCatalogTable state changed. Reason: RaftConsensus started. Latest consensus state: current_term: 1 leader_uuid: "b047e9968d9249bb8dcab814b541180f" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "b047e9968d9249bb8dcab814b541180f" member_type: VOTER } }
I20260812 06:17:15.899592 26887 sys_catalog.cc:455] T 00000000000000000000000000000000 P b047e9968d9249bb8dcab814b541180f [sys.catalog]: SysCatalogTable state changed. Reason: New leader b047e9968d9249bb8dcab814b541180f. Latest consensus state: current_term: 1 leader_uuid: "b047e9968d9249bb8dcab814b541180f" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "b047e9968d9249bb8dcab814b541180f" member_type: VOTER } }
I20260812 06:17:15.899662 26886 sys_catalog.cc:458] T 00000000000000000000000000000000 P b047e9968d9249bb8dcab814b541180f [sys.catalog]: This master's current role is: LEADER
I20260812 06:17:15.899689 26887 sys_catalog.cc:458] T 00000000000000000000000000000000 P b047e9968d9249bb8dcab814b541180f [sys.catalog]: This master's current role is: LEADER
I20260812 06:17:15.899910 26891 catalog_manager.cc:1511] Loading table and tablet metadata into memory...
I20260812 06:17:15.900820 26891 catalog_manager.cc:1520] Initializing Kudu cluster ID...
I20260812 06:17:15.901055 26595 internal_mini_cluster.cc:184] Waiting to initialize catalog manager on master 0
I20260812 06:17:15.902647 26891 catalog_manager.cc:1383] Generated new cluster ID: 8a6dbedea6644aca9598bae30be5140c
I20260812 06:17:15.902717 26891 catalog_manager.cc:1531] Initializing Kudu internal certificate authority...
I20260812 06:17:15.919695 26891 catalog_manager.cc:1406] Generated new certificate authority record
I20260812 06:17:15.920245 26891 catalog_manager.cc:1540] Loading token signing keys...
I20260812 06:17:15.925729 26891 catalog_manager.cc:6092] T 00000000000000000000000000000000 P b047e9968d9249bb8dcab814b541180f: Generated new TSK 0
I20260812 06:17:15.925915 26891 catalog_manager.cc:1550] Initializing in-progress tserver states...
I20260812 06:17:15.933396 26595 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:17:15.935377 26908 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:17:15.935493 26906 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:17:15.935418 26905 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:17:15.935549 26595 server_base.cc:1061] running on GCE node
I20260812 06:17:15.935866 26595 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:17:15.935911 26595 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:17:15.935926 26595 hybrid_clock.cc:648] HybridClock initialized: now 1786515435935927 us; error 0 us; skew 500 ppm
I20260812 06:17:15.936811 26595 webserver.cc:533] Webserver started at http://127.25.248.193:35069/ using document root <none> and password file <none>
I20260812 06:17:15.936942 26595 fs_manager.cc:362] Metadata directory not provided
I20260812 06:17:15.936987 26595 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:17:15.937039 26595 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:17:15.937394 26595 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskdBxro6/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515429510153-26595-0/minicluster-data/ts-0-root/instance:
uuid: "66b138bc169a4198891e2f1784cb2739"
format_stamp: "Formatted at 2026-08-12 06:17:15 on dist-test-slave-10pc"
I20260812 06:17:15.938861 26595 fs_manager.cc:696] Time spent creating directory manager: real 0.001s	user 0.000s	sys 0.002s
I20260812 06:17:15.939771 26913 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:17:15.940013 26595 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.000s	sys 0.001s
I20260812 06:17:15.940110 26595 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskdBxro6/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515429510153-26595-0/minicluster-data/ts-0-root
uuid: "66b138bc169a4198891e2f1784cb2739"
format_stamp: "Formatted at 2026-08-12 06:17:15 on dist-test-slave-10pc"
I20260812 06:17:15.940198 26595 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskdBxro6/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515429510153-26595-0/minicluster-data/ts-0-root
metadata directory: /tmp/dist-test-taskdBxro6/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515429510153-26595-0/minicluster-data/ts-0-root
1 data directories: /tmp/dist-test-taskdBxro6/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515429510153-26595-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:17:15.944751 26595 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:17:15.945102 26595 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:17:15.945394 26595 txn_system_client.cc:432] TxnSystemClient initialization is disabled...
I20260812 06:17:15.945828 26595 ts_tablet_manager.cc:585] Loaded tablet metadata (0 total tablets, 0 live tablets)
I20260812 06:17:15.945890 26595 ts_tablet_manager.cc:531] Time spent load tablet metadata: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:17:15.945947 26595 ts_tablet_manager.cc:616] Registered 0 tablets
I20260812 06:17:15.945983 26595 ts_tablet_manager.cc:595] Time spent register tablets: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:17:15.950594 26595 rpc_server.cc:307] RPC server started. Bound to: 127.25.248.193:46559
I20260812 06:17:15.951171 26985 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.25.248.193:46559 every 8 connection(s)
I20260812 06:17:15.961951 26986 heartbeater.cc:344] Connected to a master server at 127.25.248.254:37567
I20260812 06:17:15.962114 26986 heartbeater.cc:461] Registering TS with master...
I20260812 06:17:15.962414 26986 heartbeater.cc:507] Master 127.25.248.254:37567 requested a full tablet report, sending...
I20260812 06:17:15.963155 26841 ts_manager.cc:194] Registered new tserver with Master: 66b138bc169a4198891e2f1784cb2739 (127.25.248.193:46559)
I20260812 06:17:15.963466 26595 internal_mini_cluster.cc:371] 1 TS(s) registered with all masters after 0.01214329s
I20260812 06:17:15.964143 26841 master_service.cc:502] Signed X509 certificate for tserver {username='slave'} at 127.0.0.1:49986
I20260812 06:17:15.970880 26841 catalog_manager.cc:2283] Servicing CreateTable request from {username='slave'} at 127.0.0.1:49992:
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:17:15.979724 26946 tablet_service.cc:1511] Processing CreateTablet for tablet 55c19a10c522408d95ff7c287ab82f51 (DEFAULT_TABLE table=heavy-update-compaction-test [id=5c93786a384243fe8b427c856c9ccdc9]), partition=
I20260812 06:17:15.980024 26946 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet 55c19a10c522408d95ff7c287ab82f51. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:17:15.982225 27000 tablet_bootstrap.cc:492] T 55c19a10c522408d95ff7c287ab82f51 P 66b138bc169a4198891e2f1784cb2739: Bootstrap starting.
I20260812 06:17:15.983079 27000 tablet_bootstrap.cc:654] T 55c19a10c522408d95ff7c287ab82f51 P 66b138bc169a4198891e2f1784cb2739: Neither blocks nor log segments found. Creating new log.
I20260812 06:17:15.984306 27000 tablet_bootstrap.cc:492] T 55c19a10c522408d95ff7c287ab82f51 P 66b138bc169a4198891e2f1784cb2739: No bootstrap required, opened a new log
I20260812 06:17:15.984424 27000 ts_tablet_manager.cc:1403] T 55c19a10c522408d95ff7c287ab82f51 P 66b138bc169a4198891e2f1784cb2739: Time spent bootstrapping tablet: real 0.002s	user 0.002s	sys 0.000s
I20260812 06:17:15.985075 27000 raft_consensus.cc:359] T 55c19a10c522408d95ff7c287ab82f51 P 66b138bc169a4198891e2f1784cb2739 [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "66b138bc169a4198891e2f1784cb2739" member_type: VOTER last_known_addr { host: "127.25.248.193" port: 46559 } }
I20260812 06:17:15.985208 27000 raft_consensus.cc:385] T 55c19a10c522408d95ff7c287ab82f51 P 66b138bc169a4198891e2f1784cb2739 [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:17:15.985255 27000 raft_consensus.cc:740] T 55c19a10c522408d95ff7c287ab82f51 P 66b138bc169a4198891e2f1784cb2739 [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: 66b138bc169a4198891e2f1784cb2739, State: Initialized, Role: FOLLOWER
I20260812 06:17:15.985400 27000 consensus_queue.cc:260] T 55c19a10c522408d95ff7c287ab82f51 P 66b138bc169a4198891e2f1784cb2739 [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: "66b138bc169a4198891e2f1784cb2739" member_type: VOTER last_known_addr { host: "127.25.248.193" port: 46559 } }
I20260812 06:17:15.985505 27000 raft_consensus.cc:399] T 55c19a10c522408d95ff7c287ab82f51 P 66b138bc169a4198891e2f1784cb2739 [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:17:15.985555 27000 raft_consensus.cc:493] T 55c19a10c522408d95ff7c287ab82f51 P 66b138bc169a4198891e2f1784cb2739 [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:17:15.985610 27000 raft_consensus.cc:3060] T 55c19a10c522408d95ff7c287ab82f51 P 66b138bc169a4198891e2f1784cb2739 [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:17:15.986382 27000 raft_consensus.cc:515] T 55c19a10c522408d95ff7c287ab82f51 P 66b138bc169a4198891e2f1784cb2739 [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "66b138bc169a4198891e2f1784cb2739" member_type: VOTER last_known_addr { host: "127.25.248.193" port: 46559 } }
I20260812 06:17:15.986541 27000 leader_election.cc:304] T 55c19a10c522408d95ff7c287ab82f51 P 66b138bc169a4198891e2f1784cb2739 [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: 66b138bc169a4198891e2f1784cb2739; no voters: 
I20260812 06:17:15.986778 27000 leader_election.cc:290] T 55c19a10c522408d95ff7c287ab82f51 P 66b138bc169a4198891e2f1784cb2739 [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:17:15.986908 27003 raft_consensus.cc:2804] T 55c19a10c522408d95ff7c287ab82f51 P 66b138bc169a4198891e2f1784cb2739 [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:17:15.987170 27000 ts_tablet_manager.cc:1434] T 55c19a10c522408d95ff7c287ab82f51 P 66b138bc169a4198891e2f1784cb2739: Time spent starting tablet: real 0.003s	user 0.000s	sys 0.002s
I20260812 06:17:15.987206 26986 heartbeater.cc:499] Master 127.25.248.254:37567 was elected leader, sending a full tablet report...
I20260812 06:17:15.987213 27003 raft_consensus.cc:697] T 55c19a10c522408d95ff7c287ab82f51 P 66b138bc169a4198891e2f1784cb2739 [term 1 LEADER]: Becoming Leader. State: Replica: 66b138bc169a4198891e2f1784cb2739, State: Running, Role: LEADER
I20260812 06:17:15.987393 27003 consensus_queue.cc:237] T 55c19a10c522408d95ff7c287ab82f51 P 66b138bc169a4198891e2f1784cb2739 [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: "66b138bc169a4198891e2f1784cb2739" member_type: VOTER last_known_addr { host: "127.25.248.193" port: 46559 } }
I20260812 06:17:15.988727 26841 catalog_manager.cc:5719] T 55c19a10c522408d95ff7c287ab82f51 P 66b138bc169a4198891e2f1784cb2739 reported cstate change: term changed from 0 to 1, leader changed from <none> to 66b138bc169a4198891e2f1784cb2739 (127.25.248.193). New cstate: current_term: 1 leader_uuid: "66b138bc169a4198891e2f1784cb2739" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "66b138bc169a4198891e2f1784cb2739" member_type: VOTER last_known_addr { host: "127.25.248.193" port: 46559 } health_report { overall_health: HEALTHY } } }
I20260812 06:17:16.049670 26595 heavy-update-compaction-itest.cc:215] Time spent inserting: real 0.054s	user 0.019s	sys 0.004s
I20260812 06:17:16.201855 26987 maintenance_manager.cc:419] P 66b138bc169a4198891e2f1784cb2739: Scheduling FlushMRSOp(55c19a10c522408d95ff7c287ab82f51): perf score=19.054940
I20260812 06:17:16.359364 26920 maintenance_manager.cc:643] P 66b138bc169a4198891e2f1784cb2739: FlushMRSOp(55c19a10c522408d95ff7c287ab82f51) complete. Timing: real 0.157s	user 0.114s	sys 0.039s Metrics: {"bytes_written":12307489,"cfile_init":1,"delete_count":0,"dirs.queue_time_us":55,"dirs.run_cpu_time_us":194,"dirs.run_wall_time_us":871,"drs_written":1,"lbm_read_time_us":47,"lbm_reads_lt_1ms":4,"lbm_write_time_us":37564,"lbm_writes_lt_1ms":757,"peak_mem_usage":0,"reinsert_count":0,"rows_written":104,"spinlock_wait_cycles":1536,"update_count":1500}
I20260812 06:17:16.360081 26987 maintenance_manager.cc:419] P 66b138bc169a4198891e2f1784cb2739: Scheduling LogGCOp(55c19a10c522408d95ff7c287ab82f51): free 20743880 bytes of WAL
I20260812 06:17:16.360325 26920 log_reader.cc:385] T 55c19a10c522408d95ff7c287ab82f51: removed 2 log segments from log reader
I20260812 06:17:16.360394 26920 log.cc:1079] T 55c19a10c522408d95ff7c287ab82f51 P 66b138bc169a4198891e2f1784cb2739: Deleting log segment in path: /tmp/dist-test-taskdBxro6/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515429510153-26595-0/minicluster-data/ts-0-root/wals/55c19a10c522408d95ff7c287ab82f51/wal-000000001 (ops 1-6)
I20260812 06:17:16.360488 26920 log.cc:1079] T 55c19a10c522408d95ff7c287ab82f51 P 66b138bc169a4198891e2f1784cb2739: Deleting log segment in path: /tmp/dist-test-taskdBxro6/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515429510153-26595-0/minicluster-data/ts-0-root/wals/55c19a10c522408d95ff7c287ab82f51/wal-000000002 (ops 7-11)
I20260812 06:17:16.367272 26920 maintenance_manager.cc:643] P 66b138bc169a4198891e2f1784cb2739: LogGCOp(55c19a10c522408d95ff7c287ab82f51) complete. Timing: real 0.007s	user 0.001s	sys 0.003s Metrics: {}
I20260812 06:17:16.367643 26987 maintenance_manager.cc:419] P 66b138bc169a4198891e2f1784cb2739: Scheduling FlushDeltaMemStoresOp(55c19a10c522408d95ff7c287ab82f51): perf score=3.181125
I20260812 06:17:16.383128 26920 maintenance_manager.cc:643] P 66b138bc169a4198891e2f1784cb2739: FlushDeltaMemStoresOp(55c19a10c522408d95ff7c287ab82f51) complete. Timing: real 0.015s	user 0.011s	sys 0.000s Metrics: {"bytes_written":4512903,"delete_count":0,"lbm_write_time_us":4961,"lbm_writes_lt_1ms":113,"reinsert_count":0,"update_count":550}
I20260812 06:17:16.383590 26987 maintenance_manager.cc:419] P 66b138bc169a4198891e2f1784cb2739: Scheduling UndoDeltaBlockGCOp(55c19a10c522408d95ff7c287ab82f51): 16411391 bytes on disk
I20260812 06:17:16.384033 26920 maintenance_manager.cc:643] P 66b138bc169a4198891e2f1784cb2739: UndoDeltaBlockGCOp(55c19a10c522408d95ff7c287ab82f51) 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:17:16.384442 26987 maintenance_manager.cc:419] P 66b138bc169a4198891e2f1784cb2739: Scheduling FlushDeltaMemStoresOp(55c19a10c522408d95ff7c287ab82f51): perf score=2.188937
I20260812 06:17:16.395345 26920 maintenance_manager.cc:643] P 66b138bc169a4198891e2f1784cb2739: FlushDeltaMemStoresOp(55c19a10c522408d95ff7c287ab82f51) complete. Timing: real 0.011s	user 0.005s	sys 0.004s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":4157,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:17:16.395779 26987 maintenance_manager.cc:419] P 66b138bc169a4198891e2f1784cb2739: Scheduling MajorDeltaCompactionOp(55c19a10c522408d95ff7c287ab82f51): perf score=1.000000
I20260812 06:17:16.603928 26920 maintenance_manager.cc:643] P 66b138bc169a4198891e2f1784cb2739: MajorDeltaCompactionOp(55c19a10c522408d95ff7c287ab82f51) complete. Timing: real 0.208s	user 0.150s	sys 0.055s Metrics: {"cfile_cache_miss":533,"cfile_cache_miss_bytes":24774797,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":78,"lbm_read_time_us":14807,"lbm_reads_lt_1ms":569,"lbm_write_time_us":33942,"lbm_writes_lt_1ms":543,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":2432,"thread_start_us":261,"threads_started":5,"update_count":2500}
I20260812 06:17:16.604562 26987 maintenance_manager.cc:419] P 66b138bc169a4198891e2f1784cb2739: Scheduling FlushDeltaMemStoresOp(55c19a10c522408d95ff7c287ab82f51): perf score=14.095187
I20260812 06:17:16.651679 26920 maintenance_manager.cc:643] P 66b138bc169a4198891e2f1784cb2739: FlushDeltaMemStoresOp(55c19a10c522408d95ff7c287ab82f51) complete. Timing: real 0.047s	user 0.019s	sys 0.025s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":21016,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:17:16.652256 26987 maintenance_manager.cc:419] P 66b138bc169a4198891e2f1784cb2739: Scheduling MajorDeltaCompactionOp(55c19a10c522408d95ff7c287ab82f51): perf score=1.000000
I20260812 06:17:16.808517 26920 maintenance_manager.cc:643] P 66b138bc169a4198891e2f1784cb2739: MajorDeltaCompactionOp(55c19a10c522408d95ff7c287ab82f51) complete. Timing: real 0.156s	user 0.108s	sys 0.043s Metrics: {"cfile_cache_miss":431,"cfile_cache_miss_bytes":20672157,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":1,"delta_iterators_relevant":1,"dirs.queue_time_us":357,"lbm_read_time_us":11604,"lbm_reads_lt_1ms":467,"lbm_write_time_us":24675,"lbm_writes_lt_1ms":443,"mutex_wait_us":104,"peak_mem_usage":50689328,"reinsert_count":0,"update_count":2000}
I20260812 06:17:16.809166 26987 maintenance_manager.cc:419] P 66b138bc169a4198891e2f1784cb2739: Scheduling FlushDeltaMemStoresOp(55c19a10c522408d95ff7c287ab82f51): perf score=11.118625
I20260812 06:17:16.851148 26920 maintenance_manager.cc:643] P 66b138bc169a4198891e2f1784cb2739: FlushDeltaMemStoresOp(55c19a10c522408d95ff7c287ab82f51) complete. Timing: real 0.042s	user 0.023s	sys 0.016s Metrics: {"bytes_written":12717735,"delete_count":0,"lbm_write_time_us":17643,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:17:16.851886 26987 maintenance_manager.cc:419] P 66b138bc169a4198891e2f1784cb2739: Scheduling FlushDeltaMemStoresOp(55c19a10c522408d95ff7c287ab82f51): perf score=2.188937
I20260812 06:17:16.878444 26920 maintenance_manager.cc:643] P 66b138bc169a4198891e2f1784cb2739: FlushDeltaMemStoresOp(55c19a10c522408d95ff7c287ab82f51) complete. Timing: real 0.026s	user 0.008s	sys 0.004s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":5762,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:17:16.878975 26987 maintenance_manager.cc:419] P 66b138bc169a4198891e2f1784cb2739: Scheduling FlushDeltaMemStoresOp(55c19a10c522408d95ff7c287ab82f51): perf score=2.188937
I20260812 06:17:16.891103 26920 maintenance_manager.cc:643] P 66b138bc169a4198891e2f1784cb2739: FlushDeltaMemStoresOp(55c19a10c522408d95ff7c287ab82f51) complete. Timing: real 0.012s	user 0.005s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4566,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:16.891744 26987 maintenance_manager.cc:419] P 66b138bc169a4198891e2f1784cb2739: Scheduling MajorDeltaCompactionOp(55c19a10c522408d95ff7c287ab82f51): perf score=1.000000
I20260812 06:17:17.077402 26920 maintenance_manager.cc:643] P 66b138bc169a4198891e2f1784cb2739: MajorDeltaCompactionOp(55c19a10c522408d95ff7c287ab82f51) complete. Timing: real 0.185s	user 0.127s	sys 0.050s 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":151,"lbm_read_time_us":10325,"lbm_reads_lt_1ms":573,"lbm_write_time_us":30038,"lbm_writes_lt_1ms":543,"mutex_wait_us":21,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":20992,"update_count":2500}
I20260812 06:17:17.078112 26987 maintenance_manager.cc:419] P 66b138bc169a4198891e2f1784cb2739: Scheduling FlushDeltaMemStoresOp(55c19a10c522408d95ff7c287ab82f51): perf score=14.095187
I20260812 06:17:17.127574 26920 maintenance_manager.cc:643] P 66b138bc169a4198891e2f1784cb2739: FlushDeltaMemStoresOp(55c19a10c522408d95ff7c287ab82f51) complete. Timing: real 0.049s	user 0.012s	sys 0.028s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":18503,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:17:17.128201 26987 maintenance_manager.cc:419] P 66b138bc169a4198891e2f1784cb2739: Scheduling FlushDeltaMemStoresOp(55c19a10c522408d95ff7c287ab82f51): perf score=2.188937
I20260812 06:17:17.145066 26920 maintenance_manager.cc:643] P 66b138bc169a4198891e2f1784cb2739: FlushDeltaMemStoresOp(55c19a10c522408d95ff7c287ab82f51) complete. Timing: real 0.017s	user 0.009s	sys 0.007s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6475,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:17.145640 26987 maintenance_manager.cc:419] P 66b138bc169a4198891e2f1784cb2739: Scheduling MajorDeltaCompactionOp(55c19a10c522408d95ff7c287ab82f51): perf score=1.000000
I20260812 06:17:17.294422 26920 maintenance_manager.cc:643] P 66b138bc169a4198891e2f1784cb2739: MajorDeltaCompactionOp(55c19a10c522408d95ff7c287ab82f51) complete. Timing: real 0.149s	user 0.122s	sys 0.024s 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":170,"lbm_read_time_us":9803,"lbm_reads_lt_1ms":572,"lbm_write_time_us":29002,"lbm_writes_lt_1ms":543,"mutex_wait_us":83,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":14976,"update_count":2500}
I20260812 06:17:17.295233 26987 maintenance_manager.cc:419] P 66b138bc169a4198891e2f1784cb2739: Scheduling FlushDeltaMemStoresOp(55c19a10c522408d95ff7c287ab82f51): perf score=10.126437
I20260812 06:17:17.332186 26920 maintenance_manager.cc:643] P 66b138bc169a4198891e2f1784cb2739: FlushDeltaMemStoresOp(55c19a10c522408d95ff7c287ab82f51) complete. Timing: real 0.037s	user 0.019s	sys 0.011s Metrics: {"bytes_written":12307489,"delete_count":0,"lbm_write_time_us":14201,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:17:17.332701 26987 maintenance_manager.cc:419] P 66b138bc169a4198891e2f1784cb2739: Scheduling FlushDeltaMemStoresOp(55c19a10c522408d95ff7c287ab82f51): perf score=2.188937
I20260812 06:17:17.347656 26920 maintenance_manager.cc:643] P 66b138bc169a4198891e2f1784cb2739: FlushDeltaMemStoresOp(55c19a10c522408d95ff7c287ab82f51) complete. Timing: real 0.015s	user 0.011s	sys 0.001s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5166,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:17.348292 26987 maintenance_manager.cc:419] P 66b138bc169a4198891e2f1784cb2739: Scheduling MajorDeltaCompactionOp(55c19a10c522408d95ff7c287ab82f51): perf score=1.000000
I20260812 06:17:17.464021 26920 maintenance_manager.cc:643] P 66b138bc169a4198891e2f1784cb2739: MajorDeltaCompactionOp(55c19a10c522408d95ff7c287ab82f51) complete. Timing: real 0.116s	user 0.107s	sys 0.008s 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":516,"lbm_read_time_us":8218,"lbm_reads_lt_1ms":472,"lbm_write_time_us":22246,"lbm_writes_lt_1ms":443,"mutex_wait_us":44,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":6272,"update_count":2000}
I20260812 06:17:17.464769 26987 maintenance_manager.cc:419] P 66b138bc169a4198891e2f1784cb2739: Scheduling FlushDeltaMemStoresOp(55c19a10c522408d95ff7c287ab82f51): perf score=10.126437
I20260812 06:17:17.501972 26920 maintenance_manager.cc:643] P 66b138bc169a4198891e2f1784cb2739: FlushDeltaMemStoresOp(55c19a10c522408d95ff7c287ab82f51) complete. Timing: real 0.037s	user 0.024s	sys 0.009s Metrics: {"bytes_written":12307492,"delete_count":0,"lbm_write_time_us":14723,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:17:17.502588 26987 maintenance_manager.cc:419] P 66b138bc169a4198891e2f1784cb2739: Scheduling FlushDeltaMemStoresOp(55c19a10c522408d95ff7c287ab82f51): perf score=2.188937
I20260812 06:17:17.517103 26920 maintenance_manager.cc:643] P 66b138bc169a4198891e2f1784cb2739: FlushDeltaMemStoresOp(55c19a10c522408d95ff7c287ab82f51) complete. Timing: real 0.014s	user 0.014s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5566,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:17.517743 26987 maintenance_manager.cc:419] P 66b138bc169a4198891e2f1784cb2739: Scheduling MajorDeltaCompactionOp(55c19a10c522408d95ff7c287ab82f51): perf score=1.000000
I20260812 06:17:17.657794 26920 maintenance_manager.cc:643] P 66b138bc169a4198891e2f1784cb2739: MajorDeltaCompactionOp(55c19a10c522408d95ff7c287ab82f51) complete. Timing: real 0.140s	user 0.116s	sys 0.024s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672279,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":161,"lbm_read_time_us":10309,"lbm_reads_lt_1ms":472,"lbm_write_time_us":26097,"lbm_writes_lt_1ms":443,"mutex_wait_us":23,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":39424,"update_count":2000}
I20260812 06:17:17.658631 26987 maintenance_manager.cc:419] P 66b138bc169a4198891e2f1784cb2739: Scheduling FlushDeltaMemStoresOp(55c19a10c522408d95ff7c287ab82f51): perf score=10.126437
I20260812 06:17:17.714186 26920 maintenance_manager.cc:643] P 66b138bc169a4198891e2f1784cb2739: FlushDeltaMemStoresOp(55c19a10c522408d95ff7c287ab82f51) complete. Timing: real 0.055s	user 0.023s	sys 0.030s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":17719,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:17:17.714809 26987 maintenance_manager.cc:419] P 66b138bc169a4198891e2f1784cb2739: Scheduling FlushDeltaMemStoresOp(55c19a10c522408d95ff7c287ab82f51): perf score=2.188937
I20260812 06:17:17.725557 26920 maintenance_manager.cc:643] P 66b138bc169a4198891e2f1784cb2739: FlushDeltaMemStoresOp(55c19a10c522408d95ff7c287ab82f51) complete. Timing: real 0.011s	user 0.005s	sys 0.004s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4204,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:17.726064 26987 maintenance_manager.cc:419] P 66b138bc169a4198891e2f1784cb2739: Scheduling FlushMRSOp(55c19a10c522408d95ff7c287ab82f51): perf score=1.000000
I20260812 06:17:17.757897 26920 maintenance_manager.cc:643] P 66b138bc169a4198891e2f1784cb2739: FlushMRSOp(55c19a10c522408d95ff7c287ab82f51) complete. Timing: real 0.032s	user 0.029s	sys 0.000s Metrics: {"bytes_written":1275443,"cfile_init":1,"dirs.queue_time_us":93,"dirs.run_cpu_time_us":296,"dirs.run_wall_time_us":1749,"drs_written":1,"lbm_read_time_us":40,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1542,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":31}
I20260812 06:17:17.758554 26987 maintenance_manager.cc:419] P 66b138bc169a4198891e2f1784cb2739: Scheduling MajorDeltaCompactionOp(55c19a10c522408d95ff7c287ab82f51): perf score=1.000000
I20260812 06:17:17.925108 26920 maintenance_manager.cc:643] P 66b138bc169a4198891e2f1784cb2739: MajorDeltaCompactionOp(55c19a10c522408d95ff7c287ab82f51) complete. Timing: real 0.166s	user 0.105s	sys 0.060s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672276,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":1152,"lbm_read_time_us":10706,"lbm_reads_lt_1ms":464,"lbm_write_time_us":27059,"lbm_writes_lt_1ms":443,"mutex_wait_us":381,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":12544,"update_count":2000}
I20260812 06:17:17.925802 26987 maintenance_manager.cc:419] P 66b138bc169a4198891e2f1784cb2739: Scheduling LogGCOp(55c19a10c522408d95ff7c287ab82f51): free 124710294 bytes of WAL
I20260812 06:17:17.926092 26920 log_reader.cc:385] T 55c19a10c522408d95ff7c287ab82f51: removed 12 log segments from log reader
I20260812 06:17:17.926159 26920 log.cc:1079] T 55c19a10c522408d95ff7c287ab82f51 P 66b138bc169a4198891e2f1784cb2739: Deleting log segment in path: /tmp/dist-test-taskdBxro6/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515429510153-26595-0/minicluster-data/ts-0-root/wals/55c19a10c522408d95ff7c287ab82f51/wal-000000003 (ops 12-16)
I20260812 06:17:17.926199 26920 log.cc:1079] T 55c19a10c522408d95ff7c287ab82f51 P 66b138bc169a4198891e2f1784cb2739: Deleting log segment in path: /tmp/dist-test-taskdBxro6/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515429510153-26595-0/minicluster-data/ts-0-root/wals/55c19a10c522408d95ff7c287ab82f51/wal-000000004 (ops 17-21)
I20260812 06:17:17.926283 26920 log.cc:1079] T 55c19a10c522408d95ff7c287ab82f51 P 66b138bc169a4198891e2f1784cb2739: Deleting log segment in path: /tmp/dist-test-taskdBxro6/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515429510153-26595-0/minicluster-data/ts-0-root/wals/55c19a10c522408d95ff7c287ab82f51/wal-000000005 (ops 22-26)
I20260812 06:17:17.926324 26920 log.cc:1079] T 55c19a10c522408d95ff7c287ab82f51 P 66b138bc169a4198891e2f1784cb2739: Deleting log segment in path: /tmp/dist-test-taskdBxro6/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515429510153-26595-0/minicluster-data/ts-0-root/wals/55c19a10c522408d95ff7c287ab82f51/wal-000000006 (ops 27-31)
I20260812 06:17:17.926348 26920 log.cc:1079] T 55c19a10c522408d95ff7c287ab82f51 P 66b138bc169a4198891e2f1784cb2739: Deleting log segment in path: /tmp/dist-test-taskdBxro6/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515429510153-26595-0/minicluster-data/ts-0-root/wals/55c19a10c522408d95ff7c287ab82f51/wal-000000007 (ops 32-36)
I20260812 06:17:17.926414 26920 log.cc:1079] T 55c19a10c522408d95ff7c287ab82f51 P 66b138bc169a4198891e2f1784cb2739: Deleting log segment in path: /tmp/dist-test-taskdBxro6/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515429510153-26595-0/minicluster-data/ts-0-root/wals/55c19a10c522408d95ff7c287ab82f51/wal-000000008 (ops 37-41)
I20260812 06:17:17.926457 26920 log.cc:1079] T 55c19a10c522408d95ff7c287ab82f51 P 66b138bc169a4198891e2f1784cb2739: Deleting log segment in path: /tmp/dist-test-taskdBxro6/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515429510153-26595-0/minicluster-data/ts-0-root/wals/55c19a10c522408d95ff7c287ab82f51/wal-000000009 (ops 42-46)
I20260812 06:17:17.926481 26920 log.cc:1079] T 55c19a10c522408d95ff7c287ab82f51 P 66b138bc169a4198891e2f1784cb2739: Deleting log segment in path: /tmp/dist-test-taskdBxro6/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515429510153-26595-0/minicluster-data/ts-0-root/wals/55c19a10c522408d95ff7c287ab82f51/wal-000000010 (ops 47-51)
I20260812 06:17:17.926527 26920 log.cc:1079] T 55c19a10c522408d95ff7c287ab82f51 P 66b138bc169a4198891e2f1784cb2739: Deleting log segment in path: /tmp/dist-test-taskdBxro6/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515429510153-26595-0/minicluster-data/ts-0-root/wals/55c19a10c522408d95ff7c287ab82f51/wal-000000011 (ops 52-56)
I20260812 06:17:17.926561 26920 log.cc:1079] T 55c19a10c522408d95ff7c287ab82f51 P 66b138bc169a4198891e2f1784cb2739: Deleting log segment in path: /tmp/dist-test-taskdBxro6/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515429510153-26595-0/minicluster-data/ts-0-root/wals/55c19a10c522408d95ff7c287ab82f51/wal-000000012 (ops 57-61)
I20260812 06:17:17.926622 26920 log.cc:1079] T 55c19a10c522408d95ff7c287ab82f51 P 66b138bc169a4198891e2f1784cb2739: Deleting log segment in path: /tmp/dist-test-taskdBxro6/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515429510153-26595-0/minicluster-data/ts-0-root/wals/55c19a10c522408d95ff7c287ab82f51/wal-000000013 (ops 62-66)
I20260812 06:17:17.926661 26920 log.cc:1079] T 55c19a10c522408d95ff7c287ab82f51 P 66b138bc169a4198891e2f1784cb2739: Deleting log segment in path: /tmp/dist-test-taskdBxro6/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515429510153-26595-0/minicluster-data/ts-0-root/wals/55c19a10c522408d95ff7c287ab82f51/wal-000000014 (ops 67-71)
I20260812 06:17:17.956882 26920 maintenance_manager.cc:643] P 66b138bc169a4198891e2f1784cb2739: LogGCOp(55c19a10c522408d95ff7c287ab82f51) complete. Timing: real 0.031s	user 0.000s	sys 0.030s Metrics: {}
I20260812 06:17:17.957391 26987 maintenance_manager.cc:419] P 66b138bc169a4198891e2f1784cb2739: Scheduling UndoDeltaBlockGCOp(55c19a10c522408d95ff7c287ab82f51): 482 bytes on disk
I20260812 06:17:17.958072 26920 maintenance_manager.cc:643] P 66b138bc169a4198891e2f1784cb2739: UndoDeltaBlockGCOp(55c19a10c522408d95ff7c287ab82f51) complete. Timing: real 0.001s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":82,"lbm_reads_lt_1ms":4}
I20260812 06:17:17.958873 26987 maintenance_manager.cc:419] P 66b138bc169a4198891e2f1784cb2739: Scheduling FlushDeltaMemStoresOp(55c19a10c522408d95ff7c287ab82f51): perf score=17.071750
I20260812 06:17:18.033526 26920 maintenance_manager.cc:643] P 66b138bc169a4198891e2f1784cb2739: FlushDeltaMemStoresOp(55c19a10c522408d95ff7c287ab82f51) complete. Timing: real 0.074s	user 0.035s	sys 0.032s Metrics: {"bytes_written":19117498,"delete_count":0,"lbm_write_time_us":27360,"lbm_writes_lt_1ms":469,"reinsert_count":0,"update_count":2330}
I20260812 06:17:18.034093 26987 maintenance_manager.cc:419] P 66b138bc169a4198891e2f1784cb2739: Scheduling FlushDeltaMemStoresOp(55c19a10c522408d95ff7c287ab82f51): perf score=4.173312
I20260812 06:17:18.056617 26920 maintenance_manager.cc:643] P 66b138bc169a4198891e2f1784cb2739: FlushDeltaMemStoresOp(55c19a10c522408d95ff7c287ab82f51) complete. Timing: real 0.022s	user 0.018s	sys 0.004s Metrics: {"bytes_written":5497489,"delete_count":0,"lbm_write_time_us":8911,"lbm_writes_lt_1ms":137,"reinsert_count":0,"update_count":670}
I20260812 06:17:18.057331 26987 maintenance_manager.cc:419] P 66b138bc169a4198891e2f1784cb2739: Scheduling MajorDeltaCompactionOp(55c19a10c522408d95ff7c287ab82f51): perf score=1.000000
I20260812 06:17:18.260599 26920 maintenance_manager.cc:643] P 66b138bc169a4198891e2f1784cb2739: MajorDeltaCompactionOp(55c19a10c522408d95ff7c287ab82f51) complete. Timing: real 0.203s	user 0.149s	sys 0.052s Metrics: {"cfile_cache_miss":632,"cfile_cache_miss_bytes":28877109,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":635,"lbm_read_time_us":16429,"lbm_reads_lt_1ms":672,"lbm_write_time_us":32136,"lbm_writes_lt_1ms":643,"mutex_wait_us":278,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":9856,"update_count":3000}
I20260812 06:17:18.261247 26987 maintenance_manager.cc:419] P 66b138bc169a4198891e2f1784cb2739: Scheduling FlushDeltaMemStoresOp(55c19a10c522408d95ff7c287ab82f51): perf score=15.087375
I20260812 06:17:18.339560 26920 maintenance_manager.cc:643] P 66b138bc169a4198891e2f1784cb2739: FlushDeltaMemStoresOp(55c19a10c522408d95ff7c287ab82f51) complete. Timing: real 0.078s	user 0.047s	sys 0.019s Metrics: {"bytes_written":16820142,"delete_count":0,"lbm_write_time_us":27504,"lbm_writes_lt_1ms":413,"reinsert_count":0,"update_count":2050}
I20260812 06:17:18.340282 26987 maintenance_manager.cc:419] P 66b138bc169a4198891e2f1784cb2739: Scheduling FlushDeltaMemStoresOp(55c19a10c522408d95ff7c287ab82f51): perf score=6.157687
I20260812 06:17:18.363011 26920 maintenance_manager.cc:643] P 66b138bc169a4198891e2f1784cb2739: FlushDeltaMemStoresOp(55c19a10c522408d95ff7c287ab82f51) complete. Timing: real 0.022s	user 0.007s	sys 0.013s Metrics: {"bytes_written":7794836,"delete_count":0,"lbm_write_time_us":9171,"lbm_writes_lt_1ms":193,"reinsert_count":0,"update_count":950}
I20260812 06:17:18.363529 26987 maintenance_manager.cc:419] P 66b138bc169a4198891e2f1784cb2739: Scheduling MajorDeltaCompactionOp(55c19a10c522408d95ff7c287ab82f51): perf score=1.000000
I20260812 06:17:18.560645 26920 maintenance_manager.cc:643] P 66b138bc169a4198891e2f1784cb2739: MajorDeltaCompactionOp(55c19a10c522408d95ff7c287ab82f51) complete. Timing: real 0.197s	user 0.100s	sys 0.096s Metrics: {"cfile_cache_miss":632,"cfile_cache_miss_bytes":28877100,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":347,"lbm_read_time_us":14575,"lbm_reads_lt_1ms":672,"lbm_write_time_us":33772,"lbm_writes_lt_1ms":643,"mutex_wait_us":41,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":70272,"update_count":3000}
I20260812 06:17:18.561218 26987 maintenance_manager.cc:419] P 66b138bc169a4198891e2f1784cb2739: Scheduling FlushDeltaMemStoresOp(55c19a10c522408d95ff7c287ab82f51): perf score=14.095187
I20260812 06:17:18.614135 26920 maintenance_manager.cc:643] P 66b138bc169a4198891e2f1784cb2739: FlushDeltaMemStoresOp(55c19a10c522408d95ff7c287ab82f51) complete. Timing: real 0.053s	user 0.031s	sys 0.016s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":22185,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:17:18.614701 26987 maintenance_manager.cc:419] P 66b138bc169a4198891e2f1784cb2739: Scheduling FlushDeltaMemStoresOp(55c19a10c522408d95ff7c287ab82f51): perf score=2.188937
I20260812 06:17:18.630676 26920 maintenance_manager.cc:643] P 66b138bc169a4198891e2f1784cb2739: FlushDeltaMemStoresOp(55c19a10c522408d95ff7c287ab82f51) complete. Timing: real 0.016s	user 0.001s	sys 0.012s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":6054,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:18.631376 26987 maintenance_manager.cc:419] P 66b138bc169a4198891e2f1784cb2739: Scheduling MajorDeltaCompactionOp(55c19a10c522408d95ff7c287ab82f51): perf score=1.000000
I20260812 06:17:18.809293 26920 maintenance_manager.cc:643] P 66b138bc169a4198891e2f1784cb2739: MajorDeltaCompactionOp(55c19a10c522408d95ff7c287ab82f51) complete. Timing: real 0.178s	user 0.134s	sys 0.043s 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":161,"lbm_read_time_us":12555,"lbm_reads_lt_1ms":572,"lbm_write_time_us":29210,"lbm_writes_lt_1ms":543,"mutex_wait_us":23,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":7168,"update_count":2500}
I20260812 06:17:18.809847 26987 maintenance_manager.cc:419] P 66b138bc169a4198891e2f1784cb2739: Scheduling FlushDeltaMemStoresOp(55c19a10c522408d95ff7c287ab82f51): perf score=14.095187
I20260812 06:17:18.873754 26920 maintenance_manager.cc:643] P 66b138bc169a4198891e2f1784cb2739: FlushDeltaMemStoresOp(55c19a10c522408d95ff7c287ab82f51) complete. Timing: real 0.064s	user 0.035s	sys 0.027s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":23532,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:17:18.874375 26987 maintenance_manager.cc:419] P 66b138bc169a4198891e2f1784cb2739: Scheduling FlushDeltaMemStoresOp(55c19a10c522408d95ff7c287ab82f51): perf score=2.188937
I20260812 06:17:18.891649 26920 maintenance_manager.cc:643] P 66b138bc169a4198891e2f1784cb2739: FlushDeltaMemStoresOp(55c19a10c522408d95ff7c287ab82f51) complete. Timing: real 0.017s	user 0.007s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6609,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:18.892196 26987 maintenance_manager.cc:419] P 66b138bc169a4198891e2f1784cb2739: Scheduling MajorDeltaCompactionOp(55c19a10c522408d95ff7c287ab82f51): perf score=1.000000
I20260812 06:17:19.073406 26920 maintenance_manager.cc:643] P 66b138bc169a4198891e2f1784cb2739: MajorDeltaCompactionOp(55c19a10c522408d95ff7c287ab82f51) complete. Timing: real 0.181s	user 0.129s	sys 0.047s 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":185,"lbm_read_time_us":12910,"lbm_reads_lt_1ms":572,"lbm_write_time_us":29725,"lbm_writes_lt_1ms":543,"mutex_wait_us":69,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":4992,"update_count":2500}
I20260812 06:17:19.074146 26987 maintenance_manager.cc:419] P 66b138bc169a4198891e2f1784cb2739: Scheduling FlushDeltaMemStoresOp(55c19a10c522408d95ff7c287ab82f51): perf score=14.095187
I20260812 06:17:19.143151 26920 maintenance_manager.cc:643] P 66b138bc169a4198891e2f1784cb2739: FlushDeltaMemStoresOp(55c19a10c522408d95ff7c287ab82f51) complete. Timing: real 0.069s	user 0.028s	sys 0.038s Metrics: {"bytes_written":16409904,"delete_count":0,"lbm_write_time_us":27482,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":402,"reinsert_count":0,"update_count":2000}
I20260812 06:17:19.143689 26987 maintenance_manager.cc:419] P 66b138bc169a4198891e2f1784cb2739: Scheduling FlushDeltaMemStoresOp(55c19a10c522408d95ff7c287ab82f51): perf score=2.188937
I20260812 06:17:19.154793 26920 maintenance_manager.cc:643] P 66b138bc169a4198891e2f1784cb2739: FlushDeltaMemStoresOp(55c19a10c522408d95ff7c287ab82f51) complete. Timing: real 0.011s	user 0.006s	sys 0.003s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4300,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:19.155292 26987 maintenance_manager.cc:419] P 66b138bc169a4198891e2f1784cb2739: Scheduling MajorDeltaCompactionOp(55c19a10c522408d95ff7c287ab82f51): perf score=1.000000
I20260812 06:17:19.357724 26920 maintenance_manager.cc:643] P 66b138bc169a4198891e2f1784cb2739: MajorDeltaCompactionOp(55c19a10c522408d95ff7c287ab82f51) complete. Timing: real 0.202s	user 0.121s	sys 0.071s 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":379,"lbm_read_time_us":14861,"lbm_reads_lt_1ms":572,"lbm_write_time_us":32369,"lbm_writes_lt_1ms":543,"mutex_wait_us":23,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":24832,"update_count":2500}
I20260812 06:17:19.358503 26987 maintenance_manager.cc:419] P 66b138bc169a4198891e2f1784cb2739: Scheduling FlushDeltaMemStoresOp(55c19a10c522408d95ff7c287ab82f51): perf score=14.095187
I20260812 06:17:19.417179 26920 maintenance_manager.cc:643] P 66b138bc169a4198891e2f1784cb2739: FlushDeltaMemStoresOp(55c19a10c522408d95ff7c287ab82f51) complete. Timing: real 0.059s	user 0.036s	sys 0.016s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":23412,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:17:19.417744 26987 maintenance_manager.cc:419] P 66b138bc169a4198891e2f1784cb2739: Scheduling FlushDeltaMemStoresOp(55c19a10c522408d95ff7c287ab82f51): perf score=2.188937
I20260812 06:17:19.438962 26920 maintenance_manager.cc:643] P 66b138bc169a4198891e2f1784cb2739: FlushDeltaMemStoresOp(55c19a10c522408d95ff7c287ab82f51) complete. Timing: real 0.021s	user 0.007s	sys 0.011s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4195,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:19.439728 26987 maintenance_manager.cc:419] P 66b138bc169a4198891e2f1784cb2739: Scheduling FlushMRSOp(55c19a10c522408d95ff7c287ab82f51): perf score=1.000000
I20260812 06:17:19.474260 26920 maintenance_manager.cc:643] P 66b138bc169a4198891e2f1784cb2739: FlushMRSOp(55c19a10c522408d95ff7c287ab82f51) complete. Timing: real 0.034s	user 0.024s	sys 0.008s Metrics: {"bytes_written":1316419,"cfile_init":1,"dirs.queue_time_us":45,"dirs.run_cpu_time_us":188,"dirs.run_wall_time_us":1342,"drs_written":1,"lbm_read_time_us":55,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1866,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":32}
I20260812 06:17:19.474941 26987 maintenance_manager.cc:419] P 66b138bc169a4198891e2f1784cb2739: Scheduling LogGCOp(55c19a10c522408d95ff7c287ab82f51): free 133024349 bytes of WAL
I20260812 06:17:19.475226 26920 log_reader.cc:385] T 55c19a10c522408d95ff7c287ab82f51: removed 13 log segments from log reader
I20260812 06:17:19.475294 26920 log.cc:1079] T 55c19a10c522408d95ff7c287ab82f51 P 66b138bc169a4198891e2f1784cb2739: Deleting log segment in path: /tmp/dist-test-taskdBxro6/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515429510153-26595-0/minicluster-data/ts-0-root/wals/55c19a10c522408d95ff7c287ab82f51/wal-000000015 (ops 72-76)
I20260812 06:17:19.475332 26920 log.cc:1079] T 55c19a10c522408d95ff7c287ab82f51 P 66b138bc169a4198891e2f1784cb2739: Deleting log segment in path: /tmp/dist-test-taskdBxro6/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515429510153-26595-0/minicluster-data/ts-0-root/wals/55c19a10c522408d95ff7c287ab82f51/wal-000000016 (ops 77-80)
I20260812 06:17:19.475364 26920 log.cc:1079] T 55c19a10c522408d95ff7c287ab82f51 P 66b138bc169a4198891e2f1784cb2739: Deleting log segment in path: /tmp/dist-test-taskdBxro6/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515429510153-26595-0/minicluster-data/ts-0-root/wals/55c19a10c522408d95ff7c287ab82f51/wal-000000017 (ops 81-85)
I20260812 06:17:19.475399 26920 log.cc:1079] T 55c19a10c522408d95ff7c287ab82f51 P 66b138bc169a4198891e2f1784cb2739: Deleting log segment in path: /tmp/dist-test-taskdBxro6/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515429510153-26595-0/minicluster-data/ts-0-root/wals/55c19a10c522408d95ff7c287ab82f51/wal-000000018 (ops 86-90)
I20260812 06:17:19.475435 26920 log.cc:1079] T 55c19a10c522408d95ff7c287ab82f51 P 66b138bc169a4198891e2f1784cb2739: Deleting log segment in path: /tmp/dist-test-taskdBxro6/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515429510153-26595-0/minicluster-data/ts-0-root/wals/55c19a10c522408d95ff7c287ab82f51/wal-000000019 (ops 91-95)
I20260812 06:17:19.475459 26920 log.cc:1079] T 55c19a10c522408d95ff7c287ab82f51 P 66b138bc169a4198891e2f1784cb2739: Deleting log segment in path: /tmp/dist-test-taskdBxro6/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515429510153-26595-0/minicluster-data/ts-0-root/wals/55c19a10c522408d95ff7c287ab82f51/wal-000000020 (ops 96-100)
I20260812 06:17:19.475488 26920 log.cc:1079] T 55c19a10c522408d95ff7c287ab82f51 P 66b138bc169a4198891e2f1784cb2739: Deleting log segment in path: /tmp/dist-test-taskdBxro6/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515429510153-26595-0/minicluster-data/ts-0-root/wals/55c19a10c522408d95ff7c287ab82f51/wal-000000021 (ops 101-105)
I20260812 06:17:19.475517 26920 log.cc:1079] T 55c19a10c522408d95ff7c287ab82f51 P 66b138bc169a4198891e2f1784cb2739: Deleting log segment in path: /tmp/dist-test-taskdBxro6/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515429510153-26595-0/minicluster-data/ts-0-root/wals/55c19a10c522408d95ff7c287ab82f51/wal-000000022 (ops 106-110)
I20260812 06:17:19.475538 26920 log.cc:1079] T 55c19a10c522408d95ff7c287ab82f51 P 66b138bc169a4198891e2f1784cb2739: Deleting log segment in path: /tmp/dist-test-taskdBxro6/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515429510153-26595-0/minicluster-data/ts-0-root/wals/55c19a10c522408d95ff7c287ab82f51/wal-000000023 (ops 111-115)
I20260812 06:17:19.475572 26920 log.cc:1079] T 55c19a10c522408d95ff7c287ab82f51 P 66b138bc169a4198891e2f1784cb2739: Deleting log segment in path: /tmp/dist-test-taskdBxro6/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515429510153-26595-0/minicluster-data/ts-0-root/wals/55c19a10c522408d95ff7c287ab82f51/wal-000000024 (ops 116-120)
I20260812 06:17:19.475607 26920 log.cc:1079] T 55c19a10c522408d95ff7c287ab82f51 P 66b138bc169a4198891e2f1784cb2739: Deleting log segment in path: /tmp/dist-test-taskdBxro6/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515429510153-26595-0/minicluster-data/ts-0-root/wals/55c19a10c522408d95ff7c287ab82f51/wal-000000025 (ops 121-125)
I20260812 06:17:19.475639 26920 log.cc:1079] T 55c19a10c522408d95ff7c287ab82f51 P 66b138bc169a4198891e2f1784cb2739: Deleting log segment in path: /tmp/dist-test-taskdBxro6/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515429510153-26595-0/minicluster-data/ts-0-root/wals/55c19a10c522408d95ff7c287ab82f51/wal-000000026 (ops 126-130)
I20260812 06:17:19.475667 26920 log.cc:1079] T 55c19a10c522408d95ff7c287ab82f51 P 66b138bc169a4198891e2f1784cb2739: Deleting log segment in path: /tmp/dist-test-taskdBxro6/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515429510153-26595-0/minicluster-data/ts-0-root/wals/55c19a10c522408d95ff7c287ab82f51/wal-000000027 (ops 131-135)
I20260812 06:17:19.508064 26920 maintenance_manager.cc:643] P 66b138bc169a4198891e2f1784cb2739: LogGCOp(55c19a10c522408d95ff7c287ab82f51) complete. Timing: real 0.033s	user 0.000s	sys 0.029s Metrics: {}
I20260812 06:17:19.508598 26987 maintenance_manager.cc:419] P 66b138bc169a4198891e2f1784cb2739: Scheduling UndoDeltaBlockGCOp(55c19a10c522408d95ff7c287ab82f51): 493 bytes on disk
I20260812 06:17:19.509111 26920 maintenance_manager.cc:643] P 66b138bc169a4198891e2f1784cb2739: UndoDeltaBlockGCOp(55c19a10c522408d95ff7c287ab82f51) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":48,"lbm_reads_lt_1ms":4}
I20260812 06:17:19.509932 26987 maintenance_manager.cc:419] P 66b138bc169a4198891e2f1784cb2739: Scheduling FlushDeltaMemStoresOp(55c19a10c522408d95ff7c287ab82f51): perf score=2.188937
I20260812 06:17:19.529853 26920 maintenance_manager.cc:643] P 66b138bc169a4198891e2f1784cb2739: FlushDeltaMemStoresOp(55c19a10c522408d95ff7c287ab82f51) complete. Timing: real 0.020s	user 0.010s	sys 0.001s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4599,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:19.530308 26987 maintenance_manager.cc:419] P 66b138bc169a4198891e2f1784cb2739: Scheduling FlushDeltaMemStoresOp(55c19a10c522408d95ff7c287ab82f51): perf score=2.188937
I20260812 06:17:19.540762 26920 maintenance_manager.cc:643] P 66b138bc169a4198891e2f1784cb2739: FlushDeltaMemStoresOp(55c19a10c522408d95ff7c287ab82f51) complete. Timing: real 0.010s	user 0.002s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3997,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:19.541254 26987 maintenance_manager.cc:419] P 66b138bc169a4198891e2f1784cb2739: Scheduling MajorDeltaCompactionOp(55c19a10c522408d95ff7c287ab82f51): perf score=1.000000
I20260812 06:17:19.790889 26920 maintenance_manager.cc:643] P 66b138bc169a4198891e2f1784cb2739: MajorDeltaCompactionOp(55c19a10c522408d95ff7c287ab82f51) complete. Timing: real 0.249s	user 0.162s	sys 0.076s 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":615,"lbm_read_time_us":16407,"lbm_reads_lt_1ms":774,"lbm_write_time_us":38896,"lbm_writes_lt_1ms":743,"mutex_wait_us":63,"peak_mem_usage":87969044,"reinsert_count":0,"spinlock_wait_cycles":768,"thread_start_us":87,"threads_started":1,"update_count":3500}
I20260812 06:17:19.791653 26987 maintenance_manager.cc:419] P 66b138bc169a4198891e2f1784cb2739: Scheduling FlushDeltaMemStoresOp(55c19a10c522408d95ff7c287ab82f51): perf score=18.063937
I20260812 06:17:19.859059 26920 maintenance_manager.cc:643] P 66b138bc169a4198891e2f1784cb2739: FlushDeltaMemStoresOp(55c19a10c522408d95ff7c287ab82f51) complete. Timing: real 0.067s	user 0.032s	sys 0.031s Metrics: {"bytes_written":20512316,"delete_count":0,"lbm_write_time_us":32983,"lbm_writes_1-10_ms":2,"lbm_writes_lt_1ms":501,"reinsert_count":0,"update_count":2500}
I20260812 06:17:19.859530 26987 maintenance_manager.cc:419] P 66b138bc169a4198891e2f1784cb2739: Scheduling FlushDeltaMemStoresOp(55c19a10c522408d95ff7c287ab82f51): perf score=2.188937
I20260812 06:17:19.870002 26920 maintenance_manager.cc:643] P 66b138bc169a4198891e2f1784cb2739: FlushDeltaMemStoresOp(55c19a10c522408d95ff7c287ab82f51) complete. Timing: real 0.010s	user 0.001s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4002,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:19.870513 26987 maintenance_manager.cc:419] P 66b138bc169a4198891e2f1784cb2739: Scheduling MajorDeltaCompactionOp(55c19a10c522408d95ff7c287ab82f51): perf score=1.000000
I20260812 06:17:20.076671 26920 maintenance_manager.cc:643] P 66b138bc169a4198891e2f1784cb2739: MajorDeltaCompactionOp(55c19a10c522408d95ff7c287ab82f51) complete. Timing: real 0.206s	user 0.133s	sys 0.067s Metrics: {"cfile_cache_miss":632,"cfile_cache_miss_bytes":28877103,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":1559,"lbm_read_time_us":15547,"lbm_reads_lt_1ms":672,"lbm_write_time_us":35053,"lbm_writes_lt_1ms":643,"mutex_wait_us":321,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":1408,"update_count":3000}
I20260812 06:17:20.077234 26987 maintenance_manager.cc:419] P 66b138bc169a4198891e2f1784cb2739: Scheduling FlushDeltaMemStoresOp(55c19a10c522408d95ff7c287ab82f51): perf score=16.079562
I20260812 06:17:20.140242 26920 maintenance_manager.cc:643] P 66b138bc169a4198891e2f1784cb2739: FlushDeltaMemStoresOp(55c19a10c522408d95ff7c287ab82f51) complete. Timing: real 0.063s	user 0.036s	sys 0.018s Metrics: {"bytes_written":18379059,"delete_count":0,"lbm_write_time_us":26634,"lbm_writes_lt_1ms":451,"reinsert_count":0,"update_count":2240}
I20260812 06:17:20.140739 26987 maintenance_manager.cc:419] P 66b138bc169a4198891e2f1784cb2739: Scheduling FlushDeltaMemStoresOp(55c19a10c522408d95ff7c287ab82f51): perf score=4.173312
I20260812 06:17:20.157814 26920 maintenance_manager.cc:643] P 66b138bc169a4198891e2f1784cb2739: FlushDeltaMemStoresOp(55c19a10c522408d95ff7c287ab82f51) complete. Timing: real 0.017s	user 0.015s	sys 0.001s Metrics: {"bytes_written":6235925,"delete_count":0,"lbm_write_time_us":6946,"lbm_writes_lt_1ms":155,"reinsert_count":0,"update_count":760}
I20260812 06:17:20.158301 26987 maintenance_manager.cc:419] P 66b138bc169a4198891e2f1784cb2739: Scheduling MajorDeltaCompactionOp(55c19a10c522408d95ff7c287ab82f51): perf score=1.000000
I20260812 06:17:20.372895 26920 maintenance_manager.cc:643] P 66b138bc169a4198891e2f1784cb2739: MajorDeltaCompactionOp(55c19a10c522408d95ff7c287ab82f51) complete. Timing: real 0.214s	user 0.151s	sys 0.060s Metrics: {"cfile_cache_miss":632,"cfile_cache_miss_bytes":28877106,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":713,"lbm_read_time_us":13886,"lbm_reads_lt_1ms":672,"lbm_write_time_us":36994,"lbm_writes_lt_1ms":643,"mutex_wait_us":339,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":51456,"update_count":3000}
I20260812 06:17:20.373703 26987 maintenance_manager.cc:419] P 66b138bc169a4198891e2f1784cb2739: Scheduling FlushDeltaMemStoresOp(55c19a10c522408d95ff7c287ab82f51): perf score=16.079562
I20260812 06:17:20.443608 26920 maintenance_manager.cc:643] P 66b138bc169a4198891e2f1784cb2739: FlushDeltaMemStoresOp(55c19a10c522408d95ff7c287ab82f51) complete. Timing: real 0.070s	user 0.030s	sys 0.024s Metrics: {"bytes_written":18214959,"delete_count":0,"lbm_write_time_us":26025,"lbm_writes_lt_1ms":447,"reinsert_count":0,"update_count":2220}
I20260812 06:17:20.444171 26987 maintenance_manager.cc:419] P 66b138bc169a4198891e2f1784cb2739: Scheduling FlushDeltaMemStoresOp(55c19a10c522408d95ff7c287ab82f51): perf score=5.165500
I20260812 06:17:20.468961 26920 maintenance_manager.cc:643] P 66b138bc169a4198891e2f1784cb2739: FlushDeltaMemStoresOp(55c19a10c522408d95ff7c287ab82f51) complete. Timing: real 0.025s	user 0.009s	sys 0.015s Metrics: {"bytes_written":6400021,"delete_count":0,"lbm_write_time_us":10129,"lbm_writes_lt_1ms":159,"reinsert_count":0,"update_count":780}
I20260812 06:17:20.469542 26987 maintenance_manager.cc:419] P 66b138bc169a4198891e2f1784cb2739: Scheduling MajorDeltaCompactionOp(55c19a10c522408d95ff7c287ab82f51): perf score=1.000000
I20260812 06:17:20.669621 26920 maintenance_manager.cc:643] P 66b138bc169a4198891e2f1784cb2739: MajorDeltaCompactionOp(55c19a10c522408d95ff7c287ab82f51) complete. Timing: real 0.200s	user 0.128s	sys 0.072s Metrics: {"cfile_cache_miss":632,"cfile_cache_miss_bytes":28877102,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":784,"lbm_read_time_us":15912,"lbm_reads_lt_1ms":664,"lbm_write_time_us":32640,"lbm_writes_lt_1ms":643,"mutex_wait_us":70,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":27520,"update_count":3000}
I20260812 06:17:20.670517 26987 maintenance_manager.cc:419] P 66b138bc169a4198891e2f1784cb2739: Scheduling FlushDeltaMemStoresOp(55c19a10c522408d95ff7c287ab82f51): perf score=14.095187
I20260812 06:17:20.724823 26920 maintenance_manager.cc:643] P 66b138bc169a4198891e2f1784cb2739: FlushDeltaMemStoresOp(55c19a10c522408d95ff7c287ab82f51) complete. Timing: real 0.054s	user 0.040s	sys 0.012s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":23676,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:17:20.725364 26987 maintenance_manager.cc:419] P 66b138bc169a4198891e2f1784cb2739: Scheduling FlushDeltaMemStoresOp(55c19a10c522408d95ff7c287ab82f51): perf score=2.188937
I20260812 06:17:20.737600 26920 maintenance_manager.cc:643] P 66b138bc169a4198891e2f1784cb2739: FlushDeltaMemStoresOp(55c19a10c522408d95ff7c287ab82f51) complete. Timing: real 0.012s	user 0.007s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4284,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:20.738197 26987 maintenance_manager.cc:419] P 66b138bc169a4198891e2f1784cb2739: Scheduling MajorDeltaCompactionOp(55c19a10c522408d95ff7c287ab82f51): perf score=1.000000
I20260812 06:17:20.912597 26920 maintenance_manager.cc:643] P 66b138bc169a4198891e2f1784cb2739: MajorDeltaCompactionOp(55c19a10c522408d95ff7c287ab82f51) complete. Timing: real 0.174s	user 0.109s	sys 0.063s 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":534,"lbm_read_time_us":13116,"lbm_reads_lt_1ms":572,"lbm_write_time_us":29235,"lbm_writes_lt_1ms":543,"mutex_wait_us":38,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":8960,"update_count":2500}
I20260812 06:17:20.914541 26987 maintenance_manager.cc:419] P 66b138bc169a4198891e2f1784cb2739: Scheduling FlushDeltaMemStoresOp(55c19a10c522408d95ff7c287ab82f51): perf score=14.095187
I20260812 06:17:20.967444 26920 maintenance_manager.cc:643] P 66b138bc169a4198891e2f1784cb2739: FlushDeltaMemStoresOp(55c19a10c522408d95ff7c287ab82f51) complete. Timing: real 0.052s	user 0.024s	sys 0.025s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":22224,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:17:20.967999 26987 maintenance_manager.cc:419] P 66b138bc169a4198891e2f1784cb2739: Scheduling FlushDeltaMemStoresOp(55c19a10c522408d95ff7c287ab82f51): perf score=2.188937
I20260812 06:17:20.983548 26920 maintenance_manager.cc:643] P 66b138bc169a4198891e2f1784cb2739: FlushDeltaMemStoresOp(55c19a10c522408d95ff7c287ab82f51) complete. Timing: real 0.015s	user 0.014s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6201,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:20.984032 26987 maintenance_manager.cc:419] P 66b138bc169a4198891e2f1784cb2739: Scheduling FlushMRSOp(55c19a10c522408d95ff7c287ab82f51): perf score=1.000000
I20260812 06:17:21.012149 26920 maintenance_manager.cc:643] P 66b138bc169a4198891e2f1784cb2739: FlushMRSOp(55c19a10c522408d95ff7c287ab82f51) complete. Timing: real 0.028s	user 0.019s	sys 0.007s Metrics: {"bytes_written":1275447,"cfile_init":1,"dirs.queue_time_us":85,"dirs.run_cpu_time_us":248,"dirs.run_wall_time_us":1253,"drs_written":1,"lbm_read_time_us":56,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1976,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":31}
I20260812 06:17:21.012933 26987 maintenance_manager.cc:419] P 66b138bc169a4198891e2f1784cb2739: Scheduling LogGCOp(55c19a10c522408d95ff7c287ab82f51): free 124257573 bytes of WAL
I20260812 06:17:21.013222 26920 log_reader.cc:385] T 55c19a10c522408d95ff7c287ab82f51: removed 12 log segments from log reader
I20260812 06:17:21.013310 26920 log.cc:1079] T 55c19a10c522408d95ff7c287ab82f51 P 66b138bc169a4198891e2f1784cb2739: Deleting log segment in path: /tmp/dist-test-taskdBxro6/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515429510153-26595-0/minicluster-data/ts-0-root/wals/55c19a10c522408d95ff7c287ab82f51/wal-000000028 (ops 136-140)
I20260812 06:17:21.013370 26920 log.cc:1079] T 55c19a10c522408d95ff7c287ab82f51 P 66b138bc169a4198891e2f1784cb2739: Deleting log segment in path: /tmp/dist-test-taskdBxro6/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515429510153-26595-0/minicluster-data/ts-0-root/wals/55c19a10c522408d95ff7c287ab82f51/wal-000000029 (ops 141-145)
I20260812 06:17:21.013437 26920 log.cc:1079] T 55c19a10c522408d95ff7c287ab82f51 P 66b138bc169a4198891e2f1784cb2739: Deleting log segment in path: /tmp/dist-test-taskdBxro6/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515429510153-26595-0/minicluster-data/ts-0-root/wals/55c19a10c522408d95ff7c287ab82f51/wal-000000030 (ops 146-150)
I20260812 06:17:21.013484 26920 log.cc:1079] T 55c19a10c522408d95ff7c287ab82f51 P 66b138bc169a4198891e2f1784cb2739: Deleting log segment in path: /tmp/dist-test-taskdBxro6/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515429510153-26595-0/minicluster-data/ts-0-root/wals/55c19a10c522408d95ff7c287ab82f51/wal-000000031 (ops 151-154)
I20260812 06:17:21.013520 26920 log.cc:1079] T 55c19a10c522408d95ff7c287ab82f51 P 66b138bc169a4198891e2f1784cb2739: Deleting log segment in path: /tmp/dist-test-taskdBxro6/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515429510153-26595-0/minicluster-data/ts-0-root/wals/55c19a10c522408d95ff7c287ab82f51/wal-000000032 (ops 155-159)
I20260812 06:17:21.013567 26920 log.cc:1079] T 55c19a10c522408d95ff7c287ab82f51 P 66b138bc169a4198891e2f1784cb2739: Deleting log segment in path: /tmp/dist-test-taskdBxro6/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515429510153-26595-0/minicluster-data/ts-0-root/wals/55c19a10c522408d95ff7c287ab82f51/wal-000000033 (ops 160-164)
I20260812 06:17:21.013607 26920 log.cc:1079] T 55c19a10c522408d95ff7c287ab82f51 P 66b138bc169a4198891e2f1784cb2739: Deleting log segment in path: /tmp/dist-test-taskdBxro6/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515429510153-26595-0/minicluster-data/ts-0-root/wals/55c19a10c522408d95ff7c287ab82f51/wal-000000034 (ops 165-169)
I20260812 06:17:21.013657 26920 log.cc:1079] T 55c19a10c522408d95ff7c287ab82f51 P 66b138bc169a4198891e2f1784cb2739: Deleting log segment in path: /tmp/dist-test-taskdBxro6/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515429510153-26595-0/minicluster-data/ts-0-root/wals/55c19a10c522408d95ff7c287ab82f51/wal-000000035 (ops 170-174)
I20260812 06:17:21.013697 26920 log.cc:1079] T 55c19a10c522408d95ff7c287ab82f51 P 66b138bc169a4198891e2f1784cb2739: Deleting log segment in path: /tmp/dist-test-taskdBxro6/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515429510153-26595-0/minicluster-data/ts-0-root/wals/55c19a10c522408d95ff7c287ab82f51/wal-000000036 (ops 175-179)
I20260812 06:17:21.013737 26920 log.cc:1079] T 55c19a10c522408d95ff7c287ab82f51 P 66b138bc169a4198891e2f1784cb2739: Deleting log segment in path: /tmp/dist-test-taskdBxro6/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515429510153-26595-0/minicluster-data/ts-0-root/wals/55c19a10c522408d95ff7c287ab82f51/wal-000000037 (ops 180-184)
I20260812 06:17:21.013778 26920 log.cc:1079] T 55c19a10c522408d95ff7c287ab82f51 P 66b138bc169a4198891e2f1784cb2739: Deleting log segment in path: /tmp/dist-test-taskdBxro6/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515429510153-26595-0/minicluster-data/ts-0-root/wals/55c19a10c522408d95ff7c287ab82f51/wal-000000038 (ops 185-189)
I20260812 06:17:21.013820 26920 log.cc:1079] T 55c19a10c522408d95ff7c287ab82f51 P 66b138bc169a4198891e2f1784cb2739: Deleting log segment in path: /tmp/dist-test-taskdBxro6/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515429510153-26595-0/minicluster-data/ts-0-root/wals/55c19a10c522408d95ff7c287ab82f51/wal-000000039 (ops 190-194)
I20260812 06:17:21.044759 26920 maintenance_manager.cc:643] P 66b138bc169a4198891e2f1784cb2739: LogGCOp(55c19a10c522408d95ff7c287ab82f51) complete. Timing: real 0.032s	user 0.000s	sys 0.031s Metrics: {}
I20260812 06:17:21.046043 26987 maintenance_manager.cc:419] P 66b138bc169a4198891e2f1784cb2739: Scheduling UndoDeltaBlockGCOp(55c19a10c522408d95ff7c287ab82f51): 482 bytes on disk
I20260812 06:17:21.046723 26920 maintenance_manager.cc:643] P 66b138bc169a4198891e2f1784cb2739: UndoDeltaBlockGCOp(55c19a10c522408d95ff7c287ab82f51) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":94,"lbm_reads_lt_1ms":4}
I20260812 06:17:21.047464 26987 maintenance_manager.cc:419] P 66b138bc169a4198891e2f1784cb2739: Scheduling FlushDeltaMemStoresOp(55c19a10c522408d95ff7c287ab82f51): perf score=5.165500
I20260812 06:17:21.066545 26920 maintenance_manager.cc:643] P 66b138bc169a4198891e2f1784cb2739: FlushDeltaMemStoresOp(55c19a10c522408d95ff7c287ab82f51) complete. Timing: real 0.019s	user 0.017s	sys 0.000s Metrics: {"bytes_written":6892306,"delete_count":0,"lbm_write_time_us":7899,"lbm_writes_lt_1ms":171,"reinsert_count":0,"update_count":840}
I20260812 06:17:21.067054 26987 maintenance_manager.cc:419] P 66b138bc169a4198891e2f1784cb2739: Scheduling LogGCOp(55c19a10c522408d95ff7c287ab82f51): free 8767140 bytes of WAL
I20260812 06:17:21.067289 26920 log_reader.cc:385] T 55c19a10c522408d95ff7c287ab82f51: removed 1 log segments from log reader
I20260812 06:17:21.067339 26920 log.cc:1079] T 55c19a10c522408d95ff7c287ab82f51 P 66b138bc169a4198891e2f1784cb2739: Deleting log segment in path: /tmp/dist-test-taskdBxro6/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515429510153-26595-0/minicluster-data/ts-0-root/wals/55c19a10c522408d95ff7c287ab82f51/wal-000000040 (ops 195-199)
I20260812 06:17:21.069321 26920 maintenance_manager.cc:643] P 66b138bc169a4198891e2f1784cb2739: LogGCOp(55c19a10c522408d95ff7c287ab82f51) complete. Timing: real 0.002s	user 0.000s	sys 0.001s Metrics: {}
I20260812 06:17:21.069679 26987 maintenance_manager.cc:419] P 66b138bc169a4198891e2f1784cb2739: Scheduling FlushDeltaMemStoresOp(55c19a10c522408d95ff7c287ab82f51): perf score=1.000000
I20260812 06:17:21.077797 26920 maintenance_manager.cc:643] P 66b138bc169a4198891e2f1784cb2739: FlushDeltaMemStoresOp(55c19a10c522408d95ff7c287ab82f51) complete. Timing: real 0.007s	user 0.005s	sys 0.001s Metrics: {"bytes_written":1312952,"delete_count":0,"lbm_write_time_us":2348,"lbm_writes_lt_1ms":35,"reinsert_count":0,"update_count":160}
I20260812 06:17:21.078298 26987 maintenance_manager.cc:419] P 66b138bc169a4198891e2f1784cb2739: Scheduling MajorDeltaCompactionOp(55c19a10c522408d95ff7c287ab82f51): perf score=1.000000
I20260812 06:17:21.095855 26595 heavy-update-compaction-itest.cc:229] Time spent updating: real 5.046s	user 1.847s	sys 0.206s
I20260812 06:17:21.195261 26595 heavy-update-compaction-itest.cc:265] Time spent scanning: real 0.099s	user 0.001s	sys 0.000s
I20260812 06:17:21.195820 26595 tablet_server.cc:179] TabletServer@127.25.248.193:0 shutting down...
I20260812 06:17:21.292199 26920 maintenance_manager.cc:643] P 66b138bc169a4198891e2f1784cb2739: MajorDeltaCompactionOp(55c19a10c522408d95ff7c287ab82f51) complete. Timing: real 0.214s	user 0.143s	sys 0.070s Metrics: {"cfile_cache_miss":734,"cfile_cache_miss_bytes":32979685,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":792,"lbm_read_time_us":18594,"lbm_reads_lt_1ms":770,"lbm_write_time_us":35599,"lbm_writes_lt_1ms":743,"mutex_wait_us":65,"peak_mem_usage":87969044,"reinsert_count":0,"spinlock_wait_cycles":94592,"thread_start_us":110,"threads_started":1,"update_count":3500}
I20260812 06:17:21.294641 26595 ts_tablet_manager.cc:1507] Shutting down tablet manager...
I20260812 06:17:21.295040 26595 tablet_replica.cc:333] T 55c19a10c522408d95ff7c287ab82f51 P 66b138bc169a4198891e2f1784cb2739: stopping tablet replica
I20260812 06:17:21.295228 26595 raft_consensus.cc:2243] T 55c19a10c522408d95ff7c287ab82f51 P 66b138bc169a4198891e2f1784cb2739 [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:17:21.295433 26595 raft_consensus.cc:2272] T 55c19a10c522408d95ff7c287ab82f51 P 66b138bc169a4198891e2f1784cb2739 [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:17:21.299887 26595 tablet_server.cc:196] TabletServer@127.25.248.193:0 shutdown complete.
I20260812 06:17:21.351840 26595 master.cc:562] Master@127.25.248.254:37567 shutting down...
I20260812 06:17:21.355146 26595 raft_consensus.cc:2243] T 00000000000000000000000000000000 P b047e9968d9249bb8dcab814b541180f [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:17:21.355341 26595 raft_consensus.cc:2272] T 00000000000000000000000000000000 P b047e9968d9249bb8dcab814b541180f [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:17:21.355433 26595 tablet_replica.cc:333] T 00000000000000000000000000000000 P b047e9968d9249bb8dcab814b541180f: stopping tablet replica
I20260812 06:17:21.367939 26595 master.cc:584] Master@127.25.248.254:37567 shutdown complete.
[       OK ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/1 (5600 ms)
[----------] 2 tests from EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy (11932 ms total)

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