[==========] 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:41.185997 15890 internal_mini_cluster.cc:156] Creating distributed mini masters. Addrs: 127.15.132.190:35197
I20260812 06:19:41.187047 15890 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:41.187654 15890 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:19:41.194404 15900 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:41.194478 15890 server_base.cc:1061] running on GCE node
W20260812 06:19:41.194386 15902 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:41.194638 15898 instance_detector.cc:116] could not retrieve AWS instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:19:41.195225 15890 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:19:41.195333 15890 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:41.195375 15890 hybrid_clock.cc:648] HybridClock initialized: now 1786515581195372 us; error 0 us; skew 500 ppm
I20260812 06:19:41.197357 15890 webserver.cc:533] Webserver started at http://127.15.132.190:35617/ using document root <none> and password file <none>
I20260812 06:19:41.198051 15890 fs_manager.cc:362] Metadata directory not provided
I20260812 06:19:41.198122 15890 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:19:41.198386 15890 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:19:41.200273 15890 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskZHdGUU/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515581174630-15890-0/minicluster-data/master-0-root/instance:
uuid: "f6d371230bfa4c1eaec5db66c894c30b"
format_stamp: "Formatted at 2026-08-12 06:19:41 on dist-test-slave-6bbx"
I20260812 06:19:41.204279 15890 fs_manager.cc:696] Time spent creating directory manager: real 0.004s	user 0.003s	sys 0.001s
I20260812 06:19:41.206670 15912 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:41.207841 15890 fs_manager.cc:730] Time spent opening block manager: real 0.002s	user 0.003s	sys 0.000s
I20260812 06:19:41.207962 15890 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskZHdGUU/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515581174630-15890-0/minicluster-data/master-0-root
uuid: "f6d371230bfa4c1eaec5db66c894c30b"
format_stamp: "Formatted at 2026-08-12 06:19:41 on dist-test-slave-6bbx"
I20260812 06:19:41.208062 15890 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskZHdGUU/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515581174630-15890-0/minicluster-data/master-0-root
metadata directory: /tmp/dist-test-taskZHdGUU/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515581174630-15890-0/minicluster-data/master-0-root
1 data directories: /tmp/dist-test-taskZHdGUU/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515581174630-15890-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:41.225397 15890 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:19:41.226114 15890 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:41.226291 15890 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:19:41.234371 15999 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.15.132.190:35197 every 8 connection(s)
I20260812 06:19:41.234377 15890 rpc_server.cc:307] RPC server started. Bound to: 127.15.132.190:35197
I20260812 06:19:41.236862 16000 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:41.242668 16000 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P f6d371230bfa4c1eaec5db66c894c30b: Bootstrap starting.
I20260812 06:19:41.245445 16000 tablet_bootstrap.cc:654] T 00000000000000000000000000000000 P f6d371230bfa4c1eaec5db66c894c30b: Neither blocks nor log segments found. Creating new log.
I20260812 06:19:41.246436 16000 log.cc:826] T 00000000000000000000000000000000 P f6d371230bfa4c1eaec5db66c894c30b: Log is configured to *not* fsync() on all Append() calls
I20260812 06:19:41.248279 16000 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P f6d371230bfa4c1eaec5db66c894c30b: No bootstrap required, opened a new log
I20260812 06:19:41.251158 16000 raft_consensus.cc:359] T 00000000000000000000000000000000 P f6d371230bfa4c1eaec5db66c894c30b [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "f6d371230bfa4c1eaec5db66c894c30b" member_type: VOTER }
I20260812 06:19:41.251366 16000 raft_consensus.cc:385] T 00000000000000000000000000000000 P f6d371230bfa4c1eaec5db66c894c30b [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:19:41.251438 16000 raft_consensus.cc:740] T 00000000000000000000000000000000 P f6d371230bfa4c1eaec5db66c894c30b [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: f6d371230bfa4c1eaec5db66c894c30b, State: Initialized, Role: FOLLOWER
I20260812 06:19:41.252056 16000 consensus_queue.cc:260] T 00000000000000000000000000000000 P f6d371230bfa4c1eaec5db66c894c30b [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: "f6d371230bfa4c1eaec5db66c894c30b" member_type: VOTER }
I20260812 06:19:41.252204 16000 raft_consensus.cc:399] T 00000000000000000000000000000000 P f6d371230bfa4c1eaec5db66c894c30b [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:19:41.252270 16000 raft_consensus.cc:493] T 00000000000000000000000000000000 P f6d371230bfa4c1eaec5db66c894c30b [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:19:41.252391 16000 raft_consensus.cc:3060] T 00000000000000000000000000000000 P f6d371230bfa4c1eaec5db66c894c30b [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:19:41.253193 16000 raft_consensus.cc:515] T 00000000000000000000000000000000 P f6d371230bfa4c1eaec5db66c894c30b [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "f6d371230bfa4c1eaec5db66c894c30b" member_type: VOTER }
I20260812 06:19:41.253631 16000 leader_election.cc:304] T 00000000000000000000000000000000 P f6d371230bfa4c1eaec5db66c894c30b [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: f6d371230bfa4c1eaec5db66c894c30b; no voters: 
I20260812 06:19:41.253973 16000 leader_election.cc:290] T 00000000000000000000000000000000 P f6d371230bfa4c1eaec5db66c894c30b [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:19:41.254079 16005 raft_consensus.cc:2804] T 00000000000000000000000000000000 P f6d371230bfa4c1eaec5db66c894c30b [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:19:41.254289 16005 raft_consensus.cc:697] T 00000000000000000000000000000000 P f6d371230bfa4c1eaec5db66c894c30b [term 1 LEADER]: Becoming Leader. State: Replica: f6d371230bfa4c1eaec5db66c894c30b, State: Running, Role: LEADER
I20260812 06:19:41.254717 16005 consensus_queue.cc:237] T 00000000000000000000000000000000 P f6d371230bfa4c1eaec5db66c894c30b [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: "f6d371230bfa4c1eaec5db66c894c30b" member_type: VOTER }
I20260812 06:19:41.254936 16000 sys_catalog.cc:565] T 00000000000000000000000000000000 P f6d371230bfa4c1eaec5db66c894c30b [sys.catalog]: configured and running, proceeding with master startup.
I20260812 06:19:41.256543 16007 sys_catalog.cc:455] T 00000000000000000000000000000000 P f6d371230bfa4c1eaec5db66c894c30b [sys.catalog]: SysCatalogTable state changed. Reason: RaftConsensus started. Latest consensus state: current_term: 1 leader_uuid: "f6d371230bfa4c1eaec5db66c894c30b" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "f6d371230bfa4c1eaec5db66c894c30b" member_type: VOTER } }
I20260812 06:19:41.256567 16008 sys_catalog.cc:455] T 00000000000000000000000000000000 P f6d371230bfa4c1eaec5db66c894c30b [sys.catalog]: SysCatalogTable state changed. Reason: New leader f6d371230bfa4c1eaec5db66c894c30b. Latest consensus state: current_term: 1 leader_uuid: "f6d371230bfa4c1eaec5db66c894c30b" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "f6d371230bfa4c1eaec5db66c894c30b" member_type: VOTER } }
I20260812 06:19:41.256664 16008 sys_catalog.cc:458] T 00000000000000000000000000000000 P f6d371230bfa4c1eaec5db66c894c30b [sys.catalog]: This master's current role is: LEADER
I20260812 06:19:41.256664 16007 sys_catalog.cc:458] T 00000000000000000000000000000000 P f6d371230bfa4c1eaec5db66c894c30b [sys.catalog]: This master's current role is: LEADER
I20260812 06:19:41.257149 15890 internal_mini_cluster.cc:184] Waiting to initialize catalog manager on master 0
W20260812 06:19:41.258978 16026 catalog_manager.cc:1594] T 00000000000000000000000000000000 P f6d371230bfa4c1eaec5db66c894c30b: loading cluster ID for follower catalog manager: Not found: cluster ID entry not found
W20260812 06:19:41.259039 16026 catalog_manager.cc:883] Not found: cluster ID entry not found: failed to prepare follower catalog manager, will retry
I20260812 06:19:41.259116 16022 catalog_manager.cc:1511] Loading table and tablet metadata into memory...
I20260812 06:19:41.260079 16022 catalog_manager.cc:1520] Initializing Kudu cluster ID...
I20260812 06:19:41.265092 16022 catalog_manager.cc:1383] Generated new cluster ID: f62ce80bf70b42b881e0a966d059b391
I20260812 06:19:41.265159 16022 catalog_manager.cc:1531] Initializing Kudu internal certificate authority...
I20260812 06:19:41.270845 16022 catalog_manager.cc:1406] Generated new certificate authority record
I20260812 06:19:41.272018 16022 catalog_manager.cc:1540] Loading token signing keys...
I20260812 06:19:41.290287 16022 catalog_manager.cc:6092] T 00000000000000000000000000000000 P f6d371230bfa4c1eaec5db66c894c30b: Generated new TSK 0
I20260812 06:19:41.290966 16022 catalog_manager.cc:1550] Initializing in-progress tserver states...
I20260812 06:19:41.322095 15890 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:19:41.325423 16041 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:41.325382 16035 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:41.325383 16036 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:41.325786 15890 server_base.cc:1061] running on GCE node
I20260812 06:19:41.325968 15890 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:19:41.326009 15890 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:41.326025 15890 hybrid_clock.cc:648] HybridClock initialized: now 1786515581326025 us; error 0 us; skew 500 ppm
I20260812 06:19:41.327032 15890 webserver.cc:533] Webserver started at http://127.15.132.129:45739/ using document root <none> and password file <none>
I20260812 06:19:41.327239 15890 fs_manager.cc:362] Metadata directory not provided
I20260812 06:19:41.327294 15890 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:19:41.327383 15890 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:19:41.327834 15890 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskZHdGUU/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515581174630-15890-0/minicluster-data/ts-0-root/instance:
uuid: "7739cbc3fba84996b23290d1fc35872b"
format_stamp: "Formatted at 2026-08-12 06:19:41 on dist-test-slave-6bbx"
I20260812 06:19:41.329358 15890 fs_manager.cc:696] Time spent creating directory manager: real 0.001s	user 0.001s	sys 0.000s
I20260812 06:19:41.330423 16048 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:41.330704 15890 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.001s	sys 0.000s
I20260812 06:19:41.330781 15890 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskZHdGUU/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515581174630-15890-0/minicluster-data/ts-0-root
uuid: "7739cbc3fba84996b23290d1fc35872b"
format_stamp: "Formatted at 2026-08-12 06:19:41 on dist-test-slave-6bbx"
I20260812 06:19:41.330863 15890 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskZHdGUU/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515581174630-15890-0/minicluster-data/ts-0-root
metadata directory: /tmp/dist-test-taskZHdGUU/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515581174630-15890-0/minicluster-data/ts-0-root
1 data directories: /tmp/dist-test-taskZHdGUU/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515581174630-15890-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:41.337970 15890 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:19:41.338495 15890 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:19:41.338963 15890 txn_system_client.cc:432] TxnSystemClient initialization is disabled...
I20260812 06:19:41.339895 15890 ts_tablet_manager.cc:585] Loaded tablet metadata (0 total tablets, 0 live tablets)
I20260812 06:19:41.339955 15890 ts_tablet_manager.cc:531] Time spent load tablet metadata: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:19:41.340014 15890 ts_tablet_manager.cc:616] Registered 0 tablets
I20260812 06:19:41.340041 15890 ts_tablet_manager.cc:595] Time spent register tablets: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:19:41.346274 15890 rpc_server.cc:307] RPC server started. Bound to: 127.15.132.129:45339
I20260812 06:19:41.346308 16150 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.15.132.129:45339 every 8 connection(s)
I20260812 06:19:41.356735 16154 heartbeater.cc:344] Connected to a master server at 127.15.132.190:35197
I20260812 06:19:41.357033 16154 heartbeater.cc:461] Registering TS with master...
I20260812 06:19:41.357558 16154 heartbeater.cc:507] Master 127.15.132.190:35197 requested a full tablet report, sending...
I20260812 06:19:41.359033 15940 ts_manager.cc:194] Registered new tserver with Master: 7739cbc3fba84996b23290d1fc35872b (127.15.132.129:45339)
I20260812 06:19:41.359282 15890 internal_mini_cluster.cc:371] 1 TS(s) registered with all masters after 0.012314128s
I20260812 06:19:41.360551 15940 master_service.cc:502] Signed X509 certificate for tserver {username='slave'} at 127.0.0.1:45548
I20260812 06:19:41.368904 15940 catalog_manager.cc:2283] Servicing CreateTable request from {username='slave'} at 127.0.0.1:45552:
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:41.382511 16090 tablet_service.cc:1511] Processing CreateTablet for tablet f8a79300516548dd91e26fd008eefeef (DEFAULT_TABLE table=heavy-update-compaction-test [id=1df0db39cd8d4cfbb4a2bf183a36e23f]), partition=
I20260812 06:19:41.382983 16090 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet f8a79300516548dd91e26fd008eefeef. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:19:41.385577 16174 tablet_bootstrap.cc:492] T f8a79300516548dd91e26fd008eefeef P 7739cbc3fba84996b23290d1fc35872b: Bootstrap starting.
I20260812 06:19:41.386643 16174 tablet_bootstrap.cc:654] T f8a79300516548dd91e26fd008eefeef P 7739cbc3fba84996b23290d1fc35872b: Neither blocks nor log segments found. Creating new log.
I20260812 06:19:41.387936 16174 tablet_bootstrap.cc:492] T f8a79300516548dd91e26fd008eefeef P 7739cbc3fba84996b23290d1fc35872b: No bootstrap required, opened a new log
I20260812 06:19:41.388044 16174 ts_tablet_manager.cc:1403] T f8a79300516548dd91e26fd008eefeef P 7739cbc3fba84996b23290d1fc35872b: Time spent bootstrapping tablet: real 0.003s	user 0.002s	sys 0.000s
I20260812 06:19:41.388509 16174 raft_consensus.cc:359] T f8a79300516548dd91e26fd008eefeef P 7739cbc3fba84996b23290d1fc35872b [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "7739cbc3fba84996b23290d1fc35872b" member_type: VOTER last_known_addr { host: "127.15.132.129" port: 45339 } }
I20260812 06:19:41.388621 16174 raft_consensus.cc:385] T f8a79300516548dd91e26fd008eefeef P 7739cbc3fba84996b23290d1fc35872b [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:19:41.388655 16174 raft_consensus.cc:740] T f8a79300516548dd91e26fd008eefeef P 7739cbc3fba84996b23290d1fc35872b [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: 7739cbc3fba84996b23290d1fc35872b, State: Initialized, Role: FOLLOWER
I20260812 06:19:41.388792 16174 consensus_queue.cc:260] T f8a79300516548dd91e26fd008eefeef P 7739cbc3fba84996b23290d1fc35872b [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: "7739cbc3fba84996b23290d1fc35872b" member_type: VOTER last_known_addr { host: "127.15.132.129" port: 45339 } }
I20260812 06:19:41.388880 16174 raft_consensus.cc:399] T f8a79300516548dd91e26fd008eefeef P 7739cbc3fba84996b23290d1fc35872b [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:19:41.388926 16174 raft_consensus.cc:493] T f8a79300516548dd91e26fd008eefeef P 7739cbc3fba84996b23290d1fc35872b [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:19:41.388974 16174 raft_consensus.cc:3060] T f8a79300516548dd91e26fd008eefeef P 7739cbc3fba84996b23290d1fc35872b [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:19:41.389731 16174 raft_consensus.cc:515] T f8a79300516548dd91e26fd008eefeef P 7739cbc3fba84996b23290d1fc35872b [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "7739cbc3fba84996b23290d1fc35872b" member_type: VOTER last_known_addr { host: "127.15.132.129" port: 45339 } }
I20260812 06:19:41.389876 16174 leader_election.cc:304] T f8a79300516548dd91e26fd008eefeef P 7739cbc3fba84996b23290d1fc35872b [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: 7739cbc3fba84996b23290d1fc35872b; no voters: 
I20260812 06:19:41.390087 16174 leader_election.cc:290] T f8a79300516548dd91e26fd008eefeef P 7739cbc3fba84996b23290d1fc35872b [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:19:41.390206 16177 raft_consensus.cc:2804] T f8a79300516548dd91e26fd008eefeef P 7739cbc3fba84996b23290d1fc35872b [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:19:41.390446 16174 ts_tablet_manager.cc:1434] T f8a79300516548dd91e26fd008eefeef P 7739cbc3fba84996b23290d1fc35872b: Time spent starting tablet: real 0.002s	user 0.000s	sys 0.003s
I20260812 06:19:41.390717 16154 heartbeater.cc:499] Master 127.15.132.190:35197 was elected leader, sending a full tablet report...
I20260812 06:19:41.390914 16177 raft_consensus.cc:697] T f8a79300516548dd91e26fd008eefeef P 7739cbc3fba84996b23290d1fc35872b [term 1 LEADER]: Becoming Leader. State: Replica: 7739cbc3fba84996b23290d1fc35872b, State: Running, Role: LEADER
I20260812 06:19:41.391115 16177 consensus_queue.cc:237] T f8a79300516548dd91e26fd008eefeef P 7739cbc3fba84996b23290d1fc35872b [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: "7739cbc3fba84996b23290d1fc35872b" member_type: VOTER last_known_addr { host: "127.15.132.129" port: 45339 } }
I20260812 06:19:41.394044 15940 catalog_manager.cc:5719] T f8a79300516548dd91e26fd008eefeef P 7739cbc3fba84996b23290d1fc35872b reported cstate change: term changed from 0 to 1, leader changed from <none> to 7739cbc3fba84996b23290d1fc35872b (127.15.132.129). New cstate: current_term: 1 leader_uuid: "7739cbc3fba84996b23290d1fc35872b" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "7739cbc3fba84996b23290d1fc35872b" member_type: VOTER last_known_addr { host: "127.15.132.129" port: 45339 } health_report { overall_health: HEALTHY } } }
I20260812 06:19:41.465562 15890 heavy-update-compaction-itest.cc:215] Time spent inserting: real 0.061s	user 0.028s	sys 0.005s
I20260812 06:19:41.597388 16156 maintenance_manager.cc:419] P 7739cbc3fba84996b23290d1fc35872b: Scheduling FlushMRSOp(f8a79300516548dd91e26fd008eefeef): perf score=19.054940
I20260812 06:19:41.774348 16054 maintenance_manager.cc:643] P 7739cbc3fba84996b23290d1fc35872b: FlushMRSOp(f8a79300516548dd91e26fd008eefeef) complete. Timing: real 0.177s	user 0.149s	sys 0.024s Metrics: {"bytes_written":12840809,"cfile_init":1,"compiler_manager_pool.queue_time_us":201,"delete_count":0,"dirs.queue_time_us":44,"dirs.run_cpu_time_us":214,"dirs.run_wall_time_us":875,"drs_written":1,"lbm_read_time_us":73,"lbm_reads_lt_1ms":4,"lbm_write_time_us":42029,"lbm_writes_lt_1ms":770,"peak_mem_usage":0,"reinsert_count":0,"rows_written":104,"spinlock_wait_cycles":200320,"thread_start_us":108,"threads_started":1,"update_count":1565}
I20260812 06:19:41.775951 16156 maintenance_manager.cc:419] P 7739cbc3fba84996b23290d1fc35872b: Scheduling LogGCOp(f8a79300516548dd91e26fd008eefeef): free 20743880 bytes of WAL
I20260812 06:19:41.776379 16054 log_reader.cc:385] T f8a79300516548dd91e26fd008eefeef: removed 2 log segments from log reader
I20260812 06:19:41.776530 16054 log.cc:1079] T f8a79300516548dd91e26fd008eefeef P 7739cbc3fba84996b23290d1fc35872b: Deleting log segment in path: /tmp/dist-test-taskZHdGUU/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515581174630-15890-0/minicluster-data/ts-0-root/wals/f8a79300516548dd91e26fd008eefeef/wal-000000001 (ops 1-6)
I20260812 06:19:41.776636 16054 log.cc:1079] T f8a79300516548dd91e26fd008eefeef P 7739cbc3fba84996b23290d1fc35872b: Deleting log segment in path: /tmp/dist-test-taskZHdGUU/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515581174630-15890-0/minicluster-data/ts-0-root/wals/f8a79300516548dd91e26fd008eefeef/wal-000000002 (ops 7-11)
I20260812 06:19:41.781242 16054 maintenance_manager.cc:643] P 7739cbc3fba84996b23290d1fc35872b: LogGCOp(f8a79300516548dd91e26fd008eefeef) complete. Timing: real 0.005s	user 0.000s	sys 0.003s Metrics: {}
I20260812 06:19:41.781589 16156 maintenance_manager.cc:419] P 7739cbc3fba84996b23290d1fc35872b: Scheduling UndoDeltaBlockGCOp(f8a79300516548dd91e26fd008eefeef): 16411393 bytes on disk
I20260812 06:19:41.782145 16054 maintenance_manager.cc:643] P 7739cbc3fba84996b23290d1fc35872b: UndoDeltaBlockGCOp(f8a79300516548dd91e26fd008eefeef) 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:41.782711 16156 maintenance_manager.cc:419] P 7739cbc3fba84996b23290d1fc35872b: Scheduling FlushDeltaMemStoresOp(f8a79300516548dd91e26fd008eefeef): perf score=2.188937
I20260812 06:19:41.800771 16054 maintenance_manager.cc:643] P 7739cbc3fba84996b23290d1fc35872b: FlushDeltaMemStoresOp(f8a79300516548dd91e26fd008eefeef) complete. Timing: real 0.018s	user 0.001s	sys 0.015s Metrics: {"bytes_written":4307783,"delete_count":0,"lbm_write_time_us":3842,"lbm_writes_lt_1ms":108,"reinsert_count":0,"update_count":525}
I20260812 06:19:41.801402 16156 maintenance_manager.cc:419] P 7739cbc3fba84996b23290d1fc35872b: Scheduling FlushDeltaMemStoresOp(f8a79300516548dd91e26fd008eefeef): perf score=2.188937
I20260812 06:19:41.814735 16054 maintenance_manager.cc:643] P 7739cbc3fba84996b23290d1fc35872b: FlushDeltaMemStoresOp(f8a79300516548dd91e26fd008eefeef) complete. Timing: real 0.013s	user 0.011s	sys 0.000s Metrics: {"bytes_written":3364205,"delete_count":0,"lbm_write_time_us":4783,"lbm_writes_lt_1ms":85,"reinsert_count":0,"update_count":410}
I20260812 06:19:41.815233 16156 maintenance_manager.cc:419] P 7739cbc3fba84996b23290d1fc35872b: Scheduling MajorDeltaCompactionOp(f8a79300516548dd91e26fd008eefeef): perf score=1.000000
I20260812 06:19:41.979049 16054 maintenance_manager.cc:643] P 7739cbc3fba84996b23290d1fc35872b: MajorDeltaCompactionOp(f8a79300516548dd91e26fd008eefeef) complete. Timing: real 0.164s	user 0.107s	sys 0.056s Metrics: {"cfile_cache_miss":533,"cfile_cache_miss_bytes":24774797,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":545,"lbm_read_time_us":11814,"lbm_reads_lt_1ms":569,"lbm_write_time_us":26829,"lbm_writes_lt_1ms":543,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":896,"thread_start_us":300,"threads_started":5,"update_count":2500}
I20260812 06:19:41.979537 16156 maintenance_manager.cc:419] P 7739cbc3fba84996b23290d1fc35872b: Scheduling FlushDeltaMemStoresOp(f8a79300516548dd91e26fd008eefeef): perf score=10.126437
I20260812 06:19:42.021036 16054 maintenance_manager.cc:643] P 7739cbc3fba84996b23290d1fc35872b: FlushDeltaMemStoresOp(f8a79300516548dd91e26fd008eefeef) complete. Timing: real 0.041s	user 0.024s	sys 0.015s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":17103,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":302,"reinsert_count":0,"update_count":1500}
I20260812 06:19:42.021659 16156 maintenance_manager.cc:419] P 7739cbc3fba84996b23290d1fc35872b: Scheduling FlushDeltaMemStoresOp(f8a79300516548dd91e26fd008eefeef): perf score=2.188937
I20260812 06:19:42.033983 16054 maintenance_manager.cc:643] P 7739cbc3fba84996b23290d1fc35872b: FlushDeltaMemStoresOp(f8a79300516548dd91e26fd008eefeef) complete. Timing: real 0.012s	user 0.005s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3971,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:42.034433 16156 maintenance_manager.cc:419] P 7739cbc3fba84996b23290d1fc35872b: Scheduling MajorDeltaCompactionOp(f8a79300516548dd91e26fd008eefeef): perf score=1.000000
I20260812 06:19:42.155282 16054 maintenance_manager.cc:643] P 7739cbc3fba84996b23290d1fc35872b: MajorDeltaCompactionOp(f8a79300516548dd91e26fd008eefeef) complete. Timing: real 0.121s	user 0.094s	sys 0.024s 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":171,"lbm_read_time_us":9652,"lbm_reads_lt_1ms":464,"lbm_write_time_us":20564,"lbm_writes_lt_1ms":443,"mutex_wait_us":70,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":3072,"update_count":2000}
I20260812 06:19:42.155794 16156 maintenance_manager.cc:419] P 7739cbc3fba84996b23290d1fc35872b: Scheduling FlushDeltaMemStoresOp(f8a79300516548dd91e26fd008eefeef): perf score=10.126437
I20260812 06:19:42.193940 16054 maintenance_manager.cc:643] P 7739cbc3fba84996b23290d1fc35872b: FlushDeltaMemStoresOp(f8a79300516548dd91e26fd008eefeef) complete. Timing: real 0.038s	user 0.026s	sys 0.009s Metrics: {"bytes_written":12307494,"delete_count":0,"lbm_write_time_us":14691,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:19:42.194434 16156 maintenance_manager.cc:419] P 7739cbc3fba84996b23290d1fc35872b: Scheduling FlushDeltaMemStoresOp(f8a79300516548dd91e26fd008eefeef): perf score=2.188937
I20260812 06:19:42.205044 16054 maintenance_manager.cc:643] P 7739cbc3fba84996b23290d1fc35872b: FlushDeltaMemStoresOp(f8a79300516548dd91e26fd008eefeef) complete. Timing: real 0.010s	user 0.004s	sys 0.005s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":3598,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:42.205549 16156 maintenance_manager.cc:419] P 7739cbc3fba84996b23290d1fc35872b: Scheduling MajorDeltaCompactionOp(f8a79300516548dd91e26fd008eefeef): perf score=1.000000
I20260812 06:19:42.318727 16054 maintenance_manager.cc:643] P 7739cbc3fba84996b23290d1fc35872b: MajorDeltaCompactionOp(f8a79300516548dd91e26fd008eefeef) complete. Timing: real 0.113s	user 0.096s	sys 0.016s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672280,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":826,"lbm_read_time_us":7854,"lbm_reads_lt_1ms":472,"lbm_write_time_us":20466,"lbm_writes_lt_1ms":443,"mutex_wait_us":93,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":896,"update_count":2000}
I20260812 06:19:42.319247 16156 maintenance_manager.cc:419] P 7739cbc3fba84996b23290d1fc35872b: Scheduling FlushDeltaMemStoresOp(f8a79300516548dd91e26fd008eefeef): perf score=10.126437
I20260812 06:19:42.365705 16054 maintenance_manager.cc:643] P 7739cbc3fba84996b23290d1fc35872b: FlushDeltaMemStoresOp(f8a79300516548dd91e26fd008eefeef) complete. Timing: real 0.046s	user 0.027s	sys 0.004s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":14083,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:19:42.366238 16156 maintenance_manager.cc:419] P 7739cbc3fba84996b23290d1fc35872b: Scheduling FlushDeltaMemStoresOp(f8a79300516548dd91e26fd008eefeef): perf score=2.188937
I20260812 06:19:42.381417 16054 maintenance_manager.cc:643] P 7739cbc3fba84996b23290d1fc35872b: FlushDeltaMemStoresOp(f8a79300516548dd91e26fd008eefeef) complete. Timing: real 0.015s	user 0.009s	sys 0.004s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":5375,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:42.381937 16156 maintenance_manager.cc:419] P 7739cbc3fba84996b23290d1fc35872b: Scheduling MajorDeltaCompactionOp(f8a79300516548dd91e26fd008eefeef): perf score=1.000000
I20260812 06:19:42.506609 16054 maintenance_manager.cc:643] P 7739cbc3fba84996b23290d1fc35872b: MajorDeltaCompactionOp(f8a79300516548dd91e26fd008eefeef) complete. Timing: real 0.124s	user 0.109s	sys 0.016s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672276,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":831,"lbm_read_time_us":9461,"lbm_reads_lt_1ms":472,"lbm_write_time_us":21263,"lbm_writes_lt_1ms":443,"mutex_wait_us":50,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":44032,"update_count":2000}
I20260812 06:19:42.507089 16156 maintenance_manager.cc:419] P 7739cbc3fba84996b23290d1fc35872b: Scheduling FlushDeltaMemStoresOp(f8a79300516548dd91e26fd008eefeef): perf score=10.126437
I20260812 06:19:42.567804 16054 maintenance_manager.cc:643] P 7739cbc3fba84996b23290d1fc35872b: FlushDeltaMemStoresOp(f8a79300516548dd91e26fd008eefeef) complete. Timing: real 0.061s	user 0.019s	sys 0.020s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":14979,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:19:42.568423 16156 maintenance_manager.cc:419] P 7739cbc3fba84996b23290d1fc35872b: Scheduling FlushDeltaMemStoresOp(f8a79300516548dd91e26fd008eefeef): perf score=2.188937
I20260812 06:19:42.586470 16054 maintenance_manager.cc:643] P 7739cbc3fba84996b23290d1fc35872b: FlushDeltaMemStoresOp(f8a79300516548dd91e26fd008eefeef) complete. Timing: real 0.018s	user 0.008s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5530,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:42.586964 16156 maintenance_manager.cc:419] P 7739cbc3fba84996b23290d1fc35872b: Scheduling MajorDeltaCompactionOp(f8a79300516548dd91e26fd008eefeef): perf score=1.000000
I20260812 06:19:42.736313 16054 maintenance_manager.cc:643] P 7739cbc3fba84996b23290d1fc35872b: MajorDeltaCompactionOp(f8a79300516548dd91e26fd008eefeef) complete. Timing: real 0.149s	user 0.094s	sys 0.044s 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":147,"lbm_read_time_us":8216,"lbm_reads_lt_1ms":464,"lbm_write_time_us":22748,"lbm_writes_lt_1ms":443,"mutex_wait_us":45,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":9984,"update_count":2000}
I20260812 06:19:42.736853 16156 maintenance_manager.cc:419] P 7739cbc3fba84996b23290d1fc35872b: Scheduling FlushDeltaMemStoresOp(f8a79300516548dd91e26fd008eefeef): perf score=14.095187
I20260812 06:19:42.783177 16054 maintenance_manager.cc:643] P 7739cbc3fba84996b23290d1fc35872b: FlushDeltaMemStoresOp(f8a79300516548dd91e26fd008eefeef) complete. Timing: real 0.046s	user 0.038s	sys 0.000s Metrics: {"bytes_written":16409903,"delete_count":0,"lbm_write_time_us":17855,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:42.783840 16156 maintenance_manager.cc:419] P 7739cbc3fba84996b23290d1fc35872b: Scheduling FlushDeltaMemStoresOp(f8a79300516548dd91e26fd008eefeef): perf score=2.188937
I20260812 06:19:42.794927 16054 maintenance_manager.cc:643] P 7739cbc3fba84996b23290d1fc35872b: FlushDeltaMemStoresOp(f8a79300516548dd91e26fd008eefeef) complete. Timing: real 0.011s	user 0.004s	sys 0.004s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":3741,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:42.795405 16156 maintenance_manager.cc:419] P 7739cbc3fba84996b23290d1fc35872b: Scheduling MajorDeltaCompactionOp(f8a79300516548dd91e26fd008eefeef): perf score=1.000000
I20260812 06:19:42.945155 16054 maintenance_manager.cc:643] P 7739cbc3fba84996b23290d1fc35872b: MajorDeltaCompactionOp(f8a79300516548dd91e26fd008eefeef) complete. Timing: real 0.150s	user 0.129s	sys 0.019s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774689,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":685,"lbm_read_time_us":9704,"lbm_reads_lt_1ms":572,"lbm_write_time_us":29163,"lbm_writes_lt_1ms":543,"mutex_wait_us":192,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":11648,"update_count":2500}
I20260812 06:19:42.945801 16156 maintenance_manager.cc:419] P 7739cbc3fba84996b23290d1fc35872b: Scheduling FlushDeltaMemStoresOp(f8a79300516548dd91e26fd008eefeef): perf score=11.118625
I20260812 06:19:42.978286 16054 maintenance_manager.cc:643] P 7739cbc3fba84996b23290d1fc35872b: FlushDeltaMemStoresOp(f8a79300516548dd91e26fd008eefeef) complete. Timing: real 0.032s	user 0.018s	sys 0.012s Metrics: {"bytes_written":12717734,"delete_count":0,"lbm_write_time_us":13444,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:19:42.978858 16156 maintenance_manager.cc:419] P 7739cbc3fba84996b23290d1fc35872b: Scheduling FlushDeltaMemStoresOp(f8a79300516548dd91e26fd008eefeef): perf score=2.188937
I20260812 06:19:42.993237 16054 maintenance_manager.cc:643] P 7739cbc3fba84996b23290d1fc35872b: FlushDeltaMemStoresOp(f8a79300516548dd91e26fd008eefeef) complete. Timing: real 0.014s	user 0.005s	sys 0.008s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":5394,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:19:42.993737 16156 maintenance_manager.cc:419] P 7739cbc3fba84996b23290d1fc35872b: Scheduling FlushMRSOp(f8a79300516548dd91e26fd008eefeef): perf score=1.000000
I20260812 06:19:43.021080 16054 maintenance_manager.cc:643] P 7739cbc3fba84996b23290d1fc35872b: FlushMRSOp(f8a79300516548dd91e26fd008eefeef) complete. Timing: real 0.027s	user 0.025s	sys 0.000s Metrics: {"bytes_written":1234473,"cfile_init":1,"dirs.queue_time_us":65,"dirs.run_cpu_time_us":215,"dirs.run_wall_time_us":1299,"drs_written":1,"lbm_read_time_us":41,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1670,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":30,"spinlock_wait_cycles":4480}
I20260812 06:19:43.021989 16156 maintenance_manager.cc:419] P 7739cbc3fba84996b23290d1fc35872b: Scheduling LogGCOp(f8a79300516548dd91e26fd008eefeef): free 120553381 bytes of WAL
I20260812 06:19:43.022256 16054 log_reader.cc:385] T f8a79300516548dd91e26fd008eefeef: removed 12 log segments from log reader
I20260812 06:19:43.022305 16054 log.cc:1079] T f8a79300516548dd91e26fd008eefeef P 7739cbc3fba84996b23290d1fc35872b: Deleting log segment in path: /tmp/dist-test-taskZHdGUU/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515581174630-15890-0/minicluster-data/ts-0-root/wals/f8a79300516548dd91e26fd008eefeef/wal-000000003 (ops 12-16)
I20260812 06:19:43.022343 16054 log.cc:1079] T f8a79300516548dd91e26fd008eefeef P 7739cbc3fba84996b23290d1fc35872b: Deleting log segment in path: /tmp/dist-test-taskZHdGUU/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515581174630-15890-0/minicluster-data/ts-0-root/wals/f8a79300516548dd91e26fd008eefeef/wal-000000004 (ops 17-20)
I20260812 06:19:43.022377 16054 log.cc:1079] T f8a79300516548dd91e26fd008eefeef P 7739cbc3fba84996b23290d1fc35872b: Deleting log segment in path: /tmp/dist-test-taskZHdGUU/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515581174630-15890-0/minicluster-data/ts-0-root/wals/f8a79300516548dd91e26fd008eefeef/wal-000000005 (ops 21-25)
I20260812 06:19:43.022408 16054 log.cc:1079] T f8a79300516548dd91e26fd008eefeef P 7739cbc3fba84996b23290d1fc35872b: Deleting log segment in path: /tmp/dist-test-taskZHdGUU/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515581174630-15890-0/minicluster-data/ts-0-root/wals/f8a79300516548dd91e26fd008eefeef/wal-000000006 (ops 26-30)
I20260812 06:19:43.022439 16054 log.cc:1079] T f8a79300516548dd91e26fd008eefeef P 7739cbc3fba84996b23290d1fc35872b: Deleting log segment in path: /tmp/dist-test-taskZHdGUU/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515581174630-15890-0/minicluster-data/ts-0-root/wals/f8a79300516548dd91e26fd008eefeef/wal-000000007 (ops 31-35)
I20260812 06:19:43.022468 16054 log.cc:1079] T f8a79300516548dd91e26fd008eefeef P 7739cbc3fba84996b23290d1fc35872b: Deleting log segment in path: /tmp/dist-test-taskZHdGUU/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515581174630-15890-0/minicluster-data/ts-0-root/wals/f8a79300516548dd91e26fd008eefeef/wal-000000008 (ops 36-40)
I20260812 06:19:43.022497 16054 log.cc:1079] T f8a79300516548dd91e26fd008eefeef P 7739cbc3fba84996b23290d1fc35872b: Deleting log segment in path: /tmp/dist-test-taskZHdGUU/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515581174630-15890-0/minicluster-data/ts-0-root/wals/f8a79300516548dd91e26fd008eefeef/wal-000000009 (ops 41-45)
I20260812 06:19:43.022526 16054 log.cc:1079] T f8a79300516548dd91e26fd008eefeef P 7739cbc3fba84996b23290d1fc35872b: Deleting log segment in path: /tmp/dist-test-taskZHdGUU/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515581174630-15890-0/minicluster-data/ts-0-root/wals/f8a79300516548dd91e26fd008eefeef/wal-000000010 (ops 46-50)
I20260812 06:19:43.022555 16054 log.cc:1079] T f8a79300516548dd91e26fd008eefeef P 7739cbc3fba84996b23290d1fc35872b: Deleting log segment in path: /tmp/dist-test-taskZHdGUU/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515581174630-15890-0/minicluster-data/ts-0-root/wals/f8a79300516548dd91e26fd008eefeef/wal-000000011 (ops 51-55)
I20260812 06:19:43.022584 16054 log.cc:1079] T f8a79300516548dd91e26fd008eefeef P 7739cbc3fba84996b23290d1fc35872b: Deleting log segment in path: /tmp/dist-test-taskZHdGUU/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515581174630-15890-0/minicluster-data/ts-0-root/wals/f8a79300516548dd91e26fd008eefeef/wal-000000012 (ops 56-60)
I20260812 06:19:43.022614 16054 log.cc:1079] T f8a79300516548dd91e26fd008eefeef P 7739cbc3fba84996b23290d1fc35872b: Deleting log segment in path: /tmp/dist-test-taskZHdGUU/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515581174630-15890-0/minicluster-data/ts-0-root/wals/f8a79300516548dd91e26fd008eefeef/wal-000000013 (ops 61-64)
I20260812 06:19:43.022641 16054 log.cc:1079] T f8a79300516548dd91e26fd008eefeef P 7739cbc3fba84996b23290d1fc35872b: Deleting log segment in path: /tmp/dist-test-taskZHdGUU/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515581174630-15890-0/minicluster-data/ts-0-root/wals/f8a79300516548dd91e26fd008eefeef/wal-000000014 (ops 65-69)
I20260812 06:19:43.044842 16054 maintenance_manager.cc:643] P 7739cbc3fba84996b23290d1fc35872b: LogGCOp(f8a79300516548dd91e26fd008eefeef) complete. Timing: real 0.023s	user 0.000s	sys 0.022s Metrics: {}
I20260812 06:19:43.045347 16156 maintenance_manager.cc:419] P 7739cbc3fba84996b23290d1fc35872b: Scheduling FlushDeltaMemStoresOp(f8a79300516548dd91e26fd008eefeef): perf score=3.181125
I20260812 06:19:43.062781 16054 maintenance_manager.cc:643] P 7739cbc3fba84996b23290d1fc35872b: FlushDeltaMemStoresOp(f8a79300516548dd91e26fd008eefeef) complete. Timing: real 0.017s	user 0.009s	sys 0.006s Metrics: {"bytes_written":4512900,"delete_count":0,"lbm_write_time_us":6487,"lbm_writes_lt_1ms":113,"reinsert_count":0,"update_count":550}
I20260812 06:19:43.063303 16156 maintenance_manager.cc:419] P 7739cbc3fba84996b23290d1fc35872b: Scheduling FlushDeltaMemStoresOp(f8a79300516548dd91e26fd008eefeef): perf score=2.188937
I20260812 06:19:43.077783 16054 maintenance_manager.cc:643] P 7739cbc3fba84996b23290d1fc35872b: FlushDeltaMemStoresOp(f8a79300516548dd91e26fd008eefeef) complete. Timing: real 0.014s	user 0.012s	sys 0.000s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":4856,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:19:43.078361 16156 maintenance_manager.cc:419] P 7739cbc3fba84996b23290d1fc35872b: Scheduling UndoDeltaBlockGCOp(f8a79300516548dd91e26fd008eefeef): 472 bytes on disk
I20260812 06:19:43.078837 16054 maintenance_manager.cc:643] P 7739cbc3fba84996b23290d1fc35872b: UndoDeltaBlockGCOp(f8a79300516548dd91e26fd008eefeef) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":71,"lbm_reads_lt_1ms":4}
I20260812 06:19:43.079308 16156 maintenance_manager.cc:419] P 7739cbc3fba84996b23290d1fc35872b: Scheduling MajorDeltaCompactionOp(f8a79300516548dd91e26fd008eefeef): perf score=1.000000
I20260812 06:19:43.278388 16054 maintenance_manager.cc:643] P 7739cbc3fba84996b23290d1fc35872b: MajorDeltaCompactionOp(f8a79300516548dd91e26fd008eefeef) complete. Timing: real 0.199s	user 0.135s	sys 0.055s Metrics: {"cfile_cache_miss":634,"cfile_cache_miss_bytes":28877316,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":539,"lbm_read_time_us":12216,"lbm_reads_lt_1ms":674,"lbm_write_time_us":33488,"lbm_writes_lt_1ms":643,"mutex_wait_us":266,"peak_mem_usage":75542472,"reinsert_count":0,"thread_start_us":82,"threads_started":1,"update_count":3000}
I20260812 06:19:43.278918 16156 maintenance_manager.cc:419] P 7739cbc3fba84996b23290d1fc35872b: Scheduling FlushDeltaMemStoresOp(f8a79300516548dd91e26fd008eefeef): perf score=14.095187
I20260812 06:19:43.330767 16054 maintenance_manager.cc:643] P 7739cbc3fba84996b23290d1fc35872b: FlushDeltaMemStoresOp(f8a79300516548dd91e26fd008eefeef) complete. Timing: real 0.052s	user 0.023s	sys 0.025s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":23429,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":402,"reinsert_count":0,"update_count":2000}
I20260812 06:19:43.331364 16156 maintenance_manager.cc:419] P 7739cbc3fba84996b23290d1fc35872b: Scheduling FlushDeltaMemStoresOp(f8a79300516548dd91e26fd008eefeef): perf score=2.188937
I20260812 06:19:43.353417 16054 maintenance_manager.cc:643] P 7739cbc3fba84996b23290d1fc35872b: FlushDeltaMemStoresOp(f8a79300516548dd91e26fd008eefeef) complete. Timing: real 0.022s	user 0.006s	sys 0.014s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5928,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:43.353977 16156 maintenance_manager.cc:419] P 7739cbc3fba84996b23290d1fc35872b: Scheduling MajorDeltaCompactionOp(f8a79300516548dd91e26fd008eefeef): perf score=1.000000
I20260812 06:19:43.524657 16054 maintenance_manager.cc:643] P 7739cbc3fba84996b23290d1fc35872b: MajorDeltaCompactionOp(f8a79300516548dd91e26fd008eefeef) complete. Timing: real 0.170s	user 0.098s	sys 0.060s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774689,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":573,"lbm_read_time_us":10091,"lbm_reads_lt_1ms":564,"lbm_write_time_us":25309,"lbm_writes_lt_1ms":543,"mutex_wait_us":252,"peak_mem_usage":63115900,"reinsert_count":0,"update_count":2500}
I20260812 06:19:43.525167 16156 maintenance_manager.cc:419] P 7739cbc3fba84996b23290d1fc35872b: Scheduling FlushDeltaMemStoresOp(f8a79300516548dd91e26fd008eefeef): perf score=14.095187
I20260812 06:19:43.571921 16054 maintenance_manager.cc:643] P 7739cbc3fba84996b23290d1fc35872b: FlushDeltaMemStoresOp(f8a79300516548dd91e26fd008eefeef) complete. Timing: real 0.047s	user 0.031s	sys 0.015s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":20161,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:43.572469 16156 maintenance_manager.cc:419] P 7739cbc3fba84996b23290d1fc35872b: Scheduling FlushDeltaMemStoresOp(f8a79300516548dd91e26fd008eefeef): perf score=2.188937
I20260812 06:19:43.582675 16054 maintenance_manager.cc:643] P 7739cbc3fba84996b23290d1fc35872b: FlushDeltaMemStoresOp(f8a79300516548dd91e26fd008eefeef) complete. Timing: real 0.010s	user 0.004s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3554,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:43.583326 16156 maintenance_manager.cc:419] P 7739cbc3fba84996b23290d1fc35872b: Scheduling MajorDeltaCompactionOp(f8a79300516548dd91e26fd008eefeef): perf score=1.000000
I20260812 06:19:43.740895 16054 maintenance_manager.cc:643] P 7739cbc3fba84996b23290d1fc35872b: MajorDeltaCompactionOp(f8a79300516548dd91e26fd008eefeef) complete. Timing: real 0.157s	user 0.117s	sys 0.033s 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":1201,"lbm_read_time_us":8937,"lbm_reads_lt_1ms":572,"lbm_write_time_us":26652,"lbm_writes_lt_1ms":543,"mutex_wait_us":327,"peak_mem_usage":63115900,"reinsert_count":0,"update_count":2500}
I20260812 06:19:43.741482 16156 maintenance_manager.cc:419] P 7739cbc3fba84996b23290d1fc35872b: Scheduling FlushDeltaMemStoresOp(f8a79300516548dd91e26fd008eefeef): perf score=11.118625
I20260812 06:19:43.778818 16054 maintenance_manager.cc:643] P 7739cbc3fba84996b23290d1fc35872b: FlushDeltaMemStoresOp(f8a79300516548dd91e26fd008eefeef) complete. Timing: real 0.037s	user 0.030s	sys 0.004s Metrics: {"bytes_written":12717737,"delete_count":0,"lbm_write_time_us":15617,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:19:43.779438 16156 maintenance_manager.cc:419] P 7739cbc3fba84996b23290d1fc35872b: Scheduling FlushDeltaMemStoresOp(f8a79300516548dd91e26fd008eefeef): perf score=2.188937
I20260812 06:19:43.802292 16054 maintenance_manager.cc:643] P 7739cbc3fba84996b23290d1fc35872b: FlushDeltaMemStoresOp(f8a79300516548dd91e26fd008eefeef) complete. Timing: real 0.023s	user 0.006s	sys 0.003s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":4196,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:19:43.802748 16156 maintenance_manager.cc:419] P 7739cbc3fba84996b23290d1fc35872b: Scheduling FlushDeltaMemStoresOp(f8a79300516548dd91e26fd008eefeef): perf score=2.188937
I20260812 06:19:43.813381 16054 maintenance_manager.cc:643] P 7739cbc3fba84996b23290d1fc35872b: FlushDeltaMemStoresOp(f8a79300516548dd91e26fd008eefeef) complete. Timing: real 0.010s	user 0.009s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3591,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:43.813923 16156 maintenance_manager.cc:419] P 7739cbc3fba84996b23290d1fc35872b: Scheduling MajorDeltaCompactionOp(f8a79300516548dd91e26fd008eefeef): perf score=1.000000
I20260812 06:19:43.954331 16054 maintenance_manager.cc:643] P 7739cbc3fba84996b23290d1fc35872b: MajorDeltaCompactionOp(f8a79300516548dd91e26fd008eefeef) complete. Timing: real 0.140s	user 0.094s	sys 0.043s Metrics: {"cfile_cache_miss":533,"cfile_cache_miss_bytes":24774801,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":1457,"lbm_read_time_us":8540,"lbm_reads_lt_1ms":573,"lbm_write_time_us":25496,"lbm_writes_lt_1ms":543,"peak_mem_usage":63115900,"reinsert_count":0,"update_count":2500}
I20260812 06:19:43.954850 16156 maintenance_manager.cc:419] P 7739cbc3fba84996b23290d1fc35872b: Scheduling FlushDeltaMemStoresOp(f8a79300516548dd91e26fd008eefeef): perf score=11.118625
I20260812 06:19:43.988756 16054 maintenance_manager.cc:643] P 7739cbc3fba84996b23290d1fc35872b: FlushDeltaMemStoresOp(f8a79300516548dd91e26fd008eefeef) complete. Timing: real 0.034s	user 0.021s	sys 0.011s Metrics: {"bytes_written":12717734,"delete_count":0,"lbm_write_time_us":14106,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:19:43.989326 16156 maintenance_manager.cc:419] P 7739cbc3fba84996b23290d1fc35872b: Scheduling FlushDeltaMemStoresOp(f8a79300516548dd91e26fd008eefeef): perf score=2.188937
I20260812 06:19:44.008728 16054 maintenance_manager.cc:643] P 7739cbc3fba84996b23290d1fc35872b: FlushDeltaMemStoresOp(f8a79300516548dd91e26fd008eefeef) complete. Timing: real 0.019s	user 0.006s	sys 0.005s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4379,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:44.009234 16156 maintenance_manager.cc:419] P 7739cbc3fba84996b23290d1fc35872b: Scheduling FlushDeltaMemStoresOp(f8a79300516548dd91e26fd008eefeef): perf score=2.188937
I20260812 06:19:44.018971 16054 maintenance_manager.cc:643] P 7739cbc3fba84996b23290d1fc35872b: FlushDeltaMemStoresOp(f8a79300516548dd91e26fd008eefeef) complete. Timing: real 0.010s	user 0.000s	sys 0.007s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3482,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:19:44.019479 16156 maintenance_manager.cc:419] P 7739cbc3fba84996b23290d1fc35872b: Scheduling MajorDeltaCompactionOp(f8a79300516548dd91e26fd008eefeef): perf score=1.000000
I20260812 06:19:44.173763 16054 maintenance_manager.cc:643] P 7739cbc3fba84996b23290d1fc35872b: MajorDeltaCompactionOp(f8a79300516548dd91e26fd008eefeef) complete. Timing: real 0.154s	user 0.122s	sys 0.028s Metrics: {"cfile_cache_miss":533,"cfile_cache_miss_bytes":24774798,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":607,"lbm_read_time_us":11760,"lbm_reads_lt_1ms":573,"lbm_write_time_us":29126,"lbm_writes_lt_1ms":543,"mutex_wait_us":288,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":18432,"update_count":2500}
I20260812 06:19:44.174460 16156 maintenance_manager.cc:419] P 7739cbc3fba84996b23290d1fc35872b: Scheduling FlushDeltaMemStoresOp(f8a79300516548dd91e26fd008eefeef): perf score=11.118625
I20260812 06:19:44.211745 16054 maintenance_manager.cc:643] P 7739cbc3fba84996b23290d1fc35872b: FlushDeltaMemStoresOp(f8a79300516548dd91e26fd008eefeef) complete. Timing: real 0.037s	user 0.022s	sys 0.015s Metrics: {"bytes_written":12717736,"delete_count":0,"lbm_write_time_us":15739,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:19:44.212457 16156 maintenance_manager.cc:419] P 7739cbc3fba84996b23290d1fc35872b: Scheduling FlushDeltaMemStoresOp(f8a79300516548dd91e26fd008eefeef): perf score=2.188937
I20260812 06:19:44.239523 16054 maintenance_manager.cc:643] P 7739cbc3fba84996b23290d1fc35872b: FlushDeltaMemStoresOp(f8a79300516548dd91e26fd008eefeef) complete. Timing: real 0.027s	user 0.000s	sys 0.012s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":5033,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:19:44.240005 16156 maintenance_manager.cc:419] P 7739cbc3fba84996b23290d1fc35872b: Scheduling FlushDeltaMemStoresOp(f8a79300516548dd91e26fd008eefeef): perf score=2.188937
I20260812 06:19:44.250299 16054 maintenance_manager.cc:643] P 7739cbc3fba84996b23290d1fc35872b: FlushDeltaMemStoresOp(f8a79300516548dd91e26fd008eefeef) complete. Timing: real 0.010s	user 0.003s	sys 0.006s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3692,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:44.250787 16156 maintenance_manager.cc:419] P 7739cbc3fba84996b23290d1fc35872b: Scheduling MajorDeltaCompactionOp(f8a79300516548dd91e26fd008eefeef): perf score=1.000000
I20260812 06:19:44.402921 16054 maintenance_manager.cc:643] P 7739cbc3fba84996b23290d1fc35872b: MajorDeltaCompactionOp(f8a79300516548dd91e26fd008eefeef) complete. Timing: real 0.152s	user 0.120s	sys 0.028s Metrics: {"cfile_cache_miss":533,"cfile_cache_miss_bytes":24774800,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":499,"lbm_read_time_us":11264,"lbm_reads_lt_1ms":573,"lbm_write_time_us":27181,"lbm_writes_lt_1ms":543,"mutex_wait_us":263,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":5632,"update_count":2500}
I20260812 06:19:44.403527 16156 maintenance_manager.cc:419] P 7739cbc3fba84996b23290d1fc35872b: Scheduling FlushDeltaMemStoresOp(f8a79300516548dd91e26fd008eefeef): perf score=11.118625
I20260812 06:19:44.436569 16054 maintenance_manager.cc:643] P 7739cbc3fba84996b23290d1fc35872b: FlushDeltaMemStoresOp(f8a79300516548dd91e26fd008eefeef) complete. Timing: real 0.033s	user 0.028s	sys 0.004s Metrics: {"bytes_written":12717734,"delete_count":0,"lbm_write_time_us":13782,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:19:44.437126 16156 maintenance_manager.cc:419] P 7739cbc3fba84996b23290d1fc35872b: Scheduling FlushDeltaMemStoresOp(f8a79300516548dd91e26fd008eefeef): perf score=2.188937
I20260812 06:19:44.452337 16054 maintenance_manager.cc:643] P 7739cbc3fba84996b23290d1fc35872b: FlushDeltaMemStoresOp(f8a79300516548dd91e26fd008eefeef) complete. Timing: real 0.015s	user 0.010s	sys 0.004s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":5546,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:19:44.452867 16156 maintenance_manager.cc:419] P 7739cbc3fba84996b23290d1fc35872b: Scheduling FlushMRSOp(f8a79300516548dd91e26fd008eefeef): perf score=1.000000
I20260812 06:19:44.486238 16054 maintenance_manager.cc:643] P 7739cbc3fba84996b23290d1fc35872b: FlushMRSOp(f8a79300516548dd91e26fd008eefeef) complete. Timing: real 0.033s	user 0.031s	sys 0.000s Metrics: {"bytes_written":1316419,"cfile_init":1,"dirs.queue_time_us":76,"dirs.run_cpu_time_us":286,"dirs.run_wall_time_us":1519,"drs_written":1,"lbm_read_time_us":45,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1722,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":32,"spinlock_wait_cycles":768}
I20260812 06:19:44.487030 16156 maintenance_manager.cc:419] P 7739cbc3fba84996b23290d1fc35872b: Scheduling LogGCOp(f8a79300516548dd91e26fd008eefeef): free 129320520 bytes of WAL
I20260812 06:19:44.487303 16054 log_reader.cc:385] T f8a79300516548dd91e26fd008eefeef: removed 13 log segments from log reader
I20260812 06:19:44.487390 16054 log.cc:1079] T f8a79300516548dd91e26fd008eefeef P 7739cbc3fba84996b23290d1fc35872b: Deleting log segment in path: /tmp/dist-test-taskZHdGUU/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515581174630-15890-0/minicluster-data/ts-0-root/wals/f8a79300516548dd91e26fd008eefeef/wal-000000015 (ops 70-74)
I20260812 06:19:44.487464 16054 log.cc:1079] T f8a79300516548dd91e26fd008eefeef P 7739cbc3fba84996b23290d1fc35872b: Deleting log segment in path: /tmp/dist-test-taskZHdGUU/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515581174630-15890-0/minicluster-data/ts-0-root/wals/f8a79300516548dd91e26fd008eefeef/wal-000000016 (ops 75-78)
I20260812 06:19:44.487525 16054 log.cc:1079] T f8a79300516548dd91e26fd008eefeef P 7739cbc3fba84996b23290d1fc35872b: Deleting log segment in path: /tmp/dist-test-taskZHdGUU/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515581174630-15890-0/minicluster-data/ts-0-root/wals/f8a79300516548dd91e26fd008eefeef/wal-000000017 (ops 79-83)
I20260812 06:19:44.487583 16054 log.cc:1079] T f8a79300516548dd91e26fd008eefeef P 7739cbc3fba84996b23290d1fc35872b: Deleting log segment in path: /tmp/dist-test-taskZHdGUU/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515581174630-15890-0/minicluster-data/ts-0-root/wals/f8a79300516548dd91e26fd008eefeef/wal-000000018 (ops 84-88)
I20260812 06:19:44.487691 16054 log.cc:1079] T f8a79300516548dd91e26fd008eefeef P 7739cbc3fba84996b23290d1fc35872b: Deleting log segment in path: /tmp/dist-test-taskZHdGUU/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515581174630-15890-0/minicluster-data/ts-0-root/wals/f8a79300516548dd91e26fd008eefeef/wal-000000019 (ops 89-93)
I20260812 06:19:44.487764 16054 log.cc:1079] T f8a79300516548dd91e26fd008eefeef P 7739cbc3fba84996b23290d1fc35872b: Deleting log segment in path: /tmp/dist-test-taskZHdGUU/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515581174630-15890-0/minicluster-data/ts-0-root/wals/f8a79300516548dd91e26fd008eefeef/wal-000000020 (ops 94-98)
I20260812 06:19:44.487820 16054 log.cc:1079] T f8a79300516548dd91e26fd008eefeef P 7739cbc3fba84996b23290d1fc35872b: Deleting log segment in path: /tmp/dist-test-taskZHdGUU/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515581174630-15890-0/minicluster-data/ts-0-root/wals/f8a79300516548dd91e26fd008eefeef/wal-000000021 (ops 99-103)
I20260812 06:19:44.487874 16054 log.cc:1079] T f8a79300516548dd91e26fd008eefeef P 7739cbc3fba84996b23290d1fc35872b: Deleting log segment in path: /tmp/dist-test-taskZHdGUU/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515581174630-15890-0/minicluster-data/ts-0-root/wals/f8a79300516548dd91e26fd008eefeef/wal-000000022 (ops 104-108)
I20260812 06:19:44.487926 16054 log.cc:1079] T f8a79300516548dd91e26fd008eefeef P 7739cbc3fba84996b23290d1fc35872b: Deleting log segment in path: /tmp/dist-test-taskZHdGUU/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515581174630-15890-0/minicluster-data/ts-0-root/wals/f8a79300516548dd91e26fd008eefeef/wal-000000023 (ops 109-112)
I20260812 06:19:44.487977 16054 log.cc:1079] T f8a79300516548dd91e26fd008eefeef P 7739cbc3fba84996b23290d1fc35872b: Deleting log segment in path: /tmp/dist-test-taskZHdGUU/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515581174630-15890-0/minicluster-data/ts-0-root/wals/f8a79300516548dd91e26fd008eefeef/wal-000000024 (ops 113-117)
I20260812 06:19:44.488027 16054 log.cc:1079] T f8a79300516548dd91e26fd008eefeef P 7739cbc3fba84996b23290d1fc35872b: Deleting log segment in path: /tmp/dist-test-taskZHdGUU/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515581174630-15890-0/minicluster-data/ts-0-root/wals/f8a79300516548dd91e26fd008eefeef/wal-000000025 (ops 118-122)
I20260812 06:19:44.488082 16054 log.cc:1079] T f8a79300516548dd91e26fd008eefeef P 7739cbc3fba84996b23290d1fc35872b: Deleting log segment in path: /tmp/dist-test-taskZHdGUU/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515581174630-15890-0/minicluster-data/ts-0-root/wals/f8a79300516548dd91e26fd008eefeef/wal-000000026 (ops 123-127)
I20260812 06:19:44.488137 16054 log.cc:1079] T f8a79300516548dd91e26fd008eefeef P 7739cbc3fba84996b23290d1fc35872b: Deleting log segment in path: /tmp/dist-test-taskZHdGUU/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515581174630-15890-0/minicluster-data/ts-0-root/wals/f8a79300516548dd91e26fd008eefeef/wal-000000027 (ops 128-132)
I20260812 06:19:44.514611 16054 maintenance_manager.cc:643] P 7739cbc3fba84996b23290d1fc35872b: LogGCOp(f8a79300516548dd91e26fd008eefeef) complete. Timing: real 0.027s	user 0.001s	sys 0.023s Metrics: {}
I20260812 06:19:44.515202 16156 maintenance_manager.cc:419] P 7739cbc3fba84996b23290d1fc35872b: Scheduling FlushDeltaMemStoresOp(f8a79300516548dd91e26fd008eefeef): perf score=6.157687
I20260812 06:19:44.543099 16054 maintenance_manager.cc:643] P 7739cbc3fba84996b23290d1fc35872b: FlushDeltaMemStoresOp(f8a79300516548dd91e26fd008eefeef) complete. Timing: real 0.028s	user 0.013s	sys 0.012s Metrics: {"bytes_written":8205077,"delete_count":0,"lbm_write_time_us":11256,"lbm_writes_lt_1ms":203,"reinsert_count":0,"update_count":1000}
I20260812 06:19:44.543659 16156 maintenance_manager.cc:419] P 7739cbc3fba84996b23290d1fc35872b: Scheduling LogGCOp(f8a79300516548dd91e26fd008eefeef): free 11564893 bytes of WAL
I20260812 06:19:44.544057 16054 log_reader.cc:385] T f8a79300516548dd91e26fd008eefeef: removed 1 log segments from log reader
I20260812 06:19:44.544111 16054 log.cc:1079] T f8a79300516548dd91e26fd008eefeef P 7739cbc3fba84996b23290d1fc35872b: Deleting log segment in path: /tmp/dist-test-taskZHdGUU/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515581174630-15890-0/minicluster-data/ts-0-root/wals/f8a79300516548dd91e26fd008eefeef/wal-000000028 (ops 133-136)
I20260812 06:19:44.546095 16054 maintenance_manager.cc:643] P 7739cbc3fba84996b23290d1fc35872b: LogGCOp(f8a79300516548dd91e26fd008eefeef) complete. Timing: real 0.002s	user 0.000s	sys 0.000s Metrics: {}
I20260812 06:19:44.546468 16156 maintenance_manager.cc:419] P 7739cbc3fba84996b23290d1fc35872b: Scheduling MajorDeltaCompactionOp(f8a79300516548dd91e26fd008eefeef): perf score=1.000000
I20260812 06:19:44.697614 16054 maintenance_manager.cc:643] P 7739cbc3fba84996b23290d1fc35872b: MajorDeltaCompactionOp(f8a79300516548dd91e26fd008eefeef) complete. Timing: real 0.151s	user 0.120s	sys 0.030s Metrics: {"cfile_cache_miss":633,"cfile_cache_miss_bytes":28877210,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":361,"lbm_read_time_us":12105,"lbm_reads_lt_1ms":665,"lbm_write_time_us":27660,"lbm_writes_lt_1ms":643,"mutex_wait_us":44,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":16384,"thread_start_us":94,"threads_started":1,"update_count":3000}
I20260812 06:19:44.698356 16156 maintenance_manager.cc:419] P 7739cbc3fba84996b23290d1fc35872b: Scheduling UndoDeltaBlockGCOp(f8a79300516548dd91e26fd008eefeef): 492 bytes on disk
I20260812 06:19:44.698971 16054 maintenance_manager.cc:643] P 7739cbc3fba84996b23290d1fc35872b: UndoDeltaBlockGCOp(f8a79300516548dd91e26fd008eefeef) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":76,"lbm_reads_lt_1ms":4}
I20260812 06:19:44.699950 16156 maintenance_manager.cc:419] P 7739cbc3fba84996b23290d1fc35872b: Scheduling FlushDeltaMemStoresOp(f8a79300516548dd91e26fd008eefeef): perf score=14.095187
I20260812 06:19:44.741483 16054 maintenance_manager.cc:643] P 7739cbc3fba84996b23290d1fc35872b: FlushDeltaMemStoresOp(f8a79300516548dd91e26fd008eefeef) complete. Timing: real 0.041s	user 0.023s	sys 0.017s Metrics: {"bytes_written":16409903,"delete_count":0,"lbm_write_time_us":17988,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:44.742691 16156 maintenance_manager.cc:419] P 7739cbc3fba84996b23290d1fc35872b: Scheduling FlushDeltaMemStoresOp(f8a79300516548dd91e26fd008eefeef): perf score=2.188937
I20260812 06:19:44.759435 16054 maintenance_manager.cc:643] P 7739cbc3fba84996b23290d1fc35872b: FlushDeltaMemStoresOp(f8a79300516548dd91e26fd008eefeef) complete. Timing: real 0.017s	user 0.010s	sys 0.003s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":6155,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:44.759900 16156 maintenance_manager.cc:419] P 7739cbc3fba84996b23290d1fc35872b: Scheduling MajorDeltaCompactionOp(f8a79300516548dd91e26fd008eefeef): perf score=1.000000
I20260812 06:19:44.909157 16054 maintenance_manager.cc:643] P 7739cbc3fba84996b23290d1fc35872b: MajorDeltaCompactionOp(f8a79300516548dd91e26fd008eefeef) complete. Timing: real 0.149s	user 0.104s	sys 0.040s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774689,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":957,"lbm_read_time_us":10669,"lbm_reads_lt_1ms":568,"lbm_write_time_us":25049,"lbm_writes_lt_1ms":543,"peak_mem_usage":63115900,"reinsert_count":0,"update_count":2500}
I20260812 06:19:44.909708 16156 maintenance_manager.cc:419] P 7739cbc3fba84996b23290d1fc35872b: Scheduling FlushDeltaMemStoresOp(f8a79300516548dd91e26fd008eefeef): perf score=14.095187
I20260812 06:19:44.970886 16054 maintenance_manager.cc:643] P 7739cbc3fba84996b23290d1fc35872b: FlushDeltaMemStoresOp(f8a79300516548dd91e26fd008eefeef) complete. Timing: real 0.061s	user 0.028s	sys 0.016s Metrics: {"bytes_written":16409900,"delete_count":0,"lbm_write_time_us":20561,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":402,"reinsert_count":0,"update_count":2000}
I20260812 06:19:44.971500 16156 maintenance_manager.cc:419] P 7739cbc3fba84996b23290d1fc35872b: Scheduling FlushDeltaMemStoresOp(f8a79300516548dd91e26fd008eefeef): perf score=2.188937
I20260812 06:19:44.982708 16054 maintenance_manager.cc:643] P 7739cbc3fba84996b23290d1fc35872b: FlushDeltaMemStoresOp(f8a79300516548dd91e26fd008eefeef) complete. Timing: real 0.011s	user 0.009s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3684,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:44.983371 16156 maintenance_manager.cc:419] P 7739cbc3fba84996b23290d1fc35872b: Scheduling MajorDeltaCompactionOp(f8a79300516548dd91e26fd008eefeef): perf score=1.000000
I20260812 06:19:45.155752 16054 maintenance_manager.cc:643] P 7739cbc3fba84996b23290d1fc35872b: MajorDeltaCompactionOp(f8a79300516548dd91e26fd008eefeef) complete. Timing: real 0.172s	user 0.102s	sys 0.063s 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":515,"lbm_read_time_us":10219,"lbm_reads_lt_1ms":572,"lbm_write_time_us":30235,"lbm_writes_lt_1ms":543,"mutex_wait_us":293,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":24832,"update_count":2500}
I20260812 06:19:45.156366 16156 maintenance_manager.cc:419] P 7739cbc3fba84996b23290d1fc35872b: Scheduling FlushDeltaMemStoresOp(f8a79300516548dd91e26fd008eefeef): perf score=14.095187
I20260812 06:19:45.212656 16054 maintenance_manager.cc:643] P 7739cbc3fba84996b23290d1fc35872b: FlushDeltaMemStoresOp(f8a79300516548dd91e26fd008eefeef) complete. Timing: real 0.056s	user 0.025s	sys 0.028s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":20101,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:45.213215 16156 maintenance_manager.cc:419] P 7739cbc3fba84996b23290d1fc35872b: Scheduling FlushDeltaMemStoresOp(f8a79300516548dd91e26fd008eefeef): perf score=2.188937
I20260812 06:19:45.223752 16054 maintenance_manager.cc:643] P 7739cbc3fba84996b23290d1fc35872b: FlushDeltaMemStoresOp(f8a79300516548dd91e26fd008eefeef) complete. Timing: real 0.010s	user 0.010s	sys 0.000s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":3840,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:45.224180 16156 maintenance_manager.cc:419] P 7739cbc3fba84996b23290d1fc35872b: Scheduling MajorDeltaCompactionOp(f8a79300516548dd91e26fd008eefeef): perf score=1.000000
I20260812 06:19:45.385790 16054 maintenance_manager.cc:643] P 7739cbc3fba84996b23290d1fc35872b: MajorDeltaCompactionOp(f8a79300516548dd91e26fd008eefeef) complete. Timing: real 0.161s	user 0.110s	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":236,"lbm_read_time_us":12474,"lbm_reads_lt_1ms":572,"lbm_write_time_us":25052,"lbm_writes_lt_1ms":543,"mutex_wait_us":47,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":30720,"update_count":2500}
I20260812 06:19:45.386333 16156 maintenance_manager.cc:419] P 7739cbc3fba84996b23290d1fc35872b: Scheduling FlushDeltaMemStoresOp(f8a79300516548dd91e26fd008eefeef): perf score=11.118625
I20260812 06:19:45.417704 16054 maintenance_manager.cc:643] P 7739cbc3fba84996b23290d1fc35872b: FlushDeltaMemStoresOp(f8a79300516548dd91e26fd008eefeef) complete. Timing: real 0.031s	user 0.016s	sys 0.013s Metrics: {"bytes_written":12717736,"delete_count":0,"lbm_write_time_us":12911,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:19:45.418296 16156 maintenance_manager.cc:419] P 7739cbc3fba84996b23290d1fc35872b: Scheduling FlushDeltaMemStoresOp(f8a79300516548dd91e26fd008eefeef): perf score=2.188937
I20260812 06:19:45.438110 16054 maintenance_manager.cc:643] P 7739cbc3fba84996b23290d1fc35872b: FlushDeltaMemStoresOp(f8a79300516548dd91e26fd008eefeef) complete. Timing: real 0.020s	user 0.006s	sys 0.011s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":5359,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:19:45.438582 16156 maintenance_manager.cc:419] P 7739cbc3fba84996b23290d1fc35872b: Scheduling MajorDeltaCompactionOp(f8a79300516548dd91e26fd008eefeef): perf score=1.000000
I20260812 06:19:45.581575 16054 maintenance_manager.cc:643] P 7739cbc3fba84996b23290d1fc35872b: MajorDeltaCompactionOp(f8a79300516548dd91e26fd008eefeef) complete. Timing: real 0.143s	user 0.076s	sys 0.063s 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":364,"lbm_read_time_us":10630,"lbm_reads_lt_1ms":472,"lbm_write_time_us":21978,"lbm_writes_lt_1ms":443,"mutex_wait_us":23,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":12416,"update_count":2000}
I20260812 06:19:45.582180 16156 maintenance_manager.cc:419] P 7739cbc3fba84996b23290d1fc35872b: Scheduling FlushDeltaMemStoresOp(f8a79300516548dd91e26fd008eefeef): perf score=11.118625
I20260812 06:19:45.617201 16054 maintenance_manager.cc:643] P 7739cbc3fba84996b23290d1fc35872b: FlushDeltaMemStoresOp(f8a79300516548dd91e26fd008eefeef) complete. Timing: real 0.035s	user 0.020s	sys 0.014s Metrics: {"bytes_written":12717736,"delete_count":0,"lbm_write_time_us":14845,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:19:45.617844 16156 maintenance_manager.cc:419] P 7739cbc3fba84996b23290d1fc35872b: Scheduling FlushDeltaMemStoresOp(f8a79300516548dd91e26fd008eefeef): perf score=2.188937
I20260812 06:19:45.640558 16054 maintenance_manager.cc:643] P 7739cbc3fba84996b23290d1fc35872b: FlushDeltaMemStoresOp(f8a79300516548dd91e26fd008eefeef) complete. Timing: real 0.023s	user 0.010s	sys 0.001s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":4588,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:19:45.641156 16156 maintenance_manager.cc:419] P 7739cbc3fba84996b23290d1fc35872b: Scheduling FlushDeltaMemStoresOp(f8a79300516548dd91e26fd008eefeef): perf score=2.188937
I20260812 06:19:45.651322 16054 maintenance_manager.cc:643] P 7739cbc3fba84996b23290d1fc35872b: FlushDeltaMemStoresOp(f8a79300516548dd91e26fd008eefeef) complete. Timing: real 0.010s	user 0.008s	sys 0.001s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":3543,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:45.651888 16156 maintenance_manager.cc:419] P 7739cbc3fba84996b23290d1fc35872b: Scheduling MajorDeltaCompactionOp(f8a79300516548dd91e26fd008eefeef): perf score=1.000000
I20260812 06:19:45.802403 16054 maintenance_manager.cc:643] P 7739cbc3fba84996b23290d1fc35872b: MajorDeltaCompactionOp(f8a79300516548dd91e26fd008eefeef) complete. Timing: real 0.150s	user 0.113s	sys 0.037s Metrics: {"cfile_cache_miss":533,"cfile_cache_miss_bytes":24774799,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":695,"lbm_read_time_us":11640,"lbm_reads_lt_1ms":573,"lbm_write_time_us":28695,"lbm_writes_lt_1ms":543,"mutex_wait_us":304,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":12032,"update_count":2500}
I20260812 06:19:45.802932 16156 maintenance_manager.cc:419] P 7739cbc3fba84996b23290d1fc35872b: Scheduling FlushDeltaMemStoresOp(f8a79300516548dd91e26fd008eefeef): perf score=10.126437
I20260812 06:19:45.832967 16054 maintenance_manager.cc:643] P 7739cbc3fba84996b23290d1fc35872b: FlushDeltaMemStoresOp(f8a79300516548dd91e26fd008eefeef) complete. Timing: real 0.030s	user 0.025s	sys 0.004s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":12369,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:19:45.834450 16156 maintenance_manager.cc:419] P 7739cbc3fba84996b23290d1fc35872b: Scheduling FlushDeltaMemStoresOp(f8a79300516548dd91e26fd008eefeef): perf score=2.188937
I20260812 06:19:45.850518 16054 maintenance_manager.cc:643] P 7739cbc3fba84996b23290d1fc35872b: FlushDeltaMemStoresOp(f8a79300516548dd91e26fd008eefeef) complete. Timing: real 0.016s	user 0.011s	sys 0.003s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6228,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:45.851104 16156 maintenance_manager.cc:419] P 7739cbc3fba84996b23290d1fc35872b: Scheduling FlushMRSOp(f8a79300516548dd91e26fd008eefeef): perf score=1.000000
I20260812 06:19:45.876219 16054 maintenance_manager.cc:643] P 7739cbc3fba84996b23290d1fc35872b: FlushMRSOp(f8a79300516548dd91e26fd008eefeef) complete. Timing: real 0.025s	user 0.021s	sys 0.004s Metrics: {"bytes_written":1193507,"cfile_init":1,"dirs.queue_time_us":75,"dirs.run_cpu_time_us":204,"dirs.run_wall_time_us":1281,"drs_written":1,"lbm_read_time_us":37,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1364,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":29}
I20260812 06:19:45.876989 16156 maintenance_manager.cc:419] P 7739cbc3fba84996b23290d1fc35872b: Scheduling LogGCOp(f8a79300516548dd91e26fd008eefeef): free 112692608 bytes of WAL
I20260812 06:19:45.877244 16054 log_reader.cc:385] T f8a79300516548dd91e26fd008eefeef: removed 11 log segments from log reader
I20260812 06:19:45.877296 16054 log.cc:1079] T f8a79300516548dd91e26fd008eefeef P 7739cbc3fba84996b23290d1fc35872b: Deleting log segment in path: /tmp/dist-test-taskZHdGUU/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515581174630-15890-0/minicluster-data/ts-0-root/wals/f8a79300516548dd91e26fd008eefeef/wal-000000029 (ops 137-141)
I20260812 06:19:45.877326 16054 log.cc:1079] T f8a79300516548dd91e26fd008eefeef P 7739cbc3fba84996b23290d1fc35872b: Deleting log segment in path: /tmp/dist-test-taskZHdGUU/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515581174630-15890-0/minicluster-data/ts-0-root/wals/f8a79300516548dd91e26fd008eefeef/wal-000000030 (ops 142-146)
I20260812 06:19:45.877343 16054 log.cc:1079] T f8a79300516548dd91e26fd008eefeef P 7739cbc3fba84996b23290d1fc35872b: Deleting log segment in path: /tmp/dist-test-taskZHdGUU/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515581174630-15890-0/minicluster-data/ts-0-root/wals/f8a79300516548dd91e26fd008eefeef/wal-000000031 (ops 147-151)
I20260812 06:19:45.877357 16054 log.cc:1079] T f8a79300516548dd91e26fd008eefeef P 7739cbc3fba84996b23290d1fc35872b: Deleting log segment in path: /tmp/dist-test-taskZHdGUU/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515581174630-15890-0/minicluster-data/ts-0-root/wals/f8a79300516548dd91e26fd008eefeef/wal-000000032 (ops 152-156)
I20260812 06:19:45.877375 16054 log.cc:1079] T f8a79300516548dd91e26fd008eefeef P 7739cbc3fba84996b23290d1fc35872b: Deleting log segment in path: /tmp/dist-test-taskZHdGUU/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515581174630-15890-0/minicluster-data/ts-0-root/wals/f8a79300516548dd91e26fd008eefeef/wal-000000033 (ops 157-161)
I20260812 06:19:45.877410 16054 log.cc:1079] T f8a79300516548dd91e26fd008eefeef P 7739cbc3fba84996b23290d1fc35872b: Deleting log segment in path: /tmp/dist-test-taskZHdGUU/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515581174630-15890-0/minicluster-data/ts-0-root/wals/f8a79300516548dd91e26fd008eefeef/wal-000000034 (ops 162-166)
I20260812 06:19:45.877434 16054 log.cc:1079] T f8a79300516548dd91e26fd008eefeef P 7739cbc3fba84996b23290d1fc35872b: Deleting log segment in path: /tmp/dist-test-taskZHdGUU/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515581174630-15890-0/minicluster-data/ts-0-root/wals/f8a79300516548dd91e26fd008eefeef/wal-000000035 (ops 167-171)
I20260812 06:19:45.877465 16054 log.cc:1079] T f8a79300516548dd91e26fd008eefeef P 7739cbc3fba84996b23290d1fc35872b: Deleting log segment in path: /tmp/dist-test-taskZHdGUU/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515581174630-15890-0/minicluster-data/ts-0-root/wals/f8a79300516548dd91e26fd008eefeef/wal-000000036 (ops 172-176)
I20260812 06:19:45.877494 16054 log.cc:1079] T f8a79300516548dd91e26fd008eefeef P 7739cbc3fba84996b23290d1fc35872b: Deleting log segment in path: /tmp/dist-test-taskZHdGUU/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515581174630-15890-0/minicluster-data/ts-0-root/wals/f8a79300516548dd91e26fd008eefeef/wal-000000037 (ops 177-181)
I20260812 06:19:45.877523 16054 log.cc:1079] T f8a79300516548dd91e26fd008eefeef P 7739cbc3fba84996b23290d1fc35872b: Deleting log segment in path: /tmp/dist-test-taskZHdGUU/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515581174630-15890-0/minicluster-data/ts-0-root/wals/f8a79300516548dd91e26fd008eefeef/wal-000000038 (ops 182-186)
I20260812 06:19:45.877555 16054 log.cc:1079] T f8a79300516548dd91e26fd008eefeef P 7739cbc3fba84996b23290d1fc35872b: Deleting log segment in path: /tmp/dist-test-taskZHdGUU/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515581174630-15890-0/minicluster-data/ts-0-root/wals/f8a79300516548dd91e26fd008eefeef/wal-000000039 (ops 187-191)
I20260812 06:19:45.896556 16054 maintenance_manager.cc:643] P 7739cbc3fba84996b23290d1fc35872b: LogGCOp(f8a79300516548dd91e26fd008eefeef) complete. Timing: real 0.019s	user 0.000s	sys 0.019s Metrics: {}
I20260812 06:19:45.897078 16156 maintenance_manager.cc:419] P 7739cbc3fba84996b23290d1fc35872b: Scheduling FlushDeltaMemStoresOp(f8a79300516548dd91e26fd008eefeef): perf score=3.181125
I20260812 06:19:45.909391 16054 maintenance_manager.cc:643] P 7739cbc3fba84996b23290d1fc35872b: FlushDeltaMemStoresOp(f8a79300516548dd91e26fd008eefeef) complete. Timing: real 0.012s	user 0.009s	sys 0.000s Metrics: {"bytes_written":4512900,"delete_count":0,"lbm_write_time_us":3914,"lbm_writes_lt_1ms":113,"reinsert_count":0,"update_count":550}
I20260812 06:19:45.909902 16156 maintenance_manager.cc:419] P 7739cbc3fba84996b23290d1fc35872b: Scheduling FlushDeltaMemStoresOp(f8a79300516548dd91e26fd008eefeef): perf score=2.188937
I20260812 06:19:45.924424 16054 maintenance_manager.cc:643] P 7739cbc3fba84996b23290d1fc35872b: FlushDeltaMemStoresOp(f8a79300516548dd91e26fd008eefeef) complete. Timing: real 0.014s	user 0.006s	sys 0.007s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":5049,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:19:45.925020 16156 maintenance_manager.cc:419] P 7739cbc3fba84996b23290d1fc35872b: Scheduling UndoDeltaBlockGCOp(f8a79300516548dd91e26fd008eefeef): 463 bytes on disk
I20260812 06:19:45.925602 16054 maintenance_manager.cc:643] P 7739cbc3fba84996b23290d1fc35872b: UndoDeltaBlockGCOp(f8a79300516548dd91e26fd008eefeef) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":71,"lbm_reads_lt_1ms":4}
I20260812 06:19:45.926254 16156 maintenance_manager.cc:419] P 7739cbc3fba84996b23290d1fc35872b: Scheduling MajorDeltaCompactionOp(f8a79300516548dd91e26fd008eefeef): perf score=1.000000
I20260812 06:19:46.048079 15890 heavy-update-compaction-itest.cc:229] Time spent updating: real 4.582s	user 1.687s	sys 0.106s
I20260812 06:19:46.082242 16054 maintenance_manager.cc:643] P 7739cbc3fba84996b23290d1fc35872b: MajorDeltaCompactionOp(f8a79300516548dd91e26fd008eefeef) complete. Timing: real 0.156s	user 0.109s	sys 0.044s Metrics: {"cfile_cache_miss":634,"cfile_cache_miss_bytes":28877326,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"lbm_read_time_us":10456,"lbm_reads_lt_1ms":670,"lbm_write_time_us":32933,"lbm_writes_lt_1ms":643,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":896,"update_count":3000}
I20260812 06:19:46.082754 16156 maintenance_manager.cc:419] P 7739cbc3fba84996b23290d1fc35872b: Scheduling FlushDeltaMemStoresOp(f8a79300516548dd91e26fd008eefeef): perf score=10.126437
I20260812 06:19:46.115738 16054 maintenance_manager.cc:643] P 7739cbc3fba84996b23290d1fc35872b: FlushDeltaMemStoresOp(f8a79300516548dd91e26fd008eefeef) complete. Timing: real 0.033s	user 0.010s	sys 0.023s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":12344,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:19:46.116286 16156 maintenance_manager.cc:419] P 7739cbc3fba84996b23290d1fc35872b: Scheduling MajorDeltaCompactionOp(f8a79300516548dd91e26fd008eefeef): perf score=1.000000
I20260812 06:19:46.119765 15890 heavy-update-compaction-itest.cc:265] Time spent scanning: real 0.071s	user 0.004s	sys 0.000s
I20260812 06:19:46.120405 15890 tablet_server.cc:179] TabletServer@127.15.132.129:0 shutting down...
I20260812 06:19:46.213064 16054 maintenance_manager.cc:643] P 7739cbc3fba84996b23290d1fc35872b: MajorDeltaCompactionOp(f8a79300516548dd91e26fd008eefeef) complete. Timing: real 0.097s	user 0.060s	sys 0.036s Metrics: {"cfile_cache_miss":331,"cfile_cache_miss_bytes":16569746,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":1,"delta_iterators_relevant":1,"dirs.queue_time_us":323,"lbm_read_time_us":7668,"lbm_reads_lt_1ms":367,"lbm_write_time_us":15112,"lbm_writes_lt_1ms":343,"mutex_wait_us":76,"peak_mem_usage":38262756,"reinsert_count":0,"spinlock_wait_cycles":31744,"update_count":1500}
I20260812 06:19:46.213871 15890 ts_tablet_manager.cc:1507] Shutting down tablet manager...
I20260812 06:19:46.214313 15890 tablet_replica.cc:333] T f8a79300516548dd91e26fd008eefeef P 7739cbc3fba84996b23290d1fc35872b: stopping tablet replica
I20260812 06:19:46.214561 15890 raft_consensus.cc:2243] T f8a79300516548dd91e26fd008eefeef P 7739cbc3fba84996b23290d1fc35872b [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:19:46.214797 15890 raft_consensus.cc:2272] T f8a79300516548dd91e26fd008eefeef P 7739cbc3fba84996b23290d1fc35872b [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:19:46.219403 15890 tablet_server.cc:196] TabletServer@127.15.132.129:0 shutdown complete.
I20260812 06:19:46.245045 15890 master.cc:562] Master@127.15.132.190:35197 shutting down...
I20260812 06:19:46.248616 15890 raft_consensus.cc:2243] T 00000000000000000000000000000000 P f6d371230bfa4c1eaec5db66c894c30b [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:19:46.248801 15890 raft_consensus.cc:2272] T 00000000000000000000000000000000 P f6d371230bfa4c1eaec5db66c894c30b [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:19:46.248876 15890 tablet_replica.cc:333] T 00000000000000000000000000000000 P f6d371230bfa4c1eaec5db66c894c30b: stopping tablet replica
I20260812 06:19:46.261279 15890 master.cc:584] Master@127.15.132.190:35197 shutdown complete.
[       OK ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/0 (5149 ms)
[ RUN      ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/1
I20260812 06:19:46.334631 15890 internal_mini_cluster.cc:156] Creating distributed mini masters. Addrs: 127.15.132.190:35993
I20260812 06:19:46.335000 15890 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:19:46.336941 16211 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:46.336936 16213 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:46.337109 16209 instance_detector.cc:116] could not retrieve AWS instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:19:46.337141 15890 server_base.cc:1061] running on GCE node
I20260812 06:19:46.337376 15890 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:19:46.337417 15890 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:46.337431 15890 hybrid_clock.cc:648] HybridClock initialized: now 1786515586337431 us; error 0 us; skew 500 ppm
I20260812 06:19:46.338322 15890 webserver.cc:533] Webserver started at http://127.15.132.190:43669/ using document root <none> and password file <none>
I20260812 06:19:46.338482 15890 fs_manager.cc:362] Metadata directory not provided
I20260812 06:19:46.338536 15890 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:19:46.338614 15890 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:19:46.339003 15890 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskZHdGUU/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515581174630-15890-0/minicluster-data/master-0-root/instance:
uuid: "924f881f305447f391e8b7a0868e9b6c"
format_stamp: "Formatted at 2026-08-12 06:19:46 on dist-test-slave-6bbx"
I20260812 06:19:46.340605 15890 fs_manager.cc:696] Time spent creating directory manager: real 0.001s	user 0.002s	sys 0.000s
I20260812 06:19:46.341522 16221 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:46.341747 15890 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.001s	sys 0.000s
I20260812 06:19:46.341823 15890 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskZHdGUU/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515581174630-15890-0/minicluster-data/master-0-root
uuid: "924f881f305447f391e8b7a0868e9b6c"
format_stamp: "Formatted at 2026-08-12 06:19:46 on dist-test-slave-6bbx"
I20260812 06:19:46.341894 15890 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskZHdGUU/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515581174630-15890-0/minicluster-data/master-0-root
metadata directory: /tmp/dist-test-taskZHdGUU/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515581174630-15890-0/minicluster-data/master-0-root
1 data directories: /tmp/dist-test-taskZHdGUU/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515581174630-15890-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:46.350965 15890 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:19:46.351329 15890 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:19:46.355198 15890 rpc_server.cc:307] RPC server started. Bound to: 127.15.132.190:35993
I20260812 06:19:46.362334 16313 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.15.132.190:35993 every 8 connection(s)
I20260812 06:19:46.362349 16315 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:46.364223 16315 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P 924f881f305447f391e8b7a0868e9b6c: Bootstrap starting.
I20260812 06:19:46.364946 16315 tablet_bootstrap.cc:654] T 00000000000000000000000000000000 P 924f881f305447f391e8b7a0868e9b6c: Neither blocks nor log segments found. Creating new log.
I20260812 06:19:46.365897 16315 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P 924f881f305447f391e8b7a0868e9b6c: No bootstrap required, opened a new log
I20260812 06:19:46.366252 16315 raft_consensus.cc:359] T 00000000000000000000000000000000 P 924f881f305447f391e8b7a0868e9b6c [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "924f881f305447f391e8b7a0868e9b6c" member_type: VOTER }
I20260812 06:19:46.366345 16315 raft_consensus.cc:385] T 00000000000000000000000000000000 P 924f881f305447f391e8b7a0868e9b6c [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:19:46.366371 16315 raft_consensus.cc:740] T 00000000000000000000000000000000 P 924f881f305447f391e8b7a0868e9b6c [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: 924f881f305447f391e8b7a0868e9b6c, State: Initialized, Role: FOLLOWER
I20260812 06:19:46.366488 16315 consensus_queue.cc:260] T 00000000000000000000000000000000 P 924f881f305447f391e8b7a0868e9b6c [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: "924f881f305447f391e8b7a0868e9b6c" member_type: VOTER }
I20260812 06:19:46.366566 16315 raft_consensus.cc:399] T 00000000000000000000000000000000 P 924f881f305447f391e8b7a0868e9b6c [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:19:46.366596 16315 raft_consensus.cc:493] T 00000000000000000000000000000000 P 924f881f305447f391e8b7a0868e9b6c [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:19:46.366628 16315 raft_consensus.cc:3060] T 00000000000000000000000000000000 P 924f881f305447f391e8b7a0868e9b6c [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:19:46.367264 16315 raft_consensus.cc:515] T 00000000000000000000000000000000 P 924f881f305447f391e8b7a0868e9b6c [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "924f881f305447f391e8b7a0868e9b6c" member_type: VOTER }
I20260812 06:19:46.367377 16315 leader_election.cc:304] T 00000000000000000000000000000000 P 924f881f305447f391e8b7a0868e9b6c [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: 924f881f305447f391e8b7a0868e9b6c; no voters: 
I20260812 06:19:46.367514 16315 leader_election.cc:290] T 00000000000000000000000000000000 P 924f881f305447f391e8b7a0868e9b6c [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:19:46.367630 16319 raft_consensus.cc:2804] T 00000000000000000000000000000000 P 924f881f305447f391e8b7a0868e9b6c [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:19:46.367846 16319 raft_consensus.cc:697] T 00000000000000000000000000000000 P 924f881f305447f391e8b7a0868e9b6c [term 1 LEADER]: Becoming Leader. State: Replica: 924f881f305447f391e8b7a0868e9b6c, State: Running, Role: LEADER
I20260812 06:19:46.367951 16315 sys_catalog.cc:565] T 00000000000000000000000000000000 P 924f881f305447f391e8b7a0868e9b6c [sys.catalog]: configured and running, proceeding with master startup.
I20260812 06:19:46.368006 16319 consensus_queue.cc:237] T 00000000000000000000000000000000 P 924f881f305447f391e8b7a0868e9b6c [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: "924f881f305447f391e8b7a0868e9b6c" member_type: VOTER }
I20260812 06:19:46.368410 16320 sys_catalog.cc:455] T 00000000000000000000000000000000 P 924f881f305447f391e8b7a0868e9b6c [sys.catalog]: SysCatalogTable state changed. Reason: RaftConsensus started. Latest consensus state: current_term: 1 leader_uuid: "924f881f305447f391e8b7a0868e9b6c" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "924f881f305447f391e8b7a0868e9b6c" member_type: VOTER } }
I20260812 06:19:46.368428 16321 sys_catalog.cc:455] T 00000000000000000000000000000000 P 924f881f305447f391e8b7a0868e9b6c [sys.catalog]: SysCatalogTable state changed. Reason: New leader 924f881f305447f391e8b7a0868e9b6c. Latest consensus state: current_term: 1 leader_uuid: "924f881f305447f391e8b7a0868e9b6c" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "924f881f305447f391e8b7a0868e9b6c" member_type: VOTER } }
I20260812 06:19:46.368522 16321 sys_catalog.cc:458] T 00000000000000000000000000000000 P 924f881f305447f391e8b7a0868e9b6c [sys.catalog]: This master's current role is: LEADER
I20260812 06:19:46.368705 16320 sys_catalog.cc:458] T 00000000000000000000000000000000 P 924f881f305447f391e8b7a0868e9b6c [sys.catalog]: This master's current role is: LEADER
I20260812 06:19:46.369030 16328 catalog_manager.cc:1511] Loading table and tablet metadata into memory...
I20260812 06:19:46.369776 16328 catalog_manager.cc:1520] Initializing Kudu cluster ID...
I20260812 06:19:46.369926 15890 internal_mini_cluster.cc:184] Waiting to initialize catalog manager on master 0
I20260812 06:19:46.371459 16328 catalog_manager.cc:1383] Generated new cluster ID: 6cece8a2e1b74c9792d2bd5dfc3f851d
I20260812 06:19:46.371511 16328 catalog_manager.cc:1531] Initializing Kudu internal certificate authority...
I20260812 06:19:46.377264 16328 catalog_manager.cc:1406] Generated new certificate authority record
I20260812 06:19:46.377831 16328 catalog_manager.cc:1540] Loading token signing keys...
I20260812 06:19:46.387923 16328 catalog_manager.cc:6092] T 00000000000000000000000000000000 P 924f881f305447f391e8b7a0868e9b6c: Generated new TSK 0
I20260812 06:19:46.388103 16328 catalog_manager.cc:1550] Initializing in-progress tserver states...
I20260812 06:19:46.402232 15890 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:19:46.404150 16346 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:46.404314 16349 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:46.404274 15890 server_base.cc:1061] running on GCE node
W20260812 06:19:46.404274 16345 instance_detector.cc:116] could not retrieve AWS instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:19:46.404597 15890 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:19:46.404647 15890 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:46.404668 15890 hybrid_clock.cc:648] HybridClock initialized: now 1786515586404668 us; error 0 us; skew 500 ppm
I20260812 06:19:46.405479 15890 webserver.cc:533] Webserver started at http://127.15.132.129:39939/ using document root <none> and password file <none>
I20260812 06:19:46.405632 15890 fs_manager.cc:362] Metadata directory not provided
I20260812 06:19:46.405678 15890 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:19:46.405756 15890 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:19:46.406126 15890 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskZHdGUU/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515581174630-15890-0/minicluster-data/ts-0-root/instance:
uuid: "5c9d175dd3194a479f91d4cfdfa78ecc"
format_stamp: "Formatted at 2026-08-12 06:19:46 on dist-test-slave-6bbx"
I20260812 06:19:46.407505 15890 fs_manager.cc:696] Time spent creating directory manager: real 0.001s	user 0.001s	sys 0.000s
I20260812 06:19:46.408437 16358 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:46.408687 15890 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.001s	sys 0.000s
I20260812 06:19:46.408752 15890 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskZHdGUU/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515581174630-15890-0/minicluster-data/ts-0-root
uuid: "5c9d175dd3194a479f91d4cfdfa78ecc"
format_stamp: "Formatted at 2026-08-12 06:19:46 on dist-test-slave-6bbx"
I20260812 06:19:46.408830 15890 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskZHdGUU/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515581174630-15890-0/minicluster-data/ts-0-root
metadata directory: /tmp/dist-test-taskZHdGUU/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515581174630-15890-0/minicluster-data/ts-0-root
1 data directories: /tmp/dist-test-taskZHdGUU/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515581174630-15890-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:46.425709 15890 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:19:46.426035 15890 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:19:46.426298 15890 txn_system_client.cc:432] TxnSystemClient initialization is disabled...
I20260812 06:19:46.426721 15890 ts_tablet_manager.cc:585] Loaded tablet metadata (0 total tablets, 0 live tablets)
I20260812 06:19:46.426765 15890 ts_tablet_manager.cc:531] Time spent load tablet metadata: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:19:46.426800 15890 ts_tablet_manager.cc:616] Registered 0 tablets
I20260812 06:19:46.426829 15890 ts_tablet_manager.cc:595] Time spent register tablets: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:19:46.430681 15890 rpc_server.cc:307] RPC server started. Bound to: 127.15.132.129:40381
I20260812 06:19:46.431620 16462 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.15.132.129:40381 every 8 connection(s)
I20260812 06:19:46.438443 16464 heartbeater.cc:344] Connected to a master server at 127.15.132.190:35993
I20260812 06:19:46.438550 16464 heartbeater.cc:461] Registering TS with master...
I20260812 06:19:46.438758 16464 heartbeater.cc:507] Master 127.15.132.190:35993 requested a full tablet report, sending...
I20260812 06:19:46.439316 16251 ts_manager.cc:194] Registered new tserver with Master: 5c9d175dd3194a479f91d4cfdfa78ecc (127.15.132.129:40381)
I20260812 06:19:46.440044 16251 master_service.cc:502] Signed X509 certificate for tserver {username='slave'} at 127.0.0.1:44920
I20260812 06:19:46.440070 15890 internal_mini_cluster.cc:371] 1 TS(s) registered with all masters after 0.008750959s
I20260812 06:19:46.446343 16251 catalog_manager.cc:2283] Servicing CreateTable request from {username='slave'} at 127.0.0.1:44928:
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:46.454387 16403 tablet_service.cc:1511] Processing CreateTablet for tablet 8173c99eb5174e02bb9d543b644c9397 (DEFAULT_TABLE table=heavy-update-compaction-test [id=9614f2d1b82542968d983d37657d6157]), partition=
I20260812 06:19:46.454653 16403 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet 8173c99eb5174e02bb9d543b644c9397. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:19:46.456506 16480 tablet_bootstrap.cc:492] T 8173c99eb5174e02bb9d543b644c9397 P 5c9d175dd3194a479f91d4cfdfa78ecc: Bootstrap starting.
I20260812 06:19:46.457324 16480 tablet_bootstrap.cc:654] T 8173c99eb5174e02bb9d543b644c9397 P 5c9d175dd3194a479f91d4cfdfa78ecc: Neither blocks nor log segments found. Creating new log.
I20260812 06:19:46.458161 16480 tablet_bootstrap.cc:492] T 8173c99eb5174e02bb9d543b644c9397 P 5c9d175dd3194a479f91d4cfdfa78ecc: No bootstrap required, opened a new log
I20260812 06:19:46.458231 16480 ts_tablet_manager.cc:1403] T 8173c99eb5174e02bb9d543b644c9397 P 5c9d175dd3194a479f91d4cfdfa78ecc: Time spent bootstrapping tablet: real 0.002s	user 0.001s	sys 0.000s
I20260812 06:19:46.458559 16480 raft_consensus.cc:359] T 8173c99eb5174e02bb9d543b644c9397 P 5c9d175dd3194a479f91d4cfdfa78ecc [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "5c9d175dd3194a479f91d4cfdfa78ecc" member_type: VOTER last_known_addr { host: "127.15.132.129" port: 40381 } }
I20260812 06:19:46.458642 16480 raft_consensus.cc:385] T 8173c99eb5174e02bb9d543b644c9397 P 5c9d175dd3194a479f91d4cfdfa78ecc [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:19:46.458668 16480 raft_consensus.cc:740] T 8173c99eb5174e02bb9d543b644c9397 P 5c9d175dd3194a479f91d4cfdfa78ecc [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: 5c9d175dd3194a479f91d4cfdfa78ecc, State: Initialized, Role: FOLLOWER
I20260812 06:19:46.458762 16480 consensus_queue.cc:260] T 8173c99eb5174e02bb9d543b644c9397 P 5c9d175dd3194a479f91d4cfdfa78ecc [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: "5c9d175dd3194a479f91d4cfdfa78ecc" member_type: VOTER last_known_addr { host: "127.15.132.129" port: 40381 } }
I20260812 06:19:46.458822 16480 raft_consensus.cc:399] T 8173c99eb5174e02bb9d543b644c9397 P 5c9d175dd3194a479f91d4cfdfa78ecc [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:19:46.458841 16480 raft_consensus.cc:493] T 8173c99eb5174e02bb9d543b644c9397 P 5c9d175dd3194a479f91d4cfdfa78ecc [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:19:46.458873 16480 raft_consensus.cc:3060] T 8173c99eb5174e02bb9d543b644c9397 P 5c9d175dd3194a479f91d4cfdfa78ecc [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:19:46.459539 16480 raft_consensus.cc:515] T 8173c99eb5174e02bb9d543b644c9397 P 5c9d175dd3194a479f91d4cfdfa78ecc [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "5c9d175dd3194a479f91d4cfdfa78ecc" member_type: VOTER last_known_addr { host: "127.15.132.129" port: 40381 } }
I20260812 06:19:46.459734 16480 leader_election.cc:304] T 8173c99eb5174e02bb9d543b644c9397 P 5c9d175dd3194a479f91d4cfdfa78ecc [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: 5c9d175dd3194a479f91d4cfdfa78ecc; no voters: 
I20260812 06:19:46.459913 16480 leader_election.cc:290] T 8173c99eb5174e02bb9d543b644c9397 P 5c9d175dd3194a479f91d4cfdfa78ecc [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:19:46.460000 16485 raft_consensus.cc:2804] T 8173c99eb5174e02bb9d543b644c9397 P 5c9d175dd3194a479f91d4cfdfa78ecc [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:19:46.460168 16485 raft_consensus.cc:697] T 8173c99eb5174e02bb9d543b644c9397 P 5c9d175dd3194a479f91d4cfdfa78ecc [term 1 LEADER]: Becoming Leader. State: Replica: 5c9d175dd3194a479f91d4cfdfa78ecc, State: Running, Role: LEADER
I20260812 06:19:46.460228 16480 ts_tablet_manager.cc:1434] T 8173c99eb5174e02bb9d543b644c9397 P 5c9d175dd3194a479f91d4cfdfa78ecc: Time spent starting tablet: real 0.002s	user 0.002s	sys 0.000s
I20260812 06:19:46.460332 16464 heartbeater.cc:499] Master 127.15.132.190:35993 was elected leader, sending a full tablet report...
I20260812 06:19:46.460367 16485 consensus_queue.cc:237] T 8173c99eb5174e02bb9d543b644c9397 P 5c9d175dd3194a479f91d4cfdfa78ecc [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: "5c9d175dd3194a479f91d4cfdfa78ecc" member_type: VOTER last_known_addr { host: "127.15.132.129" port: 40381 } }
I20260812 06:19:46.461607 16251 catalog_manager.cc:5719] T 8173c99eb5174e02bb9d543b644c9397 P 5c9d175dd3194a479f91d4cfdfa78ecc reported cstate change: term changed from 0 to 1, leader changed from <none> to 5c9d175dd3194a479f91d4cfdfa78ecc (127.15.132.129). New cstate: current_term: 1 leader_uuid: "5c9d175dd3194a479f91d4cfdfa78ecc" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "5c9d175dd3194a479f91d4cfdfa78ecc" member_type: VOTER last_known_addr { host: "127.15.132.129" port: 40381 } health_report { overall_health: HEALTHY } } }
I20260812 06:19:46.514458 15890 heavy-update-compaction-itest.cc:215] Time spent inserting: real 0.049s	user 0.016s	sys 0.004s
I20260812 06:19:46.682174 16467 maintenance_manager.cc:419] P 5c9d175dd3194a479f91d4cfdfa78ecc: Scheduling FlushMRSOp(8173c99eb5174e02bb9d543b644c9397): perf score=23.023690
I20260812 06:19:46.846990 16369 maintenance_manager.cc:643] P 5c9d175dd3194a479f91d4cfdfa78ecc: FlushMRSOp(8173c99eb5174e02bb9d543b644c9397) complete. Timing: real 0.165s	user 0.106s	sys 0.055s Metrics: {"bytes_written":12717734,"cfile_init":1,"delete_count":0,"dirs.queue_time_us":94,"dirs.run_cpu_time_us":239,"dirs.run_wall_time_us":4831,"drs_written":1,"lbm_read_time_us":52,"lbm_reads_lt_1ms":4,"lbm_write_time_us":43767,"lbm_writes_lt_1ms":867,"peak_mem_usage":0,"reinsert_count":0,"rows_written":105,"update_count":1550}
I20260812 06:19:46.847725 16467 maintenance_manager.cc:419] P 5c9d175dd3194a479f91d4cfdfa78ecc: Scheduling LogGCOp(8173c99eb5174e02bb9d543b644c9397): free 20743880 bytes of WAL
I20260812 06:19:46.847936 16369 log_reader.cc:385] T 8173c99eb5174e02bb9d543b644c9397: removed 2 log segments from log reader
I20260812 06:19:46.848011 16369 log.cc:1079] T 8173c99eb5174e02bb9d543b644c9397 P 5c9d175dd3194a479f91d4cfdfa78ecc: Deleting log segment in path: /tmp/dist-test-taskZHdGUU/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515581174630-15890-0/minicluster-data/ts-0-root/wals/8173c99eb5174e02bb9d543b644c9397/wal-000000001 (ops 1-6)
I20260812 06:19:46.848075 16369 log.cc:1079] T 8173c99eb5174e02bb9d543b644c9397 P 5c9d175dd3194a479f91d4cfdfa78ecc: Deleting log segment in path: /tmp/dist-test-taskZHdGUU/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515581174630-15890-0/minicluster-data/ts-0-root/wals/8173c99eb5174e02bb9d543b644c9397/wal-000000002 (ops 7-11)
I20260812 06:19:46.853091 16369 maintenance_manager.cc:643] P 5c9d175dd3194a479f91d4cfdfa78ecc: LogGCOp(8173c99eb5174e02bb9d543b644c9397) complete. Timing: real 0.005s	user 0.000s	sys 0.004s Metrics: {}
I20260812 06:19:46.853391 16467 maintenance_manager.cc:419] P 5c9d175dd3194a479f91d4cfdfa78ecc: Scheduling FlushDeltaMemStoresOp(8173c99eb5174e02bb9d543b644c9397): perf score=2.188937
I20260812 06:19:46.877748 16369 maintenance_manager.cc:643] P 5c9d175dd3194a479f91d4cfdfa78ecc: FlushDeltaMemStoresOp(8173c99eb5174e02bb9d543b644c9397) complete. Timing: real 0.024s	user 0.009s	sys 0.001s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":4371,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:19:46.878204 16467 maintenance_manager.cc:419] P 5c9d175dd3194a479f91d4cfdfa78ecc: Scheduling FlushDeltaMemStoresOp(8173c99eb5174e02bb9d543b644c9397): perf score=2.188937
I20260812 06:19:46.893486 16369 maintenance_manager.cc:643] P 5c9d175dd3194a479f91d4cfdfa78ecc: FlushDeltaMemStoresOp(8173c99eb5174e02bb9d543b644c9397) complete. Timing: real 0.015s	user 0.005s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5392,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:46.894212 16467 maintenance_manager.cc:419] P 5c9d175dd3194a479f91d4cfdfa78ecc: Scheduling UndoDeltaBlockGCOp(8173c99eb5174e02bb9d543b644c9397): 20513813 bytes on disk
I20260812 06:19:46.895020 16369 maintenance_manager.cc:643] P 5c9d175dd3194a479f91d4cfdfa78ecc: UndoDeltaBlockGCOp(8173c99eb5174e02bb9d543b644c9397) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":103,"lbm_reads_lt_1ms":4}
I20260812 06:19:46.895818 16467 maintenance_manager.cc:419] P 5c9d175dd3194a479f91d4cfdfa78ecc: Scheduling MajorDeltaCompactionOp(8173c99eb5174e02bb9d543b644c9397): perf score=1.000000
I20260812 06:19:47.055845 16369 maintenance_manager.cc:643] P 5c9d175dd3194a479f91d4cfdfa78ecc: MajorDeltaCompactionOp(8173c99eb5174e02bb9d543b644c9397) complete. Timing: real 0.160s	user 0.123s	sys 0.029s Metrics: {"cfile_cache_miss":533,"cfile_cache_miss_bytes":24815793,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":428,"lbm_read_time_us":10897,"lbm_reads_lt_1ms":569,"lbm_write_time_us":26308,"lbm_writes_lt_1ms":543,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":2560,"thread_start_us":349,"threads_started":5,"update_count":2500}
I20260812 06:19:47.056423 16467 maintenance_manager.cc:419] P 5c9d175dd3194a479f91d4cfdfa78ecc: Scheduling FlushDeltaMemStoresOp(8173c99eb5174e02bb9d543b644c9397): perf score=14.095187
I20260812 06:19:47.115513 16369 maintenance_manager.cc:643] P 5c9d175dd3194a479f91d4cfdfa78ecc: FlushDeltaMemStoresOp(8173c99eb5174e02bb9d543b644c9397) complete. Timing: real 0.059s	user 0.019s	sys 0.019s Metrics: {"bytes_written":16409904,"delete_count":0,"lbm_write_time_us":19024,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:47.116042 16467 maintenance_manager.cc:419] P 5c9d175dd3194a479f91d4cfdfa78ecc: Scheduling FlushDeltaMemStoresOp(8173c99eb5174e02bb9d543b644c9397): perf score=2.188937
I20260812 06:19:47.131105 16369 maintenance_manager.cc:643] P 5c9d175dd3194a479f91d4cfdfa78ecc: FlushDeltaMemStoresOp(8173c99eb5174e02bb9d543b644c9397) complete. Timing: real 0.015s	user 0.009s	sys 0.003s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5496,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:47.131609 16467 maintenance_manager.cc:419] P 5c9d175dd3194a479f91d4cfdfa78ecc: Scheduling MajorDeltaCompactionOp(8173c99eb5174e02bb9d543b644c9397): perf score=1.000000
I20260812 06:19:47.307315 16369 maintenance_manager.cc:643] P 5c9d175dd3194a479f91d4cfdfa78ecc: MajorDeltaCompactionOp(8173c99eb5174e02bb9d543b644c9397) complete. Timing: real 0.175s	user 0.126s	sys 0.044s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24815686,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":80,"lbm_read_time_us":12465,"lbm_reads_lt_1ms":572,"lbm_write_time_us":32044,"lbm_writes_lt_1ms":543,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":5504,"update_count":2500}
I20260812 06:19:47.307901 16467 maintenance_manager.cc:419] P 5c9d175dd3194a479f91d4cfdfa78ecc: Scheduling FlushDeltaMemStoresOp(8173c99eb5174e02bb9d543b644c9397): perf score=11.118625
I20260812 06:19:47.344502 16369 maintenance_manager.cc:643] P 5c9d175dd3194a479f91d4cfdfa78ecc: FlushDeltaMemStoresOp(8173c99eb5174e02bb9d543b644c9397) complete. Timing: real 0.036s	user 0.027s	sys 0.008s Metrics: {"bytes_written":12717735,"delete_count":0,"lbm_write_time_us":15748,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:19:47.345168 16467 maintenance_manager.cc:419] P 5c9d175dd3194a479f91d4cfdfa78ecc: Scheduling FlushDeltaMemStoresOp(8173c99eb5174e02bb9d543b644c9397): perf score=2.188937
I20260812 06:19:47.356294 16369 maintenance_manager.cc:643] P 5c9d175dd3194a479f91d4cfdfa78ecc: FlushDeltaMemStoresOp(8173c99eb5174e02bb9d543b644c9397) complete. Timing: real 0.011s	user 0.002s	sys 0.008s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3939,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:19:47.356863 16467 maintenance_manager.cc:419] P 5c9d175dd3194a479f91d4cfdfa78ecc: Scheduling MajorDeltaCompactionOp(8173c99eb5174e02bb9d543b644c9397): perf score=1.000000
I20260812 06:19:47.497339 16369 maintenance_manager.cc:643] P 5c9d175dd3194a479f91d4cfdfa78ecc: MajorDeltaCompactionOp(8173c99eb5174e02bb9d543b644c9397) complete. Timing: real 0.140s	user 0.104s	sys 0.036s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20713263,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":280,"lbm_read_time_us":10165,"lbm_reads_lt_1ms":472,"lbm_write_time_us":21708,"lbm_writes_lt_1ms":443,"mutex_wait_us":45,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":3968,"update_count":2000}
I20260812 06:19:47.497839 16467 maintenance_manager.cc:419] P 5c9d175dd3194a479f91d4cfdfa78ecc: Scheduling FlushDeltaMemStoresOp(8173c99eb5174e02bb9d543b644c9397): perf score=10.126437
I20260812 06:19:47.540728 16369 maintenance_manager.cc:643] P 5c9d175dd3194a479f91d4cfdfa78ecc: FlushDeltaMemStoresOp(8173c99eb5174e02bb9d543b644c9397) complete. Timing: real 0.043s	user 0.018s	sys 0.016s Metrics: {"bytes_written":12307491,"delete_count":0,"lbm_write_time_us":14930,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:19:47.541211 16467 maintenance_manager.cc:419] P 5c9d175dd3194a479f91d4cfdfa78ecc: Scheduling FlushDeltaMemStoresOp(8173c99eb5174e02bb9d543b644c9397): perf score=2.188937
I20260812 06:19:47.553838 16369 maintenance_manager.cc:643] P 5c9d175dd3194a479f91d4cfdfa78ecc: FlushDeltaMemStoresOp(8173c99eb5174e02bb9d543b644c9397) complete. Timing: real 0.012s	user 0.005s	sys 0.004s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":5336,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":102,"reinsert_count":0,"update_count":500}
I20260812 06:19:47.554446 16467 maintenance_manager.cc:419] P 5c9d175dd3194a479f91d4cfdfa78ecc: Scheduling MajorDeltaCompactionOp(8173c99eb5174e02bb9d543b644c9397): perf score=1.000000
I20260812 06:19:47.697595 16369 maintenance_manager.cc:643] P 5c9d175dd3194a479f91d4cfdfa78ecc: MajorDeltaCompactionOp(8173c99eb5174e02bb9d543b644c9397) complete. Timing: real 0.143s	user 0.111s	sys 0.030s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20713272,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":224,"lbm_read_time_us":9835,"lbm_reads_lt_1ms":472,"lbm_write_time_us":25308,"lbm_writes_lt_1ms":443,"mutex_wait_us":53,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":70016,"update_count":2000}
I20260812 06:19:47.698091 16467 maintenance_manager.cc:419] P 5c9d175dd3194a479f91d4cfdfa78ecc: Scheduling FlushDeltaMemStoresOp(8173c99eb5174e02bb9d543b644c9397): perf score=10.126437
I20260812 06:19:47.737440 16369 maintenance_manager.cc:643] P 5c9d175dd3194a479f91d4cfdfa78ecc: FlushDeltaMemStoresOp(8173c99eb5174e02bb9d543b644c9397) complete. Timing: real 0.039s	user 0.024s	sys 0.009s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":15250,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:19:47.737983 16467 maintenance_manager.cc:419] P 5c9d175dd3194a479f91d4cfdfa78ecc: Scheduling FlushDeltaMemStoresOp(8173c99eb5174e02bb9d543b644c9397): perf score=2.188937
I20260812 06:19:47.748445 16369 maintenance_manager.cc:643] P 5c9d175dd3194a479f91d4cfdfa78ecc: FlushDeltaMemStoresOp(8173c99eb5174e02bb9d543b644c9397) complete. Timing: real 0.010s	user 0.006s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3860,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:47.749104 16467 maintenance_manager.cc:419] P 5c9d175dd3194a479f91d4cfdfa78ecc: Scheduling MajorDeltaCompactionOp(8173c99eb5174e02bb9d543b644c9397): perf score=1.000000
I20260812 06:19:47.872987 16369 maintenance_manager.cc:643] P 5c9d175dd3194a479f91d4cfdfa78ecc: MajorDeltaCompactionOp(8173c99eb5174e02bb9d543b644c9397) complete. Timing: real 0.124s	user 0.095s	sys 0.028s 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":539,"lbm_read_time_us":8841,"lbm_reads_lt_1ms":472,"lbm_write_time_us":21316,"lbm_writes_lt_1ms":443,"mutex_wait_us":45,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":14720,"update_count":2000}
I20260812 06:19:47.873458 16467 maintenance_manager.cc:419] P 5c9d175dd3194a479f91d4cfdfa78ecc: Scheduling FlushDeltaMemStoresOp(8173c99eb5174e02bb9d543b644c9397): perf score=10.126437
I20260812 06:19:47.918071 16369 maintenance_manager.cc:643] P 5c9d175dd3194a479f91d4cfdfa78ecc: FlushDeltaMemStoresOp(8173c99eb5174e02bb9d543b644c9397) complete. Timing: real 0.044s	user 0.014s	sys 0.016s Metrics: {"bytes_written":12307491,"delete_count":0,"lbm_write_time_us":13980,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:19:47.918685 16467 maintenance_manager.cc:419] P 5c9d175dd3194a479f91d4cfdfa78ecc: Scheduling FlushDeltaMemStoresOp(8173c99eb5174e02bb9d543b644c9397): perf score=2.188937
I20260812 06:19:47.934361 16369 maintenance_manager.cc:643] P 5c9d175dd3194a479f91d4cfdfa78ecc: FlushDeltaMemStoresOp(8173c99eb5174e02bb9d543b644c9397) complete. Timing: real 0.015s	user 0.010s	sys 0.003s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6002,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:47.934866 16467 maintenance_manager.cc:419] P 5c9d175dd3194a479f91d4cfdfa78ecc: Scheduling MajorDeltaCompactionOp(8173c99eb5174e02bb9d543b644c9397): perf score=1.000000
I20260812 06:19:48.051743 16369 maintenance_manager.cc:643] P 5c9d175dd3194a479f91d4cfdfa78ecc: MajorDeltaCompactionOp(8173c99eb5174e02bb9d543b644c9397) complete. Timing: real 0.117s	user 0.109s	sys 0.007s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20713273,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":921,"lbm_read_time_us":8396,"lbm_reads_lt_1ms":472,"lbm_write_time_us":23067,"lbm_writes_lt_1ms":443,"peak_mem_usage":50689328,"reinsert_count":0,"update_count":2000}
I20260812 06:19:48.052327 16467 maintenance_manager.cc:419] P 5c9d175dd3194a479f91d4cfdfa78ecc: Scheduling FlushDeltaMemStoresOp(8173c99eb5174e02bb9d543b644c9397): perf score=10.126437
I20260812 06:19:48.098317 16369 maintenance_manager.cc:643] P 5c9d175dd3194a479f91d4cfdfa78ecc: FlushDeltaMemStoresOp(8173c99eb5174e02bb9d543b644c9397) complete. Timing: real 0.046s	user 0.026s	sys 0.012s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":14190,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:19:48.098910 16467 maintenance_manager.cc:419] P 5c9d175dd3194a479f91d4cfdfa78ecc: Scheduling FlushDeltaMemStoresOp(8173c99eb5174e02bb9d543b644c9397): perf score=2.188937
I20260812 06:19:48.109216 16369 maintenance_manager.cc:643] P 5c9d175dd3194a479f91d4cfdfa78ecc: FlushDeltaMemStoresOp(8173c99eb5174e02bb9d543b644c9397) complete. Timing: real 0.010s	user 0.008s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3831,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:48.109707 16467 maintenance_manager.cc:419] P 5c9d175dd3194a479f91d4cfdfa78ecc: Scheduling FlushMRSOp(8173c99eb5174e02bb9d543b644c9397): perf score=1.000000
I20260812 06:19:48.138847 16369 maintenance_manager.cc:643] P 5c9d175dd3194a479f91d4cfdfa78ecc: FlushMRSOp(8173c99eb5174e02bb9d543b644c9397) complete. Timing: real 0.029s	user 0.023s	sys 0.004s Metrics: {"bytes_written":1234473,"cfile_init":1,"dirs.queue_time_us":52,"dirs.run_cpu_time_us":188,"dirs.run_wall_time_us":1213,"drs_written":1,"lbm_read_time_us":123,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1914,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":30}
I20260812 06:19:48.139477 16467 maintenance_manager.cc:419] P 5c9d175dd3194a479f91d4cfdfa78ecc: Scheduling LogGCOp(8173c99eb5174e02bb9d543b644c9397): free 124257236 bytes of WAL
I20260812 06:19:48.139731 16369 log_reader.cc:385] T 8173c99eb5174e02bb9d543b644c9397: removed 12 log segments from log reader
I20260812 06:19:48.139792 16369 log.cc:1079] T 8173c99eb5174e02bb9d543b644c9397 P 5c9d175dd3194a479f91d4cfdfa78ecc: Deleting log segment in path: /tmp/dist-test-taskZHdGUU/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515581174630-15890-0/minicluster-data/ts-0-root/wals/8173c99eb5174e02bb9d543b644c9397/wal-000000003 (ops 12-16)
I20260812 06:19:48.139883 16369 log.cc:1079] T 8173c99eb5174e02bb9d543b644c9397 P 5c9d175dd3194a479f91d4cfdfa78ecc: Deleting log segment in path: /tmp/dist-test-taskZHdGUU/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515581174630-15890-0/minicluster-data/ts-0-root/wals/8173c99eb5174e02bb9d543b644c9397/wal-000000004 (ops 17-21)
I20260812 06:19:48.139919 16369 log.cc:1079] T 8173c99eb5174e02bb9d543b644c9397 P 5c9d175dd3194a479f91d4cfdfa78ecc: Deleting log segment in path: /tmp/dist-test-taskZHdGUU/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515581174630-15890-0/minicluster-data/ts-0-root/wals/8173c99eb5174e02bb9d543b644c9397/wal-000000005 (ops 22-26)
I20260812 06:19:48.139941 16369 log.cc:1079] T 8173c99eb5174e02bb9d543b644c9397 P 5c9d175dd3194a479f91d4cfdfa78ecc: Deleting log segment in path: /tmp/dist-test-taskZHdGUU/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515581174630-15890-0/minicluster-data/ts-0-root/wals/8173c99eb5174e02bb9d543b644c9397/wal-000000006 (ops 27-31)
I20260812 06:19:48.139969 16369 log.cc:1079] T 8173c99eb5174e02bb9d543b644c9397 P 5c9d175dd3194a479f91d4cfdfa78ecc: Deleting log segment in path: /tmp/dist-test-taskZHdGUU/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515581174630-15890-0/minicluster-data/ts-0-root/wals/8173c99eb5174e02bb9d543b644c9397/wal-000000007 (ops 32-36)
I20260812 06:19:48.140028 16369 log.cc:1079] T 8173c99eb5174e02bb9d543b644c9397 P 5c9d175dd3194a479f91d4cfdfa78ecc: Deleting log segment in path: /tmp/dist-test-taskZHdGUU/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515581174630-15890-0/minicluster-data/ts-0-root/wals/8173c99eb5174e02bb9d543b644c9397/wal-000000008 (ops 37-41)
I20260812 06:19:48.140062 16369 log.cc:1079] T 8173c99eb5174e02bb9d543b644c9397 P 5c9d175dd3194a479f91d4cfdfa78ecc: Deleting log segment in path: /tmp/dist-test-taskZHdGUU/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515581174630-15890-0/minicluster-data/ts-0-root/wals/8173c99eb5174e02bb9d543b644c9397/wal-000000009 (ops 42-46)
I20260812 06:19:48.140105 16369 log.cc:1079] T 8173c99eb5174e02bb9d543b644c9397 P 5c9d175dd3194a479f91d4cfdfa78ecc: Deleting log segment in path: /tmp/dist-test-taskZHdGUU/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515581174630-15890-0/minicluster-data/ts-0-root/wals/8173c99eb5174e02bb9d543b644c9397/wal-000000010 (ops 47-51)
I20260812 06:19:48.140136 16369 log.cc:1079] T 8173c99eb5174e02bb9d543b644c9397 P 5c9d175dd3194a479f91d4cfdfa78ecc: Deleting log segment in path: /tmp/dist-test-taskZHdGUU/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515581174630-15890-0/minicluster-data/ts-0-root/wals/8173c99eb5174e02bb9d543b644c9397/wal-000000011 (ops 52-56)
I20260812 06:19:48.140194 16369 log.cc:1079] T 8173c99eb5174e02bb9d543b644c9397 P 5c9d175dd3194a479f91d4cfdfa78ecc: Deleting log segment in path: /tmp/dist-test-taskZHdGUU/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515581174630-15890-0/minicluster-data/ts-0-root/wals/8173c99eb5174e02bb9d543b644c9397/wal-000000012 (ops 57-60)
I20260812 06:19:48.140232 16369 log.cc:1079] T 8173c99eb5174e02bb9d543b644c9397 P 5c9d175dd3194a479f91d4cfdfa78ecc: Deleting log segment in path: /tmp/dist-test-taskZHdGUU/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515581174630-15890-0/minicluster-data/ts-0-root/wals/8173c99eb5174e02bb9d543b644c9397/wal-000000013 (ops 61-65)
I20260812 06:19:48.140290 16369 log.cc:1079] T 8173c99eb5174e02bb9d543b644c9397 P 5c9d175dd3194a479f91d4cfdfa78ecc: Deleting log segment in path: /tmp/dist-test-taskZHdGUU/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515581174630-15890-0/minicluster-data/ts-0-root/wals/8173c99eb5174e02bb9d543b644c9397/wal-000000014 (ops 66-70)
I20260812 06:19:48.160663 16369 maintenance_manager.cc:643] P 5c9d175dd3194a479f91d4cfdfa78ecc: LogGCOp(8173c99eb5174e02bb9d543b644c9397) complete. Timing: real 0.021s	user 0.000s	sys 0.020s Metrics: {}
I20260812 06:19:48.161116 16467 maintenance_manager.cc:419] P 5c9d175dd3194a479f91d4cfdfa78ecc: Scheduling UndoDeltaBlockGCOp(8173c99eb5174e02bb9d543b644c9397): 472 bytes on disk
I20260812 06:19:48.161720 16369 maintenance_manager.cc:643] P 5c9d175dd3194a479f91d4cfdfa78ecc: UndoDeltaBlockGCOp(8173c99eb5174e02bb9d543b644c9397) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":52,"lbm_reads_lt_1ms":4}
I20260812 06:19:48.162180 16467 maintenance_manager.cc:419] P 5c9d175dd3194a479f91d4cfdfa78ecc: Scheduling FlushDeltaMemStoresOp(8173c99eb5174e02bb9d543b644c9397): perf score=1.196750
I20260812 06:19:48.176402 16369 maintenance_manager.cc:643] P 5c9d175dd3194a479f91d4cfdfa78ecc: FlushDeltaMemStoresOp(8173c99eb5174e02bb9d543b644c9397) complete. Timing: real 0.014s	user 0.002s	sys 0.007s Metrics: {"bytes_written":3036009,"delete_count":0,"lbm_write_time_us":3420,"lbm_writes_lt_1ms":77,"reinsert_count":0,"update_count":370}
I20260812 06:19:48.176880 16467 maintenance_manager.cc:419] P 5c9d175dd3194a479f91d4cfdfa78ecc: Scheduling MajorDeltaCompactionOp(8173c99eb5174e02bb9d543b644c9397): perf score=1.000000
I20260812 06:19:48.358978 16369 maintenance_manager.cc:643] P 5c9d175dd3194a479f91d4cfdfa78ecc: MajorDeltaCompactionOp(8173c99eb5174e02bb9d543b644c9397) complete. Timing: real 0.182s	user 0.128s	sys 0.050s Metrics: {"cfile_cache_miss":507,"cfile_cache_miss_bytes":23749153,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":937,"lbm_read_time_us":11779,"lbm_reads_lt_1ms":543,"lbm_write_time_us":28628,"lbm_writes_lt_1ms":517,"mutex_wait_us":311,"peak_mem_usage":59968222,"reinsert_count":0,"spinlock_wait_cycles":3584,"thread_start_us":103,"threads_started":1,"update_count":2370}
I20260812 06:19:48.359531 16467 maintenance_manager.cc:419] P 5c9d175dd3194a479f91d4cfdfa78ecc: Scheduling FlushDeltaMemStoresOp(8173c99eb5174e02bb9d543b644c9397): perf score=15.087375
I20260812 06:19:48.417017 16369 maintenance_manager.cc:643] P 5c9d175dd3194a479f91d4cfdfa78ecc: FlushDeltaMemStoresOp(8173c99eb5174e02bb9d543b644c9397) complete. Timing: real 0.057s	user 0.028s	sys 0.024s Metrics: {"bytes_written":17476537,"delete_count":0,"lbm_write_time_us":19789,"lbm_writes_lt_1ms":429,"reinsert_count":0,"update_count":2130}
I20260812 06:19:48.417569 16467 maintenance_manager.cc:419] P 5c9d175dd3194a479f91d4cfdfa78ecc: Scheduling FlushDeltaMemStoresOp(8173c99eb5174e02bb9d543b644c9397): perf score=2.188937
I20260812 06:19:48.432545 16369 maintenance_manager.cc:643] P 5c9d175dd3194a479f91d4cfdfa78ecc: FlushDeltaMemStoresOp(8173c99eb5174e02bb9d543b644c9397) complete. Timing: real 0.015s	user 0.014s	sys 0.000s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":5661,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:48.433058 16467 maintenance_manager.cc:419] P 5c9d175dd3194a479f91d4cfdfa78ecc: Scheduling MajorDeltaCompactionOp(8173c99eb5174e02bb9d543b644c9397): perf score=1.000000
I20260812 06:19:48.611483 16369 maintenance_manager.cc:643] P 5c9d175dd3194a479f91d4cfdfa78ecc: MajorDeltaCompactionOp(8173c99eb5174e02bb9d543b644c9397) complete. Timing: real 0.178s	user 0.101s	sys 0.068s Metrics: {"cfile_cache_miss":558,"cfile_cache_miss_bytes":25882318,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":529,"lbm_read_time_us":12828,"lbm_reads_lt_1ms":598,"lbm_write_time_us":27569,"lbm_writes_lt_1ms":569,"mutex_wait_us":289,"peak_mem_usage":66263578,"reinsert_count":0,"spinlock_wait_cycles":21248,"update_count":2630}
I20260812 06:19:48.612092 16467 maintenance_manager.cc:419] P 5c9d175dd3194a479f91d4cfdfa78ecc: Scheduling FlushDeltaMemStoresOp(8173c99eb5174e02bb9d543b644c9397): perf score=14.095187
I20260812 06:19:48.665383 16369 maintenance_manager.cc:643] P 5c9d175dd3194a479f91d4cfdfa78ecc: FlushDeltaMemStoresOp(8173c99eb5174e02bb9d543b644c9397) complete. Timing: real 0.053s	user 0.036s	sys 0.010s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":16626,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:48.665978 16467 maintenance_manager.cc:419] P 5c9d175dd3194a479f91d4cfdfa78ecc: Scheduling FlushDeltaMemStoresOp(8173c99eb5174e02bb9d543b644c9397): perf score=2.188937
I20260812 06:19:48.681277 16369 maintenance_manager.cc:643] P 5c9d175dd3194a479f91d4cfdfa78ecc: FlushDeltaMemStoresOp(8173c99eb5174e02bb9d543b644c9397) complete. Timing: real 0.015s	user 0.013s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5812,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:48.681772 16467 maintenance_manager.cc:419] P 5c9d175dd3194a479f91d4cfdfa78ecc: Scheduling MajorDeltaCompactionOp(8173c99eb5174e02bb9d543b644c9397): perf score=1.000000
I20260812 06:19:48.856592 16369 maintenance_manager.cc:643] P 5c9d175dd3194a479f91d4cfdfa78ecc: MajorDeltaCompactionOp(8173c99eb5174e02bb9d543b644c9397) complete. Timing: real 0.175s	user 0.108s	sys 0.056s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24815684,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":166,"lbm_read_time_us":12664,"lbm_reads_lt_1ms":572,"lbm_write_time_us":26069,"lbm_writes_lt_1ms":543,"mutex_wait_us":55,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":55424,"update_count":2500}
I20260812 06:19:48.857101 16467 maintenance_manager.cc:419] P 5c9d175dd3194a479f91d4cfdfa78ecc: Scheduling FlushDeltaMemStoresOp(8173c99eb5174e02bb9d543b644c9397): perf score=14.095187
I20260812 06:19:48.911054 16369 maintenance_manager.cc:643] P 5c9d175dd3194a479f91d4cfdfa78ecc: FlushDeltaMemStoresOp(8173c99eb5174e02bb9d543b644c9397) complete. Timing: real 0.054s	user 0.040s	sys 0.007s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":22074,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:48.911711 16467 maintenance_manager.cc:419] P 5c9d175dd3194a479f91d4cfdfa78ecc: Scheduling FlushDeltaMemStoresOp(8173c99eb5174e02bb9d543b644c9397): perf score=2.188937
I20260812 06:19:48.935634 16369 maintenance_manager.cc:643] P 5c9d175dd3194a479f91d4cfdfa78ecc: FlushDeltaMemStoresOp(8173c99eb5174e02bb9d543b644c9397) complete. Timing: real 0.024s	user 0.011s	sys 0.009s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":6448,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:48.936183 16467 maintenance_manager.cc:419] P 5c9d175dd3194a479f91d4cfdfa78ecc: Scheduling MajorDeltaCompactionOp(8173c99eb5174e02bb9d543b644c9397): perf score=1.000000
I20260812 06:19:49.117851 16369 maintenance_manager.cc:643] P 5c9d175dd3194a479f91d4cfdfa78ecc: MajorDeltaCompactionOp(8173c99eb5174e02bb9d543b644c9397) complete. Timing: real 0.181s	user 0.120s	sys 0.057s 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":585,"lbm_read_time_us":12776,"lbm_reads_lt_1ms":572,"lbm_write_time_us":27827,"lbm_writes_lt_1ms":543,"mutex_wait_us":43,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":1792,"update_count":2500}
I20260812 06:19:49.118405 16467 maintenance_manager.cc:419] P 5c9d175dd3194a479f91d4cfdfa78ecc: Scheduling FlushDeltaMemStoresOp(8173c99eb5174e02bb9d543b644c9397): perf score=14.095187
I20260812 06:19:49.164990 16369 maintenance_manager.cc:643] P 5c9d175dd3194a479f91d4cfdfa78ecc: FlushDeltaMemStoresOp(8173c99eb5174e02bb9d543b644c9397) complete. Timing: real 0.046s	user 0.034s	sys 0.007s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":18020,"lbm_writes_lt_1ms":403,"reinsert_count":0,"spinlock_wait_cycles":896,"update_count":2000}
I20260812 06:19:49.165582 16467 maintenance_manager.cc:419] P 5c9d175dd3194a479f91d4cfdfa78ecc: Scheduling FlushDeltaMemStoresOp(8173c99eb5174e02bb9d543b644c9397): perf score=2.188937
I20260812 06:19:49.176469 16369 maintenance_manager.cc:643] P 5c9d175dd3194a479f91d4cfdfa78ecc: FlushDeltaMemStoresOp(8173c99eb5174e02bb9d543b644c9397) complete. Timing: real 0.011s	user 0.010s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3926,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:49.177116 16467 maintenance_manager.cc:419] P 5c9d175dd3194a479f91d4cfdfa78ecc: Scheduling MajorDeltaCompactionOp(8173c99eb5174e02bb9d543b644c9397): perf score=1.000000
I20260812 06:19:49.322299 16369 maintenance_manager.cc:643] P 5c9d175dd3194a479f91d4cfdfa78ecc: MajorDeltaCompactionOp(8173c99eb5174e02bb9d543b644c9397) complete. Timing: real 0.145s	user 0.100s	sys 0.045s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24815684,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":280,"lbm_read_time_us":8867,"lbm_reads_lt_1ms":572,"lbm_write_time_us":27681,"lbm_writes_lt_1ms":543,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":6144,"update_count":2500}
I20260812 06:19:49.322911 16467 maintenance_manager.cc:419] P 5c9d175dd3194a479f91d4cfdfa78ecc: Scheduling FlushDeltaMemStoresOp(8173c99eb5174e02bb9d543b644c9397): perf score=11.118625
I20260812 06:19:49.350473 16369 maintenance_manager.cc:643] P 5c9d175dd3194a479f91d4cfdfa78ecc: FlushDeltaMemStoresOp(8173c99eb5174e02bb9d543b644c9397) complete. Timing: real 0.027s	user 0.012s	sys 0.012s Metrics: {"bytes_written":12717734,"delete_count":0,"lbm_write_time_us":11530,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:19:49.351210 16467 maintenance_manager.cc:419] P 5c9d175dd3194a479f91d4cfdfa78ecc: Scheduling FlushDeltaMemStoresOp(8173c99eb5174e02bb9d543b644c9397): perf score=2.188937
I20260812 06:19:49.369633 16369 maintenance_manager.cc:643] P 5c9d175dd3194a479f91d4cfdfa78ecc: FlushDeltaMemStoresOp(8173c99eb5174e02bb9d543b644c9397) complete. Timing: real 0.018s	user 0.008s	sys 0.007s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":6846,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":92,"reinsert_count":0,"update_count":450}
I20260812 06:19:49.370169 16467 maintenance_manager.cc:419] P 5c9d175dd3194a479f91d4cfdfa78ecc: Scheduling MajorDeltaCompactionOp(8173c99eb5174e02bb9d543b644c9397): perf score=1.000000
I20260812 06:19:49.495155 16369 maintenance_manager.cc:643] P 5c9d175dd3194a479f91d4cfdfa78ecc: MajorDeltaCompactionOp(8173c99eb5174e02bb9d543b644c9397) complete. Timing: real 0.125s	user 0.087s	sys 0.035s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20713262,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"lbm_read_time_us":8540,"lbm_reads_lt_1ms":464,"lbm_write_time_us":23422,"lbm_writes_lt_1ms":443,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":6784,"update_count":2000}
I20260812 06:19:49.495914 16467 maintenance_manager.cc:419] P 5c9d175dd3194a479f91d4cfdfa78ecc: Scheduling FlushDeltaMemStoresOp(8173c99eb5174e02bb9d543b644c9397): perf score=10.126437
I20260812 06:19:49.534773 16369 maintenance_manager.cc:643] P 5c9d175dd3194a479f91d4cfdfa78ecc: FlushDeltaMemStoresOp(8173c99eb5174e02bb9d543b644c9397) complete. Timing: real 0.039s	user 0.019s	sys 0.013s Metrics: {"bytes_written":12307489,"delete_count":0,"lbm_write_time_us":15634,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":302,"reinsert_count":0,"update_count":1500}
I20260812 06:19:49.535339 16467 maintenance_manager.cc:419] P 5c9d175dd3194a479f91d4cfdfa78ecc: Scheduling FlushDeltaMemStoresOp(8173c99eb5174e02bb9d543b644c9397): perf score=2.188937
I20260812 06:19:49.545459 16369 maintenance_manager.cc:643] P 5c9d175dd3194a479f91d4cfdfa78ecc: FlushDeltaMemStoresOp(8173c99eb5174e02bb9d543b644c9397) complete. Timing: real 0.010s	user 0.008s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3530,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:49.546041 16467 maintenance_manager.cc:419] P 5c9d175dd3194a479f91d4cfdfa78ecc: Scheduling FlushMRSOp(8173c99eb5174e02bb9d543b644c9397): perf score=1.000000
I20260812 06:19:49.578192 16369 maintenance_manager.cc:643] P 5c9d175dd3194a479f91d4cfdfa78ecc: FlushMRSOp(8173c99eb5174e02bb9d543b644c9397) complete. Timing: real 0.032s	user 0.028s	sys 0.003s Metrics: {"bytes_written":1193509,"cfile_init":1,"dirs.queue_time_us":54,"dirs.run_cpu_time_us":212,"dirs.run_wall_time_us":1501,"drs_written":1,"lbm_read_time_us":37,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1884,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":29}
I20260812 06:19:49.578912 16467 maintenance_manager.cc:419] P 5c9d175dd3194a479f91d4cfdfa78ecc: Scheduling LogGCOp(8173c99eb5174e02bb9d543b644c9397): free 121006391 bytes of WAL
I20260812 06:19:49.579154 16369 log_reader.cc:385] T 8173c99eb5174e02bb9d543b644c9397: removed 12 log segments from log reader
I20260812 06:19:49.579228 16369 log.cc:1079] T 8173c99eb5174e02bb9d543b644c9397 P 5c9d175dd3194a479f91d4cfdfa78ecc: Deleting log segment in path: /tmp/dist-test-taskZHdGUU/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515581174630-15890-0/minicluster-data/ts-0-root/wals/8173c99eb5174e02bb9d543b644c9397/wal-000000015 (ops 71-75)
I20260812 06:19:49.579262 16369 log.cc:1079] T 8173c99eb5174e02bb9d543b644c9397 P 5c9d175dd3194a479f91d4cfdfa78ecc: Deleting log segment in path: /tmp/dist-test-taskZHdGUU/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515581174630-15890-0/minicluster-data/ts-0-root/wals/8173c99eb5174e02bb9d543b644c9397/wal-000000016 (ops 76-80)
I20260812 06:19:49.579296 16369 log.cc:1079] T 8173c99eb5174e02bb9d543b644c9397 P 5c9d175dd3194a479f91d4cfdfa78ecc: Deleting log segment in path: /tmp/dist-test-taskZHdGUU/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515581174630-15890-0/minicluster-data/ts-0-root/wals/8173c99eb5174e02bb9d543b644c9397/wal-000000017 (ops 81-85)
I20260812 06:19:49.579317 16369 log.cc:1079] T 8173c99eb5174e02bb9d543b644c9397 P 5c9d175dd3194a479f91d4cfdfa78ecc: Deleting log segment in path: /tmp/dist-test-taskZHdGUU/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515581174630-15890-0/minicluster-data/ts-0-root/wals/8173c99eb5174e02bb9d543b644c9397/wal-000000018 (ops 86-90)
I20260812 06:19:49.579348 16369 log.cc:1079] T 8173c99eb5174e02bb9d543b644c9397 P 5c9d175dd3194a479f91d4cfdfa78ecc: Deleting log segment in path: /tmp/dist-test-taskZHdGUU/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515581174630-15890-0/minicluster-data/ts-0-root/wals/8173c99eb5174e02bb9d543b644c9397/wal-000000019 (ops 91-95)
I20260812 06:19:49.579380 16369 log.cc:1079] T 8173c99eb5174e02bb9d543b644c9397 P 5c9d175dd3194a479f91d4cfdfa78ecc: Deleting log segment in path: /tmp/dist-test-taskZHdGUU/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515581174630-15890-0/minicluster-data/ts-0-root/wals/8173c99eb5174e02bb9d543b644c9397/wal-000000020 (ops 96-100)
I20260812 06:19:49.579411 16369 log.cc:1079] T 8173c99eb5174e02bb9d543b644c9397 P 5c9d175dd3194a479f91d4cfdfa78ecc: Deleting log segment in path: /tmp/dist-test-taskZHdGUU/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515581174630-15890-0/minicluster-data/ts-0-root/wals/8173c99eb5174e02bb9d543b644c9397/wal-000000021 (ops 101-105)
I20260812 06:19:49.579442 16369 log.cc:1079] T 8173c99eb5174e02bb9d543b644c9397 P 5c9d175dd3194a479f91d4cfdfa78ecc: Deleting log segment in path: /tmp/dist-test-taskZHdGUU/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515581174630-15890-0/minicluster-data/ts-0-root/wals/8173c99eb5174e02bb9d543b644c9397/wal-000000022 (ops 106-110)
I20260812 06:19:49.579473 16369 log.cc:1079] T 8173c99eb5174e02bb9d543b644c9397 P 5c9d175dd3194a479f91d4cfdfa78ecc: Deleting log segment in path: /tmp/dist-test-taskZHdGUU/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515581174630-15890-0/minicluster-data/ts-0-root/wals/8173c99eb5174e02bb9d543b644c9397/wal-000000023 (ops 111-114)
I20260812 06:19:49.579505 16369 log.cc:1079] T 8173c99eb5174e02bb9d543b644c9397 P 5c9d175dd3194a479f91d4cfdfa78ecc: Deleting log segment in path: /tmp/dist-test-taskZHdGUU/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515581174630-15890-0/minicluster-data/ts-0-root/wals/8173c99eb5174e02bb9d543b644c9397/wal-000000024 (ops 115-119)
I20260812 06:19:49.579536 16369 log.cc:1079] T 8173c99eb5174e02bb9d543b644c9397 P 5c9d175dd3194a479f91d4cfdfa78ecc: Deleting log segment in path: /tmp/dist-test-taskZHdGUU/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515581174630-15890-0/minicluster-data/ts-0-root/wals/8173c99eb5174e02bb9d543b644c9397/wal-000000025 (ops 120-124)
I20260812 06:19:49.579567 16369 log.cc:1079] T 8173c99eb5174e02bb9d543b644c9397 P 5c9d175dd3194a479f91d4cfdfa78ecc: Deleting log segment in path: /tmp/dist-test-taskZHdGUU/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515581174630-15890-0/minicluster-data/ts-0-root/wals/8173c99eb5174e02bb9d543b644c9397/wal-000000026 (ops 125-129)
I20260812 06:19:49.601153 16369 maintenance_manager.cc:643] P 5c9d175dd3194a479f91d4cfdfa78ecc: LogGCOp(8173c99eb5174e02bb9d543b644c9397) complete. Timing: real 0.022s	user 0.002s	sys 0.019s Metrics: {}
I20260812 06:19:49.601660 16467 maintenance_manager.cc:419] P 5c9d175dd3194a479f91d4cfdfa78ecc: Scheduling UndoDeltaBlockGCOp(8173c99eb5174e02bb9d543b644c9397): 462 bytes on disk
I20260812 06:19:49.602099 16369 maintenance_manager.cc:643] P 5c9d175dd3194a479f91d4cfdfa78ecc: UndoDeltaBlockGCOp(8173c99eb5174e02bb9d543b644c9397) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":48,"lbm_reads_lt_1ms":4}
I20260812 06:19:49.602613 16467 maintenance_manager.cc:419] P 5c9d175dd3194a479f91d4cfdfa78ecc: Scheduling FlushDeltaMemStoresOp(8173c99eb5174e02bb9d543b644c9397): perf score=3.181125
I20260812 06:19:49.616130 16369 maintenance_manager.cc:643] P 5c9d175dd3194a479f91d4cfdfa78ecc: FlushDeltaMemStoresOp(8173c99eb5174e02bb9d543b644c9397) complete. Timing: real 0.013s	user 0.004s	sys 0.007s Metrics: {"bytes_written":4512900,"delete_count":0,"lbm_write_time_us":4221,"lbm_writes_lt_1ms":113,"reinsert_count":0,"update_count":550}
I20260812 06:19:49.616552 16467 maintenance_manager.cc:419] P 5c9d175dd3194a479f91d4cfdfa78ecc: Scheduling FlushDeltaMemStoresOp(8173c99eb5174e02bb9d543b644c9397): perf score=2.188937
I20260812 06:19:49.625839 16369 maintenance_manager.cc:643] P 5c9d175dd3194a479f91d4cfdfa78ecc: FlushDeltaMemStoresOp(8173c99eb5174e02bb9d543b644c9397) complete. Timing: real 0.009s	user 0.004s	sys 0.003s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3273,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:19:49.626289 16467 maintenance_manager.cc:419] P 5c9d175dd3194a479f91d4cfdfa78ecc: Scheduling MajorDeltaCompactionOp(8173c99eb5174e02bb9d543b644c9397): perf score=1.000000
I20260812 06:19:49.780725 16369 maintenance_manager.cc:643] P 5c9d175dd3194a479f91d4cfdfa78ecc: MajorDeltaCompactionOp(8173c99eb5174e02bb9d543b644c9397) complete. Timing: real 0.154s	user 0.121s	sys 0.031s Metrics: {"cfile_cache_miss":634,"cfile_cache_miss_bytes":28918320,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":140,"lbm_read_time_us":10643,"lbm_reads_lt_1ms":674,"lbm_write_time_us":29942,"lbm_writes_lt_1ms":643,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":12800,"thread_start_us":83,"threads_started":1,"update_count":3000}
I20260812 06:19:49.782330 16467 maintenance_manager.cc:419] P 5c9d175dd3194a479f91d4cfdfa78ecc: Scheduling FlushDeltaMemStoresOp(8173c99eb5174e02bb9d543b644c9397): perf score=14.095187
I20260812 06:19:49.829957 16369 maintenance_manager.cc:643] P 5c9d175dd3194a479f91d4cfdfa78ecc: FlushDeltaMemStoresOp(8173c99eb5174e02bb9d543b644c9397) complete. Timing: real 0.047s	user 0.030s	sys 0.012s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":19181,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:49.830490 16467 maintenance_manager.cc:419] P 5c9d175dd3194a479f91d4cfdfa78ecc: Scheduling FlushDeltaMemStoresOp(8173c99eb5174e02bb9d543b644c9397): perf score=2.188937
I20260812 06:19:49.841372 16369 maintenance_manager.cc:643] P 5c9d175dd3194a479f91d4cfdfa78ecc: FlushDeltaMemStoresOp(8173c99eb5174e02bb9d543b644c9397) complete. Timing: real 0.011s	user 0.009s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3627,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:49.842013 16467 maintenance_manager.cc:419] P 5c9d175dd3194a479f91d4cfdfa78ecc: Scheduling MajorDeltaCompactionOp(8173c99eb5174e02bb9d543b644c9397): perf score=1.000000
I20260812 06:19:49.995147 16369 maintenance_manager.cc:643] P 5c9d175dd3194a479f91d4cfdfa78ecc: MajorDeltaCompactionOp(8173c99eb5174e02bb9d543b644c9397) complete. Timing: real 0.153s	user 0.119s	sys 0.029s 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":770,"lbm_read_time_us":10247,"lbm_reads_lt_1ms":572,"lbm_write_time_us":28373,"lbm_writes_lt_1ms":543,"mutex_wait_us":62,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":13184,"update_count":2500}
I20260812 06:19:49.995854 16467 maintenance_manager.cc:419] P 5c9d175dd3194a479f91d4cfdfa78ecc: Scheduling FlushDeltaMemStoresOp(8173c99eb5174e02bb9d543b644c9397): perf score=12.110812
I20260812 06:19:50.031076 16369 maintenance_manager.cc:643] P 5c9d175dd3194a479f91d4cfdfa78ecc: FlushDeltaMemStoresOp(8173c99eb5174e02bb9d543b644c9397) complete. Timing: real 0.035s	user 0.019s	sys 0.013s Metrics: {"bytes_written":13784351,"delete_count":0,"lbm_write_time_us":14870,"lbm_writes_lt_1ms":339,"reinsert_count":0,"update_count":1680}
I20260812 06:19:50.031520 16467 maintenance_manager.cc:419] P 5c9d175dd3194a479f91d4cfdfa78ecc: Scheduling FlushDeltaMemStoresOp(8173c99eb5174e02bb9d543b644c9397): perf score=1.196750
I20260812 06:19:50.042678 16369 maintenance_manager.cc:643] P 5c9d175dd3194a479f91d4cfdfa78ecc: FlushDeltaMemStoresOp(8173c99eb5174e02bb9d543b644c9397) complete. Timing: real 0.011s	user 0.005s	sys 0.004s Metrics: {"bytes_written":2625754,"delete_count":0,"lbm_write_time_us":3866,"lbm_writes_lt_1ms":67,"reinsert_count":0,"update_count":320}
I20260812 06:19:50.043155 16467 maintenance_manager.cc:419] P 5c9d175dd3194a479f91d4cfdfa78ecc: Scheduling MajorDeltaCompactionOp(8173c99eb5174e02bb9d543b644c9397): perf score=1.000000
I20260812 06:19:50.186415 16369 maintenance_manager.cc:643] P 5c9d175dd3194a479f91d4cfdfa78ecc: MajorDeltaCompactionOp(8173c99eb5174e02bb9d543b644c9397) complete. Timing: real 0.143s	user 0.085s	sys 0.056s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20713228,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":964,"lbm_read_time_us":10431,"lbm_reads_lt_1ms":468,"lbm_write_time_us":23712,"lbm_writes_lt_1ms":443,"mutex_wait_us":291,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":1792,"update_count":2000}
I20260812 06:19:50.190539 16467 maintenance_manager.cc:419] P 5c9d175dd3194a479f91d4cfdfa78ecc: Scheduling FlushDeltaMemStoresOp(8173c99eb5174e02bb9d543b644c9397): perf score=11.118625
I20260812 06:19:50.225711 16369 maintenance_manager.cc:643] P 5c9d175dd3194a479f91d4cfdfa78ecc: FlushDeltaMemStoresOp(8173c99eb5174e02bb9d543b644c9397) complete. Timing: real 0.035s	user 0.016s	sys 0.017s Metrics: {"bytes_written":12717735,"delete_count":0,"lbm_write_time_us":14975,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:19:50.226200 16467 maintenance_manager.cc:419] P 5c9d175dd3194a479f91d4cfdfa78ecc: Scheduling FlushDeltaMemStoresOp(8173c99eb5174e02bb9d543b644c9397): perf score=2.188937
I20260812 06:19:50.239300 16369 maintenance_manager.cc:643] P 5c9d175dd3194a479f91d4cfdfa78ecc: FlushDeltaMemStoresOp(8173c99eb5174e02bb9d543b644c9397) complete. Timing: real 0.013s	user 0.006s	sys 0.004s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":4772,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:19:50.239809 16467 maintenance_manager.cc:419] P 5c9d175dd3194a479f91d4cfdfa78ecc: Scheduling MajorDeltaCompactionOp(8173c99eb5174e02bb9d543b644c9397): perf score=1.000000
I20260812 06:19:50.366966 16369 maintenance_manager.cc:643] P 5c9d175dd3194a479f91d4cfdfa78ecc: MajorDeltaCompactionOp(8173c99eb5174e02bb9d543b644c9397) complete. Timing: real 0.127s	user 0.109s	sys 0.016s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20713263,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":427,"lbm_read_time_us":9826,"lbm_reads_lt_1ms":472,"lbm_write_time_us":22383,"lbm_writes_lt_1ms":443,"mutex_wait_us":58,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":990720,"update_count":2000}
I20260812 06:19:50.367522 16467 maintenance_manager.cc:419] P 5c9d175dd3194a479f91d4cfdfa78ecc: Scheduling FlushDeltaMemStoresOp(8173c99eb5174e02bb9d543b644c9397): perf score=10.126437
I20260812 06:19:50.405599 16369 maintenance_manager.cc:643] P 5c9d175dd3194a479f91d4cfdfa78ecc: FlushDeltaMemStoresOp(8173c99eb5174e02bb9d543b644c9397) complete. Timing: real 0.038s	user 0.019s	sys 0.017s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":15985,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":302,"reinsert_count":0,"update_count":1500}
I20260812 06:19:50.406106 16467 maintenance_manager.cc:419] P 5c9d175dd3194a479f91d4cfdfa78ecc: Scheduling FlushDeltaMemStoresOp(8173c99eb5174e02bb9d543b644c9397): perf score=2.188937
I20260812 06:19:50.422009 16369 maintenance_manager.cc:643] P 5c9d175dd3194a479f91d4cfdfa78ecc: FlushDeltaMemStoresOp(8173c99eb5174e02bb9d543b644c9397) complete. Timing: real 0.016s	user 0.010s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5975,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:50.422611 16467 maintenance_manager.cc:419] P 5c9d175dd3194a479f91d4cfdfa78ecc: Scheduling MajorDeltaCompactionOp(8173c99eb5174e02bb9d543b644c9397): perf score=1.000000
I20260812 06:19:50.539923 16369 maintenance_manager.cc:643] P 5c9d175dd3194a479f91d4cfdfa78ecc: MajorDeltaCompactionOp(8173c99eb5174e02bb9d543b644c9397) complete. Timing: real 0.117s	user 0.095s	sys 0.021s 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":414,"lbm_read_time_us":8133,"lbm_reads_lt_1ms":472,"lbm_write_time_us":20652,"lbm_writes_lt_1ms":443,"mutex_wait_us":73,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":3072,"update_count":2000}
I20260812 06:19:50.540458 16467 maintenance_manager.cc:419] P 5c9d175dd3194a479f91d4cfdfa78ecc: Scheduling FlushDeltaMemStoresOp(8173c99eb5174e02bb9d543b644c9397): perf score=10.126437
I20260812 06:19:50.576495 16369 maintenance_manager.cc:643] P 5c9d175dd3194a479f91d4cfdfa78ecc: FlushDeltaMemStoresOp(8173c99eb5174e02bb9d543b644c9397) complete. Timing: real 0.036s	user 0.026s	sys 0.009s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":15382,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:19:50.577054 16467 maintenance_manager.cc:419] P 5c9d175dd3194a479f91d4cfdfa78ecc: Scheduling FlushDeltaMemStoresOp(8173c99eb5174e02bb9d543b644c9397): perf score=2.188937
I20260812 06:19:50.592397 16369 maintenance_manager.cc:643] P 5c9d175dd3194a479f91d4cfdfa78ecc: FlushDeltaMemStoresOp(8173c99eb5174e02bb9d543b644c9397) complete. Timing: real 0.015s	user 0.010s	sys 0.004s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":5758,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:50.592914 16467 maintenance_manager.cc:419] P 5c9d175dd3194a479f91d4cfdfa78ecc: Scheduling MajorDeltaCompactionOp(8173c99eb5174e02bb9d543b644c9397): perf score=1.000000
I20260812 06:19:50.706161 16369 maintenance_manager.cc:643] P 5c9d175dd3194a479f91d4cfdfa78ecc: MajorDeltaCompactionOp(8173c99eb5174e02bb9d543b644c9397) complete. Timing: real 0.113s	user 0.090s	sys 0.023s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20713271,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":161,"lbm_read_time_us":8107,"lbm_reads_lt_1ms":472,"lbm_write_time_us":20922,"lbm_writes_lt_1ms":443,"mutex_wait_us":26,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":6144,"update_count":2000}
I20260812 06:19:50.706995 16467 maintenance_manager.cc:419] P 5c9d175dd3194a479f91d4cfdfa78ecc: Scheduling FlushDeltaMemStoresOp(8173c99eb5174e02bb9d543b644c9397): perf score=10.126437
I20260812 06:19:50.762796 16369 maintenance_manager.cc:643] P 5c9d175dd3194a479f91d4cfdfa78ecc: FlushDeltaMemStoresOp(8173c99eb5174e02bb9d543b644c9397) complete. Timing: real 0.056s	user 0.020s	sys 0.023s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":16583,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:19:50.763567 16467 maintenance_manager.cc:419] P 5c9d175dd3194a479f91d4cfdfa78ecc: Scheduling FlushDeltaMemStoresOp(8173c99eb5174e02bb9d543b644c9397): perf score=2.188937
I20260812 06:19:50.774401 16369 maintenance_manager.cc:643] P 5c9d175dd3194a479f91d4cfdfa78ecc: FlushDeltaMemStoresOp(8173c99eb5174e02bb9d543b644c9397) 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:50.774912 16467 maintenance_manager.cc:419] P 5c9d175dd3194a479f91d4cfdfa78ecc: Scheduling MajorDeltaCompactionOp(8173c99eb5174e02bb9d543b644c9397): perf score=1.000000
I20260812 06:19:50.909723 16369 maintenance_manager.cc:643] P 5c9d175dd3194a479f91d4cfdfa78ecc: MajorDeltaCompactionOp(8173c99eb5174e02bb9d543b644c9397) complete. Timing: real 0.135s	user 0.086s	sys 0.049s 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":181,"lbm_read_time_us":10183,"lbm_reads_lt_1ms":472,"lbm_write_time_us":20948,"lbm_writes_lt_1ms":443,"mutex_wait_us":20,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":27136,"update_count":2000}
I20260812 06:19:50.910421 16467 maintenance_manager.cc:419] P 5c9d175dd3194a479f91d4cfdfa78ecc: Scheduling FlushDeltaMemStoresOp(8173c99eb5174e02bb9d543b644c9397): perf score=10.126437
I20260812 06:19:50.954654 16369 maintenance_manager.cc:643] P 5c9d175dd3194a479f91d4cfdfa78ecc: FlushDeltaMemStoresOp(8173c99eb5174e02bb9d543b644c9397) complete. Timing: real 0.044s	user 0.028s	sys 0.012s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":19074,"lbm_writes_1-10_ms":2,"lbm_writes_lt_1ms":301,"reinsert_count":0,"update_count":1500}
I20260812 06:19:50.955183 16467 maintenance_manager.cc:419] P 5c9d175dd3194a479f91d4cfdfa78ecc: Scheduling FlushDeltaMemStoresOp(8173c99eb5174e02bb9d543b644c9397): perf score=2.188937
I20260812 06:19:50.965348 16369 maintenance_manager.cc:643] P 5c9d175dd3194a479f91d4cfdfa78ecc: FlushDeltaMemStoresOp(8173c99eb5174e02bb9d543b644c9397) complete. Timing: real 0.010s	user 0.008s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3604,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:50.966063 16467 maintenance_manager.cc:419] P 5c9d175dd3194a479f91d4cfdfa78ecc: Scheduling FlushMRSOp(8173c99eb5174e02bb9d543b644c9397): perf score=1.000000
I20260812 06:19:50.994397 16369 maintenance_manager.cc:643] P 5c9d175dd3194a479f91d4cfdfa78ecc: FlushMRSOp(8173c99eb5174e02bb9d543b644c9397) complete. Timing: real 0.028s	user 0.026s	sys 0.000s Metrics: {"bytes_written":1275447,"cfile_init":1,"dirs.queue_time_us":86,"dirs.run_cpu_time_us":211,"dirs.run_wall_time_us":1246,"drs_written":1,"lbm_read_time_us":62,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1395,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":31}
I20260812 06:19:50.995148 16467 maintenance_manager.cc:419] P 5c9d175dd3194a479f91d4cfdfa78ecc: Scheduling LogGCOp(8173c99eb5174e02bb9d543b644c9397): free 128867779 bytes of WAL
I20260812 06:19:50.995393 16369 log_reader.cc:385] T 8173c99eb5174e02bb9d543b644c9397: removed 13 log segments from log reader
I20260812 06:19:50.995455 16369 log.cc:1079] T 8173c99eb5174e02bb9d543b644c9397 P 5c9d175dd3194a479f91d4cfdfa78ecc: Deleting log segment in path: /tmp/dist-test-taskZHdGUU/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515581174630-15890-0/minicluster-data/ts-0-root/wals/8173c99eb5174e02bb9d543b644c9397/wal-000000027 (ops 130-134)
I20260812 06:19:50.995504 16369 log.cc:1079] T 8173c99eb5174e02bb9d543b644c9397 P 5c9d175dd3194a479f91d4cfdfa78ecc: Deleting log segment in path: /tmp/dist-test-taskZHdGUU/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515581174630-15890-0/minicluster-data/ts-0-root/wals/8173c99eb5174e02bb9d543b644c9397/wal-000000028 (ops 135-138)
I20260812 06:19:50.995534 16369 log.cc:1079] T 8173c99eb5174e02bb9d543b644c9397 P 5c9d175dd3194a479f91d4cfdfa78ecc: Deleting log segment in path: /tmp/dist-test-taskZHdGUU/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515581174630-15890-0/minicluster-data/ts-0-root/wals/8173c99eb5174e02bb9d543b644c9397/wal-000000029 (ops 139-143)
I20260812 06:19:50.995558 16369 log.cc:1079] T 8173c99eb5174e02bb9d543b644c9397 P 5c9d175dd3194a479f91d4cfdfa78ecc: Deleting log segment in path: /tmp/dist-test-taskZHdGUU/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515581174630-15890-0/minicluster-data/ts-0-root/wals/8173c99eb5174e02bb9d543b644c9397/wal-000000030 (ops 144-148)
I20260812 06:19:50.995589 16369 log.cc:1079] T 8173c99eb5174e02bb9d543b644c9397 P 5c9d175dd3194a479f91d4cfdfa78ecc: Deleting log segment in path: /tmp/dist-test-taskZHdGUU/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515581174630-15890-0/minicluster-data/ts-0-root/wals/8173c99eb5174e02bb9d543b644c9397/wal-000000031 (ops 149-153)
I20260812 06:19:50.995618 16369 log.cc:1079] T 8173c99eb5174e02bb9d543b644c9397 P 5c9d175dd3194a479f91d4cfdfa78ecc: Deleting log segment in path: /tmp/dist-test-taskZHdGUU/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515581174630-15890-0/minicluster-data/ts-0-root/wals/8173c99eb5174e02bb9d543b644c9397/wal-000000032 (ops 154-158)
I20260812 06:19:50.995645 16369 log.cc:1079] T 8173c99eb5174e02bb9d543b644c9397 P 5c9d175dd3194a479f91d4cfdfa78ecc: Deleting log segment in path: /tmp/dist-test-taskZHdGUU/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515581174630-15890-0/minicluster-data/ts-0-root/wals/8173c99eb5174e02bb9d543b644c9397/wal-000000033 (ops 159-162)
I20260812 06:19:50.995707 16369 log.cc:1079] T 8173c99eb5174e02bb9d543b644c9397 P 5c9d175dd3194a479f91d4cfdfa78ecc: Deleting log segment in path: /tmp/dist-test-taskZHdGUU/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515581174630-15890-0/minicluster-data/ts-0-root/wals/8173c99eb5174e02bb9d543b644c9397/wal-000000034 (ops 163-167)
I20260812 06:19:50.995738 16369 log.cc:1079] T 8173c99eb5174e02bb9d543b644c9397 P 5c9d175dd3194a479f91d4cfdfa78ecc: Deleting log segment in path: /tmp/dist-test-taskZHdGUU/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515581174630-15890-0/minicluster-data/ts-0-root/wals/8173c99eb5174e02bb9d543b644c9397/wal-000000035 (ops 168-172)
I20260812 06:19:50.995770 16369 log.cc:1079] T 8173c99eb5174e02bb9d543b644c9397 P 5c9d175dd3194a479f91d4cfdfa78ecc: Deleting log segment in path: /tmp/dist-test-taskZHdGUU/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515581174630-15890-0/minicluster-data/ts-0-root/wals/8173c99eb5174e02bb9d543b644c9397/wal-000000036 (ops 173-176)
I20260812 06:19:50.995800 16369 log.cc:1079] T 8173c99eb5174e02bb9d543b644c9397 P 5c9d175dd3194a479f91d4cfdfa78ecc: Deleting log segment in path: /tmp/dist-test-taskZHdGUU/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515581174630-15890-0/minicluster-data/ts-0-root/wals/8173c99eb5174e02bb9d543b644c9397/wal-000000037 (ops 177-181)
I20260812 06:19:50.995828 16369 log.cc:1079] T 8173c99eb5174e02bb9d543b644c9397 P 5c9d175dd3194a479f91d4cfdfa78ecc: Deleting log segment in path: /tmp/dist-test-taskZHdGUU/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515581174630-15890-0/minicluster-data/ts-0-root/wals/8173c99eb5174e02bb9d543b644c9397/wal-000000038 (ops 182-186)
I20260812 06:19:50.995855 16369 log.cc:1079] T 8173c99eb5174e02bb9d543b644c9397 P 5c9d175dd3194a479f91d4cfdfa78ecc: Deleting log segment in path: /tmp/dist-test-taskZHdGUU/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515581174630-15890-0/minicluster-data/ts-0-root/wals/8173c99eb5174e02bb9d543b644c9397/wal-000000039 (ops 187-191)
I20260812 06:19:51.022637 16369 maintenance_manager.cc:643] P 5c9d175dd3194a479f91d4cfdfa78ecc: LogGCOp(8173c99eb5174e02bb9d543b644c9397) complete. Timing: real 0.027s	user 0.001s	sys 0.023s Metrics: {}
I20260812 06:19:51.023031 16467 maintenance_manager.cc:419] P 5c9d175dd3194a479f91d4cfdfa78ecc: Scheduling FlushDeltaMemStoresOp(8173c99eb5174e02bb9d543b644c9397): perf score=3.181125
I20260812 06:19:51.044755 16369 maintenance_manager.cc:643] P 5c9d175dd3194a479f91d4cfdfa78ecc: FlushDeltaMemStoresOp(8173c99eb5174e02bb9d543b644c9397) complete. Timing: real 0.022s	user 0.007s	sys 0.010s Metrics: {"bytes_written":4512901,"delete_count":0,"lbm_write_time_us":4056,"lbm_writes_lt_1ms":113,"reinsert_count":0,"update_count":550}
I20260812 06:19:51.045387 16467 maintenance_manager.cc:419] P 5c9d175dd3194a479f91d4cfdfa78ecc: Scheduling UndoDeltaBlockGCOp(8173c99eb5174e02bb9d543b644c9397): 481 bytes on disk
I20260812 06:19:51.045868 16369 maintenance_manager.cc:643] P 5c9d175dd3194a479f91d4cfdfa78ecc: UndoDeltaBlockGCOp(8173c99eb5174e02bb9d543b644c9397) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":61,"lbm_reads_lt_1ms":4}
I20260812 06:19:51.046404 16467 maintenance_manager.cc:419] P 5c9d175dd3194a479f91d4cfdfa78ecc: Scheduling FlushDeltaMemStoresOp(8173c99eb5174e02bb9d543b644c9397): perf score=2.188937
I20260812 06:19:51.060963 16369 maintenance_manager.cc:643] P 5c9d175dd3194a479f91d4cfdfa78ecc: FlushDeltaMemStoresOp(8173c99eb5174e02bb9d543b644c9397) complete. Timing: real 0.014s	user 0.008s	sys 0.005s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":5311,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:19:51.061499 16467 maintenance_manager.cc:419] P 5c9d175dd3194a479f91d4cfdfa78ecc: Scheduling MajorDeltaCompactionOp(8173c99eb5174e02bb9d543b644c9397): perf score=1.000000
I20260812 06:19:51.214423 15890 heavy-update-compaction-itest.cc:229] Time spent updating: real 4.700s	user 1.748s	sys 0.135s
I20260812 06:19:51.257490 16369 maintenance_manager.cc:643] P 5c9d175dd3194a479f91d4cfdfa78ecc: MajorDeltaCompactionOp(8173c99eb5174e02bb9d543b644c9397) complete. Timing: real 0.196s	user 0.104s	sys 0.089s Metrics: {"cfile_cache_miss":634,"cfile_cache_miss_bytes":28918322,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"lbm_read_time_us":14843,"lbm_reads_lt_1ms":670,"lbm_write_time_us":32244,"lbm_writes_lt_1ms":643,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":6656,"update_count":3000}
I20260812 06:19:51.258003 16467 maintenance_manager.cc:419] P 5c9d175dd3194a479f91d4cfdfa78ecc: Scheduling FlushDeltaMemStoresOp(8173c99eb5174e02bb9d543b644c9397): perf score=10.126437
I20260812 06:19:51.283833 15890 heavy-update-compaction-itest.cc:265] Time spent scanning: real 0.069s	user 0.003s	sys 0.000s
I20260812 06:19:51.284302 15890 tablet_server.cc:179] TabletServer@127.15.132.129:0 shutting down...
I20260812 06:19:51.286304 16369 maintenance_manager.cc:643] P 5c9d175dd3194a479f91d4cfdfa78ecc: FlushDeltaMemStoresOp(8173c99eb5174e02bb9d543b644c9397) complete. Timing: real 0.028s	user 0.014s	sys 0.012s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":12321,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:19:51.286957 16467 maintenance_manager.cc:419] P 5c9d175dd3194a479f91d4cfdfa78ecc: Scheduling MajorDeltaCompactionOp(8173c99eb5174e02bb9d543b644c9397): perf score=1.000000
I20260812 06:19:51.376665 16369 maintenance_manager.cc:643] P 5c9d175dd3194a479f91d4cfdfa78ecc: MajorDeltaCompactionOp(8173c99eb5174e02bb9d543b644c9397) complete. Timing: real 0.090s	user 0.066s	sys 0.024s Metrics: {"cfile_cache_miss":331,"cfile_cache_miss_bytes":16610741,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":1,"delta_iterators_relevant":1,"dirs.queue_time_us":329,"lbm_read_time_us":6135,"lbm_reads_lt_1ms":367,"lbm_write_time_us":15401,"lbm_writes_lt_1ms":343,"mutex_wait_us":57,"peak_mem_usage":38262756,"reinsert_count":0,"update_count":1500}
I20260812 06:19:51.377374 15890 ts_tablet_manager.cc:1507] Shutting down tablet manager...
I20260812 06:19:51.377619 15890 tablet_replica.cc:333] T 8173c99eb5174e02bb9d543b644c9397 P 5c9d175dd3194a479f91d4cfdfa78ecc: stopping tablet replica
I20260812 06:19:51.377753 15890 raft_consensus.cc:2243] T 8173c99eb5174e02bb9d543b644c9397 P 5c9d175dd3194a479f91d4cfdfa78ecc [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:19:51.377907 15890 raft_consensus.cc:2272] T 8173c99eb5174e02bb9d543b644c9397 P 5c9d175dd3194a479f91d4cfdfa78ecc [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:19:51.392072 15890 tablet_server.cc:196] TabletServer@127.15.132.129:0 shutdown complete.
I20260812 06:19:51.409474 15890 master.cc:562] Master@127.15.132.190:35993 shutting down...
I20260812 06:19:51.412968 15890 raft_consensus.cc:2243] T 00000000000000000000000000000000 P 924f881f305447f391e8b7a0868e9b6c [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:19:51.413146 15890 raft_consensus.cc:2272] T 00000000000000000000000000000000 P 924f881f305447f391e8b7a0868e9b6c [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:19:51.413213 15890 tablet_replica.cc:333] T 00000000000000000000000000000000 P 924f881f305447f391e8b7a0868e9b6c: stopping tablet replica
I20260812 06:19:51.426499 15890 master.cc:584] Master@127.15.132.190:35993 shutdown complete.
[       OK ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/1 (5164 ms)
[----------] 2 tests from EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy (10314 ms total)

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