[==========] 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:16:36.671509 20146 internal_mini_cluster.cc:156] Creating distributed mini masters. Addrs: 127.19.172.190:34785
I20260812 06:16:36.672363 20146 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:16:36.672910 20146 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:16:36.678498 20163 instance_detector.cc:116] could not retrieve OpenStack instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:16:36.678555 20161 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:16:36.678681 20146 server_base.cc:1061] running on GCE node
W20260812 06:16:36.678716 20158 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:16:36.679126 20146 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:16:36.679214 20146 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:16:36.679255 20146 hybrid_clock.cc:648] HybridClock initialized: now 1786515396679252 us; error 0 us; skew 500 ppm
I20260812 06:16:36.680723 20146 webserver.cc:533] Webserver started at http://127.19.172.190:37873/ using document root <none> and password file <none>
I20260812 06:16:36.681183 20146 fs_manager.cc:362] Metadata directory not provided
I20260812 06:16:36.681242 20146 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:16:36.681443 20146 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:16:36.682920 20146 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskDoCWee/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515396661473-20146-0/minicluster-data/master-0-root/instance:
uuid: "54c6f400c9b546baac5a56cdf74d6300"
format_stamp: "Formatted at 2026-08-12 06:16:36 on dist-test-slave-tc2s"
I20260812 06:16:36.685954 20146 fs_manager.cc:696] Time spent creating directory manager: real 0.003s	user 0.003s	sys 0.001s
I20260812 06:16:36.687721 20175 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:16:36.688601 20146 fs_manager.cc:730] Time spent opening block manager: real 0.002s	user 0.000s	sys 0.002s
I20260812 06:16:36.688696 20146 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskDoCWee/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515396661473-20146-0/minicluster-data/master-0-root
uuid: "54c6f400c9b546baac5a56cdf74d6300"
format_stamp: "Formatted at 2026-08-12 06:16:36 on dist-test-slave-tc2s"
I20260812 06:16:36.688771 20146 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskDoCWee/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515396661473-20146-0/minicluster-data/master-0-root
metadata directory: /tmp/dist-test-taskDoCWee/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515396661473-20146-0/minicluster-data/master-0-root
1 data directories: /tmp/dist-test-taskDoCWee/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515396661473-20146-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:16:36.711831 20146 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:16:36.712318 20146 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:16:36.712451 20146 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:16:36.719172 20146 rpc_server.cc:307] RPC server started. Bound to: 127.19.172.190:34785
I20260812 06:16:36.719197 20273 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.19.172.190:34785 every 8 connection(s)
I20260812 06:16:36.721632 20274 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:16:36.726666 20274 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P 54c6f400c9b546baac5a56cdf74d6300: Bootstrap starting.
I20260812 06:16:36.728789 20274 tablet_bootstrap.cc:654] T 00000000000000000000000000000000 P 54c6f400c9b546baac5a56cdf74d6300: Neither blocks nor log segments found. Creating new log.
I20260812 06:16:36.729592 20274 log.cc:826] T 00000000000000000000000000000000 P 54c6f400c9b546baac5a56cdf74d6300: Log is configured to *not* fsync() on all Append() calls
I20260812 06:16:36.731061 20274 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P 54c6f400c9b546baac5a56cdf74d6300: No bootstrap required, opened a new log
I20260812 06:16:36.733561 20274 raft_consensus.cc:359] T 00000000000000000000000000000000 P 54c6f400c9b546baac5a56cdf74d6300 [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "54c6f400c9b546baac5a56cdf74d6300" member_type: VOTER }
I20260812 06:16:36.733708 20274 raft_consensus.cc:385] T 00000000000000000000000000000000 P 54c6f400c9b546baac5a56cdf74d6300 [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:16:36.733773 20274 raft_consensus.cc:740] T 00000000000000000000000000000000 P 54c6f400c9b546baac5a56cdf74d6300 [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: 54c6f400c9b546baac5a56cdf74d6300, State: Initialized, Role: FOLLOWER
I20260812 06:16:36.734325 20274 consensus_queue.cc:260] T 00000000000000000000000000000000 P 54c6f400c9b546baac5a56cdf74d6300 [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: "54c6f400c9b546baac5a56cdf74d6300" member_type: VOTER }
I20260812 06:16:36.734464 20274 raft_consensus.cc:399] T 00000000000000000000000000000000 P 54c6f400c9b546baac5a56cdf74d6300 [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:16:36.734527 20274 raft_consensus.cc:493] T 00000000000000000000000000000000 P 54c6f400c9b546baac5a56cdf74d6300 [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:16:36.734640 20274 raft_consensus.cc:3060] T 00000000000000000000000000000000 P 54c6f400c9b546baac5a56cdf74d6300 [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:16:36.735304 20274 raft_consensus.cc:515] T 00000000000000000000000000000000 P 54c6f400c9b546baac5a56cdf74d6300 [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "54c6f400c9b546baac5a56cdf74d6300" member_type: VOTER }
I20260812 06:16:36.735690 20274 leader_election.cc:304] T 00000000000000000000000000000000 P 54c6f400c9b546baac5a56cdf74d6300 [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: 54c6f400c9b546baac5a56cdf74d6300; no voters: 
I20260812 06:16:36.735952 20274 leader_election.cc:290] T 00000000000000000000000000000000 P 54c6f400c9b546baac5a56cdf74d6300 [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:16:36.736047 20282 raft_consensus.cc:2804] T 00000000000000000000000000000000 P 54c6f400c9b546baac5a56cdf74d6300 [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:16:36.736225 20282 raft_consensus.cc:697] T 00000000000000000000000000000000 P 54c6f400c9b546baac5a56cdf74d6300 [term 1 LEADER]: Becoming Leader. State: Replica: 54c6f400c9b546baac5a56cdf74d6300, State: Running, Role: LEADER
I20260812 06:16:36.736629 20282 consensus_queue.cc:237] T 00000000000000000000000000000000 P 54c6f400c9b546baac5a56cdf74d6300 [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: "54c6f400c9b546baac5a56cdf74d6300" member_type: VOTER }
I20260812 06:16:36.736792 20274 sys_catalog.cc:565] T 00000000000000000000000000000000 P 54c6f400c9b546baac5a56cdf74d6300 [sys.catalog]: configured and running, proceeding with master startup.
I20260812 06:16:36.738313 20284 sys_catalog.cc:455] T 00000000000000000000000000000000 P 54c6f400c9b546baac5a56cdf74d6300 [sys.catalog]: SysCatalogTable state changed. Reason: New leader 54c6f400c9b546baac5a56cdf74d6300. Latest consensus state: current_term: 1 leader_uuid: "54c6f400c9b546baac5a56cdf74d6300" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "54c6f400c9b546baac5a56cdf74d6300" member_type: VOTER } }
I20260812 06:16:36.738345 20283 sys_catalog.cc:455] T 00000000000000000000000000000000 P 54c6f400c9b546baac5a56cdf74d6300 [sys.catalog]: SysCatalogTable state changed. Reason: RaftConsensus started. Latest consensus state: current_term: 1 leader_uuid: "54c6f400c9b546baac5a56cdf74d6300" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "54c6f400c9b546baac5a56cdf74d6300" member_type: VOTER } }
I20260812 06:16:36.738473 20284 sys_catalog.cc:458] T 00000000000000000000000000000000 P 54c6f400c9b546baac5a56cdf74d6300 [sys.catalog]: This master's current role is: LEADER
I20260812 06:16:36.738484 20283 sys_catalog.cc:458] T 00000000000000000000000000000000 P 54c6f400c9b546baac5a56cdf74d6300 [sys.catalog]: This master's current role is: LEADER
I20260812 06:16:36.739004 20146 internal_mini_cluster.cc:184] Waiting to initialize catalog manager on master 0
W20260812 06:16:36.741042 20305 catalog_manager.cc:1594] T 00000000000000000000000000000000 P 54c6f400c9b546baac5a56cdf74d6300: loading cluster ID for follower catalog manager: Not found: cluster ID entry not found
W20260812 06:16:36.741101 20305 catalog_manager.cc:883] Not found: cluster ID entry not found: failed to prepare follower catalog manager, will retry
I20260812 06:16:36.741164 20302 catalog_manager.cc:1511] Loading table and tablet metadata into memory...
I20260812 06:16:36.741850 20302 catalog_manager.cc:1520] Initializing Kudu cluster ID...
I20260812 06:16:36.745972 20302 catalog_manager.cc:1383] Generated new cluster ID: f8b806e93bba4adc987f692524ecde64
I20260812 06:16:36.746029 20302 catalog_manager.cc:1531] Initializing Kudu internal certificate authority...
I20260812 06:16:36.778879 20302 catalog_manager.cc:1406] Generated new certificate authority record
I20260812 06:16:36.779922 20302 catalog_manager.cc:1540] Loading token signing keys...
I20260812 06:16:36.795833 20302 catalog_manager.cc:6092] T 00000000000000000000000000000000 P 54c6f400c9b546baac5a56cdf74d6300: Generated new TSK 0
I20260812 06:16:36.796460 20302 catalog_manager.cc:1550] Initializing in-progress tserver states...
I20260812 06:16:36.803881 20146 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:16:36.806411 20313 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:16:36.806452 20318 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:16:36.806697 20146 server_base.cc:1061] running on GCE node
W20260812 06:16:36.806556 20312 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:16:36.806932 20146 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:16:36.806984 20146 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:16:36.807008 20146 hybrid_clock.cc:648] HybridClock initialized: now 1786515396807007 us; error 0 us; skew 500 ppm
I20260812 06:16:36.807829 20146 webserver.cc:533] Webserver started at http://127.19.172.129:44895/ using document root <none> and password file <none>
I20260812 06:16:36.807984 20146 fs_manager.cc:362] Metadata directory not provided
I20260812 06:16:36.808032 20146 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:16:36.808106 20146 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:16:36.808437 20146 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskDoCWee/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515396661473-20146-0/minicluster-data/ts-0-root/instance:
uuid: "92bd2362d128445d8bff18ab85c57afe"
format_stamp: "Formatted at 2026-08-12 06:16:36 on dist-test-slave-tc2s"
I20260812 06:16:36.809784 20146 fs_manager.cc:696] Time spent creating directory manager: real 0.001s	user 0.001s	sys 0.000s
I20260812 06:16:36.810683 20332 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:16:36.810923 20146 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.000s	sys 0.001s
I20260812 06:16:36.810992 20146 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskDoCWee/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515396661473-20146-0/minicluster-data/ts-0-root
uuid: "92bd2362d128445d8bff18ab85c57afe"
format_stamp: "Formatted at 2026-08-12 06:16:36 on dist-test-slave-tc2s"
I20260812 06:16:36.811055 20146 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskDoCWee/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515396661473-20146-0/minicluster-data/ts-0-root
metadata directory: /tmp/dist-test-taskDoCWee/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515396661473-20146-0/minicluster-data/ts-0-root
1 data directories: /tmp/dist-test-taskDoCWee/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515396661473-20146-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:16:36.820850 20146 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:16:36.821187 20146 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:16:36.821612 20146 txn_system_client.cc:432] TxnSystemClient initialization is disabled...
I20260812 06:16:36.822467 20146 ts_tablet_manager.cc:585] Loaded tablet metadata (0 total tablets, 0 live tablets)
I20260812 06:16:36.822517 20146 ts_tablet_manager.cc:531] Time spent load tablet metadata: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:16:36.822558 20146 ts_tablet_manager.cc:616] Registered 0 tablets
I20260812 06:16:36.822589 20146 ts_tablet_manager.cc:595] Time spent register tablets: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:16:36.828799 20146 rpc_server.cc:307] RPC server started. Bound to: 127.19.172.129:37217
I20260812 06:16:36.828848 20452 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.19.172.129:37217 every 8 connection(s)
I20260812 06:16:36.838097 20453 heartbeater.cc:344] Connected to a master server at 127.19.172.190:34785
I20260812 06:16:36.838310 20453 heartbeater.cc:461] Registering TS with master...
I20260812 06:16:36.838747 20453 heartbeater.cc:507] Master 127.19.172.190:34785 requested a full tablet report, sending...
I20260812 06:16:36.840040 20209 ts_manager.cc:194] Registered new tserver with Master: 92bd2362d128445d8bff18ab85c57afe (127.19.172.129:37217)
I20260812 06:16:36.840623 20146 internal_mini_cluster.cc:371] 1 TS(s) registered with all masters after 0.01125015s
I20260812 06:16:36.841085 20209 master_service.cc:502] Signed X509 certificate for tserver {username='slave'} at 127.0.0.1:33598
I20260812 06:16:36.848912 20209 catalog_manager.cc:2283] Servicing CreateTable request from {username='slave'} at 127.0.0.1:33604:
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:16:36.861645 20385 tablet_service.cc:1511] Processing CreateTablet for tablet 355f3874af8f46608ac22907343e3041 (DEFAULT_TABLE table=heavy-update-compaction-test [id=9f007c73d1f64ebdbce89c58d52e0de3]), partition=
I20260812 06:16:36.862067 20385 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet 355f3874af8f46608ac22907343e3041. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:16:36.864131 20477 tablet_bootstrap.cc:492] T 355f3874af8f46608ac22907343e3041 P 92bd2362d128445d8bff18ab85c57afe: Bootstrap starting.
I20260812 06:16:36.865164 20477 tablet_bootstrap.cc:654] T 355f3874af8f46608ac22907343e3041 P 92bd2362d128445d8bff18ab85c57afe: Neither blocks nor log segments found. Creating new log.
I20260812 06:16:36.866633 20477 tablet_bootstrap.cc:492] T 355f3874af8f46608ac22907343e3041 P 92bd2362d128445d8bff18ab85c57afe: No bootstrap required, opened a new log
I20260812 06:16:36.866732 20477 ts_tablet_manager.cc:1403] T 355f3874af8f46608ac22907343e3041 P 92bd2362d128445d8bff18ab85c57afe: Time spent bootstrapping tablet: real 0.003s	user 0.002s	sys 0.000s
I20260812 06:16:36.867235 20477 raft_consensus.cc:359] T 355f3874af8f46608ac22907343e3041 P 92bd2362d128445d8bff18ab85c57afe [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "92bd2362d128445d8bff18ab85c57afe" member_type: VOTER last_known_addr { host: "127.19.172.129" port: 37217 } }
I20260812 06:16:36.867347 20477 raft_consensus.cc:385] T 355f3874af8f46608ac22907343e3041 P 92bd2362d128445d8bff18ab85c57afe [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:16:36.867388 20477 raft_consensus.cc:740] T 355f3874af8f46608ac22907343e3041 P 92bd2362d128445d8bff18ab85c57afe [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: 92bd2362d128445d8bff18ab85c57afe, State: Initialized, Role: FOLLOWER
I20260812 06:16:36.867514 20477 consensus_queue.cc:260] T 355f3874af8f46608ac22907343e3041 P 92bd2362d128445d8bff18ab85c57afe [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: "92bd2362d128445d8bff18ab85c57afe" member_type: VOTER last_known_addr { host: "127.19.172.129" port: 37217 } }
I20260812 06:16:36.867604 20477 raft_consensus.cc:399] T 355f3874af8f46608ac22907343e3041 P 92bd2362d128445d8bff18ab85c57afe [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:16:36.867645 20477 raft_consensus.cc:493] T 355f3874af8f46608ac22907343e3041 P 92bd2362d128445d8bff18ab85c57afe [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:16:36.867691 20477 raft_consensus.cc:3060] T 355f3874af8f46608ac22907343e3041 P 92bd2362d128445d8bff18ab85c57afe [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:16:36.868556 20477 raft_consensus.cc:515] T 355f3874af8f46608ac22907343e3041 P 92bd2362d128445d8bff18ab85c57afe [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "92bd2362d128445d8bff18ab85c57afe" member_type: VOTER last_known_addr { host: "127.19.172.129" port: 37217 } }
I20260812 06:16:36.868697 20477 leader_election.cc:304] T 355f3874af8f46608ac22907343e3041 P 92bd2362d128445d8bff18ab85c57afe [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: 92bd2362d128445d8bff18ab85c57afe; no voters: 
I20260812 06:16:36.868884 20477 leader_election.cc:290] T 355f3874af8f46608ac22907343e3041 P 92bd2362d128445d8bff18ab85c57afe [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:16:36.869000 20479 raft_consensus.cc:2804] T 355f3874af8f46608ac22907343e3041 P 92bd2362d128445d8bff18ab85c57afe [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:16:36.869259 20477 ts_tablet_manager.cc:1434] T 355f3874af8f46608ac22907343e3041 P 92bd2362d128445d8bff18ab85c57afe: Time spent starting tablet: real 0.002s	user 0.003s	sys 0.000s
I20260812 06:16:36.869270 20479 raft_consensus.cc:697] T 355f3874af8f46608ac22907343e3041 P 92bd2362d128445d8bff18ab85c57afe [term 1 LEADER]: Becoming Leader. State: Replica: 92bd2362d128445d8bff18ab85c57afe, State: Running, Role: LEADER
I20260812 06:16:36.869663 20453 heartbeater.cc:499] Master 127.19.172.190:34785 was elected leader, sending a full tablet report...
I20260812 06:16:36.869796 20479 consensus_queue.cc:237] T 355f3874af8f46608ac22907343e3041 P 92bd2362d128445d8bff18ab85c57afe [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: "92bd2362d128445d8bff18ab85c57afe" member_type: VOTER last_known_addr { host: "127.19.172.129" port: 37217 } }
I20260812 06:16:36.872192 20209 catalog_manager.cc:5719] T 355f3874af8f46608ac22907343e3041 P 92bd2362d128445d8bff18ab85c57afe reported cstate change: term changed from 0 to 1, leader changed from <none> to 92bd2362d128445d8bff18ab85c57afe (127.19.172.129). New cstate: current_term: 1 leader_uuid: "92bd2362d128445d8bff18ab85c57afe" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "92bd2362d128445d8bff18ab85c57afe" member_type: VOTER last_known_addr { host: "127.19.172.129" port: 37217 } health_report { overall_health: HEALTHY } } }
I20260812 06:16:36.936185 20146 heavy-update-compaction-itest.cc:215] Time spent inserting: real 0.054s	user 0.014s	sys 0.012s
I20260812 06:16:37.079943 20455 maintenance_manager.cc:419] P 92bd2362d128445d8bff18ab85c57afe: Scheduling FlushMRSOp(355f3874af8f46608ac22907343e3041): perf score=19.054940
I20260812 06:16:37.270830 20343 maintenance_manager.cc:643] P 92bd2362d128445d8bff18ab85c57afe: FlushMRSOp(355f3874af8f46608ac22907343e3041) complete. Timing: real 0.191s	user 0.168s	sys 0.020s Metrics: {"bytes_written":17107318,"cfile_init":1,"compiler_manager_pool.queue_time_us":199,"delete_count":0,"dirs.queue_time_us":41,"dirs.run_cpu_time_us":185,"dirs.run_wall_time_us":659,"drs_written":1,"lbm_read_time_us":69,"lbm_reads_lt_1ms":4,"lbm_write_time_us":42016,"lbm_writes_lt_1ms":884,"peak_mem_usage":0,"reinsert_count":0,"rows_written":105,"spinlock_wait_cycles":75520,"thread_start_us":116,"threads_started":1,"update_count":2085}
I20260812 06:16:37.272073 20455 maintenance_manager.cc:419] P 92bd2362d128445d8bff18ab85c57afe: Scheduling LogGCOp(355f3874af8f46608ac22907343e3041): free 20743880 bytes of WAL
I20260812 06:16:37.272392 20343 log_reader.cc:385] T 355f3874af8f46608ac22907343e3041: removed 2 log segments from log reader
I20260812 06:16:37.272467 20343 log.cc:1079] T 355f3874af8f46608ac22907343e3041 P 92bd2362d128445d8bff18ab85c57afe: Deleting log segment in path: /tmp/dist-test-taskDoCWee/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515396661473-20146-0/minicluster-data/ts-0-root/wals/355f3874af8f46608ac22907343e3041/wal-000000001 (ops 1-6)
I20260812 06:16:37.272529 20343 log.cc:1079] T 355f3874af8f46608ac22907343e3041 P 92bd2362d128445d8bff18ab85c57afe: Deleting log segment in path: /tmp/dist-test-taskDoCWee/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515396661473-20146-0/minicluster-data/ts-0-root/wals/355f3874af8f46608ac22907343e3041/wal-000000002 (ops 7-11)
I20260812 06:16:37.277580 20343 maintenance_manager.cc:643] P 92bd2362d128445d8bff18ab85c57afe: LogGCOp(355f3874af8f46608ac22907343e3041) complete. Timing: real 0.005s	user 0.000s	sys 0.002s Metrics: {}
I20260812 06:16:37.277974 20455 maintenance_manager.cc:419] P 92bd2362d128445d8bff18ab85c57afe: Scheduling FlushDeltaMemStoresOp(355f3874af8f46608ac22907343e3041): perf score=5.165500
I20260812 06:16:37.293294 20343 maintenance_manager.cc:643] P 92bd2362d128445d8bff18ab85c57afe: FlushDeltaMemStoresOp(355f3874af8f46608ac22907343e3041) complete. Timing: real 0.015s	user 0.005s	sys 0.008s Metrics: {"bytes_written":7097432,"delete_count":0,"lbm_write_time_us":6546,"lbm_writes_lt_1ms":176,"reinsert_count":0,"update_count":865}
I20260812 06:16:37.293612 20455 maintenance_manager.cc:419] P 92bd2362d128445d8bff18ab85c57afe: Scheduling MajorDeltaCompactionOp(355f3874af8f46608ac22907343e3041): perf score=1.000000
I20260812 06:16:37.476145 20343 maintenance_manager.cc:643] P 92bd2362d128445d8bff18ab85c57afe: MajorDeltaCompactionOp(355f3874af8f46608ac22907343e3041) complete. Timing: real 0.182s	user 0.144s	sys 0.035s Metrics: {"cfile_cache_miss":622,"cfile_cache_miss_bytes":28507867,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":820,"lbm_read_time_us":12325,"lbm_reads_lt_1ms":658,"lbm_write_time_us":29351,"lbm_writes_lt_1ms":633,"peak_mem_usage":74091738,"reinsert_count":0,"thread_start_us":281,"threads_started":5,"update_count":2950}
I20260812 06:16:37.476639 20455 maintenance_manager.cc:419] P 92bd2362d128445d8bff18ab85c57afe: Scheduling FlushDeltaMemStoresOp(355f3874af8f46608ac22907343e3041): perf score=14.095187
I20260812 06:16:37.525581 20343 maintenance_manager.cc:643] P 92bd2362d128445d8bff18ab85c57afe: FlushDeltaMemStoresOp(355f3874af8f46608ac22907343e3041) complete. Timing: real 0.049s	user 0.030s	sys 0.012s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":17968,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:16:37.526145 20455 maintenance_manager.cc:419] P 92bd2362d128445d8bff18ab85c57afe: Scheduling UndoDeltaBlockGCOp(355f3874af8f46608ac22907343e3041): 16821648 bytes on disk
I20260812 06:16:37.526609 20343 maintenance_manager.cc:643] P 92bd2362d128445d8bff18ab85c57afe: UndoDeltaBlockGCOp(355f3874af8f46608ac22907343e3041) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":41,"lbm_reads_lt_1ms":4}
I20260812 06:16:37.526995 20455 maintenance_manager.cc:419] P 92bd2362d128445d8bff18ab85c57afe: Scheduling FlushDeltaMemStoresOp(355f3874af8f46608ac22907343e3041): perf score=2.188937
I20260812 06:16:37.537729 20343 maintenance_manager.cc:643] P 92bd2362d128445d8bff18ab85c57afe: FlushDeltaMemStoresOp(355f3874af8f46608ac22907343e3041) complete. Timing: real 0.011s	user 0.008s	sys 0.000s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4088,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:37.538118 20455 maintenance_manager.cc:419] P 92bd2362d128445d8bff18ab85c57afe: Scheduling MajorDeltaCompactionOp(355f3874af8f46608ac22907343e3041): perf score=1.000000
I20260812 06:16:37.698211 20343 maintenance_manager.cc:643] P 92bd2362d128445d8bff18ab85c57afe: MajorDeltaCompactionOp(355f3874af8f46608ac22907343e3041) complete. Timing: real 0.160s	user 0.079s	sys 0.073s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24815682,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":906,"lbm_read_time_us":10383,"lbm_reads_lt_1ms":572,"lbm_write_time_us":25100,"lbm_writes_lt_1ms":543,"mutex_wait_us":279,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":896,"update_count":2500}
I20260812 06:16:37.698743 20455 maintenance_manager.cc:419] P 92bd2362d128445d8bff18ab85c57afe: Scheduling FlushDeltaMemStoresOp(355f3874af8f46608ac22907343e3041): perf score=14.095187
I20260812 06:16:37.757243 20343 maintenance_manager.cc:643] P 92bd2362d128445d8bff18ab85c57afe: FlushDeltaMemStoresOp(355f3874af8f46608ac22907343e3041) complete. Timing: real 0.058s	user 0.032s	sys 0.020s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":20811,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:16:37.757709 20455 maintenance_manager.cc:419] P 92bd2362d128445d8bff18ab85c57afe: Scheduling FlushDeltaMemStoresOp(355f3874af8f46608ac22907343e3041): perf score=2.188937
I20260812 06:16:37.767284 20343 maintenance_manager.cc:643] P 92bd2362d128445d8bff18ab85c57afe: FlushDeltaMemStoresOp(355f3874af8f46608ac22907343e3041) complete. Timing: real 0.009s	user 0.004s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3726,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:37.767635 20455 maintenance_manager.cc:419] P 92bd2362d128445d8bff18ab85c57afe: Scheduling MajorDeltaCompactionOp(355f3874af8f46608ac22907343e3041): perf score=1.000000
I20260812 06:16:37.934001 20343 maintenance_manager.cc:643] P 92bd2362d128445d8bff18ab85c57afe: MajorDeltaCompactionOp(355f3874af8f46608ac22907343e3041) complete. Timing: real 0.166s	user 0.097s	sys 0.066s 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":249,"lbm_read_time_us":12135,"lbm_reads_lt_1ms":572,"lbm_write_time_us":28528,"lbm_writes_lt_1ms":543,"mutex_wait_us":1,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":1664,"update_count":2500}
I20260812 06:16:37.934602 20455 maintenance_manager.cc:419] P 92bd2362d128445d8bff18ab85c57afe: Scheduling FlushDeltaMemStoresOp(355f3874af8f46608ac22907343e3041): perf score=11.118625
I20260812 06:16:37.963063 20343 maintenance_manager.cc:643] P 92bd2362d128445d8bff18ab85c57afe: FlushDeltaMemStoresOp(355f3874af8f46608ac22907343e3041) complete. Timing: real 0.028s	user 0.006s	sys 0.022s Metrics: {"bytes_written":12717735,"delete_count":0,"lbm_write_time_us":11626,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:16:37.963678 20455 maintenance_manager.cc:419] P 92bd2362d128445d8bff18ab85c57afe: Scheduling FlushDeltaMemStoresOp(355f3874af8f46608ac22907343e3041): perf score=2.188937
I20260812 06:16:37.980609 20343 maintenance_manager.cc:643] P 92bd2362d128445d8bff18ab85c57afe: FlushDeltaMemStoresOp(355f3874af8f46608ac22907343e3041) complete. Timing: real 0.017s	user 0.012s	sys 0.000s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":5163,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:16:37.981020 20455 maintenance_manager.cc:419] P 92bd2362d128445d8bff18ab85c57afe: Scheduling MajorDeltaCompactionOp(355f3874af8f46608ac22907343e3041): perf score=1.000000
I20260812 06:16:38.128265 20343 maintenance_manager.cc:643] P 92bd2362d128445d8bff18ab85c57afe: MajorDeltaCompactionOp(355f3874af8f46608ac22907343e3041) complete. Timing: real 0.147s	user 0.093s	sys 0.039s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20713263,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":1321,"lbm_read_time_us":8335,"lbm_reads_lt_1ms":464,"lbm_write_time_us":20833,"lbm_writes_lt_1ms":443,"mutex_wait_us":336,"peak_mem_usage":50689328,"reinsert_count":0,"update_count":2000}
I20260812 06:16:38.128700 20455 maintenance_manager.cc:419] P 92bd2362d128445d8bff18ab85c57afe: Scheduling FlushDeltaMemStoresOp(355f3874af8f46608ac22907343e3041): perf score=14.095187
I20260812 06:16:38.171016 20343 maintenance_manager.cc:643] P 92bd2362d128445d8bff18ab85c57afe: FlushDeltaMemStoresOp(355f3874af8f46608ac22907343e3041) complete. Timing: real 0.042s	user 0.021s	sys 0.019s Metrics: {"bytes_written":16409903,"delete_count":0,"lbm_write_time_us":18826,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":402,"reinsert_count":0,"update_count":2000}
I20260812 06:16:38.171486 20455 maintenance_manager.cc:419] P 92bd2362d128445d8bff18ab85c57afe: Scheduling FlushDeltaMemStoresOp(355f3874af8f46608ac22907343e3041): perf score=2.188937
I20260812 06:16:38.182183 20343 maintenance_manager.cc:643] P 92bd2362d128445d8bff18ab85c57afe: FlushDeltaMemStoresOp(355f3874af8f46608ac22907343e3041) complete. Timing: real 0.011s	user 0.006s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3861,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:38.182662 20455 maintenance_manager.cc:419] P 92bd2362d128445d8bff18ab85c57afe: Scheduling MajorDeltaCompactionOp(355f3874af8f46608ac22907343e3041): perf score=1.000000
I20260812 06:16:38.324829 20343 maintenance_manager.cc:643] P 92bd2362d128445d8bff18ab85c57afe: MajorDeltaCompactionOp(355f3874af8f46608ac22907343e3041) complete. Timing: real 0.142s	user 0.125s	sys 0.016s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24815685,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":2003,"lbm_read_time_us":9909,"lbm_reads_lt_1ms":572,"lbm_write_time_us":27947,"lbm_writes_lt_1ms":543,"mutex_wait_us":702,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":1920,"update_count":2500}
I20260812 06:16:38.325318 20455 maintenance_manager.cc:419] P 92bd2362d128445d8bff18ab85c57afe: Scheduling FlushDeltaMemStoresOp(355f3874af8f46608ac22907343e3041): perf score=11.118625
I20260812 06:16:38.366910 20343 maintenance_manager.cc:643] P 92bd2362d128445d8bff18ab85c57afe: FlushDeltaMemStoresOp(355f3874af8f46608ac22907343e3041) complete. Timing: real 0.041s	user 0.021s	sys 0.018s Metrics: {"bytes_written":12717736,"delete_count":0,"lbm_write_time_us":17986,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":312,"reinsert_count":0,"update_count":1550}
I20260812 06:16:38.370172 20455 maintenance_manager.cc:419] P 92bd2362d128445d8bff18ab85c57afe: Scheduling FlushDeltaMemStoresOp(355f3874af8f46608ac22907343e3041): perf score=2.188937
I20260812 06:16:38.389529 20343 maintenance_manager.cc:643] P 92bd2362d128445d8bff18ab85c57afe: FlushDeltaMemStoresOp(355f3874af8f46608ac22907343e3041) complete. Timing: real 0.019s	user 0.006s	sys 0.005s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":4849,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:16:38.390013 20455 maintenance_manager.cc:419] P 92bd2362d128445d8bff18ab85c57afe: Scheduling FlushDeltaMemStoresOp(355f3874af8f46608ac22907343e3041): perf score=2.188937
I20260812 06:16:38.403824 20343 maintenance_manager.cc:643] P 92bd2362d128445d8bff18ab85c57afe: FlushDeltaMemStoresOp(355f3874af8f46608ac22907343e3041) complete. Timing: real 0.014s	user 0.007s	sys 0.005s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":5188,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:38.404446 20455 maintenance_manager.cc:419] P 92bd2362d128445d8bff18ab85c57afe: Scheduling FlushMRSOp(355f3874af8f46608ac22907343e3041): perf score=1.000000
I20260812 06:16:38.433517 20343 maintenance_manager.cc:643] P 92bd2362d128445d8bff18ab85c57afe: FlushMRSOp(355f3874af8f46608ac22907343e3041) complete. Timing: real 0.029s	user 0.025s	sys 0.000s Metrics: {"bytes_written":1193503,"cfile_init":1,"dirs.queue_time_us":63,"dirs.run_cpu_time_us":249,"dirs.run_wall_time_us":1320,"drs_written":1,"lbm_read_time_us":37,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1325,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":29}
I20260812 06:16:38.434389 20455 maintenance_manager.cc:419] P 92bd2362d128445d8bff18ab85c57afe: Scheduling LogGCOp(355f3874af8f46608ac22907343e3041): free 124710252 bytes of WAL
I20260812 06:16:38.434614 20343 log_reader.cc:385] T 355f3874af8f46608ac22907343e3041: removed 12 log segments from log reader
I20260812 06:16:38.434674 20343 log.cc:1079] T 355f3874af8f46608ac22907343e3041 P 92bd2362d128445d8bff18ab85c57afe: Deleting log segment in path: /tmp/dist-test-taskDoCWee/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515396661473-20146-0/minicluster-data/ts-0-root/wals/355f3874af8f46608ac22907343e3041/wal-000000003 (ops 12-16)
I20260812 06:16:38.434717 20343 log.cc:1079] T 355f3874af8f46608ac22907343e3041 P 92bd2362d128445d8bff18ab85c57afe: Deleting log segment in path: /tmp/dist-test-taskDoCWee/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515396661473-20146-0/minicluster-data/ts-0-root/wals/355f3874af8f46608ac22907343e3041/wal-000000004 (ops 17-21)
I20260812 06:16:38.434752 20343 log.cc:1079] T 355f3874af8f46608ac22907343e3041 P 92bd2362d128445d8bff18ab85c57afe: Deleting log segment in path: /tmp/dist-test-taskDoCWee/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515396661473-20146-0/minicluster-data/ts-0-root/wals/355f3874af8f46608ac22907343e3041/wal-000000005 (ops 22-26)
I20260812 06:16:38.434780 20343 log.cc:1079] T 355f3874af8f46608ac22907343e3041 P 92bd2362d128445d8bff18ab85c57afe: Deleting log segment in path: /tmp/dist-test-taskDoCWee/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515396661473-20146-0/minicluster-data/ts-0-root/wals/355f3874af8f46608ac22907343e3041/wal-000000006 (ops 27-31)
I20260812 06:16:38.434808 20343 log.cc:1079] T 355f3874af8f46608ac22907343e3041 P 92bd2362d128445d8bff18ab85c57afe: Deleting log segment in path: /tmp/dist-test-taskDoCWee/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515396661473-20146-0/minicluster-data/ts-0-root/wals/355f3874af8f46608ac22907343e3041/wal-000000007 (ops 32-36)
I20260812 06:16:38.434836 20343 log.cc:1079] T 355f3874af8f46608ac22907343e3041 P 92bd2362d128445d8bff18ab85c57afe: Deleting log segment in path: /tmp/dist-test-taskDoCWee/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515396661473-20146-0/minicluster-data/ts-0-root/wals/355f3874af8f46608ac22907343e3041/wal-000000008 (ops 37-41)
I20260812 06:16:38.434868 20343 log.cc:1079] T 355f3874af8f46608ac22907343e3041 P 92bd2362d128445d8bff18ab85c57afe: Deleting log segment in path: /tmp/dist-test-taskDoCWee/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515396661473-20146-0/minicluster-data/ts-0-root/wals/355f3874af8f46608ac22907343e3041/wal-000000009 (ops 42-46)
I20260812 06:16:38.434897 20343 log.cc:1079] T 355f3874af8f46608ac22907343e3041 P 92bd2362d128445d8bff18ab85c57afe: Deleting log segment in path: /tmp/dist-test-taskDoCWee/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515396661473-20146-0/minicluster-data/ts-0-root/wals/355f3874af8f46608ac22907343e3041/wal-000000010 (ops 47-51)
I20260812 06:16:38.434924 20343 log.cc:1079] T 355f3874af8f46608ac22907343e3041 P 92bd2362d128445d8bff18ab85c57afe: Deleting log segment in path: /tmp/dist-test-taskDoCWee/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515396661473-20146-0/minicluster-data/ts-0-root/wals/355f3874af8f46608ac22907343e3041/wal-000000011 (ops 52-56)
I20260812 06:16:38.434954 20343 log.cc:1079] T 355f3874af8f46608ac22907343e3041 P 92bd2362d128445d8bff18ab85c57afe: Deleting log segment in path: /tmp/dist-test-taskDoCWee/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515396661473-20146-0/minicluster-data/ts-0-root/wals/355f3874af8f46608ac22907343e3041/wal-000000012 (ops 57-61)
I20260812 06:16:38.434981 20343 log.cc:1079] T 355f3874af8f46608ac22907343e3041 P 92bd2362d128445d8bff18ab85c57afe: Deleting log segment in path: /tmp/dist-test-taskDoCWee/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515396661473-20146-0/minicluster-data/ts-0-root/wals/355f3874af8f46608ac22907343e3041/wal-000000013 (ops 62-66)
I20260812 06:16:38.435014 20343 log.cc:1079] T 355f3874af8f46608ac22907343e3041 P 92bd2362d128445d8bff18ab85c57afe: Deleting log segment in path: /tmp/dist-test-taskDoCWee/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515396661473-20146-0/minicluster-data/ts-0-root/wals/355f3874af8f46608ac22907343e3041/wal-000000014 (ops 67-71)
I20260812 06:16:38.460492 20343 maintenance_manager.cc:643] P 92bd2362d128445d8bff18ab85c57afe: LogGCOp(355f3874af8f46608ac22907343e3041) complete. Timing: real 0.026s	user 0.000s	sys 0.023s Metrics: {}
I20260812 06:16:38.460870 20455 maintenance_manager.cc:419] P 92bd2362d128445d8bff18ab85c57afe: Scheduling FlushDeltaMemStoresOp(355f3874af8f46608ac22907343e3041): perf score=3.181125
I20260812 06:16:38.480435 20343 maintenance_manager.cc:643] P 92bd2362d128445d8bff18ab85c57afe: FlushDeltaMemStoresOp(355f3874af8f46608ac22907343e3041) complete. Timing: real 0.019s	user 0.015s	sys 0.000s Metrics: {"bytes_written":4512902,"delete_count":0,"lbm_write_time_us":6362,"lbm_writes_lt_1ms":113,"reinsert_count":0,"update_count":550}
I20260812 06:16:38.480796 20455 maintenance_manager.cc:419] P 92bd2362d128445d8bff18ab85c57afe: Scheduling UndoDeltaBlockGCOp(355f3874af8f46608ac22907343e3041): 462 bytes on disk
I20260812 06:16:38.481156 20343 maintenance_manager.cc:643] P 92bd2362d128445d8bff18ab85c57afe: UndoDeltaBlockGCOp(355f3874af8f46608ac22907343e3041) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":44,"lbm_reads_lt_1ms":4}
I20260812 06:16:38.481559 20455 maintenance_manager.cc:419] P 92bd2362d128445d8bff18ab85c57afe: Scheduling FlushDeltaMemStoresOp(355f3874af8f46608ac22907343e3041): perf score=2.188937
I20260812 06:16:38.490497 20343 maintenance_manager.cc:643] P 92bd2362d128445d8bff18ab85c57afe: FlushDeltaMemStoresOp(355f3874af8f46608ac22907343e3041) complete. Timing: real 0.009s	user 0.008s	sys 0.000s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3308,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:16:38.490857 20455 maintenance_manager.cc:419] P 92bd2362d128445d8bff18ab85c57afe: Scheduling MajorDeltaCompactionOp(355f3874af8f46608ac22907343e3041): perf score=1.000000
I20260812 06:16:38.665118 20343 maintenance_manager.cc:643] P 92bd2362d128445d8bff18ab85c57afe: MajorDeltaCompactionOp(355f3874af8f46608ac22907343e3041) complete. Timing: real 0.174s	user 0.134s	sys 0.039s Metrics: {"cfile_cache_miss":735,"cfile_cache_miss_bytes":33020845,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":5,"delta_iterators_relevant":5,"dirs.queue_time_us":994,"lbm_read_time_us":13433,"lbm_reads_lt_1ms":775,"lbm_write_time_us":32588,"lbm_writes_lt_1ms":743,"mutex_wait_us":59,"peak_mem_usage":87969044,"reinsert_count":0,"spinlock_wait_cycles":3072,"thread_start_us":78,"threads_started":1,"update_count":3500}
I20260812 06:16:38.665563 20455 maintenance_manager.cc:419] P 92bd2362d128445d8bff18ab85c57afe: Scheduling FlushDeltaMemStoresOp(355f3874af8f46608ac22907343e3041): perf score=14.095187
I20260812 06:16:38.712157 20343 maintenance_manager.cc:643] P 92bd2362d128445d8bff18ab85c57afe: FlushDeltaMemStoresOp(355f3874af8f46608ac22907343e3041) complete. Timing: real 0.046s	user 0.046s	sys 0.000s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":20124,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:16:38.712633 20455 maintenance_manager.cc:419] P 92bd2362d128445d8bff18ab85c57afe: Scheduling FlushDeltaMemStoresOp(355f3874af8f46608ac22907343e3041): perf score=2.188937
I20260812 06:16:38.723537 20343 maintenance_manager.cc:643] P 92bd2362d128445d8bff18ab85c57afe: FlushDeltaMemStoresOp(355f3874af8f46608ac22907343e3041) complete. Timing: real 0.011s	user 0.009s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4262,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:38.723930 20455 maintenance_manager.cc:419] P 92bd2362d128445d8bff18ab85c57afe: Scheduling MajorDeltaCompactionOp(355f3874af8f46608ac22907343e3041): perf score=1.000000
I20260812 06:16:38.873939 20343 maintenance_manager.cc:643] P 92bd2362d128445d8bff18ab85c57afe: MajorDeltaCompactionOp(355f3874af8f46608ac22907343e3041) complete. Timing: real 0.150s	user 0.116s	sys 0.019s 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":3497,"dirs.run_cpu_time_us":517,"dirs.run_wall_time_us":2956,"lbm_read_time_us":10741,"lbm_reads_lt_1ms":572,"lbm_write_time_us":25716,"lbm_writes_lt_1ms":543,"mutex_wait_us":2985,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":3328,"update_count":2500}
I20260812 06:16:38.874521 20455 maintenance_manager.cc:419] P 92bd2362d128445d8bff18ab85c57afe: Scheduling FlushDeltaMemStoresOp(355f3874af8f46608ac22907343e3041): perf score=14.095187
I20260812 06:16:38.925092 20343 maintenance_manager.cc:643] P 92bd2362d128445d8bff18ab85c57afe: FlushDeltaMemStoresOp(355f3874af8f46608ac22907343e3041) complete. Timing: real 0.050s	user 0.031s	sys 0.015s Metrics: {"bytes_written":16409900,"delete_count":0,"lbm_write_time_us":21794,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":402,"reinsert_count":0,"update_count":2000}
I20260812 06:16:38.925618 20455 maintenance_manager.cc:419] P 92bd2362d128445d8bff18ab85c57afe: Scheduling FlushDeltaMemStoresOp(355f3874af8f46608ac22907343e3041): perf score=2.188937
I20260812 06:16:38.935144 20343 maintenance_manager.cc:643] P 92bd2362d128445d8bff18ab85c57afe: FlushDeltaMemStoresOp(355f3874af8f46608ac22907343e3041) complete. Timing: real 0.009s	user 0.008s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3555,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:38.935598 20455 maintenance_manager.cc:419] P 92bd2362d128445d8bff18ab85c57afe: Scheduling MajorDeltaCompactionOp(355f3874af8f46608ac22907343e3041): perf score=1.000000
I20260812 06:16:39.119663 20343 maintenance_manager.cc:643] P 92bd2362d128445d8bff18ab85c57afe: MajorDeltaCompactionOp(355f3874af8f46608ac22907343e3041) complete. Timing: real 0.184s	user 0.134s	sys 0.046s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24815682,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":118,"lbm_read_time_us":11748,"lbm_reads_lt_1ms":572,"lbm_write_time_us":31198,"lbm_writes_lt_1ms":543,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":1664,"update_count":2500}
I20260812 06:16:39.124127 20455 maintenance_manager.cc:419] P 92bd2362d128445d8bff18ab85c57afe: Scheduling FlushDeltaMemStoresOp(355f3874af8f46608ac22907343e3041): perf score=14.095187
I20260812 06:16:39.163933 20343 maintenance_manager.cc:643] P 92bd2362d128445d8bff18ab85c57afe: FlushDeltaMemStoresOp(355f3874af8f46608ac22907343e3041) complete. Timing: real 0.040s	user 0.021s	sys 0.016s Metrics: {"bytes_written":16409905,"delete_count":0,"lbm_write_time_us":17611,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:16:39.164420 20455 maintenance_manager.cc:419] P 92bd2362d128445d8bff18ab85c57afe: Scheduling MajorDeltaCompactionOp(355f3874af8f46608ac22907343e3041): perf score=1.000000
I20260812 06:16:39.307899 20343 maintenance_manager.cc:643] P 92bd2362d128445d8bff18ab85c57afe: MajorDeltaCompactionOp(355f3874af8f46608ac22907343e3041) complete. Timing: real 0.143s	user 0.090s	sys 0.048s Metrics: {"cfile_cache_miss":431,"cfile_cache_miss_bytes":20713156,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":1,"delta_iterators_relevant":1,"dirs.queue_time_us":587,"lbm_read_time_us":8875,"lbm_reads_lt_1ms":463,"lbm_write_time_us":23432,"lbm_writes_lt_1ms":443,"mutex_wait_us":38,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":15360,"update_count":2000}
I20260812 06:16:39.308449 20455 maintenance_manager.cc:419] P 92bd2362d128445d8bff18ab85c57afe: Scheduling FlushDeltaMemStoresOp(355f3874af8f46608ac22907343e3041): perf score=14.095187
I20260812 06:16:39.354548 20343 maintenance_manager.cc:643] P 92bd2362d128445d8bff18ab85c57afe: FlushDeltaMemStoresOp(355f3874af8f46608ac22907343e3041) complete. Timing: real 0.046s	user 0.034s	sys 0.003s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":16744,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:16:39.355022 20455 maintenance_manager.cc:419] P 92bd2362d128445d8bff18ab85c57afe: Scheduling FlushDeltaMemStoresOp(355f3874af8f46608ac22907343e3041): perf score=2.188937
I20260812 06:16:39.364912 20343 maintenance_manager.cc:643] P 92bd2362d128445d8bff18ab85c57afe: FlushDeltaMemStoresOp(355f3874af8f46608ac22907343e3041) complete. Timing: real 0.010s	user 0.004s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3828,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:39.365664 20455 maintenance_manager.cc:419] P 92bd2362d128445d8bff18ab85c57afe: Scheduling MajorDeltaCompactionOp(355f3874af8f46608ac22907343e3041): perf score=1.000000
I20260812 06:16:39.540150 20343 maintenance_manager.cc:643] P 92bd2362d128445d8bff18ab85c57afe: MajorDeltaCompactionOp(355f3874af8f46608ac22907343e3041) complete. Timing: real 0.174s	user 0.124s	sys 0.039s 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":115,"lbm_read_time_us":8695,"lbm_reads_lt_1ms":572,"lbm_write_time_us":28083,"lbm_writes_lt_1ms":543,"mutex_wait_us":39,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":8320,"update_count":2500}
I20260812 06:16:39.540729 20455 maintenance_manager.cc:419] P 92bd2362d128445d8bff18ab85c57afe: Scheduling FlushDeltaMemStoresOp(355f3874af8f46608ac22907343e3041): perf score=14.095187
I20260812 06:16:39.591048 20343 maintenance_manager.cc:643] P 92bd2362d128445d8bff18ab85c57afe: FlushDeltaMemStoresOp(355f3874af8f46608ac22907343e3041) complete. Timing: real 0.050s	user 0.037s	sys 0.011s Metrics: {"bytes_written":16409900,"delete_count":0,"lbm_write_time_us":22110,"lbm_writes_lt_1ms":403,"mutex_wait_us":2,"reinsert_count":0,"update_count":2000}
I20260812 06:16:39.591521 20455 maintenance_manager.cc:419] P 92bd2362d128445d8bff18ab85c57afe: Scheduling FlushDeltaMemStoresOp(355f3874af8f46608ac22907343e3041): perf score=2.188937
I20260812 06:16:39.601114 20343 maintenance_manager.cc:643] P 92bd2362d128445d8bff18ab85c57afe: FlushDeltaMemStoresOp(355f3874af8f46608ac22907343e3041) complete. Timing: real 0.009s	user 0.004s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3760,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:39.601722 20455 maintenance_manager.cc:419] P 92bd2362d128445d8bff18ab85c57afe: Scheduling MajorDeltaCompactionOp(355f3874af8f46608ac22907343e3041): perf score=1.000000
I20260812 06:16:39.760417 20343 maintenance_manager.cc:643] P 92bd2362d128445d8bff18ab85c57afe: MajorDeltaCompactionOp(355f3874af8f46608ac22907343e3041) complete. Timing: real 0.158s	user 0.107s	sys 0.040s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24815682,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":589,"lbm_read_time_us":11028,"lbm_reads_lt_1ms":572,"lbm_write_time_us":28152,"lbm_writes_lt_1ms":543,"mutex_wait_us":270,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":16768,"update_count":2500}
I20260812 06:16:39.760929 20455 maintenance_manager.cc:419] P 92bd2362d128445d8bff18ab85c57afe: Scheduling FlushDeltaMemStoresOp(355f3874af8f46608ac22907343e3041): perf score=14.095187
I20260812 06:16:39.807421 20343 maintenance_manager.cc:643] P 92bd2362d128445d8bff18ab85c57afe: FlushDeltaMemStoresOp(355f3874af8f46608ac22907343e3041) complete. Timing: real 0.046s	user 0.034s	sys 0.004s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":17347,"lbm_writes_lt_1ms":403,"mutex_wait_us":2,"reinsert_count":0,"update_count":2000}
I20260812 06:16:39.807921 20455 maintenance_manager.cc:419] P 92bd2362d128445d8bff18ab85c57afe: Scheduling FlushDeltaMemStoresOp(355f3874af8f46608ac22907343e3041): perf score=2.188937
I20260812 06:16:39.817765 20343 maintenance_manager.cc:643] P 92bd2362d128445d8bff18ab85c57afe: FlushDeltaMemStoresOp(355f3874af8f46608ac22907343e3041) complete. Timing: real 0.010s	user 0.004s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3767,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:39.818365 20455 maintenance_manager.cc:419] P 92bd2362d128445d8bff18ab85c57afe: Scheduling FlushMRSOp(355f3874af8f46608ac22907343e3041): perf score=1.000000
I20260812 06:16:39.851235 20343 maintenance_manager.cc:643] P 92bd2362d128445d8bff18ab85c57afe: FlushMRSOp(355f3874af8f46608ac22907343e3041) complete. Timing: real 0.033s	user 0.027s	sys 0.004s Metrics: {"bytes_written":1275449,"cfile_init":1,"dirs.queue_time_us":58,"dirs.run_cpu_time_us":224,"dirs.run_wall_time_us":1141,"drs_written":1,"lbm_read_time_us":44,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1593,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":31}
I20260812 06:16:39.852013 20455 maintenance_manager.cc:419] P 92bd2362d128445d8bff18ab85c57afe: Scheduling LogGCOp(355f3874af8f46608ac22907343e3041): free 120553435 bytes of WAL
I20260812 06:16:39.852254 20343 log_reader.cc:385] T 355f3874af8f46608ac22907343e3041: removed 12 log segments from log reader
I20260812 06:16:39.852308 20343 log.cc:1079] T 355f3874af8f46608ac22907343e3041 P 92bd2362d128445d8bff18ab85c57afe: Deleting log segment in path: /tmp/dist-test-taskDoCWee/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515396661473-20146-0/minicluster-data/ts-0-root/wals/355f3874af8f46608ac22907343e3041/wal-000000015 (ops 72-76)
I20260812 06:16:39.852348 20343 log.cc:1079] T 355f3874af8f46608ac22907343e3041 P 92bd2362d128445d8bff18ab85c57afe: Deleting log segment in path: /tmp/dist-test-taskDoCWee/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515396661473-20146-0/minicluster-data/ts-0-root/wals/355f3874af8f46608ac22907343e3041/wal-000000016 (ops 77-81)
I20260812 06:16:39.852381 20343 log.cc:1079] T 355f3874af8f46608ac22907343e3041 P 92bd2362d128445d8bff18ab85c57afe: Deleting log segment in path: /tmp/dist-test-taskDoCWee/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515396661473-20146-0/minicluster-data/ts-0-root/wals/355f3874af8f46608ac22907343e3041/wal-000000017 (ops 82-86)
I20260812 06:16:39.852407 20343 log.cc:1079] T 355f3874af8f46608ac22907343e3041 P 92bd2362d128445d8bff18ab85c57afe: Deleting log segment in path: /tmp/dist-test-taskDoCWee/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515396661473-20146-0/minicluster-data/ts-0-root/wals/355f3874af8f46608ac22907343e3041/wal-000000018 (ops 87-91)
I20260812 06:16:39.852437 20343 log.cc:1079] T 355f3874af8f46608ac22907343e3041 P 92bd2362d128445d8bff18ab85c57afe: Deleting log segment in path: /tmp/dist-test-taskDoCWee/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515396661473-20146-0/minicluster-data/ts-0-root/wals/355f3874af8f46608ac22907343e3041/wal-000000019 (ops 92-96)
I20260812 06:16:39.852466 20343 log.cc:1079] T 355f3874af8f46608ac22907343e3041 P 92bd2362d128445d8bff18ab85c57afe: Deleting log segment in path: /tmp/dist-test-taskDoCWee/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515396661473-20146-0/minicluster-data/ts-0-root/wals/355f3874af8f46608ac22907343e3041/wal-000000020 (ops 97-101)
I20260812 06:16:39.852496 20343 log.cc:1079] T 355f3874af8f46608ac22907343e3041 P 92bd2362d128445d8bff18ab85c57afe: Deleting log segment in path: /tmp/dist-test-taskDoCWee/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515396661473-20146-0/minicluster-data/ts-0-root/wals/355f3874af8f46608ac22907343e3041/wal-000000021 (ops 102-106)
I20260812 06:16:39.852525 20343 log.cc:1079] T 355f3874af8f46608ac22907343e3041 P 92bd2362d128445d8bff18ab85c57afe: Deleting log segment in path: /tmp/dist-test-taskDoCWee/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515396661473-20146-0/minicluster-data/ts-0-root/wals/355f3874af8f46608ac22907343e3041/wal-000000022 (ops 107-110)
I20260812 06:16:39.852555 20343 log.cc:1079] T 355f3874af8f46608ac22907343e3041 P 92bd2362d128445d8bff18ab85c57afe: Deleting log segment in path: /tmp/dist-test-taskDoCWee/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515396661473-20146-0/minicluster-data/ts-0-root/wals/355f3874af8f46608ac22907343e3041/wal-000000023 (ops 111-115)
I20260812 06:16:39.852584 20343 log.cc:1079] T 355f3874af8f46608ac22907343e3041 P 92bd2362d128445d8bff18ab85c57afe: Deleting log segment in path: /tmp/dist-test-taskDoCWee/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515396661473-20146-0/minicluster-data/ts-0-root/wals/355f3874af8f46608ac22907343e3041/wal-000000024 (ops 116-120)
I20260812 06:16:39.852613 20343 log.cc:1079] T 355f3874af8f46608ac22907343e3041 P 92bd2362d128445d8bff18ab85c57afe: Deleting log segment in path: /tmp/dist-test-taskDoCWee/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515396661473-20146-0/minicluster-data/ts-0-root/wals/355f3874af8f46608ac22907343e3041/wal-000000025 (ops 121-124)
I20260812 06:16:39.852643 20343 log.cc:1079] T 355f3874af8f46608ac22907343e3041 P 92bd2362d128445d8bff18ab85c57afe: Deleting log segment in path: /tmp/dist-test-taskDoCWee/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515396661473-20146-0/minicluster-data/ts-0-root/wals/355f3874af8f46608ac22907343e3041/wal-000000026 (ops 125-129)
I20260812 06:16:39.874264 20343 maintenance_manager.cc:643] P 92bd2362d128445d8bff18ab85c57afe: LogGCOp(355f3874af8f46608ac22907343e3041) complete. Timing: real 0.022s	user 0.000s	sys 0.022s Metrics: {}
I20260812 06:16:39.874833 20455 maintenance_manager.cc:419] P 92bd2362d128445d8bff18ab85c57afe: Scheduling UndoDeltaBlockGCOp(355f3874af8f46608ac22907343e3041): 481 bytes on disk
I20260812 06:16:39.875249 20343 maintenance_manager.cc:643] P 92bd2362d128445d8bff18ab85c57afe: UndoDeltaBlockGCOp(355f3874af8f46608ac22907343e3041) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":49,"lbm_reads_lt_1ms":4}
I20260812 06:16:39.875905 20455 maintenance_manager.cc:419] P 92bd2362d128445d8bff18ab85c57afe: Scheduling FlushDeltaMemStoresOp(355f3874af8f46608ac22907343e3041): perf score=3.181125
I20260812 06:16:39.895682 20343 maintenance_manager.cc:643] P 92bd2362d128445d8bff18ab85c57afe: FlushDeltaMemStoresOp(355f3874af8f46608ac22907343e3041) complete. Timing: real 0.020s	user 0.000s	sys 0.018s Metrics: {"bytes_written":4512903,"delete_count":0,"lbm_write_time_us":4581,"lbm_writes_lt_1ms":113,"reinsert_count":0,"update_count":550}
I20260812 06:16:39.896072 20455 maintenance_manager.cc:419] P 92bd2362d128445d8bff18ab85c57afe: Scheduling FlushDeltaMemStoresOp(355f3874af8f46608ac22907343e3041): perf score=2.188937
I20260812 06:16:39.904846 20343 maintenance_manager.cc:643] P 92bd2362d128445d8bff18ab85c57afe: FlushDeltaMemStoresOp(355f3874af8f46608ac22907343e3041) complete. Timing: real 0.009s	user 0.001s	sys 0.006s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3385,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:16:39.905241 20455 maintenance_manager.cc:419] P 92bd2362d128445d8bff18ab85c57afe: Scheduling MajorDeltaCompactionOp(355f3874af8f46608ac22907343e3041): perf score=1.000000
I20260812 06:16:40.121006 20343 maintenance_manager.cc:643] P 92bd2362d128445d8bff18ab85c57afe: MajorDeltaCompactionOp(355f3874af8f46608ac22907343e3041) complete. Timing: real 0.216s	user 0.136s	sys 0.080s Metrics: {"cfile_cache_miss":734,"cfile_cache_miss_bytes":33020736,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":144,"lbm_read_time_us":15598,"lbm_reads_lt_1ms":774,"lbm_write_time_us":36654,"lbm_writes_lt_1ms":743,"mutex_wait_us":2,"peak_mem_usage":87969044,"reinsert_count":0,"spinlock_wait_cycles":768,"thread_start_us":70,"threads_started":1,"update_count":3500}
I20260812 06:16:40.121510 20455 maintenance_manager.cc:419] P 92bd2362d128445d8bff18ab85c57afe: Scheduling FlushDeltaMemStoresOp(355f3874af8f46608ac22907343e3041): perf score=14.095187
I20260812 06:16:40.178622 20343 maintenance_manager.cc:643] P 92bd2362d128445d8bff18ab85c57afe: FlushDeltaMemStoresOp(355f3874af8f46608ac22907343e3041) complete. Timing: real 0.057s	user 0.037s	sys 0.019s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":23255,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":402,"reinsert_count":0,"update_count":2000}
I20260812 06:16:40.179049 20455 maintenance_manager.cc:419] P 92bd2362d128445d8bff18ab85c57afe: Scheduling FlushDeltaMemStoresOp(355f3874af8f46608ac22907343e3041): perf score=2.188937
I20260812 06:16:40.190524 20343 maintenance_manager.cc:643] P 92bd2362d128445d8bff18ab85c57afe: FlushDeltaMemStoresOp(355f3874af8f46608ac22907343e3041) complete. Timing: real 0.011s	user 0.009s	sys 0.000s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":3846,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:40.190996 20455 maintenance_manager.cc:419] P 92bd2362d128445d8bff18ab85c57afe: Scheduling MajorDeltaCompactionOp(355f3874af8f46608ac22907343e3041): perf score=1.000000
I20260812 06:16:40.348798 20343 maintenance_manager.cc:643] P 92bd2362d128445d8bff18ab85c57afe: MajorDeltaCompactionOp(355f3874af8f46608ac22907343e3041) complete. Timing: real 0.158s	user 0.098s	sys 0.060s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24815682,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":768,"lbm_read_time_us":11348,"lbm_reads_lt_1ms":564,"lbm_write_time_us":26367,"lbm_writes_lt_1ms":543,"mutex_wait_us":22,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":64000,"update_count":2500}
I20260812 06:16:40.349263 20455 maintenance_manager.cc:419] P 92bd2362d128445d8bff18ab85c57afe: Scheduling FlushDeltaMemStoresOp(355f3874af8f46608ac22907343e3041): perf score=14.095187
I20260812 06:16:40.404527 20343 maintenance_manager.cc:643] P 92bd2362d128445d8bff18ab85c57afe: FlushDeltaMemStoresOp(355f3874af8f46608ac22907343e3041) complete. Timing: real 0.055s	user 0.035s	sys 0.015s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":19458,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:16:40.405040 20455 maintenance_manager.cc:419] P 92bd2362d128445d8bff18ab85c57afe: Scheduling FlushDeltaMemStoresOp(355f3874af8f46608ac22907343e3041): perf score=5.165500
I20260812 06:16:40.419786 20343 maintenance_manager.cc:643] P 92bd2362d128445d8bff18ab85c57afe: FlushDeltaMemStoresOp(355f3874af8f46608ac22907343e3041) complete. Timing: real 0.015s	user 0.000s	sys 0.012s Metrics: {"bytes_written":6441038,"delete_count":0,"lbm_write_time_us":6176,"lbm_writes_lt_1ms":160,"reinsert_count":0,"update_count":785}
I20260812 06:16:40.420257 20455 maintenance_manager.cc:419] P 92bd2362d128445d8bff18ab85c57afe: Scheduling FlushDeltaMemStoresOp(355f3874af8f46608ac22907343e3041): perf score=1.000000
I20260812 06:16:40.425609 20343 maintenance_manager.cc:643] P 92bd2362d128445d8bff18ab85c57afe: FlushDeltaMemStoresOp(355f3874af8f46608ac22907343e3041) complete. Timing: real 0.005s	user 0.004s	sys 0.000s Metrics: {"bytes_written":1764227,"delete_count":0,"lbm_write_time_us":1712,"lbm_writes_lt_1ms":46,"reinsert_count":0,"update_count":215}
I20260812 06:16:40.426137 20455 maintenance_manager.cc:419] P 92bd2362d128445d8bff18ab85c57afe: Scheduling MajorDeltaCompactionOp(355f3874af8f46608ac22907343e3041): perf score=1.000000
I20260812 06:16:40.614012 20343 maintenance_manager.cc:643] P 92bd2362d128445d8bff18ab85c57afe: MajorDeltaCompactionOp(355f3874af8f46608ac22907343e3041) complete. Timing: real 0.188s	user 0.097s	sys 0.091s Metrics: {"cfile_cache_miss":633,"cfile_cache_miss_bytes":28918156,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":320,"lbm_read_time_us":13717,"lbm_reads_lt_1ms":673,"lbm_write_time_us":31592,"lbm_writes_lt_1ms":643,"mutex_wait_us":71,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":896,"update_count":3000}
I20260812 06:16:40.614933 20455 maintenance_manager.cc:419] P 92bd2362d128445d8bff18ab85c57afe: Scheduling FlushDeltaMemStoresOp(355f3874af8f46608ac22907343e3041): perf score=14.095187
I20260812 06:16:40.664156 20343 maintenance_manager.cc:643] P 92bd2362d128445d8bff18ab85c57afe: FlushDeltaMemStoresOp(355f3874af8f46608ac22907343e3041) complete. Timing: real 0.049s	user 0.036s	sys 0.009s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":20610,"lbm_writes_1-10_ms":2,"lbm_writes_lt_1ms":401,"reinsert_count":0,"update_count":2000}
I20260812 06:16:40.664637 20455 maintenance_manager.cc:419] P 92bd2362d128445d8bff18ab85c57afe: Scheduling FlushDeltaMemStoresOp(355f3874af8f46608ac22907343e3041): perf score=2.188937
I20260812 06:16:40.679847 20343 maintenance_manager.cc:643] P 92bd2362d128445d8bff18ab85c57afe: FlushDeltaMemStoresOp(355f3874af8f46608ac22907343e3041) complete. Timing: real 0.015s	user 0.005s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5836,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:40.680579 20455 maintenance_manager.cc:419] P 92bd2362d128445d8bff18ab85c57afe: Scheduling MajorDeltaCompactionOp(355f3874af8f46608ac22907343e3041): perf score=1.000000
I20260812 06:16:40.843945 20343 maintenance_manager.cc:643] P 92bd2362d128445d8bff18ab85c57afe: MajorDeltaCompactionOp(355f3874af8f46608ac22907343e3041) complete. Timing: real 0.163s	user 0.117s	sys 0.046s 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":12917,"lbm_reads_lt_1ms":572,"lbm_write_time_us":25979,"lbm_writes_lt_1ms":543,"mutex_wait_us":19,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":24320,"update_count":2500}
I20260812 06:16:40.844625 20455 maintenance_manager.cc:419] P 92bd2362d128445d8bff18ab85c57afe: Scheduling FlushDeltaMemStoresOp(355f3874af8f46608ac22907343e3041): perf score=14.095187
I20260812 06:16:40.905637 20343 maintenance_manager.cc:643] P 92bd2362d128445d8bff18ab85c57afe: FlushDeltaMemStoresOp(355f3874af8f46608ac22907343e3041) complete. Timing: real 0.061s	user 0.026s	sys 0.028s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":22076,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:16:40.906164 20455 maintenance_manager.cc:419] P 92bd2362d128445d8bff18ab85c57afe: Scheduling FlushDeltaMemStoresOp(355f3874af8f46608ac22907343e3041): perf score=2.188937
I20260812 06:16:40.916080 20343 maintenance_manager.cc:643] P 92bd2362d128445d8bff18ab85c57afe: FlushDeltaMemStoresOp(355f3874af8f46608ac22907343e3041) complete. Timing: real 0.010s	user 0.008s	sys 0.000s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":3779,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:40.916477 20455 maintenance_manager.cc:419] P 92bd2362d128445d8bff18ab85c57afe: Scheduling MajorDeltaCompactionOp(355f3874af8f46608ac22907343e3041): perf score=1.000000
I20260812 06:16:41.086570 20343 maintenance_manager.cc:643] P 92bd2362d128445d8bff18ab85c57afe: MajorDeltaCompactionOp(355f3874af8f46608ac22907343e3041) complete. Timing: real 0.170s	user 0.117s	sys 0.044s 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":335,"lbm_read_time_us":11478,"lbm_reads_lt_1ms":572,"lbm_write_time_us":27138,"lbm_writes_lt_1ms":543,"mutex_wait_us":26,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":3968,"update_count":2500}
I20260812 06:16:41.087139 20455 maintenance_manager.cc:419] P 92bd2362d128445d8bff18ab85c57afe: Scheduling FlushDeltaMemStoresOp(355f3874af8f46608ac22907343e3041): perf score=14.095187
I20260812 06:16:41.139598 20343 maintenance_manager.cc:643] P 92bd2362d128445d8bff18ab85c57afe: FlushDeltaMemStoresOp(355f3874af8f46608ac22907343e3041) complete. Timing: real 0.052s	user 0.011s	sys 0.035s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":18476,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:16:41.140110 20455 maintenance_manager.cc:419] P 92bd2362d128445d8bff18ab85c57afe: Scheduling FlushDeltaMemStoresOp(355f3874af8f46608ac22907343e3041): perf score=2.188937
I20260812 06:16:41.150257 20343 maintenance_manager.cc:643] P 92bd2362d128445d8bff18ab85c57afe: FlushDeltaMemStoresOp(355f3874af8f46608ac22907343e3041) complete. Timing: real 0.010s	user 0.005s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3907,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:41.150676 20455 maintenance_manager.cc:419] P 92bd2362d128445d8bff18ab85c57afe: Scheduling FlushMRSOp(355f3874af8f46608ac22907343e3041): perf score=1.000000
I20260812 06:16:41.179601 20343 maintenance_manager.cc:643] P 92bd2362d128445d8bff18ab85c57afe: FlushMRSOp(355f3874af8f46608ac22907343e3041) complete. Timing: real 0.029s	user 0.022s	sys 0.004s Metrics: {"bytes_written":1152512,"cfile_init":1,"dirs.queue_time_us":56,"dirs.run_cpu_time_us":173,"dirs.run_wall_time_us":1142,"drs_written":1,"lbm_read_time_us":36,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1555,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":28}
I20260812 06:16:41.180261 20455 maintenance_manager.cc:419] P 92bd2362d128445d8bff18ab85c57afe: Scheduling UndoDeltaBlockGCOp(355f3874af8f46608ac22907343e3041): 447 bytes on disk
I20260812 06:16:41.180727 20343 maintenance_manager.cc:643] P 92bd2362d128445d8bff18ab85c57afe: UndoDeltaBlockGCOp(355f3874af8f46608ac22907343e3041) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":45,"lbm_reads_lt_1ms":4}
I20260812 06:16:41.181211 20455 maintenance_manager.cc:419] P 92bd2362d128445d8bff18ab85c57afe: Scheduling MajorDeltaCompactionOp(355f3874af8f46608ac22907343e3041): perf score=1.000000
I20260812 06:16:41.338459 20343 maintenance_manager.cc:643] P 92bd2362d128445d8bff18ab85c57afe: MajorDeltaCompactionOp(355f3874af8f46608ac22907343e3041) complete. Timing: real 0.157s	user 0.098s	sys 0.057s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24815684,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":2188,"lbm_read_time_us":10433,"lbm_reads_lt_1ms":564,"lbm_write_time_us":26885,"lbm_writes_lt_1ms":543,"mutex_wait_us":628,"peak_mem_usage":63115900,"reinsert_count":0,"update_count":2500}
I20260812 06:16:41.339229 20455 maintenance_manager.cc:419] P 92bd2362d128445d8bff18ab85c57afe: Scheduling LogGCOp(355f3874af8f46608ac22907343e3041): free 116849781 bytes of WAL
I20260812 06:16:41.339438 20343 log_reader.cc:385] T 355f3874af8f46608ac22907343e3041: removed 12 log segments from log reader
I20260812 06:16:41.339481 20343 log.cc:1079] T 355f3874af8f46608ac22907343e3041 P 92bd2362d128445d8bff18ab85c57afe: Deleting log segment in path: /tmp/dist-test-taskDoCWee/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515396661473-20146-0/minicluster-data/ts-0-root/wals/355f3874af8f46608ac22907343e3041/wal-000000027 (ops 130-134)
I20260812 06:16:41.339519 20343 log.cc:1079] T 355f3874af8f46608ac22907343e3041 P 92bd2362d128445d8bff18ab85c57afe: Deleting log segment in path: /tmp/dist-test-taskDoCWee/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515396661473-20146-0/minicluster-data/ts-0-root/wals/355f3874af8f46608ac22907343e3041/wal-000000028 (ops 135-139)
I20260812 06:16:41.339551 20343 log.cc:1079] T 355f3874af8f46608ac22907343e3041 P 92bd2362d128445d8bff18ab85c57afe: Deleting log segment in path: /tmp/dist-test-taskDoCWee/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515396661473-20146-0/minicluster-data/ts-0-root/wals/355f3874af8f46608ac22907343e3041/wal-000000029 (ops 140-144)
I20260812 06:16:41.339612 20343 log.cc:1079] T 355f3874af8f46608ac22907343e3041 P 92bd2362d128445d8bff18ab85c57afe: Deleting log segment in path: /tmp/dist-test-taskDoCWee/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515396661473-20146-0/minicluster-data/ts-0-root/wals/355f3874af8f46608ac22907343e3041/wal-000000030 (ops 145-148)
I20260812 06:16:41.339650 20343 log.cc:1079] T 355f3874af8f46608ac22907343e3041 P 92bd2362d128445d8bff18ab85c57afe: Deleting log segment in path: /tmp/dist-test-taskDoCWee/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515396661473-20146-0/minicluster-data/ts-0-root/wals/355f3874af8f46608ac22907343e3041/wal-000000031 (ops 149-153)
I20260812 06:16:41.339674 20343 log.cc:1079] T 355f3874af8f46608ac22907343e3041 P 92bd2362d128445d8bff18ab85c57afe: Deleting log segment in path: /tmp/dist-test-taskDoCWee/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515396661473-20146-0/minicluster-data/ts-0-root/wals/355f3874af8f46608ac22907343e3041/wal-000000032 (ops 154-158)
I20260812 06:16:41.339730 20343 log.cc:1079] T 355f3874af8f46608ac22907343e3041 P 92bd2362d128445d8bff18ab85c57afe: Deleting log segment in path: /tmp/dist-test-taskDoCWee/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515396661473-20146-0/minicluster-data/ts-0-root/wals/355f3874af8f46608ac22907343e3041/wal-000000033 (ops 159-162)
I20260812 06:16:41.339763 20343 log.cc:1079] T 355f3874af8f46608ac22907343e3041 P 92bd2362d128445d8bff18ab85c57afe: Deleting log segment in path: /tmp/dist-test-taskDoCWee/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515396661473-20146-0/minicluster-data/ts-0-root/wals/355f3874af8f46608ac22907343e3041/wal-000000034 (ops 163-167)
I20260812 06:16:41.339818 20343 log.cc:1079] T 355f3874af8f46608ac22907343e3041 P 92bd2362d128445d8bff18ab85c57afe: Deleting log segment in path: /tmp/dist-test-taskDoCWee/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515396661473-20146-0/minicluster-data/ts-0-root/wals/355f3874af8f46608ac22907343e3041/wal-000000035 (ops 168-172)
I20260812 06:16:41.339851 20343 log.cc:1079] T 355f3874af8f46608ac22907343e3041 P 92bd2362d128445d8bff18ab85c57afe: Deleting log segment in path: /tmp/dist-test-taskDoCWee/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515396661473-20146-0/minicluster-data/ts-0-root/wals/355f3874af8f46608ac22907343e3041/wal-000000036 (ops 173-176)
I20260812 06:16:41.339913 20343 log.cc:1079] T 355f3874af8f46608ac22907343e3041 P 92bd2362d128445d8bff18ab85c57afe: Deleting log segment in path: /tmp/dist-test-taskDoCWee/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515396661473-20146-0/minicluster-data/ts-0-root/wals/355f3874af8f46608ac22907343e3041/wal-000000037 (ops 177-181)
I20260812 06:16:41.339947 20343 log.cc:1079] T 355f3874af8f46608ac22907343e3041 P 92bd2362d128445d8bff18ab85c57afe: Deleting log segment in path: /tmp/dist-test-taskDoCWee/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515396661473-20146-0/minicluster-data/ts-0-root/wals/355f3874af8f46608ac22907343e3041/wal-000000038 (ops 182-186)
I20260812 06:16:41.359506 20343 maintenance_manager.cc:643] P 92bd2362d128445d8bff18ab85c57afe: LogGCOp(355f3874af8f46608ac22907343e3041) complete. Timing: real 0.020s	user 0.000s	sys 0.018s Metrics: {}
I20260812 06:16:41.359951 20455 maintenance_manager.cc:419] P 92bd2362d128445d8bff18ab85c57afe: Scheduling FlushDeltaMemStoresOp(355f3874af8f46608ac22907343e3041): perf score=18.063937
I20260812 06:16:41.420642 20343 maintenance_manager.cc:643] P 92bd2362d128445d8bff18ab85c57afe: FlushDeltaMemStoresOp(355f3874af8f46608ac22907343e3041) complete. Timing: real 0.061s	user 0.027s	sys 0.023s Metrics: {"bytes_written":19773903,"delete_count":0,"lbm_write_time_us":20157,"lbm_writes_lt_1ms":485,"reinsert_count":0,"update_count":2410}
I20260812 06:16:41.421167 20455 maintenance_manager.cc:419] P 92bd2362d128445d8bff18ab85c57afe: Scheduling FlushDeltaMemStoresOp(355f3874af8f46608ac22907343e3041): perf score=3.181125
I20260812 06:16:41.432909 20343 maintenance_manager.cc:643] P 92bd2362d128445d8bff18ab85c57afe: FlushDeltaMemStoresOp(355f3874af8f46608ac22907343e3041) complete. Timing: real 0.012s	user 0.010s	sys 0.000s Metrics: {"bytes_written":4841098,"delete_count":0,"lbm_write_time_us":4601,"lbm_writes_lt_1ms":121,"reinsert_count":0,"update_count":590}
I20260812 06:16:41.433471 20455 maintenance_manager.cc:419] P 92bd2362d128445d8bff18ab85c57afe: Scheduling MajorDeltaCompactionOp(355f3874af8f46608ac22907343e3041): perf score=1.000000
I20260812 06:16:41.477098 20146 heavy-update-compaction-itest.cc:229] Time spent updating: real 4.541s	user 1.631s	sys 0.168s
I20260812 06:16:41.577625 20146 heavy-update-compaction-itest.cc:265] Time spent scanning: real 0.100s	user 0.002s	sys 0.000s
I20260812 06:16:41.578274 20146 tablet_server.cc:179] TabletServer@127.19.172.129:0 shutting down...
I20260812 06:16:41.619328 20343 maintenance_manager.cc:643] P 92bd2362d128445d8bff18ab85c57afe: MajorDeltaCompactionOp(355f3874af8f46608ac22907343e3041) complete. Timing: real 0.186s	user 0.112s	sys 0.071s Metrics: {"cfile_cache_miss":632,"cfile_cache_miss_bytes":28918124,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":880,"lbm_read_time_us":15532,"lbm_reads_1-10_ms":1,"lbm_reads_lt_1ms":667,"lbm_write_time_us":31448,"lbm_writes_lt_1ms":643,"mutex_wait_us":375,"peak_mem_usage":75542472,"reinsert_count":0,"update_count":3000}
I20260812 06:16:41.619887 20146 ts_tablet_manager.cc:1507] Shutting down tablet manager...
I20260812 06:16:41.620282 20146 tablet_replica.cc:333] T 355f3874af8f46608ac22907343e3041 P 92bd2362d128445d8bff18ab85c57afe: stopping tablet replica
I20260812 06:16:41.620529 20146 raft_consensus.cc:2243] T 355f3874af8f46608ac22907343e3041 P 92bd2362d128445d8bff18ab85c57afe [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:16:41.620757 20146 raft_consensus.cc:2272] T 355f3874af8f46608ac22907343e3041 P 92bd2362d128445d8bff18ab85c57afe [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:16:41.636561 20146 tablet_server.cc:196] TabletServer@127.19.172.129:0 shutdown complete.
I20260812 06:16:41.673995 20146 master.cc:562] Master@127.19.172.190:34785 shutting down...
I20260812 06:16:41.677038 20146 raft_consensus.cc:2243] T 00000000000000000000000000000000 P 54c6f400c9b546baac5a56cdf74d6300 [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:16:41.677210 20146 raft_consensus.cc:2272] T 00000000000000000000000000000000 P 54c6f400c9b546baac5a56cdf74d6300 [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:16:41.677284 20146 tablet_replica.cc:333] T 00000000000000000000000000000000 P 54c6f400c9b546baac5a56cdf74d6300: stopping tablet replica
I20260812 06:16:41.689375 20146 master.cc:584] Master@127.19.172.190:34785 shutdown complete.
[       OK ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/0 (5091 ms)
[ RUN      ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/1
I20260812 06:16:41.773522 20146 internal_mini_cluster.cc:156] Creating distributed mini masters. Addrs: 127.19.172.190:40833
I20260812 06:16:41.773952 20146 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:16:41.775789 20508 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:16:41.775862 20510 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:16:41.776027 20146 server_base.cc:1061] running on GCE node
W20260812 06:16:41.776043 20512 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:16:41.776249 20146 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:16:41.776288 20146 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:16:41.776302 20146 hybrid_clock.cc:648] HybridClock initialized: now 1786515401776302 us; error 0 us; skew 500 ppm
I20260812 06:16:41.777086 20146 webserver.cc:533] Webserver started at http://127.19.172.190:39727/ using document root <none> and password file <none>
I20260812 06:16:41.777236 20146 fs_manager.cc:362] Metadata directory not provided
I20260812 06:16:41.777281 20146 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:16:41.777355 20146 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:16:41.777733 20146 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskDoCWee/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515396661473-20146-0/minicluster-data/master-0-root/instance:
uuid: "3311b838d2b441c088060de21af46960"
format_stamp: "Formatted at 2026-08-12 06:16:41 on dist-test-slave-tc2s"
I20260812 06:16:41.779307 20146 fs_manager.cc:696] Time spent creating directory manager: real 0.001s	user 0.000s	sys 0.001s
I20260812 06:16:41.780148 20518 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:16:41.780364 20146 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.000s	sys 0.001s
I20260812 06:16:41.780432 20146 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskDoCWee/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515396661473-20146-0/minicluster-data/master-0-root
uuid: "3311b838d2b441c088060de21af46960"
format_stamp: "Formatted at 2026-08-12 06:16:41 on dist-test-slave-tc2s"
I20260812 06:16:41.780503 20146 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskDoCWee/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515396661473-20146-0/minicluster-data/master-0-root
metadata directory: /tmp/dist-test-taskDoCWee/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515396661473-20146-0/minicluster-data/master-0-root
1 data directories: /tmp/dist-test-taskDoCWee/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515396661473-20146-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:16:41.791491 20146 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:16:41.791785 20146 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:16:41.795583 20146 rpc_server.cc:307] RPC server started. Bound to: 127.19.172.190:40833
I20260812 06:16:41.799724 20626 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.19.172.190:40833 every 8 connection(s)
I20260812 06:16:41.800141 20630 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:16:41.801800 20630 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P 3311b838d2b441c088060de21af46960: Bootstrap starting.
I20260812 06:16:41.802590 20630 tablet_bootstrap.cc:654] T 00000000000000000000000000000000 P 3311b838d2b441c088060de21af46960: Neither blocks nor log segments found. Creating new log.
I20260812 06:16:41.803504 20630 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P 3311b838d2b441c088060de21af46960: No bootstrap required, opened a new log
I20260812 06:16:41.803884 20630 raft_consensus.cc:359] T 00000000000000000000000000000000 P 3311b838d2b441c088060de21af46960 [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "3311b838d2b441c088060de21af46960" member_type: VOTER }
I20260812 06:16:41.803967 20630 raft_consensus.cc:385] T 00000000000000000000000000000000 P 3311b838d2b441c088060de21af46960 [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:16:41.803999 20630 raft_consensus.cc:740] T 00000000000000000000000000000000 P 3311b838d2b441c088060de21af46960 [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: 3311b838d2b441c088060de21af46960, State: Initialized, Role: FOLLOWER
I20260812 06:16:41.804136 20630 consensus_queue.cc:260] T 00000000000000000000000000000000 P 3311b838d2b441c088060de21af46960 [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: "3311b838d2b441c088060de21af46960" member_type: VOTER }
I20260812 06:16:41.804201 20630 raft_consensus.cc:399] T 00000000000000000000000000000000 P 3311b838d2b441c088060de21af46960 [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:16:41.804237 20630 raft_consensus.cc:493] T 00000000000000000000000000000000 P 3311b838d2b441c088060de21af46960 [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:16:41.804286 20630 raft_consensus.cc:3060] T 00000000000000000000000000000000 P 3311b838d2b441c088060de21af46960 [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:16:41.804917 20630 raft_consensus.cc:515] T 00000000000000000000000000000000 P 3311b838d2b441c088060de21af46960 [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "3311b838d2b441c088060de21af46960" member_type: VOTER }
I20260812 06:16:41.805034 20630 leader_election.cc:304] T 00000000000000000000000000000000 P 3311b838d2b441c088060de21af46960 [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: 3311b838d2b441c088060de21af46960; no voters: 
I20260812 06:16:41.805203 20630 leader_election.cc:290] T 00000000000000000000000000000000 P 3311b838d2b441c088060de21af46960 [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:16:41.805300 20633 raft_consensus.cc:2804] T 00000000000000000000000000000000 P 3311b838d2b441c088060de21af46960 [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:16:41.805475 20633 raft_consensus.cc:697] T 00000000000000000000000000000000 P 3311b838d2b441c088060de21af46960 [term 1 LEADER]: Becoming Leader. State: Replica: 3311b838d2b441c088060de21af46960, State: Running, Role: LEADER
I20260812 06:16:41.805609 20630 sys_catalog.cc:565] T 00000000000000000000000000000000 P 3311b838d2b441c088060de21af46960 [sys.catalog]: configured and running, proceeding with master startup.
I20260812 06:16:41.805631 20633 consensus_queue.cc:237] T 00000000000000000000000000000000 P 3311b838d2b441c088060de21af46960 [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: "3311b838d2b441c088060de21af46960" member_type: VOTER }
I20260812 06:16:41.806069 20635 sys_catalog.cc:455] T 00000000000000000000000000000000 P 3311b838d2b441c088060de21af46960 [sys.catalog]: SysCatalogTable state changed. Reason: RaftConsensus started. Latest consensus state: current_term: 1 leader_uuid: "3311b838d2b441c088060de21af46960" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "3311b838d2b441c088060de21af46960" member_type: VOTER } }
I20260812 06:16:41.806097 20636 sys_catalog.cc:455] T 00000000000000000000000000000000 P 3311b838d2b441c088060de21af46960 [sys.catalog]: SysCatalogTable state changed. Reason: New leader 3311b838d2b441c088060de21af46960. Latest consensus state: current_term: 1 leader_uuid: "3311b838d2b441c088060de21af46960" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "3311b838d2b441c088060de21af46960" member_type: VOTER } }
I20260812 06:16:41.806249 20636 sys_catalog.cc:458] T 00000000000000000000000000000000 P 3311b838d2b441c088060de21af46960 [sys.catalog]: This master's current role is: LEADER
I20260812 06:16:41.806228 20635 sys_catalog.cc:458] T 00000000000000000000000000000000 P 3311b838d2b441c088060de21af46960 [sys.catalog]: This master's current role is: LEADER
I20260812 06:16:41.806674 20643 catalog_manager.cc:1511] Loading table and tablet metadata into memory...
I20260812 06:16:41.807631 20643 catalog_manager.cc:1520] Initializing Kudu cluster ID...
I20260812 06:16:41.807842 20146 internal_mini_cluster.cc:184] Waiting to initialize catalog manager on master 0
I20260812 06:16:41.809281 20643 catalog_manager.cc:1383] Generated new cluster ID: 2af89d6f38624030a0df8213fe716dcd
I20260812 06:16:41.809329 20643 catalog_manager.cc:1531] Initializing Kudu internal certificate authority...
I20260812 06:16:41.838625 20643 catalog_manager.cc:1406] Generated new certificate authority record
I20260812 06:16:41.839151 20643 catalog_manager.cc:1540] Loading token signing keys...
I20260812 06:16:41.848871 20643 catalog_manager.cc:6092] T 00000000000000000000000000000000 P 3311b838d2b441c088060de21af46960: Generated new TSK 0
I20260812 06:16:41.849030 20643 catalog_manager.cc:1550] Initializing in-progress tserver states...
I20260812 06:16:41.872115 20146 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:16:41.873883 20669 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:16:41.873979 20146 server_base.cc:1061] running on GCE node
W20260812 06:16:41.873945 20676 instance_detector.cc:116] could not retrieve OpenStack instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:16:41.874141 20663 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:16:41.874322 20146 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:16:41.874363 20146 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:16:41.874378 20146 hybrid_clock.cc:648] HybridClock initialized: now 1786515401874378 us; error 0 us; skew 500 ppm
I20260812 06:16:41.875109 20146 webserver.cc:533] Webserver started at http://127.19.172.129:34611/ using document root <none> and password file <none>
I20260812 06:16:41.875241 20146 fs_manager.cc:362] Metadata directory not provided
I20260812 06:16:41.875280 20146 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:16:41.875337 20146 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:16:41.875679 20146 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskDoCWee/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515396661473-20146-0/minicluster-data/ts-0-root/instance:
uuid: "c73d258340b34264837fab21878bc358"
format_stamp: "Formatted at 2026-08-12 06:16:41 on dist-test-slave-tc2s"
I20260812 06:16:41.876986 20146 fs_manager.cc:696] Time spent creating directory manager: real 0.001s	user 0.000s	sys 0.002s
I20260812 06:16:41.877806 20682 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:16:41.878032 20146 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.000s	sys 0.001s
I20260812 06:16:41.878095 20146 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskDoCWee/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515396661473-20146-0/minicluster-data/ts-0-root
uuid: "c73d258340b34264837fab21878bc358"
format_stamp: "Formatted at 2026-08-12 06:16:41 on dist-test-slave-tc2s"
I20260812 06:16:41.878161 20146 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskDoCWee/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515396661473-20146-0/minicluster-data/ts-0-root
metadata directory: /tmp/dist-test-taskDoCWee/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515396661473-20146-0/minicluster-data/ts-0-root
1 data directories: /tmp/dist-test-taskDoCWee/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515396661473-20146-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:16:41.895612 20146 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:16:41.895908 20146 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:16:41.896174 20146 txn_system_client.cc:432] TxnSystemClient initialization is disabled...
I20260812 06:16:41.896600 20146 ts_tablet_manager.cc:585] Loaded tablet metadata (0 total tablets, 0 live tablets)
I20260812 06:16:41.896636 20146 ts_tablet_manager.cc:531] Time spent load tablet metadata: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:16:41.896668 20146 ts_tablet_manager.cc:616] Registered 0 tablets
I20260812 06:16:41.896697 20146 ts_tablet_manager.cc:595] Time spent register tablets: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:16:41.900709 20146 rpc_server.cc:307] RPC server started. Bound to: 127.19.172.129:38513
I20260812 06:16:41.901535 20792 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.19.172.129:38513 every 8 connection(s)
I20260812 06:16:41.908380 20795 heartbeater.cc:344] Connected to a master server at 127.19.172.190:40833
I20260812 06:16:41.908479 20795 heartbeater.cc:461] Registering TS with master...
I20260812 06:16:41.908653 20795 heartbeater.cc:507] Master 127.19.172.190:40833 requested a full tablet report, sending...
I20260812 06:16:41.909237 20545 ts_manager.cc:194] Registered new tserver with Master: c73d258340b34264837fab21878bc358 (127.19.172.129:38513)
I20260812 06:16:41.909936 20545 master_service.cc:502] Signed X509 certificate for tserver {username='slave'} at 127.0.0.1:58874
I20260812 06:16:41.910118 20146 internal_mini_cluster.cc:371] 1 TS(s) registered with all masters after 0.008786848s
I20260812 06:16:41.915993 20545 catalog_manager.cc:2283] Servicing CreateTable request from {username='slave'} at 127.0.0.1:58878:
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:16:41.924016 20728 tablet_service.cc:1511] Processing CreateTablet for tablet b9cbe9188ec6434c87f5997054949fb1 (DEFAULT_TABLE table=heavy-update-compaction-test [id=17e389e956a94236bcc2e7f5dd6d2c46]), partition=
I20260812 06:16:41.924235 20728 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet b9cbe9188ec6434c87f5997054949fb1. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:16:41.926024 20819 tablet_bootstrap.cc:492] T b9cbe9188ec6434c87f5997054949fb1 P c73d258340b34264837fab21878bc358: Bootstrap starting.
I20260812 06:16:41.926895 20819 tablet_bootstrap.cc:654] T b9cbe9188ec6434c87f5997054949fb1 P c73d258340b34264837fab21878bc358: Neither blocks nor log segments found. Creating new log.
I20260812 06:16:41.927825 20819 tablet_bootstrap.cc:492] T b9cbe9188ec6434c87f5997054949fb1 P c73d258340b34264837fab21878bc358: No bootstrap required, opened a new log
I20260812 06:16:41.927897 20819 ts_tablet_manager.cc:1403] T b9cbe9188ec6434c87f5997054949fb1 P c73d258340b34264837fab21878bc358: Time spent bootstrapping tablet: real 0.002s	user 0.001s	sys 0.000s
I20260812 06:16:41.928285 20819 raft_consensus.cc:359] T b9cbe9188ec6434c87f5997054949fb1 P c73d258340b34264837fab21878bc358 [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "c73d258340b34264837fab21878bc358" member_type: VOTER last_known_addr { host: "127.19.172.129" port: 38513 } }
I20260812 06:16:41.928369 20819 raft_consensus.cc:385] T b9cbe9188ec6434c87f5997054949fb1 P c73d258340b34264837fab21878bc358 [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:16:41.928403 20819 raft_consensus.cc:740] T b9cbe9188ec6434c87f5997054949fb1 P c73d258340b34264837fab21878bc358 [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: c73d258340b34264837fab21878bc358, State: Initialized, Role: FOLLOWER
I20260812 06:16:41.928534 20819 consensus_queue.cc:260] T b9cbe9188ec6434c87f5997054949fb1 P c73d258340b34264837fab21878bc358 [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: "c73d258340b34264837fab21878bc358" member_type: VOTER last_known_addr { host: "127.19.172.129" port: 38513 } }
I20260812 06:16:41.928612 20819 raft_consensus.cc:399] T b9cbe9188ec6434c87f5997054949fb1 P c73d258340b34264837fab21878bc358 [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:16:41.928650 20819 raft_consensus.cc:493] T b9cbe9188ec6434c87f5997054949fb1 P c73d258340b34264837fab21878bc358 [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:16:41.928699 20819 raft_consensus.cc:3060] T b9cbe9188ec6434c87f5997054949fb1 P c73d258340b34264837fab21878bc358 [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:16:41.929534 20819 raft_consensus.cc:515] T b9cbe9188ec6434c87f5997054949fb1 P c73d258340b34264837fab21878bc358 [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "c73d258340b34264837fab21878bc358" member_type: VOTER last_known_addr { host: "127.19.172.129" port: 38513 } }
I20260812 06:16:41.929678 20819 leader_election.cc:304] T b9cbe9188ec6434c87f5997054949fb1 P c73d258340b34264837fab21878bc358 [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: c73d258340b34264837fab21878bc358; no voters: 
I20260812 06:16:41.929848 20819 leader_election.cc:290] T b9cbe9188ec6434c87f5997054949fb1 P c73d258340b34264837fab21878bc358 [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:16:41.929977 20822 raft_consensus.cc:2804] T b9cbe9188ec6434c87f5997054949fb1 P c73d258340b34264837fab21878bc358 [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:16:41.930191 20819 ts_tablet_manager.cc:1434] T b9cbe9188ec6434c87f5997054949fb1 P c73d258340b34264837fab21878bc358: Time spent starting tablet: real 0.002s	user 0.002s	sys 0.000s
I20260812 06:16:41.930195 20795 heartbeater.cc:499] Master 127.19.172.190:40833 was elected leader, sending a full tablet report...
I20260812 06:16:41.930209 20822 raft_consensus.cc:697] T b9cbe9188ec6434c87f5997054949fb1 P c73d258340b34264837fab21878bc358 [term 1 LEADER]: Becoming Leader. State: Replica: c73d258340b34264837fab21878bc358, State: Running, Role: LEADER
I20260812 06:16:41.930408 20822 consensus_queue.cc:237] T b9cbe9188ec6434c87f5997054949fb1 P c73d258340b34264837fab21878bc358 [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: "c73d258340b34264837fab21878bc358" member_type: VOTER last_known_addr { host: "127.19.172.129" port: 38513 } }
I20260812 06:16:41.931545 20545 catalog_manager.cc:5719] T b9cbe9188ec6434c87f5997054949fb1 P c73d258340b34264837fab21878bc358 reported cstate change: term changed from 0 to 1, leader changed from <none> to c73d258340b34264837fab21878bc358 (127.19.172.129). New cstate: current_term: 1 leader_uuid: "c73d258340b34264837fab21878bc358" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "c73d258340b34264837fab21878bc358" member_type: VOTER last_known_addr { host: "127.19.172.129" port: 38513 } health_report { overall_health: HEALTHY } } }
I20260812 06:16:41.987969 20146 heavy-update-compaction-itest.cc:215] Time spent inserting: real 0.053s	user 0.010s	sys 0.012s
I20260812 06:16:42.151895 20796 maintenance_manager.cc:419] P c73d258340b34264837fab21878bc358: Scheduling FlushMRSOp(b9cbe9188ec6434c87f5997054949fb1): perf score=23.023690
I20260812 06:16:42.376960 20691 maintenance_manager.cc:643] P c73d258340b34264837fab21878bc358: FlushMRSOp(b9cbe9188ec6434c87f5997054949fb1) complete. Timing: real 0.225s	user 0.100s	sys 0.060s Metrics: {"bytes_written":12307490,"cfile_init":1,"delete_count":0,"dirs.queue_time_us":52,"dirs.run_cpu_time_us":202,"dirs.run_wall_time_us":57043,"drs_written":1,"lbm_read_time_us":49,"lbm_reads_lt_1ms":4,"lbm_write_time_us":42381,"lbm_writes_lt_1ms":857,"peak_mem_usage":0,"reinsert_count":0,"rows_written":105,"update_count":1500}
I20260812 06:16:42.377600 20796 maintenance_manager.cc:419] P c73d258340b34264837fab21878bc358: Scheduling LogGCOp(b9cbe9188ec6434c87f5997054949fb1): free 20743880 bytes of WAL
I20260812 06:16:42.377825 20691 log_reader.cc:385] T b9cbe9188ec6434c87f5997054949fb1: removed 2 log segments from log reader
I20260812 06:16:42.377883 20691 log.cc:1079] T b9cbe9188ec6434c87f5997054949fb1 P c73d258340b34264837fab21878bc358: Deleting log segment in path: /tmp/dist-test-taskDoCWee/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515396661473-20146-0/minicluster-data/ts-0-root/wals/b9cbe9188ec6434c87f5997054949fb1/wal-000000001 (ops 1-6)
I20260812 06:16:42.377959 20691 log.cc:1079] T b9cbe9188ec6434c87f5997054949fb1 P c73d258340b34264837fab21878bc358: Deleting log segment in path: /tmp/dist-test-taskDoCWee/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515396661473-20146-0/minicluster-data/ts-0-root/wals/b9cbe9188ec6434c87f5997054949fb1/wal-000000002 (ops 7-11)
I20260812 06:16:42.382090 20691 maintenance_manager.cc:643] P c73d258340b34264837fab21878bc358: LogGCOp(b9cbe9188ec6434c87f5997054949fb1) complete. Timing: real 0.004s	user 0.000s	sys 0.004s Metrics: {}
I20260812 06:16:42.382501 20796 maintenance_manager.cc:419] P c73d258340b34264837fab21878bc358: Scheduling FlushDeltaMemStoresOp(b9cbe9188ec6434c87f5997054949fb1): perf score=10.126437
I20260812 06:16:42.467486 20691 maintenance_manager.cc:643] P c73d258340b34264837fab21878bc358: FlushDeltaMemStoresOp(b9cbe9188ec6434c87f5997054949fb1) complete. Timing: real 0.085s	user 0.022s	sys 0.011s Metrics: {"bytes_written":12307489,"delete_count":0,"lbm_write_time_us":14804,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:16:42.467926 20796 maintenance_manager.cc:419] P c73d258340b34264837fab21878bc358: Scheduling FlushDeltaMemStoresOp(b9cbe9188ec6434c87f5997054949fb1): perf score=6.157687
I20260812 06:16:42.568636 20691 maintenance_manager.cc:643] P c73d258340b34264837fab21878bc358: FlushDeltaMemStoresOp(b9cbe9188ec6434c87f5997054949fb1) complete. Timing: real 0.101s	user 0.023s	sys 0.003s Metrics: {"bytes_written":8205078,"delete_count":0,"lbm_write_time_us":11840,"lbm_writes_lt_1ms":203,"reinsert_count":0,"update_count":1000}
I20260812 06:16:42.569375 20796 maintenance_manager.cc:419] P c73d258340b34264837fab21878bc358: Scheduling UndoDeltaBlockGCOp(b9cbe9188ec6434c87f5997054949fb1): 20513813 bytes on disk
I20260812 06:16:42.570118 20691 maintenance_manager.cc:643] P c73d258340b34264837fab21878bc358: UndoDeltaBlockGCOp(b9cbe9188ec6434c87f5997054949fb1) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":140,"lbm_reads_lt_1ms":4}
I20260812 06:16:42.570729 20796 maintenance_manager.cc:419] P c73d258340b34264837fab21878bc358: Scheduling FlushDeltaMemStoresOp(b9cbe9188ec6434c87f5997054949fb1): perf score=6.157687
I20260812 06:16:42.677197 20691 maintenance_manager.cc:643] P c73d258340b34264837fab21878bc358: FlushDeltaMemStoresOp(b9cbe9188ec6434c87f5997054949fb1) complete. Timing: real 0.106s	user 0.021s	sys 0.009s Metrics: {"bytes_written":8205078,"delete_count":0,"lbm_write_time_us":11032,"lbm_writes_lt_1ms":203,"reinsert_count":0,"spinlock_wait_cycles":1920,"update_count":1000}
I20260812 06:16:42.677861 20796 maintenance_manager.cc:419] P c73d258340b34264837fab21878bc358: Scheduling FlushDeltaMemStoresOp(b9cbe9188ec6434c87f5997054949fb1): perf score=8.142062
I20260812 06:16:42.776389 20691 maintenance_manager.cc:643] P c73d258340b34264837fab21878bc358: FlushDeltaMemStoresOp(b9cbe9188ec6434c87f5997054949fb1) complete. Timing: real 0.098s	user 0.019s	sys 0.005s Metrics: {"bytes_written":9476828,"delete_count":0,"lbm_write_time_us":10743,"lbm_writes_lt_1ms":234,"reinsert_count":0,"update_count":1155}
I20260812 06:16:42.777017 20796 maintenance_manager.cc:419] P c73d258340b34264837fab21878bc358: Scheduling FlushDeltaMemStoresOp(b9cbe9188ec6434c87f5997054949fb1): perf score=7.149875
I20260812 06:16:42.877107 20691 maintenance_manager.cc:643] P c73d258340b34264837fab21878bc358: FlushDeltaMemStoresOp(b9cbe9188ec6434c87f5997054949fb1) complete. Timing: real 0.100s	user 0.009s	sys 0.012s Metrics: {"bytes_written":9312738,"delete_count":0,"lbm_write_time_us":9169,"lbm_writes_lt_1ms":230,"reinsert_count":0,"update_count":1135}
I20260812 06:16:42.877851 20796 maintenance_manager.cc:419] P c73d258340b34264837fab21878bc358: Scheduling FlushDeltaMemStoresOp(b9cbe9188ec6434c87f5997054949fb1): perf score=8.142062
I20260812 06:16:42.981140 20691 maintenance_manager.cc:643] P c73d258340b34264837fab21878bc358: FlushDeltaMemStoresOp(b9cbe9188ec6434c87f5997054949fb1) complete. Timing: real 0.103s	user 0.022s	sys 0.001s Metrics: {"bytes_written":9928097,"delete_count":0,"lbm_write_time_us":10136,"lbm_writes_lt_1ms":245,"reinsert_count":0,"update_count":1210}
I20260812 06:16:42.981801 20796 maintenance_manager.cc:419] P c73d258340b34264837fab21878bc358: Scheduling FlushDeltaMemStoresOp(b9cbe9188ec6434c87f5997054949fb1): perf score=10.126437
I20260812 06:16:43.086018 20691 maintenance_manager.cc:643] P c73d258340b34264837fab21878bc358: FlushDeltaMemStoresOp(b9cbe9188ec6434c87f5997054949fb1) complete. Timing: real 0.104s	user 0.017s	sys 0.013s Metrics: {"bytes_written":11979298,"delete_count":0,"lbm_write_time_us":12564,"lbm_writes_lt_1ms":295,"reinsert_count":0,"update_count":1460}
I20260812 06:16:43.086514 20796 maintenance_manager.cc:419] P c73d258340b34264837fab21878bc358: Scheduling FlushDeltaMemStoresOp(b9cbe9188ec6434c87f5997054949fb1): perf score=7.149875
I20260812 06:16:43.186370 20691 maintenance_manager.cc:643] P c73d258340b34264837fab21878bc358: FlushDeltaMemStoresOp(b9cbe9188ec6434c87f5997054949fb1) complete. Timing: real 0.100s	user 0.007s	sys 0.013s Metrics: {"bytes_written":8943517,"delete_count":0,"lbm_write_time_us":8262,"lbm_writes_lt_1ms":221,"reinsert_count":0,"update_count":1090}
I20260812 06:16:43.186913 20796 maintenance_manager.cc:419] P c73d258340b34264837fab21878bc358: Scheduling FlushDeltaMemStoresOp(b9cbe9188ec6434c87f5997054949fb1): perf score=10.126437
I20260812 06:16:43.289309 20691 maintenance_manager.cc:643] P c73d258340b34264837fab21878bc358: FlushDeltaMemStoresOp(b9cbe9188ec6434c87f5997054949fb1) complete. Timing: real 0.102s	user 0.019s	sys 0.009s Metrics: {"bytes_written":11897249,"delete_count":0,"lbm_write_time_us":12109,"lbm_writes_lt_1ms":293,"reinsert_count":0,"update_count":1450}
I20260812 06:16:43.289795 20796 maintenance_manager.cc:419] P c73d258340b34264837fab21878bc358: Scheduling FlushDeltaMemStoresOp(b9cbe9188ec6434c87f5997054949fb1): perf score=6.157687
I20260812 06:16:43.391148 20691 maintenance_manager.cc:643] P c73d258340b34264837fab21878bc358: FlushDeltaMemStoresOp(b9cbe9188ec6434c87f5997054949fb1) complete. Timing: real 0.101s	user 0.012s	sys 0.009s Metrics: {"bytes_written":8205078,"delete_count":0,"lbm_write_time_us":8483,"lbm_writes_lt_1ms":203,"reinsert_count":0,"update_count":1000}
I20260812 06:16:43.391889 20796 maintenance_manager.cc:419] P c73d258340b34264837fab21878bc358: Scheduling FlushDeltaMemStoresOp(b9cbe9188ec6434c87f5997054949fb1): perf score=9.134250
I20260812 06:16:43.494059 20691 maintenance_manager.cc:643] P c73d258340b34264837fab21878bc358: FlushDeltaMemStoresOp(b9cbe9188ec6434c87f5997054949fb1) complete. Timing: real 0.102s	user 0.017s	sys 0.015s Metrics: {"bytes_written":10543454,"delete_count":0,"lbm_write_time_us":14058,"lbm_writes_lt_1ms":260,"reinsert_count":0,"update_count":1285}
I20260812 06:16:43.494716 20796 maintenance_manager.cc:419] P c73d258340b34264837fab21878bc358: Scheduling FlushDeltaMemStoresOp(b9cbe9188ec6434c87f5997054949fb1): perf score=8.142062
I20260812 06:16:43.596740 20691 maintenance_manager.cc:643] P c73d258340b34264837fab21878bc358: FlushDeltaMemStoresOp(b9cbe9188ec6434c87f5997054949fb1) complete. Timing: real 0.102s	user 0.010s	sys 0.014s Metrics: {"bytes_written":9969125,"delete_count":0,"lbm_write_time_us":10281,"lbm_writes_lt_1ms":246,"reinsert_count":0,"update_count":1215}
I20260812 06:16:43.597254 20796 maintenance_manager.cc:419] P c73d258340b34264837fab21878bc358: Scheduling FlushDeltaMemStoresOp(b9cbe9188ec6434c87f5997054949fb1): perf score=8.142062
I20260812 06:16:43.699225 20691 maintenance_manager.cc:643] P c73d258340b34264837fab21878bc358: FlushDeltaMemStoresOp(b9cbe9188ec6434c87f5997054949fb1) complete. Timing: real 0.102s	user 0.024s	sys 0.004s Metrics: {"bytes_written":10338332,"delete_count":0,"lbm_write_time_us":11911,"lbm_writes_lt_1ms":255,"reinsert_count":0,"update_count":1260}
I20260812 06:16:43.699738 20796 maintenance_manager.cc:419] P c73d258340b34264837fab21878bc358: Scheduling FlushDeltaMemStoresOp(b9cbe9188ec6434c87f5997054949fb1): perf score=8.142062
I20260812 06:16:43.801250 20691 maintenance_manager.cc:643] P c73d258340b34264837fab21878bc358: FlushDeltaMemStoresOp(b9cbe9188ec6434c87f5997054949fb1) complete. Timing: real 0.101s	user 0.003s	sys 0.024s Metrics: {"bytes_written":10174244,"delete_count":0,"lbm_write_time_us":12098,"lbm_writes_lt_1ms":251,"reinsert_count":0,"update_count":1240}
I20260812 06:16:43.801826 20796 maintenance_manager.cc:419] P c73d258340b34264837fab21878bc358: Scheduling FlushDeltaMemStoresOp(b9cbe9188ec6434c87f5997054949fb1): perf score=7.149875
I20260812 06:16:43.902999 20691 maintenance_manager.cc:643] P c73d258340b34264837fab21878bc358: FlushDeltaMemStoresOp(b9cbe9188ec6434c87f5997054949fb1) complete. Timing: real 0.101s	user 0.011s	sys 0.013s Metrics: {"bytes_written":8615322,"delete_count":0,"lbm_write_time_us":10092,"lbm_writes_lt_1ms":213,"reinsert_count":0,"update_count":1050}
I20260812 06:16:43.903509 20796 maintenance_manager.cc:419] P c73d258340b34264837fab21878bc358: Scheduling FlushDeltaMemStoresOp(b9cbe9188ec6434c87f5997054949fb1): perf score=10.126437
I20260812 06:16:44.009476 20691 maintenance_manager.cc:643] P c73d258340b34264837fab21878bc358: FlushDeltaMemStoresOp(b9cbe9188ec6434c87f5997054949fb1) complete. Timing: real 0.106s	user 0.026s	sys 0.003s Metrics: {"bytes_written":11897250,"delete_count":0,"lbm_write_time_us":12849,"lbm_writes_lt_1ms":293,"reinsert_count":0,"update_count":1450}
I20260812 06:16:44.010145 20796 maintenance_manager.cc:419] P c73d258340b34264837fab21878bc358: Scheduling FlushDeltaMemStoresOp(b9cbe9188ec6434c87f5997054949fb1): perf score=9.134250
I20260812 06:16:44.111992 20691 maintenance_manager.cc:643] P c73d258340b34264837fab21878bc358: FlushDeltaMemStoresOp(b9cbe9188ec6434c87f5997054949fb1) complete. Timing: real 0.102s	user 0.026s	sys 0.006s Metrics: {"bytes_written":11404959,"delete_count":0,"lbm_write_time_us":14943,"lbm_writes_lt_1ms":281,"reinsert_count":0,"update_count":1390}
I20260812 06:16:44.112480 20796 maintenance_manager.cc:419] P c73d258340b34264837fab21878bc358: Scheduling FlushDeltaMemStoresOp(b9cbe9188ec6434c87f5997054949fb1): perf score=7.149875
I20260812 06:16:44.210430 20691 maintenance_manager.cc:643] P c73d258340b34264837fab21878bc358: FlushDeltaMemStoresOp(b9cbe9188ec6434c87f5997054949fb1) complete. Timing: real 0.098s	user 0.010s	sys 0.014s Metrics: {"bytes_written":9107611,"delete_count":0,"lbm_write_time_us":10582,"lbm_writes_lt_1ms":225,"reinsert_count":0,"update_count":1110}
I20260812 06:16:44.212587 20796 maintenance_manager.cc:419] P c73d258340b34264837fab21878bc358: Scheduling FlushDeltaMemStoresOp(b9cbe9188ec6434c87f5997054949fb1): perf score=7.149875
I20260812 06:16:44.313410 20691 maintenance_manager.cc:643] P c73d258340b34264837fab21878bc358: FlushDeltaMemStoresOp(b9cbe9188ec6434c87f5997054949fb1) complete. Timing: real 0.101s	user 0.003s	sys 0.015s Metrics: {"bytes_written":8615323,"delete_count":0,"lbm_write_time_us":8443,"lbm_writes_lt_1ms":213,"reinsert_count":0,"update_count":1050}
I20260812 06:16:44.314054 20796 maintenance_manager.cc:419] P c73d258340b34264837fab21878bc358: Scheduling FlushDeltaMemStoresOp(b9cbe9188ec6434c87f5997054949fb1): perf score=10.126437
I20260812 06:16:44.413822 20691 maintenance_manager.cc:643] P c73d258340b34264837fab21878bc358: FlushDeltaMemStoresOp(b9cbe9188ec6434c87f5997054949fb1) complete. Timing: real 0.100s	user 0.030s	sys 0.005s Metrics: {"bytes_written":11897249,"delete_count":0,"lbm_write_time_us":15285,"lbm_writes_lt_1ms":293,"reinsert_count":0,"update_count":1450}
I20260812 06:16:44.414546 20796 maintenance_manager.cc:419] P c73d258340b34264837fab21878bc358: Scheduling FlushDeltaMemStoresOp(b9cbe9188ec6434c87f5997054949fb1): perf score=6.157687
I20260812 06:16:44.516283 20691 maintenance_manager.cc:643] P c73d258340b34264837fab21878bc358: FlushDeltaMemStoresOp(b9cbe9188ec6434c87f5997054949fb1) complete. Timing: real 0.101s	user 0.007s	sys 0.012s Metrics: {"bytes_written":8205080,"delete_count":0,"lbm_write_time_us":8658,"lbm_writes_lt_1ms":203,"reinsert_count":0,"update_count":1000}
I20260812 06:16:44.516877 20796 maintenance_manager.cc:419] P c73d258340b34264837fab21878bc358: Scheduling FlushDeltaMemStoresOp(b9cbe9188ec6434c87f5997054949fb1): perf score=8.142062
I20260812 06:16:44.619735 20691 maintenance_manager.cc:643] P c73d258340b34264837fab21878bc358: FlushDeltaMemStoresOp(b9cbe9188ec6434c87f5997054949fb1) complete. Timing: real 0.103s	user 0.011s	sys 0.009s Metrics: {"bytes_written":9681945,"delete_count":0,"lbm_write_time_us":8641,"lbm_writes_lt_1ms":239,"reinsert_count":0,"update_count":1180}
I20260812 06:16:44.620362 20796 maintenance_manager.cc:419] P c73d258340b34264837fab21878bc358: Scheduling FlushDeltaMemStoresOp(b9cbe9188ec6434c87f5997054949fb1): perf score=9.134250
I20260812 06:16:44.720229 20691 maintenance_manager.cc:643] P c73d258340b34264837fab21878bc358: FlushDeltaMemStoresOp(b9cbe9188ec6434c87f5997054949fb1) complete. Timing: real 0.100s	user 0.016s	sys 0.009s Metrics: {"bytes_written":10830631,"delete_count":0,"lbm_write_time_us":11850,"lbm_writes_lt_1ms":267,"reinsert_count":0,"update_count":1320}
I20260812 06:16:44.720779 20796 maintenance_manager.cc:419] P c73d258340b34264837fab21878bc358: Scheduling FlushDeltaMemStoresOp(b9cbe9188ec6434c87f5997054949fb1): perf score=7.149875
I20260812 06:16:44.740777 20691 maintenance_manager.cc:643] P c73d258340b34264837fab21878bc358: FlushDeltaMemStoresOp(b9cbe9188ec6434c87f5997054949fb1) complete. Timing: real 0.020s	user 0.002s	sys 0.015s Metrics: {"bytes_written":9271708,"delete_count":0,"lbm_write_time_us":8388,"lbm_writes_lt_1ms":229,"reinsert_count":0,"update_count":1130}
I20260812 06:16:44.741533 20796 maintenance_manager.cc:419] P c73d258340b34264837fab21878bc358: Scheduling FlushDeltaMemStoresOp(b9cbe9188ec6434c87f5997054949fb1): perf score=1.196750
I20260812 06:16:44.756390 20691 maintenance_manager.cc:643] P c73d258340b34264837fab21878bc358: FlushDeltaMemStoresOp(b9cbe9188ec6434c87f5997054949fb1) complete. Timing: real 0.015s	user 0.009s	sys 0.000s Metrics: {"bytes_written":3036005,"delete_count":0,"lbm_write_time_us":4798,"lbm_writes_lt_1ms":77,"reinsert_count":0,"update_count":370}
I20260812 06:16:44.756937 20796 maintenance_manager.cc:419] P c73d258340b34264837fab21878bc358: Scheduling FlushMRSOp(b9cbe9188ec6434c87f5997054949fb1): perf score=1.195565
I20260812 06:16:44.809505 20691 maintenance_manager.cc:643] P c73d258340b34264837fab21878bc358: FlushMRSOp(b9cbe9188ec6434c87f5997054949fb1) complete. Timing: real 0.052s	user 0.026s	sys 0.009s Metrics: {"bytes_written":2586837,"cfile_init":1,"dirs.queue_time_us":207,"dirs.run_cpu_time_us":238,"dirs.run_wall_time_us":1085,"drs_written":1,"lbm_read_time_us":38,"lbm_reads_lt_1ms":4,"lbm_write_time_us":3309,"lbm_writes_lt_1ms":44,"peak_mem_usage":0,"rows_written":63,"thread_start_us":96,"threads_started":1}
I20260812 06:16:44.810240 20796 maintenance_manager.cc:419] P c73d258340b34264837fab21878bc358: Scheduling LogGCOp(b9cbe9188ec6434c87f5997054949fb1): free 257734749 bytes of WAL
I20260812 06:16:44.810491 20691 log_reader.cc:385] T b9cbe9188ec6434c87f5997054949fb1: removed 25 log segments from log reader
I20260812 06:16:44.810542 20691 log.cc:1079] T b9cbe9188ec6434c87f5997054949fb1 P c73d258340b34264837fab21878bc358: Deleting log segment in path: /tmp/dist-test-taskDoCWee/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515396661473-20146-0/minicluster-data/ts-0-root/wals/b9cbe9188ec6434c87f5997054949fb1/wal-000000003 (ops 12-16)
I20260812 06:16:44.810580 20691 log.cc:1079] T b9cbe9188ec6434c87f5997054949fb1 P c73d258340b34264837fab21878bc358: Deleting log segment in path: /tmp/dist-test-taskDoCWee/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515396661473-20146-0/minicluster-data/ts-0-root/wals/b9cbe9188ec6434c87f5997054949fb1/wal-000000004 (ops 17-20)
I20260812 06:16:44.810611 20691 log.cc:1079] T b9cbe9188ec6434c87f5997054949fb1 P c73d258340b34264837fab21878bc358: Deleting log segment in path: /tmp/dist-test-taskDoCWee/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515396661473-20146-0/minicluster-data/ts-0-root/wals/b9cbe9188ec6434c87f5997054949fb1/wal-000000005 (ops 21-25)
I20260812 06:16:44.810633 20691 log.cc:1079] T b9cbe9188ec6434c87f5997054949fb1 P c73d258340b34264837fab21878bc358: Deleting log segment in path: /tmp/dist-test-taskDoCWee/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515396661473-20146-0/minicluster-data/ts-0-root/wals/b9cbe9188ec6434c87f5997054949fb1/wal-000000006 (ops 26-30)
I20260812 06:16:44.810664 20691 log.cc:1079] T b9cbe9188ec6434c87f5997054949fb1 P c73d258340b34264837fab21878bc358: Deleting log segment in path: /tmp/dist-test-taskDoCWee/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515396661473-20146-0/minicluster-data/ts-0-root/wals/b9cbe9188ec6434c87f5997054949fb1/wal-000000007 (ops 31-35)
I20260812 06:16:44.810695 20691 log.cc:1079] T b9cbe9188ec6434c87f5997054949fb1 P c73d258340b34264837fab21878bc358: Deleting log segment in path: /tmp/dist-test-taskDoCWee/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515396661473-20146-0/minicluster-data/ts-0-root/wals/b9cbe9188ec6434c87f5997054949fb1/wal-000000008 (ops 36-40)
I20260812 06:16:44.810725 20691 log.cc:1079] T b9cbe9188ec6434c87f5997054949fb1 P c73d258340b34264837fab21878bc358: Deleting log segment in path: /tmp/dist-test-taskDoCWee/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515396661473-20146-0/minicluster-data/ts-0-root/wals/b9cbe9188ec6434c87f5997054949fb1/wal-000000009 (ops 41-45)
I20260812 06:16:44.810755 20691 log.cc:1079] T b9cbe9188ec6434c87f5997054949fb1 P c73d258340b34264837fab21878bc358: Deleting log segment in path: /tmp/dist-test-taskDoCWee/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515396661473-20146-0/minicluster-data/ts-0-root/wals/b9cbe9188ec6434c87f5997054949fb1/wal-000000010 (ops 46-50)
I20260812 06:16:44.810784 20691 log.cc:1079] T b9cbe9188ec6434c87f5997054949fb1 P c73d258340b34264837fab21878bc358: Deleting log segment in path: /tmp/dist-test-taskDoCWee/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515396661473-20146-0/minicluster-data/ts-0-root/wals/b9cbe9188ec6434c87f5997054949fb1/wal-000000011 (ops 51-55)
I20260812 06:16:44.810812 20691 log.cc:1079] T b9cbe9188ec6434c87f5997054949fb1 P c73d258340b34264837fab21878bc358: Deleting log segment in path: /tmp/dist-test-taskDoCWee/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515396661473-20146-0/minicluster-data/ts-0-root/wals/b9cbe9188ec6434c87f5997054949fb1/wal-000000012 (ops 56-60)
I20260812 06:16:44.810842 20691 log.cc:1079] T b9cbe9188ec6434c87f5997054949fb1 P c73d258340b34264837fab21878bc358: Deleting log segment in path: /tmp/dist-test-taskDoCWee/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515396661473-20146-0/minicluster-data/ts-0-root/wals/b9cbe9188ec6434c87f5997054949fb1/wal-000000013 (ops 61-65)
I20260812 06:16:44.810871 20691 log.cc:1079] T b9cbe9188ec6434c87f5997054949fb1 P c73d258340b34264837fab21878bc358: Deleting log segment in path: /tmp/dist-test-taskDoCWee/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515396661473-20146-0/minicluster-data/ts-0-root/wals/b9cbe9188ec6434c87f5997054949fb1/wal-000000014 (ops 66-70)
I20260812 06:16:44.810900 20691 log.cc:1079] T b9cbe9188ec6434c87f5997054949fb1 P c73d258340b34264837fab21878bc358: Deleting log segment in path: /tmp/dist-test-taskDoCWee/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515396661473-20146-0/minicluster-data/ts-0-root/wals/b9cbe9188ec6434c87f5997054949fb1/wal-000000015 (ops 71-75)
I20260812 06:16:44.810930 20691 log.cc:1079] T b9cbe9188ec6434c87f5997054949fb1 P c73d258340b34264837fab21878bc358: Deleting log segment in path: /tmp/dist-test-taskDoCWee/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515396661473-20146-0/minicluster-data/ts-0-root/wals/b9cbe9188ec6434c87f5997054949fb1/wal-000000016 (ops 76-80)
I20260812 06:16:44.810958 20691 log.cc:1079] T b9cbe9188ec6434c87f5997054949fb1 P c73d258340b34264837fab21878bc358: Deleting log segment in path: /tmp/dist-test-taskDoCWee/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515396661473-20146-0/minicluster-data/ts-0-root/wals/b9cbe9188ec6434c87f5997054949fb1/wal-000000017 (ops 81-85)
I20260812 06:16:44.810987 20691 log.cc:1079] T b9cbe9188ec6434c87f5997054949fb1 P c73d258340b34264837fab21878bc358: Deleting log segment in path: /tmp/dist-test-taskDoCWee/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515396661473-20146-0/minicluster-data/ts-0-root/wals/b9cbe9188ec6434c87f5997054949fb1/wal-000000018 (ops 86-90)
I20260812 06:16:44.811025 20691 log.cc:1079] T b9cbe9188ec6434c87f5997054949fb1 P c73d258340b34264837fab21878bc358: Deleting log segment in path: /tmp/dist-test-taskDoCWee/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515396661473-20146-0/minicluster-data/ts-0-root/wals/b9cbe9188ec6434c87f5997054949fb1/wal-000000019 (ops 91-95)
I20260812 06:16:44.811054 20691 log.cc:1079] T b9cbe9188ec6434c87f5997054949fb1 P c73d258340b34264837fab21878bc358: Deleting log segment in path: /tmp/dist-test-taskDoCWee/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515396661473-20146-0/minicluster-data/ts-0-root/wals/b9cbe9188ec6434c87f5997054949fb1/wal-000000020 (ops 96-100)
I20260812 06:16:44.811084 20691 log.cc:1079] T b9cbe9188ec6434c87f5997054949fb1 P c73d258340b34264837fab21878bc358: Deleting log segment in path: /tmp/dist-test-taskDoCWee/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515396661473-20146-0/minicluster-data/ts-0-root/wals/b9cbe9188ec6434c87f5997054949fb1/wal-000000021 (ops 101-105)
I20260812 06:16:44.811112 20691 log.cc:1079] T b9cbe9188ec6434c87f5997054949fb1 P c73d258340b34264837fab21878bc358: Deleting log segment in path: /tmp/dist-test-taskDoCWee/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515396661473-20146-0/minicluster-data/ts-0-root/wals/b9cbe9188ec6434c87f5997054949fb1/wal-000000022 (ops 106-110)
I20260812 06:16:44.811141 20691 log.cc:1079] T b9cbe9188ec6434c87f5997054949fb1 P c73d258340b34264837fab21878bc358: Deleting log segment in path: /tmp/dist-test-taskDoCWee/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515396661473-20146-0/minicluster-data/ts-0-root/wals/b9cbe9188ec6434c87f5997054949fb1/wal-000000023 (ops 111-115)
I20260812 06:16:44.811170 20691 log.cc:1079] T b9cbe9188ec6434c87f5997054949fb1 P c73d258340b34264837fab21878bc358: Deleting log segment in path: /tmp/dist-test-taskDoCWee/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515396661473-20146-0/minicluster-data/ts-0-root/wals/b9cbe9188ec6434c87f5997054949fb1/wal-000000024 (ops 116-120)
I20260812 06:16:44.811199 20691 log.cc:1079] T b9cbe9188ec6434c87f5997054949fb1 P c73d258340b34264837fab21878bc358: Deleting log segment in path: /tmp/dist-test-taskDoCWee/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515396661473-20146-0/minicluster-data/ts-0-root/wals/b9cbe9188ec6434c87f5997054949fb1/wal-000000025 (ops 121-125)
I20260812 06:16:44.811228 20691 log.cc:1079] T b9cbe9188ec6434c87f5997054949fb1 P c73d258340b34264837fab21878bc358: Deleting log segment in path: /tmp/dist-test-taskDoCWee/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515396661473-20146-0/minicluster-data/ts-0-root/wals/b9cbe9188ec6434c87f5997054949fb1/wal-000000026 (ops 126-130)
I20260812 06:16:44.811257 20691 log.cc:1079] T b9cbe9188ec6434c87f5997054949fb1 P c73d258340b34264837fab21878bc358: Deleting log segment in path: /tmp/dist-test-taskDoCWee/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515396661473-20146-0/minicluster-data/ts-0-root/wals/b9cbe9188ec6434c87f5997054949fb1/wal-000000027 (ops 131-135)
I20260812 06:16:44.857815 20691 maintenance_manager.cc:643] P c73d258340b34264837fab21878bc358: LogGCOp(b9cbe9188ec6434c87f5997054949fb1) complete. Timing: real 0.047s	user 0.000s	sys 0.044s Metrics: {}
I20260812 06:16:44.858260 20796 maintenance_manager.cc:419] P c73d258340b34264837fab21878bc358: Scheduling FlushDeltaMemStoresOp(b9cbe9188ec6434c87f5997054949fb1): perf score=10.126437
I20260812 06:16:44.897687 20691 maintenance_manager.cc:643] P c73d258340b34264837fab21878bc358: FlushDeltaMemStoresOp(b9cbe9188ec6434c87f5997054949fb1) complete. Timing: real 0.039s	user 0.009s	sys 0.021s Metrics: {"bytes_written":12307491,"delete_count":0,"lbm_write_time_us":14187,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:16:44.898167 20796 maintenance_manager.cc:419] P c73d258340b34264837fab21878bc358: Scheduling LogGCOp(b9cbe9188ec6434c87f5997054949fb1): free 12017962 bytes of WAL
I20260812 06:16:44.898375 20691 log_reader.cc:385] T b9cbe9188ec6434c87f5997054949fb1: removed 1 log segments from log reader
I20260812 06:16:44.898422 20691 log.cc:1079] T b9cbe9188ec6434c87f5997054949fb1 P c73d258340b34264837fab21878bc358: Deleting log segment in path: /tmp/dist-test-taskDoCWee/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515396661473-20146-0/minicluster-data/ts-0-root/wals/b9cbe9188ec6434c87f5997054949fb1/wal-000000028 (ops 136-140)
I20260812 06:16:44.900203 20691 maintenance_manager.cc:643] P c73d258340b34264837fab21878bc358: LogGCOp(b9cbe9188ec6434c87f5997054949fb1) complete. Timing: real 0.002s	user 0.000s	sys 0.000s Metrics: {}
I20260812 06:16:44.900518 20796 maintenance_manager.cc:419] P c73d258340b34264837fab21878bc358: Scheduling UndoDeltaBlockGCOp(b9cbe9188ec6434c87f5997054949fb1): 843 bytes on disk
I20260812 06:16:44.900898 20691 maintenance_manager.cc:643] P c73d258340b34264837fab21878bc358: UndoDeltaBlockGCOp(b9cbe9188ec6434c87f5997054949fb1) 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:16:44.901361 20796 maintenance_manager.cc:419] P c73d258340b34264837fab21878bc358: Scheduling FlushDeltaMemStoresOp(b9cbe9188ec6434c87f5997054949fb1): perf score=2.188937
I20260812 06:16:44.912425 20691 maintenance_manager.cc:643] P c73d258340b34264837fab21878bc358: FlushDeltaMemStoresOp(b9cbe9188ec6434c87f5997054949fb1) complete. Timing: real 0.011s	user 0.010s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4045,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:44.912881 20796 maintenance_manager.cc:419] P c73d258340b34264837fab21878bc358: Scheduling MajorDeltaCompactionOp(b9cbe9188ec6434c87f5997054949fb1): perf score=1.000000
I20260812 06:16:46.584604 20146 heavy-update-compaction-itest.cc:229] Time spent updating: real 4.597s	user 1.597s	sys 0.116s
I20260812 06:16:46.664469 20691 maintenance_manager.cc:643] P c73d258340b34264837fab21878bc358: MajorDeltaCompactionOp(b9cbe9188ec6434c87f5997054949fb1) complete. Timing: real 1.751s	user 0.992s	sys 0.755s Metrics: {"cfile_cache_miss":6658,"cfile_cache_miss_bytes":275065973,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":28,"delta_iterators_relevant":28,"lbm_read_time_us":108614,"lbm_reads_lt_1ms":6694,"lbm_write_time_us":362493,"lbm_writes_lt_1ms":6648,"peak_mem_usage":821136792,"reinsert_count":0,"spinlock_wait_cycles":30464,"update_count":33000}
I20260812 06:16:46.665210 20796 maintenance_manager.cc:419] P c73d258340b34264837fab21878bc358: Scheduling FlushDeltaMemStoresOp(b9cbe9188ec6434c87f5997054949fb1): perf score=113.313937
I20260812 06:16:46.876441 20691 maintenance_manager.cc:643] P c73d258340b34264837fab21878bc358: FlushDeltaMemStoresOp(b9cbe9188ec6434c87f5997054949fb1) complete. Timing: real 0.211s	user 0.119s	sys 0.091s Metrics: {"bytes_written":118970352,"delete_count":0,"lbm_write_time_us":105119,"lbm_writes_lt_1ms":2905,"reinsert_count":0,"spinlock_wait_cycles":12288,"update_count":14500}
I20260812 06:16:46.877094 20796 maintenance_manager.cc:419] P c73d258340b34264837fab21878bc358: Scheduling FlushMRSOp(b9cbe9188ec6434c87f5997054949fb1): perf score=1.000000
I20260812 06:16:46.903962 20691 maintenance_manager.cc:643] P c73d258340b34264837fab21878bc358: FlushMRSOp(b9cbe9188ec6434c87f5997054949fb1) complete. Timing: real 0.027s	user 0.025s	sys 0.000s Metrics: {"bytes_written":1316415,"cfile_init":1,"dirs.queue_time_us":196,"dirs.run_cpu_time_us":167,"dirs.run_wall_time_us":718,"drs_written":1,"lbm_read_time_us":44,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1429,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":32,"thread_start_us":84,"threads_started":1}
I20260812 06:16:46.904557 20796 maintenance_manager.cc:419] P c73d258340b34264837fab21878bc358: Scheduling LogGCOp(b9cbe9188ec6434c87f5997054949fb1): free 8767140 bytes of WAL
I20260812 06:16:46.904758 20691 log_reader.cc:385] T b9cbe9188ec6434c87f5997054949fb1: removed 1 log segments from log reader
I20260812 06:16:46.904803 20691 log.cc:1079] T b9cbe9188ec6434c87f5997054949fb1 P c73d258340b34264837fab21878bc358: Deleting log segment in path: /tmp/dist-test-taskDoCWee/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515396661473-20146-0/minicluster-data/ts-0-root/wals/b9cbe9188ec6434c87f5997054949fb1/wal-000000029 (ops 141-145)
I20260812 06:16:46.906457 20691 maintenance_manager.cc:643] P c73d258340b34264837fab21878bc358: LogGCOp(b9cbe9188ec6434c87f5997054949fb1) complete. Timing: real 0.002s	user 0.000s	sys 0.001s Metrics: {}
I20260812 06:16:46.906735 20796 maintenance_manager.cc:419] P c73d258340b34264837fab21878bc358: Scheduling UndoDeltaBlockGCOp(b9cbe9188ec6434c87f5997054949fb1): 493 bytes on disk
I20260812 06:16:46.907150 20691 maintenance_manager.cc:643] P c73d258340b34264837fab21878bc358: UndoDeltaBlockGCOp(b9cbe9188ec6434c87f5997054949fb1) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":53,"lbm_reads_lt_1ms":4}
I20260812 06:16:46.907615 20796 maintenance_manager.cc:419] P c73d258340b34264837fab21878bc358: Scheduling MajorDeltaCompactionOp(b9cbe9188ec6434c87f5997054949fb1): perf score=1.000000
W20260812 06:16:47.321748 20146 scanner-internal.cc:458] Time spent opening tablet: real 0.737s	user 0.001s	sys 0.000s
I20260812 06:16:47.325176 20146 heavy-update-compaction-itest.cc:265] Time spent scanning: real 0.740s	user 0.001s	sys 0.000s
I20260812 06:16:47.325819 20146 tablet_server.cc:179] TabletServer@127.19.172.129:0 shutting down...
I20260812 06:16:47.783991 20691 maintenance_manager.cc:643] P c73d258340b34264837fab21878bc358: MajorDeltaCompactionOp(b9cbe9188ec6434c87f5997054949fb1) complete. Timing: real 0.876s	user 0.401s	sys 0.284s Metrics: {"cfile_cache_miss":2933,"cfile_cache_miss_bytes":123273604,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":1,"delta_iterators_relevant":1,"dirs.queue_time_us":147,"lbm_read_time_us":44625,"lbm_reads_lt_1ms":2969,"lbm_write_time_us":115399,"lbm_writes_lt_1ms":2945,"mutex_wait_us":50,"peak_mem_usage":361353628,"reinsert_count":0,"spinlock_wait_cycles":174976,"update_count":14500}
I20260812 06:16:47.785256 20146 ts_tablet_manager.cc:1507] Shutting down tablet manager...
I20260812 06:16:47.785497 20146 tablet_replica.cc:333] T b9cbe9188ec6434c87f5997054949fb1 P c73d258340b34264837fab21878bc358: stopping tablet replica
I20260812 06:16:47.785624 20146 raft_consensus.cc:2243] T b9cbe9188ec6434c87f5997054949fb1 P c73d258340b34264837fab21878bc358 [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:16:47.785785 20146 raft_consensus.cc:2272] T b9cbe9188ec6434c87f5997054949fb1 P c73d258340b34264837fab21878bc358 [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:16:47.798784 20146 tablet_server.cc:196] TabletServer@127.19.172.129:0 shutdown complete.
I20260812 06:16:48.840137 20146 master.cc:562] Master@127.19.172.190:40833 shutting down...
I20260812 06:16:48.843051 20146 raft_consensus.cc:2243] T 00000000000000000000000000000000 P 3311b838d2b441c088060de21af46960 [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:16:48.843235 20146 raft_consensus.cc:2272] T 00000000000000000000000000000000 P 3311b838d2b441c088060de21af46960 [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:16:48.843304 20146 tablet_replica.cc:333] T 00000000000000000000000000000000 P 3311b838d2b441c088060de21af46960: stopping tablet replica
I20260812 06:16:48.855465 20146 master.cc:584] Master@127.19.172.190:40833 shutdown complete.
[       OK ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/1 (7173 ms)
[----------] 2 tests from EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy (12266 ms total)

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