[==========] 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:18:50.640618 20910 internal_mini_cluster.cc:156] Creating distributed mini masters. Addrs: 127.20.107.190:44361
I20260812 06:18:50.641594 20910 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:18:50.642184 20910 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:18:50.648408 20920 instance_detector.cc:116] could not retrieve AWS instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:18:50.648409 20926 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:18:50.648448 20921 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:18:50.648904 20910 server_base.cc:1061] running on GCE node
I20260812 06:18:50.649333 20910 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:18:50.649448 20910 system_unsync_time.cc:38] NTP support is disabled. Clock error bounds will not be accurate. This configuration is not suitable for distributed clusters.
I20260812 06:18:50.649498 20910 hybrid_clock.cc:648] HybridClock initialized: now 1786515530649495 us; error 0 us; skew 500 ppm
I20260812 06:18:50.651166 20910 webserver.cc:533] Webserver started at http://127.20.107.190:39129/ using document root <none> and password file <none>
I20260812 06:18:50.651757 20910 fs_manager.cc:362] Metadata directory not provided
I20260812 06:18:50.651844 20910 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:18:50.652070 20910 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:18:50.653596 20910 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskkQAF1q/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515530630243-20910-0/minicluster-data/master-0-root/instance:
uuid: "383e399c502046d1a8573279edc6101e"
format_stamp: "Formatted at 2026-08-12 06:18:50 on dist-test-slave-92m1"
I20260812 06:18:50.656831 20910 fs_manager.cc:696] Time spent creating directory manager: real 0.003s	user 0.002s	sys 0.003s
I20260812 06:18:50.658787 20932 log_block_manager.cc:4127] Time spent loading block containers with low live blocks: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:18:50.659739 20910 fs_manager.cc:730] Time spent opening block manager: real 0.002s	user 0.002s	sys 0.000s
I20260812 06:18:50.659866 20910 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskkQAF1q/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515530630243-20910-0/minicluster-data/master-0-root
uuid: "383e399c502046d1a8573279edc6101e"
format_stamp: "Formatted at 2026-08-12 06:18:50 on dist-test-slave-92m1"
I20260812 06:18:50.659991 20910 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskkQAF1q/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515530630243-20910-0/minicluster-data/master-0-root
metadata directory: /tmp/dist-test-taskkQAF1q/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515530630243-20910-0/minicluster-data/master-0-root
1 data directories: /tmp/dist-test-taskkQAF1q/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515530630243-20910-0/minicluster-data/master-0-root/data
Total live blocks: 0
Total live bytes: 0
Total live bytes (after alignment): 0
Total number of LBM containers: 0 (0 full)
Did not check for missing blocks
Did not check for orphaned blocks
Total full LBM containers with extra space: 0 (0 repaired)
Total full LBM container extra space in bytes: 0 (0 repaired)
Total incomplete LBM containers: 0 (0 repaired)
Total LBM partial records: 0 (0 repaired)
Total corrupted LBM metadata records in RocksDB: 0 (0 repaired)
I20260812 06:18:50.680440 20910 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:18:50.681012 20910 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:18:50.681185 20910 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:18:50.688350 20910 rpc_server.cc:307] RPC server started. Bound to: 127.20.107.190:44361
I20260812 06:18:50.688419 21030 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.20.107.190:44361 every 8 connection(s)
I20260812 06:18:50.690451 21031 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet 00000000000000000000000000000000. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:18:50.695678 21031 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P 383e399c502046d1a8573279edc6101e: Bootstrap starting.
I20260812 06:18:50.698167 21031 tablet_bootstrap.cc:654] T 00000000000000000000000000000000 P 383e399c502046d1a8573279edc6101e: Neither blocks nor log segments found. Creating new log.
I20260812 06:18:50.699025 21031 log.cc:826] T 00000000000000000000000000000000 P 383e399c502046d1a8573279edc6101e: Log is configured to *not* fsync() on all Append() calls
I20260812 06:18:50.700634 21031 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P 383e399c502046d1a8573279edc6101e: No bootstrap required, opened a new log
I20260812 06:18:50.703293 21031 raft_consensus.cc:359] T 00000000000000000000000000000000 P 383e399c502046d1a8573279edc6101e [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "383e399c502046d1a8573279edc6101e" member_type: VOTER }
I20260812 06:18:50.703441 21031 raft_consensus.cc:385] T 00000000000000000000000000000000 P 383e399c502046d1a8573279edc6101e [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:18:50.703540 21031 raft_consensus.cc:740] T 00000000000000000000000000000000 P 383e399c502046d1a8573279edc6101e [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: 383e399c502046d1a8573279edc6101e, State: Initialized, Role: FOLLOWER
I20260812 06:18:50.704098 21031 consensus_queue.cc:260] T 00000000000000000000000000000000 P 383e399c502046d1a8573279edc6101e [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: "383e399c502046d1a8573279edc6101e" member_type: VOTER }
I20260812 06:18:50.704257 21031 raft_consensus.cc:399] T 00000000000000000000000000000000 P 383e399c502046d1a8573279edc6101e [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:18:50.704325 21031 raft_consensus.cc:493] T 00000000000000000000000000000000 P 383e399c502046d1a8573279edc6101e [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:18:50.704465 21031 raft_consensus.cc:3060] T 00000000000000000000000000000000 P 383e399c502046d1a8573279edc6101e [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:18:50.705221 21031 raft_consensus.cc:515] T 00000000000000000000000000000000 P 383e399c502046d1a8573279edc6101e [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "383e399c502046d1a8573279edc6101e" member_type: VOTER }
I20260812 06:18:50.705638 21031 leader_election.cc:304] T 00000000000000000000000000000000 P 383e399c502046d1a8573279edc6101e [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: 383e399c502046d1a8573279edc6101e; no voters: 
I20260812 06:18:50.705938 21031 leader_election.cc:290] T 00000000000000000000000000000000 P 383e399c502046d1a8573279edc6101e [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:18:50.706074 21036 raft_consensus.cc:2804] T 00000000000000000000000000000000 P 383e399c502046d1a8573279edc6101e [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:18:50.706326 21036 raft_consensus.cc:697] T 00000000000000000000000000000000 P 383e399c502046d1a8573279edc6101e [term 1 LEADER]: Becoming Leader. State: Replica: 383e399c502046d1a8573279edc6101e, State: Running, Role: LEADER
I20260812 06:18:50.706732 21036 consensus_queue.cc:237] T 00000000000000000000000000000000 P 383e399c502046d1a8573279edc6101e [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: "383e399c502046d1a8573279edc6101e" member_type: VOTER }
I20260812 06:18:50.706913 21031 sys_catalog.cc:565] T 00000000000000000000000000000000 P 383e399c502046d1a8573279edc6101e [sys.catalog]: configured and running, proceeding with master startup.
I20260812 06:18:50.708643 21037 sys_catalog.cc:455] T 00000000000000000000000000000000 P 383e399c502046d1a8573279edc6101e [sys.catalog]: SysCatalogTable state changed. Reason: RaftConsensus started. Latest consensus state: current_term: 1 leader_uuid: "383e399c502046d1a8573279edc6101e" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "383e399c502046d1a8573279edc6101e" member_type: VOTER } }
I20260812 06:18:50.708757 21037 sys_catalog.cc:458] T 00000000000000000000000000000000 P 383e399c502046d1a8573279edc6101e [sys.catalog]: This master's current role is: LEADER
I20260812 06:18:50.708618 21038 sys_catalog.cc:455] T 00000000000000000000000000000000 P 383e399c502046d1a8573279edc6101e [sys.catalog]: SysCatalogTable state changed. Reason: New leader 383e399c502046d1a8573279edc6101e. Latest consensus state: current_term: 1 leader_uuid: "383e399c502046d1a8573279edc6101e" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "383e399c502046d1a8573279edc6101e" member_type: VOTER } }
I20260812 06:18:50.708992 21038 sys_catalog.cc:458] T 00000000000000000000000000000000 P 383e399c502046d1a8573279edc6101e [sys.catalog]: This master's current role is: LEADER
I20260812 06:18:50.709249 21053 catalog_manager.cc:1511] Loading table and tablet metadata into memory...
I20260812 06:18:50.709335 20910 internal_mini_cluster.cc:184] Waiting to initialize catalog manager on master 0
I20260812 06:18:50.711338 21053 catalog_manager.cc:1520] Initializing Kudu cluster ID...
I20260812 06:18:50.715952 21053 catalog_manager.cc:1383] Generated new cluster ID: 71a27d7d43ad45c88f742042de66027b
I20260812 06:18:50.716019 21053 catalog_manager.cc:1531] Initializing Kudu internal certificate authority...
I20260812 06:18:50.735633 21053 catalog_manager.cc:1406] Generated new certificate authority record
I20260812 06:18:50.736486 21053 catalog_manager.cc:1540] Loading token signing keys...
I20260812 06:18:50.743173 21053 catalog_manager.cc:6092] T 00000000000000000000000000000000 P 383e399c502046d1a8573279edc6101e: Generated new TSK 0
I20260812 06:18:50.743783 21053 catalog_manager.cc:1550] Initializing in-progress tserver states...
I20260812 06:18:50.774377 20910 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:18:50.777240 21069 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:18:50.777267 21066 instance_detector.cc:116] could not retrieve AWS instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:18:50.777433 20910 server_base.cc:1061] running on GCE node
W20260812 06:18:50.777632 21067 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:18:50.777851 20910 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:18:50.777951 20910 system_unsync_time.cc:38] NTP support is disabled. Clock error bounds will not be accurate. This configuration is not suitable for distributed clusters.
I20260812 06:18:50.777987 20910 hybrid_clock.cc:648] HybridClock initialized: now 1786515530777985 us; error 0 us; skew 500 ppm
I20260812 06:18:50.778947 20910 webserver.cc:533] Webserver started at http://127.20.107.129:33199/ using document root <none> and password file <none>
I20260812 06:18:50.779121 20910 fs_manager.cc:362] Metadata directory not provided
I20260812 06:18:50.779191 20910 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:18:50.779297 20910 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:18:50.779697 20910 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskkQAF1q/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515530630243-20910-0/minicluster-data/ts-0-root/instance:
uuid: "ed46bdcf8fbb41b4b16b9a0f24e6db42"
format_stamp: "Formatted at 2026-08-12 06:18:50 on dist-test-slave-92m1"
I20260812 06:18:50.781198 20910 fs_manager.cc:696] Time spent creating directory manager: real 0.001s	user 0.002s	sys 0.000s
I20260812 06:18:50.782174 21077 log_block_manager.cc:4127] Time spent loading block containers with low live blocks: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:18:50.782413 20910 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.001s	sys 0.000s
I20260812 06:18:50.782485 20910 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskkQAF1q/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515530630243-20910-0/minicluster-data/ts-0-root
uuid: "ed46bdcf8fbb41b4b16b9a0f24e6db42"
format_stamp: "Formatted at 2026-08-12 06:18:50 on dist-test-slave-92m1"
I20260812 06:18:50.782573 20910 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskkQAF1q/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515530630243-20910-0/minicluster-data/ts-0-root
metadata directory: /tmp/dist-test-taskkQAF1q/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515530630243-20910-0/minicluster-data/ts-0-root
1 data directories: /tmp/dist-test-taskkQAF1q/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515530630243-20910-0/minicluster-data/ts-0-root/data
Total live blocks: 0
Total live bytes: 0
Total live bytes (after alignment): 0
Total number of LBM containers: 0 (0 full)
Did not check for missing blocks
Did not check for orphaned blocks
Total full LBM containers with extra space: 0 (0 repaired)
Total full LBM container extra space in bytes: 0 (0 repaired)
Total incomplete LBM containers: 0 (0 repaired)
Total LBM partial records: 0 (0 repaired)
Total corrupted LBM metadata records in RocksDB: 0 (0 repaired)
I20260812 06:18:50.794394 20910 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:18:50.794793 20910 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:18:50.795324 20910 txn_system_client.cc:432] TxnSystemClient initialization is disabled...
I20260812 06:18:50.796171 20910 ts_tablet_manager.cc:585] Loaded tablet metadata (0 total tablets, 0 live tablets)
I20260812 06:18:50.796222 20910 ts_tablet_manager.cc:531] Time spent load tablet metadata: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:18:50.796284 20910 ts_tablet_manager.cc:616] Registered 0 tablets
I20260812 06:18:50.796326 20910 ts_tablet_manager.cc:595] Time spent register tablets: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:18:50.803296 20910 rpc_server.cc:307] RPC server started. Bound to: 127.20.107.129:43575
I20260812 06:18:50.803380 21177 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.20.107.129:43575 every 8 connection(s)
I20260812 06:18:50.813951 21178 heartbeater.cc:344] Connected to a master server at 127.20.107.190:44361
I20260812 06:18:50.814244 21178 heartbeater.cc:461] Registering TS with master...
I20260812 06:18:50.814690 21178 heartbeater.cc:507] Master 127.20.107.190:44361 requested a full tablet report, sending...
I20260812 06:18:50.816149 20959 ts_manager.cc:194] Registered new tserver with Master: ed46bdcf8fbb41b4b16b9a0f24e6db42 (127.20.107.129:43575)
I20260812 06:18:50.816505 20910 internal_mini_cluster.cc:371] 1 TS(s) registered with all masters after 0.012517635s
I20260812 06:18:50.817596 20959 master_service.cc:502] Signed X509 certificate for tserver {username='slave'} at 127.0.0.1:38206
I20260812 06:18:50.825887 20959 catalog_manager.cc:2283] Servicing CreateTable request from {username='slave'} at 127.0.0.1:38208:
name: "heavy-update-compaction-test"
schema {
  columns {
    name: "key"
    type: INT64
    is_key: true
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_a"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_b"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_c"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_d"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_e"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
}
num_replicas: 1
split_rows_range_bounds {
}
partition_schema {
  range_schema {
  }
}
I20260812 06:18:50.839322 21116 tablet_service.cc:1511] Processing CreateTablet for tablet d85e95ddae73456f9799bef2f80cc4f6 (DEFAULT_TABLE table=heavy-update-compaction-test [id=ad8184d646fc49c4ab0e2d27f0480b68]), partition=
I20260812 06:18:50.839761 21116 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet d85e95ddae73456f9799bef2f80cc4f6. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:18:50.842190 21205 tablet_bootstrap.cc:492] T d85e95ddae73456f9799bef2f80cc4f6 P ed46bdcf8fbb41b4b16b9a0f24e6db42: Bootstrap starting.
I20260812 06:18:50.843497 21205 tablet_bootstrap.cc:654] T d85e95ddae73456f9799bef2f80cc4f6 P ed46bdcf8fbb41b4b16b9a0f24e6db42: Neither blocks nor log segments found. Creating new log.
I20260812 06:18:50.844753 21205 tablet_bootstrap.cc:492] T d85e95ddae73456f9799bef2f80cc4f6 P ed46bdcf8fbb41b4b16b9a0f24e6db42: No bootstrap required, opened a new log
I20260812 06:18:50.844870 21205 ts_tablet_manager.cc:1403] T d85e95ddae73456f9799bef2f80cc4f6 P ed46bdcf8fbb41b4b16b9a0f24e6db42: Time spent bootstrapping tablet: real 0.003s	user 0.002s	sys 0.000s
I20260812 06:18:50.845330 21205 raft_consensus.cc:359] T d85e95ddae73456f9799bef2f80cc4f6 P ed46bdcf8fbb41b4b16b9a0f24e6db42 [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "ed46bdcf8fbb41b4b16b9a0f24e6db42" member_type: VOTER last_known_addr { host: "127.20.107.129" port: 43575 } }
I20260812 06:18:50.845463 21205 raft_consensus.cc:385] T d85e95ddae73456f9799bef2f80cc4f6 P ed46bdcf8fbb41b4b16b9a0f24e6db42 [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:18:50.845498 21205 raft_consensus.cc:740] T d85e95ddae73456f9799bef2f80cc4f6 P ed46bdcf8fbb41b4b16b9a0f24e6db42 [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: ed46bdcf8fbb41b4b16b9a0f24e6db42, State: Initialized, Role: FOLLOWER
I20260812 06:18:50.845667 21205 consensus_queue.cc:260] T d85e95ddae73456f9799bef2f80cc4f6 P ed46bdcf8fbb41b4b16b9a0f24e6db42 [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: "ed46bdcf8fbb41b4b16b9a0f24e6db42" member_type: VOTER last_known_addr { host: "127.20.107.129" port: 43575 } }
I20260812 06:18:50.845800 21205 raft_consensus.cc:399] T d85e95ddae73456f9799bef2f80cc4f6 P ed46bdcf8fbb41b4b16b9a0f24e6db42 [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:18:50.845856 21205 raft_consensus.cc:493] T d85e95ddae73456f9799bef2f80cc4f6 P ed46bdcf8fbb41b4b16b9a0f24e6db42 [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:18:50.845923 21205 raft_consensus.cc:3060] T d85e95ddae73456f9799bef2f80cc4f6 P ed46bdcf8fbb41b4b16b9a0f24e6db42 [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:18:50.846614 21205 raft_consensus.cc:515] T d85e95ddae73456f9799bef2f80cc4f6 P ed46bdcf8fbb41b4b16b9a0f24e6db42 [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "ed46bdcf8fbb41b4b16b9a0f24e6db42" member_type: VOTER last_known_addr { host: "127.20.107.129" port: 43575 } }
I20260812 06:18:50.846765 21205 leader_election.cc:304] T d85e95ddae73456f9799bef2f80cc4f6 P ed46bdcf8fbb41b4b16b9a0f24e6db42 [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: ed46bdcf8fbb41b4b16b9a0f24e6db42; no voters: 
I20260812 06:18:50.846997 21205 leader_election.cc:290] T d85e95ddae73456f9799bef2f80cc4f6 P ed46bdcf8fbb41b4b16b9a0f24e6db42 [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:18:50.847105 21209 raft_consensus.cc:2804] T d85e95ddae73456f9799bef2f80cc4f6 P ed46bdcf8fbb41b4b16b9a0f24e6db42 [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:18:50.847362 21209 raft_consensus.cc:697] T d85e95ddae73456f9799bef2f80cc4f6 P ed46bdcf8fbb41b4b16b9a0f24e6db42 [term 1 LEADER]: Becoming Leader. State: Replica: ed46bdcf8fbb41b4b16b9a0f24e6db42, State: Running, Role: LEADER
I20260812 06:18:50.847402 21205 ts_tablet_manager.cc:1434] T d85e95ddae73456f9799bef2f80cc4f6 P ed46bdcf8fbb41b4b16b9a0f24e6db42: Time spent starting tablet: real 0.002s	user 0.003s	sys 0.000s
I20260812 06:18:50.847574 21209 consensus_queue.cc:237] T d85e95ddae73456f9799bef2f80cc4f6 P ed46bdcf8fbb41b4b16b9a0f24e6db42 [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: "ed46bdcf8fbb41b4b16b9a0f24e6db42" member_type: VOTER last_known_addr { host: "127.20.107.129" port: 43575 } }
I20260812 06:18:50.847925 21178 heartbeater.cc:499] Master 127.20.107.190:44361 was elected leader, sending a full tablet report...
I20260812 06:18:50.850687 20959 catalog_manager.cc:5719] T d85e95ddae73456f9799bef2f80cc4f6 P ed46bdcf8fbb41b4b16b9a0f24e6db42 reported cstate change: term changed from 0 to 1, leader changed from <none> to ed46bdcf8fbb41b4b16b9a0f24e6db42 (127.20.107.129). New cstate: current_term: 1 leader_uuid: "ed46bdcf8fbb41b4b16b9a0f24e6db42" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "ed46bdcf8fbb41b4b16b9a0f24e6db42" member_type: VOTER last_known_addr { host: "127.20.107.129" port: 43575 } health_report { overall_health: HEALTHY } } }
I20260812 06:18:50.929518 20910 heavy-update-compaction-itest.cc:215] Time spent inserting: real 0.069s	user 0.020s	sys 0.013s
I20260812 06:18:51.054469 21179 maintenance_manager.cc:419] P ed46bdcf8fbb41b4b16b9a0f24e6db42: Scheduling FlushMRSOp(d85e95ddae73456f9799bef2f80cc4f6): perf score=15.086190
I20260812 06:18:51.259943 21085 maintenance_manager.cc:643] P ed46bdcf8fbb41b4b16b9a0f24e6db42: FlushMRSOp(d85e95ddae73456f9799bef2f80cc4f6) complete. Timing: real 0.205s	user 0.158s	sys 0.043s Metrics: {"bytes_written":15999661,"cfile_init":1,"compiler_manager_pool.queue_time_us":195,"delete_count":0,"dirs.queue_time_us":67,"dirs.run_cpu_time_us":233,"dirs.run_wall_time_us":745,"drs_written":1,"lbm_read_time_us":92,"lbm_reads_lt_1ms":4,"lbm_write_time_us":54121,"lbm_writes_lt_1ms":757,"peak_mem_usage":0,"reinsert_count":0,"rows_written":104,"spinlock_wait_cycles":2944,"thread_start_us":122,"threads_started":1,"update_count":1950}
I20260812 06:18:51.261119 21179 maintenance_manager.cc:419] P ed46bdcf8fbb41b4b16b9a0f24e6db42: Scheduling UndoDeltaBlockGCOp(d85e95ddae73456f9799bef2f80cc4f6): 12719218 bytes on disk
I20260812 06:18:51.261821 21085 maintenance_manager.cc:643] P ed46bdcf8fbb41b4b16b9a0f24e6db42: UndoDeltaBlockGCOp(d85e95ddae73456f9799bef2f80cc4f6) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":71,"lbm_reads_lt_1ms":4}
I20260812 06:18:51.262255 21179 maintenance_manager.cc:419] P ed46bdcf8fbb41b4b16b9a0f24e6db42: Scheduling FlushDeltaMemStoresOp(d85e95ddae73456f9799bef2f80cc4f6): perf score=4.173312
I20260812 06:18:51.292634 21085 maintenance_manager.cc:643] P ed46bdcf8fbb41b4b16b9a0f24e6db42: FlushDeltaMemStoresOp(d85e95ddae73456f9799bef2f80cc4f6) complete. Timing: real 0.030s	user 0.008s	sys 0.016s Metrics: {"bytes_written":5579539,"delete_count":0,"lbm_write_time_us":9516,"lbm_writes_lt_1ms":139,"reinsert_count":0,"update_count":680}
I20260812 06:18:51.293291 21179 maintenance_manager.cc:419] P ed46bdcf8fbb41b4b16b9a0f24e6db42: Scheduling LogGCOp(d85e95ddae73456f9799bef2f80cc4f6): free 20743880 bytes of WAL
I20260812 06:18:51.293684 21085 log_reader.cc:385] T d85e95ddae73456f9799bef2f80cc4f6: removed 2 log segments from log reader
I20260812 06:18:51.293818 21085 log.cc:1079] T d85e95ddae73456f9799bef2f80cc4f6 P ed46bdcf8fbb41b4b16b9a0f24e6db42: Deleting log segment in path: /tmp/dist-test-taskkQAF1q/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515530630243-20910-0/minicluster-data/ts-0-root/wals/d85e95ddae73456f9799bef2f80cc4f6/wal-000000001 (ops 1-6)
I20260812 06:18:51.293939 21085 log.cc:1079] T d85e95ddae73456f9799bef2f80cc4f6 P ed46bdcf8fbb41b4b16b9a0f24e6db42: Deleting log segment in path: /tmp/dist-test-taskkQAF1q/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515530630243-20910-0/minicluster-data/ts-0-root/wals/d85e95ddae73456f9799bef2f80cc4f6/wal-000000002 (ops 7-11)
I20260812 06:18:51.298956 21085 maintenance_manager.cc:643] P ed46bdcf8fbb41b4b16b9a0f24e6db42: LogGCOp(d85e95ddae73456f9799bef2f80cc4f6) complete. Timing: real 0.005s	user 0.000s	sys 0.002s Metrics: {}
I20260812 06:18:51.299355 21179 maintenance_manager.cc:419] P ed46bdcf8fbb41b4b16b9a0f24e6db42: Scheduling FlushDeltaMemStoresOp(d85e95ddae73456f9799bef2f80cc4f6): perf score=1.196750
I20260812 06:18:51.307585 21085 maintenance_manager.cc:643] P ed46bdcf8fbb41b4b16b9a0f24e6db42: FlushDeltaMemStoresOp(d85e95ddae73456f9799bef2f80cc4f6) complete. Timing: real 0.008s	user 0.003s	sys 0.005s Metrics: {"bytes_written":2625754,"delete_count":0,"lbm_write_time_us":2935,"lbm_writes_lt_1ms":67,"reinsert_count":0,"update_count":320}
I20260812 06:18:51.308207 21179 maintenance_manager.cc:419] P ed46bdcf8fbb41b4b16b9a0f24e6db42: Scheduling MajorDeltaCompactionOp(d85e95ddae73456f9799bef2f80cc4f6): perf score=1.000000
I20260812 06:18:51.522241 21085 maintenance_manager.cc:643] P ed46bdcf8fbb41b4b16b9a0f24e6db42: MajorDeltaCompactionOp(d85e95ddae73456f9799bef2f80cc4f6) complete. Timing: real 0.214s	user 0.143s	sys 0.065s Metrics: {"cfile_cache_miss":623,"cfile_cache_miss_bytes":28466948,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":253,"lbm_read_time_us":15642,"lbm_reads_lt_1ms":659,"lbm_write_time_us":36556,"lbm_writes_lt_1ms":633,"mutex_wait_us":33,"peak_mem_usage":74091738,"reinsert_count":0,"spinlock_wait_cycles":2688,"thread_start_us":303,"threads_started":5,"update_count":2950}
I20260812 06:18:51.522804 21179 maintenance_manager.cc:419] P ed46bdcf8fbb41b4b16b9a0f24e6db42: Scheduling FlushDeltaMemStoresOp(d85e95ddae73456f9799bef2f80cc4f6): perf score=14.095187
I20260812 06:18:51.602465 21085 maintenance_manager.cc:643] P ed46bdcf8fbb41b4b16b9a0f24e6db42: FlushDeltaMemStoresOp(d85e95ddae73456f9799bef2f80cc4f6) complete. Timing: real 0.079s	user 0.052s	sys 0.008s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":26216,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:18:51.602998 21179 maintenance_manager.cc:419] P ed46bdcf8fbb41b4b16b9a0f24e6db42: Scheduling FlushDeltaMemStoresOp(d85e95ddae73456f9799bef2f80cc4f6): perf score=2.188937
I20260812 06:18:51.614034 21085 maintenance_manager.cc:643] P ed46bdcf8fbb41b4b16b9a0f24e6db42: FlushDeltaMemStoresOp(d85e95ddae73456f9799bef2f80cc4f6) complete. Timing: real 0.011s	user 0.009s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4319,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:51.614432 21179 maintenance_manager.cc:419] P ed46bdcf8fbb41b4b16b9a0f24e6db42: Scheduling MajorDeltaCompactionOp(d85e95ddae73456f9799bef2f80cc4f6): perf score=1.000000
I20260812 06:18:51.773075 21085 maintenance_manager.cc:643] P ed46bdcf8fbb41b4b16b9a0f24e6db42: MajorDeltaCompactionOp(d85e95ddae73456f9799bef2f80cc4f6) complete. Timing: real 0.158s	user 0.110s	sys 0.048s 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":681,"lbm_read_time_us":11744,"lbm_reads_lt_1ms":572,"lbm_write_time_us":28767,"lbm_writes_lt_1ms":543,"mutex_wait_us":278,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":896,"update_count":2500}
I20260812 06:18:51.773690 21179 maintenance_manager.cc:419] P ed46bdcf8fbb41b4b16b9a0f24e6db42: Scheduling FlushDeltaMemStoresOp(d85e95ddae73456f9799bef2f80cc4f6): perf score=10.126437
I20260812 06:18:51.813750 21085 maintenance_manager.cc:643] P ed46bdcf8fbb41b4b16b9a0f24e6db42: FlushDeltaMemStoresOp(d85e95ddae73456f9799bef2f80cc4f6) complete. Timing: real 0.040s	user 0.020s	sys 0.011s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":14840,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:18:51.814218 21179 maintenance_manager.cc:419] P ed46bdcf8fbb41b4b16b9a0f24e6db42: Scheduling FlushDeltaMemStoresOp(d85e95ddae73456f9799bef2f80cc4f6): perf score=2.188937
I20260812 06:18:51.825160 21085 maintenance_manager.cc:643] P ed46bdcf8fbb41b4b16b9a0f24e6db42: FlushDeltaMemStoresOp(d85e95ddae73456f9799bef2f80cc4f6) complete. Timing: real 0.011s	user 0.006s	sys 0.003s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4427,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:51.825626 21179 maintenance_manager.cc:419] P ed46bdcf8fbb41b4b16b9a0f24e6db42: Scheduling MajorDeltaCompactionOp(d85e95ddae73456f9799bef2f80cc4f6): perf score=1.000000
I20260812 06:18:51.957551 21085 maintenance_manager.cc:643] P ed46bdcf8fbb41b4b16b9a0f24e6db42: MajorDeltaCompactionOp(d85e95ddae73456f9799bef2f80cc4f6) complete. Timing: real 0.132s	user 0.089s	sys 0.041s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672277,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":194,"lbm_read_time_us":9523,"lbm_reads_lt_1ms":472,"lbm_write_time_us":22253,"lbm_writes_lt_1ms":443,"mutex_wait_us":26,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":108416,"update_count":2000}
I20260812 06:18:51.958112 21179 maintenance_manager.cc:419] P ed46bdcf8fbb41b4b16b9a0f24e6db42: Scheduling FlushDeltaMemStoresOp(d85e95ddae73456f9799bef2f80cc4f6): perf score=10.126437
I20260812 06:18:52.000699 21085 maintenance_manager.cc:643] P ed46bdcf8fbb41b4b16b9a0f24e6db42: FlushDeltaMemStoresOp(d85e95ddae73456f9799bef2f80cc4f6) complete. Timing: real 0.042s	user 0.020s	sys 0.015s Metrics: {"bytes_written":12307489,"delete_count":0,"lbm_write_time_us":15882,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:18:52.001207 21179 maintenance_manager.cc:419] P ed46bdcf8fbb41b4b16b9a0f24e6db42: Scheduling FlushDeltaMemStoresOp(d85e95ddae73456f9799bef2f80cc4f6): perf score=2.188937
I20260812 06:18:52.012336 21085 maintenance_manager.cc:643] P ed46bdcf8fbb41b4b16b9a0f24e6db42: FlushDeltaMemStoresOp(d85e95ddae73456f9799bef2f80cc4f6) complete. Timing: real 0.011s	user 0.010s	sys 0.000s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4117,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:52.012902 21179 maintenance_manager.cc:419] P ed46bdcf8fbb41b4b16b9a0f24e6db42: Scheduling MajorDeltaCompactionOp(d85e95ddae73456f9799bef2f80cc4f6): perf score=1.000000
I20260812 06:18:52.132910 21085 maintenance_manager.cc:643] P ed46bdcf8fbb41b4b16b9a0f24e6db42: MajorDeltaCompactionOp(d85e95ddae73456f9799bef2f80cc4f6) complete. Timing: real 0.120s	user 0.093s	sys 0.026s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672275,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":659,"lbm_read_time_us":7524,"lbm_reads_lt_1ms":472,"lbm_write_time_us":22135,"lbm_writes_lt_1ms":443,"mutex_wait_us":50,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":12544,"update_count":2000}
I20260812 06:18:52.133489 21179 maintenance_manager.cc:419] P ed46bdcf8fbb41b4b16b9a0f24e6db42: Scheduling FlushDeltaMemStoresOp(d85e95ddae73456f9799bef2f80cc4f6): perf score=10.126437
I20260812 06:18:52.178258 21085 maintenance_manager.cc:643] P ed46bdcf8fbb41b4b16b9a0f24e6db42: FlushDeltaMemStoresOp(d85e95ddae73456f9799bef2f80cc4f6) complete. Timing: real 0.045s	user 0.014s	sys 0.020s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":15026,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:18:52.178750 21179 maintenance_manager.cc:419] P ed46bdcf8fbb41b4b16b9a0f24e6db42: Scheduling FlushDeltaMemStoresOp(d85e95ddae73456f9799bef2f80cc4f6): perf score=2.188937
I20260812 06:18:52.189411 21085 maintenance_manager.cc:643] P ed46bdcf8fbb41b4b16b9a0f24e6db42: FlushDeltaMemStoresOp(d85e95ddae73456f9799bef2f80cc4f6) complete. Timing: real 0.010s	user 0.006s	sys 0.003s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4167,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:52.190022 21179 maintenance_manager.cc:419] P ed46bdcf8fbb41b4b16b9a0f24e6db42: Scheduling MajorDeltaCompactionOp(d85e95ddae73456f9799bef2f80cc4f6): perf score=1.000000
I20260812 06:18:52.314942 21085 maintenance_manager.cc:643] P ed46bdcf8fbb41b4b16b9a0f24e6db42: MajorDeltaCompactionOp(d85e95ddae73456f9799bef2f80cc4f6) complete. Timing: real 0.125s	user 0.092s	sys 0.032s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672277,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":199,"lbm_read_time_us":8953,"lbm_reads_lt_1ms":472,"lbm_write_time_us":24776,"lbm_writes_lt_1ms":443,"mutex_wait_us":26,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":5888,"update_count":2000}
I20260812 06:18:52.315618 21179 maintenance_manager.cc:419] P ed46bdcf8fbb41b4b16b9a0f24e6db42: Scheduling FlushDeltaMemStoresOp(d85e95ddae73456f9799bef2f80cc4f6): perf score=10.126437
I20260812 06:18:52.367430 21085 maintenance_manager.cc:643] P ed46bdcf8fbb41b4b16b9a0f24e6db42: FlushDeltaMemStoresOp(d85e95ddae73456f9799bef2f80cc4f6) complete. Timing: real 0.052s	user 0.009s	sys 0.042s Metrics: {"bytes_written":12307491,"delete_count":0,"lbm_write_time_us":19388,"lbm_writes_1-10_ms":2,"lbm_writes_lt_1ms":301,"reinsert_count":0,"update_count":1500}
I20260812 06:18:52.368072 21179 maintenance_manager.cc:419] P ed46bdcf8fbb41b4b16b9a0f24e6db42: Scheduling FlushDeltaMemStoresOp(d85e95ddae73456f9799bef2f80cc4f6): perf score=2.188937
I20260812 06:18:52.379916 21085 maintenance_manager.cc:643] P ed46bdcf8fbb41b4b16b9a0f24e6db42: FlushDeltaMemStoresOp(d85e95ddae73456f9799bef2f80cc4f6) complete. Timing: real 0.012s	user 0.010s	sys 0.001s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4604,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:52.380544 21179 maintenance_manager.cc:419] P ed46bdcf8fbb41b4b16b9a0f24e6db42: Scheduling MajorDeltaCompactionOp(d85e95ddae73456f9799bef2f80cc4f6): perf score=1.000000
I20260812 06:18:52.530503 21085 maintenance_manager.cc:643] P ed46bdcf8fbb41b4b16b9a0f24e6db42: MajorDeltaCompactionOp(d85e95ddae73456f9799bef2f80cc4f6) complete. Timing: real 0.150s	user 0.110s	sys 0.036s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672278,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":413,"lbm_read_time_us":13351,"lbm_reads_1-10_ms":1,"lbm_reads_lt_1ms":471,"lbm_write_time_us":26100,"lbm_writes_lt_1ms":443,"mutex_wait_us":51,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":1792,"update_count":2000}
I20260812 06:18:52.531260 21179 maintenance_manager.cc:419] P ed46bdcf8fbb41b4b16b9a0f24e6db42: Scheduling FlushDeltaMemStoresOp(d85e95ddae73456f9799bef2f80cc4f6): perf score=10.126437
I20260812 06:18:52.579139 21085 maintenance_manager.cc:643] P ed46bdcf8fbb41b4b16b9a0f24e6db42: FlushDeltaMemStoresOp(d85e95ddae73456f9799bef2f80cc4f6) complete. Timing: real 0.048s	user 0.019s	sys 0.017s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":18473,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:18:52.579653 21179 maintenance_manager.cc:419] P ed46bdcf8fbb41b4b16b9a0f24e6db42: Scheduling FlushDeltaMemStoresOp(d85e95ddae73456f9799bef2f80cc4f6): perf score=2.188937
I20260812 06:18:52.590133 21085 maintenance_manager.cc:643] P ed46bdcf8fbb41b4b16b9a0f24e6db42: FlushDeltaMemStoresOp(d85e95ddae73456f9799bef2f80cc4f6) complete. Timing: real 0.010s	user 0.005s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4104,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:52.590938 21179 maintenance_manager.cc:419] P ed46bdcf8fbb41b4b16b9a0f24e6db42: Scheduling FlushMRSOp(d85e95ddae73456f9799bef2f80cc4f6): perf score=1.000000
I20260812 06:18:52.621610 21085 maintenance_manager.cc:643] P ed46bdcf8fbb41b4b16b9a0f24e6db42: FlushMRSOp(d85e95ddae73456f9799bef2f80cc4f6) complete. Timing: real 0.030s	user 0.029s	sys 0.000s Metrics: {"bytes_written":1234473,"cfile_init":1,"dirs.queue_time_us":54,"dirs.run_cpu_time_us":198,"dirs.run_wall_time_us":1071,"drs_written":1,"lbm_read_time_us":41,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1920,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":30}
I20260812 06:18:52.622413 21179 maintenance_manager.cc:419] P ed46bdcf8fbb41b4b16b9a0f24e6db42: Scheduling LogGCOp(d85e95ddae73456f9799bef2f80cc4f6): free 120553393 bytes of WAL
I20260812 06:18:52.622666 21085 log_reader.cc:385] T d85e95ddae73456f9799bef2f80cc4f6: removed 12 log segments from log reader
I20260812 06:18:52.622711 21085 log.cc:1079] T d85e95ddae73456f9799bef2f80cc4f6 P ed46bdcf8fbb41b4b16b9a0f24e6db42: Deleting log segment in path: /tmp/dist-test-taskkQAF1q/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515530630243-20910-0/minicluster-data/ts-0-root/wals/d85e95ddae73456f9799bef2f80cc4f6/wal-000000003 (ops 12-16)
I20260812 06:18:52.622741 21085 log.cc:1079] T d85e95ddae73456f9799bef2f80cc4f6 P ed46bdcf8fbb41b4b16b9a0f24e6db42: Deleting log segment in path: /tmp/dist-test-taskkQAF1q/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515530630243-20910-0/minicluster-data/ts-0-root/wals/d85e95ddae73456f9799bef2f80cc4f6/wal-000000004 (ops 17-21)
I20260812 06:18:52.622807 21085 log.cc:1079] T d85e95ddae73456f9799bef2f80cc4f6 P ed46bdcf8fbb41b4b16b9a0f24e6db42: Deleting log segment in path: /tmp/dist-test-taskkQAF1q/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515530630243-20910-0/minicluster-data/ts-0-root/wals/d85e95ddae73456f9799bef2f80cc4f6/wal-000000005 (ops 22-26)
I20260812 06:18:52.622849 21085 log.cc:1079] T d85e95ddae73456f9799bef2f80cc4f6 P ed46bdcf8fbb41b4b16b9a0f24e6db42: Deleting log segment in path: /tmp/dist-test-taskkQAF1q/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515530630243-20910-0/minicluster-data/ts-0-root/wals/d85e95ddae73456f9799bef2f80cc4f6/wal-000000006 (ops 27-31)
I20260812 06:18:52.622893 21085 log.cc:1079] T d85e95ddae73456f9799bef2f80cc4f6 P ed46bdcf8fbb41b4b16b9a0f24e6db42: Deleting log segment in path: /tmp/dist-test-taskkQAF1q/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515530630243-20910-0/minicluster-data/ts-0-root/wals/d85e95ddae73456f9799bef2f80cc4f6/wal-000000007 (ops 32-36)
I20260812 06:18:52.622956 21085 log.cc:1079] T d85e95ddae73456f9799bef2f80cc4f6 P ed46bdcf8fbb41b4b16b9a0f24e6db42: Deleting log segment in path: /tmp/dist-test-taskkQAF1q/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515530630243-20910-0/minicluster-data/ts-0-root/wals/d85e95ddae73456f9799bef2f80cc4f6/wal-000000008 (ops 37-40)
I20260812 06:18:52.622993 21085 log.cc:1079] T d85e95ddae73456f9799bef2f80cc4f6 P ed46bdcf8fbb41b4b16b9a0f24e6db42: Deleting log segment in path: /tmp/dist-test-taskkQAF1q/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515530630243-20910-0/minicluster-data/ts-0-root/wals/d85e95ddae73456f9799bef2f80cc4f6/wal-000000009 (ops 41-45)
I20260812 06:18:52.623049 21085 log.cc:1079] T d85e95ddae73456f9799bef2f80cc4f6 P ed46bdcf8fbb41b4b16b9a0f24e6db42: Deleting log segment in path: /tmp/dist-test-taskkQAF1q/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515530630243-20910-0/minicluster-data/ts-0-root/wals/d85e95ddae73456f9799bef2f80cc4f6/wal-000000010 (ops 46-50)
I20260812 06:18:52.623091 21085 log.cc:1079] T d85e95ddae73456f9799bef2f80cc4f6 P ed46bdcf8fbb41b4b16b9a0f24e6db42: Deleting log segment in path: /tmp/dist-test-taskkQAF1q/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515530630243-20910-0/minicluster-data/ts-0-root/wals/d85e95ddae73456f9799bef2f80cc4f6/wal-000000011 (ops 51-54)
I20260812 06:18:52.623131 21085 log.cc:1079] T d85e95ddae73456f9799bef2f80cc4f6 P ed46bdcf8fbb41b4b16b9a0f24e6db42: Deleting log segment in path: /tmp/dist-test-taskkQAF1q/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515530630243-20910-0/minicluster-data/ts-0-root/wals/d85e95ddae73456f9799bef2f80cc4f6/wal-000000012 (ops 55-59)
I20260812 06:18:52.623174 21085 log.cc:1079] T d85e95ddae73456f9799bef2f80cc4f6 P ed46bdcf8fbb41b4b16b9a0f24e6db42: Deleting log segment in path: /tmp/dist-test-taskkQAF1q/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515530630243-20910-0/minicluster-data/ts-0-root/wals/d85e95ddae73456f9799bef2f80cc4f6/wal-000000013 (ops 60-64)
I20260812 06:18:52.623238 21085 log.cc:1079] T d85e95ddae73456f9799bef2f80cc4f6 P ed46bdcf8fbb41b4b16b9a0f24e6db42: Deleting log segment in path: /tmp/dist-test-taskkQAF1q/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515530630243-20910-0/minicluster-data/ts-0-root/wals/d85e95ddae73456f9799bef2f80cc4f6/wal-000000014 (ops 65-69)
I20260812 06:18:52.649294 21085 maintenance_manager.cc:643] P ed46bdcf8fbb41b4b16b9a0f24e6db42: LogGCOp(d85e95ddae73456f9799bef2f80cc4f6) complete. Timing: real 0.027s	user 0.002s	sys 0.023s Metrics: {}
I20260812 06:18:52.649735 21179 maintenance_manager.cc:419] P ed46bdcf8fbb41b4b16b9a0f24e6db42: Scheduling FlushDeltaMemStoresOp(d85e95ddae73456f9799bef2f80cc4f6): perf score=3.181125
I20260812 06:18:52.661578 21085 maintenance_manager.cc:643] P ed46bdcf8fbb41b4b16b9a0f24e6db42: FlushDeltaMemStoresOp(d85e95ddae73456f9799bef2f80cc4f6) complete. Timing: real 0.012s	user 0.007s	sys 0.003s Metrics: {"bytes_written":4594953,"delete_count":0,"lbm_write_time_us":4704,"lbm_writes_lt_1ms":115,"reinsert_count":0,"update_count":560}
I20260812 06:18:52.661954 21179 maintenance_manager.cc:419] P ed46bdcf8fbb41b4b16b9a0f24e6db42: Scheduling FlushDeltaMemStoresOp(d85e95ddae73456f9799bef2f80cc4f6): perf score=2.188937
I20260812 06:18:52.678596 21085 maintenance_manager.cc:643] P ed46bdcf8fbb41b4b16b9a0f24e6db42: FlushDeltaMemStoresOp(d85e95ddae73456f9799bef2f80cc4f6) complete. Timing: real 0.016s	user 0.006s	sys 0.007s Metrics: {"bytes_written":3610355,"delete_count":0,"lbm_write_time_us":3608,"lbm_writes_lt_1ms":91,"reinsert_count":0,"update_count":440}
I20260812 06:18:52.679080 21179 maintenance_manager.cc:419] P ed46bdcf8fbb41b4b16b9a0f24e6db42: Scheduling MajorDeltaCompactionOp(d85e95ddae73456f9799bef2f80cc4f6): perf score=1.000000
I20260812 06:18:52.871799 21085 maintenance_manager.cc:643] P ed46bdcf8fbb41b4b16b9a0f24e6db42: MajorDeltaCompactionOp(d85e95ddae73456f9799bef2f80cc4f6) complete. Timing: real 0.192s	user 0.130s	sys 0.061s Metrics: {"cfile_cache_miss":634,"cfile_cache_miss_bytes":28877329,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":2477,"lbm_read_time_us":15685,"lbm_reads_lt_1ms":674,"lbm_write_time_us":31939,"lbm_writes_lt_1ms":643,"mutex_wait_us":1072,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":1792,"thread_start_us":84,"threads_started":1,"update_count":3000}
I20260812 06:18:52.872429 21179 maintenance_manager.cc:419] P ed46bdcf8fbb41b4b16b9a0f24e6db42: Scheduling FlushDeltaMemStoresOp(d85e95ddae73456f9799bef2f80cc4f6): perf score=11.118625
I20260812 06:18:52.905700 21085 maintenance_manager.cc:643] P ed46bdcf8fbb41b4b16b9a0f24e6db42: FlushDeltaMemStoresOp(d85e95ddae73456f9799bef2f80cc4f6) complete. Timing: real 0.033s	user 0.018s	sys 0.013s Metrics: {"bytes_written":12717735,"delete_count":0,"lbm_write_time_us":14681,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:18:52.906299 21179 maintenance_manager.cc:419] P ed46bdcf8fbb41b4b16b9a0f24e6db42: Scheduling FlushDeltaMemStoresOp(d85e95ddae73456f9799bef2f80cc4f6): perf score=2.188937
I20260812 06:18:52.920850 21085 maintenance_manager.cc:643] P ed46bdcf8fbb41b4b16b9a0f24e6db42: FlushDeltaMemStoresOp(d85e95ddae73456f9799bef2f80cc4f6) complete. Timing: real 0.014s	user 0.009s	sys 0.004s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":5454,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:18:52.921401 21179 maintenance_manager.cc:419] P ed46bdcf8fbb41b4b16b9a0f24e6db42: Scheduling MajorDeltaCompactionOp(d85e95ddae73456f9799bef2f80cc4f6): perf score=1.000000
I20260812 06:18:53.089313 21085 maintenance_manager.cc:643] P ed46bdcf8fbb41b4b16b9a0f24e6db42: MajorDeltaCompactionOp(d85e95ddae73456f9799bef2f80cc4f6) complete. Timing: real 0.166s	user 0.111s	sys 0.038s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672268,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":284,"lbm_read_time_us":9269,"lbm_reads_lt_1ms":464,"lbm_write_time_us":24571,"lbm_writes_lt_1ms":443,"peak_mem_usage":50689328,"reinsert_count":0,"update_count":2000}
I20260812 06:18:53.090016 21179 maintenance_manager.cc:419] P ed46bdcf8fbb41b4b16b9a0f24e6db42: Scheduling UndoDeltaBlockGCOp(d85e95ddae73456f9799bef2f80cc4f6): 473 bytes on disk
I20260812 06:18:53.090498 21085 maintenance_manager.cc:643] P ed46bdcf8fbb41b4b16b9a0f24e6db42: UndoDeltaBlockGCOp(d85e95ddae73456f9799bef2f80cc4f6) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":57,"lbm_reads_lt_1ms":4}
I20260812 06:18:53.091020 21179 maintenance_manager.cc:419] P ed46bdcf8fbb41b4b16b9a0f24e6db42: Scheduling FlushDeltaMemStoresOp(d85e95ddae73456f9799bef2f80cc4f6): perf score=14.095187
I20260812 06:18:53.143616 21085 maintenance_manager.cc:643] P ed46bdcf8fbb41b4b16b9a0f24e6db42: FlushDeltaMemStoresOp(d85e95ddae73456f9799bef2f80cc4f6) complete. Timing: real 0.052s	user 0.041s	sys 0.007s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":21332,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:18:53.144040 21179 maintenance_manager.cc:419] P ed46bdcf8fbb41b4b16b9a0f24e6db42: Scheduling FlushDeltaMemStoresOp(d85e95ddae73456f9799bef2f80cc4f6): perf score=2.188937
I20260812 06:18:53.154109 21085 maintenance_manager.cc:643] P ed46bdcf8fbb41b4b16b9a0f24e6db42: FlushDeltaMemStoresOp(d85e95ddae73456f9799bef2f80cc4f6) complete. Timing: real 0.010s	user 0.008s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3797,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:53.154627 21179 maintenance_manager.cc:419] P ed46bdcf8fbb41b4b16b9a0f24e6db42: Scheduling MajorDeltaCompactionOp(d85e95ddae73456f9799bef2f80cc4f6): perf score=1.000000
I20260812 06:18:53.306371 21085 maintenance_manager.cc:643] P ed46bdcf8fbb41b4b16b9a0f24e6db42: MajorDeltaCompactionOp(d85e95ddae73456f9799bef2f80cc4f6) complete. Timing: real 0.152s	user 0.121s	sys 0.019s 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":613,"lbm_read_time_us":9819,"lbm_reads_lt_1ms":572,"lbm_write_time_us":28981,"lbm_writes_lt_1ms":543,"mutex_wait_us":272,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":3200,"update_count":2500}
I20260812 06:18:53.306926 21179 maintenance_manager.cc:419] P ed46bdcf8fbb41b4b16b9a0f24e6db42: Scheduling FlushDeltaMemStoresOp(d85e95ddae73456f9799bef2f80cc4f6): perf score=14.095187
I20260812 06:18:53.357836 21085 maintenance_manager.cc:643] P ed46bdcf8fbb41b4b16b9a0f24e6db42: FlushDeltaMemStoresOp(d85e95ddae73456f9799bef2f80cc4f6) complete. Timing: real 0.051s	user 0.032s	sys 0.007s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":18552,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:18:53.358367 21179 maintenance_manager.cc:419] P ed46bdcf8fbb41b4b16b9a0f24e6db42: Scheduling FlushDeltaMemStoresOp(d85e95ddae73456f9799bef2f80cc4f6): perf score=2.188937
I20260812 06:18:53.373463 21085 maintenance_manager.cc:643] P ed46bdcf8fbb41b4b16b9a0f24e6db42: FlushDeltaMemStoresOp(d85e95ddae73456f9799bef2f80cc4f6) complete. Timing: real 0.015s	user 0.009s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5610,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:53.374044 21179 maintenance_manager.cc:419] P ed46bdcf8fbb41b4b16b9a0f24e6db42: Scheduling MajorDeltaCompactionOp(d85e95ddae73456f9799bef2f80cc4f6): perf score=1.000000
I20260812 06:18:53.533812 21085 maintenance_manager.cc:643] P ed46bdcf8fbb41b4b16b9a0f24e6db42: MajorDeltaCompactionOp(d85e95ddae73456f9799bef2f80cc4f6) complete. Timing: real 0.160s	user 0.116s	sys 0.044s 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":536,"lbm_read_time_us":10952,"lbm_reads_lt_1ms":572,"lbm_write_time_us":33434,"lbm_writes_lt_1ms":543,"mutex_wait_us":113,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":10624,"update_count":2500}
I20260812 06:18:53.534421 21179 maintenance_manager.cc:419] P ed46bdcf8fbb41b4b16b9a0f24e6db42: Scheduling FlushDeltaMemStoresOp(d85e95ddae73456f9799bef2f80cc4f6): perf score=10.126437
I20260812 06:18:53.575855 21085 maintenance_manager.cc:643] P ed46bdcf8fbb41b4b16b9a0f24e6db42: FlushDeltaMemStoresOp(d85e95ddae73456f9799bef2f80cc4f6) complete. Timing: real 0.041s	user 0.018s	sys 0.019s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":16269,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:18:53.576439 21179 maintenance_manager.cc:419] P ed46bdcf8fbb41b4b16b9a0f24e6db42: Scheduling FlushDeltaMemStoresOp(d85e95ddae73456f9799bef2f80cc4f6): perf score=2.188937
I20260812 06:18:53.586658 21085 maintenance_manager.cc:643] P ed46bdcf8fbb41b4b16b9a0f24e6db42: FlushDeltaMemStoresOp(d85e95ddae73456f9799bef2f80cc4f6) complete. Timing: real 0.010s	user 0.008s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3826,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:53.587255 21179 maintenance_manager.cc:419] P ed46bdcf8fbb41b4b16b9a0f24e6db42: Scheduling MajorDeltaCompactionOp(d85e95ddae73456f9799bef2f80cc4f6): perf score=1.000000
I20260812 06:18:53.718119 21085 maintenance_manager.cc:643] P ed46bdcf8fbb41b4b16b9a0f24e6db42: MajorDeltaCompactionOp(d85e95ddae73456f9799bef2f80cc4f6) complete. Timing: real 0.131s	user 0.118s	sys 0.013s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672277,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":302,"lbm_read_time_us":9403,"lbm_reads_lt_1ms":472,"lbm_write_time_us":23342,"lbm_writes_lt_1ms":443,"mutex_wait_us":3,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":2944,"update_count":2000}
I20260812 06:18:53.718842 21179 maintenance_manager.cc:419] P ed46bdcf8fbb41b4b16b9a0f24e6db42: Scheduling FlushDeltaMemStoresOp(d85e95ddae73456f9799bef2f80cc4f6): perf score=10.126437
I20260812 06:18:53.773063 21085 maintenance_manager.cc:643] P ed46bdcf8fbb41b4b16b9a0f24e6db42: FlushDeltaMemStoresOp(d85e95ddae73456f9799bef2f80cc4f6) complete. Timing: real 0.054s	user 0.026s	sys 0.023s Metrics: {"bytes_written":12307491,"delete_count":0,"lbm_write_time_us":21077,"lbm_writes_1-10_ms":2,"lbm_writes_lt_1ms":301,"reinsert_count":0,"update_count":1500}
I20260812 06:18:53.773695 21179 maintenance_manager.cc:419] P ed46bdcf8fbb41b4b16b9a0f24e6db42: Scheduling FlushDeltaMemStoresOp(d85e95ddae73456f9799bef2f80cc4f6): perf score=2.188937
I20260812 06:18:53.784477 21085 maintenance_manager.cc:643] P ed46bdcf8fbb41b4b16b9a0f24e6db42: FlushDeltaMemStoresOp(d85e95ddae73456f9799bef2f80cc4f6) complete. Timing: real 0.011s	user 0.005s	sys 0.004s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4192,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:53.785022 21179 maintenance_manager.cc:419] P ed46bdcf8fbb41b4b16b9a0f24e6db42: Scheduling MajorDeltaCompactionOp(d85e95ddae73456f9799bef2f80cc4f6): perf score=1.000000
I20260812 06:18:53.936600 21085 maintenance_manager.cc:643] P ed46bdcf8fbb41b4b16b9a0f24e6db42: MajorDeltaCompactionOp(d85e95ddae73456f9799bef2f80cc4f6) complete. Timing: real 0.151s	user 0.111s	sys 0.040s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672277,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":756,"lbm_read_time_us":12969,"lbm_reads_lt_1ms":472,"lbm_write_time_us":22973,"lbm_writes_lt_1ms":443,"mutex_wait_us":251,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":8320,"update_count":2000}
I20260812 06:18:53.937094 21179 maintenance_manager.cc:419] P ed46bdcf8fbb41b4b16b9a0f24e6db42: Scheduling FlushDeltaMemStoresOp(d85e95ddae73456f9799bef2f80cc4f6): perf score=10.126437
I20260812 06:18:53.982919 21085 maintenance_manager.cc:643] P ed46bdcf8fbb41b4b16b9a0f24e6db42: FlushDeltaMemStoresOp(d85e95ddae73456f9799bef2f80cc4f6) complete. Timing: real 0.046s	user 0.018s	sys 0.016s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":16603,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:18:53.983438 21179 maintenance_manager.cc:419] P ed46bdcf8fbb41b4b16b9a0f24e6db42: Scheduling FlushDeltaMemStoresOp(d85e95ddae73456f9799bef2f80cc4f6): perf score=2.188937
I20260812 06:18:53.994560 21085 maintenance_manager.cc:643] P ed46bdcf8fbb41b4b16b9a0f24e6db42: FlushDeltaMemStoresOp(d85e95ddae73456f9799bef2f80cc4f6) complete. Timing: real 0.011s	user 0.008s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4131,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:53.995055 21179 maintenance_manager.cc:419] P ed46bdcf8fbb41b4b16b9a0f24e6db42: Scheduling FlushMRSOp(d85e95ddae73456f9799bef2f80cc4f6): perf score=1.000000
I20260812 06:18:54.025977 21085 maintenance_manager.cc:643] P ed46bdcf8fbb41b4b16b9a0f24e6db42: FlushMRSOp(d85e95ddae73456f9799bef2f80cc4f6) complete. Timing: real 0.031s	user 0.029s	sys 0.000s Metrics: {"bytes_written":1152514,"cfile_init":1,"dirs.queue_time_us":56,"dirs.run_cpu_time_us":179,"dirs.run_wall_time_us":1211,"drs_written":1,"lbm_read_time_us":36,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1389,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":28}
I20260812 06:18:54.026714 21179 maintenance_manager.cc:419] P ed46bdcf8fbb41b4b16b9a0f24e6db42: Scheduling LogGCOp(d85e95ddae73456f9799bef2f80cc4f6): free 115943189 bytes of WAL
I20260812 06:18:54.026944 21085 log_reader.cc:385] T d85e95ddae73456f9799bef2f80cc4f6: removed 11 log segments from log reader
I20260812 06:18:54.026991 21085 log.cc:1079] T d85e95ddae73456f9799bef2f80cc4f6 P ed46bdcf8fbb41b4b16b9a0f24e6db42: Deleting log segment in path: /tmp/dist-test-taskkQAF1q/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515530630243-20910-0/minicluster-data/ts-0-root/wals/d85e95ddae73456f9799bef2f80cc4f6/wal-000000015 (ops 70-74)
I20260812 06:18:54.027019 21085 log.cc:1079] T d85e95ddae73456f9799bef2f80cc4f6 P ed46bdcf8fbb41b4b16b9a0f24e6db42: Deleting log segment in path: /tmp/dist-test-taskkQAF1q/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515530630243-20910-0/minicluster-data/ts-0-root/wals/d85e95ddae73456f9799bef2f80cc4f6/wal-000000016 (ops 75-79)
I20260812 06:18:54.027086 21085 log.cc:1079] T d85e95ddae73456f9799bef2f80cc4f6 P ed46bdcf8fbb41b4b16b9a0f24e6db42: Deleting log segment in path: /tmp/dist-test-taskkQAF1q/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515530630243-20910-0/minicluster-data/ts-0-root/wals/d85e95ddae73456f9799bef2f80cc4f6/wal-000000017 (ops 80-84)
I20260812 06:18:54.027130 21085 log.cc:1079] T d85e95ddae73456f9799bef2f80cc4f6 P ed46bdcf8fbb41b4b16b9a0f24e6db42: Deleting log segment in path: /tmp/dist-test-taskkQAF1q/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515530630243-20910-0/minicluster-data/ts-0-root/wals/d85e95ddae73456f9799bef2f80cc4f6/wal-000000018 (ops 85-89)
I20260812 06:18:54.027176 21085 log.cc:1079] T d85e95ddae73456f9799bef2f80cc4f6 P ed46bdcf8fbb41b4b16b9a0f24e6db42: Deleting log segment in path: /tmp/dist-test-taskkQAF1q/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515530630243-20910-0/minicluster-data/ts-0-root/wals/d85e95ddae73456f9799bef2f80cc4f6/wal-000000019 (ops 90-94)
I20260812 06:18:54.027258 21085 log.cc:1079] T d85e95ddae73456f9799bef2f80cc4f6 P ed46bdcf8fbb41b4b16b9a0f24e6db42: Deleting log segment in path: /tmp/dist-test-taskkQAF1q/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515530630243-20910-0/minicluster-data/ts-0-root/wals/d85e95ddae73456f9799bef2f80cc4f6/wal-000000020 (ops 95-99)
I20260812 06:18:54.027302 21085 log.cc:1079] T d85e95ddae73456f9799bef2f80cc4f6 P ed46bdcf8fbb41b4b16b9a0f24e6db42: Deleting log segment in path: /tmp/dist-test-taskkQAF1q/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515530630243-20910-0/minicluster-data/ts-0-root/wals/d85e95ddae73456f9799bef2f80cc4f6/wal-000000021 (ops 100-104)
I20260812 06:18:54.027341 21085 log.cc:1079] T d85e95ddae73456f9799bef2f80cc4f6 P ed46bdcf8fbb41b4b16b9a0f24e6db42: Deleting log segment in path: /tmp/dist-test-taskkQAF1q/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515530630243-20910-0/minicluster-data/ts-0-root/wals/d85e95ddae73456f9799bef2f80cc4f6/wal-000000022 (ops 105-109)
I20260812 06:18:54.027382 21085 log.cc:1079] T d85e95ddae73456f9799bef2f80cc4f6 P ed46bdcf8fbb41b4b16b9a0f24e6db42: Deleting log segment in path: /tmp/dist-test-taskkQAF1q/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515530630243-20910-0/minicluster-data/ts-0-root/wals/d85e95ddae73456f9799bef2f80cc4f6/wal-000000023 (ops 110-114)
I20260812 06:18:54.027421 21085 log.cc:1079] T d85e95ddae73456f9799bef2f80cc4f6 P ed46bdcf8fbb41b4b16b9a0f24e6db42: Deleting log segment in path: /tmp/dist-test-taskkQAF1q/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515530630243-20910-0/minicluster-data/ts-0-root/wals/d85e95ddae73456f9799bef2f80cc4f6/wal-000000024 (ops 115-119)
I20260812 06:18:54.027463 21085 log.cc:1079] T d85e95ddae73456f9799bef2f80cc4f6 P ed46bdcf8fbb41b4b16b9a0f24e6db42: Deleting log segment in path: /tmp/dist-test-taskkQAF1q/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515530630243-20910-0/minicluster-data/ts-0-root/wals/d85e95ddae73456f9799bef2f80cc4f6/wal-000000025 (ops 120-124)
I20260812 06:18:54.055270 21085 maintenance_manager.cc:643] P ed46bdcf8fbb41b4b16b9a0f24e6db42: LogGCOp(d85e95ddae73456f9799bef2f80cc4f6) complete. Timing: real 0.028s	user 0.005s	sys 0.023s Metrics: {}
I20260812 06:18:54.055742 21179 maintenance_manager.cc:419] P ed46bdcf8fbb41b4b16b9a0f24e6db42: Scheduling UndoDeltaBlockGCOp(d85e95ddae73456f9799bef2f80cc4f6): 447 bytes on disk
I20260812 06:18:54.056295 21085 maintenance_manager.cc:643] P ed46bdcf8fbb41b4b16b9a0f24e6db42: UndoDeltaBlockGCOp(d85e95ddae73456f9799bef2f80cc4f6) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":89,"lbm_reads_lt_1ms":4}
I20260812 06:18:54.056835 21179 maintenance_manager.cc:419] P ed46bdcf8fbb41b4b16b9a0f24e6db42: Scheduling FlushDeltaMemStoresOp(d85e95ddae73456f9799bef2f80cc4f6): perf score=3.181125
I20260812 06:18:54.080134 21085 maintenance_manager.cc:643] P ed46bdcf8fbb41b4b16b9a0f24e6db42: FlushDeltaMemStoresOp(d85e95ddae73456f9799bef2f80cc4f6) complete. Timing: real 0.023s	user 0.009s	sys 0.011s Metrics: {"bytes_written":4512902,"delete_count":0,"lbm_write_time_us":4637,"lbm_writes_lt_1ms":113,"reinsert_count":0,"update_count":550}
I20260812 06:18:54.080659 21179 maintenance_manager.cc:419] P ed46bdcf8fbb41b4b16b9a0f24e6db42: Scheduling FlushDeltaMemStoresOp(d85e95ddae73456f9799bef2f80cc4f6): perf score=2.188937
I20260812 06:18:54.092398 21085 maintenance_manager.cc:643] P ed46bdcf8fbb41b4b16b9a0f24e6db42: FlushDeltaMemStoresOp(d85e95ddae73456f9799bef2f80cc4f6) complete. Timing: real 0.012s	user 0.010s	sys 0.001s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":4581,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:18:54.092979 21179 maintenance_manager.cc:419] P ed46bdcf8fbb41b4b16b9a0f24e6db42: Scheduling MajorDeltaCompactionOp(d85e95ddae73456f9799bef2f80cc4f6): perf score=1.000000
I20260812 06:18:54.318017 21085 maintenance_manager.cc:643] P ed46bdcf8fbb41b4b16b9a0f24e6db42: MajorDeltaCompactionOp(d85e95ddae73456f9799bef2f80cc4f6) complete. Timing: real 0.225s	user 0.134s	sys 0.090s Metrics: {"cfile_cache_miss":634,"cfile_cache_miss_bytes":28877328,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":879,"lbm_read_time_us":16621,"lbm_reads_lt_1ms":674,"lbm_write_time_us":40766,"lbm_writes_lt_1ms":643,"mutex_wait_us":295,"peak_mem_usage":75542472,"reinsert_count":0,"thread_start_us":80,"threads_started":1,"update_count":3000}
I20260812 06:18:54.318790 21179 maintenance_manager.cc:419] P ed46bdcf8fbb41b4b16b9a0f24e6db42: Scheduling FlushDeltaMemStoresOp(d85e95ddae73456f9799bef2f80cc4f6): perf score=14.095187
I20260812 06:18:54.390986 21085 maintenance_manager.cc:643] P ed46bdcf8fbb41b4b16b9a0f24e6db42: FlushDeltaMemStoresOp(d85e95ddae73456f9799bef2f80cc4f6) complete. Timing: real 0.072s	user 0.028s	sys 0.039s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":26670,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:18:54.391588 21179 maintenance_manager.cc:419] P ed46bdcf8fbb41b4b16b9a0f24e6db42: Scheduling FlushDeltaMemStoresOp(d85e95ddae73456f9799bef2f80cc4f6): perf score=2.188937
I20260812 06:18:54.404618 21085 maintenance_manager.cc:643] P ed46bdcf8fbb41b4b16b9a0f24e6db42: FlushDeltaMemStoresOp(d85e95ddae73456f9799bef2f80cc4f6) complete. Timing: real 0.013s	user 0.007s	sys 0.005s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4651,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:54.405079 21179 maintenance_manager.cc:419] P ed46bdcf8fbb41b4b16b9a0f24e6db42: Scheduling MajorDeltaCompactionOp(d85e95ddae73456f9799bef2f80cc4f6): perf score=1.000000
I20260812 06:18:54.602470 21085 maintenance_manager.cc:643] P ed46bdcf8fbb41b4b16b9a0f24e6db42: MajorDeltaCompactionOp(d85e95ddae73456f9799bef2f80cc4f6) complete. Timing: real 0.197s	user 0.123s	sys 0.069s 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":375,"lbm_read_time_us":14639,"lbm_reads_lt_1ms":572,"lbm_write_time_us":34811,"lbm_writes_lt_1ms":543,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":768,"update_count":2500}
I20260812 06:18:54.603042 21179 maintenance_manager.cc:419] P ed46bdcf8fbb41b4b16b9a0f24e6db42: Scheduling FlushDeltaMemStoresOp(d85e95ddae73456f9799bef2f80cc4f6): perf score=14.095187
I20260812 06:18:54.651791 21085 maintenance_manager.cc:643] P ed46bdcf8fbb41b4b16b9a0f24e6db42: FlushDeltaMemStoresOp(d85e95ddae73456f9799bef2f80cc4f6) complete. Timing: real 0.049s	user 0.026s	sys 0.016s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":18874,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:18:54.652292 21179 maintenance_manager.cc:419] P ed46bdcf8fbb41b4b16b9a0f24e6db42: Scheduling FlushDeltaMemStoresOp(d85e95ddae73456f9799bef2f80cc4f6): perf score=2.188937
I20260812 06:18:54.677373 21085 maintenance_manager.cc:643] P ed46bdcf8fbb41b4b16b9a0f24e6db42: FlushDeltaMemStoresOp(d85e95ddae73456f9799bef2f80cc4f6) complete. Timing: real 0.025s	user 0.011s	sys 0.012s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6130,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:54.677966 21179 maintenance_manager.cc:419] P ed46bdcf8fbb41b4b16b9a0f24e6db42: Scheduling MajorDeltaCompactionOp(d85e95ddae73456f9799bef2f80cc4f6): perf score=1.000000
I20260812 06:18:54.859364 21085 maintenance_manager.cc:643] P ed46bdcf8fbb41b4b16b9a0f24e6db42: MajorDeltaCompactionOp(d85e95ddae73456f9799bef2f80cc4f6) complete. Timing: real 0.181s	user 0.133s	sys 0.037s 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":789,"lbm_read_time_us":11097,"lbm_reads_lt_1ms":572,"lbm_write_time_us":29954,"lbm_writes_lt_1ms":543,"mutex_wait_us":289,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":4864,"update_count":2500}
I20260812 06:18:54.860116 21179 maintenance_manager.cc:419] P ed46bdcf8fbb41b4b16b9a0f24e6db42: Scheduling FlushDeltaMemStoresOp(d85e95ddae73456f9799bef2f80cc4f6): perf score=14.095187
I20260812 06:18:54.906826 21085 maintenance_manager.cc:643] P ed46bdcf8fbb41b4b16b9a0f24e6db42: FlushDeltaMemStoresOp(d85e95ddae73456f9799bef2f80cc4f6) complete. Timing: real 0.047s	user 0.026s	sys 0.017s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":20643,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:18:54.907399 21179 maintenance_manager.cc:419] P ed46bdcf8fbb41b4b16b9a0f24e6db42: Scheduling FlushDeltaMemStoresOp(d85e95ddae73456f9799bef2f80cc4f6): perf score=2.188937
I20260812 06:18:54.921159 21085 maintenance_manager.cc:643] P ed46bdcf8fbb41b4b16b9a0f24e6db42: FlushDeltaMemStoresOp(d85e95ddae73456f9799bef2f80cc4f6) complete. Timing: real 0.014s	user 0.007s	sys 0.005s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":5258,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:54.921715 21179 maintenance_manager.cc:419] P ed46bdcf8fbb41b4b16b9a0f24e6db42: Scheduling MajorDeltaCompactionOp(d85e95ddae73456f9799bef2f80cc4f6): perf score=1.000000
I20260812 06:18:55.109906 21085 maintenance_manager.cc:643] P ed46bdcf8fbb41b4b16b9a0f24e6db42: MajorDeltaCompactionOp(d85e95ddae73456f9799bef2f80cc4f6) complete. Timing: real 0.188s	user 0.116s	sys 0.058s 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":392,"lbm_read_time_us":9307,"lbm_reads_lt_1ms":572,"lbm_write_time_us":32452,"lbm_writes_lt_1ms":543,"peak_mem_usage":63115900,"reinsert_count":0,"update_count":2500}
I20260812 06:18:55.110586 21179 maintenance_manager.cc:419] P ed46bdcf8fbb41b4b16b9a0f24e6db42: Scheduling FlushDeltaMemStoresOp(d85e95ddae73456f9799bef2f80cc4f6): perf score=14.095187
I20260812 06:18:55.170768 21085 maintenance_manager.cc:643] P ed46bdcf8fbb41b4b16b9a0f24e6db42: FlushDeltaMemStoresOp(d85e95ddae73456f9799bef2f80cc4f6) complete. Timing: real 0.060s	user 0.036s	sys 0.020s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":28564,"lbm_writes_1-10_ms":2,"lbm_writes_lt_1ms":401,"reinsert_count":0,"update_count":2000}
I20260812 06:18:55.171669 21179 maintenance_manager.cc:419] P ed46bdcf8fbb41b4b16b9a0f24e6db42: Scheduling FlushDeltaMemStoresOp(d85e95ddae73456f9799bef2f80cc4f6): perf score=2.188937
I20260812 06:18:55.187927 21085 maintenance_manager.cc:643] P ed46bdcf8fbb41b4b16b9a0f24e6db42: FlushDeltaMemStoresOp(d85e95ddae73456f9799bef2f80cc4f6) complete. Timing: real 0.016s	user 0.013s	sys 0.001s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5788,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:55.188436 21179 maintenance_manager.cc:419] P ed46bdcf8fbb41b4b16b9a0f24e6db42: Scheduling MajorDeltaCompactionOp(d85e95ddae73456f9799bef2f80cc4f6): perf score=1.000000
I20260812 06:18:55.349408 21085 maintenance_manager.cc:643] P ed46bdcf8fbb41b4b16b9a0f24e6db42: MajorDeltaCompactionOp(d85e95ddae73456f9799bef2f80cc4f6) complete. Timing: real 0.161s	user 0.101s	sys 0.049s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774688,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":1143,"lbm_read_time_us":9988,"lbm_reads_lt_1ms":564,"lbm_write_time_us":30586,"lbm_writes_lt_1ms":543,"mutex_wait_us":324,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":896,"update_count":2500}
I20260812 06:18:55.349970 21179 maintenance_manager.cc:419] P ed46bdcf8fbb41b4b16b9a0f24e6db42: Scheduling FlushDeltaMemStoresOp(d85e95ddae73456f9799bef2f80cc4f6): perf score=14.095187
I20260812 06:18:55.400202 21085 maintenance_manager.cc:643] P ed46bdcf8fbb41b4b16b9a0f24e6db42: FlushDeltaMemStoresOp(d85e95ddae73456f9799bef2f80cc4f6) complete. Timing: real 0.050s	user 0.032s	sys 0.008s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":18592,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:18:55.400719 21179 maintenance_manager.cc:419] P ed46bdcf8fbb41b4b16b9a0f24e6db42: Scheduling FlushDeltaMemStoresOp(d85e95ddae73456f9799bef2f80cc4f6): perf score=2.188937
I20260812 06:18:55.413046 21085 maintenance_manager.cc:643] P ed46bdcf8fbb41b4b16b9a0f24e6db42: FlushDeltaMemStoresOp(d85e95ddae73456f9799bef2f80cc4f6) complete. Timing: real 0.012s	user 0.005s	sys 0.005s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4684,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:55.413698 21179 maintenance_manager.cc:419] P ed46bdcf8fbb41b4b16b9a0f24e6db42: Scheduling MajorDeltaCompactionOp(d85e95ddae73456f9799bef2f80cc4f6): perf score=1.000000
I20260812 06:18:55.564186 21085 maintenance_manager.cc:643] P ed46bdcf8fbb41b4b16b9a0f24e6db42: MajorDeltaCompactionOp(d85e95ddae73456f9799bef2f80cc4f6) complete. Timing: real 0.150s	user 0.125s	sys 0.025s 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":860,"lbm_read_time_us":11574,"lbm_reads_lt_1ms":572,"lbm_write_time_us":30414,"lbm_writes_lt_1ms":543,"mutex_wait_us":118,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":18048,"update_count":2500}
I20260812 06:18:55.564817 21179 maintenance_manager.cc:419] P ed46bdcf8fbb41b4b16b9a0f24e6db42: Scheduling FlushDeltaMemStoresOp(d85e95ddae73456f9799bef2f80cc4f6): perf score=11.118625
I20260812 06:18:55.598974 21085 maintenance_manager.cc:643] P ed46bdcf8fbb41b4b16b9a0f24e6db42: FlushDeltaMemStoresOp(d85e95ddae73456f9799bef2f80cc4f6) complete. Timing: real 0.034s	user 0.022s	sys 0.008s Metrics: {"bytes_written":12717737,"delete_count":0,"lbm_write_time_us":13842,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:18:55.599550 21179 maintenance_manager.cc:419] P ed46bdcf8fbb41b4b16b9a0f24e6db42: Scheduling FlushDeltaMemStoresOp(d85e95ddae73456f9799bef2f80cc4f6): perf score=2.188937
I20260812 06:18:55.623397 21085 maintenance_manager.cc:643] P ed46bdcf8fbb41b4b16b9a0f24e6db42: FlushDeltaMemStoresOp(d85e95ddae73456f9799bef2f80cc4f6) complete. Timing: real 0.024s	user 0.010s	sys 0.003s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":5355,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:18:55.623880 21179 maintenance_manager.cc:419] P ed46bdcf8fbb41b4b16b9a0f24e6db42: Scheduling FlushDeltaMemStoresOp(d85e95ddae73456f9799bef2f80cc4f6): perf score=2.188937
I20260812 06:18:55.634378 21085 maintenance_manager.cc:643] P ed46bdcf8fbb41b4b16b9a0f24e6db42: FlushDeltaMemStoresOp(d85e95ddae73456f9799bef2f80cc4f6) complete. Timing: real 0.010s	user 0.001s	sys 0.007s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4141,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:55.634814 21179 maintenance_manager.cc:419] P ed46bdcf8fbb41b4b16b9a0f24e6db42: Scheduling FlushMRSOp(d85e95ddae73456f9799bef2f80cc4f6): perf score=1.000000
I20260812 06:18:55.668335 21085 maintenance_manager.cc:643] P ed46bdcf8fbb41b4b16b9a0f24e6db42: FlushMRSOp(d85e95ddae73456f9799bef2f80cc4f6) complete. Timing: real 0.033s	user 0.028s	sys 0.004s Metrics: {"bytes_written":1316417,"cfile_init":1,"dirs.queue_time_us":59,"dirs.run_cpu_time_us":255,"dirs.run_wall_time_us":1197,"drs_written":1,"lbm_read_time_us":87,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1669,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":32}
I20260812 06:18:55.668985 21179 maintenance_manager.cc:419] P ed46bdcf8fbb41b4b16b9a0f24e6db42: Scheduling LogGCOp(d85e95ddae73456f9799bef2f80cc4f6): free 133477682 bytes of WAL
I20260812 06:18:55.669214 21085 log_reader.cc:385] T d85e95ddae73456f9799bef2f80cc4f6: removed 13 log segments from log reader
I20260812 06:18:55.669257 21085 log.cc:1079] T d85e95ddae73456f9799bef2f80cc4f6 P ed46bdcf8fbb41b4b16b9a0f24e6db42: Deleting log segment in path: /tmp/dist-test-taskkQAF1q/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515530630243-20910-0/minicluster-data/ts-0-root/wals/d85e95ddae73456f9799bef2f80cc4f6/wal-000000026 (ops 125-129)
I20260812 06:18:55.669286 21085 log.cc:1079] T d85e95ddae73456f9799bef2f80cc4f6 P ed46bdcf8fbb41b4b16b9a0f24e6db42: Deleting log segment in path: /tmp/dist-test-taskkQAF1q/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515530630243-20910-0/minicluster-data/ts-0-root/wals/d85e95ddae73456f9799bef2f80cc4f6/wal-000000027 (ops 130-134)
I20260812 06:18:55.669343 21085 log.cc:1079] T d85e95ddae73456f9799bef2f80cc4f6 P ed46bdcf8fbb41b4b16b9a0f24e6db42: Deleting log segment in path: /tmp/dist-test-taskkQAF1q/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515530630243-20910-0/minicluster-data/ts-0-root/wals/d85e95ddae73456f9799bef2f80cc4f6/wal-000000028 (ops 135-139)
I20260812 06:18:55.669386 21085 log.cc:1079] T d85e95ddae73456f9799bef2f80cc4f6 P ed46bdcf8fbb41b4b16b9a0f24e6db42: Deleting log segment in path: /tmp/dist-test-taskkQAF1q/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515530630243-20910-0/minicluster-data/ts-0-root/wals/d85e95ddae73456f9799bef2f80cc4f6/wal-000000029 (ops 140-144)
I20260812 06:18:55.669415 21085 log.cc:1079] T d85e95ddae73456f9799bef2f80cc4f6 P ed46bdcf8fbb41b4b16b9a0f24e6db42: Deleting log segment in path: /tmp/dist-test-taskkQAF1q/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515530630243-20910-0/minicluster-data/ts-0-root/wals/d85e95ddae73456f9799bef2f80cc4f6/wal-000000030 (ops 145-149)
I20260812 06:18:55.669474 21085 log.cc:1079] T d85e95ddae73456f9799bef2f80cc4f6 P ed46bdcf8fbb41b4b16b9a0f24e6db42: Deleting log segment in path: /tmp/dist-test-taskkQAF1q/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515530630243-20910-0/minicluster-data/ts-0-root/wals/d85e95ddae73456f9799bef2f80cc4f6/wal-000000031 (ops 150-154)
I20260812 06:18:55.669519 21085 log.cc:1079] T d85e95ddae73456f9799bef2f80cc4f6 P ed46bdcf8fbb41b4b16b9a0f24e6db42: Deleting log segment in path: /tmp/dist-test-taskkQAF1q/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515530630243-20910-0/minicluster-data/ts-0-root/wals/d85e95ddae73456f9799bef2f80cc4f6/wal-000000032 (ops 155-159)
I20260812 06:18:55.669561 21085 log.cc:1079] T d85e95ddae73456f9799bef2f80cc4f6 P ed46bdcf8fbb41b4b16b9a0f24e6db42: Deleting log segment in path: /tmp/dist-test-taskkQAF1q/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515530630243-20910-0/minicluster-data/ts-0-root/wals/d85e95ddae73456f9799bef2f80cc4f6/wal-000000033 (ops 160-164)
I20260812 06:18:55.669605 21085 log.cc:1079] T d85e95ddae73456f9799bef2f80cc4f6 P ed46bdcf8fbb41b4b16b9a0f24e6db42: Deleting log segment in path: /tmp/dist-test-taskkQAF1q/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515530630243-20910-0/minicluster-data/ts-0-root/wals/d85e95ddae73456f9799bef2f80cc4f6/wal-000000034 (ops 165-169)
I20260812 06:18:55.669646 21085 log.cc:1079] T d85e95ddae73456f9799bef2f80cc4f6 P ed46bdcf8fbb41b4b16b9a0f24e6db42: Deleting log segment in path: /tmp/dist-test-taskkQAF1q/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515530630243-20910-0/minicluster-data/ts-0-root/wals/d85e95ddae73456f9799bef2f80cc4f6/wal-000000035 (ops 170-174)
I20260812 06:18:55.669685 21085 log.cc:1079] T d85e95ddae73456f9799bef2f80cc4f6 P ed46bdcf8fbb41b4b16b9a0f24e6db42: Deleting log segment in path: /tmp/dist-test-taskkQAF1q/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515530630243-20910-0/minicluster-data/ts-0-root/wals/d85e95ddae73456f9799bef2f80cc4f6/wal-000000036 (ops 175-179)
I20260812 06:18:55.669725 21085 log.cc:1079] T d85e95ddae73456f9799bef2f80cc4f6 P ed46bdcf8fbb41b4b16b9a0f24e6db42: Deleting log segment in path: /tmp/dist-test-taskkQAF1q/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515530630243-20910-0/minicluster-data/ts-0-root/wals/d85e95ddae73456f9799bef2f80cc4f6/wal-000000037 (ops 180-184)
I20260812 06:18:55.669765 21085 log.cc:1079] T d85e95ddae73456f9799bef2f80cc4f6 P ed46bdcf8fbb41b4b16b9a0f24e6db42: Deleting log segment in path: /tmp/dist-test-taskkQAF1q/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515530630243-20910-0/minicluster-data/ts-0-root/wals/d85e95ddae73456f9799bef2f80cc4f6/wal-000000038 (ops 185-189)
I20260812 06:18:55.696795 21085 maintenance_manager.cc:643] P ed46bdcf8fbb41b4b16b9a0f24e6db42: LogGCOp(d85e95ddae73456f9799bef2f80cc4f6) complete. Timing: real 0.028s	user 0.000s	sys 0.026s Metrics: {}
I20260812 06:18:55.697274 21179 maintenance_manager.cc:419] P ed46bdcf8fbb41b4b16b9a0f24e6db42: Scheduling UndoDeltaBlockGCOp(d85e95ddae73456f9799bef2f80cc4f6): 493 bytes on disk
I20260812 06:18:55.697677 21085 maintenance_manager.cc:643] P ed46bdcf8fbb41b4b16b9a0f24e6db42: UndoDeltaBlockGCOp(d85e95ddae73456f9799bef2f80cc4f6) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":50,"lbm_reads_lt_1ms":4}
I20260812 06:18:55.698299 21179 maintenance_manager.cc:419] P ed46bdcf8fbb41b4b16b9a0f24e6db42: Scheduling FlushDeltaMemStoresOp(d85e95ddae73456f9799bef2f80cc4f6): perf score=5.165500
I20260812 06:18:55.715377 21085 maintenance_manager.cc:643] P ed46bdcf8fbb41b4b16b9a0f24e6db42: FlushDeltaMemStoresOp(d85e95ddae73456f9799bef2f80cc4f6) complete. Timing: real 0.017s	user 0.009s	sys 0.008s Metrics: {"bytes_written":6769231,"delete_count":0,"lbm_write_time_us":7362,"lbm_writes_lt_1ms":168,"reinsert_count":0,"update_count":825}
I20260812 06:18:55.715829 21179 maintenance_manager.cc:419] P ed46bdcf8fbb41b4b16b9a0f24e6db42: Scheduling FlushDeltaMemStoresOp(d85e95ddae73456f9799bef2f80cc4f6): perf score=1.000000
I20260812 06:18:55.725991 21085 maintenance_manager.cc:643] P ed46bdcf8fbb41b4b16b9a0f24e6db42: FlushDeltaMemStoresOp(d85e95ddae73456f9799bef2f80cc4f6) complete. Timing: real 0.010s	user 0.006s	sys 0.000s Metrics: {"bytes_written":1436027,"delete_count":0,"lbm_write_time_us":2700,"lbm_writes_lt_1ms":38,"reinsert_count":0,"update_count":175}
I20260812 06:18:55.726455 21179 maintenance_manager.cc:419] P ed46bdcf8fbb41b4b16b9a0f24e6db42: Scheduling MajorDeltaCompactionOp(d85e95ddae73456f9799bef2f80cc4f6): perf score=1.000000
I20260812 06:18:55.889879 20910 heavy-update-compaction-itest.cc:229] Time spent updating: real 4.960s	user 1.815s	sys 0.153s
I20260812 06:18:55.918581 21085 maintenance_manager.cc:643] P ed46bdcf8fbb41b4b16b9a0f24e6db42: MajorDeltaCompactionOp(d85e95ddae73456f9799bef2f80cc4f6) complete. Timing: real 0.192s	user 0.146s	sys 0.043s Metrics: {"cfile_cache_miss":735,"cfile_cache_miss_bytes":32979797,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":5,"delta_iterators_relevant":5,"lbm_read_time_us":13760,"lbm_reads_lt_1ms":767,"lbm_write_time_us":39315,"lbm_writes_lt_1ms":743,"peak_mem_usage":87969044,"reinsert_count":0,"spinlock_wait_cycles":1792,"update_count":3500}
I20260812 06:18:55.919122 21179 maintenance_manager.cc:419] P ed46bdcf8fbb41b4b16b9a0f24e6db42: Scheduling FlushDeltaMemStoresOp(d85e95ddae73456f9799bef2f80cc4f6): perf score=14.095187
I20260812 06:18:55.956595 21085 maintenance_manager.cc:643] P ed46bdcf8fbb41b4b16b9a0f24e6db42: FlushDeltaMemStoresOp(d85e95ddae73456f9799bef2f80cc4f6) complete. Timing: real 0.037s	user 0.028s	sys 0.008s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":17917,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:18:55.957100 21179 maintenance_manager.cc:419] P ed46bdcf8fbb41b4b16b9a0f24e6db42: Scheduling MajorDeltaCompactionOp(d85e95ddae73456f9799bef2f80cc4f6): perf score=1.000000
I20260812 06:18:55.982277 20910 heavy-update-compaction-itest.cc:265] Time spent scanning: real 0.092s	user 0.002s	sys 0.000s
I20260812 06:18:55.983170 20910 tablet_server.cc:179] TabletServer@127.20.107.129:0 shutting down...
I20260812 06:18:56.069977 21085 maintenance_manager.cc:643] P ed46bdcf8fbb41b4b16b9a0f24e6db42: MajorDeltaCompactionOp(d85e95ddae73456f9799bef2f80cc4f6) complete. Timing: real 0.113s	user 0.088s	sys 0.024s Metrics: {"cfile_cache_miss":431,"cfile_cache_miss_bytes":20672157,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":1,"delta_iterators_relevant":1,"dirs.queue_time_us":1153,"lbm_read_time_us":8713,"lbm_reads_lt_1ms":467,"lbm_write_time_us":23561,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":442,"mutex_wait_us":282,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":3072,"update_count":2000}
I20260812 06:18:56.070819 20910 ts_tablet_manager.cc:1507] Shutting down tablet manager...
I20260812 06:18:56.071295 20910 tablet_replica.cc:333] T d85e95ddae73456f9799bef2f80cc4f6 P ed46bdcf8fbb41b4b16b9a0f24e6db42: stopping tablet replica
I20260812 06:18:56.071539 20910 raft_consensus.cc:2243] T d85e95ddae73456f9799bef2f80cc4f6 P ed46bdcf8fbb41b4b16b9a0f24e6db42 [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:18:56.071781 20910 raft_consensus.cc:2272] T d85e95ddae73456f9799bef2f80cc4f6 P ed46bdcf8fbb41b4b16b9a0f24e6db42 [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:18:56.088127 20910 tablet_server.cc:196] TabletServer@127.20.107.129:0 shutdown complete.
I20260812 06:18:56.113318 20910 master.cc:562] Master@127.20.107.190:44361 shutting down...
I20260812 06:18:56.117013 20910 raft_consensus.cc:2243] T 00000000000000000000000000000000 P 383e399c502046d1a8573279edc6101e [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:18:56.117205 20910 raft_consensus.cc:2272] T 00000000000000000000000000000000 P 383e399c502046d1a8573279edc6101e [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:18:56.117302 20910 tablet_replica.cc:333] T 00000000000000000000000000000000 P 383e399c502046d1a8573279edc6101e: stopping tablet replica
I20260812 06:18:56.129647 20910 master.cc:584] Master@127.20.107.190:44361 shutdown complete.
[       OK ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/0 (5574 ms)
[ RUN      ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/1
I20260812 06:18:56.227818 20910 internal_mini_cluster.cc:156] Creating distributed mini masters. Addrs: 127.20.107.190:40103
I20260812 06:18:56.228258 20910 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:18:56.230371 21241 instance_detector.cc:116] could not retrieve Azure instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:18:56.230357 21243 instance_detector.cc:116] could not retrieve OpenStack instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:18:56.230511 20910 server_base.cc:1061] running on GCE node
W20260812 06:18:56.230346 21240 instance_detector.cc:116] could not retrieve AWS instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:18:56.230756 20910 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:18:56.230798 20910 system_unsync_time.cc:38] NTP support is disabled. Clock error bounds will not be accurate. This configuration is not suitable for distributed clusters.
I20260812 06:18:56.230814 20910 hybrid_clock.cc:648] HybridClock initialized: now 1786515536230814 us; error 0 us; skew 500 ppm
I20260812 06:18:56.231735 20910 webserver.cc:533] Webserver started at http://127.20.107.190:38479/ using document root <none> and password file <none>
I20260812 06:18:56.231910 20910 fs_manager.cc:362] Metadata directory not provided
I20260812 06:18:56.231966 20910 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:18:56.232067 20910 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:18:56.232491 20910 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskkQAF1q/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515530630243-20910-0/minicluster-data/master-0-root/instance:
uuid: "6cfaf933698b4a43a6c858e38fdd7a41"
format_stamp: "Formatted at 2026-08-12 06:18:56 on dist-test-slave-92m1"
I20260812 06:18:56.234090 20910 fs_manager.cc:696] Time spent creating directory manager: real 0.001s	user 0.002s	sys 0.000s
I20260812 06:18:56.234995 21253 log_block_manager.cc:4127] Time spent loading block containers with low live blocks: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:18:56.235273 20910 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.001s	sys 0.000s
I20260812 06:18:56.235370 20910 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskkQAF1q/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515530630243-20910-0/minicluster-data/master-0-root
uuid: "6cfaf933698b4a43a6c858e38fdd7a41"
format_stamp: "Formatted at 2026-08-12 06:18:56 on dist-test-slave-92m1"
I20260812 06:18:56.235461 20910 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskkQAF1q/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515530630243-20910-0/minicluster-data/master-0-root
metadata directory: /tmp/dist-test-taskkQAF1q/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515530630243-20910-0/minicluster-data/master-0-root
1 data directories: /tmp/dist-test-taskkQAF1q/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515530630243-20910-0/minicluster-data/master-0-root/data
Total live blocks: 0
Total live bytes: 0
Total live bytes (after alignment): 0
Total number of LBM containers: 0 (0 full)
Did not check for missing blocks
Did not check for orphaned blocks
Total full LBM containers with extra space: 0 (0 repaired)
Total full LBM container extra space in bytes: 0 (0 repaired)
Total incomplete LBM containers: 0 (0 repaired)
Total LBM partial records: 0 (0 repaired)
Total corrupted LBM metadata records in RocksDB: 0 (0 repaired)
I20260812 06:18:56.246768 20910 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:18:56.247134 20910 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:18:56.251080 20910 rpc_server.cc:307] RPC server started. Bound to: 127.20.107.190:40103
I20260812 06:18:56.257308 21343 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.20.107.190:40103 every 8 connection(s)
I20260812 06:18:56.257826 21345 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet 00000000000000000000000000000000. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:18:56.259717 21345 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P 6cfaf933698b4a43a6c858e38fdd7a41: Bootstrap starting.
I20260812 06:18:56.260470 21345 tablet_bootstrap.cc:654] T 00000000000000000000000000000000 P 6cfaf933698b4a43a6c858e38fdd7a41: Neither blocks nor log segments found. Creating new log.
I20260812 06:18:56.261451 21345 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P 6cfaf933698b4a43a6c858e38fdd7a41: No bootstrap required, opened a new log
I20260812 06:18:56.261837 21345 raft_consensus.cc:359] T 00000000000000000000000000000000 P 6cfaf933698b4a43a6c858e38fdd7a41 [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "6cfaf933698b4a43a6c858e38fdd7a41" member_type: VOTER }
I20260812 06:18:56.261943 21345 raft_consensus.cc:385] T 00000000000000000000000000000000 P 6cfaf933698b4a43a6c858e38fdd7a41 [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:18:56.262007 21345 raft_consensus.cc:740] T 00000000000000000000000000000000 P 6cfaf933698b4a43a6c858e38fdd7a41 [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: 6cfaf933698b4a43a6c858e38fdd7a41, State: Initialized, Role: FOLLOWER
I20260812 06:18:56.262217 21345 consensus_queue.cc:260] T 00000000000000000000000000000000 P 6cfaf933698b4a43a6c858e38fdd7a41 [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: "6cfaf933698b4a43a6c858e38fdd7a41" member_type: VOTER }
I20260812 06:18:56.262326 21345 raft_consensus.cc:399] T 00000000000000000000000000000000 P 6cfaf933698b4a43a6c858e38fdd7a41 [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:18:56.262372 21345 raft_consensus.cc:493] T 00000000000000000000000000000000 P 6cfaf933698b4a43a6c858e38fdd7a41 [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:18:56.262431 21345 raft_consensus.cc:3060] T 00000000000000000000000000000000 P 6cfaf933698b4a43a6c858e38fdd7a41 [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:18:56.263085 21345 raft_consensus.cc:515] T 00000000000000000000000000000000 P 6cfaf933698b4a43a6c858e38fdd7a41 [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "6cfaf933698b4a43a6c858e38fdd7a41" member_type: VOTER }
I20260812 06:18:56.263257 21345 leader_election.cc:304] T 00000000000000000000000000000000 P 6cfaf933698b4a43a6c858e38fdd7a41 [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: 6cfaf933698b4a43a6c858e38fdd7a41; no voters: 
I20260812 06:18:56.263458 21345 leader_election.cc:290] T 00000000000000000000000000000000 P 6cfaf933698b4a43a6c858e38fdd7a41 [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:18:56.263562 21349 raft_consensus.cc:2804] T 00000000000000000000000000000000 P 6cfaf933698b4a43a6c858e38fdd7a41 [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:18:56.263820 21349 raft_consensus.cc:697] T 00000000000000000000000000000000 P 6cfaf933698b4a43a6c858e38fdd7a41 [term 1 LEADER]: Becoming Leader. State: Replica: 6cfaf933698b4a43a6c858e38fdd7a41, State: Running, Role: LEADER
I20260812 06:18:56.263882 21345 sys_catalog.cc:565] T 00000000000000000000000000000000 P 6cfaf933698b4a43a6c858e38fdd7a41 [sys.catalog]: configured and running, proceeding with master startup.
I20260812 06:18:56.263970 21349 consensus_queue.cc:237] T 00000000000000000000000000000000 P 6cfaf933698b4a43a6c858e38fdd7a41 [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: "6cfaf933698b4a43a6c858e38fdd7a41" member_type: VOTER }
I20260812 06:18:56.264367 21350 sys_catalog.cc:455] T 00000000000000000000000000000000 P 6cfaf933698b4a43a6c858e38fdd7a41 [sys.catalog]: SysCatalogTable state changed. Reason: RaftConsensus started. Latest consensus state: current_term: 1 leader_uuid: "6cfaf933698b4a43a6c858e38fdd7a41" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "6cfaf933698b4a43a6c858e38fdd7a41" member_type: VOTER } }
I20260812 06:18:56.264387 21351 sys_catalog.cc:455] T 00000000000000000000000000000000 P 6cfaf933698b4a43a6c858e38fdd7a41 [sys.catalog]: SysCatalogTable state changed. Reason: New leader 6cfaf933698b4a43a6c858e38fdd7a41. Latest consensus state: current_term: 1 leader_uuid: "6cfaf933698b4a43a6c858e38fdd7a41" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "6cfaf933698b4a43a6c858e38fdd7a41" member_type: VOTER } }
I20260812 06:18:56.264509 21350 sys_catalog.cc:458] T 00000000000000000000000000000000 P 6cfaf933698b4a43a6c858e38fdd7a41 [sys.catalog]: This master's current role is: LEADER
I20260812 06:18:56.264536 21351 sys_catalog.cc:458] T 00000000000000000000000000000000 P 6cfaf933698b4a43a6c858e38fdd7a41 [sys.catalog]: This master's current role is: LEADER
I20260812 06:18:56.265096 21361 catalog_manager.cc:1511] Loading table and tablet metadata into memory...
I20260812 06:18:56.265936 21361 catalog_manager.cc:1520] Initializing Kudu cluster ID...
I20260812 06:18:56.266156 20910 internal_mini_cluster.cc:184] Waiting to initialize catalog manager on master 0
I20260812 06:18:56.267658 21361 catalog_manager.cc:1383] Generated new cluster ID: 8ea6b91066ec47ccbab69cbb5b873fba
I20260812 06:18:56.267724 21361 catalog_manager.cc:1531] Initializing Kudu internal certificate authority...
I20260812 06:18:56.277597 21361 catalog_manager.cc:1406] Generated new certificate authority record
I20260812 06:18:56.278123 21361 catalog_manager.cc:1540] Loading token signing keys...
I20260812 06:18:56.284211 21361 catalog_manager.cc:6092] T 00000000000000000000000000000000 P 6cfaf933698b4a43a6c858e38fdd7a41: Generated new TSK 0
I20260812 06:18:56.284369 21361 catalog_manager.cc:1550] Initializing in-progress tserver states...
I20260812 06:18:56.298341 20910 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:18:56.300383 21377 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:18:56.300467 20910 server_base.cc:1061] running on GCE node
W20260812 06:18:56.300472 21376 instance_detector.cc:116] could not retrieve AWS instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:18:56.300673 21380 instance_detector.cc:116] could not retrieve OpenStack instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:18:56.300997 20910 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:18:56.301043 20910 system_unsync_time.cc:38] NTP support is disabled. Clock error bounds will not be accurate. This configuration is not suitable for distributed clusters.
I20260812 06:18:56.301060 20910 hybrid_clock.cc:648] HybridClock initialized: now 1786515536301060 us; error 0 us; skew 500 ppm
I20260812 06:18:56.301923 20910 webserver.cc:533] Webserver started at http://127.20.107.129:33015/ using document root <none> and password file <none>
I20260812 06:18:56.302055 20910 fs_manager.cc:362] Metadata directory not provided
I20260812 06:18:56.302100 20910 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:18:56.302151 20910 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:18:56.302477 20910 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskkQAF1q/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515530630243-20910-0/minicluster-data/ts-0-root/instance:
uuid: "9cdce43c70c24b37aff4531a818a59bc"
format_stamp: "Formatted at 2026-08-12 06:18:56 on dist-test-slave-92m1"
I20260812 06:18:56.304020 20910 fs_manager.cc:696] Time spent creating directory manager: real 0.001s	user 0.002s	sys 0.000s
I20260812 06:18:56.304859 21392 log_block_manager.cc:4127] Time spent loading block containers with low live blocks: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:18:56.305161 20910 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.001s	sys 0.000s
I20260812 06:18:56.305223 20910 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskkQAF1q/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515530630243-20910-0/minicluster-data/ts-0-root
uuid: "9cdce43c70c24b37aff4531a818a59bc"
format_stamp: "Formatted at 2026-08-12 06:18:56 on dist-test-slave-92m1"
I20260812 06:18:56.305274 20910 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskkQAF1q/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515530630243-20910-0/minicluster-data/ts-0-root
metadata directory: /tmp/dist-test-taskkQAF1q/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515530630243-20910-0/minicluster-data/ts-0-root
1 data directories: /tmp/dist-test-taskkQAF1q/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515530630243-20910-0/minicluster-data/ts-0-root/data
Total live blocks: 0
Total live bytes: 0
Total live bytes (after alignment): 0
Total number of LBM containers: 0 (0 full)
Did not check for missing blocks
Did not check for orphaned blocks
Total full LBM containers with extra space: 0 (0 repaired)
Total full LBM container extra space in bytes: 0 (0 repaired)
Total incomplete LBM containers: 0 (0 repaired)
Total LBM partial records: 0 (0 repaired)
Total corrupted LBM metadata records in RocksDB: 0 (0 repaired)
I20260812 06:18:56.315663 20910 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:18:56.315943 20910 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:18:56.316161 20910 txn_system_client.cc:432] TxnSystemClient initialization is disabled...
I20260812 06:18:56.316605 20910 ts_tablet_manager.cc:585] Loaded tablet metadata (0 total tablets, 0 live tablets)
I20260812 06:18:56.316642 20910 ts_tablet_manager.cc:531] Time spent load tablet metadata: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:18:56.316702 20910 ts_tablet_manager.cc:616] Registered 0 tablets
I20260812 06:18:56.316741 20910 ts_tablet_manager.cc:595] Time spent register tablets: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:18:56.320785 20910 rpc_server.cc:307] RPC server started. Bound to: 127.20.107.129:46411
I20260812 06:18:56.320856 21505 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.20.107.129:46411 every 8 connection(s)
I20260812 06:18:56.328727 21507 heartbeater.cc:344] Connected to a master server at 127.20.107.190:40103
I20260812 06:18:56.328842 21507 heartbeater.cc:461] Registering TS with master...
I20260812 06:18:56.329062 21507 heartbeater.cc:507] Master 127.20.107.190:40103 requested a full tablet report, sending...
I20260812 06:18:56.329708 21284 ts_manager.cc:194] Registered new tserver with Master: 9cdce43c70c24b37aff4531a818a59bc (127.20.107.129:46411)
I20260812 06:18:56.330039 20910 internal_mini_cluster.cc:371] 1 TS(s) registered with all masters after 0.008802701s
I20260812 06:18:56.330466 21284 master_service.cc:502] Signed X509 certificate for tserver {username='slave'} at 127.0.0.1:44090
I20260812 06:18:56.336925 21284 catalog_manager.cc:2283] Servicing CreateTable request from {username='slave'} at 127.0.0.1:44106:
name: "heavy-update-compaction-test"
schema {
  columns {
    name: "key"
    type: INT64
    is_key: true
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_a"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_b"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_c"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_d"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_e"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
}
num_replicas: 1
split_rows_range_bounds {
}
partition_schema {
  range_schema {
  }
}
I20260812 06:18:56.345323 21440 tablet_service.cc:1511] Processing CreateTablet for tablet 7c2f1d14334f4a13964d4d81da76d694 (DEFAULT_TABLE table=heavy-update-compaction-test [id=eb5abed509d6497d9d5708db47d865eb]), partition=
I20260812 06:18:56.345598 21440 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet 7c2f1d14334f4a13964d4d81da76d694. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:18:56.347505 21530 tablet_bootstrap.cc:492] T 7c2f1d14334f4a13964d4d81da76d694 P 9cdce43c70c24b37aff4531a818a59bc: Bootstrap starting.
I20260812 06:18:56.348405 21530 tablet_bootstrap.cc:654] T 7c2f1d14334f4a13964d4d81da76d694 P 9cdce43c70c24b37aff4531a818a59bc: Neither blocks nor log segments found. Creating new log.
I20260812 06:18:56.349319 21530 tablet_bootstrap.cc:492] T 7c2f1d14334f4a13964d4d81da76d694 P 9cdce43c70c24b37aff4531a818a59bc: No bootstrap required, opened a new log
I20260812 06:18:56.349412 21530 ts_tablet_manager.cc:1403] T 7c2f1d14334f4a13964d4d81da76d694 P 9cdce43c70c24b37aff4531a818a59bc: Time spent bootstrapping tablet: real 0.002s	user 0.001s	sys 0.000s
I20260812 06:18:56.349797 21530 raft_consensus.cc:359] T 7c2f1d14334f4a13964d4d81da76d694 P 9cdce43c70c24b37aff4531a818a59bc [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "9cdce43c70c24b37aff4531a818a59bc" member_type: VOTER last_known_addr { host: "127.20.107.129" port: 46411 } }
I20260812 06:18:56.349877 21530 raft_consensus.cc:385] T 7c2f1d14334f4a13964d4d81da76d694 P 9cdce43c70c24b37aff4531a818a59bc [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:18:56.349944 21530 raft_consensus.cc:740] T 7c2f1d14334f4a13964d4d81da76d694 P 9cdce43c70c24b37aff4531a818a59bc [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: 9cdce43c70c24b37aff4531a818a59bc, State: Initialized, Role: FOLLOWER
I20260812 06:18:56.350132 21530 consensus_queue.cc:260] T 7c2f1d14334f4a13964d4d81da76d694 P 9cdce43c70c24b37aff4531a818a59bc [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: "9cdce43c70c24b37aff4531a818a59bc" member_type: VOTER last_known_addr { host: "127.20.107.129" port: 46411 } }
I20260812 06:18:56.350219 21530 raft_consensus.cc:399] T 7c2f1d14334f4a13964d4d81da76d694 P 9cdce43c70c24b37aff4531a818a59bc [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:18:56.350284 21530 raft_consensus.cc:493] T 7c2f1d14334f4a13964d4d81da76d694 P 9cdce43c70c24b37aff4531a818a59bc [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:18:56.350343 21530 raft_consensus.cc:3060] T 7c2f1d14334f4a13964d4d81da76d694 P 9cdce43c70c24b37aff4531a818a59bc [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:18:56.351135 21530 raft_consensus.cc:515] T 7c2f1d14334f4a13964d4d81da76d694 P 9cdce43c70c24b37aff4531a818a59bc [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "9cdce43c70c24b37aff4531a818a59bc" member_type: VOTER last_known_addr { host: "127.20.107.129" port: 46411 } }
I20260812 06:18:56.351307 21530 leader_election.cc:304] T 7c2f1d14334f4a13964d4d81da76d694 P 9cdce43c70c24b37aff4531a818a59bc [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: 9cdce43c70c24b37aff4531a818a59bc; no voters: 
I20260812 06:18:56.351532 21530 leader_election.cc:290] T 7c2f1d14334f4a13964d4d81da76d694 P 9cdce43c70c24b37aff4531a818a59bc [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:18:56.351639 21532 raft_consensus.cc:2804] T 7c2f1d14334f4a13964d4d81da76d694 P 9cdce43c70c24b37aff4531a818a59bc [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:18:56.351893 21532 raft_consensus.cc:697] T 7c2f1d14334f4a13964d4d81da76d694 P 9cdce43c70c24b37aff4531a818a59bc [term 1 LEADER]: Becoming Leader. State: Replica: 9cdce43c70c24b37aff4531a818a59bc, State: Running, Role: LEADER
I20260812 06:18:56.351903 21507 heartbeater.cc:499] Master 127.20.107.190:40103 was elected leader, sending a full tablet report...
I20260812 06:18:56.351998 21530 ts_tablet_manager.cc:1434] T 7c2f1d14334f4a13964d4d81da76d694 P 9cdce43c70c24b37aff4531a818a59bc: Time spent starting tablet: real 0.003s	user 0.000s	sys 0.003s
I20260812 06:18:56.352058 21532 consensus_queue.cc:237] T 7c2f1d14334f4a13964d4d81da76d694 P 9cdce43c70c24b37aff4531a818a59bc [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: "9cdce43c70c24b37aff4531a818a59bc" member_type: VOTER last_known_addr { host: "127.20.107.129" port: 46411 } }
I20260812 06:18:56.353292 21284 catalog_manager.cc:5719] T 7c2f1d14334f4a13964d4d81da76d694 P 9cdce43c70c24b37aff4531a818a59bc reported cstate change: term changed from 0 to 1, leader changed from <none> to 9cdce43c70c24b37aff4531a818a59bc (127.20.107.129). New cstate: current_term: 1 leader_uuid: "9cdce43c70c24b37aff4531a818a59bc" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "9cdce43c70c24b37aff4531a818a59bc" member_type: VOTER last_known_addr { host: "127.20.107.129" port: 46411 } health_report { overall_health: HEALTHY } } }
I20260812 06:18:56.409134 20910 heavy-update-compaction-itest.cc:215] Time spent inserting: real 0.052s	user 0.014s	sys 0.008s
I20260812 06:18:56.571645 21508 maintenance_manager.cc:419] P 9cdce43c70c24b37aff4531a818a59bc: Scheduling FlushMRSOp(7c2f1d14334f4a13964d4d81da76d694): perf score=19.054940
I20260812 06:18:56.751667 21401 maintenance_manager.cc:643] P 9cdce43c70c24b37aff4531a818a59bc: FlushMRSOp(7c2f1d14334f4a13964d4d81da76d694) complete. Timing: real 0.180s	user 0.114s	sys 0.063s Metrics: {"bytes_written":12307490,"cfile_init":1,"delete_count":0,"dirs.queue_time_us":128,"dirs.run_cpu_time_us":176,"dirs.run_wall_time_us":700,"drs_written":1,"lbm_read_time_us":91,"lbm_reads_lt_1ms":4,"lbm_write_time_us":47380,"lbm_writes_lt_1ms":857,"peak_mem_usage":0,"reinsert_count":0,"rows_written":105,"spinlock_wait_cycles":1920,"update_count":1500}
I20260812 06:18:56.752305 21508 maintenance_manager.cc:419] P 9cdce43c70c24b37aff4531a818a59bc: Scheduling LogGCOp(7c2f1d14334f4a13964d4d81da76d694): free 20743880 bytes of WAL
I20260812 06:18:56.752544 21401 log_reader.cc:385] T 7c2f1d14334f4a13964d4d81da76d694: removed 2 log segments from log reader
I20260812 06:18:56.752604 21401 log.cc:1079] T 7c2f1d14334f4a13964d4d81da76d694 P 9cdce43c70c24b37aff4531a818a59bc: Deleting log segment in path: /tmp/dist-test-taskkQAF1q/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515530630243-20910-0/minicluster-data/ts-0-root/wals/7c2f1d14334f4a13964d4d81da76d694/wal-000000001 (ops 1-6)
I20260812 06:18:56.752668 21401 log.cc:1079] T 7c2f1d14334f4a13964d4d81da76d694 P 9cdce43c70c24b37aff4531a818a59bc: Deleting log segment in path: /tmp/dist-test-taskkQAF1q/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515530630243-20910-0/minicluster-data/ts-0-root/wals/7c2f1d14334f4a13964d4d81da76d694/wal-000000002 (ops 7-11)
I20260812 06:18:56.757232 21401 maintenance_manager.cc:643] P 9cdce43c70c24b37aff4531a818a59bc: LogGCOp(7c2f1d14334f4a13964d4d81da76d694) complete. Timing: real 0.005s	user 0.000s	sys 0.003s Metrics: {}
I20260812 06:18:56.757583 21508 maintenance_manager.cc:419] P 9cdce43c70c24b37aff4531a818a59bc: Scheduling FlushDeltaMemStoresOp(7c2f1d14334f4a13964d4d81da76d694): perf score=2.188937
I20260812 06:18:56.770254 21401 maintenance_manager.cc:643] P 9cdce43c70c24b37aff4531a818a59bc: FlushDeltaMemStoresOp(7c2f1d14334f4a13964d4d81da76d694) complete. Timing: real 0.012s	user 0.007s	sys 0.003s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4871,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:56.770721 21508 maintenance_manager.cc:419] P 9cdce43c70c24b37aff4531a818a59bc: Scheduling MajorDeltaCompactionOp(7c2f1d14334f4a13964d4d81da76d694): perf score=1.000000
I20260812 06:18:56.920823 21401 maintenance_manager.cc:643] P 9cdce43c70c24b37aff4531a818a59bc: MajorDeltaCompactionOp(7c2f1d14334f4a13964d4d81da76d694) complete. Timing: real 0.150s	user 0.122s	sys 0.024s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20713272,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":435,"lbm_read_time_us":10745,"lbm_reads_lt_1ms":468,"lbm_write_time_us":22950,"lbm_writes_lt_1ms":443,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":896,"thread_start_us":309,"threads_started":5,"update_count":2000}
I20260812 06:18:56.921355 21508 maintenance_manager.cc:419] P 9cdce43c70c24b37aff4531a818a59bc: Scheduling UndoDeltaBlockGCOp(7c2f1d14334f4a13964d4d81da76d694): 20513816 bytes on disk
I20260812 06:18:56.921793 21401 maintenance_manager.cc:643] P 9cdce43c70c24b37aff4531a818a59bc: UndoDeltaBlockGCOp(7c2f1d14334f4a13964d4d81da76d694) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":104,"lbm_reads_lt_1ms":4}
I20260812 06:18:56.922297 21508 maintenance_manager.cc:419] P 9cdce43c70c24b37aff4531a818a59bc: Scheduling FlushDeltaMemStoresOp(7c2f1d14334f4a13964d4d81da76d694): perf score=11.118625
I20260812 06:18:56.958609 21401 maintenance_manager.cc:643] P 9cdce43c70c24b37aff4531a818a59bc: FlushDeltaMemStoresOp(7c2f1d14334f4a13964d4d81da76d694) complete. Timing: real 0.036s	user 0.025s	sys 0.008s Metrics: {"bytes_written":12717737,"delete_count":0,"lbm_write_time_us":15827,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:18:56.959357 21508 maintenance_manager.cc:419] P 9cdce43c70c24b37aff4531a818a59bc: Scheduling FlushDeltaMemStoresOp(7c2f1d14334f4a13964d4d81da76d694): perf score=2.188937
I20260812 06:18:56.981346 21401 maintenance_manager.cc:643] P 9cdce43c70c24b37aff4531a818a59bc: FlushDeltaMemStoresOp(7c2f1d14334f4a13964d4d81da76d694) complete. Timing: real 0.022s	user 0.011s	sys 0.005s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":4674,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:18:56.981827 21508 maintenance_manager.cc:419] P 9cdce43c70c24b37aff4531a818a59bc: Scheduling MajorDeltaCompactionOp(7c2f1d14334f4a13964d4d81da76d694): perf score=1.000000
I20260812 06:18:57.138345 21401 maintenance_manager.cc:643] P 9cdce43c70c24b37aff4531a818a59bc: MajorDeltaCompactionOp(7c2f1d14334f4a13964d4d81da76d694) complete. Timing: real 0.156s	user 0.088s	sys 0.068s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20713265,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":195,"lbm_read_time_us":10760,"lbm_reads_lt_1ms":464,"lbm_write_time_us":24357,"lbm_writes_lt_1ms":443,"mutex_wait_us":38,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":5376,"update_count":2000}
I20260812 06:18:57.138891 21508 maintenance_manager.cc:419] P 9cdce43c70c24b37aff4531a818a59bc: Scheduling FlushDeltaMemStoresOp(7c2f1d14334f4a13964d4d81da76d694): perf score=14.095187
I20260812 06:18:57.195125 21401 maintenance_manager.cc:643] P 9cdce43c70c24b37aff4531a818a59bc: FlushDeltaMemStoresOp(7c2f1d14334f4a13964d4d81da76d694) complete. Timing: real 0.056s	user 0.035s	sys 0.015s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":24175,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:18:57.195679 21508 maintenance_manager.cc:419] P 9cdce43c70c24b37aff4531a818a59bc: Scheduling FlushDeltaMemStoresOp(7c2f1d14334f4a13964d4d81da76d694): perf score=2.188937
I20260812 06:18:57.205924 21401 maintenance_manager.cc:643] P 9cdce43c70c24b37aff4531a818a59bc: FlushDeltaMemStoresOp(7c2f1d14334f4a13964d4d81da76d694) complete. Timing: real 0.010s	user 0.004s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3921,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:57.206537 21508 maintenance_manager.cc:419] P 9cdce43c70c24b37aff4531a818a59bc: Scheduling MajorDeltaCompactionOp(7c2f1d14334f4a13964d4d81da76d694): perf score=1.000000
I20260812 06:18:57.355623 21401 maintenance_manager.cc:643] P 9cdce43c70c24b37aff4531a818a59bc: MajorDeltaCompactionOp(7c2f1d14334f4a13964d4d81da76d694) complete. Timing: real 0.149s	user 0.121s	sys 0.019s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24815684,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":162,"lbm_read_time_us":8860,"lbm_reads_lt_1ms":572,"lbm_write_time_us":28337,"lbm_writes_lt_1ms":543,"mutex_wait_us":18,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":22272,"update_count":2500}
I20260812 06:18:57.356259 21508 maintenance_manager.cc:419] P 9cdce43c70c24b37aff4531a818a59bc: Scheduling FlushDeltaMemStoresOp(7c2f1d14334f4a13964d4d81da76d694): perf score=14.095187
I20260812 06:18:57.409478 21401 maintenance_manager.cc:643] P 9cdce43c70c24b37aff4531a818a59bc: FlushDeltaMemStoresOp(7c2f1d14334f4a13964d4d81da76d694) complete. Timing: real 0.053s	user 0.039s	sys 0.012s Metrics: {"bytes_written":16409900,"delete_count":0,"lbm_write_time_us":24804,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":402,"reinsert_count":0,"update_count":2000}
I20260812 06:18:57.410017 21508 maintenance_manager.cc:419] P 9cdce43c70c24b37aff4531a818a59bc: Scheduling FlushDeltaMemStoresOp(7c2f1d14334f4a13964d4d81da76d694): perf score=2.188937
I20260812 06:18:57.422477 21401 maintenance_manager.cc:643] P 9cdce43c70c24b37aff4531a818a59bc: FlushDeltaMemStoresOp(7c2f1d14334f4a13964d4d81da76d694) complete. Timing: real 0.012s	user 0.003s	sys 0.007s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4829,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:57.422971 21508 maintenance_manager.cc:419] P 9cdce43c70c24b37aff4531a818a59bc: Scheduling MajorDeltaCompactionOp(7c2f1d14334f4a13964d4d81da76d694): perf score=1.000000
I20260812 06:18:57.577119 21401 maintenance_manager.cc:643] P 9cdce43c70c24b37aff4531a818a59bc: MajorDeltaCompactionOp(7c2f1d14334f4a13964d4d81da76d694) complete. Timing: real 0.154s	user 0.130s	sys 0.024s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24815682,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":207,"lbm_read_time_us":10753,"lbm_reads_lt_1ms":572,"lbm_write_time_us":31278,"lbm_writes_lt_1ms":543,"mutex_wait_us":43,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":14208,"update_count":2500}
I20260812 06:18:57.577690 21508 maintenance_manager.cc:419] P 9cdce43c70c24b37aff4531a818a59bc: Scheduling FlushDeltaMemStoresOp(7c2f1d14334f4a13964d4d81da76d694): perf score=14.095187
I20260812 06:18:57.622079 21401 maintenance_manager.cc:643] P 9cdce43c70c24b37aff4531a818a59bc: FlushDeltaMemStoresOp(7c2f1d14334f4a13964d4d81da76d694) complete. Timing: real 0.044s	user 0.017s	sys 0.024s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":19850,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:18:57.622575 21508 maintenance_manager.cc:419] P 9cdce43c70c24b37aff4531a818a59bc: Scheduling FlushDeltaMemStoresOp(7c2f1d14334f4a13964d4d81da76d694): perf score=2.188937
I20260812 06:18:57.636986 21401 maintenance_manager.cc:643] P 9cdce43c70c24b37aff4531a818a59bc: FlushDeltaMemStoresOp(7c2f1d14334f4a13964d4d81da76d694) complete. Timing: real 0.014s	user 0.010s	sys 0.004s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":5644,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:57.637492 21508 maintenance_manager.cc:419] P 9cdce43c70c24b37aff4531a818a59bc: Scheduling MajorDeltaCompactionOp(7c2f1d14334f4a13964d4d81da76d694): perf score=1.000000
I20260812 06:18:57.795560 21401 maintenance_manager.cc:643] P 9cdce43c70c24b37aff4531a818a59bc: MajorDeltaCompactionOp(7c2f1d14334f4a13964d4d81da76d694) complete. Timing: real 0.158s	user 0.117s	sys 0.040s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24815682,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":629,"lbm_read_time_us":9572,"lbm_reads_lt_1ms":572,"lbm_write_time_us":31943,"lbm_writes_lt_1ms":543,"mutex_wait_us":346,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":1664,"update_count":2500}
I20260812 06:18:57.796293 21508 maintenance_manager.cc:419] P 9cdce43c70c24b37aff4531a818a59bc: Scheduling FlushDeltaMemStoresOp(7c2f1d14334f4a13964d4d81da76d694): perf score=10.126437
I20260812 06:18:57.837198 21401 maintenance_manager.cc:643] P 9cdce43c70c24b37aff4531a818a59bc: FlushDeltaMemStoresOp(7c2f1d14334f4a13964d4d81da76d694) complete. Timing: real 0.041s	user 0.018s	sys 0.016s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":15996,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:18:57.837881 21508 maintenance_manager.cc:419] P 9cdce43c70c24b37aff4531a818a59bc: Scheduling FlushDeltaMemStoresOp(7c2f1d14334f4a13964d4d81da76d694): perf score=2.188937
I20260812 06:18:57.849676 21401 maintenance_manager.cc:643] P 9cdce43c70c24b37aff4531a818a59bc: FlushDeltaMemStoresOp(7c2f1d14334f4a13964d4d81da76d694) complete. Timing: real 0.012s	user 0.006s	sys 0.003s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4380,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:57.850435 21508 maintenance_manager.cc:419] P 9cdce43c70c24b37aff4531a818a59bc: Scheduling MajorDeltaCompactionOp(7c2f1d14334f4a13964d4d81da76d694): perf score=1.000000
I20260812 06:18:57.979251 21401 maintenance_manager.cc:643] P 9cdce43c70c24b37aff4531a818a59bc: MajorDeltaCompactionOp(7c2f1d14334f4a13964d4d81da76d694) complete. Timing: real 0.129s	user 0.105s	sys 0.023s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20713272,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":494,"lbm_read_time_us":9107,"lbm_reads_lt_1ms":472,"lbm_write_time_us":24706,"lbm_writes_lt_1ms":443,"mutex_wait_us":2,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":1408,"update_count":2000}
I20260812 06:18:57.979987 21508 maintenance_manager.cc:419] P 9cdce43c70c24b37aff4531a818a59bc: Scheduling FlushDeltaMemStoresOp(7c2f1d14334f4a13964d4d81da76d694): perf score=10.126437
I20260812 06:18:58.032889 21401 maintenance_manager.cc:643] P 9cdce43c70c24b37aff4531a818a59bc: FlushDeltaMemStoresOp(7c2f1d14334f4a13964d4d81da76d694) complete. Timing: real 0.053s	user 0.020s	sys 0.027s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":16995,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:18:58.033393 21508 maintenance_manager.cc:419] P 9cdce43c70c24b37aff4531a818a59bc: Scheduling FlushDeltaMemStoresOp(7c2f1d14334f4a13964d4d81da76d694): perf score=2.188937
I20260812 06:18:58.044245 21401 maintenance_manager.cc:643] P 9cdce43c70c24b37aff4531a818a59bc: FlushDeltaMemStoresOp(7c2f1d14334f4a13964d4d81da76d694) complete. Timing: real 0.011s	user 0.005s	sys 0.004s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4336,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:58.044696 21508 maintenance_manager.cc:419] P 9cdce43c70c24b37aff4531a818a59bc: Scheduling FlushMRSOp(7c2f1d14334f4a13964d4d81da76d694): perf score=1.000000
I20260812 06:18:58.077922 21401 maintenance_manager.cc:643] P 9cdce43c70c24b37aff4531a818a59bc: FlushMRSOp(7c2f1d14334f4a13964d4d81da76d694) complete. Timing: real 0.033s	user 0.025s	sys 0.004s Metrics: {"bytes_written":1275444,"cfile_init":1,"dirs.queue_time_us":72,"dirs.run_cpu_time_us":297,"dirs.run_wall_time_us":1318,"drs_written":1,"lbm_read_time_us":37,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1488,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":31}
I20260812 06:18:58.078612 21508 maintenance_manager.cc:419] P 9cdce43c70c24b37aff4531a818a59bc: Scheduling MajorDeltaCompactionOp(7c2f1d14334f4a13964d4d81da76d694): perf score=1.000000
I20260812 06:18:58.238147 21401 maintenance_manager.cc:643] P 9cdce43c70c24b37aff4531a818a59bc: MajorDeltaCompactionOp(7c2f1d14334f4a13964d4d81da76d694) complete. Timing: real 0.159s	user 0.113s	sys 0.036s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20713271,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":436,"lbm_read_time_us":11062,"lbm_reads_lt_1ms":464,"lbm_write_time_us":24476,"lbm_writes_lt_1ms":443,"mutex_wait_us":73,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":15872,"update_count":2000}
I20260812 06:18:58.238920 21508 maintenance_manager.cc:419] P 9cdce43c70c24b37aff4531a818a59bc: Scheduling LogGCOp(7c2f1d14334f4a13964d4d81da76d694): free 132571304 bytes of WAL
I20260812 06:18:58.239169 21401 log_reader.cc:385] T 7c2f1d14334f4a13964d4d81da76d694: removed 13 log segments from log reader
I20260812 06:18:58.239248 21401 log.cc:1079] T 7c2f1d14334f4a13964d4d81da76d694 P 9cdce43c70c24b37aff4531a818a59bc: Deleting log segment in path: /tmp/dist-test-taskkQAF1q/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515530630243-20910-0/minicluster-data/ts-0-root/wals/7c2f1d14334f4a13964d4d81da76d694/wal-000000003 (ops 12-16)
I20260812 06:18:58.239343 21401 log.cc:1079] T 7c2f1d14334f4a13964d4d81da76d694 P 9cdce43c70c24b37aff4531a818a59bc: Deleting log segment in path: /tmp/dist-test-taskkQAF1q/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515530630243-20910-0/minicluster-data/ts-0-root/wals/7c2f1d14334f4a13964d4d81da76d694/wal-000000004 (ops 17-21)
I20260812 06:18:58.239382 21401 log.cc:1079] T 7c2f1d14334f4a13964d4d81da76d694 P 9cdce43c70c24b37aff4531a818a59bc: Deleting log segment in path: /tmp/dist-test-taskkQAF1q/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515530630243-20910-0/minicluster-data/ts-0-root/wals/7c2f1d14334f4a13964d4d81da76d694/wal-000000005 (ops 22-26)
I20260812 06:18:58.239441 21401 log.cc:1079] T 7c2f1d14334f4a13964d4d81da76d694 P 9cdce43c70c24b37aff4531a818a59bc: Deleting log segment in path: /tmp/dist-test-taskkQAF1q/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515530630243-20910-0/minicluster-data/ts-0-root/wals/7c2f1d14334f4a13964d4d81da76d694/wal-000000006 (ops 27-31)
I20260812 06:18:58.239481 21401 log.cc:1079] T 7c2f1d14334f4a13964d4d81da76d694 P 9cdce43c70c24b37aff4531a818a59bc: Deleting log segment in path: /tmp/dist-test-taskkQAF1q/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515530630243-20910-0/minicluster-data/ts-0-root/wals/7c2f1d14334f4a13964d4d81da76d694/wal-000000007 (ops 32-36)
I20260812 06:18:58.239537 21401 log.cc:1079] T 7c2f1d14334f4a13964d4d81da76d694 P 9cdce43c70c24b37aff4531a818a59bc: Deleting log segment in path: /tmp/dist-test-taskkQAF1q/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515530630243-20910-0/minicluster-data/ts-0-root/wals/7c2f1d14334f4a13964d4d81da76d694/wal-000000008 (ops 37-40)
I20260812 06:18:58.239573 21401 log.cc:1079] T 7c2f1d14334f4a13964d4d81da76d694 P 9cdce43c70c24b37aff4531a818a59bc: Deleting log segment in path: /tmp/dist-test-taskkQAF1q/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515530630243-20910-0/minicluster-data/ts-0-root/wals/7c2f1d14334f4a13964d4d81da76d694/wal-000000009 (ops 41-45)
I20260812 06:18:58.239631 21401 log.cc:1079] T 7c2f1d14334f4a13964d4d81da76d694 P 9cdce43c70c24b37aff4531a818a59bc: Deleting log segment in path: /tmp/dist-test-taskkQAF1q/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515530630243-20910-0/minicluster-data/ts-0-root/wals/7c2f1d14334f4a13964d4d81da76d694/wal-000000010 (ops 46-50)
I20260812 06:18:58.239670 21401 log.cc:1079] T 7c2f1d14334f4a13964d4d81da76d694 P 9cdce43c70c24b37aff4531a818a59bc: Deleting log segment in path: /tmp/dist-test-taskkQAF1q/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515530630243-20910-0/minicluster-data/ts-0-root/wals/7c2f1d14334f4a13964d4d81da76d694/wal-000000011 (ops 51-55)
I20260812 06:18:58.239725 21401 log.cc:1079] T 7c2f1d14334f4a13964d4d81da76d694 P 9cdce43c70c24b37aff4531a818a59bc: Deleting log segment in path: /tmp/dist-test-taskkQAF1q/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515530630243-20910-0/minicluster-data/ts-0-root/wals/7c2f1d14334f4a13964d4d81da76d694/wal-000000012 (ops 56-60)
I20260812 06:18:58.239759 21401 log.cc:1079] T 7c2f1d14334f4a13964d4d81da76d694 P 9cdce43c70c24b37aff4531a818a59bc: Deleting log segment in path: /tmp/dist-test-taskkQAF1q/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515530630243-20910-0/minicluster-data/ts-0-root/wals/7c2f1d14334f4a13964d4d81da76d694/wal-000000013 (ops 61-65)
I20260812 06:18:58.239820 21401 log.cc:1079] T 7c2f1d14334f4a13964d4d81da76d694 P 9cdce43c70c24b37aff4531a818a59bc: Deleting log segment in path: /tmp/dist-test-taskkQAF1q/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515530630243-20910-0/minicluster-data/ts-0-root/wals/7c2f1d14334f4a13964d4d81da76d694/wal-000000014 (ops 66-70)
I20260812 06:18:58.239856 21401 log.cc:1079] T 7c2f1d14334f4a13964d4d81da76d694 P 9cdce43c70c24b37aff4531a818a59bc: Deleting log segment in path: /tmp/dist-test-taskkQAF1q/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515530630243-20910-0/minicluster-data/ts-0-root/wals/7c2f1d14334f4a13964d4d81da76d694/wal-000000015 (ops 71-74)
I20260812 06:18:58.271657 21401 maintenance_manager.cc:643] P 9cdce43c70c24b37aff4531a818a59bc: LogGCOp(7c2f1d14334f4a13964d4d81da76d694) complete. Timing: real 0.033s	user 0.001s	sys 0.031s Metrics: {}
I20260812 06:18:58.272217 21508 maintenance_manager.cc:419] P 9cdce43c70c24b37aff4531a818a59bc: Scheduling UndoDeltaBlockGCOp(7c2f1d14334f4a13964d4d81da76d694): 484 bytes on disk
I20260812 06:18:58.272858 21401 maintenance_manager.cc:643] P 9cdce43c70c24b37aff4531a818a59bc: UndoDeltaBlockGCOp(7c2f1d14334f4a13964d4d81da76d694) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":95,"lbm_reads_lt_1ms":4}
I20260812 06:18:58.273387 21508 maintenance_manager.cc:419] P 9cdce43c70c24b37aff4531a818a59bc: Scheduling FlushDeltaMemStoresOp(7c2f1d14334f4a13964d4d81da76d694): perf score=14.095187
I20260812 06:18:58.312942 21401 maintenance_manager.cc:643] P 9cdce43c70c24b37aff4531a818a59bc: FlushDeltaMemStoresOp(7c2f1d14334f4a13964d4d81da76d694) complete. Timing: real 0.039s	user 0.026s	sys 0.012s Metrics: {"bytes_written":16409903,"delete_count":0,"lbm_write_time_us":17948,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:18:58.313470 21508 maintenance_manager.cc:419] P 9cdce43c70c24b37aff4531a818a59bc: Scheduling FlushDeltaMemStoresOp(7c2f1d14334f4a13964d4d81da76d694): perf score=2.188937
I20260812 06:18:58.347702 21401 maintenance_manager.cc:643] P 9cdce43c70c24b37aff4531a818a59bc: FlushDeltaMemStoresOp(7c2f1d14334f4a13964d4d81da76d694) complete. Timing: real 0.034s	user 0.003s	sys 0.020s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5368,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:58.348233 21508 maintenance_manager.cc:419] P 9cdce43c70c24b37aff4531a818a59bc: Scheduling FlushDeltaMemStoresOp(7c2f1d14334f4a13964d4d81da76d694): perf score=2.188937
I20260812 06:18:58.364435 21401 maintenance_manager.cc:643] P 9cdce43c70c24b37aff4531a818a59bc: FlushDeltaMemStoresOp(7c2f1d14334f4a13964d4d81da76d694) complete. Timing: real 0.016s	user 0.013s	sys 0.002s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6302,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:58.365054 21508 maintenance_manager.cc:419] P 9cdce43c70c24b37aff4531a818a59bc: Scheduling MajorDeltaCompactionOp(7c2f1d14334f4a13964d4d81da76d694): perf score=1.000000
I20260812 06:18:58.591688 21401 maintenance_manager.cc:643] P 9cdce43c70c24b37aff4531a818a59bc: MajorDeltaCompactionOp(7c2f1d14334f4a13964d4d81da76d694) complete. Timing: real 0.226s	user 0.162s	sys 0.057s Metrics: {"cfile_cache_miss":633,"cfile_cache_miss_bytes":28918216,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":616,"lbm_read_time_us":16197,"lbm_reads_lt_1ms":673,"lbm_write_time_us":39064,"lbm_writes_lt_1ms":643,"mutex_wait_us":48,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":1664,"update_count":3000}
I20260812 06:18:58.592478 21508 maintenance_manager.cc:419] P 9cdce43c70c24b37aff4531a818a59bc: Scheduling FlushDeltaMemStoresOp(7c2f1d14334f4a13964d4d81da76d694): perf score=15.087375
I20260812 06:18:58.657572 21401 maintenance_manager.cc:643] P 9cdce43c70c24b37aff4531a818a59bc: FlushDeltaMemStoresOp(7c2f1d14334f4a13964d4d81da76d694) complete. Timing: real 0.065s	user 0.039s	sys 0.023s Metrics: {"bytes_written":16984247,"delete_count":0,"lbm_write_time_us":25074,"lbm_writes_lt_1ms":417,"reinsert_count":0,"update_count":2070}
I20260812 06:18:58.658061 21508 maintenance_manager.cc:419] P 9cdce43c70c24b37aff4531a818a59bc: Scheduling FlushDeltaMemStoresOp(7c2f1d14334f4a13964d4d81da76d694): perf score=2.188937
I20260812 06:18:58.677621 21401 maintenance_manager.cc:643] P 9cdce43c70c24b37aff4531a818a59bc: FlushDeltaMemStoresOp(7c2f1d14334f4a13964d4d81da76d694) complete. Timing: real 0.019s	user 0.011s	sys 0.004s Metrics: {"bytes_written":3938559,"delete_count":0,"lbm_write_time_us":7084,"lbm_writes_lt_1ms":99,"reinsert_count":0,"update_count":480}
I20260812 06:18:58.678109 21508 maintenance_manager.cc:419] P 9cdce43c70c24b37aff4531a818a59bc: Scheduling FlushDeltaMemStoresOp(7c2f1d14334f4a13964d4d81da76d694): perf score=2.188937
I20260812 06:18:58.688973 21401 maintenance_manager.cc:643] P 9cdce43c70c24b37aff4531a818a59bc: FlushDeltaMemStoresOp(7c2f1d14334f4a13964d4d81da76d694) complete. Timing: real 0.011s	user 0.002s	sys 0.007s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":4420,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:18:58.689569 21508 maintenance_manager.cc:419] P 9cdce43c70c24b37aff4531a818a59bc: Scheduling MajorDeltaCompactionOp(7c2f1d14334f4a13964d4d81da76d694): perf score=1.000000
I20260812 06:18:58.941026 21401 maintenance_manager.cc:643] P 9cdce43c70c24b37aff4531a818a59bc: MajorDeltaCompactionOp(7c2f1d14334f4a13964d4d81da76d694) complete. Timing: real 0.251s	user 0.151s	sys 0.088s Metrics: {"cfile_cache_miss":633,"cfile_cache_miss_bytes":28918206,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":379,"lbm_read_time_us":15590,"lbm_reads_lt_1ms":673,"lbm_write_time_us":40136,"lbm_writes_lt_1ms":643,"peak_mem_usage":75542472,"reinsert_count":0,"update_count":3000}
I20260812 06:18:58.941704 21508 maintenance_manager.cc:419] P 9cdce43c70c24b37aff4531a818a59bc: Scheduling FlushDeltaMemStoresOp(7c2f1d14334f4a13964d4d81da76d694): perf score=18.063937
I20260812 06:18:59.020196 21401 maintenance_manager.cc:643] P 9cdce43c70c24b37aff4531a818a59bc: FlushDeltaMemStoresOp(7c2f1d14334f4a13964d4d81da76d694) complete. Timing: real 0.078s	user 0.035s	sys 0.040s Metrics: {"bytes_written":20512314,"delete_count":0,"lbm_write_time_us":34423,"lbm_writes_1-10_ms":2,"lbm_writes_lt_1ms":501,"reinsert_count":0,"update_count":2500}
I20260812 06:18:59.020732 21508 maintenance_manager.cc:419] P 9cdce43c70c24b37aff4531a818a59bc: Scheduling FlushDeltaMemStoresOp(7c2f1d14334f4a13964d4d81da76d694): perf score=2.188937
I20260812 06:18:59.033293 21401 maintenance_manager.cc:643] P 9cdce43c70c24b37aff4531a818a59bc: FlushDeltaMemStoresOp(7c2f1d14334f4a13964d4d81da76d694) complete. Timing: real 0.012s	user 0.005s	sys 0.006s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4259,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:59.033871 21508 maintenance_manager.cc:419] P 9cdce43c70c24b37aff4531a818a59bc: Scheduling MajorDeltaCompactionOp(7c2f1d14334f4a13964d4d81da76d694): perf score=1.000000
I20260812 06:18:59.279914 21401 maintenance_manager.cc:643] P 9cdce43c70c24b37aff4531a818a59bc: MajorDeltaCompactionOp(7c2f1d14334f4a13964d4d81da76d694) complete. Timing: real 0.246s	user 0.166s	sys 0.076s Metrics: {"cfile_cache_miss":632,"cfile_cache_miss_bytes":28918096,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":148,"lbm_read_time_us":16101,"lbm_reads_lt_1ms":672,"lbm_write_time_us":40671,"lbm_writes_lt_1ms":643,"mutex_wait_us":23,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":11392,"update_count":3000}
I20260812 06:18:59.280674 21508 maintenance_manager.cc:419] P 9cdce43c70c24b37aff4531a818a59bc: Scheduling FlushDeltaMemStoresOp(7c2f1d14334f4a13964d4d81da76d694): perf score=16.079562
I20260812 06:18:59.346377 21401 maintenance_manager.cc:643] P 9cdce43c70c24b37aff4531a818a59bc: FlushDeltaMemStoresOp(7c2f1d14334f4a13964d4d81da76d694) complete. Timing: real 0.066s	user 0.027s	sys 0.027s Metrics: {"bytes_written":17845750,"delete_count":0,"lbm_write_time_us":23845,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":437,"reinsert_count":0,"update_count":2175}
I20260812 06:18:59.346828 21508 maintenance_manager.cc:419] P 9cdce43c70c24b37aff4531a818a59bc: Scheduling FlushDeltaMemStoresOp(7c2f1d14334f4a13964d4d81da76d694): perf score=5.165500
I20260812 06:18:59.367321 21401 maintenance_manager.cc:643] P 9cdce43c70c24b37aff4531a818a59bc: FlushDeltaMemStoresOp(7c2f1d14334f4a13964d4d81da76d694) complete. Timing: real 0.020s	user 0.017s	sys 0.003s Metrics: {"bytes_written":6769237,"delete_count":0,"lbm_write_time_us":8223,"lbm_writes_lt_1ms":168,"reinsert_count":0,"update_count":825}
I20260812 06:18:59.367985 21508 maintenance_manager.cc:419] P 9cdce43c70c24b37aff4531a818a59bc: Scheduling MajorDeltaCompactionOp(7c2f1d14334f4a13964d4d81da76d694): perf score=1.000000
I20260812 06:18:59.567715 21401 maintenance_manager.cc:643] P 9cdce43c70c24b37aff4531a818a59bc: MajorDeltaCompactionOp(7c2f1d14334f4a13964d4d81da76d694) complete. Timing: real 0.200s	user 0.139s	sys 0.055s Metrics: {"cfile_cache_miss":632,"cfile_cache_miss_bytes":28918104,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":966,"lbm_read_time_us":12874,"lbm_reads_lt_1ms":672,"lbm_write_time_us":33834,"lbm_writes_lt_1ms":643,"mutex_wait_us":270,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":2816,"update_count":3000}
I20260812 06:18:59.568584 21508 maintenance_manager.cc:419] P 9cdce43c70c24b37aff4531a818a59bc: Scheduling FlushDeltaMemStoresOp(7c2f1d14334f4a13964d4d81da76d694): perf score=18.063937
I20260812 06:18:59.636615 21401 maintenance_manager.cc:643] P 9cdce43c70c24b37aff4531a818a59bc: FlushDeltaMemStoresOp(7c2f1d14334f4a13964d4d81da76d694) complete. Timing: real 0.068s	user 0.028s	sys 0.024s Metrics: {"bytes_written":20512316,"delete_count":0,"lbm_write_time_us":24658,"lbm_writes_lt_1ms":503,"reinsert_count":0,"update_count":2500}
I20260812 06:18:59.637072 21508 maintenance_manager.cc:419] P 9cdce43c70c24b37aff4531a818a59bc: Scheduling FlushDeltaMemStoresOp(7c2f1d14334f4a13964d4d81da76d694): perf score=2.188937
I20260812 06:18:59.648401 21401 maintenance_manager.cc:643] P 9cdce43c70c24b37aff4531a818a59bc: FlushDeltaMemStoresOp(7c2f1d14334f4a13964d4d81da76d694) complete. Timing: real 0.011s	user 0.002s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4322,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:59.648831 21508 maintenance_manager.cc:419] P 9cdce43c70c24b37aff4531a818a59bc: Scheduling FlushMRSOp(7c2f1d14334f4a13964d4d81da76d694): perf score=1.000000
I20260812 06:18:59.683560 21401 maintenance_manager.cc:643] P 9cdce43c70c24b37aff4531a818a59bc: FlushMRSOp(7c2f1d14334f4a13964d4d81da76d694) complete. Timing: real 0.035s	user 0.026s	sys 0.008s Metrics: {"bytes_written":1234477,"cfile_init":1,"dirs.queue_time_us":73,"dirs.run_cpu_time_us":187,"dirs.run_wall_time_us":1214,"drs_written":1,"lbm_read_time_us":42,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1644,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":30}
I20260812 06:18:59.684309 21508 maintenance_manager.cc:419] P 9cdce43c70c24b37aff4531a818a59bc: Scheduling LogGCOp(7c2f1d14334f4a13964d4d81da76d694): free 121459530 bytes of WAL
I20260812 06:18:59.684564 21401 log_reader.cc:385] T 7c2f1d14334f4a13964d4d81da76d694: removed 12 log segments from log reader
I20260812 06:18:59.684630 21401 log.cc:1079] T 7c2f1d14334f4a13964d4d81da76d694 P 9cdce43c70c24b37aff4531a818a59bc: Deleting log segment in path: /tmp/dist-test-taskkQAF1q/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515530630243-20910-0/minicluster-data/ts-0-root/wals/7c2f1d14334f4a13964d4d81da76d694/wal-000000016 (ops 75-79)
I20260812 06:18:59.684685 21401 log.cc:1079] T 7c2f1d14334f4a13964d4d81da76d694 P 9cdce43c70c24b37aff4531a818a59bc: Deleting log segment in path: /tmp/dist-test-taskkQAF1q/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515530630243-20910-0/minicluster-data/ts-0-root/wals/7c2f1d14334f4a13964d4d81da76d694/wal-000000017 (ops 80-84)
I20260812 06:18:59.684744 21401 log.cc:1079] T 7c2f1d14334f4a13964d4d81da76d694 P 9cdce43c70c24b37aff4531a818a59bc: Deleting log segment in path: /tmp/dist-test-taskkQAF1q/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515530630243-20910-0/minicluster-data/ts-0-root/wals/7c2f1d14334f4a13964d4d81da76d694/wal-000000018 (ops 85-89)
I20260812 06:18:59.684788 21401 log.cc:1079] T 7c2f1d14334f4a13964d4d81da76d694 P 9cdce43c70c24b37aff4531a818a59bc: Deleting log segment in path: /tmp/dist-test-taskkQAF1q/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515530630243-20910-0/minicluster-data/ts-0-root/wals/7c2f1d14334f4a13964d4d81da76d694/wal-000000019 (ops 90-94)
I20260812 06:18:59.684826 21401 log.cc:1079] T 7c2f1d14334f4a13964d4d81da76d694 P 9cdce43c70c24b37aff4531a818a59bc: Deleting log segment in path: /tmp/dist-test-taskkQAF1q/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515530630243-20910-0/minicluster-data/ts-0-root/wals/7c2f1d14334f4a13964d4d81da76d694/wal-000000020 (ops 95-99)
I20260812 06:18:59.684866 21401 log.cc:1079] T 7c2f1d14334f4a13964d4d81da76d694 P 9cdce43c70c24b37aff4531a818a59bc: Deleting log segment in path: /tmp/dist-test-taskkQAF1q/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515530630243-20910-0/minicluster-data/ts-0-root/wals/7c2f1d14334f4a13964d4d81da76d694/wal-000000021 (ops 100-104)
I20260812 06:18:59.684901 21401 log.cc:1079] T 7c2f1d14334f4a13964d4d81da76d694 P 9cdce43c70c24b37aff4531a818a59bc: Deleting log segment in path: /tmp/dist-test-taskkQAF1q/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515530630243-20910-0/minicluster-data/ts-0-root/wals/7c2f1d14334f4a13964d4d81da76d694/wal-000000022 (ops 105-109)
I20260812 06:18:59.684942 21401 log.cc:1079] T 7c2f1d14334f4a13964d4d81da76d694 P 9cdce43c70c24b37aff4531a818a59bc: Deleting log segment in path: /tmp/dist-test-taskkQAF1q/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515530630243-20910-0/minicluster-data/ts-0-root/wals/7c2f1d14334f4a13964d4d81da76d694/wal-000000023 (ops 110-114)
I20260812 06:18:59.684983 21401 log.cc:1079] T 7c2f1d14334f4a13964d4d81da76d694 P 9cdce43c70c24b37aff4531a818a59bc: Deleting log segment in path: /tmp/dist-test-taskkQAF1q/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515530630243-20910-0/minicluster-data/ts-0-root/wals/7c2f1d14334f4a13964d4d81da76d694/wal-000000024 (ops 115-119)
I20260812 06:18:59.685021 21401 log.cc:1079] T 7c2f1d14334f4a13964d4d81da76d694 P 9cdce43c70c24b37aff4531a818a59bc: Deleting log segment in path: /tmp/dist-test-taskkQAF1q/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515530630243-20910-0/minicluster-data/ts-0-root/wals/7c2f1d14334f4a13964d4d81da76d694/wal-000000025 (ops 120-124)
I20260812 06:18:59.685062 21401 log.cc:1079] T 7c2f1d14334f4a13964d4d81da76d694 P 9cdce43c70c24b37aff4531a818a59bc: Deleting log segment in path: /tmp/dist-test-taskkQAF1q/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515530630243-20910-0/minicluster-data/ts-0-root/wals/7c2f1d14334f4a13964d4d81da76d694/wal-000000026 (ops 125-129)
I20260812 06:18:59.685102 21401 log.cc:1079] T 7c2f1d14334f4a13964d4d81da76d694 P 9cdce43c70c24b37aff4531a818a59bc: Deleting log segment in path: /tmp/dist-test-taskkQAF1q/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515530630243-20910-0/minicluster-data/ts-0-root/wals/7c2f1d14334f4a13964d4d81da76d694/wal-000000027 (ops 130-134)
I20260812 06:18:59.712101 21401 maintenance_manager.cc:643] P 9cdce43c70c24b37aff4531a818a59bc: LogGCOp(7c2f1d14334f4a13964d4d81da76d694) complete. Timing: real 0.028s	user 0.000s	sys 0.027s Metrics: {}
I20260812 06:18:59.712569 21508 maintenance_manager.cc:419] P 9cdce43c70c24b37aff4531a818a59bc: Scheduling UndoDeltaBlockGCOp(7c2f1d14334f4a13964d4d81da76d694): 472 bytes on disk
I20260812 06:18:59.713181 21401 maintenance_manager.cc:643] P 9cdce43c70c24b37aff4531a818a59bc: UndoDeltaBlockGCOp(7c2f1d14334f4a13964d4d81da76d694) 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:59.713722 21508 maintenance_manager.cc:419] P 9cdce43c70c24b37aff4531a818a59bc: Scheduling FlushDeltaMemStoresOp(7c2f1d14334f4a13964d4d81da76d694): perf score=3.181125
I20260812 06:18:59.734406 21401 maintenance_manager.cc:643] P 9cdce43c70c24b37aff4531a818a59bc: FlushDeltaMemStoresOp(7c2f1d14334f4a13964d4d81da76d694) complete. Timing: real 0.020s	user 0.012s	sys 0.004s Metrics: {"bytes_written":4512900,"delete_count":0,"lbm_write_time_us":7404,"lbm_writes_lt_1ms":113,"reinsert_count":0,"update_count":550}
I20260812 06:18:59.734823 21508 maintenance_manager.cc:419] P 9cdce43c70c24b37aff4531a818a59bc: Scheduling FlushDeltaMemStoresOp(7c2f1d14334f4a13964d4d81da76d694): perf score=2.188937
I20260812 06:18:59.745242 21401 maintenance_manager.cc:643] P 9cdce43c70c24b37aff4531a818a59bc: FlushDeltaMemStoresOp(7c2f1d14334f4a13964d4d81da76d694) complete. Timing: real 0.010s	user 0.006s	sys 0.003s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":4157,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:18:59.745646 21508 maintenance_manager.cc:419] P 9cdce43c70c24b37aff4531a818a59bc: Scheduling MajorDeltaCompactionOp(7c2f1d14334f4a13964d4d81da76d694): perf score=1.000000
I20260812 06:18:59.983862 21401 maintenance_manager.cc:643] P 9cdce43c70c24b37aff4531a818a59bc: MajorDeltaCompactionOp(7c2f1d14334f4a13964d4d81da76d694) complete. Timing: real 0.238s	user 0.162s	sys 0.076s Metrics: {"cfile_cache_miss":834,"cfile_cache_miss_bytes":37123147,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":178,"lbm_read_time_us":18599,"lbm_reads_lt_1ms":874,"lbm_write_time_us":44333,"lbm_writes_lt_1ms":843,"mutex_wait_us":101,"peak_mem_usage":100395616,"reinsert_count":0,"spinlock_wait_cycles":1152,"thread_start_us":76,"threads_started":1,"update_count":4000}
I20260812 06:18:59.985302 21508 maintenance_manager.cc:419] P 9cdce43c70c24b37aff4531a818a59bc: Scheduling FlushDeltaMemStoresOp(7c2f1d14334f4a13964d4d81da76d694): perf score=19.056125
I20260812 06:19:00.059166 21401 maintenance_manager.cc:643] P 9cdce43c70c24b37aff4531a818a59bc: FlushDeltaMemStoresOp(7c2f1d14334f4a13964d4d81da76d694) complete. Timing: real 0.074s	user 0.023s	sys 0.035s Metrics: {"bytes_written":20922553,"delete_count":0,"lbm_write_time_us":29178,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":512,"reinsert_count":0,"update_count":2550}
I20260812 06:19:00.059686 21508 maintenance_manager.cc:419] P 9cdce43c70c24b37aff4531a818a59bc: Scheduling FlushDeltaMemStoresOp(7c2f1d14334f4a13964d4d81da76d694): perf score=6.157687
I20260812 06:19:00.083781 21401 maintenance_manager.cc:643] P 9cdce43c70c24b37aff4531a818a59bc: FlushDeltaMemStoresOp(7c2f1d14334f4a13964d4d81da76d694) complete. Timing: real 0.024s	user 0.018s	sys 0.004s Metrics: {"bytes_written":7794836,"delete_count":0,"lbm_write_time_us":10361,"lbm_writes_lt_1ms":193,"reinsert_count":0,"update_count":950}
I20260812 06:19:00.084309 21508 maintenance_manager.cc:419] P 9cdce43c70c24b37aff4531a818a59bc: Scheduling MajorDeltaCompactionOp(7c2f1d14334f4a13964d4d81da76d694): perf score=1.000000
I20260812 06:19:00.266837 21401 maintenance_manager.cc:643] P 9cdce43c70c24b37aff4531a818a59bc: MajorDeltaCompactionOp(7c2f1d14334f4a13964d4d81da76d694) complete. Timing: real 0.182s	user 0.154s	sys 0.028s Metrics: {"cfile_cache_miss":732,"cfile_cache_miss_bytes":33020506,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":232,"lbm_read_time_us":13859,"lbm_reads_lt_1ms":764,"lbm_write_time_us":38296,"lbm_writes_lt_1ms":743,"mutex_wait_us":44,"peak_mem_usage":87969044,"reinsert_count":0,"spinlock_wait_cycles":10752,"update_count":3500}
I20260812 06:19:00.267508 21508 maintenance_manager.cc:419] P 9cdce43c70c24b37aff4531a818a59bc: Scheduling FlushDeltaMemStoresOp(7c2f1d14334f4a13964d4d81da76d694): perf score=18.063937
I20260812 06:19:00.332576 21401 maintenance_manager.cc:643] P 9cdce43c70c24b37aff4531a818a59bc: FlushDeltaMemStoresOp(7c2f1d14334f4a13964d4d81da76d694) complete. Timing: real 0.065s	user 0.028s	sys 0.035s Metrics: {"bytes_written":20512316,"delete_count":0,"lbm_write_time_us":30955,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":502,"reinsert_count":0,"update_count":2500}
I20260812 06:19:00.333130 21508 maintenance_manager.cc:419] P 9cdce43c70c24b37aff4531a818a59bc: Scheduling FlushDeltaMemStoresOp(7c2f1d14334f4a13964d4d81da76d694): perf score=2.188937
I20260812 06:19:00.349275 21401 maintenance_manager.cc:643] P 9cdce43c70c24b37aff4531a818a59bc: FlushDeltaMemStoresOp(7c2f1d14334f4a13964d4d81da76d694) complete. Timing: real 0.016s	user 0.003s	sys 0.008s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":5209,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:00.349860 21508 maintenance_manager.cc:419] P 9cdce43c70c24b37aff4531a818a59bc: Scheduling MajorDeltaCompactionOp(7c2f1d14334f4a13964d4d81da76d694): perf score=1.000000
I20260812 06:19:00.514067 21401 maintenance_manager.cc:643] P 9cdce43c70c24b37aff4531a818a59bc: MajorDeltaCompactionOp(7c2f1d14334f4a13964d4d81da76d694) complete. Timing: real 0.164s	user 0.120s	sys 0.044s Metrics: {"cfile_cache_miss":632,"cfile_cache_miss_bytes":28918097,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":268,"lbm_read_time_us":12235,"lbm_reads_lt_1ms":664,"lbm_write_time_us":32626,"lbm_writes_lt_1ms":643,"mutex_wait_us":64,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":6528,"update_count":3000}
I20260812 06:19:00.514828 21508 maintenance_manager.cc:419] P 9cdce43c70c24b37aff4531a818a59bc: Scheduling FlushDeltaMemStoresOp(7c2f1d14334f4a13964d4d81da76d694): perf score=14.095187
I20260812 06:19:00.558911 21401 maintenance_manager.cc:643] P 9cdce43c70c24b37aff4531a818a59bc: FlushDeltaMemStoresOp(7c2f1d14334f4a13964d4d81da76d694) complete. Timing: real 0.044s	user 0.028s	sys 0.012s Metrics: {"bytes_written":16409900,"delete_count":0,"lbm_write_time_us":19689,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:00.559523 21508 maintenance_manager.cc:419] P 9cdce43c70c24b37aff4531a818a59bc: Scheduling FlushDeltaMemStoresOp(7c2f1d14334f4a13964d4d81da76d694): perf score=2.188937
I20260812 06:19:00.575757 21401 maintenance_manager.cc:643] P 9cdce43c70c24b37aff4531a818a59bc: FlushDeltaMemStoresOp(7c2f1d14334f4a13964d4d81da76d694) complete. Timing: real 0.016s	user 0.011s	sys 0.005s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6424,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:00.576274 21508 maintenance_manager.cc:419] P 9cdce43c70c24b37aff4531a818a59bc: Scheduling MajorDeltaCompactionOp(7c2f1d14334f4a13964d4d81da76d694): perf score=1.000000
I20260812 06:19:00.730326 21401 maintenance_manager.cc:643] P 9cdce43c70c24b37aff4531a818a59bc: MajorDeltaCompactionOp(7c2f1d14334f4a13964d4d81da76d694) complete. Timing: real 0.154s	user 0.113s	sys 0.040s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24815682,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":593,"lbm_read_time_us":11492,"lbm_reads_lt_1ms":564,"lbm_write_time_us":30312,"lbm_writes_lt_1ms":543,"mutex_wait_us":92,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":9472,"update_count":2500}
I20260812 06:19:00.730875 21508 maintenance_manager.cc:419] P 9cdce43c70c24b37aff4531a818a59bc: Scheduling FlushDeltaMemStoresOp(7c2f1d14334f4a13964d4d81da76d694): perf score=10.126437
I20260812 06:19:00.771983 21401 maintenance_manager.cc:643] P 9cdce43c70c24b37aff4531a818a59bc: FlushDeltaMemStoresOp(7c2f1d14334f4a13964d4d81da76d694) complete. Timing: real 0.041s	user 0.019s	sys 0.020s Metrics: {"bytes_written":12307493,"delete_count":0,"lbm_write_time_us":18461,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:19:00.772528 21508 maintenance_manager.cc:419] P 9cdce43c70c24b37aff4531a818a59bc: Scheduling FlushDeltaMemStoresOp(7c2f1d14334f4a13964d4d81da76d694): perf score=2.188937
I20260812 06:19:00.783440 21401 maintenance_manager.cc:643] P 9cdce43c70c24b37aff4531a818a59bc: FlushDeltaMemStoresOp(7c2f1d14334f4a13964d4d81da76d694) complete. Timing: real 0.011s	user 0.006s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4051,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:00.783926 21508 maintenance_manager.cc:419] P 9cdce43c70c24b37aff4531a818a59bc: Scheduling MajorDeltaCompactionOp(7c2f1d14334f4a13964d4d81da76d694): perf score=1.000000
I20260812 06:19:00.935271 21401 maintenance_manager.cc:643] P 9cdce43c70c24b37aff4531a818a59bc: MajorDeltaCompactionOp(7c2f1d14334f4a13964d4d81da76d694) complete. Timing: real 0.151s	user 0.100s	sys 0.048s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20713275,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":442,"lbm_read_time_us":11981,"lbm_reads_lt_1ms":472,"lbm_write_time_us":23648,"lbm_writes_lt_1ms":443,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":18304,"update_count":2000}
I20260812 06:19:00.936255 21508 maintenance_manager.cc:419] P 9cdce43c70c24b37aff4531a818a59bc: Scheduling FlushDeltaMemStoresOp(7c2f1d14334f4a13964d4d81da76d694): perf score=11.118625
I20260812 06:19:00.976039 21401 maintenance_manager.cc:643] P 9cdce43c70c24b37aff4531a818a59bc: FlushDeltaMemStoresOp(7c2f1d14334f4a13964d4d81da76d694) complete. Timing: real 0.040s	user 0.027s	sys 0.012s Metrics: {"bytes_written":12717735,"delete_count":0,"lbm_write_time_us":16887,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:19:00.976696 21508 maintenance_manager.cc:419] P 9cdce43c70c24b37aff4531a818a59bc: Scheduling FlushDeltaMemStoresOp(7c2f1d14334f4a13964d4d81da76d694): perf score=2.188937
I20260812 06:19:00.990381 21401 maintenance_manager.cc:643] P 9cdce43c70c24b37aff4531a818a59bc: FlushDeltaMemStoresOp(7c2f1d14334f4a13964d4d81da76d694) complete. Timing: real 0.013s	user 0.004s	sys 0.004s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":4224,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:19:00.990963 21508 maintenance_manager.cc:419] P 9cdce43c70c24b37aff4531a818a59bc: Scheduling FlushMRSOp(7c2f1d14334f4a13964d4d81da76d694): perf score=1.000000
I20260812 06:19:01.038440 21401 maintenance_manager.cc:643] P 9cdce43c70c24b37aff4531a818a59bc: FlushMRSOp(7c2f1d14334f4a13964d4d81da76d694) complete. Timing: real 0.047s	user 0.031s	sys 0.000s Metrics: {"bytes_written":1193507,"cfile_init":1,"dirs.queue_time_us":66,"dirs.run_cpu_time_us":274,"dirs.run_wall_time_us":1364,"drs_written":1,"lbm_read_time_us":49,"lbm_reads_lt_1ms":4,"lbm_write_time_us":2190,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":29}
I20260812 06:19:01.039089 21508 maintenance_manager.cc:419] P 9cdce43c70c24b37aff4531a818a59bc: Scheduling LogGCOp(7c2f1d14334f4a13964d4d81da76d694): free 111786441 bytes of WAL
I20260812 06:19:01.039352 21401 log_reader.cc:385] T 7c2f1d14334f4a13964d4d81da76d694: removed 11 log segments from log reader
I20260812 06:19:01.039399 21401 log.cc:1079] T 7c2f1d14334f4a13964d4d81da76d694 P 9cdce43c70c24b37aff4531a818a59bc: Deleting log segment in path: /tmp/dist-test-taskkQAF1q/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515530630243-20910-0/minicluster-data/ts-0-root/wals/7c2f1d14334f4a13964d4d81da76d694/wal-000000028 (ops 135-138)
I20260812 06:19:01.039428 21401 log.cc:1079] T 7c2f1d14334f4a13964d4d81da76d694 P 9cdce43c70c24b37aff4531a818a59bc: Deleting log segment in path: /tmp/dist-test-taskkQAF1q/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515530630243-20910-0/minicluster-data/ts-0-root/wals/7c2f1d14334f4a13964d4d81da76d694/wal-000000029 (ops 139-143)
I20260812 06:19:01.039489 21401 log.cc:1079] T 7c2f1d14334f4a13964d4d81da76d694 P 9cdce43c70c24b37aff4531a818a59bc: Deleting log segment in path: /tmp/dist-test-taskkQAF1q/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515530630243-20910-0/minicluster-data/ts-0-root/wals/7c2f1d14334f4a13964d4d81da76d694/wal-000000030 (ops 144-148)
I20260812 06:19:01.039520 21401 log.cc:1079] T 7c2f1d14334f4a13964d4d81da76d694 P 9cdce43c70c24b37aff4531a818a59bc: Deleting log segment in path: /tmp/dist-test-taskkQAF1q/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515530630243-20910-0/minicluster-data/ts-0-root/wals/7c2f1d14334f4a13964d4d81da76d694/wal-000000031 (ops 149-153)
I20260812 06:19:01.039562 21401 log.cc:1079] T 7c2f1d14334f4a13964d4d81da76d694 P 9cdce43c70c24b37aff4531a818a59bc: Deleting log segment in path: /tmp/dist-test-taskkQAF1q/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515530630243-20910-0/minicluster-data/ts-0-root/wals/7c2f1d14334f4a13964d4d81da76d694/wal-000000032 (ops 154-158)
I20260812 06:19:01.039603 21401 log.cc:1079] T 7c2f1d14334f4a13964d4d81da76d694 P 9cdce43c70c24b37aff4531a818a59bc: Deleting log segment in path: /tmp/dist-test-taskkQAF1q/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515530630243-20910-0/minicluster-data/ts-0-root/wals/7c2f1d14334f4a13964d4d81da76d694/wal-000000033 (ops 159-162)
I20260812 06:19:01.039642 21401 log.cc:1079] T 7c2f1d14334f4a13964d4d81da76d694 P 9cdce43c70c24b37aff4531a818a59bc: Deleting log segment in path: /tmp/dist-test-taskkQAF1q/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515530630243-20910-0/minicluster-data/ts-0-root/wals/7c2f1d14334f4a13964d4d81da76d694/wal-000000034 (ops 163-167)
I20260812 06:19:01.039683 21401 log.cc:1079] T 7c2f1d14334f4a13964d4d81da76d694 P 9cdce43c70c24b37aff4531a818a59bc: Deleting log segment in path: /tmp/dist-test-taskkQAF1q/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515530630243-20910-0/minicluster-data/ts-0-root/wals/7c2f1d14334f4a13964d4d81da76d694/wal-000000035 (ops 168-172)
I20260812 06:19:01.039722 21401 log.cc:1079] T 7c2f1d14334f4a13964d4d81da76d694 P 9cdce43c70c24b37aff4531a818a59bc: Deleting log segment in path: /tmp/dist-test-taskkQAF1q/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515530630243-20910-0/minicluster-data/ts-0-root/wals/7c2f1d14334f4a13964d4d81da76d694/wal-000000036 (ops 173-177)
I20260812 06:19:01.039762 21401 log.cc:1079] T 7c2f1d14334f4a13964d4d81da76d694 P 9cdce43c70c24b37aff4531a818a59bc: Deleting log segment in path: /tmp/dist-test-taskkQAF1q/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515530630243-20910-0/minicluster-data/ts-0-root/wals/7c2f1d14334f4a13964d4d81da76d694/wal-000000037 (ops 178-182)
I20260812 06:19:01.039804 21401 log.cc:1079] T 7c2f1d14334f4a13964d4d81da76d694 P 9cdce43c70c24b37aff4531a818a59bc: Deleting log segment in path: /tmp/dist-test-taskkQAF1q/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515530630243-20910-0/minicluster-data/ts-0-root/wals/7c2f1d14334f4a13964d4d81da76d694/wal-000000038 (ops 183-187)
I20260812 06:19:01.062832 21401 maintenance_manager.cc:643] P 9cdce43c70c24b37aff4531a818a59bc: LogGCOp(7c2f1d14334f4a13964d4d81da76d694) complete. Timing: real 0.024s	user 0.000s	sys 0.020s Metrics: {}
I20260812 06:19:01.063360 21508 maintenance_manager.cc:419] P 9cdce43c70c24b37aff4531a818a59bc: Scheduling FlushDeltaMemStoresOp(7c2f1d14334f4a13964d4d81da76d694): perf score=6.157687
I20260812 06:19:01.089466 21401 maintenance_manager.cc:643] P 9cdce43c70c24b37aff4531a818a59bc: FlushDeltaMemStoresOp(7c2f1d14334f4a13964d4d81da76d694) complete. Timing: real 0.026s	user 0.022s	sys 0.001s Metrics: {"bytes_written":8205077,"delete_count":0,"lbm_write_time_us":10787,"lbm_writes_lt_1ms":203,"reinsert_count":0,"update_count":1000}
I20260812 06:19:01.089942 21508 maintenance_manager.cc:419] P 9cdce43c70c24b37aff4531a818a59bc: Scheduling LogGCOp(7c2f1d14334f4a13964d4d81da76d694): free 12018004 bytes of WAL
I20260812 06:19:01.090170 21401 log_reader.cc:385] T 7c2f1d14334f4a13964d4d81da76d694: removed 1 log segments from log reader
I20260812 06:19:01.090217 21401 log.cc:1079] T 7c2f1d14334f4a13964d4d81da76d694 P 9cdce43c70c24b37aff4531a818a59bc: Deleting log segment in path: /tmp/dist-test-taskkQAF1q/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515530630243-20910-0/minicluster-data/ts-0-root/wals/7c2f1d14334f4a13964d4d81da76d694/wal-000000039 (ops 188-192)
I20260812 06:19:01.092784 21401 maintenance_manager.cc:643] P 9cdce43c70c24b37aff4531a818a59bc: LogGCOp(7c2f1d14334f4a13964d4d81da76d694) complete. Timing: real 0.003s	user 0.000s	sys 0.001s Metrics: {}
I20260812 06:19:01.093138 21508 maintenance_manager.cc:419] P 9cdce43c70c24b37aff4531a818a59bc: Scheduling FlushDeltaMemStoresOp(7c2f1d14334f4a13964d4d81da76d694): perf score=1.000000
I20260812 06:19:01.101202 21401 maintenance_manager.cc:643] P 9cdce43c70c24b37aff4531a818a59bc: FlushDeltaMemStoresOp(7c2f1d14334f4a13964d4d81da76d694) complete. Timing: real 0.008s	user 0.003s	sys 0.000s Metrics: {"bytes_written":1189881,"delete_count":0,"lbm_write_time_us":1367,"lbm_writes_lt_1ms":32,"reinsert_count":0,"update_count":145}
I20260812 06:19:01.101634 21508 maintenance_manager.cc:419] P 9cdce43c70c24b37aff4531a818a59bc: Scheduling FlushDeltaMemStoresOp(7c2f1d14334f4a13964d4d81da76d694): perf score=1.196750
I20260812 06:19:01.109661 21401 maintenance_manager.cc:643] P 9cdce43c70c24b37aff4531a818a59bc: FlushDeltaMemStoresOp(7c2f1d14334f4a13964d4d81da76d694) complete. Timing: real 0.008s	user 0.007s	sys 0.000s Metrics: {"bytes_written":2912930,"delete_count":0,"lbm_write_time_us":3022,"lbm_writes_lt_1ms":74,"reinsert_count":0,"update_count":355}
I20260812 06:19:01.110052 21508 maintenance_manager.cc:419] P 9cdce43c70c24b37aff4531a818a59bc: Scheduling MajorDeltaCompactionOp(7c2f1d14334f4a13964d4d81da76d694): perf score=1.000000
I20260812 06:19:01.263418 20910 heavy-update-compaction-itest.cc:229] Time spent updating: real 4.854s	user 1.798s	sys 0.190s
I20260812 06:19:01.346601 21401 maintenance_manager.cc:643] P 9cdce43c70c24b37aff4531a818a59bc: MajorDeltaCompactionOp(7c2f1d14334f4a13964d4d81da76d694) complete. Timing: real 0.236s	user 0.139s	sys 0.097s Metrics: {"cfile_cache_miss":735,"cfile_cache_miss_bytes":33020762,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":5,"delta_iterators_relevant":5,"dirs.queue_time_us":329,"lbm_read_time_us":16067,"lbm_reads_lt_1ms":771,"lbm_write_time_us":42528,"lbm_writes_lt_1ms":743,"mutex_wait_us":28,"peak_mem_usage":87969044,"reinsert_count":0,"spinlock_wait_cycles":18944,"thread_start_us":76,"threads_started":1,"update_count":3500}
I20260812 06:19:01.347193 21508 maintenance_manager.cc:419] P 9cdce43c70c24b37aff4531a818a59bc: Scheduling FlushDeltaMemStoresOp(7c2f1d14334f4a13964d4d81da76d694): perf score=10.126437
I20260812 06:19:01.356693 20910 heavy-update-compaction-itest.cc:265] Time spent scanning: real 0.093s	user 0.001s	sys 0.000s
I20260812 06:19:01.357190 20910 tablet_server.cc:179] TabletServer@127.20.107.129:0 shutting down...
I20260812 06:19:01.382117 21401 maintenance_manager.cc:643] P 9cdce43c70c24b37aff4531a818a59bc: FlushDeltaMemStoresOp(7c2f1d14334f4a13964d4d81da76d694) complete. Timing: real 0.035s	user 0.022s	sys 0.009s Metrics: {"bytes_written":12307489,"delete_count":0,"lbm_write_time_us":15297,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:19:01.382748 20910 ts_tablet_manager.cc:1507] Shutting down tablet manager...
I20260812 06:19:01.383038 20910 tablet_replica.cc:333] T 7c2f1d14334f4a13964d4d81da76d694 P 9cdce43c70c24b37aff4531a818a59bc: stopping tablet replica
I20260812 06:19:01.383278 20910 raft_consensus.cc:2243] T 7c2f1d14334f4a13964d4d81da76d694 P 9cdce43c70c24b37aff4531a818a59bc [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:19:01.383500 20910 raft_consensus.cc:2272] T 7c2f1d14334f4a13964d4d81da76d694 P 9cdce43c70c24b37aff4531a818a59bc [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:19:01.386840 20910 tablet_server.cc:196] TabletServer@127.20.107.129:0 shutdown complete.
I20260812 06:19:01.403832 20910 master.cc:562] Master@127.20.107.190:40103 shutting down...
I20260812 06:19:01.406929 20910 raft_consensus.cc:2243] T 00000000000000000000000000000000 P 6cfaf933698b4a43a6c858e38fdd7a41 [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:19:01.407115 20910 raft_consensus.cc:2272] T 00000000000000000000000000000000 P 6cfaf933698b4a43a6c858e38fdd7a41 [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:19:01.407198 20910 tablet_replica.cc:333] T 00000000000000000000000000000000 P 6cfaf933698b4a43a6c858e38fdd7a41: stopping tablet replica
I20260812 06:19:01.419325 20910 master.cc:584] Master@127.20.107.190:40103 shutdown complete.
[       OK ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/1 (5287 ms)
[----------] 2 tests from EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy (10863 ms total)

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