[==========] 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:55.790807 21826 internal_mini_cluster.cc:156] Creating distributed mini masters. Addrs: 127.21.80.190:43525
I20260812 06:17:55.791767 21826 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:55.792342 21826 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:17:55.798650 21836 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:55.798650 21837 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:55.798928 21826 server_base.cc:1061] running on GCE node
W20260812 06:17:55.798947 21839 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:55.799386 21826 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:17:55.799503 21826 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:55.799566 21826 hybrid_clock.cc:648] HybridClock initialized: now 1786515475799563 us; error 0 us; skew 500 ppm
I20260812 06:17:55.801183 21826 webserver.cc:533] Webserver started at http://127.21.80.190:41197/ using document root <none> and password file <none>
I20260812 06:17:55.801707 21826 fs_manager.cc:362] Metadata directory not provided
I20260812 06:17:55.801795 21826 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:17:55.802063 21826 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:17:55.803809 21826 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskCQqSFo/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515475780686-21826-0/minicluster-data/master-0-root/instance:
uuid: "74036b23fda847e284867a3c589501e2"
format_stamp: "Formatted at 2026-08-12 06:17:55 on dist-test-slave-znh6"
I20260812 06:17:55.807421 21826 fs_manager.cc:696] Time spent creating directory manager: real 0.003s	user 0.004s	sys 0.000s
I20260812 06:17:55.809432 21851 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:55.810365 21826 fs_manager.cc:730] Time spent opening block manager: real 0.002s	user 0.002s	sys 0.000s
I20260812 06:17:55.810497 21826 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskCQqSFo/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515475780686-21826-0/minicluster-data/master-0-root
uuid: "74036b23fda847e284867a3c589501e2"
format_stamp: "Formatted at 2026-08-12 06:17:55 on dist-test-slave-znh6"
I20260812 06:17:55.810607 21826 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskCQqSFo/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515475780686-21826-0/minicluster-data/master-0-root
metadata directory: /tmp/dist-test-taskCQqSFo/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515475780686-21826-0/minicluster-data/master-0-root
1 data directories: /tmp/dist-test-taskCQqSFo/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515475780686-21826-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:55.820638 21826 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:17:55.821179 21826 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:55.821354 21826 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:17:55.828701 21826 rpc_server.cc:307] RPC server started. Bound to: 127.21.80.190:43525
I20260812 06:17:55.828723 21927 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.21.80.190:43525 every 8 connection(s)
I20260812 06:17:55.830801 21928 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:55.836005 21928 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P 74036b23fda847e284867a3c589501e2: Bootstrap starting.
I20260812 06:17:55.838171 21928 tablet_bootstrap.cc:654] T 00000000000000000000000000000000 P 74036b23fda847e284867a3c589501e2: Neither blocks nor log segments found. Creating new log.
I20260812 06:17:55.839035 21928 log.cc:826] T 00000000000000000000000000000000 P 74036b23fda847e284867a3c589501e2: Log is configured to *not* fsync() on all Append() calls
I20260812 06:17:55.840499 21928 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P 74036b23fda847e284867a3c589501e2: No bootstrap required, opened a new log
I20260812 06:17:55.843052 21928 raft_consensus.cc:359] T 00000000000000000000000000000000 P 74036b23fda847e284867a3c589501e2 [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "74036b23fda847e284867a3c589501e2" member_type: VOTER }
I20260812 06:17:55.843204 21928 raft_consensus.cc:385] T 00000000000000000000000000000000 P 74036b23fda847e284867a3c589501e2 [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:17:55.843258 21928 raft_consensus.cc:740] T 00000000000000000000000000000000 P 74036b23fda847e284867a3c589501e2 [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: 74036b23fda847e284867a3c589501e2, State: Initialized, Role: FOLLOWER
I20260812 06:17:55.843734 21928 consensus_queue.cc:260] T 00000000000000000000000000000000 P 74036b23fda847e284867a3c589501e2 [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: "74036b23fda847e284867a3c589501e2" member_type: VOTER }
I20260812 06:17:55.843858 21928 raft_consensus.cc:399] T 00000000000000000000000000000000 P 74036b23fda847e284867a3c589501e2 [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:17:55.843902 21928 raft_consensus.cc:493] T 00000000000000000000000000000000 P 74036b23fda847e284867a3c589501e2 [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:17:55.843983 21928 raft_consensus.cc:3060] T 00000000000000000000000000000000 P 74036b23fda847e284867a3c589501e2 [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:17:55.844645 21928 raft_consensus.cc:515] T 00000000000000000000000000000000 P 74036b23fda847e284867a3c589501e2 [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "74036b23fda847e284867a3c589501e2" member_type: VOTER }
I20260812 06:17:55.844995 21928 leader_election.cc:304] T 00000000000000000000000000000000 P 74036b23fda847e284867a3c589501e2 [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: 74036b23fda847e284867a3c589501e2; no voters: 
I20260812 06:17:55.845232 21928 leader_election.cc:290] T 00000000000000000000000000000000 P 74036b23fda847e284867a3c589501e2 [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:17:55.845391 21933 raft_consensus.cc:2804] T 00000000000000000000000000000000 P 74036b23fda847e284867a3c589501e2 [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:17:55.845647 21933 raft_consensus.cc:697] T 00000000000000000000000000000000 P 74036b23fda847e284867a3c589501e2 [term 1 LEADER]: Becoming Leader. State: Replica: 74036b23fda847e284867a3c589501e2, State: Running, Role: LEADER
I20260812 06:17:55.846035 21933 consensus_queue.cc:237] T 00000000000000000000000000000000 P 74036b23fda847e284867a3c589501e2 [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: "74036b23fda847e284867a3c589501e2" member_type: VOTER }
I20260812 06:17:55.846154 21928 sys_catalog.cc:565] T 00000000000000000000000000000000 P 74036b23fda847e284867a3c589501e2 [sys.catalog]: configured and running, proceeding with master startup.
I20260812 06:17:55.847908 21935 sys_catalog.cc:455] T 00000000000000000000000000000000 P 74036b23fda847e284867a3c589501e2 [sys.catalog]: SysCatalogTable state changed. Reason: New leader 74036b23fda847e284867a3c589501e2. Latest consensus state: current_term: 1 leader_uuid: "74036b23fda847e284867a3c589501e2" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "74036b23fda847e284867a3c589501e2" member_type: VOTER } }
I20260812 06:17:55.847947 21934 sys_catalog.cc:455] T 00000000000000000000000000000000 P 74036b23fda847e284867a3c589501e2 [sys.catalog]: SysCatalogTable state changed. Reason: RaftConsensus started. Latest consensus state: current_term: 1 leader_uuid: "74036b23fda847e284867a3c589501e2" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "74036b23fda847e284867a3c589501e2" member_type: VOTER } }
I20260812 06:17:55.848021 21935 sys_catalog.cc:458] T 00000000000000000000000000000000 P 74036b23fda847e284867a3c589501e2 [sys.catalog]: This master's current role is: LEADER
I20260812 06:17:55.848054 21934 sys_catalog.cc:458] T 00000000000000000000000000000000 P 74036b23fda847e284867a3c589501e2 [sys.catalog]: This master's current role is: LEADER
I20260812 06:17:55.848358 21951 catalog_manager.cc:1511] Loading table and tablet metadata into memory...
I20260812 06:17:55.848464 21826 internal_mini_cluster.cc:184] Waiting to initialize catalog manager on master 0
I20260812 06:17:55.850653 21951 catalog_manager.cc:1520] Initializing Kudu cluster ID...
I20260812 06:17:55.854939 21951 catalog_manager.cc:1383] Generated new cluster ID: 22a9e0a4dc4640edad26be7b9e127a9b
I20260812 06:17:55.855000 21951 catalog_manager.cc:1531] Initializing Kudu internal certificate authority...
I20260812 06:17:55.883929 21951 catalog_manager.cc:1406] Generated new certificate authority record
I20260812 06:17:55.884893 21951 catalog_manager.cc:1540] Loading token signing keys...
I20260812 06:17:55.893386 21951 catalog_manager.cc:6092] T 00000000000000000000000000000000 P 74036b23fda847e284867a3c589501e2: Generated new TSK 0
I20260812 06:17:55.893942 21951 catalog_manager.cc:1550] Initializing in-progress tserver states...
I20260812 06:17:55.913120 21826 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:17:55.915879 21970 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:55.915970 21966 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:55.916024 21973 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:55.916282 21826 server_base.cc:1061] running on GCE node
I20260812 06:17:55.916465 21826 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:17:55.916520 21826 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:55.916554 21826 hybrid_clock.cc:648] HybridClock initialized: now 1786515475916553 us; error 0 us; skew 500 ppm
I20260812 06:17:55.917500 21826 webserver.cc:533] Webserver started at http://127.21.80.129:44517/ using document root <none> and password file <none>
I20260812 06:17:55.917683 21826 fs_manager.cc:362] Metadata directory not provided
I20260812 06:17:55.917753 21826 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:17:55.917830 21826 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:17:55.918224 21826 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskCQqSFo/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515475780686-21826-0/minicluster-data/ts-0-root/instance:
uuid: "ead5f2336a04427480deb54762779c17"
format_stamp: "Formatted at 2026-08-12 06:17:55 on dist-test-slave-znh6"
I20260812 06:17:55.919873 21826 fs_manager.cc:696] Time spent creating directory manager: real 0.001s	user 0.000s	sys 0.002s
I20260812 06:17:55.920872 21981 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:55.921111 21826 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.000s	sys 0.001s
I20260812 06:17:55.921185 21826 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskCQqSFo/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515475780686-21826-0/minicluster-data/ts-0-root
uuid: "ead5f2336a04427480deb54762779c17"
format_stamp: "Formatted at 2026-08-12 06:17:55 on dist-test-slave-znh6"
I20260812 06:17:55.921280 21826 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskCQqSFo/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515475780686-21826-0/minicluster-data/ts-0-root
metadata directory: /tmp/dist-test-taskCQqSFo/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515475780686-21826-0/minicluster-data/ts-0-root
1 data directories: /tmp/dist-test-taskCQqSFo/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515475780686-21826-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:55.927269 21826 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:17:55.927630 21826 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:17:55.928077 21826 txn_system_client.cc:432] TxnSystemClient initialization is disabled...
I20260812 06:17:55.928884 21826 ts_tablet_manager.cc:585] Loaded tablet metadata (0 total tablets, 0 live tablets)
I20260812 06:17:55.928936 21826 ts_tablet_manager.cc:531] Time spent load tablet metadata: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:17:55.928998 21826 ts_tablet_manager.cc:616] Registered 0 tablets
I20260812 06:17:55.929040 21826 ts_tablet_manager.cc:595] Time spent register tablets: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:17:55.935875 21826 rpc_server.cc:307] RPC server started. Bound to: 127.21.80.129:41615
I20260812 06:17:55.935936 22082 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.21.80.129:41615 every 8 connection(s)
I20260812 06:17:55.945403 22083 heartbeater.cc:344] Connected to a master server at 127.21.80.190:43525
I20260812 06:17:55.945626 22083 heartbeater.cc:461] Registering TS with master...
I20260812 06:17:55.946010 22083 heartbeater.cc:507] Master 127.21.80.190:43525 requested a full tablet report, sending...
I20260812 06:17:55.948053 21872 ts_manager.cc:194] Registered new tserver with Master: ead5f2336a04427480deb54762779c17 (127.21.80.129:41615)
I20260812 06:17:55.949508 21826 internal_mini_cluster.cc:371] 1 TS(s) registered with all masters after 0.013008705s
I20260812 06:17:55.949546 21872 master_service.cc:502] Signed X509 certificate for tserver {username='slave'} at 127.0.0.1:46576
I20260812 06:17:55.958305 21872 catalog_manager.cc:2283] Servicing CreateTable request from {username='slave'} at 127.0.0.1:46586:
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:55.970993 22023 tablet_service.cc:1511] Processing CreateTablet for tablet 1ff0bf7f1072443fb49179a247de166a (DEFAULT_TABLE table=heavy-update-compaction-test [id=b45707490fc24c6db217d9a30d3e8327]), partition=
I20260812 06:17:55.971402 22023 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet 1ff0bf7f1072443fb49179a247de166a. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:17:55.973711 22105 tablet_bootstrap.cc:492] T 1ff0bf7f1072443fb49179a247de166a P ead5f2336a04427480deb54762779c17: Bootstrap starting.
I20260812 06:17:55.974768 22105 tablet_bootstrap.cc:654] T 1ff0bf7f1072443fb49179a247de166a P ead5f2336a04427480deb54762779c17: Neither blocks nor log segments found. Creating new log.
I20260812 06:17:55.976033 22105 tablet_bootstrap.cc:492] T 1ff0bf7f1072443fb49179a247de166a P ead5f2336a04427480deb54762779c17: No bootstrap required, opened a new log
I20260812 06:17:55.976140 22105 ts_tablet_manager.cc:1403] T 1ff0bf7f1072443fb49179a247de166a P ead5f2336a04427480deb54762779c17: Time spent bootstrapping tablet: real 0.003s	user 0.000s	sys 0.002s
I20260812 06:17:55.976663 22105 raft_consensus.cc:359] T 1ff0bf7f1072443fb49179a247de166a P ead5f2336a04427480deb54762779c17 [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "ead5f2336a04427480deb54762779c17" member_type: VOTER last_known_addr { host: "127.21.80.129" port: 41615 } }
I20260812 06:17:55.976792 22105 raft_consensus.cc:385] T 1ff0bf7f1072443fb49179a247de166a P ead5f2336a04427480deb54762779c17 [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:17:55.976838 22105 raft_consensus.cc:740] T 1ff0bf7f1072443fb49179a247de166a P ead5f2336a04427480deb54762779c17 [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: ead5f2336a04427480deb54762779c17, State: Initialized, Role: FOLLOWER
I20260812 06:17:55.976984 22105 consensus_queue.cc:260] T 1ff0bf7f1072443fb49179a247de166a P ead5f2336a04427480deb54762779c17 [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: "ead5f2336a04427480deb54762779c17" member_type: VOTER last_known_addr { host: "127.21.80.129" port: 41615 } }
I20260812 06:17:55.977097 22105 raft_consensus.cc:399] T 1ff0bf7f1072443fb49179a247de166a P ead5f2336a04427480deb54762779c17 [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:17:55.977146 22105 raft_consensus.cc:493] T 1ff0bf7f1072443fb49179a247de166a P ead5f2336a04427480deb54762779c17 [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:17:55.977198 22105 raft_consensus.cc:3060] T 1ff0bf7f1072443fb49179a247de166a P ead5f2336a04427480deb54762779c17 [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:17:55.978679 22105 raft_consensus.cc:515] T 1ff0bf7f1072443fb49179a247de166a P ead5f2336a04427480deb54762779c17 [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "ead5f2336a04427480deb54762779c17" member_type: VOTER last_known_addr { host: "127.21.80.129" port: 41615 } }
I20260812 06:17:55.978858 22105 leader_election.cc:304] T 1ff0bf7f1072443fb49179a247de166a P ead5f2336a04427480deb54762779c17 [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: ead5f2336a04427480deb54762779c17; no voters: 
I20260812 06:17:55.979063 22105 leader_election.cc:290] T 1ff0bf7f1072443fb49179a247de166a P ead5f2336a04427480deb54762779c17 [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:17:55.979200 22107 raft_consensus.cc:2804] T 1ff0bf7f1072443fb49179a247de166a P ead5f2336a04427480deb54762779c17 [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:17:55.979478 22105 ts_tablet_manager.cc:1434] T 1ff0bf7f1072443fb49179a247de166a P ead5f2336a04427480deb54762779c17: Time spent starting tablet: real 0.003s	user 0.003s	sys 0.001s
I20260812 06:17:55.979718 22083 heartbeater.cc:499] Master 127.21.80.190:43525 was elected leader, sending a full tablet report...
I20260812 06:17:55.979775 22107 raft_consensus.cc:697] T 1ff0bf7f1072443fb49179a247de166a P ead5f2336a04427480deb54762779c17 [term 1 LEADER]: Becoming Leader. State: Replica: ead5f2336a04427480deb54762779c17, State: Running, Role: LEADER
I20260812 06:17:55.980000 22107 consensus_queue.cc:237] T 1ff0bf7f1072443fb49179a247de166a P ead5f2336a04427480deb54762779c17 [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: "ead5f2336a04427480deb54762779c17" member_type: VOTER last_known_addr { host: "127.21.80.129" port: 41615 } }
I20260812 06:17:55.982595 21872 catalog_manager.cc:5719] T 1ff0bf7f1072443fb49179a247de166a P ead5f2336a04427480deb54762779c17 reported cstate change: term changed from 0 to 1, leader changed from <none> to ead5f2336a04427480deb54762779c17 (127.21.80.129). New cstate: current_term: 1 leader_uuid: "ead5f2336a04427480deb54762779c17" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "ead5f2336a04427480deb54762779c17" member_type: VOTER last_known_addr { host: "127.21.80.129" port: 41615 } health_report { overall_health: HEALTHY } } }
I20260812 06:17:56.048607 21826 heavy-update-compaction-itest.cc:215] Time spent inserting: real 0.056s	user 0.018s	sys 0.009s
I20260812 06:17:56.187145 22089 maintenance_manager.cc:419] P ead5f2336a04427480deb54762779c17: Scheduling FlushMRSOp(1ff0bf7f1072443fb49179a247de166a): perf score=19.054940
I20260812 06:17:56.385282 21991 maintenance_manager.cc:643] P ead5f2336a04427480deb54762779c17: FlushMRSOp(1ff0bf7f1072443fb49179a247de166a) complete. Timing: real 0.198s	user 0.151s	sys 0.044s Metrics: {"bytes_written":16409901,"cfile_init":1,"compiler_manager_pool.queue_time_us":398,"delete_count":0,"dirs.queue_time_us":45,"dirs.run_cpu_time_us":210,"dirs.run_wall_time_us":774,"drs_written":1,"lbm_read_time_us":73,"lbm_reads_lt_1ms":4,"lbm_write_time_us":49915,"lbm_writes_lt_1ms":857,"peak_mem_usage":0,"reinsert_count":0,"rows_written":104,"thread_start_us":151,"threads_started":1,"update_count":2000}
I20260812 06:17:56.386564 22089 maintenance_manager.cc:419] P ead5f2336a04427480deb54762779c17: Scheduling LogGCOp(1ff0bf7f1072443fb49179a247de166a): free 20743880 bytes of WAL
I20260812 06:17:56.386967 21991 log_reader.cc:385] T 1ff0bf7f1072443fb49179a247de166a: removed 2 log segments from log reader
I20260812 06:17:56.387086 21991 log.cc:1079] T 1ff0bf7f1072443fb49179a247de166a P ead5f2336a04427480deb54762779c17: Deleting log segment in path: /tmp/dist-test-taskCQqSFo/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515475780686-21826-0/minicluster-data/ts-0-root/wals/1ff0bf7f1072443fb49179a247de166a/wal-000000001 (ops 1-6)
I20260812 06:17:56.387176 21991 log.cc:1079] T 1ff0bf7f1072443fb49179a247de166a P ead5f2336a04427480deb54762779c17: Deleting log segment in path: /tmp/dist-test-taskCQqSFo/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515475780686-21826-0/minicluster-data/ts-0-root/wals/1ff0bf7f1072443fb49179a247de166a/wal-000000002 (ops 7-11)
I20260812 06:17:56.392671 21991 maintenance_manager.cc:643] P ead5f2336a04427480deb54762779c17: LogGCOp(1ff0bf7f1072443fb49179a247de166a) complete. Timing: real 0.006s	user 0.001s	sys 0.003s Metrics: {}
I20260812 06:17:56.393013 22089 maintenance_manager.cc:419] P ead5f2336a04427480deb54762779c17: Scheduling FlushDeltaMemStoresOp(1ff0bf7f1072443fb49179a247de166a): perf score=6.157687
I20260812 06:17:56.421916 21991 maintenance_manager.cc:643] P ead5f2336a04427480deb54762779c17: FlushDeltaMemStoresOp(1ff0bf7f1072443fb49179a247de166a) complete. Timing: real 0.029s	user 0.020s	sys 0.004s Metrics: {"bytes_written":7671762,"delete_count":0,"lbm_write_time_us":11351,"lbm_writes_lt_1ms":190,"reinsert_count":0,"update_count":935}
I20260812 06:17:56.422636 22089 maintenance_manager.cc:419] P ead5f2336a04427480deb54762779c17: Scheduling MajorDeltaCompactionOp(1ff0bf7f1072443fb49179a247de166a): perf score=1.000000
I20260812 06:17:56.611882 21991 maintenance_manager.cc:643] P ead5f2336a04427480deb54762779c17: MajorDeltaCompactionOp(1ff0bf7f1072443fb49179a247de166a) complete. Timing: real 0.189s	user 0.121s	sys 0.057s Metrics: {"cfile_cache_miss":619,"cfile_cache_miss_bytes":28343785,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":443,"lbm_read_time_us":11545,"lbm_reads_lt_1ms":651,"lbm_write_time_us":32841,"lbm_writes_lt_1ms":630,"peak_mem_usage":73968633,"reinsert_count":0,"spinlock_wait_cycles":768,"thread_start_us":226,"threads_started":5,"update_count":2935}
I20260812 06:17:56.612393 22089 maintenance_manager.cc:419] P ead5f2336a04427480deb54762779c17: Scheduling FlushDeltaMemStoresOp(1ff0bf7f1072443fb49179a247de166a): perf score=15.087375
I20260812 06:17:56.673493 21991 maintenance_manager.cc:643] P ead5f2336a04427480deb54762779c17: FlushDeltaMemStoresOp(1ff0bf7f1072443fb49179a247de166a) complete. Timing: real 0.061s	user 0.026s	sys 0.032s Metrics: {"bytes_written":16943222,"delete_count":0,"lbm_write_time_us":29256,"lbm_writes_1-10_ms":3,"lbm_writes_lt_1ms":413,"reinsert_count":0,"update_count":2065}
I20260812 06:17:56.674007 22089 maintenance_manager.cc:419] P ead5f2336a04427480deb54762779c17: Scheduling FlushDeltaMemStoresOp(1ff0bf7f1072443fb49179a247de166a): perf score=2.188937
I20260812 06:17:56.686981 21991 maintenance_manager.cc:643] P ead5f2336a04427480deb54762779c17: FlushDeltaMemStoresOp(1ff0bf7f1072443fb49179a247de166a) complete. Timing: real 0.013s	user 0.005s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5142,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:56.687505 22089 maintenance_manager.cc:419] P ead5f2336a04427480deb54762779c17: Scheduling UndoDeltaBlockGCOp(1ff0bf7f1072443fb49179a247de166a): 16411392 bytes on disk
I20260812 06:17:56.687942 21991 maintenance_manager.cc:643] P ead5f2336a04427480deb54762779c17: UndoDeltaBlockGCOp(1ff0bf7f1072443fb49179a247de166a) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":47,"lbm_reads_lt_1ms":4}
I20260812 06:17:56.688313 22089 maintenance_manager.cc:419] P ead5f2336a04427480deb54762779c17: Scheduling MajorDeltaCompactionOp(1ff0bf7f1072443fb49179a247de166a): perf score=1.000000
I20260812 06:17:56.858647 21991 maintenance_manager.cc:643] P ead5f2336a04427480deb54762779c17: MajorDeltaCompactionOp(1ff0bf7f1072443fb49179a247de166a) complete. Timing: real 0.170s	user 0.126s	sys 0.044s Metrics: {"cfile_cache_miss":545,"cfile_cache_miss_bytes":25308009,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":172,"lbm_read_time_us":12522,"lbm_reads_lt_1ms":577,"lbm_write_time_us":29100,"lbm_writes_lt_1ms":556,"mutex_wait_us":2,"peak_mem_usage":64689739,"reinsert_count":0,"update_count":2565}
I20260812 06:17:56.859125 22089 maintenance_manager.cc:419] P ead5f2336a04427480deb54762779c17: Scheduling FlushDeltaMemStoresOp(1ff0bf7f1072443fb49179a247de166a): perf score=14.095187
I20260812 06:17:56.912190 21991 maintenance_manager.cc:643] P ead5f2336a04427480deb54762779c17: FlushDeltaMemStoresOp(1ff0bf7f1072443fb49179a247de166a) complete. Timing: real 0.053s	user 0.033s	sys 0.019s Metrics: {"bytes_written":16409903,"delete_count":0,"lbm_write_time_us":20078,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:17:56.912662 22089 maintenance_manager.cc:419] P ead5f2336a04427480deb54762779c17: Scheduling FlushDeltaMemStoresOp(1ff0bf7f1072443fb49179a247de166a): perf score=2.188937
I20260812 06:17:56.923127 21991 maintenance_manager.cc:643] P ead5f2336a04427480deb54762779c17: FlushDeltaMemStoresOp(1ff0bf7f1072443fb49179a247de166a) complete. Timing: real 0.010s	user 0.002s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4209,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:56.923525 22089 maintenance_manager.cc:419] P ead5f2336a04427480deb54762779c17: Scheduling MajorDeltaCompactionOp(1ff0bf7f1072443fb49179a247de166a): perf score=1.000000
I20260812 06:17:57.098856 21991 maintenance_manager.cc:643] P ead5f2336a04427480deb54762779c17: MajorDeltaCompactionOp(1ff0bf7f1072443fb49179a247de166a) complete. Timing: real 0.175s	user 0.120s	sys 0.044s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774690,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":897,"lbm_read_time_us":12639,"lbm_reads_lt_1ms":572,"lbm_write_time_us":29746,"lbm_writes_lt_1ms":543,"mutex_wait_us":25,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":9344,"update_count":2500}
I20260812 06:17:57.099444 22089 maintenance_manager.cc:419] P ead5f2336a04427480deb54762779c17: Scheduling FlushDeltaMemStoresOp(1ff0bf7f1072443fb49179a247de166a): perf score=14.095187
I20260812 06:17:57.159718 21991 maintenance_manager.cc:643] P ead5f2336a04427480deb54762779c17: FlushDeltaMemStoresOp(1ff0bf7f1072443fb49179a247de166a) complete. Timing: real 0.060s	user 0.027s	sys 0.031s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":22420,"lbm_writes_1-10_ms":2,"lbm_writes_lt_1ms":401,"reinsert_count":0,"update_count":2000}
I20260812 06:17:57.160297 22089 maintenance_manager.cc:419] P ead5f2336a04427480deb54762779c17: Scheduling FlushDeltaMemStoresOp(1ff0bf7f1072443fb49179a247de166a): perf score=2.188937
I20260812 06:17:57.176177 21991 maintenance_manager.cc:643] P ead5f2336a04427480deb54762779c17: FlushDeltaMemStoresOp(1ff0bf7f1072443fb49179a247de166a) complete. Timing: real 0.016s	user 0.014s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6025,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:57.176692 22089 maintenance_manager.cc:419] P ead5f2336a04427480deb54762779c17: Scheduling MajorDeltaCompactionOp(1ff0bf7f1072443fb49179a247de166a): perf score=1.000000
I20260812 06:17:57.346956 21991 maintenance_manager.cc:643] P ead5f2336a04427480deb54762779c17: MajorDeltaCompactionOp(1ff0bf7f1072443fb49179a247de166a) complete. Timing: real 0.170s	user 0.121s	sys 0.046s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774689,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":467,"lbm_read_time_us":11664,"lbm_reads_lt_1ms":572,"lbm_write_time_us":30875,"lbm_writes_lt_1ms":543,"peak_mem_usage":63115900,"reinsert_count":0,"update_count":2500}
I20260812 06:17:57.347529 22089 maintenance_manager.cc:419] P ead5f2336a04427480deb54762779c17: Scheduling FlushDeltaMemStoresOp(1ff0bf7f1072443fb49179a247de166a): perf score=11.118625
I20260812 06:17:57.376652 21991 maintenance_manager.cc:643] P ead5f2336a04427480deb54762779c17: FlushDeltaMemStoresOp(1ff0bf7f1072443fb49179a247de166a) complete. Timing: real 0.029s	user 0.009s	sys 0.018s Metrics: {"bytes_written":12717735,"delete_count":0,"lbm_write_time_us":13209,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:17:57.377180 22089 maintenance_manager.cc:419] P ead5f2336a04427480deb54762779c17: Scheduling FlushDeltaMemStoresOp(1ff0bf7f1072443fb49179a247de166a): perf score=2.188937
I20260812 06:17:57.389465 21991 maintenance_manager.cc:643] P ead5f2336a04427480deb54762779c17: FlushDeltaMemStoresOp(1ff0bf7f1072443fb49179a247de166a) complete. Timing: real 0.012s	user 0.005s	sys 0.004s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":4197,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:17:57.389940 22089 maintenance_manager.cc:419] P ead5f2336a04427480deb54762779c17: Scheduling MajorDeltaCompactionOp(1ff0bf7f1072443fb49179a247de166a): perf score=1.000000
I20260812 06:17:57.523434 21991 maintenance_manager.cc:643] P ead5f2336a04427480deb54762779c17: MajorDeltaCompactionOp(1ff0bf7f1072443fb49179a247de166a) complete. Timing: real 0.133s	user 0.105s	sys 0.023s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672268,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":795,"lbm_read_time_us":8205,"lbm_reads_lt_1ms":472,"lbm_write_time_us":27493,"lbm_writes_lt_1ms":443,"mutex_wait_us":20,"peak_mem_usage":50689328,"reinsert_count":0,"update_count":2000}
I20260812 06:17:57.523924 22089 maintenance_manager.cc:419] P ead5f2336a04427480deb54762779c17: Scheduling FlushDeltaMemStoresOp(1ff0bf7f1072443fb49179a247de166a): perf score=10.126437
I20260812 06:17:57.570695 21991 maintenance_manager.cc:643] P ead5f2336a04427480deb54762779c17: FlushDeltaMemStoresOp(1ff0bf7f1072443fb49179a247de166a) complete. Timing: real 0.045s	user 0.031s	sys 0.003s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":16300,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:17:57.571245 22089 maintenance_manager.cc:419] P ead5f2336a04427480deb54762779c17: Scheduling FlushDeltaMemStoresOp(1ff0bf7f1072443fb49179a247de166a): perf score=2.188937
I20260812 06:17:57.581920 21991 maintenance_manager.cc:643] P ead5f2336a04427480deb54762779c17: FlushDeltaMemStoresOp(1ff0bf7f1072443fb49179a247de166a) complete. Timing: real 0.010s	user 0.008s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3973,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:57.582461 22089 maintenance_manager.cc:419] P ead5f2336a04427480deb54762779c17: Scheduling FlushMRSOp(1ff0bf7f1072443fb49179a247de166a): perf score=1.000000
I20260812 06:17:57.612998 21991 maintenance_manager.cc:643] P ead5f2336a04427480deb54762779c17: FlushMRSOp(1ff0bf7f1072443fb49179a247de166a) complete. Timing: real 0.030s	user 0.029s	sys 0.000s Metrics: {"bytes_written":1193503,"cfile_init":1,"dirs.queue_time_us":40,"dirs.run_cpu_time_us":243,"dirs.run_wall_time_us":1377,"drs_written":1,"lbm_read_time_us":40,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1970,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":29}
I20260812 06:17:57.613855 22089 maintenance_manager.cc:419] P ead5f2336a04427480deb54762779c17: Scheduling LogGCOp(1ff0bf7f1072443fb49179a247de166a): free 112692371 bytes of WAL
I20260812 06:17:57.614094 21991 log_reader.cc:385] T 1ff0bf7f1072443fb49179a247de166a: removed 11 log segments from log reader
I20260812 06:17:57.614162 21991 log.cc:1079] T 1ff0bf7f1072443fb49179a247de166a P ead5f2336a04427480deb54762779c17: Deleting log segment in path: /tmp/dist-test-taskCQqSFo/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515475780686-21826-0/minicluster-data/ts-0-root/wals/1ff0bf7f1072443fb49179a247de166a/wal-000000003 (ops 12-16)
I20260812 06:17:57.614207 21991 log.cc:1079] T 1ff0bf7f1072443fb49179a247de166a P ead5f2336a04427480deb54762779c17: Deleting log segment in path: /tmp/dist-test-taskCQqSFo/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515475780686-21826-0/minicluster-data/ts-0-root/wals/1ff0bf7f1072443fb49179a247de166a/wal-000000004 (ops 17-21)
I20260812 06:17:57.614256 21991 log.cc:1079] T 1ff0bf7f1072443fb49179a247de166a P ead5f2336a04427480deb54762779c17: Deleting log segment in path: /tmp/dist-test-taskCQqSFo/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515475780686-21826-0/minicluster-data/ts-0-root/wals/1ff0bf7f1072443fb49179a247de166a/wal-000000005 (ops 22-26)
I20260812 06:17:57.614305 21991 log.cc:1079] T 1ff0bf7f1072443fb49179a247de166a P ead5f2336a04427480deb54762779c17: Deleting log segment in path: /tmp/dist-test-taskCQqSFo/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515475780686-21826-0/minicluster-data/ts-0-root/wals/1ff0bf7f1072443fb49179a247de166a/wal-000000006 (ops 27-31)
I20260812 06:17:57.614364 21991 log.cc:1079] T 1ff0bf7f1072443fb49179a247de166a P ead5f2336a04427480deb54762779c17: Deleting log segment in path: /tmp/dist-test-taskCQqSFo/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515475780686-21826-0/minicluster-data/ts-0-root/wals/1ff0bf7f1072443fb49179a247de166a/wal-000000007 (ops 32-36)
I20260812 06:17:57.614400 21991 log.cc:1079] T 1ff0bf7f1072443fb49179a247de166a P ead5f2336a04427480deb54762779c17: Deleting log segment in path: /tmp/dist-test-taskCQqSFo/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515475780686-21826-0/minicluster-data/ts-0-root/wals/1ff0bf7f1072443fb49179a247de166a/wal-000000008 (ops 37-41)
I20260812 06:17:57.614425 21991 log.cc:1079] T 1ff0bf7f1072443fb49179a247de166a P ead5f2336a04427480deb54762779c17: Deleting log segment in path: /tmp/dist-test-taskCQqSFo/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515475780686-21826-0/minicluster-data/ts-0-root/wals/1ff0bf7f1072443fb49179a247de166a/wal-000000009 (ops 42-46)
I20260812 06:17:57.614468 21991 log.cc:1079] T 1ff0bf7f1072443fb49179a247de166a P ead5f2336a04427480deb54762779c17: Deleting log segment in path: /tmp/dist-test-taskCQqSFo/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515475780686-21826-0/minicluster-data/ts-0-root/wals/1ff0bf7f1072443fb49179a247de166a/wal-000000010 (ops 47-51)
I20260812 06:17:57.614506 21991 log.cc:1079] T 1ff0bf7f1072443fb49179a247de166a P ead5f2336a04427480deb54762779c17: Deleting log segment in path: /tmp/dist-test-taskCQqSFo/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515475780686-21826-0/minicluster-data/ts-0-root/wals/1ff0bf7f1072443fb49179a247de166a/wal-000000011 (ops 52-56)
I20260812 06:17:57.614543 21991 log.cc:1079] T 1ff0bf7f1072443fb49179a247de166a P ead5f2336a04427480deb54762779c17: Deleting log segment in path: /tmp/dist-test-taskCQqSFo/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515475780686-21826-0/minicluster-data/ts-0-root/wals/1ff0bf7f1072443fb49179a247de166a/wal-000000012 (ops 57-61)
I20260812 06:17:57.614581 21991 log.cc:1079] T 1ff0bf7f1072443fb49179a247de166a P ead5f2336a04427480deb54762779c17: Deleting log segment in path: /tmp/dist-test-taskCQqSFo/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515475780686-21826-0/minicluster-data/ts-0-root/wals/1ff0bf7f1072443fb49179a247de166a/wal-000000013 (ops 62-66)
I20260812 06:17:57.640499 21991 maintenance_manager.cc:643] P ead5f2336a04427480deb54762779c17: LogGCOp(1ff0bf7f1072443fb49179a247de166a) complete. Timing: real 0.026s	user 0.000s	sys 0.025s Metrics: {}
I20260812 06:17:57.640851 22089 maintenance_manager.cc:419] P ead5f2336a04427480deb54762779c17: Scheduling UndoDeltaBlockGCOp(1ff0bf7f1072443fb49179a247de166a): 462 bytes on disk
I20260812 06:17:57.641229 21991 maintenance_manager.cc:643] P ead5f2336a04427480deb54762779c17: UndoDeltaBlockGCOp(1ff0bf7f1072443fb49179a247de166a) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":50,"lbm_reads_lt_1ms":4}
I20260812 06:17:57.641714 22089 maintenance_manager.cc:419] P ead5f2336a04427480deb54762779c17: Scheduling FlushDeltaMemStoresOp(1ff0bf7f1072443fb49179a247de166a): perf score=3.181125
I20260812 06:17:57.658782 21991 maintenance_manager.cc:643] P ead5f2336a04427480deb54762779c17: FlushDeltaMemStoresOp(1ff0bf7f1072443fb49179a247de166a) complete. Timing: real 0.017s	user 0.011s	sys 0.004s Metrics: {"bytes_written":4800077,"delete_count":0,"lbm_write_time_us":7292,"lbm_writes_lt_1ms":120,"reinsert_count":0,"update_count":585}
I20260812 06:17:57.659231 22089 maintenance_manager.cc:419] P ead5f2336a04427480deb54762779c17: Scheduling LogGCOp(1ff0bf7f1072443fb49179a247de166a): free 11564875 bytes of WAL
I20260812 06:17:57.659438 21991 log_reader.cc:385] T 1ff0bf7f1072443fb49179a247de166a: removed 1 log segments from log reader
I20260812 06:17:57.659495 21991 log.cc:1079] T 1ff0bf7f1072443fb49179a247de166a P ead5f2336a04427480deb54762779c17: Deleting log segment in path: /tmp/dist-test-taskCQqSFo/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515475780686-21826-0/minicluster-data/ts-0-root/wals/1ff0bf7f1072443fb49179a247de166a/wal-000000014 (ops 67-70)
I20260812 06:17:57.661751 21991 maintenance_manager.cc:643] P ead5f2336a04427480deb54762779c17: LogGCOp(1ff0bf7f1072443fb49179a247de166a) complete. Timing: real 0.002s	user 0.000s	sys 0.000s Metrics: {}
I20260812 06:17:57.662025 22089 maintenance_manager.cc:419] P ead5f2336a04427480deb54762779c17: Scheduling FlushDeltaMemStoresOp(1ff0bf7f1072443fb49179a247de166a): perf score=2.188937
I20260812 06:17:57.672267 21991 maintenance_manager.cc:643] P ead5f2336a04427480deb54762779c17: FlushDeltaMemStoresOp(1ff0bf7f1072443fb49179a247de166a) complete. Timing: real 0.010s	user 0.009s	sys 0.000s Metrics: {"bytes_written":3405230,"delete_count":0,"lbm_write_time_us":3591,"lbm_writes_lt_1ms":86,"reinsert_count":0,"update_count":415}
I20260812 06:17:57.672732 22089 maintenance_manager.cc:419] P ead5f2336a04427480deb54762779c17: Scheduling MajorDeltaCompactionOp(1ff0bf7f1072443fb49179a247de166a): perf score=1.000000
I20260812 06:17:57.846148 21991 maintenance_manager.cc:643] P ead5f2336a04427480deb54762779c17: MajorDeltaCompactionOp(1ff0bf7f1072443fb49179a247de166a) complete. Timing: real 0.173s	user 0.145s	sys 0.028s Metrics: {"cfile_cache_miss":634,"cfile_cache_miss_bytes":28877328,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":175,"lbm_read_time_us":13062,"lbm_reads_lt_1ms":674,"lbm_write_time_us":34472,"lbm_writes_lt_1ms":643,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":896,"thread_start_us":76,"threads_started":1,"update_count":3000}
I20260812 06:17:57.846755 22089 maintenance_manager.cc:419] P ead5f2336a04427480deb54762779c17: Scheduling FlushDeltaMemStoresOp(1ff0bf7f1072443fb49179a247de166a): perf score=14.095187
I20260812 06:17:57.897648 21991 maintenance_manager.cc:643] P ead5f2336a04427480deb54762779c17: FlushDeltaMemStoresOp(1ff0bf7f1072443fb49179a247de166a) complete. Timing: real 0.051s	user 0.031s	sys 0.016s Metrics: {"bytes_written":16409903,"delete_count":0,"lbm_write_time_us":21825,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:17:57.898396 22089 maintenance_manager.cc:419] P ead5f2336a04427480deb54762779c17: Scheduling FlushDeltaMemStoresOp(1ff0bf7f1072443fb49179a247de166a): perf score=2.188937
I20260812 06:17:57.914320 21991 maintenance_manager.cc:643] P ead5f2336a04427480deb54762779c17: FlushDeltaMemStoresOp(1ff0bf7f1072443fb49179a247de166a) complete. Timing: real 0.016s	user 0.013s	sys 0.000s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":5469,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:57.914752 22089 maintenance_manager.cc:419] P ead5f2336a04427480deb54762779c17: Scheduling MajorDeltaCompactionOp(1ff0bf7f1072443fb49179a247de166a): perf score=1.000000
I20260812 06:17:58.059967 21991 maintenance_manager.cc:643] P ead5f2336a04427480deb54762779c17: MajorDeltaCompactionOp(1ff0bf7f1072443fb49179a247de166a) complete. Timing: real 0.145s	user 0.109s	sys 0.033s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774689,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":676,"lbm_read_time_us":10554,"lbm_reads_lt_1ms":564,"lbm_write_time_us":29040,"lbm_writes_lt_1ms":543,"mutex_wait_us":74,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":3584,"update_count":2500}
I20260812 06:17:58.060494 22089 maintenance_manager.cc:419] P ead5f2336a04427480deb54762779c17: Scheduling FlushDeltaMemStoresOp(1ff0bf7f1072443fb49179a247de166a): perf score=14.095187
I20260812 06:17:58.114850 21991 maintenance_manager.cc:643] P ead5f2336a04427480deb54762779c17: FlushDeltaMemStoresOp(1ff0bf7f1072443fb49179a247de166a) complete. Timing: real 0.054s	user 0.030s	sys 0.020s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":25723,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":402,"reinsert_count":0,"update_count":2000}
I20260812 06:17:58.115322 22089 maintenance_manager.cc:419] P ead5f2336a04427480deb54762779c17: Scheduling FlushDeltaMemStoresOp(1ff0bf7f1072443fb49179a247de166a): perf score=2.188937
I20260812 06:17:58.125836 21991 maintenance_manager.cc:643] P ead5f2336a04427480deb54762779c17: FlushDeltaMemStoresOp(1ff0bf7f1072443fb49179a247de166a) complete. Timing: real 0.010s	user 0.004s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4132,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:58.126422 22089 maintenance_manager.cc:419] P ead5f2336a04427480deb54762779c17: Scheduling MajorDeltaCompactionOp(1ff0bf7f1072443fb49179a247de166a): perf score=1.000000
I20260812 06:17:58.277000 21991 maintenance_manager.cc:643] P ead5f2336a04427480deb54762779c17: MajorDeltaCompactionOp(1ff0bf7f1072443fb49179a247de166a) complete. Timing: real 0.149s	user 0.122s	sys 0.025s 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":89,"lbm_read_time_us":11299,"lbm_reads_lt_1ms":572,"lbm_write_time_us":30543,"lbm_writes_lt_1ms":543,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":2816,"update_count":2500}
I20260812 06:17:58.278213 22089 maintenance_manager.cc:419] P ead5f2336a04427480deb54762779c17: Scheduling FlushDeltaMemStoresOp(1ff0bf7f1072443fb49179a247de166a): perf score=10.126437
I20260812 06:17:58.323130 21991 maintenance_manager.cc:643] P ead5f2336a04427480deb54762779c17: FlushDeltaMemStoresOp(1ff0bf7f1072443fb49179a247de166a) complete. Timing: real 0.045s	user 0.031s	sys 0.007s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":16255,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:17:58.323648 22089 maintenance_manager.cc:419] P ead5f2336a04427480deb54762779c17: Scheduling FlushDeltaMemStoresOp(1ff0bf7f1072443fb49179a247de166a): perf score=2.188937
I20260812 06:17:58.334879 21991 maintenance_manager.cc:643] P ead5f2336a04427480deb54762779c17: FlushDeltaMemStoresOp(1ff0bf7f1072443fb49179a247de166a) complete. Timing: real 0.011s	user 0.011s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4179,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:58.335297 22089 maintenance_manager.cc:419] P ead5f2336a04427480deb54762779c17: Scheduling MajorDeltaCompactionOp(1ff0bf7f1072443fb49179a247de166a): perf score=1.000000
I20260812 06:17:58.466146 21991 maintenance_manager.cc:643] P ead5f2336a04427480deb54762779c17: MajorDeltaCompactionOp(1ff0bf7f1072443fb49179a247de166a) complete. Timing: real 0.131s	user 0.111s	sys 0.020s 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":221,"lbm_read_time_us":7908,"lbm_reads_lt_1ms":472,"lbm_write_time_us":27686,"lbm_writes_lt_1ms":443,"mutex_wait_us":47,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":12800,"update_count":2000}
I20260812 06:17:58.466760 22089 maintenance_manager.cc:419] P ead5f2336a04427480deb54762779c17: Scheduling FlushDeltaMemStoresOp(1ff0bf7f1072443fb49179a247de166a): perf score=10.126437
I20260812 06:17:58.512254 21991 maintenance_manager.cc:643] P ead5f2336a04427480deb54762779c17: FlushDeltaMemStoresOp(1ff0bf7f1072443fb49179a247de166a) complete. Timing: real 0.045s	user 0.019s	sys 0.025s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":15515,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:17:58.512823 22089 maintenance_manager.cc:419] P ead5f2336a04427480deb54762779c17: Scheduling FlushDeltaMemStoresOp(1ff0bf7f1072443fb49179a247de166a): perf score=2.188937
I20260812 06:17:58.529800 21991 maintenance_manager.cc:643] P ead5f2336a04427480deb54762779c17: FlushDeltaMemStoresOp(1ff0bf7f1072443fb49179a247de166a) complete. Timing: real 0.017s	user 0.011s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6510,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:58.530339 22089 maintenance_manager.cc:419] P ead5f2336a04427480deb54762779c17: Scheduling MajorDeltaCompactionOp(1ff0bf7f1072443fb49179a247de166a): perf score=1.000000
I20260812 06:17:58.667979 21991 maintenance_manager.cc:643] P ead5f2336a04427480deb54762779c17: MajorDeltaCompactionOp(1ff0bf7f1072443fb49179a247de166a) complete. Timing: real 0.137s	user 0.093s	sys 0.043s 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":1109,"lbm_read_time_us":11353,"lbm_reads_lt_1ms":472,"lbm_write_time_us":22906,"lbm_writes_lt_1ms":443,"mutex_wait_us":38,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":1920,"update_count":2000}
I20260812 06:17:58.668646 22089 maintenance_manager.cc:419] P ead5f2336a04427480deb54762779c17: Scheduling FlushDeltaMemStoresOp(1ff0bf7f1072443fb49179a247de166a): perf score=10.126437
I20260812 06:17:58.710181 21991 maintenance_manager.cc:643] P ead5f2336a04427480deb54762779c17: FlushDeltaMemStoresOp(1ff0bf7f1072443fb49179a247de166a) complete. Timing: real 0.041s	user 0.011s	sys 0.016s Metrics: {"bytes_written":12307491,"delete_count":0,"lbm_write_time_us":13572,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:17:58.710698 22089 maintenance_manager.cc:419] P ead5f2336a04427480deb54762779c17: Scheduling FlushDeltaMemStoresOp(1ff0bf7f1072443fb49179a247de166a): perf score=2.188937
I20260812 06:17:58.723487 21991 maintenance_manager.cc:643] P ead5f2336a04427480deb54762779c17: FlushDeltaMemStoresOp(1ff0bf7f1072443fb49179a247de166a) complete. Timing: real 0.013s	user 0.007s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4679,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:58.724169 22089 maintenance_manager.cc:419] P ead5f2336a04427480deb54762779c17: Scheduling MajorDeltaCompactionOp(1ff0bf7f1072443fb49179a247de166a): perf score=1.000000
I20260812 06:17:58.867403 21991 maintenance_manager.cc:643] P ead5f2336a04427480deb54762779c17: MajorDeltaCompactionOp(1ff0bf7f1072443fb49179a247de166a) complete. Timing: real 0.143s	user 0.113s	sys 0.020s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672278,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":331,"lbm_read_time_us":10299,"lbm_reads_lt_1ms":472,"lbm_write_time_us":26242,"lbm_writes_lt_1ms":443,"mutex_wait_us":54,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":3840,"update_count":2000}
I20260812 06:17:58.867960 22089 maintenance_manager.cc:419] P ead5f2336a04427480deb54762779c17: Scheduling FlushDeltaMemStoresOp(1ff0bf7f1072443fb49179a247de166a): perf score=14.095187
I20260812 06:17:58.915609 21991 maintenance_manager.cc:643] P ead5f2336a04427480deb54762779c17: FlushDeltaMemStoresOp(1ff0bf7f1072443fb49179a247de166a) complete. Timing: real 0.047s	user 0.019s	sys 0.020s Metrics: {"bytes_written":16409903,"delete_count":0,"lbm_write_time_us":17822,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:17:58.916118 22089 maintenance_manager.cc:419] P ead5f2336a04427480deb54762779c17: Scheduling FlushDeltaMemStoresOp(1ff0bf7f1072443fb49179a247de166a): perf score=2.188937
I20260812 06:17:58.927580 21991 maintenance_manager.cc:643] P ead5f2336a04427480deb54762779c17: FlushDeltaMemStoresOp(1ff0bf7f1072443fb49179a247de166a) complete. Timing: real 0.011s	user 0.006s	sys 0.004s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4263,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:58.928030 22089 maintenance_manager.cc:419] P ead5f2336a04427480deb54762779c17: Scheduling FlushMRSOp(1ff0bf7f1072443fb49179a247de166a): perf score=1.000000
I20260812 06:17:58.955295 21991 maintenance_manager.cc:643] P ead5f2336a04427480deb54762779c17: FlushMRSOp(1ff0bf7f1072443fb49179a247de166a) complete. Timing: real 0.027s	user 0.027s	sys 0.000s Metrics: {"bytes_written":1193509,"cfile_init":1,"dirs.queue_time_us":33,"dirs.run_cpu_time_us":181,"dirs.run_wall_time_us":1150,"drs_written":1,"lbm_read_time_us":54,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1526,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":29}
I20260812 06:17:58.956053 22089 maintenance_manager.cc:419] P ead5f2336a04427480deb54762779c17: Scheduling LogGCOp(1ff0bf7f1072443fb49179a247de166a): free 108535407 bytes of WAL
I20260812 06:17:58.956318 21991 log_reader.cc:385] T 1ff0bf7f1072443fb49179a247de166a: removed 11 log segments from log reader
I20260812 06:17:58.956377 21991 log.cc:1079] T 1ff0bf7f1072443fb49179a247de166a P ead5f2336a04427480deb54762779c17: Deleting log segment in path: /tmp/dist-test-taskCQqSFo/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515475780686-21826-0/minicluster-data/ts-0-root/wals/1ff0bf7f1072443fb49179a247de166a/wal-000000015 (ops 71-75)
I20260812 06:17:58.956415 21991 log.cc:1079] T 1ff0bf7f1072443fb49179a247de166a P ead5f2336a04427480deb54762779c17: Deleting log segment in path: /tmp/dist-test-taskCQqSFo/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515475780686-21826-0/minicluster-data/ts-0-root/wals/1ff0bf7f1072443fb49179a247de166a/wal-000000016 (ops 76-80)
I20260812 06:17:58.956451 21991 log.cc:1079] T 1ff0bf7f1072443fb49179a247de166a P ead5f2336a04427480deb54762779c17: Deleting log segment in path: /tmp/dist-test-taskCQqSFo/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515475780686-21826-0/minicluster-data/ts-0-root/wals/1ff0bf7f1072443fb49179a247de166a/wal-000000017 (ops 81-84)
I20260812 06:17:58.956476 21991 log.cc:1079] T 1ff0bf7f1072443fb49179a247de166a P ead5f2336a04427480deb54762779c17: Deleting log segment in path: /tmp/dist-test-taskCQqSFo/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515475780686-21826-0/minicluster-data/ts-0-root/wals/1ff0bf7f1072443fb49179a247de166a/wal-000000018 (ops 85-89)
I20260812 06:17:58.956499 21991 log.cc:1079] T 1ff0bf7f1072443fb49179a247de166a P ead5f2336a04427480deb54762779c17: Deleting log segment in path: /tmp/dist-test-taskCQqSFo/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515475780686-21826-0/minicluster-data/ts-0-root/wals/1ff0bf7f1072443fb49179a247de166a/wal-000000019 (ops 90-94)
I20260812 06:17:58.956521 21991 log.cc:1079] T 1ff0bf7f1072443fb49179a247de166a P ead5f2336a04427480deb54762779c17: Deleting log segment in path: /tmp/dist-test-taskCQqSFo/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515475780686-21826-0/minicluster-data/ts-0-root/wals/1ff0bf7f1072443fb49179a247de166a/wal-000000020 (ops 95-99)
I20260812 06:17:58.956543 21991 log.cc:1079] T 1ff0bf7f1072443fb49179a247de166a P ead5f2336a04427480deb54762779c17: Deleting log segment in path: /tmp/dist-test-taskCQqSFo/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515475780686-21826-0/minicluster-data/ts-0-root/wals/1ff0bf7f1072443fb49179a247de166a/wal-000000021 (ops 100-104)
I20260812 06:17:58.956565 21991 log.cc:1079] T 1ff0bf7f1072443fb49179a247de166a P ead5f2336a04427480deb54762779c17: Deleting log segment in path: /tmp/dist-test-taskCQqSFo/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515475780686-21826-0/minicluster-data/ts-0-root/wals/1ff0bf7f1072443fb49179a247de166a/wal-000000022 (ops 105-108)
I20260812 06:17:58.956593 21991 log.cc:1079] T 1ff0bf7f1072443fb49179a247de166a P ead5f2336a04427480deb54762779c17: Deleting log segment in path: /tmp/dist-test-taskCQqSFo/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515475780686-21826-0/minicluster-data/ts-0-root/wals/1ff0bf7f1072443fb49179a247de166a/wal-000000023 (ops 109-113)
I20260812 06:17:58.956616 21991 log.cc:1079] T 1ff0bf7f1072443fb49179a247de166a P ead5f2336a04427480deb54762779c17: Deleting log segment in path: /tmp/dist-test-taskCQqSFo/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515475780686-21826-0/minicluster-data/ts-0-root/wals/1ff0bf7f1072443fb49179a247de166a/wal-000000024 (ops 114-118)
I20260812 06:17:58.956638 21991 log.cc:1079] T 1ff0bf7f1072443fb49179a247de166a P ead5f2336a04427480deb54762779c17: Deleting log segment in path: /tmp/dist-test-taskCQqSFo/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515475780686-21826-0/minicluster-data/ts-0-root/wals/1ff0bf7f1072443fb49179a247de166a/wal-000000025 (ops 119-123)
I20260812 06:17:58.983210 21991 maintenance_manager.cc:643] P ead5f2336a04427480deb54762779c17: LogGCOp(1ff0bf7f1072443fb49179a247de166a) complete. Timing: real 0.027s	user 0.000s	sys 0.027s Metrics: {}
I20260812 06:17:58.983683 22089 maintenance_manager.cc:419] P ead5f2336a04427480deb54762779c17: Scheduling FlushDeltaMemStoresOp(1ff0bf7f1072443fb49179a247de166a): perf score=2.188937
I20260812 06:17:59.008277 21991 maintenance_manager.cc:643] P ead5f2336a04427480deb54762779c17: FlushDeltaMemStoresOp(1ff0bf7f1072443fb49179a247de166a) complete. Timing: real 0.024s	user 0.014s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6671,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:59.008742 22089 maintenance_manager.cc:419] P ead5f2336a04427480deb54762779c17: Scheduling LogGCOp(1ff0bf7f1072443fb49179a247de166a): free 12017983 bytes of WAL
I20260812 06:17:59.008942 21991 log_reader.cc:385] T 1ff0bf7f1072443fb49179a247de166a: removed 1 log segments from log reader
I20260812 06:17:59.008987 21991 log.cc:1079] T 1ff0bf7f1072443fb49179a247de166a P ead5f2336a04427480deb54762779c17: Deleting log segment in path: /tmp/dist-test-taskCQqSFo/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515475780686-21826-0/minicluster-data/ts-0-root/wals/1ff0bf7f1072443fb49179a247de166a/wal-000000026 (ops 124-128)
I20260812 06:17:59.011401 21991 maintenance_manager.cc:643] P ead5f2336a04427480deb54762779c17: LogGCOp(1ff0bf7f1072443fb49179a247de166a) complete. Timing: real 0.002s	user 0.000s	sys 0.002s Metrics: {}
I20260812 06:17:59.011682 22089 maintenance_manager.cc:419] P ead5f2336a04427480deb54762779c17: Scheduling UndoDeltaBlockGCOp(1ff0bf7f1072443fb49179a247de166a): 463 bytes on disk
I20260812 06:17:59.012058 21991 maintenance_manager.cc:643] P ead5f2336a04427480deb54762779c17: UndoDeltaBlockGCOp(1ff0bf7f1072443fb49179a247de166a) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":47,"lbm_reads_lt_1ms":4}
I20260812 06:17:59.012513 22089 maintenance_manager.cc:419] P ead5f2336a04427480deb54762779c17: Scheduling FlushDeltaMemStoresOp(1ff0bf7f1072443fb49179a247de166a): perf score=2.188937
I20260812 06:17:59.024396 21991 maintenance_manager.cc:643] P ead5f2336a04427480deb54762779c17: FlushDeltaMemStoresOp(1ff0bf7f1072443fb49179a247de166a) complete. Timing: real 0.012s	user 0.010s	sys 0.001s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4366,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:59.024961 22089 maintenance_manager.cc:419] P ead5f2336a04427480deb54762779c17: Scheduling MajorDeltaCompactionOp(1ff0bf7f1072443fb49179a247de166a): perf score=1.000000
I20260812 06:17:59.215863 21991 maintenance_manager.cc:643] P ead5f2336a04427480deb54762779c17: MajorDeltaCompactionOp(1ff0bf7f1072443fb49179a247de166a) complete. Timing: real 0.191s	user 0.163s	sys 0.028s 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":931,"lbm_read_time_us":15205,"lbm_reads_lt_1ms":774,"lbm_write_time_us":39134,"lbm_writes_lt_1ms":743,"mutex_wait_us":273,"peak_mem_usage":87969044,"reinsert_count":0,"thread_start_us":73,"threads_started":1,"update_count":3500}
I20260812 06:17:59.216509 22089 maintenance_manager.cc:419] P ead5f2336a04427480deb54762779c17: Scheduling FlushDeltaMemStoresOp(1ff0bf7f1072443fb49179a247de166a): perf score=14.095187
I20260812 06:17:59.265794 21991 maintenance_manager.cc:643] P ead5f2336a04427480deb54762779c17: FlushDeltaMemStoresOp(1ff0bf7f1072443fb49179a247de166a) complete. Timing: real 0.049s	user 0.023s	sys 0.024s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":21293,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:17:59.266311 22089 maintenance_manager.cc:419] P ead5f2336a04427480deb54762779c17: Scheduling FlushDeltaMemStoresOp(1ff0bf7f1072443fb49179a247de166a): perf score=2.188937
I20260812 06:17:59.288080 21991 maintenance_manager.cc:643] P ead5f2336a04427480deb54762779c17: FlushDeltaMemStoresOp(1ff0bf7f1072443fb49179a247de166a) complete. Timing: real 0.022s	user 0.017s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":7096,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:59.288657 22089 maintenance_manager.cc:419] P ead5f2336a04427480deb54762779c17: Scheduling MajorDeltaCompactionOp(1ff0bf7f1072443fb49179a247de166a): perf score=1.000000
I20260812 06:17:59.462520 21991 maintenance_manager.cc:643] P ead5f2336a04427480deb54762779c17: MajorDeltaCompactionOp(1ff0bf7f1072443fb49179a247de166a) complete. Timing: real 0.174s	user 0.142s	sys 0.031s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774688,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":924,"lbm_read_time_us":12867,"lbm_reads_lt_1ms":564,"lbm_write_time_us":28018,"lbm_writes_lt_1ms":543,"mutex_wait_us":88,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":768,"update_count":2500}
I20260812 06:17:59.463145 22089 maintenance_manager.cc:419] P ead5f2336a04427480deb54762779c17: Scheduling FlushDeltaMemStoresOp(1ff0bf7f1072443fb49179a247de166a): perf score=14.095187
I20260812 06:17:59.506150 21991 maintenance_manager.cc:643] P ead5f2336a04427480deb54762779c17: FlushDeltaMemStoresOp(1ff0bf7f1072443fb49179a247de166a) complete. Timing: real 0.043s	user 0.027s	sys 0.013s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":18990,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:17:59.506695 22089 maintenance_manager.cc:419] P ead5f2336a04427480deb54762779c17: Scheduling FlushDeltaMemStoresOp(1ff0bf7f1072443fb49179a247de166a): perf score=2.188937
I20260812 06:17:59.519265 21991 maintenance_manager.cc:643] P ead5f2336a04427480deb54762779c17: FlushDeltaMemStoresOp(1ff0bf7f1072443fb49179a247de166a) complete. Timing: real 0.012s	user 0.011s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4201,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:59.519699 22089 maintenance_manager.cc:419] P ead5f2336a04427480deb54762779c17: Scheduling MajorDeltaCompactionOp(1ff0bf7f1072443fb49179a247de166a): perf score=1.000000
I20260812 06:17:59.679023 21991 maintenance_manager.cc:643] P ead5f2336a04427480deb54762779c17: MajorDeltaCompactionOp(1ff0bf7f1072443fb49179a247de166a) complete. Timing: real 0.159s	user 0.124s	sys 0.033s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774688,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":377,"lbm_read_time_us":11103,"lbm_reads_lt_1ms":568,"lbm_write_time_us":29513,"lbm_writes_lt_1ms":543,"mutex_wait_us":55,"peak_mem_usage":63115900,"reinsert_count":0,"update_count":2500}
I20260812 06:17:59.679498 22089 maintenance_manager.cc:419] P ead5f2336a04427480deb54762779c17: Scheduling FlushDeltaMemStoresOp(1ff0bf7f1072443fb49179a247de166a): perf score=11.118625
I20260812 06:17:59.722096 21991 maintenance_manager.cc:643] P ead5f2336a04427480deb54762779c17: FlushDeltaMemStoresOp(1ff0bf7f1072443fb49179a247de166a) complete. Timing: real 0.042s	user 0.023s	sys 0.016s Metrics: {"bytes_written":12717735,"delete_count":0,"lbm_write_time_us":18441,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:17:59.722851 22089 maintenance_manager.cc:419] P ead5f2336a04427480deb54762779c17: Scheduling FlushDeltaMemStoresOp(1ff0bf7f1072443fb49179a247de166a): perf score=2.188937
I20260812 06:17:59.737793 21991 maintenance_manager.cc:643] P ead5f2336a04427480deb54762779c17: FlushDeltaMemStoresOp(1ff0bf7f1072443fb49179a247de166a) complete. Timing: real 0.014s	user 0.004s	sys 0.004s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3876,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:17:59.738191 22089 maintenance_manager.cc:419] P ead5f2336a04427480deb54762779c17: Scheduling FlushDeltaMemStoresOp(1ff0bf7f1072443fb49179a247de166a): perf score=2.188937
I20260812 06:17:59.748448 21991 maintenance_manager.cc:643] P ead5f2336a04427480deb54762779c17: FlushDeltaMemStoresOp(1ff0bf7f1072443fb49179a247de166a) complete. Timing: real 0.010s	user 0.004s	sys 0.004s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":3990,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:59.748848 22089 maintenance_manager.cc:419] P ead5f2336a04427480deb54762779c17: Scheduling MajorDeltaCompactionOp(1ff0bf7f1072443fb49179a247de166a): perf score=1.000000
I20260812 06:17:59.897321 21991 maintenance_manager.cc:643] P ead5f2336a04427480deb54762779c17: MajorDeltaCompactionOp(1ff0bf7f1072443fb49179a247de166a) complete. Timing: real 0.148s	user 0.133s	sys 0.013s Metrics: {"cfile_cache_miss":533,"cfile_cache_miss_bytes":24774798,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":227,"lbm_read_time_us":11017,"lbm_reads_lt_1ms":573,"lbm_write_time_us":29956,"lbm_writes_lt_1ms":543,"mutex_wait_us":54,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":2432,"update_count":2500}
I20260812 06:17:59.898028 22089 maintenance_manager.cc:419] P ead5f2336a04427480deb54762779c17: Scheduling FlushDeltaMemStoresOp(1ff0bf7f1072443fb49179a247de166a): perf score=11.118625
I20260812 06:17:59.933796 21991 maintenance_manager.cc:643] P ead5f2336a04427480deb54762779c17: FlushDeltaMemStoresOp(1ff0bf7f1072443fb49179a247de166a) complete. Timing: real 0.036s	user 0.025s	sys 0.008s Metrics: {"bytes_written":12717736,"delete_count":0,"lbm_write_time_us":15640,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:17:59.934379 22089 maintenance_manager.cc:419] P ead5f2336a04427480deb54762779c17: Scheduling FlushDeltaMemStoresOp(1ff0bf7f1072443fb49179a247de166a): perf score=2.188937
I20260812 06:17:59.948177 21991 maintenance_manager.cc:643] P ead5f2336a04427480deb54762779c17: FlushDeltaMemStoresOp(1ff0bf7f1072443fb49179a247de166a) complete. Timing: real 0.014s	user 0.012s	sys 0.000s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":5384,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:17:59.948798 22089 maintenance_manager.cc:419] P ead5f2336a04427480deb54762779c17: Scheduling MajorDeltaCompactionOp(1ff0bf7f1072443fb49179a247de166a): perf score=1.000000
I20260812 06:18:00.078962 21991 maintenance_manager.cc:643] P ead5f2336a04427480deb54762779c17: MajorDeltaCompactionOp(1ff0bf7f1072443fb49179a247de166a) complete. Timing: real 0.129s	user 0.098s	sys 0.031s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672269,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":204,"lbm_read_time_us":8019,"lbm_reads_lt_1ms":464,"lbm_write_time_us":26611,"lbm_writes_lt_1ms":443,"mutex_wait_us":52,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":1280,"update_count":2000}
I20260812 06:18:00.079903 22089 maintenance_manager.cc:419] P ead5f2336a04427480deb54762779c17: Scheduling FlushDeltaMemStoresOp(1ff0bf7f1072443fb49179a247de166a): perf score=10.126437
I20260812 06:18:00.121260 21991 maintenance_manager.cc:643] P ead5f2336a04427480deb54762779c17: FlushDeltaMemStoresOp(1ff0bf7f1072443fb49179a247de166a) complete. Timing: real 0.041s	user 0.019s	sys 0.012s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":14956,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:18:00.121796 22089 maintenance_manager.cc:419] P ead5f2336a04427480deb54762779c17: Scheduling FlushDeltaMemStoresOp(1ff0bf7f1072443fb49179a247de166a): perf score=2.188937
I20260812 06:18:00.132268 21991 maintenance_manager.cc:643] P ead5f2336a04427480deb54762779c17: FlushDeltaMemStoresOp(1ff0bf7f1072443fb49179a247de166a) complete. Timing: real 0.010s	user 0.001s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4037,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:00.132917 22089 maintenance_manager.cc:419] P ead5f2336a04427480deb54762779c17: Scheduling MajorDeltaCompactionOp(1ff0bf7f1072443fb49179a247de166a): perf score=1.000000
I20260812 06:18:00.249934 21991 maintenance_manager.cc:643] P ead5f2336a04427480deb54762779c17: MajorDeltaCompactionOp(1ff0bf7f1072443fb49179a247de166a) complete. Timing: real 0.117s	user 0.081s	sys 0.035s 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":2215,"lbm_read_time_us":8504,"lbm_reads_lt_1ms":472,"lbm_write_time_us":22613,"lbm_writes_lt_1ms":443,"mutex_wait_us":952,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":13568,"update_count":2000}
I20260812 06:18:00.250594 22089 maintenance_manager.cc:419] P ead5f2336a04427480deb54762779c17: Scheduling FlushDeltaMemStoresOp(1ff0bf7f1072443fb49179a247de166a): perf score=10.126437
I20260812 06:18:00.299823 21991 maintenance_manager.cc:643] P ead5f2336a04427480deb54762779c17: FlushDeltaMemStoresOp(1ff0bf7f1072443fb49179a247de166a) complete. Timing: real 0.049s	user 0.020s	sys 0.027s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":17042,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:18:00.300467 22089 maintenance_manager.cc:419] P ead5f2336a04427480deb54762779c17: Scheduling FlushDeltaMemStoresOp(1ff0bf7f1072443fb49179a247de166a): perf score=2.188937
I20260812 06:18:00.313788 21991 maintenance_manager.cc:643] P ead5f2336a04427480deb54762779c17: FlushDeltaMemStoresOp(1ff0bf7f1072443fb49179a247de166a) complete. Timing: real 0.013s	user 0.004s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4090,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:00.314353 22089 maintenance_manager.cc:419] P ead5f2336a04427480deb54762779c17: Scheduling FlushMRSOp(1ff0bf7f1072443fb49179a247de166a): perf score=1.000000
I20260812 06:18:00.351438 21991 maintenance_manager.cc:643] P ead5f2336a04427480deb54762779c17: FlushMRSOp(1ff0bf7f1072443fb49179a247de166a) complete. Timing: real 0.037s	user 0.027s	sys 0.000s Metrics: {"bytes_written":1234475,"cfile_init":1,"dirs.queue_time_us":60,"dirs.run_cpu_time_us":216,"dirs.run_wall_time_us":1263,"drs_written":1,"lbm_read_time_us":50,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1464,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":30}
I20260812 06:18:00.352252 22089 maintenance_manager.cc:419] P ead5f2336a04427480deb54762779c17: Scheduling LogGCOp(1ff0bf7f1072443fb49179a247de166a): free 112692608 bytes of WAL
I20260812 06:18:00.352581 21991 log_reader.cc:385] T 1ff0bf7f1072443fb49179a247de166a: removed 11 log segments from log reader
I20260812 06:18:00.352654 21991 log.cc:1079] T 1ff0bf7f1072443fb49179a247de166a P ead5f2336a04427480deb54762779c17: Deleting log segment in path: /tmp/dist-test-taskCQqSFo/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515475780686-21826-0/minicluster-data/ts-0-root/wals/1ff0bf7f1072443fb49179a247de166a/wal-000000027 (ops 129-133)
I20260812 06:18:00.352706 21991 log.cc:1079] T 1ff0bf7f1072443fb49179a247de166a P ead5f2336a04427480deb54762779c17: Deleting log segment in path: /tmp/dist-test-taskCQqSFo/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515475780686-21826-0/minicluster-data/ts-0-root/wals/1ff0bf7f1072443fb49179a247de166a/wal-000000028 (ops 134-138)
I20260812 06:18:00.352756 21991 log.cc:1079] T 1ff0bf7f1072443fb49179a247de166a P ead5f2336a04427480deb54762779c17: Deleting log segment in path: /tmp/dist-test-taskCQqSFo/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515475780686-21826-0/minicluster-data/ts-0-root/wals/1ff0bf7f1072443fb49179a247de166a/wal-000000029 (ops 139-143)
I20260812 06:18:00.352795 21991 log.cc:1079] T 1ff0bf7f1072443fb49179a247de166a P ead5f2336a04427480deb54762779c17: Deleting log segment in path: /tmp/dist-test-taskCQqSFo/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515475780686-21826-0/minicluster-data/ts-0-root/wals/1ff0bf7f1072443fb49179a247de166a/wal-000000030 (ops 144-148)
I20260812 06:18:00.352841 21991 log.cc:1079] T 1ff0bf7f1072443fb49179a247de166a P ead5f2336a04427480deb54762779c17: Deleting log segment in path: /tmp/dist-test-taskCQqSFo/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515475780686-21826-0/minicluster-data/ts-0-root/wals/1ff0bf7f1072443fb49179a247de166a/wal-000000031 (ops 149-153)
I20260812 06:18:00.352877 21991 log.cc:1079] T 1ff0bf7f1072443fb49179a247de166a P ead5f2336a04427480deb54762779c17: Deleting log segment in path: /tmp/dist-test-taskCQqSFo/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515475780686-21826-0/minicluster-data/ts-0-root/wals/1ff0bf7f1072443fb49179a247de166a/wal-000000032 (ops 154-158)
I20260812 06:18:00.352923 21991 log.cc:1079] T 1ff0bf7f1072443fb49179a247de166a P ead5f2336a04427480deb54762779c17: Deleting log segment in path: /tmp/dist-test-taskCQqSFo/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515475780686-21826-0/minicluster-data/ts-0-root/wals/1ff0bf7f1072443fb49179a247de166a/wal-000000033 (ops 159-163)
I20260812 06:18:00.352967 21991 log.cc:1079] T 1ff0bf7f1072443fb49179a247de166a P ead5f2336a04427480deb54762779c17: Deleting log segment in path: /tmp/dist-test-taskCQqSFo/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515475780686-21826-0/minicluster-data/ts-0-root/wals/1ff0bf7f1072443fb49179a247de166a/wal-000000034 (ops 164-168)
I20260812 06:18:00.353011 21991 log.cc:1079] T 1ff0bf7f1072443fb49179a247de166a P ead5f2336a04427480deb54762779c17: Deleting log segment in path: /tmp/dist-test-taskCQqSFo/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515475780686-21826-0/minicluster-data/ts-0-root/wals/1ff0bf7f1072443fb49179a247de166a/wal-000000035 (ops 169-173)
I20260812 06:18:00.353058 21991 log.cc:1079] T 1ff0bf7f1072443fb49179a247de166a P ead5f2336a04427480deb54762779c17: Deleting log segment in path: /tmp/dist-test-taskCQqSFo/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515475780686-21826-0/minicluster-data/ts-0-root/wals/1ff0bf7f1072443fb49179a247de166a/wal-000000036 (ops 174-178)
I20260812 06:18:00.353103 21991 log.cc:1079] T 1ff0bf7f1072443fb49179a247de166a P ead5f2336a04427480deb54762779c17: Deleting log segment in path: /tmp/dist-test-taskCQqSFo/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515475780686-21826-0/minicluster-data/ts-0-root/wals/1ff0bf7f1072443fb49179a247de166a/wal-000000037 (ops 179-183)
I20260812 06:18:00.377048 21991 maintenance_manager.cc:643] P ead5f2336a04427480deb54762779c17: LogGCOp(1ff0bf7f1072443fb49179a247de166a) complete. Timing: real 0.025s	user 0.000s	sys 0.022s Metrics: {}
I20260812 06:18:00.377405 22089 maintenance_manager.cc:419] P ead5f2336a04427480deb54762779c17: Scheduling FlushDeltaMemStoresOp(1ff0bf7f1072443fb49179a247de166a): perf score=6.157687
I20260812 06:18:00.415588 21991 maintenance_manager.cc:643] P ead5f2336a04427480deb54762779c17: FlushDeltaMemStoresOp(1ff0bf7f1072443fb49179a247de166a) complete. Timing: real 0.038s	user 0.019s	sys 0.004s Metrics: {"bytes_written":8205079,"delete_count":0,"lbm_write_time_us":10034,"lbm_writes_lt_1ms":203,"reinsert_count":0,"update_count":1000}
I20260812 06:18:00.416128 22089 maintenance_manager.cc:419] P ead5f2336a04427480deb54762779c17: Scheduling LogGCOp(1ff0bf7f1072443fb49179a247de166a): free 12017954 bytes of WAL
I20260812 06:18:00.416342 21991 log_reader.cc:385] T 1ff0bf7f1072443fb49179a247de166a: removed 1 log segments from log reader
I20260812 06:18:00.416389 21991 log.cc:1079] T 1ff0bf7f1072443fb49179a247de166a P ead5f2336a04427480deb54762779c17: Deleting log segment in path: /tmp/dist-test-taskCQqSFo/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515475780686-21826-0/minicluster-data/ts-0-root/wals/1ff0bf7f1072443fb49179a247de166a/wal-000000038 (ops 184-188)
I20260812 06:18:00.418790 21991 maintenance_manager.cc:643] P ead5f2336a04427480deb54762779c17: LogGCOp(1ff0bf7f1072443fb49179a247de166a) complete. Timing: real 0.002s	user 0.000s	sys 0.000s Metrics: {}
I20260812 06:18:00.419153 22089 maintenance_manager.cc:419] P ead5f2336a04427480deb54762779c17: Scheduling FlushDeltaMemStoresOp(1ff0bf7f1072443fb49179a247de166a): perf score=2.188937
I20260812 06:18:00.432145 21991 maintenance_manager.cc:643] P ead5f2336a04427480deb54762779c17: FlushDeltaMemStoresOp(1ff0bf7f1072443fb49179a247de166a) complete. Timing: real 0.013s	user 0.002s	sys 0.009s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4975,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:00.432711 22089 maintenance_manager.cc:419] P ead5f2336a04427480deb54762779c17: Scheduling UndoDeltaBlockGCOp(1ff0bf7f1072443fb49179a247de166a): 472 bytes on disk
I20260812 06:18:00.433314 21991 maintenance_manager.cc:643] P ead5f2336a04427480deb54762779c17: UndoDeltaBlockGCOp(1ff0bf7f1072443fb49179a247de166a) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":65,"lbm_reads_lt_1ms":4}
I20260812 06:18:00.434072 22089 maintenance_manager.cc:419] P ead5f2336a04427480deb54762779c17: Scheduling MajorDeltaCompactionOp(1ff0bf7f1072443fb49179a247de166a): perf score=1.000000
I20260812 06:18:00.644286 21991 maintenance_manager.cc:643] P ead5f2336a04427480deb54762779c17: MajorDeltaCompactionOp(1ff0bf7f1072443fb49179a247de166a) complete. Timing: real 0.210s	user 0.146s	sys 0.063s Metrics: {"cfile_cache_miss":734,"cfile_cache_miss_bytes":32979752,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":887,"lbm_read_time_us":15099,"lbm_reads_lt_1ms":766,"lbm_write_time_us":39131,"lbm_writes_lt_1ms":743,"mutex_wait_us":21,"peak_mem_usage":87969044,"reinsert_count":0,"spinlock_wait_cycles":10880,"thread_start_us":96,"threads_started":1,"update_count":3500}
I20260812 06:18:00.644927 22089 maintenance_manager.cc:419] P ead5f2336a04427480deb54762779c17: Scheduling FlushDeltaMemStoresOp(1ff0bf7f1072443fb49179a247de166a): perf score=14.095187
I20260812 06:18:00.697527 21991 maintenance_manager.cc:643] P ead5f2336a04427480deb54762779c17: FlushDeltaMemStoresOp(1ff0bf7f1072443fb49179a247de166a) complete. Timing: real 0.052s	user 0.037s	sys 0.012s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":22901,"lbm_writes_1-10_ms":2,"lbm_writes_lt_1ms":401,"reinsert_count":0,"update_count":2000}
I20260812 06:18:00.698130 22089 maintenance_manager.cc:419] P ead5f2336a04427480deb54762779c17: Scheduling FlushDeltaMemStoresOp(1ff0bf7f1072443fb49179a247de166a): perf score=2.188937
I20260812 06:18:00.711891 21826 heavy-update-compaction-itest.cc:229] Time spent updating: real 4.663s	user 1.773s	sys 0.119s
I20260812 06:18:00.713476 21991 maintenance_manager.cc:643] P ead5f2336a04427480deb54762779c17: FlushDeltaMemStoresOp(1ff0bf7f1072443fb49179a247de166a) complete. Timing: real 0.015s	user 0.007s	sys 0.003s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4929,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:00.713936 22089 maintenance_manager.cc:419] P ead5f2336a04427480deb54762779c17: Scheduling FlushDeltaMemStoresOp(1ff0bf7f1072443fb49179a247de166a): perf score=2.188937
I20260812 06:18:00.723404 21991 maintenance_manager.cc:643] P ead5f2336a04427480deb54762779c17: FlushDeltaMemStoresOp(1ff0bf7f1072443fb49179a247de166a) complete. Timing: real 0.009s	user 0.009s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3996,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:00.723753 22089 maintenance_manager.cc:419] P ead5f2336a04427480deb54762779c17: Scheduling MajorDeltaCompactionOp(1ff0bf7f1072443fb49179a247de166a): perf score=1.000000
I20260812 06:18:00.766636 21826 heavy-update-compaction-itest.cc:265] Time spent scanning: real 0.054s	user 0.001s	sys 0.004s
I20260812 06:18:00.767417 21826 tablet_server.cc:179] TabletServer@127.21.80.129:0 shutting down...
I20260812 06:18:00.861938 21991 maintenance_manager.cc:643] P ead5f2336a04427480deb54762779c17: MajorDeltaCompactionOp(1ff0bf7f1072443fb49179a247de166a) complete. Timing: real 0.138s	user 0.109s	sys 0.027s Metrics: {"cfile_cache_hit":280,"cfile_cache_hit_bytes":11407856,"cfile_cache_miss":353,"cfile_cache_miss_bytes":17469363,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":822,"lbm_read_time_us":6309,"lbm_reads_lt_1ms":385,"lbm_write_time_us":29102,"lbm_writes_lt_1ms":643,"mutex_wait_us":63,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":132096,"update_count":3000}
I20260812 06:18:00.862845 21826 ts_tablet_manager.cc:1507] Shutting down tablet manager...
I20260812 06:18:00.863268 21826 tablet_replica.cc:333] T 1ff0bf7f1072443fb49179a247de166a P ead5f2336a04427480deb54762779c17: stopping tablet replica
I20260812 06:18:00.863539 21826 raft_consensus.cc:2243] T 1ff0bf7f1072443fb49179a247de166a P ead5f2336a04427480deb54762779c17 [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:18:00.863811 21826 raft_consensus.cc:2272] T 1ff0bf7f1072443fb49179a247de166a P ead5f2336a04427480deb54762779c17 [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:18:00.879503 21826 tablet_server.cc:196] TabletServer@127.21.80.129:0 shutdown complete.
I20260812 06:18:00.914955 21826 master.cc:562] Master@127.21.80.190:43525 shutting down...
I20260812 06:18:00.918573 21826 raft_consensus.cc:2243] T 00000000000000000000000000000000 P 74036b23fda847e284867a3c589501e2 [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:18:00.918732 21826 raft_consensus.cc:2272] T 00000000000000000000000000000000 P 74036b23fda847e284867a3c589501e2 [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:18:00.918785 21826 tablet_replica.cc:333] T 00000000000000000000000000000000 P 74036b23fda847e284867a3c589501e2: stopping tablet replica
I20260812 06:18:00.931232 21826 master.cc:584] Master@127.21.80.190:43525 shutdown complete.
[       OK ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/0 (5233 ms)
[ RUN      ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/1
I20260812 06:18:01.023864 21826 internal_mini_cluster.cc:156] Creating distributed mini masters. Addrs: 127.21.80.190:45665
I20260812 06:18:01.024209 21826 file_cache.cc:504] Constructed file cache file cache with capacity 419430
I20260812 06:18:01.026463 21826 server_base.cc:1061] running on GCE node
W20260812 06:18:01.026379 22136 instance_detector.cc:116] could not retrieve AWS instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:18:01.026396 22137 instance_detector.cc:116] could not retrieve Azure instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:18:01.026449 22140 instance_detector.cc:116] could not retrieve OpenStack instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:18:01.026897 21826 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:18:01.026952 21826 system_unsync_time.cc:38] NTP support is disabled. Clock error bounds will not be accurate. This configuration is not suitable for distributed clusters.
I20260812 06:18:01.026968 21826 hybrid_clock.cc:648] HybridClock initialized: now 1786515481026968 us; error 0 us; skew 500 ppm
I20260812 06:18:01.027770 21826 webserver.cc:533] Webserver started at http://127.21.80.190:43265/ using document root <none> and password file <none>
I20260812 06:18:01.027941 21826 fs_manager.cc:362] Metadata directory not provided
I20260812 06:18:01.027987 21826 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:18:01.028085 21826 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:18:01.028533 21826 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskCQqSFo/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515475780686-21826-0/minicluster-data/master-0-root/instance:
uuid: "8aa30d4fc4ce486c92942da655b2331c"
format_stamp: "Formatted at 2026-08-12 06:18:01 on dist-test-slave-znh6"
I20260812 06:18:01.030007 21826 fs_manager.cc:696] Time spent creating directory manager: real 0.001s	user 0.002s	sys 0.000s
I20260812 06:18:01.030929 22148 log_block_manager.cc:4127] Time spent loading block containers with low live blocks: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:18:01.031169 21826 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.001s	sys 0.000s
I20260812 06:18:01.031279 21826 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskCQqSFo/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515475780686-21826-0/minicluster-data/master-0-root
uuid: "8aa30d4fc4ce486c92942da655b2331c"
format_stamp: "Formatted at 2026-08-12 06:18:01 on dist-test-slave-znh6"
I20260812 06:18:01.031373 21826 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskCQqSFo/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515475780686-21826-0/minicluster-data/master-0-root
metadata directory: /tmp/dist-test-taskCQqSFo/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515475780686-21826-0/minicluster-data/master-0-root
1 data directories: /tmp/dist-test-taskCQqSFo/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515475780686-21826-0/minicluster-data/master-0-root/data
Total live blocks: 0
Total live bytes: 0
Total live bytes (after alignment): 0
Total number of LBM containers: 0 (0 full)
Did not check for missing blocks
Did not check for orphaned blocks
Total full LBM containers with extra space: 0 (0 repaired)
Total full LBM container extra space in bytes: 0 (0 repaired)
Total incomplete LBM containers: 0 (0 repaired)
Total LBM partial records: 0 (0 repaired)
Total corrupted LBM metadata records in RocksDB: 0 (0 repaired)
I20260812 06:18:01.047600 21826 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:18:01.047924 21826 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:18:01.051869 21826 rpc_server.cc:307] RPC server started. Bound to: 127.21.80.190:45665
I20260812 06:18:01.055661 22231 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.21.80.190:45665 every 8 connection(s)
I20260812 06:18:01.056378 22232 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet 00000000000000000000000000000000. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:18:01.062212 22232 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P 8aa30d4fc4ce486c92942da655b2331c: Bootstrap starting.
I20260812 06:18:01.062906 22232 tablet_bootstrap.cc:654] T 00000000000000000000000000000000 P 8aa30d4fc4ce486c92942da655b2331c: Neither blocks nor log segments found. Creating new log.
I20260812 06:18:01.063817 22232 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P 8aa30d4fc4ce486c92942da655b2331c: No bootstrap required, opened a new log
I20260812 06:18:01.064142 22232 raft_consensus.cc:359] T 00000000000000000000000000000000 P 8aa30d4fc4ce486c92942da655b2331c [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "8aa30d4fc4ce486c92942da655b2331c" member_type: VOTER }
I20260812 06:18:01.064222 22232 raft_consensus.cc:385] T 00000000000000000000000000000000 P 8aa30d4fc4ce486c92942da655b2331c [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:18:01.064244 22232 raft_consensus.cc:740] T 00000000000000000000000000000000 P 8aa30d4fc4ce486c92942da655b2331c [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: 8aa30d4fc4ce486c92942da655b2331c, State: Initialized, Role: FOLLOWER
I20260812 06:18:01.064383 22232 consensus_queue.cc:260] T 00000000000000000000000000000000 P 8aa30d4fc4ce486c92942da655b2331c [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: "8aa30d4fc4ce486c92942da655b2331c" member_type: VOTER }
I20260812 06:18:01.064443 22232 raft_consensus.cc:399] T 00000000000000000000000000000000 P 8aa30d4fc4ce486c92942da655b2331c [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:18:01.064466 22232 raft_consensus.cc:493] T 00000000000000000000000000000000 P 8aa30d4fc4ce486c92942da655b2331c [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:18:01.064499 22232 raft_consensus.cc:3060] T 00000000000000000000000000000000 P 8aa30d4fc4ce486c92942da655b2331c [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:18:01.065084 22232 raft_consensus.cc:515] T 00000000000000000000000000000000 P 8aa30d4fc4ce486c92942da655b2331c [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "8aa30d4fc4ce486c92942da655b2331c" member_type: VOTER }
I20260812 06:18:01.065196 22232 leader_election.cc:304] T 00000000000000000000000000000000 P 8aa30d4fc4ce486c92942da655b2331c [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: 8aa30d4fc4ce486c92942da655b2331c; no voters: 
I20260812 06:18:01.065338 22232 leader_election.cc:290] T 00000000000000000000000000000000 P 8aa30d4fc4ce486c92942da655b2331c [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:18:01.065500 22238 raft_consensus.cc:2804] T 00000000000000000000000000000000 P 8aa30d4fc4ce486c92942da655b2331c [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:18:01.065690 22238 raft_consensus.cc:697] T 00000000000000000000000000000000 P 8aa30d4fc4ce486c92942da655b2331c [term 1 LEADER]: Becoming Leader. State: Replica: 8aa30d4fc4ce486c92942da655b2331c, State: Running, Role: LEADER
I20260812 06:18:01.065806 22232 sys_catalog.cc:565] T 00000000000000000000000000000000 P 8aa30d4fc4ce486c92942da655b2331c [sys.catalog]: configured and running, proceeding with master startup.
I20260812 06:18:01.065863 22238 consensus_queue.cc:237] T 00000000000000000000000000000000 P 8aa30d4fc4ce486c92942da655b2331c [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: "8aa30d4fc4ce486c92942da655b2331c" member_type: VOTER }
I20260812 06:18:01.066323 22240 sys_catalog.cc:455] T 00000000000000000000000000000000 P 8aa30d4fc4ce486c92942da655b2331c [sys.catalog]: SysCatalogTable state changed. Reason: New leader 8aa30d4fc4ce486c92942da655b2331c. Latest consensus state: current_term: 1 leader_uuid: "8aa30d4fc4ce486c92942da655b2331c" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "8aa30d4fc4ce486c92942da655b2331c" member_type: VOTER } }
I20260812 06:18:01.066421 22240 sys_catalog.cc:458] T 00000000000000000000000000000000 P 8aa30d4fc4ce486c92942da655b2331c [sys.catalog]: This master's current role is: LEADER
I20260812 06:18:01.066305 22239 sys_catalog.cc:455] T 00000000000000000000000000000000 P 8aa30d4fc4ce486c92942da655b2331c [sys.catalog]: SysCatalogTable state changed. Reason: RaftConsensus started. Latest consensus state: current_term: 1 leader_uuid: "8aa30d4fc4ce486c92942da655b2331c" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "8aa30d4fc4ce486c92942da655b2331c" member_type: VOTER } }
I20260812 06:18:01.066561 22239 sys_catalog.cc:458] T 00000000000000000000000000000000 P 8aa30d4fc4ce486c92942da655b2331c [sys.catalog]: This master's current role is: LEADER
I20260812 06:18:01.067183 22247 catalog_manager.cc:1511] Loading table and tablet metadata into memory...
I20260812 06:18:01.068128 22247 catalog_manager.cc:1520] Initializing Kudu cluster ID...
I20260812 06:18:01.068362 21826 internal_mini_cluster.cc:184] Waiting to initialize catalog manager on master 0
I20260812 06:18:01.069933 22247 catalog_manager.cc:1383] Generated new cluster ID: 7c2b7a965cdb4126878ac8f3b9caea84
I20260812 06:18:01.069989 22247 catalog_manager.cc:1531] Initializing Kudu internal certificate authority...
I20260812 06:18:01.085381 22247 catalog_manager.cc:1406] Generated new certificate authority record
I20260812 06:18:01.085850 22247 catalog_manager.cc:1540] Loading token signing keys...
I20260812 06:18:01.092168 22247 catalog_manager.cc:6092] T 00000000000000000000000000000000 P 8aa30d4fc4ce486c92942da655b2331c: Generated new TSK 0
I20260812 06:18:01.092315 22247 catalog_manager.cc:1550] Initializing in-progress tserver states...
I20260812 06:18:01.100498 21826 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:18:01.102216 22271 instance_detector.cc:116] could not retrieve Azure instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:18:01.102373 22273 instance_detector.cc:116] could not retrieve OpenStack instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:18:01.102353 21826 server_base.cc:1061] running on GCE node
W20260812 06:18:01.102344 22269 instance_detector.cc:116] could not retrieve AWS instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:18:01.102644 21826 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:18:01.102686 21826 system_unsync_time.cc:38] NTP support is disabled. Clock error bounds will not be accurate. This configuration is not suitable for distributed clusters.
I20260812 06:18:01.102701 21826 hybrid_clock.cc:648] HybridClock initialized: now 1786515481102701 us; error 0 us; skew 500 ppm
I20260812 06:18:01.103523 21826 webserver.cc:533] Webserver started at http://127.21.80.129:42879/ using document root <none> and password file <none>
I20260812 06:18:01.103639 21826 fs_manager.cc:362] Metadata directory not provided
I20260812 06:18:01.103677 21826 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:18:01.103725 21826 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:18:01.104091 21826 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskCQqSFo/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515475780686-21826-0/minicluster-data/ts-0-root/instance:
uuid: "3bade047a80b4bf79e872e69a1737c34"
format_stamp: "Formatted at 2026-08-12 06:18:01 on dist-test-slave-znh6"
I20260812 06:18:01.105413 21826 fs_manager.cc:696] Time spent creating directory manager: real 0.001s	user 0.000s	sys 0.002s
I20260812 06:18:01.106201 22278 log_block_manager.cc:4127] Time spent loading block containers with low live blocks: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:18:01.106432 21826 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.000s	sys 0.001s
I20260812 06:18:01.106491 21826 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskCQqSFo/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515475780686-21826-0/minicluster-data/ts-0-root
uuid: "3bade047a80b4bf79e872e69a1737c34"
format_stamp: "Formatted at 2026-08-12 06:18:01 on dist-test-slave-znh6"
I20260812 06:18:01.106539 21826 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskCQqSFo/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515475780686-21826-0/minicluster-data/ts-0-root
metadata directory: /tmp/dist-test-taskCQqSFo/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515475780686-21826-0/minicluster-data/ts-0-root
1 data directories: /tmp/dist-test-taskCQqSFo/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515475780686-21826-0/minicluster-data/ts-0-root/data
Total live blocks: 0
Total live bytes: 0
Total live bytes (after alignment): 0
Total number of LBM containers: 0 (0 full)
Did not check for missing blocks
Did not check for orphaned blocks
Total full LBM containers with extra space: 0 (0 repaired)
Total full LBM container extra space in bytes: 0 (0 repaired)
Total incomplete LBM containers: 0 (0 repaired)
Total LBM partial records: 0 (0 repaired)
Total corrupted LBM metadata records in RocksDB: 0 (0 repaired)
I20260812 06:18:01.119167 21826 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:18:01.119426 21826 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:18:01.119637 21826 txn_system_client.cc:432] TxnSystemClient initialization is disabled...
I20260812 06:18:01.120055 21826 ts_tablet_manager.cc:585] Loaded tablet metadata (0 total tablets, 0 live tablets)
I20260812 06:18:01.120091 21826 ts_tablet_manager.cc:531] Time spent load tablet metadata: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:18:01.120147 21826 ts_tablet_manager.cc:616] Registered 0 tablets
I20260812 06:18:01.120188 21826 ts_tablet_manager.cc:595] Time spent register tablets: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:18:01.124473 21826 rpc_server.cc:307] RPC server started. Bound to: 127.21.80.129:45125
I20260812 06:18:01.125692 22394 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.21.80.129:45125 every 8 connection(s)
I20260812 06:18:01.133677 22396 heartbeater.cc:344] Connected to a master server at 127.21.80.190:45665
I20260812 06:18:01.133765 22396 heartbeater.cc:461] Registering TS with master...
I20260812 06:18:01.133976 22396 heartbeater.cc:507] Master 127.21.80.190:45665 requested a full tablet report, sending...
I20260812 06:18:01.134580 22175 ts_manager.cc:194] Registered new tserver with Master: 3bade047a80b4bf79e872e69a1737c34 (127.21.80.129:45125)
I20260812 06:18:01.135205 21826 internal_mini_cluster.cc:371] 1 TS(s) registered with all masters after 0.009994987s
I20260812 06:18:01.135428 22175 master_service.cc:502] Signed X509 certificate for tserver {username='slave'} at 127.0.0.1:54914
I20260812 06:18:01.141661 22175 catalog_manager.cc:2283] Servicing CreateTable request from {username='slave'} at 127.0.0.1:54924:
name: "heavy-update-compaction-test"
schema {
  columns {
    name: "key"
    type: INT64
    is_key: true
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_a"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_b"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_c"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_d"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_e"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
}
num_replicas: 1
split_rows_range_bounds {
}
partition_schema {
  range_schema {
  }
}
I20260812 06:18:01.149969 22325 tablet_service.cc:1511] Processing CreateTablet for tablet ab6b259c5c924e39a766fc0786917dfc (DEFAULT_TABLE table=heavy-update-compaction-test [id=ba747b7771b54817a93b6dafe38b2260]), partition=
I20260812 06:18:01.150225 22325 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet ab6b259c5c924e39a766fc0786917dfc. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:18:01.152043 22413 tablet_bootstrap.cc:492] T ab6b259c5c924e39a766fc0786917dfc P 3bade047a80b4bf79e872e69a1737c34: Bootstrap starting.
I20260812 06:18:01.152987 22413 tablet_bootstrap.cc:654] T ab6b259c5c924e39a766fc0786917dfc P 3bade047a80b4bf79e872e69a1737c34: Neither blocks nor log segments found. Creating new log.
I20260812 06:18:01.153961 22413 tablet_bootstrap.cc:492] T ab6b259c5c924e39a766fc0786917dfc P 3bade047a80b4bf79e872e69a1737c34: No bootstrap required, opened a new log
I20260812 06:18:01.154032 22413 ts_tablet_manager.cc:1403] T ab6b259c5c924e39a766fc0786917dfc P 3bade047a80b4bf79e872e69a1737c34: Time spent bootstrapping tablet: real 0.002s	user 0.001s	sys 0.000s
I20260812 06:18:01.154397 22413 raft_consensus.cc:359] T ab6b259c5c924e39a766fc0786917dfc P 3bade047a80b4bf79e872e69a1737c34 [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "3bade047a80b4bf79e872e69a1737c34" member_type: VOTER last_known_addr { host: "127.21.80.129" port: 45125 } }
I20260812 06:18:01.154479 22413 raft_consensus.cc:385] T ab6b259c5c924e39a766fc0786917dfc P 3bade047a80b4bf79e872e69a1737c34 [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:18:01.154501 22413 raft_consensus.cc:740] T ab6b259c5c924e39a766fc0786917dfc P 3bade047a80b4bf79e872e69a1737c34 [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: 3bade047a80b4bf79e872e69a1737c34, State: Initialized, Role: FOLLOWER
I20260812 06:18:01.154596 22413 consensus_queue.cc:260] T ab6b259c5c924e39a766fc0786917dfc P 3bade047a80b4bf79e872e69a1737c34 [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: "3bade047a80b4bf79e872e69a1737c34" member_type: VOTER last_known_addr { host: "127.21.80.129" port: 45125 } }
I20260812 06:18:01.154654 22413 raft_consensus.cc:399] T ab6b259c5c924e39a766fc0786917dfc P 3bade047a80b4bf79e872e69a1737c34 [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:18:01.154677 22413 raft_consensus.cc:493] T ab6b259c5c924e39a766fc0786917dfc P 3bade047a80b4bf79e872e69a1737c34 [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:18:01.154711 22413 raft_consensus.cc:3060] T ab6b259c5c924e39a766fc0786917dfc P 3bade047a80b4bf79e872e69a1737c34 [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:18:01.155624 22413 raft_consensus.cc:515] T ab6b259c5c924e39a766fc0786917dfc P 3bade047a80b4bf79e872e69a1737c34 [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "3bade047a80b4bf79e872e69a1737c34" member_type: VOTER last_known_addr { host: "127.21.80.129" port: 45125 } }
I20260812 06:18:01.155799 22413 leader_election.cc:304] T ab6b259c5c924e39a766fc0786917dfc P 3bade047a80b4bf79e872e69a1737c34 [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: 3bade047a80b4bf79e872e69a1737c34; no voters: 
I20260812 06:18:01.156008 22413 leader_election.cc:290] T ab6b259c5c924e39a766fc0786917dfc P 3bade047a80b4bf79e872e69a1737c34 [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:18:01.156095 22418 raft_consensus.cc:2804] T ab6b259c5c924e39a766fc0786917dfc P 3bade047a80b4bf79e872e69a1737c34 [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:18:01.156366 22418 raft_consensus.cc:697] T ab6b259c5c924e39a766fc0786917dfc P 3bade047a80b4bf79e872e69a1737c34 [term 1 LEADER]: Becoming Leader. State: Replica: 3bade047a80b4bf79e872e69a1737c34, State: Running, Role: LEADER
I20260812 06:18:01.156378 22413 ts_tablet_manager.cc:1434] T ab6b259c5c924e39a766fc0786917dfc P 3bade047a80b4bf79e872e69a1737c34: Time spent starting tablet: real 0.002s	user 0.000s	sys 0.003s
I20260812 06:18:01.156432 22396 heartbeater.cc:499] Master 127.21.80.190:45665 was elected leader, sending a full tablet report...
I20260812 06:18:01.156507 22418 consensus_queue.cc:237] T ab6b259c5c924e39a766fc0786917dfc P 3bade047a80b4bf79e872e69a1737c34 [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: "3bade047a80b4bf79e872e69a1737c34" member_type: VOTER last_known_addr { host: "127.21.80.129" port: 45125 } }
I20260812 06:18:01.157768 22175 catalog_manager.cc:5719] T ab6b259c5c924e39a766fc0786917dfc P 3bade047a80b4bf79e872e69a1737c34 reported cstate change: term changed from 0 to 1, leader changed from <none> to 3bade047a80b4bf79e872e69a1737c34 (127.21.80.129). New cstate: current_term: 1 leader_uuid: "3bade047a80b4bf79e872e69a1737c34" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "3bade047a80b4bf79e872e69a1737c34" member_type: VOTER last_known_addr { host: "127.21.80.129" port: 45125 } health_report { overall_health: HEALTHY } } }
I20260812 06:18:01.212738 21826 heavy-update-compaction-itest.cc:215] Time spent inserting: real 0.051s	user 0.016s	sys 0.006s
I20260812 06:18:01.376231 22397 maintenance_manager.cc:419] P 3bade047a80b4bf79e872e69a1737c34: Scheduling FlushMRSOp(ab6b259c5c924e39a766fc0786917dfc): perf score=23.023690
I20260812 06:18:01.535588 22286 maintenance_manager.cc:643] P 3bade047a80b4bf79e872e69a1737c34: FlushMRSOp(ab6b259c5c924e39a766fc0786917dfc) complete. Timing: real 0.159s	user 0.118s	sys 0.040s Metrics: {"bytes_written":12307490,"cfile_init":1,"delete_count":0,"dirs.queue_time_us":84,"dirs.run_cpu_time_us":230,"dirs.run_wall_time_us":826,"drs_written":1,"lbm_read_time_us":36,"lbm_reads_lt_1ms":4,"lbm_write_time_us":43320,"lbm_writes_lt_1ms":857,"peak_mem_usage":0,"reinsert_count":0,"rows_written":105,"update_count":1500}
I20260812 06:18:01.536185 22397 maintenance_manager.cc:419] P 3bade047a80b4bf79e872e69a1737c34: Scheduling LogGCOp(ab6b259c5c924e39a766fc0786917dfc): free 20290830 bytes of WAL
I20260812 06:18:01.536474 22286 log_reader.cc:385] T ab6b259c5c924e39a766fc0786917dfc: removed 2 log segments from log reader
I20260812 06:18:01.536525 22286 log.cc:1079] T ab6b259c5c924e39a766fc0786917dfc P 3bade047a80b4bf79e872e69a1737c34: Deleting log segment in path: /tmp/dist-test-taskCQqSFo/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515475780686-21826-0/minicluster-data/ts-0-root/wals/ab6b259c5c924e39a766fc0786917dfc/wal-000000001 (ops 1-6)
I20260812 06:18:01.536556 22286 log.cc:1079] T ab6b259c5c924e39a766fc0786917dfc P 3bade047a80b4bf79e872e69a1737c34: Deleting log segment in path: /tmp/dist-test-taskCQqSFo/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515475780686-21826-0/minicluster-data/ts-0-root/wals/ab6b259c5c924e39a766fc0786917dfc/wal-000000002 (ops 7-10)
I20260812 06:18:01.541322 22286 maintenance_manager.cc:643] P 3bade047a80b4bf79e872e69a1737c34: LogGCOp(ab6b259c5c924e39a766fc0786917dfc) complete. Timing: real 0.005s	user 0.000s	sys 0.002s Metrics: {}
I20260812 06:18:01.541775 22397 maintenance_manager.cc:419] P 3bade047a80b4bf79e872e69a1737c34: Scheduling UndoDeltaBlockGCOp(ab6b259c5c924e39a766fc0786917dfc): 20513814 bytes on disk
I20260812 06:18:01.542289 22286 maintenance_manager.cc:643] P 3bade047a80b4bf79e872e69a1737c34: UndoDeltaBlockGCOp(ab6b259c5c924e39a766fc0786917dfc) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":83,"lbm_reads_lt_1ms":4}
I20260812 06:18:01.542726 22397 maintenance_manager.cc:419] P 3bade047a80b4bf79e872e69a1737c34: Scheduling FlushDeltaMemStoresOp(ab6b259c5c924e39a766fc0786917dfc): perf score=2.188937
I20260812 06:18:01.555248 22286 maintenance_manager.cc:643] P 3bade047a80b4bf79e872e69a1737c34: FlushDeltaMemStoresOp(ab6b259c5c924e39a766fc0786917dfc) complete. Timing: real 0.012s	user 0.008s	sys 0.004s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4924,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:01.555619 22397 maintenance_manager.cc:419] P 3bade047a80b4bf79e872e69a1737c34: Scheduling MajorDeltaCompactionOp(ab6b259c5c924e39a766fc0786917dfc): perf score=1.000000
I20260812 06:18:01.709435 22286 maintenance_manager.cc:643] P 3bade047a80b4bf79e872e69a1737c34: MajorDeltaCompactionOp(ab6b259c5c924e39a766fc0786917dfc) complete. Timing: real 0.154s	user 0.102s	sys 0.052s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20713271,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":519,"lbm_read_time_us":11289,"lbm_reads_lt_1ms":464,"lbm_write_time_us":25628,"lbm_writes_lt_1ms":443,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":7552,"thread_start_us":358,"threads_started":5,"update_count":2000}
I20260812 06:18:01.710057 22397 maintenance_manager.cc:419] P 3bade047a80b4bf79e872e69a1737c34: Scheduling FlushDeltaMemStoresOp(ab6b259c5c924e39a766fc0786917dfc): perf score=11.118625
I20260812 06:18:01.739764 22286 maintenance_manager.cc:643] P 3bade047a80b4bf79e872e69a1737c34: FlushDeltaMemStoresOp(ab6b259c5c924e39a766fc0786917dfc) complete. Timing: real 0.030s	user 0.017s	sys 0.012s Metrics: {"bytes_written":12717736,"delete_count":0,"lbm_write_time_us":13284,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:18:01.740204 22397 maintenance_manager.cc:419] P 3bade047a80b4bf79e872e69a1737c34: Scheduling FlushDeltaMemStoresOp(ab6b259c5c924e39a766fc0786917dfc): perf score=2.188937
I20260812 06:18:01.749807 22286 maintenance_manager.cc:643] P 3bade047a80b4bf79e872e69a1737c34: FlushDeltaMemStoresOp(ab6b259c5c924e39a766fc0786917dfc) complete. Timing: real 0.009s	user 0.008s	sys 0.000s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3685,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:18:01.750221 22397 maintenance_manager.cc:419] P 3bade047a80b4bf79e872e69a1737c34: Scheduling MajorDeltaCompactionOp(ab6b259c5c924e39a766fc0786917dfc): perf score=1.000000
I20260812 06:18:01.902491 22286 maintenance_manager.cc:643] P 3bade047a80b4bf79e872e69a1737c34: MajorDeltaCompactionOp(ab6b259c5c924e39a766fc0786917dfc) complete. Timing: real 0.152s	user 0.116s	sys 0.036s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20713264,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":219,"lbm_read_time_us":11714,"lbm_reads_lt_1ms":472,"lbm_write_time_us":26831,"lbm_writes_lt_1ms":443,"mutex_wait_us":54,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":11904,"update_count":2000}
I20260812 06:18:01.905898 22397 maintenance_manager.cc:419] P 3bade047a80b4bf79e872e69a1737c34: Scheduling FlushDeltaMemStoresOp(ab6b259c5c924e39a766fc0786917dfc): perf score=10.126437
I20260812 06:18:01.943768 22286 maintenance_manager.cc:643] P 3bade047a80b4bf79e872e69a1737c34: FlushDeltaMemStoresOp(ab6b259c5c924e39a766fc0786917dfc) complete. Timing: real 0.038s	user 0.029s	sys 0.008s Metrics: {"bytes_written":12307491,"delete_count":0,"lbm_write_time_us":17591,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:18:01.944197 22397 maintenance_manager.cc:419] P 3bade047a80b4bf79e872e69a1737c34: Scheduling FlushDeltaMemStoresOp(ab6b259c5c924e39a766fc0786917dfc): perf score=2.188937
I20260812 06:18:01.955822 22286 maintenance_manager.cc:643] P 3bade047a80b4bf79e872e69a1737c34: FlushDeltaMemStoresOp(ab6b259c5c924e39a766fc0786917dfc) complete. Timing: real 0.011s	user 0.005s	sys 0.005s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4356,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:01.956323 22397 maintenance_manager.cc:419] P 3bade047a80b4bf79e872e69a1737c34: Scheduling MajorDeltaCompactionOp(ab6b259c5c924e39a766fc0786917dfc): perf score=1.000000
I20260812 06:18:02.090034 22286 maintenance_manager.cc:643] P 3bade047a80b4bf79e872e69a1737c34: MajorDeltaCompactionOp(ab6b259c5c924e39a766fc0786917dfc) complete. Timing: real 0.134s	user 0.091s	sys 0.041s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20713273,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":621,"lbm_read_time_us":10477,"lbm_reads_lt_1ms":472,"lbm_write_time_us":25543,"lbm_writes_lt_1ms":443,"mutex_wait_us":37,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":9216,"update_count":2000}
I20260812 06:18:02.090728 22397 maintenance_manager.cc:419] P 3bade047a80b4bf79e872e69a1737c34: Scheduling FlushDeltaMemStoresOp(ab6b259c5c924e39a766fc0786917dfc): perf score=10.126437
I20260812 06:18:02.131304 22286 maintenance_manager.cc:643] P 3bade047a80b4bf79e872e69a1737c34: FlushDeltaMemStoresOp(ab6b259c5c924e39a766fc0786917dfc) complete. Timing: real 0.040s	user 0.028s	sys 0.008s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":15802,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:18:02.131783 22397 maintenance_manager.cc:419] P 3bade047a80b4bf79e872e69a1737c34: Scheduling FlushDeltaMemStoresOp(ab6b259c5c924e39a766fc0786917dfc): perf score=2.188937
I20260812 06:18:02.142675 22286 maintenance_manager.cc:643] P 3bade047a80b4bf79e872e69a1737c34: FlushDeltaMemStoresOp(ab6b259c5c924e39a766fc0786917dfc) complete. Timing: real 0.011s	user 0.005s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4153,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:02.143275 22397 maintenance_manager.cc:419] P 3bade047a80b4bf79e872e69a1737c34: Scheduling MajorDeltaCompactionOp(ab6b259c5c924e39a766fc0786917dfc): perf score=1.000000
I20260812 06:18:02.262487 22286 maintenance_manager.cc:643] P 3bade047a80b4bf79e872e69a1737c34: MajorDeltaCompactionOp(ab6b259c5c924e39a766fc0786917dfc) complete. Timing: real 0.119s	user 0.099s	sys 0.020s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20713272,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":420,"lbm_read_time_us":9249,"lbm_reads_lt_1ms":472,"lbm_write_time_us":22754,"lbm_writes_lt_1ms":443,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":1792,"update_count":2000}
I20260812 06:18:02.263129 22397 maintenance_manager.cc:419] P 3bade047a80b4bf79e872e69a1737c34: Scheduling FlushDeltaMemStoresOp(ab6b259c5c924e39a766fc0786917dfc): perf score=10.126437
I20260812 06:18:02.312209 22286 maintenance_manager.cc:643] P 3bade047a80b4bf79e872e69a1737c34: FlushDeltaMemStoresOp(ab6b259c5c924e39a766fc0786917dfc) complete. Timing: real 0.049s	user 0.028s	sys 0.020s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":20351,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:18:02.312724 22397 maintenance_manager.cc:419] P 3bade047a80b4bf79e872e69a1737c34: Scheduling FlushDeltaMemStoresOp(ab6b259c5c924e39a766fc0786917dfc): perf score=2.188937
I20260812 06:18:02.323879 22286 maintenance_manager.cc:643] P 3bade047a80b4bf79e872e69a1737c34: FlushDeltaMemStoresOp(ab6b259c5c924e39a766fc0786917dfc) complete. Timing: real 0.011s	user 0.005s	sys 0.005s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4248,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:02.324529 22397 maintenance_manager.cc:419] P 3bade047a80b4bf79e872e69a1737c34: Scheduling MajorDeltaCompactionOp(ab6b259c5c924e39a766fc0786917dfc): perf score=1.000000
I20260812 06:18:02.449342 22286 maintenance_manager.cc:643] P 3bade047a80b4bf79e872e69a1737c34: MajorDeltaCompactionOp(ab6b259c5c924e39a766fc0786917dfc) complete. Timing: real 0.125s	user 0.092s	sys 0.030s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20713272,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":604,"lbm_read_time_us":8007,"lbm_reads_lt_1ms":472,"lbm_write_time_us":23521,"lbm_writes_lt_1ms":443,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":1280,"update_count":2000}
I20260812 06:18:02.450194 22397 maintenance_manager.cc:419] P 3bade047a80b4bf79e872e69a1737c34: Scheduling FlushDeltaMemStoresOp(ab6b259c5c924e39a766fc0786917dfc): perf score=11.118625
I20260812 06:18:02.495988 22286 maintenance_manager.cc:643] P 3bade047a80b4bf79e872e69a1737c34: FlushDeltaMemStoresOp(ab6b259c5c924e39a766fc0786917dfc) complete. Timing: real 0.046s	user 0.025s	sys 0.019s Metrics: {"bytes_written":12717735,"delete_count":0,"lbm_write_time_us":15713,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:18:02.496507 22397 maintenance_manager.cc:419] P 3bade047a80b4bf79e872e69a1737c34: Scheduling FlushDeltaMemStoresOp(ab6b259c5c924e39a766fc0786917dfc): perf score=2.188937
I20260812 06:18:02.506273 22286 maintenance_manager.cc:643] P 3bade047a80b4bf79e872e69a1737c34: FlushDeltaMemStoresOp(ab6b259c5c924e39a766fc0786917dfc) complete. Timing: real 0.010s	user 0.008s	sys 0.000s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3715,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:18:02.506716 22397 maintenance_manager.cc:419] P 3bade047a80b4bf79e872e69a1737c34: Scheduling MajorDeltaCompactionOp(ab6b259c5c924e39a766fc0786917dfc): perf score=1.000000
I20260812 06:18:02.654181 22286 maintenance_manager.cc:643] P 3bade047a80b4bf79e872e69a1737c34: MajorDeltaCompactionOp(ab6b259c5c924e39a766fc0786917dfc) complete. Timing: real 0.147s	user 0.095s	sys 0.049s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20713263,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":149,"lbm_read_time_us":11175,"lbm_reads_lt_1ms":472,"lbm_write_time_us":24282,"lbm_writes_lt_1ms":443,"peak_mem_usage":50689328,"reinsert_count":0,"update_count":2000}
I20260812 06:18:02.654771 22397 maintenance_manager.cc:419] P 3bade047a80b4bf79e872e69a1737c34: Scheduling FlushDeltaMemStoresOp(ab6b259c5c924e39a766fc0786917dfc): perf score=10.126437
I20260812 06:18:02.689991 22286 maintenance_manager.cc:643] P 3bade047a80b4bf79e872e69a1737c34: FlushDeltaMemStoresOp(ab6b259c5c924e39a766fc0786917dfc) complete. Timing: real 0.035s	user 0.009s	sys 0.022s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":14299,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:18:02.690516 22397 maintenance_manager.cc:419] P 3bade047a80b4bf79e872e69a1737c34: Scheduling FlushDeltaMemStoresOp(ab6b259c5c924e39a766fc0786917dfc): perf score=2.188937
I20260812 06:18:02.702659 22286 maintenance_manager.cc:643] P 3bade047a80b4bf79e872e69a1737c34: FlushDeltaMemStoresOp(ab6b259c5c924e39a766fc0786917dfc) complete. Timing: real 0.012s	user 0.007s	sys 0.003s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4726,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:02.703318 22397 maintenance_manager.cc:419] P 3bade047a80b4bf79e872e69a1737c34: Scheduling FlushMRSOp(ab6b259c5c924e39a766fc0786917dfc): perf score=1.000000
I20260812 06:18:02.733691 22286 maintenance_manager.cc:643] P 3bade047a80b4bf79e872e69a1737c34: FlushMRSOp(ab6b259c5c924e39a766fc0786917dfc) complete. Timing: real 0.030s	user 0.023s	sys 0.005s Metrics: {"bytes_written":1152508,"cfile_init":1,"dirs.queue_time_us":74,"dirs.run_cpu_time_us":224,"dirs.run_wall_time_us":1174,"drs_written":1,"lbm_read_time_us":54,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1794,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":28}
I20260812 06:18:02.734359 22397 maintenance_manager.cc:419] P 3bade047a80b4bf79e872e69a1737c34: Scheduling LogGCOp(ab6b259c5c924e39a766fc0786917dfc): free 121006422 bytes of WAL
I20260812 06:18:02.734619 22286 log_reader.cc:385] T ab6b259c5c924e39a766fc0786917dfc: removed 12 log segments from log reader
I20260812 06:18:02.734683 22286 log.cc:1079] T ab6b259c5c924e39a766fc0786917dfc P 3bade047a80b4bf79e872e69a1737c34: Deleting log segment in path: /tmp/dist-test-taskCQqSFo/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515475780686-21826-0/minicluster-data/ts-0-root/wals/ab6b259c5c924e39a766fc0786917dfc/wal-000000003 (ops 11-15)
I20260812 06:18:02.734719 22286 log.cc:1079] T ab6b259c5c924e39a766fc0786917dfc P 3bade047a80b4bf79e872e69a1737c34: Deleting log segment in path: /tmp/dist-test-taskCQqSFo/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515475780686-21826-0/minicluster-data/ts-0-root/wals/ab6b259c5c924e39a766fc0786917dfc/wal-000000004 (ops 16-20)
I20260812 06:18:02.734757 22286 log.cc:1079] T ab6b259c5c924e39a766fc0786917dfc P 3bade047a80b4bf79e872e69a1737c34: Deleting log segment in path: /tmp/dist-test-taskCQqSFo/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515475780686-21826-0/minicluster-data/ts-0-root/wals/ab6b259c5c924e39a766fc0786917dfc/wal-000000005 (ops 21-25)
I20260812 06:18:02.734792 22286 log.cc:1079] T ab6b259c5c924e39a766fc0786917dfc P 3bade047a80b4bf79e872e69a1737c34: Deleting log segment in path: /tmp/dist-test-taskCQqSFo/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515475780686-21826-0/minicluster-data/ts-0-root/wals/ab6b259c5c924e39a766fc0786917dfc/wal-000000006 (ops 26-30)
I20260812 06:18:02.734861 22286 log.cc:1079] T ab6b259c5c924e39a766fc0786917dfc P 3bade047a80b4bf79e872e69a1737c34: Deleting log segment in path: /tmp/dist-test-taskCQqSFo/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515475780686-21826-0/minicluster-data/ts-0-root/wals/ab6b259c5c924e39a766fc0786917dfc/wal-000000007 (ops 31-34)
I20260812 06:18:02.734887 22286 log.cc:1079] T ab6b259c5c924e39a766fc0786917dfc P 3bade047a80b4bf79e872e69a1737c34: Deleting log segment in path: /tmp/dist-test-taskCQqSFo/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515475780686-21826-0/minicluster-data/ts-0-root/wals/ab6b259c5c924e39a766fc0786917dfc/wal-000000008 (ops 35-39)
I20260812 06:18:02.734910 22286 log.cc:1079] T ab6b259c5c924e39a766fc0786917dfc P 3bade047a80b4bf79e872e69a1737c34: Deleting log segment in path: /tmp/dist-test-taskCQqSFo/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515475780686-21826-0/minicluster-data/ts-0-root/wals/ab6b259c5c924e39a766fc0786917dfc/wal-000000009 (ops 40-44)
I20260812 06:18:02.734939 22286 log.cc:1079] T ab6b259c5c924e39a766fc0786917dfc P 3bade047a80b4bf79e872e69a1737c34: Deleting log segment in path: /tmp/dist-test-taskCQqSFo/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515475780686-21826-0/minicluster-data/ts-0-root/wals/ab6b259c5c924e39a766fc0786917dfc/wal-000000010 (ops 45-49)
I20260812 06:18:02.734972 22286 log.cc:1079] T ab6b259c5c924e39a766fc0786917dfc P 3bade047a80b4bf79e872e69a1737c34: Deleting log segment in path: /tmp/dist-test-taskCQqSFo/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515475780686-21826-0/minicluster-data/ts-0-root/wals/ab6b259c5c924e39a766fc0786917dfc/wal-000000011 (ops 50-54)
I20260812 06:18:02.735005 22286 log.cc:1079] T ab6b259c5c924e39a766fc0786917dfc P 3bade047a80b4bf79e872e69a1737c34: Deleting log segment in path: /tmp/dist-test-taskCQqSFo/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515475780686-21826-0/minicluster-data/ts-0-root/wals/ab6b259c5c924e39a766fc0786917dfc/wal-000000012 (ops 55-59)
I20260812 06:18:02.735038 22286 log.cc:1079] T ab6b259c5c924e39a766fc0786917dfc P 3bade047a80b4bf79e872e69a1737c34: Deleting log segment in path: /tmp/dist-test-taskCQqSFo/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515475780686-21826-0/minicluster-data/ts-0-root/wals/ab6b259c5c924e39a766fc0786917dfc/wal-000000013 (ops 60-64)
I20260812 06:18:02.735067 22286 log.cc:1079] T ab6b259c5c924e39a766fc0786917dfc P 3bade047a80b4bf79e872e69a1737c34: Deleting log segment in path: /tmp/dist-test-taskCQqSFo/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515475780686-21826-0/minicluster-data/ts-0-root/wals/ab6b259c5c924e39a766fc0786917dfc/wal-000000014 (ops 65-69)
I20260812 06:18:02.763427 22286 maintenance_manager.cc:643] P 3bade047a80b4bf79e872e69a1737c34: LogGCOp(ab6b259c5c924e39a766fc0786917dfc) complete. Timing: real 0.029s	user 0.001s	sys 0.027s Metrics: {}
I20260812 06:18:02.763887 22397 maintenance_manager.cc:419] P 3bade047a80b4bf79e872e69a1737c34: Scheduling UndoDeltaBlockGCOp(ab6b259c5c924e39a766fc0786917dfc): 447 bytes on disk
I20260812 06:18:02.764283 22286 maintenance_manager.cc:643] P 3bade047a80b4bf79e872e69a1737c34: UndoDeltaBlockGCOp(ab6b259c5c924e39a766fc0786917dfc) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":50,"lbm_reads_lt_1ms":4}
I20260812 06:18:02.764832 22397 maintenance_manager.cc:419] P 3bade047a80b4bf79e872e69a1737c34: Scheduling FlushDeltaMemStoresOp(ab6b259c5c924e39a766fc0786917dfc): perf score=3.181125
I20260812 06:18:02.785419 22286 maintenance_manager.cc:643] P 3bade047a80b4bf79e872e69a1737c34: FlushDeltaMemStoresOp(ab6b259c5c924e39a766fc0786917dfc) complete. Timing: real 0.020s	user 0.000s	sys 0.018s Metrics: {"bytes_written":4800077,"delete_count":0,"lbm_write_time_us":4874,"lbm_writes_lt_1ms":120,"reinsert_count":0,"update_count":585}
I20260812 06:18:02.785859 22397 maintenance_manager.cc:419] P 3bade047a80b4bf79e872e69a1737c34: Scheduling FlushDeltaMemStoresOp(ab6b259c5c924e39a766fc0786917dfc): perf score=2.188937
I20260812 06:18:02.794991 22286 maintenance_manager.cc:643] P 3bade047a80b4bf79e872e69a1737c34: FlushDeltaMemStoresOp(ab6b259c5c924e39a766fc0786917dfc) complete. Timing: real 0.009s	user 0.005s	sys 0.004s Metrics: {"bytes_written":3405230,"delete_count":0,"lbm_write_time_us":3686,"lbm_writes_lt_1ms":86,"reinsert_count":0,"update_count":415}
I20260812 06:18:02.795337 22397 maintenance_manager.cc:419] P 3bade047a80b4bf79e872e69a1737c34: Scheduling MajorDeltaCompactionOp(ab6b259c5c924e39a766fc0786917dfc): perf score=1.000000
I20260812 06:18:03.000918 22286 maintenance_manager.cc:643] P 3bade047a80b4bf79e872e69a1737c34: MajorDeltaCompactionOp(ab6b259c5c924e39a766fc0786917dfc) complete. Timing: real 0.205s	user 0.142s	sys 0.062s Metrics: {"cfile_cache_miss":634,"cfile_cache_miss_bytes":28918323,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":1481,"lbm_read_time_us":13668,"lbm_reads_lt_1ms":674,"lbm_write_time_us":35552,"lbm_writes_lt_1ms":643,"mutex_wait_us":298,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":6912,"thread_start_us":90,"threads_started":1,"update_count":3000}
I20260812 06:18:03.001613 22397 maintenance_manager.cc:419] P 3bade047a80b4bf79e872e69a1737c34: Scheduling FlushDeltaMemStoresOp(ab6b259c5c924e39a766fc0786917dfc): perf score=14.095187
I20260812 06:18:03.061708 22286 maintenance_manager.cc:643] P 3bade047a80b4bf79e872e69a1737c34: FlushDeltaMemStoresOp(ab6b259c5c924e39a766fc0786917dfc) complete. Timing: real 0.060s	user 0.028s	sys 0.029s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":21371,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:18:03.062170 22397 maintenance_manager.cc:419] P 3bade047a80b4bf79e872e69a1737c34: Scheduling FlushDeltaMemStoresOp(ab6b259c5c924e39a766fc0786917dfc): perf score=2.188937
I20260812 06:18:03.073091 22286 maintenance_manager.cc:643] P 3bade047a80b4bf79e872e69a1737c34: FlushDeltaMemStoresOp(ab6b259c5c924e39a766fc0786917dfc) complete. Timing: real 0.011s	user 0.006s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4446,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:03.073551 22397 maintenance_manager.cc:419] P 3bade047a80b4bf79e872e69a1737c34: Scheduling MajorDeltaCompactionOp(ab6b259c5c924e39a766fc0786917dfc): perf score=1.000000
I20260812 06:18:03.255488 22286 maintenance_manager.cc:643] P 3bade047a80b4bf79e872e69a1737c34: MajorDeltaCompactionOp(ab6b259c5c924e39a766fc0786917dfc) complete. Timing: real 0.182s	user 0.145s	sys 0.035s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24815684,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":193,"lbm_read_time_us":11964,"lbm_reads_lt_1ms":572,"lbm_write_time_us":31758,"lbm_writes_lt_1ms":543,"mutex_wait_us":21,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":4864,"update_count":2500}
I20260812 06:18:03.256094 22397 maintenance_manager.cc:419] P 3bade047a80b4bf79e872e69a1737c34: Scheduling FlushDeltaMemStoresOp(ab6b259c5c924e39a766fc0786917dfc): perf score=14.095187
I20260812 06:18:03.306679 22286 maintenance_manager.cc:643] P 3bade047a80b4bf79e872e69a1737c34: FlushDeltaMemStoresOp(ab6b259c5c924e39a766fc0786917dfc) complete. Timing: real 0.050s	user 0.037s	sys 0.004s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":19792,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:18:03.307276 22397 maintenance_manager.cc:419] P 3bade047a80b4bf79e872e69a1737c34: Scheduling FlushDeltaMemStoresOp(ab6b259c5c924e39a766fc0786917dfc): perf score=2.188937
I20260812 06:18:03.329365 22286 maintenance_manager.cc:643] P 3bade047a80b4bf79e872e69a1737c34: FlushDeltaMemStoresOp(ab6b259c5c924e39a766fc0786917dfc) complete. Timing: real 0.022s	user 0.004s	sys 0.015s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4214,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:03.329856 22397 maintenance_manager.cc:419] P 3bade047a80b4bf79e872e69a1737c34: Scheduling MajorDeltaCompactionOp(ab6b259c5c924e39a766fc0786917dfc): perf score=1.000000
I20260812 06:18:03.503881 22286 maintenance_manager.cc:643] P 3bade047a80b4bf79e872e69a1737c34: MajorDeltaCompactionOp(ab6b259c5c924e39a766fc0786917dfc) complete. Timing: real 0.174s	user 0.118s	sys 0.056s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24815684,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":356,"lbm_read_time_us":11525,"lbm_reads_lt_1ms":572,"lbm_write_time_us":29439,"lbm_writes_lt_1ms":543,"mutex_wait_us":40,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":768,"update_count":2500}
I20260812 06:18:03.504539 22397 maintenance_manager.cc:419] P 3bade047a80b4bf79e872e69a1737c34: Scheduling FlushDeltaMemStoresOp(ab6b259c5c924e39a766fc0786917dfc): perf score=14.095187
I20260812 06:18:03.558250 22286 maintenance_manager.cc:643] P 3bade047a80b4bf79e872e69a1737c34: FlushDeltaMemStoresOp(ab6b259c5c924e39a766fc0786917dfc) complete. Timing: real 0.054s	user 0.031s	sys 0.019s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":24275,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:18:03.558738 22397 maintenance_manager.cc:419] P 3bade047a80b4bf79e872e69a1737c34: Scheduling FlushDeltaMemStoresOp(ab6b259c5c924e39a766fc0786917dfc): perf score=2.188937
I20260812 06:18:03.572705 22286 maintenance_manager.cc:643] P 3bade047a80b4bf79e872e69a1737c34: FlushDeltaMemStoresOp(ab6b259c5c924e39a766fc0786917dfc) complete. Timing: real 0.014s	user 0.011s	sys 0.001s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5274,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:03.573294 22397 maintenance_manager.cc:419] P 3bade047a80b4bf79e872e69a1737c34: Scheduling MajorDeltaCompactionOp(ab6b259c5c924e39a766fc0786917dfc): perf score=1.000000
I20260812 06:18:03.751967 22286 maintenance_manager.cc:643] P 3bade047a80b4bf79e872e69a1737c34: MajorDeltaCompactionOp(ab6b259c5c924e39a766fc0786917dfc) complete. Timing: real 0.178s	user 0.107s	sys 0.064s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24815683,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":665,"lbm_read_time_us":10422,"lbm_reads_lt_1ms":568,"lbm_write_time_us":28173,"lbm_writes_lt_1ms":543,"mutex_wait_us":67,"peak_mem_usage":63115900,"reinsert_count":0,"update_count":2500}
I20260812 06:18:03.752558 22397 maintenance_manager.cc:419] P 3bade047a80b4bf79e872e69a1737c34: Scheduling FlushDeltaMemStoresOp(ab6b259c5c924e39a766fc0786917dfc): perf score=14.095187
I20260812 06:18:03.804569 22286 maintenance_manager.cc:643] P 3bade047a80b4bf79e872e69a1737c34: FlushDeltaMemStoresOp(ab6b259c5c924e39a766fc0786917dfc) complete. Timing: real 0.052s	user 0.030s	sys 0.020s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":23484,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:18:03.805107 22397 maintenance_manager.cc:419] P 3bade047a80b4bf79e872e69a1737c34: Scheduling FlushDeltaMemStoresOp(ab6b259c5c924e39a766fc0786917dfc): perf score=2.188937
I20260812 06:18:03.821543 22286 maintenance_manager.cc:643] P 3bade047a80b4bf79e872e69a1737c34: FlushDeltaMemStoresOp(ab6b259c5c924e39a766fc0786917dfc) complete. Timing: real 0.016s	user 0.009s	sys 0.004s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":5916,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:03.822108 22397 maintenance_manager.cc:419] P 3bade047a80b4bf79e872e69a1737c34: Scheduling MajorDeltaCompactionOp(ab6b259c5c924e39a766fc0786917dfc): perf score=1.000000
I20260812 06:18:03.970723 22286 maintenance_manager.cc:643] P 3bade047a80b4bf79e872e69a1737c34: MajorDeltaCompactionOp(ab6b259c5c924e39a766fc0786917dfc) complete. Timing: real 0.148s	user 0.116s	sys 0.028s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24815683,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":1026,"lbm_read_time_us":9343,"lbm_reads_lt_1ms":564,"lbm_write_time_us":29931,"lbm_writes_lt_1ms":543,"mutex_wait_us":342,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":12032,"update_count":2500}
I20260812 06:18:03.971392 22397 maintenance_manager.cc:419] P 3bade047a80b4bf79e872e69a1737c34: Scheduling FlushDeltaMemStoresOp(ab6b259c5c924e39a766fc0786917dfc): perf score=14.095187
I20260812 06:18:04.027279 22286 maintenance_manager.cc:643] P 3bade047a80b4bf79e872e69a1737c34: FlushDeltaMemStoresOp(ab6b259c5c924e39a766fc0786917dfc) complete. Timing: real 0.056s	user 0.033s	sys 0.015s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":22319,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:18:04.027861 22397 maintenance_manager.cc:419] P 3bade047a80b4bf79e872e69a1737c34: Scheduling FlushDeltaMemStoresOp(ab6b259c5c924e39a766fc0786917dfc): perf score=2.188937
I20260812 06:18:04.039264 22286 maintenance_manager.cc:643] P 3bade047a80b4bf79e872e69a1737c34: FlushDeltaMemStoresOp(ab6b259c5c924e39a766fc0786917dfc) complete. Timing: real 0.011s	user 0.011s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4237,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:04.039734 22397 maintenance_manager.cc:419] P 3bade047a80b4bf79e872e69a1737c34: Scheduling MajorDeltaCompactionOp(ab6b259c5c924e39a766fc0786917dfc): perf score=1.000000
I20260812 06:18:04.192633 22286 maintenance_manager.cc:643] P 3bade047a80b4bf79e872e69a1737c34: MajorDeltaCompactionOp(ab6b259c5c924e39a766fc0786917dfc) complete. Timing: real 0.153s	user 0.122s	sys 0.023s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24815684,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":599,"lbm_read_time_us":11225,"lbm_reads_lt_1ms":572,"lbm_write_time_us":28637,"lbm_writes_lt_1ms":543,"mutex_wait_us":329,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":29952,"update_count":2500}
I20260812 06:18:04.193183 22397 maintenance_manager.cc:419] P 3bade047a80b4bf79e872e69a1737c34: Scheduling FlushDeltaMemStoresOp(ab6b259c5c924e39a766fc0786917dfc): perf score=14.095187
I20260812 06:18:04.252089 22286 maintenance_manager.cc:643] P 3bade047a80b4bf79e872e69a1737c34: FlushDeltaMemStoresOp(ab6b259c5c924e39a766fc0786917dfc) complete. Timing: real 0.059s	user 0.025s	sys 0.025s Metrics: {"bytes_written":16409907,"delete_count":0,"lbm_write_time_us":23150,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:18:04.252672 22397 maintenance_manager.cc:419] P 3bade047a80b4bf79e872e69a1737c34: Scheduling FlushDeltaMemStoresOp(ab6b259c5c924e39a766fc0786917dfc): perf score=2.188937
I20260812 06:18:04.263300 22286 maintenance_manager.cc:643] P 3bade047a80b4bf79e872e69a1737c34: FlushDeltaMemStoresOp(ab6b259c5c924e39a766fc0786917dfc) complete. Timing: real 0.010s	user 0.010s	sys 0.000s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4019,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:04.263850 22397 maintenance_manager.cc:419] P 3bade047a80b4bf79e872e69a1737c34: Scheduling FlushMRSOp(ab6b259c5c924e39a766fc0786917dfc): perf score=1.000000
I20260812 06:18:04.292562 22286 maintenance_manager.cc:643] P 3bade047a80b4bf79e872e69a1737c34: FlushMRSOp(ab6b259c5c924e39a766fc0786917dfc) complete. Timing: real 0.029s	user 0.024s	sys 0.003s Metrics: {"bytes_written":1316419,"cfile_init":1,"dirs.queue_time_us":62,"dirs.run_cpu_time_us":220,"dirs.run_wall_time_us":1292,"drs_written":1,"lbm_read_time_us":73,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1729,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":32}
I20260812 06:18:04.293285 22397 maintenance_manager.cc:419] P 3bade047a80b4bf79e872e69a1737c34: Scheduling LogGCOp(ab6b259c5c924e39a766fc0786917dfc): free 132571337 bytes of WAL
I20260812 06:18:04.293537 22286 log_reader.cc:385] T ab6b259c5c924e39a766fc0786917dfc: removed 13 log segments from log reader
I20260812 06:18:04.293608 22286 log.cc:1079] T ab6b259c5c924e39a766fc0786917dfc P 3bade047a80b4bf79e872e69a1737c34: Deleting log segment in path: /tmp/dist-test-taskCQqSFo/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515475780686-21826-0/minicluster-data/ts-0-root/wals/ab6b259c5c924e39a766fc0786917dfc/wal-000000015 (ops 70-74)
I20260812 06:18:04.293663 22286 log.cc:1079] T ab6b259c5c924e39a766fc0786917dfc P 3bade047a80b4bf79e872e69a1737c34: Deleting log segment in path: /tmp/dist-test-taskCQqSFo/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515475780686-21826-0/minicluster-data/ts-0-root/wals/ab6b259c5c924e39a766fc0786917dfc/wal-000000016 (ops 75-79)
I20260812 06:18:04.293720 22286 log.cc:1079] T ab6b259c5c924e39a766fc0786917dfc P 3bade047a80b4bf79e872e69a1737c34: Deleting log segment in path: /tmp/dist-test-taskCQqSFo/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515475780686-21826-0/minicluster-data/ts-0-root/wals/ab6b259c5c924e39a766fc0786917dfc/wal-000000017 (ops 80-84)
I20260812 06:18:04.293762 22286 log.cc:1079] T ab6b259c5c924e39a766fc0786917dfc P 3bade047a80b4bf79e872e69a1737c34: Deleting log segment in path: /tmp/dist-test-taskCQqSFo/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515475780686-21826-0/minicluster-data/ts-0-root/wals/ab6b259c5c924e39a766fc0786917dfc/wal-000000018 (ops 85-88)
I20260812 06:18:04.293799 22286 log.cc:1079] T ab6b259c5c924e39a766fc0786917dfc P 3bade047a80b4bf79e872e69a1737c34: Deleting log segment in path: /tmp/dist-test-taskCQqSFo/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515475780686-21826-0/minicluster-data/ts-0-root/wals/ab6b259c5c924e39a766fc0786917dfc/wal-000000019 (ops 89-93)
I20260812 06:18:04.293838 22286 log.cc:1079] T ab6b259c5c924e39a766fc0786917dfc P 3bade047a80b4bf79e872e69a1737c34: Deleting log segment in path: /tmp/dist-test-taskCQqSFo/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515475780686-21826-0/minicluster-data/ts-0-root/wals/ab6b259c5c924e39a766fc0786917dfc/wal-000000020 (ops 94-98)
I20260812 06:18:04.293886 22286 log.cc:1079] T ab6b259c5c924e39a766fc0786917dfc P 3bade047a80b4bf79e872e69a1737c34: Deleting log segment in path: /tmp/dist-test-taskCQqSFo/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515475780686-21826-0/minicluster-data/ts-0-root/wals/ab6b259c5c924e39a766fc0786917dfc/wal-000000021 (ops 99-103)
I20260812 06:18:04.293923 22286 log.cc:1079] T ab6b259c5c924e39a766fc0786917dfc P 3bade047a80b4bf79e872e69a1737c34: Deleting log segment in path: /tmp/dist-test-taskCQqSFo/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515475780686-21826-0/minicluster-data/ts-0-root/wals/ab6b259c5c924e39a766fc0786917dfc/wal-000000022 (ops 104-108)
I20260812 06:18:04.293962 22286 log.cc:1079] T ab6b259c5c924e39a766fc0786917dfc P 3bade047a80b4bf79e872e69a1737c34: Deleting log segment in path: /tmp/dist-test-taskCQqSFo/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515475780686-21826-0/minicluster-data/ts-0-root/wals/ab6b259c5c924e39a766fc0786917dfc/wal-000000023 (ops 109-112)
I20260812 06:18:04.294000 22286 log.cc:1079] T ab6b259c5c924e39a766fc0786917dfc P 3bade047a80b4bf79e872e69a1737c34: Deleting log segment in path: /tmp/dist-test-taskCQqSFo/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515475780686-21826-0/minicluster-data/ts-0-root/wals/ab6b259c5c924e39a766fc0786917dfc/wal-000000024 (ops 113-117)
I20260812 06:18:04.294037 22286 log.cc:1079] T ab6b259c5c924e39a766fc0786917dfc P 3bade047a80b4bf79e872e69a1737c34: Deleting log segment in path: /tmp/dist-test-taskCQqSFo/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515475780686-21826-0/minicluster-data/ts-0-root/wals/ab6b259c5c924e39a766fc0786917dfc/wal-000000025 (ops 118-122)
I20260812 06:18:04.294075 22286 log.cc:1079] T ab6b259c5c924e39a766fc0786917dfc P 3bade047a80b4bf79e872e69a1737c34: Deleting log segment in path: /tmp/dist-test-taskCQqSFo/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515475780686-21826-0/minicluster-data/ts-0-root/wals/ab6b259c5c924e39a766fc0786917dfc/wal-000000026 (ops 123-127)
I20260812 06:18:04.294113 22286 log.cc:1079] T ab6b259c5c924e39a766fc0786917dfc P 3bade047a80b4bf79e872e69a1737c34: Deleting log segment in path: /tmp/dist-test-taskCQqSFo/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515475780686-21826-0/minicluster-data/ts-0-root/wals/ab6b259c5c924e39a766fc0786917dfc/wal-000000027 (ops 128-132)
I20260812 06:18:04.325407 22286 maintenance_manager.cc:643] P 3bade047a80b4bf79e872e69a1737c34: LogGCOp(ab6b259c5c924e39a766fc0786917dfc) complete. Timing: real 0.032s	user 0.000s	sys 0.029s Metrics: {}
I20260812 06:18:04.325867 22397 maintenance_manager.cc:419] P 3bade047a80b4bf79e872e69a1737c34: Scheduling UndoDeltaBlockGCOp(ab6b259c5c924e39a766fc0786917dfc): 493 bytes on disk
I20260812 06:18:04.326581 22286 maintenance_manager.cc:643] P 3bade047a80b4bf79e872e69a1737c34: UndoDeltaBlockGCOp(ab6b259c5c924e39a766fc0786917dfc) complete. Timing: real 0.001s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":87,"lbm_reads_lt_1ms":4}
I20260812 06:18:04.327251 22397 maintenance_manager.cc:419] P 3bade047a80b4bf79e872e69a1737c34: Scheduling FlushDeltaMemStoresOp(ab6b259c5c924e39a766fc0786917dfc): perf score=3.181125
I20260812 06:18:04.344719 22286 maintenance_manager.cc:643] P 3bade047a80b4bf79e872e69a1737c34: FlushDeltaMemStoresOp(ab6b259c5c924e39a766fc0786917dfc) complete. Timing: real 0.017s	user 0.012s	sys 0.004s Metrics: {"bytes_written":5046218,"delete_count":0,"lbm_write_time_us":7636,"lbm_writes_lt_1ms":126,"reinsert_count":0,"update_count":615}
I20260812 06:18:04.345090 22397 maintenance_manager.cc:419] P 3bade047a80b4bf79e872e69a1737c34: Scheduling FlushDeltaMemStoresOp(ab6b259c5c924e39a766fc0786917dfc): perf score=1.196750
I20260812 06:18:04.354861 22286 maintenance_manager.cc:643] P 3bade047a80b4bf79e872e69a1737c34: FlushDeltaMemStoresOp(ab6b259c5c924e39a766fc0786917dfc) complete. Timing: real 0.010s	user 0.010s	sys 0.000s Metrics: {"bytes_written":3159080,"delete_count":0,"lbm_write_time_us":3120,"lbm_writes_lt_1ms":80,"reinsert_count":0,"update_count":385}
I20260812 06:18:04.355468 22397 maintenance_manager.cc:419] P 3bade047a80b4bf79e872e69a1737c34: Scheduling MajorDeltaCompactionOp(ab6b259c5c924e39a766fc0786917dfc): perf score=1.000000
I20260812 06:18:04.541328 22286 maintenance_manager.cc:643] P 3bade047a80b4bf79e872e69a1737c34: MajorDeltaCompactionOp(ab6b259c5c924e39a766fc0786917dfc) complete. Timing: real 0.186s	user 0.141s	sys 0.044s Metrics: {"cfile_cache_miss":734,"cfile_cache_miss_bytes":33020730,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":516,"lbm_read_time_us":13403,"lbm_reads_lt_1ms":774,"lbm_write_time_us":41150,"lbm_writes_lt_1ms":743,"mutex_wait_us":294,"peak_mem_usage":87969044,"reinsert_count":0,"spinlock_wait_cycles":1792,"thread_start_us":75,"threads_started":1,"update_count":3500}
I20260812 06:18:04.542135 22397 maintenance_manager.cc:419] P 3bade047a80b4bf79e872e69a1737c34: Scheduling FlushDeltaMemStoresOp(ab6b259c5c924e39a766fc0786917dfc): perf score=14.095187
I20260812 06:18:04.601534 22286 maintenance_manager.cc:643] P 3bade047a80b4bf79e872e69a1737c34: FlushDeltaMemStoresOp(ab6b259c5c924e39a766fc0786917dfc) complete. Timing: real 0.059s	user 0.029s	sys 0.027s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":24974,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:18:04.602048 22397 maintenance_manager.cc:419] P 3bade047a80b4bf79e872e69a1737c34: Scheduling FlushDeltaMemStoresOp(ab6b259c5c924e39a766fc0786917dfc): perf score=2.188937
I20260812 06:18:04.626078 22286 maintenance_manager.cc:643] P 3bade047a80b4bf79e872e69a1737c34: FlushDeltaMemStoresOp(ab6b259c5c924e39a766fc0786917dfc) complete. Timing: real 0.024s	user 0.008s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5607,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:04.626500 22397 maintenance_manager.cc:419] P 3bade047a80b4bf79e872e69a1737c34: Scheduling FlushDeltaMemStoresOp(ab6b259c5c924e39a766fc0786917dfc): perf score=2.188937
I20260812 06:18:04.636674 22286 maintenance_manager.cc:643] P 3bade047a80b4bf79e872e69a1737c34: FlushDeltaMemStoresOp(ab6b259c5c924e39a766fc0786917dfc) complete. Timing: real 0.010s	user 0.008s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3950,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:04.637125 22397 maintenance_manager.cc:419] P 3bade047a80b4bf79e872e69a1737c34: Scheduling MajorDeltaCompactionOp(ab6b259c5c924e39a766fc0786917dfc): perf score=1.000000
I20260812 06:18:04.806944 22286 maintenance_manager.cc:643] P 3bade047a80b4bf79e872e69a1737c34: MajorDeltaCompactionOp(ab6b259c5c924e39a766fc0786917dfc) complete. Timing: real 0.170s	user 0.121s	sys 0.048s Metrics: {"cfile_cache_miss":633,"cfile_cache_miss_bytes":28918215,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":823,"lbm_read_time_us":13747,"lbm_reads_lt_1ms":673,"lbm_write_time_us":34488,"lbm_writes_lt_1ms":643,"mutex_wait_us":39,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":27392,"update_count":3000}
I20260812 06:18:04.807648 22397 maintenance_manager.cc:419] P 3bade047a80b4bf79e872e69a1737c34: Scheduling FlushDeltaMemStoresOp(ab6b259c5c924e39a766fc0786917dfc): perf score=14.095187
I20260812 06:18:04.853327 22286 maintenance_manager.cc:643] P 3bade047a80b4bf79e872e69a1737c34: FlushDeltaMemStoresOp(ab6b259c5c924e39a766fc0786917dfc) complete. Timing: real 0.046s	user 0.018s	sys 0.025s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":20431,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:18:04.853835 22397 maintenance_manager.cc:419] P 3bade047a80b4bf79e872e69a1737c34: Scheduling FlushDeltaMemStoresOp(ab6b259c5c924e39a766fc0786917dfc): perf score=2.188937
I20260812 06:18:04.869166 22286 maintenance_manager.cc:643] P 3bade047a80b4bf79e872e69a1737c34: FlushDeltaMemStoresOp(ab6b259c5c924e39a766fc0786917dfc) complete. Timing: real 0.015s	user 0.009s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5940,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:04.869767 22397 maintenance_manager.cc:419] P 3bade047a80b4bf79e872e69a1737c34: Scheduling MajorDeltaCompactionOp(ab6b259c5c924e39a766fc0786917dfc): perf score=1.000000
I20260812 06:18:05.041606 22286 maintenance_manager.cc:643] P 3bade047a80b4bf79e872e69a1737c34: MajorDeltaCompactionOp(ab6b259c5c924e39a766fc0786917dfc) complete. Timing: real 0.172s	user 0.111s	sys 0.045s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24815684,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":177,"lbm_read_time_us":10582,"lbm_reads_lt_1ms":572,"lbm_write_time_us":31358,"lbm_writes_lt_1ms":543,"mutex_wait_us":67,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":896,"update_count":2500}
I20260812 06:18:05.042285 22397 maintenance_manager.cc:419] P 3bade047a80b4bf79e872e69a1737c34: Scheduling FlushDeltaMemStoresOp(ab6b259c5c924e39a766fc0786917dfc): perf score=14.095187
I20260812 06:18:05.097828 22286 maintenance_manager.cc:643] P 3bade047a80b4bf79e872e69a1737c34: FlushDeltaMemStoresOp(ab6b259c5c924e39a766fc0786917dfc) complete. Timing: real 0.055s	user 0.032s	sys 0.016s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":22480,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:18:05.098284 22397 maintenance_manager.cc:419] P 3bade047a80b4bf79e872e69a1737c34: Scheduling FlushDeltaMemStoresOp(ab6b259c5c924e39a766fc0786917dfc): perf score=2.188937
I20260812 06:18:05.113600 22286 maintenance_manager.cc:643] P 3bade047a80b4bf79e872e69a1737c34: FlushDeltaMemStoresOp(ab6b259c5c924e39a766fc0786917dfc) complete. Timing: real 0.015s	user 0.010s	sys 0.003s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5719,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:05.114517 22397 maintenance_manager.cc:419] P 3bade047a80b4bf79e872e69a1737c34: Scheduling MajorDeltaCompactionOp(ab6b259c5c924e39a766fc0786917dfc): perf score=1.000000
I20260812 06:18:05.291895 22286 maintenance_manager.cc:643] P 3bade047a80b4bf79e872e69a1737c34: MajorDeltaCompactionOp(ab6b259c5c924e39a766fc0786917dfc) complete. Timing: real 0.177s	user 0.118s	sys 0.059s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24815684,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":627,"lbm_read_time_us":12161,"lbm_reads_lt_1ms":572,"lbm_write_time_us":28103,"lbm_writes_lt_1ms":543,"mutex_wait_us":250,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":768,"update_count":2500}
I20260812 06:18:05.292634 22397 maintenance_manager.cc:419] P 3bade047a80b4bf79e872e69a1737c34: Scheduling FlushDeltaMemStoresOp(ab6b259c5c924e39a766fc0786917dfc): perf score=14.095187
I20260812 06:18:05.357298 22286 maintenance_manager.cc:643] P 3bade047a80b4bf79e872e69a1737c34: FlushDeltaMemStoresOp(ab6b259c5c924e39a766fc0786917dfc) complete. Timing: real 0.064s	user 0.036s	sys 0.017s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":26175,"lbm_writes_1-10_ms":2,"lbm_writes_lt_1ms":401,"reinsert_count":0,"update_count":2000}
I20260812 06:18:05.357815 22397 maintenance_manager.cc:419] P 3bade047a80b4bf79e872e69a1737c34: Scheduling FlushDeltaMemStoresOp(ab6b259c5c924e39a766fc0786917dfc): perf score=2.188937
I20260812 06:18:05.369130 22286 maintenance_manager.cc:643] P 3bade047a80b4bf79e872e69a1737c34: FlushDeltaMemStoresOp(ab6b259c5c924e39a766fc0786917dfc) complete. Timing: real 0.011s	user 0.009s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3924,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:05.369800 22397 maintenance_manager.cc:419] P 3bade047a80b4bf79e872e69a1737c34: Scheduling MajorDeltaCompactionOp(ab6b259c5c924e39a766fc0786917dfc): perf score=1.000000
I20260812 06:18:05.544417 22286 maintenance_manager.cc:643] P 3bade047a80b4bf79e872e69a1737c34: MajorDeltaCompactionOp(ab6b259c5c924e39a766fc0786917dfc) complete. Timing: real 0.174s	user 0.130s	sys 0.043s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24815683,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":924,"lbm_read_time_us":12284,"lbm_reads_lt_1ms":572,"lbm_write_time_us":29160,"lbm_writes_lt_1ms":543,"mutex_wait_us":312,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":18304,"update_count":2500}
I20260812 06:18:05.544946 22397 maintenance_manager.cc:419] P 3bade047a80b4bf79e872e69a1737c34: Scheduling FlushDeltaMemStoresOp(ab6b259c5c924e39a766fc0786917dfc): perf score=14.095187
I20260812 06:18:05.613286 22286 maintenance_manager.cc:643] P 3bade047a80b4bf79e872e69a1737c34: FlushDeltaMemStoresOp(ab6b259c5c924e39a766fc0786917dfc) complete. Timing: real 0.068s	user 0.035s	sys 0.031s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":25672,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:18:05.613868 22397 maintenance_manager.cc:419] P 3bade047a80b4bf79e872e69a1737c34: Scheduling FlushDeltaMemStoresOp(ab6b259c5c924e39a766fc0786917dfc): perf score=2.188937
I20260812 06:18:05.631461 22286 maintenance_manager.cc:643] P 3bade047a80b4bf79e872e69a1737c34: FlushDeltaMemStoresOp(ab6b259c5c924e39a766fc0786917dfc) complete. Timing: real 0.017s	user 0.007s	sys 0.010s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":6493,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:05.632059 22397 maintenance_manager.cc:419] P 3bade047a80b4bf79e872e69a1737c34: Scheduling FlushMRSOp(ab6b259c5c924e39a766fc0786917dfc): perf score=1.000000
I20260812 06:18:05.669976 22286 maintenance_manager.cc:643] P 3bade047a80b4bf79e872e69a1737c34: FlushMRSOp(ab6b259c5c924e39a766fc0786917dfc) complete. Timing: real 0.038s	user 0.033s	sys 0.001s Metrics: {"bytes_written":1152512,"cfile_init":1,"dirs.queue_time_us":71,"dirs.run_cpu_time_us":236,"dirs.run_wall_time_us":1344,"drs_written":1,"lbm_read_time_us":38,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1443,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":28}
I20260812 06:18:05.670872 22397 maintenance_manager.cc:419] P 3bade047a80b4bf79e872e69a1737c34: Scheduling LogGCOp(ab6b259c5c924e39a766fc0786917dfc): free 108535640 bytes of WAL
I20260812 06:18:05.671118 22286 log_reader.cc:385] T ab6b259c5c924e39a766fc0786917dfc: removed 11 log segments from log reader
I20260812 06:18:05.671190 22286 log.cc:1079] T ab6b259c5c924e39a766fc0786917dfc P 3bade047a80b4bf79e872e69a1737c34: Deleting log segment in path: /tmp/dist-test-taskCQqSFo/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515475780686-21826-0/minicluster-data/ts-0-root/wals/ab6b259c5c924e39a766fc0786917dfc/wal-000000028 (ops 133-137)
I20260812 06:18:05.671243 22286 log.cc:1079] T ab6b259c5c924e39a766fc0786917dfc P 3bade047a80b4bf79e872e69a1737c34: Deleting log segment in path: /tmp/dist-test-taskCQqSFo/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515475780686-21826-0/minicluster-data/ts-0-root/wals/ab6b259c5c924e39a766fc0786917dfc/wal-000000029 (ops 138-142)
I20260812 06:18:05.671276 22286 log.cc:1079] T ab6b259c5c924e39a766fc0786917dfc P 3bade047a80b4bf79e872e69a1737c34: Deleting log segment in path: /tmp/dist-test-taskCQqSFo/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515475780686-21826-0/minicluster-data/ts-0-root/wals/ab6b259c5c924e39a766fc0786917dfc/wal-000000030 (ops 143-146)
I20260812 06:18:05.671300 22286 log.cc:1079] T ab6b259c5c924e39a766fc0786917dfc P 3bade047a80b4bf79e872e69a1737c34: Deleting log segment in path: /tmp/dist-test-taskCQqSFo/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515475780686-21826-0/minicluster-data/ts-0-root/wals/ab6b259c5c924e39a766fc0786917dfc/wal-000000031 (ops 147-151)
I20260812 06:18:05.671332 22286 log.cc:1079] T ab6b259c5c924e39a766fc0786917dfc P 3bade047a80b4bf79e872e69a1737c34: Deleting log segment in path: /tmp/dist-test-taskCQqSFo/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515475780686-21826-0/minicluster-data/ts-0-root/wals/ab6b259c5c924e39a766fc0786917dfc/wal-000000032 (ops 152-156)
I20260812 06:18:05.671368 22286 log.cc:1079] T ab6b259c5c924e39a766fc0786917dfc P 3bade047a80b4bf79e872e69a1737c34: Deleting log segment in path: /tmp/dist-test-taskCQqSFo/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515475780686-21826-0/minicluster-data/ts-0-root/wals/ab6b259c5c924e39a766fc0786917dfc/wal-000000033 (ops 157-161)
I20260812 06:18:05.671406 22286 log.cc:1079] T ab6b259c5c924e39a766fc0786917dfc P 3bade047a80b4bf79e872e69a1737c34: Deleting log segment in path: /tmp/dist-test-taskCQqSFo/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515475780686-21826-0/minicluster-data/ts-0-root/wals/ab6b259c5c924e39a766fc0786917dfc/wal-000000034 (ops 162-166)
I20260812 06:18:05.671442 22286 log.cc:1079] T ab6b259c5c924e39a766fc0786917dfc P 3bade047a80b4bf79e872e69a1737c34: Deleting log segment in path: /tmp/dist-test-taskCQqSFo/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515475780686-21826-0/minicluster-data/ts-0-root/wals/ab6b259c5c924e39a766fc0786917dfc/wal-000000035 (ops 167-171)
I20260812 06:18:05.671479 22286 log.cc:1079] T ab6b259c5c924e39a766fc0786917dfc P 3bade047a80b4bf79e872e69a1737c34: Deleting log segment in path: /tmp/dist-test-taskCQqSFo/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515475780686-21826-0/minicluster-data/ts-0-root/wals/ab6b259c5c924e39a766fc0786917dfc/wal-000000036 (ops 172-176)
I20260812 06:18:05.671515 22286 log.cc:1079] T ab6b259c5c924e39a766fc0786917dfc P 3bade047a80b4bf79e872e69a1737c34: Deleting log segment in path: /tmp/dist-test-taskCQqSFo/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515475780686-21826-0/minicluster-data/ts-0-root/wals/ab6b259c5c924e39a766fc0786917dfc/wal-000000037 (ops 177-180)
I20260812 06:18:05.671551 22286 log.cc:1079] T ab6b259c5c924e39a766fc0786917dfc P 3bade047a80b4bf79e872e69a1737c34: Deleting log segment in path: /tmp/dist-test-taskCQqSFo/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515475780686-21826-0/minicluster-data/ts-0-root/wals/ab6b259c5c924e39a766fc0786917dfc/wal-000000038 (ops 181-185)
I20260812 06:18:05.696323 22286 maintenance_manager.cc:643] P 3bade047a80b4bf79e872e69a1737c34: LogGCOp(ab6b259c5c924e39a766fc0786917dfc) complete. Timing: real 0.025s	user 0.000s	sys 0.024s Metrics: {}
I20260812 06:18:05.696810 22397 maintenance_manager.cc:419] P 3bade047a80b4bf79e872e69a1737c34: Scheduling FlushDeltaMemStoresOp(ab6b259c5c924e39a766fc0786917dfc): perf score=2.188937
I20260812 06:18:05.712574 22286 maintenance_manager.cc:643] P 3bade047a80b4bf79e872e69a1737c34: FlushDeltaMemStoresOp(ab6b259c5c924e39a766fc0786917dfc) complete. Timing: real 0.016s	user 0.005s	sys 0.004s 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:18:05.713053 22397 maintenance_manager.cc:419] P 3bade047a80b4bf79e872e69a1737c34: Scheduling FlushDeltaMemStoresOp(ab6b259c5c924e39a766fc0786917dfc): perf score=2.188937
I20260812 06:18:05.724622 22286 maintenance_manager.cc:643] P 3bade047a80b4bf79e872e69a1737c34: FlushDeltaMemStoresOp(ab6b259c5c924e39a766fc0786917dfc) complete. Timing: real 0.011s	user 0.010s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4746,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:05.725106 22397 maintenance_manager.cc:419] P 3bade047a80b4bf79e872e69a1737c34: Scheduling MajorDeltaCompactionOp(ab6b259c5c924e39a766fc0786917dfc): perf score=1.000000
I20260812 06:18:05.938879 21826 heavy-update-compaction-itest.cc:229] Time spent updating: real 4.726s	user 1.729s	sys 0.201s
I20260812 06:18:05.947594 22286 maintenance_manager.cc:643] P 3bade047a80b4bf79e872e69a1737c34: MajorDeltaCompactionOp(ab6b259c5c924e39a766fc0786917dfc) complete. Timing: real 0.222s	user 0.166s	sys 0.055s Metrics: {"cfile_cache_miss":734,"cfile_cache_miss_bytes":33020744,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"lbm_read_time_us":17011,"lbm_reads_lt_1ms":770,"lbm_write_time_us":41152,"lbm_writes_lt_1ms":743,"peak_mem_usage":87969044,"reinsert_count":0,"spinlock_wait_cycles":768,"update_count":3500}
I20260812 06:18:05.948046 22397 maintenance_manager.cc:419] P 3bade047a80b4bf79e872e69a1737c34: Scheduling FlushDeltaMemStoresOp(ab6b259c5c924e39a766fc0786917dfc): perf score=18.063937
I20260812 06:18:05.987479 22286 maintenance_manager.cc:643] P 3bade047a80b4bf79e872e69a1737c34: FlushDeltaMemStoresOp(ab6b259c5c924e39a766fc0786917dfc) complete. Timing: real 0.039s	user 0.027s	sys 0.012s Metrics: {"bytes_written":20512311,"delete_count":0,"lbm_write_time_us":19185,"lbm_writes_lt_1ms":503,"reinsert_count":0,"update_count":2500}
I20260812 06:18:05.987937 22397 maintenance_manager.cc:419] P 3bade047a80b4bf79e872e69a1737c34: Scheduling MajorDeltaCompactionOp(ab6b259c5c924e39a766fc0786917dfc): perf score=1.000000
I20260812 06:18:06.010151 21826 heavy-update-compaction-itest.cc:265] Time spent scanning: real 0.071s	user 0.000s	sys 0.000s
I20260812 06:18:06.010658 21826 tablet_server.cc:179] TabletServer@127.21.80.129:0 shutting down...
I20260812 06:18:06.114974 22286 maintenance_manager.cc:643] P 3bade047a80b4bf79e872e69a1737c34: MajorDeltaCompactionOp(ab6b259c5c924e39a766fc0786917dfc) complete. Timing: real 0.127s	user 0.086s	sys 0.040s Metrics: {"cfile_cache_miss":531,"cfile_cache_miss_bytes":24815562,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":1,"delta_iterators_relevant":1,"dirs.queue_time_us":1006,"lbm_read_time_us":10455,"lbm_reads_lt_1ms":567,"lbm_write_time_us":26706,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":542,"mutex_wait_us":353,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":1280,"update_count":2500}
I20260812 06:18:06.115589 21826 ts_tablet_manager.cc:1507] Shutting down tablet manager...
I20260812 06:18:06.115895 21826 tablet_replica.cc:333] T ab6b259c5c924e39a766fc0786917dfc P 3bade047a80b4bf79e872e69a1737c34: stopping tablet replica
I20260812 06:18:06.116045 21826 raft_consensus.cc:2243] T ab6b259c5c924e39a766fc0786917dfc P 3bade047a80b4bf79e872e69a1737c34 [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:18:06.116220 21826 raft_consensus.cc:2272] T ab6b259c5c924e39a766fc0786917dfc P 3bade047a80b4bf79e872e69a1737c34 [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:18:06.119652 21826 tablet_server.cc:196] TabletServer@127.21.80.129:0 shutdown complete.
I20260812 06:18:06.162030 21826 master.cc:562] Master@127.21.80.190:45665 shutting down...
I20260812 06:18:06.166149 21826 raft_consensus.cc:2243] T 00000000000000000000000000000000 P 8aa30d4fc4ce486c92942da655b2331c [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:18:06.166323 21826 raft_consensus.cc:2272] T 00000000000000000000000000000000 P 8aa30d4fc4ce486c92942da655b2331c [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:18:06.166374 21826 tablet_replica.cc:333] T 00000000000000000000000000000000 P 8aa30d4fc4ce486c92942da655b2331c: stopping tablet replica
I20260812 06:18:06.178932 21826 master.cc:584] Master@127.21.80.190:45665 shutdown complete.
[       OK ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/1 (5246 ms)
[----------] 2 tests from EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy (10481 ms total)

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