[==========] Running 2 tests from 1 test suite.
[----------] Global test environment set-up.
[----------] 2 tests from EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy
[ RUN      ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/0
WARNING: Logging before InitGoogleLogging() is written to STDERR
I20260812 06:17:53.535554 24678 internal_mini_cluster.cc:156] Creating distributed mini masters. Addrs: 127.24.25.190:41071
I20260812 06:17:53.536630 24678 env_posix.cc:2285] Not raising this process' open files per process limit of 1048576; it is already as high as it can go
I20260812 06:17:53.537237 24678 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:17:53.543848 24687 instance_detector.cc:116] could not retrieve Azure instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:17:53.543855 24686 instance_detector.cc:116] could not retrieve AWS instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:17:53.544126 24689 instance_detector.cc:116] could not retrieve OpenStack instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:17:53.544128 24678 server_base.cc:1061] running on GCE node
I20260812 06:17:53.544734 24678 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:17:53.544854 24678 system_unsync_time.cc:38] NTP support is disabled. Clock error bounds will not be accurate. This configuration is not suitable for distributed clusters.
I20260812 06:17:53.544907 24678 hybrid_clock.cc:648] HybridClock initialized: now 1786515473544905 us; error 0 us; skew 500 ppm
I20260812 06:17:53.546736 24678 webserver.cc:533] Webserver started at http://127.24.25.190:34799/ using document root <none> and password file <none>
I20260812 06:17:53.547319 24678 fs_manager.cc:362] Metadata directory not provided
I20260812 06:17:53.547390 24678 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:17:53.547641 24678 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:17:53.549394 24678 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskZSRD0G/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515473524603-24678-0/minicluster-data/master-0-root/instance:
uuid: "d4616b1438fe41e6a75ffa722d2c44e0"
format_stamp: "Formatted at 2026-08-12 06:17:53 on dist-test-slave-mvvj"
I20260812 06:17:53.553200 24678 fs_manager.cc:696] Time spent creating directory manager: real 0.003s	user 0.004s	sys 0.000s
I20260812 06:17:53.555593 24695 log_block_manager.cc:4127] Time spent loading block containers with low live blocks: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:17:53.556788 24678 fs_manager.cc:730] Time spent opening block manager: real 0.002s	user 0.003s	sys 0.000s
I20260812 06:17:53.556905 24678 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskZSRD0G/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515473524603-24678-0/minicluster-data/master-0-root
uuid: "d4616b1438fe41e6a75ffa722d2c44e0"
format_stamp: "Formatted at 2026-08-12 06:17:53 on dist-test-slave-mvvj"
I20260812 06:17:53.557071 24678 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskZSRD0G/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515473524603-24678-0/minicluster-data/master-0-root
metadata directory: /tmp/dist-test-taskZSRD0G/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515473524603-24678-0/minicluster-data/master-0-root
1 data directories: /tmp/dist-test-taskZSRD0G/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515473524603-24678-0/minicluster-data/master-0-root/data
Total live blocks: 0
Total live bytes: 0
Total live bytes (after alignment): 0
Total number of LBM containers: 0 (0 full)
Did not check for missing blocks
Did not check for orphaned blocks
Total full LBM containers with extra space: 0 (0 repaired)
Total full LBM container extra space in bytes: 0 (0 repaired)
Total incomplete LBM containers: 0 (0 repaired)
Total LBM partial records: 0 (0 repaired)
Total corrupted LBM metadata records in RocksDB: 0 (0 repaired)
I20260812 06:17:53.584643 24678 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:17:53.585384 24678 env_posix.cc:2285] Not raising this process' running threads per effective uid limit of 18446744073709551615; it is already as high as it can go
I20260812 06:17:53.585592 24678 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:17:53.593850 24678 rpc_server.cc:307] RPC server started. Bound to: 127.24.25.190:41071
I20260812 06:17:53.593858 24752 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.24.25.190:41071 every 8 connection(s)
I20260812 06:17:53.596443 24753 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet 00000000000000000000000000000000. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:17:53.602645 24753 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P d4616b1438fe41e6a75ffa722d2c44e0: Bootstrap starting.
I20260812 06:17:53.605280 24753 tablet_bootstrap.cc:654] T 00000000000000000000000000000000 P d4616b1438fe41e6a75ffa722d2c44e0: Neither blocks nor log segments found. Creating new log.
I20260812 06:17:53.606366 24753 log.cc:826] T 00000000000000000000000000000000 P d4616b1438fe41e6a75ffa722d2c44e0: Log is configured to *not* fsync() on all Append() calls
I20260812 06:17:53.608404 24753 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P d4616b1438fe41e6a75ffa722d2c44e0: No bootstrap required, opened a new log
I20260812 06:17:53.611651 24753 raft_consensus.cc:359] T 00000000000000000000000000000000 P d4616b1438fe41e6a75ffa722d2c44e0 [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "d4616b1438fe41e6a75ffa722d2c44e0" member_type: VOTER }
I20260812 06:17:53.611912 24753 raft_consensus.cc:385] T 00000000000000000000000000000000 P d4616b1438fe41e6a75ffa722d2c44e0 [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:17:53.612028 24753 raft_consensus.cc:740] T 00000000000000000000000000000000 P d4616b1438fe41e6a75ffa722d2c44e0 [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: d4616b1438fe41e6a75ffa722d2c44e0, State: Initialized, Role: FOLLOWER
I20260812 06:17:53.612793 24753 consensus_queue.cc:260] T 00000000000000000000000000000000 P d4616b1438fe41e6a75ffa722d2c44e0 [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: "d4616b1438fe41e6a75ffa722d2c44e0" member_type: VOTER }
I20260812 06:17:53.612967 24753 raft_consensus.cc:399] T 00000000000000000000000000000000 P d4616b1438fe41e6a75ffa722d2c44e0 [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:17:53.613056 24753 raft_consensus.cc:493] T 00000000000000000000000000000000 P d4616b1438fe41e6a75ffa722d2c44e0 [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:17:53.613222 24753 raft_consensus.cc:3060] T 00000000000000000000000000000000 P d4616b1438fe41e6a75ffa722d2c44e0 [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:17:53.614161 24753 raft_consensus.cc:515] T 00000000000000000000000000000000 P d4616b1438fe41e6a75ffa722d2c44e0 [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "d4616b1438fe41e6a75ffa722d2c44e0" member_type: VOTER }
I20260812 06:17:53.614676 24753 leader_election.cc:304] T 00000000000000000000000000000000 P d4616b1438fe41e6a75ffa722d2c44e0 [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: d4616b1438fe41e6a75ffa722d2c44e0; no voters: 
I20260812 06:17:53.615135 24753 leader_election.cc:290] T 00000000000000000000000000000000 P d4616b1438fe41e6a75ffa722d2c44e0 [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:17:53.615382 24756 raft_consensus.cc:2804] T 00000000000000000000000000000000 P d4616b1438fe41e6a75ffa722d2c44e0 [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:17:53.615688 24756 raft_consensus.cc:697] T 00000000000000000000000000000000 P d4616b1438fe41e6a75ffa722d2c44e0 [term 1 LEADER]: Becoming Leader. State: Replica: d4616b1438fe41e6a75ffa722d2c44e0, State: Running, Role: LEADER
I20260812 06:17:53.616106 24756 consensus_queue.cc:237] T 00000000000000000000000000000000 P d4616b1438fe41e6a75ffa722d2c44e0 [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: "d4616b1438fe41e6a75ffa722d2c44e0" member_type: VOTER }
I20260812 06:17:53.616369 24753 sys_catalog.cc:565] T 00000000000000000000000000000000 P d4616b1438fe41e6a75ffa722d2c44e0 [sys.catalog]: configured and running, proceeding with master startup.
I20260812 06:17:53.617955 24757 sys_catalog.cc:455] T 00000000000000000000000000000000 P d4616b1438fe41e6a75ffa722d2c44e0 [sys.catalog]: SysCatalogTable state changed. Reason: RaftConsensus started. Latest consensus state: current_term: 1 leader_uuid: "d4616b1438fe41e6a75ffa722d2c44e0" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "d4616b1438fe41e6a75ffa722d2c44e0" member_type: VOTER } }
I20260812 06:17:53.618103 24757 sys_catalog.cc:458] T 00000000000000000000000000000000 P d4616b1438fe41e6a75ffa722d2c44e0 [sys.catalog]: This master's current role is: LEADER
I20260812 06:17:53.618459 24759 sys_catalog.cc:455] T 00000000000000000000000000000000 P d4616b1438fe41e6a75ffa722d2c44e0 [sys.catalog]: SysCatalogTable state changed. Reason: New leader d4616b1438fe41e6a75ffa722d2c44e0. Latest consensus state: current_term: 1 leader_uuid: "d4616b1438fe41e6a75ffa722d2c44e0" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "d4616b1438fe41e6a75ffa722d2c44e0" member_type: VOTER } }
I20260812 06:17:53.618537 24759 sys_catalog.cc:458] T 00000000000000000000000000000000 P d4616b1438fe41e6a75ffa722d2c44e0 [sys.catalog]: This master's current role is: LEADER
I20260812 06:17:53.618849 24768 catalog_manager.cc:1511] Loading table and tablet metadata into memory...
I20260812 06:17:53.618914 24678 internal_mini_cluster.cc:184] Waiting to initialize catalog manager on master 0
I20260812 06:17:53.621277 24768 catalog_manager.cc:1520] Initializing Kudu cluster ID...
I20260812 06:17:53.626554 24768 catalog_manager.cc:1383] Generated new cluster ID: 3710dc8fdcd24d1da15b12bc7d71c571
I20260812 06:17:53.626641 24768 catalog_manager.cc:1531] Initializing Kudu internal certificate authority...
I20260812 06:17:53.635772 24768 catalog_manager.cc:1406] Generated new certificate authority record
I20260812 06:17:53.636708 24768 catalog_manager.cc:1540] Loading token signing keys...
I20260812 06:17:53.646544 24768 catalog_manager.cc:6092] T 00000000000000000000000000000000 P d4616b1438fe41e6a75ffa722d2c44e0: Generated new TSK 0
I20260812 06:17:53.647269 24768 catalog_manager.cc:1550] Initializing in-progress tserver states...
I20260812 06:17:53.651463 24678 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:17:53.654342 24777 instance_detector.cc:116] could not retrieve AWS instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:17:53.654402 24781 instance_detector.cc:116] could not retrieve OpenStack instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:17:53.654512 24778 instance_detector.cc:116] could not retrieve Azure instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:17:53.654747 24678 server_base.cc:1061] running on GCE node
I20260812 06:17:53.654929 24678 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:17:53.654974 24678 system_unsync_time.cc:38] NTP support is disabled. Clock error bounds will not be accurate. This configuration is not suitable for distributed clusters.
I20260812 06:17:53.654995 24678 hybrid_clock.cc:648] HybridClock initialized: now 1786515473654996 us; error 0 us; skew 500 ppm
I20260812 06:17:53.656006 24678 webserver.cc:533] Webserver started at http://127.24.25.129:41323/ using document root <none> and password file <none>
I20260812 06:17:53.656185 24678 fs_manager.cc:362] Metadata directory not provided
I20260812 06:17:53.656247 24678 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:17:53.656317 24678 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:17:53.656774 24678 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskZSRD0G/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515473524603-24678-0/minicluster-data/ts-0-root/instance:
uuid: "5be12e9f5aa94f94bad4707ad79175b2"
format_stamp: "Formatted at 2026-08-12 06:17:53 on dist-test-slave-mvvj"
I20260812 06:17:53.658733 24678 fs_manager.cc:696] Time spent creating directory manager: real 0.002s	user 0.002s	sys 0.000s
I20260812 06:17:53.659983 24788 log_block_manager.cc:4127] Time spent loading block containers with low live blocks: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:17:53.660254 24678 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.001s	sys 0.000s
I20260812 06:17:53.660333 24678 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskZSRD0G/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515473524603-24678-0/minicluster-data/ts-0-root
uuid: "5be12e9f5aa94f94bad4707ad79175b2"
format_stamp: "Formatted at 2026-08-12 06:17:53 on dist-test-slave-mvvj"
I20260812 06:17:53.660403 24678 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskZSRD0G/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515473524603-24678-0/minicluster-data/ts-0-root
metadata directory: /tmp/dist-test-taskZSRD0G/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515473524603-24678-0/minicluster-data/ts-0-root
1 data directories: /tmp/dist-test-taskZSRD0G/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515473524603-24678-0/minicluster-data/ts-0-root/data
Total live blocks: 0
Total live bytes: 0
Total live bytes (after alignment): 0
Total number of LBM containers: 0 (0 full)
Did not check for missing blocks
Did not check for orphaned blocks
Total full LBM containers with extra space: 0 (0 repaired)
Total full LBM container extra space in bytes: 0 (0 repaired)
Total incomplete LBM containers: 0 (0 repaired)
Total LBM partial records: 0 (0 repaired)
Total corrupted LBM metadata records in RocksDB: 0 (0 repaired)
I20260812 06:17:53.696033 24678 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:17:53.696566 24678 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:17:53.697117 24678 txn_system_client.cc:432] TxnSystemClient initialization is disabled...
I20260812 06:17:53.698066 24678 ts_tablet_manager.cc:585] Loaded tablet metadata (0 total tablets, 0 live tablets)
I20260812 06:17:53.698122 24678 ts_tablet_manager.cc:531] Time spent load tablet metadata: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:17:53.698191 24678 ts_tablet_manager.cc:616] Registered 0 tablets
I20260812 06:17:53.698239 24678 ts_tablet_manager.cc:595] Time spent register tablets: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:17:53.705312 24678 rpc_server.cc:307] RPC server started. Bound to: 127.24.25.129:35615
I20260812 06:17:53.705343 24855 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.24.25.129:35615 every 8 connection(s)
I20260812 06:17:53.716761 24856 heartbeater.cc:344] Connected to a master server at 127.24.25.190:41071
I20260812 06:17:53.717062 24856 heartbeater.cc:461] Registering TS with master...
I20260812 06:17:53.717650 24856 heartbeater.cc:507] Master 127.24.25.190:41071 requested a full tablet report, sending...
I20260812 06:17:53.719369 24714 ts_manager.cc:194] Registered new tserver with Master: 5be12e9f5aa94f94bad4707ad79175b2 (127.24.25.129:35615)
I20260812 06:17:53.719563 24678 internal_mini_cluster.cc:371] 1 TS(s) registered with all masters after 0.013529284s
I20260812 06:17:53.721033 24714 master_service.cc:502] Signed X509 certificate for tserver {username='slave'} at 127.0.0.1:34236
I20260812 06:17:53.730094 24714 catalog_manager.cc:2283] Servicing CreateTable request from {username='slave'} at 127.0.0.1:34242:
name: "heavy-update-compaction-test"
schema {
  columns {
    name: "key"
    type: INT64
    is_key: true
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_a"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_b"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_c"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_d"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_e"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
}
num_replicas: 1
split_rows_range_bounds {
}
partition_schema {
  range_schema {
  }
}
I20260812 06:17:53.745317 24818 tablet_service.cc:1511] Processing CreateTablet for tablet f37826639f47441d8b669e8df8766d9c (DEFAULT_TABLE table=heavy-update-compaction-test [id=76d4f76cd17f4d20b127794cb252688e]), partition=
I20260812 06:17:53.745875 24818 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet f37826639f47441d8b669e8df8766d9c. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:17:53.748287 24870 tablet_bootstrap.cc:492] T f37826639f47441d8b669e8df8766d9c P 5be12e9f5aa94f94bad4707ad79175b2: Bootstrap starting.
I20260812 06:17:53.749439 24870 tablet_bootstrap.cc:654] T f37826639f47441d8b669e8df8766d9c P 5be12e9f5aa94f94bad4707ad79175b2: Neither blocks nor log segments found. Creating new log.
I20260812 06:17:53.750638 24870 tablet_bootstrap.cc:492] T f37826639f47441d8b669e8df8766d9c P 5be12e9f5aa94f94bad4707ad79175b2: No bootstrap required, opened a new log
I20260812 06:17:53.750763 24870 ts_tablet_manager.cc:1403] T f37826639f47441d8b669e8df8766d9c P 5be12e9f5aa94f94bad4707ad79175b2: Time spent bootstrapping tablet: real 0.003s	user 0.002s	sys 0.000s
I20260812 06:17:53.751212 24870 raft_consensus.cc:359] T f37826639f47441d8b669e8df8766d9c P 5be12e9f5aa94f94bad4707ad79175b2 [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "5be12e9f5aa94f94bad4707ad79175b2" member_type: VOTER last_known_addr { host: "127.24.25.129" port: 35615 } }
I20260812 06:17:53.751335 24870 raft_consensus.cc:385] T f37826639f47441d8b669e8df8766d9c P 5be12e9f5aa94f94bad4707ad79175b2 [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:17:53.751384 24870 raft_consensus.cc:740] T f37826639f47441d8b669e8df8766d9c P 5be12e9f5aa94f94bad4707ad79175b2 [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: 5be12e9f5aa94f94bad4707ad79175b2, State: Initialized, Role: FOLLOWER
I20260812 06:17:53.751559 24870 consensus_queue.cc:260] T f37826639f47441d8b669e8df8766d9c P 5be12e9f5aa94f94bad4707ad79175b2 [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: "5be12e9f5aa94f94bad4707ad79175b2" member_type: VOTER last_known_addr { host: "127.24.25.129" port: 35615 } }
I20260812 06:17:53.751662 24870 raft_consensus.cc:399] T f37826639f47441d8b669e8df8766d9c P 5be12e9f5aa94f94bad4707ad79175b2 [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:17:53.751711 24870 raft_consensus.cc:493] T f37826639f47441d8b669e8df8766d9c P 5be12e9f5aa94f94bad4707ad79175b2 [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:17:53.751765 24870 raft_consensus.cc:3060] T f37826639f47441d8b669e8df8766d9c P 5be12e9f5aa94f94bad4707ad79175b2 [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:17:53.752586 24870 raft_consensus.cc:515] T f37826639f47441d8b669e8df8766d9c P 5be12e9f5aa94f94bad4707ad79175b2 [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "5be12e9f5aa94f94bad4707ad79175b2" member_type: VOTER last_known_addr { host: "127.24.25.129" port: 35615 } }
I20260812 06:17:53.752745 24870 leader_election.cc:304] T f37826639f47441d8b669e8df8766d9c P 5be12e9f5aa94f94bad4707ad79175b2 [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: 5be12e9f5aa94f94bad4707ad79175b2; no voters: 
I20260812 06:17:53.752995 24870 leader_election.cc:290] T f37826639f47441d8b669e8df8766d9c P 5be12e9f5aa94f94bad4707ad79175b2 [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:17:53.753279 24873 raft_consensus.cc:2804] T f37826639f47441d8b669e8df8766d9c P 5be12e9f5aa94f94bad4707ad79175b2 [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:17:53.753322 24870 ts_tablet_manager.cc:1434] T f37826639f47441d8b669e8df8766d9c P 5be12e9f5aa94f94bad4707ad79175b2: Time spent starting tablet: real 0.002s	user 0.003s	sys 0.000s
I20260812 06:17:53.753466 24873 raft_consensus.cc:697] T f37826639f47441d8b669e8df8766d9c P 5be12e9f5aa94f94bad4707ad79175b2 [term 1 LEADER]: Becoming Leader. State: Replica: 5be12e9f5aa94f94bad4707ad79175b2, State: Running, Role: LEADER
I20260812 06:17:53.753769 24856 heartbeater.cc:499] Master 127.24.25.190:41071 was elected leader, sending a full tablet report...
I20260812 06:17:53.753659 24873 consensus_queue.cc:237] T f37826639f47441d8b669e8df8766d9c P 5be12e9f5aa94f94bad4707ad79175b2 [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: "5be12e9f5aa94f94bad4707ad79175b2" member_type: VOTER last_known_addr { host: "127.24.25.129" port: 35615 } }
I20260812 06:17:53.756697 24714 catalog_manager.cc:5719] T f37826639f47441d8b669e8df8766d9c P 5be12e9f5aa94f94bad4707ad79175b2 reported cstate change: term changed from 0 to 1, leader changed from <none> to 5be12e9f5aa94f94bad4707ad79175b2 (127.24.25.129). New cstate: current_term: 1 leader_uuid: "5be12e9f5aa94f94bad4707ad79175b2" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "5be12e9f5aa94f94bad4707ad79175b2" member_type: VOTER last_known_addr { host: "127.24.25.129" port: 35615 } health_report { overall_health: HEALTHY } } }
I20260812 06:17:53.835873 24678 heavy-update-compaction-itest.cc:215] Time spent inserting: real 0.070s	user 0.015s	sys 0.008s
I20260812 06:17:53.956651 24857 maintenance_manager.cc:419] P 5be12e9f5aa94f94bad4707ad79175b2: Scheduling FlushMRSOp(f37826639f47441d8b669e8df8766d9c): perf score=15.086190
I20260812 06:17:54.118346 24794 maintenance_manager.cc:643] P 5be12e9f5aa94f94bad4707ad79175b2: FlushMRSOp(f37826639f47441d8b669e8df8766d9c) complete. Timing: real 0.161s	user 0.123s	sys 0.033s Metrics: {"bytes_written":12307490,"cfile_init":1,"compiler_manager_pool.queue_time_us":845,"delete_count":0,"dirs.queue_time_us":77,"dirs.run_cpu_time_us":209,"dirs.run_wall_time_us":960,"drs_written":1,"lbm_read_time_us":72,"lbm_reads_lt_1ms":4,"lbm_write_time_us":38735,"lbm_writes_lt_1ms":657,"peak_mem_usage":0,"reinsert_count":0,"rows_written":103,"thread_start_us":152,"threads_started":1,"update_count":1500}
I20260812 06:17:54.119536 24857 maintenance_manager.cc:419] P 5be12e9f5aa94f94bad4707ad79175b2: Scheduling LogGCOp(f37826639f47441d8b669e8df8766d9c): free 8725963 bytes of WAL
I20260812 06:17:54.119917 24794 log_reader.cc:385] T f37826639f47441d8b669e8df8766d9c: removed 1 log segments from log reader
I20260812 06:17:54.120002 24794 log.cc:1079] T f37826639f47441d8b669e8df8766d9c P 5be12e9f5aa94f94bad4707ad79175b2: Deleting log segment in path: /tmp/dist-test-taskZSRD0G/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515473524603-24678-0/minicluster-data/ts-0-root/wals/f37826639f47441d8b669e8df8766d9c/wal-000000001 (ops 1-6)
I20260812 06:17:54.122018 24794 maintenance_manager.cc:643] P 5be12e9f5aa94f94bad4707ad79175b2: LogGCOp(f37826639f47441d8b669e8df8766d9c) complete. Timing: real 0.002s	user 0.000s	sys 0.000s Metrics: {}
I20260812 06:17:54.122365 24857 maintenance_manager.cc:419] P 5be12e9f5aa94f94bad4707ad79175b2: Scheduling UndoDeltaBlockGCOp(f37826639f47441d8b669e8df8766d9c): 12308959 bytes on disk
I20260812 06:17:54.122931 24794 maintenance_manager.cc:643] P 5be12e9f5aa94f94bad4707ad79175b2: UndoDeltaBlockGCOp(f37826639f47441d8b669e8df8766d9c) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":58,"lbm_reads_lt_1ms":4}
I20260812 06:17:54.123315 24857 maintenance_manager.cc:419] P 5be12e9f5aa94f94bad4707ad79175b2: Scheduling FlushDeltaMemStoresOp(f37826639f47441d8b669e8df8766d9c): perf score=2.188937
I20260812 06:17:54.138216 24794 maintenance_manager.cc:643] P 5be12e9f5aa94f94bad4707ad79175b2: FlushDeltaMemStoresOp(f37826639f47441d8b669e8df8766d9c) complete. Timing: real 0.015s	user 0.012s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5305,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:54.138887 24857 maintenance_manager.cc:419] P 5be12e9f5aa94f94bad4707ad79175b2: Scheduling MajorDeltaCompactionOp(f37826639f47441d8b669e8df8766d9c): perf score=1.000000
I20260812 06:17:54.264065 24794 maintenance_manager.cc:643] P 5be12e9f5aa94f94bad4707ad79175b2: MajorDeltaCompactionOp(f37826639f47441d8b669e8df8766d9c) complete. Timing: real 0.125s	user 0.092s	sys 0.033s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20631312,"cfile_init":7,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":815,"lbm_read_time_us":7363,"lbm_reads_lt_1ms":460,"lbm_write_time_us":22620,"lbm_writes_lt_1ms":443,"mutex_wait_us":22,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":9472,"thread_start_us":299,"threads_started":5,"update_count":2000}
I20260812 06:17:54.264659 24857 maintenance_manager.cc:419] P 5be12e9f5aa94f94bad4707ad79175b2: Scheduling FlushDeltaMemStoresOp(f37826639f47441d8b669e8df8766d9c): perf score=10.126437
I20260812 06:17:54.306946 24794 maintenance_manager.cc:643] P 5be12e9f5aa94f94bad4707ad79175b2: FlushDeltaMemStoresOp(f37826639f47441d8b669e8df8766d9c) complete. Timing: real 0.042s	user 0.022s	sys 0.008s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":14253,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:17:54.307444 24857 maintenance_manager.cc:419] P 5be12e9f5aa94f94bad4707ad79175b2: Scheduling FlushDeltaMemStoresOp(f37826639f47441d8b669e8df8766d9c): perf score=2.188937
I20260812 06:17:54.318634 24794 maintenance_manager.cc:643] P 5be12e9f5aa94f94bad4707ad79175b2: FlushDeltaMemStoresOp(f37826639f47441d8b669e8df8766d9c) complete. Timing: real 0.011s	user 0.003s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3947,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:54.319278 24857 maintenance_manager.cc:419] P 5be12e9f5aa94f94bad4707ad79175b2: Scheduling MajorDeltaCompactionOp(f37826639f47441d8b669e8df8766d9c): perf score=1.000000
I20260812 06:17:54.443326 24794 maintenance_manager.cc:643] P 5be12e9f5aa94f94bad4707ad79175b2: MajorDeltaCompactionOp(f37826639f47441d8b669e8df8766d9c) complete. Timing: real 0.124s	user 0.107s	sys 0.016s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20631312,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":1234,"lbm_read_time_us":7338,"lbm_reads_lt_1ms":472,"lbm_write_time_us":24708,"lbm_writes_lt_1ms":443,"mutex_wait_us":282,"peak_mem_usage":50689328,"reinsert_count":0,"update_count":2000}
I20260812 06:17:54.444144 24857 maintenance_manager.cc:419] P 5be12e9f5aa94f94bad4707ad79175b2: Scheduling FlushDeltaMemStoresOp(f37826639f47441d8b669e8df8766d9c): perf score=10.126437
I20260812 06:17:54.479185 24794 maintenance_manager.cc:643] P 5be12e9f5aa94f94bad4707ad79175b2: FlushDeltaMemStoresOp(f37826639f47441d8b669e8df8766d9c) complete. Timing: real 0.035s	user 0.022s	sys 0.008s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":14254,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:17:54.479694 24857 maintenance_manager.cc:419] P 5be12e9f5aa94f94bad4707ad79175b2: Scheduling FlushDeltaMemStoresOp(f37826639f47441d8b669e8df8766d9c): perf score=2.188937
I20260812 06:17:54.490804 24794 maintenance_manager.cc:643] P 5be12e9f5aa94f94bad4707ad79175b2: FlushDeltaMemStoresOp(f37826639f47441d8b669e8df8766d9c) complete. Timing: real 0.011s	user 0.009s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4042,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:54.491497 24857 maintenance_manager.cc:419] P 5be12e9f5aa94f94bad4707ad79175b2: Scheduling MajorDeltaCompactionOp(f37826639f47441d8b669e8df8766d9c): perf score=1.000000
I20260812 06:17:54.609170 24794 maintenance_manager.cc:643] P 5be12e9f5aa94f94bad4707ad79175b2: MajorDeltaCompactionOp(f37826639f47441d8b669e8df8766d9c) complete. Timing: real 0.117s	user 0.081s	sys 0.034s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20631312,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":239,"lbm_read_time_us":8079,"lbm_reads_lt_1ms":472,"lbm_write_time_us":22897,"lbm_writes_lt_1ms":443,"mutex_wait_us":29,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":1664,"update_count":2000}
I20260812 06:17:54.609745 24857 maintenance_manager.cc:419] P 5be12e9f5aa94f94bad4707ad79175b2: Scheduling FlushDeltaMemStoresOp(f37826639f47441d8b669e8df8766d9c): perf score=10.126437
I20260812 06:17:54.649420 24794 maintenance_manager.cc:643] P 5be12e9f5aa94f94bad4707ad79175b2: FlushDeltaMemStoresOp(f37826639f47441d8b669e8df8766d9c) complete. Timing: real 0.040s	user 0.011s	sys 0.025s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":13725,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:17:54.650171 24857 maintenance_manager.cc:419] P 5be12e9f5aa94f94bad4707ad79175b2: Scheduling MajorDeltaCompactionOp(f37826639f47441d8b669e8df8766d9c): perf score=1.000000
I20260812 06:17:54.762837 24794 maintenance_manager.cc:643] P 5be12e9f5aa94f94bad4707ad79175b2: MajorDeltaCompactionOp(f37826639f47441d8b669e8df8766d9c) complete. Timing: real 0.112s	user 0.078s	sys 0.034s Metrics: {"cfile_cache_miss":331,"cfile_cache_miss_bytes":16528781,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":1,"delta_iterators_relevant":1,"dirs.queue_time_us":643,"lbm_read_time_us":7217,"lbm_reads_lt_1ms":363,"lbm_write_time_us":16989,"lbm_writes_lt_1ms":343,"mutex_wait_us":284,"peak_mem_usage":38262756,"reinsert_count":0,"update_count":1500}
I20260812 06:17:54.763478 24857 maintenance_manager.cc:419] P 5be12e9f5aa94f94bad4707ad79175b2: Scheduling FlushDeltaMemStoresOp(f37826639f47441d8b669e8df8766d9c): perf score=10.126437
I20260812 06:17:54.809702 24794 maintenance_manager.cc:643] P 5be12e9f5aa94f94bad4707ad79175b2: FlushDeltaMemStoresOp(f37826639f47441d8b669e8df8766d9c) complete. Timing: real 0.046s	user 0.019s	sys 0.017s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":16669,"lbm_writes_lt_1ms":303,"reinsert_count":0,"spinlock_wait_cycles":2816,"update_count":1500}
I20260812 06:17:54.810220 24857 maintenance_manager.cc:419] P 5be12e9f5aa94f94bad4707ad79175b2: Scheduling FlushDeltaMemStoresOp(f37826639f47441d8b669e8df8766d9c): perf score=2.188937
I20260812 06:17:54.823817 24794 maintenance_manager.cc:643] P 5be12e9f5aa94f94bad4707ad79175b2: FlushDeltaMemStoresOp(f37826639f47441d8b669e8df8766d9c) complete. Timing: real 0.013s	user 0.010s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4572,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:54.824498 24857 maintenance_manager.cc:419] P 5be12e9f5aa94f94bad4707ad79175b2: Scheduling MajorDeltaCompactionOp(f37826639f47441d8b669e8df8766d9c): perf score=1.000000
I20260812 06:17:54.942473 24794 maintenance_manager.cc:643] P 5be12e9f5aa94f94bad4707ad79175b2: MajorDeltaCompactionOp(f37826639f47441d8b669e8df8766d9c) complete. Timing: real 0.118s	user 0.097s	sys 0.020s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20631312,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":943,"lbm_read_time_us":7560,"lbm_reads_lt_1ms":472,"lbm_write_time_us":22120,"lbm_writes_lt_1ms":443,"mutex_wait_us":361,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":10880,"update_count":2000}
I20260812 06:17:54.943181 24857 maintenance_manager.cc:419] P 5be12e9f5aa94f94bad4707ad79175b2: Scheduling FlushDeltaMemStoresOp(f37826639f47441d8b669e8df8766d9c): perf score=10.126437
I20260812 06:17:54.981963 24794 maintenance_manager.cc:643] P 5be12e9f5aa94f94bad4707ad79175b2: FlushDeltaMemStoresOp(f37826639f47441d8b669e8df8766d9c) complete. Timing: real 0.039s	user 0.019s	sys 0.013s Metrics: {"bytes_written":12307491,"delete_count":0,"lbm_write_time_us":14948,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:17:54.982573 24857 maintenance_manager.cc:419] P 5be12e9f5aa94f94bad4707ad79175b2: Scheduling FlushDeltaMemStoresOp(f37826639f47441d8b669e8df8766d9c): perf score=2.188937
I20260812 06:17:54.993016 24794 maintenance_manager.cc:643] P 5be12e9f5aa94f94bad4707ad79175b2: FlushDeltaMemStoresOp(f37826639f47441d8b669e8df8766d9c) complete. Timing: real 0.010s	user 0.004s	sys 0.005s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3893,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:54.993498 24857 maintenance_manager.cc:419] P 5be12e9f5aa94f94bad4707ad79175b2: Scheduling MajorDeltaCompactionOp(f37826639f47441d8b669e8df8766d9c): perf score=1.000000
I20260812 06:17:55.117341 24794 maintenance_manager.cc:643] P 5be12e9f5aa94f94bad4707ad79175b2: MajorDeltaCompactionOp(f37826639f47441d8b669e8df8766d9c) complete. Timing: real 0.124s	user 0.093s	sys 0.030s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20631313,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":624,"lbm_read_time_us":8437,"lbm_reads_lt_1ms":472,"lbm_write_time_us":23742,"lbm_writes_lt_1ms":443,"mutex_wait_us":230,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":12160,"update_count":2000}
I20260812 06:17:55.117978 24857 maintenance_manager.cc:419] P 5be12e9f5aa94f94bad4707ad79175b2: Scheduling FlushDeltaMemStoresOp(f37826639f47441d8b669e8df8766d9c): perf score=10.126437
I20260812 06:17:55.168318 24794 maintenance_manager.cc:643] P 5be12e9f5aa94f94bad4707ad79175b2: FlushDeltaMemStoresOp(f37826639f47441d8b669e8df8766d9c) complete. Timing: real 0.050s	user 0.032s	sys 0.008s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":14226,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:17:55.168865 24857 maintenance_manager.cc:419] P 5be12e9f5aa94f94bad4707ad79175b2: Scheduling FlushDeltaMemStoresOp(f37826639f47441d8b669e8df8766d9c): perf score=2.188937
I20260812 06:17:55.179400 24794 maintenance_manager.cc:643] P 5be12e9f5aa94f94bad4707ad79175b2: FlushDeltaMemStoresOp(f37826639f47441d8b669e8df8766d9c) complete. Timing: real 0.010s	user 0.005s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4097,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:55.179895 24857 maintenance_manager.cc:419] P 5be12e9f5aa94f94bad4707ad79175b2: Scheduling MajorDeltaCompactionOp(f37826639f47441d8b669e8df8766d9c): perf score=1.000000
I20260812 06:17:55.325649 24794 maintenance_manager.cc:643] P 5be12e9f5aa94f94bad4707ad79175b2: MajorDeltaCompactionOp(f37826639f47441d8b669e8df8766d9c) complete. Timing: real 0.146s	user 0.108s	sys 0.036s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20631312,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":740,"lbm_read_time_us":10575,"lbm_reads_lt_1ms":472,"lbm_write_time_us":23151,"lbm_writes_lt_1ms":443,"mutex_wait_us":46,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":768,"update_count":2000}
I20260812 06:17:55.326381 24857 maintenance_manager.cc:419] P 5be12e9f5aa94f94bad4707ad79175b2: Scheduling FlushDeltaMemStoresOp(f37826639f47441d8b669e8df8766d9c): perf score=10.126437
I20260812 06:17:55.370046 24794 maintenance_manager.cc:643] P 5be12e9f5aa94f94bad4707ad79175b2: FlushDeltaMemStoresOp(f37826639f47441d8b669e8df8766d9c) complete. Timing: real 0.043s	user 0.013s	sys 0.016s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":13872,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:17:55.370507 24857 maintenance_manager.cc:419] P 5be12e9f5aa94f94bad4707ad79175b2: Scheduling FlushDeltaMemStoresOp(f37826639f47441d8b669e8df8766d9c): perf score=2.188937
I20260812 06:17:55.381275 24794 maintenance_manager.cc:643] P 5be12e9f5aa94f94bad4707ad79175b2: FlushDeltaMemStoresOp(f37826639f47441d8b669e8df8766d9c) complete. Timing: real 0.011s	user 0.005s	sys 0.004s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":3998,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:55.382002 24857 maintenance_manager.cc:419] P 5be12e9f5aa94f94bad4707ad79175b2: Scheduling FlushMRSOp(f37826639f47441d8b669e8df8766d9c): perf score=1.000000
I20260812 06:17:55.411456 24794 maintenance_manager.cc:643] P 5be12e9f5aa94f94bad4707ad79175b2: FlushMRSOp(f37826639f47441d8b669e8df8766d9c) complete. Timing: real 0.029s	user 0.028s	sys 0.000s Metrics: {"bytes_written":1275444,"cfile_init":1,"dirs.queue_time_us":68,"dirs.run_cpu_time_us":252,"dirs.run_wall_time_us":1550,"drs_written":1,"lbm_read_time_us":39,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1617,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":31}
I20260812 06:17:55.412397 24857 maintenance_manager.cc:419] P 5be12e9f5aa94f94bad4707ad79175b2: Scheduling LogGCOp(f37826639f47441d8b669e8df8766d9c): free 136275163 bytes of WAL
I20260812 06:17:55.412640 24794 log_reader.cc:385] T f37826639f47441d8b669e8df8766d9c: removed 13 log segments from log reader
I20260812 06:17:55.412684 24794 log.cc:1079] T f37826639f47441d8b669e8df8766d9c P 5be12e9f5aa94f94bad4707ad79175b2: Deleting log segment in path: /tmp/dist-test-taskZSRD0G/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515473524603-24678-0/minicluster-data/ts-0-root/wals/f37826639f47441d8b669e8df8766d9c/wal-000000002 (ops 7-11)
I20260812 06:17:55.412732 24794 log.cc:1079] T f37826639f47441d8b669e8df8766d9c P 5be12e9f5aa94f94bad4707ad79175b2: Deleting log segment in path: /tmp/dist-test-taskZSRD0G/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515473524603-24678-0/minicluster-data/ts-0-root/wals/f37826639f47441d8b669e8df8766d9c/wal-000000003 (ops 12-16)
I20260812 06:17:55.412776 24794 log.cc:1079] T f37826639f47441d8b669e8df8766d9c P 5be12e9f5aa94f94bad4707ad79175b2: Deleting log segment in path: /tmp/dist-test-taskZSRD0G/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515473524603-24678-0/minicluster-data/ts-0-root/wals/f37826639f47441d8b669e8df8766d9c/wal-000000004 (ops 17-20)
I20260812 06:17:55.412829 24794 log.cc:1079] T f37826639f47441d8b669e8df8766d9c P 5be12e9f5aa94f94bad4707ad79175b2: Deleting log segment in path: /tmp/dist-test-taskZSRD0G/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515473524603-24678-0/minicluster-data/ts-0-root/wals/f37826639f47441d8b669e8df8766d9c/wal-000000005 (ops 21-25)
I20260812 06:17:55.412884 24794 log.cc:1079] T f37826639f47441d8b669e8df8766d9c P 5be12e9f5aa94f94bad4707ad79175b2: Deleting log segment in path: /tmp/dist-test-taskZSRD0G/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515473524603-24678-0/minicluster-data/ts-0-root/wals/f37826639f47441d8b669e8df8766d9c/wal-000000006 (ops 26-30)
I20260812 06:17:55.412940 24794 log.cc:1079] T f37826639f47441d8b669e8df8766d9c P 5be12e9f5aa94f94bad4707ad79175b2: Deleting log segment in path: /tmp/dist-test-taskZSRD0G/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515473524603-24678-0/minicluster-data/ts-0-root/wals/f37826639f47441d8b669e8df8766d9c/wal-000000007 (ops 31-35)
I20260812 06:17:55.412981 24794 log.cc:1079] T f37826639f47441d8b669e8df8766d9c P 5be12e9f5aa94f94bad4707ad79175b2: Deleting log segment in path: /tmp/dist-test-taskZSRD0G/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515473524603-24678-0/minicluster-data/ts-0-root/wals/f37826639f47441d8b669e8df8766d9c/wal-000000008 (ops 36-40)
I20260812 06:17:55.413019 24794 log.cc:1079] T f37826639f47441d8b669e8df8766d9c P 5be12e9f5aa94f94bad4707ad79175b2: Deleting log segment in path: /tmp/dist-test-taskZSRD0G/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515473524603-24678-0/minicluster-data/ts-0-root/wals/f37826639f47441d8b669e8df8766d9c/wal-000000009 (ops 41-45)
I20260812 06:17:55.413058 24794 log.cc:1079] T f37826639f47441d8b669e8df8766d9c P 5be12e9f5aa94f94bad4707ad79175b2: Deleting log segment in path: /tmp/dist-test-taskZSRD0G/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515473524603-24678-0/minicluster-data/ts-0-root/wals/f37826639f47441d8b669e8df8766d9c/wal-000000010 (ops 46-50)
I20260812 06:17:55.413097 24794 log.cc:1079] T f37826639f47441d8b669e8df8766d9c P 5be12e9f5aa94f94bad4707ad79175b2: Deleting log segment in path: /tmp/dist-test-taskZSRD0G/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515473524603-24678-0/minicluster-data/ts-0-root/wals/f37826639f47441d8b669e8df8766d9c/wal-000000011 (ops 51-55)
I20260812 06:17:55.413141 24794 log.cc:1079] T f37826639f47441d8b669e8df8766d9c P 5be12e9f5aa94f94bad4707ad79175b2: Deleting log segment in path: /tmp/dist-test-taskZSRD0G/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515473524603-24678-0/minicluster-data/ts-0-root/wals/f37826639f47441d8b669e8df8766d9c/wal-000000012 (ops 56-60)
I20260812 06:17:55.413192 24794 log.cc:1079] T f37826639f47441d8b669e8df8766d9c P 5be12e9f5aa94f94bad4707ad79175b2: Deleting log segment in path: /tmp/dist-test-taskZSRD0G/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515473524603-24678-0/minicluster-data/ts-0-root/wals/f37826639f47441d8b669e8df8766d9c/wal-000000013 (ops 61-65)
I20260812 06:17:55.413250 24794 log.cc:1079] T f37826639f47441d8b669e8df8766d9c P 5be12e9f5aa94f94bad4707ad79175b2: Deleting log segment in path: /tmp/dist-test-taskZSRD0G/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515473524603-24678-0/minicluster-data/ts-0-root/wals/f37826639f47441d8b669e8df8766d9c/wal-000000014 (ops 66-70)
I20260812 06:17:55.443090 24794 maintenance_manager.cc:643] P 5be12e9f5aa94f94bad4707ad79175b2: LogGCOp(f37826639f47441d8b669e8df8766d9c) complete. Timing: real 0.031s	user 0.000s	sys 0.027s Metrics: {}
I20260812 06:17:55.443715 24857 maintenance_manager.cc:419] P 5be12e9f5aa94f94bad4707ad79175b2: Scheduling UndoDeltaBlockGCOp(f37826639f47441d8b669e8df8766d9c): 482 bytes on disk
I20260812 06:17:55.444262 24794 maintenance_manager.cc:643] P 5be12e9f5aa94f94bad4707ad79175b2: UndoDeltaBlockGCOp(f37826639f47441d8b669e8df8766d9c) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":72,"lbm_reads_lt_1ms":4}
I20260812 06:17:55.444826 24857 maintenance_manager.cc:419] P 5be12e9f5aa94f94bad4707ad79175b2: Scheduling FlushDeltaMemStoresOp(f37826639f47441d8b669e8df8766d9c): perf score=3.181125
I20260812 06:17:55.471491 24794 maintenance_manager.cc:643] P 5be12e9f5aa94f94bad4707ad79175b2: FlushDeltaMemStoresOp(f37826639f47441d8b669e8df8766d9c) complete. Timing: real 0.026s	user 0.019s	sys 0.004s Metrics: {"bytes_written":4512902,"delete_count":0,"lbm_write_time_us":6796,"lbm_writes_lt_1ms":113,"reinsert_count":0,"update_count":550}
I20260812 06:17:55.472138 24857 maintenance_manager.cc:419] P 5be12e9f5aa94f94bad4707ad79175b2: Scheduling FlushDeltaMemStoresOp(f37826639f47441d8b669e8df8766d9c): perf score=2.188937
I20260812 06:17:55.482133 24794 maintenance_manager.cc:643] P 5be12e9f5aa94f94bad4707ad79175b2: FlushDeltaMemStoresOp(f37826639f47441d8b669e8df8766d9c) complete. Timing: real 0.010s	user 0.008s	sys 0.000s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3755,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:17:55.482609 24857 maintenance_manager.cc:419] P 5be12e9f5aa94f94bad4707ad79175b2: Scheduling MajorDeltaCompactionOp(f37826639f47441d8b669e8df8766d9c): perf score=1.000000
I20260812 06:17:55.672159 24794 maintenance_manager.cc:643] P 5be12e9f5aa94f94bad4707ad79175b2: MajorDeltaCompactionOp(f37826639f47441d8b669e8df8766d9c) complete. Timing: real 0.189s	user 0.126s	sys 0.062s Metrics: {"cfile_cache_miss":634,"cfile_cache_miss_bytes":28836362,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":278,"lbm_read_time_us":14811,"lbm_reads_lt_1ms":674,"lbm_write_time_us":32094,"lbm_writes_lt_1ms":643,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":2304,"thread_start_us":79,"threads_started":1,"update_count":3000}
I20260812 06:17:55.672749 24857 maintenance_manager.cc:419] P 5be12e9f5aa94f94bad4707ad79175b2: Scheduling FlushDeltaMemStoresOp(f37826639f47441d8b669e8df8766d9c): perf score=11.118625
I20260812 06:17:55.714186 24794 maintenance_manager.cc:643] P 5be12e9f5aa94f94bad4707ad79175b2: FlushDeltaMemStoresOp(f37826639f47441d8b669e8df8766d9c) complete. Timing: real 0.041s	user 0.030s	sys 0.008s Metrics: {"bytes_written":12717736,"delete_count":0,"lbm_write_time_us":17473,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:17:55.714946 24857 maintenance_manager.cc:419] P 5be12e9f5aa94f94bad4707ad79175b2: Scheduling FlushDeltaMemStoresOp(f37826639f47441d8b669e8df8766d9c): perf score=2.188937
I20260812 06:17:55.745922 24794 maintenance_manager.cc:643] P 5be12e9f5aa94f94bad4707ad79175b2: FlushDeltaMemStoresOp(f37826639f47441d8b669e8df8766d9c) complete. Timing: real 0.031s	user 0.006s	sys 0.009s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":5273,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:17:55.746527 24857 maintenance_manager.cc:419] P 5be12e9f5aa94f94bad4707ad79175b2: Scheduling FlushDeltaMemStoresOp(f37826639f47441d8b669e8df8766d9c): perf score=2.188937
I20260812 06:17:55.757584 24794 maintenance_manager.cc:643] P 5be12e9f5aa94f94bad4707ad79175b2: FlushDeltaMemStoresOp(f37826639f47441d8b669e8df8766d9c) complete. Timing: real 0.011s	user 0.005s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4285,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:55.758049 24857 maintenance_manager.cc:419] P 5be12e9f5aa94f94bad4707ad79175b2: Scheduling MajorDeltaCompactionOp(f37826639f47441d8b669e8df8766d9c): perf score=1.000000
I20260812 06:17:55.927209 24794 maintenance_manager.cc:643] P 5be12e9f5aa94f94bad4707ad79175b2: MajorDeltaCompactionOp(f37826639f47441d8b669e8df8766d9c) complete. Timing: real 0.169s	user 0.114s	sys 0.051s Metrics: {"cfile_cache_miss":533,"cfile_cache_miss_bytes":24733835,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":253,"lbm_read_time_us":12451,"lbm_reads_lt_1ms":573,"lbm_write_time_us":30240,"lbm_writes_lt_1ms":543,"mutex_wait_us":3,"peak_mem_usage":63115900,"reinsert_count":0,"update_count":2500}
I20260812 06:17:55.927726 24857 maintenance_manager.cc:419] P 5be12e9f5aa94f94bad4707ad79175b2: Scheduling FlushDeltaMemStoresOp(f37826639f47441d8b669e8df8766d9c): perf score=10.126437
I20260812 06:17:55.967473 24794 maintenance_manager.cc:643] P 5be12e9f5aa94f94bad4707ad79175b2: FlushDeltaMemStoresOp(f37826639f47441d8b669e8df8766d9c) complete. Timing: real 0.039s	user 0.015s	sys 0.021s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":17339,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:17:55.968271 24857 maintenance_manager.cc:419] P 5be12e9f5aa94f94bad4707ad79175b2: Scheduling FlushDeltaMemStoresOp(f37826639f47441d8b669e8df8766d9c): perf score=2.188937
I20260812 06:17:55.979482 24794 maintenance_manager.cc:643] P 5be12e9f5aa94f94bad4707ad79175b2: FlushDeltaMemStoresOp(f37826639f47441d8b669e8df8766d9c) complete. Timing: real 0.011s	user 0.005s	sys 0.004s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4306,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:55.980147 24857 maintenance_manager.cc:419] P 5be12e9f5aa94f94bad4707ad79175b2: Scheduling MajorDeltaCompactionOp(f37826639f47441d8b669e8df8766d9c): perf score=1.000000
I20260812 06:17:56.117241 24794 maintenance_manager.cc:643] P 5be12e9f5aa94f94bad4707ad79175b2: MajorDeltaCompactionOp(f37826639f47441d8b669e8df8766d9c) complete. Timing: real 0.137s	user 0.107s	sys 0.024s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20631311,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":1223,"lbm_read_time_us":9074,"lbm_reads_lt_1ms":472,"lbm_write_time_us":25072,"lbm_writes_lt_1ms":443,"mutex_wait_us":290,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":1408,"update_count":2000}
I20260812 06:17:56.117828 24857 maintenance_manager.cc:419] P 5be12e9f5aa94f94bad4707ad79175b2: Scheduling FlushDeltaMemStoresOp(f37826639f47441d8b669e8df8766d9c): perf score=10.126437
I20260812 06:17:56.166067 24794 maintenance_manager.cc:643] P 5be12e9f5aa94f94bad4707ad79175b2: FlushDeltaMemStoresOp(f37826639f47441d8b669e8df8766d9c) complete. Timing: real 0.048s	user 0.016s	sys 0.021s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":19514,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":302,"reinsert_count":0,"update_count":1500}
I20260812 06:17:56.166554 24857 maintenance_manager.cc:419] P 5be12e9f5aa94f94bad4707ad79175b2: Scheduling FlushDeltaMemStoresOp(f37826639f47441d8b669e8df8766d9c): perf score=2.188937
I20260812 06:17:56.177992 24794 maintenance_manager.cc:643] P 5be12e9f5aa94f94bad4707ad79175b2: FlushDeltaMemStoresOp(f37826639f47441d8b669e8df8766d9c) complete. Timing: real 0.011s	user 0.005s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4136,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:56.178552 24857 maintenance_manager.cc:419] P 5be12e9f5aa94f94bad4707ad79175b2: Scheduling MajorDeltaCompactionOp(f37826639f47441d8b669e8df8766d9c): perf score=1.000000
I20260812 06:17:56.303308 24794 maintenance_manager.cc:643] P 5be12e9f5aa94f94bad4707ad79175b2: MajorDeltaCompactionOp(f37826639f47441d8b669e8df8766d9c) complete. Timing: real 0.125s	user 0.105s	sys 0.020s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20631312,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":303,"lbm_read_time_us":8815,"lbm_reads_lt_1ms":472,"lbm_write_time_us":24695,"lbm_writes_lt_1ms":443,"mutex_wait_us":21,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":6912,"update_count":2000}
I20260812 06:17:56.303978 24857 maintenance_manager.cc:419] P 5be12e9f5aa94f94bad4707ad79175b2: Scheduling FlushDeltaMemStoresOp(f37826639f47441d8b669e8df8766d9c): perf score=10.126437
I20260812 06:17:56.344789 24794 maintenance_manager.cc:643] P 5be12e9f5aa94f94bad4707ad79175b2: FlushDeltaMemStoresOp(f37826639f47441d8b669e8df8766d9c) complete. Timing: real 0.041s	user 0.031s	sys 0.004s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":15741,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:17:56.345252 24857 maintenance_manager.cc:419] P 5be12e9f5aa94f94bad4707ad79175b2: Scheduling FlushDeltaMemStoresOp(f37826639f47441d8b669e8df8766d9c): perf score=2.188937
I20260812 06:17:56.357349 24794 maintenance_manager.cc:643] P 5be12e9f5aa94f94bad4707ad79175b2: FlushDeltaMemStoresOp(f37826639f47441d8b669e8df8766d9c) complete. Timing: real 0.012s	user 0.010s	sys 0.000s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4452,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:56.358034 24857 maintenance_manager.cc:419] P 5be12e9f5aa94f94bad4707ad79175b2: Scheduling MajorDeltaCompactionOp(f37826639f47441d8b669e8df8766d9c): perf score=1.000000
I20260812 06:17:56.478143 24794 maintenance_manager.cc:643] P 5be12e9f5aa94f94bad4707ad79175b2: MajorDeltaCompactionOp(f37826639f47441d8b669e8df8766d9c) complete. Timing: real 0.120s	user 0.104s	sys 0.016s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20631311,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":194,"lbm_read_time_us":7737,"lbm_reads_lt_1ms":472,"lbm_write_time_us":23865,"lbm_writes_lt_1ms":443,"mutex_wait_us":67,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":2176,"update_count":2000}
I20260812 06:17:56.478859 24857 maintenance_manager.cc:419] P 5be12e9f5aa94f94bad4707ad79175b2: Scheduling FlushDeltaMemStoresOp(f37826639f47441d8b669e8df8766d9c): perf score=10.126437
I20260812 06:17:56.523242 24794 maintenance_manager.cc:643] P 5be12e9f5aa94f94bad4707ad79175b2: FlushDeltaMemStoresOp(f37826639f47441d8b669e8df8766d9c) complete. Timing: real 0.044s	user 0.022s	sys 0.019s Metrics: {"bytes_written":12307491,"delete_count":0,"lbm_write_time_us":15648,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:17:56.523873 24857 maintenance_manager.cc:419] P 5be12e9f5aa94f94bad4707ad79175b2: Scheduling FlushDeltaMemStoresOp(f37826639f47441d8b669e8df8766d9c): perf score=2.188937
I20260812 06:17:56.538995 24794 maintenance_manager.cc:643] P 5be12e9f5aa94f94bad4707ad79175b2: FlushDeltaMemStoresOp(f37826639f47441d8b669e8df8766d9c) complete. Timing: real 0.015s	user 0.005s	sys 0.008s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":6199,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:56.539549 24857 maintenance_manager.cc:419] P 5be12e9f5aa94f94bad4707ad79175b2: Scheduling MajorDeltaCompactionOp(f37826639f47441d8b669e8df8766d9c): perf score=1.000000
I20260812 06:17:56.694900 24794 maintenance_manager.cc:643] P 5be12e9f5aa94f94bad4707ad79175b2: MajorDeltaCompactionOp(f37826639f47441d8b669e8df8766d9c) complete. Timing: real 0.155s	user 0.105s	sys 0.047s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20631312,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":213,"lbm_read_time_us":10760,"lbm_reads_lt_1ms":472,"lbm_write_time_us":25512,"lbm_writes_lt_1ms":443,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":1280,"update_count":2000}
I20260812 06:17:56.695613 24857 maintenance_manager.cc:419] P 5be12e9f5aa94f94bad4707ad79175b2: Scheduling FlushDeltaMemStoresOp(f37826639f47441d8b669e8df8766d9c): perf score=10.126437
I20260812 06:17:56.741753 24794 maintenance_manager.cc:643] P 5be12e9f5aa94f94bad4707ad79175b2: FlushDeltaMemStoresOp(f37826639f47441d8b669e8df8766d9c) complete. Timing: real 0.046s	user 0.023s	sys 0.015s Metrics: {"bytes_written":12307491,"delete_count":0,"lbm_write_time_us":17900,"lbm_writes_lt_1ms":303,"reinsert_count":0,"spinlock_wait_cycles":2816,"update_count":1500}
I20260812 06:17:56.742242 24857 maintenance_manager.cc:419] P 5be12e9f5aa94f94bad4707ad79175b2: Scheduling FlushDeltaMemStoresOp(f37826639f47441d8b669e8df8766d9c): perf score=2.188937
I20260812 06:17:56.753451 24794 maintenance_manager.cc:643] P 5be12e9f5aa94f94bad4707ad79175b2: FlushDeltaMemStoresOp(f37826639f47441d8b669e8df8766d9c) complete. Timing: real 0.011s	user 0.005s	sys 0.004s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4112,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:56.754338 24857 maintenance_manager.cc:419] P 5be12e9f5aa94f94bad4707ad79175b2: Scheduling MajorDeltaCompactionOp(f37826639f47441d8b669e8df8766d9c): perf score=1.000000
I20260812 06:17:56.879648 24794 maintenance_manager.cc:643] P 5be12e9f5aa94f94bad4707ad79175b2: MajorDeltaCompactionOp(f37826639f47441d8b669e8df8766d9c) complete. Timing: real 0.125s	user 0.103s	sys 0.019s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20631312,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":295,"lbm_read_time_us":8998,"lbm_reads_lt_1ms":472,"lbm_write_time_us":23163,"lbm_writes_lt_1ms":443,"mutex_wait_us":2,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":384,"update_count":2000}
I20260812 06:17:56.880342 24857 maintenance_manager.cc:419] P 5be12e9f5aa94f94bad4707ad79175b2: Scheduling FlushDeltaMemStoresOp(f37826639f47441d8b669e8df8766d9c): perf score=10.126437
I20260812 06:17:56.922755 24794 maintenance_manager.cc:643] P 5be12e9f5aa94f94bad4707ad79175b2: FlushDeltaMemStoresOp(f37826639f47441d8b669e8df8766d9c) complete. Timing: real 0.042s	user 0.030s	sys 0.004s Metrics: {"bytes_written":12307489,"delete_count":0,"lbm_write_time_us":16025,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:17:56.923321 24857 maintenance_manager.cc:419] P 5be12e9f5aa94f94bad4707ad79175b2: Scheduling FlushDeltaMemStoresOp(f37826639f47441d8b669e8df8766d9c): perf score=2.188937
I20260812 06:17:56.934464 24794 maintenance_manager.cc:643] P 5be12e9f5aa94f94bad4707ad79175b2: FlushDeltaMemStoresOp(f37826639f47441d8b669e8df8766d9c) complete. Timing: real 0.011s	user 0.009s	sys 0.000s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4223,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:56.935279 24857 maintenance_manager.cc:419] P 5be12e9f5aa94f94bad4707ad79175b2: Scheduling FlushMRSOp(f37826639f47441d8b669e8df8766d9c): perf score=1.000000
I20260812 06:17:56.968993 24794 maintenance_manager.cc:643] P 5be12e9f5aa94f94bad4707ad79175b2: FlushMRSOp(f37826639f47441d8b669e8df8766d9c) complete. Timing: real 0.033s	user 0.028s	sys 0.003s Metrics: {"bytes_written":1275449,"cfile_init":1,"dirs.queue_time_us":72,"dirs.run_cpu_time_us":259,"dirs.run_wall_time_us":1428,"drs_written":1,"lbm_read_time_us":56,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1875,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":31}
I20260812 06:17:56.969887 24857 maintenance_manager.cc:419] P 5be12e9f5aa94f94bad4707ad79175b2: Scheduling LogGCOp(f37826639f47441d8b669e8df8766d9c): free 129320468 bytes of WAL
I20260812 06:17:56.970172 24794 log_reader.cc:385] T f37826639f47441d8b669e8df8766d9c: removed 13 log segments from log reader
I20260812 06:17:56.970247 24794 log.cc:1079] T f37826639f47441d8b669e8df8766d9c P 5be12e9f5aa94f94bad4707ad79175b2: Deleting log segment in path: /tmp/dist-test-taskZSRD0G/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515473524603-24678-0/minicluster-data/ts-0-root/wals/f37826639f47441d8b669e8df8766d9c/wal-000000015 (ops 71-75)
I20260812 06:17:56.970322 24794 log.cc:1079] T f37826639f47441d8b669e8df8766d9c P 5be12e9f5aa94f94bad4707ad79175b2: Deleting log segment in path: /tmp/dist-test-taskZSRD0G/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515473524603-24678-0/minicluster-data/ts-0-root/wals/f37826639f47441d8b669e8df8766d9c/wal-000000016 (ops 76-80)
I20260812 06:17:56.970369 24794 log.cc:1079] T f37826639f47441d8b669e8df8766d9c P 5be12e9f5aa94f94bad4707ad79175b2: Deleting log segment in path: /tmp/dist-test-taskZSRD0G/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515473524603-24678-0/minicluster-data/ts-0-root/wals/f37826639f47441d8b669e8df8766d9c/wal-000000017 (ops 81-85)
I20260812 06:17:56.970412 24794 log.cc:1079] T f37826639f47441d8b669e8df8766d9c P 5be12e9f5aa94f94bad4707ad79175b2: Deleting log segment in path: /tmp/dist-test-taskZSRD0G/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515473524603-24678-0/minicluster-data/ts-0-root/wals/f37826639f47441d8b669e8df8766d9c/wal-000000018 (ops 86-90)
I20260812 06:17:56.970453 24794 log.cc:1079] T f37826639f47441d8b669e8df8766d9c P 5be12e9f5aa94f94bad4707ad79175b2: Deleting log segment in path: /tmp/dist-test-taskZSRD0G/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515473524603-24678-0/minicluster-data/ts-0-root/wals/f37826639f47441d8b669e8df8766d9c/wal-000000019 (ops 91-95)
I20260812 06:17:56.970494 24794 log.cc:1079] T f37826639f47441d8b669e8df8766d9c P 5be12e9f5aa94f94bad4707ad79175b2: Deleting log segment in path: /tmp/dist-test-taskZSRD0G/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515473524603-24678-0/minicluster-data/ts-0-root/wals/f37826639f47441d8b669e8df8766d9c/wal-000000020 (ops 96-100)
I20260812 06:17:56.970534 24794 log.cc:1079] T f37826639f47441d8b669e8df8766d9c P 5be12e9f5aa94f94bad4707ad79175b2: Deleting log segment in path: /tmp/dist-test-taskZSRD0G/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515473524603-24678-0/minicluster-data/ts-0-root/wals/f37826639f47441d8b669e8df8766d9c/wal-000000021 (ops 101-104)
I20260812 06:17:56.970575 24794 log.cc:1079] T f37826639f47441d8b669e8df8766d9c P 5be12e9f5aa94f94bad4707ad79175b2: Deleting log segment in path: /tmp/dist-test-taskZSRD0G/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515473524603-24678-0/minicluster-data/ts-0-root/wals/f37826639f47441d8b669e8df8766d9c/wal-000000022 (ops 105-109)
I20260812 06:17:56.970615 24794 log.cc:1079] T f37826639f47441d8b669e8df8766d9c P 5be12e9f5aa94f94bad4707ad79175b2: Deleting log segment in path: /tmp/dist-test-taskZSRD0G/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515473524603-24678-0/minicluster-data/ts-0-root/wals/f37826639f47441d8b669e8df8766d9c/wal-000000023 (ops 110-114)
I20260812 06:17:56.970656 24794 log.cc:1079] T f37826639f47441d8b669e8df8766d9c P 5be12e9f5aa94f94bad4707ad79175b2: Deleting log segment in path: /tmp/dist-test-taskZSRD0G/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515473524603-24678-0/minicluster-data/ts-0-root/wals/f37826639f47441d8b669e8df8766d9c/wal-000000024 (ops 115-119)
I20260812 06:17:56.970696 24794 log.cc:1079] T f37826639f47441d8b669e8df8766d9c P 5be12e9f5aa94f94bad4707ad79175b2: Deleting log segment in path: /tmp/dist-test-taskZSRD0G/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515473524603-24678-0/minicluster-data/ts-0-root/wals/f37826639f47441d8b669e8df8766d9c/wal-000000025 (ops 120-124)
I20260812 06:17:56.970737 24794 log.cc:1079] T f37826639f47441d8b669e8df8766d9c P 5be12e9f5aa94f94bad4707ad79175b2: Deleting log segment in path: /tmp/dist-test-taskZSRD0G/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515473524603-24678-0/minicluster-data/ts-0-root/wals/f37826639f47441d8b669e8df8766d9c/wal-000000026 (ops 125-128)
I20260812 06:17:56.970778 24794 log.cc:1079] T f37826639f47441d8b669e8df8766d9c P 5be12e9f5aa94f94bad4707ad79175b2: Deleting log segment in path: /tmp/dist-test-taskZSRD0G/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515473524603-24678-0/minicluster-data/ts-0-root/wals/f37826639f47441d8b669e8df8766d9c/wal-000000027 (ops 129-133)
I20260812 06:17:57.000567 24794 maintenance_manager.cc:643] P 5be12e9f5aa94f94bad4707ad79175b2: LogGCOp(f37826639f47441d8b669e8df8766d9c) complete. Timing: real 0.030s	user 0.000s	sys 0.030s Metrics: {}
I20260812 06:17:57.000984 24857 maintenance_manager.cc:419] P 5be12e9f5aa94f94bad4707ad79175b2: Scheduling FlushDeltaMemStoresOp(f37826639f47441d8b669e8df8766d9c): perf score=5.165500
I20260812 06:17:57.019685 24794 maintenance_manager.cc:643] P 5be12e9f5aa94f94bad4707ad79175b2: FlushDeltaMemStoresOp(f37826639f47441d8b669e8df8766d9c) complete. Timing: real 0.019s	user 0.007s	sys 0.008s Metrics: {"bytes_written":7302545,"delete_count":0,"lbm_write_time_us":7327,"lbm_writes_lt_1ms":181,"mutex_wait_us":96,"reinsert_count":0,"update_count":890}
I20260812 06:17:57.020252 24857 maintenance_manager.cc:419] P 5be12e9f5aa94f94bad4707ad79175b2: Scheduling UndoDeltaBlockGCOp(f37826639f47441d8b669e8df8766d9c): 483 bytes on disk
I20260812 06:17:57.020946 24794 maintenance_manager.cc:643] P 5be12e9f5aa94f94bad4707ad79175b2: UndoDeltaBlockGCOp(f37826639f47441d8b669e8df8766d9c) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":63,"lbm_reads_lt_1ms":4}
I20260812 06:17:57.021759 24857 maintenance_manager.cc:419] P 5be12e9f5aa94f94bad4707ad79175b2: Scheduling MajorDeltaCompactionOp(f37826639f47441d8b669e8df8766d9c): perf score=1.000000
I20260812 06:17:57.185792 24794 maintenance_manager.cc:643] P 5be12e9f5aa94f94bad4707ad79175b2: MajorDeltaCompactionOp(f37826639f47441d8b669e8df8766d9c) complete. Timing: real 0.164s	user 0.134s	sys 0.027s Metrics: {"cfile_cache_miss":611,"cfile_cache_miss_bytes":27933721,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":702,"lbm_read_time_us":10128,"lbm_reads_lt_1ms":647,"lbm_write_time_us":32323,"lbm_writes_lt_1ms":621,"mutex_wait_us":301,"peak_mem_usage":72558934,"reinsert_count":0,"spinlock_wait_cycles":11392,"thread_start_us":84,"threads_started":1,"update_count":2890}
I20260812 06:17:57.187850 24857 maintenance_manager.cc:419] P 5be12e9f5aa94f94bad4707ad79175b2: Scheduling FlushDeltaMemStoresOp(f37826639f47441d8b669e8df8766d9c): perf score=15.087375
I20260812 06:17:57.237558 24794 maintenance_manager.cc:643] P 5be12e9f5aa94f94bad4707ad79175b2: FlushDeltaMemStoresOp(f37826639f47441d8b669e8df8766d9c) complete. Timing: real 0.049s	user 0.035s	sys 0.009s Metrics: {"bytes_written":17312440,"delete_count":0,"lbm_write_time_us":20437,"lbm_writes_lt_1ms":425,"reinsert_count":0,"update_count":2110}
I20260812 06:17:57.238039 24857 maintenance_manager.cc:419] P 5be12e9f5aa94f94bad4707ad79175b2: Scheduling FlushDeltaMemStoresOp(f37826639f47441d8b669e8df8766d9c): perf score=2.188937
I20260812 06:17:57.250428 24794 maintenance_manager.cc:643] P 5be12e9f5aa94f94bad4707ad79175b2: FlushDeltaMemStoresOp(f37826639f47441d8b669e8df8766d9c) complete. Timing: real 0.012s	user 0.005s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4276,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:57.251004 24857 maintenance_manager.cc:419] P 5be12e9f5aa94f94bad4707ad79175b2: Scheduling MajorDeltaCompactionOp(f37826639f47441d8b669e8df8766d9c): perf score=1.000000
I20260812 06:17:57.419121 24794 maintenance_manager.cc:643] P 5be12e9f5aa94f94bad4707ad79175b2: MajorDeltaCompactionOp(f37826639f47441d8b669e8df8766d9c) complete. Timing: real 0.167s	user 0.118s	sys 0.037s Metrics: {"cfile_cache_miss":554,"cfile_cache_miss_bytes":25636262,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":156,"lbm_read_time_us":9643,"lbm_reads_lt_1ms":594,"lbm_write_time_us":33787,"lbm_writes_lt_1ms":565,"mutex_wait_us":59,"peak_mem_usage":65059054,"reinsert_count":0,"update_count":2610}
I20260812 06:17:57.419868 24857 maintenance_manager.cc:419] P 5be12e9f5aa94f94bad4707ad79175b2: Scheduling FlushDeltaMemStoresOp(f37826639f47441d8b669e8df8766d9c): perf score=14.095187
I20260812 06:17:57.471455 24794 maintenance_manager.cc:643] P 5be12e9f5aa94f94bad4707ad79175b2: FlushDeltaMemStoresOp(f37826639f47441d8b669e8df8766d9c) complete. Timing: real 0.051s	user 0.034s	sys 0.012s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":21385,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:17:57.472086 24857 maintenance_manager.cc:419] P 5be12e9f5aa94f94bad4707ad79175b2: Scheduling FlushDeltaMemStoresOp(f37826639f47441d8b669e8df8766d9c): perf score=2.188937
I20260812 06:17:57.488298 24794 maintenance_manager.cc:643] P 5be12e9f5aa94f94bad4707ad79175b2: FlushDeltaMemStoresOp(f37826639f47441d8b669e8df8766d9c) complete. Timing: real 0.016s	user 0.007s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6346,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:57.488920 24857 maintenance_manager.cc:419] P 5be12e9f5aa94f94bad4707ad79175b2: Scheduling MajorDeltaCompactionOp(f37826639f47441d8b669e8df8766d9c): perf score=1.000000
I20260812 06:17:57.667903 24794 maintenance_manager.cc:643] P 5be12e9f5aa94f94bad4707ad79175b2: MajorDeltaCompactionOp(f37826639f47441d8b669e8df8766d9c) complete. Timing: real 0.179s	user 0.122s	sys 0.051s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24733723,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":456,"lbm_read_time_us":10934,"lbm_reads_lt_1ms":572,"lbm_write_time_us":31131,"lbm_writes_lt_1ms":543,"mutex_wait_us":28,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":15488,"update_count":2500}
I20260812 06:17:57.668582 24857 maintenance_manager.cc:419] P 5be12e9f5aa94f94bad4707ad79175b2: Scheduling FlushDeltaMemStoresOp(f37826639f47441d8b669e8df8766d9c): perf score=14.095187
I20260812 06:17:57.710345 24794 maintenance_manager.cc:643] P 5be12e9f5aa94f94bad4707ad79175b2: FlushDeltaMemStoresOp(f37826639f47441d8b669e8df8766d9c) complete. Timing: real 0.042s	user 0.030s	sys 0.009s Metrics: {"bytes_written":16409903,"delete_count":0,"lbm_write_time_us":18808,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:17:57.710840 24857 maintenance_manager.cc:419] P 5be12e9f5aa94f94bad4707ad79175b2: Scheduling MajorDeltaCompactionOp(f37826639f47441d8b669e8df8766d9c): perf score=1.000000
I20260812 06:17:57.853389 24794 maintenance_manager.cc:643] P 5be12e9f5aa94f94bad4707ad79175b2: MajorDeltaCompactionOp(f37826639f47441d8b669e8df8766d9c) complete. Timing: real 0.142s	user 0.106s	sys 0.036s Metrics: {"cfile_cache_miss":431,"cfile_cache_miss_bytes":20631194,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":1,"delta_iterators_relevant":1,"dirs.queue_time_us":684,"lbm_read_time_us":9081,"lbm_reads_lt_1ms":467,"lbm_write_time_us":23730,"lbm_writes_lt_1ms":443,"mutex_wait_us":50,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":10368,"update_count":2000}
I20260812 06:17:57.854096 24857 maintenance_manager.cc:419] P 5be12e9f5aa94f94bad4707ad79175b2: Scheduling FlushDeltaMemStoresOp(f37826639f47441d8b669e8df8766d9c): perf score=10.126437
I20260812 06:17:57.885393 24794 maintenance_manager.cc:643] P 5be12e9f5aa94f94bad4707ad79175b2: FlushDeltaMemStoresOp(f37826639f47441d8b669e8df8766d9c) complete. Timing: real 0.031s	user 0.014s	sys 0.016s Metrics: {"bytes_written":12307492,"delete_count":0,"lbm_write_time_us":13343,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:17:57.885979 24857 maintenance_manager.cc:419] P 5be12e9f5aa94f94bad4707ad79175b2: Scheduling FlushDeltaMemStoresOp(f37826639f47441d8b669e8df8766d9c): perf score=2.188937
I20260812 06:17:57.901682 24794 maintenance_manager.cc:643] P 5be12e9f5aa94f94bad4707ad79175b2: FlushDeltaMemStoresOp(f37826639f47441d8b669e8df8766d9c) complete. Timing: real 0.015s	user 0.009s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5918,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:57.902765 24857 maintenance_manager.cc:419] P 5be12e9f5aa94f94bad4707ad79175b2: Scheduling MajorDeltaCompactionOp(f37826639f47441d8b669e8df8766d9c): perf score=1.000000
I20260812 06:17:58.021744 24794 maintenance_manager.cc:643] P 5be12e9f5aa94f94bad4707ad79175b2: MajorDeltaCompactionOp(f37826639f47441d8b669e8df8766d9c) complete. Timing: real 0.119s	user 0.088s	sys 0.030s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20631314,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":441,"lbm_read_time_us":9924,"lbm_reads_lt_1ms":472,"lbm_write_time_us":21385,"lbm_writes_lt_1ms":443,"mutex_wait_us":79,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":2432,"update_count":2000}
I20260812 06:17:58.022473 24857 maintenance_manager.cc:419] P 5be12e9f5aa94f94bad4707ad79175b2: Scheduling FlushDeltaMemStoresOp(f37826639f47441d8b669e8df8766d9c): perf score=10.126437
I20260812 06:17:58.068825 24794 maintenance_manager.cc:643] P 5be12e9f5aa94f94bad4707ad79175b2: FlushDeltaMemStoresOp(f37826639f47441d8b669e8df8766d9c) complete. Timing: real 0.046s	user 0.033s	sys 0.005s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":16356,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:17:58.069545 24857 maintenance_manager.cc:419] P 5be12e9f5aa94f94bad4707ad79175b2: Scheduling MajorDeltaCompactionOp(f37826639f47441d8b669e8df8766d9c): perf score=1.000000
I20260812 06:17:58.170394 24794 maintenance_manager.cc:643] P 5be12e9f5aa94f94bad4707ad79175b2: MajorDeltaCompactionOp(f37826639f47441d8b669e8df8766d9c) complete. Timing: real 0.101s	user 0.089s	sys 0.012s Metrics: {"cfile_cache_miss":331,"cfile_cache_miss_bytes":16528781,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":1,"delta_iterators_relevant":1,"dirs.queue_time_us":151,"lbm_read_time_us":7464,"lbm_reads_lt_1ms":363,"lbm_write_time_us":17631,"lbm_writes_lt_1ms":343,"mutex_wait_us":62,"peak_mem_usage":38262756,"reinsert_count":0,"spinlock_wait_cycles":6016,"update_count":1500}
I20260812 06:17:58.171101 24857 maintenance_manager.cc:419] P 5be12e9f5aa94f94bad4707ad79175b2: Scheduling FlushDeltaMemStoresOp(f37826639f47441d8b669e8df8766d9c): perf score=10.126437
I20260812 06:17:58.225263 24794 maintenance_manager.cc:643] P 5be12e9f5aa94f94bad4707ad79175b2: FlushDeltaMemStoresOp(f37826639f47441d8b669e8df8766d9c) complete. Timing: real 0.054s	user 0.029s	sys 0.012s Metrics: {"bytes_written":12307492,"delete_count":0,"lbm_write_time_us":18123,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:17:58.225782 24857 maintenance_manager.cc:419] P 5be12e9f5aa94f94bad4707ad79175b2: Scheduling FlushDeltaMemStoresOp(f37826639f47441d8b669e8df8766d9c): perf score=2.188937
I20260812 06:17:58.236398 24794 maintenance_manager.cc:643] P 5be12e9f5aa94f94bad4707ad79175b2: FlushDeltaMemStoresOp(f37826639f47441d8b669e8df8766d9c) complete. Timing: real 0.010s	user 0.010s	sys 0.000s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":3959,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:58.236869 24857 maintenance_manager.cc:419] P 5be12e9f5aa94f94bad4707ad79175b2: Scheduling MajorDeltaCompactionOp(f37826639f47441d8b669e8df8766d9c): perf score=1.000000
I20260812 06:17:58.385491 24794 maintenance_manager.cc:643] P 5be12e9f5aa94f94bad4707ad79175b2: MajorDeltaCompactionOp(f37826639f47441d8b669e8df8766d9c) complete. Timing: real 0.148s	user 0.116s	sys 0.032s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20631313,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":639,"lbm_read_time_us":11161,"lbm_reads_lt_1ms":472,"lbm_write_time_us":25004,"lbm_writes_lt_1ms":443,"mutex_wait_us":58,"peak_mem_usage":50689328,"reinsert_count":0,"update_count":2000}
I20260812 06:17:58.386073 24857 maintenance_manager.cc:419] P 5be12e9f5aa94f94bad4707ad79175b2: Scheduling FlushDeltaMemStoresOp(f37826639f47441d8b669e8df8766d9c): perf score=10.126437
I20260812 06:17:58.427794 24794 maintenance_manager.cc:643] P 5be12e9f5aa94f94bad4707ad79175b2: FlushDeltaMemStoresOp(f37826639f47441d8b669e8df8766d9c) complete. Timing: real 0.042s	user 0.021s	sys 0.016s Metrics: {"bytes_written":12307489,"delete_count":0,"lbm_write_time_us":18413,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":302,"reinsert_count":0,"update_count":1500}
I20260812 06:17:58.428391 24857 maintenance_manager.cc:419] P 5be12e9f5aa94f94bad4707ad79175b2: Scheduling FlushDeltaMemStoresOp(f37826639f47441d8b669e8df8766d9c): perf score=2.188937
I20260812 06:17:58.444466 24794 maintenance_manager.cc:643] P 5be12e9f5aa94f94bad4707ad79175b2: FlushDeltaMemStoresOp(f37826639f47441d8b669e8df8766d9c) complete. Timing: real 0.016s	user 0.011s	sys 0.003s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":5894,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:58.445034 24857 maintenance_manager.cc:419] P 5be12e9f5aa94f94bad4707ad79175b2: Scheduling FlushMRSOp(f37826639f47441d8b669e8df8766d9c): perf score=1.000000
I20260812 06:17:58.505635 24794 maintenance_manager.cc:643] P 5be12e9f5aa94f94bad4707ad79175b2: FlushMRSOp(f37826639f47441d8b669e8df8766d9c) complete. Timing: real 0.060s	user 0.035s	sys 0.000s Metrics: {"bytes_written":1316417,"cfile_init":1,"dirs.queue_time_us":53,"dirs.run_cpu_time_us":238,"dirs.run_wall_time_us":1465,"drs_written":1,"lbm_read_time_us":62,"lbm_reads_lt_1ms":4,"lbm_write_time_us":2476,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":32}
I20260812 06:17:58.506390 24857 maintenance_manager.cc:419] P 5be12e9f5aa94f94bad4707ad79175b2: Scheduling LogGCOp(f37826639f47441d8b669e8df8766d9c): free 121006757 bytes of WAL
I20260812 06:17:58.506626 24794 log_reader.cc:385] T f37826639f47441d8b669e8df8766d9c: removed 12 log segments from log reader
I20260812 06:17:58.506671 24794 log.cc:1079] T f37826639f47441d8b669e8df8766d9c P 5be12e9f5aa94f94bad4707ad79175b2: Deleting log segment in path: /tmp/dist-test-taskZSRD0G/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515473524603-24678-0/minicluster-data/ts-0-root/wals/f37826639f47441d8b669e8df8766d9c/wal-000000028 (ops 134-138)
I20260812 06:17:58.506701 24794 log.cc:1079] T f37826639f47441d8b669e8df8766d9c P 5be12e9f5aa94f94bad4707ad79175b2: Deleting log segment in path: /tmp/dist-test-taskZSRD0G/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515473524603-24678-0/minicluster-data/ts-0-root/wals/f37826639f47441d8b669e8df8766d9c/wal-000000029 (ops 139-143)
I20260812 06:17:58.506765 24794 log.cc:1079] T f37826639f47441d8b669e8df8766d9c P 5be12e9f5aa94f94bad4707ad79175b2: Deleting log segment in path: /tmp/dist-test-taskZSRD0G/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515473524603-24678-0/minicluster-data/ts-0-root/wals/f37826639f47441d8b669e8df8766d9c/wal-000000030 (ops 144-148)
I20260812 06:17:58.506805 24794 log.cc:1079] T f37826639f47441d8b669e8df8766d9c P 5be12e9f5aa94f94bad4707ad79175b2: Deleting log segment in path: /tmp/dist-test-taskZSRD0G/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515473524603-24678-0/minicluster-data/ts-0-root/wals/f37826639f47441d8b669e8df8766d9c/wal-000000031 (ops 149-152)
I20260812 06:17:58.506855 24794 log.cc:1079] T f37826639f47441d8b669e8df8766d9c P 5be12e9f5aa94f94bad4707ad79175b2: Deleting log segment in path: /tmp/dist-test-taskZSRD0G/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515473524603-24678-0/minicluster-data/ts-0-root/wals/f37826639f47441d8b669e8df8766d9c/wal-000000032 (ops 153-157)
I20260812 06:17:58.506898 24794 log.cc:1079] T f37826639f47441d8b669e8df8766d9c P 5be12e9f5aa94f94bad4707ad79175b2: Deleting log segment in path: /tmp/dist-test-taskZSRD0G/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515473524603-24678-0/minicluster-data/ts-0-root/wals/f37826639f47441d8b669e8df8766d9c/wal-000000033 (ops 158-162)
I20260812 06:17:58.506955 24794 log.cc:1079] T f37826639f47441d8b669e8df8766d9c P 5be12e9f5aa94f94bad4707ad79175b2: Deleting log segment in path: /tmp/dist-test-taskZSRD0G/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515473524603-24678-0/minicluster-data/ts-0-root/wals/f37826639f47441d8b669e8df8766d9c/wal-000000034 (ops 163-167)
I20260812 06:17:58.506992 24794 log.cc:1079] T f37826639f47441d8b669e8df8766d9c P 5be12e9f5aa94f94bad4707ad79175b2: Deleting log segment in path: /tmp/dist-test-taskZSRD0G/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515473524603-24678-0/minicluster-data/ts-0-root/wals/f37826639f47441d8b669e8df8766d9c/wal-000000035 (ops 168-172)
I20260812 06:17:58.507032 24794 log.cc:1079] T f37826639f47441d8b669e8df8766d9c P 5be12e9f5aa94f94bad4707ad79175b2: Deleting log segment in path: /tmp/dist-test-taskZSRD0G/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515473524603-24678-0/minicluster-data/ts-0-root/wals/f37826639f47441d8b669e8df8766d9c/wal-000000036 (ops 173-177)
I20260812 06:17:58.507078 24794 log.cc:1079] T f37826639f47441d8b669e8df8766d9c P 5be12e9f5aa94f94bad4707ad79175b2: Deleting log segment in path: /tmp/dist-test-taskZSRD0G/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515473524603-24678-0/minicluster-data/ts-0-root/wals/f37826639f47441d8b669e8df8766d9c/wal-000000037 (ops 178-182)
I20260812 06:17:58.507119 24794 log.cc:1079] T f37826639f47441d8b669e8df8766d9c P 5be12e9f5aa94f94bad4707ad79175b2: Deleting log segment in path: /tmp/dist-test-taskZSRD0G/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515473524603-24678-0/minicluster-data/ts-0-root/wals/f37826639f47441d8b669e8df8766d9c/wal-000000038 (ops 183-187)
I20260812 06:17:58.507159 24794 log.cc:1079] T f37826639f47441d8b669e8df8766d9c P 5be12e9f5aa94f94bad4707ad79175b2: Deleting log segment in path: /tmp/dist-test-taskZSRD0G/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515473524603-24678-0/minicluster-data/ts-0-root/wals/f37826639f47441d8b669e8df8766d9c/wal-000000039 (ops 188-192)
I20260812 06:17:58.531325 24794 maintenance_manager.cc:643] P 5be12e9f5aa94f94bad4707ad79175b2: LogGCOp(f37826639f47441d8b669e8df8766d9c) complete. Timing: real 0.025s	user 0.000s	sys 0.021s Metrics: {}
I20260812 06:17:58.531872 24857 maintenance_manager.cc:419] P 5be12e9f5aa94f94bad4707ad79175b2: Scheduling FlushDeltaMemStoresOp(f37826639f47441d8b669e8df8766d9c): perf score=6.157687
I20260812 06:17:58.551726 24794 maintenance_manager.cc:643] P 5be12e9f5aa94f94bad4707ad79175b2: FlushDeltaMemStoresOp(f37826639f47441d8b669e8df8766d9c) complete. Timing: real 0.019s	user 0.009s	sys 0.008s Metrics: {"bytes_written":8205077,"delete_count":0,"lbm_write_time_us":8339,"lbm_writes_lt_1ms":203,"reinsert_count":0,"update_count":1000}
I20260812 06:17:58.552254 24857 maintenance_manager.cc:419] P 5be12e9f5aa94f94bad4707ad79175b2: Scheduling LogGCOp(f37826639f47441d8b669e8df8766d9c): free 11564893 bytes of WAL
I20260812 06:17:58.552520 24794 log_reader.cc:385] T f37826639f47441d8b669e8df8766d9c: removed 1 log segments from log reader
I20260812 06:17:58.552597 24794 log.cc:1079] T f37826639f47441d8b669e8df8766d9c P 5be12e9f5aa94f94bad4707ad79175b2: Deleting log segment in path: /tmp/dist-test-taskZSRD0G/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515473524603-24678-0/minicluster-data/ts-0-root/wals/f37826639f47441d8b669e8df8766d9c/wal-000000040 (ops 193-196)
I20260812 06:17:58.555145 24794 maintenance_manager.cc:643] P 5be12e9f5aa94f94bad4707ad79175b2: LogGCOp(f37826639f47441d8b669e8df8766d9c) complete. Timing: real 0.003s	user 0.000s	sys 0.000s Metrics: {}
I20260812 06:17:58.555501 24857 maintenance_manager.cc:419] P 5be12e9f5aa94f94bad4707ad79175b2: Scheduling UndoDeltaBlockGCOp(f37826639f47441d8b669e8df8766d9c): 492 bytes on disk
I20260812 06:17:58.556008 24794 maintenance_manager.cc:643] P 5be12e9f5aa94f94bad4707ad79175b2: UndoDeltaBlockGCOp(f37826639f47441d8b669e8df8766d9c) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":111,"lbm_reads_lt_1ms":4}
I20260812 06:17:58.556638 24857 maintenance_manager.cc:419] P 5be12e9f5aa94f94bad4707ad79175b2: Scheduling FlushDeltaMemStoresOp(f37826639f47441d8b669e8df8766d9c): perf score=2.188937
I20260812 06:17:58.569752 24794 maintenance_manager.cc:643] P 5be12e9f5aa94f94bad4707ad79175b2: FlushDeltaMemStoresOp(f37826639f47441d8b669e8df8766d9c) complete. Timing: real 0.013s	user 0.007s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5059,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:58.570327 24857 maintenance_manager.cc:419] P 5be12e9f5aa94f94bad4707ad79175b2: Scheduling MajorDeltaCompactionOp(f37826639f47441d8b669e8df8766d9c): perf score=1.000000
I20260812 06:17:58.592748 24678 heavy-update-compaction-itest.cc:229] Time spent updating: real 4.757s	user 1.763s	sys 0.132s
I20260812 06:17:58.703701 24678 heavy-update-compaction-itest.cc:265] Time spent scanning: real 0.110s	user 0.001s	sys 0.000s
I20260812 06:17:58.704406 24678 tablet_server.cc:179] TabletServer@127.24.25.129:0 shutting down...
I20260812 06:17:58.761750 24794 maintenance_manager.cc:643] P 5be12e9f5aa94f94bad4707ad79175b2: MajorDeltaCompactionOp(f37826639f47441d8b669e8df8766d9c) complete. Timing: real 0.191s	user 0.158s	sys 0.032s Metrics: {"cfile_cache_miss":734,"cfile_cache_miss_bytes":32938784,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":753,"lbm_read_time_us":15878,"lbm_reads_lt_1ms":770,"lbm_write_time_us":33725,"lbm_writes_lt_1ms":743,"mutex_wait_us":31,"peak_mem_usage":87969044,"reinsert_count":0,"spinlock_wait_cycles":18432,"thread_start_us":82,"threads_started":1,"update_count":3500}
I20260812 06:17:58.762617 24678 ts_tablet_manager.cc:1507] Shutting down tablet manager...
I20260812 06:17:58.763087 24678 tablet_replica.cc:333] T f37826639f47441d8b669e8df8766d9c P 5be12e9f5aa94f94bad4707ad79175b2: stopping tablet replica
I20260812 06:17:58.763366 24678 raft_consensus.cc:2243] T f37826639f47441d8b669e8df8766d9c P 5be12e9f5aa94f94bad4707ad79175b2 [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:17:58.763639 24678 raft_consensus.cc:2272] T f37826639f47441d8b669e8df8766d9c P 5be12e9f5aa94f94bad4707ad79175b2 [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:17:58.780409 24678 tablet_server.cc:196] TabletServer@127.24.25.129:0 shutdown complete.
I20260812 06:17:58.819617 24678 master.cc:562] Master@127.24.25.190:41071 shutting down...
I20260812 06:17:58.823596 24678 raft_consensus.cc:2243] T 00000000000000000000000000000000 P d4616b1438fe41e6a75ffa722d2c44e0 [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:17:58.823817 24678 raft_consensus.cc:2272] T 00000000000000000000000000000000 P d4616b1438fe41e6a75ffa722d2c44e0 [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:17:58.823946 24678 tablet_replica.cc:333] T 00000000000000000000000000000000 P d4616b1438fe41e6a75ffa722d2c44e0: stopping tablet replica
I20260812 06:17:58.836459 24678 master.cc:584] Master@127.24.25.190:41071 shutdown complete.
[       OK ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/0 (5384 ms)
[ RUN      ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/1
I20260812 06:17:58.931181 24678 internal_mini_cluster.cc:156] Creating distributed mini masters. Addrs: 127.24.25.190:33669
I20260812 06:17:58.931632 24678 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:17:58.934183 24894 instance_detector.cc:116] could not retrieve OpenStack instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:17:58.934202 24678 server_base.cc:1061] running on GCE node
W20260812 06:17:58.934190 24892 instance_detector.cc:116] could not retrieve Azure instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:17:58.934451 24891 instance_detector.cc:116] could not retrieve AWS instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:17:58.934687 24678 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:17:58.934729 24678 system_unsync_time.cc:38] NTP support is disabled. Clock error bounds will not be accurate. This configuration is not suitable for distributed clusters.
I20260812 06:17:58.934746 24678 hybrid_clock.cc:648] HybridClock initialized: now 1786515478934746 us; error 0 us; skew 500 ppm
I20260812 06:17:58.935609 24678 webserver.cc:533] Webserver started at http://127.24.25.190:36395/ using document root <none> and password file <none>
I20260812 06:17:58.935760 24678 fs_manager.cc:362] Metadata directory not provided
I20260812 06:17:58.935806 24678 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:17:58.935940 24678 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:17:58.936407 24678 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskZSRD0G/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515473524603-24678-0/minicluster-data/master-0-root/instance:
uuid: "7e52605c27b0442b9d83c6215747f6d5"
format_stamp: "Formatted at 2026-08-12 06:17:58 on dist-test-slave-mvvj"
I20260812 06:17:58.937920 24678 fs_manager.cc:696] Time spent creating directory manager: real 0.001s	user 0.002s	sys 0.000s
I20260812 06:17:58.938848 24901 log_block_manager.cc:4127] Time spent loading block containers with low live blocks: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:17:58.939100 24678 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.001s	sys 0.000s
I20260812 06:17:58.939191 24678 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskZSRD0G/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515473524603-24678-0/minicluster-data/master-0-root
uuid: "7e52605c27b0442b9d83c6215747f6d5"
format_stamp: "Formatted at 2026-08-12 06:17:58 on dist-test-slave-mvvj"
I20260812 06:17:58.939278 24678 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskZSRD0G/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515473524603-24678-0/minicluster-data/master-0-root
metadata directory: /tmp/dist-test-taskZSRD0G/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515473524603-24678-0/minicluster-data/master-0-root
1 data directories: /tmp/dist-test-taskZSRD0G/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515473524603-24678-0/minicluster-data/master-0-root/data
Total live blocks: 0
Total live bytes: 0
Total live bytes (after alignment): 0
Total number of LBM containers: 0 (0 full)
Did not check for missing blocks
Did not check for orphaned blocks
Total full LBM containers with extra space: 0 (0 repaired)
Total full LBM container extra space in bytes: 0 (0 repaired)
Total incomplete LBM containers: 0 (0 repaired)
Total LBM partial records: 0 (0 repaired)
Total corrupted LBM metadata records in RocksDB: 0 (0 repaired)
I20260812 06:17:58.943477 24678 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:17:58.943951 24678 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:17:58.948374 24678 rpc_server.cc:307] RPC server started. Bound to: 127.24.25.190:33669
I20260812 06:17:58.949710 24960 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.24.25.190:33669 every 8 connection(s)
I20260812 06:17:58.950265 24961 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet 00000000000000000000000000000000. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:17:58.959383 24961 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P 7e52605c27b0442b9d83c6215747f6d5: Bootstrap starting.
I20260812 06:17:58.960371 24961 tablet_bootstrap.cc:654] T 00000000000000000000000000000000 P 7e52605c27b0442b9d83c6215747f6d5: Neither blocks nor log segments found. Creating new log.
I20260812 06:17:58.961519 24961 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P 7e52605c27b0442b9d83c6215747f6d5: No bootstrap required, opened a new log
I20260812 06:17:58.961935 24961 raft_consensus.cc:359] T 00000000000000000000000000000000 P 7e52605c27b0442b9d83c6215747f6d5 [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "7e52605c27b0442b9d83c6215747f6d5" member_type: VOTER }
I20260812 06:17:58.962028 24961 raft_consensus.cc:385] T 00000000000000000000000000000000 P 7e52605c27b0442b9d83c6215747f6d5 [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:17:58.962050 24961 raft_consensus.cc:740] T 00000000000000000000000000000000 P 7e52605c27b0442b9d83c6215747f6d5 [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: 7e52605c27b0442b9d83c6215747f6d5, State: Initialized, Role: FOLLOWER
I20260812 06:17:58.962158 24961 consensus_queue.cc:260] T 00000000000000000000000000000000 P 7e52605c27b0442b9d83c6215747f6d5 [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: "7e52605c27b0442b9d83c6215747f6d5" member_type: VOTER }
I20260812 06:17:58.962216 24961 raft_consensus.cc:399] T 00000000000000000000000000000000 P 7e52605c27b0442b9d83c6215747f6d5 [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:17:58.962239 24961 raft_consensus.cc:493] T 00000000000000000000000000000000 P 7e52605c27b0442b9d83c6215747f6d5 [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:17:58.962270 24961 raft_consensus.cc:3060] T 00000000000000000000000000000000 P 7e52605c27b0442b9d83c6215747f6d5 [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:17:58.963006 24961 raft_consensus.cc:515] T 00000000000000000000000000000000 P 7e52605c27b0442b9d83c6215747f6d5 [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "7e52605c27b0442b9d83c6215747f6d5" member_type: VOTER }
I20260812 06:17:58.963127 24961 leader_election.cc:304] T 00000000000000000000000000000000 P 7e52605c27b0442b9d83c6215747f6d5 [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: 7e52605c27b0442b9d83c6215747f6d5; no voters: 
I20260812 06:17:58.963303 24961 leader_election.cc:290] T 00000000000000000000000000000000 P 7e52605c27b0442b9d83c6215747f6d5 [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:17:58.963471 24964 raft_consensus.cc:2804] T 00000000000000000000000000000000 P 7e52605c27b0442b9d83c6215747f6d5 [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:17:58.963665 24964 raft_consensus.cc:697] T 00000000000000000000000000000000 P 7e52605c27b0442b9d83c6215747f6d5 [term 1 LEADER]: Becoming Leader. State: Replica: 7e52605c27b0442b9d83c6215747f6d5, State: Running, Role: LEADER
I20260812 06:17:58.963825 24964 consensus_queue.cc:237] T 00000000000000000000000000000000 P 7e52605c27b0442b9d83c6215747f6d5 [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: "7e52605c27b0442b9d83c6215747f6d5" member_type: VOTER }
I20260812 06:17:58.963910 24961 sys_catalog.cc:565] T 00000000000000000000000000000000 P 7e52605c27b0442b9d83c6215747f6d5 [sys.catalog]: configured and running, proceeding with master startup.
I20260812 06:17:58.964298 24966 sys_catalog.cc:455] T 00000000000000000000000000000000 P 7e52605c27b0442b9d83c6215747f6d5 [sys.catalog]: SysCatalogTable state changed. Reason: RaftConsensus started. Latest consensus state: current_term: 1 leader_uuid: "7e52605c27b0442b9d83c6215747f6d5" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "7e52605c27b0442b9d83c6215747f6d5" member_type: VOTER } }
I20260812 06:17:58.964315 24967 sys_catalog.cc:455] T 00000000000000000000000000000000 P 7e52605c27b0442b9d83c6215747f6d5 [sys.catalog]: SysCatalogTable state changed. Reason: New leader 7e52605c27b0442b9d83c6215747f6d5. Latest consensus state: current_term: 1 leader_uuid: "7e52605c27b0442b9d83c6215747f6d5" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "7e52605c27b0442b9d83c6215747f6d5" member_type: VOTER } }
I20260812 06:17:58.964473 24966 sys_catalog.cc:458] T 00000000000000000000000000000000 P 7e52605c27b0442b9d83c6215747f6d5 [sys.catalog]: This master's current role is: LEADER
I20260812 06:17:58.964504 24967 sys_catalog.cc:458] T 00000000000000000000000000000000 P 7e52605c27b0442b9d83c6215747f6d5 [sys.catalog]: This master's current role is: LEADER
I20260812 06:17:58.965112 24969 catalog_manager.cc:1511] Loading table and tablet metadata into memory...
I20260812 06:17:58.965799 24969 catalog_manager.cc:1520] Initializing Kudu cluster ID...
I20260812 06:17:58.965979 24678 internal_mini_cluster.cc:184] Waiting to initialize catalog manager on master 0
I20260812 06:17:58.967998 24969 catalog_manager.cc:1383] Generated new cluster ID: eb48a322728a47f1a4da896c10b0eeb6
I20260812 06:17:58.968068 24969 catalog_manager.cc:1531] Initializing Kudu internal certificate authority...
I20260812 06:17:58.983714 24969 catalog_manager.cc:1406] Generated new certificate authority record
I20260812 06:17:58.984460 24969 catalog_manager.cc:1540] Loading token signing keys...
I20260812 06:17:59.010520 24969 catalog_manager.cc:6092] T 00000000000000000000000000000000 P 7e52605c27b0442b9d83c6215747f6d5: Generated new TSK 0
I20260812 06:17:59.010742 24969 catalog_manager.cc:1550] Initializing in-progress tserver states...
I20260812 06:17:59.030911 24678 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:17:59.033241 24984 instance_detector.cc:116] could not retrieve AWS instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:17:59.033378 24678 server_base.cc:1061] running on GCE node
W20260812 06:17:59.033250 24985 instance_detector.cc:116] could not retrieve Azure instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:17:59.033250 24988 instance_detector.cc:116] could not retrieve OpenStack instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:17:59.033778 24678 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:17:59.033821 24678 system_unsync_time.cc:38] NTP support is disabled. Clock error bounds will not be accurate. This configuration is not suitable for distributed clusters.
I20260812 06:17:59.033836 24678 hybrid_clock.cc:648] HybridClock initialized: now 1786515479033837 us; error 0 us; skew 500 ppm
I20260812 06:17:59.034693 24678 webserver.cc:533] Webserver started at http://127.24.25.129:45467/ using document root <none> and password file <none>
I20260812 06:17:59.034837 24678 fs_manager.cc:362] Metadata directory not provided
I20260812 06:17:59.034893 24678 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:17:59.034951 24678 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:17:59.035310 24678 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskZSRD0G/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515473524603-24678-0/minicluster-data/ts-0-root/instance:
uuid: "8175aef9d2144665a5ba6fc0218242f7"
format_stamp: "Formatted at 2026-08-12 06:17:59 on dist-test-slave-mvvj"
I20260812 06:17:59.036900 24678 fs_manager.cc:696] Time spent creating directory manager: real 0.001s	user 0.000s	sys 0.002s
I20260812 06:17:59.037875 24993 log_block_manager.cc:4127] Time spent loading block containers with low live blocks: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:17:59.038241 24678 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.000s	sys 0.001s
I20260812 06:17:59.038341 24678 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskZSRD0G/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515473524603-24678-0/minicluster-data/ts-0-root
uuid: "8175aef9d2144665a5ba6fc0218242f7"
format_stamp: "Formatted at 2026-08-12 06:17:59 on dist-test-slave-mvvj"
I20260812 06:17:59.038491 24678 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskZSRD0G/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515473524603-24678-0/minicluster-data/ts-0-root
metadata directory: /tmp/dist-test-taskZSRD0G/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515473524603-24678-0/minicluster-data/ts-0-root
1 data directories: /tmp/dist-test-taskZSRD0G/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515473524603-24678-0/minicluster-data/ts-0-root/data
Total live blocks: 0
Total live bytes: 0
Total live bytes (after alignment): 0
Total number of LBM containers: 0 (0 full)
Did not check for missing blocks
Did not check for orphaned blocks
Total full LBM containers with extra space: 0 (0 repaired)
Total full LBM container extra space in bytes: 0 (0 repaired)
Total incomplete LBM containers: 0 (0 repaired)
Total LBM partial records: 0 (0 repaired)
Total corrupted LBM metadata records in RocksDB: 0 (0 repaired)
I20260812 06:17:59.049557 24678 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:17:59.049976 24678 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:17:59.050290 24678 txn_system_client.cc:432] TxnSystemClient initialization is disabled...
I20260812 06:17:59.050751 24678 ts_tablet_manager.cc:585] Loaded tablet metadata (0 total tablets, 0 live tablets)
I20260812 06:17:59.050805 24678 ts_tablet_manager.cc:531] Time spent load tablet metadata: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:17:59.050863 24678 ts_tablet_manager.cc:616] Registered 0 tablets
I20260812 06:17:59.050895 24678 ts_tablet_manager.cc:595] Time spent register tablets: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:17:59.055368 24678 rpc_server.cc:307] RPC server started. Bound to: 127.24.25.129:40563
I20260812 06:17:59.055421 25065 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.24.25.129:40563 every 8 connection(s)
I20260812 06:17:59.064903 25066 heartbeater.cc:344] Connected to a master server at 127.24.25.190:33669
I20260812 06:17:59.065071 25066 heartbeater.cc:461] Registering TS with master...
I20260812 06:17:59.065356 25066 heartbeater.cc:507] Master 127.24.25.190:33669 requested a full tablet report, sending...
I20260812 06:17:59.066062 24919 ts_manager.cc:194] Registered new tserver with Master: 8175aef9d2144665a5ba6fc0218242f7 (127.24.25.129:40563)
I20260812 06:17:59.066820 24919 master_service.cc:502] Signed X509 certificate for tserver {username='slave'} at 127.0.0.1:58704
I20260812 06:17:59.067027 24678 internal_mini_cluster.cc:371] 1 TS(s) registered with all masters after 0.011175197s
I20260812 06:17:59.075511 24919 catalog_manager.cc:2283] Servicing CreateTable request from {username='slave'} at 127.0.0.1:58712:
name: "heavy-update-compaction-test"
schema {
  columns {
    name: "key"
    type: INT64
    is_key: true
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_a"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_b"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_c"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_d"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_e"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
}
num_replicas: 1
split_rows_range_bounds {
}
partition_schema {
  range_schema {
  }
}
I20260812 06:17:59.085631 25026 tablet_service.cc:1511] Processing CreateTablet for tablet 8c06d71c2b86460e8f9870570e92a643 (DEFAULT_TABLE table=heavy-update-compaction-test [id=04809c2cff9a4d3e9c93efe188094d60]), partition=
I20260812 06:17:59.085945 25026 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet 8c06d71c2b86460e8f9870570e92a643. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:17:59.087999 25080 tablet_bootstrap.cc:492] T 8c06d71c2b86460e8f9870570e92a643 P 8175aef9d2144665a5ba6fc0218242f7: Bootstrap starting.
I20260812 06:17:59.088960 25080 tablet_bootstrap.cc:654] T 8c06d71c2b86460e8f9870570e92a643 P 8175aef9d2144665a5ba6fc0218242f7: Neither blocks nor log segments found. Creating new log.
I20260812 06:17:59.090188 25080 tablet_bootstrap.cc:492] T 8c06d71c2b86460e8f9870570e92a643 P 8175aef9d2144665a5ba6fc0218242f7: No bootstrap required, opened a new log
I20260812 06:17:59.090296 25080 ts_tablet_manager.cc:1403] T 8c06d71c2b86460e8f9870570e92a643 P 8175aef9d2144665a5ba6fc0218242f7: Time spent bootstrapping tablet: real 0.002s	user 0.000s	sys 0.002s
I20260812 06:17:59.090890 25080 raft_consensus.cc:359] T 8c06d71c2b86460e8f9870570e92a643 P 8175aef9d2144665a5ba6fc0218242f7 [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "8175aef9d2144665a5ba6fc0218242f7" member_type: VOTER last_known_addr { host: "127.24.25.129" port: 40563 } }
I20260812 06:17:59.091022 25080 raft_consensus.cc:385] T 8c06d71c2b86460e8f9870570e92a643 P 8175aef9d2144665a5ba6fc0218242f7 [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:17:59.091095 25080 raft_consensus.cc:740] T 8c06d71c2b86460e8f9870570e92a643 P 8175aef9d2144665a5ba6fc0218242f7 [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: 8175aef9d2144665a5ba6fc0218242f7, State: Initialized, Role: FOLLOWER
I20260812 06:17:59.091256 25080 consensus_queue.cc:260] T 8c06d71c2b86460e8f9870570e92a643 P 8175aef9d2144665a5ba6fc0218242f7 [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: "8175aef9d2144665a5ba6fc0218242f7" member_type: VOTER last_known_addr { host: "127.24.25.129" port: 40563 } }
I20260812 06:17:59.091337 25080 raft_consensus.cc:399] T 8c06d71c2b86460e8f9870570e92a643 P 8175aef9d2144665a5ba6fc0218242f7 [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:17:59.091398 25080 raft_consensus.cc:493] T 8c06d71c2b86460e8f9870570e92a643 P 8175aef9d2144665a5ba6fc0218242f7 [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:17:59.091459 25080 raft_consensus.cc:3060] T 8c06d71c2b86460e8f9870570e92a643 P 8175aef9d2144665a5ba6fc0218242f7 [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:17:59.092324 25080 raft_consensus.cc:515] T 8c06d71c2b86460e8f9870570e92a643 P 8175aef9d2144665a5ba6fc0218242f7 [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "8175aef9d2144665a5ba6fc0218242f7" member_type: VOTER last_known_addr { host: "127.24.25.129" port: 40563 } }
I20260812 06:17:59.092486 25080 leader_election.cc:304] T 8c06d71c2b86460e8f9870570e92a643 P 8175aef9d2144665a5ba6fc0218242f7 [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: 8175aef9d2144665a5ba6fc0218242f7; no voters: 
I20260812 06:17:59.092743 25080 leader_election.cc:290] T 8c06d71c2b86460e8f9870570e92a643 P 8175aef9d2144665a5ba6fc0218242f7 [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:17:59.092898 25083 raft_consensus.cc:2804] T 8c06d71c2b86460e8f9870570e92a643 P 8175aef9d2144665a5ba6fc0218242f7 [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:17:59.093124 25083 raft_consensus.cc:697] T 8c06d71c2b86460e8f9870570e92a643 P 8175aef9d2144665a5ba6fc0218242f7 [term 1 LEADER]: Becoming Leader. State: Replica: 8175aef9d2144665a5ba6fc0218242f7, State: Running, Role: LEADER
I20260812 06:17:59.093201 25066 heartbeater.cc:499] Master 127.24.25.190:33669 was elected leader, sending a full tablet report...
I20260812 06:17:59.093163 25080 ts_tablet_manager.cc:1434] T 8c06d71c2b86460e8f9870570e92a643 P 8175aef9d2144665a5ba6fc0218242f7: Time spent starting tablet: real 0.003s	user 0.003s	sys 0.001s
I20260812 06:17:59.093335 25083 consensus_queue.cc:237] T 8c06d71c2b86460e8f9870570e92a643 P 8175aef9d2144665a5ba6fc0218242f7 [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: "8175aef9d2144665a5ba6fc0218242f7" member_type: VOTER last_known_addr { host: "127.24.25.129" port: 40563 } }
I20260812 06:17:59.094774 24919 catalog_manager.cc:5719] T 8c06d71c2b86460e8f9870570e92a643 P 8175aef9d2144665a5ba6fc0218242f7 reported cstate change: term changed from 0 to 1, leader changed from <none> to 8175aef9d2144665a5ba6fc0218242f7 (127.24.25.129). New cstate: current_term: 1 leader_uuid: "8175aef9d2144665a5ba6fc0218242f7" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "8175aef9d2144665a5ba6fc0218242f7" member_type: VOTER last_known_addr { host: "127.24.25.129" port: 40563 } health_report { overall_health: HEALTHY } } }
I20260812 06:17:59.158807 24678 heavy-update-compaction-itest.cc:215] Time spent inserting: real 0.057s	user 0.017s	sys 0.008s
I20260812 06:17:59.306527 25067 maintenance_manager.cc:419] P 8175aef9d2144665a5ba6fc0218242f7: Scheduling FlushMRSOp(8c06d71c2b86460e8f9870570e92a643): perf score=19.054940
I20260812 06:17:59.457913 24998 maintenance_manager.cc:643] P 8175aef9d2144665a5ba6fc0218242f7: FlushMRSOp(8c06d71c2b86460e8f9870570e92a643) complete. Timing: real 0.151s	user 0.117s	sys 0.032s Metrics: {"bytes_written":12307490,"cfile_init":1,"delete_count":0,"dirs.queue_time_us":75,"dirs.run_cpu_time_us":221,"dirs.run_wall_time_us":880,"drs_written":1,"lbm_read_time_us":39,"lbm_reads_lt_1ms":4,"lbm_write_time_us":39197,"lbm_writes_lt_1ms":757,"peak_mem_usage":0,"reinsert_count":0,"rows_written":104,"update_count":1500}
I20260812 06:17:59.458876 25067 maintenance_manager.cc:419] P 8175aef9d2144665a5ba6fc0218242f7: Scheduling LogGCOp(8c06d71c2b86460e8f9870570e92a643): free 20743831 bytes of WAL
I20260812 06:17:59.459189 24998 log_reader.cc:385] T 8c06d71c2b86460e8f9870570e92a643: removed 2 log segments from log reader
I20260812 06:17:59.459241 24998 log.cc:1079] T 8c06d71c2b86460e8f9870570e92a643 P 8175aef9d2144665a5ba6fc0218242f7: Deleting log segment in path: /tmp/dist-test-taskZSRD0G/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515473524603-24678-0/minicluster-data/ts-0-root/wals/8c06d71c2b86460e8f9870570e92a643/wal-000000001 (ops 1-6)
I20260812 06:17:59.459287 24998 log.cc:1079] T 8c06d71c2b86460e8f9870570e92a643 P 8175aef9d2144665a5ba6fc0218242f7: Deleting log segment in path: /tmp/dist-test-taskZSRD0G/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515473524603-24678-0/minicluster-data/ts-0-root/wals/8c06d71c2b86460e8f9870570e92a643/wal-000000002 (ops 7-11)
I20260812 06:17:59.464274 24998 maintenance_manager.cc:643] P 8175aef9d2144665a5ba6fc0218242f7: LogGCOp(8c06d71c2b86460e8f9870570e92a643) complete. Timing: real 0.005s	user 0.000s	sys 0.005s Metrics: {}
I20260812 06:17:59.464783 25067 maintenance_manager.cc:419] P 8175aef9d2144665a5ba6fc0218242f7: Scheduling FlushDeltaMemStoresOp(8c06d71c2b86460e8f9870570e92a643): perf score=2.188937
I20260812 06:17:59.478044 24998 maintenance_manager.cc:643] P 8175aef9d2144665a5ba6fc0218242f7: FlushDeltaMemStoresOp(8c06d71c2b86460e8f9870570e92a643) complete. Timing: real 0.013s	user 0.008s	sys 0.003s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4745,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:59.478543 25067 maintenance_manager.cc:419] P 8175aef9d2144665a5ba6fc0218242f7: Scheduling MajorDeltaCompactionOp(8c06d71c2b86460e8f9870570e92a643): perf score=1.000000
I20260812 06:17:59.631541 24998 maintenance_manager.cc:643] P 8175aef9d2144665a5ba6fc0218242f7: MajorDeltaCompactionOp(8c06d71c2b86460e8f9870570e92a643) complete. Timing: real 0.153s	user 0.105s	sys 0.048s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672276,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":967,"lbm_read_time_us":9985,"lbm_reads_lt_1ms":464,"lbm_write_time_us":24310,"lbm_writes_lt_1ms":443,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":768,"thread_start_us":372,"threads_started":5,"update_count":2000}
I20260812 06:17:59.632318 25067 maintenance_manager.cc:419] P 8175aef9d2144665a5ba6fc0218242f7: Scheduling UndoDeltaBlockGCOp(8c06d71c2b86460e8f9870570e92a643): 16411394 bytes on disk
I20260812 06:17:59.634092 24998 maintenance_manager.cc:643] P 8175aef9d2144665a5ba6fc0218242f7: UndoDeltaBlockGCOp(8c06d71c2b86460e8f9870570e92a643) complete. Timing: real 0.002s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":71,"lbm_reads_lt_1ms":4}
I20260812 06:17:59.634742 25067 maintenance_manager.cc:419] P 8175aef9d2144665a5ba6fc0218242f7: Scheduling FlushDeltaMemStoresOp(8c06d71c2b86460e8f9870570e92a643): perf score=12.110812
I20260812 06:17:59.702481 24998 maintenance_manager.cc:643] P 8175aef9d2144665a5ba6fc0218242f7: FlushDeltaMemStoresOp(8c06d71c2b86460e8f9870570e92a643) complete. Timing: real 0.068s	user 0.044s	sys 0.020s Metrics: {"bytes_written":13948452,"delete_count":0,"lbm_write_time_us":28179,"lbm_writes_lt_1ms":343,"reinsert_count":0,"update_count":1700}
I20260812 06:17:59.703645 25067 maintenance_manager.cc:419] P 8175aef9d2144665a5ba6fc0218242f7: Scheduling FlushDeltaMemStoresOp(8c06d71c2b86460e8f9870570e92a643): perf score=1.196750
I20260812 06:17:59.727777 24998 maintenance_manager.cc:643] P 8175aef9d2144665a5ba6fc0218242f7: FlushDeltaMemStoresOp(8c06d71c2b86460e8f9870570e92a643) complete. Timing: real 0.024s	user 0.002s	sys 0.009s Metrics: {"bytes_written":2871909,"delete_count":0,"lbm_write_time_us":4744,"lbm_writes_lt_1ms":73,"reinsert_count":0,"update_count":350}
I20260812 06:17:59.728513 25067 maintenance_manager.cc:419] P 8175aef9d2144665a5ba6fc0218242f7: Scheduling FlushDeltaMemStoresOp(8c06d71c2b86460e8f9870570e92a643): perf score=2.188937
I20260812 06:17:59.745039 24998 maintenance_manager.cc:643] P 8175aef9d2144665a5ba6fc0218242f7: FlushDeltaMemStoresOp(8c06d71c2b86460e8f9870570e92a643) complete. Timing: real 0.016s	user 0.010s	sys 0.005s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":6386,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:17:59.745940 25067 maintenance_manager.cc:419] P 8175aef9d2144665a5ba6fc0218242f7: Scheduling MajorDeltaCompactionOp(8c06d71c2b86460e8f9870570e92a643): perf score=1.000000
I20260812 06:18:00.048915 24998 maintenance_manager.cc:643] P 8175aef9d2144665a5ba6fc0218242f7: MajorDeltaCompactionOp(8c06d71c2b86460e8f9870570e92a643) complete. Timing: real 0.303s	user 0.184s	sys 0.110s Metrics: {"cfile_cache_miss":533,"cfile_cache_miss_bytes":24774766,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":1400,"lbm_read_time_us":21186,"lbm_reads_lt_1ms":573,"lbm_write_time_us":52453,"lbm_writes_lt_1ms":543,"mutex_wait_us":524,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":1280,"update_count":2500}
I20260812 06:18:00.050056 25067 maintenance_manager.cc:419] P 8175aef9d2144665a5ba6fc0218242f7: Scheduling FlushDeltaMemStoresOp(8c06d71c2b86460e8f9870570e92a643): perf score=14.095187
I20260812 06:18:00.152983 24998 maintenance_manager.cc:643] P 8175aef9d2144665a5ba6fc0218242f7: FlushDeltaMemStoresOp(8c06d71c2b86460e8f9870570e92a643) complete. Timing: real 0.103s	user 0.041s	sys 0.052s Metrics: {"bytes_written":16409900,"delete_count":0,"lbm_write_time_us":42572,"lbm_writes_lt_1ms":403,"reinsert_count":0,"spinlock_wait_cycles":1408,"update_count":2000}
I20260812 06:18:00.153975 25067 maintenance_manager.cc:419] P 8175aef9d2144665a5ba6fc0218242f7: Scheduling FlushDeltaMemStoresOp(8c06d71c2b86460e8f9870570e92a643): perf score=2.188937
I20260812 06:18:00.174345 24998 maintenance_manager.cc:643] P 8175aef9d2144665a5ba6fc0218242f7: FlushDeltaMemStoresOp(8c06d71c2b86460e8f9870570e92a643) complete. Timing: real 0.020s	user 0.017s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":7635,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:00.175657 25067 maintenance_manager.cc:419] P 8175aef9d2144665a5ba6fc0218242f7: Scheduling MajorDeltaCompactionOp(8c06d71c2b86460e8f9870570e92a643): perf score=1.000000
I20260812 06:18:00.437989 24998 maintenance_manager.cc:643] P 8175aef9d2144665a5ba6fc0218242f7: MajorDeltaCompactionOp(8c06d71c2b86460e8f9870570e92a643) complete. Timing: real 0.262s	user 0.173s	sys 0.088s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774687,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":811,"lbm_read_time_us":18957,"lbm_reads_lt_1ms":572,"lbm_write_time_us":45643,"lbm_writes_lt_1ms":543,"mutex_wait_us":35,"peak_mem_usage":63115900,"reinsert_count":0,"update_count":2500}
I20260812 06:18:00.439075 25067 maintenance_manager.cc:419] P 8175aef9d2144665a5ba6fc0218242f7: Scheduling FlushDeltaMemStoresOp(8c06d71c2b86460e8f9870570e92a643): perf score=14.095187
I20260812 06:18:00.526389 24998 maintenance_manager.cc:643] P 8175aef9d2144665a5ba6fc0218242f7: FlushDeltaMemStoresOp(8c06d71c2b86460e8f9870570e92a643) complete. Timing: real 0.087s	user 0.041s	sys 0.043s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":35168,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:18:00.527462 25067 maintenance_manager.cc:419] P 8175aef9d2144665a5ba6fc0218242f7: Scheduling FlushDeltaMemStoresOp(8c06d71c2b86460e8f9870570e92a643): perf score=2.188937
I20260812 06:18:00.544695 24998 maintenance_manager.cc:643] P 8175aef9d2144665a5ba6fc0218242f7: FlushDeltaMemStoresOp(8c06d71c2b86460e8f9870570e92a643) complete. Timing: real 0.017s	user 0.009s	sys 0.007s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6788,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:00.545359 25067 maintenance_manager.cc:419] P 8175aef9d2144665a5ba6fc0218242f7: Scheduling MajorDeltaCompactionOp(8c06d71c2b86460e8f9870570e92a643): perf score=1.000000
I20260812 06:18:00.849539 24998 maintenance_manager.cc:643] P 8175aef9d2144665a5ba6fc0218242f7: MajorDeltaCompactionOp(8c06d71c2b86460e8f9870570e92a643) complete. Timing: real 0.304s	user 0.221s	sys 0.080s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774689,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":1505,"lbm_read_time_us":21434,"lbm_reads_lt_1ms":572,"lbm_write_time_us":52426,"lbm_writes_lt_1ms":543,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":3456,"update_count":2500}
I20260812 06:18:00.850739 25067 maintenance_manager.cc:419] P 8175aef9d2144665a5ba6fc0218242f7: Scheduling FlushDeltaMemStoresOp(8c06d71c2b86460e8f9870570e92a643): perf score=14.095187
I20260812 06:18:00.957180 24998 maintenance_manager.cc:643] P 8175aef9d2144665a5ba6fc0218242f7: FlushDeltaMemStoresOp(8c06d71c2b86460e8f9870570e92a643) complete. Timing: real 0.106s	user 0.054s	sys 0.051s Metrics: {"bytes_written":16409898,"delete_count":0,"lbm_write_time_us":41643,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:18:00.958056 25067 maintenance_manager.cc:419] P 8175aef9d2144665a5ba6fc0218242f7: Scheduling FlushDeltaMemStoresOp(8c06d71c2b86460e8f9870570e92a643): perf score=2.188937
I20260812 06:18:00.980842 24998 maintenance_manager.cc:643] P 8175aef9d2144665a5ba6fc0218242f7: FlushDeltaMemStoresOp(8c06d71c2b86460e8f9870570e92a643) complete. Timing: real 0.022s	user 0.014s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":9322,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:00.981600 25067 maintenance_manager.cc:419] P 8175aef9d2144665a5ba6fc0218242f7: Scheduling MajorDeltaCompactionOp(8c06d71c2b86460e8f9870570e92a643): perf score=1.000000
I20260812 06:18:01.313057 24998 maintenance_manager.cc:643] P 8175aef9d2144665a5ba6fc0218242f7: MajorDeltaCompactionOp(8c06d71c2b86460e8f9870570e92a643) complete. Timing: real 0.331s	user 0.185s	sys 0.133s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774685,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":1464,"lbm_read_time_us":25122,"lbm_reads_lt_1ms":572,"lbm_write_time_us":56940,"lbm_writes_lt_1ms":543,"mutex_wait_us":250,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":3840,"update_count":2500}
I20260812 06:18:01.313958 25067 maintenance_manager.cc:419] P 8175aef9d2144665a5ba6fc0218242f7: Scheduling FlushDeltaMemStoresOp(8c06d71c2b86460e8f9870570e92a643): perf score=14.095187
I20260812 06:18:01.399546 24998 maintenance_manager.cc:643] P 8175aef9d2144665a5ba6fc0218242f7: FlushDeltaMemStoresOp(8c06d71c2b86460e8f9870570e92a643) complete. Timing: real 0.085s	user 0.057s	sys 0.019s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":35809,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:18:01.400575 25067 maintenance_manager.cc:419] P 8175aef9d2144665a5ba6fc0218242f7: Scheduling FlushDeltaMemStoresOp(8c06d71c2b86460e8f9870570e92a643): perf score=2.188937
I20260812 06:18:01.424394 24998 maintenance_manager.cc:643] P 8175aef9d2144665a5ba6fc0218242f7: FlushDeltaMemStoresOp(8c06d71c2b86460e8f9870570e92a643) complete. Timing: real 0.023s	user 0.014s	sys 0.009s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":8962,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:01.425145 25067 maintenance_manager.cc:419] P 8175aef9d2144665a5ba6fc0218242f7: Scheduling FlushMRSOp(8c06d71c2b86460e8f9870570e92a643): perf score=1.000000
I20260812 06:18:01.505334 24998 maintenance_manager.cc:643] P 8175aef9d2144665a5ba6fc0218242f7: FlushMRSOp(8c06d71c2b86460e8f9870570e92a643) complete. Timing: real 0.080s	user 0.054s	sys 0.006s Metrics: {"bytes_written":1193503,"cfile_init":1,"dirs.queue_time_us":78,"dirs.run_cpu_time_us":375,"dirs.run_wall_time_us":1921,"drs_written":1,"lbm_read_time_us":65,"lbm_reads_lt_1ms":4,"lbm_write_time_us":3198,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":29}
I20260812 06:18:01.506387 25067 maintenance_manager.cc:419] P 8175aef9d2144665a5ba6fc0218242f7: Scheduling LogGCOp(8c06d71c2b86460e8f9870570e92a643): free 120553378 bytes of WAL
I20260812 06:18:01.506819 24998 log_reader.cc:385] T 8c06d71c2b86460e8f9870570e92a643: removed 12 log segments from log reader
I20260812 06:18:01.506886 24998 log.cc:1079] T 8c06d71c2b86460e8f9870570e92a643 P 8175aef9d2144665a5ba6fc0218242f7: Deleting log segment in path: /tmp/dist-test-taskZSRD0G/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515473524603-24678-0/minicluster-data/ts-0-root/wals/8c06d71c2b86460e8f9870570e92a643/wal-000000003 (ops 12-16)
I20260812 06:18:01.506928 24998 log.cc:1079] T 8c06d71c2b86460e8f9870570e92a643 P 8175aef9d2144665a5ba6fc0218242f7: Deleting log segment in path: /tmp/dist-test-taskZSRD0G/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515473524603-24678-0/minicluster-data/ts-0-root/wals/8c06d71c2b86460e8f9870570e92a643/wal-000000004 (ops 17-21)
I20260812 06:18:01.507056 24998 log.cc:1079] T 8c06d71c2b86460e8f9870570e92a643 P 8175aef9d2144665a5ba6fc0218242f7: Deleting log segment in path: /tmp/dist-test-taskZSRD0G/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515473524603-24678-0/minicluster-data/ts-0-root/wals/8c06d71c2b86460e8f9870570e92a643/wal-000000005 (ops 22-26)
I20260812 06:18:01.507139 24998 log.cc:1079] T 8c06d71c2b86460e8f9870570e92a643 P 8175aef9d2144665a5ba6fc0218242f7: Deleting log segment in path: /tmp/dist-test-taskZSRD0G/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515473524603-24678-0/minicluster-data/ts-0-root/wals/8c06d71c2b86460e8f9870570e92a643/wal-000000006 (ops 27-31)
I20260812 06:18:01.507231 24998 log.cc:1079] T 8c06d71c2b86460e8f9870570e92a643 P 8175aef9d2144665a5ba6fc0218242f7: Deleting log segment in path: /tmp/dist-test-taskZSRD0G/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515473524603-24678-0/minicluster-data/ts-0-root/wals/8c06d71c2b86460e8f9870570e92a643/wal-000000007 (ops 32-36)
I20260812 06:18:01.507323 24998 log.cc:1079] T 8c06d71c2b86460e8f9870570e92a643 P 8175aef9d2144665a5ba6fc0218242f7: Deleting log segment in path: /tmp/dist-test-taskZSRD0G/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515473524603-24678-0/minicluster-data/ts-0-root/wals/8c06d71c2b86460e8f9870570e92a643/wal-000000008 (ops 37-40)
I20260812 06:18:01.507413 24998 log.cc:1079] T 8c06d71c2b86460e8f9870570e92a643 P 8175aef9d2144665a5ba6fc0218242f7: Deleting log segment in path: /tmp/dist-test-taskZSRD0G/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515473524603-24678-0/minicluster-data/ts-0-root/wals/8c06d71c2b86460e8f9870570e92a643/wal-000000009 (ops 41-45)
I20260812 06:18:01.507480 24998 log.cc:1079] T 8c06d71c2b86460e8f9870570e92a643 P 8175aef9d2144665a5ba6fc0218242f7: Deleting log segment in path: /tmp/dist-test-taskZSRD0G/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515473524603-24678-0/minicluster-data/ts-0-root/wals/8c06d71c2b86460e8f9870570e92a643/wal-000000010 (ops 46-50)
I20260812 06:18:01.507553 24998 log.cc:1079] T 8c06d71c2b86460e8f9870570e92a643 P 8175aef9d2144665a5ba6fc0218242f7: Deleting log segment in path: /tmp/dist-test-taskZSRD0G/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515473524603-24678-0/minicluster-data/ts-0-root/wals/8c06d71c2b86460e8f9870570e92a643/wal-000000011 (ops 51-54)
I20260812 06:18:01.507632 24998 log.cc:1079] T 8c06d71c2b86460e8f9870570e92a643 P 8175aef9d2144665a5ba6fc0218242f7: Deleting log segment in path: /tmp/dist-test-taskZSRD0G/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515473524603-24678-0/minicluster-data/ts-0-root/wals/8c06d71c2b86460e8f9870570e92a643/wal-000000012 (ops 55-59)
I20260812 06:18:01.507707 24998 log.cc:1079] T 8c06d71c2b86460e8f9870570e92a643 P 8175aef9d2144665a5ba6fc0218242f7: Deleting log segment in path: /tmp/dist-test-taskZSRD0G/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515473524603-24678-0/minicluster-data/ts-0-root/wals/8c06d71c2b86460e8f9870570e92a643/wal-000000013 (ops 60-64)
I20260812 06:18:01.507781 24998 log.cc:1079] T 8c06d71c2b86460e8f9870570e92a643 P 8175aef9d2144665a5ba6fc0218242f7: Deleting log segment in path: /tmp/dist-test-taskZSRD0G/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515473524603-24678-0/minicluster-data/ts-0-root/wals/8c06d71c2b86460e8f9870570e92a643/wal-000000014 (ops 65-69)
I20260812 06:18:01.547197 24998 maintenance_manager.cc:643] P 8175aef9d2144665a5ba6fc0218242f7: LogGCOp(8c06d71c2b86460e8f9870570e92a643) complete. Timing: real 0.040s	user 0.000s	sys 0.037s Metrics: {}
I20260812 06:18:01.548010 25067 maintenance_manager.cc:419] P 8175aef9d2144665a5ba6fc0218242f7: Scheduling FlushDeltaMemStoresOp(8c06d71c2b86460e8f9870570e92a643): perf score=2.188937
I20260812 06:18:01.591176 24998 maintenance_manager.cc:643] P 8175aef9d2144665a5ba6fc0218242f7: FlushDeltaMemStoresOp(8c06d71c2b86460e8f9870570e92a643) complete. Timing: real 0.043s	user 0.004s	sys 0.014s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":8544,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:01.591981 25067 maintenance_manager.cc:419] P 8175aef9d2144665a5ba6fc0218242f7: Scheduling UndoDeltaBlockGCOp(8c06d71c2b86460e8f9870570e92a643): 462 bytes on disk
I20260812 06:18:01.592674 24998 maintenance_manager.cc:643] P 8175aef9d2144665a5ba6fc0218242f7: UndoDeltaBlockGCOp(8c06d71c2b86460e8f9870570e92a643) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":114,"lbm_reads_lt_1ms":4}
I20260812 06:18:01.593317 25067 maintenance_manager.cc:419] P 8175aef9d2144665a5ba6fc0218242f7: Scheduling FlushDeltaMemStoresOp(8c06d71c2b86460e8f9870570e92a643): perf score=2.188937
I20260812 06:18:01.611543 24998 maintenance_manager.cc:643] P 8175aef9d2144665a5ba6fc0218242f7: FlushDeltaMemStoresOp(8c06d71c2b86460e8f9870570e92a643) complete. Timing: real 0.018s	user 0.008s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":7218,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:01.612221 25067 maintenance_manager.cc:419] P 8175aef9d2144665a5ba6fc0218242f7: Scheduling MajorDeltaCompactionOp(8c06d71c2b86460e8f9870570e92a643): perf score=1.000000
I20260812 06:18:01.878204 24998 maintenance_manager.cc:643] P 8175aef9d2144665a5ba6fc0218242f7: MajorDeltaCompactionOp(8c06d71c2b86460e8f9870570e92a643) complete. Timing: real 0.266s	user 0.149s	sys 0.106s Metrics: {"cfile_cache_miss":734,"cfile_cache_miss_bytes":32979750,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":2247,"lbm_read_time_us":22749,"lbm_reads_lt_1ms":774,"lbm_write_time_us":38035,"lbm_writes_lt_1ms":743,"mutex_wait_us":779,"peak_mem_usage":87969044,"reinsert_count":0,"spinlock_wait_cycles":14592,"thread_start_us":466,"threads_started":6,"update_count":3500}
I20260812 06:18:01.878957 25067 maintenance_manager.cc:419] P 8175aef9d2144665a5ba6fc0218242f7: Scheduling FlushDeltaMemStoresOp(8c06d71c2b86460e8f9870570e92a643): perf score=18.063937
I20260812 06:18:01.935750 24998 maintenance_manager.cc:643] P 8175aef9d2144665a5ba6fc0218242f7: FlushDeltaMemStoresOp(8c06d71c2b86460e8f9870570e92a643) complete. Timing: real 0.057s	user 0.036s	sys 0.016s Metrics: {"bytes_written":20512315,"delete_count":0,"lbm_write_time_us":25299,"lbm_writes_lt_1ms":503,"reinsert_count":0,"update_count":2500}
I20260812 06:18:01.936372 25067 maintenance_manager.cc:419] P 8175aef9d2144665a5ba6fc0218242f7: Scheduling MajorDeltaCompactionOp(8c06d71c2b86460e8f9870570e92a643): perf score=1.000000
I20260812 06:18:02.106318 24998 maintenance_manager.cc:643] P 8175aef9d2144665a5ba6fc0218242f7: MajorDeltaCompactionOp(8c06d71c2b86460e8f9870570e92a643) complete. Timing: real 0.170s	user 0.104s	sys 0.065s Metrics: {"cfile_cache_miss":531,"cfile_cache_miss_bytes":24774571,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":1,"delta_iterators_relevant":1,"dirs.queue_time_us":190,"lbm_read_time_us":11552,"lbm_reads_lt_1ms":563,"lbm_write_time_us":28803,"lbm_writes_lt_1ms":543,"mutex_wait_us":31,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":9088,"update_count":2500}
I20260812 06:18:02.106982 25067 maintenance_manager.cc:419] P 8175aef9d2144665a5ba6fc0218242f7: Scheduling FlushDeltaMemStoresOp(8c06d71c2b86460e8f9870570e92a643): perf score=14.095187
I20260812 06:18:02.168638 24998 maintenance_manager.cc:643] P 8175aef9d2144665a5ba6fc0218242f7: FlushDeltaMemStoresOp(8c06d71c2b86460e8f9870570e92a643) complete. Timing: real 0.061s	user 0.034s	sys 0.022s Metrics: {"bytes_written":16409903,"delete_count":0,"lbm_write_time_us":19710,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:18:02.169329 25067 maintenance_manager.cc:419] P 8175aef9d2144665a5ba6fc0218242f7: Scheduling FlushDeltaMemStoresOp(8c06d71c2b86460e8f9870570e92a643): perf score=2.188937
I20260812 06:18:02.181079 24998 maintenance_manager.cc:643] P 8175aef9d2144665a5ba6fc0218242f7: FlushDeltaMemStoresOp(8c06d71c2b86460e8f9870570e92a643) complete. Timing: real 0.012s	user 0.010s	sys 0.001s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4619,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:02.181571 25067 maintenance_manager.cc:419] P 8175aef9d2144665a5ba6fc0218242f7: Scheduling MajorDeltaCompactionOp(8c06d71c2b86460e8f9870570e92a643): perf score=1.000000
I20260812 06:18:02.372733 24998 maintenance_manager.cc:643] P 8175aef9d2144665a5ba6fc0218242f7: MajorDeltaCompactionOp(8c06d71c2b86460e8f9870570e92a643) complete. Timing: real 0.191s	user 0.128s	sys 0.056s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774690,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":364,"lbm_read_time_us":13778,"lbm_reads_lt_1ms":572,"lbm_write_time_us":29310,"lbm_writes_lt_1ms":543,"mutex_wait_us":26,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":21248,"update_count":2500}
I20260812 06:18:02.373314 25067 maintenance_manager.cc:419] P 8175aef9d2144665a5ba6fc0218242f7: Scheduling FlushDeltaMemStoresOp(8c06d71c2b86460e8f9870570e92a643): perf score=14.095187
I20260812 06:18:02.430950 24998 maintenance_manager.cc:643] P 8175aef9d2144665a5ba6fc0218242f7: FlushDeltaMemStoresOp(8c06d71c2b86460e8f9870570e92a643) complete. Timing: real 0.057s	user 0.026s	sys 0.020s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":22165,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:18:02.431497 25067 maintenance_manager.cc:419] P 8175aef9d2144665a5ba6fc0218242f7: Scheduling FlushDeltaMemStoresOp(8c06d71c2b86460e8f9870570e92a643): perf score=2.188937
I20260812 06:18:02.454151 24998 maintenance_manager.cc:643] P 8175aef9d2144665a5ba6fc0218242f7: FlushDeltaMemStoresOp(8c06d71c2b86460e8f9870570e92a643) complete. Timing: real 0.022s	user 0.010s	sys 0.011s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5045,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:02.454687 25067 maintenance_manager.cc:419] P 8175aef9d2144665a5ba6fc0218242f7: Scheduling MajorDeltaCompactionOp(8c06d71c2b86460e8f9870570e92a643): perf score=1.000000
I20260812 06:18:02.644702 24998 maintenance_manager.cc:643] P 8175aef9d2144665a5ba6fc0218242f7: MajorDeltaCompactionOp(8c06d71c2b86460e8f9870570e92a643) complete. Timing: real 0.190s	user 0.123s	sys 0.056s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774688,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":702,"lbm_read_time_us":12862,"lbm_reads_lt_1ms":572,"lbm_write_time_us":29016,"lbm_writes_lt_1ms":543,"mutex_wait_us":255,"peak_mem_usage":63115900,"reinsert_count":0,"update_count":2500}
I20260812 06:18:02.645226 25067 maintenance_manager.cc:419] P 8175aef9d2144665a5ba6fc0218242f7: Scheduling FlushDeltaMemStoresOp(8c06d71c2b86460e8f9870570e92a643): perf score=14.095187
I20260812 06:18:02.696399 24998 maintenance_manager.cc:643] P 8175aef9d2144665a5ba6fc0218242f7: FlushDeltaMemStoresOp(8c06d71c2b86460e8f9870570e92a643) complete. Timing: real 0.051s	user 0.031s	sys 0.011s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":19129,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:18:02.696908 25067 maintenance_manager.cc:419] P 8175aef9d2144665a5ba6fc0218242f7: Scheduling FlushDeltaMemStoresOp(8c06d71c2b86460e8f9870570e92a643): perf score=2.188937
I20260812 06:18:02.709159 24998 maintenance_manager.cc:643] P 8175aef9d2144665a5ba6fc0218242f7: FlushDeltaMemStoresOp(8c06d71c2b86460e8f9870570e92a643) complete. Timing: real 0.012s	user 0.006s	sys 0.004s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4329,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:02.709632 25067 maintenance_manager.cc:419] P 8175aef9d2144665a5ba6fc0218242f7: Scheduling MajorDeltaCompactionOp(8c06d71c2b86460e8f9870570e92a643): perf score=1.000000
I20260812 06:18:02.920084 24998 maintenance_manager.cc:643] P 8175aef9d2144665a5ba6fc0218242f7: MajorDeltaCompactionOp(8c06d71c2b86460e8f9870570e92a643) complete. Timing: real 0.210s	user 0.156s	sys 0.046s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774688,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":610,"lbm_read_time_us":11989,"lbm_reads_lt_1ms":572,"lbm_write_time_us":35643,"lbm_writes_lt_1ms":543,"mutex_wait_us":53,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":11904,"update_count":2500}
I20260812 06:18:02.922097 25067 maintenance_manager.cc:419] P 8175aef9d2144665a5ba6fc0218242f7: Scheduling FlushDeltaMemStoresOp(8c06d71c2b86460e8f9870570e92a643): perf score=14.095187
I20260812 06:18:02.974246 24998 maintenance_manager.cc:643] P 8175aef9d2144665a5ba6fc0218242f7: FlushDeltaMemStoresOp(8c06d71c2b86460e8f9870570e92a643) complete. Timing: real 0.052s	user 0.034s	sys 0.016s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":23210,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:18:02.974844 25067 maintenance_manager.cc:419] P 8175aef9d2144665a5ba6fc0218242f7: Scheduling FlushDeltaMemStoresOp(8c06d71c2b86460e8f9870570e92a643): perf score=2.188937
I20260812 06:18:02.992151 24998 maintenance_manager.cc:643] P 8175aef9d2144665a5ba6fc0218242f7: FlushDeltaMemStoresOp(8c06d71c2b86460e8f9870570e92a643) complete. Timing: real 0.017s	user 0.012s	sys 0.003s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5989,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:02.992657 25067 maintenance_manager.cc:419] P 8175aef9d2144665a5ba6fc0218242f7: Scheduling MajorDeltaCompactionOp(8c06d71c2b86460e8f9870570e92a643): perf score=1.000000
I20260812 06:18:03.162014 24998 maintenance_manager.cc:643] P 8175aef9d2144665a5ba6fc0218242f7: MajorDeltaCompactionOp(8c06d71c2b86460e8f9870570e92a643) complete. Timing: real 0.169s	user 0.115s	sys 0.043s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774689,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":340,"lbm_read_time_us":12345,"lbm_reads_1-10_ms":1,"lbm_reads_lt_1ms":563,"lbm_write_time_us":33021,"lbm_writes_lt_1ms":543,"mutex_wait_us":48,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":89728,"update_count":2500}
I20260812 06:18:03.162761 25067 maintenance_manager.cc:419] P 8175aef9d2144665a5ba6fc0218242f7: Scheduling FlushDeltaMemStoresOp(8c06d71c2b86460e8f9870570e92a643): perf score=14.095187
I20260812 06:18:03.211143 24998 maintenance_manager.cc:643] P 8175aef9d2144665a5ba6fc0218242f7: FlushDeltaMemStoresOp(8c06d71c2b86460e8f9870570e92a643) complete. Timing: real 0.048s	user 0.023s	sys 0.019s Metrics: {"bytes_written":16409904,"delete_count":0,"lbm_write_time_us":20086,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:18:03.211642 25067 maintenance_manager.cc:419] P 8175aef9d2144665a5ba6fc0218242f7: Scheduling FlushDeltaMemStoresOp(8c06d71c2b86460e8f9870570e92a643): perf score=2.188937
I20260812 06:18:03.223330 24998 maintenance_manager.cc:643] P 8175aef9d2144665a5ba6fc0218242f7: FlushDeltaMemStoresOp(8c06d71c2b86460e8f9870570e92a643) complete. Timing: real 0.011s	user 0.006s	sys 0.003s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4315,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:03.224139 25067 maintenance_manager.cc:419] P 8175aef9d2144665a5ba6fc0218242f7: Scheduling FlushMRSOp(8c06d71c2b86460e8f9870570e92a643): perf score=1.000000
I20260812 06:18:03.259274 24998 maintenance_manager.cc:643] P 8175aef9d2144665a5ba6fc0218242f7: FlushMRSOp(8c06d71c2b86460e8f9870570e92a643) complete. Timing: real 0.035s	user 0.033s	sys 0.000s Metrics: {"bytes_written":1316419,"cfile_init":1,"dirs.queue_time_us":59,"dirs.run_cpu_time_us":282,"dirs.run_wall_time_us":1567,"drs_written":1,"lbm_read_time_us":41,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1770,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":32}
I20260812 06:18:03.260069 25067 maintenance_manager.cc:419] P 8175aef9d2144665a5ba6fc0218242f7: Scheduling LogGCOp(8c06d71c2b86460e8f9870570e92a643): free 129320571 bytes of WAL
I20260812 06:18:03.260291 24998 log_reader.cc:385] T 8c06d71c2b86460e8f9870570e92a643: removed 13 log segments from log reader
I20260812 06:18:03.260360 24998 log.cc:1079] T 8c06d71c2b86460e8f9870570e92a643 P 8175aef9d2144665a5ba6fc0218242f7: Deleting log segment in path: /tmp/dist-test-taskZSRD0G/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515473524603-24678-0/minicluster-data/ts-0-root/wals/8c06d71c2b86460e8f9870570e92a643/wal-000000015 (ops 70-74)
I20260812 06:18:03.260419 24998 log.cc:1079] T 8c06d71c2b86460e8f9870570e92a643 P 8175aef9d2144665a5ba6fc0218242f7: Deleting log segment in path: /tmp/dist-test-taskZSRD0G/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515473524603-24678-0/minicluster-data/ts-0-root/wals/8c06d71c2b86460e8f9870570e92a643/wal-000000016 (ops 75-78)
I20260812 06:18:03.260475 24998 log.cc:1079] T 8c06d71c2b86460e8f9870570e92a643 P 8175aef9d2144665a5ba6fc0218242f7: Deleting log segment in path: /tmp/dist-test-taskZSRD0G/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515473524603-24678-0/minicluster-data/ts-0-root/wals/8c06d71c2b86460e8f9870570e92a643/wal-000000017 (ops 79-83)
I20260812 06:18:03.260520 24998 log.cc:1079] T 8c06d71c2b86460e8f9870570e92a643 P 8175aef9d2144665a5ba6fc0218242f7: Deleting log segment in path: /tmp/dist-test-taskZSRD0G/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515473524603-24678-0/minicluster-data/ts-0-root/wals/8c06d71c2b86460e8f9870570e92a643/wal-000000018 (ops 84-88)
I20260812 06:18:03.260558 24998 log.cc:1079] T 8c06d71c2b86460e8f9870570e92a643 P 8175aef9d2144665a5ba6fc0218242f7: Deleting log segment in path: /tmp/dist-test-taskZSRD0G/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515473524603-24678-0/minicluster-data/ts-0-root/wals/8c06d71c2b86460e8f9870570e92a643/wal-000000019 (ops 89-93)
I20260812 06:18:03.260597 24998 log.cc:1079] T 8c06d71c2b86460e8f9870570e92a643 P 8175aef9d2144665a5ba6fc0218242f7: Deleting log segment in path: /tmp/dist-test-taskZSRD0G/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515473524603-24678-0/minicluster-data/ts-0-root/wals/8c06d71c2b86460e8f9870570e92a643/wal-000000020 (ops 94-98)
I20260812 06:18:03.260637 24998 log.cc:1079] T 8c06d71c2b86460e8f9870570e92a643 P 8175aef9d2144665a5ba6fc0218242f7: Deleting log segment in path: /tmp/dist-test-taskZSRD0G/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515473524603-24678-0/minicluster-data/ts-0-root/wals/8c06d71c2b86460e8f9870570e92a643/wal-000000021 (ops 99-103)
I20260812 06:18:03.260674 24998 log.cc:1079] T 8c06d71c2b86460e8f9870570e92a643 P 8175aef9d2144665a5ba6fc0218242f7: Deleting log segment in path: /tmp/dist-test-taskZSRD0G/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515473524603-24678-0/minicluster-data/ts-0-root/wals/8c06d71c2b86460e8f9870570e92a643/wal-000000022 (ops 104-108)
I20260812 06:18:03.260713 24998 log.cc:1079] T 8c06d71c2b86460e8f9870570e92a643 P 8175aef9d2144665a5ba6fc0218242f7: Deleting log segment in path: /tmp/dist-test-taskZSRD0G/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515473524603-24678-0/minicluster-data/ts-0-root/wals/8c06d71c2b86460e8f9870570e92a643/wal-000000023 (ops 109-112)
I20260812 06:18:03.260752 24998 log.cc:1079] T 8c06d71c2b86460e8f9870570e92a643 P 8175aef9d2144665a5ba6fc0218242f7: Deleting log segment in path: /tmp/dist-test-taskZSRD0G/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515473524603-24678-0/minicluster-data/ts-0-root/wals/8c06d71c2b86460e8f9870570e92a643/wal-000000024 (ops 113-117)
I20260812 06:18:03.260792 24998 log.cc:1079] T 8c06d71c2b86460e8f9870570e92a643 P 8175aef9d2144665a5ba6fc0218242f7: Deleting log segment in path: /tmp/dist-test-taskZSRD0G/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515473524603-24678-0/minicluster-data/ts-0-root/wals/8c06d71c2b86460e8f9870570e92a643/wal-000000025 (ops 118-122)
I20260812 06:18:03.260830 24998 log.cc:1079] T 8c06d71c2b86460e8f9870570e92a643 P 8175aef9d2144665a5ba6fc0218242f7: Deleting log segment in path: /tmp/dist-test-taskZSRD0G/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515473524603-24678-0/minicluster-data/ts-0-root/wals/8c06d71c2b86460e8f9870570e92a643/wal-000000026 (ops 123-127)
I20260812 06:18:03.260871 24998 log.cc:1079] T 8c06d71c2b86460e8f9870570e92a643 P 8175aef9d2144665a5ba6fc0218242f7: Deleting log segment in path: /tmp/dist-test-taskZSRD0G/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515473524603-24678-0/minicluster-data/ts-0-root/wals/8c06d71c2b86460e8f9870570e92a643/wal-000000027 (ops 128-132)
I20260812 06:18:03.289274 24998 maintenance_manager.cc:643] P 8175aef9d2144665a5ba6fc0218242f7: LogGCOp(8c06d71c2b86460e8f9870570e92a643) complete. Timing: real 0.029s	user 0.000s	sys 0.028s Metrics: {}
I20260812 06:18:03.289762 25067 maintenance_manager.cc:419] P 8175aef9d2144665a5ba6fc0218242f7: Scheduling FlushDeltaMemStoresOp(8c06d71c2b86460e8f9870570e92a643): perf score=4.173312
I20260812 06:18:03.318526 24998 maintenance_manager.cc:643] P 8175aef9d2144665a5ba6fc0218242f7: FlushDeltaMemStoresOp(8c06d71c2b86460e8f9870570e92a643) complete. Timing: real 0.029s	user 0.015s	sys 0.011s Metrics: {"bytes_written":5825680,"delete_count":0,"lbm_write_time_us":7681,"lbm_writes_lt_1ms":145,"reinsert_count":0,"update_count":710}
I20260812 06:18:03.319149 25067 maintenance_manager.cc:419] P 8175aef9d2144665a5ba6fc0218242f7: Scheduling UndoDeltaBlockGCOp(8c06d71c2b86460e8f9870570e92a643): 493 bytes on disk
I20260812 06:18:03.319625 24998 maintenance_manager.cc:643] P 8175aef9d2144665a5ba6fc0218242f7: UndoDeltaBlockGCOp(8c06d71c2b86460e8f9870570e92a643) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":66,"lbm_reads_lt_1ms":4}
I20260812 06:18:03.320194 25067 maintenance_manager.cc:419] P 8175aef9d2144665a5ba6fc0218242f7: Scheduling FlushDeltaMemStoresOp(8c06d71c2b86460e8f9870570e92a643): perf score=1.196750
I20260812 06:18:03.327644 24998 maintenance_manager.cc:643] P 8175aef9d2144665a5ba6fc0218242f7: FlushDeltaMemStoresOp(8c06d71c2b86460e8f9870570e92a643) complete. Timing: real 0.007s	user 0.005s	sys 0.001s Metrics: {"bytes_written":2379604,"delete_count":0,"lbm_write_time_us":2490,"lbm_writes_lt_1ms":61,"reinsert_count":0,"update_count":290}
I20260812 06:18:03.328325 25067 maintenance_manager.cc:419] P 8175aef9d2144665a5ba6fc0218242f7: Scheduling MajorDeltaCompactionOp(8c06d71c2b86460e8f9870570e92a643): perf score=1.000000
I20260812 06:18:03.579041 24998 maintenance_manager.cc:643] P 8175aef9d2144665a5ba6fc0218242f7: MajorDeltaCompactionOp(8c06d71c2b86460e8f9870570e92a643) complete. Timing: real 0.250s	user 0.161s	sys 0.084s Metrics: {"cfile_cache_miss":734,"cfile_cache_miss_bytes":32979713,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":514,"lbm_read_time_us":18502,"lbm_reads_lt_1ms":774,"lbm_write_time_us":39923,"lbm_writes_lt_1ms":743,"peak_mem_usage":87969044,"reinsert_count":0,"spinlock_wait_cycles":768,"thread_start_us":85,"threads_started":1,"update_count":3500}
I20260812 06:18:03.580036 25067 maintenance_manager.cc:419] P 8175aef9d2144665a5ba6fc0218242f7: Scheduling FlushDeltaMemStoresOp(8c06d71c2b86460e8f9870570e92a643): perf score=15.087375
I20260812 06:18:03.654449 24998 maintenance_manager.cc:643] P 8175aef9d2144665a5ba6fc0218242f7: FlushDeltaMemStoresOp(8c06d71c2b86460e8f9870570e92a643) complete. Timing: real 0.074s	user 0.033s	sys 0.024s Metrics: {"bytes_written":16820142,"delete_count":0,"lbm_write_time_us":26966,"lbm_writes_1-10_ms":2,"lbm_writes_lt_1ms":411,"reinsert_count":0,"update_count":2050}
I20260812 06:18:03.655061 25067 maintenance_manager.cc:419] P 8175aef9d2144665a5ba6fc0218242f7: Scheduling FlushDeltaMemStoresOp(8c06d71c2b86460e8f9870570e92a643): perf score=6.157687
I20260812 06:18:03.676537 24998 maintenance_manager.cc:643] P 8175aef9d2144665a5ba6fc0218242f7: FlushDeltaMemStoresOp(8c06d71c2b86460e8f9870570e92a643) complete. Timing: real 0.021s	user 0.013s	sys 0.007s Metrics: {"bytes_written":7794836,"delete_count":0,"lbm_write_time_us":8785,"lbm_writes_lt_1ms":193,"reinsert_count":0,"update_count":950}
I20260812 06:18:03.677102 25067 maintenance_manager.cc:419] P 8175aef9d2144665a5ba6fc0218242f7: Scheduling MajorDeltaCompactionOp(8c06d71c2b86460e8f9870570e92a643): perf score=1.000000
I20260812 06:18:03.903508 24998 maintenance_manager.cc:643] P 8175aef9d2144665a5ba6fc0218242f7: MajorDeltaCompactionOp(8c06d71c2b86460e8f9870570e92a643) complete. Timing: real 0.226s	user 0.149s	sys 0.076s Metrics: {"cfile_cache_miss":632,"cfile_cache_miss_bytes":28877100,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":857,"lbm_read_time_us":15463,"lbm_reads_lt_1ms":664,"lbm_write_time_us":38136,"lbm_writes_lt_1ms":643,"mutex_wait_us":315,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":6144,"update_count":3000}
I20260812 06:18:03.904256 25067 maintenance_manager.cc:419] P 8175aef9d2144665a5ba6fc0218242f7: Scheduling FlushDeltaMemStoresOp(8c06d71c2b86460e8f9870570e92a643): perf score=15.087375
I20260812 06:18:03.960598 24998 maintenance_manager.cc:643] P 8175aef9d2144665a5ba6fc0218242f7: FlushDeltaMemStoresOp(8c06d71c2b86460e8f9870570e92a643) complete. Timing: real 0.056s	user 0.044s	sys 0.011s Metrics: {"bytes_written":16820142,"delete_count":0,"lbm_write_time_us":23620,"lbm_writes_lt_1ms":413,"reinsert_count":0,"update_count":2050}
I20260812 06:18:03.961356 25067 maintenance_manager.cc:419] P 8175aef9d2144665a5ba6fc0218242f7: Scheduling FlushDeltaMemStoresOp(8c06d71c2b86460e8f9870570e92a643): perf score=2.188937
I20260812 06:18:03.980618 24998 maintenance_manager.cc:643] P 8175aef9d2144665a5ba6fc0218242f7: FlushDeltaMemStoresOp(8c06d71c2b86460e8f9870570e92a643) complete. Timing: real 0.019s	user 0.007s	sys 0.008s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":6207,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:18:03.981164 25067 maintenance_manager.cc:419] P 8175aef9d2144665a5ba6fc0218242f7: Scheduling MajorDeltaCompactionOp(8c06d71c2b86460e8f9870570e92a643): perf score=1.000000
I20260812 06:18:04.160724 24998 maintenance_manager.cc:643] P 8175aef9d2144665a5ba6fc0218242f7: MajorDeltaCompactionOp(8c06d71c2b86460e8f9870570e92a643) complete. Timing: real 0.179s	user 0.127s	sys 0.052s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774675,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":794,"lbm_read_time_us":13133,"lbm_reads_lt_1ms":564,"lbm_write_time_us":30417,"lbm_writes_lt_1ms":543,"mutex_wait_us":325,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":2304,"update_count":2500}
I20260812 06:18:04.161274 25067 maintenance_manager.cc:419] P 8175aef9d2144665a5ba6fc0218242f7: Scheduling FlushDeltaMemStoresOp(8c06d71c2b86460e8f9870570e92a643): perf score=14.095187
I20260812 06:18:04.223172 24998 maintenance_manager.cc:643] P 8175aef9d2144665a5ba6fc0218242f7: FlushDeltaMemStoresOp(8c06d71c2b86460e8f9870570e92a643) complete. Timing: real 0.062s	user 0.029s	sys 0.026s Metrics: {"bytes_written":16409903,"delete_count":0,"lbm_write_time_us":22453,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:18:04.223788 25067 maintenance_manager.cc:419] P 8175aef9d2144665a5ba6fc0218242f7: Scheduling FlushDeltaMemStoresOp(8c06d71c2b86460e8f9870570e92a643): perf score=2.188937
I20260812 06:18:04.234886 24998 maintenance_manager.cc:643] P 8175aef9d2144665a5ba6fc0218242f7: FlushDeltaMemStoresOp(8c06d71c2b86460e8f9870570e92a643) complete. Timing: real 0.011s	user 0.005s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4235,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:04.235373 25067 maintenance_manager.cc:419] P 8175aef9d2144665a5ba6fc0218242f7: Scheduling MajorDeltaCompactionOp(8c06d71c2b86460e8f9870570e92a643): perf score=1.000000
I20260812 06:18:04.455247 24998 maintenance_manager.cc:643] P 8175aef9d2144665a5ba6fc0218242f7: MajorDeltaCompactionOp(8c06d71c2b86460e8f9870570e92a643) complete. Timing: real 0.220s	user 0.164s	sys 0.052s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774690,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":691,"lbm_read_time_us":14161,"lbm_reads_lt_1ms":572,"lbm_write_time_us":37168,"lbm_writes_lt_1ms":543,"mutex_wait_us":41,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":6144,"update_count":2500}
I20260812 06:18:04.456115 25067 maintenance_manager.cc:419] P 8175aef9d2144665a5ba6fc0218242f7: Scheduling FlushDeltaMemStoresOp(8c06d71c2b86460e8f9870570e92a643): perf score=11.118625
I20260812 06:18:04.536577 24998 maintenance_manager.cc:643] P 8175aef9d2144665a5ba6fc0218242f7: FlushDeltaMemStoresOp(8c06d71c2b86460e8f9870570e92a643) complete. Timing: real 0.080s	user 0.036s	sys 0.040s Metrics: {"bytes_written":12717735,"delete_count":0,"lbm_write_time_us":23962,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:18:04.537225 25067 maintenance_manager.cc:419] P 8175aef9d2144665a5ba6fc0218242f7: Scheduling FlushDeltaMemStoresOp(8c06d71c2b86460e8f9870570e92a643): perf score=6.157687
I20260812 06:18:04.569748 24998 maintenance_manager.cc:643] P 8175aef9d2144665a5ba6fc0218242f7: FlushDeltaMemStoresOp(8c06d71c2b86460e8f9870570e92a643) complete. Timing: real 0.032s	user 0.029s	sys 0.002s Metrics: {"bytes_written":7794836,"delete_count":0,"lbm_write_time_us":13087,"lbm_writes_lt_1ms":193,"reinsert_count":0,"update_count":950}
I20260812 06:18:04.570375 25067 maintenance_manager.cc:419] P 8175aef9d2144665a5ba6fc0218242f7: Scheduling MajorDeltaCompactionOp(8c06d71c2b86460e8f9870570e92a643): perf score=1.000000
I20260812 06:18:04.765391 24998 maintenance_manager.cc:643] P 8175aef9d2144665a5ba6fc0218242f7: MajorDeltaCompactionOp(8c06d71c2b86460e8f9870570e92a643) complete. Timing: real 0.195s	user 0.103s	sys 0.090s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774693,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":199,"lbm_read_time_us":11421,"lbm_reads_lt_1ms":564,"lbm_write_time_us":35988,"lbm_writes_lt_1ms":543,"mutex_wait_us":2,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":3712,"update_count":2500}
I20260812 06:18:04.766163 25067 maintenance_manager.cc:419] P 8175aef9d2144665a5ba6fc0218242f7: Scheduling FlushDeltaMemStoresOp(8c06d71c2b86460e8f9870570e92a643): perf score=11.118625
I20260812 06:18:04.812541 24998 maintenance_manager.cc:643] P 8175aef9d2144665a5ba6fc0218242f7: FlushDeltaMemStoresOp(8c06d71c2b86460e8f9870570e92a643) complete. Timing: real 0.046s	user 0.036s	sys 0.009s Metrics: {"bytes_written":12512611,"delete_count":0,"lbm_write_time_us":18873,"lbm_writes_lt_1ms":308,"reinsert_count":0,"update_count":1525}
I20260812 06:18:04.813167 25067 maintenance_manager.cc:419] P 8175aef9d2144665a5ba6fc0218242f7: Scheduling FlushDeltaMemStoresOp(8c06d71c2b86460e8f9870570e92a643): perf score=2.188937
I20260812 06:18:04.826565 24998 maintenance_manager.cc:643] P 8175aef9d2144665a5ba6fc0218242f7: FlushDeltaMemStoresOp(8c06d71c2b86460e8f9870570e92a643) complete. Timing: real 0.013s	user 0.008s	sys 0.003s Metrics: {"bytes_written":3897534,"delete_count":0,"lbm_write_time_us":5303,"lbm_writes_lt_1ms":98,"reinsert_count":0,"update_count":475}
I20260812 06:18:04.827318 25067 maintenance_manager.cc:419] P 8175aef9d2144665a5ba6fc0218242f7: Scheduling MajorDeltaCompactionOp(8c06d71c2b86460e8f9870570e92a643): perf score=1.000000
I20260812 06:18:04.953042 24998 maintenance_manager.cc:643] P 8175aef9d2144665a5ba6fc0218242f7: MajorDeltaCompactionOp(8c06d71c2b86460e8f9870570e92a643) complete. Timing: real 0.125s	user 0.098s	sys 0.027s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672273,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":1318,"lbm_read_time_us":8205,"lbm_reads_lt_1ms":472,"lbm_write_time_us":23507,"lbm_writes_lt_1ms":443,"mutex_wait_us":316,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":19584,"update_count":2000}
I20260812 06:18:04.953647 25067 maintenance_manager.cc:419] P 8175aef9d2144665a5ba6fc0218242f7: Scheduling FlushDeltaMemStoresOp(8c06d71c2b86460e8f9870570e92a643): perf score=10.126437
I20260812 06:18:04.995980 24998 maintenance_manager.cc:643] P 8175aef9d2144665a5ba6fc0218242f7: FlushDeltaMemStoresOp(8c06d71c2b86460e8f9870570e92a643) complete. Timing: real 0.042s	user 0.020s	sys 0.016s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":15687,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:18:04.996521 25067 maintenance_manager.cc:419] P 8175aef9d2144665a5ba6fc0218242f7: Scheduling FlushDeltaMemStoresOp(8c06d71c2b86460e8f9870570e92a643): perf score=2.188937
I20260812 06:18:05.009331 24998 maintenance_manager.cc:643] P 8175aef9d2144665a5ba6fc0218242f7: FlushDeltaMemStoresOp(8c06d71c2b86460e8f9870570e92a643) complete. Timing: real 0.013s	user 0.005s	sys 0.006s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4485,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:05.010092 25067 maintenance_manager.cc:419] P 8175aef9d2144665a5ba6fc0218242f7: Scheduling FlushMRSOp(8c06d71c2b86460e8f9870570e92a643): perf score=1.000000
I20260812 06:18:05.041642 24998 maintenance_manager.cc:643] P 8175aef9d2144665a5ba6fc0218242f7: FlushMRSOp(8c06d71c2b86460e8f9870570e92a643) complete. Timing: real 0.031s	user 0.030s	sys 0.000s Metrics: {"bytes_written":1275447,"cfile_init":1,"dirs.queue_time_us":74,"dirs.run_cpu_time_us":238,"dirs.run_wall_time_us":1464,"drs_written":1,"lbm_read_time_us":65,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1806,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":31,"spinlock_wait_cycles":1920}
I20260812 06:18:05.042333 25067 maintenance_manager.cc:419] P 8175aef9d2144665a5ba6fc0218242f7: Scheduling LogGCOp(8c06d71c2b86460e8f9870570e92a643): free 132118544 bytes of WAL
I20260812 06:18:05.042593 24998 log_reader.cc:385] T 8c06d71c2b86460e8f9870570e92a643: removed 13 log segments from log reader
I20260812 06:18:05.042640 24998 log.cc:1079] T 8c06d71c2b86460e8f9870570e92a643 P 8175aef9d2144665a5ba6fc0218242f7: Deleting log segment in path: /tmp/dist-test-taskZSRD0G/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515473524603-24678-0/minicluster-data/ts-0-root/wals/8c06d71c2b86460e8f9870570e92a643/wal-000000028 (ops 133-136)
I20260812 06:18:05.042670 24998 log.cc:1079] T 8c06d71c2b86460e8f9870570e92a643 P 8175aef9d2144665a5ba6fc0218242f7: Deleting log segment in path: /tmp/dist-test-taskZSRD0G/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515473524603-24678-0/minicluster-data/ts-0-root/wals/8c06d71c2b86460e8f9870570e92a643/wal-000000029 (ops 137-141)
I20260812 06:18:05.042730 24998 log.cc:1079] T 8c06d71c2b86460e8f9870570e92a643 P 8175aef9d2144665a5ba6fc0218242f7: Deleting log segment in path: /tmp/dist-test-taskZSRD0G/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515473524603-24678-0/minicluster-data/ts-0-root/wals/8c06d71c2b86460e8f9870570e92a643/wal-000000030 (ops 142-146)
I20260812 06:18:05.042761 24998 log.cc:1079] T 8c06d71c2b86460e8f9870570e92a643 P 8175aef9d2144665a5ba6fc0218242f7: Deleting log segment in path: /tmp/dist-test-taskZSRD0G/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515473524603-24678-0/minicluster-data/ts-0-root/wals/8c06d71c2b86460e8f9870570e92a643/wal-000000031 (ops 147-151)
I20260812 06:18:05.042810 24998 log.cc:1079] T 8c06d71c2b86460e8f9870570e92a643 P 8175aef9d2144665a5ba6fc0218242f7: Deleting log segment in path: /tmp/dist-test-taskZSRD0G/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515473524603-24678-0/minicluster-data/ts-0-root/wals/8c06d71c2b86460e8f9870570e92a643/wal-000000032 (ops 152-156)
I20260812 06:18:05.042837 24998 log.cc:1079] T 8c06d71c2b86460e8f9870570e92a643 P 8175aef9d2144665a5ba6fc0218242f7: Deleting log segment in path: /tmp/dist-test-taskZSRD0G/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515473524603-24678-0/minicluster-data/ts-0-root/wals/8c06d71c2b86460e8f9870570e92a643/wal-000000033 (ops 157-160)
I20260812 06:18:05.042878 24998 log.cc:1079] T 8c06d71c2b86460e8f9870570e92a643 P 8175aef9d2144665a5ba6fc0218242f7: Deleting log segment in path: /tmp/dist-test-taskZSRD0G/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515473524603-24678-0/minicluster-data/ts-0-root/wals/8c06d71c2b86460e8f9870570e92a643/wal-000000034 (ops 161-165)
I20260812 06:18:05.042927 24998 log.cc:1079] T 8c06d71c2b86460e8f9870570e92a643 P 8175aef9d2144665a5ba6fc0218242f7: Deleting log segment in path: /tmp/dist-test-taskZSRD0G/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515473524603-24678-0/minicluster-data/ts-0-root/wals/8c06d71c2b86460e8f9870570e92a643/wal-000000035 (ops 166-170)
I20260812 06:18:05.042965 24998 log.cc:1079] T 8c06d71c2b86460e8f9870570e92a643 P 8175aef9d2144665a5ba6fc0218242f7: Deleting log segment in path: /tmp/dist-test-taskZSRD0G/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515473524603-24678-0/minicluster-data/ts-0-root/wals/8c06d71c2b86460e8f9870570e92a643/wal-000000036 (ops 171-175)
I20260812 06:18:05.043006 24998 log.cc:1079] T 8c06d71c2b86460e8f9870570e92a643 P 8175aef9d2144665a5ba6fc0218242f7: Deleting log segment in path: /tmp/dist-test-taskZSRD0G/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515473524603-24678-0/minicluster-data/ts-0-root/wals/8c06d71c2b86460e8f9870570e92a643/wal-000000037 (ops 176-180)
I20260812 06:18:05.043045 24998 log.cc:1079] T 8c06d71c2b86460e8f9870570e92a643 P 8175aef9d2144665a5ba6fc0218242f7: Deleting log segment in path: /tmp/dist-test-taskZSRD0G/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515473524603-24678-0/minicluster-data/ts-0-root/wals/8c06d71c2b86460e8f9870570e92a643/wal-000000038 (ops 181-185)
I20260812 06:18:05.043084 24998 log.cc:1079] T 8c06d71c2b86460e8f9870570e92a643 P 8175aef9d2144665a5ba6fc0218242f7: Deleting log segment in path: /tmp/dist-test-taskZSRD0G/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515473524603-24678-0/minicluster-data/ts-0-root/wals/8c06d71c2b86460e8f9870570e92a643/wal-000000039 (ops 186-190)
I20260812 06:18:05.043124 24998 log.cc:1079] T 8c06d71c2b86460e8f9870570e92a643 P 8175aef9d2144665a5ba6fc0218242f7: Deleting log segment in path: /tmp/dist-test-taskZSRD0G/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515473524603-24678-0/minicluster-data/ts-0-root/wals/8c06d71c2b86460e8f9870570e92a643/wal-000000040 (ops 191-194)
I20260812 06:18:05.072414 24998 maintenance_manager.cc:643] P 8175aef9d2144665a5ba6fc0218242f7: LogGCOp(8c06d71c2b86460e8f9870570e92a643) complete. Timing: real 0.030s	user 0.000s	sys 0.029s Metrics: {}
I20260812 06:18:05.072988 25067 maintenance_manager.cc:419] P 8175aef9d2144665a5ba6fc0218242f7: Scheduling UndoDeltaBlockGCOp(8c06d71c2b86460e8f9870570e92a643): 482 bytes on disk
I20260812 06:18:05.073583 24998 maintenance_manager.cc:643] P 8175aef9d2144665a5ba6fc0218242f7: UndoDeltaBlockGCOp(8c06d71c2b86460e8f9870570e92a643) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":54,"lbm_reads_lt_1ms":4}
I20260812 06:18:05.074155 25067 maintenance_manager.cc:419] P 8175aef9d2144665a5ba6fc0218242f7: Scheduling FlushDeltaMemStoresOp(8c06d71c2b86460e8f9870570e92a643): perf score=5.165500
I20260812 06:18:05.096547 24998 maintenance_manager.cc:643] P 8175aef9d2144665a5ba6fc0218242f7: FlushDeltaMemStoresOp(8c06d71c2b86460e8f9870570e92a643) complete. Timing: real 0.022s	user 0.005s	sys 0.017s Metrics: {"bytes_written":6933327,"delete_count":0,"lbm_write_time_us":9418,"lbm_writes_lt_1ms":172,"reinsert_count":0,"update_count":845}
I20260812 06:18:05.097182 25067 maintenance_manager.cc:419] P 8175aef9d2144665a5ba6fc0218242f7: Scheduling FlushDeltaMemStoresOp(8c06d71c2b86460e8f9870570e92a643): perf score=1.000000
I20260812 06:18:05.105286 24998 maintenance_manager.cc:643] P 8175aef9d2144665a5ba6fc0218242f7: FlushDeltaMemStoresOp(8c06d71c2b86460e8f9870570e92a643) complete. Timing: real 0.008s	user 0.006s	sys 0.000s Metrics: {"bytes_written":1271927,"delete_count":0,"lbm_write_time_us":2263,"lbm_writes_lt_1ms":34,"reinsert_count":0,"update_count":155}
I20260812 06:18:05.107508 25067 maintenance_manager.cc:419] P 8175aef9d2144665a5ba6fc0218242f7: Scheduling MajorDeltaCompactionOp(8c06d71c2b86460e8f9870570e92a643): perf score=1.000000
I20260812 06:18:05.190191 24678 heavy-update-compaction-itest.cc:229] Time spent updating: real 6.031s	user 2.105s	sys 0.259s
I20260812 06:18:05.272117 24678 heavy-update-compaction-itest.cc:265] Time spent scanning: real 0.081s	user 0.004s	sys 0.000s
I20260812 06:18:05.272709 24678 tablet_server.cc:179] TabletServer@127.24.25.129:0 shutting down...
I20260812 06:18:05.280133 24998 maintenance_manager.cc:643] P 8175aef9d2144665a5ba6fc0218242f7: MajorDeltaCompactionOp(8c06d71c2b86460e8f9870570e92a643) complete. Timing: real 0.172s	user 0.113s	sys 0.056s Metrics: {"cfile_cache_miss":634,"cfile_cache_miss_bytes":28877269,"cfile_init":7,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":3771,"dirs.run_cpu_time_us":681,"dirs.run_wall_time_us":3379,"lbm_read_time_us":13003,"lbm_reads_lt_1ms":662,"lbm_write_time_us":33845,"lbm_writes_lt_1ms":643,"mutex_wait_us":3189,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":16640,"thread_start_us":83,"threads_started":1,"update_count":3000}
I20260812 06:18:05.282788 24678 ts_tablet_manager.cc:1507] Shutting down tablet manager...
I20260812 06:18:05.283020 24678 tablet_replica.cc:333] T 8c06d71c2b86460e8f9870570e92a643 P 8175aef9d2144665a5ba6fc0218242f7: stopping tablet replica
I20260812 06:18:05.283149 24678 raft_consensus.cc:2243] T 8c06d71c2b86460e8f9870570e92a643 P 8175aef9d2144665a5ba6fc0218242f7 [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:18:05.283291 24678 raft_consensus.cc:2272] T 8c06d71c2b86460e8f9870570e92a643 P 8175aef9d2144665a5ba6fc0218242f7 [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:18:05.298615 24678 tablet_server.cc:196] TabletServer@127.24.25.129:0 shutdown complete.
I20260812 06:18:05.328440 24678 master.cc:562] Master@127.24.25.190:33669 shutting down...
I20260812 06:18:05.332124 24678 raft_consensus.cc:2243] T 00000000000000000000000000000000 P 7e52605c27b0442b9d83c6215747f6d5 [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:18:05.332310 24678 raft_consensus.cc:2272] T 00000000000000000000000000000000 P 7e52605c27b0442b9d83c6215747f6d5 [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:18:05.332361 24678 tablet_replica.cc:333] T 00000000000000000000000000000000 P 7e52605c27b0442b9d83c6215747f6d5: stopping tablet replica
I20260812 06:18:05.346174 24678 master.cc:584] Master@127.24.25.190:33669 shutdown complete.
[       OK ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/1 (6508 ms)
[----------] 2 tests from EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy (11894 ms total)

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