[==========] Running 2 tests from 1 test suite.
[----------] Global test environment set-up.
[----------] 2 tests from EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy
[ RUN      ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/0
WARNING: Logging before InitGoogleLogging() is written to STDERR
I20260812 06:18:03.285284 22190 internal_mini_cluster.cc:156] Creating distributed mini masters. Addrs: 127.21.171.190:37173
I20260812 06:18:03.286307 22190 env_posix.cc:2285] Not raising this process' open files per process limit of 1048576; it is already as high as it can go
I20260812 06:18:03.286906 22190 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:18:03.293578 22195 instance_detector.cc:116] could not retrieve AWS instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:18:03.293656 22190 server_base.cc:1061] running on GCE node
W20260812 06:18:03.293587 22199 instance_detector.cc:116] could not retrieve OpenStack instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:18:03.293879 22197 instance_detector.cc:116] could not retrieve Azure instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:18:03.294413 22190 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:18:03.294543 22190 system_unsync_time.cc:38] NTP support is disabled. Clock error bounds will not be accurate. This configuration is not suitable for distributed clusters.
I20260812 06:18:03.294589 22190 hybrid_clock.cc:648] HybridClock initialized: now 1786515483294587 us; error 0 us; skew 500 ppm
I20260812 06:18:03.296622 22190 webserver.cc:533] Webserver started at http://127.21.171.190:44523/ using document root <none> and password file <none>
I20260812 06:18:03.297240 22190 fs_manager.cc:362] Metadata directory not provided
I20260812 06:18:03.297333 22190 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:18:03.297600 22190 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:18:03.299338 22190 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskoJaC7T/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515483274578-22190-0/minicluster-data/master-0-root/instance:
uuid: "0c9b1dc981a740b9946d3e1120d868a5"
format_stamp: "Formatted at 2026-08-12 06:18:03 on dist-test-slave-qg60"
I20260812 06:18:03.302922 22190 fs_manager.cc:696] Time spent creating directory manager: real 0.003s	user 0.005s	sys 0.000s
I20260812 06:18:03.305101 22207 log_block_manager.cc:4127] Time spent loading block containers with low live blocks: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:18:03.306162 22190 fs_manager.cc:730] Time spent opening block manager: real 0.002s	user 0.003s	sys 0.000s
I20260812 06:18:03.306301 22190 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskoJaC7T/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515483274578-22190-0/minicluster-data/master-0-root
uuid: "0c9b1dc981a740b9946d3e1120d868a5"
format_stamp: "Formatted at 2026-08-12 06:18:03 on dist-test-slave-qg60"
I20260812 06:18:03.306407 22190 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskoJaC7T/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515483274578-22190-0/minicluster-data/master-0-root
metadata directory: /tmp/dist-test-taskoJaC7T/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515483274578-22190-0/minicluster-data/master-0-root
1 data directories: /tmp/dist-test-taskoJaC7T/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515483274578-22190-0/minicluster-data/master-0-root/data
Total live blocks: 0
Total live bytes: 0
Total live bytes (after alignment): 0
Total number of LBM containers: 0 (0 full)
Did not check for missing blocks
Did not check for orphaned blocks
Total full LBM containers with extra space: 0 (0 repaired)
Total full LBM container extra space in bytes: 0 (0 repaired)
Total incomplete LBM containers: 0 (0 repaired)
Total LBM partial records: 0 (0 repaired)
Total corrupted LBM metadata records in RocksDB: 0 (0 repaired)
I20260812 06:18:03.321143 22190 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:18:03.321803 22190 env_posix.cc:2285] Not raising this process' running threads per effective uid limit of 18446744073709551615; it is already as high as it can go
I20260812 06:18:03.321990 22190 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:18:03.331084 22263 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.21.171.190:37173 every 8 connection(s)
I20260812 06:18:03.331084 22190 rpc_server.cc:307] RPC server started. Bound to: 127.21.171.190:37173
I20260812 06:18:03.333606 22267 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet 00000000000000000000000000000000. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:18:03.339134 22267 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P 0c9b1dc981a740b9946d3e1120d868a5: Bootstrap starting.
I20260812 06:18:03.341676 22267 tablet_bootstrap.cc:654] T 00000000000000000000000000000000 P 0c9b1dc981a740b9946d3e1120d868a5: Neither blocks nor log segments found. Creating new log.
I20260812 06:18:03.342609 22267 log.cc:826] T 00000000000000000000000000000000 P 0c9b1dc981a740b9946d3e1120d868a5: Log is configured to *not* fsync() on all Append() calls
I20260812 06:18:03.344468 22267 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P 0c9b1dc981a740b9946d3e1120d868a5: No bootstrap required, opened a new log
I20260812 06:18:03.347301 22267 raft_consensus.cc:359] T 00000000000000000000000000000000 P 0c9b1dc981a740b9946d3e1120d868a5 [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "0c9b1dc981a740b9946d3e1120d868a5" member_type: VOTER }
I20260812 06:18:03.347472 22267 raft_consensus.cc:385] T 00000000000000000000000000000000 P 0c9b1dc981a740b9946d3e1120d868a5 [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:18:03.347522 22267 raft_consensus.cc:740] T 00000000000000000000000000000000 P 0c9b1dc981a740b9946d3e1120d868a5 [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: 0c9b1dc981a740b9946d3e1120d868a5, State: Initialized, Role: FOLLOWER
I20260812 06:18:03.348079 22267 consensus_queue.cc:260] T 00000000000000000000000000000000 P 0c9b1dc981a740b9946d3e1120d868a5 [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: "0c9b1dc981a740b9946d3e1120d868a5" member_type: VOTER }
I20260812 06:18:03.348214 22267 raft_consensus.cc:399] T 00000000000000000000000000000000 P 0c9b1dc981a740b9946d3e1120d868a5 [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:18:03.348261 22267 raft_consensus.cc:493] T 00000000000000000000000000000000 P 0c9b1dc981a740b9946d3e1120d868a5 [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:18:03.348390 22267 raft_consensus.cc:3060] T 00000000000000000000000000000000 P 0c9b1dc981a740b9946d3e1120d868a5 [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:18:03.349355 22267 raft_consensus.cc:515] T 00000000000000000000000000000000 P 0c9b1dc981a740b9946d3e1120d868a5 [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "0c9b1dc981a740b9946d3e1120d868a5" member_type: VOTER }
I20260812 06:18:03.349751 22267 leader_election.cc:304] T 00000000000000000000000000000000 P 0c9b1dc981a740b9946d3e1120d868a5 [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: 0c9b1dc981a740b9946d3e1120d868a5; no voters: 
I20260812 06:18:03.350036 22267 leader_election.cc:290] T 00000000000000000000000000000000 P 0c9b1dc981a740b9946d3e1120d868a5 [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:18:03.350203 22271 raft_consensus.cc:2804] T 00000000000000000000000000000000 P 0c9b1dc981a740b9946d3e1120d868a5 [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:18:03.350469 22271 raft_consensus.cc:697] T 00000000000000000000000000000000 P 0c9b1dc981a740b9946d3e1120d868a5 [term 1 LEADER]: Becoming Leader. State: Replica: 0c9b1dc981a740b9946d3e1120d868a5, State: Running, Role: LEADER
I20260812 06:18:03.350908 22271 consensus_queue.cc:237] T 00000000000000000000000000000000 P 0c9b1dc981a740b9946d3e1120d868a5 [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: "0c9b1dc981a740b9946d3e1120d868a5" member_type: VOTER }
I20260812 06:18:03.351215 22267 sys_catalog.cc:565] T 00000000000000000000000000000000 P 0c9b1dc981a740b9946d3e1120d868a5 [sys.catalog]: configured and running, proceeding with master startup.
I20260812 06:18:03.352872 22273 sys_catalog.cc:455] T 00000000000000000000000000000000 P 0c9b1dc981a740b9946d3e1120d868a5 [sys.catalog]: SysCatalogTable state changed. Reason: New leader 0c9b1dc981a740b9946d3e1120d868a5. Latest consensus state: current_term: 1 leader_uuid: "0c9b1dc981a740b9946d3e1120d868a5" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "0c9b1dc981a740b9946d3e1120d868a5" member_type: VOTER } }
I20260812 06:18:03.352877 22272 sys_catalog.cc:455] T 00000000000000000000000000000000 P 0c9b1dc981a740b9946d3e1120d868a5 [sys.catalog]: SysCatalogTable state changed. Reason: RaftConsensus started. Latest consensus state: current_term: 1 leader_uuid: "0c9b1dc981a740b9946d3e1120d868a5" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "0c9b1dc981a740b9946d3e1120d868a5" member_type: VOTER } }
I20260812 06:18:03.353021 22273 sys_catalog.cc:458] T 00000000000000000000000000000000 P 0c9b1dc981a740b9946d3e1120d868a5 [sys.catalog]: This master's current role is: LEADER
I20260812 06:18:03.353077 22272 sys_catalog.cc:458] T 00000000000000000000000000000000 P 0c9b1dc981a740b9946d3e1120d868a5 [sys.catalog]: This master's current role is: LEADER
I20260812 06:18:03.353466 22283 catalog_manager.cc:1511] Loading table and tablet metadata into memory...
I20260812 06:18:03.353565 22190 internal_mini_cluster.cc:184] Waiting to initialize catalog manager on master 0
I20260812 06:18:03.355779 22283 catalog_manager.cc:1520] Initializing Kudu cluster ID...
I20260812 06:18:03.360471 22283 catalog_manager.cc:1383] Generated new cluster ID: e30d0030f57741b28e2cf073fc209c4f
I20260812 06:18:03.360553 22283 catalog_manager.cc:1531] Initializing Kudu internal certificate authority...
I20260812 06:18:03.376700 22283 catalog_manager.cc:1406] Generated new certificate authority record
I20260812 06:18:03.378077 22283 catalog_manager.cc:1540] Loading token signing keys...
I20260812 06:18:03.398952 22283 catalog_manager.cc:6092] T 00000000000000000000000000000000 P 0c9b1dc981a740b9946d3e1120d868a5: Generated new TSK 0
I20260812 06:18:03.399694 22283 catalog_manager.cc:1550] Initializing in-progress tserver states...
I20260812 06:18:03.418496 22190 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:18:03.421542 22293 instance_detector.cc:116] could not retrieve Azure instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:18:03.421571 22292 instance_detector.cc:116] could not retrieve AWS instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:18:03.421708 22295 instance_detector.cc:116] could not retrieve OpenStack instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:18:03.421829 22190 server_base.cc:1061] running on GCE node
I20260812 06:18:03.422142 22190 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:18:03.422209 22190 system_unsync_time.cc:38] NTP support is disabled. Clock error bounds will not be accurate. This configuration is not suitable for distributed clusters.
I20260812 06:18:03.422236 22190 hybrid_clock.cc:648] HybridClock initialized: now 1786515483422236 us; error 0 us; skew 500 ppm
I20260812 06:18:03.423167 22190 webserver.cc:533] Webserver started at http://127.21.171.129:38635/ using document root <none> and password file <none>
I20260812 06:18:03.423360 22190 fs_manager.cc:362] Metadata directory not provided
I20260812 06:18:03.423437 22190 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:18:03.423518 22190 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:18:03.423933 22190 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskoJaC7T/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515483274578-22190-0/minicluster-data/ts-0-root/instance:
uuid: "d99290adb4d3468693ca0e6270bbf67f"
format_stamp: "Formatted at 2026-08-12 06:18:03 on dist-test-slave-qg60"
I20260812 06:18:03.425591 22190 fs_manager.cc:696] Time spent creating directory manager: real 0.001s	user 0.002s	sys 0.000s
I20260812 06:18:03.426632 22300 log_block_manager.cc:4127] Time spent loading block containers with low live blocks: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:18:03.426889 22190 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.001s	sys 0.000s
I20260812 06:18:03.426962 22190 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskoJaC7T/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515483274578-22190-0/minicluster-data/ts-0-root
uuid: "d99290adb4d3468693ca0e6270bbf67f"
format_stamp: "Formatted at 2026-08-12 06:18:03 on dist-test-slave-qg60"
I20260812 06:18:03.427054 22190 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskoJaC7T/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515483274578-22190-0/minicluster-data/ts-0-root
metadata directory: /tmp/dist-test-taskoJaC7T/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515483274578-22190-0/minicluster-data/ts-0-root
1 data directories: /tmp/dist-test-taskoJaC7T/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515483274578-22190-0/minicluster-data/ts-0-root/data
Total live blocks: 0
Total live bytes: 0
Total live bytes (after alignment): 0
Total number of LBM containers: 0 (0 full)
Did not check for missing blocks
Did not check for orphaned blocks
Total full LBM containers with extra space: 0 (0 repaired)
Total full LBM container extra space in bytes: 0 (0 repaired)
Total incomplete LBM containers: 0 (0 repaired)
Total LBM partial records: 0 (0 repaired)
Total corrupted LBM metadata records in RocksDB: 0 (0 repaired)
I20260812 06:18:03.453760 22190 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:18:03.454264 22190 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:18:03.454797 22190 txn_system_client.cc:432] TxnSystemClient initialization is disabled...
I20260812 06:18:03.455694 22190 ts_tablet_manager.cc:585] Loaded tablet metadata (0 total tablets, 0 live tablets)
I20260812 06:18:03.455746 22190 ts_tablet_manager.cc:531] Time spent load tablet metadata: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:18:03.455811 22190 ts_tablet_manager.cc:616] Registered 0 tablets
I20260812 06:18:03.455852 22190 ts_tablet_manager.cc:595] Time spent register tablets: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:18:03.462849 22190 rpc_server.cc:307] RPC server started. Bound to: 127.21.171.129:44307
I20260812 06:18:03.462888 22375 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.21.171.129:44307 every 8 connection(s)
I20260812 06:18:03.473495 22376 heartbeater.cc:344] Connected to a master server at 127.21.171.190:37173
I20260812 06:18:03.473799 22376 heartbeater.cc:461] Registering TS with master...
I20260812 06:18:03.474262 22376 heartbeater.cc:507] Master 127.21.171.190:37173 requested a full tablet report, sending...
I20260812 06:18:03.475879 22224 ts_manager.cc:194] Registered new tserver with Master: d99290adb4d3468693ca0e6270bbf67f (127.21.171.129:44307)
I20260812 06:18:03.475966 22190 internal_mini_cluster.cc:371] 1 TS(s) registered with all masters after 0.012434438s
I20260812 06:18:03.477514 22224 master_service.cc:502] Signed X509 certificate for tserver {username='slave'} at 127.0.0.1:52800
I20260812 06:18:03.487133 22224 catalog_manager.cc:2283] Servicing CreateTable request from {username='slave'} at 127.0.0.1:52812:
name: "heavy-update-compaction-test"
schema {
  columns {
    name: "key"
    type: INT64
    is_key: true
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_a"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_b"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_c"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_d"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_e"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
}
num_replicas: 1
split_rows_range_bounds {
}
partition_schema {
  range_schema {
  }
}
I20260812 06:18:03.502902 22333 tablet_service.cc:1511] Processing CreateTablet for tablet 450188465a6a4e688121c178e0f6ca89 (DEFAULT_TABLE table=heavy-update-compaction-test [id=7005714f454e4f98ab817985f0628f4a]), partition=
I20260812 06:18:03.503407 22333 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet 450188465a6a4e688121c178e0f6ca89. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:18:03.506388 22391 tablet_bootstrap.cc:492] T 450188465a6a4e688121c178e0f6ca89 P d99290adb4d3468693ca0e6270bbf67f: Bootstrap starting.
I20260812 06:18:03.507761 22391 tablet_bootstrap.cc:654] T 450188465a6a4e688121c178e0f6ca89 P d99290adb4d3468693ca0e6270bbf67f: Neither blocks nor log segments found. Creating new log.
I20260812 06:18:03.509433 22391 tablet_bootstrap.cc:492] T 450188465a6a4e688121c178e0f6ca89 P d99290adb4d3468693ca0e6270bbf67f: No bootstrap required, opened a new log
I20260812 06:18:03.509649 22391 ts_tablet_manager.cc:1403] T 450188465a6a4e688121c178e0f6ca89 P d99290adb4d3468693ca0e6270bbf67f: Time spent bootstrapping tablet: real 0.003s	user 0.002s	sys 0.000s
I20260812 06:18:03.510309 22391 raft_consensus.cc:359] T 450188465a6a4e688121c178e0f6ca89 P d99290adb4d3468693ca0e6270bbf67f [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "d99290adb4d3468693ca0e6270bbf67f" member_type: VOTER last_known_addr { host: "127.21.171.129" port: 44307 } }
I20260812 06:18:03.510536 22391 raft_consensus.cc:385] T 450188465a6a4e688121c178e0f6ca89 P d99290adb4d3468693ca0e6270bbf67f [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:18:03.510594 22391 raft_consensus.cc:740] T 450188465a6a4e688121c178e0f6ca89 P d99290adb4d3468693ca0e6270bbf67f [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: d99290adb4d3468693ca0e6270bbf67f, State: Initialized, Role: FOLLOWER
I20260812 06:18:03.510778 22391 consensus_queue.cc:260] T 450188465a6a4e688121c178e0f6ca89 P d99290adb4d3468693ca0e6270bbf67f [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: "d99290adb4d3468693ca0e6270bbf67f" member_type: VOTER last_known_addr { host: "127.21.171.129" port: 44307 } }
I20260812 06:18:03.510895 22391 raft_consensus.cc:399] T 450188465a6a4e688121c178e0f6ca89 P d99290adb4d3468693ca0e6270bbf67f [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:18:03.511004 22391 raft_consensus.cc:493] T 450188465a6a4e688121c178e0f6ca89 P d99290adb4d3468693ca0e6270bbf67f [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:18:03.511054 22391 raft_consensus.cc:3060] T 450188465a6a4e688121c178e0f6ca89 P d99290adb4d3468693ca0e6270bbf67f [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:18:03.511852 22391 raft_consensus.cc:515] T 450188465a6a4e688121c178e0f6ca89 P d99290adb4d3468693ca0e6270bbf67f [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "d99290adb4d3468693ca0e6270bbf67f" member_type: VOTER last_known_addr { host: "127.21.171.129" port: 44307 } }
I20260812 06:18:03.512106 22391 leader_election.cc:304] T 450188465a6a4e688121c178e0f6ca89 P d99290adb4d3468693ca0e6270bbf67f [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: d99290adb4d3468693ca0e6270bbf67f; no voters: 
I20260812 06:18:03.512372 22391 leader_election.cc:290] T 450188465a6a4e688121c178e0f6ca89 P d99290adb4d3468693ca0e6270bbf67f [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:18:03.512486 22393 raft_consensus.cc:2804] T 450188465a6a4e688121c178e0f6ca89 P d99290adb4d3468693ca0e6270bbf67f [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:18:03.512763 22393 raft_consensus.cc:697] T 450188465a6a4e688121c178e0f6ca89 P d99290adb4d3468693ca0e6270bbf67f [term 1 LEADER]: Becoming Leader. State: Replica: d99290adb4d3468693ca0e6270bbf67f, State: Running, Role: LEADER
I20260812 06:18:03.512789 22391 ts_tablet_manager.cc:1434] T 450188465a6a4e688121c178e0f6ca89 P d99290adb4d3468693ca0e6270bbf67f: Time spent starting tablet: real 0.003s	user 0.004s	sys 0.000s
I20260812 06:18:03.512962 22393 consensus_queue.cc:237] T 450188465a6a4e688121c178e0f6ca89 P d99290adb4d3468693ca0e6270bbf67f [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: "d99290adb4d3468693ca0e6270bbf67f" member_type: VOTER last_known_addr { host: "127.21.171.129" port: 44307 } }
I20260812 06:18:03.513089 22376 heartbeater.cc:499] Master 127.21.171.190:37173 was elected leader, sending a full tablet report...
I20260812 06:18:03.516201 22224 catalog_manager.cc:5719] T 450188465a6a4e688121c178e0f6ca89 P d99290adb4d3468693ca0e6270bbf67f reported cstate change: term changed from 0 to 1, leader changed from <none> to d99290adb4d3468693ca0e6270bbf67f (127.21.171.129). New cstate: current_term: 1 leader_uuid: "d99290adb4d3468693ca0e6270bbf67f" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "d99290adb4d3468693ca0e6270bbf67f" member_type: VOTER last_known_addr { host: "127.21.171.129" port: 44307 } health_report { overall_health: HEALTHY } } }
I20260812 06:18:03.581643 22190 heavy-update-compaction-itest.cc:215] Time spent inserting: real 0.058s	user 0.012s	sys 0.013s
I20260812 06:18:03.714015 22377 maintenance_manager.cc:419] P d99290adb4d3468693ca0e6270bbf67f: Scheduling FlushMRSOp(450188465a6a4e688121c178e0f6ca89): perf score=17.070565
I20260812 06:18:03.876143 22307 maintenance_manager.cc:643] P d99290adb4d3468693ca0e6270bbf67f: FlushMRSOp(450188465a6a4e688121c178e0f6ca89) complete. Timing: real 0.162s	user 0.115s	sys 0.044s Metrics: {"bytes_written":8615323,"cfile_init":1,"compiler_manager_pool.queue_time_us":300,"delete_count":0,"dirs.queue_time_us":34,"dirs.run_cpu_time_us":165,"dirs.run_wall_time_us":933,"drs_written":1,"lbm_read_time_us":53,"lbm_reads_lt_1ms":4,"lbm_write_time_us":40302,"lbm_writes_lt_1ms":667,"peak_mem_usage":0,"reinsert_count":0,"rows_written":104,"thread_start_us":147,"threads_started":1,"update_count":1050}
I20260812 06:18:03.877525 22377 maintenance_manager.cc:419] P d99290adb4d3468693ca0e6270bbf67f: Scheduling LogGCOp(450188465a6a4e688121c178e0f6ca89): free 20743880 bytes of WAL
I20260812 06:18:03.877898 22307 log_reader.cc:385] T 450188465a6a4e688121c178e0f6ca89: removed 2 log segments from log reader
I20260812 06:18:03.877976 22307 log.cc:1079] T 450188465a6a4e688121c178e0f6ca89 P d99290adb4d3468693ca0e6270bbf67f: Deleting log segment in path: /tmp/dist-test-taskoJaC7T/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515483274578-22190-0/minicluster-data/ts-0-root/wals/450188465a6a4e688121c178e0f6ca89/wal-000000001 (ops 1-6)
I20260812 06:18:03.878088 22307 log.cc:1079] T 450188465a6a4e688121c178e0f6ca89 P d99290adb4d3468693ca0e6270bbf67f: Deleting log segment in path: /tmp/dist-test-taskoJaC7T/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515483274578-22190-0/minicluster-data/ts-0-root/wals/450188465a6a4e688121c178e0f6ca89/wal-000000002 (ops 7-11)
I20260812 06:18:03.883803 22307 maintenance_manager.cc:643] P d99290adb4d3468693ca0e6270bbf67f: LogGCOp(450188465a6a4e688121c178e0f6ca89) complete. Timing: real 0.006s	user 0.000s	sys 0.003s Metrics: {}
I20260812 06:18:03.884320 22377 maintenance_manager.cc:419] P d99290adb4d3468693ca0e6270bbf67f: Scheduling UndoDeltaBlockGCOp(450188465a6a4e688121c178e0f6ca89): 16411392 bytes on disk
I20260812 06:18:03.885056 22307 maintenance_manager.cc:643] P d99290adb4d3468693ca0e6270bbf67f: UndoDeltaBlockGCOp(450188465a6a4e688121c178e0f6ca89) complete. Timing: real 0.001s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":89,"lbm_reads_lt_1ms":4}
I20260812 06:18:03.885547 22377 maintenance_manager.cc:419] P d99290adb4d3468693ca0e6270bbf67f: Scheduling FlushDeltaMemStoresOp(450188465a6a4e688121c178e0f6ca89): perf score=2.188937
I20260812 06:18:03.911913 22307 maintenance_manager.cc:643] P d99290adb4d3468693ca0e6270bbf67f: FlushDeltaMemStoresOp(450188465a6a4e688121c178e0f6ca89) complete. Timing: real 0.026s	user 0.005s	sys 0.007s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":5321,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:18:03.912431 22377 maintenance_manager.cc:419] P d99290adb4d3468693ca0e6270bbf67f: Scheduling FlushDeltaMemStoresOp(450188465a6a4e688121c178e0f6ca89): perf score=2.188937
I20260812 06:18:03.924664 22307 maintenance_manager.cc:643] P d99290adb4d3468693ca0e6270bbf67f: FlushDeltaMemStoresOp(450188465a6a4e688121c178e0f6ca89) complete. Timing: real 0.012s	user 0.007s	sys 0.003s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4781,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:03.925400 22377 maintenance_manager.cc:419] P d99290adb4d3468693ca0e6270bbf67f: Scheduling MajorDeltaCompactionOp(450188465a6a4e688121c178e0f6ca89): perf score=1.000000
I20260812 06:18:04.060937 22307 maintenance_manager.cc:643] P d99290adb4d3468693ca0e6270bbf67f: MajorDeltaCompactionOp(450188465a6a4e688121c178e0f6ca89) complete. Timing: real 0.135s	user 0.099s	sys 0.033s Metrics: {"cfile_cache_miss":433,"cfile_cache_miss_bytes":20672386,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":978,"lbm_read_time_us":8358,"lbm_reads_lt_1ms":469,"lbm_write_time_us":23795,"lbm_writes_lt_1ms":443,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":2048,"thread_start_us":338,"threads_started":5,"update_count":2000}
I20260812 06:18:04.061545 22377 maintenance_manager.cc:419] P d99290adb4d3468693ca0e6270bbf67f: Scheduling FlushDeltaMemStoresOp(450188465a6a4e688121c178e0f6ca89): perf score=10.126437
I20260812 06:18:04.104435 22307 maintenance_manager.cc:643] P d99290adb4d3468693ca0e6270bbf67f: FlushDeltaMemStoresOp(450188465a6a4e688121c178e0f6ca89) complete. Timing: real 0.043s	user 0.017s	sys 0.018s Metrics: {"bytes_written":12307491,"delete_count":0,"lbm_write_time_us":17360,"lbm_writes_1-10_ms":2,"lbm_writes_lt_1ms":301,"reinsert_count":0,"update_count":1500}
I20260812 06:18:04.104998 22377 maintenance_manager.cc:419] P d99290adb4d3468693ca0e6270bbf67f: Scheduling FlushDeltaMemStoresOp(450188465a6a4e688121c178e0f6ca89): perf score=2.188937
I20260812 06:18:04.115895 22307 maintenance_manager.cc:643] P d99290adb4d3468693ca0e6270bbf67f: FlushDeltaMemStoresOp(450188465a6a4e688121c178e0f6ca89) complete. Timing: real 0.011s	user 0.009s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4078,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:04.116389 22377 maintenance_manager.cc:419] P d99290adb4d3468693ca0e6270bbf67f: Scheduling MajorDeltaCompactionOp(450188465a6a4e688121c178e0f6ca89): perf score=1.000000
I20260812 06:18:04.244187 22307 maintenance_manager.cc:643] P d99290adb4d3468693ca0e6270bbf67f: MajorDeltaCompactionOp(450188465a6a4e688121c178e0f6ca89) complete. Timing: real 0.128s	user 0.094s	sys 0.033s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672278,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":205,"lbm_read_time_us":8545,"lbm_reads_lt_1ms":472,"lbm_write_time_us":23370,"lbm_writes_lt_1ms":443,"mutex_wait_us":21,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":7808,"update_count":2000}
I20260812 06:18:04.244843 22377 maintenance_manager.cc:419] P d99290adb4d3468693ca0e6270bbf67f: Scheduling FlushDeltaMemStoresOp(450188465a6a4e688121c178e0f6ca89): perf score=10.126437
I20260812 06:18:04.280220 22307 maintenance_manager.cc:643] P d99290adb4d3468693ca0e6270bbf67f: FlushDeltaMemStoresOp(450188465a6a4e688121c178e0f6ca89) complete. Timing: real 0.035s	user 0.021s	sys 0.009s Metrics: {"bytes_written":12307489,"delete_count":0,"lbm_write_time_us":14537,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:18:04.280704 22377 maintenance_manager.cc:419] P d99290adb4d3468693ca0e6270bbf67f: Scheduling MajorDeltaCompactionOp(450188465a6a4e688121c178e0f6ca89): perf score=1.000000
I20260812 06:18:04.384608 22307 maintenance_manager.cc:643] P d99290adb4d3468693ca0e6270bbf67f: MajorDeltaCompactionOp(450188465a6a4e688121c178e0f6ca89) complete. Timing: real 0.104s	user 0.083s	sys 0.021s Metrics: {"cfile_cache_miss":331,"cfile_cache_miss_bytes":16569745,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":1,"delta_iterators_relevant":1,"dirs.queue_time_us":396,"lbm_read_time_us":5753,"lbm_reads_lt_1ms":363,"lbm_write_time_us":20273,"lbm_writes_lt_1ms":343,"mutex_wait_us":64,"peak_mem_usage":38262756,"reinsert_count":0,"spinlock_wait_cycles":5760,"update_count":1500}
I20260812 06:18:04.385262 22377 maintenance_manager.cc:419] P d99290adb4d3468693ca0e6270bbf67f: Scheduling FlushDeltaMemStoresOp(450188465a6a4e688121c178e0f6ca89): perf score=10.126437
I20260812 06:18:04.420785 22307 maintenance_manager.cc:643] P d99290adb4d3468693ca0e6270bbf67f: FlushDeltaMemStoresOp(450188465a6a4e688121c178e0f6ca89) complete. Timing: real 0.035s	user 0.019s	sys 0.012s Metrics: {"bytes_written":12307491,"delete_count":0,"lbm_write_time_us":14717,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:18:04.421324 22377 maintenance_manager.cc:419] P d99290adb4d3468693ca0e6270bbf67f: Scheduling MajorDeltaCompactionOp(450188465a6a4e688121c178e0f6ca89): perf score=1.000000
I20260812 06:18:04.528873 22307 maintenance_manager.cc:643] P d99290adb4d3468693ca0e6270bbf67f: MajorDeltaCompactionOp(450188465a6a4e688121c178e0f6ca89) complete. Timing: real 0.107s	user 0.078s	sys 0.028s Metrics: {"cfile_cache_miss":331,"cfile_cache_miss_bytes":16569747,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":1,"delta_iterators_relevant":1,"dirs.queue_time_us":577,"lbm_read_time_us":6149,"lbm_reads_lt_1ms":363,"lbm_write_time_us":21102,"lbm_writes_lt_1ms":343,"mutex_wait_us":511,"peak_mem_usage":38262756,"reinsert_count":0,"spinlock_wait_cycles":4608,"update_count":1500}
I20260812 06:18:04.529548 22377 maintenance_manager.cc:419] P d99290adb4d3468693ca0e6270bbf67f: Scheduling FlushDeltaMemStoresOp(450188465a6a4e688121c178e0f6ca89): perf score=10.126437
I20260812 06:18:04.571079 22307 maintenance_manager.cc:643] P d99290adb4d3468693ca0e6270bbf67f: FlushDeltaMemStoresOp(450188465a6a4e688121c178e0f6ca89) complete. Timing: real 0.041s	user 0.022s	sys 0.017s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":18000,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":302,"reinsert_count":0,"update_count":1500}
I20260812 06:18:04.571547 22377 maintenance_manager.cc:419] P d99290adb4d3468693ca0e6270bbf67f: Scheduling FlushDeltaMemStoresOp(450188465a6a4e688121c178e0f6ca89): perf score=2.188937
I20260812 06:18:04.584636 22307 maintenance_manager.cc:643] P d99290adb4d3468693ca0e6270bbf67f: FlushDeltaMemStoresOp(450188465a6a4e688121c178e0f6ca89) complete. Timing: real 0.013s	user 0.007s	sys 0.003s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4629,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:04.585144 22377 maintenance_manager.cc:419] P d99290adb4d3468693ca0e6270bbf67f: Scheduling MajorDeltaCompactionOp(450188465a6a4e688121c178e0f6ca89): perf score=1.000000
I20260812 06:18:04.707444 22307 maintenance_manager.cc:643] P d99290adb4d3468693ca0e6270bbf67f: MajorDeltaCompactionOp(450188465a6a4e688121c178e0f6ca89) complete. Timing: real 0.122s	user 0.101s	sys 0.020s 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":994,"lbm_read_time_us":7700,"lbm_reads_lt_1ms":472,"lbm_write_time_us":25869,"lbm_writes_lt_1ms":443,"mutex_wait_us":394,"peak_mem_usage":50689328,"reinsert_count":0,"update_count":2000}
I20260812 06:18:04.708045 22377 maintenance_manager.cc:419] P d99290adb4d3468693ca0e6270bbf67f: Scheduling FlushDeltaMemStoresOp(450188465a6a4e688121c178e0f6ca89): perf score=10.126437
I20260812 06:18:04.765276 22307 maintenance_manager.cc:643] P d99290adb4d3468693ca0e6270bbf67f: FlushDeltaMemStoresOp(450188465a6a4e688121c178e0f6ca89) complete. Timing: real 0.057s	user 0.023s	sys 0.023s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":17222,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:18:04.765786 22377 maintenance_manager.cc:419] P d99290adb4d3468693ca0e6270bbf67f: Scheduling FlushDeltaMemStoresOp(450188465a6a4e688121c178e0f6ca89): perf score=2.188937
I20260812 06:18:04.776515 22307 maintenance_manager.cc:643] P d99290adb4d3468693ca0e6270bbf67f: FlushDeltaMemStoresOp(450188465a6a4e688121c178e0f6ca89) complete. Timing: real 0.011s	user 0.005s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4209,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:04.777000 22377 maintenance_manager.cc:419] P d99290adb4d3468693ca0e6270bbf67f: Scheduling MajorDeltaCompactionOp(450188465a6a4e688121c178e0f6ca89): perf score=1.000000
I20260812 06:18:04.926659 22307 maintenance_manager.cc:643] P d99290adb4d3468693ca0e6270bbf67f: MajorDeltaCompactionOp(450188465a6a4e688121c178e0f6ca89) complete. Timing: real 0.149s	user 0.108s	sys 0.036s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672277,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":198,"lbm_read_time_us":10372,"lbm_reads_lt_1ms":472,"lbm_write_time_us":22740,"lbm_writes_lt_1ms":443,"mutex_wait_us":21,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":7424,"update_count":2000}
I20260812 06:18:04.927346 22377 maintenance_manager.cc:419] P d99290adb4d3468693ca0e6270bbf67f: Scheduling FlushDeltaMemStoresOp(450188465a6a4e688121c178e0f6ca89): perf score=10.126437
I20260812 06:18:04.974886 22307 maintenance_manager.cc:643] P d99290adb4d3468693ca0e6270bbf67f: FlushDeltaMemStoresOp(450188465a6a4e688121c178e0f6ca89) complete. Timing: real 0.047s	user 0.013s	sys 0.020s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":15150,"lbm_writes_lt_1ms":303,"reinsert_count":0,"spinlock_wait_cycles":896,"update_count":1500}
I20260812 06:18:04.975359 22377 maintenance_manager.cc:419] P d99290adb4d3468693ca0e6270bbf67f: Scheduling FlushDeltaMemStoresOp(450188465a6a4e688121c178e0f6ca89): perf score=2.188937
I20260812 06:18:04.986753 22307 maintenance_manager.cc:643] P d99290adb4d3468693ca0e6270bbf67f: FlushDeltaMemStoresOp(450188465a6a4e688121c178e0f6ca89) complete. Timing: real 0.011s	user 0.005s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4156,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:04.987454 22377 maintenance_manager.cc:419] P d99290adb4d3468693ca0e6270bbf67f: Scheduling MajorDeltaCompactionOp(450188465a6a4e688121c178e0f6ca89): perf score=1.000000
I20260812 06:18:05.120486 22307 maintenance_manager.cc:643] P d99290adb4d3468693ca0e6270bbf67f: MajorDeltaCompactionOp(450188465a6a4e688121c178e0f6ca89) complete. Timing: real 0.133s	user 0.109s	sys 0.023s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672277,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":657,"lbm_read_time_us":9760,"lbm_reads_lt_1ms":472,"lbm_write_time_us":26420,"lbm_writes_lt_1ms":443,"mutex_wait_us":255,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":2048,"update_count":2000}
I20260812 06:18:05.121206 22377 maintenance_manager.cc:419] P d99290adb4d3468693ca0e6270bbf67f: Scheduling FlushDeltaMemStoresOp(450188465a6a4e688121c178e0f6ca89): perf score=10.126437
I20260812 06:18:05.167076 22307 maintenance_manager.cc:643] P d99290adb4d3468693ca0e6270bbf67f: FlushDeltaMemStoresOp(450188465a6a4e688121c178e0f6ca89) complete. Timing: real 0.046s	user 0.020s	sys 0.012s Metrics: {"bytes_written":12307491,"delete_count":0,"lbm_write_time_us":15387,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:18:05.167591 22377 maintenance_manager.cc:419] P d99290adb4d3468693ca0e6270bbf67f: Scheduling FlushDeltaMemStoresOp(450188465a6a4e688121c178e0f6ca89): perf score=2.188937
I20260812 06:18:05.179075 22307 maintenance_manager.cc:643] P d99290adb4d3468693ca0e6270bbf67f: FlushDeltaMemStoresOp(450188465a6a4e688121c178e0f6ca89) complete. Timing: real 0.011s	user 0.008s	sys 0.001s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4053,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:05.179793 22377 maintenance_manager.cc:419] P d99290adb4d3468693ca0e6270bbf67f: Scheduling FlushMRSOp(450188465a6a4e688121c178e0f6ca89): perf score=1.000000
I20260812 06:18:05.211381 22307 maintenance_manager.cc:643] P d99290adb4d3468693ca0e6270bbf67f: FlushMRSOp(450188465a6a4e688121c178e0f6ca89) complete. Timing: real 0.031s	user 0.030s	sys 0.000s Metrics: {"bytes_written":1234473,"cfile_init":1,"dirs.queue_time_us":72,"dirs.run_cpu_time_us":239,"dirs.run_wall_time_us":1697,"drs_written":1,"lbm_read_time_us":41,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1537,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":30}
I20260812 06:18:05.212199 22377 maintenance_manager.cc:419] P d99290adb4d3468693ca0e6270bbf67f: Scheduling LogGCOp(450188465a6a4e688121c178e0f6ca89): free 120553319 bytes of WAL
I20260812 06:18:05.212424 22307 log_reader.cc:385] T 450188465a6a4e688121c178e0f6ca89: removed 12 log segments from log reader
I20260812 06:18:05.212486 22307 log.cc:1079] T 450188465a6a4e688121c178e0f6ca89 P d99290adb4d3468693ca0e6270bbf67f: Deleting log segment in path: /tmp/dist-test-taskoJaC7T/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515483274578-22190-0/minicluster-data/ts-0-root/wals/450188465a6a4e688121c178e0f6ca89/wal-000000003 (ops 12-16)
I20260812 06:18:05.212536 22307 log.cc:1079] T 450188465a6a4e688121c178e0f6ca89 P d99290adb4d3468693ca0e6270bbf67f: Deleting log segment in path: /tmp/dist-test-taskoJaC7T/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515483274578-22190-0/minicluster-data/ts-0-root/wals/450188465a6a4e688121c178e0f6ca89/wal-000000004 (ops 17-20)
I20260812 06:18:05.212602 22307 log.cc:1079] T 450188465a6a4e688121c178e0f6ca89 P d99290adb4d3468693ca0e6270bbf67f: Deleting log segment in path: /tmp/dist-test-taskoJaC7T/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515483274578-22190-0/minicluster-data/ts-0-root/wals/450188465a6a4e688121c178e0f6ca89/wal-000000005 (ops 21-25)
I20260812 06:18:05.212643 22307 log.cc:1079] T 450188465a6a4e688121c178e0f6ca89 P d99290adb4d3468693ca0e6270bbf67f: Deleting log segment in path: /tmp/dist-test-taskoJaC7T/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515483274578-22190-0/minicluster-data/ts-0-root/wals/450188465a6a4e688121c178e0f6ca89/wal-000000006 (ops 26-30)
I20260812 06:18:05.212682 22307 log.cc:1079] T 450188465a6a4e688121c178e0f6ca89 P d99290adb4d3468693ca0e6270bbf67f: Deleting log segment in path: /tmp/dist-test-taskoJaC7T/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515483274578-22190-0/minicluster-data/ts-0-root/wals/450188465a6a4e688121c178e0f6ca89/wal-000000007 (ops 31-35)
I20260812 06:18:05.212721 22307 log.cc:1079] T 450188465a6a4e688121c178e0f6ca89 P d99290adb4d3468693ca0e6270bbf67f: Deleting log segment in path: /tmp/dist-test-taskoJaC7T/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515483274578-22190-0/minicluster-data/ts-0-root/wals/450188465a6a4e688121c178e0f6ca89/wal-000000008 (ops 36-40)
I20260812 06:18:05.212826 22307 log.cc:1079] T 450188465a6a4e688121c178e0f6ca89 P d99290adb4d3468693ca0e6270bbf67f: Deleting log segment in path: /tmp/dist-test-taskoJaC7T/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515483274578-22190-0/minicluster-data/ts-0-root/wals/450188465a6a4e688121c178e0f6ca89/wal-000000009 (ops 41-45)
I20260812 06:18:05.212872 22307 log.cc:1079] T 450188465a6a4e688121c178e0f6ca89 P d99290adb4d3468693ca0e6270bbf67f: Deleting log segment in path: /tmp/dist-test-taskoJaC7T/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515483274578-22190-0/minicluster-data/ts-0-root/wals/450188465a6a4e688121c178e0f6ca89/wal-000000010 (ops 46-50)
I20260812 06:18:05.212913 22307 log.cc:1079] T 450188465a6a4e688121c178e0f6ca89 P d99290adb4d3468693ca0e6270bbf67f: Deleting log segment in path: /tmp/dist-test-taskoJaC7T/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515483274578-22190-0/minicluster-data/ts-0-root/wals/450188465a6a4e688121c178e0f6ca89/wal-000000011 (ops 51-54)
I20260812 06:18:05.212952 22307 log.cc:1079] T 450188465a6a4e688121c178e0f6ca89 P d99290adb4d3468693ca0e6270bbf67f: Deleting log segment in path: /tmp/dist-test-taskoJaC7T/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515483274578-22190-0/minicluster-data/ts-0-root/wals/450188465a6a4e688121c178e0f6ca89/wal-000000012 (ops 55-59)
I20260812 06:18:05.212991 22307 log.cc:1079] T 450188465a6a4e688121c178e0f6ca89 P d99290adb4d3468693ca0e6270bbf67f: Deleting log segment in path: /tmp/dist-test-taskoJaC7T/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515483274578-22190-0/minicluster-data/ts-0-root/wals/450188465a6a4e688121c178e0f6ca89/wal-000000013 (ops 60-64)
I20260812 06:18:05.213029 22307 log.cc:1079] T 450188465a6a4e688121c178e0f6ca89 P d99290adb4d3468693ca0e6270bbf67f: Deleting log segment in path: /tmp/dist-test-taskoJaC7T/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515483274578-22190-0/minicluster-data/ts-0-root/wals/450188465a6a4e688121c178e0f6ca89/wal-000000014 (ops 65-69)
I20260812 06:18:05.238070 22307 maintenance_manager.cc:643] P d99290adb4d3468693ca0e6270bbf67f: LogGCOp(450188465a6a4e688121c178e0f6ca89) complete. Timing: real 0.026s	user 0.001s	sys 0.023s Metrics: {}
I20260812 06:18:05.238564 22377 maintenance_manager.cc:419] P d99290adb4d3468693ca0e6270bbf67f: Scheduling UndoDeltaBlockGCOp(450188465a6a4e688121c178e0f6ca89): 473 bytes on disk
I20260812 06:18:05.239142 22307 maintenance_manager.cc:643] P d99290adb4d3468693ca0e6270bbf67f: UndoDeltaBlockGCOp(450188465a6a4e688121c178e0f6ca89) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":70,"lbm_reads_lt_1ms":4}
I20260812 06:18:05.239728 22377 maintenance_manager.cc:419] P d99290adb4d3468693ca0e6270bbf67f: Scheduling FlushDeltaMemStoresOp(450188465a6a4e688121c178e0f6ca89): perf score=3.181125
I20260812 06:18:05.252018 22307 maintenance_manager.cc:643] P d99290adb4d3468693ca0e6270bbf67f: FlushDeltaMemStoresOp(450188465a6a4e688121c178e0f6ca89) complete. Timing: real 0.012s	user 0.002s	sys 0.007s Metrics: {"bytes_written":4512902,"delete_count":0,"lbm_write_time_us":4340,"lbm_writes_lt_1ms":113,"reinsert_count":0,"update_count":550}
I20260812 06:18:05.252527 22377 maintenance_manager.cc:419] P d99290adb4d3468693ca0e6270bbf67f: Scheduling FlushDeltaMemStoresOp(450188465a6a4e688121c178e0f6ca89): perf score=2.188937
I20260812 06:18:05.265772 22307 maintenance_manager.cc:643] P d99290adb4d3468693ca0e6270bbf67f: FlushDeltaMemStoresOp(450188465a6a4e688121c178e0f6ca89) complete. Timing: real 0.013s	user 0.011s	sys 0.001s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":4878,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:18:05.266281 22377 maintenance_manager.cc:419] P d99290adb4d3468693ca0e6270bbf67f: Scheduling MajorDeltaCompactionOp(450188465a6a4e688121c178e0f6ca89): perf score=1.000000
I20260812 06:18:05.446941 22307 maintenance_manager.cc:643] P d99290adb4d3468693ca0e6270bbf67f: MajorDeltaCompactionOp(450188465a6a4e688121c178e0f6ca89) complete. Timing: real 0.180s	user 0.135s	sys 0.038s Metrics: {"cfile_cache_miss":634,"cfile_cache_miss_bytes":28877329,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":1265,"lbm_read_time_us":13093,"lbm_reads_lt_1ms":674,"lbm_write_time_us":34158,"lbm_writes_lt_1ms":643,"mutex_wait_us":70,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":35968,"thread_start_us":81,"threads_started":1,"update_count":3000}
I20260812 06:18:05.447629 22377 maintenance_manager.cc:419] P d99290adb4d3468693ca0e6270bbf67f: Scheduling FlushDeltaMemStoresOp(450188465a6a4e688121c178e0f6ca89): perf score=14.095187
I20260812 06:18:05.499048 22307 maintenance_manager.cc:643] P d99290adb4d3468693ca0e6270bbf67f: FlushDeltaMemStoresOp(450188465a6a4e688121c178e0f6ca89) complete. Timing: real 0.051s	user 0.033s	sys 0.016s Metrics: {"bytes_written":16409903,"delete_count":0,"lbm_write_time_us":25596,"lbm_writes_1-10_ms":2,"lbm_writes_lt_1ms":401,"reinsert_count":0,"update_count":2000}
I20260812 06:18:05.499610 22377 maintenance_manager.cc:419] P d99290adb4d3468693ca0e6270bbf67f: Scheduling FlushDeltaMemStoresOp(450188465a6a4e688121c178e0f6ca89): perf score=2.188937
I20260812 06:18:05.513665 22307 maintenance_manager.cc:643] P d99290adb4d3468693ca0e6270bbf67f: FlushDeltaMemStoresOp(450188465a6a4e688121c178e0f6ca89) complete. Timing: real 0.014s	user 0.009s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5050,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:05.514236 22377 maintenance_manager.cc:419] P d99290adb4d3468693ca0e6270bbf67f: Scheduling MajorDeltaCompactionOp(450188465a6a4e688121c178e0f6ca89): perf score=1.000000
I20260812 06:18:05.681679 22307 maintenance_manager.cc:643] P d99290adb4d3468693ca0e6270bbf67f: MajorDeltaCompactionOp(450188465a6a4e688121c178e0f6ca89) complete. Timing: real 0.167s	user 0.111s	sys 0.049s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774690,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":337,"lbm_read_time_us":9847,"lbm_reads_lt_1ms":572,"lbm_write_time_us":33973,"lbm_writes_lt_1ms":543,"peak_mem_usage":63115900,"reinsert_count":0,"update_count":2500}
I20260812 06:18:05.682340 22377 maintenance_manager.cc:419] P d99290adb4d3468693ca0e6270bbf67f: Scheduling FlushDeltaMemStoresOp(450188465a6a4e688121c178e0f6ca89): perf score=14.095187
I20260812 06:18:05.746222 22307 maintenance_manager.cc:643] P d99290adb4d3468693ca0e6270bbf67f: FlushDeltaMemStoresOp(450188465a6a4e688121c178e0f6ca89) complete. Timing: real 0.064s	user 0.031s	sys 0.017s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":22472,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:18:05.746687 22377 maintenance_manager.cc:419] P d99290adb4d3468693ca0e6270bbf67f: Scheduling FlushDeltaMemStoresOp(450188465a6a4e688121c178e0f6ca89): perf score=2.188937
I20260812 06:18:05.758811 22307 maintenance_manager.cc:643] P d99290adb4d3468693ca0e6270bbf67f: FlushDeltaMemStoresOp(450188465a6a4e688121c178e0f6ca89) complete. Timing: real 0.012s	user 0.001s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4562,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:05.759373 22377 maintenance_manager.cc:419] P d99290adb4d3468693ca0e6270bbf67f: Scheduling MajorDeltaCompactionOp(450188465a6a4e688121c178e0f6ca89): perf score=1.000000
I20260812 06:18:05.934852 22307 maintenance_manager.cc:643] P d99290adb4d3468693ca0e6270bbf67f: MajorDeltaCompactionOp(450188465a6a4e688121c178e0f6ca89) complete. Timing: real 0.175s	user 0.135s	sys 0.040s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774688,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":347,"lbm_read_time_us":11334,"lbm_reads_lt_1ms":572,"lbm_write_time_us":32564,"lbm_writes_lt_1ms":543,"mutex_wait_us":26,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":2304,"update_count":2500}
I20260812 06:18:05.935573 22377 maintenance_manager.cc:419] P d99290adb4d3468693ca0e6270bbf67f: Scheduling FlushDeltaMemStoresOp(450188465a6a4e688121c178e0f6ca89): perf score=14.095187
I20260812 06:18:05.992424 22307 maintenance_manager.cc:643] P d99290adb4d3468693ca0e6270bbf67f: FlushDeltaMemStoresOp(450188465a6a4e688121c178e0f6ca89) complete. Timing: real 0.057s	user 0.030s	sys 0.023s Metrics: {"bytes_written":16409900,"delete_count":0,"lbm_write_time_us":26171,"lbm_writes_1-10_ms":2,"lbm_writes_lt_1ms":401,"reinsert_count":0,"update_count":2000}
I20260812 06:18:05.993067 22377 maintenance_manager.cc:419] P d99290adb4d3468693ca0e6270bbf67f: Scheduling FlushDeltaMemStoresOp(450188465a6a4e688121c178e0f6ca89): perf score=2.188937
I20260812 06:18:06.007027 22307 maintenance_manager.cc:643] P d99290adb4d3468693ca0e6270bbf67f: FlushDeltaMemStoresOp(450188465a6a4e688121c178e0f6ca89) complete. Timing: real 0.014s	user 0.012s	sys 0.000s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":5318,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:06.007616 22377 maintenance_manager.cc:419] P d99290adb4d3468693ca0e6270bbf67f: Scheduling MajorDeltaCompactionOp(450188465a6a4e688121c178e0f6ca89): perf score=1.000000
I20260812 06:18:06.185490 22307 maintenance_manager.cc:643] P d99290adb4d3468693ca0e6270bbf67f: MajorDeltaCompactionOp(450188465a6a4e688121c178e0f6ca89) complete. Timing: real 0.178s	user 0.126s	sys 0.052s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774686,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":231,"lbm_read_time_us":13788,"lbm_reads_lt_1ms":572,"lbm_write_time_us":31505,"lbm_writes_lt_1ms":543,"mutex_wait_us":42,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":4736,"update_count":2500}
I20260812 06:18:06.186041 22377 maintenance_manager.cc:419] P d99290adb4d3468693ca0e6270bbf67f: Scheduling FlushDeltaMemStoresOp(450188465a6a4e688121c178e0f6ca89): perf score=14.095187
I20260812 06:18:06.249245 22307 maintenance_manager.cc:643] P d99290adb4d3468693ca0e6270bbf67f: FlushDeltaMemStoresOp(450188465a6a4e688121c178e0f6ca89) complete. Timing: real 0.063s	user 0.043s	sys 0.019s Metrics: {"bytes_written":16409903,"delete_count":0,"lbm_write_time_us":23001,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:18:06.250005 22377 maintenance_manager.cc:419] P d99290adb4d3468693ca0e6270bbf67f: Scheduling FlushDeltaMemStoresOp(450188465a6a4e688121c178e0f6ca89): perf score=2.188937
I20260812 06:18:06.271337 22307 maintenance_manager.cc:643] P d99290adb4d3468693ca0e6270bbf67f: FlushDeltaMemStoresOp(450188465a6a4e688121c178e0f6ca89) complete. Timing: real 0.021s	user 0.013s	sys 0.004s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":7587,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:06.272109 22377 maintenance_manager.cc:419] P d99290adb4d3468693ca0e6270bbf67f: Scheduling MajorDeltaCompactionOp(450188465a6a4e688121c178e0f6ca89): perf score=1.000000
I20260812 06:18:06.452979 22307 maintenance_manager.cc:643] P d99290adb4d3468693ca0e6270bbf67f: MajorDeltaCompactionOp(450188465a6a4e688121c178e0f6ca89) complete. Timing: real 0.181s	user 0.138s	sys 0.036s 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":142,"lbm_read_time_us":13928,"lbm_reads_lt_1ms":572,"lbm_write_time_us":29643,"lbm_writes_lt_1ms":543,"mutex_wait_us":25,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":14464,"update_count":2500}
I20260812 06:18:06.453469 22377 maintenance_manager.cc:419] P d99290adb4d3468693ca0e6270bbf67f: Scheduling FlushDeltaMemStoresOp(450188465a6a4e688121c178e0f6ca89): perf score=14.095187
I20260812 06:18:06.520570 22307 maintenance_manager.cc:643] P d99290adb4d3468693ca0e6270bbf67f: FlushDeltaMemStoresOp(450188465a6a4e688121c178e0f6ca89) complete. Timing: real 0.067s	user 0.043s	sys 0.015s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":24479,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:18:06.521217 22377 maintenance_manager.cc:419] P d99290adb4d3468693ca0e6270bbf67f: Scheduling FlushDeltaMemStoresOp(450188465a6a4e688121c178e0f6ca89): perf score=2.188937
I20260812 06:18:06.533236 22307 maintenance_manager.cc:643] P d99290adb4d3468693ca0e6270bbf67f: FlushDeltaMemStoresOp(450188465a6a4e688121c178e0f6ca89) complete. Timing: real 0.012s	user 0.003s	sys 0.009s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4627,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:06.533833 22377 maintenance_manager.cc:419] P d99290adb4d3468693ca0e6270bbf67f: Scheduling MajorDeltaCompactionOp(450188465a6a4e688121c178e0f6ca89): perf score=1.000000
I20260812 06:18:06.714341 22307 maintenance_manager.cc:643] P d99290adb4d3468693ca0e6270bbf67f: MajorDeltaCompactionOp(450188465a6a4e688121c178e0f6ca89) complete. Timing: real 0.180s	user 0.122s	sys 0.055s 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":769,"lbm_read_time_us":16146,"lbm_reads_1-10_ms":1,"lbm_reads_lt_1ms":571,"lbm_write_time_us":28777,"lbm_writes_lt_1ms":543,"mutex_wait_us":52,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":7552,"update_count":2500}
I20260812 06:18:06.714954 22377 maintenance_manager.cc:419] P d99290adb4d3468693ca0e6270bbf67f: Scheduling FlushDeltaMemStoresOp(450188465a6a4e688121c178e0f6ca89): perf score=11.118625
I20260812 06:18:06.783074 22307 maintenance_manager.cc:643] P d99290adb4d3468693ca0e6270bbf67f: FlushDeltaMemStoresOp(450188465a6a4e688121c178e0f6ca89) complete. Timing: real 0.068s	user 0.029s	sys 0.005s Metrics: {"bytes_written":12717735,"delete_count":0,"lbm_write_time_us":39628,"lbm_writes_10-100_ms":1,"lbm_writes_lt_1ms":312,"reinsert_count":0,"update_count":1550}
I20260812 06:18:06.783603 22377 maintenance_manager.cc:419] P d99290adb4d3468693ca0e6270bbf67f: Scheduling FlushDeltaMemStoresOp(450188465a6a4e688121c178e0f6ca89): perf score=6.157687
I20260812 06:18:06.805438 22307 maintenance_manager.cc:643] P d99290adb4d3468693ca0e6270bbf67f: FlushDeltaMemStoresOp(450188465a6a4e688121c178e0f6ca89) complete. Timing: real 0.022s	user 0.013s	sys 0.008s Metrics: {"bytes_written":7794836,"delete_count":0,"lbm_write_time_us":8960,"lbm_writes_lt_1ms":193,"reinsert_count":0,"update_count":950}
I20260812 06:18:06.806151 22377 maintenance_manager.cc:419] P d99290adb4d3468693ca0e6270bbf67f: Scheduling FlushMRSOp(450188465a6a4e688121c178e0f6ca89): perf score=1.000000
I20260812 06:18:06.846886 22307 maintenance_manager.cc:643] P d99290adb4d3468693ca0e6270bbf67f: FlushMRSOp(450188465a6a4e688121c178e0f6ca89) complete. Timing: real 0.040s	user 0.033s	sys 0.004s Metrics: {"bytes_written":1316419,"cfile_init":1,"dirs.queue_time_us":85,"dirs.run_cpu_time_us":266,"dirs.run_wall_time_us":1357,"drs_written":1,"lbm_read_time_us":49,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1838,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":32}
I20260812 06:18:06.847875 22377 maintenance_manager.cc:419] P d99290adb4d3468693ca0e6270bbf67f: Scheduling LogGCOp(450188465a6a4e688121c178e0f6ca89): free 133024437 bytes of WAL
I20260812 06:18:06.848203 22307 log_reader.cc:385] T 450188465a6a4e688121c178e0f6ca89: removed 13 log segments from log reader
I20260812 06:18:06.848280 22307 log.cc:1079] T 450188465a6a4e688121c178e0f6ca89 P d99290adb4d3468693ca0e6270bbf67f: Deleting log segment in path: /tmp/dist-test-taskoJaC7T/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515483274578-22190-0/minicluster-data/ts-0-root/wals/450188465a6a4e688121c178e0f6ca89/wal-000000015 (ops 70-74)
I20260812 06:18:06.848332 22307 log.cc:1079] T 450188465a6a4e688121c178e0f6ca89 P d99290adb4d3468693ca0e6270bbf67f: Deleting log segment in path: /tmp/dist-test-taskoJaC7T/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515483274578-22190-0/minicluster-data/ts-0-root/wals/450188465a6a4e688121c178e0f6ca89/wal-000000016 (ops 75-79)
I20260812 06:18:06.848387 22307 log.cc:1079] T 450188465a6a4e688121c178e0f6ca89 P d99290adb4d3468693ca0e6270bbf67f: Deleting log segment in path: /tmp/dist-test-taskoJaC7T/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515483274578-22190-0/minicluster-data/ts-0-root/wals/450188465a6a4e688121c178e0f6ca89/wal-000000017 (ops 80-84)
I20260812 06:18:06.848430 22307 log.cc:1079] T 450188465a6a4e688121c178e0f6ca89 P d99290adb4d3468693ca0e6270bbf67f: Deleting log segment in path: /tmp/dist-test-taskoJaC7T/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515483274578-22190-0/minicluster-data/ts-0-root/wals/450188465a6a4e688121c178e0f6ca89/wal-000000018 (ops 85-89)
I20260812 06:18:06.848469 22307 log.cc:1079] T 450188465a6a4e688121c178e0f6ca89 P d99290adb4d3468693ca0e6270bbf67f: Deleting log segment in path: /tmp/dist-test-taskoJaC7T/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515483274578-22190-0/minicluster-data/ts-0-root/wals/450188465a6a4e688121c178e0f6ca89/wal-000000019 (ops 90-94)
I20260812 06:18:06.848508 22307 log.cc:1079] T 450188465a6a4e688121c178e0f6ca89 P d99290adb4d3468693ca0e6270bbf67f: Deleting log segment in path: /tmp/dist-test-taskoJaC7T/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515483274578-22190-0/minicluster-data/ts-0-root/wals/450188465a6a4e688121c178e0f6ca89/wal-000000020 (ops 95-98)
I20260812 06:18:06.848542 22307 log.cc:1079] T 450188465a6a4e688121c178e0f6ca89 P d99290adb4d3468693ca0e6270bbf67f: Deleting log segment in path: /tmp/dist-test-taskoJaC7T/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515483274578-22190-0/minicluster-data/ts-0-root/wals/450188465a6a4e688121c178e0f6ca89/wal-000000021 (ops 99-103)
I20260812 06:18:06.848565 22307 log.cc:1079] T 450188465a6a4e688121c178e0f6ca89 P d99290adb4d3468693ca0e6270bbf67f: Deleting log segment in path: /tmp/dist-test-taskoJaC7T/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515483274578-22190-0/minicluster-data/ts-0-root/wals/450188465a6a4e688121c178e0f6ca89/wal-000000022 (ops 104-108)
I20260812 06:18:06.848598 22307 log.cc:1079] T 450188465a6a4e688121c178e0f6ca89 P d99290adb4d3468693ca0e6270bbf67f: Deleting log segment in path: /tmp/dist-test-taskoJaC7T/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515483274578-22190-0/minicluster-data/ts-0-root/wals/450188465a6a4e688121c178e0f6ca89/wal-000000023 (ops 109-113)
I20260812 06:18:06.848636 22307 log.cc:1079] T 450188465a6a4e688121c178e0f6ca89 P d99290adb4d3468693ca0e6270bbf67f: Deleting log segment in path: /tmp/dist-test-taskoJaC7T/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515483274578-22190-0/minicluster-data/ts-0-root/wals/450188465a6a4e688121c178e0f6ca89/wal-000000024 (ops 114-118)
I20260812 06:18:06.848673 22307 log.cc:1079] T 450188465a6a4e688121c178e0f6ca89 P d99290adb4d3468693ca0e6270bbf67f: Deleting log segment in path: /tmp/dist-test-taskoJaC7T/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515483274578-22190-0/minicluster-data/ts-0-root/wals/450188465a6a4e688121c178e0f6ca89/wal-000000025 (ops 119-123)
I20260812 06:18:06.848713 22307 log.cc:1079] T 450188465a6a4e688121c178e0f6ca89 P d99290adb4d3468693ca0e6270bbf67f: Deleting log segment in path: /tmp/dist-test-taskoJaC7T/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515483274578-22190-0/minicluster-data/ts-0-root/wals/450188465a6a4e688121c178e0f6ca89/wal-000000026 (ops 124-128)
I20260812 06:18:06.848785 22307 log.cc:1079] T 450188465a6a4e688121c178e0f6ca89 P d99290adb4d3468693ca0e6270bbf67f: Deleting log segment in path: /tmp/dist-test-taskoJaC7T/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515483274578-22190-0/minicluster-data/ts-0-root/wals/450188465a6a4e688121c178e0f6ca89/wal-000000027 (ops 129-133)
I20260812 06:18:06.879824 22307 maintenance_manager.cc:643] P d99290adb4d3468693ca0e6270bbf67f: LogGCOp(450188465a6a4e688121c178e0f6ca89) complete. Timing: real 0.032s	user 0.000s	sys 0.030s Metrics: {}
I20260812 06:18:06.880669 22377 maintenance_manager.cc:419] P d99290adb4d3468693ca0e6270bbf67f: Scheduling UndoDeltaBlockGCOp(450188465a6a4e688121c178e0f6ca89): 492 bytes on disk
I20260812 06:18:06.881263 22307 maintenance_manager.cc:643] P d99290adb4d3468693ca0e6270bbf67f: UndoDeltaBlockGCOp(450188465a6a4e688121c178e0f6ca89) 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:18:06.881925 22377 maintenance_manager.cc:419] P d99290adb4d3468693ca0e6270bbf67f: Scheduling FlushDeltaMemStoresOp(450188465a6a4e688121c178e0f6ca89): perf score=6.157687
I20260812 06:18:06.902861 22307 maintenance_manager.cc:643] P d99290adb4d3468693ca0e6270bbf67f: FlushDeltaMemStoresOp(450188465a6a4e688121c178e0f6ca89) complete. Timing: real 0.021s	user 0.006s	sys 0.012s Metrics: {"bytes_written":7835861,"delete_count":0,"lbm_write_time_us":8199,"lbm_writes_lt_1ms":194,"reinsert_count":0,"update_count":955}
I20260812 06:18:06.903414 22377 maintenance_manager.cc:419] P d99290adb4d3468693ca0e6270bbf67f: Scheduling MajorDeltaCompactionOp(450188465a6a4e688121c178e0f6ca89): perf score=1.000000
I20260812 06:18:07.155073 22307 maintenance_manager.cc:643] P d99290adb4d3468693ca0e6270bbf67f: MajorDeltaCompactionOp(450188465a6a4e688121c178e0f6ca89) complete. Timing: real 0.251s	user 0.167s	sys 0.071s Metrics: {"cfile_cache_miss":724,"cfile_cache_miss_bytes":32610420,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":5668,"lbm_read_time_us":15188,"lbm_reads_lt_1ms":756,"lbm_write_time_us":41161,"lbm_writes_lt_1ms":734,"mutex_wait_us":1574,"peak_mem_usage":86559345,"reinsert_count":0,"spinlock_wait_cycles":2048,"thread_start_us":90,"threads_started":1,"update_count":3455}
I20260812 06:18:07.155764 22377 maintenance_manager.cc:419] P d99290adb4d3468693ca0e6270bbf67f: Scheduling FlushDeltaMemStoresOp(450188465a6a4e688121c178e0f6ca89): perf score=19.056125
I20260812 06:18:07.230080 22307 maintenance_manager.cc:643] P d99290adb4d3468693ca0e6270bbf67f: FlushDeltaMemStoresOp(450188465a6a4e688121c178e0f6ca89) complete. Timing: real 0.074s	user 0.034s	sys 0.036s Metrics: {"bytes_written":20881532,"delete_count":0,"lbm_write_time_us":35322,"lbm_writes_1-10_ms":3,"lbm_writes_lt_1ms":509,"reinsert_count":0,"update_count":2545}
I20260812 06:18:07.230634 22377 maintenance_manager.cc:419] P d99290adb4d3468693ca0e6270bbf67f: Scheduling FlushDeltaMemStoresOp(450188465a6a4e688121c178e0f6ca89): perf score=2.188937
I20260812 06:18:07.242000 22307 maintenance_manager.cc:643] P d99290adb4d3468693ca0e6270bbf67f: FlushDeltaMemStoresOp(450188465a6a4e688121c178e0f6ca89) complete. Timing: real 0.011s	user 0.006s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4112,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:07.242667 22377 maintenance_manager.cc:419] P d99290adb4d3468693ca0e6270bbf67f: Scheduling MajorDeltaCompactionOp(450188465a6a4e688121c178e0f6ca89): perf score=1.000000
I20260812 06:18:07.449100 22307 maintenance_manager.cc:643] P d99290adb4d3468693ca0e6270bbf67f: MajorDeltaCompactionOp(450188465a6a4e688121c178e0f6ca89) complete. Timing: real 0.206s	user 0.127s	sys 0.069s Metrics: {"cfile_cache_miss":641,"cfile_cache_miss_bytes":29246319,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":759,"lbm_read_time_us":12605,"lbm_reads_lt_1ms":681,"lbm_write_time_us":34686,"lbm_writes_lt_1ms":652,"mutex_wait_us":321,"peak_mem_usage":75911787,"reinsert_count":0,"spinlock_wait_cycles":16896,"update_count":3045}
I20260812 06:18:07.449863 22377 maintenance_manager.cc:419] P d99290adb4d3468693ca0e6270bbf67f: Scheduling FlushDeltaMemStoresOp(450188465a6a4e688121c178e0f6ca89): perf score=18.063937
I20260812 06:18:07.519990 22307 maintenance_manager.cc:643] P d99290adb4d3468693ca0e6270bbf67f: FlushDeltaMemStoresOp(450188465a6a4e688121c178e0f6ca89) complete. Timing: real 0.070s	user 0.022s	sys 0.036s Metrics: {"bytes_written":20512317,"delete_count":0,"lbm_write_time_us":27160,"lbm_writes_lt_1ms":503,"reinsert_count":0,"update_count":2500}
I20260812 06:18:07.520613 22377 maintenance_manager.cc:419] P d99290adb4d3468693ca0e6270bbf67f: Scheduling FlushDeltaMemStoresOp(450188465a6a4e688121c178e0f6ca89): perf score=2.188937
I20260812 06:18:07.532244 22307 maintenance_manager.cc:643] P d99290adb4d3468693ca0e6270bbf67f: FlushDeltaMemStoresOp(450188465a6a4e688121c178e0f6ca89) complete. Timing: real 0.011s	user 0.001s	sys 0.009s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4650,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:07.533087 22377 maintenance_manager.cc:419] P d99290adb4d3468693ca0e6270bbf67f: Scheduling MajorDeltaCompactionOp(450188465a6a4e688121c178e0f6ca89): perf score=1.000000
I20260812 06:18:07.728557 22307 maintenance_manager.cc:643] P d99290adb4d3468693ca0e6270bbf67f: MajorDeltaCompactionOp(450188465a6a4e688121c178e0f6ca89) complete. Timing: real 0.195s	user 0.138s	sys 0.057s Metrics: {"cfile_cache_miss":632,"cfile_cache_miss_bytes":28877104,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":1287,"lbm_read_time_us":14784,"lbm_reads_lt_1ms":672,"lbm_write_time_us":34750,"lbm_writes_lt_1ms":643,"mutex_wait_us":279,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":3712,"update_count":3000}
I20260812 06:18:07.729349 22377 maintenance_manager.cc:419] P d99290adb4d3468693ca0e6270bbf67f: Scheduling FlushDeltaMemStoresOp(450188465a6a4e688121c178e0f6ca89): perf score=14.095187
I20260812 06:18:07.787724 22307 maintenance_manager.cc:643] P d99290adb4d3468693ca0e6270bbf67f: FlushDeltaMemStoresOp(450188465a6a4e688121c178e0f6ca89) complete. Timing: real 0.058s	user 0.029s	sys 0.019s Metrics: {"bytes_written":16409900,"delete_count":0,"lbm_write_time_us":22615,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:18:07.788240 22377 maintenance_manager.cc:419] P d99290adb4d3468693ca0e6270bbf67f: Scheduling FlushDeltaMemStoresOp(450188465a6a4e688121c178e0f6ca89): perf score=2.188937
I20260812 06:18:07.799744 22307 maintenance_manager.cc:643] P d99290adb4d3468693ca0e6270bbf67f: FlushDeltaMemStoresOp(450188465a6a4e688121c178e0f6ca89) complete. Timing: real 0.011s	user 0.006s	sys 0.003s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4019,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:07.800223 22377 maintenance_manager.cc:419] P d99290adb4d3468693ca0e6270bbf67f: Scheduling MajorDeltaCompactionOp(450188465a6a4e688121c178e0f6ca89): perf score=1.000000
I20260812 06:18:07.985450 22307 maintenance_manager.cc:643] P d99290adb4d3468693ca0e6270bbf67f: MajorDeltaCompactionOp(450188465a6a4e688121c178e0f6ca89) complete. Timing: real 0.185s	user 0.134s	sys 0.037s 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":868,"lbm_read_time_us":11676,"lbm_reads_lt_1ms":572,"lbm_write_time_us":30616,"lbm_writes_lt_1ms":543,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":10880,"update_count":2500}
I20260812 06:18:07.986258 22377 maintenance_manager.cc:419] P d99290adb4d3468693ca0e6270bbf67f: Scheduling FlushDeltaMemStoresOp(450188465a6a4e688121c178e0f6ca89): perf score=14.095187
I20260812 06:18:08.052305 22307 maintenance_manager.cc:643] P d99290adb4d3468693ca0e6270bbf67f: FlushDeltaMemStoresOp(450188465a6a4e688121c178e0f6ca89) complete. Timing: real 0.066s	user 0.015s	sys 0.044s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":22646,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:18:08.053123 22377 maintenance_manager.cc:419] P d99290adb4d3468693ca0e6270bbf67f: Scheduling FlushDeltaMemStoresOp(450188465a6a4e688121c178e0f6ca89): perf score=2.188937
I20260812 06:18:08.065092 22307 maintenance_manager.cc:643] P d99290adb4d3468693ca0e6270bbf67f: FlushDeltaMemStoresOp(450188465a6a4e688121c178e0f6ca89) complete. Timing: real 0.012s	user 0.003s	sys 0.009s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4636,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:08.065601 22377 maintenance_manager.cc:419] P d99290adb4d3468693ca0e6270bbf67f: Scheduling MajorDeltaCompactionOp(450188465a6a4e688121c178e0f6ca89): perf score=1.000000
I20260812 06:18:08.245757 22307 maintenance_manager.cc:643] P d99290adb4d3468693ca0e6270bbf67f: MajorDeltaCompactionOp(450188465a6a4e688121c178e0f6ca89) complete. Timing: real 0.180s	user 0.107s	sys 0.067s 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":203,"lbm_read_time_us":13330,"lbm_reads_lt_1ms":572,"lbm_write_time_us":30194,"lbm_writes_lt_1ms":543,"mutex_wait_us":47,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":13568,"update_count":2500}
I20260812 06:18:08.246559 22377 maintenance_manager.cc:419] P d99290adb4d3468693ca0e6270bbf67f: Scheduling FlushDeltaMemStoresOp(450188465a6a4e688121c178e0f6ca89): perf score=14.095187
I20260812 06:18:08.307752 22307 maintenance_manager.cc:643] P d99290adb4d3468693ca0e6270bbf67f: FlushDeltaMemStoresOp(450188465a6a4e688121c178e0f6ca89) complete. Timing: real 0.061s	user 0.019s	sys 0.039s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":22622,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":402,"reinsert_count":0,"update_count":2000}
I20260812 06:18:08.308396 22377 maintenance_manager.cc:419] P d99290adb4d3468693ca0e6270bbf67f: Scheduling FlushDeltaMemStoresOp(450188465a6a4e688121c178e0f6ca89): perf score=2.188937
I20260812 06:18:08.325233 22307 maintenance_manager.cc:643] P d99290adb4d3468693ca0e6270bbf67f: FlushDeltaMemStoresOp(450188465a6a4e688121c178e0f6ca89) complete. Timing: real 0.017s	user 0.008s	sys 0.007s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":6141,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:08.325763 22377 maintenance_manager.cc:419] P d99290adb4d3468693ca0e6270bbf67f: Scheduling FlushMRSOp(450188465a6a4e688121c178e0f6ca89): perf score=1.000000
I20260812 06:18:08.359719 22307 maintenance_manager.cc:643] P d99290adb4d3468693ca0e6270bbf67f: FlushMRSOp(450188465a6a4e688121c178e0f6ca89) complete. Timing: real 0.034s	user 0.029s	sys 0.003s Metrics: {"bytes_written":1234477,"cfile_init":1,"dirs.queue_time_us":69,"dirs.run_cpu_time_us":253,"dirs.run_wall_time_us":2168,"drs_written":1,"lbm_read_time_us":63,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1832,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":30}
I20260812 06:18:08.360761 22377 maintenance_manager.cc:419] P d99290adb4d3468693ca0e6270bbf67f: Scheduling LogGCOp(450188465a6a4e688121c178e0f6ca89): free 124257514 bytes of WAL
I20260812 06:18:08.361052 22307 log_reader.cc:385] T 450188465a6a4e688121c178e0f6ca89: removed 12 log segments from log reader
I20260812 06:18:08.361130 22307 log.cc:1079] T 450188465a6a4e688121c178e0f6ca89 P d99290adb4d3468693ca0e6270bbf67f: Deleting log segment in path: /tmp/dist-test-taskoJaC7T/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515483274578-22190-0/minicluster-data/ts-0-root/wals/450188465a6a4e688121c178e0f6ca89/wal-000000028 (ops 134-138)
I20260812 06:18:08.361186 22307 log.cc:1079] T 450188465a6a4e688121c178e0f6ca89 P d99290adb4d3468693ca0e6270bbf67f: Deleting log segment in path: /tmp/dist-test-taskoJaC7T/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515483274578-22190-0/minicluster-data/ts-0-root/wals/450188465a6a4e688121c178e0f6ca89/wal-000000029 (ops 139-143)
I20260812 06:18:08.361238 22307 log.cc:1079] T 450188465a6a4e688121c178e0f6ca89 P d99290adb4d3468693ca0e6270bbf67f: Deleting log segment in path: /tmp/dist-test-taskoJaC7T/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515483274578-22190-0/minicluster-data/ts-0-root/wals/450188465a6a4e688121c178e0f6ca89/wal-000000030 (ops 144-148)
I20260812 06:18:08.361279 22307 log.cc:1079] T 450188465a6a4e688121c178e0f6ca89 P d99290adb4d3468693ca0e6270bbf67f: Deleting log segment in path: /tmp/dist-test-taskoJaC7T/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515483274578-22190-0/minicluster-data/ts-0-root/wals/450188465a6a4e688121c178e0f6ca89/wal-000000031 (ops 149-153)
I20260812 06:18:08.361315 22307 log.cc:1079] T 450188465a6a4e688121c178e0f6ca89 P d99290adb4d3468693ca0e6270bbf67f: Deleting log segment in path: /tmp/dist-test-taskoJaC7T/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515483274578-22190-0/minicluster-data/ts-0-root/wals/450188465a6a4e688121c178e0f6ca89/wal-000000032 (ops 154-158)
I20260812 06:18:08.361352 22307 log.cc:1079] T 450188465a6a4e688121c178e0f6ca89 P d99290adb4d3468693ca0e6270bbf67f: Deleting log segment in path: /tmp/dist-test-taskoJaC7T/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515483274578-22190-0/minicluster-data/ts-0-root/wals/450188465a6a4e688121c178e0f6ca89/wal-000000033 (ops 159-163)
I20260812 06:18:08.361389 22307 log.cc:1079] T 450188465a6a4e688121c178e0f6ca89 P d99290adb4d3468693ca0e6270bbf67f: Deleting log segment in path: /tmp/dist-test-taskoJaC7T/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515483274578-22190-0/minicluster-data/ts-0-root/wals/450188465a6a4e688121c178e0f6ca89/wal-000000034 (ops 164-168)
I20260812 06:18:08.361425 22307 log.cc:1079] T 450188465a6a4e688121c178e0f6ca89 P d99290adb4d3468693ca0e6270bbf67f: Deleting log segment in path: /tmp/dist-test-taskoJaC7T/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515483274578-22190-0/minicluster-data/ts-0-root/wals/450188465a6a4e688121c178e0f6ca89/wal-000000035 (ops 169-173)
I20260812 06:18:08.361475 22307 log.cc:1079] T 450188465a6a4e688121c178e0f6ca89 P d99290adb4d3468693ca0e6270bbf67f: Deleting log segment in path: /tmp/dist-test-taskoJaC7T/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515483274578-22190-0/minicluster-data/ts-0-root/wals/450188465a6a4e688121c178e0f6ca89/wal-000000036 (ops 174-178)
I20260812 06:18:08.361513 22307 log.cc:1079] T 450188465a6a4e688121c178e0f6ca89 P d99290adb4d3468693ca0e6270bbf67f: Deleting log segment in path: /tmp/dist-test-taskoJaC7T/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515483274578-22190-0/minicluster-data/ts-0-root/wals/450188465a6a4e688121c178e0f6ca89/wal-000000037 (ops 179-183)
I20260812 06:18:08.361550 22307 log.cc:1079] T 450188465a6a4e688121c178e0f6ca89 P d99290adb4d3468693ca0e6270bbf67f: Deleting log segment in path: /tmp/dist-test-taskoJaC7T/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515483274578-22190-0/minicluster-data/ts-0-root/wals/450188465a6a4e688121c178e0f6ca89/wal-000000038 (ops 184-188)
I20260812 06:18:08.361593 22307 log.cc:1079] T 450188465a6a4e688121c178e0f6ca89 P d99290adb4d3468693ca0e6270bbf67f: Deleting log segment in path: /tmp/dist-test-taskoJaC7T/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515483274578-22190-0/minicluster-data/ts-0-root/wals/450188465a6a4e688121c178e0f6ca89/wal-000000039 (ops 189-192)
I20260812 06:18:08.391650 22307 maintenance_manager.cc:643] P d99290adb4d3468693ca0e6270bbf67f: LogGCOp(450188465a6a4e688121c178e0f6ca89) complete. Timing: real 0.031s	user 0.000s	sys 0.028s Metrics: {}
I20260812 06:18:08.392220 22377 maintenance_manager.cc:419] P d99290adb4d3468693ca0e6270bbf67f: Scheduling UndoDeltaBlockGCOp(450188465a6a4e688121c178e0f6ca89): 473 bytes on disk
I20260812 06:18:08.392936 22307 maintenance_manager.cc:643] P d99290adb4d3468693ca0e6270bbf67f: UndoDeltaBlockGCOp(450188465a6a4e688121c178e0f6ca89) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":82,"lbm_reads_lt_1ms":4}
I20260812 06:18:08.393667 22377 maintenance_manager.cc:419] P d99290adb4d3468693ca0e6270bbf67f: Scheduling FlushDeltaMemStoresOp(450188465a6a4e688121c178e0f6ca89): perf score=3.181125
I20260812 06:18:08.413880 22307 maintenance_manager.cc:643] P d99290adb4d3468693ca0e6270bbf67f: FlushDeltaMemStoresOp(450188465a6a4e688121c178e0f6ca89) complete. Timing: real 0.020s	user 0.014s	sys 0.005s Metrics: {"bytes_written":4923146,"delete_count":0,"lbm_write_time_us":8467,"lbm_writes_lt_1ms":123,"reinsert_count":0,"update_count":600}
I20260812 06:18:08.414446 22377 maintenance_manager.cc:419] P d99290adb4d3468693ca0e6270bbf67f: Scheduling FlushDeltaMemStoresOp(450188465a6a4e688121c178e0f6ca89): perf score=2.188937
I20260812 06:18:08.425101 22307 maintenance_manager.cc:643] P d99290adb4d3468693ca0e6270bbf67f: FlushDeltaMemStoresOp(450188465a6a4e688121c178e0f6ca89) complete. Timing: real 0.010s	user 0.009s	sys 0.001s Metrics: {"bytes_written":3282155,"delete_count":0,"lbm_write_time_us":3827,"lbm_writes_lt_1ms":83,"reinsert_count":0,"update_count":400}
I20260812 06:18:08.425591 22377 maintenance_manager.cc:419] P d99290adb4d3468693ca0e6270bbf67f: Scheduling MajorDeltaCompactionOp(450188465a6a4e688121c178e0f6ca89): perf score=1.000000
I20260812 06:18:08.595489 22190 heavy-update-compaction-itest.cc:229] Time spent updating: real 5.014s	user 1.857s	sys 0.142s
I20260812 06:18:08.661872 22307 maintenance_manager.cc:643] P d99290adb4d3468693ca0e6270bbf67f: MajorDeltaCompactionOp(450188465a6a4e688121c178e0f6ca89) complete. Timing: real 0.236s	user 0.156s	sys 0.079s Metrics: {"cfile_cache_miss":734,"cfile_cache_miss_bytes":32979733,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"lbm_read_time_us":17499,"lbm_reads_lt_1ms":770,"lbm_write_time_us":41579,"lbm_writes_lt_1ms":743,"peak_mem_usage":87969044,"reinsert_count":0,"update_count":3500}
I20260812 06:18:08.662417 22377 maintenance_manager.cc:419] P d99290adb4d3468693ca0e6270bbf67f: Scheduling FlushDeltaMemStoresOp(450188465a6a4e688121c178e0f6ca89): perf score=10.126437
I20260812 06:18:08.693723 22307 maintenance_manager.cc:643] P d99290adb4d3468693ca0e6270bbf67f: FlushDeltaMemStoresOp(450188465a6a4e688121c178e0f6ca89) complete. Timing: real 0.031s	user 0.014s	sys 0.016s Metrics: {"bytes_written":12307492,"delete_count":0,"lbm_write_time_us":13542,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:18:08.694289 22377 maintenance_manager.cc:419] P d99290adb4d3468693ca0e6270bbf67f: Scheduling MajorDeltaCompactionOp(450188465a6a4e688121c178e0f6ca89): perf score=1.000000
I20260812 06:18:08.694319 22190 heavy-update-compaction-itest.cc:265] Time spent scanning: real 0.098s	user 0.003s	sys 0.000s
I20260812 06:18:08.694975 22190 tablet_server.cc:179] TabletServer@127.21.171.129:0 shutting down...
I20260812 06:18:08.800244 22307 maintenance_manager.cc:643] P d99290adb4d3468693ca0e6270bbf67f: MajorDeltaCompactionOp(450188465a6a4e688121c178e0f6ca89) complete. Timing: real 0.106s	user 0.080s	sys 0.024s Metrics: {"cfile_cache_miss":331,"cfile_cache_miss_bytes":16569748,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":1,"delta_iterators_relevant":1,"dirs.queue_time_us":446,"lbm_read_time_us":7659,"lbm_reads_lt_1ms":367,"lbm_write_time_us":17709,"lbm_writes_lt_1ms":343,"mutex_wait_us":22,"peak_mem_usage":38262756,"reinsert_count":0,"spinlock_wait_cycles":9472,"update_count":1500}
I20260812 06:18:08.801085 22190 ts_tablet_manager.cc:1507] Shutting down tablet manager...
I20260812 06:18:08.801537 22190 tablet_replica.cc:333] T 450188465a6a4e688121c178e0f6ca89 P d99290adb4d3468693ca0e6270bbf67f: stopping tablet replica
I20260812 06:18:08.801782 22190 raft_consensus.cc:2243] T 450188465a6a4e688121c178e0f6ca89 P d99290adb4d3468693ca0e6270bbf67f [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:18:08.802018 22190 raft_consensus.cc:2272] T 450188465a6a4e688121c178e0f6ca89 P d99290adb4d3468693ca0e6270bbf67f [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:18:08.817108 22190 tablet_server.cc:196] TabletServer@127.21.171.129:0 shutdown complete.
I20260812 06:18:08.833590 22190 master.cc:562] Master@127.21.171.190:37173 shutting down...
I20260812 06:18:08.837654 22190 raft_consensus.cc:2243] T 00000000000000000000000000000000 P 0c9b1dc981a740b9946d3e1120d868a5 [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:18:08.837867 22190 raft_consensus.cc:2272] T 00000000000000000000000000000000 P 0c9b1dc981a740b9946d3e1120d868a5 [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:18:08.837955 22190 tablet_replica.cc:333] T 00000000000000000000000000000000 P 0c9b1dc981a740b9946d3e1120d868a5: stopping tablet replica
I20260812 06:18:08.850508 22190 master.cc:584] Master@127.21.171.190:37173 shutdown complete.
[       OK ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/0 (5655 ms)
[ RUN      ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/1
I20260812 06:18:08.940304 22190 internal_mini_cluster.cc:156] Creating distributed mini masters. Addrs: 127.21.171.190:46475
I20260812 06:18:08.940790 22190 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:18:08.942927 22415 instance_detector.cc:116] could not retrieve Azure instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:18:08.943022 22414 instance_detector.cc:116] could not retrieve AWS instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:18:08.943164 22190 server_base.cc:1061] running on GCE node
W20260812 06:18:08.943065 22417 instance_detector.cc:116] could not retrieve OpenStack instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:18:08.943511 22190 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:18:08.943558 22190 system_unsync_time.cc:38] NTP support is disabled. Clock error bounds will not be accurate. This configuration is not suitable for distributed clusters.
I20260812 06:18:08.943576 22190 hybrid_clock.cc:648] HybridClock initialized: now 1786515488943576 us; error 0 us; skew 500 ppm
I20260812 06:18:08.944626 22190 webserver.cc:533] Webserver started at http://127.21.171.190:46165/ using document root <none> and password file <none>
I20260812 06:18:08.944844 22190 fs_manager.cc:362] Metadata directory not provided
I20260812 06:18:08.944902 22190 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:18:08.945015 22190 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:18:08.945456 22190 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskoJaC7T/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515483274578-22190-0/minicluster-data/master-0-root/instance:
uuid: "ee812164448c4c51b9e00822b3aa5efa"
format_stamp: "Formatted at 2026-08-12 06:18:08 on dist-test-slave-qg60"
I20260812 06:18:08.947125 22190 fs_manager.cc:696] Time spent creating directory manager: real 0.001s	user 0.002s	sys 0.000s
I20260812 06:18:08.948164 22424 log_block_manager.cc:4127] Time spent loading block containers with low live blocks: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:18:08.948457 22190 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.001s	sys 0.000s
I20260812 06:18:08.948522 22190 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskoJaC7T/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515483274578-22190-0/minicluster-data/master-0-root
uuid: "ee812164448c4c51b9e00822b3aa5efa"
format_stamp: "Formatted at 2026-08-12 06:18:08 on dist-test-slave-qg60"
I20260812 06:18:08.948581 22190 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskoJaC7T/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515483274578-22190-0/minicluster-data/master-0-root
metadata directory: /tmp/dist-test-taskoJaC7T/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515483274578-22190-0/minicluster-data/master-0-root
1 data directories: /tmp/dist-test-taskoJaC7T/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515483274578-22190-0/minicluster-data/master-0-root/data
Total live blocks: 0
Total live bytes: 0
Total live bytes (after alignment): 0
Total number of LBM containers: 0 (0 full)
Did not check for missing blocks
Did not check for orphaned blocks
Total full LBM containers with extra space: 0 (0 repaired)
Total full LBM container extra space in bytes: 0 (0 repaired)
Total incomplete LBM containers: 0 (0 repaired)
Total LBM partial records: 0 (0 repaired)
Total corrupted LBM metadata records in RocksDB: 0 (0 repaired)
I20260812 06:18:08.970048 22190 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:18:08.970456 22190 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:18:08.974521 22190 rpc_server.cc:307] RPC server started. Bound to: 127.21.171.190:46475
I20260812 06:18:08.977495 22484 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.21.171.190:46475 every 8 connection(s)
I20260812 06:18:08.977768 22485 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet 00000000000000000000000000000000. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:18:08.991592 22485 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P ee812164448c4c51b9e00822b3aa5efa: Bootstrap starting.
I20260812 06:18:08.992453 22485 tablet_bootstrap.cc:654] T 00000000000000000000000000000000 P ee812164448c4c51b9e00822b3aa5efa: Neither blocks nor log segments found. Creating new log.
I20260812 06:18:08.993748 22485 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P ee812164448c4c51b9e00822b3aa5efa: No bootstrap required, opened a new log
I20260812 06:18:08.994143 22485 raft_consensus.cc:359] T 00000000000000000000000000000000 P ee812164448c4c51b9e00822b3aa5efa [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "ee812164448c4c51b9e00822b3aa5efa" member_type: VOTER }
I20260812 06:18:08.994240 22485 raft_consensus.cc:385] T 00000000000000000000000000000000 P ee812164448c4c51b9e00822b3aa5efa [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:18:08.994262 22485 raft_consensus.cc:740] T 00000000000000000000000000000000 P ee812164448c4c51b9e00822b3aa5efa [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: ee812164448c4c51b9e00822b3aa5efa, State: Initialized, Role: FOLLOWER
I20260812 06:18:08.994371 22485 consensus_queue.cc:260] T 00000000000000000000000000000000 P ee812164448c4c51b9e00822b3aa5efa [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: "ee812164448c4c51b9e00822b3aa5efa" member_type: VOTER }
I20260812 06:18:08.994432 22485 raft_consensus.cc:399] T 00000000000000000000000000000000 P ee812164448c4c51b9e00822b3aa5efa [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:18:08.994454 22485 raft_consensus.cc:493] T 00000000000000000000000000000000 P ee812164448c4c51b9e00822b3aa5efa [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:18:08.994484 22485 raft_consensus.cc:3060] T 00000000000000000000000000000000 P ee812164448c4c51b9e00822b3aa5efa [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:18:08.995204 22485 raft_consensus.cc:515] T 00000000000000000000000000000000 P ee812164448c4c51b9e00822b3aa5efa [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "ee812164448c4c51b9e00822b3aa5efa" member_type: VOTER }
I20260812 06:18:08.995321 22485 leader_election.cc:304] T 00000000000000000000000000000000 P ee812164448c4c51b9e00822b3aa5efa [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: ee812164448c4c51b9e00822b3aa5efa; no voters: 
I20260812 06:18:08.995483 22485 leader_election.cc:290] T 00000000000000000000000000000000 P ee812164448c4c51b9e00822b3aa5efa [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:18:08.995659 22488 raft_consensus.cc:2804] T 00000000000000000000000000000000 P ee812164448c4c51b9e00822b3aa5efa [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:18:08.995919 22488 raft_consensus.cc:697] T 00000000000000000000000000000000 P ee812164448c4c51b9e00822b3aa5efa [term 1 LEADER]: Becoming Leader. State: Replica: ee812164448c4c51b9e00822b3aa5efa, State: Running, Role: LEADER
I20260812 06:18:08.995931 22485 sys_catalog.cc:565] T 00000000000000000000000000000000 P ee812164448c4c51b9e00822b3aa5efa [sys.catalog]: configured and running, proceeding with master startup.
I20260812 06:18:08.996142 22488 consensus_queue.cc:237] T 00000000000000000000000000000000 P ee812164448c4c51b9e00822b3aa5efa [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: "ee812164448c4c51b9e00822b3aa5efa" member_type: VOTER }
I20260812 06:18:08.996654 22491 sys_catalog.cc:455] T 00000000000000000000000000000000 P ee812164448c4c51b9e00822b3aa5efa [sys.catalog]: SysCatalogTable state changed. Reason: New leader ee812164448c4c51b9e00822b3aa5efa. Latest consensus state: current_term: 1 leader_uuid: "ee812164448c4c51b9e00822b3aa5efa" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "ee812164448c4c51b9e00822b3aa5efa" member_type: VOTER } }
I20260812 06:18:08.996776 22491 sys_catalog.cc:458] T 00000000000000000000000000000000 P ee812164448c4c51b9e00822b3aa5efa [sys.catalog]: This master's current role is: LEADER
I20260812 06:18:08.996641 22490 sys_catalog.cc:455] T 00000000000000000000000000000000 P ee812164448c4c51b9e00822b3aa5efa [sys.catalog]: SysCatalogTable state changed. Reason: RaftConsensus started. Latest consensus state: current_term: 1 leader_uuid: "ee812164448c4c51b9e00822b3aa5efa" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "ee812164448c4c51b9e00822b3aa5efa" member_type: VOTER } }
I20260812 06:18:08.997108 22490 sys_catalog.cc:458] T 00000000000000000000000000000000 P ee812164448c4c51b9e00822b3aa5efa [sys.catalog]: This master's current role is: LEADER
I20260812 06:18:08.997210 22498 catalog_manager.cc:1511] Loading table and tablet metadata into memory...
I20260812 06:18:08.997918 22498 catalog_manager.cc:1520] Initializing Kudu cluster ID...
I20260812 06:18:08.998188 22190 internal_mini_cluster.cc:184] Waiting to initialize catalog manager on master 0
I20260812 06:18:08.999886 22498 catalog_manager.cc:1383] Generated new cluster ID: 8fb349e5bd4b45dd9937601b494f2622
I20260812 06:18:08.999953 22498 catalog_manager.cc:1531] Initializing Kudu internal certificate authority...
I20260812 06:18:09.016077 22498 catalog_manager.cc:1406] Generated new certificate authority record
I20260812 06:18:09.016985 22498 catalog_manager.cc:1540] Loading token signing keys...
I20260812 06:18:09.026858 22498 catalog_manager.cc:6092] T 00000000000000000000000000000000 P ee812164448c4c51b9e00822b3aa5efa: Generated new TSK 0
I20260812 06:18:09.027070 22498 catalog_manager.cc:1550] Initializing in-progress tserver states...
I20260812 06:18:09.030997 22190 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:18:09.033244 22509 instance_detector.cc:116] could not retrieve AWS instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:18:09.033358 22512 instance_detector.cc:116] could not retrieve OpenStack instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:18:09.033424 22190 server_base.cc:1061] running on GCE node
W20260812 06:18:09.033536 22510 instance_detector.cc:116] could not retrieve Azure instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:18:09.033746 22190 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:18:09.033792 22190 system_unsync_time.cc:38] NTP support is disabled. Clock error bounds will not be accurate. This configuration is not suitable for distributed clusters.
I20260812 06:18:09.033807 22190 hybrid_clock.cc:648] HybridClock initialized: now 1786515489033808 us; error 0 us; skew 500 ppm
I20260812 06:18:09.034773 22190 webserver.cc:533] Webserver started at http://127.21.171.129:42413/ using document root <none> and password file <none>
I20260812 06:18:09.034921 22190 fs_manager.cc:362] Metadata directory not provided
I20260812 06:18:09.035048 22190 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:18:09.035120 22190 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:18:09.035566 22190 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskoJaC7T/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515483274578-22190-0/minicluster-data/ts-0-root/instance:
uuid: "8fc05e2c5f1d4769886914438129337e"
format_stamp: "Formatted at 2026-08-12 06:18:09 on dist-test-slave-qg60"
I20260812 06:18:09.037317 22190 fs_manager.cc:696] Time spent creating directory manager: real 0.002s	user 0.002s	sys 0.000s
I20260812 06:18:09.038409 22518 log_block_manager.cc:4127] Time spent loading block containers with low live blocks: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:18:09.038738 22190 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.001s	sys 0.000s
I20260812 06:18:09.038807 22190 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskoJaC7T/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515483274578-22190-0/minicluster-data/ts-0-root
uuid: "8fc05e2c5f1d4769886914438129337e"
format_stamp: "Formatted at 2026-08-12 06:18:09 on dist-test-slave-qg60"
I20260812 06:18:09.038924 22190 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskoJaC7T/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515483274578-22190-0/minicluster-data/ts-0-root
metadata directory: /tmp/dist-test-taskoJaC7T/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515483274578-22190-0/minicluster-data/ts-0-root
1 data directories: /tmp/dist-test-taskoJaC7T/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515483274578-22190-0/minicluster-data/ts-0-root/data
Total live blocks: 0
Total live bytes: 0
Total live bytes (after alignment): 0
Total number of LBM containers: 0 (0 full)
Did not check for missing blocks
Did not check for orphaned blocks
Total full LBM containers with extra space: 0 (0 repaired)
Total full LBM container extra space in bytes: 0 (0 repaired)
Total incomplete LBM containers: 0 (0 repaired)
Total LBM partial records: 0 (0 repaired)
Total corrupted LBM metadata records in RocksDB: 0 (0 repaired)
I20260812 06:18:09.075455 22190 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:18:09.075918 22190 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:18:09.076303 22190 txn_system_client.cc:432] TxnSystemClient initialization is disabled...
I20260812 06:18:09.076874 22190 ts_tablet_manager.cc:585] Loaded tablet metadata (0 total tablets, 0 live tablets)
I20260812 06:18:09.076947 22190 ts_tablet_manager.cc:531] Time spent load tablet metadata: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:18:09.077013 22190 ts_tablet_manager.cc:616] Registered 0 tablets
I20260812 06:18:09.077064 22190 ts_tablet_manager.cc:595] Time spent register tablets: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:18:09.081986 22190 rpc_server.cc:307] RPC server started. Bound to: 127.21.171.129:46709
I20260812 06:18:09.082000 22593 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.21.171.129:46709 every 8 connection(s)
I20260812 06:18:09.093120 22595 heartbeater.cc:344] Connected to a master server at 127.21.171.190:46475
I20260812 06:18:09.093271 22595 heartbeater.cc:461] Registering TS with master...
I20260812 06:18:09.093534 22595 heartbeater.cc:507] Master 127.21.171.190:46475 requested a full tablet report, sending...
I20260812 06:18:09.094291 22443 ts_manager.cc:194] Registered new tserver with Master: 8fc05e2c5f1d4769886914438129337e (127.21.171.129:46709)
I20260812 06:18:09.094720 22190 internal_mini_cluster.cc:371] 1 TS(s) registered with all masters after 0.012207132s
I20260812 06:18:09.095088 22443 master_service.cc:502] Signed X509 certificate for tserver {username='slave'} at 127.0.0.1:57276
I20260812 06:18:09.102409 22443 catalog_manager.cc:2283] Servicing CreateTable request from {username='slave'} at 127.0.0.1:57288:
name: "heavy-update-compaction-test"
schema {
  columns {
    name: "key"
    type: INT64
    is_key: true
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_a"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_b"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_c"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_d"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_e"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
}
num_replicas: 1
split_rows_range_bounds {
}
partition_schema {
  range_schema {
  }
}
I20260812 06:18:09.111650 22551 tablet_service.cc:1511] Processing CreateTablet for tablet 679444cdcbde4daf94bf8e08d04b427f (DEFAULT_TABLE table=heavy-update-compaction-test [id=80768c9380c9424e9a1fc16b9e0d6501]), partition=
I20260812 06:18:09.111958 22551 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet 679444cdcbde4daf94bf8e08d04b427f. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:18:09.114414 22609 tablet_bootstrap.cc:492] T 679444cdcbde4daf94bf8e08d04b427f P 8fc05e2c5f1d4769886914438129337e: Bootstrap starting.
I20260812 06:18:09.115412 22609 tablet_bootstrap.cc:654] T 679444cdcbde4daf94bf8e08d04b427f P 8fc05e2c5f1d4769886914438129337e: Neither blocks nor log segments found. Creating new log.
I20260812 06:18:09.116524 22609 tablet_bootstrap.cc:492] T 679444cdcbde4daf94bf8e08d04b427f P 8fc05e2c5f1d4769886914438129337e: No bootstrap required, opened a new log
I20260812 06:18:09.116628 22609 ts_tablet_manager.cc:1403] T 679444cdcbde4daf94bf8e08d04b427f P 8fc05e2c5f1d4769886914438129337e: Time spent bootstrapping tablet: real 0.002s	user 0.002s	sys 0.000s
I20260812 06:18:09.117168 22609 raft_consensus.cc:359] T 679444cdcbde4daf94bf8e08d04b427f P 8fc05e2c5f1d4769886914438129337e [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "8fc05e2c5f1d4769886914438129337e" member_type: VOTER last_known_addr { host: "127.21.171.129" port: 46709 } }
I20260812 06:18:09.117295 22609 raft_consensus.cc:385] T 679444cdcbde4daf94bf8e08d04b427f P 8fc05e2c5f1d4769886914438129337e [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:18:09.117333 22609 raft_consensus.cc:740] T 679444cdcbde4daf94bf8e08d04b427f P 8fc05e2c5f1d4769886914438129337e [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: 8fc05e2c5f1d4769886914438129337e, State: Initialized, Role: FOLLOWER
I20260812 06:18:09.117512 22609 consensus_queue.cc:260] T 679444cdcbde4daf94bf8e08d04b427f P 8fc05e2c5f1d4769886914438129337e [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: "8fc05e2c5f1d4769886914438129337e" member_type: VOTER last_known_addr { host: "127.21.171.129" port: 46709 } }
I20260812 06:18:09.117605 22609 raft_consensus.cc:399] T 679444cdcbde4daf94bf8e08d04b427f P 8fc05e2c5f1d4769886914438129337e [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:18:09.117631 22609 raft_consensus.cc:493] T 679444cdcbde4daf94bf8e08d04b427f P 8fc05e2c5f1d4769886914438129337e [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:18:09.117660 22609 raft_consensus.cc:3060] T 679444cdcbde4daf94bf8e08d04b427f P 8fc05e2c5f1d4769886914438129337e [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:18:09.118454 22609 raft_consensus.cc:515] T 679444cdcbde4daf94bf8e08d04b427f P 8fc05e2c5f1d4769886914438129337e [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "8fc05e2c5f1d4769886914438129337e" member_type: VOTER last_known_addr { host: "127.21.171.129" port: 46709 } }
I20260812 06:18:09.118575 22609 leader_election.cc:304] T 679444cdcbde4daf94bf8e08d04b427f P 8fc05e2c5f1d4769886914438129337e [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: 8fc05e2c5f1d4769886914438129337e; no voters: 
I20260812 06:18:09.118737 22609 leader_election.cc:290] T 679444cdcbde4daf94bf8e08d04b427f P 8fc05e2c5f1d4769886914438129337e [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:18:09.118865 22612 raft_consensus.cc:2804] T 679444cdcbde4daf94bf8e08d04b427f P 8fc05e2c5f1d4769886914438129337e [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:18:09.119145 22595 heartbeater.cc:499] Master 127.21.171.190:46475 was elected leader, sending a full tablet report...
I20260812 06:18:09.119153 22612 raft_consensus.cc:697] T 679444cdcbde4daf94bf8e08d04b427f P 8fc05e2c5f1d4769886914438129337e [term 1 LEADER]: Becoming Leader. State: Replica: 8fc05e2c5f1d4769886914438129337e, State: Running, Role: LEADER
I20260812 06:18:09.119155 22609 ts_tablet_manager.cc:1434] T 679444cdcbde4daf94bf8e08d04b427f P 8fc05e2c5f1d4769886914438129337e: Time spent starting tablet: real 0.002s	user 0.000s	sys 0.003s
I20260812 06:18:09.119318 22612 consensus_queue.cc:237] T 679444cdcbde4daf94bf8e08d04b427f P 8fc05e2c5f1d4769886914438129337e [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: "8fc05e2c5f1d4769886914438129337e" member_type: VOTER last_known_addr { host: "127.21.171.129" port: 46709 } }
I20260812 06:18:09.120702 22443 catalog_manager.cc:5719] T 679444cdcbde4daf94bf8e08d04b427f P 8fc05e2c5f1d4769886914438129337e reported cstate change: term changed from 0 to 1, leader changed from <none> to 8fc05e2c5f1d4769886914438129337e (127.21.171.129). New cstate: current_term: 1 leader_uuid: "8fc05e2c5f1d4769886914438129337e" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "8fc05e2c5f1d4769886914438129337e" member_type: VOTER last_known_addr { host: "127.21.171.129" port: 46709 } health_report { overall_health: HEALTHY } } }
I20260812 06:18:09.183873 22190 heavy-update-compaction-itest.cc:215] Time spent inserting: real 0.056s	user 0.010s	sys 0.013s
I20260812 06:18:09.333091 22597 maintenance_manager.cc:419] P 8fc05e2c5f1d4769886914438129337e: Scheduling FlushMRSOp(679444cdcbde4daf94bf8e08d04b427f): perf score=19.054940
I20260812 06:18:09.496753 22524 maintenance_manager.cc:643] P 8fc05e2c5f1d4769886914438129337e: FlushMRSOp(679444cdcbde4daf94bf8e08d04b427f) complete. Timing: real 0.163s	user 0.123s	sys 0.036s Metrics: {"bytes_written":12307490,"cfile_init":1,"delete_count":0,"dirs.queue_time_us":71,"dirs.run_cpu_time_us":212,"dirs.run_wall_time_us":1004,"drs_written":1,"lbm_read_time_us":40,"lbm_reads_lt_1ms":4,"lbm_write_time_us":45387,"lbm_writes_lt_1ms":757,"peak_mem_usage":0,"reinsert_count":0,"rows_written":104,"update_count":1500}
I20260812 06:18:09.497502 22597 maintenance_manager.cc:419] P 8fc05e2c5f1d4769886914438129337e: Scheduling LogGCOp(679444cdcbde4daf94bf8e08d04b427f): free 20743831 bytes of WAL
I20260812 06:18:09.497730 22524 log_reader.cc:385] T 679444cdcbde4daf94bf8e08d04b427f: removed 2 log segments from log reader
I20260812 06:18:09.497788 22524 log.cc:1079] T 679444cdcbde4daf94bf8e08d04b427f P 8fc05e2c5f1d4769886914438129337e: Deleting log segment in path: /tmp/dist-test-taskoJaC7T/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515483274578-22190-0/minicluster-data/ts-0-root/wals/679444cdcbde4daf94bf8e08d04b427f/wal-000000001 (ops 1-6)
I20260812 06:18:09.497848 22524 log.cc:1079] T 679444cdcbde4daf94bf8e08d04b427f P 8fc05e2c5f1d4769886914438129337e: Deleting log segment in path: /tmp/dist-test-taskoJaC7T/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515483274578-22190-0/minicluster-data/ts-0-root/wals/679444cdcbde4daf94bf8e08d04b427f/wal-000000002 (ops 7-11)
I20260812 06:18:09.503000 22524 maintenance_manager.cc:643] P 8fc05e2c5f1d4769886914438129337e: LogGCOp(679444cdcbde4daf94bf8e08d04b427f) complete. Timing: real 0.005s	user 0.000s	sys 0.003s Metrics: {}
I20260812 06:18:09.503432 22597 maintenance_manager.cc:419] P 8fc05e2c5f1d4769886914438129337e: Scheduling FlushDeltaMemStoresOp(679444cdcbde4daf94bf8e08d04b427f): perf score=2.188937
I20260812 06:18:09.515573 22524 maintenance_manager.cc:643] P 8fc05e2c5f1d4769886914438129337e: FlushDeltaMemStoresOp(679444cdcbde4daf94bf8e08d04b427f) complete. Timing: real 0.012s	user 0.009s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4031,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:09.516052 22597 maintenance_manager.cc:419] P 8fc05e2c5f1d4769886914438129337e: Scheduling UndoDeltaBlockGCOp(679444cdcbde4daf94bf8e08d04b427f): 16411393 bytes on disk
I20260812 06:18:09.516552 22524 maintenance_manager.cc:643] P 8fc05e2c5f1d4769886914438129337e: UndoDeltaBlockGCOp(679444cdcbde4daf94bf8e08d04b427f) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":59,"lbm_reads_lt_1ms":4}
I20260812 06:18:09.517066 22597 maintenance_manager.cc:419] P 8fc05e2c5f1d4769886914438129337e: Scheduling MajorDeltaCompactionOp(679444cdcbde4daf94bf8e08d04b427f): perf score=1.000000
I20260812 06:18:09.660413 22524 maintenance_manager.cc:643] P 8fc05e2c5f1d4769886914438129337e: MajorDeltaCompactionOp(679444cdcbde4daf94bf8e08d04b427f) complete. Timing: real 0.143s	user 0.119s	sys 0.024s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672277,"cfile_init":7,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":667,"lbm_read_time_us":10463,"lbm_reads_lt_1ms":460,"lbm_write_time_us":26316,"lbm_writes_lt_1ms":443,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":768,"thread_start_us":347,"threads_started":5,"update_count":2000}
I20260812 06:18:09.661083 22597 maintenance_manager.cc:419] P 8fc05e2c5f1d4769886914438129337e: Scheduling FlushDeltaMemStoresOp(679444cdcbde4daf94bf8e08d04b427f): perf score=10.126437
I20260812 06:18:09.695991 22524 maintenance_manager.cc:643] P 8fc05e2c5f1d4769886914438129337e: FlushDeltaMemStoresOp(679444cdcbde4daf94bf8e08d04b427f) complete. Timing: real 0.035s	user 0.023s	sys 0.008s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":15153,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:18:09.696581 22597 maintenance_manager.cc:419] P 8fc05e2c5f1d4769886914438129337e: Scheduling FlushDeltaMemStoresOp(679444cdcbde4daf94bf8e08d04b427f): perf score=2.188937
I20260812 06:18:09.716225 22524 maintenance_manager.cc:643] P 8fc05e2c5f1d4769886914438129337e: FlushDeltaMemStoresOp(679444cdcbde4daf94bf8e08d04b427f) complete. Timing: real 0.019s	user 0.007s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6324,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:09.716826 22597 maintenance_manager.cc:419] P 8fc05e2c5f1d4769886914438129337e: Scheduling MajorDeltaCompactionOp(679444cdcbde4daf94bf8e08d04b427f): perf score=1.000000
I20260812 06:18:09.842741 22524 maintenance_manager.cc:643] P 8fc05e2c5f1d4769886914438129337e: MajorDeltaCompactionOp(679444cdcbde4daf94bf8e08d04b427f) complete. Timing: real 0.126s	user 0.101s	sys 0.025s 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":212,"lbm_read_time_us":7832,"lbm_reads_lt_1ms":464,"lbm_write_time_us":23934,"lbm_writes_lt_1ms":443,"mutex_wait_us":94,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":2176,"update_count":2000}
I20260812 06:18:09.843451 22597 maintenance_manager.cc:419] P 8fc05e2c5f1d4769886914438129337e: Scheduling FlushDeltaMemStoresOp(679444cdcbde4daf94bf8e08d04b427f): perf score=11.118625
I20260812 06:18:09.882838 22524 maintenance_manager.cc:643] P 8fc05e2c5f1d4769886914438129337e: FlushDeltaMemStoresOp(679444cdcbde4daf94bf8e08d04b427f) complete. Timing: real 0.039s	user 0.025s	sys 0.012s Metrics: {"bytes_written":12717735,"delete_count":0,"lbm_write_time_us":18652,"lbm_writes_1-10_ms":3,"lbm_writes_lt_1ms":310,"reinsert_count":0,"update_count":1550}
I20260812 06:18:09.883281 22597 maintenance_manager.cc:419] P 8fc05e2c5f1d4769886914438129337e: Scheduling FlushDeltaMemStoresOp(679444cdcbde4daf94bf8e08d04b427f): perf score=2.188937
I20260812 06:18:09.906613 22524 maintenance_manager.cc:643] P 8fc05e2c5f1d4769886914438129337e: FlushDeltaMemStoresOp(679444cdcbde4daf94bf8e08d04b427f) complete. Timing: real 0.023s	user 0.003s	sys 0.008s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":5008,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:18:09.907119 22597 maintenance_manager.cc:419] P 8fc05e2c5f1d4769886914438129337e: Scheduling FlushDeltaMemStoresOp(679444cdcbde4daf94bf8e08d04b427f): perf score=2.188937
I20260812 06:18:09.917775 22524 maintenance_manager.cc:643] P 8fc05e2c5f1d4769886914438129337e: FlushDeltaMemStoresOp(679444cdcbde4daf94bf8e08d04b427f) complete. Timing: real 0.010s	user 0.008s	sys 0.001s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3973,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:09.918264 22597 maintenance_manager.cc:419] P 8fc05e2c5f1d4769886914438129337e: Scheduling MajorDeltaCompactionOp(679444cdcbde4daf94bf8e08d04b427f): perf score=1.000000
I20260812 06:18:10.098640 22524 maintenance_manager.cc:643] P 8fc05e2c5f1d4769886914438129337e: MajorDeltaCompactionOp(679444cdcbde4daf94bf8e08d04b427f) complete. Timing: real 0.180s	user 0.132s	sys 0.035s 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":922,"lbm_read_time_us":10311,"lbm_reads_lt_1ms":573,"lbm_write_time_us":32630,"lbm_writes_lt_1ms":543,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":1408,"update_count":2500}
I20260812 06:18:10.099261 22597 maintenance_manager.cc:419] P 8fc05e2c5f1d4769886914438129337e: Scheduling FlushDeltaMemStoresOp(679444cdcbde4daf94bf8e08d04b427f): perf score=14.095187
I20260812 06:18:10.143671 22524 maintenance_manager.cc:643] P 8fc05e2c5f1d4769886914438129337e: FlushDeltaMemStoresOp(679444cdcbde4daf94bf8e08d04b427f) complete. Timing: real 0.044s	user 0.037s	sys 0.004s Metrics: {"bytes_written":16409900,"delete_count":0,"lbm_write_time_us":19861,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:18:10.144297 22597 maintenance_manager.cc:419] P 8fc05e2c5f1d4769886914438129337e: Scheduling MajorDeltaCompactionOp(679444cdcbde4daf94bf8e08d04b427f): perf score=1.000000
I20260812 06:18:10.312892 22524 maintenance_manager.cc:643] P 8fc05e2c5f1d4769886914438129337e: MajorDeltaCompactionOp(679444cdcbde4daf94bf8e08d04b427f) complete. Timing: real 0.168s	user 0.133s	sys 0.031s Metrics: {"cfile_cache_miss":431,"cfile_cache_miss_bytes":20672156,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":1,"delta_iterators_relevant":1,"dirs.queue_time_us":939,"lbm_read_time_us":11854,"lbm_reads_lt_1ms":467,"lbm_write_time_us":28372,"lbm_writes_lt_1ms":443,"mutex_wait_us":285,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":21120,"update_count":2000}
I20260812 06:18:10.313701 22597 maintenance_manager.cc:419] P 8fc05e2c5f1d4769886914438129337e: Scheduling FlushDeltaMemStoresOp(679444cdcbde4daf94bf8e08d04b427f): perf score=11.118625
I20260812 06:18:10.354560 22524 maintenance_manager.cc:643] P 8fc05e2c5f1d4769886914438129337e: FlushDeltaMemStoresOp(679444cdcbde4daf94bf8e08d04b427f) complete. Timing: real 0.040s	user 0.009s	sys 0.028s Metrics: {"bytes_written":12881836,"delete_count":0,"lbm_write_time_us":17940,"lbm_writes_lt_1ms":317,"reinsert_count":0,"update_count":1570}
I20260812 06:18:10.355111 22597 maintenance_manager.cc:419] P 8fc05e2c5f1d4769886914438129337e: Scheduling FlushDeltaMemStoresOp(679444cdcbde4daf94bf8e08d04b427f): perf score=2.188937
I20260812 06:18:10.367609 22524 maintenance_manager.cc:643] P 8fc05e2c5f1d4769886914438129337e: FlushDeltaMemStoresOp(679444cdcbde4daf94bf8e08d04b427f) complete. Timing: real 0.012s	user 0.008s	sys 0.000s Metrics: {"bytes_written":3938560,"delete_count":0,"lbm_write_time_us":3916,"lbm_writes_lt_1ms":99,"reinsert_count":0,"update_count":480}
I20260812 06:18:10.368073 22597 maintenance_manager.cc:419] P 8fc05e2c5f1d4769886914438129337e: Scheduling FlushDeltaMemStoresOp(679444cdcbde4daf94bf8e08d04b427f): perf score=2.188937
I20260812 06:18:10.377799 22524 maintenance_manager.cc:643] P 8fc05e2c5f1d4769886914438129337e: FlushDeltaMemStoresOp(679444cdcbde4daf94bf8e08d04b427f) complete. Timing: real 0.010s	user 0.005s	sys 0.004s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3562,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:18:10.378310 22597 maintenance_manager.cc:419] P 8fc05e2c5f1d4769886914438129337e: Scheduling MajorDeltaCompactionOp(679444cdcbde4daf94bf8e08d04b427f): perf score=1.000000
I20260812 06:18:10.568523 22524 maintenance_manager.cc:643] P 8fc05e2c5f1d4769886914438129337e: MajorDeltaCompactionOp(679444cdcbde4daf94bf8e08d04b427f) complete. Timing: real 0.190s	user 0.124s	sys 0.061s 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":1008,"lbm_read_time_us":11789,"lbm_reads_lt_1ms":573,"lbm_write_time_us":28589,"lbm_writes_lt_1ms":543,"mutex_wait_us":301,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":149632,"update_count":2500}
I20260812 06:18:10.569386 22597 maintenance_manager.cc:419] P 8fc05e2c5f1d4769886914438129337e: Scheduling FlushDeltaMemStoresOp(679444cdcbde4daf94bf8e08d04b427f): perf score=14.095187
I20260812 06:18:10.624251 22524 maintenance_manager.cc:643] P 8fc05e2c5f1d4769886914438129337e: FlushDeltaMemStoresOp(679444cdcbde4daf94bf8e08d04b427f) complete. Timing: real 0.055s	user 0.044s	sys 0.007s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":24103,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:18:10.624898 22597 maintenance_manager.cc:419] P 8fc05e2c5f1d4769886914438129337e: Scheduling FlushDeltaMemStoresOp(679444cdcbde4daf94bf8e08d04b427f): perf score=2.188937
I20260812 06:18:10.641803 22524 maintenance_manager.cc:643] P 8fc05e2c5f1d4769886914438129337e: FlushDeltaMemStoresOp(679444cdcbde4daf94bf8e08d04b427f) complete. Timing: real 0.017s	user 0.015s	sys 0.001s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6483,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:10.642310 22597 maintenance_manager.cc:419] P 8fc05e2c5f1d4769886914438129337e: Scheduling MajorDeltaCompactionOp(679444cdcbde4daf94bf8e08d04b427f): perf score=1.000000
I20260812 06:18:10.811309 22524 maintenance_manager.cc:643] P 8fc05e2c5f1d4769886914438129337e: MajorDeltaCompactionOp(679444cdcbde4daf94bf8e08d04b427f) complete. Timing: real 0.169s	user 0.124s	sys 0.032s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774688,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":993,"lbm_read_time_us":10593,"lbm_reads_lt_1ms":564,"lbm_write_time_us":33237,"lbm_writes_lt_1ms":543,"mutex_wait_us":310,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":15232,"update_count":2500}
I20260812 06:18:10.811913 22597 maintenance_manager.cc:419] P 8fc05e2c5f1d4769886914438129337e: Scheduling FlushDeltaMemStoresOp(679444cdcbde4daf94bf8e08d04b427f): perf score=14.095187
I20260812 06:18:10.872408 22524 maintenance_manager.cc:643] P 8fc05e2c5f1d4769886914438129337e: FlushDeltaMemStoresOp(679444cdcbde4daf94bf8e08d04b427f) complete. Timing: real 0.060s	user 0.015s	sys 0.035s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":24825,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:18:10.873026 22597 maintenance_manager.cc:419] P 8fc05e2c5f1d4769886914438129337e: Scheduling FlushDeltaMemStoresOp(679444cdcbde4daf94bf8e08d04b427f): perf score=2.188937
I20260812 06:18:10.884598 22524 maintenance_manager.cc:643] P 8fc05e2c5f1d4769886914438129337e: FlushDeltaMemStoresOp(679444cdcbde4daf94bf8e08d04b427f) complete. Timing: real 0.011s	user 0.005s	sys 0.004s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4306,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:10.885423 22597 maintenance_manager.cc:419] P 8fc05e2c5f1d4769886914438129337e: Scheduling FlushMRSOp(679444cdcbde4daf94bf8e08d04b427f): perf score=1.000000
I20260812 06:18:10.919652 22524 maintenance_manager.cc:643] P 8fc05e2c5f1d4769886914438129337e: FlushMRSOp(679444cdcbde4daf94bf8e08d04b427f) complete. Timing: real 0.034s	user 0.032s	sys 0.000s Metrics: {"bytes_written":1316413,"cfile_init":1,"dirs.queue_time_us":81,"dirs.run_cpu_time_us":273,"dirs.run_wall_time_us":1969,"drs_written":1,"lbm_read_time_us":118,"lbm_reads_lt_1ms":4,"lbm_write_time_us":2109,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":32}
I20260812 06:18:10.920307 22597 maintenance_manager.cc:419] P 8fc05e2c5f1d4769886914438129337e: Scheduling LogGCOp(679444cdcbde4daf94bf8e08d04b427f): free 132571365 bytes of WAL
I20260812 06:18:10.920562 22524 log_reader.cc:385] T 679444cdcbde4daf94bf8e08d04b427f: removed 13 log segments from log reader
I20260812 06:18:10.920609 22524 log.cc:1079] T 679444cdcbde4daf94bf8e08d04b427f P 8fc05e2c5f1d4769886914438129337e: Deleting log segment in path: /tmp/dist-test-taskoJaC7T/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515483274578-22190-0/minicluster-data/ts-0-root/wals/679444cdcbde4daf94bf8e08d04b427f/wal-000000003 (ops 12-16)
I20260812 06:18:10.920639 22524 log.cc:1079] T 679444cdcbde4daf94bf8e08d04b427f P 8fc05e2c5f1d4769886914438129337e: Deleting log segment in path: /tmp/dist-test-taskoJaC7T/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515483274578-22190-0/minicluster-data/ts-0-root/wals/679444cdcbde4daf94bf8e08d04b427f/wal-000000004 (ops 17-21)
I20260812 06:18:10.920698 22524 log.cc:1079] T 679444cdcbde4daf94bf8e08d04b427f P 8fc05e2c5f1d4769886914438129337e: Deleting log segment in path: /tmp/dist-test-taskoJaC7T/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515483274578-22190-0/minicluster-data/ts-0-root/wals/679444cdcbde4daf94bf8e08d04b427f/wal-000000005 (ops 22-26)
I20260812 06:18:10.920769 22524 log.cc:1079] T 679444cdcbde4daf94bf8e08d04b427f P 8fc05e2c5f1d4769886914438129337e: Deleting log segment in path: /tmp/dist-test-taskoJaC7T/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515483274578-22190-0/minicluster-data/ts-0-root/wals/679444cdcbde4daf94bf8e08d04b427f/wal-000000006 (ops 27-31)
I20260812 06:18:10.920810 22524 log.cc:1079] T 679444cdcbde4daf94bf8e08d04b427f P 8fc05e2c5f1d4769886914438129337e: Deleting log segment in path: /tmp/dist-test-taskoJaC7T/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515483274578-22190-0/minicluster-data/ts-0-root/wals/679444cdcbde4daf94bf8e08d04b427f/wal-000000007 (ops 32-36)
I20260812 06:18:10.920828 22524 log.cc:1079] T 679444cdcbde4daf94bf8e08d04b427f P 8fc05e2c5f1d4769886914438129337e: Deleting log segment in path: /tmp/dist-test-taskoJaC7T/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515483274578-22190-0/minicluster-data/ts-0-root/wals/679444cdcbde4daf94bf8e08d04b427f/wal-000000008 (ops 37-41)
I20260812 06:18:10.920881 22524 log.cc:1079] T 679444cdcbde4daf94bf8e08d04b427f P 8fc05e2c5f1d4769886914438129337e: Deleting log segment in path: /tmp/dist-test-taskoJaC7T/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515483274578-22190-0/minicluster-data/ts-0-root/wals/679444cdcbde4daf94bf8e08d04b427f/wal-000000009 (ops 42-46)
I20260812 06:18:10.920923 22524 log.cc:1079] T 679444cdcbde4daf94bf8e08d04b427f P 8fc05e2c5f1d4769886914438129337e: Deleting log segment in path: /tmp/dist-test-taskoJaC7T/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515483274578-22190-0/minicluster-data/ts-0-root/wals/679444cdcbde4daf94bf8e08d04b427f/wal-000000010 (ops 47-50)
I20260812 06:18:10.920962 22524 log.cc:1079] T 679444cdcbde4daf94bf8e08d04b427f P 8fc05e2c5f1d4769886914438129337e: Deleting log segment in path: /tmp/dist-test-taskoJaC7T/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515483274578-22190-0/minicluster-data/ts-0-root/wals/679444cdcbde4daf94bf8e08d04b427f/wal-000000011 (ops 51-55)
I20260812 06:18:10.921005 22524 log.cc:1079] T 679444cdcbde4daf94bf8e08d04b427f P 8fc05e2c5f1d4769886914438129337e: Deleting log segment in path: /tmp/dist-test-taskoJaC7T/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515483274578-22190-0/minicluster-data/ts-0-root/wals/679444cdcbde4daf94bf8e08d04b427f/wal-000000012 (ops 56-60)
I20260812 06:18:10.921051 22524 log.cc:1079] T 679444cdcbde4daf94bf8e08d04b427f P 8fc05e2c5f1d4769886914438129337e: Deleting log segment in path: /tmp/dist-test-taskoJaC7T/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515483274578-22190-0/minicluster-data/ts-0-root/wals/679444cdcbde4daf94bf8e08d04b427f/wal-000000013 (ops 61-65)
I20260812 06:18:10.921096 22524 log.cc:1079] T 679444cdcbde4daf94bf8e08d04b427f P 8fc05e2c5f1d4769886914438129337e: Deleting log segment in path: /tmp/dist-test-taskoJaC7T/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515483274578-22190-0/minicluster-data/ts-0-root/wals/679444cdcbde4daf94bf8e08d04b427f/wal-000000014 (ops 66-70)
I20260812 06:18:10.921134 22524 log.cc:1079] T 679444cdcbde4daf94bf8e08d04b427f P 8fc05e2c5f1d4769886914438129337e: Deleting log segment in path: /tmp/dist-test-taskoJaC7T/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515483274578-22190-0/minicluster-data/ts-0-root/wals/679444cdcbde4daf94bf8e08d04b427f/wal-000000015 (ops 71-74)
I20260812 06:18:10.949105 22524 maintenance_manager.cc:643] P 8fc05e2c5f1d4769886914438129337e: LogGCOp(679444cdcbde4daf94bf8e08d04b427f) complete. Timing: real 0.029s	user 0.001s	sys 0.027s Metrics: {}
I20260812 06:18:10.949687 22597 maintenance_manager.cc:419] P 8fc05e2c5f1d4769886914438129337e: Scheduling UndoDeltaBlockGCOp(679444cdcbde4daf94bf8e08d04b427f): 492 bytes on disk
I20260812 06:18:10.950249 22524 maintenance_manager.cc:643] P 8fc05e2c5f1d4769886914438129337e: UndoDeltaBlockGCOp(679444cdcbde4daf94bf8e08d04b427f) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":55,"lbm_reads_lt_1ms":4}
I20260812 06:18:10.950754 22597 maintenance_manager.cc:419] P 8fc05e2c5f1d4769886914438129337e: Scheduling FlushDeltaMemStoresOp(679444cdcbde4daf94bf8e08d04b427f): perf score=5.165500
I20260812 06:18:10.979218 22524 maintenance_manager.cc:643] P 8fc05e2c5f1d4769886914438129337e: FlushDeltaMemStoresOp(679444cdcbde4daf94bf8e08d04b427f) complete. Timing: real 0.028s	user 0.014s	sys 0.011s Metrics: {"bytes_written":6523087,"delete_count":0,"lbm_write_time_us":6754,"lbm_writes_lt_1ms":162,"reinsert_count":0,"update_count":795}
I20260812 06:18:10.979871 22597 maintenance_manager.cc:419] P 8fc05e2c5f1d4769886914438129337e: Scheduling FlushDeltaMemStoresOp(679444cdcbde4daf94bf8e08d04b427f): perf score=1.000000
I20260812 06:18:10.987543 22524 maintenance_manager.cc:643] P 8fc05e2c5f1d4769886914438129337e: FlushDeltaMemStoresOp(679444cdcbde4daf94bf8e08d04b427f) complete. Timing: real 0.007s	user 0.000s	sys 0.006s Metrics: {"bytes_written":1682177,"delete_count":0,"lbm_write_time_us":2425,"lbm_writes_lt_1ms":44,"reinsert_count":0,"update_count":205}
I20260812 06:18:10.988132 22597 maintenance_manager.cc:419] P 8fc05e2c5f1d4769886914438129337e: Scheduling MajorDeltaCompactionOp(679444cdcbde4daf94bf8e08d04b427f): perf score=1.000000
I20260812 06:18:11.269127 22524 maintenance_manager.cc:643] P 8fc05e2c5f1d4769886914438129337e: MajorDeltaCompactionOp(679444cdcbde4daf94bf8e08d04b427f) complete. Timing: real 0.281s	user 0.179s	sys 0.088s Metrics: {"cfile_cache_miss":734,"cfile_cache_miss_bytes":32979691,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":897,"lbm_read_time_us":19292,"lbm_reads_lt_1ms":774,"lbm_write_time_us":46479,"lbm_writes_lt_1ms":743,"mutex_wait_us":46,"peak_mem_usage":87969044,"reinsert_count":0,"spinlock_wait_cycles":5120,"thread_start_us":86,"threads_started":1,"update_count":3500}
I20260812 06:18:11.269773 22597 maintenance_manager.cc:419] P 8fc05e2c5f1d4769886914438129337e: Scheduling FlushDeltaMemStoresOp(679444cdcbde4daf94bf8e08d04b427f): perf score=18.063937
I20260812 06:18:11.341220 22524 maintenance_manager.cc:643] P 8fc05e2c5f1d4769886914438129337e: FlushDeltaMemStoresOp(679444cdcbde4daf94bf8e08d04b427f) complete. Timing: real 0.071s	user 0.035s	sys 0.024s Metrics: {"bytes_written":20512315,"delete_count":0,"lbm_write_time_us":27087,"lbm_writes_lt_1ms":503,"reinsert_count":0,"update_count":2500}
I20260812 06:18:11.341745 22597 maintenance_manager.cc:419] P 8fc05e2c5f1d4769886914438129337e: Scheduling FlushDeltaMemStoresOp(679444cdcbde4daf94bf8e08d04b427f): perf score=2.188937
I20260812 06:18:11.353519 22524 maintenance_manager.cc:643] P 8fc05e2c5f1d4769886914438129337e: FlushDeltaMemStoresOp(679444cdcbde4daf94bf8e08d04b427f) complete. Timing: real 0.012s	user 0.011s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4083,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:11.354017 22597 maintenance_manager.cc:419] P 8fc05e2c5f1d4769886914438129337e: Scheduling MajorDeltaCompactionOp(679444cdcbde4daf94bf8e08d04b427f): perf score=1.000000
I20260812 06:18:11.577175 22524 maintenance_manager.cc:643] P 8fc05e2c5f1d4769886914438129337e: MajorDeltaCompactionOp(679444cdcbde4daf94bf8e08d04b427f) complete. Timing: real 0.223s	user 0.163s	sys 0.059s Metrics: {"cfile_cache_miss":632,"cfile_cache_miss_bytes":28877102,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":1104,"lbm_read_time_us":13862,"lbm_reads_lt_1ms":672,"lbm_write_time_us":36432,"lbm_writes_lt_1ms":643,"mutex_wait_us":337,"peak_mem_usage":75542472,"reinsert_count":0,"update_count":3000}
I20260812 06:18:11.577780 22597 maintenance_manager.cc:419] P 8fc05e2c5f1d4769886914438129337e: Scheduling FlushDeltaMemStoresOp(679444cdcbde4daf94bf8e08d04b427f): perf score=18.063937
I20260812 06:18:11.657564 22524 maintenance_manager.cc:643] P 8fc05e2c5f1d4769886914438129337e: FlushDeltaMemStoresOp(679444cdcbde4daf94bf8e08d04b427f) complete. Timing: real 0.080s	user 0.033s	sys 0.032s Metrics: {"bytes_written":20512317,"delete_count":0,"lbm_write_time_us":30131,"lbm_writes_lt_1ms":503,"reinsert_count":0,"update_count":2500}
I20260812 06:18:11.658095 22597 maintenance_manager.cc:419] P 8fc05e2c5f1d4769886914438129337e: Scheduling FlushDeltaMemStoresOp(679444cdcbde4daf94bf8e08d04b427f): perf score=2.188937
I20260812 06:18:11.670373 22524 maintenance_manager.cc:643] P 8fc05e2c5f1d4769886914438129337e: FlushDeltaMemStoresOp(679444cdcbde4daf94bf8e08d04b427f) complete. Timing: real 0.012s	user 0.009s	sys 0.002s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4138,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:11.670984 22597 maintenance_manager.cc:419] P 8fc05e2c5f1d4769886914438129337e: Scheduling MajorDeltaCompactionOp(679444cdcbde4daf94bf8e08d04b427f): perf score=1.000000
I20260812 06:18:11.891757 22524 maintenance_manager.cc:643] P 8fc05e2c5f1d4769886914438129337e: MajorDeltaCompactionOp(679444cdcbde4daf94bf8e08d04b427f) complete. Timing: real 0.220s	user 0.162s	sys 0.056s Metrics: {"cfile_cache_miss":632,"cfile_cache_miss_bytes":28877104,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":173,"lbm_read_time_us":14103,"lbm_reads_lt_1ms":672,"lbm_write_time_us":38521,"lbm_writes_lt_1ms":643,"mutex_wait_us":63,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":10880,"update_count":3000}
I20260812 06:18:11.892706 22597 maintenance_manager.cc:419] P 8fc05e2c5f1d4769886914438129337e: Scheduling FlushDeltaMemStoresOp(679444cdcbde4daf94bf8e08d04b427f): perf score=16.079562
I20260812 06:18:11.938508 22524 maintenance_manager.cc:643] P 8fc05e2c5f1d4769886914438129337e: FlushDeltaMemStoresOp(679444cdcbde4daf94bf8e08d04b427f) complete. Timing: real 0.046s	user 0.019s	sys 0.024s Metrics: {"bytes_written":17968822,"delete_count":0,"lbm_write_time_us":20837,"lbm_writes_lt_1ms":441,"reinsert_count":0,"update_count":2190}
I20260812 06:18:11.939030 22597 maintenance_manager.cc:419] P 8fc05e2c5f1d4769886914438129337e: Scheduling FlushDeltaMemStoresOp(679444cdcbde4daf94bf8e08d04b427f): perf score=1.196750
I20260812 06:18:11.964263 22524 maintenance_manager.cc:643] P 8fc05e2c5f1d4769886914438129337e: FlushDeltaMemStoresOp(679444cdcbde4daf94bf8e08d04b427f) complete. Timing: real 0.025s	user 0.009s	sys 0.000s Metrics: {"bytes_written":2953959,"delete_count":0,"lbm_write_time_us":4113,"lbm_writes_lt_1ms":75,"reinsert_count":0,"update_count":360}
I20260812 06:18:11.964972 22597 maintenance_manager.cc:419] P 8fc05e2c5f1d4769886914438129337e: Scheduling FlushDeltaMemStoresOp(679444cdcbde4daf94bf8e08d04b427f): perf score=2.188937
I20260812 06:18:11.979307 22524 maintenance_manager.cc:643] P 8fc05e2c5f1d4769886914438129337e: FlushDeltaMemStoresOp(679444cdcbde4daf94bf8e08d04b427f) complete. Timing: real 0.014s	user 0.008s	sys 0.004s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":5319,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:18:11.979964 22597 maintenance_manager.cc:419] P 8fc05e2c5f1d4769886914438129337e: Scheduling MajorDeltaCompactionOp(679444cdcbde4daf94bf8e08d04b427f): perf score=1.000000
I20260812 06:18:12.212815 22524 maintenance_manager.cc:643] P 8fc05e2c5f1d4769886914438129337e: MajorDeltaCompactionOp(679444cdcbde4daf94bf8e08d04b427f) complete. Timing: real 0.233s	user 0.129s	sys 0.103s Metrics: {"cfile_cache_miss":633,"cfile_cache_miss_bytes":28877186,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":852,"lbm_read_time_us":14834,"lbm_reads_lt_1ms":673,"lbm_write_time_us":42476,"lbm_writes_lt_1ms":643,"mutex_wait_us":344,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":28544,"update_count":3000}
I20260812 06:18:12.213486 22597 maintenance_manager.cc:419] P 8fc05e2c5f1d4769886914438129337e: Scheduling FlushDeltaMemStoresOp(679444cdcbde4daf94bf8e08d04b427f): perf score=14.095187
I20260812 06:18:12.272939 22524 maintenance_manager.cc:643] P 8fc05e2c5f1d4769886914438129337e: FlushDeltaMemStoresOp(679444cdcbde4daf94bf8e08d04b427f) complete. Timing: real 0.059s	user 0.049s	sys 0.008s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":25074,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:18:12.273522 22597 maintenance_manager.cc:419] P 8fc05e2c5f1d4769886914438129337e: Scheduling FlushDeltaMemStoresOp(679444cdcbde4daf94bf8e08d04b427f): perf score=2.188937
I20260812 06:18:12.285568 22524 maintenance_manager.cc:643] P 8fc05e2c5f1d4769886914438129337e: FlushDeltaMemStoresOp(679444cdcbde4daf94bf8e08d04b427f) complete. Timing: real 0.012s	user 0.010s	sys 0.001s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4521,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:12.286307 22597 maintenance_manager.cc:419] P 8fc05e2c5f1d4769886914438129337e: Scheduling MajorDeltaCompactionOp(679444cdcbde4daf94bf8e08d04b427f): perf score=1.000000
I20260812 06:18:12.476212 22524 maintenance_manager.cc:643] P 8fc05e2c5f1d4769886914438129337e: MajorDeltaCompactionOp(679444cdcbde4daf94bf8e08d04b427f) complete. Timing: real 0.190s	user 0.133s	sys 0.056s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774688,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":223,"lbm_read_time_us":11427,"lbm_reads_lt_1ms":572,"lbm_write_time_us":34216,"lbm_writes_lt_1ms":543,"mutex_wait_us":27,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":12928,"update_count":2500}
I20260812 06:18:12.476948 22597 maintenance_manager.cc:419] P 8fc05e2c5f1d4769886914438129337e: Scheduling FlushDeltaMemStoresOp(679444cdcbde4daf94bf8e08d04b427f): perf score=14.095187
I20260812 06:18:12.525466 22524 maintenance_manager.cc:643] P 8fc05e2c5f1d4769886914438129337e: FlushDeltaMemStoresOp(679444cdcbde4daf94bf8e08d04b427f) complete. Timing: real 0.048s	user 0.027s	sys 0.020s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":21897,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:18:12.526041 22597 maintenance_manager.cc:419] P 8fc05e2c5f1d4769886914438129337e: Scheduling FlushDeltaMemStoresOp(679444cdcbde4daf94bf8e08d04b427f): perf score=2.188937
I20260812 06:18:12.539444 22524 maintenance_manager.cc:643] P 8fc05e2c5f1d4769886914438129337e: FlushDeltaMemStoresOp(679444cdcbde4daf94bf8e08d04b427f) complete. Timing: real 0.013s	user 0.006s	sys 0.005s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4799,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:12.540124 22597 maintenance_manager.cc:419] P 8fc05e2c5f1d4769886914438129337e: Scheduling FlushMRSOp(679444cdcbde4daf94bf8e08d04b427f): perf score=1.000000
I20260812 06:18:12.573570 22524 maintenance_manager.cc:643] P 8fc05e2c5f1d4769886914438129337e: FlushMRSOp(679444cdcbde4daf94bf8e08d04b427f) complete. Timing: real 0.033s	user 0.028s	sys 0.004s Metrics: {"bytes_written":1234477,"cfile_init":1,"dirs.queue_time_us":89,"dirs.run_cpu_time_us":244,"dirs.run_wall_time_us":1368,"drs_written":1,"lbm_read_time_us":55,"lbm_reads_lt_1ms":4,"lbm_write_time_us":2263,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":30}
I20260812 06:18:12.574271 22597 maintenance_manager.cc:419] P 8fc05e2c5f1d4769886914438129337e: Scheduling LogGCOp(679444cdcbde4daf94bf8e08d04b427f): free 121006417 bytes of WAL
I20260812 06:18:12.574525 22524 log_reader.cc:385] T 679444cdcbde4daf94bf8e08d04b427f: removed 12 log segments from log reader
I20260812 06:18:12.574574 22524 log.cc:1079] T 679444cdcbde4daf94bf8e08d04b427f P 8fc05e2c5f1d4769886914438129337e: Deleting log segment in path: /tmp/dist-test-taskoJaC7T/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515483274578-22190-0/minicluster-data/ts-0-root/wals/679444cdcbde4daf94bf8e08d04b427f/wal-000000016 (ops 75-79)
I20260812 06:18:12.574652 22524 log.cc:1079] T 679444cdcbde4daf94bf8e08d04b427f P 8fc05e2c5f1d4769886914438129337e: Deleting log segment in path: /tmp/dist-test-taskoJaC7T/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515483274578-22190-0/minicluster-data/ts-0-root/wals/679444cdcbde4daf94bf8e08d04b427f/wal-000000017 (ops 80-84)
I20260812 06:18:12.574723 22524 log.cc:1079] T 679444cdcbde4daf94bf8e08d04b427f P 8fc05e2c5f1d4769886914438129337e: Deleting log segment in path: /tmp/dist-test-taskoJaC7T/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515483274578-22190-0/minicluster-data/ts-0-root/wals/679444cdcbde4daf94bf8e08d04b427f/wal-000000018 (ops 85-89)
I20260812 06:18:12.574795 22524 log.cc:1079] T 679444cdcbde4daf94bf8e08d04b427f P 8fc05e2c5f1d4769886914438129337e: Deleting log segment in path: /tmp/dist-test-taskoJaC7T/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515483274578-22190-0/minicluster-data/ts-0-root/wals/679444cdcbde4daf94bf8e08d04b427f/wal-000000019 (ops 90-94)
I20260812 06:18:12.574867 22524 log.cc:1079] T 679444cdcbde4daf94bf8e08d04b427f P 8fc05e2c5f1d4769886914438129337e: Deleting log segment in path: /tmp/dist-test-taskoJaC7T/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515483274578-22190-0/minicluster-data/ts-0-root/wals/679444cdcbde4daf94bf8e08d04b427f/wal-000000020 (ops 95-99)
I20260812 06:18:12.574930 22524 log.cc:1079] T 679444cdcbde4daf94bf8e08d04b427f P 8fc05e2c5f1d4769886914438129337e: Deleting log segment in path: /tmp/dist-test-taskoJaC7T/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515483274578-22190-0/minicluster-data/ts-0-root/wals/679444cdcbde4daf94bf8e08d04b427f/wal-000000021 (ops 100-104)
I20260812 06:18:12.575006 22524 log.cc:1079] T 679444cdcbde4daf94bf8e08d04b427f P 8fc05e2c5f1d4769886914438129337e: Deleting log segment in path: /tmp/dist-test-taskoJaC7T/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515483274578-22190-0/minicluster-data/ts-0-root/wals/679444cdcbde4daf94bf8e08d04b427f/wal-000000022 (ops 105-109)
I20260812 06:18:12.575059 22524 log.cc:1079] T 679444cdcbde4daf94bf8e08d04b427f P 8fc05e2c5f1d4769886914438129337e: Deleting log segment in path: /tmp/dist-test-taskoJaC7T/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515483274578-22190-0/minicluster-data/ts-0-root/wals/679444cdcbde4daf94bf8e08d04b427f/wal-000000023 (ops 110-114)
I20260812 06:18:12.575101 22524 log.cc:1079] T 679444cdcbde4daf94bf8e08d04b427f P 8fc05e2c5f1d4769886914438129337e: Deleting log segment in path: /tmp/dist-test-taskoJaC7T/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515483274578-22190-0/minicluster-data/ts-0-root/wals/679444cdcbde4daf94bf8e08d04b427f/wal-000000024 (ops 115-118)
I20260812 06:18:12.575143 22524 log.cc:1079] T 679444cdcbde4daf94bf8e08d04b427f P 8fc05e2c5f1d4769886914438129337e: Deleting log segment in path: /tmp/dist-test-taskoJaC7T/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515483274578-22190-0/minicluster-data/ts-0-root/wals/679444cdcbde4daf94bf8e08d04b427f/wal-000000025 (ops 119-123)
I20260812 06:18:12.575186 22524 log.cc:1079] T 679444cdcbde4daf94bf8e08d04b427f P 8fc05e2c5f1d4769886914438129337e: Deleting log segment in path: /tmp/dist-test-taskoJaC7T/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515483274578-22190-0/minicluster-data/ts-0-root/wals/679444cdcbde4daf94bf8e08d04b427f/wal-000000026 (ops 124-128)
I20260812 06:18:12.575227 22524 log.cc:1079] T 679444cdcbde4daf94bf8e08d04b427f P 8fc05e2c5f1d4769886914438129337e: Deleting log segment in path: /tmp/dist-test-taskoJaC7T/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515483274578-22190-0/minicluster-data/ts-0-root/wals/679444cdcbde4daf94bf8e08d04b427f/wal-000000027 (ops 129-133)
I20260812 06:18:12.605379 22524 maintenance_manager.cc:643] P 8fc05e2c5f1d4769886914438129337e: LogGCOp(679444cdcbde4daf94bf8e08d04b427f) complete. Timing: real 0.031s	user 0.000s	sys 0.030s Metrics: {}
I20260812 06:18:12.605827 22597 maintenance_manager.cc:419] P 8fc05e2c5f1d4769886914438129337e: Scheduling FlushDeltaMemStoresOp(679444cdcbde4daf94bf8e08d04b427f): perf score=4.173312
I20260812 06:18:12.623112 22524 maintenance_manager.cc:643] P 8fc05e2c5f1d4769886914438129337e: FlushDeltaMemStoresOp(679444cdcbde4daf94bf8e08d04b427f) complete. Timing: real 0.017s	user 0.008s	sys 0.007s Metrics: {"bytes_written":5866705,"delete_count":0,"lbm_write_time_us":6918,"lbm_writes_lt_1ms":146,"reinsert_count":0,"update_count":715}
I20260812 06:18:12.623580 22597 maintenance_manager.cc:419] P 8fc05e2c5f1d4769886914438129337e: Scheduling UndoDeltaBlockGCOp(679444cdcbde4daf94bf8e08d04b427f): 473 bytes on disk
I20260812 06:18:12.624042 22524 maintenance_manager.cc:643] P 8fc05e2c5f1d4769886914438129337e: UndoDeltaBlockGCOp(679444cdcbde4daf94bf8e08d04b427f) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":66,"lbm_reads_lt_1ms":4}
I20260812 06:18:12.624523 22597 maintenance_manager.cc:419] P 8fc05e2c5f1d4769886914438129337e: Scheduling FlushDeltaMemStoresOp(679444cdcbde4daf94bf8e08d04b427f): perf score=1.196750
I20260812 06:18:12.633165 22524 maintenance_manager.cc:643] P 8fc05e2c5f1d4769886914438129337e: FlushDeltaMemStoresOp(679444cdcbde4daf94bf8e08d04b427f) complete. Timing: real 0.008s	user 0.008s	sys 0.000s Metrics: {"bytes_written":2338579,"delete_count":0,"lbm_write_time_us":2923,"lbm_writes_lt_1ms":60,"reinsert_count":0,"update_count":285}
I20260812 06:18:12.633636 22597 maintenance_manager.cc:419] P 8fc05e2c5f1d4769886914438129337e: Scheduling MajorDeltaCompactionOp(679444cdcbde4daf94bf8e08d04b427f): perf score=1.000000
I20260812 06:18:12.855018 22524 maintenance_manager.cc:643] P 8fc05e2c5f1d4769886914438129337e: MajorDeltaCompactionOp(679444cdcbde4daf94bf8e08d04b427f) complete. Timing: real 0.221s	user 0.133s	sys 0.088s Metrics: {"cfile_cache_miss":734,"cfile_cache_miss_bytes":32979711,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":1008,"lbm_read_time_us":16084,"lbm_reads_lt_1ms":774,"lbm_write_time_us":41432,"lbm_writes_lt_1ms":743,"mutex_wait_us":343,"peak_mem_usage":87969044,"reinsert_count":0,"spinlock_wait_cycles":11008,"thread_start_us":105,"threads_started":1,"update_count":3500}
I20260812 06:18:12.855825 22597 maintenance_manager.cc:419] P 8fc05e2c5f1d4769886914438129337e: Scheduling FlushDeltaMemStoresOp(679444cdcbde4daf94bf8e08d04b427f): perf score=18.063937
I20260812 06:18:12.918092 22524 maintenance_manager.cc:643] P 8fc05e2c5f1d4769886914438129337e: FlushDeltaMemStoresOp(679444cdcbde4daf94bf8e08d04b427f) complete. Timing: real 0.062s	user 0.054s	sys 0.007s Metrics: {"bytes_written":20512315,"delete_count":0,"lbm_write_time_us":28028,"lbm_writes_lt_1ms":503,"reinsert_count":0,"update_count":2500}
I20260812 06:18:12.918776 22597 maintenance_manager.cc:419] P 8fc05e2c5f1d4769886914438129337e: Scheduling FlushDeltaMemStoresOp(679444cdcbde4daf94bf8e08d04b427f): perf score=2.188937
I20260812 06:18:12.939904 22524 maintenance_manager.cc:643] P 8fc05e2c5f1d4769886914438129337e: FlushDeltaMemStoresOp(679444cdcbde4daf94bf8e08d04b427f) complete. Timing: real 0.021s	user 0.014s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6416,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:12.940687 22597 maintenance_manager.cc:419] P 8fc05e2c5f1d4769886914438129337e: Scheduling MajorDeltaCompactionOp(679444cdcbde4daf94bf8e08d04b427f): perf score=1.000000
I20260812 06:18:13.126178 22524 maintenance_manager.cc:643] P 8fc05e2c5f1d4769886914438129337e: MajorDeltaCompactionOp(679444cdcbde4daf94bf8e08d04b427f) complete. Timing: real 0.185s	user 0.132s	sys 0.043s Metrics: {"cfile_cache_miss":632,"cfile_cache_miss_bytes":28877102,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":593,"lbm_read_time_us":12220,"lbm_reads_lt_1ms":664,"lbm_write_time_us":37208,"lbm_writes_lt_1ms":643,"mutex_wait_us":321,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":32384,"update_count":3000}
I20260812 06:18:13.126758 22597 maintenance_manager.cc:419] P 8fc05e2c5f1d4769886914438129337e: Scheduling FlushDeltaMemStoresOp(679444cdcbde4daf94bf8e08d04b427f): perf score=18.063937
I20260812 06:18:13.187125 22524 maintenance_manager.cc:643] P 8fc05e2c5f1d4769886914438129337e: FlushDeltaMemStoresOp(679444cdcbde4daf94bf8e08d04b427f) complete. Timing: real 0.060s	user 0.021s	sys 0.037s Metrics: {"bytes_written":20512315,"delete_count":0,"lbm_write_time_us":27592,"lbm_writes_lt_1ms":503,"reinsert_count":0,"update_count":2500}
I20260812 06:18:13.187625 22597 maintenance_manager.cc:419] P 8fc05e2c5f1d4769886914438129337e: Scheduling FlushDeltaMemStoresOp(679444cdcbde4daf94bf8e08d04b427f): perf score=2.188937
I20260812 06:18:13.201078 22524 maintenance_manager.cc:643] P 8fc05e2c5f1d4769886914438129337e: FlushDeltaMemStoresOp(679444cdcbde4daf94bf8e08d04b427f) complete. Timing: real 0.013s	user 0.005s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5128,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:13.201614 22597 maintenance_manager.cc:419] P 8fc05e2c5f1d4769886914438129337e: Scheduling MajorDeltaCompactionOp(679444cdcbde4daf94bf8e08d04b427f): perf score=1.000000
I20260812 06:18:13.369259 22524 maintenance_manager.cc:643] P 8fc05e2c5f1d4769886914438129337e: MajorDeltaCompactionOp(679444cdcbde4daf94bf8e08d04b427f) complete. Timing: real 0.167s	user 0.116s	sys 0.051s Metrics: {"cfile_cache_miss":632,"cfile_cache_miss_bytes":28877102,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":205,"lbm_read_time_us":12123,"lbm_reads_lt_1ms":672,"lbm_write_time_us":33994,"lbm_writes_lt_1ms":643,"mutex_wait_us":24,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":6144,"update_count":3000}
I20260812 06:18:13.369823 22597 maintenance_manager.cc:419] P 8fc05e2c5f1d4769886914438129337e: Scheduling FlushDeltaMemStoresOp(679444cdcbde4daf94bf8e08d04b427f): perf score=14.095187
I20260812 06:18:13.417065 22524 maintenance_manager.cc:643] P 8fc05e2c5f1d4769886914438129337e: FlushDeltaMemStoresOp(679444cdcbde4daf94bf8e08d04b427f) complete. Timing: real 0.047s	user 0.030s	sys 0.017s Metrics: {"bytes_written":16409903,"delete_count":0,"lbm_write_time_us":21153,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:18:13.417711 22597 maintenance_manager.cc:419] P 8fc05e2c5f1d4769886914438129337e: Scheduling FlushDeltaMemStoresOp(679444cdcbde4daf94bf8e08d04b427f): perf score=2.188937
I20260812 06:18:13.439306 22524 maintenance_manager.cc:643] P 8fc05e2c5f1d4769886914438129337e: FlushDeltaMemStoresOp(679444cdcbde4daf94bf8e08d04b427f) complete. Timing: real 0.021s	user 0.010s	sys 0.005s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6448,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:13.440037 22597 maintenance_manager.cc:419] P 8fc05e2c5f1d4769886914438129337e: Scheduling MajorDeltaCompactionOp(679444cdcbde4daf94bf8e08d04b427f): perf score=1.000000
I20260812 06:18:13.606673 22524 maintenance_manager.cc:643] P 8fc05e2c5f1d4769886914438129337e: MajorDeltaCompactionOp(679444cdcbde4daf94bf8e08d04b427f) complete. Timing: real 0.166s	user 0.139s	sys 0.027s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774690,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":998,"lbm_read_time_us":11230,"lbm_reads_lt_1ms":564,"lbm_write_time_us":31140,"lbm_writes_lt_1ms":543,"mutex_wait_us":49,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":3584,"update_count":2500}
I20260812 06:18:13.607430 22597 maintenance_manager.cc:419] P 8fc05e2c5f1d4769886914438129337e: Scheduling FlushDeltaMemStoresOp(679444cdcbde4daf94bf8e08d04b427f): perf score=14.095187
I20260812 06:18:13.671602 22524 maintenance_manager.cc:643] P 8fc05e2c5f1d4769886914438129337e: FlushDeltaMemStoresOp(679444cdcbde4daf94bf8e08d04b427f) complete. Timing: real 0.064s	user 0.028s	sys 0.021s Metrics: {"bytes_written":16409903,"delete_count":0,"lbm_write_time_us":23168,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:18:13.672127 22597 maintenance_manager.cc:419] P 8fc05e2c5f1d4769886914438129337e: Scheduling FlushDeltaMemStoresOp(679444cdcbde4daf94bf8e08d04b427f): perf score=2.188937
I20260812 06:18:13.683974 22524 maintenance_manager.cc:643] P 8fc05e2c5f1d4769886914438129337e: FlushDeltaMemStoresOp(679444cdcbde4daf94bf8e08d04b427f) complete. Timing: real 0.012s	user 0.007s	sys 0.003s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4596,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:13.684544 22597 maintenance_manager.cc:419] P 8fc05e2c5f1d4769886914438129337e: Scheduling MajorDeltaCompactionOp(679444cdcbde4daf94bf8e08d04b427f): perf score=1.000000
I20260812 06:18:13.876617 22524 maintenance_manager.cc:643] P 8fc05e2c5f1d4769886914438129337e: MajorDeltaCompactionOp(679444cdcbde4daf94bf8e08d04b427f) complete. Timing: real 0.192s	user 0.115s	sys 0.069s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774690,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":326,"lbm_read_time_us":13236,"lbm_reads_lt_1ms":572,"lbm_write_time_us":32310,"lbm_writes_lt_1ms":543,"mutex_wait_us":25,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":34176,"update_count":2500}
I20260812 06:18:13.877267 22597 maintenance_manager.cc:419] P 8fc05e2c5f1d4769886914438129337e: Scheduling FlushDeltaMemStoresOp(679444cdcbde4daf94bf8e08d04b427f): perf score=14.095187
I20260812 06:18:13.938373 22524 maintenance_manager.cc:643] P 8fc05e2c5f1d4769886914438129337e: FlushDeltaMemStoresOp(679444cdcbde4daf94bf8e08d04b427f) complete. Timing: real 0.061s	user 0.026s	sys 0.023s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":19198,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:18:13.938931 22597 maintenance_manager.cc:419] P 8fc05e2c5f1d4769886914438129337e: Scheduling FlushDeltaMemStoresOp(679444cdcbde4daf94bf8e08d04b427f): perf score=2.188937
I20260812 06:18:13.950313 22524 maintenance_manager.cc:643] P 8fc05e2c5f1d4769886914438129337e: FlushDeltaMemStoresOp(679444cdcbde4daf94bf8e08d04b427f) complete. Timing: real 0.011s	user 0.005s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4328,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:13.950862 22597 maintenance_manager.cc:419] P 8fc05e2c5f1d4769886914438129337e: Scheduling FlushMRSOp(679444cdcbde4daf94bf8e08d04b427f): perf score=1.000000
I20260812 06:18:13.993920 22524 maintenance_manager.cc:643] P 8fc05e2c5f1d4769886914438129337e: FlushMRSOp(679444cdcbde4daf94bf8e08d04b427f) complete. Timing: real 0.043s	user 0.033s	sys 0.000s Metrics: {"bytes_written":1193507,"cfile_init":1,"dirs.queue_time_us":68,"dirs.run_cpu_time_us":269,"dirs.run_wall_time_us":1289,"drs_written":1,"lbm_read_time_us":43,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1962,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":29}
I20260812 06:18:13.994644 22597 maintenance_manager.cc:419] P 8fc05e2c5f1d4769886914438129337e: Scheduling LogGCOp(679444cdcbde4daf94bf8e08d04b427f): free 124257565 bytes of WAL
I20260812 06:18:13.994884 22524 log_reader.cc:385] T 679444cdcbde4daf94bf8e08d04b427f: removed 12 log segments from log reader
I20260812 06:18:13.994946 22524 log.cc:1079] T 679444cdcbde4daf94bf8e08d04b427f P 8fc05e2c5f1d4769886914438129337e: Deleting log segment in path: /tmp/dist-test-taskoJaC7T/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515483274578-22190-0/minicluster-data/ts-0-root/wals/679444cdcbde4daf94bf8e08d04b427f/wal-000000028 (ops 134-138)
I20260812 06:18:13.995000 22524 log.cc:1079] T 679444cdcbde4daf94bf8e08d04b427f P 8fc05e2c5f1d4769886914438129337e: Deleting log segment in path: /tmp/dist-test-taskoJaC7T/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515483274578-22190-0/minicluster-data/ts-0-root/wals/679444cdcbde4daf94bf8e08d04b427f/wal-000000029 (ops 139-142)
I20260812 06:18:13.995064 22524 log.cc:1079] T 679444cdcbde4daf94bf8e08d04b427f P 8fc05e2c5f1d4769886914438129337e: Deleting log segment in path: /tmp/dist-test-taskoJaC7T/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515483274578-22190-0/minicluster-data/ts-0-root/wals/679444cdcbde4daf94bf8e08d04b427f/wal-000000030 (ops 143-147)
I20260812 06:18:13.995112 22524 log.cc:1079] T 679444cdcbde4daf94bf8e08d04b427f P 8fc05e2c5f1d4769886914438129337e: Deleting log segment in path: /tmp/dist-test-taskoJaC7T/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515483274578-22190-0/minicluster-data/ts-0-root/wals/679444cdcbde4daf94bf8e08d04b427f/wal-000000031 (ops 148-152)
I20260812 06:18:13.995149 22524 log.cc:1079] T 679444cdcbde4daf94bf8e08d04b427f P 8fc05e2c5f1d4769886914438129337e: Deleting log segment in path: /tmp/dist-test-taskoJaC7T/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515483274578-22190-0/minicluster-data/ts-0-root/wals/679444cdcbde4daf94bf8e08d04b427f/wal-000000032 (ops 153-157)
I20260812 06:18:13.995186 22524 log.cc:1079] T 679444cdcbde4daf94bf8e08d04b427f P 8fc05e2c5f1d4769886914438129337e: Deleting log segment in path: /tmp/dist-test-taskoJaC7T/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515483274578-22190-0/minicluster-data/ts-0-root/wals/679444cdcbde4daf94bf8e08d04b427f/wal-000000033 (ops 158-162)
I20260812 06:18:13.995224 22524 log.cc:1079] T 679444cdcbde4daf94bf8e08d04b427f P 8fc05e2c5f1d4769886914438129337e: Deleting log segment in path: /tmp/dist-test-taskoJaC7T/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515483274578-22190-0/minicluster-data/ts-0-root/wals/679444cdcbde4daf94bf8e08d04b427f/wal-000000034 (ops 163-167)
I20260812 06:18:13.995302 22524 log.cc:1079] T 679444cdcbde4daf94bf8e08d04b427f P 8fc05e2c5f1d4769886914438129337e: Deleting log segment in path: /tmp/dist-test-taskoJaC7T/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515483274578-22190-0/minicluster-data/ts-0-root/wals/679444cdcbde4daf94bf8e08d04b427f/wal-000000035 (ops 168-172)
I20260812 06:18:13.995347 22524 log.cc:1079] T 679444cdcbde4daf94bf8e08d04b427f P 8fc05e2c5f1d4769886914438129337e: Deleting log segment in path: /tmp/dist-test-taskoJaC7T/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515483274578-22190-0/minicluster-data/ts-0-root/wals/679444cdcbde4daf94bf8e08d04b427f/wal-000000036 (ops 173-177)
I20260812 06:18:13.995374 22524 log.cc:1079] T 679444cdcbde4daf94bf8e08d04b427f P 8fc05e2c5f1d4769886914438129337e: Deleting log segment in path: /tmp/dist-test-taskoJaC7T/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515483274578-22190-0/minicluster-data/ts-0-root/wals/679444cdcbde4daf94bf8e08d04b427f/wal-000000037 (ops 178-182)
I20260812 06:18:13.995432 22524 log.cc:1079] T 679444cdcbde4daf94bf8e08d04b427f P 8fc05e2c5f1d4769886914438129337e: Deleting log segment in path: /tmp/dist-test-taskoJaC7T/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515483274578-22190-0/minicluster-data/ts-0-root/wals/679444cdcbde4daf94bf8e08d04b427f/wal-000000038 (ops 183-187)
I20260812 06:18:13.995496 22524 log.cc:1079] T 679444cdcbde4daf94bf8e08d04b427f P 8fc05e2c5f1d4769886914438129337e: Deleting log segment in path: /tmp/dist-test-taskoJaC7T/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515483274578-22190-0/minicluster-data/ts-0-root/wals/679444cdcbde4daf94bf8e08d04b427f/wal-000000039 (ops 188-192)
I20260812 06:18:14.021916 22524 maintenance_manager.cc:643] P 8fc05e2c5f1d4769886914438129337e: LogGCOp(679444cdcbde4daf94bf8e08d04b427f) complete. Timing: real 0.027s	user 0.000s	sys 0.026s Metrics: {}
I20260812 06:18:14.022454 22597 maintenance_manager.cc:419] P 8fc05e2c5f1d4769886914438129337e: Scheduling FlushDeltaMemStoresOp(679444cdcbde4daf94bf8e08d04b427f): perf score=2.188937
I20260812 06:18:14.040388 22524 maintenance_manager.cc:643] P 8fc05e2c5f1d4769886914438129337e: FlushDeltaMemStoresOp(679444cdcbde4daf94bf8e08d04b427f) complete. Timing: real 0.018s	user 0.004s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5462,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:14.040953 22597 maintenance_manager.cc:419] P 8fc05e2c5f1d4769886914438129337e: Scheduling UndoDeltaBlockGCOp(679444cdcbde4daf94bf8e08d04b427f): 462 bytes on disk
I20260812 06:18:14.041515 22524 maintenance_manager.cc:643] P 8fc05e2c5f1d4769886914438129337e: UndoDeltaBlockGCOp(679444cdcbde4daf94bf8e08d04b427f) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":77,"lbm_reads_lt_1ms":4}
I20260812 06:18:14.042028 22597 maintenance_manager.cc:419] P 8fc05e2c5f1d4769886914438129337e: Scheduling FlushDeltaMemStoresOp(679444cdcbde4daf94bf8e08d04b427f): perf score=2.188937
I20260812 06:18:14.052577 22524 maintenance_manager.cc:643] P 8fc05e2c5f1d4769886914438129337e: FlushDeltaMemStoresOp(679444cdcbde4daf94bf8e08d04b427f) complete. Timing: real 0.010s	user 0.008s	sys 0.000s 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:18:14.053189 22597 maintenance_manager.cc:419] P 8fc05e2c5f1d4769886914438129337e: Scheduling MajorDeltaCompactionOp(679444cdcbde4daf94bf8e08d04b427f): perf score=1.000000
I20260812 06:18:14.175105 22190 heavy-update-compaction-itest.cc:229] Time spent updating: real 4.991s	user 1.899s	sys 0.172s
I20260812 06:18:14.266170 22524 maintenance_manager.cc:643] P 8fc05e2c5f1d4769886914438129337e: MajorDeltaCompactionOp(679444cdcbde4daf94bf8e08d04b427f) complete. Timing: real 0.213s	user 0.133s	sys 0.080s Metrics: {"cfile_cache_miss":734,"cfile_cache_miss_bytes":32979750,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":859,"lbm_read_time_us":14221,"lbm_reads_lt_1ms":770,"lbm_write_time_us":36534,"lbm_writes_lt_1ms":743,"mutex_wait_us":41,"peak_mem_usage":87969044,"reinsert_count":0,"spinlock_wait_cycles":16128,"thread_start_us":90,"threads_started":1,"update_count":3500}
I20260812 06:18:14.266949 22597 maintenance_manager.cc:419] P 8fc05e2c5f1d4769886914438129337e: Scheduling FlushDeltaMemStoresOp(679444cdcbde4daf94bf8e08d04b427f): perf score=10.126437
I20260812 06:18:14.275378 22190 heavy-update-compaction-itest.cc:265] Time spent scanning: real 0.100s	user 0.001s	sys 0.000s
I20260812 06:18:14.275933 22190 tablet_server.cc:179] TabletServer@127.21.171.129:0 shutting down...
I20260812 06:18:14.304049 22524 maintenance_manager.cc:643] P 8fc05e2c5f1d4769886914438129337e: FlushDeltaMemStoresOp(679444cdcbde4daf94bf8e08d04b427f) complete. Timing: real 0.037s	user 0.020s	sys 0.014s Metrics: {"bytes_written":12307489,"delete_count":0,"lbm_write_time_us":16495,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":302,"reinsert_count":0,"update_count":1500}
I20260812 06:18:14.304662 22190 ts_tablet_manager.cc:1507] Shutting down tablet manager...
I20260812 06:18:14.304951 22190 tablet_replica.cc:333] T 679444cdcbde4daf94bf8e08d04b427f P 8fc05e2c5f1d4769886914438129337e: stopping tablet replica
I20260812 06:18:14.305155 22190 raft_consensus.cc:2243] T 679444cdcbde4daf94bf8e08d04b427f P 8fc05e2c5f1d4769886914438129337e [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:18:14.305352 22190 raft_consensus.cc:2272] T 679444cdcbde4daf94bf8e08d04b427f P 8fc05e2c5f1d4769886914438129337e [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:18:14.320292 22190 tablet_server.cc:196] TabletServer@127.21.171.129:0 shutdown complete.
I20260812 06:18:14.323585 22190 master.cc:562] Master@127.21.171.190:46475 shutting down...
I20260812 06:18:14.326655 22190 raft_consensus.cc:2243] T 00000000000000000000000000000000 P ee812164448c4c51b9e00822b3aa5efa [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:18:14.326874 22190 raft_consensus.cc:2272] T 00000000000000000000000000000000 P ee812164448c4c51b9e00822b3aa5efa [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:18:14.326985 22190 tablet_replica.cc:333] T 00000000000000000000000000000000 P ee812164448c4c51b9e00822b3aa5efa: stopping tablet replica
I20260812 06:18:14.339478 22190 master.cc:584] Master@127.21.171.190:46475 shutdown complete.
[       OK ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/1 (5485 ms)
[----------] 2 tests from EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy (11142 ms total)

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