[==========] 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:19:48.438495 11983 internal_mini_cluster.cc:156] Creating distributed mini masters. Addrs: 127.11.179.254:44513
I20260812 06:19:48.439491 11983 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:19:48.440104 11983 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:19:48.446300 11991 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:19:48.446317 11983 server_base.cc:1061] running on GCE node
W20260812 06:19:48.446425 11988 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:19:48.446606 11989 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:19:48.447124 11983 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:19:48.447247 11983 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:19:48.447294 11983 hybrid_clock.cc:648] HybridClock initialized: now 1786515588447292 us; error 0 us; skew 500 ppm
I20260812 06:19:48.449129 11983 webserver.cc:533] Webserver started at http://127.11.179.254:36921/ using document root <none> and password file <none>
I20260812 06:19:48.449687 11983 fs_manager.cc:362] Metadata directory not provided
I20260812 06:19:48.449774 11983 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:19:48.450014 11983 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:19:48.451699 11983 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskujMVo5/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515588428075-11983-0/minicluster-data/master-0-root/instance:
uuid: "bfe40359faf94ed4a61f3010c7a6f717"
format_stamp: "Formatted at 2026-08-12 06:19:48 on dist-test-slave-5k54"
I20260812 06:19:48.455052 11983 fs_manager.cc:696] Time spent creating directory manager: real 0.003s	user 0.003s	sys 0.000s
I20260812 06:19:48.457122 11997 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:19:48.458063 11983 fs_manager.cc:730] Time spent opening block manager: real 0.002s	user 0.000s	sys 0.001s
I20260812 06:19:48.458196 11983 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskujMVo5/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515588428075-11983-0/minicluster-data/master-0-root
uuid: "bfe40359faf94ed4a61f3010c7a6f717"
format_stamp: "Formatted at 2026-08-12 06:19:48 on dist-test-slave-5k54"
I20260812 06:19:48.458297 11983 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskujMVo5/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515588428075-11983-0/minicluster-data/master-0-root
metadata directory: /tmp/dist-test-taskujMVo5/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515588428075-11983-0/minicluster-data/master-0-root
1 data directories: /tmp/dist-test-taskujMVo5/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515588428075-11983-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:19:48.470973 11983 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:19:48.471598 11983 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:19:48.471771 11983 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:19:48.479240 11983 rpc_server.cc:307] RPC server started. Bound to: 127.11.179.254:44513
I20260812 06:19:48.479243 12055 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.11.179.254:44513 every 8 connection(s)
I20260812 06:19:48.481446 12056 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:19:48.486780 12056 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P bfe40359faf94ed4a61f3010c7a6f717: Bootstrap starting.
I20260812 06:19:48.489405 12056 tablet_bootstrap.cc:654] T 00000000000000000000000000000000 P bfe40359faf94ed4a61f3010c7a6f717: Neither blocks nor log segments found. Creating new log.
I20260812 06:19:48.490263 12056 log.cc:826] T 00000000000000000000000000000000 P bfe40359faf94ed4a61f3010c7a6f717: Log is configured to *not* fsync() on all Append() calls
I20260812 06:19:48.492111 12056 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P bfe40359faf94ed4a61f3010c7a6f717: No bootstrap required, opened a new log
I20260812 06:19:48.495153 12056 raft_consensus.cc:359] T 00000000000000000000000000000000 P bfe40359faf94ed4a61f3010c7a6f717 [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "bfe40359faf94ed4a61f3010c7a6f717" member_type: VOTER }
I20260812 06:19:48.495337 12056 raft_consensus.cc:385] T 00000000000000000000000000000000 P bfe40359faf94ed4a61f3010c7a6f717 [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:19:48.495383 12056 raft_consensus.cc:740] T 00000000000000000000000000000000 P bfe40359faf94ed4a61f3010c7a6f717 [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: bfe40359faf94ed4a61f3010c7a6f717, State: Initialized, Role: FOLLOWER
I20260812 06:19:48.496100 12056 consensus_queue.cc:260] T 00000000000000000000000000000000 P bfe40359faf94ed4a61f3010c7a6f717 [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: "bfe40359faf94ed4a61f3010c7a6f717" member_type: VOTER }
I20260812 06:19:48.496249 12056 raft_consensus.cc:399] T 00000000000000000000000000000000 P bfe40359faf94ed4a61f3010c7a6f717 [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:19:48.496309 12056 raft_consensus.cc:493] T 00000000000000000000000000000000 P bfe40359faf94ed4a61f3010c7a6f717 [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:19:48.496399 12056 raft_consensus.cc:3060] T 00000000000000000000000000000000 P bfe40359faf94ed4a61f3010c7a6f717 [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:19:48.497195 12056 raft_consensus.cc:515] T 00000000000000000000000000000000 P bfe40359faf94ed4a61f3010c7a6f717 [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "bfe40359faf94ed4a61f3010c7a6f717" member_type: VOTER }
I20260812 06:19:48.497597 12056 leader_election.cc:304] T 00000000000000000000000000000000 P bfe40359faf94ed4a61f3010c7a6f717 [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: bfe40359faf94ed4a61f3010c7a6f717; no voters: 
I20260812 06:19:48.497874 12056 leader_election.cc:290] T 00000000000000000000000000000000 P bfe40359faf94ed4a61f3010c7a6f717 [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:19:48.498014 12060 raft_consensus.cc:2804] T 00000000000000000000000000000000 P bfe40359faf94ed4a61f3010c7a6f717 [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:19:48.498270 12060 raft_consensus.cc:697] T 00000000000000000000000000000000 P bfe40359faf94ed4a61f3010c7a6f717 [term 1 LEADER]: Becoming Leader. State: Replica: bfe40359faf94ed4a61f3010c7a6f717, State: Running, Role: LEADER
I20260812 06:19:48.498725 12060 consensus_queue.cc:237] T 00000000000000000000000000000000 P bfe40359faf94ed4a61f3010c7a6f717 [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: "bfe40359faf94ed4a61f3010c7a6f717" member_type: VOTER }
I20260812 06:19:48.499039 12056 sys_catalog.cc:565] T 00000000000000000000000000000000 P bfe40359faf94ed4a61f3010c7a6f717 [sys.catalog]: configured and running, proceeding with master startup.
I20260812 06:19:48.500736 12062 sys_catalog.cc:455] T 00000000000000000000000000000000 P bfe40359faf94ed4a61f3010c7a6f717 [sys.catalog]: SysCatalogTable state changed. Reason: New leader bfe40359faf94ed4a61f3010c7a6f717. Latest consensus state: current_term: 1 leader_uuid: "bfe40359faf94ed4a61f3010c7a6f717" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "bfe40359faf94ed4a61f3010c7a6f717" member_type: VOTER } }
I20260812 06:19:48.500763 12061 sys_catalog.cc:455] T 00000000000000000000000000000000 P bfe40359faf94ed4a61f3010c7a6f717 [sys.catalog]: SysCatalogTable state changed. Reason: RaftConsensus started. Latest consensus state: current_term: 1 leader_uuid: "bfe40359faf94ed4a61f3010c7a6f717" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "bfe40359faf94ed4a61f3010c7a6f717" member_type: VOTER } }
I20260812 06:19:48.500888 12062 sys_catalog.cc:458] T 00000000000000000000000000000000 P bfe40359faf94ed4a61f3010c7a6f717 [sys.catalog]: This master's current role is: LEADER
I20260812 06:19:48.500895 12061 sys_catalog.cc:458] T 00000000000000000000000000000000 P bfe40359faf94ed4a61f3010c7a6f717 [sys.catalog]: This master's current role is: LEADER
I20260812 06:19:48.501236 12071 catalog_manager.cc:1511] Loading table and tablet metadata into memory...
I20260812 06:19:48.503808 12071 catalog_manager.cc:1520] Initializing Kudu cluster ID...
I20260812 06:19:48.504101 11983 internal_mini_cluster.cc:184] Waiting to initialize catalog manager on master 0
I20260812 06:19:48.508852 12071 catalog_manager.cc:1383] Generated new cluster ID: 0a7fc78e7a964491b546114e8ca0b823
I20260812 06:19:48.508924 12071 catalog_manager.cc:1531] Initializing Kudu internal certificate authority...
I20260812 06:19:48.521577 12071 catalog_manager.cc:1406] Generated new certificate authority record
I20260812 06:19:48.522415 12071 catalog_manager.cc:1540] Loading token signing keys...
I20260812 06:19:48.534107 12071 catalog_manager.cc:6092] T 00000000000000000000000000000000 P bfe40359faf94ed4a61f3010c7a6f717: Generated new TSK 0
I20260812 06:19:48.534749 12071 catalog_manager.cc:1550] Initializing in-progress tserver states...
I20260812 06:19:48.536562 11983 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:19:48.539160 12082 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:19:48.539167 12081 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:19:48.539168 12084 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:19:48.539475 11983 server_base.cc:1061] running on GCE node
I20260812 06:19:48.539690 11983 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:19:48.539731 11983 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:19:48.539747 11983 hybrid_clock.cc:648] HybridClock initialized: now 1786515588539748 us; error 0 us; skew 500 ppm
I20260812 06:19:48.540649 11983 webserver.cc:533] Webserver started at http://127.11.179.193:39995/ using document root <none> and password file <none>
I20260812 06:19:48.540827 11983 fs_manager.cc:362] Metadata directory not provided
I20260812 06:19:48.540877 11983 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:19:48.540980 11983 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:19:48.541368 11983 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskujMVo5/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515588428075-11983-0/minicluster-data/ts-0-root/instance:
uuid: "4d06f60e9d8c4d24885d671b043411ff"
format_stamp: "Formatted at 2026-08-12 06:19:48 on dist-test-slave-5k54"
I20260812 06:19:48.542906 11983 fs_manager.cc:696] Time spent creating directory manager: real 0.001s	user 0.002s	sys 0.000s
I20260812 06:19:48.543978 12089 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:19:48.544258 11983 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.000s	sys 0.000s
I20260812 06:19:48.544320 11983 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskujMVo5/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515588428075-11983-0/minicluster-data/ts-0-root
uuid: "4d06f60e9d8c4d24885d671b043411ff"
format_stamp: "Formatted at 2026-08-12 06:19:48 on dist-test-slave-5k54"
I20260812 06:19:48.544405 11983 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskujMVo5/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515588428075-11983-0/minicluster-data/ts-0-root
metadata directory: /tmp/dist-test-taskujMVo5/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515588428075-11983-0/minicluster-data/ts-0-root
1 data directories: /tmp/dist-test-taskujMVo5/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515588428075-11983-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:19:48.550518 11983 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:19:48.550916 11983 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:19:48.551347 11983 txn_system_client.cc:432] TxnSystemClient initialization is disabled...
I20260812 06:19:48.552248 11983 ts_tablet_manager.cc:585] Loaded tablet metadata (0 total tablets, 0 live tablets)
I20260812 06:19:48.552300 11983 ts_tablet_manager.cc:531] Time spent load tablet metadata: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:19:48.552364 11983 ts_tablet_manager.cc:616] Registered 0 tablets
I20260812 06:19:48.552408 11983 ts_tablet_manager.cc:595] Time spent register tablets: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:19:48.558775 11983 rpc_server.cc:307] RPC server started. Bound to: 127.11.179.193:41621
I20260812 06:19:48.558993 12160 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.11.179.193:41621 every 8 connection(s)
I20260812 06:19:48.573154 12161 heartbeater.cc:344] Connected to a master server at 127.11.179.254:44513
I20260812 06:19:48.573436 12161 heartbeater.cc:461] Registering TS with master...
I20260812 06:19:48.573983 12161 heartbeater.cc:507] Master 127.11.179.254:44513 requested a full tablet report, sending...
I20260812 06:19:48.575634 12016 ts_manager.cc:194] Registered new tserver with Master: 4d06f60e9d8c4d24885d671b043411ff (127.11.179.193:41621)
I20260812 06:19:48.576284 11983 internal_mini_cluster.cc:371] 1 TS(s) registered with all masters after 0.016778443s
I20260812 06:19:48.577106 12016 master_service.cc:502] Signed X509 certificate for tserver {username='slave'} at 127.0.0.1:44374
I20260812 06:19:48.586419 12016 catalog_manager.cc:2283] Servicing CreateTable request from {username='slave'} at 127.0.0.1:44376:
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:19:48.600857 12121 tablet_service.cc:1511] Processing CreateTablet for tablet c809678222cd414480fa19f663ab45f0 (DEFAULT_TABLE table=heavy-update-compaction-test [id=1e5001c19bc149858d855c82474f1a0c]), partition=
I20260812 06:19:48.601377 12121 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet c809678222cd414480fa19f663ab45f0. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:19:48.604378 12174 tablet_bootstrap.cc:492] T c809678222cd414480fa19f663ab45f0 P 4d06f60e9d8c4d24885d671b043411ff: Bootstrap starting.
I20260812 06:19:48.605455 12174 tablet_bootstrap.cc:654] T c809678222cd414480fa19f663ab45f0 P 4d06f60e9d8c4d24885d671b043411ff: Neither blocks nor log segments found. Creating new log.
I20260812 06:19:48.606604 12174 tablet_bootstrap.cc:492] T c809678222cd414480fa19f663ab45f0 P 4d06f60e9d8c4d24885d671b043411ff: No bootstrap required, opened a new log
I20260812 06:19:48.606745 12174 ts_tablet_manager.cc:1403] T c809678222cd414480fa19f663ab45f0 P 4d06f60e9d8c4d24885d671b043411ff: Time spent bootstrapping tablet: real 0.002s	user 0.002s	sys 0.000s
I20260812 06:19:48.607152 12174 raft_consensus.cc:359] T c809678222cd414480fa19f663ab45f0 P 4d06f60e9d8c4d24885d671b043411ff [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "4d06f60e9d8c4d24885d671b043411ff" member_type: VOTER last_known_addr { host: "127.11.179.193" port: 41621 } }
I20260812 06:19:48.607302 12174 raft_consensus.cc:385] T c809678222cd414480fa19f663ab45f0 P 4d06f60e9d8c4d24885d671b043411ff [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:19:48.607379 12174 raft_consensus.cc:740] T c809678222cd414480fa19f663ab45f0 P 4d06f60e9d8c4d24885d671b043411ff [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: 4d06f60e9d8c4d24885d671b043411ff, State: Initialized, Role: FOLLOWER
I20260812 06:19:48.607568 12174 consensus_queue.cc:260] T c809678222cd414480fa19f663ab45f0 P 4d06f60e9d8c4d24885d671b043411ff [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: "4d06f60e9d8c4d24885d671b043411ff" member_type: VOTER last_known_addr { host: "127.11.179.193" port: 41621 } }
I20260812 06:19:48.607697 12174 raft_consensus.cc:399] T c809678222cd414480fa19f663ab45f0 P 4d06f60e9d8c4d24885d671b043411ff [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:19:48.607746 12174 raft_consensus.cc:493] T c809678222cd414480fa19f663ab45f0 P 4d06f60e9d8c4d24885d671b043411ff [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:19:48.607800 12174 raft_consensus.cc:3060] T c809678222cd414480fa19f663ab45f0 P 4d06f60e9d8c4d24885d671b043411ff [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:19:48.608606 12174 raft_consensus.cc:515] T c809678222cd414480fa19f663ab45f0 P 4d06f60e9d8c4d24885d671b043411ff [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "4d06f60e9d8c4d24885d671b043411ff" member_type: VOTER last_known_addr { host: "127.11.179.193" port: 41621 } }
I20260812 06:19:48.608767 12174 leader_election.cc:304] T c809678222cd414480fa19f663ab45f0 P 4d06f60e9d8c4d24885d671b043411ff [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: 4d06f60e9d8c4d24885d671b043411ff; no voters: 
I20260812 06:19:48.609017 12174 leader_election.cc:290] T c809678222cd414480fa19f663ab45f0 P 4d06f60e9d8c4d24885d671b043411ff [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:19:48.609110 12176 raft_consensus.cc:2804] T c809678222cd414480fa19f663ab45f0 P 4d06f60e9d8c4d24885d671b043411ff [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:19:48.609306 12176 raft_consensus.cc:697] T c809678222cd414480fa19f663ab45f0 P 4d06f60e9d8c4d24885d671b043411ff [term 1 LEADER]: Becoming Leader. State: Replica: 4d06f60e9d8c4d24885d671b043411ff, State: Running, Role: LEADER
I20260812 06:19:48.609390 12174 ts_tablet_manager.cc:1434] T c809678222cd414480fa19f663ab45f0 P 4d06f60e9d8c4d24885d671b043411ff: Time spent starting tablet: real 0.003s	user 0.000s	sys 0.003s
I20260812 06:19:48.609517 12176 consensus_queue.cc:237] T c809678222cd414480fa19f663ab45f0 P 4d06f60e9d8c4d24885d671b043411ff [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: "4d06f60e9d8c4d24885d671b043411ff" member_type: VOTER last_known_addr { host: "127.11.179.193" port: 41621 } }
I20260812 06:19:48.609728 12161 heartbeater.cc:499] Master 127.11.179.254:44513 was elected leader, sending a full tablet report...
I20260812 06:19:48.612507 12016 catalog_manager.cc:5719] T c809678222cd414480fa19f663ab45f0 P 4d06f60e9d8c4d24885d671b043411ff reported cstate change: term changed from 0 to 1, leader changed from <none> to 4d06f60e9d8c4d24885d671b043411ff (127.11.179.193). New cstate: current_term: 1 leader_uuid: "4d06f60e9d8c4d24885d671b043411ff" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "4d06f60e9d8c4d24885d671b043411ff" member_type: VOTER last_known_addr { host: "127.11.179.193" port: 41621 } health_report { overall_health: HEALTHY } } }
I20260812 06:19:48.683884 11983 heavy-update-compaction-itest.cc:215] Time spent inserting: real 0.062s	user 0.023s	sys 0.012s
I20260812 06:19:48.809914 12162 maintenance_manager.cc:419] P 4d06f60e9d8c4d24885d671b043411ff: Scheduling FlushMRSOp(c809678222cd414480fa19f663ab45f0): perf score=15.086190
I20260812 06:19:48.976481 12095 maintenance_manager.cc:643] P 4d06f60e9d8c4d24885d671b043411ff: FlushMRSOp(c809678222cd414480fa19f663ab45f0) complete. Timing: real 0.166s	user 0.116s	sys 0.049s Metrics: {"bytes_written":8656350,"cfile_init":1,"compiler_manager_pool.queue_time_us":326,"delete_count":0,"dirs.queue_time_us":61,"dirs.run_cpu_time_us":193,"dirs.run_wall_time_us":1173,"drs_written":1,"lbm_read_time_us":57,"lbm_reads_lt_1ms":4,"lbm_write_time_us":39053,"lbm_writes_lt_1ms":668,"peak_mem_usage":0,"reinsert_count":0,"rows_written":104,"spinlock_wait_cycles":158592,"update_count":1055}
I20260812 06:19:48.977615 12162 maintenance_manager.cc:419] P 4d06f60e9d8c4d24885d671b043411ff: Scheduling LogGCOp(c809678222cd414480fa19f663ab45f0): free 20743880 bytes of WAL
I20260812 06:19:48.977897 12095 log_reader.cc:385] T c809678222cd414480fa19f663ab45f0: removed 2 log segments from log reader
I20260812 06:19:48.977978 12095 log.cc:1079] T c809678222cd414480fa19f663ab45f0 P 4d06f60e9d8c4d24885d671b043411ff: Deleting log segment in path: /tmp/dist-test-taskujMVo5/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515588428075-11983-0/minicluster-data/ts-0-root/wals/c809678222cd414480fa19f663ab45f0/wal-000000001 (ops 1-6)
I20260812 06:19:48.978081 12095 log.cc:1079] T c809678222cd414480fa19f663ab45f0 P 4d06f60e9d8c4d24885d671b043411ff: Deleting log segment in path: /tmp/dist-test-taskujMVo5/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515588428075-11983-0/minicluster-data/ts-0-root/wals/c809678222cd414480fa19f663ab45f0/wal-000000002 (ops 7-11)
I20260812 06:19:48.983527 12095 maintenance_manager.cc:643] P 4d06f60e9d8c4d24885d671b043411ff: LogGCOp(c809678222cd414480fa19f663ab45f0) complete. Timing: real 0.006s	user 0.000s	sys 0.006s Metrics: {}
I20260812 06:19:48.983899 12162 maintenance_manager.cc:419] P 4d06f60e9d8c4d24885d671b043411ff: Scheduling FlushDeltaMemStoresOp(c809678222cd414480fa19f663ab45f0): perf score=2.188937
I20260812 06:19:49.000391 12095 maintenance_manager.cc:643] P 4d06f60e9d8c4d24885d671b043411ff: FlushDeltaMemStoresOp(c809678222cd414480fa19f663ab45f0) complete. Timing: real 0.016s	user 0.011s	sys 0.002s Metrics: {"bytes_written":3651380,"delete_count":0,"lbm_write_time_us":4950,"lbm_writes_lt_1ms":92,"reinsert_count":0,"update_count":445}
I20260812 06:19:49.001005 12162 maintenance_manager.cc:419] P 4d06f60e9d8c4d24885d671b043411ff: Scheduling MajorDeltaCompactionOp(c809678222cd414480fa19f663ab45f0): perf score=1.000000
I20260812 06:19:49.110848 12095 maintenance_manager.cc:643] P 4d06f60e9d8c4d24885d671b043411ff: MajorDeltaCompactionOp(c809678222cd414480fa19f663ab45f0) complete. Timing: real 0.109s	user 0.088s	sys 0.021s Metrics: {"cfile_cache_miss":332,"cfile_cache_miss_bytes":16569858,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":758,"lbm_read_time_us":5771,"lbm_reads_lt_1ms":364,"lbm_write_time_us":21013,"lbm_writes_lt_1ms":343,"peak_mem_usage":38262756,"reinsert_count":0,"spinlock_wait_cycles":1408,"thread_start_us":327,"threads_started":5,"update_count":1500}
I20260812 06:19:49.111457 12162 maintenance_manager.cc:419] P 4d06f60e9d8c4d24885d671b043411ff: Scheduling FlushDeltaMemStoresOp(c809678222cd414480fa19f663ab45f0): perf score=10.126437
I20260812 06:19:49.155485 12095 maintenance_manager.cc:643] P 4d06f60e9d8c4d24885d671b043411ff: FlushDeltaMemStoresOp(c809678222cd414480fa19f663ab45f0) complete. Timing: real 0.044s	user 0.023s	sys 0.009s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":15099,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:19:49.155977 12162 maintenance_manager.cc:419] P 4d06f60e9d8c4d24885d671b043411ff: Scheduling FlushDeltaMemStoresOp(c809678222cd414480fa19f663ab45f0): perf score=2.188937
I20260812 06:19:49.166800 12095 maintenance_manager.cc:643] P 4d06f60e9d8c4d24885d671b043411ff: FlushDeltaMemStoresOp(c809678222cd414480fa19f663ab45f0) complete. Timing: real 0.011s	user 0.005s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3975,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:49.167460 12162 maintenance_manager.cc:419] P 4d06f60e9d8c4d24885d671b043411ff: Scheduling MajorDeltaCompactionOp(c809678222cd414480fa19f663ab45f0): perf score=1.000000
I20260812 06:19:49.298260 12095 maintenance_manager.cc:643] P 4d06f60e9d8c4d24885d671b043411ff: MajorDeltaCompactionOp(c809678222cd414480fa19f663ab45f0) complete. Timing: real 0.131s	user 0.108s	sys 0.021s 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":521,"lbm_read_time_us":9087,"lbm_reads_lt_1ms":472,"lbm_write_time_us":23456,"lbm_writes_lt_1ms":443,"mutex_wait_us":42,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":384,"update_count":2000}
I20260812 06:19:49.298830 12162 maintenance_manager.cc:419] P 4d06f60e9d8c4d24885d671b043411ff: Scheduling FlushDeltaMemStoresOp(c809678222cd414480fa19f663ab45f0): perf score=10.126437
I20260812 06:19:49.351239 12095 maintenance_manager.cc:643] P 4d06f60e9d8c4d24885d671b043411ff: FlushDeltaMemStoresOp(c809678222cd414480fa19f663ab45f0) complete. Timing: real 0.052s	user 0.017s	sys 0.023s Metrics: {"bytes_written":12307492,"delete_count":0,"lbm_write_time_us":17695,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":302,"reinsert_count":0,"update_count":1500}
I20260812 06:19:49.351872 12162 maintenance_manager.cc:419] P 4d06f60e9d8c4d24885d671b043411ff: Scheduling UndoDeltaBlockGCOp(c809678222cd414480fa19f663ab45f0): 16411392 bytes on disk
I20260812 06:19:49.352360 12095 maintenance_manager.cc:643] P 4d06f60e9d8c4d24885d671b043411ff: UndoDeltaBlockGCOp(c809678222cd414480fa19f663ab45f0) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":54,"lbm_reads_lt_1ms":4}
I20260812 06:19:49.352752 12162 maintenance_manager.cc:419] P 4d06f60e9d8c4d24885d671b043411ff: Scheduling FlushDeltaMemStoresOp(c809678222cd414480fa19f663ab45f0): perf score=2.188937
I20260812 06:19:49.362973 12095 maintenance_manager.cc:643] P 4d06f60e9d8c4d24885d671b043411ff: FlushDeltaMemStoresOp(c809678222cd414480fa19f663ab45f0) complete. Timing: real 0.010s	user 0.004s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3895,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:49.363314 12162 maintenance_manager.cc:419] P 4d06f60e9d8c4d24885d671b043411ff: Scheduling MajorDeltaCompactionOp(c809678222cd414480fa19f663ab45f0): perf score=1.000000
I20260812 06:19:49.504654 12095 maintenance_manager.cc:643] P 4d06f60e9d8c4d24885d671b043411ff: MajorDeltaCompactionOp(c809678222cd414480fa19f663ab45f0) complete. Timing: real 0.141s	user 0.101s	sys 0.040s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672279,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":616,"lbm_read_time_us":10332,"lbm_reads_lt_1ms":472,"lbm_write_time_us":23015,"lbm_writes_lt_1ms":443,"mutex_wait_us":290,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":24832,"update_count":2000}
I20260812 06:19:49.505151 12162 maintenance_manager.cc:419] P 4d06f60e9d8c4d24885d671b043411ff: Scheduling FlushDeltaMemStoresOp(c809678222cd414480fa19f663ab45f0): perf score=10.126437
I20260812 06:19:49.557785 12095 maintenance_manager.cc:643] P 4d06f60e9d8c4d24885d671b043411ff: FlushDeltaMemStoresOp(c809678222cd414480fa19f663ab45f0) complete. Timing: real 0.052s	user 0.022s	sys 0.020s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":22051,"lbm_writes_1-10_ms":2,"lbm_writes_lt_1ms":301,"reinsert_count":0,"update_count":1500}
I20260812 06:19:49.558287 12162 maintenance_manager.cc:419] P 4d06f60e9d8c4d24885d671b043411ff: Scheduling FlushDeltaMemStoresOp(c809678222cd414480fa19f663ab45f0): perf score=2.188937
I20260812 06:19:49.569506 12095 maintenance_manager.cc:643] P 4d06f60e9d8c4d24885d671b043411ff: FlushDeltaMemStoresOp(c809678222cd414480fa19f663ab45f0) complete. Timing: real 0.011s	user 0.005s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4024,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:49.570057 12162 maintenance_manager.cc:419] P 4d06f60e9d8c4d24885d671b043411ff: Scheduling MajorDeltaCompactionOp(c809678222cd414480fa19f663ab45f0): perf score=1.000000
I20260812 06:19:49.701563 12095 maintenance_manager.cc:643] P 4d06f60e9d8c4d24885d671b043411ff: MajorDeltaCompactionOp(c809678222cd414480fa19f663ab45f0) complete. Timing: real 0.131s	user 0.095s	sys 0.036s 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":444,"lbm_read_time_us":9840,"lbm_reads_lt_1ms":472,"lbm_write_time_us":22756,"lbm_writes_lt_1ms":443,"mutex_wait_us":39,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":15744,"update_count":2000}
I20260812 06:19:49.702355 12162 maintenance_manager.cc:419] P 4d06f60e9d8c4d24885d671b043411ff: Scheduling FlushDeltaMemStoresOp(c809678222cd414480fa19f663ab45f0): perf score=10.126437
I20260812 06:19:49.743939 12095 maintenance_manager.cc:643] P 4d06f60e9d8c4d24885d671b043411ff: FlushDeltaMemStoresOp(c809678222cd414480fa19f663ab45f0) complete. Timing: real 0.041s	user 0.026s	sys 0.012s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":16428,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:19:49.744576 12162 maintenance_manager.cc:419] P 4d06f60e9d8c4d24885d671b043411ff: Scheduling FlushDeltaMemStoresOp(c809678222cd414480fa19f663ab45f0): perf score=2.188937
I20260812 06:19:49.759820 12095 maintenance_manager.cc:643] P 4d06f60e9d8c4d24885d671b043411ff: FlushDeltaMemStoresOp(c809678222cd414480fa19f663ab45f0) complete. Timing: real 0.015s	user 0.011s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5553,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:49.760492 12162 maintenance_manager.cc:419] P 4d06f60e9d8c4d24885d671b043411ff: Scheduling MajorDeltaCompactionOp(c809678222cd414480fa19f663ab45f0): perf score=1.000000
I20260812 06:19:49.892104 12095 maintenance_manager.cc:643] P 4d06f60e9d8c4d24885d671b043411ff: MajorDeltaCompactionOp(c809678222cd414480fa19f663ab45f0) complete. Timing: real 0.131s	user 0.123s	sys 0.008s 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":683,"lbm_read_time_us":9991,"lbm_reads_lt_1ms":472,"lbm_write_time_us":24085,"lbm_writes_lt_1ms":443,"mutex_wait_us":48,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":896,"update_count":2000}
I20260812 06:19:49.892683 12162 maintenance_manager.cc:419] P 4d06f60e9d8c4d24885d671b043411ff: Scheduling FlushDeltaMemStoresOp(c809678222cd414480fa19f663ab45f0): perf score=10.126437
I20260812 06:19:49.937717 12095 maintenance_manager.cc:643] P 4d06f60e9d8c4d24885d671b043411ff: FlushDeltaMemStoresOp(c809678222cd414480fa19f663ab45f0) complete. Timing: real 0.045s	user 0.015s	sys 0.027s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":16023,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":302,"reinsert_count":0,"update_count":1500}
I20260812 06:19:49.938297 12162 maintenance_manager.cc:419] P 4d06f60e9d8c4d24885d671b043411ff: Scheduling FlushDeltaMemStoresOp(c809678222cd414480fa19f663ab45f0): perf score=2.188937
I20260812 06:19:49.951563 12095 maintenance_manager.cc:643] P 4d06f60e9d8c4d24885d671b043411ff: FlushDeltaMemStoresOp(c809678222cd414480fa19f663ab45f0) complete. Timing: real 0.013s	user 0.013s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4805,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:49.951977 12162 maintenance_manager.cc:419] P 4d06f60e9d8c4d24885d671b043411ff: Scheduling MajorDeltaCompactionOp(c809678222cd414480fa19f663ab45f0): perf score=1.000000
I20260812 06:19:50.103262 12095 maintenance_manager.cc:643] P 4d06f60e9d8c4d24885d671b043411ff: MajorDeltaCompactionOp(c809678222cd414480fa19f663ab45f0) complete. Timing: real 0.150s	user 0.090s	sys 0.060s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672277,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":1046,"lbm_read_time_us":9388,"lbm_reads_lt_1ms":464,"lbm_write_time_us":25121,"lbm_writes_lt_1ms":443,"mutex_wait_us":304,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":11520,"update_count":2000}
I20260812 06:19:50.104233 12162 maintenance_manager.cc:419] P 4d06f60e9d8c4d24885d671b043411ff: Scheduling FlushDeltaMemStoresOp(c809678222cd414480fa19f663ab45f0): perf score=11.118625
I20260812 06:19:50.133745 12095 maintenance_manager.cc:643] P 4d06f60e9d8c4d24885d671b043411ff: FlushDeltaMemStoresOp(c809678222cd414480fa19f663ab45f0) complete. Timing: real 0.029s	user 0.011s	sys 0.016s Metrics: {"bytes_written":12717739,"delete_count":0,"lbm_write_time_us":12982,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:19:50.134398 12162 maintenance_manager.cc:419] P 4d06f60e9d8c4d24885d671b043411ff: Scheduling FlushDeltaMemStoresOp(c809678222cd414480fa19f663ab45f0): perf score=2.188937
I20260812 06:19:50.147981 12095 maintenance_manager.cc:643] P 4d06f60e9d8c4d24885d671b043411ff: FlushDeltaMemStoresOp(c809678222cd414480fa19f663ab45f0) complete. Timing: real 0.013s	user 0.001s	sys 0.012s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":4596,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:19:50.148546 12162 maintenance_manager.cc:419] P 4d06f60e9d8c4d24885d671b043411ff: Scheduling MajorDeltaCompactionOp(c809678222cd414480fa19f663ab45f0): perf score=1.000000
I20260812 06:19:50.270689 12095 maintenance_manager.cc:643] P 4d06f60e9d8c4d24885d671b043411ff: MajorDeltaCompactionOp(c809678222cd414480fa19f663ab45f0) complete. Timing: real 0.122s	user 0.089s	sys 0.028s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672272,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":301,"lbm_read_time_us":7474,"lbm_reads_lt_1ms":468,"lbm_write_time_us":23368,"lbm_writes_lt_1ms":443,"mutex_wait_us":66,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":11392,"update_count":2000}
I20260812 06:19:50.271461 12162 maintenance_manager.cc:419] P 4d06f60e9d8c4d24885d671b043411ff: Scheduling FlushDeltaMemStoresOp(c809678222cd414480fa19f663ab45f0): perf score=11.118625
I20260812 06:19:50.307133 12095 maintenance_manager.cc:643] P 4d06f60e9d8c4d24885d671b043411ff: FlushDeltaMemStoresOp(c809678222cd414480fa19f663ab45f0) complete. Timing: real 0.035s	user 0.023s	sys 0.009s Metrics: {"bytes_written":12717736,"delete_count":0,"lbm_write_time_us":14970,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:19:50.307677 12162 maintenance_manager.cc:419] P 4d06f60e9d8c4d24885d671b043411ff: Scheduling FlushDeltaMemStoresOp(c809678222cd414480fa19f663ab45f0): perf score=2.188937
I20260812 06:19:50.322427 12095 maintenance_manager.cc:643] P 4d06f60e9d8c4d24885d671b043411ff: FlushDeltaMemStoresOp(c809678222cd414480fa19f663ab45f0) complete. Timing: real 0.015s	user 0.007s	sys 0.005s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":5193,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:19:50.322944 12162 maintenance_manager.cc:419] P 4d06f60e9d8c4d24885d671b043411ff: Scheduling FlushMRSOp(c809678222cd414480fa19f663ab45f0): perf score=1.000000
I20260812 06:19:50.373248 12095 maintenance_manager.cc:643] P 4d06f60e9d8c4d24885d671b043411ff: FlushMRSOp(c809678222cd414480fa19f663ab45f0) complete. Timing: real 0.050s	user 0.033s	sys 0.000s Metrics: {"bytes_written":1316413,"cfile_init":1,"dirs.queue_time_us":60,"dirs.run_cpu_time_us":219,"dirs.run_wall_time_us":1491,"drs_written":1,"lbm_read_time_us":36,"lbm_reads_lt_1ms":4,"lbm_write_time_us":2064,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":32}
I20260812 06:19:50.374081 12162 maintenance_manager.cc:419] P 4d06f60e9d8c4d24885d671b043411ff: Scheduling LogGCOp(c809678222cd414480fa19f663ab45f0): free 121006433 bytes of WAL
I20260812 06:19:50.374312 12095 log_reader.cc:385] T c809678222cd414480fa19f663ab45f0: removed 12 log segments from log reader
I20260812 06:19:50.374358 12095 log.cc:1079] T c809678222cd414480fa19f663ab45f0 P 4d06f60e9d8c4d24885d671b043411ff: Deleting log segment in path: /tmp/dist-test-taskujMVo5/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515588428075-11983-0/minicluster-data/ts-0-root/wals/c809678222cd414480fa19f663ab45f0/wal-000000003 (ops 12-16)
I20260812 06:19:50.374387 12095 log.cc:1079] T c809678222cd414480fa19f663ab45f0 P 4d06f60e9d8c4d24885d671b043411ff: Deleting log segment in path: /tmp/dist-test-taskujMVo5/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515588428075-11983-0/minicluster-data/ts-0-root/wals/c809678222cd414480fa19f663ab45f0/wal-000000004 (ops 17-21)
I20260812 06:19:50.374446 12095 log.cc:1079] T c809678222cd414480fa19f663ab45f0 P 4d06f60e9d8c4d24885d671b043411ff: Deleting log segment in path: /tmp/dist-test-taskujMVo5/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515588428075-11983-0/minicluster-data/ts-0-root/wals/c809678222cd414480fa19f663ab45f0/wal-000000005 (ops 22-26)
I20260812 06:19:50.374491 12095 log.cc:1079] T c809678222cd414480fa19f663ab45f0 P 4d06f60e9d8c4d24885d671b043411ff: Deleting log segment in path: /tmp/dist-test-taskujMVo5/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515588428075-11983-0/minicluster-data/ts-0-root/wals/c809678222cd414480fa19f663ab45f0/wal-000000006 (ops 27-31)
I20260812 06:19:50.374536 12095 log.cc:1079] T c809678222cd414480fa19f663ab45f0 P 4d06f60e9d8c4d24885d671b043411ff: Deleting log segment in path: /tmp/dist-test-taskujMVo5/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515588428075-11983-0/minicluster-data/ts-0-root/wals/c809678222cd414480fa19f663ab45f0/wal-000000007 (ops 32-36)
I20260812 06:19:50.374571 12095 log.cc:1079] T c809678222cd414480fa19f663ab45f0 P 4d06f60e9d8c4d24885d671b043411ff: Deleting log segment in path: /tmp/dist-test-taskujMVo5/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515588428075-11983-0/minicluster-data/ts-0-root/wals/c809678222cd414480fa19f663ab45f0/wal-000000008 (ops 37-41)
I20260812 06:19:50.374614 12095 log.cc:1079] T c809678222cd414480fa19f663ab45f0 P 4d06f60e9d8c4d24885d671b043411ff: Deleting log segment in path: /tmp/dist-test-taskujMVo5/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515588428075-11983-0/minicluster-data/ts-0-root/wals/c809678222cd414480fa19f663ab45f0/wal-000000009 (ops 42-46)
I20260812 06:19:50.374655 12095 log.cc:1079] T c809678222cd414480fa19f663ab45f0 P 4d06f60e9d8c4d24885d671b043411ff: Deleting log segment in path: /tmp/dist-test-taskujMVo5/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515588428075-11983-0/minicluster-data/ts-0-root/wals/c809678222cd414480fa19f663ab45f0/wal-000000010 (ops 47-51)
I20260812 06:19:50.374694 12095 log.cc:1079] T c809678222cd414480fa19f663ab45f0 P 4d06f60e9d8c4d24885d671b043411ff: Deleting log segment in path: /tmp/dist-test-taskujMVo5/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515588428075-11983-0/minicluster-data/ts-0-root/wals/c809678222cd414480fa19f663ab45f0/wal-000000011 (ops 52-56)
I20260812 06:19:50.374733 12095 log.cc:1079] T c809678222cd414480fa19f663ab45f0 P 4d06f60e9d8c4d24885d671b043411ff: Deleting log segment in path: /tmp/dist-test-taskujMVo5/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515588428075-11983-0/minicluster-data/ts-0-root/wals/c809678222cd414480fa19f663ab45f0/wal-000000012 (ops 57-60)
I20260812 06:19:50.374773 12095 log.cc:1079] T c809678222cd414480fa19f663ab45f0 P 4d06f60e9d8c4d24885d671b043411ff: Deleting log segment in path: /tmp/dist-test-taskujMVo5/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515588428075-11983-0/minicluster-data/ts-0-root/wals/c809678222cd414480fa19f663ab45f0/wal-000000013 (ops 61-65)
I20260812 06:19:50.374812 12095 log.cc:1079] T c809678222cd414480fa19f663ab45f0 P 4d06f60e9d8c4d24885d671b043411ff: Deleting log segment in path: /tmp/dist-test-taskujMVo5/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515588428075-11983-0/minicluster-data/ts-0-root/wals/c809678222cd414480fa19f663ab45f0/wal-000000014 (ops 66-70)
I20260812 06:19:50.399646 12095 maintenance_manager.cc:643] P 4d06f60e9d8c4d24885d671b043411ff: LogGCOp(c809678222cd414480fa19f663ab45f0) complete. Timing: real 0.025s	user 0.002s	sys 0.023s Metrics: {}
I20260812 06:19:50.400115 12162 maintenance_manager.cc:419] P 4d06f60e9d8c4d24885d671b043411ff: Scheduling FlushDeltaMemStoresOp(c809678222cd414480fa19f663ab45f0): perf score=7.149875
I20260812 06:19:50.422192 12095 maintenance_manager.cc:643] P 4d06f60e9d8c4d24885d671b043411ff: FlushDeltaMemStoresOp(c809678222cd414480fa19f663ab45f0) complete. Timing: real 0.022s	user 0.018s	sys 0.001s Metrics: {"bytes_written":8615323,"delete_count":0,"lbm_write_time_us":8929,"lbm_writes_lt_1ms":213,"reinsert_count":0,"update_count":1050}
I20260812 06:19:50.422748 12162 maintenance_manager.cc:419] P 4d06f60e9d8c4d24885d671b043411ff: Scheduling LogGCOp(c809678222cd414480fa19f663ab45f0): free 12017927 bytes of WAL
I20260812 06:19:50.423024 12095 log_reader.cc:385] T c809678222cd414480fa19f663ab45f0: removed 1 log segments from log reader
I20260812 06:19:50.423092 12095 log.cc:1079] T c809678222cd414480fa19f663ab45f0 P 4d06f60e9d8c4d24885d671b043411ff: Deleting log segment in path: /tmp/dist-test-taskujMVo5/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515588428075-11983-0/minicluster-data/ts-0-root/wals/c809678222cd414480fa19f663ab45f0/wal-000000015 (ops 71-75)
I20260812 06:19:50.425997 12095 maintenance_manager.cc:643] P 4d06f60e9d8c4d24885d671b043411ff: LogGCOp(c809678222cd414480fa19f663ab45f0) complete. Timing: real 0.003s	user 0.000s	sys 0.001s Metrics: {}
I20260812 06:19:50.426432 12162 maintenance_manager.cc:419] P 4d06f60e9d8c4d24885d671b043411ff: Scheduling FlushDeltaMemStoresOp(c809678222cd414480fa19f663ab45f0): perf score=2.188937
I20260812 06:19:50.441464 12095 maintenance_manager.cc:643] P 4d06f60e9d8c4d24885d671b043411ff: FlushDeltaMemStoresOp(c809678222cd414480fa19f663ab45f0) complete. Timing: real 0.015s	user 0.011s	sys 0.001s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":5224,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:19:50.441958 12162 maintenance_manager.cc:419] P 4d06f60e9d8c4d24885d671b043411ff: Scheduling MajorDeltaCompactionOp(c809678222cd414480fa19f663ab45f0): perf score=1.000000
I20260812 06:19:50.626106 12095 maintenance_manager.cc:643] P 4d06f60e9d8c4d24885d671b043411ff: MajorDeltaCompactionOp(c809678222cd414480fa19f663ab45f0) complete. Timing: real 0.184s	user 0.149s	sys 0.032s Metrics: {"cfile_cache_miss":734,"cfile_cache_miss_bytes":32979735,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":921,"lbm_read_time_us":11908,"lbm_reads_lt_1ms":766,"lbm_write_time_us":35698,"lbm_writes_lt_1ms":743,"mutex_wait_us":86,"peak_mem_usage":87969044,"reinsert_count":0,"spinlock_wait_cycles":11008,"thread_start_us":81,"threads_started":1,"update_count":3500}
I20260812 06:19:50.626888 12162 maintenance_manager.cc:419] P 4d06f60e9d8c4d24885d671b043411ff: Scheduling UndoDeltaBlockGCOp(c809678222cd414480fa19f663ab45f0): 493 bytes on disk
I20260812 06:19:50.627370 12095 maintenance_manager.cc:643] P 4d06f60e9d8c4d24885d671b043411ff: UndoDeltaBlockGCOp(c809678222cd414480fa19f663ab45f0) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":90,"lbm_reads_lt_1ms":4}
I20260812 06:19:50.628037 12162 maintenance_manager.cc:419] P 4d06f60e9d8c4d24885d671b043411ff: Scheduling FlushDeltaMemStoresOp(c809678222cd414480fa19f663ab45f0): perf score=15.087375
I20260812 06:19:50.682354 12095 maintenance_manager.cc:643] P 4d06f60e9d8c4d24885d671b043411ff: FlushDeltaMemStoresOp(c809678222cd414480fa19f663ab45f0) complete. Timing: real 0.054s	user 0.033s	sys 0.019s Metrics: {"bytes_written":16820142,"delete_count":0,"lbm_write_time_us":23594,"lbm_writes_lt_1ms":413,"reinsert_count":0,"update_count":2050}
I20260812 06:19:50.682832 12162 maintenance_manager.cc:419] P 4d06f60e9d8c4d24885d671b043411ff: Scheduling FlushDeltaMemStoresOp(c809678222cd414480fa19f663ab45f0): perf score=2.188937
I20260812 06:19:50.698297 12095 maintenance_manager.cc:643] P 4d06f60e9d8c4d24885d671b043411ff: FlushDeltaMemStoresOp(c809678222cd414480fa19f663ab45f0) complete. Timing: real 0.015s	user 0.010s	sys 0.003s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":5979,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:19:50.698724 12162 maintenance_manager.cc:419] P 4d06f60e9d8c4d24885d671b043411ff: Scheduling MajorDeltaCompactionOp(c809678222cd414480fa19f663ab45f0): perf score=1.000000
I20260812 06:19:50.858573 12095 maintenance_manager.cc:643] P 4d06f60e9d8c4d24885d671b043411ff: MajorDeltaCompactionOp(c809678222cd414480fa19f663ab45f0) complete. Timing: real 0.160s	user 0.118s	sys 0.041s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774675,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":239,"lbm_read_time_us":9782,"lbm_reads_lt_1ms":568,"lbm_write_time_us":26771,"lbm_writes_lt_1ms":543,"mutex_wait_us":36,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":1792,"update_count":2500}
I20260812 06:19:50.859164 12162 maintenance_manager.cc:419] P 4d06f60e9d8c4d24885d671b043411ff: Scheduling FlushDeltaMemStoresOp(c809678222cd414480fa19f663ab45f0): perf score=14.095187
I20260812 06:19:50.913707 12095 maintenance_manager.cc:643] P 4d06f60e9d8c4d24885d671b043411ff: FlushDeltaMemStoresOp(c809678222cd414480fa19f663ab45f0) complete. Timing: real 0.054s	user 0.039s	sys 0.007s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":21344,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:50.914227 12162 maintenance_manager.cc:419] P 4d06f60e9d8c4d24885d671b043411ff: Scheduling FlushDeltaMemStoresOp(c809678222cd414480fa19f663ab45f0): perf score=2.188937
I20260812 06:19:50.925117 12095 maintenance_manager.cc:643] P 4d06f60e9d8c4d24885d671b043411ff: FlushDeltaMemStoresOp(c809678222cd414480fa19f663ab45f0) complete. Timing: real 0.011s	user 0.005s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3954,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:50.925592 12162 maintenance_manager.cc:419] P 4d06f60e9d8c4d24885d671b043411ff: Scheduling MajorDeltaCompactionOp(c809678222cd414480fa19f663ab45f0): perf score=1.000000
I20260812 06:19:51.102779 12095 maintenance_manager.cc:643] P 4d06f60e9d8c4d24885d671b043411ff: MajorDeltaCompactionOp(c809678222cd414480fa19f663ab45f0) complete. Timing: real 0.177s	user 0.133s	sys 0.040s 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":157,"lbm_read_time_us":11098,"lbm_reads_lt_1ms":572,"lbm_write_time_us":32260,"lbm_writes_lt_1ms":543,"mutex_wait_us":42,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":4992,"update_count":2500}
I20260812 06:19:51.106707 12162 maintenance_manager.cc:419] P 4d06f60e9d8c4d24885d671b043411ff: Scheduling FlushDeltaMemStoresOp(c809678222cd414480fa19f663ab45f0): perf score=11.118625
I20260812 06:19:51.146041 12095 maintenance_manager.cc:643] P 4d06f60e9d8c4d24885d671b043411ff: FlushDeltaMemStoresOp(c809678222cd414480fa19f663ab45f0) complete. Timing: real 0.039s	user 0.020s	sys 0.016s Metrics: {"bytes_written":12717736,"delete_count":0,"lbm_write_time_us":17072,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:19:51.146533 12162 maintenance_manager.cc:419] P 4d06f60e9d8c4d24885d671b043411ff: Scheduling FlushDeltaMemStoresOp(c809678222cd414480fa19f663ab45f0): perf score=2.188937
I20260812 06:19:51.157626 12095 maintenance_manager.cc:643] P 4d06f60e9d8c4d24885d671b043411ff: FlushDeltaMemStoresOp(c809678222cd414480fa19f663ab45f0) complete. Timing: real 0.011s	user 0.006s	sys 0.003s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":4135,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:19:51.158051 12162 maintenance_manager.cc:419] P 4d06f60e9d8c4d24885d671b043411ff: Scheduling MajorDeltaCompactionOp(c809678222cd414480fa19f663ab45f0): perf score=1.000000
I20260812 06:19:51.284394 12095 maintenance_manager.cc:643] P 4d06f60e9d8c4d24885d671b043411ff: MajorDeltaCompactionOp(c809678222cd414480fa19f663ab45f0) complete. Timing: real 0.126s	user 0.092s	sys 0.034s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672269,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":252,"lbm_read_time_us":8609,"lbm_reads_lt_1ms":472,"lbm_write_time_us":25228,"lbm_writes_lt_1ms":443,"mutex_wait_us":24,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":15232,"update_count":2000}
I20260812 06:19:51.284953 12162 maintenance_manager.cc:419] P 4d06f60e9d8c4d24885d671b043411ff: Scheduling FlushDeltaMemStoresOp(c809678222cd414480fa19f663ab45f0): perf score=10.126437
I20260812 06:19:51.327702 12095 maintenance_manager.cc:643] P 4d06f60e9d8c4d24885d671b043411ff: FlushDeltaMemStoresOp(c809678222cd414480fa19f663ab45f0) complete. Timing: real 0.043s	user 0.023s	sys 0.010s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":14330,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:19:51.328220 12162 maintenance_manager.cc:419] P 4d06f60e9d8c4d24885d671b043411ff: Scheduling FlushDeltaMemStoresOp(c809678222cd414480fa19f663ab45f0): perf score=2.188937
I20260812 06:19:51.339145 12095 maintenance_manager.cc:643] P 4d06f60e9d8c4d24885d671b043411ff: FlushDeltaMemStoresOp(c809678222cd414480fa19f663ab45f0) complete. Timing: real 0.011s	user 0.009s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4031,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:51.339800 12162 maintenance_manager.cc:419] P 4d06f60e9d8c4d24885d671b043411ff: Scheduling MajorDeltaCompactionOp(c809678222cd414480fa19f663ab45f0): perf score=1.000000
I20260812 06:19:51.461720 12095 maintenance_manager.cc:643] P 4d06f60e9d8c4d24885d671b043411ff: MajorDeltaCompactionOp(c809678222cd414480fa19f663ab45f0) complete. Timing: real 0.121s	user 0.104s	sys 0.016s 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":341,"lbm_read_time_us":8958,"lbm_reads_lt_1ms":472,"lbm_write_time_us":21808,"lbm_writes_lt_1ms":443,"mutex_wait_us":77,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":130432,"update_count":2000}
I20260812 06:19:51.462441 12162 maintenance_manager.cc:419] P 4d06f60e9d8c4d24885d671b043411ff: Scheduling FlushDeltaMemStoresOp(c809678222cd414480fa19f663ab45f0): perf score=10.126437
I20260812 06:19:51.512293 12095 maintenance_manager.cc:643] P 4d06f60e9d8c4d24885d671b043411ff: FlushDeltaMemStoresOp(c809678222cd414480fa19f663ab45f0) complete. Timing: real 0.050s	user 0.024s	sys 0.018s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":15923,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:19:51.512811 12162 maintenance_manager.cc:419] P 4d06f60e9d8c4d24885d671b043411ff: Scheduling FlushDeltaMemStoresOp(c809678222cd414480fa19f663ab45f0): perf score=2.188937
I20260812 06:19:51.523132 12095 maintenance_manager.cc:643] P 4d06f60e9d8c4d24885d671b043411ff: FlushDeltaMemStoresOp(c809678222cd414480fa19f663ab45f0) complete. Timing: real 0.010s	user 0.008s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4039,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:51.523654 12162 maintenance_manager.cc:419] P 4d06f60e9d8c4d24885d671b043411ff: Scheduling MajorDeltaCompactionOp(c809678222cd414480fa19f663ab45f0): perf score=1.000000
I20260812 06:19:51.663571 12095 maintenance_manager.cc:643] P 4d06f60e9d8c4d24885d671b043411ff: MajorDeltaCompactionOp(c809678222cd414480fa19f663ab45f0) complete. Timing: real 0.140s	user 0.081s	sys 0.059s 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":216,"lbm_read_time_us":10637,"lbm_reads_lt_1ms":472,"lbm_write_time_us":23124,"lbm_writes_lt_1ms":443,"mutex_wait_us":24,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":13440,"update_count":2000}
I20260812 06:19:51.664222 12162 maintenance_manager.cc:419] P 4d06f60e9d8c4d24885d671b043411ff: Scheduling FlushDeltaMemStoresOp(c809678222cd414480fa19f663ab45f0): perf score=10.126437
I20260812 06:19:51.715315 12095 maintenance_manager.cc:643] P 4d06f60e9d8c4d24885d671b043411ff: FlushDeltaMemStoresOp(c809678222cd414480fa19f663ab45f0) complete. Timing: real 0.051s	user 0.024s	sys 0.013s Metrics: {"bytes_written":12307491,"delete_count":0,"lbm_write_time_us":17847,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:19:51.715866 12162 maintenance_manager.cc:419] P 4d06f60e9d8c4d24885d671b043411ff: Scheduling FlushDeltaMemStoresOp(c809678222cd414480fa19f663ab45f0): perf score=2.188937
I20260812 06:19:51.727200 12095 maintenance_manager.cc:643] P 4d06f60e9d8c4d24885d671b043411ff: FlushDeltaMemStoresOp(c809678222cd414480fa19f663ab45f0) complete. Timing: real 0.011s	user 0.010s	sys 0.001s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4052,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:51.727809 12162 maintenance_manager.cc:419] P 4d06f60e9d8c4d24885d671b043411ff: Scheduling FlushMRSOp(c809678222cd414480fa19f663ab45f0): perf score=1.000000
I20260812 06:19:51.757548 12095 maintenance_manager.cc:643] P 4d06f60e9d8c4d24885d671b043411ff: FlushMRSOp(c809678222cd414480fa19f663ab45f0) complete. Timing: real 0.029s	user 0.025s	sys 0.002s Metrics: {"bytes_written":1152512,"cfile_init":1,"dirs.queue_time_us":66,"dirs.run_cpu_time_us":253,"dirs.run_wall_time_us":1391,"drs_written":1,"lbm_read_time_us":36,"lbm_reads_lt_1ms":4,"lbm_write_time_us":2019,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":28}
I20260812 06:19:51.758284 12162 maintenance_manager.cc:419] P 4d06f60e9d8c4d24885d671b043411ff: Scheduling LogGCOp(c809678222cd414480fa19f663ab45f0): free 115943188 bytes of WAL
I20260812 06:19:51.758515 12095 log_reader.cc:385] T c809678222cd414480fa19f663ab45f0: removed 11 log segments from log reader
I20260812 06:19:51.758561 12095 log.cc:1079] T c809678222cd414480fa19f663ab45f0 P 4d06f60e9d8c4d24885d671b043411ff: Deleting log segment in path: /tmp/dist-test-taskujMVo5/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515588428075-11983-0/minicluster-data/ts-0-root/wals/c809678222cd414480fa19f663ab45f0/wal-000000016 (ops 76-80)
I20260812 06:19:51.758590 12095 log.cc:1079] T c809678222cd414480fa19f663ab45f0 P 4d06f60e9d8c4d24885d671b043411ff: Deleting log segment in path: /tmp/dist-test-taskujMVo5/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515588428075-11983-0/minicluster-data/ts-0-root/wals/c809678222cd414480fa19f663ab45f0/wal-000000017 (ops 81-85)
I20260812 06:19:51.758657 12095 log.cc:1079] T c809678222cd414480fa19f663ab45f0 P 4d06f60e9d8c4d24885d671b043411ff: Deleting log segment in path: /tmp/dist-test-taskujMVo5/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515588428075-11983-0/minicluster-data/ts-0-root/wals/c809678222cd414480fa19f663ab45f0/wal-000000018 (ops 86-90)
I20260812 06:19:51.758700 12095 log.cc:1079] T c809678222cd414480fa19f663ab45f0 P 4d06f60e9d8c4d24885d671b043411ff: Deleting log segment in path: /tmp/dist-test-taskujMVo5/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515588428075-11983-0/minicluster-data/ts-0-root/wals/c809678222cd414480fa19f663ab45f0/wal-000000019 (ops 91-95)
I20260812 06:19:51.758742 12095 log.cc:1079] T c809678222cd414480fa19f663ab45f0 P 4d06f60e9d8c4d24885d671b043411ff: Deleting log segment in path: /tmp/dist-test-taskujMVo5/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515588428075-11983-0/minicluster-data/ts-0-root/wals/c809678222cd414480fa19f663ab45f0/wal-000000020 (ops 96-100)
I20260812 06:19:51.758803 12095 log.cc:1079] T c809678222cd414480fa19f663ab45f0 P 4d06f60e9d8c4d24885d671b043411ff: Deleting log segment in path: /tmp/dist-test-taskujMVo5/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515588428075-11983-0/minicluster-data/ts-0-root/wals/c809678222cd414480fa19f663ab45f0/wal-000000021 (ops 101-105)
I20260812 06:19:51.758839 12095 log.cc:1079] T c809678222cd414480fa19f663ab45f0 P 4d06f60e9d8c4d24885d671b043411ff: Deleting log segment in path: /tmp/dist-test-taskujMVo5/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515588428075-11983-0/minicluster-data/ts-0-root/wals/c809678222cd414480fa19f663ab45f0/wal-000000022 (ops 106-110)
I20260812 06:19:51.758894 12095 log.cc:1079] T c809678222cd414480fa19f663ab45f0 P 4d06f60e9d8c4d24885d671b043411ff: Deleting log segment in path: /tmp/dist-test-taskujMVo5/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515588428075-11983-0/minicluster-data/ts-0-root/wals/c809678222cd414480fa19f663ab45f0/wal-000000023 (ops 111-115)
I20260812 06:19:51.758936 12095 log.cc:1079] T c809678222cd414480fa19f663ab45f0 P 4d06f60e9d8c4d24885d671b043411ff: Deleting log segment in path: /tmp/dist-test-taskujMVo5/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515588428075-11983-0/minicluster-data/ts-0-root/wals/c809678222cd414480fa19f663ab45f0/wal-000000024 (ops 116-120)
I20260812 06:19:51.758981 12095 log.cc:1079] T c809678222cd414480fa19f663ab45f0 P 4d06f60e9d8c4d24885d671b043411ff: Deleting log segment in path: /tmp/dist-test-taskujMVo5/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515588428075-11983-0/minicluster-data/ts-0-root/wals/c809678222cd414480fa19f663ab45f0/wal-000000025 (ops 121-125)
I20260812 06:19:51.759021 12095 log.cc:1079] T c809678222cd414480fa19f663ab45f0 P 4d06f60e9d8c4d24885d671b043411ff: Deleting log segment in path: /tmp/dist-test-taskujMVo5/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515588428075-11983-0/minicluster-data/ts-0-root/wals/c809678222cd414480fa19f663ab45f0/wal-000000026 (ops 126-130)
I20260812 06:19:51.783500 12095 maintenance_manager.cc:643] P 4d06f60e9d8c4d24885d671b043411ff: LogGCOp(c809678222cd414480fa19f663ab45f0) complete. Timing: real 0.025s	user 0.000s	sys 0.025s Metrics: {}
I20260812 06:19:51.783918 12162 maintenance_manager.cc:419] P 4d06f60e9d8c4d24885d671b043411ff: Scheduling UndoDeltaBlockGCOp(c809678222cd414480fa19f663ab45f0): 447 bytes on disk
I20260812 06:19:51.784512 12095 maintenance_manager.cc:643] P 4d06f60e9d8c4d24885d671b043411ff: UndoDeltaBlockGCOp(c809678222cd414480fa19f663ab45f0) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":69,"lbm_reads_lt_1ms":4}
I20260812 06:19:51.785100 12162 maintenance_manager.cc:419] P 4d06f60e9d8c4d24885d671b043411ff: Scheduling FlushDeltaMemStoresOp(c809678222cd414480fa19f663ab45f0): perf score=3.181125
I20260812 06:19:51.804574 12095 maintenance_manager.cc:643] P 4d06f60e9d8c4d24885d671b043411ff: FlushDeltaMemStoresOp(c809678222cd414480fa19f663ab45f0) complete. Timing: real 0.019s	user 0.011s	sys 0.005s Metrics: {"bytes_written":4307780,"delete_count":0,"lbm_write_time_us":6843,"lbm_writes_lt_1ms":108,"reinsert_count":0,"update_count":525}
I20260812 06:19:51.805124 12162 maintenance_manager.cc:419] P 4d06f60e9d8c4d24885d671b043411ff: Scheduling FlushDeltaMemStoresOp(c809678222cd414480fa19f663ab45f0): perf score=2.188937
I20260812 06:19:51.824466 12095 maintenance_manager.cc:643] P 4d06f60e9d8c4d24885d671b043411ff: FlushDeltaMemStoresOp(c809678222cd414480fa19f663ab45f0) complete. Timing: real 0.019s	user 0.011s	sys 0.007s Metrics: {"bytes_written":3897534,"delete_count":0,"lbm_write_time_us":4031,"lbm_writes_lt_1ms":98,"reinsert_count":0,"update_count":475}
I20260812 06:19:51.825137 12162 maintenance_manager.cc:419] P 4d06f60e9d8c4d24885d671b043411ff: Scheduling MajorDeltaCompactionOp(c809678222cd414480fa19f663ab45f0): perf score=1.000000
I20260812 06:19:52.030421 12095 maintenance_manager.cc:643] P 4d06f60e9d8c4d24885d671b043411ff: MajorDeltaCompactionOp(c809678222cd414480fa19f663ab45f0) complete. Timing: real 0.205s	user 0.157s	sys 0.048s Metrics: {"cfile_cache_miss":634,"cfile_cache_miss_bytes":28877336,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":746,"lbm_read_time_us":14134,"lbm_reads_lt_1ms":674,"lbm_write_time_us":34714,"lbm_writes_lt_1ms":643,"mutex_wait_us":319,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":8576,"thread_start_us":83,"threads_started":1,"update_count":3000}
I20260812 06:19:52.031193 12162 maintenance_manager.cc:419] P 4d06f60e9d8c4d24885d671b043411ff: Scheduling FlushDeltaMemStoresOp(c809678222cd414480fa19f663ab45f0): perf score=14.095187
I20260812 06:19:52.099715 12095 maintenance_manager.cc:643] P 4d06f60e9d8c4d24885d671b043411ff: FlushDeltaMemStoresOp(c809678222cd414480fa19f663ab45f0) complete. Timing: real 0.068s	user 0.023s	sys 0.038s Metrics: {"bytes_written":16409904,"delete_count":0,"lbm_write_time_us":23576,"lbm_writes_lt_1ms":403,"reinsert_count":0,"spinlock_wait_cycles":768,"update_count":2000}
I20260812 06:19:52.100396 12162 maintenance_manager.cc:419] P 4d06f60e9d8c4d24885d671b043411ff: Scheduling FlushDeltaMemStoresOp(c809678222cd414480fa19f663ab45f0): perf score=2.188937
I20260812 06:19:52.111475 12095 maintenance_manager.cc:643] P 4d06f60e9d8c4d24885d671b043411ff: FlushDeltaMemStoresOp(c809678222cd414480fa19f663ab45f0) complete. Timing: real 0.011s	user 0.001s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4370,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:52.111958 12162 maintenance_manager.cc:419] P 4d06f60e9d8c4d24885d671b043411ff: Scheduling MajorDeltaCompactionOp(c809678222cd414480fa19f663ab45f0): perf score=1.000000
I20260812 06:19:52.274891 12095 maintenance_manager.cc:643] P 4d06f60e9d8c4d24885d671b043411ff: MajorDeltaCompactionOp(c809678222cd414480fa19f663ab45f0) complete. Timing: real 0.163s	user 0.118s	sys 0.044s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774691,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":961,"lbm_read_time_us":12225,"lbm_reads_lt_1ms":572,"lbm_write_time_us":25020,"lbm_writes_lt_1ms":543,"mutex_wait_us":30,"peak_mem_usage":63115900,"reinsert_count":0,"update_count":2500}
I20260812 06:19:52.275626 12162 maintenance_manager.cc:419] P 4d06f60e9d8c4d24885d671b043411ff: Scheduling FlushDeltaMemStoresOp(c809678222cd414480fa19f663ab45f0): perf score=10.126437
I20260812 06:19:52.312088 12095 maintenance_manager.cc:643] P 4d06f60e9d8c4d24885d671b043411ff: FlushDeltaMemStoresOp(c809678222cd414480fa19f663ab45f0) complete. Timing: real 0.036s	user 0.019s	sys 0.012s Metrics: {"bytes_written":12307491,"delete_count":0,"lbm_write_time_us":13631,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:19:52.313242 12162 maintenance_manager.cc:419] P 4d06f60e9d8c4d24885d671b043411ff: Scheduling FlushDeltaMemStoresOp(c809678222cd414480fa19f663ab45f0): perf score=2.188937
I20260812 06:19:52.328130 12095 maintenance_manager.cc:643] P 4d06f60e9d8c4d24885d671b043411ff: FlushDeltaMemStoresOp(c809678222cd414480fa19f663ab45f0) complete. Timing: real 0.015s	user 0.005s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5320,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:52.328593 12162 maintenance_manager.cc:419] P 4d06f60e9d8c4d24885d671b043411ff: Scheduling MajorDeltaCompactionOp(c809678222cd414480fa19f663ab45f0): perf score=1.000000
I20260812 06:19:52.455557 12095 maintenance_manager.cc:643] P 4d06f60e9d8c4d24885d671b043411ff: MajorDeltaCompactionOp(c809678222cd414480fa19f663ab45f0) complete. Timing: real 0.127s	user 0.104s	sys 0.020s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672278,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":1721,"lbm_read_time_us":8514,"lbm_reads_lt_1ms":472,"lbm_write_time_us":23143,"lbm_writes_lt_1ms":443,"mutex_wait_us":590,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":1664,"update_count":2000}
I20260812 06:19:52.456233 12162 maintenance_manager.cc:419] P 4d06f60e9d8c4d24885d671b043411ff: Scheduling FlushDeltaMemStoresOp(c809678222cd414480fa19f663ab45f0): perf score=10.126437
I20260812 06:19:52.516074 12095 maintenance_manager.cc:643] P 4d06f60e9d8c4d24885d671b043411ff: FlushDeltaMemStoresOp(c809678222cd414480fa19f663ab45f0) complete. Timing: real 0.059s	user 0.023s	sys 0.032s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":25651,"lbm_writes_1-10_ms":2,"lbm_writes_lt_1ms":301,"reinsert_count":0,"update_count":1500}
I20260812 06:19:52.516827 12162 maintenance_manager.cc:419] P 4d06f60e9d8c4d24885d671b043411ff: Scheduling FlushDeltaMemStoresOp(c809678222cd414480fa19f663ab45f0): perf score=3.181125
I20260812 06:19:52.535765 12095 maintenance_manager.cc:643] P 4d06f60e9d8c4d24885d671b043411ff: FlushDeltaMemStoresOp(c809678222cd414480fa19f663ab45f0) complete. Timing: real 0.019s	user 0.010s	sys 0.008s Metrics: {"bytes_written":4512900,"delete_count":0,"lbm_write_time_us":7266,"lbm_writes_lt_1ms":113,"reinsert_count":0,"update_count":550}
I20260812 06:19:52.536371 12162 maintenance_manager.cc:419] P 4d06f60e9d8c4d24885d671b043411ff: Scheduling FlushDeltaMemStoresOp(c809678222cd414480fa19f663ab45f0): perf score=2.188937
I20260812 06:19:52.545831 12095 maintenance_manager.cc:643] P 4d06f60e9d8c4d24885d671b043411ff: FlushDeltaMemStoresOp(c809678222cd414480fa19f663ab45f0) complete. Timing: real 0.009s	user 0.004s	sys 0.003s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3472,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:19:52.546377 12162 maintenance_manager.cc:419] P 4d06f60e9d8c4d24885d671b043411ff: Scheduling MajorDeltaCompactionOp(c809678222cd414480fa19f663ab45f0): perf score=1.000000
I20260812 06:19:52.744673 12095 maintenance_manager.cc:643] P 4d06f60e9d8c4d24885d671b043411ff: MajorDeltaCompactionOp(c809678222cd414480fa19f663ab45f0) complete. Timing: real 0.198s	user 0.162s	sys 0.022s Metrics: {"cfile_cache_miss":533,"cfile_cache_miss_bytes":24774795,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":225,"lbm_read_time_us":10412,"lbm_reads_lt_1ms":573,"lbm_write_time_us":35185,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":542,"peak_mem_usage":63115900,"reinsert_count":0,"update_count":2500}
I20260812 06:19:52.745355 12162 maintenance_manager.cc:419] P 4d06f60e9d8c4d24885d671b043411ff: Scheduling FlushDeltaMemStoresOp(c809678222cd414480fa19f663ab45f0): perf score=14.095187
I20260812 06:19:52.811759 12095 maintenance_manager.cc:643] P 4d06f60e9d8c4d24885d671b043411ff: FlushDeltaMemStoresOp(c809678222cd414480fa19f663ab45f0) complete. Timing: real 0.066s	user 0.037s	sys 0.012s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":21076,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:52.812244 12162 maintenance_manager.cc:419] P 4d06f60e9d8c4d24885d671b043411ff: Scheduling FlushDeltaMemStoresOp(c809678222cd414480fa19f663ab45f0): perf score=2.188937
I20260812 06:19:52.827147 12095 maintenance_manager.cc:643] P 4d06f60e9d8c4d24885d671b043411ff: FlushDeltaMemStoresOp(c809678222cd414480fa19f663ab45f0) complete. Timing: real 0.015s	user 0.008s	sys 0.004s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":5535,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:52.827732 12162 maintenance_manager.cc:419] P 4d06f60e9d8c4d24885d671b043411ff: Scheduling MajorDeltaCompactionOp(c809678222cd414480fa19f663ab45f0): perf score=1.000000
I20260812 06:19:52.997898 12095 maintenance_manager.cc:643] P 4d06f60e9d8c4d24885d671b043411ff: MajorDeltaCompactionOp(c809678222cd414480fa19f663ab45f0) complete. Timing: real 0.170s	user 0.117s	sys 0.050s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774687,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":820,"lbm_read_time_us":10720,"lbm_reads_lt_1ms":572,"lbm_write_time_us":34940,"lbm_writes_lt_1ms":543,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":7168,"update_count":2500}
I20260812 06:19:52.998520 12162 maintenance_manager.cc:419] P 4d06f60e9d8c4d24885d671b043411ff: Scheduling FlushDeltaMemStoresOp(c809678222cd414480fa19f663ab45f0): perf score=10.126437
I20260812 06:19:53.042055 12095 maintenance_manager.cc:643] P 4d06f60e9d8c4d24885d671b043411ff: FlushDeltaMemStoresOp(c809678222cd414480fa19f663ab45f0) complete. Timing: real 0.043s	user 0.032s	sys 0.007s Metrics: {"bytes_written":12307489,"delete_count":0,"lbm_write_time_us":18165,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:19:53.042608 12162 maintenance_manager.cc:419] P 4d06f60e9d8c4d24885d671b043411ff: Scheduling MajorDeltaCompactionOp(c809678222cd414480fa19f663ab45f0): perf score=1.000000
I20260812 06:19:53.161273 12095 maintenance_manager.cc:643] P 4d06f60e9d8c4d24885d671b043411ff: MajorDeltaCompactionOp(c809678222cd414480fa19f663ab45f0) complete. Timing: real 0.118s	user 0.089s	sys 0.027s Metrics: {"cfile_cache_miss":331,"cfile_cache_miss_bytes":16569745,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":1,"delta_iterators_relevant":1,"dirs.queue_time_us":374,"lbm_read_time_us":6176,"lbm_reads_lt_1ms":367,"lbm_write_time_us":19052,"lbm_writes_lt_1ms":343,"mutex_wait_us":104,"peak_mem_usage":38262756,"reinsert_count":0,"spinlock_wait_cycles":2560,"update_count":1500}
I20260812 06:19:53.161994 12162 maintenance_manager.cc:419] P 4d06f60e9d8c4d24885d671b043411ff: Scheduling FlushDeltaMemStoresOp(c809678222cd414480fa19f663ab45f0): perf score=10.126437
I20260812 06:19:53.208575 12095 maintenance_manager.cc:643] P 4d06f60e9d8c4d24885d671b043411ff: FlushDeltaMemStoresOp(c809678222cd414480fa19f663ab45f0) complete. Timing: real 0.046s	user 0.034s	sys 0.003s Metrics: {"bytes_written":12307492,"delete_count":0,"lbm_write_time_us":16551,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:19:53.209075 12162 maintenance_manager.cc:419] P 4d06f60e9d8c4d24885d671b043411ff: Scheduling FlushDeltaMemStoresOp(c809678222cd414480fa19f663ab45f0): perf score=2.188937
I20260812 06:19:53.219485 12095 maintenance_manager.cc:643] P 4d06f60e9d8c4d24885d671b043411ff: FlushDeltaMemStoresOp(c809678222cd414480fa19f663ab45f0) complete. Timing: real 0.010s	user 0.002s	sys 0.008s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":3958,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:53.220328 12162 maintenance_manager.cc:419] P 4d06f60e9d8c4d24885d671b043411ff: Scheduling FlushMRSOp(c809678222cd414480fa19f663ab45f0): perf score=1.000000
I20260812 06:19:53.250291 12095 maintenance_manager.cc:643] P 4d06f60e9d8c4d24885d671b043411ff: FlushMRSOp(c809678222cd414480fa19f663ab45f0) complete. Timing: real 0.030s	user 0.028s	sys 0.000s Metrics: {"bytes_written":1152510,"cfile_init":1,"dirs.queue_time_us":58,"dirs.run_cpu_time_us":231,"dirs.run_wall_time_us":1402,"drs_written":1,"lbm_read_time_us":36,"lbm_reads_lt_1ms":4,"lbm_write_time_us":2048,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":28}
I20260812 06:19:53.251112 12162 maintenance_manager.cc:419] P 4d06f60e9d8c4d24885d671b043411ff: Scheduling LogGCOp(c809678222cd414480fa19f663ab45f0): free 112239562 bytes of WAL
I20260812 06:19:53.251338 12095 log_reader.cc:385] T c809678222cd414480fa19f663ab45f0: removed 11 log segments from log reader
I20260812 06:19:53.251386 12095 log.cc:1079] T c809678222cd414480fa19f663ab45f0 P 4d06f60e9d8c4d24885d671b043411ff: Deleting log segment in path: /tmp/dist-test-taskujMVo5/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515588428075-11983-0/minicluster-data/ts-0-root/wals/c809678222cd414480fa19f663ab45f0/wal-000000027 (ops 131-135)
I20260812 06:19:53.251415 12095 log.cc:1079] T c809678222cd414480fa19f663ab45f0 P 4d06f60e9d8c4d24885d671b043411ff: Deleting log segment in path: /tmp/dist-test-taskujMVo5/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515588428075-11983-0/minicluster-data/ts-0-root/wals/c809678222cd414480fa19f663ab45f0/wal-000000028 (ops 136-140)
I20260812 06:19:53.251498 12095 log.cc:1079] T c809678222cd414480fa19f663ab45f0 P 4d06f60e9d8c4d24885d671b043411ff: Deleting log segment in path: /tmp/dist-test-taskujMVo5/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515588428075-11983-0/minicluster-data/ts-0-root/wals/c809678222cd414480fa19f663ab45f0/wal-000000029 (ops 141-145)
I20260812 06:19:53.251564 12095 log.cc:1079] T c809678222cd414480fa19f663ab45f0 P 4d06f60e9d8c4d24885d671b043411ff: Deleting log segment in path: /tmp/dist-test-taskujMVo5/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515588428075-11983-0/minicluster-data/ts-0-root/wals/c809678222cd414480fa19f663ab45f0/wal-000000030 (ops 146-150)
I20260812 06:19:53.251605 12095 log.cc:1079] T c809678222cd414480fa19f663ab45f0 P 4d06f60e9d8c4d24885d671b043411ff: Deleting log segment in path: /tmp/dist-test-taskujMVo5/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515588428075-11983-0/minicluster-data/ts-0-root/wals/c809678222cd414480fa19f663ab45f0/wal-000000031 (ops 151-155)
I20260812 06:19:53.251664 12095 log.cc:1079] T c809678222cd414480fa19f663ab45f0 P 4d06f60e9d8c4d24885d671b043411ff: Deleting log segment in path: /tmp/dist-test-taskujMVo5/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515588428075-11983-0/minicluster-data/ts-0-root/wals/c809678222cd414480fa19f663ab45f0/wal-000000032 (ops 156-160)
I20260812 06:19:53.251701 12095 log.cc:1079] T c809678222cd414480fa19f663ab45f0 P 4d06f60e9d8c4d24885d671b043411ff: Deleting log segment in path: /tmp/dist-test-taskujMVo5/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515588428075-11983-0/minicluster-data/ts-0-root/wals/c809678222cd414480fa19f663ab45f0/wal-000000033 (ops 161-165)
I20260812 06:19:53.251742 12095 log.cc:1079] T c809678222cd414480fa19f663ab45f0 P 4d06f60e9d8c4d24885d671b043411ff: Deleting log segment in path: /tmp/dist-test-taskujMVo5/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515588428075-11983-0/minicluster-data/ts-0-root/wals/c809678222cd414480fa19f663ab45f0/wal-000000034 (ops 166-170)
I20260812 06:19:53.251781 12095 log.cc:1079] T c809678222cd414480fa19f663ab45f0 P 4d06f60e9d8c4d24885d671b043411ff: Deleting log segment in path: /tmp/dist-test-taskujMVo5/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515588428075-11983-0/minicluster-data/ts-0-root/wals/c809678222cd414480fa19f663ab45f0/wal-000000035 (ops 171-174)
I20260812 06:19:53.251820 12095 log.cc:1079] T c809678222cd414480fa19f663ab45f0 P 4d06f60e9d8c4d24885d671b043411ff: Deleting log segment in path: /tmp/dist-test-taskujMVo5/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515588428075-11983-0/minicluster-data/ts-0-root/wals/c809678222cd414480fa19f663ab45f0/wal-000000036 (ops 175-179)
I20260812 06:19:53.251860 12095 log.cc:1079] T c809678222cd414480fa19f663ab45f0 P 4d06f60e9d8c4d24885d671b043411ff: Deleting log segment in path: /tmp/dist-test-taskujMVo5/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515588428075-11983-0/minicluster-data/ts-0-root/wals/c809678222cd414480fa19f663ab45f0/wal-000000037 (ops 180-184)
I20260812 06:19:53.275342 12095 maintenance_manager.cc:643] P 4d06f60e9d8c4d24885d671b043411ff: LogGCOp(c809678222cd414480fa19f663ab45f0) complete. Timing: real 0.024s	user 0.000s	sys 0.020s Metrics: {}
I20260812 06:19:53.275959 12162 maintenance_manager.cc:419] P 4d06f60e9d8c4d24885d671b043411ff: Scheduling FlushDeltaMemStoresOp(c809678222cd414480fa19f663ab45f0): perf score=3.181125
I20260812 06:19:53.294149 12095 maintenance_manager.cc:643] P 4d06f60e9d8c4d24885d671b043411ff: FlushDeltaMemStoresOp(c809678222cd414480fa19f663ab45f0) complete. Timing: real 0.018s	user 0.008s	sys 0.008s Metrics: {"bytes_written":4512899,"delete_count":0,"lbm_write_time_us":7116,"lbm_writes_lt_1ms":113,"reinsert_count":0,"update_count":550}
I20260812 06:19:53.294680 12162 maintenance_manager.cc:419] P 4d06f60e9d8c4d24885d671b043411ff: Scheduling FlushDeltaMemStoresOp(c809678222cd414480fa19f663ab45f0): perf score=2.188937
I20260812 06:19:53.304782 12095 maintenance_manager.cc:643] P 4d06f60e9d8c4d24885d671b043411ff: FlushDeltaMemStoresOp(c809678222cd414480fa19f663ab45f0) complete. Timing: real 0.010s	user 0.008s	sys 0.000s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3668,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:19:53.305420 12162 maintenance_manager.cc:419] P 4d06f60e9d8c4d24885d671b043411ff: Scheduling UndoDeltaBlockGCOp(c809678222cd414480fa19f663ab45f0): 448 bytes on disk
I20260812 06:19:53.305984 12095 maintenance_manager.cc:643] P 4d06f60e9d8c4d24885d671b043411ff: UndoDeltaBlockGCOp(c809678222cd414480fa19f663ab45f0) 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:19:53.307021 12162 maintenance_manager.cc:419] P 4d06f60e9d8c4d24885d671b043411ff: Scheduling MajorDeltaCompactionOp(c809678222cd414480fa19f663ab45f0): perf score=1.000000
I20260812 06:19:53.515897 12095 maintenance_manager.cc:643] P 4d06f60e9d8c4d24885d671b043411ff: MajorDeltaCompactionOp(c809678222cd414480fa19f663ab45f0) complete. Timing: real 0.209s	user 0.150s	sys 0.049s Metrics: {"cfile_cache_miss":634,"cfile_cache_miss_bytes":28877326,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":545,"lbm_read_time_us":12272,"lbm_reads_lt_1ms":674,"lbm_write_time_us":35533,"lbm_writes_lt_1ms":643,"mutex_wait_us":45,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":6528,"thread_start_us":87,"threads_started":1,"update_count":3000}
I20260812 06:19:53.516629 12162 maintenance_manager.cc:419] P 4d06f60e9d8c4d24885d671b043411ff: Scheduling FlushDeltaMemStoresOp(c809678222cd414480fa19f663ab45f0): perf score=14.095187
I20260812 06:19:53.563897 12095 maintenance_manager.cc:643] P 4d06f60e9d8c4d24885d671b043411ff: FlushDeltaMemStoresOp(c809678222cd414480fa19f663ab45f0) complete. Timing: real 0.047s	user 0.030s	sys 0.013s Metrics: {"bytes_written":16409906,"delete_count":0,"lbm_write_time_us":18711,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:53.564484 12162 maintenance_manager.cc:419] P 4d06f60e9d8c4d24885d671b043411ff: Scheduling FlushDeltaMemStoresOp(c809678222cd414480fa19f663ab45f0): perf score=2.188937
I20260812 06:19:53.576725 12095 maintenance_manager.cc:643] P 4d06f60e9d8c4d24885d671b043411ff: FlushDeltaMemStoresOp(c809678222cd414480fa19f663ab45f0) complete. Timing: real 0.012s	user 0.010s	sys 0.001s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4685,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:53.577188 12162 maintenance_manager.cc:419] P 4d06f60e9d8c4d24885d671b043411ff: Scheduling MajorDeltaCompactionOp(c809678222cd414480fa19f663ab45f0): perf score=1.000000
I20260812 06:19:53.613806 11983 heavy-update-compaction-itest.cc:229] Time spent updating: real 4.930s	user 1.831s	sys 0.138s
I20260812 06:19:53.695717 11983 heavy-update-compaction-itest.cc:265] Time spent scanning: real 0.081s	user 0.000s	sys 0.004s
I20260812 06:19:53.696415 11983 tablet_server.cc:179] TabletServer@127.11.179.193:0 shutting down...
I20260812 06:19:53.732540 12095 maintenance_manager.cc:643] P 4d06f60e9d8c4d24885d671b043411ff: MajorDeltaCompactionOp(c809678222cd414480fa19f663ab45f0) complete. Timing: real 0.155s	user 0.094s	sys 0.055s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774692,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":359,"lbm_read_time_us":9037,"lbm_reads_lt_1ms":568,"lbm_write_time_us":24622,"lbm_writes_lt_1ms":543,"mutex_wait_us":41,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":4736,"update_count":2500}
I20260812 06:19:53.733233 11983 ts_tablet_manager.cc:1507] Shutting down tablet manager...
I20260812 06:19:53.733711 11983 tablet_replica.cc:333] T c809678222cd414480fa19f663ab45f0 P 4d06f60e9d8c4d24885d671b043411ff: stopping tablet replica
I20260812 06:19:53.733953 11983 raft_consensus.cc:2243] T c809678222cd414480fa19f663ab45f0 P 4d06f60e9d8c4d24885d671b043411ff [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:19:53.734194 11983 raft_consensus.cc:2272] T c809678222cd414480fa19f663ab45f0 P 4d06f60e9d8c4d24885d671b043411ff [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:19:53.750439 11983 tablet_server.cc:196] TabletServer@127.11.179.193:0 shutdown complete.
I20260812 06:19:53.779511 11983 master.cc:562] Master@127.11.179.254:44513 shutting down...
I20260812 06:19:53.783565 11983 raft_consensus.cc:2243] T 00000000000000000000000000000000 P bfe40359faf94ed4a61f3010c7a6f717 [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:19:53.783776 11983 raft_consensus.cc:2272] T 00000000000000000000000000000000 P bfe40359faf94ed4a61f3010c7a6f717 [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:19:53.783872 11983 tablet_replica.cc:333] T 00000000000000000000000000000000 P bfe40359faf94ed4a61f3010c7a6f717: stopping tablet replica
I20260812 06:19:53.797081 11983 master.cc:584] Master@127.11.179.254:44513 shutdown complete.
[       OK ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/0 (5444 ms)
[ RUN      ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/1
I20260812 06:19:53.883069 11983 internal_mini_cluster.cc:156] Creating distributed mini masters. Addrs: 127.11.179.254:46167
I20260812 06:19:53.883548 11983 file_cache.cc:504] Constructed file cache file cache with capacity 419430
I20260812 06:19:53.885948 11983 server_base.cc:1061] running on GCE node
W20260812 06:19:53.885990 12195 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:19:53.885908 12194 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:19:53.886077 12197 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:19:53.886317 11983 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:19:53.886363 11983 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:19:53.886408 11983 hybrid_clock.cc:648] HybridClock initialized: now 1786515593886408 us; error 0 us; skew 500 ppm
I20260812 06:19:53.887279 11983 webserver.cc:533] Webserver started at http://127.11.179.254:41267/ using document root <none> and password file <none>
I20260812 06:19:53.887409 11983 fs_manager.cc:362] Metadata directory not provided
I20260812 06:19:53.887526 11983 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:19:53.887593 11983 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:19:53.887923 11983 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskujMVo5/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515588428075-11983-0/minicluster-data/master-0-root/instance:
uuid: "6ff5322d8dc1405c90b61e7641847ef2"
format_stamp: "Formatted at 2026-08-12 06:19:53 on dist-test-slave-5k54"
I20260812 06:19:53.889376 11983 fs_manager.cc:696] Time spent creating directory manager: real 0.001s	user 0.002s	sys 0.000s
I20260812 06:19:53.890283 12203 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:19:53.890566 11983 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.001s	sys 0.000s
I20260812 06:19:53.890657 11983 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskujMVo5/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515588428075-11983-0/minicluster-data/master-0-root
uuid: "6ff5322d8dc1405c90b61e7641847ef2"
format_stamp: "Formatted at 2026-08-12 06:19:53 on dist-test-slave-5k54"
I20260812 06:19:53.890744 11983 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskujMVo5/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515588428075-11983-0/minicluster-data/master-0-root
metadata directory: /tmp/dist-test-taskujMVo5/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515588428075-11983-0/minicluster-data/master-0-root
1 data directories: /tmp/dist-test-taskujMVo5/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515588428075-11983-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:19:53.900555 11983 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:19:53.900976 11983 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:19:53.905367 11983 rpc_server.cc:307] RPC server started. Bound to: 127.11.179.254:46167
I20260812 06:19:53.907235 12262 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.11.179.254:46167 every 8 connection(s)
I20260812 06:19:53.910140 12263 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:19:53.922554 12263 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P 6ff5322d8dc1405c90b61e7641847ef2: Bootstrap starting.
I20260812 06:19:53.923367 12263 tablet_bootstrap.cc:654] T 00000000000000000000000000000000 P 6ff5322d8dc1405c90b61e7641847ef2: Neither blocks nor log segments found. Creating new log.
I20260812 06:19:53.924497 12263 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P 6ff5322d8dc1405c90b61e7641847ef2: No bootstrap required, opened a new log
I20260812 06:19:53.924875 12263 raft_consensus.cc:359] T 00000000000000000000000000000000 P 6ff5322d8dc1405c90b61e7641847ef2 [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "6ff5322d8dc1405c90b61e7641847ef2" member_type: VOTER }
I20260812 06:19:53.924960 12263 raft_consensus.cc:385] T 00000000000000000000000000000000 P 6ff5322d8dc1405c90b61e7641847ef2 [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:19:53.924983 12263 raft_consensus.cc:740] T 00000000000000000000000000000000 P 6ff5322d8dc1405c90b61e7641847ef2 [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: 6ff5322d8dc1405c90b61e7641847ef2, State: Initialized, Role: FOLLOWER
I20260812 06:19:53.925092 12263 consensus_queue.cc:260] T 00000000000000000000000000000000 P 6ff5322d8dc1405c90b61e7641847ef2 [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: "6ff5322d8dc1405c90b61e7641847ef2" member_type: VOTER }
I20260812 06:19:53.925149 12263 raft_consensus.cc:399] T 00000000000000000000000000000000 P 6ff5322d8dc1405c90b61e7641847ef2 [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:19:53.925172 12263 raft_consensus.cc:493] T 00000000000000000000000000000000 P 6ff5322d8dc1405c90b61e7641847ef2 [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:19:53.925207 12263 raft_consensus.cc:3060] T 00000000000000000000000000000000 P 6ff5322d8dc1405c90b61e7641847ef2 [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:19:53.925861 12263 raft_consensus.cc:515] T 00000000000000000000000000000000 P 6ff5322d8dc1405c90b61e7641847ef2 [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "6ff5322d8dc1405c90b61e7641847ef2" member_type: VOTER }
I20260812 06:19:53.925978 12263 leader_election.cc:304] T 00000000000000000000000000000000 P 6ff5322d8dc1405c90b61e7641847ef2 [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: 6ff5322d8dc1405c90b61e7641847ef2; no voters: 
I20260812 06:19:53.926132 12263 leader_election.cc:290] T 00000000000000000000000000000000 P 6ff5322d8dc1405c90b61e7641847ef2 [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:19:53.926267 12267 raft_consensus.cc:2804] T 00000000000000000000000000000000 P 6ff5322d8dc1405c90b61e7641847ef2 [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:19:53.926514 12267 raft_consensus.cc:697] T 00000000000000000000000000000000 P 6ff5322d8dc1405c90b61e7641847ef2 [term 1 LEADER]: Becoming Leader. State: Replica: 6ff5322d8dc1405c90b61e7641847ef2, State: Running, Role: LEADER
I20260812 06:19:53.926638 12263 sys_catalog.cc:565] T 00000000000000000000000000000000 P 6ff5322d8dc1405c90b61e7641847ef2 [sys.catalog]: configured and running, proceeding with master startup.
I20260812 06:19:53.926652 12267 consensus_queue.cc:237] T 00000000000000000000000000000000 P 6ff5322d8dc1405c90b61e7641847ef2 [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: "6ff5322d8dc1405c90b61e7641847ef2" member_type: VOTER }
I20260812 06:19:53.927147 12268 sys_catalog.cc:455] T 00000000000000000000000000000000 P 6ff5322d8dc1405c90b61e7641847ef2 [sys.catalog]: SysCatalogTable state changed. Reason: RaftConsensus started. Latest consensus state: current_term: 1 leader_uuid: "6ff5322d8dc1405c90b61e7641847ef2" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "6ff5322d8dc1405c90b61e7641847ef2" member_type: VOTER } }
I20260812 06:19:53.927197 12269 sys_catalog.cc:455] T 00000000000000000000000000000000 P 6ff5322d8dc1405c90b61e7641847ef2 [sys.catalog]: SysCatalogTable state changed. Reason: New leader 6ff5322d8dc1405c90b61e7641847ef2. Latest consensus state: current_term: 1 leader_uuid: "6ff5322d8dc1405c90b61e7641847ef2" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "6ff5322d8dc1405c90b61e7641847ef2" member_type: VOTER } }
I20260812 06:19:53.927314 12268 sys_catalog.cc:458] T 00000000000000000000000000000000 P 6ff5322d8dc1405c90b61e7641847ef2 [sys.catalog]: This master's current role is: LEADER
I20260812 06:19:53.927333 12269 sys_catalog.cc:458] T 00000000000000000000000000000000 P 6ff5322d8dc1405c90b61e7641847ef2 [sys.catalog]: This master's current role is: LEADER
I20260812 06:19:53.927906 12275 catalog_manager.cc:1511] Loading table and tablet metadata into memory...
I20260812 06:19:53.928814 12275 catalog_manager.cc:1520] Initializing Kudu cluster ID...
I20260812 06:19:53.929075 11983 internal_mini_cluster.cc:184] Waiting to initialize catalog manager on master 0
I20260812 06:19:53.930640 12275 catalog_manager.cc:1383] Generated new cluster ID: 26e00617ce7741b6a1ed011c8a4d66bc
I20260812 06:19:53.930702 12275 catalog_manager.cc:1531] Initializing Kudu internal certificate authority...
I20260812 06:19:53.950132 12275 catalog_manager.cc:1406] Generated new certificate authority record
I20260812 06:19:53.950665 12275 catalog_manager.cc:1540] Loading token signing keys...
I20260812 06:19:53.955468 12275 catalog_manager.cc:6092] T 00000000000000000000000000000000 P 6ff5322d8dc1405c90b61e7641847ef2: Generated new TSK 0
I20260812 06:19:53.955652 12275 catalog_manager.cc:1550] Initializing in-progress tserver states...
I20260812 06:19:53.961295 11983 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:19:53.963207 12293 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:19:53.963233 12290 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:19:53.963480 12291 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:19:53.963547 11983 server_base.cc:1061] running on GCE node
I20260812 06:19:53.963775 11983 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:19:53.963820 11983 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:19:53.963850 11983 hybrid_clock.cc:648] HybridClock initialized: now 1786515593963850 us; error 0 us; skew 500 ppm
I20260812 06:19:53.964751 11983 webserver.cc:533] Webserver started at http://127.11.179.193:44653/ using document root <none> and password file <none>
I20260812 06:19:53.964999 11983 fs_manager.cc:362] Metadata directory not provided
I20260812 06:19:53.965076 11983 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:19:53.965163 11983 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:19:53.965574 11983 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskujMVo5/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515588428075-11983-0/minicluster-data/ts-0-root/instance:
uuid: "45fd906423cf4970a97a978b1bc2a808"
format_stamp: "Formatted at 2026-08-12 06:19:53 on dist-test-slave-5k54"
I20260812 06:19:53.967047 11983 fs_manager.cc:696] Time spent creating directory manager: real 0.001s	user 0.002s	sys 0.000s
I20260812 06:19:53.968053 12298 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:19:53.968300 11983 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.000s	sys 0.000s
I20260812 06:19:53.968367 11983 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskujMVo5/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515588428075-11983-0/minicluster-data/ts-0-root
uuid: "45fd906423cf4970a97a978b1bc2a808"
format_stamp: "Formatted at 2026-08-12 06:19:53 on dist-test-slave-5k54"
I20260812 06:19:53.968463 11983 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskujMVo5/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515588428075-11983-0/minicluster-data/ts-0-root
metadata directory: /tmp/dist-test-taskujMVo5/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515588428075-11983-0/minicluster-data/ts-0-root
1 data directories: /tmp/dist-test-taskujMVo5/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515588428075-11983-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:19:53.975390 11983 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:19:53.975766 11983 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:19:53.976051 11983 txn_system_client.cc:432] TxnSystemClient initialization is disabled...
I20260812 06:19:53.976481 11983 ts_tablet_manager.cc:585] Loaded tablet metadata (0 total tablets, 0 live tablets)
I20260812 06:19:53.976541 11983 ts_tablet_manager.cc:531] Time spent load tablet metadata: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:19:53.976601 11983 ts_tablet_manager.cc:616] Registered 0 tablets
I20260812 06:19:53.976635 11983 ts_tablet_manager.cc:595] Time spent register tablets: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:19:53.981012 11983 rpc_server.cc:307] RPC server started. Bound to: 127.11.179.193:37459
I20260812 06:19:53.981038 12367 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.11.179.193:37459 every 8 connection(s)
I20260812 06:19:53.988714 12368 heartbeater.cc:344] Connected to a master server at 127.11.179.254:46167
I20260812 06:19:53.988832 12368 heartbeater.cc:461] Registering TS with master...
I20260812 06:19:53.989096 12368 heartbeater.cc:507] Master 127.11.179.254:46167 requested a full tablet report, sending...
I20260812 06:19:53.989735 12220 ts_manager.cc:194] Registered new tserver with Master: 45fd906423cf4970a97a978b1bc2a808 (127.11.179.193:37459)
I20260812 06:19:53.990330 11983 internal_mini_cluster.cc:371] 1 TS(s) registered with all masters after 0.008914457s
I20260812 06:19:53.990483 12220 master_service.cc:502] Signed X509 certificate for tserver {username='slave'} at 127.0.0.1:51288
I20260812 06:19:53.997108 12220 catalog_manager.cc:2283] Servicing CreateTable request from {username='slave'} at 127.0.0.1:51300:
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:19:54.005815 12329 tablet_service.cc:1511] Processing CreateTablet for tablet 5d47842c233543b2a851aefc24632dc8 (DEFAULT_TABLE table=heavy-update-compaction-test [id=a245d872c2c942efbd866dc2683c5c38]), partition=
I20260812 06:19:54.006047 12329 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet 5d47842c233543b2a851aefc24632dc8. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:19:54.007972 12380 tablet_bootstrap.cc:492] T 5d47842c233543b2a851aefc24632dc8 P 45fd906423cf4970a97a978b1bc2a808: Bootstrap starting.
I20260812 06:19:54.008876 12380 tablet_bootstrap.cc:654] T 5d47842c233543b2a851aefc24632dc8 P 45fd906423cf4970a97a978b1bc2a808: Neither blocks nor log segments found. Creating new log.
I20260812 06:19:54.009912 12380 tablet_bootstrap.cc:492] T 5d47842c233543b2a851aefc24632dc8 P 45fd906423cf4970a97a978b1bc2a808: No bootstrap required, opened a new log
I20260812 06:19:54.009987 12380 ts_tablet_manager.cc:1403] T 5d47842c233543b2a851aefc24632dc8 P 45fd906423cf4970a97a978b1bc2a808: Time spent bootstrapping tablet: real 0.002s	user 0.001s	sys 0.000s
I20260812 06:19:54.010433 12380 raft_consensus.cc:359] T 5d47842c233543b2a851aefc24632dc8 P 45fd906423cf4970a97a978b1bc2a808 [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "45fd906423cf4970a97a978b1bc2a808" member_type: VOTER last_known_addr { host: "127.11.179.193" port: 37459 } }
I20260812 06:19:54.010527 12380 raft_consensus.cc:385] T 5d47842c233543b2a851aefc24632dc8 P 45fd906423cf4970a97a978b1bc2a808 [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:19:54.010584 12380 raft_consensus.cc:740] T 5d47842c233543b2a851aefc24632dc8 P 45fd906423cf4970a97a978b1bc2a808 [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: 45fd906423cf4970a97a978b1bc2a808, State: Initialized, Role: FOLLOWER
I20260812 06:19:54.010736 12380 consensus_queue.cc:260] T 5d47842c233543b2a851aefc24632dc8 P 45fd906423cf4970a97a978b1bc2a808 [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: "45fd906423cf4970a97a978b1bc2a808" member_type: VOTER last_known_addr { host: "127.11.179.193" port: 37459 } }
I20260812 06:19:54.010830 12380 raft_consensus.cc:399] T 5d47842c233543b2a851aefc24632dc8 P 45fd906423cf4970a97a978b1bc2a808 [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:19:54.010856 12380 raft_consensus.cc:493] T 5d47842c233543b2a851aefc24632dc8 P 45fd906423cf4970a97a978b1bc2a808 [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:19:54.010921 12380 raft_consensus.cc:3060] T 5d47842c233543b2a851aefc24632dc8 P 45fd906423cf4970a97a978b1bc2a808 [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:19:54.011714 12380 raft_consensus.cc:515] T 5d47842c233543b2a851aefc24632dc8 P 45fd906423cf4970a97a978b1bc2a808 [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "45fd906423cf4970a97a978b1bc2a808" member_type: VOTER last_known_addr { host: "127.11.179.193" port: 37459 } }
I20260812 06:19:54.011831 12380 leader_election.cc:304] T 5d47842c233543b2a851aefc24632dc8 P 45fd906423cf4970a97a978b1bc2a808 [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: 45fd906423cf4970a97a978b1bc2a808; no voters: 
I20260812 06:19:54.012076 12380 leader_election.cc:290] T 5d47842c233543b2a851aefc24632dc8 P 45fd906423cf4970a97a978b1bc2a808 [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:19:54.012221 12383 raft_consensus.cc:2804] T 5d47842c233543b2a851aefc24632dc8 P 45fd906423cf4970a97a978b1bc2a808 [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:19:54.012385 12380 ts_tablet_manager.cc:1434] T 5d47842c233543b2a851aefc24632dc8 P 45fd906423cf4970a97a978b1bc2a808: Time spent starting tablet: real 0.002s	user 0.003s	sys 0.000s
I20260812 06:19:54.012399 12368 heartbeater.cc:499] Master 127.11.179.254:46167 was elected leader, sending a full tablet report...
I20260812 06:19:54.012450 12383 raft_consensus.cc:697] T 5d47842c233543b2a851aefc24632dc8 P 45fd906423cf4970a97a978b1bc2a808 [term 1 LEADER]: Becoming Leader. State: Replica: 45fd906423cf4970a97a978b1bc2a808, State: Running, Role: LEADER
I20260812 06:19:54.012615 12383 consensus_queue.cc:237] T 5d47842c233543b2a851aefc24632dc8 P 45fd906423cf4970a97a978b1bc2a808 [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: "45fd906423cf4970a97a978b1bc2a808" member_type: VOTER last_known_addr { host: "127.11.179.193" port: 37459 } }
I20260812 06:19:54.013906 12220 catalog_manager.cc:5719] T 5d47842c233543b2a851aefc24632dc8 P 45fd906423cf4970a97a978b1bc2a808 reported cstate change: term changed from 0 to 1, leader changed from <none> to 45fd906423cf4970a97a978b1bc2a808 (127.11.179.193). New cstate: current_term: 1 leader_uuid: "45fd906423cf4970a97a978b1bc2a808" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "45fd906423cf4970a97a978b1bc2a808" member_type: VOTER last_known_addr { host: "127.11.179.193" port: 37459 } health_report { overall_health: HEALTHY } } }
I20260812 06:19:54.072677 11983 heavy-update-compaction-itest.cc:215] Time spent inserting: real 0.051s	user 0.019s	sys 0.003s
I20260812 06:19:54.231848 12369 maintenance_manager.cc:419] P 45fd906423cf4970a97a978b1bc2a808: Scheduling FlushMRSOp(5d47842c233543b2a851aefc24632dc8): perf score=23.023690
I20260812 06:19:54.387347 12303 maintenance_manager.cc:643] P 45fd906423cf4970a97a978b1bc2a808: FlushMRSOp(5d47842c233543b2a851aefc24632dc8) complete. Timing: real 0.155s	user 0.119s	sys 0.032s Metrics: {"bytes_written":12307491,"cfile_init":1,"delete_count":0,"dirs.queue_time_us":64,"dirs.run_cpu_time_us":227,"dirs.run_wall_time_us":896,"drs_written":1,"lbm_read_time_us":38,"lbm_reads_lt_1ms":4,"lbm_write_time_us":42298,"lbm_writes_lt_1ms":857,"peak_mem_usage":0,"reinsert_count":0,"rows_written":105,"update_count":1500}
I20260812 06:19:54.388118 12369 maintenance_manager.cc:419] P 45fd906423cf4970a97a978b1bc2a808: Scheduling LogGCOp(5d47842c233543b2a851aefc24632dc8): free 20743831 bytes of WAL
I20260812 06:19:54.388350 12303 log_reader.cc:385] T 5d47842c233543b2a851aefc24632dc8: removed 2 log segments from log reader
I20260812 06:19:54.388419 12303 log.cc:1079] T 5d47842c233543b2a851aefc24632dc8 P 45fd906423cf4970a97a978b1bc2a808: Deleting log segment in path: /tmp/dist-test-taskujMVo5/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515588428075-11983-0/minicluster-data/ts-0-root/wals/5d47842c233543b2a851aefc24632dc8/wal-000000001 (ops 1-6)
I20260812 06:19:54.388473 12303 log.cc:1079] T 5d47842c233543b2a851aefc24632dc8 P 45fd906423cf4970a97a978b1bc2a808: Deleting log segment in path: /tmp/dist-test-taskujMVo5/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515588428075-11983-0/minicluster-data/ts-0-root/wals/5d47842c233543b2a851aefc24632dc8/wal-000000002 (ops 7-11)
I20260812 06:19:54.392820 12303 maintenance_manager.cc:643] P 45fd906423cf4970a97a978b1bc2a808: LogGCOp(5d47842c233543b2a851aefc24632dc8) complete. Timing: real 0.005s	user 0.000s	sys 0.003s Metrics: {}
I20260812 06:19:54.393338 12369 maintenance_manager.cc:419] P 45fd906423cf4970a97a978b1bc2a808: Scheduling UndoDeltaBlockGCOp(5d47842c233543b2a851aefc24632dc8): 20513816 bytes on disk
I20260812 06:19:54.394081 12303 maintenance_manager.cc:643] P 45fd906423cf4970a97a978b1bc2a808: UndoDeltaBlockGCOp(5d47842c233543b2a851aefc24632dc8) complete. Timing: real 0.001s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":106,"lbm_reads_lt_1ms":4}
I20260812 06:19:54.394716 12369 maintenance_manager.cc:419] P 45fd906423cf4970a97a978b1bc2a808: Scheduling FlushDeltaMemStoresOp(5d47842c233543b2a851aefc24632dc8): perf score=2.188937
I20260812 06:19:54.422891 12303 maintenance_manager.cc:643] P 45fd906423cf4970a97a978b1bc2a808: FlushDeltaMemStoresOp(5d47842c233543b2a851aefc24632dc8) complete. Timing: real 0.028s	user 0.011s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6558,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:54.423354 12369 maintenance_manager.cc:419] P 45fd906423cf4970a97a978b1bc2a808: Scheduling FlushDeltaMemStoresOp(5d47842c233543b2a851aefc24632dc8): perf score=2.188937
I20260812 06:19:54.434264 12303 maintenance_manager.cc:643] P 45fd906423cf4970a97a978b1bc2a808: FlushDeltaMemStoresOp(5d47842c233543b2a851aefc24632dc8) complete. Timing: real 0.011s	user 0.001s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4318,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:54.434691 12369 maintenance_manager.cc:419] P 45fd906423cf4970a97a978b1bc2a808: Scheduling MajorDeltaCompactionOp(5d47842c233543b2a851aefc24632dc8): perf score=1.000000
I20260812 06:19:54.610905 12303 maintenance_manager.cc:643] P 45fd906423cf4970a97a978b1bc2a808: MajorDeltaCompactionOp(5d47842c233543b2a851aefc24632dc8) complete. Timing: real 0.176s	user 0.128s	sys 0.048s Metrics: {"cfile_cache_miss":533,"cfile_cache_miss_bytes":24815804,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":557,"lbm_read_time_us":12122,"lbm_reads_lt_1ms":569,"lbm_write_time_us":28066,"lbm_writes_lt_1ms":543,"peak_mem_usage":63115900,"reinsert_count":0,"thread_start_us":321,"threads_started":5,"update_count":2500}
I20260812 06:19:54.611601 12369 maintenance_manager.cc:419] P 45fd906423cf4970a97a978b1bc2a808: Scheduling FlushDeltaMemStoresOp(5d47842c233543b2a851aefc24632dc8): perf score=14.095187
I20260812 06:19:54.672333 12303 maintenance_manager.cc:643] P 45fd906423cf4970a97a978b1bc2a808: FlushDeltaMemStoresOp(5d47842c233543b2a851aefc24632dc8) complete. Timing: real 0.061s	user 0.040s	sys 0.016s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":21083,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:54.672806 12369 maintenance_manager.cc:419] P 45fd906423cf4970a97a978b1bc2a808: Scheduling FlushDeltaMemStoresOp(5d47842c233543b2a851aefc24632dc8): perf score=2.188937
I20260812 06:19:54.683216 12303 maintenance_manager.cc:643] P 45fd906423cf4970a97a978b1bc2a808: FlushDeltaMemStoresOp(5d47842c233543b2a851aefc24632dc8) complete. Timing: real 0.010s	user 0.009s	sys 0.000s 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:54.683706 12369 maintenance_manager.cc:419] P 45fd906423cf4970a97a978b1bc2a808: Scheduling MajorDeltaCompactionOp(5d47842c233543b2a851aefc24632dc8): perf score=1.000000
I20260812 06:19:54.874408 12303 maintenance_manager.cc:643] P 45fd906423cf4970a97a978b1bc2a808: MajorDeltaCompactionOp(5d47842c233543b2a851aefc24632dc8) complete. Timing: real 0.191s	user 0.156s	sys 0.028s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24815683,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":413,"lbm_read_time_us":13022,"lbm_reads_lt_1ms":572,"lbm_write_time_us":30504,"lbm_writes_lt_1ms":543,"mutex_wait_us":108,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":416128,"update_count":2500}
I20260812 06:19:54.875126 12369 maintenance_manager.cc:419] P 45fd906423cf4970a97a978b1bc2a808: Scheduling FlushDeltaMemStoresOp(5d47842c233543b2a851aefc24632dc8): perf score=11.118625
I20260812 06:19:54.905838 12303 maintenance_manager.cc:643] P 45fd906423cf4970a97a978b1bc2a808: FlushDeltaMemStoresOp(5d47842c233543b2a851aefc24632dc8) complete. Timing: real 0.030s	user 0.020s	sys 0.008s Metrics: {"bytes_written":12717735,"delete_count":0,"lbm_write_time_us":12775,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:19:54.906348 12369 maintenance_manager.cc:419] P 45fd906423cf4970a97a978b1bc2a808: Scheduling FlushDeltaMemStoresOp(5d47842c233543b2a851aefc24632dc8): perf score=2.188937
I20260812 06:19:54.921639 12303 maintenance_manager.cc:643] P 45fd906423cf4970a97a978b1bc2a808: FlushDeltaMemStoresOp(5d47842c233543b2a851aefc24632dc8) complete. Timing: real 0.015s	user 0.012s	sys 0.000s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":5408,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:19:54.922083 12369 maintenance_manager.cc:419] P 45fd906423cf4970a97a978b1bc2a808: Scheduling MajorDeltaCompactionOp(5d47842c233543b2a851aefc24632dc8): perf score=1.000000
I20260812 06:19:55.044796 12303 maintenance_manager.cc:643] P 45fd906423cf4970a97a978b1bc2a808: MajorDeltaCompactionOp(5d47842c233543b2a851aefc24632dc8) complete. Timing: real 0.123s	user 0.086s	sys 0.036s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20713263,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":173,"lbm_read_time_us":7199,"lbm_reads_lt_1ms":464,"lbm_write_time_us":24169,"lbm_writes_lt_1ms":443,"mutex_wait_us":47,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":4736,"update_count":2000}
I20260812 06:19:55.045467 12369 maintenance_manager.cc:419] P 45fd906423cf4970a97a978b1bc2a808: Scheduling FlushDeltaMemStoresOp(5d47842c233543b2a851aefc24632dc8): perf score=10.126437
I20260812 06:19:55.081004 12303 maintenance_manager.cc:643] P 45fd906423cf4970a97a978b1bc2a808: FlushDeltaMemStoresOp(5d47842c233543b2a851aefc24632dc8) complete. Timing: real 0.035s	user 0.026s	sys 0.008s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":15071,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:19:55.081575 12369 maintenance_manager.cc:419] P 45fd906423cf4970a97a978b1bc2a808: Scheduling FlushDeltaMemStoresOp(5d47842c233543b2a851aefc24632dc8): perf score=2.188937
I20260812 06:19:55.097348 12303 maintenance_manager.cc:643] P 45fd906423cf4970a97a978b1bc2a808: FlushDeltaMemStoresOp(5d47842c233543b2a851aefc24632dc8) complete. Timing: real 0.016s	user 0.001s	sys 0.012s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5990,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:55.097847 12369 maintenance_manager.cc:419] P 45fd906423cf4970a97a978b1bc2a808: Scheduling MajorDeltaCompactionOp(5d47842c233543b2a851aefc24632dc8): perf score=1.000000
I20260812 06:19:55.227517 12303 maintenance_manager.cc:643] P 45fd906423cf4970a97a978b1bc2a808: MajorDeltaCompactionOp(5d47842c233543b2a851aefc24632dc8) complete. Timing: real 0.129s	user 0.097s	sys 0.032s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20713272,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":284,"lbm_read_time_us":7769,"lbm_reads_lt_1ms":464,"lbm_write_time_us":25117,"lbm_writes_lt_1ms":443,"mutex_wait_us":59,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":9984,"update_count":2000}
I20260812 06:19:55.228261 12369 maintenance_manager.cc:419] P 45fd906423cf4970a97a978b1bc2a808: Scheduling FlushDeltaMemStoresOp(5d47842c233543b2a851aefc24632dc8): perf score=10.126437
I20260812 06:19:55.270874 12303 maintenance_manager.cc:643] P 45fd906423cf4970a97a978b1bc2a808: FlushDeltaMemStoresOp(5d47842c233543b2a851aefc24632dc8) complete. Timing: real 0.042s	user 0.021s	sys 0.012s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":15846,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:19:55.271337 12369 maintenance_manager.cc:419] P 45fd906423cf4970a97a978b1bc2a808: Scheduling FlushDeltaMemStoresOp(5d47842c233543b2a851aefc24632dc8): perf score=2.188937
I20260812 06:19:55.281654 12303 maintenance_manager.cc:643] P 45fd906423cf4970a97a978b1bc2a808: FlushDeltaMemStoresOp(5d47842c233543b2a851aefc24632dc8) complete. Timing: real 0.010s	user 0.004s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3969,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:55.282395 12369 maintenance_manager.cc:419] P 45fd906423cf4970a97a978b1bc2a808: Scheduling MajorDeltaCompactionOp(5d47842c233543b2a851aefc24632dc8): perf score=1.000000
I20260812 06:19:55.407369 12303 maintenance_manager.cc:643] P 45fd906423cf4970a97a978b1bc2a808: MajorDeltaCompactionOp(5d47842c233543b2a851aefc24632dc8) complete. Timing: real 0.125s	user 0.087s	sys 0.036s 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":169,"lbm_read_time_us":8411,"lbm_reads_lt_1ms":472,"lbm_write_time_us":24907,"lbm_writes_lt_1ms":443,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":17280,"update_count":2000}
I20260812 06:19:55.407930 12369 maintenance_manager.cc:419] P 45fd906423cf4970a97a978b1bc2a808: Scheduling FlushDeltaMemStoresOp(5d47842c233543b2a851aefc24632dc8): perf score=10.126437
I20260812 06:19:55.457063 12303 maintenance_manager.cc:643] P 45fd906423cf4970a97a978b1bc2a808: FlushDeltaMemStoresOp(5d47842c233543b2a851aefc24632dc8) complete. Timing: real 0.049s	user 0.026s	sys 0.019s Metrics: {"bytes_written":12307492,"delete_count":0,"lbm_write_time_us":16801,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:19:55.457645 12369 maintenance_manager.cc:419] P 45fd906423cf4970a97a978b1bc2a808: Scheduling FlushDeltaMemStoresOp(5d47842c233543b2a851aefc24632dc8): perf score=2.188937
I20260812 06:19:55.468374 12303 maintenance_manager.cc:643] P 45fd906423cf4970a97a978b1bc2a808: FlushDeltaMemStoresOp(5d47842c233543b2a851aefc24632dc8) complete. Timing: real 0.011s	user 0.005s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4206,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:55.468816 12369 maintenance_manager.cc:419] P 45fd906423cf4970a97a978b1bc2a808: Scheduling MajorDeltaCompactionOp(5d47842c233543b2a851aefc24632dc8): perf score=1.000000
I20260812 06:19:55.618263 12303 maintenance_manager.cc:643] P 45fd906423cf4970a97a978b1bc2a808: MajorDeltaCompactionOp(5d47842c233543b2a851aefc24632dc8) complete. Timing: real 0.149s	user 0.113s	sys 0.036s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20713274,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":954,"lbm_read_time_us":11167,"lbm_reads_lt_1ms":472,"lbm_write_time_us":23793,"lbm_writes_lt_1ms":443,"mutex_wait_us":263,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":896,"update_count":2000}
I20260812 06:19:55.619132 12369 maintenance_manager.cc:419] P 45fd906423cf4970a97a978b1bc2a808: Scheduling FlushDeltaMemStoresOp(5d47842c233543b2a851aefc24632dc8): perf score=10.126437
I20260812 06:19:55.651576 12303 maintenance_manager.cc:643] P 45fd906423cf4970a97a978b1bc2a808: FlushDeltaMemStoresOp(5d47842c233543b2a851aefc24632dc8) complete. Timing: real 0.032s	user 0.021s	sys 0.011s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":13891,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:19:55.652053 12369 maintenance_manager.cc:419] P 45fd906423cf4970a97a978b1bc2a808: Scheduling FlushDeltaMemStoresOp(5d47842c233543b2a851aefc24632dc8): perf score=2.188937
I20260812 06:19:55.663203 12303 maintenance_manager.cc:643] P 45fd906423cf4970a97a978b1bc2a808: FlushDeltaMemStoresOp(5d47842c233543b2a851aefc24632dc8) complete. Timing: real 0.011s	user 0.001s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4144,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:55.663887 12369 maintenance_manager.cc:419] P 45fd906423cf4970a97a978b1bc2a808: Scheduling FlushMRSOp(5d47842c233543b2a851aefc24632dc8): perf score=1.000000
I20260812 06:19:55.699613 12303 maintenance_manager.cc:643] P 45fd906423cf4970a97a978b1bc2a808: FlushMRSOp(5d47842c233543b2a851aefc24632dc8) complete. Timing: real 0.036s	user 0.034s	sys 0.002s Metrics: {"bytes_written":1234473,"cfile_init":1,"dirs.queue_time_us":65,"dirs.run_cpu_time_us":243,"dirs.run_wall_time_us":1400,"drs_written":1,"lbm_read_time_us":39,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1562,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":30}
I20260812 06:19:55.700368 12369 maintenance_manager.cc:419] P 45fd906423cf4970a97a978b1bc2a808: Scheduling LogGCOp(5d47842c233543b2a851aefc24632dc8): free 124710337 bytes of WAL
I20260812 06:19:55.700637 12303 log_reader.cc:385] T 5d47842c233543b2a851aefc24632dc8: removed 12 log segments from log reader
I20260812 06:19:55.700709 12303 log.cc:1079] T 5d47842c233543b2a851aefc24632dc8 P 45fd906423cf4970a97a978b1bc2a808: Deleting log segment in path: /tmp/dist-test-taskujMVo5/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515588428075-11983-0/minicluster-data/ts-0-root/wals/5d47842c233543b2a851aefc24632dc8/wal-000000003 (ops 12-16)
I20260812 06:19:55.700766 12303 log.cc:1079] T 5d47842c233543b2a851aefc24632dc8 P 45fd906423cf4970a97a978b1bc2a808: Deleting log segment in path: /tmp/dist-test-taskujMVo5/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515588428075-11983-0/minicluster-data/ts-0-root/wals/5d47842c233543b2a851aefc24632dc8/wal-000000004 (ops 17-21)
I20260812 06:19:55.700801 12303 log.cc:1079] T 5d47842c233543b2a851aefc24632dc8 P 45fd906423cf4970a97a978b1bc2a808: Deleting log segment in path: /tmp/dist-test-taskujMVo5/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515588428075-11983-0/minicluster-data/ts-0-root/wals/5d47842c233543b2a851aefc24632dc8/wal-000000005 (ops 22-26)
I20260812 06:19:55.700836 12303 log.cc:1079] T 5d47842c233543b2a851aefc24632dc8 P 45fd906423cf4970a97a978b1bc2a808: Deleting log segment in path: /tmp/dist-test-taskujMVo5/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515588428075-11983-0/minicluster-data/ts-0-root/wals/5d47842c233543b2a851aefc24632dc8/wal-000000006 (ops 27-31)
I20260812 06:19:55.700874 12303 log.cc:1079] T 5d47842c233543b2a851aefc24632dc8 P 45fd906423cf4970a97a978b1bc2a808: Deleting log segment in path: /tmp/dist-test-taskujMVo5/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515588428075-11983-0/minicluster-data/ts-0-root/wals/5d47842c233543b2a851aefc24632dc8/wal-000000007 (ops 32-36)
I20260812 06:19:55.700914 12303 log.cc:1079] T 5d47842c233543b2a851aefc24632dc8 P 45fd906423cf4970a97a978b1bc2a808: Deleting log segment in path: /tmp/dist-test-taskujMVo5/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515588428075-11983-0/minicluster-data/ts-0-root/wals/5d47842c233543b2a851aefc24632dc8/wal-000000008 (ops 37-41)
I20260812 06:19:55.700953 12303 log.cc:1079] T 5d47842c233543b2a851aefc24632dc8 P 45fd906423cf4970a97a978b1bc2a808: Deleting log segment in path: /tmp/dist-test-taskujMVo5/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515588428075-11983-0/minicluster-data/ts-0-root/wals/5d47842c233543b2a851aefc24632dc8/wal-000000009 (ops 42-46)
I20260812 06:19:55.700991 12303 log.cc:1079] T 5d47842c233543b2a851aefc24632dc8 P 45fd906423cf4970a97a978b1bc2a808: Deleting log segment in path: /tmp/dist-test-taskujMVo5/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515588428075-11983-0/minicluster-data/ts-0-root/wals/5d47842c233543b2a851aefc24632dc8/wal-000000010 (ops 47-51)
I20260812 06:19:55.701031 12303 log.cc:1079] T 5d47842c233543b2a851aefc24632dc8 P 45fd906423cf4970a97a978b1bc2a808: Deleting log segment in path: /tmp/dist-test-taskujMVo5/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515588428075-11983-0/minicluster-data/ts-0-root/wals/5d47842c233543b2a851aefc24632dc8/wal-000000011 (ops 52-56)
I20260812 06:19:55.701069 12303 log.cc:1079] T 5d47842c233543b2a851aefc24632dc8 P 45fd906423cf4970a97a978b1bc2a808: Deleting log segment in path: /tmp/dist-test-taskujMVo5/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515588428075-11983-0/minicluster-data/ts-0-root/wals/5d47842c233543b2a851aefc24632dc8/wal-000000012 (ops 57-61)
I20260812 06:19:55.701108 12303 log.cc:1079] T 5d47842c233543b2a851aefc24632dc8 P 45fd906423cf4970a97a978b1bc2a808: Deleting log segment in path: /tmp/dist-test-taskujMVo5/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515588428075-11983-0/minicluster-data/ts-0-root/wals/5d47842c233543b2a851aefc24632dc8/wal-000000013 (ops 62-66)
I20260812 06:19:55.701145 12303 log.cc:1079] T 5d47842c233543b2a851aefc24632dc8 P 45fd906423cf4970a97a978b1bc2a808: Deleting log segment in path: /tmp/dist-test-taskujMVo5/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515588428075-11983-0/minicluster-data/ts-0-root/wals/5d47842c233543b2a851aefc24632dc8/wal-000000014 (ops 67-71)
I20260812 06:19:55.727866 12303 maintenance_manager.cc:643] P 45fd906423cf4970a97a978b1bc2a808: LogGCOp(5d47842c233543b2a851aefc24632dc8) complete. Timing: real 0.027s	user 0.000s	sys 0.027s Metrics: {}
I20260812 06:19:55.728319 12369 maintenance_manager.cc:419] P 45fd906423cf4970a97a978b1bc2a808: Scheduling FlushDeltaMemStoresOp(5d47842c233543b2a851aefc24632dc8): perf score=5.165500
I20260812 06:19:55.751390 12303 maintenance_manager.cc:643] P 45fd906423cf4970a97a978b1bc2a808: FlushDeltaMemStoresOp(5d47842c233543b2a851aefc24632dc8) complete. Timing: real 0.023s	user 0.011s	sys 0.008s Metrics: {"bytes_written":6687183,"delete_count":0,"lbm_write_time_us":6476,"lbm_writes_lt_1ms":166,"reinsert_count":0,"update_count":815}
I20260812 06:19:55.751972 12369 maintenance_manager.cc:419] P 45fd906423cf4970a97a978b1bc2a808: Scheduling FlushDeltaMemStoresOp(5d47842c233543b2a851aefc24632dc8): perf score=1.000000
I20260812 06:19:55.758301 12303 maintenance_manager.cc:643] P 45fd906423cf4970a97a978b1bc2a808: FlushDeltaMemStoresOp(5d47842c233543b2a851aefc24632dc8) complete. Timing: real 0.006s	user 0.001s	sys 0.004s Metrics: {"bytes_written":1518077,"delete_count":0,"lbm_write_time_us":1819,"lbm_writes_lt_1ms":40,"reinsert_count":0,"update_count":185}
I20260812 06:19:55.763881 12369 maintenance_manager.cc:419] P 45fd906423cf4970a97a978b1bc2a808: Scheduling MajorDeltaCompactionOp(5d47842c233543b2a851aefc24632dc8): perf score=1.000000
I20260812 06:19:55.970945 12303 maintenance_manager.cc:643] P 45fd906423cf4970a97a978b1bc2a808: MajorDeltaCompactionOp(5d47842c233543b2a851aefc24632dc8) complete. Timing: real 0.207s	user 0.158s	sys 0.049s Metrics: {"cfile_cache_miss":634,"cfile_cache_miss_bytes":28918271,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":1128,"lbm_read_time_us":13797,"lbm_reads_lt_1ms":666,"lbm_write_time_us":35721,"lbm_writes_lt_1ms":643,"mutex_wait_us":22,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":14464,"thread_start_us":80,"threads_started":1,"update_count":3000}
I20260812 06:19:55.971771 12369 maintenance_manager.cc:419] P 45fd906423cf4970a97a978b1bc2a808: Scheduling FlushDeltaMemStoresOp(5d47842c233543b2a851aefc24632dc8): perf score=14.095187
I20260812 06:19:56.032742 12303 maintenance_manager.cc:643] P 45fd906423cf4970a97a978b1bc2a808: FlushDeltaMemStoresOp(5d47842c233543b2a851aefc24632dc8) complete. Timing: real 0.061s	user 0.026s	sys 0.034s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":21776,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:56.033370 12369 maintenance_manager.cc:419] P 45fd906423cf4970a97a978b1bc2a808: Scheduling FlushDeltaMemStoresOp(5d47842c233543b2a851aefc24632dc8): perf score=2.188937
I20260812 06:19:56.050616 12303 maintenance_manager.cc:643] P 45fd906423cf4970a97a978b1bc2a808: FlushDeltaMemStoresOp(5d47842c233543b2a851aefc24632dc8) complete. Timing: real 0.017s	user 0.002s	sys 0.013s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":6425,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:56.051220 12369 maintenance_manager.cc:419] P 45fd906423cf4970a97a978b1bc2a808: Scheduling UndoDeltaBlockGCOp(5d47842c233543b2a851aefc24632dc8): 472 bytes on disk
I20260812 06:19:56.051833 12303 maintenance_manager.cc:643] P 45fd906423cf4970a97a978b1bc2a808: UndoDeltaBlockGCOp(5d47842c233543b2a851aefc24632dc8) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":97,"lbm_reads_lt_1ms":4}
I20260812 06:19:56.052330 12369 maintenance_manager.cc:419] P 45fd906423cf4970a97a978b1bc2a808: Scheduling MajorDeltaCompactionOp(5d47842c233543b2a851aefc24632dc8): perf score=1.000000
I20260812 06:19:56.231586 12303 maintenance_manager.cc:643] P 45fd906423cf4970a97a978b1bc2a808: MajorDeltaCompactionOp(5d47842c233543b2a851aefc24632dc8) complete. Timing: real 0.179s	user 0.119s	sys 0.053s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24815683,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":1288,"lbm_read_time_us":12077,"lbm_reads_lt_1ms":572,"lbm_write_time_us":27035,"lbm_writes_lt_1ms":543,"mutex_wait_us":320,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":14464,"update_count":2500}
I20260812 06:19:56.232087 12369 maintenance_manager.cc:419] P 45fd906423cf4970a97a978b1bc2a808: Scheduling FlushDeltaMemStoresOp(5d47842c233543b2a851aefc24632dc8): perf score=14.095187
I20260812 06:19:56.281442 12303 maintenance_manager.cc:643] P 45fd906423cf4970a97a978b1bc2a808: FlushDeltaMemStoresOp(5d47842c233543b2a851aefc24632dc8) complete. Timing: real 0.049s	user 0.034s	sys 0.004s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":17734,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:56.281957 12369 maintenance_manager.cc:419] P 45fd906423cf4970a97a978b1bc2a808: Scheduling FlushDeltaMemStoresOp(5d47842c233543b2a851aefc24632dc8): perf score=2.188937
I20260812 06:19:56.293421 12303 maintenance_manager.cc:643] P 45fd906423cf4970a97a978b1bc2a808: FlushDeltaMemStoresOp(5d47842c233543b2a851aefc24632dc8) complete. Timing: real 0.011s	user 0.009s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4102,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:56.294029 12369 maintenance_manager.cc:419] P 45fd906423cf4970a97a978b1bc2a808: Scheduling MajorDeltaCompactionOp(5d47842c233543b2a851aefc24632dc8): perf score=1.000000
I20260812 06:19:56.471297 12303 maintenance_manager.cc:643] P 45fd906423cf4970a97a978b1bc2a808: MajorDeltaCompactionOp(5d47842c233543b2a851aefc24632dc8) complete. Timing: real 0.177s	user 0.120s	sys 0.053s 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":434,"lbm_read_time_us":9135,"lbm_reads_lt_1ms":572,"lbm_write_time_us":29269,"lbm_writes_lt_1ms":543,"mutex_wait_us":99,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":8320,"update_count":2500}
I20260812 06:19:56.471973 12369 maintenance_manager.cc:419] P 45fd906423cf4970a97a978b1bc2a808: Scheduling FlushDeltaMemStoresOp(5d47842c233543b2a851aefc24632dc8): perf score=14.095187
I20260812 06:19:56.525677 12303 maintenance_manager.cc:643] P 45fd906423cf4970a97a978b1bc2a808: FlushDeltaMemStoresOp(5d47842c233543b2a851aefc24632dc8) complete. Timing: real 0.054s	user 0.024s	sys 0.020s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":20224,"lbm_writes_lt_1ms":403,"reinsert_count":0,"spinlock_wait_cycles":1408,"update_count":2000}
I20260812 06:19:56.526226 12369 maintenance_manager.cc:419] P 45fd906423cf4970a97a978b1bc2a808: Scheduling FlushDeltaMemStoresOp(5d47842c233543b2a851aefc24632dc8): perf score=2.188937
I20260812 06:19:56.538048 12303 maintenance_manager.cc:643] P 45fd906423cf4970a97a978b1bc2a808: FlushDeltaMemStoresOp(5d47842c233543b2a851aefc24632dc8) complete. Timing: real 0.012s	user 0.005s	sys 0.004s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4251,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:56.538555 12369 maintenance_manager.cc:419] P 45fd906423cf4970a97a978b1bc2a808: Scheduling MajorDeltaCompactionOp(5d47842c233543b2a851aefc24632dc8): perf score=1.000000
I20260812 06:19:56.701267 12303 maintenance_manager.cc:643] P 45fd906423cf4970a97a978b1bc2a808: MajorDeltaCompactionOp(5d47842c233543b2a851aefc24632dc8) complete. Timing: real 0.163s	user 0.107s	sys 0.050s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24815683,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":950,"lbm_read_time_us":9997,"lbm_reads_lt_1ms":572,"lbm_write_time_us":30322,"lbm_writes_lt_1ms":543,"mutex_wait_us":21,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":11520,"update_count":2500}
I20260812 06:19:56.701963 12369 maintenance_manager.cc:419] P 45fd906423cf4970a97a978b1bc2a808: Scheduling FlushDeltaMemStoresOp(5d47842c233543b2a851aefc24632dc8): perf score=14.095187
I20260812 06:19:56.747815 12303 maintenance_manager.cc:643] P 45fd906423cf4970a97a978b1bc2a808: FlushDeltaMemStoresOp(5d47842c233543b2a851aefc24632dc8) complete. Timing: real 0.046s	user 0.032s	sys 0.013s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":19205,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:56.748400 12369 maintenance_manager.cc:419] P 45fd906423cf4970a97a978b1bc2a808: Scheduling FlushDeltaMemStoresOp(5d47842c233543b2a851aefc24632dc8): perf score=2.188937
I20260812 06:19:56.758747 12303 maintenance_manager.cc:643] P 45fd906423cf4970a97a978b1bc2a808: FlushDeltaMemStoresOp(5d47842c233543b2a851aefc24632dc8) complete. Timing: real 0.010s	user 0.001s	sys 0.007s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4144,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:56.759207 12369 maintenance_manager.cc:419] P 45fd906423cf4970a97a978b1bc2a808: Scheduling MajorDeltaCompactionOp(5d47842c233543b2a851aefc24632dc8): perf score=1.000000
I20260812 06:19:56.917903 12303 maintenance_manager.cc:643] P 45fd906423cf4970a97a978b1bc2a808: MajorDeltaCompactionOp(5d47842c233543b2a851aefc24632dc8) complete. Timing: real 0.159s	user 0.124s	sys 0.028s 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":284,"lbm_read_time_us":10419,"lbm_reads_lt_1ms":572,"lbm_write_time_us":31305,"lbm_writes_lt_1ms":543,"mutex_wait_us":2,"peak_mem_usage":63115900,"reinsert_count":0,"update_count":2500}
I20260812 06:19:56.918505 12369 maintenance_manager.cc:419] P 45fd906423cf4970a97a978b1bc2a808: Scheduling FlushDeltaMemStoresOp(5d47842c233543b2a851aefc24632dc8): perf score=11.118625
I20260812 06:19:56.952409 12303 maintenance_manager.cc:643] P 45fd906423cf4970a97a978b1bc2a808: FlushDeltaMemStoresOp(5d47842c233543b2a851aefc24632dc8) complete. Timing: real 0.034s	user 0.025s	sys 0.007s Metrics: {"bytes_written":12717735,"delete_count":0,"lbm_write_time_us":14143,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:19:56.953215 12369 maintenance_manager.cc:419] P 45fd906423cf4970a97a978b1bc2a808: Scheduling FlushDeltaMemStoresOp(5d47842c233543b2a851aefc24632dc8): perf score=2.188937
I20260812 06:19:56.973950 12303 maintenance_manager.cc:643] P 45fd906423cf4970a97a978b1bc2a808: FlushDeltaMemStoresOp(5d47842c233543b2a851aefc24632dc8) complete. Timing: real 0.020s	user 0.012s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5140,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:56.974460 12369 maintenance_manager.cc:419] P 45fd906423cf4970a97a978b1bc2a808: Scheduling FlushDeltaMemStoresOp(5d47842c233543b2a851aefc24632dc8): perf score=2.188937
I20260812 06:19:56.984149 12303 maintenance_manager.cc:643] P 45fd906423cf4970a97a978b1bc2a808: FlushDeltaMemStoresOp(5d47842c233543b2a851aefc24632dc8) complete. Timing: real 0.010s	user 0.005s	sys 0.004s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3651,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:19:56.984606 12369 maintenance_manager.cc:419] P 45fd906423cf4970a97a978b1bc2a808: Scheduling MajorDeltaCompactionOp(5d47842c233543b2a851aefc24632dc8): perf score=1.000000
I20260812 06:19:57.135524 12303 maintenance_manager.cc:643] P 45fd906423cf4970a97a978b1bc2a808: MajorDeltaCompactionOp(5d47842c233543b2a851aefc24632dc8) complete. Timing: real 0.151s	user 0.139s	sys 0.011s Metrics: {"cfile_cache_miss":533,"cfile_cache_miss_bytes":24815794,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":575,"lbm_read_time_us":10839,"lbm_reads_lt_1ms":573,"lbm_write_time_us":31187,"lbm_writes_lt_1ms":543,"mutex_wait_us":300,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":3072,"update_count":2500}
I20260812 06:19:57.136276 12369 maintenance_manager.cc:419] P 45fd906423cf4970a97a978b1bc2a808: Scheduling FlushDeltaMemStoresOp(5d47842c233543b2a851aefc24632dc8): perf score=10.126437
I20260812 06:19:57.172477 12303 maintenance_manager.cc:643] P 45fd906423cf4970a97a978b1bc2a808: FlushDeltaMemStoresOp(5d47842c233543b2a851aefc24632dc8) complete. Timing: real 0.036s	user 0.031s	sys 0.004s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":15526,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:19:57.173055 12369 maintenance_manager.cc:419] P 45fd906423cf4970a97a978b1bc2a808: Scheduling FlushDeltaMemStoresOp(5d47842c233543b2a851aefc24632dc8): perf score=2.188937
I20260812 06:19:57.187234 12303 maintenance_manager.cc:643] P 45fd906423cf4970a97a978b1bc2a808: FlushDeltaMemStoresOp(5d47842c233543b2a851aefc24632dc8) complete. Timing: real 0.014s	user 0.008s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5441,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:57.187711 12369 maintenance_manager.cc:419] P 45fd906423cf4970a97a978b1bc2a808: Scheduling FlushMRSOp(5d47842c233543b2a851aefc24632dc8): perf score=1.000000
I20260812 06:19:57.217238 12303 maintenance_manager.cc:643] P 45fd906423cf4970a97a978b1bc2a808: FlushMRSOp(5d47842c233543b2a851aefc24632dc8) complete. Timing: real 0.029s	user 0.028s	sys 0.000s Metrics: {"bytes_written":1275449,"cfile_init":1,"dirs.queue_time_us":77,"dirs.run_cpu_time_us":191,"dirs.run_wall_time_us":1362,"drs_written":1,"lbm_read_time_us":44,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1600,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":31}
I20260812 06:19:57.217932 12369 maintenance_manager.cc:419] P 45fd906423cf4970a97a978b1bc2a808: Scheduling LogGCOp(5d47842c233543b2a851aefc24632dc8): free 129320537 bytes of WAL
I20260812 06:19:57.218194 12303 log_reader.cc:385] T 5d47842c233543b2a851aefc24632dc8: removed 13 log segments from log reader
I20260812 06:19:57.218271 12303 log.cc:1079] T 5d47842c233543b2a851aefc24632dc8 P 45fd906423cf4970a97a978b1bc2a808: Deleting log segment in path: /tmp/dist-test-taskujMVo5/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515588428075-11983-0/minicluster-data/ts-0-root/wals/5d47842c233543b2a851aefc24632dc8/wal-000000015 (ops 72-76)
I20260812 06:19:57.218309 12303 log.cc:1079] T 5d47842c233543b2a851aefc24632dc8 P 45fd906423cf4970a97a978b1bc2a808: Deleting log segment in path: /tmp/dist-test-taskujMVo5/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515588428075-11983-0/minicluster-data/ts-0-root/wals/5d47842c233543b2a851aefc24632dc8/wal-000000016 (ops 77-81)
I20260812 06:19:57.218405 12303 log.cc:1079] T 5d47842c233543b2a851aefc24632dc8 P 45fd906423cf4970a97a978b1bc2a808: Deleting log segment in path: /tmp/dist-test-taskujMVo5/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515588428075-11983-0/minicluster-data/ts-0-root/wals/5d47842c233543b2a851aefc24632dc8/wal-000000017 (ops 82-86)
I20260812 06:19:57.218459 12303 log.cc:1079] T 5d47842c233543b2a851aefc24632dc8 P 45fd906423cf4970a97a978b1bc2a808: Deleting log segment in path: /tmp/dist-test-taskujMVo5/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515588428075-11983-0/minicluster-data/ts-0-root/wals/5d47842c233543b2a851aefc24632dc8/wal-000000018 (ops 87-91)
I20260812 06:19:57.218488 12303 log.cc:1079] T 5d47842c233543b2a851aefc24632dc8 P 45fd906423cf4970a97a978b1bc2a808: Deleting log segment in path: /tmp/dist-test-taskujMVo5/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515588428075-11983-0/minicluster-data/ts-0-root/wals/5d47842c233543b2a851aefc24632dc8/wal-000000019 (ops 92-96)
I20260812 06:19:57.218575 12303 log.cc:1079] T 5d47842c233543b2a851aefc24632dc8 P 45fd906423cf4970a97a978b1bc2a808: Deleting log segment in path: /tmp/dist-test-taskujMVo5/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515588428075-11983-0/minicluster-data/ts-0-root/wals/5d47842c233543b2a851aefc24632dc8/wal-000000020 (ops 97-100)
I20260812 06:19:57.218662 12303 log.cc:1079] T 5d47842c233543b2a851aefc24632dc8 P 45fd906423cf4970a97a978b1bc2a808: Deleting log segment in path: /tmp/dist-test-taskujMVo5/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515588428075-11983-0/minicluster-data/ts-0-root/wals/5d47842c233543b2a851aefc24632dc8/wal-000000021 (ops 101-105)
I20260812 06:19:57.218734 12303 log.cc:1079] T 5d47842c233543b2a851aefc24632dc8 P 45fd906423cf4970a97a978b1bc2a808: Deleting log segment in path: /tmp/dist-test-taskujMVo5/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515588428075-11983-0/minicluster-data/ts-0-root/wals/5d47842c233543b2a851aefc24632dc8/wal-000000022 (ops 106-110)
I20260812 06:19:57.218802 12303 log.cc:1079] T 5d47842c233543b2a851aefc24632dc8 P 45fd906423cf4970a97a978b1bc2a808: Deleting log segment in path: /tmp/dist-test-taskujMVo5/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515588428075-11983-0/minicluster-data/ts-0-root/wals/5d47842c233543b2a851aefc24632dc8/wal-000000023 (ops 111-114)
I20260812 06:19:57.218878 12303 log.cc:1079] T 5d47842c233543b2a851aefc24632dc8 P 45fd906423cf4970a97a978b1bc2a808: Deleting log segment in path: /tmp/dist-test-taskujMVo5/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515588428075-11983-0/minicluster-data/ts-0-root/wals/5d47842c233543b2a851aefc24632dc8/wal-000000024 (ops 115-119)
I20260812 06:19:57.218974 12303 log.cc:1079] T 5d47842c233543b2a851aefc24632dc8 P 45fd906423cf4970a97a978b1bc2a808: Deleting log segment in path: /tmp/dist-test-taskujMVo5/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515588428075-11983-0/minicluster-data/ts-0-root/wals/5d47842c233543b2a851aefc24632dc8/wal-000000025 (ops 120-124)
I20260812 06:19:57.219038 12303 log.cc:1079] T 5d47842c233543b2a851aefc24632dc8 P 45fd906423cf4970a97a978b1bc2a808: Deleting log segment in path: /tmp/dist-test-taskujMVo5/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515588428075-11983-0/minicluster-data/ts-0-root/wals/5d47842c233543b2a851aefc24632dc8/wal-000000026 (ops 125-129)
I20260812 06:19:57.219077 12303 log.cc:1079] T 5d47842c233543b2a851aefc24632dc8 P 45fd906423cf4970a97a978b1bc2a808: Deleting log segment in path: /tmp/dist-test-taskujMVo5/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515588428075-11983-0/minicluster-data/ts-0-root/wals/5d47842c233543b2a851aefc24632dc8/wal-000000027 (ops 130-134)
I20260812 06:19:57.245525 12303 maintenance_manager.cc:643] P 45fd906423cf4970a97a978b1bc2a808: LogGCOp(5d47842c233543b2a851aefc24632dc8) complete. Timing: real 0.027s	user 0.002s	sys 0.023s Metrics: {}
I20260812 06:19:57.246068 12369 maintenance_manager.cc:419] P 45fd906423cf4970a97a978b1bc2a808: Scheduling FlushDeltaMemStoresOp(5d47842c233543b2a851aefc24632dc8): perf score=6.157687
I20260812 06:19:57.270874 12303 maintenance_manager.cc:643] P 45fd906423cf4970a97a978b1bc2a808: FlushDeltaMemStoresOp(5d47842c233543b2a851aefc24632dc8) complete. Timing: real 0.025s	user 0.015s	sys 0.004s Metrics: {"bytes_written":8205077,"delete_count":0,"lbm_write_time_us":8797,"lbm_writes_lt_1ms":203,"reinsert_count":0,"update_count":1000}
I20260812 06:19:57.271481 12369 maintenance_manager.cc:419] P 45fd906423cf4970a97a978b1bc2a808: Scheduling UndoDeltaBlockGCOp(5d47842c233543b2a851aefc24632dc8): 482 bytes on disk
I20260812 06:19:57.272058 12303 maintenance_manager.cc:643] P 45fd906423cf4970a97a978b1bc2a808: UndoDeltaBlockGCOp(5d47842c233543b2a851aefc24632dc8) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":119,"lbm_reads_lt_1ms":4}
I20260812 06:19:57.272609 12369 maintenance_manager.cc:419] P 45fd906423cf4970a97a978b1bc2a808: Scheduling MajorDeltaCompactionOp(5d47842c233543b2a851aefc24632dc8): perf score=1.000000
I20260812 06:19:57.432793 12303 maintenance_manager.cc:643] P 45fd906423cf4970a97a978b1bc2a808: MajorDeltaCompactionOp(5d47842c233543b2a851aefc24632dc8) complete. Timing: real 0.160s	user 0.119s	sys 0.040s Metrics: {"cfile_cache_miss":633,"cfile_cache_miss_bytes":28918215,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":717,"lbm_read_time_us":10524,"lbm_reads_lt_1ms":665,"lbm_write_time_us":33146,"lbm_writes_lt_1ms":643,"mutex_wait_us":316,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":12416,"thread_start_us":92,"threads_started":1,"update_count":3000}
I20260812 06:19:57.433532 12369 maintenance_manager.cc:419] P 45fd906423cf4970a97a978b1bc2a808: Scheduling FlushDeltaMemStoresOp(5d47842c233543b2a851aefc24632dc8): perf score=14.095187
I20260812 06:19:57.480173 12303 maintenance_manager.cc:643] P 45fd906423cf4970a97a978b1bc2a808: FlushDeltaMemStoresOp(5d47842c233543b2a851aefc24632dc8) complete. Timing: real 0.046s	user 0.030s	sys 0.016s Metrics: {"bytes_written":16409904,"delete_count":0,"lbm_write_time_us":19735,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:57.480809 12369 maintenance_manager.cc:419] P 45fd906423cf4970a97a978b1bc2a808: Scheduling FlushDeltaMemStoresOp(5d47842c233543b2a851aefc24632dc8): perf score=2.188937
I20260812 06:19:57.497470 12303 maintenance_manager.cc:643] P 45fd906423cf4970a97a978b1bc2a808: FlushDeltaMemStoresOp(5d47842c233543b2a851aefc24632dc8) complete. Timing: real 0.016s	user 0.009s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5933,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:57.498020 12369 maintenance_manager.cc:419] P 45fd906423cf4970a97a978b1bc2a808: Scheduling MajorDeltaCompactionOp(5d47842c233543b2a851aefc24632dc8): perf score=1.000000
I20260812 06:19:57.648921 12303 maintenance_manager.cc:643] P 45fd906423cf4970a97a978b1bc2a808: MajorDeltaCompactionOp(5d47842c233543b2a851aefc24632dc8) complete. Timing: real 0.151s	user 0.096s	sys 0.051s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24815686,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":227,"lbm_read_time_us":8648,"lbm_reads_lt_1ms":564,"lbm_write_time_us":28653,"lbm_writes_lt_1ms":543,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":8448,"update_count":2500}
I20260812 06:19:57.649821 12369 maintenance_manager.cc:419] P 45fd906423cf4970a97a978b1bc2a808: Scheduling FlushDeltaMemStoresOp(5d47842c233543b2a851aefc24632dc8): perf score=14.095187
I20260812 06:19:57.709044 12303 maintenance_manager.cc:643] P 45fd906423cf4970a97a978b1bc2a808: FlushDeltaMemStoresOp(5d47842c233543b2a851aefc24632dc8) complete. Timing: real 0.059s	user 0.034s	sys 0.012s Metrics: {"bytes_written":16409897,"delete_count":0,"lbm_write_time_us":20746,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:57.709641 12369 maintenance_manager.cc:419] P 45fd906423cf4970a97a978b1bc2a808: Scheduling FlushDeltaMemStoresOp(5d47842c233543b2a851aefc24632dc8): perf score=2.188937
I20260812 06:19:57.719928 12303 maintenance_manager.cc:643] P 45fd906423cf4970a97a978b1bc2a808: FlushDeltaMemStoresOp(5d47842c233543b2a851aefc24632dc8) complete. Timing: real 0.010s	user 0.006s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3894,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:57.720458 12369 maintenance_manager.cc:419] P 45fd906423cf4970a97a978b1bc2a808: Scheduling MajorDeltaCompactionOp(5d47842c233543b2a851aefc24632dc8): perf score=1.000000
I20260812 06:19:57.888080 12303 maintenance_manager.cc:643] P 45fd906423cf4970a97a978b1bc2a808: MajorDeltaCompactionOp(5d47842c233543b2a851aefc24632dc8) complete. Timing: real 0.167s	user 0.106s	sys 0.055s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24815679,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":436,"dirs.run_cpu_time_us":593,"dirs.run_wall_time_us":3134,"lbm_read_time_us":11448,"lbm_reads_lt_1ms":572,"lbm_write_time_us":28687,"lbm_writes_lt_1ms":543,"mutex_wait_us":112,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":8576,"update_count":2500}
I20260812 06:19:57.888720 12369 maintenance_manager.cc:419] P 45fd906423cf4970a97a978b1bc2a808: Scheduling FlushDeltaMemStoresOp(5d47842c233543b2a851aefc24632dc8): perf score=14.095187
I20260812 06:19:57.943043 12303 maintenance_manager.cc:643] P 45fd906423cf4970a97a978b1bc2a808: FlushDeltaMemStoresOp(5d47842c233543b2a851aefc24632dc8) complete. Timing: real 0.054s	user 0.023s	sys 0.028s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":19356,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:57.943696 12369 maintenance_manager.cc:419] P 45fd906423cf4970a97a978b1bc2a808: Scheduling FlushDeltaMemStoresOp(5d47842c233543b2a851aefc24632dc8): perf score=2.188937
I20260812 06:19:57.960695 12303 maintenance_manager.cc:643] P 45fd906423cf4970a97a978b1bc2a808: FlushDeltaMemStoresOp(5d47842c233543b2a851aefc24632dc8) complete. Timing: real 0.017s	user 0.011s	sys 0.005s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":6227,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:57.961280 12369 maintenance_manager.cc:419] P 45fd906423cf4970a97a978b1bc2a808: Scheduling MajorDeltaCompactionOp(5d47842c233543b2a851aefc24632dc8): perf score=1.000000
I20260812 06:19:58.142719 12303 maintenance_manager.cc:643] P 45fd906423cf4970a97a978b1bc2a808: MajorDeltaCompactionOp(5d47842c233543b2a851aefc24632dc8) complete. Timing: real 0.181s	user 0.101s	sys 0.068s 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":889,"lbm_read_time_us":13338,"lbm_reads_1-10_ms":1,"lbm_reads_lt_1ms":571,"lbm_write_time_us":29501,"lbm_writes_lt_1ms":543,"mutex_wait_us":253,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":13568,"update_count":2500}
I20260812 06:19:58.143354 12369 maintenance_manager.cc:419] P 45fd906423cf4970a97a978b1bc2a808: Scheduling FlushDeltaMemStoresOp(5d47842c233543b2a851aefc24632dc8): perf score=14.095187
I20260812 06:19:58.198374 12303 maintenance_manager.cc:643] P 45fd906423cf4970a97a978b1bc2a808: FlushDeltaMemStoresOp(5d47842c233543b2a851aefc24632dc8) complete. Timing: real 0.055s	user 0.016s	sys 0.033s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":19382,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:58.198912 12369 maintenance_manager.cc:419] P 45fd906423cf4970a97a978b1bc2a808: Scheduling FlushDeltaMemStoresOp(5d47842c233543b2a851aefc24632dc8): perf score=2.188937
I20260812 06:19:58.209367 12303 maintenance_manager.cc:643] P 45fd906423cf4970a97a978b1bc2a808: FlushDeltaMemStoresOp(5d47842c233543b2a851aefc24632dc8) complete. Timing: real 0.010s	user 0.002s	sys 0.007s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4049,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:58.209806 12369 maintenance_manager.cc:419] P 45fd906423cf4970a97a978b1bc2a808: Scheduling MajorDeltaCompactionOp(5d47842c233543b2a851aefc24632dc8): perf score=1.000000
I20260812 06:19:58.395654 12303 maintenance_manager.cc:643] P 45fd906423cf4970a97a978b1bc2a808: MajorDeltaCompactionOp(5d47842c233543b2a851aefc24632dc8) complete. Timing: real 0.186s	user 0.143s	sys 0.038s 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":2931,"lbm_read_time_us":13059,"lbm_reads_lt_1ms":572,"lbm_write_time_us":30035,"lbm_writes_lt_1ms":543,"mutex_wait_us":2573,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":768,"update_count":2500}
I20260812 06:19:58.396286 12369 maintenance_manager.cc:419] P 45fd906423cf4970a97a978b1bc2a808: Scheduling FlushDeltaMemStoresOp(5d47842c233543b2a851aefc24632dc8): perf score=14.095187
I20260812 06:19:58.442103 12303 maintenance_manager.cc:643] P 45fd906423cf4970a97a978b1bc2a808: FlushDeltaMemStoresOp(5d47842c233543b2a851aefc24632dc8) complete. Timing: real 0.046s	user 0.028s	sys 0.013s Metrics: {"bytes_written":16409905,"delete_count":0,"lbm_write_time_us":19025,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:58.442621 12369 maintenance_manager.cc:419] P 45fd906423cf4970a97a978b1bc2a808: Scheduling FlushDeltaMemStoresOp(5d47842c233543b2a851aefc24632dc8): perf score=2.188937
I20260812 06:19:58.463038 12303 maintenance_manager.cc:643] P 45fd906423cf4970a97a978b1bc2a808: FlushDeltaMemStoresOp(5d47842c233543b2a851aefc24632dc8) complete. Timing: real 0.020s	user 0.010s	sys 0.007s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3869,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:58.463716 12369 maintenance_manager.cc:419] P 45fd906423cf4970a97a978b1bc2a808: Scheduling MajorDeltaCompactionOp(5d47842c233543b2a851aefc24632dc8): perf score=1.000000
I20260812 06:19:58.641372 12303 maintenance_manager.cc:643] P 45fd906423cf4970a97a978b1bc2a808: MajorDeltaCompactionOp(5d47842c233543b2a851aefc24632dc8) complete. Timing: real 0.177s	user 0.128s	sys 0.049s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24815687,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":163,"lbm_read_time_us":11624,"lbm_reads_lt_1ms":572,"lbm_write_time_us":30975,"lbm_writes_lt_1ms":543,"mutex_wait_us":41,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":11136,"update_count":2500}
I20260812 06:19:58.642023 12369 maintenance_manager.cc:419] P 45fd906423cf4970a97a978b1bc2a808: Scheduling FlushDeltaMemStoresOp(5d47842c233543b2a851aefc24632dc8): perf score=14.095187
I20260812 06:19:58.687116 12303 maintenance_manager.cc:643] P 45fd906423cf4970a97a978b1bc2a808: FlushDeltaMemStoresOp(5d47842c233543b2a851aefc24632dc8) complete. Timing: real 0.045s	user 0.031s	sys 0.007s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":18357,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:58.687718 12369 maintenance_manager.cc:419] P 45fd906423cf4970a97a978b1bc2a808: Scheduling FlushDeltaMemStoresOp(5d47842c233543b2a851aefc24632dc8): perf score=2.188937
I20260812 06:19:58.702911 12303 maintenance_manager.cc:643] P 45fd906423cf4970a97a978b1bc2a808: FlushDeltaMemStoresOp(5d47842c233543b2a851aefc24632dc8) complete. Timing: real 0.015s	user 0.008s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5647,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:58.703459 12369 maintenance_manager.cc:419] P 45fd906423cf4970a97a978b1bc2a808: Scheduling FlushMRSOp(5d47842c233543b2a851aefc24632dc8): perf score=1.000000
I20260812 06:19:58.745548 12303 maintenance_manager.cc:643] P 45fd906423cf4970a97a978b1bc2a808: FlushMRSOp(5d47842c233543b2a851aefc24632dc8) complete. Timing: real 0.042s	user 0.035s	sys 0.003s Metrics: {"bytes_written":1316417,"cfile_init":1,"dirs.queue_time_us":84,"dirs.run_cpu_time_us":203,"dirs.run_wall_time_us":1344,"drs_written":1,"lbm_read_time_us":38,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1798,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":32}
I20260812 06:19:58.746260 12369 maintenance_manager.cc:419] P 45fd906423cf4970a97a978b1bc2a808: Scheduling LogGCOp(5d47842c233543b2a851aefc24632dc8): free 133024646 bytes of WAL
I20260812 06:19:58.746491 12303 log_reader.cc:385] T 5d47842c233543b2a851aefc24632dc8: removed 13 log segments from log reader
I20260812 06:19:58.746536 12303 log.cc:1079] T 5d47842c233543b2a851aefc24632dc8 P 45fd906423cf4970a97a978b1bc2a808: Deleting log segment in path: /tmp/dist-test-taskujMVo5/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515588428075-11983-0/minicluster-data/ts-0-root/wals/5d47842c233543b2a851aefc24632dc8/wal-000000028 (ops 135-139)
I20260812 06:19:58.746564 12303 log.cc:1079] T 5d47842c233543b2a851aefc24632dc8 P 45fd906423cf4970a97a978b1bc2a808: Deleting log segment in path: /tmp/dist-test-taskujMVo5/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515588428075-11983-0/minicluster-data/ts-0-root/wals/5d47842c233543b2a851aefc24632dc8/wal-000000029 (ops 140-144)
I20260812 06:19:58.746632 12303 log.cc:1079] T 5d47842c233543b2a851aefc24632dc8 P 45fd906423cf4970a97a978b1bc2a808: Deleting log segment in path: /tmp/dist-test-taskujMVo5/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515588428075-11983-0/minicluster-data/ts-0-root/wals/5d47842c233543b2a851aefc24632dc8/wal-000000030 (ops 145-149)
I20260812 06:19:58.746676 12303 log.cc:1079] T 5d47842c233543b2a851aefc24632dc8 P 45fd906423cf4970a97a978b1bc2a808: Deleting log segment in path: /tmp/dist-test-taskujMVo5/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515588428075-11983-0/minicluster-data/ts-0-root/wals/5d47842c233543b2a851aefc24632dc8/wal-000000031 (ops 150-154)
I20260812 06:19:58.746716 12303 log.cc:1079] T 5d47842c233543b2a851aefc24632dc8 P 45fd906423cf4970a97a978b1bc2a808: Deleting log segment in path: /tmp/dist-test-taskujMVo5/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515588428075-11983-0/minicluster-data/ts-0-root/wals/5d47842c233543b2a851aefc24632dc8/wal-000000032 (ops 155-159)
I20260812 06:19:58.746760 12303 log.cc:1079] T 5d47842c233543b2a851aefc24632dc8 P 45fd906423cf4970a97a978b1bc2a808: Deleting log segment in path: /tmp/dist-test-taskujMVo5/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515588428075-11983-0/minicluster-data/ts-0-root/wals/5d47842c233543b2a851aefc24632dc8/wal-000000033 (ops 160-164)
I20260812 06:19:58.746803 12303 log.cc:1079] T 5d47842c233543b2a851aefc24632dc8 P 45fd906423cf4970a97a978b1bc2a808: Deleting log segment in path: /tmp/dist-test-taskujMVo5/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515588428075-11983-0/minicluster-data/ts-0-root/wals/5d47842c233543b2a851aefc24632dc8/wal-000000034 (ops 165-168)
I20260812 06:19:58.746845 12303 log.cc:1079] T 5d47842c233543b2a851aefc24632dc8 P 45fd906423cf4970a97a978b1bc2a808: Deleting log segment in path: /tmp/dist-test-taskujMVo5/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515588428075-11983-0/minicluster-data/ts-0-root/wals/5d47842c233543b2a851aefc24632dc8/wal-000000035 (ops 169-173)
I20260812 06:19:58.746884 12303 log.cc:1079] T 5d47842c233543b2a851aefc24632dc8 P 45fd906423cf4970a97a978b1bc2a808: Deleting log segment in path: /tmp/dist-test-taskujMVo5/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515588428075-11983-0/minicluster-data/ts-0-root/wals/5d47842c233543b2a851aefc24632dc8/wal-000000036 (ops 174-178)
I20260812 06:19:58.746923 12303 log.cc:1079] T 5d47842c233543b2a851aefc24632dc8 P 45fd906423cf4970a97a978b1bc2a808: Deleting log segment in path: /tmp/dist-test-taskujMVo5/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515588428075-11983-0/minicluster-data/ts-0-root/wals/5d47842c233543b2a851aefc24632dc8/wal-000000037 (ops 179-183)
I20260812 06:19:58.746963 12303 log.cc:1079] T 5d47842c233543b2a851aefc24632dc8 P 45fd906423cf4970a97a978b1bc2a808: Deleting log segment in path: /tmp/dist-test-taskujMVo5/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515588428075-11983-0/minicluster-data/ts-0-root/wals/5d47842c233543b2a851aefc24632dc8/wal-000000038 (ops 184-188)
I20260812 06:19:58.747001 12303 log.cc:1079] T 5d47842c233543b2a851aefc24632dc8 P 45fd906423cf4970a97a978b1bc2a808: Deleting log segment in path: /tmp/dist-test-taskujMVo5/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515588428075-11983-0/minicluster-data/ts-0-root/wals/5d47842c233543b2a851aefc24632dc8/wal-000000039 (ops 189-193)
I20260812 06:19:58.747041 12303 log.cc:1079] T 5d47842c233543b2a851aefc24632dc8 P 45fd906423cf4970a97a978b1bc2a808: Deleting log segment in path: /tmp/dist-test-taskujMVo5/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515588428075-11983-0/minicluster-data/ts-0-root/wals/5d47842c233543b2a851aefc24632dc8/wal-000000040 (ops 194-198)
I20260812 06:19:58.774212 12303 maintenance_manager.cc:643] P 45fd906423cf4970a97a978b1bc2a808: LogGCOp(5d47842c233543b2a851aefc24632dc8) complete. Timing: real 0.028s	user 0.000s	sys 0.025s Metrics: {}
I20260812 06:19:58.774673 12369 maintenance_manager.cc:419] P 45fd906423cf4970a97a978b1bc2a808: Scheduling FlushDeltaMemStoresOp(5d47842c233543b2a851aefc24632dc8): perf score=3.181125
I20260812 06:19:58.795255 11983 heavy-update-compaction-itest.cc:229] Time spent updating: real 4.722s	user 1.778s	sys 0.193s
I20260812 06:19:58.797019 12303 maintenance_manager.cc:643] P 45fd906423cf4970a97a978b1bc2a808: FlushDeltaMemStoresOp(5d47842c233543b2a851aefc24632dc8) complete. Timing: real 0.022s	user 0.000s	sys 0.010s Metrics: {"bytes_written":4512900,"delete_count":0,"lbm_write_time_us":4661,"lbm_writes_lt_1ms":113,"reinsert_count":0,"update_count":550}
I20260812 06:19:58.797556 12369 maintenance_manager.cc:419] P 45fd906423cf4970a97a978b1bc2a808: Scheduling UndoDeltaBlockGCOp(5d47842c233543b2a851aefc24632dc8): 493 bytes on disk
I20260812 06:19:58.797950 12303 maintenance_manager.cc:643] P 45fd906423cf4970a97a978b1bc2a808: UndoDeltaBlockGCOp(5d47842c233543b2a851aefc24632dc8) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":45,"lbm_reads_lt_1ms":4}
I20260812 06:19:58.798450 12369 maintenance_manager.cc:419] P 45fd906423cf4970a97a978b1bc2a808: Scheduling FlushDeltaMemStoresOp(5d47842c233543b2a851aefc24632dc8): perf score=2.188937
I20260812 06:19:58.807046 12303 maintenance_manager.cc:643] P 45fd906423cf4970a97a978b1bc2a808: FlushDeltaMemStoresOp(5d47842c233543b2a851aefc24632dc8) complete. Timing: real 0.008s	user 0.008s	sys 0.000s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3480,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:19:58.807392 12369 maintenance_manager.cc:419] P 45fd906423cf4970a97a978b1bc2a808: Scheduling MajorDeltaCompactionOp(5d47842c233543b2a851aefc24632dc8): perf score=1.000000
I20260812 06:19:58.880914 11983 heavy-update-compaction-itest.cc:265] Time spent scanning: real 0.085s	user 0.001s	sys 0.000s
I20260812 06:19:58.881459 11983 tablet_server.cc:179] TabletServer@127.11.179.193:0 shutting down...
I20260812 06:19:58.974634 12303 maintenance_manager.cc:643] P 45fd906423cf4970a97a978b1bc2a808: MajorDeltaCompactionOp(5d47842c233543b2a851aefc24632dc8) complete. Timing: real 0.167s	user 0.102s	sys 0.063s Metrics: {"cfile_cache_hit":225,"cfile_cache_hit_bytes":9112803,"cfile_cache_miss":509,"cfile_cache_miss_bytes":23907930,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":543,"lbm_read_time_us":9612,"lbm_reads_lt_1ms":541,"lbm_write_time_us":33673,"lbm_writes_lt_1ms":743,"mutex_wait_us":24,"peak_mem_usage":87969044,"reinsert_count":0,"spinlock_wait_cycles":132224,"thread_start_us":81,"threads_started":1,"update_count":3500}
I20260812 06:19:58.975298 11983 ts_tablet_manager.cc:1507] Shutting down tablet manager...
I20260812 06:19:58.975548 11983 tablet_replica.cc:333] T 5d47842c233543b2a851aefc24632dc8 P 45fd906423cf4970a97a978b1bc2a808: stopping tablet replica
I20260812 06:19:58.975723 11983 raft_consensus.cc:2243] T 5d47842c233543b2a851aefc24632dc8 P 45fd906423cf4970a97a978b1bc2a808 [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:19:58.975896 11983 raft_consensus.cc:2272] T 5d47842c233543b2a851aefc24632dc8 P 45fd906423cf4970a97a978b1bc2a808 [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:19:58.989974 11983 tablet_server.cc:196] TabletServer@127.11.179.193:0 shutdown complete.
I20260812 06:19:59.031934 11983 master.cc:562] Master@127.11.179.254:46167 shutting down...
I20260812 06:19:59.035027 11983 raft_consensus.cc:2243] T 00000000000000000000000000000000 P 6ff5322d8dc1405c90b61e7641847ef2 [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:19:59.035184 11983 raft_consensus.cc:2272] T 00000000000000000000000000000000 P 6ff5322d8dc1405c90b61e7641847ef2 [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:19:59.035234 11983 tablet_replica.cc:333] T 00000000000000000000000000000000 P 6ff5322d8dc1405c90b61e7641847ef2: stopping tablet replica
I20260812 06:19:59.047822 11983 master.cc:584] Master@127.11.179.254:46167 shutdown complete.
[       OK ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/1 (5245 ms)
[----------] 2 tests from EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy (10691 ms total)

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